C3845 12.4(24)7T device reload with error message "%SYS-2-MALLOCFAIL"

Eungbok Lee · ‎12-18-2014

Hello,

Reloaded the deivce with error message.

It's has many bug the message.

Please help, I can find for the correct bug.

Cisco 3845, IOS 12.4(24)T7 (c3845-spservicesk9-mz.124-24.T7.bin)

- error message -

%SYS-2-MALLOCFAIL: Memory allocation of 65536 bytes failed from 0x60130770, alignment 0

2014-12-15 13:10:49 Local7.Critical 119.199.34.30 963: Pool: Processor Free: 10685012 Cause: Memory fragmentation

2014-12-15 13:10:49 Local7.Critical 119.199.34.30 964: Alternate Pool: None Free: 0 Cause: No Alternate pool

2014-12-15 13:10:49 Local7.Critical 119.199.34.30 965: -Process= "CCSIP_UDP_SOCKET", ipl= 0, pid= 276, -Traceback= 0x600F4C40z 0x6010B884z 0x6012B6D8z 0x600F48B0z 0x6010CAE8z 0x6389BD88z 0x615C97F4z 0x615D3BB8z 0x61619088z 0x61619590z 0x616C2E10z 0x616C2F70z 0x631149E8z 0x631149CCz

2014-12-15 13:10:56 Local7.Info 119.199.34.30 966: 000959: Dec 15 13:13:45.320 KST: %ISDN-6-DISCONNECT: Interface Serial1/0:1

%SYS-2-MALLOCFAIL: Memory allocation of 65536 bytes failed from 0x60130770, alignment 0

2014-12-15 13:18:38 Local7.Critical 119.199.34.30 1042: Pool: Processor Free: 10254300 Cause: Memory fragmentation

2014-12-15 13:18:38 Local7.Critical 119.199.34.30 1043: Alternate Pool: None Free: 0 Cause: No Alternate pool

2014-12-15 13:18:38 Local7.Critical 119.199.34.30 1044: -Process= "CCSIP_SPI_CONTROL", ipl= 0, pid= 274, -Traceback= 0x600F4C40z 0x6010B884z 0x6012B6D8z 0x600F48B0z 0x6010CAE8z 0x6389BD88z 0x618979F8z 0x615CA284z 0x615CA578z 0x61623C30z 0x615DFC8Cz 0x615F6234z 0x61603144z 0x6160482Cz 0x616C145Cz 0x616C17B0z

2014-12-15 13:18:39 Local7.Info 119.199.34.30 1045: 001035: Dec 15 13:21:28.802 KST: %ISDN-6-DISCONNECT: Interface Serial1/0:12 disconnected from 01048405975 , call lasted 94 seconds

%SYS-2-MALLOCFAIL: Memory allocation of 65536 bytes failed from 0x60130770, alignment 0

2014-12-15 13:34:01 Local7.Critical 119.199.34.30 1185: Pool: Processor Free: 9692484 Cause: Memory fragmentation

2014-12-15 13:34:01 Local7.Critical 119.199.34.30 1186: Alternate Pool: None Free: 0 Cause: No Alternate pool

2014-12-15 13:34:01 Local7.Critical 119.199.34.30 1187: -Process= "CCSIP_UDP_SOCKET", ipl= 0, pid= 276, -Traceback= 0x600F4C40z 0x6010B884z 0x6012B6D8z 0x600F48B0z 0x6010CAE8z 0x6389BD88z 0x615D6B64z 0x615CC120z 0x615D3C4Cz 0x61619088z 0x61619590z 0x616C2E10z 0x616C2F70z 0x631149E8z 0x631149CCz

2014-12-15 13:34:11 Local7.Info 119.199.34.30 1188: 001175: Dec 15 13:37:00.548 KST: %ISDN-6-DISCONNECT: Interface Serial1/0:11 disconnected from 0514691386 , call lasted 93 seconds

%SYS-2-MALLOCFAIL: Memory allocation of 65536 bytes failed from 0x60130770, alignment 0

2014-12-15 13:36:57 Local7.Critical 119.199.34.30 1225: Pool: Processor Free: 1600036 Cause: Memory fragmentation

