Bug 1316803

Summary: libvirt use wrong format to scan cpu info in /proc/qemupid/task/cputid/stat
Product: [Community] Virtualization Tools Reporter: Luyao Huang <lhuang>
Component: libvirtAssignee: Jiri Denemark <jdenemar>
Status: CLOSED NEXTRELEASE QA Contact:
Severity: medium Docs Contact:
Priority: medium    
Version: unspecifiedCC: jdenemar, rbalakri
Target Milestone: ---   
Target Release: ---   
Hardware: x86_64   
OS: Linux   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2016-03-29 14:47:49 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:

Description Luyao Huang 2016-03-11 07:48:51 UTC
Description of problem:
libvirt use wrong format to scan cpu info in /proc/qemupid/task/cputid/stat

Version-Release number of selected component (if applicable):
v1.3.2-119-g1e34a8f

How reproducible:
100%

Steps to Reproduce:
1.start a guest with new build libvirt:
# virsh start rhel7.0-rhel
Domain rhel7.0-rhel started

2.
check guest vcpuinfo

# virsh vcpuinfo rhel7.0-rhel
VCPU:           0
CPU:            0
State:          running
CPU Affinity:   yyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyy

VCPU:           1
CPU:            0
State:          running
CPU Affinity:   yyyyyyyyyyyyyyyyyyyyyyyyyyyyyyyy

VCPU:           2
CPU:            0
State:          running
CPU Affinity:   -y------------------------------


3. check log

2016-03-11 06:59:04.653+0000: 4842: warning : qemuGetProcessInfo:1475 : cannot parse process status data
2016-03-11 06:59:04.662+0000: 4842: warning : qemuGetProcessInfo:1475 : cannot parse process status data
2016-03-11 06:59:04.667+0000: 4842: warning : qemuGetProcessInfo:1475 : cannot parse process status data



Actual results:

libvirt cannot get cpu time any more.


Expected results:

parse info success

Additional info:

i have checked stat:

# cat /proc/`pidof qemu-kvm`/task/*/stat
5337 (qemu-kvm) S 1 5335 5335 0 -1 1212162432 12799 0 0 0 84 87 0 0 20 0 6 0 10148852 4755070976 104474 18446744073709551615 140268365217792 140268369549260 140721229100000 140721229098976 140268236880959 0 268444224 4096 16963 18446744071580887989 0 0 17 7 0 0 0 0 0 140268371646608 140268372896098 140268408942592 140721229108868 140721229111181 140721229111181 140721229111266 0
5355 (qemu-kvm) S 1 5335 5335 0 -1 1077944384 18 0 0 0 1 1 0 0 20 0 6 0 10148860 4755070976 104474 18446744073709551615 140268365217792 140268369549260 140721229100000 140268096051672 140268236900681 0 2147221247 4096 16963 18446744071579772004 0 0 -1 5 0 0 0 0 0 140268371646608 140268372896098 140268408942592 140721229108868 140721229111181 140721229111181 140721229111266 0
5374 (CPU 0/KVM) S 1 5335 5335 0 -1 138420416 17876 0 0 0 657 149 0 0 20 0 6 0 10148862 4755070976 104474 18446744073709551615 140268365217792 140268369549260 140721229100000 140263924304184 140268236886615 0 2147220671 4096 16963 18446744072104545539 0 0 -1 13 0 3 0 640 0 140268371646608 140268372896098 140268408942592 140721229108868 140721229111181 140721229111181 140721229111266 0
5376 (CPU 1/KVM) S 1 5335 5335 0 -1 138420416 454 0 0 0 150 10 0 0 20 0 6 0 10148863 4755070976 104474 18446744073709551615 140268365217792 140268369549260 140721229100000 140263915911480 140268236886615 0 2147220671 4096 16963 18446744072104545539 0 0 -1 26 0 5 0 149 0 140268371646608 140268372896098 140268408942592 140721229108868 140721229111181 140721229111181 140721229111266 0
5378 (CPU 2/KVM) S 1 5335 5335 0 -1 138420416 311 0 0 0 119 8 0 0 20 0 6 0 10148863 4755070976 104474 18446744073709551615 140268365217792 140268369549260 140721229100000 140263907518776 140268236886615 0 2147220671 4096 16963 18446744072104545539 0 0 -1 1 0 5 0 120 0 140268371646608 140268372896098 140268408942592 140721229108868 140721229111181 140721229111181 140721229111266 0
5410 (qemu-kvm) S 1 5335 5335 0 -1 1212162240 2040 0 0 0 19 41 0 0 20 0 6 0 10148868 4755070976 104474 18446744073709551615 140268365217792 140268369549260 140721229100000 140263748004112 140268236880765 0 2147220087 4096 16963 18446744071580887989 0 0 -1 5 0 0 0 0 0 140268371646608 140268372896098 140268408942592 140721229108868 140721229111181 140721229111181 140721229111266 0


you can see that vcpu tasks now is :

5374 (CPU 0/KVM) S 1 ...
         ^
         |
       here is the problem

so fscanf in qemuGetProcessInfo cannot parse it then report the warnning

Comment 1 Luyao Huang 2016-03-11 08:00:26 UTC
debug-threads=on cause the thread name been changed.

Comment 2 Jiri Denemark 2016-03-11 08:10:50 UTC
Yeah, that's what we get for using fscanf and we deserve the punishment.

Comment 3 Jiri Denemark 2016-03-29 14:47:49 UTC
Fixed upstream by v1.3.2-339-g801a5f6:

commit 801a5f65fa83f03eb8627875c670652cf8c30e4b
Author:     Jiri Denemark <jdenemar>
AuthorDate: Tue Mar 29 15:35:19 2016 +0200
Commit:     Jiri Denemark <jdenemar>
CommitDate: Tue Mar 29 16:41:20 2016 +0200

    qemu: Fix /proc/**/stat parsing
    
    Since commit v1.3.2-119-g1e34a8f which enabled debug-threads in QEMU
    qemuGetProcessInfo would fail to parse stats for any thread with a space
    in its name.
    
    https://bugzilla.redhat.com/show_bug.cgi?id=1316803
    
    Signed-off-by: Jiri Denemark <jdenemar>