[Sep 18 14:54:42] VERBOSE[28699] logger.c: Really destroying SIP dialog 'ODk1NjU5Y2JlZjA5MzdjNjczMzdlOWY1MTJjNDk4ZDA.' Method: REGISTER [Sep 18 14:54:43] VERBOSE[28699] logger.c: <--- SIP read from UDP://192.168.15.40:5060 ---> INVITE sip:3171111@192.168.15.137 SIP/2.0 Via: SIP/2.0/UDP 192.168.15.40:5060;branch=z9hG4bK16ccbaa0;rport Max-Forwards: 70 From: "Operator One" ;tag=as4279ca14 To: Contact: Call-ID: 58c5533d62eec33054172d2b2a14782d@192.168.15.40 CSeq: 102 INVITE User-Agent: Asterisk PBX 1.6.0.6 Date: Fri, 18 Sep 2009 18:54:42 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces, timer Content-Type: application/sdp Content-Length: 334 v=0 o=root 676962363 676962363 IN IP4 192.168.15.40 s=Asterisk PBX 1.6.0.6 c=IN IP4 192.168.15.40 t=0 0 m=audio 16436 RTP/AVP 0 8 5 3 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:5 DVI4/8000 a=rtpmap:3 GSM/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv <-------------> [Sep 18 14:54:43] VERBOSE[28699] logger.c: --- (14 headers 15 lines) --- [Sep 18 14:54:43] VERBOSE[28699] logger.c: == Using SIP RTP CoS mark 5 [Sep 18 14:54:43] VERBOSE[28699] logger.c: Sending to 192.168.15.40 : 5060 (no NAT) [Sep 18 14:54:43] VERBOSE[28699] logger.c: Using INVITE request as basis request - 58c5533d62eec33054172d2b2a14782d@192.168.15.40 [Sep 18 14:54:43] VERBOSE[28699] logger.c: No user '2601' in SIP users list [Sep 18 14:54:43] VERBOSE[28699] logger.c: Found peer '205' for '2601' from 192.168.15.40:5060 [Sep 18 14:54:43] VERBOSE[28699] logger.c: <--- Reliably Transmitting (no NAT) to 192.168.15.40:5060 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 192.168.15.40:5060;branch=z9hG4bK16ccbaa0;received=192.168.15.40;rport=5060 From: "Operator One" ;tag=as4279ca14 To: ;tag=as41afb8d1 Call-ID: 58c5533d62eec33054172d2b2a14782d@192.168.15.40 CSeq: 102 INVITE User-Agent: Asterisk PBX 1.6.0.15 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="73e4fb1a" Content-Length: 0 <------------> [Sep 18 14:54:43] VERBOSE[28699] logger.c: Scheduling destruction of SIP dialog '58c5533d62eec33054172d2b2a14782d@192.168.15.40' in 6400 ms (Method: INVITE) [Sep 18 14:54:43] VERBOSE[28699] logger.c: <--- SIP read from UDP://192.168.15.40:5060 ---> ACK sip:3171111@192.168.15.137 SIP/2.0 Via: SIP/2.0/UDP 192.168.15.40:5060;branch=z9hG4bK16ccbaa0;rport Max-Forwards: 70 From: "Operator One" ;tag=as4279ca14 To: ;tag=as41afb8d1 Contact: Call-ID: 58c5533d62eec33054172d2b2a14782d@192.168.15.40 CSeq: 102 ACK User-Agent: Asterisk PBX 1.6.0.6 Content-Length: 0 <-------------> [Sep 18 14:54:43] VERBOSE[28699] logger.c: --- (10 headers 0 lines) --- [Sep 18 14:54:43] VERBOSE[28699] logger.c: <--- SIP read from UDP://192.168.15.40:5060 ---> INVITE sip:3171111@192.168.15.137 SIP/2.0 Via: SIP/2.0/UDP 192.168.15.40:5060;branch=z9hG4bK503ebe5b;rport Max-Forwards: 70 From: "Operator One" ;tag=as4279ca14 To: Contact: Call-ID: 58c5533d62eec33054172d2b2a14782d@192.168.15.40 CSeq: 103 INVITE User-Agent: Asterisk PBX 1.6.0.6 Authorization: Digest username="205", realm="asterisk", algorithm=MD5, uri="sip:3171111@192.168.15.137", nonce="73e4fb1a", response="8478bafe0243757edfe29a64fa4dd94c" Date: Fri, 18 Sep 2009 18:54:42 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces, timer Content-Type: application/sdp Content-Length: 334 v=0 o=root 676962363 676962364 IN IP4 192.168.15.40 s=Asterisk PBX 1.6.0.6 c=IN IP4 192.168.15.40 t=0 0 m=audio 16436 RTP/AVP 0 8 5 3 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:5 DVI4/8000 a=rtpmap:3 GSM/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv <-------------> [Sep 18 14:54:43] VERBOSE[28699] logger.c: --- (15 headers 15 lines) --- [Sep 18 14:54:43] VERBOSE[28699] logger.c: Sending to 192.168.15.40 : 5060 (no NAT) [Sep 18 14:54:43] VERBOSE[28699] logger.c: Using INVITE request as basis request - 58c5533d62eec33054172d2b2a14782d@192.168.15.40 [Sep 18 14:54:43] VERBOSE[28699] logger.c: No user '2601' in SIP users list [Sep 18 14:54:43] VERBOSE[28699] logger.c: Found peer '205' for '2601' from 192.168.15.40:5060 [Sep 18 14:54:43] VERBOSE[28699] logger.c: Found RTP audio format 0 [Sep 18 14:54:43] VERBOSE[28699] logger.c: Found RTP audio format 8 [Sep 18 14:54:43] VERBOSE[28699] logger.c: Found RTP audio format 5 [Sep 18 14:54:43] VERBOSE[28699] logger.c: Found RTP audio format 3 [Sep 18 14:54:43] VERBOSE[28699] logger.c: Found RTP audio format 101 [Sep 18 14:54:43] VERBOSE[28699] logger.c: Peer audio RTP is at port 192.168.15.40:16436 [Sep 18 14:54:43] VERBOSE[28699] logger.c: Found audio description format PCMU for ID 0 [Sep 18 14:54:43] VERBOSE[28699] logger.c: Found audio description format PCMA for ID 8 [Sep 18 14:54:43] VERBOSE[28699] logger.c: Found audio description format DVI4 for ID 5 [Sep 18 14:54:43] VERBOSE[28699] logger.c: Found audio description format GSM for ID 3 [Sep 18 14:54:43] VERBOSE[28699] logger.c: Found audio description format telephone-event for ID 101 [Sep 18 14:54:43] VERBOSE[28699] logger.c: Got unsupported a:fmtp in SDP offer [Sep 18 14:54:43] VERBOSE[28699] logger.c: Capabilities: us - 0x8000e (gsm|ulaw|alaw|h263), peer - audio=0x2e (gsm|ulaw|alaw|adpcm)/video=0x0 (nothing)/text=0x0 (nothing), combined - 0xe (gsm|ulaw|alaw) [Sep 18 14:54:43] VERBOSE[28699] logger.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) [Sep 18 14:54:43] VERBOSE[28699] logger.c: Peer audio RTP is at port 192.168.15.40:16436 [Sep 18 14:54:43] VERBOSE[28699] logger.c: Looking for 3171111 in cos_internal+local+ld+intl (domain 192.168.15.137) [Sep 18 14:54:43] VERBOSE[28699] logger.c: list_route: hop: [Sep 18 14:54:43] VERBOSE[28699] logger.c: <--- Transmitting (no NAT) to 192.168.15.40:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.15.40:5060;branch=z9hG4bK503ebe5b;received=192.168.15.40;rport=5060 From: "Operator One" ;tag=as4279ca14 To: Call-ID: 58c5533d62eec33054172d2b2a14782d@192.168.15.40 CSeq: 103 INVITE User-Agent: Asterisk PBX 1.6.0.15 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Require: timer Session-Expires: -1;refresher=uas Contact: Content-Length: 0 <------------> [Sep 18 14:54:43] VERBOSE[28760] logger.c: -- Executing [3171111@cos_internal+local+ld+intl:1] Goto("SIP/205-b694e820", "_cos_internal+local+ld+intl,3171111,1") in new stack [Sep 18 14:54:43] VERBOSE[28760] logger.c: -- Goto (_cos_internal+local+ld+intl,3171111,1) [Sep 18 14:54:43] VERBOSE[28760] logger.c: -- Executing [3171111@_cos_internal+local+ld+intl:1] Set("SIP/205-b694e820", "__dialdigits=3171111") in new stack [Sep 18 14:54:43] VERBOSE[28760] logger.c: -- Executing [3171111@_cos_internal+local+ld+intl:2] Dial("SIP/205-b694e820", "SIP/AudioCodesFXO1,,rM(dialdigits)") in new stack [Sep 18 14:54:43] VERBOSE[28760] logger.c: == Using SIP RTP CoS mark 5 [Sep 18 14:54:43] VERBOSE[28760] logger.c: Audio is at 192.168.15.137 port 16168 [Sep 18 14:54:43] VERBOSE[28760] logger.c: Adding codec 0x4 (ulaw) to SDP [Sep 18 14:54:43] VERBOSE[28760] logger.c: Adding codec 0x2 (gsm) to SDP [Sep 18 14:54:43] VERBOSE[28760] logger.c: Adding codec 0x8 (alaw) to SDP [Sep 18 14:54:43] VERBOSE[28760] logger.c: Adding non-codec 0x1 (telephone-event) to SDP [Sep 18 14:54:43] VERBOSE[28760] logger.c: Reliably Transmitting (no NAT) to 192.168.15.138:5060: INVITE sip:AudioCodesFXO1@192.168.15.138 SIP/2.0 Via: SIP/2.0/UDP 192.168.15.137:5060;branch=z9hG4bK419993c9;rport Max-Forwards: 70 From: "Operator One" ;tag=as1c75afae To: Contact: Call-ID: 3dbc12da7ce4128501ef3bef21d44a82@192.168.15.137 CSeq: 102 INVITE User-Agent: Asterisk PBX 1.6.0.15 Date: Fri, 18 Sep 2009 18:54:43 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Content-Type: application/sdp Content-Length: 313 v=0 o=root 651559983 651559983 IN IP4 192.168.15.137 s=Asterisk PBX 1.6.0.15 c=IN IP4 192.168.15.137 t=0 0 m=audio 16168 RTP/AVP 0 3 8 101 a=rtpmap:0 PCMU/8000 a=rtpmap:3 GSM/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv --- [Sep 18 14:54:43] VERBOSE[28760] logger.c: -- Called AudioCodesFXO1 [Sep 18 14:54:43] VERBOSE[28760] logger.c: <--- Transmitting (no NAT) to 192.168.15.40:5060 ---> SIP/2.0 180 Ringing Via: SIP/2.0/UDP 192.168.15.40:5060;branch=z9hG4bK503ebe5b;received=192.168.15.40;rport=5060 From: "Operator One" ;tag=as4279ca14 To: ;tag=as06fc3a40 Call-ID: 58c5533d62eec33054172d2b2a14782d@192.168.15.40 CSeq: 103 INVITE User-Agent: Asterisk PBX 1.6.0.15 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Require: timer Session-Expires: -1;refresher=uas Contact: Content-Length: 0 <------------> [Sep 18 14:54:43] VERBOSE[28699] logger.c: <--- SIP read from UDP://192.168.15.138:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.15.137:5060;branch=z9hG4bK419993c9;rport From: "Operator One" ;tag=as1c75afae To: ;tag=1c187769642 Call-ID: 3dbc12da7ce4128501ef3bef21d44a82@192.168.15.137 CSeq: 102 INVITE Supported: em,timer,replaces,path,early-session,resource-priority Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE Server: Audiocodes-Sip-Gateway-MP-114 FXS_FXO/v.5.00A.024 Content-Length: 0 <-------------> [Sep 18 14:54:43] VERBOSE[28699] logger.c: --- (10 headers 0 lines) --- [Sep 18 14:54:43] VERBOSE[28699] logger.c: <--- SIP read from UDP://192.168.15.138:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.15.137:5060;branch=z9hG4bK419993c9;rport From: "Operator One" ;tag=as1c75afae To: ;tag=1c187769642 Call-ID: 3dbc12da7ce4128501ef3bef21d44a82@192.168.15.137 CSeq: 102 INVITE Contact: Supported: em,timer,replaces,path,early-session,resource-priority Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE Server: Audiocodes-Sip-Gateway-MP-114 FXS_FXO/v.5.00A.024 Content-Type: application/sdp Content-Length: 270 v=0 o=AudiocodesGW 187790227 187790110 IN IP4 192.168.15.138 s=Phone-Call c=IN IP4 192.168.15.138 t=0 0 m=audio 6020 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:20 a=sendrecv a=rtcp:6021 IN IP4 192.168.15.138 <-------------> [Sep 18 14:54:43] VERBOSE[28699] logger.c: --- (12 headers 12 lines) --- [Sep 18 14:54:43] VERBOSE[28699] logger.c: Found RTP audio format 0 [Sep 18 14:54:43] VERBOSE[28699] logger.c: Found RTP audio format 101 [Sep 18 14:54:43] VERBOSE[28699] logger.c: Peer audio RTP is at port 192.168.15.138:6020 [Sep 18 14:54:43] VERBOSE[28699] logger.c: Found audio description format PCMU for ID 0 [Sep 18 14:54:43] VERBOSE[28699] logger.c: Found audio description format telephone-event for ID 101 [Sep 18 14:54:43] VERBOSE[28699] logger.c: Got unsupported a:fmtp in SDP offer [Sep 18 14:54:43] VERBOSE[28699] logger.c: Got unsupported a:rtcp in SDP offer [Sep 18 14:54:43] VERBOSE[28699] logger.c: Capabilities: us - 0x8000e (gsm|ulaw|alaw|h263), peer - audio=0x4 (ulaw)/video=0x0 (nothing)/text=0x0 (nothing), combined - 0x4 (ulaw) [Sep 18 14:54:43] VERBOSE[28699] logger.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) [Sep 18 14:54:43] VERBOSE[28699] logger.c: Peer audio RTP is at port 192.168.15.138:6020 [Sep 18 14:54:43] VERBOSE[28699] logger.c: list_route: hop: [Sep 18 14:54:43] VERBOSE[28699] logger.c: set_destination: Parsing for address/port to send to [Sep 18 14:54:43] VERBOSE[28699] logger.c: set_destination: set destination to 192.168.15.138, port 5060 [Sep 18 14:54:43] VERBOSE[28699] logger.c: Transmitting (no NAT) to 192.168.15.138:5060: ACK sip:AudioCodesFXO1@192.168.15.138 SIP/2.0 Via: SIP/2.0/UDP 192.168.15.137:5060;branch=z9hG4bK0b7f8c4a;rport Max-Forwards: 70 From: "Operator One" ;tag=as1c75afae To: ;tag=1c187769642 Contact: Call-ID: 3dbc12da7ce4128501ef3bef21d44a82@192.168.15.137 CSeq: 102 ACK User-Agent: Asterisk PBX 1.6.0.15 Content-Length: 0 --- [Sep 18 14:54:43] VERBOSE[28760] logger.c: -- SIP/AudioCodesFXO1-b6967288 answered SIP/205-b694e820 [Sep 18 14:54:43] VERBOSE[28760] logger.c: -- Executing [s@macro-dialdigits:1] Wait("SIP/AudioCodesFXO1-b6967288", "1") in new stack [Sep 18 14:54:44] VERBOSE[28760] logger.c: -- Executing [s@macro-dialdigits:2] SendDTMF("SIP/AudioCodesFXO1-b6967288", "9") in new stack [Sep 18 14:54:45] VERBOSE[28760] logger.c: -- Executing [s@macro-dialdigits:3] Wait("SIP/AudioCodesFXO1-b6967288", "1") in new stack [Sep 18 14:54:45] VERBOSE[28681] logger.c: T203 counter expired, sending RR and scheduling T203 again [Sep 18 14:54:45] VERBOSE[28681] logger.c: Sending Receiver Ready (27) [Sep 18 14:54:45] VERBOSE[28681] logger.c: > [ 02 01 01 37 ] [Sep 18 14:54:45] VERBOSE[28681] logger.c: > Supervisory frame: [Sep 18 14:54:45] VERBOSE[28681] logger.c: > SAPI: 00 C/R: 1 EA: 0 > TEI: 000 EA: 1 [Sep 18 14:54:45] VERBOSE[28681] logger.c: > Zero: 0 S: 0 01: 1 [ RR (receive ready) ] > N(R): 027 P/F: 1 > 0 bytes of data [Sep 18 14:54:45] VERBOSE[28681] logger.c: < [ 02 01 01 31 ] [Sep 18 14:54:45] VERBOSE[28681] logger.c: < Supervisory frame: [Sep 18 14:54:45] VERBOSE[28681] logger.c: < SAPI: 00 C/R: 1 EA: 0 < TEI: 000 EA: 1 [Sep 18 14:54:45] VERBOSE[28681] logger.c: < Zero: 0 S: 0 01: 1 [ RR (receive ready) ] < N(R): 024 P/F: 1 < 0 bytes of data [Sep 18 14:54:45] VERBOSE[28681] logger.c: Handling message for SAPI/TEI=0/0 [Sep 18 14:54:45] VERBOSE[28681] logger.c: -- ACKing all packets from 23 to (but not including) 24 [Sep 18 14:54:45] VERBOSE[28681] logger.c: -- Since there was nothing left, stopping T200 counter [Sep 18 14:54:45] VERBOSE[28681] logger.c: -- Stopping T203 counter since we got an ACK [Sep 18 14:54:45] VERBOSE[28681] logger.c: -- Nothing left, starting T203 counter [Sep 18 14:54:45] VERBOSE[28681] logger.c: -- Got RR response to our frame [Sep 18 14:54:45] VERBOSE[28681] logger.c: -- Restarting T203 timer [Sep 18 14:54:46] VERBOSE[28760] logger.c: -- Executing [s@macro-dialdigits:4] SendDTMF("SIP/AudioCodesFXO1-b6967288", "3171111") in new stack [Sep 18 14:54:48] VERBOSE[28681] logger.c: < [ 00 01 36 30 08 02 06 99 05 04 03 90 90 a2 18 03 a1 83 97 1e 02 81 83 70 08 c1 33 31 37 31 31 31 31 ] [Sep 18 14:54:48] VERBOSE[28681] logger.c: < Informational frame: [Sep 18 14:54:48] VERBOSE[28681] logger.c: < SAPI: 00 C/R: 0 EA: 0 < TEI: 000 EA: 1 [Sep 18 14:54:48] VERBOSE[28681] logger.c: < N(S): 027 0: 0 < N(R): 024 P: 0 < 29 bytes of data [Sep 18 14:54:48] VERBOSE[28681] logger.c: Handling message for SAPI/TEI=0/0 [Sep 18 14:54:48] VERBOSE[28681] logger.c: -- ACKing all packets from 23 to (but not including) 24 [Sep 18 14:54:48] VERBOSE[28681] logger.c: -- Since there was nothing left, stopping T200 counter [Sep 18 14:54:48] VERBOSE[28681] logger.c: -- Stopping T203 counter since we got an ACK [Sep 18 14:54:48] VERBOSE[28681] logger.c: -- Nothing left, starting T203 counter [Sep 18 14:54:48] VERBOSE[28681] logger.c: < Protocol Discriminator: Q.931 (8) len=29 [Sep 18 14:54:48] VERBOSE[28681] logger.c: < Call Ref: len= 2 (reference 1689/0x699) (Originator) [Sep 18 14:54:48] VERBOSE[28681] logger.c: < Message type: SETUP (5) [Sep 18 14:54:48] VERBOSE[28681] logger.c: < [04 03 90 90 a2] [Sep 18 14:54:48] VERBOSE[28681] logger.c: < Bearer Capability (len= 5) [ Ext: 1 Q.931 Std: 0 Info transfer capability: 3.1kHz audio (16) [Sep 18 14:54:48] VERBOSE[28681] logger.c: < Ext: 1 Trans mode/rate: 64kbps, circuit-mode (16) [Sep 18 14:54:48] VERBOSE[28681] logger.c: < User information layer 1: u-Law (34) [Sep 18 14:54:48] VERBOSE[28681] logger.c: < [18 03 a1 83 97] [Sep 18 14:54:48] VERBOSE[28681] logger.c: < Channel ID (len= 5) [ Ext: 1 IntID: Implicit PRI Spare: 0 Preferred Dchan: 0 [Sep 18 14:54:48] VERBOSE[28681] logger.c: < ChanSel: As indicated in following octets [Sep 18 14:54:48] VERBOSE[28681] logger.c: < Ext: 1 Coding: 0 Number Specified Channel Type: 3 [Sep 18 14:54:48] VERBOSE[28681] logger.c: < Ext: 1 Channel: 23 ] [Sep 18 14:54:48] VERBOSE[28681] logger.c: < [1e 02 81 83] [Sep 18 14:54:48] VERBOSE[28681] logger.c: < Progress Indicator (len= 4) [ Ext: 1 Coding: CCITT (ITU) standard (0) 0: 0 Location: Private network serving the local user (1) [Sep 18 14:54:48] VERBOSE[28681] logger.c: < Ext: 1 Progress Description: Calling equipment is non-ISDN. (3) ] [Sep 18 14:54:48] VERBOSE[28681] logger.c: < [70 08 c1 33 31 37 31 31 31 31] [Sep 18 14:54:48] VERBOSE[28681] logger.c: < Called Number (len=10) [ Ext: 1 TON: Subscriber Number (4) NPI: ISDN/Telephony Numbering Plan (E.164/E.163) (1) '3171111' ] [Sep 18 14:54:48] VERBOSE[28681] logger.c: -- Making new call for cr 1689 [Sep 18 14:54:48] VERBOSE[28681] logger.c: -- Processing Q.931 Call Setup [Sep 18 14:54:48] VERBOSE[28681] logger.c: -- Processing IE 4 (cs0, Bearer Capability) [Sep 18 14:54:48] VERBOSE[28681] logger.c: -- Processing IE 24 (cs0, Channel Identification) [Sep 18 14:54:48] VERBOSE[28681] logger.c: -- Processing IE 30 (cs0, Progress Indicator) [Sep 18 14:54:48] VERBOSE[28681] logger.c: -- Processing IE 112 (cs0, Called Party Number) [Sep 18 14:54:48] VERBOSE[28681] logger.c: q931.c:3545 q931_receive: call 1689 on channel 23 enters state 6 (Call Present) [Sep 18 14:54:48] VERBOSE[28681] logger.c: Sending Receiver Ready (28) [Sep 18 14:54:48] VERBOSE[28681] logger.c: > [ 00 01 01 38 ] [Sep 18 14:54:48] VERBOSE[28681] logger.c: > Supervisory frame: [Sep 18 14:54:48] VERBOSE[28681] logger.c: > SAPI: 00 C/R: 0 EA: 0 > TEI: 000 EA: 1 [Sep 18 14:54:48] VERBOSE[28681] logger.c: > Zero: 0 S: 0 01: 1 [ RR (receive ready) ] > N(R): 028 P/F: 0 > 0 bytes of data [Sep 18 14:54:48] VERBOSE[28681] logger.c: -- Restarting T203 timer [Sep 18 14:54:48] VERBOSE[28681] logger.c: q931.c:2810 q931_call_proceeding: call 1689 on channel 23 enters state 9 (Incoming Call Proceeding) [Sep 18 14:54:48] VERBOSE[28681] logger.c: > [ 02 01 30 38 08 02 86 99 02 18 03 a9 83 97 ] [Sep 18 14:54:48] VERBOSE[28681] logger.c: > Informational frame: [Sep 18 14:54:48] VERBOSE[28681] logger.c: > SAPI: 00 C/R: 1 EA: 0 > TEI: 000 EA: 1 [Sep 18 14:54:48] VERBOSE[28681] logger.c: > N(S): 024 0: 0 > N(R): 028 P: 0 > 10 bytes of data [Sep 18 14:54:48] VERBOSE[28681] logger.c: Stopping T_203 timer [Sep 18 14:54:48] VERBOSE[28681] logger.c: Starting T_200 timer [Sep 18 14:54:48] VERBOSE[28681] logger.c: -- Restarting T200 timer [Sep 18 14:54:48] VERBOSE[28681] logger.c: > Protocol Discriminator: Q.931 (8) len=10 [Sep 18 14:54:48] VERBOSE[28681] logger.c: > Call Ref: len= 2 (reference 1689/0x699) (Terminator) [Sep 18 14:54:48] VERBOSE[28681] logger.c: > Message type: CALL PROCEEDING (2) [Sep 18 14:54:48] VERBOSE[28681] logger.c: > [18 03 a9 83 97] [Sep 18 14:54:48] VERBOSE[28681] logger.c: > Channel ID (len= 5) [ Ext: 1 IntID: Implicit PRI Spare: 0 Exclusive Dchan: 0 [Sep 18 14:54:48] VERBOSE[28681] logger.c: > ChanSel: As indicated in following octets [Sep 18 14:54:48] VERBOSE[28681] logger.c: > Ext: 1 Coding: 0 Number Specified Channel Type: 3 [Sep 18 14:54:48] VERBOSE[28681] logger.c: > Ext: 1 Channel: 23 ] [Sep 18 14:54:48] VERBOSE[28681] logger.c: -- Accepting call from '' to '3171111' on channel 0/23, span 1 [Sep 18 14:54:48] VERBOSE[28762] logger.c: -- Executing [3171111@trunkhandler_incoming_custom:1] Set("DAHDI/23-1", "CALLERID(name)=foo") in new stack [Sep 18 14:54:48] VERBOSE[28762] logger.c: -- Executing [3171111@trunkhandler_incoming_custom:2] Dial("DAHDI/23-1", "SIP/201") in new stack [Sep 18 14:54:48] VERBOSE[28762] logger.c: == Using SIP RTP CoS mark 5 [Sep 18 14:54:48] WARNING[28762] chan_sip.c: Unsupported callingpres (-1) [Sep 18 14:54:48] VERBOSE[28762] logger.c: Audio is at 192.168.15.137 port 16244 [Sep 18 14:54:48] VERBOSE[28762] logger.c: Adding codec 0x4 (ulaw) to SDP [Sep 18 14:54:48] VERBOSE[28762] logger.c: Adding codec 0x2 (gsm) to SDP [Sep 18 14:54:48] VERBOSE[28762] logger.c: Adding codec 0x8 (alaw) to SDP [Sep 18 14:54:48] VERBOSE[28762] logger.c: Adding non-codec 0x1 (telephone-event) to SDP [Sep 18 14:54:48] VERBOSE[28762] logger.c: Reliably Transmitting (no NAT) to 192.168.15.138:5060: INVITE sip:201@192.168.15.138 SIP/2.0 Via: SIP/2.0/UDP 192.168.15.137:5060;branch=z9hG4bK182c5b4a;rport Max-Forwards: 70 From: "foo" ;tag=as60391556 To: Contact: Call-ID: 37f774cb1c2acb600e7a967f1e874b6a@192.168.15.137 CSeq: 102 INVITE User-Agent: Asterisk PBX 1.6.0.15 Remote-Party-ID: "foo" ;privacy=full;screen=no Date: Fri, 18 Sep 2009 18:54:48 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Content-Type: application/sdp Content-Length: 313 v=0 o=root 467250073 467250073 IN IP4 192.168.15.137 s=Asterisk PBX 1.6.0.15 c=IN IP4 192.168.15.137 t=0 0 m=audio 16244 RTP/AVP 0 3 8 101 a=rtpmap:0 PCMU/8000 a=rtpmap:3 GSM/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv --- [Sep 18 14:54:48] VERBOSE[28762] logger.c: -- Called 201 [Sep 18 14:54:48] VERBOSE[28681] logger.c: < [ 02 01 01 32 ] [Sep 18 14:54:48] VERBOSE[28681] logger.c: < Supervisory frame: [Sep 18 14:54:48] VERBOSE[28681] logger.c: < SAPI: 00 C/R: 1 EA: 0 < TEI: 000 EA: 1 [Sep 18 14:54:48] VERBOSE[28681] logger.c: < Zero: 0 S: 0 01: 1 [ RR (receive ready) ] < N(R): 025 P/F: 0 < 0 bytes of data [Sep 18 14:54:48] VERBOSE[28681] logger.c: Handling message for SAPI/TEI=0/0 [Sep 18 14:54:48] VERBOSE[28681] logger.c: -- ACKing all packets from 23 to (but not including) 25 [Sep 18 14:54:48] VERBOSE[28681] logger.c: -- ACKing packet 24, new txqueue is -1 (-1 means empty) [Sep 18 14:54:48] VERBOSE[28681] logger.c: -- Since there was nothing left, stopping T200 counter [Sep 18 14:54:48] VERBOSE[28681] logger.c: -- Nothing left, starting T203 counter [Sep 18 14:54:48] VERBOSE[28681] logger.c: -- Restarting T203 timer [Sep 18 14:54:48] VERBOSE[28760] logger.c: Audio is at 192.168.15.137 port 16212 [Sep 18 14:54:48] VERBOSE[28760] logger.c: Adding codec 0x2 (gsm) to SDP [Sep 18 14:54:48] VERBOSE[28760] logger.c: Adding codec 0x4 (ulaw) to SDP [Sep 18 14:54:48] VERBOSE[28760] logger.c: Adding codec 0x8 (alaw) to SDP [Sep 18 14:54:48] VERBOSE[28760] logger.c: Adding non-codec 0x1 (telephone-event) to SDP [Sep 18 14:54:48] VERBOSE[28760] logger.c: <--- Reliably Transmitting (no NAT) to 192.168.15.40:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.15.40:5060;branch=z9hG4bK503ebe5b;received=192.168.15.40;rport=5060 From: "Operator One" ;tag=as4279ca14 To: ;tag=as06fc3a40 Call-ID: 58c5533d62eec33054172d2b2a14782d@192.168.15.40 CSeq: 103 INVITE User-Agent: Asterisk PBX 1.6.0.15 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Require: timer Session-Expires: -1;refresher=uas Contact: Content-Type: application/sdp Content-Length: 313 v=0 o=root 452685064 452685064 IN IP4 192.168.15.137 s=Asterisk PBX 1.6.0.15 c=IN IP4 192.168.15.137 t=0 0 m=audio 16212 RTP/AVP 3 0 8 101 a=rtpmap:3 GSM/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv <------------> [Sep 18 14:54:48] VERBOSE[28760] logger.c: -- Packet2Packet bridging SIP/205-b694e820 and SIP/AudioCodesFXO1-b6967288 [Sep 18 14:54:48] VERBOSE[28699] logger.c: <--- SIP read from UDP://192.168.15.40:5060 ---> ACK sip:3171111@192.168.15.137 SIP/2.0 Via: SIP/2.0/UDP 192.168.15.40:5060;branch=z9hG4bK5dc5ee57;rport Max-Forwards: 70 From: "Operator One" ;tag=as4279ca14 To: ;tag=as06fc3a40 Contact: Call-ID: 58c5533d62eec33054172d2b2a14782d@192.168.15.40 CSeq: 103 ACK User-Agent: Asterisk PBX 1.6.0.6 Content-Length: 0 <-------------> [Sep 18 14:54:48] VERBOSE[28699] logger.c: --- (10 headers 0 lines) --- [Sep 18 14:54:48] VERBOSE[28699] logger.c: Retransmitting #1 (no NAT) to 192.168.15.138:5060: INVITE sip:201@192.168.15.138 SIP/2.0 Via: SIP/2.0/UDP 192.168.15.137:5060;branch=z9hG4bK182c5b4a;rport Max-Forwards: 70 From: "foo" ;tag=as60391556 To: Contact: Call-ID: 37f774cb1c2acb600e7a967f1e874b6a@192.168.15.137 CSeq: 102 INVITE User-Agent: Asterisk PBX 1.6.0.15 Remote-Party-ID: "foo" ;privacy=full;screen=no Date: Fri, 18 Sep 2009 18:54:48 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Content-Type: application/sdp Content-Length: 313 v=0 o=root 467250073 467250073 IN IP4 192.168.15.137 s=Asterisk PBX 1.6.0.15 c=IN IP4 192.168.15.137 t=0 0 m=audio 16244 RTP/AVP 0 3 8 101 a=rtpmap:0 PCMU/8000 a=rtpmap:3 GSM/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv --- [Sep 18 14:54:49] VERBOSE[28699] logger.c: <--- SIP read from UDP://192.168.15.138:5060 ---> OPTIONS sip:AudioCodesFXO2@192.168.15.138 SIP/2.0 Via: SIP/2.0/UDP 192.168.15.138;branch=z9hG4bKac200762660 Max-Forwards: 70 From: ;tag=1c200759794 To: Call-ID: 20075945121200014715@192.168.15.138 CSeq: 1 OPTIONS Contact: Supported: em,timer,replaces,path,resource-priority Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE User-Agent: Audiocodes-Sip-Gateway-MP-114 FXS_FXO/v.5.00A.024 Content-Length: 0 <-------------> [Sep 18 14:54:49] VERBOSE[28699] logger.c: --- (12 headers 0 lines) --- [Sep 18 14:54:49] VERBOSE[28699] logger.c: Looking for AudioCodesFXO2 in default (domain 192.168.15.138) [Sep 18 14:54:49] VERBOSE[28699] logger.c: <--- Transmitting (no NAT) to 192.168.15.138:5060 ---> SIP/2.0 404 Not Found Via: SIP/2.0/UDP 192.168.15.138;branch=z9hG4bKac200762660;received=192.168.15.138 From: ;tag=1c200759794 To: ;tag=as331d2b0f Call-ID: 20075945121200014715@192.168.15.138 CSeq: 1 OPTIONS User-Agent: Asterisk PBX 1.6.0.15 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Accept: application/sdp Content-Length: 0 <------------> [Sep 18 14:54:49] VERBOSE[28699] logger.c: Scheduling destruction of SIP dialog '20075945121200014715@192.168.15.138' in 32000 ms (Method: OPTIONS) [Sep 18 14:54:49] VERBOSE[28699] logger.c: Retransmitting #2 (no NAT) to 192.168.15.138:5060: INVITE sip:201@192.168.15.138 SIP/2.0 Via: SIP/2.0/UDP 192.168.15.137:5060;branch=z9hG4bK182c5b4a;rport Max-Forwards: 70 From: "foo" ;tag=as60391556 To: Contact: Call-ID: 37f774cb1c2acb600e7a967f1e874b6a@192.168.15.137 CSeq: 102 INVITE User-Agent: Asterisk PBX 1.6.0.15 Remote-Party-ID: "foo" ;privacy=full;screen=no Date: Fri, 18 Sep 2009 18:54:48 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Content-Type: application/sdp Content-Length: 313 v=0 o=root 467250073 467250073 IN IP4 192.168.15.137 s=Asterisk PBX 1.6.0.15 c=IN IP4 192.168.15.137 t=0 0 m=audio 16244 RTP/AVP 0 3 8 101 a=rtpmap:0 PCMU/8000 a=rtpmap:3 GSM/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv --- [Sep 18 14:54:49] VERBOSE[28699] logger.c: Retransmitting #3 (no NAT) to 192.168.15.138:5060: INVITE sip:201@192.168.15.138 SIP/2.0 Via: SIP/2.0/UDP 192.168.15.137:5060;branch=z9hG4bK182c5b4a;rport Max-Forwards: 70 From: "foo" ;tag=as60391556 To: Contact: Call-ID: 37f774cb1c2acb600e7a967f1e874b6a@192.168.15.137 CSeq: 102 INVITE User-Agent: Asterisk PBX 1.6.0.15 Remote-Party-ID: "foo" ;privacy=full;screen=no Date: Fri, 18 Sep 2009 18:54:48 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Content-Type: application/sdp Content-Length: 313 v=0 o=root 467250073 467250073 IN IP4 192.168.15.137 s=Asterisk PBX 1.6.0.15 c=IN IP4 192.168.15.137 t=0 0 m=audio 16244 RTP/AVP 0 3 8 101 a=rtpmap:0 PCMU/8000 a=rtpmap:3 GSM/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv --- [Sep 18 14:54:50] VERBOSE[28699] logger.c: Retransmitting #4 (no NAT) to 192.168.15.138:5060: INVITE sip:201@192.168.15.138 SIP/2.0 Via: SIP/2.0/UDP 192.168.15.137:5060;branch=z9hG4bK182c5b4a;rport Max-Forwards: 70 From: "foo" ;tag=as60391556 To: Contact: Call-ID: 37f774cb1c2acb600e7a967f1e874b6a@192.168.15.137 CSeq: 102 INVITE User-Agent: Asterisk PBX 1.6.0.15 Remote-Party-ID: "foo" ;privacy=full;screen=no Date: Fri, 18 Sep 2009 18:54:48 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Content-Type: application/sdp Content-Length: 313 v=0 o=root 467250073 467250073 IN IP4 192.168.15.137 s=Asterisk PBX 1.6.0.15 c=IN IP4 192.168.15.137 t=0 0 m=audio 16244 RTP/AVP 0 3 8 101 a=rtpmap:0 PCMU/8000 a=rtpmap:3 GSM/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv --- [Sep 18 14:54:51] VERBOSE[28699] logger.c: Retransmitting #5 (no NAT) to 192.168.15.138:5060: INVITE sip:201@192.168.15.138 SIP/2.0 Via: SIP/2.0/UDP 192.168.15.137:5060;branch=z9hG4bK182c5b4a;rport Max-Forwards: 70 From: "foo" ;tag=as60391556 To: Contact: Call-ID: 37f774cb1c2acb600e7a967f1e874b6a@192.168.15.137 CSeq: 102 INVITE User-Agent: Asterisk PBX 1.6.0.15 Remote-Party-ID: "foo" ;privacy=full;screen=no Date: Fri, 18 Sep 2009 18:54:48 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Content-Type: application/sdp Content-Length: 313 v=0 o=root 467250073 467250073 IN IP4 192.168.15.137 s=Asterisk PBX 1.6.0.15 c=IN IP4 192.168.15.137 t=0 0 m=audio 16244 RTP/AVP 0 3 8 101 a=rtpmap:0 PCMU/8000 a=rtpmap:3 GSM/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv --- [Sep 18 14:54:55] VERBOSE[28699] logger.c: Retransmitting #6 (no NAT) to 192.168.15.138:5060: INVITE sip:201@192.168.15.138 SIP/2.0 Via: SIP/2.0/UDP 192.168.15.137:5060;branch=z9hG4bK182c5b4a;rport Max-Forwards: 70 From: "foo" ;tag=as60391556 To: Contact: Call-ID: 37f774cb1c2acb600e7a967f1e874b6a@192.168.15.137 CSeq: 102 INVITE User-Agent: Asterisk PBX 1.6.0.15 Remote-Party-ID: "foo" ;privacy=full;screen=no Date: Fri, 18 Sep 2009 18:54:48 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Content-Type: application/sdp Content-Length: 313 v=0 o=root 467250073 467250073 IN IP4 192.168.15.137 s=Asterisk PBX 1.6.0.15 c=IN IP4 192.168.15.137 t=0 0 m=audio 16244 RTP/AVP 0 3 8 101 a=rtpmap:0 PCMU/8000 a=rtpmap:3 GSM/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv --- [Sep 18 14:54:58] VERBOSE[28681] logger.c: T203 counter expired, sending RR and scheduling T203 again [Sep 18 14:54:58] VERBOSE[28681] logger.c: Sending Receiver Ready (28) [Sep 18 14:54:58] VERBOSE[28681] logger.c: > [ 02 01 01 39 ] [Sep 18 14:54:58] VERBOSE[28681] logger.c: > Supervisory frame: [Sep 18 14:54:58] VERBOSE[28681] logger.c: > SAPI: 00 C/R: 1 EA: 0 > TEI: 000 EA: 1 [Sep 18 14:54:58] VERBOSE[28681] logger.c: > Zero: 0 S: 0 01: 1 [ RR (receive ready) ] > N(R): 028 P/F: 1 > 0 bytes of data [Sep 18 14:54:58] VERBOSE[28681] logger.c: < [ 02 01 01 33 ] [Sep 18 14:54:58] VERBOSE[28681] logger.c: < Supervisory frame: [Sep 18 14:54:58] VERBOSE[28681] logger.c: < SAPI: 00 C/R: 1 EA: 0 < TEI: 000 EA: 1 [Sep 18 14:54:58] VERBOSE[28681] logger.c: < Zero: 0 S: 0 01: 1 [ RR (receive ready) ] < N(R): 025 P/F: 1 < 0 bytes of data [Sep 18 14:54:58] VERBOSE[28681] logger.c: Handling message for SAPI/TEI=0/0 [Sep 18 14:54:58] VERBOSE[28681] logger.c: -- ACKing all packets from 24 to (but not including) 25 [Sep 18 14:54:58] VERBOSE[28681] logger.c: -- Since there was nothing left, stopping T200 counter [Sep 18 14:54:58] VERBOSE[28681] logger.c: -- Stopping T203 counter since we got an ACK [Sep 18 14:54:58] VERBOSE[28681] logger.c: -- Nothing left, starting T203 counter [Sep 18 14:54:58] VERBOSE[28681] logger.c: -- Got RR response to our frame [Sep 18 14:54:58] VERBOSE[28681] logger.c: -- Restarting T203 timer [Sep 18 14:54:58] VERBOSE[28699] logger.c: Really destroying SIP dialog '0d08bc7e750483f3352506a3645c723c@127.0.0.1' Method: REGISTER [Sep 18 14:54:59] VERBOSE[28699] logger.c: Really destroying SIP dialog '1634214630f8255f45f19fc36c05b6e5@192.168.15.40' Method: OPTIONS [Sep 18 14:55:00] VERBOSE[28699] logger.c: <--- SIP read from UDP://192.168.15.138:5060 ---> REGISTER sip:192.168.15.137 SIP/2.0 Via: SIP/2.0/UDP 192.168.15.138;branch=z9hG4bKac228762463 Max-Forwards: 70 From: ;tag=1c228759572 To: Call-ID: 667454741120000012@192.168.15.138 CSeq: 2078 REGISTER Contact: ;expires=180 Supported: em,timer,replaces,path,resource-priority Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE Expires: 180 User-Agent: Audiocodes-Sip-Gateway-MP-114 FXS_FXO/v.5.00A.024 Content-Length: 0 <-------------> [Sep 18 14:55:00] VERBOSE[28699] logger.c: --- (13 headers 0 lines) --- [Sep 18 14:55:00] VERBOSE[28699] logger.c: Sending to 192.168.15.138 : 5060 (no NAT) [Sep 18 14:55:00] VERBOSE[28699] logger.c: <--- Transmitting (no NAT) to 192.168.15.138:5060 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 192.168.15.138;branch=z9hG4bKac228762463;received=192.168.15.138 From: ;tag=1c228759572 To: ;tag=as7567549c Call-ID: 667454741120000012@192.168.15.138 CSeq: 2078 REGISTER User-Agent: Asterisk PBX 1.6.0.15 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="587260a8" Content-Length: 0 <------------> [Sep 18 14:55:00] VERBOSE[28699] logger.c: Scheduling destruction of SIP dialog '667454741120000012@192.168.15.138' in 32000 ms (Method: REGISTER) [Sep 18 14:55:00] VERBOSE[28699] logger.c: <--- SIP read from UDP://192.168.15.138:5060 ---> REGISTER sip:192.168.15.137 SIP/2.0 Via: SIP/2.0/UDP 192.168.15.138;branch=z9hG4bKac228830436 Max-Forwards: 70 From: ;tag=1c228759572 To: Call-ID: 667454741120000012@192.168.15.138 CSeq: 2079 REGISTER Authorization: Digest username="AudioCodesFXO2",realm="asterisk",nonce="587260a8",uri="sip:192.168.15.137",algorithm=MD5,response="3595687241692c34f6371dd7e81fcb8e" Contact: ;expires=180 Supported: em,timer,replaces,path,resource-priority Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE Expires: 180 User-Agent: Audiocodes-Sip-Gateway-MP-114 FXS_FXO/v.5.00A.024 Content-Length: 0 <-------------> [Sep 18 14:55:00] VERBOSE[28699] logger.c: --- (14 headers 0 lines) --- [Sep 18 14:55:00] VERBOSE[28699] logger.c: Sending to 192.168.15.138 : 5060 (no NAT) [Sep 18 14:55:00] VERBOSE[28699] logger.c: Reliably Transmitting (no NAT) to 192.168.15.138:5060: OPTIONS sip:AudioCodesFXO2@192.168.15.138 SIP/2.0 Via: SIP/2.0/UDP 192.168.15.137:5060;branch=z9hG4bK12cce312;rport Max-Forwards: 70 From: "asterisk" ;tag=as73277276 To: Contact: Call-ID: 6388188d667ed96f1a50fabb77cefde1@192.168.15.137 CSeq: 102 OPTIONS User-Agent: Asterisk PBX 1.6.0.15 Date: Fri, 18 Sep 2009 18:55:00 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Content-Length: 0 --- [Sep 18 14:55:00] VERBOSE[28699] logger.c: <--- Transmitting (no NAT) to 192.168.15.138:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.15.138;branch=z9hG4bKac228830436;received=192.168.15.138 From: ;tag=1c228759572 To: ;tag=as7567549c Call-ID: 667454741120000012@192.168.15.138 CSeq: 2079 REGISTER User-Agent: Asterisk PBX 1.6.0.15 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Expires: 180 Contact: ;expires=180 Date: Fri, 18 Sep 2009 18:55:00 GMT Content-Length: 0 <------------> [Sep 18 14:55:00] VERBOSE[28699] logger.c: Scheduling destruction of SIP dialog '667454741120000012@192.168.15.138' in 32000 ms (Method: REGISTER) [Sep 18 14:55:00] VERBOSE[28699] logger.c: <--- SIP read from UDP://192.168.15.138:5060 ---> SIP/2.0 404 Not Found Via: SIP/2.0/UDP 192.168.15.137:5060;branch=z9hG4bK12cce312;rport From: "asterisk" ;tag=as73277276 To: ;tag=1c228898224 Call-ID: 6388188d667ed96f1a50fabb77cefde1@192.168.15.137 CSeq: 102 OPTIONS Supported: em,100rel,timer,replaces,path,resource-priority Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE Content-Length: 0 <-------------> [Sep 18 14:55:00] VERBOSE[28699] logger.c: --- (9 headers 0 lines) --- [Sep 18 14:55:00] VERBOSE[28699] logger.c: Really destroying SIP dialog '6388188d667ed96f1a50fabb77cefde1@192.168.15.137' Method: OPTIONS [Sep 18 14:55:01] WARNING[28699] chan_sip.c: Maximum retries exceeded on transmission 37f774cb1c2acb600e7a967f1e874b6a@192.168.15.137 for seqno 102 (Critical Request) -- See doc/sip-retransmit.txt. [Sep 18 14:55:01] WARNING[28699] chan_sip.c: Hanging up call 37f774cb1c2acb600e7a967f1e874b6a@192.168.15.137 - no reply to our critical packet (see doc/sip-retransmit.txt). [Sep 18 14:55:01] VERBOSE[28762] logger.c: == Everyone is busy/congested at this time (1:0/0/1) [Sep 18 14:55:01] VERBOSE[28762] logger.c: -- Executing [3171111@trunkhandler_incoming_custom:3] Goto("DAHDI/23-1", "trunkhandler_incoming,1111,1") in new stack [Sep 18 14:55:01] VERBOSE[28762] logger.c: -- Goto (trunkhandler_incoming,1111,1) [Sep 18 14:55:01] VERBOSE[28762] logger.c: -- Executing [1111@trunkhandler_incoming:1] Wait("DAHDI/23-1", ".50") in new stack [Sep 18 14:55:02] VERBOSE[28762] logger.c: -- Executing [1111@trunkhandler_incoming:2] NoOp("DAHDI/23-1", "CALL FROM: foo <> To: 1111") in new stack [Sep 18 14:55:02] VERBOSE[28762] logger.c: -- Executing [1111@trunkhandler_incoming:3] Monitor("DAHDI/23-1", "WAV,,bm") in new stack [Sep 18 14:55:02] VERBOSE[28762] logger.c: -- Executing [1111@trunkhandler_incoming:4] Set("DAHDI/23-1", "__dialed_number=8143171111") in new stack [Sep 18 14:55:02] VERBOSE[28762] logger.c: -- Executing [1111@trunkhandler_incoming:5] Gosub("DAHDI/23-1", "log_calls_init,s,1(answerlinks)") in new stack [Sep 18 14:55:02] VERBOSE[28762] logger.c: -- Executing [s@log_calls_init:1] Set("DAHDI/23-1", "LOCAL(userfield)=answerlinks") in new stack [Sep 18 14:55:02] VERBOSE[28762] logger.c: -- Executing [s@log_calls_init:2] Set("DAHDI/23-1", "__call_log_id=1672954") in new stack [Sep 18 14:55:02] VERBOSE[28762] logger.c: -- Executing [s@log_calls_init:3] Set("DAHDI/23-1", "ODBC_CALLS_CallStart("1672954","2009-09-18 14:54:48","1253300088.39","DAHDI/23-1","foo","","8143171111")=1") in new stack [Sep 18 14:55:02] WARNING[28762] pbx.c: Please avoid unnecessary spaces on variables as it may lead to unexpected results ('ODBC_CALLS_CallStart(1672954,2009-09-18 14:54:48,1253300088.39,DAHDI/23-1,foo,,8143171111)' set to '1'). [Sep 18 14:55:02] VERBOSE[28762] logger.c: -- Executing [s@log_calls_init:4] Set("DAHDI/23-1", "ODBC_CALLS_AppendUserField(1672954,answerlinks)=1") in new stack [Sep 18 14:55:02] VERBOSE[28762] logger.c: -- Executing [s@log_calls_init:5] Return("DAHDI/23-1", "") in new stack [Sep 18 14:55:02] VERBOSE[28762] logger.c: -- Executing [1111@trunkhandler_incoming:6] Set("DAHDI/23-1", "we_handle_calls=1") in new stack [Sep 18 14:55:02] VERBOSE[28762] logger.c: -- Executing [1111@trunkhandler_incoming:7] GotoIf("DAHDI/23-1", "1?8:11") in new stack [Sep 18 14:55:02] VERBOSE[28762] logger.c: -- Goto (trunkhandler_incoming,1111,8) [Sep 18 14:55:02] VERBOSE[28762] logger.c: -- Executing [1111@trunkhandler_incoming:8] Set("DAHDI/23-1", "ODBC_CALLS_SetAccountCode(1672954,8143171111)=1") in new stack [Sep 18 14:55:02] VERBOSE[28762] logger.c: -- Executing [1111@trunkhandler_incoming:9] Gosub("DAHDI/23-1", "handleIncomingCall,s,1(1111)") in new stack [Sep 18 14:55:02] VERBOSE[28762] logger.c: -- Executing [s@handleIncomingCall:1] Set("DAHDI/23-1", "LOCAL(dialed_number)=1111") in new stack [Sep 18 14:55:02] VERBOSE[28762] logger.c: -- Executing [s@handleIncomingCall:2] Answer("DAHDI/23-1", "") in new stack [Sep 18 14:55:02] VERBOSE[28762] logger.c: q931.c:2943 q931_connect: call 1689 on channel 23 enters state 10 (Active) [Sep 18 14:55:02] VERBOSE[28762] logger.c: > [ 02 01 32 38 08 02 86 99 07 18 03 a9 83 97 1e 02 81 82 ] [Sep 18 14:55:02] VERBOSE[28762] logger.c: > Informational frame: [Sep 18 14:55:02] VERBOSE[28762] logger.c: > SAPI: 00 C/R: 1 EA: 0 > TEI: 000 EA: 1 [Sep 18 14:55:02] VERBOSE[28762] logger.c: > N(S): 025 0: 0 > N(R): 028 P: 0 > 14 bytes of data [Sep 18 14:55:02] VERBOSE[28762] logger.c: Stopping T_203 timer [Sep 18 14:55:02] VERBOSE[28762] logger.c: Starting T_200 timer [Sep 18 14:55:02] VERBOSE[28762] logger.c: -- Restarting T200 timer [Sep 18 14:55:02] VERBOSE[28762] logger.c: > Protocol Discriminator: Q.931 (8) len=14 [Sep 18 14:55:02] VERBOSE[28762] logger.c: > Call Ref: len= 2 (reference 1689/0x699) (Terminator) [Sep 18 14:55:02] VERBOSE[28762] logger.c: > Message type: CONNECT (7) [Sep 18 14:55:02] VERBOSE[28762] logger.c: > [18 03 a9 83 97] [Sep 18 14:55:02] VERBOSE[28762] logger.c: > Channel ID (len= 5) [ Ext: 1 IntID: Implicit PRI Spare: 0 Exclusive Dchan: 0 [Sep 18 14:55:02] VERBOSE[28762] logger.c: > ChanSel: As indicated in following octets [Sep 18 14:55:02] VERBOSE[28762] logger.c: > Ext: 1 Coding: 0 Number Specified Channel Type: 3 [Sep 18 14:55:02] VERBOSE[28762] logger.c: > Ext: 1 Channel: 23 ] [Sep 18 14:55:02] VERBOSE[28762] logger.c: > [1e 02 81 82] [Sep 18 14:55:02] VERBOSE[28762] logger.c: > Progress Indicator (len= 4) [ Ext: 1 Coding: CCITT (ITU) standard (0) 0: 0 Location: Private network serving the local user (1) [Sep 18 14:55:02] VERBOSE[28762] logger.c: > Ext: 1 Progress Description: Called equipment is non-ISDN. (2) ] [Sep 18 14:55:02] VERBOSE[28762] logger.c: -- Executing [s@handleIncomingCall:3] Ringing("DAHDI/23-1", "") in new stack [Sep 18 14:55:02] VERBOSE[28762] logger.c: -- Executing [s@handleIncomingCall:4] Set("DAHDI/23-1", "__dialed_number=1111") in new stack [Sep 18 14:55:02] VERBOSE[28762] logger.c: -- Executing [s@handleIncomingCall:5] NoOp("DAHDI/23-1", "DEBUG: 1253300088.39 Handle Incoming Call - To 1111 - From: foo <>") in new stack [Sep 18 14:55:02] VERBOSE[28762] logger.c: -- Executing [s@handleIncomingCall:6] Set("DAHDI/23-1", "__callerid_name=foo") in new stack [Sep 18 14:55:02] VERBOSE[28762] logger.c: -- Executing [s@handleIncomingCall:7] Set("DAHDI/23-1", "__callerid_num=") in new stack [Sep 18 14:55:02] VERBOSE[28762] logger.c: -- Executing [s@handleIncomingCall:8] Set("DAHDI/23-1", "__dest_exten=bronze") in new stack [Sep 18 14:55:02] VERBOSE[28762] logger.c: -- Executing [s@handleIncomingCall:9] Set("DAHDI/23-1", "__dest_context=incoming_queues") in new stack [Sep 18 14:55:02] VERBOSE[28681] logger.c: < [ 02 01 01 34 ] [Sep 18 14:55:02] VERBOSE[28681] logger.c: < Supervisory frame: [Sep 18 14:55:02] VERBOSE[28681] logger.c: < SAPI: 00 C/R: 1 EA: 0 < TEI: 000 EA: 1 [Sep 18 14:55:02] VERBOSE[28681] logger.c: < Zero: 0 S: 0 01: 1 [ RR (receive ready) ] < N(R): 026 P/F: 0 < 0 bytes of data [Sep 18 14:55:02] VERBOSE[28681] logger.c: Handling message for SAPI/TEI=0/0 [Sep 18 14:55:02] VERBOSE[28681] logger.c: -- ACKing all packets from 24 to (but not including) 26 [Sep 18 14:55:02] VERBOSE[28681] logger.c: -- ACKing packet 25, new txqueue is -1 (-1 means empty) [Sep 18 14:55:02] VERBOSE[28681] logger.c: -- Since there was nothing left, stopping T200 counter [Sep 18 14:55:02] VERBOSE[28681] logger.c: -- Nothing left, starting T203 counter [Sep 18 14:55:02] VERBOSE[28681] logger.c: -- Restarting T203 timer [Sep 18 14:55:02] VERBOSE[28762] logger.c: -- Executing [s@handleIncomingCall:10] Set("DAHDI/23-1", "__dest_name=Belis Urologic") in new stack [Sep 18 14:55:02] VERBOSE[28762] logger.c: -- Executing [s@handleIncomingCall:11] Set("DAHDI/23-1", "__dest_number=1111") in new stack [Sep 18 14:55:02] VERBOSE[28762] logger.c: -- Executing [s@handleIncomingCall:12] Set("DAHDI/23-1", "__parent_UNIQUEID=1253300088.39") in new stack [Sep 18 14:55:02] VERBOSE[28762] logger.c: -- Executing [s@handleIncomingCall:13] Set("DAHDI/23-1", "CALLERID(name)="Belis Urologic"") in new stack [Sep 18 14:55:02] VERBOSE[28762] logger.c: -- Executing [s@handleIncomingCall:14] Set("DAHDI/23-1", "CALLERID(num)="1111"") in new stack [Sep 18 14:55:02] VERBOSE[28762] logger.c: -- Executing [s@handleIncomingCall:15] GotoIf("DAHDI/23-1", "0?16:26") in new stack [Sep 18 14:55:02] VERBOSE[28762] logger.c: -- Goto (handleIncomingCall,s,26) [Sep 18 14:55:02] VERBOSE[28762] logger.c: -- Executing [s@handleIncomingCall:26] NoOp("DAHDI/23-1", "Finish if-handleIncomingCall-85") in new stack [Sep 18 14:55:02] VERBOSE[28762] logger.c: -- Executing [s@handleIncomingCall:27] NoOp("DAHDI/23-1", "DEBUG: 1253300088.39 Handle Incoming Call - Destination bronze@incoming_queues - Belis Urologic") in new stack [Sep 18 14:55:02] VERBOSE[28762] logger.c: -- Executing [s@handleIncomingCall:28] Gosub("DAHDI/23-1", "incoming_queues,bronze,1") in new stack [Sep 18 14:55:02] VERBOSE[28762] logger.c: -- Executing [bronze@incoming_queues:1] NoOp("DAHDI/23-1", "DEBUG: 1253300088.39 Entering Bronze Handler") in new stack [Sep 18 14:55:02] VERBOSE[28762] logger.c: -- Executing [bronze@incoming_queues:2] Goto("DAHDI/23-1", "queue_helper,bronze,1") in new stack [Sep 18 14:55:02] VERBOSE[28762] logger.c: -- Goto (queue_helper,bronze,1) [Sep 18 14:55:02] VERBOSE[28762] logger.c: -- Executing [bronze@queue_helper:1] Set("DAHDI/23-1", "__ringall_group=bronze") in new stack [Sep 18 14:55:02] VERBOSE[28762] logger.c: -- Executing [bronze@queue_helper:2] GotoIf("DAHDI/23-1", "1?3:11") in new stack [Sep 18 14:55:02] VERBOSE[28762] logger.c: -- Goto (queue_helper,bronze,3) [Sep 18 14:55:02] VERBOSE[28762] logger.c: -- Executing [bronze@queue_helper:3] NoOp("DAHDI/23-1", "DEBUG: 1253300088.39 Entering Ringall Bronze") in new stack [Sep 18 14:55:02] VERBOSE[28762] logger.c: -- Executing [bronze@queue_helper:4] Gosub("DAHDI/23-1", "queue_join,s,1(bronze)") in new stack [Sep 18 14:55:02] VERBOSE[28762] logger.c: -- Executing [s@queue_join:1] Set("DAHDI/23-1", "LOCAL(queue)=bronze") in new stack [Sep 18 14:55:02] VERBOSE[28762] logger.c: -- Executing [s@queue_join:2] UserEvent("DAHDI/23-1", "QueueJoin,Channel:DAHDI/23-1,Queue:bronze,SrcNum:,SrcName:foo") in new stack [Sep 18 14:55:02] VERBOSE[28762] logger.c: -- Executing [s@queue_join:3] Set("DAHDI/23-1", "__queue_current=bronze") in new stack [Sep 18 14:55:02] VERBOSE[28762] logger.c: -- Executing [s@queue_join:4] Set("DAHDI/23-1", "queue_members_gold="SIP/201,SIP/202,SIP/203,SIP/204,SIP/205,SIP/206"") in new stack [Sep 18 14:55:02] VERBOSE[28762] logger.c: -- Executing [s@queue_join:5] Set("DAHDI/23-1", "queue_members_gold="SIP/201,SIP/202,SIP/203,SIP/204,SIP/205,SIP/206,SIP/207,SIP/208,SIP/209,SIP/210,SIP/211,SIP/212,SIP/213"") in new stack [Sep 18 14:55:02] VERBOSE[28762] logger.c: -- Executing [s@queue_join:6] GotoIf("DAHDI/23-1", "1?7:12") in new stack [Sep 18 14:55:02] VERBOSE[28762] logger.c: -- Goto (queue_join,s,7) [Sep 18 14:55:02] VERBOSE[28762] logger.c: -- Executing [s@queue_join:7] Set("DAHDI/23-1", "queue_members=""") in new stack [Sep 18 14:55:02] VERBOSE[28762] logger.c: -- Executing [s@queue_join:8] GotoIf("DAHDI/23-1", "1?9:10") in new stack [Sep 18 14:55:02] VERBOSE[28762] logger.c: -- Goto (queue_join,s,9) [Sep 18 14:55:02] VERBOSE[28762] logger.c: -- Executing [s@queue_join:9] Set("DAHDI/23-1", "queue_members=SIP/201,SIP/202,SIP/203,SIP/204,SIP/205,SIP/206,SIP/207,SIP/208,SIP/209,SIP/210,SIP/211,SIP/212,SIP/213") in new stack [Sep 18 14:55:02] WARNING[28762] pbx.c: MSet: ignoring entry 'SIP/202' with no '=' (in s@queue_join:9 [Sep 18 14:55:02] WARNING[28762] pbx.c: MSet: ignoring entry 'SIP/203' with no '=' (in s@queue_join:9 [Sep 18 14:55:02] WARNING[28762] pbx.c: MSet: ignoring entry 'SIP/204' with no '=' (in s@queue_join:9 [Sep 18 14:55:02] WARNING[28762] pbx.c: MSet: ignoring entry 'SIP/205' with no '=' (in s@queue_join:9 [Sep 18 14:55:02] WARNING[28762] pbx.c: MSet: ignoring entry 'SIP/206' with no '=' (in s@queue_join:9 [Sep 18 14:55:02] WARNING[28762] pbx.c: MSet: ignoring entry 'SIP/207' with no '=' (in s@queue_join:9 [Sep 18 14:55:02] WARNING[28762] pbx.c: MSet: ignoring entry 'SIP/208' with no '=' (in s@queue_join:9 [Sep 18 14:55:02] WARNING[28762] pbx.c: MSet: ignoring entry 'SIP/209' with no '=' (in s@queue_join:9 [Sep 18 14:55:02] WARNING[28762] pbx.c: MSet: ignoring entry 'SIP/210' with no '=' (in s@queue_join:9 [Sep 18 14:55:02] WARNING[28762] pbx.c: MSet: ignoring entry 'SIP/211' with no '=' (in s@queue_join:9 [Sep 18 14:55:02] WARNING[28762] pbx.c: MSet: ignoring entry 'SIP/212' with no '=' (in s@queue_join:9 [Sep 18 14:55:02] WARNING[28762] pbx.c: MSet: ignoring entry 'SIP/213' with no '=' (in s@queue_join:9 [Sep 18 14:55:02] VERBOSE[28762] logger.c: -- Executing [s@queue_join:10] NoOp("DAHDI/23-1", "Finish if-if-queue_join-98-99") in new stack [Sep 18 14:55:02] VERBOSE[28762] logger.c: -- Executing [s@queue_join:11] Goto("DAHDI/23-1", "17") in new stack [Sep 18 14:55:02] VERBOSE[28762] logger.c: -- Goto (queue_join,s,17) [Sep 18 14:55:02] VERBOSE[28762] logger.c: -- Executing [s@queue_join:17] NoOp("DAHDI/23-1", "Finish if-queue_join-98") in new stack [Sep 18 14:55:02] VERBOSE[28762] logger.c: -- Executing [s@queue_join:18] Set("DAHDI/23-1", "member_count=1") in new stack [Sep 18 14:55:02] VERBOSE[28762] logger.c: -- Executing [s@queue_join:19] Set("DAHDI/23-1", "dial=""") in new stack [Sep 18 14:55:02] VERBOSE[28762] logger.c: -- Executing [s@queue_join:20] Set("DAHDI/23-1", "i=0") in new stack [Sep 18 14:55:02] VERBOSE[28762] logger.c: -- Executing [s@queue_join:21] GotoIf("DAHDI/23-1", "1?22:29") in new stack [Sep 18 14:55:02] VERBOSE[28762] logger.c: -- Goto (queue_join,s,22) [Sep 18 14:55:02] VERBOSE[28762] logger.c: -- Executing [s@queue_join:22] Set("DAHDI/23-1", "pos=1") in new stack [Sep 18 14:55:02] VERBOSE[28762] logger.c: -- Executing [s@queue_join:23] Set("DAHDI/23-1", "member=SIP/201") in new stack [Sep 18 14:55:02] VERBOSE[28762] logger.c: -- Executing [s@queue_join:24] Set("DAHDI/23-1", "device=U0lQLzIwMQ==") in new stack [Sep 18 14:55:02] VERBOSE[28762] logger.c: -- Executing [s@queue_join:25] Set("DAHDI/23-1", "foo=SIP/201") in new stack [Sep 18 14:55:02] VERBOSE[28762] logger.c: -- Executing [s@queue_join:26] Set("DAHDI/23-1", "dial="&Local/U0lQLzIwMQ==@queue_keeptrying_extension"") in new stack [Sep 18 14:55:02] VERBOSE[28762] logger.c: -- Executing [s@queue_join:27] Set("DAHDI/23-1", "i=1") in new stack [Sep 18 14:55:02] VERBOSE[28762] logger.c: -- Executing [s@queue_join:28] Goto("DAHDI/23-1", "21") in new stack [Sep 18 14:55:02] VERBOSE[28762] logger.c: -- Goto (queue_join,s,21) [Sep 18 14:55:02] VERBOSE[28762] logger.c: -- Executing [s@queue_join:21] GotoIf("DAHDI/23-1", "0?22:29") in new stack [Sep 18 14:55:02] VERBOSE[28762] logger.c: -- Goto (queue_join,s,29) [Sep 18 14:55:02] VERBOSE[28762] logger.c: -- Executing [s@queue_join:29] NoOp("DAHDI/23-1", "Finish for-queue_join-101") in new stack [Sep 18 14:55:02] VERBOSE[28762] logger.c: -- Executing [s@queue_join:30] Set("DAHDI/23-1", "dial=Local/U0lQLzIwMQ==@queue_keeptrying_extension") in new stack [Sep 18 14:55:02] VERBOSE[28762] logger.c: -- Executing [s@queue_join:31] Set("DAHDI/23-1", "CHANNEL(musicclass)=ring") in new stack [Sep 18 14:55:02] VERBOSE[28762] logger.c: -- Executing [s@queue_join:32] Answer("DAHDI/23-1", "") in new stack [Sep 18 14:55:02] VERBOSE[28762] logger.c: -- Executing [s@queue_join:33] Dial("DAHDI/23-1", "Local/U0lQLzIwMQ==@queue_keeptrying_extension,,mM(ringall-pickup)") in new stack [Sep 18 14:55:02] VERBOSE[28764] logger.c: -- Executing [U0lQLzIwMQ==@queue_keeptrying_extension:1] Set("Local/U0lQLzIwMQ==@queue_keeptrying_extension-296e;2", "dial=SIP/201") in new stack [Sep 18 14:55:02] VERBOSE[28764] logger.c: -- Executing [U0lQLzIwMQ==@queue_keeptrying_extension:2] GotoIf("Local/U0lQLzIwMQ==@queue_keeptrying_extension-296e;2", "1?3:11") in new stack [Sep 18 14:55:02] VERBOSE[28764] logger.c: -- Goto (queue_keeptrying_extension,U0lQLzIwMQ==,3) [Sep 18 14:55:02] VERBOSE[28764] logger.c: -- Executing [U0lQLzIwMQ==@queue_keeptrying_extension:3] Dial("Local/U0lQLzIwMQ==@queue_keeptrying_extension-296e;2", "SIP/201") in new stack [Sep 18 14:55:02] VERBOSE[28764] logger.c: == Using SIP RTP CoS mark 5 [Sep 18 14:55:02] WARNING[28764] chan_sip.c: Unsupported callingpres (-1) [Sep 18 14:55:02] VERBOSE[28764] logger.c: Audio is at 192.168.15.137 port 16308 [Sep 18 14:55:02] VERBOSE[28764] logger.c: Adding codec 0x4 (ulaw) to SDP [Sep 18 14:55:02] VERBOSE[28764] logger.c: Adding codec 0x2 (gsm) to SDP [Sep 18 14:55:02] VERBOSE[28764] logger.c: Adding codec 0x8 (alaw) to SDP [Sep 18 14:55:02] VERBOSE[28764] logger.c: Adding non-codec 0x1 (telephone-event) to SDP [Sep 18 14:55:02] VERBOSE[28764] logger.c: Reliably Transmitting (no NAT) to 192.168.15.138:5060: INVITE sip:201@192.168.15.138 SIP/2.0 Via: SIP/2.0/UDP 192.168.15.137:5060;branch=z9hG4bK1cc37fd9;rport Max-Forwards: 70 From: "Belis Urologic" ;tag=as6968a1bb To: Contact: Call-ID: 3a5b4bcd378ba6807414be983ac5395b@192.168.15.137 CSeq: 102 INVITE User-Agent: Asterisk PBX 1.6.0.15 Remote-Party-ID: "Belis Urologic" ;privacy=full;screen=no Date: Fri, 18 Sep 2009 18:55:02 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Content-Type: application/sdp Content-Length: 315 v=0 o=root 1562499233 1562499233 IN IP4 192.168.15.137 s=Asterisk PBX 1.6.0.15 c=IN IP4 192.168.15.137 t=0 0 m=audio 16308 RTP/AVP 0 3 8 101 a=rtpmap:0 PCMU/8000 a=rtpmap:3 GSM/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv --- [Sep 18 14:55:02] VERBOSE[28764] logger.c: -- Called 201 [Sep 18 14:55:02] VERBOSE[28699] logger.c: Really destroying SIP dialog '37f774cb1c2acb600e7a967f1e874b6a@192.168.15.137' Method: INVITE [Sep 18 14:55:02] VERBOSE[28762] logger.c: -- Called U0lQLzIwMQ==@queue_keeptrying_extension [Sep 18 14:55:02] VERBOSE[28762] logger.c: -- Started music on hold, class 'ring', on DAHDI/23-1 [Sep 18 14:55:02] VERBOSE[28762] logger.c: > [ 02 01 34 38 08 02 86 99 03 1e 02 81 88 ] [Sep 18 14:55:02] VERBOSE[28762] logger.c: > Informational frame: [Sep 18 14:55:02] VERBOSE[28762] logger.c: > SAPI: 00 C/R: 1 EA: 0 > TEI: 000 EA: 1 [Sep 18 14:55:02] VERBOSE[28762] logger.c: > N(S): 026 0: 0 > N(R): 028 P: 0 > 9 bytes of data [Sep 18 14:55:02] VERBOSE[28762] logger.c: Stopping T_203 timer [Sep 18 14:55:02] VERBOSE[28762] logger.c: Starting T_200 timer [Sep 18 14:55:02] VERBOSE[28762] logger.c: -- Restarting T200 timer [Sep 18 14:55:02] VERBOSE[28762] logger.c: > Protocol Discriminator: Q.931 (8) len=9 [Sep 18 14:55:02] VERBOSE[28762] logger.c: > Call Ref: len= 2 (reference 1689/0x699) (Terminator) [Sep 18 14:55:02] VERBOSE[28762] logger.c: > Message type: PROGRESS (3) [Sep 18 14:55:02] VERBOSE[28762] logger.c: > [1e 02 81 88] [Sep 18 14:55:02] VERBOSE[28762] logger.c: > Progress Indicator (len= 4) [ Ext: 1 Coding: CCITT (ITU) standard (0) 0: 0 Location: Private network serving the local user (1) [Sep 18 14:55:02] VERBOSE[28762] logger.c: > Ext: 1 Progress Description: Inband information or appropriate pattern now available. (8) ] [Sep 18 14:55:02] VERBOSE[28681] logger.c: < [ 02 01 01 36 ] [Sep 18 14:55:02] VERBOSE[28681] logger.c: < Supervisory frame: [Sep 18 14:55:02] VERBOSE[28681] logger.c: < SAPI: 00 C/R: 1 EA: 0 < TEI: 000 EA: 1 [Sep 18 14:55:02] VERBOSE[28681] logger.c: < Zero: 0 S: 0 01: 1 [ RR (receive ready) ] < N(R): 027 P/F: 0 < 0 bytes of data [Sep 18 14:55:02] VERBOSE[28681] logger.c: Handling message for SAPI/TEI=0/0 [Sep 18 14:55:02] VERBOSE[28681] logger.c: -- ACKing all packets from 25 to (but not including) 27 [Sep 18 14:55:02] VERBOSE[28681] logger.c: -- ACKing packet 26, new txqueue is -1 (-1 means empty) [Sep 18 14:55:02] VERBOSE[28681] logger.c: -- Since there was nothing left, stopping T200 counter [Sep 18 14:55:02] VERBOSE[28681] logger.c: -- Nothing left, starting T203 counter [Sep 18 14:55:02] VERBOSE[28681] logger.c: -- Restarting T203 timer [Sep 18 14:55:02] VERBOSE[28681] logger.c: < [ 00 01 38 36 08 02 06 99 0f ] [Sep 18 14:55:02] VERBOSE[28681] logger.c: < Informational frame: [Sep 18 14:55:02] VERBOSE[28681] logger.c: < SAPI: 00 C/R: 0 EA: 0 < TEI: 000 EA: 1 [Sep 18 14:55:02] VERBOSE[28681] logger.c: < N(S): 028 0: 0 < N(R): 027 P: 0 < 5 bytes of data [Sep 18 14:55:02] VERBOSE[28681] logger.c: Handling message for SAPI/TEI=0/0 [Sep 18 14:55:02] VERBOSE[28681] logger.c: -- ACKing all packets from 26 to (but not including) 27 [Sep 18 14:55:02] VERBOSE[28681] logger.c: -- Since there was nothing left, stopping T200 counter [Sep 18 14:55:02] VERBOSE[28681] logger.c: -- Stopping T203 counter since we got an ACK [Sep 18 14:55:02] VERBOSE[28681] logger.c: -- Nothing left, starting T203 counter [Sep 18 14:55:02] VERBOSE[28681] logger.c: < Protocol Discriminator: Q.931 (8) len=5 [Sep 18 14:55:02] VERBOSE[28681] logger.c: < Call Ref: len= 2 (reference 1689/0x699) (Originator) [Sep 18 14:55:02] VERBOSE[28681] logger.c: < Message type: CONNECT ACKNOWLEDGE (15) [Sep 18 14:55:02] VERBOSE[28681] logger.c: Sending Receiver Ready (29) [Sep 18 14:55:02] VERBOSE[28681] logger.c: > [ 00 01 01 3a ] [Sep 18 14:55:02] VERBOSE[28681] logger.c: > Supervisory frame: [Sep 18 14:55:02] VERBOSE[28681] logger.c: > SAPI: 00 C/R: 0 EA: 0 > TEI: 000 EA: 1 [Sep 18 14:55:02] VERBOSE[28681] logger.c: > Zero: 0 S: 0 01: 1 [ RR (receive ready) ] > N(R): 029 P/F: 0 > 0 bytes of data [Sep 18 14:55:02] VERBOSE[28681] logger.c: -- Restarting T203 timer [Sep 18 14:55:02] VERBOSE[28681] logger.c: < [ 00 01 3a 36 08 02 06 99 7d 08 03 81 e2 03 14 01 0a ] [Sep 18 14:55:02] VERBOSE[28681] logger.c: < Informational frame: [Sep 18 14:55:02] VERBOSE[28681] logger.c: < SAPI: 00 C/R: 0 EA: 0 < TEI: 000 EA: 1 [Sep 18 14:55:02] VERBOSE[28681] logger.c: < N(S): 029 0: 0 < N(R): 027 P: 0 < 13 bytes of data [Sep 18 14:55:02] VERBOSE[28681] logger.c: Handling message for SAPI/TEI=0/0 [Sep 18 14:55:02] VERBOSE[28681] logger.c: -- ACKing all packets from 26 to (but not including) 27 [Sep 18 14:55:02] VERBOSE[28681] logger.c: -- Since there was nothing left, stopping T200 counter [Sep 18 14:55:02] VERBOSE[28681] logger.c: -- Stopping T203 counter since we got an ACK [Sep 18 14:55:02] VERBOSE[28681] logger.c: -- Nothing left, starting T203 counter [Sep 18 14:55:02] VERBOSE[28681] logger.c: < Protocol Discriminator: Q.931 (8) len=13 [Sep 18 14:55:02] VERBOSE[28681] logger.c: < Call Ref: len= 2 (reference 1689/0x699) (Originator) [Sep 18 14:55:02] VERBOSE[28681] logger.c: < Message type: STATUS (125) [Sep 18 14:55:02] VERBOSE[28681] logger.c: < [08 03 81 e2 03] [Sep 18 14:55:02] VERBOSE[28681] logger.c: < Cause (len= 5) [ Ext: 1 Coding: CCITT (ITU) standard (0) Spare: 0 Location: Private network serving the local user (1) [Sep 18 14:55:02] VERBOSE[28681] logger.c: < Ext: 1 Cause: Wrong message (98), class = Protocol Error (e.g. unknown message) (6) ] [Sep 18 14:55:02] VERBOSE[28681] logger.c: < Cause data 1: 03 (3) [Sep 18 14:55:02] VERBOSE[28681] logger.c: < [14 01 0a] [Sep 18 14:55:02] VERBOSE[28681] logger.c: < Call State (len= 3) [ Ext: 0 Coding: CCITT (ITU) standard (0) Call state: Active (10) [Sep 18 14:55:02] VERBOSE[28681] logger.c: -- Processing IE 8 (cs0, Cause) [Sep 18 14:55:02] VERBOSE[28681] logger.c: -- Processing IE 20 (cs0, Call State) [Sep 18 14:55:02] VERBOSE[28681] logger.c: Sending Receiver Ready (30) [Sep 18 14:55:02] VERBOSE[28681] logger.c: > [ 00 01 01 3c ] [Sep 18 14:55:02] VERBOSE[28681] logger.c: > Supervisory frame: [Sep 18 14:55:02] VERBOSE[28681] logger.c: > SAPI: 00 C/R: 0 EA: 0 > TEI: 000 EA: 1 [Sep 18 14:55:02] VERBOSE[28681] logger.c: > Zero: 0 S: 0 01: 1 [ RR (receive ready) ] > N(R): 030 P/F: 0 > 0 bytes of data [Sep 18 14:55:02] VERBOSE[28681] logger.c: -- Restarting T203 timer [Sep 18 14:55:02] VERBOSE[28699] logger.c: <--- SIP read from UDP://192.168.15.138:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.15.137:5060;branch=z9hG4bK1cc37fd9;rport From: "Belis Urologic" ;tag=as6968a1bb To: ;tag=1c233400642 Call-ID: 3a5b4bcd378ba6807414be983ac5395b@192.168.15.137 CSeq: 102 INVITE Supported: em,timer,replaces,path,early-session,resource-priority Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE Server: Audiocodes-Sip-Gateway-MP-114 FXS_FXO/v.5.00A.024 Content-Length: 0 <-------------> [Sep 18 14:55:02] VERBOSE[28699] logger.c: --- (10 headers 0 lines) --- [Sep 18 14:55:02] VERBOSE[28699] logger.c: <--- SIP read from UDP://192.168.15.138:5060 ---> SIP/2.0 180 Ringing Via: SIP/2.0/UDP 192.168.15.137:5060;branch=z9hG4bK1cc37fd9;rport From: "Belis Urologic" ;tag=as6968a1bb To: ;tag=1c233400642 Call-ID: 3a5b4bcd378ba6807414be983ac5395b@192.168.15.137 CSeq: 102 INVITE Contact: Supported: em,timer,replaces,path,early-session,resource-priority Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE Server: Audiocodes-Sip-Gateway-MP-114 FXS_FXO/v.5.00A.024 Content-Length: 0 <-------------> [Sep 18 14:55:02] VERBOSE[28699] logger.c: --- (11 headers 0 lines) --- [Sep 18 14:55:02] VERBOSE[28764] logger.c: -- SIP/201-08271218 is ringing [Sep 18 14:55:02] VERBOSE[28762] logger.c: -- Local/U0lQLzIwMQ==@queue_keeptrying_extension-296e;1 is ringing [Sep 18 14:55:02] VERBOSE[28699] logger.c: Really destroying SIP dialog '4ffea7381fae5fbb1d3e0518043f2e24@127.0.0.1' Method: REGISTER [Sep 18 14:55:02] VERBOSE[28699] logger.c: Really destroying SIP dialog '63c548714d9c4c9818678cca0128ef92@127.0.0.1' Method: REGISTER [Sep 18 14:55:11] VERBOSE[28699] logger.c: <--- SIP read from UDP://192.168.15.40:5062 ---> REGISTER sip:192.168.15.137;transport=UDP SIP/2.0 Via: SIP/2.0/UDP 207.255.24.91:5062;branch=z9hG4bK-d8754z-5b3daf2c3a3f48da-1---d8754z- Max-Forwards: 70 Contact: To: From: ;tag=cac57d5a Call-ID: ODk1NjU5Y2JlZjA5MzdjNjczMzdlOWY1MTJjNDk4ZDA. CSeq: 39 REGISTER Expires: 3600 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, NOTIFY, REFER, MESSAGE, OPTIONS, INFO User-Agent: Zoiper rev.2505 Allow-Events: presence Content-Length: 0 <-------------> [Sep 18 14:55:11] VERBOSE[28699] logger.c: --- (13 headers 0 lines) --- [Sep 18 14:55:11] VERBOSE[28699] logger.c: Sending to 207.255.24.91 : 5062 (no NAT) [Sep 18 14:55:11] VERBOSE[28699] logger.c: <--- Transmitting (no NAT) to 207.255.24.91:5062 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 207.255.24.91:5062;branch=z9hG4bK-d8754z-5b3daf2c3a3f48da-1---d8754z-;received=192.168.15.40 From: ;tag=cac57d5a To: ;tag=as2547ff85 Call-ID: ODk1NjU5Y2JlZjA5MzdjNjczMzdlOWY1MTJjNDk4ZDA. CSeq: 39 REGISTER User-Agent: Asterisk PBX 1.6.0.15 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="42eae8e8" Content-Length: 0 <------------> [Sep 18 14:55:11] VERBOSE[28699] logger.c: Scheduling destruction of SIP dialog 'ODk1NjU5Y2JlZjA5MzdjNjczMzdlOWY1MTJjNDk4ZDA.' in 32000 ms (Method: REGISTER) [Sep 18 14:55:11] VERBOSE[28699] logger.c: <--- SIP read from UDP://192.168.15.40:5062 ---> REGISTER sip:192.168.15.137;transport=UDP SIP/2.0 Via: SIP/2.0/UDP 207.255.24.91:5062;branch=z9hG4bK-d8754z-5b3daf2c3a3f48da-1---d8754z- Max-Forwards: 70 Contact: To: From: ;tag=cac57d5a Call-ID: ODk1NjU5Y2JlZjA5MzdjNjczMzdlOWY1MTJjNDk4ZDA. CSeq: 39 REGISTER Expires: 3600 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, NOTIFY, REFER, MESSAGE, OPTIONS, INFO User-Agent: Zoiper rev.2505 Allow-Events: presence Content-Length: 0 <-------------> [Sep 18 14:55:11] VERBOSE[28699] logger.c: --- (13 headers 0 lines) --- [Sep 18 14:55:11] VERBOSE[28699] logger.c: Sending to 207.255.24.91 : 5062 (no NAT) [Sep 18 14:55:11] VERBOSE[28699] logger.c: <--- Transmitting (no NAT) to 207.255.24.91:5062 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 207.255.24.91:5062;branch=z9hG4bK-d8754z-5b3daf2c3a3f48da-1---d8754z-;received=192.168.15.40 From: ;tag=cac57d5a To: ;tag=as2547ff85 Call-ID: ODk1NjU5Y2JlZjA5MzdjNjczMzdlOWY1MTJjNDk4ZDA. CSeq: 39 REGISTER User-Agent: Asterisk PBX 1.6.0.15 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="42eae8e8" Content-Length: 0 <------------> [Sep 18 14:55:11] VERBOSE[28699] logger.c: Scheduling destruction of SIP dialog 'ODk1NjU5Y2JlZjA5MzdjNjczMzdlOWY1MTJjNDk4ZDA.' in 32000 ms (Method: REGISTER) [Sep 18 14:55:12] VERBOSE[28681] logger.c: T203 counter expired, sending RR and scheduling T203 again [Sep 18 14:55:12] VERBOSE[28681] logger.c: Sending Receiver Ready (30) [Sep 18 14:55:12] VERBOSE[28681] logger.c: > [ 02 01 01 3d ] [Sep 18 14:55:12] VERBOSE[28681] logger.c: > Supervisory frame: [Sep 18 14:55:12] VERBOSE[28681] logger.c: > SAPI: 00 C/R: 1 EA: 0 > TEI: 000 EA: 1 [Sep 18 14:55:12] VERBOSE[28681] logger.c: > Zero: 0 S: 0 01: 1 [ RR (receive ready) ] > N(R): 030 P/F: 1 > 0 bytes of data [Sep 18 14:55:12] VERBOSE[28681] logger.c: < [ 02 01 01 37 ] [Sep 18 14:55:12] VERBOSE[28681] logger.c: < Supervisory frame: [Sep 18 14:55:12] VERBOSE[28681] logger.c: < SAPI: 00 C/R: 1 EA: 0 < TEI: 000 EA: 1 [Sep 18 14:55:12] VERBOSE[28681] logger.c: < Zero: 0 S: 0 01: 1 [ RR (receive ready) ] < N(R): 027 P/F: 1 < 0 bytes of data [Sep 18 14:55:12] VERBOSE[28681] logger.c: Handling message for SAPI/TEI=0/0 [Sep 18 14:55:12] VERBOSE[28681] logger.c: -- ACKing all packets from 26 to (but not including) 27 [Sep 18 14:55:12] VERBOSE[28681] logger.c: -- Since there was nothing left, stopping T200 counter [Sep 18 14:55:12] VERBOSE[28681] logger.c: -- Stopping T203 counter since we got an ACK [Sep 18 14:55:12] VERBOSE[28681] logger.c: -- Nothing left, starting T203 counter [Sep 18 14:55:12] VERBOSE[28681] logger.c: -- Got RR response to our frame [Sep 18 14:55:12] VERBOSE[28681] logger.c: -- Restarting T203 timer [Sep 18 14:55:12] VERBOSE[28699] logger.c: <--- SIP read from UDP://192.168.15.40:5062 ---> REGISTER sip:192.168.15.137;transport=UDP SIP/2.0 Via: SIP/2.0/UDP 207.255.24.91:5062;branch=z9hG4bK-d8754z-5b3daf2c3a3f48da-1---d8754z- Max-Forwards: 70 Contact: To: From: ;tag=cac57d5a Call-ID: ODk1NjU5Y2JlZjA5MzdjNjczMzdlOWY1MTJjNDk4ZDA. CSeq: 39 REGISTER Expires: 3600 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, NOTIFY, REFER, MESSAGE, OPTIONS, INFO User-Agent: Zoiper rev.2505 Allow-Events: presence Content-Length: 0 <-------------> [Sep 18 14:55:12] VERBOSE[28699] logger.c: --- (13 headers 0 lines) --- [Sep 18 14:55:12] VERBOSE[28699] logger.c: Sending to 207.255.24.91 : 5062 (no NAT) [Sep 18 14:55:12] VERBOSE[28699] logger.c: <--- Transmitting (no NAT) to 207.255.24.91:5062 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 207.255.24.91:5062;branch=z9hG4bK-d8754z-5b3daf2c3a3f48da-1---d8754z-;received=192.168.15.40 From: ;tag=cac57d5a To: ;tag=as2547ff85 Call-ID: ODk1NjU5Y2JlZjA5MzdjNjczMzdlOWY1MTJjNDk4ZDA. CSeq: 39 REGISTER User-Agent: Asterisk PBX 1.6.0.15 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="42eae8e8" Content-Length: 0 <------------> [Sep 18 14:55:12] VERBOSE[28699] logger.c: Scheduling destruction of SIP dialog 'ODk1NjU5Y2JlZjA5MzdjNjczMzdlOWY1MTJjNDk4ZDA.' in 32000 ms (Method: REGISTER) [Sep 18 14:55:14] VERBOSE[28699] logger.c: <--- SIP read from UDP://192.168.15.40:5062 ---> REGISTER sip:192.168.15.137;transport=UDP SIP/2.0 Via: SIP/2.0/UDP 207.255.24.91:5062;branch=z9hG4bK-d8754z-5b3daf2c3a3f48da-1---d8754z- Max-Forwards: 70 Contact: To: From: ;tag=cac57d5a Call-ID: ODk1NjU5Y2JlZjA5MzdjNjczMzdlOWY1MTJjNDk4ZDA. CSeq: 39 REGISTER Expires: 3600 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, NOTIFY, REFER, MESSAGE, OPTIONS, INFO User-Agent: Zoiper rev.2505 Allow-Events: presence Content-Length: 0 <-------------> [Sep 18 14:55:14] VERBOSE[28699] logger.c: --- (13 headers 0 lines) --- [Sep 18 14:55:14] VERBOSE[28699] logger.c: Sending to 207.255.24.91 : 5062 (no NAT) [Sep 18 14:55:14] VERBOSE[28699] logger.c: <--- Transmitting (no NAT) to 207.255.24.91:5062 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 207.255.24.91:5062;branch=z9hG4bK-d8754z-5b3daf2c3a3f48da-1---d8754z-;received=192.168.15.40 From: ;tag=cac57d5a To: ;tag=as2547ff85 Call-ID: ODk1NjU5Y2JlZjA5MzdjNjczMzdlOWY1MTJjNDk4ZDA. CSeq: 39 REGISTER User-Agent: Asterisk PBX 1.6.0.15 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="42eae8e8" Content-Length: 0 <------------> [Sep 18 14:55:14] VERBOSE[28699] logger.c: Scheduling destruction of SIP dialog 'ODk1NjU5Y2JlZjA5MzdjNjczMzdlOWY1MTJjNDk4ZDA.' in 32000 ms (Method: REGISTER) [Sep 18 14:55:18] VERBOSE[28699] logger.c: <--- SIP read from UDP://192.168.15.40:5062 ---> REGISTER sip:192.168.15.137;transport=UDP SIP/2.0 Via: SIP/2.0/UDP 207.255.24.91:5062;branch=z9hG4bK-d8754z-5b3daf2c3a3f48da-1---d8754z- Max-Forwards: 70 Contact: To: From: ;tag=cac57d5a Call-ID: ODk1NjU5Y2JlZjA5MzdjNjczMzdlOWY1MTJjNDk4ZDA. CSeq: 39 REGISTER Expires: 3600 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, NOTIFY, REFER, MESSAGE, OPTIONS, INFO User-Agent: Zoiper rev.2505 Allow-Events: presence Content-Length: 0 <-------------> [Sep 18 14:55:18] VERBOSE[28699] logger.c: --- (13 headers 0 lines) --- [Sep 18 14:55:18] VERBOSE[28699] logger.c: Sending to 207.255.24.91 : 5062 (no NAT) [Sep 18 14:55:18] VERBOSE[28699] logger.c: <--- Transmitting (no NAT) to 207.255.24.91:5062 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 207.255.24.91:5062;branch=z9hG4bK-d8754z-5b3daf2c3a3f48da-1---d8754z-;received=192.168.15.40 From: ;tag=cac57d5a To: ;tag=as2547ff85 Call-ID: ODk1NjU5Y2JlZjA5MzdjNjczMzdlOWY1MTJjNDk4ZDA. CSeq: 39 REGISTER User-Agent: Asterisk PBX 1.6.0.15 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="42eae8e8" Content-Length: 0 <------------> [Sep 18 14:55:18] VERBOSE[28699] logger.c: Scheduling destruction of SIP dialog 'ODk1NjU5Y2JlZjA5MzdjNjczMzdlOWY1MTJjNDk4ZDA.' in 32000 ms (Method: REGISTER) [Sep 18 14:55:21] VERBOSE[28699] logger.c: Really destroying SIP dialog '20075945121200014715@192.168.15.138' Method: OPTIONS [Sep 18 14:55:22] VERBOSE[28681] logger.c: T203 counter expired, sending RR and scheduling T203 again [Sep 18 14:55:22] VERBOSE[28681] logger.c: Sending Receiver Ready (30) [Sep 18 14:55:22] VERBOSE[28681] logger.c: > [ 02 01 01 3d ] [Sep 18 14:55:22] VERBOSE[28681] logger.c: > Supervisory frame: [Sep 18 14:55:22] VERBOSE[28681] logger.c: > SAPI: 00 C/R: 1 EA: 0 > TEI: 000 EA: 1 [Sep 18 14:55:22] VERBOSE[28681] logger.c: > Zero: 0 S: 0 01: 1 [ RR (receive ready) ] > N(R): 030 P/F: 1 > 0 bytes of data [Sep 18 14:55:22] VERBOSE[28681] logger.c: < [ 02 01 01 37 ] [Sep 18 14:55:22] VERBOSE[28681] logger.c: < Supervisory frame: [Sep 18 14:55:22] VERBOSE[28681] logger.c: < SAPI: 00 C/R: 1 EA: 0 < TEI: 000 EA: 1 [Sep 18 14:55:22] VERBOSE[28681] logger.c: < Zero: 0 S: 0 01: 1 [ RR (receive ready) ] < N(R): 027 P/F: 1 < 0 bytes of data [Sep 18 14:55:22] VERBOSE[28681] logger.c: Handling message for SAPI/TEI=0/0 [Sep 18 14:55:22] VERBOSE[28681] logger.c: -- ACKing all packets from 26 to (but not including) 27 [Sep 18 14:55:22] VERBOSE[28681] logger.c: -- Since there was nothing left, stopping T200 counter [Sep 18 14:55:22] VERBOSE[28681] logger.c: -- Stopping T203 counter since we got an ACK [Sep 18 14:55:22] VERBOSE[28681] logger.c: -- Nothing left, starting T203 counter [Sep 18 14:55:22] VERBOSE[28681] logger.c: -- Got RR response to our frame [Sep 18 14:55:22] VERBOSE[28681] logger.c: -- Restarting T203 timer [Sep 18 14:55:22] VERBOSE[28699] logger.c: <--- SIP read from UDP://192.168.15.40:5062 ---> REGISTER sip:192.168.15.137;transport=UDP SIP/2.0 Via: SIP/2.0/UDP 207.255.24.91:5062;branch=z9hG4bK-d8754z-5b3daf2c3a3f48da-1---d8754z- Max-Forwards: 70 Contact: To: From: ;tag=cac57d5a Call-ID: ODk1NjU5Y2JlZjA5MzdjNjczMzdlOWY1MTJjNDk4ZDA. CSeq: 39 REGISTER Expires: 3600 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, NOTIFY, REFER, MESSAGE, OPTIONS, INFO User-Agent: Zoiper rev.2505 Allow-Events: presence Content-Length: 0 <-------------> [Sep 18 14:55:22] VERBOSE[28699] logger.c: --- (13 headers 0 lines) --- [Sep 18 14:55:22] VERBOSE[28699] logger.c: Sending to 207.255.24.91 : 5062 (no NAT) [Sep 18 14:55:22] VERBOSE[28699] logger.c: <--- Transmitting (no NAT) to 207.255.24.91:5062 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 207.255.24.91:5062;branch=z9hG4bK-d8754z-5b3daf2c3a3f48da-1---d8754z-;received=192.168.15.40 From: ;tag=cac57d5a To: ;tag=as2547ff85 Call-ID: ODk1NjU5Y2JlZjA5MzdjNjczMzdlOWY1MTJjNDk4ZDA. CSeq: 39 REGISTER User-Agent: Asterisk PBX 1.6.0.15 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="42eae8e8" Content-Length: 0 <------------> [Sep 18 14:55:22] VERBOSE[28699] logger.c: Scheduling destruction of SIP dialog 'ODk1NjU5Y2JlZjA5MzdjNjczMzdlOWY1MTJjNDk4ZDA.' in 32000 ms (Method: REGISTER) [Sep 18 14:55:23] VERBOSE[28699] logger.c: <--- SIP read from UDP://192.168.15.40:5060 ---> BYE sip:3171111@192.168.15.137 SIP/2.0 Via: SIP/2.0/UDP 192.168.15.40:5060;branch=z9hG4bK68feba0b;rport Max-Forwards: 70 From: "Operator One" ;tag=as4279ca14 To: ;tag=as06fc3a40 Call-ID: 58c5533d62eec33054172d2b2a14782d@192.168.15.40 CSeq: 104 BYE User-Agent: Asterisk PBX 1.6.0.6 Authorization: Digest username="205", realm="asterisk", algorithm=MD5, uri="sip:3171111@192.168.15.137", nonce="73e4fb1a", response="0d902a430a71e5846451062ab91f9ad1" X-Asterisk-HangupCause: Normal Clearing X-Asterisk-HangupCauseCode: 16 Content-Length: 0 <-------------> [Sep 18 14:55:23] VERBOSE[28699] logger.c: --- (12 headers 0 lines) --- [Sep 18 14:55:23] VERBOSE[28699] logger.c: Sending to 192.168.15.40 : 5060 (no NAT) [Sep 18 14:55:23] VERBOSE[28699] logger.c: <--- Transmitting (no NAT) to 192.168.15.40:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.15.40:5060;branch=z9hG4bK68feba0b;received=192.168.15.40;rport=5060 From: "Operator One" ;tag=as4279ca14 To: ;tag=as06fc3a40 Call-ID: 58c5533d62eec33054172d2b2a14782d@192.168.15.40 CSeq: 104 BYE User-Agent: Asterisk PBX 1.6.0.15 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Content-Length: 0 <------------> [Sep 18 14:55:23] VERBOSE[28760] logger.c: -- Executing [h@_cos_internal+local+ld+intl:1] GotoIf("SIP/205-b694e820", "0?2:3") in new stack [Sep 18 14:55:23] VERBOSE[28760] logger.c: -- Goto (_cos_internal+local+ld+intl,h,3) [Sep 18 14:55:23] VERBOSE[28760] logger.c: -- Executing [h@_cos_internal+local+ld+intl:3] NoOp("SIP/205-b694e820", "Finish if-services-112") in new stack [Sep 18 14:55:23] VERBOSE[28760] logger.c: Scheduling destruction of SIP dialog '3dbc12da7ce4128501ef3bef21d44a82@192.168.15.137' in 6400 ms (Method: INVITE) [Sep 18 14:55:23] VERBOSE[28760] logger.c: set_destination: Parsing for address/port to send to [Sep 18 14:55:23] VERBOSE[28760] logger.c: set_destination: set destination to 192.168.15.138, port 5060 [Sep 18 14:55:23] VERBOSE[28760] logger.c: Reliably Transmitting (no NAT) to 192.168.15.138:5060: BYE sip:AudioCodesFXO1@192.168.15.138 SIP/2.0 Via: SIP/2.0/UDP 192.168.15.137:5060;branch=z9hG4bK29e5e74b;rport Max-Forwards: 70 From: "Operator One" ;tag=as1c75afae To: ;tag=1c187769642 Call-ID: 3dbc12da7ce4128501ef3bef21d44a82@192.168.15.137 CSeq: 103 BYE User-Agent: Asterisk PBX 1.6.0.15 X-Asterisk-HangupCause: Normal Clearing X-Asterisk-HangupCauseCode: 16 Content-Length: 0 --- [Sep 18 14:55:23] VERBOSE[28760] logger.c: == Spawn extension (_cos_internal+local+ld+intl, 3171111, 2) exited non-zero on 'SIP/205-b694e820' [Sep 18 14:55:23] VERBOSE[28699] logger.c: <--- SIP read from UDP://192.168.15.138:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.15.137:5060;branch=z9hG4bK29e5e74b;rport From: "Operator One" ;tag=as1c75afae To: ;tag=1c187769642 Call-ID: 3dbc12da7ce4128501ef3bef21d44a82@192.168.15.137 CSeq: 103 BYE Contact: Supported: em,timer,replaces,path,early-session,resource-priority Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE Server: Audiocodes-Sip-Gateway-MP-114 FXS_FXO/v.5.00A.024 Content-Length: 0 <-------------> [Sep 18 14:55:23] VERBOSE[28699] logger.c: --- (11 headers 0 lines) --- [Sep 18 14:55:23] VERBOSE[28699] logger.c: Really destroying SIP dialog '3dbc12da7ce4128501ef3bef21d44a82@192.168.15.137' Method: INVITE [Sep 18 14:55:23] VERBOSE[28699] logger.c: Really destroying SIP dialog '58c5533d62eec33054172d2b2a14782d@192.168.15.40' Method: BYE [Sep 18 14:55:24] VERBOSE[28681] logger.c: < [ 00 01 3c 36 08 02 06 99 45 08 02 81 90 ] [Sep 18 14:55:24] VERBOSE[28681] logger.c: < Informational frame: [Sep 18 14:55:24] VERBOSE[28681] logger.c: < SAPI: 00 C/R: 0 EA: 0 < TEI: 000 EA: 1 [Sep 18 14:55:24] VERBOSE[28681] logger.c: < N(S): 030 0: 0 < N(R): 027 P: 0 < 9 bytes of data [Sep 18 14:55:24] VERBOSE[28681] logger.c: Handling message for SAPI/TEI=0/0 [Sep 18 14:55:24] VERBOSE[28681] logger.c: -- ACKing all packets from 26 to (but not including) 27 [Sep 18 14:55:24] VERBOSE[28681] logger.c: -- Since there was nothing left, stopping T200 counter [Sep 18 14:55:24] VERBOSE[28681] logger.c: -- Stopping T203 counter since we got an ACK [Sep 18 14:55:24] VERBOSE[28681] logger.c: -- Nothing left, starting T203 counter [Sep 18 14:55:24] VERBOSE[28681] logger.c: < Protocol Discriminator: Q.931 (8) len=9 [Sep 18 14:55:24] VERBOSE[28681] logger.c: < Call Ref: len= 2 (reference 1689/0x699) (Originator) [Sep 18 14:55:24] VERBOSE[28681] logger.c: < Message type: DISCONNECT (69) [Sep 18 14:55:24] VERBOSE[28681] logger.c: < [08 02 81 90] [Sep 18 14:55:24] VERBOSE[28681] logger.c: < Cause (len= 4) [ Ext: 1 Coding: CCITT (ITU) standard (0) Spare: 0 Location: Private network serving the local user (1) [Sep 18 14:55:24] VERBOSE[28681] logger.c: < Ext: 1 Cause: Normal Clearing (16), class = Normal Event (1) ] [Sep 18 14:55:24] VERBOSE[28681] logger.c: -- Processing IE 8 (cs0, Cause) [Sep 18 14:55:24] VERBOSE[28681] logger.c: q931.c:3820 q931_receive: call 1689 on channel 23 enters state 12 (Disconnect Indication) [Sep 18 14:55:24] VERBOSE[28681] logger.c: Sending Receiver Ready (31) [Sep 18 14:55:24] VERBOSE[28681] logger.c: > [ 00 01 01 3e ] [Sep 18 14:55:24] VERBOSE[28681] logger.c: > Supervisory frame: [Sep 18 14:55:24] VERBOSE[28681] logger.c: > SAPI: 00 C/R: 0 EA: 0 > TEI: 000 EA: 1 [Sep 18 14:55:24] VERBOSE[28681] logger.c: > Zero: 0 S: 0 01: 1 [ RR (receive ready) ] > N(R): 031 P/F: 0 > 0 bytes of data [Sep 18 14:55:24] VERBOSE[28681] logger.c: -- Restarting T203 timer [Sep 18 14:55:24] VERBOSE[28681] logger.c: -- Channel 0/23, span 1 got hangup request, cause 16 [Sep 18 14:55:24] VERBOSE[28762] logger.c: -- Stopped music on hold on DAHDI/23-1 [Sep 18 14:55:24] VERBOSE[28762] logger.c: == Spawn extension (queue_join, s, 33) exited non-zero on 'DAHDI/23-1' [Sep 18 14:55:24] VERBOSE[28762] logger.c: -- Executing [h@queue_join:1] Gosub("DAHDI/23-1", "queue_leave,s,1") in new stack [Sep 18 14:55:24] VERBOSE[28762] logger.c: -- Executing [s@queue_leave:1] UserEvent("DAHDI/23-1", "QueueLeave,Channel:DAHDI/23-1,Queue:bronze,SrcNum:,SrcName:foo") in new stack [Sep 18 14:55:24] VERBOSE[28762] logger.c: -- Executing [s@queue_leave:2] Return("DAHDI/23-1", "") in new stack [Sep 18 14:55:24] VERBOSE[28762] logger.c: NEW_HANGUP DEBUG: Calling q931_hangup, ourstate Disconnect Indication, peerstate Disconnect Request [Sep 18 14:55:24] VERBOSE[28762] logger.c: q931.c:2961 q931_release: call 1689 on channel 23 enters state 19 (Release Request) [Sep 18 14:55:24] VERBOSE[28762] logger.c: > [ 02 01 36 3e 08 02 86 99 4d 08 02 81 90 ] [Sep 18 14:55:24] VERBOSE[28762] logger.c: > Informational frame: [Sep 18 14:55:24] VERBOSE[28762] logger.c: > SAPI: 00 C/R: 1 EA: 0 > TEI: 000 EA: 1 [Sep 18 14:55:24] VERBOSE[28762] logger.c: > N(S): 027 0: 0 > N(R): 031 P: 0 > 9 bytes of data [Sep 18 14:55:24] VERBOSE[28762] logger.c: Stopping T_203 timer [Sep 18 14:55:24] VERBOSE[28762] logger.c: Starting T_200 timer [Sep 18 14:55:24] VERBOSE[28762] logger.c: -- Restarting T200 timer [Sep 18 14:55:24] VERBOSE[28762] logger.c: > Protocol Discriminator: Q.931 (8) len=9 [Sep 18 14:55:24] VERBOSE[28762] logger.c: > Call Ref: len= 2 (reference 1689/0x699) (Terminator) [Sep 18 14:55:24] VERBOSE[28762] logger.c: > Message type: RELEASE (77) [Sep 18 14:55:24] VERBOSE[28762] logger.c: > [08 02 81 90] [Sep 18 14:55:24] VERBOSE[28762] logger.c: > Cause (len= 4) [ Ext: 1 Coding: CCITT (ITU) standard (0) Spare: 0 Location: Private network serving the local user (1) [Sep 18 14:55:24] VERBOSE[28762] logger.c: > Ext: 1 Cause: Normal Clearing (16), class = Normal Event (1) ] [Sep 18 14:55:24] VERBOSE[28762] logger.c: -- Hungup 'DAHDI/23-1' [Sep 18 14:55:24] VERBOSE[28764] logger.c: Scheduling destruction of SIP dialog '3a5b4bcd378ba6807414be983ac5395b@192.168.15.137' in 6400 ms (Method: INVITE) [Sep 18 14:55:24] VERBOSE[28764] logger.c: Reliably Transmitting (no NAT) to 192.168.15.138:5060: CANCEL sip:201@192.168.15.138 SIP/2.0 Via: SIP/2.0/UDP 192.168.15.137:5060;branch=z9hG4bK1cc37fd9;rport Max-Forwards: 70 From: "Belis Urologic" ;tag=as6968a1bb To: Call-ID: 3a5b4bcd378ba6807414be983ac5395b@192.168.15.137 CSeq: 102 CANCEL User-Agent: Asterisk PBX 1.6.0.15 Remote-Party-ID: "Belis Urologic" ;privacy=full;screen=no Content-Length: 0 --- [Sep 18 14:55:24] VERBOSE[28764] logger.c: Scheduling destruction of SIP dialog '3a5b4bcd378ba6807414be983ac5395b@192.168.15.137' in 6400 ms (Method: INVITE) [Sep 18 14:55:24] VERBOSE[28764] logger.c: == Spawn extension (queue_keeptrying_extension, U0lQLzIwMQ==, 3) exited non-zero on 'Local/U0lQLzIwMQ==@queue_keeptrying_extension-296e;2' [Sep 18 14:55:24] VERBOSE[28764] logger.c: -- Executing [h@queue_keeptrying_extension:1] NoOp("Local/U0lQLzIwMQ==@queue_keeptrying_extension-296e;2", "") in new stack [Sep 18 14:55:24] VERBOSE[28764] logger.c: -- Executing [h@queue_keeptrying_extension:2] GotoIf("Local/U0lQLzIwMQ==@queue_keeptrying_extension-296e;2", "1?3:11") in new stack [Sep 18 14:55:24] VERBOSE[28764] logger.c: -- Goto (queue_keeptrying_extension,h,3) [Sep 18 14:55:24] VERBOSE[28764] logger.c: -- Executing [h@queue_keeptrying_extension:3] Dial("Local/U0lQLzIwMQ==@queue_keeptrying_extension-296e;2", "SIP/201") in new stack [Sep 18 14:55:24] VERBOSE[28764] logger.c: == Using SIP RTP CoS mark 5 [Sep 18 14:55:24] WARNING[28764] chan_sip.c: Unsupported callingpres (-1) [Sep 18 14:55:24] VERBOSE[28764] logger.c: Audio is at 192.168.15.137 port 16088 [Sep 18 14:55:24] VERBOSE[28764] logger.c: Adding codec 0x4 (ulaw) to SDP [Sep 18 14:55:24] VERBOSE[28764] logger.c: Adding codec 0x2 (gsm) to SDP [Sep 18 14:55:24] VERBOSE[28764] logger.c: Adding codec 0x8 (alaw) to SDP [Sep 18 14:55:24] VERBOSE[28764] logger.c: Adding non-codec 0x1 (telephone-event) to SDP [Sep 18 14:55:24] VERBOSE[28764] logger.c: Reliably Transmitting (no NAT) to 192.168.15.138:5060: INVITE sip:201@192.168.15.138 SIP/2.0 Via: SIP/2.0/UDP 192.168.15.137:5060;branch=z9hG4bK5ef69eff;rport Max-Forwards: 70 From: "Belis Urologic" ;tag=as36f959b8 To: Contact: Call-ID: 5a56f4257878c82a31251f792622b159@192.168.15.137 CSeq: 102 INVITE User-Agent: Asterisk PBX 1.6.0.15 Remote-Party-ID: "Belis Urologic" ;privacy=full;screen=no Date: Fri, 18 Sep 2009 18:55:24 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Content-Type: application/sdp Content-Length: 315 v=0 o=root 1234184305 1234184305 IN IP4 192.168.15.137 s=Asterisk PBX 1.6.0.15 c=IN IP4 192.168.15.137 t=0 0 m=audio 16088 RTP/AVP 0 3 8 101 a=rtpmap:0 PCMU/8000 a=rtpmap:3 GSM/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv --- [Sep 18 14:55:24] VERBOSE[28764] logger.c: -- Called 201 [Sep 18 14:55:24] VERBOSE[28764] logger.c: Scheduling destruction of SIP dialog '5a56f4257878c82a31251f792622b159@192.168.15.137' in 6400 ms (Method: INVITE) [Sep 18 14:55:24] VERBOSE[28764] logger.c: == Spawn extension (queue_keeptrying_extension, h, 3) exited non-zero on 'Local/U0lQLzIwMQ==@queue_keeptrying_extension-296e;2' [Sep 18 14:55:24] VERBOSE[28681] logger.c: < [ 02 01 01 38 ] [Sep 18 14:55:24] VERBOSE[28681] logger.c: < Supervisory frame: [Sep 18 14:55:24] VERBOSE[28681] logger.c: < SAPI: 00 C/R: 1 EA: 0 < TEI: 000 EA: 1 [Sep 18 14:55:24] VERBOSE[28681] logger.c: < Zero: 0 S: 0 01: 1 [ RR (receive ready) ] < N(R): 028 P/F: 0 < 0 bytes of data [Sep 18 14:55:24] VERBOSE[28681] logger.c: Handling message for SAPI/TEI=0/0 [Sep 18 14:55:24] VERBOSE[28681] logger.c: -- ACKing all packets from 26 to (but not including) 28 [Sep 18 14:55:24] VERBOSE[28681] logger.c: -- ACKing packet 27, new txqueue is -1 (-1 means empty) [Sep 18 14:55:24] VERBOSE[28681] logger.c: -- Since there was nothing left, stopping T200 counter [Sep 18 14:55:24] VERBOSE[28681] logger.c: -- Nothing left, starting T203 counter [Sep 18 14:55:24] VERBOSE[28681] logger.c: -- Restarting T203 timer [Sep 18 14:55:24] VERBOSE[28699] logger.c: <--- SIP read from UDP://192.168.15.138:5060 ---> SIP/2.0 487 Request Terminated Via: SIP/2.0/UDP 192.168.15.137:5060;branch=z9hG4bK1cc37fd9;rport From: "Belis Urologic" ;tag=as6968a1bb To: ;tag=1c233400642 Call-ID: 3a5b4bcd378ba6807414be983ac5395b@192.168.15.137 CSeq: 102 INVITE Supported: em,timer,replaces,path,early-session,resource-priority Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE Server: Audiocodes-Sip-Gateway-MP-114 FXS_FXO/v.5.00A.024 Reason: SIP ;cause=487 ;text="487 Request Terminated" Content-Length: 0 <-------------> [Sep 18 14:55:24] VERBOSE[28699] logger.c: --- (11 headers 0 lines) --- [Sep 18 14:55:24] VERBOSE[28699] logger.c: Transmitting (no NAT) to 192.168.15.138:5060: ACK sip:201@192.168.15.138 SIP/2.0 Via: SIP/2.0/UDP 192.168.15.137:5060;branch=z9hG4bK1cc37fd9;rport Max-Forwards: 70 From: "Belis Urologic" ;tag=as6968a1bb To: ;tag=1c233400642 Contact: Call-ID: 3a5b4bcd378ba6807414be983ac5395b@192.168.15.137 CSeq: 102 ACK User-Agent: Asterisk PBX 1.6.0.15 Remote-Party-ID: "Belis Urologic" ;privacy=full;screen=no Content-Length: 0 --- [Sep 18 14:55:24] VERBOSE[28699] logger.c: <--- SIP read from UDP://192.168.15.138:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.15.137:5060;branch=z9hG4bK1cc37fd9;rport From: "Belis Urologic" ;tag=as6968a1bb To: ;tag=1c233400642 Call-ID: 3a5b4bcd378ba6807414be983ac5395b@192.168.15.137 CSeq: 102 CANCEL Contact: Supported: em,timer,replaces,path,early-session,resource-priority Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE Server: Audiocodes-Sip-Gateway-MP-114 FXS_FXO/v.5.00A.024 Content-Length: 0 <-------------> [Sep 18 14:55:24] VERBOSE[28699] logger.c: --- (11 headers 0 lines) --- [Sep 18 14:55:24] VERBOSE[28699] logger.c: Really destroying SIP dialog '3a5b4bcd378ba6807414be983ac5395b@192.168.15.137' Method: INVITE [Sep 18 14:55:24] VERBOSE[28681] logger.c: < [ 00 01 3e 38 08 02 06 99 5a ] [Sep 18 14:55:24] VERBOSE[28681] logger.c: < Informational frame: [Sep 18 14:55:24] VERBOSE[28681] logger.c: < SAPI: 00 C/R: 0 EA: 0 < TEI: 000 EA: 1 [Sep 18 14:55:24] VERBOSE[28681] logger.c: < N(S): 031 0: 0 < N(R): 028 P: 0 < 5 bytes of data [Sep 18 14:55:24] VERBOSE[28681] logger.c: Handling message for SAPI/TEI=0/0 [Sep 18 14:55:24] VERBOSE[28681] logger.c: -- ACKing all packets from 27 to (but not including) 28 [Sep 18 14:55:24] VERBOSE[28681] logger.c: -- Since there was nothing left, stopping T200 counter [Sep 18 14:55:24] VERBOSE[28681] logger.c: -- Stopping T203 counter since we got an ACK [Sep 18 14:55:24] VERBOSE[28681] logger.c: -- Nothing left, starting T203 counter [Sep 18 14:55:24] VERBOSE[28681] logger.c: < Protocol Discriminator: Q.931 (8) len=5 [Sep 18 14:55:24] VERBOSE[28681] logger.c: < Call Ref: len= 2 (reference 1689/0x699) (Originator) [Sep 18 14:55:24] VERBOSE[28681] logger.c: < Message type: RELEASE COMPLETE (90) [Sep 18 14:55:24] VERBOSE[28681] logger.c: q931.c:3760 q931_receive: call 1689 on channel 23 enters state 0 (Null) [Sep 18 14:55:24] VERBOSE[28681] logger.c: NEW_HANGUP DEBUG: Calling q931_hangup, ourstate Null, peerstate Null [Sep 18 14:55:24] VERBOSE[28681] logger.c: NEW_HANGUP DEBUG: Destroying the call, ourstate Null, peerstate Null [Sep 18 14:55:24] VERBOSE[28681] logger.c: Sending Receiver Ready (32) [Sep 18 14:55:24] VERBOSE[28681] logger.c: > [ 00 01 01 40 ] [Sep 18 14:55:24] VERBOSE[28681] logger.c: > Supervisory frame: [Sep 18 14:55:24] VERBOSE[28681] logger.c: > SAPI: 00 C/R: 0 EA: 0 > TEI: 000 EA: 1 [Sep 18 14:55:24] VERBOSE[28681] logger.c: > Zero: 0 S: 0 01: 1 [ RR (receive ready) ] > N(R): 032 P/F: 0 > 0 bytes of data [Sep 18 14:55:24] VERBOSE[28681] logger.c: -- Restarting T203 timer [Sep 18 14:55:24] VERBOSE[28699] logger.c: <--- SIP read from UDP://192.168.15.138:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.15.137:5060;branch=z9hG4bK5ef69eff;rport From: "Belis Urologic" ;tag=as36f959b8 To: ;tag=1c290298446 Call-ID: 5a56f4257878c82a31251f792622b159@192.168.15.137 CSeq: 102 INVITE Supported: em,timer,replaces,path,early-session,resource-priority Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE Server: Audiocodes-Sip-Gateway-MP-114 FXS_FXO/v.5.00A.024 Content-Length: 0 <-------------> [Sep 18 14:55:24] VERBOSE[28699] logger.c: --- (10 headers 0 lines) --- [Sep 18 14:55:24] VERBOSE[28699] logger.c: Reliably Transmitting (no NAT) to 192.168.15.138:5060: CANCEL sip:201@192.168.15.138 SIP/2.0 Via: SIP/2.0/UDP 192.168.15.137:5060;branch=z9hG4bK5ef69eff;rport Max-Forwards: 70 From: "Belis Urologic" ;tag=as36f959b8 To: Call-ID: 5a56f4257878c82a31251f792622b159@192.168.15.137 CSeq: 102 CANCEL User-Agent: Asterisk PBX 1.6.0.15 Remote-Party-ID: "Belis Urologic" ;privacy=full;screen=no Content-Length: 0 --- [Sep 18 14:55:24] VERBOSE[28699] logger.c: Scheduling destruction of SIP dialog '5a56f4257878c82a31251f792622b159@192.168.15.137' in 6400 ms (Method: INVITE) [Sep 18 14:55:24] VERBOSE[28699] logger.c: <--- SIP read from UDP://192.168.15.138:5060 ---> SIP/2.0 180 Ringing Via: SIP/2.0/UDP 192.168.15.137:5060;branch=z9hG4bK5ef69eff;rport From: "Belis Urologic" ;tag=as36f959b8 To: ;tag=1c290298446 Call-ID: 5a56f4257878c82a31251f792622b159@192.168.15.137 CSeq: 102 INVITE Contact: Supported: em,timer,replaces,path,early-session,resource-priority Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE Server: Audiocodes-Sip-Gateway-MP-114 FXS_FXO/v.5.00A.024 Content-Length: 0 <-------------> [Sep 18 14:55:24] VERBOSE[28699] logger.c: --- (11 headers 0 lines) --- [Sep 18 14:55:24] VERBOSE[28699] logger.c: <--- SIP read from UDP://192.168.15.138:5060 ---> SIP/2.0 487 Request Terminated Via: SIP/2.0/UDP 192.168.15.137:5060;branch=z9hG4bK5ef69eff;rport From: "Belis Urologic" ;tag=as36f959b8 To: ;tag=1c290298446 Call-ID: 5a56f4257878c82a31251f792622b159@192.168.15.137 CSeq: 102 INVITE Supported: em,timer,replaces,path,early-session,resource-priority Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE Server: Audiocodes-Sip-Gateway-MP-114 FXS_FXO/v.5.00A.024 Reason: SIP ;cause=487 ;text="487 Request Terminated" Content-Length: 0 <-------------> [Sep 18 14:55:24] VERBOSE[28699] logger.c: --- (11 headers 0 lines) --- [Sep 18 14:55:24] VERBOSE[28699] logger.c: Transmitting (no NAT) to 192.168.15.138:5060: ACK sip:201@192.168.15.138 SIP/2.0 Via: SIP/2.0/UDP 192.168.15.137:5060;branch=z9hG4bK5ef69eff;rport Max-Forwards: 70 From: "Belis Urologic" ;tag=as36f959b8 To: ;tag=1c290298446 Contact: Call-ID: 5a56f4257878c82a31251f792622b159@192.168.15.137 CSeq: 102 ACK User-Agent: Asterisk PBX 1.6.0.15 Remote-Party-ID: "Belis Urologic" ;privacy=full;screen=no Content-Length: 0 --- [Sep 18 14:55:24] VERBOSE[28699] logger.c: <--- SIP read from UDP://192.168.15.138:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.15.137:5060;branch=z9hG4bK5ef69eff;rport From: "Belis Urologic" ;tag=as36f959b8 To: ;tag=1c290298446 Call-ID: 5a56f4257878c82a31251f792622b159@192.168.15.137 CSeq: 102 CANCEL Contact: Supported: em,timer,replaces,path,early-session,resource-priority Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE Server: Audiocodes-Sip-Gateway-MP-114 FXS_FXO/v.5.00A.024 Content-Length: 0 <-------------> [Sep 18 14:55:24] VERBOSE[28699] logger.c: --- (11 headers 0 lines) --- [Sep 18 14:55:24] VERBOSE[28699] logger.c: Really destroying SIP dialog '5a56f4257878c82a31251f792622b159@192.168.15.137' Method: INVITE [Sep 18 14:55:26] VERBOSE[28699] logger.c: <--- SIP read from UDP://192.168.15.40:5062 ---> REGISTER sip:192.168.15.137;transport=UDP SIP/2.0 Via: SIP/2.0/UDP 207.255.24.91:5062;branch=z9hG4bK-d8754z-5b3daf2c3a3f48da-1---d8754z- Max-Forwards: 70 Contact: To: From: ;tag=cac57d5a Call-ID: ODk1NjU5Y2JlZjA5MzdjNjczMzdlOWY1MTJjNDk4ZDA. CSeq: 39 REGISTER Expires: 3600 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, NOTIFY, REFER, MESSAGE, OPTIONS, INFO User-Agent: Zoiper rev.2505 Allow-Events: presence Content-Length: 0 <-------------> [Sep 18 14:55:26] VERBOSE[28699] logger.c: --- (13 headers 0 lines) --- [Sep 18 14:55:26] VERBOSE[28699] logger.c: Sending to 207.255.24.91 : 5062 (no NAT) [Sep 18 14:55:26] VERBOSE[28699] logger.c: <--- Transmitting (no NAT) to 207.255.24.91:5062 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 207.255.24.91:5062;branch=z9hG4bK-d8754z-5b3daf2c3a3f48da-1---d8754z-;received=192.168.15.40 From: ;tag=cac57d5a To: ;tag=as2547ff85 Call-ID: ODk1NjU5Y2JlZjA5MzdjNjczMzdlOWY1MTJjNDk4ZDA. CSeq: 39 REGISTER User-Agent: Asterisk PBX 1.6.0.15 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="42eae8e8" Content-Length: 0 <------------> [Sep 18 14:55:26] VERBOSE[28699] logger.c: Scheduling destruction of SIP dialog 'ODk1NjU5Y2JlZjA5MzdjNjczMzdlOWY1MTJjNDk4ZDA.' in 32000 ms (Method: REGISTER) [Sep 18 14:55:27] VERBOSE[28699] logger.c: <--- SIP read from UDP://192.168.15.40:5060 ---> OPTIONS sip:192.168.15.137 SIP/2.0 Via: SIP/2.0/UDP 192.168.15.40:5060;branch=z9hG4bK09efd529;rport Max-Forwards: 70 From: "asterisk" ;tag=as1377643e To: Contact: Call-ID: 6ec52f1052856f8844871c1a244309f5@192.168.15.40 CSeq: 102 OPTIONS User-Agent: Asterisk PBX 1.6.0.6 Date: Fri, 18 Sep 2009 18:55:26 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces, timer Content-Length: 0 <-------------> [Sep 18 14:55:27] VERBOSE[28699] logger.c: --- (13 headers 0 lines) --- [Sep 18 14:55:27] VERBOSE[28699] logger.c: Looking for s in default (domain 192.168.15.137) [Sep 18 14:55:27] VERBOSE[28699] logger.c: <--- Transmitting (no NAT) to 192.168.15.40:5060 ---> SIP/2.0 404 Not Found Via: SIP/2.0/UDP 192.168.15.40:5060;branch=z9hG4bK09efd529;received=192.168.15.40;rport=5060 From: "asterisk" ;tag=as1377643e To: ;tag=as68370c25 Call-ID: 6ec52f1052856f8844871c1a244309f5@192.168.15.40 CSeq: 102 OPTIONS User-Agent: Asterisk PBX 1.6.0.15 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Accept: application/sdp Content-Length: 0 <------------> [Sep 18 14:55:27] VERBOSE[28699] logger.c: Scheduling destruction of SIP dialog '6ec52f1052856f8844871c1a244309f5@192.168.15.40' in 32000 ms (Method: OPTIONS) [Sep 18 14:55:30] VERBOSE[28699] logger.c: <--- SIP read from UDP://192.168.15.138:5060 ---> REGISTER sip:192.168.15.137 SIP/2.0 Via: SIP/2.0/UDP 192.168.15.138;branch=z9hG4bKac304074502 Max-Forwards: 70 From: ;tag=1c304071665 To: Call-ID: 667465271120000012@192.168.15.138 CSeq: 2079 REGISTER Contact: ;expires=180 Supported: em,timer,replaces,path,resource-priority Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE Expires: 180 User-Agent: Audiocodes-Sip-Gateway-MP-114 FXS_FXO/v.5.00A.024 Content-Length: 0 <-------------> [Sep 18 14:55:30] VERBOSE[28699] logger.c: --- (13 headers 0 lines) --- [Sep 18 14:55:30] VERBOSE[28699] logger.c: Sending to 192.168.15.138 : 5060 (no NAT) [Sep 18 14:55:30] VERBOSE[28699] logger.c: <--- Transmitting (no NAT) to 192.168.15.138:5060 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 192.168.15.138;branch=z9hG4bKac304074502;received=192.168.15.138 From: ;tag=1c304071665 To: ;tag=as27ccd190 Call-ID: 667465271120000012@192.168.15.138 CSeq: 2079 REGISTER User-Agent: Asterisk PBX 1.6.0.15 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="535be3ef" Content-Length: 0 <------------> [Sep 18 14:55:30] VERBOSE[28699] logger.c: Scheduling destruction of SIP dialog '667465271120000012@192.168.15.138' in 32000 ms (Method: REGISTER) [Sep 18 14:55:30] VERBOSE[28699] logger.c: <--- SIP read from UDP://192.168.15.138:5060 ---> REGISTER sip:192.168.15.137 SIP/2.0 Via: SIP/2.0/UDP 192.168.15.138;branch=z9hG4bKac304142131 Max-Forwards: 70 From: ;tag=1c304139330 To: Call-ID: 667470221120000012@192.168.15.138 CSeq: 2079 REGISTER Contact: ;expires=180 Supported: em,timer,replaces,path,resource-priority Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE Expires: 180 User-Agent: Audiocodes-Sip-Gateway-MP-114 FXS_FXO/v.5.00A.024 Content-Length: 0 <-------------> [Sep 18 14:55:30] VERBOSE[28699] logger.c: --- (13 headers 0 lines) --- [Sep 18 14:55:30] VERBOSE[28699] logger.c: Sending to 192.168.15.138 : 5060 (no NAT) [Sep 18 14:55:30] VERBOSE[28699] logger.c: <--- Transmitting (no NAT) to 192.168.15.138:5060 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 192.168.15.138;branch=z9hG4bKac304142131;received=192.168.15.138 From: ;tag=1c304139330 To: ;tag=as73eb000f Call-ID: 667470221120000012@192.168.15.138 CSeq: 2079 REGISTER User-Agent: Asterisk PBX 1.6.0.15 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="42269fd5" Content-Length: 0 <------------> [Sep 18 14:55:30] VERBOSE[28699] logger.c: Scheduling destruction of SIP dialog '667470221120000012@192.168.15.138' in 32000 ms (Method: REGISTER) [Sep 18 14:55:30] VERBOSE[28699] logger.c: Reliably Transmitting (no NAT) to 192.168.15.138:5060: OPTIONS sip:201@192.168.15.138 SIP/2.0 Via: SIP/2.0/UDP 192.168.15.137:5060;branch=z9hG4bK787c654f;rport Max-Forwards: 70 From: "asterisk" ;tag=as1e3f15cb To: Contact: Call-ID: 018165055a76273f20b3315219fde4f3@192.168.15.137 CSeq: 102 OPTIONS User-Agent: Asterisk PBX 1.6.0.15 Date: Fri, 18 Sep 2009 18:55:30 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Content-Length: 0 --- [Sep 18 14:55:30] VERBOSE[28699] logger.c: <--- SIP read from UDP://192.168.15.138:5060 ---> REGISTER sip:192.168.15.137 SIP/2.0 Via: SIP/2.0/UDP 192.168.15.138;branch=z9hG4bKac304156984 Max-Forwards: 70 From: ;tag=1c304071665 To: Call-ID: 667465271120000012@192.168.15.138 CSeq: 2080 REGISTER Authorization: Digest username="202",realm="asterisk",nonce="535be3ef",uri="sip:192.168.15.137",algorithm=MD5,response="a8b9a9629687dc410f9900a9e43acf98" Contact: ;expires=180 Supported: em,timer,replaces,path,resource-priority Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE Expires: 180 User-Agent: Audiocodes-Sip-Gateway-MP-114 FXS_FXO/v.5.00A.024 Content-Length: 0 <-------------> [Sep 18 14:55:30] VERBOSE[28699] logger.c: --- (14 headers 0 lines) --- [Sep 18 14:55:30] VERBOSE[28699] logger.c: Sending to 192.168.15.138 : 5060 (no NAT) [Sep 18 14:55:30] VERBOSE[28699] logger.c: Reliably Transmitting (no NAT) to 192.168.15.138:5060: OPTIONS sip:202@192.168.15.138 SIP/2.0 Via: SIP/2.0/UDP 192.168.15.137:5060;branch=z9hG4bK1dd70ad8;rport Max-Forwards: 70 From: "asterisk" ;tag=as2d52527d To: Contact: Call-ID: 38f32f204e4821102b7d62897c088a9b@192.168.15.137 CSeq: 102 OPTIONS User-Agent: Asterisk PBX 1.6.0.15 Date: Fri, 18 Sep 2009 18:55:30 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Content-Length: 0 --- [Sep 18 14:55:30] VERBOSE[28699] logger.c: <--- Transmitting (no NAT) to 192.168.15.138:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.15.138;branch=z9hG4bKac304156984;received=192.168.15.138 From: ;tag=1c304071665 To: ;tag=as27ccd190 Call-ID: 667465271120000012@192.168.15.138 CSeq: 2080 REGISTER User-Agent: Asterisk PBX 1.6.0.15 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Expires: 180 Contact: ;expires=180 Date: Fri, 18 Sep 2009 18:55:30 GMT Content-Length: 0 <------------> [Sep 18 14:55:30] VERBOSE[28699] logger.c: Scheduling destruction of SIP dialog '667465271120000012@192.168.15.138' in 32000 ms (Method: REGISTER) [Sep 18 14:55:30] VERBOSE[28699] logger.c: <--- SIP read from UDP://192.168.15.138:5060 ---> REGISTER sip:192.168.15.137 SIP/2.0 Via: SIP/2.0/UDP 192.168.15.138;branch=z9hG4bKac304174738 Max-Forwards: 70 From: ;tag=1c304139330 To: Call-ID: 667470221120000012@192.168.15.138 CSeq: 2080 REGISTER Authorization: Digest username="201",realm="asterisk",nonce="42269fd5",uri="sip:192.168.15.137",algorithm=MD5,response="94605dd66793e10eb504d10ca1f26350" Contact: ;expires=180 Supported: em,timer,replaces,path,resource-priority Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE Expires: 180 User-Agent: Audiocodes-Sip-Gateway-MP-114 FXS_FXO/v.5.00A.024 Content-Length: 0 <-------------> [Sep 18 14:55:30] VERBOSE[28699] logger.c: --- (14 headers 0 lines) --- [Sep 18 14:55:30] VERBOSE[28699] logger.c: Sending to 192.168.15.138 : 5060 (no NAT) [Sep 18 14:55:30] NOTICE[28699] chan_sip.c: Still have a QUALIFY dialog active, deleting [Sep 18 14:55:30] VERBOSE[28699] logger.c: Really destroying SIP dialog '018165055a76273f20b3315219fde4f3@192.168.15.137' Method: OPTIONS [Sep 18 14:55:30] VERBOSE[28699] logger.c: Reliably Transmitting (no NAT) to 192.168.15.138:5060: OPTIONS sip:201@192.168.15.138 SIP/2.0 Via: SIP/2.0/UDP 192.168.15.137:5060;branch=z9hG4bK5c7edbb4;rport Max-Forwards: 70 From: "asterisk" ;tag=as53c7e8ae To: Contact: Call-ID: 62269548591b71f3705ebd6c7ae03016@192.168.15.137 CSeq: 102 OPTIONS User-Agent: Asterisk PBX 1.6.0.15 Date: Fri, 18 Sep 2009 18:55:30 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Content-Length: 0 --- [Sep 18 14:55:30] VERBOSE[28699] logger.c: <--- Transmitting (no NAT) to 192.168.15.138:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.15.138;branch=z9hG4bKac304174738;received=192.168.15.138 From: ;tag=1c304139330 To: ;tag=as73eb000f Call-ID: 667470221120000012@192.168.15.138 CSeq: 2080 REGISTER User-Agent: Asterisk PBX 1.6.0.15 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Expires: 180 Contact: ;expires=180 Date: Fri, 18 Sep 2009 18:55:30 GMT Content-Length: 0 <------------> [Sep 18 14:55:30] VERBOSE[28699] logger.c: Scheduling destruction of SIP dialog '667470221120000012@192.168.15.138' in 32000 ms (Method: REGISTER) [Sep 18 14:55:30] VERBOSE[28699] logger.c: <--- SIP read from UDP://192.168.15.138:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.15.137:5060;branch=z9hG4bK787c654f;rport From: "asterisk" ;tag=as1e3f15cb To: ;tag=1c304193584 Call-ID: 018165055a76273f20b3315219fde4f3@192.168.15.137 CSeq: 102 OPTIONS Supported: em,100rel,timer,replaces,path,resource-priority Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE X-Resources: telchs=3/0;mediachs=0/0 Content-Type: application/sdp Content-Length: 267 v=0 o=AudiocodesGW 304196690 304196567 IN IP4 192.168.15.138 s=Phone-Call c=IN IP4 192.168.15.138 t=0 0 m=audio 6000 RTP/AVP 0 96 a=rtpmap:0 PCMU/8000 a=rtpmap:96 telephone-event/8000 a=fmtp:96 0-15 a=ptime:20 a=sendrecv a=rtcp:6001 IN IP4 192.168.15.138 <-------------> [Sep 18 14:55:30] VERBOSE[28699] logger.c: --- (11 headers 12 lines) --- [Sep 18 14:55:30] VERBOSE[28699] logger.c: <--- SIP read from UDP://192.168.15.138:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.15.137:5060;branch=z9hG4bK1dd70ad8;rport From: "asterisk" ;tag=as2d52527d To: ;tag=1c304218577 Call-ID: 38f32f204e4821102b7d62897c088a9b@192.168.15.137 CSeq: 102 OPTIONS Supported: em,100rel,timer,replaces,path,resource-priority Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE X-Resources: telchs=3/0;mediachs=0/0 Content-Type: application/sdp Content-Length: 267 v=0 o=AudiocodesGW 304221655 304221533 IN IP4 192.168.15.138 s=Phone-Call c=IN IP4 192.168.15.138 t=0 0 m=audio 6000 RTP/AVP 0 96 a=rtpmap:0 PCMU/8000 a=rtpmap:96 telephone-event/8000 a=fmtp:96 0-15 a=ptime:20 a=sendrecv a=rtcp:6001 IN IP4 192.168.15.138 <-------------> [Sep 18 14:55:30] VERBOSE[28699] logger.c: --- (11 headers 12 lines) --- [Sep 18 14:55:30] VERBOSE[28699] logger.c: Really destroying SIP dialog '38f32f204e4821102b7d62897c088a9b@192.168.15.137' Method: OPTIONS [Sep 18 14:55:30] VERBOSE[28699] logger.c: <--- SIP read from UDP://192.168.15.138:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.15.137:5060;branch=z9hG4bK5c7edbb4;rport From: "asterisk" ;tag=as53c7e8ae To: ;tag=1c304252080 Call-ID: 62269548591b71f3705ebd6c7ae03016@192.168.15.137 CSeq: 102 OPTIONS Supported: em,100rel,timer,replaces,path,resource-priority Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE X-Resources: telchs=3/0;mediachs=0/0 Content-Type: application/sdp Content-Length: 267 v=0 o=AudiocodesGW 304255107 304254984 IN IP4 192.168.15.138 s=Phone-Call c=IN IP4 192.168.15.138 t=0 0 m=audio 6000 RTP/AVP 0 96 a=rtpmap:0 PCMU/8000 a=rtpmap:96 telephone-event/8000 a=fmtp:96 0-15 a=ptime:20 a=sendrecv a=rtcp:6001 IN IP4 192.168.15.138 <-------------> [Sep 18 14:55:30] VERBOSE[28699] logger.c: --- (11 headers 12 lines) --- [Sep 18 14:55:30] VERBOSE[28699] logger.c: Really destroying SIP dialog '62269548591b71f3705ebd6c7ae03016@192.168.15.137' Method: OPTIONS [Sep 18 14:55:30] VERBOSE[28699] logger.c: <--- SIP read from UDP://192.168.15.40:5062 ---> REGISTER sip:192.168.15.137;transport=UDP SIP/2.0 Via: SIP/2.0/UDP 207.255.24.91:5062;branch=z9hG4bK-d8754z-5b3daf2c3a3f48da-1---d8754z- Max-Forwards: 70 Contact: To: From: ;tag=cac57d5a Call-ID: ODk1NjU5Y2JlZjA5MzdjNjczMzdlOWY1MTJjNDk4ZDA. CSeq: 39 REGISTER Expires: 3600 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, NOTIFY, REFER, MESSAGE, OPTIONS, INFO User-Agent: Zoiper rev.2505 Allow-Events: presence Content-Length: 0 <-------------> [Sep 18 14:55:30] VERBOSE[28699] logger.c: --- (13 headers 0 lines) --- [Sep 18 14:55:30] VERBOSE[28699] logger.c: Sending to 207.255.24.91 : 5062 (no NAT) [Sep 18 14:55:30] VERBOSE[28699] logger.c: <--- Transmitting (no NAT) to 207.255.24.91:5062 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 207.255.24.91:5062;branch=z9hG4bK-d8754z-5b3daf2c3a3f48da-1---d8754z-;received=192.168.15.40 From: ;tag=cac57d5a To: ;tag=as2547ff85 Call-ID: ODk1NjU5Y2JlZjA5MzdjNjczMzdlOWY1MTJjNDk4ZDA. CSeq: 39 REGISTER User-Agent: Asterisk PBX 1.6.0.15 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="42eae8e8" Content-Length: 0 <------------> [Sep 18 14:55:30] VERBOSE[28699] logger.c: Scheduling destruction of SIP dialog 'ODk1NjU5Y2JlZjA5MzdjNjczMzdlOWY1MTJjNDk4ZDA.' in 32000 ms (Method: REGISTER) [Sep 18 14:55:30] VERBOSE[28699] logger.c: <--- SIP read from UDP://192.168.15.138:5060 ---> REGISTER sip:192.168.15.137 SIP/2.0 Via: SIP/2.0/UDP 192.168.15.138;branch=z9hG4bKac304574641 Max-Forwards: 70 From: ;tag=1c304571737 To: Call-ID: 667460341120000012@192.168.15.138 CSeq: 2078 REGISTER Contact: ;expires=180 Supported: em,timer,replaces,path,resource-priority Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE Expires: 180 User-Agent: Audiocodes-Sip-Gateway-MP-114 FXS_FXO/v.5.00A.024 Content-Length: 0 <-------------> [Sep 18 14:55:30] VERBOSE[28699] logger.c: --- (13 headers 0 lines) --- [Sep 18 14:55:30] VERBOSE[28699] logger.c: Sending to 192.168.15.138 : 5060 (no NAT) [Sep 18 14:55:30] VERBOSE[28699] logger.c: <--- Transmitting (no NAT) to 192.168.15.138:5060 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 192.168.15.138;branch=z9hG4bKac304574641;received=192.168.15.138 From: ;tag=1c304571737 To: ;tag=as6441f2ee Call-ID: 667460341120000012@192.168.15.138 CSeq: 2078 REGISTER User-Agent: Asterisk PBX 1.6.0.15 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="70672a6e" Content-Length: 0 <------------> [Sep 18 14:55:30] VERBOSE[28699] logger.c: Scheduling destruction of SIP dialog '667460341120000012@192.168.15.138' in 32000 ms (Method: REGISTER) [Sep 18 14:55:30] VERBOSE[28699] logger.c: <--- SIP read from UDP://192.168.15.138:5060 ---> REGISTER sip:192.168.15.137 SIP/2.0 Via: SIP/2.0/UDP 192.168.15.138;branch=z9hG4bKac304648492 Max-Forwards: 70 From: ;tag=1c304571737 To: Call-ID: 667460341120000012@192.168.15.138 CSeq: 2079 REGISTER Authorization: Digest username="AudioCodesFXO1",realm="asterisk",nonce="70672a6e",uri="sip:192.168.15.137",algorithm=MD5,response="514ced5be2d4cd9e1210a03dc43b3785" Contact: ;expires=180 Supported: em,timer,replaces,path,resource-priority Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE Expires: 180 User-Agent: Audiocodes-Sip-Gateway-MP-114 FXS_FXO/v.5.00A.024 Content-Length: 0 <-------------> [Sep 18 14:55:30] VERBOSE[28699] logger.c: --- (14 headers 0 lines) --- [Sep 18 14:55:30] VERBOSE[28699] logger.c: Sending to 192.168.15.138 : 5060 (no NAT) [Sep 18 14:55:30] VERBOSE[28699] logger.c: Reliably Transmitting (no NAT) to 192.168.15.138:5060: OPTIONS sip:AudioCodesFXO1@192.168.15.138 SIP/2.0 Via: SIP/2.0/UDP 192.168.15.137:5060;branch=z9hG4bK2a278464;rport Max-Forwards: 70 From: "asterisk" ;tag=as504ead61 To: Contact: Call-ID: 0d317433548c20850ce981fa20721052@192.168.15.137 CSeq: 102 OPTIONS User-Agent: Asterisk PBX 1.6.0.15 Date: Fri, 18 Sep 2009 18:55:30 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Content-Length: 0 --- [Sep 18 14:55:30] VERBOSE[28699] logger.c: <--- Transmitting (no NAT) to 192.168.15.138:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.15.138;branch=z9hG4bKac304648492;received=192.168.15.138 From: ;tag=1c304571737 To: ;tag=as6441f2ee Call-ID: 667460341120000012@192.168.15.138 CSeq: 2079 REGISTER User-Agent: Asterisk PBX 1.6.0.15 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Expires: 180 Contact: ;expires=180 Date: Fri, 18 Sep 2009 18:55:30 GMT Content-Length: 0 <------------> [Sep 18 14:55:30] VERBOSE[28699] logger.c: Scheduling destruction of SIP dialog '667460341120000012@192.168.15.138' in 32000 ms (Method: REGISTER) [Sep 18 14:55:30] VERBOSE[28699] logger.c: <--- SIP read from UDP://192.168.15.138:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.15.137:5060;branch=z9hG4bK2a278464;rport From: "asterisk" ;tag=as504ead61 To: ;tag=1c304707946 Call-ID: 0d317433548c20850ce981fa20721052@192.168.15.137 CSeq: 102 OPTIONS Supported: em,100rel,timer,replaces,path,resource-priority Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE X-Resources: telchs=3/0;mediachs=0/0 Content-Type: application/sdp Content-Length: 267 v=0 o=AudiocodesGW 304711415 304711285 IN IP4 192.168.15.138 s=Phone-Call c=IN IP4 192.168.15.138 t=0 0 m=audio 6000 RTP/AVP 0 96 a=rtpmap:0 PCMU/8000 a=rtpmap:96 telephone-event/8000 a=fmtp:96 0-15 a=ptime:20 a=sendrecv a=rtcp:6001 IN IP4 192.168.15.138 <-------------> [Sep 18 14:55:30] VERBOSE[28699] logger.c: --- (11 headers 12 lines) --- [Sep 18 14:55:30] VERBOSE[28699] logger.c: Really destroying SIP dialog '0d317433548c20850ce981fa20721052@192.168.15.137' Method: OPTIONS [Sep 18 14:55:30] VERBOSE[28699] logger.c: Reliably Transmitting (no NAT) to 192.168.15.40:5060: OPTIONS sip:s@192.168.15.40 SIP/2.0 Via: SIP/2.0/UDP 192.168.15.137:5060;branch=z9hG4bK50c67577;rport Max-Forwards: 70 From: "asterisk" ;tag=as5f791625 To: Contact: Call-ID: 0bda205820a792a111f162977a2df519@192.168.15.137 CSeq: 102 OPTIONS User-Agent: Asterisk PBX 1.6.0.15 Date: Fri, 18 Sep 2009 18:55:30 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Content-Length: 0 --- [Sep 18 14:55:30] VERBOSE[28699] logger.c: <--- SIP read from UDP://192.168.15.40:5060 ---> SIP/2.0 404 Not Found Via: SIP/2.0/UDP 192.168.15.137:5060;branch=z9hG4bK50c67577;received=192.168.15.137;rport=5060 From: "asterisk" ;tag=as5f791625 To: ;tag=as395b316f Call-ID: 0bda205820a792a111f162977a2df519@192.168.15.137 CSeq: 102 OPTIONS User-Agent: Asterisk PBX 1.6.0.6 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces, timer Accept: application/sdp Content-Length: 0 <-------------> [Sep 18 14:55:30] VERBOSE[28699] logger.c: --- (11 headers 0 lines) --- [Sep 18 14:55:30] VERBOSE[28699] logger.c: Really destroying SIP dialog '0bda205820a792a111f162977a2df519@192.168.15.137' Method: OPTIONS [Sep 18 14:55:32] VERBOSE[28699] logger.c: Really destroying SIP dialog '667454741120000012@192.168.15.138' Method: REGISTER [Sep 18 14:55:34] VERBOSE[28699] logger.c: <--- SIP read from UDP://192.168.15.40:5062 ---> REGISTER sip:192.168.15.137;transport=UDP SIP/2.0 Via: SIP/2.0/UDP 207.255.24.91:5062;branch=z9hG4bK-d8754z-5b3daf2c3a3f48da-1---d8754z- Max-Forwards: 70 Contact: To: From: ;tag=cac57d5a Call-ID: ODk1NjU5Y2JlZjA5MzdjNjczMzdlOWY1MTJjNDk4ZDA. CSeq: 39 REGISTER Expires: 3600 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, NOTIFY, REFER, MESSAGE, OPTIONS, INFO User-Agent: Zoiper rev.2505 Allow-Events: presence Content-Length: 0 <-------------> [Sep 18 14:55:34] VERBOSE[28699] logger.c: --- (13 headers 0 lines) --- [Sep 18 14:55:34] VERBOSE[28699] logger.c: Sending to 207.255.24.91 : 5062 (no NAT) [Sep 18 14:55:34] VERBOSE[28699] logger.c: <--- Transmitting (no NAT) to 207.255.24.91:5062 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 207.255.24.91:5062;branch=z9hG4bK-d8754z-5b3daf2c3a3f48da-1---d8754z-;received=192.168.15.40 From: ;tag=cac57d5a To: ;tag=as2547ff85 Call-ID: ODk1NjU5Y2JlZjA5MzdjNjczMzdlOWY1MTJjNDk4ZDA. CSeq: 39 REGISTER User-Agent: Asterisk PBX 1.6.0.15 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="42eae8e8" Content-Length: 0 <------------> [Sep 18 14:55:34] VERBOSE[28699] logger.c: Scheduling destruction of SIP dialog 'ODk1NjU5Y2JlZjA5MzdjNjczMzdlOWY1MTJjNDk4ZDA.' in 32000 ms (Method: REGISTER) [Sep 18 14:55:34] VERBOSE[28681] logger.c: T203 counter expired, sending RR and scheduling T203 again [Sep 18 14:55:34] VERBOSE[28681] logger.c: Sending Receiver Ready (32) [Sep 18 14:55:34] VERBOSE[28681] logger.c: > [ 02 01 01 41 ] [Sep 18 14:55:34] VERBOSE[28681] logger.c: > Supervisory frame: [Sep 18 14:55:34] VERBOSE[28681] logger.c: > SAPI: 00 C/R: 1 EA: 0 > TEI: 000 EA: 1 [Sep 18 14:55:34] VERBOSE[28681] logger.c: > Zero: 0 S: 0 01: 1 [ RR (receive ready) ] > N(R): 032 P/F: 1 > 0 bytes of data [Sep 18 14:55:34] VERBOSE[28681] logger.c: < [ 02 01 01 39 ] [Sep 18 14:55:34] VERBOSE[28681] logger.c: < Supervisory frame: [Sep 18 14:55:34] VERBOSE[28681] logger.c: < SAPI: 00 C/R: 1 EA: 0 < TEI: 000 EA: 1 [Sep 18 14:55:34] VERBOSE[28681] logger.c: < Zero: 0 S: 0 01: 1 [ RR (receive ready) ] < N(R): 028 P/F: 1 < 0 bytes of data [Sep 18 14:55:34] VERBOSE[28681] logger.c: Handling message for SAPI/TEI=0/0 [Sep 18 14:55:34] VERBOSE[28681] logger.c: -- ACKing all packets from 27 to (but not including) 28 [Sep 18 14:55:34] VERBOSE[28681] logger.c: -- Since there was nothing left, stopping T200 counter [Sep 18 14:55:34] VERBOSE[28681] logger.c: -- Stopping T203 counter since we got an ACK [Sep 18 14:55:34] VERBOSE[28681] logger.c: -- Nothing left, starting T203 counter [Sep 18 14:55:34] VERBOSE[28681] logger.c: -- Got RR response to our frame [Sep 18 14:55:34] VERBOSE[28681] logger.c: -- Restarting T203 timer [Sep 18 14:55:38] VERBOSE[28699] logger.c: <--- SIP read from UDP://192.168.15.40:5062 ---> REGISTER sip:192.168.15.137;transport=UDP SIP/2.0 Via: SIP/2.0/UDP 207.255.24.91:5062;branch=z9hG4bK-d8754z-5b3daf2c3a3f48da-1---d8754z- Max-Forwards: 70 Contact: To: From: ;tag=cac57d5a Call-ID: ODk1NjU5Y2JlZjA5MzdjNjczMzdlOWY1MTJjNDk4ZDA. CSeq: 39 REGISTER Expires: 3600 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, NOTIFY, REFER, MESSAGE, OPTIONS, INFO User-Agent: Zoiper rev.2505 Allow-Events: presence Content-Length: 0 <-------------> [Sep 18 14:55:38] VERBOSE[28699] logger.c: --- (13 headers 0 lines) --- [Sep 18 14:55:38] VERBOSE[28699] logger.c: Sending to 207.255.24.91 : 5062 (no NAT) [Sep 18 14:55:38] VERBOSE[28699] logger.c: <--- Transmitting (no NAT) to 207.255.24.91:5062 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 207.255.24.91:5062;branch=z9hG4bK-d8754z-5b3daf2c3a3f48da-1---d8754z-;received=192.168.15.40 From: ;tag=cac57d5a To: ;tag=as2547ff85 Call-ID: ODk1NjU5Y2JlZjA5MzdjNjczMzdlOWY1MTJjNDk4ZDA. CSeq: 39 REGISTER User-Agent: Asterisk PBX 1.6.0.15 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="42eae8e8" Content-Length: 0 <------------> [Sep 18 14:55:38] VERBOSE[28699] logger.c: Scheduling destruction of SIP dialog 'ODk1NjU5Y2JlZjA5MzdjNjczMzdlOWY1MTJjNDk4ZDA.' in 32000 ms (Method: REGISTER) [Sep 18 14:55:42] VERBOSE[28699] logger.c: <--- SIP read from UDP://192.168.15.40:5062 ---> REGISTER sip:192.168.15.137;transport=UDP SIP/2.0 Via: SIP/2.0/UDP 207.255.24.91:5062;branch=z9hG4bK-d8754z-5b3daf2c3a3f48da-1---d8754z- Max-Forwards: 70 Contact: To: From: ;tag=cac57d5a Call-ID: ODk1NjU5Y2JlZjA5MzdjNjczMzdlOWY1MTJjNDk4ZDA. CSeq: 39 REGISTER Expires: 3600 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, NOTIFY, REFER, MESSAGE, OPTIONS, INFO User-Agent: Zoiper rev.2505 Allow-Events: presence Content-Length: 0 <-------------> [Sep 18 14:55:42] VERBOSE[28699] logger.c: --- (13 headers 0 lines) --- [Sep 18 14:55:42] VERBOSE[28699] logger.c: Sending to 207.255.24.91 : 5062 (no NAT) [Sep 18 14:55:42] VERBOSE[28699] logger.c: <--- Transmitting (no NAT) to 207.255.24.91:5062 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 207.255.24.91:5062;branch=z9hG4bK-d8754z-5b3daf2c3a3f48da-1---d8754z-;received=192.168.15.40 From: ;tag=cac57d5a To: ;tag=as2547ff85 Call-ID: ODk1NjU5Y2JlZjA5MzdjNjczMzdlOWY1MTJjNDk4ZDA. CSeq: 39 REGISTER User-Agent: Asterisk PBX 1.6.0.15 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="42eae8e8" Content-Length: 0 <------------> [Sep 18 14:55:42] VERBOSE[28699] logger.c: Scheduling destruction of SIP dialog 'ODk1NjU5Y2JlZjA5MzdjNjczMzdlOWY1MTJjNDk4ZDA.' in 32000 ms (Method: REGISTER) [Sep 18 14:55:44] VERBOSE[28681] logger.c: T203 counter expired, sending RR and scheduling T203 again [Sep 18 14:55:44] VERBOSE[28681] logger.c: Sending Receiver Ready (32) [Sep 18 14:55:44] VERBOSE[28681] logger.c: > [ 02 01 01 41 ] [Sep 18 14:55:44] VERBOSE[28681] logger.c: > Supervisory frame: [Sep 18 14:55:44] VERBOSE[28681] logger.c: > SAPI: 00 C/R: 1 EA: 0 > TEI: 000 EA: 1 [Sep 18 14:55:44] VERBOSE[28681] logger.c: > Zero: 0 S: 0 01: 1 [ RR (receive ready) ] > N(R): 032 P/F: 1 > 0 bytes of data [Sep 18 14:55:44] VERBOSE[28681] logger.c: < [ 02 01 01 39 ] [Sep 18 14:55:44] VERBOSE[28681] logger.c: < Supervisory frame: [Sep 18 14:55:44] VERBOSE[28681] logger.c: < SAPI: 00 C/R: 1 EA: 0 < TEI: 000 EA: 1 [Sep 18 14:55:44] VERBOSE[28681] logger.c: < Zero: 0 S: 0 01: 1 [ RR (receive ready) ] < N(R): 028 P/F: 1 < 0 bytes of data [Sep 18 14:55:44] VERBOSE[28681] logger.c: Handling message for SAPI/TEI=0/0 [Sep 18 14:55:44] VERBOSE[28681] logger.c: -- ACKing all packets from 27 to (but not including) 28 [Sep 18 14:55:44] VERBOSE[28681] logger.c: -- Since there was nothing left, stopping T200 counter [Sep 18 14:55:44] VERBOSE[28681] logger.c: -- Stopping T203 counter since we got an ACK [Sep 18 14:55:44] VERBOSE[28681] logger.c: -- Nothing left, starting T203 counter [Sep 18 14:55:44] VERBOSE[28681] logger.c: -- Got RR response to our frame [Sep 18 14:55:44] VERBOSE[28681] logger.c: -- Restarting T203 timer [Sep 18 14:55:49] VERBOSE[28699] logger.c: <--- SIP read from UDP://192.168.15.138:5060 ---> OPTIONS sip:AudioCodesFXO2@192.168.15.138 SIP/2.0 Via: SIP/2.0/UDP 192.168.15.138;branch=z9hG4bKac350951749 Max-Forwards: 70 From: ;tag=1c350947872 To: Call-ID: 35094753521200014815@192.168.15.138 CSeq: 1 OPTIONS Contact: Supported: em,timer,replaces,path,resource-priority Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE User-Agent: Audiocodes-Sip-Gateway-MP-114 FXS_FXO/v.5.00A.024 Content-Length: 0 <-------------> [Sep 18 14:55:49] VERBOSE[28699] logger.c: --- (12 headers 0 lines) --- [Sep 18 14:55:49] VERBOSE[28699] logger.c: Looking for AudioCodesFXO2 in default (domain 192.168.15.138) [Sep 18 14:55:49] VERBOSE[28699] logger.c: <--- Transmitting (no NAT) to 192.168.15.138:5060 ---> SIP/2.0 404 Not Found Via: SIP/2.0/UDP 192.168.15.138;branch=z9hG4bKac350951749;received=192.168.15.138 From: ;tag=1c350947872 To: ;tag=as74c4a6f9 Call-ID: 35094753521200014815@192.168.15.138 CSeq: 1 OPTIONS User-Agent: Asterisk PBX 1.6.0.15 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Accept: application/sdp Content-Length: 0 <------------> [Sep 18 14:55:49] VERBOSE[28699] logger.c: Scheduling destruction of SIP dialog '35094753521200014815@192.168.15.138' in 32000 ms (Method: OPTIONS)