Which jobs are failing?

The recent builds fail on each main commit: https://copr.fedorainfracloud.org/coprs/rhcontainerbot/podman-next/build/4788630/

Which tests are failing?

Every copr build on main

Since when has it been failing?

I don't think they ever worked.

Reason for failure (if possible)

No response

Anything else we need to know?

No response

cc @rphillips @lsm5

We're already using the tracing crate, which has support for Open Telemetry (OTEL) as well: https://github.com/tokio-rs/tracing/tree/master/tracing-opentelemetry

Using the crate would probably incorporate adding those, too:

• https://docs.rs/opentelemetry
• https://docs.rs/opentelemetry-jaeger

Independently how we wanna use it from a configuration perspective, having OTEL support would increase the observability of the runtime stack (together with CRI-O) by gaining much more insights about what is going on in conmon-rs.

What type of PR is this?

/kind bug

What this PR does / why we need it:

The conformance CRI test does not stop the running container after checking its output. It expects that the connection gets dropped when there is no more input to read. We now adjust the current attach behavior to stop in that case, which hopefully does not break the Podman use case.

See: https://github.com/kubernetes-sigs/cri-tools/blob/909f652/pkg/validate/streaming.go#L266-L305

We also strip down the size of the data packets to return the right amount of received bytes in the client.

A debug message has been changed which correctly logs the amount of written packets.

Which issue(s) this PR fixes:

None

Special notes for your reviewer:

None

Does this PR introduce a user-facing change?

Fixed critest "runtime should support attach" test.

What type of PR is this?

/kind ci

What this PR does / why we need it:

I also refactored some logs to automatically trace the PID as well as sanitized them.

Which issue(s) this PR fixes:

None

Special notes for your reviewer:

The new test cases:

ConmonClient CreateContainer
  should catch out of memory (oom) events with terminal
  /home/runner/work/conmon-rs/conmon-rs/pkg/client/client_test.go:135
