Bug 1475725 - [Pegas1.0 P9] Guest "rcu_sched detected stalls on CPUs/tasks" under stress testing
[Pegas1.0 P9] Guest "rcu_sched detected stalls on CPUs/tasks" under stress t...
Status: CLOSED CURRENTRELEASE
Product: Red Hat Enterprise Linux 7
Classification: Red Hat
Component: qemu-kvm (Show other bugs)
7.4-Alt
ppc64le Linux
high Severity high
: rc
: 7.4-Alt
Assigned To: David Gibson
Zhengtong
:
Depends On: 1474963
Blocks: 1440030
  Show dependency treegraph
 
Reported: 2017-07-27 04:40 EDT by Zhengtong
Modified: 2017-08-07 02:50 EDT (History)
8 users (show)

See Also:
Fixed In Version:
Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of:
Environment:
Last Closed: 2017-08-06 21:43:38 EDT
Type: Bug
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Category: ---
oVirt Team: ---
RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: ---


Attachments (Terms of Use)


External Trackers
Tracker ID Priority Status Summary Last Updated
IBM Linux Technology Center 157330 None None None 2017-08-06 06:25 EDT

  None (edit)
Description Zhengtong 2017-07-27 04:40:41 EDT
Description of problem:
Doing stress test inside guest , will cause guest rcu_sched to detect stalls on CPUs/tasks.

Version-Release number of selected component (if applicable):
Host&Guest kernel:4.11.0-14.el7a.ppc64le
qemu-kvm-2.9.0-18.el7a
SLOF-20170303-4.git66d250e.el7.noarch

How reproducible:
always

Steps to Reproduce:
1.Boot one guest.
2.Run stress testing inside guest
#stress --vm 4 --vm-bytes 256M --vm-keep
3.Wait for the testing 

