Rewrite journald LogReader and unit test it#43219
Conversation
corhere
force-pushed
the
sdjournal
branch
2 times, most recently
from
65cce27 to
4ad6604
Compare
corhere
force-pushed
the
sdjournal
branch
2 times, most recently
from
8d7d022 to
46fbcf5
Compare
|
@thaJeztah @tianon @kolyshkin @cpuguy83 @rumpl @ndeloof PTAL Note for reviewers: the sequence of commits escalates from minor refactorings up to a complete rewrite which clobbers large swathes of code touched in prior commits. I have done this to capture (a cleaned up version of) the steps I took which led up to the rewrite in git history and so that we have multiple bisection points to revert to in case I have introduced a regression. In light of this, I recommend starting by reviewing the squashed diff rather than the individual commits. |
thaJeztah
added
area/logging
status/2-code-review
kind/refactor
corhere
added
kind/enhancement
Signed-off-by: Cory Snider <[email protected]>
Ensure the package can be imported, no matter the build constratints, by adding an unconstrained doc.go containing a package statement. Signed-off-by: Cory Snider <[email protected]>
Signed-off-by: Cory Snider <[email protected]>
Signed-off-by: Cory Snider <[email protected]>
Wrap the libsystemd journal reading functionality in a more idiomatic Go API and refactor the journald logging driver's ReadLogs implementation to use the wrapper. Rewrite the parts of the ReadLogs implementation in Go which were previously implemented in C as part of the cgo preamble. Separating the business logic from the cgo minutiae should hopefully make the code more accessible to a wider audience of developers for reviewing the code and contributing improvements. The structure of the ReadLogs implementation is retained with few modifications. Any ignored errors were also ignored before the refactor; the explicit error return values afforded by the sdjournal wrapper makes this more obvious. The package github.com/coreos/go-systemd/v22/sdjournal also provides a more idiomatic Go wrapper around libsystemd. It is unsuitable for our needs as it does not expose wrappers for the sd_journal_process and sd_journal_get_fd functions. Signed-off-by: Cory Snider <[email protected]>
Careful management of the journal read pointer is sufficient to ensure that no entry is read more than once. Unit test the journald logger without requiring a running journald by using the systemd-journal-remote command to write arbitrary entries to journal files. Signed-off-by: Cory Snider <[email protected]>
Fix journald and logfile-powered (jsonfile, local) log readers incorrectly filtering out messages with timestamps < Since which were preceded by a message with a timestamp >= Since. Signed-off-by: Cory Snider <[email protected]>
Implement --follow entirely correctly for the journald log reader, such that it exits immediately upon reading back the last log message written to the journal before the logger was closed. The impossibility of doing so has been slightly exaggerated. Signed-off-by: Cory Snider <[email protected]>
thaJeztah
left a comment
thaJeztah
left a comment
There was a problem hiding this comment.
LGTM
did not look into all bits fully in-depth, but went through the commits a couple of times; looks great!
| RUN mkdir -p hack \ | ||
| && curl -o hack/dind-systemd https://raw.githubusercontent.com/AkihiroSuda/containerized-systemd/b70bac0daeea120456764248164c21684ade7d0d/docker-entrypoint.sh \ | ||
| && chmod +x hack/dind-systemd |
There was a problem hiding this comment.
./cc @AkihiroSuda (FYI - this commit adds a copy/variation of the above in hack/)
(I recall there originally was some discussion about this in #40493 (comment))
There was a problem hiding this comment.
Copying the script SGTM, but what is the modification here?
| // well-known paths and the directories named in the $PATH environment variable. | ||
| func JournalRemoteCmdPath() (string, error) { | ||
| for _, p := range cmdPaths { | ||
| if path, err := exec.LookPath(p); err == nil { |
There was a problem hiding this comment.
Wondering if (in a follow-up) we should use golang.org/x/sys/execabs for this; https://github.com/golang/sys/blob/b6088ccd6cba9272b1e5639ef2df5b5731b85abc/execabs/execabs.go#L5-L13
edit: Ignore me; this is an internal package and only for testing
| // The systemd-journal-remote command is not conventionally installed on $PATH. | ||
| // The manpage from upstream systemd lists the command as | ||
| // /usr/lib/systemd/systemd-journal-remote, but Debian installs it to | ||
| // /lib/systemd instead. |
There was a problem hiding this comment.
This is awkward. Well.. it is what it is 🤷♂️
Rewrite journald LogReader and unit test it Signed-off-by: CrazyMax <[email protected]>
6 participants
- What I did
I rewrote the journald
LogReaderusing a thin cgo wrapper around thesd_journalC API and performing all the heavy lifting in idiomatic Go code. I eliminated the need to use journal cursors to check for duplicate log messages by carefully managing the movement of the journal read pointer. The rewritten implementation passes the fullLogReadertest suite and implements the--followflag correctly and performantly. (The claim in #38859 that this is impossible was slightly exaggerated.)I fixed edge cases in the handling of
--sincewith non-monotonic message timestamps in both the journald and logfile readers and extended theLogReadersuite to regression test it.- How I did it
libsystemd's
sd_journalAPI has some known bugs around read-pointer movement. The existing implementation triggered these bugs and worked around them with brute force using cursors. I was able to work around the bugs in the reimplementation so that the read-pointer always moves where it is intended to go, no cursors required.SystemD provides a
systemd-journal-remotecommand which can be used to write arbitrary journal entries to journal files at arbitrary paths. I wrote a fakejournal.Sendwhich uses that command to write journal entries to isolated, temporary journal files which are independent from the system or user journals. This is what makes it possible to close the loop between the journal log writer, libsystemd and the journal log reader in unit tests.- How to verify it
- Description for the changelog
journaldlog driver.CONTAINER_PARTIAL_ID,CONTAINER_PARTIAL_ORDINAL,CONTAINER_PARTIAL_MESSAGE,CONTAINER_PARTIAL_LASTandIMAGE_NAMEare no longer output fromdocker logs --detailswhen using thejournaldlog driver.docker logs --sinceon containers using thejson-file,localorjournaldlog drivers if the system clock had been rolled back to before the--sincetimestamp while the container was running.- A picture of a cute animal (not mandatory but encouraged)