Print log write errors to stderr rather than stdout #216

ysndr · 2024-08-07T14:21:15Z

Currently the write error message emitted by process-compose process logs --tail is indistinguishable from actual log output coming from the process.

processes:
  never_exit:
    command: sleep infinity
  foo:
    command: |
      echo 1
      echo 2
      echo 3

will log as:

$ process-compose process logs -u test.sock -n 2 foo 2>/dev/null
2
3
write close: write unix ->test.sock: write: broken pipe

This change will make it so that write close: write unix ->test.sock: write: broken pipe would be printed to stderr, i.e. the same command as above would log as:

$ process-compose process logs -u test.sock -n 2 foo 2>/dev/null
2
3

Currently the write error message emitted by `process-compose process logs --tail` is indistinguishable from actual log output coming from the process. ```yaml processes: never_exit: command: sleep infinity foo: command: | echo 1 echo 2 echo 3 ``` will log as: ``` $ process-compose process logs -u test.sock -n 2 foo 2>/dev/null 2 3 write close: write unix ->test.sock: write: broken pipe ``` This change will make it so that `write close: write unix ->test.sock: write: broken pipe` would be printed to stderr, i.e. the same command as above would log as: ``` $ process-compose process logs -u test.sock -n 2 foo 2>/dev/null 2 3 ```

sonarqubecloud · 2024-08-07T14:21:33Z

Quality Gate passed

Issues
0 New issues
0 Accepted issues

Measures
0 Security Hotspots
0.0% Coverage on New Code
0.0% Duplication on New Code

See analysis details on SonarCloud

Allows to start a reader that reads from a `process-compose process logs --tail <n>` process that we expect to quit after at most `<n>` logged lines. Empirically, process-compose will * log the last _up to_ `<n>` lines logged by a process * exit with `0` exit code * not wait for more logs of running processes, even if they logged less than `<n>` lines yet * print a particular error message to `stderr`: $ process-compose process logs -u test.sock -n 2 foo 2>/dev/null 2 3 write close: write unix ->test.sock: write: broken pipe Currently we use this as another cue that the reading completed, however we cannot know whether this was printed by process compose or a running service. A PR to banish these logs to stderr was opened upstream at <F1bonacc1/process-compose#216>

Empirically, process-compose will * log the last _up to_ `<n>` lines logged by a process * exit with `0` exit code * not wait for more logs of running processes, even if they logged less than `<n>` lines yet * print a particular error message to `stderr`: $ process-compose process logs -u test.sock -n 2 foo 2>/dev/null 2 3 write close: write unix ->test.sock: write: broken pipe Currently we use this as another cue that the reading completed, however we cannot know whether this was printed by process compose or a running service. A PR to banish these logs to stderr was opened upstream at <F1bonacc1/process-compose#216> This adds a new `ProcessComposeLogTail` that calls `process-compose process logs` with `--tail` and directly reads its output, storing all lines in a vector. Because log lines are currently not timestamped, we can only meaningfully provide tail logs for a single process. Thus the complexity of the multiplexed readers we need for streaming logs can be sidestepped here, with an independent reading implementation and `Command::output`.

F1bonacc1

LGTM
Thanks

## Proposed Changes ### feat: impl ProcessComposeLogTail to read logs with --tail Empirically, process-compose will * log the last _up to_ `<n>` lines logged by a process * exit with `0` exit code * not wait for more logs of running processes, even if they logged less than `<n>` lines yet * print a particular error message to `stderr`: ``` $ process-compose process logs -u test.sock -n 2 foo 2>/dev/null 2 3 write close: write unix ->test.sock: write: broken pipe ``` Currently we use this as another cue that the reading completed, however we cannot know whether this was printed by process compose or a running service. A PR to banish these logs to stderr was opened upstream at <F1bonacc1/process-compose#216> This adds a new `ProcessComposeLogTail` that calls `process-compose process logs` with `--tail` and directly reads its output, storing all lines in a vector. Because log lines are currently not timestamped, we can only meaningfully provide tail logs for a single process. Thus the complexity of the multiplexed readers we need for streaming logs can be sidestepped here, with an independent reading implementation and `Command::output`. ### feat: allow configuring tail for log streams and add `--tail` flag This is a convenience enabled by recent process-compose updates. By default, `process-compose process logs --follow` will _also_ print the entirety of the currently buffered lines for the logged process. Since that can be a few, we provide the same `--tail`/`-n` flag we would like for non following logs, to following logs as well. My memory tells me that previously `process-compose` ignored `-n` when `--follow` was provided. This also ensures that the interface for following and non-following logs is closer. ### feat: impl one shot log for single processes Implement the currently stubbed out branch of `!self.follow`. Ensure that only a single service name was provided and that the service indeed exists. Without the latter check, we would ask `process-compose` for logs of a non-existent service, which would block indefinitely without output. ### test: add `logs` integration tests * Test service name arg handling for oneshot logs and `--follow` Oneshot logs require exactly one argument while with `--follow` multiple logs can be specified, or omitted to default to all processes. * Test whether without `--follow`, `logs` exits by itself and does not wait for the service to finish or produce more logs. More detailed tests are found in the respective unit tests for `ProcessComposeLogTail`. Apparently `process-compose` blocks for another second or so after printing logs almost instantaneously. We heuristically account for that with a timeout. * Test that --follows waits for logs and keeps receiving new lines. Wrapping these calls in a `timeout` to ensure they are being killed as they would otherwise run indefinitely.

Empirically, process-compose will * log the last _up to_ `<n>` lines logged by a process * exit with `0` exit code * not wait for more logs of running processes, even if they logged less than `<n>` lines yet * print a particular error message to `stderr`: $ process-compose process logs -u test.sock -n 2 foo 2>/dev/null 2 3 write close: write unix ->test.sock: write: broken pipe Currently we use this as another cue that the reading completed, however we cannot know whether this was printed by process compose or a running service. A PR to banish these logs to stderr was opened upstream at <F1bonacc1/process-compose#216> This adds a new `ProcessComposeLogTail` that calls `process-compose process logs` with `--tail` and directly reads its output, storing all lines in a vector. Because log lines are currently not timestamped, we can only meaningfully provide tail logs for a single process. Thus the complexity of the multiplexed readers we need for streaming logs can be sidestepped here, with an independent reading implementation and `Command::output`.

ysndr mentioned this pull request Aug 7, 2024

feat: oneshot logs/tail for flox services flox/flox#1903

Merged

F1bonacc1 approved these changes Aug 9, 2024

View reviewed changes

F1bonacc1 merged commit c3a16e8 into F1bonacc1:main Aug 9, 2024
3 checks passed

mkenigs mentioned this pull request Aug 21, 2024

Update process-compose to 1.24.0 flox/flox#1977

Open

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Print log write errors to stderr rather than stdout #216

Print log write errors to stderr rather than stdout #216

ysndr commented Aug 7, 2024

sonarqubecloud bot commented Aug 7, 2024

F1bonacc1 left a comment

Print log write errors to stderr rather than stdout #216

Print log write errors to stderr rather than stdout #216

Conversation

ysndr commented Aug 7, 2024

sonarqubecloud bot commented Aug 7, 2024

Quality Gate passed

F1bonacc1 left a comment

Choose a reason for hiding this comment