Quoted log lines are caused

help · ‎03-22-2017

Hi, I apologize if I am vague but this is my first time writing to one of these discussion boards.

Anywho, I have a couple of SPA112 ATAs that seem to randomly crash and lock up which means I have to go to the customer's site and reboot the damn thing everytime it happens, which is a pain in my ass. So I was hoping that someone could have an answer.

I have updated the devices to the latest firmware available from the cisco website (1.4.1 (002)) but I am curious about one thing. I read the release notes for the upgrade and saw that it works only for certain models that have a serial within a certain range:

My ATA:

Model:	SPA112, 2 FXS
Hardware Version:	1.1.0
Boot Version:	1.3.1 (Dec 11 2013 - 17:43:53)
Firmware Version:	1.4.1 (002) Oct 26 2015
Recovery Firmware:	1.3.0 (001)
WAN MAC Address:	50:67:AE:F0:CA:FD
Host Name:	SPA112
Domain Name:	xxxx.org
Serial Number:	CCQ193716QY
Current Time:	Wed, 22 Mar 2017 09:37:19

According to Release Notes:

SPA112, SPA122, SPA232D (3 types of devices)	Model	SN Range	1.4.1(SPA112/SPA122/SPA232D) 1.4.0 (SPA112/SPA122/SPA232D) 1.3.6 (SPA232D) 1.3.5p and 1.3.2p (SPA112/SPA122)	1.3.5, 1.3.4, 1.3.3, 1.3.2n	1.3.2 or earlier
Device 1 (128MB Flash + New SLIC)	SPA112	CCQ18400001 to CCQ1841033K After CCQ18500DAE	Yes	No	No
	SPA122	CCQ1834031U to CCQ1834037D CCQ1847066I to CCQ184707YA CCQ184902ED to CCQ184904UL CCQ184904UM to CCQ184904Y3 CCQ184904Y4 to CCQ184904Y5 After CCQ185001YH
	SPA232D	After CCQ1906001V
Device 2 (128MB Flash + Old SLIC)	SPA112	CCQ175106J3 to CCQ175106OM CCQ181607OO to CCQ181607U7 CCQ18240E34 to CCQ18400000 CCQ1841033L to CCQ18500D9K	Yes	Yes	No
	SPA122	CCQ174602V3 to CCQ1746030M CCQ181502B7 to CCQ181502GQ CCQ182002W3 to CCQ1834031T CCQ1834037E to CCQ18470660 CCQ184707YB to CCQ184902EC CCQ184904UM to CCQ184904UL CCQ184904Y4 to CCQ184904Y3 CCQ184904Y6 to CCQ185001YH
	SPA232D	CCQ17100G3L to CCQ1906001U
Device 3 (32MB Flash + Old SLIC)	SPA112	Before CCQ182002W2	Yes	Yes	Yes
	SPA122	Before CCQ181805KR
	SPA232D	Before CCQ17100FS0

So my CCQ number should be included within the device 1 row and included in the After CCQ18500DAE range right?

If this the case how can I debug the crashing? I have turned on logging locally, but I believe every time the ATA crashes it resets the logging.... Would syslog help in this situation?

Here is the log from startup:

Jan 1 00:00:07 SPA112 kern.warning [ 0.000000] CPU: ARM926EJ-S [41069265] revision 5 (ARMv5TEJ), cr=00053177

Jan 1 00:00:07 SPA112 kern.warning [ 0.000000] Machine: NXP PNX8181

Jan 1 00:00:07 SPA112 kern.warning [ 0.000000] Memory policy: ECC disabled, Data cache writeback

Jan 1 00:00:07 SPA112 kern.warning [ 0.000000] CPU0: D VIVT write-back cache

Jan 1 00:00:07 SPA112 kern.warning [ 0.000000] CPU0: I cache: 32768 bytes, associativity 4, 32 byte lines, 256 sets

Jan 1 00:00:07 SPA112 kern.warning [ 0.000000] CPU0: D cache: 32768 bytes, associativity 4, 32 byte lines, 256 sets

Jan 1 00:00:07 SPA112 kern.warning [17179569.184000] Built 1 zonelists in Zone order, mobility grouping on. Total pages: 7874

Jan 1 00:00:07 SPA112 kern.warning [17179569.184000] PID hash table entries: 128 (order: 7, 512 bytes)

Jan 1 00:00:07 SPA112 kern.warning [17179569.184000] Console: colour dummy device 80x30

Jan 1 00:00:07 SPA112 kern.warning [17179569.268000] Mount-cache hash table entries: 512

