Dec 8 12:07:32 DEBUG[5929] chan_zap.c: Monitor doohicky got event Ring Begin on channel 3 Dec 8 12:07:34 DEBUG[5929] chan_zap.c: Monitor doohicky got event Polarity Reversal on channel 3 Dec 8 12:07:35 DEBUG[5929] chan_zap.c: Monitor doohicky got event Ring/Answered on channel 3 Dec 8 12:07:35 DEBUG[5922] devicestate.c: Changing state for Zap/3 - state 2 (In use) Dec 8 12:07:36 DEBUG[5980] chan_zap.c: CallerID number: 5106041769, name: CHAN WILSON , flags=0 Dec 8 12:07:36 DEBUG[5980] pbx.c: Launching 'Wait' Dec 8 12:07:36 DEBUG[5980] chan_zap.c: Exception on 21, channel 3 Dec 8 12:07:36 DEBUG[5980] chan_zap.c: Got event Polarity Reversal(17) on channel 3 (index 0) Dec 8 12:07:36 DEBUG[5980] chan_zap.c: Ignore switch to REVERSED Polarity on channel 3, state 4 Dec 8 12:07:36 DEBUG[5980] chan_zap.c: Ignoring Polarity switch to IDLE on channel 3, state 4 Dec 8 12:07:36 DEBUG[5980] chan_zap.c: Polarity Reversal event occured - DEBUG 2: channel 3, state 4, pol= 0, aonp= 0, honp= 0, pdelay= 600, tv= 201090181 Dec 8 12:07:37 DEBUG[5980] pbx.c: Expression result is '0' Dec 8 12:07:37 DEBUG[5980] pbx.c: Launching 'GotoIf' Dec 8 12:07:37 DEBUG[5980] pbx.c: Not taking any branch Dec 8 12:07:37 DEBUG[5980] pbx.c: Launching 'LDAPget' Dec 8 12:07:37 DEBUG[5980] config.c: Parsing /etc/asterisk/ldap.conf Dec 8 12:07:37 DEBUG[5980] pbx.c: Expression result is '0' Dec 8 12:07:37 DEBUG[5980] pbx.c: Launching 'GotoIf' Dec 8 12:07:37 DEBUG[5980] pbx.c: Not taking any branch Dec 8 12:07:37 DEBUG[5980] pbx.c: Launching 'Set' Dec 8 12:07:37 DEBUG[5980] pbx.c: Launching 'Set' Dec 8 12:07:37 DEBUG[5980] pbx.c: Launching 'Dial' Dec 8 12:07:37 DEBUG[5980] channel.c: Not copying variable STACK-home-incoming-s-7. Dec 8 12:07:37 DEBUG[5980] channel.c: Not copying variable STACK-home-incoming-s-6. Dec 8 12:07:37 DEBUG[5980] channel.c: Not copying variable STACK-home-incoming-s-5. Dec 8 12:07:37 DEBUG[5980] channel.c: Not copying variable STACK-home-incoming-s-4. Dec 8 12:07:37 DEBUG[5980] channel.c: Not copying variable CIDNAME. Dec 8 12:07:37 DEBUG[5980] channel.c: Not copying variable STACK-home-incoming-s-3. Dec 8 12:07:37 DEBUG[5980] channel.c: Not copying variable STACK-home-incoming-s-2. Dec 8 12:07:37 DEBUG[5980] channel.c: Not copying variable STACK-home-incoming-s-1. Dec 8 12:07:37 DEBUG[5980] channel.c: Not copying variable TRANSFERCAPABILITY. Dec 8 12:07:37 DEBUG[5980] channel.c: Not copying variable STACK-home-incoming-s-7. Dec 8 12:07:37 DEBUG[5980] channel.c: Not copying variable STACK-home-incoming-s-6. Dec 8 12:07:37 DEBUG[5980] channel.c: Not copying variable STACK-home-incoming-s-5. Dec 8 12:07:37 DEBUG[5980] channel.c: Not copying variable STACK-home-incoming-s-4. Dec 8 12:07:37 DEBUG[5980] channel.c: Not copying variable CIDNAME. Dec 8 12:07:37 DEBUG[5980] channel.c: Not copying variable STACK-home-incoming-s-3. Dec 8 12:07:37 DEBUG[5980] channel.c: Not copying variable STACK-home-incoming-s-2. Dec 8 12:07:37 DEBUG[5980] channel.c: Not copying variable STACK-home-incoming-s-1. Dec 8 12:07:37 DEBUG[5980] channel.c: Not copying variable TRANSFERCAPABILITY. Dec 8 12:07:37 DEBUG[5922] devicestate.c: Changing state for Local/1@two-rings - state 2 (In use) Dec 8 12:07:37 DEBUG[5922] devicestate.c: Changing state for Local/2@two-rings - state 2 (In use) Dec 8 12:07:37 DEBUG[5981] pbx.c: Launching 'Dial' Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP) Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Setting NAT on RTP to 0 Dec 8 12:07:37 DEBUG[5981] channel.c: Not copying variable STACK-two-rings-1-1. Dec 8 12:07:37 DEBUG[5981] channel.c: Not copying variable DIALEDPEERNUMBER. Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Outgoing Call for wilson-polycom Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Updating call counter for outgoing call Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Header 0: INVITE sip:wilson-polycom@10.1.1.200 SIP/2.0 (44) Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.1.1.48:5060;branch=z9hG4bK7a60e001;rport (60) Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Header 2: From: "Wilson J. Chan" ;tag=as7df987c3 (66) Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Header 3: To: (35) Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Header 4: Contact: (37) Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Header 5: Call-ID: 05fcc4ea5c3c98dc42ea19752005ef30@10.1.1.48 (51) Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Header 6: CSeq: 102 INVITE (16) Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Header 7: User-Agent: Asterisk PBX (24) Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Header 8: Max-Forwards: 70 (16) Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Header 9: Date: Thu, 08 Dec 2005 20:07:37 GMT (35) Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Header 11: Content-Type: application/sdp (29) Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Header 12: Content-Length: 279 (19) Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Header 13: (0) Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Line: v=0 (3) Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Line: o=root 5918 5918 IN IP4 10.1.1.48 (33) Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Line: s=session (9) Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Line: c=IN IP4 10.1.1.48 (18) Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Line: t=0 0 (5) Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Line: m=audio 17668 RTP/AVP 0 8 18 101 (32) Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Line: a=rtpmap:0 PCMU/8000 (20) Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Line: a=rtpmap:8 PCMA/8000 (20) Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Line: a=rtpmap:18 G729/8000 (21) Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Line: a=fmtp:18 annexb=no (19) Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33) Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Line: a=fmtp:101 0-16 (15) Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Line: a=silenceSupp:off - - - - (25) Dec 8 12:07:37 DEBUG[5981] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #40 Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP) Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Setting NAT on RTP to 0 Dec 8 12:07:37 DEBUG[5981] channel.c: Not copying variable STACK-two-rings-1-1. Dec 8 12:07:37 DEBUG[5981] channel.c: Not copying variable DIALEDPEERNUMBER. Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Outgoing Call for scott-polycom Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Updating call counter for outgoing call Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Header 0: INVITE sip:scott-polycom@10.1.1.201 SIP/2.0 (43) Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.1.1.48:5060;branch=z9hG4bK697bd9f5;rport (60) Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Header 2: From: "Wilson J. Chan" ;tag=as504acb4a (66) Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Header 3: To: (34) Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Header 4: Contact: (37) Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Header 5: Call-ID: 0d0efafd3d2830ca6a1cf321103887ee@10.1.1.48 (51) Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Header 6: CSeq: 102 INVITE (16) Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Header 7: User-Agent: Asterisk PBX (24) Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Header 8: Max-Forwards: 70 (16) Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Header 9: Date: Thu, 08 Dec 2005 20:07:37 GMT (35) Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Header 11: Content-Type: application/sdp (29) Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Header 12: Content-Length: 279 (19) Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Header 13: (0) Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Line: v=0 (3) Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Line: o=root 5918 5918 IN IP4 10.1.1.48 (33) Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Line: s=session (9) Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Line: c=IN IP4 10.1.1.48 (18) Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Line: t=0 0 (5) Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Line: m=audio 19488 RTP/AVP 0 8 18 101 (32) Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Line: a=rtpmap:0 PCMU/8000 (20) Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Line: a=rtpmap:8 PCMA/8000 (20) Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Line: a=rtpmap:18 G729/8000 (21) Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Line: a=fmtp:18 annexb=no (19) Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33) Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Line: a=fmtp:101 0-16 (15) Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Line: a=silenceSupp:off - - - - (25) Dec 8 12:07:37 DEBUG[5981] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #41 Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP) Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Setting NAT on RTP to 0 Dec 8 12:07:37 DEBUG[5981] channel.c: Not copying variable STACK-two-rings-1-1. Dec 8 12:07:37 DEBUG[5981] channel.c: Not copying variable DIALEDPEERNUMBER. Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Outgoing Call for kitchen-polycom Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Updating call counter for outgoing call Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Header 0: INVITE sip:kitchen-polycom@10.1.1.204 SIP/2.0 (45) Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.1.1.48:5060;branch=z9hG4bK09ff7720;rport (60) Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Header 2: From: "Wilson J. Chan" ;tag=as0c63514f (66) Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Header 3: To: (36) Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Header 4: Contact: (37) Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Header 5: Call-ID: 19aee4ca7200b461231abe1b5b278d3a@10.1.1.48 (51) Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Header 6: CSeq: 102 INVITE (16) Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Header 7: User-Agent: Asterisk PBX (24) Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Header 8: Max-Forwards: 70 (16) Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Header 9: Date: Thu, 08 Dec 2005 20:07:37 GMT (35) Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Header 11: Content-Type: application/sdp (29) Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Header 12: Content-Length: 279 (19) Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Header 13: (0) Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Line: v=0 (3) Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Line: o=root 5918 5918 IN IP4 10.1.1.48 (33) Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Line: s=session (9) Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Line: c=IN IP4 10.1.1.48 (18) Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Line: t=0 0 (5) Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Line: m=audio 18404 RTP/AVP 0 8 18 101 (32) Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Line: a=rtpmap:0 PCMU/8000 (20) Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Line: a=rtpmap:8 PCMA/8000 (20) Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Line: a=rtpmap:18 G729/8000 (21) Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Line: a=fmtp:18 annexb=no (19) Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33) Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Line: a=fmtp:101 0-16 (15) Dec 8 12:07:37 DEBUG[5981] chan_sip.c: Line: a=silenceSupp:off - - - - (25) Dec 8 12:07:37 DEBUG[5981] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #42 Dec 8 12:07:37 DEBUG[5982] pbx.c: Launching 'Set' Dec 8 12:07:37 DEBUG[5982] pbx.c: Launching 'Dial' Dec 8 12:07:37 DEBUG[5982] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP) Dec 8 12:07:37 DEBUG[5982] chan_sip.c: Setting NAT on RTP to 0 Dec 8 12:07:37 DEBUG[5982] channel.c: Not copying variable STACK-two-rings-2-2. Dec 8 12:07:37 DEBUG[5982] channel.c: Copying soft-transferable variable ALERT_INFO. Dec 8 12:07:37 DEBUG[5982] channel.c: Not copying variable STACK-two-rings-2-1. Dec 8 12:07:37 DEBUG[5982] channel.c: Not copying variable DIALEDPEERNUMBER. Dec 8 12:07:37 DEBUG[5982] chan_sip.c: Outgoing Call for theater-polycom Dec 8 12:07:37 DEBUG[5982] chan_sip.c: Updating call counter for outgoing call Dec 8 12:07:37 DEBUG[5982] chan_sip.c: Header 0: INVITE sip:theater-polycom@10.1.1.203 SIP/2.0 (45) Dec 8 12:07:37 DEBUG[5982] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.1.1.48:5060;branch=z9hG4bK2128d34a;rport (60) Dec 8 12:07:37 DEBUG[5982] chan_sip.c: Header 2: From: "Wilson J. Chan" ;tag=as091773b5 (66) Dec 8 12:07:37 DEBUG[5982] chan_sip.c: Header 3: To: (36) Dec 8 12:07:37 DEBUG[5982] chan_sip.c: Header 4: Contact: (37) Dec 8 12:07:37 DEBUG[5982] chan_sip.c: Header 5: Call-ID: 527ed0db7b0fb1f22bb3214c03a8210e@10.1.1.48 (51) Dec 8 12:07:37 DEBUG[5982] chan_sip.c: Header 6: CSeq: 102 INVITE (16) Dec 8 12:07:37 DEBUG[5982] chan_sip.c: Header 7: User-Agent: Asterisk PBX (24) Dec 8 12:07:37 DEBUG[5982] chan_sip.c: Header 8: Max-Forwards: 70 (16) Dec 8 12:07:37 DEBUG[5982] chan_sip.c: Header 9: Date: Thu, 08 Dec 2005 20:07:37 GMT (35) Dec 8 12:07:37 DEBUG[5982] chan_sip.c: Header 10: Alert-Info: "Visual" (20) Dec 8 12:07:37 DEBUG[5982] chan_sip.c: Header 11: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) Dec 8 12:07:37 DEBUG[5982] chan_sip.c: Header 12: Content-Type: application/sdp (29) Dec 8 12:07:37 DEBUG[5982] chan_sip.c: Header 13: Content-Length: 279 (19) Dec 8 12:07:37 DEBUG[5982] chan_sip.c: Header 14: (0) Dec 8 12:07:37 DEBUG[5982] chan_sip.c: Line: v=0 (3) Dec 8 12:07:37 DEBUG[5982] chan_sip.c: Line: o=root 5918 5918 IN IP4 10.1.1.48 (33) Dec 8 12:07:37 DEBUG[5982] chan_sip.c: Line: s=session (9) Dec 8 12:07:37 DEBUG[5982] chan_sip.c: Line: c=IN IP4 10.1.1.48 (18) Dec 8 12:07:37 DEBUG[5982] chan_sip.c: Line: t=0 0 (5) Dec 8 12:07:37 DEBUG[5982] chan_sip.c: Line: m=audio 12662 RTP/AVP 0 8 18 101 (32) Dec 8 12:07:37 DEBUG[5982] chan_sip.c: Line: a=rtpmap:0 PCMU/8000 (20) Dec 8 12:07:37 DEBUG[5982] chan_sip.c: Line: a=rtpmap:8 PCMA/8000 (20) Dec 8 12:07:37 DEBUG[5982] chan_sip.c: Line: a=rtpmap:18 G729/8000 (21) Dec 8 12:07:37 DEBUG[5982] chan_sip.c: Line: a=fmtp:18 annexb=no (19) Dec 8 12:07:37 DEBUG[5982] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33) Dec 8 12:07:37 DEBUG[5982] chan_sip.c: Line: a=fmtp:101 0-16 (15) Dec 8 12:07:37 DEBUG[5982] chan_sip.c: Line: a=silenceSupp:off - - - - (25) Dec 8 12:07:37 DEBUG[5982] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #43 Dec 8 12:07:37 DEBUG[5982] channel.c: Set channel SIP/theater-polycom-550f to read format slin Dec 8 12:07:37 DEBUG[5982] channel.c: Set channel Local/2@two-rings-d9a9,2 to write format slin Dec 8 12:07:37 DEBUG[5982] channel.c: Set channel Local/2@two-rings-d9a9,2 to read format slin Dec 8 12:07:37 DEBUG[5982] channel.c: Set channel SIP/theater-polycom-550f to write format slin Dec 8 12:07:37 DEBUG[5927] chan_sip.c: Header 0: SIP/2.0 100 Trying (18) Dec 8 12:07:37 DEBUG[5927] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.1.1.48:5060;branch=z9hG4bK7a60e001;rport (60) Dec 8 12:07:37 DEBUG[5927] chan_sip.c: Header 2: From: "Wilson J. Chan" ;tag=as7df987c3 (66) Dec 8 12:07:37 DEBUG[5927] chan_sip.c: Header 3: To: ;tag=B8ACBE32-77879D39 (57) Dec 8 12:07:37 DEBUG[5927] chan_sip.c: Header 4: CSeq: 102 INVITE (16) Dec 8 12:07:37 DEBUG[5927] chan_sip.c: Header 5: Call-ID: 05fcc4ea5c3c98dc42ea19752005ef30@10.1.1.48 (51) Dec 8 12:07:37 DEBUG[5927] chan_sip.c: Header 6: Contact: (40) Dec 8 12:07:37 DEBUG[5927] chan_sip.c: Header 7: User-Agent: PolycomSoundPointIP-SPIP_600-UA/1.6.2.0041 (54) Dec 8 12:07:37 DEBUG[5927] chan_sip.c: Header 8: Content-Length: 0 (17) Dec 8 12:07:37 DEBUG[5927] chan_sip.c: Header 9: (0) Dec 8 12:07:37 DEBUG[5927] chan_sip.c: = No match Their Call ID: 527ed0db7b0fb1f22bb3214c03a8210e@10.1.1.48 Their Tag Our tag: as091773b5 Dec 8 12:07:37 DEBUG[5927] chan_sip.c: = No match Their Call ID: 19aee4ca7200b461231abe1b5b278d3a@10.1.1.48 Their Tag Our tag: as0c63514f Dec 8 12:07:37 DEBUG[5927] chan_sip.c: = No match Their Call ID: 0d0efafd3d2830ca6a1cf321103887ee@10.1.1.48 Their Tag Our tag: as504acb4a Dec 8 12:07:37 DEBUG[5927] chan_sip.c: = Found Their Call ID: 05fcc4ea5c3c98dc42ea19752005ef30@10.1.1.48 Their Tag Our tag: as7df987c3 Dec 8 12:07:37 DEBUG[5927] chan_sip.c: *** SIP TIMER: Cancelling retransmission #40 - INVITE (got response) Dec 8 12:07:37 DEBUG[5927] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '05fcc4ea5c3c98dc42ea19752005ef30@10.1.1.48' Request 102: Found Dec 8 12:07:37 DEBUG[5927] chan_sip.c: SIP response 100 to standard invite Dec 8 12:07:37 DEBUG[5927] chan_sip.c: Header 0: SIP/2.0 100 Trying (18) Dec 8 12:07:37 DEBUG[5927] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.1.1.48:5060;branch=z9hG4bK697bd9f5;rport (60) Dec 8 12:07:37 DEBUG[5927] chan_sip.c: Header 2: From: "Wilson J. Chan" ;tag=as504acb4a (66) Dec 8 12:07:37 DEBUG[5927] chan_sip.c: Header 3: To: ;tag=CC755F29-E2EC8DB4 (56) Dec 8 12:07:37 DEBUG[5927] chan_sip.c: Header 4: CSeq: 102 INVITE (16) Dec 8 12:07:37 DEBUG[5927] chan_sip.c: Header 5: Call-ID: 0d0efafd3d2830ca6a1cf321103887ee@10.1.1.48 (51) Dec 8 12:07:37 DEBUG[5927] chan_sip.c: Header 6: Contact: (39) Dec 8 12:07:37 DEBUG[5927] chan_sip.c: Header 7: User-Agent: PolycomSoundPointIP-SPIP_600-UA/1.6.2.0041 (54) Dec 8 12:07:37 DEBUG[5927] chan_sip.c: Header 8: Content-Length: 0 (17) Dec 8 12:07:37 DEBUG[5927] chan_sip.c: Header 9: (0) Dec 8 12:07:37 DEBUG[5927] chan_sip.c: = No match Their Call ID: 527ed0db7b0fb1f22bb3214c03a8210e@10.1.1.48 Their Tag Our tag: as091773b5 Dec 8 12:07:37 DEBUG[5927] chan_sip.c: = No match Their Call ID: 19aee4ca7200b461231abe1b5b278d3a@10.1.1.48 Their Tag Our tag: as0c63514f Dec 8 12:07:37 DEBUG[5927] chan_sip.c: = Found Their Call ID: 0d0efafd3d2830ca6a1cf321103887ee@10.1.1.48 Their Tag Our tag: as504acb4a Dec 8 12:07:37 DEBUG[5927] chan_sip.c: *** SIP TIMER: Cancelling retransmission #41 - INVITE (got response) Dec 8 12:07:37 DEBUG[5927] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '0d0efafd3d2830ca6a1cf321103887ee@10.1.1.48' Request 102: Found Dec 8 12:07:37 DEBUG[5927] chan_sip.c: SIP response 100 to standard invite Dec 8 12:07:37 DEBUG[5927] chan_sip.c: Header 0: SIP/2.0 100 Trying (18) Dec 8 12:07:37 DEBUG[5927] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.1.1.48:5060;branch=z9hG4bK09ff7720;rport (60) Dec 8 12:07:37 DEBUG[5927] chan_sip.c: Header 2: From: "Wilson J. Chan" ;tag=as0c63514f (66) Dec 8 12:07:37 DEBUG[5927] chan_sip.c: Header 3: To: ;tag=45193490-FAF69303 (58) Dec 8 12:07:37 DEBUG[5927] chan_sip.c: Header 4: CSeq: 102 INVITE (16) Dec 8 12:07:37 DEBUG[5927] chan_sip.c: Header 5: Call-ID: 19aee4ca7200b461231abe1b5b278d3a@10.1.1.48 (51) Dec 8 12:07:37 DEBUG[5927] chan_sip.c: Header 6: Contact: (41) Dec 8 12:07:37 DEBUG[5927] chan_sip.c: Header 7: User-Agent: PolycomSoundPointIP-SPIP_600-UA/1.6.2.0041 (54) Dec 8 12:07:37 DEBUG[5927] chan_sip.c: Header 8: Content-Length: 0 (17) Dec 8 12:07:37 DEBUG[5927] chan_sip.c: Header 9: (0) Dec 8 12:07:37 DEBUG[5927] chan_sip.c: = No match Their Call ID: 527ed0db7b0fb1f22bb3214c03a8210e@10.1.1.48 Their Tag Our tag: as091773b5 Dec 8 12:07:37 DEBUG[5927] chan_sip.c: = Found Their Call ID: 19aee4ca7200b461231abe1b5b278d3a@10.1.1.48 Their Tag Our tag: as0c63514f Dec 8 12:07:37 DEBUG[5927] chan_sip.c: *** SIP TIMER: Cancelling retransmission #42 - INVITE (got response) Dec 8 12:07:37 DEBUG[5927] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '19aee4ca7200b461231abe1b5b278d3a@10.1.1.48' Request 102: Found Dec 8 12:07:37 DEBUG[5927] chan_sip.c: SIP response 100 to standard invite Dec 8 12:07:37 DEBUG[5927] chan_sip.c: Header 0: SIP/2.0 100 Trying (18) Dec 8 12:07:37 DEBUG[5927] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.1.1.48:5060;branch=z9hG4bK2128d34a;rport (60) Dec 8 12:07:37 DEBUG[5927] chan_sip.c: Header 2: From: "Wilson J. Chan" ;tag=as091773b5 (66) Dec 8 12:07:37 DEBUG[5927] chan_sip.c: Header 3: To: ;tag=C0F8B373-9B4EF72A (58) Dec 8 12:07:37 DEBUG[5927] chan_sip.c: Header 4: CSeq: 102 INVITE (16) Dec 8 12:07:37 DEBUG[5927] chan_sip.c: Header 5: Call-ID: 527ed0db7b0fb1f22bb3214c03a8210e@10.1.1.48 (51) Dec 8 12:07:37 DEBUG[5927] chan_sip.c: Header 6: Contact: (41) Dec 8 12:07:37 DEBUG[5927] chan_sip.c: Header 7: User-Agent: PolycomSoundPointIP-SPIP_600-UA/1.6.2.0041 (54) Dec 8 12:07:37 DEBUG[5927] chan_sip.c: Header 8: Content-Length: 0 (17) Dec 8 12:07:37 DEBUG[5927] chan_sip.c: Header 9: (0) Dec 8 12:07:37 DEBUG[5927] chan_sip.c: = Found Their Call ID: 527ed0db7b0fb1f22bb3214c03a8210e@10.1.1.48 Their Tag Our tag: as091773b5 Dec 8 12:07:37 DEBUG[5927] chan_sip.c: *** SIP TIMER: Cancelling retransmission #43 - INVITE (got response) Dec 8 12:07:37 DEBUG[5927] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '527ed0db7b0fb1f22bb3214c03a8210e@10.1.1.48' Request 102: Found Dec 8 12:07:37 DEBUG[5927] chan_sip.c: SIP response 100 to standard invite Dec 8 12:07:37 DEBUG[5927] chan_sip.c: Header 0: SIP/2.0 180 Ringing (19) Dec 8 12:07:37 DEBUG[5927] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.1.1.48:5060;branch=z9hG4bK7a60e001;rport (60) Dec 8 12:07:37 DEBUG[5927] chan_sip.c: Header 2: From: "Wilson J. Chan" ;tag=as7df987c3 (66) Dec 8 12:07:37 DEBUG[5927] chan_sip.c: Header 3: To: ;tag=B8ACBE32-77879D39 (57) Dec 8 12:07:37 DEBUG[5927] chan_sip.c: Header 4: CSeq: 102 INVITE (16) Dec 8 12:07:37 DEBUG[5927] chan_sip.c: Header 5: Call-ID: 05fcc4ea5c3c98dc42ea19752005ef30@10.1.1.48 (51) Dec 8 12:07:37 DEBUG[5927] chan_sip.c: Header 6: Contact: (40) Dec 8 12:07:37 DEBUG[5927] chan_sip.c: Header 7: User-Agent: PolycomSoundPointIP-SPIP_600-UA/1.6.2.0041 (54) Dec 8 12:07:37 DEBUG[5927] chan_sip.c: Header 8: Allow-Events: talk,hold,conference (34) Dec 8 12:07:37 DEBUG[5927] chan_sip.c: Header 9: Content-Length: 0 (17) Dec 8 12:07:37 DEBUG[5927] chan_sip.c: Header 10: (0) Dec 8 12:07:37 DEBUG[5927] chan_sip.c: = No match Their Call ID: 527ed0db7b0fb1f22bb3214c03a8210e@10.1.1.48 Their Tag C0F8B373-9B4EF72A Our tag: as091773b5 Dec 8 12:07:37 DEBUG[5927] chan_sip.c: = No match Their Call ID: 19aee4ca7200b461231abe1b5b278d3a@10.1.1.48 Their Tag 45193490-FAF69303 Our tag: as0c63514f Dec 8 12:07:37 DEBUG[5927] chan_sip.c: = No match Their Call ID: 0d0efafd3d2830ca6a1cf321103887ee@10.1.1.48 Their Tag CC755F29-E2EC8DB4 Our tag: as504acb4a Dec 8 12:07:37 DEBUG[5927] chan_sip.c: = Found Their Call ID: 05fcc4ea5c3c98dc42ea19752005ef30@10.1.1.48 Their Tag B8ACBE32-77879D39 Our tag: as7df987c3 Dec 8 12:07:37 DEBUG[5927] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '05fcc4ea5c3c98dc42ea19752005ef30@10.1.1.48' Request 102: Found Dec 8 12:07:37 DEBUG[5927] chan_sip.c: SIP response 180 to standard invite Dec 8 12:07:37 DEBUG[5922] chan_sip.c: Checking device state for peer wilson-polycom Dec 8 12:07:37 DEBUG[5922] devicestate.c: Changing state for SIP/wilson-polycom - state 6 (Ringing) Dec 8 12:07:37 DEBUG[5922] chan_sip.c: Checking device state for peer wilson-polycom Dec 8 12:07:37 DEBUG[5980] chan_zap.c: Requested indication 3 on channel Zap/3-1 Dec 8 12:07:37 DEBUG[5927] chan_sip.c: Header 0: SIP/2.0 180 Ringing (19) Dec 8 12:07:37 DEBUG[5927] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.1.1.48:5060;branch=z9hG4bK697bd9f5;rport (60) Dec 8 12:07:37 DEBUG[5927] chan_sip.c: Header 2: From: "Wilson J. Chan" ;tag=as504acb4a (66) Dec 8 12:07:37 DEBUG[5927] chan_sip.c: Header 3: To: ;tag=CC755F29-E2EC8DB4 (56) Dec 8 12:07:37 DEBUG[5927] chan_sip.c: Header 4: CSeq: 102 INVITE (16) Dec 8 12:07:37 DEBUG[5927] chan_sip.c: Header 5: Call-ID: 0d0efafd3d2830ca6a1cf321103887ee@10.1.1.48 (51) Dec 8 12:07:37 DEBUG[5927] chan_sip.c: Header 6: Contact: (39) Dec 8 12:07:37 DEBUG[5927] chan_sip.c: Header 7: User-Agent: PolycomSoundPointIP-SPIP_600-UA/1.6.2.0041 (54) Dec 8 12:07:37 DEBUG[5927] chan_sip.c: Header 8: Allow-Events: talk,hold,conference (34) Dec 8 12:07:37 DEBUG[5927] chan_sip.c: Header 9: Content-Length: 0 (17) Dec 8 12:07:37 DEBUG[5927] chan_sip.c: Header 10: (0) Dec 8 12:07:37 DEBUG[5927] chan_sip.c: = No match Their Call ID: 527ed0db7b0fb1f22bb3214c03a8210e@10.1.1.48 Their Tag C0F8B373-9B4EF72A Our tag: as091773b5 Dec 8 12:07:37 DEBUG[5927] chan_sip.c: = No match Their Call ID: 19aee4ca7200b461231abe1b5b278d3a@10.1.1.48 Their Tag 45193490-FAF69303 Our tag: as0c63514f Dec 8 12:07:37 DEBUG[5927] chan_sip.c: = Found Their Call ID: 0d0efafd3d2830ca6a1cf321103887ee@10.1.1.48 Their Tag CC755F29-E2EC8DB4 Our tag: as504acb4a Dec 8 12:07:37 DEBUG[5927] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '0d0efafd3d2830ca6a1cf321103887ee@10.1.1.48' Request 102: Found Dec 8 12:07:37 DEBUG[5927] chan_sip.c: SIP response 180 to standard invite Dec 8 12:07:37 DEBUG[5922] chan_sip.c: Checking device state for peer scott-polycom Dec 8 12:07:37 DEBUG[5922] devicestate.c: Changing state for SIP/scott-polycom - state 6 (Ringing) Dec 8 12:07:37 DEBUG[5922] chan_sip.c: Checking device state for peer scott-polycom Dec 8 12:07:37 DEBUG[5927] chan_sip.c: Header 0: SIP/2.0 180 Ringing (19) Dec 8 12:07:37 DEBUG[5927] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.1.1.48:5060;branch=z9hG4bK09ff7720;rport (60) Dec 8 12:07:37 DEBUG[5927] chan_sip.c: Header 2: From: "Wilson J. Chan" ;tag=as0c63514f (66) Dec 8 12:07:37 DEBUG[5927] chan_sip.c: Header 3: To: ;tag=45193490-FAF69303 (58) Dec 8 12:07:37 DEBUG[5927] chan_sip.c: Header 4: CSeq: 102 INVITE (16) Dec 8 12:07:37 DEBUG[5927] chan_sip.c: Header 5: Call-ID: 19aee4ca7200b461231abe1b5b278d3a@10.1.1.48 (51) Dec 8 12:07:37 DEBUG[5927] chan_sip.c: Header 6: Contact: (41) Dec 8 12:07:37 DEBUG[5927] chan_sip.c: Header 7: User-Agent: PolycomSoundPointIP-SPIP_600-UA/1.6.2.0041 (54) Dec 8 12:07:37 DEBUG[5927] chan_sip.c: Header 8: Allow-Events: talk,hold,conference (34) Dec 8 12:07:37 DEBUG[5927] chan_sip.c: Header 9: Content-Length: 0 (17) Dec 8 12:07:37 DEBUG[5927] chan_sip.c: Header 10: (0) Dec 8 12:07:37 DEBUG[5927] chan_sip.c: = No match Their Call ID: 527ed0db7b0fb1f22bb3214c03a8210e@10.1.1.48 Their Tag C0F8B373-9B4EF72A Our tag: as091773b5 Dec 8 12:07:37 DEBUG[5927] chan_sip.c: = Found Their Call ID: 19aee4ca7200b461231abe1b5b278d3a@10.1.1.48 Their Tag 45193490-FAF69303 Our tag: as0c63514f Dec 8 12:07:37 DEBUG[5927] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '19aee4ca7200b461231abe1b5b278d3a@10.1.1.48' Request 102: Found Dec 8 12:07:37 DEBUG[5927] chan_sip.c: SIP response 180 to standard invite Dec 8 12:07:37 DEBUG[5922] chan_sip.c: Checking device state for peer kitchen-polycom Dec 8 12:07:37 DEBUG[5922] devicestate.c: Changing state for SIP/kitchen-polycom - state 6 (Ringing) Dec 8 12:07:37 DEBUG[5927] chan_sip.c: Header 0: SIP/2.0 180 Ringing (19) Dec 8 12:07:37 DEBUG[5927] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.1.1.48:5060;branch=z9hG4bK2128d34a;rport (60) Dec 8 12:07:37 DEBUG[5927] chan_sip.c: Header 2: From: "Wilson J. Chan" ;tag=as091773b5 (66) Dec 8 12:07:37 DEBUG[5927] chan_sip.c: Header 3: To: ;tag=C0F8B373-9B4EF72A (58) Dec 8 12:07:37 DEBUG[5927] chan_sip.c: Header 4: CSeq: 102 INVITE (16) Dec 8 12:07:37 DEBUG[5927] chan_sip.c: Header 5: Call-ID: 527ed0db7b0fb1f22bb3214c03a8210e@10.1.1.48 (51) Dec 8 12:07:37 DEBUG[5927] chan_sip.c: Header 6: Contact: (41) Dec 8 12:07:37 DEBUG[5927] chan_sip.c: Header 7: User-Agent: PolycomSoundPointIP-SPIP_600-UA/1.6.2.0041 (54) Dec 8 12:07:37 DEBUG[5927] chan_sip.c: Header 8: Allow-Events: talk,hold,conference (34) Dec 8 12:07:37 DEBUG[5927] chan_sip.c: Header 9: Content-Length: 0 (17) Dec 8 12:07:37 DEBUG[5927] chan_sip.c: Header 10: (0) Dec 8 12:07:37 DEBUG[5927] chan_sip.c: = Found Their Call ID: 527ed0db7b0fb1f22bb3214c03a8210e@10.1.1.48 Their Tag C0F8B373-9B4EF72A Our tag: as091773b5 Dec 8 12:07:37 DEBUG[5927] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '527ed0db7b0fb1f22bb3214c03a8210e@10.1.1.48' Request 102: Found Dec 8 12:07:37 DEBUG[5927] chan_sip.c: SIP response 180 to standard invite Dec 8 12:07:37 DEBUG[5922] chan_sip.c: Checking device state for peer theater-polycom Dec 8 12:07:37 DEBUG[5922] devicestate.c: Changing state for SIP/theater-polycom - state 6 (Ringing) Dec 8 12:07:38 DEBUG[5980] chan_zap.c: Exception on 21, channel 3 Dec 8 12:07:38 DEBUG[5980] chan_zap.c: Got event Ring Begin(18) on channel 3 (index 0) Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Header 0: SIP/2.0 200 OK (14) Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.1.1.48:5060;branch=z9hG4bK7a60e001;rport (60) Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Header 2: From: "Wilson J. Chan" ;tag=as7df987c3 (66) Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Header 3: To: ;tag=B8ACBE32-77879D39 (57) Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Header 4: CSeq: 102 INVITE (16) Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Header 5: Call-ID: 05fcc4ea5c3c98dc42ea19752005ef30@10.1.1.48 (51) Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Header 6: Contact: (40) Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Header 7: Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER (96) Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Header 8: User-Agent: PolycomSoundPointIP-SPIP_600-UA/1.6.2.0041 (54) Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Header 9: Content-Type: application/sdp (29) Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Header 10: Content-Length: 183 (19) Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Header 11: (0) Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Line: v=0 (3) Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Line: o=- 1134072431 1134072431 IN IP4 10.1.1.200 (43) Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Line: s=Polycom IP Phone (18) Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Line: c=IN IP4 10.1.1.200 (19) Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Line: t=0 0 (5) Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Line: m=audio 2252 RTP/AVP 0 101 (26) Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Line: a=rtpmap:0 PCMU/8000 (20) Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33) Dec 8 12:07:38 DEBUG[5927] chan_sip.c: = No match Their Call ID: 527ed0db7b0fb1f22bb3214c03a8210e@10.1.1.48 Their Tag C0F8B373-9B4EF72A Our tag: as091773b5 Dec 8 12:07:38 DEBUG[5927] chan_sip.c: = No match Their Call ID: 19aee4ca7200b461231abe1b5b278d3a@10.1.1.48 Their Tag 45193490-FAF69303 Our tag: as0c63514f Dec 8 12:07:38 DEBUG[5927] chan_sip.c: = No match Their Call ID: 0d0efafd3d2830ca6a1cf321103887ee@10.1.1.48 Their Tag CC755F29-E2EC8DB4 Our tag: as504acb4a Dec 8 12:07:38 DEBUG[5927] chan_sip.c: = Found Their Call ID: 05fcc4ea5c3c98dc42ea19752005ef30@10.1.1.48 Their Tag B8ACBE32-77879D39 Our tag: as7df987c3 Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Acked pending invite 102 Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Stopping retransmission on '05fcc4ea5c3c98dc42ea19752005ef30@10.1.1.48' of Request 102: Match Found Dec 8 12:07:38 DEBUG[5927] chan_sip.c: SIP response 200 to standard invite Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Peer audio RTP is at port 10.1.1.200:2252 Dec 8 12:07:38 DEBUG[5927] chan_sip.c: build_route: Contact hop: Dec 8 12:07:38 DEBUG[5981] channel.c: Hanging up channel 'SIP/kitchen-polycom-e570' Dec 8 12:07:38 DEBUG[5981] chan_sip.c: Hangup call SIP/kitchen-polycom-e570, SIP callid 19aee4ca7200b461231abe1b5b278d3a@10.1.1.48) Dec 8 12:07:38 DEBUG[5981] chan_sip.c: update_call_counter(kitchen-polycom) - decrement call limit counter Dec 8 12:07:38 DEBUG[5981] chan_sip.c: Updating call counter for outgoing call Dec 8 12:07:38 DEBUG[5981] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #44 Dec 8 12:07:38 DEBUG[5981] chan_sip.c: Acked pending invite 102 Dec 8 12:07:38 DEBUG[5981] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #44 Dec 8 12:07:38 DEBUG[5981] chan_sip.c: Stopping retransmission on '19aee4ca7200b461231abe1b5b278d3a@10.1.1.48' of Request 102: Match Found Dec 8 12:07:38 DEBUG[5981] chan_sip.c: Stopping retransmission on '19aee4ca7200b461231abe1b5b278d3a@10.1.1.48' of Request 102: Match Found Dec 8 12:07:38 DEBUG[5981] channel.c: Hanging up channel 'SIP/scott-polycom-f18b' Dec 8 12:07:38 DEBUG[5981] chan_sip.c: Hangup call SIP/scott-polycom-f18b, SIP callid 0d0efafd3d2830ca6a1cf321103887ee@10.1.1.48) Dec 8 12:07:38 DEBUG[5981] chan_sip.c: update_call_counter(scott-polycom) - decrement call limit counter Dec 8 12:07:38 DEBUG[5981] chan_sip.c: Updating call counter for outgoing call Dec 8 12:07:38 DEBUG[5981] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #46 Dec 8 12:07:38 DEBUG[5981] chan_sip.c: Acked pending invite 102 Dec 8 12:07:38 DEBUG[5981] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #46 Dec 8 12:07:38 DEBUG[5981] chan_sip.c: Stopping retransmission on '0d0efafd3d2830ca6a1cf321103887ee@10.1.1.48' of Request 102: Match Found Dec 8 12:07:38 DEBUG[5981] chan_sip.c: Stopping retransmission on '0d0efafd3d2830ca6a1cf321103887ee@10.1.1.48' of Request 102: Match Found Dec 8 12:07:38 DEBUG[5980] chan_zap.c: Requested indication -1 on channel Zap/3-1 Dec 8 12:07:38 DEBUG[5981] channel.c: Set channel Local/1@two-rings-3656,2 to read format slin Dec 8 12:07:38 DEBUG[5981] channel.c: Set channel SIP/wilson-polycom-2df5 to write format slin Dec 8 12:07:38 DEBUG[5981] channel.c: Set channel SIP/wilson-polycom-2df5 to read format slin Dec 8 12:07:38 DEBUG[5981] channel.c: Set channel Local/1@two-rings-3656,2 to write format slin Dec 8 12:07:38 DEBUG[5980] channel.c: Hanging up channel 'Local/2@two-rings-d9a9,1' Dec 8 12:07:38 DEBUG[5980] channel.c: Set channel Zap/3-1 to read format slin Dec 8 12:07:38 DEBUG[5980] channel.c: Set channel Local/1@two-rings-3656,1 to write format slin Dec 8 12:07:38 DEBUG[5980] channel.c: Set channel Local/1@two-rings-3656,1 to read format slin Dec 8 12:07:38 DEBUG[5980] channel.c: Set channel Zap/3-1 to write format slin Dec 8 12:07:38 DEBUG[5980] chan_zap.c: Took Zap/3-1 off hook Dec 8 12:07:38 DEBUG[5980] chan_zap.c: Enabled echo cancellation on channel 3 Dec 8 12:07:38 DEBUG[5980] chan_zap.c: Engaged echo training on channel 3 Dec 8 12:07:38 DEBUG[5922] chan_sip.c: Checking device state for peer wilson-polycom Dec 8 12:07:38 DEBUG[5922] devicestate.c: Changing state for SIP/wilson-polycom - state 2 (In use) Dec 8 12:07:38 DEBUG[5922] chan_sip.c: Checking device state for peer wilson-polycom Dec 8 12:07:38 DEBUG[5922] chan_sip.c: Checking device state for peer kitchen-polycom Dec 8 12:07:38 DEBUG[5922] devicestate.c: Changing state for SIP/kitchen-polycom - state 1 (Not in use) Dec 8 12:07:38 DEBUG[5922] chan_sip.c: Checking device state for peer scott-polycom Dec 8 12:07:38 DEBUG[5922] devicestate.c: Changing state for SIP/scott-polycom - state 1 (Not in use) Dec 8 12:07:38 DEBUG[5922] chan_sip.c: Checking device state for peer scott-polycom Dec 8 12:07:38 DEBUG[5922] devicestate.c: Changing state for Local/1@two-rings - state 2 (In use) Dec 8 12:07:38 DEBUG[5922] devicestate.c: Changing state for Local/2@two-rings - state 2 (In use) Dec 8 12:07:38 DEBUG[5922] devicestate.c: Changing state for Zap/3 - state 2 (In use) Dec 8 12:07:38 DEBUG[5922] devicestate.c: Changing state for Local/1@two-rings - state 2 (In use) Dec 8 12:07:38 DEBUG[5982] channel.c: Hanging up channel 'SIP/theater-polycom-550f' Dec 8 12:07:38 DEBUG[5982] chan_sip.c: Hangup call SIP/theater-polycom-550f, SIP callid 527ed0db7b0fb1f22bb3214c03a8210e@10.1.1.48) Dec 8 12:07:38 DEBUG[5982] chan_sip.c: update_call_counter(theater-polycom) - decrement call limit counter Dec 8 12:07:38 DEBUG[5982] chan_sip.c: Updating call counter for outgoing call Dec 8 12:07:38 DEBUG[5982] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #48 Dec 8 12:07:38 DEBUG[5982] chan_sip.c: Acked pending invite 102 Dec 8 12:07:38 DEBUG[5982] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #48 Dec 8 12:07:38 DEBUG[5982] chan_sip.c: Stopping retransmission on '527ed0db7b0fb1f22bb3214c03a8210e@10.1.1.48' of Request 102: Match Found Dec 8 12:07:38 DEBUG[5982] chan_sip.c: Stopping retransmission on '527ed0db7b0fb1f22bb3214c03a8210e@10.1.1.48' of Request 102: Match Found Dec 8 12:07:38 DEBUG[5982] app_dial.c: Exiting with DIALSTATUS=CANCEL. Dec 8 12:07:38 DEBUG[5982] pbx.c: Spawn extension (two-rings,2,2) exited non-zero on 'Local/2@two-rings-d9a9,2' Dec 8 12:07:38 DEBUG[5982] channel.c: Hanging up channel 'Local/2@two-rings-d9a9,2' Dec 8 12:07:38 DEBUG[5922] chan_sip.c: Checking device state for peer theater-polycom Dec 8 12:07:38 DEBUG[5922] devicestate.c: Changing state for SIP/theater-polycom - state 1 (Not in use) Dec 8 12:07:38 DEBUG[5922] devicestate.c: Changing state for Local/2@two-rings - state 0 (Unknown) Dec 8 12:07:38 DEBUG[5980] channel.c: Planning to masquerade channel Zap/3-1 into the structure of Local/1@two-rings-3656,2 Dec 8 12:07:38 DEBUG[5980] channel.c: Done planning to masquerade channel Zap/3-1 into the structure of Local/1@two-rings-3656,2 Dec 8 12:07:38 DEBUG[5980] chan_local.c: Not posting to queue since already masked on 'Local/1@two-rings-3656,1' Dec 8 12:07:38 DEBUG[5981] channel.c: Actually Masquerading Zap/3-1(6) into the structure of Local/1@two-rings-3656,2(6) Dec 8 12:07:38 DEBUG[5981] channel.c: Got clone lock for masquerade on 'Zap/3-1' at 0x9368ec4 Dec 8 12:07:38 DEBUG[5980] channel.c: Didn't get a frame from channel: Local/1@two-rings-3656,1 Dec 8 12:07:38 DEBUG[5980] channel.c: Bridge stops bridging channels Zap/3-1 and Local/1@two-rings-3656,1 Dec 8 12:07:38 DEBUG[5980] channel.c: Hanging up channel 'Local/1@two-rings-3656,1' Dec 8 12:07:38 DEBUG[5981] channel.c: Set channel Zap/3-1 to write format slin Dec 8 12:07:38 DEBUG[5981] channel.c: Set channel Zap/3-1 to read format slin Dec 8 12:07:38 DEBUG[5981] channel.c: Putting channel Zap/3-1 in 64/64 formats Dec 8 12:07:38 DEBUG[5981] chan_zap.c: New owner for channel 3 is Zap/3-1 Dec 8 12:07:38 DEBUG[5981] chan_zap.c: Updated conferencing on 3, with 0 conference users Dec 8 12:07:38 DEBUG[5981] chan_zap.c: Updated conferencing on 3, with 0 conference users Dec 8 12:07:38 DEBUG[5981] channel.c: Released clone lock on 'Local/1@two-rings-3656,2' Dec 8 12:07:38 DEBUG[5981] channel.c: Done Masquerading Zap/3-1 (6) Dec 8 12:07:38 DEBUG[5981] channel.c: Set channel Zap/3-1 to read format ulaw Dec 8 12:07:38 DEBUG[5981] channel.c: Set channel SIP/wilson-polycom-2df5 to write format ulaw Dec 8 12:07:38 DEBUG[5981] channel.c: Set channel SIP/wilson-polycom-2df5 to read format ulaw Dec 8 12:07:38 DEBUG[5981] channel.c: Set channel Zap/3-1 to write format ulaw Dec 8 12:07:38 DEBUG[5980] app_dial.c: Exiting with DIALSTATUS=ANSWER. Dec 8 12:07:38 DEBUG[5980] pbx.c: Spawn extension (home-incoming,s,7) exited non-zero on 'Local/1@two-rings-3656,2' Dec 8 12:07:38 DEBUG[5980] channel.c: Hanging up zombie 'Local/1@two-rings-3656,2' Dec 8 12:07:38 DEBUG[5922] devicestate.c: Changing state for Local/1@two-rings - state 0 (Unknown) Dec 8 12:07:38 DEBUG[5922] devicestate.c: Changing state for Local/1@two-rings - state 0 (Unknown) Dec 8 12:07:38 DEBUG[5981] rtp.c: Ooh, format changed from unknown to ulaw Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Header 0: SIP/2.0 200 OK (14) Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.1.1.48:5060;branch=z9hG4bK697bd9f5;rport (60) Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Header 2: From: "Wilson J. Chan" ;tag=as504acb4a (66) Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Header 3: To: (34) Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Header 4: CSeq: 102 CANCEL (16) Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Header 5: Call-ID: 0d0efafd3d2830ca6a1cf321103887ee@10.1.1.48 (51) Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Header 6: Contact: (39) Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Header 7: User-Agent: PolycomSoundPointIP-SPIP_600-UA/1.6.2.0041 (54) Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Header 8: Content-Length: 0 (17) Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Header 9: (0) Dec 8 12:07:38 DEBUG[5927] chan_sip.c: = No match Their Call ID: 527ed0db7b0fb1f22bb3214c03a8210e@10.1.1.48 Their Tag C0F8B373-9B4EF72A Our tag: as091773b5 Dec 8 12:07:38 DEBUG[5927] chan_sip.c: = No match Their Call ID: 19aee4ca7200b461231abe1b5b278d3a@10.1.1.48 Their Tag 45193490-FAF69303 Our tag: as0c63514f Dec 8 12:07:38 DEBUG[5927] chan_sip.c: = Found Their Call ID: 0d0efafd3d2830ca6a1cf321103887ee@10.1.1.48 Their Tag CC755F29-E2EC8DB4 Our tag: as504acb4a Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Stopping retransmission on '0d0efafd3d2830ca6a1cf321103887ee@10.1.1.48' of Request 102: Match Not Found Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Header 0: SIP/2.0 200 OK (14) Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.1.1.48:5060;branch=z9hG4bK09ff7720;rport (60) Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Header 2: From: "Wilson J. Chan" ;tag=as0c63514f (66) Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Header 3: To: (36) Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Header 4: CSeq: 102 CANCEL (16) Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Header 5: Call-ID: 19aee4ca7200b461231abe1b5b278d3a@10.1.1.48 (51) Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Header 6: Contact: (41) Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Header 7: User-Agent: PolycomSoundPointIP-SPIP_600-UA/1.6.2.0041 (54) Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Header 8: Content-Length: 0 (17) Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Header 9: (0) Dec 8 12:07:38 DEBUG[5927] chan_sip.c: = No match Their Call ID: 527ed0db7b0fb1f22bb3214c03a8210e@10.1.1.48 Their Tag C0F8B373-9B4EF72A Our tag: as091773b5 Dec 8 12:07:38 DEBUG[5927] chan_sip.c: = Found Their Call ID: 19aee4ca7200b461231abe1b5b278d3a@10.1.1.48 Their Tag 45193490-FAF69303 Our tag: as0c63514f Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Stopping retransmission on '19aee4ca7200b461231abe1b5b278d3a@10.1.1.48' of Request 102: Match Not Found Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Header 0: SIP/2.0 200 OK (14) Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.1.1.48:5060;branch=z9hG4bK2128d34a;rport (60) Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Header 2: From: "Wilson J. Chan" ;tag=as091773b5 (66) Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Header 3: To: (36) Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Header 4: CSeq: 102 CANCEL (16) Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Header 5: Call-ID: 527ed0db7b0fb1f22bb3214c03a8210e@10.1.1.48 (51) Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Header 6: Contact: (41) Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Header 7: User-Agent: PolycomSoundPointIP-SPIP_600-UA/1.6.2.0041 (54) Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Header 8: Content-Length: 0 (17) Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Header 9: (0) Dec 8 12:07:38 DEBUG[5927] chan_sip.c: = Found Their Call ID: 527ed0db7b0fb1f22bb3214c03a8210e@10.1.1.48 Their Tag C0F8B373-9B4EF72A Our tag: as091773b5 Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Stopping retransmission on '527ed0db7b0fb1f22bb3214c03a8210e@10.1.1.48' of Request 102: Match Not Found Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Header 0: SIP/2.0 487 Request Cancelled (29) Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.1.1.48:5060;branch=z9hG4bK2128d34a;rport (60) Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Header 2: From: "Wilson J. Chan" ;tag=as091773b5 (66) Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Header 3: To: ;tag=C0F8B373-9B4EF72A (58) Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Header 4: CSeq: 102 INVITE (16) Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Header 5: Call-ID: 527ed0db7b0fb1f22bb3214c03a8210e@10.1.1.48 (51) Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Header 6: Contact: (41) Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Header 7: User-Agent: PolycomSoundPointIP-SPIP_600-UA/1.6.2.0041 (54) Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Header 8: Content-Length: 0 (17) Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Header 9: (0) Dec 8 12:07:38 DEBUG[5927] chan_sip.c: = Found Their Call ID: 527ed0db7b0fb1f22bb3214c03a8210e@10.1.1.48 Their Tag Our tag: as091773b5 Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Stopping retransmission on '527ed0db7b0fb1f22bb3214c03a8210e@10.1.1.48' of Request 102: Match Not Found Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Updating call counter for outgoing call Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Header 0: SIP/2.0 487 Request Cancelled (29) Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.1.1.48:5060;branch=z9hG4bK697bd9f5;rport (60) Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Header 2: From: "Wilson J. Chan" ;tag=as504acb4a (66) Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Header 3: To: ;tag=CC755F29-E2EC8DB4 (56) Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Header 4: CSeq: 102 INVITE (16) Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Header 5: Call-ID: 0d0efafd3d2830ca6a1cf321103887ee@10.1.1.48 (51) Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Header 6: Contact: (39) Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Header 7: User-Agent: PolycomSoundPointIP-SPIP_600-UA/1.6.2.0041 (54) Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Header 8: Content-Length: 0 (17) Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Header 9: (0) Dec 8 12:07:38 DEBUG[5927] chan_sip.c: = No match Their Call ID: 19aee4ca7200b461231abe1b5b278d3a@10.1.1.48 Their Tag Our tag: as0c63514f Dec 8 12:07:38 DEBUG[5927] chan_sip.c: = Found Their Call ID: 0d0efafd3d2830ca6a1cf321103887ee@10.1.1.48 Their Tag Our tag: as504acb4a Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Stopping retransmission on '0d0efafd3d2830ca6a1cf321103887ee@10.1.1.48' of Request 102: Match Not Found Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Updating call counter for outgoing call Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Header 0: SIP/2.0 487 Request Cancelled (29) Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.1.1.48:5060;branch=z9hG4bK09ff7720;rport (60) Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Header 2: From: "Wilson J. Chan" ;tag=as0c63514f (66) Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Header 3: To: ;tag=45193490-FAF69303 (58) Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Header 4: CSeq: 102 INVITE (16) Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Header 5: Call-ID: 19aee4ca7200b461231abe1b5b278d3a@10.1.1.48 (51) Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Header 6: Contact: (41) Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Header 7: User-Agent: PolycomSoundPointIP-SPIP_600-UA/1.6.2.0041 (54) Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Header 8: Content-Length: 0 (17) Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Header 9: (0) Dec 8 12:07:38 DEBUG[5927] chan_sip.c: = Found Their Call ID: 19aee4ca7200b461231abe1b5b278d3a@10.1.1.48 Their Tag Our tag: as0c63514f Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Stopping retransmission on '19aee4ca7200b461231abe1b5b278d3a@10.1.1.48' of Request 102: Match Not Found Dec 8 12:07:38 DEBUG[5927] chan_sip.c: Updating call counter for outgoing call Dec 8 12:07:40 DEBUG[5927] chan_sip.c: Header 0: INVITE sip:915106041769@10.1.1.48 SIP/2.0 (41) Dec 8 12:07:40 DEBUG[5927] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.1.1.200;branch=z9hG4bK6a626fb3D60E8BFC (58) Dec 8 12:07:40 DEBUG[5927] chan_sip.c: Header 2: From: ;tag=B8ACBE32-77879D39 (59) Dec 8 12:07:40 DEBUG[5927] chan_sip.c: Header 3: To: "Wilson J. Chan" ;tag=as7df987c3 (64) Dec 8 12:07:40 DEBUG[5927] chan_sip.c: Header 4: CSeq: 1 INVITE (14) Dec 8 12:07:40 DEBUG[5927] chan_sip.c: Header 5: Call-ID: 05fcc4ea5c3c98dc42ea19752005ef30@10.1.1.48 (51) Dec 8 12:07:40 DEBUG[5927] chan_sip.c: Header 6: Contact: (40) Dec 8 12:07:40 DEBUG[5927] chan_sip.c: Header 7: Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER (96) Dec 8 12:07:40 DEBUG[5927] chan_sip.c: Header 8: User-Agent: PolycomSoundPointIP-SPIP_600-UA/1.6.2.0041 (54) Dec 8 12:07:40 DEBUG[5927] chan_sip.c: Header 9: Supported: 100rel,replace (25) Dec 8 12:07:40 DEBUG[5927] chan_sip.c: Header 10: Allow-Events: talk,hold,conference (34) Dec 8 12:07:40 DEBUG[5927] chan_sip.c: Header 11: Max-Forwards: 70 (16) Dec 8 12:07:40 DEBUG[5927] chan_sip.c: Header 12: Content-Type: application/sdp (29) Dec 8 12:07:40 DEBUG[5927] chan_sip.c: Header 13: Content-Length: 180 (19) Dec 8 12:07:40 DEBUG[5927] chan_sip.c: Header 14: (0) Dec 8 12:07:40 DEBUG[5927] chan_sip.c: Line: v=0 (3) Dec 8 12:07:40 DEBUG[5927] chan_sip.c: Line: o=- 1134072432 1134072432 IN IP4 10.1.1.200 (43) Dec 8 12:07:40 DEBUG[5927] chan_sip.c: Line: s=Polycom IP Phone (18) Dec 8 12:07:40 DEBUG[5927] chan_sip.c: Line: c=IN IP4 0.0.0.0 (16) Dec 8 12:07:40 DEBUG[5927] chan_sip.c: Line: t=0 0 (5) Dec 8 12:07:40 DEBUG[5927] chan_sip.c: Line: m=audio 2252 RTP/AVP 0 101 (26) Dec 8 12:07:40 DEBUG[5927] chan_sip.c: Line: a=rtpmap:0 PCMU/8000 (20) Dec 8 12:07:40 DEBUG[5927] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33) Dec 8 12:07:40 DEBUG[5927] chan_sip.c: = Found Their Call ID: 05fcc4ea5c3c98dc42ea19752005ef30@10.1.1.48 Their Tag B8ACBE32-77879D39 Our tag: as7df987c3 Dec 8 12:07:40 DEBUG[5927] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE Dec 8 12:07:40 DEBUG[5927] chan_sip.c: Begin: parsing SIP "Supported: 100rel,replace" Dec 8 12:07:40 DEBUG[5927] chan_sip.c: Found SIP option: -100rel- Dec 8 12:07:40 DEBUG[5927] chan_sip.c: Matched SIP option: 100rel Dec 8 12:07:40 DEBUG[5927] chan_sip.c: Found SIP option: -replace- Dec 8 12:07:40 DEBUG[5927] chan_sip.c: Found no match for SIP option: replace (Please file bug report!) Dec 8 12:07:40 DEBUG[5927] chan_sip.c: * SIP extension value: 2 for call 05fcc4ea5c3c98dc42ea19752005ef30@10.1.1.48 Dec 8 12:07:40 DEBUG[5927] chan_sip.c: Peer audio RTP is at port 0.0.0.0:2252 Dec 8 12:07:40 DEBUG[5927] channel.c: Set channel Zap/3-1 to write format slin Dec 8 12:07:40 DEBUG[5927] channel.c: Scheduling timer at 160 sample intervals Dec 8 12:07:40 DEBUG[5927] chan_sip.c: Got a SIP re-invite for call 05fcc4ea5c3c98dc42ea19752005ef30@10.1.1.48 Dec 8 12:07:40 DEBUG[5927] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #50 Dec 8 12:07:40 DEBUG[5981] channel.c: Generator got voice, switching to phase locked mode Dec 8 12:07:40 DEBUG[5981] channel.c: Scheduling timer at 0 sample intervals Dec 8 12:07:40 DEBUG[5927] chan_sip.c: Header 0: ACK sip:915106041769@10.1.1.48 SIP/2.0 (38) Dec 8 12:07:40 DEBUG[5927] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.1.1.200;branch=z9hG4bK2224ef4dF69507E6 (58) Dec 8 12:07:40 DEBUG[5927] chan_sip.c: Header 2: From: ;tag=B8ACBE32-77879D39 (59) Dec 8 12:07:40 DEBUG[5927] chan_sip.c: Header 3: To: "Wilson J. Chan" ;tag=as7df987c3 (64) Dec 8 12:07:40 DEBUG[5927] chan_sip.c: Header 4: CSeq: 1 ACK (11) Dec 8 12:07:40 DEBUG[5927] chan_sip.c: Header 5: Call-ID: 05fcc4ea5c3c98dc42ea19752005ef30@10.1.1.48 (51) Dec 8 12:07:40 DEBUG[5927] chan_sip.c: Header 6: Contact: (40) Dec 8 12:07:40 DEBUG[5927] chan_sip.c: Header 7: Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER (96) Dec 8 12:07:40 DEBUG[5927] chan_sip.c: Header 8: User-Agent: PolycomSoundPointIP-SPIP_600-UA/1.6.2.0041 (54) Dec 8 12:07:40 DEBUG[5927] chan_sip.c: Header 9: Max-Forwards: 70 (16) Dec 8 12:07:40 DEBUG[5927] chan_sip.c: Header 10: Content-Length: 0 (17) Dec 8 12:07:40 DEBUG[5927] chan_sip.c: Header 11: (0) Dec 8 12:07:40 DEBUG[5927] chan_sip.c: = Found Their Call ID: 05fcc4ea5c3c98dc42ea19752005ef30@10.1.1.48 Their Tag B8ACBE32-77879D39 Our tag: as7df987c3 Dec 8 12:07:40 DEBUG[5927] chan_sip.c: **** Received ACK (6) - Command in SIP ACK Dec 8 12:07:40 DEBUG[5927] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #50 Dec 8 12:07:40 DEBUG[5927] chan_sip.c: Stopping retransmission on '05fcc4ea5c3c98dc42ea19752005ef30@10.1.1.48' of Response 1: Match Found Dec 8 12:07:43 DEBUG[5927] chan_sip.c: Header 0: INVITE sip:1000@10.1.1.48:5060;user=phone SIP/2.0 (49) Dec 8 12:07:43 DEBUG[5927] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.1.1.200;branch=z9hG4bK47afe607C4AACBF0 (58) Dec 8 12:07:43 DEBUG[5927] chan_sip.c: Header 2: From: "Wilson" ;tag=CF4B58F5-91C3464 (66) Dec 8 12:07:43 DEBUG[5927] chan_sip.c: Header 3: To: (35) Dec 8 12:07:43 DEBUG[5927] chan_sip.c: Header 4: CSeq: 1 INVITE (14) Dec 8 12:07:43 DEBUG[5927] chan_sip.c: Header 5: Call-ID: e3023de1-30d300db-b521921a@10.1.1.200 (46) Dec 8 12:07:43 DEBUG[5927] chan_sip.c: Header 6: Contact: (40) Dec 8 12:07:43 DEBUG[5927] chan_sip.c: Header 7: Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER (96) Dec 8 12:07:43 DEBUG[5927] chan_sip.c: Header 8: User-Agent: PolycomSoundPointIP-SPIP_600-UA/1.6.2.0041 (54) Dec 8 12:07:43 DEBUG[5927] chan_sip.c: Header 9: Supported: 100rel,replace (25) Dec 8 12:07:43 DEBUG[5927] chan_sip.c: Header 10: Allow-Events: talk,hold,conference (34) Dec 8 12:07:43 DEBUG[5927] chan_sip.c: Header 11: Max-Forwards: 70 (16) Dec 8 12:07:43 DEBUG[5927] chan_sip.c: Header 12: Content-Type: application/sdp (29) Dec 8 12:07:43 DEBUG[5927] chan_sip.c: Header 13: Content-Length: 245 (19) Dec 8 12:07:43 DEBUG[5927] chan_sip.c: Header 14: (0) Dec 8 12:07:43 DEBUG[5927] chan_sip.c: Line: v=0 (3) Dec 8 12:07:43 DEBUG[5927] chan_sip.c: Line: o=- 1134072436 1134072436 IN IP4 10.1.1.200 (43) Dec 8 12:07:43 DEBUG[5927] chan_sip.c: Line: s=Polycom IP Phone (18) Dec 8 12:07:43 DEBUG[5927] chan_sip.c: Line: c=IN IP4 10.1.1.200 (19) Dec 8 12:07:43 DEBUG[5927] chan_sip.c: Line: t=0 0 (5) Dec 8 12:07:43 DEBUG[5927] chan_sip.c: Line: a=sendrecv (10) Dec 8 12:07:43 DEBUG[5927] chan_sip.c: Line: m=audio 2254 RTP/AVP 0 8 18 101 (31) Dec 8 12:07:43 DEBUG[5927] chan_sip.c: Line: a=rtpmap:0 PCMU/8000 (20) Dec 8 12:07:43 DEBUG[5927] chan_sip.c: Line: a=rtpmap:8 PCMA/8000 (20) Dec 8 12:07:43 DEBUG[5927] chan_sip.c: Line: a=rtpmap:18 G729/8000 (21) Dec 8 12:07:43 DEBUG[5927] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33) Dec 8 12:07:43 DEBUG[5927] chan_sip.c: = No match Their Call ID: 05fcc4ea5c3c98dc42ea19752005ef30@10.1.1.48 Their Tag B8ACBE32-77879D39 Our tag: as7df987c3 Dec 8 12:07:43 DEBUG[5927] chan_sip.c: Allocating new SIP dialog for e3023de1-30d300db-b521921a@10.1.1.200 - INVITE (With RTP) Dec 8 12:07:43 DEBUG[5927] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE Dec 8 12:07:43 DEBUG[5927] chan_sip.c: Begin: parsing SIP "Supported: 100rel,replace" Dec 8 12:07:43 DEBUG[5927] chan_sip.c: Found SIP option: -100rel- Dec 8 12:07:43 DEBUG[5927] chan_sip.c: Matched SIP option: 100rel Dec 8 12:07:43 DEBUG[5927] chan_sip.c: Found SIP option: -replace- Dec 8 12:07:43 DEBUG[5927] chan_sip.c: Found no match for SIP option: replace (Please file bug report!) Dec 8 12:07:43 DEBUG[5927] chan_sip.c: * SIP extension value: 2 for call e3023de1-30d300db-b521921a@10.1.1.200 Dec 8 12:07:43 DEBUG[5927] chan_sip.c: Setting NAT on RTP to 0 Dec 8 12:07:43 DEBUG[5927] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #51 Dec 8 12:07:43 DEBUG[5927] chan_sip.c: Header 0: ACK sip:1000@10.1.1.48:5060 SIP/2.0 (35) Dec 8 12:07:43 DEBUG[5927] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.1.1.200;branch=z9hG4bK47afe607C4AACBF0 (58) Dec 8 12:07:43 DEBUG[5927] chan_sip.c: Header 2: From: "Wilson" ;tag=CF4B58F5-91C3464 (66) Dec 8 12:07:43 DEBUG[5927] chan_sip.c: Header 3: To: ;tag=as3ce7f398 (50) Dec 8 12:07:43 DEBUG[5927] chan_sip.c: Header 4: CSeq: 1 ACK (11) Dec 8 12:07:43 DEBUG[5927] chan_sip.c: Header 5: Call-ID: e3023de1-30d300db-b521921a@10.1.1.200 (46) Dec 8 12:07:43 DEBUG[5927] chan_sip.c: Header 6: Contact: (40) Dec 8 12:07:43 DEBUG[5927] chan_sip.c: Header 7: Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER (96) Dec 8 12:07:43 DEBUG[5927] chan_sip.c: Header 8: User-Agent: PolycomSoundPointIP-SPIP_600-UA/1.6.2.0041 (54) Dec 8 12:07:43 DEBUG[5927] chan_sip.c: Header 9: Max-Forwards: 70 (16) Dec 8 12:07:43 DEBUG[5927] chan_sip.c: Header 10: Content-Length: 0 (17) Dec 8 12:07:43 DEBUG[5927] chan_sip.c: Header 11: (0) Dec 8 12:07:43 DEBUG[5927] chan_sip.c: = Found Their Call ID: e3023de1-30d300db-b521921a@10.1.1.200 Their Tag CF4B58F5-91C3464 Our tag: as3ce7f398 Dec 8 12:07:43 DEBUG[5927] chan_sip.c: **** Received ACK (6) - Command in SIP ACK Dec 8 12:07:43 DEBUG[5927] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #51 Dec 8 12:07:43 DEBUG[5927] chan_sip.c: Stopping retransmission on 'e3023de1-30d300db-b521921a@10.1.1.200' of Response 1: Match Found Dec 8 12:07:43 DEBUG[5927] chan_sip.c: Header 0: INVITE sip:1000@10.1.1.48:5060;user=phone SIP/2.0 (49) Dec 8 12:07:43 DEBUG[5927] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.1.1.200;branch=z9hG4bKf818acce2BE0902F (58) Dec 8 12:07:43 DEBUG[5927] chan_sip.c: Header 2: From: "Wilson" ;tag=CF4B58F5-91C3464 (66) Dec 8 12:07:43 DEBUG[5927] chan_sip.c: Header 3: To: (35) Dec 8 12:07:43 DEBUG[5927] chan_sip.c: Header 4: CSeq: 2 INVITE (14) Dec 8 12:07:43 DEBUG[5927] chan_sip.c: Header 5: Call-ID: e3023de1-30d300db-b521921a@10.1.1.200 (46) Dec 8 12:07:43 DEBUG[5927] chan_sip.c: Header 6: Contact: (40) Dec 8 12:07:43 DEBUG[5927] chan_sip.c: Header 7: Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER (96) Dec 8 12:07:43 DEBUG[5927] chan_sip.c: Header 8: User-Agent: PolycomSoundPointIP-SPIP_600-UA/1.6.2.0041 (54) Dec 8 12:07:43 DEBUG[5927] chan_sip.c: Header 9: Supported: 100rel,replace (25) Dec 8 12:07:43 DEBUG[5927] chan_sip.c: Header 10: Allow-Events: talk,hold,conference (34) Dec 8 12:07:43 DEBUG[5927] chan_sip.c: Header 11: Proxy-Authorization: Digest username="wilson-polycom", realm="asterisk", nonce="5f1de370", uri="sip:1000@10.1.1.48:5060;user=phone", response="db1250508d3ac91c94b126bcb3e6aca0", algorithm=MD5 (191) Dec 8 12:07:43 DEBUG[5927] chan_sip.c: Header 12: Max-Forwards: 70 (16) Dec 8 12:07:43 DEBUG[5927] chan_sip.c: Header 13: Content-Type: application/sdp (29) Dec 8 12:07:43 DEBUG[5927] chan_sip.c: Header 14: Content-Length: 245 (19) Dec 8 12:07:43 DEBUG[5927] chan_sip.c: Header 15: (0) Dec 8 12:07:43 DEBUG[5927] chan_sip.c: Line: v=0 (3) Dec 8 12:07:43 DEBUG[5927] chan_sip.c: Line: o=- 1134072436 1134072436 IN IP4 10.1.1.200 (43) Dec 8 12:07:43 DEBUG[5927] chan_sip.c: Line: s=Polycom IP Phone (18) Dec 8 12:07:43 DEBUG[5927] chan_sip.c: Line: c=IN IP4 10.1.1.200 (19) Dec 8 12:07:43 DEBUG[5927] chan_sip.c: Line: t=0 0 (5) Dec 8 12:07:43 DEBUG[5927] chan_sip.c: Line: a=sendrecv (10) Dec 8 12:07:43 DEBUG[5927] chan_sip.c: Line: m=audio 2254 RTP/AVP 0 8 18 101 (31) Dec 8 12:07:43 DEBUG[5927] chan_sip.c: Line: a=rtpmap:0 PCMU/8000 (20) Dec 8 12:07:43 DEBUG[5927] chan_sip.c: Line: a=rtpmap:8 PCMA/8000 (20) Dec 8 12:07:43 DEBUG[5927] chan_sip.c: Line: a=rtpmap:18 G729/8000 (21) Dec 8 12:07:43 DEBUG[5927] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33) Dec 8 12:07:43 DEBUG[5927] chan_sip.c: = Found Their Call ID: e3023de1-30d300db-b521921a@10.1.1.200 Their Tag CF4B58F5-91C3464 Our tag: as3ce7f398 Dec 8 12:07:43 DEBUG[5927] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE Dec 8 12:07:43 DEBUG[5927] chan_sip.c: Setting NAT on RTP to 0 Dec 8 12:07:43 DEBUG[5927] chan_sip.c: Peer audio RTP is at port 10.1.1.200:2254 Dec 8 12:07:43 DEBUG[5927] chan_sip.c: Checking SIP call limits for device wilson-polycom Dec 8 12:07:43 DEBUG[5927] chan_sip.c: Updating call counter for incoming call Dec 8 12:07:43 DEBUG[5927] chan_sip.c: build_route: Contact hop: Dec 8 12:07:43 DEBUG[5922] chan_sip.c: Checking device state for peer wilson-polycom Dec 8 12:07:43 DEBUG[5922] devicestate.c: Changing state for SIP/wilson-polycom - state 2 (In use) Dec 8 12:07:43 DEBUG[5922] chan_sip.c: Checking device state for peer wilson-polycom Dec 8 12:07:43 DEBUG[5983] pbx.c: Launching 'Dial' Dec 8 12:07:43 DEBUG[5983] chan_zap.c: Using channel 1 Dec 8 12:07:43 DEBUG[5922] devicestate.c: Changing state for Zap/1 - state 2 (In use) Dec 8 12:07:43 DEBUG[5983] channel.c: Not copying variable STACK-from-sip-1000-1. Dec 8 12:07:43 DEBUG[5983] channel.c: Not copying variable SIPCALLID. Dec 8 12:07:43 DEBUG[5983] channel.c: Not copying variable SIPUSERAGENT. Dec 8 12:07:43 DEBUG[5983] channel.c: Not copying variable SIPDOMAIN. Dec 8 12:07:43 DEBUG[5983] channel.c: Not copying variable SIPURI. Dec 8 12:07:43 DEBUG[5922] channel.c: Avoiding initial deadlock for 'Zap/1-1' Dec 8 12:07:43 DEBUG[5983] channel.c: Set channel Zap/1-1 to read format ulaw Dec 8 12:07:43 DEBUG[5983] channel.c: Set channel SIP/wilson-polycom-0c48 to write format ulaw Dec 8 12:07:43 DEBUG[5983] channel.c: Set channel SIP/wilson-polycom-0c48 to read format ulaw Dec 8 12:07:43 DEBUG[5983] channel.c: Set channel Zap/1-1 to write format ulaw Dec 8 12:07:43 DEBUG[5922] devicestate.c: Changing state for Zap/1 - state 6 (Ringing) Dec 8 12:07:45 DEBUG[5983] chan_zap.c: Exception on 18, channel 1 Dec 8 12:07:45 DEBUG[5983] chan_zap.c: Got event Ringer Off(11) on channel 1 (index 0) Dec 8 12:07:46 DEBUG[5983] chan_zap.c: Restored conferencing Dec 8 12:07:49 DEBUG[5983] chan_zap.c: Exception on 18, channel 1 Dec 8 12:07:49 DEBUG[5983] chan_zap.c: Got event Ringer On(10) on channel 1 (index 0) Dec 8 12:07:50 DEBUG[5927] chan_sip.c: Header 0: REFER sip:915106041769@10.1.1.48 SIP/2.0 (40) Dec 8 12:07:50 DEBUG[5927] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.1.1.200;branch=z9hG4bKacaf64031FADBECC (58) Dec 8 12:07:50 DEBUG[5927] chan_sip.c: Header 2: From: ;tag=B8ACBE32-77879D39 (59) Dec 8 12:07:50 DEBUG[5927] chan_sip.c: Header 3: To: "Wilson J. Chan" ;tag=as7df987c3 (64) Dec 8 12:07:50 DEBUG[5927] chan_sip.c: Header 4: CSeq: 2 REFER (13) Dec 8 12:07:50 DEBUG[5927] chan_sip.c: Header 5: Call-ID: 05fcc4ea5c3c98dc42ea19752005ef30@10.1.1.48 (51) Dec 8 12:07:50 DEBUG[5927] chan_sip.c: Header 6: Contact: (40) Dec 8 12:07:50 DEBUG[5927] chan_sip.c: Header 7: User-Agent: PolycomSoundPointIP-SPIP_600-UA/1.6.2.0041 (54) Dec 8 12:07:50 DEBUG[5927] chan_sip.c: Header 8: Refer-To: (142) Dec 8 12:07:50 DEBUG[5927] chan_sip.c: Header 9: Referred-By: (44) Dec 8 12:07:50 DEBUG[5927] chan_sip.c: Header 10: Max-Forwards: 70 (16) Dec 8 12:07:50 DEBUG[5927] chan_sip.c: Header 11: Content-Length: 0 (17) Dec 8 12:07:50 DEBUG[5927] chan_sip.c: Header 12: (0) Dec 8 12:07:50 DEBUG[5927] chan_sip.c: = No match Their Call ID: e3023de1-30d300db-b521921a@10.1.1.200 Their Tag CF4B58F5-91C3464 Our tag: as0ae8ca56 Dec 8 12:07:50 DEBUG[5927] chan_sip.c: = Found Their Call ID: 05fcc4ea5c3c98dc42ea19752005ef30@10.1.1.48 Their Tag B8ACBE32-77879D39 Our tag: as7df987c3 Dec 8 12:07:50 DEBUG[5927] chan_sip.c: **** Received REFER (9) - Command in SIP REFER Dec 8 12:07:50 DEBUG[5927] chan_sip.c: SIP call transfer received for call 05fcc4ea5c3c98dc42ea19752005ef30@10.1.1.48 (REFER)! Dec 8 12:07:50 DEBUG[5927] chan_sip.c: Assigning Replace-Call-ID Info e3023de1-30d300db-b521921a@10.1.1.200 to REPLACE_CALL_ID Dec 8 12:07:50 DEBUG[5927] chan_sip.c: 202 Accepted (supervised) Dec 8 12:07:50 DEBUG[5927] channel.c: Set channel Zap/3-1 to write format ulaw Dec 8 12:07:50 DEBUG[5927] channel.c: Scheduling timer at 0 sample intervals Dec 8 12:07:50 DEBUG[5927] channel.c: Planning to masquerade channel Zap/3-1 into the structure of SIP/wilson-polycom-0c48 Dec 8 12:07:50 DEBUG[5927] channel.c: Done planning to masquerade channel Zap/3-1 into the structure of SIP/wilson-polycom-0c48 Dec 8 12:07:50 DEBUG[5983] channel.c: Actually Masquerading Zap/3-1(6) into the structure of SIP/wilson-polycom-0c48(4) Dec 8 12:07:50 DEBUG[5983] channel.c: Got clone lock for masquerade on 'Zap/3-1' at 0x9370b5c Dec 8 12:07:50 DEBUG[5927] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #53 Dec 8 12:07:50 DEBUG[5927] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #54 Dec 8 12:07:50 DEBUG[5983] chan_sip.c: Hangup call Zap/3-1, SIP callid e3023de1-30d300db-b521921a@10.1.1.200) Dec 8 12:07:50 DEBUG[5983] chan_sip.c: update_call_counter(wilson-polycom) - decrement call limit counter Dec 8 12:07:50 DEBUG[5983] chan_sip.c: Updating call counter for incoming call Dec 8 12:07:50 DEBUG[5983] chan_sip.c: AST hangup cause 16 (no match found in SIP) Dec 8 12:07:50 DEBUG[5983] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #55 Dec 8 12:07:50 DEBUG[5983] channel.c: Set channel Zap/3-1 to write format ulaw Dec 8 12:07:50 DEBUG[5983] channel.c: Set channel Zap/3-1 to read format ulaw Dec 8 12:07:50 DEBUG[5983] channel.c: Putting channel Zap/3-1 in 4/4 formats Dec 8 12:07:50 DEBUG[5983] chan_zap.c: New owner for channel 3 is Zap/3-1 Dec 8 12:07:50 DEBUG[5983] chan_zap.c: Updated conferencing on 3, with 0 conference users Dec 8 12:07:50 DEBUG[5983] chan_zap.c: Updated conferencing on 3, with 0 conference users Dec 8 12:07:50 DEBUG[5983] channel.c: Released clone lock on 'SIP/wilson-polycom-0c48' Dec 8 12:07:50 DEBUG[5983] channel.c: Done Masquerading Zap/3-1 (6) Dec 8 12:07:50 DEBUG[5983] chan_zap.c: Dropping frame since I'm still dialing on Zap/1-1... Dec 8 12:07:50 DEBUG[5981] channel.c: Didn't get a frame from channel: SIP/wilson-polycom-0c48 Dec 8 12:07:50 DEBUG[5981] channel.c: Bridge stops bridging channels SIP/wilson-polycom-0c48 and SIP/wilson-polycom-2df5 Dec 8 12:07:50 DEBUG[5981] channel.c: Hanging up channel 'SIP/wilson-polycom-2df5' Dec 8 12:07:50 DEBUG[5981] chan_sip.c: Hangup call SIP/wilson-polycom-2df5, SIP callid 05fcc4ea5c3c98dc42ea19752005ef30@10.1.1.48) Dec 8 12:07:50 DEBUG[5981] chan_sip.c: update_call_counter(wilson-polycom) - decrement call limit counter Dec 8 12:07:50 DEBUG[5981] chan_sip.c: Updating call counter for incoming call Dec 8 12:07:50 DEBUG[5981] app_dial.c: Exiting with DIALSTATUS=ANSWER. Dec 8 12:07:50 DEBUG[5981] pbx.c: Spawn extension (two-rings,1,1) exited non-zero on 'SIP/wilson-polycom-0c48' Dec 8 12:07:50 DEBUG[5981] channel.c: Hanging up zombie 'SIP/wilson-polycom-0c48' Dec 8 12:07:50 DEBUG[5922] chan_sip.c: Checking device state for peer wilson-polycom Dec 8 12:07:50 DEBUG[5922] devicestate.c: Changing state for SIP/wilson-polycom - state 1 (Not in use) Dec 8 12:07:50 DEBUG[5922] chan_sip.c: Checking device state for peer wilson-polycom Dec 8 12:07:50 DEBUG[5922] chan_sip.c: Checking device state for peer wilson-polycom Dec 8 12:07:50 DEBUG[5922] devicestate.c: Changing state for SIP/wilson-polycom - state 1 (Not in use) Dec 8 12:07:50 DEBUG[5922] chan_sip.c: Checking device state for peer wilson-polycom Dec 8 12:07:50 DEBUG[5983] chan_zap.c: Dropping frame since I'm still dialing on Zap/1-1... Dec 8 12:07:50 DEBUG[5983] chan_zap.c: Dropping frame since I'm still dialing on Zap/1-1... Dec 8 12:07:50 DEBUG[5983] chan_zap.c: Dropping frame since I'm still dialing on Zap/1-1... Dec 8 12:07:50 DEBUG[5983] chan_zap.c: Dropping frame since I'm still dialing on Zap/1-1... Dec 8 12:07:50 DEBUG[5927] chan_sip.c: Header 0: SIP/2.0 200 OK (14) Dec 8 12:07:50 DEBUG[5927] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.1.1.48:5060;branch=z9hG4bK3e423f10;rport (60) Dec 8 12:07:50 DEBUG[5927] chan_sip.c: Header 2: From: "Wilson J. Chan" ;tag=as7df987c3 (66) Dec 8 12:07:50 DEBUG[5927] chan_sip.c: Header 3: To: ;tag=B8ACBE32-77879D39 (57) Dec 8 12:07:50 DEBUG[5927] chan_sip.c: Header 4: CSeq: 103 NOTIFY (16) Dec 8 12:07:50 DEBUG[5927] chan_sip.c: Header 5: Call-ID: 05fcc4ea5c3c98dc42ea19752005ef30@10.1.1.48 (51) Dec 8 12:07:50 DEBUG[5927] chan_sip.c: Header 6: Contact: (40) Dec 8 12:07:50 DEBUG[5927] chan_sip.c: Header 7: Event: refer;id=2 (17) Dec 8 12:07:50 DEBUG[5927] chan_sip.c: Header 8: User-Agent: PolycomSoundPointIP-SPIP_600-UA/1.6.2.0041 (54) Dec 8 12:07:50 DEBUG[5927] chan_sip.c: Header 9: Content-Length: 0 (17) Dec 8 12:07:50 DEBUG[5927] chan_sip.c: Header 10: (0) Dec 8 12:07:50 DEBUG[5927] chan_sip.c: = No match Their Call ID: e3023de1-30d300db-b521921a@10.1.1.200 Their Tag CF4B58F5-91C3464 Our tag: as0ae8ca56 Dec 8 12:07:50 DEBUG[5927] chan_sip.c: = Found Their Call ID: 05fcc4ea5c3c98dc42ea19752005ef30@10.1.1.48 Their Tag B8ACBE32-77879D39 Our tag: as7df987c3 Dec 8 12:07:50 DEBUG[5927] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #53 Dec 8 12:07:50 DEBUG[5927] chan_sip.c: Stopping retransmission on '05fcc4ea5c3c98dc42ea19752005ef30@10.1.1.48' of Request 103: Match Found Dec 8 12:07:50 DEBUG[5983] chan_zap.c: Dropping frame since I'm still dialing on Zap/1-1... Dec 8 12:07:51 DEBUG[5927] chan_sip.c: Header 0: BYE sip:915106041769@10.1.1.48 SIP/2.0 (38) Dec 8 12:07:51 DEBUG[5927] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.1.1.200;branch=z9hG4bKccba349dF319D3B6 (58) Dec 8 12:07:51 DEBUG[5927] chan_sip.c: Header 2: From: ;tag=B8ACBE32-77879D39 (59) Dec 8 12:07:51 DEBUG[5927] chan_sip.c: Header 3: To: "Wilson J. Chan" ;tag=as7df987c3 (64) Dec 8 12:07:51 DEBUG[5927] chan_sip.c: Header 4: CSeq: 3 BYE (11) Dec 8 12:07:51 DEBUG[5927] chan_sip.c: Header 5: Call-ID: 05fcc4ea5c3c98dc42ea19752005ef30@10.1.1.48 (51) Dec 8 12:07:51 DEBUG[5927] chan_sip.c: Header 6: Contact: (40) Dec 8 12:07:51 DEBUG[5927] chan_sip.c: Header 7: User-Agent: PolycomSoundPointIP-SPIP_600-UA/1.6.2.0041 (54) Dec 8 12:07:51 DEBUG[5927] chan_sip.c: Header 8: Max-Forwards: 70 (16) Dec 8 12:07:51 DEBUG[5927] chan_sip.c: Header 9: Content-Length: 0 (17) Dec 8 12:07:51 DEBUG[5927] chan_sip.c: Header 10: (0) Dec 8 12:07:51 DEBUG[5927] chan_sip.c: = No match Their Call ID: e3023de1-30d300db-b521921a@10.1.1.200 Their Tag CF4B58F5-91C3464 Our tag: as0ae8ca56 Dec 8 12:07:51 DEBUG[5927] chan_sip.c: = Found Their Call ID: 05fcc4ea5c3c98dc42ea19752005ef30@10.1.1.48 Their Tag B8ACBE32-77879D39 Our tag: as7df987c3 Dec 8 12:07:51 DEBUG[5927] chan_sip.c: **** Received BYE (8) - Command in SIP BYE Dec 8 12:07:51 DEBUG[5983] chan_zap.c: Dropping frame since I'm still dialing on Zap/1-1... Dec 8 12:07:51 DEBUG[5983] chan_zap.c: Dropping frame since I'm still dialing on Zap/1-1... Dec 8 12:07:51 DEBUG[5983] chan_zap.c: Dropping frame since I'm still dialing on Zap/1-1... Dec 8 12:07:51 DEBUG[5983] chan_zap.c: Dropping frame since I'm still dialing on Zap/1-1... Dec 8 12:07:51 DEBUG[5927] chan_sip.c: Header 0: SIP/2.0 500 Internal Server Error (33) Dec 8 12:07:51 DEBUG[5927] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.1.1.48:5060;branch=z9hG4bK341dca0d;rport (60) Dec 8 12:07:51 DEBUG[5927] chan_sip.c: Header 2: From: "Wilson J. Chan" ;tag=as7df987c3 (66) Dec 8 12:07:51 DEBUG[5927] chan_sip.c: Header 3: To: ;tag=B8ACBE32-77879D39 (57) Dec 8 12:07:51 DEBUG[5927] chan_sip.c: Header 4: CSeq: 104 BYE (13) Dec 8 12:07:51 DEBUG[5927] chan_sip.c: Header 5: Call-ID: 05fcc4ea5c3c98dc42ea19752005ef30@10.1.1.48 (51) Dec 8 12:07:51 DEBUG[5927] chan_sip.c: Header 6: Contact: (40) Dec 8 12:07:51 DEBUG[5927] chan_sip.c: Header 7: User-Agent: PolycomSoundPointIP-SPIP_600-UA/1.6.2.0041 (54) Dec 8 12:07:51 DEBUG[5927] chan_sip.c: Header 8: Content-Length: 0 (17) Dec 8 12:07:51 DEBUG[5927] chan_sip.c: Header 9: (0) Dec 8 12:07:51 DEBUG[5927] chan_sip.c: = No match Their Call ID: e3023de1-30d300db-b521921a@10.1.1.200 Their Tag CF4B58F5-91C3464 Our tag: as0ae8ca56 Dec 8 12:07:51 DEBUG[5927] chan_sip.c: = Found Their Call ID: 05fcc4ea5c3c98dc42ea19752005ef30@10.1.1.48 Their Tag B8ACBE32-77879D39 Our tag: as7df987c3 Dec 8 12:07:51 DEBUG[5927] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #54 Dec 8 12:07:51 DEBUG[5927] chan_sip.c: Stopping retransmission on '05fcc4ea5c3c98dc42ea19752005ef30@10.1.1.48' of Request 104: Match Found Dec 8 12:07:51 DEBUG[5983] chan_zap.c: Dropping frame since I'm still dialing on Zap/1-1... Dec 8 12:07:51 DEBUG[5983] chan_zap.c: Dropping frame since I'm still dialing on Zap/1-1... Dec 8 12:07:51 DEBUG[5983] chan_zap.c: Dropping frame since I'm still dialing on Zap/1-1... Dec 8 12:07:51 DEBUG[5983] chan_zap.c: Dropping frame since I'm still dialing on Zap/1-1... Dec 8 12:07:51 DEBUG[5927] chan_sip.c: Header 0: ACK sip:1000@10.1.1.48 SIP/2.0 (30) Dec 8 12:07:51 DEBUG[5927] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.1.1.200;branch=z9hG4bKf818acce2BE0902F (58) Dec 8 12:07:51 DEBUG[5927] chan_sip.c: Header 2: From: "Wilson" ;tag=CF4B58F5-91C3464 (66) Dec 8 12:07:51 DEBUG[5927] chan_sip.c: Header 3: To: ;tag=as0ae8ca56 (50) Dec 8 12:07:51 DEBUG[5927] chan_sip.c: Header 4: CSeq: 2 ACK (11) Dec 8 12:07:51 DEBUG[5927] chan_sip.c: Header 5: Call-ID: e3023de1-30d300db-b521921a@10.1.1.200 (46) Dec 8 12:07:51 DEBUG[5927] chan_sip.c: Header 6: Contact: (40) Dec 8 12:07:51 DEBUG[5927] chan_sip.c: Header 7: Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER (96) Dec 8 12:07:51 DEBUG[5927] chan_sip.c: Header 8: User-Agent: PolycomSoundPointIP-SPIP_600-UA/1.6.2.0041 (54) Dec 8 12:07:51 DEBUG[5927] chan_sip.c: Header 9: Max-Forwards: 70 (16) Dec 8 12:07:51 DEBUG[5927] chan_sip.c: Header 10: Content-Length: 0 (17) Dec 8 12:07:51 DEBUG[5927] chan_sip.c: Header 11: (0) Dec 8 12:07:51 DEBUG[5927] chan_sip.c: = Found Their Call ID: e3023de1-30d300db-b521921a@10.1.1.200 Their Tag CF4B58F5-91C3464 Our tag: as0ae8ca56 Dec 8 12:07:51 DEBUG[5927] chan_sip.c: **** Received ACK (6) - Command in SIP ACK Dec 8 12:07:51 DEBUG[5927] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #55 Dec 8 12:07:51 DEBUG[5927] chan_sip.c: Stopping retransmission on 'e3023de1-30d300db-b521921a@10.1.1.200' of Response 2: Match Found Dec 8 12:07:51 DEBUG[5983] chan_zap.c: Dropping frame since I'm still dialing on Zap/1-1... Dec 8 12:07:51 DEBUG[5983] chan_zap.c: Dropping frame since I'm still dialing on Zap/1-1... Dec 8 12:07:51 DEBUG[5983] chan_zap.c: Dropping frame since I'm still dialing on Zap/1-1... Dec 8 12:07:51 DEBUG[5983] chan_zap.c: Dropping frame since I'm still dialing on Zap/1-1... Dec 8 12:07:51 DEBUG[5983] chan_zap.c: Dropping frame since I'm still dialing on Zap/1-1... Dec 8 12:07:51 DEBUG[5983] chan_zap.c: Dropping frame since I'm still dialing on Zap/1-1... Dec 8 12:07:51 DEBUG[5983] chan_zap.c: Dropping frame since I'm still dialing on Zap/1-1... Dec 8 12:07:51 DEBUG[5983] chan_zap.c: Dropping frame since I'm still dialing on Zap/1-1... Dec 8 12:07:51 DEBUG[5983] chan_zap.c: Dropping frame since I'm still dialing on Zap/1-1... Dec 8 12:07:51 DEBUG[5983] chan_zap.c: Dropping frame since I'm still dialing on Zap/1-1... Dec 8 12:07:51 DEBUG[5983] chan_zap.c: Dropping frame since I'm still dialing on Zap/1-1... Dec 8 12:07:51 DEBUG[5983] chan_zap.c: Dropping frame since I'm still dialing on Zap/1-1... Dec 8 12:07:51 DEBUG[5983] chan_zap.c: Dropping frame since I'm still dialing on Zap/1-1... Dec 8 12:07:51 DEBUG[5983] chan_zap.c: Dropping frame since I'm still dialing on Zap/1-1... Dec 8 12:07:51 DEBUG[5983] chan_zap.c: Dropping frame since I'm still dialing on Zap/1-1... Dec 8 12:07:51 DEBUG[5983] chan_zap.c: Dropping frame since I'm still dialing on Zap/1-1... Dec 8 12:07:51 DEBUG[5983] chan_zap.c: Dropping frame since I'm still dialing on Zap/1-1... Dec 8 12:07:51 DEBUG[5983] chan_zap.c: Dropping frame since I'm still dialing on Zap/1-1... Dec 8 12:07:51 DEBUG[5983] chan_zap.c: Dropping frame since I'm still dialing on Zap/1-1... Dec 8 12:07:51 DEBUG[5983] chan_zap.c: Dropping frame since I'm still dialing on Zap/1-1... Dec 8 12:07:51 DEBUG[5983] chan_zap.c: Dropping frame since I'm still dialing on Zap/1-1... Dec 8 12:07:51 DEBUG[5983] chan_zap.c: Dropping frame since I'm still dialing on Zap/1-1... Dec 8 12:07:51 DEBUG[5983] chan_zap.c: Dropping frame since I'm still dialing on Zap/1-1... Dec 8 12:07:51 DEBUG[5983] chan_zap.c: Dropping frame since I'm still dialing on Zap/1-1... Dec 8 12:07:51 DEBUG[5983] chan_zap.c: Dropping frame since I'm still dialing on Zap/1-1... Dec 8 12:07:51 DEBUG[5983] chan_zap.c: Dropping frame since I'm still dialing on Zap/1-1... Dec 8 12:07:51 DEBUG[5983] chan_zap.c: Dropping frame since I'm still dialing on Zap/1-1... Dec 8 12:07:51 DEBUG[5983] chan_zap.c: Dropping frame since I'm still dialing on Zap/1-1... Dec 8 12:07:51 DEBUG[5983] chan_zap.c: Dropping frame since I'm still dialing on Zap/1-1... Dec 8 12:07:51 DEBUG[5983] chan_zap.c: Dropping frame since I'm still dialing on Zap/1-1... Dec 8 12:07:51 DEBUG[5983] chan_zap.c: Dropping frame since I'm still dialing on Zap/1-1... Dec 8 12:07:51 DEBUG[5983] chan_zap.c: Dropping frame since I'm still dialing on Zap/1-1... Dec 8 12:07:51 DEBUG[5983] chan_zap.c: Dropping frame since I'm still dialing on Zap/1-1... Dec 8 12:07:51 DEBUG[5983] chan_zap.c: Dropping frame since I'm still dialing on Zap/1-1... Dec 8 12:07:51 DEBUG[5983] chan_zap.c: Dropping frame since I'm still dialing on Zap/1-1... Dec 8 12:07:51 DEBUG[5983] chan_zap.c: Dropping frame since I'm still dialing on Zap/1-1... Dec 8 12:07:51 DEBUG[5983] chan_zap.c: Dropping frame since I'm still dialing on Zap/1-1... Dec 8 12:07:51 DEBUG[5983] chan_zap.c: Dropping frame since I'm still dialing on Zap/1-1... Dec 8 12:07:51 DEBUG[5983] chan_zap.c: Dropping frame since I'm still dialing on Zap/1-1... Dec 8 12:07:51 DEBUG[5983] chan_zap.c: Exception on 18, channel 1 Dec 8 12:07:51 DEBUG[5983] chan_zap.c: Got event Ringer Off(11) on channel 1 (index 0) Dec 8 12:07:51 DEBUG[5983] chan_zap.c: Dropping frame since I'm still dialing on Zap/1-1... Dec 8 12:07:51 DEBUG[5983] chan_zap.c: Dropping frame since I'm still dialing on Zap/1-1... Dec 8 12:07:51 DEBUG[5983] chan_zap.c: Dropping frame since I'm still dialing on Zap/1-1... Dec 8 12:07:52 DEBUG[5983] chan_zap.c: Dropping frame since I'm still dialing on Zap/1-1... Dec 8 12:07:52 DEBUG[5983] chan_zap.c: Dropping frame since I'm still dialing on Zap/1-1... Dec 8 12:07:52 DEBUG[5983] chan_zap.c: Dropping frame since I'm still dialing on Zap/1-1... Dec 8 12:07:52 DEBUG[5983] chan_zap.c: Dropping frame since I'm still dialing on Zap/1-1... Dec 8 12:07:52 DEBUG[5983] chan_zap.c: Dropping frame since I'm still dialing on Zap/1-1... Dec 8 12:07:52 DEBUG[5983] chan_zap.c: Dropping frame since I'm still dialing on Zap/1-1... Dec 8 12:07:52 DEBUG[5983] chan_zap.c: Dropping frame since I'm still dialing on Zap/1-1... Dec 8 12:07:52 DEBUG[5983] chan_zap.c: Exception on 18, channel 1 Dec 8 12:07:52 DEBUG[5983] chan_zap.c: Got event Ring/Answered(2) on channel 1 (index 0) Dec 8 12:07:52 DEBUG[5983] chan_zap.c: Enabled echo cancellation on channel 1 Dec 8 12:07:52 DEBUG[5983] chan_zap.c: No echo training requested Dec 8 12:07:52 DEBUG[5983] chan_zap.c: channel 1 answered Dec 8 12:07:52 DEBUG[5983] chan_zap.c: Requested indication -1 on channel Zap/3-1 Dec 8 12:07:52 DEBUG[5983] channel.c: Set channel Zap/3-1 to read format slin Dec 8 12:07:52 DEBUG[5983] channel.c: Set channel Zap/1-1 to write format slin Dec 8 12:07:52 DEBUG[5983] channel.c: Set channel Zap/1-1 to read format slin Dec 8 12:07:52 DEBUG[5983] channel.c: Set channel Zap/3-1 to write format slin Dec 8 12:07:52 DEBUG[5983] chan_zap.c: master: 3, slave: 1, nothingok: 0 Dec 8 12:07:52 DEBUG[5983] chan_zap.c: Stopping tones on 3/0 talking to 1/0 Dec 8 12:07:52 DEBUG[5983] chan_zap.c: Stopping tones on 1/0 talking to 3/0 Dec 8 12:07:52 DEBUG[5983] chan_zap.c: Making 1 slave to master 3 at 0 Dec 8 12:07:52 DEBUG[5983] chan_zap.c: Added 18 to conference 9/3 Dec 8 12:07:52 DEBUG[5983] chan_zap.c: Added 21 to conference 9/1 Dec 8 12:07:52 DEBUG[5983] chan_zap.c: Updated conferencing on 3, with 0 conference users Dec 8 12:07:52 DEBUG[5983] chan_zap.c: Updated conferencing on 1, with 0 conference users Dec 8 12:07:52 DEBUG[5922] devicestate.c: Changing state for Zap/1 - state 2 (In use) Dec 8 12:07:56 DEBUG[5983] chan_zap.c: Exception on 21, channel 3 Dec 8 12:07:56 DEBUG[5983] chan_zap.c: Got event On hook(1) on channel 3 (index 0) Dec 8 12:07:56 DEBUG[5983] chan_zap.c: disabled echo cancellation on channel 3 Dec 8 12:07:56 DEBUG[5983] chan_zap.c: Enabled echo cancellation on channel 3 Dec 8 12:07:56 DEBUG[5983] chan_zap.c: Echo cancellation already on Dec 8 12:07:56 DEBUG[5983] chan_zap.c: Unlinking slave 1 from 3 Dec 8 12:07:56 DEBUG[5983] chan_zap.c: Removed 18 from conference 9/3 Dec 8 12:07:56 DEBUG[5983] chan_zap.c: Removed 21 from conference 9/1 Dec 8 12:07:56 DEBUG[5983] chan_zap.c: Updated conferencing on 3, with 0 conference users Dec 8 12:07:56 DEBUG[5983] channel.c: Returning from native bridge, channels: Zap/3-1, Zap/1-1 Dec 8 12:07:56 DEBUG[5983] channel.c: Hanging up channel 'Zap/1-1' Dec 8 12:07:56 DEBUG[5983] chan_zap.c: zt_hangup(Zap/1-1) Dec 8 12:07:56 DEBUG[5983] chan_zap.c: Hangup: channel: 1 index = 0, normal = 18, callwait = -1, thirdcall = -1 Dec 8 12:07:56 DEBUG[5983] chan_zap.c: disabled echo cancellation on channel 1 Dec 8 12:07:56 DEBUG[5983] chan_zap.c: Set option TDD MODE, value: OFF(0) on Zap/1-1 Dec 8 12:07:56 DEBUG[5983] chan_zap.c: Updated conferencing on 1, with 0 conference users Dec 8 12:07:56 DEBUG[5983] app_dial.c: Exiting with DIALSTATUS=ANSWER. Dec 8 12:07:56 DEBUG[5983] pbx.c: Spawn extension (from-sip,1000,1) exited non-zero on 'Zap/3-1' Dec 8 12:07:56 DEBUG[5983] channel.c: Hanging up channel 'Zap/3-1' Dec 8 12:07:56 DEBUG[5983] chan_zap.c: zt_hangup(Zap/3-1) Dec 8 12:07:56 DEBUG[5983] chan_zap.c: Hangup: channel: 3 index = 0, normal = 21, callwait = -1, thirdcall = -1 Dec 8 12:07:56 DEBUG[5983] chan_zap.c: disabled echo cancellation on channel 3 Dec 8 12:07:56 DEBUG[5983] chan_zap.c: Set option TDD MODE, value: OFF(0) on Zap/3-1 Dec 8 12:07:56 DEBUG[5983] chan_zap.c: Updated conferencing on 3, with 0 conference users Dec 8 12:07:56 DEBUG[5922] devicestate.c: Changing state for Zap/1 - state 0 (Unknown) Dec 8 12:07:56 DEBUG[5922] devicestate.c: Changing state for Zap/3 - state 0 (Unknown) Dec 8 12:07:56 DEBUG[5929] chan_zap.c: Monitor doohicky got event Hook Transition Complete on channel 1 Dec 8 12:07:56 DEBUG[5929] chan_zap.c: Monitor doohicky got event On hook on channel 1 Dec 8 12:07:56 DEBUG[5929] chan_zap.c: disabled echo cancellation on channel 1