Actual results:
Guest got CPus/tasks stalls
[  466.877503] INFO: rcu_sched detected stalls on CPUs/tasks:
[  466.900303] 	(detected by 0, t=6004 jiffies, g=3829, c=3828, q=814)
[  466.900430] All QSes seen, last rcu_sched kthread activity 6001 (4294983984-4294977983), jiffies_till_next_fqs=1, root ->qsmask 0x0
[  466.900619] stress          R  running task        0  9461   9459 0x00040080
[  466.900745] Call Trace:
[  466.900838] [c0000000f9b7fa30] [c000000000b5fa30] sched_show_task.part.61+0x78/0x90 (unreliable)
[  466.900998] [c0000000f9b7faa0] [c0000000001b6690] rcu_check_callbacks+0xcb0/0xcd0
[  466.901137] [c0000000f9b7fbc0] [c0000000001beecc] update_process_times+0x7c/0xf0
[  466.901268] [c0000000f9b7fc00] [c0000000001da9e4] tick_sched_timer+0x84/0x1a0
[  466.901394] [c0000000f9b7fc40] [c0000000001bfc48] __hrtimer_run_queues+0x118/0x3e0
[  466.901519] [c0000000f9b7fce0] [c0000000001c0e84] hrtimer_interrupt+0xf4/0x300
[  466.901636] [c0000000f9b7fdb0] [c000000000023fd0] __timer_interrupt+0x90/0x270
[  466.901763] [c0000000f9b7fe00] [c0000000000243e0] timer_interrupt+0xa0/0xe0
[  466.901891] [c0000000f9b7fe30] [c000000000008f84] decrementer_common+0x114/0x120
[  466.902052] rcu_sched kthread starved for 6001 jiffies! g3829 c3828 f0x2 RCU_GP_WAIT_FQS(3) ->state=0x100
[  466.902219] rcu_sched       W    0     8      2 0x00000800
[  466.902314] Call Trace:
[  466.902364] [c0000000fe95f880] [c0000000fe929aa8] 0xc0000000fe929aa8 (unreliable)
[  466.902528] [c0000000fe95fa50] [c00000000001b910] __switch_to+0x300/0x470
[  466.902658] [c0000000fe95fab0] [c000000000b4bd48] __schedule+0x3a8/0xb70
[  466.902778] [c0000000fe95fb80] [c000000000b4c550] schedule+0x40/0xb0
[  466.902899] [c0000000fe95fbb0] [c000000000b52734] schedule_timeout+0x374/0x550
[  466.903047] [c0000000fe95fc90] [c0000000001b4324] rcu_gp_kthread+0x664/0x14e0
[  466.903216] [c0000000fe95fdc0] [c00000000013b070] kthread+0x160/0x1a0
[  466.903314] [c0000000fe95fe30] [c00000000000b368] ret_from_kernel_thread+0x5c/0x74
[  646.927305] INFO: rcu_sched detected stalls on CPUs/tasks:
[  646.929567] 	(detected by 2, t=24007 jiffies, g=3829, c=3828, q=2996)
[  646.930765] All QSes seen, last rcu_sched kthread activity 24004 (4295001987-4294977983), jiffies_till_next_fqs=1, root ->qsmask 0x0
[  646.932851] stress          R  running task        0  9460   9459 0x00040080
[  646.934043] Call Trace:
[  646.934697] [c0000000f9b43a30] [c000000000b5fa30] sched_show_task.part.61+0x78/0x90 (unreliable)
[  646.936217] [c0000000f9b43aa0] [c0000000001b6690] rcu_check_callbacks+0xcb0/0xcd0
[  646.937360] [c0000000f9b43bc0] [c0000000001beecc] update_process_times+0x7c/0xf0
[  646.938637] [c0000000f9b43c00] [c0000000001da9e4] tick_sched_timer+0x84/0x1a0
[  646.939712] [c0000000f9b43c40] [c0000000001bfc48] __hrtimer_run_queues+0x118/0x3e0
[  646.941176] [c0000000f9b43ce0] [c0000000001c0e84] hrtimer_interrupt+0xf4/0x300
[  646.942342] [c0000000f9b43db0] [c000000000023fd0] __timer_interrupt+0x90/0x270
[  646.943736] [c0000000f9b43e00] [c0000000000243e0] timer_interrupt+0xa0/0xe0
[  646.944666] [c0000000f9b43e30] [c000000000008f84] decrementer_common+0x114/0x120
[  646.946331] rcu_sched kthread starved for 24005 jiffies! g3829 c3828 f0x2 RCU_GP_WAIT_FQS(3) ->state=0x100
[  646.947875] rcu_sched       W    0     8      2 0x00000800


Expected results:
no cpu stalls call trace , the guest can run slower

Additional info:
Guest bootcmd:
/usr/libexec/qemu-kvm \
-name vm1 \
-machine pseries-rhel7.4.0 \
-m 4G \
-nodefaults \
-smp 4,cores=4,threads=1,sockets=1 \
-boot order=cdn,once=d,menu=off,strict=off \
-device nec-usb-xhci,id=xhci \
-device usb-tablet,id=usb-tablet0 \
-device usb-kbd,id=usb-kbd0 \
-chardev socket,id=qmp_id_qmpmonitor,path=/var/tmp/console0,server,nowait \
-mon chardev=qmp_id_qmpmonitor,mode=control \
-enable-kvm \
-device virtio-scsi-pci,bus=pci.0,addr=0x06,id=scsi-pci-0 \
-drive file=/home/zhengtli/rhel74-alt-sys-11929-20G.qcow2,format=qcow2,if=none,aio=threads,cache=none,media=disk,werror=stop,rerror=stop,id=drive-0 \
-device scsi-hd,bus=scsi-pci-0.0,id=scsi-hd-0,drive=drive-0,channel=0,scsi-id=0,lun=0,bootindex=0 \
-netdev tap,id=hostnet0,script=/etc/qemu-ifup \
-device virtio-net-pci,netdev=hostnet0,id=virtio-net-pci0,mac=40:f2:e9:cd:ac:03 \
-qmp tcp:0:3000,server,nowait \
-serial unix:serial,server,nowait \
-monitor stdio \
-vnc :18
Comment 2 Zhengtong 2017-07-27 04:45:25 EDT
Not hit the issue on  x86 with Pegas host and Pegas guest
Not hit the issue on  Power8 with RHEL7.4 host and Pegas guest
Comment 3 Zhengtong 2017-07-27 04:53:00 EDT
On Power9 Pegas/Pegas(Host/guest), while doing stress testing in guest, I feel the guest is stuck somewhere obviously, as the guest will take quit a long time to response to the command I inject in termination. That's different on x86, the guest is still keeping an very quick response while suffering stress test.

