<-- SIP read from 192.168.0.131:18856: INVITE sip:874@192.168.0.8 SIP/2.0 Via: SIP/2.0/UDP 192.168.0.131:18856;branch=z9hG4bK-d87543-b36ca013ea15f607-1--d87543-;rport Max-Forwards: 70 Contact: To: "874" From: "Ronald Voermans";tag=5706bb26 Call-ID: 0d300a0d53359e6aYjllMDdiMDg1OGJhNzA5NWIwOGI5MjJhZDhhZGQ2ZmU. CSeq: 1 INVITE Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO Content-Type: application/sdp User-Agent: eyeBeam release 1003s stamp 31159 Content-Length: 497 v=0 o=- 6 2 IN IP4 192.168.0.131 s=CounterPath eyeBeam 1.5 c=IN IP4 192.168.0.131 t=0 0 m=audio 28066 RTP/AVP 107 100 106 6 0 105 18 3 5 101 a=alt:1 2 : Tc95JQs4 0/WsLIol 192.168.0.120 28066 a=alt:2 1 : xA/2MQMl vc1Lp2FG 192.168.0.131 28066 a=fmtp:18 annexb=no a=fmtp:101 0-15 a=rtpmap:107 BV32/16000 a=rtpmap:100 SPEEX/16000 a=rtpmap:106 SPEEX-FEC/16000 a=rtpmap:105 SPEEX-FEC/8000 a=rtpmap:101 telephone-event/8000 a=sendrecv a=x-rtp-session-id:6AF30F01A3894141A437C173A21BC41D Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 0: INVITE sip:874@192.168.0.8 SIP/2.0 (34) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.0.131:18856;branch=z9hG4bK-d87543-b36ca013ea15f607-1--d87543-;rport (92) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 2: Max-Forwards: 70 (16) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 3: Contact: (38) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 4: To: "874" (30) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 5: From: "Ronald Voermans";tag=5706bb26 (57) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 6: Call-ID: 0d300a0d53359e6aYjllMDdiMDg1OGJhNzA5NWIwOGI5MjJhZDhhZGQ2ZmU. (69) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 7: CSeq: 1 INVITE (14) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 8: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO (81) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 9: Content-Type: application/sdp (29) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 10: User-Agent: eyeBeam release 1003s stamp 31159 (45) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 11: Content-Length: 497 (19) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 12: (0) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Line: v=0 (3) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Line: o=- 6 2 IN IP4 192.168.0.131 (28) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Line: s=CounterPath eyeBeam 1.5 (25) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Line: c=IN IP4 192.168.0.131 (22) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Line: t=0 0 (5) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Line: m=audio 28066 RTP/AVP 107 100 106 6 0 105 18 3 5 101 (52) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Line: a=alt:1 2 : Tc95JQs4 0/WsLIol 192.168.0.120 28066 (49) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Line: a=alt:2 1 : xA/2MQMl vc1Lp2FG 192.168.0.131 28066 (49) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Line: a=fmtp:18 annexb=no (19) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Line: a=fmtp:101 0-15 (15) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Line: a=rtpmap:107 BV32/16000 (23) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Line: a=rtpmap:100 SPEEX/16000 (24) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Line: a=rtpmap:106 SPEEX-FEC/16000 (28) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Line: a=rtpmap:105 SPEEX-FEC/8000 (27) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Line: a=sendrecv (10) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Line: a=x-rtp-session-id:6AF30F01A3894141A437C173A21BC41D (51) Aug 9 14:27:17 VERBOSE[6438] logger.c: --- (12 headers 17 lines)Aug 9 14:27:17 VERBOSE[6438] logger.c: --- (12 headers 17 lines)--- Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Allocating new SIP dialog for 0d300a0d53359e6aYjllMDdiMDg1OGJhNzA5NWIwOGI5MjJhZDhhZGQ2ZmU. - INVITE (With RTP) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE Aug 9 14:27:17 VERBOSE[6438] logger.c: Using INVITE request as basis request - 0d300a0d53359e6aYjllMDdiMDg1OGJhNzA5NWIwOGI5MjJhZDhhZGQ2ZmU. Aug 9 14:27:17 VERBOSE[6438] logger.c: Sending to 192.168.0.131 : 18856 (NAT) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Setting NAT on RTP to 0 Aug 9 14:27:17 VERBOSE[6438] logger.c: Reliably Transmitting (no NAT) to 192.168.0.131:18856: SIP/2.0 407 Proxy Authentication Required Via: SIP/2.0/UDP 192.168.0.131:18856;branch=z9hG4bK-d87543-b36ca013ea15f607-1--d87543-;rport;received=192.168.0.131 From: "Ronald Voermans";tag=5706bb26 To: "874";tag=as356bfa3a Call-ID: 0d300a0d53359e6aYjllMDdiMDg1OGJhNzA5NWIwOGI5MjJhZDhhZGQ2ZmU. CSeq: 1 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Proxy-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="5c88a441" Content-Length: 0 --- Aug 9 14:27:17 DEBUG[6438] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #364671 Aug 9 14:27:17 VERBOSE[6438] logger.c: Scheduling destruction of call '0d300a0d53359e6aYjllMDdiMDg1OGJhNzA5NWIwOGI5MjJhZDhhZGQ2ZmU.' in 15000 ms Aug 9 14:27:17 VERBOSE[6438] logger.c: Found user '706' Aug 9 14:27:17 VERBOSE[6438] logger.c: <-- SIP read from 192.168.0.131:18856: ACK sip:874@192.168.0.8 SIP/2.0 Via: SIP/2.0/UDP 192.168.0.131:18856;branch=z9hG4bK-d87543-b36ca013ea15f607-1--d87543-;rport To: "874";tag=as356bfa3a From: "Ronald Voermans";tag=5706bb26 Call-ID: 0d300a0d53359e6aYjllMDdiMDg1OGJhNzA5NWIwOGI5MjJhZDhhZGQ2ZmU. CSeq: 1 ACK Content-Length: 0 Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 0: ACK sip:874@192.168.0.8 SIP/2.0 (31) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.0.131:18856;branch=z9hG4bK-d87543-b36ca013ea15f607-1--d87543-;rport (92) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 2: To: "874";tag=as356bfa3a (45) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 3: From: "Ronald Voermans";tag=5706bb26 (57) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 4: Call-ID: 0d300a0d53359e6aYjllMDdiMDg1OGJhNzA5NWIwOGI5MjJhZDhhZGQ2ZmU. (69) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 5: CSeq: 1 ACK (11) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 6: Content-Length: 0 (17) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 7: (0) Aug 9 14:27:17 VERBOSE[6438] logger.c: --- (7 headers 0 lines)Aug 9 14:27:17 VERBOSE[6438] logger.c: --- (7 headers 0 lines)--- Aug 9 14:27:17 DEBUG[6438] chan_sip.c: **** Received ACK (6) - Command in SIP ACK Aug 9 14:27:17 DEBUG[6438] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #364671 Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Stopping retransmission on '0d300a0d53359e6aYjllMDdiMDg1OGJhNzA5NWIwOGI5MjJhZDhhZGQ2ZmU.' of Response 1: Match Found Aug 9 14:27:17 VERBOSE[6438] logger.c: <-- SIP read from 192.168.0.131:18856: INVITE sip:874@192.168.0.8 SIP/2.0 Via: SIP/2.0/UDP 192.168.0.131:18856;branch=z9hG4bK-d87543-e17fbd168f49ae54-1--d87543-;rport Max-Forwards: 70 Contact: To: "874" From: "Ronald Voermans";tag=5706bb26 Call-ID: 0d300a0d53359e6aYjllMDdiMDg1OGJhNzA5NWIwOGI5MjJhZDhhZGQ2ZmU. CSeq: 2 INVITE Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO Content-Type: application/sdp Proxy-Authorization: Digest username="706",realm="asterisk",nonce="5c88a441",uri="sip:874@192.168.0.8",response="19cbd0fa7ac0f4a382b1856014e62043",algorithm=MD5 User-Agent: eyeBeam release 1003s stamp 31159 Content-Length: 497 v=0 o=- 6 2 IN IP4 192.168.0.131 s=CounterPath eyeBeam 1.5 c=IN IP4 192.168.0.131 t=0 0 m=audio 28066 RTP/AVP 107 100 106 6 0 105 18 3 5 101 a=alt:1 2 : Tc95JQs4 0/WsLIol 192.168.0.120 28066 a=alt:2 1 : xA/2MQMl vc1Lp2FG 192.168.0.131 28066 a=fmtp:18 annexb=no a=fmtp:101 0-15 a=rtpmap:107 BV32/16000 a=rtpmap:100 SPEEX/16000 a=rtpmap:106 SPEEX-FEC/16000 a=rtpmap:105 SPEEX-FEC/8000 a=rtpmap:101 telephone-event/8000 a=sendrecv a=x-rtp-session-id:6AF30F01A3894141A437C173A21BC41D Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 0: INVITE sip:874@192.168.0.8 SIP/2.0 (34) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.0.131:18856;branch=z9hG4bK-d87543-e17fbd168f49ae54-1--d87543-;rport (92) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 2: Max-Forwards: 70 (16) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 3: Contact: (38) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 4: To: "874" (30) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 5: From: "Ronald Voermans";tag=5706bb26 (57) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 6: Call-ID: 0d300a0d53359e6aYjllMDdiMDg1OGJhNzA5NWIwOGI5MjJhZDhhZGQ2ZmU. (69) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 7: CSeq: 2 INVITE (14) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 8: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO (81) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 9: Content-Type: application/sdp (29) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 10: Proxy-Authorization: Digest username="706",realm="asterisk",nonce="5c88a441",uri="sip:874@192.168.0.8",response="19cbd0fa7ac0f4a382b1856014e62043",algorithm=MD5 (160) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 11: User-Agent: eyeBeam release 1003s stamp 31159 (45) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 12: Content-Length: 497 (19) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 13: (0) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Line: v=0 (3) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Line: o=- 6 2 IN IP4 192.168.0.131 (28) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Line: s=CounterPath eyeBeam 1.5 (25) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Line: c=IN IP4 192.168.0.131 (22) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Line: t=0 0 (5) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Line: m=audio 28066 RTP/AVP 107 100 106 6 0 105 18 3 5 101 (52) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Line: a=alt:1 2 : Tc95JQs4 0/WsLIol 192.168.0.120 28066 (49) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Line: a=alt:2 1 : xA/2MQMl vc1Lp2FG 192.168.0.131 28066 (49) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Line: a=fmtp:18 annexb=no (19) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Line: a=fmtp:101 0-15 (15) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Line: a=rtpmap:107 BV32/16000 (23) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Line: a=rtpmap:100 SPEEX/16000 (24) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Line: a=rtpmap:106 SPEEX-FEC/16000 (28) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Line: a=rtpmap:105 SPEEX-FEC/8000 (27) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Line: a=sendrecv (10) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Line: a=x-rtp-session-id:6AF30F01A3894141A437C173A21BC41D (51) Aug 9 14:27:17 VERBOSE[6438] logger.c: --- (13 headers 17 lines)Aug 9 14:27:17 VERBOSE[6438] logger.c: --- (13 headers 17 lines)--- Aug 9 14:27:17 DEBUG[6438] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE Aug 9 14:27:17 VERBOSE[6438] logger.c: Using INVITE request as basis request - 0d300a0d53359e6aYjllMDdiMDg1OGJhNzA5NWIwOGI5MjJhZDhhZGQ2ZmU. Aug 9 14:27:17 VERBOSE[6438] logger.c: Sending to 192.168.0.131 : 18856 (NAT) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Setting NAT on RTP to 0 Aug 9 14:27:17 VERBOSE[6438] logger.c: Found user '706' Aug 9 14:27:17 VERBOSE[6438] logger.c: Found RTP audio format 107 Aug 9 14:27:17 VERBOSE[6438] logger.c: Found RTP audio format 100 Aug 9 14:27:17 VERBOSE[6438] logger.c: Found RTP audio format 106 Aug 9 14:27:17 VERBOSE[6438] logger.c: Found RTP audio format 6 Aug 9 14:27:17 VERBOSE[6438] logger.c: Found RTP audio format 0 Aug 9 14:27:17 VERBOSE[6438] logger.c: Found RTP audio format 105 Aug 9 14:27:17 VERBOSE[6438] logger.c: Found RTP audio format 18 Aug 9 14:27:17 VERBOSE[6438] logger.c: Found RTP audio format 3 Aug 9 14:27:17 VERBOSE[6438] logger.c: Found RTP audio format 5 Aug 9 14:27:17 VERBOSE[6438] logger.c: Found RTP audio format 101 Aug 9 14:27:17 VERBOSE[6438] logger.c: Peer audio RTP is at port 192.168.0.131:28066 Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Peer audio RTP is at port 192.168.0.131:28066 Aug 9 14:27:17 VERBOSE[6438] logger.c: Found description format BV32 Aug 9 14:27:17 VERBOSE[6438] logger.c: Found description format SPEEX Aug 9 14:27:17 VERBOSE[6438] logger.c: Found description format SPEEX-FEC Aug 9 14:27:17 VERBOSE[6438] logger.c: Found description format SPEEX-FEC Aug 9 14:27:17 VERBOSE[6438] logger.c: Found description format telephone-event Aug 9 14:27:17 VERBOSE[6438] logger.c: Capabilities: us - 0x100 (g729), peer - audio=0x326 (gsm|ulaw|adpcm|g729|speex)/video=0x0 (nothing), combined - 0x100 (g729) Aug 9 14:27:17 VERBOSE[6438] logger.c: Non-codec capabilities: us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Checking SIP call limits for device 706 Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Updating call counter for incoming call Aug 9 14:27:17 VERBOSE[6438] logger.c: Looking for 874 in from-internal (domain 192.168.0.8) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: build_route: Contact hop: Aug 9 14:27:17 VERBOSE[6438] logger.c: list_route: hop: Aug 9 14:27:17 VERBOSE[6438] logger.c: Transmitting (no NAT) to 192.168.0.131:18856: SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.0.131:18856;branch=z9hG4bK-d87543-e17fbd168f49ae54-1--d87543-;rport;received=192.168.0.131 From: "Ronald Voermans";tag=5706bb26 To: "874" Call-ID: 0d300a0d53359e6aYjllMDdiMDg1OGJhNzA5NWIwOGI5MjJhZDhhZGQ2ZmU. CSeq: 2 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Length: 0 --- Aug 9 14:27:17 DEBUG[6427] chan_sip.c: Checking device state for peer 706 Aug 9 14:27:17 DEBUG[6427] channel.c: Avoiding initial deadlock for 'SIP/706-08ae26b8' Aug 9 14:27:17 DEBUG[8110] pbx.c: Launching 'Macro' Aug 9 14:27:17 VERBOSE[8110] logger.c: -- Executing Macro("SIP/706-08ae26b8", "exten-vm|novm|874") in new stack Aug 9 14:27:17 DEBUG[8110] pbx.c: Launching 'Macro' Aug 9 14:27:17 VERBOSE[8110] logger.c: -- Executing Macro("SIP/706-08ae26b8", "user-callerid") in new stack Aug 9 14:27:17 DEBUG[8110] pbx.c: Expression result is '0' Aug 9 14:27:17 DEBUG[8110] pbx.c: Launching 'GotoIf' Aug 9 14:27:17 VERBOSE[8110] logger.c: -- Executing GotoIf("SIP/706-08ae26b8", "0?report") in new stack Aug 9 14:27:17 DEBUG[8110] pbx.c: Not taking any branch Aug 9 14:27:17 DEBUG[8110] pbx.c: Expression result is '0' Aug 9 14:27:17 DEBUG[8110] pbx.c: Launching 'GotoIf' Aug 9 14:27:17 VERBOSE[8110] logger.c: -- Executing GotoIf("SIP/706-08ae26b8", "0?start") in new stack Aug 9 14:27:17 DEBUG[8110] pbx.c: Not taking any branch Aug 9 14:27:17 DEBUG[8110] pbx.c: Function result is '706' Aug 9 14:27:17 DEBUG[8110] pbx.c: Launching 'Set' Aug 9 14:27:17 VERBOSE[8110] logger.c: -- Executing Set("SIP/706-08ae26b8", "REALCALLERIDNUM=706") in new stack Aug 9 14:27:17 DEBUG[8110] pbx.c: Launching 'NoOp' Aug 9 14:27:17 VERBOSE[8110] logger.c: -- Executing NoOp("SIP/706-08ae26b8", "REALCALLERIDNUM is 706") in new stack Aug 9 14:27:17 DEBUG[8110] pbx.c: Function result is '706' Aug 9 14:27:17 DEBUG[8110] pbx.c: Launching 'Set' Aug 9 14:27:17 VERBOSE[8110] logger.c: -- Executing Set("SIP/706-08ae26b8", "AMPUSER=706") in new stack Aug 9 14:27:17 DEBUG[8110] pbx.c: Function result is 'Ronald SoftPhone' Aug 9 14:27:17 DEBUG[8110] pbx.c: Launching 'Set' Aug 9 14:27:17 VERBOSE[8110] logger.c: -- Executing Set("SIP/706-08ae26b8", "AMPUSERCIDNAME=Ronald SoftPhone") in new stack Aug 9 14:27:17 DEBUG[8110] pbx.c: Expression result is '0' Aug 9 14:27:17 DEBUG[8110] pbx.c: Launching 'GotoIf' Aug 9 14:27:17 VERBOSE[8110] logger.c: -- Executing GotoIf("SIP/706-08ae26b8", "0?report") in new stack Aug 9 14:27:17 DEBUG[8110] pbx.c: Not taking any branch Aug 9 14:27:17 DEBUG[8110] pbx.c: Launching 'Set' Aug 9 14:27:17 VERBOSE[8110] logger.c: -- Executing Set("SIP/706-08ae26b8", "CALLERID(all)=Ronald SoftPhone <706>") in new stack Aug 9 14:27:17 DEBUG[8110] pbx.c: Function result is '"Ronald SoftPhone" <706>' Aug 9 14:27:17 DEBUG[8110] pbx.c: Launching 'NoOp' Aug 9 14:27:17 VERBOSE[8110] logger.c: -- Executing NoOp("SIP/706-08ae26b8", "Using CallerID "Ronald SoftPhone" <706>") in new stack Aug 9 14:27:17 DEBUG[8110] pbx.c: Launching 'Set' Aug 9 14:27:17 VERBOSE[8110] logger.c: -- Executing Set("SIP/706-08ae26b8", "FROMCONTEXT=exten-vm") in new stack Aug 9 14:27:17 DEBUG[8110] pbx.c: Launching 'Set' Aug 9 14:27:17 VERBOSE[8110] logger.c: -- Executing Set("SIP/706-08ae26b8", "VMBOX=novm") in new stack Aug 9 14:27:17 DEBUG[8110] pbx.c: Launching 'Set' Aug 9 14:27:17 VERBOSE[8110] logger.c: -- Executing Set("SIP/706-08ae26b8", "EXTTOCALL=874") in new stack Aug 9 14:27:17 DEBUG[8110] db.c: Unable to find key '874' in family 'CFU' Aug 9 14:27:17 DEBUG[8110] func_db.c: DB: CFU/874 not found in database. Aug 9 14:27:17 DEBUG[8110] pbx.c: Function result is '' Aug 9 14:27:17 DEBUG[8110] pbx.c: Launching 'Set' Aug 9 14:27:17 VERBOSE[8110] logger.c: -- Executing Set("SIP/706-08ae26b8", "CFUEXT=") in new stack Aug 9 14:27:17 DEBUG[8110] pbx.c: Expression result is '0' Aug 9 14:27:17 DEBUG[8110] pbx.c: Expression result is '0' Aug 9 14:27:17 DEBUG[8110] pbx.c: Expression result is '0' Aug 9 14:27:17 DEBUG[8110] pbx.c: Function result is '' Aug 9 14:27:17 DEBUG[8110] pbx.c: Launching 'Set' Aug 9 14:27:17 VERBOSE[8110] logger.c: -- Executing Set("SIP/706-08ae26b8", "RT=") in new stack Aug 9 14:27:17 DEBUG[8110] pbx.c: Launching 'Macro' Aug 9 14:27:17 VERBOSE[8110] logger.c: -- Executing Macro("SIP/706-08ae26b8", "record-enable|874|IN") in new stack Aug 9 14:27:17 DEBUG[8110] pbx.c: Function result is '0' Aug 9 14:27:17 DEBUG[8110] pbx.c: Launching 'GotoIf' Aug 9 14:27:17 VERBOSE[8110] logger.c: -- Executing GotoIf("SIP/706-08ae26b8", "0 > 0?2:4") in new stack Aug 9 14:27:17 VERBOSE[8110] logger.c: -- Goto (macro-record-enable,s,4) Aug 9 14:27:17 DEBUG[8110] pbx.c: Launching 'AGI' Aug 9 14:27:17 VERBOSE[8110] logger.c: -- Executing AGI("SIP/706-08ae26b8", "recordingcheck|20060809-142717|1155126437.1146") in new stack Aug 9 14:27:17 DEBUG[6427] devicestate.c: Changing state for SIP/706 - state 2 (In use) Aug 9 14:27:17 DEBUG[6427] chan_sip.c: Checking device state for peer 706 Aug 9 14:27:17 VERBOSE[8110] logger.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck Aug 9 14:27:17 DEBUG[8112] app_queue.c: Device 'SIP/706' changed to state '2' (In use) but we don't care because they're not a member of any queue. Aug 9 14:27:17 VERBOSE[8110] logger.c: recordingcheck|20060809-142717|1155126437.1146: Inbound recording not enabled Aug 9 14:27:17 VERBOSE[8110] logger.c: -- AGI Script recordingcheck completed, returning 0 Aug 9 14:27:17 DEBUG[8110] pbx.c: Launching 'NoOp' Aug 9 14:27:17 VERBOSE[8110] logger.c: -- Executing NoOp("SIP/706-08ae26b8", "No recording needed") in new stack Aug 9 14:27:17 DEBUG[8110] pbx.c: Expression result is '0' Aug 9 14:27:17 DEBUG[8110] pbx.c: Launching 'GotoIf' Aug 9 14:27:17 VERBOSE[8110] logger.c: -- Executing GotoIf("SIP/706-08ae26b8", "0?dolocaldial|1") in new stack Aug 9 14:27:17 DEBUG[8110] pbx.c: Not taking any branch Aug 9 14:27:17 DEBUG[8110] pbx.c: Launching 'Macro' Aug 9 14:27:17 VERBOSE[8110] logger.c: -- Executing Macro("SIP/706-08ae26b8", "dial||trwW|874") in new stack Aug 9 14:27:17 DEBUG[8110] pbx.c: Launching 'AGI' Aug 9 14:27:17 VERBOSE[8110] logger.c: -- Executing AGI("SIP/706-08ae26b8", "dialparties.agi") in new stack Aug 9 14:27:17 VERBOSE[8110] logger.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/dialparties.agi Aug 9 14:27:17 VERBOSE[8110] logger.c: dialparties.agi: Starting New Dialparties.agi Aug 9 14:27:17 VERBOSE[8110] logger.c: -- dialparties.agi: priority is 1 Aug 9 14:27:17 VERBOSE[8110] logger.c: dialparties.agi: Caller ID name is 'Ronald SoftPhone' number is '706' Aug 9 14:27:17 VERBOSE[8110] logger.c: dialparties.agi: Methodology of ring is 'none' Aug 9 14:27:17 VERBOSE[8110] logger.c: -- dialparties.agi: Added extension 874 to extension map Aug 9 14:27:17 DEBUG[8110] db.c: Unable to find key '874' in family 'CF' Aug 9 14:27:17 VERBOSE[8110] logger.c: -- dialparties.agi: Extension 874 cf is disabled Aug 9 14:27:17 DEBUG[8110] db.c: Unable to find key '874' in family 'DND' Aug 9 14:27:17 VERBOSE[8110] logger.c: -- dialparties.agi: Extension 874 do not disturb is disabled Aug 9 14:27:17 DEBUG[8110] db.c: Unable to find key '874' in family 'CFB' Aug 9 14:27:17 DEBUG[8110] db.c: Unable to find key '874' in family 'CFU' Aug 9 14:27:17 VERBOSE[8110] logger.c: > dialparties.agi: extnum: 874 Aug 9 14:27:17 VERBOSE[8110] logger.c: > dialparties.agi: exthascw: 1 Aug 9 14:27:17 VERBOSE[8110] logger.c: > dialparties.agi: exthascfb: 0 Aug 9 14:27:17 VERBOSE[8110] logger.c: > dialparties.agi: extcfb: Aug 9 14:27:17 VERBOSE[8110] logger.c: > dialparties.agi: exthascfu: 0 Aug 9 14:27:17 VERBOSE[8110] logger.c: > dialparties.agi: extcfu: Aug 9 14:27:17 VERBOSE[8110] logger.c: -- dialparties.agi: DbSet CALLTRACE/874 to 706 Aug 9 14:27:17 VERBOSE[8110] logger.c: -- AGI Script dialparties.agi completed, returning 0 Aug 9 14:27:17 DEBUG[8110] pbx.c: Launching 'Dial' Aug 9 14:27:17 VERBOSE[8110] logger.c: -- Executing Dial("SIP/706-08ae26b8", "SIP/701&SIP/705&SIP/703&SIP/704&SIP/874||trwW") in new stack Aug 9 14:27:17 DEBUG[8110] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP) Aug 9 14:27:17 DEBUG[8110] chan_sip.c: Setting NAT on RTP to 0 Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable STACK-macro-dial-s-10. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable MACRO_DEPTH. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable ds. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable STACK-macro-dial-s-1. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable ARG3. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable ARG2. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable ARG1. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable MACRO_PRIORITY. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable MACRO_CONTEXT. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable MACRO_EXTEN. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable STACK-macro-exten-vm-s-9. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable STACK-macro-exten-vm-s-8. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable STACK-macro-record-enable-s-5. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable STACK-macro-record-enable-s-4. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable STACK-macro-record-enable-s-1. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable STACK-macro-exten-vm-s-7. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable RT. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable STACK-macro-exten-vm-s-6. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable CFUEXT. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable STACK-macro-exten-vm-s-5. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable EXTTOCALL. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable STACK-macro-exten-vm-s-4. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable VMBOX. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable STACK-macro-exten-vm-s-3. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable FROMCONTEXT. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable STACK-macro-exten-vm-s-2. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable STACK-macro-user-callerid-s-9. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable STACK-macro-user-callerid-s-8. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable STACK-macro-user-callerid-s-7. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable AMPUSERCIDNAME. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable STACK-macro-user-callerid-s-6. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable DB_RESULT. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable AMPUSER. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable STACK-macro-user-callerid-s-5. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable STACK-macro-user-callerid-s-4. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable REALCALLERIDNUM. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable STACK-macro-user-callerid-s-3. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable STACK-macro-user-callerid-s-2. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable STACK-macro-user-callerid-s-1. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable STACK-macro-exten-vm-s-1. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable STACK-from-internal-874-1. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable SIPCALLID. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable SIPUSERAGENT. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable SIPDOMAIN. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable SIPURI. Aug 9 14:27:17 DEBUG[8110] chan_sip.c: Outgoing Call for 701 Aug 9 14:27:17 DEBUG[8110] chan_sip.c: Updating call counter for outgoing call Aug 9 14:27:17 VERBOSE[8110] logger.c: We're at 192.168.0.8 port 19090 Aug 9 14:27:17 VERBOSE[8110] logger.c: Adding codec 0x100 (g729) to SDP Aug 9 14:27:17 VERBOSE[8110] logger.c: Adding non-codec 0x1 (telephone-event) to SDP Aug 9 14:27:17 DEBUG[8110] chan_sip.c: Header 0: INVITE sip:701@192.168.0.100;user=phone SIP/2.0 (47) Aug 9 14:27:17 DEBUG[8110] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.0.8:5060;branch=z9hG4bK786aa9b9 (56) Aug 9 14:27:17 DEBUG[8110] chan_sip.c: Header 2: From: "Ronald SoftPhone" ;tag=as57bf173e (61) Aug 9 14:27:17 DEBUG[8110] chan_sip.c: Header 3: To: (38) Aug 9 14:27:17 DEBUG[8110] chan_sip.c: Header 4: Contact: (30) Aug 9 14:27:17 DEBUG[8110] chan_sip.c: Header 5: Call-ID: 6c56f8ae4f10281e06f1dba40ec7238b@192.168.0.8 (53) Aug 9 14:27:17 DEBUG[8110] chan_sip.c: Header 6: CSeq: 102 INVITE (16) Aug 9 14:27:17 DEBUG[8110] chan_sip.c: Header 7: User-Agent: Asterisk PBX (24) Aug 9 14:27:17 DEBUG[8110] chan_sip.c: Header 8: Max-Forwards: 70 (16) Aug 9 14:27:17 DEBUG[8110] chan_sip.c: Header 9: Date: Wed, 09 Aug 2006 12:27:17 GMT (35) Aug 9 14:27:17 DEBUG[8110] chan_sip.c: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) Aug 9 14:27:17 DEBUG[8110] chan_sip.c: Header 11: Content-Type: application/sdp (29) Aug 9 14:27:17 DEBUG[8110] chan_sip.c: Header 12: Content-Length: 235 (19) Aug 9 14:27:17 DEBUG[8110] chan_sip.c: Header 13: (0) Aug 9 14:27:17 DEBUG[8110] chan_sip.c: Line: v=0 (3) Aug 9 14:27:17 DEBUG[8110] chan_sip.c: Line: o=root 6409 6409 IN IP4 192.168.0.8 (35) Aug 9 14:27:17 DEBUG[8110] chan_sip.c: Line: s=session (9) Aug 9 14:27:17 DEBUG[8110] chan_sip.c: Line: c=IN IP4 192.168.0.8 (20) Aug 9 14:27:17 DEBUG[8110] chan_sip.c: Line: t=0 0 (5) Aug 9 14:27:17 DEBUG[8110] chan_sip.c: Line: m=audio 19090 RTP/AVP 18 101 (28) Aug 9 14:27:17 DEBUG[8110] chan_sip.c: Line: a=rtpmap:18 G729/8000 (21) Aug 9 14:27:17 DEBUG[8110] chan_sip.c: Line: a=fmtp:18 annexb=no (19) Aug 9 14:27:17 DEBUG[8110] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33) Aug 9 14:27:17 DEBUG[8110] chan_sip.c: Line: a=fmtp:101 0-16 (15) Aug 9 14:27:17 DEBUG[8110] chan_sip.c: Line: a=silenceSupp:off - - - - (25) Aug 9 14:27:17 VERBOSE[8110] logger.c: 13 headers, 11 lines Aug 9 14:27:17 VERBOSE[8110] logger.c: Reliably Transmitting (no NAT) to 192.168.0.100:5060: INVITE sip:701@192.168.0.100;user=phone SIP/2.0 Via: SIP/2.0/UDP 192.168.0.8:5060;branch=z9hG4bK786aa9b9 From: "Ronald SoftPhone" ;tag=as57bf173e To: Contact: Call-ID: 6c56f8ae4f10281e06f1dba40ec7238b@192.168.0.8 CSeq: 102 INVITE User-Agent: Asterisk PBX Max-Forwards: 70 Date: Wed, 09 Aug 2006 12:27:17 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Content-Type: application/sdp Content-Length: 235 v=0 o=root 6409 6409 IN IP4 192.168.0.8 s=session c=IN IP4 192.168.0.8 t=0 0 m=audio 19090 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 - - - - --- Aug 9 14:27:17 DEBUG[8110] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #364673 Aug 9 14:27:17 VERBOSE[8110] logger.c: -- Called 701 Aug 9 14:27:17 DEBUG[8110] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP) Aug 9 14:27:17 VERBOSE[8110] logger.c: Destroying call '0bae154071b62fe91a0b0f425ca0d324@127.0.0.1' Aug 9 14:27:17 NOTICE[8110] app_dial.c: Unable to create channel of type 'SIP' (cause 3 - No route to destination) Aug 9 14:27:17 DEBUG[8110] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP) Aug 9 14:27:17 VERBOSE[8110] logger.c: Destroying call '05403c58180a775e4f1e163e590e5d92@127.0.0.1' Aug 9 14:27:17 NOTICE[8110] app_dial.c: Unable to create channel of type 'SIP' (cause 3 - No route to destination) Aug 9 14:27:17 DEBUG[8110] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP) Aug 9 14:27:17 DEBUG[8110] chan_sip.c: Setting NAT on RTP to 0 Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable STACK-macro-dial-s-10. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable MACRO_DEPTH. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable ds. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable STACK-macro-dial-s-1. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable ARG3. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable ARG2. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable ARG1. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable MACRO_PRIORITY. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable MACRO_CONTEXT. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable MACRO_EXTEN. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable STACK-macro-exten-vm-s-9. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable STACK-macro-exten-vm-s-8. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable STACK-macro-record-enable-s-5. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable STACK-macro-record-enable-s-4. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable STACK-macro-record-enable-s-1. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable STACK-macro-exten-vm-s-7. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable RT. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable STACK-macro-exten-vm-s-6. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable CFUEXT. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable STACK-macro-exten-vm-s-5. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable EXTTOCALL. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable STACK-macro-exten-vm-s-4. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable VMBOX. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable STACK-macro-exten-vm-s-3. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable FROMCONTEXT. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable STACK-macro-exten-vm-s-2. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable STACK-macro-user-callerid-s-9. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable STACK-macro-user-callerid-s-8. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable STACK-macro-user-callerid-s-7. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable AMPUSERCIDNAME. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable STACK-macro-user-callerid-s-6. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable DB_RESULT. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable AMPUSER. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable STACK-macro-user-callerid-s-5. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable STACK-macro-user-callerid-s-4. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable REALCALLERIDNUM. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable STACK-macro-user-callerid-s-3. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable STACK-macro-user-callerid-s-2. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable STACK-macro-user-callerid-s-1. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable STACK-macro-exten-vm-s-1. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable STACK-from-internal-874-1. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable SIPCALLID. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable SIPUSERAGENT. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable SIPDOMAIN. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable SIPURI. Aug 9 14:27:17 DEBUG[8110] chan_sip.c: Outgoing Call for 704 Aug 9 14:27:17 DEBUG[8110] chan_sip.c: Updating call counter for outgoing call Aug 9 14:27:17 VERBOSE[8110] logger.c: We're at 192.168.0.8 port 11322 Aug 9 14:27:17 VERBOSE[8110] logger.c: Adding codec 0x100 (g729) to SDP Aug 9 14:27:17 VERBOSE[8110] logger.c: Adding non-codec 0x1 (telephone-event) to SDP Aug 9 14:27:17 DEBUG[8110] chan_sip.c: Header 0: INVITE sip:704@192.168.0.149 SIP/2.0 (36) Aug 9 14:27:17 DEBUG[8110] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.0.8:5060;branch=z9hG4bK02a33be9 (56) Aug 9 14:27:17 DEBUG[8110] chan_sip.c: Header 2: From: "Ronald SoftPhone" ;tag=as3350cd6f (61) Aug 9 14:27:17 DEBUG[8110] chan_sip.c: Header 3: To: (27) Aug 9 14:27:17 DEBUG[8110] chan_sip.c: Header 4: Contact: (30) Aug 9 14:27:17 DEBUG[8110] chan_sip.c: Header 5: Call-ID: 18ff89ba1541988c295b7cdc30986bc0@192.168.0.8 (53) Aug 9 14:27:17 DEBUG[8110] chan_sip.c: Header 6: CSeq: 102 INVITE (16) Aug 9 14:27:17 DEBUG[8110] chan_sip.c: Header 7: User-Agent: Asterisk PBX (24) Aug 9 14:27:17 DEBUG[8110] chan_sip.c: Header 8: Max-Forwards: 70 (16) Aug 9 14:27:17 DEBUG[8110] chan_sip.c: Header 9: Date: Wed, 09 Aug 2006 12:27:17 GMT (35) Aug 9 14:27:17 DEBUG[8110] chan_sip.c: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) Aug 9 14:27:17 DEBUG[8110] chan_sip.c: Header 11: Content-Type: application/sdp (29) Aug 9 14:27:17 DEBUG[8110] chan_sip.c: Header 12: Content-Length: 235 (19) Aug 9 14:27:17 DEBUG[8110] chan_sip.c: Header 13: (0) Aug 9 14:27:17 DEBUG[8110] chan_sip.c: Line: v=0 (3) Aug 9 14:27:17 DEBUG[8110] chan_sip.c: Line: o=root 6409 6409 IN IP4 192.168.0.8 (35) Aug 9 14:27:17 DEBUG[8110] chan_sip.c: Line: s=session (9) Aug 9 14:27:17 DEBUG[8110] chan_sip.c: Line: c=IN IP4 192.168.0.8 (20) Aug 9 14:27:17 DEBUG[8110] chan_sip.c: Line: t=0 0 (5) Aug 9 14:27:17 DEBUG[8110] chan_sip.c: Line: m=audio 11322 RTP/AVP 18 101 (28) Aug 9 14:27:17 DEBUG[8110] chan_sip.c: Line: a=rtpmap:18 G729/8000 (21) Aug 9 14:27:17 DEBUG[8110] chan_sip.c: Line: a=fmtp:18 annexb=no (19) Aug 9 14:27:17 DEBUG[8110] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33) Aug 9 14:27:17 DEBUG[8110] chan_sip.c: Line: a=fmtp:101 0-16 (15) Aug 9 14:27:17 DEBUG[8110] chan_sip.c: Line: a=silenceSupp:off - - - - (25) Aug 9 14:27:17 VERBOSE[8110] logger.c: 13 headers, 11 lines Aug 9 14:27:17 VERBOSE[8110] logger.c: Reliably Transmitting (no NAT) to 192.168.0.149:5060: INVITE sip:704@192.168.0.149 SIP/2.0 Via: SIP/2.0/UDP 192.168.0.8:5060;branch=z9hG4bK02a33be9 From: "Ronald SoftPhone" ;tag=as3350cd6f To: Contact: Call-ID: 18ff89ba1541988c295b7cdc30986bc0@192.168.0.8 CSeq: 102 INVITE User-Agent: Asterisk PBX Max-Forwards: 70 Date: Wed, 09 Aug 2006 12:27:17 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Content-Type: application/sdp Content-Length: 235 v=0 o=root 6409 6409 IN IP4 192.168.0.8 s=session c=IN IP4 192.168.0.8 t=0 0 m=audio 11322 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 - - - - --- Aug 9 14:27:17 DEBUG[8110] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #364675 Aug 9 14:27:17 VERBOSE[6438] logger.c: <-- SIP read from 192.168.0.100:5060: SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.0.8:5060;branch=z9hG4bK786aa9b9 From: "Ronald SoftPhone" ;tag=as57bf173e To: Call-ID: 6c56f8ae4f10281e06f1dba40ec7238b@192.168.0.8 CSeq: 102 INVITE User-Agent: Grandstream HT286 1.0.6.7 Content-Length: 0 Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 0: SIP/2.0 100 Trying (18) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.0.8:5060;branch=z9hG4bK786aa9b9 (56) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 2: From: "Ronald SoftPhone" ;tag=as57bf173e (61) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 3: To: (38) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 4: Call-ID: 6c56f8ae4f10281e06f1dba40ec7238b@192.168.0.8 (53) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 5: CSeq: 102 INVITE (16) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 6: User-Agent: Grandstream HT286 1.0.6.7 (37) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 7: Content-Length: 0 (17) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 8: (0) Aug 9 14:27:17 VERBOSE[6438] logger.c: --- (8 headers 0 lines)Aug 9 14:27:17 VERBOSE[6438] logger.c: --- (8 headers 0 lines)--- Aug 9 14:27:17 DEBUG[6438] chan_sip.c: *** SIP TIMER: Cancelling retransmission #364673 - INVITE (got response) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '6c56f8ae4f10281e06f1dba40ec7238b@192.168.0.8' Request 102: Found Aug 9 14:27:17 DEBUG[6438] chan_sip.c: SIP response 100 to standard invite Aug 9 14:27:17 VERBOSE[8110] logger.c: -- Called 704 Aug 9 14:27:17 VERBOSE[6438] logger.c: <-- SIP read from 192.168.0.100:5060: SIP/2.0 180 Ringing Via: SIP/2.0/UDP 192.168.0.8:5060;branch=z9hG4bK786aa9b9 From: "Ronald SoftPhone" ;tag=as57bf173e To: ;tag=271db1435c26194c Call-ID: 6c56f8ae4f10281e06f1dba40ec7238b@192.168.0.8 CSeq: 102 INVITE User-Agent: Grandstream HT286 1.0.6.7 Content-Length: 0 Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 0: SIP/2.0 180 Ringing (19) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.0.8:5060;branch=z9hG4bK786aa9b9 (56) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 2: From: "Ronald SoftPhone" ;tag=as57bf173e (61) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 3: To: ;tag=271db1435c26194c (59) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 4: Call-ID: 6c56f8ae4f10281e06f1dba40ec7238b@192.168.0.8 (53) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 5: CSeq: 102 INVITE (16) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 6: User-Agent: Grandstream HT286 1.0.6.7 (37) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 7: Content-Length: 0 (17) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 8: (0) Aug 9 14:27:17 VERBOSE[6438] logger.c: --- (8 headers 0 lines)Aug 9 14:27:17 VERBOSE[6438] logger.c: --- (8 headers 0 lines)--- Aug 9 14:27:17 DEBUG[6438] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '6c56f8ae4f10281e06f1dba40ec7238b@192.168.0.8' Request 102: Found Aug 9 14:27:17 DEBUG[6438] chan_sip.c: SIP response 180 to standard invite Aug 9 14:27:17 DEBUG[6427] chan_sip.c: Checking device state for peer 701 Aug 9 14:27:17 DEBUG[6427] devicestate.c: Changing state for SIP/701 - state 6 (Ringing) Aug 9 14:27:17 DEBUG[6427] chan_sip.c: Checking device state for peer 874 Aug 9 14:27:17 DEBUG[6427] chan_sip.c: Checking device state for peer 700 Aug 9 14:27:17 DEBUG[6427] chan_sip.c: Checking device state for peer 701 Aug 9 14:27:17 DEBUG[6427] chan_sip.c: Checking device state for peer 703 Aug 9 14:27:17 DEBUG[6427] chan_sip.c: Checking device state for peer 704 Aug 9 14:27:17 DEBUG[6427] chan_sip.c: Checking device state for peer 705 Aug 9 14:27:17 DEBUG[8114] app_queue.c: Device 'SIP/701' changed to state '6' (Ringing) but we don't care because they're not a member of any queue. Aug 9 14:27:17 DEBUG[6427] chan_sip.c: Checking device state for peer 874&SIP/700&SIP/701&SIP/703&SIP/704&SIP/705 Aug 9 14:27:17 VERBOSE[6427] logger.c: Reliably Transmitting (no NAT) to 192.168.255.79:5060: NOTIFY sip:822@192.168.255.79 SIP/2.0 Via: SIP/2.0/UDP 192.168.255.1:5060;branch=z9hG4bK1f5a56aa From: ;tag=as45233269 To: "Laetitia van Rijsbergen" ;tag=e7d1c9576b22d460 Contact: Call-ID: 8a287f2d002a7084@192.168.255.79 CSeq: 122 NOTIFY User-Agent: Asterisk PBX Max-Forwards: 70 Event: dialog Content-Type: application/dialog-info+xml Subscription-State: active Content-Length: 211

