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

diskq: fix invalid read after disk_buf_size #3726

Merged
merged 14 commits into from Jul 15, 2021

Conversation

alltilla
Copy link
Collaborator

@alltilla alltilla commented Jul 7, 2021

We do not check beforehand, whether we can fit a new message to the disk-buffer, we decide to wrap the write_head after we wrote over the disk-buf-size limit.

It is possible to be just before the disk-buf-size with the write_head and write a huge message, then wrap the write_head to the beginning. This will change self->file_size to be a large value.

Let's say we set truncate-size-ratio(1), so we never truncate and never change the file_size from that large value.

Imagine, that we handled every message, then wrote a lot of messages to the disk-buffer again, so we are just before the disk-buf-size limit.
We write 2 small messages, one will end just after disk-buf-size but still before the huge self->file_size, the next one will start at the beginning, and end a bit after that.
This is because we decide to wrap the write_head based on the position related to disk-buf-size (see _is_qdisk_overwritten()).

When we are reading from the disk-buffer we currently decide to wrap the read_head based on whether it is after the self->file_size.
We read the small message that ends just after disk-buf-size, and we decide not to wrap, and try to read one more message there, which is the middle of an old message.

This PR matches the wrap logic between the write and read head, so they both measure their position relative to disk-buf-size.

Signed-off-by: Attila Szakacs attila.szakacs@oneidentity.com

@szemere szemere self-requested a review July 7, 2021 14:18
@kira-syslogng
Copy link
Contributor

Build FAILURE

@alltilla alltilla changed the title diskq: fix invalid read after disk_buf_size [wip] diskq: fix invalid read after disk_buf_size Jul 7, 2021
@alltilla alltilla marked this pull request as draft July 7, 2021 16:32
@kira-syslogng
Copy link
Contributor

Build FAILURE

@alltilla alltilla changed the title [wip] diskq: fix invalid read after disk_buf_size [wip] qdisk: store useful file size Jul 7, 2021
@kira-syslogng
Copy link
Contributor

Build FAILURE

@alltilla
Copy link
Collaborator Author

alltilla commented Jul 7, 2021

@kira-syslogng do stresstest

@MrAnno
Copy link
Collaborator

MrAnno commented Jul 7, 2021

Can you explain the exact difference between useful_file_size and file_size and when they have to be updated?
Maybe we could find a more "intention-revealing" variable name that way.

@alltilla
Copy link
Collaborator Author

alltilla commented Jul 7, 2021

file_size is the physical disk used by the disk-queue file. useful_file_size is the physical disk usage of the mmapped region and the log messages which are waiting to be processed (read or acked). Sorry if I am cryptic.

Edit: This is not completely true, because we can have already handled messages in the start of the disk buffer... The useful_file_size variable is the theoretically minimal file size, if we would truncate every time. So it does not take into account the already handled messages in the end of the file, which could have been removed by truncate, but wasn't because of truncate-size-ratio.

@kira-syslogng
Copy link
Contributor

Kira-stress-test: Build SUCCESS

@alltilla alltilla marked this pull request as ready for review July 8, 2021 06:03
@alltilla alltilla changed the title [wip] qdisk: store useful file size qdisk: store useful file size Jul 8, 2021
@MrAnno MrAnno self-requested a review July 8, 2021 18:53
alltilla added a commit to alltilla/syslog-ng that referenced this pull request Jul 9, 2021
Signed-off-by: Attila Szakacs <attila.szakacs@oneidentity.com>
@MrAnno
Copy link
Collaborator

MrAnno commented Jul 9, 2021

It seems that useful_file_size is not recovered after restarting syslog-ng, so the fix may be incomplete.

I think the best would be if we could fix this issue without adding more "state".
If we could calculate useful_file_size at restart, then it's actually an unnecessary field, otherwise, we should persist this field as well.

@MrAnno
Copy link
Collaborator

MrAnno commented Jul 9, 2021

@kira-syslogng do stresstest

@kira-syslogng
Copy link
Contributor

Kira-stress-test: Build SUCCESS

alltilla added a commit to alltilla/syslog-ng that referenced this pull request Jul 9, 2021
Signed-off-by: Attila Szakacs <attila.szakacs@oneidentity.com>
@MrAnno
Copy link
Collaborator

MrAnno commented Jul 9, 2021

It turned out that the additional "state" is required, and it also has to be persisted (has to be added to the disk buffer header).

This is because the truncation logic was not only used to reduce file size, but for 2 special operations as well:

  • to remove persisted memory-buffers (qout, overflow, backlog) from the disk buffer after a restart (non-reliable qdisk)
  • to remove an overflowing disk buffer section when we write past disk-buf-size() (we allow a single message at the end of the disk-buffer to exceed the disk-buf-size limit)

