rendered paste body<--- SIP read from 192.168.254.100:5060 --->
REGISTER sip:pbx.rplaw:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.254.100;branch=z9hG4bKb513517aEB6CD8ED
From: "Chip (Flagstaff)" <sip:307@pbx.rplaw>;tag=CB36B93D-662A9AB4
To: <sip:307@pbx.rplaw>
CSeq: 123 REGISTER
Call-ID: 35b6b2f0-40eeebab-ad01dd0a@192.168.254.100
Contact: <sip:307@192.168.254.100>;methods="INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER"
User-Agent: PolycomSoundPointIP-SPIP_330-UA/2.2.2.0084
Authorization: Digest username="307", realm="asterisk", nonce="02fe34ce", uri="sip:pbx.rplaw:5060", response="eff67ffe3b64a91a7214a8f3193e634e", algorithm=MD5
Max-Forwards: 70
Expires: 3600
Content-Length: 0
<------------->
[Nov 16 14:51:17] VERBOSE[3200] logger.c: --- (12 headers 0 lines) ---
[Nov 16 14:51:17] VERBOSE[3200] logger.c: Using latest REGISTER request as basis request
[Nov 16 14:51:17] VERBOSE[3200] logger.c: Sending to 192.168.254.100 : 5060 (no NAT)
[Nov 16 14:51:17] VERBOSE[3200] logger.c:
<--- Transmitting (no NAT) to 192.168.254.100:5060 --->
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 192.168.254.100;branch=z9hG4bKb513517aEB6CD8ED;received=192.168.254.100
From: "Chip (Flagstaff)" <sip:307@pbx.rplaw>;tag=CB36B93D-662A9AB4
To: <sip:307@pbx.rplaw>
Call-ID: 35b6b2f0-40eeebab-ad01dd0a@192.168.254.100
CSeq: 123 REGISTER
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
Contact: <sip:307@192.168.255.2>
Content-Length: 0
<------------>
[Nov 16 14:51:17] VERBOSE[3200] logger.c:
<--- Transmitting (no NAT) to 192.168.254.100:5060 --->
SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP 192.168.254.100;branch=z9hG4bKb513517aEB6CD8ED;received=192.168.254.100
From: "Chip (Flagstaff)" <sip:307@pbx.rplaw>;tag=CB36B93D-662A9AB4
To: <sip:307@pbx.rplaw>;tag=as784e5d2d
Call-ID: 35b6b2f0-40eeebab-ad01dd0a@192.168.254.100
CSeq: 123 REGISTER
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="22f65f6e"
Content-Length: 0
<------------>
[Nov 16 14:51:17] VERBOSE[3200] logger.c: Scheduling destruction of SIP dialog '35b6b2f0-40eeebab-ad01dd0a@192.168.254.100' in 32000 ms (Method: REGISTER)
[Nov 16 14:51:17] VERBOSE[3200] logger.c:
<--- SIP read from 192.168.254.100:5060 --->
REGISTER sip:pbx.rplaw:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.254.100;branch=z9hG4bKcf1bb4a41C7464F
From: "Chip (Flagstaff)" <sip:307@pbx.rplaw>;tag=CB36B93D-662A9AB4
To: <sip:307@pbx.rplaw>
CSeq: 124 REGISTER
Call-ID: 35b6b2f0-40eeebab-ad01dd0a@192.168.254.100
Contact: <sip:307@192.168.254.100>;methods="INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER"
User-Agent: PolycomSoundPointIP-SPIP_330-UA/2.2.2.0084
Authorization: Digest username="307", realm="asterisk", nonce="22f65f6e", uri="sip:pbx.rplaw:5060", response="02f92131dd898d755d82d62dc429bc90", algorithm=MD5
Max-Forwards: 70
Expires: 3600
Content-Length: 0
<------------->
[Nov 16 14:51:17] VERBOSE[3200] logger.c: --- (12 headers 0 lines) ---
[Nov 16 14:51:17] VERBOSE[3200] logger.c: Using latest REGISTER request as basis request
[Nov 16 14:51:17] VERBOSE[3200] logger.c: Sending to 192.168.254.100 : 5060 (no NAT)
[Nov 16 14:51:17] VERBOSE[3200] logger.c:
<--- Transmitting (no NAT) to 192.168.254.100:5060 --->
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 192.168.254.100;branch=z9hG4bKcf1bb4a41C7464F;received=192.168.254.100
From: "Chip (Flagstaff)" <sip:307@pbx.rplaw>;tag=CB36B93D-662A9AB4
To: <sip:307@pbx.rplaw>
Call-ID: 35b6b2f0-40eeebab-ad01dd0a@192.168.254.100
CSeq: 124 REGISTER
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
Contact: <sip:307@192.168.255.2>
Content-Length: 0
<------------>
[Nov 16 14:51:17] VERBOSE[3200] logger.c:
<--- Transmitting (no NAT) to 192.168.254.100:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.254.100;branch=z9hG4bKcf1bb4a41C7464F;received=192.168.254.100
From: "Chip (Flagstaff)" <sip:307@pbx.rplaw>;tag=CB36B93D-662A9AB4
To: <sip:307@pbx.rplaw>;tag=as784e5d2d
Call-ID: 35b6b2f0-40eeebab-ad01dd0a@192.168.254.100
CSeq: 124 REGISTER
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
Expires: 3600
Contact: <sip:307@192.168.254.100>;expires=3600
Date: Sun, 16 Nov 2008 21:51:17 GMT
Content-Length: 0
<------------>
[Nov 16 14:51:17] VERBOSE[3200] logger.c: Scheduling destruction of SIP dialog '35b6b2f0-40eeebab-ad01dd0a@192.168.254.100' in 32000 ms (Method: REGISTER)
[Nov 16 14:51:21] VERBOSE[3200] logger.c: Scheduling destruction of SIP dialog '637933a10ea57f5a29d7c39435f41a92@192.168.255.2' in 6400 ms (Method: NOTIFY)
[Nov 16 14:51:21] VERBOSE[3200] logger.c: Reliably Transmitting (no NAT) to 192.168.254.100:5060:
NOTIFY sip:307@192.168.254.100 SIP/2.0
Via: SIP/2.0/UDP 192.168.255.2:5060;branch=z9hG4bK1b94df98;rport
From: "Unknown" <sip:Unknown@192.168.255.2>;tag=as480173b2
To: <sip:307@192.168.254.100>
Contact: <sip:Unknown@192.168.255.2>
Call-ID: 637933a10ea57f5a29d7c39435f41a92@192.168.255.2
CSeq: 102 NOTIFY
User-Agent: Asterisk PBX
Max-Forwards: 70
Event: message-summary
Content-Type: application/simple-message-summary
Content-Length: 93
Messages-Waiting: no
Message-Account: sip:asterisk@192.168.255.2
Voice-Message: 0/0 (0/0)
---
[Nov 16 14:51:21] VERBOSE[3200] logger.c:
<--- SIP read from 192.168.254.100:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.255.2:5060;branch=z9hG4bK1b94df98;rport
From: "Unknown" <sip:Unknown@192.168.255.2>;tag=as480173b2
To: <sip:307@192.168.254.100>;tag=6A6C41DE-5EAA3081
CSeq: 102 NOTIFY
Call-ID: 637933a10ea57f5a29d7c39435f41a92@192.168.255.2
Contact: <sip:307@192.168.254.100>
Event: message-summary
User-Agent: PolycomSoundPointIP-SPIP_330-UA/2.2.2.0084
Content-Length: 0
<------------->
[Nov 16 14:51:21] VERBOSE[3200] logger.c: --- (10 headers 0 lines) ---
[Nov 16 14:51:21] VERBOSE[3200] logger.c: Really destroying SIP dialog '637933a10ea57f5a29d7c39435f41a92@192.168.255.2' Method: NOTIFY
[Nov 16 14:51:30] VERBOSE[3200] logger.c:
<--- SIP read from 192.168.254.100:5060 --->
INVITE sip:8913738@pbx.rplaw:5060;user=phone SIP/2.0
Via: SIP/2.0/UDP 192.168.254.100;branch=z9hG4bK9a87f7a8AC2A1403
From: "Chip (Flagstaff)" <sip:307@pbx.rplaw>;tag=3121FCF7-AAE15966
To: <sip:8913738@pbx.rplaw;user=phone>
CSeq: 1 INVITE
Call-ID: 40137882-903b4155-5a49aaec@192.168.254.100
Contact: <sip:307@192.168.254.100>
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER
User-Agent: PolycomSoundPointIP-SPIP_330-UA/2.2.2.0084
Supported: 100rel,replaces
Allow-Events: talk,hold,conference
Max-Forwards: 70
Content-Type: application/sdp
Content-Length: 255
v=0
o=- 1226871209 1226871209 IN IP4 192.168.254.100
s=Polycom IP Phone
c=IN IP4 192.168.254.100
t=0 0
m=audio 2236 RTP/AVP 18 0 8 101
a=sendrecv
a=rtpmap:18 G729/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
<------------->
[Nov 16 14:51:30] VERBOSE[3200] logger.c: --- (14 headers 11 lines) ---
[Nov 16 14:51:30] VERBOSE[3200] logger.c: Sending to 192.168.254.100 : 5060 (no NAT)
[Nov 16 14:51:30] VERBOSE[3200] logger.c: Using INVITE request as basis request - 40137882-903b4155-5a49aaec@192.168.254.100
[Nov 16 14:51:30] VERBOSE[3200] logger.c:
<--- Reliably Transmitting (no NAT) to 192.168.254.100:5060 --->
SIP/2.0 407 Proxy Authentication Required
Via: SIP/2.0/UDP 192.168.254.100;branch=z9hG4bK9a87f7a8AC2A1403;received=192.168.254.100
From: "Chip (Flagstaff)" <sip:307@pbx.rplaw>;tag=3121FCF7-AAE15966
To: <sip:8913738@pbx.rplaw;user=phone>;tag=as44f1cbf5
Call-ID: 40137882-903b4155-5a49aaec@192.168.254.100
CSeq: 1 INVITE
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
Proxy-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="2373f9f2"
Content-Length: 0
<------------>
[Nov 16 14:51:30] VERBOSE[3200] logger.c: Scheduling destruction of SIP dialog '40137882-903b4155-5a49aaec@192.168.254.100' in 32000 ms (Method: INVITE)
[Nov 16 14:51:30] VERBOSE[3200] logger.c: Found user '307'
[Nov 16 14:51:30] VERBOSE[3200] logger.c:
<--- SIP read from 192.168.254.100:5060 --->
ACK sip:8913738@pbx.rplaw:5060 SIP/2.0
Via: SIP/2.0/UDP 192.168.254.100;branch=z9hG4bK9a87f7a8AC2A1403
From: "Chip (Flagstaff)" <sip:307@pbx.rplaw>;tag=3121FCF7-AAE15966
To: <sip:8913738@pbx.rplaw;user=phone>;tag=as44f1cbf5
CSeq: 1 ACK
Call-ID: 40137882-903b4155-5a49aaec@192.168.254.100
Contact: <sip:307@192.168.254.100>
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER
User-Agent: PolycomSoundPointIP-SPIP_330-UA/2.2.2.0084
Max-Forwards: 70
Content-Length: 0
<------------->
[Nov 16 14:51:30] VERBOSE[3200] logger.c: --- (11 headers 0 lines) ---
[Nov 16 14:51:30] VERBOSE[3200] logger.c:
<--- SIP read from 192.168.254.100:5060 --->
INVITE sip:8913738@pbx.rplaw:5060;user=phone SIP/2.0
Via: SIP/2.0/UDP 192.168.254.100;branch=z9hG4bK813f9f6990CBD270
From: "Chip (Flagstaff)" <sip:307@pbx.rplaw>;tag=3121FCF7-AAE15966
To: <sip:8913738@pbx.rplaw;user=phone>
CSeq: 2 INVITE
Call-ID: 40137882-903b4155-5a49aaec@192.168.254.100
Contact: <sip:307@192.168.254.100>
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER
User-Agent: PolycomSoundPointIP-SPIP_330-UA/2.2.2.0084
Supported: 100rel,replaces
Allow-Events: talk,hold,conference
Proxy-Authorization: Digest username="307", realm="asterisk", nonce="2373f9f2", uri="sip:8913738@pbx.rplaw:5060;user=phone", response="b5544359370b7f304967b7a896c091d6", algorithm=MD5
Max-Forwards: 70
Content-Type: application/sdp
Content-Length: 255
v=0
o=- 1226871209 1226871209 IN IP4 192.168.254.100
s=Polycom IP Phone
c=IN IP4 192.168.254.100
t=0 0
m=audio 2236 RTP/AVP 18 0 8 101
a=sendrecv
a=rtpmap:18 G729/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
<------------->
[Nov 16 14:51:30] VERBOSE[3200] logger.c: --- (15 headers 11 lines) ---
[Nov 16 14:51:30] VERBOSE[3200] logger.c: Sending to 192.168.254.100 : 5060 (no NAT)
[Nov 16 14:51:30] VERBOSE[3200] logger.c: Using INVITE request as basis request - 40137882-903b4155-5a49aaec@192.168.254.100
[Nov 16 14:51:30] VERBOSE[3200] logger.c: Found user '307'
[Nov 16 14:51:30] VERBOSE[3200] logger.c: Found RTP audio format 18
[Nov 16 14:51:30] VERBOSE[3200] logger.c: Found RTP audio format 0
[Nov 16 14:51:30] VERBOSE[3200] logger.c: Found RTP audio format 8
[Nov 16 14:51:30] VERBOSE[3200] logger.c: Found RTP audio format 101
[Nov 16 14:51:30] VERBOSE[3200] logger.c: Peer audio RTP is at port 192.168.254.100:2236
[Nov 16 14:51:30] VERBOSE[3200] logger.c: Found description format G729 for ID 18
[Nov 16 14:51:30] VERBOSE[3200] logger.c: Found description format PCMU for ID 0
[Nov 16 14:51:30] VERBOSE[3200] logger.c: Found description format PCMA for ID 8
[Nov 16 14:51:30] VERBOSE[3200] logger.c: Found description format telephone-event for ID 101
[Nov 16 14:51:30] VERBOSE[3200] logger.c: Capabilities: us - 0x100 (g729), peer - audio=0x10c (ulaw|alaw|g729)/video=0x0 (nothing), combined - 0x100 (g729)
[Nov 16 14:51:30] VERBOSE[3200] logger.c: Non-codec capabilities (dtmf): us - 0x1 (telephone-event), peer - 0x1 (telephone-event), combined - 0x1 (telephone-event)
[Nov 16 14:51:30] VERBOSE[3200] logger.c: Peer audio RTP is at port 192.168.254.100:2236
[Nov 16 14:51:30] DEBUG[3200] chan_sip.c: Call from peer '307' is 1 out of 50
[Nov 16 14:51:30] VERBOSE[3200] logger.c: Looking for 8913738 in from-internal (domain pbx.rplaw)
[Nov 16 14:51:30] VERBOSE[3200] logger.c: list_route: hop: <sip:307@192.168.254.100>
[Nov 16 14:51:30] VERBOSE[3200] logger.c:
<--- Transmitting (no NAT) to 192.168.254.100:5060 --->
SIP/2.0 100 Trying
Via: SIP/2.0/UDP 192.168.254.100;branch=z9hG4bK813f9f6990CBD270;received=192.168.254.100
From: "Chip (Flagstaff)" <sip:307@pbx.rplaw>;tag=3121FCF7-AAE15966
To: <sip:8913738@pbx.rplaw;user=phone>
Call-ID: 40137882-903b4155-5a49aaec@192.168.254.100
CSeq: 2 INVITE
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
Contact: <sip:8913738@192.168.255.2>
Content-Length: 0
<------------>
[Nov 16 14:51:30] VERBOSE[3134] logger.c: Extension Changed 307 new state InUse for Notify User 317
[Nov 16 14:51:30] VERBOSE[12687] logger.c: -- Executing [8913738@from-internal:1] Macro("SIP/307-b856ca90", "dialout-trunk|1|8913738||") in new stack
[Nov 16 14:51:30] VERBOSE[3134] logger.c: Extension Changed 307 new state InUse for Notify User 303
[Nov 16 14:51:30] VERBOSE[12687] logger.c: -- Executing [s@macro-dialout-trunk:1] Set("SIP/307-b856ca90", "DIAL_TRUNK=1") in new stack
[Nov 16 14:51:30] DEBUG[12687] app_macro.c: Executed application: Set
[Nov 16 14:51:30] VERBOSE[12687] logger.c: -- Executing [s@macro-dialout-trunk:2] Set("SIP/307-b856ca90", "DIAL_NUMBER=8913738") in new stack
[Nov 16 14:51:30] VERBOSE[3134] logger.c: Extension Changed 307 new state InUse for Notify User 316
[Nov 16 14:51:30] DEBUG[12687] app_macro.c: Executed application: Set
[Nov 16 14:51:30] VERBOSE[12687] logger.c: -- Executing [s@macro-dialout-trunk:3] Set("SIP/307-b856ca90", "ROUTE_PASSWD=") in new stack
[Nov 16 14:51:30] VERBOSE[3134] logger.c: Extension Changed 307 new state InUse for Notify User 301
[Nov 16 14:51:30] DEBUG[12687] app_macro.c: Executed application: Set
[Nov 16 14:51:30] VERBOSE[3134] logger.c: Extension Changed 307 new state InUse for Notify User 306
[Nov 16 14:51:30] VERBOSE[12687] logger.c: -- Executing [s@macro-dialout-trunk:4] GotoIf("SIP/307-b856ca90", "1?noauth") in new stack
[Nov 16 14:51:30] VERBOSE[12687] logger.c: -- Goto (macro-dialout-trunk,s,6)
[Nov 16 14:51:30] DEBUG[12687] app_macro.c: Executed application: GotoIf
[Nov 16 14:51:30] VERBOSE[3134] logger.c: Extension Changed 307 new state InUse for Notify User 308
[Nov 16 14:51:30] VERBOSE[12687] logger.c: -- Executing [s@macro-dialout-trunk:6] GotoIf("SIP/307-b856ca90", "0?disabletrunk|1") in new stack
[Nov 16 14:51:30] DEBUG[12687] app_macro.c: Executed application: GotoIf
[Nov 16 14:51:30] VERBOSE[12687] logger.c: -- Executing [s@macro-dialout-trunk:7] Set("SIP/307-b856ca90", "_NODEST=") in new stack
[Nov 16 14:51:30] VERBOSE[3134] logger.c: Extension Changed 307 new state InUse for Notify User 323
[Nov 16 14:51:30] DEBUG[12687] app_macro.c: Executed application: Set
[Nov 16 14:51:30] VERBOSE[12687] logger.c: -- Executing [s@macro-dialout-trunk:8] Set("SIP/307-b856ca90", "DIAL_TRUNK_OPTIONS=trw") in new stack
[Nov 16 14:51:30] DEBUG[12687] app_macro.c: Executed application: Set
[Nov 16 14:51:30] VERBOSE[12687] logger.c: -- Executing [s@macro-dialout-trunk:9] Set("SIP/307-b856ca90", "GROUP()=OUT_1") in new stack
[Nov 16 14:51:30] DEBUG[12687] app_macro.c: Executed application: Set
[Nov 16 14:51:30] VERBOSE[12687] logger.c: -- Executing [s@macro-dialout-trunk:10] Macro("SIP/307-b856ca90", "user-callerid|SKIPTTL") in new stack
[Nov 16 14:51:30] VERBOSE[12687] logger.c: -- Executing [s@macro-user-callerid:1] NoOp("SIP/307-b856ca90", "user-callerid: device 307") in new stack
[Nov 16 14:51:30] DEBUG[12687] app_macro.c: Executed application: Noop
[Nov 16 14:51:30] VERBOSE[12687] logger.c: -- Executing [s@macro-user-callerid:2] Set("SIP/307-b856ca90", "AMPUSER=307") in new stack
[Nov 16 14:51:30] DEBUG[12687] app_macro.c: Executed application: Set
[Nov 16 14:51:30] VERBOSE[12687] logger.c: -- Executing [s@macro-user-callerid:3] GotoIf("SIP/307-b856ca90", "0?report") in new stack
[Nov 16 14:51:30] DEBUG[12687] app_macro.c: Executed application: GotoIf
[Nov 16 14:51:30] VERBOSE[12687] logger.c: -- Executing [s@macro-user-callerid:4] GotoIf("SIP/307-b856ca90", "0?start") in new stack
[Nov 16 14:51:30] DEBUG[12687] app_macro.c: Executed application: GotoIf
[Nov 16 14:51:30] VERBOSE[12687] logger.c: -- Executing [s@macro-user-callerid:5] Set("SIP/307-b856ca90", "REALCALLERIDNUM=307") in new stack
[Nov 16 14:51:30] DEBUG[12687] app_macro.c: Executed application: Set
[Nov 16 14:51:30] VERBOSE[12687] logger.c: -- Executing [s@macro-user-callerid:6] NoOp("SIP/307-b856ca90", "REALCALLERIDNUM is 307") in new stack
[Nov 16 14:51:30] DEBUG[12687] app_macro.c: Executed application: NoOp
[Nov 16 14:51:30] VERBOSE[12687] logger.c: -- Executing [s@macro-user-callerid:7] Set("SIP/307-b856ca90", "AMPUSER=307") in new stack
[Nov 16 14:51:30] DEBUG[12687] app_macro.c: Executed application: Set
[Nov 16 14:51:30] VERBOSE[12687] logger.c: -- Executing [s@macro-user-callerid:8] Set("SIP/307-b856ca90", "AMPUSERCIDNAME=Chip (Flagstaff)") in new stack
[Nov 16 14:51:30] DEBUG[12687] app_macro.c: Executed application: Set
[Nov 16 14:51:30] VERBOSE[12687] logger.c: -- Executing [s@macro-user-callerid:9] GotoIf("SIP/307-b856ca90", "0?report") in new stack
[Nov 16 14:51:30] DEBUG[12687] app_macro.c: Executed application: GotoIf
[Nov 16 14:51:30] VERBOSE[12687] logger.c: -- Executing [s@macro-user-callerid:10] Set("SIP/307-b856ca90", "AMPUSERCID=307") in new stack
[Nov 16 14:51:30] DEBUG[12687] app_macro.c: Executed application: Set
[Nov 16 14:51:30] VERBOSE[12687] logger.c: -- Executing [s@macro-user-callerid:11] Set("SIP/307-b856ca90", "CALLERID(all)="Chip (Flagstaff)" <307>") in new stack
[Nov 16 14:51:30] DEBUG[12687] app_macro.c: Executed application: Set
[Nov 16 14:51:30] VERBOSE[12687] logger.c: -- Executing [s@macro-user-callerid:12] Set("SIP/307-b856ca90", "REALCALLERIDNUM=307") in new stack
[Nov 16 14:51:30] DEBUG[12687] app_macro.c: Executed application: Set
[Nov 16 14:51:30] VERBOSE[12687] logger.c: -- Executing [s@macro-user-callerid:13] NoOp("SIP/307-b856ca90", "TTL: ARG1: SKIPTTL") in new stack
[Nov 16 14:51:30] DEBUG[12687] app_macro.c: Executed application: Noop
[Nov 16 14:51:30] VERBOSE[12687] logger.c: -- Executing [s@macro-user-callerid:14] GotoIf("SIP/307-b856ca90", "1?continue") in new stack
[Nov 16 14:51:30] VERBOSE[12687] logger.c: -- Goto (macro-user-callerid,s,23)
[Nov 16 14:51:30] DEBUG[12687] app_macro.c: Executed application: GotoIf
[Nov 16 14:51:30] VERBOSE[12687] logger.c: -- Executing [s@macro-user-callerid:23] NoOp("SIP/307-b856ca90", "Using CallerID "Chip (Flagstaff)" <307>") in new stack
[Nov 16 14:51:30] DEBUG[12687] app_macro.c: Executed application: NoOp
[Nov 16 14:51:30] DEBUG[12687] app_macro.c: Executed application: Macro
[Nov 16 14:51:30] VERBOSE[12687] logger.c: -- Executing [s@macro-dialout-trunk:11] Macro("SIP/307-b856ca90", "record-enable|307|OUT") in new stack
[Nov 16 14:51:30] VERBOSE[12687] logger.c: -- Executing [s@macro-record-enable:1] GotoIf("SIP/307-b856ca90", "0?2:4") in new stack
[Nov 16 14:51:30] VERBOSE[12687] logger.c: -- Goto (macro-record-enable,s,4)
[Nov 16 14:51:30] DEBUG[12687] app_macro.c: Executed application: GotoIf
[Nov 16 14:51:30] VERBOSE[12687] logger.c: -- Executing [s@macro-record-enable:4] AGI("SIP/307-b856ca90", "recordingcheck|20081116-145130|1226872290.542") in new stack
[Nov 16 14:51:30] VERBOSE[12687] logger.c: -- Launched AGI Script /usr/share/asterisk/agi-bin/recordingcheck
[Nov 16 14:51:31] VERBOSE[12687] logger.c: recordingcheck|20081116-145130|1226872290.542: Outbound recording not enabled
[Nov 16 14:51:31] VERBOSE[12687] logger.c: -- AGI Script recordingcheck completed, returning 0
[Nov 16 14:51:31] DEBUG[12687] app_macro.c: Executed application: AGI
[Nov 16 14:51:31] VERBOSE[12687] logger.c: -- Executing [s@macro-record-enable:5] NoOp("SIP/307-b856ca90", "No recording needed") in new stack
[Nov 16 14:51:31] DEBUG[12687] app_macro.c: Executed application: Noop
[Nov 16 14:51:31] DEBUG[12687] app_macro.c: Executed application: Macro
[Nov 16 14:51:31] VERBOSE[12687] logger.c: -- Executing [s@macro-dialout-trunk:12] GotoIf("SIP/307-b856ca90", "0?skipoutcid") in new stack
[Nov 16 14:51:31] DEBUG[12687] app_macro.c: Executed application: GotoIf
[Nov 16 14:51:31] VERBOSE[12687] logger.c: -- Executing [s@macro-dialout-trunk:13] Set("SIP/307-b856ca90", "DIAL_TRUNK_OPTIONS=W") in new stack
[Nov 16 14:51:31] DEBUG[12687] app_macro.c: Executed application: Set
[Nov 16 14:51:31] VERBOSE[12687] logger.c: -- Executing [s@macro-dialout-trunk:14] Macro("SIP/307-b856ca90", "outbound-callerid|1") in new stack
[Nov 16 14:51:31] VERBOSE[12687] logger.c: -- Executing [s@macro-outbound-callerid:1] GotoIf("SIP/307-b856ca90", "1?start") in new stack
[Nov 16 14:51:31] VERBOSE[12687] logger.c: -- Goto (macro-outbound-callerid,s,3)
[Nov 16 14:51:31] DEBUG[12687] app_macro.c: Executed application: GotoIf
[Nov 16 14:51:31] VERBOSE[12687] logger.c: -- Executing [s@macro-outbound-callerid:3] NoOp("SIP/307-b856ca90", "REALCALLERIDNUM is 307") in new stack
[Nov 16 14:51:31] DEBUG[12687] app_macro.c: Executed application: NoOp
[Nov 16 14:51:31] VERBOSE[12687] logger.c: -- Executing [s@macro-outbound-callerid:4] GotoIf("SIP/307-b856ca90", "1?normcid") in new stack
[Nov 16 14:51:31] VERBOSE[12687] logger.c: -- Goto (macro-outbound-callerid,s,9)
[Nov 16 14:51:31] DEBUG[12687] app_macro.c: Executed application: GotoIf
[Nov 16 14:51:31] VERBOSE[12687] logger.c: -- Executing [s@macro-outbound-callerid:9] Set("SIP/307-b856ca90", "USEROUTCID=") in new stack
[Nov 16 14:51:31] DEBUG[12687] app_macro.c: Executed application: Set
[Nov 16 14:51:31] DEBUG[12687] db.c: Unable to find key '307/emergency_cid' in family 'DEVICE'
[Nov 16 14:51:31] DEBUG[12687] func_db.c: DB: DEVICE/307/emergency_cid not found in database.
[Nov 16 14:51:31] VERBOSE[12687] logger.c: -- Executing [s@macro-outbound-callerid:10] Set("SIP/307-b856ca90", "EMERGENCYCID=") in new stack
[Nov 16 14:51:31] DEBUG[12687] app_macro.c: Executed application: Set
[Nov 16 14:51:31] VERBOSE[12687] logger.c: -- Executing [s@macro-outbound-callerid:11] Set("SIP/307-b856ca90", "TRUNKOUTCID=<5208886740>") in new stack
[Nov 16 14:51:31] DEBUG[12687] app_macro.c: Executed application: Set
[Nov 16 14:51:31] VERBOSE[12687] logger.c: -- Executing [s@macro-outbound-callerid:12] GotoIf("SIP/307-b856ca90", "1?trunkcid") in new stack
[Nov 16 14:51:31] VERBOSE[12687] logger.c: -- Goto (macro-outbound-callerid,s,16)
[Nov 16 14:51:31] DEBUG[12687] app_macro.c: Executed application: GotoIf
[Nov 16 14:51:31] VERBOSE[12687] logger.c: -- Executing [s@macro-outbound-callerid:16] GotoIf("SIP/307-b856ca90", "0?usercid") in new stack
[Nov 16 14:51:31] DEBUG[12687] app_macro.c: Executed application: GotoIf
[Nov 16 14:51:31] VERBOSE[12687] logger.c: -- Executing [s@macro-outbound-callerid:17] Set("SIP/307-b856ca90", "CALLERID(all)=<5208886740>") in new stack
[Nov 16 14:51:31] DEBUG[12687] app_macro.c: Executed application: Set
[Nov 16 14:51:31] VERBOSE[12687] logger.c: -- Executing [s@macro-outbound-callerid:18] GotoIf("SIP/307-b856ca90", "1?report") in new stack
[Nov 16 14:51:31] VERBOSE[12687] logger.c: -- Goto (macro-outbound-callerid,s,22)
[Nov 16 14:51:31] DEBUG[12687] app_macro.c: Executed application: GotoIf
[Nov 16 14:51:31] VERBOSE[12687] logger.c: -- Executing [s@macro-outbound-callerid:22] NoOp("SIP/307-b856ca90", "CallerID set to "" <5208886740>") in new stack
[Nov 16 14:51:31] DEBUG[12687] app_macro.c: Executed application: NoOp
[Nov 16 14:51:31] DEBUG[12687] app_macro.c: Executed application: Macro
[Nov 16 14:51:31] VERBOSE[12687] logger.c: -- Executing [s@macro-dialout-trunk:15] GotoIf("SIP/307-b856ca90", "0?nomax") in new stack
[Nov 16 14:51:31] DEBUG[12687] app_macro.c: Executed application: GotoIf
[Nov 16 14:51:31] VERBOSE[12687] logger.c: -- Executing [s@macro-dialout-trunk:16] GotoIf("SIP/307-b856ca90", "0?chanfull") in new stack
[Nov 16 14:51:31] DEBUG[12687] app_macro.c: Executed application: GotoIf
[Nov 16 14:51:31] VERBOSE[12687] logger.c: -- Executing [s@macro-dialout-trunk:17] AGI("SIP/307-b856ca90", "fixlocalprefix") in new stack
[Nov 16 14:51:31] VERBOSE[12687] logger.c: -- Launched AGI Script /usr/share/asterisk/agi-bin/fixlocalprefix
[Nov 16 14:51:31] VERBOSE[12687] logger.c: > fixlocalprefix: Using pattern 520+NXXXXXX
[Nov 16 14:51:31] VERBOSE[12687] logger.c: == fixlocalprefix: Dialpattern 520+NXXXXXX matched. 8913738 -> 5208913738
[Nov 16 14:51:31] VERBOSE[12687] logger.c: -- AGI Script fixlocalprefix completed, returning 0
[Nov 16 14:51:31] DEBUG[12687] app_macro.c: Executed application: AGI
[Nov 16 14:51:31] VERBOSE[12687] logger.c: -- Executing [s@macro-dialout-trunk:18] Set("SIP/307-b856ca90", "OUTNUM=5208913738") in new stack
[Nov 16 14:51:31] DEBUG[12687] app_macro.c: Executed application: Set
[Nov 16 14:51:31] VERBOSE[12687] logger.c: -- Executing [s@macro-dialout-trunk:19] Set("SIP/307-b856ca90", "custom=ZAP/g0") in new stack
[Nov 16 14:51:31] DEBUG[12687] app_macro.c: Executed application: Set
[Nov 16 14:51:31] VERBOSE[12687] logger.c: -- Executing [s@macro-dialout-trunk:20] GotoIf("SIP/307-b856ca90", "1?gocall") in new stack
[Nov 16 14:51:31] VERBOSE[12687] logger.c: -- Goto (macro-dialout-trunk,s,22)
[Nov 16 14:51:31] DEBUG[12687] app_macro.c: Executed application: GotoIf
[Nov 16 14:51:31] VERBOSE[12687] logger.c: -- Executing [s@macro-dialout-trunk:22] Macro("SIP/307-b856ca90", "dialout-trunk-predial-hook") in new stack
[Nov 16 14:51:31] WARNING[12687] app_macro.c: Context 'macro-dialout-trunk-predial-hook' for macro 'dialout-trunk-predial-hook' lacks 's' extension, priority 1
[Nov 16 14:51:31] DEBUG[12687] app_macro.c: Executed application: Macro
[Nov 16 14:51:31] VERBOSE[12687] logger.c: -- Executing [s@macro-dialout-trunk:23] GotoIf("SIP/307-b856ca90", "0?bypass|1") in new stack
[Nov 16 14:51:31] DEBUG[12687] app_macro.c: Executed application: GotoIf
[Nov 16 14:51:31] VERBOSE[12687] logger.c: -- Executing [s@macro-dialout-trunk:24] GotoIf("SIP/307-b856ca90", "0?customtrunk") in new stack
[Nov 16 14:51:31] DEBUG[12687] app_macro.c: Executed application: GotoIf
[Nov 16 14:51:31] VERBOSE[12687] logger.c: -- Executing [s@macro-dialout-trunk:25] Dial("SIP/307-b856ca90", "ZAP/g0/5208913738|300|W") in new stack
[Nov 16 14:51:31] VERBOSE[12687] logger.c: -- Requested transfer capability: 0x00 - SPEECH
[Nov 16 14:51:31] VERBOSE[12687] logger.c: -- Called g0/5208913738
[Nov 16 14:51:31] VERBOSE[12687] logger.c: Audio is at 192.168.255.2 port 18226
[Nov 16 14:51:31] VERBOSE[12687] logger.c: Adding codec 0x100 (g729) to SDP
[Nov 16 14:51:31] VERBOSE[12687] logger.c: Adding non-codec 0x1 (telephone-event) to SDP
[Nov 16 14:51:31] VERBOSE[12687] logger.c:
<--- Transmitting (no NAT) to 192.168.254.100:5060 --->
SIP/2.0 183 Session Progress
Via: SIP/2.0/UDP 192.168.254.100;branch=z9hG4bK813f9f6990CBD270;received=192.168.254.100
From: "Chip (Flagstaff)" <sip:307@pbx.rplaw>;tag=3121FCF7-AAE15966
To: <sip:8913738@pbx.rplaw;user=phone>;tag=as74cc641c
Call-ID: 40137882-903b4155-5a49aaec@192.168.254.100
CSeq: 2 INVITE
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
Contact: <sip:8913738@192.168.255.2>
Content-Type: application/sdp
Content-Length: 263
v=0
o=root 3126 3126 IN IP4 192.168.255.2
s=session
c=IN IP4 192.168.255.2
t=0 0
m=audio 18226 RTP/AVP 18 101
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=silenceSupp:off - - - -
a=ptime:20
a=sendrecv
<------------>
[Nov 16 14:51:31] DEBUG[3183] chan_zap.c: Queuing frame from PRI_EVENT_PROCEEDING on channel 0/1 span 1
[Nov 16 14:51:31] VERBOSE[12687] logger.c: -- Zap/1-1 is proceeding passing it to SIP/307-b856ca90
[Nov 16 14:51:33] DEBUG[3183] chan_zap.c: Enabled echo cancellation on channel 1
[Nov 16 14:51:33] VERBOSE[12687] logger.c: -- Zap/1-1 is ringing
[Nov 16 14:51:33] VERBOSE[12687] logger.c:
<--- Transmitting (no NAT) to 192.168.254.100:5060 --->
SIP/2.0 180 Ringing
Via: SIP/2.0/UDP 192.168.254.100;branch=z9hG4bK813f9f6990CBD270;received=192.168.254.100
From: "Chip (Flagstaff)" <sip:307@pbx.rplaw>;tag=3121FCF7-AAE15966
To: <sip:8913738@pbx.rplaw;user=phone>;tag=as74cc641c
Call-ID: 40137882-903b4155-5a49aaec@192.168.254.100
CSeq: 2 INVITE
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
Contact: <sip:8913738@192.168.255.2>
Content-Length: 0
<------------>
[Nov 16 14:51:38] DEBUG[3183] chan_zap.c: Echo cancellation already on
[Nov 16 14:51:38] VERBOSE[12687] logger.c: -- Zap/1-1 answered SIP/307-b856ca90
[Nov 16 14:51:38] WARNING[12687] channel.c: No path to translate from SIP/307-b856ca90(256) to Zap/1-1(68)
[Nov 16 14:51:38] WARNING[12687] app_dial.c: Had to drop call because I couldn't make SIP/307-b856ca90 compatible with Zap/1-1
[Nov 16 14:51:38] DEBUG[12687] chan_zap.c: Set option AUDIO MODE, value: ON(1) on Zap/1-1
[Nov 16 14:51:38] DEBUG[12687] chan_zap.c: Not yet hungup... Calling hangup once with icause, and clearing call
[Nov 16 14:51:38] DEBUG[12687] chan_zap.c: disabled echo cancellation on channel 1
[Nov 16 14:51:38] DEBUG[12687] chan_zap.c: Set option AUDIO MODE, value: OFF(0) on Zap/1-1
[Nov 16 14:51:38] DEBUG[12687] chan_zap.c: disabled echo cancellation on channel 1
[Nov 16 14:51:38] VERBOSE[12687] logger.c: -- Hungup 'Zap/1-1'
[Nov 16 14:51:38] VERBOSE[12687] logger.c: == Spawn extension (macro-dialout-trunk, s, 25) exited non-zero on 'SIP/307-b856ca90' in macro 'dialout-trunk'
[Nov 16 14:51:38] VERBOSE[12687] logger.c: == Spawn extension (macro-dialout-trunk, s, 25) exited non-zero on 'SIP/307-b856ca90'
[Nov 16 14:51:38] VERBOSE[12687] logger.c: -- Executing [h@macro-dialout-trunk:1] Macro("SIP/307-b856ca90", "hangupcall") in new stack
[Nov 16 14:51:38] VERBOSE[12687] logger.c: -- Executing [s@macro-hangupcall:1] ResetCDR("SIP/307-b856ca90", "w") in new stack
[Nov 16 14:51:38] DEBUG[12687] app_macro.c: Executed application: ResetCDR
[Nov 16 14:51:38] VERBOSE[12687] logger.c: -- Executing [s@macro-hangupcall:2] NoCDR("SIP/307-b856ca90", "") in new stack
[Nov 16 14:51:38] DEBUG[12687] app_macro.c: Executed application: NoCDR
[Nov 16 14:51:38] VERBOSE[12687] logger.c: -- Executing [s@macro-hangupcall:3] GotoIf("SIP/307-b856ca90", "1?skiprg") in new stack
[Nov 16 14:51:38] VERBOSE[12687] logger.c: -- Goto (macro-hangupcall,s,6)
[Nov 16 14:51:38] DEBUG[12687] app_macro.c: Executed application: GotoIf
[Nov 16 14:51:38] VERBOSE[12687] logger.c: -- Executing [s@macro-hangupcall:6] GotoIf("SIP/307-b856ca90", "1?skipblkvm") in new stack
[Nov 16 14:51:38] VERBOSE[12687] logger.c: -- Goto (macro-hangupcall,s,9)
[Nov 16 14:51:38] DEBUG[12687] app_macro.c: Executed application: GotoIf
[Nov 16 14:51:38] VERBOSE[12687] logger.c: -- Executing [s@macro-hangupcall:9] GotoIf("SIP/307-b856ca90", "1?theend") in new stack
[Nov 16 14:51:38] VERBOSE[12687] logger.c: -- Goto (macro-hangupcall,s,11)
[Nov 16 14:51:38] DEBUG[12687] app_macro.c: Executed application: GotoIf
[Nov 16 14:51:38] VERBOSE[12687] logger.c: -- Executing [s@macro-hangupcall:11] Hangup("SIP/307-b856ca90", "") in new stack
[Nov 16 14:51:38] VERBOSE[12687] logger.c: == Spawn extension (macro-hangupcall, s, 11) exited non-zero on 'SIP/307-b856ca90' in macro 'hangupcall'
[Nov 16 14:51:38] VERBOSE[12687] logger.c: == Spawn extension (macro-hangupcall, s, 11) exited non-zero on 'SIP/307-b856ca90'
[Nov 16 14:51:38] DEBUG[12687] chan_sip.c: Call from peer '307' removed from call limit 50
[Nov 16 14:51:38] VERBOSE[12687] logger.c: Scheduling destruction of SIP dialog '40137882-903b4155-5a49aaec@192.168.254.100' in 32000 ms (Method: INVITE)
[Nov 16 14:51:38] VERBOSE[12687] logger.c:
<--- Reliably Transmitting (no NAT) to 192.168.254.100:5060 --->
SIP/2.0 603 Declined
Via: SIP/2.0/UDP 192.168.254.100;branch=z9hG4bK813f9f6990CBD270;received=192.168.254.100
From: "Chip (Flagstaff)" <sip:307@pbx.rplaw>;tag=3121FCF7-AAE15966
To: <sip:8913738@pbx.rplaw;user=phone>;tag=as74cc641c
Call-ID: 40137882-903b4155-5a49aaec@192.168.254.100
CSeq: 2 INVITE
User-Agent: Asterisk PBX
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
Contact: <sip:8913738@192.168.255.2>
Content-Length: 0
<------------>
[Nov 16 14:51:38] VERBOSE[3134] logger.c: Extension Changed 307 new state Idle for Notify User 317
[Nov 16 14:51:38] VERBOSE[3134] logger.c: Extension Changed 307 new state Idle for Notify User 303
[Nov 16 14:51:38] VERBOSE[3134] logger.c: Extension Changed 307 new state Idle for Notify User 316
[Nov 16 14:51:38] VERBOSE[3134] logger.c: Extension Changed 307 new state Idle for Notify User 301
[Nov 16 14:51:38] VERBOSE[3134] logger.c: Extension Changed 307 new state Idle for Notify User 306
[Nov 16 14:51:38] VERBOSE[3134] logger.c: Extension Changed 307 new state Idle for Notify User 308
[Nov 16 14:51:38] VERBOSE[3134] logger.c: Extension Changed 307 new state Idle for Notify User 323
[Nov 16 14:51:38] VERBOSE[3200] logger.c:
<--- SIP read from 192.168.254.100:5060 --->
ACK sip:8913738@192.168.255.2 SIP/2.0
Via: SIP/2.0/UDP 192.168.254.100;branch=z9hG4bK813f9f6990CBD270
From: "Chip (Flagstaff)" <sip:307@pbx.rplaw>;tag=3121FCF7-AAE15966
To: <sip:8913738@pbx.rplaw;user=phone>;tag=as74cc641c
CSeq: 2 ACK
Call-ID: 40137882-903b4155-5a49aaec@192.168.254.100
Contact: <sip:307@192.168.254.100>
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER
User-Agent: PolycomSoundPointIP-SPIP_330-UA/2.2.2.0084
Proxy-Authorization: Digest username="307", realm="asterisk", nonce="2373f9f2", uri="sip:8913738@pbx.rplaw:5060;user=phone", response="b5544359370b7f304967b7a896c091d6", algorithm=MD5
Max-Forwards: 70
Content-Length: 0
<------------->
[Nov 16 14:51:38] VERBOSE[3200] logger.c: --- (12 headers 0 lines) ---
[Nov 16 14:51:48] VERBOSE[3200] logger.c: Reliably Transmitting (no NAT) to 192.168.254.100:5060:
OPTIONS sip:307@192.168.254.100 SIP/2.0
Via: SIP/2.0/UDP 192.168.255.2:5060;branch=z9hG4bK65f3a86f;rport
From: "Unknown" <sip:Unknown@192.168.255.2>;tag=as783c72ba
To: <sip:307@192.168.254.100>
Contact: <sip:Unknown@192.168.255.2>
Call-ID: 1bb5e242062188de7835c2b1542877ad@192.168.255.2
CSeq: 102 OPTIONS
User-Agent: Asterisk PBX
Max-Forwards: 70
Date: Sun, 16 Nov 2008 21:51:48 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY
Supported: replaces
Content-Length: 0
---
[Nov 16 14:51:48] VERBOSE[3200] logger.c:
<--- SIP read from 192.168.254.100:5060 --->
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.255.2:5060;branch=z9hG4bK65f3a86f;rport
From: "Unknown" <sip:Unknown@192.168.255.2>;tag=as783c72ba
To: <sip:307@192.168.254.100>;tag=DED2D351-1672CE38
CSeq: 102 OPTIONS
Call-ID: 1bb5e242062188de7835c2b1542877ad@192.168.255.2
Contact: <sip:307@192.168.254.100>
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, INFO, MESSAGE, SUBSCRIBE, NOTIFY, PRACK, UPDATE, REFER
User-Agent: PolycomSoundPointIP-SPIP_330-UA/2.2.2.0084
Content-Length: 0
<------------->
[Nov 16 14:51:48] VERBOSE[3200] logger.c: --- (10 headers 0 lines) ---
[Nov 16 14:51:48] VERBOSE[3200] logger.c: Really destroying SIP dialog '1bb5e242062188de7835c2b1542877ad@192.168.255.2' Method: OPTIONS