early

--- Aug 9 14:27:17 DEBUG[6427] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #364677 Aug 9 14:27:17 VERBOSE[6427] logger.c: Extension Changed 874 new state InUse&Ringing for Notify User 822 Aug 9 14:27:17 DEBUG[6427] chan_sip.c: Checking device state for peer 874&SIP/700&SIP/701&SIP/703&SIP/704&SIP/705 Aug 9 14:27:17 DEBUG[8110] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - INVITE (With RTP) Aug 9 14:27:17 DEBUG[8110] chan_sip.c: Setting NAT on RTP to 0 Aug 9 14:27:17 VERBOSE[6427] logger.c: Reliably Transmitting (no NAT) to 192.168.255.70:2051: NOTIFY sip:888@allium.gilze.global-t.nl SIP/2.0 Via: SIP/2.0/UDP 192.168.255.1:5060;branch=z9hG4bK1fa4b25f From: ;tag=as268c3087 To: ;tag=9gk18xrxm7 Contact: Call-ID: 3c267026668a-vkkokdwfsz66@snom360-0004132310B4 CSeq: 320 NOTIFY User-Agent: Asterisk PBX Max-Forwards: 70 Event: dialog Content-Type: application/dialog-info+xml Subscription-State: active Content-Length: 212

early

--- Aug 9 14:27:17 DEBUG[6427] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #364678 Aug 9 14:27:17 VERBOSE[6427] logger.c: Extension Changed 874 new state InUse&Ringing for Notify User 888 Aug 9 14:27:17 DEBUG[6427] chan_sip.c: Checking device state for peer 874&SIP/700&SIP/701&SIP/703&SIP/704&SIP/705 Aug 9 14:27:17 VERBOSE[6427] logger.c: Reliably Transmitting (no NAT) to 192.168.255.91:5060: NOTIFY sip:826@192.168.255.91 SIP/2.0 Via: SIP/2.0/UDP 192.168.255.1:5060;branch=z9hG4bK47158783 From: ;tag=as654cf311 To: "Ron van Engelen" ;tag=5ff906d3193d7bd3 Contact: Call-ID: 3ae34e7184d831fb@192.168.255.91 CSeq: 434 NOTIFY User-Agent: Asterisk PBX Max-Forwards: 70 Event: dialog Content-Type: application/dialog-info+xml Subscription-State: active Content-Length: 212

