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.

Sign up for GitHub

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

Jump to bottom

Travis TestWrite10 failure #363

Closed
rfjakob opened this issue Feb 4, 2019 · 4 comments
Closed

Travis TestWrite10 failure #363

rfjakob opened this issue Feb 4, 2019 · 4 comments

Comments

@rfjakob
Copy link
Owner

rfjakob commented Feb 4, 2019 •
edited
Loading

https://api.travis-ci.org/v3/job/488037836/log.txt / https://travis-ci.org/rfjakob/gocryptfs/jobs/488037836

doRead 1450284: corrupt header: ParseHeader: invalid version, want=2 have=0
-wpanic turns this warning into a panic: doRead 1450284: corrupt header: ParseHeader: invalid version, want=2 have=0
panic: -wpanic turns this warning into a panic: doRead 1450284: corrupt header: ParseHeader: invalid version, want=2 have=0

goroutine 20 [running]:
log.(*Logger).Panic(0xc4200904b0, 0xc42031d950, 0x1, 0x1)
	/home/travis/.gimme/versions/go1.9.7.linux.amd64/src/log/log.go:212 +0xbe
github.com/rfjakob/gocryptfs/internal/tlog.(*toggledLogger).Printf(0xc4200748a0, 0x68b773, 0x1d, 0xc42031db38, 0x2, 0x2)
	github.com/rfjakob/gocryptfs/internal/tlog/log.go:78 +0x221
github.com/rfjakob/gocryptfs/internal/fusefrontend.(*File).doRead(0xc420312540, 0xc42039c000, 0x0, 0x1000, 0x0, 0x1000, 0x60000000001, 0x8, 0x18, 0xc420384340)
	github.com/rfjakob/gocryptfs/internal/fusefrontend/file.go:161 +0xfda
github.com/rfjakob/gocryptfs/internal/fusefrontend.(*File).Read(0xc420312540, 0xc42039c000, 0x1000, 0x1000, 0x0, 0x0, 0x0, 0xc400000000)
	github.com/rfjakob/gocryptfs/internal/fusefrontend/file.go:246 +0x290
github.com/hanwen/go-fuse/fuse/pathfs.(*pathInode).Read(0xc4200c0510, 0x9c19a0, 0xc420312540, 0xc42039c000, 0x1000, 0x1000, 0x0, 0xc4202de198, 0x1000, 0x1000, ...)
	github.com/hanwen/go-fuse/fuse/pathfs/pathfs.go:749 +0x65
github.com/hanwen/go-fuse/fuse/nodefs.(*rawBridge).Read(0xc420074f30, 0xc4202de180, 0xc42039c000, 0x1000, 0x1000, 0x1000, 0x533901, 0xc420384320)
	github.com/hanwen/go-fuse/fuse/nodefs/fsops.go:451 +0xda
github.com/hanwen/go-fuse/fuse.doRead(0xc42008e300, 0xc4202de000)
	github.com/hanwen/go-fuse/fuse/opcode.go:364 +0x9d
github.com/hanwen/go-fuse/fuse.(*Server).handleRequest(0xc42008e300, 0xc4202de000, 0xc4202de000)
	github.com/hanwen/go-fuse/fuse/server.go:431 +0x296
github.com/hanwen/go-fuse/fuse.(*Server).loop(0xc42008e300, 0xc42019f601)
	github.com/hanwen/go-fuse/fuse/server.go:403 +0x1a9
created by github.com/hanwen/go-fuse/fuse.(*Server).readRequest
	github.com/hanwen/go-fuse/fuse/server.go:291 +0x2be
ReadFile: open /tmp/gocryptfs-test-parent/187858704/default-plain/10: transport endpoint is not connected
--- FAIL: TestWrite10 (0.00s)
	helpers.go:184: ReadFile failed: read /tmp/gocryptfs-test-parent/187858704/default-plain/10: transport endpoint is not connected
	helpers.go:191: Stat failed: stat /tmp/gocryptfs-test-parent/187858704/default-plain/10: transport endpoint is not connected
	matrix_test.go:117: Wrong content, hashWant=a63c90cc3684ad8b0a2176a6a8fe9005 hashActual=
[...]
FAIL	github.com/rfjakob/gocryptfs/tests/matrix	1.019s
rfjakob added a commit that referenced this issue Feb 17, 2019
@rfjakob
ParseHeader: print hexdump on error
179471b 
Should help debugging #363
@rfjakob
Copy link
Owner Author

rfjakob commented Mar 2, 2019

Another one (log), and this time we have a hexdump:

doRead 1575182: corrupt header: ParseHeader: invalid version, want=2 have=0.
Hexdump: 000000000000000000000000000000000000

rfjakob added a commit that referenced this issue Mar 5, 2019
@rfjakob
tests: add additional TestWrite10Tight test
f6cb403 
Try to find out what goes wrong in
#363
rfjakob added a commit that referenced this issue Mar 5, 2019
@rfjakob
tests: add TestConcurrentReadWrite
5aefe4c 
Another attempt to find out what is going on behind
#363
@rfjakob
Copy link
Owner Author

rfjakob commented Mar 5, 2019

TestWrite10Tight caught one as well: https://travis-ci.org/rfjakob/gocryptfs/jobs/502204426

rfjakob added a commit that referenced this issue Mar 5, 2019
@rfjakob
tests: add TestConcurrentReadWrite
c9c109f 
Another attempt to find out what is going on behind
#363
rfjakob added a commit that referenced this issue Mar 5, 2019
@rfjakob
tests: add TestConcurrentReadCreate, move to new file
abe65ac 
#363
rfjakob added a commit that referenced this issue Mar 5, 2019
@rfjakob
travis: run tests with "-v"
83414fa 
Let's log more details.

