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

Assertion failure when reading 2048 bytes from block device #1180

Closed
nyh opened this issue Nov 29, 2021 · 2 comments
Closed

Assertion failure when reading 2048 bytes from block device #1180

nyh opened this issue Nov 29, 2021 · 2 comments
Assignees
Labels

Comments

@nyh
Copy link
Contributor

nyh commented Nov 29, 2021

@rickpayne noted on the mailing list that if you run cloud-init and it reads from a block device, it fails on an assertion that a read not a multiple of BSIZE was attempted:

scripts/build image=cloud-init
scripts/run.py --cloud-init-image=/any/iso/file/you/might/have.iso -e /usr/mgmt/cloud-init.so

Fails with:

OSv v0.56.0-21-g317d259a
eth0: 192.168.122.15
Booted up in 147.06 ms
Cmdline: /usr/mgmt/cloud-init.so
Assertion failed: (uio->uio_resid % BSIZE) == 0 (fs/vfs/vfs_bdev.cc: bdev_read: 33)

The backtrace from gdb:

#4  0x0000000040238269 in __assert_fail (expr=<optimized out>, file=<optimized out>, line=<optimized out>, func=<optimized out>)    at runtime.cc:145
#5  0x000000004043a3b6 in bdev_read (dev=<optimized out>, uio=0x2000006ff140,     ioflags=<optimized out>) at fs/vfs/vfs_bdev.cc:33
#6  0x0000000040442dba in device_read (dev=0xffffa00000f80200, uio=0x2000006ff140, ioflags=0) at fs/devfs/device.cc:387
#7  0x00000000404401eb in vfs_file::read (this=0xffffa00001b95880,  uio=0x2000006ff140, flags=<optimized out>) at fs/vfs/vfs_fops.cc:54
#8  0x000000004043d9b3 in sys_read (fp=0xffffa00001b95880, iov=0x2000006ff1f0, niov=2, offset=-1, count=0x2000006ff1b8) at fs/vfs/vfs_syscalls.cc:275
#9  0x0000000040433a0d in preadv (fd=<optimized out>, iov=iov@entry=0x2000006ff1f0, iovcnt=iovcnt@entry=2,     offset=offset@entry=-1) at fs/vfs/main.cc:435
#10 0x0000000040433a6c in readv (fd=<optimized out>, iov=iov@entry=0x2000006ff1f0, iovcnt=iovcnt@entry=2) at fs/vfs/main.cc:450
#11 0x000000004045746a in __stdio_read (f=0xffff900001b8f000,  buf=<optimized out>, len=2048) at libc/stdio/__stdio_read.c:28
#12 0x000000004048afcd in fread (destv=<optimized out>, size=1, nmemb=2048, f=0xffff900001b8f000) at musl/src/stdio/fread.c:27
#13 0x00001000006d7aa4 in _stdio_read ()
#14 0x00001000006d7ef5 in cdio_stream_read ()
#15 0x00001000007081f9 in iso9660_seek_read_framesize ()
#16 0x000010000070822f in iso9660_iso_seek_read ()
#17 0x000010000070792e in iso9660_ifs_read_pvd_loglevel ()
#18 0x0000100000707990 in iso9660_ifs_read_pvd ()
#19 0x00001000007079d3 in iso9660_ifs_read_superblock ()
#20 0x0000100000707358 in iso9660_open_ext_private ()
#21 0x0000100000707454 in iso9660_open_ext ()
#22 0x0000100000707427 in iso9660_open ()
#23 0x00001000006bf934 in read_iso_file ()
#24 0x00001000006bff01 in main ()

This problem seems very similar to issue #877, which was already fixed long ago by commit 0b65142 so I don't know how it (or something similar) came back... You can see here (frame 11) that __stdio_read() was called to read 2048 bytes - which clearly is a multiple of BSIZE (=512 bytes) - but somehow we ended up calling the low-level read with what is not a multiple of BSIZE.

@rickpayne reported that this is a regression - the same use case used to work on earlier versions of OSv.

I'll try to debug why this happens.

@nyh nyh added the bug label Nov 29, 2021
@nyh nyh self-assigned this Nov 29, 2021
@nyh
Copy link
Contributor Author

nyh commented Nov 29, 2021

It turns out that a call to __stdio_read(..., len=2048) calls readv() for two buffers - one with exactly the requested 2048 bytes and the second for 131064 bytes to fill the next buffer. This second buffer size comes from f->buf_size and is 8 bytes less than 128 KB, and thus truely not a multiple of 512 bytes (BSIZE).
I'm now trying to figure out where this f->buf_size comes from and why it is not a multiple of the the block size 512, and whether or how this is a new regression...

@nyh
Copy link
Contributor Author

nyh commented Nov 29, 2021

It turns out that setvbuf() takes the user's buffer, uses the first 8 bytes (UNGET) for unget, and sets f->buf_size = size - UNGET. This is how one ends up with the silly 8-byte-short f->buf_size.

This changed in musl commit 0b80a7b04 in 2018. Before that commit, the setvbuf() ignored the user's buffer or buffer size.
We had the old setvbuf implementation from musl 0.9.12, and then got the new one from musl 1.1.24.

I can think of different fixes for this bug, but all of them ugly. I'll try to prepare one which is least ugly and send a patch :-(
The nice fix would have been to move the 8 UNGET bytes away from the buffer and into separate 8 bytes. But changing this will be too intrusive and I don't want to do it...

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

No branches or pull requests

1 participant