early

--- Aug 9 14:27:17 DEBUG[6427] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #364679 Aug 9 14:27:17 VERBOSE[6427] logger.c: Extension Changed 874 new state InUse&Ringing for Notify User 826 Aug 9 14:27:17 DEBUG[6427] chan_sip.c: Checking device state for peer 874&SIP/700&SIP/701&SIP/703&SIP/704&SIP/705 Aug 9 14:27:17 VERBOSE[6427] logger.c: Reliably Transmitting (no NAT) to 192.168.255.90:5060: NOTIFY sip:823@192.168.255.90 SIP/2.0 Via: SIP/2.0/UDP 192.168.255.1:5060;branch=z9hG4bK0344b00c From: ;tag=as67ecc51f To: "Alfred Daanen" ;tag=f258829930f48e4c Contact: Call-ID: 553c654628b3d9f1@192.168.255.90 CSeq: 391 NOTIFY User-Agent: Asterisk PBX Max-Forwards: 70 Event: dialog Content-Type: application/dialog-info+xml Subscription-State: active Content-Length: 212

early

--- Aug 9 14:27:17 DEBUG[6427] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #364680 Aug 9 14:27:17 VERBOSE[6427] logger.c: Extension Changed 874 new state InUse&Ringing for Notify User 823 Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable STACK-macro-dial-s-10. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable MACRO_DEPTH. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable ds. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable STACK-macro-dial-s-1. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable ARG3. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable ARG2. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable ARG1. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable MACRO_PRIORITY. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable MACRO_CONTEXT. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable MACRO_EXTEN. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable STACK-macro-exten-vm-s-9. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable STACK-macro-exten-vm-s-8. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable STACK-macro-record-enable-s-5. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable STACK-macro-record-enable-s-4. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable STACK-macro-record-enable-s-1. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable STACK-macro-exten-vm-s-7. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable RT. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable STACK-macro-exten-vm-s-6. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable CFUEXT. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable STACK-macro-exten-vm-s-5. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable EXTTOCALL. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable STACK-macro-exten-vm-s-4. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable VMBOX. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable STACK-macro-exten-vm-s-3. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable FROMCONTEXT. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable STACK-macro-exten-vm-s-2. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable STACK-macro-user-callerid-s-9. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable STACK-macro-user-callerid-s-8. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable STACK-macro-user-callerid-s-7. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable AMPUSERCIDNAME. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable STACK-macro-user-callerid-s-6. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable DB_RESULT. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable AMPUSER. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable STACK-macro-user-callerid-s-5. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable STACK-macro-user-callerid-s-4. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable REALCALLERIDNUM. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable STACK-macro-user-callerid-s-3. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable STACK-macro-user-callerid-s-2. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable STACK-macro-user-callerid-s-1. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable STACK-macro-exten-vm-s-1. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable STACK-from-internal-874-1. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable SIPCALLID. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable SIPUSERAGENT. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable SIPDOMAIN. Aug 9 14:27:17 DEBUG[8110] channel.c: Not copying variable SIPURI. Aug 9 14:27:17 DEBUG[8110] chan_sip.c: Outgoing Call for 874 Aug 9 14:27:17 DEBUG[8110] chan_sip.c: Updating call counter for outgoing call Aug 9 14:27:17 VERBOSE[8110] logger.c: We're at 192.168.255.1 port 18968 Aug 9 14:27:17 VERBOSE[8110] logger.c: Adding codec 0x100 (g729) to SDP Aug 9 14:27:17 VERBOSE[8110] logger.c: Adding non-codec 0x1 (telephone-event) to SDP Aug 9 14:27:17 DEBUG[8110] chan_sip.c: Header 0: INVITE sip:874@192.168.255.40:5060;user=phone SIP/2.0 (53) Aug 9 14:27:17 DEBUG[8110] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.255.1:5060;branch=z9hG4bK3a11802d (58) Aug 9 14:27:17 DEBUG[8110] chan_sip.c: Header 2: From: "Ronald SoftPhone" ;tag=as19bacd30 (63) Aug 9 14:27:17 DEBUG[8110] chan_sip.c: Header 3: To: (44) Aug 9 14:27:17 DEBUG[8110] chan_sip.c: Header 4: Contact: (32) Aug 9 14:27:17 DEBUG[8110] chan_sip.c: Header 5: Call-ID: 772f2db0214039c10a47e0d036ed0456@192.168.255.1 (55) Aug 9 14:27:17 DEBUG[8110] chan_sip.c: Header 6: CSeq: 102 INVITE (16) Aug 9 14:27:17 DEBUG[8110] chan_sip.c: Header 7: User-Agent: Asterisk PBX (24) Aug 9 14:27:17 DEBUG[8110] chan_sip.c: Header 8: Max-Forwards: 70 (16) Aug 9 14:27:17 DEBUG[8110] chan_sip.c: Header 9: Date: Wed, 09 Aug 2006 12:27:17 GMT (35) Aug 9 14:27:17 DEBUG[8110] chan_sip.c: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) Aug 9 14:27:17 DEBUG[8110] chan_sip.c: Header 11: Content-Type: application/sdp (29) Aug 9 14:27:17 DEBUG[8110] chan_sip.c: Header 12: Content-Length: 239 (19) Aug 9 14:27:17 DEBUG[8110] chan_sip.c: Header 13: (0) Aug 9 14:27:17 DEBUG[8110] chan_sip.c: Line: v=0 (3) Aug 9 14:27:17 DEBUG[8110] chan_sip.c: Line: o=root 6409 6409 IN IP4 192.168.255.1 (37) Aug 9 14:27:17 DEBUG[8110] chan_sip.c: Line: s=session (9) Aug 9 14:27:17 DEBUG[8110] chan_sip.c: Line: c=IN IP4 192.168.255.1 (22) Aug 9 14:27:17 DEBUG[8110] chan_sip.c: Line: t=0 0 (5) Aug 9 14:27:17 DEBUG[8110] chan_sip.c: Line: m=audio 18968 RTP/AVP 18 101 (28) Aug 9 14:27:17 DEBUG[8110] chan_sip.c: Line: a=rtpmap:18 G729/8000 (21) Aug 9 14:27:17 DEBUG[8110] chan_sip.c: Line: a=fmtp:18 annexb=no (19) Aug 9 14:27:17 DEBUG[8110] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33) Aug 9 14:27:17 DEBUG[8110] chan_sip.c: Line: a=fmtp:101 0-16 (15) Aug 9 14:27:17 DEBUG[8110] chan_sip.c: Line: a=silenceSupp:off - - - - (25) Aug 9 14:27:17 VERBOSE[8110] logger.c: 13 headers, 11 lines Aug 9 14:27:17 VERBOSE[8110] logger.c: Reliably Transmitting (no NAT) to 192.168.255.40:5060: INVITE sip:874@192.168.255.40:5060;user=phone SIP/2.0 Via: SIP/2.0/UDP 192.168.255.1:5060;branch=z9hG4bK3a11802d From: "Ronald SoftPhone" ;tag=as19bacd30 To: Contact: Call-ID: 772f2db0214039c10a47e0d036ed0456@192.168.255.1 CSeq: 102 INVITE User-Agent: Asterisk PBX Max-Forwards: 70 Date: Wed, 09 Aug 2006 12:27:17 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Content-Type: application/sdp Content-Length: 239 v=0 o=root 6409 6409 IN IP4 192.168.255.1 s=session c=IN IP4 192.168.255.1 t=0 0 m=audio 18968 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 - - - - --- Aug 9 14:27:17 DEBUG[8110] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #364681 Aug 9 14:27:17 VERBOSE[6438] logger.c: <-- SIP read from 192.168.255.91:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.255.1:5060;branch=z9hG4bK47158783 From: ;tag=as654cf311 To: "Ron van Engelen" ;tag=5ff906d3193d7bd3 Call-ID: 3ae34e7184d831fb@192.168.255.91 CSeq: 434 NOTIFY User-Agent: Grandstream GXP2000 1.1.0.11 Contact: Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK Supported: replaces, timer Content-Length: 0 Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 0: SIP/2.0 200 OK (14) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.255.1:5060;branch=z9hG4bK47158783 (58) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 2: From: ;tag=as654cf311 (66) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 3: To: "Ron van Engelen" ;tag=5ff906d3193d7bd3 (88) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 4: Call-ID: 3ae34e7184d831fb@192.168.255.91 (40) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 5: CSeq: 434 NOTIFY (16) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 6: User-Agent: Grandstream GXP2000 1.1.0.11 (40) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 7: Contact: (44) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 8: Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK (77) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 9: Supported: replaces, timer (26) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 10: Content-Length: 0 (17) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 11: (0) Aug 9 14:27:17 VERBOSE[6438] logger.c: --- (11 headers 0 lines)Aug 9 14:27:17 VERBOSE[6438] logger.c: --- (11 headers 0 lines)--- Aug 9 14:27:17 DEBUG[6438] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #364679 Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Stopping retransmission on '3ae34e7184d831fb@192.168.255.91' of Request 434: Match Found Aug 9 14:27:17 VERBOSE[8110] logger.c: -- Called 874 Aug 9 14:27:17 VERBOSE[8110] logger.c: Transmitting (no NAT) to 192.168.0.131:18856: SIP/2.0 180 Ringing Via: SIP/2.0/UDP 192.168.0.131:18856;branch=z9hG4bK-d87543-e17fbd168f49ae54-1--d87543-;rport;received=192.168.0.131 From: "Ronald Voermans";tag=5706bb26 To: "874";tag=as77a12ac8 Call-ID: 0d300a0d53359e6aYjllMDdiMDg1OGJhNzA5NWIwOGI5MjJhZDhhZGQ2ZmU. CSeq: 2 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Length: 0 --- Aug 9 14:27:17 VERBOSE[8110] logger.c: -- SIP/701-08a8a648 is ringing Aug 9 14:27:17 VERBOSE[6438] logger.c: <-- SIP read from 192.168.255.90:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.255.1:5060;branch=z9hG4bK0344b00c From: ;tag=as67ecc51f To: "Alfred Daanen" ;tag=f258829930f48e4c Call-ID: 553c654628b3d9f1@192.168.255.90 CSeq: 391 NOTIFY User-Agent: Grandstream GXP2000 1.1.0.11 Contact: Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK Supported: replaces, timer Content-Length: 0 Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 0: SIP/2.0 200 OK (14) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.255.1:5060;branch=z9hG4bK0344b00c (58) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 2: From: ;tag=as67ecc51f (66) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 3: To: "Alfred Daanen" ;tag=f258829930f48e4c (86) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 4: Call-ID: 553c654628b3d9f1@192.168.255.90 (40) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 5: CSeq: 391 NOTIFY (16) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 6: User-Agent: Grandstream GXP2000 1.1.0.11 (40) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 7: Contact: (44) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 8: Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK (77) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 9: Supported: replaces, timer (26) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 10: Content-Length: 0 (17) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 11: (0) Aug 9 14:27:17 VERBOSE[6438] logger.c: --- (11 headers 0 lines)Aug 9 14:27:17 VERBOSE[6438] logger.c: --- (11 headers 0 lines)--- Aug 9 14:27:17 DEBUG[6438] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #364680 Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Stopping retransmission on '553c654628b3d9f1@192.168.255.90' of Request 391: Match Found Aug 9 14:27:17 VERBOSE[6438] logger.c: <-- SIP read from 192.168.255.79:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.255.1:5060;branch=z9hG4bK1f5a56aa From: ;tag=as45233269 To: "Laetitia van Rijsbergen" ;tag=e7d1c9576b22d460 Call-ID: 8a287f2d002a7084@192.168.255.79 CSeq: 122 NOTIFY User-Agent: Grandstream GXP2000 1.0.2.13 Contact: Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK Supported: replaces, timer Content-Length: 0 Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 0: SIP/2.0 200 OK (14) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.255.1:5060;branch=z9hG4bK1f5a56aa (58) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 2: From: ;tag=as45233269 (66) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 3: To: "Laetitia van Rijsbergen" ;tag=e7d1c9576b22d460 (85) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 4: Call-ID: 8a287f2d002a7084@192.168.255.79 (40) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 5: CSeq: 122 NOTIFY (16) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 6: User-Agent: Grandstream GXP2000 1.0.2.13 (40) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 7: Contact: (33) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 8: Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK (77) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 9: Supported: replaces, timer (26) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 10: Content-Length: 0 (17) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 11: (0) Aug 9 14:27:17 VERBOSE[6438] logger.c: --- (11 headers 0 lines)Aug 9 14:27:17 VERBOSE[6438] logger.c: --- (11 headers 0 lines)--- Aug 9 14:27:17 DEBUG[6438] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #364677 Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Stopping retransmission on '8a287f2d002a7084@192.168.255.79' of Request 122: Match Found Aug 9 14:27:17 VERBOSE[6438] logger.c: <-- SIP read from 192.168.255.70:2051: SIP/2.0 200 Ok Via: SIP/2.0/UDP 192.168.255.1:5060;branch=z9hG4bK1fa4b25f From: ;tag=as268c3087 To: ;tag=9gk18xrxm7 Call-ID: 3c267026668a-vkkokdwfsz66@snom360-0004132310B4 CSeq: 320 NOTIFY Content-Length: 0 Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 0: SIP/2.0 200 Ok (14) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.255.1:5060;branch=z9hG4bK1fa4b25f (58) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 2: From: ;tag=as268c3087 (55) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 3: To: ;tag=9gk18xrxm7 (53) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 4: Call-ID: 3c267026668a-vkkokdwfsz66@snom360-0004132310B4 (55) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 5: CSeq: 320 NOTIFY (16) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 6: Content-Length: 0 (17) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 7: (0) Aug 9 14:27:17 VERBOSE[6438] logger.c: --- (7 headers 0 lines)Aug 9 14:27:17 VERBOSE[6438] logger.c: --- (7 headers 0 lines)--- Aug 9 14:27:17 DEBUG[6438] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #364678 Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Stopping retransmission on '3c267026668a-vkkokdwfsz66@snom360-0004132310B4' of Request 320: Match Found Aug 9 14:27:17 DEBUG[6438] chan_sip.c: SIP TIMER: Rescheduling retransmission #364681 (1) INVITE - 5 Aug 9 14:27:17 DEBUG[6438] chan_sip.c: ** SIP timers: Rescheduling retransmission 2 to 14 ms (t1 7 ms (Retrans id #364681)) Aug 9 14:27:17 VERBOSE[6438] logger.c: Retransmitting #1 (no NAT) to 192.168.255.40:5060: INVITE sip:874@192.168.255.40:5060;user=phone SIP/2.0 Via: SIP/2.0/UDP 192.168.255.1:5060;branch=z9hG4bK3a11802d From: "Ronald SoftPhone" ;tag=as19bacd30 To: Contact: Call-ID: 772f2db0214039c10a47e0d036ed0456@192.168.255.1 CSeq: 102 INVITE User-Agent: Asterisk PBX Max-Forwards: 70 Date: Wed, 09 Aug 2006 12:27:17 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Content-Type: application/sdp Content-Length: 239 v=0 o=root 6409 6409 IN IP4 192.168.255.1 s=session c=IN IP4 192.168.255.1 t=0 0 m=audio 18968 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 - - - - --- Aug 9 14:27:17 VERBOSE[6438] logger.c: <-- SIP read from 192.168.255.40:5060: SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.255.1:5060;branch=z9hG4bK3a11802d From: "Ronald SoftPhone";tag=as19bacd30 To: Call-ID: 772f2db0214039c10a47e0d036ed0456@192.168.255.1 CSeq: 102 INVITE Content-Length: 0 Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 0: SIP/2.0 100 Trying (18) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.255.1:5060;branch=z9hG4bK3a11802d (58) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 2: From: "Ronald SoftPhone";tag=as19bacd30 (62) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 3: To: (44) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 4: Call-ID: 772f2db0214039c10a47e0d036ed0456@192.168.255.1 (55) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 5: CSeq: 102 INVITE (16) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 6: Content-Length: 0 (17) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 7: (0) Aug 9 14:27:17 VERBOSE[6438] logger.c: --- (7 headers 0 lines)Aug 9 14:27:17 VERBOSE[6438] logger.c: --- (7 headers 0 lines)--- Aug 9 14:27:17 DEBUG[6438] chan_sip.c: *** SIP TIMER: Cancelling retransmission #364681 - INVITE (got response) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '772f2db0214039c10a47e0d036ed0456@192.168.255.1' Request 102: Found Aug 9 14:27:17 DEBUG[6438] chan_sip.c: SIP response 100 to standard invite Aug 9 14:27:17 VERBOSE[6438] logger.c: <-- SIP read from 192.168.255.40:5060: SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.255.1:5060;branch=z9hG4bK3a11802d From: "Ronald SoftPhone";tag=as19bacd30 To: Call-ID: 772f2db0214039c10a47e0d036ed0456@192.168.255.1 CSeq: 102 INVITE Content-Length: 0 Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 0: SIP/2.0 100 Trying (18) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.255.1:5060;branch=z9hG4bK3a11802d (58) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 2: From: "Ronald SoftPhone";tag=as19bacd30 (62) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 3: To: (44) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 4: Call-ID: 772f2db0214039c10a47e0d036ed0456@192.168.255.1 (55) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 5: CSeq: 102 INVITE (16) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 6: Content-Length: 0 (17) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 7: (0) Aug 9 14:27:17 VERBOSE[6438] logger.c: --- (7 headers 0 lines)Aug 9 14:27:17 VERBOSE[6438] logger.c: --- (7 headers 0 lines)--- Aug 9 14:27:17 DEBUG[6438] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '772f2db0214039c10a47e0d036ed0456@192.168.255.1' Request 102: Found Aug 9 14:27:17 DEBUG[6438] chan_sip.c: SIP response 100 to standard invite Aug 9 14:27:17 VERBOSE[6438] logger.c: <-- SIP read from 192.168.255.40:5060: SIP/2.0 180 Ringing Via: SIP/2.0/UDP 192.168.255.1:5060;branch=z9hG4bK3a11802d From: "Ronald SoftPhone";tag=as19bacd30 To: ;tag=c0a80101-39c1fa Call-ID: 772f2db0214039c10a47e0d036ed0456@192.168.255.1 CSeq: 102 INVITE Allow: INVITE,ACK,BYE,CANCEL,OPTIONS,PRACK,SUBSCRIBE,NOTIFY,UPDATE,REFER,REGISTER,INFO Contact: Content-Length: 0 Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 0: SIP/2.0 180 Ringing (19) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.255.1:5060;branch=z9hG4bK3a11802d (58) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 2: From: "Ronald SoftPhone";tag=as19bacd30 (62) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 3: To: ;tag=c0a80101-39c1fa (64) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 4: Call-ID: 772f2db0214039c10a47e0d036ed0456@192.168.255.1 (55) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 5: CSeq: 102 INVITE (16) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 6: Allow: INVITE,ACK,BYE,CANCEL,OPTIONS,PRACK,SUBSCRIBE,NOTIFY,UPDATE,REFER,REGISTER,INFO (86) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 7: Contact: (49) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 8: Content-Length: 0 (17) Aug 9 14:27:17 DEBUG[6438] chan_sip.c: Header 9: (0) Aug 9 14:27:17 VERBOSE[6438] logger.c: --- (9 headers 0 lines)Aug 9 14:27:17 VERBOSE[6438] logger.c: --- (9 headers 0 lines)--- Aug 9 14:27:17 DEBUG[6438] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '772f2db0214039c10a47e0d036ed0456@192.168.255.1' Request 102: Found Aug 9 14:27:17 DEBUG[6438] chan_sip.c: SIP response 180 to standard invite Aug 9 14:27:17 DEBUG[6427] chan_sip.c: Checking device state for peer 874 Aug 9 14:27:17 DEBUG[6427] devicestate.c: Changing state for SIP/874 - state 6 (Ringing) Aug 9 14:27:17 DEBUG[6427] chan_sip.c: Checking device state for peer 874 Aug 9 14:27:17 DEBUG[6427] chan_sip.c: Checking device state for peer 700 Aug 9 14:27:17 DEBUG[6427] chan_sip.c: Checking device state for peer 701 Aug 9 14:27:17 DEBUG[6427] chan_sip.c: Checking device state for peer 703 Aug 9 14:27:17 DEBUG[6427] chan_sip.c: Checking device state for peer 704 Aug 9 14:27:17 DEBUG[6427] chan_sip.c: Checking device state for peer 705 Aug 9 14:27:17 DEBUG[8115] app_queue.c: Device 'SIP/874' changed to state '6' (Ringing) but we don't care because they're not a member of any queue. Aug 9 14:27:17 VERBOSE[8110] logger.c: -- SIP/874-08ac8450 is ringing Aug 9 14:27:17 DEBUG[6438] chan_sip.c: SIP TIMER: Not rescheduling id #364669:OPTIONS (Method 3) (No timer T1) Aug 9 14:27:17 VERBOSE[6438] logger.c: Retransmitting #1 (no NAT) to 192.168.255.63:5061: OPTIONS sip:192.168.255.63:5061 SIP/2.0 Via: SIP/2.0/UDP 192.168.255.1:5060;branch=z9hG4bK48e058e5;rport From: "Unknown" ;tag=as44551689 To: Contact: Call-ID: 618584de7626d356126747b20993906a@192.168.255.1 CSeq: 102 OPTIONS User-Agent: Asterisk PBX Max-Forwards: 70 Date: Wed, 09 Aug 2006 12:27:16 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Content-Length: 0 --- Aug 9 14:27:18 VERBOSE[6438] logger.c: <-- SIP read from 192.168.0.149:5060: SIP/2.0 100 Trying Via: SIP/2.0/UDP 192.168.0.8:5060;branch=z9hG4bK02a33be9 From: "Ronald SoftPhone" ;tag=as3350cd6f To: Call-ID: 18ff89ba1541988c295b7cdc30986bc0@192.168.0.8 CSeq: 102 INVITE Content-Length: 0 Aug 9 14:27:18 DEBUG[6438] chan_sip.c: Header 0: SIP/2.0 100 Trying (18) Aug 9 14:27:18 DEBUG[6438] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.0.8:5060;branch=z9hG4bK02a33be9 (56) Aug 9 14:27:18 DEBUG[6438] chan_sip.c: Header 2: From: "Ronald SoftPhone" ;tag=as3350cd6f (61) Aug 9 14:27:18 DEBUG[6438] chan_sip.c: Header 3: To: (27) Aug 9 14:27:18 DEBUG[6438] chan_sip.c: Header 4: Call-ID: 18ff89ba1541988c295b7cdc30986bc0@192.168.0.8 (53) Aug 9 14:27:18 DEBUG[6438] chan_sip.c: Header 5: CSeq: 102 INVITE (16) Aug 9 14:27:18 DEBUG[6438] chan_sip.c: Header 6: Content-Length: 0 (17) Aug 9 14:27:18 DEBUG[6438] chan_sip.c: Header 7: (0) Aug 9 14:27:18 VERBOSE[6438] logger.c: --- (7 headers 0 lines)Aug 9 14:27:18 VERBOSE[6438] logger.c: --- (7 headers 0 lines)--- Aug 9 14:27:18 DEBUG[6438] chan_sip.c: *** SIP TIMER: Cancelling retransmission #364675 - INVITE (got response) Aug 9 14:27:18 DEBUG[6438] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '18ff89ba1541988c295b7cdc30986bc0@192.168.0.8' Request 102: Found Aug 9 14:27:18 DEBUG[6438] chan_sip.c: SIP response 100 to standard invite Aug 9 14:27:18 VERBOSE[6438] logger.c: <-- SIP read from 192.168.0.149:5060: SIP/2.0 180 Ringing Via: SIP/2.0/UDP 192.168.0.8:5060;branch=z9hG4bK02a33be9 From: "Ronald SoftPhone" ;tag=as3350cd6f To: ;tag=1064250115 Call-ID: 18ff89ba1541988c295b7cdc30986bc0@192.168.0.8 CSeq: 102 INVITE Contact: Content-Length: 0 Aug 9 14:27:18 DEBUG[6438] chan_sip.c: Header 0: SIP/2.0 180 Ringing (19) Aug 9 14:27:18 DEBUG[6438] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.0.8:5060;branch=z9hG4bK02a33be9 (56) Aug 9 14:27:18 DEBUG[6438] chan_sip.c: Header 2: From: "Ronald SoftPhone" ;tag=as3350cd6f (61) Aug 9 14:27:18 DEBUG[6438] chan_sip.c: Header 3: To: ;tag=1064250115 (42) Aug 9 14:27:18 DEBUG[6438] chan_sip.c: Header 4: Call-ID: 18ff89ba1541988c295b7cdc30986bc0@192.168.0.8 (53) Aug 9 14:27:18 DEBUG[6438] chan_sip.c: Header 5: CSeq: 102 INVITE (16) Aug 9 14:27:18 DEBUG[6438] chan_sip.c: Header 6: Contact: (32) Aug 9 14:27:18 DEBUG[6438] chan_sip.c: Header 7: Content-Length: 0 (17) Aug 9 14:27:18 DEBUG[6438] chan_sip.c: Header 8: (0) Aug 9 14:27:18 VERBOSE[6438] logger.c: --- (8 headers 0 lines)Aug 9 14:27:18 VERBOSE[6438] logger.c: --- (8 headers 0 lines)--- Aug 9 14:27:18 DEBUG[6438] chan_sip.c: (Provisional) Stopping retransmission (but retaining packet) on '18ff89ba1541988c295b7cdc30986bc0@192.168.0.8' Request 102: Found Aug 9 14:27:18 DEBUG[6438] chan_sip.c: SIP response 180 to standard invite Aug 9 14:27:18 DEBUG[6427] chan_sip.c: Checking device state for peer 704 Aug 9 14:27:18 DEBUG[6427] channel.c: Avoiding initial deadlock for 'SIP/704-08ad8b00' Aug 9 14:27:18 VERBOSE[8110] logger.c: -- SIP/704-08ad8b00 is ringing Aug 9 14:27:18 DEBUG[6427] devicestate.c: Changing state for SIP/704 - state 6 (Ringing) Aug 9 14:27:18 DEBUG[6427] chan_sip.c: Checking device state for peer 874 Aug 9 14:27:18 DEBUG[6427] chan_sip.c: Checking device state for peer 700 Aug 9 14:27:18 DEBUG[6427] chan_sip.c: Checking device state for peer 701 Aug 9 14:27:18 DEBUG[6427] chan_sip.c: Checking device state for peer 703 Aug 9 14:27:18 DEBUG[6427] chan_sip.c: Checking device state for peer 704 Aug 9 14:27:18 DEBUG[6427] chan_sip.c: Checking device state for peer 705 Aug 9 14:27:18 DEBUG[6427] chan_sip.c: Checking device state for peer 874&SIP/700&SIP/701&SIP/703&SIP/704&SIP/705 Aug 9 14:27:18 DEBUG[8116] app_queue.c: Device 'SIP/704' changed to state '6' (Ringing) but we don't care because they're not a member of any queue. Aug 9 14:27:18 VERBOSE[6427] logger.c: Reliably Transmitting (no NAT) to 192.168.255.79:5060: NOTIFY sip:822@192.168.255.79 SIP/2.0 Via: SIP/2.0/UDP 192.168.255.1:5060;branch=z9hG4bK1fe661fa From: ;tag=as45233269 To: "Laetitia van Rijsbergen" ;tag=e7d1c9576b22d460 Contact: Call-ID: 8a287f2d002a7084@192.168.255.79 CSeq: 123 NOTIFY User-Agent: Asterisk PBX Max-Forwards: 70 Event: dialog Content-Type: application/dialog-info+xml Subscription-State: active Content-Length: 211

