[Mar 20 08:59:07] VERBOSE[28663] asterisk.c: -- Remote UNIX connection [Mar 20 08:59:23] Asterisk 11.16-0SNAPSHOT built by root @ b2v-deb-build-wheezy on a x86_64 running Linux on 2015-03-19 13:05:05 UTC [Mar 20 08:59:23] DEBUG[29083] config.c: Parsing /etc/asterisk/logger.conf [Mar 20 08:59:23] VERBOSE[29083] config.c: == Parsing '/etc/asterisk/logger.conf': Found [Mar 20 08:59:23] DEBUG[29083] config.c: Parsing /etc/asterisk/logger_common.conf [Mar 20 08:59:23] VERBOSE[29083] config.c: == Parsing '/etc/asterisk/logger_common.conf': Found [Mar 20 08:59:23] VERBOSE[29083] logger.c: Asterisk Queue Logger restarted [Mar 20 09:01:54] VERBOSE[28690] chan_dahdi.c: PRI Span: 1 [Mar 20 09:01:54] VERBOSE[28690] chan_dahdi.c: PRI Span: 1 < Protocol Discriminator: Q.931 (8) len=47 [Mar 20 09:01:54] VERBOSE[28690] chan_dahdi.c: PRI Span: 1 < TEI=0 Call Ref: len= 2 (reference 20682/0x50CA) (Sent from originator) [Mar 20 09:01:54] VERBOSE[28690] chan_dahdi.c: PRI Span: 1 < Message Type: SETUP (5) [Mar 20 09:01:54] VERBOSE[28690] chan_dahdi.c: PRI Span: 1 < [a1] [Mar 20 09:01:54] VERBOSE[28690] chan_dahdi.c: PRI Span: 1 < Sending Complete (len= 1) [Mar 20 09:01:54] VERBOSE[28690] chan_dahdi.c: PRI Span: 1 < [04 03 90 90 a3] [Mar 20 09:01:54] VERBOSE[28690] chan_dahdi.c: PRI Span: 1 < Bearer Capability (len= 5) [ Ext: 1 Coding-Std: 0 Info transfer capability: 3.1kHz audio (16) [Mar 20 09:01:54] VERBOSE[28690] chan_dahdi.c: PRI Span: 1 < Ext: 1 Trans mode/rate: 64kbps, circuit-mode (16) [Mar 20 09:01:54] VERBOSE[28690] chan_dahdi.c: PRI Span: 1 < User information layer 1: A-Law (35) [Mar 20 09:01:54] VERBOSE[28690] chan_dahdi.c: PRI Span: 1 < [18 03 a1 83 82] [Mar 20 09:01:54] VERBOSE[28690] chan_dahdi.c: PRI Span: 1 < Channel ID (len= 5) [ Ext: 1 IntID: Implicit Other(PRI) Spare: 0 Preferred Dchan: 0 [Mar 20 09:01:54] VERBOSE[28690] chan_dahdi.c: PRI Span: 1 < ChanSel: As indicated in following octets [Mar 20 09:01:54] VERBOSE[28690] chan_dahdi.c: PRI Span: 1 < Ext: 1 Coding: 0 Number Specified Channel Type: 3 [Mar 20 09:01:54] VERBOSE[28690] chan_dahdi.c: PRI Span: 1 < Ext: 1 Channel: 2 Type: CPE] [Mar 20 09:01:54] VERBOSE[28690] chan_dahdi.c: PRI Span: 1 < [1e 02 8a 81] [Mar 20 09:01:54] VERBOSE[28690] chan_dahdi.c: PRI Span: 1 < Progress Indicator (len= 4) [ Ext: 1 Coding: CCITT (ITU) standard (0) 0: 0 Location: Network beyond the interworking point (10) [Mar 20 09:01:54] VERBOSE[28690] chan_dahdi.c: PRI Span: 1 < Ext: 1 Progress Description: Call is not end-to-end ISDN; further call progress information may be available inband. (1) ] [Mar 20 09:01:54] VERBOSE[28690] chan_dahdi.c: PRI Span: 1 < [6c 0d 21 83 38 39 32 31 39 30 39 39 38 34 34] [Mar 20 09:01:54] VERBOSE[28690] chan_dahdi.c: PRI Span: 1 < Calling Party Number (len=15) [ Ext: 0 TON: National Number (2) NPI: ISDN/Telephony Numbering Plan (E.164/E.163) (1) [Mar 20 09:01:54] VERBOSE[28690] chan_dahdi.c: PRI Span: 1 < Presentation: Presentation allowed, Network provided (3) '89xxxxxxxxx' ] [Mar 20 09:01:54] VERBOSE[28690] chan_dahdi.c: PRI Span: 1 < [70 0a c1 33 35 38 39 39 32 34 30 30] [Mar 20 09:01:54] VERBOSE[28690] chan_dahdi.c: PRI Span: 1 < Called Party Number (len=12) [ Ext: 1 TON: Subscriber Number (4) NPI: ISDN/Telephony Numbering Plan (E.164/E.163) (1) '3yyyyy400' ] [Mar 20 09:01:54] VERBOSE[28690] chan_dahdi.c: PRI Span: 1 -- Making new call for cref 20682 [Mar 20 09:01:54] VERBOSE[28690] chan_dahdi.c: PRI Span: 1 Received message for call 0x7fe9f4024350 on link 0x2c36780 TEI/SAPI 0/0 [Mar 20 09:01:54] VERBOSE[28690] chan_dahdi.c: PRI Span: 1 -- Processing Q.931 Call Setup [Mar 20 09:01:54] VERBOSE[28690] chan_dahdi.c: PRI Span: 1 -- Processing IE 161 (cs0, Sending Complete) [Mar 20 09:01:54] VERBOSE[28690] chan_dahdi.c: PRI Span: 1 -- Processing IE 4 (cs0, Bearer Capability) [Mar 20 09:01:54] VERBOSE[28690] chan_dahdi.c: PRI Span: 1 -- Processing IE 24 (cs0, Channel ID) [Mar 20 09:01:54] VERBOSE[28690] chan_dahdi.c: PRI Span: 1 -- Processing IE 30 (cs0, Progress Indicator) [Mar 20 09:01:54] VERBOSE[28690] chan_dahdi.c: PRI Span: 1 -- Processing IE 108 (cs0, Calling Party Number) [Mar 20 09:01:54] VERBOSE[28690] chan_dahdi.c: PRI Span: 1 -- Processing IE 112 (cs0, Called Party Number) [Mar 20 09:01:54] VERBOSE[28690] chan_dahdi.c: PRI Span: 1 q931.c:8661 post_handle_q931_message: Call 20682 enters state 6 (Call Present). Hold state: Idle [Mar 20 09:01:54] VERBOSE[28690] sig_pri.c: Span 1: Processing event PRI_EVENT_RING(5) [Mar 20 09:01:54] DEBUG[28690][C-00000001] sig_pri.c: prioffset: 2 mastertrunkgroup: 0 logicalspan: 0 result: 2 [Mar 20 09:01:54] VERBOSE[28690] chan_dahdi.c: PRI Span: 1 q931.c:5707 q931_call_proceeding: Call 20682 enters state 9 (Incoming Call Proceeding). Hold state: Idle [Mar 20 09:01:54] VERBOSE[28690] chan_dahdi.c: PRI Span: 1 [Mar 20 09:01:54] VERBOSE[28690] chan_dahdi.c: PRI Span: 1 > DL-DATA request [Mar 20 09:01:54] VERBOSE[28690] chan_dahdi.c: PRI Span: 1 > Protocol Discriminator: Q.931 (8) len=10 [Mar 20 09:01:54] VERBOSE[28690] chan_dahdi.c: PRI Span: 1 > TEI=0 Call Ref: len= 2 (reference 20682/0x50CA) (Sent to originator) [Mar 20 09:01:54] VERBOSE[28690] chan_dahdi.c: PRI Span: 1 > Message Type: CALL PROCEEDING (2) [Mar 20 09:01:54] VERBOSE[28690] chan_dahdi.c: PRI Span: 1 TEI=0 Transmitting N(S)=4, window is open V(A)=4 K=7 [Mar 20 09:01:54] VERBOSE[28690] chan_dahdi.c: PRI Span: 1 [Mar 20 09:01:54] VERBOSE[28690] chan_dahdi.c: PRI Span: 1 > Protocol Discriminator: Q.931 (8) len=10 [Mar 20 09:01:54] VERBOSE[28690] chan_dahdi.c: PRI Span: 1 > TEI=0 Call Ref: len= 2 (reference 20682/0x50CA) (Sent to originator) [Mar 20 09:01:54] VERBOSE[28690] chan_dahdi.c: PRI Span: 1 > Message Type: CALL PROCEEDING (2) [Mar 20 09:01:54] VERBOSE[28690] chan_dahdi.c: PRI Span: 1 > [18 03 a9 83 82] [Mar 20 09:01:54] VERBOSE[28690] chan_dahdi.c: PRI Span: 1 > Channel ID (len= 5) [ Ext: 1 IntID: Implicit Other(PRI) Spare: 0 Exclusive Dchan: 0 [Mar 20 09:01:54] VERBOSE[28690] chan_dahdi.c: PRI Span: 1 > ChanSel: As indicated in following octets [Mar 20 09:01:54] VERBOSE[28690] chan_dahdi.c: PRI Span: 1 > Ext: 1 Coding: 0 Number Specified Channel Type: 3 [Mar 20 09:01:54] VERBOSE[28690] chan_dahdi.c: PRI Span: 1 > Ext: 1 Channel: 2 Type: CPE] [Mar 20 09:01:54] DEBUG[28690][C-00000001] dsp.c: Setup tone 1100 Hz, 500 ms, block_size=160, hits_required=21 [Mar 20 09:01:54] DEBUG[28690][C-00000001] dsp.c: Setup tone 2100 Hz, 2600 ms, block_size=160, hits_required=116 [Mar 20 09:01:54] DEBUG[28696] manager.c: Examining event: Event: Newchannel Privilege: call,all Channel: DAHDI/i1/4989xxxxxxxxx-2 ChannelState: 4 ChannelStateDesc: Ring CallerIDNum: 4989xxxxxxxxx CallerIDName: AccountCode: Exten: 3yyyyy400 Context: default Uniqueid: 1426838514.1 [Mar 20 09:01:54] DEBUG[28682] devicestate.c: No provider found, checking channel drivers for DAHDI - i1/4989xxxxxxxxx [Mar 20 09:01:54] DEBUG[28696] manager.c: Examining event: Event: DAHDIChannel Privilege: call,all Channel: DAHDI/i1/4989xxxxxxxxx-2 Uniqueid: 1426838514.1 DAHDISpan: 1 DAHDIChannel: 2 [Mar 20 09:01:54] DEBUG[28682] devicestate.c: Changing state for DAHDI/i1/4989xxxxxxxxx - state 2 (In use) [Mar 20 09:01:54] DEBUG[28682] devicestate.c: device 'DAHDI/i1/4989xxxxxxxxx' state '2' [Mar 20 09:01:54] VERBOSE[28690][C-00000001] sig_pri.c: -- Accepting call from '4989xxxxxxxxx' to '3yyyyy400' on channel 0/2, span 1 [Mar 20 09:01:54] DEBUG[29084][C-00000001] pbx.c: Result of 'MONITORING_ENABLED' is '0' [Mar 20 09:01:54] DEBUG[29084][C-00000001] pbx.c: Expression result is '1' [Mar 20 09:01:54] DEBUG[29084][C-00000001] pbx.c: Launching 'GotoIf' [Mar 20 09:01:54] VERBOSE[29084][C-00000001] pbx.c: -- Executing [3yyyyy400@default:1] GotoIf("DAHDI/i1/4989xxxxxxxxx-2", "1?nomonitor") in new stack [Mar 20 09:01:54] VERBOSE[29084][C-00000001] pbx.c: -- Goto (default,3yyyyy400,5) [Mar 20 09:01:54] DEBUG[29084][C-00000001] pbx.c: Result of 'HEAD_NUMBER' is '358992' [Mar 20 09:01:54] DEBUG[29084][C-00000001] pbx.c: Function LEN(358992) result is '6' [Mar 20 09:01:54] DEBUG[29084][C-00000001] pbx.c: Result of 'EXTEN' is '3yyyyy400' [Mar 20 09:01:54] DEBUG[29084][C-00000001] pbx.c: Launching 'Goto' [Mar 20 09:01:54] VERBOSE[29084][C-00000001] pbx.c: -- Executing [3yyyyy400@default:5] Goto("DAHDI/i1/4989xxxxxxxxx-2", "default,400,1") in new stack [Mar 20 09:01:54] VERBOSE[29084][C-00000001] pbx.c: -- Goto (default,400,1) [Mar 20 09:01:54] DEBUG[29084][C-00000001] pbx.c: Launching 'Answer' [Mar 20 09:01:54] VERBOSE[29084][C-00000001] pbx.c: -- Executing [400@default:1] Answer("DAHDI/i1/4989xxxxxxxxx-2", "") in new stack [Mar 20 09:01:54] DEBUG[28682] devicestate.c: No provider found, checking channel drivers for DAHDI - i1/4989xxxxxxxxx [Mar 20 09:01:54] DEBUG[28696] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/i1/4989xxxxxxxxx-2 Variable: TRANSFERCAPABILITY Value: 3K1AUDIO Uniqueid: 1426838514.1 [Mar 20 09:01:54] DEBUG[28696] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/i1/4989xxxxxxxxx-2 Variable: ANI2 Value: 0 Uniqueid: 1426838514.1 [Mar 20 09:01:54] DEBUG[28696] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/i1/4989xxxxxxxxx-2 Variable: CALLEDTON Value: 65 Uniqueid: 1426838514.1 [Mar 20 09:01:54] DEBUG[28696] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/i1/4989xxxxxxxxx-2 Variable: PRIREDIRECTREASON Value: UNKNOWN Uniqueid: 1426838514.1 [Mar 20 09:01:54] DEBUG[28696] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/i1/4989xxxxxxxxx-2 Context: default Extension: 3yyyyy400 Priority: 1 Application: GotoIf AppData: 1?nomonitor Uniqueid: 1426838514.1 [Mar 20 09:01:54] DEBUG[28696] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/i1/4989xxxxxxxxx-2 Context: default Extension: 3yyyyy400 Priority: 5 Application: Goto AppData: default,400,1 Uniqueid: 1426838514.1 [Mar 20 09:01:54] DEBUG[28696] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/i1/4989xxxxxxxxx-2 Context: default Extension: 400 Priority: 1 Application: Answer AppData: Uniqueid: 1426838514.1 [Mar 20 09:01:54] DEBUG[28696] manager.c: Examining event: Event: Newstate Privilege: call,all Channel: DAHDI/i1/4989xxxxxxxxx-2 ChannelState: 6 ChannelStateDesc: Up CallerIDNum: 4989xxxxxxxxx CallerIDName: ConnectedLineNum: ConnectedLineName: Uniqueid: 1426838514.1 [Mar 20 09:01:54] DEBUG[28690][C-00000001] chan_dahdi.c: Enabled echo cancellation on channel 2 [Mar 20 09:01:54] VERBOSE[29084] chan_dahdi.c: PRI Span: 1 q931.c:5903 q931_connect: Call 20682 enters state 8 (Connect Request). Hold state: Idle [Mar 20 09:01:54] VERBOSE[29084] chan_dahdi.c: PRI Span: 1 [Mar 20 09:01:54] VERBOSE[29084] chan_dahdi.c: PRI Span: 1 > DL-DATA request [Mar 20 09:01:54] VERBOSE[29084] chan_dahdi.c: PRI Span: 1 > Protocol Discriminator: Q.931 (8) len=14 [Mar 20 09:01:54] VERBOSE[29084] chan_dahdi.c: PRI Span: 1 > TEI=0 Call Ref: len= 2 (reference 20682/0x50CA) (Sent to originator) [Mar 20 09:01:54] VERBOSE[29084] chan_dahdi.c: PRI Span: 1 > Message Type: CONNECT (7) [Mar 20 09:01:54] VERBOSE[29084] chan_dahdi.c: PRI Span: 1 TEI=0 Transmitting N(S)=5, window is open V(A)=4 K=7 [Mar 20 09:01:54] VERBOSE[29084] chan_dahdi.c: PRI Span: 1 [Mar 20 09:01:54] VERBOSE[29084] chan_dahdi.c: PRI Span: 1 > Protocol Discriminator: Q.931 (8) len=14 [Mar 20 09:01:54] VERBOSE[29084] chan_dahdi.c: PRI Span: 1 > TEI=0 Call Ref: len= 2 (reference 20682/0x50CA) (Sent to originator) [Mar 20 09:01:54] VERBOSE[29084] chan_dahdi.c: PRI Span: 1 > Message Type: CONNECT (7) [Mar 20 09:01:54] VERBOSE[29084] chan_dahdi.c: PRI Span: 1 > [18 03 a9 83 82] [Mar 20 09:01:54] VERBOSE[29084] chan_dahdi.c: PRI Span: 1 > Channel ID (len= 5) [ Ext: 1 IntID: Implicit Other(PRI) Spare: 0 Exclusive Dchan: 0 [Mar 20 09:01:54] VERBOSE[29084] chan_dahdi.c: PRI Span: 1 > ChanSel: As indicated in following octets [Mar 20 09:01:54] VERBOSE[29084] chan_dahdi.c: PRI Span: 1 > Ext: 1 Coding: 0 Number Specified Channel Type: 3 [Mar 20 09:01:54] VERBOSE[29084] chan_dahdi.c: PRI Span: 1 > Ext: 1 Channel: 2 Type: CPE] [Mar 20 09:01:54] VERBOSE[29084] chan_dahdi.c: PRI Span: 1 > [1e 02 81 82] [Mar 20 09:01:54] VERBOSE[29084] chan_dahdi.c: PRI Span: 1 > Progress Indicator (len= 4) [ Ext: 1 Coding: CCITT (ITU) standard (0) 0: 0 Location: Private network serving the local user (1) [Mar 20 09:01:54] VERBOSE[29084] chan_dahdi.c: PRI Span: 1 > Ext: 1 Progress Description: Called equipment is non-ISDN. (2) ] [Mar 20 09:01:54] DEBUG[28682] devicestate.c: Changing state for DAHDI/i1/4989xxxxxxxxx - state 2 (In use) [Mar 20 09:01:54] DEBUG[28682] devicestate.c: device 'DAHDI/i1/4989xxxxxxxxx' state '2' [Mar 20 09:01:54] DEBUG[29084][C-00000001] chan_dahdi.c: Requested indication -1 on channel DAHDI/i1/4989xxxxxxxxx-2 [Mar 20 09:01:54] DEBUG[29084][C-00000001] pbx.c: Launching 'Playback' [Mar 20 09:01:54] VERBOSE[29084][C-00000001] pbx.c: -- Executing [400@default:2] Playback("DAHDI/i1/4989xxxxxxxxx-2", "hello-world") in new stack [Mar 20 09:01:54] DEBUG[28696] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/i1/4989xxxxxxxxx-2 Context: default Extension: 400 Priority: 2 Application: Playback AppData: hello-world Uniqueid: 1426838514.1 [Mar 20 09:01:54] DEBUG[29084][C-00000001] channel.c: Set channel DAHDI/i1/4989xxxxxxxxx-2 to write format gsm [Mar 20 09:01:54] DEBUG[29084][C-00000001] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second [Mar 20 09:01:54] VERBOSE[29084][C-00000001] file.c: -- Playing 'hello-world.gsm' (language 'de') [Mar 20 09:01:55] VERBOSE[28690] chan_dahdi.c: PRI Span: 1 [Mar 20 09:01:55] VERBOSE[28690] chan_dahdi.c: PRI Span: 1 < Protocol Discriminator: Q.931 (8) len=5 [Mar 20 09:01:55] VERBOSE[28690] chan_dahdi.c: PRI Span: 1 < TEI=0 Call Ref: len= 2 (reference 20682/0x50CA) (Sent from originator) [Mar 20 09:01:55] VERBOSE[28690] chan_dahdi.c: PRI Span: 1 < Message Type: CONNECT ACKNOWLEDGE (15) [Mar 20 09:01:55] VERBOSE[28690] chan_dahdi.c: PRI Span: 1 Received message for call 0x7fe9f4024350 on link 0x2c36780 TEI/SAPI 0/0 [Mar 20 09:01:55] VERBOSE[28690] chan_dahdi.c: PRI Span: 1 q931.c:8876 post_handle_q931_message: Call 20682 enters state 10 (Active). Hold state: Idle [Mar 20 09:01:55] VERBOSE[28690] sig_pri.c: Span 1: Processing event PRI_EVENT_CONNECT_ACK(27) [Mar 20 09:01:56] DEBUG[29084][C-00000001] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Mar 20 09:01:56] DEBUG[29084][C-00000001] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Mar 20 09:01:56] DEBUG[29084][C-00000001] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Mar 20 09:01:56] DEBUG[29084][C-00000001] channel.c: Set channel DAHDI/i1/4989xxxxxxxxx-2 to write format alaw [Mar 20 09:01:56] DEBUG[29084][C-00000001] pbx.c: Launching 'Playback' [Mar 20 09:01:56] VERBOSE[29084][C-00000001] pbx.c: -- Executing [400@default:3] Playback("DAHDI/i1/4989xxxxxxxxx-2", "hello-world") in new stack [Mar 20 09:01:56] DEBUG[28696] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/i1/4989xxxxxxxxx-2 Variable: PLAYBACKSTATUS Value: SUCCESS Uniqueid: 1426838514.1 [Mar 20 09:01:56] DEBUG[28696] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/i1/4989xxxxxxxxx-2 Context: default Extension: 400 Priority: 3 Application: Playback AppData: hello-world Uniqueid: 1426838514.1 [Mar 20 09:01:56] DEBUG[29084][C-00000001] channel.c: Set channel DAHDI/i1/4989xxxxxxxxx-2 to write format gsm [Mar 20 09:01:56] DEBUG[29084][C-00000001] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second [Mar 20 09:01:56] VERBOSE[29084][C-00000001] file.c: -- Playing 'hello-world.gsm' (language 'de') [Mar 20 09:01:58] DEBUG[29084][C-00000001] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Mar 20 09:01:58] DEBUG[29084][C-00000001] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Mar 20 09:01:58] DEBUG[29084][C-00000001] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Mar 20 09:01:58] DEBUG[29084][C-00000001] channel.c: Set channel DAHDI/i1/4989xxxxxxxxx-2 to write format alaw [Mar 20 09:01:58] DEBUG[29084][C-00000001] pbx.c: Launching 'Playback' [Mar 20 09:01:58] VERBOSE[29084][C-00000001] pbx.c: -- Executing [400@default:4] Playback("DAHDI/i1/4989xxxxxxxxx-2", "hello-world") in new stack [Mar 20 09:01:58] DEBUG[28696] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/i1/4989xxxxxxxxx-2 Variable: PLAYBACKSTATUS Value: SUCCESS Uniqueid: 1426838514.1 [Mar 20 09:01:58] DEBUG[28696] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/i1/4989xxxxxxxxx-2 Context: default Extension: 400 Priority: 4 Application: Playback AppData: hello-world Uniqueid: 1426838514.1 [Mar 20 09:01:58] DEBUG[29084][C-00000001] channel.c: Set channel DAHDI/i1/4989xxxxxxxxx-2 to write format gsm [Mar 20 09:01:58] DEBUG[29084][C-00000001] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second [Mar 20 09:01:58] VERBOSE[29084][C-00000001] file.c: -- Playing 'hello-world.gsm' (language 'de') [Mar 20 09:01:59] DEBUG[29084][C-00000001] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Mar 20 09:01:59] DEBUG[29084][C-00000001] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Mar 20 09:01:59] DEBUG[29084][C-00000001] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Mar 20 09:01:59] DEBUG[29084][C-00000001] channel.c: Set channel DAHDI/i1/4989xxxxxxxxx-2 to write format alaw [Mar 20 09:01:59] DEBUG[29084][C-00000001] pbx.c: Launching 'Playback' [Mar 20 09:01:59] VERBOSE[29084][C-00000001] pbx.c: -- Executing [400@default:5] Playback("DAHDI/i1/4989xxxxxxxxx-2", "hello-world") in new stack [Mar 20 09:01:59] DEBUG[28696] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/i1/4989xxxxxxxxx-2 Variable: PLAYBACKSTATUS Value: SUCCESS Uniqueid: 1426838514.1 [Mar 20 09:01:59] DEBUG[28696] manager.c: Examining event: Event: Newexten Privilege: dialplan,all Channel: DAHDI/i1/4989xxxxxxxxx-2 Context: default Extension: 400 Priority: 5 Application: Playback AppData: hello-world Uniqueid: 1426838514.1 [Mar 20 09:01:59] DEBUG[29084][C-00000001] channel.c: Set channel DAHDI/i1/4989xxxxxxxxx-2 to write format gsm [Mar 20 09:01:59] DEBUG[29084][C-00000001] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second [Mar 20 09:01:59] VERBOSE[29084][C-00000001] file.c: -- Playing 'hello-world.gsm' (language 'de') [Mar 20 09:02:00] VERBOSE[28690] chan_dahdi.c: PRI Span: 1 [Mar 20 09:02:00] VERBOSE[28690] chan_dahdi.c: PRI Span: 1 < Protocol Discriminator: Q.931 (8) len=13 [Mar 20 09:02:00] VERBOSE[28690] chan_dahdi.c: PRI Span: 1 < TEI=0 Call Ref: len= 2 (reference 20682/0x50CA) (Sent from originator) [Mar 20 09:02:00] VERBOSE[28690] chan_dahdi.c: PRI Span: 1 < Message Type: DISCONNECT (69) [Mar 20 09:02:00] VERBOSE[28690] chan_dahdi.c: PRI Span: 1 < [08 02 80 90] [Mar 20 09:02:00] VERBOSE[28690] chan_dahdi.c: PRI Span: 1 < Cause (len= 4) [ Ext: 1 Coding: CCITT (ITU) standard (0) Spare: 0 Location: User (0) [Mar 20 09:02:00] VERBOSE[28690] chan_dahdi.c: PRI Span: 1 < Ext: 1 Cause: Normal Clearing (16), class = Normal Event (1) ] [Mar 20 09:02:00] VERBOSE[28690] chan_dahdi.c: PRI Span: 1 < [1e 02 82 88] [Mar 20 09:02:00] VERBOSE[28690] chan_dahdi.c: PRI Span: 1 < Progress Indicator (len= 4) [ Ext: 1 Coding: CCITT (ITU) standard (0) 0: 0 Location: Public network serving the local user (2) [Mar 20 09:02:00] VERBOSE[28690] chan_dahdi.c: PRI Span: 1 < Ext: 1 Progress Description: Inband information or appropriate pattern now available. (8) ] [Mar 20 09:02:00] VERBOSE[28690] chan_dahdi.c: PRI Span: 1 Received message for call 0x7fe9f4024350 on link 0x2c36780 TEI/SAPI 0/0 [Mar 20 09:02:00] VERBOSE[28690] chan_dahdi.c: PRI Span: 1 -- Processing IE 8 (cs0, Cause) [Mar 20 09:02:00] VERBOSE[28690] chan_dahdi.c: PRI Span: 1 -- Processing IE 30 (cs0, Progress Indicator) [Mar 20 09:02:00] VERBOSE[28690] chan_dahdi.c: PRI Span: 1 -- Found active call: 0x7fe9f4024350 cref:20682 [Mar 20 09:02:00] VERBOSE[28690] chan_dahdi.c: PRI Span: 1 q931.c:9099 post_handle_q931_message: Call 20682 enters state 12 (Disconnect Indication). Hold state: Idle [Mar 20 09:02:00] VERBOSE[28690] sig_pri.c: Span 1: Processing event PRI_EVENT_HANGUP_REQ(15) [Mar 20 09:02:00] VERBOSE[28690][C-00000001] sig_pri.c: -- Span 1: Channel 0/2 got hangup request, cause 16 [Mar 20 09:02:00] DEBUG[29084][C-00000001] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Mar 20 09:02:00] DEBUG[29084][C-00000001] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [Mar 20 09:02:00] DEBUG[29084][C-00000001] channel.c: Set channel DAHDI/i1/4989xxxxxxxxx-2 to write format alaw [Mar 20 09:02:00] DEBUG[29084][C-00000001] pbx.c: Spawn extension (default,400,5) exited non-zero on 'DAHDI/i1/4989xxxxxxxxx-2' [Mar 20 09:02:00] VERBOSE[29084][C-00000001] pbx.c: == Spawn extension (default, 400, 5) exited non-zero on 'DAHDI/i1/4989xxxxxxxxx-2' [Mar 20 09:02:00] DEBUG[29084][C-00000001] channel.c: Soft-Hanging up channel 'DAHDI/i1/4989xxxxxxxxx-2' [Mar 20 09:02:00] DEBUG[28696] manager.c: Examining event: Event: VarSet Privilege: dialplan,all Channel: DAHDI/i1/4989xxxxxxxxx-2 Variable: PLAYBACKSTATUS Value: SUCCESS Uniqueid: 1426838514.1 [Mar 20 09:02:00] DEBUG[29084][C-00000001] channel.c: Hanging up channel 'DAHDI/i1/4989xxxxxxxxx-2' [Mar 20 09:02:00] DEBUG[29084][C-00000001] chan_dahdi.c: dahdi_hangup(DAHDI/i1/4989xxxxxxxxx-2) [Mar 20 09:02:00] DEBUG[29084][C-00000001] chan_dahdi.c: Set option AUDIO MODE, value: ON(1) on DAHDI/i1/4989xxxxxxxxx-2 [Mar 20 09:02:00] DEBUG[28696] manager.c: Examining event: Event: SoftHangupRequest Privilege: call,all Channel: DAHDI/i1/4989xxxxxxxxx-2 Uniqueid: 1426838514.1 Cause: 16 [Mar 20 09:02:00] DEBUG[29084][C-00000001] sig_pri.c: sig_pri_hangup 2 [Mar 20 09:02:00] DEBUG[29084][C-00000001] sig_pri.c: Channel 'DAHDI/i1/4989xxxxxxxxx-2' MOH-Event: SIG_PRI_MOH_EVENT_RESET in state SIG_PRI_MOH_STATE_IDLE [Mar 20 09:02:00] DEBUG[29084][C-00000001] sig_pri.c: Channel 'DAHDI/i1/4989xxxxxxxxx-2' MOH-Next-State: $ [Mar 20 09:02:00] DEBUG[29084][C-00000001] sig_pri.c: Not yet hungup... Calling hangup with cause 16, and clearing call [Mar 20 09:02:00] VERBOSE[29084] chan_dahdi.c: PRI Span: 1 q931.c:7151 q931_hangup: Hangup other cref:20682 [Mar 20 09:02:00] VERBOSE[29084] chan_dahdi.c: PRI Span: 1 q931.c:6908 __q931_hangup: ourstate Disconnect Indication, peerstate Disconnect Request, hold-state Idle [Mar 20 09:02:00] VERBOSE[29084] chan_dahdi.c: PRI Span: 1 q931.c:5946 q931_release: Call 20682 enters state 19 (Release Request). Hold state: Idle [Mar 20 09:02:00] VERBOSE[29084] chan_dahdi.c: PRI Span: 1 [Mar 20 09:02:00] VERBOSE[29084] chan_dahdi.c: PRI Span: 1 > DL-DATA request [Mar 20 09:02:00] VERBOSE[29084] chan_dahdi.c: PRI Span: 1 > Protocol Discriminator: Q.931 (8) len=9 [Mar 20 09:02:00] VERBOSE[29084] chan_dahdi.c: PRI Span: 1 > TEI=0 Call Ref: len= 2 (reference 20682/0x50CA) (Sent to originator) [Mar 20 09:02:00] VERBOSE[29084] chan_dahdi.c: PRI Span: 1 > Message Type: RELEASE (77) [Mar 20 09:02:00] VERBOSE[29084] chan_dahdi.c: PRI Span: 1 TEI=0 Transmitting N(S)=6, window is open V(A)=6 K=7 [Mar 20 09:02:00] VERBOSE[29084] chan_dahdi.c: PRI Span: 1 [Mar 20 09:02:00] VERBOSE[29084] chan_dahdi.c: PRI Span: 1 > Protocol Discriminator: Q.931 (8) len=9 [Mar 20 09:02:00] VERBOSE[29084] chan_dahdi.c: PRI Span: 1 > TEI=0 Call Ref: len= 2 (reference 20682/0x50CA) (Sent to originator) [Mar 20 09:02:00] VERBOSE[29084] chan_dahdi.c: PRI Span: 1 > Message Type: RELEASE (77) [Mar 20 09:02:00] VERBOSE[29084] chan_dahdi.c: PRI Span: 1 > [08 02 81 90] [Mar 20 09:02:00] VERBOSE[29084] chan_dahdi.c: PRI Span: 1 > Cause (len= 4) [ Ext: 1 Coding: CCITT (ITU) standard (0) Spare: 0 Location: Private network serving the local user (1) [Mar 20 09:02:00] VERBOSE[29084] chan_dahdi.c: PRI Span: 1 > Ext: 1 Cause: Normal Clearing (16), class = Normal Event (1) ] [Mar 20 09:02:00] DEBUG[29084][C-00000001] chan_dahdi.c: Disabled echo cancellation on channel 2 [Mar 20 09:02:00] DEBUG[29084][C-00000001] chan_dahdi.c: Set option TDD MODE, value: OFF(0) on DAHDI/i1/4989xxxxxxxxx-2 [Mar 20 09:02:00] DEBUG[29084][C-00000001] chan_dahdi.c: Updated conferencing on 2, with 0 conference users [Mar 20 09:02:00] DEBUG[29084][C-00000001] chan_dahdi.c: Set option AUDIO MODE, value: OFF(0) on DAHDI/i1/4989xxxxxxxxx-2 [Mar 20 09:02:00] VERBOSE[29084][C-00000001] chan_dahdi.c: -- Hungup 'DAHDI/i1/4989xxxxxxxxx-2' [Mar 20 09:02:00] DEBUG[28696] manager.c: Examining event: Event: Hangup Privilege: call,all Channel: DAHDI/i1/4989xxxxxxxxx-2 Uniqueid: 1426838514.1 CallerIDNum: 4989xxxxxxxxx CallerIDName: ConnectedLineNum: ConnectedLineName: AccountCode: Cause: 16 Cause-txt: Normal Clearing [Mar 20 09:02:00] DEBUG[28682] devicestate.c: No provider found, checking channel drivers for DAHDI - i1/4989xxxxxxxxx [Mar 20 09:02:00] DEBUG[28682] devicestate.c: Changing state for DAHDI/i1/4989xxxxxxxxx - state 0 (Unknown) [Mar 20 09:02:00] DEBUG[28682] devicestate.c: device 'DAHDI/i1/4989xxxxxxxxx' state '0' [Mar 20 09:02:00] VERBOSE[28690] chan_dahdi.c: PRI Span: 1 [Mar 20 09:02:00] VERBOSE[28690] chan_dahdi.c: PRI Span: 1 < Protocol Discriminator: Q.931 (8) len=5 [Mar 20 09:02:00] VERBOSE[28690] chan_dahdi.c: PRI Span: 1 < TEI=0 Call Ref: len= 2 (reference 20682/0x50CA) (Sent from originator) [Mar 20 09:02:00] VERBOSE[28690] chan_dahdi.c: PRI Span: 1 < Message Type: RELEASE COMPLETE (90) [Mar 20 09:02:00] VERBOSE[28690] chan_dahdi.c: PRI Span: 1 Received message for call 0x7fe9f4024350 on link 0x2c36780 TEI/SAPI 0/0 [Mar 20 09:02:00] VERBOSE[28690] chan_dahdi.c: PRI Span: 1 q931.c:8959 post_handle_q931_message: Call 20682 enters state 0 (Null). Hold state: Idle [Mar 20 09:02:00] VERBOSE[28690] chan_dahdi.c: PRI Span: 1 q931.c:7151 q931_hangup: Hangup other cref:20682 [Mar 20 09:02:00] VERBOSE[28690] chan_dahdi.c: PRI Span: 1 q931.c:6908 __q931_hangup: ourstate Null, peerstate Null, hold-state Idle [Mar 20 09:02:00] VERBOSE[28690] chan_dahdi.c: PRI Span: 1 Destroying call 0x7fe9f4024350, ourstate Null, peerstate Null, hold-state Idle [Mar 20 09:02:00] VERBOSE[28690] sig_pri.c: Span 1: Processing event PRI_EVENT_HANGUP_ACK(9) [Mar 20 09:03:01] VERBOSE[29083] asterisk.c: -- Remote UNIX connection disconnected