2014-01-21 16:38:21

by Toralf Förster

[permalink] [raw]
Subject: 3.13 hangs when I tried to start a KVM at a 32 bit stable Gentoo

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA256

Well,

sysrq at least works, the output of

$>sudo strings /var/log/messages | grep -e 'Jan 21 17:17:46' -e 'Jan 21 17:18:..' -e 'Jan 21 17:2[01]:..' > messages.txt

is attached - the .config is attached too.


- --
MfG/Sincerely
Toralf Förster
pgp finger print:1A37 6F99 4A9D 026F 13E2 4DCF C4EA CDDE 0076 E94E
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v2.0.22 (GNU/Linux)
Comment: Using GnuPG with Thunderbird - http://www.enigmail.net/

iF4EAREIAAYFAlLeom8ACgkQxOrN3gB26U4p5AD+KieL23Dlz43H0Eanoxej+/Ob
bVnCKmi4ExEkN68hPnEA/iiISwgaHlDx86abBCrEc1alfyfmyZMvy5S8bYowR2kP
=d9Ln
-----END PGP SIGNATURE-----


Attachments:
messages.txt (28.02 kB)
.config (83.61 kB)
messages.txt.sig (96.00 B)
.config.sig (96.00 B)
Download all attachments

2014-01-23 18:56:00

by Dave Hansen

[permalink] [raw]
Subject: Re: 3.13 hangs when I tried to start a KVM at a 32 bit stable Gentoo

On 01/21/2014 08:38 AM, Toralf Förster wrote:
> Jan 21 17:18:57 n22 kernel: INFO: rcu_sched self-detected stall on CPU { 2} (t=60001 jiffies g=18494 c=18493 q=183951)
> Jan 21 17:18:57 n22 kernel: sending NMI to all CPUs:
> Jan 21 17:18:57 n22 kernel: NMI backtrace for cpu 2
> Jan 21 17:18:57 n22 kernel: CPU: 2 PID: 6779 Comm: qemu-system-x86 Not tainted 3.13.0 #3
> Jan 21 17:18:57 n22 kernel: Hardware name: LENOVO 4180F65/4180F65, BIOS 83ET75WW (1.45 ) 05/10/2013
> Jan 21 17:18:57 n22 kernel: task: e921c370 ti: e5f36000 task.ti: e5f36000

I'm seeing a very similar hang with an ubuntu guest and a custom kernel.
I'm on commit 0dc3fd0249a, and it's 100% reproducible every time I run KVM.

Cc-ing a few more folks...

2014-01-23 19:33:35

by Dave Hansen

[permalink] [raw]
Subject: Re: 3.13 hangs when I tried to start a KVM at a 32 bit stable Gentoo

On 01/23/2014 10:55 AM, Dave Hansen wrote:
> On 01/21/2014 08:38 AM, Toralf Förster wrote:
>> Jan 21 17:18:57 n22 kernel: INFO: rcu_sched self-detected stall on CPU { 2} (t=60001 jiffies g=18494 c=18493 q=183951)
>> Jan 21 17:18:57 n22 kernel: sending NMI to all CPUs:
>> Jan 21 17:18:57 n22 kernel: NMI backtrace for cpu 2
>> Jan 21 17:18:57 n22 kernel: CPU: 2 PID: 6779 Comm: qemu-system-x86 Not tainted 3.13.0 #3
>> Jan 21 17:18:57 n22 kernel: Hardware name: LENOVO 4180F65/4180F65, BIOS 83ET75WW (1.45 ) 05/10/2013
>> Jan 21 17:18:57 n22 kernel: task: e921c370 ti: e5f36000 task.ti: e5f36000
>
> I'm seeing a very similar hang with an ubuntu guest and a custom kernel.
> I'm on commit 0dc3fd0249a, and it's 100% reproducible every time I run KVM.

Did a little more LKML digging and found this:

http://marc.info/?l=linux-kernel&m=139038631607917&q=raw

Peter's fix works for me. I'm also running a CONFIG_PREEMPT_VOLUNTARY=y
config.

2014-01-23 19:50:19

by Toralf Förster

[permalink] [raw]
Subject: Re: 3.13 hangs when I tried to start a KVM at a 32 bit stable Gentoo

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA256

