Oct 5 12:05:19 localhost asterisk[30833]: VERBOSE[30909]: < Protocol Discriminator: Q.931 (8) len=34 Oct 5 12:05:19 localhost asterisk[30833]: VERBOSE[30909]: < Call Ref: len= 2 (reference 2544/0x9F0) (Originator) Oct 5 12:05:19 localhost asterisk[30833]: VERBOSE[30909]: < Message type: SETUP (5) Oct 5 12:05:19 localhost asterisk[30833]: VERBOSE[30909]: < [04 03 80 90 a3] Oct 5 12:05:19 localhost asterisk[30833]: VERBOSE[30909]: < Bearer Capability (len= 5) [ Ext: 1 Q.931 Std: 0 Info transfer capability: Speech (0) Oct 5 12:05:19 localhost asterisk[30833]: VERBOSE[30909]: < Ext: 1 Trans mode/rate: 64kbps, circuit-mode (16) Oct 5 12:05:19 localhost asterisk[30833]: VERBOSE[30909]: < Ext: 1 User information layer 1: A-Law (35) Oct 5 12:05:19 localhost asterisk[30833]: VERBOSE[30909]: < [18 03 a1 83 81] Oct 5 12:05:19 localhost asterisk[30833]: VERBOSE[30909]: < Channel ID (len= 5) [ Ext: 1 IntID: Implicit, PRI Spare: 0, Preferred Dchan: 0 Oct 5 12:05:19 localhost asterisk[30833]: VERBOSE[30909]: < ChanSel: Reserved Oct 5 12:05:19 localhost asterisk[30833]: VERBOSE[30909]: < Ext: 1 Coding: 0 Number Specified Channel Type: 3 Oct 5 12:05:19 localhost asterisk[30833]: VERBOSE[30909]: < Ext: 1 Channel: 1 ] Oct 5 12:05:19 localhost asterisk[30833]: VERBOSE[30909]: < [1e 02 82 81] Oct 5 12:05:19 localhost asterisk[30833]: VERBOSE[30909]: < Progress Indicator (len= 4) [ Ext: 1 Coding: CCITT (ITU) standard (0) 0: 0 Location: Public network serving the local user (2) Oct 5 12:05:19 localhost asterisk[30833]: VERBOSE[30909]: < Ext: 1 Progress Description: Call is not end-to-end ISDN; further call progress information may be available inband. (1) ] Oct 5 12:05:19 localhost asterisk[30833]: VERBOSE[30909]: < [6c 02 00 c3] Oct 5 12:05:19 localhost asterisk[30833]: VERBOSE[30909]: < Calling Number (len= 4) [ Ext: 0 TON: Unknown Number Type (0) NPI: Unknown Number Plan (0) Oct 5 12:05:19 localhost asterisk[30833]: VERBOSE[30909]: < Presentation: Number not available (67) '' ] Oct 5 12:05:19 localhost asterisk[30833]: VERBOSE[30909]: < [70 08 c1 39 30 30 39 31 30 33] Oct 5 12:05:19 localhost asterisk[30833]: VERBOSE[30909]: < Called Number (len=10) [ Ext: 1 TON: Subscriber Number (4) NPI: ISDN/Telephony Numbering Plan (E.164/E.163) (1) 'XXX9103' ] Oct 5 12:05:19 localhost asterisk[30833]: VERBOSE[30909]: < [ Oct 5 12:05:19 localhost asterisk[30833]: VERBOSE[30909]: < [a1 Oct 5 12:05:19 localhost asterisk[30833]: VERBOSE[30909]: < [a1] Oct 5 12:05:19 localhost asterisk[30833]: VERBOSE[30909]: < Sending Complete (len= 1) Oct 5 12:05:19 localhost asterisk[30833]: VERBOSE[30909]: -- Making new call for cr 2544 Oct 5 12:05:19 localhost asterisk[30833]: VERBOSE[30909]: -- Processing Q.931 Call Setup Oct 5 12:05:19 localhost asterisk[30833]: VERBOSE[30909]: -- Processing IE 4 (cs0, Bearer Capability) Oct 5 12:05:19 localhost asterisk[30833]: VERBOSE[30909]: -- Processing IE 24 (cs0, Channel Identification) Oct 5 12:05:19 localhost asterisk[30833]: VERBOSE[30909]: -- Processing IE 30 (cs0, Progress Indicator) Oct 5 12:05:19 localhost asterisk[30833]: VERBOSE[30909]: -- Processing IE 108 (cs0, Calling Party Number) Oct 5 12:05:19 localhost asterisk[30833]: VERBOSE[30909]: -- Processing IE 112 (cs0, Called Party Number) Oct 5 12:05:19 localhost asterisk[30833]: VERBOSE[30909]: -- Processing IE 161 (cs0, Sending Complete) Oct 5 12:05:19 localhost asterisk[30833]: VERBOSE[30909]: > Protocol Discriminator: Q.931 (8) len=10 Oct 5 12:05:19 localhost asterisk[30833]: VERBOSE[30909]: > Call Ref: len= 2 (reference 2544/0x9F0) (Terminator) Oct 5 12:05:19 localhost asterisk[30833]: VERBOSE[30909]: > Message type: CALL PROCEEDING (2) Oct 5 12:05:19 localhost asterisk[30833]: VERBOSE[30909]: > [18 03 a9 83 81] Oct 5 12:05:19 localhost asterisk[30833]: VERBOSE[30909]: > Channel ID (len= 5) [ Ext: 1 IntID: Implicit, PRI Spare: 0, Exclusive Dchan: 0 Oct 5 12:05:19 localhost asterisk[30833]: VERBOSE[30909]: > ChanSel: Reserved Oct 5 12:05:19 localhost asterisk[30833]: VERBOSE[30909]: > Ext: 1 Coding: 0 Number Specified Channel Type: 3 Oct 5 12:05:19 localhost asterisk[30833]: VERBOSE[30909]: > Ext: 1 Channel: 1 ] Oct 5 12:05:19 localhost asterisk[30833]: VERBOSE[30909]: -- Accepting call from '' to 'XXX9103' on channel 0/1, span 1 Oct 5 12:05:19 localhost asterisk[30833]: VERBOSE[32485]: -- Executing Goto("Zap/1-1", "test|s|1") in new stack Oct 5 12:05:19 localhost asterisk[30833]: VERBOSE[32485]: -- Goto (test,s,1) Oct 5 12:05:19 localhost asterisk[30833]: VERBOSE[32485]: -- Executing Wait("Zap/1-1", "1") in new stack Oct 5 12:05:20 localhost asterisk[30833]: VERBOSE[32485]: -- Executing Set("Zap/1-1", "TIMEOUT(digit)=5") in new stack Oct 5 12:05:20 localhost asterisk[30833]: VERBOSE[32485]: -- Digit timeout set to 5 Oct 5 12:05:20 localhost asterisk[30833]: VERBOSE[32485]: -- Executing Set("Zap/1-1", "TIMEOUT(response)=10") in new stack Oct 5 12:05:20 localhost asterisk[30833]: VERBOSE[32485]: -- Response timeout set to 10 Oct 5 12:05:20 localhost asterisk[30833]: VERBOSE[32485]: -- Executing NoOp("Zap/1-1", "XXX9103") in new stack Oct 5 12:05:20 localhost asterisk[30833]: VERBOSE[32485]: -- Executing AGI("Zap/1-1", "inbound_call.php") in new stack Oct 5 12:05:20 localhost asterisk[30833]: VERBOSE[32485]: -- Launched AGI Script /var/lib/asterisk/agi-bin/inbound_call.php Oct 5 12:05:20 localhost asterisk[30833]: VERBOSE[32485]: > inbound_call.php: VAR CALLERID not found on context(0,) Oct 5 12:05:20 localhost asterisk[30833]: VERBOSE[32485]: > Protocol Discriminator: Q.931 (8) len=14 Oct 5 12:05:20 localhost asterisk[30833]: VERBOSE[32485]: > Call Ref: len= 2 (reference 2544/0x9F0) (Terminator) Oct 5 12:05:20 localhost asterisk[30833]: VERBOSE[32485]: > Message type: CONNECT (7) Oct 5 12:05:20 localhost asterisk[30833]: VERBOSE[32485]: > [18 03 a9 83 81] Oct 5 12:05:20 localhost asterisk[30833]: VERBOSE[32485]: > Channel ID (len= 5) [ Ext: 1 IntID: Implicit, PRI Spare: 0, Exclusive Dchan: 0 Oct 5 12:05:20 localhost asterisk[30833]: VERBOSE[32485]: > ChanSel: Reserved Oct 5 12:05:20 localhost asterisk[30833]: VERBOSE[32485]: > Ext: 1 Coding: 0 Number Specified Channel Type: 3 Oct 5 12:05:20 localhost asterisk[30833]: VERBOSE[32485]: > Ext: 1 Channel: 1 ] Oct 5 12:05:20 localhost asterisk[30833]: VERBOSE[32485]: > [1e 02 81 82] Oct 5 12:05:20 localhost asterisk[30833]: VERBOSE[32485]: > Progress Indicator (len= 4) [ Ext: 1 Coding: CCITT (ITU) standard (0) 0: 0 Location: Private network serving the local user (1) Oct 5 12:05:20 localhost asterisk[30833]: WARNING[30903]: channel.c:787 in channel_find_locked: Avoided initial deadlock for '0xb7b02f18', 10 retries! Oct 5 12:05:20 localhost asterisk[30833]: VERBOSE[32485]: > Ext: 1 Progress Description: Called equipment is non-ISDN. (2) ] Oct 5 12:05:20 localhost asterisk[30833]: VERBOSE[32485]: -- AGI Script inbound_call.php completed, returning 0 Oct 5 12:05:20 localhost asterisk[30833]: VERBOSE[32485]: -- Executing Playback("Zap/1-1", "/home/tcivr/prompts/inbound/playrandom/3/101") in new stack Oct 5 12:05:20 localhost asterisk[30833]: VERBOSE[32485]: -- Playing '/home/tcivr/prompts/inbound/playrandom/3/101' (language 'en') Oct 5 12:05:20 localhost asterisk[30833]: VERBOSE[30909]: < Protocol Discriminator: Q.931 (8) len=5 Oct 5 12:05:20 localhost asterisk[30833]: VERBOSE[30909]: < Call Ref: len= 2 (reference 2544/0x9F0) (Originator) Oct 5 12:05:20 localhost asterisk[30833]: VERBOSE[30909]: < Message type: CONNECT ACKNOWLEDGE (15) Oct 5 12:05:54 localhost asterisk[30833]: VERBOSE[30909]: < Protocol Discriminator: Q.931 (8) len=9 Oct 5 12:05:54 localhost asterisk[30833]: VERBOSE[30909]: < Call Ref: len= 2 (reference 2544/0x9F0) (Originator) Oct 5 12:05:54 localhost asterisk[30833]: VERBOSE[30909]: < Message type: DISCONNECT (69) Oct 5 12:05:54 localhost asterisk[30833]: VERBOSE[30909]: < [08 02 83 91] Oct 5 12:05:54 localhost asterisk[30833]: VERBOSE[30909]: < Cause (len= 4) [ Ext: 1 Coding: CCITT (ITU) standard (0) 0: 0 Location: Transit network (3) Oct 5 12:05:54 localhost asterisk[30833]: VERBOSE[30909]: < Ext: 1 Cause: User busy (17), class = Normal Event (1) ] Oct 5 12:05:54 localhost asterisk[30833]: VERBOSE[30909]: -- Processing IE 8 (cs0, Cause) Oct 5 12:05:54 localhost asterisk[30833]: VERBOSE[30909]: -- Channel 0/1, span 1 got hangup request Oct 5 12:05:54 localhost asterisk[30833]: WARNING[32485]: file.c:1039 in ast_waitstream: Unexpected control subclass '5' Oct 5 12:06:24 localhost asterisk[30833]: VERBOSE[30909]: < Protocol Discriminator: Q.931 (8) len=9 Oct 5 12:06:24 localhost asterisk[30833]: VERBOSE[30909]: < Call Ref: len= 2 (reference 2544/0x9F0) (Originator) Oct 5 12:06:24 localhost asterisk[30833]: VERBOSE[30909]: < Message type: RELEASE (77) Oct 5 12:06:24 localhost asterisk[30833]: VERBOSE[30909]: < [08 02 83 91] Oct 5 12:06:24 localhost asterisk[30833]: VERBOSE[30909]: < Cause (len= 4) [ Ext: 1 Coding: CCITT (ITU) standard (0) 0: 0 Location: Transit network (3) Oct 5 12:06:24 localhost asterisk[30833]: VERBOSE[30909]: < Ext: 1 Cause: User busy (17), class = Normal Event (1) ] Oct 5 12:06:24 localhost asterisk[30833]: VERBOSE[30909]: -- Processing IE 8 (cs0, Cause) Oct 5 12:06:24 localhost asterisk[30833]: VERBOSE[30909]: -- Channel 0/1, span 1 got hangup Oct 5 12:06:24 localhost asterisk[30833]: WARNING[32485]: file.c:1039 in ast_waitstream: Unexpected control subclass '5' Oct 5 12:06:28 localhost asterisk[30833]: VERBOSE[30909]: < Protocol Discriminator: Q.931 (8) len=9 Oct 5 12:06:28 localhost asterisk[30833]: VERBOSE[30909]: < Call Ref: len= 2 (reference 2544/0x9F0) (Originator) Oct 5 12:06:28 localhost asterisk[30833]: VERBOSE[30909]: < Message type: RELEASE (77) Oct 5 12:06:28 localhost asterisk[30833]: VERBOSE[30909]: < [08 02 83 91] Oct 5 12:06:28 localhost asterisk[30833]: VERBOSE[30909]: < Cause (len= 4) [ Ext: 1 Coding: CCITT (ITU) standard (0) 0: 0 Location: Transit network (3) Oct 5 12:06:28 localhost asterisk[30833]: VERBOSE[30909]: < Ext: 1 Cause: User busy (17), class = Normal Event (1) ] Oct 5 12:06:28 localhost asterisk[30833]: VERBOSE[30909]: -- Processing IE 8 (cs0, Cause) Oct 5 12:06:28 localhost asterisk[30833]: VERBOSE[30909]: NEW_HANGUP DEBUG: Calling q931_hangup, ourstate Null, peerstate Release Request Oct 5 12:06:28 localhost asterisk[30833]: VERBOSE[30909]: > Protocol Discriminator: Q.931 (8) len=9 Oct 5 12:06:28 localhost asterisk[30833]: VERBOSE[30909]: > Call Ref: len= 2 (reference 2544/0x9F0) (Terminator) Oct 5 12:06:28 localhost asterisk[30833]: VERBOSE[30909]: > Message type: RELEASE COMPLETE (90) Oct 5 12:06:28 localhost asterisk[30833]: VERBOSE[30909]: > [08 02 81 91] Oct 5 12:06:28 localhost asterisk[30833]: VERBOSE[30909]: > Cause (len= 4) [ Ext: 1 Coding: CCITT (ITU) standard (0) 0: 0 Location: Private network serving the local user (1) Oct 5 12:06:28 localhost asterisk[30833]: VERBOSE[30909]: > Ext: 1 Cause: User busy (17), class = Normal Event (1) ] Oct 5 12:06:28 localhost asterisk[30833]: VERBOSE[30909]: NEW_HANGUP DEBUG: Calling q931_hangup, ourstate Null, peerstate Null Oct 5 12:06:28 localhost asterisk[30833]: VERBOSE[30909]: NEW_HANGUP DEBUG: Destroying the call, ourstate Null, peerstate Null Oct 5 12:12:48 localhost asterisk[30833]: VERBOSE[30909]: > Protocol Discriminator: Q.931 (8) len=13 Oct 5 12:12:48 localhost asterisk[30833]: VERBOSE[30909]: > Call Ref: len= 2 (reference 0/0x0) (Originator) Oct 5 12:12:48 localhost asterisk[30833]: VERBOSE[30909]: > Message type: RESTART (70) Oct 5 12:12:48 localhost asterisk[30833]: VERBOSE[30909]: > [18 03 a9 83 81] Oct 5 12:12:48 localhost asterisk[30833]: VERBOSE[30909]: > Channel ID (len= 5) [ Ext: 1 IntID: Implicit, PRI Spare: 0, Exclusive Dchan: 0 Oct 5 12:12:48 localhost asterisk[30833]: VERBOSE[30909]: > ChanSel: Reserved Oct 5 12:12:48 localhost asterisk[30833]: VERBOSE[30909]: > Ext: 1 Coding: 0 Number Specified Channel Type: 3 Oct 5 12:12:48 localhost asterisk[30833]: VERBOSE[30909]: > Ext: 1 Channel: 1 ] Oct 5 12:12:48 localhost asterisk[30833]: VERBOSE[30909]: > [79 01 80] Oct 5 12:12:48 localhost asterisk[30833]: VERBOSE[30909]: > Restart Indentifier (len= 3) [ Ext: 1 Spare: 0 Resetting Indicated Channel (0) ] Oct 5 12:12:48 localhost asterisk[30833]: VERBOSE[30909]: < Protocol Discriminator: Q.931 (8) len=13 Oct 5 12:12:48 localhost asterisk[30833]: VERBOSE[30909]: < Call Ref: len= 2 (reference 0/0x0) (Terminator) Oct 5 12:12:48 localhost asterisk[30833]: VERBOSE[30909]: < Message type: RESTART ACKNOWLEDGE (78) Oct 5 12:12:48 localhost asterisk[30833]: VERBOSE[30909]: < [18 03 a9 83 81] Oct 5 12:12:48 localhost asterisk[30833]: VERBOSE[30909]: < Channel ID (len= 5) [ Ext: 1 IntID: Implicit, PRI Spare: 0, Exclusive Dchan: 0 Oct 5 12:12:48 localhost asterisk[30833]: VERBOSE[30909]: < ChanSel: Reserved Oct 5 12:12:48 localhost asterisk[30833]: VERBOSE[30909]: < Ext: 1 Coding: 0 Number Specified Channel Type: 3 Oct 5 12:12:48 localhost asterisk[30833]: VERBOSE[30909]: < Ext: 1 Channel: 1 ] Oct 5 12:12:48 localhost asterisk[30833]: VERBOSE[30909]: < [79 01 80] Oct 5 12:12:48 localhost asterisk[30833]: VERBOSE[30909]: < Restart Indentifier (len= 3) [ Ext: 1 Spare: 0 Resetting Indicated Channel (0) ] Oct 5 12:12:48 localhost asterisk[30833]: VERBOSE[30909]: -- Processing IE 24 (cs0, Channel Identification) Oct 5 12:12:48 localhost asterisk[30833]: VERBOSE[30909]: -- Processing IE 121 (cs0, Restart Indicator) Oct 5 12:12:48 localhost asterisk[30833]: WARNING[30909]: chan_zap.c:9006 in pri_dchannel: Got restart ack on channel 0/1 span 1 with owner Oct 5 12:12:48 localhost asterisk[30833]: VERBOSE[30909]: -- B-channel 0/1 successfully restarted on span 1 Oct 5 12:12:48 localhost asterisk[30833]: VERBOSE[30909]: > Protocol Discriminator: Q.931 (8) len=13 Oct 5 12:12:48 localhost asterisk[30833]: VERBOSE[30909]: > Call Ref: len= 2 (reference 0/0x0) (Originator) Oct 5 12:12:48 localhost asterisk[30833]: VERBOSE[30909]: > Message type: RESTART (70) Oct 5 12:12:48 localhost asterisk[30833]: VERBOSE[30909]: > [18 03 a9 83 82] Oct 5 12:12:48 localhost asterisk[30833]: VERBOSE[30909]: > Channel ID (len= 5) [ Ext: 1 IntID: Implicit, PRI Spare: 0, Exclusive Dchan: 0 Oct 5 12:12:48 localhost asterisk[30833]: VERBOSE[30909]: > ChanSel: Reserved Oct 5 12:12:48 localhost asterisk[30833]: VERBOSE[30909]: > Ext: 1 Coding: 0 Number Specified Channel Type: 3 Oct 5 12:12:48 localhost asterisk[30833]: VERBOSE[30909]: > Ext: 1 Channel: 2 ] Oct 5 12:12:48 localhost asterisk[30833]: VERBOSE[30909]: > [79 01 80] Oct 5 12:12:48 localhost asterisk[30833]: VERBOSE[30909]: > Restart Indentifier (len= 3) [ Ext: 1 Spare: 0 Resetting Indicated Channel (0) ] Oct 5 12:12:48 localhost asterisk[30833]: VERBOSE[32485]: == Spawn extension (test, s, 6) exited non-zero on 'Zap/1-1' Oct 5 12:12:48 localhost asterisk[30833]: VERBOSE[32485]: -- Executing DeadAGI("Zap/1-1", "inbound_call.php") in new stack Oct 5 12:12:48 localhost asterisk[30833]: VERBOSE[32485]: -- Launched AGI Script /var/lib/asterisk/agi-bin/inbound_call.php Oct 5 12:12:48 localhost asterisk[30833]: VERBOSE[30909]: < Protocol Discriminator: Q.931 (8) len=13 Oct 5 12:12:48 localhost asterisk[30833]: VERBOSE[30909]: < Call Ref: len= 2 (reference 0/0x0) (Terminator) Oct 5 12:12:48 localhost asterisk[30833]: VERBOSE[30909]: < Message type: RESTART ACKNOWLEDGE (78) Oct 5 12:12:48 localhost asterisk[30833]: VERBOSE[30909]: < [18 03 a9 83 82] Oct 5 12:12:48 localhost asterisk[30833]: VERBOSE[30909]: < Channel ID (len= 5) [ Ext: 1 IntID: Implicit, PRI Spare: 0, Exclusive Dchan: 0 Oct 5 12:12:48 localhost asterisk[30833]: VERBOSE[30909]: < ChanSel: Reserved Oct 5 12:12:48 localhost asterisk[30833]: VERBOSE[30909]: < Ext: 1 Coding: 0 Number Specified Channel Type: 3 Oct 5 12:12:48 localhost asterisk[30833]: VERBOSE[30909]: < Ext: 1 Channel: 2 ] Oct 5 12:12:49 localhost asterisk[30833]: VERBOSE[30909]: < [79 01 80] Oct 5 12:12:49 localhost asterisk[30833]: VERBOSE[30909]: < Restart Indentifier (len= 3) [ Ext: 1 Spare: 0 Resetting Indicated Channel (0) ] Oct 5 12:12:49 localhost asterisk[30833]: VERBOSE[30909]: -- Processing IE 24 (cs0, Channel Identification) Oct 5 12:12:49 localhost asterisk[30833]: VERBOSE[30909]: -- Processing IE 121 (cs0, Restart Indicator) Oct 5 12:12:49 localhost asterisk[30833]: VERBOSE[30909]: -- B-channel 0/2 successfully restarted on span 1 Oct 5 12:12:49 localhost asterisk[30833]: VERBOSE[30909]: > Protocol Discriminator: Q.931 (8) len=13 Oct 5 12:12:49 localhost asterisk[30833]: VERBOSE[30909]: > Call Ref: len= 2 (reference 0/0x0) (Originator) Oct 5 12:12:49 localhost asterisk[30833]: VERBOSE[30909]: > Message type: RESTART (70) Oct 5 12:12:49 localhost asterisk[30833]: VERBOSE[30909]: > [18 03 a9 83 83] Oct 5 12:12:49 localhost asterisk[30833]: VERBOSE[30909]: > Channel ID (len= 5) [ Ext: 1 IntID: Implicit, PRI Spare: 0, Exclusive Dchan: 0 Oct 5 12:12:49 localhost asterisk[30833]: VERBOSE[30909]: > ChanSel: Reserved Oct 5 12:12:49 localhost asterisk[30833]: VERBOSE[30909]: > Ext: 1 Coding: 0 Number Specified Channel Type: 3 Oct 5 12:12:49 localhost asterisk[30833]: VERBOSE[30909]: > Ext: 1 Channel: 3 ] Oct 5 12:12:49 localhost asterisk[30833]: VERBOSE[30909]: > [79 01 80] Oct 5 12:12:49 localhost asterisk[30833]: VERBOSE[30909]: > Restart Indentifier (len= 3) [ Ext: 1 Spare: 0 Resetting Indicated Channel (0) ] Oct 5 12:12:49 localhost asterisk[30833]: VERBOSE[32485]: > inbound_call.php: VAR CALLERID not found on context(0,) Oct 5 12:12:49 localhost asterisk[30833]: VERBOSE[32485]: > inbound_call.php: VAR TC_CDRDONE not found on context(0,) Oct 5 12:12:49 localhost asterisk[30833]: VERBOSE[32485]: -- AGI Script inbound_call.php completed, returning 0 Oct 5 12:12:49 localhost asterisk[30833]: VERBOSE[32485]: -- Hungup 'Zap/1-1'