I’m using an asterisk 1.4 with TDM2400p (4 FXO/20 FXS) in our local pbx and often get a
complain from user of disconnection in middle of the calls. I’ve notice in my logs that all the reported
disconnected call has these message " [2010-03-03 17:17:07] DEBUG[4557] chan_zap.c: Something changed out on 146/0 to 125/2, returning -3 to restart " . This happen both inbound and outbound calls.
Here is the sample logs of the call leg…
Regards,
Piker M
[2010-03-03 17:16:08] VERBOSE[4557] logger.c: – Starting simple switch on ‘Zap/146-1’
[2010-03-03 17:16:08] VERBOSE[4557] logger.c: – Executing [s@incoming-pldt:1] Goto(“Zap/146-1”, “checktime|_X.|1”) in new stack
[2010-03-03 17:16:08] VERBOSE[4557] logger.c: – Goto (checktime,_X.,1)
[2010-03-03 17:16:08] VERBOSE[4557] logger.c: – Executing [_X.@checktime:1] Set(“Zap/146-1”, “CDR(userfield)=IN”) in new stack
[2010-03-03 17:16:08] VERBOSE[4557] logger.c: – Executing [_X.@checktime:2] Set(“Zap/146-1”, “FROM-EXTERNAL=YES”) in new stack
[2010-03-03 17:16:08] VERBOSE[4557] logger.c: – Executing [_X.@checktime:3] Set(“Zap/146-1”, “CALLED-NUM=_X.”) in new stack
[2010-03-03 17:16:08] VERBOSE[4557] logger.c: – Executing [_X.@checktime:4] GotoIfTime(“Zap/146-1”, “08:00-21:00|mon-sat||?incoming-reghours|s|1”) in new stack
[2010-03-03 17:16:08] VERBOSE[4557] logger.c: – Goto (incoming-reghours,s,1)
[2010-03-03 17:16:08] VERBOSE[4557] logger.c: – Executing [s@incoming-reghours:1] Goto(“Zap/146-1”, “custom-exten-1|s|1”) in new stack
[2010-03-03 17:16:08] VERBOSE[4557] logger.c: – Goto (custom-exten-1,s,1)
[2010-03-03 17:16:08] VERBOSE[4557] logger.c: – Executing [s@custom-exten-1:1] Answer(“Zap/146-1”, “”) in new stack
[2010-03-03 17:16:08] DEBUG[4557] chan_zap.c: Took Zap/146-1 off hook
[2010-03-03 17:16:08] WARNING[4557] chan_zap.c: Unable to request echo training on channel 146
[2010-03-03 17:16:08] VERBOSE[4557] logger.c: – Executing [s@custom-exten-1:2] Wait(“Zap/146-1”, “3”) in new stack
[2010-03-03 17:16:11] VERBOSE[4557] logger.c: – Executing [s@custom-exten-1:3] BackGround(“Zap/146-1”, “pivr11&otherwise&calls-taken-by&reception&personnel”) in new stack
[2010-03-03 17:16:11] VERBOSE[4557] logger.c: – <Zap/146-1> Playing ‘pivr11’ (language ‘en’)
[2010-03-03 17:16:17] VERBOSE[4557] logger.c: – <Zap/146-1> Playing ‘otherwise’ (language ‘en’)
[2010-03-03 17:16:18] VERBOSE[4557] logger.c: – <Zap/146-1> Playing ‘calls-taken-by’ (language ‘en’)
[2010-03-03 17:16:20] VERBOSE[4557] logger.c: – <Zap/146-1> Playing ‘reception’ (language ‘en’)
[2010-03-03 17:16:21] VERBOSE[4557] logger.c: – <Zap/146-1> Playing ‘personnel’ (language ‘en’)
[2010-03-03 17:16:22] VERBOSE[4557] logger.c: – Executing [s@custom-exten-1:4] Wait(“Zap/146-1”, “5”) in new stack
[2010-03-03 17:16:27] VERBOSE[4557] logger.c: – Executing [s@custom-exten-1:5] WaitExten(“Zap/146-1”, “5”) in new stack
[2010-03-03 17:16:33] VERBOSE[4557] logger.c: – Timeout on Zap/146-1, continuing…
[2010-03-03 17:16:33] VERBOSE[4557] logger.c: – Executing [s@custom-exten-1:6] Goto(“Zap/146-1”, “10|1”) in new stack
[2010-03-03 17:16:33] VERBOSE[4557] logger.c: – Goto (custom-exten-1,10,1)
[2010-03-03 17:16:33] VERBOSE[4557] logger.c: – Executing [10@custom-exten-1:1] Answer(“Zap/146-1”, “”) in new stack
[2010-03-03 17:16:33] VERBOSE[4557] logger.c: – Executing [10@custom-exten-1:2] Dial(“Zap/146-1”, “Zap/125|55”) in new stack
[2010-03-03 17:16:33] VERBOSE[4557] logger.c: – Called 125
[2010-03-03 17:16:33] VERBOSE[4557] logger.c: – Zap/125-1 is ringing
[2010-03-03 17:16:34] WARNING[4557] chan_zap.c: Unable to request echo training on channel 125
[2010-03-03 17:16:34] DEBUG[4557] chan_zap.c: channel 125 answered
[2010-03-03 17:16:34] VERBOSE[4557] logger.c: – Zap/125-1 answered Zap/146-1
[2010-03-03 17:16:34] DEBUG[4557] chan_zap.c: master: 146, slave: 125, nothingok: 0
[2010-03-03 17:16:34] DEBUG[4557] chan_zap.c: Stopping tones on 146/0 talking to 125/0
[2010-03-03 17:16:34] DEBUG[4557] chan_zap.c: Stopping tones on 125/0 talking to 146/0
[2010-03-03 17:16:34] DEBUG[4557] chan_zap.c: Making 125 slave to master 146 at 0
[2010-03-03 17:16:34] DEBUG[4557] chan_zap.c: Added 17 to conference 9/146
[2010-03-03 17:16:34] DEBUG[4557] chan_zap.c: Added 38 to conference 9/125
[2010-03-03 17:16:34] VERBOSE[4557] logger.c: – Native bridging Zap/146-1 and Zap/125-1
[2010-03-03 17:16:56] DEBUG[4557] chan_zap.c: Winkflash, index: 0, normal: 17, callwait: -1, thirdcall: -1
[2010-03-03 17:16:56] DEBUG[4557] chan_zap.c: Swapping 2 and 0
[2010-03-03 17:16:56] VERBOSE[4557] logger.c: – Started three way call on channel 125
[2010-03-03 17:16:56] DEBUG[4557] chan_zap.c: Something changed out on 146/0 to 125/0, returning -3 to restart
[2010-03-03 17:16:56] DEBUG[4557] chan_zap.c: Echo cancellation already on
[2010-03-03 17:16:56] DEBUG[4557] chan_zap.c: Unlinking slave 125 from 146
[2010-03-03 17:16:56] DEBUG[4557] chan_zap.c: Removed 17 from conference 9/146
[2010-03-03 17:16:56] DEBUG[4557] chan_zap.c: Removed 38 from conference 9/125
[2010-03-03 17:16:56] DEBUG[4557] chan_zap.c: master: 0, slave: 0, nothingok: 1
[2010-03-03 17:16:56] VERBOSE[4557] logger.c: – Native bridging Zap/146-1 and Zap/125-1
[2010-03-03 17:16:56] DEBUG[4557] chan_zap.c: Echo cancellation already on
[2010-03-03 17:16:56] DEBUG[4557] chan_zap.c: Echo cancellation already on
[2010-03-03 17:16:56] VERBOSE[4557] logger.c: – Started music on hold, class ‘default’, on Zap/146-1
[2010-03-03 17:16:56] DEBUG[4557] chan_zap.c: master: 0, slave: 0, nothingok: 1
[2010-03-03 17:16:56] VERBOSE[4557] logger.c: – Native bridging Zap/146-1 and Zap/125-1
[2010-03-03 17:16:56] VERBOSE[4559] logger.c: – Starting simple switch on ‘Zap/125-1’
[2010-03-03 17:16:56] DEBUG[4557] chan_zap.c: Sending hold on ‘Zap/125-1’
[2010-03-03 17:16:56] DEBUG[4557] chan_zap.c: Echo cancellation already on
[2010-03-03 17:16:56] DEBUG[4557] chan_zap.c: Echo cancellation already on
[2010-03-03 17:16:56] VERBOSE[4557] logger.c: – Stopped music on hold on Zap/146-1
[2010-03-03 17:16:56] VERBOSE[4557] logger.c: – Started music on hold, class ‘default’, on Zap/146-1
[2010-03-03 17:16:56] DEBUG[4557] chan_zap.c: master: 0, slave: 0, nothingok: 1
[2010-03-03 17:16:56] VERBOSE[4557] logger.c: – Native bridging Zap/146-1 and Zap/125-1
[2010-03-03 17:16:59] DEBUG[4559] chan_zap.c: Echo cancellation already on
[2010-03-03 17:16:59] VERBOSE[4559] logger.c: – Executing [19011@_operator_1:1] Answer(“Zap/125-1”, “”) in new stack
[2010-03-03 17:16:59] DEBUG[4559] chan_zap.c: Took Zap/125-1 off hook
[2010-03-03 17:16:59] VERBOSE[4559] logger.c: – Executing [19011@_operator_1:2] Dial(“Zap/125-1”, “Zap/127”) in new stack
[2010-03-03 17:16:59] VERBOSE[4559] logger.c: – Called 127
[2010-03-03 17:16:59] VERBOSE[4559] logger.c: – Zap/127-1 is ringing
[2010-03-03 17:17:01] WARNING[4559] chan_zap.c: Unable to request echo training on channel 127
[2010-03-03 17:17:01] DEBUG[4559] chan_zap.c: channel 127 answered
[2010-03-03 17:17:01] VERBOSE[4559] logger.c: – Zap/127-1 answered Zap/125-1
[2010-03-03 17:17:01] DEBUG[4559] chan_zap.c: master: 125, slave: 127, nothingok: 0
[2010-03-03 17:17:01] DEBUG[4559] chan_zap.c: Stopping tones on 125/0 talking to 127/0
[2010-03-03 17:17:01] DEBUG[4559] chan_zap.c: Stopping tones on 127/0 talking to 125/0
[2010-03-03 17:17:01] DEBUG[4559] chan_zap.c: Making 127 slave to master 125 at 0
[2010-03-03 17:17:01] DEBUG[4559] chan_zap.c: Added 19 to conference 9/125
[2010-03-03 17:17:01] DEBUG[4559] chan_zap.c: Added 17 to conference 9/127
[2010-03-03 17:17:01] VERBOSE[4559] logger.c: – Native bridging Zap/125-1 and Zap/127-1
[2010-03-03 17:17:07] DEBUG[4559] chan_zap.c: Last flash was 10661 ms ago
[2010-03-03 17:17:07] DEBUG[4559] chan_zap.c: Released sub 2 of channel 125
[2010-03-03 17:17:07] DEBUG[4559] chan_zap.c: Echo cancellation already on
[2010-03-03 17:17:07] DEBUG[4559] chan_zap.c: Unlinking slave 127 from 125
[2010-03-03 17:17:07] DEBUG[4559] chan_zap.c: Removed 19 from conference 9/125
[2010-03-03 17:17:07] DEBUG[4559] chan_zap.c: Removed 17 from conference 9/127
[2010-03-03 17:17:07] VERBOSE[4559] logger.c: == Spawn extension (_operator_1, 19011, 2) exited non-zero on ‘Zap/125-1’
[2010-03-03 17:17:07] WARNING[4559] cdr.c: CDR on channel ‘Zap/125-1’ has not started
[2010-03-03 17:17:07] DEBUG[4557] chan_zap.c: New owner for channel 125 is Zap/127-1
[2010-03-03 17:17:07] VERBOSE[4557] logger.c: – Hungup ‘Zap/127-1’
[2010-03-03 17:17:07] DEBUG[4557] chan_zap.c: New owner for channel 127 is Zap/127-1
[2010-03-03 17:17:07] DEBUG[4557] chan_zap.c: Something changed out on 146/0 to 125/2, returning -3 to restart
[2010-03-03 17:17:07] DEBUG[4557] chan_zap.c: Echo cancellation already on
[2010-03-03 17:17:07] DEBUG[4557] chan_zap.c: master: 146, slave: 127, nothingok: 0
[2010-03-03 17:17:07] DEBUG[4557] chan_zap.c: Stopping tones on 146/0 talking to 127/0
[2010-03-03 17:17:07] DEBUG[4557] chan_zap.c: Stopping tones on 127/0 talking to 146/0
[2010-03-03 17:17:07] DEBUG[4557] chan_zap.c: Making 127 slave to master 146 at 0
[2010-03-03 17:17:07] DEBUG[4557] chan_zap.c: Added 19 to conference 9/146
[2010-03-03 17:17:07] DEBUG[4557] chan_zap.c: Added 38 to conference 9/127
[2010-03-03 17:17:07] VERBOSE[4557] logger.c: – Native bridging Zap/146-1 and Zap/127-1
[2010-03-03 17:17:07] DEBUG[4557] chan_zap.c: Echo cancellation already on
[2010-03-03 17:17:07] DEBUG[4557] chan_zap.c: Echo cancellation already on
[2010-03-03 17:17:07] DEBUG[4557] chan_zap.c: Unlinking slave 127 from 146
[2010-03-03 17:17:07] DEBUG[4557] chan_zap.c: Removed 19 from conference 9/146
[2010-03-03 17:17:07] DEBUG[4557] chan_zap.c: Removed 38 from conference 9/127
[2010-03-03 17:17:07] VERBOSE[4557] logger.c: – Stopped music on hold on Zap/146-1
[2010-03-03 17:17:07] DEBUG[4557] chan_zap.c: master: 146, slave: 127, nothingok: 0
[2010-03-03 17:17:07] DEBUG[4557] chan_zap.c: Stopping tones on 146/0 talking to 127/0
[2010-03-03 17:17:07] DEBUG[4557] chan_zap.c: Stopping tones on 127/0 talking to 146/0
[2010-03-03 17:17:07] DEBUG[4557] chan_zap.c: Making 127 slave to master 146 at 0
[2010-03-03 17:17:07] DEBUG[4557] chan_zap.c: Added 19 to conference 9/146
[2010-03-03 17:17:07] DEBUG[4557] chan_zap.c: Added 38 to conference 9/127
[2010-03-03 17:17:07] VERBOSE[4557] logger.c: – Native bridging Zap/146-1 and Zap/127-1
[2010-03-03 17:17:07] VERBOSE[4559] logger.c: – Hungup ‘Zap/125-1’