Jan 25 21:26:46 VERBOSE[10638] logger.c: Asterisk Event Logger restarted Jan 25 21:26:46 VERBOSE[10638] logger.c: Asterisk Queue Logger restarted Jan 25 21:26:52 VERBOSE[13281] logger.c: T203 counter expired, sending RR and scheduling T203 again Jan 25 21:26:52 VERBOSE[13281] logger.c: Sending Receiver Ready (30) Jan 25 21:26:52 VERBOSE[13281] logger.c: > [ 00 01 01 3d ] Jan 25 21:26:52 VERBOSE[13281] logger.c: > Supervisory frame: Jan 25 21:26:52 VERBOSE[13281] logger.c: > SAPI: 00 C/R: 0 EA: 0 > TEI: 000 EA: 1 Jan 25 21:26:52 VERBOSE[13281] logger.c: > Zero: 0 S: 0 01: 1 [ RR (receive ready) ] > N(R): 030 P/F: 1 > 0 bytes of data Jan 25 21:26:52 VERBOSE[13281] logger.c: -- Restarting T203 counter Jan 25 21:26:52 VERBOSE[13281] logger.c: < [ 00 01 01 3d ] Jan 25 21:26:52 VERBOSE[13281] logger.c: < Supervisory frame: Jan 25 21:26:52 VERBOSE[13281] logger.c: < SAPI: 00 C/R: 0 EA: 0 < TEI: 000 EA: 1 Jan 25 21:26:52 VERBOSE[13281] logger.c: < Zero: 0 S: 0 01: 1 [ RR (receive ready) ] < N(R): 030 P/F: 1 < 0 bytes of data Jan 25 21:26:52 VERBOSE[13281] logger.c: -- ACKing all packets from 29 to (but not including) 30 Jan 25 21:26:52 VERBOSE[13281] logger.c: -- Since there was nothing left, stopping T200 counter Jan 25 21:26:52 VERBOSE[13281] logger.c: -- Stopping T203 counter since we got an ACK Jan 25 21:26:52 VERBOSE[13281] logger.c: -- Nothing left, starting T203 counter Jan 25 21:26:52 VERBOSE[13281] logger.c: -- Got RR response to our frame Jan 25 21:26:52 VERBOSE[13281] logger.c: -- Restarting T203 counter Jan 25 21:27:02 VERBOSE[13281] logger.c: T203 counter expired, sending RR and scheduling T203 again Jan 25 21:27:02 VERBOSE[13281] logger.c: Sending Receiver Ready (30) Jan 25 21:27:02 VERBOSE[13281] logger.c: > [ 00 01 01 3d ] Jan 25 21:27:02 VERBOSE[13281] logger.c: > Supervisory frame: Jan 25 21:27:02 VERBOSE[13281] logger.c: > SAPI: 00 C/R: 0 EA: 0 > TEI: 000 EA: 1 Jan 25 21:27:02 VERBOSE[13281] logger.c: > Zero: 0 S: 0 01: 1 [ RR (receive ready) ] > N(R): 030 P/F: 1 > 0 bytes of data Jan 25 21:27:02 VERBOSE[13281] logger.c: -- Restarting T203 counter Jan 25 21:27:02 VERBOSE[13281] logger.c: < [ 00 01 01 3d ] Jan 25 21:27:02 VERBOSE[13281] logger.c: < Supervisory frame: Jan 25 21:27:02 VERBOSE[13281] logger.c: < SAPI: 00 C/R: 0 EA: 0 < TEI: 000 EA: 1 Jan 25 21:27:02 VERBOSE[13281] logger.c: < Zero: 0 S: 0 01: 1 [ RR (receive ready) ] < N(R): 030 P/F: 1 < 0 bytes of data Jan 25 21:27:02 VERBOSE[13281] logger.c: -- ACKing all packets from 29 to (but not including) 30 Jan 25 21:27:02 VERBOSE[13281] logger.c: -- Since there was nothing left, stopping T200 counter Jan 25 21:27:02 VERBOSE[13281] logger.c: -- Stopping T203 counter since we got an ACK Jan 25 21:27:02 VERBOSE[13281] logger.c: -- Nothing left, starting T203 counter Jan 25 21:27:02 VERBOSE[13281] logger.c: -- Got RR response to our frame Jan 25 21:27:02 VERBOSE[13281] logger.c: -- Restarting T203 counter Jan 25 21:27:12 VERBOSE[13281] logger.c: T203 counter expired, sending RR and scheduling T203 again Jan 25 21:27:12 VERBOSE[13281] logger.c: Sending Receiver Ready (30) Jan 25 21:27:12 VERBOSE[13281] logger.c: > [ 00 01 01 3d ] Jan 25 21:27:12 VERBOSE[13281] logger.c: > Supervisory frame: Jan 25 21:27:12 VERBOSE[13281] logger.c: > SAPI: 00 C/R: 0 EA: 0 > TEI: 000 EA: 1 Jan 25 21:27:12 VERBOSE[13281] logger.c: > Zero: 0 S: 0 01: 1 [ RR (receive ready) ] > N(R): 030 P/F: 1 > 0 bytes of data Jan 25 21:27:12 VERBOSE[13281] logger.c: -- Restarting T203 counter Jan 25 21:27:12 VERBOSE[13281] logger.c: < [ 00 01 01 3d ] Jan 25 21:27:12 VERBOSE[13281] logger.c: < Supervisory frame: Jan 25 21:27:12 VERBOSE[13281] logger.c: < SAPI: 00 C/R: 0 EA: 0 < TEI: 000 EA: 1 Jan 25 21:27:12 VERBOSE[13281] logger.c: < Zero: 0 S: 0 01: 1 [ RR (receive ready) ] < N(R): 030 P/F: 1 < 0 bytes of data Jan 25 21:27:12 VERBOSE[13281] logger.c: -- ACKing all packets from 29 to (but not including) 30 Jan 25 21:27:12 VERBOSE[13281] logger.c: -- Since there was nothing left, stopping T200 counter Jan 25 21:27:12 VERBOSE[13281] logger.c: -- Stopping T203 counter since we got an ACK Jan 25 21:27:12 VERBOSE[13281] logger.c: -- Nothing left, starting T203 counter Jan 25 21:27:12 VERBOSE[13281] logger.c: -- Got RR response to our frame Jan 25 21:27:12 VERBOSE[13281] logger.c: -- Restarting T203 counter Jan 25 21:27:22 VERBOSE[13281] logger.c: T203 counter expired, sending RR and scheduling T203 again Jan 25 21:27:22 VERBOSE[13281] logger.c: Sending Receiver Ready (30) Jan 25 21:27:22 VERBOSE[13281] logger.c: > [ 00 01 01 3d ] Jan 25 21:27:22 VERBOSE[13281] logger.c: > Supervisory frame: Jan 25 21:27:22 VERBOSE[13281] logger.c: > SAPI: 00 C/R: 0 EA: 0 > TEI: 000 EA: 1 Jan 25 21:27:22 VERBOSE[13281] logger.c: > Zero: 0 S: 0 01: 1 [ RR (receive ready) ] > N(R): 030 P/F: 1 > 0 bytes of data Jan 25 21:27:22 VERBOSE[13281] logger.c: -- Restarting T203 counter Jan 25 21:27:22 VERBOSE[13281] logger.c: < [ 00 01 01 3d ] Jan 25 21:27:22 VERBOSE[13281] logger.c: < Supervisory frame: Jan 25 21:27:22 VERBOSE[13281] logger.c: < SAPI: 00 C/R: 0 EA: 0 < TEI: 000 EA: 1 Jan 25 21:27:22 VERBOSE[13281] logger.c: < Zero: 0 S: 0 01: 1 [ RR (receive ready) ] < N(R): 030 P/F: 1 < 0 bytes of data Jan 25 21:27:22 VERBOSE[13281] logger.c: -- ACKing all packets from 29 to (but not including) 30 Jan 25 21:27:22 VERBOSE[13281] logger.c: -- Since there was nothing left, stopping T200 counter Jan 25 21:27:22 VERBOSE[13281] logger.c: -- Stopping T203 counter since we got an ACK Jan 25 21:27:22 VERBOSE[13281] logger.c: -- Nothing left, starting T203 counter Jan 25 21:27:22 VERBOSE[13281] logger.c: -- Got RR response to our frame Jan 25 21:27:22 VERBOSE[13281] logger.c: -- Restarting T203 counter Jan 25 21:27:32 VERBOSE[13281] logger.c: T203 counter expired, sending RR and scheduling T203 again Jan 25 21:27:32 VERBOSE[13281] logger.c: Sending Receiver Ready (30) Jan 25 21:27:32 VERBOSE[13281] logger.c: > [ 00 01 01 3d ] Jan 25 21:27:32 VERBOSE[13281] logger.c: > Supervisory frame: Jan 25 21:27:32 VERBOSE[13281] logger.c: > SAPI: 00 C/R: 0 EA: 0 > TEI: 000 EA: 1 Jan 25 21:27:32 VERBOSE[13281] logger.c: > Zero: 0 S: 0 01: 1 [ RR (receive ready) ] > N(R): 030 P/F: 1 > 0 bytes of data Jan 25 21:27:32 VERBOSE[13281] logger.c: -- Restarting T203 counter Jan 25 21:27:32 VERBOSE[13281] logger.c: < [ 00 01 01 3d ] Jan 25 21:27:32 VERBOSE[13281] logger.c: < Supervisory frame: Jan 25 21:27:32 VERBOSE[13281] logger.c: < SAPI: 00 C/R: 0 EA: 0 < TEI: 000 EA: 1 Jan 25 21:27:32 VERBOSE[13281] logger.c: < Zero: 0 S: 0 01: 1 [ RR (receive ready) ] < N(R): 030 P/F: 1 < 0 bytes of data Jan 25 21:27:32 VERBOSE[13281] logger.c: -- ACKing all packets from 29 to (but not including) 30 Jan 25 21:27:32 VERBOSE[13281] logger.c: -- Since there was nothing left, stopping T200 counter Jan 25 21:27:32 VERBOSE[13281] logger.c: -- Stopping T203 counter since we got an ACK Jan 25 21:27:32 VERBOSE[13281] logger.c: -- Nothing left, starting T203 counter Jan 25 21:27:32 VERBOSE[13281] logger.c: -- Got RR response to our frame Jan 25 21:27:32 VERBOSE[13281] logger.c: -- Restarting T203 counter Jan 25 21:27:42 VERBOSE[13281] logger.c: T203 counter expired, sending RR and scheduling T203 again Jan 25 21:27:42 VERBOSE[13281] logger.c: Sending Receiver Ready (30) Jan 25 21:27:42 VERBOSE[13281] logger.c: > [ 00 01 01 3d ] Jan 25 21:27:42 VERBOSE[13281] logger.c: > Supervisory frame: Jan 25 21:27:42 VERBOSE[13281] logger.c: > SAPI: 00 C/R: 0 EA: 0 > TEI: 000 EA: 1 Jan 25 21:27:42 VERBOSE[13281] logger.c: > Zero: 0 S: 0 01: 1 [ RR (receive ready) ] > N(R): 030 P/F: 1 > 0 bytes of data Jan 25 21:27:42 VERBOSE[13281] logger.c: -- Restarting T203 counter Jan 25 21:27:42 VERBOSE[13281] logger.c: < [ 00 01 01 3d ] Jan 25 21:27:42 VERBOSE[13281] logger.c: < Supervisory frame: Jan 25 21:27:42 VERBOSE[13281] logger.c: < SAPI: 00 C/R: 0 EA: 0 < TEI: 000 EA: 1 Jan 25 21:27:42 VERBOSE[13281] logger.c: < Zero: 0 S: 0 01: 1 [ RR (receive ready) ] < N(R): 030 P/F: 1 < 0 bytes of data Jan 25 21:27:42 VERBOSE[13281] logger.c: -- ACKing all packets from 29 to (but not including) 30 Jan 25 21:27:42 VERBOSE[13281] logger.c: -- Since there was nothing left, stopping T200 counter Jan 25 21:27:42 VERBOSE[13281] logger.c: -- Stopping T203 counter since we got an ACK Jan 25 21:27:42 VERBOSE[13281] logger.c: -- Nothing left, starting T203 counter Jan 25 21:27:42 VERBOSE[13281] logger.c: -- Got RR response to our frame Jan 25 21:27:42 VERBOSE[13281] logger.c: -- Restarting T203 counter Jan 25 21:27:52 VERBOSE[13281] logger.c: T203 counter expired, sending RR and scheduling T203 again Jan 25 21:27:52 VERBOSE[13281] logger.c: Sending Receiver Ready (30) Jan 25 21:27:52 VERBOSE[13281] logger.c: > [ 00 01 01 3d ] Jan 25 21:27:52 VERBOSE[13281] logger.c: > Supervisory frame: Jan 25 21:27:52 VERBOSE[13281] logger.c: > SAPI: 00 C/R: 0 EA: 0 > TEI: 000 EA: 1 Jan 25 21:27:52 VERBOSE[13281] logger.c: > Zero: 0 S: 0 01: 1 [ RR (receive ready) ] > N(R): 030 P/F: 1 > 0 bytes of data Jan 25 21:27:52 VERBOSE[13281] logger.c: -- Restarting T203 counter Jan 25 21:27:52 VERBOSE[13281] logger.c: < [ 00 01 01 3d ] Jan 25 21:27:52 VERBOSE[13281] logger.c: < Supervisory frame: Jan 25 21:27:52 VERBOSE[13281] logger.c: < SAPI: 00 C/R: 0 EA: 0 < TEI: 000 EA: 1 Jan 25 21:27:52 VERBOSE[13281] logger.c: < Zero: 0 S: 0 01: 1 [ RR (receive ready) ] < N(R): 030 P/F: 1 < 0 bytes of data Jan 25 21:27:52 VERBOSE[13281] logger.c: -- ACKing all packets from 29 to (but not including) 30 Jan 25 21:27:52 VERBOSE[13281] logger.c: -- Since there was nothing left, stopping T200 counter Jan 25 21:27:52 VERBOSE[13281] logger.c: -- Stopping T203 counter since we got an ACK Jan 25 21:27:52 VERBOSE[13281] logger.c: -- Nothing left, starting T203 counter Jan 25 21:27:52 VERBOSE[13281] logger.c: -- Got RR response to our frame Jan 25 21:27:52 VERBOSE[13281] logger.c: -- Restarting T203 counter Jan 25 21:27:57 VERBOSE[13281] logger.c: < [ 02 01 3c 3c 08 02 09 00 05 04 03 90 90 a3 18 03 a9 83 89 1e 02 84 83 1e 02 a1 90 6c 0c 21 83 31 32 32 35 37 39 30 36 37 35 70 05 c9 34 30 30 31 a1 95 31 01 80 ] Jan 25 21:27:57 VERBOSE[13281] logger.c: < Informational frame: Jan 25 21:27:57 VERBOSE[13281] logger.c: < SAPI: 00 C/R: 1 EA: 0 < TEI: 000 EA: 1 Jan 25 21:27:57 VERBOSE[13281] logger.c: < N(S): 030 0: 0 < N(R): 030 P: 0 < 49 bytes of data Jan 25 21:27:57 VERBOSE[13281] logger.c: -- ACKing all packets from 29 to (but not including) 30 Jan 25 21:27:57 VERBOSE[13281] logger.c: -- Since there was nothing left, stopping T200 counter Jan 25 21:27:57 VERBOSE[13281] logger.c: -- Stopping T203 counter since we got an ACK Jan 25 21:27:57 VERBOSE[13281] logger.c: -- Nothing left, starting T203 counter Jan 25 21:27:57 VERBOSE[13281] logger.c: < Protocol Discriminator: Q.931 (8) len=49 Jan 25 21:27:57 VERBOSE[13281] logger.c: < Call Ref: len= 2 (reference 2304/0x900) (Originator) Jan 25 21:27:57 VERBOSE[13281] logger.c: < Message type: SETUP (5) Jan 25 21:27:57 VERBOSE[13281] logger.c: < [04 03 90 90 a3] Jan 25 21:27:57 VERBOSE[13281] logger.c: < Bearer Capability (len= 5) [ Ext: 1 Q.931 Std: 0 Info transfer capability: 3.1kHz audio (16) Jan 25 21:27:57 VERBOSE[13281] logger.c: < Ext: 1 Trans mode/rate: 64kbps, circuit-mode (16) Jan 25 21:27:57 VERBOSE[13281] logger.c: < Ext: 1 User information layer 1: A-Law (35) Jan 25 21:27:57 VERBOSE[13281] logger.c: < [18 03 a9 83 89] Jan 25 21:27:57 VERBOSE[13281] logger.c: < Channel ID (len= 5) [ Ext: 1 IntID: Implicit PRI Spare: 0 Exclusive Dchan: 0 Jan 25 21:27:57 VERBOSE[13281] logger.c: < ChanSel: Reserved Jan 25 21:27:57 VERBOSE[13281] logger.c: < Ext: 1 Coding: 0 Number Specified Channel Type: 3 Jan 25 21:27:57 VERBOSE[13281] logger.c: < Ext: 1 Channel: 9 ] Jan 25 21:27:57 VERBOSE[13281] logger.c: < [1e 02 84 83] Jan 25 21:27:57 VERBOSE[13281] logger.c: < Progress Indicator (len= 4) [ Ext: 1 Coding: CCITT (ITU) standard (0) 0: 0 Location: Public network serving the remote user (4) Jan 25 21:27:57 VERBOSE[13281] logger.c: < Ext: 1 Progress Description: Calling equipment is non-ISDN. (3) ] Jan 25 21:27:57 VERBOSE[13281] logger.c: < [1e 02 a1 90] Jan 25 21:27:57 VERBOSE[13281] logger.c: < Progress Indicator (len= 4) [ Ext: 1 Coding: Non-ITU international standard (1) 0: 0 Location: Private network serving the local user (1) Jan 25 21:27:57 VERBOSE[13281] logger.c: < Ext: 1 Progress Description: Interworking with a public network. (16) ] Jan 25 21:27:57 VERBOSE[13281] logger.c: < [6c 0c 21 83 31 32 32 35 37 39 30 36 37 35] Jan 25 21:27:57 VERBOSE[13281] logger.c: < Calling Number (len=14) [ Ext: 0 TON: National Number (2) NPI: ISDN/Telephony Numbering Plan (E.164/E.163) (1) Jan 25 21:27:57 VERBOSE[13281] logger.c: < Presentation: Presentation allowed of network provided number (3) '' ] Jan 25 21:27:57 VERBOSE[13281] logger.c: < [70 05 c9 34 30 30 31] Jan 25 21:27:57 VERBOSE[13281] logger.c: < Called Number (len= 7) [ Ext: 1 TON: Subscriber Number (4) NPI: Private Numbering Plan (9) '4001' ] Jan 25 21:27:57 VERBOSE[13281] logger.c: < [a1] Jan 25 21:27:57 VERBOSE[13281] logger.c: < Sending Complete (len= 1) Jan 25 21:27:57 VERBOSE[13281] logger.c: < [95] Jan 25 21:27:57 VERBOSE[13281] logger.c: < Locking Shift (len=01): Requested codeset 5 Jan 25 21:27:57 VERBOSE[13281] logger.c: < [31 01 80] Jan 25 21:27:57 VERBOSE[13281] logger.c: !! < Unknown IE 49 (cs5, len = 3) Jan 25 21:27:57 VERBOSE[13281] logger.c: !! Unknown IE 49 (cs5, Unknown Information Element) Jan 25 21:27:57 VERBOSE[13281] logger.c: Sending Receiver Ready (31) Jan 25 21:27:57 VERBOSE[13281] logger.c: > [ 02 01 01 3e ] Jan 25 21:27:57 VERBOSE[13281] logger.c: > Supervisory frame: Jan 25 21:27:57 VERBOSE[13281] logger.c: > SAPI: 00 C/R: 1 EA: 0 > TEI: 000 EA: 1 Jan 25 21:27:57 VERBOSE[13281] logger.c: > Zero: 0 S: 0 01: 1 [ RR (receive ready) ] > N(R): 031 P/F: 0 > 0 bytes of data Jan 25 21:27:57 VERBOSE[13281] logger.c: -- Restarting T203 counter Jan 25 21:27:57 VERBOSE[13281] logger.c: -- Restarting T203 counter Jan 25 21:27:57 VERBOSE[13281] logger.c: > [ 00 01 3c 3e 08 02 89 00 02 18 03 a9 83 89 ] Jan 25 21:27:57 VERBOSE[13281] logger.c: > Informational frame: Jan 25 21:27:57 VERBOSE[13281] logger.c: > SAPI: 00 C/R: 0 EA: 0 > TEI: 000 EA: 1 Jan 25 21:27:57 VERBOSE[13281] logger.c: > N(S): 030 0: 0 > N(R): 031 P: 0 > 10 bytes of data Jan 25 21:27:57 VERBOSE[13281] logger.c: -- Restarting T203 counter Jan 25 21:27:57 VERBOSE[13281] logger.c: Stopping T_203 timer Jan 25 21:27:57 VERBOSE[13281] logger.c: Starting T_200 timer Jan 25 21:27:57 VERBOSE[13281] logger.c: > Protocol Discriminator: Q.931 (8) len=10 Jan 25 21:27:57 VERBOSE[13281] logger.c: > Call Ref: len= 2 (reference 2304/0x900) (Terminator) Jan 25 21:27:57 VERBOSE[13281] logger.c: > Message type: CALL PROCEEDING (2) Jan 25 21:27:57 VERBOSE[13281] logger.c: > [18 03 a9 83 89] Jan 25 21:27:57 VERBOSE[13281] logger.c: > Channel ID (len= 5) [ Ext: 1 IntID: Implicit PRI Spare: 0 Exclusive Dchan: 0 Jan 25 21:27:57 VERBOSE[13281] logger.c: > ChanSel: Reserved Jan 25 21:27:57 VERBOSE[13281] logger.c: > Ext: 1 Coding: 0 Number Specified Channel Type: 3 Jan 25 21:27:57 VERBOSE[13281] logger.c: > Ext: 1 Channel: 9 ] Jan 25 21:27:57 VERBOSE[13281] logger.c: -- Accepting call from '' to '' on channel 0/9, span 1 Jan 25 21:27:57 DEBUG[13281] chan_zap.c: No echo cancellation requested Jan 25 21:27:57 DEBUG[13288] pbx.c: Launching 'Dial' Jan 25 21:27:57 DEBUG[13271] devicestate.c: Changing state for Zap/9 - state 2 (In use) Jan 25 21:27:57 DEBUG[13289] app_queue.c: Device 'Zap/9' changed to state '2' (In use) but we don't care because they're not a member of any queue. Jan 25 21:27:57 VERBOSE[13288] logger.c: -- Executing Dial("Zap/9-1", "ZAP/g1/") in new stack Jan 25 21:27:57 DEBUG[13288] chan_zap.c: Using channel 1 Jan 25 21:27:57 DEBUG[13288] channel.c: Not copying variable STACK-inbound--1. Jan 25 21:27:57 DEBUG[13288] channel.c: Not copying variable CALLEDTON. Jan 25 21:27:57 DEBUG[13288] channel.c: Not copying variable ANI2. Jan 25 21:27:57 DEBUG[13288] channel.c: Not copying variable TRANSFERCAPABILITY. Jan 25 21:27:57 VERBOSE[13288] logger.c: -- Requested transfer capability: 0x10 - 3K1AUDIO Jan 25 21:27:57 VERBOSE[13288] logger.c: > [ 00 01 3e 3e 08 02 00 02 05 04 03 90 90 a3 18 03 a9 83 81 6c 0c 21 81 31 32 32 35 37 39 30 36 37 35 70 0d 91 39 30 37 38 38 31 36 32 36 30 39 38 ] Jan 25 21:27:57 VERBOSE[13288] logger.c: > Informational frame: Jan 25 21:27:57 VERBOSE[13288] logger.c: > SAPI: 00 C/R: 0 EA: 0 > TEI: 000 EA: 1 Jan 25 21:27:57 VERBOSE[13288] logger.c: > N(S): 031 0: 0 > N(R): 031 P: 0 > 44 bytes of data Jan 25 21:27:57 VERBOSE[13288] logger.c: T_200 timer already going (2) Jan 25 21:27:57 VERBOSE[13288] logger.c: > Protocol Discriminator: Q.931 (8) len=44 Jan 25 21:27:57 VERBOSE[13288] logger.c: > Call Ref: len= 2 (reference 2/0x2) (Originator) Jan 25 21:27:57 DEBUG[13271] channel.c: Avoiding initial deadlock for 'Zap/1-1' Jan 25 21:27:57 VERBOSE[13288] logger.c: > Message type: SETUP (5) Jan 25 21:27:57 VERBOSE[13288] logger.c: > [04 03 90 90 a3] Jan 25 21:27:57 VERBOSE[13288] logger.c: > Bearer Capability (len= 5) [ Ext: 1 Q.931 Std: 0 Info transfer capability: 3.1kHz audio (16) Jan 25 21:27:57 VERBOSE[13288] logger.c: > Ext: 1 Trans mode/rate: 64kbps, circuit-mode (16) Jan 25 21:27:57 VERBOSE[13288] logger.c: > Ext: 1 User information layer 1: A-Law (35) Jan 25 21:27:57 VERBOSE[13288] logger.c: > [18 03 a9 83 81] Jan 25 21:27:57 VERBOSE[13288] logger.c: > Channel ID (len= 5) [ Ext: 1 IntID: Implicit PRI Spare: 0 Exclusive Dchan: 0 Jan 25 21:27:57 VERBOSE[13288] logger.c: > ChanSel: Reserved Jan 25 21:27:57 VERBOSE[13288] logger.c: > Ext: 1 Coding: 0 Number Specified Channel Type: 3 Jan 25 21:27:57 VERBOSE[13288] logger.c: > Ext: 1 Channel: 1 ] Jan 25 21:27:57 VERBOSE[13288] logger.c: > [6c 0c 21 81 31 32 32 35 37 39 30 36 37 35] Jan 25 21:27:57 VERBOSE[13288] logger.c: > Calling Number (len=14) [ Ext: 0 TON: National Number (2) NPI: ISDN/Telephony Numbering Plan (E.164/E.163) (1) Jan 25 21:27:57 VERBOSE[13288] logger.c: > Presentation: Presentation permitted, user number passed network screening (1) '' ] Jan 25 21:27:57 VERBOSE[13288] logger.c: > [70 0d 91 39 30 37 38 38 31 36 32 36 30 39 38] Jan 25 21:27:57 VERBOSE[13288] logger.c: > Called Number (len=15) [ Ext: 1 TON: International Number (1) NPI: ISDN/Telephony Numbering Plan (E.164/E.163) (1) '' ] Jan 25 21:27:57 VERBOSE[13288] logger.c: -- Called g1/ Jan 25 21:27:57 DEBUG[13288] channel.c: Set channel Zap/1-1 to read format slin Jan 25 21:27:57 DEBUG[13288] channel.c: Set channel Zap/9-1 to write format slin Jan 25 21:27:57 DEBUG[13288] channel.c: Set channel Zap/9-1 to read format slin Jan 25 21:27:57 DEBUG[13288] channel.c: Set channel Zap/1-1 to write format slin Jan 25 21:27:57 DEBUG[13271] devicestate.c: Changing state for Zap/1 - state 2 (In use) Jan 25 21:27:57 DEBUG[13290] app_queue.c: Device 'Zap/1' changed to state '2' (In use) but we don't care because they're not a member of any queue. Jan 25 21:27:57 DEBUG[13271] devicestate.c: Changing state for Zap/1 - state 2 (In use) Jan 25 21:27:57 DEBUG[13291] app_queue.c: Device 'Zap/1' changed to state '2' (In use) but we don't care because they're not a member of any queue. Jan 25 21:27:57 VERBOSE[13281] logger.c: < [ 00 01 01 40 ] Jan 25 21:27:57 VERBOSE[13281] logger.c: < Supervisory frame: Jan 25 21:27:57 VERBOSE[13281] logger.c: < SAPI: 00 C/R: 0 EA: 0 < TEI: 000 EA: 1 Jan 25 21:27:57 VERBOSE[13281] logger.c: < Zero: 0 S: 0 01: 1 [ RR (receive ready) ] < N(R): 032 P/F: 0 < 0 bytes of data Jan 25 21:27:57 VERBOSE[13281] logger.c: -- ACKing all packets from 29 to (but not including) 32 Jan 25 21:27:57 VERBOSE[13281] logger.c: -- ACKing packet 30, new txqueue is 31 (-1 means empty) Jan 25 21:27:57 VERBOSE[13281] logger.c: -- ACKing packet 31, new txqueue is -1 (-1 means empty) Jan 25 21:27:57 VERBOSE[13281] logger.c: -- Since there was nothing left, stopping T200 counter Jan 25 21:27:57 VERBOSE[13281] logger.c: -- Nothing left, starting T203 counter Jan 25 21:27:57 VERBOSE[13281] logger.c: -- Restarting T203 counter Jan 25 21:27:57 VERBOSE[13281] logger.c: < [ 02 01 3e 40 08 02 80 02 02 18 03 a9 83 81 ] Jan 25 21:27:57 VERBOSE[13281] logger.c: < Informational frame: Jan 25 21:27:57 VERBOSE[13281] logger.c: < SAPI: 00 C/R: 1 EA: 0 < TEI: 000 EA: 1 Jan 25 21:27:57 VERBOSE[13281] logger.c: < N(S): 031 0: 0 < N(R): 032 P: 0 < 10 bytes of data Jan 25 21:27:57 VERBOSE[13281] logger.c: -- ACKing all packets from 31 to (but not including) 32 Jan 25 21:27:57 VERBOSE[13281] logger.c: -- Since there was nothing left, stopping T200 counter Jan 25 21:27:57 VERBOSE[13281] logger.c: -- Stopping T203 counter since we got an ACK Jan 25 21:27:57 VERBOSE[13281] logger.c: -- Nothing left, starting T203 counter Jan 25 21:27:57 VERBOSE[13281] logger.c: < Protocol Discriminator: Q.931 (8) len=10 Jan 25 21:27:57 VERBOSE[13281] logger.c: < Call Ref: len= 2 (reference 2/0x2) (Terminator) Jan 25 21:27:57 VERBOSE[13281] logger.c: < Message type: CALL PROCEEDING (2) Jan 25 21:27:57 VERBOSE[13281] logger.c: < [18 03 a9 83 81] Jan 25 21:27:57 VERBOSE[13281] logger.c: < Channel ID (len= 5) [ Ext: 1 IntID: Implicit PRI Spare: 0 Exclusive Dchan: 0 Jan 25 21:27:57 VERBOSE[13281] logger.c: < ChanSel: Reserved Jan 25 21:27:57 VERBOSE[13281] logger.c: < Ext: 1 Coding: 0 Number Specified Channel Type: 3 Jan 25 21:27:57 VERBOSE[13281] logger.c: < Ext: 1 Channel: 1 ] Jan 25 21:27:57 VERBOSE[13281] logger.c: Sending Receiver Ready (32) Jan 25 21:27:57 VERBOSE[13281] logger.c: > [ 02 01 01 40 ] Jan 25 21:27:57 VERBOSE[13281] logger.c: > Supervisory frame: Jan 25 21:27:57 VERBOSE[13281] logger.c: > SAPI: 00 C/R: 1 EA: 0 > TEI: 000 EA: 1 Jan 25 21:27:57 VERBOSE[13281] logger.c: > Zero: 0 S: 0 01: 1 [ RR (receive ready) ] > N(R): 032 P/F: 0 > 0 bytes of data Jan 25 21:27:57 VERBOSE[13281] logger.c: -- Restarting T203 counter Jan 25 21:27:57 VERBOSE[13281] logger.c: -- Restarting T203 counter Jan 25 21:27:57 DEBUG[13281] chan_zap.c: Queuing frame from PRI_EVENT_PROCEEDING on channel 0/1 span 1 Jan 25 21:27:57 VERBOSE[13288] logger.c: -- Zap/1-1 is proceeding passing it to Zap/9-1 Jan 25 21:27:57 DEBUG[13288] chan_zap.c: Requested indication 15 on channel Zap/9-1 Jan 25 21:27:57 DEBUG[13288] chan_zap.c: Received AST_CONTROL_PROCEEDING on Zap/9-1 Jan 25 21:28:02 VERBOSE[13281] logger.c: T203 counter expired, sending RR and scheduling T203 again Jan 25 21:28:02 VERBOSE[13281] logger.c: Sending Receiver Ready (32) Jan 25 21:28:02 VERBOSE[13281] logger.c: > [ 00 01 01 41 ] Jan 25 21:28:02 VERBOSE[13281] logger.c: > Supervisory frame: Jan 25 21:28:02 VERBOSE[13281] logger.c: > SAPI: 00 C/R: 0 EA: 0 > TEI: 000 EA: 1 Jan 25 21:28:02 VERBOSE[13281] logger.c: > Zero: 0 S: 0 01: 1 [ RR (receive ready) ] > N(R): 032 P/F: 1 > 0 bytes of data Jan 25 21:28:02 VERBOSE[13281] logger.c: -- Restarting T203 counter Jan 25 21:28:02 VERBOSE[13281] logger.c: < [ 00 01 01 41 ] Jan 25 21:28:02 VERBOSE[13281] logger.c: < Supervisory frame: Jan 25 21:28:02 VERBOSE[13281] logger.c: < SAPI: 00 C/R: 0 EA: 0 < TEI: 000 EA: 1 Jan 25 21:28:02 VERBOSE[13281] logger.c: < Zero: 0 S: 0 01: 1 [ RR (receive ready) ] < N(R): 032 P/F: 1 < 0 bytes of data Jan 25 21:28:02 VERBOSE[13281] logger.c: -- ACKing all packets from 31 to (but not including) 32 Jan 25 21:28:02 VERBOSE[13281] logger.c: -- Since there was nothing left, stopping T200 counter Jan 25 21:28:02 VERBOSE[13281] logger.c: -- Stopping T203 counter since we got an ACK Jan 25 21:28:02 VERBOSE[13281] logger.c: -- Nothing left, starting T203 counter Jan 25 21:28:02 VERBOSE[13281] logger.c: -- Got RR response to our frame Jan 25 21:28:02 VERBOSE[13281] logger.c: -- Restarting T203 counter Jan 25 21:28:10 VERBOSE[13281] logger.c: < [ 02 01 40 40 08 02 80 02 01 1e 02 84 82 ] Jan 25 21:28:10 VERBOSE[13281] logger.c: < Informational frame: Jan 25 21:28:10 VERBOSE[13281] logger.c: < SAPI: 00 C/R: 1 EA: 0 < TEI: 000 EA: 1 Jan 25 21:28:10 VERBOSE[13281] logger.c: < N(S): 032 0: 0 < N(R): 032 P: 0 < 9 bytes of data Jan 25 21:28:10 VERBOSE[13281] logger.c: -- ACKing all packets from 31 to (but not including) 32 Jan 25 21:28:10 VERBOSE[13281] logger.c: -- Since there was nothing left, stopping T200 counter Jan 25 21:28:10 VERBOSE[13281] logger.c: -- Stopping T203 counter since we got an ACK Jan 25 21:28:10 VERBOSE[13281] logger.c: -- Nothing left, starting T203 counter Jan 25 21:28:10 VERBOSE[13281] logger.c: < Protocol Discriminator: Q.931 (8) len=9 Jan 25 21:28:10 VERBOSE[13281] logger.c: < Call Ref: len= 2 (reference 2/0x2) (Terminator) Jan 25 21:28:10 VERBOSE[13281] logger.c: < Message type: ALERTING (1) Jan 25 21:28:10 VERBOSE[13281] logger.c: < [1e 02 84 82] Jan 25 21:28:10 VERBOSE[13281] logger.c: < Progress Indicator (len= 4) [ Ext: 1 Coding: CCITT (ITU) standard (0) 0: 0 Location: Public network serving the remote user (4) Jan 25 21:28:10 VERBOSE[13281] logger.c: < Ext: 1 Progress Description: Called equipment is non-ISDN. (2) ] Jan 25 21:28:10 VERBOSE[13281] logger.c: Sending Receiver Ready (33) Jan 25 21:28:10 VERBOSE[13281] logger.c: > [ 02 01 01 42 ] Jan 25 21:28:10 VERBOSE[13281] logger.c: > Supervisory frame: Jan 25 21:28:10 VERBOSE[13281] logger.c: > SAPI: 00 C/R: 1 EA: 0 > TEI: 000 EA: 1 Jan 25 21:28:10 VERBOSE[13281] logger.c: > Zero: 0 S: 0 01: 1 [ RR (receive ready) ] > N(R): 033 P/F: 0 > 0 bytes of data Jan 25 21:28:10 VERBOSE[13281] logger.c: -- Restarting T203 counter Jan 25 21:28:10 VERBOSE[13281] logger.c: -- Restarting T203 counter Jan 25 21:28:10 DEBUG[13281] chan_zap.c: No echo cancellation requested Jan 25 21:28:10 VERBOSE[13288] logger.c: -- Zap/1-1 is ringing Jan 25 21:28:10 DEBUG[13288] chan_zap.c: Requested indication 3 on channel Zap/9-1 Jan 25 21:28:10 VERBOSE[13288] logger.c: > [ 00 01 40 42 08 02 89 00 01 1e 02 81 88 ] Jan 25 21:28:10 VERBOSE[13288] logger.c: > Informational frame: Jan 25 21:28:10 VERBOSE[13288] logger.c: > SAPI: 00 C/R: 0 EA: 0 > TEI: 000 EA: 1 Jan 25 21:28:10 VERBOSE[13288] logger.c: > N(S): 032 0: 0 > N(R): 033 P: 0 > 9 bytes of data Jan 25 21:28:10 VERBOSE[13288] logger.c: -- Restarting T203 counter Jan 25 21:28:10 VERBOSE[13288] logger.c: Stopping T_203 timer Jan 25 21:28:10 VERBOSE[13288] logger.c: Starting T_200 timer Jan 25 21:28:10 VERBOSE[13288] logger.c: > Protocol Discriminator: Q.931 (8) len=9 Jan 25 21:28:10 VERBOSE[13288] logger.c: > Call Ref: len= 2 (reference 2304/0x900) (Terminator) Jan 25 21:28:10 VERBOSE[13288] logger.c: > Message type: ALERTING (1) Jan 25 21:28:10 VERBOSE[13288] logger.c: > [1e 02 81 88] Jan 25 21:28:10 VERBOSE[13288] logger.c: > Progress Indicator (len= 4) [ Ext: 1 Coding: CCITT (ITU) standard (0) 0: 0 Location: Private network serving the local user (1) Jan 25 21:28:10 VERBOSE[13288] logger.c: > Ext: 1 Progress Description: Inband information or appropriate pattern now available. (8) ] Jan 25 21:28:10 DEBUG[13271] devicestate.c: Changing state for Zap/1 - state 6 (Ringing) Jan 25 21:28:10 DEBUG[13292] app_queue.c: Device 'Zap/1' changed to state '6' (Ringing) but we don't care because they're not a member of any queue. Jan 25 21:28:11 VERBOSE[13281] logger.c: < [ 00 01 01 42 ] Jan 25 21:28:11 VERBOSE[13281] logger.c: < Supervisory frame: Jan 25 21:28:11 VERBOSE[13281] logger.c: < SAPI: 00 C/R: 0 EA: 0 < TEI: 000 EA: 1 Jan 25 21:28:11 VERBOSE[13281] logger.c: < Zero: 0 S: 0 01: 1 [ RR (receive ready) ] < N(R): 033 P/F: 0 < 0 bytes of data Jan 25 21:28:11 VERBOSE[13281] logger.c: -- ACKing all packets from 31 to (but not including) 33 Jan 25 21:28:11 VERBOSE[13281] logger.c: -- ACKing packet 32, new txqueue is -1 (-1 means empty) Jan 25 21:28:11 VERBOSE[13281] logger.c: -- Since there was nothing left, stopping T200 counter Jan 25 21:28:11 VERBOSE[13281] logger.c: -- Nothing left, starting T203 counter Jan 25 21:28:11 VERBOSE[13281] logger.c: -- Restarting T203 counter Jan 25 21:28:11 VERBOSE[13281] logger.c: < [ 02 01 42 42 08 02 80 02 07 1e 02 a1 90 ] Jan 25 21:28:11 VERBOSE[13281] logger.c: < Informational frame: Jan 25 21:28:11 VERBOSE[13281] logger.c: < SAPI: 00 C/R: 1 EA: 0 < TEI: 000 EA: 1 Jan 25 21:28:11 VERBOSE[13281] logger.c: < N(S): 033 0: 0 < N(R): 033 P: 0 < 9 bytes of data Jan 25 21:28:11 VERBOSE[13281] logger.c: -- ACKing all packets from 32 to (but not including) 33 Jan 25 21:28:11 VERBOSE[13281] logger.c: -- Since there was nothing left, stopping T200 counter Jan 25 21:28:11 VERBOSE[13281] logger.c: -- Stopping T203 counter since we got an ACK Jan 25 21:28:11 VERBOSE[13281] logger.c: -- Nothing left, starting T203 counter Jan 25 21:28:11 VERBOSE[13281] logger.c: < Protocol Discriminator: Q.931 (8) len=9 Jan 25 21:28:11 VERBOSE[13281] logger.c: < Call Ref: len= 2 (reference 2/0x2) (Terminator) Jan 25 21:28:11 VERBOSE[13281] logger.c: < Message type: CONNECT (7) Jan 25 21:28:11 VERBOSE[13281] logger.c: < [1e 02 a1 90] Jan 25 21:28:11 VERBOSE[13281] logger.c: < Progress Indicator (len= 4) [ Ext: 1 Coding: Non-ITU international standard (1) 0: 0 Location: Private network serving the local user (1) Jan 25 21:28:11 VERBOSE[13281] logger.c: < Ext: 1 Progress Description: Interworking with a public network. (16) ] Jan 25 21:28:11 VERBOSE[13281] logger.c: > [ 00 01 42 44 08 02 00 02 0f ] Jan 25 21:28:11 VERBOSE[13281] logger.c: > Informational frame: Jan 25 21:28:11 VERBOSE[13281] logger.c: > SAPI: 00 C/R: 0 EA: 0 > TEI: 000 EA: 1 Jan 25 21:28:11 VERBOSE[13281] logger.c: > N(S): 033 0: 0 > N(R): 034 P: 0 > 5 bytes of data Jan 25 21:28:11 VERBOSE[13281] logger.c: -- Restarting T203 counter Jan 25 21:28:11 VERBOSE[13281] logger.c: Stopping T_203 timer Jan 25 21:28:11 VERBOSE[13281] logger.c: Starting T_200 timer Jan 25 21:28:11 VERBOSE[13281] logger.c: > Protocol Discriminator: Q.931 (8) len=5 Jan 25 21:28:11 VERBOSE[13281] logger.c: > Call Ref: len= 2 (reference 2/0x2) (Originator) Jan 25 21:28:11 VERBOSE[13281] logger.c: > Message type: CONNECT ACKNOWLEDGE (15) Jan 25 21:28:11 DEBUG[13281] chan_zap.c: No echo cancellation requested Jan 25 21:28:11 VERBOSE[13288] logger.c: -- Zap/1-1 answered Zap/9-1 Jan 25 21:28:11 DEBUG[13288] chan_zap.c: Requested indication -1 on channel Zap/9-1 Jan 25 21:28:11 DEBUG[13271] devicestate.c: Changing state for Zap/1 - state 2 (In use) Jan 25 21:28:11 DEBUG[13293] app_queue.c: Device 'Zap/1' changed to state '2' (In use) but we don't care because they're not a member of any queue. Jan 25 21:28:11 VERBOSE[13288] logger.c: > [ 00 01 44 44 08 02 89 00 07 18 03 a9 83 89 1e 02 81 82 ] Jan 25 21:28:11 VERBOSE[13288] logger.c: > Informational frame: Jan 25 21:28:11 VERBOSE[13288] logger.c: > SAPI: 00 C/R: 0 EA: 0 > TEI: 000 EA: 1 Jan 25 21:28:11 VERBOSE[13288] logger.c: > N(S): 034 0: 0 > N(R): 034 P: 0 > 14 bytes of data Jan 25 21:28:11 VERBOSE[13288] logger.c: T_200 timer already going (2) Jan 25 21:28:11 VERBOSE[13288] logger.c: > Protocol Discriminator: Q.931 (8) len=14 Jan 25 21:28:11 VERBOSE[13288] logger.c: > Call Ref: len= 2 (reference 2304/0x900) (Terminator) Jan 25 21:28:11 VERBOSE[13288] logger.c: > Message type: CONNECT (7) Jan 25 21:28:11 VERBOSE[13288] logger.c: > [18 03 a9 83 89] Jan 25 21:28:11 VERBOSE[13288] logger.c: > Channel ID (len= 5) [ Ext: 1 IntID: Implicit PRI Spare: 0 Exclusive Dchan: 0 Jan 25 21:28:11 VERBOSE[13288] logger.c: > ChanSel: Reserved Jan 25 21:28:11 VERBOSE[13288] logger.c: > Ext: 1 Coding: 0 Number Specified Channel Type: 3 Jan 25 21:28:11 VERBOSE[13288] logger.c: > Ext: 1 Channel: 9 ] Jan 25 21:28:11 VERBOSE[13288] logger.c: > [1e 02 81 82] Jan 25 21:28:11 VERBOSE[13288] logger.c: > Progress Indicator (len= 4) [ Ext: 1 Coding: CCITT (ITU) standard (0) 0: 0 Location: Private network serving the local user (1) Jan 25 21:28:11 VERBOSE[13288] logger.c: > Ext: 1 Progress Description: Called equipment is non-ISDN. (2) ] Jan 25 21:28:11 VERBOSE[13288] logger.c: -- Attempting native bridge of Zap/9-1 and Zap/1-1 Jan 25 21:28:11 DEBUG[13288] chan_zap.c: master: 9, slave: 1, nothingok: 0 Jan 25 21:28:11 DEBUG[13288] chan_zap.c: Stopping tones on 9/0 talking to 1/0 Jan 25 21:28:11 DEBUG[13288] chan_zap.c: Stopping tones on 1/0 talking to 9/0 Jan 25 21:28:11 DEBUG[13288] chan_zap.c: Making 1 slave to master 9 at 0 Jan 25 21:28:11 DEBUG[13288] chan_zap.c: Added 17 to conference 9/9 Jan 25 21:28:11 DEBUG[13288] chan_zap.c: Added 26 to conference 9/1 Jan 25 21:28:11 DEBUG[13288] chan_zap.c: Updated conferencing on 9, with 0 conference users Jan 25 21:28:11 DEBUG[13288] chan_zap.c: Updated conferencing on 1, with 0 conference users Jan 25 21:28:11 VERBOSE[13288] logger.c: > [ 00 01 46 44 08 02 89 00 62 1c 22 9f aa 06 80 01 00 82 01 00 8b 01 02 a1 14 02 01 01 02 01 0c 30 0c 0a 01 00 81 00 0a 01 01 02 02 80 02 ] Jan 25 21:28:11 VERBOSE[13288] logger.c: > Informational frame: Jan 25 21:28:11 VERBOSE[13288] logger.c: > SAPI: 00 C/R: 0 EA: 0 > TEI: 000 EA: 1 Jan 25 21:28:11 VERBOSE[13288] logger.c: > N(S): 035 0: 0 > N(R): 034 P: 0 > 41 bytes of data Jan 25 21:28:11 VERBOSE[13288] logger.c: T_200 timer already going (2) Jan 25 21:28:11 VERBOSE[13288] logger.c: > Protocol Discriminator: Q.931 (8) len=41 Jan 25 21:28:11 VERBOSE[13288] logger.c: > Call Ref: len= 2 (reference 2304/0x900) (Terminator) Jan 25 21:28:11 VERBOSE[13288] logger.c: > Message type: FACILITY (98) Jan 25 21:28:11 VERBOSE[13288] logger.c: > [1c 22 9f aa 06 80 01 00 82 01 00 8b 01 02 a1 14 02 01 01 02 01 0c 30 0c 0a 01 00 81 00 0a 01 01 02 02 80 02] Jan 25 21:28:11 VERBOSE[13288] logger.c: > Facility (len=36, codeset=0) [ Jan 25 21:28:11 VERBOSE[13288] logger.c: > Facility (len=36, codeset=0) [ 0x9F, 0xAA, 0x06, 0x80, 0x01, 0x00, 0x82, 0x01, 0x00, 0x8B, 0x01, 0x02, 0xA1, 0x14, 0x02, 0x01, 0x01, 0x02, 0x01, 0x0C, '0', 0x0C, 0x0A, 0x01, 0x00, 0x81, 0x00, 0x0A, 0x01, 0x01, 0x02, 0x02, 0x80, 0x02Jan 25 21:28:11 VERBOSE[13288] logger.c: > Facility (len=36, codeset=0) [ 0x9F, 0xAA, 0x06, 0x80, 0x01, 0x00, 0x82, 0x01, 0x00, 0x8B, 0x01, 0x02, 0xA1, 0x14, 0x02, 0x01, 0x01, 0x02, 0x01, 0x0C, '0', 0x0C, 0x0A, 0x01, 0x00, 0x81, 0x00, 0x0A, 0x01, 0x01, 0x02, 0x02, 0x80, 0x02 ] Jan 25 21:28:11 VERBOSE[13288] logger.c: PROTOCOL 1F Jan 25 21:28:11 VERBOSE[13288] logger.c: AA 0006Jan 25 21:28:11 VERBOSE[13288] logger.c: AA 0006 (CONTEXT SPECIFIC [10])Jan 25 21:28:11 VERBOSE[13288] logger.c: AA 0006 (CONTEXT SPECIFIC [10]) Jan 25 21:28:11 DEBUG[13271] channel.c: Avoiding initial deadlock for 'Zap/9-1' Jan 25 21:28:11 VERBOSE[13288] logger.c: 80 0001Jan 25 21:28:11 VERBOSE[13288] logger.c: 80 0001 00Jan 25 21:28:11 VERBOSE[13288] logger.c: 80 0001 00 (CONTEXT SPECIFIC [0])Jan 25 21:28:11 VERBOSE[13288] logger.c: 80 0001 00 (CONTEXT SPECIFIC [0]) Jan 25 21:28:11 VERBOSE[13288] logger.c: 82 0001Jan 25 21:28:11 VERBOSE[13288] logger.c: 82 0001 00Jan 25 21:28:11 VERBOSE[13288] logger.c: 82 0001 00 (CONTEXT SPECIFIC [2])Jan 25 21:28:11 VERBOSE[13288] logger.c: 82 0001 00 (CONTEXT SPECIFIC [2]) Jan 25 21:28:11 VERBOSE[13288] logger.c: 8B 0001Jan 25 21:28:11 VERBOSE[13288] logger.c: 8B 0001 02Jan 25 21:28:11 VERBOSE[13288] logger.c: 8B 0001 02 (CONTEXT SPECIFIC [11])Jan 25 21:28:11 VERBOSE[13288] logger.c: 8B 0001 02 (CONTEXT SPECIFIC [11]) Jan 25 21:28:11 VERBOSE[13288] logger.c: A1 0014Jan 25 21:28:11 VERBOSE[13288] logger.c: A1 0014 (CONTEXT SPECIFIC [1])Jan 25 21:28:11 VERBOSE[13288] logger.c: A1 0014 (CONTEXT SPECIFIC [1]) Jan 25 21:28:11 VERBOSE[13288] logger.c: 02 0001Jan 25 21:28:11 VERBOSE[13288] logger.c: 02 0001 01Jan 25 21:28:11 VERBOSE[13288] logger.c: 02 0001 01 (INTEGER: 1)Jan 25 21:28:11 VERBOSE[13288] logger.c: 02 0001 01 (INTEGER: 1) Jan 25 21:28:11 VERBOSE[13288] logger.c: 02 0001Jan 25 21:28:11 VERBOSE[13288] logger.c: 02 0001 0CJan 25 21:28:11 VERBOSE[13288] logger.c: 02 0001 0C (INTEGER: 12)Jan 25 21:28:11 VERBOSE[13288] logger.c: 02 0001 0C (INTEGER: 12) Jan 25 21:28:11 VERBOSE[13288] logger.c: 30 000CJan 25 21:28:11 VERBOSE[13288] logger.c: 30 000C (SEQUENCE)Jan 25 21:28:11 VERBOSE[13288] logger.c: 30 000C (SEQUENCE) Jan 25 21:28:11 VERBOSE[13288] logger.c: 0A 0001Jan 25 21:28:11 VERBOSE[13288] logger.c: 0A 0001 00Jan 25 21:28:11 VERBOSE[13288] logger.c: 0A 0001 00 (ENUMERATED: 0)Jan 25 21:28:11 VERBOSE[13288] logger.c: 0A 0001 00 (ENUMERATED: 0) Jan 25 21:28:11 VERBOSE[13288] logger.c: 81 0000Jan 25 21:28:11 VERBOSE[13288] logger.c: 81 0000 (CONTEXT SPECIFIC [1])Jan 25 21:28:11 VERBOSE[13288] logger.c: 81 0000 (CONTEXT SPECIFIC [1]) Jan 25 21:28:11 VERBOSE[13288] logger.c: 0A 0001Jan 25 21:28:11 VERBOSE[13288] logger.c: 0A 0001 01Jan 25 21:28:11 VERBOSE[13288] logger.c: 0A 0001 01 (ENUMERATED: 1)Jan 25 21:28:11 VERBOSE[13288] logger.c: 0A 0001 01 (ENUMERATED: 1) Jan 25 21:28:11 VERBOSE[13288] logger.c: 02 0002Jan 25 21:28:11 VERBOSE[13288] logger.c: 02 0002 80Jan 25 21:28:11 VERBOSE[13288] logger.c: 02 0002 80 02Jan 25 21:28:11 VERBOSE[13288] logger.c: 02 0002 80 02 (INTEGER: 32770)Jan 25 21:28:11 VERBOSE[13288] logger.c: 02 0002 80 02 (INTEGER: 32770) Jan 25 21:28:11 VERBOSE[13288] logger.c: > [ 00 01 48 44 08 02 00 02 62 1c 22 9f aa 06 80 01 00 82 01 00 8b 01 02 a1 14 02 01 02 02 01 0c 30 0c 0a 01 01 81 00 0a 01 01 02 02 80 02 ] Jan 25 21:28:11 VERBOSE[13288] logger.c: > Informational frame: Jan 25 21:28:11 VERBOSE[13288] logger.c: > SAPI: 00 C/R: 0 EA: 0 > TEI: 000 EA: 1 Jan 25 21:28:11 VERBOSE[13288] logger.c: > N(S): 036 0: 0 > N(R): 034 P: 0 > 41 bytes of data Jan 25 21:28:11 VERBOSE[13288] logger.c: T_200 timer already going (2) Jan 25 21:28:11 VERBOSE[13288] logger.c: > Protocol Discriminator: Q.931 (8) len=41 Jan 25 21:28:11 VERBOSE[13288] logger.c: > Call Ref: len= 2 (reference 2/0x2) (Originator) Jan 25 21:28:11 VERBOSE[13288] logger.c: > Message type: FACILITY (98) Jan 25 21:28:11 VERBOSE[13288] logger.c: > [1c 22 9f aa 06 80 01 00 82 01 00 8b 01 02 a1 14 02 01 02 02 01 0c 30 0c 0a 01 01 81 00 0a 01 01 02 02 80 02] Jan 25 21:28:11 VERBOSE[13288] logger.c: > Facility (len=36, codeset=0) [ Jan 25 21:28:11 VERBOSE[13288] logger.c: > Facility (len=36, codeset=0) [ 0x9F, 0xAA, 0x06, 0x80, 0x01, 0x00, 0x82, 0x01, 0x00, 0x8B, 0x01, 0x02, 0xA1, 0x14, 0x02, 0x01, 0x02, 0x02, 0x01, 0x0C, '0', 0x0C, 0x0A, 0x01, 0x01, 0x81, 0x00, 0x0A, 0x01, 0x01, 0x02, 0x02, 0x80, 0x02Jan 25 21:28:11 VERBOSE[13288] logger.c: > Facility (len=36, codeset=0) [ 0x9F, 0xAA, 0x06, 0x80, 0x01, 0x00, 0x82, 0x01, 0x00, 0x8B, 0x01, 0x02, 0xA1, 0x14, 0x02, 0x01, 0x02, 0x02, 0x01, 0x0C, '0', 0x0C, 0x0A, 0x01, 0x01, 0x81, 0x00, 0x0A, 0x01, 0x01, 0x02, 0x02, 0x80, 0x02 ] Jan 25 21:28:11 VERBOSE[13288] logger.c: PROTOCOL 1F Jan 25 21:28:11 VERBOSE[13288] logger.c: AA 0006Jan 25 21:28:11 VERBOSE[13288] logger.c: AA 0006 (CONTEXT SPECIFIC [10])Jan 25 21:28:11 VERBOSE[13288] logger.c: AA 0006 (CONTEXT SPECIFIC [10]) Jan 25 21:28:11 VERBOSE[13288] logger.c: 80 0001Jan 25 21:28:11 VERBOSE[13288] logger.c: 80 0001 00Jan 25 21:28:11 VERBOSE[13288] logger.c: 80 0001 00 (CONTEXT SPECIFIC [0])Jan 25 21:28:11 VERBOSE[13288] logger.c: 80 0001 00 (CONTEXT SPECIFIC [0]) Jan 25 21:28:11 VERBOSE[13288] logger.c: 82 0001Jan 25 21:28:11 VERBOSE[13288] logger.c: 82 0001 00Jan 25 21:28:11 VERBOSE[13288] logger.c: 82 0001 00 (CONTEXT SPECIFIC [2])Jan 25 21:28:11 VERBOSE[13288] logger.c: 82 0001 00 (CONTEXT SPECIFIC [2]) Jan 25 21:28:11 VERBOSE[13288] logger.c: 8B 0001Jan 25 21:28:11 VERBOSE[13288] logger.c: 8B 0001 02Jan 25 21:28:11 VERBOSE[13288] logger.c: 8B 0001 02 (CONTEXT SPECIFIC [11])Jan 25 21:28:11 VERBOSE[13288] logger.c: 8B 0001 02 (CONTEXT SPECIFIC [11]) Jan 25 21:28:11 VERBOSE[13288] logger.c: A1 0014Jan 25 21:28:11 VERBOSE[13288] logger.c: A1 0014 (CONTEXT SPECIFIC [1])Jan 25 21:28:11 VERBOSE[13288] logger.c: A1 0014 (CONTEXT SPECIFIC [1]) Jan 25 21:28:11 VERBOSE[13288] logger.c: 02 0001Jan 25 21:28:11 VERBOSE[13288] logger.c: 02 0001 02Jan 25 21:28:11 VERBOSE[13288] logger.c: 02 0001 02 (INTEGER: 2)Jan 25 21:28:11 VERBOSE[13288] logger.c: 02 0001 02 (INTEGER: 2) Jan 25 21:28:11 VERBOSE[13288] logger.c: 02 0001Jan 25 21:28:11 VERBOSE[13288] logger.c: 02 0001 0CJan 25 21:28:11 VERBOSE[13288] logger.c: 02 0001 0C (INTEGER: 12)Jan 25 21:28:11 VERBOSE[13288] logger.c: 02 0001 0C (INTEGER: 12) Jan 25 21:28:11 VERBOSE[13288] logger.c: 30 000CJan 25 21:28:11 VERBOSE[13288] logger.c: 30 000C (SEQUENCE)Jan 25 21:28:11 VERBOSE[13288] logger.c: 30 000C (SEQUENCE) Jan 25 21:28:11 VERBOSE[13288] logger.c: 0A 0001Jan 25 21:28:11 VERBOSE[13288] logger.c: 0A 0001 01Jan 25 21:28:11 VERBOSE[13288] logger.c: 0A 0001 01 (ENUMERATED: 1)Jan 25 21:28:11 VERBOSE[13288] logger.c: 0A 0001 01 (ENUMERATED: 1) Jan 25 21:28:11 VERBOSE[13288] logger.c: 81 0000Jan 25 21:28:11 VERBOSE[13288] logger.c: 81 0000 (CONTEXT SPECIFIC [1])Jan 25 21:28:11 VERBOSE[13288] logger.c: 81 0000 (CONTEXT SPECIFIC [1]) Jan 25 21:28:11 VERBOSE[13288] logger.c: 0A 0001Jan 25 21:28:11 VERBOSE[13288] logger.c: 0A 0001 01Jan 25 21:28:11 VERBOSE[13288] logger.c: 0A 0001 01 (ENUMERATED: 1)Jan 25 21:28:11 VERBOSE[13288] logger.c: 0A 0001 01 (ENUMERATED: 1) Jan 25 21:28:11 VERBOSE[13288] logger.c: 02 0002Jan 25 21:28:11 VERBOSE[13288] logger.c: 02 0002 80Jan 25 21:28:11 VERBOSE[13288] logger.c: 02 0002 80 02Jan 25 21:28:11 VERBOSE[13288] logger.c: 02 0002 80 02 (INTEGER: 32770)Jan 25 21:28:11 VERBOSE[13288] logger.c: 02 0002 80 02 (INTEGER: 32770) Jan 25 21:28:11 DEBUG[13271] devicestate.c: Changing state for Zap/9 - state 2 (In use) Jan 25 21:28:11 DEBUG[13294] app_queue.c: Device 'Zap/9' changed to state '2' (In use) but we don't care because they're not a member of any queue. Jan 25 21:28:11 VERBOSE[13281] logger.c: < [ 02 01 44 4a 08 02 09 00 0f ] Jan 25 21:28:11 VERBOSE[13281] logger.c: < Informational frame: Jan 25 21:28:11 VERBOSE[13281] logger.c: < SAPI: 00 C/R: 1 EA: 0 < TEI: 000 EA: 1 Jan 25 21:28:11 VERBOSE[13281] logger.c: < N(S): 034 0: 0 < N(R): 037 P: 0 < 5 bytes of data Jan 25 21:28:11 VERBOSE[13281] logger.c: -- ACKing all packets from 32 to (but not including) 37 Jan 25 21:28:11 VERBOSE[13281] logger.c: -- ACKing packet 33, new txqueue is 34 (-1 means empty) Jan 25 21:28:11 VERBOSE[13281] logger.c: -- ACKing packet 34, new txqueue is 35 (-1 means empty) Jan 25 21:28:11 VERBOSE[13281] logger.c: -- ACKing packet 35, new txqueue is 36 (-1 means empty) Jan 25 21:28:11 VERBOSE[13281] logger.c: -- ACKing packet 36, new txqueue is -1 (-1 means empty) Jan 25 21:28:11 VERBOSE[13281] logger.c: -- Since there was nothing left, stopping T200 counter Jan 25 21:28:11 VERBOSE[13281] logger.c: -- Nothing left, starting T203 counter Jan 25 21:28:11 VERBOSE[13281] logger.c: < Protocol Discriminator: Q.931 (8) len=5 Jan 25 21:28:11 VERBOSE[13281] logger.c: < Call Ref: len= 2 (reference 2304/0x900) (Originator) Jan 25 21:28:11 VERBOSE[13281] logger.c: < Message type: CONNECT ACKNOWLEDGE (15) Jan 25 21:28:11 VERBOSE[13281] logger.c: Sending Receiver Ready (35) Jan 25 21:28:11 VERBOSE[13281] logger.c: > [ 02 01 01 46 ] Jan 25 21:28:11 VERBOSE[13281] logger.c: > Supervisory frame: Jan 25 21:28:11 VERBOSE[13281] logger.c: > SAPI: 00 C/R: 1 EA: 0 > TEI: 000 EA: 1 Jan 25 21:28:11 VERBOSE[13281] logger.c: > Zero: 0 S: 0 01: 1 [ RR (receive ready) ] > N(R): 035 P/F: 0 > 0 bytes of data Jan 25 21:28:11 VERBOSE[13281] logger.c: -- Restarting T203 counter Jan 25 21:28:11 VERBOSE[13281] logger.c: -- Restarting T203 counter Jan 25 21:28:11 VERBOSE[13281] logger.c: < [ 02 01 46 4a 08 02 09 00 7d 08 02 81 e4 14 01 0a ] Jan 25 21:28:11 VERBOSE[13281] logger.c: < Informational frame: Jan 25 21:28:11 VERBOSE[13281] logger.c: < SAPI: 00 C/R: 1 EA: 0 < TEI: 000 EA: 1 Jan 25 21:28:11 VERBOSE[13281] logger.c: < N(S): 035 0: 0 < N(R): 037 P: 0 < 12 bytes of data Jan 25 21:28:11 VERBOSE[13281] logger.c: -- ACKing all packets from 36 to (but not including) 37 Jan 25 21:28:11 VERBOSE[13281] logger.c: -- Since there was nothing left, stopping T200 counter Jan 25 21:28:11 VERBOSE[13281] logger.c: -- Stopping T203 counter since we got an ACK Jan 25 21:28:11 VERBOSE[13281] logger.c: -- Nothing left, starting T203 counter Jan 25 21:28:11 VERBOSE[13281] logger.c: < Protocol Discriminator: Q.931 (8) len=12 Jan 25 21:28:11 VERBOSE[13281] logger.c: < Call Ref: len= 2 (reference 2304/0x900) (Originator) Jan 25 21:28:11 VERBOSE[13281] logger.c: < Message type: STATUS (125) Jan 25 21:28:11 VERBOSE[13281] logger.c: < [08 02 81 e4] Jan 25 21:28:11 VERBOSE[13281] logger.c: < Cause (len= 4) [ Ext: 1 Coding: CCITT (ITU) standard (0) Spare: 0 Location: Private network serving the local user (1) Jan 25 21:28:11 VERBOSE[13281] logger.c: < Ext: 1 Cause: Invalid information element contents (100), class = Protocol Error (e.g. unknown message) (6) ] Jan 25 21:28:11 VERBOSE[13281] logger.c: < [14 01 0a] Jan 25 21:28:11 VERBOSE[13281] logger.c: < Call State (len= 3) [ Ext: 0 Coding: CCITT (ITU) standard (0) Call state: Active (10) Jan 25 21:28:11 VERBOSE[13281] logger.c: Sending Receiver Ready (36) Jan 25 21:28:11 VERBOSE[13281] logger.c: > [ 02 01 01 48 ] Jan 25 21:28:11 VERBOSE[13281] logger.c: > Supervisory frame: Jan 25 21:28:11 VERBOSE[13281] logger.c: > SAPI: 00 C/R: 1 EA: 0 > TEI: 000 EA: 1 Jan 25 21:28:11 VERBOSE[13281] logger.c: > Zero: 0 S: 0 01: 1 [ RR (receive ready) ] > N(R): 036 P/F: 0 > 0 bytes of data Jan 25 21:28:11 VERBOSE[13281] logger.c: -- Restarting T203 counter Jan 25 21:28:11 VERBOSE[13281] logger.c: -- Restarting T203 counter Jan 25 21:28:11 VERBOSE[13281] logger.c: < [ 02 01 48 4a 08 02 80 02 7d 08 02 81 e4 14 01 0a ] Jan 25 21:28:11 VERBOSE[13281] logger.c: < Informational frame: Jan 25 21:28:11 VERBOSE[13281] logger.c: < SAPI: 00 C/R: 1 EA: 0 < TEI: 000 EA: 1 Jan 25 21:28:11 VERBOSE[13281] logger.c: < N(S): 036 0: 0 < N(R): 037 P: 0 < 12 bytes of data Jan 25 21:28:11 VERBOSE[13281] logger.c: -- ACKing all packets from 36 to (but not including) 37 Jan 25 21:28:11 VERBOSE[13281] logger.c: -- Since there was nothing left, stopping T200 counter Jan 25 21:28:11 VERBOSE[13281] logger.c: -- Stopping T203 counter since we got an ACK Jan 25 21:28:11 VERBOSE[13281] logger.c: -- Nothing left, starting T203 counter Jan 25 21:28:11 VERBOSE[13281] logger.c: < Protocol Discriminator: Q.931 (8) len=12 Jan 25 21:28:11 VERBOSE[13281] logger.c: < Call Ref: len= 2 (reference 2/0x2) (Terminator) Jan 25 21:28:11 VERBOSE[13281] logger.c: < Message type: STATUS (125) Jan 25 21:28:11 VERBOSE[13281] logger.c: < [08 02 81 e4] Jan 25 21:28:11 VERBOSE[13281] logger.c: < Cause (len= 4) [ Ext: 1 Coding: CCITT (ITU) standard (0) Spare: 0 Location: Private network serving the local user (1) Jan 25 21:28:11 VERBOSE[13281] logger.c: < Ext: 1 Cause: Invalid information element contents (100), class = Protocol Error (e.g. unknown message) (6) ] Jan 25 21:28:11 VERBOSE[13281] logger.c: < [14 01 0a] Jan 25 21:28:11 VERBOSE[13281] logger.c: < Call State (len= 3) [ Ext: 0 Coding: CCITT (ITU) standard (0) Call state: Active (10) Jan 25 21:28:11 VERBOSE[13281] logger.c: Sending Receiver Ready (37) Jan 25 21:28:11 VERBOSE[13281] logger.c: > [ 02 01 01 4a ] Jan 25 21:28:11 VERBOSE[13281] logger.c: > Supervisory frame: Jan 25 21:28:11 VERBOSE[13281] logger.c: > SAPI: 00 C/R: 1 EA: 0 > TEI: 000 EA: 1 Jan 25 21:28:11 VERBOSE[13281] logger.c: > Zero: 0 S: 0 01: 1 [ RR (receive ready) ] > N(R): 037 P/F: 0 > 0 bytes of data Jan 25 21:28:11 VERBOSE[13281] logger.c: -- Restarting T203 counter Jan 25 21:28:11 VERBOSE[13281] logger.c: -- Restarting T203 counter Jan 25 21:28:12 VERBOSE[13281] logger.c: T203 counter expired, sending RR and scheduling T203 again Jan 25 21:28:12 VERBOSE[13281] logger.c: Sending Receiver Ready (37) Jan 25 21:28:12 VERBOSE[13281] logger.c: > [ 00 01 01 4b ] Jan 25 21:28:12 VERBOSE[13281] logger.c: > Supervisory frame: Jan 25 21:28:12 VERBOSE[13281] logger.c: > SAPI: 00 C/R: 0 EA: 0 > TEI: 000 EA: 1 Jan 25 21:28:12 VERBOSE[13281] logger.c: > Zero: 0 S: 0 01: 1 [ RR (receive ready) ] > N(R): 037 P/F: 1 > 0 bytes of data Jan 25 21:28:12 VERBOSE[13281] logger.c: -- Restarting T203 counter Jan 25 21:28:12 VERBOSE[13281] logger.c: < [ 00 01 01 4b ] Jan 25 21:28:12 VERBOSE[13281] logger.c: < Supervisory frame: Jan 25 21:28:12 VERBOSE[13281] logger.c: < SAPI: 00 C/R: 0 EA: 0 < TEI: 000 EA: 1 Jan 25 21:28:12 VERBOSE[13281] logger.c: < Zero: 0 S: 0 01: 1 [ RR (receive ready) ] < N(R): 037 P/F: 1 < 0 bytes of data Jan 25 21:28:12 VERBOSE[13281] logger.c: -- ACKing all packets from 36 to (but not including) 37 Jan 25 21:28:12 VERBOSE[13281] logger.c: -- Since there was nothing left, stopping T200 counter Jan 25 21:28:12 VERBOSE[13281] logger.c: -- Stopping T203 counter since we got an ACK Jan 25 21:28:12 VERBOSE[13281] logger.c: -- Nothing left, starting T203 counter Jan 25 21:28:12 VERBOSE[13281] logger.c: -- Got RR response to our frame Jan 25 21:28:12 VERBOSE[13281] logger.c: -- Restarting T203 counter Jan 25 21:28:22 VERBOSE[13281] logger.c: T203 counter expired, sending RR and scheduling T203 again Jan 25 21:28:22 VERBOSE[13281] logger.c: Sending Receiver Ready (37) Jan 25 21:28:22 VERBOSE[13281] logger.c: > [ 00 01 01 4b ] Jan 25 21:28:22 VERBOSE[13281] logger.c: > Supervisory frame: Jan 25 21:28:22 VERBOSE[13281] logger.c: > SAPI: 00 C/R: 0 EA: 0 > TEI: 000 EA: 1 Jan 25 21:28:22 VERBOSE[13281] logger.c: > Zero: 0 S: 0 01: 1 [ RR (receive ready) ] > N(R): 037 P/F: 1 > 0 bytes of data Jan 25 21:28:22 VERBOSE[13281] logger.c: -- Restarting T203 counter Jan 25 21:28:22 VERBOSE[13281] logger.c: < [ 00 01 01 4b ] Jan 25 21:28:22 VERBOSE[13281] logger.c: < Supervisory frame: Jan 25 21:28:22 VERBOSE[13281] logger.c: < SAPI: 00 C/R: 0 EA: 0 < TEI: 000 EA: 1 Jan 25 21:28:22 VERBOSE[13281] logger.c: < Zero: 0 S: 0 01: 1 [ RR (receive ready) ] < N(R): 037 P/F: 1 < 0 bytes of data Jan 25 21:28:22 VERBOSE[13281] logger.c: -- ACKing all packets from 36 to (but not including) 37 Jan 25 21:28:22 VERBOSE[13281] logger.c: -- Since there was nothing left, stopping T200 counter Jan 25 21:28:22 VERBOSE[13281] logger.c: -- Stopping T203 counter since we got an ACK Jan 25 21:28:22 VERBOSE[13281] logger.c: -- Nothing left, starting T203 counter Jan 25 21:28:22 VERBOSE[13281] logger.c: -- Got RR response to our frame Jan 25 21:28:22 VERBOSE[13281] logger.c: -- Restarting T203 counter Jan 25 21:28:26 VERBOSE[13281] logger.c: < [ 02 01 4a 4a 08 02 09 00 45 08 02 81 90 ] Jan 25 21:28:26 VERBOSE[13281] logger.c: < Informational frame: Jan 25 21:28:26 VERBOSE[13281] logger.c: < SAPI: 00 C/R: 1 EA: 0 < TEI: 000 EA: 1 Jan 25 21:28:26 VERBOSE[13281] logger.c: < N(S): 037 0: 0 < N(R): 037 P: 0 < 9 bytes of data Jan 25 21:28:26 VERBOSE[13281] logger.c: -- ACKing all packets from 36 to (but not including) 37 Jan 25 21:28:26 VERBOSE[13281] logger.c: -- Since there was nothing left, stopping T200 counter Jan 25 21:28:26 VERBOSE[13281] logger.c: -- Stopping T203 counter since we got an ACK Jan 25 21:28:26 VERBOSE[13281] logger.c: -- Nothing left, starting T203 counter Jan 25 21:28:26 VERBOSE[13281] logger.c: < Protocol Discriminator: Q.931 (8) len=9 Jan 25 21:28:26 VERBOSE[13281] logger.c: < Call Ref: len= 2 (reference 2304/0x900) (Originator) Jan 25 21:28:26 VERBOSE[13281] logger.c: < Message type: DISCONNECT (69) Jan 25 21:28:26 VERBOSE[13281] logger.c: < [08 02 81 90] Jan 25 21:28:26 VERBOSE[13281] logger.c: < Cause (len= 4) [ Ext: 1 Coding: CCITT (ITU) standard (0) Spare: 0 Location: Private network serving the local user (1) Jan 25 21:28:26 VERBOSE[13281] logger.c: < Ext: 1 Cause: Normal Clearing (16), class = Normal Event (1) ] Jan 25 21:28:26 VERBOSE[13281] logger.c: Sending Receiver Ready (38) Jan 25 21:28:26 VERBOSE[13281] logger.c: > [ 02 01 01 4c ] Jan 25 21:28:26 VERBOSE[13281] logger.c: > Supervisory frame: Jan 25 21:28:26 VERBOSE[13281] logger.c: > SAPI: 00 C/R: 1 EA: 0 > TEI: 000 EA: 1 Jan 25 21:28:26 VERBOSE[13281] logger.c: > Zero: 0 S: 0 01: 1 [ RR (receive ready) ] > N(R): 038 P/F: 0 > 0 bytes of data Jan 25 21:28:26 VERBOSE[13281] logger.c: -- Restarting T203 counter Jan 25 21:28:26 VERBOSE[13281] logger.c: -- Restarting T203 counter Jan 25 21:28:26 VERBOSE[13281] logger.c: -- Channel 0/9, span 1 got hangup request Jan 25 21:28:26 DEBUG[13288] chan_zap.c: No echo cancellation requested Jan 25 21:28:26 DEBUG[13288] chan_zap.c: No echo cancellation requested Jan 25 21:28:26 DEBUG[13288] chan_zap.c: Unlinking slave 1 from 9 Jan 25 21:28:26 DEBUG[13288] chan_zap.c: Removed 17 from conference 9/9 Jan 25 21:28:26 DEBUG[13288] chan_zap.c: Removed 26 from conference 9/1 Jan 25 21:28:26 DEBUG[13288] chan_zap.c: Updated conferencing on 9, with 0 conference users Jan 25 21:28:26 DEBUG[13288] channel.c: Returning from native bridge, channels: Zap/9-1, Zap/1-1 Jan 25 21:28:26 DEBUG[13288] channel.c: Hanging up channel 'Zap/1-1' Jan 25 21:28:26 DEBUG[13288] chan_zap.c: zt_hangup(Zap/1-1) Jan 25 21:28:26 DEBUG[13288] chan_zap.c: Set option AUDIO MODE, value: ON(1) on Zap/1-1 Jan 25 21:28:26 DEBUG[13288] chan_zap.c: Hangup: channel: 1 index = 0, normal = 17, callwait = -1, thirdcall = -1 Jan 25 21:28:26 DEBUG[13288] chan_zap.c: Not yet hungup... Calling hangup once with icause, and clearing call Jan 25 21:28:26 VERBOSE[13288] logger.c: > [ 00 01 4a 4c 08 02 00 02 45 08 02 81 90 ] Jan 25 21:28:26 VERBOSE[13288] logger.c: > Informational frame: Jan 25 21:28:26 VERBOSE[13288] logger.c: > SAPI: 00 C/R: 0 EA: 0 > TEI: 000 EA: 1 Jan 25 21:28:26 VERBOSE[13288] logger.c: > N(S): 037 0: 0 > N(R): 038 P: 0 > 9 bytes of data Jan 25 21:28:26 VERBOSE[13288] logger.c: -- Restarting T203 counter Jan 25 21:28:26 VERBOSE[13288] logger.c: Stopping T_203 timer Jan 25 21:28:26 VERBOSE[13288] logger.c: Starting T_200 timer Jan 25 21:28:26 VERBOSE[13288] logger.c: > Protocol Discriminator: Q.931 (8) len=9 Jan 25 21:28:26 VERBOSE[13288] logger.c: > Call Ref: len= 2 (reference 2/0x2) (Originator) Jan 25 21:28:26 VERBOSE[13288] logger.c: > Message type: DISCONNECT (69) Jan 25 21:28:26 VERBOSE[13288] logger.c: > [08 02 81 90] Jan 25 21:28:26 VERBOSE[13288] logger.c: > Cause (len= 4) [ Ext: 1 Coding: CCITT (ITU) standard (0) Spare: 0 Location: Private network serving the local user (1) Jan 25 21:28:26 VERBOSE[13288] logger.c: > Ext: 1 Cause: Normal Clearing (16), class = Normal Event (1) ] Jan 25 21:28:26 DEBUG[13288] chan_zap.c: Set option TDD MODE, value: OFF(0) on Zap/1-1 Jan 25 21:28:26 DEBUG[13288] chan_zap.c: Updated conferencing on 1, with 0 conference users Jan 25 21:28:26 DEBUG[13288] chan_zap.c: Set option AUDIO MODE, value: OFF(0) on Zap/1-1 Jan 25 21:28:26 VERBOSE[13288] logger.c: -- Hungup 'Zap/1-1' Jan 25 21:28:26 DEBUG[13288] app_dial.c: Exiting with DIALSTATUS=ANSWER. Jan 25 21:28:26 DEBUG[13288] pbx.c: Spawn extension (inbound,,1) exited non-zero on 'Zap/9-1' Jan 25 21:28:26 VERBOSE[13288] logger.c: == Spawn extension (inbound, , 1) exited non-zero on 'Zap/9-1' Jan 25 21:28:26 DEBUG[13288] pbx.c: Function result is '' Jan 25 21:28:26 DEBUG[13288] pbx.c: Function result is '' Jan 25 21:28:26 DEBUG[13288] pbx.c: Function result is '' Jan 25 21:28:26 DEBUG[13288] pbx.c: Function result is 'inbound' Jan 25 21:28:26 DEBUG[13288] pbx.c: Function result is 'Zap/9-1' Jan 25 21:28:26 DEBUG[13288] pbx.c: Function result is 'Zap/1-1' Jan 25 21:28:26 DEBUG[13288] pbx.c: Function result is 'Dial' Jan 25 21:28:26 DEBUG[13288] pbx.c: Function result is 'ZAP/g1/' Jan 25 21:28:26 DEBUG[13288] pbx.c: Function result is '2007-01-25 21:27:57' Jan 25 21:28:26 DEBUG[13288] pbx.c: Function result is '2007-01-25 21:28:11' Jan 25 21:28:26 DEBUG[13288] pbx.c: Function result is '2007-01-25 21:28:26' Jan 25 21:28:26 DEBUG[13288] pbx.c: Function result is '29' Jan 25 21:28:26 DEBUG[13288] pbx.c: Function result is '15' Jan 25 21:28:26 DEBUG[13288] pbx.c: Function result is 'ANSWERED' Jan 25 21:28:26 DEBUG[13288] pbx.c: Function result is 'DOCUMENTATION' Jan 25 21:28:26 DEBUG[13288] pbx.c: Function result is '(null)' Jan 25 21:28:26 DEBUG[13288] pbx.c: Function result is '1169760477.0' Jan 25 21:28:26 DEBUG[13288] pbx.c: Function result is '(null)' Jan 25 21:28:26 DEBUG[13288] channel.c: Hanging up channel 'Zap/9-1' Jan 25 21:28:26 DEBUG[13288] chan_zap.c: zt_hangup(Zap/9-1) Jan 25 21:28:26 DEBUG[13288] chan_zap.c: Set option AUDIO MODE, value: ON(1) on Zap/9-1 Jan 25 21:28:26 DEBUG[13288] chan_zap.c: Hangup: channel: 9 index = 0, normal = 26, callwait = -1, thirdcall = -1 Jan 25 21:28:26 DEBUG[13288] chan_zap.c: Not yet hungup... Calling hangup once with icause, and clearing call Jan 25 21:28:26 VERBOSE[13288] logger.c: > [ 00 01 4c 4c 08 02 89 00 4d 08 02 81 90 ] Jan 25 21:28:26 VERBOSE[13288] logger.c: > Informational frame: Jan 25 21:28:26 VERBOSE[13288] logger.c: > SAPI: 00 C/R: 0 EA: 0 > TEI: 000 EA: 1 Jan 25 21:28:26 VERBOSE[13288] logger.c: > N(S): 038 0: 0 > N(R): 038 P: 0 > 9 bytes of data Jan 25 21:28:26 VERBOSE[13288] logger.c: T_200 timer already going (2) Jan 25 21:28:26 VERBOSE[13288] logger.c: > Protocol Discriminator: Q.931 (8) len=9 Jan 25 21:28:26 VERBOSE[13288] logger.c: > Call Ref: len= 2 (reference 2304/0x900) (Terminator) Jan 25 21:28:26 VERBOSE[13288] logger.c: > Message type: RELEASE (77) Jan 25 21:28:26 VERBOSE[13288] logger.c: > [08 02 81 90] Jan 25 21:28:26 VERBOSE[13288] logger.c: > Cause (len= 4) [ Ext: 1 Coding: CCITT (ITU) standard (0) Spare: 0 Location: Private network serving the local user (1) Jan 25 21:28:26 VERBOSE[13288] logger.c: > Ext: 1 Cause: Normal Clearing (16), class = Normal Event (1) ] Jan 25 21:28:26 DEBUG[13288] chan_zap.c: Set option TDD MODE, value: OFF(0) on Zap/9-1 Jan 25 21:28:26 DEBUG[13288] chan_zap.c: Updated conferencing on 9, with 0 conference users Jan 25 21:28:26 DEBUG[13288] chan_zap.c: Set option AUDIO MODE, value: OFF(0) on Zap/9-1 Jan 25 21:28:26 VERBOSE[13288] logger.c: -- Hungup 'Zap/9-1' Jan 25 21:28:26 DEBUG[13271] devicestate.c: Changing state for Zap/1 - state 0 (Unknown) Jan 25 21:28:26 DEBUG[13296] app_queue.c: Device 'Zap/1' changed to state '0' (Unknown) but we don't care because they're not a member of any queue. Jan 25 21:28:26 DEBUG[13271] devicestate.c: Changing state for Zap/9 - state 0 (Unknown) Jan 25 21:28:26 DEBUG[13297] app_queue.c: Device 'Zap/9' changed to state '0' (Unknown) but we don't care because they're not a member of any queue. Jan 25 21:28:26 VERBOSE[13281] logger.c: < [ 02 01 4c 4e 08 02 80 02 4d ] Jan 25 21:28:26 VERBOSE[13281] logger.c: < Informational frame: Jan 25 21:28:26 VERBOSE[13281] logger.c: < SAPI: 00 C/R: 1 EA: 0 < TEI: 000 EA: 1 Jan 25 21:28:26 VERBOSE[13281] logger.c: < N(S): 038 0: 0 < N(R): 039 P: 0 < 5 bytes of data Jan 25 21:28:26 VERBOSE[13281] logger.c: -- ACKing all packets from 36 to (but not including) 39 Jan 25 21:28:26 VERBOSE[13281] logger.c: -- ACKing packet 37, new txqueue is 38 (-1 means empty) Jan 25 21:28:26 VERBOSE[13281] logger.c: -- ACKing packet 38, new txqueue is -1 (-1 means empty) Jan 25 21:28:26 VERBOSE[13281] logger.c: -- Since there was nothing left, stopping T200 counter Jan 25 21:28:26 VERBOSE[13281] logger.c: -- Nothing left, starting T203 counter Jan 25 21:28:26 VERBOSE[13281] logger.c: < Protocol Discriminator: Q.931 (8) len=5 Jan 25 21:28:26 VERBOSE[13281] logger.c: < Call Ref: len= 2 (reference 2/0x2) (Terminator) Jan 25 21:28:26 VERBOSE[13281] logger.c: < Message type: RELEASE (77) Jan 25 21:28:26 VERBOSE[13281] logger.c: Sending Receiver Ready (39) Jan 25 21:28:26 VERBOSE[13281] logger.c: > [ 02 01 01 4e ] Jan 25 21:28:26 VERBOSE[13281] logger.c: > Supervisory frame: Jan 25 21:28:26 VERBOSE[13281] logger.c: > SAPI: 00 C/R: 1 EA: 0 > TEI: 000 EA: 1 Jan 25 21:28:26 VERBOSE[13281] logger.c: > Zero: 0 S: 0 01: 1 [ RR (receive ready) ] > N(R): 039 P/F: 0 > 0 bytes of data Jan 25 21:28:26 VERBOSE[13281] logger.c: -- Restarting T203 counter Jan 25 21:28:26 VERBOSE[13281] logger.c: -- Restarting T203 counter Jan 25 21:28:26 VERBOSE[13281] logger.c: > [ 00 01 4e 4e 08 02 00 02 5a 08 02 81 90 ] Jan 25 21:28:26 VERBOSE[13281] logger.c: > Informational frame: Jan 25 21:28:26 VERBOSE[13281] logger.c: > SAPI: 00 C/R: 0 EA: 0 > TEI: 000 EA: 1 Jan 25 21:28:26 VERBOSE[13281] logger.c: > N(S): 039 0: 0 > N(R): 039 P: 0 > 9 bytes of data Jan 25 21:28:26 VERBOSE[13281] logger.c: -- Restarting T203 counter Jan 25 21:28:26 VERBOSE[13281] logger.c: Stopping T_203 timer Jan 25 21:28:26 VERBOSE[13281] logger.c: Starting T_200 timer Jan 25 21:28:26 VERBOSE[13281] logger.c: > Protocol Discriminator: Q.931 (8) len=9 Jan 25 21:28:26 VERBOSE[13281] logger.c: > Call Ref: len= 2 (reference 2/0x2) (Originator) Jan 25 21:28:26 VERBOSE[13281] logger.c: > Message type: RELEASE COMPLETE (90) Jan 25 21:28:26 VERBOSE[13281] logger.c: > [08 02 81 90] Jan 25 21:28:26 VERBOSE[13281] logger.c: > Cause (len= 4) [ Ext: 1 Coding: CCITT (ITU) standard (0) Spare: 0 Location: Private network serving the local user (1) Jan 25 21:28:26 VERBOSE[13281] logger.c: > Ext: 1 Cause: Normal Clearing (16), class = Normal Event (1) ] Jan 25 21:28:26 VERBOSE[13281] logger.c: < [ 02 01 4e 4e 08 02 09 00 5a ] Jan 25 21:28:26 VERBOSE[13281] logger.c: < Informational frame: Jan 25 21:28:26 VERBOSE[13281] logger.c: < SAPI: 00 C/R: 1 EA: 0 < TEI: 000 EA: 1 Jan 25 21:28:26 VERBOSE[13281] logger.c: < N(S): 039 0: 0 < N(R): 039 P: 0 < 5 bytes of data Jan 25 21:28:26 VERBOSE[13281] logger.c: -- ACKing all packets from 38 to (but not including) 39 Jan 25 21:28:26 VERBOSE[13281] logger.c: -- Something left to transmit (39), restarting T200 counter Jan 25 21:28:26 VERBOSE[13281] logger.c: < Protocol Discriminator: Q.931 (8) len=5 Jan 25 21:28:26 VERBOSE[13281] logger.c: < Call Ref: len= 2 (reference 2304/0x900) (Originator) Jan 25 21:28:26 VERBOSE[13281] logger.c: < Message type: RELEASE COMPLETE (90) Jan 25 21:28:26 VERBOSE[13281] logger.c: Sending Receiver Ready (40) Jan 25 21:28:26 VERBOSE[13281] logger.c: > [ 02 01 01 50 ] Jan 25 21:28:26 VERBOSE[13281] logger.c: > Supervisory frame: Jan 25 21:28:26 VERBOSE[13281] logger.c: > SAPI: 00 C/R: 1 EA: 0 > TEI: 000 EA: 1 Jan 25 21:28:26 VERBOSE[13281] logger.c: > Zero: 0 S: 0 01: 1 [ RR (receive ready) ] > N(R): 040 P/F: 0 > 0 bytes of data Jan 25 21:28:26 VERBOSE[13281] logger.c: < [ 00 01 01 50 ] Jan 25 21:28:26 VERBOSE[13281] logger.c: < Supervisory frame: Jan 25 21:28:26 VERBOSE[13281] logger.c: < SAPI: 00 C/R: 0 EA: 0 < TEI: 000 EA: 1 Jan 25 21:28:26 VERBOSE[13281] logger.c: < Zero: 0 S: 0 01: 1 [ RR (receive ready) ] < N(R): 040 P/F: 0 < 0 bytes of data Jan 25 21:28:26 VERBOSE[13281] logger.c: -- ACKing all packets from 38 to (but not including) 40 Jan 25 21:28:26 VERBOSE[13281] logger.c: -- ACKing packet 39, new txqueue is -1 (-1 means empty) Jan 25 21:28:26 VERBOSE[13281] logger.c: -- Since there was nothing left, stopping T200 counter Jan 25 21:28:26 VERBOSE[13281] logger.c: -- Nothing left, starting T203 counter Jan 25 21:28:26 VERBOSE[13281] logger.c: -- Restarting T203 counter Jan 25 21:28:32 VERBOSE[13281] logger.c: T203 counter expired, sending RR and scheduling T203 again Jan 25 21:28:32 VERBOSE[13281] logger.c: Sending Receiver Ready (40) Jan 25 21:28:32 VERBOSE[13281] logger.c: > [ 00 01 01 51 ] Jan 25 21:28:32 VERBOSE[13281] logger.c: > Supervisory frame: Jan 25 21:28:32 VERBOSE[13281] logger.c: > SAPI: 00 C/R: 0 EA: 0 > TEI: 000 EA: 1 Jan 25 21:28:32 VERBOSE[13281] logger.c: > Zero: 0 S: 0 01: 1 [ RR (receive ready) ] > N(R): 040 P/F: 1 > 0 bytes of data Jan 25 21:28:32 VERBOSE[13281] logger.c: -- Restarting T203 counter Jan 25 21:28:32 VERBOSE[13281] logger.c: < [ 00 01 01 51 ] Jan 25 21:28:32 VERBOSE[13281] logger.c: < Supervisory frame: Jan 25 21:28:32 VERBOSE[13281] logger.c: < SAPI: 00 C/R: 0 EA: 0 < TEI: 000 EA: 1 Jan 25 21:28:32 VERBOSE[13281] logger.c: < Zero: 0 S: 0 01: 1 [ RR (receive ready) ] < N(R): 040 P/F: 1 < 0 bytes of data Jan 25 21:28:32 VERBOSE[13281] logger.c: -- ACKing all packets from 39 to (but not including) 40 Jan 25 21:28:32 VERBOSE[13281] logger.c: -- Since there was nothing left, stopping T200 counter Jan 25 21:28:32 VERBOSE[13281] logger.c: -- Stopping T203 counter since we got an ACK Jan 25 21:28:32 VERBOSE[13281] logger.c: -- Nothing left, starting T203 counter Jan 25 21:28:32 VERBOSE[13281] logger.c: -- Got RR response to our frame Jan 25 21:28:32 VERBOSE[13281] logger.c: -- Restarting T203 counter