screen shot for the guest on P9:
top - 20:33:03 up 40 min,  3 users,  load average: 4.15, 4.65, 4.59
Tasks: 129 total,   7 running, 122 sleeping,   0 stopped,   0 zombie
%Cpu(s): 98.5 us,  1.4 sy,  0.0 ni,  0.0 id,  0.0 wa,  0.0 hi,  0.1 si,  0.0 st
KiB Mem :  3636672 total,  1808256 free,  1266944 used,   561472 buff/cache
KiB Swap:  2097088 total,  2097088 free,        0 used.  1772736 avail Mem 

  PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND                              
 9461 root      20   0  266112 261184    768 R  96.1  7.2  36:29.98 stress                               
 9460 root      20   0  266112 261184    768 R  95.0  7.2  36:32.37 stress                               
 9463 root      20   0  266112 261184    768 R  93.4  7.2  36:33.50 stress                               
 9462 root      20   0  266112 261184    768 R  88.7  7.2  36:35.63 stress   

screen shot for the guest on x86:
Tasks: 179 total,   6 running, 173 sleeping,   0 stopped,   0 zombie
%Cpu(s):100.0 us,  0.0 sy,  0.0 ni,  0.0 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
KiB Mem :  3880556 total,  1970784 free,  1359980 used,   549792 buff/cache
KiB Swap:  3145724 total,  3145724 free,        0 used.  2237664 avail Mem 

  PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND                  
25784 root      20   0  269424 262588    600 R 100.0  6.8  20:51.99 stress                   
25785 root      20   0  269424 262588    600 R 100.0  6.8  20:52.10 stress                   
25786 root      20   0  269424 262588    600 R 100.0  6.8  20:51.98 stress                   
25787 root      20   0  269424 262588    600 R  97.4  6.8  20:51.98 stress
Comment 4 Zhengtong 2017-07-27 04:56:04 EDT
There is only one time till now that the host stuck in the guest's stress testing on P9. But I didn't get the host system log now , because the host haven't recovered.
Comment 5 David Gibson 2017-07-27 21:42:20 EDT
Could you retest with the fix for bug 1474963 applied - it's possible it could have the same root cause.
Comment 6 Zhengtong 2017-07-27 22:46:25 EDT
Will have a try with that kernel, when the fixed kernel-alt verision of bug 1274963 coming out.
Comment 7 Zhengtong 2017-07-27 23:03:10 EDT
sorry the bug should be "bug 1474963" in last commit
Comment 8 David Gibson 2017-08-03 00:55:23 EDT
You'll want to retest with -19.  That should have the fix for bug 1474963 and also for the guest boot failure that was in 15..18 (unrelated but would prevent testing).
Comment 9 Zhengtong 2017-08-04 03:53:56 EDT
Update  kernel to 4.11.0-19.el7a.ppc64le. The issues seems fixed in this version

Run stress testing for ~4.5 hours, the guest performed good, and no cpu stalls.
Comment 10 David Gibson 2017-08-06 21:43:38 EDT
Ok, looks like it had the same cause as bug 1474963.

Note You need to log in before you can comment on or make changes to this bug.