Auto Call Hangup on special customer phones

[phil_discount]

Hello,

i've got a very strange behaivior!
if we are calling private persons over PRI or SIP which are using a fritz!box (internet router with voip) the calls hang up automatically after answer,
but not everytime. 80 percent of the calls to this special customers will work, the rest of the calls will hangup instant after answering the channel.
if i make a call directly from my SIP phone which is connected to vicidial it always works fine.
i tried turning off AMD, manual call .. no matter, call sometimes hangup. perhaps the customer have got a poor internet connection, i dont know.
if i'm logged into vicidial, i get the blub and during half a second the call disconnects.

we are dialing with an asterisk gateway (WAHLSERVER) which is using dahdi and sip providers.
the problem appears on both technologies. the asterisk gateway is connected through IAX2 to vicidial
because we've got no problems with calling, i think voip providers of the customers or their voip (fritz!box) routers arent working correctly.

what can i do?

regards
philip

11:59:53 Dialing
11:59:53 Ringing
12:00:22 Answer
12:00:22 Hangup

Code: Select all

[Sep 11 11:59:53] VERBOSE[12882] logger.c: [Sep 11 11:59:53]   == Parsing '/etc/asterisk/manager.conf': [Sep 11 11:59:53] DEBUG[12882] config.c: Parsing /etc/asterisk/manager.conf
[Sep 11 11:59:53] VERBOSE[12882] logger.c: [Sep 11 11:59:53] Found
[Sep 11 11:59:53] VERBOSE[12882] logger.c: [Sep 11 11:59:53]   == Manager 'sendcron' logged on from 127.0.0.1
[Sep 11 11:59:53] DEBUG[12882] manager.c: Manager received command 'Originate'
[Sep 11 11:59:53] DEBUG[12883] pbx.c: Launching 'AGI'
[Sep 11 11:59:53] VERBOSE[12883] logger.c: [Sep 11 11:59:53]     -- Executing [99999056xxxxxx@default:1] AGI("Local/99999056xxxxxx@default-d418,2", "agi://127.0.0.1:4577/call_log") in new stack
[Sep 11 11:59:53] VERBOSE[12883] logger.c: [Sep 11 11:59:53] AGI Tx >> agi_network: yes
[Sep 11 11:59:53] VERBOSE[12883] logger.c: [Sep 11 11:59:53] AGI Tx >> agi_network_script: call_log
[Sep 11 11:59:53] DEBUG[12883] res_agi.c: Wow, connected!
[Sep 11 11:59:53] VERBOSE[12883] logger.c: [Sep 11 11:59:53] AGI Tx >> agi_request: agi://127.0.0.1:4577/call_log
[Sep 11 11:59:53] VERBOSE[12883] logger.c: [Sep 11 11:59:53] AGI Tx >> agi_channel: Local/99999056xxxxxx@default-d418,2
[Sep 11 11:59:53] VERBOSE[12883] logger.c: [Sep 11 11:59:53] AGI Tx >> agi_language: en
[Sep 11 11:59:53] VERBOSE[12883] logger.c: [Sep 11 11:59:53] AGI Tx >> agi_type: Local
[Sep 11 11:59:53] VERBOSE[12883] logger.c: [Sep 11 11:59:53] AGI Tx >> agi_uniqueid: 1347357593.1207
[Sep 11 11:59:53] VERBOSE[12883] logger.c: [Sep 11 11:59:53] AGI Tx >> agi_callerid: 180599007202
[Sep 11 11:59:53] VERBOSE[12883] logger.c: [Sep 11 11:59:53] AGI Tx >> agi_calleridname: V0911115952007893596
[Sep 11 11:59:53] VERBOSE[12883] logger.c: [Sep 11 11:59:53] AGI Tx >> agi_callingpres: 0
[Sep 11 11:59:53] VERBOSE[12883] logger.c: [Sep 11 11:59:53] AGI Tx >> agi_callingani2: 0
[Sep 11 11:59:53] VERBOSE[12883] logger.c: [Sep 11 11:59:53] AGI Tx >> agi_callington: 0
[Sep 11 11:59:53] VERBOSE[12883] logger.c: [Sep 11 11:59:53] AGI Tx >> agi_callingtns: 0
[Sep 11 11:59:53] VERBOSE[12883] logger.c: [Sep 11 11:59:53] AGI Tx >> agi_dnid: unknown
[Sep 11 11:59:53] VERBOSE[12883] logger.c: [Sep 11 11:59:53] AGI Tx >> agi_rdnis: unknown
[Sep 11 11:59:53] VERBOSE[12883] logger.c: [Sep 11 11:59:53] AGI Tx >> agi_context: default
[Sep 11 11:59:53] VERBOSE[12883] logger.c: [Sep 11 11:59:53] AGI Tx >> agi_extension: 99999056xxxxxx
[Sep 11 11:59:53] VERBOSE[12883] logger.c: [Sep 11 11:59:53] AGI Tx >> agi_priority: 1
[Sep 11 11:59:53] VERBOSE[12883] logger.c: [Sep 11 11:59:53] AGI Tx >> agi_enhanced: 0.0
[Sep 11 11:59:53] VERBOSE[12883] logger.c: [Sep 11 11:59:53] AGI Tx >> agi_accountcode:
[Sep 11 11:59:53] VERBOSE[12883] logger.c: [Sep 11 11:59:53] AGI Tx >>
[Sep 11 11:59:53] VERBOSE[12883] logger.c: [Sep 11 11:59:53]     -- AGI Script agi://127.0.0.1:4577/call_log completed, returning 0
[Sep 11 11:59:53] DEBUG[12883] pbx.c: Launching 'Dial'
[Sep 11 11:59:53] VERBOSE[12883] logger.c: [Sep 11 11:59:53]     -- Executing [99999056xxxxxx@default:2] Dial("Local/99999056xxxxxx@default-d418,2", "IAX2/WAHLSERVER:test@192.168.203.33/99999056xxxxxx|60|tToR") in new stack
[Sep 11 11:59:53] DEBUG[12883] chan_iax2.c: ip callno count incremented to 6 for 192.168.203.33
[Sep 11 11:59:53] DEBUG[12883] rtp.c: Channel 'IAX2/192.168.203.33:4569-3521' has no RTP, not doing anything
[Sep 11 11:59:53] DEBUG[12883] channel.c: Not copying variable DIALEDTIME.
[Sep 11 11:59:53] DEBUG[12883] channel.c: Not copying variable ANSWEREDTIME.
[Sep 11 11:59:53] DEBUG[12883] channel.c: Not copying variable DIALEDPEERNAME.
[Sep 11 11:59:53] DEBUG[12883] channel.c: Not copying variable DIALEDPEERNUMBER.
[Sep 11 11:59:53] DEBUG[12883] channel.c: Not copying variable DIALSTATUS.
[Sep 11 11:59:53] DEBUG[12883] channel.c: Not copying variable AGISTATUS.
[Sep 11 11:59:53] DEBUG[12883] devicestate.c: Notification of state change to be queued on device/channel IAX2/192.168.203.33:4569
[Sep 11 11:59:53] DEBUG[2465] devicestate.c: No provider found, checking channel drivers for IAX2 - 192.168.203.33:4569
[Sep 11 11:59:53] DEBUG[2465] chan_iax2.c: Checking device state for device 192.168.203.33
[Sep 11 11:59:53] DEBUG[2465] devicestate.c: Changing state for IAX2/192.168.203.33:4569 - state 4 (Invalid)
[Sep 11 11:59:53] DEBUG[2531] app_queue.c: Device 'IAX2/192.168.203.33:4569' changed to state '4' (Invalid) but we don't care because they're not a member of any queue.
[Sep 11 11:59:53] VERBOSE[12883] logger.c: [Sep 11 11:59:53]     -- Called WAHLSERVER:test@192.168.203.33/99999056xxxxxx
[Sep 11 11:59:53] DEBUG[12883] channel.c: Set channel IAX2/192.168.203.33:4569-3521 to read format slin
[Sep 11 11:59:53] DEBUG[12883] channel.c: Set channel Local/99999056xxxxxx@default-d418,2 to read format gsm
[Sep 11 11:59:53] DEBUG[12883] channel.c: Set channel IAX2/192.168.203.33:4569-3521 to write format gsm
[Sep 11 11:59:53] VERBOSE[2496] logger.c: [Sep 11 11:59:53]     -- Call accepted by 192.168.203.33 (format ulaw)
[Sep 11 11:59:53] VERBOSE[2496] logger.c: [Sep 11 11:59:53]     -- Format for call is ulaw
[Sep 11 11:59:53] DEBUG[2496] channel.c: Set channel IAX2/192.168.203.33:4569-3521 to write format gsm
[Sep 11 11:59:53] DEBUG[2496] channel.c: Set channel IAX2/192.168.203.33:4569-3521 to read format slin
[Sep 11 11:59:53] DEBUG[2522] chan_iax2.c: ip callno count decremented to 6 for 192.168.203.34
[Sep 11 11:59:53] DEBUG[2564] manager.c: Manager received command 'Command'
[Sep 11 11:59:53] DEBUG[2564] manager.c: Manager received command 'Command'
[Sep 11 11:59:55] VERBOSE[12883] logger.c: [Sep 11 11:59:55]     -- IAX2/192.168.203.33:4569-3521 is ringing
[Sep 11 11:59:55] DEBUG[12883] rtp.c: Channel 'Local/99999056xxxxxx@default-d418,2' has no RTP, not doing anything

