2.6.24 Kernel Soft Lock Up with heavy I/O in dm-crypt

2.6.24 Kernel Soft Lock Up with heavy I/O in dm-crypt

[Ritesh Raj Sarraf]

[-- Attachment #1.1: Type: text/plain, Size: 629 bytes --]

Hi Christophe,

I noted kernel soft lockup messages on my laptop when doing a lot of I/O 
(200GB) to a dm-crypt device. It was setup using LUKS.
The I/O never got disrupted nor anything failed. Just the messages.

Kernel: 2.6.24
Distribution: Debian Testing/Unstable
Tainted: Yes (nvidia proprietary drivers)

I've not filed a bugzilla because my kernel is a tainted kernel because of 
nvidia drivers.

I'm attaching the messages. Please let me know if it stands as a candidate for 
a bug report.


Ritesh
-- 
Ritesh Raj Sarraf
RESEARCHUT - http://www.researchut.com
"Necessity is the mother of invention."

[-- Attachment #1.2: kernel.bug --]
[-- Type: text/plain, Size: 30695 bytes --]

a200 EDI: 0000000a EBP: 00000000 ESP: f32bfd7c
 DS: 007b ES: 007b FS: 00d8 GS: 0000 SS: 0068
CR0: 8005003b CR2: b3c3e000 CR3: 003b5000 CR4: 000026d0
DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
DR6: ffff0ff0 DR7: 00000400
 [<c012902d>] do_softirq+0x45/0x53
 [<c0129291>] irq_exit+0x38/0x6b
 [<c01066f2>] do_IRQ+0x5a/0x70
 [<c01048c3>] common_interrupt+0x23/0x28
 [<f899202f>] xor_128+0x0/0x17 [cbc]
 [<f899237e>] crypto_cbc_encrypt+0xe4/0x146 [cbc]
 [<f899202f>] xor_128+0x0/0x17 [cbc]
 [<c01dd80a>] cfq_allow_merge+0x0/0x5a
 [<f89ad6ef>] aes_encrypt+0x0/0x17 [aes_i586]
 [<f88fe648>] crypt_convert_scatterlist+0x73/0xc3 [dm_crypt]
 [<f88fe7e0>] crypt_convert+0x148/0x185 [dm_crypt]
 [<f88fe9fe>] kcryptd_do_crypt+0x1e1/0x25e [dm_crypt]
 [<f88fe81d>] kcryptd_do_crypt+0x0/0x25e [dm_crypt]
 [<c0132225>] run_workqueue+0x7d/0x109
 [<c0135554>] prepare_to_wait+0x12/0x49
 [<c0132a9b>] worker_thread+0x0/0xc5
 [<c0132b55>] worker_thread+0xba/0xc5
 [<c0135441>] autoremove_wake_function+0x0/0x35
 [<c013537a>] kthread+0x38/0x5e
 [<c0135342>] kthread+0x0/0x5e
 [<c0104b0f>] kernel_thread_helper+0x7/0x10
 =======================
BUG: soft lockup - CPU#0 stuck for 11s! [kcryptd:22652]

Pid: 22652, comm: kcryptd Tainted: P        (2.6.24-1-686 #1)
EIP: 0060:[<c0128f6c>] EFLAGS: 00000202 CPU: 0
EIP is at __do_softirq+0x57/0xd3
EAX: c03b4860 EBX: 00000020 ECX: 00000009 EDX: 01c5c000
ESI: c036a200 EDI: 0000000a EBP: 00000000 ESP: f32bfd30
 DS: 007b ES: 007b FS: 00d8 GS: 0000 SS: 0068
CR0: 8005003b CR2: b3c3e000 CR3: 003b5000 CR4: 000026d0
DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
DR6: ffff0ff0 DR7: 00000400
 [<c012902d>] do_softirq+0x45/0x53
 [<c0129291>] irq_exit+0x38/0x6b
 [<c01066f2>] do_IRQ+0x5a/0x70
 [<c01048c3>] common_interrupt+0x23/0x28
 [<c01100d8>] cyrix_get_arr+0xb4/0x126
 [<c011ad36>] native_flush_tlb_single+0x3/0x4
 [<c011d0e9>] kunmap_atomic+0x60/0x94
 [<f89742d5>] blkcipher_walk_done+0x87/0x1fe [blkcipher]
 [<f89923cc>] crypto_cbc_encrypt+0x132/0x146 [cbc]
 [<f899202f>] xor_128+0x0/0x17 [cbc]
 [<c01dd80a>] cfq_allow_merge+0x0/0x5a
 [<f89ad6ef>] aes_encrypt+0x0/0x17 [aes_i586]
 [<f88fe648>] crypt_convert_scatterlist+0x73/0xc3 [dm_crypt]
 [<f88fe7e0>] crypt_convert+0x148/0x185 [dm_crypt]
 [<f88fe9fe>] kcryptd_do_crypt+0x1e1/0x25e [dm_crypt]
 [<f88fe81d>] kcryptd_do_crypt+0x0/0x25e [dm_crypt]
 [<c0132225>] run_workqueue+0x7d/0x109
 [<c0135554>] prepare_to_wait+0x12/0x49
 [<c0132a9b>] worker_thread+0x0/0xc5
 [<c0132b55>] worker_thread+0xba/0xc5
 [<c0135441>] autoremove_wake_function+0x0/0x35
 [<c013537a>] kthread+0x38/0x5e
 [<c0135342>] kthread+0x0/0x5e
 [<c0104b0f>] kernel_thread_helper+0x7/0x10
 =======================
BUG: soft lockup - CPU#0 stuck for 11s! [kcryptd:22652]

Pid: 22652, comm: kcryptd Tainted: P        (2.6.24-1-686 #1)
EIP: 0060:[<f89ac666>] EFLAGS: 00000286 CPU: 0
EIP is at aes_enc_blk+0x666/0xb6c [aes_i586]
EAX: 2605adab EBX: b84a5bae ECX: 04fa11f8 EDX: 000000f8
ESI: b3d37092 EDI: 8c24d4a9 EBP: f518f030 ESP: f32bfdcc
 DS: 007b ES: 007b FS: 00d8 GS: 0000 SS: 0068
CR0: 8005003b CR2: b3c3e000 CR3: 003b5000 CR4: 000026d0
DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
DR6: ffff0ff0 DR7: 00000400
 [<f89ad702>] aes_encrypt+0x13/0x17 [aes_i586]
 [<f899238d>] crypto_cbc_encrypt+0xf3/0x146 [cbc]
 [<f899202f>] xor_128+0x0/0x17 [cbc]
 [<c01dd80a>] cfq_allow_merge+0x0/0x5a
 [<f89ad6ef>] aes_encrypt+0x0/0x17 [aes_i586]
 [<f88fe648>] crypt_convert_scatterlist+0x73/0xc3 [dm_crypt]
 [<f88fe7e0>] crypt_convert+0x148/0x185 [dm_crypt]
 [<f88fe9fe>] kcryptd_do_crypt+0x1e1/0x25e [dm_crypt]
 [<f88fe81d>] kcryptd_do_crypt+0x0/0x25e [dm_crypt]
 [<c0132225>] run_workqueue+0x7d/0x109
 [<c0135554>] prepare_to_wait+0x12/0x49
 [<c0132a9b>] worker_thread+0x0/0xc5
 [<c0132b55>] worker_thread+0xba/0xc5
 [<c0135441>] autoremove_wake_function+0x0/0x35
 [<c013537a>] kthread+0x38/0x5e
 [<c0135342>] kthread+0x0/0x5e
 [<c0104b0f>] kernel_thread_helper+0x7/0x10
 =======================
iwl3945: Microcode SW error detected.  Restarting 0x82000008.
iwl3945: Can't stop Rx DMA.
BUG: soft lockup - CPU#0 stuck for 11s! [kcryptd:22652]

Pid: 22652, comm: kcryptd Tainted: P        (2.6.24-1-686 #1)
EIP: 0060:[<c02bda19>] EFLAGS: 00000292 CPU: 0
EIP is at _spin_unlock_irqrestore+0xa/0x13
EAX: 00000292 EBX: f6eff300 ECX: 00000292 EDX: 00000200
ESI: f6eff314 EDI: 00000292 EBP: f6f9fffc ESP: f32bfcc4
 DS: 007b ES: 007b FS: 00d8 GS: 0000 SS: 0068
CR0: 8005003b CR2: b4e7d000 CR3: 003b5000 CR4: 000026d0
DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
DR6: ffff0ff0 DR7: 00000400
 [<f991b6f6>] os_release_sema+0x3b/0x5a [nvidia]
 [<f98793bf>] _nv003771rm+0x9/0x12 [nvidia]
 [<f987b1e9>] _nv002876rm+0x8f/0x99 [nvidia]
 [<f987fdee>] rm_isr_bh+0x77/0xa2 [nvidia]
 [<f9918ad1>] nv_kern_isr_bh+0x73/0x79 [nvidia]
 [<c01293e3>] tasklet_action+0x58/0xb8
 [<c0128f7b>] __do_softirq+0x66/0xd3
 [<c012902d>] do_softirq+0x45/0x53
 [<c0129291>] irq_exit+0x38/0x6b
 [<c01066f2>] do_IRQ+0x5a/0x70
 [<c01292ac>] irq_exit+0x53/0x6b
 [<c0115e6c>] smp_apic_timer_interrupt+0x71/0x7d
 [<c01048c3>] common_interrupt+0x23/0x28
 [<c01d007b>] cap_syslog+0x1d/0x20
 [<f89ac4d6>] aes_enc_blk+0x4d6/0xb6c [aes_i586]
 [<f89ad702>] aes_encrypt+0x13/0x17 [aes_i586]
 [<f899238d>] crypto_cbc_encrypt+0xf3/0x146 [cbc]
 [<f899202f>] xor_128+0x0/0x17 [cbc]
 [<c01dd80a>] cfq_allow_merge+0x0/0x5a
 [<f89ad6ef>] aes_encrypt+0x0/0x17 [aes_i586]
 [<f88fe648>] crypt_convert_scatterlist+0x73/0xc3 [dm_crypt]
 [<f88fe7e0>] crypt_convert+0x148/0x185 [dm_crypt]
 [<f88fe9fe>] kcryptd_do_crypt+0x1e1/0x25e [dm_crypt]
 [<f88fe81d>] kcryptd_do_crypt+0x0/0x25e [dm_crypt]
 [<c0132225>] run_workqueue+0x7d/0x109
 [<c0135554>] prepare_to_wait+0x12/0x49
 [<c0132a9b>] worker_thread+0x0/0xc5
 [<c0132b55>] worker_thread+0xba/0xc5
 [<c0135441>] autoremove_wake_function+0x0/0x35
 [<c013537a>] kthread+0x38/0x5e
 [<c0135342>] kthread+0x0/0x5e
 [<c0104b0f>] kernel_thread_helper+0x7/0x10
 =======================
BUG: soft lockup - CPU#0 stuck for 11s! [kcryptd:22652]

Pid: 22652, comm: kcryptd Tainted: P        (2.6.24-1-686 #1)
EIP: 0060:[<f899203f>] EFLAGS: 00000286 CPU: 0
EIP is at xor_128+0x10/0x17 [cbc]
EAX: f32bfe80 EBX: 00000010 ECX: dc801d88 EDX: fffb7200
ESI: f5fa0340 EDI: f8901114 EBP: fffb7200 ESP: f32bfdf4
 DS: 007b ES: 007b FS: 00d8 GS: 0000 SS: 0068
CR0: 8005003b CR2: b4e7d000 CR3: 003b5000 CR4: 000026d0
DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
DR6: ffff0ff0 DR7: 00000400
 [<f899237e>] crypto_cbc_encrypt+0xe4/0x146 [cbc]
 [<f899202f>] xor_128+0x0/0x17 [cbc]
 [<c01dd80a>] cfq_allow_merge+0x0/0x5a
 [<f89ad6ef>] aes_encrypt+0x0/0x17 [aes_i586]
 [<f88fe648>] crypt_convert_scatterlist+0x73/0xc3 [dm_crypt]
 [<f88fe7e0>] crypt_convert+0x148/0x185 [dm_crypt]
 [<f88fe9fe>] kcryptd_do_crypt+0x1e1/0x25e [dm_crypt]
 [<f88fe81d>] kcryptd_do_crypt+0x0/0x25e [dm_crypt]
 [<c0132225>] run_workqueue+0x7d/0x109
 [<c0135554>] prepare_to_wait+0x12/0x49
 [<c0132a9b>] worker_thread+0x0/0xc5
 [<c0132b55>] worker_thread+0xba/0xc5
 [<c0135441>] autoremove_wake_function+0x0/0x35
 [<c013537a>] kthread+0x38/0x5e
 [<c0135342>] kthread+0x0/0x5e
 [<c0104b0f>] kernel_thread_helper+0x7/0x10
 =======================
BUG: soft lockup - CPU#0 stuck for 11s! [kcryptd:22652]

Pid: 22652, comm: kcryptd Tainted: P        (2.6.24-1-686 #1)
EIP: 0060:[<f89ac783>] EFLAGS: 00000202 CPU: 0
EIP is at aes_enc_blk+0x783/0xb6c [aes_i586]
EAX: 81754e72 EBX: 51bcfa68 ECX: 000000d0 EDX: 0000008b
ESI: cbd409ea EDI: 45dc1dbb EBP: f518f030 ESP: f32bfdcc
 DS: 007b ES: 007b FS: 00d8 GS: 0000 SS: 0068
CR0: 8005003b CR2: b4e7d000 CR3: 003b5000 CR4: 000026d0
DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
DR6: ffff0ff0 DR7: 00000400
 [<f89ad702>] aes_encrypt+0x13/0x17 [aes_i586]
 [<f899238d>] crypto_cbc_encrypt+0xf3/0x146 [cbc]
 [<f899202f>] xor_128+0x0/0x17 [cbc]
 [<c01dd80a>] cfq_allow_merge+0x0/0x5a
 [<f89ad6ef>] aes_encrypt+0x0/0x17 [aes_i586]
 [<f88fe648>] crypt_convert_scatterlist+0x73/0xc3 [dm_crypt]
 [<f88fe7e0>] crypt_convert+0x148/0x185 [dm_crypt]
 [<f88fe9fe>] kcryptd_do_crypt+0x1e1/0x25e [dm_crypt]
 [<f88fe81d>] kcryptd_do_crypt+0x0/0x25e [dm_crypt]
 [<c0132225>] run_workqueue+0x7d/0x109
 [<c0135554>] prepare_to_wait+0x12/0x49
 [<c0132a9b>] worker_thread+0x0/0xc5
 [<c0132b55>] worker_thread+0xba/0xc5
 [<c0135441>] autoremove_wake_function+0x0/0x35
 [<c013537a>] kthread+0x38/0x5e
 [<c0135342>] kthread+0x0/0x5e
 [<c0104b0f>] kernel_thread_helper+0x7/0x10
 =======================
BUG: soft lockup - CPU#0 stuck for 11s! [kcryptd:22652]

Pid: 22652, comm: kcryptd Tainted: P        (2.6.24-1-686 #1)
EIP: 0060:[<c0128f6c>] EFLAGS: 00000202 CPU: 0
EIP is at __do_softirq+0x57/0xd3
EAX: c03b4860 EBX: 00000020 ECX: 00000009 EDX: 01c5c000
ESI: c036a200 EDI: 0000000a EBP: 00000000 ESP: f32bfd54
 DS: 007b ES: 007b FS: 00d8 GS: 0000 SS: 0068
CR0: 8005003b CR2: b4e7d000 CR3: 003b5000 CR4: 000026d0
DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
DR6: ffff0ff0 DR7: 00000400
 [<c012902d>] do_softirq+0x45/0x53
 [<c0129291>] irq_exit+0x38/0x6b
 [<c01066f2>] do_IRQ+0x5a/0x70
 [<c01292ac>] irq_exit+0x53/0x6b
 [<c01066f2>] do_IRQ+0x5a/0x70
 [<c01048c3>] common_interrupt+0x23/0x28
 [<c01d007b>] cap_syslog+0x1d/0x20
 [<f89ac3b1>] aes_enc_blk+0x3b1/0xb6c [aes_i586]
 [<f89ad702>] aes_encrypt+0x13/0x17 [aes_i586]
 [<f899238d>] crypto_cbc_encrypt+0xf3/0x146 [cbc]
 [<f899202f>] xor_128+0x0/0x17 [cbc]
 [<c01dd80a>] cfq_allow_merge+0x0/0x5a
 [<f89ad6ef>] aes_encrypt+0x0/0x17 [aes_i586]
 [<f88fe648>] crypt_convert_scatterlist+0x73/0xc3 [dm_crypt]
 [<f88fe7e0>] crypt_convert+0x148/0x185 [dm_crypt]
 [<f88fe9fe>] kcryptd_do_crypt+0x1e1/0x25e [dm_crypt]
 [<f88fe81d>] kcryptd_do_crypt+0x0/0x25e [dm_crypt]
 [<c0132225>] run_workqueue+0x7d/0x109
 [<c0135554>] prepare_to_wait+0x12/0x49
 [<c0132a9b>] worker_thread+0x0/0xc5
 [<c0132b55>] worker_thread+0xba/0xc5
 [<c0135441>] autoremove_wake_function+0x0/0x35
 [<c013537a>] kthread+0x38/0x5e
 [<c0135342>] kthread+0x0/0x5e
 [<c0104b0f>] kernel_thread_helper+0x7/0x10
 =======================
BUG: soft lockup - CPU#0 stuck for 11s! [kcryptd:22652]

Pid: 22652, comm: kcryptd Tainted: P        (2.6.24-1-686 #1)
EIP: 0060:[<f89ac590>] EFLAGS: 00000202 CPU: 0
EIP is at aes_enc_blk+0x590/0xb6c [aes_i586]
EAX: 000000c8 EBX: bf1ada9f ECX: 8a4a7f71 EDX: 000000fd
ESI: 2bb72c79 EDI: c22842b9 EBP: f518f030 ESP: f32bfdcc
 DS: 007b ES: 007b FS: 00d8 GS: 0000 SS: 0068
CR0: 8005003b CR2: b4e7d000 CR3: 003b5000 CR4: 000026d0
DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
DR6: ffff0ff0 DR7: 00000400
 [<f89ad702>] aes_encrypt+0x13/0x17 [aes_i586]
 [<f899238d>] crypto_cbc_encrypt+0xf3/0x146 [cbc]
 [<f899202f>] xor_128+0x0/0x17 [cbc]
 [<c01dd80a>] cfq_allow_merge+0x0/0x5a
 [<f89ad6ef>] aes_encrypt+0x0/0x17 [aes_i586]
 [<f88fe648>] crypt_convert_scatterlist+0x73/0xc3 [dm_crypt]
 [<f88fe7e0>] crypt_convert+0x148/0x185 [dm_crypt]
 [<f88fe9fe>] kcryptd_do_crypt+0x1e1/0x25e [dm_crypt]
 [<f88fe81d>] kcryptd_do_crypt+0x0/0x25e [dm_crypt]
 [<c0132225>] run_workqueue+0x7d/0x109
 [<c0135554>] prepare_to_wait+0x12/0x49
 [<c0132a9b>] worker_thread+0x0/0xc5
 [<c0132b55>] worker_thread+0xba/0xc5
 [<c0135441>] autoremove_wake_function+0x0/0x35
 [<c013537a>] kthread+0x38/0x5e
 [<c0135342>] kthread+0x0/0x5e
 [<c0104b0f>] kernel_thread_helper+0x7/0x10
 =======================
iwl3945: Microcode SW error detected.  Restarting 0x82000008.
iwl3945: Can't stop Rx DMA.
wlan0_rename: Initial auth_alg=0
wlan0_rename: authenticate with AP 00:16:b6:a5:e7:1c
wlan0_rename: RX authentication from 00:16:b6:a5:e7:1c (alg=0 transaction=2 status=0)
wlan0_rename: authenticated
wlan0_rename: associate with AP 00:16:b6:a5:e7:1c
wlan0_rename: RX ReassocResp from 00:16:b6:a5:e7:1c (capab=0x411 status=0 aid=1)
wlan0_rename: associated
wlan0_rename: WMM queue=2 aci=0 acm=0 aifs=3 cWmin=15 cWmax=1023 burst=0
wlan0_rename: WMM queue=3 aci=1 acm=0 aifs=7 cWmin=15 cWmax=1023 burst=0
wlan0_rename: WMM queue=1 aci=2 acm=0 aifs=2 cWmin=7 cWmax=15 burst=30
wlan0_rename: WMM queue=0 aci=3 acm=0 aifs=2 cWmin=3 cWmax=7 burst=15
ADDRCONF(NETDEV_CHANGE): wlan0_rename: link becomes ready
wlan0_rename: deauthenticate(reason=3)
ADDRCONF(NETDEV_UP): wlan0_rename: link is not ready
BUG: soft lockup - CPU#1 stuck for 11s! [kcryptd:22652]

Pid: 22652, comm: kcryptd Tainted: P        (2.6.24-1-686 #1)
EIP: 0060:[<f89ac575>] EFLAGS: 00000207 CPU: 1
EIP is at aes_enc_blk+0x575/0xb6c [aes_i586]
EAX: 00002cd1 EBX: fbfb97b0 ECX: 529e504e EDX: 000000a4
ESI: 00e87e9a EDI: f5e85f79 EBP: f518f030 ESP: f32bfdcc
 DS: 007b ES: 007b FS: 00d8 GS: 0000 SS: 0068
CR0: 8005003b CR2: 080fcf18 CR3: 332cf000 CR4: 000026d0
DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
DR6: ffff0ff0 DR7: 00000400
 [<f89ad702>] aes_encrypt+0x13/0x17 [aes_i586]
 [<f899238d>] crypto_cbc_encrypt+0xf3/0x146 [cbc]
 [<f899202f>] xor_128+0x0/0x17 [cbc]
 [<f89ad6ef>] aes_encrypt+0x0/0x17 [aes_i586]
 [<f88fe648>] crypt_convert_scatterlist+0x73/0xc3 [dm_crypt]
 [<f88fe7e0>] crypt_convert+0x148/0x185 [dm_crypt]
 [<f88fe9fe>] kcryptd_do_crypt+0x1e1/0x25e [dm_crypt]
 [<f88fe81d>] kcryptd_do_crypt+0x0/0x25e [dm_crypt]
 [<c0132225>] run_workqueue+0x7d/0x109
 [<c0135554>] prepare_to_wait+0x12/0x49
 [<c0132a9b>] worker_thread+0x0/0xc5
 [<c0132b55>] worker_thread+0xba/0xc5
 [<c0135441>] autoremove_wake_function+0x0/0x35
 [<c013537a>] kthread+0x38/0x5e
 [<c0135342>] kthread+0x0/0x5e
 [<c0104b0f>] kernel_thread_helper+0x7/0x10
 =======================
BUG: soft lockup - CPU#0 stuck for 11s! [kcryptd:22652]

Pid: 22652, comm: kcryptd Tainted: P        (2.6.24-1-686 #1)
EIP: 0060:[<f89ac957>] EFLAGS: 00000282 CPU: 0
EIP is at aes_enc_blk+0x957/0xb6c [aes_i586]
EAX: 23678e89 EBX: f1c85eec ECX: 7c69a25c EDX: 0000005c
ESI: b61fba3a EDI: 59230267 EBP: f518f030 ESP: f32bfdcc
 DS: 007b ES: 007b FS: 00d8 GS: 0000 SS: 0068
CR0: 8005003b CR2: b7ee7ed4 CR3: 003b5000 CR4: 000026d0
DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
DR6: ffff0ff0 DR7: 00000400
 [<f89ad702>] aes_encrypt+0x13/0x17 [aes_i586]
 [<f899238d>] crypto_cbc_encrypt+0xf3/0x146 [cbc]
 [<f899202f>] xor_128+0x0/0x17 [cbc]
 [<c01dd80a>] cfq_allow_merge+0x0/0x5a
 [<f89ad6ef>] aes_encrypt+0x0/0x17 [aes_i586]
 [<f88fe648>] crypt_convert_scatterlist+0x73/0xc3 [dm_crypt]
 [<f88fe7e0>] crypt_convert+0x148/0x185 [dm_crypt]
 [<f88fe9fe>] kcryptd_do_crypt+0x1e1/0x25e [dm_crypt]
 [<f88fe81d>] kcryptd_do_crypt+0x0/0x25e [dm_crypt]
 [<c0132225>] run_workqueue+0x7d/0x109
 [<c0135554>] prepare_to_wait+0x12/0x49
 [<c0132a9b>] worker_thread+0x0/0xc5
 [<c0132b55>] worker_thread+0xba/0xc5
 [<c0135441>] autoremove_wake_function+0x0/0x35
 [<c013537a>] kthread+0x38/0x5e
 [<c0135342>] kthread+0x0/0x5e
 [<c0104b0f>] kernel_thread_helper+0x7/0x10
 =======================
BUG: soft lockup - CPU#1 stuck for 11s! [kcryptd:22652]

Pid: 22652, comm: kcryptd Tainted: P        (2.6.24-1-686 #1)
EIP: 0060:[<f89ac9a0>] EFLAGS: 00000282 CPU: 1
EIP is at aes_enc_blk+0x9a0/0xb6c [aes_i586]
EAX: a3e4820a EBX: 835f477f ECX: 0000003e EDX: 000000b8
ESI: d4e9965a EDI: a3dce360 EBP: f518f030 ESP: f32bfdcc
 DS: 007b ES: 007b FS: 00d8 GS: 0000 SS: 0068
CR0: 8005003b CR2: b7f02000 CR3: 25df4000 CR4: 000026d0
DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
DR6: ffff0ff0 DR7: 00000400
 [<f89ad702>] aes_encrypt+0x13/0x17 [aes_i586]
 [<f899238d>] crypto_cbc_encrypt+0xf3/0x146 [cbc]
 [<f899202f>] xor_128+0x0/0x17 [cbc]
 [<c01dd80a>] cfq_allow_merge+0x0/0x5a
 [<f89ad6ef>] aes_encrypt+0x0/0x17 [aes_i586]
 [<f88fe648>] crypt_convert_scatterlist+0x73/0xc3 [dm_crypt]
 [<f88fe7e0>] crypt_convert+0x148/0x185 [dm_crypt]
 [<f88fe9fe>] kcryptd_do_crypt+0x1e1/0x25e [dm_crypt]
 [<f88fe81d>] kcryptd_do_crypt+0x0/0x25e [dm_crypt]
 [<c0132225>] run_workqueue+0x7d/0x109
 [<c0135554>] prepare_to_wait+0x12/0x49
 [<c0132a9b>] worker_thread+0x0/0xc5
 [<c0132b55>] worker_thread+0xba/0xc5
 [<c0135441>] autoremove_wake_function+0x0/0x35
 [<c013537a>] kthread+0x38/0x5e
 [<c0135342>] kthread+0x0/0x5e
 [<c0104b0f>] kernel_thread_helper+0x7/0x10
 =======================
BUG: soft lockup - CPU#1 stuck for 11s! [kcryptd:22652]

Pid: 22652, comm: kcryptd Tainted: P        (2.6.24-1-686 #1)
EIP: 0060:[<f89ac3cb>] EFLAGS: 00000206 CPU: 1
EIP is at aes_enc_blk+0x3cb/0xb6c [aes_i586]
EAX: 00000088 EBX: 3f2b4328 ECX: 4ad5ff0f EDX: 00000009
ESI: d5ca35ba EDI: a3755a93 EBP: f518f030 ESP: f32bfdcc
 DS: 007b ES: 007b FS: 00d8 GS: 0000 SS: 0068
CR0: 8005003b CR2: b7f02000 CR3: 25df4000 CR4: 000026d0
DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
DR6: ffff0ff0 DR7: 00000400
 [<f89ad702>] aes_encrypt+0x13/0x17 [aes_i586]
 [<f899238d>] crypto_cbc_encrypt+0xf3/0x146 [cbc]
 [<f899202f>] xor_128+0x0/0x17 [cbc]
 [<c01dd80a>] cfq_allow_merge+0x0/0x5a
 [<f89ad6ef>] aes_encrypt+0x0/0x17 [aes_i586]
 [<f88fe648>] crypt_convert_scatterlist+0x73/0xc3 [dm_crypt]
 [<f88fe7e0>] crypt_convert+0x148/0x185 [dm_crypt]
 [<f88fe9fe>] kcryptd_do_crypt+0x1e1/0x25e [dm_crypt]
 [<f88fe81d>] kcryptd_do_crypt+0x0/0x25e [dm_crypt]
 [<c0132225>] run_workqueue+0x7d/0x109
 [<c0135554>] prepare_to_wait+0x12/0x49
 [<c0132a9b>] worker_thread+0x0/0xc5
 [<c0132b55>] worker_thread+0xba/0xc5
 [<c0135441>] autoremove_wake_function+0x0/0x35
 [<c013537a>] kthread+0x38/0x5e
 [<c0135342>] kthread+0x0/0x5e
 [<c0104b0f>] kernel_thread_helper+0x7/0x10
 =======================
BUG: soft lockup - CPU#0 stuck for 11s! [kcryptd:22652]

Pid: 22652, comm: kcryptd Tainted: P        (2.6.24-1-686 #1)
EIP: 0060:[<c0175502>] EFLAGS: 00000206 CPU: 0
EIP is at kmem_cache_alloc+0x55/0x84
EAX: 00000206 EBX: f33a0070 ECX: f7c812c0 EDX: f7c8c600
ESI: f7c812c0 EDI: 00000206 EBP: 00011200 ESP: f32bfd80
 DS: 007b ES: 007b FS: 00d8 GS: 0000 SS: 0068
CR0: 8005003b CR2: 0840d8dc CR3: 003b5000 CR4: 000026d0
DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
DR6: ffff0ff0 DR7: 00000400
 [<c015ce79>] mempool_alloc+0x1c/0xba
 [<c011cfbd>] kmap_atomic_prot+0x9c/0xcb
 [<c01d6537>] get_request+0x153/0x2c9
 [<f897439d>] blkcipher_walk_done+0x14f/0x1fe [blkcipher]
 [<c01d6eb3>] get_request_wait+0x26/0x175
 [<c01dd83d>] cfq_allow_merge+0x33/0x5a
 [<c01dd80a>] cfq_allow_merge+0x0/0x5a
 [<c01d3291>] elv_iosched_allow_merge+0x21/0x25
 [<c01d42f8>] elv_merge+0x59/0x1b1
 [<c01d8193>] __make_request+0x44f/0x4ff
 [<f88fe648>] crypt_convert_scatterlist+0x73/0xc3 [dm_crypt]
 [<c01d577e>] generic_make_request+0x3b3/0x3e1
 [<f88fe7e0>] crypt_convert+0x148/0x185 [dm_crypt]
 [<f88fea5b>] kcryptd_do_crypt+0x23e/0x25e [dm_crypt]
 [<f88fe81d>] kcryptd_do_crypt+0x0/0x25e [dm_crypt]
 [<c0132225>] run_workqueue+0x7d/0x109
 [<c0135554>] prepare_to_wait+0x12/0x49
 [<c0132a9b>] worker_thread+0x0/0xc5
 [<c0132b55>] worker_thread+0xba/0xc5
 [<c0135441>] autoremove_wake_function+0x0/0x35
 [<c013537a>] kthread+0x38/0x5e
 [<c0135342>] kthread+0x0/0x5e
 [<c0104b0f>] kernel_thread_helper+0x7/0x10
 =======================
usb 1-1: USB disconnect, address 18
usb 1-1: new high speed USB device using ehci_hcd and address 19
usb 1-1: configuration #1 chosen from 1 choice
scsi10 : SCSI emulation for USB Mass Storage devices
usb-storage: device found at 19
usb-storage: waiting for device to settle before scanning
usb-storage: device scan complete
scsi 10:0:0:0: Direct-Access     WD       1600BEV External 1.04 PQ: 0 ANSI: 4
sd 10:0:0:0: [sdc] 312581808 512-byte hardware sectors (160042 MB)
sd 10:0:0:0: [sdc] Write Protect is off
sd 10:0:0:0: [sdc] Mode Sense: 21 00 00 00
sd 10:0:0:0: [sdc] Assuming drive cache: write through
sd 10:0:0:0: [sdc] 312581808 512-byte hardware sectors (160042 MB)
sd 10:0:0:0: [sdc] Write Protect is off
sd 10:0:0:0: [sdc] Mode Sense: 21 00 00 00
sd 10:0:0:0: [sdc] Assuming drive cache: write through
 sdc: sdc1
sd 10:0:0:0: [sdc] Attached SCSI disk
sd 10:0:0:0: Attached scsi generic sg3 type 0
SELinux: initialized (dev sdc1, type vfat), uses genfs_contexts
usb 1-1: USB disconnect, address 19
usb 1-1: new high speed USB device using ehci_hcd and address 20
usb 1-1: configuration #1 chosen from 1 choice
scsi11 : SCSI emulation for USB Mass Storage devices
usb-storage: device found at 20
usb-storage: waiting for device to settle before scanning
usb-storage: device scan complete
scsi 11:0:0:0: Direct-Access     ST912082 2A               0811 PQ: 0 ANSI: 0
sd 11:0:0:0: [sdc] 234441648 512-byte hardware sectors (120034 MB)
sd 11:0:0:0: [sdc] Test WP failed, assume Write Enabled
sd 11:0:0:0: [sdc] Assuming drive cache: write through
sd 11:0:0:0: [sdc] 234441648 512-byte hardware sectors (120034 MB)
sd 11:0:0:0: [sdc] Test WP failed, assume Write Enabled
sd 11:0:0:0: [sdc] Assuming drive cache: write through
 sdc: sdc1 sdc2 sdc3
sd 11:0:0:0: [sdc] Attached SCSI disk
sd 11:0:0:0: Attached scsi generic sg3 type 0
kjournald starting.  Commit interval 5 seconds
EXT3 FS on sdc1, internal journal
EXT3-fs: mounted filesystem with ordered data mode.
SELinux: initialized (dev sdc1, type ext3), uses xattr
BUG: soft lockup - CPU#0 stuck for 11s! [kcryptd:22652]

Pid: 22652, comm: kcryptd Tainted: P        (2.6.24-1-686 #1)
EIP: 0060:[<f89ac7d4>] EFLAGS: 00000282 CPU: 0
EIP is at aes_enc_blk+0x7d4/0xb6c [aes_i586]
EAX: edc4b146 EBX: d596de83 ECX: 0000c8f1 EDX: 000000f4
ESI: 45a60374 EDI: 9dd50ec9 EBP: f518f030 ESP: f32bfdcc
 DS: 007b ES: 007b FS: 00d8 GS: 0000 SS: 0068
CR0: 8005003b CR2: b4434000 CR3: 003b5000 CR4: 000026d0
DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
DR6: ffff0ff0 DR7: 00000400
 [<f89ad702>] aes_encrypt+0x13/0x17 [aes_i586]
 [<f899238d>] crypto_cbc_encrypt+0xf3/0x146 [cbc]
 [<f899202f>] xor_128+0x0/0x17 [cbc]
 [<c01dd80a>] cfq_allow_merge+0x0/0x5a
 [<f89ad6ef>] aes_encrypt+0x0/0x17 [aes_i586]
 [<f88fe648>] crypt_convert_scatterlist+0x73/0xc3 [dm_crypt]
 [<f88fe7e0>] crypt_convert+0x148/0x185 [dm_crypt]
 [<f88fe9fe>] kcryptd_do_crypt+0x1e1/0x25e [dm_crypt]
 [<f88fe81d>] kcryptd_do_crypt+0x0/0x25e [dm_crypt]
 [<c0132225>] run_workqueue+0x7d/0x109
 [<c0132a9b>] worker_thread+0x0/0xc5
 [<c0132b55>] worker_thread+0xba/0xc5
 [<c0135441>] autoremove_wake_function+0x0/0x35
 [<c013537a>] kthread+0x38/0x5e
 [<c0135342>] kthread+0x0/0x5e
 [<c0104b0f>] kernel_thread_helper+0x7/0x10
 =======================
BUG: soft lockup - CPU#0 stuck for 11s! [kcryptd:22652]

Pid: 22652, comm: kcryptd Tainted: P        (2.6.24-1-686 #1)
EIP: 0060:[<f89ac82e>] EFLAGS: 00000282 CPU: 0
EIP is at aes_enc_blk+0x82e/0xb6c [aes_i586]
EAX: b067668e EBX: 04ac9072 ECX: deee0d83 EDX: 0000008e
ESI: 3214ce69 EDI: 04b1f0a0 EBP: f518f030 ESP: f32bfdcc
 DS: 007b ES: 007b FS: 00d8 GS: 0000 SS: 0068
CR0: 8005003b CR2: b4434000 CR3: 003b5000 CR4: 000026d0
DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
DR6: ffff0ff0 DR7: 00000400
 [<f89ad702>] aes_encrypt+0x13/0x17 [aes_i586]
 [<f899238d>] crypto_cbc_encrypt+0xf3/0x146 [cbc]
 [<f899202f>] xor_128+0x0/0x17 [cbc]
 [<c01dd80a>] cfq_allow_merge+0x0/0x5a
 [<f89ad6ef>] aes_encrypt+0x0/0x17 [aes_i586]
 [<f88fe648>] crypt_convert_scatterlist+0x73/0xc3 [dm_crypt]
 [<f88fe7e0>] crypt_convert+0x148/0x185 [dm_crypt]
 [<f88fe9fe>] kcryptd_do_crypt+0x1e1/0x25e [dm_crypt]
 [<f88fe81d>] kcryptd_do_crypt+0x0/0x25e [dm_crypt]
 [<c0132225>] run_workqueue+0x7d/0x109
 [<c0132a9b>] worker_thread+0x0/0xc5
 [<c0132b55>] worker_thread+0xba/0xc5
 [<c0135441>] autoremove_wake_function+0x0/0x35
 [<c013537a>] kthread+0x38/0x5e
 [<c0135342>] kthread+0x0/0x5e
 [<c0104b0f>] kernel_thread_helper+0x7/0x10
 =======================
BUG: soft lockup - CPU#0 stuck for 11s! [kcryptd:22652]

Pid: 22652, comm: kcryptd Tainted: P        (2.6.24-1-686 #1)
EIP: 0060:[<f8974726>] EFLAGS: 00000282 CPU: 0
EIP is at blkcipher_walk_first+0x4/0x179 [blkcipher]
EAX: f32bfea4 EBX: f518f000 ECX: 00000010 EDX: f32bfe20
ESI: f5fa0340 EDI: f8901114 EBP: f32bfe20 ESP: f32bfdec
 DS: 007b ES: 007b FS: 00d8 GS: 0000 SS: 0068
CR0: 8005003b CR2: 0843d7c0 CR3: 1ff64000 CR4: 000026d0
DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
DR6: ffff0ff0 DR7: 00000400
 [<f89922d4>] crypto_cbc_encrypt+0x3a/0x146 [cbc]
 [<f899202f>] xor_128+0x0/0x17 [cbc]
 [<c01dd80a>] cfq_allow_merge+0x0/0x5a
 [<f89ad6ef>] aes_encrypt+0x0/0x17 [aes_i586]
 [<f89ad702>] aes_encrypt+0x13/0x17 [aes_i586]
 [<f88fe648>] crypt_convert_scatterlist+0x73/0xc3 [dm_crypt]
 [<f88fe7e0>] crypt_convert+0x148/0x185 [dm_crypt]
 [<f88fe9fe>] kcryptd_do_crypt+0x1e1/0x25e [dm_crypt]
 [<f88fe81d>] kcryptd_do_crypt+0x0/0x25e [dm_crypt]
 [<c0132225>] run_workqueue+0x7d/0x109
 [<c0135554>] prepare_to_wait+0x12/0x49
 [<c0132a9b>] worker_thread+0x0/0xc5
 [<c0132b55>] worker_thread+0xba/0xc5
 [<c0135441>] autoremove_wake_function+0x0/0x35
 [<c013537a>] kthread+0x38/0x5e
 [<c0135342>] kthread+0x0/0x5e
 [<c0104b0f>] kernel_thread_helper+0x7/0x10
 =======================
BUG: soft lockup - CPU#0 stuck for 11s! [kcryptd:22652]

Pid: 22652, comm: kcryptd Tainted: P        (2.6.24-1-686 #1)
EIP: 0060:[<f89ac8e9>] EFLAGS: 00000286 CPU: 0
EIP is at aes_enc_blk+0x8e9/0xb6c [aes_i586]
EAX: 1505dcbd EBX: a16c8192 ECX: a82d7918 EDX: 0000000c
ESI: f3a37640 EDI: c501a21d EBP: f518f030 ESP: f32bfdcc
 DS: 007b ES: 007b FS: 00d8 GS: 0000 SS: 0068
CR0: 8005003b CR2: 08441250 CR3: 333ed000 CR4: 000026d0
DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
DR6: ffff0ff0 DR7: 00000400
 [<f89ad702>] aes_encrypt+0x13/0x17 [aes_i586]
 [<f899238d>] crypto_cbc_encrypt+0xf3/0x146 [cbc]
 [<f899202f>] xor_128+0x0/0x17 [cbc]
 [<c01dd80a>] cfq_allow_merge+0x0/0x5a
 [<f89ad6ef>] aes_encrypt+0x0/0x17 [aes_i586]
 [<f88fe648>] crypt_convert_scatterlist+0x73/0xc3 [dm_crypt]
 [<f88fe7e0>] crypt_convert+0x148/0x185 [dm_crypt]
 [<f88fe9fe>] kcryptd_do_crypt+0x1e1/0x25e [dm_crypt]
 [<f88fe81d>] kcryptd_do_crypt+0x0/0x25e [dm_crypt]
 [<c0132225>] run_workqueue+0x7d/0x109
 [<c0132a9b>] worker_thread+0x0/0xc5
 [<c0132b55>] worker_thread+0xba/0xc5
 [<c0135441>] autoremove_wake_function+0x0/0x35
 [<c013537a>] kthread+0x38/0x5e
 [<c0135342>] kthread+0x0/0x5e
 [<c0104b0f>] kernel_thread_helper+0x7/0x10
 =======================
BUG: soft lockup - CPU#0 stuck for 11s! [kcryptd:22652]

Pid: 22652, comm: kcryptd Tainted: P        (2.6.24-1-686 #1)
EIP: 0060:[<f89ac950>] EFLAGS: 00000202 CPU: 0
EIP is at aes_enc_blk+0x950/0xb6c [aes_i586]
EAX: 2248b187 EBX: 6e6cb3db ECX: cc1ff777 EDX: 00000077
ESI: 5672a35f EDI: 7e5053b9 EBP: f518f030 ESP: f32bfdcc
 DS: 007b ES: 007b FS: 00d8 GS: 0000 SS: 0068
CR0: 8005003b CR2: 08499b40 CR3: 003b5000 CR4: 000026d0
DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
DR6: ffff0ff0 DR7: 00000400
 [<f89ad702>] aes_encrypt+0x13/0x17 [aes_i586]
 [<f899238d>] crypto_cbc_encrypt+0xf3/0x146 [cbc]
 [<f899202f>] xor_128+0x0/0x17 [cbc]
 [<c01dd80a>] cfq_allow_merge+0x0/0x5a
 [<f89ad6ef>] aes_encrypt+0x0/0x17 [aes_i586]
 [<f88fe648>] crypt_convert_scatterlist+0x73/0xc3 [dm_crypt]
 [<f88fe7e0>] crypt_convert+0x148/0x185 [dm_crypt]
 [<f88fe9fe>] kcryptd_do_crypt+0x1e1/0x25e [dm_crypt]
 [<f88fe81d>] kcryptd_do_crypt+0x0/0x25e [dm_crypt]
 [<c0132225>] run_workqueue+0x7d/0x109
 [<c0132a9b>] worker_thread+0x0/0xc5
 [<c0132b55>] worker_thread+0xba/0xc5
 [<c0135441>] autoremove_wake_function+0x0/0x35
 [<c013537a>] kthread+0x38/0x5e
 [<c0135342>] kthread+0x0/0x5e
 [<c0104b0f>] kernel_thread_helper+0x7/0x10
 =======================
BUG: soft lockup - CPU#0 stuck for 11s! [kcryptd:22652]

Pid: 22652, comm: kcryptd Tainted: P        (2.6.24-1-686 #1)
EIP: 0060:[<f89ac673>] EFLAGS: 00000202 CPU: 0
EIP is at aes_enc_blk+0x673/0xb6c [aes_i586]
EAX: 41890ece EBX: 86b32555 ECX: 000082f5 EDX: 000000da
ESI: 2da6097a EDI: c7b00061 EBP: f518f030 ESP: f32bfdcc
 DS: 007b ES: 007b FS: 00d8 GS: 0000 SS: 0068
CR0: 8005003b CR2: b7f0e000 CR3: 1ff70000 CR4: 000026d0
DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
DR6: ffff0ff0 DR7: 00000400
 [<f89ad702>] aes_encrypt+0x13/0x17 [aes_i586]
 [<f899238d>] crypto_cbc_encrypt+0xf3/0x146 [cbc]
 [<f899202f>] xor_128+0x0/0x17 [cbc]
 [<c01dd80a>] cfq_allow_merge+0x0/0x5a
 [<f89ad6ef>] aes_encrypt+0x0/0x17 [aes_i586]
 [<f88fe648>] crypt_convert_scatterlist+0x73/0xc3 [dm_crypt]
 [<f88fe7e0>] crypt_convert+0x148/0x185 [dm_crypt]
 [<f88fe9fe>] kcryptd_do_crypt+0x1e1/0x25e [dm_crypt]
 [<f88fe81d>] kcryptd_do_crypt+0x0/0x25e [dm_crypt]
 [<c0132225>] run_workqueue+0x7d/0x109
 [<c0135554>] prepare_to_wait+0x12/0x49
 [<c0132a9b>] worker_thread+0x0/0xc5
 [<c0132b55>] worker_thread+0xba/0xc5
 [<c0135441>] autoremove_wake_function+0x0/0x35
 [<c013537a>] kthread+0x38/0x5e
 [<c0135342>] kthread+0x0/0x5e
 [<c0104b0f>] kernel_thread_helper+0x7/0x10
 =======================
BUG: soft lockup - CPU#0 stuck for 11s! [kcryptd:22652]

Pid: 22652, comm: kcryptd Tainted: P        (2.6.24-1-686 #1)
EIP: 0060:[<f89923ac>] EFLAGS: 00000203 CPU: 0
EIP is at crypto_cbc_encrypt+0x112/0x146 [cbc]
EAX: 00000001 EBX: 00000010 ECX: fffffff0 EDX: 000000ab
ESI: f5e912d0 EDI: f32bfe90 EBP: c6ca72c0 ESP: f32bfdf8
 DS: 007b ES: 007b FS: 00d8 GS: 0000 SS: 0068
CR0: 8005003b CR2: 080f8e78 CR3: 309fc000 CR4: 000026d0
DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
DR6: ffff0ff0 DR7: 00000400
 [<f899202f>] xor_128+0x0/0x17 [cbc]
 [<f89ad6ef>] aes_encrypt+0x0/0x17 [aes_i586]
 [<f88fe648>] crypt_convert_scatterlist+0x73/0xc3 [dm_crypt]
 [<f88fe7e0>] crypt_convert+0x148/0x185 [dm_crypt]
 [<f88fe9fe>] kcryptd_do_crypt+0x1e1/0x25e [dm_crypt]
 [<f88fe81d>] kcryptd_do_crypt+0x0/0x25e [dm_crypt]
 [<c0132225>] run_workqueue+0x7d/0x109
 [<c0132a9b>] worker_thread+0x0/0xc5
 [<c0132b55>] worker_thread+0xba/0xc5
 [<c0135441>] autoremove_wake_function+0x0/0x35
 [<c013537a>] kthread+0x38/0x5e
 [<c0135342>] kthread+0x0/0x5e
 [<c0104b0f>] kernel_thread_helper+0x7/0x10
 =======================
BUG: soft lockup - CPU#0 stuck for 11s! [kcryptd:22652]

Pid: 22652, comm: kcryptd Tainted: P        (2.6.24-1-686 #1)
EIP: 0060:[<f89aca3e>] EFLAGS: 00000206 CPU: 0
EIP is at aes_enc_blk+0xa3e/0xb6c [aes_i586]
EAX: 00000082 EBX: a6054c84 ECX: 432211c3 EDX: 00000087
ESI: be022a17 EDI: 3fac9aaf EBP: f518f030 ESP: f32bfdcc
 DS: 007b ES: 007b FS: 00d8 GS: 0000 SS: 0068
CR0: 8005003b CR2: 080f8e78 CR3: 1ff70000 CR4: 000026d0
DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
DR6: ffff0ff0 DR7: 00000400
 [<f89ad702>] aes_encrypt+0x13/0x17 [aes_i586]
 [<f899238d>] crypto_cbc_encrypt+0xf3/0x146 [cbc]
 [<f899202f>] xor_128+0x0/0x17 [cbc]
 [<c01dd80a>] cfq_allow_merge+0x0/0x5a
 [<f89ad6ef>] aes_encrypt+0x0/0x17 [aes_i586]
 [<f88fe648>] crypt_convert_scatterlist+0x73/0xc3 [dm_crypt]
 [<f88fe7e0>] crypt_convert+0x148/0x185 [dm_crypt]
 [<f88fe9fe>] kcryptd_do_crypt+0x1e1/0x25e [dm_crypt]
 [<f88fe81d>] kcryptd_do_crypt+0x0/0x25e [dm_crypt]
 [<c0132225>] run_workqueue+0x7d/0x109
 [<c0135554>] prepare_to_wait+0x12/0x49
 [<c0132a9b>] worker_thread+0x0/0xc5
 [<c0132b55>] worker_thread+0xba/0xc5
 [<c0135441>] autoremove_wake_function+0x0/0x35
 [<c013537a>] kthread+0x38/0x5e
 [<c0135342>] kthread+0x0/0x5e
 [<c0104b0f>] kernel_thread_helper+0x7/0x10
 =======================

[-- Attachment #2: This is a digitally signed message part. --]
[-- Type: application/pgp-signature, Size: 189 bytes --]

Re: 2.6.24 Kernel Soft Lock Up with heavy I/O in dm-crypt

[Andrew Morton]

On Thu, 28 Feb 2008 19:24:03 +0530 Ritesh Raj Sarraf <rrs@researchut.com> wrote:

> Hi Christophe,

(cc's added)

> I noted kernel soft lockup messages on my laptop when doing a lot of I/O 
> (200GB) to a dm-crypt device. It was setup using LUKS.
> The I/O never got disrupted nor anything failed. Just the messages.
> 
> Kernel: 2.6.24
> Distribution: Debian Testing/Unstable
> Tainted: Yes (nvidia proprietary drivers)
> 
> I've not filed a bugzilla because my kernel is a tainted kernel because of 
> nvidia drivers.

That would be pretty dogmatic - if nuking the nvodia module prevents this
I'll eat several hats.

> I'm attaching the messages. Please let me know if it stands as a candidate for 
> a bug report.
> 

> a200 EDI: 0000000a EBP: 00000000 ESP: f32bfd7c
>  DS: 007b ES: 007b FS: 00d8 GS: 0000 SS: 0068
> CR0: 8005003b CR2: b3c3e000 CR3: 003b5000 CR4: 000026d0
> DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
> DR6: ffff0ff0 DR7: 00000400
>  [<c012902d>] do_softirq+0x45/0x53
>  [<c0129291>] irq_exit+0x38/0x6b
>  [<c01066f2>] do_IRQ+0x5a/0x70
>  [<c01048c3>] common_interrupt+0x23/0x28
>  [<f899202f>] xor_128+0x0/0x17 [cbc]
>  [<f899237e>] crypto_cbc_encrypt+0xe4/0x146 [cbc]
>  [<f899202f>] xor_128+0x0/0x17 [cbc]
>  [<c01dd80a>] cfq_allow_merge+0x0/0x5a
>  [<f89ad6ef>] aes_encrypt+0x0/0x17 [aes_i586]
>  [<f88fe648>] crypt_convert_scatterlist+0x73/0xc3 [dm_crypt]
>  [<f88fe7e0>] crypt_convert+0x148/0x185 [dm_crypt]
>  [<f88fe9fe>] kcryptd_do_crypt+0x1e1/0x25e [dm_crypt]
>  [<f88fe81d>] kcryptd_do_crypt+0x0/0x25e [dm_crypt]
>  [<c0132225>] run_workqueue+0x7d/0x109
>  [<c0135554>] prepare_to_wait+0x12/0x49
>  [<c0132a9b>] worker_thread+0x0/0xc5
>  [<c0132b55>] worker_thread+0xba/0xc5
>  [<c0135441>] autoremove_wake_function+0x0/0x35
>  [<c013537a>] kthread+0x38/0x5e
>  [<c0135342>] kthread+0x0/0x5e
>  [<c0104b0f>] kernel_thread_helper+0x7/0x10
>  =======================
> BUG: soft lockup - CPU#0 stuck for 11s! [kcryptd:22652]
> 
> Pid: 22652, comm: kcryptd Tainted: P        (2.6.24-1-686 #1)
> EIP: 0060:[<c0128f6c>] EFLAGS: 00000202 CPU: 0
> EIP is at __do_softirq+0x57/0xd3
> EAX: c03b4860 EBX: 00000020 ECX: 00000009 EDX: 01c5c000
> ESI: c036a200 EDI: 0000000a EBP: 00000000 ESP: f32bfd30
>  DS: 007b ES: 007b FS: 00d8 GS: 0000 SS: 0068
> CR0: 8005003b CR2: b3c3e000 CR3: 003b5000 CR4: 000026d0
> DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
> DR6: ffff0ff0 DR7: 00000400
>  [<c012902d>] do_softirq+0x45/0x53
>  [<c0129291>] irq_exit+0x38/0x6b
>  [<c01066f2>] do_IRQ+0x5a/0x70
>  [<c01048c3>] common_interrupt+0x23/0x28
>  [<c01100d8>] cyrix_get_arr+0xb4/0x126
>  [<c011ad36>] native_flush_tlb_single+0x3/0x4
>  [<c011d0e9>] kunmap_atomic+0x60/0x94
>  [<f89742d5>] blkcipher_walk_done+0x87/0x1fe [blkcipher]
>  [<f89923cc>] crypto_cbc_encrypt+0x132/0x146 [cbc]
>  [<f899202f>] xor_128+0x0/0x17 [cbc]
>  [<c01dd80a>] cfq_allow_merge+0x0/0x5a
>  [<f89ad6ef>] aes_encrypt+0x0/0x17 [aes_i586]
>  [<f88fe648>] crypt_convert_scatterlist+0x73/0xc3 [dm_crypt]
>  [<f88fe7e0>] crypt_convert+0x148/0x185 [dm_crypt]
>  [<f88fe9fe>] kcryptd_do_crypt+0x1e1/0x25e [dm_crypt]
>  [<f88fe81d>] kcryptd_do_crypt+0x0/0x25e [dm_crypt]
>  [<c0132225>] run_workqueue+0x7d/0x109
>  [<c0135554>] prepare_to_wait+0x12/0x49
>  [<c0132a9b>] worker_thread+0x0/0xc5
>  [<c0132b55>] worker_thread+0xba/0xc5
>  [<c0135441>] autoremove_wake_function+0x0/0x35
>  [<c013537a>] kthread+0x38/0x5e
>  [<c0135342>] kthread+0x0/0x5e
>  [<c0104b0f>] kernel_thread_helper+0x7/0x10
>  =======================
> BUG: soft lockup - CPU#0 stuck for 11s! [kcryptd:22652]
> 

Could be a dm-crypt problem, could be a crypto problem, could even be a
core block problems.

If nothing happens in the next few days, yes, please do raise a bugzilla
report.  That helps us to avoid forgetting about it, but it doesn't do much
to get things fixed, I'm afraid.

If you can provide us with a simple step-by-step recipe to reprodue this,
and if others can indeed reproduce it, the chances of getting it fixed will
increase.


Now, I'm assuming that it's just unreasonable for a machine to spend a full
11 seconds crunching away on crypto in that code path.  Maybe it _is_
reasonable, and all we need to do is to poke a cond_resched() in there
somewhere.  Herbert, any thoughts?  What's the speed of that code?

Thanks.

Re: 2.6.24 Kernel Soft Lock Up with heavy I/O in dm-crypt

[Herbert Xu]

On Thu, Feb 28, 2008 at 11:20:48PM -0800, Andrew Morton wrote:
>
> Now, I'm assuming that it's just unreasonable for a machine to spend a full
> 11 seconds crunching away on crypto in that code path.  Maybe it _is_
> reasonable, and all we need to do is to poke a cond_resched() in there
> somewhere.  Herbert, any thoughts?  What's the speed of that code?

It encryps 512 bytes each time so it should definitely be pretty
quick.  Perhaps the caller is disabling interrupts or something?

Cheers,
-- 
Visit Openswan at http://www.openswan.org/
Email: Herbert Xu ~{PmV>HI~} <herbert@gondor.apana.org.au>
Home Page: http://gondor.apana.org.au/~herbert/
PGP Key: http://gondor.apana.org.au/~herbert/pubkey.txt

Re: [dm-devel] Re: 2.6.24 Kernel Soft Lock Up with heavy I/O in dm-crypt

[Alasdair G Kergon]

On Thu, Feb 28, 2008 at 11:20:48PM -0800, Andrew Morton wrote:
> On Thu, 28 Feb 2008 19:24:03 +0530 Ritesh Raj Sarraf <rrs@researchut.com> wrote:
> > Kernel: 2.6.24
> > Distribution: Debian Testing/Unstable
> > Tainted: Yes (nvidia proprietary drivers)

Any chance you can try to reproduce it upstream e.g. in 2.6.25-rc3?

There have been significant changes in this area of the code.

Alasdair
-- 
agk@redhat.com

Re: [dm-devel] Re: 2.6.24 Kernel Soft Lock Up with heavy I/O in dm-crypt

[Ritesh Raj Sarraf]

[-- Attachment #1.1: Type: text/plain, Size: 1291 bytes --]

On Saturday 01 March 2008, Alasdair G Kergon wrote:
> On Thu, Feb 28, 2008 at 11:20:48PM -0800, Andrew Morton wrote:
> > On Thu, 28 Feb 2008 19:24:03 +0530 Ritesh Raj Sarraf <rrs@researchut.com> 
wrote:
> > > Kernel: 2.6.24
> > > Distribution: Debian Testing/Unstable
> > > Tainted: Yes (nvidia proprietary drivers)
>
> Any chance you can try to reproduce it upstream e.g. in 2.6.25-rc3?
>
I can do that but only by Monday Evening IST.

Meanwhile I was able to reproduce the bug again with the same configuration 
and the same scenario. So I believe that the bug can be reproduced 
consistently.

Here are the steps:

1) Initialize a device using dm-crypt and LUKS
2) Create a filesystem on top of it and mount it.
3) Write huge amount of data (as a normal user). Something like 150GB.

As the load goes hight (to something like 12-14), the kernel lock-up is logged 
into dmesg.
At that moment, the OS is barely responsive.

The I/O scheduler in use is:
rrs@learner:/sys/block/sdb/queue$ cat scheduler
noop anticipatory deadline [cfq]

The kernel logs are the same like the last time but I'm attaching it. There 
still is a delay of 11seconds.

Ritesh
-- 
Ritesh Raj Sarraf
RESEARCHUT - http://www.researchut.com
"Necessity is the mother of invention."

[-- Attachment #1.2: kernel.bug.new --]
[-- Type: text/plain, Size: 31058 bytes --]

dm-2 ino=3850241 scontext=system_u:system_r:rpcd_t tcontext=system_u:object_r:bin_t tclass=dir
audit(1204228759.615:24): avc:  denied  { execute } for  pid=3279 comm="rpc.statd" name="sm-notify" dev=dm-2 ino=3850484 scontext=system_u:system_r:rpcd_t tcontext=system_u:object_r:bin_t tclass=file
audit(1204228759.615:24): avc:  denied  { read } for  pid=3279 comm="rpc.statd" name="sm-notify" dev=dm-2 ino=3850484 scontext=system_u:system_r:rpcd_t tcontext=system_u:object_r:bin_t tclass=file
audit(1204228759.615:24): avc:  denied  { execute_no_trans } for  pid=3279 comm="rpc.statd" path="/sbin/sm-notify" dev=dm-2 ino=3850484 scontext=system_u:system_r:rpcd_t tcontext=system_u:object_r:bin_t tclass=file
audit(1204228759.615:24): arch=40000003 syscall=11 success=yes exit=0 a0=804f88a a1=bf9b2cb4 a2=bf9b2edc a3=1 items=0 ppid=3278 pid=3279 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) comm="sm-notify" exe="/sbin/sm-notify" subj=system_u:system_r:rpcd_t key=(null)
audit(1204228759.943:25): avc:  denied  { search } for  pid=3279 comm="sm-notify" scontext=system_u:system_r:rpcd_t tcontext=system_u:object_r:sysctl_fs_t tclass=dir
audit(1204228759.943:25): arch=40000003 syscall=5 success=no exit=-2 a0=804a67c a1=1 a2=4 a3=bf926528 items=0 ppid=3278 pid=3279 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) comm="sm-notify" exe="/sbin/sm-notify" subj=system_u:system_r:rpcd_t key=(null)
audit(1204228760.363:26): avc:  denied  { use } for  pid=3405 comm="loadkeys" path="/dev/console" dev=tmpfs ino=628 scontext=system_u:system_r:loadkeys_t tcontext=system_u:system_r:init_t tclass=fd
audit(1204228760.363:26): arch=40000003 syscall=11 success=yes exit=0 a0=8124ae8 a1=8124f88 a2=8104008 a3=8124ae8 items=0 ppid=3303 pid=3405 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=tty1 comm="loadkeys" exe="/bin/loadkeys" subj=system_u:system_r:loadkeys_t key=(null)
audit(1204228760.664:27): avc:  denied  { read write } for  pid=3444 comm="dmesg" name="tty1" dev=tmpfs ino=724 scontext=system_u:system_r:dmesg_t tcontext=system_u:object_r:tty_device_t tclass=chr_file
audit(1204228760.664:27): arch=40000003 syscall=11 success=yes exit=0 a0=8107788 a1=8107928 a2=8101408 a3=8107788 items=0 ppid=3417 pid=3444 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=tty1 comm="dmesg" exe="/bin/dmesg" subj=system_u:system_r:dmesg_t key=(null)
audit(1204228760.676:28): avc:  denied  { read } for  pid=3444 comm="dmesg" name="ld.so.cache" dev=dm-2 ino=2834454 scontext=system_u:system_r:dmesg_t tcontext=user_u:object_r:etc_t tclass=file
audit(1204228760.676:28): arch=40000003 syscall=5 success=yes exit=3 a0=b7f03b0f a1=0 a2=0 a3=ffffffff items=0 ppid=3417 pid=3444 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=tty1 comm="dmesg" exe="/bin/dmesg" subj=system_u:system_r:dmesg_t key=(null)
audit(1204228760.676:29): avc:  denied  { getattr } for  pid=3444 comm="dmesg" path="/etc/ld.so.cache" dev=dm-2 ino=2834454 scontext=system_u:system_r:dmesg_t tcontext=user_u:object_r:etc_t tclass=file
audit(1204228760.676:29): arch=40000003 syscall=197 success=yes exit=0 a0=3 a1=bff5fa80 a2=b7f05ff4 a3=ffffffff items=0 ppid=3417 pid=3444 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=tty1 comm="dmesg" exe="/bin/dmesg" subj=system_u:system_r:dmesg_t key=(null)
audit(1204228761.035:30): avc:  denied  { setsched } for  pid=3500 comm="modprobe" scontext=system_u:system_r:insmod_t tcontext=system_u:system_r:kernel_t tclass=process
audit(1204228761.035:30): arch=40000003 syscall=128 success=yes exit=0 a0=b7f92000 a1=183a a2=805d758 a3=805d758 items=0 ppid=3481 pid=3500 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) comm="modprobe" exe="/sbin/modprobe" subj=system_u:system_r:insmod_t key=(null)
audit(1204228761.459:31): avc:  denied  { use } for  pid=3575 comm="vbetool" path="/dev/console" dev=tmpfs ino=628 scontext=system_u:system_r:vbetool_t tcontext=system_u:system_r:init_t tclass=fd
audit(1204228761.459:31): avc:  denied  { read write } for  pid=3575 comm="vbetool" path="/dev/console" dev=tmpfs ino=628 scontext=system_u:system_r:vbetool_t tcontext=system_u:object_r:console_device_t tclass=chr_file
audit(1204228761.459:31): avc:  denied  { write } for  pid=3575 comm="vbetool" path="/var/lib/acpi-support/vbestate" dev=dm-2 ino=4063580 scontext=system_u:system_r:vbetool_t tcontext=system_u:object_r:var_lib_t tclass=file
audit(1204228761.459:31): arch=40000003 syscall=11 success=yes exit=0 a0=8103708 a1=8113b48 a2=8103e08 a3=8103708 items=0 ppid=3563 pid=3575 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) comm="vbetool" exe="/usr/sbin/vbetool" subj=system_u:system_r:vbetool_t key=(null)
audit(1204228761.487:32): avc:  denied  { read } for  pid=3575 comm="vbetool" name="ld.so.cache" dev=dm-2 ino=2834454 scontext=system_u:system_r:vbetool_t tcontext=user_u:object_r:etc_t tclass=file
audit(1204228761.487:32): arch=40000003 syscall=5 success=yes exit=3 a0=b7f01b0f a1=0 a2=0 a3=ffffffff items=0 ppid=3563 pid=3575 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) comm="vbetool" exe="/usr/sbin/vbetool" subj=system_u:system_r:vbetool_t key=(null)
audit(1204228761.487:33): avc:  denied  { getattr } for  pid=3575 comm="vbetool" path="/etc/ld.so.cache" dev=dm-2 ino=2834454 scontext=system_u:system_r:vbetool_t tcontext=user_u:object_r:etc_t tclass=file
audit(1204228761.487:33): arch=40000003 syscall=197 success=yes exit=0 a0=3 a1=bfeda470 a2=b7f03ff4 a3=ffffffff items=0 ppid=3563 pid=3575 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) comm="vbetool" exe="/usr/sbin/vbetool" subj=system_u:system_r:vbetool_t key=(null)
audit(1204228762.095:34): avc:  denied  { write } for  pid=3601 comm="auditd" name="log" dev=tmpfs ino=9797 scontext=system_u:system_r:auditd_t tcontext=system_u:object_r:device_t tclass=sock_file
audit(1204228762.095:34): avc:  denied  { sendto } for  pid=3601 comm="auditd" path="/dev/log" scontext=system_u:system_r:auditd_t tcontext=system_u:system_r:initrc_t tclass=unix_dgram_socket
audit(1204228762.095:34): arch=40000003 syscall=102 success=yes exit=0 a0=3 a1=bf9e0980 a2=b7f42ff4 a3=0 items=0 ppid=3600 pid=3601 auid=4294967295 uid=0 gid=0 euid=0 suid=0 fsuid=0 egid=0 sgid=0 fsgid=0 tty=(none) comm="auditd" exe="/sbin/auditd" subj=system_u:system_r:auditd_t key=(null)
audit(1204228762.095:35): audit_pid=3601 old=0 by auid=4294967295 subj=system_u:system_r:auditd_t
NET: Registered protocol family 10
lo: Disabled Privacy Extensions
ADDRCONF(NETDEV_UP): eth0: link is not ready
lp: driver loaded but no devices found
ppdev: user-space parallel port driver
tun: Universal TUN/TAP device driver, 1.6
tun: (C) 1999-2004 Max Krasnyansky <maxk@qualcomm.com>
Bluetooth: Core ver 2.11
NET: Registered protocol family 31
Bluetooth: HCI device and connection manager initialized
Bluetooth: HCI socket layer initialized
Bluetooth: L2CAP ver 2.9
Bluetooth: L2CAP socket layer initialized
Bluetooth: RFCOMM socket layer initialized
Bluetooth: RFCOMM TTY layer initialized
Bluetooth: RFCOMM ver 1.8
ADDRCONF(NETDEV_UP): wlan0_rename: link is not ready
SELinux: initialized (dev binfmt_misc, type binfmt_misc), uses genfs_contexts
nvidia: module license 'NVIDIA' taints kernel.
ACPI: PCI Interrupt 0000:01:00.0[A] -> GSI 16 (level, low) -> IRQ 16
PCI: Setting latency timer of device 0000:01:00.0 to 64
NVRM: loading NVIDIA UNIX x86 Kernel Module  169.09  Fri Jan 11 14:38:28 PST 2008
NET: Registered protocol family 4
NET: Registered protocol family 3
NET: Registered protocol family 5
ip_tables: (C) 2000-2006 Netfilter Core Team
nf_conntrack version 0.5.0 (16384 buckets, 65536 max)
wlan0_rename: Initial auth_alg=0
wlan0_rename: authenticate with AP 00:16:b6:a5:e7:1c
wlan0_rename: RX authentication from 00:16:b6:a5:e7:1c (alg=0 transaction=2 status=0)
wlan0_rename: authenticated
wlan0_rename: associate with AP 00:16:b6:a5:e7:1c
wlan0_rename: RX AssocResp from 00:16:b6:a5:e7:1c (capab=0x411 status=0 aid=2)
wlan0_rename: associated
wlan0_rename: WMM queue=2 aci=0 acm=0 aifs=3 cWmin=15 cWmax=1023 burst=0
wlan0_rename: WMM queue=3 aci=1 acm=0 aifs=7 cWmin=15 cWmax=1023 burst=0
wlan0_rename: WMM queue=1 aci=2 acm=0 aifs=2 cWmin=7 cWmax=15 burst=30
wlan0_rename: WMM queue=0 aci=3 acm=0 aifs=2 cWmin=3 cWmax=7 burst=15
ADDRCONF(NETDEV_CHANGE): wlan0_rename: link becomes ready
SELinux: initialized (dev fuse, type fuse), uses genfs_contexts
wlan0_rename: no IPv6 routers present
tun0: Disabled Privacy Extensions
usb 5-1: new high speed USB device using ehci_hcd and address 7
usb 5-1: configuration #1 chosen from 1 choice
scsi3 : SCSI emulation for USB Mass Storage devices
usb-storage: device found at 7
usb-storage: waiting for device to settle before scanning
usb-storage: device scan complete
scsi 3:0:0:0: Direct-Access     WD       1600BEV External 1.04 PQ: 0 ANSI: 4
sd 3:0:0:0: [sdc] 312581808 512-byte hardware sectors (160042 MB)
sd 3:0:0:0: [sdc] Write Protect is off
sd 3:0:0:0: [sdc] Mode Sense: 21 00 00 00
sd 3:0:0:0: [sdc] Assuming drive cache: write through
sd 3:0:0:0: [sdc] 312581808 512-byte hardware sectors (160042 MB)
sd 3:0:0:0: [sdc] Write Protect is off
sd 3:0:0:0: [sdc] Mode Sense: 21 00 00 00
sd 3:0:0:0: [sdc] Assuming drive cache: write through
 sdc: sdc1
sd 3:0:0:0: [sdc] Attached SCSI disk
sd 3:0:0:0: Attached scsi generic sg3 type 0
SELinux: initialized (dev sdc1, type vfat), uses genfs_contexts
kjournald starting.  Commit interval 5 seconds
EXT3 FS on dm-3, internal journal
EXT3-fs: mounted filesystem with ordered data mode.
SELinux: initialized (dev dm-3, type ext3), uses xattr
kjournald starting.  Commit interval 5 seconds
EXT3 FS on dm-3, internal journal
EXT3-fs: mounted filesystem with ordered data mode.
SELinux: initialized (dev dm-3, type ext3), uses xattr
BUG: soft lockup - CPU#1 stuck for 11s! [kcryptd:10051]

Pid: 10051, comm: kcryptd Tainted: P        (2.6.24-1-686 #1)
EIP: 0060:[<f89b492c>] EFLAGS: 00000206 CPU: 1
EIP is at aes_enc_blk+0x92c/0xb6c [aes_i586]
EAX: 672bf2e1 EBX: 0c20e1b7 ECX: a5e532cb EDX: 00000032
ESI: 07f20dd2 EDI: 4157f550 EBP: f0534030 ESP: f07fbdcc
 DS: 007b ES: 007b FS: 00d8 GS: 0000 SS: 0068
CR0: 8005003b CR2: bfbe00f4 CR3: 2fc7c000 CR4: 000026d0
DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
DR6: ffff0ff0 DR7: 00000400
 [<f89b5702>] aes_encrypt+0x13/0x17 [aes_i586]
 [<f891838d>] crypto_cbc_encrypt+0xf3/0x146 [cbc]
 [<f891802f>] xor_128+0x0/0x17 [cbc]
 [<c01dd80a>] cfq_allow_merge+0x0/0x5a
 [<f89b56ef>] aes_encrypt+0x0/0x17 [aes_i586]
 [<f889f648>] crypt_convert_scatterlist+0x73/0xc3 [dm_crypt]
 [<f889f7e0>] crypt_convert+0x148/0x185 [dm_crypt]
 [<f889f9fe>] kcryptd_do_crypt+0x1e1/0x25e [dm_crypt]
 [<f889f81d>] kcryptd_do_crypt+0x0/0x25e [dm_crypt]
 [<c0132225>] run_workqueue+0x7d/0x109
 [<c0135554>] prepare_to_wait+0x12/0x49
 [<c0132a9b>] worker_thread+0x0/0xc5
 [<c0132b55>] worker_thread+0xba/0xc5
 [<c0135441>] autoremove_wake_function+0x0/0x35
 [<c013537a>] kthread+0x38/0x5e
 [<c0135342>] kthread+0x0/0x5e
 [<c0104b0f>] kernel_thread_helper+0x7/0x10
 =======================
BUG: soft lockup - CPU#0 stuck for 11s! [kcryptd:10051]

Pid: 10051, comm: kcryptd Tainted: P        (2.6.24-1-686 #1)
EIP: 0060:[<f89b4766>] EFLAGS: 00000202 CPU: 0
EIP is at aes_enc_blk+0x766/0xb6c [aes_i586]
EAX: 70d3e825 EBX: d2c6b2e3 ECX: 25678de9 EDX: 000000e9
ESI: 985c2cf3 EDI: a23bc889 EBP: f0534030 ESP: f07fbdcc
 DS: 007b ES: 007b FS: 00d8 GS: 0000 SS: 0068
CR0: 8005003b CR2: 0807d9e0 CR3: 2fc7c000 CR4: 000026d0
DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
DR6: ffff0ff0 DR7: 00000400
 [<f89b5702>] aes_encrypt+0x13/0x17 [aes_i586]
 [<f891838d>] crypto_cbc_encrypt+0xf3/0x146 [cbc]
 [<f891802f>] xor_128+0x0/0x17 [cbc]
 [<f89b56ef>] aes_encrypt+0x0/0x17 [aes_i586]
 [<f889f648>] crypt_convert_scatterlist+0x73/0xc3 [dm_crypt]
 [<f889f7e0>] crypt_convert+0x148/0x185 [dm_crypt]
 [<f889f9fe>] kcryptd_do_crypt+0x1e1/0x25e [dm_crypt]
 [<f889f81d>] kcryptd_do_crypt+0x0/0x25e [dm_crypt]
 [<c0132225>] run_workqueue+0x7d/0x109
 [<c0135554>] prepare_to_wait+0x12/0x49
 [<c0132a9b>] worker_thread+0x0/0xc5
 [<c0132b55>] worker_thread+0xba/0xc5
 [<c0135441>] autoremove_wake_function+0x0/0x35
 [<c013537a>] kthread+0x38/0x5e
 [<c0135342>] kthread+0x0/0x5e
 [<c0104b0f>] kernel_thread_helper+0x7/0x10
 =======================
BUG: soft lockup - CPU#0 stuck for 11s! [kcryptd:10051]

Pid: 10051, comm: kcryptd Tainted: P        (2.6.24-1-686 #1)
EIP: 0060:[<f89b451e>] EFLAGS: 00000282 CPU: 0
EIP is at aes_enc_blk+0x51e/0xb6c [aes_i586]
EAX: 00004d54 EBX: 629c8c3d ECX: 9769e3f4 EDX: 00000005
ESI: f0d1e8b0 EDI: c8e0c4b5 EBP: f0534030 ESP: f07fbdcc
 DS: 007b ES: 007b FS: 00d8 GS: 0000 SS: 0068
CR0: 8005003b CR2: 080f773c CR3: 2fc7c000 CR4: 000026d0
DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
DR6: ffff0ff0 DR7: 00000400
 [<f89b5702>] aes_encrypt+0x13/0x17 [aes_i586]
 [<f891838d>] crypto_cbc_encrypt+0xf3/0x146 [cbc]
 [<f891802f>] xor_128+0x0/0x17 [cbc]
 [<f89b56ef>] aes_encrypt+0x0/0x17 [aes_i586]
 [<f889f648>] crypt_convert_scatterlist+0x73/0xc3 [dm_crypt]
 [<f889f7e0>] crypt_convert+0x148/0x185 [dm_crypt]
 [<f889f9fe>] kcryptd_do_crypt+0x1e1/0x25e [dm_crypt]
 [<f889f81d>] kcryptd_do_crypt+0x0/0x25e [dm_crypt]
 [<c0132225>] run_workqueue+0x7d/0x109
 [<c0135554>] prepare_to_wait+0x12/0x49
 [<c0132a9b>] worker_thread+0x0/0xc5
 [<c0132b55>] worker_thread+0xba/0xc5
 [<c0135441>] autoremove_wake_function+0x0/0x35
 [<c013537a>] kthread+0x38/0x5e
 [<c0135342>] kthread+0x0/0x5e
 [<c0104b0f>] kernel_thread_helper+0x7/0x10
 =======================
iwl3945: Microcode SW error detected.  Restarting 0x82000008.
iwl3945: Can't stop Rx DMA.
BUG: soft lockup - CPU#1 stuck for 11s! [kcryptd:10051]

Pid: 10051, comm: kcryptd Tainted: P        (2.6.24-1-686 #1)
EIP: 0060:[<c01d1c59>] EFLAGS: 00000206 CPU: 1
EIP is at scatterwalk_done+0x6/0xf
EAX: f07fbe30 EBX: 00000000 ECX: 00000000 EDX: 00000000
ESI: fffa9600 EDI: f07fbe90 EBP: f07fbe20 ESP: f07fbdc0
 DS: 007b ES: 007b FS: 00d8 GS: 0000 SS: 0068
CR0: 8005003b CR2: 080f773c CR3: 003b5000 CR4: 000026d0
DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
DR6: ffff0ff0 DR7: 00000400
 [<f891538e>] blkcipher_walk_done+0x140/0x1fe [blkcipher]
 [<f89183cc>] crypto_cbc_encrypt+0x132/0x146 [cbc]
 [<f891802f>] xor_128+0x0/0x17 [cbc]
 [<f89b56ef>] aes_encrypt+0x0/0x17 [aes_i586]
 [<f889f648>] crypt_convert_scatterlist+0x73/0xc3 [dm_crypt]
 [<f889f7e0>] crypt_convert+0x148/0x185 [dm_crypt]
 [<f889f9fe>] kcryptd_do_crypt+0x1e1/0x25e [dm_crypt]
 [<f889f81d>] kcryptd_do_crypt+0x0/0x25e [dm_crypt]
 [<c0132225>] run_workqueue+0x7d/0x109
 [<c0135554>] prepare_to_wait+0x12/0x49
 [<c0132a9b>] worker_thread+0x0/0xc5
 [<c0132b55>] worker_thread+0xba/0xc5
 [<c0135441>] autoremove_wake_function+0x0/0x35
 [<c013537a>] kthread+0x38/0x5e
 [<c0135342>] kthread+0x0/0x5e
 [<c0104b0f>] kernel_thread_helper+0x7/0x10
 =======================
BUG: soft lockup - CPU#1 stuck for 11s! [kcryptd:10051]

Pid: 10051, comm: kcryptd Tainted: P        (2.6.24-1-686 #1)
EIP: 0060:[<f89b4929>] EFLAGS: 00000286 CPU: 1
EIP is at aes_enc_blk+0x929/0xb6c [aes_i586]
EAX: f85e870b EBX: 5454cd9b ECX: b3b420c2 EDX: 000000c2
ESI: ae1d0541 EDI: 1c0a4fb7 EBP: f0534030 ESP: f07fbdcc
 DS: 007b ES: 007b FS: 00d8 GS: 0000 SS: 0068
CR0: 8005003b CR2: 080f773c CR3: 2fc7c000 CR4: 000026d0
DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
DR6: ffff0ff0 DR7: 00000400
 [<f89b5702>] aes_encrypt+0x13/0x17 [aes_i586]
 [<f891838d>] crypto_cbc_encrypt+0xf3/0x146 [cbc]
 [<f891802f>] xor_128+0x0/0x17 [cbc]
 [<f89b56ef>] aes_encrypt+0x0/0x17 [aes_i586]
 [<f889f648>] crypt_convert_scatterlist+0x73/0xc3 [dm_crypt]
 [<f889f7e0>] crypt_convert+0x148/0x185 [dm_crypt]
 [<f889f9fe>] kcryptd_do_crypt+0x1e1/0x25e [dm_crypt]
 [<f889f81d>] kcryptd_do_crypt+0x0/0x25e [dm_crypt]
 [<c0132225>] run_workqueue+0x7d/0x109
 [<c0135554>] prepare_to_wait+0x12/0x49
 [<c0132a9b>] worker_thread+0x0/0xc5
 [<c0132b55>] worker_thread+0xba/0xc5
 [<c0135441>] autoremove_wake_function+0x0/0x35
 [<c013537a>] kthread+0x38/0x5e
 [<c0135342>] kthread+0x0/0x5e
 [<c0104b0f>] kernel_thread_helper+0x7/0x10
 =======================
BUG: soft lockup - CPU#0 stuck for 11s! [kcryptd:10051]

Pid: 10051, comm: kcryptd Tainted: P        (2.6.24-1-686 #1)
EIP: 0060:[<c0128f6c>] EFLAGS: 00000202 CPU: 0
EIP is at __do_softirq+0x57/0xd3
EAX: c03b4860 EBX: 00000020 ECX: 00000009 EDX: 01c5c000
ESI: c036a200 EDI: 0000000a EBP: 00000000 ESP: f07fbd54
 DS: 007b ES: 007b FS: 00d8 GS: 0000 SS: 0068
CR0: 8005003b CR2: 080f773c CR3: 1f8cb000 CR4: 000026d0
DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
DR6: ffff0ff0 DR7: 00000400
 [<c012902d>] do_softirq+0x45/0x53
 [<c0129291>] irq_exit+0x38/0x6b
 [<c01066f2>] do_IRQ+0x5a/0x70
 [<f8852a06>] ehci_irq+0x13e/0x161 [ehci_hcd]
 [<c01048c3>] common_interrupt+0x23/0x28
 [<c01d007b>] cap_syslog+0x1d/0x20
 [<f89b4517>] aes_enc_blk+0x517/0xb6c [aes_i586]
 [<f89b5702>] aes_encrypt+0x13/0x17 [aes_i586]
 [<f891838d>] crypto_cbc_encrypt+0xf3/0x146 [cbc]
 [<f891802f>] xor_128+0x0/0x17 [cbc]
 [<c01dd80a>] cfq_allow_merge+0x0/0x5a
 [<f89b56ef>] aes_encrypt+0x0/0x17 [aes_i586]
 [<f889f648>] crypt_convert_scatterlist+0x73/0xc3 [dm_crypt]
 [<f889f7e0>] crypt_convert+0x148/0x185 [dm_crypt]
 [<f889f9fe>] kcryptd_do_crypt+0x1e1/0x25e [dm_crypt]
 [<f889f81d>] kcryptd_do_crypt+0x0/0x25e [dm_crypt]
 [<c0132225>] run_workqueue+0x7d/0x109
 [<c0135554>] prepare_to_wait+0x12/0x49
 [<c0132a9b>] worker_thread+0x0/0xc5
 [<c0132b55>] worker_thread+0xba/0xc5
 [<c0135441>] autoremove_wake_function+0x0/0x35
 [<c013537a>] kthread+0x38/0x5e
 [<c0135342>] kthread+0x0/0x5e
 [<c0104b0f>] kernel_thread_helper+0x7/0x10
 =======================
BUG: soft lockup - CPU#0 stuck for 11s! [kcryptd:10051]

Pid: 10051, comm: kcryptd Tainted: P        (2.6.24-1-686 #1)
EIP: 0060:[<f89b4035>] EFLAGS: 00000293 CPU: 0
EIP is at aes_enc_blk+0x35/0xb6c [aes_i586]
EAX: 4458f5df EBX: 83636dd3 ECX: f07fbe80 EDX: 0000000a
ESI: a9e624c0 EDI: 9114fb98 EBP: f0534030 ESP: f07fbdcc
 DS: 007b ES: 007b FS: 00d8 GS: 0000 SS: 0068
CR0: 8005003b CR2: b7f6a000 CR3: 2fc7c000 CR4: 000026d0
DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
DR6: ffff0ff0 DR7: 00000400
 [<f89b5702>] aes_encrypt+0x13/0x17 [aes_i586]
 [<f891838d>] crypto_cbc_encrypt+0xf3/0x146 [cbc]
 [<f891802f>] xor_128+0x0/0x17 [cbc]
 [<f89b56ef>] aes_encrypt+0x0/0x17 [aes_i586]
 [<f889f648>] crypt_convert_scatterlist+0x73/0xc3 [dm_crypt]
 [<f889f7e0>] crypt_convert+0x148/0x185 [dm_crypt]
 [<f889f9fe>] kcryptd_do_crypt+0x1e1/0x25e [dm_crypt]
 [<f889f81d>] kcryptd_do_crypt+0x0/0x25e [dm_crypt]
 [<c0132225>] run_workqueue+0x7d/0x109
 [<c0132a9b>] worker_thread+0x0/0xc5
 [<c0132b55>] worker_thread+0xba/0xc5
 [<c0135441>] autoremove_wake_function+0x0/0x35
 [<c013537a>] kthread+0x38/0x5e
 [<c0135342>] kthread+0x0/0x5e
 [<c0104b0f>] kernel_thread_helper+0x7/0x10
 =======================
BUG: soft lockup - CPU#0 stuck for 11s! [kcryptd:10051]

Pid: 10051, comm: kcryptd Tainted: P        (2.6.24-1-686 #1)
EIP: 0060:[<f89b47ec>] EFLAGS: 00000282 CPU: 0
EIP is at aes_enc_blk+0x7ec/0xb6c [aes_i586]
EAX: a99a76bf EBX: 3560b875 ECX: 295127af EDX: 0000001a
ESI: c842b8d6 EDI: 3235a54f EBP: f0534030 ESP: f07fbdcc
 DS: 007b ES: 007b FS: 00d8 GS: 0000 SS: 0068
CR0: 8005003b CR2: 0830fbdc CR3: 37fde000 CR4: 000026d0
DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
DR6: ffff0ff0 DR7: 00000400
 [<f89b5702>] aes_encrypt+0x13/0x17 [aes_i586]
 [<f891838d>] crypto_cbc_encrypt+0xf3/0x146 [cbc]
 [<f891802f>] xor_128+0x0/0x17 [cbc]
 [<f89b56ef>] aes_encrypt+0x0/0x17 [aes_i586]
 [<f889f648>] crypt_convert_scatterlist+0x73/0xc3 [dm_crypt]
 [<f889f7e0>] crypt_convert+0x148/0x185 [dm_crypt]
 [<f889f9fe>] kcryptd_do_crypt+0x1e1/0x25e [dm_crypt]
 [<f889f81d>] kcryptd_do_crypt+0x0/0x25e [dm_crypt]
 [<c0132225>] run_workqueue+0x7d/0x109
 [<c0135554>] prepare_to_wait+0x12/0x49
 [<c0132a9b>] worker_thread+0x0/0xc5
 [<c0132b55>] worker_thread+0xba/0xc5
 [<c0135441>] autoremove_wake_function+0x0/0x35
 [<c013537a>] kthread+0x38/0x5e
 [<c0135342>] kthread+0x0/0x5e
 [<c0104b0f>] kernel_thread_helper+0x7/0x10
 =======================
BUG: soft lockup - CPU#0 stuck for 11s! [kcryptd:10051]

Pid: 10051, comm: kcryptd Tainted: P        (2.6.24-1-686 #1)
EIP: 0060:[<f89b402f>] EFLAGS: 00000296 CPU: 0
EIP is at aes_enc_blk+0x2f/0xb6c [aes_i586]
EAX: 22254b51 EBX: ac4d2980 ECX: f07fbe80 EDX: 0000000a
ESI: 8e10c34b EDI: 1b82caec EBP: f0534020 ESP: f07fbdcc
 DS: 007b ES: 007b FS: 00d8 GS: 0000 SS: 0068
CR0: 8005003b CR2: 0838c178 CR3: 003b5000 CR4: 000026d0
DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
DR6: ffff0ff0 DR7: 00000400
 [<f89b5702>] aes_encrypt+0x13/0x17 [aes_i586]
 [<f891838d>] crypto_cbc_encrypt+0xf3/0x146 [cbc]
 [<f891802f>] xor_128+0x0/0x17 [cbc]
 [<f89b56ef>] aes_encrypt+0x0/0x17 [aes_i586]
 [<f889f648>] crypt_convert_scatterlist+0x73/0xc3 [dm_crypt]
 [<f889f7e0>] crypt_convert+0x148/0x185 [dm_crypt]
 [<f889f9fe>] kcryptd_do_crypt+0x1e1/0x25e [dm_crypt]
 [<f889f81d>] kcryptd_do_crypt+0x0/0x25e [dm_crypt]
 [<c0132225>] run_workqueue+0x7d/0x109
 [<c0135554>] prepare_to_wait+0x12/0x49
 [<c0132a9b>] worker_thread+0x0/0xc5
 [<c0132b55>] worker_thread+0xba/0xc5
 [<c0135441>] autoremove_wake_function+0x0/0x35
 [<c013537a>] kthread+0x38/0x5e
 [<c0135342>] kthread+0x0/0x5e
 [<c0104b0f>] kernel_thread_helper+0x7/0x10
 =======================
BUG: soft lockup - CPU#0 stuck for 11s! [kcryptd:10051]

Pid: 10051, comm: kcryptd Tainted: P        (2.6.24-1-686 #1)
EIP: 0060:[<f89b4609>] EFLAGS: 00000286 CPU: 0
EIP is at aes_enc_blk+0x609/0xb6c [aes_i586]
EAX: d64cf16b EBX: c668b39c ECX: a70e014d EDX: 0000004d
ESI: f9912a33 EDI: 71758637 EBP: f0534030 ESP: f07fbdcc
 DS: 007b ES: 007b FS: 00d8 GS: 0000 SS: 0068
CR0: 8005003b CR2: 0807d9e0 CR3: 003b5000 CR4: 000026d0
DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
DR6: ffff0ff0 DR7: 00000400
 [<f89b5702>] aes_encrypt+0x13/0x17 [aes_i586]
 [<f891838d>] crypto_cbc_encrypt+0xf3/0x146 [cbc]
 [<f891802f>] xor_128+0x0/0x17 [cbc]
 [<c01dd80a>] cfq_allow_merge+0x0/0x5a
 [<f89b56ef>] aes_encrypt+0x0/0x17 [aes_i586]
 [<f889f648>] crypt_convert_scatterlist+0x73/0xc3 [dm_crypt]
 [<f889f7e0>] crypt_convert+0x148/0x185 [dm_crypt]
 [<f889f9fe>] kcryptd_do_crypt+0x1e1/0x25e [dm_crypt]
 [<f889f81d>] kcryptd_do_crypt+0x0/0x25e [dm_crypt]
 [<c0132225>] run_workqueue+0x7d/0x109
 [<c0132a9b>] worker_thread+0x0/0xc5
 [<c0132b55>] worker_thread+0xba/0xc5
 [<c0135441>] autoremove_wake_function+0x0/0x35
 [<c013537a>] kthread+0x38/0x5e
 [<c0135342>] kthread+0x0/0x5e
 [<c0104b0f>] kernel_thread_helper+0x7/0x10
 =======================
BUG: soft lockup - CPU#0 stuck for 11s! [kcryptd:10051]

Pid: 10051, comm: kcryptd Tainted: P        (2.6.24-1-686 #1)
EIP: 0060:[<f89b4001>] EFLAGS: 00000292 CPU: 0
EIP is at aes_enc_blk+0x1/0xb6c [aes_i586]
EAX: f0534400 EBX: f0534400 ECX: f07fbe80 EDX: f07fbe80
ESI: f120dac0 EDI: f07fbe90 EBP: f07fbebc ESP: f07fbe44
 DS: 007b ES: 007b FS: 00d8 GS: 0000 SS: 0068
CR0: 8005003b CR2: 084b0fb0 CR3: 1f8cb000 CR4: 000026d0
DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
DR6: ffff0ff0 DR7: 00000400
 [<f89b5702>] aes_encrypt+0x13/0x17 [aes_i586]
 [<f889fc08>] crypt_iv_essiv_gen+0x45/0x4c [dm_crypt]
 [<f889f629>] crypt_convert_scatterlist+0x54/0xc3 [dm_crypt]
 [<f889f7e0>] crypt_convert+0x148/0x185 [dm_crypt]
 [<f889f9fe>] kcryptd_do_crypt+0x1e1/0x25e [dm_crypt]
 [<f889f81d>] kcryptd_do_crypt+0x0/0x25e [dm_crypt]
 [<c0132225>] run_workqueue+0x7d/0x109
 [<c0132a9b>] worker_thread+0x0/0xc5
 [<c0132b55>] worker_thread+0xba/0xc5
 [<c0135441>] autoremove_wake_function+0x0/0x35
 [<c013537a>] kthread+0x38/0x5e
 [<c0135342>] kthread+0x0/0x5e
 [<c0104b0f>] kernel_thread_helper+0x7/0x10
 =======================
BUG: soft lockup - CPU#0 stuck for 11s! [kcryptd:10051]

Pid: 10051, comm: kcryptd Tainted: P        (2.6.24-1-686 #1)
EIP: 0060:[<f89b4446>] EFLAGS: 00000286 CPU: 0
EIP is at aes_enc_blk+0x446/0xb6c [aes_i586]
EAX: 8b9d3e63 EBX: a71d3357 ECX: 175afea6 EDX: 000000a6
ESI: 65c1c3a1 EDI: a332ca36 EBP: f0534030 ESP: f07fbdcc
 DS: 007b ES: 007b FS: 00d8 GS: 0000 SS: 0068
CR0: 8005003b CR2: 080f773c CR3: 31216000 CR4: 000026d0
DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
DR6: ffff0ff0 DR7: 00000400
 [<f89b5702>] aes_encrypt+0x13/0x17 [aes_i586]
 [<f891838d>] crypto_cbc_encrypt+0xf3/0x146 [cbc]
 [<f891802f>] xor_128+0x0/0x17 [cbc]
 [<c01dd80a>] cfq_allow_merge+0x0/0x5a
 [<f89b56ef>] aes_encrypt+0x0/0x17 [aes_i586]
 [<f889f648>] crypt_convert_scatterlist+0x73/0xc3 [dm_crypt]
 [<f889f7e0>] crypt_convert+0x148/0x185 [dm_crypt]
 [<f889f9fe>] kcryptd_do_crypt+0x1e1/0x25e [dm_crypt]
 [<f889f81d>] kcryptd_do_crypt+0x0/0x25e [dm_crypt]
 [<c0132225>] run_workqueue+0x7d/0x109
 [<c0132a9b>] worker_thread+0x0/0xc5
 [<c0132b55>] worker_thread+0xba/0xc5
 [<c0135441>] autoremove_wake_function+0x0/0x35
 [<c013537a>] kthread+0x38/0x5e
 [<c0135342>] kthread+0x0/0x5e
 [<c0104b0f>] kernel_thread_helper+0x7/0x10
 =======================
BUG: soft lockup - CPU#0 stuck for 11s! [kcryptd:10051]

Pid: 10051, comm: kcryptd Tainted: P        (2.6.24-1-686 #1)
EIP: 0060:[<f89b49f3>] EFLAGS: 00000202 CPU: 0
EIP is at aes_enc_blk+0x9f3/0xb6c [aes_i586]
EAX: f9681c08 EBX: 4728e46f ECX: 85bbb6a5 EDX: 00000099
ESI: 0345141f EDI: 453c0181 EBP: f0534030 ESP: f07fbdcc
 DS: 007b ES: 007b FS: 00d8 GS: 0000 SS: 0068
CR0: 8005003b CR2: 080f773c CR3: 003b5000 CR4: 000026d0
DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
DR6: ffff0ff0 DR7: 00000400
 [<f89b5702>] aes_encrypt+0x13/0x17 [aes_i586]
 [<f891838d>] crypto_cbc_encrypt+0xf3/0x146 [cbc]
 [<f891802f>] xor_128+0x0/0x17 [cbc]
 [<c01dd80a>] cfq_allow_merge+0x0/0x5a
 [<f89b56ef>] aes_encrypt+0x0/0x17 [aes_i586]
 [<f889f648>] crypt_convert_scatterlist+0x73/0xc3 [dm_crypt]
 [<f889f7e0>] crypt_convert+0x148/0x185 [dm_crypt]
 [<f889f9fe>] kcryptd_do_crypt+0x1e1/0x25e [dm_crypt]
 [<f889f81d>] kcryptd_do_crypt+0x0/0x25e [dm_crypt]
 [<c0132225>] run_workqueue+0x7d/0x109
 [<c0132a9b>] worker_thread+0x0/0xc5
 [<c0132b55>] worker_thread+0xba/0xc5
 [<c0135441>] autoremove_wake_function+0x0/0x35
 [<c013537a>] kthread+0x38/0x5e
 [<c0135342>] kthread+0x0/0x5e
 [<c0104b0f>] kernel_thread_helper+0x7/0x10
 =======================
BUG: soft lockup - CPU#0 stuck for 11s! [kcryptd:10051]

Pid: 10051, comm: kcryptd Tainted: P        (2.6.24-1-686 #1)
EIP: 0060:[<f89b4026>] EFLAGS: 00000202 CPU: 0
EIP is at aes_enc_blk+0x26/0xb6c [aes_i586]
EAX: 9f4295a8 EBX: 09b75cbc ECX: f07fbe80 EDX: 0000000a
ESI: 9b040326 EDI: afa57368 EBP: f0534020 ESP: f07fbdd4
 DS: 007b ES: 007b FS: 00d8 GS: 0000 SS: 0068
CR0: 8005003b CR2: 080f773c CR3: 2fc7c000 CR4: 000026d0
DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
DR6: ffff0ff0 DR7: 00000400
 [<f89b5702>] aes_encrypt+0x13/0x17 [aes_i586]
 [<f891838d>] crypto_cbc_encrypt+0xf3/0x146 [cbc]
 [<f891802f>] xor_128+0x0/0x17 [cbc]
 [<c01dd80a>] cfq_allow_merge+0x0/0x5a
 [<f89b56ef>] aes_encrypt+0x0/0x17 [aes_i586]
 [<f889f648>] crypt_convert_scatterlist+0x73/0xc3 [dm_crypt]
 [<f889f7e0>] crypt_convert+0x148/0x185 [dm_crypt]
 [<f889f9fe>] kcryptd_do_crypt+0x1e1/0x25e [dm_crypt]
 [<f889f81d>] kcryptd_do_crypt+0x0/0x25e [dm_crypt]
 [<c0132225>] run_workqueue+0x7d/0x109
 [<c0135554>] prepare_to_wait+0x12/0x49
 [<c0132a9b>] worker_thread+0x0/0xc5
 [<c0132b55>] worker_thread+0xba/0xc5
 [<c0135441>] autoremove_wake_function+0x0/0x35
 [<c013537a>] kthread+0x38/0x5e
 [<c0135342>] kthread+0x0/0x5e
 [<c0104b0f>] kernel_thread_helper+0x7/0x10
 =======================
BUG: soft lockup - CPU#0 stuck for 11s! [kcryptd:10051]

Pid: 10051, comm: kcryptd Tainted: P        (2.6.24-1-686 #1)
EIP: 0060:[<c011ad36>] EFLAGS: 00000292 CPU: 0
EIP is at native_flush_tlb_single+0x3/0x4
EAX: fffb7000 EBX: fffb7000 ECX: c03b6edc EDX: fffb7000
ESI: c0345160 EDI: 00000003 EBP: 00000000 ESP: f07fbda8
 DS: 007b ES: 007b FS: 00d8 GS: 0000 SS: 0068
CR0: 8005003b CR2: 08251e90 CR3: 2fc7c000 CR4: 000026d0
DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
DR6: ffff0ff0 DR7: 00000400
 [<c011d0e9>] kunmap_atomic+0x60/0x94
 [<f89152d5>] blkcipher_walk_done+0x87/0x1fe [blkcipher]
 [<f89183cc>] crypto_cbc_encrypt+0x132/0x146 [cbc]
 [<f891802f>] xor_128+0x0/0x17 [cbc]
 [<f89b56ef>] aes_encrypt+0x0/0x17 [aes_i586]
 [<f889f648>] crypt_convert_scatterlist+0x73/0xc3 [dm_crypt]
 [<f889f7e0>] crypt_convert+0x148/0x185 [dm_crypt]
 [<f889f9fe>] kcryptd_do_crypt+0x1e1/0x25e [dm_crypt]
 [<f889f81d>] kcryptd_do_crypt+0x0/0x25e [dm_crypt]
 [<c0132225>] run_workqueue+0x7d/0x109
 [<c0135554>] prepare_to_wait+0x12/0x49
 [<c0132a9b>] worker_thread+0x0/0xc5
 [<c0132b55>] worker_thread+0xba/0xc5
 [<c0135441>] autoremove_wake_function+0x0/0x35
 [<c013537a>] kthread+0x38/0x5e
 [<c0135342>] kthread+0x0/0x5e
 [<c0104b0f>] kernel_thread_helper+0x7/0x10
 =======================
BUG: soft lockup - CPU#0 stuck for 11s! [kcryptd:10051]

Pid: 10051, comm: kcryptd Tainted: P        (2.6.24-1-686 #1)
EIP: 0060:[<f89b4850>] EFLAGS: 00000282 CPU: 0
EIP is at aes_enc_blk+0x850/0xb6c [aes_i586]
EAX: fb6342c0 EBX: 9266f5c2 ECX: a132d120 EDX: 0000009b
ESI: a68a3829 EDI: 5de8424b EBP: f0534030 ESP: f07fbdcc
 DS: 007b ES: 007b FS: 00d8 GS: 0000 SS: 0068
CR0: 8005003b CR2: 080f773c CR3: 003b5000 CR4: 000026d0
DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
DR6: ffff0ff0 DR7: 00000400
 [<f89b5702>] aes_encrypt+0x13/0x17 [aes_i586]
 [<f891838d>] crypto_cbc_encrypt+0xf3/0x146 [cbc]
 [<f891802f>] xor_128+0x0/0x17 [cbc]
 [<f89b56ef>] aes_encrypt+0x0/0x17 [aes_i586]
 [<f889f648>] crypt_convert_scatterlist+0x73/0xc3 [dm_crypt]
 [<f889f7e0>] crypt_convert+0x148/0x185 [dm_crypt]
 [<f889f9fe>] kcryptd_do_crypt+0x1e1/0x25e [dm_crypt]
 [<f889f81d>] kcryptd_do_crypt+0x0/0x25e [dm_crypt]
 [<c0132225>] run_workqueue+0x7d/0x109
 [<c0132a9b>] worker_thread+0x0/0xc5
 [<c0132b55>] worker_thread+0xba/0xc5
 [<c0135441>] autoremove_wake_function+0x0/0x35
 [<c013537a>] kthread+0x38/0x5e
 [<c0135342>] kthread+0x0/0x5e
 [<c0104b0f>] kernel_thread_helper+0x7/0x10
 =======================
ADDRCONF(NETDEV_CHANGE): wlan0_rename: link becomes ready
wlan0_rename: deauthenticate(reason=3)
ADDRCONF(NETDEV_UP): wlan0_rename: link is not ready
wlan0_rename: Initial auth_alg=0
wlan0_rename: authenticate with AP 00:16:b6:a5:e7:1c
wlan0_rename: RX authentication from 00:16:b6:a5:e7:1c (alg=0 transaction=2 status=0)
wlan0_rename: authenticated
wlan0_rename: associate with AP 00:16:b6:a5:e7:1c
wlan0_rename: RX AssocResp from 00:16:b6:a5:e7:1c (capab=0x411 status=0 aid=2)
wlan0_rename: associated
wlan0_rename: WMM queue=2 aci=0 acm=0 aifs=3 cWmin=15 cWmax=1023 burst=0
wlan0_rename: WMM queue=3 aci=1 acm=0 aifs=7 cWmin=15 cWmax=1023 burst=0
wlan0_rename: WMM queue=1 aci=2 acm=0 aifs=2 cWmin=7 cWmax=15 burst=30
wlan0_rename: WMM queue=0 aci=3 acm=0 aifs=2 cWmin=3 cWmax=7 burst=15
ADDRCONF(NETDEV_CHANGE): wlan0_rename: link becomes ready
wlan0_rename: no IPv6 routers present
tun0: Disabled Privacy Extensions

[-- Attachment #2: This is a digitally signed message part. --]
[-- Type: application/pgp-signature, Size: 189 bytes --]

Re: [dm-devel] Re: 2.6.24 Kernel Soft Lock Up with heavy I/O in dm-crypt

[Milan Broz]

Ritesh Raj Sarraf wrote:

> 1) Initialize a device using dm-crypt and LUKS
> 2) Create a filesystem on top of it and mount it.
> 3) Write huge amount of data (as a normal user). Something like 150GB.
>
> As the load goes hight (to something like 12-14), the kernel lock-up is logged 
> into dmesg.
> At that moment, the OS is barely responsive.
>
>   
Please could you try to reproduce it with this patch applied?
(patch for 2.6.25-rc3, for 2.6.24 will follow - code changed here)

Milan
mbroz@redhat.com
--

Add cond_resched() to prevent stuck in big bio processing.

Signed-off-by: Milan Broz <mbroz@redhat.com>
---
 drivers/md/dm-crypt.c |    1 +
 1 files changed, 1 insertions(+), 0 deletions(-)

diff --git a/drivers/md/dm-crypt.c b/drivers/md/dm-crypt.c
index b04f98d..2032228 100644
--- a/drivers/md/dm-crypt.c
+++ b/drivers/md/dm-crypt.c
@@ -432,6 +432,7 @@ static int crypt_convert(struct crypt_config *cc,
 			/* fall through*/
 		case 0:
 			ctx->sector++;
+			cond_resched();
 			continue;
 		}
 

Re: [dm-devel] Re: 2.6.24 Kernel Soft Lock Up with heavy I/O in dm-crypt

[Milan Broz]

(the same patch for 2.6.24)

Milan
--
Add cond_resched() to prevent stuck in big bio processing.

Signed-off-by: Milan Broz <mbroz@redhat.com>
---
 drivers/md/dm-crypt.c |    1 +
 1 file changed, 1 insertion(+)

Index: linux-2.6.24.3/drivers/md/dm-crypt.c
===================================================================
--- linux-2.6.24.3.orig/drivers/md/dm-crypt.c	2008-02-26 01:20:20.000000000 +0100
+++ linux-2.6.24.3/drivers/md/dm-crypt.c	2008-03-01 16:46:24.000000000 +0100
@@ -374,6 +374,7 @@ static int crypt_convert(struct crypt_co
 			break;
 
 		ctx->sector++;
+		cond_resched();
 	}
 
 	return r;

Re: Re: 2.6.24 Kernel Soft Lock Up with heavy I/O in dm-crypt

[Gunter Ohrner]

Milan Broz wrote:
> (the same patch for 2.6.24)

Observations using this patch:

* I did not get a Soft Lockup during my tests so far.

* The latency problems I experienced when writing massive amounts of data to
  an encrypted partitions are improved, though not solved. Using the "dd
  if=/dev/zero of=test.null bs=4M count=1024 ; rm test.null" approach
  mentioned in the other thread, the system stays more responsive and even
  listening to music works more or less, although there are still audible
  interruptions. A few times during the write, CPU usage will spike and IO
  (including music playing in Amarok) will stall for about 0.5 seconds or a
  second.

* This patch seems to hurt performance, I got much lower thoughput and the
  system was never fully loaded, ie. gkrellm showed both cores to run
  between 10% and 40% with a combined CPU utilization fo 30% most of the
  time.
  I got unstable timings from my dd command, but targetting the reiserfs
  partition I got around 18 MB/sec and 34 MB/sec instead of the 41 MB/sec I
  achieved in my tests yesterday.
  So this looks like a viable work around if it reliably avoids the Soft
  Lockup, but it does not seem to be a perfect solution.
  (Addendum: I just got 41 MB/sec with this patch, with an otherwise nearly
  idle system, ie. lots of active processes but none doing anything serious.
  The numbers before applying the patch were much more stable and generally
  higher. Now simply playing or not playing an OGG seems to make the
  difference between 40 MB/sec and 30 MB/sec.)

Greetings,

  Gunter

Re: Re: 2.6.24 Kernel Soft Lock Up with heavy I/O in dm-crypt

[Gunter Ohrner]

Gunter Ohrner wrote:
> * This patch seems to hurt performance, I got much lower thoughput and the

Mh, strange, today I cannot reproduce the performance degradation...

There seem to have been some factors in effect during my yesterday's tests
which I'm not aware of - anyway, currently throughput is fine while running
a 2.6.24.3 kernel with this patch applied.

Greetings,

  Gunter

Re: [dm-devel] Re: 2.6.24 Kernel Soft Lock Up with heavy I/O in dm-crypt

[Ritesh Raj Sarraf]

[-- Attachment #1: Type: text/plain, Size: 1185 bytes --]

I have a problem now.
I'm not able to reproduce the bug on an IBM xSeries box.

CPU: Dual Core 3.8 Ghz
RAM: 1 GB

The big difference in the configuration is that the laptop read data from a 
USB HDD and copied it to another USB HDD (dm-crypted)
The IBM box reads it from an NFS share and copies it to the local hdd 
(dm-crypted)

Ritesh


On Sunday 02 March 2008, Milan Broz wrote:
> (the same patch for 2.6.24)
>
> Milan
> --
> Add cond_resched() to prevent stuck in big bio processing.
>
> Signed-off-by: Milan Broz <mbroz@redhat.com>
> ---
>  drivers/md/dm-crypt.c |    1 +
>  1 file changed, 1 insertion(+)
>
> Index: linux-2.6.24.3/drivers/md/dm-crypt.c
> ===================================================================
> --- linux-2.6.24.3.orig/drivers/md/dm-crypt.c	2008-02-26 01:20:20.000000000
> +0100 +++ linux-2.6.24.3/drivers/md/dm-crypt.c	2008-03-01
> 16:46:24.000000000 +0100 @@ -374,6 +374,7 @@ static int
> crypt_convert(struct crypt_co
>  			break;
>
>  		ctx->sector++;
> +		cond_resched();
>  	}
>
>  	return r;



-- 
Ritesh Raj Sarraf
RESEARCHUT - http://www.researchut.com
"Necessity is the mother of invention."

[-- Attachment #2: This is a digitally signed message part. --]
[-- Type: application/pgp-signature, Size: 189 bytes --]

Re: 2.6.24 Kernel Soft Lock Up with heavy I/O in dm-crypt

[Yan Li]

On Thu, 28 Feb 2008 23:20:48 -0800, Andrew Morton wrote:
> On Thu, 28 Feb 2008 19:24:03 +0530 Ritesh Raj Sarraf <rrs@researchut.com> wrote:
> > I noted kernel soft lockup messages on my laptop when doing a lot of I/O 
> > (200GB) to a dm-crypt device. It was setup using LUKS.
> > The I/O never got disrupted nor anything failed. Just the messages.

I met the same problem yesterday.

> Could be a dm-crypt problem, could be a crypto problem, could even be a
> core block problems.

I think it's due to heavy encryption computation that run longer than
10s and triggered the warning. By heavy I mean dm-crypt with
aes-xts-plain, 512b key size.

This is a typical soft lockup call trace snip from dmesg:
Call Trace:
 [<ffffffff882c60b6>] :xts:crypt+0x9d/0xea
 [<ffffffff882b5705>] :aes_x86_64:aes_encrypt+0x0/0x5
 [<ffffffff882b5705>] :aes_x86_64:aes_encrypt+0x0/0x5
 [<ffffffff882c622e>] :xts:encrypt+0x41/0x46
 [<ffffffff8828273f>] :dm_crypt:crypt_convert_scatterlist+0x7b/0xc7
 [<ffffffff882828ae>] :dm_crypt:crypt_convert+0x123/0x15d
 [<ffffffff88282abd>] :dm_crypt:kcryptd_do_crypt+0x1d5/0x253
 [<ffffffff882828e8>] :dm_crypt:kcryptd_do_crypt+0x0/0x253
 [<ffffffff802448e5>] run_workqueue+0x7f/0x10b
... (omitted)

> If nothing happens in the next few days, yes, please do raise a bugzilla
> report. 

Anybody has done this yet? Or I'll do it.

> If you can provide us with a simple step-by-step recipe to reprodue this,
> and if others can indeed reproduce it, the chances of getting it fixed will
> increase.

Here's my step to reproduce: 

1. You need a moderate computer, it can't be too fast (I'm testing
   this on a Intel(R) Xeon Duo 3040 @ 1.86GHz with 2G ECC RAM on a
   Dell SC440 server, and it's slow enough). On faster computer the
   computation maybe fast enough and not trigger the soft lockup
   detector.

2. Use a 2.6.24+ kernel (I'm using a 2.6.24-etchnhalf.1-amd64 from
   Debian)

3. Create a big partition (or loop file, I think it's OK), at least
   40G.

4. # modprobe xts
   # modprobe aes (or aes-x86_64, same result)
   # cryptsetup -c aes-xts-plain -s 512 luksFormat /dev/sd<Partition>
   # cryptsetup luksOpen /dev/sd<Partition> open_par

5. Do heavy I/O on it, like this:
   # dd if=/dev/zero of=/dev/mapper/open_par

6. After some time (like one hour), run top, I found "kcryptd" is
   running at 100%sy. Check dmesg and I found the soft lockup warning.

I think disk I/O speed is not important here. I'm using a 500G SATA2
drive.

On my server, only AES-XTS with 512 keysize is slow enough to trigger
the lockup detector.  Other slow cryptor such as AES-CBC is OK that I
have test it for hours without any problem.

> Now, I'm assuming that it's just unreasonable for a machine to spend a full
> 11 seconds crunching away on crypto in that code path.  Maybe it _is_
> reasonable, and all we need to do is to poke a cond_resched() in there
> somewhere.

I think this can solve the problem, however, this may harm the
performance of most average users who use only simple crypto such as
CBC-ESSIV, or the performance of high-end server that could handle XTS
with 512b keysize in less than 10s.

Or we can just ignore this problem is there's no data
corruption. Since for moderate computers running XTS with 512 keysize,
the status quo is not very bad, only some dmesg lockup warning and a
unresponsive system. We can add a warning to the document like
"running AES-XTS with 512b key size is a CPU hog and may slow down
your computer."

Anybody see a data corruption?

-- 
Li, Yan

Re: 2.6.24 Kernel Soft Lock Up with heavy I/O in dm-crypt

[Milan Broz]

Yan Li wrote:
> On Thu, 28 Feb 2008 23:20:48 -0800, Andrew Morton wrote:
>> On Thu, 28 Feb 2008 19:24:03 +0530 Ritesh Raj Sarraf <rrs@researchut.com> wrote:
>>> I noted kernel soft lockup messages on my laptop when doing a lot of I/O 
>>> (200GB) to a dm-crypt device. It was setup using LUKS.
>>> The I/O never got disrupted nor anything failed. Just the messages.
> 
> I met the same problem yesterday.
> 
>> Could be a dm-crypt problem, could be a crypto problem, could even be a
>> core block problems.
> 
> I think it's due to heavy encryption computation that run longer than
> 10s and triggered the warning. By heavy I mean dm-crypt with
> aes-xts-plain, 512b key size.
> 
> This is a typical soft lockup call trace snip from dmesg:
> Call Trace:
>  [<ffffffff882c60b6>] :xts:crypt+0x9d/0xea
>  [<ffffffff882b5705>] :aes_x86_64:aes_encrypt+0x0/0x5
>  [<ffffffff882b5705>] :aes_x86_64:aes_encrypt+0x0/0x5
>  [<ffffffff882c622e>] :xts:encrypt+0x41/0x46
>  [<ffffffff8828273f>] :dm_crypt:crypt_convert_scatterlist+0x7b/0xc7
>  [<ffffffff882828ae>] :dm_crypt:crypt_convert+0x123/0x15d
>  [<ffffffff88282abd>] :dm_crypt:kcryptd_do_crypt+0x1d5/0x253
>  [<ffffffff882828e8>] :dm_crypt:kcryptd_do_crypt+0x0/0x253
>  [<ffffffff802448e5>] run_workqueue+0x7f/0x10b
> ... (omitted)

Please could you try if  patch here helps and doesn't cause performance degradation?

http://www2.kernel.org/pub/linux/kernel/people/agk/patches/2.6/2.6.25/dm-crypt-add-cond_resched.patch

...
> Anybody see a data corruption?

It shouldn't cause any corruption of data.

Milan

Re: 2.6.24 Kernel Soft Lock Up with heavy I/O in dm-crypt

[Yan Li]

Hi Milan,

On Mon, Jun 02, 2008 at 08:52:00AM +0200, Milan Broz wrote:
> Please could you try if  patch here helps and doesn't cause performance degradation?
> http://www2.kernel.org/pub/linux/kernel/people/agk/patches/2.6/2.6.25/dm-crypt-add-cond_resched.patch

Will the result of testing a Debian 2.6.24-etchnhalf.1-amd64 kernel
(very near a vanilla kernel) be of same value?  Since the data on some
other drives on this server is important so I dare not try 2.6.25-rc
on it.

Following is my test plan, comments are welcomed:

Test command:
# dd if=/dev/zero of=/dev/mapper/open_device bs=500M count=10
(this server has 2G memory)

The command will be run	for 3 times, and average speed of last two
runs will be taken as result score.

Dm-crypt LUKS Encryption scenarios:
aes-cbc-essiv:sha256, keysize 128
aes-xts-plain, keysize 256
aes-xts-plain, keysize 512

I will compare the speed of all above 3 encryption scenarios, with and
without the patch.

--
Li, Yan

Re: 2.6.24 Kernel Soft Lock Up with heavy I/O in dm-crypt

[Milan Broz]

Yan Li wrote:

>> Please could you try if  patch here helps and doesn't cause performance degradation?
>> http://www2.kernel.org/pub/linux/kernel/people/agk/patches/2.6/2.6.25/dm-crypt-add-cond_resched.patch
>>     
>
> Will the result of testing a Debian 2.6.24-etchnhalf.1-amd64 kernel
> (very near a vanilla kernel) be of same value?  Since the data on some
> other drives on this server is important so I dare not try 2.6.25-rc
> on it.
>   
patch just adds cond_resched(), problem is the same in all recent kernel I think.
just for 2.6.24 kernel patch need to be slighly modified (see below)

> Following is my test plan, comments are welcomed:
>
> Test command:
> # dd if=/dev/zero of=/dev/mapper/open_device bs=500M count=10
> (this server has 2G memory)
>   
bonnie++ test or something like that is more appropriate, but

for this problem is dd test enough

> The command will be run	for 3 times, and average speed of last two
> runs will be taken as result score.
>
>   
flush caches between tests or simple luksClose & luksOpen + mount device between
test runs

> Dm-crypt LUKS Encryption scenarios:
> aes-cbc-essiv:sha256, keysize 128
> aes-xts-plain, keysize 256
> aes-xts-plain, keysize 512
>
> I will compare the speed of all above 3 encryption scenarios, with and
> without the patch.
>
>   
Patch for 2.6.24 kernel

Add cond_resched() to prevent stuck in big bio processing.

Signed-off-by: Milan Broz <mbroz@redhat.com>
---
 drivers/md/dm-crypt.c |    1 +
 1 file changed, 1 insertion(+)

Index: linux-2.6.24.3/drivers/md/dm-crypt.c
===================================================================
--- linux-2.6.24.3.orig/drivers/md/dm-crypt.c	2008-02-26 01:20:20.000000000 +0100
+++ linux-2.6.24.3/drivers/md/dm-crypt.c	2008-03-01 16:46:24.000000000 +0100
@@ -374,6 +374,7 @@ static int crypt_convert(struct crypt_co
 			break;
 
 		ctx->sector++;
+		cond_resched();
 	}
 
 	return r;

Re: 2.6.24 Kernel Soft Lock Up with heavy I/O in dm-crypt

[Yan Li]

On Wed, Jun 04, 2008 at 01:16:30AM +0530, Ritesh Raj Sarraf wrote:
> Following is the bugzilla that was opened against this problem.
> http://bugzilla.kernel.org/show_bug.cgi?id=10378
> 
> Since I wasn't able to reproduce it on a server machine again, it was later
> closed.
> 
> If you think it is the same issue, please feel free to re-open it.

I think they are not the same. My problem lied in the slow crypto
computation under heavy I/O. I'm testing Milan Broz's patch, till now
it seems has solved my problem.

-- 
Li, Yan

Re: 2.6.24 Kernel Soft Lock Up with heavy I/O in dm-crypt

[Yan Li]

[-- Attachment #1: Type: text/plain, Size: 1368 bytes --]

On Mon, Jun 02, 2008 at 02:51:04PM +0200, Milan Broz wrote:
> Patch for 2.6.24 kernel
> Add cond_resched() to prevent stuck in big bio processing.

This patch actual has lead to performance _gain_.

Test Result, performance gain:
aes-cbc-essiv:sha256, keysize 128: 2.53%
aes-xts-plain, keysize 256: 0.26%
aes-xts-plain, keysize 512: 9.31%

Test kernel:
AMD64 2.6.24 from Debian Etch-and-a-half

Test command:
# dd if=/dev/zero of=/dev/mapper/open_device bs=500M count=100

This would write 50G zero data to an open LUKS raw device (no
filesystem overhead here), as 500M per block.  This will stress mainly
the cryptographic and dm code, with little overhead. During the test,
the CPU usage was always full, thus HD speed was not bottleneck.

The count is 10 times bigger than my initial plan.  Any by doing this
I found that, on my server, all the encryption methods has triggered
soft lockup for at least one time.  So this problem is universal, not
only with XTS or LRW operation mode.

With patched kernel, soft lockup _no longer_ occurred.

This server has 2G memory, Intel Xeon Duo @ 1.86GHz.

The command will be run	for 3 times, and average speed of last two
runs will be taken as result score.
  
Device was synced (luksClose ; sync ; luksOpen) between tests.

With my test script (Makefile), calculation spreadsheet and raw test
result attached.

-- 
Li, Yan

[-- Attachment #2: Makefile --]
[-- Type: text/plain, Size: 3346 bytes --]

# dm-crypt stress & benchmark
# Copyright Yan Li <elliot.li.tech@gmail.com>
# License: GPLv3 or above

# README
# this test should be run in runlevel 1
# check dmsg after test for soft lockup

all: show_sysinfo prepare test

show_sysinfo:
	echo ============ SYS INFO ============
	uname -a
	cat /proc/cpuinfo
	free
	hdparm -I /dev/sdc

prepare:
	/etc/init.d/boinc-client stop
	/etc/init.d/mysql stop
	/etc/init.d/apache2 stop
	[ -b /dev/mapper/ohome ] && cryptsetup luksClose ohome || true
	sync

test: test_cbc_128 test_xts_256 test_xts_512

# device ohome must be closed
test_cbc_128:
	echo ============ TEST: aes-cbc-essiv:sha256 keysize: 128 ============
	echo "abc123" | cryptsetup -s 128 -c aes-cbc-essiv:sha256 -d - luksFormat /dev/bigotvg/home
	echo "abc123" | cryptsetup luksOpen /dev/bigotvg/home ohome
	sync
	sleep 2
	echo ============ WARM UP ============
	dd if=/dev/zero of=/dev/mapper/ohome bs=500M count=100
	cryptsetup luksClose ohome && sync && echo "abc123" | cryptsetup luksOpen /dev/bigotvg/home ohome
	sync
	sleep 2
	echo ============ ROUND 1 ============
	dd if=/dev/zero of=/dev/mapper/ohome bs=500M count=100
	cryptsetup luksClose ohome && sync && echo "abc123" | cryptsetup luksOpen /dev/bigotvg/home ohome
	sync
	sleep 2
	echo ============ ROUND 2 ============
	dd if=/dev/zero of=/dev/mapper/ohome bs=500M count=100
	cryptsetup luksClose ohome && sync && echo "abc123" | cryptsetup luksOpen /dev/bigotvg/home ohome
	sync
	sleep 2
	cryptsetup luksClose ohome

# device ohome must be closed
test_xts_256:
	echo ============ TEST: aes-xts-plain keysize: 256 ============
	echo "abc123" | cryptsetup -s 256 -c aes-xts-plain -d - luksFormat /dev/bigotvg/home
	echo "abc123" | cryptsetup luksOpen /dev/bigotvg/home ohome
	sync
	sleep 2
	echo ============ WARM UP ============
	dd if=/dev/zero of=/dev/mapper/ohome bs=500M count=100
	cryptsetup luksClose ohome && sync && echo "abc123" | cryptsetup luksOpen /dev/bigotvg/home ohome
	sync
	sleep 2
	echo ============ ROUND 1 ============
	dd if=/dev/zero of=/dev/mapper/ohome bs=500M count=100
	cryptsetup luksClose ohome && sync && echo "abc123" | cryptsetup luksOpen /dev/bigotvg/home ohome
	sync
	sleep 2
	echo ============ ROUND 2 ============
	dd if=/dev/zero of=/dev/mapper/ohome bs=500M count=100
	cryptsetup luksClose ohome && sync && echo "abc123" | cryptsetup luksOpen /dev/bigotvg/home ohome
	sync
	sleep 2
	cryptsetup luksClose ohome

# device ohome must be closed
test_xts_512:
	echo ============ TEST: aes-xts-plain keysize: 512 ============
	echo "abc123" | cryptsetup -s 512 -c aes-xts-plain -d - luksFormat /dev/bigotvg/home
	echo "abc123" | cryptsetup luksOpen /dev/bigotvg/home ohome
	sync
	sleep 2
	echo ============ WARM UP ============
	dd if=/dev/zero of=/dev/mapper/ohome bs=500M count=100
	cryptsetup luksClose ohome && sync && echo "abc123" | cryptsetup luksOpen /dev/bigotvg/home ohome
	sync
	sleep 2
	echo ============ ROUND 1 ============
	dd if=/dev/zero of=/dev/mapper/ohome bs=500M count=100
	cryptsetup luksClose ohome && sync && echo "abc123" | cryptsetup luksOpen /dev/bigotvg/home ohome
	sync
	sleep 2
	echo ============ ROUND 2 ============
	dd if=/dev/zero of=/dev/mapper/ohome bs=500M count=100
	cryptsetup luksClose ohome && sync && echo "abc123" | cryptsetup luksOpen /dev/bigotvg/home ohome
	sync
	sleep 2
	cryptsetup luksClose ohome

[-- Attachment #3: 2008-06-05-patched.out --]
[-- Type: text/plain, Size: 4573 bytes --]

echo ============ SYS INFO ============
============ SYS INFO ============
uname -a
Linux bigot 2.6.24-etchnhalf.1-amd64 #1 SMP Wed Jun 4 08:56:22 CST 2008 x86_64 GNU/Linux
cat /proc/cpuinfo
processor	: 0
vendor_id	: GenuineIntel
cpu family	: 6
model		: 15
model name	: Intel(R) Xeon(R) CPU            3040  @ 1.86GHz
stepping	: 2
cpu MHz		: 1862.000
cache size	: 2048 KB
physical id	: 0
siblings	: 2
core id		: 0
cpu cores	: 2
fpu		: yes
fpu_exception	: yes
cpuid level	: 10
wp		: yes
flags		: fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush dts acpi mmx fxsr sse sse2 ss ht tm pbe syscall nx lm constant_tsc arch_perfmon pebs bts rep_good pni monitor ds_cpl vmx est tm2 ssse3 cx16 xtpr lahf_lm
bogomips	: 3726.81
clflush size	: 64
cache_alignment	: 64
address sizes	: 36 bits physical, 48 bits virtual
power management:

processor	: 1
vendor_id	: GenuineIntel
cpu family	: 6
model		: 15
model name	: Intel(R) Xeon(R) CPU            3040  @ 1.86GHz
stepping	: 2
cpu MHz		: 1862.000
cache size	: 2048 KB
physical id	: 0
siblings	: 2
core id		: 1
cpu cores	: 2
fpu		: yes
fpu_exception	: yes
cpuid level	: 10
wp		: yes
flags		: fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush dts acpi mmx fxsr sse sse2 ss ht tm pbe syscall nx lm constant_tsc arch_perfmon pebs bts rep_good pni monitor ds_cpl vmx est tm2 ssse3 cx16 xtpr lahf_lm
bogomips	: 3724.06
clflush size	: 64
cache_alignment	: 64
address sizes	: 36 bits physical, 48 bits virtual
power management:

free
             total       used       free     shared    buffers     cached
Mem:       2062188      54756    2007432          0       5020      15292
-/+ buffers/cache:      34444    2027744
Swap:      5863704          0    5863704
hdparm -I /dev/sdc

/dev/sdc:

ATA device, with non-removable media
	Model Number:       ST3500320NS                             
	Serial Number:      9QM1NV32
	Firmware Revision:  SN04    
Standards:
	Used: ATA/ATAPI-6 T13 1410D revision 2 
	Supported: 6 5 4 
Configuration:
	Logical		max	current
	cylinders	16383	16383
	heads		16	16
	sectors/track	63	63
	--
	CHS current addressable sectors:   16514064
	LBA    user addressable sectors:  268435455
	LBA48  user addressable sectors:  976773168
	device size with M = 1024*1024:      476940 MBytes
	device size with M = 1000*1000:      500107 MBytes (500 GB)
Capabilities:
	LBA, IORDY(can be disabled)
	Queue depth: 32
	Standby timer values: spec'd by Standard, no device specific minimum
	R/W multiple sector transfer: Max = 16	Current = 8
	Recommended acoustic management value: 254, current value: 0
	DMA: mdma0 mdma1 mdma2 udma0 udma1 udma2 udma3 udma4 udma5 *udma6 
	     Cycle time: min=120ns recommended=120ns
	PIO: pio0 pio1 pio2 pio3 pio4 
	     Cycle time: no flow control=120ns  IORDY flow control=120ns
Commands/features:
	Enabled	Supported:
	   *	SMART feature set
	    	Security Mode feature set
	   *	Power Management feature set
	   *	Write cache
	   *	Look-ahead
	   *	Host Protected Area feature set
	   *	WRITE_BUFFER command
	   *	READ_BUFFER command
	   *	DOWNLOAD_MICROCODE
	    	SET_MAX security extension
	   *	48-bit Address feature set
	   *	Device Configuration Overlay feature set
	   *	Mandatory FLUSH_CACHE
	   *	FLUSH_CACHE_EXT
	   *	SMART error logging
	   *	SMART self-test
	    	General Purpose Logging feature set
	   *	64-bit World wide name
	   *	Write-Read-Verify feature set
	   *	WRITE_UNCORRECTABLE command
	   *	SATA-I signaling speed (1.5Gb/s)
	   *	SATA-II signaling speed (3.0Gb/s)
	   *	Native Command Queueing (NCQ)
	   *	Phy event counters
	   *	Software settings preservation
	   *	SMART Command Transport (SCT) feature set
	   *	SCT LBA Segment Access (AC2)
	   *	SCT Error Recovery Control (AC3)
	   *	SCT Features Control (AC4)
	   *	SCT Data Tables (AC5)
Security: 
	Master password revision code = 65534
		supported
	not	enabled
	not	locked
		frozen
	not	expired: security count
		supported: enhanced erase
Checksum: correct
/etc/init.d/boinc-client stop
Stopping BOINC core client: boinc_client not running.
/etc/init.d/mysql stop
Stopping MySQL database server: mysqld.
/etc/init.d/apache2 stop
Stopping web server (apache2)...apache2: Could not reliably determine the server's fully qualified domain name, using 127.0.0.1 for ServerName
httpd (no pid file) not running
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/

Re: 2.6.24 Kernel Soft Lock Up with heavy I/O in dm-crypt

[Milan Broz]

Yan Li wrote:
> On Mon, Jun 02, 2008 at 02:51:04PM +0200, Milan Broz wrote:
>> Patch for 2.6.24 kernel
>> Add cond_resched() to prevent stuck in big bio processing.
> 
> This patch actual has lead to performance _gain_.
hmmm, nice:)

> With patched kernel, soft lockup _no longer_ occurred.

Alasdair, please could you move this patch back to actual tree
and sent it upstream?

We have at least two separate reports confirming that it fixes
the problem.

Milan
--
mbroz@redhat.com