New to Asterisk and FreePbx, but making progress. FreePBX 2.11.0.0beta2.6 and Asterisk 11.1.2 on Raspberry Pi (RaspPbx distribution).
I’ve got a fairly basic test setup working using a mix of softphones, Yealink and Grandstream hard phones, and an SPA3102, which so far works as expected (albeit with some dialling delays which I imagine are down to dialplans not being set up properly). Its all on a single local network segment.
But I’m having a problem with this door entry phone http://www.alphatech.cz/english/slim-ipdp.html (which seems to be ‘badged’ by a number of manufacturers - mine are ‘Protalk’).
Its apparently all set up OK, and registers to FreePbx. Pretty much default settings on FreePbx - started with the same settings as for the hardphone extensions.
I can dial the entry phone from another extension, and works OK - entry phone picks up, two-way audio, can control door release relays, hangs up OK.
The problem is when a button is pushed on the entry phone - configured extension rings OK. Pick up call, and there is no audio in either direction. Hang up is OK.
I’ve taken a SIP trace of traffic to the entry phone (below), but not expert enough to identify the problem. (I noticed the sending of the SnomIPPhoneImageFile information, which was rejected, and managed to disable this in the entry phone - no difference).
Can anyone shed any light on this?
=============================================================================================
[2013-03-29 22:04:45] VERBOSE[30354][C-0000006d] pbx.c: – Executing [dstring@macro-dial-one:8] GosubIf(“SIP/719-000000c1”, “1?zap2dahdi,1()”) in new stack
[2013-03-29 22:04:45] VERBOSE[30354][C-0000006d] pbx.c: – Executing [zap2dahdi@macro-dial-one:1] ExecIf(“SIP/719-000000c1”, “0?Return()”) in new stack
[2013-03-29 22:04:45] VERBOSE[30354][C-0000006d] pbx.c: – Executing [zap2dahdi@macro-dial-one:2] Set(“SIP/719-000000c1”, “NEWDIAL=”) in new stack
[2013-03-29 22:04:45] VERBOSE[30354][C-0000006d] pbx.c: – Executing [zap2dahdi@macro-dial-one:3] Set(“SIP/719-000000c1”, “LOOPCNT2=1”) in new stack
[2013-03-29 22:04:45] VERBOSE[30354][C-0000006d] pbx.c: – Executing [zap2dahdi@macro-dial-one:4] Set(“SIP/719-000000c1”, “ITER2=1”) in new stack
[2013-03-29 22:04:45] VERBOSE[30354][C-0000006d] pbx.c: – Executing [zap2dahdi@macro-dial-one:5] Set(“SIP/719-000000c1”, “THISPART2=SIP/704”) in new stack
[2013-03-29 22:04:45] VERBOSE[30354][C-0000006d] pbx.c: – Executing [zap2dahdi@macro-dial-one:6] ExecIf(“SIP/719-000000c1”, “0?Set(THISPART2=DAHDI/704)”) in new stack
[2013-03-29 22:04:45] VERBOSE[30354][C-0000006d] pbx.c: – Executing [zap2dahdi@macro-dial-one:7] Set(“SIP/719-000000c1”, “NEWDIAL=SIP/704&”) in new stack
[2013-03-29 22:04:45] VERBOSE[30354][C-0000006d] pbx.c: – Executing [zap2dahdi@macro-dial-one:8] Set(“SIP/719-000000c1”, “ITER2=2”) in new stack
[2013-03-29 22:04:45] VERBOSE[30354][C-0000006d] pbx.c: – Executing [zap2dahdi@macro-dial-one:9] GotoIf(“SIP/719-000000c1”, “0?begin2”) in new stack
[2013-03-29 22:04:45] VERBOSE[30354][C-0000006d] pbx.c: – Executing [zap2dahdi@macro-dial-one:10] Set(“SIP/719-000000c1”, “THISDIAL=SIP/704”) in new stack
[2013-03-29 22:04:45] VERBOSE[30354][C-0000006d] pbx.c: – Executing [zap2dahdi@macro-dial-one:11] Return(“SIP/719-000000c1”, “”) in new stack
[2013-03-29 22:04:45] VERBOSE[30354][C-0000006d] pbx.c: – Executing [dstring@macro-dial-one:9] Set(“SIP/719-000000c1”, “DSTRING=SIP/704&”) in new stack
[2013-03-29 22:04:45] VERBOSE[30354][C-0000006d] pbx.c: – Executing [dstring@macro-dial-one:10] Set(“SIP/719-000000c1”, “ITER=2”) in new stack
[2013-03-29 22:04:45] VERBOSE[30354][C-0000006d] pbx.c: – Executing [dstring@macro-dial-one:11] GotoIf(“SIP/719-000000c1”, “0?begin”) in new stack
[2013-03-29 22:04:45] VERBOSE[30354][C-0000006d] pbx.c: – Executing [dstring@macro-dial-one:12] Set(“SIP/719-000000c1”, “DSTRING=SIP/704”) in new stack
[2013-03-29 22:04:45] VERBOSE[30354][C-0000006d] pbx.c: – Executing [dstring@macro-dial-one:13] Return(“SIP/719-000000c1”, “”) in new stack
[2013-03-29 22:04:45] VERBOSE[30354][C-0000006d] pbx.c: – Executing [s@macro-dial-one:27] GotoIf(“SIP/719-000000c1”, “0?nodial”) in new stack
[2013-03-29 22:04:45] VERBOSE[30354][C-0000006d] pbx.c: – Executing [s@macro-dial-one:28] GotoIf(“SIP/719-000000c1”, “0?skiptrace”) in new stack
[2013-03-29 22:04:45] VERBOSE[30354][C-0000006d] pbx.c: – Executing [s@macro-dial-one:29] GosubIf(“SIP/719-000000c1”, “1?ctset,1():ctclear,1()”) in new stack
[2013-03-29 22:04:45] VERBOSE[30354][C-0000006d] pbx.c: – Executing [ctset@macro-dial-one:1] Set(“SIP/719-000000c1”, “DB(CALLTRACE/704)=719”) in new stack
[2013-03-29 22:04:45] VERBOSE[30354][C-0000006d] pbx.c: – Executing [ctset@macro-dial-one:2] Return(“SIP/719-000000c1”, “”) in new stack
[2013-03-29 22:04:45] VERBOSE[30354][C-0000006d] pbx.c: – Executing [s@macro-dial-one:30] Set(“SIP/719-000000c1”, “D_OPTIONS=tr”) in new stack
[2013-03-29 22:04:45] VERBOSE[30354][C-0000006d] pbx.c: – Executing [s@macro-dial-one:31] ExecIf(“SIP/719-000000c1”, “0?SIPAddHeader(Alert-Info: )”) in new stack
[2013-03-29 22:04:45] VERBOSE[30354][C-0000006d] pbx.c: – Executing [s@macro-dial-one:32] ExecIf(“SIP/719-000000c1”, “0?SIPAddHeader()”) in new stack
[2013-03-29 22:04:45] VERBOSE[30354][C-0000006d] pbx.c: – Executing [s@macro-dial-one:33] ExecIf(“SIP/719-000000c1”, “0?Set(CHANNEL(musicclass)=)”) in new stack
[2013-03-29 22:04:45] VERBOSE[30354][C-0000006d] pbx.c: – Executing [s@macro-dial-one:34] GosubIf(“SIP/719-000000c1”, “0?qwait,1()”) in new stack
[2013-03-29 22:04:45] VERBOSE[30354][C-0000006d] pbx.c: – Executing [s@macro-dial-one:35] Set(“SIP/719-000000c1”, “__CWIGNORE=”) in new stack
[2013-03-29 22:04:45] VERBOSE[30354][C-0000006d] pbx.c: – Executing [s@macro-dial-one:36] Set(“SIP/719-000000c1”, “__KEEPCID=TRUE”) in new stack
[2013-03-29 22:04:45] VERBOSE[30354][C-0000006d] pbx.c: – Executing [s@macro-dial-one:37] GotoIf(“SIP/719-000000c1”, “0?usegoto,1”) in new stack
[2013-03-29 22:04:45] VERBOSE[2771] chan_sip.c:
<— SIP read from UDP:[EntryPhone]:5060 —>
REGISTER sip:[FreePbx] SIP/2.0
Via: SIP/2.0/UDP [EntryPhone]:5060;rport;branch=z9hG4bK106323313
From: “Prod Door” sip:719@FreePbx;tag=1874547334
To: “Prod Door” sip:719@FreePbx
Call-ID: 61629487
CSeq: 23 REGISTER
Contact: sip:719@EntryPhone:5060;line=6e3db27916951df
Authorization: Digest username=“719”, realm=“asterisk”, nonce=“0a8440ac”, uri=“sip:[FreePbx]”, response=“85d4207857847dde6d4bd48c10a95f2e”, algorithm=MD5
Max-Forwards: 70
User-Agent: VoIP Guard
Expires: 600
Content-Length: 0
<------------->
[2013-03-29 22:04:45] VERBOSE[2771] chan_sip.c: — (12 headers 0 lines) —
[2013-03-29 22:04:45] VERBOSE[2771] chan_sip.c: Sending to [EntryPhone]:5060 (no NAT)
[2013-03-29 22:04:45] VERBOSE[2771] chan_sip.c:
<— Transmitting (no NAT) to [EntryPhone]:5060 —>
SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP [EntryPhone]:5060;branch=z9hG4bK106323313;received=[EntryPhone];rport=5060
From: “Prod Door” sip:719@FreePbx;tag=1874547334
To: “Prod Door” sip:719@FreePbx;tag=as2f0f5156
Call-ID: 61629487
CSeq: 23 REGISTER
Server: FPBX2.11.0beta3(11.1.2)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
WWW-Authenticate: Digest algorithm=MD5, realm=“asterisk”, nonce="67be26bf"
Content-Length: 0
<------------>
[2013-03-29 22:04:45] VERBOSE[2771] chan_sip.c: Scheduling destruction of SIP dialog ‘61629487’ in 32000 ms (Method: REGISTER)
[2013-03-29 22:04:45] VERBOSE[2771] chan_sip.c:
<— SIP read from UDP:[EntryPhone]:5060 —>
REGISTER sip:[FreePbx] SIP/2.0
Via: SIP/2.0/UDP [EntryPhone]:5060;rport;branch=z9hG4bK1528902680
From: “Prod Door” sip:719@FreePbx;tag=1874547334
To: “Prod Door” sip:719@FreePbx
Call-ID: 61629487
CSeq: 24 REGISTER
Contact: sip:719@EntryPhone:5060;line=6e3db27916951df
Authorization: Digest username=“719”, realm=“asterisk”, nonce=“67be26bf”, uri=“sip:[FreePbx]”, response=“e1365d30a5c65e683c89abf4fff57bc5”, algorithm=MD5
Max-Forwards: 70
User-Agent: VoIP Guard
Expires: 600
Content-Length: 0
<------------->
[2013-03-29 22:04:45] VERBOSE[2771] chan_sip.c: — (12 headers 0 lines) —
[2013-03-29 22:04:45] VERBOSE[2771] chan_sip.c: Sending to [EntryPhone]:5060 (no NAT)
[2013-03-29 22:04:48] VERBOSE[30354][C-0000006d] pbx.c: – Executing [s@macro-dial-one:38] GotoIf(“SIP/719-000000c1”, “0?godial”) in new stack
[2013-03-29 22:04:48] VERBOSE[30354][C-0000006d] pbx.c: – Executing [s@macro-dial-one:39] Set(“SIP/719-000000c1”, “CONNECTEDLINE(name,i)=X704”) in new stack
[2013-03-29 22:04:48] VERBOSE[30354][C-0000006d] pbx.c: – Executing [s@macro-dial-one:40] Set(“SIP/719-000000c1”, “CONNECTEDLINE(num)=704”) in new stack
[2013-03-29 22:04:48] VERBOSE[30354][C-0000006d] pbx.c: – Executing [s@macro-dial-one:41] Set(“SIP/719-000000c1”, “D_OPTIONS=trI”) in new stack
[2013-03-29 22:04:48] VERBOSE[2771] chan_sip.c: Reliably Transmitting (no NAT) to [EntryPhone]:5060:
OPTIONS sip:719@[EntryPhone]:5060;line=6e3db27916951df SIP/2.0
Via: SIP/2.0/UDP [FreePbx]:5060;branch=z9hG4bK339d0bff
Max-Forwards: 70
From: “Unknown” sip:Unknown@FreePbx;tag=as3d2663a5
To: sip:719@EntryPhone:5060;line=6e3db27916951df
Contact: sip:Unknown@FreePbx:5060
Call-ID: 0e7998d372a3b0ac02bf38460b775aa9@[FreePbx]:5060
CSeq: 102 OPTIONS
User-Agent: FPBX2.11.0beta3(11.1.2)
Date: Fri, 29 Mar 2013 22:04:48 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Content-Length: 0
[2013-03-29 22:04:48] VERBOSE[2771] chan_sip.c:
<— Transmitting (no NAT) to [EntryPhone]:5060 —>
SIP/2.0 200 OK
Via: SIP/2.0/UDP [EntryPhone]:5060;branch=z9hG4bK1528902680;received=[EntryPhone];rport=5060
From: “Prod Door” sip:719@FreePbx;tag=1874547334
To: “Prod Door” sip:719@FreePbx;tag=as2f0f5156
Call-ID: 61629487
CSeq: 24 REGISTER
Server: FPBX2.11.0beta3(11.1.2)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Expires: 600
Contact: sip:719@EntryPhone:5060;line=6e3db27916951df;expires=600
Date: Fri, 29 Mar 2013 22:04:48 GMT
Content-Length: 0
<------------>
[2013-03-29 22:04:48] VERBOSE[2771] chan_sip.c: Scheduling destruction of SIP dialog ‘6506faaf3d2453b900eea1587b58c848@[FreePbx]:5060’ in 6400 ms (Method: NOTIFY)
[2013-03-29 22:04:48] VERBOSE[2771] chan_sip.c: Reliably Transmitting (no NAT) to [EntryPhone]:5060:
NOTIFY sip:719@[EntryPhone]:5060;line=6e3db27916951df SIP/2.0
Via: SIP/2.0/UDP [FreePbx]:5060;branch=z9hG4bK1d9ee8a7
Max-Forwards: 70
From: “Unknown” sip:Unknown@FreePbx;tag=as21c600f8
To: sip:719@EntryPhone:5060;line=6e3db27916951df
Contact: sip:Unknown@FreePbx:5060
Call-ID: 6506faaf3d2453b900eea1587b58c848@[FreePbx]:5060
CSeq: 102 NOTIFY
User-Agent: FPBX2.11.0beta3(11.1.2)
Event: message-summary
Content-Type: application/simple-message-summary
Content-Length: 89
Messages-Waiting: no
Message-Account: sip:*97@[FreePbx]
Voice-Message: 0/0 (0/0)
[2013-03-29 22:04:48] VERBOSE[30354][C-0000006d] pbx.c: – Executing [s@macro-dial-one:42] Dial(“SIP/719-000000c1”, “SIP/704,trI”) in new stack
[2013-03-29 22:04:48] VERBOSE[30354][C-0000006d] netsock2.c: == Using SIP RTP TOS bits 184
[2013-03-29 22:04:48] VERBOSE[30354][C-0000006d] netsock2.c: == Using SIP RTP CoS mark 5
[2013-03-29 22:04:48] VERBOSE[2771] chan_sip.c: Scheduling destruction of SIP dialog ‘61629487’ in 32000 ms (Method: REGISTER)
[2013-03-29 22:04:48] VERBOSE[2771] chan_sip.c:
<— SIP read from UDP:[EntryPhone]:5060 —>
REGISTER sip:[FreePbx] SIP/2.0
Via: SIP/2.0/UDP [EntryPhone]:5060;rport;branch=z9hG4bK1528902680
From: “Prod Door” sip:719@FreePbx;tag=1874547334
To: “Prod Door” sip:719@FreePbx
Call-ID: 61629487
CSeq: 24 REGISTER
Contact: sip:719@EntryPhone:5060;line=6e3db27916951df
Authorization: Digest username=“719”, realm=“asterisk”, nonce=“67be26bf”, uri=“sip:[FreePbx]”, response=“e1365d30a5c65e683c89abf4fff57bc5”, algorithm=MD5
Max-Forwards: 70
User-Agent: VoIP Guard
Expires: 600
Content-Length: 0
<------------->
[2013-03-29 22:04:48] VERBOSE[2771] chan_sip.c: — (12 headers 0 lines) —
[2013-03-29 22:04:48] VERBOSE[2771] chan_sip.c: Sending to [EntryPhone]:5060 (no NAT)
[2013-03-29 22:04:48] NOTICE[2771] chan_sip.c: Correct auth, but based on stale nonce received from ‘“Prod Door” sip:719@FreePbx;tag=1874547334’
[2013-03-29 22:04:48] VERBOSE[2771] chan_sip.c:
<— Transmitting (no NAT) to [EntryPhone]:5060 —>
SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP [EntryPhone]:5060;branch=z9hG4bK1528902680;received=[EntryPhone];rport=5060
From: “Prod Door” sip:719@FreePbx;tag=1874547334
To: “Prod Door” sip:719@FreePbx;tag=as2f0f5156
Call-ID: 61629487
CSeq: 24 REGISTER
Server: FPBX2.11.0beta3(11.1.2)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
WWW-Authenticate: Digest algorithm=MD5, realm=“asterisk”, nonce=“2cb6cf77”, stale=true
Content-Length: 0
<------------>
[2013-03-29 22:04:48] VERBOSE[2771] chan_sip.c: Scheduling destruction of SIP dialog ‘61629487’ in 32000 ms (Method: REGISTER)
[2013-03-29 22:04:48] VERBOSE[30354][C-0000006d] app_dial.c: – Called SIP/704
[2013-03-29 22:04:48] VERBOSE[30354][C-0000006d] chan_sip.c:
<— Transmitting (no NAT) to [EntryPhone]:5060 —>
SIP/2.0 180 Ringing
Via: SIP/2.0/UDP [EntryPhone]:5060;branch=z9hG4bK1524082986;received=[EntryPhone];rport=5060
From: “Prod Door” sip:719@FreePbx;tag=320428240
To: sip:704@FreePbx;tag=as040ccf54
Call-ID: 1396090569
CSeq: 21 INVITE
Server: FPBX2.11.0beta3(11.1.2)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Contact: sip:704@FreePbx:5060
Content-Length: 0
<------------>
[2013-03-29 22:04:48] VERBOSE[30354][C-0000006d] app_dial.c: – Connected line update to SIP/719-000000c1 prevented.
[2013-03-29 22:04:48] VERBOSE[2771] chan_sip.c:
<— SIP read from UDP:[EntryPhone]:5060 —>
REGISTER sip:[FreePbx] SIP/2.0
Via: SIP/2.0/UDP [EntryPhone]:5060;rport;branch=z9hG4bK1528902680
From: “Prod Door” sip:719@FreePbx;tag=1874547334
To: “Prod Door” sip:719@FreePbx
Call-ID: 61629487
CSeq: 24 REGISTER
Contact: sip:719@EntryPhone:5060;line=6e3db27916951df
Authorization: Digest username=“719”, realm=“asterisk”, nonce=“67be26bf”, uri=“sip:[FreePbx]”, response=“e1365d30a5c65e683c89abf4fff57bc5”, algorithm=MD5
Max-Forwards: 70
User-Agent: VoIP Guard
Expires: 600
Content-Length: 0
<------------->
[2013-03-29 22:04:48] VERBOSE[2771] chan_sip.c: — (12 headers 0 lines) —
[2013-03-29 22:04:48] VERBOSE[2771] chan_sip.c: Sending to [EntryPhone]:5060 (no NAT)
[2013-03-29 22:04:48] NOTICE[2771] chan_sip.c: Correct auth, but based on stale nonce received from ‘“Prod Door” sip:719@FreePbx;tag=1874547334’
[2013-03-29 22:04:48] VERBOSE[2771] chan_sip.c:
<— Transmitting (no NAT) to [EntryPhone]:5060 —>
SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP [EntryPhone]:5060;branch=z9hG4bK1528902680;received=[EntryPhone];rport=5060
From: “Prod Door” sip:719@FreePbx;tag=1874547334
To: “Prod Door” sip:719@FreePbx;tag=as2f0f5156
Call-ID: 61629487
CSeq: 24 REGISTER
Server: FPBX2.11.0beta3(11.1.2)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
WWW-Authenticate: Digest algorithm=MD5, realm=“asterisk”, nonce=“2cb6cf77”, stale=true
Content-Length: 0
<------------>
[2013-03-29 22:04:48] VERBOSE[2771] chan_sip.c: Scheduling destruction of SIP dialog ‘61629487’ in 32000 ms (Method: REGISTER)
[2013-03-29 22:04:48] VERBOSE[2771] chan_sip.c:
<— SIP read from UDP:[EntryPhone]:5060 —>
SIP/2.0 200 OK
Via: SIP/2.0/UDP [FreePbx]:5060;branch=z9hG4bK339d0bff
From: “Unknown” sip:Unknown@FreePbx;tag=as3d2663a5
To: sip:719@EntryPhone:5060;line=6e3db27916951df;tag=1285556830
Call-ID: 0e7998d372a3b0ac02bf38460b775aa9@[FreePbx]:5060
CSeq: 102 OPTIONS
Allow: INVITE, ACK, BYE, CANCEL, REFER, OPTIONS, INFO, REGISTER
Accept: application/sdp
User-Agent: VoIP Guard
Content-Length: 0
<------------->
[2013-03-29 22:04:48] VERBOSE[2771] chan_sip.c: — (10 headers 0 lines) —
[2013-03-29 22:04:48] VERBOSE[2771] chan_sip.c: Really destroying SIP dialog ‘0e7998d372a3b0ac02bf38460b775aa9@[FreePbx]:5060’ Method: OPTIONS
[2013-03-29 22:04:48] VERBOSE[2771] chan_sip.c:
<— SIP read from UDP:[EntryPhone]:5060 —>
SIP/2.0 481 Subscription Does Not Exist
Via: SIP/2.0/UDP [FreePbx]:5060;branch=z9hG4bK1d9ee8a7
From: “Unknown” sip:Unknown@FreePbx;tag=as21c600f8
To: sip:719@EntryPhone:5060;line=6e3db27916951df;tag=1684613317
Call-ID: 6506faaf3d2453b900eea1587b58c848@[FreePbx]:5060
CSeq: 102 NOTIFY
User-Agent: VoIP Guard
Content-Length: 0
<------------->
[2013-03-29 22:04:48] VERBOSE[2771] chan_sip.c: — (8 headers 0 lines) —
[2013-03-29 22:04:48] VERBOSE[2771] chan_sip.c: Really destroying SIP dialog ‘6506faaf3d2453b900eea1587b58c848@[FreePbx]:5060’ Method: NOTIFY
[2013-03-29 22:04:48] VERBOSE[2771] chan_sip.c:
<— SIP read from UDP:[EntryPhone]:5060 —>
NOTIFY sip:704@[FreePbx] SIP/2.0
Via: SIP/2.0/UDP [EntryPhone]:5060;rport;branch=z9hG4bK1109136888
From: “Prod Door” sip:719@FreePbx;tag=565414963
To: sip:704@FreePbx
Call-ID: 1530514004
CSeq: 20 NOTIFY
Content-Type: application/snomxml
Max-Forwards: 70
User-Agent: VoIP Guard
Content-Length: 235
<------------>
[2013-03-29 22:04:48] VERBOSE[2771] chan_sip.c: Scheduling destruction of SIP dialog ‘1530514004’ in 32000 ms (Method: NOTIFY)
[2013-03-29 22:04:48] VERBOSE[30354][C-0000006d] app_dial.c: – SIP/704-000000c2 is ringing
[2013-03-29 22:04:48] VERBOSE[30354][C-0000006d] chan_sip.c:
<— Transmitting (no NAT) to [EntryPhone]:5060 —>
SIP/2.0 180 Ringing
Via: SIP/2.0/UDP [EntryPhone]:5060;branch=z9hG4bK1524082986;received=[EntryPhone];rport=5060
From: “Prod Door” sip:719@FreePbx;tag=320428240
To: sip:704@FreePbx;tag=as040ccf54
Call-ID: 1396090569
CSeq: 21 INVITE
Server: FPBX2.11.0beta3(11.1.2)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Contact: sip:704@FreePbx:5060
Content-Length: 0
<------------>
[2013-03-29 22:04:48] VERBOSE[2771] chan_sip.c:
<— SIP read from UDP:[EntryPhone]:5060 —>
NOTIFY sip:704@[FreePbx] SIP/2.0
Via: SIP/2.0/UDP [EntryPhone]:5060;rport;branch=z9hG4bK537528715
From: “Prod Door” sip:719@FreePbx;tag=472532245
To: sip:704@FreePbx
Call-ID: 392454681
CSeq: 20 NOTIFY
Content-Type: application/snomxml
Max-Forwards: 70
User-Agent: VoIP Guard
Content-Length: 235
<------------>
[2013-03-29 22:04:48] VERBOSE[2771] chan_sip.c: Scheduling destruction of SIP dialog ‘392454681’ in 32000 ms (Method: NOTIFY)
[2013-03-29 22:04:50] VERBOSE[30354][C-0000006d] app_dial.c: – Connected line update to SIP/719-000000c1 prevented.
[2013-03-29 22:04:50] VERBOSE[30354][C-0000006d] app_dial.c: – SIP/704-000000c2 answered SIP/719-000000c1
[2013-03-29 22:04:50] VERBOSE[30354][C-0000006d] chan_sip.c: Audio is at 7256
[2013-03-29 22:04:50] VERBOSE[30354][C-0000006d] chan_sip.c: Adding codec 100003 (ulaw) to SDP
[2013-03-29 22:04:50] VERBOSE[30354][C-0000006d] chan_sip.c: Adding codec 100004 (alaw) to SDP
[2013-03-29 22:04:50] VERBOSE[30354][C-0000006d] chan_sip.c: Adding non-codec 0x1 (telephone-event) to SDP
[2013-03-29 22:04:50] VERBOSE[30354][C-0000006d] chan_sip.c:
<— Reliably Transmitting (no NAT) to [EntryPhone]:5060 —>
SIP/2.0 200 OK
Via: SIP/2.0/UDP [EntryPhone]:5060;branch=z9hG4bK1524082986;received=[EntryPhone];rport=5060
From: “Prod Door” sip:719@FreePbx;tag=320428240
To: sip:704@FreePbx;tag=as040ccf54
Call-ID: 1396090569
CSeq: 21 INVITE
Server: FPBX2.11.0beta3(11.1.2)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH
Supported: replaces, timer
Contact: sip:704@FreePbx:5060
Content-Type: application/sdp
Content-Length: 313
v=0
o=root 1165129459 1165129459 IN IP4 [FreePbx]
s=Asterisk PBX 11.1.2
c=IN IP4 [FreePbx]
t=0 0
m=audio 7256 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 - - - -
a=ptime:20
a=sendrecv
m=video 0 RTP/AVP 34 102
<------------>
[2013-03-29 22:04:50] VERBOSE[2771] chan_sip.c:
<— SIP read from UDP:[EntryPhone]:5060 —>
ACK sip:704@[FreePbx]:5060 SIP/2.0
Via: SIP/2.0/UDP [EntryPhone]:5060;rport;branch=z9hG4bK1971181931
From: “Prod Door” sip:719@FreePbx;tag=320428240
To: sip:704@FreePbx;tag=as040ccf54
Call-ID: 1396090569
CSeq: 21 ACK
Contact: sip:719@EntryPhone:5060
Max-Forwards: 70
User-Agent: VoIP Guard
Content-Length: 0
<------------->
[2013-03-29 22:04:50] VERBOSE[2771] chan_sip.c: — (10 headers 0 lines) —
[2013-03-29 22:04:50] VERBOSE[2771] chan_sip.c:
<— SIP read from UDP:[EntryPhone]:5060 —>
NOTIFY sip:704@[FreePbx] SIP/2.0
Via: SIP/2.0/UDP [EntryPhone]:5060;rport;branch=z9hG4bK1289796849
From: “Prod Door” sip:719@FreePbx;tag=899238535
To: sip:704@FreePbx
Call-ID: 2075904362
CSeq: 20 NOTIFY
Content-Type: application/snomxml
Max-Forwards: 70
User-Agent: VoIP Guard
Content-Length: 235
<------------>
[2013-03-29 22:04:50] VERBOSE[2771] chan_sip.c: Scheduling destruction of SIP dialog ‘2075904362’ in 32000 ms (Method: NOTIFY)
[2013-03-29 22:04:55] VERBOSE[2771] chan_sip.c:
<— SIP read from UDP:[EntryPhone]:5060 —>
jaK
<------------->
[2013-03-29 22:05:11] VERBOSE[30354][C-0000006d] pbx.c: – Executing [h@macro-dial-one:1] Macro(“SIP/719-000000c1”, “hangupcall,”) in new stack
[2013-03-29 22:05:11] VERBOSE[30354][C-0000006d] pbx.c: – Executing [s@macro-hangupcall:1] GotoIf(“SIP/719-000000c1”, “1?theend”) in new stack
[2013-03-29 22:05:11] VERBOSE[30354][C-0000006d] pbx.c: – Goto (macro-hangupcall,s,3)
[2013-03-29 22:05:11] VERBOSE[30354][C-0000006d] pbx.c: – Executing [s@macro-hangupcall:3] ExecIf(“SIP/719-000000c1”, “0?Set(CDR(recordingfile)=)”) in new stack
[2013-03-29 22:05:11] VERBOSE[30354][C-0000006d] pbx.c: – Executing [s@macro-hangupcall:4] Hangup(“SIP/719-000000c1”, “”) in new stack
[2013-03-29 22:05:11] VERBOSE[30354][C-0000006d] app_macro.c: == Spawn extension (macro-hangupcall, s, 4) exited non-zero on ‘SIP/719-000000c1’ in macro ‘hangupcall’
[2013-03-29 22:05:11] VERBOSE[30354][C-0000006d] pbx.c: == Spawn extension (macro-dial-one, h, 1) exited non-zero on ‘SIP/719-000000c1’
[2013-03-29 22:05:13] VERBOSE[30354][C-0000006d] app_macro.c: == Spawn extension (macro-dial-one, s, 42) exited non-zero on ‘SIP/719-000000c1’ in macro ‘dial-one’
[2013-03-29 22:05:13] VERBOSE[30354][C-0000006d] app_macro.c: == Spawn extension (macro-exten-vm, s, 14) exited non-zero on ‘SIP/719-000000c1’ in macro ‘exten-vm’
[2013-03-29 22:05:13] VERBOSE[30354][C-0000006d] pbx.c: == Spawn extension (from-internal, 704, 2) exited non-zero on ‘SIP/719-000000c1’
[2013-03-29 22:05:13] VERBOSE[30354][C-0000006d] chan_sip.c: Scheduling destruction of SIP dialog ‘1396090569’ in 6400 ms (Method: ACK)
[2013-03-29 22:05:13] VERBOSE[30354][C-0000006d] chan_sip.c: set_destination: Parsing sip:719@EntryPhone:5060 for address/port to send to
[2013-03-29 22:05:13] VERBOSE[30354][C-0000006d] chan_sip.c: set_destination: set destination to [EntryPhone]:5060
[2013-03-29 22:05:13] VERBOSE[30354][C-0000006d] chan_sip.c: Reliably Transmitting (no NAT) to [EntryPhone]:5060:
BYE sip:719@[EntryPhone]:5060 SIP/2.0
Via: SIP/2.0/UDP [FreePbx]:5060;branch=z9hG4bK079c25a7;rport
Max-Forwards: 70
From: sip:704@FreePbx;tag=as040ccf54
To: “Prod Door” sip:719@FreePbx;tag=320428240
Call-ID: 1396090569
CSeq: 102 BYE
User-Agent: FPBX2.11.0beta3(11.1.2)
Proxy-Authorization: Digest username=“719”, realm=“asterisk”, algorithm=MD5, uri=“sip:[FreePbx]”, nonce=“56d2e246”, response="4536eb57fed0f593722ad58bfb5500ae"
X-Asterisk-HangupCause: Normal Clearing
X-Asterisk-HangupCauseCode: 16
Content-Length: 0
[2013-03-29 22:05:13] VERBOSE[2771] chan_sip.c:
<— SIP read from UDP:[EntryPhone]:5060 —>
SIP/2.0 200 OK
Via: SIP/2.0/UDP [FreePbx]:5060;branch=z9hG4bK079c25a7;rport=5060
From: sip:704@FreePbx;tag=as040ccf54
To: “Prod Door” sip:719@FreePbx;tag=320428240
Call-ID: 1396090569
CSeq: 102 BYE
User-Agent: VoIP Guard
Content-Length: 0
<------------->
[2013-03-29 22:05:13] VERBOSE[2771] chan_sip.c: — (8 headers 0 lines) —
[2013-03-29 22:05:13] VERBOSE[2771][C-0000006d] chan_sip.c: SIP Response message for INCOMING dialog BYE arrived
[2013-03-29 22:05:13] VERBOSE[2771] chan_sip.c: Really destroying SIP dialog ‘1396090569’ Method: ACK
[2013-03-29 22:05:17] VERBOSE[2771] chan_sip.c: Really destroying SIP dialog ‘1322599030’ Method: NOTIFY
[2013-03-29 22:05:20] VERBOSE[2771] chan_sip.c: Really destroying SIP dialog ‘61629487’ Method: REGISTER
[2013-03-29 22:05:20] VERBOSE[2771] chan_sip.c: Really destroying SIP dialog ‘1530514004’ Method: NOTIFY
[2013-03-29 22:05:20] VERBOSE[2771] chan_sip.c: Really destroying SIP dialog ‘392454681’ Method: NOTIFY