root@asterisk:~# tail -f /var/log/asterisk/full [2009-09-28 16:20:45] DEBUG[20544] devicestate.c: No provider found, checking channel drivers for IAX2 - FaxDSP0 [2009-09-28 16:20:45] DEBUG[20544] chan_iax2.c: Checking device state for device FaxDSP0 [2009-09-28 16:20:45] DEBUG[20544] chan_iax2.c: iax2_devicestate: Found peer. What's device state of FaxDSP0? addr=2130706433, defaddr=0 maxms=0, lastms=0 [2009-09-28 16:20:45] DEBUG[20544] devicestate.c: Changing state for IAX2/FaxDSP0 - state 0 (Unknown) [2009-09-28 16:20:45] DEBUG[20544] devicestate.c: device 'IAX2/FaxDSP0' state '0' [2009-09-28 16:20:45] DEBUG[20544] devicestate.c: No provider found, checking channel drivers for IAX2 - FaxDSP0 [2009-09-28 16:20:45] DEBUG[20544] chan_iax2.c: Checking device state for device FaxDSP0 [2009-09-28 16:20:45] DEBUG[20544] chan_iax2.c: iax2_devicestate: Found peer. What's device state of FaxDSP0? addr=2130706433, defaddr=0 maxms=0, lastms=0 [2009-09-28 16:20:45] DEBUG[20544] devicestate.c: Changing state for IAX2/FaxDSP0 - state 0 (Unknown) [2009-09-28 16:20:45] DEBUG[20544] devicestate.c: device 'IAX2/FaxDSP0' state '0' [2009-09-28 16:20:56] VERBOSE[20575] chan_sip.c: [2009-09-28 16:20:56] <--- SIP read from UDP:192.168.0.30:5060 ---> INVITE sip:8000@asterisk.crosscomm.net SIP/2.0 Via: SIP/2.0/UDP 192.168.0.30:5060;branch=z9hG4bK-ae940c3 From: CrossComm, Inc. ;tag=26d2eea73721f323o0 To: Call-ID: af00e7f7-1143ca13@192.168.0.30 CSeq: 101 INVITE Max-Forwards: 70 Contact: CrossComm, Inc. Expires: 240 User-Agent: Linksys/PAP2T-5.1.6(LS) Content-Length: 397 Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER Supported: x-sipura, replaces Content-Type: application/sdp v=0 o=- 1226527 1226527 IN IP4 192.168.0.30 s=- c=IN IP4 192.168.0.30 t=0 0 m=audio 16460 RTP/AVP 0 2 4 8 18 96 97 98 101 a=rtpmap:0 PCMU/8000 a=rtpmap:2 G726-32/8000 a=rtpmap:4 G723/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:18 G729a/8000 a=rtpmap:96 G726-40/8000 a=rtpmap:97 G726-24/8000 a=rtpmap:98 G726-16/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:30 a=sendrecv <-------------> [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Header 0 [ 46]: INVITE sip:8000@asterisk.crosscomm.net SIP/2.0 [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Header 1 [ 57]: Via: SIP/2.0/UDP 192.168.0.30:5060;branch=z9hG4bK-ae940c3 [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Header 2 [ 79]: From: CrossComm, Inc. ;tag=26d2eea73721f323o0 [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Header 3 [ 37]: To: [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Header 4 [ 39]: Call-ID: af00e7f7-1143ca13@192.168.0.30 [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Header 5 [ 16]: CSeq: 101 INVITE [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Header 6 [ 16]: Max-Forwards: 70 [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Header 7 [ 54]: Contact: CrossComm, Inc. [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Header 8 [ 12]: Expires: 240 [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Header 9 [ 35]: User-Agent: Linksys/PAP2T-5.1.6(LS) [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Header 10 [ 19]: Content-Length: 397 [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Header 11 [ 61]: Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Header 12 [ 29]: Supported: x-sipura, replaces [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Header 13 [ 29]: Content-Type: application/sdp [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Header 14 [ 0]: [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Body 0 [ 3]: v=0 [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Body 1 [ 39]: o=- 1226527 1226527 IN IP4 192.168.0.30 [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Body 2 [ 3]: s=- [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Body 3 [ 21]: c=IN IP4 192.168.0.30 [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Body 4 [ 5]: t=0 0 [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Body 5 [ 45]: m=audio 16460 RTP/AVP 0 2 4 8 18 96 97 98 101 [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Body 6 [ 20]: a=rtpmap:0 PCMU/8000 [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Body 7 [ 23]: a=rtpmap:2 G726-32/8000 [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Body 8 [ 20]: a=rtpmap:4 G723/8000 [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Body 9 [ 20]: a=rtpmap:8 PCMA/8000 [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Body 10 [ 22]: a=rtpmap:18 G729a/8000 [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Body 11 [ 24]: a=rtpmap:96 G726-40/8000 [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Body 12 [ 24]: a=rtpmap:97 G726-24/8000 [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Body 13 [ 24]: a=rtpmap:98 G726-16/8000 [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Body 14 [ 33]: a=rtpmap:101 telephone-event/8000 [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Body 15 [ 15]: a=fmtp:101 0-15 [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Body 16 [ 10]: a=ptime:30 [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Body 17 [ 10]: a=sendrecv [2009-09-28 16:20:56] VERBOSE[20575] chan_sip.c: [2009-09-28 16:20:56] --- (14 headers 18 lines) --- [2009-09-28 16:20:56] DEBUG[20575] acl.c: Found IP address for this socket [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 64.105.202.244:5060 [2009-09-28 16:20:56] VERBOSE[20575] netsock.c: [2009-09-28 16:20:56] == Using SIP RTP TOS bits 16 [2009-09-28 16:20:56] VERBOSE[20575] netsock.c: [2009-09-28 16:20:56] == Using SIP RTP CoS mark 5 [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Setting NAT on RTP to Off [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Allocating new SIP dialog for af00e7f7-1143ca13@192.168.0.30 - INVITE (With RTP) [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Begin: parsing SIP "Supported: x-sipura, replaces" [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Found SIP option: -x-sipura- [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Found private SIP option, not supported: x-sipura [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Found SIP option: -replaces- [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Matched SIP option: replaces [2009-09-28 16:20:56] VERBOSE[20575] chan_sip.c: [2009-09-28 16:20:56] Sending to 192.168.0.30 : 5060 (no NAT) [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Initializing initreq for method INVITE - callid af00e7f7-1143ca13@192.168.0.30 [2009-09-28 16:20:56] VERBOSE[20575] chan_sip.c: [2009-09-28 16:20:56] Using INVITE request as basis request - af00e7f7-1143ca13@192.168.0.30 [2009-09-28 16:20:56] VERBOSE[20575] chan_sip.c: [2009-09-28 16:20:56] Found peer 'line3' for 'line3' from 192.168.0.30:5060 [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Setting NAT on RTP to Off [2009-09-28 16:20:56] VERBOSE[20575] chan_sip.c: [2009-09-28 16:20:56] <--- Reliably Transmitting (no NAT) to 192.168.0.30:5060 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 192.168.0.30:5060;branch=z9hG4bK-ae940c3;received=192.168.0.30 From: CrossComm, Inc. ;tag=26d2eea73721f323o0 To: ;tag=as266dcab4 Call-ID: af00e7f7-1143ca13@192.168.0.30 CSeq: 101 INVITE Server: Asterisk PBX 1.6.2.0-beta4 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer WWW-Authenticate: Digest algorithm=MD5, realm="asterisk.crosscomm.net", nonce="2c035955" Content-Length: 0 <------------> [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Header 0 [ 24]: SIP/2.0 401 Unauthorized [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Header 1 [ 79]: Via: SIP/2.0/UDP 192.168.0.30:5060;branch=z9hG4bK-ae940c3;received=192.168.0.30 [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Header 2 [ 79]: From: CrossComm, Inc. ;tag=26d2eea73721f323o0 [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Header 3 [ 52]: To: ;tag=as266dcab4 [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Header 4 [ 39]: Call-ID: af00e7f7-1143ca13@192.168.0.30 [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Header 5 [ 16]: CSeq: 101 INVITE [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Header 6 [ 34]: Server: Asterisk PBX 1.6.2.0-beta4 [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Header 7 [ 72]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Header 8 [ 26]: Supported: replaces, timer [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Header 9 [ 88]: WWW-Authenticate: Digest algorithm=MD5, realm="asterisk.crosscomm.net", nonce="2c035955" [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Header 10 [ 17]: Content-Length: 0 [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Header 11 [ 0]: [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #37 [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Trying to put 'SIP/2.0 40' onto UDP socket destined for 192.168.0.30:5060 [2009-09-28 16:20:56] VERBOSE[20575] chan_sip.c: [2009-09-28 16:20:56] Scheduling destruction of SIP dialog 'af00e7f7-1143ca13@192.168.0.30' in 6400 ms (Method: INVITE) [2009-09-28 16:20:56] VERBOSE[20575] chan_sip.c: [2009-09-28 16:20:56] <--- SIP read from UDP:192.168.0.30:5060 ---> ACK sip:8000@asterisk.crosscomm.net SIP/2.0 Via: SIP/2.0/UDP 192.168.0.30:5060;branch=z9hG4bK-ae940c3 From: CrossComm, Inc. ;tag=26d2eea73721f323o0 To: ;tag=as266dcab4 Call-ID: af00e7f7-1143ca13@192.168.0.30 CSeq: 101 ACK Max-Forwards: 70 Contact: CrossComm, Inc. User-Agent: Linksys/PAP2T-5.1.6(LS) Content-Length: 0 <-------------> [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Header 0 [ 43]: ACK sip:8000@asterisk.crosscomm.net SIP/2.0 [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Header 1 [ 57]: Via: SIP/2.0/UDP 192.168.0.30:5060;branch=z9hG4bK-ae940c3 [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Header 2 [ 79]: From: CrossComm, Inc. ;tag=26d2eea73721f323o0 [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Header 3 [ 52]: To: ;tag=as266dcab4 [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Header 4 [ 39]: Call-ID: af00e7f7-1143ca13@192.168.0.30 [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Header 5 [ 13]: CSeq: 101 ACK [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Header 6 [ 16]: Max-Forwards: 70 [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Header 7 [ 54]: Contact: CrossComm, Inc. [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Header 8 [ 35]: User-Agent: Linksys/PAP2T-5.1.6(LS) [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Header 9 [ 17]: Content-Length: 0 [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Header 10 [ 0]: [2009-09-28 16:20:56] VERBOSE[20575] chan_sip.c: [2009-09-28 16:20:56] --- (10 headers 0 lines) --- [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: **** Received ACK (6) - Command in SIP ACK [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #37 [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Stopping retransmission on 'af00e7f7-1143ca13@192.168.0.30' of Response 101: Match Found [2009-09-28 16:20:56] VERBOSE[20575] chan_sip.c: [2009-09-28 16:20:56] <--- SIP read from UDP:192.168.0.30:5060 ---> INVITE sip:8000@asterisk.crosscomm.net SIP/2.0 Via: SIP/2.0/UDP 192.168.0.30:5060;branch=z9hG4bK-df83152f From: CrossComm, Inc. ;tag=26d2eea73721f323o0 To: Call-ID: af00e7f7-1143ca13@192.168.0.30 CSeq: 102 INVITE Max-Forwards: 70 Authorization: Digest username="line3",realm="asterisk.crosscomm.net",nonce="2c035955",uri="sip:8000@asterisk.crosscomm.net",algorithm=MD5,response="4a501d5b223f291d1b1112737a607a73" Contact: CrossComm, Inc. Expires: 240 User-Agent: Linksys/PAP2T-5.1.6(LS) Content-Length: 397 Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER Supported: x-sipura, replaces Content-Type: application/sdp v=0 o=- 1226527 1226527 IN IP4 192.168.0.30 s=- c=IN IP4 192.168.0.30 t=0 0 m=audio 16460 RTP/AVP 0 2 4 8 18 96 97 98 101 a=rtpmap:0 PCMU/8000 a=rtpmap:2 G726-32/8000 a=rtpmap:4 G723/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:18 G729a/8000 a=rtpmap:96 G726-40/8000 a=rtpmap:97 G726-24/8000 a=rtpmap:98 G726-16/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:30 a=sendrecv <-------------> [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Header 0 [ 46]: INVITE sip:8000@asterisk.crosscomm.net SIP/2.0 [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Header 1 [ 58]: Via: SIP/2.0/UDP 192.168.0.30:5060;branch=z9hG4bK-df83152f [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Header 2 [ 79]: From: CrossComm, Inc. ;tag=26d2eea73721f323o0 [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Header 3 [ 37]: To: [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Header 4 [ 39]: Call-ID: af00e7f7-1143ca13@192.168.0.30 [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Header 5 [ 16]: CSeq: 102 INVITE [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Header 6 [ 16]: Max-Forwards: 70 [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Header 7 [182]: Authorization: Digest username="line3",realm="asterisk.crosscomm.net",nonce="2c035955",uri="sip:8000@asterisk.crosscomm.net",algorithm=MD5,response="4a501d5b223f291d1b1112737a607a73" [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Header 8 [ 54]: Contact: CrossComm, Inc. [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Header 9 [ 12]: Expires: 240 [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Header 10 [ 35]: User-Agent: Linksys/PAP2T-5.1.6(LS) [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Header 11 [ 19]: Content-Length: 397 [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Header 12 [ 61]: Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Header 13 [ 29]: Supported: x-sipura, replaces [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Header 14 [ 29]: Content-Type: application/sdp [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Header 15 [ 0]: [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Body 0 [ 3]: v=0 [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Body 1 [ 39]: o=- 1226527 1226527 IN IP4 192.168.0.30 [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Body 2 [ 3]: s=- [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Body 3 [ 21]: c=IN IP4 192.168.0.30 [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Body 4 [ 5]: t=0 0 [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Body 5 [ 45]: m=audio 16460 RTP/AVP 0 2 4 8 18 96 97 98 101 [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Body 6 [ 20]: a=rtpmap:0 PCMU/8000 [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Body 7 [ 23]: a=rtpmap:2 G726-32/8000 [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Body 8 [ 20]: a=rtpmap:4 G723/8000 [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Body 9 [ 20]: a=rtpmap:8 PCMA/8000 [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Body 10 [ 22]: a=rtpmap:18 G729a/8000 [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Body 11 [ 24]: a=rtpmap:96 G726-40/8000 [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Body 12 [ 24]: a=rtpmap:97 G726-24/8000 [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Body 13 [ 24]: a=rtpmap:98 G726-16/8000 [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Body 14 [ 33]: a=rtpmap:101 telephone-event/8000 [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Body 15 [ 15]: a=fmtp:101 0-15 [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Body 16 [ 10]: a=ptime:30 [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Body 17 [ 10]: a=sendrecv [2009-09-28 16:20:56] VERBOSE[20575] chan_sip.c: [2009-09-28 16:20:56] --- (15 headers 18 lines) --- [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE [2009-09-28 16:20:56] VERBOSE[20575] chan_sip.c: [2009-09-28 16:20:56] Sending to 192.168.0.30 : 5060 (no NAT) [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Initializing initreq for method INVITE - callid af00e7f7-1143ca13@192.168.0.30 [2009-09-28 16:20:56] VERBOSE[20575] chan_sip.c: [2009-09-28 16:20:56] Using INVITE request as basis request - af00e7f7-1143ca13@192.168.0.30 [2009-09-28 16:20:56] VERBOSE[20575] chan_sip.c: [2009-09-28 16:20:56] Found peer 'line3' for 'line3' from 192.168.0.30:5060 [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Setting NAT on RTP to Off [2009-09-28 16:20:56] VERBOSE[20575] chan_sip.c: [2009-09-28 16:20:56] Found RTP audio format 0 [2009-09-28 16:20:56] VERBOSE[20575] chan_sip.c: [2009-09-28 16:20:56] Found RTP audio format 2 [2009-09-28 16:20:56] VERBOSE[20575] chan_sip.c: [2009-09-28 16:20:56] Found RTP audio format 4 [2009-09-28 16:20:56] VERBOSE[20575] chan_sip.c: [2009-09-28 16:20:56] Found RTP audio format 8 [2009-09-28 16:20:56] VERBOSE[20575] chan_sip.c: [2009-09-28 16:20:56] Found RTP audio format 18 [2009-09-28 16:20:56] VERBOSE[20575] chan_sip.c: [2009-09-28 16:20:56] Found RTP audio format 96 [2009-09-28 16:20:56] VERBOSE[20575] chan_sip.c: [2009-09-28 16:20:56] Found RTP audio format 97 [2009-09-28 16:20:56] VERBOSE[20575] chan_sip.c: [2009-09-28 16:20:56] Found RTP audio format 98 [2009-09-28 16:20:56] VERBOSE[20575] chan_sip.c: [2009-09-28 16:20:56] Found RTP audio format 101 [2009-09-28 16:20:56] VERBOSE[20575] chan_sip.c: [2009-09-28 16:20:56] Peer audio RTP is at port 192.168.0.30:16460 [2009-09-28 16:20:56] VERBOSE[20575] chan_sip.c: [2009-09-28 16:20:56] Found audio description format PCMU for ID 0 [2009-09-28 16:20:56] VERBOSE[20575] chan_sip.c: [2009-09-28 16:20:56] Found audio description format G726-32 for ID 2 [2009-09-28 16:20:56] VERBOSE[20575] chan_sip.c: [2009-09-28 16:20:56] Found audio description format G723 for ID 4 [2009-09-28 16:20:56] VERBOSE[20575] chan_sip.c: [2009-09-28 16:20:56] Found audio description format PCMA for ID 8 [2009-09-28 16:20:56] VERBOSE[20575] chan_sip.c: [2009-09-28 16:20:56] Found audio description format G729a for ID 18 [2009-09-28 16:20:56] VERBOSE[20575] chan_sip.c: [2009-09-28 16:20:56] Found audio description format G726-40 for ID 96 [2009-09-28 16:20:56] VERBOSE[20575] chan_sip.c: [2009-09-28 16:20:56] Found audio description format G726-24 for ID 97 [2009-09-28 16:20:56] VERBOSE[20575] chan_sip.c: [2009-09-28 16:20:56] Found audio description format G726-16 for ID 98 [2009-09-28 16:20:56] VERBOSE[20575] chan_sip.c: [2009-09-28 16:20:56] Found audio description format telephone-event for ID 101 [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Got unsupported a:fmtp:101 0-15 in SDP offer [2009-09-28 16:20:56] VERBOSE[20575] chan_sip.c: [2009-09-28 16:20:56] Capabilities: us - 0xc (ulaw|alaw), peer - audio=0x100d0d (g723|ulaw|alaw|g726|g729|ilbc|h263p)/video=0x0 (nothing)/text=0x0 (nothing), combined - 0xc (ulaw|alaw) [2009-09-28 16:20:56] VERBOSE[20575] chan_sip.c: [2009-09-28 16:20:56] Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) [2009-09-28 16:20:56] VERBOSE[20575] chan_sip.c: [2009-09-28 16:20:56] Peer audio RTP is at port 192.168.0.30:16460 [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: We're settling with these formats: 0xc (ulaw|alaw) [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Checking SIP call limits for device line3 [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Updating call counter for incoming call [2009-09-28 16:20:56] VERBOSE[20575] chan_sip.c: [2009-09-28 16:20:56] Looking for 8000 in softphones (domain asterisk.crosscomm.net) [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: *** Our native formats are 0x4 (ulaw) [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: *** Joint capabilities are 0xc (ulaw|alaw) [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: *** Our capabilities are 0xc (ulaw|alaw) [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw) [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: This channel will not be able to handle video. [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: build_route: Contact hop: CrossComm, Inc. [2009-09-28 16:20:56] VERBOSE[20575] chan_sip.c: [2009-09-28 16:20:56] list_route: hop: [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: SIP/line3-482c8fd0: New call is still down.... Trying... [2009-09-28 16:20:56] VERBOSE[20575] chan_sip.c: [2009-09-28 16:20:56] <--- Transmitting (no NAT) to 192.168.0.30:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.0.30:5060;branch=z9hG4bK-df83152f;received=192.168.0.30 From: CrossComm, Inc. ;tag=26d2eea73721f323o0 To: Call-ID: af00e7f7-1143ca13@192.168.0.30 CSeq: 102 INVITE Server: Asterisk PBX 1.6.2.0-beta4 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Contact: Content-Length: 0 <------------> [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Header 0 [ 18]: SIP/2.0 100 Trying [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Header 1 [ 80]: Via: SIP/2.0/UDP 192.168.0.30:5060;branch=z9hG4bK-df83152f;received=192.168.0.30 [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Header 2 [ 79]: From: CrossComm, Inc. ;tag=26d2eea73721f323o0 [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Header 3 [ 37]: To: [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Header 4 [ 39]: Call-ID: af00e7f7-1143ca13@192.168.0.30 [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Header 5 [ 16]: CSeq: 102 INVITE [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Header 6 [ 34]: Server: Asterisk PBX 1.6.2.0-beta4 [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Header 7 [ 72]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Header 8 [ 26]: Supported: replaces, timer [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Header 9 [ 34]: Contact: [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Header 10 [ 17]: Content-Length: 0 [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Header 11 [ 0]: [2009-09-28 16:20:56] DEBUG[20575] chan_sip.c: Trying to put 'SIP/2.0 10' onto UDP socket destined for 192.168.0.30:5060 [2009-09-28 16:20:56] DEBUG[20544] devicestate.c: No provider found, checking channel drivers for SIP - line3 [2009-09-28 16:20:56] DEBUG[20544] chan_sip.c: Checking device state for peer line3 [2009-09-28 16:20:56] DEBUG[20544] devicestate.c: Changing state for SIP/line3 - state 1 (Not in use) [2009-09-28 16:20:56] DEBUG[20544] devicestate.c: device 'SIP/line3' state '1' [2009-09-28 16:20:56] DEBUG[20545] devicestate.c: No provider found, checking channel drivers for SIP - line3 [2009-09-28 16:20:56] DEBUG[20545] chan_sip.c: Checking device state for peer line3 [2009-09-28 16:20:56] DEBUG[20545] devicestate.c: No provider found, checking channel drivers for IAX2 - line3 [2009-09-28 16:20:56] DEBUG[20545] chan_iax2.c: Checking device state for device line3 [2009-09-28 16:20:56] DEBUG[20545] chan_iax2.c: iax2_devicestate: Found peer. What's device state of line3? addr=0, defaddr=0 maxms=2000, lastms=0 [2009-09-28 16:20:56] DEBUG[20607] pbx.c: Launching 'ConfBridge' [2009-09-28 16:20:56] VERBOSE[20607] pbx.c: [2009-09-28 16:20:56] -- Executing [8000@softphones:1] ConfBridge("SIP/line3-482c8fd0", "8000") in new stack [2009-09-28 16:20:56] DEBUG[20607] app_confbridge.c: Trying to find conference bridge '8000' [2009-09-28 16:20:56] DEBUG[20607] bridging.c: Bridge technology softmix has capabilities 52 and we want 4 [2009-09-28 16:20:56] DEBUG[20607] bridging.c: Bridge technology multiplexed_bridge has capabilities 2 and we want 4 [2009-09-28 16:20:56] DEBUG[20607] bridging.c: Bridge technology multiplexed_bridge does not have the capabilities we need. [2009-09-28 16:20:56] DEBUG[20607] bridging.c: Bridge technology simple_bridge has capabilities 34 and we want 4 [2009-09-28 16:20:56] DEBUG[20607] bridging.c: Bridge technology simple_bridge does not have the capabilities we need. [2009-09-28 16:20:56] DEBUG[20607] bridging.c: Chose bridge technology softmix [2009-09-28 16:20:56] DEBUG[20607] bridging.c: Giving bridge technology softmix the bridge structure 0x1034dd90 to setup [2009-09-28 16:20:56] DEBUG[20607] bridging.c: Telling all channels in bridge 0x1034dd90 to end and leave the party [2009-09-28 16:20:56] DEBUG[20607] bridging.c: Actually destroying bridge 0x1034dd90, nobody wants it anymore [2009-09-28 16:20:56] DEBUG[20607] bridging.c: Giving bridge technology softmix the bridge structure 0x1034dd90 to destroy [2009-09-28 16:20:56] DEBUG[20607] bridging.c: Bridge technology softmix has capabilities 52 and we want 2 [2009-09-28 16:20:56] DEBUG[20607] bridging.c: Bridge technology softmix does not have the capabilities we need. [2009-09-28 16:20:56] DEBUG[20607] bridging.c: Bridge technology multiplexed_bridge has capabilities 2 and we want 2 [2009-09-28 16:20:56] DEBUG[20607] bridging.c: Bridge technology simple_bridge has capabilities 34 and we want 2 [2009-09-28 16:20:56] DEBUG[20607] bridging.c: Bridge technology simple_bridge has preference 1 while multiplexed_bridge has preference 0. Skipping. [2009-09-28 16:20:56] DEBUG[20607] bridging.c: Chose bridge technology multiplexed_bridge [2009-09-28 16:20:56] DEBUG[20607] bridging.c: Giving bridge technology multiplexed_bridge the bridge structure 0x1034dd98 to setup [2009-09-28 16:20:56] DEBUG[20607] bridge_multiplexed.c: Created multiplexed thread '0x10354a98' for bridge '0x1034dd98' [2009-09-28 16:20:56] DEBUG[20607] app_confbridge.c: Created conference bridge '8000' and linked to container '0x482a0408' [2009-09-28 16:20:56] DEBUG[20607] channel.c: Set channel SIP/line3-482c8fd0 to write format slin [2009-09-28 16:20:56] DEBUG[20607] chan_sip.c: Setting framing from config on incoming call [2009-09-28 16:20:56] DEBUG[20607] chan_sip.c: ** Our capability: 0xc (ulaw|alaw) Video flag: True Text flag: True [2009-09-28 16:20:56] DEBUG[20607] chan_sip.c: ** Our prefcodec: 0x0 (nothing) [2009-09-28 16:20:56] VERBOSE[20607] chan_sip.c: [2009-09-28 16:20:56] Audio is at 64.105.202.244 port 20016 [2009-09-28 16:20:56] VERBOSE[20607] chan_sip.c: [2009-09-28 16:20:56] Adding codec 0x4 (ulaw) to SDP [2009-09-28 16:20:56] VERBOSE[20607] chan_sip.c: [2009-09-28 16:20:56] Adding codec 0x8 (alaw) to SDP [2009-09-28 16:20:56] VERBOSE[20607] chan_sip.c: [2009-09-28 16:20:56] Adding non-codec 0x1 (telephone-event) to SDP [2009-09-28 16:20:56] DEBUG[20607] chan_sip.c: -- Done with adding codecs to SDP [2009-09-28 16:20:56] DEBUG[20607] channel.c: Internal timing is disabled (option_internal_timing=0 chan->timingfd=36) [2009-09-28 16:20:56] DEBUG[20607] chan_sip.c: Done building SDP. Settling with this capability: 0xc (ulaw|alaw) [2009-09-28 16:20:56] VERBOSE[20607] chan_sip.c: [2009-09-28 16:20:56] <--- Transmitting (no NAT) to 192.168.0.30:5060 ---> SIP/2.0 183 Session Progress Via: SIP/2.0/UDP 192.168.0.30:5060;branch=z9hG4bK-df83152f;received=192.168.0.30 From: CrossComm, Inc. ;tag=26d2eea73721f323o0 To: ;tag=as5fb80a11 Call-ID: af00e7f7-1143ca13@192.168.0.30 CSeq: 102 INVITE Server: Asterisk PBX 1.6.2.0-beta4 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Contact: Content-Type: application/sdp Content-Length: 297 v=0 o=root 1376066602 1376066602 IN IP4 64.105.202.244 s=Asterisk PBX 1.6.2.0-beta4 c=IN IP4 64.105.202.244 t=0 0 m=audio 20016 RTP/AVP 0 8 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv <------------> [2009-09-28 16:20:56] DEBUG[20607] chan_sip.c: Header 0 [ 28]: SIP/2.0 183 Session Progress [2009-09-28 16:20:56] DEBUG[20607] chan_sip.c: Header 1 [ 80]: Via: SIP/2.0/UDP 192.168.0.30:5060;branch=z9hG4bK-df83152f;received=192.168.0.30 [2009-09-28 16:20:56] DEBUG[20607] chan_sip.c: Header 2 [ 79]: From: CrossComm, Inc. ;tag=26d2eea73721f323o0 [2009-09-28 16:20:56] DEBUG[20607] chan_sip.c: Header 3 [ 52]: To: ;tag=as5fb80a11 [2009-09-28 16:20:56] DEBUG[20607] chan_sip.c: Header 4 [ 39]: Call-ID: af00e7f7-1143ca13@192.168.0.30 [2009-09-28 16:20:56] DEBUG[20607] chan_sip.c: Header 5 [ 16]: CSeq: 102 INVITE [2009-09-28 16:20:56] DEBUG[20607] chan_sip.c: Header 6 [ 34]: Server: Asterisk PBX 1.6.2.0-beta4 [2009-09-28 16:20:56] DEBUG[20607] chan_sip.c: Header 7 [ 72]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO [2009-09-28 16:20:56] DEBUG[20607] chan_sip.c: Header 8 [ 26]: Supported: replaces, timer [2009-09-28 16:20:56] DEBUG[20607] chan_sip.c: Header 9 [ 34]: Contact: [2009-09-28 16:20:56] DEBUG[20607] chan_sip.c: Header 10 [ 29]: Content-Type: application/sdp [2009-09-28 16:20:56] DEBUG[20607] chan_sip.c: Header 11 [ 19]: Content-Length: 297 [2009-09-28 16:20:56] DEBUG[20607] chan_sip.c: Header 12 [ 0]: [2009-09-28 16:20:56] DEBUG[20607] chan_sip.c: Body 0 [ 3]: v=0 [2009-09-28 16:20:56] DEBUG[20607] chan_sip.c: Body 1 [ 50]: o=root 1376066602 1376066602 IN IP4 64.105.202.244 [2009-09-28 16:20:56] DEBUG[20607] chan_sip.c: Body 2 [ 28]: s=Asterisk PBX 1.6.2.0-beta4 [2009-09-28 16:20:56] DEBUG[20607] chan_sip.c: Body 3 [ 23]: c=IN IP4 64.105.202.244 [2009-09-28 16:20:56] DEBUG[20607] chan_sip.c: Body 4 [ 5]: t=0 0 [2009-09-28 16:20:56] DEBUG[20607] chan_sip.c: Body 5 [ 29]: m=audio 20016 RTP/AVP 0 8 101 [2009-09-28 16:20:56] DEBUG[20607] chan_sip.c: Body 6 [ 20]: a=rtpmap:0 PCMU/8000 [2009-09-28 16:20:56] DEBUG[20607] chan_sip.c: Body 7 [ 20]: a=rtpmap:8 PCMA/8000 [2009-09-28 16:20:56] DEBUG[20607] chan_sip.c: Body 8 [ 33]: a=rtpmap:101 telephone-event/8000 [2009-09-28 16:20:56] DEBUG[20607] chan_sip.c: Body 9 [ 15]: a=fmtp:101 0-16 [2009-09-28 16:20:56] DEBUG[20607] chan_sip.c: Body 10 [ 25]: a=silenceSupp:off - - - - [2009-09-28 16:20:56] DEBUG[20607] chan_sip.c: Body 11 [ 10]: a=ptime:20 [2009-09-28 16:20:56] DEBUG[20607] chan_sip.c: Body 12 [ 10]: a=sendrecv [2009-09-28 16:20:56] DEBUG[20607] chan_sip.c: Trying to put 'SIP/2.0 18' onto UDP socket destined for 192.168.0.30:5060 [2009-09-28 16:20:56] DEBUG[20607] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second [2009-09-28 16:20:56] VERBOSE[20607] file.c: [2009-09-28 16:20:56] -- Playing 'conf-onlyperson.slin' (language 'en') [2009-09-28 16:20:56] DEBUG[20607] rtp.c: Ooh, format changed from unknown to ulaw [2009-09-28 16:20:56] DEBUG[20607] rtp.c: Created smoother: format: 4 ms: 20 len: 160 [2009-09-28 16:20:59] DEBUG[20607] channel.c: Scheduling timer at (113 requested / 100 actual) timer ticks per second [2009-09-28 16:20:59] DEBUG[20607] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [2009-09-28 16:20:59] DEBUG[20607] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [2009-09-28 16:20:59] DEBUG[20607] channel.c: Set channel SIP/line3-482c8fd0 to write format ulaw [2009-09-28 16:20:59] DEBUG[20607] bridging.c: Joining bridge channel 0x488ea520 to bridge 0x1034dd98 [2009-09-28 16:20:59] DEBUG[20607] bridging.c: Added channel SIP/line3-482c8fd0(0x482cd848) to bridge array on 0x1034dd98, new count is 1 [2009-09-28 16:20:59] DEBUG[20607] bridging.c: Bridge 0x1034dd98 channel count (1) is within limits for bridge technology multiplexed_bridge, not performing smart bridge operation. [2009-09-28 16:20:59] DEBUG[20607] bridging.c: Bridge 0x1034dd98 is happy that channel SIP/line3-482c8fd0 already has read format ulaw(4) [2009-09-28 16:20:59] DEBUG[20607] bridging.c: Bridge 0x1034dd98 is happy that channel SIP/line3-482c8fd0 already has write format ulaw(4) [2009-09-28 16:20:59] DEBUG[20607] bridging.c: Giving bridge technology multiplexed_bridge notification that 0x488ea520 is joining bridge 0x1034dd98 [2009-09-28 16:20:59] DEBUG[20607] bridge_multiplexed.c: Adding channel 'SIP/line3-482c8fd0' to multiplexed thread '0x10354a98' for monitoring [2009-09-28 16:20:59] DEBUG[20607] bridging.c: Going into a single threaded signal wait for bridge channel 0x488ea520 of bridge 0x1034dd98 [2009-09-28 16:20:59] DEBUG[20608] bridge_multiplexed.c: Starting actual thread for multiplexed thread '0x10354a98' [2009-09-28 16:21:01] VERBOSE[20575] chan_sip.c: [2009-09-28 16:21:01] <--- SIP read from UDP:64.61.93.190:5060 ---> INVITE sip:19192460171@64.105.202.244:5060 SIP/2.0 Record-Route: Via: SIP/2.0/UDP 64.61.93.190;branch=z9hG4bKc0b1.a1daaf32.0 Via: SIP/2.0/UDP 64.61.93.174;rport=5060;branch=z9hG4bKc0b1.4350e62.0 Via: SIP/2.0/UDP 64.61.93.170:5060;received=64.61.93.170;branch=z9hG4bK022e706f;rport=5060 From: "Martin Brendan " ;tag=as0c0039c0 To: Contact: Call-ID: 2ff281b92105b33d1363e3e6737f7e2c@64.61.93.170 CSeq: 102 INVITE User-Agent: Asterisk PBX Max-Forwards: 68 Remote-Party-ID: "Martin Brendan " ;privacy=off;screen=no Date: Mon, 28 Sep 2009 20:21:01 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Type: application/sdp Content-Length: 410 v=0 o=root 29667 29667 IN IP4 64.61.93.170 s=session c=IN IP4 64.61.93.170 t=0 0 m=audio 19496 RTP/AVP 0 8 3 97 111 5 7 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:3 GSM/8000 a=rtpmap:97 iLBC/8000 a=fmtp:97 mode=30 a=rtpmap:111 G726-32/8000 a=rtpmap:5 DVI4/8000 a=rtpmap:7 LPC/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv <-------------> [2009-09-28 16:21:01] DEBUG[20575] chan_sip.c: Header 0 [ 50]: INVITE sip:19192460171@64.105.202.244:5060 SIP/2.0 [2009-09-28 16:21:01] DEBUG[20575] chan_sip.c: Header 1 [ 95]: Record-Route: [2009-09-28 16:21:01] DEBUG[20575] chan_sip.c: Header 2 [ 59]: Via: SIP/2.0/UDP 64.61.93.190;branch=z9hG4bKc0b1.a1daaf32.0 [2009-09-28 16:21:01] DEBUG[20575] chan_sip.c: Header 3 [ 69]: Via: SIP/2.0/UDP 64.61.93.174;rport=5060;branch=z9hG4bKc0b1.4350e62.0 [2009-09-28 16:21:01] DEBUG[20575] chan_sip.c: Header 4 [ 90]: Via: SIP/2.0/UDP 64.61.93.170:5060;received=64.61.93.170;branch=z9hG4bK022e706f;rport=5060 [2009-09-28 16:21:01] DEBUG[20575] chan_sip.c: Header 5 [ 68]: From: "Martin Brendan " ;tag=as0c0039c0 [2009-09-28 16:21:01] DEBUG[20575] chan_sip.c: Header 6 [ 47]: To: [2009-09-28 16:21:01] DEBUG[20575] chan_sip.c: Header 7 [ 38]: Contact: [2009-09-28 16:21:01] DEBUG[20575] chan_sip.c: Header 8 [ 54]: Call-ID: 2ff281b92105b33d1363e3e6737f7e2c@64.61.93.170 [2009-09-28 16:21:01] DEBUG[20575] chan_sip.c: Header 9 [ 16]: CSeq: 102 INVITE [2009-09-28 16:21:01] DEBUG[20575] chan_sip.c: Header 10 [ 24]: User-Agent: Asterisk PBX [2009-09-28 16:21:01] DEBUG[20575] chan_sip.c: Header 11 [ 16]: Max-Forwards: 68 [2009-09-28 16:21:01] DEBUG[20575] chan_sip.c: Header 12 [ 86]: Remote-Party-ID: "Martin Brendan " ;privacy=off;screen=no [2009-09-28 16:21:01] DEBUG[20575] chan_sip.c: Header 13 [ 35]: Date: Mon, 28 Sep 2009 20:21:01 GMT [2009-09-28 16:21:01] DEBUG[20575] chan_sip.c: Header 14 [ 66]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY [2009-09-28 16:21:01] DEBUG[20575] chan_sip.c: Header 15 [ 19]: Supported: replaces [2009-09-28 16:21:01] DEBUG[20575] chan_sip.c: Header 16 [ 29]: Content-Type: application/sdp [2009-09-28 16:21:01] DEBUG[20575] chan_sip.c: Header 17 [ 19]: Content-Length: 410 [2009-09-28 16:21:01] DEBUG[20575] chan_sip.c: Header 18 [ 0]: [2009-09-28 16:21:01] DEBUG[20575] chan_sip.c: Body 0 [ 3]: v=0 [2009-09-28 16:21:01] DEBUG[20575] chan_sip.c: Body 1 [ 38]: o=root 29667 29667 IN IP4 64.61.93.170 [2009-09-28 16:21:01] DEBUG[20575] chan_sip.c: Body 2 [ 9]: s=session [2009-09-28 16:21:01] DEBUG[20575] chan_sip.c: Body 3 [ 21]: c=IN IP4 64.61.93.170 [2009-09-28 16:21:01] DEBUG[20575] chan_sip.c: Body 4 [ 5]: t=0 0 [2009-09-28 16:21:01] DEBUG[20575] chan_sip.c: Body 5 [ 42]: m=audio 19496 RTP/AVP 0 8 3 97 111 5 7 101 [2009-09-28 16:21:01] DEBUG[20575] chan_sip.c: Body 6 [ 20]: a=rtpmap:0 PCMU/8000 [2009-09-28 16:21:01] DEBUG[20575] chan_sip.c: Body 7 [ 20]: a=rtpmap:8 PCMA/8000 [2009-09-28 16:21:01] DEBUG[20575] chan_sip.c: Body 8 [ 19]: a=rtpmap:3 GSM/8000 [2009-09-28 16:21:01] DEBUG[20575] chan_sip.c: Body 9 [ 21]: a=rtpmap:97 iLBC/8000 [2009-09-28 16:21:01] DEBUG[20575] chan_sip.c: Body 10 [ 17]: a=fmtp:97 mode=30 [2009-09-28 16:21:01] DEBUG[20575] chan_sip.c: Body 11 [ 25]: a=rtpmap:111 G726-32/8000 [2009-09-28 16:21:01] DEBUG[20575] chan_sip.c: Body 12 [ 20]: a=rtpmap:5 DVI4/8000 [2009-09-28 16:21:01] DEBUG[20575] chan_sip.c: Body 13 [ 19]: a=rtpmap:7 LPC/8000 [2009-09-28 16:21:01] DEBUG[20575] chan_sip.c: Body 14 [ 33]: a=rtpmap:101 telephone-event/8000 [2009-09-28 16:21:01] DEBUG[20575] chan_sip.c: Body 15 [ 15]: a=fmtp:101 0-16 [2009-09-28 16:21:01] DEBUG[20575] chan_sip.c: Body 16 [ 25]: a=silenceSupp:off - - - - [2009-09-28 16:21:01] DEBUG[20575] chan_sip.c: Body 17 [ 10]: a=ptime:20 [2009-09-28 16:21:01] DEBUG[20575] chan_sip.c: Body 18 [ 10]: a=sendrecv [2009-09-28 16:21:01] VERBOSE[20575] chan_sip.c: [2009-09-28 16:21:01] --- (18 headers 19 lines) --- [2009-09-28 16:21:01] DEBUG[20575] acl.c: Found IP address for this socket [2009-09-28 16:21:01] DEBUG[20575] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 64.105.202.244:5060 [2009-09-28 16:21:01] VERBOSE[20575] netsock.c: [2009-09-28 16:21:01] == Using SIP RTP TOS bits 16 [2009-09-28 16:21:01] VERBOSE[20575] netsock.c: [2009-09-28 16:21:01] == Using SIP RTP CoS mark 5 [2009-09-28 16:21:01] DEBUG[20575] chan_sip.c: Setting NAT on RTP to Off [2009-09-28 16:21:01] DEBUG[20575] chan_sip.c: Allocating new SIP dialog for 2ff281b92105b33d1363e3e6737f7e2c@64.61.93.170 - INVITE (With RTP) [2009-09-28 16:21:01] DEBUG[20575] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE [2009-09-28 16:21:01] DEBUG[20575] chan_sip.c: Begin: parsing SIP "Supported: replaces" [2009-09-28 16:21:01] DEBUG[20575] chan_sip.c: Found SIP option: -replaces- [2009-09-28 16:21:01] DEBUG[20575] chan_sip.c: Matched SIP option: replaces [2009-09-28 16:21:01] VERBOSE[20575] chan_sip.c: [2009-09-28 16:21:01] Sending to 64.61.93.190 : 5060 (no NAT) [2009-09-28 16:21:01] DEBUG[20575] chan_sip.c: Initializing initreq for method INVITE - callid 2ff281b92105b33d1363e3e6737f7e2c@64.61.93.170 [2009-09-28 16:21:01] VERBOSE[20575] chan_sip.c: [2009-09-28 16:21:01] Using INVITE request as basis request - 2ff281b92105b33d1363e3e6737f7e2c@64.61.93.170 [2009-09-28 16:21:01] VERBOSE[20575] chan_sip.c: [2009-09-28 16:21:01] Found peer 'VoicePulse-Primary-Brendan' for '8479227343' from 64.61.93.190:5060 [2009-09-28 16:21:01] DEBUG[20575] chan_sip.c: Setting NAT on RTP to Off [2009-09-28 16:21:01] VERBOSE[20575] chan_sip.c: [2009-09-28 16:21:01] Found RTP audio format 0 [2009-09-28 16:21:01] VERBOSE[20575] chan_sip.c: [2009-09-28 16:21:01] Found RTP audio format 8 [2009-09-28 16:21:01] VERBOSE[20575] chan_sip.c: [2009-09-28 16:21:01] Found RTP audio format 3 [2009-09-28 16:21:01] VERBOSE[20575] chan_sip.c: [2009-09-28 16:21:01] Found RTP audio format 97 [2009-09-28 16:21:01] VERBOSE[20575] chan_sip.c: [2009-09-28 16:21:01] Found RTP audio format 111 [2009-09-28 16:21:01] VERBOSE[20575] chan_sip.c: [2009-09-28 16:21:01] Found RTP audio format 5 [2009-09-28 16:21:01] VERBOSE[20575] chan_sip.c: [2009-09-28 16:21:01] Found RTP audio format 7 [2009-09-28 16:21:01] VERBOSE[20575] chan_sip.c: [2009-09-28 16:21:01] Found RTP audio format 101 [2009-09-28 16:21:01] VERBOSE[20575] chan_sip.c: [2009-09-28 16:21:01] Peer audio RTP is at port 64.61.93.170:19496 [2009-09-28 16:21:01] VERBOSE[20575] chan_sip.c: [2009-09-28 16:21:01] Found audio description format PCMU for ID 0 [2009-09-28 16:21:01] VERBOSE[20575] chan_sip.c: [2009-09-28 16:21:01] Found audio description format PCMA for ID 8 [2009-09-28 16:21:01] VERBOSE[20575] chan_sip.c: [2009-09-28 16:21:01] Found audio description format GSM for ID 3 [2009-09-28 16:21:01] VERBOSE[20575] chan_sip.c: [2009-09-28 16:21:01] Found audio description format iLBC for ID 97 [2009-09-28 16:21:01] DEBUG[20575] chan_sip.c: Got unsupported a:fmtp:97 mode=30 in SDP offer [2009-09-28 16:21:01] VERBOSE[20575] chan_sip.c: [2009-09-28 16:21:01] Found audio description format G726-32 for ID 111 [2009-09-28 16:21:01] VERBOSE[20575] chan_sip.c: [2009-09-28 16:21:01] Found audio description format DVI4 for ID 5 [2009-09-28 16:21:01] VERBOSE[20575] chan_sip.c: [2009-09-28 16:21:01] Found audio description format LPC for ID 7 [2009-09-28 16:21:01] VERBOSE[20575] chan_sip.c: [2009-09-28 16:21:01] Found audio description format telephone-event for ID 101 [2009-09-28 16:21:01] DEBUG[20575] chan_sip.c: Got unsupported a:fmtp:101 0-16 in SDP offer [2009-09-28 16:21:01] VERBOSE[20575] chan_sip.c: [2009-09-28 16:21:01] Capabilities: us - 0x8000e (gsm|ulaw|alaw|h263), peer - audio=0xcae (gsm|ulaw|alaw|g726|adpcm|lpc10|ilbc)/video=0x0 (nothing)/text=0x0 (nothing), combined - 0xe (gsm|ulaw|alaw) [2009-09-28 16:21:01] VERBOSE[20575] chan_sip.c: [2009-09-28 16:21:01] Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) [2009-09-28 16:21:01] VERBOSE[20575] chan_sip.c: [2009-09-28 16:21:01] Peer audio RTP is at port 64.61.93.170:19496 [2009-09-28 16:21:01] DEBUG[20575] chan_sip.c: We're settling with these formats: 0xe (gsm|ulaw|alaw) [2009-09-28 16:21:01] DEBUG[20575] chan_sip.c: Checking SIP call limits for device ocY97PJM89 [2009-09-28 16:21:01] DEBUG[20575] chan_sip.c: Updating call counter for incoming call [2009-09-28 16:21:01] VERBOSE[20575] chan_sip.c: [2009-09-28 16:21:01] Looking for 19192460171 in inbound (domain 64.105.202.244) [2009-09-28 16:21:01] DEBUG[20575] frame.c: Could not find preferred codec - Going for the best codec [2009-09-28 16:21:01] DEBUG[20575] chan_sip.c: *** Our native formats are 0x4 (ulaw) [2009-09-28 16:21:01] DEBUG[20575] chan_sip.c: *** Joint capabilities are 0xe (gsm|ulaw|alaw) [2009-09-28 16:21:01] DEBUG[20575] chan_sip.c: *** Our capabilities are 0x8000e (gsm|ulaw|alaw|h263) [2009-09-28 16:21:01] DEBUG[20575] frame.c: Could not find preferred codec - Going for the best codec [2009-09-28 16:21:01] DEBUG[20575] chan_sip.c: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw) [2009-09-28 16:21:01] DEBUG[20575] chan_sip.c: This channel will not be able to handle video. [2009-09-28 16:21:01] DEBUG[20575] chan_sip.c: build_route: Record-Route hop: [2009-09-28 16:21:01] VERBOSE[20575] chan_sip.c: [2009-09-28 16:21:01] list_route: hop: [2009-09-28 16:21:01] DEBUG[20575] chan_sip.c: SIP/VoicePulse-Primary-Brendan-10367280: New call is still down.... Trying... [2009-09-28 16:21:01] VERBOSE[20575] chan_sip.c: [2009-09-28 16:21:01] <--- Transmitting (no NAT) to 64.61.93.190:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 64.61.93.190;branch=z9hG4bKc0b1.a1daaf32.0;received=64.61.93.190 Via: SIP/2.0/UDP 64.61.93.174;rport=5060;branch=z9hG4bKc0b1.4350e62.0 Via: SIP/2.0/UDP 64.61.93.170:5060;received=64.61.93.170;branch=z9hG4bK022e706f;rport=5060 Record-Route: From: "Martin Brendan " ;tag=as0c0039c0 To: Call-ID: 2ff281b92105b33d1363e3e6737f7e2c@64.61.93.170 CSeq: 102 INVITE Server: Asterisk PBX 1.6.2.0-beta4 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Contact: Content-Length: 0 <------------> [2009-09-28 16:21:01] DEBUG[20575] chan_sip.c: Header 0 [ 18]: SIP/2.0 100 Trying [2009-09-28 16:21:01] DEBUG[20575] chan_sip.c: Header 1 [ 81]: Via: SIP/2.0/UDP 64.61.93.190;branch=z9hG4bKc0b1.a1daaf32.0;received=64.61.93.190 [2009-09-28 16:21:01] DEBUG[20575] chan_sip.c: Header 2 [ 69]: Via: SIP/2.0/UDP 64.61.93.174;rport=5060;branch=z9hG4bKc0b1.4350e62.0 [2009-09-28 16:21:01] DEBUG[20575] chan_sip.c: Header 3 [ 90]: Via: SIP/2.0/UDP 64.61.93.170:5060;received=64.61.93.170;branch=z9hG4bK022e706f;rport=5060 [2009-09-28 16:21:01] DEBUG[20575] chan_sip.c: Header 4 [ 95]: Record-Route: [2009-09-28 16:21:01] DEBUG[20575] chan_sip.c: Header 5 [ 68]: From: "Martin Brendan " ;tag=as0c0039c0 [2009-09-28 16:21:01] DEBUG[20575] chan_sip.c: Header 6 [ 47]: To: [2009-09-28 16:21:01] DEBUG[20575] chan_sip.c: Header 7 [ 54]: Call-ID: 2ff281b92105b33d1363e3e6737f7e2c@64.61.93.170 [2009-09-28 16:21:01] DEBUG[20575] chan_sip.c: Header 8 [ 16]: CSeq: 102 INVITE [2009-09-28 16:21:01] DEBUG[20575] chan_sip.c: Header 9 [ 34]: Server: Asterisk PBX 1.6.2.0-beta4 [2009-09-28 16:21:01] DEBUG[20575] chan_sip.c: Header 10 [ 72]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO [2009-09-28 16:21:01] DEBUG[20575] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [2009-09-28 16:21:01] DEBUG[20575] chan_sip.c: Header 12 [ 41]: Contact: [2009-09-28 16:21:01] DEBUG[20575] chan_sip.c: Header 13 [ 17]: Content-Length: 0 [2009-09-28 16:21:01] DEBUG[20575] chan_sip.c: Header 14 [ 0]: [2009-09-28 16:21:01] DEBUG[20575] chan_sip.c: Trying to put 'SIP/2.0 10' onto UDP socket destined for 64.61.93.190:5060 [2009-09-28 16:21:01] DEBUG[20609] pbx.c: Launching 'ConfBridge' [2009-09-28 16:21:01] VERBOSE[20609] pbx.c: [2009-09-28 16:21:01] -- Executing [19192460171@inbound:1] ConfBridge("SIP/VoicePulse-Primary-Brendan-10367280", "8000,mMsc") in new stack [2009-09-28 16:21:01] DEBUG[20609] app_confbridge.c: Trying to find conference bridge '8000' [2009-09-28 16:21:01] DEBUG[20544] devicestate.c: No provider found, checking channel drivers for SIP - VoicePulse-Primary-Brendan [2009-09-28 16:21:01] DEBUG[20544] chan_sip.c: Checking device state for peer VoicePulse-Primary-Brendan [2009-09-28 16:21:01] DEBUG[20544] devicestate.c: Changing state for SIP/VoicePulse-Primary-Brendan - state 1 (Not in use) [2009-09-28 16:21:01] DEBUG[20544] devicestate.c: device 'SIP/VoicePulse-Primary-Brendan' state '1' [2009-09-28 16:21:01] DEBUG[20609] channel.c: Set channel SIP/VoicePulse-Primary-Brendan-10367280 to write format slin [2009-09-28 16:21:01] DEBUG[20609] chan_sip.c: Setting framing from config on incoming call [2009-09-28 16:21:01] DEBUG[20609] chan_sip.c: ** Our capability: 0xe (gsm|ulaw|alaw) Video flag: True Text flag: True [2009-09-28 16:21:01] DEBUG[20609] chan_sip.c: ** Our prefcodec: 0x0 (nothing) [2009-09-28 16:21:01] VERBOSE[20609] chan_sip.c: [2009-09-28 16:21:01] Audio is at 64.105.202.244 port 20008 [2009-09-28 16:21:01] VERBOSE[20609] chan_sip.c: [2009-09-28 16:21:01] Adding codec 0x2 (gsm) to SDP [2009-09-28 16:21:01] VERBOSE[20609] chan_sip.c: [2009-09-28 16:21:01] Adding codec 0x4 (ulaw) to SDP [2009-09-28 16:21:01] VERBOSE[20609] chan_sip.c: [2009-09-28 16:21:01] Adding codec 0x8 (alaw) to SDP [2009-09-28 16:21:01] VERBOSE[20609] chan_sip.c: [2009-09-28 16:21:01] Adding non-codec 0x1 (telephone-event) to SDP [2009-09-28 16:21:01] DEBUG[20609] chan_sip.c: -- Done with adding codecs to SDP [2009-09-28 16:21:01] DEBUG[20609] channel.c: Internal timing is disabled (option_internal_timing=0 chan->timingfd=42) [2009-09-28 16:21:01] DEBUG[20609] chan_sip.c: Done building SDP. Settling with this capability: 0xe (gsm|ulaw|alaw) [2009-09-28 16:21:01] VERBOSE[20609] chan_sip.c: [2009-09-28 16:21:01] <--- Transmitting (no NAT) to 64.61.93.190:5060 ---> SIP/2.0 183 Session Progress Via: SIP/2.0/UDP 64.61.93.190;branch=z9hG4bKc0b1.a1daaf32.0;received=64.61.93.190 Via: SIP/2.0/UDP 64.61.93.174;rport=5060;branch=z9hG4bKc0b1.4350e62.0 Via: SIP/2.0/UDP 64.61.93.170:5060;received=64.61.93.170;branch=z9hG4bK022e706f;rport=5060 Record-Route: From: "Martin Brendan " ;tag=as0c0039c0 To: ;tag=as08f5ee1b Call-ID: 2ff281b92105b33d1363e3e6737f7e2c@64.61.93.170 CSeq: 102 INVITE Server: Asterisk PBX 1.6.2.0-beta4 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Contact: Content-Type: application/sdp Content-Length: 318 v=0 o=root 712800917 712800917 IN IP4 64.105.202.244 s=Asterisk PBX 1.6.2.0-beta4 c=IN IP4 64.105.202.244 t=0 0 m=audio 20008 RTP/AVP 3 0 8 101 a=rtpmap:3 GSM/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv <------------> [2009-09-28 16:21:01] DEBUG[20609] chan_sip.c: Header 0 [ 28]: SIP/2.0 183 Session Progress [2009-09-28 16:21:01] DEBUG[20609] chan_sip.c: Header 1 [ 81]: Via: SIP/2.0/UDP 64.61.93.190;branch=z9hG4bKc0b1.a1daaf32.0;received=64.61.93.190 [2009-09-28 16:21:01] DEBUG[20609] chan_sip.c: Header 2 [ 69]: Via: SIP/2.0/UDP 64.61.93.174;rport=5060;branch=z9hG4bKc0b1.4350e62.0 [2009-09-28 16:21:01] DEBUG[20609] chan_sip.c: Header 3 [ 90]: Via: SIP/2.0/UDP 64.61.93.170:5060;received=64.61.93.170;branch=z9hG4bK022e706f;rport=5060 [2009-09-28 16:21:01] DEBUG[20609] chan_sip.c: Header 4 [ 95]: Record-Route: [2009-09-28 16:21:01] DEBUG[20609] chan_sip.c: Header 5 [ 68]: From: "Martin Brendan " ;tag=as0c0039c0 [2009-09-28 16:21:01] DEBUG[20609] chan_sip.c: Header 6 [ 62]: To: ;tag=as08f5ee1b [2009-09-28 16:21:01] DEBUG[20609] chan_sip.c: Header 7 [ 54]: Call-ID: 2ff281b92105b33d1363e3e6737f7e2c@64.61.93.170 [2009-09-28 16:21:01] DEBUG[20609] chan_sip.c: Header 8 [ 16]: CSeq: 102 INVITE [2009-09-28 16:21:01] DEBUG[20609] chan_sip.c: Header 9 [ 34]: Server: Asterisk PBX 1.6.2.0-beta4 [2009-09-28 16:21:01] DEBUG[20609] chan_sip.c: Header 10 [ 72]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO [2009-09-28 16:21:01] DEBUG[20609] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [2009-09-28 16:21:01] DEBUG[20609] chan_sip.c: Header 12 [ 41]: Contact: [2009-09-28 16:21:01] DEBUG[20609] chan_sip.c: Header 13 [ 29]: Content-Type: application/sdp [2009-09-28 16:21:01] DEBUG[20609] chan_sip.c: Header 14 [ 19]: Content-Length: 318 [2009-09-28 16:21:01] DEBUG[20609] chan_sip.c: Header 15 [ 0]: [2009-09-28 16:21:01] DEBUG[20609] chan_sip.c: Body 0 [ 3]: v=0 [2009-09-28 16:21:01] DEBUG[20609] chan_sip.c: Body 1 [ 48]: o=root 712800917 712800917 IN IP4 64.105.202.244 [2009-09-28 16:21:01] DEBUG[20609] chan_sip.c: Body 2 [ 28]: s=Asterisk PBX 1.6.2.0-beta4 [2009-09-28 16:21:01] DEBUG[20609] chan_sip.c: Body 3 [ 23]: c=IN IP4 64.105.202.244 [2009-09-28 16:21:01] DEBUG[20609] chan_sip.c: Body 4 [ 5]: t=0 0 [2009-09-28 16:21:01] DEBUG[20609] chan_sip.c: Body 5 [ 31]: m=audio 20008 RTP/AVP 3 0 8 101 [2009-09-28 16:21:01] DEBUG[20609] chan_sip.c: Body 6 [ 19]: a=rtpmap:3 GSM/8000 [2009-09-28 16:21:01] DEBUG[20609] chan_sip.c: Body 7 [ 20]: a=rtpmap:0 PCMU/8000 [2009-09-28 16:21:01] DEBUG[20609] chan_sip.c: Body 8 [ 20]: a=rtpmap:8 PCMA/8000 [2009-09-28 16:21:01] DEBUG[20609] chan_sip.c: Body 9 [ 33]: a=rtpmap:101 telephone-event/8000 [2009-09-28 16:21:01] DEBUG[20609] chan_sip.c: Body 10 [ 15]: a=fmtp:101 0-16 [2009-09-28 16:21:01] DEBUG[20609] chan_sip.c: Body 11 [ 25]: a=silenceSupp:off - - - - [2009-09-28 16:21:01] DEBUG[20609] chan_sip.c: Body 12 [ 10]: a=ptime:20 [2009-09-28 16:21:01] DEBUG[20609] chan_sip.c: Body 13 [ 10]: a=sendrecv [2009-09-28 16:21:01] DEBUG[20609] chan_sip.c: Trying to put 'SIP/2.0 18' onto UDP socket destined for 64.61.93.190:5060 [2009-09-28 16:21:01] DEBUG[20609] channel.c: Scheduling timer at (50 requested / 50 actual) timer ticks per second [2009-09-28 16:21:01] VERBOSE[20609] file.c: [2009-09-28 16:21:01] -- Playing 'conf-onlyone.slin' (language 'en') [2009-09-28 16:21:01] DEBUG[20609] rtp.c: Ooh, format changed from unknown to ulaw [2009-09-28 16:21:01] DEBUG[20609] rtp.c: Created smoother: format: 4 ms: 20 len: 160 [2009-09-28 16:21:04] DEBUG[20609] channel.c: Scheduling timer at (98 requested / 98 actual) timer ticks per second [2009-09-28 16:21:04] DEBUG[20609] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [2009-09-28 16:21:04] DEBUG[20609] channel.c: Scheduling timer at (0 requested / 0 actual) timer ticks per second [2009-09-28 16:21:04] DEBUG[20609] channel.c: Set channel SIP/VoicePulse-Primary-Brendan-10367280 to write format ulaw [2009-09-28 16:21:04] DEBUG[20609] bridging.c: Joining bridge channel 0x48962520 to bridge 0x1034dd98 [2009-09-28 16:21:04] DEBUG[20609] bridging.c: Added channel SIP/VoicePulse-Primary-Brendan-10367280(0x482d30b0) to bridge array on 0x1034dd98, new count is 2 [2009-09-28 16:21:04] DEBUG[20609] bridging.c: Bridge 0x1034dd98 channel count (2) is within limits for bridge technology multiplexed_bridge, not performing smart bridge operation. [2009-09-28 16:21:04] DEBUG[20609] bridging.c: Bridge 0x1034dd98 is happy that channel SIP/VoicePulse-Primary-Brendan-10367280 already has read format ulaw(4) [2009-09-28 16:21:04] DEBUG[20609] bridging.c: Bridge 0x1034dd98 is happy that channel SIP/VoicePulse-Primary-Brendan-10367280 already has write format ulaw(4) [2009-09-28 16:21:04] DEBUG[20609] bridging.c: Giving bridge technology multiplexed_bridge notification that 0x48962520 is joining bridge 0x1034dd98 [2009-09-28 16:21:04] DEBUG[20609] bridge_multiplexed.c: Adding channel 'SIP/VoicePulse-Primary-Brendan-10367280' to multiplexed thread '0x10354a98' for monitoring [2009-09-28 16:21:04] DEBUG[20609] bridging.c: Going into a single threaded signal wait for bridge channel 0x48962520 of bridge 0x1034dd98 [2009-09-28 16:21:05] VERBOSE[20575] chan_sip.c: [2009-09-28 16:21:05] <--- SIP read from UDP:192.168.0.30:5060 ---> SUBSCRIBE sip:asterisk.crosscomm.net SIP/2.0 Via: SIP/2.0/UDP 192.168.0.30:5060;branch=z9hG4bK-246fcfba From: CrossComm, Inc. ;tag=f0fff61673677df3 To: CrossComm, Inc. ;tag=as35894806 Call-ID: f353b712-ec105127@192.168.0.30 CSeq: 49583 SUBSCRIBE Max-Forwards: 70 Authorization: Digest username="line3",realm="asterisk.crosscomm.net",nonce="50424a67",uri="sip:asterisk.crosscomm.net",algorithm=MD5,response="609aeab1fda1388c708673839efbe578" Contact: CrossComm, Inc. Accept: application/simple-message-summary Expires: 2147483647 Event: message-summary User-Agent: Linksys/PAP2T-5.1.6(LS) Content-Length: 0 <-------------> [2009-09-28 16:21:05] DEBUG[20575] chan_sip.c: Header 0 [ 44]: SUBSCRIBE sip:asterisk.crosscomm.net SIP/2.0 [2009-09-28 16:21:05] DEBUG[20575] chan_sip.c: Header 1 [ 58]: Via: SIP/2.0/UDP 192.168.0.30:5060;branch=z9hG4bK-246fcfba [2009-09-28 16:21:05] DEBUG[20575] chan_sip.c: Header 2 [ 77]: From: CrossComm, Inc. ;tag=f0fff61673677df3 [2009-09-28 16:21:05] DEBUG[20575] chan_sip.c: Header 3 [ 69]: To: CrossComm, Inc. ;tag=as35894806 [2009-09-28 16:21:05] DEBUG[20575] chan_sip.c: Header 4 [ 39]: Call-ID: f353b712-ec105127@192.168.0.30 [2009-09-28 16:21:05] DEBUG[20575] chan_sip.c: Header 5 [ 21]: CSeq: 49583 SUBSCRIBE [2009-09-28 16:21:05] DEBUG[20575] chan_sip.c: Header 6 [ 16]: Max-Forwards: 70 [2009-09-28 16:21:05] DEBUG[20575] chan_sip.c: Header 7 [177]: Authorization: Digest username="line3",realm="asterisk.crosscomm.net",nonce="50424a67",uri="sip:asterisk.crosscomm.net",algorithm=MD5,response="609aeab1fda1388c708673839efbe578" [2009-09-28 16:21:05] DEBUG[20575] chan_sip.c: Header 8 [ 54]: Contact: CrossComm, Inc. [2009-09-28 16:21:05] DEBUG[20575] chan_sip.c: Header 9 [ 42]: Accept: application/simple-message-summary [2009-09-28 16:21:05] DEBUG[20575] chan_sip.c: Header 10 [ 19]: Expires: 2147483647 [2009-09-28 16:21:05] DEBUG[20575] chan_sip.c: Header 11 [ 22]: Event: message-summary [2009-09-28 16:21:05] DEBUG[20575] chan_sip.c: Header 12 [ 35]: User-Agent: Linksys/PAP2T-5.1.6(LS) [2009-09-28 16:21:05] DEBUG[20575] chan_sip.c: Header 13 [ 17]: Content-Length: 0 [2009-09-28 16:21:05] DEBUG[20575] chan_sip.c: Header 14 [ 0]: [2009-09-28 16:21:05] VERBOSE[20575] chan_sip.c: [2009-09-28 16:21:05] --- (14 headers 0 lines) --- [2009-09-28 16:21:05] DEBUG[20575] acl.c: Found IP address for this socket [2009-09-28 16:21:05] DEBUG[20575] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 64.105.202.244:5060 [2009-09-28 16:21:05] DEBUG[20575] chan_sip.c: Allocating new SIP dialog for f353b712-ec105127@192.168.0.30 - SUBSCRIBE (No RTP) [2009-09-28 16:21:05] DEBUG[20575] chan_sip.c: **** Received SUBSCRIBE (10) - Command in SIP SUBSCRIBE [2009-09-28 16:21:05] VERBOSE[20575] chan_sip.c: [2009-09-28 16:21:05] Received resubscription for a dialog we no longer know about. Telling remote side to subscribe again. [2009-09-28 16:21:05] VERBOSE[20575] chan_sip.c: [2009-09-28 16:21:05] <--- Transmitting (no NAT) to 192.168.0.30:5060 ---> SIP/2.0 481 Subscription does not exist Via: SIP/2.0/UDP 192.168.0.30:5060;branch=z9hG4bK-246fcfba;received=192.168.0.30 From: CrossComm, Inc. ;tag=f0fff61673677df3 To: CrossComm, Inc. ;tag=as35894806 Call-ID: f353b712-ec105127@192.168.0.30 CSeq: 49583 SUBSCRIBE Server: Asterisk PBX 1.6.2.0-beta4 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Content-Length: 0 <------------> [2009-09-28 16:21:05] DEBUG[20575] chan_sip.c: Header 0 [ 39]: SIP/2.0 481 Subscription does not exist [2009-09-28 16:21:05] DEBUG[20575] chan_sip.c: Header 1 [ 80]: Via: SIP/2.0/UDP 192.168.0.30:5060;branch=z9hG4bK-246fcfba;received=192.168.0.30 [2009-09-28 16:21:05] DEBUG[20575] chan_sip.c: Header 2 [ 77]: From: CrossComm, Inc. ;tag=f0fff61673677df3 [2009-09-28 16:21:05] DEBUG[20575] chan_sip.c: Header 3 [ 69]: To: CrossComm, Inc. ;tag=as35894806 [2009-09-28 16:21:05] DEBUG[20575] chan_sip.c: Header 4 [ 39]: Call-ID: f353b712-ec105127@192.168.0.30 [2009-09-28 16:21:05] DEBUG[20575] chan_sip.c: Header 5 [ 21]: CSeq: 49583 SUBSCRIBE [2009-09-28 16:21:05] DEBUG[20575] chan_sip.c: Header 6 [ 34]: Server: Asterisk PBX 1.6.2.0-beta4 [2009-09-28 16:21:05] DEBUG[20575] chan_sip.c: Header 7 [ 72]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO [2009-09-28 16:21:05] DEBUG[20575] chan_sip.c: Header 8 [ 26]: Supported: replaces, timer [2009-09-28 16:21:05] DEBUG[20575] chan_sip.c: Header 9 [ 17]: Content-Length: 0 [2009-09-28 16:21:05] DEBUG[20575] chan_sip.c: Header 10 [ 0]: [2009-09-28 16:21:05] DEBUG[20575] chan_sip.c: Trying to put 'SIP/2.0 48' onto UDP socket destined for 192.168.0.30:5060 [2009-09-28 16:21:05] DEBUG[20575] chan_sip.c: Destroying SIP dialog f353b712-ec105127@192.168.0.30 [2009-09-28 16:21:05] VERBOSE[20575] chan_sip.c: [2009-09-28 16:21:05] Really destroying SIP dialog 'f353b712-ec105127@192.168.0.30' Method: SUBSCRIBE [2009-09-28 16:21:06] DEBUG[20608] rtp.c: Got RTCP report of 44 bytes [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Allocating new SIP dialog for 341dca275df45a4f35256ddb16c3bdef@64.105.202.244 - OPTIONS (No RTP) [2009-09-28 16:21:09] DEBUG[20575] acl.c: Found IP address for this socket [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 64.105.202.244:5060 [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Initializing initreq for method OPTIONS - callid 23f98dac71a094896ecefff473765bcd@64.105.202.244 [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 0 [ 43]: OPTIONS sip:line3@192.168.0.30:5060 SIP/2.0 [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 1 [ 65]: Via: SIP/2.0/UDP 64.105.202.244:5060;branch=z9hG4bK72a786ca;rport [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 3 [ 61]: From: "asterisk" ;tag=as5c007557 [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 4 [ 33]: To: [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 5 [ 38]: Contact: [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 6 [ 56]: Call-ID: 23f98dac71a094896ecefff473765bcd@64.105.202.244 [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 7 [ 17]: CSeq: 102 OPTIONS [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 8 [ 38]: User-Agent: Asterisk PBX 1.6.2.0-beta4 [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 9 [ 35]: Date: Mon, 28 Sep 2009 20:21:09 GMT [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 10 [ 72]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 12 [ 17]: Content-Length: 0 [2009-09-28 16:21:09] VERBOSE[20575] chan_sip.c: [2009-09-28 16:21:09] Reliably Transmitting (no NAT) to 192.168.0.30:5060: OPTIONS sip:line3@192.168.0.30:5060 SIP/2.0 Via: SIP/2.0/UDP 64.105.202.244:5060;branch=z9hG4bK72a786ca;rport Max-Forwards: 70 From: "asterisk" ;tag=as5c007557 To: Contact: Call-ID: 23f98dac71a094896ecefff473765bcd@64.105.202.244 CSeq: 102 OPTIONS User-Agent: Asterisk PBX 1.6.2.0-beta4 Date: Mon, 28 Sep 2009 20:21:09 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Content-Length: 0 --- [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 0 [ 43]: OPTIONS sip:line3@192.168.0.30:5060 SIP/2.0 [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 1 [ 65]: Via: SIP/2.0/UDP 64.105.202.244:5060;branch=z9hG4bK72a786ca;rport [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 3 [ 61]: From: "asterisk" ;tag=as5c007557 [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 4 [ 33]: To: [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 5 [ 38]: Contact: [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 6 [ 56]: Call-ID: 23f98dac71a094896ecefff473765bcd@64.105.202.244 [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 7 [ 17]: CSeq: 102 OPTIONS [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 8 [ 38]: User-Agent: Asterisk PBX 1.6.2.0-beta4 [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 9 [ 35]: Date: Mon, 28 Sep 2009 20:21:09 GMT [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 10 [ 72]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 12 [ 17]: Content-Length: 0 [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 13 [ 0]: [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #41 [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 192.168.0.30:5060 [2009-09-28 16:21:09] VERBOSE[20575] chan_sip.c: [2009-09-28 16:21:09] <--- SIP read from UDP:192.168.0.30:5060 ---> SIP/2.0 486 Busy Here To: ;tag=f76be8be46253182i0 From: "asterisk" ;tag=as5c007557 Call-ID: 23f98dac71a094896ecefff473765bcd@64.105.202.244 CSeq: 102 OPTIONS Via: SIP/2.0/UDP 64.105.202.244:5060;branch=z9hG4bK72a786ca Server: Linksys/PAP2T-5.1.6(LS) Content-Length: 0 Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER Supported: x-sipura, replaces <-------------> [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 0 [ 21]: SIP/2.0 486 Busy Here [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 1 [ 56]: To: ;tag=f76be8be46253182i0 [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 2 [ 61]: From: "asterisk" ;tag=as5c007557 [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 3 [ 56]: Call-ID: 23f98dac71a094896ecefff473765bcd@64.105.202.244 [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 4 [ 17]: CSeq: 102 OPTIONS [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 5 [ 59]: Via: SIP/2.0/UDP 64.105.202.244:5060;branch=z9hG4bK72a786ca [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 6 [ 31]: Server: Linksys/PAP2T-5.1.6(LS) [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 7 [ 17]: Content-Length: 0 [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 8 [ 61]: Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 9 [ 29]: Supported: x-sipura, replaces [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 10 [ 0]: [2009-09-28 16:21:09] VERBOSE[20575] chan_sip.c: [2009-09-28 16:21:09] --- (10 headers 0 lines) --- [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #41 [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Stopping retransmission on '23f98dac71a094896ecefff473765bcd@64.105.202.244' of Request 102: Match Found [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Destroying SIP dialog 23f98dac71a094896ecefff473765bcd@64.105.202.244 [2009-09-28 16:21:09] VERBOSE[20575] chan_sip.c: [2009-09-28 16:21:09] Really destroying SIP dialog '23f98dac71a094896ecefff473765bcd@64.105.202.244' Method: OPTIONS [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Allocating new SIP dialog for 37924f582fbe4946337d2eac0faaac6c@64.105.202.244 - OPTIONS (No RTP) [2009-09-28 16:21:09] DEBUG[20575] acl.c: Found IP address for this socket [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 64.105.202.244:5060 [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Initializing initreq for method OPTIONS - callid 04876e5b5c5ae52e58d5039775ca2912@64.105.202.244 [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 0 [ 45]: OPTIONS sip:jfk-backup.voicepulse.com SIP/2.0 [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 1 [ 65]: Via: SIP/2.0/UDP 64.105.202.244:5060;branch=z9hG4bK572acc27;rport [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 3 [ 61]: From: "asterisk" ;tag=as521dfabd [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 4 [ 35]: To: [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 5 [ 38]: Contact: [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 6 [ 56]: Call-ID: 04876e5b5c5ae52e58d5039775ca2912@64.105.202.244 [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 7 [ 17]: CSeq: 102 OPTIONS [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 8 [ 38]: User-Agent: Asterisk PBX 1.6.2.0-beta4 [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 9 [ 35]: Date: Mon, 28 Sep 2009 20:21:09 GMT [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 10 [ 72]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 12 [ 17]: Content-Length: 0 [2009-09-28 16:21:09] VERBOSE[20575] chan_sip.c: [2009-09-28 16:21:09] Reliably Transmitting (no NAT) to 67.108.9.165:5060: OPTIONS sip:jfk-backup.voicepulse.com SIP/2.0 Via: SIP/2.0/UDP 64.105.202.244:5060;branch=z9hG4bK572acc27;rport Max-Forwards: 70 From: "asterisk" ;tag=as521dfabd To: Contact: Call-ID: 04876e5b5c5ae52e58d5039775ca2912@64.105.202.244 CSeq: 102 OPTIONS User-Agent: Asterisk PBX 1.6.2.0-beta4 Date: Mon, 28 Sep 2009 20:21:09 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Content-Length: 0 --- [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 0 [ 45]: OPTIONS sip:jfk-backup.voicepulse.com SIP/2.0 [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 1 [ 65]: Via: SIP/2.0/UDP 64.105.202.244:5060;branch=z9hG4bK572acc27;rport [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 3 [ 61]: From: "asterisk" ;tag=as521dfabd [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 4 [ 35]: To: [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 5 [ 38]: Contact: [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 6 [ 56]: Call-ID: 04876e5b5c5ae52e58d5039775ca2912@64.105.202.244 [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 7 [ 17]: CSeq: 102 OPTIONS [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 8 [ 38]: User-Agent: Asterisk PBX 1.6.2.0-beta4 [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 9 [ 35]: Date: Mon, 28 Sep 2009 20:21:09 GMT [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 10 [ 72]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 12 [ 17]: Content-Length: 0 [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 13 [ 0]: [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #44 [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 67.108.9.165:5060 [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Allocating new SIP dialog for 75d273744ee10f230842a14a46ba3a7b@64.105.202.244 - OPTIONS (No RTP) [2009-09-28 16:21:09] DEBUG[20575] acl.c: Found IP address for this socket [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 64.105.202.244:5060 [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Initializing initreq for method OPTIONS - callid 4e1686f61afa356f455363bc74b6c283@64.105.202.244 [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 0 [ 46]: OPTIONS sip:jfk-primary.voicepulse.com SIP/2.0 [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 1 [ 65]: Via: SIP/2.0/UDP 64.105.202.244:5060;branch=z9hG4bK5f5c2b08;rport [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 3 [ 61]: From: "asterisk" ;tag=as1d1097dc [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 4 [ 36]: To: [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 5 [ 38]: Contact: [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 6 [ 56]: Call-ID: 4e1686f61afa356f455363bc74b6c283@64.105.202.244 [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 7 [ 17]: CSeq: 102 OPTIONS [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 8 [ 38]: User-Agent: Asterisk PBX 1.6.2.0-beta4 [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 9 [ 35]: Date: Mon, 28 Sep 2009 20:21:09 GMT [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 10 [ 72]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 12 [ 17]: Content-Length: 0 [2009-09-28 16:21:09] VERBOSE[20575] chan_sip.c: [2009-09-28 16:21:09] Reliably Transmitting (no NAT) to 64.61.93.190:5060: OPTIONS sip:jfk-primary.voicepulse.com SIP/2.0 Via: SIP/2.0/UDP 64.105.202.244:5060;branch=z9hG4bK5f5c2b08;rport Max-Forwards: 70 From: "asterisk" ;tag=as1d1097dc To: Contact: Call-ID: 4e1686f61afa356f455363bc74b6c283@64.105.202.244 CSeq: 102 OPTIONS User-Agent: Asterisk PBX 1.6.2.0-beta4 Date: Mon, 28 Sep 2009 20:21:09 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Content-Length: 0 --- [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 0 [ 46]: OPTIONS sip:jfk-primary.voicepulse.com SIP/2.0 [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 1 [ 65]: Via: SIP/2.0/UDP 64.105.202.244:5060;branch=z9hG4bK5f5c2b08;rport [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 3 [ 61]: From: "asterisk" ;tag=as1d1097dc [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 4 [ 36]: To: [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 5 [ 38]: Contact: [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 6 [ 56]: Call-ID: 4e1686f61afa356f455363bc74b6c283@64.105.202.244 [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 7 [ 17]: CSeq: 102 OPTIONS [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 8 [ 38]: User-Agent: Asterisk PBX 1.6.2.0-beta4 [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 9 [ 35]: Date: Mon, 28 Sep 2009 20:21:09 GMT [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 10 [ 72]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 12 [ 17]: Content-Length: 0 [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 13 [ 0]: [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #46 [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 64.61.93.190:5060 [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Allocating new SIP dialog for 511d33c341fc862e307a9fe609360052@64.105.202.244 - OPTIONS (No RTP) [2009-09-28 16:21:09] DEBUG[20575] acl.c: Found IP address for this socket [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 64.105.202.244:5060 [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Initializing initreq for method OPTIONS - callid 7670ab426b7bbfb436bb9f8c79a010c8@64.105.202.244 [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 0 [ 43]: OPTIONS sip:line4@192.168.0.30:5061 SIP/2.0 [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 1 [ 65]: Via: SIP/2.0/UDP 64.105.202.244:5060;branch=z9hG4bK78bbb74c;rport [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 3 [ 61]: From: "asterisk" ;tag=as5cbd6d8b [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 4 [ 33]: To: [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 5 [ 38]: Contact: [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 6 [ 56]: Call-ID: 7670ab426b7bbfb436bb9f8c79a010c8@64.105.202.244 [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 7 [ 17]: CSeq: 102 OPTIONS [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 8 [ 38]: User-Agent: Asterisk PBX 1.6.2.0-beta4 [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 9 [ 35]: Date: Mon, 28 Sep 2009 20:21:09 GMT [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 10 [ 72]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 12 [ 17]: Content-Length: 0 [2009-09-28 16:21:09] VERBOSE[20575] chan_sip.c: [2009-09-28 16:21:09] Reliably Transmitting (no NAT) to 192.168.0.30:5061: OPTIONS sip:line4@192.168.0.30:5061 SIP/2.0 Via: SIP/2.0/UDP 64.105.202.244:5060;branch=z9hG4bK78bbb74c;rport Max-Forwards: 70 From: "asterisk" ;tag=as5cbd6d8b To: Contact: Call-ID: 7670ab426b7bbfb436bb9f8c79a010c8@64.105.202.244 CSeq: 102 OPTIONS User-Agent: Asterisk PBX 1.6.2.0-beta4 Date: Mon, 28 Sep 2009 20:21:09 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Content-Length: 0 --- [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 0 [ 43]: OPTIONS sip:line4@192.168.0.30:5061 SIP/2.0 [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 1 [ 65]: Via: SIP/2.0/UDP 64.105.202.244:5060;branch=z9hG4bK78bbb74c;rport [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 3 [ 61]: From: "asterisk" ;tag=as5cbd6d8b [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 4 [ 33]: To: [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 5 [ 38]: Contact: [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 6 [ 56]: Call-ID: 7670ab426b7bbfb436bb9f8c79a010c8@64.105.202.244 [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 7 [ 17]: CSeq: 102 OPTIONS [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 8 [ 38]: User-Agent: Asterisk PBX 1.6.2.0-beta4 [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 9 [ 35]: Date: Mon, 28 Sep 2009 20:21:09 GMT [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 10 [ 72]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 12 [ 17]: Content-Length: 0 [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 13 [ 0]: [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #48 [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 192.168.0.30:5061 [2009-09-28 16:21:09] VERBOSE[20575] chan_sip.c: [2009-09-28 16:21:09] <--- SIP read from UDP:64.61.93.190:5060 ---> SIP/2.0 200 OK to keepalive Via: SIP/2.0/UDP 64.105.202.244:5060;branch=z9hG4bK5f5c2b08;rport=5060 From: "asterisk" ;tag=as1d1097dc To: ;tag=329cfeaa6ded039da25ff8cbb8668bd2.b36d Call-ID: 4e1686f61afa356f455363bc74b6c283@64.105.202.244 CSeq: 102 OPTIONS Server: OpenSER (1.3.2-notls (i386/linux)) Content-Length: 0 <-------------> [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 0 [ 27]: SIP/2.0 200 OK to keepalive [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 1 [ 70]: Via: SIP/2.0/UDP 64.105.202.244:5060;branch=z9hG4bK5f5c2b08;rport=5060 [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 2 [ 61]: From: "asterisk" ;tag=as1d1097dc [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 3 [ 78]: To: ;tag=329cfeaa6ded039da25ff8cbb8668bd2.b36d [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 4 [ 56]: Call-ID: 4e1686f61afa356f455363bc74b6c283@64.105.202.244 [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 5 [ 17]: CSeq: 102 OPTIONS [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 6 [ 42]: Server: OpenSER (1.3.2-notls (i386/linux)) [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 7 [ 17]: Content-Length: 0 [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 8 [ 0]: [2009-09-28 16:21:09] VERBOSE[20575] chan_sip.c: [2009-09-28 16:21:09] --- (8 headers 0 lines) --- [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #46 [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Stopping retransmission on '4e1686f61afa356f455363bc74b6c283@64.105.202.244' of Request 102: Match Found [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Destroying SIP dialog 4e1686f61afa356f455363bc74b6c283@64.105.202.244 [2009-09-28 16:21:09] VERBOSE[20575] chan_sip.c: [2009-09-28 16:21:09] Really destroying SIP dialog '4e1686f61afa356f455363bc74b6c283@64.105.202.244' Method: OPTIONS [2009-09-28 16:21:09] VERBOSE[20575] chan_sip.c: [2009-09-28 16:21:09] <--- SIP read from UDP:192.168.0.30:5061 ---> SIP/2.0 200 OK To: ;tag=3de4cede920481e2i1 From: "asterisk" ;tag=as5cbd6d8b Call-ID: 7670ab426b7bbfb436bb9f8c79a010c8@64.105.202.244 CSeq: 102 OPTIONS Via: SIP/2.0/UDP 64.105.202.244:5060;branch=z9hG4bK78bbb74c Server: Linksys/PAP2T-5.1.6(LS) Content-Length: 0 Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER Supported: x-sipura, replaces <-------------> [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 1 [ 56]: To: ;tag=3de4cede920481e2i1 [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 2 [ 61]: From: "asterisk" ;tag=as5cbd6d8b [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 3 [ 56]: Call-ID: 7670ab426b7bbfb436bb9f8c79a010c8@64.105.202.244 [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 4 [ 17]: CSeq: 102 OPTIONS [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 5 [ 59]: Via: SIP/2.0/UDP 64.105.202.244:5060;branch=z9hG4bK78bbb74c [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 6 [ 31]: Server: Linksys/PAP2T-5.1.6(LS) [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 7 [ 17]: Content-Length: 0 [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 8 [ 61]: Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 9 [ 29]: Supported: x-sipura, replaces [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 10 [ 0]: [2009-09-28 16:21:09] VERBOSE[20575] chan_sip.c: [2009-09-28 16:21:09] --- (10 headers 0 lines) --- [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #48 [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Stopping retransmission on '7670ab426b7bbfb436bb9f8c79a010c8@64.105.202.244' of Request 102: Match Found [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Destroying SIP dialog 7670ab426b7bbfb436bb9f8c79a010c8@64.105.202.244 [2009-09-28 16:21:09] VERBOSE[20575] chan_sip.c: [2009-09-28 16:21:09] Really destroying SIP dialog '7670ab426b7bbfb436bb9f8c79a010c8@64.105.202.244' Method: OPTIONS [2009-09-28 16:21:09] VERBOSE[20575] chan_sip.c: [2009-09-28 16:21:09] <--- SIP read from UDP:67.108.9.165:5060 ---> SIP/2.0 200 OK to keepalive Via: SIP/2.0/UDP 64.105.202.244:5060;branch=z9hG4bK572acc27;rport=5060 From: "asterisk" ;tag=as521dfabd To: ;tag=329cfeaa6ded039da25ff8cbb8668bd2.e496 Call-ID: 04876e5b5c5ae52e58d5039775ca2912@64.105.202.244 CSeq: 102 OPTIONS Server: OpenSER (1.3.2-notls (i386/linux)) Content-Length: 0 <-------------> [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 0 [ 27]: SIP/2.0 200 OK to keepalive [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 1 [ 70]: Via: SIP/2.0/UDP 64.105.202.244:5060;branch=z9hG4bK572acc27;rport=5060 [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 2 [ 61]: From: "asterisk" ;tag=as521dfabd [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 3 [ 77]: To: ;tag=329cfeaa6ded039da25ff8cbb8668bd2.e496 [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 4 [ 56]: Call-ID: 04876e5b5c5ae52e58d5039775ca2912@64.105.202.244 [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 5 [ 17]: CSeq: 102 OPTIONS [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 6 [ 42]: Server: OpenSER (1.3.2-notls (i386/linux)) [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 7 [ 17]: Content-Length: 0 [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Header 8 [ 0]: [2009-09-28 16:21:09] VERBOSE[20575] chan_sip.c: [2009-09-28 16:21:09] --- (8 headers 0 lines) --- [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #44 [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Stopping retransmission on '04876e5b5c5ae52e58d5039775ca2912@64.105.202.244' of Request 102: Match Found [2009-09-28 16:21:09] DEBUG[20575] chan_sip.c: Destroying SIP dialog 04876e5b5c5ae52e58d5039775ca2912@64.105.202.244 [2009-09-28 16:21:09] VERBOSE[20575] chan_sip.c: [2009-09-28 16:21:09] Really destroying SIP dialog '04876e5b5c5ae52e58d5039775ca2912@64.105.202.244' Method: OPTIONS [2009-09-28 16:21:11] DEBUG[20608] rtp.c: Got RTCP report of 44 bytes [2009-09-28 16:21:16] DEBUG[20608] rtp.c: Got RTCP report of 44 bytes [2009-09-28 16:21:21] DEBUG[20608] rtp.c: Got RTCP report of 44 bytes [2009-09-28 16:21:26] DEBUG[20608] rtp.c: Got RTCP report of 44 bytes [2009-09-28 16:21:31] DEBUG[20608] rtp.c: Got RTCP report of 44 bytes [2009-09-28 16:21:35] VERBOSE[20575] chan_sip.c: [2009-09-28 16:21:35] <--- SIP read from UDP:192.168.0.30:5060 ---> SUBSCRIBE sip:asterisk.crosscomm.net SIP/2.0 Via: SIP/2.0/UDP 192.168.0.30:5060;branch=z9hG4bK-45fe0cf0 From: CrossComm, Inc. ;tag=40074c287f28dac2 To: CrossComm, Inc. ;tag=as35894806 Call-ID: 29673ca0-a438e4aa@192.168.0.30 CSeq: 56409 SUBSCRIBE Max-Forwards: 70 Authorization: Digest username="line3",realm="asterisk.crosscomm.net",nonce="50424a67",uri="sip:asterisk.crosscomm.net",algorithm=MD5,response="609aeab1fda1388c708673839efbe578" Contact: CrossComm, Inc. Accept: application/simple-message-summary Expires: 2147483647 Event: message-summary User-Agent: Linksys/PAP2T-5.1.6(LS) Content-Length: 0 <-------------> [2009-09-28 16:21:35] DEBUG[20575] chan_sip.c: Header 0 [ 44]: SUBSCRIBE sip:asterisk.crosscomm.net SIP/2.0 [2009-09-28 16:21:35] DEBUG[20575] chan_sip.c: Header 1 [ 58]: Via: SIP/2.0/UDP 192.168.0.30:5060;branch=z9hG4bK-45fe0cf0 [2009-09-28 16:21:35] DEBUG[20575] chan_sip.c: Header 2 [ 77]: From: CrossComm, Inc. ;tag=40074c287f28dac2 [2009-09-28 16:21:35] DEBUG[20575] chan_sip.c: Header 3 [ 69]: To: CrossComm, Inc. ;tag=as35894806 [2009-09-28 16:21:35] DEBUG[20575] chan_sip.c: Header 4 [ 39]: Call-ID: 29673ca0-a438e4aa@192.168.0.30 [2009-09-28 16:21:35] DEBUG[20575] chan_sip.c: Header 5 [ 21]: CSeq: 56409 SUBSCRIBE [2009-09-28 16:21:35] DEBUG[20575] chan_sip.c: Header 6 [ 16]: Max-Forwards: 70 [2009-09-28 16:21:35] DEBUG[20575] chan_sip.c: Header 7 [177]: Authorization: Digest username="line3",realm="asterisk.crosscomm.net",nonce="50424a67",uri="sip:asterisk.crosscomm.net",algorithm=MD5,response="609aeab1fda1388c708673839efbe578" [2009-09-28 16:21:35] DEBUG[20575] chan_sip.c: Header 8 [ 54]: Contact: CrossComm, Inc. [2009-09-28 16:21:35] DEBUG[20575] chan_sip.c: Header 9 [ 42]: Accept: application/simple-message-summary [2009-09-28 16:21:35] DEBUG[20575] chan_sip.c: Header 10 [ 19]: Expires: 2147483647 [2009-09-28 16:21:35] DEBUG[20575] chan_sip.c: Header 11 [ 22]: Event: message-summary [2009-09-28 16:21:35] DEBUG[20575] chan_sip.c: Header 12 [ 35]: User-Agent: Linksys/PAP2T-5.1.6(LS) [2009-09-28 16:21:35] DEBUG[20575] chan_sip.c: Header 13 [ 17]: Content-Length: 0 [2009-09-28 16:21:35] DEBUG[20575] chan_sip.c: Header 14 [ 0]: [2009-09-28 16:21:35] VERBOSE[20575] chan_sip.c: [2009-09-28 16:21:35] --- (14 headers 0 lines) --- [2009-09-28 16:21:35] DEBUG[20575] acl.c: Found IP address for this socket [2009-09-28 16:21:35] DEBUG[20575] chan_sip.c: Setting SIP_TRANSPORT_UDP with address 64.105.202.244:5060 [2009-09-28 16:21:35] DEBUG[20575] chan_sip.c: Allocating new SIP dialog for 29673ca0-a438e4aa@192.168.0.30 - SUBSCRIBE (No RTP) [2009-09-28 16:21:35] DEBUG[20575] chan_sip.c: **** Received SUBSCRIBE (10) - Command in SIP SUBSCRIBE [2009-09-28 16:21:35] VERBOSE[20575] chan_sip.c: [2009-09-28 16:21:35] Received resubscription for a dialog we no longer know about. Telling remote side to subscribe again. [2009-09-28 16:21:35] VERBOSE[20575] chan_sip.c: [2009-09-28 16:21:35] <--- Transmitting (no NAT) to 192.168.0.30:5060 ---> SIP/2.0 481 Subscription does not exist Via: SIP/2.0/UDP 192.168.0.30:5060;branch=z9hG4bK-45fe0cf0;received=192.168.0.30 From: CrossComm, Inc. ;tag=40074c287f28dac2 To: CrossComm, Inc. ;tag=as35894806 Call-ID: 29673ca0-a438e4aa@192.168.0.30 CSeq: 56409 SUBSCRIBE Server: Asterisk PBX 1.6.2.0-beta4 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Content-Length: 0 <------------> [2009-09-28 16:21:35] DEBUG[20575] chan_sip.c: Header 0 [ 39]: SIP/2.0 481 Subscription does not exist [2009-09-28 16:21:35] DEBUG[20575] chan_sip.c: Header 1 [ 80]: Via: SIP/2.0/UDP 192.168.0.30:5060;branch=z9hG4bK-45fe0cf0;received=192.168.0.30 [2009-09-28 16:21:35] DEBUG[20575] chan_sip.c: Header 2 [ 77]: From: CrossComm, Inc. ;tag=40074c287f28dac2 [2009-09-28 16:21:35] DEBUG[20575] chan_sip.c: Header 3 [ 69]: To: CrossComm, Inc. ;tag=as35894806 [2009-09-28 16:21:35] DEBUG[20575] chan_sip.c: Header 4 [ 39]: Call-ID: 29673ca0-a438e4aa@192.168.0.30 [2009-09-28 16:21:35] DEBUG[20575] chan_sip.c: Header 5 [ 21]: CSeq: 56409 SUBSCRIBE [2009-09-28 16:21:35] DEBUG[20575] chan_sip.c: Header 6 [ 34]: Server: Asterisk PBX 1.6.2.0-beta4 [2009-09-28 16:21:35] DEBUG[20575] chan_sip.c: Header 7 [ 72]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO [2009-09-28 16:21:35] DEBUG[20575] chan_sip.c: Header 8 [ 26]: Supported: replaces, timer [2009-09-28 16:21:35] DEBUG[20575] chan_sip.c: Header 9 [ 17]: Content-Length: 0 [2009-09-28 16:21:35] DEBUG[20575] chan_sip.c: Header 10 [ 0]: [2009-09-28 16:21:35] DEBUG[20575] chan_sip.c: Trying to put 'SIP/2.0 48' onto UDP socket destined for 192.168.0.30:5060 [2009-09-28 16:21:35] DEBUG[20575] chan_sip.c: Destroying SIP dialog 29673ca0-a438e4aa@192.168.0.30 [2009-09-28 16:21:35] VERBOSE[20575] chan_sip.c: [2009-09-28 16:21:35] Really destroying SIP dialog '29673ca0-a438e4aa@192.168.0.30' Method: SUBSCRIBE [2009-09-28 16:21:36] DEBUG[20608] rtp.c: Got RTCP report of 44 bytes [2009-09-28 16:21:40] DEBUG[20544] devicestate.c: No provider found, checking channel drivers for IAX2 - FaxDSP1 [2009-09-28 16:21:40] DEBUG[20544] chan_iax2.c: Checking device state for device FaxDSP1 [2009-09-28 16:21:40] DEBUG[20544] chan_iax2.c: iax2_devicestate: Found peer. What's device state of FaxDSP1? addr=2130706433, defaddr=0 maxms=0, lastms=0 [2009-09-28 16:21:40] DEBUG[20544] devicestate.c: Changing state for IAX2/FaxDSP1 - state 0 (Unknown) [2009-09-28 16:21:40] DEBUG[20544] devicestate.c: device 'IAX2/FaxDSP1' state '0' [2009-09-28 16:21:40] DEBUG[20544] devicestate.c: No provider found, checking channel drivers for IAX2 - FaxDSP1 [2009-09-28 16:21:40] DEBUG[20544] chan_iax2.c: Checking device state for device FaxDSP1 [2009-09-28 16:21:40] DEBUG[20544] chan_iax2.c: iax2_devicestate: Found peer. What's device state of FaxDSP1? addr=2130706433, defaddr=0 maxms=0, lastms=0 [2009-09-28 16:21:40] DEBUG[20544] devicestate.c: Changing state for IAX2/FaxDSP1 - state 0 (Unknown) [2009-09-28 16:21:40] DEBUG[20544] devicestate.c: device 'IAX2/FaxDSP1' state '0' [2009-09-28 16:21:40] DEBUG[20544] devicestate.c: No provider found, checking channel drivers for IAX2 - FaxDSP0 [2009-09-28 16:21:40] DEBUG[20544] chan_iax2.c: Checking device state for device FaxDSP0 [2009-09-28 16:21:40] DEBUG[20544] chan_iax2.c: iax2_devicestate: Found peer. What's device state of FaxDSP0? addr=2130706433, defaddr=0 maxms=0, lastms=0 [2009-09-28 16:21:40] DEBUG[20544] devicestate.c: Changing state for IAX2/FaxDSP0 - state 0 (Unknown) [2009-09-28 16:21:40] DEBUG[20544] devicestate.c: device 'IAX2/FaxDSP0' state '0' [2009-09-28 16:21:40] DEBUG[20544] devicestate.c: No provider found, checking channel drivers for IAX2 - FaxDSP0 [2009-09-28 16:21:40] DEBUG[20544] chan_iax2.c: Checking device state for device FaxDSP0 [2009-09-28 16:21:40] DEBUG[20544] chan_iax2.c: iax2_devicestate: Found peer. What's device state of FaxDSP0? addr=2130706433, defaddr=0 maxms=0, lastms=0 [2009-09-28 16:21:40] DEBUG[20544] devicestate.c: Changing state for IAX2/FaxDSP0 - state 0 (Unknown) [2009-09-28 16:21:40] DEBUG[20544] devicestate.c: device 'IAX2/FaxDSP0' state '0' [2009-09-28 16:21:41] DEBUG[20608] rtp.c: Got RTCP report of 44 bytes [2009-09-28 16:21:44] VERBOSE[20575] chan_sip.c: [2009-09-28 16:21:44] <--- SIP read from UDP:64.61.93.190:5060 ---> CANCEL sip:19192460171@64.105.202.244:5060 SIP/2.0 Via: SIP/2.0/UDP 64.61.93.190;branch=z9hG4bKc0b1.a1daaf32.0 From: "Martin Brendan " ;tag=as0c0039c0 Call-ID: 2ff281b92105b33d1363e3e6737f7e2c@64.61.93.170 To: CSeq: 102 CANCEL Max-Forwards: 70 User-Agent: OpenSER (1.3.2-notls (i386/linux)) Content-Length: 0 <-------------> [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Header 0 [ 50]: CANCEL sip:19192460171@64.105.202.244:5060 SIP/2.0 [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Header 1 [ 59]: Via: SIP/2.0/UDP 64.61.93.190;branch=z9hG4bKc0b1.a1daaf32.0 [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Header 2 [ 68]: From: "Martin Brendan " ;tag=as0c0039c0 [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Header 3 [ 54]: Call-ID: 2ff281b92105b33d1363e3e6737f7e2c@64.61.93.170 [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Header 4 [ 47]: To: [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Header 5 [ 16]: CSeq: 102 CANCEL [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Header 6 [ 16]: Max-Forwards: 70 [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Header 7 [ 46]: User-Agent: OpenSER (1.3.2-notls (i386/linux)) [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Header 8 [ 17]: Content-Length: 0 [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Header 9 [ 0]: [2009-09-28 16:21:44] VERBOSE[20575] chan_sip.c: [2009-09-28 16:21:44] --- (9 headers 0 lines) --- [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: **** Received CANCEL (14) - Command in SIP CANCEL [2009-09-28 16:21:44] VERBOSE[20575] chan_sip.c: [2009-09-28 16:21:44] Sending to 64.61.93.190 : 5060 (no NAT) [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Setting SIP_ALREADYGONE on dialog 2ff281b92105b33d1363e3e6737f7e2c@64.61.93.170 [2009-09-28 16:21:44] VERBOSE[20575] chan_sip.c: [2009-09-28 16:21:44] <--- Reliably Transmitting (no NAT) to 64.61.93.190:5060 ---> SIP/2.0 487 Request Terminated Via: SIP/2.0/UDP 64.61.93.190;branch=z9hG4bKc0b1.a1daaf32.0;received=64.61.93.190 Via: SIP/2.0/UDP 64.61.93.174;rport=5060;branch=z9hG4bKc0b1.4350e62.0 Via: SIP/2.0/UDP 64.61.93.170:5060;received=64.61.93.170;branch=z9hG4bK022e706f;rport=5060 From: "Martin Brendan " ;tag=as0c0039c0 To: ;tag=as08f5ee1b Call-ID: 2ff281b92105b33d1363e3e6737f7e2c@64.61.93.170 CSeq: 102 INVITE Server: Asterisk PBX 1.6.2.0-beta4 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Content-Length: 0 <------------> [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Header 0 [ 30]: SIP/2.0 487 Request Terminated [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Header 1 [ 81]: Via: SIP/2.0/UDP 64.61.93.190;branch=z9hG4bKc0b1.a1daaf32.0;received=64.61.93.190 [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Header 2 [ 69]: Via: SIP/2.0/UDP 64.61.93.174;rport=5060;branch=z9hG4bKc0b1.4350e62.0 [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Header 3 [ 90]: Via: SIP/2.0/UDP 64.61.93.170:5060;received=64.61.93.170;branch=z9hG4bK022e706f;rport=5060 [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Header 4 [ 68]: From: "Martin Brendan " ;tag=as0c0039c0 [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Header 5 [ 62]: To: ;tag=as08f5ee1b [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Header 6 [ 54]: Call-ID: 2ff281b92105b33d1363e3e6737f7e2c@64.61.93.170 [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Header 7 [ 16]: CSeq: 102 INVITE [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Header 8 [ 34]: Server: Asterisk PBX 1.6.2.0-beta4 [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Header 9 [ 72]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Header 10 [ 26]: Supported: replaces, timer [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Header 11 [ 17]: Content-Length: 0 [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Header 12 [ 0]: [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #53 [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Trying to put 'SIP/2.0 48' onto UDP socket destined for 64.61.93.190:5060 [2009-09-28 16:21:44] VERBOSE[20575] chan_sip.c: [2009-09-28 16:21:44] <--- Transmitting (no NAT) to 64.61.93.190:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 64.61.93.190;branch=z9hG4bKc0b1.a1daaf32.0;received=64.61.93.190 From: "Martin Brendan " ;tag=as0c0039c0 To: ;tag=as08f5ee1b Call-ID: 2ff281b92105b33d1363e3e6737f7e2c@64.61.93.170 CSeq: 102 CANCEL Server: Asterisk PBX 1.6.2.0-beta4 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Content-Length: 0 <------------> [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Header 1 [ 81]: Via: SIP/2.0/UDP 64.61.93.190;branch=z9hG4bKc0b1.a1daaf32.0;received=64.61.93.190 [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Header 2 [ 68]: From: "Martin Brendan " ;tag=as0c0039c0 [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Header 3 [ 62]: To: ;tag=as08f5ee1b [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Header 4 [ 54]: Call-ID: 2ff281b92105b33d1363e3e6737f7e2c@64.61.93.170 [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Header 5 [ 16]: CSeq: 102 CANCEL [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Header 6 [ 34]: Server: Asterisk PBX 1.6.2.0-beta4 [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Header 7 [ 72]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Header 8 [ 26]: Supported: replaces, timer [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Header 9 [ 17]: Content-Length: 0 [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Header 10 [ 0]: [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Trying to put 'SIP/2.0 20' onto UDP socket destined for 64.61.93.190:5060 [2009-09-28 16:21:44] DEBUG[20609] bridging.c: Giving bridge technology multiplexed_bridge notification that 0x48962520 is leaving bridge 0x1034dd98 [2009-09-28 16:21:44] DEBUG[20609] bridge_multiplexed.c: Removing channel 'SIP/VoicePulse-Primary-Brendan-10367280' from multiplexed thread '0x10354a98' [2009-09-28 16:21:44] DEBUG[20609] bridging.c: Removed channel 0x482d30b0 from bridge array on 0x1034dd98, new count is 1 [2009-09-28 16:21:44] DEBUG[20609] bridging.c: Bridge 0x1034dd98 channel count (1) is within limits for bridge technology multiplexed_bridge, not performing smart bridge operation. [2009-09-28 16:21:44] DEBUG[20609] pbx.c: Extension 19192460171, priority 1 returned normally even though call was hung up [2009-09-28 16:21:44] DEBUG[20609] channel.c: Soft-Hanging up channel 'SIP/VoicePulse-Primary-Brendan-10367280' [2009-09-28 16:21:44] DEBUG[20609] channel.c: Hanging up channel 'SIP/VoicePulse-Primary-Brendan-10367280' [2009-09-28 16:21:44] DEBUG[20609] chan_sip.c: Hangup call SIP/VoicePulse-Primary-Brendan-10367280, SIP callid 2ff281b92105b33d1363e3e6737f7e2c@64.61.93.170 [2009-09-28 16:21:44] DEBUG[20609] cdr.c: Dropping CDR ! [2009-09-28 16:21:44] DEBUG[20544] devicestate.c: No provider found, checking channel drivers for SIP - VoicePulse-Primary-Brendan [2009-09-28 16:21:44] DEBUG[20544] chan_sip.c: Checking device state for peer VoicePulse-Primary-Brendan [2009-09-28 16:21:44] DEBUG[20544] devicestate.c: Changing state for SIP/VoicePulse-Primary-Brendan - state 1 (Not in use) [2009-09-28 16:21:44] DEBUG[20544] devicestate.c: device 'SIP/VoicePulse-Primary-Brendan' state '1' [2009-09-28 16:21:44] VERBOSE[20575] chan_sip.c: [2009-09-28 16:21:44] <--- SIP read from UDP:64.61.93.190:5060 ---> ACK sip:19192460171@64.105.202.244:5060 SIP/2.0 Via: SIP/2.0/UDP 64.61.93.190;branch=z9hG4bKc0b1.a1daaf32.0 From: "Martin Brendan " ;tag=as0c0039c0 Call-ID: 2ff281b92105b33d1363e3e6737f7e2c@64.61.93.170 To: ;tag=as08f5ee1b CSeq: 102 ACK Max-Forwards: 70 User-Agent: OpenSER (1.3.2-notls (i386/linux)) Content-Length: 0 <-------------> [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Header 0 [ 47]: ACK sip:19192460171@64.105.202.244:5060 SIP/2.0 [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Header 1 [ 59]: Via: SIP/2.0/UDP 64.61.93.190;branch=z9hG4bKc0b1.a1daaf32.0 [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Header 2 [ 68]: From: "Martin Brendan " ;tag=as0c0039c0 [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Header 3 [ 54]: Call-ID: 2ff281b92105b33d1363e3e6737f7e2c@64.61.93.170 [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Header 4 [ 62]: To: ;tag=as08f5ee1b [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Header 5 [ 13]: CSeq: 102 ACK [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Header 6 [ 16]: Max-Forwards: 70 [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Header 7 [ 46]: User-Agent: OpenSER (1.3.2-notls (i386/linux)) [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Header 8 [ 17]: Content-Length: 0 [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Header 9 [ 0]: [2009-09-28 16:21:44] VERBOSE[20575] chan_sip.c: [2009-09-28 16:21:44] --- (9 headers 0 lines) --- [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: **** Received ACK (6) - Command in SIP ACK [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #53 [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Stopping retransmission on '2ff281b92105b33d1363e3e6737f7e2c@64.61.93.170' of Response 102: Match Found [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Destroying SIP dialog 2ff281b92105b33d1363e3e6737f7e2c@64.61.93.170 [2009-09-28 16:21:44] VERBOSE[20575] chan_sip.c: [2009-09-28 16:21:44] Really destroying SIP dialog '2ff281b92105b33d1363e3e6737f7e2c@64.61.93.170' Method: ACK [2009-09-28 16:21:44] VERBOSE[20575] chan_sip.c: [2009-09-28 16:21:44] <--- SIP read from UDP:192.168.0.30:5060 ---> CANCEL sip:8000@asterisk.crosscomm.net SIP/2.0 Via: SIP/2.0/UDP 192.168.0.30:5060;branch=z9hG4bK-df83152f From: CrossComm, Inc. ;tag=26d2eea73721f323o0 To: Call-ID: af00e7f7-1143ca13@192.168.0.30 CSeq: 102 CANCEL Max-Forwards: 70 Authorization: Digest username="line3",realm="asterisk.crosscomm.net",nonce="2c035955",uri="sip:8000@asterisk.crosscomm.net",algorithm=MD5,response="5c509570c4ed61d805cf6a134623e29b" User-Agent: Linksys/PAP2T-5.1.6(LS) Content-Length: 0 <-------------> [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Header 0 [ 46]: CANCEL sip:8000@asterisk.crosscomm.net SIP/2.0 [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Header 1 [ 58]: Via: SIP/2.0/UDP 192.168.0.30:5060;branch=z9hG4bK-df83152f [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Header 2 [ 79]: From: CrossComm, Inc. ;tag=26d2eea73721f323o0 [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Header 3 [ 37]: To: [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Header 4 [ 39]: Call-ID: af00e7f7-1143ca13@192.168.0.30 [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Header 5 [ 16]: CSeq: 102 CANCEL [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Header 6 [ 16]: Max-Forwards: 70 [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Header 7 [182]: Authorization: Digest username="line3",realm="asterisk.crosscomm.net",nonce="2c035955",uri="sip:8000@asterisk.crosscomm.net",algorithm=MD5,response="5c509570c4ed61d805cf6a134623e29b" [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Header 8 [ 35]: User-Agent: Linksys/PAP2T-5.1.6(LS) [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Header 9 [ 17]: Content-Length: 0 [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Header 10 [ 0]: [2009-09-28 16:21:44] VERBOSE[20575] chan_sip.c: [2009-09-28 16:21:44] --- (10 headers 0 lines) --- [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: **** Received CANCEL (14) - Command in SIP CANCEL [2009-09-28 16:21:44] VERBOSE[20575] chan_sip.c: [2009-09-28 16:21:44] Sending to 192.168.0.30 : 5060 (no NAT) [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Setting SIP_ALREADYGONE on dialog af00e7f7-1143ca13@192.168.0.30 [2009-09-28 16:21:44] VERBOSE[20575] chan_sip.c: [2009-09-28 16:21:44] <--- Reliably Transmitting (no NAT) to 192.168.0.30:5060 ---> SIP/2.0 487 Request Terminated Via: SIP/2.0/UDP 192.168.0.30:5060;branch=z9hG4bK-df83152f;received=192.168.0.30 From: CrossComm, Inc. ;tag=26d2eea73721f323o0 To: ;tag=as5fb80a11 Call-ID: af00e7f7-1143ca13@192.168.0.30 CSeq: 102 INVITE Server: Asterisk PBX 1.6.2.0-beta4 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Content-Length: 0 <------------> [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Header 0 [ 30]: SIP/2.0 487 Request Terminated [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Header 1 [ 80]: Via: SIP/2.0/UDP 192.168.0.30:5060;branch=z9hG4bK-df83152f;received=192.168.0.30 [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Header 2 [ 79]: From: CrossComm, Inc. ;tag=26d2eea73721f323o0 [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Header 3 [ 52]: To: ;tag=as5fb80a11 [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Header 4 [ 39]: Call-ID: af00e7f7-1143ca13@192.168.0.30 [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Header 5 [ 16]: CSeq: 102 INVITE [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Header 6 [ 34]: Server: Asterisk PBX 1.6.2.0-beta4 [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Header 7 [ 72]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Header 8 [ 26]: Supported: replaces, timer [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Header 9 [ 17]: Content-Length: 0 [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Header 10 [ 0]: [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #54 [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Trying to put 'SIP/2.0 48' onto UDP socket destined for 192.168.0.30:5060 [2009-09-28 16:21:44] VERBOSE[20575] chan_sip.c: [2009-09-28 16:21:44] <--- Transmitting (no NAT) to 192.168.0.30:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.0.30:5060;branch=z9hG4bK-df83152f;received=192.168.0.30 From: CrossComm, Inc. ;tag=26d2eea73721f323o0 To: ;tag=as5fb80a11 Call-ID: af00e7f7-1143ca13@192.168.0.30 CSeq: 102 CANCEL Server: Asterisk PBX 1.6.2.0-beta4 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO Supported: replaces, timer Content-Length: 0 <------------> [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Header 1 [ 80]: Via: SIP/2.0/UDP 192.168.0.30:5060;branch=z9hG4bK-df83152f;received=192.168.0.30 [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Header 2 [ 79]: From: CrossComm, Inc. ;tag=26d2eea73721f323o0 [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Header 3 [ 52]: To: ;tag=as5fb80a11 [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Header 4 [ 39]: Call-ID: af00e7f7-1143ca13@192.168.0.30 [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Header 5 [ 16]: CSeq: 102 CANCEL [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Header 6 [ 34]: Server: Asterisk PBX 1.6.2.0-beta4 [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Header 7 [ 72]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Header 8 [ 26]: Supported: replaces, timer [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Header 9 [ 17]: Content-Length: 0 [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Header 10 [ 0]: [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Trying to put 'SIP/2.0 20' onto UDP socket destined for 192.168.0.30:5060 [2009-09-28 16:21:44] DEBUG[20607] bridging.c: Giving bridge technology multiplexed_bridge notification that 0x488ea520 is leaving bridge 0x1034dd98 [2009-09-28 16:21:44] DEBUG[20607] bridge_multiplexed.c: Removing channel 'SIP/line3-482c8fd0' from multiplexed thread '0x10354a98' [2009-09-28 16:21:44] VERBOSE[20575] chan_sip.c: [2009-09-28 16:21:44] <--- SIP read from UDP:192.168.0.30:5060 ---> ACK sip:8000@asterisk.crosscomm.net SIP/2.0 Via: SIP/2.0/UDP 192.168.0.30:5060;branch=z9hG4bK-df83152f From: CrossComm, Inc. ;tag=26d2eea73721f323o0 To: ;tag=as5fb80a11 Call-ID: af00e7f7-1143ca13@192.168.0.30 CSeq: 102 ACK Max-Forwards: 70 Authorization: Digest username="line3",realm="asterisk.crosscomm.net",nonce="2c035955",uri="sip:8000@asterisk.crosscomm.net",algorithm=MD5,response="4a501d5b223f291d1b1112737a607a73" Contact: CrossComm, Inc. User-Agent: Linksys/PAP2T-5.1.6(LS) Content-Length: 0 <-------------> [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Header 0 [ 43]: ACK sip:8000@asterisk.crosscomm.net SIP/2.0 [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Header 1 [ 58]: Via: SIP/2.0/UDP 192.168.0.30:5060;branch=z9hG4bK-df83152f [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Header 2 [ 79]: From: CrossComm, Inc. ;tag=26d2eea73721f323o0 [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Header 3 [ 52]: To: ;tag=as5fb80a11 [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Header 4 [ 39]: Call-ID: af00e7f7-1143ca13@192.168.0.30 [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Header 5 [ 13]: CSeq: 102 ACK [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Header 6 [ 16]: Max-Forwards: 70 [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Header 7 [182]: Authorization: Digest username="line3",realm="asterisk.crosscomm.net",nonce="2c035955",uri="sip:8000@asterisk.crosscomm.net",algorithm=MD5,response="4a501d5b223f291d1b1112737a607a73" [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Header 8 [ 54]: Contact: CrossComm, Inc. [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Header 9 [ 35]: User-Agent: Linksys/PAP2T-5.1.6(LS) [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Header 10 [ 17]: Content-Length: 0 [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Header 11 [ 0]: [2009-09-28 16:21:44] VERBOSE[20575] chan_sip.c: [2009-09-28 16:21:44] --- (11 headers 0 lines) --- [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: **** Received ACK (6) - Command in SIP ACK [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #54 [2009-09-28 16:21:44] DEBUG[20575] chan_sip.c: Stopping retransmission on 'af00e7f7-1143ca13@192.168.0.30' of Response 102: Match Found [2009-09-28 16:21:44] DEBUG[20608] bridge_multiplexed.c: Stopping actual thread for multiplexed thread '0x10354a98' [2009-09-28 16:21:44] DEBUG[20607] bridging.c: Removed channel 0x482cd848 from bridge array on 0x1034dd98, new count is 0 [2009-09-28 16:21:44] DEBUG[20607] bridging.c: Bridge 0x1034dd98 channel count (0) is within limits for bridge technology multiplexed_bridge, not performing smart bridge operation. [2009-09-28 16:21:44] DEBUG[20607] app_confbridge.c: Destroying conference bridge '8000' [2009-09-28 16:21:44] DEBUG[20607] bridging.c: Telling all channels in bridge 0x1034dd98 to end and leave the party [2009-09-28 16:21:44] DEBUG[20607] bridging.c: Actually destroying bridge 0x1034dd98, nobody wants it anymore [2009-09-28 16:21:44] DEBUG[20607] bridging.c: Giving bridge technology multiplexed_bridge the bridge structure 0x1034dd98 to destroy [2009-09-28 16:21:44] DEBUG[20607] bridge_multiplexed.c: Unlinking multiplexed thread '0x10354a98' since nobody is using it anymore [2009-09-28 16:21:44] DEBUG[20607] pbx.c: Extension 8000, priority 1 returned normally even though call was hung up [2009-09-28 16:21:44] DEBUG[20607] channel.c: Soft-Hanging up channel 'SIP/line3-482c8fd0' [2009-09-28 16:21:44] DEBUG[20607] channel.c: Hanging up channel 'SIP/line3-482c8fd0' [2009-09-28 16:21:44] DEBUG[20607] chan_sip.c: Hangup call SIP/line3-482c8fd0, SIP callid af00e7f7-1143ca13@192.168.0.30 [2009-09-28 16:21:44] DEBUG[20607] cdr.c: Dropping CDR ! [2009-09-28 16:21:44] DEBUG[20544] devicestate.c: No provider found, checking channel drivers for SIP - line3 [2009-09-28 16:21:44] DEBUG[20544] chan_sip.c: Checking device state for peer line3 [2009-09-28 16:21:44] DEBUG[20544] devicestate.c: Changing state for SIP/line3 - state 1 (Not in use) [2009-09-28 16:21:44] DEBUG[20544] devicestate.c: device 'SIP/line3' state '1' [2009-09-28 16:21:44] DEBUG[20545] devicestate.c: No provider found, checking channel drivers for SIP - line3 [2009-09-28 16:21:44] DEBUG[20545] chan_sip.c: Checking device state for peer line3 [2009-09-28 16:21:44] DEBUG[20545] devicestate.c: No provider found, checking channel drivers for IAX2 - line3 [2009-09-28 16:21:44] DEBUG[20545] chan_iax2.c: Checking device state for device line3 [2009-09-28 16:21:44] DEBUG[20545] chan_iax2.c: iax2_devicestate: Found peer. What's device state of line3? addr=0, defaddr=0 maxms=2000, lastms=0 [2009-09-28 16:21:45] DEBUG[20575] chan_sip.c: Destroying SIP dialog af00e7f7-1143ca13@192.168.0.30 [2009-09-28 16:21:45] VERBOSE[20575] chan_sip.c: [2009-09-28 16:21:45] Really destroying SIP dialog 'af00e7f7-1143ca13@192.168.0.30' Method: ACK