Thanks Nadav, I realise my report was a bit vague (even for me!).
I'm a bit limited on data here at the moment (slow satellite email
only) but I compiled up the most recent OSv tree I have from git. The
tag is 29eb3d53.
Compiled like this:
scripts/build mode=debug fs_size_mb=500 image=cloud-init
Then I put a test iso in the current directory (doesn't seem to matter
what it is, I had an Ubuntu image iso to hand), and ran:
scripts/run.py -d --cloud-init-image=test.iso \
-e /usr/mgmt/cloud-init.so
It hits the same assert:
rickp@clifford:~/src/osv-cloudius$ scripts/run.py -d --cloud-init-
image=test.iso -e /usr/mgmt/cloud-init.soWARNING: Image format was not
specified for '/home/rickp/src/osv-cloudius/test.iso' and probing
guessed raw.
Automatically detecting the format is dangerous for raw
images, write operations on block 0 will be restricted.
Specify the 'raw' format explicitly to remove the
restrictions.
OSv v0.56.0-18-g29eb3d53
eth0: 192.168.122.15
Booted up in 250.69 ms
Cmdline: /usr/mgmt/cloud-init.so
Assertion failed: (uio->uio_resid % BSIZE) == 0 (fs/vfs/vfs_bdev.cc:
bdev_read: 33)
[backtrace]
0x0000000040224a28 <abort(char const*, ...)+274>
0x0000000040224a8d <__assert_fail+62>
0x00000000406b99ad <bdev_read+144>
0x0000000040460008 <???+1078329352>
0x00000000406c93d0 <device_read+135>
0x00000000406c880b <???+1080854539>
0x00000000406c4213 <vfs_file::read(uio*, int)+141>
0x00000000406c0e1d <sys_read+395>
0x000000004068d0d2 <???+1080611026>
0x000000004068d142 <readv+45>
0x00000000406f243f <???+1081025599>
0x000000004073bc83 <fread+318>
0x00001000006a772a <???+6977322>
0x00001000006a7c0c <cdio_stream_read+107>
0x00001000006d9a50 <???+7182928>
0x00001000006d9a8a <iso9660_iso_seek_read+55>
0x00001000006d9011 <???+7180305>
0x00001000006d9077 <???+7180407>
0x00001000006d90cd <iso9660_ifs_read_superblock+83>
0x00001000006d8a03 <???+7178755>
0x00001000006d8b07 <???+7179015>
0x00001000006d8ad6 <???+7178966>
0x000010000068cc9f <???+6868127>
0x000010000068d347 <???+6869831>
0x000000004067b38e <osv::application::run_main()+128>
0x000000004067ace4 <osv::application::main()+172>
0x000000004067ab08 <osv::application::start_and_join(waiter*)+164>
0x0000000040679e97
<osv::application::run_and_join(std::__cxx11::basic_string<char,
std::char_traits<char>, std::allocator<char> > const&,
std::vector<std::__cxx11::basic_string<char, std::char_traits<char>,
std::allocator<char> >, std::allocator<std::__cxx11::basic_string<char,
std::char_traits<char>, std::allocator<char> > > > const&, bool,
std::unordered_map<std::__cxx11::basic_string<char,
std::char_traits<char>, std::allocator<char> >,
std::__cxx11::basic_string<char, std::char_traits<char>,
std::allocator<char> >, std::hash<std::__cxx11::basic_string<char,
std::char_traits<char>, std::allocator<char> > >,
std::equal_to<std::__cxx11::basic_string<char, std::char_traits<char>,
std::allocator<char> > >,
std::allocator<std::pair<std::__cxx11::basic_string<char,
std::char_traits<char>, std::allocator<char> > const,
std::__cxx11::basic_string<char, std::char_traits<char>,
std::allocator<char> > > > > const*, waiter*,
std::__cxx11::basic_string<char, std::char_traits<char>,
std::allocator<char> > const&, std:0x0000000040662943
<osv::run(std::__cxx11::basic_string<char, std::char_traits<char>,
std::allocator<char> >, std::vector<std::__cxx11::basic_string<char,
std::char_traits<char>, std::allocator<char> >,
std::allocator<std::__cxx11::basic_string<char, std::char_traits<char>,
std::allocator<char> > > >, int*, bool,
std::unordered_map<std::__cxx11::basic_string<char,
std::char_traits<char>, std::allocator<char> >,
std::__cxx11::basic_string<char, std::char_traits<char>,
std::allocator<char> >, std::hash<std::__cxx11::basic_string<char,
std::char_traits<char>, std::allocator<char> > >,
std::equal_to<std::__cxx11::basic_string<char, std::char_traits<char>,
std::allocator<char> > >,
std::allocator<std::pair<std::__cxx11::basic_string<char,
std::char_traits<char>, std::allocator<char> > const,
std::__cxx11::basic_string<char, std::char_traits<char>,
std::allocator<char> > > > > const*)+147>
0x000010000015eaef <???+1436399>
0x000010000015f881 <main+2460>
0x000000004067b38e <osv::application::run_main()+128>
0x000000004067ace4 <osv::application::main()+172>
0x000000004067a647 <???+1080534599>
0x000000004067a66f <???+1080534639>
0x00000000406fb1a8 <???+1081061800>
0x00000000406fde5a <???+1081073242>
0x0000000040498c39 <std::function<void ()>::operator()() const+53>
0x00000000405eb5ab <sched::thread::main()+31>
0x00000000405e6f32 <thread_main_c+42>
0x0000000040493d32 <???+1078541618>
0x0018f0130018f7ff <???+1636351>
0x00000000405eadf1 <sched::thread::~thread()+655>
0x7d894848ec834852 <???+-326940590>
I'd git bitsect it but I'm unable to deal with the submodule stuff
without data. Might be able to do this later this week though.
Cheers,
Rick
On Sun, 2021-11-28 at 11:27 +0200, Nadav Har'El wrote:
> As you noted I fixed a very similar (apparently...) bug in the past
> (#877 as you noticed) in commit
> https://github.com/cloudius-systems/osv/commit/0b651428b91663255d8da9a4913663d0cd4cc710
>
> The patch involved fixing a musl bug, so because Waldek recently did
> a lot of musl-related changes it was reasonable that somehow this bug
> returned - but looking at the latest code it doesn't seem to me that
> this is the case - it seems __stdio_read is still my fixed version.
> We also have a unit test tests/tst-fread.cc for this case, which
> doesn't seem to break - so I wonder how your use case is different.
>
> So I guess this needs more debugging. Can you please create an issue
> on how this error can be reproduced on the master version (what image
> to build and how to run it) and I'll try to debug it - unless you
> plan to? We should add more printouts on how much exactly the caller
> tried to read.
>
> Another possibility is that the application was genuinely trying to
> read a part of a block. OSv *could* implement this (reading more and
> then dropping a part of it) but I'm not sure that it should - or why
> this only started to happen recently - so I don't want to go in this
> direction unless we know why.
>
> --
> Nadav Har'El
> n...@scylladb.com
>
>
> On Sat, Nov 27, 2021 at 12:19 AM Rick Payne <ri...@rossfell.co.uk>
> wrote:
> > Hiya,
> >
> > Trying to get cloud-init working on a fairly recent OSv (0.55)
> > image
> > using an ISO to provide the YAML file. This used to work fine on my
> > previous OSv image, but now I'm hitting an assert failure:
> >
> > Assertion failed: (uio->uio_resid % BSIZE) == 0
> > (fs/vfs/vfs_bdev.cc:
> > bdev_read: 33)
> >
> > [backtrace]
> > 0x000000004023acac <__assert_fail+28>
> > 0x00000000404459e5 <bdev_read+261>
> > 0x000000004044e62d <device_read+61>
> > 0x000000004044babe <vfs_file::read(uio*, int)+94>
> > 0x00000000404491ba <sys_read+234>
> > 0x000000004043ef10 <???+1078193936>
> > 0x0000000040464b4d <__stdio_read+61>
> > 0x00000000404994cc <fread_unlocked+188>
> > 0x00001000006a772a <???+6977322>
> > 0x00001000006a7c0c <cdio_stream_read+107>
> > 0x00001000006d9a50 <???+7182928>
> > 0x00001000006d9a8a <iso9660_iso_seek_read+55>
> > 0x00001000006d9011 <???+7180305>
> > 0x00001000006d9077 <???+7180407>
> > 0x00001000006d90cd <iso9660_ifs_read_superblock+83>
> > 0x00001000006d8a03 <???+7178755>
> > 0x00001000006d8b07 <???+7179015>
> > 0x00001000006d8ad6 <???+7178966>
> > 0x000010000068cc9f <???+6868127>
> > 0x000010000068d347 <???+6869831>
> > 0x00000000404377a0 <osv::application::run_main()+64>
> > 0x0000000040223523 <osv::application::main()+147>
> >
> > The iso hasn't changed and mounts fine on a loopback under linux.
> > Building a new iso gives the same error. GDB backtrace is as
> > follows:
> >
> > #0 0x0000000040399f32 in processor::cli_hlt () at
> > arch/x64/processor.hh:247
> > #1 arch::halt_no_interrupts () at arch/x64/arch.hh:48
> > #2 osv::halt () at arch/x64/power.cc:26
> > #3 0x000000004023ac82 in abort (fmt=fmt@entry=0x406535f0
> > "Assertion
> > failed: %s (%s: %s: %d)\n")
> > at runtime.cc:140
> > #4 0x000000004023acad in __assert_fail (expr=expr@entry=0x406a46d1
> > "(uio->uio_resid % BSIZE) == 0",
> > file=file@entry=0x406a46a6 "fs/vfs/vfs_bdev.cc",
> > line=line@entry=33,
> > func=func@entry=0x406a469c "bdev_read") at runtime.cc:147
> > #5 0x00000000404459e6 in bdev_read (dev=<optimised out>,
> > uio=0x2000012ff480, ioflags=<optimised out>)
> > at fs/vfs/vfs_bdev.cc:42
> > #6 0x000000004044e62e in device_read (dev=0xffffa00100a18080,
> > uio=0x2000012ff480, ioflags=0)
> > at fs/devfs/device.cc:387
> > #7 0x000000004044babf in vfs_file::read (this=0xffffa00101545900,
> > uio=0x2000012ff480, flags=<optimised out>)
> > at fs/vfs/vfs_fops.cc:54
> > #8 0x00000000404491bb in sys_read (fp=0xffffa00101545900,
> > iov=iov@entry=0x2000012ff530, niov=niov@entry=2,
> > offset=offset@entry=-1, count=count@entry=0x2000012ff4f8) at
> > fs/vfs/vfs_syscalls.cc:275
> > #9 0x000000004043ef11 in preadv (fd=<optimised out>,
> > iov=iov@entry=0x2000012ff530, iovcnt=iovcnt@entry=2,
> > offset=offset@entry=-1) at fs/vfs/main.cc:422
> > #10 0x000000004043ef80 in readv (fd=<optimised out>,
> > iov=iov@entry=0x2000012ff530, iovcnt=iovcnt@entry=2)
> > at fs/vfs/main.cc:436
> > #11 0x0000000040464b4e in __stdio_read (f=0xffff900101577000,
> > buf=<optimised out>, len=2048)
> > at libc/stdio/__stdio_read.c:28
> > #12 0x00000000404994cd in fread (destv=<optimised out>, size=1,
> > nmemb=2048, f=0xffff900101577000)
> > at musl/src/stdio/fread.c:26
> > #13 0x00001000006a772b in _stdio_read ()
> > #14 0x00001000006a7c0d in cdio_stream_read ()
> > #15 0x00001000006d9a51 in iso9660_seek_read_framesize ()
> > #16 0x00001000006d9a8b in iso9660_iso_seek_read ()
> > #17 0x00001000006d9012 in iso9660_ifs_read_pvd_loglevel ()
> > #18 0x00001000006d9078 in iso9660_ifs_read_pvd ()
> >
> > #5 0x00000000404459e6 in bdev_read (dev=<optimised out>,
> > uio=0x2000012ff480, ioflags=<optimised out>)
> > at fs/vfs/vfs_bdev.cc:42
> > 42 while (uio->uio_resid > 0) {
> > (gdb) p uio->uio_resid
> > $8 = 133112
> >
> > (gdb) up
> > #6 0x000000004044e62e in device_read (dev=0xffffa00100a18080,
> > uio=0x2000012ff480, ioflags=0)
> > at fs/devfs/device.cc:387
> > 387 error = (*ops->read)(dev, uio, ioflags);
> > (gdb) p dev->name
> > $9 = "vblk1\000\000\000\000\000\000"
> >
> > It seem to be reading the correct block device:
> >
> > virtio-blk: Add blk device instances 0 as vblk0, devsize=524288000
> > virtio-blk: Add blk device instances 1 as vblk1, devsize=378880
> >
> > I see there was a similar assert that Justin hit a while back
> > (#877). I
> > made the same change (replace fread with read and change the args)
> > and
> > that no longer asserts, but doesn't read the ISO (as Justin found).
> >
> > Any ideas?
> >
> > Cheers
> > Rick
> >
--
You received this message because you are subscribed to the Google Groups "OSv
Development" group.
To unsubscribe from this group and stop receiving emails from it, send an email
to osv-dev+unsubscr...@googlegroups.com.
To view this discussion on the web visit
https://groups.google.com/d/msgid/osv-dev/758d33f596eddcd6f0478d7aac8e56173b029b45.camel%40rossfell.co.uk.