#363
rfjakob added a commit that referenced this issue Apr 8, 2019
@rfjakob
tests: add additional TestWrite10Tight test
311c34a 
Try to find out what goes wrong in
#363
rfjakob added a commit that referenced this issue Apr 8, 2019
@rfjakob
tests: add TestConcurrentReadWrite
d22ccf6 
Another attempt to find out what is going on behind
#363
rfjakob added a commit that referenced this issue Apr 8, 2019
@rfjakob
tests: add TestConcurrentReadCreate, move to new file
d851cf8 
#363
rfjakob added a commit that referenced this issue Apr 8, 2019
@rfjakob
travis: run tests with "-v"
8cad0e2 
Let's log more details.

#363
@rfjakob
Copy link
Owner Author

rfjakob commented Sep 2, 2019

Running the "matrix" tests in a loop for 4 hours on my local machine ( 5.1.15-300.fc30.x86_64 ) did not trigger this. Kernel version dependent?

rfjakob added a commit that referenced this issue Oct 6, 2019
@rfjakob
[DO NOT MERGE] only run TestWrite10
3c19920 
#363
rfjakob added a commit that referenced this issue Oct 6, 2019
@rfjakob
contentenc: add explicit test for all-zero header
9229fc7 
#363
rfjakob added a commit that referenced this issue Oct 6, 2019
@rfjakob
fusefrontend: print file hexdump on header error
bb1face 
This should help debugging #363 ,
but does no harm in normal operation as it only prints ciphertext to the log.
rfjakob added a commit that referenced this issue Oct 6, 2019
@rfjakob
contentenc: add explicit test for all-zero header
b3c88f5 
#363
rfjakob added a commit that referenced this issue Oct 6, 2019
@rfjakob
fusefrontend: print file hexdump on header error
4326594 
This should help debugging #363 ,
but does no harm in normal operation as it only prints ciphertext to the log.
rfjakob added a commit that referenced this issue Oct 6, 2019
@rfjakob
[DO NOT MERGE] only run TestWrite10
d71ec68 
#363
@rfjakob
Copy link
Owner Author

rfjakob commented Oct 6, 2019

Gotcha:

...
doWrite: file was empty, new fileID: [115 66 59 129 1 85 112 250 172 58 255 190 217 235 13 88]read ok, 10 bytes
doWrite: file was empty, new fileID: [23 133 110 231 192 80 249 147 52 117 113 151 72 92 225 115]read ok, 10 bytes
doWrite: file was empty, new fileID: [253 182 222 67 115 161 225 0 184 245 157 22 158 239 175 43]read ok, 10 bytes
doWrite: file was empty, new fileID: [88 43 26 123 250 225 24 4 246 254 249 183 54 140 25 17]read ok, 10 bytes
doWrite: file was empty, new fileID: [10 71 200 122 115 201 36 1 33 158 178 3 130 208 15 138]read ok, 10 bytes
doWrite: file was empty, new fileID: [186 145 0 238 142 185 140 223 9 240 37 142 208 62 157 58]read ok, 10 bytes
doWrite: file was empty, new fileID: [108 212 151 134 143 228 138 118 111 42 218 92 2 176 79 196]read ok, 10 bytes
doWrite: file was empty, new fileID: [163 170 59 191 132 131 63 112 201 162 72 97 10 240 70 24]read ok, 10 bytes
doWrite: file was empty, new fileID: [52 202 122 33 57 106 31 228 6 72 193 21 37 174 54 134]read ok, 10 bytes
doWrite: file was empty, new fileID: [99 162 214 221 109 101 98 8 110 46 203 151 111 99 218 139]read ok, 10 bytes
doWrite: file was empty, new fileID: [204 135 155 46 168 155 62 157 134 95 130 91 173 201 11 150]read ok, 10 bytes
doWrite: file was empty, new fileID: [15 12 106 64 11 208 119 132 167 59 253 214 148 56 190 23]read ok, 10 bytes
doWrite: file was empty, new fileID: [170 68 23 222 23 241 87 68 101 238 69 206 49 235 66 103]read ok, 10 bytes
doWrite: file already had a fileID: [170 68 23 222 23 241 87 68 101 238 69 206 49 235 66 103]
doRead 2561939: corrupt header: ParseHeader: header is all-zero. Header hexdump: 000000000000000000000000000000000000
File hexdump (60 bytes): 0000000000000000000000000000000000001c7e3ceaaa4174354e375f62334d622cc25f2ab216d66eb8e5a84ba7f8ffb745269060bfc73bc2fec47e

The inode number is reused before the Close() finishes

rfjakob added a commit that referenced this issue Oct 6, 2019
@rfjakob
fusefrontend: unregister from openfiletable before closing the fd
6476088 
Closing the fd means the inode number may be reused immediately
by a new file, so we have to get the old fileID out of the table
beforehand!

Hopefully fixes #363
rfjakob added a commit that referenced this issue Oct 6, 2019
@rfjakob
fusefrontend: unregister from openfiletable before closing the fd
f3e285f 
Closing the fd means the inode number may be reused immediately
by a new file, so we have to get the old fileID out of the table
beforehand!

Hopefully fixes #363
@rfjakob rfjakob closed this as completed in 00af4f4 Oct 6, 2019
@rfjakob rfjakob mentioned this issue Aug 2, 2021
Closed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
1 participant
@rfjakob