2022-05-13T09:09:27.337145Z  INFO conmon::server: 166: Received SIGINT
2022-05-13T09:09:27.338161Z  INFO conmon::server: 120: Using stdout logger
2022-05-13T09:09:27.338182Z  INFO conmon::server: 130: Set log level to: debug
2022-05-13T09:09:27.339977Z DEBUG conmon::rpc: 50: Got a version request
2022-05-13T09:09:27.340533Z DEBUG create_container{container_id="e388beccf6761109b0a3b850199f6311ca34ca3fdb671c783aafe1540d0db0cf" uuid="4d244a31-43be-4081-9884-765931e0b45f"}: conmon::rpc: 74: Got a create container request
2022-05-13T09:09:27.340586Z DEBUG create_container{container_id="e388beccf6761109b0a3b850199f6311ca34ca3fdb671c783aafe1540d0db0cf" uuid="4d244a31-43be-4081-9884-765931e0b45f"}: conmon::terminal: 61: Creating new terminal
2022-05-13T09:09:27.340716Z DEBUG create_container{container_id="e388beccf6761109b0a3b850199f6311ca34ca3fdb671c783aafe1540d0db0cf" uuid="4d244a31-43be-4081-9884-765931e0b45f"}:listen: conmon::terminal: 137: Listening terminal socket on /tmp/conmon-term-1Xxeio4.sock
2022-05-13T09:09:27.340936Z DEBUG create_container{container_id="e388beccf6761109b0a3b850199f6311ca34ca3fdb671c783aafe1540d0db0cf" uuid="4d244a31-43be-4081-9884-765931e0b45f"}: conmon::rpc: 83: PID file is /tmp/conmon-client4[275](https://github.com/containers/conmon-rs/runs/6420332913?check_suite_focus=true#step:11:275)970848/pidfile
2022-05-13T09:09:27.340954Z DEBUG create_container{container_id="e388beccf6761109b0a3b850199f6311ca34ca3fdb671c783aafe1540d0db0cf" uuid="4d244a31-43be-4081-9884-765931e0b45f"}: conmon::server: 240: Runtime args "--root=/tmp/conmon-client4275970848/root create --bundle /tmp/conmon-client4275970848 --pid-file /tmp/conmon-client4275970848/pidfile --console-socket=/tmp/conmon-term-1Xxeio4.sock e388beccf6761109b0a3b850199f6311ca34ca3fdb671c783aafe1540d0db0cf"
2022-05-13T09:09:27.340973Z DEBUG create_container{container_id="e388beccf6761109b0a3b850199f6311ca34ca3fdb671c783aafe1540d0db0cf" uuid="4d244a31-43be-4081-9884-765931e0b45f"}:promise: conmon::cri_logger: 48: Initializing CRI logger in path /tmp/conmon-client4275970848/log
2022-05-13T09:09:27.341425Z DEBUG create_container{container_id="e388beccf6761109b0a3b850199f6311ca34ca3fdb671c783aafe1540d0db0cf" uuid="4d244a31-43be-4081-9884-765931e0b45f"}:promise: conmon::terminal: 100: Waiting for terminal socket connection
2022-05-13T09:09:27.348721Z DEBUG create_container{container_id="e388beccf6761109b0a3b850199f6311ca34ca3fdb671c783aafe1540d0db0cf" uuid="4d244a31-43be-4081-9884-765931e0b45f"}:listen: conmon::terminal: 151: Got terminal socket stream: PollEvented { io: Some(UnixStream { fd: FileDesc(OwnedFd { fd: 13 }), local: "/proc/self/fd/11/conmon-term-1Xxeio4.sock" (pathname), peer: (unnamed) }) }
2022-05-13T09:09:27.375075Z DEBUG create_container{container_id="e388beccf6761109b0a3b850199f6311ca34ca3fdb671c783aafe1540d0db0cf" uuid="4d244a31-43be-4081-9884-765931e0b45f"}:listen: conmon::terminal: 174: Removing socket path /tmp/conmon-term-1Xxeio4.sock
2022-05-13T09:09:27.375199Z DEBUG create_container{container_id="e388beccf6761109b0a3b850199f6311ca34ca3fdb671c783aafe1540d0db0cf" uuid="4d244a31-43be-4081-9884-765931e0b45f"}:listen: conmon::terminal: 177: Shutting down receiver stream
2022-05-13T09:09:27.375214Z DEBUG create_container{container_id="e388beccf6761109b0a3b850199f6311ca34ca3fdb671c783aafe1540d0db0cf" uuid="4d244a31-43be-4081-9884-765931e0b45f"}:listen: conmon::terminal: 185: Received terminal file descriptor
2022-05-13T09:09:27.375221Z DEBUG create_container{container_id="e388beccf6761109b0a3b850199f6311ca34ca3fdb671c783aafe1540d0db0cf" uuid="4d244a31-43be-4081-9884-765931e0b45f"}:listen: conmon::terminal: 188: Changing terminal settings
2022-05-13T09:09:27.375260Z DEBUG create_container{container_id="e388beccf6761109b0a3b850199f6311ca34ca3fdb671c783aafe1540d0db0cf" uuid="4d244a31-43be-4081-9884-765931e0b45f"}:listen: conmon::terminal: 226: Shutting down listener thread
2022-05-13T09:09:28.298365Z DEBUG create_container{container_id="e388beccf6761109b0a3b850199f6311ca34ca3fdb671c783aafe1540d0db0cf" uuid="4d244a31-43be-4081-9884-765931e0b45f"}:promise:watch{pid=6017}:task:oom_handling_cgroup_v1{pid=6017}: conmon::oom_watcher: 309: Using cgroup path: /proc/6017/cgroup
2022-05-13T09:09:28.299439Z DEBUG create_container{container_id="e388beccf6761109b0a3b850199f6311ca34ca3fdb671c783aafe1540d0db0cf" uuid="4d244a31-43be-4081-9884-765931e0b45f"}:promise:watch{pid=6017}:task: conmon::oom_watcher: 94: Setup cgroup v1 oom handling path="/sys/fs/cgroup/memory/system.slice/runner-provisioner.service/e388beccf6761109b0a3b850199f6311ca34ca3fdb671c783aafe1540d0db0cf/memory.oom_control"
2022-05-13T09:09:28.300149Z DEBUG create_container{container_id="e388beccf6761109b0a3b850199f6311ca34ca3fdb671c783aafe1540d0db0cf" uuid="4d244a31-43be-4081-9884-765931e0b45f"}:promise:watch{pid=6017}:task: conmon::oom_watcher: 121: Successfully setup cgroup v1 oom detection
Waiting for OOM exit path to exist
Waiting for OOM exit path to exist
Waiting for OOM exit path to exist
Waiting for OOM exit path to exist
2022-05-13T09:09:31.669855Z DEBUG create_container{container_id="e388beccf6761109b0a3b850199f6311ca34ca3fdb671c783aafe1540d0db0cf" uuid="4d244a31-43be-4081-9884-765931e0b45f"}:promise:watch{pid=6017}:task: conmon::oom_watcher: 132: Got oom event
2022-05-13T09:09:31.669896Z DEBUG create_container{container_id="e388beccf6761109b0a3b850199f6311ca34ca3fdb671c783aafe1540d0db0cf" uuid="4d244a31-43be-4081-9884-765931e0b45f"}:promise:watch{pid=6017}:task:write_oom_file: conmon::oom_watcher: [276](https://github.com/containers/conmon-rs/runs/6420332913?check_suite_focus=true#step:11:276): Writing OOM file: /tmp/conmon-client4275970848/oom_exit
2022-05-13T09:09:31.670044Z DEBUG create_container{container_id="e388beccf6761109b0a3b850199f6311ca34ca3fdb671c783aafe1540d0db0cf" uuid="4d244a31-43be-4081-9884-765931e0b45f"}:promise:watch{pid=6017}:task: conmon::oom_watcher: 136: Successfully wrote oom files
2022-05-13T09:09:31.670054Z DEBUG create_container{container_id="e388beccf6761109b0a3b850199f6311ca34ca3fdb671c783aafe1540d0db0cf" uuid="4d244a31-43be-4081-9884-765931e0b45f"}:promise:watch{pid=6017}:task: conmon::oom_watcher: 144: Done watching for ooms
VmRSS for server is 196
2022-05-13T09:09:32.427510Z DEBUG create_container{container_id="e388beccf6761109b0a3b850199f6311ca34ca3fdb671c783aafe1540d0db0cf" uuid="4d244a31-43be-4081-9884-765931e0b45f"}:promise:watch{pid=6017}:wait_for_exit_code: conmon::child_reaper: 332: Signaled
2022-05-13T09:09:32.4[277](https://github.com/containers/conmon-rs/runs/6420332913?check_suite_focus=true#step:11:277)99Z DEBUG create_container{container_id="e388beccf6761109b0a3b850199f6311ca34ca3fdb671c783aafe1540d0db0cf" uuid="4d244a31-43be-4081-9884-765931e0b45f"}:listen:read_loop: conmon::container_io: 245: Stopping read loop
2022-05-13T09:09:32.428445Z DEBUG create_container{container_id="e388beccf6761109b0a3b850199f6311ca34ca3fdb671c783aafe1540d0db0cf" uuid="4d244a31-43be-4081-9884-765931e0b45f"}:promise:watch{pid=6017}: conmon::child_reaper: 293: Sending exit struct to channel: ExitChannelData { exit_code: 137, oomed: true, timed_out: false }
2022-05-13T09:09:32.428880Z DEBUG create_container{container_id="e388beccf6761109b0a3b850199f6311ca34ca3fdb671c783aafe1540d0db0cf" uuid="4d244a31-43be-4081-9884-765931e0b45f"}:promise:watch{pid=6017}: conmon::child_reaper: 297: Write to exit paths: /tmp/conmon-client4275970848/exit
------------------------------
• [SLOW TEST] [5.161 seconds]
ConmonClient
/home/runner/work/conmon-rs/conmon-rs/pkg/client/client_test.go:20
  CreateContainer
  /home/runner/work/conmon-rs/conmon-rs/pkg/client/client_test.go:52
    should catch out of memory (oom) events with terminal
    /home/runner/work/conmon-rs/conmon-rs/pkg/client/client_test.go:135

Does this PR introduce a user-facing change?

None

Bumps tower-http from 0.3.4 to 0.3.5.

Dependabot will resolve any conflicts with this PR as long as you don't alter it yourself. You can also trigger a rebase manually by commenting @dependabot rebase.

We right now use the default logger in CRI-O, which logs to systemd. It would be good to have at least a runtime monitor configuration to also log to stdout. This allows us to collect conmon and CRI-O logs in parallel.

Q: Do we wanna make stdout logging the default? Which benefits do we gain when logging to systemd?

What type of PR is this?

/kind documentation

What this PR does / why we need it:

Which issue(s) this PR fixes:

None

Special notes for your reviewer:

We require a new CRI-O v1.25.2 to be released including the backport for conmon-rs v0.4.0: https://github.com/cri-o/cri-o/pull/6359

Does this PR introduce a user-facing change?

Added usage documentation.

What happened?

The builds fails since a couple of commits with the error message:

https://download.copr.fedorainfracloud.org/results/rhcontainerbot/podman-next/fedora-35-i386/04836395-conmon-rs/root.log.gz

DEBUG util.py:445:  No match for argument: golang-1.18.6-1.fc35.i386
DEBUG util.py:443:  Error: Unable to find a match: golang-1.18.6-1.fc35.i386

What did you expect to happen?

The build should work like the other ones.

How can we reproduce it (as minimally and precisely as possible)?

Mostly on every recent commit on https://copr.fedorainfracloud.org/coprs/rhcontainerbot/podman-next/package/conmon-rs/

Anything else we need to know?

No response

conmon-rs version

$ conmonrs --version
# paste output here

OS version

# On Linux:
$ cat /etc/os-release
# paste output here
$ uname -a
# paste output here

Additional environment details (AWS, VirtualBox, physical, etc.)

What happened?

We print the active goroutines after each integration test. It looks like that the util.CopyDetachable still leaves a running goroutine open:

2022-07-20T14:16:05.7893221Z 2 @ 0x44c076 0x45d112 0x4b882e 0x4b92e5 0x654416 0x6dc739 0x47dfc1
2022-07-20T14:16:05.7893648Z #	0x4b882d	io.(*pipe).read+0x14d										/opt/hostedtoolcache/go/1.18.4/x64/src/io/pipe.go:57
2022-07-20T14:16:05.7894140Z #	0x4b92e4	io.(*PipeReader).Read+0x64									/opt/hostedtoolcache/go/1.18.4/x64/src/io/pipe.go:136
2022-07-20T14:16:05.7895004Z #	0x654415	github.com/containers/common/pkg/util.CopyDetachable+0xb5					/home/runner/go/pkg/mod/github.com/containers/[email protected]/pkg/util/copy.go:16
2022-07-20T14:16:05.7895944Z #	0x6dc738	github.com/containers/conmon-rs/pkg/client.(*ConmonClient).setupStdioChannels.func2+0xb8	/home/runner/work/conmon-rs/conmon-rs/pkg/client/attach.go:201

https://github.com/containers/conmon-rs/blob/13d4828464b72d0c734643c5ce405dbb60fbb6fe/pkg/client/attach.go#L198-L204

We should find a way to cleanup the goroutine on server shutdown as well.

What did you expect to happen?

No running goroutines for attach after the integration tests.

How can we reproduce it (as minimally and precisely as possible)?

Running the integration tests reveals the issue by printing the goroutines at the end.

Anything else we need to know?

No

conmon-rs version

$ conmonrs --version
version: 0.1.0-dev
tag: none
commit: 68252d0373b8e262bdf7ff8780fb2b5ab6f66c29
build: 2022-07-20 14:13:13 +00:00
rustc 1.62.1 (e092d0b6b 2022-07-16)

OS version

Not relevant

Additional environment details (AWS, VirtualBox, physical, etc.)

No

What type of PR is this?

/kind cleanup

What this PR does / why we need it:

We now apply a bunch of rules, for example:

• Start logs upper case
• Remove redundant information like the PID (already part of the tracing span)
• Do not print "Error" for error logs, since the level already tells us that it's an error.

Which issue(s) this PR fixes:

None

Special notes for your reviewer:

None

Does this PR introduce a user-facing change?

None

We disconnect the stdout/err streams from conmon at a certain point of execution. Therefore it would make more sense to log to a dedicated driver instead of those streams. We now add a --log-driver option as well as a default systemd logger.

Bumps shadow-rs from 0.16.1 to 0.20.0.

Dependabot will resolve any conflicts with this PR as long as you don't alter it yourself. You can also trigger a rebase manually by commenting @dependabot rebase.

Bumps serde from 1.0.149 to 1.0.152.

Dependabot will resolve any conflicts with this PR as long as you don't alter it yourself. You can also trigger a rebase manually by commenting @dependabot rebase.

Bumps capnproto.org/go/capnp/v3 from 3.0.0-alpha.9 to 3.0.0-alpha.17.

Dependabot will resolve any conflicts with this PR as long as you don't alter it yourself. You can also trigger a rebase manually by commenting @dependabot rebase.

Bumps syn from 1.0.105 to 1.0.107.

Dependabot will resolve any conflicts with this PR as long as you don't alter it yourself. You can also trigger a rebase manually by commenting @dependabot rebase.

Bumps itoa from 1.0.4 to 1.0.5.

Dependabot will resolve any conflicts with this PR as long as you don't alter it yourself. You can also trigger a rebase manually by commenting @dependabot rebase.

Bumps link-cplusplus from 1.0.7 to 1.0.8.

Dependabot will resolve any conflicts with this PR as long as you don't alter it yourself. You can also trigger a rebase manually by commenting @dependabot rebase.