Asterisk HangUp Not Breaking Incoming Call For Caller

Home » Asterisk Users » Asterisk HangUp Not Breaking Incoming Call For Caller
Asterisk Users 6 Comments

Hi,

Asterisk 1.8.13 on Debian Testing (Wheezy), MTNL Mumbai. Digium, Inc. Wildcard AEX410 4-port analog card (PCI-Express)

When Asterisk executes HangUp() on an incoming call, the line remains connected for the caller.

Zone = in, opermode = INDIA. Line set to fxsks. Any help on where to start looking appreciated.

Sample log:
[Sep 11 22:06:18] DEBUG[4759]: chan_dahdi.c:11895 do_monitor: Monitor doohicky got event Ring Begin on channel 1
[Sep 11 22:06:18] DEBUG[4759]: sig_analog.c:3621
analog_handle_init_event: channel (1) – signaling (5) – event
(ANALOG_EVENT_RINGBEGIN)
[Sep 11 22:06:19] DEBUG[4759]: chan_dahdi.c:11895 do_monitor: Monitor doohicky got event Ring/Answered on channel 1
[Sep 11 22:06:19] DEBUG[4759]: sig_analog.c:3621
analog_handle_init_event: channel (1) – signaling (5) – event
(ANALOG_EVENT_RINGOFFHOOK)
[Sep 11 22:06:19] DEBUG[4759]: dsp.c:471 ast_tone_detect_init: Setup tone 1100 Hz, 500 ms, block_size0, hits_required!
[Sep 11 22:06:19] DEBUG[4759]: dsp.c:471 ast_tone_detect_init: Setup tone 2100 Hz, 2600 ms, block_size0, hits_required6
[Sep 11 22:06:19] DEBUG[4759]: dsp.c:1576 ast_dsp_set_busy_pattern: dsp busy pattern set to 0,0
[Sep 11 22:06:19] DEBUG[4737]: devicestate.c:340 _ast_device_state: No provider found, checking channel drivers for DAHDI – 1
[Sep 11 22:06:19] DEBUG[5414]: sig_analog.c:1769 __analog_ss_thread:
__analog_ss_thread 1
— Starting simple switch on ‘DAHDI/1-1’
[Sep 11 22:06:19] DEBUG[4737]: devicestate.c:458 do_state_change:
Changing state for DAHDI/1 – state 2 (In use)
[Sep 11 22:06:19] DEBUG[4737]: devicestate.c:438 devstate_event: device
‘DAHDI/1’ state ‘2’
[Sep 11 22:06:19] DEBUG[5414]: sig_analog.c:2392 __analog_ss_thread:
Receiving DTMF cid on channel DAHDI/1-1
[Sep 11 22:06:19] DEBUG[4772]: app_queue.c:1487 handle_statechange:
Device ‘DAHDI/1’ changed to state ‘2’ (In use) but we don’t care because they’re not a member of any queue.
[Sep 11 22:06:21] DEBUG[5414]: sig_analog.c:3509 analog_exception:
analog_exception 1
[Sep 11 22:06:21] DEBUG[5414]: sig_analog.c:3603 analog_exception:
Exception on 16, channel 1
[Sep 11 22:06:21] DEBUG[5414]: sig_analog.c:2660 __analog_handle_event:
__analog_handle_event 1
[Sep 11 22:06:21] DEBUG[5414]: sig_analog.c:2687 __analog_handle_event:
Got event ANALOG_EVENT_RINGBEGIN(12) on channel 1 (index 0)
[Sep 11 22:06:21] DEBUG[5414]: sig_analog.c:3509 analog_exception:
analog_exception 1
[Sep 11 22:06:21] DEBUG[5414]: sig_analog.c:3603 analog_exception:
Exception on 16, channel 1
[Sep 11 22:06:21] DEBUG[5414]: sig_analog.c:2660 __analog_handle_event:
__analog_handle_event 1
[Sep 11 22:06:21] DEBUG[5414]: sig_analog.c:2687 __analog_handle_event:
Got event ANALOG_EVENT_RINGOFFHOOK(2) on channel 1 (index 0)
[Sep 11 22:06:21] DEBUG[5414]: sig_analog.c:3043 __analog_handle_event:
Ring detected
[Sep 11 22:06:21] DEBUG[5414]: sig_analog.c:2441 __analog_ss_thread: CID
got string ”
[Sep 11 22:06:21] DEBUG[5414]: callerid.c:207 callerid_get_dtmf: No cid detected
[Sep 11 22:06:21] DEBUG[5414]: sig_analog.c:2443 __analog_ss_thread: CID
is ”, flags 8
[Sep 11 22:06:21] DEBUG[5414]: pbx.c:3239 ast_str_retrieve_variable:
Result of ‘EXTEN’ is ‘s’
[Sep 11 22:06:21] DEBUG[4737]: devicestate.c:340 _ast_device_state: No provider found, checking channel drivers for DAHDI – 1
[Sep 11 22:06:21] DEBUG[5414]: pbx.c:4230 pbx_extension_helper:
Launching ‘NoOp’
[Sep 11 22:06:21] DEBUG[4737]: devicestate.c:458 do_state_change:
Changing state for DAHDI/1 – state 2 (In use)
[Sep 11 22:06:21] DEBUG[4737]: devicestate.c:438 devstate_event: device
‘DAHDI/1’ state ‘2’
— Executing [s@incoming:1] NoOp(“DAHDI/1-1”, “Incoming s”) in new stack
[Sep 11 22:06:21] DEBUG[5414]: pbx.c:4058
pbx_substitute_variables_helper_full: Function result is ”
[Sep 11 22:06:21] DEBUG[5414]: pbx.c:4230 pbx_extension_helper:
Launching ‘Verbose’
— Executing [s@incoming:2] Verbose(“DAHDI/1-1”, “CID “) in new stack CID
[Sep 11 22:06:21] DEBUG[5414]: pbx.c:4230 pbx_extension_helper:
Launching ‘Set’
— Executing [s@incoming:3] Set(“DAHDI/1-1”, “SPYGROUP=queue-01”) in new stack
[Sep 11 22:06:21] DEBUG[5414]: pbx.c:4230 pbx_extension_helper:
Launching ‘Answer’
— Executing [s@incoming:4] Answer(“DAHDI/1-1”, “”) in new stack
[Sep 11 22:06:21] DEBUG[5414]: sig_analog.c:1499 analog_answer:
analog_answer 1
[Sep 11 22:06:21] DEBUG[5414]: sig_analog.c:1530 analog_answer: Took DAHDI/1-1 off hook
[Sep 11 22:06:21] DEBUG[5414]: chan_dahdi.c:4927 dahdi_enable_ec:
Enabled echo cancellation on channel 1
[Sep 11 22:06:21] DEBUG[4737]: devicestate.c:340 _ast_device_state: No provider found, checking channel drivers for DAHDI – 1
[Sep 11 22:06:21] DEBUG[5414]: chan_dahdi.c:4946 dahdi_train_ec: No echo training requested
[Sep 11 22:06:21] DEBUG[5414]: chan_dahdi.c:9403 dahdi_indicate:
Requested indication -1 on channel DAHDI/1-1
[Sep 11 22:06:21] DEBUG[4772]: app_queue.c:1487 handle_statechange:
Device ‘DAHDI/1’ changed to state ‘2’ (In use) but we don’t care because they’re not a member of any queue.
[Sep 11 22:06:21] DEBUG[4737]: devicestate.c:458 do_state_change:
Changing state for DAHDI/1 – state 2 (In use)
[Sep 11 22:06:21] DEBUG[4737]: devicestate.c:438 devstate_event: device
‘DAHDI/1’ state ‘2’
[Sep 11 22:06:21] DEBUG[4772]: app_queue.c:1487 handle_statechange:
Device ‘DAHDI/1’ changed to state ‘2’ (In use) but we don’t care because they’re not a member of any queue.
[Sep 11 22:06:21] DEBUG[5414]: pbx.c:4230 pbx_extension_helper:
Launching ‘AGI’
— Executing [s@incoming:5] AGI(“DAHDI/1-1”,
“/usr/local/lib/agi/office-hours.agi,custom/no-service”) in new stack
— Launched AGI Script /usr/local/lib/agi/office-hours.agi
> /usr/local/lib/agi/office-hours.agi,custom/no-service: FILE
custom/no-service
/usr/local/lib/agi/office-hours.agi,custom/no-service: Week day 2
/usr/local/lib/agi/office-hours.agi,custom/no-service: OS: 36000, OE:
79200, CUR: 79581
— AGI Script Executing Application: (Playback) Options:
(custom/test)
[Sep 11 22:06:21] DEBUG[5414]: channel.c:5171 set_format: Set channel DAHDI/1-1 to write format slin
[Sep 11 22:06:21] DEBUG[5414]: channel.c:3506 ast_settimeout: Scheduling timer at (50 requested / 50 actual) timer ticks per second
Playing ‘custom/test.slin’ (language ‘en’)
[Sep 11 22:06:28] DEBUG[5414]: channel.c:3506 ast_settimeout: Scheduling timer at (52 requested / 52 actual) timer ticks per second
[Sep 11 22:06:28] DEBUG[5414]: channel.c:3506 ast_settimeout: Scheduling timer at (0 requested / 0 actual) timer ticks per second
[Sep 11 22:06:28] DEBUG[5414]: channel.c:3506 ast_settimeout: Scheduling timer at (0 requested / 0 actual) timer ticks per second
[Sep 11 22:06:28] DEBUG[5414]: channel.c:3506 ast_settimeout: Scheduling timer at (0 requested / 0 actual) timer ticks per second
[Sep 11 22:06:28] DEBUG[5414]: channel.c:5171 set_format: Set channel DAHDI/1-1 to write format ulaw
AGI Script /usr/local/lib/agi/office-hours.agi completed, returning 0
[Sep 11 22:06:28] DEBUG[5414]: pbx.c:3239 ast_str_retrieve_variable:
Result of ‘PASS’ is ‘0’
[Sep 11 22:06:28] DEBUG[5414]: pbx.c:4126
pbx_substitute_variables_helper_full: Expression result is ‘1’
[Sep 11 22:06:28] DEBUG[5414]: pbx.c:4230 pbx_extension_helper:
Launching ‘GotoIf’
— Executing [s@incoming:6] GotoIf(“DAHDI/1-1”, “1 ?done”) in new stack
— Goto (incoming,s,12)
[Sep 11 22:06:28] DEBUG[5414]: pbx.c:4230 pbx_extension_helper:
Launching ‘NoOp’
— Executing [s@incoming:12] NoOp(“DAHDI/1-1”, “”) in new stack
[Sep 11 22:06:28] DEBUG[5414]: pbx.c:4230 pbx_extension_helper:
Launching ‘Hangup’
— Executing [s@incoming:13] Hangup(“DAHDI/1-1”, “”) in new stack
[Sep 11 22:06:28] DEBUG[5414]: pbx.c:5047 __ast_pbx_run: Spawn extension
(incoming,s,13) exited non-zero on ‘DAHDI/1-1’
== Spawn extension (incoming, s, 13) exited non-zero on ‘DAHDI/1-1’
[Sep 11 22:06:28] DEBUG[5414]: channel.c:2683 ast_softhangup_nolock:
Soft-Hanging up channel ‘DAHDI/1-1’
[Sep 11 22:06:28] DEBUG[5414]: channel.c:2831 ast_hangup: Hanging up channel ‘DAHDI/1-1’
[Sep 11 22:06:28] DEBUG[5414]: chan_dahdi.c:6149 dahdi_hangup:
dahdi_hangup(DAHDI/1-1)
[Sep 11 22:06:28] DEBUG[5414]: sig_analog.c:1282 analog_hangup:
analog_hangup 1
[Sep 11 22:06:28] DEBUG[5414]: sig_analog.c:1305 analog_hangup: Hangup:
channel: 1 index = 0, normal = 1, callwait = 0, thirdcall = 0
[Sep 11 22:06:28] DEBUG[5414]: chan_dahdi.c:4962 dahdi_disable_ec:
Disabled echo cancellation on channel 1
[Sep 11 22:06:28] DEBUG[5414]: chan_dahdi.c:6747 dahdi_setoption: Set option TONE VERIFY, mode: OFF(0) on DAHDI/1-1
[Sep 11 22:06:28] DEBUG[5414]: chan_dahdi.c:6757 dahdi_setoption: Set option TDD MODE, value: OFF(0) on DAHDI/1-1
[Sep 11 22:06:28] DEBUG[5414]: sig_analog.c:782 analog_update_conf:
Updated conferencing on 1, with 0 conference users
— Hanging up on ‘DAHDI/1-1’
— Hungup ‘DAHDI/1-1’
[Sep 11 22:06:28] DEBUG[5414]: res_odbc.c:1050 odbc_release_obj2:
odbc_release_obj2(0x7f537401ac78) called (obj->txf = (nil))
[Sep 11 22:06:28] DEBUG[5414]: cdr_radius.c:208 radius_log: Unable to create RADIUS record. CDR not recorded!
[Sep 11 22:06:28] DEBUG[5414]: res_config_sqlite.c:834 cdr_handler: SQL
query: INSERT IGNORE INTO ast_cdr
(dst,dcontext,channel,lastapp,start,answer,end,duration,billsec,disposition,amaflags,uniqueid)
VALUES (‘s’,’incoming’,’DAHDI/1-1′,’Hangup’,’2012-09-11
22:06:19′,’2012-09-11 22:06:21′,’2012-09-11
22:06:28′,’9′,’7′,’ANSWERED’,’DOCUMENTATION’,’1347381379.5′)
[Sep 11 22:06:28] DEBUG[4737]: devicestate.c:340 _ast_device_state: No provider found, checking channel drivers for DAHDI – 1
[Sep 11 22:06:28] DEBUG[4737]: devicestate.c:458 do_state_change:
Changing state for DAHDI/1 – state 0 (Unknown)
[Sep 11 22:06:28] DEBUG[4737]: devicestate.c:438 devstate_event: device
‘DAHDI/1’ state ‘0’
[Sep 11 22:06:28] DEBUG[4772]: app_queue.c:1487 handle_statechange:
Device ‘DAHDI/1’ changed to state ‘0’ (Unknown) but we don’t care because they’re not a member of any queue.

