systemtap stapvirt tool
I am having a quandary with libvirt and am wondering if someone can shed some light. Systemtap converts a probing and instrumentation language into a kernel module. The module can optionally be run remotely via ssh or libvirt. The libvirt mechanism is not working (not yet sure of timing of regression) The systemtap stap command pipes to a stapvirt command that is the libvirt interface. The remote is running a stapsh tool that receives the requests. The initial commands are sent and received okay (strace output on remote) but never receives the stap kernel module: # local sent option data request [pid 11959] read(3, "option data\n", 4096) = 12 # remote says OK [pid 11959] write(3, "OK\n", 3) = 3 [pid 11959] poll([{fd=3, events=POLLIN}, {fd=0, events=0}, {fd=0, events=0}], 3, -1) = 1 ([{fd=3, revents=POLLIN}]) [pid 11959] --- SIGIO {si_signo=SIGIO, si_code=SI_KERNEL} --- [pid 11959] poll([{fd=3, events=POLLHUP}], 1, 0) = 0 (Timeout) [pid 11959] rt_sigreturn({mask=[]}) = 1 # local sent file ... request to download the module [pid 11959] read(3, "file 926928 stap_1f18b4b54e74602"..., 4096) = 58 # remote opens the module [pid 11959] openat(AT_FDCWD, "stap_1f18b4b54e74602a0a1f0685f2f7333e_1006.ko", O_WRONLY|O_CREAT|O_TRUNC, 0666) = 4 # but never receives it [pid 11959] read(3, "", 4096) = 0 The local sets up callbacks for stdin, stdout, stream: ctxt.stdin_w = virEventAddHandle(STDIN_FILENO, VIR_EVENT_HANDLE_READABLE, stdin_event, &ctxt, NULL); ... ctxt.stdout_w = virEventAddHandle(STDOUT_FILENO, 0, stdout_event, &ctxt, NULL); ... virStreamEventAddCallback(ctxt.st, VIR_STREAM_EVENT_READABLE | VIR_EVENT_HANDLE_WRITABLE, stream_event, &ctxt, NULL) < 0) Then starts an even loop while (!disconnect) { if (virEventRunDefaultImpl() != 0) break; } stream_event is notified for the command requests, but is not notified for the kernel module chunks: stdin_event excerpt: bytes_read = read(fd, ctxt->termbuf + ctxt->termbuf_off, sizeof(ctxt->termbuf) - ctxt->termbuf_off); ... ctxt->termbuf_off += bytes_read; ... if (ctxt->termbuf_off) { // we have stuff to write to the stream virStreamEventUpdateCallback(ctxt->st, VIR_STREAM_EVENT_READABLE | VIR_STREAM_EVENT_WRITABLE); } stream_event excerpt: if ((events & VIR_STREAM_EVENT_READABLE) && (ctxt->stbuf_off < sizeof(ctxt->stbuf))) { int bytes_recv = virStreamRecv(st, ctxt->stbuf + ctxt->stbuf_off, sizeof(ctxt->stbuf) - ctxt->stbuf_off); I notice https://libvirt.org/html/libvirt-libvirt-stream.html has an example using virStreamSend. Is that the preferred way to do the above?
On Wed, Jul 06, 2022 at 11:43:41AM -0400, Stan Cox wrote:
I am having a quandary with libvirt and am wondering if someone can shed some light.
Systemtap converts a probing and instrumentation language into a kernel module. The module can optionally be run remotely via ssh or libvirt. The libvirt mechanism is not working (not yet sure of timing of regression) The systemtap stap command pipes to a stapvirt command that is the libvirt interface. The remote is running a stapsh tool that receives the requests. The initial commands are sent and received okay (strace output on remote) but never receives the stap kernel module:
# local sent option data request [pid 11959] read(3, "option data\n", 4096) = 12 # remote says OK [pid 11959] write(3, "OK\n", 3) = 3 [pid 11959] poll([{fd=3, events=POLLIN}, {fd=0, events=0}, {fd=0, events=0}], 3, -1) = 1 ([{fd=3, revents=POLLIN}]) [pid 11959] --- SIGIO {si_signo=SIGIO, si_code=SI_KERNEL} --- [pid 11959] poll([{fd=3, events=POLLHUP}], 1, 0) = 0 (Timeout) [pid 11959] rt_sigreturn({mask=[]}) = 1 # local sent file ... request to download the module [pid 11959] read(3, "file 926928 stap_1f18b4b54e74602"..., 4096) = 58 # remote opens the module [pid 11959] openat(AT_FDCWD, "stap_1f18b4b54e74602a0a1f0685f2f7333e_1006.ko", O_WRONLY|O_CREAT|O_TRUNC, 0666) = 4 # but never receives it [pid 11959] read(3, "", 4096) = 0
The local sets up callbacks for stdin, stdout, stream: ctxt.stdin_w = virEventAddHandle(STDIN_FILENO, VIR_EVENT_HANDLE_READABLE, stdin_event, &ctxt, NULL); ... ctxt.stdout_w = virEventAddHandle(STDOUT_FILENO, 0, stdout_event, &ctxt, NULL); ... virStreamEventAddCallback(ctxt.st, VIR_STREAM_EVENT_READABLE | VIR_EVENT_HANDLE_WRITABLE, stream_event, &ctxt, NULL) < 0)
Then starts an even loop while (!disconnect) { if (virEventRunDefaultImpl() != 0) break; }
stream_event is notified for the command requests, but is not notified for the kernel module chunks:
stdin_event excerpt: bytes_read = read(fd, ctxt->termbuf + ctxt->termbuf_off, sizeof(ctxt->termbuf) - ctxt->termbuf_off); ... ctxt->termbuf_off += bytes_read; ... if (ctxt->termbuf_off) { // we have stuff to write to the stream virStreamEventUpdateCallback(ctxt->st, VIR_STREAM_EVENT_READABLE | VIR_STREAM_EVENT_WRITABLE); }
stream_event excerpt:
if ((events & VIR_STREAM_EVENT_READABLE) && (ctxt->stbuf_off < sizeof(ctxt->stbuf))) { int bytes_recv = virStreamRecv(st, ctxt->stbuf + ctxt->stbuf_off, sizeof(ctxt->stbuf) - ctxt->stbuf_off);
I notice https://libvirt.org/html/libvirt-libvirt-stream.html has an example using virStreamSend. Is that the preferred way to do the above?
The example is fairly simplistic and wouldn't suit your need where you have interleaved bi-directional I/O The virsh console code is likely the best matching example that we know is pretty reliable https://gitlab.com/libvirt/libvirt/-/blob/master/tools/virsh-console.c With regards, Daniel -- |: https://berrange.com -o- https://www.flickr.com/photos/dberrange :| |: https://libvirt.org -o- https://fstop138.berrange.com :| |: https://entangle-photo.org -o- https://www.instagram.com/dberrange :|
stapvirt seems to have a quite similar layout to virsh-console. All is fine for short packets: 1. Send file command to remote, stdin_event gets event stdin_event:1000 fd 0 events 0x1 stbuf_off 0 stbuf 0x7ffd0e99f848 termbuf_off 58 buf "file 926928 stap_1f18b4b" 2. stream_event gets event stream_event:1067 events 0x2 stbuf_off 0 stbuf 0x7ffd0e99f848 buf "file 926928 stap_1f18b4b" but stream_event is not triggered when kernel module is being sent in chunks 3. stdin_event reads first chunk of kernel module (which does virStreamEventUpdateCallback when it notices buffer contents) stdin_event:1000 fd 0 events 0x1 stbuf_off 0 stbuf 0x7ffd0e99f848 termbuf_off 1024 buf "^?ELF^B^A^A" 4. but stream_event is never triggered What triggers stream_event to be called such that the 2 case would be triggered but not the 4 case?
On Wed, Jul 06, 2022 at 05:25:32PM -0400, Stan Cox wrote:
stapvirt seems to have a quite similar layout to virsh-console. All is fine for short packets:
1. Send file command to remote, stdin_event gets event stdin_event:1000 fd 0 events 0x1 stbuf_off 0 stbuf 0x7ffd0e99f848 termbuf_off 58 buf "file 926928 stap_1f18b4b" 2. stream_event gets event stream_event:1067 events 0x2 stbuf_off 0 stbuf 0x7ffd0e99f848 buf "file 926928 stap_1f18b4b"
but stream_event is not triggered when kernel module is being sent in chunks
3. stdin_event reads first chunk of kernel module (which does virStreamEventUpdateCallback when it notices buffer contents) stdin_event:1000 fd 0 events 0x1 stbuf_off 0 stbuf 0x7ffd0e99f848 termbuf_off 1024 buf "^?ELF^B^A^A" 4. but stream_event is never triggered
What triggers stream_event to be called such that the 2 case would be triggered but not the 4 case?
I don't know - as best I can tell all your logic matches what is in virsh console. What libvirt version are you testing with, and have you tried a differnt version ? With regards, Daniel -- |: https://berrange.com -o- https://www.flickr.com/photos/dberrange :| |: https://libvirt.org -o- https://fstop138.berrange.com :| |: https://entangle-photo.org -o- https://www.instagram.com/dberrange :|
I turned on: LIBVIRT_DEBUG=debug which shows the deviation, indicated by "->". The working case, stdin event followed by stream event is: stapvirt: ##### stdin_event:1000 fd 0 events 0x1 stbuf_off 0 stbuf 0x7fff259eecb8 termbuf_off 58 buf "file 926928 stap_b861775" 2022-07-07 17:20:55.565+0000: 353069: debug : virStreamEventUpdateCallback:1102 : stream=0x2013150, events=3 2022-07-07 17:20:55.565+0000: 353069: debug : virNetClientStreamEventTimerUpdate:86 : Check timer rx=(nil) cbEvents=3 2022-07-07 17:20:55.565+0000: 353069: debug : virNetClientStreamEventTimerUpdate:91 : Enabling event timer 2022-07-07 17:20:55.565+0000: 353069: info : virEventGLibTimeoutUpdate:395 : EVENT_GLIB_UPDATE_TIMEOUT: timer=1 interval=0 2022-07-07 17:20:55.565+0000: 353069: debug : virEventGLibTimeoutUpdate:406 : Update timeout data=0x2017e00 timer=1 interval=0 ms 2022-07-07 17:20:55.565+0000: 353069: debug : virEventRunDefaultImpl:341 : running default event implementation ->2022-07-07 17:20:55.565+0000: 353069: debug : virEventGLibTimeoutDispatch:303 : Dispatch timeout data=0x2017e00 cb=0x7fe5f98436a0 timer=1 opaque=0x200d170 2022-07-07 17:20:55.565+0000: 353069: info : virEventGLibTimeoutDispatch:306 : EVENT_GLIB_DISPATCH_TIMEOUT: timer=1 cb=0x7fe5f98436a0 opaque=0x200d170 2022-07-07 17:20:55.565+0000: 353069: debug : virNetClientStreamEventTimer:116 : Got Timer dispatch events=2 cbEvents=3 rx=(nil) stapvirt: ##### stream_event:1043 st 0x2013150 events 0x2 stbuf_off 0 stbuf 0x7fff259eecb8 The case where stream event is not hit is: stapvirt: ##### stdin_event:1000 fd 0 events 0x1 stbuf_off 0 stbuf 0x7fff259eecb8 termbuf_off 1024 buf "^?ELF^B^A^A" 2022-07-07 17:20:55.565+0000: 353069: debug : virStreamEventUpdateCallback:1102 : stream=0x2013150, events=3 2022-07-07 17:20:55.565+0000: 353069: debug : virNetClientStreamEventTimerUpdate:86 : Check timer rx=(nil) cbEvents=3 2022-07-07 17:20:55.565+0000: 353069: debug : virNetClientStreamEventTimerUpdate:91 : Enabling event timer 2022-07-07 17:20:55.565+0000: 353069: info : virEventGLibTimeoutUpdate:395 : EVENT_GLIB_UPDATE_TIMEOUT: timer=1 interval=0 2022-07-07 17:20:55.565+0000: 353069: debug : virEventGLibTimeoutUpdate:406 : Update timeout data=0x2017e00 timer=1 interval=0 ms 2022-07-07 17:20:55.566+0000: 353069: debug : virEventRunDefaultImpl:341 : running default event implementation -> 2022-07-07 17:20:55.566+0000: 353069: debug : virEventGLibHandleDispatch:113 : Dispatch handler data=0x201e600 watch=2 fd=0 events=1 opaque=0x7fff259ee8a0 2022-07-07 17:20:55.566+0000: 353069: info : virEventGLibHandleDispatch:116 : EVENT_GLIB_DISPATCH_HANDLE: watch=2 events=1 cb=0x4046e9 opaque=0x7fff259ee8a0 stapvirt: ##### stdin_event:975 fd 0 events 0x1 termbuf_off 1024 1024 Hits stream Doesn't hit stream ... ... virEventRunDefaultImpl:341 virEventRunDefaultImpl:341 virEventGLibHandleDispatch:113 virEventGLibTimeoutDispatch:303 virEventGLibTimeoutDispatch:306 virNetClientStreamEventTimer:116 virEventGLibHandleDispatch:116 stream_event stdin_event
What libvirt version are you testing with, and have you tried a differnt version ?
This is: libvirt-8.1.0-2.fc36.x86_64 I have not tried another version but will give that a shot.
participants (2)
-
Daniel P. Berrangé -
Stan Cox