Description of problem: userList is not updated when queering guestAgent data. Version-Release number of selected component (if applicable): How reproducible: sometimes, usually after a VM runs for some time. Steps to Reproduce: 1. create a VM, install guest agent 2. login some users 3. query guest agent API 4. wait a few hours 5. login some new users 6 query guest agent API again Actual results: userList show the first login Expected results: userList show new logins Additional info: who command show one user logged in. API request: /apis/subresources.kubevirt.io/v1alpha3/namespaces/yzamir/virtualmachineinstances/fedora-iso/guestosinfo { "guestAgentVersion": "4.2.0", "hostname": "localhost.localdomain", "os": { "name": "Fedora", "kernelRelease": "5.6.16-300.fc32.x86_64", "version": "32 (Workstation Edition)", "prettyName": "Fedora 32 (Workstation Edition)", "versionId": "32", "kernelVersion": "#1 SMP Thu Jun 4 18:08:38 UTC 2020", "machine": "x86_64", "id": "fedora" }, "timezone": "IDT, 10800", "fsInfo": { "disks": [ { "diskName": "vda1", "mountPoint": "/boot", "fileSystemType": "ext4", "usedBytes": 235569152, "totalBytes": 952840192 }, { "diskName": "dm-0", "mountPoint": "/", "fileSystemType": "ext4", "usedBytes": 6816079872, "totalBytes": 12412723200 } ] } } Virt api logs: TTP/1.1","remoteAddress":"10.130.2.1","statusCode":200,"timestamp":"2020-06-16T14:30:06.865549Z","url":"/apis/subresources.kubevirt.io/v1alpha3/healthz","username":"-"} {"component":"virt-api","contentLength":714,"level":"info","method":"GET","pos":"filter.go:46","proto":"HTTP/1.1","remoteAddress":"10.128.0.1","statusCode":200,"timestamp":"2020-06-16T14:30:07.610706Z","url":"/apis/subresources.kubevirt.io/v1alpha3/namespaces/yzamir/virtualmachineinstances/fedora-iso/guestosinfo","username":"-"} {"component":"virt-api","contentLength":714,"level":"info","method":"GET","pos":"filter.go:46","proto":"HTTP/1.1","remoteAddress":"10.128.0.1","statusCode":200,"timestamp":"2020-06-16T14:30:07.642485Z","url":"/apis/subresources.kubevirt.io/v1alpha3/namespaces/yzamir/virtualmachineinstances/fedora-iso/guestosinfo","username":"-"} {"component":"virt-api","contentLength":714,"level":"info","method":"GET","pos":"filter.go:46","proto":"HTTP/1.1","remoteAddress":"10.128.0.1","statusCode":200,"timestamp":"2020-06-16T14:30:07.667576Z","url":"/apis/subresources.kubevirt.io/v1alpha3/namespaces/yzamir/virtualmachineinstances/fedora-iso/guestosinfo","username":"-"} {"component":"virt-api","contentLength":1686,"level":"info","method":"GET","pos":"filter.go:46","proto":"HTTP/1.1","remoteAddress":"10.128.0.1","statusCode":200,"timestamp":"2020-06-16T14:30:08.832820Z","url":"/apis/subresources.kubevirt.io/v1alpha3","username":"-"} virt-handler logs: {"component":"virt-handler","kind":"","level":"info","msg":"returning guestinfo :\u0026TypeMeta{Kind:,APIVersion:,}","name":"fedora-iso","namespace":"yzamir","pos":"lifecycle.go:128","timestamp":"2020-06-16T14:30:57.517806Z","uid":"db1668e0-1519-4e7d-b7cd-57bc9ed72312"} {"component":"virt-handler","level":"info","msg":"Retreiving guestinfo","pos":"lifecycle.go:101","timestamp":"2020-06-16T14:30:57.715311Z"} {"component":"virt-handler","kind":"","level":"info","msg":"Retreiving guestinfo from fedora-iso","name":"fedora-iso","namespace":"yzamir","pos":"lifecycle.go:109","timestamp":"2020-06-16T14:30:57.715414Z","uid":"db1668e0-1519-4e7d-b7cd-57bc9ed72312"} {"component":"virt-handler","level":"info","msg":"Retreiving guestinfo","pos":"lifecycle.go:101","timestamp":"2020-06-16T14:30:57.718107Z"} {"component":"virt-handler","kind":"","level":"info","msg":"Retreiving guestinfo from fedora-iso","name":"fedora-iso","namespace":"yzamir","pos":"lifecycle.go:109","timestamp":"2020-06-16T14:30:57.718257Z","uid":"db1668e0-1519-4e7d-b7cd-57bc9ed72312"} {"component":"virt-handler","kind":"","level":"info","msg":"returning guestinfo :\u0026TypeMeta{Kind:,APIVersion:,}","name":"fedora-iso","namespace":"yzamir","pos":"lifecycle.go:128","timestamp":"2020-06-16T14:30:57.723681Z","uid":"db1668e0-1519-4e7d-b7cd-57bc9ed72312"} {"component":"virt-handler","kind":"","level":"info","msg":"returning guestinfo :\u0026TypeMeta{Kind:,APIVersion:,}","name":"fedora-iso","namespace":"yzamir","pos":"lifecycle.go:128","timestamp":"2020-06-16T14:30:57.723839Z","uid":"db1668e0-1519-4e7d-b7cd-57bc9ed72312"} {"component":"virt-handler","level":"info","msg":"Retreiving guestinfo","pos":"lifecycle.go:101","timestamp":"2020-06-16T14:30:59.549204Z"} {"component":"virt-handler","kind":"","level":"info","msg":"Retreiving guestinfo from fedora-iso","name":"fedora-iso","namespace":"yzamir","pos":"lifecycle.go:109","timestamp":"2020-06-16T14:30:59.549288Z","uid":"db1668e0-1519-4e7d-b7cd-57bc9ed72312"} {"component":"virt-handler","kind":"","level":"info","msg":"returning guestinfo :\u0026TypeMeta{Kind:,APIVersion:,}","name":"fedora-iso","namespace":"yzamir","pos":"lifecycle.go:128","timestamp":"2020-06-16T14:30:59.554568Z","uid":"db1668e0-1519-4e7d-b7cd-57bc9ed72312"} :"fedora-iso","namespace":"yzamir","pos":"lifecycle.go:109","timestamp":"2020-06-16T14:29:15.742677Z","uid":"db1668e0-1519-4e7d-b7cd-57bc9ed72312"} {"component":"virt-handler","kind":"","level":"info","msg":"returning guestinfo :\u0026TypeMeta{Kind:,APIVersion:,}","name":"fedora-iso","namespace":"yzamir","pos":"lifecycle.go:128","timestamp":"2020-06-16T14:29:15.744682Z","uid":"db1668e0-1519-4e7d-b7cd-57bc9ed72312"} {"component":"virt-handler","kind":"","level":"info","msg":"Websocket connection upgraded","name":"fedora-iso","namespace":"yzamir","pos":"console.go:157","timestamp":"2020-06-16T14:29:17.829344Z","uid":"db1668e0-1519-4e7d-b7cd-57bc9ed72312"} {"component":"virt-handler","kind":"","level":"info","msg":"Connecting to proc/3752325/root/var/run/kubevirt-private/db1668e0-1519-4e7d-b7cd-57bc9ed72312/virt-vnc","name":"fedora-iso","namespace":"yzamir","pos":"console.go:158","timestamp":"2020-06-16T14:29:17.829442Z","uid":"db1668e0-1519-4e7d-b7cd-57bc9ed72312"} {"component":"virt-handler","kind":"","level":"info","msg":"Connected to proc/3752325/root/var/run/kubevirt-private/db1668e0-1519-4e7d-b7cd-57bc9ed72312/virt-vnc","name":"fedora-iso","namespace":"yzamir","pos":"console.go:168","timestamp":"2020-06-16T14:29:17.843976Z","uid":"db1668e0-1519-4e7d-b7cd-57bc9ed72312"} {"component":"virt-handler","kind":"","level":"error","msg":"error encountered reading from client (virt-api) websocket","name":"fedora-iso","namespace":"yzamir","pos":"console.go:179","reason":"websocket: close 1006 (abnormal closure): unexpected EOF","timestamp":"2020-06-16T14:29:33.535438Z","uid":"db1668e0-1519-4e7d-b7cd-57bc9ed72312"} {"component":"virt-handler","kind":"","level":"error","msg":"Error in proxing websocket and unix socket","name":"fedora-iso","namespace":"yzamir","pos":"console.go:188","reason":"websocket: close 1006 (abnormal closure): unexpected EOF","timestamp":"2020-06-16T14:29:33.535764Z","uid":"db1668e0-1519-4e7d-b7cd-57bc9ed72312"} {"component":"virt-handler","level":"info","msg":"http: response.WriteHeader on hijacked connection from kubevirt.io/kubevirt/vendor/github.com/emicklei/go-restful.(*Response).WriteHeader (response.go:220)\n","pos":"server.go:3012","timestamp":"2020-06-16T14:29:33.535864Z"} {"component":"virt-handler","kind":"","level":"error","msg":"error encountered reading from unix socket","name":"fedora-iso","namespace":"yzamir","pos":"console.go:173","reason":"read unix @-\u003e/var/run/kubevirt-private/db1668e0-1519-4e7d-b7cd-57bc9ed72312/virt-vnc: use of closed network connection","timestamp":"2020-06-16T14:29:33.535926Z","uid":"db1668e0-1519-4e7d-b7cd-57bc9ed72312"} {"component":"virt-handler","level":"info","msg":"Retreiving guestinfo","pos":"lifecycle.go:101","timestamp":"2020-06-16T14:29:33.603508Z"}
moving from component Guest Agent to VIrtualization
You see this issue on which setup, 2.3 or 2.4 ?
kubeVirtVersion: v0.29.0 with ocp-release:4.5.0-rc.1-x86_64
I suspect this might have been a symptom of the same root cause as: https://bugzilla.redhat.com/show_bug.cgi?id=1856979 Thus I suspect this might be fixed in the latest builds. Are you still able to reproduce this?
> Thus I suspect this might be fixed in the latest builds. Are you still able to reproduce this? Just run a quick test: created a VM, and logged in, should have seen one logged in user, but no users available in the api call, Req: http://localhost:9000/api/kubernetes/apis/subresources.kubevirt.io/v1alpha3/namespaces/yzamir/virtualmachineinstances/vm-example-01/guestosinfo Res: { "guestAgentVersion": "4.2.1", "hostname": "vm-example", "os": { "name": "Fedora", "kernelRelease": "5.6.6-300.fc32.x86_64", "version": "32 (Cloud Edition)", "prettyName": "Fedora 32 (Cloud Edition)", "versionId": "32", "kernelVersion": "#1 SMP Tue Apr 21 13:44:19 UTC 2020", "machine": "x86_64", "id": "fedora" }, "timezone": "UTC, 0", "fsInfo": { "disks": [ { "diskName": "vda1", "mountPoint": "/", "fileSystemType": "ext4", "usedBytes": 990404608, "totalBytes": 3927900160 } ] } } I'm using: imageID: >- docker.io/kubevirt/virt-api@sha256:54dda3a9e7b363f424caabcb0f3bc68826063f25c97d4572f54ed6489fabcb5c image: 'docker.io/kubevirt/virt-api:v0.31.0' virt-api log line: {"component":"virt-api","contentLength":537,"level":"info","method":"GET","pos":"filter.go:46","proto":"HTTP/1.1","remoteAddress":"10.128.0.1","statusCode":200,"timestamp":"2020-08-12T14:04:12.061016Z","url":"/apis/subresources.kubevirt.io/v1alpha3/namespaces/yzamir/virtualmachineinstances/vm-example-01/guestosinfo","username":"-"}
I was able to reproduce original issue: VM was up all night, and now new users are not shown in cnv Env: oc get csv -n openshift-cnv NAME DISPLAY VERSION REPLACES PHASE kubevirt-hyperconverged-operator.v2.4.1 OpenShift Virtualization 2.4.1 kubevirt-hyperconverged-operator.v2.4.0 Succeeded oc get clusterversions.config.openshift.io NAME VERSION AVAILABLE PROGRESSING SINCE STATUS version 4.5.4 True False 10d Cluster version is 4.5.4 [void@fedora-32 ~]$ who void ttyS0 2020-08-13 00:03 fedora pts/0 2020-08-13 07:39 (10.128.2.1) virtctl -n supported-os-common-templates-fedora-test-fedora-os-support userlist fedora-32 { "metadata": {}, "items": [ { "userName": "void", "loginTime": 1597277027.044367 } ] } but in libvirt all users are shown: [root@fedora-32 /]# virsh qemu-agent-command 1 '{"execute":"guest-get-users"}' {"return":[{"login-time":1597277027.044367,"user":"void"},{"login-time":1597304371.608503,"user":"fedora"}]}
There exists a workaround to this issue, and that is to use the "who" or "w" commands from the console.
Short Summary: Was unable to reproduce this issue on CNV-2.6.0 (cnv/virt-operator/v2.6.0-106) Lot changes were added around Guest Agent recently and this appears to be fixed with CNV-2.6.0 [kbidarka@localhost ocs]$ oc get vmi NAME AGE PHASE IP NODENAME vm-rhel83-nfs 4m49s Running 10.zz.xx.yy cnv06.redhat.com [kbidarka@localhost ocs]$ virtctl console vm-rhel83-nfs Successfully connected to vm-rhel83-nfs console. The escape sequence is ^] Red Hat Enterprise Linux 8.3 (Ootpa) Kernel 4.18.0-240.12.1.el8_3.x86_64 on an x86_64 Activate the web console with: systemctl enable --now cockpit.socket vm-rhel83-nfs login: cloud-user Password: [cloud-user@vm-rhel83-nfs ~]$ sudo su - [root@vm-rhel83-nfs ~]# useradd kbidarka [root@vm-rhel83-nfs ~]# passwd kbidarka Changing password for user kbidarka. New password: Retype new password: passwd: all authentication tokens updated successfully. [root@vm-rhel83-nfs ~]# exit logout [cloud-user@vm-rhel83-nfs ~]$ [kbidarka@localhost ocs]$ virtctl userlist vm-rhel83-nfs { "metadata": {}, "items": [ { "userName": "cloud-user", "loginTime": 1611862890.102064 } ] } [kbidarka@localhost git_world]$ virtctl guestosinfo vm-rhel83-nfs { "guestAgentVersion": "4.2.0", "hostname": "localhost.localdomain", "os": { "name": "Red Hat Enterprise Linux", "kernelRelease": "4.18.0-240.12.1.el8_3.x86_64", "version": "8.3 (Ootpa)", "prettyName": "Red Hat Enterprise Linux 8.3 (Ootpa)", "versionId": "8.3", "kernelVersion": "#1 SMP Wed Jan 13 06:05:15 EST 2021", "machine": "x86_64", "id": "rhel" }, "timezone": "EST, -18000", "userList": [ { "userName": "cloud-user", "loginTime": 1611862890.102064 } ], "fsInfo": { "disks": [ { "diskName": "vda2", "mountPoint": "/boot/efi", "fileSystemType": "vfat", "usedBytes": 7170048, "totalBytes": 104634368 }, { "diskName": "vda3", "mountPoint": "/", "fileSystemType": "xfs", "usedBytes": 1508306944, "totalBytes": 21357375488 } ] } } [kbidarka@localhost auth]$ oc get vmi NAME AGE PHASE IP NODENAME rhel8-random-access1 22h Running 10.zz.xx.yy cnv06.redhat.com vm-rhel83-nfs 23h Running 10.zz.xx.yy cnv06.redhat.com vm1-rhel83-nfs 23h Running 10.zz.xx.yy cnv05.redhat.com [kbidarka@localhost auth]$ virtctl console vm-rhel83-nfs Successfully connected to vm-rhel83-nfs console. The escape sequence is ^] [cloud-user@vm-rhel83-nfs ~]$ exit logout Red Hat Enterprise Linux 8.3 (Ootpa) Kernel 4.18.0-240.12.1.el8_3.x86_64 on an x86_64 Activate the web console with: systemctl enable --now cockpit.socket vm-rhel83-nfs login: kbidarka Password: [kbidarka@vm-rhel83-nfs ~]$ [kbidarka@vm-rhel83-nfs ~]$ uptime 14:25:36 up 23:49, 1 user, load average: 0.00, 0.00, 0.00 [kbidarka@vm-rhel83-nfs ~]$ [kbidarka@localhost migration]$ virtctl userlist vm-rhel83-nfs { "metadata": {}, "items": [ { "userName": "kbidarka", "loginTime": 1611946064.543369 } ] } --------------------------------- VIA the API also, we are able to get the user info of the new user who just logged in After 23hrs. --------------------------------- https://console-openshift-console.apps.redhat.com/api/kubernetes/apis/subresources.kubevirt.io/v1alpha3/namespaces/default/virtualmachineinstances/vm-rhel83-nfs/guestosinfo { "guestAgentVersion": "4.2.0", "hostname": "localhost.localdomain", "os": { "name": "Red Hat Enterprise Linux", "kernelRelease": "4.18.0-240.12.1.el8_3.x86_64", "version": "8.3 (Ootpa)", "prettyName": "Red Hat Enterprise Linux 8.3 (Ootpa)", "versionId": "8.3", "kernelVersion": "#1 SMP Wed Jan 13 06:05:15 EST 2021", "machine": "x86_64", "id": "rhel" }, "timezone": "EST, -18000", "userList": [ { "userName": "kbidarka", "loginTime": 1611946064.543369 } ], "fsInfo": { "disks": [ { "diskName": "vda2", "mountPoint": "/boot/efi", "fileSystemType": "vfat", "usedBytes": 7170048, "totalBytes": 104634368 }, { "diskName": "vda3", "mountPoint": "/", "fileSystemType": "xfs", "usedBytes": 1508306944, "totalBytes": 21357375488 } ] } } ------------------------------------------------------------------- Logged in another user, one from console and the other one from VNC ------------------------------------------------------------------- [kbidarka@localhost auth]$ virtctl userlist vm-rhel83-nfs { "metadata": {}, "items": [ { "userName": "cloud-user", "loginTime": 1611948660.530897 }, { "userName": "kbidarka", "loginTime": 1611946064.543369 } ] } --- https://console-openshift-console.apps.redhat.com/api/kubernetes/apis/subresources.kubevirt.io/v1alpha3/namespaces/default/virtualmachineinstances/vm-rhel83-nfs/guestosinfo { "guestAgentVersion": "4.2.0", "hostname": "localhost.localdomain", "os": { "name": "Red Hat Enterprise Linux", "kernelRelease": "4.18.0-240.12.1.el8_3.x86_64", "version": "8.3 (Ootpa)", "prettyName": "Red Hat Enterprise Linux 8.3 (Ootpa)", "versionId": "8.3", "kernelVersion": "#1 SMP Wed Jan 13 06:05:15 EST 2021", "machine": "x86_64", "id": "rhel" }, "timezone": "EST, -18000", "userList": [ { "userName": "cloud-user", "loginTime": 1611948660.530897 }, { "userName": "kbidarka", "loginTime": 1611946064.543369 } ], "fsInfo": { "disks": [ { "diskName": "vda2", "mountPoint": "/boot/efi", "fileSystemType": "vfat", "usedBytes": 7170048, "totalBytes": 104634368 }, { "diskName": "vda3", "mountPoint": "/", "fileSystemType": "xfs", "usedBytes": 1508306944, "totalBytes": 21357375488 } ] } }
Kedar - I managed to reprodcue on virt-operator v2.6.0-106 with RHEL 8.3: 1. Restart the qemu-guest-agent service in the VMI (from console) 2. Disconnect from console (including logout) rhel-8-3-1612184050-627989 login: cloud-user Password: Last login: Mon Feb 1 08:46:01 on ttyS0 [cloud-user@rhel-8-3-1612184050-627989 ~]$ w 08:52:25 up 56 min, 1 user, load average: 0.02, 0.01, 0.00 USER TTY FROM LOGIN@ IDLE JCPU PCPU WHAT cloud-us ttyS0 - 08:52 1.00s 0.01s 0.01s w [cloud-user@rhel-8-3-1612184050-627989 ~]$ [cnv-quserlistns@ssp01-t6h4t-executor ~]$ virtctl console -n ssp-supported-os-common-templates-rhel-test-rhel-os-support rhel-8-3-1612184050-627989 { "metadata": {}, "items": [] } The userList is empty; only if I am logged in via console do I get the info: $ virtctl userlist -n ssp-supported-os-common-templates-rhel-test-rhel-os-support rhel-8-3-1612184050-627989 { "metadata": {}, "items": [ { "userName": "cloud-user", "loginTime": 1612187844.519378 } ] }
Thanks for reproducing this. ok, this is new info to me that I need to restart "quemu-guest-agent service". This was no where mentioned in this bug. :) Let me retry this bug, with restarting the above "quemu-guest-agent" service and check.
Per comments #11 and #12 I've re-named this BZ for clarity as to what the actual issue is.
I am not able to reproduce it. It seems to be fixed in some previous releases. Can you check if this is still present?
This might have been fixed along with the other guest-agent bugs. Also all the tests in 4.10 related to user_info seem to have PASSED for ALL RHEL Versions. https://main-jenkins-csb-cnvqe.apps.ocp-c1.prod.psi.redhat.com/job/test-pytest-cnv-4.10-compute/12/testReport/tests.compute.ssp.supported_os.common_templates.rhel.test_rhel_os_support/TestCommonTemplatesRhel/ Also, all the tests in 4.10 related to guest-agent have PASSED for RHEL7, RHEL8 and RHEL9, looking at the same link above. Agree with 'Federico Fossemo' appears, we are not able to reproduce it anymore. [kbidarka@localhost cnv-tests]$ virtctl userlist vm-rhel84-ocs { "metadata": {}, "items": [ { "userName": "kbidarka", "loginTime": 1644256714.567439 } , { "userName": "cloud-user", "loginTime": 1644256696.477174 } ] } [kbidarka@localhost cnv-tests]$ virtctl console vm-rhel84-ocs Successfully connected to vm-rhel84-ocs console. The escape sequence is ^] [cloud-user@vm-rhel84-ocs ~]$ [cloud-user@vm-rhel84-ocs ~]$ sudo systemctl status qemu-guest-agent ● qemu-guest-agent.service - QEMU Guest Agent Loaded: loaded (/usr/lib/systemd/system/qemu-guest-agent.service; enabled; v> Active: active (running) since Mon 2022-02-07 09:55:56 EST; 3h 3min ago Main PID: 725 (qemu-ga) Tasks: 1 (limit: 4740) Memory: 3.8M CGroup: /system.slice/qemu-guest-agent.service └─725 /usr/bin/qemu-ga --method=virtio-serial --path=/dev/virtio-por> Feb 07 09:55:56 vm-rhel84-ocs systemd[1]: Started QEMU Guest Agent. [cloud-user@vm-rhel84-ocs ~]$ [cloud-user@vm-rhel84-ocs ~]$ sudo systemctl restart qemu-guest-agent [cloud-user@vm-rhel84-ocs ~]$ sudo systemctl status qemu-guest-agent ● qemu-guest-agent.service - QEMU Guest Agent Loaded: loaded (/usr/lib/systemd/system/qemu-guest-agent.service; enabled; v> Active: active (running) since Mon 2022-02-07 12:59:45 EST; 2s ago Main PID: 1754 (qemu-ga) Tasks: 1 (limit: 4740) Memory: 1.1M CGroup: /system.slice/qemu-guest-agent.service └─1754 /usr/bin/qemu-ga --method=virtio-serial --path=/dev/virtio-po> Feb 07 12:59:45 vm-rhel84-ocs systemd[1]: qemu-guest-agent.service: Succeeded. Feb 07 12:59:45 vm-rhel84-ocs systemd[1]: Stopped QEMU Guest Agent. Feb 07 12:59:45 vm-rhel84-ocs systemd[1]: Started QEMU Guest Agent. [cloud-user@vm-rhel84-ocs ~]$ [cloud-user@vm-rhel84-ocs ~]$ [kbidarka@localhost cnv-tests]$ [kbidarka@localhost cnv-tests]$ [kbidarka@localhost cnv-tests]$ virtctl userlist vm-rhel84-ocs { "metadata": {}, "items": [ { "userName": "kbidarka", "loginTime": 1644256714.567439 } , { "userName": "cloud-user", "loginTime": 1644256696.477174 } ] Closing this bug, as it "WORKSFORME" with 4.10.0