Synchronize logging in cmdio (#2418)

## Changes
Add mutex synchronization in cmdio logger Log() method.

## Why

Since we issue multiple calls to underlying writer, we should lock the
whole method, otherwise we can get broken messages. One that can be
easily reproduced today is

```
 hyperfine -m 100 --show-output 'go test ./acceptance -run ^TestAccept$/^bundle$/^artifacts$/^whl_multiple$ -count=1'
...
            -Uploading my_test_code-0.0.1-py3-none-any.whl...
            -Uploading my_test_code_2-0.0.1-py3-none-any.whl...
            +Uploading my_test_code-0.0.1-py3-none-any.whl...Uploading my_test_code_2-0.0.1-py3-none-any.whl...

Error: Command terminated with non-zero exit code 1 in benchmark iteration 54. Use the '-i'/'--ignore-failure' option if you want to ignore this. Alternatively, use the '--show-output' option to debug what went wrong.
```

An alternative could be to prepare a message fully in a local buffer and
write it in one call (I’m assuming underlying writer is still
synchronized). However, that’s more complicated and unclear if it’s
worth it, perf-wise.

## Tests
With this change I’m running the same hyperfine command with 1000
iterations with no failures.
This commit is contained in:
Denis Bilenko 2025-03-03 14:42:43 +01:00 committed by GitHub
parent e4cd782852
commit 5c146ca57a
No known key found for this signature in database
GPG Key ID: B5690EEEBB952194
1 changed files with 5 additions and 0 deletions

View File

@ -9,6 +9,7 @@ import (
"io"
"os"
"strings"
"sync"
"github.com/databricks/cli/libs/flags"
"github.com/manifoldco/promptui"
@ -29,6 +30,8 @@ type Logger struct {
// If true, indicates no events have been printed by the logger yet. Used
// by inplace logging for formatting
isFirstEvent bool
mutex sync.Mutex
}
func NewLogger(mode flags.ProgressLogFormat) *Logger {
@ -216,6 +219,8 @@ func (l *Logger) writeInplace(event Event) {
}
func (l *Logger) Log(event Event) {
l.mutex.Lock()
defer l.mutex.Unlock()
switch l.Mode {
case flags.ModeInplace:
if event.IsInplaceSupported() {