Jan 1 00:00:07 SPA112 kern.warning [17179569.272000] Board HW MODEL : 0x3

Jan 1 00:00:07 SPA112 kern.warning [17179569.340000] squashfs: LZMA suppport for slax.org by jro

Jan 1 00:00:07 SPA112 kern.warning [17179569.388000] [ip3912] : Bridge Mode...

Jan 1 00:00:07 SPA112 kern.err [17179569.420000] physmap-flash physmap-flash.0: map_probe failed

Jan 1 00:00:07 SPA112 kern.warning [17179569.432000] Using Full Image\'s RootFS

Jan 1 00:00:07 SPA112 kern.warning [17179569.436000] Using static partition definition

Jan 1 00:00:07 SPA112 kern.warning [17179569.440000] !!! do adler32 checksum !!!

Jan 1 00:00:07 SPA112 kern.warning [17179571.000000] File system image checksum OK

Jan 1 00:00:07 SPA112 kern.err [17179571.088000] ksz8873 0-005f: failed with status -1

Jan 1 00:00:07 SPA112 kern.warning [17179571.092000] ksz8873: probe of 0-005f failed with error -1

Jan 1 00:00:07 SPA112 kern.warning [17179571.096000] PNX8181 watchdog timer: timer margin 16 sec

Jan 1 00:00:07 SPA112 kern.warning [17179571.112000] GACT probability on

Jan 1 00:00:07 SPA112 kern.warning [17179571.116000] Mirror/redirect action on

Jan 1 00:00:07 SPA112 kern.warning [17179571.120000] u32 classifier

Jan 1 00:00:07 SPA112 kern.warning [17179571.124000] Performance counters on

Jan 1 00:00:07 SPA112 kern.warning [17179571.128000] input device check on

Jan 1 00:00:07 SPA112 kern.warning [17179571.132000] Actions configured

Jan 1 00:00:07 SPA112 kern.warning [17179571.136000] Netfilter messages via NETLINK v0.30.

Jan 1 00:00:07 SPA112 kern.warning [17179571.140000] nf_conntrack version 0.5.0 (1024 buckets, 4096 max)

Jan 1 00:00:07 SPA112 kern.warning [17179571.148000] ipt_time loading

Jan 1 00:00:07 SPA112 kern.warning [17179571.192000] VFS: Mounted root (squashfs filesystem) readonly.

Jan 1 00:00:07 SPA112 kern.warning [17179575.580000] ***** LED_DRV init *****

Jan 1 00:00:07 SPA112 kern.warning [17179575.584000] ***** LED_DRV end *****

Jan 1 00:00:07 SPA112 kern.warning [17179575.612000] *** sys event driver initialized ***

Jan 1 00:00:07 SPA112 kern.err [17179580.080000] br0: Dropping NETIF_F_UFO since no NETIF_F_HW_CSUM feature.

Jan 1 00:00:07 SPA112 kern.warning [17179581.876000] Empty flash at 0x00302d94 ends at 0x00303000

Jan 1 00:00:07 SPA112 kern.warning [17179581.892000] Empty flash at 0x003077c8 ends at 0x00307800

Jan 1 00:00:07 SPA112 kern.warning [17179581.908000] Empty flash at 0x0030a018 ends at 0x0030a800

Jan 1 00:00:07 SPA112 kern.warning [17179581.920000] Empty flash at 0x0030d508 ends at 0x0030d800

Jan 1 00:00:07 SPA112 kern.warning [17179581.932000] Empty flash at 0x0031084c ends at 0x00311000

Jan 1 00:00:07 SPA112 kern.warning [17179581.940000] Empty flash at 0x003159bc ends at 0x00316000

Jan 1 00:00:07 SPA112 kern.warning [17179581.948000] Empty flash at 0x00319034 ends at 0x00319800

Jan 1 00:00:07 SPA112 kern.warning [17179581.952000] Empty flash at 0x0031b84c ends at 0x0031c000

Jan 1 00:00:07 SPA112 kern.warning [17179581.952000] Empty flash at 0x0031eb28 ends at 0x0031f000

Jan 1 00:00:07 SPA112 kern.warning [17179581.996000] Empty flash at 0x0034085c ends at 0x00341000

Jan 1 00:00:07 SPA112 kern.warning [17179582.020000] Empty flash at 0x00343048 ends at 0x00343800

Jan 1 00:00:07 SPA112 kern.warning [17179582.084000] Empty flash at 0x003a3174 ends at 0x003a3800

Jan 1 00:00:07 SPA112 kern.warning [17179582.104000] Empty flash at 0x003a6b58 ends at 0x003a7000

