Skip to content

Commit 122f929

Browse files
authored
feat(cli): record command duration in telemetry (#3454)
1 parent ce6039f commit 122f929

12 files changed

Lines changed: 1371 additions & 127 deletions

‎app/cli/cmd/root.go‎

Lines changed: 52 additions & 102 deletions
Original file line numberDiff line numberDiff line change
@@ -16,20 +16,16 @@
1616
package cmd
1717

1818
import (
19-
"context"
2019
"crypto/sha256"
2120
"encoding/hex"
2221
"errors"
2322
"fmt"
2423
"os"
2524
"path/filepath"
2625
"strings"
27-
"sync"
26+
"time"
2827

2928
"github.com/adrg/xdg"
30-
"github.com/chainloop-dev/chainloop/app/cli/internal/telemetry"
31-
"github.com/chainloop-dev/chainloop/app/cli/internal/telemetry/posthog"
32-
token "github.com/chainloop-dev/chainloop/app/cli/internal/token"
3329
"github.com/chainloop-dev/chainloop/app/cli/pkg/action"
3430
"github.com/chainloop-dev/chainloop/app/cli/pkg/plugins"
3531
v1 "github.com/chainloop-dev/chainloop/app/controlplane/api/controlplane/v1"
@@ -82,13 +78,32 @@ const (
8278
cliReferenceURL = "https://github.com/chainloop-dev/chainloop/blob/main/app/cli/documentation/cli-reference.md"
8379
)
8480

85-
var telemetryWg sync.WaitGroup
86-
8781
// Environment variable prefix for vipers
8882
const envPrefix = "CHAINLOOP"
8983

84+
// pluginLessCommands are the commands that never make use of plugins, keyed by the first
85+
// argument on the command line. Loading plugins starts a subprocess per installed plugin,
86+
// so it is skipped for the commands that cannot benefit from it.
87+
var pluginLessCommands = map[string]bool{
88+
"completion": true,
89+
"help": true,
90+
telemetryCmdUse: true,
91+
}
92+
93+
// processStart is when this process began, as close to it as a package variable gets. The
94+
// reported duration is measured from here rather than from the top of Execute because
95+
// NewRootCmd runs first and loads plugins, which starts a subprocess and an RPC handshake
96+
// per plugin. Timing from Execute would leave that out for exactly the users who have
97+
// plugins installed, making their numbers incomparable with everyone else's.
98+
var processStart = time.Now()
99+
90100
func Execute(rootCmd *cobra.Command) error {
91-
if err := rootCmd.Execute(); err != nil {
101+
// The command outcome is reported from here, the only place that sees both ends of
102+
// every command, including the ones that fail and so skip cobra's post-run hooks.
103+
executed, err := rootCmd.ExecuteC()
104+
reportCommand(executed, time.Since(processStart), err)
105+
106+
if err != nil {
92107
// The local file is pointing to the wrong organization, we remove it
93108
if v1.IsUserNotMemberOfOrgErrorNotInOrg(err) {
94109
if err := setLocalOrganization(""); err != nil {
@@ -218,44 +233,6 @@ Command reference: ` + cliReferenceURL,
218233
return fmt.Errorf("failed to register discover builtin: %w", err)
219234
}
220235

221-
if !isTelemetryDisabled() {
222-
logger.Debug().Msg("Telemetry enabled, to disable it use DO_NOT_TRACK=1")
223-
224-
telemetryWg.Add(1)
225-
go func() {
226-
defer telemetryWg.Done()
227-
228-
// Stop waiting on the delivery goroutine after the flush deadline, so a slow
229-
// or unreachable telemetry endpoint cannot hold up the command.
230-
ctx, cancel := context.WithTimeout(context.Background(), telemetry.FlushTimeout)
231-
defer cancel()
232-
done := make(chan struct{})
233-
234-
go func() {
235-
// For telemetry reasons we parse the token to know the type of token is being used when executing the CLI
236-
// Once we have the token type we can send it to the telemetry service by injecting it on the context
237-
authToken, err := token.Parse(authToken)
238-
if err != nil {
239-
logger.Debug().Err(err).Msg("parsing token for telemetry")
240-
return
241-
}
242-
243-
err = recordCommand(cmd, authToken)
244-
if err != nil {
245-
logger.Debug().Err(err).Msg("sending command to telemetry")
246-
}
247-
close(done)
248-
}()
249-
250-
select {
251-
case <-done:
252-
// The parsing and recording finished successfully within the timeout
253-
case <-ctx.Done():
254-
// The operation took more than timeout
255-
}
256-
}()
257-
}
258-
259236
return nil
260237
},
261238
PersistentPostRunE: func(_ *cobra.Command, _ []string) error {
@@ -313,11 +290,14 @@ Command reference: ` + cliReferenceURL,
313290
newAttestationCmd(), newArtifactCmd(), newConfigCmd(),
314291
newIntegrationCmd(), newOrganizationCmd(), newCASBackendCmd(),
315292
newReferrerDiscoverCmd(), newPolicyCmd(), newApplyCmd(),
316-
newTraceCmd(),
293+
newTraceCmd(), newTelemetryCmd(),
317294
)
318295

319-
// Load plugins for root command and subcommands (except completion and help)
320-
if len(os.Args) == 1 || (len(os.Args) > 1 && os.Args[1] != "completion" && os.Args[1] != "help") {
296+
// Load plugins for root command and subcommands, except for the ones that cannot use
297+
// them. `telemetry` is in that list because it is the detached child that delivers an
298+
// analytics event: loading plugins there would spawn a subprocess and an RPC handshake
299+
// per installed plugin, for a process whose whole job is one HTTP request.
300+
if len(os.Args) == 1 || (len(os.Args) > 1 && !pluginLessCommands[os.Args[1]]) {
321301
pluginManager = plugins.NewManager(&logger)
322302
if err := loadAllPlugins(rootCmd); err != nil {
323303
logger.Error().Err(err).Msg("Failed to load plugins, continuing with built-in commands only")
@@ -341,11 +321,6 @@ func CalculateEnvVarName(key string) string {
341321

342322
func init() {
343323
cobra.OnInitialize(initConfigFile)
344-
// Using the cobra.OnFinalize because the hooks don't work on error
345-
cobra.OnFinalize(func() {
346-
// In some cases the command is faster than the telemetry, in that case we wait
347-
telemetryWg.Wait()
348-
})
349324
}
350325

351326
// isTelemetryDisabled checks if the telemetry is disabled by the user or if we are running a development version
@@ -370,6 +345,14 @@ func initLogger(logger zerolog.Logger) (zerolog.Logger, error) {
370345
}
371346

372347
func initConfigFile() {
348+
// The telemetry child reads nothing from the config: everything it needs is either
349+
// compiled in or arrived in its payload. Skipping the setup keeps it from creating the
350+
// config directory and writing a default file, and from panicking below when that
351+
// directory cannot be created, in a process whose only job is one HTTP request.
352+
if isTelemetryFlushInvocation() {
353+
return
354+
}
355+
373356
// An existing config file was passed as a flag and we use it as is
374357
if flagCfgFile != "" {
375358
viper.SetConfigFile(flagCfgFile)
@@ -482,65 +465,32 @@ var (
482465
posthogEndpoint = "https://t.chainloop.dev"
483466
)
484467

485-
// recordCommand sends the command to the telemetry service
486-
func recordCommand(executedCmd *cobra.Command, authInfo *token.ParsedToken) error {
487-
telemetryClient, err := posthog.NewClient(posthogAPIKey, posthogEndpoint)
488-
if err != nil {
489-
logger.Debug().Err(err).Msgf("creating telemetry client: %v", err)
490-
return nil
491-
}
492-
493-
cmdTracker := telemetry.NewCommandTracker(telemetryClient)
494-
controlplaneURL, controlplaneHash := hashControlPlaneURL()
495-
496-
tags := telemetry.Tags{
497-
"cli_version": Version,
498-
"edition": Edition,
499-
"cp_url_hash": controlplaneHash,
500-
"cp_installation_url": controlplaneURL,
501-
"chainloop_source": "cli",
502-
}
503-
504-
// It tries to extract the token from the context and add it to the tags. If it fails, it will ignore it.
505-
if authInfo != nil {
506-
tags["token_type"] = authInfo.TokenType.String()
507-
tags["user_id"] = authInfo.ID
508-
tags["org_id"] = authInfo.OrgID
509-
}
510-
511-
// Add organization name if available
512-
orgName := viper.GetString(confOptions.organization.viperKey)
513-
if orgName != "" {
514-
tags["organization_name"] = orgName
515-
}
516-
517-
if err = cmdTracker.Track(executedCmd.Context(), extractCmdLineFromCommand(executedCmd), tags); err != nil {
518-
return fmt.Errorf("sending event: %w", err)
519-
}
520-
521-
return nil
522-
}
523-
524468
// extractCmdLineFromCommand returns the full command hierarchy as a string from a cobra.Command
525469
func extractCmdLineFromCommand(cmd *cobra.Command) string {
526470
var cmdHierarchy []string
527-
currentCmd := cmd
528-
// While the current command is not the root command, keep iteration.
529-
// This is done to get the full hierarchy of the command and remove the root command from the hierarchy.
530-
for currentCmd.Use != "chainloop" {
471+
// Walk up to the root command, which is dropped from the hierarchy. The nil check is
472+
// what terminates the walk for a command that is not attached to the root: this runs on
473+
// the exit path of every command, including the ones that failed, and telemetry must
474+
// never be the reason the CLI panics.
475+
for currentCmd := cmd; currentCmd != nil && currentCmd.Use != appName; currentCmd = currentCmd.Parent() {
531476
cmdHierarchy = append([]string{currentCmd.Use}, cmdHierarchy...)
532-
currentCmd = currentCmd.Parent()
533477
}
534478

535479
cmdLine := strings.Join(cmdHierarchy, " ")
536480
return cmdLine
537481
}
538482

539-
// hashControlPlaneURL returns a hash of the control plane URL
540-
func hashControlPlaneURL() (url string, hash string) {
541-
url = viper.GetString(confOptions.controlplaneAPI.viperKey)
483+
// controlPlaneURL returns the control plane the CLI is configured to talk to.
484+
func controlPlaneURL() string {
485+
return viper.GetString(confOptions.controlplaneAPI.viperKey)
486+
}
487+
488+
// hashURL is the hash telemetry groups events by. It takes the URL rather than reading the
489+
// configuration so that the telemetry child, which only receives the URL, computes the
490+
// same value as the parent would.
491+
func hashURL(url string) string {
542492
sum := sha256.Sum256([]byte(url))
543-
return url, hex.EncodeToString(sum[:])
493+
return hex.EncodeToString(sum[:])
544494
}
545495

546496
func apiInsecure() bool {
Lines changed: 29 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,29 @@
1+
//
2+
// Copyright 2026 The Chainloop Authors.
3+
//
4+
// Licensed under the Apache License, Version 2.0 (the "License");
5+
// you may not use this file except in compliance with the License.
6+
// You may obtain a copy of the License at
7+
//
8+
// http://www.apache.org/licenses/LICENSE-2.0
9+
//
10+
// Unless required by applicable law or agreed to in writing, software
11+
// distributed under the License is distributed on an "AS IS" BASIS,
12+
// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
13+
// See the License for the specific language governing permissions and
14+
// limitations under the License.
15+
16+
//go:build !windows
17+
18+
package cmd
19+
20+
import "syscall"
21+
22+
// detachSysProcAttr puts the telemetry child in a new session, which detaches it from the
23+
// controlling terminal and takes it out of the parent's process group. That is what keeps
24+
// it alive for the second or so it needs after the parent exits: a SIGHUP on terminal
25+
// close, the shell's job control, and a CI runner killing the step's process group all
26+
// address the group the child has just left.
27+
func detachSysProcAttr() *syscall.SysProcAttr {
28+
return &syscall.SysProcAttr{Setsid: true}
29+
}
Lines changed: 37 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,37 @@
1+
//
2+
// Copyright 2026 The Chainloop Authors.
3+
//
4+
// Licensed under the Apache License, Version 2.0 (the "License");
5+
// you may not use this file except in compliance with the License.
6+
// You may obtain a copy of the License at
7+
//
8+
// http://www.apache.org/licenses/LICENSE-2.0
9+
//
10+
// Unless required by applicable law or agreed to in writing, software
11+
// distributed under the License is distributed on an "AS IS" BASIS,
12+
// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
13+
// See the License for the specific language governing permissions and
14+
// limitations under the License.
15+
16+
//go:build windows
17+
18+
package cmd
19+
20+
import "syscall"
21+
22+
// detachedProcess is CREATE_NEW_PROCESS_GROUP's companion flag, DETACHED_PROCESS, which
23+
// the syscall package does not define. It is spelled out here rather than pulled from
24+
// golang.org/x/sys/windows so that module stays an indirect dependency instead of becoming
25+
// a direct one for the sake of a single constant.
26+
// https://learn.microsoft.com/en-us/windows/win32/procthread/process-creation-flags
27+
const detachedProcess = 0x00000008
28+
29+
// detachSysProcAttr gives the telemetry child its own process group and no console, so a
30+
// Ctrl-C in the parent's console and the console's teardown do not reach it. Windows is
31+
// not a release target for the CLI, so this is best effort: it keeps `go install` builds
32+
// working and behaving sensibly rather than being tuned for it.
33+
func detachSysProcAttr() *syscall.SysProcAttr {
34+
return &syscall.SysProcAttr{
35+
CreationFlags: syscall.CREATE_NEW_PROCESS_GROUP | detachedProcess,
36+
}
37+
}

0 commit comments

Comments
 (0)