[Nov 20 10:26:24] VERBOSE[32338] logger.c: [Nov 20 10:26:24] --- (16 headers 11 lines) --- [Nov 20 10:26:24] DEBUG[32338] chan_sip.c: Stopping retransmission on '0c0b472a4b9b1da146cc7213408d1181@87.255.0.218' of Request 102: Match Not Found [Nov 20 10:26:24] VERBOSE[32338] logger.c: [Nov 20 10:26:24] Really destroying SIP dialog '0c0b472a4b9b1da146cc7213408d1181@87.255.0.218' Method: OPTIONS [Nov 20 10:26:24] DEBUG[19422] app_queue.c: Even though there are 0 available members, the strategy is ringall so only the head call is allowed in [Nov 20 10:26:24] DEBUG[19422] app_queue.c: There are 1 available members. [Nov 20 10:26:24] DEBUG[19422] app_queue.c: It's not our turn (SIP/87.255.0.210-b6066a68). [Nov 20 10:26:24] DEBUG[18674] rtp.c: Got RTCP report of 132 bytes [Nov 20 10:26:24] DEBUG[22160] rtp.c: Got RTCP report of 132 bytes [Nov 20 10:26:24] DEBUG[18674] app_queue.c: Even though there are 0 available members, the strategy is ringall so only the head call is allowed in [Nov 20 10:26:24] DEBUG[18674] app_queue.c: There are 1 available members. [Nov 20 10:26:24] DEBUG[18674] app_queue.c: It's our turn (SIP/87.255.5.254-b60b2010). [Nov 20 10:26:24] DEBUG[18674] app_queue.c: SIP/87.255.5.254-b60b2010 is trying to call a queue member. [Nov 20 10:26:24] DEBUG[18674] app_queue.c: (Parallel) Trying 'SIP/office_855' with metric 0 [Nov 20 10:26:24] DEBUG[18674] app_queue.c: SIP/office_855 in use, can't receive call [Nov 20 10:26:24] DEBUG[18674] app_queue.c: (Parallel) Trying 'SIP/office_854' with metric 0 [Nov 20 10:26:24] DEBUG[18674] app_queue.c: SIP/office_854 paused, can't receive call [Nov 20 10:26:24] DEBUG[18674] app_queue.c: (Parallel) Trying 'SIP/office_853' with metric 0 [Nov 20 10:26:24] DEBUG[18674] chan_sip.c: Asked to create a SIP channel with formats: 0x4 (ulaw) [Nov 20 10:26:24] DEBUG[18674] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP) [Nov 20 10:26:24] DEBUG[18674] chan_sip.c: Setting NAT on RTP to Off [Nov 20 10:26:24] DEBUG[18674] acl.c: ##### Testing 10.10.15.40 with 87.255.7.0 [Nov 20 10:26:24] DEBUG[18674] acl.c: ##### Testing 10.10.15.40 with 87.255.5.0 [Nov 20 10:26:24] DEBUG[18674] acl.c: ##### Testing 10.10.15.40 with 87.255.4.0 [Nov 20 10:26:24] DEBUG[18674] acl.c: ##### Testing 10.10.15.40 with 87.255.3.0 [Nov 20 10:26:24] DEBUG[18674] acl.c: ##### Testing 10.10.15.40 with 87.255.1.0 [Nov 20 10:26:24] DEBUG[18674] acl.c: ##### Testing 10.10.15.40 with 87.255.0.64 [Nov 20 10:26:24] DEBUG[18674] acl.c: ##### Testing 10.10.15.40 with 192.168.0.0 [Nov 20 10:26:24] DEBUG[18674] acl.c: ##### Testing 10.10.15.40 with 10.0.0.0 [Nov 20 10:26:24] DEBUG[18674] acl.c: ##### Testing 10.10.15.40 with 172.16.0.0 [Nov 20 10:26:24] DEBUG[18674] chan_sip.c: *** Our native formats are 0x4 (ulaw) [Nov 20 10:26:24] DEBUG[18674] chan_sip.c: *** Joint capabilities are 0x0 (nothing) [Nov 20 10:26:24] DEBUG[18674] chan_sip.c: *** Our capabilities are 0xc (ulaw|alaw) [Nov 20 10:26:24] DEBUG[18674] chan_sip.c: *** AST_CODEC_CHOOSE formats are 0x4 (ulaw) [Nov 20 10:26:24] DEBUG[18674] chan_sip.c: *** Our preferred formats from the incoming channel are 0x4 (ulaw) [Nov 20 10:26:24] DEBUG[18674] chan_sip.c: This channel will not be able to handle video. [Nov 20 10:26:24] DEBUG[18674] channel.c: Not copying variable MONITOR_FILENAME. [Nov 20 10:26:24] DEBUG[18674] channel.c: Copying soft-transferable variable SIPTRANSFER_REFERER. [Nov 20 10:26:24] DEBUG[18674] channel.c: Copying soft-transferable variable SIPTRANSFER. [Nov 20 10:26:24] DEBUG[18674] channel.c: Not copying variable SIPDOMAIN. [Nov 20 10:26:24] DEBUG[18674] channel.c: Not copying variable BLINDTRANSFER. [Nov 20 10:26:24] DEBUG[18674] channel.c: Not copying variable BRIDGEPEER. [Nov 20 10:26:24] DEBUG[18674] channel.c: Not copying variable MIXMONITOR_FILENAME. [Nov 20 10:26:24] DEBUG[18674] channel.c: Not copying variable finance. [Nov 20 10:26:24] DEBUG[18674] channel.c: Not copying variable tech_vs_cc. [Nov 20 10:26:24] DEBUG[18674] channel.c: Not copying variable holyday. [Nov 20 10:26:24] DEBUG[18674] channel.c: Not copying variable MACRO_DEPTH. [Nov 20 10:26:24] DEBUG[18674] channel.c: Not copying variable SIPCALLID. [Nov 20 10:26:24] DEBUG[18674] channel.c: Not copying variable SIPUSERAGENT. [Nov 20 10:26:24] DEBUG[18674] channel.c: Not copying variable SIPURI. [Nov 20 10:26:24] DEBUG[18674] chan_sip.c: Call for office_853 transfered by office_805@87.255.0.218 [Nov 20 10:26:24] DEBUG[18674] chan_sip.c: Outgoing Call for office_853 [Nov 20 10:26:24] DEBUG[18674] chan_sip.c: Updating call counter for outgoing call [Nov 20 10:26:24] DEBUG[18674] chan_sip.c: Call to peer 'office_853' is 1 out of 8 [Nov 20 10:26:24] DEBUG[18674] devicestate.c: Notification of state change to be queued on device/channel SIP/office_853 [Nov 20 10:26:24] DEBUG[18674] chan_sip.c: Our T38 capability (3856), joint T38 capability (3856) [Nov 20 10:26:24] DEBUG[18674] chan_sip.c: ** Our capability: 0xc (ulaw|alaw) Video flag: False [Nov 20 10:26:24] DEBUG[18674] chan_sip.c: ** Our prefcodec: 0x4 (ulaw) [Nov 20 10:26:24] VERBOSE[18674] logger.c: [Nov 20 10:26:24] Audio is at 87.255.0.218 port 18906 [Nov 20 10:26:24] VERBOSE[18674] logger.c: [Nov 20 10:26:24] Adding codec 0x4 (ulaw) to SDP [Nov 20 10:26:24] VERBOSE[18674] logger.c: [Nov 20 10:26:24] Adding codec 0x8 (alaw) to SDP [Nov 20 10:26:24] VERBOSE[18674] logger.c: [Nov 20 10:26:24] Adding non-codec 0x1 (telephone-event) to SDP [Nov 20 10:26:24] DEBUG[18674] chan_sip.c: -- Done with adding codecs to SDP [Nov 20 10:26:24] DEBUG[18674] chan_sip.c: Done building SDP. Settling with this capability: 0xc (ulaw|alaw) [Nov 20 10:26:24] VERBOSE[18674] logger.c: [Nov 20 10:26:24] Reliably Transmitting (no NAT) to 10.10.15.40:5060: INVITE sip:office_853@10.10.15.40:5060;user=phone;transport=udp SIP/2.0 Via: SIP/2.0/UDP 87.255.0.218:5060;branch=z9hG4bK18bda275;rport From: "7877871" ;tag=as447d807e To: Contact: Call-ID: 77e8e8a02c0daa456817173237cf6533@87.255.0.218 CSeq: 102 INVITE User-Agent: Asterisk PBX Max-Forwards: 70 Date: Tue, 20 Nov 2007 07:26:24 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Remote-Party-ID: "7877871" ;party=calling;privacy=off;screen=no Content-Type: application/sdp Content-Length: 264 v=0 o=root 32315 32315 IN IP4 87.255.0.218 s=session c=IN IP4 87.255.0.218 t=0 0 m=audio 18906 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 --- [Nov 20 10:26:24] DEBUG[18674] app_queue.c: (Parallel) Trying 'SIP/office_852' with metric 0 [Nov 20 10:26:24] DEBUG[18674] app_queue.c: SIP/office_852 in use, can't receive call [Nov 20 10:26:24] DEBUG[18674] app_queue.c: (Parallel) Trying 'SIP/office_851' with metric 0 [Nov 20 10:26:24] DEBUG[18674] app_queue.c: SIP/office_851 paused, can't receive call [Nov 20 10:26:24] DEBUG[18674] app_queue.c: Nobody left to try ringing in queue [Nov 20 10:26:24] DEBUG[22688] rtp.c: Got RTCP report of 132 bytes [Nov 20 10:26:24] DEBUG[32320] chan_sip.c: Checking device state for peer office_853 [Nov 20 10:26:24] DEBUG[32320] devicestate.c: Changing state for SIP/office_853 - state 6 (Ringing) [Nov 20 10:26:24] DEBUG[32340] app_queue.c: Device 'SIP/office_853' changed to state '6' (Ringing) [Nov 20 10:26:24] DEBUG[22007] app_queue.c: Even though there are 0 available members, the strategy is ringall so only the head call is allowed in [Nov 20 10:26:24] DEBUG[22007] app_queue.c: There are 1 available members. [Nov 20 10:26:24] DEBUG[22007] app_queue.c: It's not our turn (SIP/87.255.5.254-083ef0a0). [Nov 20 10:26:25] VERBOSE[32317] logger.c: [Nov 20 10:26:25] -- Remote UNIX connection [Nov 20 10:26:25] VERBOSE[22827] logger.c: [Nov 20 10:26:25] -- Remote UNIX connection disconnected [Nov 20 10:26:25] VERBOSE[32338] logger.c: [Nov 20 10:26:25] <--- SIP read from 10.10.15.40:50608 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 87.255.0.218:5060;branch=z9hG4bK18bda275;rport From: "7877871" ;tag=as447d807e To: Call-ID: 77e8e8a02c0daa456817173237cf6533@87.255.0.218 Date: Tue, 20 Nov 2007 07:26:04 GMT CSeq: 102 INVITE Server: Cisco-CP7940G/8.0 Contact: Allow: ACK,BYE,CANCEL,INVITE,NOTIFY,OPTIONS,REFER,REGISTER,UPDATE Content-Length: 0 <-------------> [Nov 20 10:26:25] VERBOSE[32338] logger.c: [Nov 20 10:26:25] --- (11 headers 0 lines) --- [Nov 20 10:26:25] DEBUG[32338] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '77e8e8a02c0daa456817173237cf6533@87.255.0.218' Request 102: Found [Nov 20 10:26:25] DEBUG[22796] rtp.c: Got RTCP report of 132 bytes [Nov 20 10:26:25] DEBUG[22007] rtp.c: Got RTCP report of 132 bytes [Nov 20 10:26:25] VERBOSE[32338] logger.c: [Nov 20 10:26:25] <--- SIP read from 10.10.15.18:5061 ---> CANCEL sip:95722001@87.255.0.218 SIP/2.0 Via: SIP/2.0/UDP 10.10.15.18:5061;branch=z9hG4bK-f7649d9e From: ;tag=82afd2a1ec29cfa6o1 To: Call-ID: 7439ae7d-f2a8457a@10.10.15.18 CSeq: 101 CANCEL Max-Forwards: 70 User-Agent: Linksys/SPA2102-5.1.12 Content-Length: 0 <-------------> [Nov 20 10:26:25] VERBOSE[32338] logger.c: [Nov 20 10:26:25] --- (9 headers 0 lines) --- [Nov 20 10:26:25] VERBOSE[32338] logger.c: [Nov 20 10:26:25] Sending to 10.10.15.18 : 5061 (no NAT) [Nov 20 10:26:25] DEBUG[32338] chan_sip.c: Setting SIP_ALREADYGONE on dialog 7439ae7d-f2a8457a@10.10.15.18 [Nov 20 10:26:25] DEBUG[32338] chan_sip.c: Updating call counter for incoming call [Nov 20 10:26:25] DEBUG[32338] chan_sip.c: Call from peer 'office_511' removed from call limit 1 [Nov 20 10:26:25] DEBUG[32338] devicestate.c: Notification of state change to be queued on device/channel SIP/office_511 [Nov 20 10:26:25] VERBOSE[32338] logger.c: [Nov 20 10:26:25] <--- Reliably Transmitting (no NAT) to 10.10.15.18:5061 ---> SIP/2.0 487 Request Terminated Via: SIP/2.0/UDP 10.10.15.18:5061;branch=z9hG4bK-f7649d9e;received=10.10.15.18 From: ;tag=82afd2a1ec29cfa6o1 To: ;tag=as57d5276a Call-ID: 7439ae7d-f2a8457a@10.10.15.18 CSeq: 101 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Length: 0 <------------> [Nov 20 10:26:25] VERBOSE[32338] logger.c: [Nov 20 10:26:25] <--- Transmitting (no NAT) to 10.10.15.18:5061 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 10.10.15.18:5061;branch=z9hG4bK-f7649d9e;received=10.10.15.18 From: ;tag=82afd2a1ec29cfa6o1 To: ;tag=as57d5276a Call-ID: 7439ae7d-f2a8457a@10.10.15.18 CSeq: 101 CANCEL User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <------------> [Nov 20 10:26:25] WARNING[22796] app_dial.c: Unable to forward voice frame [Nov 20 10:26:25] DEBUG[22796] rtp.c: Channel '' has no RTP, not doing anything [Nov 20 10:26:25] DEBUG[22796] channel.c: Hanging up channel 'SIP/cisco3600-trunk-08413cf8' [Nov 20 10:26:25] DEBUG[22796] chan_sip.c: Hangup call SIP/cisco3600-trunk-08413cf8, SIP callid 14815fdb32431d1f415379b35142d259@87.255.0.218) [Nov 20 10:26:25] VERBOSE[22796] logger.c: [Nov 20 10:26:25] Scheduling destruction of SIP dialog '14815fdb32431d1f415379b35142d259@87.255.0.218' in 6400 ms (Method: INVITE) [Nov 20 10:26:25] DEBUG[22796] chan_sip.c: Acked pending invite 102 [Nov 20 10:26:25] DEBUG[22796] chan_sip.c: Stopping retransmission on '14815fdb32431d1f415379b35142d259@87.255.0.218' of Request 102: Match Not Found [Nov 20 10:26:25] VERBOSE[22796] logger.c: [Nov 20 10:26:25] Reliably Transmitting (no NAT) to 87.255.5.254:5060: CANCEL sip:00310000085722001@87.255.5.254 SIP/2.0 Via: SIP/2.0/UDP 87.255.0.218:5060;branch=z9hG4bK2fad2aef;rport From: "Fax 2" ;tag=as1839b898 To: Call-ID: 14815fdb32431d1f415379b35142d259@87.255.0.218 CSeq: 102 CANCEL User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- [Nov 20 10:26:25] VERBOSE[22796] logger.c: [Nov 20 10:26:25] Scheduling destruction of SIP dialog '14815fdb32431d1f415379b35142d259@87.255.0.218' in 6400 ms (Method: INVITE) [Nov 20 10:26:25] DEBUG[22796] devicestate.c: Notification of state change to be queued on device/channel SIP/cisco3600-trunk-08413cf8 [Nov 20 10:26:25] DEBUG[22796] cdr.c: CDR detaching from this thread [Nov 20 10:26:25] DEBUG[22796] app_dial.c: Exiting with DIALSTATUS=CANCEL. [Nov 20 10:26:25] DEBUG[22796] pbx.c: Spawn extension (out-def-city,5722001,3) exited non-zero on 'SIP/office_511-084ca7b8' [Nov 20 10:26:25] VERBOSE[22796] logger.c: [Nov 20 10:26:25] == Spawn extension (out-def-city, 5722001, 3) exited non-zero on 'SIP/office_511-084ca7b8' [Nov 20 10:26:25] DEBUG[22796] channel.c: Soft-Hanging up channel 'SIP/office_511-084ca7b8' [Nov 20 10:26:25] DEBUG[22796] channel.c: Hanging up channel 'SIP/office_511-084ca7b8' [Nov 20 10:26:25] DEBUG[22796] chan_sip.c: Hangup call SIP/office_511-084ca7b8, SIP callid 7439ae7d-f2a8457a@10.10.15.18) [Nov 20 10:26:25] DEBUG[22796] devicestate.c: Notification of state change to be queued on device/channel SIP/office_511-084ca7b8 [Nov 20 10:26:25] DEBUG[22796] cdr.c: CDR detaching from this thread [Nov 20 10:26:25] DEBUG[32320] chan_sip.c: Checking device state for peer office_511 [Nov 20 10:26:25] DEBUG[32320] devicestate.c: Changing state for SIP/office_511 - state 1 (Not in use) [Nov 20 10:26:25] DEBUG[32320] chan_sip.c: Checking device state for peer cisco3600-trunk [Nov 20 10:26:25] DEBUG[32320] devicestate.c: Changing state for SIP/cisco3600-trunk - state 1 (Not in use) [Nov 20 10:26:25] DEBUG[32320] chan_sip.c: Checking device state for peer office_511 [Nov 20 10:26:25] DEBUG[32320] devicestate.c: Changing state for SIP/office_511 - state 1 (Not in use) [Nov 20 10:26:25] DEBUG[32340] app_queue.c: Device 'SIP/office_511' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Nov 20 10:26:25] DEBUG[32340] app_queue.c: Device 'SIP/cisco3600-trunk' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Nov 20 10:26:25] DEBUG[32340] app_queue.c: Device 'SIP/office_511' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Nov 20 10:26:25] VERBOSE[32338] logger.c: [Nov 20 10:26:25] <--- SIP read from 10.10.15.18:5061 ---> ACK sip:95722001@87.255.0.218 SIP/2.0 Via: SIP/2.0/UDP 10.10.15.18:5061;branch=z9hG4bK-f7649d9e From: ;tag=82afd2a1ec29cfa6o1 To: ;tag=as57d5276a Call-ID: 7439ae7d-f2a8457a@10.10.15.18 CSeq: 101 ACK Max-Forwards: 70 Contact: User-Agent: Linksys/SPA2102-5.1.12 Content-Length: 0 <-------------> [Nov 20 10:26:25] VERBOSE[32338] logger.c: [Nov 20 10:26:25] --- (10 headers 0 lines) --- [Nov 20 10:26:25] DEBUG[32338] chan_sip.c: Stopping retransmission on '7439ae7d-f2a8457a@10.10.15.18' of Response 101: Match Not Found [Nov 20 10:26:25] VERBOSE[32338] logger.c: [Nov 20 10:26:25] Really destroying SIP dialog '7439ae7d-f2a8457a@10.10.15.18' Method: ACK [Nov 20 10:26:25] VERBOSE[32338] logger.c: [Nov 20 10:26:25] <--- SIP read from 87.255.5.254:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 87.255.0.218:5060;branch=z9hG4bK2fad2aef;rport From: "Fax 2" ;tag=as1839b898 To: Date: Tue, 20 Nov 2007 07:26:04 GMT Call-ID: 14815fdb32431d1f415379b35142d259@87.255.0.218 Content-Length: 0 CSeq: 102 CANCEL <-------------> [Nov 20 10:26:25] VERBOSE[32338] logger.c: [Nov 20 10:26:25] --- (8 headers 0 lines) --- [Nov 20 10:26:25] DEBUG[32338] chan_sip.c: Stopping retransmission on '14815fdb32431d1f415379b35142d259@87.255.0.218' of Request 102: Match Not Found [Nov 20 10:26:25] VERBOSE[32338] logger.c: [Nov 20 10:26:25] <--- SIP read from 10.10.15.40:50608 ---> SIP/2.0 180 Ringing Via: SIP/2.0/UDP 87.255.0.218:5060;branch=z9hG4bK18bda275;rport From: "7877871" ;tag=as447d807e To: ;tag=00164739abb6086c5eab217f-7521f315 Call-ID: 77e8e8a02c0daa456817173237cf6533@87.255.0.218 Date: Tue, 20 Nov 2007 07:26:05 GMT CSeq: 102 INVITE Server: Cisco-CP7940G/8.0 Contact: Allow: ACK,BYE,CANCEL,INVITE,NOTIFY,OPTIONS,REFER,REGISTER,UPDATE Remote-Party-ID: "Night Support" ;party=called;id-type=subscriber;privacy=off;screen=yes Content-Length: 0 <-------------> [Nov 20 10:26:25] VERBOSE[32338] logger.c: [Nov 20 10:26:25] --- (12 headers 0 lines) --- [Nov 20 10:26:25] DEBUG[32338] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '77e8e8a02c0daa456817173237cf6533@87.255.0.218' Request 102: Found [Nov 20 10:26:25] DEBUG[32338] devicestate.c: Notification of state change to be queued on device/channel SIP/office_853-085923c0 [Nov 20 10:26:25] VERBOSE[18674] logger.c: [Nov 20 10:26:25] -- SIP/office_853-085923c0 is ringing [Nov 20 10:26:25] DEBUG[32320] chan_sip.c: Checking device state for peer office_853 [Nov 20 10:26:25] DEBUG[32320] devicestate.c: Changing state for SIP/office_853 - state 6 (Ringing) [Nov 20 10:26:25] DEBUG[32340] app_queue.c: Device 'SIP/office_853' changed to state '6' (Ringing) [Nov 20 10:26:25] VERBOSE[32338] logger.c: [Nov 20 10:26:25] <--- SIP read from 87.255.5.254:5060 ---> SIP/2.0 487 Request Cancelled Via: SIP/2.0/UDP 87.255.0.218:5060;branch=z9hG4bK2fad2aef;rport From: "Fax 2" ;tag=as1839b898 To: ;tag=832E5D08-1C9C Date: Tue, 20 Nov 2007 07:26:04 GMT Call-ID: 14815fdb32431d1f415379b35142d259@87.255.0.218 Server: Cisco-SIPGateway/IOS-12.x CSeq: 102 INVITE Allow-Events: telephone-event Content-Length: 0 <-------------> [Nov 20 10:26:25] VERBOSE[32338] logger.c: [Nov 20 10:26:25] --- (10 headers 0 lines) --- [Nov 20 10:26:25] DEBUG[32338] chan_sip.c: Stopping retransmission on '14815fdb32431d1f415379b35142d259@87.255.0.218' of Request 102: Match Found [Nov 20 10:26:25] VERBOSE[32338] logger.c: [Nov 20 10:26:25] Transmitting (no NAT) to 87.255.5.254:5060: ACK sip:00310000085722001@87.255.5.254 SIP/2.0 Via: SIP/2.0/UDP 87.255.0.218:5060;branch=z9hG4bK2fad2aef;rport From: "Fax 2" ;tag=as1839b898 To: ;tag=832E5D08-1C9C Contact: Call-ID: 14815fdb32431d1f415379b35142d259@87.255.0.218 CSeq: 102 ACK User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- [Nov 20 10:26:25] DEBUG[32338] chan_sip.c: Updating call counter for outgoing call [Nov 20 10:26:25] DEBUG[32338] chan_sip.c: Setting SIP_ALREADYGONE on dialog 14815fdb32431d1f415379b35142d259@87.255.0.218 [Nov 20 10:26:25] VERBOSE[32338] logger.c: [Nov 20 10:26:25] Really destroying SIP dialog '14815fdb32431d1f415379b35142d259@87.255.0.218' Method: INVITE [Nov 20 10:26:25] DEBUG[22063] app_queue.c: Even though there are 0 available members, the strategy is ringall so only the head call is allowed in [Nov 20 10:26:25] DEBUG[22063] app_queue.c: There are 1 available members. [Nov 20 10:26:25] DEBUG[22063] app_queue.c: It's not our turn (SIP/87.255.0.210-08358b18). [Nov 20 10:26:25] DEBUG[21136] app_queue.c: Even though there are 0 available members, the strategy is ringall so only the head call is allowed in [Nov 20 10:26:25] DEBUG[21136] app_queue.c: There are 1 available members. [Nov 20 10:26:25] DEBUG[21136] app_queue.c: It's not our turn (SIP/87.255.0.210-08563b20). [Nov 20 10:26:25] DEBUG[21967] app_queue.c: Even though there are 0 available members, the strategy is ringall so only the head call is allowed in [Nov 20 10:26:25] DEBUG[21967] app_queue.c: There are 1 available members. [Nov 20 10:26:25] DEBUG[21967] app_queue.c: It's not our turn (SIP/87.255.0.210-08457c40). [Nov 20 10:26:25] DEBUG[21806] app_queue.c: Even though there are 0 available members, the strategy is ringall so only the head call is allowed in [Nov 20 10:26:25] DEBUG[21806] app_queue.c: There are 1 available members. [Nov 20 10:26:25] DEBUG[21806] app_queue.c: It's not our turn (SIP/87.255.5.254-0833f4d0). [Nov 20 10:26:25] VERBOSE[32338] logger.c: [Nov 20 10:26:25] Retransmitting #1 (no NAT) to 87.255.5.115:5060: OPTIONS sip:87.255.5.115 SIP/2.0 Via: SIP/2.0/UDP 87.255.0.218:5060;branch=z9hG4bK127e6673;rport From: "asterisk" ;tag=as3ef58805 To: Contact: Call-ID: 4e0ac2355735c35f2b478d92705a4a3c@87.255.0.218 CSeq: 102 OPTIONS User-Agent: Asterisk PBX Max-Forwards: 70 Date: Tue, 20 Nov 2007 07:26:24 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Length: 0 --- [Nov 20 10:26:25] VERBOSE[32338] logger.c: [Nov 20 10:26:25] <--- SIP read from 10.10.15.31:50359 ---> SIP/2.0 481 Call Leg/Transaction Does Not Exist Via: SIP/2.0/UDP 87.255.0.218:5060;branch=z9hG4bK3eedec57;rport From: ;tag=as693d36fc To: "call2" ;tag=000a8a179649304a13affdd0-50742aef Call-ID: 000a8a17-964901c2-446278d0-3cd3b54d@10.10.15.31 Date: Wed, 14 Nov 2007 13:15:22 GMT CSeq: 102 INVITE Server: Cisco-CP7940G/8.0 Contact: Allow: ACK,BYE,CANCEL,INVITE,NOTIFY,OPTIONS,REFER,REGISTER,UPDATE Remote-Party-ID: "call2" ;party=called;id-type=subscriber;privacy=off;screen=yes Content-Length: 0 <-------------> [Nov 20 10:26:25] VERBOSE[32338] logger.c: [Nov 20 10:26:25] --- (12 headers 0 lines) --- [Nov 20 10:26:25] DEBUG[32338] chan_sip.c: Invalid SIP message - rejected , no callid, len 659 [Nov 20 10:26:25] DEBUG[32338] chan_sip.c: Auto destroying SIP dialog '513cc4355874eb3066e72198668a2c83@87.255.0.218' [Nov 20 10:26:25] DEBUG[32338] chan_sip.c: Finally hanging up channel after transfer: 513cc4355874eb3066e72198668a2c83@87.255.0.218 [Nov 20 10:26:25] DEBUG[32338] chan_sip.c: Strict routing enforced for session 513cc4355874eb3066e72198668a2c83@87.255.0.218 [Nov 20 10:26:25] VERBOSE[32338] logger.c: [Nov 20 10:26:25] set_destination: Parsing for address/port to send to [Nov 20 10:26:25] VERBOSE[32338] logger.c: [Nov 20 10:26:25] set_destination: set destination to 10.10.15.31, port 5060 [Nov 20 10:26:25] VERBOSE[32338] logger.c: [Nov 20 10:26:25] Reliably Transmitting (no NAT) to 10.10.15.31:5060: BYE sip:office_802@10.10.15.31:5060;user=phone;transport=udp SIP/2.0 Via: SIP/2.0/UDP 87.255.0.218:5060;branch=z9hG4bK2daecebe;rport From: "7877871" ;tag=as782c414a To: ;tag=000a8a179649556238e1ca97-08e0fa0d Call-ID: 513cc4355874eb3066e72198668a2c83@87.255.0.218 CSeq: 105 BYE User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- [Nov 20 10:26:25] VERBOSE[32338] logger.c: [Nov 20 10:26:25] Scheduling destruction of SIP dialog '513cc4355874eb3066e72198668a2c83@87.255.0.218' in 111616 ms (Method: BYE) [Nov 20 10:26:25] DEBUG[19422] app_queue.c: Even though there are 0 available members, the strategy is ringall so only the head call is allowed in [Nov 20 10:26:25] DEBUG[19422] app_queue.c: There are 1 available members. [Nov 20 10:26:25] DEBUG[19422] app_queue.c: It's not our turn (SIP/87.255.0.210-b6066a68). [Nov 20 10:26:25] DEBUG[22671] rtp.c: Got RTCP report of 132 bytes [Nov 20 10:26:25] DEBUG[22007] app_queue.c: Even though there are 0 available members, the strategy is ringall so only the head call is allowed in [Nov 20 10:26:25] DEBUG[22007] app_queue.c: There are 1 available members. [Nov 20 10:26:25] DEBUG[22007] app_queue.c: It's not our turn (SIP/87.255.5.254-083ef0a0). [Nov 20 10:26:26] VERBOSE[32338] logger.c: [Nov 20 10:26:26] <--- SIP read from 10.10.15.31:51291 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 87.255.0.218:5060;branch=z9hG4bK2daecebe;rport From: "7877871" ;tag=as782c414a To: ;tag=000a8a179649556238e1ca97-08e0fa0d Call-ID: 513cc4355874eb3066e72198668a2c83@87.255.0.218 Date: Tue, 20 Nov 2007 07:26:04 GMT CSeq: 105 BYE Content-Length: 0 <-------------> [Nov 20 10:26:26] VERBOSE[32338] logger.c: [Nov 20 10:26:26] --- (8 headers 0 lines) --- [Nov 20 10:26:26] DEBUG[32338] chan_sip.c: Stopping retransmission on '513cc4355874eb3066e72198668a2c83@87.255.0.218' of Request 105: Match Not Found [Nov 20 10:26:26] VERBOSE[32338] logger.c: [Nov 20 10:26:26] SIP Response message for INCOMING dialog BYE arrived [Nov 20 10:26:26] VERBOSE[32338] logger.c: [Nov 20 10:26:26] Really destroying SIP dialog '513cc4355874eb3066e72198668a2c83@87.255.0.218' Method: BYE [Nov 20 10:26:26] DEBUG[32338] chan_sip.c: Updating call counter for outgoing call [Nov 20 10:26:26] DEBUG[32338] chan_sip.c: Call to peer 'office_802' removed from call limit 8 [Nov 20 10:26:26] DEBUG[32338] devicestate.c: Notification of state change to be queued on device/channel SIP/office_802 [Nov 20 10:26:26] DEBUG[32338] chan_sip.c: This call did not properly clean up call limits. Call ID 513cc4355874eb3066e72198668a2c83@87.255.0.218 [Nov 20 10:26:26] DEBUG[32320] chan_sip.c: Checking device state for peer office_802 [Nov 20 10:26:26] DEBUG[32320] devicestate.c: Changing state for SIP/office_802 - state 1 (Not in use) [Nov 20 10:26:26] DEBUG[32340] app_queue.c: Device 'SIP/office_802' changed to state '1' (Not in use) [Nov 20 10:26:26] VERBOSE[32317] logger.c: [Nov 20 10:26:26] -- Remote UNIX connection [Nov 20 10:26:26] DEBUG[18440] rtp.c: Got RTCP report of 132 bytes [Nov 20 10:26:26] DEBUG[19901] rtp.c: Got RTCP report of 132 bytes [Nov 20 10:26:26] VERBOSE[22834] logger.c: [Nov 20 10:26:26] -- Remote UNIX connection disconnected [Nov 20 10:26:26] VERBOSE[32338] logger.c: [Nov 20 10:26:26] <--- SIP read from 10.10.25.24:5060 ---> INVITE sip:8499794@87.255.0.218 SIP/2.0 Via: SIP/2.0/UDP 10.10.25.24:5060;branch=z9hG4bK-bb5226dd From: ;tag=8130afaf534f450do0 To: Remote-Party-ID: ;screen=yes;party=calling Call-ID: 210a55d7-e4a19505@10.10.25.24 CSeq: 101 INVITE Max-Forwards: 70 Contact: Expires: 240 User-Agent: Linksys/SPA2102-5.1.12 Content-Length: 440 Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER Supported: x-sipura, replaces Content-Type: application/sdp v=0 o=- 923249 923249 IN IP4 10.10.25.24 s=- c=IN IP4 10.10.25.24 t=0 0 m=audio 16428 RTP/AVP 0 2 4 8 18 96 97 98 100 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:100 NSE/8000 a=fmtp:100 192-193 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:30 a=sendrecv <-------------> [Nov 20 10:26:26] VERBOSE[32338] logger.c: [Nov 20 10:26:26] --- (15 headers 20 lines) --- [Nov 20 10:26:26] DEBUG[32338] acl.c: ##### Testing 10.10.25.24 with 87.255.7.0 [Nov 20 10:26:26] DEBUG[32338] acl.c: ##### Testing 10.10.25.24 with 87.255.5.0 [Nov 20 10:26:26] DEBUG[32338] acl.c: ##### Testing 10.10.25.24 with 87.255.4.0 [Nov 20 10:26:26] DEBUG[32338] acl.c: ##### Testing 10.10.25.24 with 87.255.3.0 [Nov 20 10:26:26] DEBUG[32338] acl.c: ##### Testing 10.10.25.24 with 87.255.1.0 [Nov 20 10:26:26] DEBUG[32338] acl.c: ##### Testing 10.10.25.24 with 87.255.0.64 [Nov 20 10:26:26] DEBUG[32338] acl.c: ##### Testing 10.10.25.24 with 192.168.0.0 [Nov 20 10:26:26] DEBUG[32338] acl.c: ##### Testing 10.10.25.24 with 10.0.0.0 [Nov 20 10:26:26] DEBUG[32338] acl.c: ##### Testing 10.10.25.24 with 172.16.0.0 [Nov 20 10:26:26] DEBUG[32338] chan_sip.c: Setting NAT on RTP to Off [Nov 20 10:26:26] DEBUG[32338] chan_sip.c: Setting NAT on VRTP to Off [Nov 20 10:26:26] DEBUG[32338] chan_sip.c: Setting NAT on UDPTL to Off [Nov 20 10:26:26] DEBUG[32338] chan_sip.c: Allocating new SIP dialog for 210a55d7-e4a19505@10.10.25.24 - INVITE (With RTP) [Nov 20 10:26:26] DEBUG[32338] chan_sip.c: Begin: parsing SIP "Supported: x-sipura, replaces" [Nov 20 10:26:26] DEBUG[32338] chan_sip.c: Found SIP option: -x-sipura- [Nov 20 10:26:26] DEBUG[32338] chan_sip.c: Found private SIP option, not supported: x-sipura [Nov 20 10:26:26] DEBUG[32338] chan_sip.c: Found SIP option: -replaces- [Nov 20 10:26:26] DEBUG[32338] chan_sip.c: Matched SIP option: replaces [Nov 20 10:26:26] VERBOSE[32338] logger.c: [Nov 20 10:26:26] Sending to 10.10.25.24 : 5060 (no NAT) [Nov 20 10:26:26] VERBOSE[32338] logger.c: [Nov 20 10:26:26] Using INVITE request as basis request - 210a55d7-e4a19505@10.10.25.24 [Nov 20 10:26:26] DEBUG[32338] chan_sip.c: Setting NAT on RTP to Off [Nov 20 10:26:26] DEBUG[32338] chan_sip.c: Setting NAT on VRTP to Off [Nov 20 10:26:26] DEBUG[32338] chan_sip.c: Setting NAT on UDPTL to Off [Nov 20 10:26:26] VERBOSE[32338] logger.c: [Nov 20 10:26:26] <--- Reliably Transmitting (no NAT) to 10.10.25.24:5060 ---> SIP/2.0 407 Proxy Authentication Required Via: SIP/2.0/UDP 10.10.25.24:5060;branch=z9hG4bK-bb5226dd;received=10.10.25.24 From: ;tag=8130afaf534f450do0 To: ;tag=as1d904142 Call-ID: 210a55d7-e4a19505@10.10.25.24 CSeq: 101 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Proxy-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="39d0b21d" Content-Length: 0 <------------> [Nov 20 10:26:26] VERBOSE[32338] logger.c: [Nov 20 10:26:26] Scheduling destruction of SIP dialog '210a55d7-e4a19505@10.10.25.24' in 32000 ms (Method: INVITE) [Nov 20 10:26:26] VERBOSE[32338] logger.c: [Nov 20 10:26:26] Found user 'a74956624655' [Nov 20 10:26:26] DEBUG[22063] app_queue.c: Even though there are 0 available members, the strategy is ringall so only the head call is allowed in [Nov 20 10:26:26] DEBUG[22063] app_queue.c: There are 1 available members. [Nov 20 10:26:26] DEBUG[22063] app_queue.c: It's not our turn (SIP/87.255.0.210-08358b18). [Nov 20 10:26:26] VERBOSE[22063] logger.c: [Nov 20 10:26:26] -- Stopped music on hold on SIP/87.255.0.210-08358b18 [Nov 20 10:26:26] DEBUG[22063] channel.c: Set channel SIP/87.255.0.210-08358b18 to write format ulaw