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

Fix handling for json-file io.UnexpectedEOF #42104

Merged
merged 2 commits into from
Mar 18, 2021

Conversation

cpuguy83
Copy link
Member

@cpuguy83 cpuguy83 commented Mar 1, 2021

Before this, we essentially end up doubling any buffered data from the
json decoder by storing it in both d.dec and d.rdr.

Thanks @tobiasstadler for pointing this error out.

Fixes #41820

@thaJeztah
Copy link
Member

s/io.UnepxectedEOF/io.UnexpectedEOF/ ☺️

@thaJeztah
Copy link
Member

@tonistiigi @tiborvass ptal

@thaJeztah thaJeztah modified the milestones: 20.10.5, 21.xx Mar 1, 2021
@cpuguy83 cpuguy83 force-pushed the 41820_fix_json_unexpected_eof branch from 243d349 to ccdc6f5 Compare March 1, 2021 23:26
@thaJeztah thaJeztah changed the title Fix handling for json-file io.UnepxectedEOF Fix handling for json-file io.UnexpectedEOF Mar 2, 2021
@thaJeztah
Copy link
Member

@cpuguy83 regression was introduced in #40796, correct?

@cpuguy83
Copy link
Member Author

cpuguy83 commented Mar 2, 2021

@thaJeztah That's correct.
Test passes before that commit (but requires some modifications due to refactoring in said PR), and fails on that PR and master.

@@ -105,8 +110,7 @@ func (d *decoder) Decode() (msg *logger.Message, err error) {
// If the json logger writes a partial json log entry to the disk
// while at the same time the decoder tries to decode it, the race condition happens.
if err == io.ErrUnexpectedEOF {
d.rdr = io.MultiReader(d.dec.Buffered(), d.rdr)
d.dec = json.NewDecoder(d.rdr)
d.dec = json.NewDecoder(io.MultiReader(d.dec.Buffered(), d.rdr))
Copy link
Member

Choose a reason for hiding this comment

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

iiuc the issue in here is not the resetting d.rdr or not (what looks more correct to me in the old version) but that we use incompatible Reader where after it returns io.EOF we can read again and it may return more data then. This does not follow the io.Reader interface that stdlib defines and therefore the utility functions behavior gets wrong. More specifically io.MultiReader caches io.EOF https://github.com/golang/go/blob/414fa8c35e7c2f65e2c767d6db2f25791e53b5c1/src/io/multi.go#L41 . So in the previous code if the MultiReader has already returned EOF once and now is added as a second reader to a new MultiReader it never gets called again and new MultiReader returns EOF without making any new Read calls to the original d.rdr.

Copy link
Member Author

Choose a reason for hiding this comment

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

Added a 2nd commit per your suggestion to replace io.MultiReader with a custom implementation that does not cache EOF's so that we can keep the full reader (with the buffered data) in d.rdr.

When the multireader hits EOF, we will always get EOF from it, so we
cannot store the multrireader fro later error handling, only for the
decoder.

Thanks @tobiasstadler for pointing this error out.

Signed-off-by: Brian Goff <cpuguy83@gmail.com>
@cpuguy83 cpuguy83 force-pushed the 41820_fix_json_unexpected_eof branch from ccdc6f5 to 4be98a3 Compare March 11, 2021 20:06
Copy link
Member

@tonistiigi tonistiigi left a comment

Choose a reason for hiding this comment

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

LGTM

SyntaxError handler seems to require combinedReader as well but that can be done separately as not directly related. Although I wonder if it might be broken because it could not have been made to work before because of the multireader issue.

@cpuguy83
Copy link
Member Author

Yeah there's no test for syntax reader and I think it never actually fixed anything.

d.dec = json.NewDecoder(d.rdr)
continue
}
}
return msg, err
}

