v=0 o=root 1184052172 1184052172 IN IP4 10.60.33.9 s=call c=IN IP4 10.60.33.9 t=0 0 m=audio 60380 RTP/AVP 0 8 9 2 3 18 4 101 a=rtpmap:0 pcmu/8000 a=rtpmap:8 pcma/8000 a=rtpmap:9 g722/8000 a=rtpmap:2 g726-32/8000 a=rtpmap:3 gsm/8000 a=rtpmap:18 g729/8000 a=rtpmap:4 g723/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=ptime:20 a=sendrecv Jul 2 13:07:14 DEBUG[26458] chan_sip.c: Header 0: INVITE sip:0400518501@10.60.33.102;user=phone SIP/2.0 (53) Jul 2 13:07:14 DEBUG[26458] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.60.33.9:2051;branch=z9hG4bK-v5320lemhqjc;rport (66) Jul 2 13:07:14 DEBUG[26458] chan_sip.c: Header 2: From: "Darren" ;tag=bgybpgubi1 (52) Jul 2 13:07:14 DEBUG[26458] chan_sip.c: Header 3: To: (44) Jul 2 13:07:14 DEBUG[26458] chan_sip.c: Header 4: Call-ID: 3c41ee87a393-sdu3blgcu8bo@snom190 (42) Jul 2 13:07:14 DEBUG[26458] chan_sip.c: Header 5: CSeq: 1 INVITE (14) Jul 2 13:07:14 DEBUG[26458] chan_sip.c: Header 6: Max-Forwards: 70 (16) Jul 2 13:07:14 DEBUG[26458] chan_sip.c: Header 7: Contact: (48) Jul 2 13:07:14 DEBUG[26458] chan_sip.c: Header 8: P-Key-Flags: keys="3" (21) Jul 2 13:07:14 DEBUG[26458] chan_sip.c: Header 9: User-Agent: snom190/3.60i (25) Jul 2 13:07:14 DEBUG[26458] chan_sip.c: Header 10: Accept: application/sdp (23) Jul 2 13:07:14 DEBUG[26458] chan_sip.c: Header 11: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO (88) Jul 2 13:07:14 DEBUG[26458] chan_sip.c: Header 12: Allow-Events: talk, hold, refer (31) Jul 2 13:07:14 DEBUG[26458] chan_sip.c: Header 13: Supported: timer, 100rel, replaces (34) Jul 2 13:07:14 DEBUG[26458] chan_sip.c: Header 14: Session-Expires: 3600 (21) Jul 2 13:07:14 DEBUG[26458] chan_sip.c: Header 15: Content-Type: application/sdp (29) Jul 2 13:07:14 DEBUG[26458] chan_sip.c: Header 16: Content-Length: 364 (19) Jul 2 13:07:14 DEBUG[26458] chan_sip.c: Header 17: (0) Jul 2 13:07:14 DEBUG[26458] chan_sip.c: Line: v=0 (3) Jul 2 13:07:14 DEBUG[26458] chan_sip.c: Line: o=root 1184052172 1184052172 IN IP4 10.60.33.9 (46) Jul 2 13:07:14 DEBUG[26458] chan_sip.c: Line: s=call (6) Jul 2 13:07:14 DEBUG[26458] chan_sip.c: Line: c=IN IP4 10.60.33.9 (19) Jul 2 13:07:14 DEBUG[26458] chan_sip.c: Line: t=0 0 (5) Jul 2 13:07:14 DEBUG[26458] chan_sip.c: Line: m=audio 60380 RTP/AVP 0 8 9 2 3 18 4 101 (40) Jul 2 13:07:14 DEBUG[26458] chan_sip.c: Line: a=rtpmap:0 pcmu/8000 (20) Jul 2 13:07:14 DEBUG[26458] chan_sip.c: Line: a=rtpmap:8 pcma/8000 (20) Jul 2 13:07:14 DEBUG[26458] chan_sip.c: Line: a=rtpmap:9 g722/8000 (20) Jul 2 13:07:14 DEBUG[26458] chan_sip.c: Line: a=rtpmap:2 g726-32/8000 (23) Jul 2 13:07:14 DEBUG[26458] chan_sip.c: Line: a=rtpmap:3 gsm/8000 (19) Jul 2 13:07:14 DEBUG[26458] chan_sip.c: Line: a=rtpmap:18 g729/8000 (21) Jul 2 13:07:14 DEBUG[26458] chan_sip.c: Line: a=rtpmap:4 g723/8000 (20) Jul 2 13:07:14 DEBUG[26458] chan_sip.c: Line: a=rtpmap:101 telephone-event/8000 (33) Jul 2 13:07:14 DEBUG[26458] chan_sip.c: Line: a=fmtp:101 0-15 (15) Jul 2 13:07:14 DEBUG[26458] chan_sip.c: Line: a=ptime:20 (10) Jul 2 13:07:14 DEBUG[26458] chan_sip.c: Line: a=sendrecv (10) Jul 2 13:07:14 VERBOSE[26458] logger.c: --- (17 headers 17 lines)Jul 2 13:07:14 VERBOSE[26458] logger.c: --- (17 headers 17 lines)--- Jul 2 13:07:14 DEBUG[26458] chan_sip.c: Allocating new SIP dialog for 3c41ee87a393-sdu3blgcu8bo@snom190 - INVITE (With RTP) Jul 2 13:07:14 DEBUG[26458] chan_sip.c: **** Received INVITE (5) - Command in SIP INVITE Jul 2 13:07:14 DEBUG[26458] chan_sip.c: Begin: parsing SIP "Supported: timer, 100rel, replaces" Jul 2 13:07:14 DEBUG[26458] chan_sip.c: Found SIP option: -timer- Jul 2 13:07:14 DEBUG[26458] chan_sip.c: Matched SIP option: timer Jul 2 13:07:14 DEBUG[26458] chan_sip.c: Found SIP option: -100rel- Jul 2 13:07:14 DEBUG[26458] chan_sip.c: Matched SIP option: 100rel Jul 2 13:07:14 DEBUG[26458] chan_sip.c: Found SIP option: -replaces- Jul 2 13:07:14 DEBUG[26458] chan_sip.c: Matched SIP option: replaces Jul 2 13:07:14 DEBUG[26458] chan_sip.c: * SIP extension value: 7 for call 3c41ee87a393-sdu3blgcu8bo@snom190 Jul 2 13:07:14 VERBOSE[26458] logger.c: Using INVITE request as basis request - 3c41ee87a393-sdu3blgcu8bo@snom190 Jul 2 13:07:14 VERBOSE[26458] logger.c: Sending to 10.60.33.9 : 2051 (NAT) Jul 2 13:07:14 DEBUG[26458] chan_sip.c: Setting NAT on RTP to 0 Jul 2 13:07:14 VERBOSE[26458] logger.c: Found user '309' Jul 2 13:07:14 VERBOSE[26458] logger.c: Found RTP audio format 0 Jul 2 13:07:14 VERBOSE[26458] logger.c: Found RTP audio format 8 Jul 2 13:07:14 VERBOSE[26458] logger.c: Found RTP audio format 9 Jul 2 13:07:14 VERBOSE[26458] logger.c: Found RTP audio format 2 Jul 2 13:07:14 VERBOSE[26458] logger.c: Found RTP audio format 3 Jul 2 13:07:14 VERBOSE[26458] logger.c: Found RTP audio format 18 Jul 2 13:07:14 VERBOSE[26458] logger.c: Found RTP audio format 4 Jul 2 13:07:14 VERBOSE[26458] logger.c: Found RTP audio format 101 Jul 2 13:07:14 VERBOSE[26458] logger.c: Peer audio RTP is at port 10.60.33.9:60380 Jul 2 13:07:14 DEBUG[26458] chan_sip.c: Peer audio RTP is at port 10.60.33.9:60380 Jul 2 13:07:14 VERBOSE[26458] logger.c: Found description format pcmu Jul 2 13:07:14 VERBOSE[26458] logger.c: Found description format pcma Jul 2 13:07:14 VERBOSE[26458] logger.c: Found description format g722 Jul 2 13:07:14 VERBOSE[26458] logger.c: Found description format g726-32 Jul 2 13:07:14 VERBOSE[26458] logger.c: Found description format gsm Jul 2 13:07:14 VERBOSE[26458] logger.c: Found description format g729 Jul 2 13:07:14 VERBOSE[26458] logger.c: Found description format g723 Jul 2 13:07:14 VERBOSE[26458] logger.c: Found description format telephone-event Jul 2 13:07:14 VERBOSE[26458] logger.c: Capabilities: us - 0xc (ulaw|alaw), peer - audio=0x11f (g723|gsm|ulaw|alaw|g726|g729)/video=0x0 (nothing), combined - 0xc (ulaw|alaw) Jul 2 13:07:14 VERBOSE[26458] logger.c: Non-codec capabilities: us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event) Jul 2 13:07:14 DEBUG[26458] chan_sip.c: Checking SIP call limits for device 309 Jul 2 13:07:14 DEBUG[26458] chan_sip.c: Updating call counter for incoming call Jul 2 13:07:14 VERBOSE[26458] logger.c: Looking for 0400518501 in from-internal (domain 10.60.33.102) Jul 2 13:07:14 DEBUG[26458] chan_sip.c: build_route: Contact hop: Jul 2 13:07:14 VERBOSE[26458] logger.c: list_route: hop: Jul 2 13:07:14 VERBOSE[26458] logger.c: Transmitting (no NAT) to 10.60.33.9:2051: SIP/2.0 100 Trying Via: SIP/2.0/UDP 10.60.33.9:2051;branch=z9hG4bK-v5320lemhqjc;rport;received=10.60.33.9 From: "Darren" ;tag=bgybpgubi1 To: Call-ID: 3c41ee87a393-sdu3blgcu8bo@snom190 CSeq: 1 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Length: 0 --- Jul 2 13:07:14 DEBUG[26446] chan_sip.c: Checking device state for peer 309 Jul 2 13:07:14 DEBUG[26446] channel.c: Avoiding initial deadlock for 'SIP/309-5000' Jul 2 13:07:14 DEBUG[27063] pbx.c: Launching 'Macro' Jul 2 13:07:14 DEBUG[26446] devicestate.c: Changing state for SIP/309 - state 2 (In use) Jul 2 13:07:14 VERBOSE[27063] logger.c: -- Executing Macro("SIP/309-5000", "dialout-trunk|4|0400518501||") in new stack Jul 2 13:07:14 DEBUG[26446] chan_sip.c: Checking device state for peer 309 Jul 2 13:07:14 DEBUG[27064] app_queue.c: Device 'SIP/309' changed to state '2' (In use) Jul 2 13:07:14 DEBUG[27063] pbx.c: Expression result is '1' Jul 2 13:07:14 DEBUG[27063] pbx.c: Launching 'GotoIf' Jul 2 13:07:14 VERBOSE[27063] logger.c: -- Executing GotoIf("SIP/309-5000", "1?3:2") in new stack Jul 2 13:07:14 VERBOSE[27063] logger.c: -- Goto (macro-dialout-trunk,s,3) Jul 2 13:07:14 DEBUG[27063] pbx.c: Launching 'Macro' Jul 2 13:07:14 VERBOSE[27063] logger.c: -- Executing Macro("SIP/309-5000", "user-callerid") in new stack Jul 2 13:07:14 DEBUG[27063] pbx.c: Expression result is '0' Jul 2 13:07:14 DEBUG[27063] pbx.c: Launching 'GotoIf' Jul 2 13:07:14 VERBOSE[27063] logger.c: -- Executing GotoIf("SIP/309-5000", "0?report") in new stack Jul 2 13:07:14 DEBUG[27063] pbx.c: Not taking any branch Jul 2 13:07:14 DEBUG[27063] pbx.c: Expression result is '0' Jul 2 13:07:14 DEBUG[27063] pbx.c: Launching 'GotoIf' Jul 2 13:07:14 VERBOSE[27063] logger.c: -- Executing GotoIf("SIP/309-5000", "0?start") in new stack Jul 2 13:07:14 DEBUG[27063] pbx.c: Not taking any branch Jul 2 13:07:14 DEBUG[27063] pbx.c: Function result is '309' Jul 2 13:07:14 DEBUG[27063] pbx.c: Launching 'Set' Jul 2 13:07:14 VERBOSE[27063] logger.c: -- Executing Set("SIP/309-5000", "REALCALLERIDNUM=309") in new stack Jul 2 13:07:14 DEBUG[27063] pbx.c: Launching 'NoOp' Jul 2 13:07:14 VERBOSE[27063] logger.c: -- Executing NoOp("SIP/309-5000", "REALCALLERIDNUM is 309") in new stack Jul 2 13:07:14 DEBUG[27063] pbx.c: Function result is '309' Jul 2 13:07:14 DEBUG[27063] pbx.c: Launching 'Set' Jul 2 13:07:14 VERBOSE[27063] logger.c: -- Executing Set("SIP/309-5000", "AMPUSER=309") in new stack Jul 2 13:07:14 DEBUG[27063] pbx.c: Function result is 'Darren' Jul 2 13:07:14 DEBUG[27063] pbx.c: Launching 'Set' Jul 2 13:07:14 VERBOSE[27063] logger.c: -- Executing Set("SIP/309-5000", "AMPUSERCIDNAME=Darren") in new stack Jul 2 13:07:14 DEBUG[27063] pbx.c: Expression result is '0' Jul 2 13:07:14 DEBUG[27063] pbx.c: Launching 'GotoIf' Jul 2 13:07:14 VERBOSE[27063] logger.c: -- Executing GotoIf("SIP/309-5000", "0?report") in new stack Jul 2 13:07:14 DEBUG[27063] pbx.c: Not taking any branch Jul 2 13:07:14 DEBUG[27063] pbx.c: Launching 'Set' Jul 2 13:07:14 VERBOSE[27063] logger.c: -- Executing Set("SIP/309-5000", "CALLERID(all)=Darren <309>") in new stack Jul 2 13:07:14 DEBUG[27063] pbx.c: Function result is '"Darren" <309>' Jul 2 13:07:14 DEBUG[27063] pbx.c: Launching 'NoOp' Jul 2 13:07:14 VERBOSE[27063] logger.c: -- Executing NoOp("SIP/309-5000", "Using CallerID "Darren" <309>") in new stack Jul 2 13:07:14 DEBUG[27063] pbx.c: Function result is '309' Jul 2 13:07:14 DEBUG[27063] pbx.c: Launching 'Macro' Jul 2 13:07:14 VERBOSE[27063] logger.c: -- Executing Macro("SIP/309-5000", "record-enable|309|OUT") in new stack Jul 2 13:07:14 DEBUG[27063] pbx.c: Function result is '0' Jul 2 13:07:14 DEBUG[27063] pbx.c: Launching 'GotoIf' Jul 2 13:07:14 VERBOSE[27063] logger.c: -- Executing GotoIf("SIP/309-5000", "0 > 0?2:4") in new stack Jul 2 13:07:14 VERBOSE[27063] logger.c: -- Goto (macro-record-enable,s,4) Jul 2 13:07:14 DEBUG[27063] pbx.c: Launching 'AGI' Jul 2 13:07:14 VERBOSE[27063] logger.c: -- Executing AGI("SIP/309-5000", "recordingcheck|20060702-130714|1151816834.76") in new stack Jul 2 13:07:14 VERBOSE[27063] logger.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/recordingcheck Jul 2 13:07:14 VERBOSE[27063] logger.c: recordingcheck|20060702-130714|1151816834.76: Outbound recording not enabled Jul 2 13:07:14 VERBOSE[27063] logger.c: -- AGI Script recordingcheck completed, returning 0 Jul 2 13:07:14 DEBUG[27063] pbx.c: Launching 'NoOp' Jul 2 13:07:14 VERBOSE[27063] logger.c: -- Executing NoOp("SIP/309-5000", "No recording needed") in new stack Jul 2 13:07:14 DEBUG[27063] pbx.c: Launching 'Macro' Jul 2 13:07:14 VERBOSE[27063] logger.c: -- Executing Macro("SIP/309-5000", "outbound-callerid|4") in new stack Jul 2 13:07:14 DEBUG[27063] pbx.c: Expression result is '1' Jul 2 13:07:14 DEBUG[27063] pbx.c: Launching 'GotoIf' Jul 2 13:07:14 VERBOSE[27063] logger.c: -- Executing GotoIf("SIP/309-5000", "1?start") in new stack Jul 2 13:07:14 VERBOSE[27063] logger.c: -- Goto (macro-outbound-callerid,s,3) Jul 2 13:07:14 DEBUG[27063] pbx.c: Launching 'NoOp' Jul 2 13:07:14 VERBOSE[27063] logger.c: -- Executing NoOp("SIP/309-5000", "REALCALLERIDNUM is 309") in new stack Jul 2 13:07:14 DEBUG[27063] pbx.c: Function result is '' Jul 2 13:07:14 DEBUG[27063] pbx.c: Launching 'Set' Jul 2 13:07:14 VERBOSE[27063] logger.c: -- Executing Set("SIP/309-5000", "USEROUTCID=") in new stack Jul 2 13:07:14 DEBUG[27063] db.c: Unable to find key '309/emergency_cid' in family 'DEVICE' Jul 2 13:07:14 DEBUG[27063] func_db.c: DB: DEVICE/309/emergency_cid not found in database. Jul 2 13:07:14 DEBUG[27063] pbx.c: Function result is '' Jul 2 13:07:14 DEBUG[27063] pbx.c: Launching 'Set' Jul 2 13:07:14 VERBOSE[27063] logger.c: -- Executing Set("SIP/309-5000", "EMERGENCYCID=") in new stack Jul 2 13:07:14 DEBUG[27063] pbx.c: Launching 'Set' Jul 2 13:07:14 VERBOSE[27063] logger.c: -- Executing Set("SIP/309-5000", "TRUNKOUTCID=") in new stack Jul 2 13:07:14 DEBUG[27063] pbx.c: Expression result is '1' Jul 2 13:07:14 DEBUG[27063] pbx.c: Launching 'GotoIf' Jul 2 13:07:14 VERBOSE[27063] logger.c: -- Executing GotoIf("SIP/309-5000", "1?trunkcid") in new stack Jul 2 13:07:14 VERBOSE[27063] logger.c: -- Goto (macro-outbound-callerid,s,11) Jul 2 13:07:14 DEBUG[27063] pbx.c: Expression result is '1' Jul 2 13:07:14 DEBUG[27063] pbx.c: Launching 'GotoIf' Jul 2 13:07:14 VERBOSE[27063] logger.c: -- Executing GotoIf("SIP/309-5000", "1?usercid") in new stack Jul 2 13:07:14 VERBOSE[27063] logger.c: -- Goto (macro-outbound-callerid,s,13) Jul 2 13:07:14 DEBUG[27063] pbx.c: Expression result is '1' Jul 2 13:07:14 DEBUG[27063] pbx.c: Launching 'GotoIf' Jul 2 13:07:14 VERBOSE[27063] logger.c: -- Executing GotoIf("SIP/309-5000", "1?report") in new stack Jul 2 13:07:14 VERBOSE[27063] logger.c: -- Goto (macro-outbound-callerid,s,15) Jul 2 13:07:14 DEBUG[27063] pbx.c: Function result is '"Darren" <309>' Jul 2 13:07:14 DEBUG[27063] pbx.c: Launching 'NoOp' Jul 2 13:07:14 VERBOSE[27063] logger.c: -- Executing NoOp("SIP/309-5000", "CallerID set to "Darren" <309>") in new stack Jul 2 13:07:14 DEBUG[27063] pbx.c: Launching 'Set' Jul 2 13:07:14 VERBOSE[27063] logger.c: -- Executing Set("SIP/309-5000", "GROUP()=OUT_4") in new stack Jul 2 13:07:14 DEBUG[27063] pbx.c: Function result is '1' Jul 2 13:07:14 DEBUG[27063] pbx.c: Expression result is '0' Jul 2 13:07:14 DEBUG[27063] pbx.c: Launching 'GotoIf' Jul 2 13:07:14 VERBOSE[27063] logger.c: -- Executing GotoIf("SIP/309-5000", "0?108") in new stack Jul 2 13:07:14 DEBUG[27063] pbx.c: Not taking any branch Jul 2 13:07:14 DEBUG[27063] pbx.c: Launching 'Set' Jul 2 13:07:14 VERBOSE[27063] logger.c: -- Executing Set("SIP/309-5000", "DIAL_NUMBER=0400518501") in new stack Jul 2 13:07:14 DEBUG[27063] pbx.c: Launching 'Set' Jul 2 13:07:14 VERBOSE[27063] logger.c: -- Executing Set("SIP/309-5000", "DIAL_TRUNK=4") in new stack Jul 2 13:07:14 DEBUG[27063] pbx.c: Launching 'AGI' Jul 2 13:07:14 VERBOSE[27063] logger.c: -- Executing AGI("SIP/309-5000", "fixlocalprefix") in new stack Jul 2 13:07:14 VERBOSE[27063] logger.c: -- Launched AGI Script /var/lib/asterisk/agi-bin/fixlocalprefix Jul 2 13:07:14 VERBOSE[27063] logger.c: fixlocalprefix: Could not parse /etc/asterisk/localprefixes.conf Jul 2 13:07:14 VERBOSE[27063] logger.c: -- AGI Script fixlocalprefix completed, returning 0 Jul 2 13:07:14 DEBUG[27063] pbx.c: Launching 'Set' Jul 2 13:07:14 VERBOSE[27063] logger.c: -- Executing Set("SIP/309-5000", "OUTNUM=0400518501") in new stack Jul 2 13:07:14 DEBUG[27063] pbx.c: Function result is 'ZAP/4' Jul 2 13:07:14 DEBUG[27063] pbx.c: Launching 'Set' Jul 2 13:07:14 VERBOSE[27063] logger.c: -- Executing Set("SIP/309-5000", "custom=ZAP/4") in new stack Jul 2 13:07:14 DEBUG[27063] pbx.c: Expression result is '0' Jul 2 13:07:14 DEBUG[27063] pbx.c: Launching 'GotoIf' Jul 2 13:07:14 VERBOSE[27063] logger.c: -- Executing GotoIf("SIP/309-5000", "0?16") in new stack Jul 2 13:07:14 DEBUG[27063] pbx.c: Not taking any branch Jul 2 13:07:14 DEBUG[27063] pbx.c: Launching 'Dial' Jul 2 13:07:14 VERBOSE[27063] logger.c: -- Executing Dial("SIP/309-5000", "ZAP/4/0400518501|120|r") in new stack Jul 2 13:07:14 DEBUG[27063] chan_zap.c: Using channel 4 Jul 2 13:07:14 DEBUG[26446] devicestate.c: Changing state for Zap/4 - state 2 (In use) Jul 2 13:07:14 DEBUG[27063] channel.c: Not copying variable STACK-macro-dialout-trunk-s-14. Jul 2 13:07:14 DEBUG[27063] channel.c: Not copying variable MACRO_DEPTH. Jul 2 13:07:14 DEBUG[27063] channel.c: Not copying variable STACK-macro-dialout-trunk-s-13. Jul 2 13:07:14 DEBUG[27063] channel.c: Not copying variable custom. Jul 2 13:07:14 DEBUG[27063] channel.c: Not copying variable STACK-macro-dialout-trunk-s-12. Jul 2 13:07:14 DEBUG[27063] channel.c: Not copying variable OUTNUM. Jul 2 13:07:14 DEBUG[27063] channel.c: Not copying variable STACK-macro-dialout-trunk-s-11. Jul 2 13:07:14 DEBUG[27063] channel.c: Not copying variable STACK-macro-dialout-trunk-s-10. Jul 2 13:07:14 DEBUG[27063] channel.c: Not copying variable DIAL_TRUNK. Jul 2 13:07:14 DEBUG[27063] channel.c: Not copying variable STACK-macro-dialout-trunk-s-9. Jul 2 13:07:14 DEBUG[27063] channel.c: Not copying variable DIAL_NUMBER. Jul 2 13:07:14 DEBUG[27063] channel.c: Not copying variable STACK-macro-dialout-trunk-s-8. Jul 2 13:07:14 DEBUG[27063] channel.c: Not copying variable STACK-macro-dialout-trunk-s-7. Jul 2 13:07:14 DEBUG[27063] channel.c: Not copying variable GROUP. Jul 2 13:07:14 DEBUG[27063] channel.c: Not copying variable STACK-macro-dialout-trunk-s-6. Jul 2 13:07:14 DEBUG[27063] channel.c: Not copying variable MACRO_PRIORITY. Jul 2 13:07:14 DEBUG[27063] channel.c: Not copying variable MACRO_CONTEXT. Jul 2 13:07:14 DEBUG[27063] channel.c: Not copying variable MACRO_EXTEN. Jul 2 13:07:14 DEBUG[27063] channel.c: Not copying variable ARG1. Jul 2 13:07:14 DEBUG[27063] channel.c: Not copying variable STACK-macro-outbound-callerid-s-15. Jul 2 13:07:14 DEBUG[27063] channel.c: Not copying variable STACK-macro-outbound-callerid-s-13. Jul 2 13:07:14 DEBUG[27063] channel.c: Not copying variable STACK-macro-outbound-callerid-s-11. Jul 2 13:07:14 DEBUG[27063] channel.c: Not copying variable STACK-macro-outbound-callerid-s-7. Jul 2 13:07:14 DEBUG[27063] channel.c: Not copying variable TRUNKOUTCID. Jul 2 13:07:14 DEBUG[27063] channel.c: Not copying variable STACK-macro-outbound-callerid-s-6. Jul 2 13:07:14 DEBUG[27063] channel.c: Not copying variable EMERGENCYCID. Jul 2 13:07:14 DEBUG[27063] channel.c: Not copying variable STACK-macro-outbound-callerid-s-5. Jul 2 13:07:14 DEBUG[27063] channel.c: Not copying variable USEROUTCID. Jul 2 13:07:14 DEBUG[27063] channel.c: Not copying variable STACK-macro-outbound-callerid-s-4. Jul 2 13:07:14 DEBUG[27063] channel.c: Not copying variable DB_RESULT. Jul 2 13:07:14 DEBUG[27063] channel.c: Not copying variable STACK-macro-outbound-callerid-s-3. Jul 2 13:07:14 DEBUG[27063] channel.c: Not copying variable STACK-macro-outbound-callerid-s-1. Jul 2 13:07:14 DEBUG[27063] channel.c: Not copying variable STACK-macro-dialout-trunk-s-5. Jul 2 13:07:14 DEBUG[27063] channel.c: Not copying variable ARG2. Jul 2 13:07:14 DEBUG[27063] channel.c: Not copying variable STACK-macro-record-enable-s-5. Jul 2 13:07:14 DEBUG[27063] channel.c: Not copying variable STACK-macro-record-enable-s-4. Jul 2 13:07:14 DEBUG[27063] channel.c: Not copying variable STACK-macro-record-enable-s-1. Jul 2 13:07:14 DEBUG[27063] channel.c: Not copying variable STACK-macro-dialout-trunk-s-4. Jul 2 13:07:14 DEBUG[27063] channel.c: Not copying variable STACK-macro-user-callerid-s-9. Jul 2 13:07:14 DEBUG[27063] channel.c: Not copying variable STACK-macro-user-callerid-s-8. Jul 2 13:07:14 DEBUG[27063] channel.c: Not copying variable STACK-macro-user-callerid-s-7. Jul 2 13:07:14 DEBUG[27063] channel.c: Not copying variable AMPUSERCIDNAME. Jul 2 13:07:14 DEBUG[27063] channel.c: Not copying variable STACK-macro-user-callerid-s-6. Jul 2 13:07:14 DEBUG[27063] channel.c: Not copying variable AMPUSER. Jul 2 13:07:14 DEBUG[27063] channel.c: Not copying variable STACK-macro-user-callerid-s-5. Jul 2 13:07:14 DEBUG[27063] channel.c: Not copying variable STACK-macro-user-callerid-s-4. Jul 2 13:07:14 DEBUG[27063] channel.c: Not copying variable REALCALLERIDNUM. Jul 2 13:07:14 DEBUG[27063] channel.c: Not copying variable STACK-macro-user-callerid-s-3. Jul 2 13:07:14 DEBUG[27063] channel.c: Not copying variable STACK-macro-user-callerid-s-2. Jul 2 13:07:14 DEBUG[27063] channel.c: Not copying variable STACK-macro-user-callerid-s-1. Jul 2 13:07:14 DEBUG[27063] channel.c: Not copying variable STACK-macro-dialout-trunk-s-3. Jul 2 13:07:14 DEBUG[27063] channel.c: Not copying variable STACK-macro-dialout-trunk-s-1. Jul 2 13:07:14 DEBUG[27063] channel.c: Not copying variable ARG4. Jul 2 13:07:14 DEBUG[27063] channel.c: Not copying variable ARG3. Jul 2 13:07:14 DEBUG[27063] channel.c: Not copying variable STACK-from-internal-0400518501-1. Jul 2 13:07:14 DEBUG[27063] channel.c: Not copying variable SIPCALLID. Jul 2 13:07:14 DEBUG[27063] channel.c: Not copying variable SIPUSERAGENT. Jul 2 13:07:14 DEBUG[27063] channel.c: Not copying variable SIPDOMAIN. Jul 2 13:07:14 DEBUG[27063] channel.c: Not copying variable SIPURI. Jul 2 13:07:14 DEBUG[27063] chan_zap.c: Dialing '0400518501' Jul 2 13:07:14 DEBUG[27063] chan_zap.c: Deferring dialing... Jul 2 13:07:14 DEBUG[26446] channel.c: Avoiding initial deadlock for 'Zap/4-1' Jul 2 13:07:14 VERBOSE[27063] logger.c: -- Called 4/0400518501 Jul 2 13:07:14 VERBOSE[27063] logger.c: Transmitting (no NAT) to 10.60.33.9:2051: SIP/2.0 180 Ringing Via: SIP/2.0/UDP 10.60.33.9:2051;branch=z9hG4bK-v5320lemhqjc;rport;received=10.60.33.9 From: "Darren" ;tag=bgybpgubi1 To: ;tag=as59bed056 Call-ID: 3c41ee87a393-sdu3blgcu8bo@snom190 CSeq: 1 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Length: 0 --- Jul 2 13:07:14 DEBUG[27067] app_queue.c: Device 'Zap/4' changed to state '2' (In use) Jul 2 13:07:14 DEBUG[26446] devicestate.c: Changing state for Zap/4 - state 2 (In use) Jul 2 13:07:14 DEBUG[27068] app_queue.c: Device 'Zap/4' changed to state '2' (In use) Jul 2 13:07:14 DEBUG[27063] chan_zap.c: Exception on 16, channel 4 Jul 2 13:07:14 DEBUG[27063] chan_zap.c: Got event Hook Transition Complete(12) on channel 4 (index 0) Jul 2 13:07:16 DEBUG[27063] chan_zap.c: Exception on 16, channel 4 Jul 2 13:07:16 DEBUG[27063] chan_zap.c: Got event Dial Complete(9) on channel 4 (index 0) Jul 2 13:07:16 DEBUG[27063] chan_zap.c: Enabled echo cancellation on channel 4 Jul 2 13:07:16 DEBUG[27063] chan_zap.c: Engaged echo training on channel 4 Jul 2 13:07:18 DEBUG[27063] chan_zap.c: Exception on 16, channel 4 Jul 2 13:07:18 DEBUG[27063] chan_zap.c: Got event Dial Complete(9) on channel 4 (index 0) Jul 2 13:07:18 DEBUG[27063] chan_zap.c: Echo cancellation already on Jul 2 13:07:18 DEBUG[26446] channel.c: Avoiding initial deadlock for 'Zap/4-1' Jul 2 13:07:18 VERBOSE[27063] logger.c: -- Zap/4-1 answered SIP/309-5000 Jul 2 13:07:18 DEBUG[27063] channel.c: Set channel SIP/309-5000 to read format ulaw Jul 2 13:07:18 DEBUG[27063] channel.c: Set channel Zap/4-1 to write format ulaw Jul 2 13:07:18 DEBUG[27063] channel.c: Set channel Zap/4-1 to read format ulaw Jul 2 13:07:18 DEBUG[27063] channel.c: Set channel SIP/309-5000 to write format ulaw Jul 2 13:07:18 DEBUG[27063] chan_sip.c: sip_answer(SIP/309-5000) Jul 2 13:07:18 VERBOSE[27063] logger.c: We're at 10.60.33.102 port 16944 Jul 2 13:07:18 VERBOSE[27063] logger.c: Adding codec 0x4 (ulaw) to SDP Jul 2 13:07:18 VERBOSE[27063] logger.c: Adding codec 0x8 (alaw) to SDP Jul 2 13:07:18 VERBOSE[27063] logger.c: Adding non-codec 0x1 (telephone-event) to SDP Jul 2 13:07:18 VERBOSE[27063] logger.c: Reliably Transmitting (no NAT) to 10.60.33.9:2051: SIP/2.0 200 OK Via: SIP/2.0/UDP 10.60.33.9:2051;branch=z9hG4bK-v5320lemhqjc;rport;received=10.60.33.9 From: "Darren" ;tag=bgybpgubi1 To: ;tag=as59bed056 Call-ID: 3c41ee87a393-sdu3blgcu8bo@snom190 CSeq: 1 INVITE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Type: application/sdp Content-Length: 240 v=0 o=root 26441 26441 IN IP4 10.60.33.102 s=session c=IN IP4 10.60.33.102 t=0 0 m=audio 16944 RTP/AVP 0 8 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=silenceSupp:off - - - - --- Jul 2 13:07:18 DEBUG[27063] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #1013 Jul 2 13:07:18 DEBUG[26446] devicestate.c: Changing state for Zap/4 - state 2 (In use) Jul 2 13:07:18 DEBUG[26446] chan_sip.c: Checking device state for peer 309 Jul 2 13:07:18 DEBUG[26446] devicestate.c: Changing state for SIP/309 - state 2 (In use) Jul 2 13:07:18 DEBUG[26446] chan_sip.c: Checking device state for peer 309 Jul 2 13:07:18 DEBUG[27069] app_queue.c: Device 'Zap/4' changed to state '2' (In use) Jul 2 13:07:18 DEBUG[27070] app_queue.c: Device 'SIP/309' changed to state '2' (In use) Jul 2 13:07:19 DEBUG[27063] rtp.c: Ooh, format changed from unknown to ulaw Jul 2 13:07:19 VERBOSE[26458] logger.c: <-- SIP read from 10.60.33.9:2051: ACK sip:0400518501@10.60.33.102 SIP/2.0 Via: SIP/2.0/UDP 10.60.33.9:2051;branch=z9hG4bK-uexurcnm06eu;rport From: "Darren" ;tag=bgybpgubi1 To: ;tag=as59bed056 Call-ID: 3c41ee87a393-sdu3blgcu8bo@snom190 CSeq: 1 ACK Max-Forwards: 70 Contact: Content-Length: 0 Jul 2 13:07:19 DEBUG[26458] chan_sip.c: Header 0: ACK sip:0400518501@10.60.33.102 SIP/2.0 (39) Jul 2 13:07:19 DEBUG[26458] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.60.33.9:2051;branch=z9hG4bK-uexurcnm06eu;rport (66) Jul 2 13:07:19 DEBUG[26458] chan_sip.c: Header 2: From: "Darren" ;tag=bgybpgubi1 (52) Jul 2 13:07:19 DEBUG[26458] chan_sip.c: Header 3: To: ;tag=as59bed056 (59) Jul 2 13:07:19 DEBUG[26458] chan_sip.c: Header 4: Call-ID: 3c41ee87a393-sdu3blgcu8bo@snom190 (42) Jul 2 13:07:19 DEBUG[26458] chan_sip.c: Header 5: CSeq: 1 ACK (11) Jul 2 13:07:19 DEBUG[26458] chan_sip.c: Header 6: Max-Forwards: 70 (16) Jul 2 13:07:19 DEBUG[26458] chan_sip.c: Header 7: Contact: (48) Jul 2 13:07:19 DEBUG[26458] chan_sip.c: Header 8: Content-Length: 0 (17) Jul 2 13:07:19 DEBUG[26458] chan_sip.c: Header 9: (0) Jul 2 13:07:19 VERBOSE[26458] logger.c: --- (9 headers 0 lines)Jul 2 13:07:19 VERBOSE[26458] logger.c: --- (9 headers 0 lines)--- Jul 2 13:07:19 DEBUG[26458] chan_sip.c: = Found Their Call ID: 3c41ee87a393-sdu3blgcu8bo@snom190 Their Tag bgybpgubi1 Our tag: as59bed056 Jul 2 13:07:19 DEBUG[26458] chan_sip.c: **** Received ACK (6) - Command in SIP ACK Jul 2 13:07:19 DEBUG[26458] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #1013 Jul 2 13:07:19 DEBUG[26458] chan_sip.c: Stopping retransmission on '3c41ee87a393-sdu3blgcu8bo@snom190' of Response 1: Match Found Jul 2 13:07:19 DEBUG[27063] chan_zap.c: Write returned -1 (Resource temporarily unavailable) on channel 4 Jul 2 13:07:23 DEBUG[26453] chan_iax2.c: Peer lastms 15, historicms 15, maxms 2000 Jul 2 13:07:24 DEBUG[26453] chan_iax2.c: Peer lastms 31, historicms 31, maxms 2000 Jul 2 13:07:26 DEBUG[26458] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP) Jul 2 13:07:26 DEBUG[26458] chan_sip.c: Header 0: OPTIONS sip:319@10.60.33.19:2051;line=jwqi2vzl SIP/2.0 (54) Jul 2 13:07:26 DEBUG[26458] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.60.33.102:5060;branch=z9hG4bK33a80e74 (57) Jul 2 13:07:26 DEBUG[26458] chan_sip.c: Header 2: From: "Unknown" ;tag=as59c77014 (57) Jul 2 13:07:26 DEBUG[26458] chan_sip.c: Header 3: To: (44) Jul 2 13:07:26 DEBUG[26458] chan_sip.c: Header 4: Contact: (35) Jul 2 13:07:26 DEBUG[26458] chan_sip.c: Header 5: Call-ID: 4897051f06fb969c57681aee1a06555f@10.60.33.102 (54) Jul 2 13:07:26 DEBUG[26458] chan_sip.c: Header 6: CSeq: 102 OPTIONS (17) Jul 2 13:07:26 DEBUG[26458] chan_sip.c: Header 7: User-Agent: Asterisk PBX (24) Jul 2 13:07:26 DEBUG[26458] chan_sip.c: Header 8: Max-Forwards: 70 (16) Jul 2 13:07:26 DEBUG[26458] chan_sip.c: Header 9: Date: Sun, 02 Jul 2006 05:07:26 GMT (35) Jul 2 13:07:26 DEBUG[26458] chan_sip.c: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) Jul 2 13:07:26 DEBUG[26458] chan_sip.c: Header 11: Content-Length: 0 (17) Jul 2 13:07:26 DEBUG[26458] chan_sip.c: Header 12: (0) Jul 2 13:07:26 DEBUG[26458] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #1014 Jul 2 13:07:26 DEBUG[26458] chan_sip.c: Header 0: SIP/2.0 200 OK (14) Jul 2 13:07:26 DEBUG[26458] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.60.33.102:5060;branch=z9hG4bK33a80e74 (57) Jul 2 13:07:26 DEBUG[26458] chan_sip.c: Header 2: From: "Unknown" ;tag=as59c77014 (57) Jul 2 13:07:26 DEBUG[26458] chan_sip.c: Header 3: To: (44) Jul 2 13:07:26 DEBUG[26458] chan_sip.c: Header 4: Call-ID: 4897051f06fb969c57681aee1a06555f@10.60.33.102 (54) Jul 2 13:07:26 DEBUG[26458] chan_sip.c: Header 5: CSeq: 102 OPTIONS (17) Jul 2 13:07:26 DEBUG[26458] chan_sip.c: Header 6: Contact: (49) Jul 2 13:07:26 DEBUG[26458] chan_sip.c: Header 7: User-Agent: snom190/3.60i (25) Jul 2 13:07:26 DEBUG[26458] chan_sip.c: Header 8: Accept-Language: en (19) Jul 2 13:07:26 DEBUG[26458] chan_sip.c: Header 9: Accept: application/sdp (23) Jul 2 13:07:26 DEBUG[26458] chan_sip.c: Header 10: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO (88) Jul 2 13:07:26 DEBUG[26458] chan_sip.c: Header 11: Allow-Events: talk, hold, refer (31) Jul 2 13:07:26 DEBUG[26458] chan_sip.c: Header 12: Supported: timer, 100rel, replaces (34) Jul 2 13:07:26 DEBUG[26458] chan_sip.c: Header 13: Content-Length: 0 (17) Jul 2 13:07:26 DEBUG[26458] chan_sip.c: Header 14: (0) Jul 2 13:07:26 DEBUG[26458] chan_sip.c: = Found Their Call ID: 4897051f06fb969c57681aee1a06555f@10.60.33.102 Their Tag Our tag: as59c77014 Jul 2 13:07:26 DEBUG[26458] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #1014 Jul 2 13:07:26 DEBUG[26458] chan_sip.c: Stopping retransmission on '4897051f06fb969c57681aee1a06555f@10.60.33.102' of Request 102: Match Found Jul 2 13:07:26 DEBUG[26453] chan_iax2.c: Peer lastms 18, historicms 18, maxms 2000 Jul 2 13:07:28 DEBUG[26780] manager.c: Manager received command 'Command' Jul 2 13:07:28 DEBUG[26780] manager.c: Manager received command 'Command' Jul 2 13:07:28 NOTICE[26453] chan_iax2.c: Peer 'dhn-sra' is not dynamic (from 10.60.34.101) Jul 2 13:07:41 DEBUG[26453] chan_iax2.c: Allocate call number Jul 2 13:07:41 DEBUG[26453] chan_iax2.c: Registration created on call 7 Jul 2 13:07:42 NOTICE[26453] chan_iax2.c: Registration of 'sra-dhn' rejected: 'Registration Refused' from: '10.60.34.101' Jul 2 13:07:43 VERBOSE[26458] logger.c: <-- SIP read from 10.60.33.9:2051: BYE sip:0400518501@10.60.33.102 SIP/2.0 Via: SIP/2.0/UDP 10.60.33.9:2051;branch=z9hG4bK-dsicr5hmakou;rport From: "Darren" ;tag=bgybpgubi1 To: ;tag=as59bed056 Call-ID: 3c41ee87a393-sdu3blgcu8bo@snom190 CSeq: 2 BYE Max-Forwards: 70 Contact: User-Agent: snom190/3.60i Content-Length: 0 Jul 2 13:07:43 DEBUG[26458] chan_sip.c: Header 0: BYE sip:0400518501@10.60.33.102 SIP/2.0 (39) Jul 2 13:07:43 DEBUG[26458] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.60.33.9:2051;branch=z9hG4bK-dsicr5hmakou;rport (66) Jul 2 13:07:43 DEBUG[26458] chan_sip.c: Header 2: From: "Darren" ;tag=bgybpgubi1 (52) Jul 2 13:07:43 DEBUG[26458] chan_sip.c: Header 3: To: ;tag=as59bed056 (59) Jul 2 13:07:43 DEBUG[26458] chan_sip.c: Header 4: Call-ID: 3c41ee87a393-sdu3blgcu8bo@snom190 (42) Jul 2 13:07:43 DEBUG[26458] chan_sip.c: Header 5: CSeq: 2 BYE (11) Jul 2 13:07:43 DEBUG[26458] chan_sip.c: Header 6: Max-Forwards: 70 (16) Jul 2 13:07:43 DEBUG[26458] chan_sip.c: Header 7: Contact: (48) Jul 2 13:07:43 DEBUG[26458] chan_sip.c: Header 8: User-Agent: snom190/3.60i (25) Jul 2 13:07:43 DEBUG[26458] chan_sip.c: Header 9: Content-Length: 0 (17) Jul 2 13:07:43 DEBUG[26458] chan_sip.c: Header 10: (0) Jul 2 13:07:43 VERBOSE[26458] logger.c: --- (10 headers 0 lines)Jul 2 13:07:43 VERBOSE[26458] logger.c: --- (10 headers 0 lines)--- Jul 2 13:07:43 DEBUG[26458] chan_sip.c: = Found Their Call ID: 3c41ee87a393-sdu3blgcu8bo@snom190 Their Tag bgybpgubi1 Our tag: as59bed056 Jul 2 13:07:43 DEBUG[26458] chan_sip.c: **** Received BYE (8) - Command in SIP BYE Jul 2 13:07:43 VERBOSE[26458] logger.c: Sending to 10.60.33.9 : 2051 (NAT) Jul 2 13:07:43 VERBOSE[26458] logger.c: Transmitting (NAT) to 10.60.33.9:2051: SIP/2.0 200 OK Via: SIP/2.0/UDP 10.60.33.9:2051;branch=z9hG4bK-dsicr5hmakou;rport;received=10.60.33.9 From: "Darren" ;tag=bgybpgubi1 To: ;tag=as59bed056 Call-ID: 3c41ee87a393-sdu3blgcu8bo@snom190 CSeq: 2 BYE User-Agent: Asterisk PBX Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY Contact: Content-Length: 0 X-Asterisk-HangupCause: Normal Clearing --- Jul 2 13:07:43 DEBUG[27063] channel.c: Didn't get a frame from channel: SIP/309-5000 Jul 2 13:07:43 DEBUG[27063] channel.c: Bridge stops bridging channels SIP/309-5000 and Zap/4-1 Jul 2 13:07:43 DEBUG[27063] channel.c: Hanging up channel 'Zap/4-1' Jul 2 13:07:43 DEBUG[27063] chan_zap.c: zt_hangup(Zap/4-1) Jul 2 13:07:43 DEBUG[27063] chan_zap.c: Hangup: channel: 4 index = 0, normal = 16, callwait = -1, thirdcall = -1 Jul 2 13:07:43 DEBUG[27063] chan_zap.c: disabled echo cancellation on channel 4 Jul 2 13:07:43 DEBUG[27063] chan_zap.c: Set option TDD MODE, value: OFF(0) on Zap/4-1 Jul 2 13:07:43 DEBUG[27063] chan_zap.c: Updated conferencing on 4, with 0 conference users Jul 2 13:07:43 VERBOSE[27063] logger.c: -- Hungup 'Zap/4-1' Jul 2 13:07:43 DEBUG[27063] app_dial.c: Exiting with DIALSTATUS=ANSWER. Jul 2 13:07:43 DEBUG[27063] app_macro.c: Spawn extension (macro-dialout-trunk,s,14) exited non-zero on 'SIP/309-5000' in macro 'dialout-trunk' Jul 2 13:07:43 DEBUG[27063] pbx.c: Spawn extension (macro-dialout-trunk,s,14) exited non-zero on 'SIP/309-5000' Jul 2 13:07:43 DEBUG[26446] devicestate.c: Changing state for Zap/4 - state 0 (Unknown) Jul 2 13:07:43 DEBUG[27063] cdr_addon_mysql.c: cdr_mysql: inserting a CDR record. Jul 2 13:07:43 DEBUG[27063] cdr_addon_mysql.c: cdr_mysql: SQL command as follows: INSERT INTO cdr (calldate,clid,src,dst,dcontext,channel,dstchannel,lastapp,lastdata,duration,billsec,disposition,amaflags,accountcode,uniqueid) VALUES ('2006-07-02 13:07:14','\"Darren\" <309>','309','0400518501','from-internal', 'SIP/309-5000','Zap/4-1','Dial','ZAP/4/0400518501|120|r',29,25,'ANSWERED',3,'','1151816834.76') Jul 2 13:07:43 DEBUG[27063] channel.c: Hanging up channel 'SIP/309-5000' Jul 2 13:07:43 DEBUG[27063] chan_sip.c: Hangup call SIP/309-5000, SIP callid 3c41ee87a393-sdu3blgcu8bo@snom190) Jul 2 13:07:43 DEBUG[27063] chan_sip.c: update_call_counter(309) - decrement call limit counter Jul 2 13:07:43 DEBUG[27063] chan_sip.c: Updating call counter for incoming call Jul 2 13:07:43 DEBUG[26446] chan_sip.c: Checking device state for peer 309 Jul 2 13:07:43 DEBUG[26446] devicestate.c: Changing state for SIP/309 - state 1 (Not in use) Jul 2 13:07:43 DEBUG[26446] chan_sip.c: Checking device state for peer 309 Jul 2 13:07:43 DEBUG[27071] app_queue.c: Device 'Zap/4' changed to state '0' (Unknown) Jul 2 13:07:43 DEBUG[27072] app_queue.c: Device 'SIP/309' changed to state '1' (Not in use) Jul 2 13:07:44 VERBOSE[26458] logger.c: Destroying call '3c41ee87a393-sdu3blgcu8bo@snom190' Jul 2 13:07:46 DEBUG[26453] chan_iax2.c: Allocate call number Jul 2 13:07:46 DEBUG[26453] chan_iax2.c: Registration created on call 8 Jul 2 13:07:54 DEBUG[26458] chan_sip.c: Header 0: SUBSCRIBE sip:301@10.60.33.102;user=phone SIP/2.0 (49) Jul 2 13:07:54 DEBUG[26458] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.60.33.39:2051;branch=z9hG4bK-9jzmqo4al9vz;rport (67) Jul 2 13:07:54 DEBUG[26458] chan_sip.c: Header 2: From: ;tag=7r5ssj161s (43) Jul 2 13:07:54 DEBUG[26458] chan_sip.c: Header 3: To: (37) Jul 2 13:07:54 DEBUG[26458] chan_sip.c: Header 4: Call-ID: 3d561c3283d6-vab9wym5x35n@snom190 (42) Jul 2 13:07:54 DEBUG[26458] chan_sip.c: Header 5: CSeq: 6553 SUBSCRIBE (20) Jul 2 13:07:54 DEBUG[26458] chan_sip.c: Header 6: Max-Forwards: 70 (16) Jul 2 13:07:54 DEBUG[26458] chan_sip.c: Header 7: Contact: (49) Jul 2 13:07:54 DEBUG[26458] chan_sip.c: Header 8: Event: dialog (13) Jul 2 13:07:54 DEBUG[26458] chan_sip.c: Header 9: Accept: application/dialog-info+xml (35) Jul 2 13:07:54 DEBUG[26458] chan_sip.c: Header 10: Expires: 3600 (13) Jul 2 13:07:54 DEBUG[26458] chan_sip.c: Header 11: Content-Length: 0 (17) Jul 2 13:07:54 DEBUG[26458] chan_sip.c: Header 12: (0) Jul 2 13:07:54 DEBUG[26458] chan_sip.c: Allocating new SIP dialog for 3d561c3283d6-vab9wym5x35n@snom190 - SUBSCRIBE (No RTP) Jul 2 13:07:54 DEBUG[26458] chan_sip.c: **** Received SUBSCRIBE (10) - Command in SIP SUBSCRIBE Jul 2 13:07:54 DEBUG[26458] chan_sip.c: Adding subscription for extension 301 context from-internal for peer 339 Jul 2 13:07:54 ERROR[26458] chan_sip.c: Got SUBSCRIBE for extensions without hint. Please add hint to 301 in context from-internal Jul 2 13:08:18 NOTICE[26453] chan_iax2.c: Peer 'dhn-sra' is not dynamic (from 10.60.34.101) Jul 2 13:08:23 DEBUG[26453] chan_iax2.c: Peer lastms 13, historicms 13, maxms 2000 Jul 2 13:08:25 DEBUG[26453] chan_iax2.c: Peer lastms 27, historicms 27, maxms 2000 Jul 2 13:08:26 DEBUG[26458] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP) Jul 2 13:08:26 DEBUG[26458] chan_sip.c: Header 0: OPTIONS sip:319@10.60.33.19:2051;line=jwqi2vzl SIP/2.0 (54) Jul 2 13:08:26 DEBUG[26458] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.60.33.102:5060;branch=z9hG4bK4f40e27a (57) Jul 2 13:08:26 DEBUG[26458] chan_sip.c: Header 2: From: "Unknown" ;tag=as79041254 (57) Jul 2 13:08:26 DEBUG[26458] chan_sip.c: Header 3: To: (44) Jul 2 13:08:26 DEBUG[26458] chan_sip.c: Header 4: Contact: (35) Jul 2 13:08:26 DEBUG[26458] chan_sip.c: Header 5: Call-ID: 2ec01e76435d6d215ae31cc3381a9c61@10.60.33.102 (54) Jul 2 13:08:26 DEBUG[26458] chan_sip.c: Header 6: CSeq: 102 OPTIONS (17) Jul 2 13:08:26 DEBUG[26458] chan_sip.c: Header 7: User-Agent: Asterisk PBX (24) Jul 2 13:08:26 DEBUG[26458] chan_sip.c: Header 8: Max-Forwards: 70 (16) Jul 2 13:08:26 DEBUG[26458] chan_sip.c: Header 9: Date: Sun, 02 Jul 2006 05:08:26 GMT (35) Jul 2 13:08:26 DEBUG[26458] chan_sip.c: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) Jul 2 13:08:26 DEBUG[26458] chan_sip.c: Header 11: Content-Length: 0 (17) Jul 2 13:08:26 DEBUG[26458] chan_sip.c: Header 12: (0) Jul 2 13:08:26 DEBUG[26458] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #1018 Jul 2 13:08:26 DEBUG[26458] chan_sip.c: Header 0: SIP/2.0 200 OK (14) Jul 2 13:08:26 DEBUG[26458] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.60.33.102:5060;branch=z9hG4bK4f40e27a (57) Jul 2 13:08:26 DEBUG[26458] chan_sip.c: Header 2: From: "Unknown" ;tag=as79041254 (57) Jul 2 13:08:26 DEBUG[26458] chan_sip.c: Header 3: To: (44) Jul 2 13:08:26 DEBUG[26458] chan_sip.c: Header 4: Call-ID: 2ec01e76435d6d215ae31cc3381a9c61@10.60.33.102 (54) Jul 2 13:08:26 DEBUG[26458] chan_sip.c: Header 5: CSeq: 102 OPTIONS (17) Jul 2 13:08:26 DEBUG[26458] chan_sip.c: Header 6: Contact: (49) Jul 2 13:08:26 DEBUG[26458] chan_sip.c: Header 7: User-Agent: snom190/3.60i (25) Jul 2 13:08:26 DEBUG[26458] chan_sip.c: Header 8: Accept-Language: en (19) Jul 2 13:08:26 DEBUG[26458] chan_sip.c: Header 9: Accept: application/sdp (23) Jul 2 13:08:26 DEBUG[26458] chan_sip.c: Header 10: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO (88) Jul 2 13:08:26 DEBUG[26458] chan_sip.c: Header 11: Allow-Events: talk, hold, refer (31) Jul 2 13:08:26 DEBUG[26458] chan_sip.c: Header 12: Supported: timer, 100rel, replaces (34) Jul 2 13:08:26 DEBUG[26458] chan_sip.c: Header 13: Content-Length: 0 (17) Jul 2 13:08:26 DEBUG[26458] chan_sip.c: Header 14: (0) Jul 2 13:08:26 DEBUG[26458] chan_sip.c: = Found Their Call ID: 2ec01e76435d6d215ae31cc3381a9c61@10.60.33.102 Their Tag Our tag: as79041254 Jul 2 13:08:26 DEBUG[26458] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #1018 Jul 2 13:08:26 DEBUG[26458] chan_sip.c: Stopping retransmission on '2ec01e76435d6d215ae31cc3381a9c61@10.60.33.102' of Request 102: Match Found Jul 2 13:08:26 DEBUG[26453] chan_iax2.c: Peer lastms 25, historicms 25, maxms 2000 Jul 2 13:08:31 DEBUG[26453] chan_iax2.c: Allocate call number Jul 2 13:08:31 DEBUG[26453] chan_iax2.c: Registration created on call 3 Jul 2 13:08:32 NOTICE[26453] chan_iax2.c: Registration of 'sra-dhn' rejected: 'Registration Refused' from: '10.60.34.101' Jul 2 13:08:36 DEBUG[26453] chan_iax2.c: Allocate call number Jul 2 13:08:36 DEBUG[26453] chan_iax2.c: Registration created on call 4 Jul 2 13:09:08 NOTICE[26453] chan_iax2.c: Peer 'dhn-sra' is not dynamic (from 10.60.34.101) Jul 2 13:09:21 DEBUG[26453] chan_iax2.c: Allocate call number Jul 2 13:09:21 DEBUG[26453] chan_iax2.c: Registration created on call 5 Jul 2 13:09:22 NOTICE[26453] chan_iax2.c: Registration of 'sra-dhn' rejected: 'Registration Refused' from: '10.60.34.101' Jul 2 13:09:23 DEBUG[26453] chan_iax2.c: Peer lastms 17, historicms 17, maxms 2000 Jul 2 13:09:25 DEBUG[26453] chan_iax2.c: Peer lastms 26, historicms 26, maxms 2000 Jul 2 13:09:26 DEBUG[26458] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP) Jul 2 13:09:26 DEBUG[26458] chan_sip.c: Header 0: OPTIONS sip:319@10.60.33.19:2051;line=jwqi2vzl SIP/2.0 (54) Jul 2 13:09:26 DEBUG[26458] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.60.33.102:5060;branch=z9hG4bK0616685f (57) Jul 2 13:09:26 DEBUG[26458] chan_sip.c: Header 2: From: "Unknown" ;tag=as631b77e2 (57) Jul 2 13:09:26 DEBUG[26458] chan_sip.c: Header 3: To: (44) Jul 2 13:09:26 DEBUG[26458] chan_sip.c: Header 4: Contact: (35) Jul 2 13:09:26 DEBUG[26458] chan_sip.c: Header 5: Call-ID: 77ef42760010059c690951ff729f9da9@10.60.33.102 (54) Jul 2 13:09:26 DEBUG[26458] chan_sip.c: Header 6: CSeq: 102 OPTIONS (17) Jul 2 13:09:26 DEBUG[26458] chan_sip.c: Header 7: User-Agent: Asterisk PBX (24) Jul 2 13:09:26 DEBUG[26458] chan_sip.c: Header 8: Max-Forwards: 70 (16) Jul 2 13:09:26 DEBUG[26458] chan_sip.c: Header 9: Date: Sun, 02 Jul 2006 05:09:26 GMT (35) Jul 2 13:09:26 DEBUG[26458] chan_sip.c: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) Jul 2 13:09:26 DEBUG[26458] chan_sip.c: Header 11: Content-Length: 0 (17) Jul 2 13:09:26 DEBUG[26458] chan_sip.c: Header 12: (0) Jul 2 13:09:26 DEBUG[26458] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #1021 Jul 2 13:09:26 DEBUG[26458] chan_sip.c: Header 0: SIP/2.0 200 OK (14) Jul 2 13:09:26 DEBUG[26458] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.60.33.102:5060;branch=z9hG4bK0616685f (57) Jul 2 13:09:26 DEBUG[26458] chan_sip.c: Header 2: From: "Unknown" ;tag=as631b77e2 (57) Jul 2 13:09:26 DEBUG[26458] chan_sip.c: Header 3: To: (44) Jul 2 13:09:26 DEBUG[26458] chan_sip.c: Header 4: Call-ID: 77ef42760010059c690951ff729f9da9@10.60.33.102 (54) Jul 2 13:09:26 DEBUG[26458] chan_sip.c: Header 5: CSeq: 102 OPTIONS (17) Jul 2 13:09:26 DEBUG[26458] chan_sip.c: Header 6: Contact: (49) Jul 2 13:09:26 DEBUG[26458] chan_sip.c: Header 7: User-Agent: snom190/3.60i (25) Jul 2 13:09:26 DEBUG[26458] chan_sip.c: Header 8: Accept-Language: en (19) Jul 2 13:09:26 DEBUG[26458] chan_sip.c: Header 9: Accept: application/sdp (23) Jul 2 13:09:26 DEBUG[26458] chan_sip.c: Header 10: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO (88) Jul 2 13:09:26 DEBUG[26458] chan_sip.c: Header 11: Allow-Events: talk, hold, refer (31) Jul 2 13:09:26 DEBUG[26458] chan_sip.c: Header 12: Supported: timer, 100rel, replaces (34) Jul 2 13:09:26 DEBUG[26458] chan_sip.c: Header 13: Content-Length: 0 (17) Jul 2 13:09:26 DEBUG[26458] chan_sip.c: Header 14: (0) Jul 2 13:09:26 DEBUG[26458] chan_sip.c: = Found Their Call ID: 77ef42760010059c690951ff729f9da9@10.60.33.102 Their Tag Our tag: as631b77e2 Jul 2 13:09:26 DEBUG[26458] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #1021 Jul 2 13:09:26 DEBUG[26458] chan_sip.c: Stopping retransmission on '77ef42760010059c690951ff729f9da9@10.60.33.102' of Request 102: Match Found Jul 2 13:09:26 DEBUG[26453] chan_iax2.c: Allocate call number Jul 2 13:09:26 DEBUG[26453] chan_iax2.c: Registration created on call 2 Jul 2 13:09:26 DEBUG[26453] chan_iax2.c: Peer lastms 18, historicms 18, maxms 2000 Jul 2 13:09:28 DEBUG[26780] manager.c: Manager received command 'Command' Jul 2 13:09:28 DEBUG[26780] manager.c: Manager received command 'Command' Jul 2 13:09:58 NOTICE[26453] chan_iax2.c: Peer 'dhn-sra' is not dynamic (from 10.60.34.101) Jul 2 13:10:11 DEBUG[26453] chan_iax2.c: Allocate call number Jul 2 13:10:11 DEBUG[26453] chan_iax2.c: Registration created on call 4 Jul 2 13:10:12 NOTICE[26453] chan_iax2.c: Registration of 'sra-dhn' rejected: 'Registration Refused' from: '10.60.34.101' Jul 2 13:10:16 DEBUG[26453] chan_iax2.c: Allocate call number Jul 2 13:10:16 DEBUG[26453] chan_iax2.c: Registration created on call 1 Jul 2 13:10:23 DEBUG[26453] chan_iax2.c: Peer lastms 16, historicms 16, maxms 2000 Jul 2 13:10:25 DEBUG[26453] chan_iax2.c: Peer lastms 30, historicms 30, maxms 2000 Jul 2 13:10:26 DEBUG[26458] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP) Jul 2 13:10:26 DEBUG[26458] chan_sip.c: Header 0: OPTIONS sip:319@10.60.33.19:2051;line=jwqi2vzl SIP/2.0 (54) Jul 2 13:10:26 DEBUG[26458] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.60.33.102:5060;branch=z9hG4bK60b035ef (57) Jul 2 13:10:26 DEBUG[26458] chan_sip.c: Header 2: From: "Unknown" ;tag=as1c8f7237 (57) Jul 2 13:10:26 DEBUG[26458] chan_sip.c: Header 3: To: (44) Jul 2 13:10:26 DEBUG[26458] chan_sip.c: Header 4: Contact: (35) Jul 2 13:10:26 DEBUG[26458] chan_sip.c: Header 5: Call-ID: 7abefa956732d3d76913abd2661bc646@10.60.33.102 (54) Jul 2 13:10:26 DEBUG[26458] chan_sip.c: Header 6: CSeq: 102 OPTIONS (17) Jul 2 13:10:26 DEBUG[26458] chan_sip.c: Header 7: User-Agent: Asterisk PBX (24) Jul 2 13:10:26 DEBUG[26458] chan_sip.c: Header 8: Max-Forwards: 70 (16) Jul 2 13:10:26 DEBUG[26458] chan_sip.c: Header 9: Date: Sun, 02 Jul 2006 05:10:26 GMT (35) Jul 2 13:10:26 DEBUG[26458] chan_sip.c: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) Jul 2 13:10:26 DEBUG[26458] chan_sip.c: Header 11: Content-Length: 0 (17) Jul 2 13:10:26 DEBUG[26458] chan_sip.c: Header 12: (0) Jul 2 13:10:26 DEBUG[26458] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #1024 Jul 2 13:10:26 DEBUG[26458] chan_sip.c: Header 0: SIP/2.0 200 OK (14) Jul 2 13:10:26 DEBUG[26458] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.60.33.102:5060;branch=z9hG4bK60b035ef (57) Jul 2 13:10:26 DEBUG[26458] chan_sip.c: Header 2: From: "Unknown" ;tag=as1c8f7237 (57) Jul 2 13:10:26 DEBUG[26458] chan_sip.c: Header 3: To: (44) Jul 2 13:10:26 DEBUG[26458] chan_sip.c: Header 4: Call-ID: 7abefa956732d3d76913abd2661bc646@10.60.33.102 (54) Jul 2 13:10:26 DEBUG[26458] chan_sip.c: Header 5: CSeq: 102 OPTIONS (17) Jul 2 13:10:26 DEBUG[26458] chan_sip.c: Header 6: Contact: (49) Jul 2 13:10:26 DEBUG[26458] chan_sip.c: Header 7: User-Agent: snom190/3.60i (25) Jul 2 13:10:26 DEBUG[26458] chan_sip.c: Header 8: Accept-Language: en (19) Jul 2 13:10:26 DEBUG[26458] chan_sip.c: Header 9: Accept: application/sdp (23) Jul 2 13:10:26 DEBUG[26458] chan_sip.c: Header 10: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO (88) Jul 2 13:10:26 DEBUG[26458] chan_sip.c: Header 11: Allow-Events: talk, hold, refer (31) Jul 2 13:10:26 DEBUG[26458] chan_sip.c: Header 12: Supported: timer, 100rel, replaces (34) Jul 2 13:10:26 DEBUG[26458] chan_sip.c: Header 13: Content-Length: 0 (17) Jul 2 13:10:26 DEBUG[26458] chan_sip.c: Header 14: (0) Jul 2 13:10:26 DEBUG[26458] chan_sip.c: = Found Their Call ID: 7abefa956732d3d76913abd2661bc646@10.60.33.102 Their Tag Our tag: as1c8f7237 Jul 2 13:10:26 DEBUG[26458] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #1024 Jul 2 13:10:26 DEBUG[26458] chan_sip.c: Stopping retransmission on '7abefa956732d3d76913abd2661bc646@10.60.33.102' of Request 102: Match Found Jul 2 13:10:26 DEBUG[26453] chan_iax2.c: Peer lastms 17, historicms 17, maxms 2000 Jul 2 13:10:48 NOTICE[26453] chan_iax2.c: Peer 'dhn-sra' is not dynamic (from 10.60.34.101) Jul 2 13:11:01 DEBUG[26453] chan_iax2.c: Allocate call number Jul 2 13:11:01 DEBUG[26453] chan_iax2.c: Registration created on call 3 Jul 2 13:11:02 NOTICE[26453] chan_iax2.c: Registration of 'sra-dhn' rejected: 'Registration Refused' from: '10.60.34.101' Jul 2 13:11:06 DEBUG[26453] chan_iax2.c: Allocate call number Jul 2 13:11:06 DEBUG[26453] chan_iax2.c: Registration created on call 11 Jul 2 13:11:23 DEBUG[26453] chan_iax2.c: Peer lastms 13, historicms 13, maxms 2000 Jul 2 13:11:25 DEBUG[26453] chan_iax2.c: Peer lastms 27, historicms 27, maxms 2000 Jul 2 13:11:26 DEBUG[26458] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP) Jul 2 13:11:26 DEBUG[26458] chan_sip.c: Header 0: OPTIONS sip:319@10.60.33.19:2051;line=jwqi2vzl SIP/2.0 (54) Jul 2 13:11:26 DEBUG[26458] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.60.33.102:5060;branch=z9hG4bK1e7c8f98 (57) Jul 2 13:11:26 DEBUG[26458] chan_sip.c: Header 2: From: "Unknown" ;tag=as4cefbf66 (57) Jul 2 13:11:26 DEBUG[26458] chan_sip.c: Header 3: To: (44) Jul 2 13:11:26 DEBUG[26458] chan_sip.c: Header 4: Contact: (35) Jul 2 13:11:26 DEBUG[26458] chan_sip.c: Header 5: Call-ID: 2e8c3ff523cdeb116669e7744a62a55b@10.60.33.102 (54) Jul 2 13:11:26 DEBUG[26458] chan_sip.c: Header 6: CSeq: 102 OPTIONS (17) Jul 2 13:11:26 DEBUG[26458] chan_sip.c: Header 7: User-Agent: Asterisk PBX (24) Jul 2 13:11:26 DEBUG[26458] chan_sip.c: Header 8: Max-Forwards: 70 (16) Jul 2 13:11:26 DEBUG[26458] chan_sip.c: Header 9: Date: Sun, 02 Jul 2006 05:11:26 GMT (35) Jul 2 13:11:26 DEBUG[26458] chan_sip.c: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) Jul 2 13:11:26 DEBUG[26458] chan_sip.c: Header 11: Content-Length: 0 (17) Jul 2 13:11:26 DEBUG[26458] chan_sip.c: Header 12: (0) Jul 2 13:11:26 DEBUG[26458] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #1027 Jul 2 13:11:26 DEBUG[26458] chan_sip.c: Header 0: SIP/2.0 200 OK (14) Jul 2 13:11:26 DEBUG[26458] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.60.33.102:5060;branch=z9hG4bK1e7c8f98 (57) Jul 2 13:11:26 DEBUG[26458] chan_sip.c: Header 2: From: "Unknown" ;tag=as4cefbf66 (57) Jul 2 13:11:26 DEBUG[26458] chan_sip.c: Header 3: To: (44) Jul 2 13:11:26 DEBUG[26458] chan_sip.c: Header 4: Call-ID: 2e8c3ff523cdeb116669e7744a62a55b@10.60.33.102 (54) Jul 2 13:11:26 DEBUG[26458] chan_sip.c: Header 5: CSeq: 102 OPTIONS (17) Jul 2 13:11:26 DEBUG[26458] chan_sip.c: Header 6: Contact: (49) Jul 2 13:11:26 DEBUG[26458] chan_sip.c: Header 7: User-Agent: snom190/3.60i (25) Jul 2 13:11:26 DEBUG[26458] chan_sip.c: Header 8: Accept-Language: en (19) Jul 2 13:11:26 DEBUG[26458] chan_sip.c: Header 9: Accept: application/sdp (23) Jul 2 13:11:26 DEBUG[26458] chan_sip.c: Header 10: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO (88) Jul 2 13:11:26 DEBUG[26458] chan_sip.c: Header 11: Allow-Events: talk, hold, refer (31) Jul 2 13:11:26 DEBUG[26458] chan_sip.c: Header 12: Supported: timer, 100rel, replaces (34) Jul 2 13:11:26 DEBUG[26458] chan_sip.c: Header 13: Content-Length: 0 (17) Jul 2 13:11:26 DEBUG[26458] chan_sip.c: Header 14: (0) Jul 2 13:11:26 DEBUG[26458] chan_sip.c: = Found Their Call ID: 2e8c3ff523cdeb116669e7744a62a55b@10.60.33.102 Their Tag Our tag: as4cefbf66 Jul 2 13:11:26 DEBUG[26458] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #1027 Jul 2 13:11:26 DEBUG[26458] chan_sip.c: Stopping retransmission on '2e8c3ff523cdeb116669e7744a62a55b@10.60.33.102' of Request 102: Match Found Jul 2 13:11:27 DEBUG[26453] chan_iax2.c: Peer lastms 1022, historicms 1022, maxms 2000 Jul 2 13:11:28 DEBUG[26780] manager.c: Manager received command 'Command' Jul 2 13:11:28 DEBUG[26780] manager.c: Manager received command 'Command' Jul 2 13:11:38 NOTICE[26453] chan_iax2.c: Peer 'dhn-sra' is not dynamic (from 10.60.34.101) Jul 2 13:11:51 DEBUG[26453] chan_iax2.c: Allocate call number Jul 2 13:11:51 DEBUG[26453] chan_iax2.c: Registration created on call 2 Jul 2 13:11:52 NOTICE[26453] chan_iax2.c: Registration of 'sra-dhn' rejected: 'Registration Refused' from: '10.60.34.101' Jul 2 13:11:56 DEBUG[26453] chan_iax2.c: Allocate call number Jul 2 13:11:56 DEBUG[26453] chan_iax2.c: Registration created on call 9 Jul 2 13:12:23 DEBUG[26453] chan_iax2.c: Peer lastms 24, historicms 24, maxms 2000 Jul 2 13:12:25 DEBUG[26453] chan_iax2.c: Peer lastms 30, historicms 30, maxms 2000 Jul 2 13:12:26 DEBUG[26458] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP) Jul 2 13:12:26 DEBUG[26458] chan_sip.c: Header 0: OPTIONS sip:319@10.60.33.19:2051;line=jwqi2vzl SIP/2.0 (54) Jul 2 13:12:26 DEBUG[26458] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.60.33.102:5060;branch=z9hG4bK73faead6 (57) Jul 2 13:12:26 DEBUG[26458] chan_sip.c: Header 2: From: "Unknown" ;tag=as3d8b497d (57) Jul 2 13:12:26 DEBUG[26458] chan_sip.c: Header 3: To: (44) Jul 2 13:12:26 DEBUG[26458] chan_sip.c: Header 4: Contact: (35) Jul 2 13:12:26 DEBUG[26458] chan_sip.c: Header 5: Call-ID: 67872131414e91454408b66025e15905@10.60.33.102 (54) Jul 2 13:12:26 DEBUG[26458] chan_sip.c: Header 6: CSeq: 102 OPTIONS (17) Jul 2 13:12:26 DEBUG[26458] chan_sip.c: Header 7: User-Agent: Asterisk PBX (24) Jul 2 13:12:26 DEBUG[26458] chan_sip.c: Header 8: Max-Forwards: 70 (16) Jul 2 13:12:26 DEBUG[26458] chan_sip.c: Header 9: Date: Sun, 02 Jul 2006 05:12:26 GMT (35) Jul 2 13:12:26 DEBUG[26458] chan_sip.c: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) Jul 2 13:12:26 DEBUG[26458] chan_sip.c: Header 11: Content-Length: 0 (17) Jul 2 13:12:26 DEBUG[26458] chan_sip.c: Header 12: (0) Jul 2 13:12:26 DEBUG[26458] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #1030 Jul 2 13:12:26 DEBUG[26458] chan_sip.c: Header 0: SIP/2.0 200 OK (14) Jul 2 13:12:26 DEBUG[26458] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.60.33.102:5060;branch=z9hG4bK73faead6 (57) Jul 2 13:12:26 DEBUG[26458] chan_sip.c: Header 2: From: "Unknown" ;tag=as3d8b497d (57) Jul 2 13:12:26 DEBUG[26458] chan_sip.c: Header 3: To: (44) Jul 2 13:12:26 DEBUG[26458] chan_sip.c: Header 4: Call-ID: 67872131414e91454408b66025e15905@10.60.33.102 (54) Jul 2 13:12:26 DEBUG[26458] chan_sip.c: Header 5: CSeq: 102 OPTIONS (17) Jul 2 13:12:26 DEBUG[26458] chan_sip.c: Header 6: Contact: (49) Jul 2 13:12:26 DEBUG[26458] chan_sip.c: Header 7: User-Agent: snom190/3.60i (25) Jul 2 13:12:26 DEBUG[26458] chan_sip.c: Header 8: Accept-Language: en (19) Jul 2 13:12:26 DEBUG[26458] chan_sip.c: Header 9: Accept: application/sdp (23) Jul 2 13:12:26 DEBUG[26458] chan_sip.c: Header 10: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO (88) Jul 2 13:12:26 DEBUG[26458] chan_sip.c: Header 11: Allow-Events: talk, hold, refer (31) Jul 2 13:12:26 DEBUG[26458] chan_sip.c: Header 12: Supported: timer, 100rel, replaces (34) Jul 2 13:12:26 DEBUG[26458] chan_sip.c: Header 13: Content-Length: 0 (17) Jul 2 13:12:26 DEBUG[26458] chan_sip.c: Header 14: (0) Jul 2 13:12:26 DEBUG[26458] chan_sip.c: = Found Their Call ID: 67872131414e91454408b66025e15905@10.60.33.102 Their Tag Our tag: as3d8b497d Jul 2 13:12:26 DEBUG[26458] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #1030 Jul 2 13:12:26 DEBUG[26458] chan_sip.c: Stopping retransmission on '67872131414e91454408b66025e15905@10.60.33.102' of Request 102: Match Found Jul 2 13:12:27 DEBUG[26453] chan_iax2.c: Peer lastms 17, historicms 17, maxms 2000 Jul 2 13:12:28 NOTICE[26453] chan_iax2.c: Peer 'dhn-sra' is not dynamic (from 10.60.34.101) Jul 2 13:12:41 DEBUG[26453] chan_iax2.c: Allocate call number Jul 2 13:12:41 DEBUG[26453] chan_iax2.c: Registration created on call 6 Jul 2 13:12:42 NOTICE[26453] chan_iax2.c: Registration of 'sra-dhn' rejected: 'Registration Refused' from: '10.60.34.101' Jul 2 13:12:46 DEBUG[26453] chan_iax2.c: Allocate call number Jul 2 13:12:46 DEBUG[26453] chan_iax2.c: Registration created on call 11 Jul 2 13:12:54 DEBUG[26458] chan_sip.c: Header 0: SUBSCRIBE sip:301@10.60.33.102;user=phone SIP/2.0 (49) Jul 2 13:12:54 DEBUG[26458] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.60.33.39:2051;branch=z9hG4bK-wzl8h0c5jnao;rport (67) Jul 2 13:12:54 DEBUG[26458] chan_sip.c: Header 2: From: ;tag=7r5ssj161s (43) Jul 2 13:12:54 DEBUG[26458] chan_sip.c: Header 3: To: (37) Jul 2 13:12:54 DEBUG[26458] chan_sip.c: Header 4: Call-ID: 3d561c3283d6-vab9wym5x35n@snom190 (42) Jul 2 13:12:54 DEBUG[26458] chan_sip.c: Header 5: CSeq: 6554 SUBSCRIBE (20) Jul 2 13:12:54 DEBUG[26458] chan_sip.c: Header 6: Max-Forwards: 70 (16) Jul 2 13:12:54 DEBUG[26458] chan_sip.c: Header 7: Contact: (49) Jul 2 13:12:54 DEBUG[26458] chan_sip.c: Header 8: Event: dialog (13) Jul 2 13:12:54 DEBUG[26458] chan_sip.c: Header 9: Accept: application/dialog-info+xml (35) Jul 2 13:12:54 DEBUG[26458] chan_sip.c: Header 10: Expires: 3600 (13) Jul 2 13:12:54 DEBUG[26458] chan_sip.c: Header 11: Content-Length: 0 (17) Jul 2 13:12:54 DEBUG[26458] chan_sip.c: Header 12: (0) Jul 2 13:12:54 DEBUG[26458] chan_sip.c: Allocating new SIP dialog for 3d561c3283d6-vab9wym5x35n@snom190 - SUBSCRIBE (No RTP) Jul 2 13:12:54 DEBUG[26458] chan_sip.c: **** Received SUBSCRIBE (10) - Command in SIP SUBSCRIBE Jul 2 13:12:54 DEBUG[26458] chan_sip.c: Adding subscription for extension 301 context from-internal for peer 339 Jul 2 13:12:54 ERROR[26458] chan_sip.c: Got SUBSCRIBE for extensions without hint. Please add hint to 301 in context from-internal Jul 2 13:13:18 NOTICE[26453] chan_iax2.c: Peer 'dhn-sra' is not dynamic (from 10.60.34.101) Jul 2 13:13:23 DEBUG[26453] chan_iax2.c: Peer lastms 12, historicms 12, maxms 2000 Jul 2 13:13:25 DEBUG[26453] chan_iax2.c: Peer lastms 32, historicms 32, maxms 2000 Jul 2 13:13:26 DEBUG[26458] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP) Jul 2 13:13:26 DEBUG[26458] chan_sip.c: Header 0: OPTIONS sip:319@10.60.33.19:2051;line=jwqi2vzl SIP/2.0 (54) Jul 2 13:13:26 DEBUG[26458] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.60.33.102:5060;branch=z9hG4bK45f50d02 (57) Jul 2 13:13:26 DEBUG[26458] chan_sip.c: Header 2: From: "Unknown" ;tag=as648453d9 (57) Jul 2 13:13:26 DEBUG[26458] chan_sip.c: Header 3: To: (44) Jul 2 13:13:26 DEBUG[26458] chan_sip.c: Header 4: Contact: (35) Jul 2 13:13:26 DEBUG[26458] chan_sip.c: Header 5: Call-ID: 1f332564183737b835765a7c6ef24f85@10.60.33.102 (54) Jul 2 13:13:26 DEBUG[26458] chan_sip.c: Header 6: CSeq: 102 OPTIONS (17) Jul 2 13:13:26 DEBUG[26458] chan_sip.c: Header 7: User-Agent: Asterisk PBX (24) Jul 2 13:13:26 DEBUG[26458] chan_sip.c: Header 8: Max-Forwards: 70 (16) Jul 2 13:13:26 DEBUG[26458] chan_sip.c: Header 9: Date: Sun, 02 Jul 2006 05:13:26 GMT (35) Jul 2 13:13:26 DEBUG[26458] chan_sip.c: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) Jul 2 13:13:26 DEBUG[26458] chan_sip.c: Header 11: Content-Length: 0 (17) Jul 2 13:13:26 DEBUG[26458] chan_sip.c: Header 12: (0) Jul 2 13:13:26 DEBUG[26458] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #1034 Jul 2 13:13:26 DEBUG[26458] chan_sip.c: Header 0: SIP/2.0 200 OK (14) Jul 2 13:13:26 DEBUG[26458] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.60.33.102:5060;branch=z9hG4bK45f50d02 (57) Jul 2 13:13:26 DEBUG[26458] chan_sip.c: Header 2: From: "Unknown" ;tag=as648453d9 (57) Jul 2 13:13:26 DEBUG[26458] chan_sip.c: Header 3: To: (44) Jul 2 13:13:26 DEBUG[26458] chan_sip.c: Header 4: Call-ID: 1f332564183737b835765a7c6ef24f85@10.60.33.102 (54) Jul 2 13:13:26 DEBUG[26458] chan_sip.c: Header 5: CSeq: 102 OPTIONS (17) Jul 2 13:13:26 DEBUG[26458] chan_sip.c: Header 6: Contact: (49) Jul 2 13:13:26 DEBUG[26458] chan_sip.c: Header 7: User-Agent: snom190/3.60i (25) Jul 2 13:13:26 DEBUG[26458] chan_sip.c: Header 8: Accept-Language: en (19) Jul 2 13:13:26 DEBUG[26458] chan_sip.c: Header 9: Accept: application/sdp (23) Jul 2 13:13:26 DEBUG[26458] chan_sip.c: Header 10: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO (88) Jul 2 13:13:26 DEBUG[26458] chan_sip.c: Header 11: Allow-Events: talk, hold, refer (31) Jul 2 13:13:26 DEBUG[26458] chan_sip.c: Header 12: Supported: timer, 100rel, replaces (34) Jul 2 13:13:26 DEBUG[26458] chan_sip.c: Header 13: Content-Length: 0 (17) Jul 2 13:13:26 DEBUG[26458] chan_sip.c: Header 14: (0) Jul 2 13:13:26 DEBUG[26458] chan_sip.c: = Found Their Call ID: 1f332564183737b835765a7c6ef24f85@10.60.33.102 Their Tag Our tag: as648453d9 Jul 2 13:13:26 DEBUG[26458] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #1034 Jul 2 13:13:26 DEBUG[26458] chan_sip.c: Stopping retransmission on '1f332564183737b835765a7c6ef24f85@10.60.33.102' of Request 102: Match Found Jul 2 13:13:27 DEBUG[26453] chan_iax2.c: Peer lastms 18, historicms 18, maxms 2000 Jul 2 13:13:28 DEBUG[26780] manager.c: Manager received command 'Command' Jul 2 13:13:28 DEBUG[26780] manager.c: Manager received command 'Command' Jul 2 13:13:31 DEBUG[26453] chan_iax2.c: Allocate call number Jul 2 13:13:31 DEBUG[26453] chan_iax2.c: Registration created on call 5 Jul 2 13:13:32 NOTICE[26453] chan_iax2.c: Registration of 'sra-dhn' rejected: 'Registration Refused' from: '10.60.34.101' Jul 2 13:13:36 DEBUG[26453] chan_iax2.c: Allocate call number Jul 2 13:13:36 DEBUG[26453] chan_iax2.c: Registration created on call 7 Jul 2 13:14:08 NOTICE[26453] chan_iax2.c: Peer 'dhn-sra' is not dynamic (from 10.60.34.101) Jul 2 13:14:21 DEBUG[26453] chan_iax2.c: Allocate call number Jul 2 13:14:21 DEBUG[26453] chan_iax2.c: Registration created on call 3 Jul 2 13:14:22 NOTICE[26453] chan_iax2.c: Registration of 'sra-dhn' rejected: 'Registration Refused' from: '10.60.34.101' Jul 2 13:14:23 DEBUG[26453] chan_iax2.c: Peer lastms 13, historicms 13, maxms 2000 Jul 2 13:14:25 DEBUG[26453] chan_iax2.c: Peer lastms 26, historicms 26, maxms 2000 Jul 2 13:14:26 DEBUG[26458] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP) Jul 2 13:14:26 DEBUG[26458] chan_sip.c: Header 0: OPTIONS sip:319@10.60.33.19:2051;line=jwqi2vzl SIP/2.0 (54) Jul 2 13:14:26 DEBUG[26458] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.60.33.102:5060;branch=z9hG4bK334b84fc (57) Jul 2 13:14:26 DEBUG[26458] chan_sip.c: Header 2: From: "Unknown" ;tag=as11a8b4d6 (57) Jul 2 13:14:26 DEBUG[26458] chan_sip.c: Header 3: To: (44) Jul 2 13:14:26 DEBUG[26458] chan_sip.c: Header 4: Contact: (35) Jul 2 13:14:26 DEBUG[26458] chan_sip.c: Header 5: Call-ID: 364c240c19679bee7612ebaa34dc6db8@10.60.33.102 (54) Jul 2 13:14:26 DEBUG[26458] chan_sip.c: Header 6: CSeq: 102 OPTIONS (17) Jul 2 13:14:26 DEBUG[26458] chan_sip.c: Header 7: User-Agent: Asterisk PBX (24) Jul 2 13:14:26 DEBUG[26458] chan_sip.c: Header 8: Max-Forwards: 70 (16) Jul 2 13:14:26 DEBUG[26458] chan_sip.c: Header 9: Date: Sun, 02 Jul 2006 05:14:26 GMT (35) Jul 2 13:14:26 DEBUG[26458] chan_sip.c: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) Jul 2 13:14:26 DEBUG[26458] chan_sip.c: Header 11: Content-Length: 0 (17) Jul 2 13:14:26 DEBUG[26458] chan_sip.c: Header 12: (0) Jul 2 13:14:26 DEBUG[26458] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #1037 Jul 2 13:14:26 DEBUG[26458] chan_sip.c: Header 0: SIP/2.0 200 OK (14) Jul 2 13:14:26 DEBUG[26458] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.60.33.102:5060;branch=z9hG4bK334b84fc (57) Jul 2 13:14:26 DEBUG[26458] chan_sip.c: Header 2: From: "Unknown" ;tag=as11a8b4d6 (57) Jul 2 13:14:26 DEBUG[26458] chan_sip.c: Header 3: To: (44) Jul 2 13:14:26 DEBUG[26458] chan_sip.c: Header 4: Call-ID: 364c240c19679bee7612ebaa34dc6db8@10.60.33.102 (54) Jul 2 13:14:26 DEBUG[26458] chan_sip.c: Header 5: CSeq: 102 OPTIONS (17) Jul 2 13:14:26 DEBUG[26458] chan_sip.c: Header 6: Contact: (49) Jul 2 13:14:26 DEBUG[26458] chan_sip.c: Header 7: User-Agent: snom190/3.60i (25) Jul 2 13:14:26 DEBUG[26458] chan_sip.c: Header 8: Accept-Language: en (19) Jul 2 13:14:26 DEBUG[26458] chan_sip.c: Header 9: Accept: application/sdp (23) Jul 2 13:14:26 DEBUG[26458] chan_sip.c: Header 10: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO (88) Jul 2 13:14:26 DEBUG[26458] chan_sip.c: Header 11: Allow-Events: talk, hold, refer (31) Jul 2 13:14:26 DEBUG[26458] chan_sip.c: Header 12: Supported: timer, 100rel, replaces (34) Jul 2 13:14:26 DEBUG[26458] chan_sip.c: Header 13: Content-Length: 0 (17) Jul 2 13:14:26 DEBUG[26458] chan_sip.c: Header 14: (0) Jul 2 13:14:26 DEBUG[26458] chan_sip.c: = Found Their Call ID: 364c240c19679bee7612ebaa34dc6db8@10.60.33.102 Their Tag Our tag: as11a8b4d6 Jul 2 13:14:26 DEBUG[26458] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #1037 Jul 2 13:14:26 DEBUG[26458] chan_sip.c: Stopping retransmission on '364c240c19679bee7612ebaa34dc6db8@10.60.33.102' of Request 102: Match Found Jul 2 13:14:26 DEBUG[26453] chan_iax2.c: Allocate call number Jul 2 13:14:26 DEBUG[26453] chan_iax2.c: Registration created on call 4 Jul 2 13:14:27 DEBUG[26453] chan_iax2.c: Peer lastms 20, historicms 20, maxms 2000 Jul 2 13:14:58 NOTICE[26453] chan_iax2.c: Peer 'dhn-sra' is not dynamic (from 10.60.34.101) Jul 2 13:15:11 DEBUG[26453] chan_iax2.c: Allocate call number Jul 2 13:15:11 DEBUG[26453] chan_iax2.c: Registration created on call 5 Jul 2 13:15:12 NOTICE[26453] chan_iax2.c: Registration of 'sra-dhn' rejected: 'Registration Refused' from: '10.60.34.101' Jul 2 13:15:16 DEBUG[26453] chan_iax2.c: Allocate call number Jul 2 13:15:16 DEBUG[26453] chan_iax2.c: Registration created on call 2 Jul 2 13:15:23 DEBUG[26453] chan_iax2.c: Peer lastms 18, historicms 18, maxms 2000 Jul 2 13:15:25 DEBUG[26453] chan_iax2.c: Peer lastms 33, historicms 33, maxms 2000 Jul 2 13:15:26 DEBUG[26458] chan_sip.c: Allocating new SIP dialog for (No Call-ID) - OPTIONS (No RTP) Jul 2 13:15:26 DEBUG[26458] chan_sip.c: Header 0: OPTIONS sip:319@10.60.33.19:2051;line=jwqi2vzl SIP/2.0 (54) Jul 2 13:15:26 DEBUG[26458] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.60.33.102:5060;branch=z9hG4bK037cbf84 (57) Jul 2 13:15:26 DEBUG[26458] chan_sip.c: Header 2: From: "Unknown" ;tag=as73215ad2 (57) Jul 2 13:15:26 DEBUG[26458] chan_sip.c: Header 3: To: (44) Jul 2 13:15:26 DEBUG[26458] chan_sip.c: Header 4: Contact: (35) Jul 2 13:15:26 DEBUG[26458] chan_sip.c: Header 5: Call-ID: 2894e02c4524526300e2d56c3e4d42b5@10.60.33.102 (54) Jul 2 13:15:26 DEBUG[26458] chan_sip.c: Header 6: CSeq: 102 OPTIONS (17) Jul 2 13:15:26 DEBUG[26458] chan_sip.c: Header 7: User-Agent: Asterisk PBX (24) Jul 2 13:15:26 DEBUG[26458] chan_sip.c: Header 8: Max-Forwards: 70 (16) Jul 2 13:15:26 DEBUG[26458] chan_sip.c: Header 9: Date: Sun, 02 Jul 2006 05:15:26 GMT (35) Jul 2 13:15:26 DEBUG[26458] chan_sip.c: Header 10: Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY (66) Jul 2 13:15:26 DEBUG[26458] chan_sip.c: Header 11: Content-Length: 0 (17) Jul 2 13:15:26 DEBUG[26458] chan_sip.c: Header 12: (0) Jul 2 13:15:26 DEBUG[26458] chan_sip.c: *** SIP TIMER: Initalizing retransmit timer on packet: Id #1040 Jul 2 13:15:26 DEBUG[26458] chan_sip.c: Header 0: SIP/2.0 200 OK (14) Jul 2 13:15:26 DEBUG[26458] chan_sip.c: Header 1: Via: SIP/2.0/UDP 10.60.33.102:5060;branch=z9hG4bK037cbf84 (57) Jul 2 13:15:26 DEBUG[26458] chan_sip.c: Header 2: From: "Unknown" ;tag=as73215ad2 (57) Jul 2 13:15:26 DEBUG[26458] chan_sip.c: Header 3: To: (44) Jul 2 13:15:26 DEBUG[26458] chan_sip.c: Header 4: Call-ID: 2894e02c4524526300e2d56c3e4d42b5@10.60.33.102 (54) Jul 2 13:15:26 DEBUG[26458] chan_sip.c: Header 5: CSeq: 102 OPTIONS (17) Jul 2 13:15:26 DEBUG[26458] chan_sip.c: Header 6: Contact: (49) Jul 2 13:15:26 DEBUG[26458] chan_sip.c: Header 7: User-Agent: snom190/3.60i (25) Jul 2 13:15:26 DEBUG[26458] chan_sip.c: Header 8: Accept-Language: en (19) Jul 2 13:15:26 DEBUG[26458] chan_sip.c: Header 9: Accept: application/sdp (23) Jul 2 13:15:26 DEBUG[26458] chan_sip.c: Header 10: Allow: INVITE, ACK, CANCEL, BYE, REFER, OPTIONS, NOTIFY, SUBSCRIBE, PRACK, MESSAGE, INFO (88) Jul 2 13:15:26 DEBUG[26458] chan_sip.c: Header 11: Allow-Events: talk, hold, refer (31) Jul 2 13:15:26 DEBUG[26458] chan_sip.c: Header 12: Supported: timer, 100rel, replaces (34) Jul 2 13:15:26 DEBUG[26458] chan_sip.c: Header 13: Content-Length: 0 (17) Jul 2 13:15:26 DEBUG[26458] chan_sip.c: Header 14: (0) Jul 2 13:15:26 DEBUG[26458] chan_sip.c: = Found Their Call ID: 2894e02c4524526300e2d56c3e4d42b5@10.60.33.102 Their Tag Our tag: as73215ad2 Jul 2 13:15:26 DEBUG[26458] chan_sip.c: ** SIP TIMER: Cancelling retransmit of packet (reply received) Retransid #1040 Jul 2 13:15:26 DEBUG[26458] chan_sip.c: Stopping retransmission on '2894e02c4524526300e2d56c3e4d42b5@10.60.33.102' of Request 102: Match Found Jul 2 13:15:28 DEBUG[26453] chan_iax2.c: Peer lastms 18, historicms 18, maxms 2000 Jul 2 13:15:28 DEBUG[26780] manager.c: Manager received command 'Command' Jul 2 13:15:28 DEBUG[26780] manager.c: Manager received command 'Command' Jul 2 13:15:48 NOTICE[26453] chan_iax2.c: Peer 'dhn-sra' is not dynamic (from 10.60.34.101) Jul 2 13:16:01 DEBUG[26453] chan_iax2.c: Allocate call number Jul 2 13:16:01 DEBUG[26453] chan_iax2.c: Registration created on call 1 Jul 2 13:16:02 NOTICE[26453] chan_iax2.c: Registration of 'sra-dhn' rejected: 'Registration Refused' from: '10.60.34.101' Jul 2 13:16:06 DEBUG[26453] chan_iax2.c: Allocate call number Jul 2 13:16:06 DEBUG[26453] chan_iax2.c: Registration created on call 11