....

[Sep 11 12:00:22] DEBUG[2490] chan_iax2.c: Ooh, voice format changed to 4
[Sep 11 12:00:22] VERBOSE[12883] logger.c: [Sep 11 12:00:22]     -- IAX2/192.168.203.33:4569-3521 stopped sounds
[Sep 11 12:00:22] DEBUG[12883] devicestate.c: Notification of state change to be queued on device/channel IAX2/192.168.203.33:4569
[Sep 11 12:00:22] DEBUG[2465] devicestate.c: No provider found, checking channel drivers for IAX2 - 192.168.203.33:4569
[Sep 11 12:00:22] DEBUG[2465] chan_iax2.c: Checking device state for device 192.168.203.33
[Sep 11 12:00:22] DEBUG[2465] devicestate.c: Changing state for IAX2/192.168.203.33:4569 - state 4 (Invalid)
[Sep 11 12:00:22] VERBOSE[12883] logger.c: [Sep 11 12:00:22]     -- IAX2/192.168.203.33:4569-3521 answered Local/99999056xxxxxx@default-d418,2
[Sep 11 12:00:22] DEBUG[12883] devicestate.c: Notification of state change to be queued on device/channel Local/99999056xxxxxx@default
[Sep 11 12:00:22] DEBUG[12882] devicestate.c: Notification of state change to be queued on device/channel Local/99999056xxxxxx@default
[Sep 11 12:00:22] DEBUG[2531] app_queue.c: Device 'IAX2/192.168.203.33:4569' changed to state '4' (Invalid) but we don't care because they're not a member of any queue.
[Sep 11 12:00:22] VERBOSE[12882] logger.c: [Sep 11 12:00:22]        > Channel Local/99999056xxxxxx@default-d418,1 was answered.
[Sep 11 12:00:22] ERROR[12882] utils.c: write() returned error: Broken pipe
[Sep 11 12:00:22] DEBUG[13009] pbx.c: Launching 'Playback'
[Sep 11 12:00:22] DEBUG[12882] manager.c: Manager received command 'Logoff'
[Sep 11 12:00:22] ERROR[12882] utils.c: write() returned error: Broken pipe
[Sep 11 12:00:22] ERROR[12882] utils.c: write() returned error: Broken pipe
[Sep 11 12:00:22] DEBUG[2465] devicestate.c: No provider found, checking channel drivers for Local - 99999056xxxxxx@default
[Sep 11 12:00:22] DEBUG[2465] chan_local.c: Checking if extension 99999056xxxxxx@default exists (devicestate)
[Sep 11 12:00:22] DEBUG[2465] devicestate.c: Changing state for Local/99999056xxxxxx@default - state 2 (In use)
[Sep 11 12:00:22] DEBUG[2465] devicestate.c: No provider found, checking channel drivers for Local - 99999056xxxxxx@default
[Sep 11 12:00:22] DEBUG[2465] chan_local.c: Checking if extension 99999056xxxxxx@default exists (devicestate)
[Sep 11 12:00:22] DEBUG[2531] app_queue.c: Device 'Local/99999056xxxxxx@default' changed to state '2' (In use) but we don't care because they're not a member of any queue.
[Sep 11 12:00:22] VERBOSE[13009] logger.c: [Sep 11 12:00:22]     -- Executing [8368@default:1] Playback("Local/99999056xxxxxx@default-d418,1", "sip-silence") in new stack
[Sep 11 12:00:22] DEBUG[2465] devicestate.c: Changing state for Local/99999056xxxxxx@default - state 2 (In use)
[Sep 11 12:00:22] VERBOSE[12882] logger.c: [Sep 11 12:00:22]   == Manager 'sendcron' logged off from 127.0.0.1
[Sep 11 12:00:22] DEBUG[2531] app_queue.c: Device 'Local/99999056xxxxxx@default' changed to state '2' (In use) but we don't care because they're not a member of any queue.
[Sep 11 12:00:22] DEBUG[13009] channel.c: Set channel Local/99999056xxxxxx@default-d418,1 to write format gsm
[Sep 11 12:00:22] DEBUG[13009] channel.c: Scheduling timer at 160 sample intervals
[Sep 11 12:00:22] VERBOSE[13009] logger.c: [Sep 11 12:00:22]     -- <Local/99999056xxxxxx@default-d418,1> Playing 'sip-silence' (language 'en')
[Sep 11 12:00:22] WARNING[13009] file.c: Unexpected control subclass '-1'
[Sep 11 12:00:22] DEBUG[12883] channel.c: Got a FRAME_CONTROL (-1) frame on channel IAX2/192.168.203.33:4569-3521
[Sep 11 12:00:22] DEBUG[12883] channel.c: Bridge stops bridging channels Local/99999056xxxxxx@default-d418,2 and IAX2/192.168.203.33:4569-3521
[Sep 11 12:00:22] WARNING[13009] file.c: Unexpected control subclass '-1'
[Sep 11 12:00:22] DEBUG[12883] channel.c: Planning to masquerade channel IAX2/192.168.203.33:4569-3521 into the structure of Local/99999056xxxxxx@default-d418,1
[Sep 11 12:00:22] DEBUG[12883] channel.c: Done planning to masquerade channel IAX2/192.168.203.33:4569-3521 into the structure of Local/99999056xxxxxx@default-d418,1
[Sep 11 12:00:22] DEBUG[12883] chan_local.c: Not posting to queue since already masked on 'Local/99999056xxxxxx@default-d418,2'
[Sep 11 12:00:22] DEBUG[13009] channel.c: Actually Masquerading IAX2/192.168.203.33:4569-3521(6) into the structure of Local/99999056xxxxxx@default-d418,1(6)
[Sep 11 12:00:22] DEBUG[13009] channel.c: Got clone lock for masquerade on 'IAX2/192.168.203.33:4569-3521' at 0x84e1e08
[Sep 11 12:00:22] DEBUG[12883] channel.c: Didn't get a frame from channel: Local/99999056xxxxxx@default-d418,2
[Sep 11 12:00:22] DEBUG[13009] channel.c: Set channel IAX2/192.168.203.33:4569-3521 to write format gsm
[Sep 11 12:00:22] DEBUG[13009] channel.c: Set channel IAX2/192.168.203.33:4569-3521 to read format slin
[Sep 11 12:00:22] DEBUG[13009] channel.c: Putting channel IAX2/192.168.203.33:4569-3521 in 2/64 formats
[Sep 11 12:00:22] DEBUG[13009] channel.c: Released clone lock on 'Local/99999056xxxxxx@default-d418,1<ZOMBIE>'
[Sep 11 12:00:22] DEBUG[13009] channel.c: Done Masquerading IAX2/192.168.203.33:4569-3521 (6)
[Sep 11 12:00:22] DEBUG[12883] channel.c: Bridge stops bridging channels Local/99999056xxxxxx@default-d418,2 and Local/99999056xxxxxx@default-d418,1<ZOMBIE>
[Sep 11 12:00:22] DEBUG[12883] pbx.c: Launching 'DeadAGI'
[Sep 11 12:00:22] VERBOSE[12883] logger.c: [Sep 11 12:00:22]     -- Executing [h@default:1] DeadAGI("Local/99999056xxxxxx@default-d418,2", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16-----ANSWER-----29-----0") in new stack
[Sep 11 12:00:22] VERBOSE[12883] logger.c: [Sep 11 12:00:22] AGI Tx >> agi_network: yes
[Sep 11 12:00:22] VERBOSE[12883] logger.c: [Sep 11 12:00:22] AGI Tx >> agi_network_script: call_log--HVcauses--PRI-----NODEBUG-----16-----ANSWER-----29-----0
[Sep 11 12:00:22] DEBUG[12883] res_agi.c: Wow, connected!
[Sep 11 12:00:22] VERBOSE[12883] logger.c: [Sep 11 12:00:22] AGI Tx >> agi_request: agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16-----ANSWER-----29-----0
[Sep 11 12:00:22] VERBOSE[12883] logger.c: [Sep 11 12:00:22] AGI Tx >> agi_channel: Local/99999056xxxxxx@default-d418,2
[Sep 11 12:00:22] VERBOSE[12883] logger.c: [Sep 11 12:00:22] AGI Tx >> agi_language: en
[Sep 11 12:00:22] VERBOSE[12883] logger.c: [Sep 11 12:00:22] AGI Tx >> agi_type: Local
[Sep 11 12:00:22] VERBOSE[12883] logger.c: [Sep 11 12:00:22] AGI Tx >> agi_uniqueid: 1347357593.1207
[Sep 11 12:00:22] VERBOSE[12883] logger.c: [Sep 11 12:00:22] AGI Tx >> agi_callerid: 180599007202
[Sep 11 12:00:22] VERBOSE[12883] logger.c: [Sep 11 12:00:22] AGI Tx >> agi_calleridname: V0911115952007893596
[Sep 11 12:00:22] VERBOSE[12883] logger.c: [Sep 11 12:00:22] AGI Tx >> agi_callingpres: 0
[Sep 11 12:00:22] VERBOSE[12883] logger.c: [Sep 11 12:00:22] AGI Tx >> agi_callingani2: 0
[Sep 11 12:00:22] VERBOSE[12883] logger.c: [Sep 11 12:00:22] AGI Tx >> agi_callington: 0
[Sep 11 12:00:22] VERBOSE[12883] logger.c: [Sep 11 12:00:22] AGI Tx >> agi_callingtns: 0
[Sep 11 12:00:22] VERBOSE[12883] logger.c: [Sep 11 12:00:22] AGI Tx >> agi_dnid: unknown
[Sep 11 12:00:22] VERBOSE[12883] logger.c: [Sep 11 12:00:22] AGI Tx >> agi_rdnis: unknown
[Sep 11 12:00:22] VERBOSE[12883] logger.c: [Sep 11 12:00:22] AGI Tx >> agi_context: default
[Sep 11 12:00:22] VERBOSE[12883] logger.c: [Sep 11 12:00:22] AGI Tx >> agi_extension: h
[Sep 11 12:00:22] VERBOSE[12883] logger.c: [Sep 11 12:00:22] AGI Tx >> agi_priority: 1
[Sep 11 12:00:22] VERBOSE[12883] logger.c: [Sep 11 12:00:22] AGI Tx >> agi_enhanced: 0.0
[Sep 11 12:00:22] VERBOSE[12883] logger.c: [Sep 11 12:00:22] AGI Tx >> agi_accountcode:
[Sep 11 12:00:22] VERBOSE[12883] logger.c: [Sep 11 12:00:22] AGI Tx >>
[Sep 11 12:00:22] VERBOSE[12883] logger.c: [Sep 11 12:00:22]     -- AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16-----ANSWER-----29-----0 completed, returning 0
[Sep 11 12:00:22] DEBUG[12883] channel.c: Hanging up zombie 'Local/99999056xxxxxx@default-d418,1<ZOMBIE>'
[Sep 11 12:00:22] DEBUG[12883] devicestate.c: Notification of state change to be queued on device/channel Local/99999056xxxxxx@default
[Sep 11 12:00:22] DEBUG[12883] rtp.c: Channel 'Local/99999056xxxxxx@default-d418,2' has no RTP, not doing anything
[Sep 11 12:00:22] DEBUG[2465] devicestate.c: No provider found, checking channel drivers for Local - 99999056xxxxxx@default
[Sep 11 12:00:22] DEBUG[2465] chan_local.c: Checking if extension 99999056xxxxxx@default exists (devicestate)
[Sep 11 12:00:22] DEBUG[12883] app_dial.c: Exiting with DIALSTATUS=ANSWER.
[Sep 11 12:00:22] DEBUG[2465] devicestate.c: Changing state for Local/99999056xxxxxx@default - state 2 (In use)
[Sep 11 12:00:22] DEBUG[12883] pbx.c: Spawn extension (default,99999056xxxxxx,2) exited non-zero on 'Local/99999056xxxxxx@default-d418,2'
[Sep 11 12:00:22] VERBOSE[12883] logger.c: [Sep 11 12:00:22]   == Spawn extension (default, 99999056xxxxxx, 2) exited non-zero on 'Local/99999056xxxxxx@default-d418,2'
[Sep 11 12:00:22] DEBUG[12883] channel.c: Soft-Hanging up channel 'Local/99999056xxxxxx@default-d418,2'
[Sep 11 12:00:22] DEBUG[12883] channel.c: Hanging up channel 'Local/99999056xxxxxx@default-d418,2'
[Sep 11 12:00:22] DEBUG[2531] app_queue.c: Device 'Local/99999056xxxxxx@default' changed to state '2' (In use) but we don't care because they're not a member of any queue.
[Sep 11 12:00:22] DEBUG[12883] devicestate.c: Notification of state change to be queued on device/channel Local/99999056xxxxxx@default
[Sep 11 12:00:22] DEBUG[2465] devicestate.c: No provider found, checking channel drivers for Local - 99999056xxxxxx@default
[Sep 11 12:00:22] DEBUG[2465] chan_local.c: Checking if extension 99999056xxxxxx@default exists (devicestate)
[Sep 11 12:00:22] DEBUG[2465] devicestate.c: Changing state for Local/99999056xxxxxx@default - state 1 (Not in use)
[Sep 11 12:00:22] DEBUG[2531] app_queue.c: Device 'Local/99999056xxxxxx@default' changed to state '1' (Not in use) but we don't care because they're not a member of any queue.
[Sep 11 12:00:22] DEBUG[13009] channel.c: Scheduling timer at 0 sample intervals
[Sep 11 12:00:22] DEBUG[13009] channel.c: Scheduling timer at 0 sample intervals
[Sep 11 12:00:22] DEBUG[13009] channel.c: Scheduling timer at 0 sample intervals
[Sep 11 12:00:22] DEBUG[13009] channel.c: Set channel IAX2/192.168.203.33:4569-3521 to write format slin
[Sep 11 12:00:22] DEBUG[13009] pbx.c: Launching 'AGI'
[Sep 11 12:00:22] VERBOSE[13009] logger.c: [Sep 11 12:00:22]     -- Executing [8368@default:2] AGI("IAX2/192.168.203.33:4569-3521", "agi://127.0.0.1:4577/call_log") in new stack
[Sep 11 12:00:22] VERBOSE[13009] logger.c: [Sep 11 12:00:22] AGI Tx >> agi_network: yes
[Sep 11 12:00:22] VERBOSE[13009] logger.c: [Sep 11 12:00:22] AGI Tx >> agi_network_script: call_log
[Sep 11 12:00:22] DEBUG[13009] res_agi.c: Wow, connected!
[Sep 11 12:00:22] VERBOSE[13009] logger.c: [Sep 11 12:00:22] AGI Tx >> agi_request: agi://127.0.0.1:4577/call_log
[Sep 11 12:00:22] VERBOSE[13009] logger.c: [Sep 11 12:00:22] AGI Tx >> agi_channel: IAX2/192.168.203.33:4569-3521
[Sep 11 12:00:22] VERBOSE[13009] logger.c: [Sep 11 12:00:22] AGI Tx >> agi_language: en
[Sep 11 12:00:22] VERBOSE[13009] logger.c: [Sep 11 12:00:22] AGI Tx >> agi_type: IAX2
[Sep 11 12:00:22] VERBOSE[13009] logger.c: [Sep 11 12:00:22] AGI Tx >> agi_uniqueid: 1347357593.1206
[Sep 11 12:00:22] VERBOSE[13009] logger.c: [Sep 11 12:00:22] AGI Tx >> agi_callerid: 180599007202
[Sep 11 12:00:22] VERBOSE[13009] logger.c: [Sep 11 12:00:22] AGI Tx >> agi_calleridname: V0911115952007893596
[Sep 11 12:00:22] VERBOSE[13009] logger.c: [Sep 11 12:00:22] AGI Tx >> agi_callingpres: 0
[Sep 11 12:00:22] VERBOSE[13009] logger.c: [Sep 11 12:00:22] AGI Tx >> agi_callingani2: 0
[Sep 11 12:00:22] VERBOSE[13009] logger.c: [Sep 11 12:00:22] AGI Tx >> agi_callington: 0
[Sep 11 12:00:22] VERBOSE[13009] logger.c: [Sep 11 12:00:22] AGI Tx >> agi_callingtns: 0
[Sep 11 12:00:22] VERBOSE[13009] logger.c: [Sep 11 12:00:22] AGI Tx >> agi_dnid: unknown
[Sep 11 12:00:22] VERBOSE[13009] logger.c: [Sep 11 12:00:22] AGI Tx >> agi_rdnis: unknown
[Sep 11 12:00:22] VERBOSE[13009] logger.c: [Sep 11 12:00:22] AGI Tx >> agi_context: default
[Sep 11 12:00:22] VERBOSE[13009] logger.c: [Sep 11 12:00:22] AGI Tx >> agi_extension: 8368
[Sep 11 12:00:22] VERBOSE[13009] logger.c: [Sep 11 12:00:22] AGI Tx >> agi_priority: 2
[Sep 11 12:00:22] VERBOSE[13009] logger.c: [Sep 11 12:00:22] AGI Tx >> agi_enhanced: 0.0
[Sep 11 12:00:22] VERBOSE[13009] logger.c: [Sep 11 12:00:22] AGI Tx >> agi_accountcode:
[Sep 11 12:00:22] VERBOSE[13009] logger.c: [Sep 11 12:00:22] AGI Tx >>
[Sep 11 12:00:22] VERBOSE[13009] logger.c: [Sep 11 12:00:22]     -- AGI Script agi://127.0.0.1:4577/call_log completed, returning 0
[Sep 11 12:00:22] DEBUG[13009] pbx.c: Launching 'AGI'
[Sep 11 12:00:22] VERBOSE[13009] logger.c: [Sep 11 12:00:22]     -- Executing [8368@default:3] AGI("IAX2/192.168.203.33:4569-3521", "agi-VDAD_ALL_outbound.agi|NORMAL-----LB") in new stack
[Sep 11 12:00:22] VERBOSE[13009] logger.c: [Sep 11 12:00:22]     -- Launched AGI Script /var/lib/asterisk/agi-bin/agi-VDAD_ALL_outbound.agi
[Sep 11 12:00:22] VERBOSE[13009] logger.c: [Sep 11 12:00:22] AGI Tx >> agi_request: agi-VDAD_ALL_outbound.agi
[Sep 11 12:00:22] VERBOSE[13009] logger.c: [Sep 11 12:00:22] AGI Tx >> agi_channel: IAX2/192.168.203.33:4569-3521
[Sep 11 12:00:22] VERBOSE[13009] logger.c: [Sep 11 12:00:22] AGI Tx >> agi_language: en
[Sep 11 12:00:22] VERBOSE[13009] logger.c: [Sep 11 12:00:22] AGI Tx >> agi_type: IAX2
[Sep 11 12:00:22] VERBOSE[13009] logger.c: [Sep 11 12:00:22] AGI Tx >> agi_uniqueid: 1347357593.1206
[Sep 11 12:00:22] VERBOSE[13009] logger.c: [Sep 11 12:00:22] AGI Tx >> agi_callerid: 180599007202
[Sep 11 12:00:22] VERBOSE[13009] logger.c: [Sep 11 12:00:22] AGI Tx >> agi_calleridname: V0911115952007893596
[Sep 11 12:00:22] VERBOSE[13009] logger.c: [Sep 11 12:00:22] AGI Tx >> agi_callingpres: 0
[Sep 11 12:00:22] VERBOSE[13009] logger.c: [Sep 11 12:00:22] AGI Tx >> agi_callingani2: 0
[Sep 11 12:00:22] VERBOSE[13009] logger.c: [Sep 11 12:00:22] AGI Tx >> agi_callington: 0
[Sep 11 12:00:22] VERBOSE[13009] logger.c: [Sep 11 12:00:22] AGI Tx >> agi_callingtns: 0
[Sep 11 12:00:22] VERBOSE[13009] logger.c: [Sep 11 12:00:22] AGI Tx >> agi_dnid: unknown
[Sep 11 12:00:22] VERBOSE[13009] logger.c: [Sep 11 12:00:22] AGI Tx >> agi_rdnis: unknown
[Sep 11 12:00:22] VERBOSE[13009] logger.c: [Sep 11 12:00:22] AGI Tx >> agi_context: default
[Sep 11 12:00:22] VERBOSE[13009] logger.c: [Sep 11 12:00:22] AGI Tx >> agi_extension: 8368
[Sep 11 12:00:22] VERBOSE[13009] logger.c: [Sep 11 12:00:22] AGI Tx >> agi_priority: 3
[Sep 11 12:00:22] VERBOSE[13009] logger.c: [Sep 11 12:00:22] AGI Tx >> agi_enhanced: 0.0
[Sep 11 12:00:22] VERBOSE[13009] logger.c: [Sep 11 12:00:22] AGI Tx >> agi_accountcode:
[Sep 11 12:00:22] VERBOSE[13009] logger.c: [Sep 11 12:00:22] AGI Tx >>
[Sep 11 12:00:22] VERBOSE[13009] logger.c: [Sep 11 12:00:22] AGI Rx << SET CALLERID V0911115952007893596
[Sep 11 12:00:22] VERBOSE[13009] logger.c: [Sep 11 12:00:22] AGI Tx >> 200 result=1
[Sep 11 12:00:22] VERBOSE[13009] logger.c: [Sep 11 12:00:22] AGI Rx << CHANNEL STATUS IAX2/192.168.203.33:4569-3521
[Sep 11 12:00:22] VERBOSE[13009] logger.c: [Sep 11 12:00:22] AGI Tx >> 200 result=6
[Sep 11 12:00:22] VERBOSE[13009] logger.c: [Sep 11 12:00:22] AGI Rx << SET CONTEXT default
[Sep 11 12:00:22] VERBOSE[13009] logger.c: [Sep 11 12:00:22] AGI Tx >> 200 result=0
[Sep 11 12:00:22] VERBOSE[13009] logger.c: [Sep 11 12:00:22] AGI Rx << SET EXTENSION 192*168*203*040*8600503
[Sep 11 12:00:22] VERBOSE[13009] logger.c: [Sep 11 12:00:22] AGI Tx >> 200 result=0
[Sep 11 12:00:22] VERBOSE[13009] logger.c: [Sep 11 12:00:22] AGI Rx << SET PRIORITY 1
[Sep 11 12:00:22] VERBOSE[13009] logger.c: [Sep 11 12:00:22] AGI Tx >> 200 result=0
[Sep 11 12:00:22] VERBOSE[13009] logger.c: [Sep 11 12:00:22]     -- AGI Script agi-VDAD_ALL_outbound.agi completed, returning 0
[Sep 11 12:00:22] DEBUG[13009] pbx.c: Launching 'Goto'
[Sep 11 12:00:22] VERBOSE[13009] logger.c: [Sep 11 12:00:22]     -- Executing [192*168*203*040*8600503@default:1] Goto("IAX2/192.168.203.33:4569-3521", "default|8600503|1") in new stack
[Sep 11 12:00:22] VERBOSE[13009] logger.c: [Sep 11 12:00:22]     -- Goto (default,8600503,1)
[Sep 11 12:00:22] DEBUG[13009] pbx.c: Launching 'MeetMe'
[Sep 11 12:00:22] VERBOSE[13009] logger.c: [Sep 11 12:00:22]     -- Executing [8600503@default:1] MeetMe("IAX2/192.168.203.33:4569-3521", "8600503|F") in new stack
[Sep 11 12:00:22] DEBUG[13009] app_meetme.c: Placed channel IAX2/192.168.203.33:4569-3521 in DAHDI conf 1023
[Sep 11 12:00:22] DEBUG[13009] app_meetme.c: Got unrecognized frame on channel IAX2/192.168.203.33:4569-3521, f->frametype=4,f->subclass=20
[Sep 11 12:00:22] DEBUG[13009] app_meetme.c: Got unrecognized frame on channel IAX2/192.168.203.33:4569-3521, f->frametype=4,f->subclass=20
[Sep 11 12:00:22] DEBUG[2564] manager.c: Manager received command 'Command'
[Sep 11 12:00:22] DEBUG[2513] chan_iax2.c: schedule decrement of callno used for 192.168.203.42 in 60 seconds
[Sep 11 12:00:22] DEBUG[2564] manager.c: Manager received command 'Command'
[Sep 11 12:00:22] DEBUG[2493] chan_iax2.c: Immediately destroying 3521, having received hangup
[Sep 11 12:00:22] DEBUG[13009] pbx.c: Spawn extension (default,8600503,1) exited non-zero on 'IAX2/192.168.203.33:4569-3521'
[Sep 11 12:00:22] VERBOSE[13009] logger.c: [Sep 11 12:00:22]   == Spawn extension (default, 8600503, 1) exited non-zero on 'IAX2/192.168.203.33:4569-3521'
[Sep 11 12:00:22] DEBUG[13009] channel.c: Soft-Hanging up channel 'IAX2/192.168.203.33:4569-3521'
[Sep 11 12:00:22] DEBUG[13009] pbx.c: Launching 'DeadAGI'
[Sep 11 12:00:22] VERBOSE[13009] logger.c: [Sep 11 12:00:22]     -- Executing [h@default:1] DeadAGI("IAX2/192.168.203.33:4569-3521", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16---------------") in new stack
[Sep 11 12:00:22] VERBOSE[13009] logger.c: [Sep 11 12:00:22] AGI Tx >> agi_network: yes
[Sep 11 12:00:22] VERBOSE[13009] logger.c: [Sep 11 12:00:22] AGI Tx >> agi_network_script: call_log--HVcauses--PRI-----NODEBUG-----16---------------
[Sep 11 12:00:22] DEBUG[13009] res_agi.c: Wow, connected!
[Sep 11 12:00:22] VERBOSE[13009] logger.c: [Sep 11 12:00:22] AGI Tx >> agi_request: agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16---------------
[Sep 11 12:00:22] VERBOSE[13009] logger.c: [Sep 11 12:00:22] AGI Tx >> agi_channel: IAX2/192.168.203.33:4569-3521
[Sep 11 12:00:22] VERBOSE[13009] logger.c: [Sep 11 12:00:22] AGI Tx >> agi_language: en
[Sep 11 12:00:22] VERBOSE[13009] logger.c: [Sep 11 12:00:22] AGI Tx >> agi_type: IAX2
[Sep 11 12:00:22] VERBOSE[13009] logger.c: [Sep 11 12:00:22] AGI Tx >> agi_uniqueid: 1347357593.1206
[Sep 11 12:00:22] VERBOSE[13009] logger.c: [Sep 11 12:00:22] AGI Tx >> agi_callerid: unknown
[Sep 11 12:00:22] VERBOSE[13009] logger.c: [Sep 11 12:00:22] AGI Tx >> agi_calleridname: V0911115952007893596
[Sep 11 12:00:22] VERBOSE[13009] logger.c: [Sep 11 12:00:22] AGI Tx >> agi_callingpres: 0
[Sep 11 12:00:22] VERBOSE[13009] logger.c: [Sep 11 12:00:22] AGI Tx >> agi_callingani2: 0
[Sep 11 12:00:22] VERBOSE[13009] logger.c: [Sep 11 12:00:22] AGI Tx >> agi_callington: 0
[Sep 11 12:00:22] VERBOSE[13009] logger.c: [Sep 11 12:00:22] AGI Tx >> agi_callingtns: 0
[Sep 11 12:00:22] VERBOSE[13009] logger.c: [Sep 11 12:00:22] AGI Tx >> agi_dnid: unknown
[Sep 11 12:00:22] VERBOSE[13009] logger.c: [Sep 11 12:00:22] AGI Tx >> agi_rdnis: unknown
[Sep 11 12:00:22] VERBOSE[13009] logger.c: [Sep 11 12:00:22] AGI Tx >> agi_context: default
[Sep 11 12:00:22] VERBOSE[13009] logger.c: [Sep 11 12:00:22] AGI Tx >> agi_extension: h
[Sep 11 12:00:22] VERBOSE[13009] logger.c: [Sep 11 12:00:22] AGI Tx >> agi_priority: 1
[Sep 11 12:00:22] VERBOSE[13009] logger.c: [Sep 11 12:00:22] AGI Tx >> agi_enhanced: 0.0
[Sep 11 12:00:22] VERBOSE[13009] logger.c: [Sep 11 12:00:22] AGI Tx >> agi_accountcode:
[Sep 11 12:00:22] VERBOSE[13009] logger.c: [Sep 11 12:00:22] AGI Tx >>
[Sep 11 12:00:22] VERBOSE[13009] logger.c: [Sep 11 12:00:22]     -- AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16--------------- completed, returning 0
[Sep 11 12:00:22] DEBUG[13009] channel.c: Hanging up channel 'IAX2/192.168.203.33:4569-3521'
[Sep 11 12:00:22] DEBUG[13009] chan_iax2.c: We're hanging up IAX2/192.168.203.33:4569-3521 now...
[Sep 11 12:00:22] DEBUG[13009] chan_iax2.c: Really destroying IAX2/192.168.203.33:4569-3521 now...
[Sep 11 12:00:22] DEBUG[13009] chan_iax2.c: schedule decrement of callno used for 192.168.203.33 in 60 seconds
[Sep 11 12:00:22] VERBOSE[13009] logger.c: [Sep 11 12:00:22]     -- Hungup 'IAX2/192.168.203.33:4569-3521'
[Sep 11 12:00:22] DEBUG[13009] devicestate.c: Notification of state change to be queued on device/channel IAX2/192.168.203.33:4569
[Sep 11 12:00:22] DEBUG[2465] devicestate.c: No provider found, checking channel drivers for IAX2 - 192.168.203.33:4569
[Sep 11 12:00:22] DEBUG[2465] chan_iax2.c: Checking device state for device 192.168.203.33
[Sep 11 12:00:22] DEBUG[2465] devicestate.c: Changing state for IAX2/192.168.203.33:4569 - state 4 (Invalid)
[Sep 11 12:00:22] DEBUG[2531] app_queue.c: Device 'IAX2/192.168.203.33:4569' changed to state '4' (Invalid) but we don't care because they're not a member of any queue.
[Sep 11 12:00:22] DEBUG[2522] chan_iax2.c: ip callno count decremented to 8 for 192.168.203.34
[Sep 11 12:00:23] DEBUG[2564] manager.c: Manager received command 'Command'
[Sep 11 12:00:23] DEBUG[2564] manager.c: Manager received command 'Command'
[Sep 11 12:00:24] DEBUG[2564] manager.c: Manager received command 'Command'
[Sep 11 12:00:24] DEBUG[2564] manager.c: Manager received command 'Command'


or a little bit shorter with less debug from a second call

Code: Select all

[Sep 11 12:01:34] VERBOSE[13130] logger.c: [Sep 11 12:01:34]     -- Executing [99999056xxxxxx@default:1] AGI("Local/99999056xxxxxx@default-248d,2", "agi://127.0.0.1:4577/call_log") in new stack
[Sep 11 12:01:34] VERBOSE[13130] logger.c: [Sep 11 12:01:34] AGI Tx >> agi_network: yes
[Sep 11 12:01:34] VERBOSE[13130] logger.c: [Sep 11 12:01:34] AGI Tx >> agi_network_script: call_log
[Sep 11 12:01:34] VERBOSE[13130] logger.c: [Sep 11 12:01:34] AGI Tx >> agi_request: agi://127.0.0.1:4577/call_log
[Sep 11 12:01:34] VERBOSE[13130] logger.c: [Sep 11 12:01:34] AGI Tx >> agi_channel: Local/99999056xxxxxx@default-248d,2
[Sep 11 12:01:34] VERBOSE[13130] logger.c: [Sep 11 12:01:34] AGI Tx >> agi_language: en
[Sep 11 12:01:34] VERBOSE[13130] logger.c: [Sep 11 12:01:34] AGI Tx >> agi_type: Local
[Sep 11 12:01:34] VERBOSE[13130] logger.c: [Sep 11 12:01:34] AGI Tx >> agi_uniqueid: 1347357694.1210
[Sep 11 12:01:34] VERBOSE[13130] logger.c: [Sep 11 12:01:34] AGI Tx >> agi_callerid: 180599007202
[Sep 11 12:01:34] VERBOSE[13130] logger.c: [Sep 11 12:01:34] AGI Tx >> agi_calleridname: V0911120133007893595
[Sep 11 12:01:34] VERBOSE[13130] logger.c: [Sep 11 12:01:34] AGI Tx >> agi_callingpres: 0
[Sep 11 12:01:34] VERBOSE[13130] logger.c: [Sep 11 12:01:34] AGI Tx >> agi_callingani2: 0
[Sep 11 12:01:34] VERBOSE[13130] logger.c: [Sep 11 12:01:34] AGI Tx >> agi_callington: 0
[Sep 11 12:01:34] VERBOSE[13130] logger.c: [Sep 11 12:01:34] AGI Tx >> agi_callingtns: 0
[Sep 11 12:01:34] VERBOSE[13130] logger.c: [Sep 11 12:01:34] AGI Tx >> agi_dnid: unknown
[Sep 11 12:01:34] VERBOSE[13130] logger.c: [Sep 11 12:01:34] AGI Tx >> agi_rdnis: unknown
[Sep 11 12:01:34] VERBOSE[13130] logger.c: [Sep 11 12:01:34] AGI Tx >> agi_context: default
[Sep 11 12:01:34] VERBOSE[13130] logger.c: [Sep 11 12:01:34] AGI Tx >> agi_extension: 99999056xxxxxx
[Sep 11 12:01:34] VERBOSE[13130] logger.c: [Sep 11 12:01:34] AGI Tx >> agi_priority: 1
[Sep 11 12:01:34] VERBOSE[13130] logger.c: [Sep 11 12:01:34] AGI Tx >> agi_enhanced: 0.0
[Sep 11 12:01:34] VERBOSE[13130] logger.c: [Sep 11 12:01:34] AGI Tx >> agi_accountcode:
[Sep 11 12:01:34] VERBOSE[13130] logger.c: [Sep 11 12:01:34] AGI Tx >>
[Sep 11 12:01:34] VERBOSE[13130] logger.c: [Sep 11 12:01:34]     -- AGI Script agi://127.0.0.1:4577/call_log completed, returning 0
[Sep 11 12:01:34] VERBOSE[13130] logger.c: [Sep 11 12:01:34]     -- Executing [99999056xxxxxx@default:2] Dial("Local/99999056xxxxxx@default-248d,2", "IAX2/WAHLSERVER:test@192.168.203.33/99999056xxxxxx|60|tToR") in new stack
[Sep 11 12:01:34] VERBOSE[13130] logger.c: [Sep 11 12:01:34]     -- Called WAHLSERVER:test@192.168.203.33/99999056xxxxxx
[Sep 11 12:01:34] VERBOSE[2515] logger.c: [Sep 11 12:01:34]     -- Call accepted by 192.168.203.33 (format ulaw)
[Sep 11 12:01:34] VERBOSE[2515] logger.c: [Sep 11 12:01:34]     -- Format for call is ulaw
[Sep 11 12:01:36] VERBOSE[13130] logger.c: [Sep 11 12:01:36]     -- IAX2/192.168.203.33:4569-11627 is ringing
[Sep 11 12:02:03] VERBOSE[13130] logger.c: [Sep 11 12:02:03]     -- IAX2/192.168.203.33:4569-11627 stopped sounds
[Sep 11 12:02:03] VERBOSE[13130] logger.c: [Sep 11 12:02:03]     -- IAX2/192.168.203.33:4569-11627 answered Local/99999056xxxxxx@default-248d,2
[Sep 11 12:02:03] VERBOSE[13129] logger.c: [Sep 11 12:02:03]        > Channel Local/99999056xxxxxx@default-248d,1 was answered.
[Sep 11 12:02:03] VERBOSE[13129] logger.c: [Sep 11 12:02:03]   == Manager 'sendcron' logged off from 127.0.0.1
[Sep 11 12:02:03] VERBOSE[13187] logger.c: [Sep 11 12:02:03]     -- Executing [8368@default:1] Playback("Local/99999056xxxxxx@default-248d,1", "sip-silence") in new stack
[Sep 11 12:02:03] VERBOSE[13187] logger.c: [Sep 11 12:02:03]     -- <Local/99999056xxxxxx@default-248d,1> Playing 'sip-silence' (language 'en')
[Sep 11 12:02:03] VERBOSE[13130] logger.c: [Sep 11 12:02:03]     -- Executing [h@default:1] DeadAGI("Local/99999056xxxxxx@default-248d,2", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16-----ANSWER-----29-----0") in new stack
[Sep 11 12:02:03] VERBOSE[13130] logger.c: [Sep 11 12:02:03] AGI Tx >> agi_network: yes
[Sep 11 12:02:03] VERBOSE[13130] logger.c: [Sep 11 12:02:03] AGI Tx >> agi_network_script: call_log--HVcauses--PRI-----NODEBUG-----16-----ANSWER-----29-----0
[Sep 11 12:02:03] VERBOSE[13130] logger.c: [Sep 11 12:02:03] AGI Tx >> agi_request: agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16-----ANSWER-----29-----0
[Sep 11 12:02:03] VERBOSE[13130] logger.c: [Sep 11 12:02:03] AGI Tx >> agi_channel: Local/99999056xxxxxx@default-248d,2
[Sep 11 12:02:03] VERBOSE[13130] logger.c: [Sep 11 12:02:03] AGI Tx >> agi_language: en
[Sep 11 12:02:03] VERBOSE[13130] logger.c: [Sep 11 12:02:03] AGI Tx >> agi_type: Local
[Sep 11 12:02:03] VERBOSE[13130] logger.c: [Sep 11 12:02:03] AGI Tx >> agi_uniqueid: 1347357694.1210
[Sep 11 12:02:03] VERBOSE[13130] logger.c: [Sep 11 12:02:03] AGI Tx >> agi_callerid: 180599007202
[Sep 11 12:02:03] VERBOSE[13130] logger.c: [Sep 11 12:02:03] AGI Tx >> agi_calleridname: V0911120133007893595
[Sep 11 12:02:03] VERBOSE[13130] logger.c: [Sep 11 12:02:03] AGI Tx >> agi_callingpres: 0
[Sep 11 12:02:03] VERBOSE[13130] logger.c: [Sep 11 12:02:03] AGI Tx >> agi_callingani2: 0
[Sep 11 12:02:03] VERBOSE[13130] logger.c: [Sep 11 12:02:03] AGI Tx >> agi_callington: 0
[Sep 11 12:02:03] VERBOSE[13130] logger.c: [Sep 11 12:02:03] AGI Tx >> agi_callingtns: 0
[Sep 11 12:02:03] VERBOSE[13130] logger.c: [Sep 11 12:02:03] AGI Tx >> agi_dnid: unknown
[Sep 11 12:02:03] VERBOSE[13130] logger.c: [Sep 11 12:02:03] AGI Tx >> agi_rdnis: unknown
[Sep 11 12:02:03] VERBOSE[13130] logger.c: [Sep 11 12:02:03] AGI Tx >> agi_context: default
[Sep 11 12:02:03] VERBOSE[13130] logger.c: [Sep 11 12:02:03] AGI Tx >> agi_extension: h
[Sep 11 12:02:03] VERBOSE[13130] logger.c: [Sep 11 12:02:03] AGI Tx >> agi_priority: 1
[Sep 11 12:02:03] VERBOSE[13130] logger.c: [Sep 11 12:02:03] AGI Tx >> agi_enhanced: 0.0
[Sep 11 12:02:03] VERBOSE[13130] logger.c: [Sep 11 12:02:03] AGI Tx >> agi_accountcode:
[Sep 11 12:02:03] VERBOSE[13130] logger.c: [Sep 11 12:02:03] AGI Tx >>
[Sep 11 12:02:03] VERBOSE[13130] logger.c: [Sep 11 12:02:03]     -- AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16-----ANSWER-----29-----0 completed, returning 0
[Sep 11 12:02:03] VERBOSE[13130] logger.c: [Sep 11 12:02:03]   == Spawn extension (default, 99999056xxxxxx, 2) exited non-zero on 'Local/99999056xxxxxx@default-248d,2'
[Sep 11 12:02:03] VERBOSE[13187] logger.c: [Sep 11 12:02:03]     -- Executing [8368@default:2] AGI("IAX2/192.168.203.33:4569-11627", "agi://127.0.0.1:4577/call_log") in new stack
[Sep 11 12:02:03] VERBOSE[13187] logger.c: [Sep 11 12:02:03] AGI Tx >> agi_network: yes
[Sep 11 12:02:03] VERBOSE[13187] logger.c: [Sep 11 12:02:03] AGI Tx >> agi_network_script: call_log
[Sep 11 12:02:03] VERBOSE[13187] logger.c: [Sep 11 12:02:03] AGI Tx >> agi_request: agi://127.0.0.1:4577/call_log
[Sep 11 12:02:03] VERBOSE[13187] logger.c: [Sep 11 12:02:03] AGI Tx >> agi_channel: IAX2/192.168.203.33:4569-11627
[Sep 11 12:02:03] VERBOSE[13187] logger.c: [Sep 11 12:02:03] AGI Tx >> agi_language: en
[Sep 11 12:02:03] VERBOSE[13187] logger.c: [Sep 11 12:02:03] AGI Tx >> agi_type: IAX2
[Sep 11 12:02:03] VERBOSE[13187] logger.c: [Sep 11 12:02:03] AGI Tx >> agi_uniqueid: 1347357694.1209
[Sep 11 12:02:03] VERBOSE[13187] logger.c: [Sep 11 12:02:03] AGI Tx >> agi_callerid: 180599007202
[Sep 11 12:02:03] VERBOSE[13187] logger.c: [Sep 11 12:02:03] AGI Tx >> agi_calleridname: V0911120133007893595
[Sep 11 12:02:03] VERBOSE[13187] logger.c: [Sep 11 12:02:03] AGI Tx >> agi_callingpres: 0
[Sep 11 12:02:03] VERBOSE[13187] logger.c: [Sep 11 12:02:03] AGI Tx >> agi_callingani2: 0
[Sep 11 12:02:03] VERBOSE[13187] logger.c: [Sep 11 12:02:03] AGI Tx >> agi_callington: 0
[Sep 11 12:02:03] VERBOSE[13187] logger.c: [Sep 11 12:02:03] AGI Tx >> agi_callingtns: 0
[Sep 11 12:02:03] VERBOSE[13187] logger.c: [Sep 11 12:02:03] AGI Tx >> agi_dnid: unknown
[Sep 11 12:02:03] VERBOSE[13187] logger.c: [Sep 11 12:02:03] AGI Tx >> agi_rdnis: unknown
[Sep 11 12:02:03] VERBOSE[13187] logger.c: [Sep 11 12:02:03] AGI Tx >> agi_context: default
[Sep 11 12:02:03] VERBOSE[13187] logger.c: [Sep 11 12:02:03] AGI Tx >> agi_extension: 8368
[Sep 11 12:02:03] VERBOSE[13187] logger.c: [Sep 11 12:02:03] AGI Tx >> agi_priority: 2
[Sep 11 12:02:03] VERBOSE[13187] logger.c: [Sep 11 12:02:03] AGI Tx >> agi_enhanced: 0.0
[Sep 11 12:02:03] VERBOSE[13187] logger.c: [Sep 11 12:02:03] AGI Tx >> agi_accountcode:
[Sep 11 12:02:03] VERBOSE[13187] logger.c: [Sep 11 12:02:03] AGI Tx >>
[Sep 11 12:02:03] VERBOSE[13187] logger.c: [Sep 11 12:02:03]     -- AGI Script agi://127.0.0.1:4577/call_log completed, returning 0
[Sep 11 12:02:03] VERBOSE[13187] logger.c: [Sep 11 12:02:03]     -- Executing [8368@default:3] AGI("IAX2/192.168.203.33:4569-11627", "agi-VDAD_ALL_outbound.agi|NORMAL-----LB") in new stack
[Sep 11 12:02:03] VERBOSE[13187] logger.c: [Sep 11 12:02:03]     -- Launched AGI Script /var/lib/asterisk/agi-bin/agi-VDAD_ALL_outbound.agi
[Sep 11 12:02:03] VERBOSE[13187] logger.c: [Sep 11 12:02:03] AGI Tx >> agi_request: agi-VDAD_ALL_outbound.agi
[Sep 11 12:02:03] VERBOSE[13187] logger.c: [Sep 11 12:02:03] AGI Tx >> agi_channel: IAX2/192.168.203.33:4569-11627
[Sep 11 12:02:03] VERBOSE[13187] logger.c: [Sep 11 12:02:03] AGI Tx >> agi_language: en
[Sep 11 12:02:03] VERBOSE[13187] logger.c: [Sep 11 12:02:03] AGI Tx >> agi_type: IAX2
[Sep 11 12:02:03] VERBOSE[13187] logger.c: [Sep 11 12:02:03] AGI Tx >> agi_uniqueid: 1347357694.1209
[Sep 11 12:02:03] VERBOSE[13187] logger.c: [Sep 11 12:02:03] AGI Tx >> agi_callerid: 180599007202
[Sep 11 12:02:03] VERBOSE[13187] logger.c: [Sep 11 12:02:03] AGI Tx >> agi_calleridname: V0911120133007893595
[Sep 11 12:02:03] VERBOSE[13187] logger.c: [Sep 11 12:02:03] AGI Tx >> agi_callingpres: 0
[Sep 11 12:02:03] VERBOSE[13187] logger.c: [Sep 11 12:02:03] AGI Tx >> agi_callingani2: 0
[Sep 11 12:02:03] VERBOSE[13187] logger.c: [Sep 11 12:02:03] AGI Tx >> agi_callington: 0
[Sep 11 12:02:03] VERBOSE[13187] logger.c: [Sep 11 12:02:03] AGI Tx >> agi_callingtns: 0
[Sep 11 12:02:03] VERBOSE[13187] logger.c: [Sep 11 12:02:03] AGI Tx >> agi_dnid: unknown
[Sep 11 12:02:03] VERBOSE[13187] logger.c: [Sep 11 12:02:03] AGI Tx >> agi_rdnis: unknown
[Sep 11 12:02:03] VERBOSE[13187] logger.c: [Sep 11 12:02:03] AGI Tx >> agi_context: default
[Sep 11 12:02:03] VERBOSE[13187] logger.c: [Sep 11 12:02:03] AGI Tx >> agi_extension: 8368
[Sep 11 12:02:03] VERBOSE[13187] logger.c: [Sep 11 12:02:03] AGI Tx >> agi_priority: 3
[Sep 11 12:02:03] VERBOSE[13187] logger.c: [Sep 11 12:02:03] AGI Tx >> agi_enhanced: 0.0
[Sep 11 12:02:03] VERBOSE[13187] logger.c: [Sep 11 12:02:03] AGI Tx >> agi_accountcode:
[Sep 11 12:02:03] VERBOSE[13187] logger.c: [Sep 11 12:02:03] AGI Tx >>
[Sep 11 12:02:03] VERBOSE[13187] logger.c: [Sep 11 12:02:03] AGI Rx << SET CALLERID V0911120133007893595
[Sep 11 12:02:03] VERBOSE[13187] logger.c: [Sep 11 12:02:03] AGI Tx >> 200 result=1
[Sep 11 12:02:03] VERBOSE[13187] logger.c: [Sep 11 12:02:03] AGI Rx << CHANNEL STATUS IAX2/192.168.203.33:4569-11627
[Sep 11 12:02:03] VERBOSE[13187] logger.c: [Sep 11 12:02:03] AGI Tx >> 200 result=6
[Sep 11 12:02:03] VERBOSE[13187] logger.c: [Sep 11 12:02:03] AGI Rx << SET CONTEXT default
[Sep 11 12:02:03] VERBOSE[13187] logger.c: [Sep 11 12:02:03] AGI Tx >> 200 result=0
[Sep 11 12:02:03] VERBOSE[13187] logger.c: [Sep 11 12:02:03] AGI Rx << SET EXTENSION 192*168*203*040*8600503
[Sep 11 12:02:03] VERBOSE[13187] logger.c: [Sep 11 12:02:03] AGI Tx >> 200 result=0
[Sep 11 12:02:03] VERBOSE[13187] logger.c: [Sep 11 12:02:03] AGI Rx << SET PRIORITY 1
[Sep 11 12:02:03] VERBOSE[13187] logger.c: [Sep 11 12:02:03] AGI Tx >> 200 result=0
[Sep 11 12:02:03] VERBOSE[13187] logger.c: [Sep 11 12:02:03]     -- AGI Script agi-VDAD_ALL_outbound.agi completed, returning 0
[Sep 11 12:02:03] VERBOSE[13187] logger.c: [Sep 11 12:02:03]     -- Executing [192*168*203*040*8600503@default:1] Goto("IAX2/192.168.203.33:4569-11627", "default|8600503|1") in new stack
[Sep 11 12:02:03] VERBOSE[13187] logger.c: [Sep 11 12:02:03]     -- Goto (default,8600503,1)
[Sep 11 12:02:03] VERBOSE[13187] logger.c: [Sep 11 12:02:03]     -- Executing [8600503@default:1] MeetMe("IAX2/192.168.203.33:4569-11627", "8600503|F") in new stack
[Sep 11 12:02:03] DEBUG[13187] app_meetme.c: Placed channel IAX2/192.168.203.33:4569-11627 in DAHDI conf 1023
[Sep 11 12:02:03] VERBOSE[13187] logger.c: [Sep 11 12:02:03]   == Spawn extension (default, 8600503, 1) exited non-zero on 'IAX2/192.168.203.33:4569-11627'
[Sep 11 12:02:03] VERBOSE[13187] logger.c: [Sep 11 12:02:03]     -- Executing [h@default:1] DeadAGI("IAX2/192.168.203.33:4569-11627", "agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16---------------") in new stack
[Sep 11 12:02:03] VERBOSE[13187] logger.c: [Sep 11 12:02:03] AGI Tx >> agi_network: yes
[Sep 11 12:02:03] VERBOSE[13187] logger.c: [Sep 11 12:02:03] AGI Tx >> agi_network_script: call_log--HVcauses--PRI-----NODEBUG-----16---------------
[Sep 11 12:02:03] VERBOSE[13187] logger.c: [Sep 11 12:02:03] AGI Tx >> agi_request: agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16---------------
[Sep 11 12:02:03] VERBOSE[13187] logger.c: [Sep 11 12:02:03] AGI Tx >> agi_channel: IAX2/192.168.203.33:4569-11627
[Sep 11 12:02:03] VERBOSE[13187] logger.c: [Sep 11 12:02:03] AGI Tx >> agi_language: en
[Sep 11 12:02:03] VERBOSE[13187] logger.c: [Sep 11 12:02:03] AGI Tx >> agi_type: IAX2
[Sep 11 12:02:03] VERBOSE[13187] logger.c: [Sep 11 12:02:03] AGI Tx >> agi_uniqueid: 1347357694.1209
[Sep 11 12:02:03] VERBOSE[13187] logger.c: [Sep 11 12:02:03] AGI Tx >> agi_callerid: unknown
[Sep 11 12:02:03] VERBOSE[13187] logger.c: [Sep 11 12:02:03] AGI Tx >> agi_calleridname: V0911120133007893595
[Sep 11 12:02:03] VERBOSE[13187] logger.c: [Sep 11 12:02:03] AGI Tx >> agi_callingpres: 0
[Sep 11 12:02:03] VERBOSE[13187] logger.c: [Sep 11 12:02:03] AGI Tx >> agi_callingani2: 0
[Sep 11 12:02:03] VERBOSE[13187] logger.c: [Sep 11 12:02:03] AGI Tx >> agi_callington: 0
[Sep 11 12:02:03] VERBOSE[13187] logger.c: [Sep 11 12:02:03] AGI Tx >> agi_callingtns: 0
[Sep 11 12:02:03] VERBOSE[13187] logger.c: [Sep 11 12:02:03] AGI Tx >> agi_dnid: unknown
[Sep 11 12:02:03] VERBOSE[13187] logger.c: [Sep 11 12:02:03] AGI Tx >> agi_rdnis: unknown
[Sep 11 12:02:03] VERBOSE[13187] logger.c: [Sep 11 12:02:03] AGI Tx >> agi_context: default
[Sep 11 12:02:03] VERBOSE[13187] logger.c: [Sep 11 12:02:03] AGI Tx >> agi_extension: h
[Sep 11 12:02:03] VERBOSE[13187] logger.c: [Sep 11 12:02:03] AGI Tx >> agi_priority: 1
[Sep 11 12:02:03] VERBOSE[13187] logger.c: [Sep 11 12:02:03] AGI Tx >> agi_enhanced: 0.0
[Sep 11 12:02:03] VERBOSE[13187] logger.c: [Sep 11 12:02:03] AGI Tx >> agi_accountcode:
[Sep 11 12:02:03] VERBOSE[13187] logger.c: [Sep 11 12:02:03] AGI Tx >>
[Sep 11 12:02:03] VERBOSE[13187] logger.c: [Sep 11 12:02:03]     -- AGI Script agi://127.0.0.1:4577/call_log--HVcauses--PRI-----NODEBUG-----16--------------- completed, returning 0
[Sep 11 12:02:03] VERBOSE[13187] logger.c: [Sep 11 12:02:03]     -- Hungup 'IAX2/192.168.203.33:4569-11627'


[phil_discount]

i read many forum topics which are writing about a 3-5 second delay of some fritzboxes.
some people have problems that there is no voice at the beginning or some are writing that their phones will ring 5 seconds later.

perhaps i can use in asterisk some iax delay configuration.

is this configuration bad for vicidial or AMD detection?

Code: Select all

autokill=no

forcejitterbuffer=yes
jittertargetextra=40


[DomeDan]

Hi.

I think I've heard this before, did some googling and found this http://www.vicidial.org/VICIDIALforum/v ... hp?t=24559
"whenever the call comes it, the status immediately changes from LIVE to Hangup. "
and the here's what they came up with:
"Thanks for the response. The issue was the DID the provider passed to me. The DID was not correct. What I did was to change from X.1; to s,1 and disable DID and the whole issue was resolved."

[phil_discount]

thanks, but your topic means incoming calls. i get hangups while answer outgoing call.

the settings in iax.conf bring no success

[DomeDan]

oh yeah... looked a bit more but found no topics with answers though http://www.vicidial.org/VICIDIALforum/v ... f=4&t=2950 http://www.vicidial.org/VICIDIALforum/v ... =4&t=25500

But post as much info as possible, dial-plan, account entry and stuff.
also it would be interesting to see the log of a call that don't get hangup, one of the special customers phones of course.

and change NODEBUG to DEBUG in extensions.conf and look in the astguiclient logs too.

does this fritzbox have any logs regarding this?

[phil_discount]

i think this is the problem, after receiving this message, the call will hangup
[Sep 11 12:00:22] DEBUG[2493] chan_iax2.c: Immediately destroying 3521, having received hangup
i get this hangup short after answer the channel (same time/second)

i'm not allowed to call the customers with the problems.
only the customers who have complained about it are using fritzbox and voip.
i cannot make tests with the customers, if i could, i instant would do that.

[williamconley]

if the other side of the call hangs up, you can't change that. call terminated by the other party.