We must not allow read_head to reach those parts of the diskq file, hence the need for the new field.
Since we need to add a new field to the header, the diskq version needs to be bumped too.


Alternatively, we could truncate in the above 2 rare(?) cases unconditionally as we did before. That would save us from complicating things further.

@kira-syslogng
Copy link
Contributor

Kira-stress-test: Build SUCCESS

@kira-syslogng
Copy link
Contributor

Build SUCCESS

Copy link
Collaborator

@gaborznagy gaborznagy left a comment

Choose a reason for hiding this comment

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

I've just glimpsed into the PR to see what's changing.

modules/diskq/qdisk.c Show resolved Hide resolved
modules/diskq/qdisk.c Outdated Show resolved Hide resolved
modules/diskq/qdisk.c Show resolved Hide resolved
modules/diskq/qdisk.c Outdated Show resolved Hide resolved
modules/diskq/qdisk.c Outdated Show resolved Hide resolved
@MrAnno MrAnno self-requested a review July 12, 2021 23:40
alltilla and others added 14 commits July 13, 2021 07:22
This is a strange unit test, it was created to help to investigate a bug
and validate its fix. I added this first, so one can checkout this
commit, and see, that it fails with the current code.

The details and the root cause of the bug will be in the next commit's
message.

Signed-off-by: Attila Szakacs <attila.szakacs@oneidentity.com>
With the truncate-size-ratio() option, now we cannot base our read_head
wrapping logic on self->file_size (see next commit).

We can base it on disk_buf_size, if we guarantee, that the write_head
does not overwrite disk_buf_size with more than 1 message.

Signed-off-by: Attila Szakacs <attila.szakacs@oneidentity.com>
We do not check beforehand, whether we can fit a new message to the
disk-buffer, we decide to wrap the write_head after we wrote over the
disk-buf-size limit.

It is possible to be just before the disk-buf-size with the write_head
and write a huge message, then wrap the write_head to the beginning.
This will change self->file_size to be a large value.

Let's say we set truncate-size-ratio(1), so we never truncate and never
change the file_size from that large value.

Imagine, that we handled every message, then wrote a lot of messages
to the disk-buffer again, so we are just before the disk-buf-size limit.
We write 2 small messages, one will end just after disk-buf-size but
still before the huge self->file_size, the next one will start at the
beginning, and end a bit after that. This is because we decide to wrap
the write_head based on the position related to disk-buf-size
(see `_is_qdisk_overwritten()`).

When we are reading from the disk-buffer we currently decide to wrap
the read_head based on whether it is after the self->file_size.
We read the small message that ends just after disk-buf-size, and we
decide not to wrap, and try to read one more message there, which is
the middle of an old message.

This commit matches the wrap logic between the write and read head,
so they both measure their position relative to disk-buf-size.

Signed-off-by: Attila Szakacs <attila.szakacs@oneidentity.com>
Signed-off-by: Attila Szakacs <attila.szakacs@oneidentity.com>
Signed-off-by: Attila Szakacs <attila.szakacs@oneidentity.com>
Signed-off-by: Attila Szakacs <attila.szakacs@oneidentity.com>
This way we can change the disk-buffer version immediately at load,
so it is easier to add a new disk-buffer version later.

Signed-off-by: Attila Szakacs <attila.szakacs@oneidentity.com>
Follow-up for syslog-ng#3689.

Signed-off-by: László Várady <laszlo.varady@protonmail.com>
As the truncation logic is now conditional, debug messages has to be
moved inside _maybe_truncate_file().

Signed-off-by: László Várady <laszlo.varady@protonmail.com>
Signed-off-by: László Várady <laszlo.varady@protonmail.com>
Signed-off-by: László Várady <laszlo.varady@protonmail.com>
Signed-off-by: László Várady <laszlo.varady@protonmail.com>
The in-memory buffers of the non-reliable diskq is persisted when syslog-ng
is restarted, which increases the size of the actual disk-buffer file.

This test case tests the correctness of the non-reliable diskq when
truncation is completely disabled.

Signed-off-by: László Várady <laszlo.varady@protonmail.com>
Signed-off-by: Attila Szakacs <attila.szakacs@oneidentity.com>
@alltilla alltilla changed the title qdisk: store useful file size diskq: fix invalid read after disk_buf_size Jul 14, 2021
@alltilla alltilla marked this pull request as ready for review July 14, 2021 18:48
@alltilla
Copy link
Collaborator Author

@kira-syslogng do stresstest

@kira-syslogng
Copy link
Contributor

Build SUCCESS

@kira-syslogng
Copy link
Contributor

Kira-stress-test: Build SUCCESS

Copy link
Collaborator

@szemere szemere left a comment

Choose a reason for hiding this comment

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

Thank You!

@szemere szemere merged commit 59d17f5 into syslog-ng:master Jul 15, 2021
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.

None yet

6 participants