On 01/23/2014 08:33 PM, Dave Hansen wrote:
> On 01/23/2014 10:55 AM, Dave Hansen wrote:
>> On 01/21/2014 08:38 AM, Toralf Förster wrote:
>>> Jan 21 17:18:57 n22 kernel: INFO: rcu_sched self-detected stall on CPU { 2} (t=60001 jiffies g=18494 c=18493 q=183951)
>>> Jan 21 17:18:57 n22 kernel: sending NMI to all CPUs:
>>> Jan 21 17:18:57 n22 kernel: NMI backtrace for cpu 2
>>> Jan 21 17:18:57 n22 kernel: CPU: 2 PID: 6779 Comm: qemu-system-x86 Not tainted 3.13.0 #3
>>> Jan 21 17:18:57 n22 kernel: Hardware name: LENOVO 4180F65/4180F65, BIOS 83ET75WW (1.45 ) 05/10/2013
>>> Jan 21 17:18:57 n22 kernel: task: e921c370 ti: e5f36000 task.ti: e5f36000
>>
>> I'm seeing a very similar hang with an ubuntu guest and a custom kernel.
>> I'm on commit 0dc3fd0249a, and it's 100% reproducible every time I run KVM.
>
> Did a little more LKML digging and found this:
>
> http://marc.info/?l=linux-kernel&m=139038631607917&q=raw
>
Hhm, that patch cannot be applied to 3.13.0 kernel :-(

> Peter's fix works for me. I'm also running a CONFIG_PREEMPT_VOLUNTARY=y
> config.
>
I do have :

n22 /usr/src/linux # zgrep CONFIG_PREEMPT /proc/config.gz
# CONFIG_PREEMPT_RCU is not set
CONFIG_PREEMPT_NOTIFIERS=y
# CONFIG_PREEMPT_NONE is not set
CONFIG_PREEMPT_VOLUNTARY=y
# CONFIG_PREEMPT is not set

>

What makes the situation really annyoing - sometimes I just can restart my wlan device it the system works normal, but sometimes the whole system hangs and for those cases then sometimes not even sysrq buttons do work.

What I see in /var/log/messages are those lines :

Jan 23 19:23:15 n22 kernel: iwlwifi 0000:03:00.0: Error sending POWER_TABLE_CMD: time out after 2000ms.
Jan 23 19:23:15 n22 kernel: iwlwifi 0000:03:00.0: Current CMD queue read_ptr 158 write_ptr 159
Jan 23 19:23:15 n22 kernel: iwlwifi 0000:03:00.0: Loaded firmware version: 18.168.6.1
Jan 23 19:23:15 n22 kernel: iwlwifi 0000:03:00.0: 0x00000000 | OK Jan 23 19:23:15 n22 kernel: iwlwifi 0000:03:00.0: 0x00000000 | uPc
Jan 23 19:23:15 n22 kernel: iwlwifi 0000:03:00.0: 0x00000000 | branchlink1
Jan 23 19:23:15 n22 kernel: iwlwifi 0000:03:00.0: 0x00000000 | branchlink2
Jan 23 19:23:15 n22 kernel: iwlwifi 0000:03:00.0: 0x00000000 | interruptlink1
Jan 23 19:23:15 n22 kernel: iwlwifi 0000:03:00.0: 0x00000000 | interruptlink2
Jan 23 19:23:15 n22 kernel: iwlwifi 0000:03:00.0: 0x00000000 | data1
Jan 23 19:23:15 n22 kernel: iwlwifi 0000:03:00.0: 0x00000000 | data2
Jan 23 19:23:15 n22 kernel: iwlwifi 0000:03:00.0: 0x00000000 | line
Jan 23 19:23:15 n22 kernel: iwlwifi 0000:03:00.0: 0x00000000 | beacon time
Jan 23 19:23:15 n22 kernel: iwlwifi 0000:03:00.0: 0x00000000 | tsf low
Jan 23 19:23:15 n22 kernel: iwlwifi 0000:03:00.0: 0x00000000 | tsf hi
Jan 23 19:23:15 n22 kernel: iwlwifi 0000:03:00.0: 0x00000000 | time gp1
Jan 23 19:23:15 n22 kernel: iwlwifi 0000:03:00.0: 0x00000000 | time gp2
Jan 23 19:23:15 n22 kernel: iwlwifi 0000:03:00.0: 0x00000000 | time gp3
Jan 23 19:23:15 n22 kernel: iwlwifi 0000:03:00.0: 0x00000000 | uCode version
Jan 23 19:23:15 n22 kernel: iwlwifi 0000:03:00.0: 0x00000000 | hw version
Jan 23 19:23:15 n22 kernel: iwlwifi 0000:03:00.0: 0x00000000 | board version
Jan 23 19:23:15 n22 kernel: iwlwifi 0000:03:00.0: 0x00000000 | hcmd
Jan 23 19:23:15 n22 kernel: iwlwifi 0000:03:00.0: 0x00000000 | isr0
Jan 23 19:23:15 n22 kernel: iwlwifi 0000:03:00.0: 0x00000000 | isr1
Jan 23 19:23:15 n22 kernel: iwlwifi 0000:03:00.0: 0x00000000 | isr2
Jan 23 19:23:15 n22 kernel: iwlwifi 0000:03:00.0: 0x00000000 | isr3
Jan 23 19:23:15 n22 kernel: iwlwifi 0000:03:00.0: 0x00000000 | isr4
Jan 23 19:23:15 n22 kernel: iwlwifi 0000:03:00.0: 0x00000000 | isr_pref
Jan 23 19:23:15 n22 kernel: iwlwifi 0000:03:00.0: 0x00000000 | wait_event
Jan 23 19:23:15 n22 kernel: iwlwifi 0000:03:00.0: 0x00000000 | l2p_control
Jan 23 19:23:15 n22 kernel: iwlwifi 0000:03:00.0: 0x00000000 | l2p_duration
Jan 23 19:23:15 n22 kernel: iwlwifi 0000:03:00.0: 0x00000000 | l2p_mhvalid
Jan 23 19:23:15 n22 kernel: iwlwifi 0000:03:00.0: 0x00000000 | l2p_addr_match
Jan 23 19:23:15 n22 kernel: iwlwifi 0000:03:00.0: 0x00000000 | lmpm_pmg_sel
Jan 23 19:23:15 n22 kernel: iwlwifi 0000:03:00.0: 0x00000000 | timestamp
Jan 23 19:23:15 n22 kernel: iwlwifi 0000:03:00.0: 0x00000000 | flow_handler
Jan 23 19:23:15 n22 kernel: iwlwifi 0000:03:00.0: Start IWL Event Log Dump: nothing in log
Jan 23 19:23:15 n22 kernel: iwlwifi 0000:03:00.0: set power fail, ret = -110
Jan 23 19:23:15 n22 kernel: iwlwifi 0000:03:00.0: iwl_trans_wait_tx_queue_empty bad state = 0
Jan 23 19:23:15 n22 kernel: ieee80211 phy0: Hardware restart was requested
Jan 23 19:23:15 n22 kernel: iwlwifi 0000:03:00.0: L1 Enabled; Disabling L0S
Jan 23 19:23:15 n22 kernel: iwlwifi 0000:03:00.0: Radio type=0x1-0x2-0x0
Jan 23 19:23:20 n22 kernel: iwlwifi 0000:03:00.0: Failed to load firmware chunk!
Jan 23 19:23:20 n22 kernel: iwlwifi 0000:03:00.0: Could not load the [0] uCode section
Jan 23 19:23:20 n22 kernel: iwlwifi 0000:03:00.0: Failed to start RT ucode: -110
Jan 23 19:23:20 n22 kernel: iwlwifi 0000:03:00.0: Unable to initialize device.
Jan 23 19:23:28 n22 dhcpcd[4878]: wlp3s0: carrier lost
Jan 23 19:23:28 n22 kernel: iwlwifi 0000:03:00.0: Fw not loaded - dropping CMD: 1e Jan 23 19:23:28 n22 kernel: iwlwifi 0000:03:00.0: Couldn't flush the AGG queue Jan 23 19:23:28 n22 kernel: iwlwifi 0000:03:00.0: Fw not loaded - dropping CMD: 18 Jan 23 19:23:28 n22 kernel: wlp3s0: HW problem - can not stop rx aggregation for 08:96:d7:05:f9:2a tid 0 Jan 23 19:23:28 n22 kernel: iwlwifi 0000:03:00.0: iwl_trans_wait_tx_queue_empty bad state = 0 Jan 23 19:23:28 n22 kernel: cfg80211: Calling CRDA to update world regulatory domain Jan 23 19:23:28 n22 kernel: cfg80211: World regulatory domain updated:
Jan 23 19:23:28 n22 kernel: cfg80211: (start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp) Jan 23 19:23:28 n22 kernel: cfg80211: (2402000 KHz - 2472000 KHz @ 40000 KHz), (300 mBi, 2000 mBm) Jan 23 19:23:28 n22 kernel: cfg80211: (2457000 KHz - 2482000 KHz @ 40000 KHz), (300 mBi, 2000 mBm) Jan 23 19:23:28 n22 kernel: cfg80211: (2474000 KHz - 2494000 KHz @ 20000 KHz), (300 mBi, 2000 mBm) Jan 23 19:23:28 n22 kernel: cfg80211: (5170000 KHz - 5250000 KHz @ 40000 KHz), (300 mBi, 2000 mBm) Jan 23 19:23:28 n22 kernel: cfg80211: (5735000 KHz - 5835000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
Jan 23 19:23:28 n22 wpa_cli: interface wlp3s0 DISCONNECTED
Jan 23 19:23:28 n22 wpa_cli: executing 'false /etc/init.d/net.wlp3s0 --quiet stop' failed
Jan 23 19:23:28 n22 kernel: iwlwifi 0000:03:00.0: Request scan called when driver not ready.
Jan 23 19:23:29 n22 kernel: iwlwifi 0000:03:00.0: Request scan called when driver not ready.
Jan 23 19:23:29 n22 ntpd[5421]: Deleting interface #3 wlp3s0, 192.168.178.21#123, interface stats: received=12, sent=12, dropped=0, active_time=188 secs
Jan 23 19:23:29 n22 ntpd[5421]: 62.116.162.126 interface 192.168.178.21 -> (none)
Jan 23 19:23:29 n22 ntpd[5421]: 131.188.3.220 interface 192.168.178.21 -> (none)
Jan 23 19:23:29 n22 ntpd[5421]: 46.165.212.205 interface 192.168.178.21 -> (none)
Jan 23 19:23:29 n22 ntpd[5421]: 46.4.54.78 interface 192.168.178.21 -> (none)
Jan 23 19:23:29 n22 ntpd[5421]: peers refreshed
Jan 23 19:23:30 n22 kernel: iwlwifi 0000:03:00.0: Request scan called when driver not ready.
Jan 23 19:23:31 n22 kernel: iwlwifi 0000:03:00.0: Request scan called when driver not ready.
Jan 23 19:23:32 n22 kernel: iwlwifi 0000:03:00.0: Request scan called when driver not ready.


The last line now repeats every second till I either restart the wlan0 device or the system completely hangs.



- --
MfG/Sincerely
Toralf Förster
pgp finger print:1A37 6F99 4A9D 026F 13E2 4DCF C4EA CDDE 0076 E94E


- --
MfG/Sincerely
Toralf Förster
pgp finger print:1A37 6F99 4A9D 026F 13E2 4DCF C4EA CDDE 0076 E94E
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v2.0.22 (GNU/Linux)
Comment: Using GnuPG with Thunderbird - http://www.enigmail.net/

iF4EAREIAAYFAlLhcnMACgkQxOrN3gB26U5pNgD9Gnd/2LOwCL/Ca2s3eeDje+Zz
lzAZKSoLk+VQXn5R0qgA/RZV4WW4BTT/xSc1E378TlmctXQ+AX7iJ/FbgfZXyLvB
=Tw8L
-----END PGP SIGNATURE-----

2014-01-24 12:37:31

by Paolo Bonzini

[permalink] [raw]
Subject: Re: 3.13 hangs when I tried to start a KVM at a 32 bit stable Gentoo

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

Il 23/01/2014 20:50, Toralf Förster ha scritto:
| What makes the situation really annyoing - sometimes I just can
| restart my wlan device it the system works normal, but sometimes
| the whole system hangs and for those cases then sometimes not even
| sysrq buttons do work.

Can you reproduce it with the wlan driver disabled completely?

Paolo
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v2.0.22 (GNU/Linux)
Comment: Using GnuPG with Thunderbird - http://www.enigmail.net/

iQIcBAEBAgAGBQJS4l5cAAoJEBvWZb6bTYbyC0AP/jrHp8WUqDjgv/1kJYcYb0+0
cSM8jqcutYCcMAKXTsKGgQj4gWdw7q/bEo4lWAEX8fQqxOfFZjBZjhTuA66XF010
fi+nOCEwjafMUeflPZaSZr34KGSix1FTtmcdzz55Kzkh+A4hZJj2NgaAYr8KFsWW
0hCoW7+MHWTRsNLIZk1ms2H/lItz19gnO9CkNYWqSIxBtx1/le5v8LNi20OkHKCz
mdemG6DSwj9sE+jfezDjZ7jV/a+RBv4Pi0v71YPEUEa7HCiyKxddVAgD0KrvMwzF
2A7H4+rTwsJLnWTKFyMdoeUUz6iC5Rntq+B4ltHVXKjN2O5bG0aqmG+cURbvXrFF
y9EzChdaEikPlYJHp/ci2NOB8NJlB6oEb9uO3k2kRITdWsr3iK5gCZE3fu99ziz4
JmNPUpFGTy5dnQVI/edsuZDyafRYVq3U4CpP+drnWxbic4aH7nCTv2iR5Op4pnhd
LQlmt0MkZAyF9+6XFNBAAfPnfV0YPBHydCxhC2UaOmqqNXiYILW65dCD5aQiXq1y
lQi2dc6i7MYbVmc28I45LV/BFD4zn622c5ges0gKw2bshgzhQm12jWHJ+dMsLDp/
qpFFvaGoqWCNJZo9FCH6vaTiN5KNUyiUOZjvKVa3u959xC9BK8nh3vTWHxinK2Yt
Do62ZMYWJbljdgTvMN7d
=cfJ7
-----END PGP SIGNATURE-----

2014-01-25 09:48:19

by Toralf Förster

[permalink] [raw]
Subject: Re: 3.13 hangs when I tried to start a KVM at a 32 bit stable Gentoo

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA256

On 01/24/2014 01:36 PM, Paolo Bonzini wrote:
> Il 23/01/2014 20:50, Toralf Förster ha scritto: | What makes the
> situation really annyoing - sometimes I just can | restart my wlan
> device it the system works normal, but sometimes | the whole system
> hangs and for those cases then sometimes not even | sysrq buttons
> do work.
>
> Can you reproduce it with the wlan driver disabled completely?
>
yes - root cause is not the wlan - that's just a victim.
> Paolo
>

- --
MfG/Sincerely
Toralf Förster
pgp finger print:1A37 6F99 4A9D 026F 13E2 4DCF C4EA CDDE 0076 E94E
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v2.0.22 (GNU/Linux)
Comment: Using GnuPG with Thunderbird - http://www.enigmail.net/

iF4EAREIAAYFAlLjiF0ACgkQxOrN3gB26U64DwD/c60zqwUORstYkSD2I1AarWLO
/4QVwWo8hW8bUg6f3SEA/2Wv7jkJTtkfTUVEyZZxeEJaNP+RChsmGSoU77Dl1G7T
=VMnB
-----END PGP SIGNATURE-----

2014-01-26 10:40:17

by Toralf Förster

[permalink] [raw]
Subject: Re: 3.13 hangs when I tried to start a KVM at a 32 bit stable Gentoo

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA256

On 01/24/2014 01:36 PM, Paolo Bonzini wrote:
> Il 23/01/2014 20:50, Toralf Förster ha scritto:
> | What makes the situation really annyoing - sometimes I just can
> | restart my wlan device it the system works normal, but sometimes
> | the whole system hangs and for those cases then sometimes not even
> | sysrq buttons do work.
>
> Can you reproduce it with the wlan driver disabled completely?

yes - with CONFIG_WLAN=n I do get a similar thing :


Jan 26 11:23:17 n22 kernel: NET: Registered protocol family 17
Jan 26 11:23:17 n22 kernel: device vnet0 entered promiscuous mode
Jan 26 11:23:17 n22 kernel: br0: port 4(vnet0) entered forwarding state
Jan 26 11:23:17 n22 kernel: br0: port 4(vnet0) entered forwarding state
Jan 26 11:23:17 n22 kernel: IPv6: ADDRCONF(NETDEV_CHANGE): br0: link becomes ready
Jan 26 11:23:17 n22 kernel: cgroup: libvirtd (6113) created nested cgroup for controller "memory" which has incomplete hierarchy support. Nested cgroups may change behavior in the future.
Jan 26 11:23:17 n22 kernel: cgroup: "memory" requires setting use_hierarchy to 1 on the root.
Jan 26 11:23:19 n22 ntpd[6015]: Listen normally on 5 br0 fe80::837:18ff:feae:caf0 UDP 123
Jan 26 11:23:19 n22 ntpd[6015]: Listen normally on 6 vnet0 fe80::fc54:ff:fed0:f1eb UDP 123
Jan 26 11:23:19 n22 ntpd[6015]: peers refreshed
Jan 26 11:23:35 n22 kernel: br0: port 4(vnet0) entered disabled state
Jan 26 11:23:35 n22 kernel: device vnet0 left promiscuous mode
Jan 26 11:23:35 n22 kernel: br0: port 4(vnet0) entered disabled state
Jan 26 11:23:38 n22 ntpd[6015]: Deleting interface #6 vnet0, fe80::fc54:ff:fed0:f1eb#123, interface stats: received=0, sent=0, dropped=0, active_time=19 secs
Jan 26 11:23:38 n22 ntpd[6015]: peers refreshed
Jan 26 11:23:45 n22 kernel: device vnet0 entered promiscuous mode
Jan 26 11:23:45 n22 kernel: br0: port 4(vnet0) entered forwarding state
Jan 26 11:23:45 n22 kernel: br0: port 4(vnet0) entered forwarding state
Jan 26 11:23:48 n22 ntpd[6015]: Listen normally on 7 vnet0 fe80::fc54:ff:fed0:f1eb UDP 123
Jan 26 11:23:48 n22 ntpd[6015]: peers refreshed
Jan 26 11:24:09 n22 kernel: br0: port 4(vnet0) entered disabled state
Jan 26 11:24:09 n22 kernel: device vnet0 left promiscuous mode
Jan 26 11:24:09 n22 kernel: br0: port 4(vnet0) entered disabled state
Jan 26 11:24:11 n22 ntpd[6015]: Deleting interface #7 vnet0, fe80::fc54:ff:fed0:f1eb#123, interface stats: received=0, sent=0, dropped=0, active_time=23 secs
Jan 26 11:24:11 n22 ntpd[6015]: peers refreshed
Jan 26 11:24:28 n22 kernel: device vnet0 entered promiscuous mode
Jan 26 11:24:28 n22 kernel: br0: port 4(vnet0) entered forwarding state
Jan 26 11:24:28 n22 kernel: br0: port 4(vnet0) entered forwarding state
Jan 26 11:24:31 n22 ntpd[6015]: Listen normally on 8 vnet0 fe80::fc54:ff:fed0:f1eb UDP 123
Jan 26 11:24:31 n22 ntpd[6015]: peers refreshed
Jan 26 11:24:57 n22 kernel: hda-intel: IRQ timing workaround is activated for card #0. Suggest a bigger bdl_pos_adj.
Jan 26 11:25:34 n22 kernel: INFO: rcu_sched self-detected stall on CPU { 3} (t=60000 jiffies g=23149 c=23148 q=7132)
Jan 26 11:25:34 n22 kernel: sending NMI to all CPUs:
Jan 26 11:25:34 n22 kernel: NMI backtrace for cpu 3
Jan 26 11:25:34 n22 kernel: CPU: 3 PID: 6523 Comm: qemu-system-x86 Not tainted 3.13.0 #5
Jan 26 11:25:34 n22 kernel: Hardware name: LENOVO 4180F65/4180F65, BIOS 83ET75WW (1.45 ) 05/10/2013
Jan 26 11:25:34 n22 kernel: task: e410c8a0 ti: eec60000 task.ti: eec60000
Jan 26 11:25:34 n22 kernel: EIP: 0060:[<c1255bed>] EFLAGS: 00000006 CPU: 3
Jan 26 11:25:34 n22 kernel: EIP is at __const_udelay+0xd/0x20
Jan 26 11:25:34 n22 kernel: EAX: 01062560 EBX: 00002710 ECX: c1557e60 EDX: 00278af4
Jan 26 11:25:34 n22 kernel: ESI: c155c500 EDI: f3627c80 EBP: eec61c64 ESP: eec61c64
Jan 26 11:25:34 n22 kernel: DS: 007b ES: 007b FS: 00d8 GS: 00e0 SS: 0068
Jan 26 11:25:34 n22 kernel: CR0: 80050033 CR2: 00000000 CR3: 23c2e000 CR4: 000427f0
Jan 26 11:25:34 n22 kernel: Stack:
Jan 26 11:25:34 n22 kernel: eec61c74 c102dc75 c14b9db5 c155c500 eec61cb8 c108ba1c c14c3ac0 0000ea60
Jan 26 11:25:34 n22 kernel: 00005a6d 00005a6c 00001bdc c106aadd 00000001 c155c500 c1595544 f3627c80
Jan 26 11:25:34 n22 kernel: 00001bdc 00000003 e410c8a0 00000000 00000003 eec61ccc c104a2fb f3627ec0
Jan 26 11:25:34 n22 kernel: Call Trace:
Jan 26 11:25:34 n22 kernel: [<c102dc75>] arch_trigger_all_cpu_backtrace+0x55/0x70
Jan 26 11:25:34 n22 kernel: [<c108ba1c>] rcu_check_callbacks+0x38c/0x590
Jan 26 11:25:34 n22 kernel: [<c106aadd>] ? account_system_time+0xbd/0x170
Jan 26 11:25:34 n22 kernel: [<c104a2fb>] update_process_times+0x3b/0x70
Jan 26 11:25:34 n22 kernel: [<c1095983>] tick_sched_handle.isra.12+0x33/0x40
Jan 26 11:25:34 n22 kernel: [<c1095b40>] tick_sched_timer+0x40/0x70
Jan 26 11:25:34 n22 kernel: [<c105dad0>] ? __remove_hrtimer+0x40/0xa0
Jan 26 11:25:34 n22 kernel: [<c105dd89>] __run_hrtimer+0x69/0x190
Jan 26 11:25:34 n22 kernel: [<c1095b00>] ? tick_sched_do_timer+0x40/0x40
Jan 26 11:25:34 n22 kernel: [<c105e917>] hrtimer_interrupt+0xf7/0x290
Jan 26 11:25:34 n22 kernel: [<c10957c9>] ? tick_program_event+0x29/0x30
Jan 26 11:25:34 n22 kernel: [<c102b9cf>] local_apic_timer_interrupt+0x2f/0x60
Jan 26 11:25:34 n22 kernel: [<c1042855>] ? irq_enter+0x15/0x60
Jan 26 11:25:34 n22 kernel: [<c14037c3>] smp_apic_timer_interrupt+0x33/0x50
Jan 26 11:25:34 n22 kernel: [<c1402acc>] apic_timer_interrupt+0x34/0x3c
Jan 26 11:25:34 n22 kernel: [<f89a3059>] ? vmx_save_host_state+0x9/0x160 [kvm_intel]
Jan 26 11:25:34 n22 kernel: [<f98340cd>] kvm_arch_vcpu_ioctl_run+0x89d/0xff0 [kvm]
Jan 26 11:25:34 n22 kernel: [<f981f171>] kvm_vcpu_ioctl+0x421/0x500 [kvm]
Jan 26 11:25:34 n22 kernel: [<c1097c7b>] ? futex_wake+0xeb/0x110
Jan 26 11:25:34 n22 kernel: [<c1099613>] ? do_futex+0xf3/0x970
Jan 26 11:25:34 n22 kernel: [<f981ed50>] ? vcpu_put+0x30/0x30 [kvm]
Jan 26 11:25:34 n22 kernel: [<c114141f>] do_vfs_ioctl+0x6f/0x550
Jan 26 11:25:34 n22 kernel: [<c1099f2b>] ? SyS_futex+0x9b/0x150
Jan 26 11:25:34 n22 kernel: [<c1141945>] SyS_ioctl+0x45/0x70
Jan 26 11:25:34 n22 kernel: [<c1403141>] sysenter_do_call+0x12/0x22
Jan 26 11:25:34 n22 kernel: Code: fd 48 5d c3 8d 76 00 8d bc 27 00 00 00 00 55 89 e5 66 66 66 66 90 ff 15 8c 61 57 c1 5d c3 55 c1 e0 02 89 e5 64 8b 15 dc ee 61 c1 <69> d2 fa 00 00 00 f7 e2 8d 42 01 ff 15 8c 61 57 c1 5d c3 55 89
Jan 26 11:25:34 n22 kernel: NMI backtrace for cpu 0
Jan 26 11:25:34 n22 kernel: CPU: 0 PID: 6385 Comm: einstein_S6CasA Not tainted 3.13.0 #5
Jan 26 11:25:34 n22 kernel: Hardware name: LENOVO 4180F65/4180F65, BIOS 83ET75WW (1.45 ) 05/10/2013
Jan 26 11:25:34 n22 kernel: task: e8f80a60 ti: edb32000 task.ti: edb32000
Jan 26 11:25:34 n22 kernel: EIP: 0073:[<0805b146>] EFLAGS: 00000202 CPU: 0
Jan 26 11:25:34 n22 kernel: EIP is at 0x805b146
Jan 26 11:25:34 n22 kernel: EAX: 12c38f18 EBX: bf825e04 ECX: 00146be5 EDX: 12c3dc50
Jan 26 11:25:34 n22 kernel: ESI: 0000009d EDI: 0014759b EBP: bf825d18 ESP: bf825a40
Jan 26 11:25:34 n22 kernel: DS: 007b ES: 007b FS: 0000 GS: 0033 SS: 007b
Jan 26 11:25:34 n22 kernel:
Jan 26 11:25:34 n22 kernel: NMI backtrace for cpu 2
Jan 26 11:25:34 n22 kernel: CPU: 2 PID: 0 Comm: swapper/2 Not tainted 3.13.0 #5
Jan 26 11:25:34 n22 kernel: Hardware name: LENOVO 4180F65/4180F65, BIOS 83ET75WW (1.45 ) 05/10/2013
Jan 26 11:25:34 n22 kernel: task: f21619f0 ti: f2194000 task.ti: f2194000
Jan 26 11:25:34 n22 kernel: EIP: 0060:[<c1289af8>] EFLAGS: 00200046 CPU: 2
Jan 26 11:25:34 n22 kernel: EIP is at intel_idle+0xa8/0x100
Jan 26 11:25:34 n22 kernel: EAX: 00000030 EBX: 00000010 ECX: 00000001 EDX: 00000000
Jan 26 11:25:34 n22 kernel: ESI: 00000005 EDI: 00000030 EBP: f2195f28 ESP: f2195f14
Jan 26 11:25:34 n22 kernel: DS: 007b ES: 007b FS: 00d8 GS: 00e0 SS: 0068
Jan 26 11:25:34 n22 kernel: CR0: 80050033 CR2: b1e66000 CR3: 01628000 CR4: 000427f0
Jan 26 11:25:34 n22 kernel: Stack:
Jan 26 11:25:34 n22 kernel: 00000004 00000002 c1577000 f3621d00 c157718c f2195f48 c13574a7 00000005
Jan 26 11:25:34 n22 kernel: c20f8743 00000074 15f05edb f3621d00 00000000 f2195f6c c13575d4 00000074
Jan 26 11:25:34 n22 kernel: 00000002 c1577000 00000005 15f05edb 00000000 00000000 f2195f74 c100ac7d
Jan 26 11:25:34 n22 kernel: Call Trace:
Jan 26 11:25:34 n22 kernel: [<c13574a7>] cpuidle_enter_state+0x37/0xd0
Jan 26 11:25:34 n22 kernel: [<c13575d4>] cpuidle_idle_call+0x94/0x1d0
Jan 26 11:25:34 n22 kernel: [<c100ac7d>] arch_cpu_idle+0xd/0x30
Jan 26 11:25:34 n22 kernel: [<c1083a9a>] cpu_startup_entry+0x1ea/0x230
Jan 26 11:25:34 n22 kernel: [<c102a461>] start_secondary+0x1c1/0x240
Jan 26 11:25:34 n22 kernel: Code: 89 e0 25 00 e0 ff ff 31 d2 83 c0 08 89 d1 0f 01 c8 0f ae f0 66 90 89 e0 25 00 e0 ff ff 8b 40 08 a8 08 75 07 b1 01 89 f8 0f 01 c9 <85> 1d 14 73 57 c1 75 0d 8d 55 f0 b8 05 00 00 00 e8 e3 a1 e0 ff
Jan 26 11:25:34 n22 kernel: NMI backtrace for cpu 1
Jan 26 11:25:34 n22 kernel: CPU: 1 PID: 6522 Comm: qemu-system-x86 Not tainted 3.13.0 #5
Jan 26 11:25:34 n22 kernel: Hardware name: LENOVO 4180F65/4180F65, BIOS 83ET75WW (1.45 ) 05/10/2013
Jan 26 11:25:34 n22 kernel: task: e41094c0 ti: ed8ae000 task.ti: ed8ae000
Jan 26 11:25:34 n22 kernel: EIP: 0060:[<c1088a5b>] EFLAGS: 00000286 CPU: 1
Jan 26 11:25:34 n22 kernel: EIP is at __srcu_read_unlock+0xb/0x20
Jan 26 11:25:34 n22 kernel: EAX: e8d6a0d4 EBX: e3e88000 ECX: 00000000 EDX: 00000001
Jan 26 11:25:34 n22 kernel: ESI: 00000000 EDI: 00000000 EBP: ed8afe00 ESP: ed8afe00
Jan 26 11:25:34 n22 kernel: DS: 007b ES: 007b FS: 00d8 GS: 00e0 SS: 0068
Jan 26 11:25:34 n22 kernel: CR0: 80050033 CR2: ffe16000 CR3: 23c2e000 CR4: 000427f0
Jan 26 11:25:34 n22 kernel: Stack:
Jan 26 11:25:34 n22 kernel: ed8afea4 f9834100 00000000 00000000 00000001 e8d6a0b0 00000002 00000002
Jan 26 11:25:34 n22 kernel: 00278b5d e41094c0 9189cb08 00000006 e41094c0 fb603320 00000067 00000202
Jan 26 11:25:34 n22 kernel: 00000000 28e95000 00000000 e8d6a0d4 7ffbfeff fffffffe 00000000 01010000
Jan 26 11:25:34 n22 kernel: Call Trace:
Jan 26 11:25:34 n22 kernel: [<f9834100>] kvm_arch_vcpu_ioctl_run+0x8d0/0xff0 [kvm]
Jan 26 11:25:34 n22 kernel: [<f981f171>] kvm_vcpu_ioctl+0x421/0x500 [kvm]
Jan 26 11:25:34 n22 kernel: [<c106b618>] ? __enqueue_entity+0x78/0x80
Jan 26 11:25:34 n22 kernel: [<c106f98c>] ? put_prev_task_fair+0x5c/0x3e0
Jan 26 11:25:34 n22 kernel: [<c106b575>] ? __dequeue_entity+0x25/0x40
Jan 26 11:25:34 n22 kernel: [<f981ed50>] ? vcpu_put+0x30/0x30 [kvm]
Jan 26 11:25:34 n22 kernel: [<c114141f>] do_vfs_ioctl+0x6f/0x550
Jan 26 11:25:34 n22 kernel: [<c13ff60e>] ? __schedule+0x22e/0x690
Jan 26 11:25:34 n22 kernel: [<c105e998>] ? hrtimer_interrupt+0x178/0x290
Jan 26 11:25:34 n22 kernel: [<c10517f9>] ? getrusage+0x319/0x350
Jan 26 11:25:34 n22 kernel: [<c1145780>] ? dget_parent+0x70/0x70
Jan 26 11:25:34 n22 kernel: [<c10517f9>] ? getrusage+0x319/0x350
Jan 26 11:25:34 n22 kernel: [<c10517f9>] ? getrusage+0x319/0x350
Jan 26 11:25:34 n22 kernel: [<c1141945>] SyS_ioctl+0x45/0x70
Jan 26 11:25:34 n22 kernel: [<c1403141>] sysenter_do_call+0x12/0x22
Jan 26 11:25:34 n22 kernel: Code: 91 0f ae f0 66 90 8b 40 04 64 03 05 24 a7 61 c1 8b 4c 90 08 83 c1 01 89 4c 90 08 5b 89 d0 5d c3 55 89 e5 66 66 66 66 90 0f ae f0 <66> 90 8b 40 04 64 ff 0c 90 5d c3 8d 76 00 8d bc 27 00 00 00 00
Jan 26 11:26:10 n22 su[6563]: Successful su for root by root
Jan 26 11:26:10 n22 su[6563]: + /dev/pts/4 root:root
Jan 26 11:26:10 n22 su[6563]: pam_unix(su:session): session opened for user root by tfoerste(uid=0)
Jan 26 11:26:50 n22 polkitd[4259]: Operator of unix-session:/org/freedesktop/ConsoleKit/Session1 successfully authenticated as unix-user:root to gain TEMPORARY authorization for action org.libvirt.unix.manage for unix-process:6597:57390 [/usr/bin/python2.7 /usr/share/virt-manager/virt-manager] (owned by unix-user:tfoerste)
Jan 26 11:27:18 n22 kernel: SysRq : Emergency Sync
Jan 26 11:27:18 n22 kernel: Emergency Sync complete


- --
MfG/Sincerely
Toralf Förster
pgp finger print:1A37 6F99 4A9D 026F 13E2 4DCF C4EA CDDE 0076 E94E
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v2.0.22 (GNU/Linux)
Comment: Using GnuPG with Thunderbird - http://www.enigmail.net/

iF4EAREIAAYFAlLk5gYACgkQxOrN3gB26U5zMAD+OoV7eCtjYkLGolGEh454sWNr
/mImeXwgajkNnCbOGmwA+wXSG0t4fNbahKYSpYrTPYGhvwvyLzSo8XDBJKQnyG9l
=JXqd
-----END PGP SIGNATURE-----

2014-02-08 08:30:33

by Toralf Förster

[permalink] [raw]
Subject: Re: 3.13 hangs when I tried to start a KVM at a 32 bit stable Gentoo

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA256

On 01/23/2014 07:55 PM, Dave Hansen wrote:
> On 01/21/2014 08:38 AM, Toralf Förster wrote:
>> Jan 21 17:18:57 n22 kernel: INFO: rcu_sched self-detected stall on CPU { 2} (t=60001 jiffies g=18494 c=18493 q=183951)
>> Jan 21 17:18:57 n22 kernel: sending NMI to all CPUs:
>> Jan 21 17:18:57 n22 kernel: NMI backtrace for cpu 2
>> Jan 21 17:18:57 n22 kernel: CPU: 2 PID: 6779 Comm: qemu-system-x86 Not tainted 3.13.0 #3
>> Jan 21 17:18:57 n22 kernel: Hardware name: LENOVO 4180F65/4180F65, BIOS 83ET75WW (1.45 ) 05/10/2013
>> Jan 21 17:18:57 n22 kernel: task: e921c370 ti: e5f36000 task.ti: e5f36000
>
> I'm seeing a very similar hang with an ubuntu guest and a custom kernel.
> I'm on commit 0dc3fd0249a, and it's 100% reproducible every time I run KVM.
>
> Cc-ing a few more folks...
>
With 3.12.2 at the same 32 bit Gentoo Linux I experienced a similar thingin a complete different scenario: I umounted a loop-mounted file, on which I created and filled a btrfs file system before (/usr/portage FWIW - I'm a Gentoo user) and the systems becomes very slowly and /var/log/messages shows :

Feb 7 22:46:46 n22 kernel: iwlwifi 0000:03:00.0: Error sending POWER_TABLE_CMD: time out after 2000ms.
Feb 7 22:46:46 n22 kernel: iwlwifi 0000:03:00.0: Current CMD queue read_ptr 100 write_ptr 101
Feb 7 22:46:46 n22 kernel: iwlwifi 0000:03:00.0: Loaded firmware version: 18.168.6.1
Feb 7 22:46:46 n22 kernel: iwlwifi 0000:03:00.0: 0x00000000 | OK
Feb 7 22:46:46 n22 kernel: iwlwifi 0000:03:00.0: 0x00000000 | uPc
Feb 7 22:46:46 n22 kernel: iwlwifi 0000:03:00.0: 0x00000000 | branchlink1
Feb 7 22:46:46 n22 kernel: iwlwifi 0000:03:00.0: 0x00000000 | branchlink2
Feb 7 22:46:46 n22 kernel: iwlwifi 0000:03:00.0: 0x00000000 | interruptlink1
Feb 7 22:46:46 n22 kernel: iwlwifi 0000:03:00.0: 0x00000000 | interruptlink2
Feb 7 22:46:46 n22 kernel: iwlwifi 0000:03:00.0: 0x00000000 | data1
Feb 7 22:46:46 n22 kernel: iwlwifi 0000:03:00.0: 0x00000000 | data2
Feb 7 22:46:46 n22 kernel: iwlwifi 0000:03:00.0: 0x00000000 | line
Feb 7 22:46:46 n22 kernel: iwlwifi 0000:03:00.0: 0x00000000 | beacon time
Feb 7 22:46:46 n22 kernel: iwlwifi 0000:03:00.0: 0x00000000 | tsf low
Feb 7 22:46:46 n22 kernel: iwlwifi 0000:03:00.0: 0x00000000 | tsf hi
Feb 7 22:46:46 n22 kernel: iwlwifi 0000:03:00.0: 0x00000000 | time gp1
Feb 7 22:46:46 n22 kernel: iwlwifi 0000:03:00.0: 0x00000000 | time gp2
Feb 7 22:46:46 n22 kernel: iwlwifi 0000:03:00.0: 0x00000000 | time gp3
Feb 7 22:46:46 n22 kernel: iwlwifi 0000:03:00.0: 0x00000000 | uCode version
Feb 7 22:46:46 n22 kernel: iwlwifi 0000:03:00.0: 0x00000000 | hw version
Feb 7 22:46:46 n22 kernel: iwlwifi 0000:03:00.0: 0x00000000 | board version
Feb 7 22:46:46 n22 kernel: iwlwifi 0000:03:00.0: 0x00000000 | hcmd
Feb 7 22:46:46 n22 kernel: iwlwifi 0000:03:00.0: 0x00000000 | isr0
Feb 7 22:46:46 n22 kernel: iwlwifi 0000:03:00.0: 0x00000000 | isr1
Feb 7 22:46:46 n22 kernel: iwlwifi 0000:03:00.0: 0x00000000 | isr2
Feb 7 22:46:46 n22 kernel: iwlwifi 0000:03:00.0: 0x00000000 | isr3
Feb 7 22:46:46 n22 kernel: iwlwifi 0000:03:00.0: 0x00000000 | isr4
Feb 7 22:46:46 n22 kernel: iwlwifi 0000:03:00.0: 0x00000000 | isr_pref
Feb 7 22:46:46 n22 kernel: iwlwifi 0000:03:00.0: 0x00000000 | wait_event
Feb 7 22:46:46 n22 kernel: iwlwifi 0000:03:00.0: 0x00000000 | l2p_control
Feb 7 22:46:46 n22 kernel: iwlwifi 0000:03:00.0: 0x00000000 | l2p_duration
Feb 7 22:46:46 n22 kernel: iwlwifi 0000:03:00.0: 0x00000000 | l2p_mhvalid
Feb 7 22:46:46 n22 kernel: iwlwifi 0000:03:00.0: 0x00000000 | l2p_addr_match
Feb 7 22:46:46 n22 kernel: iwlwifi 0000:03:00.0: 0x00000000 | lmpm_pmg_sel
Feb 7 22:46:46 n22 kernel: iwlwifi 0000:03:00.0: 0x00000000 | timestamp
Feb 7 22:46:46 n22 kernel: iwlwifi 0000:03:00.0: 0x00000000 | flow_handler
Feb 7 22:46:46 n22 kernel: iwlwifi 0000:03:00.0: Start IWL Event Log Dump: nothing in log
Feb 7 22:46:46 n22 kernel: iwlwifi 0000:03:00.0: set power fail, ret = -110
Feb 7 22:46:46 n22 kernel: iwlwifi 0000:03:00.0: iwl_trans_wait_tx_queue_empty bad state = 0
Feb 7 22:46:46 n22 kernel: ieee80211 phy0: Hardware restart was requested
Feb 7 22:46:46 n22 kernel: iwlwifi 0000:03:00.0: L1 Enabled; Disabling L0S
Feb 7 22:46:46 n22 kernel: iwlwifi 0000:03:00.0: Radio type=0x1-0x2-0x0
Feb 7 22:46:51 n22 kernel: iwlwifi 0000:03:00.0: Failed to load firmware chunk!
Feb 7 22:46:51 n22 kernel: iwlwifi 0000:03:00.0: Could not load the [0] uCode section
Feb 7 22:46:51 n22 kernel: iwlwifi 0000:03:00.0: Failed to start RT ucode: -110
Feb 7 22:46:51 n22 kernel: iwlwifi 0000:03:00.0: Unable to initialize device.
Feb 7 22:46:51 n22 kernel: iwlwifi 0000:03:00.0: Fw not loaded - dropping CMD: 18
Feb 7 22:46:51 n22 kernel: wlp3s0: HW problem - can not stop rx aggregation for 08:96:d7:05:f9:2a tid 0
Feb 7 22:46:51 n22 kernel: iwlwifi 0000:03:00.0: Fw not loaded - dropping CMD: 18
Feb 7 22:46:51 n22 kernel: wlp3s0: HW problem - can not stop rx aggregation for 08:96:d7:05:f9:2a tid 6
Feb 7 22:47:06 n22 dhcpcd[5978]: wlp3s0: carrier lost
Feb 7 22:47:06 n22 dhcpcd[5978]: wlp3s0: deleting route to 192.168.178.0/24
Feb 7 22:47:06 n22 dhcpcd[5978]: wlp3s0: deleting default route via 192.168.178.1
Feb 7 22:47:06 n22 kernel: iwlwifi 0000:03:00.0: iwl_trans_wait_tx_queue_empty bad state = 0
Feb 7 22:47:06 n22 kernel: cfg80211: Calling CRDA to update world regulatory domain
Feb 7 22:47:06 n22 kernel: iwlwifi 0000:03:00.0: Request scan called when driver not ready.
Feb 7 22:47:06 n22 wpa_cli: interface wlp3s0 DISCONNECTED
Feb 7 22:47:06 n22 wpa_cli: executing 'false /etc/init.d/net.wlp3s0 --quiet stop' failed
Feb 7 22:47:07 n22 kernel: cfg80211: World regulatory domain updated:
Feb 7 22:47:07 n22 kernel: cfg80211: (start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp)
Feb 7 22:47:07 n22 kernel: cfg80211: (2402000 KHz - 2472000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
Feb 7 22:47:07 n22 kernel: cfg80211: (2457000 KHz - 2482000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
Feb 7 22:47:07 n22 kernel: cfg80211: (2474000 KHz - 2494000 KHz @ 20000 KHz), (300 mBi, 2000 mBm)
Feb 7 22:47:07 n22 kernel: cfg80211: (5170000 KHz - 5250000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
Feb 7 22:47:07 n22 kernel: cfg80211: (5735000 KHz - 5835000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
Feb 7 22:47:07 n22 kernel: iwlwifi 0000:03:00.0: Request scan called when driver not ready.
Feb 7 22:47:08 n22 ntpd[6263]: Deleting interface #3 wlp3s0, 192.168.178.21#123, interface stats: received=279, sent=281, dropped=0, active_time=12050 secs
Feb 7 22:47:08 n22 ntpd[6263]: 144.76.117.245 interface 192.168.178.21 -> (none)
Feb 7 22:47:08 n22 ntpd[6263]: 193.175.73.151 interface 192.168.178.21 -> (none)
Feb 7 22:47:08 n22 ntpd[6263]: 78.47.93.200 interface 192.168.178.21 -> (none)
Feb 7 22:47:08 n22 ntpd[6263]: 130.149.220.125 interface 192.168.178.21 -> (none)
Feb 7 22:47:08 n22 ntpd[6263]: peers refreshed
Feb 7 22:47:08 n22 kernel: iwlwifi 0000:03:00.0: Request scan called when driver not ready.
Feb 7 22:47:09 n22 kernel: iwlwifi 0000:03:00.0: Request scan called when driver not ready.
Feb 7 22:47:10 n22 kernel: iwlwifi 0000:03:00.0: Request scan called when driver not ready.
Feb 7 22:47:11 n22 kernel: iwlwifi 0000:03:00.0: Request scan called when driver not ready.
Feb 7 22:47:12 n22 kernel: iwlwifi 0000:03:00.0: Request scan called when driver not ready.
Feb 7 22:47:13 n22 kernel: iwlwifi 0000:03:00.0: Request scan called when driver not ready.
Feb 7 22:47:14 n22 kernel: iwlwifi 0000:03:00.0: Request scan called when driver not ready.
Feb 7 22:47:15 n22 kernel: iwlwifi 0000:03:00.0: Request scan called when driver not ready.
Feb 7 22:47:16 n22 kernel: iwlwifi 0000:03:00.0: Request scan called when driver not ready.
Feb 7 22:47:17 n22 kernel: iwlwifi 0000:03:00.0: Request scan called when driver not ready.
Feb 7 22:47:18 n22 kernel: iwlwifi 0000:03:00.0: Request scan called when driver not ready.
Feb 7 22:47:19 n22 kernel: iwlwifi 0000:03:00.0: Request scan called when driver not ready.
Feb 7 22:47:20 n22 kernel: iwlwifi 0000:03:00.0: Request scan called when driver not ready.
Feb 7 22:47:21 n22 kernel: iwlwifi 0000:03:00.0: Request scan called when driver not ready.
Feb 7 22:47:22 n22 kernel: iwlwifi 0000:03:00.0: Request scan called when driver not ready.
Feb 7 22:47:23 n22 kernel: iwlwifi 0000:03:00.0: Request scan called when driver not ready.
Feb 7 22:47:24 n22 kernel: iwlwifi 0000:03:00.0: Request scan called when driver not ready.
Feb 7 22:47:25 n22 kernel: iwlwifi 0000:03:00.0: Request scan called when driver not ready.
Feb 7 22:47:26 n22 kernel: iwlwifi 0000:03:00.0: Request scan called when driver not ready.
Feb 7 22:47:27 n22 kernel: iwlwifi 0000:03:00.0: Request scan called when driver not ready.
...


- --
MfG/Sincerely
Toralf Förster
pgp finger print:1A37 6F99 4A9D 026F 13E2 4DCF C4EA CDDE 0076 E94E
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v2.0.22 (GNU/Linux)
Comment: Using GnuPG with Thunderbird - http://www.enigmail.net/

iF0EAREIAAYFAlL16yIACgkQxOrN3gB26U6ZLAD4+xOsxbCxkoLLyZm10XESUBxh
3SK0iNuGjBEamGth3gD9GgeZoyK2dwfA5SJX/r6IwWVvwgwQ03frfqCRWQNe6BU=
=Eyi4
-----END PGP SIGNATURE-----

2014-02-09 16:39:09

by Toralf Förster

[permalink] [raw]
Subject: Re: 3.13 hangs when I tried to start a KVM at a 32 bit stable Gentoo

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA256

On 01/23/2014 08:33 PM, Dave Hansen wrote:
> On 01/23/2014 10:55 AM, Dave Hansen wrote:
>> On 01/21/2014 08:38 AM, Toralf Förster wrote:
>>> Jan 21 17:18:57 n22 kernel: INFO: rcu_sched self-detected stall on CPU { 2} (t=60001 jiffies g=18494 c=18493 q=183951)
>>> Jan 21 17:18:57 n22 kernel: sending NMI to all CPUs:
>>> Jan 21 17:18:57 n22 kernel: NMI backtrace for cpu 2
>>> Jan 21 17:18:57 n22 kernel: CPU: 2 PID: 6779 Comm: qemu-system-x86 Not tainted 3.13.0 #3
>>> Jan 21 17:18:57 n22 kernel: Hardware name: LENOVO 4180F65/4180F65, BIOS 83ET75WW (1.45 ) 05/10/2013
>>> Jan 21 17:18:57 n22 kernel: task: e921c370 ti: e5f36000 task.ti: e5f36000
>>
>> I'm seeing a very similar hang with an ubuntu guest and a custom kernel.
>> I'm on commit 0dc3fd0249a, and it's 100% reproducible every time I run KVM.
>
> Did a little more LKML digging and found this:
>
> http://marc.info/?l=linux-kernel&m=139038631607917&q=raw
>
> Peter's fix works for me. I'm also running a CONFIG_PREEMPT_VOLUNTARY=y
> config.
>
>
Hhhm, that fix seems not to be applicable for 3.13.x
With 3.13.2 I removed multimedia, sound and wlan and few file systems from the kernel's config, now at least the kernel doesn't hang, but I do still get while trying to start a virtual machine (and please note, I run into a similar issue while just umounting a btrfs file system) :


Feb 9 17:14:59 n22 polkitd[4129]: Operator of unix-session:/org/freedesktop/ConsoleKit/Session1 successfully authenticated as unix-user:root to gain TEMPORARY authorization for action org.libvirt.unix.manage for unix-process:6544:23328 [/usr/bin/python2.7 /usr/share/virt-manager/virt-manager] (owned by unix-user:tfoerste)
Feb 9 17:15:01 n22 kernel: type=1006 audit(1391962501.815:5): pid=6601 uid=0 old auid=4294967295 new auid=0 old ses=4294967295 new ses=4 res=1
Feb 9 17:15:01 n22 crond[6601]: pam_unix(crond:session): session opened for user root by (uid=0)
Feb 9 17:15:01 n22 CROND[6602]: (root) CMD (/usr/lib/sa/sa1 60 15 )
Feb 9 17:15:05 n22 kernel: NET: Registered protocol family 17
Feb 9 17:15:05 n22 kernel: device vnet0 entered promiscuous mode
Feb 9 17:15:05 n22 kernel: br0: port 4(vnet0) entered forwarding state
Feb 9 17:15:05 n22 kernel: br0: port 4(vnet0) entered forwarding state
Feb 9 17:15:05 n22 kernel: IPv6: ADDRCONF(NETDEV_CHANGE): br0: link becomes ready
Feb 9 17:15:05 n22 kernel: cgroup: libvirtd (5677) created nested cgroup for controller "memory" which has incomplete hierarchy support. Nested cgroups may change behavior in the future.
Feb 9 17:15:05 n22 kernel: cgroup: "memory" requires setting use_hierarchy to 1 on the root.
Feb 9 17:15:08 n22 ntpd[5582]: Listen normally on 5 br0 fe80::acb9:fbff:fea0:57f9 UDP 123
Feb 9 17:15:08 n22 ntpd[5582]: Listen normally on 6 vnet0 fe80::fc54:ff:fe46:1fc4 UDP 123
Feb 9 17:15:08 n22 ntpd[5582]: peers refreshed
Feb 9 17:16:57 n22 kernel: INFO: rcu_sched self-detected stall on CPU { 0} (t=60000 jiffies g=16324 c=16323 q=11304)
Feb 9 17:16:57 n22 kernel: sending NMI to all CPUs:
Feb 9 17:16:57 n22 kernel: NMI backtrace for cpu 0
Feb 9 17:16:57 n22 kernel: CPU: 0 PID: 6617 Comm: qemu-system-x86 Not tainted 3.13.2 #17
Feb 9 17:16:57 n22 kernel: Hardware name: LENOVO 4180F65/4180F65, BIOS 83ET75WW (1.45 ) 05/10/2013
Feb 9 17:16:57 n22 kernel: task: e70e5b40 ti: e736e000 task.ti: e736e000
Feb 9 17:16:57 n22 kernel: EIP: 0060:[<c12ac9cd>] EFLAGS: 00000006 CPU: 0
Feb 9 17:16:57 n22 kernel: EIP is at __const_udelay+0xd/0x20
Feb 9 17:16:57 n22 kernel: EAX: 01062560 EBX: 00002710 ECX: c1599460 EDX: 00278bf9
Feb 9 17:16:57 n22 kernel: ESI: c159c580 EDI: f3650c40 EBP: e736fca8 ESP: e736fca8
Feb 9 17:16:57 n22 kernel: DS: 007b ES: 007b FS: 00d8 GS: 00e0 SS: 0068
Feb 9 17:16:57 n22 kernel: CR0: 80050033 CR2: 091441f4 CR3: 00110000 CR4: 000427f0
Feb 9 17:16:57 n22 kernel: Stack:
Feb 9 17:16:57 n22 kernel: e736fcb8 c102ba30 c1500d39 c159c580 e736fcfc c107febc c150cd0c 0000ea60
Feb 9 17:16:57 n22 kernel: 00003fc4 00003fc3 00002c28 c10606d8 00000001 c159c580 c15c4a84 f3650c40
Feb 9 17:16:57 n22 kernel: 00002c28 00000000 e70e5b40 00000000 00000000 e736fd10 c1044126 f3650e60
Feb 9 17:16:57 n22 kernel: Call Trace:
Feb 9 17:16:57 n22 kernel: [<c102ba30>] arch_trigger_all_cpu_backtrace+0x50/0x70
Feb 9 17:16:57 n22 kernel: [<c107febc>] rcu_check_callbacks+0x31c/0x520
Feb 9 17:16:57 n22 kernel: [<c10606d8>] ? account_system_time+0xb8/0x170
Feb 9 17:16:57 n22 kernel: [<c1044126>] update_process_times+0x36/0x70
Feb 9 17:16:57 n22 kernel: [<c108985e>] tick_sched_handle.isra.13+0x2e/0x30
Feb 9 17:16:57 n22 kernel: [<c10899fb>] tick_sched_timer+0x3b/0x70
Feb 9 17:16:57 n22 kernel: [<c1055f52>] ? __remove_hrtimer+0x42/0xa0
Feb 9 17:16:57 n22 kernel: [<c105603c>] __run_hrtimer.isra.29+0x3c/0xb0
Feb 9 17:16:57 n22 kernel: [<c1056c75>] hrtimer_interrupt+0x1e5/0x270
Feb 9 17:16:57 n22 kernel: [<c10298ca>] local_apic_timer_interrupt+0x2a/0x50
Feb 9 17:16:57 n22 kernel: [<c103e420>] ? irq_enter+0x10/0x60
Feb 9 17:16:57 n22 kernel: [<c1029e0e>] smp_apic_timer_interrupt+0x2e/0x50
Feb 9 17:16:57 n22 kernel: [<c144ece4>] apic_timer_interrupt+0x34/0x3c
Feb 9 17:16:57 n22 kernel: [<c107d22b>] ? __srcu_read_unlock+0xb/0x20
Feb 9 17:16:57 n22 kernel: [<f88cae70>] kvm_arch_vcpu_ioctl_run+0x8c0/0xf30 [kvm]
Feb 9 17:16:57 n22 kernel: [<f88ba84b>] kvm_vcpu_ioctl+0x40b/0x4a0 [kvm]
Feb 9 17:16:57 n22 kernel: [<c10653ac>] ? put_prev_task_fair+0x5c/0x3e0
Feb 9 17:16:57 n22 kernel: [<c105bd63>] ? ttwu_do_activate.constprop.82+0x53/0x60
Feb 9 17:16:57 n22 kernel: [<c1061100>] ? __dequeue_entity+0x20/0x40
Feb 9 17:16:57 n22 kernel: [<f88ba440>] ? vcpu_put+0x20/0x20 [kvm]
Feb 9 17:16:57 n22 kernel: [<c110d34a>] do_vfs_ioctl+0x6a/0x540
Feb 9 17:16:57 n22 kernel: [<c144bb1e>] ? __schedule+0x20e/0x660
Feb 9 17:16:57 n22 kernel: [<c110d860>] SyS_ioctl+0x40/0x70
Feb 9 17:16:57 n22 kernel: [<c144f201>] sysenter_do_call+0x12/0x22
Feb 9 17:16:57 n22 kernel: [<c1440000>] ? dns_resolver_instantiate+0x400/0x480
Feb 9 17:16:57 n22 kernel: Code: fd 48 5d c3 8d 76 00 8d bc 27 00 00 00 00 55 89 e5 ff 15 6c ea 5a c1 5d c3 90 8d 74 26 00 55 c1 e0 02 89 e5 64 8b 15 5c 7d 62 c1 <69> d2 fa 00 00 00 f7 e2 8d 42 01 ff 15 6c ea 5a c1 5d c3 55 69
Feb 9 17:16:57 n22 kernel: NMI backtrace for cpu 1
Feb 9 17:16:57 n22 kernel: CPU: 1 PID: 5818 Comm: period_search_1 Not tainted 3.13.2 #17
Feb 9 17:16:57 n22 kernel: Hardware name: LENOVO 4180F65/4180F65, BIOS 83ET75WW (1.45 ) 05/10/2013
Feb 9 17:16:57 n22 kernel: task: f00716d0 ti: ef3be000 task.ti: ef3be000
Feb 9 17:16:57 n22 kernel: EIP: 0073:[<08050915>] EFLAGS: 00000246 CPU: 1
Feb 9 17:16:57 n22 kernel: EIP is at 0x8050915
Feb 9 17:16:57 n22 kernel: EAX: 000000ac EBX: 0000004d ECX: 00000120 EDX: 0000000e
Feb 9 17:16:57 n22 kernel: ESI: 00000980 EDI: 0a846fc8 EBP: bfcd34b8 ESP: bfcc9dc0
Feb 9 17:16:57 n22 kernel: DS: 007b ES: 007b FS: 0000 GS: 0033 SS: 007b
Feb 9 17:16:57 n22 kernel:
Feb 9 17:16:57 n22 kernel: NMI backtrace for cpu 2
Feb 9 17:16:57 n22 kernel: CPU: 2 PID: 5817 Comm: period_search_1 Not tainted 3.13.2 #17
Feb 9 17:16:57 n22 kernel: Hardware name: LENOVO 4180F65/4180F65, BIOS 83ET75WW (1.45 ) 05/10/2013
Feb 9 17:16:57 n22 kernel: task: f0075fd0 ti: f12ca000 task.ti: f12ca000
Feb 9 17:16:57 n22 kernel: EIP: 0073:[<08050d94>] EFLAGS: 00000287 CPU: 2
Feb 9 17:16:57 n22 kernel: EIP is at 0x8050d94
Feb 9 17:16:57 n22 kernel: EAX: 00000128 EBX: 0858a720 ECX: bfcb42e0 EDX: 00000180
Feb 9 17:16:57 n22 kernel: ESI: bfcb3320 EDI: 000001f8 EBP: bfcbc058 ESP: bfcb2960
Feb 9 17:16:57 n22 kernel: DS: 007b ES: 007b FS: 0000 GS: 0033 SS: 007b
Feb 9 17:16:57 n22 kernel:
Feb 9 17:16:57 n22 kernel: NMI backtrace for cpu 3
Feb 9 17:16:57 n22 kernel: CPU: 3 PID: 5814 Comm: einstein_S6CasA Not tainted 3.13.2 #17
Feb 9 17:16:57 n22 kernel: Hardware name: LENOVO 4180F65/4180F65, BIOS 83ET75WW (1.45 ) 05/10/2013
Feb 9 17:16:57 n22 kernel: task: f0073b50 ti: ef722000 task.ti: ef722000
Feb 9 17:16:57 n22 kernel: EIP: 0073:[<080558e1>] EFLAGS: 00000202 CPU: 3
Feb 9 17:16:57 n22 kernel: EIP is at 0x80558e1
Feb 9 17:16:57 n22 kernel: EAX: b3214120 EBX: bfc8d160 ECX: b4589b98 EDX: 00010450
Feb 9 17:16:57 n22 kernel: ESI: 00010450 EDI: 00016cf1 EBP: bfc8d2f8 ESP: bfc8caa0
Feb 9 17:16:57 n22 kernel: DS: 007b ES: 007b FS: 0000 GS: 0033 SS: 007b
Feb 9 17:16:57 n22 kernel:
Feb 9 17:17:53 n22 kernel: br0: port 4(vnet0) entered disabled state
Feb 9 17:17:53 n22 kernel: device vnet0 left promiscuous mode
Feb 9 17:17:53 n22 kernel: br0: port 4(vnet0) entered disabled state
Feb 9 17:17:54 n22 ntpd[5582]: Deleting interface #6 vnet0, fe80::fc54:ff:fe46:1fc4#123, interface stats: received=0, sent=0, dropped=0, active_time=166 secs
Feb 9 17:17:54 n22 ntpd[5582]: peers refreshed
Feb 9 17:18:25 n22 polkitd[4129]: Unregistered Authentication Agent for unix-session:/org/freedesktop/ConsoleKit/Session1 (system bus name :1.18, object path /org/kde/PolicyKit1/AuthenticationAgent, locale en_US.utf8)
Feb 9 17:18:26 n22 kdm: :0[4888]: pam_unix(kde:session): session closed for user tfoerste
Feb 9 17:18:26 n22 shutdown[7138]: shutting down for system reboot
Feb 9 17:18:27 n22 init: Switching to runlevel: 6
Feb 9 17:18:28 n22 thinkfan:
Caught deadly signal.
F



- --
MfG/Sincerely
Toralf Förster
pgp finger print:1A37 6F99 4A9D 026F 13E2 4DCF C4EA CDDE 0076 E94E
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v2.0.22 (GNU/Linux)
Comment: Using GnuPG with Thunderbird - http://www.enigmail.net/

iF4EAREIAAYFAlL3rx4ACgkQxOrN3gB26U4uDwD+MofngLtD/et921CrLyVrAFr+
1QkIVk0cyUFIAp4986wA/2d5zZ1jRj61uXnGidDcxCq2AyIl85Iqy0KkNkDGQ/FM
=W0Ci
-----END PGP SIGNATURE-----


Attachments:
.config (69.59 kB)
.config.sig (95.00 B)
Download all attachments

2014-02-23 18:59:22

by Toralf Förster

[permalink] [raw]
Subject: Re: 3.13 hangs when I tried to start a KVM at a 32 bit stable Gentoo

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA256

The issue seen below is still a problem in stable 3.13.5 as well as in
latest git tree of Linus' - are there any patches flying around to
solve it ?

On 01/21/2014 05:38 PM, Toralf Förster wrote:
> Well,
>
> sysrq at least works, the output of
>
> $>sudo strings /var/log/messages | grep -e 'Jan 21 17:17:46' -e
> 'Jan 21 17:18:..' -e 'Jan 21 17:2[01]:..' > messages.txt
>
> is attached - the .config is attached too.
>
>
> -- MfG/Sincerely Toralf Förster pgp finger print:1A37 6F99 4A9D
> 026F 13E2 4DCF C4EA CDDE 0076 E94E
>
>
> messages.txt
>
>
> Jan 21 17:17:46 n22 kernel: device vnet0 entered promiscuous mode
> Jan 21 17:17:46 n22 kernel: br0: port 4(vnet0) entered forwarding
> state Jan 21 17:17:46 n22 kernel: br0: port 4(vnet0) entered
> forwarding state Jan 21 17:17:46 n22 kernel: IPv6:
> ADDRCONF(NETDEV_CHANGE): br0: link becomes ready Jan 21 17:17:46
> n22 kernel: cgroup: libvirtd (6355) created nested cgroup for
> controller "memory" which has incomplete hierarchy support. Nested
> cgroups may change behavior in the future. Jan 21 17:17:46 n22
> kernel: cgroup: "memory" requires setting use_hierarchy to 1 on the
> root. Jan 21 17:18:00 n22 kernel: iwlwifi 0000:03:00.0: Error
> sending POWER_TABLE_CMD: time out after 2000ms. Jan 21 17:18:00 n22
> kernel: iwlwifi 0000:03:00.0: Current CMD queue read_ptr 129
> write_ptr 130 Jan 21 17:18:00 n22 kernel: iwlwifi 0000:03:00.0:
> Loaded firmware version: 18.168.6.1 Jan 21 17:18:00 n22 kernel:
> iwlwifi 0000:03:00.0: 0x00000000 | OK Jan 21 17:18:00 n22 kernel:
> iwlwifi 0000:03:00.0: 0x00000000 | uPc Jan 21 17:18:00 n22 kernel:
> iwlwifi 0000:03:00.0: 0x00000000 | branchlink1 Jan 21 17:18:00 n22
> kernel: iwlwifi 0000:03:00.0: 0x00000000 | branchlink2 Jan 21
> 17:18:00 n22 kernel: iwlwifi 0000:03:00.0: 0x00000000 |
> interruptlink1 Jan 21 17:18:00 n22 kernel: iwlwifi 0000:03:00.0:
> 0x00000000 | interruptlink2 Jan 21 17:18:00 n22 kernel: iwlwifi
> 0000:03:00.0: 0x00000000 | data1 Jan 21 17:18:00 n22 kernel:
> iwlwifi 0000:03:00.0: 0x00000000 | data2 Jan 21 17:18:00 n22
> kernel: iwlwifi 0000:03:00.0: 0x00000000 | line Jan 21 17:18:00 n22
> kernel: iwlwifi 0000:03:00.0: 0x00000000 | beacon time Jan 21
> 17:18:00 n22 kernel: iwlwifi 0000:03:00.0: 0x00000000 | tsf low Jan
> 21 17:18:00 n22 kernel: iwlwifi 0000:03:00.0: 0x00000000 | tsf hi
> Jan 21 17:18:00 n22 kernel: iwlwifi 0000:03:00.0: 0x00000000 | time
> gp1 Jan 21 17:18:00 n22 kernel: iwlwifi 0000:03:00.0: 0x00000000 |
> time gp2 Jan 21 17:18:00 n22 kernel: iwlwifi 0000:03:00.0:
> 0x00000000 | time gp3 Jan 21 17:18:00 n22 kernel: iwlwifi
> 0000:03:00.0: 0x00000000 | uCode version Jan 21 17:18:00 n22
> kernel: iwlwifi 0000:03:00.0: 0x00000000 | hw version Jan 21
> 17:18:00 n22 kernel: iwlwifi 0000:03:00.0: 0x00000000 | board
> version Jan 21 17:18:00 n22 kernel: iwlwifi 0000:03:00.0:
> 0x00000000 | hcmd Jan 21 17:18:00 n22 kernel: iwlwifi 0000:03:00.0:
> 0x00000000 | isr0 Jan 21 17:18:00 n22 kernel: iwlwifi 0000:03:00.0:
> 0x00000000 | isr1 Jan 21 17:18:00 n22 kernel: iwlwifi 0000:03:00.0:
> 0x00000000 | isr2 Jan 21 17:18:00 n22 kernel: iwlwifi 0000:03:00.0:
> 0x00000000 | isr3 Jan 21 17:18:00 n22 kernel: iwlwifi 0000:03:00.0:
> 0x00000000 | isr4 Jan 21 17:18:00 n22 kernel: iwlwifi 0000:03:00.0:
> 0x00000000 | isr_pref Jan 21 17:18:00 n22 kernel: iwlwifi
> 0000:03:00.0: 0x00000000 | wait_event Jan 21 17:18:00 n22 kernel:
> iwlwifi 0000:03:00.0: 0x00000000 | l2p_control Jan 21 17:18:00 n22
> kernel: iwlwifi 0000:03:00.0: 0x00000000 | l2p_duration Jan 21
> 17:18:00 n22 kernel: iwlwifi 0000:03:00.0: 0x00000000 |
> l2p_mhvalid Jan 21 17:18:00 n22 kernel: iwlwifi 0000:03:00.0:
> 0x00000000 | l2p_addr_match Jan 21 17:18:00 n22 kernel: iwlwifi
> 0000:03:00.0: 0x00000000 | lmpm_pmg_sel Jan 21 17:18:00 n22 kernel:
> iwlwifi 0000:03:00.0: 0x00000000 | timestamp Jan 21 17:18:00 n22
> kernel: iwlwifi 0000:03:00.0: 0x00000000 | flow_handler Jan 21
> 17:18:00 n22 kernel: iwlwifi 0000:03:00.0: Start IWL Event Log
> Dump: nothing in log Jan 21 17:18:00 n22 kernel: iwlwifi
> 0000:03:00.0: set power fail, ret = -110 Jan 21 17:18:02 n22
> kernel: iwlwifi 0000:03:00.0: fail to flush all tx fifo queues Q 0
> Jan 21 17:18:02 n22 kernel: iwlwifi 0000:03:00.0: Current SW
> read_ptr 11 write_ptr 12 Jan 21 17:18:02 n22 kernel: iwl data:
> 00000000: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
> ................ Jan 21 17:18:02 n22 kernel: iwlwifi 0000:03:00.0:
> FH TRBs(0) = 0x00000000 Jan 21 17:18:02 n22 kernel: iwlwifi
> 0000:03:00.0: FH TRBs(1) = 0x80102088 Jan 21 17:18:02 n22 kernel:
> iwlwifi 0000:03:00.0: FH TRBs(2) = 0x00000000 Jan 21 17:18:02 n22
> kernel: iwlwifi 0000:03:00.0: FH TRBs(3) = 0x8030000b Jan 21
> 17:18:02 n22 kernel: iwlwifi 0000:03:00.0: FH TRBs(4) = 0x00000000
> Jan 21 17:18:02 n22 kernel: iwlwifi 0000:03:00.0: FH TRBs(5) =
> 0x00000000 Jan 21 17:18:02 n22 kernel: iwlwifi 0000:03:00.0: FH
> TRBs(6) = 0x00000000 Jan 21 17:18:02 n22 kernel: iwlwifi
> 0000:03:00.0: FH TRBs(7) = 0x00709081 Jan 21 17:18:02 n22 kernel:
> iwlwifi 0000:03:00.0: Q 0 is active and mapped to fifo 3 ra_tid
> 0x0000 [12,12] Jan 21 17:18:02 n22 kernel: iwlwifi 0000:03:00.0: Q
> 1 is active and mapped to fifo 2 ra_tid 0x0000 [0,0] Jan 21
> 17:18:02 n22 kernel: iwlwifi 0000:03:00.0: Q 2 is active and mapped
> to fifo 1 ra_tid 0x0000 [137,137] Jan 21 17:18:02 n22 kernel:
> iwlwifi 0000:03:00.0: Q 3 is active and mapped to fifo 0 ra_tid
> 0x0000 [0,0] Jan 21 17:18:02 n22 kernel: iwlwifi 0000:03:00.0: Q 4
> is active and mapped to fifo 0 ra_tid 0x0000 [0,0] Jan 21 17:18:02
> n22 kernel: iwlwifi 0000:03:00.0: Q 5 is active and mapped to fifo
> 4 ra_tid 0x0000 [0,0] Jan 21 17:18:02 n22 kernel: iwlwifi
> 0000:03:00.0: Q 6 is active and mapped to fifo 2 ra_tid 0x0000
> [0,0] Jan 21 17:18:02 n22 kernel: iwlwifi 0000:03:00.0: Q 7 is
> active and mapped to fifo 5 ra_tid 0x0000 [0,0] Jan 21 17:18:02 n22
> kernel: iwlwifi 0000:03:00.0: Q 8 is active and mapped to fifo 4
> ra_tid 0x0000 [0,0] Jan 21 17:18:02 n22 kernel: iwlwifi
> 0000:03:00.0: Q 9 is active and mapped to fifo 7 ra_tid 0x0000
> [130,130] Jan 21 17:18:02 n22 kernel: iwlwifi 0000:03:00.0: Q 10 is
> active and mapped to fifo 5 ra_tid 0x0000 [0,0] Jan 21 17:18:02 n22
> kernel: iwlwifi 0000:03:00.0: Q 11 is inactive and mapped to fifo 0
> ra_tid 0x0000 [0,0] Jan 21 17:18:02 n22 kernel: iwlwifi
> 0000:03:00.0: Q 12 is inactive and mapped to fifo 0 ra_tid 0x0000
> [0,0] Jan 21 17:18:02 n22 kernel: iwlwifi 0000:03:00.0: Q 13 is
> inactive and mapped to fifo 0 ra_tid 0x0000 [0,0] Jan 21 17:18:02
> n22 kernel: iwlwifi 0000:03:00.0: Q 14 is inactive and mapped to
> fifo 0 ra_tid 0x0000 [0,0] Jan 21 17:18:02 n22 kernel: iwlwifi
> 0000:03:00.0: Q 15 is inactive and mapped to fifo 0 ra_tid 0x0000
> [0,0] Jan 21 17:18:02 n22 kernel: iwlwifi 0000:03:00.0: Q 16 is
> inactive and mapped to fifo 0 ra_tid 0x0000 [0,0] Jan 21 17:18:02
> n22 kernel: iwlwifi 0000:03:00.0: Q 17 is inactive and mapped to
> fifo 0 ra_tid 0x0000 [0,0] Jan 21 17:18:02 n22 kernel: iwlwifi
> 0000:03:00.0: Q 18 is inactive and mapped to fifo 0 ra_tid 0x0000
> [0,0] Jan 21 17:18:02 n22 kernel: iwlwifi 0000:03:00.0: Q 19 is
> inactive and mapped to fifo 0 ra_tid 0x0000 [0,0]


- --
MfG/Sincerely
Toralf Förster
pgp finger print:1A37 6F99 4A9D 026F 13E2 4DCF C4EA CDDE 0076 E94E
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v2.0.22 (GNU/Linux)
Comment: Using GnuPG with Thunderbird - http://www.enigmail.net/

iF4EAREIAAYFAlMKRQQACgkQxOrN3gB26U553gD/Vi1FtZgpiQ2nXXzVID+D8jCs
G+ofHYN3Jz14y2nRWgUA/R5/jA2g5WyJ3i23FALDO/qeGHRQq4BJW1RTvTKQXvxM
=H8HV
-----END PGP SIGNATURE-----

2014-02-24 20:39:13

by Toralf Förster

[permalink] [raw]
Subject: Re: 3.13 hangs when I tried to start a KVM at a 32 bit stable Gentoo

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA256

On 01/23/2014 07:55 PM, Dave Hansen wrote:
> On 01/21/2014 08:38 AM, Toralf Förster wrote:
>> Jan 21 17:18:57 n22 kernel: INFO: rcu_sched self-detected stall on CPU { 2} (t=60001 jiffies g=18494 c=18493 q=183951)
>> Jan 21 17:18:57 n22 kernel: sending NMI to all CPUs:
>> Jan 21 17:18:57 n22 kernel: NMI backtrace for cpu 2
>> Jan 21 17:18:57 n22 kernel: CPU: 2 PID: 6779 Comm: qemu-system-x86 Not tainted 3.13.0 #3
>> Jan 21 17:18:57 n22 kernel: Hardware name: LENOVO 4180F65/4180F65, BIOS 83ET75WW (1.45 ) 05/10/2013
>> Jan 21 17:18:57 n22 kernel: task: e921c370 ti: e5f36000 task.ti: e5f36000
>
> I'm seeing a very similar hang with an ubuntu guest and a custom kernel.
> I'm on commit 0dc3fd0249a, and it's 100% reproducible every time I run KVM.
>
> Cc-ing a few more folks...
>

I tried to bisect it - the first attempt to bisetc it between v3.12. and v3.13 blamed this commit :

commit 37bf06375c90a42fe07b9bebdb07bc316ae5a0ce
Merge: 6bfa687 d0e639c
Author: Ingo Molnar <[email protected]>
Date: Wed Oct 9 12:36:13 2013 +0200

Merge tag 'v3.12-rc4' into sched/core

Merge Linux v3.12-rc4 to fix a conflict and also to refresh the tree
before applying more scheduler patches.

Conflicts:
arch/avr32/include/asm/Kbuild

Signed-off-by: Ingo Molnar <[email protected]>


which seems rather to be the upper limit where to search for the first bad commit, or ?



- --
MfG/Sincerely
Toralf Förster
pgp finger print:1A37 6F99 4A9D 026F 13E2 4DCF C4EA CDDE 0076 E94E
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v2.0.22 (GNU/Linux)
Comment: Using GnuPG with Thunderbird - http://www.enigmail.net/

iF4EAREIAAYFAlMLregACgkQxOrN3gB26U7P7gD/Wage68loQ++oP4moD94kTNpn
goyT7fvssm3jyF+2HagA/0EIR5MOcl7xlBPNw5JKqcI0pPx0yBytUljtz+KTPS/Y
=P8vB
-----END PGP SIGNATURE-----