2014-12-15 13:36:57 Local7.Critical 119.199.34.30 1226: Alternate Pool: None Free: 0 Cause: No Alternate pool

2014-12-15 13:36:57 Local7.Critical 119.199.34.30 1227: -Process= "CCSIP_SPI_CONTROL", ipl= 0, pid= 274, -Traceback= 0x600F4C40z 0x6010B884z 0x6012B6D8z 0x600F48B0z 0x6010CAE8z 0x6389BD88z 0x618979F8z 0x638955D8z 0x63895D94z 0x63895E44z 0x615C1C0Cz 0x615C22CCz 0x61602060z 0x61602A34z 0x61602CFCz 0x6160482Cz

2014-12-15 13:37:01 Local7.Error 119.199.34.30 1228: 001212: Dec 15 13:39:50.260 KST: %AAA-3-ACCT_LOW_MEM_UID_FAIL: AAA unable to create UID for incoming calls due to insufficient processor memory

2014-12-15 13:37:01 Local7.Error 119.199.34.30 1229: 001213: Dec 15 13:39:50.264 KST: %DSMP-3-INTERNAL: Internal Error : Unable to allocate memory for dsmp session, -Traceback= 0x61A3B09Cz 0x61A3B7C8z 0x61A0ED98z 0x61A0F440z 0x631149E8z 0x631149CCz

2014-12-15 13:37:03 Local7.Error 119.199.34.30 1230: 001214: Dec 15 13:39:52.876 KST: %VTSP-3-DOCALLHISFAIL:

2014-12-15 13:37:03 Local7.Error 119.199.34.30 1231: vtsp_do_call_history: cannot allocate call history entry to release active call entry

%SYS-2-MALLOCFAIL: Memory allocation of 65536 bytes failed from 0x6012F9B8, alignment 0

2014-12-15 13:38:20 Local7.Critical 119.199.34.30 1240: Pool: Processor Free: 4413420 Cause: Memory fragmentation

2014-12-15 13:38:20 Local7.Critical 119.199.34.30 1241: Alternate Pool: None Free: 0 Cause: No Alternate pool

2014-12-15 13:38:20 Local7.Critical 119.199.34.30 1242: -Process= "VTSP", ipl= 0, pid= 265, -Traceback= 0x600F4C40z 0x6010B884z 0x6012A920z 0x62F27FA0z 0x62F300ACz 0x62F28F20z 0x638B7374z 0x62F368B4z 0x619B84E0z 0x619B8654z 0x614D3820z 0x6103759Cz 0x6103C4D8z 0x61041A94z 0x6387BB20z 0x6387C3FCz

2014-12-15 13:38:23 Local7.Info 119.199.34.30 1243: 001223: Dec 15 13:41:12.851 KST: %ISDN-6-CONNECT: Interface Serial1/0:23 is now connected to 0516240098 N/A

%DSMP-3-INTERNAL: Internal Error : NO MEMORY, -Traceback= 0x61A08AE8z 0x619F7560z 0x61036810z 0x6103CB88z 0x6103D520z 0x6103DAF8z 0x6103E92Cz 0x631149E8z 0x631149CCz

2014-12-15 13:38:50 Local7.Error 119.199.34.30 1250: 001230: Dec 15 13:41:39.511 KST: %DSMP-3-INTERNAL: Internal Error : NO MEMORY, -Traceback= 0x61A08AE8z 0x619F75A4z 0x61036810z 0x6103CB88z 0x6103D520z 0x6103DAF8z 0x6103E92Cz 0x631149E8z 0x631149CCz

2014-12-15 13:38:51 Local7.Critical 119.199.34.30 1251: 001231: Dec 15 13:41:40.355 KST: %SYS-2-MALLOCFAIL: Memory allocation of 65536 bytes failed from 0x60130770, alignment 0

2014-12-15 13:38:51 Local7.Critical 119.199.34.30 1252: Pool: Processor Free: 628 Cause: Not enough free memory

2014-12-15 13:38:51 Local7.Critical 119.199.34.30 1253: Alternate Pool: None Free: 0 Cause: No Alternate pool

