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

logging: buffer partial messages to journald #321

Merged

Conversation

cfsnyder
Copy link
Contributor

Ensures that log lines less than or equal to 8k in size are logged as a single journald message by buffering partial messages from subsequent read calls until a newline is observed (or buffer is full).

Fixes: #242
Signed-off-by: Cory Snyder csnyder@iland.com

@cfsnyder cfsnyder force-pushed the wip-242-buffer-partial-journald-logs branch from 7729621 to 036ec75 Compare January 20, 2022 13:36
@rhatdan
Copy link
Member

rhatdan commented Jan 20, 2022

@giuseppe @haircommander @mheon PTAL

@haircommander
Copy link
Collaborator

amazing, thank you @cfsnyder ! for some reason I had worked myself up and thought the solution would be more complex. Before we merge this, I'd like to get CI a bit more in order to make sure we have a proper smoke test against breaking changes here. I've done a manual test and it works great!

_cleanup_free_ char *message = g_strdup_printf("MESSAGE=%s", buf);
if (writev_buffer_append_segment(dev_null, &bufv, message, line_len + MESSAGE_EQ_LEN) < 0)
ssize_t msg_len = line_len + MESSAGE_EQ_LEN + *partial_buf_len;
partial_buf[*partial_buf_len] = '\0';
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This is where C bites me. Do you need a length check here to make sure you're not writing past the buffer? I'm just concerned with a max length partial_buf.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thanks for checking @TomSweeneyRedHat. Verify my logic here, but I believe that the invariant is upheld. Line 280 is the only statement that updates partial_buf_len to a non-zero value. On that line, it is updated to the sum of the previous partial_buf_len and line_len. The if statement surrounding that update guarantees that the maximum value of line_len is STDIO_BUF_SIZE - partial_buf_len - 1. Therefore, the maximum value that partial_buf_len might obtain is partial_buf_len + STDIO_BUF_SIZE - partial_buf_len - 1, which simplifies to STDIO_BUF_SIZE - 1. Of course, an index of STDIO_BUF_SIZE - 1 is always valid on an array of size STDIO_BUF_SiZE.

(In fact, prior to double checking this, I was unnecessarily subtracting 1 from the right side of the conditional on line 278 - so I'm glad you asked!)

@cfsnyder cfsnyder force-pushed the wip-242-buffer-partial-journald-logs branch from 036ec75 to 4c9116d Compare January 21, 2022 01:58
ssize_t msg_len = line_len + MESSAGE_EQ_LEN + *partial_buf_len;
partial_buf[*partial_buf_len] = '\0';
_cleanup_free_ char *message = g_strdup_printf("MESSAGE=%s%s", partial_buf, buf);
if (writev_buffer_append_segment(dev_null, &bufv, message, msg_len) < 0)
Copy link
Member

@giuseppe giuseppe Jan 21, 2022

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

would it work if you don't allocate a string here (I know it is pre-existing code) but now we are already having an extra buffered copy?

if (writev_buffer_append_segment(dev_null, &bufv, "MESSAGE=", MESSAGE_EQ_LEN) < 0)
....
if (writev_buffer_append_segment(dev_null, &bufv, partial_buf, *partial_buf_len) < 0)
...
if (writev_buffer_append_segment(dev_null, &bufv, buf, line_len) < 0)
...

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Each structure in the iovec that is passed to sd_journal_sendv must represent one field of the entry to submit. What you have above would create 3 separate structures in the iovec for the MESSAGE field, so that doesn't quite work. Ultimately all components of the entry need to be stored in contiguous memory, one way or another. It would be possible to avoid the heap allocation by placing the message field in a char array on the stack (and memcpy the components of the message there). What do you think?

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Ww could probably prepend it to the buffer before writing anything else, but let's not worry about it as part of the PR as anyway the issue was already existing.

Thanks for checking it!

@rhatdan
Copy link
Member

rhatdan commented Jan 21, 2022

If/When this gets merged, I think it is time for a new Conmon Release, to align with Podman 4.0.
@haircommander

@haircommander
Copy link
Collaborator

I agree I'd deem this 2.1 material :)

@haircommander
Copy link
Collaborator

heya @cfsnyder can you rebase on latest main? I've fixed most of CI so we should get a better signal on this PR

Ensures that log lines less than or equal to 8k in size are logged as a single journald message by buffering partial messages from subsequent read calls until a newline is observed (or buffer is full).

Fixes: containers#242
Signed-off-by: Cory Snyder <csnyder@iland.com>
@cfsnyder cfsnyder force-pushed the wip-242-buffer-partial-journald-logs branch from 4c9116d to 2c9f5f0 Compare January 24, 2022 14:44
@cfsnyder
Copy link
Contributor Author

Thanks @haircommander, just rebased!

@haircommander
Copy link
Collaborator

LGTM, thanks a bunch @cfsnyder

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

extra newlines in logged container output
5 participants