%SYS-2-MALLOCFAIL -- 3825 crash when ephones unregister register

astanislaus · ‎04-23-2008

Before the crash we see a lot of ephones unregistering / registering and soon the router crashes. Has happend twice in 5 weeks.

Same events occur in log before the crash.

Not sure if unregistering / registering of ephones causes the MALLOCFAIL crash of 3835 router.

Version:

========

flash:c3825-spservicesk9-mz.124-15.T4.bin

=========================================

Apr 23 06:09:51.428: %IPPHONE-6-REG_ALARM: Name=SEP00131A6C25F2 Load=CP7912080002SCCP060817A Last=TCP-timeout

Apr 23 06:09:51.524: %IPPHONE-6-REGISTER_NEW: ephone-2:SEP00131A6C25F2 IP:10.120.86.25 Socket:1 DeviceType:Phone has registered.

Apr 23 06:09:53.996: %IPPHONE-6-REG_ALARM: Name=SEP00131A6C2E2E Load=CP7912080002SCCP060817A Last=TCP-timeout

Apr 23 06:09:54.100: %IPPHONE-6-REGISTER_NEW: ephone-3:SEP00131A6C2E2E IP:10.120.86.112 Socket:18 DeviceType:Phone has registered.

Apr 23 06:09:58.388: %IPPHONE-6-REG_ALARM: Name=SEP00131ADC5224 Load=CP7902080002SCCP060817A Last=TCP-timeout

Apr 23 06:09:58.492: %IPPHONE-6-REGISTER_NEW: ephone-4:SEP00131ADC5224 IP:10.120.86.103 Socket:34 DeviceType:Phone has registered.

Apr 23 06:11:22.740: %IPPHONE-6-UNREGISTER_ABNORMAL: ephone-2:SEP00131A6C25F2 IP:10.120.86.25 Socket:1 DeviceType:Phone has unregistered abnormally.

Apr 23 06:11:26.744: %IPPHONE-6-UNREGISTER_ABNORMAL: ephone-3:SEP00131A6C2E2E IP:10.120.86.112 Socket:18 DeviceType:Phone has unregistered abnormally.

Apr 23 06:11:59.679: %SEC-6-IPACCESSLOGNP: list 2 denied 0 127.127.7.1 -> 0.0.0.0, 4 packets

Apr 23 06:12:05.011: %IPPHONE-6-UNREGISTER_NORMAL: ephone-4:SEP00131ADC5224 IP:10.120.86.103 Socket:34 DeviceType:Phone has unregistered normally.

Apr 23 06:17:59.674: %SEC-6-IPACCESSLOGNP: list 2 denied 0 127.127.7.1 -> 0.0.0.0, 6 packets

Apr 23 06:18:40.997: %IPPHONE-6-REG_ALARM: Name=SEP00131A6C2599 Load=CP7912080002SCCP060817A Last=TCP-timeout

Apr 23 06:18:41.093: %IPPHONE-6-REGISTER_NEW: ephone-5:SEP00131A6C2599 IP:10.120.86.3 Socket:16 DeviceType:Phone has registered.

Apr 23 06:18:41.705: %IPPHONE-6-REG_ALARM: Name=SEP00131A592ABA Load=CP7912080002SCCP060817A Last=TCP-timeout

Apr 23 06:18:41.713: %IPPHONE-6-REG_ALARM: Name=SEP00131A6C2E2E Load=CP7912080002SCCP060817A Last=TCP-timeout

Apr 23 06:18:41.733: %IPPHONE-6-REG_ALARM: Name=SEP00131A6C2A92 Load=CP7912080002SCCP060817A Last=TCP-timeout

Apr 23 06:18:41.801: %IPPHONE-6-REGISTER_NEW: ephone-6:SEP00131A592ABA IP:10.120.86.123 Socket:18 DeviceType:Phone has registered.

Apr 23 06:18:41.809: %IPPHONE-6-REGISTER_NEW: ephone-3:SEP00131A6C2E2E IP:10.120.86.112 Socket:19 DeviceType:Phone has registered.

Apr 23 06:18:41.829: %IPPHONE-6-REGISTER_NEW: ephone-7:SEP00131A6C2A92 IP:10.120.86.119 Socket:20 DeviceType:Phone has registered.

Apr 23 06:18:42.685: %IPPHONE-6-REG_ALARM: Name=SEP00131ADC5224 Load=CP7902080002SCCP060817A Last=CM-aborted-TCP

Apr 23 06:18:42.785: %IPPHONE-6-REGISTER_NEW: ephone-4:SEP00131ADC5224 IP:10.120.86.103 Socket:34 DeviceType:Phone has registered.

Apr 23 06:19:03.129: %SYS-2-MALLOCFAIL: Memory allocation of 65536 bytes failed from 0x60102BA0, alignment 0

Pool: Processor Free: 95296 Cause: Memory fragmentation

Alternate Pool: None Free: 0 Cause: No Alternate pool

-Process= "Skinny MOH Server", ipl= 0, pid= 258, -Traceback= 0x61581D40 0x600F0A98 0x600F68D4 0x600F6E40 0x60102BA8 0x60103AF4 0x60191008 0x60182C0C 0x60183DFC 0x6017E618 0x61AAA100 0x605DAA9C 0x605E0594 -Traceback= 0x609EDFA8 0x60987FA8 -Traceback= 0x609EDAE8 0x609EDFDC 0x60987FA8

Apr 23 06:19:12.789: %ISDN-2-ISDN_FATAL: ISDN FATAL ERROR: file ../isdn/lif_common.c, function LIF_GetPkt, message: malloc of Buffer failed

Apr 23 06:19:12.789: %ISDN-2-ISDN_EXIT: malloc of Buffer failed

%Software-forced reload

18:19:12 NZST Wed Apr 23 2008: Breakpoint exception, CPU signal 23, PC = 0x60D8759C

Sushil Kumar Katre · ‎04-23-2008

Hi,

This seems to be happening because of the MoH feature.

Are you using Flash of the router as MOH server?

You are running 12.4(15)T4 which is affected bu a BUG - CSCsk66907 -

%SYS-3-CPUHOG: due to Skinny MOH Server process

Alternate Headline: %SYS-3-CPUHOG: due to Skinny MOH Server process

Symptom:

CPU Hog due to Skinny MOH Server causing phones to unregister:

%SYS-3-CPUHOG: Task is running for (xxx)msecs, more than (xxx)msecs

(xxxxxx),process = Skinny MOH Server.

Conditions

Occurs if Music on Hold (MOH) is being streamed from flash in IOS 12.4(11)XW3

Workaround:

- Use the live feed option by plugging in a CD player or iPOD or any such

device to the MOH port on the UC500

- Disable MOH from flash - that implies tone on hold (or beep on hold)

http://tools.cisco.com/Support/BugToolKit/search/getBugDetails.do?method=fetchBugDetails&bugId=CSCsk66907

Try disabling MOH server on flash and keep it under observation for some time to see if this resolves the issue. In the mean while have a separate MOH server.

This issue is resolved in the followig releases -

12.4(17.9)PI1c

12.4(11)XW5

12.4(15)XY

So you can look for upgrading the router as well.

I'll appreciate if you can send us the show tech output from the router.

-> Sushil

astanislaus · ‎04-23-2008

Sushil,

Thanks for the information. The customer just said to me that the fault may be related to a faulty PoE switch that is intermittently loosing power and turning OFF / ON and hence a whole heap of phones to deregister / register. We think that may be the reason for MALLOCFAIL because a lot of ephones are deregistering/registering at the same time.