[May 12 12:53:48] DEBUG[1680]: chan_iax2.c:2696 peercnt_add: ip callno count incremented to 4 for 192.168.1.5 -- Accepting AUTHENTICATED call from 192.168.1.5:4569: -- > requested format = ulaw, -- > requested prefs = (ulaw|alaw), -- > actual format = ulaw, -- > host prefs = (ulaw|alaw), -- > priority = mine [May 12 12:53:48] DEBUG[1015][C-00000009]: pbx.c:2875 pbx_extension_helper: Launching 'ConfBridge' -- Executing [765@sipin:1] ConfBridge("IAX2/halifax-10026", "1,,qsd-confbridge-1") in new stack [May 12 12:53:48] DEBUG[1015][C-00000009]: chan_iax2.c:5753 iax2_answer: Answering IAX2 call [May 12 12:53:48] DEBUG[1595]: devicestate.c:369 _ast_device_state: No provider found, checking channel drivers for IAX2 - halifax [May 12 12:53:48] DEBUG[1595]: chan_iax2.c:14516 iax2_devicestate: Checking device state for device halifax [May 12 12:53:48] DEBUG[1595]: chan_iax2.c:14525 iax2_devicestate: Found peer. What's device state of halifax? addr=192.168.1.5:4569, defaddr=(null) maxms=1000, lastms=3 [May 12 12:53:48] DEBUG[1595]: devicestate.c:474 do_state_change: Changing state for IAX2/halifax - state 2 (In use) [May 12 12:53:48] DEBUG[1696]: app_queue.c:2482 device_state_cb: Device 'IAX2/halifax' changed to state '2' (In use) but we don't care because they're not a member of any queue. [May 12 12:53:48] DEBUG[1675]: chan_iax2.c:10628 socket_process_helper: Ooh, voice format changed to 'ulaw' [May 12 12:53:48] DEBUG[1015][C-00000009]: app.c:1555 __ast_play_and_record: play_and_record: vm-rec-name, /var/spool/asterisk/confbridge/confbridge-name-1-1494604428.34, 'sln' [May 12 12:53:48] DEBUG[1015][C-00000009]: channel.c:3478 ast_settimeout_full: Scheduling timer at (50 requested / 50 actual) timer ticks per second -- Playing 'vm-rec-name.ulaw' (language 'en') [May 12 12:53:49] DEBUG[1011]: threadpool.c:1137 worker_idle: Worker thread idle timeout reached. Dying. [May 12 12:53:49] DEBUG[1584]: threadpool.c:996 worker_thread_destroy: Destroying worker thread 201 [May 12 12:53:50] DEBUG[1678]: chan_iax2.c:10989 socket_process_helper: Immediately destroying 10026, having received hangup [May 12 12:53:50] DEBUG[1015][C-00000009]: channel.c:3478 ast_settimeout_full: Scheduling timer at (0 requested / 0 actual) timer ticks per second [May 12 12:53:50] DEBUG[1015][C-00000009]: channel.c:3478 ast_settimeout_full: Scheduling timer at (0 requested / 0 actual) timer ticks per second [May 12 12:53:50] DEBUG[1015][C-00000009]: app_confbridge.c:1422 join_conference_bridge: Trying to find conference bridge '1' [May 12 12:53:50] DEBUG[1015][C-00000009]: bridge.c:496 find_best_technology: Bridge technology native_rtp does not have any capabilities we want. [May 12 12:53:50] DEBUG[1015][C-00000009]: bridge.c:496 find_best_technology: Bridge technology holding_bridge does not have any capabilities we want. [May 12 12:53:50] DEBUG[1015][C-00000009]: bridge.c:496 find_best_technology: Bridge technology simple_bridge does not have any capabilities we want. [May 12 12:53:50] DEBUG[1015][C-00000009]: bridge.c:515 find_best_technology: Chose bridge technology softmix [May 12 12:53:50] DEBUG[1015][C-00000009]: bridge.c:794 bridge_base_init: Bridge 0a89ba55-3089-4ff1-b244-39b6140629a1: calling softmix technology constructor [May 12 12:53:50] DEBUG[1015][C-00000009]: bridge.c:802 bridge_base_init: Bridge 0a89ba55-3089-4ff1-b244-39b6140629a1: calling softmix technology start [May 12 12:53:50] DEBUG[1018]: bridge_softmix.c:1100 softmix_mixing_thread: Bridge 0a89ba55-3089-4ff1-b244-39b6140629a1: starting mixing thread [May 12 12:53:50] DEBUG[1015][C-00000009]: bridge_roles.c:272 setup_bridge_role: Set role 'announcer' [May 12 12:53:50] DEBUG[1015][C-00000009]: app_confbridge.c:1367 alloc_playback_chan: Created announcer channel 'CBAnn/1-00000008;1' to conference bridge '1' [May 12 12:53:50] DEBUG[1015][C-00000009]: app_confbridge.c:1524 join_conference_bridge: Created conference '1' and linked to container. [May 12 12:53:50] DEBUG[1015][C-00000009]: confbridge/conf_state.c:84 conf_change_state: Changing conference '1' state from EMPTY to SINGLE [May 12 12:53:50] DEBUG[1696]: app_queue.c:2482 device_state_cb: Device 'confbridge:1' changed to state '2' (In use) but we don't care because they're not a member of any queue. [May 12 12:53:50] DEBUG[1015][C-00000009]: app_confbridge.c:1145 conf_update_user_mute: User IAX2/halifax-10026 is unmuted: user:0 system:0. [May 12 12:53:50] DEBUG[1015][C-00000009]: confbridge/conf_state.c:84 conf_change_state: Changing conference '1' state from SINGLE to EMPTY [May 12 12:53:50] DEBUG[1020]: bridge_channel.c:2654 bridge_channel_internal_join: Bridge 0a89ba55-3089-4ff1-b244-39b6140629a1: 0x7fe514001390(CBAnn/1-00000008;2) is joining [May 12 12:53:50] DEBUG[1696]: app_queue.c:2482 device_state_cb: Device 'confbridge:1' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [May 12 12:53:50] DEBUG[1020]: bridge_channel.c:2118 bridge_channel_internal_push_full: Bridge 0a89ba55-3089-4ff1-b244-39b6140629a1: pushing 0x7fe514001390(CBAnn/1-00000008;2) [May 12 12:53:50] DEBUG[1020]: bridge_roles.c:272 setup_bridge_role: Set role 'announcer' -- Channel CBAnn/1-00000008;2 joined 'softmix' base-bridge <0a89ba55-3089-4ff1-b244-39b6140629a1> [May 12 12:53:50] DEBUG[1020]: bridge.c:432 bridge_channel_complete_join: Bridge 0a89ba55-3089-4ff1-b244-39b6140629a1: 0x7fe514001390(CBAnn/1-00000008;2) is joining softmix technology [May 12 12:53:50] DEBUG[1020]: dsp.c:499 ast_tone_detect_init: Setup tone 1100 Hz, 500 ms, block_size=160, hits_required=21 [May 12 12:53:50] DEBUG[1020]: dsp.c:499 ast_tone_detect_init: Setup tone 2100 Hz, 2600 ms, block_size=160, hits_required=116 [May 12 12:53:50] DEBUG[1015][C-00000009]: app_confbridge.c:1027 destroy_conference_bridge: Destroying conference bridge '1' [May 12 12:53:50] DEBUG[1019]: channel.c:2731 ast_hangup: Hanging up channel 'CBAnn/1-00000008;1' [May 12 12:53:50] DEBUG[1020]: bridge_channel.c:288 ast_bridge_channel_leave_bridge_nolock: Setting 0x7fe514001390(CBAnn/1-00000008;2) state from:0 to:1 [May 12 12:53:50] DEBUG[1020]: bridge_channel.c:2055 bridge_channel_internal_pull: Bridge 0a89ba55-3089-4ff1-b244-39b6140629a1: pulling 0x7fe514001390(CBAnn/1-00000008;2) -- Channel CBAnn/1-00000008;2 left 'softmix' base-bridge <0a89ba55-3089-4ff1-b244-39b6140629a1> [May 12 12:53:50] DEBUG[1020]: bridge_channel.c:2067 bridge_channel_internal_pull: Bridge 0a89ba55-3089-4ff1-b244-39b6140629a1: 0x7fe514001390(CBAnn/1-00000008;2) is leaving softmix technology [May 12 12:53:50] DEBUG[1015][C-00000009]: bridge.c:960 ast_bridge_destroy: Bridge 0a89ba55-3089-4ff1-b244-39b6140629a1: telling all channels to leave the party [May 12 12:53:50] DEBUG[1595]: devicestate.c:369 _ast_device_state: No provider found, checking channel drivers for CBAnn - 1 [May 12 12:53:50] DEBUG[1015][C-00000009]: bridge.c:322 bridge_dissolve: Bridge 0a89ba55-3089-4ff1-b244-39b6140629a1: dissolving bridge with cause 16(Normal Clearing) [May 12 12:53:50] DEBUG[1015][C-00000009]: bridge.c:283 bridge_queue_action_nodup: Bridge 0a89ba55-3089-4ff1-b244-39b6140629a1: queueing action type:13 sub:1001 [May 12 12:53:50] DEBUG[1595]: devicestate.c:474 do_state_change: Changing state for CBAnn/1 - state 2 (In use) [May 12 12:53:50] DEBUG[1020]: channel.c:2731 ast_hangup: Hanging up channel 'CBAnn/1-00000008;2' [May 12 12:53:50] DEBUG[1020]: bridge.c:648 destroy_bridge: Bridge 0a89ba55-3089-4ff1-b244-39b6140629a1: actually destroying base bridge, nobody wants it anymore [May 12 12:53:50] DEBUG[1696]: app_queue.c:2482 device_state_cb: Device 'CBAnn/1' changed to state '2' (In use) but we don't care because they're not a member of any queue. [May 12 12:53:50] DEBUG[1015][C-00000009]: pbx.c:4345 __ast_pbx_run: Spawn extension (sipin,765,1) exited non-zero on 'IAX2/halifax-10026' [May 12 12:53:50] DEBUG[1020]: bridge.c:673 destroy_bridge: Bridge 0a89ba55-3089-4ff1-b244-39b6140629a1: calling base bridge destructor [May 12 12:53:50] DEBUG[1020]: bridge.c:679 destroy_bridge: Bridge 0a89ba55-3089-4ff1-b244-39b6140629a1: calling softmix technology stop [May 12 12:53:50] DEBUG[1020]: bridge.c:686 destroy_bridge: Bridge 0a89ba55-3089-4ff1-b244-39b6140629a1: calling softmix technology destructor [May 12 12:53:50] DEBUG[1020]: bridge_softmix.c:1222 softmix_bridge_destroy: Bridge 0a89ba55-3089-4ff1-b244-39b6140629a1: Waiting for mixing thread to die. == Spawn extension (sipin, 765, 1) exited non-zero on 'IAX2/halifax-10026' [May 12 12:53:50] DEBUG[1015][C-00000009]: channel.c:2582 ast_softhangup_nolock: Soft-Hanging (0x10) up channel 'IAX2/halifax-10026' [May 12 12:53:50] DEBUG[1015][C-00000009]: channel.c:2731 ast_hangup: Hanging up channel 'IAX2/halifax-10026' [May 12 12:53:50] DEBUG[1015][C-00000009]: chan_iax2.c:5331 iax2_hangup: We're hanging up IAX2/halifax-10026 now... [May 12 12:53:50] DEBUG[1015][C-00000009]: chan_iax2.c:5348 iax2_hangup: Really destroying IAX2/halifax-10026 now... [May 12 12:53:50] DEBUG[1015][C-00000009]: chan_iax2.c:3096 sched_delay_remove: schedule decrement of callno used for 192.168.1.5 in 60 seconds -- Hungup 'IAX2/halifax-10026' [May 12 12:53:50] DEBUG[1597]: cdr.c:1293 cdr_object_finalize: Finalized CDR for IAX2/halifax-10026 - start 1494604428.042206 answer 1494604428.042481 end 1494604430.243515 dispo ANSWERED [May 12 12:53:50] DEBUG[1595]: devicestate.c:369 _ast_device_state: No provider found, checking channel drivers for IAX2 - halifax [May 12 12:53:50] DEBUG[1595]: chan_iax2.c:14516 iax2_devicestate: Checking device state for device halifax [May 12 12:53:50] DEBUG[1595]: chan_iax2.c:14525 iax2_devicestate: Found peer. What's device state of halifax? addr=192.168.1.5:4569, defaddr=(null) maxms=1000, lastms=3 [May 12 12:53:50] DEBUG[1595]: devicestate.c:474 do_state_change: Changing state for IAX2/halifax - state 0 (Unknown) [May 12 12:53:50] DEBUG[1696]: app_queue.c:2482 device_state_cb: Device 'IAX2/halifax' changed to state '0' (Unknown) but we don't care because they're not a member of any queue. [May 12 12:53:50] DEBUG[1597]: cdr_radius.c:222 radius_log: Unable to create RADIUS record. CDR not recorded! [May 12 12:53:50] DEBUG[1018]: bridge_softmix.c:1128 softmix_mixing_thread: Bridge 0a89ba55-3089-4ff1-b244-39b6140629a1: stopping mixing thread [May 12 12:53:50] DEBUG[1595]: devicestate.c:369 _ast_device_state: No provider found, checking channel drivers for CBAnn - 1 [May 12 12:53:50] DEBUG[1595]: devicestate.c:474 do_state_change: Changing state for CBAnn/1 - state 0 (Unknown) [May 12 12:53:50] DEBUG[1696]: app_queue.c:2482 device_state_cb: Device 'CBAnn/1' changed to state '0' (Unknown) but we don't care because they're not a member of any queue. [May 12 12:53:52] DEBUG[1669]: chan_iax2.c:2728 peercnt_remove: ip callno count decremented to 3 for 192.168.1.5 havana*CLI> core show channels Channel Location State Application(Data) 0 active channels 0 active calls 10 calls processed