[Jul 15 13:27:21] VERBOSE[20197] logger.c: == Manager 'lmt' logged off from 127.0.0.1 [Jul 15 13:27:22] DEBUG[19834] chan_sip.c: Auto destroying SIP dialog '3c30a9d7329c-5c2mafwyaqxe' [Jul 15 13:27:22] DEBUG[19834] chan_sip.c: Destroying SIP dialog 3c30a9d7329c-5c2mafwyaqxe [Jul 15 13:27:22] VERBOSE[19834] logger.c: Really destroying SIP dialog '3c30a9d7329c-5c2mafwyaqxe' Method: REGISTER [Jul 15 13:27:27] VERBOSE[19834] logger.c: <--- SIP read from 192.168.161.4:5060 ---> INVITE sip:400@pbx.example.net;user=phone SIP/2.0 Via: SIP/2.0/UDP 192.168.161.4;branch=z9hG4bKac845322220 Max-Forwards: 70 From: "R&D 1" ;tag=1c845315586 To: Call-ID: 8453148291572008132727@192.168.161.4 CSeq: 1 INVITE Contact: Supported: em,100rel,timer,replaces,path,early-session,resource-priority Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE Remote-Party-ID: "R&D 1" ;party=calling;privacy=off;screen=yes;screen-ind=3;npi=9;ton=0 Remote-Party-ID: ;party=called;npi=0;ton=0 User-Agent: acM1000-01/v.5.20A.032.001 Content-Type: application/sdp Content-Disposition: session Content-Length: 314 v=0 o=acM1000-01 845302855 845302580 IN IP4 192.168.161.4 s=Phone-Call c=IN IP4 192.168.161.4 t=0 0 m=audio 10300 RTP/AVP 8 18 101 a=rtpmap:8 PCMA/8000 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:20 a=sendrecv a=rtcp:10301 IN IP4 192.168.161.4 <-------------> [Jul 15 13:27:27] DEBUG[19834] chan_sip.c: Header 0: INVITE sip:400@pbx.example.net;user=phone SIP/2.0 (49) [Jul 15 13:27:27] DEBUG[19834] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.161.4;branch=z9hG4bKac845322220 (56) [Jul 15 13:27:27] DEBUG[19834] chan_sip.c: Header 2: Max-Forwards: 70 (16) [Jul 15 13:27:27] DEBUG[19834] chan_sip.c: Header 3: From: "R&D 1" ;tag=1c845315586 (55) [Jul 15 13:27:27] DEBUG[19834] chan_sip.c: Header 4: To: (40) [Jul 15 13:27:27] DEBUG[19834] chan_sip.c: Header 5: Call-ID: 8453148291572008132727@192.168.161.4 (45) [Jul 15 13:27:27] DEBUG[19834] chan_sip.c: Header 6: CSeq: 1 INVITE (14) [Jul 15 13:27:27] DEBUG[19834] chan_sip.c: Header 7: Contact: (39) [Jul 15 13:27:27] DEBUG[19834] chan_sip.c: Header 8: Supported: em,100rel,timer,replaces,path,early-session,resource-priority (72) [Jul 15 13:27:27] DEBUG[19834] chan_sip.c: Header 9: Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE (86) [Jul 15 13:27:27] DEBUG[19834] chan_sip.c: Header 10: Remote-Party-ID: "R&D 1" ;party=calling;privacy=off;screen=yes;screen-ind=3;npi=9;ton=0 (112) [Jul 15 13:27:27] DEBUG[19834] chan_sip.c: Header 11: Remote-Party-ID: ;party=called;npi=0;ton=0 (67) [Jul 15 13:27:27] DEBUG[19834] chan_sip.c: Header 12: User-Agent: acM1000-01/v.5.20A.032.001 (38) [Jul 15 13:27:27] DEBUG[19834] chan_sip.c: Header 13: Content-Type: application/sdp (29) [Jul 15 13:27:27] DEBUG[19834] chan_sip.c: Header 14: Content-Disposition: session (28) [Jul 15 13:27:27] DEBUG[19834] chan_sip.c: Header 15: Content-Length: 314 (19) [Jul 15 13:27:27] DEBUG[19834] chan_sip.c: Header 16: (0) [Jul 15 13:27:27] DEBUG[19834] chan_sip.c: Line: v=0 (3) [Jul 15 13:27:27] DEBUG[19834] chan_sip.c: Line: o=acM1000-01 845302855 845302580 IN IP4 192.168.161.4 (53) [Jul 15 13:27:27] DEBUG[19834] chan_sip.c: Line: s=Phone-Call (12) [Jul 15 13:27:27] DEBUG[19834] chan_sip.c: Line: c=IN IP4 192.168.161.4 (22) [Jul 15 13:27:27] DEBUG[19834] chan_sip.c: Line: t=0 0 (5) [Jul 15 13:27:27] DEBUG[19834] chan_sip.c: Line: m=audio 10300 RTP/AVP 8 18 101 (30) [Jul 15 13:27:27] DEBUG[19834] chan_sip.c: Line: a=rtpmap:8 PCMA/8000 (20) [Jul 15 13:27:27] DEBUG[19834] chan_sip.c: Line: a=rtpmap:18 G729/8000 (21) [Jul 15 13:27:27] DEBUG[19834] chan_sip.c: Line: a=fmtp:18 annexb=no (19) [Jul 15 13:27:27] DEBUG[19834] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33) [Jul 15 13:27:27] DEBUG[19834] chan_sip.c: Line: a=fmtp:101 0-15 (15) [Jul 15 13:27:27] DEBUG[19834] chan_sip.c: Line: a=ptime:20 (10) [Jul 15 13:27:27] DEBUG[19834] chan_sip.c: Line: a=sendrecv (10) [Jul 15 13:27:27] DEBUG[19834] chan_sip.c: Line: a=rtcp:10301 IN IP4 192.168.161.4 (33) [Jul 15 13:27:27] VERBOSE[19834] logger.c: --- (16 headers 14 lines) --- [Jul 15 13:27:27] DEBUG[19834] acl.c: ##### Testing 192.168.161.4 with 192.168.161.0 [Jul 15 13:27:27] DEBUG[19834] acl.c: ##### Testing 192.168.161.4 with 192.168.200.0 [Jul 15 13:27:27] DEBUG[19834] acl.c: ##### Testing 192.168.161.4 with 192.168.1.0 [Jul 15 13:27:27] DEBUG[19834] chan_sip.c: Setting NAT on RTP to Off [Jul 15 13:27:27] DEBUG[19834] chan_sip.c: Setting NAT on VRTP to Off [Jul 15 13:27:27] DEBUG[19834] chan_sip.c: Setting NAT on UDPTL to Off [Jul 15 13:27:27] DEBUG[19834] chan_sip.c: Allocating new SIP dialog for 8453148291572008132727@192.168.161.4 - INVITE (With RTP) [Jul 15 13:27:27] DEBUG[19834] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE [Jul 15 13:27:27] DEBUG[19834] chan_sip.c: Begin: parsing SIP "Supported: em,100rel,timer,replaces,path,early-session,resource-priority" [Jul 15 13:27:27] DEBUG[19834] chan_sip.c: Found SIP option: -em- [Jul 15 13:27:27] DEBUG[19834] chan_sip.c: Found no match for SIP option: em (Please file bug report!) [Jul 15 13:27:27] DEBUG[19834] chan_sip.c: Found SIP option: -100rel- [Jul 15 13:27:27] DEBUG[19834] chan_sip.c: Matched SIP option: 100rel [Jul 15 13:27:27] DEBUG[19834] chan_sip.c: Found SIP option: -timer- [Jul 15 13:27:27] DEBUG[19834] chan_sip.c: Matched SIP option: timer [Jul 15 13:27:27] DEBUG[19834] chan_sip.c: Found SIP option: -replaces- [Jul 15 13:27:27] DEBUG[19834] chan_sip.c: Matched SIP option: replaces [Jul 15 13:27:27] DEBUG[19834] chan_sip.c: Found SIP option: -path- [Jul 15 13:27:27] DEBUG[19834] chan_sip.c: Matched SIP option: path [Jul 15 13:27:27] DEBUG[19834] chan_sip.c: Found SIP option: -early-session- [Jul 15 13:27:27] DEBUG[19834] chan_sip.c: Matched SIP option: early-session [Jul 15 13:27:27] DEBUG[19834] chan_sip.c: Found SIP option: -resource-priority- [Jul 15 13:27:27] DEBUG[19834] chan_sip.c: Matched SIP option: resource-priority [Jul 15 13:27:27] VERBOSE[19834] logger.c: Sending to 192.168.161.4 : 5060 (no NAT) [Jul 15 13:27:27] VERBOSE[19834] logger.c: Using INVITE request as basis request - 8453148291572008132727@192.168.161.4 [Jul 15 13:27:27] VERBOSE[19834] logger.c: Found peer 'acM1000-01' [Jul 15 13:27:27] DEBUG[19834] chan_sip.c: Setting NAT on RTP to Off [Jul 15 13:27:27] DEBUG[19834] chan_sip.c: Setting NAT on VRTP to Off [Jul 15 13:27:27] DEBUG[19834] chan_sip.c: Setting NAT on UDPTL to Off [Jul 15 13:27:27] VERBOSE[19834] logger.c: Found RTP audio format 8 [Jul 15 13:27:27] VERBOSE[19834] logger.c: Found RTP audio format 18 [Jul 15 13:27:27] VERBOSE[19834] logger.c: Found RTP audio format 101 [Jul 15 13:27:27] DEBUG[19834] chan_sip.c: Peer doesn't provide T.38 UDPTL [Jul 15 13:27:27] VERBOSE[19834] logger.c: Peer audio RTP is at port 192.168.161.4:10300 [Jul 15 13:27:27] VERBOSE[19834] logger.c: Found audio description format PCMA for ID 8 [Jul 15 13:27:27] VERBOSE[19834] logger.c: Found audio description format G729 for ID 18 [Jul 15 13:27:27] VERBOSE[19834] logger.c: Got unsupported a:fmtp in SDP offer [Jul 15 13:27:27] VERBOSE[19834] logger.c: Found audio description format telephone-event for ID 101 [Jul 15 13:27:27] VERBOSE[19834] logger.c: Got unsupported a:fmtp in SDP offer [Jul 15 13:27:27] VERBOSE[19834] logger.c: Got unsupported a:rtcp in SDP offer [Jul 15 13:27:27] DEBUG[19834] chan_sip.c: T38 state changed to 0 on channel [Jul 15 13:27:27] VERBOSE[19834] logger.c: Capabilities: us - 0x8 (alaw), peer - audio=0x108 (alaw|g729)/video=0x0 (nothing), combined - 0x8 (alaw) [Jul 15 13:27:27] VERBOSE[19834] logger.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) [Jul 15 13:27:27] VERBOSE[19834] logger.c: Peer audio RTP is at port 192.168.161.4:10300 [Jul 15 13:27:27] DEBUG[19834] chan_sip.c: We're settling with these formats: 0x8 (alaw) [Jul 15 13:27:27] DEBUG[19834] chan_sip.c: Checking SIP call limits for device acM1000-01 [Jul 15 13:27:27] DEBUG[19834] chan_sip.c: Updating call counter for incoming call [Jul 15 13:27:27] DEBUG[19834] chan_sip.c: Call from peer 'acM1000-01' is 1 out of 31 [Jul 15 13:27:27] DEBUG[19834] devicestate.c: Notification of state change to be queued on device/channel SIP/acM1000-01 [Jul 15 13:27:27] DEBUG[19834] devicestate.c: Notification of state change to be queued on device/channel SIP/acM1000 [Jul 15 13:27:27] VERBOSE[19834] logger.c: Looking for 400 in trunk-06 (domain pbx.example.net) [Jul 15 13:27:27] DEBUG[19834] chan_sip.c: *** Our native formats are 0x8 (alaw) [Jul 15 13:27:27] DEBUG[19834] chan_sip.c: *** Joint capabilities are 0x8 (alaw) [Jul 15 13:27:27] DEBUG[19834] chan_sip.c: *** Our capabilities are 0x8 (alaw) [Jul 15 13:27:27] DEBUG[19834] chan_sip.c: *** AST_CODEC_CHOOSE formats are 0x8 (alaw) [Jul 15 13:27:27] DEBUG[19834] chan_sip.c: This channel will not be able to handle video. [Jul 15 13:27:27] DEBUG[19834] chan_sip.c: build_route: Contact hop: [Jul 15 13:27:27] VERBOSE[19834] logger.c: list_route: hop: [Jul 15 13:27:27] DEBUG[19834] chan_sip.c: SIP/acM1000-01-09277790: New call is still down.... Trying... [Jul 15 13:27:27] VERBOSE[19834] logger.c: <--- Transmitting (no NAT) to 192.168.161.4:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.161.4;branch=z9hG4bKac845322220;received=192.168.161.4 From: "R&D 1" ;tag=1c845315586 To: Call-ID: 8453148291572008132727@192.168.161.4 CSeq: 1 INVITE User-Agent: atCOM PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <------------> [Jul 15 13:27:27] DEBUG[19834] devicestate.c: Notification of state change to be queued on device/channel SIP/acM1000-01-09277790 [Jul 15 13:27:27] DEBUG[19834] devicestate.c: Notification of state change to be queued on device/channel SIP/acM1000-01 [Jul 15 13:27:27] DEBUG[19797] devicestate.c: No provider found, checking channel drivers for SIP - acM1000-01 [Jul 15 13:27:27] DEBUG[19797] chan_sip.c: Checking device state for peer acM1000-01 [Jul 15 13:27:27] DEBUG[19797] devicestate.c: Changing state for SIP/acM1000-01 - state 2 (In use) [Jul 15 13:27:27] DEBUG[19797] devicestate.c: No provider found, checking channel drivers for SIP - acM1000 [Jul 15 13:27:27] DEBUG[19797] chan_sip.c: Checking device state for peer acM1000 [Jul 15 13:27:27] DEBUG[20262] pbx.c: Launching 'Dial' [Jul 15 13:27:27] VERBOSE[20262] logger.c: -- Executing [400@trunk-06:1] Dial("SIP/acM1000-01-09277790", "SIP/400") in new stack [Jul 15 13:27:27] DEBUG[20262] chan_sip.c: Asked to create a SIP channel with formats: 0x8 (alaw) [Jul 15 13:27:27] DEBUG[20262] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP) [Jul 15 13:27:27] DEBUG[20262] chan_sip.c: Setting NAT on RTP to Off [Jul 15 13:27:27] DEBUG[20262] acl.c: ##### Testing 192.168.161.216 with 192.168.161.0 [Jul 15 13:27:27] DEBUG[20262] acl.c: ##### Testing 192.168.161.216 with 192.168.200.0 [Jul 15 13:27:27] DEBUG[20262] acl.c: ##### Testing 192.168.161.216 with 192.168.1.0 [Jul 15 13:27:27] DEBUG[20262] chan_sip.c: *** Our native formats are 0x100 (g729) [Jul 15 13:27:27] DEBUG[20262] chan_sip.c: *** Joint capabilities are 0x0 (nothing) [Jul 15 13:27:27] DEBUG[20262] chan_sip.c: *** Our capabilities are 0x100 (g729) [Jul 15 13:27:27] DEBUG[20262] chan_sip.c: *** AST_CODEC_CHOOSE formats are 0x100 (g729) [Jul 15 13:27:27] DEBUG[20262] chan_sip.c: *** Our preferred formats from the incoming channel are 0x8 (alaw) [Jul 15 13:27:27] DEBUG[20262] chan_sip.c: This channel will not be able to handle video. [Jul 15 13:27:27] DEBUG[20262] rtp.c: Seeded SDP of 'SIP/400-092757c8' with that of 'SIP/acM1000-01-09277790' [Jul 15 13:27:27] DEBUG[20262] channel.c: Not copying variable SIPCALLID. [Jul 15 13:27:27] DEBUG[20262] channel.c: Not copying variable SIPUSERAGENT. [Jul 15 13:27:27] DEBUG[20262] channel.c: Not copying variable SIPDOMAIN. [Jul 15 13:27:27] DEBUG[20262] channel.c: Not copying variable SIPURI. [Jul 15 13:27:27] DEBUG[20262] chan_sip.c: Outgoing Call for 400 [Jul 15 13:27:27] DEBUG[20262] chan_sip.c: Updating call counter for outgoing call [Jul 15 13:27:27] DEBUG[20262] chan_sip.c: Call to peer '400' is 1 out of 30 [Jul 15 13:27:27] DEBUG[20262] devicestate.c: Notification of state change to be queued on device/channel SIP/400 [Jul 15 13:27:27] DEBUG[20262] chan_sip.c: Our T38 capability (3856), joint T38 capability (3856) [Jul 15 13:27:27] DEBUG[20262] chan_sip.c: ** Our capability: 0x100 (g729) Video flag: False [Jul 15 13:27:27] DEBUG[20262] chan_sip.c: ** Our prefcodec: 0x8 (alaw) [Jul 15 13:27:27] VERBOSE[20262] logger.c: Audio is at 192.168.161.100 port 16244 [Jul 15 13:27:27] VERBOSE[20262] logger.c: Adding codec 0x100 (g729) to SDP [Jul 15 13:27:27] VERBOSE[20262] logger.c: Adding non-codec 0x1 (telephone-event) to SDP [Jul 15 13:27:27] DEBUG[20262] chan_sip.c: -- Done with adding codecs to SDP [Jul 15 13:27:27] DEBUG[20262] channel.c: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30) [Jul 15 13:27:27] DEBUG[20262] chan_sip.c: Done building SDP. Settling with this capability: 0x100 (g729) [Jul 15 13:27:27] DEBUG[20262] chan_sip.c: Header 0: INVITE sip:400@192.168.161.216:5060 SIP/2.0 (43) [Jul 15 13:27:27] DEBUG[20262] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.161.100:5060;branch=z9hG4bK0d7170c1;rport (66) [Jul 15 13:27:27] DEBUG[20262] chan_sip.c: Header 2: From: "R&D 1" ;tag=as041cea96 (54) [Jul 15 13:27:27] DEBUG[20262] chan_sip.c: Header 3: To: (34) [Jul 15 13:27:27] DEBUG[20262] chan_sip.c: Header 4: Contact: (34) [Jul 15 13:27:27] DEBUG[20262] chan_sip.c: Header 5: Call-ID: 49899a0d74d45ac9143bcace5e16c126@pbx.example.net (57) [Jul 15 13:27:27] DEBUG[20262] chan_sip.c: Header 6: CSeq: 102 INVITE (16) [Jul 15 13:27:27] DEBUG[20262] chan_sip.c: Header 7: User-Agent: atCOM PBX (21) [Jul 15 13:27:27] DEBUG[20262] chan_sip.c: Header 8: Max-Forwards: 70 (16) [Jul 15 13:27:27] DEBUG[20262] chan_sip.c: Header 9: Remote-Party-ID: "R&D 1" ;privacy=off;screen=no (72) [Jul 15 13:27:27] DEBUG[20262] chan_sip.c: Header 10: Date: Tue, 15 Jul 2008 11:27:27 GMT (35) [Jul 15 13:27:27] DEBUG[20262] chan_sip.c: Header 11: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) [Jul 15 13:27:27] DEBUG[20262] chan_sip.c: Header 12: Supported: replaces (19) [Jul 15 13:27:27] DEBUG[20262] chan_sip.c: Header 13: Content-Type: application/sdp (29) [Jul 15 13:27:27] DEBUG[20262] chan_sip.c: Header 14: Content-Length: 269 (19) [Jul 15 13:27:27] DEBUG[20262] chan_sip.c: Header 15: (0) [Jul 15 13:27:27] DEBUG[20262] chan_sip.c: Line: v=0 (3) [Jul 15 13:27:27] DEBUG[20262] chan_sip.c: Line: o=root 19767 19767 IN IP4 192.168.161.100 (41) [Jul 15 13:27:27] DEBUG[20262] chan_sip.c: Line: s=session (9) [Jul 15 13:27:27] DEBUG[20262] chan_sip.c: Line: c=IN IP4 192.168.161.100 (24) [Jul 15 13:27:27] DEBUG[20262] chan_sip.c: Line: t=0 0 (5) [Jul 15 13:27:27] DEBUG[20262] chan_sip.c: Line: m=audio 16244 RTP/AVP 18 101 (28) [Jul 15 13:27:27] DEBUG[20262] chan_sip.c: Line: a=rtpmap:18 G729/8000 (21) [Jul 15 13:27:27] DEBUG[20262] chan_sip.c: Line: a=fmtp:18 annexb=no (19) [Jul 15 13:27:27] DEBUG[20262] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33) [Jul 15 13:27:27] DEBUG[20262] chan_sip.c: Line: a=fmtp:101 0-16 (15) [Jul 15 13:27:27] DEBUG[20262] chan_sip.c: Line: a=silenceSupp:off - - - - (25) [Jul 15 13:27:27] DEBUG[20262] chan_sip.c: Line: a=ptime:20 (10) [Jul 15 13:27:27] DEBUG[20262] chan_sip.c: Line: a=sendrecv (10) [Jul 15 13:27:27] VERBOSE[20262] logger.c: Reliably Transmitting (no NAT) to 192.168.161.216:5060: INVITE sip:400@192.168.161.216:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.161.100:5060;branch=z9hG4bK0d7170c1;rport From: "R&D 1" ;tag=as041cea96 To: Contact: Call-ID: 49899a0d74d45ac9143bcace5e16c126@pbx.example.net CSeq: 102 INVITE User-Agent: atCOM PBX Max-Forwards: 70 Remote-Party-ID: "R&D 1" ;privacy=off;screen=no Date: Tue, 15 Jul 2008 11:27:27 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Content-Type: application/sdp Content-Length: 269 v=0 o=root 19767 19767 IN IP4 192.168.161.100 s=session c=IN IP4 192.168.161.100 t=0 0 m=audio 16244 RTP/AVP 18 101 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv --- [Jul 15 13:27:27] DEBUG[20262] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #-1 [Jul 15 13:27:27] VERBOSE[20262] logger.c: -- Called 400 [Jul 15 13:27:27] DEBUG[20262] channel.c: Set channel SIP/400-092757c8 to read format slin [Jul 15 13:27:27] DEBUG[20262] channel.c: Set channel SIP/acM1000-01-09277790 to write format slin [Jul 15 13:27:27] DEBUG[20262] channel.c: Set channel SIP/acM1000-01-09277790 to read format slin [Jul 15 13:27:27] DEBUG[20262] channel.c: Set channel SIP/400-092757c8 to write format slin [Jul 15 13:27:27] DEBUG[19836] app_queue.c: Device 'SIP/acM1000-01' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Jul 15 13:27:27] DEBUG[19797] devicestate.c: Changing state for SIP/acM1000 - state 4 (Invalid) [Jul 15 13:27:27] DEBUG[19797] devicestate.c: No provider found, checking channel drivers for SIP - acM1000-01-09277790 [Jul 15 13:27:27] DEBUG[19797] chan_sip.c: Checking device state for peer acM1000-01-09277790 [Jul 15 13:27:27] DEBUG[19836] app_queue.c: Device 'SIP/acM1000' changed to state '4' (Invalid) but we don't care because they're not a member of any queue. [Jul 15 13:27:27] DEBUG[19797] devicestate.c: Changing state for SIP/acM1000-01-09277790 - state 4 (Invalid) [Jul 15 13:27:27] DEBUG[19797] devicestate.c: No provider found, checking channel drivers for SIP - acM1000-01 [Jul 15 13:27:27] DEBUG[19797] chan_sip.c: Checking device state for peer acM1000-01 [Jul 15 13:27:27] DEBUG[19797] devicestate.c: Changing state for SIP/acM1000-01 - state 2 (In use) [Jul 15 13:27:27] DEBUG[19797] devicestate.c: No provider found, checking channel drivers for SIP - 400 [Jul 15 13:27:27] DEBUG[19797] chan_sip.c: Checking device state for peer 400 [Jul 15 13:27:27] DEBUG[19797] devicestate.c: Changing state for SIP/400 - state 6 (Ringing) [Jul 15 13:27:27] DEBUG[19797] devicestate.c: No provider found, checking channel drivers for SIP - 400 [Jul 15 13:27:27] DEBUG[19797] chan_sip.c: Checking device state for peer 400 [Jul 15 13:27:27] DEBUG[19836] app_queue.c: Device 'SIP/acM1000-01-09277790' changed to state '4' (Invalid) but we don't care because they're not a member of any queue. [Jul 15 13:27:27] DEBUG[19836] app_queue.c: Device 'SIP/acM1000-01' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Jul 15 13:27:27] DEBUG[19836] app_queue.c: Device 'SIP/400' changed to state '6' (Ringing) but we don't care because they're not a member of any queue. [Jul 15 13:27:27] VERBOSE[19834] logger.c: <--- SIP read from 192.168.161.216:5060 ---> SIP/2.0 180 Ringing Via: SIP/2.0/UDP 192.168.161.100:5060;branch=z9hG4bK0d7170c1;rport=5060 From: "R&D 1" ;tag=as041cea96 To: ;tag=ookgb4qgqm Call-ID: 49899a0d74d45ac9143bcace5e16c126@pbx.example.net CSeq: 102 INVITE Contact: ;flow-id=1 Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO Allow-Events: talk, hold, refer, call-info Content-Length: 0 <-------------> [Jul 15 13:27:27] DEBUG[19834] chan_sip.c: Header 0: SIP/2.0 180 Ringing (19) [Jul 15 13:27:27] DEBUG[19834] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.161.100:5060;branch=z9hG4bK0d7170c1;rport=5060 (71) [Jul 15 13:27:27] DEBUG[19834] chan_sip.c: Header 2: From: "R&D 1" ;tag=as041cea96 (54) [Jul 15 13:27:27] DEBUG[19834] chan_sip.c: Header 3: To: ;tag=ookgb4qgqm (49) [Jul 15 13:27:27] DEBUG[19834] chan_sip.c: Header 4: Call-ID: 49899a0d74d45ac9143bcace5e16c126@pbx.example.net (57) [Jul 15 13:27:27] DEBUG[19834] chan_sip.c: Header 5: CSeq: 102 INVITE (16) [Jul 15 13:27:27] DEBUG[19834] chan_sip.c: Header 6: Contact: ;flow-id=1 (49) [Jul 15 13:27:27] DEBUG[19834] chan_sip.c: Header 7: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO (88) [Jul 15 13:27:27] DEBUG[19834] chan_sip.c: Header 8: Allow-Events: talk, hold, refer, call-info (42) [Jul 15 13:27:27] DEBUG[19834] chan_sip.c: Header 9: Content-Length: 0 (17) [Jul 15 13:27:27] DEBUG[19834] chan_sip.c: Header 10: (0) [Jul 15 13:27:27] VERBOSE[19834] logger.c: --- (10 headers 0 lines) --- [Jul 15 13:27:27] DEBUG[19834] chan_sip.c: = Found Their Call ID: 49899a0d74d45ac9143bcace5e16c126@pbx.example.net Their Tag Our tag: as041cea96 [Jul 15 13:27:27] DEBUG[19834] chan_sip.c: *** SIP TIMER: Cancelling retransmission #203 - INVITE (got response) [Jul 15 13:27:27] DEBUG[19834] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '49899a0d74d45ac9143bcace5e16c126@pbx.example.net' Request 102: Found [Jul 15 13:27:27] DEBUG[19834] chan_sip.c: SIP response 180 to standard invite [Jul 15 13:27:27] DEBUG[19834] devicestate.c: Notification of state change to be queued on device/channel SIP/400-092757c8 [Jul 15 13:27:27] DEBUG[19834] devicestate.c: Notification of state change to be queued on device/channel SIP/400 [Jul 15 13:27:27] VERBOSE[20262] logger.c: -- SIP/400-092757c8 is ringing [Jul 15 13:27:27] DEBUG[20262] rtp.c: Setting early bridge SDP of 'SIP/acM1000-01-09277790' with that of 'SIP/400-092757c8' [Jul 15 13:27:27] VERBOSE[20262] logger.c: <--- Transmitting (no NAT) to 192.168.161.4:5060 ---> SIP/2.0 180 Ringing Via: SIP/2.0/UDP 192.168.161.4;branch=z9hG4bKac845322220;received=192.168.161.4 From: "R&D 1" ;tag=1c845315586 To: ;tag=as11bc3276 Call-ID: 8453148291572008132727@192.168.161.4 CSeq: 1 INVITE User-Agent: atCOM PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <------------> [Jul 15 13:27:27] DEBUG[19797] devicestate.c: No provider found, checking channel drivers for SIP - 400-092757c8 [Jul 15 13:27:27] DEBUG[19797] chan_sip.c: Checking device state for peer 400-092757c8 [Jul 15 13:27:27] DEBUG[19797] devicestate.c: Changing state for SIP/400-092757c8 - state 4 (Invalid) [Jul 15 13:27:27] DEBUG[19797] devicestate.c: No provider found, checking channel drivers for SIP - 400 [Jul 15 13:27:27] DEBUG[19797] chan_sip.c: Checking device state for peer 400 [Jul 15 13:27:27] DEBUG[19797] devicestate.c: Changing state for SIP/400 - state 6 (Ringing) [Jul 15 13:27:27] DEBUG[19797] devicestate.c: No provider found, checking channel drivers for SIP - 400 [Jul 15 13:27:27] DEBUG[19797] chan_sip.c: Checking device state for peer 400 [Jul 15 13:27:27] DEBUG[19836] app_queue.c: Device 'SIP/400-092757c8' changed to state '4' (Invalid) but we don't care because they're not a member of any queue. [Jul 15 13:27:27] DEBUG[19836] app_queue.c: Device 'SIP/400' changed to state '6' (Ringing) but we don't care because they're not a member of any queue. [Jul 15 13:27:28] VERBOSE[19834] logger.c: <--- SIP read from 192.168.161.216:5060 ---> SIP/2.0 180 Ringing Via: SIP/2.0/UDP 192.168.161.100:5060;branch=z9hG4bK0d7170c1;rport=5060 From: "R&D 1" ;tag=as041cea96 To: ;tag=ookgb4qgqm Call-ID: 49899a0d74d45ac9143bcace5e16c126@pbx.example.net CSeq: 102 INVITE Contact: ;flow-id=1 Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO Allow-Events: talk, hold, refer, call-info Content-Length: 0 <-------------> [Jul 15 13:27:28] DEBUG[19834] chan_sip.c: Header 0: SIP/2.0 180 Ringing (19) [Jul 15 13:27:28] DEBUG[19834] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.161.100:5060;branch=z9hG4bK0d7170c1;rport=5060 (71) [Jul 15 13:27:28] DEBUG[19834] chan_sip.c: Header 2: From: "R&D 1" ;tag=as041cea96 (54) [Jul 15 13:27:28] DEBUG[19834] chan_sip.c: Header 3: To: ;tag=ookgb4qgqm (49) [Jul 15 13:27:28] DEBUG[19834] chan_sip.c: Header 4: Call-ID: 49899a0d74d45ac9143bcace5e16c126@pbx.example.net (57) [Jul 15 13:27:28] DEBUG[19834] chan_sip.c: Header 5: CSeq: 102 INVITE (16) [Jul 15 13:27:28] DEBUG[19834] chan_sip.c: Header 6: Contact: ;flow-id=1 (49) [Jul 15 13:27:28] DEBUG[19834] chan_sip.c: Header 7: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO (88) [Jul 15 13:27:28] DEBUG[19834] chan_sip.c: Header 8: Allow-Events: talk, hold, refer, call-info (42) [Jul 15 13:27:28] DEBUG[19834] chan_sip.c: Header 9: Content-Length: 0 (17) [Jul 15 13:27:28] DEBUG[19834] chan_sip.c: Header 10: (0) [Jul 15 13:27:28] VERBOSE[19834] logger.c: --- (10 headers 0 lines) --- [Jul 15 13:27:28] DEBUG[19834] chan_sip.c: = Found Their Call ID: 49899a0d74d45ac9143bcace5e16c126@pbx.example.net Their Tag ookgb4qgqm Our tag: as041cea96 [Jul 15 13:27:28] DEBUG[19834] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '49899a0d74d45ac9143bcace5e16c126@pbx.example.net' Request 102: Found [Jul 15 13:27:28] DEBUG[19834] chan_sip.c: SIP response 180 to standard invite [Jul 15 13:27:28] VERBOSE[20262] logger.c: -- SIP/400-092757c8 is ringing [Jul 15 13:27:28] DEBUG[20262] rtp.c: Setting early bridge SDP of 'SIP/acM1000-01-09277790' with that of 'SIP/400-092757c8' [Jul 15 13:27:29] VERBOSE[19834] logger.c: <--- SIP read from 192.168.161.216:5060 ---> SIP/2.0 180 Ringing Via: SIP/2.0/UDP 192.168.161.100:5060;branch=z9hG4bK0d7170c1;rport=5060 From: "R&D 1" ;tag=as041cea96 To: ;tag=ookgb4qgqm Call-ID: 49899a0d74d45ac9143bcace5e16c126@pbx.example.net CSeq: 102 INVITE Contact: ;flow-id=1 Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO Allow-Events: talk, hold, refer, call-info Content-Length: 0 <-------------> [Jul 15 13:27:29] DEBUG[19834] chan_sip.c: Header 0: SIP/2.0 180 Ringing (19) [Jul 15 13:27:29] DEBUG[19834] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.161.100:5060;branch=z9hG4bK0d7170c1;rport=5060 (71) [Jul 15 13:27:29] DEBUG[19834] chan_sip.c: Header 2: From: "R&D 1" ;tag=as041cea96 (54) [Jul 15 13:27:29] DEBUG[19834] chan_sip.c: Header 3: To: ;tag=ookgb4qgqm (49) [Jul 15 13:27:29] DEBUG[19834] chan_sip.c: Header 4: Call-ID: 49899a0d74d45ac9143bcace5e16c126@pbx.example.net (57) [Jul 15 13:27:29] DEBUG[19834] chan_sip.c: Header 5: CSeq: 102 INVITE (16) [Jul 15 13:27:29] DEBUG[19834] chan_sip.c: Header 6: Contact: ;flow-id=1 (49) [Jul 15 13:27:29] DEBUG[19834] chan_sip.c: Header 7: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO (88) [Jul 15 13:27:29] DEBUG[19834] chan_sip.c: Header 8: Allow-Events: talk, hold, refer, call-info (42) [Jul 15 13:27:29] DEBUG[19834] chan_sip.c: Header 9: Content-Length: 0 (17) [Jul 15 13:27:29] DEBUG[19834] chan_sip.c: Header 10: (0) [Jul 15 13:27:29] VERBOSE[19834] logger.c: --- (10 headers 0 lines) --- [Jul 15 13:27:29] DEBUG[19834] chan_sip.c: = Found Their Call ID: 49899a0d74d45ac9143bcace5e16c126@pbx.example.net Their Tag ookgb4qgqm Our tag: as041cea96 [Jul 15 13:27:29] DEBUG[19834] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '49899a0d74d45ac9143bcace5e16c126@pbx.example.net' Request 102: Found [Jul 15 13:27:29] DEBUG[19834] chan_sip.c: SIP response 180 to standard invite [Jul 15 13:27:29] VERBOSE[20262] logger.c: -- SIP/400-092757c8 is ringing [Jul 15 13:27:29] DEBUG[20262] rtp.c: Setting early bridge SDP of 'SIP/acM1000-01-09277790' with that of 'SIP/400-092757c8' [Jul 15 13:27:30] VERBOSE[19834] logger.c: <--- SIP read from 192.168.161.216:5060 ---> SIP/2.0 200 Ok Via: SIP/2.0/UDP 192.168.161.100:5060;branch=z9hG4bK0d7170c1;rport=5060 From: "R&D 1" ;tag=as041cea96 To: ;tag=ookgb4qgqm Call-ID: 49899a0d74d45ac9143bcace5e16c126@pbx.example.net CSeq: 102 INVITE Contact: ;flow-id=1 User-Agent: snom320/7.1.33 Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO Allow-Events: talk, hold, refer, call-info Supported: timer, 100rel, replaces, from-change Content-Type: application/sdp Content-Length: 226 v=0 o=root 563802528 563802529 IN IP4 192.168.161.216 s=call c=IN IP4 192.168.161.216 t=0 0 m=audio 10030 RTP/AVP 18 101 a=rtpmap:18 g729/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=sendrecv <-------------> [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 0: SIP/2.0 200 Ok (14) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.161.100:5060;branch=z9hG4bK0d7170c1;rport=5060 (71) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 2: From: "R&D 1" ;tag=as041cea96 (54) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 3: To: ;tag=ookgb4qgqm (49) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 4: Call-ID: 49899a0d74d45ac9143bcace5e16c126@pbx.example.net (57) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 5: CSeq: 102 INVITE (16) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 6: Contact: ;flow-id=1 (49) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 7: User-Agent: snom320/7.1.33 (26) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 8: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO (88) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 9: Allow-Events: talk, hold, refer, call-info (42) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 10: Supported: timer, 100rel, replaces, from-change (47) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 11: Content-Type: application/sdp (29) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 12: Content-Length: 226 (19) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 13: (0) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Line: v=0 (3) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Line: o=root 563802528 563802529 IN IP4 192.168.161.216 (49) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Line: s=call (6) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Line: c=IN IP4 192.168.161.216 (24) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Line: t=0 0 (5) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Line: m=audio 10030 RTP/AVP 18 101 (28) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Line: a=rtpmap:18 g729/8000 (21) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Line: a=fmtp:101 0-16 (15) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Line: a=ptime:20 (10) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Line: a=sendrecv (10) [Jul 15 13:27:30] VERBOSE[19834] logger.c: --- (13 headers 11 lines) --- [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: = Found Their Call ID: 49899a0d74d45ac9143bcace5e16c126@pbx.example.net Their Tag ookgb4qgqm Our tag: as041cea96 [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Acked pending invite 102 [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Stopping retransmission on '49899a0d74d45ac9143bcace5e16c126@pbx.example.net' of Request 102: Match Found [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: SIP response 200 to standard invite [Jul 15 13:27:30] VERBOSE[19834] logger.c: Found RTP audio format 18 [Jul 15 13:27:30] VERBOSE[19834] logger.c: Found RTP audio format 101 [Jul 15 13:27:30] VERBOSE[19834] logger.c: Peer audio RTP is at port 192.168.161.216:10030 [Jul 15 13:27:30] VERBOSE[19834] logger.c: Found audio description format g729 for ID 18 [Jul 15 13:27:30] VERBOSE[19834] logger.c: Found audio description format telephone-event for ID 101 [Jul 15 13:27:30] VERBOSE[19834] logger.c: Got unsupported a:fmtp in SDP offer [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: T38 state changed to 0 on channel SIP/400-092757c8 [Jul 15 13:27:30] VERBOSE[19834] logger.c: Capabilities: us - 0x100 (g729), peer - audio=0x100 (g729)/video=0x0 (nothing), combined - 0x100 (g729) [Jul 15 13:27:30] VERBOSE[19834] logger.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) [Jul 15 13:27:30] VERBOSE[19834] logger.c: Peer audio RTP is at port 192.168.161.216:10030 [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: We're settling with these formats: 0x100 (g729) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: We have an owner, now see if we need to change this call [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Updating call counter for outgoing call [Jul 15 13:27:30] DEBUG[19834] devicestate.c: Notification of state change to be queued on device/channel SIP/400 [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: build_route: Contact hop: ;flow-id=1 [Jul 15 13:27:30] VERBOSE[19834] logger.c: list_route: hop: [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Strict routing enforced for session 49899a0d74d45ac9143bcace5e16c126@pbx.example.net [Jul 15 13:27:30] VERBOSE[19834] logger.c: set_destination: Parsing for address/port to send to [Jul 15 13:27:30] VERBOSE[19834] logger.c: set_destination: set destination to 192.168.161.216, port 5060 [Jul 15 13:27:30] VERBOSE[19834] logger.c: Transmitting (no NAT) to 192.168.161.216:5060: ACK sip:400@192.168.161.216:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.161.100:5060;branch=z9hG4bK315a22a8;rport From: "R&D 1" ;tag=as041cea96 To: ;tag=ookgb4qgqm Contact: Call-ID: 49899a0d74d45ac9143bcace5e16c126@pbx.example.net CSeq: 102 ACK User-Agent: atCOM PBX Max-Forwards: 70 Remote-Party-ID: "R&D 1" ;privacy=off;screen=no Content-Length: 0 --- [Jul 15 13:27:30] DEBUG[19797] devicestate.c: No provider found, checking channel drivers for SIP - 400 [Jul 15 13:27:30] DEBUG[19797] chan_sip.c: Checking device state for peer 400 [Jul 15 13:27:30] DEBUG[19797] devicestate.c: Changing state for SIP/400 - state 2 (In use) [Jul 15 13:27:30] DEBUG[19797] devicestate.c: No provider found, checking channel drivers for SIP - 400 [Jul 15 13:27:30] DEBUG[19797] chan_sip.c: Checking device state for peer 400 [Jul 15 13:27:30] DEBUG[20262] devicestate.c: Notification of state change to be queued on device/channel SIP/400-092757c8 [Jul 15 13:27:30] DEBUG[20262] devicestate.c: Notification of state change to be queued on device/channel SIP/400 [Jul 15 13:27:30] VERBOSE[20262] logger.c: -- SIP/400-092757c8 answered SIP/acM1000-01-09277790 [Jul 15 13:27:30] DEBUG[20262] rtp.c: Setting early bridge SDP of 'SIP/acM1000-01-09277790' with that of 'SIP/400-092757c8' [Jul 15 13:27:30] DEBUG[20262] devicestate.c: Notification of state change to be queued on device/channel SIP/acM1000-01-09277790 [Jul 15 13:27:30] DEBUG[20262] devicestate.c: Notification of state change to be queued on device/channel SIP/acM1000-01 [Jul 15 13:27:30] DEBUG[20262] chan_sip.c: SIP answering channel: SIP/acM1000-01-09277790 [Jul 15 13:27:30] DEBUG[20262] chan_sip.c: Setting framing from config on incoming call [Jul 15 13:27:30] DEBUG[20262] chan_sip.c: ** Our capability: 0x8 (alaw) Video flag: True [Jul 15 13:27:30] DEBUG[20262] chan_sip.c: ** Our prefcodec: 0x0 (nothing) [Jul 15 13:27:30] VERBOSE[20262] logger.c: Audio is at 192.168.161.100 port 16574 [Jul 15 13:27:30] VERBOSE[20262] logger.c: Adding codec 0x8 (alaw) to SDP [Jul 15 13:27:30] VERBOSE[20262] logger.c: Adding non-codec 0x1 (telephone-event) to SDP [Jul 15 13:27:30] DEBUG[20262] chan_sip.c: -- Done with adding codecs to SDP [Jul 15 13:27:30] DEBUG[20262] channel.c: Internal timing is disabled (option_internal_timing=0 chan->timingfd=25) [Jul 15 13:27:30] DEBUG[20262] chan_sip.c: Done building SDP. Settling with this capability: 0x8 (alaw) [Jul 15 13:27:30] VERBOSE[20262] logger.c: <--- Reliably Transmitting (no NAT) to 192.168.161.4:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.161.4;branch=z9hG4bKac845322220;received=192.168.161.4 From: "R&D 1" ;tag=1c845315586 To: ;tag=as11bc3276 Call-ID: 8453148291572008132727@192.168.161.4 CSeq: 1 INVITE User-Agent: atCOM PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Type: application/sdp Content-Length: 246 v=0 o=root 19767 19767 IN IP4 192.168.161.100 s=session c=IN IP4 192.168.161.100 t=0 0 m=audio 16574 RTP/AVP 8 101 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv <------------> [Jul 15 13:27:30] DEBUG[20262] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #-1 [Jul 15 13:27:30] VERBOSE[20262] logger.c: -- Native bridging SIP/acM1000-01-09277790 and SIP/400-092757c8 [Jul 15 13:27:30] DEBUG[20262] chan_sip.c: Deferring reinvite on SIP '8453148291572008132727@192.168.161.4' - It's audio will be redirected to IP 192.168.161.216 [Jul 15 13:27:30] DEBUG[20262] chan_sip.c: Sending reinvite on SIP '49899a0d74d45ac9143bcace5e16c126@pbx.example.net' - It's audio soon redirected to IP 192.168.161.4 [Jul 15 13:27:30] DEBUG[20262] chan_sip.c: Strict routing enforced for session 49899a0d74d45ac9143bcace5e16c126@pbx.example.net [Jul 15 13:27:30] VERBOSE[20262] logger.c: set_destination: Parsing for address/port to send to [Jul 15 13:27:30] VERBOSE[20262] logger.c: set_destination: set destination to 192.168.161.216, port 5060 [Jul 15 13:27:30] DEBUG[20262] chan_sip.c: ** Our capability: 0x100 (g729) Video flag: True [Jul 15 13:27:30] DEBUG[20262] chan_sip.c: ** Our prefcodec: 0x8 (alaw) [Jul 15 13:27:30] VERBOSE[20262] logger.c: Audio is at 192.168.161.100 port 16244 [Jul 15 13:27:30] VERBOSE[20262] logger.c: Adding codec 0x100 (g729) to SDP [Jul 15 13:27:30] VERBOSE[20262] logger.c: Adding non-codec 0x1 (telephone-event) to SDP [Jul 15 13:27:30] DEBUG[20262] chan_sip.c: -- Done with adding codecs to SDP [Jul 15 13:27:30] DEBUG[20262] channel.c: Internal timing is disabled (option_internal_timing=0 chan->timingfd=30) [Jul 15 13:27:30] DEBUG[20262] chan_sip.c: Done building SDP. Settling with this capability: 0x100 (g729) [Jul 15 13:27:30] DEBUG[20262] chan_sip.c: Initializing already initialized SIP dialog 49899a0d74d45ac9143bcace5e16c126@pbx.example.net (presumably reinvite) [Jul 15 13:27:30] DEBUG[20262] chan_sip.c: Header 0: INVITE sip:400@192.168.161.216:5060 SIP/2.0 (43) [Jul 15 13:27:30] DEBUG[20262] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.161.100:5060;branch=z9hG4bK69f8a1a3;rport (66) [Jul 15 13:27:30] DEBUG[20262] chan_sip.c: Header 2: From: "R&D 1" ;tag=as041cea96 (54) [Jul 15 13:27:30] DEBUG[20262] chan_sip.c: Header 3: To: ;tag=ookgb4qgqm (49) [Jul 15 13:27:30] DEBUG[20262] chan_sip.c: Header 4: Contact: (34) [Jul 15 13:27:30] DEBUG[20262] chan_sip.c: Header 5: Call-ID: 49899a0d74d45ac9143bcace5e16c126@pbx.example.net (57) [Jul 15 13:27:30] DEBUG[20262] chan_sip.c: Header 6: CSeq: 103 INVITE (16) [Jul 15 13:27:30] DEBUG[20262] chan_sip.c: Header 7: User-Agent: atCOM PBX (21) [Jul 15 13:27:30] DEBUG[20262] chan_sip.c: Header 8: Max-Forwards: 70 (16) [Jul 15 13:27:30] DEBUG[20262] chan_sip.c: Header 9: Remote-Party-ID: "R&D 1" ;privacy=off;screen=no (72) [Jul 15 13:27:30] DEBUG[20262] chan_sip.c: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) [Jul 15 13:27:30] DEBUG[20262] chan_sip.c: Header 11: Supported: replaces (19) [Jul 15 13:27:30] DEBUG[20262] chan_sip.c: Header 12: X-asterisk-Info: SIP re-invite (External RTP bridge) (52) [Jul 15 13:27:30] DEBUG[20262] chan_sip.c: Header 13: Content-Type: application/sdp (29) [Jul 15 13:27:30] DEBUG[20262] chan_sip.c: Header 14: Content-Length: 265 (19) [Jul 15 13:27:30] DEBUG[20262] chan_sip.c: Header 15: (0) [Jul 15 13:27:30] DEBUG[20262] chan_sip.c: Line: v=0 (3) [Jul 15 13:27:30] DEBUG[20262] chan_sip.c: Line: o=root 19767 19768 IN IP4 192.168.161.4 (39) [Jul 15 13:27:30] DEBUG[20262] chan_sip.c: Line: s=session (9) [Jul 15 13:27:30] DEBUG[20262] chan_sip.c: Line: c=IN IP4 192.168.161.4 (22) [Jul 15 13:27:30] DEBUG[20262] chan_sip.c: Line: t=0 0 (5) [Jul 15 13:27:30] DEBUG[20262] chan_sip.c: Line: m=audio 10300 RTP/AVP 18 101 (28) [Jul 15 13:27:30] DEBUG[20262] chan_sip.c: Line: a=rtpmap:18 G729/8000 (21) [Jul 15 13:27:30] DEBUG[20262] chan_sip.c: Line: a=fmtp:18 annexb=no (19) [Jul 15 13:27:30] DEBUG[20262] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33) [Jul 15 13:27:30] DEBUG[20262] chan_sip.c: Line: a=fmtp:101 0-16 (15) [Jul 15 13:27:30] DEBUG[20262] chan_sip.c: Line: a=silenceSupp:off - - - - (25) [Jul 15 13:27:30] DEBUG[20262] chan_sip.c: Line: a=ptime:20 (10) [Jul 15 13:27:30] DEBUG[20262] chan_sip.c: Line: a=sendrecv (10) [Jul 15 13:27:30] VERBOSE[20262] logger.c: Reliably Transmitting (no NAT) to 192.168.161.216:5060: INVITE sip:400@192.168.161.216:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.161.100:5060;branch=z9hG4bK69f8a1a3;rport From: "R&D 1" ;tag=as041cea96 To: ;tag=ookgb4qgqm Contact: Call-ID: 49899a0d74d45ac9143bcace5e16c126@pbx.example.net CSeq: 103 INVITE User-Agent: atCOM PBX Max-Forwards: 70 Remote-Party-ID: "R&D 1" ;privacy=off;screen=no Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces X-asterisk-Info: SIP re-invite (External RTP bridge) Content-Type: application/sdp Content-Length: 265 v=0 o=root 19767 19768 IN IP4 192.168.161.4 s=session c=IN IP4 192.168.161.4 t=0 0 m=audio 10300 RTP/AVP 18 101 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv --- [Jul 15 13:27:30] DEBUG[20262] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #-1 [Jul 15 13:27:30] DEBUG[19836] app_queue.c: Device 'SIP/400' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Jul 15 13:27:30] DEBUG[19797] devicestate.c: No provider found, checking channel drivers for SIP - 400-092757c8 [Jul 15 13:27:30] DEBUG[19797] chan_sip.c: Checking device state for peer 400-092757c8 [Jul 15 13:27:30] DEBUG[19797] devicestate.c: Changing state for SIP/400-092757c8 - state 4 (Invalid) [Jul 15 13:27:30] DEBUG[19797] devicestate.c: No provider found, checking channel drivers for SIP - 400 [Jul 15 13:27:30] DEBUG[19797] chan_sip.c: Checking device state for peer 400 [Jul 15 13:27:30] DEBUG[19797] devicestate.c: Changing state for SIP/400 - state 2 (In use) [Jul 15 13:27:30] DEBUG[19797] devicestate.c: No provider found, checking channel drivers for SIP - 400 [Jul 15 13:27:30] DEBUG[19797] chan_sip.c: Checking device state for peer 400 [Jul 15 13:27:30] DEBUG[19797] devicestate.c: No provider found, checking channel drivers for SIP - acM1000-01-09277790 [Jul 15 13:27:30] DEBUG[19797] chan_sip.c: Checking device state for peer acM1000-01-09277790 [Jul 15 13:27:30] DEBUG[19836] app_queue.c: Device 'SIP/400-092757c8' changed to state '4' (Invalid) but we don't care because they're not a member of any queue. [Jul 15 13:27:30] DEBUG[19836] app_queue.c: Device 'SIP/400' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Jul 15 13:27:30] DEBUG[19797] devicestate.c: Changing state for SIP/acM1000-01-09277790 - state 4 (Invalid) [Jul 15 13:27:30] DEBUG[19797] devicestate.c: No provider found, checking channel drivers for SIP - acM1000-01 [Jul 15 13:27:30] DEBUG[19797] chan_sip.c: Checking device state for peer acM1000-01 [Jul 15 13:27:30] DEBUG[19797] devicestate.c: Changing state for SIP/acM1000-01 - state 2 (In use) [Jul 15 13:27:30] DEBUG[19836] app_queue.c: Device 'SIP/acM1000-01-09277790' changed to state '4' (Invalid) but we don't care because they're not a member of any queue. [Jul 15 13:27:30] DEBUG[19836] app_queue.c: Device 'SIP/acM1000-01' changed to state '2' (In use) but we don't care because they're not a member of any queue. [Jul 15 13:27:30] VERBOSE[19834] logger.c: <--- SIP read from 192.168.161.4:5060 ---> ACK sip:400@192.168.161.100 SIP/2.0 Via: SIP/2.0/UDP 192.168.161.4;branch=z9hG4bKac886961015 Max-Forwards: 70 From: "R&D 1" ;tag=1c845315586 To: ;tag=as11bc3276 Call-ID: 8453148291572008132727@192.168.161.4 CSeq: 1 ACK Contact: Supported: em,timer,replaces,path,early-session,resource-priority Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE User-Agent: acM1000-01/v.5.20A.032.001 Content-Length: 0 <-------------> [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 0: ACK sip:400@192.168.161.100 SIP/2.0 (35) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.161.4;branch=z9hG4bKac886961015 (56) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 2: Max-Forwards: 70 (16) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 3: From: "R&D 1" ;tag=1c845315586 (55) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 4: To: ;tag=as11bc3276 (55) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 5: Call-ID: 8453148291572008132727@192.168.161.4 (45) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 6: CSeq: 1 ACK (11) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 7: Contact: (39) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 8: Supported: em,timer,replaces,path,early-session,resource-priority (65) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 9: Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE (86) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 10: User-Agent: acM1000-01/v.5.20A.032.001 (38) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 11: Content-Length: 0 (17) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 12: (0) [Jul 15 13:27:30] VERBOSE[19834] logger.c: --- (12 headers 0 lines) --- [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: = No match Their Call ID: 49899a0d74d45ac9143bcace5e16c126@pbx.example.net Their Tag ookgb4qgqm Our tag: as041cea96 [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: = Found Their Call ID: 8453148291572008132727@192.168.161.4 Their Tag 1c845315586 Our tag: as11bc3276 [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: **** Received ACK (6) - Command in SIP ACK [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #205 [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Stopping retransmission on '8453148291572008132727@192.168.161.4' of Response 1: Match Found [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Sending pending reinvite on '8453148291572008132727@192.168.161.4' [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Strict routing enforced for session 8453148291572008132727@192.168.161.4 [Jul 15 13:27:30] VERBOSE[19834] logger.c: set_destination: Parsing for address/port to send to [Jul 15 13:27:30] VERBOSE[19834] logger.c: set_destination: set destination to 192.168.161.4, port 5060 [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: ** Our capability: 0x0 (nothing) Video flag: True [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: ** Our prefcodec: 0x0 (nothing) [Jul 15 13:27:30] VERBOSE[19834] logger.c: Audio is at 192.168.161.100 port 16574 [Jul 15 13:27:30] VERBOSE[19834] logger.c: Adding non-codec 0x1 (telephone-event) to SDP [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: -- Done with adding codecs to SDP [Jul 15 13:27:30] DEBUG[19834] channel.c: Internal timing is disabled (option_internal_timing=0 chan->timingfd=25) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Done building SDP. Settling with this capability: 0x0 (nothing) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Initializing already initialized SIP dialog 8453148291572008132727@192.168.161.4 (presumably reinvite) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 0: INVITE sip:acM1000-01@192.168.161.4 SIP/2.0 (43) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.161.100:5060;branch=z9hG4bK2b689357;rport (66) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 2: From: ;tag=as11bc3276 (57) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 3: To: "R&D 1" ;tag=1c845315586 (53) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 4: Contact: (34) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 5: Call-ID: 8453148291572008132727@192.168.161.4 (45) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 6: CSeq: 102 INVITE (16) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 7: User-Agent: atCOM PBX (21) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 8: Max-Forwards: 70 (16) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 9: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 10: Supported: replaces (19) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 11: X-asterisk-Info: SIP re-invite (External RTP bridge) (52) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 12: Content-Type: application/sdp (29) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 13: Content-Length: 210 (19) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 14: (0) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Line: v=0 (3) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Line: o=root 19767 19768 IN IP4 192.168.161.216 (41) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Line: s=session (9) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Line: c=IN IP4 192.168.161.216 (24) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Line: t=0 0 (5) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Line: m=audio 10030 RTP/AVP 101 (25) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Line: a=fmtp:101 0-16 (15) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Line: a=silenceSupp:off - - - - (25) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Line: a=sendrecv (10) [Jul 15 13:27:30] VERBOSE[19834] logger.c: Reliably Transmitting (no NAT) to 192.168.161.4:5060: INVITE sip:acM1000-01@192.168.161.4 SIP/2.0 Via: SIP/2.0/UDP 192.168.161.100:5060;branch=z9hG4bK2b689357;rport From: ;tag=as11bc3276 To: "R&D 1" ;tag=1c845315586 Contact: Call-ID: 8453148291572008132727@192.168.161.4 CSeq: 102 INVITE User-Agent: atCOM PBX Max-Forwards: 70 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces X-asterisk-Info: SIP re-invite (External RTP bridge) Content-Type: application/sdp Content-Length: 210 v=0 o=root 19767 19768 IN IP4 192.168.161.216 s=session c=IN IP4 192.168.161.216 t=0 0 m=audio 10030 RTP/AVP 101 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - a=sendrecv --- [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #-1 [Jul 15 13:27:30] DEBUG[20262] rtp.c: Got RTCP report of 44 bytes [Jul 15 13:27:30] DEBUG[20262] rtp.c: Ooh, format changed from unknown to g729 [Jul 15 13:27:30] DEBUG[20262] rtp.c: Created smoother: format: 256 ms: 20 len: 20 [Jul 15 13:27:30] VERBOSE[19834] logger.c: <--- SIP read from 192.168.161.4:5060 ---> SIP/2.0 488 Not Acceptable Here Via: SIP/2.0/UDP 192.168.161.100:5060;branch=z9hG4bK2b689357;rport From: ;tag=as11bc3276 To: "R&D 1" ;tag=1c845315586 Call-ID: 8453148291572008132727@192.168.161.4 CSeq: 102 INVITE Supported: em,timer,replaces,path,early-session,resource-priority Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE Server: acM1000-01/v.5.20A.032.001 Content-Length: 0 <-------------> [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 0: SIP/2.0 488 Not Acceptable Here (31) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.161.100:5060;branch=z9hG4bK2b689357;rport (66) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 2: From: ;tag=as11bc3276 (57) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 3: To: "R&D 1" ;tag=1c845315586 (53) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 4: Call-ID: 8453148291572008132727@192.168.161.4 (45) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 5: CSeq: 102 INVITE (16) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 6: Supported: em,timer,replaces,path,early-session,resource-priority (65) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 7: Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE (86) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 8: Server: acM1000-01/v.5.20A.032.001 (34) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 9: Content-Length: 0 (17) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 10: (0) [Jul 15 13:27:30] VERBOSE[19834] logger.c: --- (10 headers 0 lines) --- [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: = No match Their Call ID: 49899a0d74d45ac9143bcace5e16c126@pbx.example.net Their Tag ookgb4qgqm Our tag: as041cea96 [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: = Found Their Call ID: 8453148291572008132727@192.168.161.4 Their Tag 1c845315586 Our tag: as11bc3276 [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Acked pending invite 102 [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #207 [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Stopping retransmission on '8453148291572008132727@192.168.161.4' of Request 102: Match Found [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: SIP response 488 to RE-invite on outgoing call 8453148291572008132727@192.168.161.4 [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Strict routing enforced for session 8453148291572008132727@192.168.161.4 [Jul 15 13:27:30] VERBOSE[19834] logger.c: set_destination: Parsing for address/port to send to [Jul 15 13:27:30] VERBOSE[19834] logger.c: set_destination: set destination to 192.168.161.4, port 5060 [Jul 15 13:27:30] VERBOSE[19834] logger.c: Transmitting (no NAT) to 192.168.161.4:5060: ACK sip:acM1000-01@192.168.161.4 SIP/2.0 Via: SIP/2.0/UDP 192.168.161.100:5060;branch=z9hG4bK2b689357;rport From: ;tag=as11bc3276 To: "R&D 1" ;tag=1c845315586 Contact: Call-ID: 8453148291572008132727@192.168.161.4 CSeq: 102 ACK User-Agent: atCOM PBX Max-Forwards: 70 Content-Length: 0 --- [Jul 15 13:27:30] ERROR[19834] chan_sip.c: Got error on T.38 re-invite. Bad configuration. Peer needs to have T.38 disabled. [Jul 15 13:27:30] DEBUG[20262] rtp.c: Got a FRAME_CONTROL (8) frame on channel SIP/acM1000-01-09277790 [Jul 15 13:27:30] DEBUG[20262] channel.c: Returning from native bridge, channels: SIP/acM1000-01-09277790, SIP/400-092757c8 [Jul 15 13:27:30] DEBUG[20262] channel.c: Hanging up channel 'SIP/400-092757c8' [Jul 15 13:27:30] DEBUG[20262] chan_sip.c: Hangup call SIP/400-092757c8, SIP callid 49899a0d74d45ac9143bcace5e16c126@pbx.example.net) [Jul 15 13:27:30] DEBUG[20262] chan_sip.c: update_call_counter(400) - decrement call limit counter on hangup [Jul 15 13:27:30] DEBUG[20262] chan_sip.c: Updating call counter for outgoing call [Jul 15 13:27:30] DEBUG[20262] chan_sip.c: Call to peer '400' removed from call limit 30 [Jul 15 13:27:30] DEBUG[20262] devicestate.c: Notification of state change to be queued on device/channel SIP/400 [Jul 15 13:27:30] VERBOSE[20262] logger.c: Scheduling destruction of SIP dialog '49899a0d74d45ac9143bcace5e16c126@pbx.example.net' in 32000 ms (Method: INVITE) [Jul 15 13:27:30] DEBUG[20262] devicestate.c: Notification of state change to be queued on device/channel SIP/400-092757c8 [Jul 15 13:27:30] DEBUG[20262] devicestate.c: Notification of state change to be queued on device/channel SIP/400 [Jul 15 13:27:30] DEBUG[20262] rtp.c: Channel '' has no RTP, not doing anything [Jul 15 13:27:30] DEBUG[20262] app_dial.c: Exiting with DIALSTATUS=ANSWER. [Jul 15 13:27:30] DEBUG[20262] pbx.c: Spawn extension (trunk-06,400,1) exited non-zero on 'SIP/acM1000-01-09277790' [Jul 15 13:27:30] VERBOSE[20262] logger.c: == Spawn extension (trunk-06, 400, 1) exited non-zero on 'SIP/acM1000-01-09277790' [Jul 15 13:27:30] DEBUG[20262] channel.c: Soft-Hanging up channel 'SIP/acM1000-01-09277790' [Jul 15 13:27:30] DEBUG[20262] channel.c: Hanging up channel 'SIP/acM1000-01-09277790' [Jul 15 13:27:30] DEBUG[20262] chan_sip.c: Hangup call SIP/acM1000-01-09277790, SIP callid 8453148291572008132727@192.168.161.4) [Jul 15 13:27:30] DEBUG[20262] chan_sip.c: update_call_counter(acM1000-01) - decrement call limit counter on hangup [Jul 15 13:27:30] DEBUG[20262] chan_sip.c: Updating call counter for incoming call [Jul 15 13:27:30] DEBUG[20262] chan_sip.c: Call from peer 'acM1000-01' removed from call limit 31 [Jul 15 13:27:30] DEBUG[20262] devicestate.c: Notification of state change to be queued on device/channel SIP/acM1000-01 [Jul 15 13:27:30] DEBUG[20262] devicestate.c: Notification of state change to be queued on device/channel SIP/acM1000 [Jul 15 13:27:30] VERBOSE[20262] logger.c: Scheduling destruction of SIP dialog '8453148291572008132727@192.168.161.4' in 32000 ms (Method: ACK) [Jul 15 13:27:30] DEBUG[20262] chan_sip.c: Strict routing enforced for session 8453148291572008132727@192.168.161.4 [Jul 15 13:27:30] VERBOSE[20262] logger.c: set_destination: Parsing for address/port to send to [Jul 15 13:27:30] VERBOSE[20262] logger.c: set_destination: set destination to 192.168.161.4, port 5060 [Jul 15 13:27:30] VERBOSE[20262] logger.c: Reliably Transmitting (no NAT) to 192.168.161.4:5060: BYE sip:acM1000-01@192.168.161.4 SIP/2.0 Via: SIP/2.0/UDP 192.168.161.100:5060;branch=z9hG4bK1b1509de;rport From: ;tag=as11bc3276 To: "R&D 1" ;tag=1c845315586 Call-ID: 8453148291572008132727@192.168.161.4 CSeq: 103 BYE User-Agent: atCOM PBX Max-Forwards: 70 Content-Length: 0 --- [Jul 15 13:27:30] DEBUG[20262] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #-1 [Jul 15 13:27:30] DEBUG[20262] devicestate.c: Notification of state change to be queued on device/channel SIP/acM1000-01-09277790 [Jul 15 13:27:30] DEBUG[20262] devicestate.c: Notification of state change to be queued on device/channel SIP/acM1000-01 [Jul 15 13:27:30] DEBUG[20262] cdr.c: Dropping CDR ! [Jul 15 13:27:30] DEBUG[19797] devicestate.c: No provider found, checking channel drivers for SIP - 400 [Jul 15 13:27:30] DEBUG[19797] chan_sip.c: Checking device state for peer 400 [Jul 15 13:27:30] DEBUG[19797] devicestate.c: Changing state for SIP/400 - state 1 (Not in use) [Jul 15 13:27:30] DEBUG[19797] devicestate.c: No provider found, checking channel drivers for SIP - 400 [Jul 15 13:27:30] DEBUG[19797] chan_sip.c: Checking device state for peer 400 [Jul 15 13:27:30] DEBUG[19797] devicestate.c: No provider found, checking channel drivers for SIP - 400-092757c8 [Jul 15 13:27:30] DEBUG[19797] chan_sip.c: Checking device state for peer 400-092757c8 [Jul 15 13:27:30] DEBUG[19836] app_queue.c: Device 'SIP/400' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Jul 15 13:27:30] DEBUG[19797] devicestate.c: Changing state for SIP/400-092757c8 - state 4 (Invalid) [Jul 15 13:27:30] DEBUG[19797] devicestate.c: No provider found, checking channel drivers for SIP - 400 [Jul 15 13:27:30] DEBUG[19797] chan_sip.c: Checking device state for peer 400 [Jul 15 13:27:30] DEBUG[19797] devicestate.c: Changing state for SIP/400 - state 1 (Not in use) [Jul 15 13:27:30] DEBUG[19797] devicestate.c: No provider found, checking channel drivers for SIP - 400 [Jul 15 13:27:30] DEBUG[19797] chan_sip.c: Checking device state for peer 400 [Jul 15 13:27:30] DEBUG[19797] devicestate.c: No provider found, checking channel drivers for SIP - acM1000-01 [Jul 15 13:27:30] DEBUG[19797] chan_sip.c: Checking device state for peer acM1000-01 [Jul 15 13:27:30] DEBUG[19797] devicestate.c: Changing state for SIP/acM1000-01 - state 1 (Not in use) [Jul 15 13:27:30] DEBUG[19797] devicestate.c: No provider found, checking channel drivers for SIP - acM1000 [Jul 15 13:27:30] DEBUG[19797] chan_sip.c: Checking device state for peer acM1000 [Jul 15 13:27:30] DEBUG[19836] app_queue.c: Device 'SIP/400-092757c8' changed to state '4' (Invalid) but we don't care because they're not a member of any queue. [Jul 15 13:27:30] DEBUG[19836] app_queue.c: Device 'SIP/400' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Jul 15 13:27:30] DEBUG[19836] app_queue.c: Device 'SIP/acM1000-01' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Jul 15 13:27:30] DEBUG[19797] devicestate.c: Changing state for SIP/acM1000 - state 4 (Invalid) [Jul 15 13:27:30] DEBUG[19797] devicestate.c: No provider found, checking channel drivers for SIP - acM1000-01-09277790 [Jul 15 13:27:30] DEBUG[19797] chan_sip.c: Checking device state for peer acM1000-01-09277790 [Jul 15 13:27:30] DEBUG[19836] app_queue.c: Device 'SIP/acM1000' changed to state '4' (Invalid) but we don't care because they're not a member of any queue. [Jul 15 13:27:30] DEBUG[19797] devicestate.c: Changing state for SIP/acM1000-01-09277790 - state 4 (Invalid) [Jul 15 13:27:30] DEBUG[19797] devicestate.c: No provider found, checking channel drivers for SIP - acM1000-01 [Jul 15 13:27:30] DEBUG[19797] chan_sip.c: Checking device state for peer acM1000-01 [Jul 15 13:27:30] DEBUG[19797] devicestate.c: Changing state for SIP/acM1000-01 - state 1 (Not in use) [Jul 15 13:27:30] DEBUG[19836] app_queue.c: Device 'SIP/acM1000-01-09277790' changed to state '4' (Invalid) but we don't care because they're not a member of any queue. [Jul 15 13:27:30] DEBUG[19836] app_queue.c: Device 'SIP/acM1000-01' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Jul 15 13:27:30] VERBOSE[19834] logger.c: <--- SIP read from 192.168.161.4:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.161.100:5060;branch=z9hG4bK1b1509de;rport From: ;tag=as11bc3276 To: "R&D 1" ;tag=1c845315586 Call-ID: 8453148291572008132727@192.168.161.4 CSeq: 103 BYE Contact: Supported: em,timer,replaces,path,early-session,resource-priority Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE Server: acM1000-01/v.5.20A.032.001 Content-Length: 0 <-------------> [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 0: SIP/2.0 200 OK (14) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.161.100:5060;branch=z9hG4bK1b1509de;rport (66) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 2: From: ;tag=as11bc3276 (57) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 3: To: "R&D 1" ;tag=1c845315586 (53) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 4: Call-ID: 8453148291572008132727@192.168.161.4 (45) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 5: CSeq: 103 BYE (13) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 6: Contact: (39) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 7: Supported: em,timer,replaces,path,early-session,resource-priority (65) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 8: Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE (86) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 9: Server: acM1000-01/v.5.20A.032.001 (34) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 10: Content-Length: 0 (17) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 11: (0) [Jul 15 13:27:30] VERBOSE[19834] logger.c: --- (11 headers 0 lines) --- [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: = No match Their Call ID: 49899a0d74d45ac9143bcace5e16c126@pbx.example.net Their Tag ookgb4qgqm Our tag: as041cea96 [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: = Found Their Call ID: 8453148291572008132727@192.168.161.4 Their Tag 1c845315586 Our tag: as11bc3276 [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #212 [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Stopping retransmission on '8453148291572008132727@192.168.161.4' of Request 103: Match Found [Jul 15 13:27:30] VERBOSE[19834] logger.c: Really destroying SIP dialog '8453148291572008132727@192.168.161.4' Method: ACK [Jul 15 13:27:30] VERBOSE[19834] logger.c: <--- SIP read from 192.168.161.216:5060 ---> SIP/2.0 200 Ok Via: SIP/2.0/UDP 192.168.161.100:5060;branch=z9hG4bK69f8a1a3;rport=5060 From: "R&D 1" ;tag=as041cea96 To: ;tag=ookgb4qgqm Call-ID: 49899a0d74d45ac9143bcace5e16c126@pbx.example.net CSeq: 103 INVITE Contact: ;flow-id=1 User-Agent: snom320/7.1.33 Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO Allow-Events: talk, hold, refer, call-info Supported: timer, 100rel, replaces, from-change Content-Type: application/sdp Content-Length: 226 v=0 o=root 563802528 563802530 IN IP4 192.168.161.216 s=call c=IN IP4 192.168.161.216 t=0 0 m=audio 10030 RTP/AVP 18 101 a=rtpmap:18 g729/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=sendrecv <-------------> [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 0: SIP/2.0 200 Ok (14) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.161.100:5060;branch=z9hG4bK69f8a1a3;rport=5060 (71) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 2: From: "R&D 1" ;tag=as041cea96 (54) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 3: To: ;tag=ookgb4qgqm (49) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 4: Call-ID: 49899a0d74d45ac9143bcace5e16c126@pbx.example.net (57) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 5: CSeq: 103 INVITE (16) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 6: Contact: ;flow-id=1 (49) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 7: User-Agent: snom320/7.1.33 (26) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 8: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO (88) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 9: Allow-Events: talk, hold, refer, call-info (42) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 10: Supported: timer, 100rel, replaces, from-change (47) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 11: Content-Type: application/sdp (29) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 12: Content-Length: 226 (19) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 13: (0) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Line: v=0 (3) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Line: o=root 563802528 563802530 IN IP4 192.168.161.216 (49) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Line: s=call (6) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Line: c=IN IP4 192.168.161.216 (24) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Line: t=0 0 (5) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Line: m=audio 10030 RTP/AVP 18 101 (28) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Line: a=rtpmap:18 g729/8000 (21) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Line: a=fmtp:101 0-16 (15) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Line: a=ptime:20 (10) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Line: a=sendrecv (10) [Jul 15 13:27:30] VERBOSE[19834] logger.c: --- (13 headers 11 lines) --- [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: = Found Their Call ID: 49899a0d74d45ac9143bcace5e16c126@pbx.example.net Their Tag ookgb4qgqm Our tag: as041cea96 [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Acked pending invite 103 [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #206 [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Stopping retransmission on '49899a0d74d45ac9143bcace5e16c126@pbx.example.net' of Request 103: Match Found [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: SIP response 200 to standard invite [Jul 15 13:27:30] VERBOSE[19834] logger.c: Found RTP audio format 18 [Jul 15 13:27:30] VERBOSE[19834] logger.c: Found RTP audio format 101 [Jul 15 13:27:30] VERBOSE[19834] logger.c: Peer audio RTP is at port 192.168.161.216:10030 [Jul 15 13:27:30] VERBOSE[19834] logger.c: Found audio description format g729 for ID 18 [Jul 15 13:27:30] VERBOSE[19834] logger.c: Found audio description format telephone-event for ID 101 [Jul 15 13:27:30] VERBOSE[19834] logger.c: Got unsupported a:fmtp in SDP offer [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: T38 state changed to 0 on channel [Jul 15 13:27:30] VERBOSE[19834] logger.c: Capabilities: us - 0x100 (g729), peer - audio=0x100 (g729)/video=0x0 (nothing), combined - 0x100 (g729) [Jul 15 13:27:30] VERBOSE[19834] logger.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) [Jul 15 13:27:30] VERBOSE[19834] logger.c: Peer audio RTP is at port 192.168.161.216:10030 [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: We're settling with these formats: 0x100 (g729) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Updating call counter for outgoing call [Jul 15 13:27:30] DEBUG[19834] devicestate.c: Notification of state change to be queued on device/channel SIP/400 [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: build_route: Retaining previous route: [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Strict routing enforced for session 49899a0d74d45ac9143bcace5e16c126@pbx.example.net [Jul 15 13:27:30] VERBOSE[19834] logger.c: set_destination: Parsing for address/port to send to [Jul 15 13:27:30] VERBOSE[19834] logger.c: set_destination: set destination to 192.168.161.216, port 5060 [Jul 15 13:27:30] VERBOSE[19834] logger.c: Transmitting (no NAT) to 192.168.161.216:5060: ACK sip:400@192.168.161.216:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.161.100:5060;branch=z9hG4bK7535fa08;rport From: "R&D 1" ;tag=as041cea96 To: ;tag=ookgb4qgqm Contact: Call-ID: 49899a0d74d45ac9143bcace5e16c126@pbx.example.net CSeq: 103 ACK User-Agent: atCOM PBX Max-Forwards: 70 Remote-Party-ID: "R&D 1" ;privacy=off;screen=no Content-Length: 0 --- [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Strict routing enforced for session 49899a0d74d45ac9143bcace5e16c126@pbx.example.net [Jul 15 13:27:30] VERBOSE[19834] logger.c: set_destination: Parsing for address/port to send to [Jul 15 13:27:30] VERBOSE[19834] logger.c: set_destination: set destination to 192.168.161.216, port 5060 [Jul 15 13:27:30] VERBOSE[19834] logger.c: Reliably Transmitting (no NAT) to 192.168.161.216:5060: BYE sip:400@192.168.161.216:5060 SIP/2.0 Via: SIP/2.0/UDP 192.168.161.100:5060;branch=z9hG4bK174a0d30;rport From: "R&D 1" ;tag=as041cea96 To: ;tag=ookgb4qgqm Call-ID: 49899a0d74d45ac9143bcace5e16c126@pbx.example.net CSeq: 104 BYE User-Agent: atCOM PBX Max-Forwards: 70 Remote-Party-ID: "R&D 1" ;privacy=off;screen=no Content-Length: 0 --- [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: *** SIP TIMER: Initializing retransmit timer on packet: Id #-1 [Jul 15 13:27:30] VERBOSE[19834] logger.c: Scheduling destruction of SIP dialog '49899a0d74d45ac9143bcace5e16c126@pbx.example.net' in 32000 ms (Method: INVITE) [Jul 15 13:27:30] DEBUG[19797] devicestate.c: No provider found, checking channel drivers for SIP - 400 [Jul 15 13:27:30] DEBUG[19797] chan_sip.c: Checking device state for peer 400 [Jul 15 13:27:30] DEBUG[19797] devicestate.c: Changing state for SIP/400 - state 1 (Not in use) [Jul 15 13:27:30] DEBUG[19797] devicestate.c: No provider found, checking channel drivers for SIP - 400 [Jul 15 13:27:30] DEBUG[19797] chan_sip.c: Checking device state for peer 400 [Jul 15 13:27:30] DEBUG[19836] app_queue.c: Device 'SIP/400' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Jul 15 13:27:30] VERBOSE[19834] logger.c: <--- SIP read from 192.168.161.216:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.161.100:5060;branch=z9hG4bK174a0d30;rport=5060 From: "R&D 1" ;tag=as041cea96 To: ;tag=ookgb4qgqm Call-ID: 49899a0d74d45ac9143bcace5e16c126@pbx.example.net CSeq: 104 BYE Contact: ;flow-id=1 User-Agent: snom320/7.1.33 RTP-RxStat: Total_Rx_Pkts=1,Rx_Pkts=1,Rx_Pkts_Lost=0,Remote_Rx_Pkts_Lost=0 RTP-TxStat: Total_Tx_Pkts=8,Tx_Pkts=8,Remote_Tx_Pkts=0 Content-Length: 0 <-------------> [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 0: SIP/2.0 200 OK (14) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.161.100:5060;branch=z9hG4bK174a0d30;rport=5060 (71) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 2: From: "R&D 1" ;tag=as041cea96 (54) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 3: To: ;tag=ookgb4qgqm (49) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 4: Call-ID: 49899a0d74d45ac9143bcace5e16c126@pbx.example.net (57) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 5: CSeq: 104 BYE (13) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 6: Contact: ;flow-id=1 (49) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 7: User-Agent: snom320/7.1.33 (26) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 8: RTP-RxStat: Total_Rx_Pkts=1,Rx_Pkts=1,Rx_Pkts_Lost=0,Remote_Rx_Pkts_Lost=0 (74) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 9: RTP-TxStat: Total_Tx_Pkts=8,Tx_Pkts=8,Remote_Tx_Pkts=0 (54) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 10: Content-Length: 0 (17) [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Header 11: (0) [Jul 15 13:27:30] VERBOSE[19834] logger.c: --- (11 headers 0 lines) --- [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: = Found Their Call ID: 49899a0d74d45ac9143bcace5e16c126@pbx.example.net Their Tag ookgb4qgqm Our tag: as041cea96 [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #213 [Jul 15 13:27:30] DEBUG[19834] chan_sip.c: Stopping retransmission on '49899a0d74d45ac9143bcace5e16c126@pbx.example.net' of Request 104: Match Found [Jul 15 13:27:30] VERBOSE[19834] logger.c: Really destroying SIP dialog '49899a0d74d45ac9143bcace5e16c126@pbx.example.net' Method: INVITE [Jul 15 13:27:36] VERBOSE[19834] logger.c: <--- SIP read from 192.168.161.237:5060 ---> REGISTER sip:pbx.example.net SIP/2.0 Via: SIP/2.0/UDP 192.168.161.237;branch=z9hG4bKac1243533071 Max-Forwards: 70 From: ;tag=1c1243529716 To: Call-ID: 4743305952942008195958@192.168.161.237 CSeq: 147248 REGISTER Contact: ;expires=180 Supported: em,timer,replaces,path,resource-priority Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE Expires: 180 User-Agent: acMP114-01/v.5.20A.032.001 Content-Length: 0 <-------------> [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 0: REGISTER sip:pbx.example.net SIP/2.0 (36) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.161.237;branch=z9hG4bKac1243533071 (59) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 2: Max-Forwards: 70 (16) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 3: From: ;tag=1c1243529716 (48) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 4: To: (29) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 5: Call-ID: 4743305952942008195958@192.168.161.237 (47) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 6: CSeq: 147248 REGISTER (21) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 7: Contact: ;expires=180 (46) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 8: Supported: em,timer,replaces,path,resource-priority (51) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 9: Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE (86) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 10: Expires: 180 (12) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 11: User-Agent: acMP114-01/v.5.20A.032.001 (38) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 12: Content-Length: 0 (17) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 13: (0) [Jul 15 13:27:36] VERBOSE[19834] logger.c: --- (13 headers 0 lines) --- [Jul 15 13:27:36] DEBUG[19834] acl.c: ##### Testing 192.168.161.237 with 192.168.161.0 [Jul 15 13:27:36] DEBUG[19834] acl.c: ##### Testing 192.168.161.237 with 192.168.200.0 [Jul 15 13:27:36] DEBUG[19834] acl.c: ##### Testing 192.168.161.237 with 192.168.1.0 [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Allocating new SIP dialog for 4743305952942008195958@192.168.161.237 - REGISTER (No RTP) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: **** Received REGISTER (2) - Command in SIP REGISTER [Jul 15 13:27:36] VERBOSE[19834] logger.c: Using latest REGISTER request as basis request [Jul 15 13:27:36] VERBOSE[19834] logger.c: Sending to 192.168.161.237 : 5060 (no NAT) [Jul 15 13:27:36] VERBOSE[19834] logger.c: <--- Transmitting (no NAT) to 192.168.161.237:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.161.237;branch=z9hG4bKac1243533071;received=192.168.161.237 From: ;tag=1c1243529716 To: Call-ID: 4743305952942008195958@192.168.161.237 CSeq: 147248 REGISTER User-Agent: atCOM PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <------------> [Jul 15 13:27:36] VERBOSE[19834] logger.c: <--- Transmitting (no NAT) to 192.168.161.237:5060 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 192.168.161.237;branch=z9hG4bKac1243533071;received=192.168.161.237 From: ;tag=1c1243529716 To: ;tag=as10615313 Call-ID: 4743305952942008195958@192.168.161.237 CSeq: 147248 REGISTER User-Agent: atCOM PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces WWW-Authenticate: Digest algorithm=MD5, realm="siprealm", nonce="2d7c4b3b" Content-Length: 0 <------------> [Jul 15 13:27:36] VERBOSE[19834] logger.c: Scheduling destruction of SIP dialog '4743305952942008195958@192.168.161.237' in 32000 ms (Method: REGISTER) [Jul 15 13:27:36] VERBOSE[19834] logger.c: <--- SIP read from 192.168.161.237:5060 ---> REGISTER sip:pbx.example.net SIP/2.0 Via: SIP/2.0/UDP 192.168.161.237;branch=z9hG4bKac1243595787 Max-Forwards: 70 From: ;tag=1c1243592370 To: Call-ID: 4743312262942008195958@192.168.161.237 CSeq: 147248 REGISTER Contact: ;expires=180 Supported: em,timer,replaces,path,resource-priority Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE Expires: 180 User-Agent: acMP114-01/v.5.20A.032.001 Content-Length: 0 <-------------> [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 0: REGISTER sip:pbx.example.net SIP/2.0 (36) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.161.237;branch=z9hG4bKac1243595787 (59) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 2: Max-Forwards: 70 (16) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 3: From: ;tag=1c1243592370 (48) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 4: To: (29) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 5: Call-ID: 4743312262942008195958@192.168.161.237 (47) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 6: CSeq: 147248 REGISTER (21) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 7: Contact: ;expires=180 (46) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 8: Supported: em,timer,replaces,path,resource-priority (51) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 9: Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE (86) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 10: Expires: 180 (12) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 11: User-Agent: acMP114-01/v.5.20A.032.001 (38) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 12: Content-Length: 0 (17) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 13: (0) [Jul 15 13:27:36] VERBOSE[19834] logger.c: --- (13 headers 0 lines) --- [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: = No match Their Call ID: 4743305952942008195958@192.168.161.237 Their Tag 1c1243529716 Our tag: as10615313 [Jul 15 13:27:36] DEBUG[19834] acl.c: ##### Testing 192.168.161.237 with 192.168.161.0 [Jul 15 13:27:36] DEBUG[19834] acl.c: ##### Testing 192.168.161.237 with 192.168.200.0 [Jul 15 13:27:36] DEBUG[19834] acl.c: ##### Testing 192.168.161.237 with 192.168.1.0 [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Allocating new SIP dialog for 4743312262942008195958@192.168.161.237 - REGISTER (No RTP) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: **** Received REGISTER (2) - Command in SIP REGISTER [Jul 15 13:27:36] VERBOSE[19834] logger.c: Using latest REGISTER request as basis request [Jul 15 13:27:36] VERBOSE[19834] logger.c: Sending to 192.168.161.237 : 5060 (no NAT) [Jul 15 13:27:36] VERBOSE[19834] logger.c: <--- Transmitting (no NAT) to 192.168.161.237:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.161.237;branch=z9hG4bKac1243595787;received=192.168.161.237 From: ;tag=1c1243592370 To: Call-ID: 4743312262942008195958@192.168.161.237 CSeq: 147248 REGISTER User-Agent: atCOM PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <------------> [Jul 15 13:27:36] VERBOSE[19834] logger.c: <--- Transmitting (no NAT) to 192.168.161.237:5060 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 192.168.161.237;branch=z9hG4bKac1243595787;received=192.168.161.237 From: ;tag=1c1243592370 To: ;tag=as1ec92f9f Call-ID: 4743312262942008195958@192.168.161.237 CSeq: 147248 REGISTER User-Agent: atCOM PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces WWW-Authenticate: Digest algorithm=MD5, realm="siprealm", nonce="4d5e5149" Content-Length: 0 <------------> [Jul 15 13:27:36] VERBOSE[19834] logger.c: Scheduling destruction of SIP dialog '4743312262942008195958@192.168.161.237' in 32000 ms (Method: REGISTER) [Jul 15 13:27:36] VERBOSE[19834] logger.c: <--- SIP read from 192.168.161.237:5060 ---> REGISTER sip:pbx.example.net SIP/2.0 Via: SIP/2.0/UDP 192.168.161.237;branch=z9hG4bKac1243614681 Max-Forwards: 70 From: ;tag=1c1243611227 To: Call-ID: 4743318622942008195958@192.168.161.237 CSeq: 147248 REGISTER Contact: ;expires=180 Supported: em,timer,replaces,path,resource-priority Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE Expires: 180 User-Agent: acMP114-01/v.5.20A.032.001 Content-Length: 0 <-------------> [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 0: REGISTER sip:pbx.example.net SIP/2.0 (36) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.161.237;branch=z9hG4bKac1243614681 (59) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 2: Max-Forwards: 70 (16) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 3: From: ;tag=1c1243611227 (48) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 4: To: (29) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 5: Call-ID: 4743318622942008195958@192.168.161.237 (47) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 6: CSeq: 147248 REGISTER (21) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 7: Contact: ;expires=180 (46) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 8: Supported: em,timer,replaces,path,resource-priority (51) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 9: Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE (86) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 10: Expires: 180 (12) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 11: User-Agent: acMP114-01/v.5.20A.032.001 (38) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 12: Content-Length: 0 (17) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 13: (0) [Jul 15 13:27:36] VERBOSE[19834] logger.c: --- (13 headers 0 lines) --- [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: = No match Their Call ID: 4743312262942008195958@192.168.161.237 Their Tag 1c1243592370 Our tag: as1ec92f9f [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: = No match Their Call ID: 4743305952942008195958@192.168.161.237 Their Tag 1c1243529716 Our tag: as10615313 [Jul 15 13:27:36] DEBUG[19834] acl.c: ##### Testing 192.168.161.237 with 192.168.161.0 [Jul 15 13:27:36] DEBUG[19834] acl.c: ##### Testing 192.168.161.237 with 192.168.200.0 [Jul 15 13:27:36] DEBUG[19834] acl.c: ##### Testing 192.168.161.237 with 192.168.1.0 [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Allocating new SIP dialog for 4743318622942008195958@192.168.161.237 - REGISTER (No RTP) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: **** Received REGISTER (2) - Command in SIP REGISTER [Jul 15 13:27:36] VERBOSE[19834] logger.c: Using latest REGISTER request as basis request [Jul 15 13:27:36] VERBOSE[19834] logger.c: Sending to 192.168.161.237 : 5060 (no NAT) [Jul 15 13:27:36] VERBOSE[19834] logger.c: <--- Transmitting (no NAT) to 192.168.161.237:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.161.237;branch=z9hG4bKac1243614681;received=192.168.161.237 From: ;tag=1c1243611227 To: Call-ID: 4743318622942008195958@192.168.161.237 CSeq: 147248 REGISTER User-Agent: atCOM PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <------------> [Jul 15 13:27:36] VERBOSE[19834] logger.c: <--- Transmitting (no NAT) to 192.168.161.237:5060 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 192.168.161.237;branch=z9hG4bKac1243614681;received=192.168.161.237 From: ;tag=1c1243611227 To: ;tag=as4d7ab1d6 Call-ID: 4743318622942008195958@192.168.161.237 CSeq: 147248 REGISTER User-Agent: atCOM PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces WWW-Authenticate: Digest algorithm=MD5, realm="siprealm", nonce="0c73b721" Content-Length: 0 <------------> [Jul 15 13:27:36] VERBOSE[19834] logger.c: Scheduling destruction of SIP dialog '4743318622942008195958@192.168.161.237' in 32000 ms (Method: REGISTER) [Jul 15 13:27:36] VERBOSE[19834] logger.c: <--- SIP read from 192.168.161.237:5060 ---> REGISTER sip:pbx.example.net SIP/2.0 Via: SIP/2.0/UDP 192.168.161.237;branch=z9hG4bKac1243628937 Max-Forwards: 70 From: ;tag=1c1243529716 To: Call-ID: 4743305952942008195958@192.168.161.237 CSeq: 147249 REGISTER Authorization: Digest username="103",realm="siprealm",nonce="2d7c4b3b",uri="sip:pbx.example.net",algorithm=MD5,response="0feeedb6d16019941e90d3ed16bccd13" Contact: ;expires=180 Supported: em,timer,replaces,path,resource-priority Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE Expires: 180 User-Agent: acMP114-01/v.5.20A.032.001 Content-Length: 0 <-------------> [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 0: REGISTER sip:pbx.example.net SIP/2.0 (36) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.161.237;branch=z9hG4bKac1243628937 (59) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 2: Max-Forwards: 70 (16) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 3: From: ;tag=1c1243529716 (48) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 4: To: (29) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 5: Call-ID: 4743305952942008195958@192.168.161.237 (47) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 6: CSeq: 147249 REGISTER (21) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 7: Authorization: Digest username="103",realm="siprealm",nonce="2d7c4b3b",uri="sip:pbx.example.net",algorithm=MD5,response="0feeedb6d16019941e90d3ed16bccd13" (154) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 8: Contact: ;expires=180 (46) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 9: Supported: em,timer,replaces,path,resource-priority (51) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 10: Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE (86) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 11: Expires: 180 (12) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 12: User-Agent: acMP114-01/v.5.20A.032.001 (38) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 13: Content-Length: 0 (17) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 14: (0) [Jul 15 13:27:36] VERBOSE[19834] logger.c: --- (14 headers 0 lines) --- [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: = No match Their Call ID: 4743318622942008195958@192.168.161.237 Their Tag 1c1243611227 Our tag: as4d7ab1d6 [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: = No match Their Call ID: 4743312262942008195958@192.168.161.237 Their Tag 1c1243592370 Our tag: as1ec92f9f [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: = Found Their Call ID: 4743305952942008195958@192.168.161.237 Their Tag 1c1243529716 Our tag: as10615313 [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: **** Received REGISTER (2) - Command in SIP REGISTER [Jul 15 13:27:36] VERBOSE[19834] logger.c: Using latest REGISTER request as basis request [Jul 15 13:27:36] VERBOSE[19834] logger.c: Sending to 192.168.161.237 : 5060 (no NAT) [Jul 15 13:27:36] VERBOSE[19834] logger.c: <--- Transmitting (no NAT) to 192.168.161.237:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.161.237;branch=z9hG4bKac1243628937;received=192.168.161.237 From: ;tag=1c1243529716 To: Call-ID: 4743305952942008195958@192.168.161.237 CSeq: 147249 REGISTER User-Agent: atCOM PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <------------> [Jul 15 13:27:36] VERBOSE[19834] logger.c: <--- Transmitting (no NAT) to 192.168.161.237:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.161.237;branch=z9hG4bKac1243628937;received=192.168.161.237 From: ;tag=1c1243529716 To: ;tag=as10615313 Call-ID: 4743305952942008195958@192.168.161.237 CSeq: 147249 REGISTER User-Agent: atCOM PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Expires: 180 Contact: ;expires=180 Date: Tue, 15 Jul 2008 11:27:36 GMT Content-Length: 0 <------------> [Jul 15 13:27:36] DEBUG[19834] devicestate.c: Notification of state change to be queued on device/channel SIP/103 [Jul 15 13:27:36] VERBOSE[19834] logger.c: Scheduling destruction of SIP dialog '4743305952942008195958@192.168.161.237' in 32000 ms (Method: REGISTER) [Jul 15 13:27:36] VERBOSE[19834] logger.c: <--- SIP read from 192.168.161.237:5060 ---> REGISTER sip:pbx.example.net SIP/2.0 Via: SIP/2.0/UDP 192.168.161.237;branch=z9hG4bKac1243643290 Max-Forwards: 70 From: ;tag=1c1243639925 To: Call-ID: 4743299462942008195958@192.168.161.237 CSeq: 147248 REGISTER Contact: ;expires=180 Supported: em,timer,replaces,path,resource-priority Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE Expires: 180 User-Agent: acMP114-01/v.5.20A.032.001 Content-Length: 0 <-------------> [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 0: REGISTER sip:pbx.example.net SIP/2.0 (36) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.161.237;branch=z9hG4bKac1243643290 (59) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 2: Max-Forwards: 70 (16) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 3: From: ;tag=1c1243639925 (48) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 4: To: (29) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 5: Call-ID: 4743299462942008195958@192.168.161.237 (47) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 6: CSeq: 147248 REGISTER (21) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 7: Contact: ;expires=180 (46) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 8: Supported: em,timer,replaces,path,resource-priority (51) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 9: Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE (86) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 10: Expires: 180 (12) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 11: User-Agent: acMP114-01/v.5.20A.032.001 (38) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 12: Content-Length: 0 (17) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 13: (0) [Jul 15 13:27:36] VERBOSE[19834] logger.c: --- (13 headers 0 lines) --- [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: = No match Their Call ID: 4743318622942008195958@192.168.161.237 Their Tag 1c1243611227 Our tag: as4d7ab1d6 [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: = No match Their Call ID: 4743312262942008195958@192.168.161.237 Their Tag 1c1243592370 Our tag: as1ec92f9f [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: = No match Their Call ID: 4743305952942008195958@192.168.161.237 Their Tag 1c1243529716 Our tag: as10615313 [Jul 15 13:27:36] DEBUG[19834] acl.c: ##### Testing 192.168.161.237 with 192.168.161.0 [Jul 15 13:27:36] DEBUG[19834] acl.c: ##### Testing 192.168.161.237 with 192.168.200.0 [Jul 15 13:27:36] DEBUG[19834] acl.c: ##### Testing 192.168.161.237 with 192.168.1.0 [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Allocating new SIP dialog for 4743299462942008195958@192.168.161.237 - REGISTER (No RTP) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: **** Received REGISTER (2) - Command in SIP REGISTER [Jul 15 13:27:36] VERBOSE[19834] logger.c: Using latest REGISTER request as basis request [Jul 15 13:27:36] VERBOSE[19834] logger.c: Sending to 192.168.161.237 : 5060 (no NAT) [Jul 15 13:27:36] VERBOSE[19834] logger.c: <--- Transmitting (no NAT) to 192.168.161.237:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.161.237;branch=z9hG4bKac1243643290;received=192.168.161.237 From: ;tag=1c1243639925 To: Call-ID: 4743299462942008195958@192.168.161.237 CSeq: 147248 REGISTER User-Agent: atCOM PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <------------> [Jul 15 13:27:36] VERBOSE[19834] logger.c: <--- Transmitting (no NAT) to 192.168.161.237:5060 ---> SIP/2.0 401 Unauthorized Via: SIP/2.0/UDP 192.168.161.237;branch=z9hG4bKac1243643290;received=192.168.161.237 From: ;tag=1c1243639925 To: ;tag=as37b7014b Call-ID: 4743299462942008195958@192.168.161.237 CSeq: 147248 REGISTER User-Agent: atCOM PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces WWW-Authenticate: Digest algorithm=MD5, realm="siprealm", nonce="59428590" Content-Length: 0 <------------> [Jul 15 13:27:36] VERBOSE[19834] logger.c: Scheduling destruction of SIP dialog '4743299462942008195958@192.168.161.237' in 32000 ms (Method: REGISTER) [Jul 15 13:27:36] DEBUG[19797] devicestate.c: No provider found, checking channel drivers for SIP - 103 [Jul 15 13:27:36] DEBUG[19797] chan_sip.c: Checking device state for peer 103 [Jul 15 13:27:36] DEBUG[19797] devicestate.c: Changing state for SIP/103 - state 1 (Not in use) [Jul 15 13:27:36] DEBUG[19797] devicestate.c: No provider found, checking channel drivers for SIP - 103 [Jul 15 13:27:36] DEBUG[19797] chan_sip.c: Checking device state for peer 103 [Jul 15 13:27:36] DEBUG[19836] app_queue.c: Device 'SIP/103' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Jul 15 13:27:36] VERBOSE[19834] logger.c: <--- SIP read from 192.168.161.237:5060 ---> REGISTER sip:pbx.example.net SIP/2.0 Via: SIP/2.0/UDP 192.168.161.237;branch=z9hG4bKac1243668307 Max-Forwards: 70 From: ;tag=1c1243592370 To: Call-ID: 4743312262942008195958@192.168.161.237 CSeq: 147249 REGISTER Authorization: Digest username="102",realm="siprealm",nonce="4d5e5149",uri="sip:pbx.example.net",algorithm=MD5,response="277715a1c075fa4b90e69c6891366cf9" Contact: ;expires=180 Supported: em,timer,replaces,path,resource-priority Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE Expires: 180 User-Agent: acMP114-01/v.5.20A.032.001 Content-Length: 0 <-------------> [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 0: REGISTER sip:pbx.example.net SIP/2.0 (36) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.161.237;branch=z9hG4bKac1243668307 (59) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 2: Max-Forwards: 70 (16) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 3: From: ;tag=1c1243592370 (48) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 4: To: (29) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 5: Call-ID: 4743312262942008195958@192.168.161.237 (47) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 6: CSeq: 147249 REGISTER (21) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 7: Authorization: Digest username="102",realm="siprealm",nonce="4d5e5149",uri="sip:pbx.example.net",algorithm=MD5,response="277715a1c075fa4b90e69c6891366cf9" (154) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 8: Contact: ;expires=180 (46) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 9: Supported: em,timer,replaces,path,resource-priority (51) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 10: Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE (86) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 11: Expires: 180 (12) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 12: User-Agent: acMP114-01/v.5.20A.032.001 (38) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 13: Content-Length: 0 (17) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 14: (0) [Jul 15 13:27:36] VERBOSE[19834] logger.c: --- (14 headers 0 lines) --- [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: = No match Their Call ID: 4743299462942008195958@192.168.161.237 Their Tag 1c1243639925 Our tag: as37b7014b [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: = No match Their Call ID: 4743318622942008195958@192.168.161.237 Their Tag 1c1243611227 Our tag: as4d7ab1d6 [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: = Found Their Call ID: 4743312262942008195958@192.168.161.237 Their Tag 1c1243592370 Our tag: as1ec92f9f [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: **** Received REGISTER (2) - Command in SIP REGISTER [Jul 15 13:27:36] VERBOSE[19834] logger.c: Using latest REGISTER request as basis request [Jul 15 13:27:36] VERBOSE[19834] logger.c: Sending to 192.168.161.237 : 5060 (no NAT) [Jul 15 13:27:36] VERBOSE[19834] logger.c: <--- Transmitting (no NAT) to 192.168.161.237:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.161.237;branch=z9hG4bKac1243668307;received=192.168.161.237 From: ;tag=1c1243592370 To: Call-ID: 4743312262942008195958@192.168.161.237 CSeq: 147249 REGISTER User-Agent: atCOM PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <------------> [Jul 15 13:27:36] VERBOSE[19834] logger.c: <--- Transmitting (no NAT) to 192.168.161.237:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.161.237;branch=z9hG4bKac1243668307;received=192.168.161.237 From: ;tag=1c1243592370 To: ;tag=as1ec92f9f Call-ID: 4743312262942008195958@192.168.161.237 CSeq: 147249 REGISTER User-Agent: atCOM PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Expires: 180 Contact: ;expires=180 Date: Tue, 15 Jul 2008 11:27:36 GMT Content-Length: 0 <------------> [Jul 15 13:27:36] DEBUG[19834] devicestate.c: Notification of state change to be queued on device/channel SIP/102 [Jul 15 13:27:36] VERBOSE[19834] logger.c: Scheduling destruction of SIP dialog '4743312262942008195958@192.168.161.237' in 32000 ms (Method: REGISTER) [Jul 15 13:27:36] DEBUG[19797] devicestate.c: No provider found, checking channel drivers for SIP - 102 [Jul 15 13:27:36] DEBUG[19797] chan_sip.c: Checking device state for peer 102 [Jul 15 13:27:36] DEBUG[19797] devicestate.c: Changing state for SIP/102 - state 1 (Not in use) [Jul 15 13:27:36] DEBUG[19797] devicestate.c: No provider found, checking channel drivers for SIP - 102 [Jul 15 13:27:36] DEBUG[19797] chan_sip.c: Checking device state for peer 102 [Jul 15 13:27:36] DEBUG[19836] app_queue.c: Device 'SIP/102' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Jul 15 13:27:36] VERBOSE[19834] logger.c: <--- SIP read from 192.168.161.237:5060 ---> REGISTER sip:pbx.example.net SIP/2.0 Via: SIP/2.0/UDP 192.168.161.237;branch=z9hG4bKac1243693185 Max-Forwards: 70 From: ;tag=1c1243611227 To: Call-ID: 4743318622942008195958@192.168.161.237 CSeq: 147249 REGISTER Authorization: Digest username="101",realm="siprealm",nonce="0c73b721",uri="sip:pbx.example.net",algorithm=MD5,response="e55fe4b4e04833ca96ffc45a0d3212ad" Contact: ;expires=180 Supported: em,timer,replaces,path,resource-priority Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE Expires: 180 User-Agent: acMP114-01/v.5.20A.032.001 Content-Length: 0 <-------------> [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 0: REGISTER sip:pbx.example.net SIP/2.0 (36) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.161.237;branch=z9hG4bKac1243693185 (59) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 2: Max-Forwards: 70 (16) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 3: From: ;tag=1c1243611227 (48) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 4: To: (29) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 5: Call-ID: 4743318622942008195958@192.168.161.237 (47) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 6: CSeq: 147249 REGISTER (21) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 7: Authorization: Digest username="101",realm="siprealm",nonce="0c73b721",uri="sip:pbx.example.net",algorithm=MD5,response="e55fe4b4e04833ca96ffc45a0d3212ad" (154) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 8: Contact: ;expires=180 (46) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 9: Supported: em,timer,replaces,path,resource-priority (51) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 10: Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE (86) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 11: Expires: 180 (12) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 12: User-Agent: acMP114-01/v.5.20A.032.001 (38) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 13: Content-Length: 0 (17) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 14: (0) [Jul 15 13:27:36] VERBOSE[19834] logger.c: --- (14 headers 0 lines) --- [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: = No match Their Call ID: 4743299462942008195958@192.168.161.237 Their Tag 1c1243639925 Our tag: as37b7014b [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: = Found Their Call ID: 4743318622942008195958@192.168.161.237 Their Tag 1c1243611227 Our tag: as4d7ab1d6 [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: **** Received REGISTER (2) - Command in SIP REGISTER [Jul 15 13:27:36] VERBOSE[19834] logger.c: Using latest REGISTER request as basis request [Jul 15 13:27:36] VERBOSE[19834] logger.c: Sending to 192.168.161.237 : 5060 (no NAT) [Jul 15 13:27:36] VERBOSE[19834] logger.c: <--- Transmitting (no NAT) to 192.168.161.237:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.161.237;branch=z9hG4bKac1243693185;received=192.168.161.237 From: ;tag=1c1243611227 To: Call-ID: 4743318622942008195958@192.168.161.237 CSeq: 147249 REGISTER User-Agent: atCOM PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <------------> [Jul 15 13:27:36] VERBOSE[19834] logger.c: <--- Transmitting (no NAT) to 192.168.161.237:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.161.237;branch=z9hG4bKac1243693185;received=192.168.161.237 From: ;tag=1c1243611227 To: ;tag=as4d7ab1d6 Call-ID: 4743318622942008195958@192.168.161.237 CSeq: 147249 REGISTER User-Agent: atCOM PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Expires: 180 Contact: ;expires=180 Date: Tue, 15 Jul 2008 11:27:36 GMT Content-Length: 0 <------------> [Jul 15 13:27:36] DEBUG[19834] devicestate.c: Notification of state change to be queued on device/channel SIP/101 [Jul 15 13:27:36] VERBOSE[19834] logger.c: Scheduling destruction of SIP dialog '4743318622942008195958@192.168.161.237' in 32000 ms (Method: REGISTER) [Jul 15 13:27:36] DEBUG[19797] devicestate.c: No provider found, checking channel drivers for SIP - 101 [Jul 15 13:27:36] DEBUG[19797] chan_sip.c: Checking device state for peer 101 [Jul 15 13:27:36] DEBUG[19797] devicestate.c: Changing state for SIP/101 - state 1 (Not in use) [Jul 15 13:27:36] DEBUG[19836] app_queue.c: Device 'SIP/101' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Jul 15 13:27:36] VERBOSE[19834] logger.c: <--- SIP read from 192.168.161.237:5060 ---> REGISTER sip:pbx.example.net SIP/2.0 Via: SIP/2.0/UDP 192.168.161.237;branch=z9hG4bKac1243736872 Max-Forwards: 70 From: ;tag=1c1243639925 To: Call-ID: 4743299462942008195958@192.168.161.237 CSeq: 147249 REGISTER Authorization: Digest username="104",realm="siprealm",nonce="59428590",uri="sip:pbx.example.net",algorithm=MD5,response="7306589ff58595f9099efde74b75cbe0" Contact: ;expires=180 Supported: em,timer,replaces,path,resource-priority Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE Expires: 180 User-Agent: acMP114-01/v.5.20A.032.001 Content-Length: 0 <-------------> [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 0: REGISTER sip:pbx.example.net SIP/2.0 (36) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.161.237;branch=z9hG4bKac1243736872 (59) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 2: Max-Forwards: 70 (16) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 3: From: ;tag=1c1243639925 (48) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 4: To: (29) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 5: Call-ID: 4743299462942008195958@192.168.161.237 (47) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 6: CSeq: 147249 REGISTER (21) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 7: Authorization: Digest username="104",realm="siprealm",nonce="59428590",uri="sip:pbx.example.net",algorithm=MD5,response="7306589ff58595f9099efde74b75cbe0" (154) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 8: Contact: ;expires=180 (46) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 9: Supported: em,timer,replaces,path,resource-priority (51) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 10: Allow: REGISTER,OPTIONS,INVITE,ACK,CANCEL,BYE,NOTIFY,PRACK,REFER,INFO,SUBSCRIBE,UPDATE (86) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 11: Expires: 180 (12) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 12: User-Agent: acMP114-01/v.5.20A.032.001 (38) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 13: Content-Length: 0 (17) [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: Header 14: (0) [Jul 15 13:27:36] VERBOSE[19834] logger.c: --- (14 headers 0 lines) --- [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: = Found Their Call ID: 4743299462942008195958@192.168.161.237 Their Tag 1c1243639925 Our tag: as37b7014b [Jul 15 13:27:36] DEBUG[19834] chan_sip.c: **** Received REGISTER (2) - Command in SIP REGISTER [Jul 15 13:27:36] VERBOSE[19834] logger.c: Using latest REGISTER request as basis request [Jul 15 13:27:36] VERBOSE[19834] logger.c: Sending to 192.168.161.237 : 5060 (no NAT) [Jul 15 13:27:36] VERBOSE[19834] logger.c: <--- Transmitting (no NAT) to 192.168.161.237:5060 ---> SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.161.237;branch=z9hG4bKac1243736872;received=192.168.161.237 From: ;tag=1c1243639925 To: Call-ID: 4743299462942008195958@192.168.161.237 CSeq: 147249 REGISTER User-Agent: atCOM PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Contact: Content-Length: 0 <------------> [Jul 15 13:27:36] VERBOSE[19834] logger.c: <--- Transmitting (no NAT) to 192.168.161.237:5060 ---> SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.161.237;branch=z9hG4bKac1243736872;received=192.168.161.237 From: ;tag=1c1243639925 To: ;tag=as37b7014b Call-ID: 4743299462942008195958@192.168.161.237 CSeq: 147249 REGISTER User-Agent: atCOM PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Supported: replaces Expires: 180 Contact: ;expires=180 Date: Tue, 15 Jul 2008 11:27:36 GMT Content-Length: 0 <------------> [Jul 15 13:27:36] DEBUG[19834] devicestate.c: Notification of state change to be queued on device/channel SIP/104 [Jul 15 13:27:36] VERBOSE[19834] logger.c: Scheduling destruction of SIP dialog '4743299462942008195958@192.168.161.237' in 32000 ms (Method: REGISTER) [Jul 15 13:27:36] DEBUG[19797] devicestate.c: No provider found, checking channel drivers for SIP - 104 [Jul 15 13:27:36] DEBUG[19797] chan_sip.c: Checking device state for peer 104 [Jul 15 13:27:36] DEBUG[19797] devicestate.c: Changing state for SIP/104 - state 1 (Not in use) [Jul 15 13:27:36] DEBUG[19797] devicestate.c: No provider found, checking channel drivers for SIP - 104 [Jul 15 13:27:36] DEBUG[19797] chan_sip.c: Checking device state for peer 104 [Jul 15 13:27:36] DEBUG[19836] app_queue.c: Device 'SIP/104' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. [Jul 15 13:27:37] DEBUG[20290] manager.c: Manager received command 'login' [Jul 15 13:27:37] VERBOSE[20290] logger.c: == Parsing '/etc/asterisk/manager.conf': [Jul 15 13:27:37] DEBUG[20290] config.c: Parsing /etc/asterisk/manager.conf [Jul 15 13:27:37] VERBOSE[20290] logger.c: Found [Jul 15 13:27:37] VERBOSE[20290] logger.c: == Parsing '/etc/asterisk/settings/manager.conf': [Jul 15 13:27:37] DEBUG[20290] config.c: Parsing /etc/asterisk/settings/manager.conf [Jul 15 13:27:37] VERBOSE[20290] logger.c: Found [Jul 15 13:27:37] DEBUG[20290] acl.c: 0.0.0.0/0.0.0.0/0.0.0.0 appended to acl for peer [Jul 15 13:27:37] DEBUG[20290] acl.c: 127.0.0.1/255.255.255.255/255.255.255.255 appended to acl for peer [Jul 15 13:27:37] DEBUG[20290] acl.c: ##### Testing 127.0.0.1 with 0.0.0.0 [Jul 15 13:27:37] DEBUG[20290] acl.c: ##### Testing 127.0.0.1 with 127.0.0.1 [Jul 15 13:27:37] VERBOSE[20290] logger.c: == Manager 'lmt' logged on from 127.0.0.1 [Jul 15 13:27:37] DEBUG[20290] manager.c: Manager received command 'Command'