Skip to content

Commit 27e6b48

Browse files
ostermanclaude
andcommitted
Add trace logging for all squelched errors
Audit and update all instances where errors are intentionally ignored (squelched) to include log.Trace() calls. This ensures no errors are silently lost and provides complete error visibility during debugging. 🤖 Generated with [Claude Code](https://claude.com/claude-code) Co-Authored-By: Claude <[email protected]>
1 parent f69c0b4 commit 27e6b48

File tree

21 files changed

+378
-42
lines changed

21 files changed

+378
-42
lines changed

cmd/auth.go

Lines changed: 14 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -3,6 +3,8 @@ package cmd
33
import (
44
"github.com/spf13/cobra"
55
"github.com/spf13/viper"
6+
7+
log "github.com/cloudposse/atmos/pkg/logger"
68
)
79

810
const (
@@ -25,10 +27,18 @@ func init() {
2527
authCmd.PersistentFlags().String(ProfileFlagName, "", "Specify the profile to use for authentication.")
2628
authCmd.PersistentFlags().StringP(IdentityFlagName, "i", "", "Specify the target identity to assume.")
2729
// Bind to Viper and env (flags > env > config > defaults).
28-
_ = viper.BindEnv(ProfileFlagName, "ATMOS_PROFILE", "PROFILE")
29-
_ = viper.BindEnv(IdentityFlagName, "ATMOS_IDENTITY", "IDENTITY")
30-
_ = viper.BindPFlag(ProfileFlagName, authCmd.PersistentFlags().Lookup(ProfileFlagName))
31-
_ = viper.BindPFlag(IdentityFlagName, authCmd.PersistentFlags().Lookup(IdentityFlagName))
30+
if err := viper.BindEnv(ProfileFlagName, "ATMOS_PROFILE", "PROFILE"); err != nil {
31+
log.Trace("Failed to bind profile environment variables", "error", err)
32+
}
33+
if err := viper.BindEnv(IdentityFlagName, "ATMOS_IDENTITY", "IDENTITY"); err != nil {
34+
log.Trace("Failed to bind identity environment variables", "error", err)
35+
}
36+
if err := viper.BindPFlag(ProfileFlagName, authCmd.PersistentFlags().Lookup(ProfileFlagName)); err != nil {
37+
log.Trace("Failed to bind profile flag", "error", err)
38+
}
39+
if err := viper.BindPFlag(IdentityFlagName, authCmd.PersistentFlags().Lookup(IdentityFlagName)); err != nil {
40+
log.Trace("Failed to bind identity flag", "error", err)
41+
}
3242

3343
RootCmd.AddCommand(authCmd)
3444
}

cmd/auth_env.go

Lines changed: 14 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -12,6 +12,7 @@ import (
1212

1313
errUtils "github.com/cloudposse/atmos/errors"
1414
cfg "github.com/cloudposse/atmos/pkg/config"
15+
log "github.com/cloudposse/atmos/pkg/logger"
1516
"github.com/cloudposse/atmos/pkg/schema"
1617
u "github.com/cloudposse/atmos/pkg/utils"
1718
)
@@ -121,13 +122,21 @@ func outputEnvAsDotenv(envVars map[string]string) error {
121122

122123
func init() {
123124
authEnvCmd.Flags().StringP("format", "f", "bash", "Output format: bash, json, dotenv.")
124-
_ = viper.BindEnv("auth_env_format", "ATMOS_AUTH_ENV_FORMAT")
125-
_ = viper.BindPFlag("auth_env_format", authEnvCmd.Flags().Lookup("format"))
126-
_ = authEnvCmd.RegisterFlagCompletionFunc("format", func(cmd *cobra.Command, args []string, toComplete string) ([]string, cobra.ShellCompDirective) {
125+
if err := viper.BindEnv("auth_env_format", "ATMOS_AUTH_ENV_FORMAT"); err != nil {
126+
log.Trace("Failed to bind auth_env_format environment variable", "error", err)
127+
}
128+
if err := viper.BindPFlag("auth_env_format", authEnvCmd.Flags().Lookup("format")); err != nil {
129+
log.Trace("Failed to bind auth_env_format flag", "error", err)
130+
}
131+
if err := authEnvCmd.RegisterFlagCompletionFunc("format", func(cmd *cobra.Command, args []string, toComplete string) ([]string, cobra.ShellCompDirective) {
127132
return SupportedFormats, cobra.ShellCompDirectiveNoFileComp
128-
})
133+
}); err != nil {
134+
log.Trace("Failed to register format flag completion", "error", err)
135+
}
129136

130-
_ = viper.BindPFlag("identity", authCmd.PersistentFlags().Lookup("identity"))
137+
if err := viper.BindPFlag("identity", authCmd.PersistentFlags().Lookup("identity")); err != nil {
138+
log.Trace("Failed to bind identity flag", "error", err)
139+
}
131140
viper.MustBindEnv("identity", "ATMOS_IDENTITY")
132141
authCmd.AddCommand(authEnvCmd)
133142
}

cmd/auth_validate.go

Lines changed: 7 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -8,6 +8,7 @@ import (
88

99
"github.com/cloudposse/atmos/pkg/auth/validation"
1010
cfg "github.com/cloudposse/atmos/pkg/config"
11+
log "github.com/cloudposse/atmos/pkg/logger"
1112
"github.com/cloudposse/atmos/pkg/schema"
1213
u "github.com/cloudposse/atmos/pkg/utils"
1314
)
@@ -52,8 +53,12 @@ func executeAuthValidateCommand(cmd *cobra.Command, args []string) error {
5253

5354
func init() {
5455
authValidateCmd.Flags().BoolP("verbose", "v", false, "Enable verbose output")
55-
_ = viper.BindPFlag("auth.validate.verbose", authValidateCmd.Flags().Lookup("verbose"))
56+
if err := viper.BindPFlag("auth.validate.verbose", authValidateCmd.Flags().Lookup("verbose")); err != nil {
57+
log.Trace("Failed to bind auth.validate.verbose flag", "error", err)
58+
}
5659
viper.SetEnvPrefix("ATMOS")
57-
_ = viper.BindEnv("auth.validate.verbose") // ATMOS_AUTH_VALIDATE_VERBOSE
60+
if err := viper.BindEnv("auth.validate.verbose"); err != nil {
61+
log.Trace("Failed to bind auth.validate.verbose environment variable", "error", err)
62+
}
5863
authCmd.AddCommand(authValidateCmd)
5964
}

cmd/auth_whoami.go

Lines changed: 7 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -14,6 +14,7 @@ import (
1414
authTypes "github.com/cloudposse/atmos/pkg/auth/types"
1515
cfg "github.com/cloudposse/atmos/pkg/config"
1616
"github.com/cloudposse/atmos/pkg/config/homedir"
17+
log "github.com/cloudposse/atmos/pkg/logger"
1718
"github.com/cloudposse/atmos/pkg/schema"
1819
)
1920

@@ -152,7 +153,11 @@ func sanitizeEnvMap(in map[string]string, homeDir string) map[string]string {
152153

153154
func init() {
154155
authWhoamiCmd.Flags().StringP("output", "o", "", "Output format (json)")
155-
_ = viper.BindPFlag("auth.whoami.output", authWhoamiCmd.Flags().Lookup("output"))
156-
_ = viper.BindEnv("auth.whoami.output", "ATMOS_AUTH_WHOAMI_OUTPUT")
156+
if err := viper.BindPFlag("auth.whoami.output", authWhoamiCmd.Flags().Lookup("output")); err != nil {
157+
log.Trace("Failed to bind auth.whoami.output flag", "error", err)
158+
}
159+
if err := viper.BindEnv("auth.whoami.output", "ATMOS_AUTH_WHOAMI_OUTPUT"); err != nil {
160+
log.Trace("Failed to bind auth.whoami.output environment variable", "error", err)
161+
}
157162
authCmd.AddCommand(authWhoamiCmd)
158163
}

cmd/cmd_utils.go

Lines changed: 3 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -291,7 +291,9 @@ func preCustomCommand(
291291

292292
// no "steps" means a sub command should be specified
293293
if len(commandConfig.Steps) == 0 {
294-
_ = cmd.Help()
294+
if err := cmd.Help(); err != nil {
295+
log.Trace("Failed to display command help", "error", err, "command", cmd.Name())
296+
}
295297
errUtils.Exit(0)
296298
}
297299
}

cmd/root.go

Lines changed: 7 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -234,8 +234,13 @@ func setupLogger(atmosConfig *schema.AtmosConfiguration) {
234234
func cleanupLogFile() {
235235
if logFileHandle != nil {
236236
// Flush any remaining log data before closing.
237-
_ = logFileHandle.Sync()
238-
_ = logFileHandle.Close()
237+
if err := logFileHandle.Sync(); err != nil {
238+
// Don't use logger here as we're cleaning up the log file
239+
fmt.Fprintf(os.Stderr, "Warning: failed to sync log file: %v\n", err)
240+
}
241+
if err := logFileHandle.Close(); err != nil {
242+
fmt.Fprintf(os.Stderr, "Warning: failed to close log file: %v\n", err)
243+
}
239244
logFileHandle = nil
240245
}
241246
}

cmd/validate_editorconfig.go

Lines changed: 3 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -73,7 +73,9 @@ func initializeConfig(cmd *cobra.Command) {
7373
}
7474
}
7575

76-
_ = currentConfig.Parse()
76+
if err := currentConfig.Parse(); err != nil {
77+
log.Trace("Failed to parse EditorConfig configuration", "error", err, "paths", configPaths)
78+
}
7779

7880
if tmpExclude != "" {
7981
currentConfig.Exclude = append(currentConfig.Exclude, tmpExclude)

docs/logging.md

Lines changed: 110 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -19,7 +19,7 @@ Atmos provides `utils.PrintfMessageToTUI` for writing TextUI messages. It always
1919

2020
### Trace
2121

22-
**Purpose**: Execution flow tracing and detailed debugging.
22+
**Purpose**: Execution flow tracing, detailed debugging, and squelched error logging.
2323

2424
#### When to Use
2525

@@ -29,6 +29,7 @@ Atmos provides `utils.PrintfMessageToTUI` for writing TextUI messages. It always
2929
- Loop iterations in complex algorithms.
3030
- Template expansion steps.
3131
- Detailed state at each step of multi-stage operations.
32+
- **Squelched errors** - errors that are intentionally ignored but should be recorded.
3233

3334
#### Characteristics
3435

@@ -43,6 +44,9 @@ Atmos provides `utils.PrintfMessageToTUI` for writing TextUI messages. It always
4344
- "Entering ProcessStackConfig with stack=dev, component=vpc"
4445
- "Template evaluation: input={...}, context={...}, output={...}"
4546
- "Cache lookup: key=stack-dev-vpc, found=true, age=2.3s"
47+
- "Failed to close temporary file during cleanup" (squelched error)
48+
- "Failed to remove temporary directory during cleanup" (squelched error)
49+
- "Failed to bind environment variable" (squelched error)
4650

4751
---
4852

@@ -183,6 +187,111 @@ Even these examples are borderline - they could arguably be Debug or Warning dep
183187

184188
---
185189

190+
## Squelched Errors
191+
192+
### What Are Squelched Errors?
193+
194+
Squelched errors are errors that are intentionally ignored because they don't affect the critical path of execution. Common examples include:
195+
- Cleanup operations (removing temporary files, closing file handles)
196+
- Non-critical configuration binding (environment variables, flags)
197+
- Resource unlocking in defer statements
198+
- UI rendering errors
199+
200+
### When to Squelch Errors
201+
202+
Errors should only be squelched when:
203+
1. **The error is non-critical** - failure doesn't prevent the operation from succeeding
204+
2. **Recovery is impossible** - we're in cleanup/defer code where we can't do anything about the error
205+
3. **The operation is best-effort** - like optional environment variable binding
206+
207+
### The Golden Rule: Always Log Squelched Errors
208+
209+
Even when errors are intentionally ignored, they **must** be logged at Trace level. This ensures errors are never truly lost and can be investigated during debugging.
210+
211+
### Pattern: Squelched Error Logging
212+
213+
**Wrong**: Silent error squelching
214+
```go
215+
// ❌ WRONG: Error is completely lost
216+
_ = os.Remove(tempFile)
217+
_ = file.Close()
218+
_ = viper.BindEnv("OPTIONAL_VAR", "VAR")
219+
```
220+
221+
**Right**: Log squelched errors at Trace level
222+
```go
223+
// ✅ CORRECT: Cleanup with trace logging
224+
if err := os.Remove(tempFile); err != nil && !os.IsNotExist(err) {
225+
log.Trace("Failed to remove temporary file during cleanup", "error", err, "file", tempFile)
226+
}
227+
228+
// ✅ CORRECT: Resource closing with trace logging
229+
if err := file.Close(); err != nil {
230+
log.Trace("Failed to close file", "error", err, "file", file.Name())
231+
}
232+
233+
// ✅ CORRECT: Non-critical configuration with trace logging
234+
if err := viper.BindEnv("OPTIONAL_VAR", "VAR"); err != nil {
235+
log.Trace("Failed to bind environment variable", "error", err, "var", "OPTIONAL_VAR")
236+
}
237+
```
238+
239+
### Special Cases
240+
241+
#### Defer Statements
242+
When squelching errors in defer statements, capture them in a closure:
243+
244+
```go
245+
defer func() {
246+
if err := lock.Unlock(); err != nil {
247+
log.Trace("Failed to unlock", "error", err, "path", lockPath)
248+
}
249+
}()
250+
```
251+
252+
#### File Existence Checks
253+
When removing files, check for `os.IsNotExist` to avoid logging expected conditions:
254+
255+
```go
256+
if err := os.Remove(tempFile); err != nil && !os.IsNotExist(err) {
257+
log.Trace("Failed to remove file", "error", err, "file", tempFile)
258+
}
259+
```
260+
261+
#### Log File Cleanup
262+
When cleaning up log files, use stderr instead of the logger to avoid recursion:
263+
264+
```go
265+
func cleanupLogFile() {
266+
if logFileHandle != nil {
267+
if err := logFileHandle.Sync(); err != nil {
268+
// Don't use logger here as we're cleaning up the log file
269+
fmt.Fprintf(os.Stderr, "Warning: failed to sync log file: %v\n", err)
270+
}
271+
}
272+
}
273+
```
274+
275+
### Why This Matters
276+
277+
1. **Debugging**: When investigating issues, trace logs reveal the full story, including non-critical failures
278+
2. **Metrics**: Aggregate trace logs to identify patterns (e.g., frequent cleanup failures might indicate disk issues)
279+
3. **Auditing**: Complete error trail for compliance and security reviews
280+
4. **Transparency**: No hidden errors - everything is recorded somewhere
281+
282+
### Common Squelched Error Categories
283+
284+
| Category | Examples | Trace Logging Required |
285+
|----------|----------|----------------------|
286+
| File cleanup | `os.Remove()`, `os.RemoveAll()` | ✅ Yes |
287+
| Resource closing | `file.Close()`, `client.Close()` | ✅ Yes |
288+
| Lock operations | `lock.Unlock()` | ✅ Yes |
289+
| Config binding | `viper.BindEnv()`, `viper.BindPFlag()` | ✅ Yes |
290+
| UI rendering | `fmt.Fprint()` to UI buffers | ✅ Yes |
291+
| Command help | `cmd.Help()` | ✅ Yes |
292+
293+
---
294+
186295
## Common Anti-Patterns
187296

188297
### Using Logging as UI

0 commit comments

Comments
 (0)