Regards,

— Raj

6 thoughts on - Asterisk HangUp Not Breaking Incoming Call For Caller

  • Hi,

    Asterisk 1.8.13 on Debian Testing (Wheezy), MTNL Mumbai. Digium, Inc. Wildcard AEX410 4-port analog card (PCI-Express)

    When Asterisk executes HangUp() on an incoming call, the line remains connected for the caller.

    Zone = in, opermode = INDIA. Line set to fxsks. Any help on where to start looking appreciated.

    Sample log:
    [Sep 11 22:06:18] DEBUG[4759]: chan_dahdi.c:11895 do_monitor: Monitor doohicky got event Ring Begin on channel 1
    [Sep 11 22:06:18] DEBUG[4759]: sig_analog.c:3621 analog_handle_init_event: channel (1) – signaling (5) – event (ANALOG_EVENT_RINGBEGIN)
    [Sep 11 22:06:19] DEBUG[4759]: chan_dahdi.c:11895 do_monitor: Monitor doohicky got event Ring/Answered on channel 1
    [Sep 11 22:06:19] DEBUG[4759]: sig_analog.c:3621 analog_handle_init_event: channel (1) – signaling (5) – event (ANALOG_EVENT_RINGOFFHOOK)
    [Sep 11 22:06:19] DEBUG[4759]: dsp.c:471 ast_tone_detect_init: Setup tone 1100 Hz, 500 ms, block_size0, hits_required!
    [Sep 11 22:06:19] DEBUG[4759]: dsp.c:471 ast_tone_detect_init: Setup tone 2100 Hz, 2600 ms, block_size0, hits_required6
    [Sep 11 22:06:19] DEBUG[4759]: dsp.c:1576 ast_dsp_set_busy_pattern: dsp busy pattern set to 0,0
    [Sep 11 22:06:19] DEBUG[4737]: devicestate.c:340 _ast_device_state: No provider found, checking channel drivers for DAHDI – 1
    [Sep 11 22:06:19] DEBUG[5414]: sig_analog.c:1769 __analog_ss_thread: __analog_ss_thread 1
    — Starting simple switch on ‘DAHDI/1-1’
    [Sep 11 22:06:19] DEBUG[4737]: devicestate.c:458 do_state_change: Changing state for DAHDI/1 – state 2 (In use)
    [Sep 11 22:06:19] DEBUG[4737]: devicestate.c:438 devstate_event: device ‘DAHDI/1’ state ‘2’
    [Sep 11 22:06:19] DEBUG[5414]: sig_analog.c:2392 __analog_ss_thread: Receiving DTMF cid on channel DAHDI/1-1
    [Sep 11 22:06:19] DEBUG[4772]: app_queue.c:1487 handle_statechange: Device ‘DAHDI/1’ changed to state ‘2’ (In use) but we don’t care because they’re not a member of any queue.
    [Sep 11 22:06:21] DEBUG[5414]: sig_analog.c:3509 analog_exception: analog_exception 1
    [Sep 11 22:06:21] DEBUG[5414]: sig_analog.c:3603 analog_exception: Exception on 16, channel 1
    [Sep 11 22:06:21] DEBUG[5414]: sig_analog.c:2660 __analog_handle_event: __analog_handle_event 1
    [Sep 11 22:06:21] DEBUG[5414]: sig_analog.c:2687 __analog_handle_event: Got event ANALOG_EVENT_RINGBEGIN(12) on channel 1 (index 0)
    [Sep 11 22:06:21] DEBUG[5414]: sig_analog.c:3509 analog_exception: analog_exception 1
    [Sep 11 22:06:21] DEBUG[5414]: sig_analog.c:3603 analog_exception: Exception on 16, channel 1
    [Sep 11 22:06:21] DEBUG[5414]: sig_analog.c:2660 __analog_handle_event: __analog_handle_event 1
    [Sep 11 22:06:21] DEBUG[5414]: sig_analog.c:2687 __analog_handle_event: Got event ANALOG_EVENT_RINGOFFHOOK(2) on channel 1 (index 0)
    [Sep 11 22:06:21] DEBUG[5414]: sig_analog.c:3043 __analog_handle_event: Ring detected
    [Sep 11 22:06:21] DEBUG[5414]: sig_analog.c:2441 __analog_ss_thread: CID got string ”
    [Sep 11 22:06:21] DEBUG[5414]: callerid.c:207 callerid_get_dtmf: No cid detected
    [Sep 11 22:06:21] DEBUG[5414]: sig_analog.c:2443 __analog_ss_thread: CID is ”, flags 8
    [Sep 11 22:06:21] DEBUG[5414]: pbx.c:3239 ast_str_retrieve_variable: Result of ‘EXTEN’ is ‘s’
    [Sep 11 22:06:21] DEBUG[4737]: devicestate.c:340 _ast_device_state: No provider found, checking channel drivers for DAHDI – 1
    [Sep 11 22:06:21] DEBUG[5414]: pbx.c:4230 pbx_extension_helper: Launching ‘NoOp’
    [Sep 11 22:06:21] DEBUG[4737]: devicestate.c:458 do_state_change: Changing state for DAHDI/1 – state 2 (In use)
    [Sep 11 22:06:21] DEBUG[4737]: devicestate.c:438 devstate_event: device ‘DAHDI/1’ state ‘2’
    — Executing [s@incoming:1] NoOp(“DAHDI/1-1”, “Incoming s”) in new stack
    [Sep 11 22:06:21] DEBUG[5414]: pbx.c:4058 pbx_substitute_variables_helper_full: Function result is ”
    [Sep 11 22:06:21] DEBUG[5414]: pbx.c:4230 pbx_extension_helper: Launching ‘Verbose’
    — Executing [s@incoming:2] Verbose(“DAHDI/1-1”, “CID “) in new stack CID
    [Sep 11 22:06:21] DEBUG[5414]: pbx.c:4230 pbx_extension_helper: Launching ‘Set’
    — Executing [s@incoming:3] Set(“DAHDI/1-1”, “SPYGROUP=queue-01”) in new stack
    [Sep 11 22:06:21] DEBUG[5414]: pbx.c:4230 pbx_extension_helper: Launching ‘Answer’
    — Executing [s@incoming:4] Answer(“DAHDI/1-1”, “”) in new stack
    [Sep 11 22:06:21] DEBUG[5414]: sig_analog.c:1499 analog_answer: analog_answer 1
    [Sep 11 22:06:21] DEBUG[5414]: sig_analog.c:1530 analog_answer: Took DAHDI/1-1 off hook
    [Sep 11 22:06:21] DEBUG[5414]: chan_dahdi.c:4927 dahdi_enable_ec: Enabled echo cancellation on channel 1
    [Sep 11 22:06:21] DEBUG[4737]: devicestate.c:340 _ast_device_state: No provider found, checking channel drivers for DAHDI – 1
    [Sep 11 22:06:21] DEBUG[5414]: chan_dahdi.c:4946 dahdi_train_ec: No echo training requested
    [Sep 11 22:06:21] DEBUG[5414]: chan_dahdi.c:9403 dahdi_indicate: Requested indication -1 on channel DAHDI/1-1
    [Sep 11 22:06:21] DEBUG[4772]: app_queue.c:1487 handle_statechange: Device ‘DAHDI/1’ changed to state ‘2’ (In use) but we don’t care because they’re not a member of any queue.
    [Sep 11 22:06:21] DEBUG[4737]: devicestate.c:458 do_state_change: Changing state for DAHDI/1 – state 2 (In use)
    [Sep 11 22:06:21] DEBUG[4737]: devicestate.c:438 devstate_event: device ‘DAHDI/1’ state ‘2’
    [Sep 11 22:06:21] DEBUG[4772]: app_queue.c:1487 handle_statechange: Device ‘DAHDI/1’ changed to state ‘2’ (In use) but we don’t care because they’re not a member of any queue.
    [Sep 11 22:06:21] DEBUG[5414]: pbx.c:4230 pbx_extension_helper: Launching ‘AGI’
    — Executing [s@incoming:5] AGI(“DAHDI/1-1”, “/usr/local/lib/agi/office-hours.agi,custom/no-service”) in new stack
    — Launched AGI Script /usr/local/lib/agi/office-hours.agi
    > /usr/local/lib/agi/office-hours.agi,custom/no-service: FILE custom/no-service
    /usr/local/lib/agi/office-hours.agi,custom/no-service: Week day 2
    /usr/local/lib/agi/office-hours.agi,custom/no-service: OS: 36000, OE: 79200, CUR: 79581
    — AGI Script Executing Application: (Playback) Options: (custom/test)
    [Sep 11 22:06:21] DEBUG[5414]: channel.c:5171 set_format: Set channel DAHDI/1-1 to write format slin
    [Sep 11 22:06:21] DEBUG[5414]: channel.c:3506 ast_settimeout: Scheduling timer at (50 requested / 50 actual) timer ticks per second
    Playing ‘custom/test.slin’ (language ‘en’)
    [Sep 11 22:06:28] DEBUG[5414]: channel.c:3506 ast_settimeout: Scheduling timer at (52 requested / 52 actual) timer ticks per second
    [Sep 11 22:06:28] DEBUG[5414]: channel.c:3506 ast_settimeout: Scheduling timer at (0 requested / 0 actual) timer ticks per second
    [Sep 11 22:06:28] DEBUG[5414]: channel.c:3506 ast_settimeout: Scheduling timer at (0 requested / 0 actual) timer ticks per second
    [Sep 11 22:06:28] DEBUG[5414]: channel.c:3506 ast_settimeout: Scheduling timer at (0 requested / 0 actual) timer ticks per second
    [Sep 11 22:06:28] DEBUG[5414]: channel.c:5171 set_format: Set channel DAHDI/1-1 to write format ulaw
    AGI Script /usr/local/lib/agi/office-hours.agi completed, returning 0
    [Sep 11 22:06:28] DEBUG[5414]: pbx.c:3239 ast_str_retrieve_variable: Result of ‘PASS’ is ‘0’
    [Sep 11 22:06:28] DEBUG[5414]: pbx.c:4126 pbx_substitute_variables_helper_full: Expression result is ‘1’
    [Sep 11 22:06:28] DEBUG[5414]: pbx.c:4230 pbx_extension_helper: Launching ‘GotoIf’
    — Executing [s@incoming:6] GotoIf(“DAHDI/1-1”, “1 ?done”) in new stack
    — Goto (incoming,s,12)
    [Sep 11 22:06:28] DEBUG[5414]: pbx.c:4230 pbx_extension_helper: Launching ‘NoOp’
    — Executing [s@incoming:12] NoOp(“DAHDI/1-1”, “”) in new stack
    [Sep 11 22:06:28] DEBUG[5414]: pbx.c:4230 pbx_extension_helper: Launching ‘Hangup’
    — Executing [s@incoming:13] Hangup(“DAHDI/1-1”, “”) in new stack
    [Sep 11 22:06:28] DEBUG[5414]: pbx.c:5047 __ast_pbx_run: Spawn extension (incoming,s,13) exited non-zero on ‘DAHDI/1-1’
    == Spawn extension (incoming, s, 13) exited non-zero on ‘DAHDI/1-1’
    [Sep 11 22:06:28] DEBUG[5414]: channel.c:2683 ast_softhangup_nolock: Soft-Hanging up channel ‘DAHDI/1-1’
    [Sep 11 22:06:28] DEBUG[5414]: channel.c:2831 ast_hangup: Hanging up channel ‘DAHDI/1-1’
    [Sep 11 22:06:28] DEBUG[5414]: chan_dahdi.c:6149 dahdi_hangup: dahdi_hangup(DAHDI/1-1)
    [Sep 11 22:06:28] DEBUG[5414]: sig_analog.c:1282 analog_hangup: analog_hangup 1
    [Sep 11 22:06:28] DEBUG[5414]: sig_analog.c:1305 analog_hangup: Hangup: channel: 1 index = 0, normal = 1, callwait = 0, thirdcall = 0
    [Sep 11 22:06:28] DEBUG[5414]: chan_dahdi.c:4962 dahdi_disable_ec: Disabled echo cancellation on channel 1
    [Sep 11 22:06:28] DEBUG[5414]: chan_dahdi.c:6747 dahdi_setoption: Set option TONE VERIFY, mode: OFF(0) on DAHDI/1-1
    [Sep 11 22:06:28] DEBUG[5414]: chan_dahdi.c:6757 dahdi_setoption: Set option TDD MODE, value: OFF(0) on DAHDI/1-1
    [Sep 11 22:06:28] DEBUG[5414]: sig_analog.c:782 analog_update_conf: Updated conferencing on 1, with 0 conference users
    — Hanging up on ‘DAHDI/1-1’
    — Hungup ‘DAHDI/1-1’
    [Sep 11 22:06:28] DEBUG[5414]: res_odbc.c:1050 odbc_release_obj2: odbc_release_obj2(0x7f537401ac78) called (obj->txf = (nil))
    [Sep 11 22:06:28] DEBUG[5414]: cdr_radius.c:208 radius_log: Unable to create RADIUS record. CDR not recorded!
    [Sep 11 22:06:28] DEBUG[5414]: res_config_sqlite.c:834 cdr_handler: SQL query: INSERT IGNORE INTO ast_cdr
    (dst,dcontext,channel,lastapp,start,answer,end,duration,billsec,disposition,amaflags,uniqueid) VALUES (‘s’,’incoming’,’DAHDI/1-1′,’Hangup’,’2012-09-11
    22:06:19′,’2012-09-11 22:06:21′,’2012-09-11 22:06:28′,’9′,’7′,’ANSWERED’,’DOCUMENTATION’,’1347381379.5′)
    [Sep 11 22:06:28] DEBUG[4737]: devicestate.c:340 _ast_device_state: No provider found, checking channel drivers for DAHDI – 1
    [Sep 11 22:06:28] DEBUG[4737]: devicestate.c:458 do_state_change: Changing state for DAHDI/1 – state 0 (Unknown)
    [Sep 11 22:06:28] DEBUG[4737]: devicestate.c:438 devstate_event: device ‘DAHDI/1’ state ‘0’
    [Sep 11 22:06:28] DEBUG[4772]: app_queue.c:1487 handle_statechange: Device ‘DAHDI/1’ changed to state ‘0’ (Unknown) but we don’t care because they’re not a member of any queue.

    Regards,

    — Raj

  • Raj,

    I am just confirming it happens here as well.

    CentOS 5.7. Asterisk 1.8.15.1. DAHDI 2.6.1.

    Digium, Inc. Wildcard TDM410 4-port analog card (rev 11)

    Loadzone = us

    The problem started manifesting itself after I switched to 1.8.x from
    1.6.2.x

    Typical scenario: a caller apparently hangs up, dial plan goes into voice mail and records a 50 sec message with the CO tones. Then something happens and the line finally gets hung up.

    Regards, Vladimir

  • This has been happening since the asterisk 1.2 days, makes me believe it has something to do with Analog FXO ckts provided.

    Mitul Limbani

  • I feel this is a different problem:

    Problem 1: Asterisk receives incoming call from PSTN. Caller hangs up.
    Asterisk doesn’t notice hangup and continues in the dialplan.

    Problem 2: Asterisk receives incoming call from PSTN. Asterisk eventually executes HangUp(). Caller does not get hung up.

    Correct me if I’m wrong, but yours seems to be the first, whereas mine is the second.

    Solved the first one by loading the appropriate zones, loading the Digium card driver with the correct opermode (which must be one of the best-kept secrets on the Internet!) and enabling busydetect in Dahdi.

    Stuck at the second one for now.

    Regards,

    — Raj

  • Raj,

    Problem 1 is where asterisk times out and line gets free

    However for problem 2

    There is no way that this line frees up, as it depends upon remote side infra of caller, if they calling from pri ckt they possibly could identify our hangup signal, but if they calling from Analog exchange this event is noy reliable and doesnt work 90% of the time.

    It can als occur if our side of operator pulls up line from Analog exchange instead of Digital, they can claim it to be analog, but i really dont trust MTNL for sure, as they dont know why they r operators too 🙂

    So well we gotta either live wth it or move on to 100% digital comm, i.e. E1 PRI ckts.

    Mitul

  • Raj,

    You are absolutely right. I am experiencing the *Problem 1*. I never experienced your *Problem 2*.

    In my opinion my problem is related to the call supervision (reverse polarity or voltage drop) being missed by Asterisk on occasion. I do not use busydetect as I do not want to have false positives.

    Good luck with your Problem 2 struggle.

    -Vladimir