[May 18 02:48:29] VERBOSE[13711] config.c: == Parsing '/etc/asterisk/logger.conf': [May 18 02:48:29] DEBUG[13711] config.c: Parsing /etc/asterisk/logger.conf [May 18 02:48:29] VERBOSE[13711] config.c: == Found [May 18 02:48:29] VERBOSE[13711] logger.c: Asterisk Queue Logger restarted [May 18 02:48:49] VERBOSE[13691] chan_sip.c: <--- SIP read from UDP:58.69.37.108:60672 ---> <-------------> [May 18 02:48:49] DEBUG[13691] chan_sip.c: Header 0 [ 0]: [May 18 02:48:52] VERBOSE[13691] chan_sip.c: <--- SIP read from UDP:58.69.37.108:60672 ---> INVITE sip:200@222.126.44.162 SIP/2.0 To: From: Agent Orange;tag=d167d863 Via: SIP/2.0/UDP 58.69.37.108:60672;branch=z9hG4bK-d87543-650131918-1--d87543-;rport Call-ID: 97338c5bd438343b CSeq: 1 INVITE Contact: Max-Forwards: 70 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO Content-Type: application/sdp User-Agent: eyeBeam release 3004w stamp 16863 Content-Length: 321 v=0 o=- 21996018 21996356 IN IP4 58.69.37.108 s=eyeBeam c=IN IP4 58.69.37.108 t=0 0 m=audio 60675 RTP/AVP 18 3 0 101 a=alt:1 1 : 6B8F8831 E985975B 58.69.37.108 60675 58.69.37.108 60928 a=alt:2 3 : FEA44E01 2542BF92 192.168.2.254 10592 a=fmtp:101 0-15 a=rtcp:60928 a=rtpmap:101 telephone-event/8000 a=sendrecv <-------------> [May 18 02:48:52] DEBUG[13691] chan_sip.c: Header 0 [ 37]: INVITE sip:200@222.126.44.162 SIP/2.0 [May 18 02:48:52] DEBUG[13691] chan_sip.c: Header 1 [ 28]: To: [May 18 02:48:52] DEBUG[13691] chan_sip.c: Header 2 [ 55]: From: Agent Orange;tag=d167d863 [May 18 02:48:52] DEBUG[13691] chan_sip.c: Header 3 [ 84]: Via: SIP/2.0/UDP 58.69.37.108:60672;branch=z9hG4bK-d87543-650131918-1--d87543-;rport [May 18 02:48:52] DEBUG[13691] chan_sip.c: Header 4 [ 25]: Call-ID: 97338c5bd438343b [May 18 02:48:52] DEBUG[13691] chan_sip.c: Header 5 [ 14]: CSeq: 1 INVITE [May 18 02:48:52] DEBUG[13691] chan_sip.c: Header 6 [ 37]: Contact: [May 18 02:48:52] DEBUG[13691] chan_sip.c: Header 7 [ 16]: Max-Forwards: 70 [May 18 02:48:52] DEBUG[13691] chan_sip.c: Header 8 [ 81]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO [May 18 02:48:52] DEBUG[13691] chan_sip.c: Header 9 [ 29]: Content-Type: application/sdp [May 18 02:48:52] DEBUG[13691] chan_sip.c: Header 10 [ 45]: User-Agent: eyeBeam release 3004w stamp 16863 [May 18 02:48:52] DEBUG[13691] chan_sip.c: Header 11 [ 19]: Content-Length: 321 [May 18 02:48:52] DEBUG[13691] chan_sip.c: Header 12 [ 0]: [May 18 02:48:52] DEBUG[13691] chan_sip.c: Body 0 [ 3]: v=0 [May 18 02:48:52] DEBUG[13691] chan_sip.c: Body 1 [ 41]: o=- 21996018 21996356 IN IP4 58.69.37.108 [May 18 02:48:52] DEBUG[13691] chan_sip.c: Body 2 [ 9]: s=eyeBeam [May 18 02:48:52] DEBUG[13691] chan_sip.c: Body 3 [ 21]: c=IN IP4 58.69.37.108 [May 18 02:48:52] DEBUG[13691] chan_sip.c: Body 4 [ 5]: t=0 0 [May 18 02:48:52] DEBUG[13691] chan_sip.c: Body 5 [ 32]: m=audio 60675 RTP/AVP 18 3 0 101 [May 18 02:48:52] DEBUG[13691] chan_sip.c: Body 6 [ 67]: a=alt:1 1 : 6B8F8831 E985975B 58.69.37.108 60675 58.69.37.108 60928 [May 18 02:48:52] DEBUG[13691] chan_sip.c: Body 7 [ 49]: a=alt:2 3 : FEA44E01 2542BF92 192.168.2.254 10592 [May 18 02:48:52] DEBUG[13691] chan_sip.c: Body 8 [ 15]: a=fmtp:101 0-15 [May 18 02:48:52] DEBUG[13691] chan_sip.c: Body 9 [ 12]: a=rtcp:60928 [May 18 02:48:52] DEBUG[13691] chan_sip.c: Body 10 [ 33]: a=rtpmap:101 telephone-event/8000 [May 18 02:48:52] DEBUG[13691] chan_sip.c: Body 11 [ 10]: a=sendrecv [May 18 02:48:52] VERBOSE[13691] chan_sip.c: --- (12 headers 12 lines) --- [May 18 02:48:52] DEBUG[13691] acl.c: Found IP address for this socket [May 18 02:48:52] DEBUG[13691] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 222.126.44.162:5060 [May 18 02:48:52] DEBUG[13691] chan_sip.c: Allocating new SIP dialog for 97338c5bd438343b - INVITE (No RTP) [May 18 02:48:52] DEBUG[13691] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE [May 18 02:48:52] VERBOSE[13691] chan_sip.c: Sending to 58.69.37.108 : 60672 (no NAT) [May 18 02:48:52] DEBUG[13691] chan_sip.c: Initializing initreq for method INVITE - callid 97338c5bd438343b [May 18 02:48:52] VERBOSE[13691] chan_sip.c: Using INVITE request as basis request - 97338c5bd438343b [May 18 02:48:52] VERBOSE[13691] chan_sip.c: Found peer '100' for '100' from 58.69.37.108:60672 [May 18 02:48:52] VERBOSE[13691] chan_sip.c: <--- Reliably Transmitting (NAT) to 58.69.37.108:60672 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 58.69.37.108:60672;branch=z9hG4bK-d87543-650131918-1--d87543-;received=58.69.37.108;rport=60672 From: Agent Orange;tag=d167d863 To: ;tag=as4c30a40f Call-ID: 97338c5bd438343b CSeq: 1 INVITE Server: Asterisk PBX SVN-trunk-r263541 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="48294513" Content-Length: 0 <------------> [May 18 02:48:52] DEBUG[13691] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #14 [May 18 02:48:52] DEBUG[13691] chan_sip.c: Trying to put 'SIP/2.0 401' onto UDP socket destined for 58.69.37.108:60672 [May 18 02:48:52] VERBOSE[13691] chan_sip.c: Scheduling destruction of SIP dialog '97338c5bd438343b' in 32000 ms (Method: INVITE) [May 18 02:48:52] VERBOSE[13691] chan_sip.c: <--- SIP read from UDP:58.69.37.108:60672 ---> ACK sip:200@222.126.44.162 SIP/2.0 To: ;tag=as4c30a40f From: Agent Orange;tag=d167d863 Via: SIP/2.0/UDP 58.69.37.108:60672;branch=z9hG4bK-d87543-650131918-1--d87543-;rport Call-ID: 97338c5bd438343b CSeq: 1 ACK Content-Length: 0 <-------------> [May 18 02:48:52] DEBUG[13691] chan_sip.c: Header 0 [ 34]: ACK sip:200@222.126.44.162 SIP/2.0 [May 18 02:48:52] DEBUG[13691] chan_sip.c: Header 1 [ 43]: To: ;tag=as4c30a40f [May 18 02:48:52] DEBUG[13691] chan_sip.c: Header 2 [ 55]: From: Agent Orange;tag=d167d863 [May 18 02:48:52] DEBUG[13691] chan_sip.c: Header 3 [ 84]: Via: SIP/2.0/UDP 58.69.37.108:60672;branch=z9hG4bK-d87543-650131918-1--d87543-;rport [May 18 02:48:52] DEBUG[13691] chan_sip.c: Header 4 [ 25]: Call-ID: 97338c5bd438343b [May 18 02:48:52] DEBUG[13691] chan_sip.c: Header 5 [ 11]: CSeq: 1 ACK [May 18 02:48:52] DEBUG[13691] chan_sip.c: Header 6 [ 17]: Content-Length: 0 [May 18 02:48:52] DEBUG[13691] chan_sip.c: Header 7 [ 0]: [May 18 02:48:52] VERBOSE[13691] chan_sip.c: --- (7 headers 0 lines) --- [May 18 02:48:52] DEBUG[13691] chan_sip.c: **** Received ACK (6) - Command in SIP ACK [May 18 02:48:52] DEBUG[13691] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #14 [May 18 02:48:52] DEBUG[13691] chan_sip.c: Stopping retransmission on '97338c5bd438343b' of Response 1: Match Found [May 18 02:48:52] VERBOSE[13691] chan_sip.c: <--- SIP read from UDP:58.69.37.108:60672 ---> INVITE sip:200@222.126.44.162 SIP/2.0 To: From: Agent Orange;tag=d167d863 Via: SIP/2.0/UDP 58.69.37.108:60672;branch=z9hG4bK-d87543-623650876-1--d87543-;rport Call-ID: 97338c5bd438343b CSeq: 2 INVITE Contact: Max-Forwards: 70 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO Content-Type: application/sdp User-Agent: eyeBeam release 3004w stamp 16863 Authorization: Digest username="100",realm="asterisk",nonce="48294513",uri="sip:200@222.126.44.162",response="a63813f42d86de4bb41f47cfb327de75",algorithm=MD5 Content-Length: 321 v=0 o=- 21996018 21996356 IN IP4 58.69.37.108 s=eyeBeam c=IN IP4 58.69.37.108 t=0 0 m=audio 60675 RTP/AVP 18 3 0 101 a=alt:1 1 : 6B8F8831 E985975B 58.69.37.108 60675 58.69.37.108 60928 a=alt:2 3 : FEA44E01 2542BF92 192.168.2.254 10592 a=fmtp:101 0-15 a=rtcp:60928 a=rtpmap:101 telephone-event/8000 a=sendrecv <-------------> [May 18 02:48:52] DEBUG[13691] chan_sip.c: Header 0 [ 37]: INVITE sip:200@222.126.44.162 SIP/2.0 [May 18 02:48:52] DEBUG[13691] chan_sip.c: Header 1 [ 28]: To: [May 18 02:48:52] DEBUG[13691] chan_sip.c: Header 2 [ 55]: From: Agent Orange;tag=d167d863 [May 18 02:48:52] DEBUG[13691] chan_sip.c: Header 3 [ 84]: Via: SIP/2.0/UDP 58.69.37.108:60672;branch=z9hG4bK-d87543-623650876-1--d87543-;rport [May 18 02:48:52] DEBUG[13691] chan_sip.c: Header 4 [ 25]: Call-ID: 97338c5bd438343b [May 18 02:48:52] DEBUG[13691] chan_sip.c: Header 5 [ 14]: CSeq: 2 INVITE [May 18 02:48:52] DEBUG[13691] chan_sip.c: Header 6 [ 37]: Contact: [May 18 02:48:52] DEBUG[13691] chan_sip.c: Header 7 [ 16]: Max-Forwards: 70 [May 18 02:48:52] DEBUG[13691] chan_sip.c: Header 8 [ 81]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO [May 18 02:48:52] DEBUG[13691] chan_sip.c: Header 9 [ 29]: Content-Type: application/sdp [May 18 02:48:52] DEBUG[13691] chan_sip.c: Header 10 [ 45]: User-Agent: eyeBeam release 3004w stamp 16863 [May 18 02:48:52] DEBUG[13691] chan_sip.c: Header 11 [157]: Authorization: Digest username="100",realm="asterisk",nonce="48294513",uri="sip:200@222.126.44.162",response="a63813f42d86de4bb41f47cfb327de75",algorithm=MD5 [May 18 02:48:52] DEBUG[13691] chan_sip.c: Header 12 [ 19]: Content-Length: 321 [May 18 02:48:52] DEBUG[13691] chan_sip.c: Header 13 [ 0]: [May 18 02:48:52] DEBUG[13691] chan_sip.c: Body 0 [ 3]: v=0 [May 18 02:48:52] DEBUG[13691] chan_sip.c: Body 1 [ 41]: o=- 21996018 21996356 IN IP4 58.69.37.108 [May 18 02:48:52] DEBUG[13691] chan_sip.c: Body 2 [ 9]: s=eyeBeam [May 18 02:48:52] DEBUG[13691] chan_sip.c: Body 3 [ 21]: c=IN IP4 58.69.37.108 [May 18 02:48:52] DEBUG[13691] chan_sip.c: Body 4 [ 5]: t=0 0 [May 18 02:48:52] DEBUG[13691] chan_sip.c: Body 5 [ 32]: m=audio 60675 RTP/AVP 18 3 0 101 [May 18 02:48:52] DEBUG[13691] chan_sip.c: Body 6 [ 67]: a=alt:1 1 : 6B8F8831 E985975B 58.69.37.108 60675 58.69.37.108 60928 [May 18 02:48:52] DEBUG[13691] chan_sip.c: Body 7 [ 49]: a=alt:2 3 : FEA44E01 2542BF92 192.168.2.254 10592 [May 18 02:48:52] DEBUG[13691] chan_sip.c: Body 8 [ 15]: a=fmtp:101 0-15 [May 18 02:48:52] DEBUG[13691] chan_sip.c: Body 9 [ 12]: a=rtcp:60928 [May 18 02:48:52] DEBUG[13691] chan_sip.c: Body 10 [ 33]: a=rtpmap:101 telephone-event/8000 [May 18 02:48:52] DEBUG[13691] chan_sip.c: Body 11 [ 10]: a=sendrecv [May 18 02:48:52] VERBOSE[13691] chan_sip.c: --- (13 headers 12 lines) --- [May 18 02:48:52] DEBUG[13691] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE [May 18 02:48:52] VERBOSE[13691] chan_sip.c: Sending to 58.69.37.108 : 60672 (NAT) [May 18 02:48:52] DEBUG[13691] chan_sip.c: Initializing initreq for method INVITE - callid 97338c5bd438343b [May 18 02:48:52] VERBOSE[13691] chan_sip.c: Using INVITE request as basis request - 97338c5bd438343b [May 18 02:48:52] VERBOSE[13691] chan_sip.c: Found peer '100' for '100' from 58.69.37.108:60672 [May 18 02:48:52] DEBUG[13691] rtp_engine.c: Using engine 'asterisk' for RTP instance '0xbacb8a8' [May 18 02:48:52] DEBUG[13691] res_rtp_asterisk.c: Allocated port 16968 for RTP instance '0xbacb8a8' [May 18 02:48:52] DEBUG[13691] rtp_engine.c: RTP instance '0xbacb8a8' is setup and ready to go [May 18 02:48:52] DEBUG[13691] res_rtp_asterisk.c: Setup RTCP on RTP instance '0xbacb8a8' [May 18 02:48:52] DEBUG[13691] chan_sip.c: Setting NAT on RTP to On [May 18 02:48:52] DEBUG[13691] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED. [May 18 02:48:52] DEBUG[13691] chan_sip.c: Processing session-level SDP o=- 21996018 21996356 IN IP4 58.69.37.108... UNSUPPORTED. [May 18 02:48:52] DEBUG[13691] chan_sip.c: Processing session-level SDP s=eyeBeam... UNSUPPORTED. [May 18 02:48:52] DEBUG[13691] chan_sip.c: Processing session-level SDP c=IN IP4 58.69.37.108... OK. [May 18 02:48:52] DEBUG[13691] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED. [May 18 02:48:52] VERBOSE[13691] chan_sip.c: Found RTP audio format 18 [May 18 02:48:52] DEBUG[13691] rtp_engine.c: Setting payload 18 based on m type on 0x741f74c [May 18 02:48:52] VERBOSE[13691] chan_sip.c: Found RTP audio format 3 [May 18 02:48:52] DEBUG[13691] rtp_engine.c: Setting payload 3 based on m type on 0x741f74c [May 18 02:48:52] VERBOSE[13691] chan_sip.c: Found RTP audio format 0 [May 18 02:48:52] DEBUG[13691] rtp_engine.c: Setting payload 0 based on m type on 0x741f74c [May 18 02:48:52] VERBOSE[13691] chan_sip.c: Found RTP audio format 101 [May 18 02:48:52] DEBUG[13691] rtp_engine.c: Setting payload 101 based on m type on 0x741f74c [May 18 02:48:52] DEBUG[13691] chan_sip.c: Processing media-level (audio) SDP a=alt:1 1 : 6B8F8831 E985975B 58.69.37.108 60675 58.69.37.108 60928... UNSUPPORTED. [May 18 02:48:52] DEBUG[13691] chan_sip.c: Processing media-level (audio) SDP a=alt:2 3 : FEA44E01 2542BF92 192.168.2.254 10592... UNSUPPORTED. [May 18 02:48:52] DEBUG[13691] chan_sip.c: Processing media-level (audio) SDP a=fmtp:101 0-15... UNSUPPORTED. [May 18 02:48:52] DEBUG[13691] chan_sip.c: Processing media-level (audio) SDP a=rtcp:60928... UNSUPPORTED. [May 18 02:48:52] VERBOSE[13691] chan_sip.c: Found audio description format telephone-event for ID 101 [May 18 02:48:52] DEBUG[13691] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK. [May 18 02:48:52] DEBUG[13691] chan_sip.c: Processing media-level (audio) SDP a=sendrecv... OK. [May 18 02:48:52] DEBUG[13691] rtp_engine.c: Incorporating payload 0 on 0x741f74c [May 18 02:48:52] DEBUG[13691] rtp_engine.c: Incorporating payload 3 on 0x741f74c [May 18 02:48:52] DEBUG[13691] rtp_engine.c: Incorporating payload 18 on 0x741f74c [May 18 02:48:52] DEBUG[13691] rtp_engine.c: Incorporating payload 101 on 0x741f74c [May 18 02:48:52] VERBOSE[13691] chan_sip.c: Capabilities: us - 0x100 (g729), peer - audio=0x106 (gsm|ulaw|g729)/video=0x0 (nothing)/text=0x0 (nothing), combined - 0x100 (g729) [May 18 02:48:52] VERBOSE[13691] chan_sip.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|) [May 18 02:48:52] DEBUG[13691] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0xbacb8a8' [May 18 02:48:52] VERBOSE[13691] chan_sip.c: Peer audio RTP is at port 58.69.37.108:60675 [May 18 02:48:52] DEBUG[13691] rtp_engine.c: Copying payload 0 from 0x741f74c to 0xbacb8f8 [May 18 02:48:52] DEBUG[13691] rtp_engine.c: Copying payload 3 from 0x741f74c to 0xbacb8f8 [May 18 02:48:52] DEBUG[13691] rtp_engine.c: Copying payload 18 from 0x741f74c to 0xbacb8f8 [May 18 02:48:52] DEBUG[13691] rtp_engine.c: Copying payload 101 from 0x741f74c to 0xbacb8f8 [May 18 02:48:52] DEBUG[13691] chan_sip.c: We're settling with these formats: 0x100 (g729) [May 18 02:48:52] DEBUG[13691] chan_sip.c: Checking SIP call limits for device 100 [May 18 02:48:52] DEBUG[13691] chan_sip.c: Updating call counter for incoming call [May 18 02:48:52] VERBOSE[13691] chan_sip.c: Looking for 200 in internal (domain 222.126.44.162) [May 18 02:48:52] DEBUG[13691] chan_sip.c: *** Our native formats are 0x100 (g729) [May 18 02:48:52] DEBUG[13691] chan_sip.c: *** Joint capabilities are 0x100 (g729) [May 18 02:48:52] DEBUG[13691] chan_sip.c: *** Our capabilities are 0x100 (g729) [May 18 02:48:52] DEBUG[13691] chan_sip.c: *** AST_CODEC_CHOOSE formats are 0x100 (g729) [May 18 02:48:52] DEBUG[13691] chan_sip.c: This channel will not be able to handle video. [May 18 02:48:52] DEBUG[13691] chan_sip.c: build_route: Contact hop: [May 18 02:48:52] VERBOSE[13691] chan_sip.c: list_route: hop: [May 18 02:48:52] DEBUG[13691] chan_sip.c: SIP/100-00000002: New call is still down.... Trying... [May 18 02:48:52] VERBOSE[13691] chan_sip.c: <--- Transmitting (NAT) to 58.69.37.108:60672 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 58.69.37.108:60672;branch=z9hG4bK-d87543-623650876-1--d87543-;received=58.69.37.108;rport=60672 From: Agent Orange;tag=d167d863 To: Call-ID: 97338c5bd438343b CSeq: 2 INVITE Server: Asterisk PBX SVN-trunk-r263541 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Contact: Content-Length: 0 <------------> [May 18 02:48:52] DEBUG[13691] chan_sip.c: Trying to put 'SIP/2.0 100' onto UDP socket destined for 58.69.37.108:60672 [May 18 02:48:52] DEBUG[13662] devicestate.c: No provider found, checking channel drivers for SIP - 100 [May 18 02:48:52] DEBUG[13662] chan_sip.c: Checking device state for peer 100 [May 18 02:48:52] DEBUG[13662] devicestate.c: Changing state for SIP/100 - state 1 (Not in use) [May 18 02:48:52] DEBUG[13662] devicestate.c: device 'SIP/100' state '1' [May 18 02:48:52] DEBUG[13717] pbx.c: Launching 'Set' [May 18 02:48:52] VERBOSE[13717] pbx.c: -- Executing [200@internal:1] Set("SIP/100-00000002", "MEETME_EXIT_CONTEXT=confexit") in new stack [May 18 02:48:52] DEBUG[13717] pbx.c: Result of 'EXTEN' is '200' [May 18 02:48:52] DEBUG[13717] pbx.c: Launching 'Set' [May 18 02:48:52] VERBOSE[13717] pbx.c: -- Executing [200@internal:2] Set("SIP/100-00000002", "lastconfno=200") in new stack [May 18 02:48:52] DEBUG[13717] pbx.c: Result of 'EXTEN' is '200' [May 18 02:48:52] DEBUG[13717] pbx.c: Launching 'MeetMe' [May 18 02:48:52] VERBOSE[13717] pbx.c: -- Executing [200@internal:3] MeetMe("SIP/100-00000002", "200,M(default)Fq") in new stack [May 18 02:48:52] DEBUG[13662] devicestate.c: No provider found, checking channel drivers for SIP - 100 [May 18 02:48:52] DEBUG[13717] chan_sip.c: SIP answering channel: SIP/100-00000002 [May 18 02:48:52] DEBUG[13662] chan_sip.c: Checking device state for peer 100 [May 18 02:48:52] DEBUG[13717] res_rtp_asterisk.c: Setting the marker bit due to a source update [May 18 02:48:52] DEBUG[13662] devicestate.c: Changing state for SIP/100 - state 1 (Not in use) [May 18 02:48:52] DEBUG[13662] devicestate.c: device 'SIP/100' state '1' [May 18 02:48:52] DEBUG[13717] chan_sip.c: Setting framing from config on incoming call [May 18 02:48:52] DEBUG[13717] chan_sip.c: ** Our capability: 0x100 (g729) Video flag: True Text flag: True [May 18 02:48:52] DEBUG[13717] chan_sip.c: ** Our prefcodec: 0x0 (nothing) [May 18 02:48:52] DEBUG[13697] app_queue.c: Device 'SIP/100' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [May 18 02:48:52] VERBOSE[13717] chan_sip.c: Audio is at 222.126.44.162 port 16968 [May 18 02:48:52] VERBOSE[13717] chan_sip.c: Adding codec 0x100 (g729) to SDP [May 18 02:48:52] DEBUG[13697] app_queue.c: Device 'SIP/100' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [May 18 02:48:52] VERBOSE[13717] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP [May 18 02:48:52] DEBUG[13717] chan_sip.c: -- Done with adding codecs to SDP [May 18 02:48:52] DEBUG[13717] chan_sip.c: Done building SDP. Settling with this capability: 0x100 (g729) [May 18 02:48:52] VERBOSE[13717] chan_sip.c: <--- Reliably Transmitting (NAT) to 58.69.37.108:60672 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 58.69.37.108:60672;branch=z9hG4bK-d87543-623650876-1--d87543-;received=58.69.37.108;rport=60672 From: Agent Orange;tag=d167d863 To: ;tag=as06bb4b7f Call-ID: 97338c5bd438343b CSeq: 2 INVITE Server: Asterisk PBX SVN-trunk-r263541 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Contact: Content-Type: application/sdp Content-Length: 296 v=0 o=root 48891555 48891555 IN IP4 222.126.44.162 s=Asterisk PBX SVN-trunk-r263541 c=IN IP4 222.126.44.162 t=0 0 m=audio 16968 RTP/AVP 18 101 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv <------------> [May 18 02:48:52] DEBUG[13717] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #17 [May 18 02:48:52] DEBUG[13717] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 58.69.37.108:60672 [May 18 02:48:52] VERBOSE[13691] chan_sip.c: <--- SIP read from UDP:58.69.37.108:60672 ---> ACK sip:200@222.126.44.162 SIP/2.0 To: ;tag=as06bb4b7f From: Agent Orange;tag=d167d863 Via: SIP/2.0/UDP 58.69.37.108:60672;branch=z9hG4bK-d87543-690124529-1--d87543-;rport Call-ID: 97338c5bd438343b CSeq: 2 ACK Contact: Max-Forwards: 70 User-Agent: eyeBeam release 3004w stamp 16863 Authorization: Digest username="100",realm="asterisk",nonce="48294513",uri="sip:200@222.126.44.162",response="a63813f42d86de4bb41f47cfb327de75",algorithm=MD5 Content-Length: 0 <-------------> [May 18 02:48:52] DEBUG[13691] chan_sip.c: Header 0 [ 34]: ACK sip:200@222.126.44.162 SIP/2.0 [May 18 02:48:52] DEBUG[13691] chan_sip.c: Header 1 [ 43]: To: ;tag=as06bb4b7f [May 18 02:48:52] DEBUG[13691] chan_sip.c: Header 2 [ 55]: From: Agent Orange;tag=d167d863 [May 18 02:48:52] DEBUG[13691] chan_sip.c: Header 3 [ 84]: Via: SIP/2.0/UDP 58.69.37.108:60672;branch=z9hG4bK-d87543-690124529-1--d87543-;rport [May 18 02:48:52] DEBUG[13691] chan_sip.c: Header 4 [ 25]: Call-ID: 97338c5bd438343b [May 18 02:48:52] DEBUG[13691] chan_sip.c: Header 5 [ 11]: CSeq: 2 ACK [May 18 02:48:52] DEBUG[13691] chan_sip.c: Header 6 [ 37]: Contact: [May 18 02:48:52] DEBUG[13691] chan_sip.c: Header 7 [ 16]: Max-Forwards: 70 [May 18 02:48:52] DEBUG[13691] chan_sip.c: Header 8 [ 45]: User-Agent: eyeBeam release 3004w stamp 16863 [May 18 02:48:52] DEBUG[13691] chan_sip.c: Header 9 [157]: Authorization: Digest username="100",realm="asterisk",nonce="48294513",uri="sip:200@222.126.44.162",response="a63813f42d86de4bb41f47cfb327de75",algorithm=MD5 [May 18 02:48:52] DEBUG[13691] chan_sip.c: Header 10 [ 17]: Content-Length: 0 [May 18 02:48:52] DEBUG[13691] chan_sip.c: Header 11 [ 0]: [May 18 02:48:52] VERBOSE[13691] chan_sip.c: --- (11 headers 0 lines) --- [May 18 02:48:52] DEBUG[13691] chan_sip.c: **** Received ACK (6) - Command in SIP ACK [May 18 02:48:52] DEBUG[13691] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #17 [May 18 02:48:52] DEBUG[13691] chan_sip.c: Stopping retransmission on '97338c5bd438343b' of Response 2: Match Found [May 18 02:48:52] DEBUG[13717] res_rtp_asterisk.c: RTCP NAT: Got RTCP from other end. Now sending to address 58.69.37.108:60928 [May 18 02:48:52] DEBUG[13717] res_rtp_asterisk.c: Got RTCP report of 72 bytes [May 18 02:48:53] DEBUG[13717] channel.c: Didn't receive a media frame from SIP/100-00000002 within 500 ms of answering. Continuing anyway [May 18 02:48:53] DEBUG[13717] app_meetme.c: The requested confno is '200'? [May 18 02:48:53] VERBOSE[13717] config.c: == Parsing '/etc/asterisk/meetme.conf': [May 18 02:48:53] DEBUG[13717] config.c: Parsing /etc/asterisk/meetme.conf [May 18 02:48:53] VERBOSE[13717] config.c: == Found [May 18 02:48:53] DEBUG[13717] app_meetme.c: Will conf 200 match 200? [May 18 02:48:53] DEBUG[13717] chan_dahdi.c: Using channel -2 [May 18 02:48:53] DEBUG[13717] devicestate.c: device 'DAHDI/pseudo-1342480689' state '2' [May 18 02:48:53] DEBUG[13717] channel.c: Set channel DAHDI/pseudo-1342480689 to read format slin [May 18 02:48:53] DEBUG[13717] channel.c: Set channel DAHDI/pseudo-1342480689 to write format slin [May 18 02:48:53] DEBUG[13697] app_queue.c: Device 'DAHDI/pseudo-1342480689' changed to state '2' (In use) but we don't care because they're not a member of any queue. [May 18 02:48:53] VERBOSE[13717] app_meetme.c: -- Created MeetMe conference 1023 for conference '200' [May 18 02:48:53] DEBUG[13717] devicestate.c: device 'meetme:200' state '2' [May 18 02:48:53] DEBUG[13717] channel.c: Set channel SIP/100-00000002 to write format slin [May 18 02:48:53] DEBUG[13697] app_queue.c: Device 'meetme:200' changed to state '2' (In use) but we don't care because they're not a member of any queue. [May 18 02:48:53] DEBUG[13717] channel.c: Set channel SIP/100-00000002 to read format slin [May 18 02:48:53] DEBUG[13717] app_meetme.c: Placed channel SIP/100-00000002 in DAHDI conf 1023 [May 18 02:48:53] DEBUG[13717] dsp.c: Setup tone 1100 Hz, 500 ms, block_size=160, hits_required=21 [May 18 02:48:53] DEBUG[13717] dsp.c: Setup tone 2100 Hz, 2600 ms, block_size=160, hits_required=116 [May 18 02:48:53] VERBOSE[13717] res_musiconhold.c: -- Started music on hold, class 'default', on SIP/100-00000002 [May 18 02:48:53] DEBUG[13717] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second [May 18 02:48:53] DEBUG[13717] res_musiconhold.c: SIP/100-00000002 Opened file 1 '/var/lib/asterisk/moh/fpm-world-mix' [May 18 02:48:53] DEBUG[13717] res_rtp_asterisk.c: Ooh, format changed from unknown to g729 [May 18 02:48:53] DEBUG[13717] res_rtp_asterisk.c: Created smoother: format: g729 ms: 20 len: 20 [May 18 02:48:53] DEBUG[13717] res_rtp_asterisk.c: Starting RTCP transmission on RTP instance '0xbacb8a8' [May 18 02:48:58] DEBUG[13717] res_rtp_asterisk.c: Got RTCP report of 32 bytes [May 18 02:48:58] DEBUG[13717] res_rtp_asterisk.c: Got RTCP report of 72 bytes [May 18 02:49:04] VERBOSE[13718] pbx_spool.c: -- Attempting call on Local/18005204433@outgoing/n for 200@confroom:1 (Retry 1) [May 18 02:49:04] DEBUG[13719] pbx.c: Result of 'EXTEN' is '18005204433' [May 18 02:49:04] DEBUG[13719] pbx.c: Launching 'Set' [May 18 02:49:04] VERBOSE[13719] pbx.c: -- Executing [18005204433@outgoing:1] Set("Local/18005204433@outgoing-f001;2", "CALLERID(name)=18005204433") in new stack [May 18 02:49:04] DEBUG[13719] pbx.c: Result of 'EXTEN' is '18005204433' [May 18 02:49:04] DEBUG[13719] pbx.c: Launching 'Dial' [May 18 02:49:04] VERBOSE[13719] pbx.c: -- Executing [18005204433@outgoing:2] Dial("Local/18005204433@outgoing-f001;2", "Sip/gw/66618005204433,60") in new stack [May 18 02:49:04] DEBUG[13719] chan_sip.c: Asked to create a SIP channel with formats: 0x40 (slin) [May 18 02:49:04] DEBUG[13719] chan_sip.c: Allocating new SIP dialog for 4c743a3e3e8a744234a28a562c8cb786@127.0.0.1 - INVITE (No RTP) [May 18 02:49:04] DEBUG[13719] rtp_engine.c: Using engine 'asterisk' for RTP instance '0xbad5f60' [May 18 02:49:04] DEBUG[13719] res_rtp_asterisk.c: Allocated port 18330 for RTP instance '0xbad5f60' [May 18 02:49:04] DEBUG[13719] rtp_engine.c: RTP instance '0xbad5f60' is setup and ready to go [May 18 02:49:04] DEBUG[13719] res_rtp_asterisk.c: Setup RTCP on RTP instance '0xbad5f60' [May 18 02:49:04] DEBUG[13719] chan_sip.c: Setting NAT on RTP to Off [May 18 02:49:04] DEBUG[13719] chan_sip.c: OBPROXY: Not applying OBproxy to this call [May 18 02:49:04] DEBUG[13719] acl.c: Found IP address for this socket [May 18 02:49:04] DEBUG[13719] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 222.126.44.162:5060 [May 18 02:49:04] DEBUG[13719] frame.c: Could not find preferred codec - Going for the best codec [May 18 02:49:04] DEBUG[13719] chan_sip.c: *** Our native formats are 0x40 (slin) [May 18 02:49:04] DEBUG[13719] chan_sip.c: *** Joint capabilities are 0x40 (slin) [May 18 02:49:04] DEBUG[13719] chan_sip.c: *** Our capabilities are 0x10e (gsm|ulaw|alaw|g729) [May 18 02:49:04] DEBUG[13719] frame.c: Could not find preferred codec - Going for the best codec [May 18 02:49:04] DEBUG[13719] chan_sip.c: *** AST_CODEC_CHOOSE formats are 0x40 (slin) [May 18 02:49:04] DEBUG[13719] chan_sip.c: *** Our preferred formats from the incoming channel are 0x40 (slin) [May 18 02:49:04] DEBUG[13719] chan_sip.c: This channel will not be able to handle video. [May 18 02:49:04] DEBUG[13719] rtp_engine.c: Can't find native functions for channel 'Local/18005204433@outgoing-f001;2' [May 18 02:49:04] DEBUG[13719] rtp_engine.c: Seeded SDP of 'SIP/gw-00000003' with that of 'Local/18005204433@outgoing-f001;2' [May 18 02:49:04] DEBUG[13719] channel.c: Not copying variable DIALEDTIME. [May 18 02:49:04] DEBUG[13719] channel.c: Not copying variable ANSWEREDTIME. [May 18 02:49:04] DEBUG[13719] channel.c: Not copying variable DIALEDPEERNAME. [May 18 02:49:04] DEBUG[13719] channel.c: Not copying variable DIALEDPEERNUMBER. [May 18 02:49:04] DEBUG[13719] channel.c: Not copying variable DIALSTATUS. [May 18 02:49:04] DEBUG[13719] chan_sip.c: Outgoing Call for 66618005204433 [May 18 02:49:04] DEBUG[13719] chan_sip.c: Updating call counter for outgoing call [May 18 02:49:04] DEBUG[13719] chan_sip.c: ** Our capability: 0x10e (gsm|ulaw|alaw|g729) Video flag: False Text flag: False [May 18 02:49:04] DEBUG[13719] chan_sip.c: ** Our prefcodec: 0x40 (slin) [May 18 02:49:04] VERBOSE[13719] chan_sip.c: Audio is at 222.126.44.162 port 18330 [May 18 02:49:04] VERBOSE[13719] chan_sip.c: Adding codec 0x100 (g729) to SDP [May 18 02:49:04] VERBOSE[13719] chan_sip.c: Adding codec 0x2 (gsm) to SDP [May 18 02:49:04] VERBOSE[13719] chan_sip.c: Adding codec 0x4 (ulaw) to SDP [May 18 02:49:04] VERBOSE[13719] chan_sip.c: Adding codec 0x8 (alaw) to SDP [May 18 02:49:04] VERBOSE[13719] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP [May 18 02:49:04] DEBUG[13719] chan_sip.c: -- Done with adding codecs to SDP [May 18 02:49:04] DEBUG[13719] chan_sip.c: Done building SDP. Settling with this capability: 0x10e (gsm|ulaw|alaw|g729) [May 18 02:49:04] DEBUG[13719] chan_sip.c: Initializing initreq for method INVITE - callid 378d2667481a8be132bb047d106a2f2f@222.126.44.162 [May 18 02:49:04] DEBUG[13719] chan_sip.c: Header 0 [ 49]: INVITE sip:66618005204433@203.176.117.204 SIP/2.0 [May 18 02:49:04] DEBUG[13719] chan_sip.c: Header 1 [ 59]: Via: SIP/2.0/UDP 222.126.44.162:5060;branch=z9hG4bK32270cfd [May 18 02:49:04] DEBUG[13719] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [May 18 02:49:04] DEBUG[13719] chan_sip.c: Header 3 [ 64]: From: "18005204433" ;tag=as63200337 [May 18 02:49:04] DEBUG[13719] chan_sip.c: Header 4 [ 40]: To: [May 18 02:49:04] DEBUG[13719] chan_sip.c: Header 5 [ 38]: Contact: [May 18 02:49:04] DEBUG[13719] chan_sip.c: Header 6 [ 56]: Call-ID: 378d2667481a8be132bb047d106a2f2f@222.126.44.162 [May 18 02:49:04] DEBUG[13719] chan_sip.c: Header 7 [ 16]: CSeq: 102 INVITE [May 18 02:49:04] DEBUG[13719] chan_sip.c: Header 8 [ 42]: User-Agent: Asterisk PBX SVN-trunk-r263541 [May 18 02:49:04] DEBUG[13719] chan_sip.c: Header 9 [ 35]: Date: Mon, 17 May 2010 18:49:04 GMT [May 18 02:49:04] DEBUG[13719] chan_sip.c: Header 10 [ 81]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH [May 18 02:49:04] DEBUG[13719] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [May 18 02:49:04] DEBUG[13719] chan_sip.c: Header 12 [ 29]: Content-Type: application/sdp [May 18 02:49:04] DEBUG[13719] chan_sip.c: Header 13 [ 19]: Content-Length: 371 [May 18 02:49:04] DEBUG[13719] chan_sip.c: Header 14 [ 0]: [May 18 02:49:04] DEBUG[13719] chan_sip.c: Body 0 [ 3]: v=0 [May 18 02:49:04] DEBUG[13719] chan_sip.c: Body 1 [ 50]: o=root 2058870869 2058870869 IN IP4 222.126.44.162 [May 18 02:49:04] DEBUG[13719] chan_sip.c: Body 2 [ 32]: s=Asterisk PBX SVN-trunk-r263541 [May 18 02:49:04] DEBUG[13719] chan_sip.c: Body 3 [ 23]: c=IN IP4 222.126.44.162 [May 18 02:49:04] DEBUG[13719] chan_sip.c: Body 4 [ 5]: t=0 0 [May 18 02:49:04] DEBUG[13719] chan_sip.c: Body 5 [ 34]: m=audio 18330 RTP/AVP 18 3 0 8 101 [May 18 02:49:04] DEBUG[13719] chan_sip.c: Body 6 [ 21]: a=rtpmap:18 G729/8000 [May 18 02:49:04] DEBUG[13719] chan_sip.c: Body 7 [ 19]: a=fmtp:18 annexb=no [May 18 02:49:04] DEBUG[13719] chan_sip.c: Body 8 [ 19]: a=rtpmap:3 GSM/8000 [May 18 02:49:04] DEBUG[13719] chan_sip.c: Body 9 [ 20]: a=rtpmap:0 PCMU/8000 [May 18 02:49:04] DEBUG[13719] chan_sip.c: Body 10 [ 20]: a=rtpmap:8 PCMA/8000 [May 18 02:49:04] DEBUG[13719] chan_sip.c: Body 11 [ 33]: a=rtpmap:101 telephone-event/8000 [May 18 02:49:04] DEBUG[13719] chan_sip.c: Body 12 [ 15]: a=fmtp:101 0-16 [May 18 02:49:04] DEBUG[13719] chan_sip.c: Body 13 [ 25]: a=silenceSupp:off - - - - [May 18 02:49:04] DEBUG[13719] chan_sip.c: Body 14 [ 10]: a=ptime:20 [May 18 02:49:04] DEBUG[13719] chan_sip.c: Body 15 [ 10]: a=sendrecv [May 18 02:49:04] VERBOSE[13719] chan_sip.c: Reliably Transmitting (no NAT) to 203.176.117.204:5060: INVITE sip:66618005204433@203.176.117.204 SIP/2.0 Via: SIP/2.0/UDP 222.126.44.162:5060;branch=z9hG4bK32270cfd Max-Forwards: 70 From: "18005204433" ;tag=as63200337 To: Contact: Call-ID: 378d2667481a8be132bb047d106a2f2f@222.126.44.162 CSeq: 102 INVITE User-Agent: Asterisk PBX SVN-trunk-r263541 Date: Mon, 17 May 2010 18:49:04 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Content-Type: application/sdp Content-Length: 371 v=0 o=root 2058870869 2058870869 IN IP4 222.126.44.162 s=Asterisk PBX SVN-trunk-r263541 c=IN IP4 222.126.44.162 t=0 0 m=audio 18330 RTP/AVP 18 3 0 8 101 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no 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 --- [May 18 02:49:04] DEBUG[13719] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #19 [May 18 02:49:04] DEBUG[13719] chan_sip.c: Trying to put 'INVITE sip:' onto UDP socket destined for 203.176.117.204:5060 [May 18 02:49:04] VERBOSE[13719] app_dial.c: -- Called gw/66618005204433 [May 18 02:49:04] VERBOSE[13691] chan_sip.c: <--- SIP read from UDP:203.176.117.204:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 222.126.44.162:5060;branch=z9hG4bK32270cfd;received=222.126.44.162 From: "18005204433" ;tag=as63200337 To: Call-ID: 378d2667481a8be132bb047d106a2f2f@222.126.44.162 CSeq: 102 INVITE Server: Asterisk PBX SVN-trunk-r263069 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Require: timer Session-Expires: 1800;refresher=uas Contact: Content-Length: 0 <-------------> [May 18 02:49:04] DEBUG[13691] chan_sip.c: Header 0 [ 18]: SIP/2.0 100 Trying [May 18 02:49:04] DEBUG[13691] chan_sip.c: Header 1 [ 83]: Via: SIP/2.0/UDP 222.126.44.162:5060;branch=z9hG4bK32270cfd;received=222.126.44.162 [May 18 02:49:04] DEBUG[13691] chan_sip.c: Header 2 [ 64]: From: "18005204433" ;tag=as63200337 [May 18 02:49:04] DEBUG[13691] chan_sip.c: Header 3 [ 40]: To: [May 18 02:49:04] DEBUG[13691] chan_sip.c: Header 4 [ 56]: Call-ID: 378d2667481a8be132bb047d106a2f2f@222.126.44.162 [May 18 02:49:04] DEBUG[13691] chan_sip.c: Header 5 [ 16]: CSeq: 102 INVITE [May 18 02:49:04] DEBUG[13691] chan_sip.c: Header 6 [ 38]: Server: Asterisk PBX SVN-trunk-r263069 [May 18 02:49:04] DEBUG[13691] chan_sip.c: Header 7 [ 81]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH [May 18 02:49:04] DEBUG[13691] chan_sip.c: Header 8 [ 26]: Supported: replaces, timer [May 18 02:49:04] DEBUG[13691] chan_sip.c: Header 9 [ 14]: Require: timer [May 18 02:49:04] DEBUG[13691] chan_sip.c: Header 10 [ 35]: Session-Expires: 1800;refresher=uas [May 18 02:49:04] DEBUG[13691] chan_sip.c: Header 11 [ 45]: Contact: [May 18 02:49:04] DEBUG[13691] chan_sip.c: Header 12 [ 17]: Content-Length: 0 [May 18 02:49:04] DEBUG[13691] chan_sip.c: Header 13 [ 0]: [May 18 02:49:04] VERBOSE[13691] chan_sip.c: --- (13 headers 0 lines) --- [May 18 02:49:04] DEBUG[13691] chan_sip.c: *** SIP TIMER: Cancelling retransmission #19 - INVITE (got response) [May 18 02:49:04] DEBUG[13691] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '378d2667481a8be132bb047d106a2f2f@222.126.44.162' Request 102: Found [May 18 02:49:04] DEBUG[13691] chan_sip.c: SIP response 100 to standard invite [May 18 02:49:04] VERBOSE[13691] chan_sip.c: <--- SIP read from UDP:203.176.117.204:5060 ---> SIP/2.0 180 Ringing Via: SIP/2.0/UDP 222.126.44.162:5060;branch=z9hG4bK32270cfd;received=222.126.44.162 From: "18005204433" ;tag=as63200337 To: ;tag=as1c6dd274 Call-ID: 378d2667481a8be132bb047d106a2f2f@222.126.44.162 CSeq: 102 INVITE Server: Asterisk PBX SVN-trunk-r263069 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Require: timer Session-Expires: 1800;refresher=uas Contact: Content-Length: 0 <-------------> [May 18 02:49:04] DEBUG[13691] chan_sip.c: Header 0 [ 19]: SIP/2.0 180 Ringing [May 18 02:49:04] DEBUG[13691] chan_sip.c: Header 1 [ 83]: Via: SIP/2.0/UDP 222.126.44.162:5060;branch=z9hG4bK32270cfd;received=222.126.44.162 [May 18 02:49:04] DEBUG[13691] chan_sip.c: Header 2 [ 64]: From: "18005204433" ;tag=as63200337 [May 18 02:49:04] DEBUG[13691] chan_sip.c: Header 3 [ 55]: To: ;tag=as1c6dd274 [May 18 02:49:04] DEBUG[13691] chan_sip.c: Header 4 [ 56]: Call-ID: 378d2667481a8be132bb047d106a2f2f@222.126.44.162 [May 18 02:49:04] DEBUG[13691] chan_sip.c: Header 5 [ 16]: CSeq: 102 INVITE [May 18 02:49:04] DEBUG[13691] chan_sip.c: Header 6 [ 38]: Server: Asterisk PBX SVN-trunk-r263069 [May 18 02:49:04] DEBUG[13691] chan_sip.c: Header 7 [ 81]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH [May 18 02:49:04] DEBUG[13691] chan_sip.c: Header 8 [ 26]: Supported: replaces, timer [May 18 02:49:04] DEBUG[13691] chan_sip.c: Header 9 [ 14]: Require: timer [May 18 02:49:04] DEBUG[13691] chan_sip.c: Header 10 [ 35]: Session-Expires: 1800;refresher=uas [May 18 02:49:04] DEBUG[13691] chan_sip.c: Header 11 [ 45]: Contact: [May 18 02:49:04] DEBUG[13691] chan_sip.c: Header 12 [ 17]: Content-Length: 0 [May 18 02:49:04] DEBUG[13691] chan_sip.c: Header 13 [ 0]: [May 18 02:49:04] VERBOSE[13691] chan_sip.c: --- (13 headers 0 lines) --- [May 18 02:49:04] DEBUG[13691] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '378d2667481a8be132bb047d106a2f2f@222.126.44.162' Request 102: Found [May 18 02:49:04] DEBUG[13691] chan_sip.c: SIP response 180 to standard invite [May 18 02:49:04] VERBOSE[13719] app_dial.c: -- SIP/gw-00000003 is ringing [May 18 02:49:04] DEBUG[13662] devicestate.c: No provider found, checking channel drivers for SIP - gw [May 18 02:49:04] DEBUG[13662] chan_sip.c: Checking device state for peer gw [May 18 02:49:04] DEBUG[13662] devicestate.c: Changing state for SIP/gw - state 1 (Not in use) [May 18 02:49:04] DEBUG[13662] devicestate.c: device 'SIP/gw' state '1' [May 18 02:49:04] DEBUG[13662] devicestate.c: No provider found, checking channel drivers for Local - 18005204433@outgoing [May 18 02:49:04] DEBUG[13697] app_queue.c: Device 'SIP/gw' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [May 18 02:49:04] DEBUG[13662] chan_local.c: Checking if extension 18005204433@outgoing exists (devicestate) [May 18 02:49:04] DEBUG[13662] devicestate.c: Changing state for Local/18005204433@outgoing - state 2 (In use) [May 18 02:49:04] DEBUG[13662] devicestate.c: device 'Local/18005204433@outgoing' state '2' [May 18 02:49:04] DEBUG[13697] app_queue.c: Device 'Local/18005204433@outgoing' changed to state '2' (In use) but we don't care because they're not a member of any queue. [May 18 02:49:08] DEBUG[13717] res_rtp_asterisk.c: Got RTCP report of 32 bytes [May 18 02:49:08] DEBUG[13717] res_rtp_asterisk.c: Got RTCP report of 72 bytes [May 18 02:49:14] DEBUG[13717] res_rtp_asterisk.c: Got RTCP report of 32 bytes [May 18 02:49:14] DEBUG[13717] res_rtp_asterisk.c: Got RTCP report of 72 bytes [May 18 02:49:19] DEBUG[13692] pbx_spool.c: Delaying retry since we're currently running '/var/spool/asterisk/outgoing/20059876714bf18fa038eed3.30516741.call' [May 18 02:49:21] DEBUG[13717] res_rtp_asterisk.c: Got RTCP report of 32 bytes [May 18 02:49:21] DEBUG[13717] res_rtp_asterisk.c: Got RTCP report of 72 bytes [May 18 02:49:24] VERBOSE[13691] chan_sip.c: <--- SIP read from UDP:203.176.117.204:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 222.126.44.162:5060;branch=z9hG4bK32270cfd;received=222.126.44.162 From: "18005204433" ;tag=as63200337 To: ;tag=as1c6dd274 Call-ID: 378d2667481a8be132bb047d106a2f2f@222.126.44.162 CSeq: 102 INVITE Server: Asterisk PBX SVN-trunk-r263069 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Require: timer Session-Expires: 1800;refresher=uas Contact: Content-Type: application/sdp Content-Length: 373 v=0 o=root 1851714331 1851714331 IN IP4 203.176.117.204 s=Asterisk PBX SVN-trunk-r263069 c=IN IP4 203.176.117.204 t=0 0 m=audio 17860 RTP/AVP 18 3 0 8 101 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no 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 <-------------> [May 18 02:49:24] DEBUG[13691] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [May 18 02:49:24] DEBUG[13691] chan_sip.c: Header 1 [ 83]: Via: SIP/2.0/UDP 222.126.44.162:5060;branch=z9hG4bK32270cfd;received=222.126.44.162 [May 18 02:49:24] DEBUG[13691] chan_sip.c: Header 2 [ 64]: From: "18005204433" ;tag=as63200337 [May 18 02:49:24] DEBUG[13691] chan_sip.c: Header 3 [ 55]: To: ;tag=as1c6dd274 [May 18 02:49:24] DEBUG[13691] chan_sip.c: Header 4 [ 56]: Call-ID: 378d2667481a8be132bb047d106a2f2f@222.126.44.162 [May 18 02:49:24] DEBUG[13691] chan_sip.c: Header 5 [ 16]: CSeq: 102 INVITE [May 18 02:49:24] DEBUG[13691] chan_sip.c: Header 6 [ 38]: Server: Asterisk PBX SVN-trunk-r263069 [May 18 02:49:24] DEBUG[13691] chan_sip.c: Header 7 [ 81]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH [May 18 02:49:24] DEBUG[13691] chan_sip.c: Header 8 [ 26]: Supported: replaces, timer [May 18 02:49:24] DEBUG[13691] chan_sip.c: Header 9 [ 14]: Require: timer [May 18 02:49:24] DEBUG[13691] chan_sip.c: Header 10 [ 35]: Session-Expires: 1800;refresher=uas [May 18 02:49:24] DEBUG[13691] chan_sip.c: Header 11 [ 45]: Contact: [May 18 02:49:24] DEBUG[13691] chan_sip.c: Header 12 [ 29]: Content-Type: application/sdp [May 18 02:49:24] DEBUG[13691] chan_sip.c: Header 13 [ 19]: Content-Length: 373 [May 18 02:49:24] DEBUG[13691] chan_sip.c: Header 14 [ 0]: [May 18 02:49:24] DEBUG[13691] chan_sip.c: Body 0 [ 3]: v=0 [May 18 02:49:24] DEBUG[13691] chan_sip.c: Body 1 [ 51]: o=root 1851714331 1851714331 IN IP4 203.176.117.204 [May 18 02:49:24] DEBUG[13691] chan_sip.c: Body 2 [ 32]: s=Asterisk PBX SVN-trunk-r263069 [May 18 02:49:24] DEBUG[13691] chan_sip.c: Body 3 [ 24]: c=IN IP4 203.176.117.204 [May 18 02:49:24] DEBUG[13691] chan_sip.c: Body 4 [ 5]: t=0 0 [May 18 02:49:24] DEBUG[13691] chan_sip.c: Body 5 [ 34]: m=audio 17860 RTP/AVP 18 3 0 8 101 [May 18 02:49:24] DEBUG[13691] chan_sip.c: Body 6 [ 21]: a=rtpmap:18 G729/8000 [May 18 02:49:24] DEBUG[13691] chan_sip.c: Body 7 [ 19]: a=fmtp:18 annexb=no [May 18 02:49:24] DEBUG[13691] chan_sip.c: Body 8 [ 19]: a=rtpmap:3 GSM/8000 [May 18 02:49:24] DEBUG[13691] chan_sip.c: Body 9 [ 20]: a=rtpmap:0 PCMU/8000 [May 18 02:49:24] DEBUG[13691] chan_sip.c: Body 10 [ 20]: a=rtpmap:8 PCMA/8000 [May 18 02:49:24] DEBUG[13691] chan_sip.c: Body 11 [ 33]: a=rtpmap:101 telephone-event/8000 [May 18 02:49:24] DEBUG[13691] chan_sip.c: Body 12 [ 15]: a=fmtp:101 0-16 [May 18 02:49:24] DEBUG[13691] chan_sip.c: Body 13 [ 25]: a=silenceSupp:off - - - - [May 18 02:49:24] DEBUG[13691] chan_sip.c: Body 14 [ 10]: a=ptime:20 [May 18 02:49:24] DEBUG[13691] chan_sip.c: Body 15 [ 10]: a=sendrecv [May 18 02:49:24] VERBOSE[13691] chan_sip.c: --- (14 headers 16 lines) --- [May 18 02:49:24] DEBUG[13691] chan_sip.c: Acked pending invite 102 [May 18 02:49:24] DEBUG[13691] chan_sip.c: Stopping retransmission on '378d2667481a8be132bb047d106a2f2f@222.126.44.162' of Request 102: Match Found [May 18 02:49:24] DEBUG[13691] chan_sip.c: SIP response 200 to standard invite [May 18 02:49:24] DEBUG[13691] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED. [May 18 02:49:24] DEBUG[13691] chan_sip.c: Processing session-level SDP o=root 1851714331 1851714331 IN IP4 203.176.117.204... UNSUPPORTED. [May 18 02:49:24] DEBUG[13691] chan_sip.c: Processing session-level SDP s=Asterisk PBX SVN-trunk-r263069... UNSUPPORTED. [May 18 02:49:24] DEBUG[13691] chan_sip.c: Processing session-level SDP c=IN IP4 203.176.117.204... OK. [May 18 02:49:24] DEBUG[13691] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED. [May 18 02:49:24] VERBOSE[13691] chan_sip.c: Found RTP audio format 18 [May 18 02:49:24] DEBUG[13691] rtp_engine.c: Setting payload 18 based on m type on 0x741fcac [May 18 02:49:24] VERBOSE[13691] chan_sip.c: Found RTP audio format 3 [May 18 02:49:24] DEBUG[13691] rtp_engine.c: Setting payload 3 based on m type on 0x741fcac [May 18 02:49:24] VERBOSE[13691] chan_sip.c: Found RTP audio format 0 [May 18 02:49:24] DEBUG[13691] rtp_engine.c: Setting payload 0 based on m type on 0x741fcac [May 18 02:49:24] VERBOSE[13691] chan_sip.c: Found RTP audio format 8 [May 18 02:49:24] DEBUG[13691] rtp_engine.c: Setting payload 8 based on m type on 0x741fcac [May 18 02:49:24] VERBOSE[13691] chan_sip.c: Found RTP audio format 101 [May 18 02:49:24] DEBUG[13691] rtp_engine.c: Setting payload 101 based on m type on 0x741fcac [May 18 02:49:24] VERBOSE[13691] chan_sip.c: Found audio description format G729 for ID 18 [May 18 02:49:24] DEBUG[13691] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:18 G729/8000... OK. [May 18 02:49:24] DEBUG[13691] chan_sip.c: Processing media-level (audio) SDP a=fmtp:18 annexb=no... UNSUPPORTED. [May 18 02:49:24] VERBOSE[13691] chan_sip.c: Found audio description format GSM for ID 3 [May 18 02:49:24] DEBUG[13691] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:3 GSM/8000... OK. [May 18 02:49:24] VERBOSE[13691] chan_sip.c: Found audio description format PCMU for ID 0 [May 18 02:49:24] DEBUG[13691] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:0 PCMU/8000... OK. [May 18 02:49:24] VERBOSE[13691] chan_sip.c: Found audio description format PCMA for ID 8 [May 18 02:49:24] DEBUG[13691] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:8 PCMA/8000... OK. [May 18 02:49:24] VERBOSE[13691] chan_sip.c: Found audio description format telephone-event for ID 101 [May 18 02:49:24] DEBUG[13691] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK. [May 18 02:49:24] DEBUG[13691] chan_sip.c: Processing media-level (audio) SDP a=fmtp:101 0-16... UNSUPPORTED. [May 18 02:49:24] DEBUG[13691] chan_sip.c: Processing media-level (audio) SDP a=silenceSupp:off - - - -... UNSUPPORTED. [May 18 02:49:24] DEBUG[13691] chan_sip.c: Processing media-level (audio) SDP a=ptime:20... OK. [May 18 02:49:24] DEBUG[13691] chan_sip.c: Processing media-level (audio) SDP a=sendrecv... OK. [May 18 02:49:24] DEBUG[13691] rtp_engine.c: Incorporating payload 0 on 0x741fcac [May 18 02:49:24] DEBUG[13691] rtp_engine.c: Incorporating payload 3 on 0x741fcac [May 18 02:49:24] DEBUG[13691] rtp_engine.c: Incorporating payload 8 on 0x741fcac [May 18 02:49:24] DEBUG[13691] rtp_engine.c: Incorporating payload 18 on 0x741fcac [May 18 02:49:24] DEBUG[13691] rtp_engine.c: Incorporating payload 101 on 0x741fcac [May 18 02:49:24] VERBOSE[13691] chan_sip.c: Capabilities: us - 0x10e (gsm|ulaw|alaw|g729), peer - audio=0x10e (gsm|ulaw|alaw|g729)/video=0x0 (nothing)/text=0x0 (nothing), combined - 0x10e (gsm|ulaw|alaw|g729) [May 18 02:49:24] VERBOSE[13691] chan_sip.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|) [May 18 02:49:24] DEBUG[13691] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0xbad5f60' [May 18 02:49:24] VERBOSE[13691] chan_sip.c: Peer audio RTP is at port 203.176.117.204:17860 [May 18 02:49:24] DEBUG[13691] rtp_engine.c: Copying payload 0 from 0x741fcac to 0xbad5fb0 [May 18 02:49:24] DEBUG[13691] rtp_engine.c: Copying payload 3 from 0x741fcac to 0xbad5fb0 [May 18 02:49:24] DEBUG[13691] rtp_engine.c: Copying payload 8 from 0x741fcac to 0xbad5fb0 [May 18 02:49:24] DEBUG[13691] rtp_engine.c: Copying payload 18 from 0x741fcac to 0xbad5fb0 [May 18 02:49:24] DEBUG[13691] rtp_engine.c: Copying payload 101 from 0x741fcac to 0xbad5fb0 [May 18 02:49:24] DEBUG[13691] chan_sip.c: We're settling with these formats: 0x10e (gsm|ulaw|alaw|g729) [May 18 02:49:24] DEBUG[13691] chan_sip.c: We have an owner, now see if we need to change this call [May 18 02:49:24] DEBUG[13691] chan_sip.c: Oooh, we need to change our audio formats since our peer supports only 0x10e (gsm|ulaw|alaw|g729) and not 0x40 (slin) [May 18 02:49:24] DEBUG[13691] channel.c: Set channel SIP/gw-00000003 to read format slin [May 18 02:49:24] DEBUG[13691] channel.c: Set channel SIP/gw-00000003 to write format slin [May 18 02:49:24] DEBUG[13691] chan_sip.c: Updating call counter for outgoing call [May 18 02:49:24] DEBUG[13691] chan_sip.c: build_route: Contact hop: [May 18 02:49:24] VERBOSE[13691] chan_sip.c: list_route: hop: [May 18 02:49:24] DEBUG[13691] chan_sip.c: Session-Expires: 1800 [May 18 02:49:24] DEBUG[13691] chan_sip.c: Refresher: UAS [May 18 02:49:24] DEBUG[13691] chan_sip.c: Session timer started: 21 - 378d2667481a8be132bb047d106a2f2f@222.126.44.162 [May 18 02:49:24] DEBUG[13691] chan_sip.c: Strict routing enforced for session 378d2667481a8be132bb047d106a2f2f@222.126.44.162 [May 18 02:49:24] VERBOSE[13691] chan_sip.c: set_destination: Parsing for address/port to send to [May 18 02:49:24] VERBOSE[13691] chan_sip.c: set_destination: set destination to 203.176.117.204, port 5060 [May 18 02:49:24] VERBOSE[13691] chan_sip.c: Transmitting (no NAT) to 203.176.117.204:5060: ACK sip:66618005204433@203.176.117.204 SIP/2.0 Via: SIP/2.0/UDP 222.126.44.162:5060;branch=z9hG4bK29c16bf5 Max-Forwards: 70 From: "18005204433" ;tag=as63200337 To: ;tag=as1c6dd274 Contact: Call-ID: 378d2667481a8be132bb047d106a2f2f@222.126.44.162 CSeq: 102 ACK User-Agent: Asterisk PBX SVN-trunk-r263541 Content-Length: 0 --- [May 18 02:49:24] DEBUG[13691] chan_sip.c: Trying to put 'ACK sip:666' onto UDP socket destined for 203.176.117.204:5060 [May 18 02:49:24] VERBOSE[13719] app_dial.c: -- SIP/gw-00000003 answered Local/18005204433@outgoing-f001;2 [May 18 02:49:24] DEBUG[13662] devicestate.c: No provider found, checking channel drivers for SIP - gw [May 18 02:49:24] DEBUG[13662] chan_sip.c: Checking device state for peer gw [May 18 02:49:24] DEBUG[13662] devicestate.c: Changing state for SIP/gw - state 1 (Not in use) [May 18 02:49:24] DEBUG[13662] devicestate.c: device 'SIP/gw' state '1' [May 18 02:49:24] VERBOSE[13718] pbx.c: > Channel Local/18005204433@outgoing-f001;1 was answered. [May 18 02:49:24] DEBUG[13662] devicestate.c: No provider found, checking channel drivers for Local - 18005204433@outgoing [May 18 02:49:24] DEBUG[13697] app_queue.c: Device 'SIP/gw' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [May 18 02:49:24] DEBUG[13718] pbx.c: Launching 'Set' [May 18 02:49:24] DEBUG[13662] chan_local.c: Checking if extension 18005204433@outgoing exists (devicestate) [May 18 02:49:24] VERBOSE[13718] pbx.c: -- Executing [200@confroom:1] Set("Local/18005204433@outgoing-f001;1", "MEETME_EXIT_CONTEXT=confexit") in new stack [May 18 02:49:24] DEBUG[13662] devicestate.c: Changing state for Local/18005204433@outgoing - state 2 (In use) [May 18 02:49:24] DEBUG[13662] devicestate.c: device 'Local/18005204433@outgoing' state '2' [May 18 02:49:24] DEBUG[13718] pbx.c: Result of 'EXTEN' is '200' [May 18 02:49:24] DEBUG[13718] pbx.c: Launching 'Set' [May 18 02:49:24] DEBUG[13662] devicestate.c: No provider found, checking channel drivers for Local - 18005204433@outgoing [May 18 02:49:24] VERBOSE[13718] pbx.c: -- Executing [200@confroom:2] Set("Local/18005204433@outgoing-f001;1", "lastconfno=200") in new stack [May 18 02:49:24] DEBUG[13697] app_queue.c: Device 'Local/18005204433@outgoing' changed to state '2' (In use) but we don't care because they're not a member of any queue. [May 18 02:49:24] DEBUG[13662] chan_local.c: Checking if extension 18005204433@outgoing exists (devicestate) [May 18 02:49:24] DEBUG[13662] devicestate.c: Changing state for Local/18005204433@outgoing - state 2 (In use) [May 18 02:49:24] DEBUG[13718] pbx.c: Result of 'EXTEN' is '200' [May 18 02:49:24] DEBUG[13662] devicestate.c: device 'Local/18005204433@outgoing' state '2' [May 18 02:49:24] DEBUG[13718] pbx.c: Launching 'MeetMe' [May 18 02:49:24] VERBOSE[13718] pbx.c: -- Executing [200@confroom:3] MeetMe("Local/18005204433@outgoing-f001;1", "200,M(default)Fq") in new stack [May 18 02:49:24] DEBUG[13697] app_queue.c: Device 'Local/18005204433@outgoing' changed to state '2' (In use) but we don't care because they're not a member of any queue. [May 18 02:49:24] DEBUG[13718] app_meetme.c: The requested confno is '200'? [May 18 02:49:24] DEBUG[13718] app_meetme.c: Does conf 200 match 200? [May 18 02:49:24] DEBUG[13718] app_meetme.c: Placed channel Local/18005204433@outgoing-f001;1 in DAHDI conf 1023 [May 18 02:49:24] DEBUG[13719] features.c: bridge answer set, chan answer set [May 18 02:49:24] DEBUG[13719] res_rtp_asterisk.c: Setting the marker bit due to a source update [May 18 02:49:24] DEBUG[13719] channel.c: Got a FRAME_CONTROL (-1) frame on channel Local/18005204433@outgoing-f001;2 [May 18 02:49:24] DEBUG[13719] res_rtp_asterisk.c: Setting the marker bit due to a source update [May 18 02:49:24] DEBUG[13719] channel.c: Bridge stops bridging channels Local/18005204433@outgoing-f001;2 and SIP/gw-00000003 [May 18 02:49:24] DEBUG[13719] res_rtp_asterisk.c: Setting the marker bit due to a source update [May 18 02:49:24] DEBUG[13718] dsp.c: Setup tone 1100 Hz, 500 ms, block_size=160, hits_required=21 [May 18 02:49:24] DEBUG[13718] dsp.c: Setup tone 2100 Hz, 2600 ms, block_size=160, hits_required=116 [May 18 02:49:24] VERBOSE[13717] res_musiconhold.c: -- Stopped music on hold on SIP/100-00000002 [May 18 02:49:24] DEBUG[13717] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [May 18 02:49:24] DEBUG[13719] res_rtp_asterisk.c: Ooh, format changed from unknown to g729 [May 18 02:49:24] DEBUG[13719] res_rtp_asterisk.c: Created smoother: format: g729 ms: 20 len: 20 [May 18 02:49:24] DEBUG[13719] res_rtp_asterisk.c: Starting RTCP transmission on RTP instance '0xbad5f60' [May 18 02:49:29] DEBUG[13719] res_rtp_asterisk.c: Got RTCP report of 64 bytes [May 18 02:49:30] DEBUG[13717] res_rtp_asterisk.c: Got RTCP report of 32 bytes [May 18 02:49:34] DEBUG[13692] pbx_spool.c: Delaying retry since we're currently running '/var/spool/asterisk/outgoing/20059876714bf18fa038eed3.30516741.call' [May 18 02:49:34] DEBUG[13692] pbx_spool.c: Delaying retry since we're currently running '/var/spool/asterisk/outgoing/20059876714bf18fa038eed3.30516741.call' [May 18 02:49:34] DEBUG[13692] pbx_spool.c: Delaying retry since we're currently running '/var/spool/asterisk/outgoing/20059876714bf18fa038eed3.30516741.call' [May 18 02:49:34] DEBUG[13719] res_rtp_asterisk.c: Got RTCP report of 64 bytes [May 18 02:49:38] VERBOSE[13691] chan_sip.c: <--- SIP read from UDP:203.176.117.204:5060 ---> BYE sip:asterisk@222.126.44.162 SIP/2.0 Via: SIP/2.0/UDP 203.176.117.204:5060;branch=z9hG4bK18c935ab Max-Forwards: 70 From: ;tag=as1c6dd274 To: "18005204433" ;tag=as63200337 Call-ID: 378d2667481a8be132bb047d106a2f2f@222.126.44.162 CSeq: 102 BYE User-Agent: Asterisk PBX SVN-trunk-r263069 X-Asterisk-HangupCause: Normal Clearing X-Asterisk-HangupCauseCode: 16 Content-Length: 0 <-------------> [May 18 02:49:38] DEBUG[13691] chan_sip.c: Header 0 [ 39]: BYE sip:asterisk@222.126.44.162 SIP/2.0 [May 18 02:49:38] DEBUG[13691] chan_sip.c: Header 1 [ 60]: Via: SIP/2.0/UDP 203.176.117.204:5060;branch=z9hG4bK18c935ab [May 18 02:49:38] DEBUG[13691] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [May 18 02:49:38] DEBUG[13691] chan_sip.c: Header 3 [ 57]: From: ;tag=as1c6dd274 [May 18 02:49:38] DEBUG[13691] chan_sip.c: Header 4 [ 62]: To: "18005204433" ;tag=as63200337 [May 18 02:49:38] DEBUG[13691] chan_sip.c: Header 5 [ 56]: Call-ID: 378d2667481a8be132bb047d106a2f2f@222.126.44.162 [May 18 02:49:38] DEBUG[13691] chan_sip.c: Header 6 [ 13]: CSeq: 102 BYE [May 18 02:49:38] DEBUG[13691] chan_sip.c: Header 7 [ 42]: User-Agent: Asterisk PBX SVN-trunk-r263069 [May 18 02:49:38] DEBUG[13691] chan_sip.c: Header 8 [ 39]: X-Asterisk-HangupCause: Normal Clearing [May 18 02:49:38] DEBUG[13691] chan_sip.c: Header 9 [ 30]: X-Asterisk-HangupCauseCode: 16 [May 18 02:49:38] DEBUG[13691] chan_sip.c: Header 10 [ 17]: Content-Length: 0 [May 18 02:49:38] DEBUG[13691] chan_sip.c: Header 11 [ 0]: [May 18 02:49:38] VERBOSE[13691] chan_sip.c: --- (11 headers 0 lines) --- [May 18 02:49:38] DEBUG[13691] chan_sip.c: **** Received BYE (8) - Command in SIP BYE [May 18 02:49:38] DEBUG[13691] chan_sip.c: Initializing initreq for method BYE - callid 378d2667481a8be132bb047d106a2f2f@222.126.44.162 [May 18 02:49:38] VERBOSE[13691] chan_sip.c: Sending to 203.176.117.204 : 5060 (no NAT) [May 18 02:49:38] DEBUG[13691] chan_sip.c: Setting SIP_ALREADYGONE on dialog 378d2667481a8be132bb047d106a2f2f@222.126.44.162 [May 18 02:49:38] DEBUG[13691] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0xbad5f60' [May 18 02:49:38] DEBUG[13691] chan_sip.c: Session timer stopped: -1 - 378d2667481a8be132bb047d106a2f2f@222.126.44.162 [May 18 02:49:38] DEBUG[13691] chan_sip.c: Received bye, issuing owner hangup [May 18 02:49:38] VERBOSE[13691] chan_sip.c: <--- Transmitting (no NAT) to 203.176.117.204:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 203.176.117.204:5060;branch=z9hG4bK18c935ab;received=203.176.117.204 From: ;tag=as1c6dd274 To: "18005204433" ;tag=as63200337 Call-ID: 378d2667481a8be132bb047d106a2f2f@222.126.44.162 CSeq: 102 BYE Server: Asterisk PBX SVN-trunk-r263541 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Content-Length: 0 <------------> [May 18 02:49:38] DEBUG[13691] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 203.176.117.204:5060 [May 18 02:49:38] DEBUG[13719] channel.c: Didn't get a frame from channel: SIP/gw-00000003 [May 18 02:49:38] DEBUG[13719] channel.c: Bridge stops bridging channels Local/18005204433@outgoing-f001;2 and SIP/gw-00000003 [May 18 02:49:38] DEBUG[13719] pbx.c: Function result is '2010-05-18 02:49:04' [May 18 02:49:38] DEBUG[13719] pbx.c: Function result is '18005204433' [May 18 02:49:38] DEBUG[13719] pbx.c: Function result is 'outgoing' [May 18 02:49:38] DEBUG[13719] pbx.c: Function result is 'Local/18005204433@outgoing-f001;2' [May 18 02:49:38] DEBUG[13719] pbx.c: Function result is 'SIP/gw-00000003' [May 18 02:49:38] DEBUG[13719] pbx.c: Function result is 'Dial' [May 18 02:49:38] DEBUG[13719] pbx.c: Function result is 'Sip/gw/66618005204433,60' [May 18 02:49:38] DEBUG[13719] pbx.c: Function result is '34' [May 18 02:49:38] DEBUG[13719] pbx.c: Function result is '14' [May 18 02:49:38] DEBUG[13719] pbx.c: Function result is 'ANSWERED' [May 18 02:49:38] DEBUG[13719] pbx.c: Function result is 'DOCUMENTATION' [May 18 02:49:38] DEBUG[13719] pbx.c: Function result is '(null)' [May 18 02:49:38] DEBUG[13719] pbx.c: Function result is '1274122144.8' [May 18 02:49:38] DEBUG[13719] pbx.c: Function result is '(null)' [May 18 02:49:38] DEBUG[13719] pbx.c: Function result is '(null)' [May 18 02:49:38] DEBUG[13719] cdr_sqlite3_custom.c: About to log: INSERT INTO cdr (calldate,clid,dcontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,accountcode,uniqueid,userfield,test) VALUES ('2010-05-18 02:49:04','18005204433','outgoing','Local/18005204433@outgoing-f001;2','SIP/gw-00000003','Dial','Sip/gw/66618005204433,60','34','14','ANSWERED','DOCUMENTATION','','1274122144.8','','') [May 18 02:49:38] DEBUG[13718] app_meetme.c: Got unrecognized frame on channel Local/18005204433@outgoing-f001;1, f->frametype=4,f->subclass=20 [May 18 02:49:38] DEBUG[13719] channel.c: Hanging up channel 'SIP/gw-00000003' [May 18 02:49:38] DEBUG[13719] chan_sip.c: Hangup call SIP/gw-00000003, SIP callid 378d2667481a8be132bb047d106a2f2f@222.126.44.162 [May 18 02:49:38] DEBUG[13719] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0xbad5f60' [May 18 02:49:38] DEBUG[13662] devicestate.c: No provider found, checking channel drivers for SIP - gw [May 18 02:49:38] DEBUG[13662] chan_sip.c: Checking device state for peer gw [May 18 02:49:38] DEBUG[13662] devicestate.c: Changing state for SIP/gw - state 1 (Not in use) [May 18 02:49:38] DEBUG[13662] devicestate.c: device 'SIP/gw' state '1' [May 18 02:49:38] DEBUG[13719] app_dial.c: Exiting with DIALSTATUS=ANSWER. [May 18 02:49:38] DEBUG[13697] app_queue.c: Device 'SIP/gw' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [May 18 02:49:38] DEBUG[13719] pbx.c: Spawn extension (outgoing,18005204433,2) exited non-zero on 'Local/18005204433@outgoing-f001;2' [May 18 02:49:38] VERBOSE[13719] pbx.c: == Spawn extension (outgoing, 18005204433, 2) exited non-zero on 'Local/18005204433@outgoing-f001;2' [May 18 02:49:38] DEBUG[13719] channel.c: Soft-Hanging up channel 'Local/18005204433@outgoing-f001;2' [May 18 02:49:38] DEBUG[13719] channel.c: Hanging up channel 'Local/18005204433@outgoing-f001;2' [May 18 02:49:38] DEBUG[13662] devicestate.c: No provider found, checking channel drivers for Local - 18005204433@outgoing [May 18 02:49:38] DEBUG[13662] chan_local.c: Checking if extension 18005204433@outgoing exists (devicestate) [May 18 02:49:38] DEBUG[13662] devicestate.c: Changing state for Local/18005204433@outgoing - state 2 (In use) [May 18 02:49:38] DEBUG[13662] devicestate.c: device 'Local/18005204433@outgoing' state '2' [May 18 02:49:38] DEBUG[13718] pbx.c: Spawn extension (confroom,200,3) exited non-zero on 'Local/18005204433@outgoing-f001;1' [May 18 02:49:38] VERBOSE[13718] pbx.c: == Spawn extension (confroom, 200, 3) exited non-zero on 'Local/18005204433@outgoing-f001;1' [May 18 02:49:38] DEBUG[13718] channel.c: Soft-Hanging up channel 'Local/18005204433@outgoing-f001;1' [May 18 02:49:38] DEBUG[13697] app_queue.c: Device 'Local/18005204433@outgoing' changed to state '2' (In use) but we don't care because they're not a member of any queue. [May 18 02:49:38] DEBUG[13718] channel.c: Hanging up channel 'Local/18005204433@outgoing-f001;1' [May 18 02:49:38] DEBUG[13718] pbx.c: Function result is '2010-05-18 02:49:04' [May 18 02:49:38] DEBUG[13718] pbx.c: Function result is '(null)' [May 18 02:49:38] DEBUG[13718] pbx.c: Function result is 'confroom' [May 18 02:49:38] DEBUG[13718] pbx.c: Function result is 'Local/18005204433@outgoing-f001;1' [May 18 02:49:38] DEBUG[13718] pbx.c: Function result is '(null)' [May 18 02:49:38] DEBUG[13718] pbx.c: Function result is 'MeetMe' [May 18 02:49:38] DEBUG[13718] pbx.c: Function result is '200,M(default)Fq' [May 18 02:49:38] DEBUG[13718] pbx.c: Function result is '34' [May 18 02:49:38] DEBUG[13718] pbx.c: Function result is '14' [May 18 02:49:38] DEBUG[13718] pbx.c: Function result is 'ANSWERED' [May 18 02:49:38] DEBUG[13718] pbx.c: Function result is 'DOCUMENTATION' [May 18 02:49:38] DEBUG[13718] pbx.c: Function result is '(null)' [May 18 02:49:38] DEBUG[13718] pbx.c: Function result is '1274122144.7' [May 18 02:49:38] DEBUG[13718] pbx.c: Function result is '(null)' [May 18 02:49:38] DEBUG[13718] pbx.c: Function result is '(null)' [May 18 02:49:38] DEBUG[13718] cdr_sqlite3_custom.c: About to log: INSERT INTO cdr (calldate,clid,dcontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,accountcode,uniqueid,userfield,test) VALUES ('2010-05-18 02:49:04','','confroom','Local/18005204433@outgoing-f001;1','','MeetMe','200,M(default)Fq','34','14','ANSWERED','DOCUMENTATION','','1274122144.7','','') [May 18 02:49:38] DEBUG[13662] devicestate.c: No provider found, checking channel drivers for Local - 18005204433@outgoing [May 18 02:49:38] DEBUG[13662] chan_local.c: Checking if extension 18005204433@outgoing exists (devicestate) [May 18 02:49:38] DEBUG[13662] devicestate.c: Changing state for Local/18005204433@outgoing - state 1 (Not in use) [May 18 02:49:38] DEBUG[13662] devicestate.c: device 'Local/18005204433@outgoing' state '1' [May 18 02:49:38] NOTICE[13718] pbx_spool.c: Call completed to Local/18005204433@outgoing/n [May 18 02:49:38] DEBUG[13697] app_queue.c: Device 'Local/18005204433@outgoing' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [May 18 02:49:38] VERBOSE[13717] res_musiconhold.c: -- Started music on hold, class 'default', on SIP/100-00000002 [May 18 02:49:38] DEBUG[13717] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second [May 18 02:49:38] DEBUG[13717] res_musiconhold.c: SIP/100-00000002 Opened file 1 '/var/lib/asterisk/moh/fpm-world-mix' [May 18 02:49:39] DEBUG[13691] chan_sip.c: Destroying SIP dialog 378d2667481a8be132bb047d106a2f2f@222.126.44.162 [May 18 02:49:39] VERBOSE[13691] chan_sip.c: Really destroying SIP dialog '378d2667481a8be132bb047d106a2f2f@222.126.44.162' Method: BYE [May 18 02:49:39] DEBUG[13691] rtp_engine.c: Destroyed RTP instance '0xbad5f60' [May 18 02:49:40] DEBUG[13717] res_rtp_asterisk.c: Got RTCP report of 32 bytes [May 18 02:49:48] DEBUG[13717] res_rtp_asterisk.c: Got RTCP report of 32 bytes [May 18 02:49:49] WARNING[13692] pbx_spool.c: Unable to open /var/spool/asterisk/outgoing/20059876714bf18fa038eed3.30516741.call: No such file or directory, deleting [May 18 02:49:49] WARNING[13692] pbx_spool.c: Unable to open /var/spool/asterisk/outgoing/20059876714bf18fa038eed3.30516741.call: No such file or directory, deleting [May 18 02:49:49] WARNING[13692] pbx_spool.c: Unable to open /var/spool/asterisk/outgoing/20059876714bf18fa038eed3.30516741.call: No such file or directory, deleting [May 18 02:49:49] WARNING[13692] pbx_spool.c: Unable to open /var/spool/asterisk/outgoing/20059876714bf18fa038eed3.30516741.call: No such file or directory, deleting [May 18 02:49:53] VERBOSE[13720] pbx_spool.c: -- Attempting call on Local/18882461234@outgoing/n for 200@confroom:1 (Retry 1) [May 18 02:49:53] DEBUG[13721] pbx.c: Result of 'EXTEN' is '18882461234' [May 18 02:49:53] DEBUG[13721] pbx.c: Launching 'Set' [May 18 02:49:53] VERBOSE[13721] pbx.c: -- Executing [18882461234@outgoing:1] Set("Local/18882461234@outgoing-591b;2", "CALLERID(name)=18882461234") in new stack [May 18 02:49:53] DEBUG[13721] pbx.c: Result of 'EXTEN' is '18882461234' [May 18 02:49:53] DEBUG[13721] pbx.c: Launching 'Dial' [May 18 02:49:53] VERBOSE[13721] pbx.c: -- Executing [18882461234@outgoing:2] Dial("Local/18882461234@outgoing-591b;2", "Sip/gw/66618882461234,60") in new stack [May 18 02:49:53] DEBUG[13721] chan_sip.c: Asked to create a SIP channel with formats: 0x40 (slin) [May 18 02:49:53] DEBUG[13721] chan_sip.c: Allocating new SIP dialog for 11cb2a5333334e887d3f2d520e103e4b@127.0.0.1 - INVITE (No RTP) [May 18 02:49:53] DEBUG[13721] rtp_engine.c: Using engine 'asterisk' for RTP instance '0xb79035c8' [May 18 02:49:53] DEBUG[13721] res_rtp_asterisk.c: Allocated port 18768 for RTP instance '0xb79035c8' [May 18 02:49:53] DEBUG[13721] rtp_engine.c: RTP instance '0xb79035c8' is setup and ready to go [May 18 02:49:53] DEBUG[13721] res_rtp_asterisk.c: Setup RTCP on RTP instance '0xb79035c8' [May 18 02:49:53] DEBUG[13721] chan_sip.c: Setting NAT on RTP to Off [May 18 02:49:53] DEBUG[13721] chan_sip.c: OBPROXY: Not applying OBproxy to this call [May 18 02:49:53] DEBUG[13721] acl.c: Found IP address for this socket [May 18 02:49:53] DEBUG[13721] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 222.126.44.162:5060 [May 18 02:49:53] DEBUG[13721] frame.c: Could not find preferred codec - Going for the best codec [May 18 02:49:53] DEBUG[13721] chan_sip.c: *** Our native formats are 0x40 (slin) [May 18 02:49:53] DEBUG[13721] chan_sip.c: *** Joint capabilities are 0x40 (slin) [May 18 02:49:53] DEBUG[13721] chan_sip.c: *** Our capabilities are 0x10e (gsm|ulaw|alaw|g729) [May 18 02:49:53] DEBUG[13721] frame.c: Could not find preferred codec - Going for the best codec [May 18 02:49:53] DEBUG[13721] chan_sip.c: *** AST_CODEC_CHOOSE formats are 0x40 (slin) [May 18 02:49:53] DEBUG[13721] chan_sip.c: *** Our preferred formats from the incoming channel are 0x40 (slin) [May 18 02:49:53] DEBUG[13721] chan_sip.c: This channel will not be able to handle video. [May 18 02:49:53] DEBUG[13721] rtp_engine.c: Can't find native functions for channel 'Local/18882461234@outgoing-591b;2' [May 18 02:49:53] DEBUG[13721] rtp_engine.c: Seeded SDP of 'SIP/gw-00000004' with that of 'Local/18882461234@outgoing-591b;2' [May 18 02:49:53] DEBUG[13721] channel.c: Not copying variable DIALEDTIME. [May 18 02:49:53] DEBUG[13721] channel.c: Not copying variable ANSWEREDTIME. [May 18 02:49:53] DEBUG[13721] channel.c: Not copying variable DIALEDPEERNAME. [May 18 02:49:53] DEBUG[13721] channel.c: Not copying variable DIALEDPEERNUMBER. [May 18 02:49:53] DEBUG[13721] channel.c: Not copying variable DIALSTATUS. [May 18 02:49:53] DEBUG[13721] chan_sip.c: Outgoing Call for 66618882461234 [May 18 02:49:53] DEBUG[13721] chan_sip.c: Updating call counter for outgoing call [May 18 02:49:53] DEBUG[13721] chan_sip.c: ** Our capability: 0x10e (gsm|ulaw|alaw|g729) Video flag: False Text flag: False [May 18 02:49:53] DEBUG[13721] chan_sip.c: ** Our prefcodec: 0x40 (slin) [May 18 02:49:53] VERBOSE[13721] chan_sip.c: Audio is at 222.126.44.162 port 18768 [May 18 02:49:53] VERBOSE[13721] chan_sip.c: Adding codec 0x100 (g729) to SDP [May 18 02:49:53] VERBOSE[13721] chan_sip.c: Adding codec 0x2 (gsm) to SDP [May 18 02:49:53] VERBOSE[13721] chan_sip.c: Adding codec 0x4 (ulaw) to SDP [May 18 02:49:53] VERBOSE[13721] chan_sip.c: Adding codec 0x8 (alaw) to SDP [May 18 02:49:53] VERBOSE[13721] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP [May 18 02:49:53] DEBUG[13721] chan_sip.c: -- Done with adding codecs to SDP [May 18 02:49:53] DEBUG[13721] chan_sip.c: Done building SDP. Settling with this capability: 0x10e (gsm|ulaw|alaw|g729) [May 18 02:49:53] DEBUG[13721] chan_sip.c: Initializing initreq for method INVITE - callid 4d6ec7bb3370fde3725078d21c989632@222.126.44.162 [May 18 02:49:53] DEBUG[13721] chan_sip.c: Header 0 [ 49]: INVITE sip:66618882461234@203.176.117.204 SIP/2.0 [May 18 02:49:53] DEBUG[13721] chan_sip.c: Header 1 [ 59]: Via: SIP/2.0/UDP 222.126.44.162:5060;branch=z9hG4bK34b3b9c7 [May 18 02:49:53] DEBUG[13721] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [May 18 02:49:53] DEBUG[13721] chan_sip.c: Header 3 [ 64]: From: "18882461234" ;tag=as372298f9 [May 18 02:49:53] DEBUG[13721] chan_sip.c: Header 4 [ 40]: To: [May 18 02:49:53] DEBUG[13721] chan_sip.c: Header 5 [ 38]: Contact: [May 18 02:49:53] DEBUG[13721] chan_sip.c: Header 6 [ 56]: Call-ID: 4d6ec7bb3370fde3725078d21c989632@222.126.44.162 [May 18 02:49:53] DEBUG[13721] chan_sip.c: Header 7 [ 16]: CSeq: 102 INVITE [May 18 02:49:53] DEBUG[13721] chan_sip.c: Header 8 [ 42]: User-Agent: Asterisk PBX SVN-trunk-r263541 [May 18 02:49:53] DEBUG[13721] chan_sip.c: Header 9 [ 35]: Date: Mon, 17 May 2010 18:49:53 GMT [May 18 02:49:53] DEBUG[13721] chan_sip.c: Header 10 [ 81]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH [May 18 02:49:53] DEBUG[13721] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [May 18 02:49:53] DEBUG[13721] chan_sip.c: Header 12 [ 29]: Content-Type: application/sdp [May 18 02:49:53] DEBUG[13721] chan_sip.c: Header 13 [ 19]: Content-Length: 371 [May 18 02:49:53] DEBUG[13721] chan_sip.c: Header 14 [ 0]: [May 18 02:49:53] DEBUG[13721] chan_sip.c: Body 0 [ 3]: v=0 [May 18 02:49:53] DEBUG[13721] chan_sip.c: Body 1 [ 50]: o=root 1780940328 1780940328 IN IP4 222.126.44.162 [May 18 02:49:53] DEBUG[13721] chan_sip.c: Body 2 [ 32]: s=Asterisk PBX SVN-trunk-r263541 [May 18 02:49:53] DEBUG[13721] chan_sip.c: Body 3 [ 23]: c=IN IP4 222.126.44.162 [May 18 02:49:53] DEBUG[13721] chan_sip.c: Body 4 [ 5]: t=0 0 [May 18 02:49:53] DEBUG[13721] chan_sip.c: Body 5 [ 34]: m=audio 18768 RTP/AVP 18 3 0 8 101 [May 18 02:49:53] DEBUG[13721] chan_sip.c: Body 6 [ 21]: a=rtpmap:18 G729/8000 [May 18 02:49:53] DEBUG[13721] chan_sip.c: Body 7 [ 19]: a=fmtp:18 annexb=no [May 18 02:49:53] DEBUG[13721] chan_sip.c: Body 8 [ 19]: a=rtpmap:3 GSM/8000 [May 18 02:49:53] DEBUG[13721] chan_sip.c: Body 9 [ 20]: a=rtpmap:0 PCMU/8000 [May 18 02:49:53] DEBUG[13721] chan_sip.c: Body 10 [ 20]: a=rtpmap:8 PCMA/8000 [May 18 02:49:53] DEBUG[13721] chan_sip.c: Body 11 [ 33]: a=rtpmap:101 telephone-event/8000 [May 18 02:49:53] DEBUG[13721] chan_sip.c: Body 12 [ 15]: a=fmtp:101 0-16 [May 18 02:49:53] DEBUG[13721] chan_sip.c: Body 13 [ 25]: a=silenceSupp:off - - - - [May 18 02:49:53] DEBUG[13721] chan_sip.c: Body 14 [ 10]: a=ptime:20 [May 18 02:49:53] DEBUG[13721] chan_sip.c: Body 15 [ 10]: a=sendrecv [May 18 02:49:53] VERBOSE[13721] chan_sip.c: Reliably Transmitting (no NAT) to 203.176.117.204:5060: INVITE sip:66618882461234@203.176.117.204 SIP/2.0 Via: SIP/2.0/UDP 222.126.44.162:5060;branch=z9hG4bK34b3b9c7 Max-Forwards: 70 From: "18882461234" ;tag=as372298f9 To: Contact: Call-ID: 4d6ec7bb3370fde3725078d21c989632@222.126.44.162 CSeq: 102 INVITE User-Agent: Asterisk PBX SVN-trunk-r263541 Date: Mon, 17 May 2010 18:49:53 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Content-Type: application/sdp Content-Length: 371 v=0 o=root 1780940328 1780940328 IN IP4 222.126.44.162 s=Asterisk PBX SVN-trunk-r263541 c=IN IP4 222.126.44.162 t=0 0 m=audio 18768 RTP/AVP 18 3 0 8 101 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no 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 --- [May 18 02:49:53] DEBUG[13721] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #23 [May 18 02:49:53] DEBUG[13721] chan_sip.c: Trying to put 'INVITE sip:' onto UDP socket destined for 203.176.117.204:5060 [May 18 02:49:53] VERBOSE[13721] app_dial.c: -- Called gw/66618882461234 [May 18 02:49:53] VERBOSE[13691] chan_sip.c: <--- SIP read from UDP:203.176.117.204:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 222.126.44.162:5060;branch=z9hG4bK34b3b9c7;received=222.126.44.162 From: "18882461234" ;tag=as372298f9 To: Call-ID: 4d6ec7bb3370fde3725078d21c989632@222.126.44.162 CSeq: 102 INVITE Server: Asterisk PBX SVN-trunk-r263069 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Require: timer Session-Expires: 1800;refresher=uas Contact: Content-Length: 0 <-------------> [May 18 02:49:53] DEBUG[13691] chan_sip.c: Header 0 [ 18]: SIP/2.0 100 Trying [May 18 02:49:53] DEBUG[13691] chan_sip.c: Header 1 [ 83]: Via: SIP/2.0/UDP 222.126.44.162:5060;branch=z9hG4bK34b3b9c7;received=222.126.44.162 [May 18 02:49:53] DEBUG[13691] chan_sip.c: Header 2 [ 64]: From: "18882461234" ;tag=as372298f9 [May 18 02:49:53] DEBUG[13691] chan_sip.c: Header 3 [ 40]: To: [May 18 02:49:53] DEBUG[13691] chan_sip.c: Header 4 [ 56]: Call-ID: 4d6ec7bb3370fde3725078d21c989632@222.126.44.162 [May 18 02:49:53] DEBUG[13691] chan_sip.c: Header 5 [ 16]: CSeq: 102 INVITE [May 18 02:49:53] DEBUG[13691] chan_sip.c: Header 6 [ 38]: Server: Asterisk PBX SVN-trunk-r263069 [May 18 02:49:53] DEBUG[13691] chan_sip.c: Header 7 [ 81]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH [May 18 02:49:53] DEBUG[13691] chan_sip.c: Header 8 [ 26]: Supported: replaces, timer [May 18 02:49:53] DEBUG[13691] chan_sip.c: Header 9 [ 14]: Require: timer [May 18 02:49:53] DEBUG[13691] chan_sip.c: Header 10 [ 35]: Session-Expires: 1800;refresher=uas [May 18 02:49:53] DEBUG[13691] chan_sip.c: Header 11 [ 45]: Contact: [May 18 02:49:53] DEBUG[13691] chan_sip.c: Header 12 [ 17]: Content-Length: 0 [May 18 02:49:53] DEBUG[13691] chan_sip.c: Header 13 [ 0]: [May 18 02:49:53] VERBOSE[13691] chan_sip.c: --- (13 headers 0 lines) --- [May 18 02:49:53] DEBUG[13691] chan_sip.c: *** SIP TIMER: Cancelling retransmission #23 - INVITE (got response) [May 18 02:49:53] DEBUG[13691] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '4d6ec7bb3370fde3725078d21c989632@222.126.44.162' Request 102: Found [May 18 02:49:53] DEBUG[13691] chan_sip.c: SIP response 100 to standard invite [May 18 02:49:53] VERBOSE[13691] chan_sip.c: <--- SIP read from UDP:203.176.117.204:5060 ---> SIP/2.0 180 Ringing Via: SIP/2.0/UDP 222.126.44.162:5060;branch=z9hG4bK34b3b9c7;received=222.126.44.162 From: "18882461234" ;tag=as372298f9 To: ;tag=as622f6683 Call-ID: 4d6ec7bb3370fde3725078d21c989632@222.126.44.162 CSeq: 102 INVITE Server: Asterisk PBX SVN-trunk-r263069 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Require: timer Session-Expires: 1800;refresher=uas Contact: Content-Length: 0 <-------------> [May 18 02:49:53] DEBUG[13691] chan_sip.c: Header 0 [ 19]: SIP/2.0 180 Ringing [May 18 02:49:53] DEBUG[13691] chan_sip.c: Header 1 [ 83]: Via: SIP/2.0/UDP 222.126.44.162:5060;branch=z9hG4bK34b3b9c7;received=222.126.44.162 [May 18 02:49:53] DEBUG[13691] chan_sip.c: Header 2 [ 64]: From: "18882461234" ;tag=as372298f9 [May 18 02:49:53] DEBUG[13691] chan_sip.c: Header 3 [ 55]: To: ;tag=as622f6683 [May 18 02:49:53] DEBUG[13691] chan_sip.c: Header 4 [ 56]: Call-ID: 4d6ec7bb3370fde3725078d21c989632@222.126.44.162 [May 18 02:49:53] DEBUG[13691] chan_sip.c: Header 5 [ 16]: CSeq: 102 INVITE [May 18 02:49:53] DEBUG[13691] chan_sip.c: Header 6 [ 38]: Server: Asterisk PBX SVN-trunk-r263069 [May 18 02:49:53] DEBUG[13691] chan_sip.c: Header 7 [ 81]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH [May 18 02:49:53] DEBUG[13691] chan_sip.c: Header 8 [ 26]: Supported: replaces, timer [May 18 02:49:53] DEBUG[13691] chan_sip.c: Header 9 [ 14]: Require: timer [May 18 02:49:53] DEBUG[13691] chan_sip.c: Header 10 [ 35]: Session-Expires: 1800;refresher=uas [May 18 02:49:53] DEBUG[13691] chan_sip.c: Header 11 [ 45]: Contact: [May 18 02:49:53] DEBUG[13691] chan_sip.c: Header 12 [ 17]: Content-Length: 0 [May 18 02:49:53] DEBUG[13691] chan_sip.c: Header 13 [ 0]: [May 18 02:49:53] VERBOSE[13691] chan_sip.c: --- (13 headers 0 lines) --- [May 18 02:49:53] DEBUG[13691] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '4d6ec7bb3370fde3725078d21c989632@222.126.44.162' Request 102: Found [May 18 02:49:53] DEBUG[13691] chan_sip.c: SIP response 180 to standard invite [May 18 02:49:53] DEBUG[13662] devicestate.c: No provider found, checking channel drivers for SIP - gw [May 18 02:49:53] DEBUG[13662] chan_sip.c: Checking device state for peer gw [May 18 02:49:53] DEBUG[13662] devicestate.c: Changing state for SIP/gw - state 1 (Not in use) [May 18 02:49:53] DEBUG[13662] devicestate.c: device 'SIP/gw' state '1' [May 18 02:49:53] DEBUG[13697] app_queue.c: Device 'SIP/gw' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [May 18 02:49:53] VERBOSE[13721] app_dial.c: -- SIP/gw-00000004 is ringing [May 18 02:49:53] DEBUG[13662] devicestate.c: No provider found, checking channel drivers for Local - 18882461234@outgoing [May 18 02:49:53] DEBUG[13662] chan_local.c: Checking if extension 18882461234@outgoing exists (devicestate) [May 18 02:49:53] DEBUG[13662] devicestate.c: Changing state for Local/18882461234@outgoing - state 2 (In use) [May 18 02:49:53] DEBUG[13662] devicestate.c: device 'Local/18882461234@outgoing' state '2' [May 18 02:49:53] DEBUG[13697] app_queue.c: Device 'Local/18882461234@outgoing' changed to state '2' (In use) but we don't care because they're not a member of any queue. [May 18 02:49:55] DEBUG[13717] res_rtp_asterisk.c: Got RTCP report of 32 bytes [May 18 02:50:04] DEBUG[13717] res_rtp_asterisk.c: Got RTCP report of 32 bytes [May 18 02:50:08] DEBUG[13692] pbx_spool.c: Delaying retry since we're currently running '/var/spool/asterisk/outgoing/18596237264bf18fd17dcce3.55306058.call' [May 18 02:50:13] VERBOSE[13691] chan_sip.c: <--- SIP read from UDP:203.176.117.204:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 222.126.44.162:5060;branch=z9hG4bK34b3b9c7;received=222.126.44.162 From: "18882461234" ;tag=as372298f9 To: ;tag=as622f6683 Call-ID: 4d6ec7bb3370fde3725078d21c989632@222.126.44.162 CSeq: 102 INVITE Server: Asterisk PBX SVN-trunk-r263069 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Require: timer Session-Expires: 1800;refresher=uas Contact: Content-Type: application/sdp Content-Length: 371 v=0 o=root 288679306 288679306 IN IP4 203.176.117.204 s=Asterisk PBX SVN-trunk-r263069 c=IN IP4 203.176.117.204 t=0 0 m=audio 19642 RTP/AVP 18 3 0 8 101 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no 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 <-------------> [May 18 02:50:13] DEBUG[13691] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [May 18 02:50:13] DEBUG[13691] chan_sip.c: Header 1 [ 83]: Via: SIP/2.0/UDP 222.126.44.162:5060;branch=z9hG4bK34b3b9c7;received=222.126.44.162 [May 18 02:50:13] DEBUG[13691] chan_sip.c: Header 2 [ 64]: From: "18882461234" ;tag=as372298f9 [May 18 02:50:13] DEBUG[13691] chan_sip.c: Header 3 [ 55]: To: ;tag=as622f6683 [May 18 02:50:13] DEBUG[13691] chan_sip.c: Header 4 [ 56]: Call-ID: 4d6ec7bb3370fde3725078d21c989632@222.126.44.162 [May 18 02:50:13] DEBUG[13691] chan_sip.c: Header 5 [ 16]: CSeq: 102 INVITE [May 18 02:50:13] DEBUG[13691] chan_sip.c: Header 6 [ 38]: Server: Asterisk PBX SVN-trunk-r263069 [May 18 02:50:13] DEBUG[13691] chan_sip.c: Header 7 [ 81]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH [May 18 02:50:13] DEBUG[13691] chan_sip.c: Header 8 [ 26]: Supported: replaces, timer [May 18 02:50:13] DEBUG[13691] chan_sip.c: Header 9 [ 14]: Require: timer [May 18 02:50:13] DEBUG[13691] chan_sip.c: Header 10 [ 35]: Session-Expires: 1800;refresher=uas [May 18 02:50:13] DEBUG[13691] chan_sip.c: Header 11 [ 45]: Contact: [May 18 02:50:13] DEBUG[13691] chan_sip.c: Header 12 [ 29]: Content-Type: application/sdp [May 18 02:50:13] DEBUG[13691] chan_sip.c: Header 13 [ 19]: Content-Length: 371 [May 18 02:50:13] DEBUG[13691] chan_sip.c: Header 14 [ 0]: [May 18 02:50:13] DEBUG[13691] chan_sip.c: Body 0 [ 3]: v=0 [May 18 02:50:13] DEBUG[13691] chan_sip.c: Body 1 [ 49]: o=root 288679306 288679306 IN IP4 203.176.117.204 [May 18 02:50:13] DEBUG[13691] chan_sip.c: Body 2 [ 32]: s=Asterisk PBX SVN-trunk-r263069 [May 18 02:50:13] DEBUG[13691] chan_sip.c: Body 3 [ 24]: c=IN IP4 203.176.117.204 [May 18 02:50:13] DEBUG[13691] chan_sip.c: Body 4 [ 5]: t=0 0 [May 18 02:50:13] DEBUG[13691] chan_sip.c: Body 5 [ 34]: m=audio 19642 RTP/AVP 18 3 0 8 101 [May 18 02:50:13] DEBUG[13691] chan_sip.c: Body 6 [ 21]: a=rtpmap:18 G729/8000 [May 18 02:50:13] DEBUG[13691] chan_sip.c: Body 7 [ 19]: a=fmtp:18 annexb=no [May 18 02:50:13] DEBUG[13691] chan_sip.c: Body 8 [ 19]: a=rtpmap:3 GSM/8000 [May 18 02:50:13] DEBUG[13691] chan_sip.c: Body 9 [ 20]: a=rtpmap:0 PCMU/8000 [May 18 02:50:13] DEBUG[13691] chan_sip.c: Body 10 [ 20]: a=rtpmap:8 PCMA/8000 [May 18 02:50:13] DEBUG[13691] chan_sip.c: Body 11 [ 33]: a=rtpmap:101 telephone-event/8000 [May 18 02:50:13] DEBUG[13691] chan_sip.c: Body 12 [ 15]: a=fmtp:101 0-16 [May 18 02:50:13] DEBUG[13691] chan_sip.c: Body 13 [ 25]: a=silenceSupp:off - - - - [May 18 02:50:13] DEBUG[13691] chan_sip.c: Body 14 [ 10]: a=ptime:20 [May 18 02:50:13] DEBUG[13691] chan_sip.c: Body 15 [ 10]: a=sendrecv [May 18 02:50:13] VERBOSE[13691] chan_sip.c: --- (14 headers 16 lines) --- [May 18 02:50:13] DEBUG[13691] chan_sip.c: Acked pending invite 102 [May 18 02:50:13] DEBUG[13691] chan_sip.c: Stopping retransmission on '4d6ec7bb3370fde3725078d21c989632@222.126.44.162' of Request 102: Match Found [May 18 02:50:13] DEBUG[13691] chan_sip.c: SIP response 200 to standard invite [May 18 02:50:13] DEBUG[13691] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED. [May 18 02:50:13] DEBUG[13691] chan_sip.c: Processing session-level SDP o=root 288679306 288679306 IN IP4 203.176.117.204... UNSUPPORTED. [May 18 02:50:13] DEBUG[13691] chan_sip.c: Processing session-level SDP s=Asterisk PBX SVN-trunk-r263069... UNSUPPORTED. [May 18 02:50:13] DEBUG[13691] chan_sip.c: Processing session-level SDP c=IN IP4 203.176.117.204... OK. [May 18 02:50:13] DEBUG[13691] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED. [May 18 02:50:13] VERBOSE[13691] chan_sip.c: Found RTP audio format 18 [May 18 02:50:13] DEBUG[13691] rtp_engine.c: Setting payload 18 based on m type on 0x741fcac [May 18 02:50:13] VERBOSE[13691] chan_sip.c: Found RTP audio format 3 [May 18 02:50:13] DEBUG[13691] rtp_engine.c: Setting payload 3 based on m type on 0x741fcac [May 18 02:50:13] VERBOSE[13691] chan_sip.c: Found RTP audio format 0 [May 18 02:50:13] DEBUG[13691] rtp_engine.c: Setting payload 0 based on m type on 0x741fcac [May 18 02:50:13] VERBOSE[13691] chan_sip.c: Found RTP audio format 8 [May 18 02:50:13] DEBUG[13691] rtp_engine.c: Setting payload 8 based on m type on 0x741fcac [May 18 02:50:13] VERBOSE[13691] chan_sip.c: Found RTP audio format 101 [May 18 02:50:13] DEBUG[13691] rtp_engine.c: Setting payload 101 based on m type on 0x741fcac [May 18 02:50:13] VERBOSE[13691] chan_sip.c: Found audio description format G729 for ID 18 [May 18 02:50:13] DEBUG[13691] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:18 G729/8000... OK. [May 18 02:50:13] DEBUG[13691] chan_sip.c: Processing media-level (audio) SDP a=fmtp:18 annexb=no... UNSUPPORTED. [May 18 02:50:13] VERBOSE[13691] chan_sip.c: Found audio description format GSM for ID 3 [May 18 02:50:13] DEBUG[13691] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:3 GSM/8000... OK. [May 18 02:50:13] VERBOSE[13691] chan_sip.c: Found audio description format PCMU for ID 0 [May 18 02:50:13] DEBUG[13691] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:0 PCMU/8000... OK. [May 18 02:50:13] VERBOSE[13691] chan_sip.c: Found audio description format PCMA for ID 8 [May 18 02:50:13] DEBUG[13691] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:8 PCMA/8000... OK. [May 18 02:50:13] VERBOSE[13691] chan_sip.c: Found audio description format telephone-event for ID 101 [May 18 02:50:13] DEBUG[13691] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK. [May 18 02:50:13] DEBUG[13691] chan_sip.c: Processing media-level (audio) SDP a=fmtp:101 0-16... UNSUPPORTED. [May 18 02:50:13] DEBUG[13691] chan_sip.c: Processing media-level (audio) SDP a=silenceSupp:off - - - -... UNSUPPORTED. [May 18 02:50:13] DEBUG[13691] chan_sip.c: Processing media-level (audio) SDP a=ptime:20... OK. [May 18 02:50:13] DEBUG[13691] chan_sip.c: Processing media-level (audio) SDP a=sendrecv... OK. [May 18 02:50:13] DEBUG[13691] rtp_engine.c: Incorporating payload 0 on 0x741fcac [May 18 02:50:13] DEBUG[13691] rtp_engine.c: Incorporating payload 3 on 0x741fcac [May 18 02:50:13] DEBUG[13691] rtp_engine.c: Incorporating payload 8 on 0x741fcac [May 18 02:50:13] DEBUG[13691] rtp_engine.c: Incorporating payload 18 on 0x741fcac [May 18 02:50:13] DEBUG[13691] rtp_engine.c: Incorporating payload 101 on 0x741fcac [May 18 02:50:13] VERBOSE[13691] chan_sip.c: Capabilities: us - 0x10e (gsm|ulaw|alaw|g729), peer - audio=0x10e (gsm|ulaw|alaw|g729)/video=0x0 (nothing)/text=0x0 (nothing), combined - 0x10e (gsm|ulaw|alaw|g729) [May 18 02:50:13] VERBOSE[13691] chan_sip.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|) [May 18 02:50:13] DEBUG[13691] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0xb79035c8' [May 18 02:50:13] VERBOSE[13691] chan_sip.c: Peer audio RTP is at port 203.176.117.204:19642 [May 18 02:50:13] DEBUG[13691] rtp_engine.c: Copying payload 0 from 0x741fcac to 0xb7903618 [May 18 02:50:13] DEBUG[13691] rtp_engine.c: Copying payload 3 from 0x741fcac to 0xb7903618 [May 18 02:50:13] DEBUG[13691] rtp_engine.c: Copying payload 8 from 0x741fcac to 0xb7903618 [May 18 02:50:13] DEBUG[13691] rtp_engine.c: Copying payload 18 from 0x741fcac to 0xb7903618 [May 18 02:50:13] DEBUG[13691] rtp_engine.c: Copying payload 101 from 0x741fcac to 0xb7903618 [May 18 02:50:13] DEBUG[13691] chan_sip.c: We're settling with these formats: 0x10e (gsm|ulaw|alaw|g729) [May 18 02:50:13] DEBUG[13691] chan_sip.c: We have an owner, now see if we need to change this call [May 18 02:50:13] DEBUG[13691] chan_sip.c: Oooh, we need to change our audio formats since our peer supports only 0x10e (gsm|ulaw|alaw|g729) and not 0x40 (slin) [May 18 02:50:13] DEBUG[13691] channel.c: Set channel SIP/gw-00000004 to read format slin [May 18 02:50:13] DEBUG[13691] channel.c: Set channel SIP/gw-00000004 to write format slin [May 18 02:50:13] DEBUG[13691] chan_sip.c: Updating call counter for outgoing call [May 18 02:50:13] DEBUG[13691] chan_sip.c: build_route: Contact hop: [May 18 02:50:13] VERBOSE[13691] chan_sip.c: list_route: hop: [May 18 02:50:13] DEBUG[13691] chan_sip.c: Session-Expires: 1800 [May 18 02:50:13] DEBUG[13691] chan_sip.c: Refresher: UAS [May 18 02:50:13] DEBUG[13691] chan_sip.c: Session timer started: 25 - 4d6ec7bb3370fde3725078d21c989632@222.126.44.162 [May 18 02:50:13] DEBUG[13691] chan_sip.c: Strict routing enforced for session 4d6ec7bb3370fde3725078d21c989632@222.126.44.162 [May 18 02:50:13] VERBOSE[13691] chan_sip.c: set_destination: Parsing for address/port to send to [May 18 02:50:13] VERBOSE[13691] chan_sip.c: set_destination: set destination to 203.176.117.204, port 5060 [May 18 02:50:13] VERBOSE[13691] chan_sip.c: Transmitting (no NAT) to 203.176.117.204:5060: ACK sip:66618882461234@203.176.117.204 SIP/2.0 Via: SIP/2.0/UDP 222.126.44.162:5060;branch=z9hG4bK0304f0c9 Max-Forwards: 70 From: "18882461234" ;tag=as372298f9 To: ;tag=as622f6683 Contact: Call-ID: 4d6ec7bb3370fde3725078d21c989632@222.126.44.162 CSeq: 102 ACK User-Agent: Asterisk PBX SVN-trunk-r263541 Content-Length: 0 --- [May 18 02:50:13] DEBUG[13691] chan_sip.c: Trying to put 'ACK sip:666' onto UDP socket destined for 203.176.117.204:5060 [May 18 02:50:13] VERBOSE[13721] app_dial.c: -- SIP/gw-00000004 answered Local/18882461234@outgoing-591b;2 [May 18 02:50:13] DEBUG[13662] devicestate.c: No provider found, checking channel drivers for SIP - gw [May 18 02:50:13] DEBUG[13662] chan_sip.c: Checking device state for peer gw [May 18 02:50:13] DEBUG[13662] devicestate.c: Changing state for SIP/gw - state 1 (Not in use) [May 18 02:50:13] DEBUG[13662] devicestate.c: device 'SIP/gw' state '1' [May 18 02:50:13] DEBUG[13662] devicestate.c: No provider found, checking channel drivers for Local - 18882461234@outgoing [May 18 02:50:13] DEBUG[13662] chan_local.c: Checking if extension 18882461234@outgoing exists (devicestate) [May 18 02:50:13] DEBUG[13662] devicestate.c: Changing state for Local/18882461234@outgoing - state 2 (In use) [May 18 02:50:13] VERBOSE[13720] pbx.c: > Channel Local/18882461234@outgoing-591b;1 was answered. [May 18 02:50:13] DEBUG[13697] app_queue.c: Device 'SIP/gw' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [May 18 02:50:13] DEBUG[13721] features.c: bridge answer set, chan answer set [May 18 02:50:13] DEBUG[13721] res_rtp_asterisk.c: Setting the marker bit due to a source update [May 18 02:50:13] DEBUG[13720] pbx.c: Launching 'Set' [May 18 02:50:13] VERBOSE[13720] pbx.c: -- Executing [200@confroom:1] Set("Local/18882461234@outgoing-591b;1", "MEETME_EXIT_CONTEXT=confexit") in new stack [May 18 02:50:13] DEBUG[13720] pbx.c: Result of 'EXTEN' is '200' [May 18 02:50:13] DEBUG[13720] pbx.c: Launching 'Set' [May 18 02:50:13] VERBOSE[13720] pbx.c: -- Executing [200@confroom:2] Set("Local/18882461234@outgoing-591b;1", "lastconfno=200") in new stack [May 18 02:50:13] DEBUG[13720] pbx.c: Result of 'EXTEN' is '200' [May 18 02:50:13] DEBUG[13720] pbx.c: Launching 'MeetMe' [May 18 02:50:13] VERBOSE[13720] pbx.c: -- Executing [200@confroom:3] MeetMe("Local/18882461234@outgoing-591b;1", "200,M(default)Fq") in new stack [May 18 02:50:13] DEBUG[13720] app_meetme.c: The requested confno is '200'? [May 18 02:50:13] DEBUG[13662] devicestate.c: device 'Local/18882461234@outgoing' state '2' [May 18 02:50:13] DEBUG[13720] app_meetme.c: Does conf 200 match 200? [May 18 02:50:13] DEBUG[13662] devicestate.c: No provider found, checking channel drivers for Local - 18882461234@outgoing [May 18 02:50:13] DEBUG[13697] app_queue.c: Device 'Local/18882461234@outgoing' changed to state '2' (In use) but we don't care because they're not a member of any queue. [May 18 02:50:13] DEBUG[13662] chan_local.c: Checking if extension 18882461234@outgoing exists (devicestate) [May 18 02:50:13] DEBUG[13662] devicestate.c: Changing state for Local/18882461234@outgoing - state 2 (In use) [May 18 02:50:13] DEBUG[13662] devicestate.c: device 'Local/18882461234@outgoing' state '2' [May 18 02:50:13] DEBUG[13721] channel.c: Got a FRAME_CONTROL (-1) frame on channel Local/18882461234@outgoing-591b;2 [May 18 02:50:13] DEBUG[13697] app_queue.c: Device 'Local/18882461234@outgoing' changed to state '2' (In use) but we don't care because they're not a member of any queue. [May 18 02:50:13] DEBUG[13721] res_rtp_asterisk.c: Setting the marker bit due to a source update [May 18 02:50:13] DEBUG[13721] channel.c: Bridge stops bridging channels Local/18882461234@outgoing-591b;2 and SIP/gw-00000004 [May 18 02:50:13] DEBUG[13720] app_meetme.c: Placed channel Local/18882461234@outgoing-591b;1 in DAHDI conf 1023 [May 18 02:50:13] DEBUG[13721] res_rtp_asterisk.c: Setting the marker bit due to a source update [May 18 02:50:13] DEBUG[13720] dsp.c: Setup tone 1100 Hz, 500 ms, block_size=160, hits_required=21 [May 18 02:50:13] DEBUG[13720] dsp.c: Setup tone 2100 Hz, 2600 ms, block_size=160, hits_required=116 [May 18 02:50:13] VERBOSE[13717] res_musiconhold.c: -- Stopped music on hold on SIP/100-00000002 [May 18 02:50:13] DEBUG[13717] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [May 18 02:50:13] DEBUG[13721] res_rtp_asterisk.c: Ooh, format changed from unknown to g729 [May 18 02:50:13] DEBUG[13721] res_rtp_asterisk.c: Created smoother: format: g729 ms: 20 len: 20 [May 18 02:50:13] DEBUG[13721] res_rtp_asterisk.c: Starting RTCP transmission on RTP instance '0xb79035c8' [May 18 02:50:14] DEBUG[13717] res_rtp_asterisk.c: Got RTCP report of 32 bytes [May 18 02:50:19] DEBUG[13721] res_rtp_asterisk.c: Got RTCP report of 64 bytes [May 18 02:50:23] DEBUG[13717] res_rtp_asterisk.c: Got RTCP report of 32 bytes [May 18 02:50:23] DEBUG[13692] pbx_spool.c: Delaying retry since we're currently running '/var/spool/asterisk/outgoing/18596237264bf18fd17dcce3.55306058.call' [May 18 02:50:23] DEBUG[13692] pbx_spool.c: Delaying retry since we're currently running '/var/spool/asterisk/outgoing/18596237264bf18fd17dcce3.55306058.call' [May 18 02:50:23] DEBUG[13692] pbx_spool.c: Delaying retry since we're currently running '/var/spool/asterisk/outgoing/18596237264bf18fd17dcce3.55306058.call' [May 18 02:50:24] DEBUG[13721] res_rtp_asterisk.c: Got RTCP report of 64 bytes [May 18 02:50:24] VERBOSE[13691] chan_sip.c: <--- SIP read from UDP:58.69.37.108:60672 ---> <-------------> [May 18 02:50:24] DEBUG[13691] chan_sip.c: Header 0 [ 0]: [May 18 02:50:27] VERBOSE[13691] chan_sip.c: <--- SIP read from UDP:203.176.117.204:5060 ---> BYE sip:asterisk@222.126.44.162 SIP/2.0 Via: SIP/2.0/UDP 203.176.117.204:5060;branch=z9hG4bK34029b68 Max-Forwards: 70 From: ;tag=as622f6683 To: "18882461234" ;tag=as372298f9 Call-ID: 4d6ec7bb3370fde3725078d21c989632@222.126.44.162 CSeq: 102 BYE User-Agent: Asterisk PBX SVN-trunk-r263069 X-Asterisk-HangupCause: Normal Clearing X-Asterisk-HangupCauseCode: 16 Content-Length: 0 <-------------> [May 18 02:50:27] DEBUG[13691] chan_sip.c: Header 0 [ 39]: BYE sip:asterisk@222.126.44.162 SIP/2.0 [May 18 02:50:27] DEBUG[13691] chan_sip.c: Header 1 [ 60]: Via: SIP/2.0/UDP 203.176.117.204:5060;branch=z9hG4bK34029b68 [May 18 02:50:27] DEBUG[13691] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [May 18 02:50:27] DEBUG[13691] chan_sip.c: Header 3 [ 57]: From: ;tag=as622f6683 [May 18 02:50:27] DEBUG[13691] chan_sip.c: Header 4 [ 62]: To: "18882461234" ;tag=as372298f9 [May 18 02:50:27] DEBUG[13691] chan_sip.c: Header 5 [ 56]: Call-ID: 4d6ec7bb3370fde3725078d21c989632@222.126.44.162 [May 18 02:50:27] DEBUG[13691] chan_sip.c: Header 6 [ 13]: CSeq: 102 BYE [May 18 02:50:27] DEBUG[13691] chan_sip.c: Header 7 [ 42]: User-Agent: Asterisk PBX SVN-trunk-r263069 [May 18 02:50:27] DEBUG[13691] chan_sip.c: Header 8 [ 39]: X-Asterisk-HangupCause: Normal Clearing [May 18 02:50:27] DEBUG[13691] chan_sip.c: Header 9 [ 30]: X-Asterisk-HangupCauseCode: 16 [May 18 02:50:27] DEBUG[13691] chan_sip.c: Header 10 [ 17]: Content-Length: 0 [May 18 02:50:27] DEBUG[13691] chan_sip.c: Header 11 [ 0]: [May 18 02:50:27] VERBOSE[13691] chan_sip.c: --- (11 headers 0 lines) --- [May 18 02:50:27] DEBUG[13691] chan_sip.c: **** Received BYE (8) - Command in SIP BYE [May 18 02:50:27] DEBUG[13691] chan_sip.c: Initializing initreq for method BYE - callid 4d6ec7bb3370fde3725078d21c989632@222.126.44.162 [May 18 02:50:27] VERBOSE[13691] chan_sip.c: Sending to 203.176.117.204 : 5060 (no NAT) [May 18 02:50:27] DEBUG[13691] chan_sip.c: Setting SIP_ALREADYGONE on dialog 4d6ec7bb3370fde3725078d21c989632@222.126.44.162 [May 18 02:50:27] DEBUG[13691] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0xb79035c8' [May 18 02:50:27] DEBUG[13691] chan_sip.c: Session timer stopped: -1 - 4d6ec7bb3370fde3725078d21c989632@222.126.44.162 [May 18 02:50:27] DEBUG[13691] chan_sip.c: Received bye, issuing owner hangup [May 18 02:50:27] VERBOSE[13691] chan_sip.c: <--- Transmitting (no NAT) to 203.176.117.204:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 203.176.117.204:5060;branch=z9hG4bK34029b68;received=203.176.117.204 From: ;tag=as622f6683 To: "18882461234" ;tag=as372298f9 Call-ID: 4d6ec7bb3370fde3725078d21c989632@222.126.44.162 CSeq: 102 BYE Server: Asterisk PBX SVN-trunk-r263541 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Content-Length: 0 <------------> [May 18 02:50:27] DEBUG[13691] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 203.176.117.204:5060 [May 18 02:50:27] DEBUG[13721] channel.c: Didn't get a frame from channel: SIP/gw-00000004 [May 18 02:50:27] DEBUG[13721] channel.c: Bridge stops bridging channels Local/18882461234@outgoing-591b;2 and SIP/gw-00000004 [May 18 02:50:27] DEBUG[13721] pbx.c: Function result is '2010-05-18 02:49:53' [May 18 02:50:27] DEBUG[13721] pbx.c: Function result is '18882461234' [May 18 02:50:27] DEBUG[13721] pbx.c: Function result is 'outgoing' [May 18 02:50:27] DEBUG[13721] pbx.c: Function result is 'Local/18882461234@outgoing-591b;2' [May 18 02:50:27] DEBUG[13721] pbx.c: Function result is 'SIP/gw-00000004' [May 18 02:50:27] DEBUG[13721] pbx.c: Function result is 'Dial' [May 18 02:50:27] DEBUG[13721] pbx.c: Function result is 'Sip/gw/66618882461234,60' [May 18 02:50:27] DEBUG[13721] pbx.c: Function result is '34' [May 18 02:50:27] DEBUG[13721] pbx.c: Function result is '14' [May 18 02:50:27] DEBUG[13721] pbx.c: Function result is 'ANSWERED' [May 18 02:50:27] DEBUG[13721] pbx.c: Function result is 'DOCUMENTATION' [May 18 02:50:27] DEBUG[13721] pbx.c: Function result is '(null)' [May 18 02:50:27] DEBUG[13721] pbx.c: Function result is '1274122193.11' [May 18 02:50:27] DEBUG[13721] pbx.c: Function result is '(null)' [May 18 02:50:27] DEBUG[13721] pbx.c: Function result is '(null)' [May 18 02:50:27] DEBUG[13721] cdr_sqlite3_custom.c: About to log: INSERT INTO cdr (calldate,clid,dcontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,accountcode,uniqueid,userfield,test) VALUES ('2010-05-18 02:49:53','18882461234','outgoing','Local/18882461234@outgoing-591b;2','SIP/gw-00000004','Dial','Sip/gw/66618882461234,60','34','14','ANSWERED','DOCUMENTATION','','1274122193.11','','') [May 18 02:50:27] DEBUG[13720] app_meetme.c: Got unrecognized frame on channel Local/18882461234@outgoing-591b;1, f->frametype=4,f->subclass=20 [May 18 02:50:27] DEBUG[13721] channel.c: Hanging up channel 'SIP/gw-00000004' [May 18 02:50:27] DEBUG[13721] chan_sip.c: Hangup call SIP/gw-00000004, SIP callid 4d6ec7bb3370fde3725078d21c989632@222.126.44.162 [May 18 02:50:27] DEBUG[13721] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0xb79035c8' [May 18 02:50:27] DEBUG[13662] devicestate.c: No provider found, checking channel drivers for SIP - gw [May 18 02:50:27] DEBUG[13662] chan_sip.c: Checking device state for peer gw [May 18 02:50:27] DEBUG[13662] devicestate.c: Changing state for SIP/gw - state 1 (Not in use) [May 18 02:50:27] DEBUG[13662] devicestate.c: device 'SIP/gw' state '1' [May 18 02:50:27] DEBUG[13721] app_dial.c: Exiting with DIALSTATUS=ANSWER. [May 18 02:50:27] DEBUG[13721] pbx.c: Spawn extension (outgoing,18882461234,2) exited non-zero on 'Local/18882461234@outgoing-591b;2' [May 18 02:50:27] DEBUG[13697] app_queue.c: Device 'SIP/gw' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [May 18 02:50:27] VERBOSE[13721] pbx.c: == Spawn extension (outgoing, 18882461234, 2) exited non-zero on 'Local/18882461234@outgoing-591b;2' [May 18 02:50:27] DEBUG[13721] channel.c: Soft-Hanging up channel 'Local/18882461234@outgoing-591b;2' [May 18 02:50:27] DEBUG[13721] channel.c: Hanging up channel 'Local/18882461234@outgoing-591b;2' [May 18 02:50:27] DEBUG[13662] devicestate.c: No provider found, checking channel drivers for Local - 18882461234@outgoing [May 18 02:50:27] DEBUG[13720] pbx.c: Spawn extension (confroom,200,3) exited non-zero on 'Local/18882461234@outgoing-591b;1' [May 18 02:50:27] DEBUG[13662] chan_local.c: Checking if extension 18882461234@outgoing exists (devicestate) [May 18 02:50:27] VERBOSE[13720] pbx.c: == Spawn extension (confroom, 200, 3) exited non-zero on 'Local/18882461234@outgoing-591b;1' [May 18 02:50:27] DEBUG[13720] channel.c: Soft-Hanging up channel 'Local/18882461234@outgoing-591b;1' [May 18 02:50:27] DEBUG[13662] devicestate.c: Changing state for Local/18882461234@outgoing - state 2 (In use) [May 18 02:50:27] DEBUG[13720] channel.c: Hanging up channel 'Local/18882461234@outgoing-591b;1' [May 18 02:50:27] DEBUG[13662] devicestate.c: device 'Local/18882461234@outgoing' state '2' [May 18 02:50:27] DEBUG[13697] app_queue.c: Device 'Local/18882461234@outgoing' changed to state '2' (In use) but we don't care because they're not a member of any queue. [May 18 02:50:27] DEBUG[13720] pbx.c: Function result is '2010-05-18 02:49:53' [May 18 02:50:27] DEBUG[13720] pbx.c: Function result is '(null)' [May 18 02:50:27] DEBUG[13720] pbx.c: Function result is 'confroom' [May 18 02:50:27] DEBUG[13720] pbx.c: Function result is 'Local/18882461234@outgoing-591b;1' [May 18 02:50:27] DEBUG[13720] pbx.c: Function result is '(null)' [May 18 02:50:27] DEBUG[13720] pbx.c: Function result is 'MeetMe' [May 18 02:50:27] DEBUG[13720] pbx.c: Function result is '200,M(default)Fq' [May 18 02:50:27] DEBUG[13720] pbx.c: Function result is '34' [May 18 02:50:27] DEBUG[13720] pbx.c: Function result is '14' [May 18 02:50:27] DEBUG[13720] pbx.c: Function result is 'ANSWERED' [May 18 02:50:27] DEBUG[13720] pbx.c: Function result is 'DOCUMENTATION' [May 18 02:50:27] DEBUG[13720] pbx.c: Function result is '(null)' [May 18 02:50:27] DEBUG[13720] pbx.c: Function result is '1274122193.10' [May 18 02:50:27] DEBUG[13720] pbx.c: Function result is '(null)' [May 18 02:50:27] DEBUG[13720] pbx.c: Function result is '(null)' [May 18 02:50:27] DEBUG[13720] cdr_sqlite3_custom.c: About to log: INSERT INTO cdr (calldate,clid,dcontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,accountcode,uniqueid,userfield,test) VALUES ('2010-05-18 02:49:53','','confroom','Local/18882461234@outgoing-591b;1','','MeetMe','200,M(default)Fq','34','14','ANSWERED','DOCUMENTATION','','1274122193.10','','') [May 18 02:50:27] DEBUG[13662] devicestate.c: No provider found, checking channel drivers for Local - 18882461234@outgoing [May 18 02:50:27] DEBUG[13662] chan_local.c: Checking if extension 18882461234@outgoing exists (devicestate) [May 18 02:50:27] DEBUG[13662] devicestate.c: Changing state for Local/18882461234@outgoing - state 1 (Not in use) [May 18 02:50:27] DEBUG[13662] devicestate.c: device 'Local/18882461234@outgoing' state '1' [May 18 02:50:27] NOTICE[13720] pbx_spool.c: Call completed to Local/18882461234@outgoing/n [May 18 02:50:27] DEBUG[13697] app_queue.c: Device 'Local/18882461234@outgoing' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [May 18 02:50:27] VERBOSE[13717] res_musiconhold.c: -- Started music on hold, class 'default', on SIP/100-00000002 [May 18 02:50:27] DEBUG[13717] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second [May 18 02:50:27] DEBUG[13717] res_musiconhold.c: SIP/100-00000002 Opened file 1 '/var/lib/asterisk/moh/fpm-world-mix' [May 18 02:50:28] DEBUG[13691] chan_sip.c: Destroying SIP dialog 4d6ec7bb3370fde3725078d21c989632@222.126.44.162 [May 18 02:50:28] VERBOSE[13691] chan_sip.c: Really destroying SIP dialog '4d6ec7bb3370fde3725078d21c989632@222.126.44.162' Method: BYE [May 18 02:50:28] DEBUG[13691] rtp_engine.c: Destroyed RTP instance '0xb79035c8' [May 18 02:50:28] VERBOSE[13691] chan_sip.c: <--- SIP read from UDP:203.176.117.204:5060 ---> BYE sip:asterisk@222.126.44.162 SIP/2.0 Via: SIP/2.0/UDP 203.176.117.204:5060;branch=z9hG4bK34029b68 Max-Forwards: 70 From: ;tag=as622f6683 To: "18882461234" ;tag=as372298f9 Call-ID: 4d6ec7bb3370fde3725078d21c989632@222.126.44.162 CSeq: 102 BYE User-Agent: Asterisk PBX SVN-trunk-r263069 X-Asterisk-HangupCause: Normal Clearing X-Asterisk-HangupCauseCode: 16 Content-Length: 0 <-------------> [May 18 02:50:28] DEBUG[13691] chan_sip.c: Header 0 [ 39]: BYE sip:asterisk@222.126.44.162 SIP/2.0 [May 18 02:50:28] DEBUG[13691] chan_sip.c: Header 1 [ 60]: Via: SIP/2.0/UDP 203.176.117.204:5060;branch=z9hG4bK34029b68 [May 18 02:50:28] DEBUG[13691] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [May 18 02:50:28] DEBUG[13691] chan_sip.c: Header 3 [ 57]: From: ;tag=as622f6683 [May 18 02:50:28] DEBUG[13691] chan_sip.c: Header 4 [ 62]: To: "18882461234" ;tag=as372298f9 [May 18 02:50:28] DEBUG[13691] chan_sip.c: Header 5 [ 56]: Call-ID: 4d6ec7bb3370fde3725078d21c989632@222.126.44.162 [May 18 02:50:28] DEBUG[13691] chan_sip.c: Header 6 [ 13]: CSeq: 102 BYE [May 18 02:50:28] DEBUG[13691] chan_sip.c: Header 7 [ 42]: User-Agent: Asterisk PBX SVN-trunk-r263069 [May 18 02:50:28] DEBUG[13691] chan_sip.c: Header 8 [ 39]: X-Asterisk-HangupCause: Normal Clearing [May 18 02:50:28] DEBUG[13691] chan_sip.c: Header 9 [ 30]: X-Asterisk-HangupCauseCode: 16 [May 18 02:50:28] DEBUG[13691] chan_sip.c: Header 10 [ 17]: Content-Length: 0 [May 18 02:50:28] DEBUG[13691] chan_sip.c: Header 11 [ 0]: [May 18 02:50:28] VERBOSE[13691] chan_sip.c: --- (11 headers 0 lines) --- [May 18 02:50:28] DEBUG[13691] acl.c: Found IP address for this socket [May 18 02:50:28] DEBUG[13691] chan_sip.c: Setting SIP_TRANSPORT_UNKNOWN with address 222.126.44.162:5060 [May 18 02:50:28] VERBOSE[13691] chan_sip.c: <--- Transmitting (no NAT) to 203.176.117.204:5060 ---> SIP/2.0 481 Call leg/transaction does not exist Via: SIP/2.0/UDP 203.176.117.204:5060;branch=z9hG4bK34029b68;received=203.176.117.204 From: ;tag=as622f6683 To: "18882461234" ;tag=as372298f9 Call-ID: 4d6ec7bb3370fde3725078d21c989632@222.126.44.162 CSeq: 102 BYE Server: Asterisk PBX SVN-trunk-r263541 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Content-Length: 0 <------------> [May 18 02:50:28] DEBUG[13691] chan_sip.c: Trying to put 'SIP/2.0 481' onto UDP socket destined for 203.176.117.204:5060 [May 18 02:50:28] DEBUG[13691] chan_sip.c: That's odd... Got a request in unknown dialog. Callid 4d6ec7bb3370fde3725078d21c989632@222.126.44.162 [May 18 02:50:28] DEBUG[13691] chan_sip.c: Invalid SIP message - rejected , no callid, len 455 [May 18 02:50:30] DEBUG[13717] res_rtp_asterisk.c: Got RTCP report of 32 bytes [May 18 02:50:36] DEBUG[13717] res_rtp_asterisk.c: Got RTCP report of 32 bytes [May 18 02:50:38] WARNING[13692] pbx_spool.c: Unable to open /var/spool/asterisk/outgoing/18596237264bf18fd17dcce3.55306058.call: No such file or directory, deleting [May 18 02:50:38] WARNING[13692] pbx_spool.c: Unable to open /var/spool/asterisk/outgoing/18596237264bf18fd17dcce3.55306058.call: No such file or directory, deleting [May 18 02:50:38] WARNING[13692] pbx_spool.c: Unable to open /var/spool/asterisk/outgoing/18596237264bf18fd17dcce3.55306058.call: No such file or directory, deleting [May 18 02:50:38] WARNING[13692] pbx_spool.c: Unable to open /var/spool/asterisk/outgoing/18596237264bf18fd17dcce3.55306058.call: No such file or directory, deleting [May 18 02:50:42] VERBOSE[13691] chan_sip.c: <--- SIP read from UDP:58.69.37.108:60672 ---> BYE sip:200@222.126.44.162 SIP/2.0 To: ;tag=as06bb4b7f From: Agent Orange;tag=d167d863 Via: SIP/2.0/UDP 58.69.37.108:60672;branch=z9hG4bK-d87543-257758362-1--d87543-;rport Call-ID: 97338c5bd438343b CSeq: 3 BYE Contact: Max-Forwards: 70 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO User-Agent: eyeBeam release 3004w stamp 16863 Authorization: Digest username="100",realm="asterisk",nonce="48294513",uri="sip:200@222.126.44.162",response="2a5a7a1ac7f3ee0427c491705479a318",algorithm=MD5 Content-Length: 0 <-------------> [May 18 02:50:42] VERBOSE[13691] chan_sip.c: --- (12 headers 0 lines) --- [May 18 02:50:42] VERBOSE[13691] chan_sip.c: Sending to 58.69.37.108 : 60672 (NAT) [May 18 02:50:42] VERBOSE[13691] chan_sip.c: <--- Transmitting (NAT) to 58.69.37.108:60672 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 58.69.37.108:60672;branch=z9hG4bK-d87543-257758362-1--d87543-;received=58.69.37.108;rport=60672 From: Agent Orange;tag=d167d863 To: ;tag=as06bb4b7f Call-ID: 97338c5bd438343b CSeq: 3 BYE Server: Asterisk PBX SVN-trunk-r263541 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Content-Length: 0 <------------> [May 18 02:50:43] VERBOSE[13691] chan_sip.c: Really destroying SIP dialog '97338c5bd438343b' Method: BYE [May 18 02:50:49] VERBOSE[13691] chan_sip.c: <--- SIP read from UDP:58.69.37.108:60672 ---> INVITE sip:quit@222.126.44.162 SIP/2.0 To: From: Agent Orange;tag=6210032f Via: SIP/2.0/UDP 58.69.37.108:60672;branch=z9hG4bK-d87543-233849801-1--d87543-;rport Call-ID: 632b4101d94fb143 CSeq: 1 INVITE Contact: Max-Forwards: 70 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO Content-Type: application/sdp User-Agent: eyeBeam release 3004w stamp 16863 Content-Length: 321 v=0 o=- 22112770 22113128 IN IP4 58.69.37.108 s=eyeBeam c=IN IP4 58.69.37.108 t=0 0 m=audio 60675 RTP/AVP 18 3 0 101 a=alt:1 1 : 9B22F006 0399AFD1 58.69.37.108 60675 58.69.37.108 60928 a=alt:2 3 : A17E9205 9FF1E673 192.168.2.254 10592 a=fmtp:101 0-15 a=rtcp:60928 a=rtpmap:101 telephone-event/8000 a=sendrecv <-------------> [May 18 02:50:49] VERBOSE[13691] chan_sip.c: --- (12 headers 12 lines) --- [May 18 02:50:49] VERBOSE[13691] chan_sip.c: Sending to 58.69.37.108 : 60672 (no NAT) [May 18 02:50:49] VERBOSE[13691] chan_sip.c: Using INVITE request as basis request - 632b4101d94fb143 [May 18 02:50:49] VERBOSE[13691] chan_sip.c: Found peer '100' for '100' from 58.69.37.108:60672 [May 18 02:50:49] VERBOSE[13691] chan_sip.c: <--- Reliably Transmitting (NAT) to 58.69.37.108:60672 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 58.69.37.108:60672;branch=z9hG4bK-d87543-233849801-1--d87543-;received=58.69.37.108;rport=60672 From: Agent Orange;tag=6210032f To: ;tag=as6fd75038 Call-ID: 632b4101d94fb143 CSeq: 1 INVITE Server: Asterisk PBX SVN-trunk-r263541 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="65b02825" Content-Length: 0 <------------> [May 18 02:50:49] VERBOSE[13691] chan_sip.c: Scheduling destruction of SIP dialog '632b4101d94fb143' in 32000 ms (Method: INVITE) [May 18 02:50:49] VERBOSE[13691] chan_sip.c: <--- SIP read from UDP:58.69.37.108:60672 ---> ACK sip:quit@222.126.44.162 SIP/2.0 To: ;tag=as6fd75038 From: Agent Orange;tag=6210032f Via: SIP/2.0/UDP 58.69.37.108:60672;branch=z9hG4bK-d87543-233849801-1--d87543-;rport Call-ID: 632b4101d94fb143 CSeq: 1 ACK Content-Length: 0 <-------------> [May 18 02:50:49] VERBOSE[13691] chan_sip.c: --- (7 headers 0 lines) --- [May 18 02:50:49] VERBOSE[13691] chan_sip.c: <--- SIP read from UDP:58.69.37.108:60672 ---> INVITE sip:quit@222.126.44.162 SIP/2.0 To: From: Agent Orange;tag=6210032f Via: SIP/2.0/UDP 58.69.37.108:60672;branch=z9hG4bK-d87543-339035877-1--d87543-;rport Call-ID: 632b4101d94fb143 CSeq: 2 INVITE Contact: Max-Forwards: 70 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO Content-Type: application/sdp User-Agent: eyeBeam release 3004w stamp 16863 Authorization: Digest username="100",realm="asterisk",nonce="65b02825",uri="sip:quit@222.126.44.162",response="45d48febc043e0514c384e162d64a08e",algorithm=MD5 Content-Length: 321 v=0 o=- 22112770 22113128 IN IP4 58.69.37.108 s=eyeBeam c=IN IP4 58.69.37.108 t=0 0 m=audio 60675 RTP/AVP 18 3 0 101 a=alt:1 1 : 9B22F006 0399AFD1 58.69.37.108 60675 58.69.37.108 60928 a=alt:2 3 : A17E9205 9FF1E673 192.168.2.254 10592 a=fmtp:101 0-15 a=rtcp:60928 a=rtpmap:101 telephone-event/8000 a=sendrecv <-------------> [May 18 02:50:49] VERBOSE[13691] chan_sip.c: --- (13 headers 12 lines) --- [May 18 02:50:49] VERBOSE[13691] chan_sip.c: Sending to 58.69.37.108 : 60672 (NAT) [May 18 02:50:49] VERBOSE[13691] chan_sip.c: Using INVITE request as basis request - 632b4101d94fb143 [May 18 02:50:49] VERBOSE[13691] chan_sip.c: Found peer '100' for '100' from 58.69.37.108:60672 [May 18 02:50:49] VERBOSE[13691] chan_sip.c: Found RTP audio format 18 [May 18 02:50:49] VERBOSE[13691] chan_sip.c: Found RTP audio format 3 [May 18 02:50:49] VERBOSE[13691] chan_sip.c: Found RTP audio format 0 [May 18 02:50:49] VERBOSE[13691] chan_sip.c: Found RTP audio format 101 [May 18 02:50:49] VERBOSE[13691] chan_sip.c: Found audio description format telephone-event for ID 101 [May 18 02:50:49] VERBOSE[13691] chan_sip.c: Capabilities: us - 0x100 (g729), peer - audio=0x106 (gsm|ulaw|g729)/video=0x0 (nothing)/text=0x0 (nothing), combined - 0x100 (g729) [May 18 02:50:49] VERBOSE[13691] chan_sip.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|) [May 18 02:50:49] VERBOSE[13691] chan_sip.c: Peer audio RTP is at port 58.69.37.108:60675 [May 18 02:50:49] VERBOSE[13691] chan_sip.c: Looking for quit in internal (domain 222.126.44.162) [May 18 02:50:49] VERBOSE[13691] chan_sip.c: <--- Reliably Transmitting (NAT) to 58.69.37.108:60672 ---> SIP/2.0 404 Not Found Via: SIP/2.0/UDP 58.69.37.108:60672;branch=z9hG4bK-d87543-339035877-1--d87543-;received=58.69.37.108;rport=60672 From: Agent Orange;tag=6210032f To: ;tag=as6fd75038 Call-ID: 632b4101d94fb143 CSeq: 2 INVITE Server: Asterisk PBX SVN-trunk-r263541 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Content-Length: 0 <------------> [May 18 02:50:49] NOTICE[13691] chan_sip.c: Call from '100' to extension 'quit' rejected because extension not found in context 'internal'. [May 18 02:50:49] VERBOSE[13691] chan_sip.c: Scheduling destruction of SIP dialog '632b4101d94fb143' in 32000 ms (Method: INVITE) [May 18 02:50:49] VERBOSE[13691] chan_sip.c: <--- SIP read from UDP:58.69.37.108:60672 ---> ACK sip:quit@222.126.44.162 SIP/2.0 To: ;tag=as6fd75038 From: Agent Orange;tag=6210032f Via: SIP/2.0/UDP 58.69.37.108:60672;branch=z9hG4bK-d87543-339035877-1--d87543-;rport Call-ID: 632b4101d94fb143 CSeq: 2 ACK Content-Length: 0 <-------------> [May 18 02:50:49] VERBOSE[13691] chan_sip.c: --- (7 headers 0 lines) --- [May 18 02:51:21] VERBOSE[13691] chan_sip.c: Really destroying SIP dialog '632b4101d94fb143' Method: ACK [May 18 02:52:00] VERBOSE[13691] chan_sip.c: <--- SIP read from UDP:58.69.37.108:60672 ---> <------------->