early

--- Aug 9 14:27:18 DEBUG[6427] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #364683 Aug 9 14:27:18 VERBOSE[6427] logger.c: Extension Changed 874 new state Ringing for Notify User 822 Aug 9 14:27:18 DEBUG[6427] chan_sip.c: Checking device state for peer 874&SIP/700&SIP/701&SIP/703&SIP/704&SIP/705 Aug 9 14:27:18 VERBOSE[6427] logger.c: Reliably Transmitting (no NAT) to 192.168.255.70:2051: NOTIFY sip:888@allium.gilze.global-t.nl SIP/2.0 Via: SIP/2.0/UDP 192.168.255.1:5060;branch=z9hG4bK171a10a6 From: ;tag=as268c3087 To: ;tag=9gk18xrxm7 Contact: Call-ID: 3c267026668a-vkkokdwfsz66@snom360-0004132310B4 CSeq: 321 NOTIFY User-Agent: Asterisk PBX Max-Forwards: 70 Event: dialog Content-Type: application/dialog-info+xml Subscription-State: active Content-Length: 212

early

--- Aug 9 14:27:18 DEBUG[6427] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #364684 Aug 9 14:27:18 VERBOSE[6427] logger.c: Extension Changed 874 new state Ringing for Notify User 888 Aug 9 14:27:18 DEBUG[6427] chan_sip.c: Checking device state for peer 874&SIP/700&SIP/701&SIP/703&SIP/704&SIP/705 Aug 9 14:27:18 VERBOSE[6427] logger.c: Reliably Transmitting (no NAT) to 192.168.255.91:5060: NOTIFY sip:826@192.168.255.91 SIP/2.0 Via: SIP/2.0/UDP 192.168.255.1:5060;branch=z9hG4bK1e58d7ac From: ;tag=as654cf311 To: "Ron van Engelen" ;tag=5ff906d3193d7bd3 Contact: Call-ID: 3ae34e7184d831fb@192.168.255.91 CSeq: 435 NOTIFY User-Agent: Asterisk PBX Max-Forwards: 70 Event: dialog Content-Type: application/dialog-info+xml Subscription-State: active Content-Length: 212

