LTX fd polling is slow in Qemu

[metan-ucw]

It looks like the file descriptor is not registered correctly when ltx is selected in kirk. What it does is to register new epoll instance and a asyncio task that polls that instance. The problem is that there is a second instance of epoll in the asyncio main loop that is used to wait for new events. I suppose that we would have to use low level asyncio add_reader() function to watch the file descriptor however that API allows us to register a reader function that would have to somehow feed data to the corutine parser and I have no idea how to do that.

[metan-ucw]

I did more debugging and it looks like while the code in kirk is absurdly suboptimal but it may actually work. The polling task calls epoll to check for data availability and read which is dumb but may actually work (which is equivalent to calling read in a loop on O_NONBLOCK socket). It looks like the problem here is that virtio serial connected to fifo in qemu drops data. Normally when someone tries to write into a fifo that has no reader the call blocks, but it looks that this is not true for virtio serial connected to a fifo, where the data are silently dropped unless someone is reading at the other end. I suppose that the easiest solution to fix this is to add support to unix sockets and tcp to kirk, so that we can connect the virtio serial to unix socket that should be able to buffer and retain data.

[metan-ucw]

And in the end I've managed to actually make things work. And the problem was qemu configuration, if you create a single fifo for a virtio-serial both ends of the fifo are connected to the serial and bytes arrive randomly either to anything that reads the fifo on host or back to the qemu virtio serial. It seems to be nondeterministic and some bytes are simply lost 🤦.

To start qemu with virtio device you need to do

mkfifo ltx-io.in
mkfifo ltx-io.out

qemu-system-x86_64 ... -chardev pipe,id=ltx-io,path=ltx-io -device virtserialport,chardev=ltx-io,name=ltx-io

To start ltx on the SUT you need

4<>/dev/vitio-ports/ltx-io
/opt/ltp/ltx <&4 >&4

Now to talk to the ltx with kirk on host:

kirk -s ltx:stdin=ltx-io.in:stdout=ltx-io.out -c date

This is enough to run simple commands, however things are awfully slow for some reason and attempts to run a tesuite hangs or end up with errors, so there are some bottlenecks/bugs in the communication. Things seem to work, albeit slow if I add debugging messages to ltx, which hints at problems in kirk deserializer.

[acerv]

The fact LTX is slow with debug messages is quite normal. Are you sure this is a bug?

[metan-ucw]

@acerv Try yourself, it's slow and it hangs, either at start or shortly after. I suppose that something is broken in the part that deserializes the messages.

[acerv]

@metan-ucw what's your qemu version?

qemu-system-x86_64: -device virtserialport,chardev=ltx-io,name=ltx-io: No 'virtio-serial-bus' bus found for device 'virtserialport'

[metan-ucw]

@acerv Ah, sorry the commandline is incomplete, you have to add -device virtio-serial

[acerv]

Sorry but I can't reproduce this problem:

• I don't see any /dev/vitio-ports/ltx-io after running qemu, so I guess it's local fifo instead?
• ltx-io.in and ltx-io.out are never used by ltx, but they are in kirk

Am I missing something?

[metan-ucw]

Ah, another missing part in the qemu parameters, you have to pass name=ltx-io in the -device option so that you get the /dev/virtion-ports/ltx-io symlink which points to /dev/vport0p1. You can as well open the port directly with 4<>/dev/vport0p1.

[acerv]

The epoll usage has been removed with #11

[acerv]

It seems the real bottle neck is related with data transfer, because testing suites execution is really fast (at the end it's only a commands list run).

It could be even a LTX bug, but I need to go deeper into it. If I increase the READ_BUFFER_SIZE variable, everything seems to work a bit better. But it's not a solution.

I also noticed that if LTX is compiled without debug info, the data transfer just doesn't work and kirk stuck waiting for data. This is not something related with kirk, but rather LTX -> Qemu serial port communication.

[metan-ucw]

I finally had time to look into this again, I kind of managed it to work with:

mkfifo ltx-io.in
mkfifo ltx-io.out
qemu- ... -chardev pipe,id=ltx-io,path=ltx-io -device virtserialport,chardev=ltx-io,name=ltx-io

Then in the qemu VM we have to run ltx, however it looks like the kirk chokes if we send data too fast. From the log it looks like the file transfer is just cut in half so it's probably not reading fast enough. As a workaround you need to add fprintf(stderr, "Write stdout %zi\n"); into the do {} while(); loop in ltx_send_message() that will slow it enough for things to work. After that you need to start the ltx with:

./ltx -s /dev/virtio-ports/ltx-io

And things seems to work okay, as long as ltx is slowed down by printing into the slow virtual machine console.

However while kirk runs it consumes 120% cpu since there is bussy loop in _read() in ltx.py that cycles in place. You can check it with running:

./kirk --run-command 'sleep 10' -v --sut ltx:stdin=ltx-io.in:stdout=ltx-io.out

And watching top in another terminal.

In summary there are two bugs, which may be possibly single one. As ltx is a simple C program it sends the data in file transfer quite fast and kirk is not able to handle that. However that may be because it runs a loop that creates a thread for each read() on the file descriptor and that may cause the reasonably large buffers in the pipe we read from overflow because of the overhead.