Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Fixes for reading journald logs #38859

Merged
merged 9 commits into from Aug 9, 2019
Merged

Fixes for reading journald logs #38859

merged 9 commits into from Aug 9, 2019

Commits on Aug 2, 2019

  1. Small journal cleanup

    Clean up a deferred function call in the journal reading logic.
    
    Signed-off-by: Nalin Dahyabhai <nalin@redhat.com>
    nalind authored and kolyshkin committed Aug 2, 2019
    Copy the full SHA
    1ada3e8 View commit details
    Browse the repository at this point in the history
  2. journald/read: simplify code

    Minor code simplification.
    
    Signed-off-by: Kir Kolyshkin <kolyshkin@gmail.com>
    kolyshkin committed Aug 2, 2019
    Copy the full SHA
    e8f6166 View commit details
    Browse the repository at this point in the history
  3. journald/read: simplify walking backwards

    In case Tail=N parameter is requested, we need to show N lines.
    It does not make sense to walk backwards one by one if we can
    do it at once. Now, if Since=T is also provided, make sure we
    haven't jumped too far (before T), and if we did, move forward.
    
    The primary motivation for this was to make the code simpler.
    
    This also fixes a tiny bug in the "since" implementation.
    
    Before this commit:
    > $ docker logs -t --tail=6000 --since="2019-03-10T03:54:25.00" $ID | head
    > 2019-03-10T03:54:24.999821000Z 95981
    
    After:
    > $ docker logs -t --tail=6000 --since="2019-03-10T03:54:25.00" $ID | head
    > 2019-03-10T03:54:25.000013000Z 95982
    
    Signed-off-by: Kir Kolyshkin <kolyshkin@gmail.com>
    kolyshkin committed Aug 2, 2019
    Copy the full SHA
    ff3cd16 View commit details
    Browse the repository at this point in the history
  4. journald/read: avoid being blocked on send

    In case the LogConsumer is gone, the code that sends the message can
    stuck forever. Wrap the code in select case, as all other loggers do.
    
    Signed-off-by: Kir Kolyshkin <kolyshkin@gmail.com>
    kolyshkin committed Aug 2, 2019
    Copy the full SHA
    7903972 View commit details
    Browse the repository at this point in the history
  5. Call sd_journal_get_fd() earlier, only if needed

    1. The journald client library initializes inotify watch(es)
    during the first call to sd_journal_get_fd(), and it make sense
    to open it earlier in order to not lose any journal file rotation
    events.
    
    2. It only makes sense to call this if we're going to use it
    later on -- so add a check for config.Follow.
    
    3. Remove the redundant call to sd_journal_get_fd().
    
    NOTE that any subsequent calls to sd_journal_get_fd() return
    the same file descriptor, so there's no real need to save it
    for later use in wait_for_data_cancelable().
    
    Based on earlier patch by Nalin Dahyabhai <nalin@redhat.com>.
    
    Signed-off-by: Kir Kolyshkin <kolyshkin@gmail.com>
    kolyshkin committed Aug 2, 2019
    Copy the full SHA
    981c016 View commit details
    Browse the repository at this point in the history
  6. journald/read: simplify/fix followJournal()

    TL;DR: simplify the code, fix --follow hanging indefinitely
    
    Do the following to simplify the followJournal() code:
    
    1. Use Go-native select instead of C-native polling.
    
    2. Use Watch{Producer,Consumer}Gone(), eliminating the need
    to have journald.closed variable, and an extra goroutine.
    
    3. Use sd_journal_wait(). In the words of its own man page:
    
    > A synchronous alternative for using sd_journal_get_fd(),
    > sd_journal_get_events(), sd_journal_get_timeout() and
    > sd_journal_process() is sd_journal_wait().
    
    Unfortunately, the logic is still not as simple as it
    could be; the reason being, once the container has exited,
    journald might still be writing some logs from its internal
    buffers onto journal file(s), and there is no way to
    figure out whether it's done so we are guaranteed to
    read all of it back. This bug can be reproduced with
    something like
    
    > $ ID=$(docker run -d busybox seq 1 150000); docker logs --follow $ID
    > ...
    > 128123
    > $
    
    (The last expected output line should be `150000`).
    
    To avoid exiting from followJournal() early, add the
    following logic: once the container is gone, keep trying
    to drain the journal until there's no new data for at
    least `waitTimeout` time period.
    
    Should fix docker/for-linux#575
    
    Signed-off-by: Kir Kolyshkin <kolyshkin@gmail.com>
    kolyshkin committed Aug 2, 2019
    Copy the full SHA
    f091feb View commit details
    Browse the repository at this point in the history
  7. journald/read: avoid piling up open files

    If we take a long time to process log messages, and during that time
    journal file rotation occurs, the journald client library will keep
    those rotated files open until sd_journal_process() is called.
    
    By periodically calling sd_journal_process() during the processing
    loop we shrink the window of time a client instance has open file
    descriptors for rotated (deleted) journal files.
    
    This code is modelled after that of journalctl [1]; the above explanation
    as well as the value of 1024 is taken from there.
    
    [v2: fix CErr() argument]
    
    [1] https://github.com/systemd/systemd/blob/dc16327c48d/src/journal/journalctl.c#L2676
    Signed-off-by: Kir Kolyshkin <kolyshkin@gmail.com>
    kolyshkin committed Aug 2, 2019
    Copy the full SHA
    b73fb8f View commit details
    Browse the repository at this point in the history
  8. journald: fix for --tail 0

    From the first glance, `docker logs --tail 0` does not make sense,
    as it is supposed to produce no output, but `tail -n 0` from GNU
    coreutils is working like that, plus there is even a test case
    (`TestLogsTail` in integration-cli/docker_cli_logs_test.go).
    
    Now, something like `docker logs --follow --tail 0` makes total
    sense, so let's make it work.
    
    (NOTE if --tail is not used, config.Tail is set to -1)
    
    Signed-off-by: Kir Kolyshkin <kolyshkin@gmail.com>
    kolyshkin committed Aug 2, 2019
    Copy the full SHA
    dd4bfe3 View commit details
    Browse the repository at this point in the history
  9. journald/read: fix/unify errors

    1. Use "in-place" variables for if statements to limit their scope to
       the respectful `if` block.
    
    2. Report the error returned from sd_journal_* by using CErr().
    
    3. Use errors.New() instead of fmt.Errorf().
    
    Signed-off-by: Kir Kolyshkin <kolyshkin@gmail.com>
    kolyshkin committed Aug 2, 2019
    Copy the full SHA
    20a0e58 View commit details
    Browse the repository at this point in the history