[Aug 18 15:55:06] VERBOSE[19793] logger.c: -- Executing [s@macro-dialout-trunk-predial-hook:354] Dial("SIP/91.199.174.215-082ab508", "SIP/VOIP_AMIS-peer/026208309,300,") in new stack [Aug 18 15:55:06] DEBUG[19793] chan_sip.c: Asked to create a SIP channel with formats: 0x8 (alaw) [Aug 18 15:55:06] WARNING[19793] netsock.c: Unable to set SIP RTP TOS to 184, may be you have no root privileges [Aug 18 15:55:06] VERBOSE[19793] logger.c: == Using SIP RTP CoS mark 5 [Aug 18 15:55:06] DEBUG[19793] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP) [Aug 18 15:55:06] DEBUG[19793] chan_sip.c: Setting NAT on RTP to Off [Aug 18 15:55:06] DEBUG[19793] chan_sip.c: OBPROXY: Not applying OBproxy to this call [Aug 18 15:55:06] DEBUG[19793] acl.c: Found IP address for this socket [Aug 18 15:55:06] DEBUG[19793] chan_sip.c: *** Our native formats are 0x8 (alaw) [Aug 18 15:55:06] DEBUG[19793] chan_sip.c: *** Joint capabilities are 0x8 (alaw) [Aug 18 15:55:06] DEBUG[19793] chan_sip.c: *** Our capabilities are 0xc (ulaw|alaw) [Aug 18 15:55:06] DEBUG[19793] chan_sip.c: *** AST_CODEC_CHOOSE formats are 0x8 (alaw) [Aug 18 15:55:06] DEBUG[19793] chan_sip.c: *** Our preferred formats from the incoming channel are 0x8 (alaw) [Aug 18 15:55:06] DEBUG[19793] chan_sip.c: This channel will not be able to handle video. [Aug 18 15:55:06] DEBUG[19793] dsp.c: Setup tone 1100 Hz, 500 ms, block_size=160, hits_required=21 [Aug 18 15:55:06] DEBUG[19793] dsp.c: Setup tone 2100 Hz, 2600 ms, block_size=160, hits_required=116 [Aug 18 15:55:06] DEBUG[19793] channel.c: Not copying variable DIALEDTIME. [Aug 18 15:55:06] DEBUG[19793] channel.c: Not copying variable ANSWEREDTIME. [Aug 18 15:55:06] DEBUG[19793] channel.c: Not copying variable DIALEDPEERNAME. [Aug 18 15:55:06] DEBUG[19793] channel.c: Not copying variable DIALEDPEERNUMBER. [Aug 18 15:55:06] DEBUG[19793] channel.c: Not copying variable DIALSTATUS. [Aug 18 15:55:06] DEBUG[19793] channel.c: Not copying variable MACRO_DEPTH. [Aug 18 15:55:06] DEBUG[19793] channel.c: Copying hard-transferable variable SIPADDHEADER02. [Aug 18 15:55:06] DEBUG[19793] channel.c: Copying hard-transferable variable SIPADDHEADER01. [Aug 18 15:55:06] DEBUG[19793] channel.c: Not copying variable post_num. [Aug 18 15:55:06] DEBUG[19793] channel.c: Not copying variable ROUTE_NAME. [Aug 18 15:55:06] DEBUG[19793] channel.c: Not copying variable the_num. [Aug 18 15:55:06] DEBUG[19793] channel.c: Not copying variable pre_num. [Aug 18 15:55:06] DEBUG[19793] channel.c: Not copying variable AGISTATUS. [Aug 18 15:55:06] DEBUG[19793] channel.c: Not copying variable ARG_DIAL_TRUNK. [Aug 18 15:55:06] DEBUG[19793] channel.c: Not copying variable ARG_CID. [Aug 18 15:55:06] DEBUG[19793] channel.c: Not copying variable REAL_CID. [Aug 18 15:55:06] DEBUG[19793] channel.c: Not copying variable PREDIAL_HOOK_RET. [Aug 18 15:55:06] DEBUG[19793] channel.c: Not copying variable ARG1. [Aug 18 15:55:06] DEBUG[19793] channel.c: Not copying variable MACRO_PRIORITY. [Aug 18 15:55:06] DEBUG[19793] channel.c: Not copying variable MACRO_CONTEXT. [Aug 18 15:55:06] DEBUG[19793] channel.c: Not copying variable MACRO_EXTEN. [Aug 18 15:55:06] DEBUG[19793] channel.c: Not copying variable custom. [Aug 18 15:55:06] DEBUG[19793] channel.c: Not copying variable OUTNUM. [Aug 18 15:55:06] DEBUG[19793] channel.c: Not copying variable TRUNKOUTCID. [Aug 18 15:55:06] DEBUG[19793] channel.c: Not copying variable EMERGENCYCID. [Aug 18 15:55:06] DEBUG[19793] channel.c: Not copying variable USEROUTCID. [Aug 18 15:55:06] DEBUG[19793] channel.c: Not copying variable REALCALLERIDNUM. [Aug 18 15:55:06] DEBUG[19793] channel.c: Not copying variable DIAL_TRUNK_OPTIONS. [Aug 18 15:55:06] DEBUG[19793] channel.c: Not copying variable OUTBOUND_GROUP. [Aug 18 15:55:06] DEBUG[19793] channel.c: Not copying variable DIAL_NUMBER. [Aug 18 15:55:06] DEBUG[19793] channel.c: Not copying variable DIAL_TRUNK. [Aug 18 15:55:06] DEBUG[19793] channel.c: Not copying variable ARG4. [Aug 18 15:55:06] DEBUG[19793] channel.c: Not copying variable ARG3. [Aug 18 15:55:06] DEBUG[19793] channel.c: Not copying variable ARG2. [Aug 18 15:55:06] DEBUG[19793] channel.c: Not copying variable trunk_num. [Aug 18 15:55:06] DEBUG[19793] channel.c: Not copying variable SIPCALLID. [Aug 18 15:55:06] DEBUG[19793] channel.c: Not copying variable SIPDOMAIN. [Aug 18 15:55:06] DEBUG[19793] channel.c: Not copying variable SIPURI. [Aug 18 15:55:06] DEBUG[19793] chan_sip.c: Outgoing Call for 026208309 [Aug 18 15:55:06] DEBUG[19793] chan_sip.c: Updating call counter for outgoing call [Aug 18 15:55:06] DEBUG[19793] chan_sip.c: Our T38 capability (0), joint T38 capability (0) [Aug 18 15:55:06] DEBUG[19793] chan_sip.c: Adding SIP Header "X-route_name" with content :: [Aug 18 15:55:06] DEBUG[19793] chan_sip.c: Adding SIP Header "X-srcuid" with content :1250603706.67: [Aug 18 15:55:06] DEBUG[19793] chan_sip.c: ** Our capability: 0xc (ulaw|alaw) Video flag: False Text flag: False [Aug 18 15:55:06] DEBUG[19793] chan_sip.c: ** Our prefcodec: 0x8 (alaw) [Aug 18 15:55:06] VERBOSE[19793] logger.c: Audio is at 10.61.16.2 port 10098 [Aug 18 15:55:06] VERBOSE[19793] logger.c: Adding codec 0x8 (alaw) to SDP [Aug 18 15:55:06] VERBOSE[19793] logger.c: Adding codec 0x4 (ulaw) to SDP [Aug 18 15:55:06] DEBUG[19793] chan_sip.c: -- Done with adding codecs to SDP [Aug 18 15:55:06] DEBUG[19793] channel.c: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1) [Aug 18 15:55:06] DEBUG[19793] chan_sip.c: Done building SDP. Settling with this capability: 0xc (ulaw|alaw) [Aug 18 15:55:06] DEBUG[19793] chan_sip.c: Initializing initreq for method INVITE - callid 0f1e533008905417497809f127add60f@10.61.16.2 [Aug 18 15:55:06] DEBUG[19793] chan_sip.c: Header 0 [ 40]: INVITE sip:026208309@10.22.11.20 SIP/2.0 [Aug 18 15:55:06] DEBUG[19793] chan_sip.c: Header 1 [ 61]: Via: SIP/2.0/UDP 10.61.16.2:5060;branch=z9hG4bK72e57847;rport [Aug 18 15:55:06] DEBUG[19793] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Aug 18 15:55:06] DEBUG[19793] chan_sip.c: Header 3 [ 62]: From: "Kocbek Milos" ;tag=as09d56ebc [Aug 18 15:55:06] DEBUG[19793] chan_sip.c: Header 4 [ 31]: To: [Aug 18 15:55:06] DEBUG[19793] chan_sip.c: Header 5 [ 35]: Contact: [Aug 18 15:55:06] DEBUG[19793] chan_sip.c: Header 6 [ 52]: Call-ID: 0f1e533008905417497809f127add60f@10.61.16.2 [Aug 18 15:55:06] DEBUG[19793] chan_sip.c: Header 7 [ 16]: CSeq: 102 INVITE [Aug 18 15:55:06] DEBUG[19793] chan_sip.c: Header 8 [ 33]: User-Agent: Asterisk PBX 1.6.0.13 [Aug 18 15:55:06] DEBUG[19793] chan_sip.c: Header 9 [ 35]: Date: Tue, 18 Aug 2009 13:55:06 GMT [Aug 18 15:55:06] DEBUG[19793] chan_sip.c: Header 10 [ 66]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY [Aug 18 15:55:06] DEBUG[19793] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [Aug 18 15:55:06] DEBUG[19793] chan_sip.c: Header 12 [ 14]: X-route_name: [Aug 18 15:55:06] DEBUG[19793] chan_sip.c: Header 13 [ 23]: X-srcuid: 1250603706.67 [Aug 18 15:55:06] DEBUG[19793] chan_sip.c: Header 14 [ 29]: Content-Type: application/sdp [Aug 18 15:55:06] DEBUG[19793] chan_sip.c: Header 15 [ 19]: Content-Length: 226 [Aug 18 15:55:06] DEBUG[19793] chan_sip.c: Header 16 [ 0]: [Aug 18 15:55:06] DEBUG[19793] chan_sip.c: Body 0 [ 3]: v=0 [Aug 18 15:55:06] DEBUG[19793] chan_sip.c: Body 1 [ 44]: o=root 475840445 475840445 IN IP4 10.61.16.2 [Aug 18 15:55:06] DEBUG[19793] chan_sip.c: Body 2 [ 23]: s=Asterisk PBX 1.6.0.13 [Aug 18 15:55:06] DEBUG[19793] chan_sip.c: Body 3 [ 19]: c=IN IP4 10.61.16.2 [Aug 18 15:55:06] DEBUG[19793] chan_sip.c: Body 4 [ 5]: t=0 0 [Aug 18 15:55:06] DEBUG[19793] chan_sip.c: Body 5 [ 25]: m=audio 10098 RTP/AVP 8 0 [Aug 18 15:55:06] DEBUG[19793] chan_sip.c: Body 6 [ 20]: a=rtpmap:8 PCMA/8000 [Aug 18 15:55:06] DEBUG[19793] chan_sip.c: Body 7 [ 20]: a=rtpmap:0 PCMU/8000 [Aug 18 15:55:06] DEBUG[19793] chan_sip.c: Body 8 [ 25]: a=silenceSupp:off - - - - [Aug 18 15:55:06] DEBUG[19793] chan_sip.c: Body 9 [ 10]: a=ptime:20 [Aug 18 15:55:06] DEBUG[19793] chan_sip.c: Body 10 [ 10]: a=sendrecv [Aug 18 15:55:06] VERBOSE[19793] logger.c: Reliably Transmitting (no NAT) to 10.22.11.20:5060: INVITE sip:026208309@10.22.11.20 SIP/2.0 Via: SIP/2.0/UDP 10.61.16.2:5060;branch=z9hG4bK72e57847;rport Max-Forwards: 70 From: "Kocbek Milos" ;tag=as09d56ebc To: Contact: Call-ID: 0f1e533008905417497809f127add60f@10.61.16.2 CSeq: 102 INVITE User-Agent: Asterisk PBX 1.6.0.13 Date: Tue, 18 Aug 2009 13:55:06 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces, timer X-route_name: X-srcuid: 1250603706.67 Content-Type: application/sdp Content-Length: 226 v=0 o=root 475840445 475840445 IN IP4 10.61.16.2 s=Asterisk PBX 1.6.0.13 c=IN IP4 10.61.16.2 t=0 0 m=audio 10098 RTP/AVP 8 0 a=rtpmap:8 PCMA/8000 a=rtpmap:0 PCMU/8000 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv --- [Aug 18 15:55:06] DEBUG[19793] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #18552 [Aug 18 15:55:06] DEBUG[19793] chan_sip.c: Trying to put 'INVITE sip' onto UDP socket destined for 10.22.11.20:5060 [Aug 18 15:55:06] VERBOSE[19793] logger.c: -- Called VOIP_AMIS-peer/026208309 [Aug 18 15:55:06] VERBOSE[19084] logger.c: <--- SIP read from UDP://10.22.11.20:5060 ---> SIP/2.0 407 authentication required Allow: UPDATE,INFO,REFER,INVITE,ACK,OPTIONS,REGISTER,SUBSCRIBE,MESSAGE,NOTIFY,BYE,CANCEL,PRACK Call-ID: 0f1e533008905417497809f127add60f@10.61.16.2 Contact: CSeq: 102 INVITE From: "Kocbek Milos" ;tag=as09d56ebc Proxy-Authenticate: Digest realm="sip-priv.amis.net",nonce="008d33201ac9dbf0619afd3b13eb9686",opaque="008b66360984230",stale=false,algorithm=MD5 Server: Cirpack/v4.42d (gw_sip) To: ;tag=02-08056-008d3348-76356bda2 Via: SIP/2.0/UDP 10.61.16.2:5060;received=10.61.16.2;rport=5060;branch=z9hG4bK72e57847 Content-Length: 0 <-------------> [Aug 18 15:55:06] DEBUG[19084] chan_sip.c: Header 0 [ 35]: SIP/2.0 407 authentication required [Aug 18 15:55:06] DEBUG[19084] chan_sip.c: Header 1 [ 94]: Allow: UPDATE,INFO,REFER,INVITE,ACK,OPTIONS,REGISTER,SUBSCRIBE,MESSAGE,NOTIFY,BYE,CANCEL,PRACK [Aug 18 15:55:06] DEBUG[19084] chan_sip.c: Header 2 [ 52]: Call-ID: 0f1e533008905417497809f127add60f@10.61.16.2 [Aug 18 15:55:06] DEBUG[19084] chan_sip.c: Header 3 [ 52]: Contact: [Aug 18 15:55:06] DEBUG[19084] chan_sip.c: Header 4 [ 16]: CSeq: 102 INVITE [Aug 18 15:55:06] DEBUG[19084] chan_sip.c: Header 5 [ 62]: From: "Kocbek Milos" ;tag=as09d56ebc [Aug 18 15:55:06] DEBUG[19084] chan_sip.c: Header 6 [144]: Proxy-Authenticate: Digest realm="sip-priv.amis.net",nonce="008d33201ac9dbf0619afd3b13eb9686",opaque="008b66360984230",stale=false,algorithm=MD5 [Aug 18 15:55:06] DEBUG[19084] chan_sip.c: Header 7 [ 31]: Server: Cirpack/v4.42d (gw_sip) [Aug 18 15:55:06] DEBUG[19084] chan_sip.c: Header 8 [ 63]: To: ;tag=02-08056-008d3348-76356bda2 [Aug 18 15:55:06] DEBUG[19084] chan_sip.c: Header 9 [ 86]: Via: SIP/2.0/UDP 10.61.16.2:5060;received=10.61.16.2;rport=5060;branch=z9hG4bK72e57847 [Aug 18 15:55:06] DEBUG[19084] chan_sip.c: Header 10 [ 17]: Content-Length: 0 [Aug 18 15:55:06] DEBUG[19084] chan_sip.c: Header 11 [ 0]: [Aug 18 15:55:06] VERBOSE[19084] logger.c: --- (11 headers 0 lines) --- [Aug 18 15:55:06] DEBUG[19084] chan_sip.c: = Found Their Call ID: 0f1e533008905417497809f127add60f@10.61.16.2 Their Tag Our tag: as09d56ebc [Aug 18 15:55:06] DEBUG[19084] chan_sip.c: Acked pending invite 102 [Aug 18 15:55:06] DEBUG[19084] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #18552 [Aug 18 15:55:06] DEBUG[19084] chan_sip.c: Stopping retransmission on '0f1e533008905417497809f127add60f@10.61.16.2' of Request 102: Match Found [Aug 18 15:55:06] DEBUG[19084] chan_sip.c: SIP response 407 to standard invite [Aug 18 15:55:06] VERBOSE[19084] logger.c: Transmitting (no NAT) to 10.22.11.20:5060: ACK sip:026208309@10.22.11.20 SIP/2.0 Via: SIP/2.0/UDP 10.61.16.2:5060;branch=z9hG4bK72e57847;rport Max-Forwards: 70 From: "Kocbek Milos" ;tag=as09d56ebc To: ;tag=02-08056-008d3348-76356bda2 Contact: Call-ID: 0f1e533008905417497809f127add60f@10.61.16.2 CSeq: 102 ACK User-Agent: Asterisk PBX 1.6.0.13 Content-Length: 0 --- [Aug 18 15:55:06] DEBUG[19084] chan_sip.c: Trying to put 'ACK sip:02' onto UDP socket destined for 10.22.11.20:5060 [Aug 18 15:55:06] DEBUG[19084] chan_sip.c: Auth attempt 1 on INVITE [Aug 18 15:55:06] DEBUG[19084] chan_sip.c: Adding SIP Header "X-route_name" with content :: [Aug 18 15:55:06] DEBUG[19084] chan_sip.c: Adding SIP Header "X-srcuid" with content :1250603706.67: [Aug 18 15:55:06] DEBUG[19084] chan_sip.c: ** Our capability: 0xc (ulaw|alaw) Video flag: False Text flag: False [Aug 18 15:55:06] DEBUG[19084] chan_sip.c: ** Our prefcodec: 0x8 (alaw) [Aug 18 15:55:06] VERBOSE[19084] logger.c: Audio is at 10.61.16.2 port 10098 [Aug 18 15:55:06] VERBOSE[19084] logger.c: Adding codec 0x8 (alaw) to SDP [Aug 18 15:55:06] VERBOSE[19084] logger.c: Adding codec 0x4 (ulaw) to SDP [Aug 18 15:55:06] DEBUG[19084] chan_sip.c: -- Done with adding codecs to SDP [Aug 18 15:55:06] DEBUG[19084] channel.c: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1) [Aug 18 15:55:06] DEBUG[19084] chan_sip.c: Done building SDP. Settling with this capability: 0xc (ulaw|alaw) [Aug 18 15:55:06] VERBOSE[19084] logger.c: Reliably Transmitting (no NAT) to 10.22.11.20:5060: INVITE sip:026208309@10.22.11.20 SIP/2.0 Via: SIP/2.0/UDP 10.61.16.2:5060;branch=z9hG4bK1255b43d;rport Max-Forwards: 70 From: "Kocbek Milos" ;tag=as09d56ebc To: Contact: Call-ID: 0f1e533008905417497809f127add60f@10.61.16.2 CSeq: 103 INVITE User-Agent: Asterisk PBX 1.6.0.13 Proxy-Authorization: Digest username="036203200", realm="sip-priv.amis.net", algorithm=MD5, uri="sip:026208309@10.22.11.20", nonce="008d33201ac9dbf0619afd3b13eb9686", response="4411a1145cf9156224446af00c28440a", opaque="008b66360984230" Date: Tue, 18 Aug 2009 13:55:06 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces, timer X-route_name: X-srcuid: 1250603706.67 Content-Type: application/sdp Content-Length: 226 v=0 o=root 475840445 475840446 IN IP4 10.61.16.2 s=Asterisk PBX 1.6.0.13 c=IN IP4 10.61.16.2 t=0 0 m=audio 10098 RTP/AVP 8 0 a=rtpmap:8 PCMA/8000 a=rtpmap:0 PCMU/8000 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv --- [Aug 18 15:55:06] DEBUG[19084] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #18554 [Aug 18 15:55:06] DEBUG[19084] chan_sip.c: Trying to put 'INVITE sip' onto UDP socket destined for 10.22.11.20:5060 [Aug 18 15:55:06] VERBOSE[19084] logger.c: <--- SIP read from UDP://10.22.11.20:5060 ---> SIP/2.0 100 Trying Allow: UPDATE,INFO,REFER,INVITE,ACK,OPTIONS,REGISTER,SUBSCRIBE,MESSAGE,NOTIFY,BYE,CANCEL,PRACK Call-ID: 0f1e533008905417497809f127add60f@10.61.16.2 Contact: CSeq: 103 INVITE From: "Kocbek Milos" ;tag=as09d56ebc Server: Cirpack/v4.42d (gw_sip) To: Via: SIP/2.0/UDP 10.61.16.2:5060;received=10.61.16.2;rport=5060;branch=z9hG4bK1255b43d Content-Length: 0 <-------------> [Aug 18 15:55:06] DEBUG[19084] chan_sip.c: Header 0 [ 18]: SIP/2.0 100 Trying [Aug 18 15:55:06] DEBUG[19084] chan_sip.c: Header 1 [ 94]: Allow: UPDATE,INFO,REFER,INVITE,ACK,OPTIONS,REGISTER,SUBSCRIBE,MESSAGE,NOTIFY,BYE,CANCEL,PRACK [Aug 18 15:55:06] DEBUG[19084] chan_sip.c: Header 2 [ 52]: Call-ID: 0f1e533008905417497809f127add60f@10.61.16.2 [Aug 18 15:55:06] DEBUG[19084] chan_sip.c: Header 3 [ 31]: Contact: [Aug 18 15:55:06] DEBUG[19084] chan_sip.c: Header 4 [ 16]: CSeq: 103 INVITE [Aug 18 15:55:06] DEBUG[19084] chan_sip.c: Header 5 [ 62]: From: "Kocbek Milos" ;tag=as09d56ebc [Aug 18 15:55:06] DEBUG[19084] chan_sip.c: Header 6 [ 31]: Server: Cirpack/v4.42d (gw_sip) [Aug 18 15:55:06] DEBUG[19084] chan_sip.c: Header 7 [ 31]: To: [Aug 18 15:55:06] DEBUG[19084] chan_sip.c: Header 8 [ 86]: Via: SIP/2.0/UDP 10.61.16.2:5060;received=10.61.16.2;rport=5060;branch=z9hG4bK1255b43d [Aug 18 15:55:06] DEBUG[19084] chan_sip.c: Header 9 [ 17]: Content-Length: 0 [Aug 18 15:55:06] DEBUG[19084] chan_sip.c: Header 10 [ 0]: [Aug 18 15:55:06] VERBOSE[19084] logger.c: --- (10 headers 0 lines) --- [Aug 18 15:55:06] DEBUG[19084] chan_sip.c: = Found Their Call ID: 0f1e533008905417497809f127add60f@10.61.16.2 Their Tag Our tag: as09d56ebc [Aug 18 15:55:06] DEBUG[19084] chan_sip.c: *** SIP TIMER: Cancelling retransmission #18554 - INVITE (got response) [Aug 18 15:55:06] DEBUG[19084] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '0f1e533008905417497809f127add60f@10.61.16.2' Request 103: Found [Aug 18 15:55:06] DEBUG[19084] chan_sip.c: SIP response 100 to standard invite [Aug 18 15:55:06] DEBUG[19084] chan_sip.c: SIP TIMER: Not rescheduling id #18546:OPTIONS (Method 3) (No timer T1) [Aug 18 15:55:06] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 213.249.97.123:5060 [Aug 18 15:55:06] DEBUG[19084] chan_sip.c: SIP TIMER: Not rescheduling id #18480:OPTIONS (Method 3) (No timer T1) [Aug 18 15:55:06] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 81.189.215.197:5060 [Aug 18 15:55:06] DEBUG[19084] chan_sip.c: Destroying SIP dialog 0545bad2141bb7602a0cdfaa650c61ef@213.157.229.45 [Aug 18 15:55:06] DEBUG[19084] devicestate.c: Notification of state change to be queued on device/channel SIP/voipy-glcr-156-peer [Aug 18 15:55:06] DEBUG[19067] devicestate.c: No provider found, checking channel drivers for SIP - voipy-glcr-156-peer [Aug 18 15:55:06] DEBUG[19067] chan_sip.c: Checking device state for peer voipy-glcr-156-peer [Aug 18 15:55:06] DEBUG[19067] devicestate.c: Changing state for SIP/voipy-glcr-156-peer - state 5 (Unavailable) [Aug 18 15:55:06] DEBUG[19083] app_queue.c: Device 'SIP/voipy-glcr-156-peer' changed to state '5' (Unavailable) but we don't care because they're not a member of any queue. [Aug 18 15:55:07] VERBOSE[19084] logger.c: <--- SIP read from UDP://10.22.11.20:5060 ---> SIP/2.0 180 Ringing Allow: UPDATE,INFO,REFER,INVITE,ACK,OPTIONS,REGISTER,SUBSCRIBE,MESSAGE,NOTIFY,BYE,CANCEL,PRACK Call-ID: 0f1e533008905417497809f127add60f@10.61.16.2 Contact: Content-Type: application/sdp CSeq: 103 INVITE From: "Kocbek Milos" ;tag=as09d56ebc Server: Cirpack/v4.42d (gw_sip) To: ;tag=02-08067-008d3349-65e715141 Via: SIP/2.0/UDP 10.61.16.2:5060;received=10.61.16.2;rport=5060;branch=z9hG4bK1255b43d Content-Length: 207 v=0 o=cp10 125060370729 125060370731 IN IP4 10.22.12.21 s=SIP Call c=IN IP4 10.22.12.21 t=0 0 m=audio 31518 RTP/AVP 8 0 b=AS:64 a=rtpmap:8 PCMA/8000/1 a=rtpmap:0 PCMU/8000/1 a=ptime:20 a=sendrecv <-------------> [Aug 18 15:55:07] DEBUG[19084] chan_sip.c: Header 0 [ 19]: SIP/2.0 180 Ringing [Aug 18 15:55:07] DEBUG[19084] chan_sip.c: Header 1 [ 94]: Allow: UPDATE,INFO,REFER,INVITE,ACK,OPTIONS,REGISTER,SUBSCRIBE,MESSAGE,NOTIFY,BYE,CANCEL,PRACK [Aug 18 15:55:07] DEBUG[19084] chan_sip.c: Header 2 [ 52]: Call-ID: 0f1e533008905417497809f127add60f@10.61.16.2 [Aug 18 15:55:07] DEBUG[19084] chan_sip.c: Header 3 [ 31]: Contact: [Aug 18 15:55:07] DEBUG[19084] chan_sip.c: Header 4 [ 29]: Content-Type: application/sdp [Aug 18 15:55:07] DEBUG[19084] chan_sip.c: Header 5 [ 16]: CSeq: 103 INVITE [Aug 18 15:55:07] DEBUG[19084] chan_sip.c: Header 6 [ 62]: From: "Kocbek Milos" ;tag=as09d56ebc [Aug 18 15:55:07] DEBUG[19084] chan_sip.c: Header 7 [ 31]: Server: Cirpack/v4.42d (gw_sip) [Aug 18 15:55:07] DEBUG[19084] chan_sip.c: Header 8 [ 63]: To: ;tag=02-08067-008d3349-65e715141 [Aug 18 15:55:07] DEBUG[19084] chan_sip.c: Header 9 [ 86]: Via: SIP/2.0/UDP 10.61.16.2:5060;received=10.61.16.2;rport=5060;branch=z9hG4bK1255b43d [Aug 18 15:55:07] DEBUG[19084] chan_sip.c: Header 10 [ 19]: Content-Length: 207 [Aug 18 15:55:07] DEBUG[19084] chan_sip.c: Header 11 [ 0]: [Aug 18 15:55:07] DEBUG[19084] chan_sip.c: Body 0 [ 3]: v=0 [Aug 18 15:55:07] DEBUG[19084] chan_sip.c: Body 1 [ 51]: o=cp10 125060370729 125060370731 IN IP4 10.22.12.21 [Aug 18 15:55:07] DEBUG[19084] chan_sip.c: Body 2 [ 10]: s=SIP Call [Aug 18 15:55:07] DEBUG[19084] chan_sip.c: Body 3 [ 20]: c=IN IP4 10.22.12.21 [Aug 18 15:55:07] DEBUG[19084] chan_sip.c: Body 4 [ 5]: t=0 0 [Aug 18 15:55:07] DEBUG[19084] chan_sip.c: Body 5 [ 25]: m=audio 31518 RTP/AVP 8 0 [Aug 18 15:55:07] DEBUG[19084] chan_sip.c: Body 6 [ 7]: b=AS:64 [Aug 18 15:55:07] DEBUG[19084] chan_sip.c: Body 7 [ 22]: a=rtpmap:8 PCMA/8000/1 [Aug 18 15:55:07] DEBUG[19084] chan_sip.c: Body 8 [ 22]: a=rtpmap:0 PCMU/8000/1 [Aug 18 15:55:07] DEBUG[19084] chan_sip.c: Body 9 [ 10]: a=ptime:20 [Aug 18 15:55:07] DEBUG[19084] chan_sip.c: Body 10 [ 10]: a=sendrecv [Aug 18 15:55:07] VERBOSE[19084] logger.c: --- (11 headers 11 lines) --- [Aug 18 15:55:07] DEBUG[19084] chan_sip.c: = Found Their Call ID: 0f1e533008905417497809f127add60f@10.61.16.2 Their Tag Our tag: as09d56ebc [Aug 18 15:55:07] DEBUG[19084] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '0f1e533008905417497809f127add60f@10.61.16.2' Request 103: Found [Aug 18 15:55:07] DEBUG[19084] chan_sip.c: SIP response 180 to standard invite [Aug 18 15:55:07] DEBUG[19084] devicestate.c: Notification of state change to be queued on device/channel SIP/VOIP_AMIS-peer [Aug 18 15:55:07] VERBOSE[19084] logger.c: Found RTP audio format 8 [Aug 18 15:55:07] VERBOSE[19084] logger.c: Found RTP audio format 0 [Aug 18 15:55:07] VERBOSE[19084] logger.c: Peer audio RTP is at port 10.22.12.21:31518 [Aug 18 15:55:07] VERBOSE[19084] logger.c: Found audio description format PCMA for ID 8 [Aug 18 15:55:07] VERBOSE[19084] logger.c: Found audio description format PCMU for ID 0 [Aug 18 15:55:07] VERBOSE[19084] logger.c: Capabilities: us - 0xc (ulaw|alaw), peer - audio=0xc (ulaw|alaw)/video=0x0 (nothing)/text=0x0 (nothing), combined - 0xc (ulaw|alaw) [Aug 18 15:55:07] VERBOSE[19084] logger.c: Non-codec capabilities (dtmf): us - 0x0 (nothing), peer - 0x0 (nothing), combined - 0x0 (nothing) [Aug 18 15:55:07] VERBOSE[19084] logger.c: Peer audio RTP is at port 10.22.12.21:31518 [Aug 18 15:55:07] DEBUG[19084] chan_sip.c: We're settling with these formats: 0xc (ulaw|alaw) [Aug 18 15:55:07] DEBUG[19084] chan_sip.c: We have an owner, now see if we need to change this call [Aug 18 15:55:07] DEBUG[19067] devicestate.c: No provider found, checking channel drivers for SIP - VOIP_AMIS-peer [Aug 18 15:55:07] DEBUG[19067] chan_sip.c: Checking device state for peer VOIP_AMIS-peer [Aug 18 15:55:07] DEBUG[19067] devicestate.c: Changing state for SIP/VOIP_AMIS-peer - state 1 (Not in use) [Aug 18 15:55:07] DEBUG[19083] app_queue.c: Device 'SIP/VOIP_AMIS-peer' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Aug 18 15:55:07] VERBOSE[19793] logger.c: -- SIP/VOIP_AMIS-peer-082c0d28 is ringing [Aug 18 15:55:07] DEBUG[19793] chan_sip.c: Trying to put 'SIP/2.0 18' onto UDP socket destined for 91.199.174.215:5060 [Aug 18 15:55:07] VERBOSE[19793] logger.c: -- SIP/VOIP_AMIS-peer-082c0d28 is making progress passing it to SIP/91.199.174.215-082ab508 [Aug 18 15:55:07] DEBUG[19793] chan_sip.c: Setting framing from config on incoming call [Aug 18 15:55:07] DEBUG[19793] chan_sip.c: ** Our capability: 0xc (ulaw|alaw) Video flag: True Text flag: True [Aug 18 15:55:07] DEBUG[19793] chan_sip.c: ** Our prefcodec: 0x0 (nothing) [Aug 18 15:55:07] DEBUG[19793] chan_sip.c: -- Done with adding codecs to SDP [Aug 18 15:55:07] DEBUG[19793] channel.c: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1) [Aug 18 15:55:07] DEBUG[19793] chan_sip.c: Done building SDP. Settling with this capability: 0xc (ulaw|alaw) [Aug 18 15:55:07] DEBUG[19793] chan_sip.c: Trying to put 'SIP/2.0 18' onto UDP socket destined for 91.199.174.215:5060 [Aug 18 15:55:07] DEBUG[19793] rtp.c: Ooh, format changed from unknown to alaw [Aug 18 15:55:07] DEBUG[19793] rtp.c: Created smoother: format: 8 ms: 20 len: 160 [Aug 18 15:55:07] DEBUG[19084] chan_sip.c: SIP TIMER: Not rescheduling id #18494:OPTIONS (Method 3) (No timer T1) [Aug 18 15:55:07] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 212.18.43.58:5060 [Aug 18 15:55:07] DEBUG[19084] chan_sip.c: Destroying SIP dialog 4207f9c8346b2a966a582d0c1bbff238@213.157.229.45 [Aug 18 15:55:07] DEBUG[19084] devicestate.c: Notification of state change to be queued on device/channel SIP/voipy-glcr-277-peer [Aug 18 15:55:07] DEBUG[19067] devicestate.c: No provider found, checking channel drivers for SIP - voipy-glcr-277-peer [Aug 18 15:55:07] DEBUG[19067] chan_sip.c: Checking device state for peer voipy-glcr-277-peer [Aug 18 15:55:07] DEBUG[19067] devicestate.c: Changing state for SIP/voipy-glcr-277-peer - state 5 (Unavailable) [Aug 18 15:55:07] DEBUG[19083] app_queue.c: Device 'SIP/voipy-glcr-277-peer' changed to state '5' (Unavailable) but we don't care because they're not a member of any queue. [Aug 18 15:55:07] DEBUG[19084] chan_sip.c: SIP TIMER: Not rescheduling id #18508:OPTIONS (Method 3) (No timer T1) [Aug 18 15:55:07] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 85.10.37.148:5060 [Aug 18 15:55:07] DEBUG[19084] chan_sip.c: Destroying SIP dialog 22530602135bd4f92ebcfb4b09af116d@213.157.229.45 [Aug 18 15:55:07] DEBUG[19084] devicestate.c: Notification of state change to be queued on device/channel SIP/voipy-glcr-334-peer [Aug 18 15:55:07] DEBUG[19067] devicestate.c: No provider found, checking channel drivers for SIP - voipy-glcr-334-peer [Aug 18 15:55:07] DEBUG[19067] chan_sip.c: Checking device state for peer voipy-glcr-334-peer [Aug 18 15:55:07] DEBUG[19067] devicestate.c: Changing state for SIP/voipy-glcr-334-peer - state 5 (Unavailable) [Aug 18 15:55:07] DEBUG[19083] app_queue.c: Device 'SIP/voipy-glcr-334-peer' changed to state '5' (Unavailable) but we don't care because they're not a member of any queue. [Aug 18 15:55:07] DEBUG[19084] chan_sip.c: Header 0 [ 0]: [Aug 18 15:55:07] DEBUG[19084] chan_sip.c: SIP TIMER: Not rescheduling id #18546:OPTIONS (Method 3) (No timer T1) [Aug 18 15:55:07] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 213.249.97.123:5060 [Aug 18 15:55:07] DEBUG[19793] rtp.c: Ooh, format changed from unknown to alaw [Aug 18 15:55:07] DEBUG[19793] rtp.c: Created smoother: format: 8 ms: 20 len: 160 [Aug 18 15:55:08] DEBUG[19080] devicestate.c: Notification of state change to be queued on device/channel IAX2/999 [Aug 18 15:55:08] DEBUG[19067] devicestate.c: No provider found, checking channel drivers for IAX2 - 999 [Aug 18 15:55:08] DEBUG[19067] chan_iax2.c: Checking device state for device 999 [Aug 18 15:55:08] DEBUG[19067] chan_iax2.c: iax2_devicestate: Found peer. What's device state of 999? addr=1689175899, defaddr=0 maxms=0, lastms=0 [Aug 18 15:55:08] DEBUG[19067] devicestate.c: Changing state for IAX2/999 - state 1 (Not in use) [Aug 18 15:55:08] DEBUG[19083] app_queue.c: Device 'IAX2/999' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Aug 18 15:55:08] DEBUG[19077] devicestate.c: Notification of state change to be queued on device/channel IAX2/999 [Aug 18 15:55:08] DEBUG[19067] devicestate.c: No provider found, checking channel drivers for IAX2 - 999 [Aug 18 15:55:08] DEBUG[19067] chan_iax2.c: Checking device state for device 999 [Aug 18 15:55:08] DEBUG[19067] chan_iax2.c: iax2_devicestate: Found peer. What's device state of 999? addr=1689175899, defaddr=0 maxms=0, lastms=0 [Aug 18 15:55:08] DEBUG[19067] devicestate.c: Changing state for IAX2/999 - state 1 (Not in use) [Aug 18 15:55:08] DEBUG[19083] app_queue.c: Device 'IAX2/999' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Aug 18 15:55:08] DEBUG[19084] chan_sip.c: SIP TIMER: Not rescheduling id #18546:OPTIONS (Method 3) (No timer T1) [Aug 18 15:55:08] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 213.249.97.123:5060 [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP) [Aug 18 15:55:09] DEBUG[19084] acl.c: Found IP address for this socket [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Initializing initreq for method OPTIONS - callid 32a3597f13d1a953137231725d58ad18@10.255.255.1 [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Header 0 [ 56]: OPTIONS sip:122@10.255.255.95:2048;line=v30zzxav SIP/2.0 [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Header 1 [ 63]: Via: SIP/2.0/UDP 10.255.255.1:5060;branch=z9hG4bK53e1d3d7;rport [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Header 3 [ 57]: From: "Unknown" ;tag=as32148791 [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Header 4 [ 46]: To: [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Header 5 [ 35]: Contact: [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Header 6 [ 54]: Call-ID: 32a3597f13d1a953137231725d58ad18@10.255.255.1 [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Header 7 [ 17]: CSeq: 102 OPTIONS [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Header 8 [ 33]: User-Agent: Asterisk PBX 1.6.0.13 [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Header 9 [ 35]: Date: Tue, 18 Aug 2009 13:55:09 GMT [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Header 10 [ 66]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Header 12 [ 17]: Content-Length: 0 [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #18560 [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 10.255.255.95:2048 [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Header 1 [ 68]: Via: SIP/2.0/UDP 10.255.255.1:5060;branch=z9hG4bK53e1d3d7;rport=5060 [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Header 2 [ 57]: From: "Unknown" ;tag=as32148791 [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Header 3 [ 46]: To: [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Header 4 [ 54]: Call-ID: 32a3597f13d1a953137231725d58ad18@10.255.255.1 [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Header 5 [ 17]: CSeq: 102 OPTIONS [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Header 6 [ 61]: Contact: ;flow-id=1 [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Header 7 [ 26]: User-Agent: snom320/7.1.30 [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Header 8 [ 19]: Accept-Language: en [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Header 9 [ 23]: Accept: application/sdp [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Header 10 [ 88]: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Header 11 [ 42]: Allow-Events: talk, hold, refer, call-info [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Header 12 [ 44]: Supported: timer, 100rel, replaces, callerid [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Header 13 [ 17]: Content-Length: 0 [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Header 14 [ 0]: [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: = Found Their Call ID: 32a3597f13d1a953137231725d58ad18@10.255.255.1 Their Tag Our tag: as32148791 [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #18560 [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Stopping retransmission on '32a3597f13d1a953137231725d58ad18@10.255.255.1' of Request 102: Match Found [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP) [Aug 18 15:55:09] DEBUG[19084] acl.c: Found IP address for this socket [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Initializing initreq for method OPTIONS - callid 559adba03b8e632e27d6260e07fb5172@10.255.255.1 [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Header 0 [ 56]: OPTIONS sip:226@10.255.255.26:2048;line=m0hqtxwt SIP/2.0 [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Header 1 [ 63]: Via: SIP/2.0/UDP 10.255.255.1:5060;branch=z9hG4bK28c6b618;rport [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Header 3 [ 57]: From: "Unknown" ;tag=as6acb7043 [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Header 4 [ 46]: To: [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Header 5 [ 35]: Contact: [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Header 6 [ 54]: Call-ID: 559adba03b8e632e27d6260e07fb5172@10.255.255.1 [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Header 7 [ 17]: CSeq: 102 OPTIONS [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Header 8 [ 33]: User-Agent: Asterisk PBX 1.6.0.13 [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Header 9 [ 35]: Date: Tue, 18 Aug 2009 13:55:09 GMT [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Header 10 [ 66]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Header 12 [ 17]: Content-Length: 0 [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #18563 [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 10.255.255.26:2048 [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Header 1 [ 68]: Via: SIP/2.0/UDP 10.255.255.1:5060;branch=z9hG4bK28c6b618;rport=5060 [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Header 2 [ 57]: From: "Unknown" ;tag=as6acb7043 [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Header 3 [ 46]: To: [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Header 4 [ 54]: Call-ID: 559adba03b8e632e27d6260e07fb5172@10.255.255.1 [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Header 5 [ 17]: CSeq: 102 OPTIONS [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Header 6 [ 61]: Contact: ;flow-id=1 [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Header 7 [ 26]: User-Agent: snom300/7.1.30 [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Header 8 [ 19]: Accept-Language: en [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Header 9 [ 23]: Accept: application/sdp [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Header 10 [ 88]: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Header 11 [ 42]: Allow-Events: talk, hold, refer, call-info [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Header 12 [ 44]: Supported: timer, 100rel, replaces, callerid [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Header 13 [ 17]: Content-Length: 0 [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Header 14 [ 0]: [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: = Found Their Call ID: 559adba03b8e632e27d6260e07fb5172@10.255.255.1 Their Tag Our tag: as6acb7043 [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #18563 [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Stopping retransmission on '559adba03b8e632e27d6260e07fb5172@10.255.255.1' of Request 102: Match Found [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Header 0 [ 0]: [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Body 0 [ 0]: [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP) [Aug 18 15:55:09] DEBUG[19084] acl.c: Found IP address for this socket [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Initializing initreq for method OPTIONS - callid 61d366351941ce8a1bee60fa1e9d9806@10.255.255.1 [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Header 0 [ 56]: OPTIONS sip:227@10.255.255.26:2048;line=j8uvnjje SIP/2.0 [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Header 1 [ 63]: Via: SIP/2.0/UDP 10.255.255.1:5060;branch=z9hG4bK54fc046b;rport [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Header 3 [ 57]: From: "Unknown" ;tag=as7bc0db44 [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Header 4 [ 46]: To: [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Header 5 [ 35]: Contact: [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Header 6 [ 54]: Call-ID: 61d366351941ce8a1bee60fa1e9d9806@10.255.255.1 [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Header 7 [ 17]: CSeq: 102 OPTIONS [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Header 8 [ 33]: User-Agent: Asterisk PBX 1.6.0.13 [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Header 9 [ 35]: Date: Tue, 18 Aug 2009 13:55:09 GMT [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Header 10 [ 66]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Header 12 [ 17]: Content-Length: 0 [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #18566 [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 10.255.255.26:2048 [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Header 1 [ 68]: Via: SIP/2.0/UDP 10.255.255.1:5060;branch=z9hG4bK54fc046b;rport=5060 [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Header 2 [ 57]: From: "Unknown" ;tag=as7bc0db44 [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Header 3 [ 46]: To: [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Header 4 [ 54]: Call-ID: 61d366351941ce8a1bee60fa1e9d9806@10.255.255.1 [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Header 5 [ 17]: CSeq: 102 OPTIONS [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Header 6 [ 61]: Contact: ;flow-id=1 [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Header 7 [ 26]: User-Agent: snom300/7.1.30 [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Header 8 [ 19]: Accept-Language: en [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Header 9 [ 23]: Accept: application/sdp [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Header 10 [ 88]: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Header 11 [ 42]: Allow-Events: talk, hold, refer, call-info [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Header 12 [ 44]: Supported: timer, 100rel, replaces, callerid [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Header 13 [ 17]: Content-Length: 0 [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Header 14 [ 0]: [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: = Found Their Call ID: 61d366351941ce8a1bee60fa1e9d9806@10.255.255.1 Their Tag Our tag: as7bc0db44 [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #18566 [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Stopping retransmission on '61d366351941ce8a1bee60fa1e9d9806@10.255.255.1' of Request 102: Match Found [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: SIP TIMER: Not rescheduling id #18546:OPTIONS (Method 3) (No timer T1) [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 213.249.97.123:5060 [Aug 18 15:55:09] DEBUG[19084] chan_sip.c: Destroying SIP dialog 63366ee936983c3c7b2e432f0c534b83@213.157.229.45 [Aug 18 15:55:09] DEBUG[19084] devicestate.c: Notification of state change to be queued on device/channel SIP/VOIP_TRAFFX-peer [Aug 18 15:55:09] DEBUG[19067] devicestate.c: No provider found, checking channel drivers for SIP - VOIP_TRAFFX-peer [Aug 18 15:55:09] DEBUG[19067] chan_sip.c: Checking device state for peer VOIP_TRAFFX-peer [Aug 18 15:55:09] DEBUG[19067] devicestate.c: Changing state for SIP/VOIP_TRAFFX-peer - state 5 (Unavailable) [Aug 18 15:55:09] DEBUG[19083] app_queue.c: Device 'SIP/VOIP_TRAFFX-peer' changed to state '5' (Unavailable) but we don't care because they're not a member of any queue. [Aug 18 15:55:11] VERBOSE[19084] logger.c: <--- SIP read from UDP://10.22.11.20:5060 ---> SIP/2.0 183 Media change Allow: UPDATE,INFO,REFER,INVITE,ACK,OPTIONS,REGISTER,SUBSCRIBE,MESSAGE,NOTIFY,BYE,CANCEL,PRACK Call-ID: 0f1e533008905417497809f127add60f@10.61.16.2 Contact: Content-Type: application/sdp CSeq: 103 INVITE From: "Kocbek Milos" ;tag=as09d56ebc Server: Cirpack/v4.42d (gw_sip) To: ;tag=02-08067-008d3349-65e715141 Via: SIP/2.0/UDP 10.61.16.2:5060;received=10.61.16.2;rport=5060;branch=z9hG4bK1255b43d Content-Length: 207 v=0 o=cp10 125060370729 125060370732 IN IP4 10.22.12.32 s=SIP Call c=IN IP4 10.22.12.32 t=0 0 m=audio 32634 RTP/AVP 8 0 b=AS:64 a=rtpmap:8 PCMA/8000/1 a=rtpmap:0 PCMU/8000/1 a=ptime:20 a=sendrecv <-------------> [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 0 [ 24]: SIP/2.0 183 Media change [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 1 [ 94]: Allow: UPDATE,INFO,REFER,INVITE,ACK,OPTIONS,REGISTER,SUBSCRIBE,MESSAGE,NOTIFY,BYE,CANCEL,PRACK [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 2 [ 52]: Call-ID: 0f1e533008905417497809f127add60f@10.61.16.2 [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 3 [ 31]: Contact: [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 4 [ 29]: Content-Type: application/sdp [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 5 [ 16]: CSeq: 103 INVITE [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 6 [ 62]: From: "Kocbek Milos" ;tag=as09d56ebc [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 7 [ 31]: Server: Cirpack/v4.42d (gw_sip) [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 8 [ 63]: To: ;tag=02-08067-008d3349-65e715141 [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 9 [ 86]: Via: SIP/2.0/UDP 10.61.16.2:5060;received=10.61.16.2;rport=5060;branch=z9hG4bK1255b43d [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 10 [ 19]: Content-Length: 207 [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 11 [ 0]: [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Body 0 [ 3]: v=0 [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Body 1 [ 51]: o=cp10 125060370729 125060370732 IN IP4 10.22.12.32 [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Body 2 [ 10]: s=SIP Call [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Body 3 [ 20]: c=IN IP4 10.22.12.32 [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Body 4 [ 5]: t=0 0 [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Body 5 [ 25]: m=audio 32634 RTP/AVP 8 0 [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Body 6 [ 7]: b=AS:64 [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Body 7 [ 22]: a=rtpmap:8 PCMA/8000/1 [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Body 8 [ 22]: a=rtpmap:0 PCMU/8000/1 [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Body 9 [ 10]: a=ptime:20 [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Body 10 [ 10]: a=sendrecv [Aug 18 15:55:11] VERBOSE[19084] logger.c: --- (11 headers 11 lines) --- [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: = Found Their Call ID: 0f1e533008905417497809f127add60f@10.61.16.2 Their Tag 02-08067-008d3349-65e715141 Our tag: as09d56ebc [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '0f1e533008905417497809f127add60f@10.61.16.2' Request 103: Found [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: SIP response 183 to standard invite [Aug 18 15:55:11] VERBOSE[19084] logger.c: Found RTP audio format 8 [Aug 18 15:55:11] VERBOSE[19084] logger.c: Found RTP audio format 0 [Aug 18 15:55:11] VERBOSE[19084] logger.c: Peer audio RTP is at port 10.22.12.32:32634 [Aug 18 15:55:11] VERBOSE[19084] logger.c: Found audio description format PCMA for ID 8 [Aug 18 15:55:11] VERBOSE[19084] logger.c: Found audio description format PCMU for ID 0 [Aug 18 15:55:11] VERBOSE[19084] logger.c: Capabilities: us - 0xc (ulaw|alaw), peer - audio=0xc (ulaw|alaw)/video=0x0 (nothing)/text=0x0 (nothing), combined - 0xc (ulaw|alaw) [Aug 18 15:55:11] VERBOSE[19084] logger.c: Non-codec capabilities (dtmf): us - 0x0 (nothing), peer - 0x0 (nothing), combined - 0x0 (nothing) [Aug 18 15:55:11] VERBOSE[19084] logger.c: Peer audio RTP is at port 10.22.12.32:32634 [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: We're settling with these formats: 0xc (ulaw|alaw) [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: We have an owner, now see if we need to change this call [Aug 18 15:55:11] VERBOSE[19793] logger.c: -- SIP/VOIP_AMIS-peer-082c0d28 is making progress passing it to SIP/91.199.174.215-082ab508 [Aug 18 15:55:11] VERBOSE[19084] logger.c: <--- SIP read from UDP://10.22.11.20:5060 ---> SIP/2.0 200 OK Allow: UPDATE,INFO,REFER,INVITE,ACK,OPTIONS,REGISTER,SUBSCRIBE,MESSAGE,NOTIFY,BYE,CANCEL,PRACK Call-ID: 0f1e533008905417497809f127add60f@10.61.16.2 Contact: Content-Type: application/sdp CSeq: 103 INVITE From: "Kocbek Milos" ;tag=as09d56ebc Server: Cirpack/v4.42d (gw_sip) To: ;tag=02-08067-008d3349-65e715141 Via: SIP/2.0/UDP 10.61.16.2:5060;received=10.61.16.2;rport=5060;branch=z9hG4bK1255b43d Content-Length: 207 v=0 o=cp10 125060370729 125060370732 IN IP4 10.22.12.32 s=SIP Call c=IN IP4 10.22.12.32 t=0 0 m=audio 32634 RTP/AVP 8 0 b=AS:64 a=rtpmap:8 PCMA/8000/1 a=rtpmap:0 PCMU/8000/1 a=ptime:20 a=sendrecv <-------------> [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 1 [ 94]: Allow: UPDATE,INFO,REFER,INVITE,ACK,OPTIONS,REGISTER,SUBSCRIBE,MESSAGE,NOTIFY,BYE,CANCEL,PRACK [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 2 [ 52]: Call-ID: 0f1e533008905417497809f127add60f@10.61.16.2 [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 3 [ 31]: Contact: [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 4 [ 29]: Content-Type: application/sdp [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 5 [ 16]: CSeq: 103 INVITE [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 6 [ 62]: From: "Kocbek Milos" ;tag=as09d56ebc [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 7 [ 31]: Server: Cirpack/v4.42d (gw_sip) [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 8 [ 63]: To: ;tag=02-08067-008d3349-65e715141 [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 9 [ 86]: Via: SIP/2.0/UDP 10.61.16.2:5060;received=10.61.16.2;rport=5060;branch=z9hG4bK1255b43d [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 10 [ 19]: Content-Length: 207 [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 11 [ 0]: [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Body 0 [ 3]: v=0 [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Body 1 [ 51]: o=cp10 125060370729 125060370732 IN IP4 10.22.12.32 [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Body 2 [ 10]: s=SIP Call [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Body 3 [ 20]: c=IN IP4 10.22.12.32 [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Body 4 [ 5]: t=0 0 [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Body 5 [ 25]: m=audio 32634 RTP/AVP 8 0 [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Body 6 [ 7]: b=AS:64 [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Body 7 [ 22]: a=rtpmap:8 PCMA/8000/1 [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Body 8 [ 22]: a=rtpmap:0 PCMU/8000/1 [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Body 9 [ 10]: a=ptime:20 [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Body 10 [ 10]: a=sendrecv [Aug 18 15:55:11] VERBOSE[19084] logger.c: --- (11 headers 11 lines) --- [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: = Found Their Call ID: 0f1e533008905417497809f127add60f@10.61.16.2 Their Tag 02-08067-008d3349-65e715141 Our tag: as09d56ebc [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Acked pending invite 103 [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Stopping retransmission on '0f1e533008905417497809f127add60f@10.61.16.2' of Request 103: Match Found [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: SIP response 200 to standard invite [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: SDP version number same as previous SDP [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Updating call counter for outgoing call [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: build_route: Contact hop: [Aug 18 15:55:11] VERBOSE[19084] logger.c: list_route: hop: [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Strict routing enforced for session 0f1e533008905417497809f127add60f@10.61.16.2 [Aug 18 15:55:11] VERBOSE[19084] logger.c: set_destination: Parsing for address/port to send to [Aug 18 15:55:11] VERBOSE[19084] logger.c: set_destination: set destination to 10.22.11.20, port 5060 [Aug 18 15:55:11] VERBOSE[19084] logger.c: Transmitting (no NAT) to 10.22.11.20:5060: ACK sip:10.22.11.20:5060 SIP/2.0 Via: SIP/2.0/UDP 10.61.16.2:5060;branch=z9hG4bK42615417;rport Max-Forwards: 70 From: "Kocbek Milos" ;tag=as09d56ebc To: ;tag=02-08067-008d3349-65e715141 Contact: Call-ID: 0f1e533008905417497809f127add60f@10.61.16.2 CSeq: 103 ACK User-Agent: Asterisk PBX 1.6.0.13 Content-Length: 0 --- [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Trying to put 'ACK sip:10' onto UDP socket destined for 10.22.11.20:5060 [Aug 18 15:55:11] VERBOSE[19084] logger.c: drugi invite <--- SIP read from UDP://10.22.11.20:5060 ---> INVITE sip:036203559@10.61.16.2 SIP/2.0 Allow: UPDATE,INFO,REFER,INVITE,ACK,OPTIONS,REGISTER,SUBSCRIBE,MESSAGE,NOTIFY,BYE,CANCEL,PRACK Call-ID: 0f1e533008905417497809f127add60f@10.61.16.2 Contact: Content-Type: application/sdp CSeq: 9026164 INVITE From: ;tag=02-08067-008d3349-65e715141 Max-Forwards: 31 To: "Kocbek Milos" ;tag=as09d56ebc User-Agent: Cirpack/v4.42d (gw_sip) Via: SIP/2.0/UDP 10.22.11.20:5060;branch=z9hG4bK-2A04-1A0733 Content-Length: 207 v=0 o=cp10 125060370729 125060370733 IN IP4 10.22.12.32 s=SIP Call c=IN IP4 10.22.12.32 t=0 0 m=audio 32634 RTP/AVP 8 0 b=AS:64 a=rtpmap:8 PCMA/8000/1 a=rtpmap:0 PCMU/8000/1 a=ptime:20 a=sendrecv <-------------> [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 0 [ 39]: INVITE sip:036203559@10.61.16.2 SIP/2.0 [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 1 [ 94]: Allow: UPDATE,INFO,REFER,INVITE,ACK,OPTIONS,REGISTER,SUBSCRIBE,MESSAGE,NOTIFY,BYE,CANCEL,PRACK [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 2 [ 52]: Call-ID: 0f1e533008905417497809f127add60f@10.61.16.2 [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 3 [ 31]: Contact: [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 4 [ 29]: Content-Type: application/sdp [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 5 [ 20]: CSeq: 9026164 INVITE [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 6 [ 65]: From: ;tag=02-08067-008d3349-65e715141 [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 7 [ 16]: Max-Forwards: 31 [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 8 [ 60]: To: "Kocbek Milos" ;tag=as09d56ebc [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 9 [ 35]: User-Agent: Cirpack/v4.42d (gw_sip) [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 10 [ 60]: Via: SIP/2.0/UDP 10.22.11.20:5060;branch=z9hG4bK-2A04-1A0733 [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 11 [ 19]: Content-Length: 207 [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 12 [ 0]: [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Body 0 [ 3]: v=0 [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Body 1 [ 51]: o=cp10 125060370729 125060370733 IN IP4 10.22.12.32 [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Body 2 [ 10]: s=SIP Call [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Body 3 [ 20]: c=IN IP4 10.22.12.32 [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Body 4 [ 5]: t=0 0 [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Body 5 [ 25]: m=audio 32634 RTP/AVP 8 0 [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Body 6 [ 7]: b=AS:64 [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Body 7 [ 22]: a=rtpmap:8 PCMA/8000/1 [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Body 8 [ 22]: a=rtpmap:0 PCMU/8000/1 [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Body 9 [ 10]: a=ptime:20 [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Body 10 [ 10]: a=sendrecv [Aug 18 15:55:11] VERBOSE[19084] logger.c: --- (12 headers 11 lines) --- [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: = Found Their Call ID: 0f1e533008905417497809f127add60f@10.61.16.2 Their Tag 02-08067-008d3349-65e715141 Our tag: as09d56ebc [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Potential spiral detected. Original RURI was sip:026208309@10.22.11.20, new RURI is sip:036203559@10.61.16.2 [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: OBPROXY: Not applying OBproxy to this call [Aug 18 15:55:11] WARNING[19084] chan_sip.c: No such host: 036203559 [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Adding SIP Header "X-route_name" with content :: [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Adding SIP Header "X-srcuid" with content :1250603706.67: [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: ** Our capability: 0xc (ulaw|alaw) Video flag: True Text flag: True [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: ** Our prefcodec: 0x8 (alaw) [Aug 18 15:55:11] VERBOSE[19084] logger.c: Audio is at 10.61.16.2 port 10098 [Aug 18 15:55:11] VERBOSE[19084] logger.c: Adding codec 0x8 (alaw) to SDP [Aug 18 15:55:11] VERBOSE[19084] logger.c: Adding codec 0x4 (ulaw) to SDP [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: -- Done with adding codecs to SDP [Aug 18 15:55:11] DEBUG[19084] channel.c: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1) [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Done building SDP. Settling with this capability: 0xc (ulaw|alaw) [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Initializing already initialized SIP dialog 0f1e533008905417497809f127add60f@10.61.16.2 (presumably reinvite) [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 0 [ 35]: INVITE sip:10.22.11.20:5060 SIP/2.0 [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 1 [ 61]: Via: SIP/2.0/UDP 10.61.16.2:5060;branch=z9hG4bK6db96123;rport [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 3 [ 62]: From: "Kocbek Milos" ;tag=as09d56ebc [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 4 [ 26]: To: [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 5 [ 35]: Contact: [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 6 [ 52]: Call-ID: 0f1e533008905417497809f127add60f@10.61.16.2 [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 7 [ 16]: CSeq: 104 INVITE [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 8 [ 33]: User-Agent: Asterisk PBX 1.6.0.13 [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 9 [ 21]: Proxy-Authorization: [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 10 [ 35]: Date: Tue, 18 Aug 2009 13:55:11 GMT [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 11 [ 66]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 12 [ 26]: Supported: replaces, timer [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 13 [ 14]: X-route_name: [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 14 [ 23]: X-srcuid: 1250603706.67 [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 15 [ 29]: Content-Type: application/sdp [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 16 [ 19]: Content-Length: 226 [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 17 [ 0]: [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Body 0 [ 3]: v=0 [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Body 1 [ 44]: o=root 475840445 475840447 IN IP4 10.61.16.2 [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Body 2 [ 23]: s=Asterisk PBX 1.6.0.13 [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Body 3 [ 19]: c=IN IP4 10.61.16.2 [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Body 4 [ 5]: t=0 0 [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Body 5 [ 25]: m=audio 10098 RTP/AVP 8 0 [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Body 6 [ 20]: a=rtpmap:8 PCMA/8000 [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Body 7 [ 20]: a=rtpmap:0 PCMU/8000 [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Body 8 [ 25]: a=silenceSupp:off - - - - [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Body 9 [ 10]: a=ptime:20 [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Body 10 [ 10]: a=sendrecv [Aug 18 15:55:11] VERBOSE[19084] logger.c: Reliably Transmitting (no NAT) to 10.22.11.20:5060: INVITE sip:10.22.11.20:5060 SIP/2.0 Via: SIP/2.0/UDP 10.61.16.2:5060;branch=z9hG4bK6db96123;rport Max-Forwards: 70 From: "Kocbek Milos" ;tag=as09d56ebc To: Contact: Call-ID: 0f1e533008905417497809f127add60f@10.61.16.2 CSeq: 104 INVITE User-Agent: Asterisk PBX 1.6.0.13 Proxy-Authorization: Date: Tue, 18 Aug 2009 13:55:11 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces, timer X-route_name: X-srcuid: 1250603706.67 Content-Type: application/sdp Content-Length: 226 v=0 o=root 475840445 475840447 IN IP4 10.61.16.2 s=Asterisk PBX 1.6.0.13 c=IN IP4 10.61.16.2 t=0 0 m=audio 10098 RTP/AVP 8 0 a=rtpmap:8 PCMA/8000 a=rtpmap:0 PCMU/8000 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv --- [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #18570 [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Trying to put 'INVITE sip' onto UDP socket destined for 10.22.11.20:5060 [Aug 18 15:55:11] VERBOSE[19084] logger.c: <--- SIP read from UDP://10.22.11.20:5060 ---> SIP/2.0 407 authentication required Allow: UPDATE,INFO,REFER,INVITE,ACK,OPTIONS,REGISTER,SUBSCRIBE,MESSAGE,NOTIFY,BYE,CANCEL,PRACK Call-ID: 0f1e533008905417497809f127add60f@10.61.16.2 Contact: CSeq: 104 INVITE From: "Kocbek Milos" ;tag=as09d56ebc Proxy-Authenticate: Digest realm="sip-priv.amis.net",nonce="008d33201ac9dbf0619afd3b13eb9686",opaque="008b66360984230",stale=false,algorithm=MD5 Server: Cirpack/v4.42d (gw_sip) To: ;tag=02-08127-008d3411-1c5b96ee0 Via: SIP/2.0/UDP 10.61.16.2:5060;received=10.61.16.2;rport=5060;branch=z9hG4bK6db96123 Content-Length: 0 <-------------> [Aug 18 15:55:11] DEBUG[19793] devicestate.c: Notification of state change to be queued on device/channel SIP/VOIP_AMIS-peer [Aug 18 15:55:11] DEBUG[19067] devicestate.c: No provider found, checking channel drivers for SIP - VOIP_AMIS-peer [Aug 18 15:55:11] DEBUG[19067] chan_sip.c: Checking device state for peer VOIP_AMIS-peer [Aug 18 15:55:11] DEBUG[19067] devicestate.c: Changing state for SIP/VOIP_AMIS-peer - state 1 (Not in use) [Aug 18 15:55:11] DEBUG[19083] app_queue.c: Device 'SIP/VOIP_AMIS-peer' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 0 [ 35]: SIP/2.0 407 authentication required [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 1 [ 94]: Allow: UPDATE,INFO,REFER,INVITE,ACK,OPTIONS,REGISTER,SUBSCRIBE,MESSAGE,NOTIFY,BYE,CANCEL,PRACK [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 2 [ 52]: Call-ID: 0f1e533008905417497809f127add60f@10.61.16.2 [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 3 [ 31]: Contact: [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 4 [ 16]: CSeq: 104 INVITE [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 5 [ 62]: From: "Kocbek Milos" ;tag=as09d56ebc [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 6 [144]: Proxy-Authenticate: Digest realm="sip-priv.amis.net",nonce="008d33201ac9dbf0619afd3b13eb9686",opaque="008b66360984230",stale=false,algorithm=MD5 [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 7 [ 31]: Server: Cirpack/v4.42d (gw_sip) [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 8 [ 58]: To: ;tag=02-08127-008d3411-1c5b96ee0 [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 9 [ 86]: Via: SIP/2.0/UDP 10.61.16.2:5060;received=10.61.16.2;rport=5060;branch=z9hG4bK6db96123 [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 10 [ 17]: Content-Length: 0 [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 11 [ 0]: [Aug 18 15:55:11] VERBOSE[19084] logger.c: --- (11 headers 0 lines) --- [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: = Found Their Call ID: 0f1e533008905417497809f127add60f@10.61.16.2 Their Tag Our tag: as09d56ebc [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Acked pending invite 104 [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #18570 [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Stopping retransmission on '0f1e533008905417497809f127add60f@10.61.16.2' of Request 104: Match Found [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: SIP response 407 to RE-invite on outgoing call 0f1e533008905417497809f127add60f@10.61.16.2 [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Strict routing enforced for session 0f1e533008905417497809f127add60f@10.61.16.2 [Aug 18 15:55:11] VERBOSE[19084] logger.c: set_destination: Parsing for address/port to send to [Aug 18 15:55:11] VERBOSE[19084] logger.c: set_destination: set destination to 10.22.11.20, port 5060 [Aug 18 15:55:11] VERBOSE[19084] logger.c: Transmitting (no NAT) to 10.22.11.20:5060: ACK sip:10.22.11.20:5060 SIP/2.0 Via: SIP/2.0/UDP 10.61.16.2:5060;branch=z9hG4bK6db96123;rport Max-Forwards: 70 From: "Kocbek Milos" ;tag=as09d56ebc To: ;tag=02-08127-008d3411-1c5b96ee0 Contact: Call-ID: 0f1e533008905417497809f127add60f@10.61.16.2 CSeq: 104 ACK User-Agent: Asterisk PBX 1.6.0.13 Content-Length: 0 --- [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Trying to put 'ACK sip:10' onto UDP socket destined for 10.22.11.20:5060 [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Auth attempt 1 on INVITE [Aug 18 15:55:11] VERBOSE[19793] logger.c: -- SIP/VOIP_AMIS-peer-082c0d28 answered SIP/91.199.174.215-082ab508 [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Strict routing enforced for session 0f1e533008905417497809f127add60f@10.61.16.2 [Aug 18 15:55:11] VERBOSE[19084] logger.c: set_destination: Parsing for address/port to send to [Aug 18 15:55:11] VERBOSE[19084] logger.c: set_destination: set destination to 10.22.11.20, port 5060 [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Adding SIP Header "X-route_name" with content :: [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Adding SIP Header "X-srcuid" with content :1250603706.67: [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: ** Our capability: 0xc (ulaw|alaw) Video flag: True Text flag: True [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: ** Our prefcodec: 0x8 (alaw) [Aug 18 15:55:11] VERBOSE[19084] logger.c: Audio is at 10.61.16.2 port 10098 [Aug 18 15:55:11] VERBOSE[19084] logger.c: Adding codec 0x8 (alaw) to SDP [Aug 18 15:55:11] VERBOSE[19084] logger.c: Adding codec 0x4 (ulaw) to SDP [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: -- Done with adding codecs to SDP [Aug 18 15:55:11] DEBUG[19084] channel.c: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1) [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Done building SDP. Settling with this capability: 0xc (ulaw|alaw) [Aug 18 15:55:11] VERBOSE[19084] logger.c: Reliably Transmitting (no NAT) to 10.22.11.20:5060: INVITE sip:10.22.11.20:5060 SIP/2.0 Via: SIP/2.0/UDP 10.61.16.2:5060;branch=z9hG4bK74046586;rport Max-Forwards: 70 From: "Kocbek Milos" ;tag=as09d56ebc To: Contact: Call-ID: 0f1e533008905417497809f127add60f@10.61.16.2 CSeq: 105 INVITE User-Agent: Asterisk PBX 1.6.0.13 Proxy-Authorization: Digest username="036203200", realm="sip-priv.amis.net", algorithm=MD5, uri="sip:10.22.11.20:5060", nonce="008d33201ac9dbf0619afd3b13eb9686", response="b2dfbfe9c01cfc7c7162d1a2294bec27", opaque="008b66360984230" Date: Tue, 18 Aug 2009 13:55:11 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces, timer X-route_name: X-srcuid: 1250603706.67 Content-Type: application/sdp Content-Length: 226 v=0 o=root 475840445 475840448 IN IP4 10.61.16.2 s=Asterisk PBX 1.6.0.13 c=IN IP4 10.61.16.2 t=0 0 m=audio 10098 RTP/AVP 8 0 a=rtpmap:8 PCMA/8000 a=rtpmap:0 PCMU/8000 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv --- [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #18571 [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Trying to put 'INVITE sip' onto UDP socket destined for 10.22.11.20:5060 [Aug 18 15:55:11] VERBOSE[19084] logger.c: <--- SIP read from UDP://10.22.11.20:5060 ---> SIP/2.0 100 Trying Allow: UPDATE,INFO,REFER,INVITE,ACK,OPTIONS,REGISTER,SUBSCRIBE,MESSAGE,NOTIFY,BYE,CANCEL,PRACK Call-ID: 0f1e533008905417497809f127add60f@10.61.16.2 Contact: CSeq: 105 INVITE From: "Kocbek Milos" ;tag=as09d56ebc Server: Cirpack/v4.42d (gw_sip) To: Via: SIP/2.0/UDP 10.61.16.2:5060;received=10.61.16.2;rport=5060;branch=z9hG4bK74046586 Content-Length: 0 <-------------> [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 0 [ 18]: SIP/2.0 100 Trying [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 1 [ 94]: Allow: UPDATE,INFO,REFER,INVITE,ACK,OPTIONS,REGISTER,SUBSCRIBE,MESSAGE,NOTIFY,BYE,CANCEL,PRACK [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 2 [ 52]: Call-ID: 0f1e533008905417497809f127add60f@10.61.16.2 [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 3 [ 31]: Contact: [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 4 [ 16]: CSeq: 105 INVITE [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 5 [ 62]: From: "Kocbek Milos" ;tag=as09d56ebc [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 6 [ 31]: Server: Cirpack/v4.42d (gw_sip) [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 7 [ 26]: To: [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 8 [ 86]: Via: SIP/2.0/UDP 10.61.16.2:5060;received=10.61.16.2;rport=5060;branch=z9hG4bK74046586 [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 9 [ 17]: Content-Length: 0 [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 10 [ 0]: [Aug 18 15:55:11] VERBOSE[19084] logger.c: --- (10 headers 0 lines) --- [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: = Found Their Call ID: 0f1e533008905417497809f127add60f@10.61.16.2 Their Tag Our tag: as09d56ebc [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: *** SIP TIMER: Cancelling retransmission #18571 - INVITE (got response) [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '0f1e533008905417497809f127add60f@10.61.16.2' Request 105: Found [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: SIP response 100 to RE-invite on outgoing call 0f1e533008905417497809f127add60f@10.61.16.2 [Aug 18 15:55:11] DEBUG[19793] devicestate.c: Notification of state change to be queued on device/channel SIP/91.199.174.215 [Aug 18 15:55:11] DEBUG[19067] devicestate.c: No provider found, checking channel drivers for SIP - 91.199.174.215 [Aug 18 15:55:11] DEBUG[19793] chan_sip.c: SIP answering channel: SIP/91.199.174.215-082ab508 [Aug 18 15:55:11] DEBUG[19067] chan_sip.c: Checking device state for peer 91.199.174.215 [Aug 18 15:55:11] DEBUG[19793] chan_sip.c: Setting framing from config on incoming call [Aug 18 15:55:11] DEBUG[19067] channel.c: Avoiding initial deadlock for channel '0x8490198' [Aug 18 15:55:11] DEBUG[19793] chan_sip.c: ** Our capability: 0xc (ulaw|alaw) Video flag: True Text flag: True [Aug 18 15:55:11] DEBUG[19793] chan_sip.c: ** Our prefcodec: 0x0 (nothing) [Aug 18 15:55:11] DEBUG[19793] chan_sip.c: -- Done with adding codecs to SDP [Aug 18 15:55:11] DEBUG[19793] channel.c: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1) [Aug 18 15:55:11] DEBUG[19793] chan_sip.c: Done building SDP. Settling with this capability: 0xc (ulaw|alaw) [Aug 18 15:55:11] DEBUG[19793] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #18572 [Aug 18 15:55:11] DEBUG[19793] chan_sip.c: Trying to put 'SIP/2.0 20' onto UDP socket destined for 91.199.174.215:5060 [Aug 18 15:55:11] DEBUG[19793] features.c: bridge answer set, chan answer set [Aug 18 15:55:11] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 0 [ 40]: ACK sip:026208309@213.157.229.45 SIP/2.0 [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 1 [ 65]: Via: SIP/2.0/UDP 91.199.174.215:5060;branch=z9hG4bK535a8b39;rport [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 3 [ 66]: From: "Kocbek Milos" ;tag=as4e650b76 [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 4 [ 49]: To: ;tag=as3f6ba72a [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 5 [ 39]: Contact: [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 6 [ 56]: Call-ID: 06e30dec72b7b932299f51831018adc6@91.199.174.215 [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 7 [ 13]: CSeq: 102 ACK [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 8 [ 32]: User-Agent: Asterisk PBX 1.6.0.9 [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 9 [ 17]: Content-Length: 0 [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 10 [ 0]: [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: = No match Their Call ID: 0f1e533008905417497809f127add60f@10.61.16.2 Their Tag Our tag: as09d56ebc [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: = Found Their Call ID: 06e30dec72b7b932299f51831018adc6@91.199.174.215 Their Tag as4e650b76 Our tag: as3f6ba72a [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: **** Received ACK (6) - Command in SIP ACK [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #18572 [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Stopping retransmission on '06e30dec72b7b932299f51831018adc6@91.199.174.215' of Response 102: Match Found [Aug 18 15:55:11] DEBUG[19067] devicestate.c: Changing state for SIP/91.199.174.215 - state 2 (In use) [Aug 18 15:55:11] DEBUG[19083] app_queue.c: Device 'SIP/91.199.174.215' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 0 [ 0]: [Aug 18 15:55:11] VERBOSE[19084] logger.c: <--- SIP read from UDP://10.22.11.20:5060 ---> INVITE sip:036203559@10.61.16.2 SIP/2.0 Allow: UPDATE,INFO,REFER,INVITE,ACK,OPTIONS,REGISTER,SUBSCRIBE,MESSAGE,NOTIFY,BYE,CANCEL,PRACK Call-ID: 0f1e533008905417497809f127add60f@10.61.16.2 Contact: Content-Type: application/sdp CSeq: 9026164 INVITE From: ;tag=02-08067-008d3349-65e715141 Max-Forwards: 31 To: "Kocbek Milos" ;tag=as09d56ebc User-Agent: Cirpack/v4.42d (gw_sip) Via: SIP/2.0/UDP 10.22.11.20:5060;branch=z9hG4bK-2A04-1A0733 Content-Length: 207 v=0 o=cp10 125060370729 125060370733 IN IP4 10.22.12.32 s=SIP Call c=IN IP4 10.22.12.32 t=0 0 m=audio 32634 RTP/AVP 8 0 b=AS:64 a=rtpmap:8 PCMA/8000/1 a=rtpmap:0 PCMU/8000/1 a=ptime:20 a=sendrecv <-------------> [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 0 [ 39]: INVITE sip:036203559@10.61.16.2 SIP/2.0 [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 1 [ 94]: Allow: UPDATE,INFO,REFER,INVITE,ACK,OPTIONS,REGISTER,SUBSCRIBE,MESSAGE,NOTIFY,BYE,CANCEL,PRACK [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 2 [ 52]: Call-ID: 0f1e533008905417497809f127add60f@10.61.16.2 [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 3 [ 31]: Contact: [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 4 [ 29]: Content-Type: application/sdp [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 5 [ 20]: CSeq: 9026164 INVITE [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 6 [ 65]: From: ;tag=02-08067-008d3349-65e715141 [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 7 [ 16]: Max-Forwards: 31 [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 8 [ 60]: To: "Kocbek Milos" ;tag=as09d56ebc [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 9 [ 35]: User-Agent: Cirpack/v4.42d (gw_sip) [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 10 [ 60]: Via: SIP/2.0/UDP 10.22.11.20:5060;branch=z9hG4bK-2A04-1A0733 [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 11 [ 19]: Content-Length: 207 [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Header 12 [ 0]: [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Body 0 [ 3]: v=0 [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Body 1 [ 51]: o=cp10 125060370729 125060370733 IN IP4 10.22.12.32 [Aug 18 15:55:11] DEBUG[19084] chan_sip.c: Body 2 [ 10]: s=SIP Call [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Body 3 [ 20]: c=IN IP4 10.22.12.32 [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Body 4 [ 5]: t=0 0 [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Body 5 [ 25]: m=audio 32634 RTP/AVP 8 0 [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Body 6 [ 7]: b=AS:64 [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Body 7 [ 22]: a=rtpmap:8 PCMA/8000/1 [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Body 8 [ 22]: a=rtpmap:0 PCMU/8000/1 [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Body 9 [ 10]: a=ptime:20 [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Body 10 [ 10]: a=sendrecv [Aug 18 15:55:12] VERBOSE[19084] logger.c: --- (12 headers 11 lines) --- [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: = Found Their Call ID: 0f1e533008905417497809f127add60f@10.61.16.2 Their Tag Our tag: as09d56ebc [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Ignoring SIP message because of retransmit (INVITE Seqno 9026164, ours 9026164) [Aug 18 15:55:12] VERBOSE[19084] logger.c: Ignoring this INVITE request [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Got a SIP re-transmit of INVITE for call 0f1e533008905417497809f127add60f@10.61.16.2 [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: SIP/VOIP_AMIS-peer-082c0d28: This call is UP.... [Aug 18 15:55:12] VERBOSE[19084] logger.c: <--- Transmitting (no NAT) to 10.22.11.20:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 10.22.11.20:5060;branch=z9hG4bK-2A04-1A0733;received=10.22.11.20 From: ;tag=02-08067-008d3349-65e715141 To: "Kocbek Milos" ;tag=as09d56ebc Call-ID: 0f1e533008905417497809f127add60f@10.61.16.2 CSeq: 9026164 INVITE User-Agent: Asterisk PBX 1.6.0.13 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces, timer Contact: Content-Length: 0 <------------> [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Trying to put 'SIP/2.0 10' onto UDP socket destined for 10.22.11.20:5060 [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: ** Our capability: 0xc (ulaw|alaw) Video flag: True Text flag: True [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: ** Our prefcodec: 0x8 (alaw) [Aug 18 15:55:12] VERBOSE[19084] logger.c: Audio is at 10.61.16.2 port 10098 [Aug 18 15:55:12] VERBOSE[19084] logger.c: Adding codec 0x8 (alaw) to SDP [Aug 18 15:55:12] VERBOSE[19084] logger.c: Adding codec 0x4 (ulaw) to SDP [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: -- Done with adding codecs to SDP [Aug 18 15:55:12] DEBUG[19084] channel.c: Internal timing is disabled (option_internal_timing=0 chan->timingfd=-1) [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Done building SDP. Settling with this capability: 0xc (ulaw|alaw) [Aug 18 15:55:12] VERBOSE[19084] logger.c: <--- Transmitting (no NAT) to 10.22.11.20:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 10.22.11.20:5060;branch=z9hG4bK-2A04-1A0733;received=10.22.11.20 From: ;tag=02-08067-008d3349-65e715141 To: "Kocbek Milos" ;tag=as09d56ebc Call-ID: 0f1e533008905417497809f127add60f@10.61.16.2 CSeq: 9026164 INVITE User-Agent: Asterisk PBX 1.6.0.13 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces, timer Contact: Content-Type: application/sdp Content-Length: 226 v=0 o=root 475840445 475840448 IN IP4 10.61.16.2 s=Asterisk PBX 1.6.0.13 c=IN IP4 10.61.16.2 t=0 0 m=audio 10098 RTP/AVP 8 0 a=rtpmap:8 PCMA/8000 a=rtpmap:0 PCMU/8000 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv <------------> [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Trying to put 'SIP/2.0 20' onto UDP socket destined for 10.22.11.20:5060 [Aug 18 15:55:12] VERBOSE[19084] logger.c: <--- SIP read from UDP://10.22.11.20:5060 ---> ACK sip:036203559@10.61.16.2 SIP/2.0 Call-ID: 0f1e533008905417497809f127add60f@10.61.16.2 CSeq: 9026164 ACK From: ;tag=02-08067-008d3349-65e715141 Max-Forwards: 31 To: "Kocbek Milos" ;tag=as09d56ebc User-Agent: Cirpack/v4.42d (gw_sip) Via: SIP/2.0/UDP 10.22.11.20:5060;branch=z9hG4bK-5194-1A073E Content-Length: 0 <-------------> [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 0 [ 36]: ACK sip:036203559@10.61.16.2 SIP/2.0 [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 1 [ 52]: Call-ID: 0f1e533008905417497809f127add60f@10.61.16.2 [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 2 [ 17]: CSeq: 9026164 ACK [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 3 [ 65]: From: ;tag=02-08067-008d3349-65e715141 [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 4 [ 16]: Max-Forwards: 31 [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 5 [ 60]: To: "Kocbek Milos" ;tag=as09d56ebc [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 6 [ 35]: User-Agent: Cirpack/v4.42d (gw_sip) [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 7 [ 60]: Via: SIP/2.0/UDP 10.22.11.20:5060;branch=z9hG4bK-5194-1A073E [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 8 [ 17]: Content-Length: 0 [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 9 [ 0]: [Aug 18 15:55:12] VERBOSE[19084] logger.c: --- (9 headers 0 lines) --- [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: = Found Their Call ID: 0f1e533008905417497809f127add60f@10.61.16.2 Their Tag 02-08067-008d3349-65e715141 Our tag: as09d56ebc [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: **** Received ACK (6) - Command in SIP ACK [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP) [Aug 18 15:55:12] DEBUG[19084] acl.c: Found IP address for this socket [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Initializing initreq for method OPTIONS - callid 01e0ad0469fc9bf217c4d24e440ceb33@10.255.255.1 [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 0 [ 56]: OPTIONS sip:360@10.255.255.90:2048;line=fxwb0cus SIP/2.0 [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 1 [ 63]: Via: SIP/2.0/UDP 10.255.255.1:5060;branch=z9hG4bK045c79af;rport [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 3 [ 57]: From: "Unknown" ;tag=as661756e8 [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 4 [ 46]: To: [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 5 [ 35]: Contact: [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 6 [ 54]: Call-ID: 01e0ad0469fc9bf217c4d24e440ceb33@10.255.255.1 [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 7 [ 17]: CSeq: 102 OPTIONS [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 8 [ 33]: User-Agent: Asterisk PBX 1.6.0.13 [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 9 [ 35]: Date: Tue, 18 Aug 2009 13:55:12 GMT [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 10 [ 66]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 12 [ 17]: Content-Length: 0 [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #18573 [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 10.255.255.90:2048 [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 1 [ 68]: Via: SIP/2.0/UDP 10.255.255.1:5060;branch=z9hG4bK045c79af;rport=5060 [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 2 [ 57]: From: "Unknown" ;tag=as661756e8 [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 3 [ 46]: To: [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 4 [ 54]: Call-ID: 01e0ad0469fc9bf217c4d24e440ceb33@10.255.255.1 [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 5 [ 17]: CSeq: 102 OPTIONS [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 6 [ 61]: Contact: ;flow-id=1 [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 7 [ 26]: User-Agent: snom320/7.1.30 [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 8 [ 19]: Accept-Language: en [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 9 [ 23]: Accept: application/sdp [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 10 [ 88]: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 11 [ 42]: Allow-Events: talk, hold, refer, call-info [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 12 [ 44]: Supported: timer, 100rel, replaces, callerid [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 13 [ 17]: Content-Length: 0 [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 14 [ 0]: [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: = Found Their Call ID: 01e0ad0469fc9bf217c4d24e440ceb33@10.255.255.1 Their Tag Our tag: as661756e8 [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #18573 [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Stopping retransmission on '01e0ad0469fc9bf217c4d24e440ceb33@10.255.255.1' of Request 102: Match Found [Aug 18 15:55:12] DEBUG[19793] rtp.c: Got RTCP report of 64 bytes [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP) [Aug 18 15:55:12] DEBUG[19084] acl.c: Found IP address for this socket [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Target address 91.199.174.240 is not local, substituting externip [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Initializing initreq for method OPTIONS - callid 03d70f8c2603cd2e4eebc3b55dc4662a@213.157.229.45 [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 0 [ 34]: OPTIONS sip:91.199.174.240 SIP/2.0 [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 1 [ 65]: Via: SIP/2.0/UDP 213.157.229.45:5060;branch=z9hG4bK1377580d;rport [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 3 [ 59]: From: "Unknown" ;tag=as5dd7fba7 [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 4 [ 24]: To: [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 5 [ 37]: Contact: [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 6 [ 56]: Call-ID: 03d70f8c2603cd2e4eebc3b55dc4662a@213.157.229.45 [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 7 [ 17]: CSeq: 102 OPTIONS [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 8 [ 33]: User-Agent: Asterisk PBX 1.6.0.13 [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 9 [ 35]: Date: Tue, 18 Aug 2009 13:55:12 GMT [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 10 [ 66]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 12 [ 17]: Content-Length: 0 [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #18576 [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 91.199.174.240:5060 [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP) [Aug 18 15:55:12] DEBUG[19084] acl.c: Found IP address for this socket [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Target address 91.199.174.249 is not local, substituting externip [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Initializing initreq for method OPTIONS - callid 02039f0a68e7f0730dc2df311ef1c28b@213.157.229.45 [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 0 [ 34]: OPTIONS sip:91.199.174.249 SIP/2.0 [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 1 [ 65]: Via: SIP/2.0/UDP 213.157.229.45:5060;branch=z9hG4bK6b9414f2;rport [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 3 [ 59]: From: "Unknown" ;tag=as499b166e [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 4 [ 24]: To: [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 5 [ 37]: Contact: [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 6 [ 56]: Call-ID: 02039f0a68e7f0730dc2df311ef1c28b@213.157.229.45 [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 7 [ 17]: CSeq: 102 OPTIONS [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 8 [ 33]: User-Agent: Asterisk PBX 1.6.0.13 [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 9 [ 35]: Date: Tue, 18 Aug 2009 13:55:12 GMT [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 10 [ 66]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 12 [ 17]: Content-Length: 0 [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #18578 [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 91.199.174.249:5060 [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP) [Aug 18 15:55:12] DEBUG[19084] acl.c: Found IP address for this socket [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Initializing initreq for method OPTIONS - callid 3719be2e3c45f709180e7be4491d4206@10.255.255.1 [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 0 [ 56]: OPTIONS sip:246@10.255.255.43:2048;line=6nwcjeec SIP/2.0 [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 1 [ 63]: Via: SIP/2.0/UDP 10.255.255.1:5060;branch=z9hG4bK288685e1;rport [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 3 [ 57]: From: "Unknown" ;tag=as14842ed7 [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 4 [ 46]: To: [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 5 [ 35]: Contact: [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 6 [ 54]: Call-ID: 3719be2e3c45f709180e7be4491d4206@10.255.255.1 [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 7 [ 17]: CSeq: 102 OPTIONS [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 8 [ 33]: User-Agent: Asterisk PBX 1.6.0.13 [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 9 [ 35]: Date: Tue, 18 Aug 2009 13:55:12 GMT [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 10 [ 66]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 12 [ 17]: Content-Length: 0 [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #18580 [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 10.255.255.43:2048 [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 1 [ 68]: Via: SIP/2.0/UDP 10.255.255.1:5060;branch=z9hG4bK288685e1;rport=5060 [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 2 [ 57]: From: "Unknown" ;tag=as14842ed7 [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 3 [ 46]: To: [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 4 [ 54]: Call-ID: 3719be2e3c45f709180e7be4491d4206@10.255.255.1 [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 5 [ 17]: CSeq: 102 OPTIONS [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 6 [ 61]: Contact: ;flow-id=1 [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 7 [ 26]: User-Agent: snom300/7.1.30 [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 8 [ 19]: Accept-Language: en [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 9 [ 23]: Accept: application/sdp [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 10 [ 88]: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 11 [ 42]: Allow-Events: talk, hold, refer, call-info [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 12 [ 44]: Supported: timer, 100rel, replaces, callerid [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 13 [ 17]: Content-Length: 0 [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 14 [ 0]: [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: = Found Their Call ID: 3719be2e3c45f709180e7be4491d4206@10.255.255.1 Their Tag Our tag: as14842ed7 [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #18580 [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Stopping retransmission on '3719be2e3c45f709180e7be4491d4206@10.255.255.1' of Request 102: Match Found [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP) [Aug 18 15:55:12] DEBUG[19084] acl.c: Found IP address for this socket [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Target address 91.199.174.51 is not local, substituting externip [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Initializing initreq for method OPTIONS - callid 7f93b7991289ff151b2765301b61c1c2@213.157.229.45 [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 0 [ 33]: OPTIONS sip:91.199.174.51 SIP/2.0 [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 1 [ 65]: Via: SIP/2.0/UDP 213.157.229.45:5060;branch=z9hG4bK515288b4;rport [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 3 [ 59]: From: "Unknown" ;tag=as60c2adf6 [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 4 [ 23]: To: [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 5 [ 37]: Contact: [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 6 [ 56]: Call-ID: 7f93b7991289ff151b2765301b61c1c2@213.157.229.45 [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 7 [ 17]: CSeq: 102 OPTIONS [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 8 [ 33]: User-Agent: Asterisk PBX 1.6.0.13 [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 9 [ 35]: Date: Tue, 18 Aug 2009 13:55:12 GMT [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 10 [ 66]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Header 12 [ 17]: Content-Length: 0 [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #18583 [Aug 18 15:55:12] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 91.199.174.51:5060 [Aug 18 15:55:13] DEBUG[19084] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP) [Aug 18 15:55:13] DEBUG[19084] acl.c: Found IP address for this socket [Aug 18 15:55:13] DEBUG[19084] chan_sip.c: Target address 84.255.199.122 is not local, substituting externip [Aug 18 15:55:13] DEBUG[19084] chan_sip.c: Initializing initreq for method OPTIONS - callid 39c5184e5b2138257aeb48950961ee6c@213.157.229.45 [Aug 18 15:55:13] DEBUG[19084] chan_sip.c: Header 0 [ 38]: OPTIONS sip:melamin.dyndns.org SIP/2.0 [Aug 18 15:55:13] DEBUG[19084] chan_sip.c: Header 1 [ 65]: Via: SIP/2.0/UDP 213.157.229.45:5060;branch=z9hG4bK76b8ac5f;rport [Aug 18 15:55:13] DEBUG[19084] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Aug 18 15:55:13] DEBUG[19084] chan_sip.c: Header 3 [ 59]: From: "Unknown" ;tag=as520ff827 [Aug 18 15:55:13] DEBUG[19084] chan_sip.c: Header 4 [ 28]: To: [Aug 18 15:55:13] DEBUG[19084] chan_sip.c: Header 5 [ 37]: Contact: [Aug 18 15:55:13] DEBUG[19084] chan_sip.c: Header 6 [ 56]: Call-ID: 39c5184e5b2138257aeb48950961ee6c@213.157.229.45 [Aug 18 15:55:13] DEBUG[19084] chan_sip.c: Header 7 [ 17]: CSeq: 102 OPTIONS [Aug 18 15:55:13] DEBUG[19084] chan_sip.c: Header 8 [ 33]: User-Agent: Asterisk PBX 1.6.0.13 [Aug 18 15:55:13] DEBUG[19084] chan_sip.c: Header 9 [ 35]: Date: Tue, 18 Aug 2009 13:55:13 GMT [Aug 18 15:55:13] DEBUG[19084] chan_sip.c: Header 10 [ 66]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY [Aug 18 15:55:13] DEBUG[19084] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [Aug 18 15:55:13] DEBUG[19084] chan_sip.c: Header 12 [ 17]: Content-Length: 0 [Aug 18 15:55:13] DEBUG[19084] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #18585 [Aug 18 15:55:13] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 84.255.199.122:5060 [Aug 18 15:55:13] DEBUG[19084] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP) [Aug 18 15:55:13] DEBUG[19084] acl.c: Found IP address for this socket [Aug 18 15:55:13] DEBUG[19084] chan_sip.c: Initializing initreq for method OPTIONS - callid 1773cbb068ef4610598bbe3246ed4e50@10.255.255.1 [Aug 18 15:55:13] DEBUG[19084] chan_sip.c: Header 0 [ 56]: OPTIONS sip:225@10.255.255.82:2048;line=aja66f1g SIP/2.0 [Aug 18 15:55:13] DEBUG[19084] chan_sip.c: Header 1 [ 63]: Via: SIP/2.0/UDP 10.255.255.1:5060;branch=z9hG4bK6cd333fe;rport [Aug 18 15:55:13] DEBUG[19084] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Aug 18 15:55:13] DEBUG[19084] chan_sip.c: Header 3 [ 57]: From: "Unknown" ;tag=as2c8af66e [Aug 18 15:55:13] DEBUG[19084] chan_sip.c: Header 4 [ 46]: To: [Aug 18 15:55:13] DEBUG[19084] chan_sip.c: Header 5 [ 35]: Contact: [Aug 18 15:55:13] DEBUG[19084] chan_sip.c: Header 6 [ 54]: Call-ID: 1773cbb068ef4610598bbe3246ed4e50@10.255.255.1 [Aug 18 15:55:13] DEBUG[19084] chan_sip.c: Header 7 [ 17]: CSeq: 102 OPTIONS [Aug 18 15:55:13] DEBUG[19084] chan_sip.c: Header 8 [ 33]: User-Agent: Asterisk PBX 1.6.0.13 [Aug 18 15:55:13] DEBUG[19084] chan_sip.c: Header 9 [ 35]: Date: Tue, 18 Aug 2009 13:55:13 GMT [Aug 18 15:55:13] DEBUG[19084] chan_sip.c: Header 10 [ 66]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY [Aug 18 15:55:13] DEBUG[19084] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [Aug 18 15:55:13] DEBUG[19084] chan_sip.c: Header 12 [ 17]: Content-Length: 0 [Aug 18 15:55:13] DEBUG[19084] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #18587 [Aug 18 15:55:13] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 10.255.255.82:2048 [Aug 18 15:55:13] DEBUG[19084] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [Aug 18 15:55:13] DEBUG[19084] chan_sip.c: Header 1 [ 68]: Via: SIP/2.0/UDP 10.255.255.1:5060;branch=z9hG4bK6cd333fe;rport=5060 [Aug 18 15:55:13] DEBUG[19084] chan_sip.c: Header 2 [ 57]: From: "Unknown" ;tag=as2c8af66e [Aug 18 15:55:13] DEBUG[19084] chan_sip.c: Header 3 [ 46]: To: [Aug 18 15:55:13] DEBUG[19084] chan_sip.c: Header 4 [ 54]: Call-ID: 1773cbb068ef4610598bbe3246ed4e50@10.255.255.1 [Aug 18 15:55:13] DEBUG[19084] chan_sip.c: Header 5 [ 17]: CSeq: 102 OPTIONS [Aug 18 15:55:13] DEBUG[19084] chan_sip.c: Header 6 [ 61]: Contact: ;flow-id=1 [Aug 18 15:55:13] DEBUG[19084] chan_sip.c: Header 7 [ 26]: User-Agent: snom320/7.1.30 [Aug 18 15:55:13] DEBUG[19084] chan_sip.c: Header 8 [ 19]: Accept-Language: en [Aug 18 15:55:13] DEBUG[19084] chan_sip.c: Header 9 [ 23]: Accept: application/sdp [Aug 18 15:55:13] DEBUG[19084] chan_sip.c: Header 10 [ 88]: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO [Aug 18 15:55:13] DEBUG[19084] chan_sip.c: Header 11 [ 42]: Allow-Events: talk, hold, refer, call-info [Aug 18 15:55:13] DEBUG[19084] chan_sip.c: Header 12 [ 44]: Supported: timer, 100rel, replaces, callerid [Aug 18 15:55:13] DEBUG[19084] chan_sip.c: Header 13 [ 17]: Content-Length: 0 [Aug 18 15:55:13] DEBUG[19084] chan_sip.c: Header 14 [ 0]: [Aug 18 15:55:13] DEBUG[19084] chan_sip.c: = Found Their Call ID: 1773cbb068ef4610598bbe3246ed4e50@10.255.255.1 Their Tag Our tag: as2c8af66e [Aug 18 15:55:13] DEBUG[19084] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #18587 [Aug 18 15:55:13] DEBUG[19084] chan_sip.c: Stopping retransmission on '1773cbb068ef4610598bbe3246ed4e50@10.255.255.1' of Request 102: Match Found [Aug 18 15:55:13] DEBUG[19084] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP) [Aug 18 15:55:13] DEBUG[19084] acl.c: Found IP address for this socket [Aug 18 15:55:13] DEBUG[19084] chan_sip.c: Target address 193.170.18.21 is not local, substituting externip [Aug 18 15:55:13] DEBUG[19084] chan_sip.c: Initializing initreq for method OPTIONS - callid 76a655a9797c9f74328d28353853df6e@213.157.229.45 [Aug 18 15:55:13] DEBUG[19084] chan_sip.c: Header 0 [ 33]: OPTIONS sip:193.170.18.21 SIP/2.0 [Aug 18 15:55:13] DEBUG[19084] chan_sip.c: Header 1 [ 65]: Via: SIP/2.0/UDP 213.157.229.45:5060;branch=z9hG4bK2e910dbc;rport [Aug 18 15:55:13] DEBUG[19084] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Aug 18 15:55:13] DEBUG[19084] chan_sip.c: Header 3 [ 59]: From: "Unknown" ;tag=as037419bd [Aug 18 15:55:13] DEBUG[19084] chan_sip.c: Header 4 [ 23]: To: [Aug 18 15:55:13] DEBUG[19084] chan_sip.c: Header 5 [ 37]: Contact: [Aug 18 15:55:13] DEBUG[19084] chan_sip.c: Header 6 [ 56]: Call-ID: 76a655a9797c9f74328d28353853df6e@213.157.229.45 [Aug 18 15:55:13] DEBUG[19084] chan_sip.c: Header 7 [ 17]: CSeq: 102 OPTIONS [Aug 18 15:55:13] DEBUG[19084] chan_sip.c: Header 8 [ 33]: User-Agent: Asterisk PBX 1.6.0.13 [Aug 18 15:55:13] DEBUG[19084] chan_sip.c: Header 9 [ 35]: Date: Tue, 18 Aug 2009 13:55:13 GMT [Aug 18 15:55:13] DEBUG[19084] chan_sip.c: Header 10 [ 66]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY [Aug 18 15:55:13] DEBUG[19084] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [Aug 18 15:55:13] DEBUG[19084] chan_sip.c: Header 12 [ 17]: Content-Length: 0 [Aug 18 15:55:13] DEBUG[19084] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #18590 [Aug 18 15:55:13] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 193.170.18.21:5060 [Aug 18 15:55:13] DEBUG[19084] chan_sip.c: SIP TIMER: Not rescheduling id #18576:OPTIONS (Method 3) (No timer T1) [Aug 18 15:55:13] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 91.199.174.240:5060 [Aug 18 15:55:13] DEBUG[19084] chan_sip.c: SIP TIMER: Not rescheduling id #18578:OPTIONS (Method 3) (No timer T1) [Aug 18 15:55:13] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 91.199.174.249:5060 [Aug 18 15:55:13] DEBUG[19084] chan_sip.c: SIP TIMER: Not rescheduling id #18583:OPTIONS (Method 3) (No timer T1) [Aug 18 15:55:13] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 91.199.174.51:5060 [Aug 18 15:55:14] DEBUG[19084] chan_sip.c: SIP TIMER: Not rescheduling id #18585:OPTIONS (Method 3) (No timer T1) [Aug 18 15:55:14] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 84.255.199.122:5060 [Aug 18 15:55:14] DEBUG[19084] chan_sip.c: SIP TIMER: Not rescheduling id #18590:OPTIONS (Method 3) (No timer T1) [Aug 18 15:55:14] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 193.170.18.21:5060 [Aug 18 15:55:14] DEBUG[19084] chan_sip.c: SIP TIMER: Not rescheduling id #18576:OPTIONS (Method 3) (No timer T1) [Aug 18 15:55:14] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 91.199.174.240:5060 [Aug 18 15:55:14] DEBUG[19084] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP) [Aug 18 15:55:14] DEBUG[19084] acl.c: Found IP address for this socket [Aug 18 15:55:14] DEBUG[19084] chan_sip.c: Target address 212.18.40.137 is not local, substituting externip [Aug 18 15:55:14] DEBUG[19084] chan_sip.c: Initializing initreq for method OPTIONS - callid 7b2aec6019d6d9d637c46485739dd790@213.157.229.45 [Aug 18 15:55:14] DEBUG[19084] chan_sip.c: Header 0 [ 33]: OPTIONS sip:212.18.40.137 SIP/2.0 [Aug 18 15:55:14] DEBUG[19084] chan_sip.c: Header 1 [ 65]: Via: SIP/2.0/UDP 213.157.229.45:5060;branch=z9hG4bK1220d23a;rport [Aug 18 15:55:14] DEBUG[19084] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Aug 18 15:55:14] DEBUG[19084] chan_sip.c: Header 3 [ 59]: From: "Unknown" ;tag=as6ef0c0ec [Aug 18 15:55:14] DEBUG[19084] chan_sip.c: Header 4 [ 23]: To: [Aug 18 15:55:14] DEBUG[19084] chan_sip.c: Header 5 [ 37]: Contact: [Aug 18 15:55:14] DEBUG[19084] chan_sip.c: Header 6 [ 56]: Call-ID: 7b2aec6019d6d9d637c46485739dd790@213.157.229.45 [Aug 18 15:55:14] DEBUG[19084] chan_sip.c: Header 7 [ 17]: CSeq: 102 OPTIONS [Aug 18 15:55:14] DEBUG[19084] chan_sip.c: Header 8 [ 33]: User-Agent: Asterisk PBX 1.6.0.13 [Aug 18 15:55:14] DEBUG[19084] chan_sip.c: Header 9 [ 35]: Date: Tue, 18 Aug 2009 13:55:14 GMT [Aug 18 15:55:14] DEBUG[19084] chan_sip.c: Header 10 [ 66]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY [Aug 18 15:55:14] DEBUG[19084] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [Aug 18 15:55:14] DEBUG[19084] chan_sip.c: Header 12 [ 17]: Content-Length: 0 [Aug 18 15:55:14] DEBUG[19084] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #18592 [Aug 18 15:55:14] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 212.18.40.137:5060 [Aug 18 15:55:14] DEBUG[19084] chan_sip.c: SIP TIMER: Not rescheduling id #18578:OPTIONS (Method 3) (No timer T1) [Aug 18 15:55:14] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 91.199.174.249:5060 [Aug 18 15:55:14] DEBUG[19084] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP) [Aug 18 15:55:14] DEBUG[19084] acl.c: Found IP address for this socket [Aug 18 15:55:14] DEBUG[19084] chan_sip.c: Target address 195.5.164.230 is not local, substituting externip [Aug 18 15:55:14] DEBUG[19084] chan_sip.c: Initializing initreq for method OPTIONS - callid 437db39827cf14612bb8f83d7e3dd48d@213.157.229.45 [Aug 18 15:55:14] DEBUG[19084] chan_sip.c: Header 0 [ 33]: OPTIONS sip:195.5.164.230 SIP/2.0 [Aug 18 15:55:14] DEBUG[19084] chan_sip.c: Header 1 [ 65]: Via: SIP/2.0/UDP 213.157.229.45:5060;branch=z9hG4bK7d9aafbe;rport [Aug 18 15:55:14] DEBUG[19084] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Aug 18 15:55:14] DEBUG[19084] chan_sip.c: Header 3 [ 59]: From: "Unknown" ;tag=as61d1ea2e [Aug 18 15:55:14] DEBUG[19084] chan_sip.c: Header 4 [ 23]: To: [Aug 18 15:55:14] DEBUG[19084] chan_sip.c: Header 5 [ 37]: Contact: [Aug 18 15:55:14] DEBUG[19084] chan_sip.c: Header 6 [ 56]: Call-ID: 437db39827cf14612bb8f83d7e3dd48d@213.157.229.45 [Aug 18 15:55:14] DEBUG[19084] chan_sip.c: Header 7 [ 17]: CSeq: 102 OPTIONS [Aug 18 15:55:14] DEBUG[19084] chan_sip.c: Header 8 [ 33]: User-Agent: Asterisk PBX 1.6.0.13 [Aug 18 15:55:14] DEBUG[19084] chan_sip.c: Header 9 [ 35]: Date: Tue, 18 Aug 2009 13:55:14 GMT [Aug 18 15:55:14] DEBUG[19084] chan_sip.c: Header 10 [ 66]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY [Aug 18 15:55:14] DEBUG[19084] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [Aug 18 15:55:14] DEBUG[19084] chan_sip.c: Header 12 [ 17]: Content-Length: 0 [Aug 18 15:55:14] DEBUG[19084] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #18594 [Aug 18 15:55:14] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 195.5.164.230:5060 [Aug 18 15:55:14] DEBUG[19084] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP) [Aug 18 15:55:14] DEBUG[19084] acl.c: Found IP address for this socket [Aug 18 15:55:14] DEBUG[19084] chan_sip.c: Target address 193.77.191.78 is not local, substituting externip [Aug 18 15:55:14] DEBUG[19084] chan_sip.c: Initializing initreq for method OPTIONS - callid 57a9cfcd6d3527b7029118250cbbb69c@213.157.229.45 [Aug 18 15:55:14] DEBUG[19084] chan_sip.c: Header 0 [ 33]: OPTIONS sip:193.77.191.78 SIP/2.0 [Aug 18 15:55:14] DEBUG[19084] chan_sip.c: Header 1 [ 65]: Via: SIP/2.0/UDP 213.157.229.45:5060;branch=z9hG4bK572d4e6a;rport [Aug 18 15:55:14] DEBUG[19084] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Aug 18 15:55:14] DEBUG[19084] chan_sip.c: Header 3 [ 59]: From: "Unknown" ;tag=as4f0ed5d2 [Aug 18 15:55:14] DEBUG[19084] chan_sip.c: Header 4 [ 23]: To: [Aug 18 15:55:14] DEBUG[19084] chan_sip.c: Header 5 [ 37]: Contact: [Aug 18 15:55:14] DEBUG[19084] chan_sip.c: Header 6 [ 56]: Call-ID: 57a9cfcd6d3527b7029118250cbbb69c@213.157.229.45 [Aug 18 15:55:14] DEBUG[19084] chan_sip.c: Header 7 [ 17]: CSeq: 102 OPTIONS [Aug 18 15:55:14] DEBUG[19084] chan_sip.c: Header 8 [ 33]: User-Agent: Asterisk PBX 1.6.0.13 [Aug 18 15:55:14] DEBUG[19084] chan_sip.c: Header 9 [ 35]: Date: Tue, 18 Aug 2009 13:55:14 GMT [Aug 18 15:55:14] DEBUG[19084] chan_sip.c: Header 10 [ 66]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY [Aug 18 15:55:14] DEBUG[19084] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [Aug 18 15:55:14] DEBUG[19084] chan_sip.c: Header 12 [ 17]: Content-Length: 0 [Aug 18 15:55:14] DEBUG[19084] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #18596 [Aug 18 15:55:14] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 193.77.191.78:5060 [Aug 18 15:55:14] DEBUG[19084] chan_sip.c: SIP TIMER: Not rescheduling id #18583:OPTIONS (Method 3) (No timer T1) [Aug 18 15:55:14] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 91.199.174.51:5060 [Aug 18 15:55:15] DEBUG[19084] chan_sip.c: SIP TIMER: Not rescheduling id #18585:OPTIONS (Method 3) (No timer T1) [Aug 18 15:55:15] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 84.255.199.122:5060 [Aug 18 15:55:15] DEBUG[19084] chan_sip.c: SIP TIMER: Not rescheduling id #18590:OPTIONS (Method 3) (No timer T1) [Aug 18 15:55:15] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 193.170.18.21:5060 [Aug 18 15:55:15] DEBUG[19084] chan_sip.c: SIP TIMER: Not rescheduling id #18576:OPTIONS (Method 3) (No timer T1) [Aug 18 15:55:15] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 91.199.174.240:5060 [Aug 18 15:55:15] DEBUG[19084] chan_sip.c: SIP TIMER: Not rescheduling id #18578:OPTIONS (Method 3) (No timer T1) [Aug 18 15:55:15] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 91.199.174.249:5060 [Aug 18 15:55:15] DEBUG[19084] chan_sip.c: SIP TIMER: Not rescheduling id #18592:OPTIONS (Method 3) (No timer T1) [Aug 18 15:55:15] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 212.18.40.137:5060 [Aug 18 15:55:15] DEBUG[19084] chan_sip.c: SIP TIMER: Not rescheduling id #18594:OPTIONS (Method 3) (No timer T1) [Aug 18 15:55:15] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 195.5.164.230:5060 [Aug 18 15:55:15] DEBUG[19084] chan_sip.c: SIP TIMER: Not rescheduling id #18596:OPTIONS (Method 3) (No timer T1) [Aug 18 15:55:15] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 193.77.191.78:5060 [Aug 18 15:55:15] DEBUG[19084] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP) [Aug 18 15:55:15] DEBUG[19084] acl.c: Found IP address for this socket [Aug 18 15:55:15] DEBUG[19084] chan_sip.c: Target address 193.81.210.21 is not local, substituting externip [Aug 18 15:55:15] DEBUG[19084] chan_sip.c: Initializing initreq for method OPTIONS - callid 22efe23b015ae7cf627d42347521b984@213.157.229.45 [Aug 18 15:55:15] DEBUG[19084] chan_sip.c: Header 0 [ 33]: OPTIONS sip:193.81.210.21 SIP/2.0 [Aug 18 15:55:15] DEBUG[19084] chan_sip.c: Header 1 [ 65]: Via: SIP/2.0/UDP 213.157.229.45:5060;branch=z9hG4bK40406228;rport [Aug 18 15:55:15] DEBUG[19084] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Aug 18 15:55:15] DEBUG[19084] chan_sip.c: Header 3 [ 59]: From: "Unknown" ;tag=as1fc555d6 [Aug 18 15:55:15] DEBUG[19084] chan_sip.c: Header 4 [ 23]: To: [Aug 18 15:55:15] DEBUG[19084] chan_sip.c: Header 5 [ 37]: Contact: [Aug 18 15:55:15] DEBUG[19084] chan_sip.c: Header 6 [ 56]: Call-ID: 22efe23b015ae7cf627d42347521b984@213.157.229.45 [Aug 18 15:55:15] DEBUG[19084] chan_sip.c: Header 7 [ 17]: CSeq: 102 OPTIONS [Aug 18 15:55:15] DEBUG[19084] chan_sip.c: Header 8 [ 33]: User-Agent: Asterisk PBX 1.6.0.13 [Aug 18 15:55:15] DEBUG[19084] chan_sip.c: Header 9 [ 35]: Date: Tue, 18 Aug 2009 13:55:15 GMT [Aug 18 15:55:15] DEBUG[19084] chan_sip.c: Header 10 [ 66]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY [Aug 18 15:55:15] DEBUG[19084] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [Aug 18 15:55:15] DEBUG[19084] chan_sip.c: Header 12 [ 17]: Content-Length: 0 [Aug 18 15:55:15] DEBUG[19084] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #18598 [Aug 18 15:55:15] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 193.81.210.21:5060 [Aug 18 15:55:15] DEBUG[19084] chan_sip.c: SIP TIMER: Not rescheduling id #18583:OPTIONS (Method 3) (No timer T1) [Aug 18 15:55:15] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 91.199.174.51:5060 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: SIP TIMER: Not rescheduling id #18585:OPTIONS (Method 3) (No timer T1) [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 84.255.199.122:5060 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP) [Aug 18 15:55:16] DEBUG[19084] acl.c: Found IP address for this socket [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Target address 193.77.187.53 is not local, substituting externip [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Initializing initreq for method OPTIONS - callid 4fcbca65142c9f242925d12479b8abc4@213.157.229.45 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 0 [ 33]: OPTIONS sip:193.77.187.53 SIP/2.0 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 1 [ 65]: Via: SIP/2.0/UDP 213.157.229.45:5060;branch=z9hG4bK31a9438d;rport [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 3 [ 59]: From: "Unknown" ;tag=as4d859912 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 4 [ 23]: To: [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 5 [ 37]: Contact: [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 6 [ 56]: Call-ID: 4fcbca65142c9f242925d12479b8abc4@213.157.229.45 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 7 [ 17]: CSeq: 102 OPTIONS [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 8 [ 33]: User-Agent: Asterisk PBX 1.6.0.13 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 9 [ 35]: Date: Tue, 18 Aug 2009 13:55:16 GMT [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 10 [ 66]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 12 [ 17]: Content-Length: 0 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #18600 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 193.77.187.53:5060 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP) [Aug 18 15:55:16] DEBUG[19084] acl.c: Found IP address for this socket [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Initializing initreq for method OPTIONS - callid 78507a9c45d4ff453af1cdc046074371@10.255.255.1 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 0 [ 72]: OPTIONS sip:9294@10.255.255.9;uniq=BA218859FD5692558E221D285DD20 SIP/2.0 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 1 [ 63]: Via: SIP/2.0/UDP 10.255.255.1:5060;branch=z9hG4bK2e01e287;rport [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 3 [ 57]: From: "Unknown" ;tag=as4fd0a3fe [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 4 [ 62]: To: [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 5 [ 35]: Contact: [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 6 [ 54]: Call-ID: 78507a9c45d4ff453af1cdc046074371@10.255.255.1 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 7 [ 17]: CSeq: 102 OPTIONS [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 8 [ 33]: User-Agent: Asterisk PBX 1.6.0.13 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 9 [ 35]: Date: Tue, 18 Aug 2009 13:55:16 GMT [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 10 [ 66]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 12 [ 17]: Content-Length: 0 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #18602 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 10.255.255.9:5060 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 1 [ 68]: Via: SIP/2.0/UDP 10.255.255.1:5060;branch=z9hG4bK2e01e287;rport=5060 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 2 [ 57]: From: "Unknown" ;tag=as4fd0a3fe [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 3 [ 83]: To: ;tag=0A1F41B35449FE04 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 4 [ 54]: Call-ID: 78507a9c45d4ff453af1cdc046074371@10.255.255.1 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 5 [ 17]: CSeq: 102 OPTIONS [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 6 [ 67]: Contact: [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 7 [ 62]: User-Agent: AVM FRITZ!Box Fon WLAN 7170 29.04.56 (May 1 2008) [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 8 [ 26]: Supported: 100rel,replaces [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 9 [ 35]: Allow-Events: telephone-event,refer [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 10 [ 85]: Allow: INVITE,ACK,OPTIONS,CANCEL,BYE,UPDATE,PRACK,INFO,SUBSCRIBE,NOTIFY,REFER,MESSAGE [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 11 [ 40]: Accept: application/sdp, multipart/mixed [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 12 [ 25]: Accept-Encoding: identity [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 13 [ 17]: Content-Length: 0 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 14 [ 0]: [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: = Found Their Call ID: 78507a9c45d4ff453af1cdc046074371@10.255.255.1 Their Tag Our tag: as4fd0a3fe [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #18602 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Stopping retransmission on '78507a9c45d4ff453af1cdc046074371@10.255.255.1' of Request 102: Match Found [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: SIP TIMER: Not rescheduling id #18590:OPTIONS (Method 3) (No timer T1) [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 193.170.18.21:5060 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: SIP TIMER: Not rescheduling id #18576:OPTIONS (Method 3) (No timer T1) [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 91.199.174.240:5060 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Destroying SIP dialog 03d70f8c2603cd2e4eebc3b55dc4662a@213.157.229.45 [Aug 18 15:55:16] DEBUG[19084] devicestate.c: Notification of state change to be queued on device/channel SIP/voipy-glcr-383-peer [Aug 18 15:55:16] DEBUG[19067] devicestate.c: No provider found, checking channel drivers for SIP - voipy-glcr-383-peer [Aug 18 15:55:16] DEBUG[19067] chan_sip.c: Checking device state for peer voipy-glcr-383-peer [Aug 18 15:55:16] DEBUG[19067] devicestate.c: Changing state for SIP/voipy-glcr-383-peer - state 5 (Unavailable) [Aug 18 15:55:16] DEBUG[19083] app_queue.c: Device 'SIP/voipy-glcr-383-peer' changed to state '5' (Unavailable) but we don't care because they're not a member of any queue. [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: SIP TIMER: Not rescheduling id #18578:OPTIONS (Method 3) (No timer T1) [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 91.199.174.249:5060 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Destroying SIP dialog 02039f0a68e7f0730dc2df311ef1c28b@213.157.229.45 [Aug 18 15:55:16] DEBUG[19084] devicestate.c: Notification of state change to be queued on device/channel SIP/voipy-glcr-381-peer [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: SIP TIMER: Not rescheduling id #18592:OPTIONS (Method 3) (No timer T1) [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 212.18.40.137:5060 [Aug 18 15:55:16] DEBUG[19067] devicestate.c: No provider found, checking channel drivers for SIP - voipy-glcr-381-peer [Aug 18 15:55:16] DEBUG[19067] chan_sip.c: Checking device state for peer voipy-glcr-381-peer [Aug 18 15:55:16] DEBUG[19067] devicestate.c: Changing state for SIP/voipy-glcr-381-peer - state 5 (Unavailable) [Aug 18 15:55:16] DEBUG[19083] app_queue.c: Device 'SIP/voipy-glcr-381-peer' changed to state '5' (Unavailable) but we don't care because they're not a member of any queue. [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP) [Aug 18 15:55:16] DEBUG[19084] acl.c: Found IP address for this socket [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Target address 193.189.170.245 is not local, substituting externip [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Initializing initreq for method OPTIONS - callid 58dbb3c276c425c3198213c252b712db@213.157.229.45 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 0 [ 35]: OPTIONS sip:193.189.170.245 SIP/2.0 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 1 [ 65]: Via: SIP/2.0/UDP 213.157.229.45:5060;branch=z9hG4bK20a68caf;rport [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 3 [ 59]: From: "Unknown" ;tag=as2b34fce9 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 4 [ 25]: To: [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 5 [ 37]: Contact: [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 6 [ 56]: Call-ID: 58dbb3c276c425c3198213c252b712db@213.157.229.45 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 7 [ 17]: CSeq: 102 OPTIONS [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 8 [ 33]: User-Agent: Asterisk PBX 1.6.0.13 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 9 [ 35]: Date: Tue, 18 Aug 2009 13:55:16 GMT [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 10 [ 66]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 12 [ 17]: Content-Length: 0 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #18607 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 193.189.170.245:5060 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: SIP TIMER: Not rescheduling id #18594:OPTIONS (Method 3) (No timer T1) [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 195.5.164.230:5060 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP) [Aug 18 15:55:16] DEBUG[19084] acl.c: Found IP address for this socket [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Target address 194.249.239.5 is not local, substituting externip [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Initializing initreq for method OPTIONS - callid 2d6a4c966e19053201d988cd43fbf291@213.157.229.45 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 0 [ 33]: OPTIONS sip:194.249.239.5 SIP/2.0 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 1 [ 65]: Via: SIP/2.0/UDP 213.157.229.45:5060;branch=z9hG4bK28cc8e04;rport [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 3 [ 59]: From: "Unknown" ;tag=as46e507e8 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 4 [ 23]: To: [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 5 [ 37]: Contact: [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 6 [ 56]: Call-ID: 2d6a4c966e19053201d988cd43fbf291@213.157.229.45 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 7 [ 17]: CSeq: 102 OPTIONS [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 8 [ 33]: User-Agent: Asterisk PBX 1.6.0.13 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 9 [ 35]: Date: Tue, 18 Aug 2009 13:55:16 GMT [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 10 [ 66]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 12 [ 17]: Content-Length: 0 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #18609 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 194.249.239.5:5060 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: SIP TIMER: Not rescheduling id #18596:OPTIONS (Method 3) (No timer T1) [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 193.77.191.78:5060 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: SIP TIMER: Not rescheduling id #18598:OPTIONS (Method 3) (No timer T1) [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 193.81.210.21:5060 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 0 [ 33]: REGISTER sip:10.255.255.1 SIP/2.0 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 1 [ 72]: Via: SIP/2.0/UDP 10.255.255.12:5060;rport;branch=z9hG4bKC128B91E8DBD8259 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 2 [ 44]: From: ;tag=4085710466 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 3 [ 27]: To: [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 4 [ 39]: Call-ID: 822F1077AB3D5774@10.255.255.12 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 5 [ 18]: CSeq: 942 REGISTER [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 6 [157]: Authorization: Digest username="9258", realm="asterisk", nonce="4aaf9d79", uri="sip:10.255.255.1", response="37dd92055e58b13ee9306e0b146d5a2c", algorithm=MD5 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 7 [ 16]: Max-Forwards: 70 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 8 [ 62]: User-Agent: AVM FRITZ!Box Fon WLAN 7170 29.04.56 (May 1 2008) [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 9 [ 26]: Supported: 100rel,replaces [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 10 [ 39]: Allow-Events: telephone-event,refer,reg [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 11 [ 85]: Allow: INVITE,ACK,OPTIONS,CANCEL,BYE,UPDATE,PRACK,INFO,SUBSCRIBE,NOTIFY,REFER,MESSAGE [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 12 [ 40]: Accept: application/sdp, multipart/mixed [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 13 [ 25]: Accept-Encoding: identity [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 14 [ 17]: Content-Length: 0 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 15 [ 0]: [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: = No match Their Call ID: 2d6a4c966e19053201d988cd43fbf291@213.157.229.45 Their Tag Our tag: as46e507e8 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: = No match Their Call ID: 58dbb3c276c425c3198213c252b712db@213.157.229.45 Their Tag Our tag: as2b34fce9 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: = No match Their Call ID: 4fcbca65142c9f242925d12479b8abc4@213.157.229.45 Their Tag Our tag: as4d859912 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: = No match Their Call ID: 22efe23b015ae7cf627d42347521b984@213.157.229.45 Their Tag Our tag: as1fc555d6 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: = No match Their Call ID: 57a9cfcd6d3527b7029118250cbbb69c@213.157.229.45 Their Tag Our tag: as4f0ed5d2 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: = No match Their Call ID: 437db39827cf14612bb8f83d7e3dd48d@213.157.229.45 Their Tag Our tag: as61d1ea2e [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: = No match Their Call ID: 7b2aec6019d6d9d637c46485739dd790@213.157.229.45 Their Tag Our tag: as6ef0c0ec [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: = No match Their Call ID: 76a655a9797c9f74328d28353853df6e@213.157.229.45 Their Tag Our tag: as037419bd [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: = No match Their Call ID: 39c5184e5b2138257aeb48950961ee6c@213.157.229.45 Their Tag Our tag: as520ff827 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: = No match Their Call ID: 7f93b7991289ff151b2765301b61c1c2@213.157.229.45 Their Tag Our tag: as60c2adf6 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: = No match Their Call ID: 0f1e533008905417497809f127add60f@10.61.16.2 Their Tag 02-08067-008d3349-65e715141 Our tag: as09d56ebc [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: = No match Their Call ID: 06e30dec72b7b932299f51831018adc6@91.199.174.215 Their Tag as4e650b76 Our tag: as3f6ba72a [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: = No match Their Call ID: 3c26701b61b7-99pfm3a5uxii Their Tag 4ihcn6xz4e Our tag: as05934142 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: = No match Their Call ID: 3c267029a2f5-wfmhfhpu3hyn Their Tag 9da9o5s4u5 Our tag: as4e75bf26 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: = No match Their Call ID: ED7C341FEC0D8D17@10.255.255.9 Their Tag 988839643 Our tag: as297b8b51 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: = No match Their Call ID: EF9B2C32E235C72D@10.255.255.6 Their Tag 2108783450 Our tag: as7088f61c [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: = No match Their Call ID: F5132C31D9CC57AC@10.255.255.8 Their Tag 1747893060 Our tag: as59d74d8b [Aug 18 15:55:16] DEBUG[19084] acl.c: Found IP address for this socket [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Allocating new SIP dialog for 822F1077AB3D5774@10.255.255.12 - REGISTER (No RTP) [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: **** Received REGISTER (2) - Command in SIP REGISTER [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Initializing initreq for method REGISTER - callid 822F1077AB3D5774@10.255.255.12 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Trying to put 'SIP/2.0 40' onto UDP socket destined for 10.255.255.12:5060 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 0 [ 33]: REGISTER sip:10.255.255.1 SIP/2.0 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 1 [ 72]: Via: SIP/2.0/UDP 10.255.255.12:5060;rport;branch=z9hG4bK4F2EAEE3BF0171C7 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 2 [ 44]: From: ;tag=4085710466 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 3 [ 27]: To: [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 4 [ 39]: Call-ID: 822F1077AB3D5774@10.255.255.12 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 5 [ 18]: CSeq: 943 REGISTER [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 6 [157]: Authorization: Digest username="9258", realm="asterisk", nonce="15e8c02d", uri="sip:10.255.255.1", response="f1b305da76688b5f237c6f265ca14f2f", algorithm=MD5 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 7 [ 16]: Max-Forwards: 70 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 8 [ 62]: User-Agent: AVM FRITZ!Box Fon WLAN 7170 29.04.56 (May 1 2008) [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 9 [ 26]: Supported: 100rel,replaces [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 10 [ 39]: Allow-Events: telephone-event,refer,reg [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 11 [ 85]: Allow: INVITE,ACK,OPTIONS,CANCEL,BYE,UPDATE,PRACK,INFO,SUBSCRIBE,NOTIFY,REFER,MESSAGE [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 12 [ 40]: Accept: application/sdp, multipart/mixed [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 13 [ 25]: Accept-Encoding: identity [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 14 [ 17]: Content-Length: 0 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 15 [ 0]: [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: = Found Their Call ID: 822F1077AB3D5774@10.255.255.12 Their Tag 4085710466 Our tag: as2a381f21 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: **** Received REGISTER (2) - Command in SIP REGISTER [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Initializing initreq for method REGISTER - callid 822F1077AB3D5774@10.255.255.12 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Trying to put 'SIP/2.0 20' onto UDP socket destined for 10.255.255.12:5060 [Aug 18 15:55:16] DEBUG[19084] devicestate.c: Notification of state change to be queued on device/channel SIP/9258 [Aug 18 15:55:16] DEBUG[19067] devicestate.c: No provider found, checking channel drivers for SIP - 9258 [Aug 18 15:55:16] DEBUG[19067] chan_sip.c: Checking device state for peer 9258 [Aug 18 15:55:16] DEBUG[19067] devicestate.c: Changing state for SIP/9258 - state 1 (Not in use) [Aug 18 15:55:16] DEBUG[19068] devicestate.c: No provider found, checking channel drivers for SIP - 9258 [Aug 18 15:55:16] DEBUG[19068] chan_sip.c: Checking device state for peer 9258 [Aug 18 15:55:16] DEBUG[19083] app_queue.c: Device 'SIP/9258' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 0 [ 33]: REGISTER sip:10.255.255.1 SIP/2.0 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 1 [ 72]: Via: SIP/2.0/UDP 10.255.255.12:5060;rport;branch=z9hG4bK1440A823F457B008 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 2 [ 44]: From: ;tag=4085710466 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 3 [ 27]: To: [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 4 [ 39]: Call-ID: 822F1077AB3D5774@10.255.255.12 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 5 [ 18]: CSeq: 944 REGISTER [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 6 [ 68]: Contact: [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 7 [157]: Authorization: Digest username="9258", realm="asterisk", nonce="15e8c02d", uri="sip:10.255.255.1", response="f1b305da76688b5f237c6f265ca14f2f", algorithm=MD5 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 8 [ 13]: Expires: 1800 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 9 [ 16]: Max-Forwards: 70 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 10 [ 62]: User-Agent: AVM FRITZ!Box Fon WLAN 7170 29.04.56 (May 1 2008) [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 11 [ 26]: Supported: 100rel,replaces [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 12 [ 39]: Allow-Events: telephone-event,refer,reg [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 13 [ 85]: Allow: INVITE,ACK,OPTIONS,CANCEL,BYE,UPDATE,PRACK,INFO,SUBSCRIBE,NOTIFY,REFER,MESSAGE [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 14 [ 40]: Accept: application/sdp, multipart/mixed [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 15 [ 25]: Accept-Encoding: identity [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 16 [ 17]: Content-Length: 0 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 17 [ 0]: [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: = Found Their Call ID: 822F1077AB3D5774@10.255.255.12 Their Tag 4085710466 Our tag: as2a381f21 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: **** Received REGISTER (2) - Command in SIP REGISTER [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Initializing initreq for method REGISTER - callid 822F1077AB3D5774@10.255.255.12 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP) [Aug 18 15:55:16] DEBUG[19084] acl.c: Found IP address for this socket [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Initializing initreq for method OPTIONS - callid 34afc0432bc594fc448043c02e8585be@10.255.255.1 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 0 [ 73]: OPTIONS sip:9258@10.255.255.12;uniq=B4343BC4DD84F417CAB1FE9ECEAD3 SIP/2.0 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 1 [ 63]: Via: SIP/2.0/UDP 10.255.255.1:5060;branch=z9hG4bK5a818497;rport [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 3 [ 57]: From: "Unknown" ;tag=as12c315e6 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 4 [ 63]: To: [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 5 [ 35]: Contact: [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 6 [ 54]: Call-ID: 34afc0432bc594fc448043c02e8585be@10.255.255.1 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 7 [ 17]: CSeq: 102 OPTIONS [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 8 [ 33]: User-Agent: Asterisk PBX 1.6.0.13 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 9 [ 35]: Date: Tue, 18 Aug 2009 13:55:16 GMT [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 10 [ 66]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 12 [ 17]: Content-Length: 0 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #18614 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 10.255.255.12:5060 [Aug 18 15:55:16] VERBOSE[19084] logger.c: > Saved useragent "AVM FRITZ!Box Fon WLAN 7170 29.04.56 (May 1 2008)" for peer 9258 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Trying to put 'SIP/2.0 20' onto UDP socket destined for 10.255.255.12:5060 [Aug 18 15:55:16] DEBUG[19084] devicestate.c: Notification of state change to be queued on device/channel SIP/9258 [Aug 18 15:55:16] DEBUG[19067] devicestate.c: No provider found, checking channel drivers for SIP - 9258 [Aug 18 15:55:16] DEBUG[19067] chan_sip.c: Checking device state for peer 9258 [Aug 18 15:55:16] DEBUG[19067] devicestate.c: Changing state for SIP/9258 - state 1 (Not in use) [Aug 18 15:55:16] DEBUG[19083] app_queue.c: Device 'SIP/9258' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Aug 18 15:55:16] DEBUG[19068] devicestate.c: No provider found, checking channel drivers for SIP - 9258 [Aug 18 15:55:16] DEBUG[19068] chan_sip.c: Checking device state for peer 9258 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP) [Aug 18 15:55:16] DEBUG[19084] acl.c: Found IP address for this socket [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Target address 81.189.215.197 is not local, substituting externip [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Initializing initreq for method OPTIONS - callid 4d0e89031315b99012052f6e4ba87c3c@213.157.229.45 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 0 [ 34]: OPTIONS sip:81.189.215.197 SIP/2.0 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 1 [ 65]: Via: SIP/2.0/UDP 213.157.229.45:5060;branch=z9hG4bK3db086d4;rport [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 3 [ 59]: From: "Unknown" ;tag=as11294d4c [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 4 [ 24]: To: [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 5 [ 37]: Contact: [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 6 [ 56]: Call-ID: 4d0e89031315b99012052f6e4ba87c3c@213.157.229.45 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 7 [ 17]: CSeq: 102 OPTIONS [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 8 [ 33]: User-Agent: Asterisk PBX 1.6.0.13 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 9 [ 35]: Date: Tue, 18 Aug 2009 13:55:16 GMT [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 10 [ 66]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 12 [ 17]: Content-Length: 0 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #18617 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 81.189.215.197:5060 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 1 [ 68]: Via: SIP/2.0/UDP 10.255.255.1:5060;branch=z9hG4bK5a818497;rport=5060 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 2 [ 57]: From: "Unknown" ;tag=as12c315e6 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 3 [ 84]: To: ;tag=817430FDEE50C785 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 4 [ 54]: Call-ID: 34afc0432bc594fc448043c02e8585be@10.255.255.1 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 5 [ 17]: CSeq: 102 OPTIONS [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 6 [ 68]: Contact: [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 7 [ 62]: User-Agent: AVM FRITZ!Box Fon WLAN 7170 29.04.56 (May 1 2008) [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 8 [ 26]: Supported: 100rel,replaces [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 9 [ 35]: Allow-Events: telephone-event,refer [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 10 [ 85]: Allow: INVITE,ACK,OPTIONS,CANCEL,BYE,UPDATE,PRACK,INFO,SUBSCRIBE,NOTIFY,REFER,MESSAGE [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 11 [ 40]: Accept: application/sdp, multipart/mixed [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 12 [ 25]: Accept-Encoding: identity [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 13 [ 17]: Content-Length: 0 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Header 14 [ 0]: [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: = No match Their Call ID: 4d0e89031315b99012052f6e4ba87c3c@213.157.229.45 Their Tag Our tag: as11294d4c [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: = Found Their Call ID: 34afc0432bc594fc448043c02e8585be@10.255.255.1 Their Tag Our tag: as12c315e6 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #18614 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Stopping retransmission on '34afc0432bc594fc448043c02e8585be@10.255.255.1' of Request 102: Match Found [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: SIP TIMER: Not rescheduling id #18583:OPTIONS (Method 3) (No timer T1) [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 91.199.174.51:5060 [Aug 18 15:55:16] DEBUG[19084] chan_sip.c: Destroying SIP dialog 7f93b7991289ff151b2765301b61c1c2@213.157.229.45 [Aug 18 15:55:16] DEBUG[19084] devicestate.c: Notification of state change to be queued on device/channel SIP/voipy-glcr-390-peer [Aug 18 15:55:16] DEBUG[19067] devicestate.c: No provider found, checking channel drivers for SIP - voipy-glcr-390-peer [Aug 18 15:55:16] DEBUG[19067] chan_sip.c: Checking device state for peer voipy-glcr-390-peer [Aug 18 15:55:16] DEBUG[19067] devicestate.c: Changing state for SIP/voipy-glcr-390-peer - state 5 (Unavailable) [Aug 18 15:55:16] DEBUG[19083] app_queue.c: Device 'SIP/voipy-glcr-390-peer' changed to state '5' (Unavailable) but we don't care because they're not a member of any queue. [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: SIP TIMER: Not rescheduling id #18585:OPTIONS (Method 3) (No timer T1) [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 84.255.199.122:5060 [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: Destroying SIP dialog 39c5184e5b2138257aeb48950961ee6c@213.157.229.45 [Aug 18 15:55:17] DEBUG[19084] devicestate.c: Notification of state change to be queued on device/channel SIP/voipy-glcr-386-peer [Aug 18 15:55:17] DEBUG[19067] devicestate.c: No provider found, checking channel drivers for SIP - voipy-glcr-386-peer [Aug 18 15:55:17] DEBUG[19067] chan_sip.c: Checking device state for peer voipy-glcr-386-peer [Aug 18 15:55:17] DEBUG[19067] devicestate.c: Changing state for SIP/voipy-glcr-386-peer - state 5 (Unavailable) [Aug 18 15:55:17] DEBUG[19083] app_queue.c: Device 'SIP/voipy-glcr-386-peer' changed to state '5' (Unavailable) but we don't care because they're not a member of any queue. [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: SIP TIMER: Not rescheduling id #18600:OPTIONS (Method 3) (No timer T1) [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 193.77.187.53:5060 [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: SIP TIMER: Not rescheduling id #18590:OPTIONS (Method 3) (No timer T1) [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 193.170.18.21:5060 [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: Destroying SIP dialog 76a655a9797c9f74328d28353853df6e@213.157.229.45 [Aug 18 15:55:17] DEBUG[19084] devicestate.c: Notification of state change to be queued on device/channel SIP/voipy-glcr-384-peer [Aug 18 15:55:17] DEBUG[19067] devicestate.c: No provider found, checking channel drivers for SIP - voipy-glcr-384-peer [Aug 18 15:55:17] DEBUG[19067] chan_sip.c: Checking device state for peer voipy-glcr-384-peer [Aug 18 15:55:17] DEBUG[19067] devicestate.c: Changing state for SIP/voipy-glcr-384-peer - state 5 (Unavailable) [Aug 18 15:55:17] DEBUG[19083] app_queue.c: Device 'SIP/voipy-glcr-384-peer' changed to state '5' (Unavailable) but we don't care because they're not a member of any queue. [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP) [Aug 18 15:55:17] DEBUG[19084] acl.c: Found IP address for this socket [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: Target address 212.18.43.58 is not local, substituting externip [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: Initializing initreq for method OPTIONS - callid 7e7274fc2c1f456027fc9d024a307b10@213.157.229.45 [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: Header 0 [ 32]: OPTIONS sip:212.18.43.58 SIP/2.0 [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: Header 1 [ 65]: Via: SIP/2.0/UDP 213.157.229.45:5060;branch=z9hG4bK7115f572;rport [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: Header 3 [ 59]: From: "Unknown" ;tag=as2545f7c4 [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: Header 4 [ 22]: To: [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: Header 5 [ 37]: Contact: [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: Header 6 [ 56]: Call-ID: 7e7274fc2c1f456027fc9d024a307b10@213.157.229.45 [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: Header 7 [ 17]: CSeq: 102 OPTIONS [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: Header 8 [ 33]: User-Agent: Asterisk PBX 1.6.0.13 [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: Header 9 [ 35]: Date: Tue, 18 Aug 2009 13:55:17 GMT [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: Header 10 [ 66]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: Header 12 [ 17]: Content-Length: 0 [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #18623 [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 212.18.43.58:5060 [Aug 18 15:55:17] DEBUG[19793] rtp.c: Got RTCP report of 64 bytes [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: SIP TIMER: Not rescheduling id #18592:OPTIONS (Method 3) (No timer T1) [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 212.18.40.137:5060 [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: SIP TIMER: Not rescheduling id #18607:OPTIONS (Method 3) (No timer T1) [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 193.189.170.245:5060 [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP) [Aug 18 15:55:17] DEBUG[19084] acl.c: Found IP address for this socket [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: Target address 85.10.37.148 is not local, substituting externip [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: Initializing initreq for method OPTIONS - callid 67c8587a29b54d852bd3eeca68bfe8de@213.157.229.45 [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: Header 0 [ 32]: OPTIONS sip:85.10.37.148 SIP/2.0 [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: Header 1 [ 65]: Via: SIP/2.0/UDP 213.157.229.45:5060;branch=z9hG4bK74ca40be;rport [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: Header 3 [ 59]: From: "Unknown" ;tag=as31155d27 [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: Header 4 [ 22]: To: [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: Header 5 [ 37]: Contact: [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: Header 6 [ 56]: Call-ID: 67c8587a29b54d852bd3eeca68bfe8de@213.157.229.45 [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: Header 7 [ 17]: CSeq: 102 OPTIONS [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: Header 8 [ 33]: User-Agent: Asterisk PBX 1.6.0.13 [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: Header 9 [ 35]: Date: Tue, 18 Aug 2009 13:55:17 GMT [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: Header 10 [ 66]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: Header 12 [ 17]: Content-Length: 0 [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #18625 [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 85.10.37.148:5060 [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: SIP TIMER: Not rescheduling id #18594:OPTIONS (Method 3) (No timer T1) [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 195.5.164.230:5060 [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: Header 0 [ 0]: [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: SIP TIMER: Not rescheduling id #18609:OPTIONS (Method 3) (No timer T1) [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 194.249.239.5:5060 [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: SIP TIMER: Not rescheduling id #18596:OPTIONS (Method 3) (No timer T1) [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 193.77.191.78:5060 [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP) [Aug 18 15:55:17] DEBUG[19084] acl.c: Found IP address for this socket [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: Initializing initreq for method OPTIONS - callid 1116ec9c064b06522969108b7ab57159@10.255.255.1 [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: Header 0 [ 56]: OPTIONS sip:278@10.255.255.32:2048;line=w32yjny3 SIP/2.0 [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: Header 1 [ 63]: Via: SIP/2.0/UDP 10.255.255.1:5060;branch=z9hG4bK6370745d;rport [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: Header 3 [ 57]: From: "Unknown" ;tag=as0f53a88e [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: Header 4 [ 46]: To: [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: Header 5 [ 35]: Contact: [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: Header 6 [ 54]: Call-ID: 1116ec9c064b06522969108b7ab57159@10.255.255.1 [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: Header 7 [ 17]: CSeq: 102 OPTIONS [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: Header 8 [ 33]: User-Agent: Asterisk PBX 1.6.0.13 [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: Header 9 [ 35]: Date: Tue, 18 Aug 2009 13:55:17 GMT [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: Header 10 [ 66]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: Header 12 [ 17]: Content-Length: 0 [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #18627 [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 10.255.255.32:2048 [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: SIP TIMER: Not rescheduling id #18598:OPTIONS (Method 3) (No timer T1) [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 193.81.210.21:5060 [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: Header 1 [ 68]: Via: SIP/2.0/UDP 10.255.255.1:5060;branch=z9hG4bK6370745d;rport=5060 [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: Header 2 [ 57]: From: "Unknown" ;tag=as0f53a88e [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: Header 3 [ 46]: To: [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: Header 4 [ 54]: Call-ID: 1116ec9c064b06522969108b7ab57159@10.255.255.1 [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: Header 5 [ 17]: CSeq: 102 OPTIONS [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: Header 6 [ 61]: Contact: ;flow-id=1 [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: Header 7 [ 26]: User-Agent: snom320/7.1.30 [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: Header 8 [ 19]: Accept-Language: en [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: Header 9 [ 23]: Accept: application/sdp [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: Header 10 [ 88]: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: Header 11 [ 42]: Allow-Events: talk, hold, refer, call-info [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: Header 12 [ 44]: Supported: timer, 100rel, replaces, callerid [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: Header 13 [ 17]: Content-Length: 0 [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: Header 14 [ 0]: [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: = Found Their Call ID: 1116ec9c064b06522969108b7ab57159@10.255.255.1 Their Tag Our tag: as0f53a88e [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #18627 [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: Stopping retransmission on '1116ec9c064b06522969108b7ab57159@10.255.255.1' of Request 102: Match Found [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: SIP TIMER: Not rescheduling id #18617:OPTIONS (Method 3) (No timer T1) [Aug 18 15:55:17] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 81.189.215.197:5060 [Aug 18 15:55:18] DEBUG[19084] chan_sip.c: SIP TIMER: Not rescheduling id #18600:OPTIONS (Method 3) (No timer T1) [Aug 18 15:55:18] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 193.77.187.53:5060 [Aug 18 15:55:18] DEBUG[19084] chan_sip.c: SIP TIMER: Not rescheduling id #18623:OPTIONS (Method 3) (No timer T1) [Aug 18 15:55:18] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 212.18.43.58:5060 [Aug 18 15:55:18] DEBUG[19084] chan_sip.c: SIP TIMER: Not rescheduling id #18592:OPTIONS (Method 3) (No timer T1) [Aug 18 15:55:18] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 212.18.40.137:5060 [Aug 18 15:55:18] DEBUG[19084] chan_sip.c: Destroying SIP dialog 7b2aec6019d6d9d637c46485739dd790@213.157.229.45 [Aug 18 15:55:18] DEBUG[19084] devicestate.c: Notification of state change to be queued on device/channel SIP/voipy-glcr-341-peer [Aug 18 15:55:18] DEBUG[19067] devicestate.c: No provider found, checking channel drivers for SIP - voipy-glcr-341-peer [Aug 18 15:55:18] DEBUG[19067] chan_sip.c: Checking device state for peer voipy-glcr-341-peer [Aug 18 15:55:18] DEBUG[19067] devicestate.c: Changing state for SIP/voipy-glcr-341-peer - state 5 (Unavailable) [Aug 18 15:55:18] DEBUG[19083] app_queue.c: Device 'SIP/voipy-glcr-341-peer' changed to state '5' (Unavailable) but we don't care because they're not a member of any queue. [Aug 18 15:55:18] DEBUG[19084] chan_sip.c: SIP TIMER: Not rescheduling id #18607:OPTIONS (Method 3) (No timer T1) [Aug 18 15:55:18] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 193.189.170.245:5060 [Aug 18 15:55:18] DEBUG[19084] chan_sip.c: SIP TIMER: Not rescheduling id #18625:OPTIONS (Method 3) (No timer T1) [Aug 18 15:55:18] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 85.10.37.148:5060 [Aug 18 15:55:18] DEBUG[19084] chan_sip.c: SIP TIMER: Not rescheduling id #18594:OPTIONS (Method 3) (No timer T1) [Aug 18 15:55:18] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 195.5.164.230:5060 [Aug 18 15:55:18] DEBUG[19084] chan_sip.c: Destroying SIP dialog 437db39827cf14612bb8f83d7e3dd48d@213.157.229.45 [Aug 18 15:55:18] DEBUG[19084] devicestate.c: Notification of state change to be queued on device/channel SIP/voipy-glcr-345-peer [Aug 18 15:55:18] DEBUG[19067] devicestate.c: No provider found, checking channel drivers for SIP - voipy-glcr-345-peer [Aug 18 15:55:18] DEBUG[19067] chan_sip.c: Checking device state for peer voipy-glcr-345-peer [Aug 18 15:55:18] DEBUG[19067] devicestate.c: Changing state for SIP/voipy-glcr-345-peer - state 5 (Unavailable) [Aug 18 15:55:18] DEBUG[19083] app_queue.c: Device 'SIP/voipy-glcr-345-peer' changed to state '5' (Unavailable) but we don't care because they're not a member of any queue. [Aug 18 15:55:18] DEBUG[19084] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP) [Aug 18 15:55:18] DEBUG[19084] acl.c: Found IP address for this socket [Aug 18 15:55:18] DEBUG[19084] chan_sip.c: Initializing initreq for method OPTIONS - callid 637c0c3a3f4ad509228c902d4e4d069c@10.255.255.1 [Aug 18 15:55:18] DEBUG[19084] chan_sip.c: Header 0 [ 72]: OPTIONS sip:9115@10.255.255.4;uniq=78F3603963A5C89D0153CC7B40B9E SIP/2.0 [Aug 18 15:55:18] DEBUG[19084] chan_sip.c: Header 1 [ 63]: Via: SIP/2.0/UDP 10.255.255.1:5060;branch=z9hG4bK6d2c3160;rport [Aug 18 15:55:18] DEBUG[19084] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Aug 18 15:55:18] DEBUG[19084] chan_sip.c: Header 3 [ 57]: From: "Unknown" ;tag=as0f4908c4 [Aug 18 15:55:18] DEBUG[19084] chan_sip.c: Header 4 [ 62]: To: [Aug 18 15:55:18] DEBUG[19084] chan_sip.c: Header 5 [ 35]: Contact: [Aug 18 15:55:18] DEBUG[19084] chan_sip.c: Header 6 [ 54]: Call-ID: 637c0c3a3f4ad509228c902d4e4d069c@10.255.255.1 [Aug 18 15:55:18] DEBUG[19084] chan_sip.c: Header 7 [ 17]: CSeq: 102 OPTIONS [Aug 18 15:55:18] DEBUG[19084] chan_sip.c: Header 8 [ 33]: User-Agent: Asterisk PBX 1.6.0.13 [Aug 18 15:55:18] DEBUG[19084] chan_sip.c: Header 9 [ 35]: Date: Tue, 18 Aug 2009 13:55:18 GMT [Aug 18 15:55:18] DEBUG[19084] chan_sip.c: Header 10 [ 66]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY [Aug 18 15:55:18] DEBUG[19084] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [Aug 18 15:55:18] DEBUG[19084] chan_sip.c: Header 12 [ 17]: Content-Length: 0 [Aug 18 15:55:18] DEBUG[19084] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #18632 [Aug 18 15:55:18] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 10.255.255.4:5060 [Aug 18 15:55:18] DEBUG[19084] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [Aug 18 15:55:18] DEBUG[19084] chan_sip.c: Header 1 [ 90]: Via: SIP/2.0/UDP 10.255.255.1:5060;branch=z9hG4bK6d2c3160;rport=5060;received=10.255.255.1 [Aug 18 15:55:18] DEBUG[19084] chan_sip.c: Header 2 [ 57]: From: "Unknown" ;tag=as0f4908c4 [Aug 18 15:55:18] DEBUG[19084] chan_sip.c: Header 3 [ 83]: To: ;tag=148DEB710E89BDB5 [Aug 18 15:55:18] DEBUG[19084] chan_sip.c: Header 4 [ 54]: Call-ID: 637c0c3a3f4ad509228c902d4e4d069c@10.255.255.1 [Aug 18 15:55:18] DEBUG[19084] chan_sip.c: Header 5 [ 17]: CSeq: 102 OPTIONS [Aug 18 15:55:18] DEBUG[19084] chan_sip.c: Header 6 [ 67]: Contact: [Aug 18 15:55:18] DEBUG[19084] chan_sip.c: Header 7 [ 62]: User-Agent: AVM FRITZ!Box Fon WLAN 7050 14.04.26 (Sep 6 2006) [Aug 18 15:55:18] DEBUG[19084] chan_sip.c: Header 8 [ 26]: Supported: 100rel,replaces [Aug 18 15:55:18] DEBUG[19084] chan_sip.c: Header 9 [ 35]: Allow-Events: telephone-event,refer [Aug 18 15:55:18] DEBUG[19084] chan_sip.c: Header 10 [ 85]: Allow: INVITE,ACK,OPTIONS,CANCEL,BYE,UPDATE,PRACK,INFO,SUBSCRIBE,NOTIFY,REFER,MESSAGE [Aug 18 15:55:18] DEBUG[19084] chan_sip.c: Header 11 [ 40]: Accept: application/sdp, multipart/mixed [Aug 18 15:55:18] DEBUG[19084] chan_sip.c: Header 12 [ 25]: Accept-Encoding: identity [Aug 18 15:55:18] DEBUG[19084] chan_sip.c: Header 13 [ 17]: Content-Length: 0 [Aug 18 15:55:18] DEBUG[19084] chan_sip.c: Header 14 [ 0]: [Aug 18 15:55:18] DEBUG[19084] chan_sip.c: = Found Their Call ID: 637c0c3a3f4ad509228c902d4e4d069c@10.255.255.1 Their Tag Our tag: as0f4908c4 [Aug 18 15:55:18] DEBUG[19084] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #18632 [Aug 18 15:55:18] DEBUG[19084] chan_sip.c: Stopping retransmission on '637c0c3a3f4ad509228c902d4e4d069c@10.255.255.1' of Request 102: Match Found [Aug 18 15:55:18] DEBUG[19084] chan_sip.c: SIP TIMER: Not rescheduling id #18609:OPTIONS (Method 3) (No timer T1) [Aug 18 15:55:18] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 194.249.239.5:5060 [Aug 18 15:55:18] DEBUG[19084] chan_sip.c: SIP TIMER: Not rescheduling id #18596:OPTIONS (Method 3) (No timer T1) [Aug 18 15:55:18] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 193.77.191.78:5060 [Aug 18 15:55:18] DEBUG[19084] chan_sip.c: Destroying SIP dialog 57a9cfcd6d3527b7029118250cbbb69c@213.157.229.45 [Aug 18 15:55:18] DEBUG[19084] devicestate.c: Notification of state change to be queued on device/channel SIP/voipy-glcr-290-peer [Aug 18 15:55:18] DEBUG[19067] devicestate.c: No provider found, checking channel drivers for SIP - voipy-glcr-290-peer [Aug 18 15:55:18] DEBUG[19067] chan_sip.c: Checking device state for peer voipy-glcr-290-peer [Aug 18 15:55:18] DEBUG[19067] devicestate.c: Changing state for SIP/voipy-glcr-290-peer - state 5 (Unavailable) [Aug 18 15:55:18] DEBUG[19083] app_queue.c: Device 'SIP/voipy-glcr-290-peer' changed to state '5' (Unavailable) but we don't care because they're not a member of any queue. [Aug 18 15:55:18] DEBUG[19084] chan_sip.c: SIP TIMER: Not rescheduling id #18598:OPTIONS (Method 3) (No timer T1) [Aug 18 15:55:18] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 193.81.210.21:5060 [Aug 18 15:55:18] DEBUG[19084] chan_sip.c: SIP TIMER: Not rescheduling id #18617:OPTIONS (Method 3) (No timer T1) [Aug 18 15:55:18] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 81.189.215.197:5060 [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: SIP TIMER: Not rescheduling id #18600:OPTIONS (Method 3) (No timer T1) [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 193.77.187.53:5060 [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: SIP TIMER: Not rescheduling id #18623:OPTIONS (Method 3) (No timer T1) [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 212.18.43.58:5060 [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: SIP TIMER: Not rescheduling id #18607:OPTIONS (Method 3) (No timer T1) [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 193.189.170.245:5060 [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: SIP TIMER: Not rescheduling id #18625:OPTIONS (Method 3) (No timer T1) [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 85.10.37.148:5060 [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP) [Aug 18 15:55:19] DEBUG[19084] acl.c: Found IP address for this socket [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: Initializing initreq for method OPTIONS - callid 7da32c630d74305e5c9e2b18715d22c0@10.255.255.1 [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: Header 0 [ 56]: OPTIONS sip:344@10.255.255.85:2048;line=02dyi3xv SIP/2.0 [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: Header 1 [ 63]: Via: SIP/2.0/UDP 10.255.255.1:5060;branch=z9hG4bK13fdc5c4;rport [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: Header 3 [ 57]: From: "Unknown" ;tag=as0c4788a9 [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: Header 4 [ 46]: To: [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: Header 5 [ 35]: Contact: [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: Header 6 [ 54]: Call-ID: 7da32c630d74305e5c9e2b18715d22c0@10.255.255.1 [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: Header 7 [ 17]: CSeq: 102 OPTIONS [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: Header 8 [ 33]: User-Agent: Asterisk PBX 1.6.0.13 [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: Header 9 [ 35]: Date: Tue, 18 Aug 2009 13:55:19 GMT [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: Header 10 [ 66]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: Header 12 [ 17]: Content-Length: 0 [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #18636 [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 10.255.255.85:2048 [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: Header 0 [ 14]: SIP/2.0 200 OK [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: Header 1 [ 68]: Via: SIP/2.0/UDP 10.255.255.1:5060;branch=z9hG4bK13fdc5c4;rport=5060 [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: Header 2 [ 57]: From: "Unknown" ;tag=as0c4788a9 [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: Header 3 [ 46]: To: [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: Header 4 [ 54]: Call-ID: 7da32c630d74305e5c9e2b18715d22c0@10.255.255.1 [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: Header 5 [ 17]: CSeq: 102 OPTIONS [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: Header 6 [ 61]: Contact: ;flow-id=1 [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: Header 7 [ 26]: User-Agent: snom320/7.1.30 [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: Header 8 [ 19]: Accept-Language: en [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: Header 9 [ 23]: Accept: application/sdp [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: Header 10 [ 88]: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: Header 11 [ 42]: Allow-Events: talk, hold, refer, call-info [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: Header 12 [ 44]: Supported: timer, 100rel, replaces, callerid [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: Header 13 [ 17]: Content-Length: 0 [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: Header 14 [ 0]: [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: = Found Their Call ID: 7da32c630d74305e5c9e2b18715d22c0@10.255.255.1 Their Tag Our tag: as0c4788a9 [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #18636 [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: Stopping retransmission on '7da32c630d74305e5c9e2b18715d22c0@10.255.255.1' of Request 102: Match Found [Aug 18 15:55:19] VERBOSE[19084] logger.c: <--- SIP read from UDP://10.22.11.20:5060 ---> SIP/2.0 183 In band info available Allow: UPDATE,INFO,REFER,INVITE,ACK,OPTIONS,REGISTER,SUBSCRIBE,MESSAGE,NOTIFY,BYE,CANCEL,PRACK Call-ID: 0f1e533008905417497809f127add60f@10.61.16.2 Contact: Content-Type: application/sdp CSeq: 105 INVITE From: "Kocbek Milos" ;tag=as09d56ebc Server: Cirpack/v4.42d (gw_sip) To: ;tag=02-08127-008d3412-2d267be81 Via: SIP/2.0/UDP 10.61.16.2:5060;received=10.61.16.2;rport=5060;branch=z9hG4bK74046586 Content-Length: 207 v=0 o=cp10 125060371921 125060371921 IN IP4 10.22.12.21 s=SIP Call c=IN IP4 10.22.12.21 t=0 0 m=audio 30918 RTP/AVP 8 0 b=AS:64 a=rtpmap:8 PCMA/8000/1 a=rtpmap:0 PCMU/8000/1 a=ptime:20 a=sendrecv <-------------> [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: Header 0 [ 34]: SIP/2.0 183 In band info available [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: Header 1 [ 94]: Allow: UPDATE,INFO,REFER,INVITE,ACK,OPTIONS,REGISTER,SUBSCRIBE,MESSAGE,NOTIFY,BYE,CANCEL,PRACK [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: Header 2 [ 52]: Call-ID: 0f1e533008905417497809f127add60f@10.61.16.2 [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: Header 3 [ 31]: Contact: [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: Header 4 [ 29]: Content-Type: application/sdp [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: Header 5 [ 16]: CSeq: 105 INVITE [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: Header 6 [ 62]: From: "Kocbek Milos" ;tag=as09d56ebc [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: Header 7 [ 31]: Server: Cirpack/v4.42d (gw_sip) [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: Header 8 [ 58]: To: ;tag=02-08127-008d3412-2d267be81 [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: Header 9 [ 86]: Via: SIP/2.0/UDP 10.61.16.2:5060;received=10.61.16.2;rport=5060;branch=z9hG4bK74046586 [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: Header 10 [ 19]: Content-Length: 207 [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: Header 11 [ 0]: [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: Body 0 [ 3]: v=0 [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: Body 1 [ 51]: o=cp10 125060371921 125060371921 IN IP4 10.22.12.21 [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: Body 2 [ 10]: s=SIP Call [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: Body 3 [ 20]: c=IN IP4 10.22.12.21 [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: Body 4 [ 5]: t=0 0 [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: Body 5 [ 25]: m=audio 30918 RTP/AVP 8 0 [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: Body 6 [ 7]: b=AS:64 [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: Body 7 [ 22]: a=rtpmap:8 PCMA/8000/1 [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: Body 8 [ 22]: a=rtpmap:0 PCMU/8000/1 [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: Body 9 [ 10]: a=ptime:20 [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: Body 10 [ 10]: a=sendrecv [Aug 18 15:55:19] VERBOSE[19084] logger.c: --- (11 headers 11 lines) --- [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: = No match Their Call ID: 67c8587a29b54d852bd3eeca68bfe8de@213.157.229.45 Their Tag Our tag: as31155d27 [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: = No match Their Call ID: 7e7274fc2c1f456027fc9d024a307b10@213.157.229.45 Their Tag Our tag: as2545f7c4 [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: = No match Their Call ID: 4d0e89031315b99012052f6e4ba87c3c@213.157.229.45 Their Tag Our tag: as11294d4c [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: = No match Their Call ID: 822F1077AB3D5774@10.255.255.12 Their Tag 4085710466 Our tag: as2a381f21 [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: = No match Their Call ID: 2d6a4c966e19053201d988cd43fbf291@213.157.229.45 Their Tag Our tag: as46e507e8 [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: = No match Their Call ID: 58dbb3c276c425c3198213c252b712db@213.157.229.45 Their Tag Our tag: as2b34fce9 [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: = No match Their Call ID: 4fcbca65142c9f242925d12479b8abc4@213.157.229.45 Their Tag Our tag: as4d859912 [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: = No match Their Call ID: 22efe23b015ae7cf627d42347521b984@213.157.229.45 Their Tag Our tag: as1fc555d6 [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: = Found Their Call ID: 0f1e533008905417497809f127add60f@10.61.16.2 Their Tag 02-08067-008d3349-65e715141 Our tag: as09d56ebc [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '0f1e533008905417497809f127add60f@10.61.16.2' Request 105: Found [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: SIP response 183 to RE-invite on outgoing call 0f1e533008905417497809f127add60f@10.61.16.2 [Aug 18 15:55:19] VERBOSE[19084] logger.c: Found RTP audio format 8 [Aug 18 15:55:19] VERBOSE[19084] logger.c: Found RTP audio format 0 [Aug 18 15:55:19] VERBOSE[19084] logger.c: Peer audio RTP is at port 10.22.12.21:30918 [Aug 18 15:55:19] VERBOSE[19084] logger.c: Found audio description format PCMA for ID 8 [Aug 18 15:55:19] VERBOSE[19084] logger.c: Found audio description format PCMU for ID 0 [Aug 18 15:55:19] VERBOSE[19084] logger.c: Capabilities: us - 0xc (ulaw|alaw), peer - audio=0xc (ulaw|alaw)/video=0x0 (nothing)/text=0x0 (nothing), combined - 0xc (ulaw|alaw) [Aug 18 15:55:19] VERBOSE[19084] logger.c: Non-codec capabilities (dtmf): us - 0x0 (nothing), peer - 0x0 (nothing), combined - 0x0 (nothing) [Aug 18 15:55:19] VERBOSE[19084] logger.c: Peer audio RTP is at port 10.22.12.21:30918 [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: We're settling with these formats: 0xc (ulaw|alaw) [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: We have an owner, now see if we need to change this call [Aug 18 15:55:19] DEBUG[19793] channel.c: Got a FRAME_CONTROL (14) frame on channel SIP/VOIP_AMIS-peer-082c0d28 [Aug 18 15:55:19] DEBUG[19793] channel.c: Bridge stops bridging channels SIP/91.199.174.215-082ab508 and SIP/VOIP_AMIS-peer-082c0d28 [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: SIP TIMER: Not rescheduling id #18609:OPTIONS (Method 3) (No timer T1) [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 194.249.239.5:5060 [Aug 18 15:55:19] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:19] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:19] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:19] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:19] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:19] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:19] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: SIP TIMER: Not rescheduling id #18598:OPTIONS (Method 3) (No timer T1) [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 193.81.210.21:5060 [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: Destroying SIP dialog 22efe23b015ae7cf627d42347521b984@213.157.229.45 [Aug 18 15:55:19] DEBUG[19084] devicestate.c: Notification of state change to be queued on device/channel SIP/voipy-glcr-265-peer [Aug 18 15:55:19] DEBUG[19067] devicestate.c: No provider found, checking channel drivers for SIP - voipy-glcr-265-peer [Aug 18 15:55:19] DEBUG[19067] chan_sip.c: Checking device state for peer voipy-glcr-265-peer [Aug 18 15:55:19] DEBUG[19067] devicestate.c: Changing state for SIP/voipy-glcr-265-peer - state 5 (Unavailable) [Aug 18 15:55:19] DEBUG[19083] app_queue.c: Device 'SIP/voipy-glcr-265-peer' changed to state '5' (Unavailable) but we don't care because they're not a member of any queue. [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP) [Aug 18 15:55:19] DEBUG[19084] acl.c: Found IP address for this socket [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: Target address 213.249.97.123 is not local, substituting externip [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: Initializing initreq for method OPTIONS - callid 249e8ee6338ec9223db55b37656c8619@213.157.229.45 [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: Header 0 [ 34]: OPTIONS sip:213.249.97.123 SIP/2.0 [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: Header 1 [ 65]: Via: SIP/2.0/UDP 213.157.229.45:5060;branch=z9hG4bK7ba7d5b8;rport [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: Header 2 [ 16]: Max-Forwards: 70 [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: Header 3 [ 59]: From: "Unknown" ;tag=as6e50740b [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: Header 4 [ 24]: To: [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: Header 5 [ 37]: Contact: [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: Header 6 [ 56]: Call-ID: 249e8ee6338ec9223db55b37656c8619@213.157.229.45 [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: Header 7 [ 17]: CSeq: 102 OPTIONS [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: Header 8 [ 33]: User-Agent: Asterisk PBX 1.6.0.13 [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: Header 9 [ 35]: Date: Tue, 18 Aug 2009 13:55:19 GMT [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: Header 10 [ 66]: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: Header 11 [ 26]: Supported: replaces, timer [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: Header 12 [ 17]: Content-Length: 0 [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #18640 [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 213.249.97.123:5060 [Aug 18 15:55:19] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:19] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:19] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:19] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:19] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:19] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:19] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:19] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: SIP TIMER: Not rescheduling id #18617:OPTIONS (Method 3) (No timer T1) [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 81.189.215.197:5060 [Aug 18 15:55:19] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:19] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:19] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:19] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:19] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:19] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: Auto destroying SIP dialog '3c26701b61b7-99pfm3a5uxii' [Aug 18 15:55:19] DEBUG[19084] chan_sip.c: Destroying SIP dialog 3c26701b61b7-99pfm3a5uxii [Aug 18 15:55:19] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19084] chan_sip.c: SIP TIMER: Not rescheduling id #18600:OPTIONS (Method 3) (No timer T1) [Aug 18 15:55:20] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 193.77.187.53:5060 [Aug 18 15:55:20] DEBUG[19084] chan_sip.c: Destroying SIP dialog 4fcbca65142c9f242925d12479b8abc4@213.157.229.45 [Aug 18 15:55:20] DEBUG[19084] devicestate.c: Notification of state change to be queued on device/channel SIP/voipy-glcr-231-peer [Aug 18 15:55:20] DEBUG[19067] devicestate.c: No provider found, checking channel drivers for SIP - voipy-glcr-231-peer [Aug 18 15:55:20] DEBUG[19067] chan_sip.c: Checking device state for peer voipy-glcr-231-peer [Aug 18 15:55:20] DEBUG[19067] devicestate.c: Changing state for SIP/voipy-glcr-231-peer - state 5 (Unavailable) [Aug 18 15:55:20] DEBUG[19083] app_queue.c: Device 'SIP/voipy-glcr-231-peer' changed to state '5' (Unavailable) but we don't care because they're not a member of any queue. [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19084] chan_sip.c: SIP TIMER: Not rescheduling id #18623:OPTIONS (Method 3) (No timer T1) [Aug 18 15:55:20] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 212.18.43.58:5060 [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19084] chan_sip.c: SIP TIMER: Not rescheduling id #18607:OPTIONS (Method 3) (No timer T1) [Aug 18 15:55:20] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 193.189.170.245:5060 [Aug 18 15:55:20] DEBUG[19084] chan_sip.c: Destroying SIP dialog 58dbb3c276c425c3198213c252b712db@213.157.229.45 [Aug 18 15:55:20] DEBUG[19084] devicestate.c: Notification of state change to be queued on device/channel SIP/voipy-glcr-218-peer [Aug 18 15:55:20] DEBUG[19067] devicestate.c: No provider found, checking channel drivers for SIP - voipy-glcr-218-peer [Aug 18 15:55:20] DEBUG[19067] chan_sip.c: Checking device state for peer voipy-glcr-218-peer [Aug 18 15:55:20] DEBUG[19067] devicestate.c: Changing state for SIP/voipy-glcr-218-peer - state 5 (Unavailable) [Aug 18 15:55:20] DEBUG[19083] app_queue.c: Device 'SIP/voipy-glcr-218-peer' changed to state '5' (Unavailable) but we don't care because they're not a member of any queue. [Aug 18 15:55:20] DEBUG[19084] chan_sip.c: SIP TIMER: Not rescheduling id #18625:OPTIONS (Method 3) (No timer T1) [Aug 18 15:55:20] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 85.10.37.148:5060 [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19084] chan_sip.c: SIP TIMER: Not rescheduling id #18609:OPTIONS (Method 3) (No timer T1) [Aug 18 15:55:20] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 194.249.239.5:5060 [Aug 18 15:55:20] DEBUG[19084] chan_sip.c: Destroying SIP dialog 2d6a4c966e19053201d988cd43fbf291@213.157.229.45 [Aug 18 15:55:20] DEBUG[19084] devicestate.c: Notification of state change to be queued on device/channel SIP/voipy-glcr-194-peer [Aug 18 15:55:20] DEBUG[19067] devicestate.c: No provider found, checking channel drivers for SIP - voipy-glcr-194-peer [Aug 18 15:55:20] DEBUG[19067] chan_sip.c: Checking device state for peer voipy-glcr-194-peer [Aug 18 15:55:20] DEBUG[19067] devicestate.c: Changing state for SIP/voipy-glcr-194-peer - state 5 (Unavailable) [Aug 18 15:55:20] DEBUG[19083] app_queue.c: Device 'SIP/voipy-glcr-194-peer' changed to state '5' (Unavailable) but we don't care because they're not a member of any queue. [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19084] chan_sip.c: SIP TIMER: Not rescheduling id #18640:OPTIONS (Method 3) (No timer T1) [Aug 18 15:55:20] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 213.249.97.123:5060 [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19084] chan_sip.c: SIP TIMER: Not rescheduling id #18617:OPTIONS (Method 3) (No timer T1) [Aug 18 15:55:20] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 81.189.215.197:5060 [Aug 18 15:55:20] DEBUG[19084] chan_sip.c: Destroying SIP dialog 4d0e89031315b99012052f6e4ba87c3c@213.157.229.45 [Aug 18 15:55:20] DEBUG[19084] devicestate.c: Notification of state change to be queued on device/channel SIP/voipy-glcr-156-peer [Aug 18 15:55:20] DEBUG[19067] devicestate.c: No provider found, checking channel drivers for SIP - voipy-glcr-156-peer [Aug 18 15:55:20] DEBUG[19067] chan_sip.c: Checking device state for peer voipy-glcr-156-peer [Aug 18 15:55:20] DEBUG[19067] devicestate.c: Changing state for SIP/voipy-glcr-156-peer - state 5 (Unavailable) [Aug 18 15:55:20] DEBUG[19083] app_queue.c: Device 'SIP/voipy-glcr-156-peer' changed to state '5' (Unavailable) but we don't care because they're not a member of any queue. [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:20] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19084] chan_sip.c: SIP TIMER: Not rescheduling id #18623:OPTIONS (Method 3) (No timer T1) [Aug 18 15:55:21] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 212.18.43.58:5060 [Aug 18 15:55:21] DEBUG[19084] chan_sip.c: Destroying SIP dialog 7e7274fc2c1f456027fc9d024a307b10@213.157.229.45 [Aug 18 15:55:21] DEBUG[19084] devicestate.c: Notification of state change to be queued on device/channel SIP/voipy-glcr-277-peer [Aug 18 15:55:21] DEBUG[19067] devicestate.c: No provider found, checking channel drivers for SIP - voipy-glcr-277-peer [Aug 18 15:55:21] DEBUG[19067] chan_sip.c: Checking device state for peer voipy-glcr-277-peer [Aug 18 15:55:21] DEBUG[19067] devicestate.c: Changing state for SIP/voipy-glcr-277-peer - state 5 (Unavailable) [Aug 18 15:55:21] DEBUG[19083] app_queue.c: Device 'SIP/voipy-glcr-277-peer' changed to state '5' (Unavailable) but we don't care because they're not a member of any queue. [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19084] chan_sip.c: SIP TIMER: Not rescheduling id #18625:OPTIONS (Method 3) (No timer T1) [Aug 18 15:55:21] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 85.10.37.148:5060 [Aug 18 15:55:21] DEBUG[19084] chan_sip.c: Destroying SIP dialog 67c8587a29b54d852bd3eeca68bfe8de@213.157.229.45 [Aug 18 15:55:21] DEBUG[19084] devicestate.c: Notification of state change to be queued on device/channel SIP/voipy-glcr-334-peer [Aug 18 15:55:21] DEBUG[19067] devicestate.c: No provider found, checking channel drivers for SIP - voipy-glcr-334-peer [Aug 18 15:55:21] DEBUG[19067] chan_sip.c: Checking device state for peer voipy-glcr-334-peer [Aug 18 15:55:21] DEBUG[19067] devicestate.c: Changing state for SIP/voipy-glcr-334-peer - state 5 (Unavailable) [Aug 18 15:55:21] DEBUG[19083] app_queue.c: Device 'SIP/voipy-glcr-334-peer' changed to state '5' (Unavailable) but we don't care because they're not a member of any queue. [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19084] chan_sip.c: SIP TIMER: Not rescheduling id #18640:OPTIONS (Method 3) (No timer T1) [Aug 18 15:55:21] DEBUG[19084] chan_sip.c: Trying to put 'OPTIONS si' onto UDP socket destined for 213.249.97.123:5060 [Aug 18 15:55:21] DEBUG[19084] chan_sip.c: Header 0 [ 0]: [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:21] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:22] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:22] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:22] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:22] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:22] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:22] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:22] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:22] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:22] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:22] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:22] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:22] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:22] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:22] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:22] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:22] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:22] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:22] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:22] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:22] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:22] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:22] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:22] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:22] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:22] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:22] DEBUG[19793] rtp.c: Got RTCP report of 64 bytes [Aug 18 15:55:22] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:22] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:22] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:22] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:22] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:22] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:22] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:22] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:22] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:22] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:22] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:22] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:22] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:22] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:22] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:22] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:22] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:22] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:22] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:22] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:22] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:22] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:22] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed [Aug 18 15:55:22] DEBUG[19793] rtp.c: Forcing Marker bit, because SSRC has changed