Jan 1 00:00:07 SPA112 kern.warning [17179582.116000] Empty flash at 0x003ac664 ends at 0x003ac800

Jan 1 00:00:07 SPA112 kern.warning [17179582.128000] Empty flash at 0x003af844 ends at 0x003b0000

Jan 1 00:00:07 SPA112 kern.warning [17179582.140000] Empty flash at 0x003b3278 ends at 0x003b3800

Jan 1 00:00:07 SPA112 kern.warning [17179582.144000] Empty flash at 0x003b684c ends at 0x003b7000

Jan 1 00:00:07 SPA112 kern.warning [17179582.152000] Empty flash at 0x003b9b90 ends at 0x003ba000

Jan 1 00:00:07 SPA112 kern.warning [17179582.152000] Empty flash at 0x003bd834 ends at 0x003be000

Jan 1 00:00:08 SPA112 daemon.err dnsmasq[149]: failed to load names from /etc/hosts: No such file or directory

Jan 1 00:00:28 SPA112 kern.err [17179605.544000] Created coma thread for processing coma control message

Jan 1 00:00:30 SPA112 kern.err [17179607.548000] br0: Dropping NETIF_F_UFO since no NETIF_F_HW_CSUM feature.

Jan 1 00:00:30 SPA112 daemon.err system[1]: notify add wan1 interface(br0)

Jan 1 00:00:30 SPA112 daemon.err system[1]: start 0 vlan-id... ok

Jan 1 00:00:52 SPA112 daemon.err dnsmasq[149]: failed to load names from /etc/hosts: No such file or directory

Mar 22 09:06:47 SPA112 kern.warning [17179635.624000] voice_release, chan: 0

Mar 22 09:06:47 SPA112 kern.warning [17179635.680000] voice_release, chan: 1

Mar 22 09:09:19 SPA112 kern.warning [17179787.760000] voice_release, chan: 0

Mar 22 09:09:19 SPA112 kern.warning [17179787.812000] voice_release, chan: 1

Dan Lukes · ‎03-22-2017

it works only for certain models that have a serial within a certain range

It's easy to explain. The SN range follow hardware version number.

First change - the device is manufactured with 128MB of internal memory instead of 32MB in older models. But firmware <=1.3.2 is so old and it can't work with memory-rich device version. Thus 1.3.2n or more recent i required - it can correctly detect the amount of memory present and it can work with it correctly.

Second change is similar - the SLIC chip has been changed. Firmware up to 1.3.5 know no such chip and can't drive it. More recent firmware can detect SLIC type correctly, thus it can work with either old or new SLIC correctly.

In short - support for new hardware configuration has been added into firmware at some time, but no support for older hardware configuration has been removed. Thus, newest models (128MB RAM, new SLIC) are supported by firmware recent enough, while old models can take any firmware.

So my CCQ number should be included within the device 1 row and included in the After CCQ18500DAE range right?

No, as explained above, 1.4.1 firmware is suitable to run on any hardware revision.

If this the case how can I debug the crashing?  I have turned on logging locally, but I believe every time the ATA crashes it resets the logging.... Would syslog help in this situation?

At the first, there are two sources of syslog messages on single SPA112 - the kernel and Voice Application. To debug crashes, you should catch both of them. And you should catch them using external syslog server, so you can ignore the internal syslog is lost after crash.

At the same time you should catch all packets sent/received by SPA112.

After few crashes you may recognize some common pattern in catched data - it may help to identify the crash cause.

help · ‎03-22-2017

Thanks for the quick response Dan!

I will see if the syslog messages reveal the root cause of the problem.

adenmasonry · ‎04-05-2017

Hi,

I noticed in your log posted above:

Jan 1 00:00:07 SPA112 kern.err [17179571.088000] ksz8873 0-005f: failed with status -1

Jan 1 00:00:07 SPA112 kern.warning [17179571.092000] ksz8873: probe of 0-005f failed with error -1

Presumably this is a software level function? Being as it was in the kernel messages of the log.

We have had a SPA122 that would not play nice with the newest firmware it was slated to support. According to the table above, you may try v1.3.5p as this is the last stable release under the v1.3.x series.

Unless you have an issue or feature that the 1.4.x series fixes a more stable firmware release may offer the stability you are looking for. Saving a trip or two to the client's location is always a win.

Good luck,

Rick.

Dan Lukes · ‎04-05-2017

Quoted log lines are caused by probe of 3-port switch on a chip ICs. Such chip is not present in SPA112/SPA122 thus probe failed. It's sign of no problem.

SPA112 1.4.1(002) Crashing Constantly