early

--- Aug 9 14:27:18 DEBUG[6427] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #364685 Aug 9 14:27:18 VERBOSE[6427] logger.c: Extension Changed 874 new state Ringing for Notify User 826 Aug 9 14:27:18 DEBUG[6427] chan_sip.c: Checking device state for peer 874&SIP/700&SIP/701&SIP/703&SIP/704&SIP/705 Aug 9 14:27:18 VERBOSE[6427] logger.c: Reliably Transmitting (no NAT) to 192.168.255.90:5060: NOTIFY sip:823@192.168.255.90 SIP/2.0 Via: SIP/2.0/UDP 192.168.255.1:5060;branch=z9hG4bK724444fe From: ;tag=as67ecc51f To: "Alfred Daanen" ;tag=f258829930f48e4c Contact: Call-ID: 553c654628b3d9f1@192.168.255.90 CSeq: 392 NOTIFY User-Agent: Asterisk PBX Max-Forwards: 70 Event: dialog Content-Type: application/dialog-info+xml Subscription-State: active Content-Length: 212

early

--- Aug 9 14:27:18 DEBUG[6427] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #364686 Aug 9 14:27:18 VERBOSE[6427] logger.c: Extension Changed 874 new state Ringing for Notify User 823 Aug 9 14:27:18 VERBOSE[6438] logger.c: <-- SIP read from 192.168.255.91:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.255.1:5060;branch=z9hG4bK1e58d7ac From: ;tag=as654cf311 To: "Ron van Engelen" ;tag=5ff906d3193d7bd3 Call-ID: 3ae34e7184d831fb@192.168.255.91 CSeq: 435 NOTIFY User-Agent: Grandstream GXP2000 1.1.0.11 Contact: Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK Supported: replaces, timer Content-Length: 0 Aug 9 14:27:18 DEBUG[6438] chan_sip.c: Header 0: SIP/2.0 200 OK (14) Aug 9 14:27:18 DEBUG[6438] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.255.1:5060;branch=z9hG4bK1e58d7ac (58) Aug 9 14:27:18 DEBUG[6438] chan_sip.c: Header 2: From: ;tag=as654cf311 (66) Aug 9 14:27:18 DEBUG[6438] chan_sip.c: Header 3: To: "Ron van Engelen" ;tag=5ff906d3193d7bd3 (88) Aug 9 14:27:18 DEBUG[6438] chan_sip.c: Header 4: Call-ID: 3ae34e7184d831fb@192.168.255.91 (40) Aug 9 14:27:18 DEBUG[6438] chan_sip.c: Header 5: CSeq: 435 NOTIFY (16) Aug 9 14:27:18 DEBUG[6438] chan_sip.c: Header 6: User-Agent: Grandstream GXP2000 1.1.0.11 (40) Aug 9 14:27:18 DEBUG[6438] chan_sip.c: Header 7: Contact: (44) Aug 9 14:27:18 DEBUG[6438] chan_sip.c: Header 8: Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK (77) Aug 9 14:27:18 DEBUG[6438] chan_sip.c: Header 9: Supported: replaces, timer (26) Aug 9 14:27:18 DEBUG[6438] chan_sip.c: Header 10: Content-Length: 0 (17) Aug 9 14:27:18 DEBUG[6438] chan_sip.c: Header 11: (0) Aug 9 14:27:18 VERBOSE[6438] logger.c: --- (11 headers 0 lines)Aug 9 14:27:18 VERBOSE[6438] logger.c: --- (11 headers 0 lines)--- Aug 9 14:27:18 DEBUG[6438] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #364685 Aug 9 14:27:18 DEBUG[6438] chan_sip.c: Stopping retransmission on '3ae34e7184d831fb@192.168.255.91' of Request 435: Match Found Aug 9 14:27:18 VERBOSE[6438] logger.c: <-- SIP read from 192.168.255.79:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.255.1:5060;branch=z9hG4bK1fe661fa From: ;tag=as45233269 To: "Laetitia van Rijsbergen" ;tag=e7d1c9576b22d460 Call-ID: 8a287f2d002a7084@192.168.255.79 CSeq: 123 NOTIFY User-Agent: Grandstream GXP2000 1.0.2.13 Contact: Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK Supported: replaces, timer Content-Length: 0 Aug 9 14:27:18 DEBUG[6438] chan_sip.c: Header 0: SIP/2.0 200 OK (14) Aug 9 14:27:18 DEBUG[6438] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.255.1:5060;branch=z9hG4bK1fe661fa (58) Aug 9 14:27:18 DEBUG[6438] chan_sip.c: Header 2: From: ;tag=as45233269 (66) Aug 9 14:27:18 DEBUG[6438] chan_sip.c: Header 3: To: "Laetitia van Rijsbergen" ;tag=e7d1c9576b22d460 (85) Aug 9 14:27:18 DEBUG[6438] chan_sip.c: Header 4: Call-ID: 8a287f2d002a7084@192.168.255.79 (40) Aug 9 14:27:18 DEBUG[6438] chan_sip.c: Header 5: CSeq: 123 NOTIFY (16) Aug 9 14:27:18 DEBUG[6438] chan_sip.c: Header 6: User-Agent: Grandstream GXP2000 1.0.2.13 (40) Aug 9 14:27:18 DEBUG[6438] chan_sip.c: Header 7: Contact: (33) Aug 9 14:27:18 DEBUG[6438] chan_sip.c: Header 8: Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK (77) Aug 9 14:27:18 DEBUG[6438] chan_sip.c: Header 9: Supported: replaces, timer (26) Aug 9 14:27:18 DEBUG[6438] chan_sip.c: Header 10: Content-Length: 0 (17) Aug 9 14:27:18 DEBUG[6438] chan_sip.c: Header 11: (0) Aug 9 14:27:18 VERBOSE[6438] logger.c: --- (11 headers 0 lines)Aug 9 14:27:18 VERBOSE[6438] logger.c: --- (11 headers 0 lines)--- Aug 9 14:27:18 DEBUG[6438] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #364683 Aug 9 14:27:18 DEBUG[6438] chan_sip.c: Stopping retransmission on '8a287f2d002a7084@192.168.255.79' of Request 123: Match Found Aug 9 14:27:18 VERBOSE[6438] logger.c: <-- SIP read from 192.168.255.90:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.255.1:5060;branch=z9hG4bK724444fe From: ;tag=as67ecc51f To: "Alfred Daanen" ;tag=f258829930f48e4c Call-ID: 553c654628b3d9f1@192.168.255.90 CSeq: 392 NOTIFY User-Agent: Grandstream GXP2000 1.1.0.11 Contact: Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK Supported: replaces, timer Content-Length: 0 Aug 9 14:27:18 DEBUG[6438] chan_sip.c: Header 0: SIP/2.0 200 OK (14) Aug 9 14:27:18 DEBUG[6438] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.255.1:5060;branch=z9hG4bK724444fe (58) Aug 9 14:27:18 DEBUG[6438] chan_sip.c: Header 2: From: ;tag=as67ecc51f (66) Aug 9 14:27:18 DEBUG[6438] chan_sip.c: Header 3: To: "Alfred Daanen" ;tag=f258829930f48e4c (86) Aug 9 14:27:18 DEBUG[6438] chan_sip.c: Header 4: Call-ID: 553c654628b3d9f1@192.168.255.90 (40) Aug 9 14:27:18 DEBUG[6438] chan_sip.c: Header 5: CSeq: 392 NOTIFY (16) Aug 9 14:27:18 DEBUG[6438] chan_sip.c: Header 6: User-Agent: Grandstream GXP2000 1.1.0.11 (40) Aug 9 14:27:18 DEBUG[6438] chan_sip.c: Header 7: Contact: (44) Aug 9 14:27:18 DEBUG[6438] chan_sip.c: Header 8: Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK (77) Aug 9 14:27:18 DEBUG[6438] chan_sip.c: Header 9: Supported: replaces, timer (26) Aug 9 14:27:18 DEBUG[6438] chan_sip.c: Header 10: Content-Length: 0 (17) Aug 9 14:27:18 DEBUG[6438] chan_sip.c: Header 11: (0) Aug 9 14:27:18 VERBOSE[6438] logger.c: --- (11 headers 0 lines)Aug 9 14:27:18 VERBOSE[6438] logger.c: --- (11 headers 0 lines)--- Aug 9 14:27:18 DEBUG[6438] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #364686 Aug 9 14:27:18 DEBUG[6438] chan_sip.c: Stopping retransmission on '553c654628b3d9f1@192.168.255.90' of Request 392: Match Found Aug 9 14:27:18 VERBOSE[6438] logger.c: <-- SIP read from 192.168.255.70:2051: SIP/2.0 200 Ok Via: SIP/2.0/UDP 192.168.255.1:5060;branch=z9hG4bK171a10a6 From: ;tag=as268c3087 To: ;tag=9gk18xrxm7 Call-ID: 3c267026668a-vkkokdwfsz66@snom360-0004132310B4 CSeq: 321 NOTIFY Content-Length: 0 Aug 9 14:27:18 DEBUG[6438] chan_sip.c: Header 0: SIP/2.0 200 Ok (14) Aug 9 14:27:18 DEBUG[6438] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.255.1:5060;branch=z9hG4bK171a10a6 (58) Aug 9 14:27:18 DEBUG[6438] chan_sip.c: Header 2: From: ;tag=as268c3087 (55) Aug 9 14:27:18 DEBUG[6438] chan_sip.c: Header 3: To: ;tag=9gk18xrxm7 (53) Aug 9 14:27:18 DEBUG[6438] chan_sip.c: Header 4: Call-ID: 3c267026668a-vkkokdwfsz66@snom360-0004132310B4 (55) Aug 9 14:27:18 DEBUG[6438] chan_sip.c: Header 5: CSeq: 321 NOTIFY (16) Aug 9 14:27:18 DEBUG[6438] chan_sip.c: Header 6: Content-Length: 0 (17) Aug 9 14:27:18 DEBUG[6438] chan_sip.c: Header 7: (0) Aug 9 14:27:18 VERBOSE[6438] logger.c: --- (7 headers 0 lines)Aug 9 14:27:18 VERBOSE[6438] logger.c: --- (7 headers 0 lines)--- Aug 9 14:27:18 DEBUG[6438] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #364684 Aug 9 14:27:18 DEBUG[6438] chan_sip.c: Stopping retransmission on '3c267026668a-vkkokdwfsz66@snom360-0004132310B4' of Request 321: Match Found Aug 9 14:27:18 DEBUG[6438] chan_sip.c: SIP TIMER: Not rescheduling id #364669:OPTIONS (Method 3) (No timer T1) Aug 9 14:27:18 VERBOSE[6438] logger.c: Retransmitting #2 (no NAT) to 192.168.255.63:5061: OPTIONS sip:192.168.255.63:5061 SIP/2.0 Via: SIP/2.0/UDP 192.168.255.1:5060;branch=z9hG4bK48e058e5;rport From: "Unknown" ;tag=as44551689 To: Contact: Call-ID: 618584de7626d356126747b20993906a@192.168.255.1 CSeq: 102 OPTIONS User-Agent: Asterisk PBX Max-Forwards: 70 Date: Wed, 09 Aug 2006 12:27:16 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Content-Length: 0 --- Aug 9 14:27:19 VERBOSE[6438] logger.c: <-- SIP read from 192.168.255.40:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.255.1:5060;branch=z9hG4bK3a11802d From: "Ronald SoftPhone";tag=as19bacd30 To: ;tag=c0a80101-39c1fa Call-ID: 772f2db0214039c10a47e0d036ed0456@192.168.255.1 CSeq: 102 INVITE Allow: INVITE,ACK,BYE,CANCEL,OPTIONS,PRACK,SUBSCRIBE,NOTIFY,UPDATE,REFER,REGISTER,INFO Contact: Content-Type: application/sdp Content-Length: 204 v=0 o=874 3786184 3786184 IN IP4 192.168.255.40 s=- c=IN IP4 192.168.255.40 t=0 0 m=audio 41000 RTP/AVP 18 101 a=rtpmap:18 G729/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=sendrecv Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 0: SIP/2.0 200 OK (14) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.255.1:5060;branch=z9hG4bK3a11802d (58) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 2: From: "Ronald SoftPhone";tag=as19bacd30 (62) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 3: To: ;tag=c0a80101-39c1fa (64) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 4: Call-ID: 772f2db0214039c10a47e0d036ed0456@192.168.255.1 (55) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 5: CSeq: 102 INVITE (16) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 6: Allow: INVITE,ACK,BYE,CANCEL,OPTIONS,PRACK,SUBSCRIBE,NOTIFY,UPDATE,REFER,REGISTER,INFO (86) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 7: Contact: (49) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 8: Content-Type: application/sdp (29) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 9: Content-Length: 204 (19) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 10: (0) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Line: v=0 (3) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Line: o=874 3786184 3786184 IN IP4 192.168.255.40 (43) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Line: s=- (3) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Line: c=IN IP4 192.168.255.40 (23) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Line: t=0 0 (5) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Line: m=audio 41000 RTP/AVP 18 101 (28) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Line: a=rtpmap:18 G729/8000 (21) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Line: a=fmtp:101 0-15 (15) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Line: a=sendrecv (10) Aug 9 14:27:19 VERBOSE[6438] logger.c: --- (10 headers 10 lines)Aug 9 14:27:19 VERBOSE[6438] logger.c: --- (10 headers 10 lines)--- Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Acked pending invite 102 Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Stopping retransmission on '772f2db0214039c10a47e0d036ed0456@192.168.255.1' of Request 102: Match Found Aug 9 14:27:19 DEBUG[6438] chan_sip.c: SIP response 200 to standard invite Aug 9 14:27:19 VERBOSE[6438] logger.c: Found RTP audio format 18 Aug 9 14:27:19 VERBOSE[6438] logger.c: Found RTP audio format 101 Aug 9 14:27:19 VERBOSE[6438] logger.c: Peer audio RTP is at port 192.168.255.40:41000 Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Peer audio RTP is at port 192.168.255.40:41000 Aug 9 14:27:19 VERBOSE[6438] logger.c: Found description format G729 Aug 9 14:27:19 VERBOSE[6438] logger.c: Found description format telephone-event Aug 9 14:27:19 VERBOSE[6438] logger.c: Capabilities: us - 0x100 (g729), peer - audio=0x100 (g729)/video=0x0 (nothing), combined - 0x100 (g729) Aug 9 14:27:19 VERBOSE[6438] logger.c: Non-codec capabilities: us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: build_route: Contact hop: Aug 9 14:27:19 VERBOSE[6438] logger.c: list_route: hop: Aug 9 14:27:19 VERBOSE[6438] logger.c: set_destination: Parsing for address/port to send to Aug 9 14:27:19 VERBOSE[6438] logger.c: set_destination: set destination to 192.168.255.40, port 5060 Aug 9 14:27:19 VERBOSE[6438] logger.c: Transmitting (no NAT) to 192.168.255.40:5060: ACK sip:874@192.168.255.40:5060;user=phone SIP/2.0 Via: SIP/2.0/UDP 192.168.255.1:5060;branch=z9hG4bK3b2b5cf9 From: "Ronald SoftPhone" ;tag=as19bacd30 To: ;tag=c0a80101-39c1fa Contact: Call-ID: 772f2db0214039c10a47e0d036ed0456@192.168.255.1 CSeq: 102 ACK User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- Aug 9 14:27:19 VERBOSE[8110] logger.c: -- SIP/874-08ac8450 answered SIP/706-08ae26b8 Aug 9 14:27:19 DEBUG[8110] channel.c: Hanging up channel 'SIP/704-08ad8b00' Aug 9 14:27:19 DEBUG[8110] chan_sip.c: Hangup call SIP/704-08ad8b00, SIP callid 18ff89ba1541988c295b7cdc30986bc0@192.168.0.8) Aug 9 14:27:19 DEBUG[8110] chan_sip.c: update_call_counter(704) - decrement call limit counter Aug 9 14:27:19 DEBUG[8110] chan_sip.c: Updating call counter for outgoing call Aug 9 14:27:19 DEBUG[8110] chan_sip.c: Acked pending invite 102 Aug 9 14:27:19 DEBUG[8110] chan_sip.c: Stopping retransmission on '18ff89ba1541988c295b7cdc30986bc0@192.168.0.8' of Request 102: Match Found Aug 9 14:27:19 VERBOSE[8110] logger.c: Reliably Transmitting (no NAT) to 192.168.0.149:5060: CANCEL sip:704@192.168.0.149 SIP/2.0 Via: SIP/2.0/UDP 192.168.0.8:5060;branch=z9hG4bK02a33be9 From: "Ronald SoftPhone" ;tag=as3350cd6f To: Contact: Call-ID: 18ff89ba1541988c295b7cdc30986bc0@192.168.0.8 CSeq: 102 CANCEL User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- Aug 9 14:27:19 DEBUG[6427] chan_sip.c: Checking device state for peer 874 Aug 9 14:27:19 DEBUG[6427] devicestate.c: Changing state for SIP/874 - state 2 (In use) Aug 9 14:27:19 DEBUG[6427] chan_sip.c: Checking device state for peer 874 Aug 9 14:27:19 DEBUG[6427] chan_sip.c: Checking device state for peer 700 Aug 9 14:27:19 DEBUG[6427] chan_sip.c: Checking device state for peer 701 Aug 9 14:27:19 DEBUG[6427] chan_sip.c: Checking device state for peer 703 Aug 9 14:27:19 DEBUG[6427] chan_sip.c: Checking device state for peer 704 Aug 9 14:27:19 DEBUG[6427] channel.c: Avoiding initial deadlock for 'SIP/704-08ad8b00' Aug 9 14:27:19 DEBUG[8117] app_queue.c: Device 'SIP/874' changed to state '2' (In use) but we don't care because they're not a member of any queue. Aug 9 14:27:19 DEBUG[8110] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #364687 Aug 9 14:27:19 VERBOSE[8110] logger.c: Scheduling destruction of call '18ff89ba1541988c295b7cdc30986bc0@192.168.0.8' in 32000 ms Aug 9 14:27:19 DEBUG[8110] channel.c: Hanging up channel 'SIP/701-08a8a648' Aug 9 14:27:19 DEBUG[8110] chan_sip.c: Hangup call SIP/701-08a8a648, SIP callid 6c56f8ae4f10281e06f1dba40ec7238b@192.168.0.8) Aug 9 14:27:19 DEBUG[8110] chan_sip.c: update_call_counter(701) - decrement call limit counter Aug 9 14:27:19 DEBUG[8110] chan_sip.c: Updating call counter for outgoing call Aug 9 14:27:19 DEBUG[8110] chan_sip.c: Acked pending invite 102 Aug 9 14:27:19 DEBUG[8110] chan_sip.c: Stopping retransmission on '6c56f8ae4f10281e06f1dba40ec7238b@192.168.0.8' of Request 102: Match Found Aug 9 14:27:19 VERBOSE[8110] logger.c: Reliably Transmitting (no NAT) to 192.168.0.100:5060: CANCEL sip:701@192.168.0.100;user=phone SIP/2.0 Via: SIP/2.0/UDP 192.168.0.8:5060;branch=z9hG4bK786aa9b9 From: "Ronald SoftPhone" ;tag=as57bf173e To: Contact: Call-ID: 6c56f8ae4f10281e06f1dba40ec7238b@192.168.0.8 CSeq: 102 CANCEL User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- Aug 9 14:27:19 DEBUG[8110] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #364689 Aug 9 14:27:19 VERBOSE[8110] logger.c: Scheduling destruction of call '6c56f8ae4f10281e06f1dba40ec7238b@192.168.0.8' in 32000 ms Aug 9 14:27:19 DEBUG[8110] chan_sip.c: sip_answer(SIP/706-08ae26b8) Aug 9 14:27:19 VERBOSE[8110] logger.c: We're at 192.168.0.8 port 10038 Aug 9 14:27:19 VERBOSE[8110] logger.c: Adding codec 0x100 (g729) to SDP Aug 9 14:27:19 VERBOSE[8110] logger.c: Adding non-codec 0x1 (telephone-event) to SDP Aug 9 14:27:19 VERBOSE[8110] logger.c: Reliably Transmitting (no NAT) to 192.168.0.131:18856: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.0.131:18856;branch=z9hG4bK-d87543-e17fbd168f49ae54-1--d87543-;rport;received=192.168.0.131 From: "Ronald Voermans";tag=5706bb26 To: "874";tag=as77a12ac8 Call-ID: 0d300a0d53359e6aYjllMDdiMDg1OGJhNzA5NWIwOGI5MjJhZDhhZGQ2ZmU. CSeq: 2 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Type: application/sdp Content-Length: 235 v=0 o=root 6409 6409 IN IP4 192.168.0.8 s=session c=IN IP4 192.168.0.8 t=0 0 m=audio 10038 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 - - - - --- Aug 9 14:27:19 DEBUG[8110] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #364691 Aug 9 14:27:19 DEBUG[8110] rtp.c: Got RTCP report of 132 bytes Aug 9 14:27:19 VERBOSE[6438] logger.c: <-- SIP read from 192.168.0.100:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.0.8:5060;branch=z9hG4bK786aa9b9 From: "Ronald SoftPhone" ;tag=as57bf173e To: ;tag=acb7bceed2692880 Call-ID: 6c56f8ae4f10281e06f1dba40ec7238b@192.168.0.8 CSeq: 102 CANCEL User-Agent: Grandstream HT286 1.0.6.7 Contact: Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE Supported: replaces Content-Length: 0 Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 0: SIP/2.0 200 OK (14) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.0.8:5060;branch=z9hG4bK786aa9b9 (56) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 2: From: "Ronald SoftPhone" ;tag=as57bf173e (61) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 3: To: ;tag=acb7bceed2692880 (59) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 4: Call-ID: 6c56f8ae4f10281e06f1dba40ec7238b@192.168.0.8 (53) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 5: CSeq: 102 CANCEL (16) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 6: User-Agent: Grandstream HT286 1.0.6.7 (37) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 7: Contact: (43) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 8: Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE (64) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 9: Supported: replaces (19) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 10: Content-Length: 0 (17) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 11: (0) Aug 9 14:27:19 VERBOSE[6438] logger.c: --- (11 headers 0 lines)Aug 9 14:27:19 VERBOSE[6438] logger.c: --- (11 headers 0 lines)--- Aug 9 14:27:19 DEBUG[6438] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #364689 Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Stopping retransmission on '6c56f8ae4f10281e06f1dba40ec7238b@192.168.0.8' of Request 102: Match Found Aug 9 14:27:19 DEBUG[8110] rtp.c: Ooh, format changed from unknown to g729 Aug 9 14:27:19 DEBUG[6427] chan_sip.c: Checking device state for peer 705 Aug 9 14:27:19 DEBUG[6427] chan_sip.c: Checking device state for peer 874&SIP/700&SIP/701&SIP/703&SIP/704&SIP/705 Aug 9 14:27:19 VERBOSE[6427] logger.c: Reliably Transmitting (no NAT) to 192.168.255.79:5060: NOTIFY sip:822@192.168.255.79 SIP/2.0 Via: SIP/2.0/UDP 192.168.255.1:5060;branch=z9hG4bK7e4863c5 From: ;tag=as45233269 To: "Laetitia van Rijsbergen" ;tag=e7d1c9576b22d460 Contact: Call-ID: 8a287f2d002a7084@192.168.255.79 CSeq: 124 NOTIFY User-Agent: Asterisk PBX Max-Forwards: 70 Event: dialog Content-Type: application/dialog-info+xml Subscription-State: active Content-Length: 211

