{"id":80,"date":"2013-06-19T21:11:51","date_gmt":"2013-06-19T19:11:51","guid":{"rendered":"https:\/\/www.timk.de\/it-blog\/?p=80"},"modified":"2013-06-20T07:27:01","modified_gmt":"2013-06-20T05:27:01","slug":"a-analysis-of-sonicwall-nsa-reboot","status":"publish","type":"post","link":"https:\/\/www.timk.de\/it-blog\/a-analysis-of-sonicwall-nsa-reboot\/","title":{"rendered":"A analysis of irregular, random SonicWALL NSA reboots by using TSR\/StackTraces"},"content":{"rendered":"

On one your SonicWALL firewall we had irregular reboots and failovers on a HA-Configuration. We got more information on downloading the “technical support report (TSR)” and found some stack traces on this report. (If you found such stack traces on this report normaly all you can do is to open a support case at SonicWALL or update the SonicWALL to the lasted (stable) version)<\/p>\n

In your case we analysed the problem with the Level3-Support of sonicwall.<\/p>\n

Informations inside the TSR:<\/p>\n

#version 1.0<\/p>\n

Status
\nSerial number 0017-xxxx-xxxx
\nRegistration code: xxxxxxxx
\nCurrent Product Code: 61xx
\nBase Product Code:\u00a0\u00a0\u00a0 61xx
\nExpanded Product Code:N\/A
\nBoard Type: 0x10
\nBoard ID: 0x4
\n06\/13\/2013 14:58:27.160
\nSonicWALL has been up: 0 Days, 1 Hour, 41 Minutes, 25 Seconds
\nFirmware version: SonicOS Enhanced 5.8.1.9-58o
\nHardware IRV: cannot detect
\nNo debug symbols in firmware
\nrestartRequired: False
\nRevision:\u00a0 5.8.1.9-58o
\nROM version 5.0.3.3
\nPrevious firmware version: none
\nmin firmware for this hardware: 4.0.0.0
\nmax firmware for this hardware: 0.0.0.0
\nvers check err: 0
\nCrypto level: domestic
\nProcessor= “8 x 550 MHz Mips64 Octeon Processor”
\nModel= NSA 4500
\nResource language: eng
\n512 MB RAM, 512 MB Flash<\/p>\n

…<\/p>\n

06\/09\/2013 17:26:02.640 System Startup F:5.8.1.9-58o T:base S:5.0.2.10 R: 5.0.3.3 0017xxxxxxxx p: 6105; b: 6100
\n06\/09\/2013 19:21:29.848 System Startup F:5.8.1.9-58o T:base S:5.0.2.10 R: 5.0.3.3 0017xxxxxxxx p: 6105; b: 6100
\n06\/10\/2013 13:09:30.640Reboot due to DP Core 3, Exception06\/10\/2013 13:09:30.640Core Trace 3:
\ncause: tlb store
\nr0:0
\n…
\ncause: tlb store
\nCAUSE:4000800c
\nSTAT:50100ce3
\nBADVA:4
\nEPC:10073340
\nStack trace:
\n0x1007312c<\/p>\n

Up: 0 d, 17:48:24
\n06\/10\/2013 13:10:32.800 System Startup F:5.8.1.9-58o T:base S:5.0.2.10 R: 5.0.3.3 0017xxxxxxxx p: 6105; b: 6100
\n06\/10\/2013 18:34:50.912Reboot due to DP Core 2, Exception06\/10\/2013 18:34:50.912Core Trace 2:
\ncause: tlb store
\nr0:0
\n…
\ncause: tlb store
\nCAUSE:4000800c
\nSTAT:50100ce3
\nBADVA:4
\nEPC:10073340
\nStack trace:
\n0x1007312c<\/p>\n

Up: 0 d, 5:24:41
\n06\/10\/2013 18:35:52.720 System Startup F:5.8.1.9-58o T:base S:5.0.2.10 R: 5.0.3.3 0017xxxxxxxx p: 6105; b: 6100
\n06\/11\/2013 14:16:00.608Reboot due to DP Core 3, Exception06\/11\/2013 14:16:00.608Core Trace 3:
\ncause: tlb store
\nr0:0
\n…
\ncause: tlb store
\nCAUSE:4000800c
\nSTAT:50100ce3
\nBADVA:4
\nEPC:10073340
\nStack trace:
\n0x1007312c<\/p>\n

Up: 0 d, 19:40:30
\n06\/11\/2013 14:17:04.112 System Startup F:5.8.1.9-58o T:base S:5.0.2.10 R: 5.0.3.3 0017xxxxxxxx p: 6105; b: 6100
\n06\/12\/2013 11:35:16.816Reboot due to DP Core 2, Exception06\/12\/2013 11:35:16.816Core Trace 2:
\ncause: tlb store
\n…
\ncause: tlb store
\nCAUSE:4000800c
\nSTAT:50100ce3
\nBADVA:4
\nEPC:10073340
\nStack trace:
\n0x1007312c<\/p>\n

Up: 0 d, 21:18:37
\n06\/12\/2013 11:36:20.944 System Startup F:5.8.1.9-58o T:base S:5.0.2.10 R: 5.0.3.3 0017xxxxxxxx p: 6105; b: 6100
\n06\/12\/2013 12:19:19.560Reboot due to task suspension06\/12\/2013 12:19:19.560Task Trace tTmrTask:
\ntTmrTask\u00a0\u00a0\u00a0 827337e0\u00a0\u00a0\u00a0\u00a0 8e060a90\u00a0 15 STOP\u00a0\u00a0\u00a0\u00a0\u00a0\u00a0 82b54884 8e0606d0\u00a0 ad0003\u00a0\u00a0\u00a0\u00a0 0
\n…
\nepc:0x82b54884
\nStack trace of tTmrTask:
\n0x82b6dcfc
\n0x82733810
\n0x82732fc8
\n0x82733068
\n0x8272bf2c
\n0x8272cadc
\n0x8272c094
\n0x827770e0
\n0x827757d0
\n0x824a8ae4
\n0x824c0bec
\n0x824c0708
\n0x82b533cc
\n0x82b54e2c
\n0x82b54884
\nUp: 0 d, 0:43:23
\n06\/12\/2013 12:20:21.896 System Startup F:5.8.1.9-58o T:base S:5.0.2.10 R: 5.0.3.3 0017xxxxxxxx p: 6105; b: 6100
\n06\/12\/2013 14:56:40.048Reboot due to DP Core 4, Exception06\/12\/2013 14:56:40.048Core Trace 4:
\ncause: tlb store
\n…
\ncause: tlb store
\nCAUSE:4000800c
\nSTAT:50100ce3
\nBADVA:4
\nEPC:10073340
\nStack trace:
\n0x1007312c<\/p>\n

Up: 0 d, 2:36:42
\n06\/12\/2013 14:57:42.848 System Startup F:5.8.1.9-58o T:base S:5.0.2.10 R: 5.0.3.3 0017xxxxxxxx p: 6105; b: 6100
\n06\/12\/2013 16:27:20.864 System Startup F:5.8.1.9-58o T:base S:5.0.2.10 R: 5.0.3.3 0017xxxxxxxx p: 6105; b: 6100
\n06\/12\/2013 16:47:48.848 System Startup F:5.8.1.9-58o T:base S:5.0.2.10 R: 5.0.3.3 0017xxxxxxxx p: 6105; b: 6100
\n06\/13\/2013 10:02:21.464Reboot due to DP Core 4, Exception06\/13\/2013 10:02:21.464Core Trace 4:
\ncause: tlb store
\n…
\ncause: tlb store
\nCAUSE:4000800c
\nSTAT:50100ce3
\nBADVA:4
\nEPC:10073340
\nStack trace:
\n0x1007312c<\/p>\n

Up: 0 d, 17:14:56
\n06\/13\/2013 10:03:24.864 System Startup F:5.8.1.9-58o T:base S:5.0.2.10 R: 5.0.3.3 0017xxxxxxxx p: 6105; b: 6100
\n06\/13\/2013 10:48:04.480Reboot due to DP Core 2, Exception06\/13\/2013 10:48:04.480Core Trace 2:
\ncause: tlb store
\n…
\ncause: tlb store
\nCAUSE:4000800c
\nSTAT:50100ce3
\nBADVA:4
\nEPC:10073340
\nStack trace:
\n0x1007312c<\/p>\n

Up: 0 d, 0:45:4
\n06\/13\/2013 10:49:06.848 System Startup F:5.8.1.9-58o T:base S:5.0.2.10 R: 5.0.3.3 0017xxxxxxxx p: 6105; b: 6100
\n06\/13\/2013 11:39:16.304Reboot due to DP Core 4, Exception06\/13\/2013 11:39:16.304Core Trace 4:
\ncause: tlb store
\n…
\ncause: tlb store
\nCAUSE:4000800c
\nSTAT:50100ce3
\nBADVA:4
\nEPC:10073340
\nStack trace:
\n0x1007312c<\/p>\n

Up: 0 d, 0:50:33
\n06\/13\/2013 11:40:18.864 System Startup F:5.8.1.9-58o T:base S:5.0.2.10 R: 5.0.3.3 0017xxxxxxxx p: 6105; b: 6100
\n06\/13\/2013 13:16:23.496Reboot due to DP Core 2, Exception06\/13\/2013 13:16:23.496Core Trace 2:
\ncause: tlb store
\n…
\ncause: tlb store
\nCAUSE:4000800c
\nSTAT:50100ce3
\nBADVA:4
\nEPC:10073340
\nStack trace:
\n0x1007312c<\/p>\n

Up: 0 d, 1:36:29
\n06\/13\/2013 13:17:25.912 System Startup F:5.8.1.9-58o T:base S:5.0.2.10 R: 5.0.3.3 0017xxxxxxxx p: 6105; b: 6100<\/p><\/blockquote>\n

On the Core-Informations (here 1 to x and not 0) you can see that the problem is not on the “core-funtions” (like taskmanager etc.) because they run on core 0.<\/p>\n

The SonicWALL support analysed that the function mz_allow failed (by decoding the firmware and search for EPC:10073340,Stack trace: 0x1007312c)<\/p>\n

On TraceLog_xxxx.wri we found some more informations:<\/p>\n

…<\/p>\n

06\/13 15:35:56.224: CRITICAL – Informational: lock_timeout_warn:59:
\n06\/13 15:35:56.224: CRITICAL – spinlock 0x83502ff0 is held for more than 1100000000 ticks. Currently held by DP core 2
\n06\/13 15:35:58.224: swAssert – swAssert failed: 0, file ..\/..\/..\/..\/firmware\/fw\/lib\/sw_spinlock.c, line 156
\n06\/13 15:35:58.224: stacktrace –
\n06\/13 15:36:29.224: CRITICAL – Informational: dpCoresCheck:764:
\n06\/13 15:36:29.224: CRITICAL – Exception occurred in DP Core 2; unit will be rebooted …
\n06\/13 15:36:31.368: reboot – *** software watchdog reboot ***
\nshowed 48 log events
\nlog core 01: num exceptions 0, state events logged 0, missed 0 – critical events logged 4, missed 0
\n——-critial (non-wrapping) log:
\n06\/13 15:35:50.240: CRITICAL – Informational: lock_timeout_warn:59:
\n06\/13 15:35:50.240: CRITICAL – spinlock 0x83502ff0 is held for more than 1100000000 ticks. Currently held by DP:2
\n06\/13 15:35:52.240: swAssert – swAssert failed: 0, file ..\/..\/..\/..\/firmware\/fw\/lib\/sw_spinlock.c, line 156
\n06\/13 15:35:52.240: stacktrace –
\nshowed 4 log events
\nlog core 02: num exceptions 1, time 08\/01 07:00:00.896: state events logged 0, missed 0 – critical events logged 5, missed 0
\n******************************************************************
\nStored DP side: Core 2: Unhandled Exception.
\nFirmware Version: SonicOS Enhanced 5.8.1.9-58o
\nDirectory: \/depot-155518-18\/Octeon\/5.8.1\/m2\/target\/oct_mips64\/sw_octeon4500-cp-base
\ncause: tlb store
\n******************************************************************
\nr0 ($00): 0x0000000000000000 \u00a0\u00a0 \u00a0\u00a0 s0 ($16): 0xffffffff83502fa0
\nat ($01): 0x0000000000000000 \u00a0\u00a0 \u00a0\u00a0 s1 ($17): 0xffffffff88d551c0
\nv0 ($02): 0x0000000000000000 \u00a0\u00a0 \u00a0\u00a0 s2 ($18): 0x00000000000000c0
\nv1 ($03): 0xffffffff88d5d680 \u00a0\u00a0 \u00a0\u00a0 s3 ($19): 0x0000000000000000
\na0 ($04): 0x000000000000155e \u00a0\u00a0 \u00a0\u00a0 s4 ($20): 0xffffffff83502ff0
\na1 ($05): 0x00000000101c6328 \u00a0\u00a0 \u00a0\u00a0 s5 ($21): 0x00000000101c0000
\na2 ($06): 0x000000000000082e \u00a0\u00a0 \u00a0\u00a0 s6 ($22): 0xffffffff83fe2740
\na3 ($07): 0x000000000c34eff8 \u00a0\u00a0 \u00a0\u00a0 s7 ($23): 0x0000000001c82468
\nt0 ($08): 0x0000000000000020 \u00a0\u00a0 \u00a0\u00a0 t8 ($24): 0x00000000000000a8
\nt1 ($09): 0x0000000000000008 \u00a0\u00a0 \u00a0\u00a0 t9 ($25): 0x0000000000000033
\nt2 ($10): 0x00000000000f4242 \u00a0\u00a0 \u00a0\u00a0 k0 ($26): 0x0000000010127da0
\nt3 ($11): 0x0000000000000001 \u00a0\u00a0 \u00a0\u00a0 k1 ($27): 0xffffffff80001190
\nt4 ($12): 0xffffffff83030000 \u00a0\u00a0 \u00a0\u00a0 gp ($28): 0x00000000120148b0
\nt5 ($13): 0x0000000000000033 \u00a0\u00a0 \u00a0\u00a0 sp ($29): 0x000000001601f2f8
\nt6 ($14): 0x000000000000000c \u00a0\u00a0 \u00a0\u00a0 s8 ($30): 0x0000000000000001
\nt7 ($15): 0x00000000000000c0 \u00a0\u00a0 \u00a0\u00a0 ra ($31): 0x000000001007312c
\nCOP0_CAUSE: 0x000000004000800c
\nCOP0_STATUS: 0x0000000050100ce3
\nCOP0_BADVADDR: 0x0000000000000004
\nCOP0_EPC: 0x0000000010073340
\n******************************************************************
\nStack trace:
\n0x1007312c<\/p>\n

——-critial (non-wrapping) log:
\n06\/13 15:35:48.256: exception – DP side: Core 2: Unhandled Exception.
\n06\/13 15:35:48.256: regset –
\nr0 ($00): 0x0000000000000000 \u00a0\u00a0 \u00a0\u00a0 s0 ($16): 0xffffffff83502fa0
\nat ($01): 0x0000000000000000 \u00a0\u00a0 \u00a0\u00a0 s1 ($17): 0xffffffff88d551c0
\nv0 ($02): 0x0000000000000000 \u00a0\u00a0 \u00a0\u00a0 s2 ($18): 0x00000000000000c0
\nv1 ($03): 0xffffffff88d5d680 \u00a0\u00a0 \u00a0\u00a0 s3 ($19): 0x0000000000000000
\na0 ($04): 0x000000000000155e \u00a0\u00a0 \u00a0\u00a0 s4 ($20): 0xffffffff83502ff0
\na1 ($05): 0x00000000101c6328 \u00a0\u00a0 \u00a0\u00a0 s5 ($21): 0x00000000101c0000
\na2 ($06): 0x000000000000082e \u00a0\u00a0 \u00a0\u00a0 s6 ($22): 0xffffffff83fe2740
\na3 ($07): 0x000000000c34eff8 \u00a0\u00a0 \u00a0\u00a0 s7 ($23): 0x0000000001c82468
\nt0 ($08): 0x0000000000000020 \u00a0\u00a0 \u00a0\u00a0 t8 ($24): 0x00000000000000a8
\nt1 ($09): 0x0000000000000008 \u00a0\u00a0 \u00a0\u00a0 t9 ($25): 0x0000000000000033
\nt2 ($10): 0x00000000000f4242 \u00a0\u00a0 \u00a0\u00a0 k0 ($26): 0x0000000010127da0
\nt3 ($11): 0x0000000000000001 \u00a0\u00a0 \u00a0\u00a0 k1 ($27): 0xffffffff80001190
\nt4 ($12): 0xffffffff83030000 \u00a0\u00a0 \u00a0\u00a0 gp ($28): 0x00000000120148b0
\nt5 ($13): 0x0000000000000033 \u00a0\u00a0 \u00a0\u00a0 sp ($29): 0x000000001601f2f8
\nt6 ($14): 0x000000000000000c \u00a0\u00a0 \u00a0\u00a0 s8 ($30): 0x0000000000000001
\nt7 ($15): 0x00000000000000c0 \u00a0\u00a0 \u00a0\u00a0 ra ($31): 0x000000001007312c
\n06\/13 15:35:48.256: exc-regset –
\nCOP0_CAUSE: 0x000000004000800c
\nCOP0_STATUS: 0x0000000050100ce3
\nCOP0_BADVADDR: 0x0000000000000004
\nCOP0_EPC: 0x0000000010073340
\n06\/13 15:35:48.256: stacktrace –
\n06\/13 15:35:48.256: exception – *** exception reboot ***
\nshowed 5 log events
\nlog core 03: num exceptions 0, state events logged 0, missed 0 – critical events logged 4, missed 0
\n——-critial (non-wrapping) log:
\n06\/13 15:35:50.224: CRITICAL – Informational: lock_timeout_warn:59:
\n06\/13 15:35:50.224: CRITICAL – spinlock 0x83502ff0 is held for more than 1100000000 ticks. Currently held by DP:2
\n06\/13 15:35:52.224: swAssert – swAssert failed: 0, file ..\/..\/..\/..\/firmware\/fw\/lib\/sw_spinlock.c, line 156
\n06\/13 15:35:52.224: stacktrace –
\nshowed 4 log events
\nlog core 04: num exceptions 0, state events logged 0, missed 0 – critical events logged 4, missed 0
\n——-critial (non-wrapping) log:
\n06\/13 15:35:50.240: CRITICAL – Informational: lock_timeout_warn:59:
\n06\/13 15:35:50.240: CRITICAL – spinlock 0x83502ff0 is held for more than 1100000000 ticks. Currently held by DP:2
\n06\/13 15:35:52.240: swAssert – swAssert failed: 0, file ..\/..\/..\/..\/firmware\/fw\/lib\/sw_spinlock.c, line 156
\n06\/13 15:35:52.240: stacktrace –
\nshowed 4 log events
\nlog core 05: num exceptions 0, state events logged 0, missed 0 – critical events logged 4, missed 0
\n——-critial (non-wrapping) log:
\n06\/13 15:35:50.224: CRITICAL – Informational: lock_timeout_warn:59:
\n06\/13 15:35:50.224: CRITICAL – spinlock 0x83502ff0 is held for more than 1100000000 ticks. Currently held by DP:2
\n06\/13 15:35:52.224: swAssert – swAssert failed: 0, file ..\/..\/..\/..\/firmware\/fw\/lib\/sw_spinlock.c, line 156
\n06\/13 15:35:52.224: stacktrace –
\nshowed 4 log events
\nlog core 06: num exceptions 0, state events logged 0, missed 0 – critical events logged 4, missed 0
\n——-critial (non-wrapping) log:
\n06\/13 15:35:50.224: CRITICAL – Informational: lock_timeout_warn:59:
\n06\/13 15:35:50.224: CRITICAL – spinlock 0x83502ff0 is held for more than 1100000000 ticks. Currently held by DP:2
\n06\/13 15:35:52.224: swAssert – swAssert failed: 0, file ..\/..\/..\/..\/firmware\/fw\/lib\/sw_spinlock.c, line 156
\n06\/13 15:35:52.224: stacktrace –
\nshowed 4 log events
\nlog core 07: num exceptions 0, state events logged 0, missed 0 – critical events logged 4, missed 0
\n——-critial (non-wrapping) log:
\n06\/13 15:35:50.224: CRITICAL – Informational: lock_timeout_warn:59:
\n06\/13 15:35:50.224: CRITICAL – spinlock 0x83502ff0 is held for more than 1100000000 ticks. Currently held by DP:2
\n06\/13 15:35:52.224: swAssert – swAssert failed: 0, file ..\/..\/..\/..\/firmware\/fw\/lib\/sw_spinlock.c, line 156
\n06\/13 15:35:52.224: stacktrace –<\/p>\n

…<\/p><\/blockquote>\n

Spinlock are use by VPNs and\/or SSL-VPNs. In our case the bug was found on the VPN-Impemtaion and was fixed on the new availabe early firmware release.<\/p>\n","protected":false},"excerpt":{"rendered":"

On one your SonicWALL firewall we had irregular reboots and failovers on a HA-Configuration. We got more information on downloading the “technical support report (TSR)” and found some stack traces on this report. (If you found such stack traces on this report normaly all you can do is to open a support case at SonicWALL […]<\/p>\n","protected":false},"author":1,"featured_media":0,"comment_status":"open","ping_status":"open","sticky":false,"template":"","format":"standard","meta":{"footnotes":""},"categories":[10],"tags":[],"class_list":["post-80","post","type-post","status-publish","format-standard","hentry","category-sonicwall"],"_links":{"self":[{"href":"https:\/\/www.timk.de\/it-blog\/wp-json\/wp\/v2\/posts\/80","targetHints":{"allow":["GET"]}}],"collection":[{"href":"https:\/\/www.timk.de\/it-blog\/wp-json\/wp\/v2\/posts"}],"about":[{"href":"https:\/\/www.timk.de\/it-blog\/wp-json\/wp\/v2\/types\/post"}],"author":[{"embeddable":true,"href":"https:\/\/www.timk.de\/it-blog\/wp-json\/wp\/v2\/users\/1"}],"replies":[{"embeddable":true,"href":"https:\/\/www.timk.de\/it-blog\/wp-json\/wp\/v2\/comments?post=80"}],"version-history":[{"count":5,"href":"https:\/\/www.timk.de\/it-blog\/wp-json\/wp\/v2\/posts\/80\/revisions"}],"predecessor-version":[{"id":84,"href":"https:\/\/www.timk.de\/it-blog\/wp-json\/wp\/v2\/posts\/80\/revisions\/84"}],"wp:attachment":[{"href":"https:\/\/www.timk.de\/it-blog\/wp-json\/wp\/v2\/media?parent=80"}],"wp:term":[{"taxonomy":"category","embeddable":true,"href":"https:\/\/www.timk.de\/it-blog\/wp-json\/wp\/v2\/categories?post=80"},{"taxonomy":"post_tag","embeddable":true,"href":"https:\/\/www.timk.de\/it-blog\/wp-json\/wp\/v2\/tags?post=80"}],"curies":[{"name":"wp","href":"https:\/\/api.w.org\/{rel}","templated":true}]}}