I have had this happen twice in about 3 weeks. Dell PC / ACID distribution / 2 URIx. I know the software restarted because I have a message play from the start-marco. ...STeve - KF5VH On 6/24/2016 6:18 PM, Bryan Fields wrote:
On 6/15/16 3:59 PM, Bryan Fields wrote:
I've had asterisk crash twice over the past few weeks. I can't see any obvious problems in the logging. I've enabled debug logging and will see what I can find out when/if it happens again. It crashed last night! The only common theme I see is Echolink connected and then it had an error of sorts.
Has anyone been seeing asterisk crashes related to this?
channel.c: Thread -1260881088 Blocking 'echolink/el0-0', already blocked by thread -1257419968 in procedure ast_waitfor_nandfds
It then dies after that message. I do have detailed logs if needed I can post them on a web server.
[Jun 24 00:17:21] DEBUG[26077] chan_iax2.c: Registration created on call 4900 [Jun 24 00:17:21] WARNING[26080] chan_iax2.c: REGISTER-LOG: registry rereqquest [Jun 24 00:17:21] DEBUG[26076] chan_iax2.c: schedule decrement of callno used for 67.215.233.178 in 60 seconds [Jun 24 00:17:27] DEBUG[26079] chan_iax2.c: Received iseqno 182 not within window 183->183 [Jun 24 00:17:27] DEBUG[26085] chan_iax2.c: ip callno count decremented to 4 for 67.215.233.178 [Jun 24 00:17:31] DEBUG[26085] chan_iax2.c: ip callno count decremented to 3 for 67.215.233.178 [Jun 24 00:17:41] VERBOSE[26064] logger.c: == Refreshing DNS lookups. [Jun 24 00:17:43] DEBUG[26077] chan_iax2.c: Received iseqno 220 not within window 221->221 [Jun 24 00:17:47] DEBUG[26077] chan_iax2.c: Received iseqno 14 not within window 15->15 [Jun 24 00:17:47] WARNING[26082] chan_iax2.c: REGISTER-LOG: Sending registration request for '40821' [Jun 24 00:17:47] DEBUG[26082] chan_iax2.c: Allocate call number [Jun 24 00:17:47] DEBUG[26082] chan_iax2.c: ip callno count incremented to 4 for 67.215.233.178 [Jun 24 00:17:47] DEBUG[26082] chan_iax2.c: Registration created on call 7527 [Jun 24 00:17:48] WARNING[26079] chan_iax2.c: REGISTER-LOG: registry rereqquest [Jun 24 00:17:48] DEBUG[26080] chan_iax2.c: schedule decrement of callno used for 67.215.233.178 in 60 seconds [Jun 24 00:17:53] DEBUG[26080] chan_iax2.c: Received iseqno 232 not within window 233->233 [Jun 24 00:17:54] DEBUG[26078] chan_iax2.c: Received iseqno 225 not within window 226->226 [Jun 24 00:17:57] DEBUG[26085] chan_iax2.c: ip callno count decremented to 3 for 67.215.233.178 [Jun 24 00:18:07] WARNING[26079] chan_iax2.c: REGISTER-LOG: Sending registration request for '42032' [Jun 24 00:18:07] DEBUG[26079] chan_iax2.c: Allocate call number [Jun 24 00:18:07] DEBUG[26079] chan_iax2.c: ip callno count incremented to 4 for 67.215.233.178 [Jun 24 00:18:07] DEBUG[26079] chan_iax2.c: Registration created on call 8176 [Jun 24 00:18:07] WARNING[26076] chan_iax2.c: REGISTER-LOG: registry rereqquest [Jun 24 00:18:07] DEBUG[26080] chan_iax2.c: schedule decrement of callno used for 67.215.233.178 in 60 seconds [Jun 24 00:18:11] WARNING[26076] chan_iax2.c: REGISTER-LOG: Sending registration request for '41618' [Jun 24 00:18:11] DEBUG[26076] chan_iax2.c: Allocate call number [Jun 24 00:18:11] DEBUG[26076] chan_iax2.c: ip callno count incremented to 5 for 67.215.233.178 [Jun 24 00:18:11] DEBUG[26076] chan_iax2.c: Registration created on call 6735 [Jun 24 00:18:12] WARNING[26075] chan_iax2.c: REGISTER-LOG: registry rereqquest [Jun 24 00:18:12] DEBUG[26078] chan_iax2.c: schedule decrement of callno used for 67.215.233.178 in 60 seconds [Jun 24 00:18:15] DEBUG[26084] chan_iax2.c: Received iseqno 241 not within window 242->242 [Jun 24 00:18:17] DEBUG[26085] chan_iax2.c: ip callno count decremented to 4 for 67.215.233.178 [Jun 24 00:18:21] DEBUG[26085] chan_iax2.c: ip callno count decremented to 3 for 67.215.233.178 [Jun 24 00:18:23] DEBUG[26082] chan_iax2.c: Received iseqno 244 not within window 245->245 [Jun 24 00:18:33] DEBUG[26075] chan_iax2.c: Received iseqno 247 not within window 248->248 [Jun 24 00:18:36] VERBOSE[26072] logger.c: -- Received OK from Echolink server nasouth.echolink.org [Jun 24 00:18:38] WARNING[26083] chan_iax2.c: REGISTER-LOG: Sending registration request for '40821' [Jun 24 00:18:38] DEBUG[26083] chan_iax2.c: Allocate call number [Jun 24 00:18:38] DEBUG[26083] chan_iax2.c: ip callno count incremented to 4 for 67.215.233.178 [Jun 24 00:18:38] DEBUG[26083] chan_iax2.c: Registration created on call 9504 [Jun 24 00:18:38] WARNING[26084] chan_iax2.c: REGISTER-LOG: registry rereqquest [Jun 24 00:18:38] DEBUG[26082] chan_iax2.c: schedule decrement of callno used for 67.215.233.178 in 60 seconds [Jun 24 00:18:43] DEBUG[26084] chan_iax2.c: Received iseqno 252 not within window 253->253 [Jun 24 00:18:48] DEBUG[26085] chan_iax2.c: ip callno count decremented to 3 for 67.215.233.178 [Jun 24 00:18:53] DEBUG[26083] chan_iax2.c: Received iseqno 254 not within window 255->255 [Jun 24 00:18:57] WARNING[26081] chan_iax2.c: REGISTER-LOG: Sending registration request for '42032' [Jun 24 00:18:57] DEBUG[26081] chan_iax2.c: Allocate call number [Jun 24 00:18:57] DEBUG[26081] chan_iax2.c: ip callno count incremented to 4 for 67.215.233.178 [Jun 24 00:18:57] DEBUG[26081] chan_iax2.c: Registration created on call 14887 [Jun 24 00:18:58] WARNING[26084] chan_iax2.c: REGISTER-LOG: registry rereqquest [Jun 24 00:18:58] DEBUG[26076] chan_iax2.c: schedule decrement of callno used for 67.215.233.178 in 60 seconds [Jun 24 00:19:02] WARNING[26078] chan_iax2.c: REGISTER-LOG: Sending registration request for '41618' [Jun 24 00:19:02] DEBUG[26078] chan_iax2.c: Allocate call number [Jun 24 00:19:02] DEBUG[26078] chan_iax2.c: ip callno count incremented to 5 for 67.215.233.178 [Jun 24 00:19:02] DEBUG[26078] chan_iax2.c: Registration created on call 5474 [Jun 24 00:19:02] WARNING[26080] chan_iax2.c: REGISTER-LOG: registry rereqquest [Jun 24 00:19:02] DEBUG[26075] chan_iax2.c: schedule decrement of callno used for 67.215.233.178 in 60 seconds [Jun 24 00:19:03] DEBUG[26083] chan_iax2.c: Received iseqno 3 not within window 4->4 [Jun 24 00:19:06] DEBUG[26084] chan_iax2.c: Received iseqno 218 not within window 219->219 [Jun 24 00:19:06] VERBOSE[26073] logger.c: -- new CALL=RV9CN,ip=44.137.75.155,name= Slava [Jun 24 00:19:06] DEBUG[15005] pbx.c: Launching 'Rpt' [Jun 24 00:19:06] VERBOSE[15005] logger.c: -- Executing [40821@radio-secure:1] Rpt("echolink/el0-0", "40821") in new stack [Jun 24 00:19:06] DEBUG[15005] channel.c: Set channel echolink/el0-0 to read format slin [Jun 24 00:19:06] DEBUG[15005] channel.c: Set channel echolink/el0-0 to write format slin [Jun 24 00:19:06] DEBUG[15005] chan_dahdi.c: Using channel -2 [Jun 24 00:19:06] DEBUG[15005] channel.c: Set channel DAHDI/pseudo-1265695481 to read format slin [Jun 24 00:19:06] DEBUG[15005] channel.c: Set channel DAHDI/pseudo-1265695481 to write format slin [Jun 24 00:19:06] DEBUG[15005] devicestate.c: Notification of state change to be queued on device/channel echolink/el0 [Jun 24 00:19:06] DEBUG[26066] devicestate.c: No provider found, checking channel drivers for echolink - el0 [Jun 24 00:19:06] DEBUG[26066] devicestate.c: Changing state for echolink/el0 - state 2 (In use) [Jun 24 00:19:06] DEBUG[15005] channel.c: Thread -1260881088 Blocking 'echolink/el0-0', already blocked by thread -1257419968 in procedure ast_waitfor_nandfds [Jun 24 00:19:06] DEBUG[15005] pbx.c: Spawn extension (radio-secure,40821,1) exited KEEPALIVE on 'echolink/el0-0' [Jun 24 00:19:06] VERBOSE[15005] logger.c: == Spawn extension (radio-secure, 40821, 1) exited KEEPALIVE on 'echolink/el0-0' [Jun 24 00:19:07] DEBUG[26089] channel.c: Ignoring answer on an inbound call! [Jun 24 00:19:07] DEBUG[26085] chan_iax2.c: ip callno count decremented to 4 for 67.215.233.178 [Jun 24 00:19:11] VERBOSE[26074] logger.c: -- Received OK from Echolink server servers.echolink.org [Jun 24 00:19:11] VERBOSE[26072] logger.c: -- Received OK from Echolink server servers.echolink.org [Jun 24 00:19:12] DEBUG[26085] chan_iax2.c: ip callno count decremented to 3 for 67.215.233.178 [Jun 24 00:19:13] DEBUG[26080] chan_iax2.c: Received iseqno 6 not within window 7->7 [Jun 24 00:19:17] DEBUG[26075] chan_iax2.c: Received iseqno 47 not within window 48->48
Output from the CLI in screen is below. It mirrors the logs.
-- new CALL=RV9CN,ip=44.137.75.155,name= Slava -- Executing [40821@radio-secure:1] Rpt("echolink/el0-0", "40821") in new stack Node Variable dump for node 40821: RPT_NUMLINKS=49
RPT_LINKS=49,T41618,T3685739,T42032,T41170,T27714,T41599,T42462,T29826,T29901,T29902,T41508,T29771,T27455,T29772,T29827,T43309,T41510,T41629,T28073,T2578,T28183,T41535,T29227,T29474,T29475,T42978,T41385,TN7GLV,T42610,T41373,T27654,T29521,T29522,T41688,T1980,T3630564,T42574,T41525,T42393,T1976,T29658,T42205,T41237,T40603,T29659,T42947,T40696,T42215,T40562 RPT_NUMALINKS=3 RPT_ALINKS=3,41618TU,3685739TU,42032TU RPT_TXKEYED=0 RPT_ETXKEYED=0 RPT_RXKEYED=0 RPT_AUTOPATCHUP=0 -- 10 variables == Spawn extension (radio-secure, 40821, 1) exited KEEPALIVE on 'echolink/el0-0' -- Received OK from Echolink server servers.echolink.org -- Received OK from Echolink server servers.echolink.org Itchy*CLI> Disconnected from Asterisk server Executing last minute cleanups Asterisk ending (0).