early

--- Aug 9 14:27:19 DEBUG[6427] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #364692 Aug 9 14:27:19 VERBOSE[6427] logger.c: Extension Changed 874 new state InUse&Ringing for Notify User 822 Aug 9 14:27:19 DEBUG[6427] chan_sip.c: Checking device state for peer 874&SIP/700&SIP/701&SIP/703&SIP/704&SIP/705 Aug 9 14:27:19 VERBOSE[6427] logger.c: Reliably Transmitting (no NAT) to 192.168.255.70:2051: NOTIFY sip:888@allium.gilze.global-t.nl SIP/2.0 Via: SIP/2.0/UDP 192.168.255.1:5060;branch=z9hG4bK3420c7f6 From: ;tag=as268c3087 To: ;tag=9gk18xrxm7 Contact: Call-ID: 3c267026668a-vkkokdwfsz66@snom360-0004132310B4 CSeq: 322 NOTIFY User-Agent: Asterisk PBX Max-Forwards: 70 Event: dialog Content-Type: application/dialog-info+xml Subscription-State: active Content-Length: 212

early

--- Aug 9 14:27:19 DEBUG[6427] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #364693 Aug 9 14:27:19 VERBOSE[6427] logger.c: Extension Changed 874 new state InUse&Ringing for Notify User 888 Aug 9 14:27:19 DEBUG[6427] chan_sip.c: Checking device state for peer 874&SIP/700&SIP/701&SIP/703&SIP/704&SIP/705 Aug 9 14:27:19 VERBOSE[6427] logger.c: Reliably Transmitting (no NAT) to 192.168.255.91:5060: NOTIFY sip:826@192.168.255.91 SIP/2.0 Via: SIP/2.0/UDP 192.168.255.1:5060;branch=z9hG4bK3e045459 From: ;tag=as654cf311 To: "Ron van Engelen" ;tag=5ff906d3193d7bd3 Contact: Call-ID: 3ae34e7184d831fb@192.168.255.91 CSeq: 436 NOTIFY User-Agent: Asterisk PBX Max-Forwards: 70 Event: dialog Content-Type: application/dialog-info+xml Subscription-State: active Content-Length: 212

early

--- Aug 9 14:27:19 DEBUG[6427] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #364694 Aug 9 14:27:19 VERBOSE[6427] logger.c: Extension Changed 874 new state InUse&Ringing for Notify User 826 Aug 9 14:27:19 DEBUG[6427] chan_sip.c: Checking device state for peer 874&SIP/700&SIP/701&SIP/703&SIP/704&SIP/705 Aug 9 14:27:19 VERBOSE[6427] logger.c: Reliably Transmitting (no NAT) to 192.168.255.90:5060: NOTIFY sip:823@192.168.255.90 SIP/2.0 Via: SIP/2.0/UDP 192.168.255.1:5060;branch=z9hG4bK7ef7385d From: ;tag=as67ecc51f To: "Alfred Daanen" ;tag=f258829930f48e4c Contact: Call-ID: 553c654628b3d9f1@192.168.255.90 CSeq: 393 NOTIFY User-Agent: Asterisk PBX Max-Forwards: 70 Event: dialog Content-Type: application/dialog-info+xml Subscription-State: active Content-Length: 212

early

--- Aug 9 14:27:19 DEBUG[6427] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #364695 Aug 9 14:27:19 VERBOSE[6427] logger.c: Extension Changed 874 new state InUse&Ringing for Notify User 823 Aug 9 14:27:19 DEBUG[6427] chan_sip.c: Checking device state for peer 704 Aug 9 14:27:19 DEBUG[6427] devicestate.c: Changing state for SIP/704 - state 1 (Not in use) Aug 9 14:27:19 DEBUG[6427] chan_sip.c: Checking device state for peer 874 Aug 9 14:27:19 DEBUG[6427] chan_sip.c: Checking device state for peer 700 Aug 9 14:27:19 DEBUG[6427] chan_sip.c: Checking device state for peer 701 Aug 9 14:27:19 DEBUG[6427] chan_sip.c: Checking device state for peer 703 Aug 9 14:27:19 DEBUG[6427] chan_sip.c: Checking device state for peer 704 Aug 9 14:27:19 DEBUG[6427] chan_sip.c: Checking device state for peer 705 Aug 9 14:27:19 DEBUG[6427] chan_sip.c: Checking device state for peer 874&SIP/700&SIP/701&SIP/703&SIP/704&SIP/705 Aug 9 14:27:19 DEBUG[8118] app_queue.c: Device 'SIP/704' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. Aug 9 14:27:19 VERBOSE[6438] logger.c: <-- SIP read from 192.168.255.79:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.255.1:5060;branch=z9hG4bK7e4863c5 From: ;tag=as45233269 To: "Laetitia van Rijsbergen" ;tag=e7d1c9576b22d460 Call-ID: 8a287f2d002a7084@192.168.255.79 CSeq: 124 NOTIFY User-Agent: Grandstream GXP2000 1.0.2.13 Contact: Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK Supported: replaces, timer Content-Length: 0 Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 0: SIP/2.0 200 OK (14) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.255.1:5060;branch=z9hG4bK7e4863c5 (58) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 2: From: ;tag=as45233269 (66) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 3: To: "Laetitia van Rijsbergen" ;tag=e7d1c9576b22d460 (85) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 4: Call-ID: 8a287f2d002a7084@192.168.255.79 (40) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 5: CSeq: 124 NOTIFY (16) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 6: User-Agent: Grandstream GXP2000 1.0.2.13 (40) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 7: Contact: (33) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 8: Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK (77) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 9: Supported: replaces, timer (26) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 10: Content-Length: 0 (17) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 11: (0) Aug 9 14:27:19 VERBOSE[6438] logger.c: --- (11 headers 0 lines)Aug 9 14:27:19 VERBOSE[6438] logger.c: --- (11 headers 0 lines)--- Aug 9 14:27:19 DEBUG[6438] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #364692 Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Stopping retransmission on '8a287f2d002a7084@192.168.255.79' of Request 124: Match Found Aug 9 14:27:19 VERBOSE[6427] logger.c: Reliably Transmitting (no NAT) to 192.168.255.79:5060: NOTIFY sip:822@192.168.255.79 SIP/2.0 Via: SIP/2.0/UDP 192.168.255.1:5060;branch=z9hG4bK258bc704 From: ;tag=as45233269 To: "Laetitia van Rijsbergen" ;tag=e7d1c9576b22d460 Contact: Call-ID: 8a287f2d002a7084@192.168.255.79 CSeq: 125 NOTIFY User-Agent: Asterisk PBX Max-Forwards: 70 Event: dialog Content-Type: application/dialog-info+xml Subscription-State: active Content-Length: 215

confirmed

--- Aug 9 14:27:19 DEBUG[6427] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #364696 Aug 9 14:27:19 VERBOSE[6427] logger.c: Extension Changed 874 new state InUse for Notify User 822 Aug 9 14:27:19 DEBUG[6427] chan_sip.c: Checking device state for peer 874&SIP/700&SIP/701&SIP/703&SIP/704&SIP/705 Aug 9 14:27:19 VERBOSE[6427] logger.c: Reliably Transmitting (no NAT) to 192.168.255.70:2051: NOTIFY sip:888@allium.gilze.global-t.nl SIP/2.0 Via: SIP/2.0/UDP 192.168.255.1:5060;branch=z9hG4bK56954793 From: ;tag=as268c3087 To: ;tag=9gk18xrxm7 Contact: Call-ID: 3c267026668a-vkkokdwfsz66@snom360-0004132310B4 CSeq: 323 NOTIFY User-Agent: Asterisk PBX Max-Forwards: 70 Event: dialog Content-Type: application/dialog-info+xml Subscription-State: active Content-Length: 216

confirmed

--- Aug 9 14:27:19 DEBUG[6427] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #364697 Aug 9 14:27:19 VERBOSE[6427] logger.c: Extension Changed 874 new state InUse for Notify User 888 Aug 9 14:27:19 DEBUG[6427] chan_sip.c: Checking device state for peer 874&SIP/700&SIP/701&SIP/703&SIP/704&SIP/705 Aug 9 14:27:19 VERBOSE[6438] logger.c: <-- SIP read from 192.168.255.91:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.255.1:5060;branch=z9hG4bK3e045459 From: ;tag=as654cf311 To: "Ron van Engelen" ;tag=5ff906d3193d7bd3 Call-ID: 3ae34e7184d831fb@192.168.255.91 CSeq: 436 NOTIFY User-Agent: Grandstream GXP2000 1.1.0.11 Contact: Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK Supported: replaces, timer Content-Length: 0 Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 0: SIP/2.0 200 OK (14) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.255.1:5060;branch=z9hG4bK3e045459 (58) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 2: From: ;tag=as654cf311 (66) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 3: To: "Ron van Engelen" ;tag=5ff906d3193d7bd3 (88) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 4: Call-ID: 3ae34e7184d831fb@192.168.255.91 (40) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 5: CSeq: 436 NOTIFY (16) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 6: User-Agent: Grandstream GXP2000 1.1.0.11 (40) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 7: Contact: (44) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 8: Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK (77) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 9: Supported: replaces, timer (26) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 10: Content-Length: 0 (17) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 11: (0) Aug 9 14:27:19 VERBOSE[6427] logger.c: Reliably Transmitting (no NAT) to 192.168.255.91:5060: NOTIFY sip:826@192.168.255.91 SIP/2.0 Via: SIP/2.0/UDP 192.168.255.1:5060;branch=z9hG4bK4f78f7a9 From: ;tag=as654cf311 To: "Ron van Engelen" ;tag=5ff906d3193d7bd3 Contact: Call-ID: 3ae34e7184d831fb@192.168.255.91 CSeq: 437 NOTIFY User-Agent: Asterisk PBX Max-Forwards: 70 Event: dialog Content-Type: application/dialog-info+xml Subscription-State: active Content-Length: 216

confirmed

--- Aug 9 14:27:19 DEBUG[6427] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #364698 Aug 9 14:27:19 VERBOSE[6438] logger.c: --- (11 headers 0 lines)Aug 9 14:27:19 VERBOSE[6438] logger.c: --- (11 headers 0 lines)--- Aug 9 14:27:19 VERBOSE[6427] logger.c: Extension Changed 874 new state InUse for Notify User 826 Aug 9 14:27:19 DEBUG[6438] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #364694 Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Stopping retransmission on '3ae34e7184d831fb@192.168.255.91' of Request 436: Match Found Aug 9 14:27:19 DEBUG[6427] chan_sip.c: Checking device state for peer 874&SIP/700&SIP/701&SIP/703&SIP/704&SIP/705 Aug 9 14:27:19 VERBOSE[6427] logger.c: Reliably Transmitting (no NAT) to 192.168.255.90:5060: NOTIFY sip:823@192.168.255.90 SIP/2.0 Via: SIP/2.0/UDP 192.168.255.1:5060;branch=z9hG4bK29feb0a6 From: ;tag=as67ecc51f To: "Alfred Daanen" ;tag=f258829930f48e4c Contact: Call-ID: 553c654628b3d9f1@192.168.255.90 CSeq: 394 NOTIFY User-Agent: Asterisk PBX Max-Forwards: 70 Event: dialog Content-Type: application/dialog-info+xml Subscription-State: active Content-Length: 216