2014-12-15 13:38:51 Local7.Critical 119.199.34.30 1254: -Process= "Licensing Auto Update Process", ipl= 0, pid= 126, -Traceback= 0x600F4C40z 0x6010B884z 0x6012B6D8z 0x600F48B0z 0x6010CAE8z 0x6389BD88z 0x637FEFECz 0x637FFF30z 0x637FEEE0z 0x637F8CF0z 0x6117931Cz 0x631149E8z 0x631149CCz

2014-12-15 13:38:55 Local7.Error 119.199.34.30 1255: 001232: Dec 15 13:41:44.727 KST: %DSMP-3-INTERNAL: Internal Error : NO MEMORY, -Traceback= 0x61A08AE8z 0x619F7560z 0x61036810z 0x6103CB88z 0x6103D520z 0x6103DAF8z 0x6103E92Cz 0x631149E8z 0x631149CCz

2014-12-15 13:38:55 Local7.Error 119.199.34.30 1256: 001233: Dec 15 13:41:44.727 KST: %DSMP-3-INTERNAL: Internal Error : NO MEMORY, -Traceback= 0x61A08AE8z 0x619F75A4z 0x61036810z 0x6103CB88z 0x6103D520z 0x6103DAF8z 0x6103E92Cz 0x631149E8z 0x631149CCz

2014-12-15 13:39:00 Local7.Error 119.199.34.30 1257: 001234: Dec 15 13:41:50.076 KST: %DSMP-3-INTERNAL: Internal Error : NO MEMORY, -Traceback= 0x61A08AE8z 0x619F7560z 0x61036810z 0x6103CB88z 0x6103D520z 0x6103DAF8z 0x6103E92Cz 0x631149E8z 0x631149CCz

2014-12-15 13:39:00 Local7.Error 119.199.34.30 1258: 001235: Dec 15 13:41:50.076 KST: %DSMP-3-INTERNAL: Internal Error : NO MEMORY, -Traceback= 0x61A08AE8z 0x619F75A4z 0x61036810z 0x6103CB88z 0x6103D520z 0x6103DAF8z 0x6103E92Cz 0x631149E8z 0x631149CCz

2014-12-15 13:39:01 Local7.Info 119.199.34.30 1259: 001236: Dec 15 13:41:50.580 KST: %ISDN-6-DISCONNECT: Interface Serial1/0:23 disconnected from 0516240098 , call lasted 37 seconds

2014-12-15 13:39:10 Local7.Critical 119.199.34.30 1260: 001244: Dec 15 13:41:54.704 KST: %SYS-2-CHUNKEXPANDFAIL: Could not expand chunk pool for CCAPI Event po. No memory available -Process= "Chunk Manager", ipl= 4, pid= 1, -Traceback= 0x601275DCz 0x631149E8z 0x631149CCz

2014-12-15 13:42:25 Local7.Info 119.199.34.30 90: 000086: *Dec 15 14:10:57.617 KST: %ISDN-6-CONNECT: Interface Serial1/0:10 is now connected to 0516247079 N/A

2014-12-15 13:42:30 Local7.Info 119.199.34.30 91: 000087: *Dec 15 14:11:02.193 KST: %ISDN-6-CONNECT: Interface Serial1/0:7 is now connected to 027285654 N/A

2014-12-15 13:42:31 Local7.Error 119.199.34.30 92: 000088: *Dec 15 14:11:04.277 KST: %AAA-3-ACCT_LOW_MEM_UID_FAIL: AAA unable to create UID for incoming calls due to insufficient processor memory

2014-12-15 13:42:31 Local7.Critical 119.199.34.30 93: 000089: *Dec 15 14:11:04.281 KST: %SYS-2-MALLOCFAIL: Memory allocation of 20000 bytes failed from 0x60138270, alignment 8

2014-12-15 13:42:31 Local7.Critical 119.199.34.30 94: Pool: Processor Free: 8416 Cause: Not enough free memory

2014-12-15 13:42:31 Local7.Critical 119.199.34.30 95: Alternate Pool: None Free: 0 Cause: No Alternate pool

2014-12-15 13:42:31 Local7.Critical 119.199.34.30 96: -Process= "VTSP", ipl= 0, pid= 265, -Traceback= 0x600F4C40z 0x6010EE24z 0x6012A698z 0x614DEB6Cz 0x614E8B54z 0x614EEF08z 0x614EF600z 0x6103BE14z 0x61041A94z 0x6387BB20z 0x6387C3FCz 0x6103DF70z 0x6103E92Cz 0x631149E8z 0x631149CCz

