Initial state with all lines busied out: Channel Location State Application(Data) SIP/snom360-0958e6e8 (None) Up Bridged Call(Zap/32-1) Zap/32-1 101@extensions:5 Up Dial(SIP/snom360|20|) Zap/1-1 s@isdn-external:1 Up Bridged Call(Zap/33-1) Zap/33-1 101@external:1 Up Dial(Zap/G1/101) Zap/2-1 s@isdn-external:1 Up Bridged Call(Zap/34-1) Zap/34-1 101@external:1 Up Dial(Zap/G1/101) Zap/3-1 s@isdn-external:1 Up Bridged Call(Zap/35-1) Zap/35-1 101@external:1 Up Dial(Zap/G1/101) Zap/4-1 s@isdn-external:1 Up Bridged Call(Zap/36-1) Zap/36-1 101@external:1 Up Dial(Zap/G1/101) Zap/5-1 s@isdn-external:1 Up Bridged Call(Zap/37-1) Zap/37-1 101@external:1 Up Dial(Zap/G1/101) Zap/6-1 s@isdn-external:1 Up Bridged Call(Zap/38-1) Zap/38-1 101@external:1 Up Dial(Zap/G1/101) Zap/7-1 s@isdn-external:1 Up Bridged Call(Zap/39-1) Zap/39-1 101@external:1 Up Dial(Zap/G1/101) Zap/8-1 s@isdn-external:1 Up Bridged Call(Zap/40-1) Zap/40-1 101@external:1 Up Dial(Zap/G1/101) Zap/9-1 s@isdn-external:1 Up Bridged Call(Zap/41-1) Zap/41-1 101@external:1 Up Dial(Zap/G1/101) Zap/10-1 s@isdn-external:1 Up Bridged Call(Zap/42-1) Zap/42-1 101@external:1 Up Dial(Zap/G1/101) Zap/11-1 s@isdn-external:1 Up Bridged Call(Zap/43-1) Zap/43-1 101@external:1 Up Dial(Zap/G1/101) Zap/12-1 s@isdn-external:1 Up Bridged Call(Zap/44-1) Zap/44-1 101@external:1 Up Dial(Zap/G1/101) Zap/13-1 s@isdn-external:1 Up Bridged Call(Zap/45-1) Zap/45-1 101@external:1 Up Dial(Zap/G1/101) Zap/14-1 s@isdn-external:1 Up Bridged Call(Zap/46-1) Zap/46-1 101@external:1 Up Dial(Zap/G1/101) Zap/15-1 s@isdn-external:1 Up Bridged Call(Zap/48-1) Zap/48-1 101@external:1 Up Dial(Zap/G1/101) Zap/17-1 s@isdn-external:1 Up Bridged Call(Zap/49-1) Zap/49-1 101@external:1 Up Dial(Zap/G1/101) Zap/18-1 s@isdn-external:1 Up Bridged Call(Zap/50-1) Zap/50-1 101@external:1 Up Dial(Zap/G1/101) Zap/19-1 s@isdn-external:1 Up Bridged Call(Zap/51-1) Zap/51-1 101@external:1 Up Dial(Zap/G1/101) Zap/20-1 s@isdn-external:1 Up Bridged Call(Zap/52-1) Zap/52-1 101@external:1 Up Dial(Zap/G1/101) Zap/21-1 s@isdn-external:1 Up Bridged Call(Zap/53-1) Zap/53-1 101@external:1 Up Dial(Zap/G1/101) Zap/22-1 s@isdn-external:1 Up Bridged Call(Zap/54-1) Zap/54-1 101@external:1 Up Dial(Zap/G1/101) Zap/23-1 s@isdn-external:1 Up Bridged Call(Zap/55-1) Zap/55-1 101@external:1 Up Dial(Zap/G1/101) Zap/24-1 s@isdn-external:1 Up Bridged Call(Zap/56-1) Zap/56-1 101@external:1 Up Dial(Zap/G1/101) Zap/25-1 s@isdn-external:1 Up Bridged Call(Zap/57-1) Zap/57-1 101@external:1 Up Dial(Zap/G1/101) Zap/26-1 s@isdn-external:1 Up Bridged Call(Zap/58-1) Zap/58-1 101@external:1 Up Dial(Zap/G1/101) Zap/27-1 s@isdn-external:1 Up Bridged Call(Zap/59-1) Zap/59-1 101@external:1 Up Dial(Zap/G1/101) Zap/28-1 s@isdn-external:1 Up Bridged Call(Zap/60-1) Zap/60-1 101@external:1 Up Dial(Zap/G1/101) Zap/29-1 s@isdn-external:1 Up Bridged Call(Zap/61-1) Zap/61-1 101@external:1 Up Dial(Zap/G1/101) Zap/30-1 s@isdn-external:1 Up Bridged Call(Zap/62-1) Zap/62-1 101@external:1 Up Dial(Zap/G1/101) Zap/31-1 s@isdn-external:1 Up Bridged Call(SIP/aastra9112i-0 SIP/aastra9112i-0967 8101@trunk:4 Up Dial(Zap/G1/101||) 62 active channels 31 active calls Verbosity is at least 5 Core debug is at least 5 FULL log starts from the point where an additional call is attempted: Dec 7 11:21:36 VERBOSE[24590] logger.c: -- Remote UNIX connection Dec 7 11:21:39 DEBUG[29042] rtp.c: Got RTCP report of 84 bytes Dec 7 11:21:44 DEBUG[29042] rtp.c: Got RTCP report of 84 bytes Dec 7 11:21:49 DEBUG[29042] rtp.c: Got RTCP report of 84 bytes Dec 7 11:21:50 VERBOSE[24602] logger.c: <-- SIP read from 10.0.0.180:2051: INVITE sip:8101@pabx.phone.domain.co.uk;user=phone SIP/2.0 Via: SIP/2.0/UDP 10.0.0.180:2051;branch=z9hG4bK-hworggyllubd;rport From: "Fred" ;tag=el94ybkvs2 To: Call-ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 CSeq: 1 INVITE Max-Forwards: 70 Contact: ;flow-id=1 P-Key-Flags: keys="3" User-Agent: snom320/6.5 Accept: application/sdp Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO Allow-Events: talk, hold, refer Supported: timer, 100rel, replaces, callerid Session-Expires: 3600;refresher=uas Min-SE: 90 Content-Type: application/sdp Content-Length: 469 v=0 o=root 686454771 686454771 IN IP4 10.0.0.180 s=call c=IN IP4 10.0.0.180 t=0 0 m=audio 10244 RTP/AVP 8 0 9 2 3 18 4 101 a=crypto:1 AES_CM_128_HMAC_SHA1_32 inline:6m5Fw2wvUv2XzY7xuG9bE80fla6L5MWcNZqhJvdU a=rtpmap:8 pcma/8000 a=rtpmap:0 pcmu/8000 a=rtpmap:9 g722/8000 a=rtpmap:2 g726-32/8000 a=rtpmap:3 gsm/8000 a=rtpmap:18 g729/8000 a=rtpmap:4 g723/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=encryption:optional a=sendrecv Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Header 0: INVITE sip:8101@pabx.phone.domain.co.uk;user=phone SIP/2.0 (58) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.0.0.180:2051;branch=z9hG4bK-hworggyllubd;rport (66) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Header 2: From: "Fred" ;tag=el94ybkvs2 (65) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Header 3: To: (49) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Header 4: Call-ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 (55) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Header 5: CSeq: 1 INVITE (14) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Header 6: Max-Forwards: 70 (16) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Header 7: Contact: ;flow-id=1 (62) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Header 8: P-Key-Flags: keys="3" (21) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Header 9: User-Agent: snom320/6.5 (23) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Header 10: Accept: application/sdp (23) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Header 11: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO (88) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Header 12: Allow-Events: talk, hold, refer (31) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Header 13: Supported: timer, 100rel, replaces, callerid (44) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Header 14: Session-Expires: 3600;refresher=uas (35) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Header 15: Min-SE: 90 (10) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Header 16: Content-Type: application/sdp (29) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Header 17: Content-Length: 469 (19) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Header 18: (0) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Line: v=0 (3) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Line: o=root 686454771 686454771 IN IP4 10.0.0.180 (44) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Line: s=call (6) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Line: c=IN IP4 10.0.0.180 (19) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Line: t=0 0 (5) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Line: m=audio 10244 RTP/AVP 8 0 9 2 3 18 4 101 (40) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Line: a=crypto:1 AES_CM_128_HMAC_SHA1_32 inline:6m5Fw2wvUv2XzY7xuG9bE80fla6L5MWcNZqhJvdU (82) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Line: a=rtpmap:8 pcma/8000 (20) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Line: a=rtpmap:0 pcmu/8000 (20) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Line: a=rtpmap:9 g722/8000 (20) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Line: a=rtpmap:2 g726-32/8000 (23) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Line: a=rtpmap:3 gsm/8000 (19) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Line: a=rtpmap:18 g729/8000 (21) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Line: a=rtpmap:4 g723/8000 (20) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Line: a=fmtp:101 0-16 (15) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Line: a=ptime:20 (10) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Line: a=encryption:optional (21) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Line: a=sendrecv (10) Dec 7 11:21:50 VERBOSE[24602] logger.c: --- (18 headers 19 lines) --- Dec 7 11:21:50 DEBUG[24602] chan_sip.c: = No match Their Call ID: 6a71153e036b09046e9ca64a61011849@pabx.phone.domain.co.uk Their Tag eqlwqew927 Our tag: as0322301d Dec 7 11:21:50 DEBUG[24602] chan_sip.c: = No match Their Call ID: 15d997533ec94e9f429482a011c8ef6c@10.0.0.164 Their Tag 42ae28f5c76791f Our tag: as7589ef80 Dec 7 11:21:50 DEBUG[24602] chan_sip.c: = No match Their Call ID: 3c2670460000-lpy2xt32tfeh@snom360 Their Tag 4wwy321iy5 Our tag: as69a394fa Dec 7 11:21:50 DEBUG[24602] chan_sip.c: = No match Their Call ID: 3c267045f1b3-sak80y79r7c5@snom360 Their Tag ppd5l0oq1y Our tag: as04c69cf1 Dec 7 11:21:50 DEBUG[24602] chan_sip.c: = No match Their Call ID: 3c267045ef42-5gs86vvqefp9@snom360 Their Tag x75htg0g73 Our tag: as1544bbc4 Dec 7 11:21:50 DEBUG[24602] chan_sip.c: = No match Their Call ID: 3c267045f1b3-ylxnv9h7ug5g@snom360 Their Tag s8gp2oeqp2 Our tag: as7be4a1f2 Dec 7 11:21:50 DEBUG[24602] chan_sip.c: = No match Their Call ID: 3c267045f1b3-qkvxenpqcacl@snom360 Their Tag vwejnfwu8o Our tag: as79d223ce Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Allocating new SIP dialog for 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 - INVITE (With RTP) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Begin: parsing SIP "Supported: timer, 100rel, replaces, callerid" Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Found SIP option: -timer- Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Matched SIP option: timer Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Found SIP option: -100rel- Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Matched SIP option: 100rel Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Found SIP option: -replaces- Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Matched SIP option: replaces Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Found SIP option: -callerid- Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Found no match for SIP option: callerid (Please file bug report!) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: * SIP extension value: 7 for call 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Dec 7 11:21:50 VERBOSE[24602] logger.c: Using INVITE request as basis request - 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Dec 7 11:21:50 VERBOSE[24602] logger.c: Sending to 10.0.0.180 : 2051 (NAT) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Setting NAT on RTP to 0 Dec 7 11:21:50 VERBOSE[24602] logger.c: Reliably Transmitting (no NAT) to 10.0.0.180:2051: SIP/2.0 407 Proxy Authentication Required Via: SIP/2.0/UDP 10.0.0.180:2051;branch=z9hG4bK-hworggyllubd;rport;received=10.0.0.180 From: "Fred" ;tag=el94ybkvs2 To: ;tag=as46f34312 Call-ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 CSeq: 1 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Proxy-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="17a84aa4" Content-Length: 0 --- Dec 7 11:21:50 DEBUG[24602] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #147627 Dec 7 11:21:50 VERBOSE[24602] logger.c: Scheduling destruction of call '3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0' in 15000 ms Dec 7 11:21:50 VERBOSE[24602] logger.c: Found user 'snom320' Dec 7 11:21:50 VERBOSE[24602] logger.c: <-- SIP read from 10.0.0.180:2051: ACK sip:8101@pabx.phone.domain.co.uk;user=phone SIP/2.0 Via: SIP/2.0/UDP 10.0.0.180:2051;branch=z9hG4bK-hworggyllubd;rport From: "Fred" ;tag=el94ybkvs2 To: ;tag=as46f34312 Call-ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 CSeq: 1 ACK Max-Forwards: 70 Contact: ;flow-id=1 Content-Length: 0 Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Header 0: ACK sip:8101@pabx.phone.domain.co.uk;user=phone SIP/2.0 (55) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.0.0.180:2051;branch=z9hG4bK-hworggyllubd;rport (66) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Header 2: From: "Fred" ;tag=el94ybkvs2 (65) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Header 3: To: ;tag=as46f34312 (64) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Header 4: Call-ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 (55) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Header 5: CSeq: 1 ACK (11) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Header 6: Max-Forwards: 70 (16) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Header 7: Contact: ;flow-id=1 (62) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Header 8: Content-Length: 0 (17) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Header 9: (0) Dec 7 11:21:50 VERBOSE[24602] logger.c: --- (9 headers 0 lines) --- Dec 7 11:21:50 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as46f34312 Dec 7 11:21:50 DEBUG[24602] chan_sip.c: **** Received ACK (6) - Command in SIP ACK Dec 7 11:21:50 DEBUG[24602] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #147627 Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Stopping retransmission on '3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0' of Response 1: Match Found Dec 7 11:21:50 VERBOSE[24602] logger.c: <-- SIP read from 10.0.0.180:2051: INVITE sip:8101@pabx.phone.domain.co.uk;user=phone SIP/2.0 Via: SIP/2.0/UDP 10.0.0.180:2051;branch=z9hG4bK-jw5srtdih7n6;rport From: "Fred" ;tag=el94ybkvs2 To: Call-ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 CSeq: 2 INVITE Max-Forwards: 70 Contact: ;flow-id=1 P-Key-Flags: keys="3" User-Agent: snom320/6.5 Accept: application/sdp Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO Allow-Events: talk, hold, refer Supported: timer, 100rel, replaces, callerid Session-Expires: 3600;refresher=uas Min-SE: 90 Proxy-Authorization: Digest username="snom320",realm="asterisk",nonce="17a84aa4",uri="sip:8101@pabx.phone.domain.co.uk;user=phone",response="edf7f00c251c1c8bad3bdf67fd159b08",algorithm=md5 Content-Type: application/sdp Content-Length: 469 v=0 o=root 686454771 686454771 IN IP4 10.0.0.180 s=call c=IN IP4 10.0.0.180 t=0 0 m=audio 10244 RTP/AVP 8 0 9 2 3 18 4 101 a=crypto:1 AES_CM_128_HMAC_SHA1_32 inline:6m5Fw2wvUv2XzY7xuG9bE80fla6L5MWcNZqhJvdU a=rtpmap:8 pcma/8000 a=rtpmap:0 pcmu/8000 a=rtpmap:9 g722/8000 a=rtpmap:2 g726-32/8000 a=rtpmap:3 gsm/8000 a=rtpmap:18 g729/8000 a=rtpmap:4 g723/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=encryption:optional a=sendrecv Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Header 0: INVITE sip:8101@pabx.phone.domain.co.uk;user=phone SIP/2.0 (58) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.0.0.180:2051;branch=z9hG4bK-jw5srtdih7n6;rport (66) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Header 2: From: "Fred" ;tag=el94ybkvs2 (65) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Header 3: To: (49) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Header 4: Call-ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 (55) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Header 5: CSeq: 2 INVITE (14) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Header 6: Max-Forwards: 70 (16) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Header 7: Contact: ;flow-id=1 (62) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Header 8: P-Key-Flags: keys="3" (21) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Header 9: User-Agent: snom320/6.5 (23) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Header 10: Accept: application/sdp (23) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Header 11: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO (88) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Header 12: Allow-Events: talk, hold, refer (31) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Header 13: Supported: timer, 100rel, replaces, callerid (44) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Header 14: Session-Expires: 3600;refresher=uas (35) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Header 15: Min-SE: 90 (10) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Header 16: Proxy-Authorization: Digest username="snom320",realm="asterisk",nonce="17a84aa4",uri="sip:8101@pabx.phone.domain.co.uk;user=phone",response="edf7f00c251c1c8bad3bdf67fd159b08",algorithm=md5 (188) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Header 17: Content-Type: application/sdp (29) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Header 18: Content-Length: 469 (19) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Header 19: (0) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Line: v=0 (3) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Line: o=root 686454771 686454771 IN IP4 10.0.0.180 (44) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Line: s=call (6) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Line: c=IN IP4 10.0.0.180 (19) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Line: t=0 0 (5) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Line: m=audio 10244 RTP/AVP 8 0 9 2 3 18 4 101 (40) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Line: a=crypto:1 AES_CM_128_HMAC_SHA1_32 inline:6m5Fw2wvUv2XzY7xuG9bE80fla6L5MWcNZqhJvdU (82) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Line: a=rtpmap:8 pcma/8000 (20) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Line: a=rtpmap:0 pcmu/8000 (20) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Line: a=rtpmap:9 g722/8000 (20) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Line: a=rtpmap:2 g726-32/8000 (23) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Line: a=rtpmap:3 gsm/8000 (19) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Line: a=rtpmap:18 g729/8000 (21) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Line: a=rtpmap:4 g723/8000 (20) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Line: a=fmtp:101 0-16 (15) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Line: a=ptime:20 (10) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Line: a=encryption:optional (21) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Line: a=sendrecv (10) Dec 7 11:21:50 VERBOSE[24602] logger.c: --- (19 headers 19 lines) --- Dec 7 11:21:50 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as46f34312 Dec 7 11:21:50 DEBUG[24602] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE Dec 7 11:21:50 VERBOSE[24602] logger.c: Using INVITE request as basis request - 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Dec 7 11:21:50 VERBOSE[24602] logger.c: Sending to 10.0.0.180 : 2051 (NAT) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Setting NAT on RTP to 0 Dec 7 11:21:50 VERBOSE[24602] logger.c: Found user 'snom320' Dec 7 11:21:50 VERBOSE[24602] logger.c: Found RTP audio format 8 Dec 7 11:21:50 VERBOSE[24602] logger.c: Found RTP audio format 0 Dec 7 11:21:50 VERBOSE[24602] logger.c: Found RTP audio format 9 Dec 7 11:21:50 VERBOSE[24602] logger.c: Found RTP audio format 2 Dec 7 11:21:50 VERBOSE[24602] logger.c: Found RTP audio format 3 Dec 7 11:21:50 VERBOSE[24602] logger.c: Found RTP audio format 18 Dec 7 11:21:50 VERBOSE[24602] logger.c: Found RTP audio format 4 Dec 7 11:21:50 VERBOSE[24602] logger.c: Found RTP audio format 101 Dec 7 11:21:50 VERBOSE[24602] logger.c: Peer audio RTP is at port 10.0.0.180:10244 Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Peer audio RTP is at port 10.0.0.180:10244 Dec 7 11:21:50 VERBOSE[24602] logger.c: Found description format pcma Dec 7 11:21:50 VERBOSE[24602] logger.c: Found description format pcmu Dec 7 11:21:50 VERBOSE[24602] logger.c: Found description format g722 Dec 7 11:21:50 VERBOSE[24602] logger.c: Found description format g726-32 Dec 7 11:21:50 VERBOSE[24602] logger.c: Found description format gsm Dec 7 11:21:50 VERBOSE[24602] logger.c: Found description format g729 Dec 7 11:21:50 VERBOSE[24602] logger.c: Found description format g723 Dec 7 11:21:50 VERBOSE[24602] logger.c: Found description format telephone-event Dec 7 11:21:50 VERBOSE[24602] logger.c: Capabilities: us - 0x8 (alaw), peer - audio=0x11f (g723|gsm|ulaw|alaw|g726|g729)/video=0x0 (nothing), combined - 0x8 (alaw) Dec 7 11:21:50 VERBOSE[24602] logger.c: Non-codec capabilities: us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Checking SIP call limits for device snom320 Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Updating call counter for incoming call Dec 7 11:21:50 VERBOSE[24602] logger.c: Looking for 8101 in local (domain pabx.phone.domain.co.uk;user=phone) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: build_route: Contact hop: ;flow-id=1 Dec 7 11:21:50 VERBOSE[24602] logger.c: list_route: hop: Dec 7 11:21:50 VERBOSE[24602] logger.c: Transmitting (no NAT) to 10.0.0.180:2051: SIP/2.0 100 Trying Via: SIP/2.0/UDP 10.0.0.180:2051;branch=z9hG4bK-jw5srtdih7n6;rport;received=10.0.0.180 From: "Fred" ;tag=el94ybkvs2 To: Call-ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 CSeq: 2 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Length: 0 --- Dec 7 11:21:50 DEBUG[24592] chan_sip.c: Checking device state for peer snom320 Dec 7 11:21:50 DEBUG[24592] devicestate.c: Changing state for SIP/snom320 - state 2 (In use) Dec 7 11:21:50 DEBUG[29289] pbx.c: Launching 'Macro' Dec 7 11:21:50 VERBOSE[29289] logger.c: -- Executing Macro("SIP/snom320-095985d0", "rec-set-caller") in new stack Dec 7 11:21:50 DEBUG[29289] pbx.c: Expression result is '0' Dec 7 11:21:50 DEBUG[29289] pbx.c: Launching 'GotoIf' Dec 7 11:21:50 VERBOSE[29289] logger.c: -- Executing GotoIf("SIP/snom320-095985d0", "0?xit|1") in new stack Dec 7 11:21:50 DEBUG[29289] pbx.c: Not taking any branch Dec 7 11:21:50 DEBUG[29289] pbx.c: Launching 'Goto' Dec 7 11:21:50 VERBOSE[29289] logger.c: -- Executing Goto("SIP/snom320-095985d0", "s-|1") in new stack Dec 7 11:21:50 VERBOSE[29289] logger.c: -- Goto (macro-rec-set-caller,s-,1) Dec 7 11:21:50 DEBUG[29289] pbx.c: Launching 'Set' Dec 7 11:21:50 VERBOSE[29289] logger.c: -- Executing Set("SIP/snom320-095985d0", "__DIALPARMS=W") in new stack Dec 7 11:21:50 DEBUG[29289] pbx.c: Launching 'Macro' Dec 7 11:21:50 VERBOSE[29289] logger.c: -- Executing Macro("SIP/snom320-095985d0", "rec-clr-callee") in new stack Dec 7 11:21:50 DEBUG[29289] pbx.c: Expression result is '0' Dec 7 11:21:50 DEBUG[29289] pbx.c: Launching 'GotoIf' Dec 7 11:21:50 VERBOSE[29289] logger.c: -- Executing GotoIf("SIP/snom320-095985d0", "0?xit|1") in new stack Dec 7 11:21:50 DEBUG[29289] pbx.c: Not taking any branch Dec 7 11:21:50 DEBUG[29289] pbx.c: Launching 'Goto' Dec 7 11:21:50 VERBOSE[29289] logger.c: -- Executing Goto("SIP/snom320-095985d0", "s-W|1") in new stack Dec 7 11:21:50 VERBOSE[29289] logger.c: -- Goto (macro-rec-clr-callee,s-W,1) Dec 7 11:21:50 DEBUG[29289] pbx.c: Function result is '104' Dec 7 11:21:50 DEBUG[29289] pbx.c: Function result is '104' Dec 7 11:21:50 DEBUG[29289] pbx.c: Launching 'Macro' Dec 7 11:21:50 VERBOSE[29289] logger.c: -- Executing Macro("SIP/snom320-095985d0", "rec-start-ifwanted|104|external|104|8101") in new stack Dec 7 11:21:50 DEBUG[29289] pbx.c: Launching 'NoOp' Dec 7 11:21:50 VERBOSE[29289] logger.c: -- Executing NoOp("SIP/snom320-095985d0", "rec-start-ifwanted|104|external") in new stack Dec 7 11:21:50 DEBUG[29289] pbx.c: Launching 'Gosub' Dec 7 11:21:50 VERBOSE[29289] logger.c: -- Executing Gosub("SIP/snom320-095985d0", "s-s104|1") in new stack Dec 7 11:21:50 DEBUG[29289] pbx.c: Launching 'Goto' Dec 7 11:21:50 VERBOSE[29289] logger.c: -- Executing Goto("SIP/snom320-095985d0", "s-sco-default|1") in new stack Dec 7 11:21:50 VERBOSE[29289] logger.c: -- Goto (macro-rec-start-ifwanted,s-sco-default,1) Dec 7 11:21:50 DEBUG[29289] pbx.c: Launching 'NoOp' Dec 7 11:21:50 VERBOSE[29289] logger.c: -- Executing NoOp("SIP/snom320-095985d0", "") in new stack Dec 7 11:21:50 DEBUG[29289] pbx.c: Launching 'Macro' Dec 7 11:21:50 VERBOSE[29289] logger.c: -- Executing Macro("SIP/snom320-095985d0", "rec-clr-caller") in new stack Dec 7 11:21:50 DEBUG[29289] pbx.c: Expression result is '0' Dec 7 11:21:50 DEBUG[29289] pbx.c: Launching 'GotoIf' Dec 7 11:21:50 VERBOSE[29289] logger.c: -- Executing GotoIf("SIP/snom320-095985d0", "0?xit|1") in new stack Dec 7 11:21:50 DEBUG[29289] pbx.c: Not taking any branch Dec 7 11:21:50 DEBUG[29289] pbx.c: Launching 'Goto' Dec 7 11:21:50 VERBOSE[29289] logger.c: -- Executing Goto("SIP/snom320-095985d0", "s-W|1") in new stack Dec 7 11:21:50 VERBOSE[29289] logger.c: -- Goto (macro-rec-clr-caller,s-W,1) Dec 7 11:21:50 DEBUG[29289] pbx.c: Launching 'Set' Dec 7 11:21:50 VERBOSE[29289] logger.c: -- Executing Set("SIP/snom320-095985d0", "__DIALPARMS=") in new stack Dec 7 11:21:50 DEBUG[29289] pbx.c: Launching 'Return' Dec 7 11:21:50 VERBOSE[29289] logger.c: -- Executing Return("SIP/snom320-095985d0", "") in new stack Dec 7 11:21:50 DEBUG[29289] pbx.c: Launching 'Gosub' Dec 7 11:21:50 VERBOSE[29289] logger.c: -- Executing Gosub("SIP/snom320-095985d0", "s-dexternal|1") in new stack Dec 7 11:21:50 DEBUG[29289] pbx.c: Launching 'Return' Dec 7 11:21:50 VERBOSE[29289] logger.c: -- Executing Return("SIP/snom320-095985d0", "") in new stack Dec 7 11:21:50 DEBUG[29289] pbx.c: Expression result is '1' Dec 7 11:21:50 DEBUG[29289] pbx.c: Launching 'GotoIf' Dec 7 11:21:50 VERBOSE[29289] logger.c: -- Executing GotoIf("SIP/snom320-095985d0", "1?s-step1|1") in new stack Dec 7 11:21:50 VERBOSE[29289] logger.c: -- Goto (macro-rec-start-ifwanted,s-step1,1) Dec 7 11:21:50 DEBUG[29289] pbx.c: Expression result is '0' Dec 7 11:21:50 DEBUG[29289] pbx.c: Launching 'GotoIf' Dec 7 11:21:50 VERBOSE[29289] logger.c: -- Executing GotoIf("SIP/snom320-095985d0", "0?s-start|1") in new stack Dec 7 11:21:50 DEBUG[29289] pbx.c: Not taking any branch Dec 7 11:21:50 DEBUG[29289] pbx.c: Expression result is '0' Dec 7 11:21:50 DEBUG[29289] pbx.c: Launching 'GotoIf' Dec 7 11:21:50 VERBOSE[29289] logger.c: -- Executing GotoIf("SIP/snom320-095985d0", "0?s-start|1") in new stack Dec 7 11:21:50 DEBUG[29289] pbx.c: Not taking any branch Dec 7 11:21:50 DEBUG[29289] pbx.c: Expression result is '0' Dec 7 11:21:50 DEBUG[29289] pbx.c: Launching 'GotoIf' Dec 7 11:21:50 VERBOSE[29289] logger.c: -- Executing GotoIf("SIP/snom320-095985d0", "0?s-start|1") in new stack Dec 7 11:21:50 DEBUG[29289] pbx.c: Not taking any branch Dec 7 11:21:50 DEBUG[29289] pbx.c: Expression result is '0' Dec 7 11:21:50 DEBUG[29289] pbx.c: Launching 'GotoIf' Dec 7 11:21:50 VERBOSE[29289] logger.c: -- Executing GotoIf("SIP/snom320-095985d0", "0?s-start|1") in new stack Dec 7 11:21:50 DEBUG[29289] pbx.c: Not taking any branch Dec 7 11:21:50 DEBUG[29289] pbx.c: Launching 'Macro' Dec 7 11:21:50 VERBOSE[29289] logger.c: -- Executing Macro("SIP/snom320-095985d0", "normcid") in new stack Dec 7 11:21:50 DEBUG[29289] pbx.c: Function result is 'default' Dec 7 11:21:50 DEBUG[29289] pbx.c: Expression result is '0' Dec 7 11:21:50 DEBUG[29289] pbx.c: Launching 'GotoIf' Dec 7 11:21:50 VERBOSE[29289] logger.c: -- Executing GotoIf("SIP/snom320-095985d0", "0?:3") in new stack Dec 7 11:21:50 VERBOSE[29289] logger.c: -- Goto (macro-normcid,s,3) Dec 7 11:21:50 DEBUG[29289] pbx.c: Function result is '104' Dec 7 11:21:50 DEBUG[29289] pbx.c: Launching 'Set' Dec 7 11:21:50 VERBOSE[29289] logger.c: -- Executing Set("SIP/snom320-095985d0", "ORIG_CIDNUM=104") in new stack Dec 7 11:21:50 DEBUG[29289] pbx.c: Function result is '104' Dec 7 11:21:50 DEBUG[29289] pbx.c: Launching 'Goto' Dec 7 11:21:50 VERBOSE[29289] logger.c: -- Executing Goto("SIP/snom320-095985d0", "s-104|1") in new stack Dec 7 11:21:50 VERBOSE[29289] logger.c: -- Goto (macro-normcid,s-104,1) Dec 7 11:21:50 DEBUG[29289] pbx.c: Launching 'Macro' Dec 7 11:21:50 VERBOSE[29289] logger.c: -- Executing Macro("SIP/snom320-095985d0", "outbarred") in new stack Dec 7 11:21:50 DEBUG[29289] pbx.c: Launching 'Goto' Dec 7 11:21:50 VERBOSE[29289] logger.c: -- Executing Goto("SIP/snom320-095985d0", "s-8101|1") in new stack Dec 7 11:21:50 VERBOSE[29289] logger.c: -- Goto (macro-outbarred,s-8101,1) Dec 7 11:21:50 DEBUG[29289] pbx.c: Launching 'Macro' Dec 7 11:21:50 VERBOSE[29289] logger.c: -- Executing Macro("SIP/snom320-095985d0", "set_forms|8101") in new stack Dec 7 11:21:50 DEBUG[29289] pbx.c: Expression result is '0' Dec 7 11:21:50 DEBUG[29289] pbx.c: Launching 'GotoIf' Dec 7 11:21:50 VERBOSE[29289] logger.c: -- Executing GotoIf("SIP/snom320-095985d0", "0?00|1") in new stack Dec 7 11:21:50 DEBUG[29289] pbx.c: Not taking any branch Dec 7 11:21:50 DEBUG[29289] pbx.c: Expression result is '0' Dec 7 11:21:50 DEBUG[29289] pbx.c: Launching 'GotoIf' Dec 7 11:21:50 VERBOSE[29289] logger.c: -- Executing GotoIf("SIP/snom320-095985d0", "0?0|1") in new stack Dec 7 11:21:50 DEBUG[29289] pbx.c: Not taking any branch Dec 7 11:21:50 DEBUG[29289] pbx.c: Launching 'Set' Dec 7 11:21:50 VERBOSE[29289] logger.c: -- Executing Set("SIP/snom320-095985d0", "EXTEN00=004419088101") in new stack Dec 7 11:21:50 DEBUG[29289] pbx.c: Launching 'Set' Dec 7 11:21:50 VERBOSE[29289] logger.c: -- Executing Set("SIP/snom320-095985d0", "EXTEN44=4419088101") in new stack Dec 7 11:21:50 DEBUG[29289] pbx.c: Launching 'Set' Dec 7 11:21:50 VERBOSE[29289] logger.c: -- Executing Set("SIP/snom320-095985d0", "EXTEN0=019088101") in new stack Dec 7 11:21:50 DEBUG[29289] pbx.c: Function result is '104' Dec 7 11:21:50 DEBUG[29289] pbx.c: Launching 'Set' Dec 7 11:21:50 VERBOSE[29289] logger.c: -- Executing Set("SIP/snom320-095985d0", "SAVE_CIDNUM=104") in new stack Dec 7 11:21:50 DEBUG[29289] pbx.c: Launching 'Goto' Dec 7 11:21:50 VERBOSE[29289] logger.c: -- Executing Goto("SIP/snom320-095985d0", "trunk|8101|1") in new stack Dec 7 11:21:50 VERBOSE[29289] logger.c: -- Goto (trunk,8101,1) Dec 7 11:21:50 DEBUG[29289] pbx.c: Launching 'Macro' Dec 7 11:21:50 VERBOSE[29289] logger.c: -- Executing Macro("SIP/snom320-095985d0", "set_forms|101|8") in new stack Dec 7 11:21:50 DEBUG[29289] pbx.c: Expression result is '0' Dec 7 11:21:50 DEBUG[29289] pbx.c: Launching 'GotoIf' Dec 7 11:21:50 VERBOSE[29289] logger.c: -- Executing GotoIf("SIP/snom320-095985d0", "0?00|1") in new stack Dec 7 11:21:50 DEBUG[29289] pbx.c: Not taking any branch Dec 7 11:21:50 DEBUG[29289] pbx.c: Expression result is '0' Dec 7 11:21:50 DEBUG[29289] pbx.c: Launching 'GotoIf' Dec 7 11:21:50 VERBOSE[29289] logger.c: -- Executing GotoIf("SIP/snom320-095985d0", "0?0|1") in new stack Dec 7 11:21:50 DEBUG[29289] pbx.c: Not taking any branch Dec 7 11:21:50 DEBUG[29289] pbx.c: Launching 'Set' Dec 7 11:21:50 VERBOSE[29289] logger.c: -- Executing Set("SIP/snom320-095985d0", "EXTEN00=800441908101") in new stack Dec 7 11:21:50 DEBUG[29289] pbx.c: Launching 'Set' Dec 7 11:21:50 VERBOSE[29289] logger.c: -- Executing Set("SIP/snom320-095985d0", "EXTEN44=8441908101") in new stack Dec 7 11:21:50 DEBUG[29289] pbx.c: Launching 'Set' Dec 7 11:21:50 VERBOSE[29289] logger.c: -- Executing Set("SIP/snom320-095985d0", "EXTEN0=801908101") in new stack Dec 7 11:21:50 DEBUG[29289] pbx.c: Launching 'Set' Dec 7 11:21:50 VERBOSE[29289] logger.c: -- Executing Set("SIP/snom320-095985d0", "GROUP()=LOCALPSTN") in new stack Dec 7 11:21:50 DEBUG[29289] pbx.c: Function result is 'default' Dec 7 11:21:50 DEBUG[29289] pbx.c: Function result is 'Fred' Dec 7 11:21:50 DEBUG[29289] pbx.c: Function result is '104' Dec 7 11:21:50 DEBUG[29289] pbx.c: Launching 'Set' Dec 7 11:21:50 VERBOSE[29289] logger.c: -- Executing Set("SIP/snom320-095985d0", "CDR(userfield)=co=default^us=Fred^ex=104^dn=441908101^sn=101^ch=ISDN^bt=") in new stack Dec 7 11:21:50 DEBUG[29289] pbx.c: Launching 'Dial' Dec 7 11:21:50 VERBOSE[29289] logger.c: -- Executing Dial("SIP/snom320-095985d0", "Zap/G1/101||") in new stack Dec 7 11:21:50 NOTICE[29289] app_dial.c: Unable to create channel of type 'Zap' (cause 34 - Circuit/channel congestion) Dec 7 11:21:50 VERBOSE[29289] logger.c: == Everyone is busy/congested at this time (1:0/1/0) Dec 7 11:21:50 DEBUG[29289] app_dial.c: Exiting with DIALSTATUS=CONGESTION. Dec 7 11:21:50 DEBUG[29289] pbx.c: Launching 'Goto' Dec 7 11:21:50 VERBOSE[29289] logger.c: -- Executing Goto("SIP/snom320-095985d0", "5") in new stack Dec 7 11:21:50 VERBOSE[29289] logger.c: -- Goto (trunk,8101,5) Dec 7 11:21:50 DEBUG[29289] pbx.c: Launching 'Busy' Dec 7 11:21:50 VERBOSE[29289] logger.c: -- Executing Busy("SIP/snom320-095985d0", "") in new stack Dec 7 11:21:50 VERBOSE[29289] logger.c: Transmitting (no NAT) to 10.0.0.180:2051: SIP/2.0 486 Busy Here Via: SIP/2.0/UDP 10.0.0.180:2051;branch=z9hG4bK-jw5srtdih7n6;rport;received=10.0.0.180 From: "Fred" ;tag=el94ybkvs2 To: ;tag=as4c9c4c7b Call-ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 CSeq: 2 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Content-Length: 0 X-Asterisk-HangupCause: Circuit/channel congestion --- Dec 7 11:21:50 DEBUG[29289] channel.c: Soft-Hanging up channel 'SIP/snom320-095985d0' Dec 7 11:21:50 DEBUG[29289] pbx.c: Spawn extension (trunk,8101,5) exited non-zero on 'SIP/snom320-095985d0' Dec 7 11:21:50 VERBOSE[29289] logger.c: == Spawn extension (trunk, 8101, 5) exited non-zero on 'SIP/snom320-095985d0' Dec 7 11:21:50 DEBUG[29289] pbx.c: Function result is '"Fred" <104>' Dec 7 11:21:50 DEBUG[29289] pbx.c: Function result is '104' Dec 7 11:21:50 DEBUG[29289] pbx.c: Function result is '8101' Dec 7 11:21:50 DEBUG[29289] pbx.c: Function result is 'trunk' Dec 7 11:21:50 DEBUG[29289] pbx.c: Function result is 'SIP/snom320-095985d0' Dec 7 11:21:50 DEBUG[29289] pbx.c: Function result is '(null)' Dec 7 11:21:50 DEBUG[29289] pbx.c: Function result is 'Busy' Dec 7 11:21:50 DEBUG[29289] pbx.c: Function result is '(null)' Dec 7 11:21:50 DEBUG[29289] pbx.c: Function result is '2006-12-07 11:21:50' Dec 7 11:21:50 DEBUG[29289] pbx.c: Function result is '(null)' Dec 7 11:21:50 DEBUG[29289] pbx.c: Function result is '2006-12-07 11:21:50' Dec 7 11:21:50 DEBUG[29289] pbx.c: Function result is '0' Dec 7 11:21:50 DEBUG[29289] pbx.c: Function result is '0' Dec 7 11:21:50 DEBUG[29289] pbx.c: Function result is 'FAILED' Dec 7 11:21:50 DEBUG[29289] pbx.c: Function result is 'DOCUMENTATION' Dec 7 11:21:50 DEBUG[29289] pbx.c: Function result is 'default' Dec 7 11:21:50 DEBUG[29289] pbx.c: Function result is 'dilbert.bp.ipcortex.-24587-1165' Dec 7 11:21:50 DEBUG[29289] pbx.c: Function result is 'co=default^us=Fred^ex=104^dn=441908101^sn=101^ch=ISDN^bt=' Dec 7 11:21:50 DEBUG[29289] cdr_pgsql.c: cdr_pgsql: inserting a CDR record. Dec 7 11:21:50 DEBUG[29289] cdr_pgsql.c: cdr_pgsql: SQL command executed: INSERT INTO cdr (calldate,clid,src,dst,dcontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,accountcode,uniqueid,userfield) VALUES ('2006-12-07 11:21:50','"Fred" <104>','104','8101','trunk', 'SIP/snom320-095985d0','','Busy','',0,0,'FAILED',3,'default','dilbert.bp.ipcortex.-24587-1165','co=default^us=Fred^ex=104^dn=441908101^sn=101^ch=ISDN^bt=') Dec 7 11:21:50 DEBUG[29290] app_queue.c: Device 'SIP/snom320' changed to state '2' (In use) but we don't care because they're not a member of any queue. Dec 7 11:21:50 DEBUG[24592] chan_sip.c: Checking device state for peer snom320 Dec 7 11:21:50 DEBUG[24592] channel.c: Avoiding initial deadlock for 'SIP/snom320-095985d0' Dec 7 11:21:50 DEBUG[24592] channel.c: Avoiding initial deadlock for 'SIP/snom320-095985d0' Dec 7 11:21:50 DEBUG[24592] channel.c: Avoiding initial deadlock for 'SIP/snom320-095985d0' Dec 7 11:21:50 DEBUG[24592] channel.c: Avoiding initial deadlock for 'SIP/snom320-095985d0' Dec 7 11:21:50 DEBUG[24592] channel.c: Avoiding initial deadlock for 'SIP/snom320-095985d0' Dec 7 11:21:50 DEBUG[24592] channel.c: Avoiding initial deadlock for 'SIP/snom320-095985d0' Dec 7 11:21:50 DEBUG[24592] channel.c: Avoiding initial deadlock for 'SIP/snom320-095985d0' Dec 7 11:21:50 DEBUG[24592] channel.c: Avoiding initial deadlock for 'SIP/snom320-095985d0' Dec 7 11:21:50 DEBUG[24592] channel.c: Avoiding initial deadlock for 'SIP/snom320-095985d0' Dec 7 11:21:50 DEBUG[24592] channel.c: Avoiding initial deadlock for 'SIP/snom320-095985d0' Dec 7 11:21:50 WARNING[24592] channel.c: Avoided initial deadlock for '0x959b8e8', 10 retries! Dec 7 11:21:50 DEBUG[24592] devicestate.c: Changing state for SIP/snom320 - state 1 (Not in use) Dec 7 11:21:50 DEBUG[29291] app_queue.c: Device 'SIP/snom320' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. Dec 7 11:21:50 VERBOSE[24602] logger.c: <-- SIP read from 10.0.0.180:2051: ACK sip:8101@pabx.phone.domain.co.uk;user=phone SIP/2.0 Via: SIP/2.0/UDP 10.0.0.180:2051;branch=z9hG4bK-jw5srtdih7n6;rport From: "Fred" ;tag=el94ybkvs2 To: ;tag=as4c9c4c7b Call-ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 CSeq: 2 ACK Max-Forwards: 70 Contact: ;flow-id=1 Content-Length: 0 Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Header 0: ACK sip:8101@pabx.phone.domain.co.uk;user=phone SIP/2.0 (55) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.0.0.180:2051;branch=z9hG4bK-jw5srtdih7n6;rport (66) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Header 2: From: "Fred" ;tag=el94ybkvs2 (65) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Header 3: To: ;tag=as4c9c4c7b (64) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Header 4: Call-ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 (55) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Header 5: CSeq: 2 ACK (11) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Header 6: Max-Forwards: 70 (16) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Header 7: Contact: ;flow-id=1 (62) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Header 8: Content-Length: 0 (17) Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Header 9: (0) Dec 7 11:21:50 VERBOSE[24602] logger.c: --- (9 headers 0 lines) --- Dec 7 11:21:50 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:50 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:50 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:50 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:50 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:50 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:50 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:50 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:50 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:50 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:50 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:50 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:50 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:50 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:50 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:50 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:50 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:50 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:50 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:50 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:50 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:50 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:50 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:50 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:50 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:50 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:50 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:50 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:50 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:50 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:50 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:50 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:50 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:50 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:50 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:50 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:50 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:50 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:50 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:50 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:50 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:50 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:50 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:50 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:50 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:50 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:50 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:50 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:50 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:50 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:50 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:50 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:50 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:50 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:50 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:50 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:50 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:50 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:50 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:50 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:50 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:50 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:50 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:50 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:50 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:50 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:50 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:50 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:50 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:50 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:50 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:50 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:50 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:50 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:50 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:50 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:50 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:50 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:50 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:50 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:51 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:51 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:51 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:51 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:51 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:51 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:51 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:51 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:51 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:51 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:51 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:51 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:51 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:51 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:51 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:51 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:51 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:51 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:51 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:51 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:51 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:51 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:51 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:51 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:51 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:51 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:51 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:51 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:51 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:51 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:51 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:51 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:51 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:51 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:51 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:51 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:51 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:51 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:51 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:51 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:51 DEBUG[24602] chan_sip.c: = Found Their Call ID: 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0 Their Tag el94ybkvs2 Our tag: as4c9c4c7b Dec 7 11:21:51 DEBUG[24602] chan_sip.c: Failed to grab lock, trying again... Dec 7 11:21:51 ERROR[24602] chan_sip.c: We could NOT get the channel lock for SIP/snom320-095985d0! Dec 7 11:21:51 ERROR[24602] chan_sip.c: SIP MESSAGE JUST IGNORED: ACK Dec 7 11:21:51 ERROR[24602] chan_sip.c: BAD! BAD! BAD! Dec 7 11:21:51 DEBUG[29289] channel.c: Hanging up channel 'SIP/snom320-095985d0' Dec 7 11:21:51 DEBUG[29289] chan_sip.c: Hangup call SIP/snom320-095985d0, SIP callid 3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0) Dec 7 11:21:51 DEBUG[29289] chan_sip.c: update_call_counter(snom320) - decrement call limit counter Dec 7 11:21:51 DEBUG[29289] chan_sip.c: Updating call counter for incoming call Dec 7 11:21:51 DEBUG[24592] chan_sip.c: Checking device state for peer snom320 Dec 7 11:21:51 DEBUG[24592] devicestate.c: Changing state for SIP/snom320 - state 1 (Not in use) Dec 7 11:21:51 DEBUG[29292] app_queue.c: Device 'SIP/snom320' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. Dec 7 11:21:52 VERBOSE[24602] logger.c: Destroying call '3c5dd5029eb1-ojqusew6m2ij@snom320-000413243DB0' Dec 7 11:21:54 DEBUG[29042] rtp.c: Got RTCP report of 84 bytes Dec 7 11:21:59 DEBUG[29042] rtp.c: Got RTCP report of 84 bytes Dec 7 11:22:04 DEBUG[29042] rtp.c: Got RTCP report of 84 bytes Dec 7 11:22:05 DEBUG[24627] manager.c: Manager received command 'Command' Dec 7 11:22:05 DEBUG[24627] manager.c: Manager received command 'Command' Dec 7 11:22:05 DEBUG[24627] manager.c: Manager received command 'Command' Dec 7 11:22:07 DEBUG[24602] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP) Dec 7 11:22:07 DEBUG[24602] chan_sip.c: Header 0: OPTIONS sip:aastra9133i@10.0.0.165 SIP/2.0 (42) Dec 7 11:22:07 DEBUG[24602] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.0.0.1:5060;branch=z9hG4bK1786ccd6;rport (59) Dec 7 11:22:07 DEBUG[24602] chan_sip.c: Header 2: From: "asterisk" ;tag=as05973707 (70) Dec 7 11:22:07 DEBUG[24602] chan_sip.c: Header 3: To: (32) Dec 7 11:22:07 DEBUG[24602] chan_sip.c: Header 4: Contact: (32) Dec 7 11:22:07 DEBUG[24602] chan_sip.c: Header 5: Call-ID: 554d1c45717806332bfbd423562a59f8@pabx.phone.domain.co.uk (65) Dec 7 11:22:07 DEBUG[24602] chan_sip.c: Header 6: CSeq: 102 OPTIONS (17) Dec 7 11:22:07 DEBUG[24602] chan_sip.c: Header 7: User-Agent: Asterisk PBX (24) Dec 7 11:22:07 DEBUG[24602] chan_sip.c: Header 8: Max-Forwards: 70 (16) Dec 7 11:22:07 DEBUG[24602] chan_sip.c: Header 9: Date: Thu, 07 Dec 2006 11:22:07 GMT (35) Dec 7 11:22:07 DEBUG[24602] chan_sip.c: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) Dec 7 11:22:07 DEBUG[24602] chan_sip.c: Header 11: Content-Length: 0 (17) Dec 7 11:22:07 DEBUG[24602] chan_sip.c: Header 12: (0) Dec 7 11:22:07 DEBUG[24602] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #147629 Dec 7 11:22:07 DEBUG[24602] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP) Dec 7 11:22:07 DEBUG[24602] chan_sip.c: Header 0: OPTIONS sip:aastra9133i_2@10.0.0.165 SIP/2.0 (44) Dec 7 11:22:07 DEBUG[24602] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.0.0.1:5060;branch=z9hG4bK3d686374;rport (59) Dec 7 11:22:07 DEBUG[24602] chan_sip.c: Header 2: From: "asterisk" ;tag=as10766ed0 (70) Dec 7 11:22:07 DEBUG[24602] chan_sip.c: Header 3: To: (34) Dec 7 11:22:07 DEBUG[24602] chan_sip.c: Header 4: Contact: (32) Dec 7 11:22:07 DEBUG[24602] chan_sip.c: Header 5: Call-ID: 5eb1c69161d3f6ae05ffe01905913a7a@pabx.phone.domain.co.uk (65) Dec 7 11:22:07 DEBUG[24602] chan_sip.c: Header 6: CSeq: 102 OPTIONS (17) Dec 7 11:22:07 DEBUG[24602] chan_sip.c: Header 7: User-Agent: Asterisk PBX (24) Dec 7 11:22:07 DEBUG[24602] chan_sip.c: Header 8: Max-Forwards: 70 (16) Dec 7 11:22:07 DEBUG[24602] chan_sip.c: Header 9: Date: Thu, 07 Dec 2006 11:22:07 GMT (35) Dec 7 11:22:07 DEBUG[24602] chan_sip.c: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) Dec 7 11:22:07 DEBUG[24602] chan_sip.c: Header 11: Content-Length: 0 (17) Dec 7 11:22:07 DEBUG[24602] chan_sip.c: Header 12: (0) Dec 7 11:22:07 DEBUG[24602] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #147631 Dec 7 11:22:07 DEBUG[24602] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP) Dec 7 11:22:07 DEBUG[24602] chan_sip.c: Header 0: OPTIONS sip:aastra9133i_3@10.0.0.165 SIP/2.0 (44) Dec 7 11:22:07 DEBUG[24602] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.0.0.1:5060;branch=z9hG4bK112f2bb5;rport (59) Dec 7 11:22:07 DEBUG[24602] chan_sip.c: Header 2: From: "asterisk" ;tag=as6d0069c0 (70) Dec 7 11:22:07 DEBUG[24602] chan_sip.c: Header 3: To: (34) Dec 7 11:22:07 DEBUG[24602] chan_sip.c: Header 4: Contact: (32) Dec 7 11:22:07 DEBUG[24602] chan_sip.c: Header 5: Call-ID: 794dd35e5a4eeba7162582be6a929adf@pabx.phone.domain.co.uk (65) Dec 7 11:22:07 DEBUG[24602] chan_sip.c: Header 6: CSeq: 102 OPTIONS (17) Dec 7 11:22:07 DEBUG[24602] chan_sip.c: Header 7: User-Agent: Asterisk PBX (24) Dec 7 11:22:07 DEBUG[24602] chan_sip.c: Header 8: Max-Forwards: 70 (16) Dec 7 11:22:07 DEBUG[24602] chan_sip.c: Header 9: Date: Thu, 07 Dec 2006 11:22:07 GMT (35) Dec 7 11:22:07 DEBUG[24602] chan_sip.c: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) Dec 7 11:22:07 DEBUG[24602] chan_sip.c: Header 11: Content-Length: 0 (17) Dec 7 11:22:07 DEBUG[24602] chan_sip.c: Header 12: (0) Dec 7 11:22:07 DEBUG[24602] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #147633 Dec 7 11:22:08 DEBUG[24602] chan_sip.c: Header 0: SIP/2.0 200 OK (14) Dec 7 11:22:08 DEBUG[24602] chan_sip.c: Header 1: Call-ID: 554d1c45717806332bfbd423562a59f8@pabx.phone.domain.co.uk (65) Dec 7 11:22:08 DEBUG[24602] chan_sip.c: Header 2: CSeq: 102 OPTIONS (17) Dec 7 11:22:08 DEBUG[24602] chan_sip.c: Header 3: From: "asterisk" ;tag=as05973707 (70) Dec 7 11:22:08 DEBUG[24602] chan_sip.c: Header 4: To: ;tag=78545c32ba883af (52) Dec 7 11:22:08 DEBUG[24602] chan_sip.c: Header 5: Via: SIP/2.0/UDP 10.0.0.1:5060;branch=z9hG4bK1786ccd6;rport (59) Dec 7 11:22:08 DEBUG[24602] chan_sip.c: Header 6: Content-Length: 0 (17) Dec 7 11:22:08 DEBUG[24602] chan_sip.c: Header 7: Allow:NOTIFY,REFER,OPTIONS,INVITE,ACK,CANCEL,BYE,INFO (53) Dec 7 11:22:08 DEBUG[24602] chan_sip.c: Header 8: Contact: (37) Dec 7 11:22:08 DEBUG[24602] chan_sip.c: Header 9: Supported: replaces (19) Dec 7 11:22:08 DEBUG[24602] chan_sip.c: Header 10: User-Agent: Aastra 9133i/1.4.1.1068 Brcm Callctrl/1.5.1.0 MxSF/v3.2.6.26 (72) Dec 7 11:22:08 DEBUG[24602] chan_sip.c: Header 11: (0) Dec 7 11:22:08 DEBUG[24602] chan_sip.c: = No match Their Call ID: 794dd35e5a4eeba7162582be6a929adf@pabx.phone.domain.co.uk Their Tag Our tag: as6d0069c0 Dec 7 11:22:08 DEBUG[24602] chan_sip.c: = No match Their Call ID: 5eb1c69161d3f6ae05ffe01905913a7a@pabx.phone.domain.co.uk Their Tag Our tag: as10766ed0 Dec 7 11:22:08 DEBUG[24602] chan_sip.c: = Found Their Call ID: 554d1c45717806332bfbd423562a59f8@pabx.phone.domain.co.uk Their Tag Our tag: as05973707 Dec 7 11:22:08 DEBUG[24602] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #147629 Dec 7 11:22:08 DEBUG[24602] chan_sip.c: Stopping retransmission on '554d1c45717806332bfbd423562a59f8@pabx.phone.domain.co.uk' of Request 102: Match Found Dec 7 11:22:08 DEBUG[24602] chan_sip.c: Header 0: SIP/2.0 200 OK (14) Dec 7 11:22:08 DEBUG[24602] chan_sip.c: Header 1: Call-ID: 5eb1c69161d3f6ae05ffe01905913a7a@pabx.phone.domain.co.uk (65) Dec 7 11:22:08 DEBUG[24602] chan_sip.c: Header 2: CSeq: 102 OPTIONS (17) Dec 7 11:22:08 DEBUG[24602] chan_sip.c: Header 3: From: "asterisk" ;tag=as10766ed0 (70) Dec 7 11:22:08 DEBUG[24602] chan_sip.c: Header 4: To: ;tag=dded1c82ad57ccd (54) Dec 7 11:22:08 DEBUG[24602] chan_sip.c: Header 5: Via: SIP/2.0/UDP 10.0.0.1:5060;branch=z9hG4bK3d686374;rport (59) Dec 7 11:22:08 DEBUG[24602] chan_sip.c: Header 6: Content-Length: 0 (17) Dec 7 11:22:08 DEBUG[24602] chan_sip.c: Header 7: Allow:NOTIFY,REFER,OPTIONS,INVITE,ACK,CANCEL,BYE,INFO (53) Dec 7 11:22:08 DEBUG[24602] chan_sip.c: Header 8: Contact: (39) Dec 7 11:22:08 DEBUG[24602] chan_sip.c: Header 9: Supported: replaces (19) Dec 7 11:22:08 DEBUG[24602] chan_sip.c: Header 10: User-Agent: Aastra 9133i/1.4.1.1068 Brcm Callctrl/1.5.1.0 MxSF/v3.2.6.26 (72) Dec 7 11:22:08 DEBUG[24602] chan_sip.c: Header 11: (0) Dec 7 11:22:08 DEBUG[24602] chan_sip.c: = No match Their Call ID: 794dd35e5a4eeba7162582be6a929adf@pabx.phone.domain.co.uk Their Tag Our tag: as6d0069c0 Dec 7 11:22:08 DEBUG[24602] chan_sip.c: = Found Their Call ID: 5eb1c69161d3f6ae05ffe01905913a7a@pabx.phone.domain.co.uk Their Tag Our tag: as10766ed0 Dec 7 11:22:08 DEBUG[24602] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #147631 Dec 7 11:22:08 DEBUG[24602] chan_sip.c: Stopping retransmission on '5eb1c69161d3f6ae05ffe01905913a7a@pabx.phone.domain.co.uk' of Request 102: Match Found Dec 7 11:22:08 DEBUG[24602] chan_sip.c: Header 0: SIP/2.0 200 OK (14) Dec 7 11:22:08 DEBUG[24602] chan_sip.c: Header 1: Call-ID: 794dd35e5a4eeba7162582be6a929adf@pabx.phone.domain.co.uk (65) Dec 7 11:22:08 DEBUG[24602] chan_sip.c: Header 2: CSeq: 102 OPTIONS (17) Dec 7 11:22:08 DEBUG[24602] chan_sip.c: Header 3: From: "asterisk" ;tag=as6d0069c0 (70) Dec 7 11:22:08 DEBUG[24602] chan_sip.c: Header 4: To: ;tag=3ff117437f60fee (54) Dec 7 11:22:08 DEBUG[24602] chan_sip.c: Header 5: Via: SIP/2.0/UDP 10.0.0.1:5060;branch=z9hG4bK112f2bb5;rport (59) Dec 7 11:22:08 DEBUG[24602] chan_sip.c: Header 6: Content-Length: 0 (17) Dec 7 11:22:08 DEBUG[24602] chan_sip.c: Header 7: Allow:NOTIFY,REFER,OPTIONS,INVITE,ACK,CANCEL,BYE,INFO (53) Dec 7 11:22:08 DEBUG[24602] chan_sip.c: Header 8: Contact: (39) Dec 7 11:22:08 DEBUG[24602] chan_sip.c: Header 9: Supported: replaces (19) Dec 7 11:22:08 DEBUG[24602] chan_sip.c: Header 10: User-Agent: Aastra 9133i/1.4.1.1068 Brcm Callctrl/1.5.1.0 MxSF/v3.2.6.26 (72) Dec 7 11:22:08 DEBUG[24602] chan_sip.c: Header 11: (0) Dec 7 11:22:08 DEBUG[24602] chan_sip.c: = Found Their Call ID: 794dd35e5a4eeba7162582be6a929adf@pabx.phone.domain.co.uk Their Tag Our tag: as6d0069c0 Dec 7 11:22:08 DEBUG[24602] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #147633 Dec 7 11:22:08 DEBUG[24602] chan_sip.c: Stopping retransmission on '794dd35e5a4eeba7162582be6a929adf@pabx.phone.domain.co.uk' of Request 102: Match Found Dec 7 11:22:09 DEBUG[29042] rtp.c: Got RTCP report of 84 bytes Dec 7 11:22:13 VERBOSE[29288] logger.c: -- Remote UNIX connection disconnected Dec 7 11:22:14 DEBUG[29042] rtp.c: Got RTCP report of 84 bytes Dec 7 11:22:19 DEBUG[29042] rtp.c: Got RTCP report of 84 bytes