confirmed

--- Aug 9 14:27:19 DEBUG[6427] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #364699 Aug 9 14:27:19 VERBOSE[6427] logger.c: Extension Changed 874 new state InUse for Notify User 823 Aug 9 14:27:19 DEBUG[6427] chan_sip.c: Checking device state for peer 701 Aug 9 14:27:19 DEBUG[6427] devicestate.c: Changing state for SIP/701 - state 1 (Not in use) Aug 9 14:27:19 DEBUG[6427] chan_sip.c: Checking device state for peer 874 Aug 9 14:27:19 DEBUG[6427] chan_sip.c: Checking device state for peer 700 Aug 9 14:27:19 DEBUG[6427] chan_sip.c: Checking device state for peer 701 Aug 9 14:27:19 DEBUG[6427] chan_sip.c: Checking device state for peer 703 Aug 9 14:27:19 DEBUG[6427] chan_sip.c: Checking device state for peer 704 Aug 9 14:27:19 DEBUG[6427] chan_sip.c: Checking device state for peer 705 Aug 9 14:27:19 DEBUG[6427] chan_sip.c: Checking device state for peer 706 Aug 9 14:27:19 DEBUG[6427] devicestate.c: Changing state for SIP/706 - state 2 (In use) Aug 9 14:27:19 DEBUG[6427] chan_sip.c: Checking device state for peer 706 Aug 9 14:27:19 DEBUG[8119] app_queue.c: Device 'SIP/701' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. Aug 9 14:27:19 DEBUG[8120] app_queue.c: Device 'SIP/706' changed to state '2' (In use) but we don't care because they're not a member of any queue. Aug 9 14:27:19 VERBOSE[6438] logger.c: <-- SIP read from 192.168.255.79:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.255.1:5060;branch=z9hG4bK258bc704 From: ;tag=as45233269 To: "Laetitia van Rijsbergen" ;tag=e7d1c9576b22d460 Call-ID: 8a287f2d002a7084@192.168.255.79 CSeq: 125 NOTIFY User-Agent: Grandstream GXP2000 1.0.2.13 Contact: Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK Supported: replaces, timer Content-Length: 0 Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 0: SIP/2.0 200 OK (14) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.255.1:5060;branch=z9hG4bK258bc704 (58) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 2: From: ;tag=as45233269 (66) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 3: To: "Laetitia van Rijsbergen" ;tag=e7d1c9576b22d460 (85) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 4: Call-ID: 8a287f2d002a7084@192.168.255.79 (40) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 5: CSeq: 125 NOTIFY (16) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 6: User-Agent: Grandstream GXP2000 1.0.2.13 (40) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 7: Contact: (33) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 8: Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK (77) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 9: Supported: replaces, timer (26) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 10: Content-Length: 0 (17) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 11: (0) Aug 9 14:27:19 VERBOSE[6438] logger.c: --- (11 headers 0 lines)Aug 9 14:27:19 VERBOSE[6438] logger.c: --- (11 headers 0 lines)--- Aug 9 14:27:19 DEBUG[6438] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #364696 Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Stopping retransmission on '8a287f2d002a7084@192.168.255.79' of Request 125: Match Found Aug 9 14:27:19 VERBOSE[6438] logger.c: <-- SIP read from 192.168.255.91:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.255.1:5060;branch=z9hG4bK4f78f7a9 From: ;tag=as654cf311 To: "Ron van Engelen" ;tag=5ff906d3193d7bd3 Call-ID: 3ae34e7184d831fb@192.168.255.91 CSeq: 437 NOTIFY User-Agent: Grandstream GXP2000 1.1.0.11 Contact: Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK Supported: replaces, timer Content-Length: 0 Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 0: SIP/2.0 200 OK (14) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.255.1:5060;branch=z9hG4bK4f78f7a9 (58) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 2: From: ;tag=as654cf311 (66) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 3: To: "Ron van Engelen" ;tag=5ff906d3193d7bd3 (88) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 4: Call-ID: 3ae34e7184d831fb@192.168.255.91 (40) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 5: CSeq: 437 NOTIFY (16) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 6: User-Agent: Grandstream GXP2000 1.1.0.11 (40) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 7: Contact: (44) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 8: Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK (77) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 9: Supported: replaces, timer (26) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 10: Content-Length: 0 (17) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 11: (0) Aug 9 14:27:19 VERBOSE[6438] logger.c: --- (11 headers 0 lines)Aug 9 14:27:19 VERBOSE[6438] logger.c: --- (11 headers 0 lines)--- Aug 9 14:27:19 DEBUG[6438] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #364698 Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Stopping retransmission on '3ae34e7184d831fb@192.168.255.91' of Request 437: Match Found Aug 9 14:27:19 VERBOSE[6438] logger.c: <-- SIP read from 192.168.255.90:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.255.1:5060;branch=z9hG4bK7ef7385d From: ;tag=as67ecc51f To: "Alfred Daanen" ;tag=f258829930f48e4c Call-ID: 553c654628b3d9f1@192.168.255.90 CSeq: 393 NOTIFY User-Agent: Grandstream GXP2000 1.1.0.11 Contact: Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK Supported: replaces, timer Content-Length: 0 Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 0: SIP/2.0 200 OK (14) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.255.1:5060;branch=z9hG4bK7ef7385d (58) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 2: From: ;tag=as67ecc51f (66) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 3: To: "Alfred Daanen" ;tag=f258829930f48e4c (86) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 4: Call-ID: 553c654628b3d9f1@192.168.255.90 (40) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 5: CSeq: 393 NOTIFY (16) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 6: User-Agent: Grandstream GXP2000 1.1.0.11 (40) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 7: Contact: (44) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 8: Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK (77) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 9: Supported: replaces, timer (26) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 10: Content-Length: 0 (17) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 11: (0) Aug 9 14:27:19 VERBOSE[6438] logger.c: --- (11 headers 0 lines)Aug 9 14:27:19 VERBOSE[6438] logger.c: --- (11 headers 0 lines)--- Aug 9 14:27:19 DEBUG[6438] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #364695 Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Stopping retransmission on '553c654628b3d9f1@192.168.255.90' of Request 393: Match Found Aug 9 14:27:19 VERBOSE[6438] logger.c: <-- SIP read from 192.168.255.70:2051: SIP/2.0 200 Ok Via: SIP/2.0/UDP 192.168.255.1:5060;branch=z9hG4bK3420c7f6 From: ;tag=as268c3087 To: ;tag=9gk18xrxm7 Call-ID: 3c267026668a-vkkokdwfsz66@snom360-0004132310B4 CSeq: 322 NOTIFY Content-Length: 0 Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 0: SIP/2.0 200 Ok (14) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.255.1:5060;branch=z9hG4bK3420c7f6 (58) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 2: From: ;tag=as268c3087 (55) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 3: To: ;tag=9gk18xrxm7 (53) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 4: Call-ID: 3c267026668a-vkkokdwfsz66@snom360-0004132310B4 (55) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 5: CSeq: 322 NOTIFY (16) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 6: Content-Length: 0 (17) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 7: (0) Aug 9 14:27:19 VERBOSE[6438] logger.c: --- (7 headers 0 lines)Aug 9 14:27:19 VERBOSE[6438] logger.c: --- (7 headers 0 lines)--- Aug 9 14:27:19 DEBUG[6438] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #364693 Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Stopping retransmission on '3c267026668a-vkkokdwfsz66@snom360-0004132310B4' of Request 322: Match Found Aug 9 14:27:19 VERBOSE[6438] logger.c: <-- SIP read from 192.168.255.90:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.255.1:5060;branch=z9hG4bK29feb0a6 From: ;tag=as67ecc51f To: "Alfred Daanen" ;tag=f258829930f48e4c Call-ID: 553c654628b3d9f1@192.168.255.90 CSeq: 394 NOTIFY User-Agent: Grandstream GXP2000 1.1.0.11 Contact: Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK Supported: replaces, timer Content-Length: 0 Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 0: SIP/2.0 200 OK (14) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.255.1:5060;branch=z9hG4bK29feb0a6 (58) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 2: From: ;tag=as67ecc51f (66) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 3: To: "Alfred Daanen" ;tag=f258829930f48e4c (86) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 4: Call-ID: 553c654628b3d9f1@192.168.255.90 (40) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 5: CSeq: 394 NOTIFY (16) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 6: User-Agent: Grandstream GXP2000 1.1.0.11 (40) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 7: Contact: (44) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 8: Allow: INVITE,ACK,CANCEL,BYE,NOTIFY,REFER,OPTIONS,INFO,SUBSCRIBE,UPDATE,PRACK (77) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 9: Supported: replaces, timer (26) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 10: Content-Length: 0 (17) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 11: (0) Aug 9 14:27:19 VERBOSE[6438] logger.c: --- (11 headers 0 lines)Aug 9 14:27:19 VERBOSE[6438] logger.c: --- (11 headers 0 lines)--- Aug 9 14:27:19 DEBUG[6438] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #364699 Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Stopping retransmission on '553c654628b3d9f1@192.168.255.90' of Request 394: Match Found Aug 9 14:27:19 DEBUG[8110] rtp.c: Ooh, format changed from unknown to g729 Aug 9 14:27:19 VERBOSE[6438] logger.c: <-- SIP read from 192.168.255.70:2051: SIP/2.0 200 Ok Via: SIP/2.0/UDP 192.168.255.1:5060;branch=z9hG4bK56954793 From: ;tag=as268c3087 To: ;tag=9gk18xrxm7 Call-ID: 3c267026668a-vkkokdwfsz66@snom360-0004132310B4 CSeq: 323 NOTIFY Content-Length: 0 Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 0: SIP/2.0 200 Ok (14) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.255.1:5060;branch=z9hG4bK56954793 (58) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 2: From: ;tag=as268c3087 (55) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 3: To: ;tag=9gk18xrxm7 (53) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 4: Call-ID: 3c267026668a-vkkokdwfsz66@snom360-0004132310B4 (55) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 5: CSeq: 323 NOTIFY (16) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 6: Content-Length: 0 (17) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 7: (0) Aug 9 14:27:19 VERBOSE[6438] logger.c: --- (7 headers 0 lines)Aug 9 14:27:19 VERBOSE[6438] logger.c: --- (7 headers 0 lines)--- Aug 9 14:27:19 DEBUG[6438] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #364697 Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Stopping retransmission on '3c267026668a-vkkokdwfsz66@snom360-0004132310B4' of Request 323: Match Found Aug 9 14:27:19 DEBUG[6438] chan_sip.c: SIP TIMER: Not rescheduling id #364669:OPTIONS (Method 3) (No timer T1) Aug 9 14:27:19 VERBOSE[6438] logger.c: Retransmitting #3 (no NAT) to 192.168.255.63:5061: OPTIONS sip:192.168.255.63:5061 SIP/2.0 Via: SIP/2.0/UDP 192.168.255.1:5060;branch=z9hG4bK48e058e5;rport From: "Unknown" ;tag=as44551689 To: Contact: Call-ID: 618584de7626d356126747b20993906a@192.168.255.1 CSeq: 102 OPTIONS User-Agent: Asterisk PBX Max-Forwards: 70 Date: Wed, 09 Aug 2006 12:27:16 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Content-Length: 0 --- Aug 9 14:27:19 VERBOSE[6438] logger.c: <-- SIP read from 192.168.0.100:5060: SIP/2.0 487 Request Cancelled Via: SIP/2.0/UDP 192.168.0.8:5060;branch=z9hG4bK786aa9b9 From: "Ronald SoftPhone" ;tag=as57bf173e To: ;tag=86f2e42a5eb072d1 Call-ID: 6c56f8ae4f10281e06f1dba40ec7238b@192.168.0.8 CSeq: 102 INVITE User-Agent: Grandstream HT286 1.0.6.7 Content-Length: 0 Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 0: SIP/2.0 487 Request Cancelled (29) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.0.8:5060;branch=z9hG4bK786aa9b9 (56) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 2: From: "Ronald SoftPhone" ;tag=as57bf173e (61) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 3: To: ;tag=86f2e42a5eb072d1 (59) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 4: Call-ID: 6c56f8ae4f10281e06f1dba40ec7238b@192.168.0.8 (53) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 5: CSeq: 102 INVITE (16) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 6: User-Agent: Grandstream HT286 1.0.6.7 (37) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 7: Content-Length: 0 (17) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 8: (0) Aug 9 14:27:19 VERBOSE[6438] logger.c: --- (8 headers 0 lines)Aug 9 14:27:19 VERBOSE[6438] logger.c: --- (8 headers 0 lines)--- Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Stopping retransmission on '6c56f8ae4f10281e06f1dba40ec7238b@192.168.0.8' of Request 102: Match Not Found Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Updating call counter for outgoing call Aug 9 14:27:19 VERBOSE[6438] logger.c: Transmitting (no NAT) to 192.168.0.100:5060: ACK sip:701@192.168.0.100;user=phone SIP/2.0 Via: SIP/2.0/UDP 192.168.0.8:5060;branch=z9hG4bK786aa9b9 From: "Ronald SoftPhone" ;tag=as57bf173e To: ;tag=86f2e42a5eb072d1 Contact: Call-ID: 6c56f8ae4f10281e06f1dba40ec7238b@192.168.0.8 CSeq: 102 ACK User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- Aug 9 14:27:19 VERBOSE[6438] logger.c: Destroying call '6c56f8ae4f10281e06f1dba40ec7238b@192.168.0.8' Aug 9 14:27:19 VERBOSE[6438] logger.c: <-- SIP read from 192.168.0.149:5060: SIP/2.0 200 OK Via: SIP/2.0/UDP 192.168.0.8:5060;branch=z9hG4bK02a33be9 From: "Ronald SoftPhone" ;tag=as3350cd6f To: ;tag=1064250115 Call-ID: 18ff89ba1541988c295b7cdc30986bc0@192.168.0.8 CSeq: 102 CANCEL Content-Length: 0 Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 0: SIP/2.0 200 OK (14) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.0.8:5060;branch=z9hG4bK02a33be9 (56) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 2: From: "Ronald SoftPhone" ;tag=as3350cd6f (61) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 3: To: ;tag=1064250115 (42) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 4: Call-ID: 18ff89ba1541988c295b7cdc30986bc0@192.168.0.8 (53) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 5: CSeq: 102 CANCEL (16) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 6: Content-Length: 0 (17) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 7: (0) Aug 9 14:27:19 VERBOSE[6438] logger.c: --- (7 headers 0 lines)Aug 9 14:27:19 VERBOSE[6438] logger.c: --- (7 headers 0 lines)--- Aug 9 14:27:19 DEBUG[6438] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #364687 Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Stopping retransmission on '18ff89ba1541988c295b7cdc30986bc0@192.168.0.8' of Request 102: Match Found Aug 9 14:27:19 VERBOSE[6438] logger.c: <-- SIP read from 192.168.0.149:5060: SIP/2.0 487 Request Terminated Via: SIP/2.0/UDP 192.168.0.8:5060;branch=z9hG4bK02a33be9 From: "Ronald SoftPhone" ;tag=as3350cd6f To: ;tag=1064250115 Call-ID: 18ff89ba1541988c295b7cdc30986bc0@192.168.0.8 CSeq: 102 INVITE Content-Length: 0 Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 0: SIP/2.0 487 Request Terminated (30) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.0.8:5060;branch=z9hG4bK02a33be9 (56) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 2: From: "Ronald SoftPhone" ;tag=as3350cd6f (61) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 3: To: ;tag=1064250115 (42) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 4: Call-ID: 18ff89ba1541988c295b7cdc30986bc0@192.168.0.8 (53) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 5: CSeq: 102 INVITE (16) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 6: Content-Length: 0 (17) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 7: (0) Aug 9 14:27:19 VERBOSE[6438] logger.c: --- (7 headers 0 lines)Aug 9 14:27:19 VERBOSE[6438] logger.c: --- (7 headers 0 lines)--- Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Stopping retransmission on '18ff89ba1541988c295b7cdc30986bc0@192.168.0.8' of Request 102: Match Not Found Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Updating call counter for outgoing call Aug 9 14:27:19 VERBOSE[6438] logger.c: Transmitting (no NAT) to 192.168.0.149:5060: ACK sip:704@192.168.0.149 SIP/2.0 Via: SIP/2.0/UDP 192.168.0.8:5060;branch=z9hG4bK02a33be9 From: "Ronald SoftPhone" ;tag=as3350cd6f To: ;tag=1064250115 Contact: Call-ID: 18ff89ba1541988c295b7cdc30986bc0@192.168.0.8 CSeq: 102 ACK User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- Aug 9 14:27:19 VERBOSE[6438] logger.c: Destroying call '18ff89ba1541988c295b7cdc30986bc0@192.168.0.8' Aug 9 14:27:19 VERBOSE[6438] logger.c: <-- SIP read from 192.168.0.131:18856: ACK sip:874@192.168.0.8 SIP/2.0 Via: SIP/2.0/UDP 192.168.0.131:18856;branch=z9hG4bK-d87543-1402ab41042d3d42-1--d87543-;rport Max-Forwards: 70 Contact: To: "874";tag=as77a12ac8 From: "Ronald Voermans";tag=5706bb26 Call-ID: 0d300a0d53359e6aYjllMDdiMDg1OGJhNzA5NWIwOGI5MjJhZDhhZGQ2ZmU. CSeq: 2 ACK Proxy-Authorization: Digest username="706",realm="asterisk",nonce="5c88a441",uri="sip:874@192.168.0.8",response="19cbd0fa7ac0f4a382b1856014e62043",algorithm=MD5 User-Agent: eyeBeam release 1003s stamp 31159 Content-Length: 0 Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 0: ACK sip:874@192.168.0.8 SIP/2.0 (31) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.0.131:18856;branch=z9hG4bK-d87543-1402ab41042d3d42-1--d87543-;rport (92) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 2: Max-Forwards: 70 (16) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 3: Contact: (38) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 4: To: "874";tag=as77a12ac8 (45) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 5: From: "Ronald Voermans";tag=5706bb26 (57) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 6: Call-ID: 0d300a0d53359e6aYjllMDdiMDg1OGJhNzA5NWIwOGI5MjJhZDhhZGQ2ZmU. (69) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 7: CSeq: 2 ACK (11) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 8: Proxy-Authorization: Digest username="706",realm="asterisk",nonce="5c88a441",uri="sip:874@192.168.0.8",response="19cbd0fa7ac0f4a382b1856014e62043",algorithm=MD5 (160) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 9: User-Agent: eyeBeam release 1003s stamp 31159 (45) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 10: Content-Length: 0 (17) Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Header 11: (0) Aug 9 14:27:19 VERBOSE[6438] logger.c: --- (11 headers 0 lines)Aug 9 14:27:19 VERBOSE[6438] logger.c: --- (11 headers 0 lines)--- Aug 9 14:27:19 DEBUG[6438] chan_sip.c: **** Received ACK (6) - Command in SIP ACK Aug 9 14:27:19 DEBUG[6438] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #364691 Aug 9 14:27:19 DEBUG[6438] chan_sip.c: Stopping retransmission on '0d300a0d53359e6aYjllMDdiMDg1OGJhNzA5NWIwOGI5MjJhZDhhZGQ2ZmU.' of Response 2: Match Found Aug 9 14:27:20 DEBUG[6438] chan_sip.c: SIP TIMER: Not rescheduling id #364669:OPTIONS (Method 3) (No timer T1) Aug 9 14:27:20 VERBOSE[6438] logger.c: Retransmitting #4 (no NAT) to 192.168.255.63:5061: OPTIONS sip:192.168.255.63:5061 SIP/2.0 Via: SIP/2.0/UDP 192.168.255.1:5060;branch=z9hG4bK48e058e5;rport From: "Unknown" ;tag=as44551689 To: Contact: Call-ID: 618584de7626d356126747b20993906a@192.168.255.1 CSeq: 102 OPTIONS User-Agent: Asterisk PBX Max-Forwards: 70 Date: Wed, 09 Aug 2006 12:27:16 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Content-Length: 0 --- Aug 9 14:27:20 VERBOSE[6438] logger.c: Destroying call '618584de7626d356126747b20993906a@192.168.255.1' Aug 9 14:27:20 DEBUG[6427] chan_sip.c: Checking device state for peer gsm_spa Aug 9 14:27:20 DEBUG[6427] devicestate.c: Changing state for SIP/gsm_spa - state 1 (Not in use) Aug 9 14:27:20 DEBUG[8121] app_queue.c: Device 'SIP/gsm_spa' changed to state '1' (Not in use) but we don't care because they're not a member of any queue. Aug 9 14:27:21 VERBOSE[6438] logger.c: <-- SIP read from 192.168.255.77:5062: Aug 9 14:27:21 VERBOSE[6438] logger.c: --- (0 headers 0 lines)Aug 9 14:27:21 VERBOSE[6438] logger.c: --- (0 headers 0 lines) Nat keepalive Aug 9 14:27:21 VERBOSE[6438] logger.c: --- (0 headers 0 lines) Nat keepalive --- Aug 9 14:27:22 DEBUG[8110] rtp.c: Got RTCP report of 176 bytes Aug 9 14:27:24 DEBUG[8110] rtp.c: Got RTCP report of 108 bytes Aug 9 14:27:25 VERBOSE[6438] logger.c: <-- SIP read from 192.168.255.78:5060: Aug 9 14:27:25 VERBOSE[6438] logger.c: --- (0 headers 0 lines)Aug 9 14:27:25 VERBOSE[6438] logger.c: --- (0 headers 0 lines) Nat keepalive Aug 9 14:27:25 VERBOSE[6438] logger.c: --- (0 headers 0 lines) Nat keepalive --- Aug 9 14:27:25 VERBOSE[6438] logger.c: <-- SIP read from 192.168.255.67:5060: Aug 9 14:27:25 VERBOSE[6438] logger.c: --- (0 headers 0 lines)Aug 9 14:27:25 VERBOSE[6438] logger.c: --- (0 headers 0 lines) Nat keepalive Aug 9 14:27:25 VERBOSE[6438] logger.c: --- (0 headers 0 lines) Nat keepalive --- Aug 9 14:27:25 DEBUG[8110] rtp.c: Got RTCP report of 44 bytes Aug 9 14:27:25 DEBUG[8110] rtp.c: Got RTCP report of 176 bytes Aug 9 14:27:27 VERBOSE[6438] logger.c: <-- SIP read from 192.168.255.68:5060: Aug 9 14:27:27 VERBOSE[6438] logger.c: --- (0 headers 0 lines)Aug 9 14:27:27 VERBOSE[6438] logger.c: --- (0 headers 0 lines) Nat keepalive Aug 9 14:27:27 VERBOSE[6438] logger.c: --- (0 headers 0 lines) Nat keepalive --- Aug 9 14:27:28 DEBUG[8110] rtp.c: Got RTCP report of 176 bytes Aug 9 14:27:29 DEBUG[8110] rtp.c: Got RTCP report of 108 bytes Aug 9 14:27:30 DEBUG[6438] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP) Aug 9 14:27:30 DEBUG[6438] chan_sip.c: Header 0: OPTIONS sip:192.168.255.63:5061 SIP/2.0 (39) Aug 9 14:27:30 DEBUG[6438] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.255.1:5060;branch=z9hG4bK33f43f92;rport (64) Aug 9 14:27:30 DEBUG[6438] chan_sip.c: Header 2: From: "Unknown" ;tag=as6bf94582 (58) Aug 9 14:27:30 DEBUG[6438] chan_sip.c: Header 3: To: (29) Aug 9 14:27:30 DEBUG[6438] chan_sip.c: Header 4: Contact: (36) Aug 9 14:27:30 DEBUG[6438] chan_sip.c: Header 5: Call-ID: 171098c2311ba8040dbc7b2803cc7497@192.168.255.1 (55) Aug 9 14:27:30 DEBUG[6438] chan_sip.c: Header 6: CSeq: 102 OPTIONS (17) Aug 9 14:27:30 DEBUG[6438] chan_sip.c: Header 7: User-Agent: Asterisk PBX (24) Aug 9 14:27:30 DEBUG[6438] chan_sip.c: Header 8: Max-Forwards: 70 (16) Aug 9 14:27:30 DEBUG[6438] chan_sip.c: Header 9: Date: Wed, 09 Aug 2006 12:27:30 GMT (35) Aug 9 14:27:30 DEBUG[6438] chan_sip.c: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) Aug 9 14:27:30 DEBUG[6438] chan_sip.c: Header 11: Content-Length: 0 (17) Aug 9 14:27:30 DEBUG[6438] chan_sip.c: Header 12: (0) Aug 9 14:27:30 VERBOSE[6438] logger.c: 12 headers, 0 lines Aug 9 14:27:30 VERBOSE[6438] logger.c: Reliably Transmitting (no NAT) to 192.168.255.63:5061: OPTIONS sip:192.168.255.63:5061 SIP/2.0 Via: SIP/2.0/UDP 192.168.255.1:5060;branch=z9hG4bK33f43f92;rport From: "Unknown" ;tag=as6bf94582 To: Contact: Call-ID: 171098c2311ba8040dbc7b2803cc7497@192.168.255.1 CSeq: 102 OPTIONS User-Agent: Asterisk PBX Max-Forwards: 70 Date: Wed, 09 Aug 2006 12:27:30 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Content-Length: 0 --- Aug 9 14:27:30 DEBUG[6438] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #364701 Aug 9 14:27:31 VERBOSE[6438] logger.c: <-- SIP read from 192.168.255.77:5060: Aug 9 14:27:31 VERBOSE[6438] logger.c: --- (0 headers 0 lines)Aug 9 14:27:31 VERBOSE[6438] logger.c: --- (0 headers 0 lines) Nat keepalive Aug 9 14:27:31 VERBOSE[6438] logger.c: --- (0 headers 0 lines) Nat keepalive --- Aug 9 14:27:31 DEBUG[8110] rtp.c: Got RTCP report of 44 bytes Aug 9 14:27:31 DEBUG[6438] chan_sip.c: SIP TIMER: Not rescheduling id #364701:OPTIONS (Method 3) (No timer T1) Aug 9 14:27:31 VERBOSE[6438] logger.c: Retransmitting #1 (no NAT) to 192.168.255.63:5061: OPTIONS sip:192.168.255.63:5061 SIP/2.0 Via: SIP/2.0/UDP 192.168.255.1:5060;branch=z9hG4bK33f43f92;rport From: "Unknown" ;tag=as6bf94582 To: Contact: Call-ID: 171098c2311ba8040dbc7b2803cc7497@192.168.255.1 CSeq: 102 OPTIONS User-Agent: Asterisk PBX Max-Forwards: 70 Date: Wed, 09 Aug 2006 12:27:30 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Content-Length: 0 --- Aug 9 14:27:31 DEBUG[8110] rtp.c: Got RTCP report of 176 bytes Aug 9 14:27:32 VERBOSE[6438] logger.c: <-- SIP read from 192.168.255.40:5060: REFER sip:70@192.168.255.1 SIP/2.0 Via: SIP/2.0/UDP 192.168.255.40:5060;branch=z9hG4bK6818137570870321421 From: ;tag=c0a80101-39de4a To: Call-ID: 209beb1-c0a80101-a-26@192.168.255.40 CSeq: 1 REFER Max-Forwards: 70 Referred-By: Refer-To: Contact: User-Agent: THOMSON ST2030 hw0 fw1.47 00-0E-50-4E-B8-6F Content-Length: 0 Aug 9 14:27:32 DEBUG[6438] chan_sip.c: Header 0: REFER sip:70@192.168.255.1 SIP/2.0 (34) Aug 9 14:27:32 DEBUG[6438] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.255.40:5060;branch=z9hG4bK6818137570870321421 (70) Aug 9 14:27:32 DEBUG[6438] chan_sip.c: Header 2: From: ;tag=c0a80101-39de4a (65) Aug 9 14:27:32 DEBUG[6438] chan_sip.c: Header 3: To: (26) Aug 9 14:27:32 DEBUG[6438] chan_sip.c: Header 4: Call-ID: 209beb1-c0a80101-a-26@192.168.255.40 (45) Aug 9 14:27:32 DEBUG[6438] chan_sip.c: Header 5: CSeq: 1 REFER (13) Aug 9 14:27:32 DEBUG[6438] chan_sip.c: Header 6: Max-Forwards: 70 (16) Aug 9 14:27:32 DEBUG[6438] chan_sip.c: Header 7: Referred-By: (47) Aug 9 14:27:32 DEBUG[6438] chan_sip.c: Header 8: Refer-To: (142) Aug 9 14:27:32 DEBUG[6438] chan_sip.c: Header 9: Contact: (49) Aug 9 14:27:32 DEBUG[6438] chan_sip.c: Header 10: User-Agent: THOMSON ST2030 hw0 fw1.47 00-0E-50-4E-B8-6F (55) Aug 9 14:27:32 DEBUG[6438] chan_sip.c: Header 11: Content-Length: 0 (17) Aug 9 14:27:32 DEBUG[6438] chan_sip.c: Header 12: (0) Aug 9 14:27:32 VERBOSE[6438] logger.c: --- (12 headers 0 lines)Aug 9 14:27:32 VERBOSE[6438] logger.c: --- (12 headers 0 lines)--- Aug 9 14:27:32 DEBUG[6438] chan_sip.c: Allocating new SIP dialog for 209beb1-c0a80101-a-26@192.168.255.40 - REFER (No RTP) Aug 9 14:27:32 DEBUG[6438] chan_sip.c: **** Received REFER (9) - Command in SIP REFER Aug 9 14:27:32 DEBUG[6438] chan_sip.c: SIP call transfer received for call 209beb1-c0a80101-a-26@192.168.255.40 (REFER)! Aug 9 14:27:32 VERBOSE[6438] logger.c: Transfer to 706 in from-internal Aug 9 14:27:32 VERBOSE[6438] logger.c: Transfer from 874 in from-internal Aug 9 14:27:32 DEBUG[6438] chan_sip.c: Assigning Replace-Call-ID Info 772f2db0214039c10a47e0d036ed0456@192.168.255.1 to REPLACE_CALL_ID Aug 9 14:27:32 DEBUG[6438] chan_sip.c: 202 Accepted (supervised) Aug 9 14:27:32 WARNING[6438] chan_sip.c: Transfer attempted without dual ownership? Aug 9 14:27:32 VERBOSE[6438] logger.c: Transmitting (no NAT) to 192.168.255.40:5060: SIP/2.0 202 Accepted Via: SIP/2.0/UDP 192.168.255.40:5060;branch=z9hG4bK6818137570870321421;received=192.168.255.40 From: ;tag=c0a80101-39de4a To: ;tag=as16311f49 Call-ID: 209beb1-c0a80101-a-26@192.168.255.40 CSeq: 1 REFER User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Content-Length: 0 --- Aug 9 14:27:32 NOTICE[6438] chan_sip.c: No field 'Call-ID' present to copy Aug 9 14:27:32 DEBUG[6438] chan_sip.c: Header 0: NOTIFY SIP/2.0 (15) Aug 9 14:27:32 DEBUG[6438] chan_sip.c: Header 1: Via: SIP/2.0/UDP 192.168.255.1:5060;branch=z9hG4bK61ba7e33;rport (64) Aug 9 14:27:32 DEBUG[6438] chan_sip.c: Header 2: From: ;tag=as16311f49 (21) Aug 9 14:27:32 DEBUG[6438] chan_sip.c: Header 3: To: (4) Aug 9 14:27:32 DEBUG[6438] chan_sip.c: Header 4: Contact: (9) Aug 9 14:27:32 DEBUG[6438] chan_sip.c: Header 5: CSeq: 102 NOTIFY (16) Aug 9 14:27:32 DEBUG[6438] chan_sip.c: Header 6: User-Agent: Asterisk PBX (24) Aug 9 14:27:32 DEBUG[6438] chan_sip.c: Header 7: Max-Forwards: 70 (16) Aug 9 14:27:32 DEBUG[6438] chan_sip.c: Header 8: Event: refer;id=1 (17) Aug 9 14:27:32 DEBUG[6438] chan_sip.c: Header 9: Subscription-state: terminated;reason=noresource (48) Aug 9 14:27:32 DEBUG[6438] chan_sip.c: Header 10: Content-Type: message/sipfrag;version=2.0 (41) Aug 9 14:27:32 DEBUG[6438] chan_sip.c: Header 11: Content-Length: 14 (18) Aug 9 14:27:32 DEBUG[6438] chan_sip.c: Header 12: (0) Aug 9 14:27:32 VERBOSE[6438] logger.c: 12 headers, 1 lines Aug 9 14:27:32 VERBOSE[6438] logger.c: Reliably Transmitting (no NAT) to 192.168.255.40:5060: NOTIFY SIP/2.0 Via: SIP/2.0/UDP 192.168.255.1:5060;branch=z9hG4bK61ba7e33;rport From: ;tag=as16311f49 To: Contact: CSeq: 102 NOTIFY User-Agent: Asterisk PBX Max-Forwards: 70 Event: refer;id=1 Subscription-state: terminated;reason=noresource Content-Type: message/sipfrag;version=2.0 Content-Length: 14 SIP/2.0 200 OK --- Aug 9 14:27:32 DEBUG[6438] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #364703 Aug 9 14:27:32 NOTICE[6438] chan_sip.c: No field 'Call-ID' present to copy Aug 9 14:27:32 VERBOSE[6438] logger.c: Reliably Transmitting (no NAT) to 192.168.255.40:5060: BYE SIP/2.0 Via: SIP/2.0/UDP 192.168.255.1:5060;branch=z9hG4bK2d824439;rport From: ;tag=as16311f49 To: ;tag=as16311f49 Contact: CSeq: 103 BYE User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0 --- Aug 9 14:27:32 DEBUG[6438] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #364704 Aug 9 14:27:32 DEBUG[6438] chan_sip.c: SIP TIMER: Not rescheduling id #364701:OPTIONS (Method 3) (No timer T1) Aug 9 14:27:32 VERBOSE[6438] logger.c: Retransmitting #2 (no NAT) to 192.168.255.63:5061: OPTIONS sip:192.168.255.63:5061 SIP/2.0 Via: SIP/2.0/UDP 192.168.255.1:5060;branch=z9hG4bK33f43f92;rport From: "Unknown" ;tag=as6bf94582 To: Contact: Call-ID: 171098c2311ba8040dbc7b2803cc7497@192.168.255.1 CSeq: 102 OPTIONS User-Agent: Asterisk PBX Max-Forwards: 70 Date: Wed, 09 Aug 2006 12:27:30 GMT Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Content-Length: 0 --- Aug 9 14:27:32 DEBUG[6435] chan_iax2.c: Peer lastms 3, historicms 3, maxms 2000 Aug 9 14:27:33 DEBUG[6438] chan_sip.c: SIP TIMER: Rescheduling retransmission #364703 (1) NOTIFY - 4 Aug 9 14:27:33 DEBUG[6438] chan_sip.c: ** SIP timers: Rescheduling retransmission 2 to 1000 ms (t1 500 ms (Retrans id #364703)) Aug 9 14:27:33 VERBOSE[6438] logger.c: Retransmitting #1 (no NAT) to 192.168.255.40:5060: NOTIFY SIP/2.0 Via: SIP/2.0/UDP 192.168.255.1:5060;branch=z9hG4bK61ba7e33;rport From: ;tag=as16311f49 To: Contact: CSeq: 102 NOTIFY User-Agent: Asterisk PBX Max-Forwards: 70 Event: refer;id=1 Subscription-state: terminated;reason=noresource Content-Type: message/sipfrag;version=2.0 Content-Length: 14 SIP/2.0 200 OK --- Aug 9 14:27:33 DEBUG[6438] chan_sip.c: SIP TIMER: Rescheduling retransmission #364704 (1) BYE - 8 Aug 9 14:27:33 DEBUG[6438] chan_sip.c: ** SIP timers: Rescheduling retransmission 2 to 1000 ms (t1 500 ms (Retrans id #364704)) Aug 9 14:27:33 VERBOSE[6438] logger.c: Retransmitting #1 (no NAT) to 192.168.255.40:5060: BYE SIP/2.0 Via: SIP/2.0/UDP 192.168.255.1:5060;branch=z9hG4bK2d824439;rport From: ;tag=as16311f49 To: ;tag=as16311f49 Contact: CSeq: 103 BYE User-Agent: Asterisk PBX Max-Forwards: 70 Content-Length: 0