2014-12-15 13:42:31 Local7.Critical 119.199.34.30 97: 000090: *Dec 15 14:11:04.281 KST: %SYS-2-CHUNKEXPANDFAIL: Could not expand chunk pool for TCL Chunks. No memory available -Process= "Chunk Manager", ipl= 4, pid= 1, -Traceback= 0x601275DCz 0x631149E8z 0x631149CCz

2014-12-15 13:42:32 Local7.Error 119.199.34.30 98: 000091: *Dec 15 14:11:04.285 KST: %VTSP-3-DOCALLHISFAIL:

2014-12-15 13:42:32 Local7.Error 119.199.34.30 99: vtsp_do_call_history: cannot allocate call history entry to release active call entry

2014-12-15 13:42:33 Local7.Notice 119.199.34.30 100: 000092: *Dec 15 14:11:05.845 KST: %LINEPROTO-5-UPDOWN: Line protocol on Interface Serial1/0:7, changed state to up

2014-12-15 13:42:33 Local7.Error 119.199.34.30 101: 000093: *Dec 15 14:11:05.845 KST: %ADJ-3-ALLOCATEFAIL: Failed to allocate an adjacency, -Traceback= 0x61C57CE0z 0x61C58250z 0x61C926B8z 0x61C92D84z 0x61C91C68z 0x61C08BF8z 0x61C69CC0z 0x61C6A004z 0x606E8EF4z 0x606EB014z 0x606E760Cz 0x631149E8z 0x631149CCz

2014-12-15 13:42:34 Local7.Notice 119.199.34.30 102: 000094: *Dec 15 14:11:06.549 KST: %LINEPROTO-5-UPDOWN: Line protocol on Interface Serial1/0:10, changed state to up

2014-12-15 13:42:36 Local7.Error 119.199.34.30 103: 000095: *Dec 15 14:11:08.001 KST: %DSMP-3-INTERNAL: Internal Error : Unable to allocate memory for dsmp session, -Traceback= 0x61A3B09Cz 0x61A3B7C8z 0x61A0ED98z 0x61A0F440z 0x631149E8z 0x631149CCz

2014-12-15 13:42:41 Local7.Error 119.199.34.30 104: 000096: *Dec 15 14:11:13.165 KST: %VTSP-3-DOCALLHISFAIL:

2014-12-15 13:42:41 Local7.Error 119.199.34.30 105: vtsp_do_call_history: cannot allocate call history entry to release active call entry

2014-12-15 13:42:41 Local7.Error 119.199.34.30 106: 000097: *Dec 15 14:11:13.805 KST: %VTSP-3-DOCALLHISFAIL:

2014-12-15 13:42:41 Local7.Error 119.199.34.30 107: vtsp_do_call_history: cannot allocate call history entry to release active call entry

2014-12-15 13:42:55 Local7.Warning 119.199.34.30 108: 000098: *Dec 15 14:11:26.066 KST: %C5510-4-NO_RING_DESCRIPTORS: No more ring descriptors available on slot 0 dsp 1.

2014-12-15 13:42:58 Local7.Info 119.199.34.30 109: 000099: *Dec 15 14:11:28.862 KST: %ISDN-6-CONNECT: Interface Serial1/0:14 is now connected to 0512908131 N/A

Leo Laohoo · ‎12-18-2014

You've got Traceback and you're running a "T" train.

You may want to upgrade to a different IOS. Maybe a more stable "M" train. Make sure the "M" train IOS supports the components in the router.

Preston Chilcote · ‎12-24-2014

A traceback alone doesn't mean you have a bug, but a MALLOCFAIL error seen after the router has been up for a long time indicates that the device has a memory leak which causes it to run out of memory. MALLOCFAIL errors are generated when an application on the router asks for memory and is denied because not enough is available. Leo is right though, that you should try upgrading to an M release, like 15.2(4)M or 15.3M if the device has enough RAM and flash. You can use "show mem stats" to watch the amount of free memory in the Processor pool to make sure it's not leaking anymore.