[Aug 9 11:45:09] VERBOSE[32296] config.c: == Parsing '/etc/asterisk/logger.conf': [Aug 9 11:45:09] DEBUG[32296] config.c: Parsing /etc/asterisk/logger.conf [Aug 9 11:45:09] VERBOSE[32296] config.c: == Found [Aug 9 11:45:09] VERBOSE[32296] logger.c: Asterisk Queue Logger restarted [Aug 9 11:45:14] VERBOSE[31464] chan_sip.c: <--- SIP read from UDP:10.13.22.38:5060 ---> INVITE sip:99764701@10.21.0.146:5061 SIP/2.0 From: "6000";tag=8824b0-26160d0a-13c4-50029-386e927a-488246b-386e927a To: Call-ID: 888f10-26160d0a-13c4-50029-386e927a-3b57bcf5-386e927a CSeq: 1 INVITE Via: SIP/2.0/UDP 10.13.22.38:5060;rport;branch=z9hG4bK-386e927a-6fec2fa9-988218 Max-Forwards: 70 Supported: replaces,100rel User-Agent: AUDC-IPPhone/1.2.1_build_6 (320HD;00908F1ED22E) Allow: REGISTER, INVITE, ACK, BYE, REFER, NOTIFY, CANCEL, INFO, OPTIONS, PRACK, SUBSCRIBE Contact: Content-Type: application/sdp Content-Length: 399 v=0 o=6000 946771323 946771323 IN IP4 10.13.22.38 s=- c=IN IP4 10.13.22.38 t=0 0 m=audio 4000 RTP/AVP 9 0 8 18 4 101 a=rtpmap:9 G722/8000 a=ptime:20 a=rtpmap:0 PCMU/8000 a=ptime:20 a=rtpmap:8 PCMA/8000 a=ptime:20 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=ptime:20 a=rtpmap:4 g723/8000 a=fmtp:4 annexa=no a=ptime:30 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=sendrecv <-------------> [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Header 0 [ 44]: INVITE sip:99764701@10.21.0.146:5061 SIP/2.0 [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Header 1 [ 91]: From: "6000";tag=8824b0-26160d0a-13c4-50029-386e927a-488246b-386e927a [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Header 2 [ 35]: To: [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Header 3 [ 62]: Call-ID: 888f10-26160d0a-13c4-50029-386e927a-3b57bcf5-386e927a [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Header 4 [ 14]: CSeq: 1 INVITE [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Header 5 [ 79]: Via: SIP/2.0/UDP 10.13.22.38:5060;rport;branch=z9hG4bK-386e927a-6fec2fa9-988218 [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Header 6 [ 16]: Max-Forwards: 70 [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Header 7 [ 26]: Supported: replaces,100rel [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Header 8 [ 59]: User-Agent: AUDC-IPPhone/1.2.1_build_6 (320HD;00908F1ED22E) [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Header 9 [ 89]: Allow: REGISTER, INVITE, ACK, BYE, REFER, NOTIFY, CANCEL, INFO, OPTIONS, PRACK, SUBSCRIBE [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Header 10 [ 31]: Contact: [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Header 11 [ 29]: Content-Type: application/sdp [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Header 12 [ 19]: Content-Length: 399 [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Header 13 [ 0]: [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Body 0 [ 3]: v=0 [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Body 1 [ 45]: o=6000 946771323 946771323 IN IP4 10.13.22.38 [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Body 2 [ 3]: s=- [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Body 3 [ 20]: c=IN IP4 10.13.22.38 [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Body 4 [ 5]: t=0 0 [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Body 5 [ 35]: m=audio 4000 RTP/AVP 9 0 8 18 4 101 [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Body 6 [ 20]: a=rtpmap:9 G722/8000 [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Body 7 [ 10]: a=ptime:20 [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Body 8 [ 20]: a=rtpmap:0 PCMU/8000 [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Body 9 [ 10]: a=ptime:20 [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Body 10 [ 20]: a=rtpmap:8 PCMA/8000 [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Body 11 [ 10]: a=ptime:20 [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Body 12 [ 21]: a=rtpmap:18 G729/8000 [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Body 13 [ 19]: a=fmtp:18 annexb=no [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Body 14 [ 10]: a=ptime:20 [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Body 15 [ 20]: a=rtpmap:4 g723/8000 [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Body 16 [ 18]: a=fmtp:4 annexa=no [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Body 17 [ 10]: a=ptime:30 [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Body 18 [ 33]: a=rtpmap:101 telephone-event/8000 [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Body 19 [ 15]: a=fmtp:101 0-15 [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Body 20 [ 10]: a=sendrecv [Aug 9 11:45:14] VERBOSE[31464] chan_sip.c: --- (13 headers 21 lines) --- [Aug 9 11:45:14] DEBUG[31464] acl.c: For destination '10.13.22.38', our source address is '10.21.0.146'. [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 10.21.0.146:5061 [Aug 9 11:45:14] VERBOSE[31464] netsock.c: == Using UDPTL CoS mark 5 [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Setting NAT on UDPTL to Off [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Allocating new SIP dialog for 888f10-26160d0a-13c4-50029-386e927a-3b57bcf5-386e927a - INVITE (No RTP) [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE [Aug 9 11:45:14] DEBUG[31464] sip/reqresp_parser.c: Begin: parsing SIP "Supported: replaces,100rel" [Aug 9 11:45:14] DEBUG[31464] sip/reqresp_parser.c: Found SIP option: -replaces- [Aug 9 11:45:14] DEBUG[31464] sip/reqresp_parser.c: Matched SIP option: replaces [Aug 9 11:45:14] DEBUG[31464] sip/reqresp_parser.c: Found SIP option: -100rel- [Aug 9 11:45:14] DEBUG[31464] sip/reqresp_parser.c: Matched SIP option: 100rel [Aug 9 11:45:14] DEBUG[31464] netsock2.c: Splitting '10.13.22.38:5060' gives... [Aug 9 11:45:14] DEBUG[31464] netsock2.c: ...host '10.13.22.38' and port '5060'. [Aug 9 11:45:14] VERBOSE[31464] chan_sip.c: Sending to 10.13.22.38:5060 (no NAT) [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Initializing initreq for method INVITE - callid 888f10-26160d0a-13c4-50029-386e927a-3b57bcf5-386e927a [Aug 9 11:45:14] VERBOSE[31464] chan_sip.c: Using INVITE request as basis request - 888f10-26160d0a-13c4-50029-386e927a-3b57bcf5-386e927a [Aug 9 11:45:14] DEBUG[31464] res_config_pgsql.c: PostgreSQL RealTime: One or more of the parameters in the config does not pass our validity checks. [Aug 9 11:45:14] DEBUG[31464] res_config_pgsql.c: PostgreSQL RealTime: Result=0xa2a7028 Query: SELECT * FROM sip_buddies WHERE name = '6000' AND host = 'dynamic' [Aug 9 11:45:14] DEBUG[31464] res_config_pgsql.c: Postgresql RealTime: Could not find any rows in table sip_buddies@asterisk. [Aug 9 11:45:14] DEBUG[31464] res_config_pgsql.c: PostgreSQL RealTime: One or more of the parameters in the config does not pass our validity checks. [Aug 9 11:45:14] DEBUG[31464] res_config_pgsql.c: PostgreSQL RealTime: Result=0x9c76328 Query: SELECT * FROM sip_buddies WHERE name = '6000' [Aug 9 11:45:14] DEBUG[31464] res_config_pgsql.c: PostgreSQL RealTime: Found 1 rows. [Aug 9 11:45:14] DEBUG[31464] netsock2.c: Splitting '10.13.22.38' gives... [Aug 9 11:45:14] DEBUG[31464] netsock2.c: ...host '10.13.22.38' and port '(null)'. [Aug 9 11:45:14] DEBUG[31464] netsock2.c: Splitting '10.13.22.38:5060' gives... [Aug 9 11:45:14] DEBUG[31464] netsock2.c: ...host '10.13.22.38' and port '5060'. [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Not an IPv4 nor IPv6 address, cannot get port. [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Not an IPv4 nor IPv6 address, cannot set port. [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Allocating new SIP dialog for 501dfa4a062508ba324806132006270f@127.0.0.1:0 - NOTIFY (No RTP) [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: OBPROXY: Not applying OBproxy to this call [Aug 9 11:45:14] DEBUG[31464] acl.c: For destination '10.13.22.38', our source address is '10.21.0.146'. [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 10.21.0.146:5061 [Aug 9 11:45:14] VERBOSE[31464] chan_sip.c: Scheduling destruction of SIP dialog '5a6687507e097d4d789b40d63bbe0a28@10.21.0.146:5061' in 32000 ms (Method: NOTIFY) [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Initializing initreq for method NOTIFY - callid 5a6687507e097d4d789b40d63bbe0a28@10.21.0.146:5061 [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Header 0 [ 40]: NOTIFY sip:6000@10.13.22.38:5060 SIP/2.0 [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Header 1 [ 56]: Via: SIP/2.0/UDP 10.21.0.146:5061;branch=z9hG4bK1a6305c3 [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Header 3 [ 63]: From: "asterisk" ;tag=as6a6fd911 [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Header 4 [ 31]: To: [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Header 5 [ 40]: Contact: [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Header 6 [ 58]: Call-ID: 5a6687507e097d4d789b40d63bbe0a28@10.21.0.146:5061 [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Header 7 [ 16]: CSeq: 102 NOTIFY [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Header 8 [ 36]: User-Agent: Asterisk PBX 1.8.0-beta2 [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Header 9 [ 22]: Event: message-summary [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Header 10 [ 48]: Content-Type: application/simple-message-summary [Aug 9 11:45:14] VERBOSE[31464] chan_sip.c: Reliably Transmitting (no NAT) to 10.13.22.38:5060: NOTIFY sip:6000@10.13.22.38:5060 SIP/2.0 Via: SIP/2.0/UDP 10.21.0.146:5061;branch=z9hG4bK1a6305c3 Max-Forwards: 70 From: "asterisk" ;tag=as6a6fd911 To: Contact: Call-ID: 5a6687507e097d4d789b40d63bbe0a28@10.21.0.146:5061 CSeq: 102 NOTIFY User-Agent: Asterisk PBX 1.8.0-beta2 Event: message-summary Content-Type: application/simple-message-summary Content-Length: 97 Messages-Waiting: no Message-Account: sip:6000@10.21.0.146:5061:5061 Voice-Message: 0/0 (0/0) --- [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #4934 [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Trying to put 'NOTIFY sip:' onto UDP socket destined for 10.13.22.38:5060 [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: -REALTIME- loading peer from database to memory. Name: 6000. Peer objects: -552 [Aug 9 11:45:14] VERBOSE[31464] chan_sip.c: Found peer '6000' for '6000' from 10.13.22.38:5060 [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Setting NAT on UDPTL to Off [Aug 9 11:45:14] VERBOSE[31464] chan_sip.c: <--- Reliably Transmitting (no NAT) to 10.13.22.38:5060 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 10.13.22.38:5060;branch=z9hG4bK-386e927a-6fec2fa9-988218;received=10.13.22.38;rport=5060 From: "6000";tag=8824b0-26160d0a-13c4-50029-386e927a-488246b-386e927a To: ;tag=as490cc93c Call-ID: 888f10-26160d0a-13c4-50029-386e927a-3b57bcf5-386e927a CSeq: 1 INVITE Server: Asterisk PBX 1.8.0-beta2 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="2a70fa38" Content-Length: 0 <------------> [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #4935 [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Trying to put 'SIP/2.0 401' onto UDP socket destined for 10.13.22.38:5060 [Aug 9 11:45:14] VERBOSE[31464] chan_sip.c: Scheduling destruction of SIP dialog '888f10-26160d0a-13c4-50029-386e927a-3b57bcf5-386e927a' in 32000 ms (Method: INVITE) [Aug 9 11:45:14] VERBOSE[31464] chan_sip.c: <--- SIP read from UDP:10.13.22.38:5060 ---> SIP/2.0 200 OK From: "asterisk";tag=as6a6fd911 To: ;tag=882650-26160d0a-13c4-50029-386e927a-71705936-386e927a Call-ID: 5a6687507e097d4d789b40d63bbe0a28@10.21.0.146:5061 CSeq: 102 NOTIFY Via: SIP/2.0/UDP 10.21.0.146:5061;branch=z9hG4bK1a6305c3 Supported: replaces,100rel User-Agent: AUDC-IPPhone/1.2.1_build_6 (320HD;00908F1ED22E) Content-Length: 0 <-------------> [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Header 1 [ 62]: From: "asterisk";tag=as6a6fd911 [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Header 2 [ 89]: To: ;tag=882650-26160d0a-13c4-50029-386e927a-71705936-386e927a [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Header 3 [ 58]: Call-ID: 5a6687507e097d4d789b40d63bbe0a28@10.21.0.146:5061 [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Header 4 [ 16]: CSeq: 102 NOTIFY [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Header 5 [ 56]: Via: SIP/2.0/UDP 10.21.0.146:5061;branch=z9hG4bK1a6305c3 [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Header 6 [ 26]: Supported: replaces,100rel [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Header 7 [ 59]: User-Agent: AUDC-IPPhone/1.2.1_build_6 (320HD;00908F1ED22E) [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Header 8 [ 17]: Content-Length: 0 [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Header 9 [ 0]: [Aug 9 11:45:14] VERBOSE[31464] chan_sip.c: --- (9 headers 0 lines) --- [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #4934 [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Stopping retransmission on '5a6687507e097d4d789b40d63bbe0a28@10.21.0.146:5061' of Request 102: Match Found [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Got 200 accepted on NOTIFY [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Destroying SIP dialog 5a6687507e097d4d789b40d63bbe0a28@10.21.0.146:5061 [Aug 9 11:45:14] VERBOSE[31464] chan_sip.c: Really destroying SIP dialog '5a6687507e097d4d789b40d63bbe0a28@10.21.0.146:5061' Method: NOTIFY [Aug 9 11:45:14] VERBOSE[31464] chan_sip.c: <--- SIP read from UDP:10.13.22.38:5060 ---> ACK sip:99764701@10.21.0.146:5061 SIP/2.0 From: "6000";tag=8824b0-26160d0a-13c4-50029-386e927a-488246b-386e927a To: ;tag=as490cc93c Call-ID: 888f10-26160d0a-13c4-50029-386e927a-3b57bcf5-386e927a CSeq: 1 ACK Via: SIP/2.0/UDP 10.13.22.38:5060;rport;branch=z9hG4bK-386e927a-6fec2fa9-988218 Max-Forwards: 70 User-Agent: AUDC-IPPhone/1.2.1_build_6 (320HD;00908F1ED22E) Contact: Content-Length: 0 <-------------> [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Header 0 [ 41]: ACK sip:99764701@10.21.0.146:5061 SIP/2.0 [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Header 1 [ 91]: From: "6000";tag=8824b0-26160d0a-13c4-50029-386e927a-488246b-386e927a [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Header 2 [ 50]: To: ;tag=as490cc93c [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Header 3 [ 62]: Call-ID: 888f10-26160d0a-13c4-50029-386e927a-3b57bcf5-386e927a [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Header 4 [ 11]: CSeq: 1 ACK [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Header 5 [ 79]: Via: SIP/2.0/UDP 10.13.22.38:5060;rport;branch=z9hG4bK-386e927a-6fec2fa9-988218 [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Header 6 [ 16]: Max-Forwards: 70 [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Header 7 [ 59]: User-Agent: AUDC-IPPhone/1.2.1_build_6 (320HD;00908F1ED22E) [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Header 8 [ 31]: Contact: [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Header 9 [ 17]: Content-Length: 0 [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Header 10 [ 0]: [Aug 9 11:45:14] VERBOSE[31464] chan_sip.c: --- (10 headers 0 lines) --- [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: **** Received ACK (6) - Command in SIP ACK [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #4935 [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Stopping retransmission on '888f10-26160d0a-13c4-50029-386e927a-3b57bcf5-386e927a' of Response 1: Match Found [Aug 9 11:45:14] VERBOSE[31464] chan_sip.c: <--- SIP read from UDP:10.13.22.38:5060 ---> INVITE sip:99764701@10.21.0.146:5061 SIP/2.0 From: "6000";tag=8824b0-26160d0a-13c4-50029-386e927a-488246b-386e927a To: Call-ID: 888f10-26160d0a-13c4-50029-386e927a-3b57bcf5-386e927a CSeq: 2 INVITE Via: SIP/2.0/UDP 10.13.22.38:5060;rport;branch=z9hG4bK-386e927a-6fec3060-72318434 Max-Forwards: 70 Supported: replaces,100rel User-Agent: AUDC-IPPhone/1.2.1_build_6 (320HD;00908F1ED22E) Allow: REGISTER, INVITE, ACK, BYE, REFER, NOTIFY, CANCEL, INFO, OPTIONS, PRACK, SUBSCRIBE Contact: Authorization: Digest username="6000",realm="asterisk",nonce="2a70fa38",uri="sip:99764701@10.21.0.146:5061",response="824d5969c04bf042135ff9b5bbd3a9e5",algorithm=MD5 Content-Type: application/sdp Content-Length: 399 v=0 o=6000 946771323 946771323 IN IP4 10.13.22.38 s=- c=IN IP4 10.13.22.38 t=0 0 m=audio 4000 RTP/AVP 9 0 8 18 4 101 a=rtpmap:9 G722/8000 a=ptime:20 a=rtpmap:0 PCMU/8000 a=ptime:20 a=rtpmap:8 PCMA/8000 a=ptime:20 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=ptime:20 a=rtpmap:4 g723/8000 a=fmtp:4 annexa=no a=ptime:30 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=sendrecv <-------------> [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Header 0 [ 44]: INVITE sip:99764701@10.21.0.146:5061 SIP/2.0 [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Header 1 [ 91]: From: "6000";tag=8824b0-26160d0a-13c4-50029-386e927a-488246b-386e927a [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Header 2 [ 35]: To: [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Header 3 [ 62]: Call-ID: 888f10-26160d0a-13c4-50029-386e927a-3b57bcf5-386e927a [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Header 4 [ 14]: CSeq: 2 INVITE [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Header 5 [ 81]: Via: SIP/2.0/UDP 10.13.22.38:5060;rport;branch=z9hG4bK-386e927a-6fec3060-72318434 [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Header 6 [ 16]: Max-Forwards: 70 [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Header 7 [ 26]: Supported: replaces,100rel [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Header 8 [ 59]: User-Agent: AUDC-IPPhone/1.2.1_build_6 (320HD;00908F1ED22E) [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Header 9 [ 89]: Allow: REGISTER, INVITE, ACK, BYE, REFER, NOTIFY, CANCEL, INFO, OPTIONS, PRACK, SUBSCRIBE [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Header 10 [ 31]: Contact: [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Header 11 [165]: Authorization: Digest username="6000",realm="asterisk",nonce="2a70fa38",uri="sip:99764701@10.21.0.146:5061",response="824d5969c04bf042135ff9b5bbd3a9e5",algorithm=MD5 [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Header 12 [ 29]: Content-Type: application/sdp [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Header 13 [ 19]: Content-Length: 399 [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Header 14 [ 0]: [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Body 0 [ 3]: v=0 [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Body 1 [ 45]: o=6000 946771323 946771323 IN IP4 10.13.22.38 [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Body 2 [ 3]: s=- [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Body 3 [ 20]: c=IN IP4 10.13.22.38 [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Body 4 [ 5]: t=0 0 [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Body 5 [ 35]: m=audio 4000 RTP/AVP 9 0 8 18 4 101 [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Body 6 [ 20]: a=rtpmap:9 G722/8000 [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Body 7 [ 10]: a=ptime:20 [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Body 8 [ 20]: a=rtpmap:0 PCMU/8000 [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Body 9 [ 10]: a=ptime:20 [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Body 10 [ 20]: a=rtpmap:8 PCMA/8000 [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Body 11 [ 10]: a=ptime:20 [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Body 12 [ 21]: a=rtpmap:18 G729/8000 [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Body 13 [ 19]: a=fmtp:18 annexb=no [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Body 14 [ 10]: a=ptime:20 [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Body 15 [ 20]: a=rtpmap:4 g723/8000 [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Body 16 [ 18]: a=fmtp:4 annexa=no [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Body 17 [ 10]: a=ptime:30 [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Body 18 [ 33]: a=rtpmap:101 telephone-event/8000 [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Body 19 [ 15]: a=fmtp:101 0-15 [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Body 20 [ 10]: a=sendrecv [Aug 9 11:45:14] VERBOSE[31464] chan_sip.c: --- (14 headers 21 lines) --- [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE [Aug 9 11:45:14] DEBUG[31464] netsock2.c: Splitting '10.13.22.38:5060' gives... [Aug 9 11:45:14] DEBUG[31464] netsock2.c: ...host '10.13.22.38' and port '5060'. [Aug 9 11:45:14] VERBOSE[31464] chan_sip.c: Sending to 10.13.22.38:5060 (no NAT) [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Initializing initreq for method INVITE - callid 888f10-26160d0a-13c4-50029-386e927a-3b57bcf5-386e927a [Aug 9 11:45:14] VERBOSE[31464] chan_sip.c: Using INVITE request as basis request - 888f10-26160d0a-13c4-50029-386e927a-3b57bcf5-386e927a [Aug 9 11:45:14] VERBOSE[31464] chan_sip.c: Found peer '6000' for '6000' from 10.13.22.38:5060 [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Setting NAT on UDPTL to Off [Aug 9 11:45:14] DEBUG[31464] rtp_engine.c: Using engine 'asterisk' for RTP instance '0xa27d9f8' [Aug 9 11:45:14] DEBUG[31464] res_rtp_asterisk.c: Allocated port 14610 for RTP instance '0xa27d9f8' [Aug 9 11:45:14] DEBUG[31464] rtp_engine.c: RTP instance '0xa27d9f8' is setup and ready to go [Aug 9 11:45:14] DEBUG[31464] res_rtp_asterisk.c: Setup RTCP on RTP instance '0xa27d9f8' [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Setting NAT on RTP to Off [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Setting NAT on UDPTL to Off [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED. [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Processing session-level SDP o=6000 946771323 946771323 IN IP4 10.13.22.38... UNSUPPORTED. [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Processing session-level SDP s=-... UNSUPPORTED. [Aug 9 11:45:14] DEBUG[31464] netsock2.c: Splitting '10.13.22.38' gives... [Aug 9 11:45:14] DEBUG[31464] netsock2.c: ...host '10.13.22.38' and port '(null)'. [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Processing session-level SDP c=IN IP4 10.13.22.38... OK. [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED. [Aug 9 11:45:14] VERBOSE[31464] chan_sip.c: Found RTP audio format 9 [Aug 9 11:45:14] DEBUG[31464] rtp_engine.c: Setting payload 9 based on m type on 0xb7cd83cc [Aug 9 11:45:14] VERBOSE[31464] chan_sip.c: Found RTP audio format 0 [Aug 9 11:45:14] DEBUG[31464] rtp_engine.c: Setting payload 0 based on m type on 0xb7cd83cc [Aug 9 11:45:14] VERBOSE[31464] chan_sip.c: Found RTP audio format 8 [Aug 9 11:45:14] DEBUG[31464] rtp_engine.c: Setting payload 8 based on m type on 0xb7cd83cc [Aug 9 11:45:14] VERBOSE[31464] chan_sip.c: Found RTP audio format 18 [Aug 9 11:45:14] DEBUG[31464] rtp_engine.c: Setting payload 18 based on m type on 0xb7cd83cc [Aug 9 11:45:14] VERBOSE[31464] chan_sip.c: Found RTP audio format 4 [Aug 9 11:45:14] DEBUG[31464] rtp_engine.c: Setting payload 4 based on m type on 0xb7cd83cc [Aug 9 11:45:14] VERBOSE[31464] chan_sip.c: Found RTP audio format 101 [Aug 9 11:45:14] DEBUG[31464] rtp_engine.c: Setting payload 101 based on m type on 0xb7cd83cc [Aug 9 11:45:14] VERBOSE[31464] chan_sip.c: Found audio description format G722 for ID 9 [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:9 G722/8000... OK. [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Processing media-level (audio) SDP a=ptime:20... OK. [Aug 9 11:45:14] VERBOSE[31464] chan_sip.c: Found audio description format PCMU for ID 0 [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:0 PCMU/8000... OK. [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Processing media-level (audio) SDP a=ptime:20... OK. [Aug 9 11:45:14] VERBOSE[31464] chan_sip.c: Found audio description format PCMA for ID 8 [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:8 PCMA/8000... OK. [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Processing media-level (audio) SDP a=ptime:20... OK. [Aug 9 11:45:14] VERBOSE[31464] chan_sip.c: Found audio description format G729 for ID 18 [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:18 G729/8000... OK. [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Processing media-level (audio) SDP a=fmtp:18 annexb=no... UNSUPPORTED. [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Processing media-level (audio) SDP a=ptime:20... OK. [Aug 9 11:45:14] VERBOSE[31464] chan_sip.c: Found audio description format g723 for ID 4 [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:4 g723/8000... OK. [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Processing media-level (audio) SDP a=fmtp:4 annexa=no... UNSUPPORTED. [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Processing media-level (audio) SDP a=ptime:30... OK. [Aug 9 11:45:14] VERBOSE[31464] chan_sip.c: Found audio description format telephone-event for ID 101 [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK. [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Processing media-level (audio) SDP a=fmtp:101 0-15... UNSUPPORTED. [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Processing media-level (audio) SDP a=sendrecv... OK. [Aug 9 11:45:14] DEBUG[31464] rtp_engine.c: Incorporating payload 0 on 0xb7cd83cc [Aug 9 11:45:14] DEBUG[31464] rtp_engine.c: Incorporating payload 4 on 0xb7cd83cc [Aug 9 11:45:14] DEBUG[31464] rtp_engine.c: Incorporating payload 8 on 0xb7cd83cc [Aug 9 11:45:14] DEBUG[31464] rtp_engine.c: Incorporating payload 9 on 0xb7cd83cc [Aug 9 11:45:14] DEBUG[31464] rtp_engine.c: Incorporating payload 18 on 0xb7cd83cc [Aug 9 11:45:14] DEBUG[31464] rtp_engine.c: Incorporating payload 101 on 0xb7cd83cc [Aug 9 11:45:14] VERBOSE[31464] chan_sip.c: Capabilities: us - 0xc (ulaw|alaw), peer - audio=0x110d (g723|ulaw|alaw|g729|g722)/video=0x0 (nothing)/text=0x0 (nothing), combined - 0xc (ulaw|alaw) [Aug 9 11:45:14] VERBOSE[31464] chan_sip.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|) [Aug 9 11:45:14] DEBUG[31464] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0xa27d9f8' [Aug 9 11:45:14] VERBOSE[31464] chan_sip.c: Peer audio RTP is at port 10.13.22.38:4000 [Aug 9 11:45:14] DEBUG[31464] rtp_engine.c: Copying payload 0 from 0xb7cd83cc to 0xa27dba4 [Aug 9 11:45:14] DEBUG[31464] rtp_engine.c: Copying payload 4 from 0xb7cd83cc to 0xa27dba4 [Aug 9 11:45:14] DEBUG[31464] rtp_engine.c: Copying payload 8 from 0xb7cd83cc to 0xa27dba4 [Aug 9 11:45:14] DEBUG[31464] rtp_engine.c: Copying payload 9 from 0xb7cd83cc to 0xa27dba4 [Aug 9 11:45:14] DEBUG[31464] rtp_engine.c: Copying payload 18 from 0xb7cd83cc to 0xa27dba4 [Aug 9 11:45:14] DEBUG[31464] rtp_engine.c: Copying payload 101 from 0xb7cd83cc to 0xa27dba4 [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Peer doesn't provide T.38 UDPTL [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: We're settling with these formats: 0x8 (alaw) [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Checking SIP call limits for device 6000 [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Updating call counter for incoming call [Aug 9 11:45:14] DEBUG[31464] chan_sip.c: Call from peer '6000' is 1 out of 6 [Aug 9 11:45:14] VERBOSE[31464] chan_sip.c: Looking for 99764701 in DLPN_DialPlanAll (domain 10.21.0.146:5061) [Aug 9 11:45:14] DEBUG[31464] res_config_pgsql.c: PostgreSQL RealTime: One or more of the parameters in the config does not pass our validity checks. [Aug 9 11:45:14] DEBUG[31458] devicestate.c: No provider found, checking channel drivers for SIP - 6000 [Aug 9 11:45:14] DEBUG[31458] chan_sip.c: Checking device state for peer 6000 [Aug 9 11:45:14] DEBUG[31458] devicestate.c: Changing state for SIP/6000 - state 3 (Busy) [Aug 9 11:45:14] DEBUG[31458] devicestate.c: device 'SIP/6000' state '3' [Aug 9 11:45:14] DEBUG[31464] res_config_pgsql.c: PostgreSQL RealTime: Result=0xa1ab390 Query: SELECT * FROM extensions_table WHERE exten = '99764701' AND context = 'ringgroups' AND priority = '1' [Aug 9 11:45:14] DEBUG[31464] res_config_pgsql.c: Postgresql RealTime: Could not find any rows in table extensions_table@asterisk. [Aug 9 11:45:14] DEBUG[31464] res_config_pgsql.c: PostgreSQL RealTime: One or more of the parameters in the config does not pass our validity checks. [Aug 9 11:45:15] DEBUG[31464] res_config_pgsql.c: PostgreSQL RealTime: Result=0xa28be90 Query: SELECT * FROM extensions_table WHERE exten LIKE '\\_%' AND context = 'ringgroups' AND priority = '1' ORDER BY exten [Aug 9 11:45:15] DEBUG[31464] res_config_pgsql.c: PostgreSQL RealTime: Could not find any rows in table extensions_table. [Aug 9 11:45:15] DEBUG[31464] chan_sip.c: *** Our native formats are 0x8 (alaw) [Aug 9 11:45:15] DEBUG[31464] chan_sip.c: *** Joint capabilities are 0x8 (alaw) [Aug 9 11:45:15] DEBUG[31464] chan_sip.c: *** Our capabilities are 0xc (ulaw|alaw) [Aug 9 11:45:15] DEBUG[31464] chan_sip.c: *** AST_CODEC_CHOOSE formats are 0x8 (alaw) [Aug 9 11:45:15] DEBUG[31464] chan_sip.c: This channel will not be able to handle video. [Aug 9 11:45:15] DEBUG[31464] chan_sip.c: build_route: Contact hop: [Aug 9 11:45:15] VERBOSE[31464] chan_sip.c: list_route: hop: [Aug 9 11:45:15] DEBUG[31464] chan_sip.c: Session timer started: 4937 - 888f10-26160d0a-13c4-50029-386e927a-3b57bcf5-386e927a [Aug 9 11:45:15] DEBUG[31464] chan_sip.c: SIP/6000-0000004b: New call is still down.... Trying... [Aug 9 11:45:15] VERBOSE[31464] chan_sip.c: <--- Transmitting (no NAT) to 10.13.22.38:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 10.13.22.38:5060;branch=z9hG4bK-386e927a-6fec3060-72318434;received=10.13.22.38;rport=5060 From: "6000";tag=8824b0-26160d0a-13c4-50029-386e927a-488246b-386e927a To: Call-ID: 888f10-26160d0a-13c4-50029-386e927a-3b57bcf5-386e927a CSeq: 2 INVITE Server: Asterisk PBX 1.8.0-beta2 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Contact: Content-Length: 0 <------------> [Aug 9 11:45:15] DEBUG[31464] chan_sip.c: Trying to put 'SIP/2.0 100' onto UDP socket destined for 10.13.22.38:5060 [Aug 9 11:45:15] DEBUG[31458] devicestate.c: No provider found, checking channel drivers for SIP - 6000 [Aug 9 11:45:15] DEBUG[31458] chan_sip.c: Checking device state for peer 6000 [Aug 9 11:45:15] DEBUG[31458] devicestate.c: Changing state for SIP/6000 - state 3 (Busy) [Aug 9 11:45:15] DEBUG[31458] devicestate.c: device 'SIP/6000' state '3' [Aug 9 11:45:15] DEBUG[32310] res_config_pgsql.c: PostgreSQL RealTime: One or more of the parameters in the config does not pass our validity checks. [Aug 9 11:45:15] DEBUG[32310] res_config_pgsql.c: PostgreSQL RealTime: Result=0xa015fd8 Query: SELECT * FROM extensions_table WHERE exten = '99764701' AND context = 'ringgroups' AND priority = '1' [Aug 9 11:45:15] DEBUG[32310] res_config_pgsql.c: Postgresql RealTime: Could not find any rows in table extensions_table@asterisk. [Aug 9 11:45:15] DEBUG[32310] res_config_pgsql.c: PostgreSQL RealTime: One or more of the parameters in the config does not pass our validity checks. [Aug 9 11:45:15] DEBUG[32310] res_config_pgsql.c: PostgreSQL RealTime: Result=0xa2a7028 Query: SELECT * FROM extensions_table WHERE exten LIKE '\\_%' AND context = 'ringgroups' AND priority = '1' ORDER BY exten [Aug 9 11:45:15] DEBUG[32310] res_config_pgsql.c: PostgreSQL RealTime: Could not find any rows in table extensions_table. [Aug 9 11:45:15] DEBUG[32310] res_config_pgsql.c: PostgreSQL RealTime: One or more of the parameters in the config does not pass our validity checks. [Aug 9 11:45:15] DEBUG[32310] res_config_pgsql.c: PostgreSQL RealTime: Result=0x9c76328 Query: SELECT * FROM extensions_table WHERE exten = '99764701' AND context = 'ringgroups' AND priority = '1' [Aug 9 11:45:15] DEBUG[32310] res_config_pgsql.c: Postgresql RealTime: Could not find any rows in table extensions_table@asterisk. [Aug 9 11:45:15] DEBUG[32310] res_config_pgsql.c: PostgreSQL RealTime: One or more of the parameters in the config does not pass our validity checks. [Aug 9 11:45:15] DEBUG[32310] res_config_pgsql.c: PostgreSQL RealTime: Result=0xa1c1ca0 Query: SELECT * FROM extensions_table WHERE exten LIKE '\\_%' AND context = 'ringgroups' AND priority = '1' ORDER BY exten [Aug 9 11:45:15] DEBUG[32310] res_config_pgsql.c: PostgreSQL RealTime: Could not find any rows in table extensions_table. [Aug 9 11:45:15] DEBUG[32310] pbx.c: Result of 'EXTEN' is '99764701' [Aug 9 11:45:15] DEBUG[32310] pbx.c: Launching 'Set' [Aug 9 11:45:15] VERBOSE[32310] pbx.c: -- Executing [99764701@DLPN_DialPlanAll:1] Set("SIP/6000-0000004b", "DN=99764701") in new stack [Aug 9 11:45:15] DEBUG[32310] res_config_pgsql.c: PostgreSQL RealTime: One or more of the parameters in the config does not pass our validity checks. [Aug 9 11:45:15] DEBUG[32310] res_config_pgsql.c: PostgreSQL RealTime: Result=0xa1ab390 Query: SELECT * FROM extensions_table WHERE exten = '99764701' AND context = 'ringgroups' AND priority = '2' [Aug 9 11:45:15] DEBUG[32310] res_config_pgsql.c: Postgresql RealTime: Could not find any rows in table extensions_table@asterisk. [Aug 9 11:45:15] DEBUG[32310] res_config_pgsql.c: PostgreSQL RealTime: One or more of the parameters in the config does not pass our validity checks. [Aug 9 11:45:15] DEBUG[32310] res_config_pgsql.c: PostgreSQL RealTime: Result=0xa28be90 Query: SELECT * FROM extensions_table WHERE exten LIKE '\\_%' AND context = 'ringgroups' AND priority = '2' ORDER BY exten [Aug 9 11:45:15] DEBUG[32310] res_config_pgsql.c: PostgreSQL RealTime: Could not find any rows in table extensions_table. [Aug 9 11:45:15] DEBUG[32310] pbx.c: Function result is 'AUDC-IPPhone/1.2.1_build_6 (320HD;00908F1ED22E)' [Aug 9 11:45:15] DEBUG[32310] pbx.c: Launching 'Set' [Aug 9 11:45:15] VERBOSE[32310] pbx.c: -- Executing [99764701@DLPN_DialPlanAll:2] Set("SIP/6000-0000004b", "UserAgent=AUDC-IPPhone/1.2.1_build_6 (320HD;00908F1ED22E)") in new stack [Aug 9 11:45:15] DEBUG[32310] res_config_pgsql.c: PostgreSQL RealTime: One or more of the parameters in the config does not pass our validity checks. [Aug 9 11:45:15] DEBUG[32310] res_config_pgsql.c: PostgreSQL RealTime: Result=0xa273d78 Query: SELECT * FROM extensions_table WHERE exten = '99764701' AND context = 'ringgroups' AND priority = '3' [Aug 9 11:45:15] DEBUG[32310] res_config_pgsql.c: Postgresql RealTime: Could not find any rows in table extensions_table@asterisk. [Aug 9 11:45:15] DEBUG[32310] res_config_pgsql.c: PostgreSQL RealTime: One or more of the parameters in the config does not pass our validity checks. [Aug 9 11:45:15] DEBUG[32310] res_config_pgsql.c: PostgreSQL RealTime: Result=0xa015fd8 Query: SELECT * FROM extensions_table WHERE exten LIKE '\\_%' AND context = 'ringgroups' AND priority = '3' ORDER BY exten [Aug 9 11:45:15] DEBUG[32310] res_config_pgsql.c: PostgreSQL RealTime: Could not find any rows in table extensions_table. [Aug 9 11:45:15] DEBUG[32310] pbx.c: Launching 'Set' [Aug 9 11:45:15] VERBOSE[32310] pbx.c: -- Executing [99764701@DLPN_DialPlanAll:3] Set("SIP/6000-0000004b", "CountReq=0") in new stack [Aug 9 11:45:15] DEBUG[32310] res_config_pgsql.c: PostgreSQL RealTime: One or more of the parameters in the config does not pass our validity checks. [Aug 9 11:45:15] DEBUG[32310] res_config_pgsql.c: PostgreSQL RealTime: Result=0xa2a7028 Query: SELECT * FROM extensions_table WHERE exten = '99764701' AND context = 'ringgroups' AND priority = '4' [Aug 9 11:45:15] DEBUG[32310] res_config_pgsql.c: Postgresql RealTime: Could not find any rows in table extensions_table@asterisk. [Aug 9 11:45:15] DEBUG[32310] res_config_pgsql.c: PostgreSQL RealTime: One or more of the parameters in the config does not pass our validity checks. [Aug 9 11:45:15] DEBUG[32310] res_config_pgsql.c: PostgreSQL RealTime: Result=0x9c76328 Query: SELECT * FROM extensions_table WHERE exten LIKE '\\_%' AND context = 'ringgroups' AND priority = '4' ORDER BY exten [Aug 9 11:45:15] DEBUG[32310] res_config_pgsql.c: PostgreSQL RealTime: Could not find any rows in table extensions_table. [Aug 9 11:45:15] DEBUG[32310] pbx.c: Launching 'Macro' [Aug 9 11:45:15] VERBOSE[32310] pbx.c: -- Executing [99764701@DLPN_DialPlanAll:4] Macro("SIP/6000-0000004b", "DialProcess") in new stack [Aug 9 11:45:15] DEBUG[32310] pbx.c: Result of 'CountReq' is '0' [Aug 9 11:45:15] DEBUG[32310] pbx.c: Expression result is '1' [Aug 9 11:45:15] DEBUG[32310] pbx.c: Launching 'Set' [Aug 9 11:45:15] VERBOSE[32310] pbx.c: -- Executing [s@macro-DialProcess:1] Set("SIP/6000-0000004b", "CountReq=1") in new stack [Aug 9 11:45:15] DEBUG[32310] app_macro.c: Executed application: Set [Aug 9 11:45:15] DEBUG[32310] pbx.c: Result of 'CountReq' is '1' [Aug 9 11:45:15] DEBUG[32310] pbx.c: Expression result is '0' [Aug 9 11:45:15] DEBUG[32310] pbx.c: Launching 'GotoIf' [Aug 9 11:45:15] VERBOSE[32310] pbx.c: -- Executing [s@macro-DialProcess:2] GotoIf("SIP/6000-0000004b", "0?1-End,1") in new stack [Aug 9 11:45:15] DEBUG[32310] pbx.c: Not taking any branch [Aug 9 11:45:15] DEBUG[32310] app_macro.c: Executed application: GotoIf [Aug 9 11:45:15] DEBUG[32310] pbx.c: Result of 'WINIP' is '10.21.0.133:8090' [Aug 9 11:45:15] DEBUG[32310] pbx.c: Result of 'DN' is '99764701' [Aug 9 11:45:15] DEBUG[32310] pbx.c: Function result is '6000' [Aug 9 11:45:15] DEBUG[32310] pbx.c: Result of 'PermissionExt' is NULL [Aug 9 11:45:15] DEBUG[32310] pbx.c: Result of 'Provider' is NULL [Aug 9 11:45:15] DEBUG[32310] pbx.c: Function result is 'Shay HD' [Aug 9 11:45:15] DEBUG[32310] pbx.c: Function result is 'Shay%20HD' [Aug 9 11:45:15] DEBUG[32310] pbx.c: Result of 'IsForward' is NULL [Aug 9 11:45:15] DEBUG[32310] func_curl.c: Called with data=0xb7b3cab8, str=0xa2e62e0, realsize=48, len=16, used=0 [Aug 9 11:45:15] DEBUG[32310] func_curl.c: Now, len=64, used=48 [Aug 9 11:45:15] DEBUG[32310] func_curl.c: str='9764701:::#6000#Shay HD#external#M1k_Shay::no###' [Aug 9 11:45:15] DEBUG[32310] pbx.c: Function result is '9764701:::#6000#Shay HD#external#M1k_Shay::no###' [Aug 9 11:45:15] DEBUG[32310] pbx.c: Launching 'Set' [Aug 9 11:45:15] VERBOSE[32310] pbx.c: -- Executing [s@macro-DialProcess:3] Set("SIP/6000-0000004b", "RuleResult=9764701:::#6000#Shay HD#external#M1k_Shay::no###") in new stack [Aug 9 11:45:15] DEBUG[32310] app_macro.c: Executed application: Set [Aug 9 11:45:15] DEBUG[32310] pbx.c: Result of 'DEF_LANG_PREFIX' is 'ru' [Aug 9 11:45:15] DEBUG[32310] pbx.c: Launching 'Set' [Aug 9 11:45:15] VERBOSE[32310] pbx.c: -- Executing [s@macro-DialProcess:4] Set("SIP/6000-0000004b", "CHANNEL(language)=ru") in new stack [Aug 9 11:45:15] DEBUG[32310] app_macro.c: Executed application: Set [Aug 9 11:45:15] DEBUG[32310] pbx.c: Evaluating 'RuleResult' (from 'RuleResult}' len 10) [Aug 9 11:45:15] DEBUG[32310] pbx.c: Result of 'RuleResult' is '9764701:::#6000#Shay HD#external#M1k_Shay::no###' [Aug 9 11:45:15] DEBUG[32310] pbx.c: Function result is 'external' [Aug 9 11:45:15] DEBUG[32310] pbx.c: Launching 'Set' [Aug 9 11:45:15] VERBOSE[32310] pbx.c: -- Executing [s@macro-DialProcess:5] Set("SIP/6000-0000004b", "CommandType=external") in new stack [Aug 9 11:45:15] DEBUG[32310] app_macro.c: Executed application: Set [Aug 9 11:45:15] DEBUG[32310] pbx.c: Evaluating 'RuleResult' (from 'RuleResult}' len 10) [Aug 9 11:45:15] DEBUG[32310] pbx.c: Result of 'RuleResult' is '9764701:::#6000#Shay HD#external#M1k_Shay::no###' [Aug 9 11:45:15] DEBUG[32310] pbx.c: Function result is '' [Aug 9 11:45:15] DEBUG[32310] pbx.c: Launching 'Set' [Aug 9 11:45:15] VERBOSE[32310] pbx.c: -- Executing [s@macro-DialProcess:6] Set("SIP/6000-0000004b", "Announc=") in new stack [Aug 9 11:45:15] DEBUG[32310] app_macro.c: Executed application: Set [Aug 9 11:45:15] DEBUG[32310] pbx.c: Result of 'Announc' is '' [Aug 9 11:45:15] DEBUG[32310] pbx.c: Function result is '0' [Aug 9 11:45:15] DEBUG[32310] pbx.c: Expression result is '1' [Aug 9 11:45:15] DEBUG[32310] pbx.c: Launching 'GotoIf' [Aug 9 11:45:15] VERBOSE[32310] pbx.c: -- Executing [s@macro-DialProcess:7] GotoIf("SIP/6000-0000004b", "1?1-Switch,1") in new stack [Aug 9 11:45:15] VERBOSE[32310] pbx.c: -- Goto (macro-DialProcess,1-Switch,1) [Aug 9 11:45:16] DEBUG[32310] app_macro.c: Executed application: GotoIf [Aug 9 11:45:16] DEBUG[32310] pbx.c: Result of 'CommandType' is 'external' [Aug 9 11:45:16] DEBUG[32310] pbx.c: Expression result is '0' [Aug 9 11:45:16] DEBUG[32310] pbx.c: Launching 'GotoIf' [Aug 9 11:45:16] VERBOSE[32310] pbx.c: -- Executing [1-Switch@macro-DialProcess:1] GotoIf("SIP/6000-0000004b", "0?1-Internal,1") in new stack [Aug 9 11:45:16] DEBUG[32310] pbx.c: Not taking any branch [Aug 9 11:45:16] DEBUG[32310] app_macro.c: Executed application: GotoIf [Aug 9 11:45:16] DEBUG[32310] pbx.c: Result of 'CommandType' is 'external' [Aug 9 11:45:16] DEBUG[32310] pbx.c: Expression result is '1' [Aug 9 11:45:16] DEBUG[32310] pbx.c: Launching 'GotoIf' [Aug 9 11:45:16] VERBOSE[32310] pbx.c: -- Executing [1-Switch@macro-DialProcess:2] GotoIf("SIP/6000-0000004b", "1?1-External,1") in new stack [Aug 9 11:45:16] VERBOSE[32310] pbx.c: -- Goto (macro-DialProcess,1-External,1) [Aug 9 11:45:16] DEBUG[32310] app_macro.c: Executed application: GotoIf [Aug 9 11:45:16] DEBUG[32310] pbx.c: Launching 'Macro' [Aug 9 11:45:16] VERBOSE[32310] pbx.c: -- Executing [1-External@macro-DialProcess:1] Macro("SIP/6000-0000004b", "Dial-Trunk") in new stack [Aug 9 11:45:16] DEBUG[32310] pbx.c: Launching 'NoOp' [Aug 9 11:45:16] VERBOSE[32310] pbx.c: -- Executing [s@macro-Dial-Trunk:1] NoOp("SIP/6000-0000004b", "Dial-Trunk") in new stack [Aug 9 11:45:16] DEBUG[32310] app_macro.c: Executed application: Noop [Aug 9 11:45:16] DEBUG[32310] pbx.c: Evaluating 'RuleResult' (from 'RuleResult}' len 10) [Aug 9 11:45:16] DEBUG[32310] pbx.c: Result of 'RuleResult' is '9764701:::#6000#Shay HD#external#M1k_Shay::no###' [Aug 9 11:45:16] DEBUG[32310] pbx.c: Function result is '9764701:::' [Aug 9 11:45:16] DEBUG[32310] pbx.c: Launching 'Set' [Aug 9 11:45:16] VERBOSE[32310] pbx.c: -- Executing [s@macro-Dial-Trunk:2] Set("SIP/6000-0000004b", "MyDN=9764701:::") in new stack [Aug 9 11:45:16] DEBUG[32310] app_macro.c: Executed application: Set [Aug 9 11:45:16] DEBUG[32310] pbx.c: Evaluating 'RuleResult' (from 'RuleResult}' len 10) [Aug 9 11:45:16] DEBUG[32310] pbx.c: Result of 'RuleResult' is '9764701:::#6000#Shay HD#external#M1k_Shay::no###' [Aug 9 11:45:16] DEBUG[32310] pbx.c: Function result is '6000' [Aug 9 11:45:16] DEBUG[32310] pbx.c: Launching 'Set' [Aug 9 11:45:16] VERBOSE[32310] pbx.c: -- Executing [s@macro-Dial-Trunk:3] Set("SIP/6000-0000004b", "CALLERID(num)=6000") in new stack [Aug 9 11:45:16] DEBUG[32310] app_macro.c: Executed application: Set [Aug 9 11:45:16] DEBUG[32310] pbx.c: Evaluating 'RuleResult' (from 'RuleResult}' len 10) [Aug 9 11:45:16] DEBUG[32310] pbx.c: Result of 'RuleResult' is '9764701:::#6000#Shay HD#external#M1k_Shay::no###' [Aug 9 11:45:16] DEBUG[32310] pbx.c: Function result is 'Shay HD' [Aug 9 11:45:16] DEBUG[32310] pbx.c: Launching 'Set' [Aug 9 11:45:16] VERBOSE[32310] pbx.c: -- Executing [s@macro-Dial-Trunk:4] Set("SIP/6000-0000004b", "CALLERID(name)=Shay HD") in new stack [Aug 9 11:45:16] DEBUG[32310] app_macro.c: Executed application: Set [Aug 9 11:45:16] DEBUG[32310] pbx.c: Evaluating 'RuleResult' (from 'RuleResult}' len 10) [Aug 9 11:45:16] DEBUG[32310] pbx.c: Result of 'RuleResult' is '9764701:::#6000#Shay HD#external#M1k_Shay::no###' [Aug 9 11:45:16] DEBUG[32310] pbx.c: Function result is 'M1k_Shay::no' [Aug 9 11:45:16] DEBUG[32310] pbx.c: Launching 'Set' [Aug 9 11:45:16] VERBOSE[32310] pbx.c: -- Executing [s@macro-Dial-Trunk:5] Set("SIP/6000-0000004b", "Providers=M1k_Shay::no") in new stack [Aug 9 11:45:16] DEBUG[32310] app_macro.c: Executed application: Set [Aug 9 11:45:16] DEBUG[32310] pbx.c: Evaluating 'Providers' (from 'Providers}' len 9) [Aug 9 11:45:16] DEBUG[32310] pbx.c: Result of 'Providers' is 'M1k_Shay::no' [Aug 9 11:45:16] DEBUG[32310] pbx.c: Function result is 'M1k_Shay' [Aug 9 11:45:16] DEBUG[32310] pbx.c: Launching 'Set' [Aug 9 11:45:16] VERBOSE[32310] pbx.c: -- Executing [s@macro-Dial-Trunk:6] Set("SIP/6000-0000004b", "PrimaryProv=M1k_Shay") in new stack [Aug 9 11:45:16] DEBUG[32310] app_macro.c: Executed application: Set [Aug 9 11:45:16] DEBUG[32310] pbx.c: Evaluating 'Providers' (from 'Providers}' len 9) [Aug 9 11:45:16] DEBUG[32310] pbx.c: Result of 'Providers' is 'M1k_Shay::no' [Aug 9 11:45:16] DEBUG[32310] pbx.c: Function result is '' [Aug 9 11:45:16] DEBUG[32310] pbx.c: Launching 'Set' [Aug 9 11:45:16] VERBOSE[32310] pbx.c: -- Executing [s@macro-Dial-Trunk:7] Set("SIP/6000-0000004b", "BackupProv=") in new stack [Aug 9 11:45:16] DEBUG[32310] app_macro.c: Executed application: Set [Aug 9 11:45:16] DEBUG[32310] pbx.c: Evaluating 'MyDN' (from 'MyDN}' len 4) [Aug 9 11:45:16] DEBUG[32310] pbx.c: Result of 'MyDN' is '9764701:::' [Aug 9 11:45:16] DEBUG[32310] pbx.c: Function result is '' [Aug 9 11:45:16] DEBUG[32310] pbx.c: Launching 'Set' [Aug 9 11:45:16] VERBOSE[32310] pbx.c: -- Executing [s@macro-Dial-Trunk:8] Set("SIP/6000-0000004b", "Mailbox=") in new stack [Aug 9 11:45:16] DEBUG[32310] app_macro.c: Executed application: Set [Aug 9 11:45:16] DEBUG[32310] pbx.c: Launching 'Goto' [Aug 9 11:45:16] VERBOSE[32310] pbx.c: -- Executing [s@macro-Dial-Trunk:9] Goto("SIP/6000-0000004b", "1-Dial,1") in new stack [Aug 9 11:45:16] VERBOSE[32310] pbx.c: -- Goto (macro-Dial-Trunk,1-Dial,1) [Aug 9 11:45:16] DEBUG[32310] app_macro.c: Executed application: Goto [Aug 9 11:45:16] DEBUG[32310] pbx.c: Evaluating 'MyDN' (from 'MyDN}' len 4) [Aug 9 11:45:16] DEBUG[32310] pbx.c: Result of 'MyDN' is '9764701:::' [Aug 9 11:45:16] DEBUG[32310] pbx.c: Function result is '9764701' [Aug 9 11:45:16] DEBUG[32310] pbx.c: Result of 'PrimaryProv' is 'M1k_Shay' [Aug 9 11:45:16] DEBUG[32310] pbx.c: Launching 'Dial' [Aug 9 11:45:16] VERBOSE[32310] pbx.c: -- Executing [1-Dial@macro-Dial-Trunk:1] Dial("SIP/6000-0000004b", "SIP/9764701@M1k_Shay,180") in new stack [Aug 9 11:45:16] DEBUG[32310] chan_sip.c: Asked to create a SIP channel with formats: 0x8 (alaw) [Aug 9 11:45:16] VERBOSE[32310] netsock.c: == Using UDPTL CoS mark 5 [Aug 9 11:45:16] DEBUG[32310] chan_sip.c: Allocating new SIP dialog for 3974c0b4465808496955ccd216eada66@127.0.0.1:0 - INVITE (No RTP) [Aug 9 11:45:16] DEBUG[32310] res_config_pgsql.c: PostgreSQL RealTime: One or more of the parameters in the config does not pass our validity checks. [Aug 9 11:45:16] DEBUG[32310] res_config_pgsql.c: PostgreSQL RealTime: Result=0xa305c80 Query: SELECT * FROM sip_buddies WHERE name = 'M1k_Shay' AND host = 'dynamic' [Aug 9 11:45:16] DEBUG[32310] res_config_pgsql.c: Postgresql RealTime: Could not find any rows in table sip_buddies@asterisk. [Aug 9 11:45:16] DEBUG[32310] res_config_pgsql.c: PostgreSQL RealTime: One or more of the parameters in the config does not pass our validity checks. [Aug 9 11:45:16] DEBUG[32310] res_config_pgsql.c: PostgreSQL RealTime: Result=0xa2cbc90 Query: SELECT * FROM sip_buddies WHERE name = 'M1k_Shay' [Aug 9 11:45:16] DEBUG[32310] res_config_pgsql.c: PostgreSQL RealTime: Found 1 rows. [Aug 9 11:45:16] VERBOSE[32310] dnsmgr.c: > doing dnsmgr_lookup for '10.21.0.135' [Aug 9 11:45:16] DEBUG[32310] netsock2.c: Splitting '10.21.0.135' gives... [Aug 9 11:45:16] DEBUG[32310] netsock2.c: ...host '10.21.0.135' and port '(null)'. [Aug 9 11:45:16] DEBUG[32310] chan_sip.c: Not an IPv4 nor IPv6 address, cannot get port. [Aug 9 11:45:16] DEBUG[32310] chan_sip.c: Not an IPv4 nor IPv6 address, cannot set port. [Aug 9 11:45:16] DEBUG[32310] chan_sip.c: -REALTIME- loading peer from database to memory. Name: M1k_Shay. Peer objects: -552 [Aug 9 11:45:16] DEBUG[32310] rtp_engine.c: Using engine 'asterisk' for RTP instance '0xa2f3460' [Aug 9 11:45:16] DEBUG[32310] res_rtp_asterisk.c: Allocated port 19132 for RTP instance '0xa2f3460' [Aug 9 11:45:16] DEBUG[32310] rtp_engine.c: RTP instance '0xa2f3460' is setup and ready to go [Aug 9 11:45:16] DEBUG[32310] res_rtp_asterisk.c: Setup RTCP on RTP instance '0xa2f3460' [Aug 9 11:45:16] DEBUG[32310] chan_sip.c: Setting NAT on RTP to Off [Aug 9 11:45:16] DEBUG[32310] chan_sip.c: Setting NAT on UDPTL to Off [Aug 9 11:45:16] DEBUG[32310] chan_sip.c: OBPROXY: Not applying OBproxy to this call [Aug 9 11:45:16] DEBUG[32310] acl.c: For destination '10.21.0.135', our source address is '10.21.0.146'. [Aug 9 11:45:16] DEBUG[32310] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 10.21.0.146:5061 [Aug 9 11:45:16] DEBUG[32310] chan_sip.c: *** Our native formats are 0x8 (alaw) [Aug 9 11:45:16] DEBUG[32310] chan_sip.c: *** Joint capabilities are 0x8 (alaw) [Aug 9 11:45:16] DEBUG[32310] chan_sip.c: *** Our capabilities are 0xc (ulaw|alaw) [Aug 9 11:45:16] DEBUG[32310] chan_sip.c: *** AST_CODEC_CHOOSE formats are 0x8 (alaw) [Aug 9 11:45:16] DEBUG[32310] chan_sip.c: *** Our preferred formats from the incoming channel are 0x8 (alaw) [Aug 9 11:45:16] DEBUG[32310] chan_sip.c: This channel will not be able to handle video. [Aug 9 11:45:16] DEBUG[32310] rtp_engine.c: Seeded SDP of 'SIP/M1k_Shay-0000004c' with that of 'SIP/6000-0000004b' [Aug 9 11:45:16] DEBUG[32310] channel.c: Not copying variable DIALEDTIME. [Aug 9 11:45:16] DEBUG[32310] channel.c: Not copying variable ANSWEREDTIME. [Aug 9 11:45:16] DEBUG[32310] channel.c: Not copying variable DIALEDPEERNAME. [Aug 9 11:45:16] DEBUG[32310] channel.c: Not copying variable DIALEDPEERNUMBER. [Aug 9 11:45:16] DEBUG[32310] channel.c: Not copying variable DIALSTATUS. [Aug 9 11:45:16] DEBUG[32310] channel.c: Not copying variable MACRO_DEPTH. [Aug 9 11:45:16] DEBUG[32310] channel.c: Not copying variable Mailbox. [Aug 9 11:45:16] DEBUG[32310] channel.c: Not copying variable BackupProv. [Aug 9 11:45:16] DEBUG[32310] channel.c: Not copying variable PrimaryProv. [Aug 9 11:45:16] DEBUG[32310] channel.c: Not copying variable Providers. [Aug 9 11:45:16] DEBUG[32310] channel.c: Not copying variable MyDN. [Aug 9 11:45:16] DEBUG[32310] channel.c: Not copying variable MACRO_PRIORITY. [Aug 9 11:45:16] DEBUG[32310] channel.c: Not copying variable MACRO_CONTEXT. [Aug 9 11:45:16] DEBUG[32310] channel.c: Not copying variable MACRO_EXTEN. [Aug 9 11:45:16] DEBUG[32310] channel.c: Not copying variable Announc. [Aug 9 11:45:16] DEBUG[32310] channel.c: Not copying variable CommandType. [Aug 9 11:45:16] DEBUG[32310] channel.c: Not copying variable RuleResult. [Aug 9 11:45:16] DEBUG[32310] channel.c: Not copying variable CountReq. [Aug 9 11:45:16] DEBUG[32310] channel.c: Not copying variable UserAgent. [Aug 9 11:45:16] DEBUG[32310] channel.c: Not copying variable DN. [Aug 9 11:45:16] DEBUG[32310] channel.c: Not copying variable SIPCALLID. [Aug 9 11:45:16] DEBUG[32310] channel.c: Not copying variable SIPDOMAIN. [Aug 9 11:45:16] DEBUG[32310] channel.c: Not copying variable SIPURI. [Aug 9 11:45:16] DEBUG[32310] chan_sip.c: Outgoing Call for 9764701 [Aug 9 11:45:16] DEBUG[32310] chan_sip.c: Updating call counter for outgoing call [Aug 9 11:45:16] DEBUG[32310] chan_sip.c: Call to peer 'M1k_Shay' is 1 out of 99 [Aug 9 11:45:16] DEBUG[32310] chan_sip.c: ** Our capability: 0xc (ulaw|alaw) Video flag: False Text flag: False [Aug 9 11:45:16] DEBUG[32310] chan_sip.c: ** Our prefcodec: 0x8 (alaw) [Aug 9 11:45:16] VERBOSE[32310] chan_sip.c: Audio is at 5061 [Aug 9 11:45:16] VERBOSE[32310] chan_sip.c: Adding codec 0x8 (alaw) to SDP [Aug 9 11:45:16] VERBOSE[32310] chan_sip.c: Adding codec 0x4 (ulaw) to SDP [Aug 9 11:45:16] VERBOSE[32310] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP [Aug 9 11:45:16] DEBUG[32310] chan_sip.c: -- Done with adding codecs to SDP [Aug 9 11:45:16] DEBUG[32310] chan_sip.c: Done building SDP. Settling with this capability: 0xc (ulaw|alaw) [Aug 9 11:45:16] DEBUG[32310] chan_sip.c: Initializing initreq for method INVITE - callid 218437655d848d51367a65487e733ae9@TTTSS [Aug 9 11:45:16] DEBUG[32310] chan_sip.c: Header 0 [ 43]: INVITE sip:9764701@10.21.0.135:5060 SIP/2.0 [Aug 9 11:45:16] DEBUG[32310] chan_sip.c: Header 1 [ 56]: Via: SIP/2.0/UDP 10.21.0.146:5061;branch=z9hG4bK7a2ba14b [Aug 9 11:45:16] DEBUG[32310] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Aug 9 11:45:16] DEBUG[32310] chan_sip.c: Header 3 [ 47]: From: "Shay HD" ;tag=as63233769 [Aug 9 11:45:16] DEBUG[32310] chan_sip.c: Header 4 [ 34]: To: [Aug 9 11:45:16] DEBUG[32310] chan_sip.c: Header 5 [ 36]: Contact: [Aug 9 11:45:16] DEBUG[32310] chan_sip.c: Header 6 [ 47]: Call-ID: 218437655d848d51367a65487e733ae9@TTTSS [Aug 9 11:45:16] DEBUG[32310] chan_sip.c: Header 7 [ 16]: CSeq: 102 INVITE [Aug 9 11:45:16] DEBUG[32310] chan_sip.c: Header 8 [ 36]: User-Agent: Asterisk PBX 1.8.0-beta2 [Aug 9 11:45:16] DEBUG[32310] chan_sip.c: Header 9 [ 35]: Date: Mon, 09 Aug 2010 08:45:16 GMT [Aug 9 11:45:16] DEBUG[32310] chan_sip.c: Header 10 [ 21]: Session-Expires: 1800 [Aug 9 11:45:16] DEBUG[32310] chan_sip.c: Header 11 [ 10]: Min-SE: 90 [Aug 9 11:45:16] DEBUG[32310] chan_sip.c: Header 12 [ 81]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH [Aug 9 11:45:16] DEBUG[32310] chan_sip.c: Header 13 [ 26]: Supported: replaces, timer [Aug 9 11:45:16] DEBUG[32310] chan_sip.c: Header 14 [ 29]: Content-Type: application/sdp [Aug 9 11:45:16] VERBOSE[32310] chan_sip.c: Reliably Transmitting (no NAT) to 10.21.0.135:5060: INVITE sip:9764701@10.21.0.135:5060 SIP/2.0 Via: SIP/2.0/UDP 10.21.0.146:5061;branch=z9hG4bK7a2ba14b Max-Forwards: 70 From: "Shay HD" ;tag=as63233769 To: Contact: Call-ID: 218437655d848d51367a65487e733ae9@TTTSS CSeq: 102 INVITE User-Agent: Asterisk PBX 1.8.0-beta2 Date: Mon, 09 Aug 2010 08:45:16 GMT Session-Expires: 1800 Min-SE: 90 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Content-Type: application/sdp Content-Length: 289 v=0 o=root 1837581894 1837581894 IN IP4 10.21.0.146 s=Asterisk PBX 1.8.0-beta2 c=IN IP4 10.21.0.146 t=0 0 m=audio 19132 RTP/AVP 8 0 101 a=rtpmap:8 PCMA/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv --- [Aug 9 11:45:16] DEBUG[32310] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #4939 [Aug 9 11:45:16] DEBUG[32310] chan_sip.c: Trying to put 'INVITE sip:' onto UDP socket destined for 10.21.0.135:5060 [Aug 9 11:45:16] VERBOSE[32310] app_dial.c: -- Called 9764701@M1k_Shay [Aug 9 11:45:16] DEBUG[31458] devicestate.c: No provider found, checking channel drivers for SIP - M1k_Shay [Aug 9 11:45:16] DEBUG[31458] chan_sip.c: Checking device state for peer M1k_Shay [Aug 9 11:45:16] DEBUG[31458] devicestate.c: Changing state for SIP/M1k_Shay - state 6 (Ringing) [Aug 9 11:45:16] DEBUG[31458] devicestate.c: device 'SIP/M1k_Shay' state '6' [Aug 9 11:45:16] VERBOSE[31464] chan_sip.c: <--- SIP read from UDP:10.21.0.135:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 10.21.0.146:5061;branch=z9hG4bK7a2ba14b From: "Shay HD" ;tag=as63233769 To: ;tag=1c1640285023 Call-ID: 218437655d848d51367a65487e733ae9@TTTSS CSeq: 102 INVITE Supported: em,timer,replaces,path,resource-priority Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE Server: Audiocodes-Sip-Gateway-/v.5.80A.023.006 Content-Length: 0 <-------------> [Aug 9 11:45:16] DEBUG[31464] chan_sip.c: Header 0 [ 18]: SIP/2.0 100 Trying [Aug 9 11:45:16] DEBUG[31464] chan_sip.c: Header 1 [ 56]: Via: SIP/2.0/UDP 10.21.0.146:5061;branch=z9hG4bK7a2ba14b [Aug 9 11:45:16] DEBUG[31464] chan_sip.c: Header 2 [ 47]: From: "Shay HD" ;tag=as63233769 [Aug 9 11:45:16] DEBUG[31464] chan_sip.c: Header 3 [ 51]: To: ;tag=1c1640285023 [Aug 9 11:45:16] DEBUG[31464] chan_sip.c: Header 4 [ 47]: Call-ID: 218437655d848d51367a65487e733ae9@TTTSS [Aug 9 11:45:16] DEBUG[31464] chan_sip.c: Header 5 [ 16]: CSeq: 102 INVITE [Aug 9 11:45:16] DEBUG[31464] chan_sip.c: Header 6 [ 51]: Supported: em,timer,replaces,path,resource-priority [Aug 9 11:45:16] DEBUG[31464] chan_sip.c: Header 7 [ 86]: Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE [Aug 9 11:45:16] DEBUG[31464] chan_sip.c: Header 8 [ 47]: Server: Audiocodes-Sip-Gateway-/v.5.80A.023.006 [Aug 9 11:45:16] DEBUG[31464] chan_sip.c: Header 9 [ 17]: Content-Length: 0 [Aug 9 11:45:16] DEBUG[31464] chan_sip.c: Header 10 [ 0]: [Aug 9 11:45:16] VERBOSE[31464] chan_sip.c: --- (10 headers 0 lines) --- [Aug 9 11:45:16] DEBUG[31464] chan_sip.c: *** SIP TIMER: Cancelling retransmission #4939 - INVITE (got response) [Aug 9 11:45:16] DEBUG[31464] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '218437655d848d51367a65487e733ae9@TTTSS' Request 102: Found [Aug 9 11:45:16] DEBUG[31464] chan_sip.c: SIP response 100 to standard invite [Aug 9 11:45:16] VERBOSE[31464] chan_sip.c: <--- SIP read from UDP:10.21.0.135:5060 ---> SIP/2.0 180 Ringing Via: SIP/2.0/UDP 10.21.0.146:5061;branch=z9hG4bK7a2ba14b From: "Shay HD" ;tag=as63233769 To: ;tag=1c1640285023 Call-ID: 218437655d848d51367a65487e733ae9@TTTSS CSeq: 102 INVITE Contact: Supported: em,timer,replaces,path,resource-priority Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE Server: Audiocodes-Sip-Gateway-/v.5.80A.023.006 Content-Length: 0 <-------------> [Aug 9 11:45:16] DEBUG[31464] chan_sip.c: Header 0 [ 19]: SIP/2.0 180 Ringing [Aug 9 11:45:16] DEBUG[31464] chan_sip.c: Header 1 [ 56]: Via: SIP/2.0/UDP 10.21.0.146:5061;branch=z9hG4bK7a2ba14b [Aug 9 11:45:16] DEBUG[31464] chan_sip.c: Header 2 [ 47]: From: "Shay HD" ;tag=as63233769 [Aug 9 11:45:16] DEBUG[31464] chan_sip.c: Header 3 [ 51]: To: ;tag=1c1640285023 [Aug 9 11:45:16] DEBUG[31464] chan_sip.c: Header 4 [ 47]: Call-ID: 218437655d848d51367a65487e733ae9@TTTSS [Aug 9 11:45:16] DEBUG[31464] chan_sip.c: Header 5 [ 16]: CSeq: 102 INVITE [Aug 9 11:45:16] DEBUG[31464] chan_sip.c: Header 6 [ 39]: Contact: [Aug 9 11:45:16] DEBUG[31464] chan_sip.c: Header 7 [ 51]: Supported: em,timer,replaces,path,resource-priority [Aug 9 11:45:16] DEBUG[31464] chan_sip.c: Header 8 [ 86]: Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE [Aug 9 11:45:16] DEBUG[31464] chan_sip.c: Header 9 [ 47]: Server: Audiocodes-Sip-Gateway-/v.5.80A.023.006 [Aug 9 11:45:16] DEBUG[31464] chan_sip.c: Header 10 [ 17]: Content-Length: 0 [Aug 9 11:45:16] DEBUG[31464] chan_sip.c: Header 11 [ 0]: [Aug 9 11:45:16] VERBOSE[31464] chan_sip.c: --- (11 headers 0 lines) --- [Aug 9 11:45:16] DEBUG[31464] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '218437655d848d51367a65487e733ae9@TTTSS' Request 102: Found [Aug 9 11:45:16] DEBUG[31464] chan_sip.c: SIP response 180 to standard invite [Aug 9 11:45:16] VERBOSE[32310] app_dial.c: -- SIP/M1k_Shay-0000004c is ringing [Aug 9 11:45:16] DEBUG[32310] rtp_engine.c: Setting early bridge SDP of 'SIP/6000-0000004b' with that of 'SIP/M1k_Shay-0000004c' [Aug 9 11:45:16] VERBOSE[32310] chan_sip.c: <--- Transmitting (no NAT) to 10.13.22.38:5060 ---> SIP/2.0 180 Ringing Via: SIP/2.0/UDP 10.13.22.38:5060;branch=z9hG4bK-386e927a-6fec3060-72318434;received=10.13.22.38;rport=5060 From: "6000";tag=8824b0-26160d0a-13c4-50029-386e927a-488246b-386e927a To: ;tag=as46255de3 Call-ID: 888f10-26160d0a-13c4-50029-386e927a-3b57bcf5-386e927a CSeq: 2 INVITE Server: Asterisk PBX 1.8.0-beta2 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Contact: Content-Length: 0 <------------> [Aug 9 11:45:16] DEBUG[32310] chan_sip.c: Trying to put 'SIP/2.0 180' onto UDP socket destined for 10.13.22.38:5060 [Aug 9 11:45:16] DEBUG[31458] devicestate.c: No provider found, checking channel drivers for SIP - M1k_Shay [Aug 9 11:45:16] DEBUG[31458] chan_sip.c: Checking device state for peer M1k_Shay [Aug 9 11:45:16] DEBUG[31458] devicestate.c: Changing state for SIP/M1k_Shay - state 6 (Ringing) [Aug 9 11:45:16] DEBUG[31458] devicestate.c: device 'SIP/M1k_Shay' state '6' [Aug 9 11:45:19] VERBOSE[31464] chan_sip.c: <--- SIP read from UDP:10.21.0.135:5060 ---> REGISTER sip:10.21.0.146 SIP/2.0 Via: SIP/2.0/UDP 10.21.0.135;branch=z9hG4bKac1701330671 Max-Forwards: 70 From: ;tag=1c1701320911 To: Call-ID: 1144486179131200004539@10.21.0.135 CSeq: 2104 REGISTER Contact: ;expires=180 Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE Expires: 180 User-Agent: Audiocodes-Sip-Gateway-/v.5.80A.023.006 Content-Length: 0 <-------------> [Aug 9 11:45:19] DEBUG[31464] chan_sip.c: Header 0 [ 32]: REGISTER sip:10.21.0.146 SIP/2.0 [Aug 9 11:45:19] DEBUG[31464] chan_sip.c: Header 1 [ 55]: Via: SIP/2.0/UDP 10.21.0.135;branch=z9hG4bKac1701330671 [Aug 9 11:45:19] DEBUG[31464] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Aug 9 11:45:19] DEBUG[31464] chan_sip.c: Header 3 [ 48]: From: ;tag=1c1701320911 [Aug 9 11:45:19] DEBUG[31464] chan_sip.c: Header 4 [ 29]: To: [Aug 9 11:45:19] DEBUG[31464] chan_sip.c: Header 5 [ 43]: Call-ID: 1144486179131200004539@10.21.0.135 [Aug 9 11:45:19] DEBUG[31464] chan_sip.c: Header 6 [ 19]: CSeq: 2104 REGISTER [Aug 9 11:45:19] DEBUG[31464] chan_sip.c: Header 7 [ 51]: Contact: ;expires=180 [Aug 9 11:45:19] DEBUG[31464] chan_sip.c: Header 8 [ 86]: Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE [Aug 9 11:45:19] DEBUG[31464] chan_sip.c: Header 9 [ 12]: Expires: 180 [Aug 9 11:45:19] DEBUG[31464] chan_sip.c: Header 10 [ 51]: User-Agent: Audiocodes-Sip-Gateway-/v.5.80A.023.006 [Aug 9 11:45:19] DEBUG[31464] chan_sip.c: Header 11 [ 17]: Content-Length: 0 [Aug 9 11:45:19] DEBUG[31464] chan_sip.c: Header 12 [ 0]: [Aug 9 11:45:19] VERBOSE[31464] chan_sip.c: --- (12 headers 0 lines) --- [Aug 9 11:45:19] DEBUG[31464] chan_sip.c: **** Received REGISTER (2) - Command in SIP REGISTER [Aug 9 11:45:19] DEBUG[31464] chan_sip.c: Initializing initreq for method REGISTER - callid 1144486179131200004539@10.21.0.135 [Aug 9 11:45:19] DEBUG[31464] netsock2.c: Splitting '10.21.0.135' gives... [Aug 9 11:45:19] DEBUG[31464] netsock2.c: ...host '10.21.0.135' and port '(null)'. [Aug 9 11:45:19] VERBOSE[31464] chan_sip.c: Sending to 10.21.0.135:5060 (no NAT) [Aug 9 11:45:19] DEBUG[31464] res_config_pgsql.c: PostgreSQL RealTime: One or more of the parameters in the config does not pass our validity checks. [Aug 9 11:45:19] DEBUG[31464] res_config_pgsql.c: PostgreSQL RealTime: Result=0xa2953d0 Query: SELECT * FROM sip_buddies WHERE name = '9764700' AND host = 'dynamic' [Aug 9 11:45:19] DEBUG[31464] res_config_pgsql.c: Postgresql RealTime: Could not find any rows in table sip_buddies@asterisk. [Aug 9 11:45:19] DEBUG[31464] res_config_pgsql.c: PostgreSQL RealTime: One or more of the parameters in the config does not pass our validity checks. [Aug 9 11:45:19] DEBUG[32310] res_rtp_asterisk.c: Got RTCP report of 24 bytes [Aug 9 11:45:19] DEBUG[31464] res_config_pgsql.c: PostgreSQL RealTime: Result=0xa2953d0 Query: SELECT * FROM sip_buddies WHERE name = '9764700' [Aug 9 11:45:19] DEBUG[31464] res_config_pgsql.c: Postgresql RealTime: Could not find any rows in table sip_buddies@asterisk. [Aug 9 11:45:19] VERBOSE[31464] chan_sip.c: <--- Transmitting (no NAT) to 10.21.0.135:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 10.21.0.135;branch=z9hG4bKac1701330671;received=10.21.0.135 From: ;tag=1c1701320911 To: Call-ID: 1144486179131200004539@10.21.0.135 CSeq: 2104 REGISTER Server: Asterisk PBX 1.8.0-beta2 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Content-Length: 0 <------------> [Aug 9 11:45:19] DEBUG[31464] chan_sip.c: Trying to put 'SIP/2.0 100' onto UDP socket destined for 10.21.0.135:5060 [Aug 9 11:45:19] VERBOSE[31464] chan_sip.c: <--- Transmitting (no NAT) to 10.21.0.135:5060 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 10.21.0.135;branch=z9hG4bKac1701330671;received=10.21.0.135 From: ;tag=1c1701320911 To: ;tag=as1db86c62 Call-ID: 1144486179131200004539@10.21.0.135 CSeq: 2104 REGISTER Server: Asterisk PBX 1.8.0-beta2 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="491680c7" Content-Length: 0 <------------> [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Trying to put 'SIP/2.0 401' onto UDP socket destined for 10.21.0.135:5060 [Aug 9 11:45:20] VERBOSE[31464] chan_sip.c: Scheduling destruction of SIP dialog '1144486179131200004539@10.21.0.135' in 32000 ms (Method: REGISTER) [Aug 9 11:45:20] NOTICE[31464] chan_sip.c: Registration from '' failed for '10.21.0.135:5060' - No matching peer found [Aug 9 11:45:20] VERBOSE[31464] chan_sip.c: Scheduling destruction of SIP dialog '1144486179131200004539@10.21.0.135' in 32000 ms (Method: REGISTER) [Aug 9 11:45:20] VERBOSE[31464] chan_sip.c: <--- SIP read from UDP:10.21.0.135:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 10.21.0.146:5061;branch=z9hG4bK7a2ba14b From: "Shay HD" ;tag=as63233769 To: ;tag=1c1640285023 Call-ID: 218437655d848d51367a65487e733ae9@TTTSS CSeq: 102 INVITE Contact: Supported: em,replaces,path,resource-priority Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE Require: timer Session-Expires: 1800;refresher=uas Min-SE: 90 Server: Audiocodes-Sip-Gateway-/v.5.80A.023.006 Content-Type: application/sdp Content-Length: 253 v=0 o=AudiocodesGW 1640343580 1640343231 IN IP4 10.21.0.135 s=Phone-Call c=IN IP4 10.21.0.135 t=0 0 m=audio 7760 RTP/AVP 8 101 c=IN IP4 10.21.0.135 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:20 a=sendrecv <-------------> [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Header 1 [ 56]: Via: SIP/2.0/UDP 10.21.0.146:5061;branch=z9hG4bK7a2ba14b [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Header 2 [ 47]: From: "Shay HD" ;tag=as63233769 [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Header 3 [ 51]: To: ;tag=1c1640285023 [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Header 4 [ 47]: Call-ID: 218437655d848d51367a65487e733ae9@TTTSS [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Header 5 [ 16]: CSeq: 102 INVITE [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Header 6 [ 39]: Contact: [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Header 7 [ 45]: Supported: em,replaces,path,resource-priority [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Header 8 [ 86]: Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Header 9 [ 14]: Require: timer [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Header 10 [ 35]: Session-Expires: 1800;refresher=uas [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Header 11 [ 10]: Min-SE: 90 [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Header 12 [ 47]: Server: Audiocodes-Sip-Gateway-/v.5.80A.023.006 [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Header 13 [ 29]: Content-Type: application/sdp [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Header 14 [ 19]: Content-Length: 253 [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Header 15 [ 0]: [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Body 0 [ 3]: v=0 [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Body 1 [ 55]: o=AudiocodesGW 1640343580 1640343231 IN IP4 10.21.0.135 [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Body 2 [ 12]: s=Phone-Call [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Body 3 [ 20]: c=IN IP4 10.21.0.135 [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Body 4 [ 5]: t=0 0 [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Body 5 [ 26]: m=audio 7760 RTP/AVP 8 101 [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Body 6 [ 20]: c=IN IP4 10.21.0.135 [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Body 7 [ 20]: a=rtpmap:8 PCMA/8000 [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Body 8 [ 33]: a=rtpmap:101 telephone-event/8000 [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Body 9 [ 15]: a=fmtp:101 0-15 [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Body 10 [ 10]: a=ptime:20 [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Body 11 [ 10]: a=sendrecv [Aug 9 11:45:20] VERBOSE[31464] chan_sip.c: --- (15 headers 12 lines) --- [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Acked pending invite 102 [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Stopping retransmission on '218437655d848d51367a65487e733ae9@TTTSS' of Request 102: Match Found [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: SIP response 200 to standard invite [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED. [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Processing session-level SDP o=AudiocodesGW 1640343580 1640343231 IN IP4 10.21.0.135... UNSUPPORTED. [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Processing session-level SDP s=Phone-Call... UNSUPPORTED. [Aug 9 11:45:20] DEBUG[31464] netsock2.c: Splitting '10.21.0.135' gives... [Aug 9 11:45:20] DEBUG[31464] netsock2.c: ...host '10.21.0.135' and port '(null)'. [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Processing session-level SDP c=IN IP4 10.21.0.135... OK. [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED. [Aug 9 11:45:20] VERBOSE[31464] chan_sip.c: Found RTP audio format 8 [Aug 9 11:45:20] DEBUG[31464] rtp_engine.c: Setting payload 8 based on m type on 0xb7cd851c [Aug 9 11:45:20] VERBOSE[31464] chan_sip.c: Found RTP audio format 101 [Aug 9 11:45:20] DEBUG[31464] rtp_engine.c: Setting payload 101 based on m type on 0xb7cd851c [Aug 9 11:45:20] DEBUG[31464] netsock2.c: Splitting '10.21.0.135' gives... [Aug 9 11:45:20] DEBUG[31464] netsock2.c: ...host '10.21.0.135' and port '(null)'. [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Processing media-level (audio) SDP c=IN IP4 10.21.0.135... OK. [Aug 9 11:45:20] VERBOSE[31464] chan_sip.c: Found audio description format PCMA for ID 8 [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:8 PCMA/8000... OK. [Aug 9 11:45:20] VERBOSE[31464] chan_sip.c: Found audio description format telephone-event for ID 101 [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK. [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Processing media-level (audio) SDP a=fmtp:101 0-15... UNSUPPORTED. [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Processing media-level (audio) SDP a=ptime:20... OK. [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Processing media-level (audio) SDP a=sendrecv... OK. [Aug 9 11:45:20] DEBUG[31464] rtp_engine.c: Incorporating payload 8 on 0xb7cd851c [Aug 9 11:45:20] DEBUG[31464] rtp_engine.c: Incorporating payload 101 on 0xb7cd851c [Aug 9 11:45:20] VERBOSE[31464] chan_sip.c: Capabilities: us - 0xc (ulaw|alaw), peer - audio=0x8 (alaw)/video=0x0 (nothing)/text=0x0 (nothing), combined - 0x8 (alaw) [Aug 9 11:45:20] VERBOSE[31464] chan_sip.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|) [Aug 9 11:45:20] DEBUG[31464] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0xa2f3460' [Aug 9 11:45:20] VERBOSE[31464] chan_sip.c: Peer audio RTP is at port 10.21.0.135:7760 [Aug 9 11:45:20] DEBUG[31464] rtp_engine.c: Copying payload 8 from 0xb7cd851c to 0xa2f360c [Aug 9 11:45:20] DEBUG[31464] rtp_engine.c: Copying payload 101 from 0xb7cd851c to 0xa2f360c [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Peer doesn't provide T.38 UDPTL [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: We're settling with these formats: 0x8 (alaw) [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: We have an owner, now see if we need to change this call [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Updating call counter for outgoing call [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: build_route: Contact hop: [Aug 9 11:45:20] VERBOSE[31464] chan_sip.c: list_route: hop: [Aug 9 11:45:20] DEBUG[31464] netsock2.c: Splitting '10.21.0.135:5060' gives... [Aug 9 11:45:20] DEBUG[31464] netsock2.c: ...host '10.21.0.135' and port '5060'. [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Session-Expires: 1800 [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Refresher: UAS [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Session timer started: 4944 - 218437655d848d51367a65487e733ae9@TTTSS [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Strict routing enforced for session 218437655d848d51367a65487e733ae9@TTTSS [Aug 9 11:45:20] VERBOSE[31464] chan_sip.c: set_destination: Parsing for address/port to send to [Aug 9 11:45:20] DEBUG[31464] netsock2.c: Splitting '10.21.0.135:5060' gives... [Aug 9 11:45:20] DEBUG[31464] netsock2.c: ...host '10.21.0.135' and port '5060'. [Aug 9 11:45:20] VERBOSE[31464] chan_sip.c: set_destination: set destination to 10.21.0.135:5060 [Aug 9 11:45:20] VERBOSE[31464] chan_sip.c: Transmitting (no NAT) to 10.21.0.135:5060: ACK sip:9764701@10.21.0.135:5060 SIP/2.0 Via: SIP/2.0/UDP 10.21.0.146:5061;branch=z9hG4bK5e75270f Max-Forwards: 70 From: "Shay HD" ;tag=as63233769 To: ;tag=1c1640285023 Contact: Call-ID: 218437655d848d51367a65487e733ae9@TTTSS CSeq: 102 ACK User-Agent: Asterisk PBX 1.8.0-beta2 Content-Length: 0 --- [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Trying to put 'ACK sip:976' onto UDP socket destined for 10.21.0.135:5060 [Aug 9 11:45:20] DEBUG[31458] devicestate.c: No provider found, checking channel drivers for SIP - M1k_Shay [Aug 9 11:45:20] DEBUG[31458] chan_sip.c: Checking device state for peer M1k_Shay [Aug 9 11:45:20] DEBUG[31458] devicestate.c: Changing state for SIP/M1k_Shay - state 2 (In use) [Aug 9 11:45:20] DEBUG[31458] devicestate.c: device 'SIP/M1k_Shay' state '2' [Aug 9 11:45:20] VERBOSE[32310] app_dial.c: -- SIP/M1k_Shay-0000004c answered SIP/6000-0000004b [Aug 9 11:45:20] DEBUG[32310] rtp_engine.c: Setting early bridge SDP of 'SIP/6000-0000004b' with that of 'SIP/M1k_Shay-0000004c' [Aug 9 11:45:20] DEBUG[32310] chan_sip.c: SIP answering channel: SIP/6000-0000004b [Aug 9 11:45:20] DEBUG[32310] res_rtp_asterisk.c: Setting the marker bit due to a source update [Aug 9 11:45:20] DEBUG[32310] chan_sip.c: Setting framing from config on incoming call [Aug 9 11:45:20] DEBUG[32310] chan_sip.c: ** Our capability: 0x8 (alaw) Video flag: True Text flag: True [Aug 9 11:45:20] DEBUG[32310] chan_sip.c: ** Our prefcodec: 0x0 (nothing) [Aug 9 11:45:20] VERBOSE[32310] chan_sip.c: Audio is at 5061 [Aug 9 11:45:20] VERBOSE[32310] chan_sip.c: Adding codec 0x8 (alaw) to SDP [Aug 9 11:45:20] VERBOSE[32310] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP [Aug 9 11:45:20] DEBUG[32310] chan_sip.c: -- Done with adding codecs to SDP [Aug 9 11:45:20] DEBUG[32310] chan_sip.c: Done building SDP. Settling with this capability: 0x8 (alaw) [Aug 9 11:45:20] VERBOSE[32310] chan_sip.c: <--- Reliably Transmitting (no NAT) to 10.13.22.38:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 10.13.22.38:5060;branch=z9hG4bK-386e927a-6fec3060-72318434;received=10.13.22.38;rport=5060 From: "6000";tag=8824b0-26160d0a-13c4-50029-386e927a-488246b-386e927a To: ;tag=as46255de3 Call-ID: 888f10-26160d0a-13c4-50029-386e927a-3b57bcf5-386e927a CSeq: 2 INVITE Server: Asterisk PBX 1.8.0-beta2 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Contact: Content-Type: application/sdp Content-Length: 265 v=0 o=root 1086490089 1086490089 IN IP4 10.21.0.146 s=Asterisk PBX 1.8.0-beta2 c=IN IP4 10.21.0.146 t=0 0 m=audio 14610 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv <------------> [Aug 9 11:45:20] DEBUG[32310] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #4945 [Aug 9 11:45:20] DEBUG[32310] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 10.13.22.38:5060 [Aug 9 11:45:20] DEBUG[32310] features.c: bridge answer set, chan answer set [Aug 9 11:45:20] DEBUG[32310] res_rtp_asterisk.c: Setting the marker bit due to a source update [Aug 9 11:45:20] DEBUG[32310] res_rtp_asterisk.c: Setting the marker bit due to a source update [Aug 9 11:45:20] VERBOSE[32310] rtp_engine.c: -- Remotely bridging SIP/6000-0000004b and SIP/M1k_Shay-0000004c [Aug 9 11:45:20] DEBUG[32310] chan_sip.c: Deferring reinvite on SIP '888f10-26160d0a-13c4-50029-386e927a-3b57bcf5-386e927a' - It's audio will be redirected to IP 10.21.0.135:7760 [Aug 9 11:45:20] DEBUG[32310] chan_sip.c: Sending reinvite on SIP '218437655d848d51367a65487e733ae9@TTTSS' - It's audio soon redirected to IP 10.13.22.38:4000 [Aug 9 11:45:20] DEBUG[32310] chan_sip.c: Strict routing enforced for session 218437655d848d51367a65487e733ae9@TTTSS [Aug 9 11:45:20] VERBOSE[32310] chan_sip.c: set_destination: Parsing for address/port to send to [Aug 9 11:45:20] DEBUG[32310] netsock2.c: Splitting '10.21.0.135:5060' gives... [Aug 9 11:45:20] DEBUG[32310] netsock2.c: ...host '10.21.0.135' and port '5060'. [Aug 9 11:45:20] VERBOSE[32310] chan_sip.c: set_destination: set destination to 10.21.0.135:5060 [Aug 9 11:45:20] DEBUG[32310] chan_sip.c: ** Our capability: 0x8 (alaw) Video flag: True Text flag: True [Aug 9 11:45:20] DEBUG[32310] chan_sip.c: ** Our prefcodec: 0x8 (alaw) [Aug 9 11:45:20] VERBOSE[32310] chan_sip.c: Audio is at 5061 [Aug 9 11:45:20] VERBOSE[32310] chan_sip.c: Adding codec 0x8 (alaw) to SDP [Aug 9 11:45:20] VERBOSE[32310] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP [Aug 9 11:45:20] DEBUG[32310] chan_sip.c: -- Done with adding codecs to SDP [Aug 9 11:45:20] DEBUG[32310] chan_sip.c: Done building SDP. Settling with this capability: 0x8 (alaw) [Aug 9 11:45:20] DEBUG[32310] chan_sip.c: Initializing already initialized SIP dialog 218437655d848d51367a65487e733ae9@TTTSS (presumably reinvite) [Aug 9 11:45:20] DEBUG[32310] chan_sip.c: Header 0 [ 43]: INVITE sip:9764701@10.21.0.135:5060 SIP/2.0 [Aug 9 11:45:20] DEBUG[32310] chan_sip.c: Header 1 [ 56]: Via: SIP/2.0/UDP 10.21.0.146:5061;branch=z9hG4bK603dd32b [Aug 9 11:45:20] DEBUG[32310] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Aug 9 11:45:20] DEBUG[32310] chan_sip.c: Header 3 [ 47]: From: "Shay HD" ;tag=as63233769 [Aug 9 11:45:20] DEBUG[32310] chan_sip.c: Header 4 [ 51]: To: ;tag=1c1640285023 [Aug 9 11:45:20] DEBUG[32310] chan_sip.c: Header 5 [ 36]: Contact: [Aug 9 11:45:20] DEBUG[32310] chan_sip.c: Header 6 [ 47]: Call-ID: 218437655d848d51367a65487e733ae9@TTTSS [Aug 9 11:45:20] DEBUG[32310] chan_sip.c: Header 7 [ 16]: CSeq: 103 INVITE [Aug 9 11:45:20] DEBUG[32310] chan_sip.c: Header 8 [ 36]: User-Agent: Asterisk PBX 1.8.0-beta2 [Aug 9 11:45:20] DEBUG[32310] chan_sip.c: Header 9 [ 14]: Require: timer [Aug 9 11:45:20] DEBUG[32310] chan_sip.c: Header 10 [ 35]: Session-Expires: 1800;refresher=uas [Aug 9 11:45:20] DEBUG[32310] chan_sip.c: Header 11 [ 10]: Min-SE: 90 [Aug 9 11:45:20] DEBUG[32310] chan_sip.c: Header 12 [ 81]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH [Aug 9 11:45:20] DEBUG[31458] devicestate.c: No provider found, checking channel drivers for SIP - M1k_Shay [Aug 9 11:45:20] DEBUG[31458] chan_sip.c: Checking device state for peer M1k_Shay [Aug 9 11:45:20] DEBUG[31458] devicestate.c: Changing state for SIP/M1k_Shay - state 2 (In use) [Aug 9 11:45:20] DEBUG[31458] devicestate.c: device 'SIP/M1k_Shay' state '2' [Aug 9 11:45:20] DEBUG[31458] devicestate.c: No provider found, checking channel drivers for SIP - 6000 [Aug 9 11:45:20] DEBUG[31458] chan_sip.c: Checking device state for peer 6000 [Aug 9 11:45:20] DEBUG[31458] devicestate.c: Changing state for SIP/6000 - state 3 (Busy) [Aug 9 11:45:20] DEBUG[31458] devicestate.c: device 'SIP/6000' state '3' [Aug 9 11:45:20] VERBOSE[31464] chan_sip.c: <--- SIP read from UDP:10.13.22.38:5060 ---> ACK sip:99764701@10.21.0.146:5061 SIP/2.0 From: "6000";tag=8824b0-26160d0a-13c4-50029-386e927a-488246b-386e927a To: ;tag=as46255de3 Call-ID: 888f10-26160d0a-13c4-50029-386e927a-3b57bcf5-386e927a CSeq: 2 ACK Via: SIP/2.0/UDP 10.13.22.38:5060;rport;branch=z9hG4bK-386e9280-6fec445d-4a786176 Max-Forwards: 70 User-Agent: AUDC-IPPhone/1.2.1_build_6 (320HD;00908F1ED22E) Contact: Authorization: Digest username="6000",realm="asterisk",nonce="2a70fa38",uri="sip:99764701@10.21.0.146:5061",response="824d5969c04bf042135ff9b5bbd3a9e5",algorithm=MD5 Content-Length: 0 <-------------> [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Header 0 [ 41]: ACK sip:99764701@10.21.0.146:5061 SIP/2.0 [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Header 1 [ 91]: From: "6000";tag=8824b0-26160d0a-13c4-50029-386e927a-488246b-386e927a [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Header 2 [ 50]: To: ;tag=as46255de3 [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Header 3 [ 62]: Call-ID: 888f10-26160d0a-13c4-50029-386e927a-3b57bcf5-386e927a [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Header 4 [ 11]: CSeq: 2 ACK [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Header 5 [ 81]: Via: SIP/2.0/UDP 10.13.22.38:5060;rport;branch=z9hG4bK-386e9280-6fec445d-4a786176 [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Header 6 [ 16]: Max-Forwards: 70 [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Header 7 [ 59]: User-Agent: AUDC-IPPhone/1.2.1_build_6 (320HD;00908F1ED22E) [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Header 8 [ 31]: Contact: [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Header 9 [165]: Authorization: Digest username="6000",realm="asterisk",nonce="2a70fa38",uri="sip:99764701@10.21.0.146:5061",response="824d5969c04bf042135ff9b5bbd3a9e5",algorithm=MD5 [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Header 10 [ 17]: Content-Length: 0 [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Header 11 [ 0]: [Aug 9 11:45:20] VERBOSE[31464] chan_sip.c: --- (11 headers 0 lines) --- [Aug 9 11:45:20] DEBUG[32310] chan_sip.c: Header 13 [ 26]: Supported: replaces, timer [Aug 9 11:45:20] DEBUG[32310] chan_sip.c: Header 14 [ 52]: X-asterisk-Info: SIP re-invite (External RTP bridge) [Aug 9 11:45:20] DEBUG[32310] chan_sip.c: Header 15 [ 29]: Content-Type: application/sdp [Aug 9 11:45:20] VERBOSE[32310] chan_sip.c: Reliably Transmitting (no NAT) to 10.21.0.135:5060: INVITE sip:9764701@10.21.0.135:5060 SIP/2.0 Via: SIP/2.0/UDP 10.21.0.146:5061;branch=z9hG4bK603dd32b Max-Forwards: 70 From: "Shay HD" ;tag=as63233769 To: ;tag=1c1640285023 Contact: Call-ID: 218437655d848d51367a65487e733ae9@TTTSS CSeq: 103 INVITE User-Agent: Asterisk PBX 1.8.0-beta2 Require: timer Session-Expires: 1800;refresher=uas Min-SE: 90 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer X-asterisk-Info: SIP re-invite (External RTP bridge) Content-Type: application/sdp Content-Length: 264 v=0 o=root 1837581894 1837581895 IN IP4 10.13.22.38 s=Asterisk PBX 1.8.0-beta2 c=IN IP4 10.13.22.38 t=0 0 m=audio 4000 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv --- [Aug 9 11:45:20] DEBUG[32310] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #4947 [Aug 9 11:45:20] DEBUG[32310] chan_sip.c: Trying to put 'INVITE sip:' onto UDP socket destined for 10.21.0.135:5060 [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: **** Received ACK (6) - Command in SIP ACK [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #4945 [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Stopping retransmission on '888f10-26160d0a-13c4-50029-386e927a-3b57bcf5-386e927a' of Response 2: Match Found [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Sending pending reinvite on '888f10-26160d0a-13c4-50029-386e927a-3b57bcf5-386e927a' [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Strict routing enforced for session 888f10-26160d0a-13c4-50029-386e927a-3b57bcf5-386e927a [Aug 9 11:45:20] VERBOSE[31464] chan_sip.c: set_destination: Parsing for address/port to send to [Aug 9 11:45:20] DEBUG[31464] netsock2.c: Splitting '10.13.22.38' gives... [Aug 9 11:45:20] DEBUG[31464] netsock2.c: ...host '10.13.22.38' and port '(null)'. [Aug 9 11:45:20] VERBOSE[31464] chan_sip.c: set_destination: set destination to 10.13.22.38:5060 [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: ** Our capability: 0x8 (alaw) Video flag: True Text flag: True [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: ** Our prefcodec: 0x0 (nothing) [Aug 9 11:45:20] VERBOSE[31464] chan_sip.c: Audio is at 5061 [Aug 9 11:45:20] VERBOSE[31464] chan_sip.c: Adding codec 0x8 (alaw) to SDP [Aug 9 11:45:20] VERBOSE[31464] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: -- Done with adding codecs to SDP [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Done building SDP. Settling with this capability: 0x8 (alaw) [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Initializing already initialized SIP dialog 888f10-26160d0a-13c4-50029-386e927a-3b57bcf5-386e927a (presumably reinvite) [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Header 0 [ 35]: INVITE sip:6000@10.13.22.38 SIP/2.0 [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Header 1 [ 62]: Via: SIP/2.0/UDP 10.21.0.146:5061;branch=z9hG4bK113c3859;rport [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Header 3 [ 52]: From: ;tag=as46255de3 [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Header 4 [ 89]: To: "6000";tag=8824b0-26160d0a-13c4-50029-386e927a-488246b-386e927a [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Header 5 [ 40]: Contact: [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Header 6 [ 62]: Call-ID: 888f10-26160d0a-13c4-50029-386e927a-3b57bcf5-386e927a [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Header 7 [ 16]: CSeq: 102 INVITE [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Header 8 [ 36]: User-Agent: Asterisk PBX 1.8.0-beta2 [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Header 9 [ 81]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Header 10 [ 26]: Supported: replaces, timer [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Header 11 [ 52]: X-asterisk-Info: SIP re-invite (External RTP bridge) [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Header 12 [ 29]: Content-Type: application/sdp [Aug 9 11:45:20] VERBOSE[31464] chan_sip.c: Reliably Transmitting (no NAT) to 10.13.22.38:5060: INVITE sip:6000@10.13.22.38 SIP/2.0 Via: SIP/2.0/UDP 10.21.0.146:5061;branch=z9hG4bK113c3859;rport Max-Forwards: 70 From: ;tag=as46255de3 To: "6000";tag=8824b0-26160d0a-13c4-50029-386e927a-488246b-386e927a Contact: Call-ID: 888f10-26160d0a-13c4-50029-386e927a-3b57bcf5-386e927a CSeq: 102 INVITE User-Agent: Asterisk PBX 1.8.0-beta2 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer X-asterisk-Info: SIP re-invite (External RTP bridge) Content-Type: application/sdp Content-Length: 264 v=0 o=root 1086490089 1086490090 IN IP4 10.21.0.135 s=Asterisk PBX 1.8.0-beta2 c=IN IP4 10.21.0.135 t=0 0 m=audio 7760 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv --- [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #4948 [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Trying to put 'INVITE sip:' onto UDP socket destined for 10.13.22.38:5060 [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '218437655d848d51367a65487e733ae9@TTTSS' Method: INVITE [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '888f10-26160d0a-13c4-50029-386e927a-3b57bcf5-386e927a' Method: ACK [Aug 9 11:45:20] VERBOSE[31464] chan_sip.c: <--- SIP read from UDP:10.21.0.135:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 10.21.0.146:5061;branch=z9hG4bK603dd32b From: "Shay HD" ;tag=as63233769 To: ;tag=1c1640285023 Call-ID: 218437655d848d51367a65487e733ae9@TTTSS CSeq: 103 INVITE Contact: Supported: em,replaces,path,resource-priority Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE Require: timer Session-Expires: 1800;refresher=uas Min-SE: 90 Server: Audiocodes-Sip-Gateway-/v.5.80A.023.006 Content-Type: application/sdp Content-Length: 253 v=0 o=AudiocodesGW 1640343580 1640343232 IN IP4 10.21.0.135 s=Phone-Call c=IN IP4 10.21.0.135 t=0 0 m=audio 7760 RTP/AVP 8 101 c=IN IP4 10.21.0.135 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:20 a=sendrecv <-------------> [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Header 1 [ 56]: Via: SIP/2.0/UDP 10.21.0.146:5061;branch=z9hG4bK603dd32b [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Header 2 [ 47]: From: "Shay HD" ;tag=as63233769 [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Header 3 [ 51]: To: ;tag=1c1640285023 [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Header 4 [ 47]: Call-ID: 218437655d848d51367a65487e733ae9@TTTSS [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Header 5 [ 16]: CSeq: 103 INVITE [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Header 6 [ 39]: Contact: [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Header 7 [ 45]: Supported: em,replaces,path,resource-priority [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Header 8 [ 86]: Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Header 9 [ 14]: Require: timer [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Header 10 [ 35]: Session-Expires: 1800;refresher=uas [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Header 11 [ 10]: Min-SE: 90 [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Header 12 [ 47]: Server: Audiocodes-Sip-Gateway-/v.5.80A.023.006 [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Header 13 [ 29]: Content-Type: application/sdp [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Header 14 [ 19]: Content-Length: 253 [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Header 15 [ 0]: [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Body 0 [ 3]: v=0 [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Body 1 [ 55]: o=AudiocodesGW 1640343580 1640343232 IN IP4 10.21.0.135 [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Body 2 [ 12]: s=Phone-Call [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Body 3 [ 20]: c=IN IP4 10.21.0.135 [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Body 4 [ 5]: t=0 0 [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Body 5 [ 26]: m=audio 7760 RTP/AVP 8 101 [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Body 6 [ 20]: c=IN IP4 10.21.0.135 [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Body 7 [ 20]: a=rtpmap:8 PCMA/8000 [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Body 8 [ 33]: a=rtpmap:101 telephone-event/8000 [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Body 9 [ 15]: a=fmtp:101 0-15 [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Body 10 [ 10]: a=ptime:20 [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Body 11 [ 10]: a=sendrecv [Aug 9 11:45:20] VERBOSE[31464] chan_sip.c: --- (15 headers 12 lines) --- [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Acked pending invite 103 [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #4947 [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Stopping retransmission on '218437655d848d51367a65487e733ae9@TTTSS' of Request 103: Match Found [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: SIP response 200 to RE-invite on outgoing call 218437655d848d51367a65487e733ae9@TTTSS [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED. [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Processing session-level SDP o=AudiocodesGW 1640343580 1640343232 IN IP4 10.21.0.135... UNSUPPORTED. [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Processing session-level SDP s=Phone-Call... UNSUPPORTED. [Aug 9 11:45:20] DEBUG[31464] netsock2.c: Splitting '10.21.0.135' gives... [Aug 9 11:45:20] DEBUG[31464] netsock2.c: ...host '10.21.0.135' and port '(null)'. [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Processing session-level SDP c=IN IP4 10.21.0.135... OK. [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Processing session-level SDP t=0 0... UNSUPPORTED. [Aug 9 11:45:20] VERBOSE[31464] chan_sip.c: Found RTP audio format 8 [Aug 9 11:45:20] DEBUG[31464] rtp_engine.c: Setting payload 8 based on m type on 0xb7cd851c [Aug 9 11:45:20] VERBOSE[31464] chan_sip.c: Found RTP audio format 101 [Aug 9 11:45:20] DEBUG[31464] rtp_engine.c: Setting payload 101 based on m type on 0xb7cd851c [Aug 9 11:45:20] DEBUG[31464] netsock2.c: Splitting '10.21.0.135' gives... [Aug 9 11:45:20] DEBUG[31464] netsock2.c: ...host '10.21.0.135' and port '(null)'. [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Processing media-level (audio) SDP c=IN IP4 10.21.0.135... OK. [Aug 9 11:45:20] VERBOSE[31464] chan_sip.c: Found audio description format PCMA for ID 8 [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:8 PCMA/8000... OK. [Aug 9 11:45:20] VERBOSE[31464] chan_sip.c: Found audio description format telephone-event for ID 101 [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Processing media-level (audio) SDP a=rtpmap:101 telephone-event/8000... OK. [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Processing media-level (audio) SDP a=fmtp:101 0-15... UNSUPPORTED. [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Processing media-level (audio) SDP a=ptime:20... OK. [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Processing media-level (audio) SDP a=sendrecv... OK. [Aug 9 11:45:20] DEBUG[31464] rtp_engine.c: Incorporating payload 8 on 0xb7cd851c [Aug 9 11:45:20] DEBUG[31464] rtp_engine.c: Incorporating payload 101 on 0xb7cd851c [Aug 9 11:45:20] VERBOSE[31464] chan_sip.c: Capabilities: us - 0xc (ulaw|alaw), peer - audio=0x8 (alaw)/video=0x0 (nothing)/text=0x0 (nothing), combined - 0x8 (alaw) [Aug 9 11:45:20] VERBOSE[31464] chan_sip.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|) [Aug 9 11:45:20] DEBUG[31464] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0xa2f3460' [Aug 9 11:45:20] VERBOSE[31464] chan_sip.c: Peer audio RTP is at port 10.21.0.135:7760 [Aug 9 11:45:20] DEBUG[31464] rtp_engine.c: Copying payload 8 from 0xb7cd851c to 0xa2f360c [Aug 9 11:45:20] DEBUG[31464] rtp_engine.c: Copying payload 101 from 0xb7cd851c to 0xa2f360c [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Peer doesn't provide T.38 UDPTL [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: We're settling with these formats: 0x8 (alaw) [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: We have an owner, now see if we need to change this call [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Updating call counter for outgoing call [Aug 9 11:45:20] DEBUG[31464] netsock2.c: Splitting '10.21.0.135:5060' gives... [Aug 9 11:45:20] DEBUG[31464] netsock2.c: ...host '10.21.0.135' and port '5060'. [Aug 9 11:45:20] DEBUG[31458] devicestate.c: No provider found, checking channel drivers for SIP - M1k_Shay [Aug 9 11:45:20] DEBUG[31458] chan_sip.c: Checking device state for peer M1k_Shay [Aug 9 11:45:20] DEBUG[31458] devicestate.c: Changing state for SIP/M1k_Shay - state 2 (In use) [Aug 9 11:45:20] DEBUG[31458] devicestate.c: device 'SIP/M1k_Shay' state '2' [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Strict routing enforced for session 218437655d848d51367a65487e733ae9@TTTSS [Aug 9 11:45:20] VERBOSE[31464] chan_sip.c: set_destination: Parsing for address/port to send to [Aug 9 11:45:20] DEBUG[31464] netsock2.c: Splitting '10.21.0.135:5060' gives... [Aug 9 11:45:20] DEBUG[31464] netsock2.c: ...host '10.21.0.135' and port '5060'. [Aug 9 11:45:20] VERBOSE[31464] chan_sip.c: set_destination: set destination to 10.21.0.135:5060 [Aug 9 11:45:20] VERBOSE[31464] chan_sip.c: Transmitting (no NAT) to 10.21.0.135:5060: ACK sip:9764701@10.21.0.135:5060 SIP/2.0 Via: SIP/2.0/UDP 10.21.0.146:5061;branch=z9hG4bK1e6725a5 Max-Forwards: 70 From: "Shay HD" ;tag=as63233769 To: ;tag=1c1640285023 Contact: Call-ID: 218437655d848d51367a65487e733ae9@TTTSS CSeq: 103 ACK User-Agent: Asterisk PBX 1.8.0-beta2 Content-Length: 0 --- [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Trying to put 'ACK sip:976' onto UDP socket destined for 10.21.0.135:5060 [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '218437655d848d51367a65487e733ae9@TTTSS' Method: INVITE [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '888f10-26160d0a-13c4-50029-386e927a-3b57bcf5-386e927a' Method: ACK [Aug 9 11:45:20] VERBOSE[31464] chan_sip.c: <--- SIP read from UDP:10.13.22.38:5060 ---> SIP/2.0 200 OK From: ;tag=as46255de3 To: "6000";tag=8824b0-26160d0a-13c4-50029-386e927a-488246b-386e927a Call-ID: 888f10-26160d0a-13c4-50029-386e927a-3b57bcf5-386e927a CSeq: 102 INVITE Via: SIP/2.0/UDP 10.21.0.146:5061;rport=5061;branch=z9hG4bK113c3859 Supported: replaces,100rel User-Agent: AUDC-IPPhone/1.2.1_build_6 (320HD;00908F1ED22E) Contact: Content-Type: application/sdp Content-Length: 200 v=0 o=6000 946770842 946770842 IN IP4 10.13.22.38 s=- c=IN IP4 10.13.22.38 t=0 0 m=audio 4000 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000 a=ptime:20 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 <-------------> [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Header 1 [ 52]: From: ;tag=as46255de3 [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Header 2 [ 89]: To: "6000";tag=8824b0-26160d0a-13c4-50029-386e927a-488246b-386e927a [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Header 3 [ 62]: Call-ID: 888f10-26160d0a-13c4-50029-386e927a-3b57bcf5-386e927a [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Header 4 [ 16]: CSeq: 102 INVITE [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Header 5 [ 67]: Via: SIP/2.0/UDP 10.21.0.146:5061;rport=5061;branch=z9hG4bK113c3859 [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Header 6 [ 26]: Supported: replaces,100rel [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Header 7 [ 59]: User-Agent: AUDC-IPPhone/1.2.1_build_6 (320HD;00908F1ED22E) [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Header 8 [ 31]: Contact: [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Header 9 [ 29]: Content-Type: application/sdp [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Header 10 [ 19]: Content-Length: 200 [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Header 11 [ 0]: [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Body 0 [ 3]: v=0 [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Body 1 [ 45]: o=6000 946770842 946770842 IN IP4 10.13.22.38 [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Body 2 [ 3]: s=- [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Body 3 [ 20]: c=IN IP4 10.13.22.38 [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Body 4 [ 5]: t=0 0 [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Body 5 [ 26]: m=audio 4000 RTP/AVP 8 101 [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Body 6 [ 20]: a=rtpmap:8 PCMA/8000 [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Body 7 [ 10]: a=ptime:20 [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Body 8 [ 33]: a=rtpmap:101 telephone-event/8000 [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Body 9 [ 15]: a=fmtp:101 0-15 [Aug 9 11:45:20] VERBOSE[31464] chan_sip.c: --- (11 headers 10 lines) --- [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Acked pending invite 102 [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #4948 [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Stopping retransmission on '888f10-26160d0a-13c4-50029-386e927a-3b57bcf5-386e927a' of Request 102: Match Found [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: SIP response 200 to RE-invite on outgoing call 888f10-26160d0a-13c4-50029-386e927a-3b57bcf5-386e927a [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED. [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Call 888f10-26160d0a-13c4-50029-386e927a-3b57bcf5-386e927a responded to our reinvite without changing SDP version; ignoring SDP. [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Updating call counter for incoming call [Aug 9 11:45:20] DEBUG[31464] netsock2.c: Splitting '10.13.22.38' gives... [Aug 9 11:45:20] DEBUG[31464] netsock2.c: ...host '10.13.22.38' and port '(null)'. [Aug 9 11:45:20] DEBUG[31458] devicestate.c: No provider found, checking channel drivers for SIP - 6000 [Aug 9 11:45:20] DEBUG[31458] chan_sip.c: Checking device state for peer 6000 [Aug 9 11:45:20] DEBUG[31458] devicestate.c: Changing state for SIP/6000 - state 3 (Busy) [Aug 9 11:45:20] DEBUG[31458] devicestate.c: device 'SIP/6000' state '3' [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Strict routing enforced for session 888f10-26160d0a-13c4-50029-386e927a-3b57bcf5-386e927a [Aug 9 11:45:20] VERBOSE[31464] chan_sip.c: set_destination: Parsing for address/port to send to [Aug 9 11:45:20] DEBUG[31464] netsock2.c: Splitting '10.13.22.38' gives... [Aug 9 11:45:20] DEBUG[31464] netsock2.c: ...host '10.13.22.38' and port '(null)'. [Aug 9 11:45:20] VERBOSE[31464] chan_sip.c: set_destination: set destination to 10.13.22.38:5060 [Aug 9 11:45:20] VERBOSE[31464] chan_sip.c: Transmitting (no NAT) to 10.13.22.38:5060: ACK sip:6000@10.13.22.38 SIP/2.0 Via: SIP/2.0/UDP 10.21.0.146:5061;branch=z9hG4bK6cd993e3;rport Max-Forwards: 70 From: ;tag=as46255de3 To: "6000";tag=8824b0-26160d0a-13c4-50029-386e927a-488246b-386e927a Contact: Call-ID: 888f10-26160d0a-13c4-50029-386e927a-3b57bcf5-386e927a CSeq: 102 ACK User-Agent: Asterisk PBX 1.8.0-beta2 Content-Length: 0 --- [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Trying to put 'ACK sip:600' onto UDP socket destined for 10.13.22.38:5060 [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '218437655d848d51367a65487e733ae9@TTTSS' Method: INVITE [Aug 9 11:45:20] DEBUG[31464] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '888f10-26160d0a-13c4-50029-386e927a-3b57bcf5-386e927a' Method: ACK [Aug 9 11:45:21] DEBUG[31464] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '218437655d848d51367a65487e733ae9@TTTSS' Method: INVITE [Aug 9 11:45:21] DEBUG[31464] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '888f10-26160d0a-13c4-50029-386e927a-3b57bcf5-386e927a' Method: ACK [Aug 9 11:45:22] DEBUG[31464] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '218437655d848d51367a65487e733ae9@TTTSS' Method: INVITE [Aug 9 11:45:22] DEBUG[31464] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '888f10-26160d0a-13c4-50029-386e927a-3b57bcf5-386e927a' Method: ACK [Aug 9 11:45:23] DEBUG[31464] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '218437655d848d51367a65487e733ae9@TTTSS' Method: INVITE [Aug 9 11:45:23] DEBUG[31464] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '888f10-26160d0a-13c4-50029-386e927a-3b57bcf5-386e927a' Method: ACK [Aug 9 11:45:24] DEBUG[31464] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '218437655d848d51367a65487e733ae9@TTTSS' Method: INVITE [Aug 9 11:45:24] DEBUG[31464] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '888f10-26160d0a-13c4-50029-386e927a-3b57bcf5-386e927a' Method: ACK [Aug 9 11:45:25] DEBUG[31464] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '218437655d848d51367a65487e733ae9@TTTSS' Method: INVITE [Aug 9 11:45:25] DEBUG[31464] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '888f10-26160d0a-13c4-50029-386e927a-3b57bcf5-386e927a' Method: ACK [Aug 9 11:45:26] DEBUG[31464] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '218437655d848d51367a65487e733ae9@TTTSS' Method: INVITE [Aug 9 11:45:26] DEBUG[31464] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '888f10-26160d0a-13c4-50029-386e927a-3b57bcf5-386e927a' Method: ACK [Aug 9 11:45:27] DEBUG[31464] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '218437655d848d51367a65487e733ae9@TTTSS' Method: INVITE [Aug 9 11:45:27] DEBUG[31464] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '888f10-26160d0a-13c4-50029-386e927a-3b57bcf5-386e927a' Method: ACK [Aug 9 11:45:28] DEBUG[31464] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '218437655d848d51367a65487e733ae9@TTTSS' Method: INVITE [Aug 9 11:45:28] DEBUG[31464] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '888f10-26160d0a-13c4-50029-386e927a-3b57bcf5-386e927a' Method: ACK [Aug 9 11:45:29] DEBUG[31464] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '218437655d848d51367a65487e733ae9@TTTSS' Method: INVITE [Aug 9 11:45:29] DEBUG[31464] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '888f10-26160d0a-13c4-50029-386e927a-3b57bcf5-386e927a' Method: ACK [Aug 9 11:45:30] DEBUG[31464] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '218437655d848d51367a65487e733ae9@TTTSS' Method: INVITE [Aug 9 11:45:30] DEBUG[31464] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '888f10-26160d0a-13c4-50029-386e927a-3b57bcf5-386e927a' Method: ACK [Aug 9 11:45:31] DEBUG[31464] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '218437655d848d51367a65487e733ae9@TTTSS' Method: INVITE [Aug 9 11:45:31] DEBUG[31464] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '888f10-26160d0a-13c4-50029-386e927a-3b57bcf5-386e927a' Method: ACK [Aug 9 11:45:32] DEBUG[31464] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '218437655d848d51367a65487e733ae9@TTTSS' Method: INVITE [Aug 9 11:45:32] DEBUG[31464] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '888f10-26160d0a-13c4-50029-386e927a-3b57bcf5-386e927a' Method: ACK [Aug 9 11:45:33] DEBUG[31464] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '218437655d848d51367a65487e733ae9@TTTSS' Method: INVITE [Aug 9 11:45:33] DEBUG[31464] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '888f10-26160d0a-13c4-50029-386e927a-3b57bcf5-386e927a' Method: ACK [Aug 9 11:45:34] DEBUG[31464] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '218437655d848d51367a65487e733ae9@TTTSS' Method: INVITE [Aug 9 11:45:34] DEBUG[31464] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '888f10-26160d0a-13c4-50029-386e927a-3b57bcf5-386e927a' Method: ACK [Aug 9 11:45:35] DEBUG[31464] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '218437655d848d51367a65487e733ae9@TTTSS' Method: INVITE [Aug 9 11:45:35] DEBUG[31464] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '888f10-26160d0a-13c4-50029-386e927a-3b57bcf5-386e927a' Method: ACK [Aug 9 11:45:35] VERBOSE[31464] chan_sip.c: <--- SIP read from UDP:10.21.0.135:5060 ---> BYE sip:6000@10.21.0.146:5061 SIP/2.0 Via: SIP/2.0/UDP 10.21.0.135;branch=z9hG4bKac1967818995 Max-Forwards: 70 From: ;tag=1c1640285023 To: "Shay HD" ;tag=as63233769 Call-ID: 218437655d848d51367a65487e733ae9@TTTSS CSeq: 1 BYE Supported: em,timer,replaces,path,resource-priority Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE User-Agent: Audiocodes-Sip-Gateway-/v.5.80A.023.006 Reason: Q.850 ;cause=16 ;text="local" Content-Length: 0 <-------------> [Aug 9 11:45:35] DEBUG[31464] chan_sip.c: Header 0 [ 37]: BYE sip:6000@10.21.0.146:5061 SIP/2.0 [Aug 9 11:45:35] DEBUG[31464] chan_sip.c: Header 1 [ 55]: Via: SIP/2.0/UDP 10.21.0.135;branch=z9hG4bKac1967818995 [Aug 9 11:45:35] DEBUG[31464] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Aug 9 11:45:35] DEBUG[31464] chan_sip.c: Header 3 [ 53]: From: ;tag=1c1640285023 [Aug 9 11:45:35] DEBUG[31464] chan_sip.c: Header 4 [ 45]: To: "Shay HD" ;tag=as63233769 [Aug 9 11:45:35] DEBUG[31464] chan_sip.c: Header 5 [ 47]: Call-ID: 218437655d848d51367a65487e733ae9@TTTSS [Aug 9 11:45:35] DEBUG[31464] chan_sip.c: Header 6 [ 11]: CSeq: 1 BYE [Aug 9 11:45:35] DEBUG[31464] chan_sip.c: Header 7 [ 51]: Supported: em,timer,replaces,path,resource-priority [Aug 9 11:45:35] DEBUG[31464] chan_sip.c: Header 8 [ 86]: Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE [Aug 9 11:45:35] DEBUG[31464] chan_sip.c: Header 9 [ 51]: User-Agent: Audiocodes-Sip-Gateway-/v.5.80A.023.006 [Aug 9 11:45:35] DEBUG[31464] chan_sip.c: Header 10 [ 37]: Reason: Q.850 ;cause=16 ;text="local" [Aug 9 11:45:35] DEBUG[31464] chan_sip.c: Header 11 [ 17]: Content-Length: 0 [Aug 9 11:45:35] DEBUG[31464] chan_sip.c: Header 12 [ 0]: [Aug 9 11:45:35] VERBOSE[31464] chan_sip.c: --- (12 headers 0 lines) --- [Aug 9 11:45:35] DEBUG[31464] chan_sip.c: **** Received BYE (8) - Command in SIP BYE [Aug 9 11:45:35] DEBUG[31464] chan_sip.c: Initializing initreq for method BYE - callid 218437655d848d51367a65487e733ae9@TTTSS [Aug 9 11:45:35] DEBUG[31464] netsock2.c: Splitting '10.21.0.135' gives... [Aug 9 11:45:35] DEBUG[31464] netsock2.c: ...host '10.21.0.135' and port '(null)'. [Aug 9 11:45:35] VERBOSE[31464] chan_sip.c: Sending to 10.21.0.135:5060 (no NAT) [Aug 9 11:45:35] DEBUG[31464] chan_sip.c: Setting SIP_ALREADYGONE on dialog 218437655d848d51367a65487e733ae9@TTTSS [Aug 9 11:45:35] DEBUG[31464] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0xa2f3460' [Aug 9 11:45:35] DEBUG[31464] chan_sip.c: Session timer stopped: -1 - 218437655d848d51367a65487e733ae9@TTTSS [Aug 9 11:45:35] VERBOSE[31464] chan_sip.c: Scheduling destruction of SIP dialog '218437655d848d51367a65487e733ae9@TTTSS' in 32000 ms (Method: BYE) [Aug 9 11:45:35] DEBUG[31464] chan_sip.c: Received bye, issuing owner hangup [Aug 9 11:45:35] VERBOSE[31464] chan_sip.c: <--- Transmitting (no NAT) to 10.21.0.135:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 10.21.0.135;branch=z9hG4bKac1967818995;received=10.21.0.135 From: ;tag=1c1640285023 To: "Shay HD" ;tag=as63233769 Call-ID: 218437655d848d51367a65487e733ae9@TTTSS CSeq: 1 BYE Server: Asterisk PBX 1.8.0-beta2 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Content-Length: 0 <------------> [Aug 9 11:45:35] DEBUG[31464] chan_sip.c: Trying to put 'SIP/2.0 200' onto UDP socket destined for 10.21.0.135:5060 [Aug 9 11:45:35] DEBUG[31464] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '218437655d848d51367a65487e733ae9@TTTSS' Method: BYE [Aug 9 11:45:35] DEBUG[31464] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '888f10-26160d0a-13c4-50029-386e927a-3b57bcf5-386e927a' Method: ACK [Aug 9 11:45:35] DEBUG[32310] rtp_engine.c: Oooh, got a hangup [Aug 9 11:45:35] DEBUG[32310] chan_sip.c: Sending reinvite on SIP '888f10-26160d0a-13c4-50029-386e927a-3b57bcf5-386e927a' - It's audio soon redirected to IP 10.21.0.146:5061 [Aug 9 11:45:35] DEBUG[32310] chan_sip.c: Strict routing enforced for session 888f10-26160d0a-13c4-50029-386e927a-3b57bcf5-386e927a [Aug 9 11:45:35] VERBOSE[32310] chan_sip.c: set_destination: Parsing for address/port to send to [Aug 9 11:45:35] DEBUG[32310] netsock2.c: Splitting '10.13.22.38' gives... [Aug 9 11:45:35] DEBUG[32310] netsock2.c: ...host '10.13.22.38' and port '(null)'. [Aug 9 11:45:35] VERBOSE[32310] chan_sip.c: set_destination: set destination to 10.13.22.38:5060 [Aug 9 11:45:35] DEBUG[32310] chan_sip.c: ** Our capability: 0x8 (alaw) Video flag: True Text flag: True [Aug 9 11:45:35] DEBUG[32310] chan_sip.c: ** Our prefcodec: 0x0 (nothing) [Aug 9 11:45:35] VERBOSE[32310] chan_sip.c: Audio is at 5061 [Aug 9 11:45:35] VERBOSE[32310] chan_sip.c: Adding codec 0x8 (alaw) to SDP [Aug 9 11:45:35] VERBOSE[32310] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP [Aug 9 11:45:35] DEBUG[32310] chan_sip.c: -- Done with adding codecs to SDP [Aug 9 11:45:35] DEBUG[32310] chan_sip.c: Done building SDP. Settling with this capability: 0x8 (alaw) [Aug 9 11:45:35] DEBUG[32310] chan_sip.c: Initializing already initialized SIP dialog 888f10-26160d0a-13c4-50029-386e927a-3b57bcf5-386e927a (presumably reinvite) [Aug 9 11:45:35] DEBUG[32310] chan_sip.c: Header 0 [ 35]: INVITE sip:6000@10.13.22.38 SIP/2.0 [Aug 9 11:45:35] DEBUG[32310] chan_sip.c: Header 1 [ 62]: Via: SIP/2.0/UDP 10.21.0.146:5061;branch=z9hG4bK2032178b;rport [Aug 9 11:45:35] DEBUG[32310] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Aug 9 11:45:35] DEBUG[32310] chan_sip.c: Header 3 [ 52]: From: ;tag=as46255de3 [Aug 9 11:45:35] DEBUG[32310] chan_sip.c: Header 4 [ 89]: To: "6000";tag=8824b0-26160d0a-13c4-50029-386e927a-488246b-386e927a [Aug 9 11:45:35] DEBUG[32310] chan_sip.c: Header 5 [ 40]: Contact: [Aug 9 11:45:35] DEBUG[32310] chan_sip.c: Header 6 [ 62]: Call-ID: 888f10-26160d0a-13c4-50029-386e927a-3b57bcf5-386e927a [Aug 9 11:45:35] DEBUG[32310] chan_sip.c: Header 7 [ 16]: CSeq: 103 INVITE [Aug 9 11:45:35] DEBUG[32310] chan_sip.c: Header 8 [ 36]: User-Agent: Asterisk PBX 1.8.0-beta2 [Aug 9 11:45:35] DEBUG[32310] chan_sip.c: Header 9 [ 81]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH [Aug 9 11:45:35] DEBUG[32310] chan_sip.c: Header 10 [ 26]: Supported: replaces, timer [Aug 9 11:45:35] DEBUG[32310] chan_sip.c: Header 11 [ 52]: X-asterisk-Info: SIP re-invite (External RTP bridge) [Aug 9 11:45:35] DEBUG[32310] chan_sip.c: Header 12 [ 29]: Content-Type: application/sdp [Aug 9 11:45:35] VERBOSE[32310] chan_sip.c: Reliably Transmitting (no NAT) to 10.13.22.38:5060: INVITE sip:6000@10.13.22.38 SIP/2.0 Via: SIP/2.0/UDP 10.21.0.146:5061;branch=z9hG4bK2032178b;rport Max-Forwards: 70 From: ;tag=as46255de3 To: "6000";tag=8824b0-26160d0a-13c4-50029-386e927a-488246b-386e927a Contact: Call-ID: 888f10-26160d0a-13c4-50029-386e927a-3b57bcf5-386e927a CSeq: 103 INVITE User-Agent: Asterisk PBX 1.8.0-beta2 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer X-asterisk-Info: SIP re-invite (External RTP bridge) Content-Type: application/sdp Content-Length: 265 v=0 o=root 1086490089 1086490091 IN IP4 10.21.0.146 s=Asterisk PBX 1.8.0-beta2 c=IN IP4 10.21.0.146 t=0 0 m=audio 14610 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv --- [Aug 9 11:45:35] DEBUG[32310] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #4950 [Aug 9 11:45:35] DEBUG[32310] chan_sip.c: Trying to put 'INVITE sip:' onto UDP socket destined for 10.13.22.38:5060 [Aug 9 11:45:35] DEBUG[31464] chan_sip.c: Bridge still active. Delaying destroy of SIP dialog '218437655d848d51367a65487e733ae9@TTTSS' Method: BYE [Aug 9 11:45:35] DEBUG[32310] channel.c: Returning from native bridge, channels: SIP/6000-0000004b, SIP/M1k_Shay-0000004c [Aug 9 11:45:35] DEBUG[32310] pbx.c: Result of 'DIALSTATUS' is 'ANSWER' [Aug 9 11:45:35] DEBUG[32310] pbx.c: Launching 'NoOp' [Aug 9 11:45:35] VERBOSE[32310] pbx.c: -- Executing [h@macro-Dial-Trunk:1] NoOp("SIP/6000-0000004b", "ANSWER ") in new stack [Aug 9 11:45:35] DEBUG[32310] pbx.c: Launching 'Macro' [Aug 9 11:45:35] VERBOSE[32310] pbx.c: -- Executing [h@macro-Dial-Trunk:2] Macro("SIP/6000-0000004b", "Check-CampOn") in new stack [Aug 9 11:45:35] DEBUG[32310] pbx.c: Launching 'NoOp' [Aug 9 11:45:35] VERBOSE[32310] pbx.c: -- Executing [s@macro-Check-CampOn:1] NoOp("SIP/6000-0000004b", "Check-CampOn") in new stack [Aug 9 11:45:35] DEBUG[32310] app_macro.c: Executed application: Noop [Aug 9 11:45:35] DEBUG[32310] pbx.c: Evaluating 'DIALEDPEERNUMBER' (from 'DIALEDPEERNUMBER}' len 16) [Aug 9 11:45:35] DEBUG[32310] pbx.c: Result of 'DIALEDPEERNUMBER' is '9764701@M1k_Shay' [Aug 9 11:45:35] DEBUG[32310] pbx.c: Function result is '9764701@M1k_Shay' [Aug 9 11:45:35] DEBUG[32310] pbx.c: Launching 'Set' [Aug 9 11:45:35] VERBOSE[32310] pbx.c: -- Executing [s@macro-Check-CampOn:2] Set("SIP/6000-0000004b", "DialedNum=9764701@M1k_Shay") in new stack [Aug 9 11:45:35] DEBUG[32310] app_macro.c: Executed application: Set [Aug 9 11:45:35] DEBUG[32310] pbx.c: Result of 'DialedNum' is '9764701@M1k_Shay' [Aug 9 11:45:35] DEBUG[32310] pbx.c: Launching 'NoOp' [Aug 9 11:45:35] VERBOSE[32310] pbx.c: -- Executing [s@macro-Check-CampOn:3] NoOp("SIP/6000-0000004b", "DIALEDPEERNUMBER 9764701@M1k_Shay") in new stack [Aug 9 11:45:35] DEBUG[32310] app_macro.c: Executed application: Noop [Aug 9 11:45:35] DEBUG[32310] pbx.c: Function result is '6000' [Aug 9 11:45:35] DEBUG[32310] pbx.c: Launching 'NoOp' [Aug 9 11:45:35] VERBOSE[32310] pbx.c: -- Executing [s@macro-Check-CampOn:4] NoOp("SIP/6000-0000004b", "CLI 6000") in new stack [Aug 9 11:45:35] DEBUG[32310] app_macro.c: Executed application: Noop [Aug 9 11:45:35] DEBUG[32310] pbx.c: Result of 'DialedNum' is '9764701@M1k_Shay' [Aug 9 11:45:35] DEBUG[32310] db.c: Unable to find key '9764701@M1k_Shay' in family 'CampOn' [Aug 9 11:45:35] DEBUG[32310] func_db.c: DB: CampOn/9764701@M1k_Shay not found in database. [Aug 9 11:45:35] DEBUG[32310] pbx.c: Function result is '' [Aug 9 11:45:35] DEBUG[32310] pbx.c: Launching 'Set' [Aug 9 11:45:35] VERBOSE[32310] pbx.c: -- Executing [s@macro-Check-CampOn:5] Set("SIP/6000-0000004b", "orig=") in new stack [Aug 9 11:45:35] DEBUG[32310] app_macro.c: Executed application: Set [Aug 9 11:45:35] DEBUG[32310] pbx.c: Function result is '6000' [Aug 9 11:45:35] DEBUG[32310] pbx.c: Launching 'Set' [Aug 9 11:45:35] VERBOSE[32310] pbx.c: -- Executing [s@macro-Check-CampOn:6] Set("SIP/6000-0000004b", "IsCli=6000") in new stack [Aug 9 11:45:35] DEBUG[32310] app_macro.c: Executed application: Set [Aug 9 11:45:35] DEBUG[32310] pbx.c: Result of 'DialedNum' is '9764701@M1k_Shay' [Aug 9 11:45:35] DEBUG[32310] pbx.c: Launching 'Set' [Aug 9 11:45:35] VERBOSE[32310] pbx.c: -- Executing [s@macro-Check-CampOn:7] Set("SIP/6000-0000004b", "dest=9764701@M1k_Shay") in new stack [Aug 9 11:45:35] DEBUG[32310] app_macro.c: Executed application: Set [Aug 9 11:45:35] DEBUG[32310] pbx.c: Result of 'orig' is '' [Aug 9 11:45:35] DEBUG[32310] pbx.c: Launching 'GotoIf' [Aug 9 11:45:35] VERBOSE[32310] pbx.c: -- Executing [s@macro-Check-CampOn:8] GotoIf("SIP/6000-0000004b", "?1-CheckOrig,1") in new stack [Aug 9 11:45:35] DEBUG[32310] pbx.c: Not taking any branch [Aug 9 11:45:35] DEBUG[32310] app_macro.c: Executed application: GotoIf [Aug 9 11:45:35] DEBUG[32310] pbx.c: Function result is '6000' [Aug 9 11:45:35] DEBUG[32310] db.c: Unable to find key '6000' in family 'CampOn' [Aug 9 11:45:35] DEBUG[32310] func_db.c: DB: CampOn/6000 not found in database. [Aug 9 11:45:35] DEBUG[32310] pbx.c: Function result is '' [Aug 9 11:45:35] DEBUG[32310] pbx.c: Launching 'Set' [Aug 9 11:45:35] VERBOSE[32310] pbx.c: -- Executing [s@macro-Check-CampOn:9] Set("SIP/6000-0000004b", "orig=") in new stack [Aug 9 11:45:35] DEBUG[32310] app_macro.c: Executed application: Set [Aug 9 11:45:35] DEBUG[32310] pbx.c: Function result is '6000' [Aug 9 11:45:35] DEBUG[32310] pbx.c: Launching 'Set' [Aug 9 11:45:35] VERBOSE[32310] pbx.c: -- Executing [s@macro-Check-CampOn:10] Set("SIP/6000-0000004b", "dest=6000") in new stack [Aug 9 11:45:35] DEBUG[32310] app_macro.c: Executed application: Set [Aug 9 11:45:35] DEBUG[32310] pbx.c: Result of 'DialedNum' is '9764701@M1k_Shay' [Aug 9 11:45:35] DEBUG[32310] pbx.c: Launching 'Set' [Aug 9 11:45:35] VERBOSE[32310] pbx.c: -- Executing [s@macro-Check-CampOn:11] Set("SIP/6000-0000004b", "IsCli=9764701@M1k_Shay") in new stack [Aug 9 11:45:35] DEBUG[32310] app_macro.c: Executed application: Set [Aug 9 11:45:35] DEBUG[32310] pbx.c: Result of 'orig' is '' [Aug 9 11:45:35] DEBUG[32310] pbx.c: Launching 'GotoIf' [Aug 9 11:45:35] VERBOSE[32310] pbx.c: -- Executing [s@macro-Check-CampOn:12] GotoIf("SIP/6000-0000004b", "?1-CheckOrig,1") in new stack [Aug 9 11:45:35] DEBUG[32310] pbx.c: Not taking any branch [Aug 9 11:45:35] DEBUG[32310] app_macro.c: Executed application: GotoIf [Aug 9 11:45:35] DEBUG[32310] pbx.c: Result of 'DialedNum' is '9764701@M1k_Shay' [Aug 9 11:45:35] DEBUG[32310] db.c: Unable to find key '9764701@M1k_Shay' in family 'CampOrig' [Aug 9 11:45:35] DEBUG[32310] func_db.c: DB: CampOrig/9764701@M1k_Shay not found in database. [Aug 9 11:45:35] DEBUG[32310] pbx.c: Function result is '' [Aug 9 11:45:35] DEBUG[32310] pbx.c: Launching 'Set' [Aug 9 11:45:35] VERBOSE[32310] pbx.c: -- Executing [s@macro-Check-CampOn:13] Set("SIP/6000-0000004b", "dest=") in new stack [Aug 9 11:45:35] DEBUG[32310] app_macro.c: Executed application: Set [Aug 9 11:45:35] DEBUG[32310] pbx.c: Function result is '6000' [Aug 9 11:45:35] DEBUG[32310] pbx.c: Launching 'Set' [Aug 9 11:45:35] VERBOSE[32310] pbx.c: -- Executing [s@macro-Check-CampOn:14] Set("SIP/6000-0000004b", "IsCli=6000") in new stack [Aug 9 11:45:35] DEBUG[32310] app_macro.c: Executed application: Set [Aug 9 11:45:35] DEBUG[32310] pbx.c: Result of 'DialedNum' is '9764701@M1k_Shay' [Aug 9 11:45:35] DEBUG[32310] pbx.c: Launching 'Set' [Aug 9 11:45:35] VERBOSE[32310] pbx.c: -- Executing [s@macro-Check-CampOn:15] Set("SIP/6000-0000004b", "orig=9764701@M1k_Shay") in new stack [Aug 9 11:45:35] DEBUG[32310] app_macro.c: Executed application: Set [Aug 9 11:45:35] DEBUG[32310] pbx.c: Result of 'dest' is '' [Aug 9 11:45:35] DEBUG[32310] pbx.c: Launching 'GotoIf' [Aug 9 11:45:35] VERBOSE[32310] pbx.c: -- Executing [s@macro-Check-CampOn:16] GotoIf("SIP/6000-0000004b", "?1-CheckDest,1") in new stack [Aug 9 11:45:35] DEBUG[32310] pbx.c: Not taking any branch [Aug 9 11:45:35] DEBUG[32310] app_macro.c: Executed application: GotoIf [Aug 9 11:45:35] DEBUG[32310] pbx.c: Function result is '6000' [Aug 9 11:45:35] DEBUG[32310] db.c: Unable to find key '6000' in family 'CampOrig' [Aug 9 11:45:35] DEBUG[32310] func_db.c: DB: CampOrig/6000 not found in database. [Aug 9 11:45:35] DEBUG[32310] pbx.c: Function result is '' [Aug 9 11:45:35] DEBUG[32310] pbx.c: Launching 'Set' [Aug 9 11:45:35] VERBOSE[32310] pbx.c: -- Executing [s@macro-Check-CampOn:17] Set("SIP/6000-0000004b", "dest=") in new stack [Aug 9 11:45:35] DEBUG[32310] app_macro.c: Executed application: Set [Aug 9 11:45:35] DEBUG[32310] pbx.c: Result of 'DialedNum' is '9764701@M1k_Shay' [Aug 9 11:45:35] DEBUG[32310] pbx.c: Launching 'Set' [Aug 9 11:45:35] VERBOSE[32310] pbx.c: -- Executing [s@macro-Check-CampOn:18] Set("SIP/6000-0000004b", "IsCli=9764701@M1k_Shay") in new stack [Aug 9 11:45:35] DEBUG[32310] app_macro.c: Executed application: Set [Aug 9 11:45:35] DEBUG[32310] pbx.c: Function result is '6000' [Aug 9 11:45:35] DEBUG[32310] pbx.c: Launching 'Set' [Aug 9 11:45:35] VERBOSE[32310] pbx.c: -- Executing [s@macro-Check-CampOn:19] Set("SIP/6000-0000004b", "orig=6000") in new stack [Aug 9 11:45:35] DEBUG[32310] app_macro.c: Executed application: Set [Aug 9 11:45:35] DEBUG[32310] pbx.c: Result of 'dest' is '' [Aug 9 11:45:35] DEBUG[32310] pbx.c: Launching 'GotoIf' [Aug 9 11:45:35] VERBOSE[32310] pbx.c: -- Executing [s@macro-Check-CampOn:20] GotoIf("SIP/6000-0000004b", "?1-CheckDest,1") in new stack [Aug 9 11:45:35] DEBUG[32310] pbx.c: Not taking any branch [Aug 9 11:45:35] DEBUG[32310] app_macro.c: Executed application: GotoIf [Aug 9 11:45:35] DEBUG[32310] channel.c: Hanging up channel 'SIP/M1k_Shay-0000004c' [Aug 9 11:45:35] DEBUG[32310] chan_sip.c: Hangup call SIP/M1k_Shay-0000004c, SIP callid 218437655d848d51367a65487e733ae9@TTTSS [Aug 9 11:45:35] DEBUG[32310] chan_sip.c: update_call_counter(9764701) - decrement call limit counter on hangup [Aug 9 11:45:35] DEBUG[32310] chan_sip.c: Updating call counter for outgoing call [Aug 9 11:45:35] DEBUG[32310] chan_sip.c: Call to peer 'M1k_Shay' removed from call limit 99 [Aug 9 11:45:35] DEBUG[31458] devicestate.c: No provider found, checking channel drivers for SIP - M1k_Shay [Aug 9 11:45:35] DEBUG[31458] chan_sip.c: Checking device state for peer M1k_Shay [Aug 9 11:45:35] DEBUG[31458] devicestate.c: Changing state for SIP/M1k_Shay - state 1 (Not in use) [Aug 9 11:45:35] DEBUG[31458] devicestate.c: device 'SIP/M1k_Shay' state '1' [Aug 9 11:45:35] DEBUG[32310] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0xa2f3460' [Aug 9 11:45:35] DEBUG[31458] devicestate.c: No provider found, checking channel drivers for SIP - M1k_Shay [Aug 9 11:45:35] DEBUG[31458] chan_sip.c: Checking device state for peer M1k_Shay [Aug 9 11:45:35] DEBUG[31458] devicestate.c: Changing state for SIP/M1k_Shay - state 1 (Not in use) [Aug 9 11:45:35] DEBUG[31458] devicestate.c: device 'SIP/M1k_Shay' state '1' [Aug 9 11:45:35] DEBUG[32310] app_dial.c: Exiting with DIALSTATUS=ANSWER. [Aug 9 11:45:35] DEBUG[32310] app_macro.c: Spawn extension (macro-Dial-Trunk,1-Dial,1) exited non-zero on 'SIP/6000-0000004b' in macro 'Dial-Trunk' [Aug 9 11:45:35] VERBOSE[32310] app_macro.c: == Spawn extension (macro-Dial-Trunk, 1-Dial, 1) exited non-zero on 'SIP/6000-0000004b' in macro 'Dial-Trunk' [Aug 9 11:45:35] DEBUG[32310] app_macro.c: Spawn extension (macro-DialProcess,1-External,1) exited non-zero on 'SIP/6000-0000004b' in macro 'DialProcess' [Aug 9 11:45:35] VERBOSE[32310] app_macro.c: == Spawn extension (macro-DialProcess, 1-External, 1) exited non-zero on 'SIP/6000-0000004b' in macro 'DialProcess' [Aug 9 11:45:35] DEBUG[32310] pbx.c: Spawn extension (DLPN_DialPlanAll,99764701,4) exited non-zero on 'SIP/6000-0000004b' [Aug 9 11:45:35] VERBOSE[32310] pbx.c: == Spawn extension (DLPN_DialPlanAll, 99764701, 4) exited non-zero on 'SIP/6000-0000004b' [Aug 9 11:45:35] DEBUG[32310] channel.c: Soft-Hanging up channel 'SIP/6000-0000004b' [Aug 9 11:45:35] DEBUG[32310] channel.c: Hanging up channel 'SIP/6000-0000004b' [Aug 9 11:45:35] DEBUG[32310] chan_sip.c: Hangup call SIP/6000-0000004b, SIP callid 888f10-26160d0a-13c4-50029-386e927a-3b57bcf5-386e927a [Aug 9 11:45:35] DEBUG[32310] chan_sip.c: update_call_counter(6000) - decrement call limit counter on hangup [Aug 9 11:45:35] DEBUG[32310] chan_sip.c: Updating call counter for incoming call [Aug 9 11:45:35] DEBUG[32310] chan_sip.c: Call from peer '6000' removed from call limit 6 [Aug 9 11:45:35] DEBUG[31458] devicestate.c: No provider found, checking channel drivers for SIP - 6000 [Aug 9 11:45:35] DEBUG[31458] chan_sip.c: Checking device state for peer 6000 [Aug 9 11:45:35] DEBUG[31458] devicestate.c: Changing state for SIP/6000 - state 1 (Not in use) [Aug 9 11:45:35] DEBUG[31458] devicestate.c: device 'SIP/6000' state '1' [Aug 9 11:45:35] DEBUG[32310] res_rtp_asterisk.c: Setting RTCP address on RTP instance '0xa27d9f8' [Aug 9 11:45:35] VERBOSE[32310] chan_sip.c: Scheduling destruction of SIP dialog '888f10-26160d0a-13c4-50029-386e927a-3b57bcf5-386e927a' in 32000 ms (Method: ACK) [Aug 9 11:45:35] DEBUG[32310] chan_sip.c: Session timer stopped: -1 - 888f10-26160d0a-13c4-50029-386e927a-3b57bcf5-386e927a [Aug 9 11:45:35] DEBUG[31458] devicestate.c: No provider found, checking channel drivers for SIP - 6000 [Aug 9 11:45:35] DEBUG[31458] chan_sip.c: Checking device state for peer 6000 [Aug 9 11:45:35] DEBUG[31458] devicestate.c: Changing state for SIP/6000 - state 1 (Not in use) [Aug 9 11:45:35] DEBUG[31458] devicestate.c: device 'SIP/6000' state '1' [Aug 9 11:45:36] VERBOSE[31464] chan_sip.c: <--- SIP read from UDP:10.13.22.38:5060 ---> SIP/2.0 200 OK From: ;tag=as46255de3 To: "6000";tag=8824b0-26160d0a-13c4-50029-386e927a-488246b-386e927a Call-ID: 888f10-26160d0a-13c4-50029-386e927a-3b57bcf5-386e927a CSeq: 103 INVITE Via: SIP/2.0/UDP 10.21.0.146:5061;rport=5061;branch=z9hG4bK2032178b Supported: replaces,100rel User-Agent: AUDC-IPPhone/1.2.1_build_6 (320HD;00908F1ED22E) Contact: Content-Type: application/sdp Content-Length: 200 v=0 o=6000 946770593 946770593 IN IP4 10.13.22.38 s=- c=IN IP4 10.13.22.38 t=0 0 m=audio 4000 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000 a=ptime:20 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 <-------------> [Aug 9 11:45:36] DEBUG[31464] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [Aug 9 11:45:36] DEBUG[31464] chan_sip.c: Header 1 [ 52]: From: ;tag=as46255de3 [Aug 9 11:45:36] DEBUG[31464] chan_sip.c: Header 2 [ 89]: To: "6000";tag=8824b0-26160d0a-13c4-50029-386e927a-488246b-386e927a [Aug 9 11:45:36] DEBUG[31464] chan_sip.c: Header 3 [ 62]: Call-ID: 888f10-26160d0a-13c4-50029-386e927a-3b57bcf5-386e927a [Aug 9 11:45:36] DEBUG[31464] chan_sip.c: Header 4 [ 16]: CSeq: 103 INVITE [Aug 9 11:45:36] DEBUG[31464] chan_sip.c: Header 5 [ 67]: Via: SIP/2.0/UDP 10.21.0.146:5061;rport=5061;branch=z9hG4bK2032178b [Aug 9 11:45:36] DEBUG[31464] chan_sip.c: Header 6 [ 26]: Supported: replaces,100rel [Aug 9 11:45:36] DEBUG[31464] chan_sip.c: Header 7 [ 59]: User-Agent: AUDC-IPPhone/1.2.1_build_6 (320HD;00908F1ED22E) [Aug 9 11:45:36] DEBUG[31464] chan_sip.c: Header 8 [ 31]: Contact: [Aug 9 11:45:36] DEBUG[31464] chan_sip.c: Header 9 [ 29]: Content-Type: application/sdp [Aug 9 11:45:36] DEBUG[31464] chan_sip.c: Header 10 [ 19]: Content-Length: 200 [Aug 9 11:45:36] DEBUG[31464] chan_sip.c: Header 11 [ 0]: [Aug 9 11:45:36] DEBUG[31464] chan_sip.c: Body 0 [ 3]: v=0 [Aug 9 11:45:36] DEBUG[31464] chan_sip.c: Body 1 [ 45]: o=6000 946770593 946770593 IN IP4 10.13.22.38 [Aug 9 11:45:36] DEBUG[31464] chan_sip.c: Body 2 [ 3]: s=- [Aug 9 11:45:36] DEBUG[31464] chan_sip.c: Body 3 [ 20]: c=IN IP4 10.13.22.38 [Aug 9 11:45:36] DEBUG[31464] chan_sip.c: Body 4 [ 5]: t=0 0 [Aug 9 11:45:36] DEBUG[31464] chan_sip.c: Body 5 [ 26]: m=audio 4000 RTP/AVP 8 101 [Aug 9 11:45:36] DEBUG[31464] chan_sip.c: Body 6 [ 20]: a=rtpmap:8 PCMA/8000 [Aug 9 11:45:36] DEBUG[31464] chan_sip.c: Body 7 [ 10]: a=ptime:20 [Aug 9 11:45:36] DEBUG[31464] chan_sip.c: Body 8 [ 33]: a=rtpmap:101 telephone-event/8000 [Aug 9 11:45:36] DEBUG[31464] chan_sip.c: Body 9 [ 15]: a=fmtp:101 0-15 [Aug 9 11:45:36] VERBOSE[31464] chan_sip.c: --- (11 headers 10 lines) --- [Aug 9 11:45:36] DEBUG[31464] chan_sip.c: Acked pending invite 103 [Aug 9 11:45:36] DEBUG[31464] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #4950 [Aug 9 11:45:36] DEBUG[31464] chan_sip.c: Stopping retransmission on '888f10-26160d0a-13c4-50029-386e927a-3b57bcf5-386e927a' of Request 103: Match Found [Aug 9 11:45:36] DEBUG[31464] chan_sip.c: SIP response 200 to standard invite [Aug 9 11:45:36] DEBUG[31464] chan_sip.c: Processing session-level SDP v=0... UNSUPPORTED. [Aug 9 11:45:36] DEBUG[31464] chan_sip.c: Call 888f10-26160d0a-13c4-50029-386e927a-3b57bcf5-386e927a responded to our reinvite without changing SDP version; ignoring SDP. [Aug 9 11:45:36] DEBUG[31464] chan_sip.c: Updating call counter for incoming call [Aug 9 11:45:36] DEBUG[31464] chan_sip.c: build_route: Retaining previous route: [Aug 9 11:45:36] DEBUG[31464] netsock2.c: Splitting '10.13.22.38' gives... [Aug 9 11:45:36] DEBUG[31464] netsock2.c: ...host '10.13.22.38' and port '(null)'. [Aug 9 11:45:36] DEBUG[31464] chan_sip.c: Strict routing enforced for session 888f10-26160d0a-13c4-50029-386e927a-3b57bcf5-386e927a [Aug 9 11:45:36] VERBOSE[31464] chan_sip.c: set_destination: Parsing for address/port to send to [Aug 9 11:45:36] DEBUG[31464] netsock2.c: Splitting '10.13.22.38' gives... [Aug 9 11:45:36] DEBUG[31464] netsock2.c: ...host '10.13.22.38' and port '(null)'. [Aug 9 11:45:36] VERBOSE[31464] chan_sip.c: set_destination: set destination to 10.13.22.38:5060 [Aug 9 11:45:36] VERBOSE[31464] chan_sip.c: Transmitting (no NAT) to 10.13.22.38:5060: ACK sip:6000@10.13.22.38 SIP/2.0 Via: SIP/2.0/UDP 10.21.0.146:5061;branch=z9hG4bK5a80cc23;rport Max-Forwards: 70 From: ;tag=as46255de3 To: "6000";tag=8824b0-26160d0a-13c4-50029-386e927a-488246b-386e927a Contact: Call-ID: 888f10-26160d0a-13c4-50029-386e927a-3b57bcf5-386e927a CSeq: 103 ACK User-Agent: Asterisk PBX 1.8.0-beta2 Content-Length: 0 --- [Aug 9 11:45:36] DEBUG[31464] chan_sip.c: Trying to put 'ACK sip:600' onto UDP socket destined for 10.13.22.38:5060 [Aug 9 11:45:36] DEBUG[31464] chan_sip.c: Strict routing enforced for session 888f10-26160d0a-13c4-50029-386e927a-3b57bcf5-386e927a [Aug 9 11:45:36] VERBOSE[31464] chan_sip.c: set_destination: Parsing for address/port to send to [Aug 9 11:45:36] DEBUG[31464] netsock2.c: Splitting '10.13.22.38' gives... [Aug 9 11:45:36] DEBUG[31464] netsock2.c: ...host '10.13.22.38' and port '(null)'. [Aug 9 11:45:36] VERBOSE[31464] chan_sip.c: set_destination: set destination to 10.13.22.38:5060 [Aug 9 11:45:36] VERBOSE[31464] chan_sip.c: Reliably Transmitting (no NAT) to 10.13.22.38:5060: BYE sip:6000@10.13.22.38 SIP/2.0 Via: SIP/2.0/UDP 10.21.0.146:5061;branch=z9hG4bK6984c3e1;rport Max-Forwards: 70 From: ;tag=as46255de3 To: "6000";tag=8824b0-26160d0a-13c4-50029-386e927a-488246b-386e927a Call-ID: 888f10-26160d0a-13c4-50029-386e927a-3b57bcf5-386e927a CSeq: 104 BYE User-Agent: Asterisk PBX 1.8.0-beta2 Proxy-Authorization: Digest username="6000", realm="asterisk", algorithm=MD5, uri="10.21.0.146:5061", nonce="", response="6d89341a43dab7b94b59080684aa129c" X-Asterisk-HangupCause: Normal Clearing X-Asterisk-HangupCauseCode: 16 Content-Length: 0 --- [Aug 9 11:45:36] DEBUG[31464] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #4952 [Aug 9 11:45:36] DEBUG[31464] chan_sip.c: Trying to put 'BYE sip:600' onto UDP socket destined for 10.13.22.38:5060 [Aug 9 11:45:36] VERBOSE[31464] chan_sip.c: Scheduling destruction of SIP dialog '888f10-26160d0a-13c4-50029-386e927a-3b57bcf5-386e927a' in 32000 ms (Method: ACK) [Aug 9 11:45:36] DEBUG[31458] devicestate.c: No provider found, checking channel drivers for SIP - 6000 [Aug 9 11:45:36] DEBUG[31458] chan_sip.c: Checking device state for peer 6000 [Aug 9 11:45:36] DEBUG[31458] devicestate.c: Changing state for SIP/6000 - state 1 (Not in use) [Aug 9 11:45:36] DEBUG[31458] devicestate.c: device 'SIP/6000' state '1' [Aug 9 11:45:36] VERBOSE[31464] chan_sip.c: <--- SIP read from UDP:10.13.22.38:5060 ---> SIP/2.0 200 OK From: ;tag=as46255de3 To: "6000";tag=8824b0-26160d0a-13c4-50029-386e927a-488246b-386e927a Call-ID: 888f10-26160d0a-13c4-50029-386e927a-3b57bcf5-386e927a CSeq: 104 BYE Via: SIP/2.0/UDP 10.21.0.146:5061;rport=5061;branch=z9hG4bK6984c3e1 Supported: replaces,100rel User-Agent: AUDC-IPPhone/1.2.1_build_6 (320HD;00908F1ED22E) Content-Length: 0 <-------------> [Aug 9 11:45:36] DEBUG[31464] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [Aug 9 11:45:36] DEBUG[31464] chan_sip.c: Header 1 [ 52]: From: ;tag=as46255de3 [Aug 9 11:45:36] DEBUG[31464] chan_sip.c: Header 2 [ 89]: To: "6000";tag=8824b0-26160d0a-13c4-50029-386e927a-488246b-386e927a [Aug 9 11:45:36] DEBUG[31464] chan_sip.c: Header 3 [ 62]: Call-ID: 888f10-26160d0a-13c4-50029-386e927a-3b57bcf5-386e927a [Aug 9 11:45:36] DEBUG[31464] chan_sip.c: Header 4 [ 13]: CSeq: 104 BYE [Aug 9 11:45:36] DEBUG[31464] chan_sip.c: Header 5 [ 67]: Via: SIP/2.0/UDP 10.21.0.146:5061;rport=5061;branch=z9hG4bK6984c3e1 [Aug 9 11:45:36] DEBUG[31464] chan_sip.c: Header 6 [ 26]: Supported: replaces,100rel [Aug 9 11:45:36] DEBUG[31464] chan_sip.c: Header 7 [ 59]: User-Agent: AUDC-IPPhone/1.2.1_build_6 (320HD;00908F1ED22E) [Aug 9 11:45:36] DEBUG[31464] chan_sip.c: Header 8 [ 17]: Content-Length: 0 [Aug 9 11:45:36] DEBUG[31464] chan_sip.c: Header 9 [ 0]: [Aug 9 11:45:36] VERBOSE[31464] chan_sip.c: --- (9 headers 0 lines) --- [Aug 9 11:45:36] DEBUG[31464] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #4952 [Aug 9 11:45:36] DEBUG[31464] chan_sip.c: Stopping retransmission on '888f10-26160d0a-13c4-50029-386e927a-3b57bcf5-386e927a' of Request 104: Match Found [Aug 9 11:45:36] DEBUG[31464] chan_sip.c: Destroying SIP dialog 888f10-26160d0a-13c4-50029-386e927a-3b57bcf5-386e927a [Aug 9 11:45:36] VERBOSE[31464] chan_sip.c: Really destroying SIP dialog '888f10-26160d0a-13c4-50029-386e927a-3b57bcf5-386e927a' Method: ACK [Aug 9 11:45:36] DEBUG[31464] rtp_engine.c: Destroyed RTP instance '0xa27d9f8' [Aug 9 11:45:50] VERBOSE[31464] chan_sip.c: <--- SIP read from UDP:10.21.0.135:5060 ---> REGISTER sip:10.21.0.146 SIP/2.0 Via: SIP/2.0/UDP 10.21.0.135;branch=z9hG4bKac53383786 Max-Forwards: 70 From: ;tag=1c53374059 To: Call-ID: 1144486179131200004539@10.21.0.135 CSeq: 2105 REGISTER Contact: ;expires=180 Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE Expires: 180 User-Agent: Audiocodes-Sip-Gateway-/v.5.80A.023.006 Content-Length: 0 <-------------> [Aug 9 11:45:50] DEBUG[31464] chan_sip.c: Header 0 [ 32]: REGISTER sip:10.21.0.146 SIP/2.0 [Aug 9 11:45:50] DEBUG[31464] chan_sip.c: Header 1 [ 53]: Via: SIP/2.0/UDP 10.21.0.135;branch=z9hG4bKac53383786 [Aug 9 11:45:50] DEBUG[31464] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Aug 9 11:45:50] DEBUG[31464] chan_sip.c: Header 3 [ 46]: From: ;tag=1c53374059 [Aug 9 11:45:50] DEBUG[31464] chan_sip.c: Header 4 [ 29]: To: [Aug 9 11:45:50] DEBUG[31464] chan_sip.c: Header 5 [ 43]: Call-ID: 1144486179131200004539@10.21.0.135 [Aug 9 11:45:50] DEBUG[31464] chan_sip.c: Header 6 [ 19]: CSeq: 2105 REGISTER [Aug 9 11:45:50] DEBUG[31464] chan_sip.c: Header 7 [ 51]: Contact: ;expires=180 [Aug 9 11:45:50] DEBUG[31464] chan_sip.c: Header 8 [ 86]: Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE [Aug 9 11:45:50] DEBUG[31464] chan_sip.c: Header 9 [ 12]: Expires: 180 [Aug 9 11:45:50] DEBUG[31464] chan_sip.c: Header 10 [ 51]: User-Agent: Audiocodes-Sip-Gateway-/v.5.80A.023.006 [Aug 9 11:45:50] DEBUG[31464] chan_sip.c: Header 11 [ 17]: Content-Length: 0 [Aug 9 11:45:50] DEBUG[31464] chan_sip.c: Header 12 [ 0]: [Aug 9 11:45:50] VERBOSE[31464] chan_sip.c: --- (12 headers 0 lines) --- [Aug 9 11:45:50] DEBUG[31464] chan_sip.c: **** Received REGISTER (2) - Command in SIP REGISTER [Aug 9 11:45:50] DEBUG[31464] chan_sip.c: Initializing initreq for method REGISTER - callid 1144486179131200004539@10.21.0.135 [Aug 9 11:45:50] DEBUG[31464] netsock2.c: Splitting '10.21.0.135' gives... [Aug 9 11:45:50] DEBUG[31464] netsock2.c: ...host '10.21.0.135' and port '(null)'. [Aug 9 11:45:50] VERBOSE[31464] chan_sip.c: Sending to 10.21.0.135:5060 (no NAT) [Aug 9 11:45:50] DEBUG[31464] res_config_pgsql.c: PostgreSQL RealTime: One or more of the parameters in the config does not pass our validity checks. [Aug 9 11:45:50] DEBUG[31464] res_config_pgsql.c: PostgreSQL RealTime: Result=0xa30d188 Query: SELECT * FROM sip_buddies WHERE name = '9764700' AND host = 'dynamic' [Aug 9 11:45:50] DEBUG[31464] res_config_pgsql.c: Postgresql RealTime: Could not find any rows in table sip_buddies@asterisk. [Aug 9 11:45:50] DEBUG[31464] res_config_pgsql.c: PostgreSQL RealTime: One or more of the parameters in the config does not pass our validity checks. [Aug 9 11:45:50] DEBUG[31464] res_config_pgsql.c: PostgreSQL RealTime: Result=0xa30d188 Query: SELECT * FROM sip_buddies WHERE name = '9764700' [Aug 9 11:45:50] DEBUG[31464] res_config_pgsql.c: Postgresql RealTime: Could not find any rows in table sip_buddies@asterisk. [Aug 9 11:45:50] VERBOSE[31464] chan_sip.c: <--- Transmitting (no NAT) to 10.21.0.135:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 10.21.0.135;branch=z9hG4bKac53383786;received=10.21.0.135 From: ;tag=1c53374059 To: Call-ID: 1144486179131200004539@10.21.0.135 CSeq: 2105 REGISTER Server: Asterisk PBX 1.8.0-beta2 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer Content-Length: 0 <------------> [Aug 9 11:45:50] DEBUG[31464] chan_sip.c: Trying to put 'SIP/2.0 100' onto UDP socket destined for 10.21.0.135:5060 [Aug 9 11:45:50] VERBOSE[31464] chan_sip.c: <--- Transmitting (no NAT) to 10.21.0.135:5060 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 10.21.0.135;branch=z9hG4bKac53383786;received=10.21.0.135 From: ;tag=1c53374059 To: ;tag=as1db86c62 Call-ID: 1144486179131200004539@10.21.0.135 CSeq: 2105 REGISTER Server: Asterisk PBX 1.8.0-beta2 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH Supported: replaces, timer WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="634c0566" Content-Length: 0 <------------> [Aug 9 11:45:50] DEBUG[31464] chan_sip.c: Trying to put 'SIP/2.0 401' onto UDP socket destined for 10.21.0.135:5060 [Aug 9 11:45:50] VERBOSE[31464] chan_sip.c: Scheduling destruction of SIP dialog '1144486179131200004539@10.21.0.135' in 32000 ms (Method: REGISTER) [Aug 9 11:45:50] NOTICE[31464] chan_sip.c: Registration from '' failed for '10.21.0.135:5060' - No matching peer found [Aug 9 11:45:50] VERBOSE[31464] chan_sip.c: Scheduling destruction of SIP dialog '1144486179131200004539@10.21.0.135' in 32000 ms (Method: REGISTER) [Aug 9 11:46:07] DEBUG[31464] chan_sip.c: Auto destroying SIP dialog '218437655d848d51367a65487e733ae9@TTTSS' [Aug 9 11:46:07] DEBUG[31464] chan_sip.c: Destroying SIP dialog 218437655d848d51367a65487e733ae9@TTTSS [Aug 9 11:46:07] VERBOSE[31464] chan_sip.c: Really destroying SIP dialog '218437655d848d51367a65487e733ae9@TTTSS' Method: BYE [Aug 9 11:46:07] DEBUG[31464] rtp_engine.c: Destroyed RTP instance '0xa2f3460' [Aug 9 11:46:22] DEBUG[31464] chan_sip.c: Auto destroying SIP dialog '1144486179131200004539@10.21.0.135' [Aug 9 11:46:22] DEBUG[31464] chan_sip.c: Destroying SIP dialog 1144486179131200004539@10.21.0.135 [Aug 9 11:46:22] VERBOSE[31464] chan_sip.c: Really destroying SIP dialog '1144486179131200004539@10.21.0.135' Method: REGISTER [Aug 9 11:52:00] VERBOSE[32296] asterisk.c: -- Remote UNIX connection disconnected [Aug 9 11:55:11] DEBUG[31464] chan_sip.c: Session timer expired: 4900 - 888d30-26160d0a-13c4-50029-386e914b-2ef98ba0-386e914b [Aug 9 11:55:11] DEBUG[31464] chan_sip.c: Session timer stopped: -1 - 888d30-26160d0a-13c4-50029-386e914b-2ef98ba0-386e914b [Aug 9 11:55:11] DEBUG[31464] chan_sip.c: Destroying SIP dialog 888d30-26160d0a-13c4-50029-386e914b-2ef98ba0-386e914b [Aug 9 11:55:11] VERBOSE[31464] chan_sip.c: Really destroying SIP dialog '888d30-26160d0a-13c4-50029-386e914b-2ef98ba0-386e914b' Method: ACK [Aug 9 11:55:11] DEBUG[31464] rtp_engine.c: Destroyed RTP instance '0xa24d320' [Aug 9 11:55:32] VERBOSE[31453] asterisk.c: -- Remote UNIX connection