func comineReaders(pre, rdr io.Reader) io.Reader {
Copy link
Member

Choose a reason for hiding this comment

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

Suggested change
func comineReaders(pre, rdr io.Reader) io.Reader {
func combineReaders(pre, rdr io.Reader) io.Reader {

Tonis mentioned that we can run into issues if there is more error
handling added here. This adds a custom reader implementation which is
like io.MultiReader except it does not cache EOF's.
What got us into trouble in the first place is `io.MultiReader` will
always return EOF once it has received an EOF, however the error
handling that we are going for is to recover from an EOF because the
underlying file is a file which can have more data added to it after
EOF.

Signed-off-by: Brian Goff <cpuguy83@gmail.com>
@cpuguy83 cpuguy83 force-pushed the 41820_fix_json_unexpected_eof branch from 4518545 to 5a664dc Compare March 18, 2021 18:44
Copy link
Member

@thaJeztah thaJeztah left a comment

Choose a reason for hiding this comment

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

LGTM

@thaJeztah
Copy link
Member

CI was green, and only typo was fixed in last push

@cpuguy83
Copy link
Member Author

=== FAIL: amd64.integration.service TestInspect (11.75s)
[2021-03-18T19:09:12.879Z] inspect_test.go:39: timeout hit after 10s: waiting for tasks to enter run state. task failed with error: task: non-zero exit (1)

This flaky inspect test :(

@cpuguy83 cpuguy83 merged commit 788f288 into moby:master Mar 18, 2021
@anodyne-canvas
Copy link

When will this be included in a release?

@thaJeztah
Copy link
Member

It's backported to the 20.10 release branch through #42174, and will be included in the 20.10.6 patch release

@anodyne-canvas
Copy link

Thanks for following up, do you know when 20.10.6 will be released?

@thaJeztah
Copy link
Member

Should be available soon (if all goes well, this week) (famous last words 😂 )

@aleon1220
Copy link

It seems to be fixed in docker engine 20.10.6 https://docs.docker.com/engine/release-notes/#20106

@BenasPaulikas
Copy link

almost 2am here. updating docker with this patch. Praying for this fix to solve my issues :)

@thaJeztah
Copy link
Member

@BenasPaulikas docker 20.10.6 and 20.10.7 have already shipped with this patch, so updating to the latest patch release should bring this patch.

@emulanob
Copy link

I'm still seeing this issue on 20.10.17, and so are many people on #41820 (comment)
Any chance this could be reviewed/reopened?

@oren-nonamesecurity
Copy link

Same here, docker 20.10.10
Screenshot from 2022-10-30 09-10-58

@BenasPaulikas
Copy link

I might be wrong here.

But there was package that was using json to get docker output or something. They changed to use streams (or something simmilar) and issue was gone. + It saved so much CPU power

@thaJeztah
Copy link
Member

I'm still seeing this issue on 20.10.17, and so are many people on #41820 (comment)
Any chance this could be reviewed/reopened?

This PR was to address an issue where docker tried to read the JSON, got an EOF, and reused the reader (which would continue to return an EOF error). Note that the EOF error can be an actual issue with a corrupt file, in which case the EOF error would be legit.

@xtemp3r
Copy link

xtemp3r commented Jan 16, 2023

I'm still seeing this issue on 20.10.17, and so are many people on #41820 (comment)

I can confirm I have this problem again on multiple systems running docker. I would also suggest that this issue is reopened.

I'm also running version: 20.10.17

@david-szabo97
Copy link

Same issue here. All our Docker instances are spamming this error continuously. Version: 20.10.22

@fredsig
Copy link

fredsig commented Apr 2, 2024

Same issue here with docker 20.10.18. Getting a couple of warnings every second (but it is not affecting my ability to process container logs) This triggered by using Loki's promtail agent to collect docker logs using the API (aka, "docker logs') via the service discovery plugin for docker:

Apr  2 16:23:52 ip-192-168-151-3 dockerd[323961]: time="2024-04-02T16:23:52.260711951Z" level=warning msg="got error while decoding json" error="unexpected EOF" retries=0
Apr  2 16:23:52 ip-192-168-151-3 dockerd[323961]: time="2024-04-02T16:23:52.587555447Z" level=warning msg="got error while decoding json" error="unexpected EOF" retries=0
Apr  2 16:23:52 ip-192-168-151-3 dockerd[323961]: time="2024-04-02T16:23:52.648610496Z" level=warning msg="got error while decoding json" error="unexpected EOF" retries=0

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

Successfully merging this pull request may close these issues.

Upgrade to 20.10 breaks log tailing: unexpected EOF errors