SIP Video Broken - TLS SRTP

kolpinkb · November 13, 2016, 1:46am

I don’t use video too often but I just recently noticed that it has stopped working. Using FreePBX 13 Asterisk 13.11.2 latest.

Seeing the following in my logs when attempting to initiate video during a call.

[2016-11-12 20:38:35] VERBOSE[19511][C-00000019] bridge_channel.c: Channel SIP/1001-0000002c joined ‘simple_bridge’ basic-bridge <93ab1bd6-e342-4c08-a9f5-7074240d318e>
[2016-11-12 20:38:38] WARNING[19472][C-00000019] chan_sip.c: Rejecting secure video stream without encryption details: video 35906 RTP/SAVP 118
[2016-11-12 20:38:44] ERROR[18924] tcptls.c: SSL_shutdown() failed: 5
[2016-11-12 20:38:53] VERBOSE[19511][C-00000019] bridge_channel.c: Channel SIP/1001-0000002c left ‘simple_bridge’ basic-bridge <93ab1bd6-e342-4c08-a9f5-7074240d318e>

Any thoughts?

billsimon · December 2, 2016, 1:04pm

It looks like the phone is enforcing media encryption for the video call but Asterisk is not set up for it. Check the phone and turn off SRTP.

kolpinkb · December 3, 2016, 12:17am

Asterisk is set up for SRTP. The audio portion of the call works fine. When either endpoint then enables a video stream I get that error message. The call signaling and audio continues without issue.

I am still on the same version of my endpoint software that I was on a few months ago where it was working ok.

billsimon · December 3, 2016, 2:46am

Could you post the full SDP?

kolpinkb · December 3, 2016, 2:50am

You mean from the Asterisk CLI? Or do I have to do a packet capture with Wireshark?

billsimon · December 3, 2016, 3:02am

SIP debug at the cli will be good.

kolpinkb · December 3, 2016, 3:43am

I accessed the asterisk CLI via “asterisk -rvvvvv”.

I set up the audio calls and then monitored when I pressed the video button on both endpoints. Only the following two lines appear:

Pressing video button on endpoint 1:

[2016-12-02 22:30:44] WARNING[13930][C-00000010]: chan_sip.c:10712 process_sdp: Rejecting secure video stream without encryption details: video 51380 RTP/SAVP 118

Pressing video button on endpoint 2:

[2016-12-02 22:30:49] WARNING[13928][C-00000010]: chan_sip.c:10712 process_sdp: Rejecting secure video stream without encryption details: video 53866 RTP/SAVP 118

Nothing else is printed.

billsimon · December 3, 2016, 3:46am

sip set debug peer 1001 in order to get the sip invite that will have the full SDP

kolpinkb · December 3, 2016, 4:32am

cloud4*CLI> sip set debug peer 1001                                                                                                                                          Unable to get IP address of peer '1001'
    -- Registered SIP '1001' at 192.168.74.70:33059
[2016-12-02 22:49:47] NOTICE[15710]: chan_sip.c:17157 check_auth: Correct auth, but based on stale nonce received from '<sip:[email protected]:5061;transport=TLS>;tag=7ac16948'
    -- Unregistered SIP '1001'
    -- Registered SIP '1001' at 192.168.74.70:33059
cloud4*CLI> sip set debug peer 1001
SIP Debugging Enabled for IP: 192.168.74.70
[2016-12-02 22:49:56] NOTICE[3786]: chan_sip.c:15601 sip_reregister:    -- Re-registration for  [email protected]
[2016-12-02 22:49:56] NOTICE[3786]: chan_sip.c:24394 handle_response_register: Outbound Registration: Expiry for callcentric.com is 60 sec (Scheduling reregistration in 45 s)

<--- SIP read from TLS:192.168.74.70:33059 --->
INVITE sip:[email protected]:5061;transport=TLS SIP/2.0
Via: SIP/2.0/TLS 192.168.74.70:33059;branch=z9hG4bK-524287-1---f16597fb73c27ff9;rport
Max-Forwards: 70
Contact: <sip:[email protected]:33059;transport=TLS>
To: <sip:[email protected]:5061;transport=TLS>
From: <sip:[email protected]:5061;transport=TLS>;tag=037ff50e
Call-ID: -1YlDayNRP8XGrf4hfJ47w..
CSeq: 1 INVITE
Content-Type: application/sdp
User-Agent: Zoiper rv2.8.15
Allow-Events: presence, kpml, talk
Content-Length: 773

v=0
o=Zoiper 0 0 IN IP4 192.168.74.70
s=Zoiper
c=IN IP4 192.168.74.70
t=0 0
m=audio 58466 RTP/SAVP 9 101
a=rtpmap:9 G722/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=sendrecv
a=crypto:5 AES_256_CM_HMAC_SHA1_80 inline:RmhGJpDw6M0wrQoQebA4tMY61maZ0Lxry0sdBIflkHvR2mEJaoGyMF+EmlJe7A==
a=crypto:6 AES_256_CM_HMAC_SHA1_32 inline:RmhGJpDw6M0wrQoQebA4tMY61maZ0Lxry0sdBIflkHvR2mEJaoGyMF+EmlJe7A==
a=crypto:3 AES_192_CM_HMAC_SHA1_80 inline:RmhGJpDw6M0wrQoQebA4tMY61maZ0Lxry0sdBIflkHvR2mEJaoE=
a=crypto:4 AES_192_CM_HMAC_SHA1_32 inline:RmhGJpDw6M0wrQoQebA4tMY61maZ0Lxry0sdBIflkHvR2mEJaoE=
a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:RmhGJpDw6M0wrQoQebA4tMY61maZ0Lxry0sdBIfl
a=crypto:2 AES_CM_128_HMAC_SHA1_32 inline:RmhGJpDw6M0wrQoQebA4tMY61maZ0Lxry0sdBIfl
<------------->
--- (12 headers 16 lines) ---
Sending to 192.168.74.70:33059 (no NAT)
Sending to 192.168.74.70:33059 (no NAT)
Using INVITE request as basis request - -1YlDayNRP8XGrf4hfJ47w..
Found peer '1001' for '1001' from 192.168.74.70:33059

<--- Reliably Transmitting (NAT) to 192.168.74.70:33059 --->
SIP/2.0 401 Unauthorized
Via: SIP/2.0/TLS 192.168.74.70:33059;branch=z9hG4bK-524287-1---f16597fb73c27ff9;received=192.168.74.70;rport=33059
From: <sip:[email protected]:5061;transport=TLS>;tag=037ff50e
To: <sip:[email protected]:5061;transport=TLS>;tag=as5d8df09b
Call-ID: -1YlDayNRP8XGrf4hfJ47w..
CSeq: 1 INVITE
Server: FPBX-13.0.190.7(13.12.1)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="365457f2"
Content-Length: 0


<------------>
Scheduling destruction of SIP dialog '-1YlDayNRP8XGrf4hfJ47w..' in 6400 ms (Method: INVITE)

<--- SIP read from TLS:192.168.74.70:33059 --->
ACK sip:[email protected]:5061;transport=TLS SIP/2.0
Via: SIP/2.0/TLS 192.168.74.70:33059;branch=z9hG4bK-524287-1---f16597fb73c27ff9;rport
Max-Forwards: 70
To: <sip:[email protected]:5061;transport=TLS>;tag=as5d8df09b
From: <sip:[email protected]:5061;transport=TLS>;tag=037ff50e
Call-ID: -1YlDayNRP8XGrf4hfJ47w..
CSeq: 1 ACK
Content-Length: 0

<------------->
--- (8 headers 0 lines) ---

<--- SIP read from TLS:192.168.74.70:33059 --->
INVITE sip:[email protected]:5061;transport=TLS SIP/2.0
Via: SIP/2.0/TLS 192.168.74.70:33059;branch=z9hG4bK-524287-1---551b1274c9885cd9;rport
Max-Forwards: 70
Contact: <sip:[email protected]:33059;transport=TLS>
To: <sip:[email protected]:5061;transport=TLS>
From: <sip:[email protected]:5061;transport=TLS>;tag=037ff50e
Call-ID: -1YlDayNRP8XGrf4hfJ47w..
CSeq: 2 INVITE
Content-Type: application/sdp
User-Agent: Zoiper rv2.8.15
Authorization: Digest username="1001",realm="asterisk",nonce="365457f2",uri="sip:[email protected]:5061;transport=TLS",response="38c7e89ea0b1329f9839c131a5afcf20",algorithm=MD5
Allow-Events: presence, kpml, talk
Content-Length: 773

v=0
o=Zoiper 0 0 IN IP4 192.168.74.70
s=Zoiper
c=IN IP4 192.168.74.70
t=0 0
m=audio 58466 RTP/SAVP 9 101
a=rtpmap:9 G722/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=sendrecv
a=crypto:5 AES_256_CM_HMAC_SHA1_80 inline:RmhGJpDw6M0wrQoQebA4tMY61maZ0Lxry0sdBIflkHvR2mEJaoGyMF+EmlJe7A==
a=crypto:6 AES_256_CM_HMAC_SHA1_32 inline:RmhGJpDw6M0wrQoQebA4tMY61maZ0Lxry0sdBIflkHvR2mEJaoGyMF+EmlJe7A==
a=crypto:3 AES_192_CM_HMAC_SHA1_80 inline:RmhGJpDw6M0wrQoQebA4tMY61maZ0Lxry0sdBIflkHvR2mEJaoE=
a=crypto:4 AES_192_CM_HMAC_SHA1_32 inline:RmhGJpDw6M0wrQoQebA4tMY61maZ0Lxry0sdBIflkHvR2mEJaoE=
a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:RmhGJpDw6M0wrQoQebA4tMY61maZ0Lxry0sdBIfl
a=crypto:2 AES_CM_128_HMAC_SHA1_32 inline:RmhGJpDw6M0wrQoQebA4tMY61maZ0Lxry0sdBIfl
<------------->
--- (13 headers 16 lines) ---
Sending to 192.168.74.70:33059 (NAT)
Using INVITE request as basis request - -1YlDayNRP8XGrf4hfJ47w..
Found peer '1001' for '1001' from 192.168.74.70:33059
  == Using SIP VIDEO TOS bits 136
  == Using SIP VIDEO CoS mark 6
  == Using SIP RTP TOS bits 184
  == Using SIP RTP CoS mark 5
Found RTP audio format 9
Found RTP audio format 101
Found audio description format G722 for ID 9
Found audio description format telephone-event for ID 101
[2016-12-02 22:50:07] WARNING[15710][C-00000011]: sdp_srtp.c:261 ast_sdp_crypto_process: Unsupported crypto suite: AES_256_CM_HMAC_SHA1_80
[2016-12-02 22:50:07] WARNING[15710][C-00000011]: sdp_srtp.c:261 ast_sdp_crypto_process: Unsupported crypto suite: AES_256_CM_HMAC_SHA1_32
[2016-12-02 22:50:07] WARNING[15710][C-00000011]: sdp_srtp.c:261 ast_sdp_crypto_process: Unsupported crypto suite: AES_192_CM_HMAC_SHA1_80
[2016-12-02 22:50:07] WARNING[15710][C-00000011]: sdp_srtp.c:261 ast_sdp_crypto_process: Unsupported crypto suite: AES_192_CM_HMAC_SHA1_32
Capabilities: us - (g722|ulaw|g729|h264), peer - audio=(g722)/video=(nothing)/text=(nothing), combined - (g722)
Non-codec capabilities (dtmf): us - 0x1 (telephone-event|), peer - 0x1 (telephone-event|), combined - 0x1 (telephone-event|)
Peer audio RTP is at port 192.168.74.70:58466
Peer doesn't provide video
Looking for 1013 in from-internal (domain xxxxxx.xxxxxxxxxxxxxx.com)
sip_route_dump: route/path hop: <sip:[email protected]:33059;transport=TLS>

<--- Transmitting (NAT) to 192.168.74.70:33059 --->
SIP/2.0 100 Trying
Via: SIP/2.0/TLS 192.168.74.70:33059;branch=z9hG4bK-524287-1---551b1274c9885cd9;received=192.168.74.70;rport=33059
From: <sip:[email protected]:5061;transport=TLS>;tag=037ff50e
To: <sip:[email protected]:5061;transport=TLS>
Call-ID: -1YlDayNRP8XGrf4hfJ47w..
CSeq: 2 INVITE
Server: FPBX-13.0.190.7(13.12.1)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Contact: <sip:[email protected]:5061;transport=TLS>
Content-Length: 0


<------------>
    -- Executing [1013@from-internal:1] GotoIf("SIP/1001-00000020", "1?ext-local,1013,1:followme-check,1013,1") in new stack
    -- Goto (ext-local,1013,1)
    -- Executing [1013@ext-local:1] Set("SIP/1001-00000020", "__RINGTIMER=15") in new stack
    -- Executing [1013@ext-local:2] Macro("SIP/1001-00000020", "exten-vm,novm,1013,0,0,0") in new stack
    -- Executing [s@macro-exten-vm:1] Macro("SIP/1001-00000020", "user-callerid,") in new stack
    -- Executing [s@macro-user-callerid:1] Set("SIP/1001-00000020", "TOUCH_MONITOR=1480737007.35") in new stack
    -- Executing [s@macro-user-callerid:2] Set("SIP/1001-00000020", "AMPUSER=1001") in new stack
    -- Executing [s@macro-user-callerid:3] GotoIf("SIP/1001-00000020", "0?report") in new stack
    -- Executing [s@macro-user-callerid:4] ExecIf("SIP/1001-00000020", "1?Set(REALCALLERIDNUM=1001)") in new stack
    -- Executing [s@macro-user-callerid:5] Set("SIP/1001-00000020", "AMPUSER=1001") in new stack
    -- Executing [s@macro-user-callerid:6] GotoIf("SIP/1001-00000020", "0?limit") in new stack
    -- Executing [s@macro-user-callerid:7] Set("SIP/1001-00000020", "AMPUSERCIDNAME=JOHN DOE") in new stack
    -- Executing [s@macro-user-callerid:8] GotoIf("SIP/1001-00000020", "0?report") in new stack
    -- Executing [s@macro-user-callerid:9] Set("SIP/1001-00000020", "AMPUSERCID=1001") in new stack
    -- Executing [s@macro-user-callerid:10] Set("SIP/1001-00000020", "__DIAL_OPTIONS=Ttr") in new stack
    -- Executing [s@macro-user-callerid:11] Set("SIP/1001-00000020", "CALLERID(all)="JOHN DOE" <1001>") in new stack
    -- Executing [s@macro-user-callerid:12] GotoIf("SIP/1001-00000020", "0?limit") in new stack
    -- Executing [s@macro-user-callerid:13] ExecIf("SIP/1001-00000020", "0?Set(GROUP(concurrency_limit)=1001)") in new stack
    -- Executing [s@macro-user-callerid:14] ExecIf("SIP/1001-00000020", "0?Set(CHANNEL(language)=)") in new stack
    -- Executing [s@macro-user-callerid:15] GotoIf("SIP/1001-00000020", "0?continue") in new stack
    -- Executing [s@macro-user-callerid:16] ExecIf("SIP/1001-00000020", "1?Set(__CALLEE_ACCOUNCODE=)") in new stack
    -- Executing [s@macro-user-callerid:17] Set("SIP/1001-00000020", "__TTL=64") in new stack
    -- Executing [s@macro-user-callerid:18] GotoIf("SIP/1001-00000020", "1?continue") in new stack
    -- Goto (macro-user-callerid,s,29)
    -- Executing [s@macro-user-callerid:29] Set("SIP/1001-00000020", "CALLERID(number)=1001") in new stack
    -- Executing [s@macro-user-callerid:30] Set("SIP/1001-00000020", "CALLERID(name)=JOHN DOE") in new stack
    -- Executing [s@macro-user-callerid:31] GotoIf("SIP/1001-00000020", "0?cnum") in new stack
    -- Executing [s@macro-user-callerid:32] Set("SIP/1001-00000020", "CDR(cnam)=JOHN DOE") in new stack
    -- Executing [s@macro-user-callerid:33] Set("SIP/1001-00000020", "CDR(cnum)=1001") in new stack
    -- Executing [s@macro-user-callerid:34] Set("SIP/1001-00000020", "CHANNEL(language)=en") in new stack
    -- Executing [s@macro-exten-vm:2] Set("SIP/1001-00000020", "RingGroupMethod=none") in new stack
    -- Executing [s@macro-exten-vm:3] Set("SIP/1001-00000020", "__EXTTOCALL=1013") in new stack
    -- Executing [s@macro-exten-vm:4] Set("SIP/1001-00000020", "__PICKUPMARK=1013") in new stack
    -- Executing [s@macro-exten-vm:5] Set("SIP/1001-00000020", "RT=") in new stack
    -- Executing [s@macro-exten-vm:6] ExecIf("SIP/1001-00000020", "0?Macro(vm,novm,DIRECTDIAL,)") in new stack
    -- Executing [s@macro-exten-vm:7] ExecIf("SIP/1001-00000020", "0?MacroExit()") in new stack
    -- Executing [s@macro-exten-vm:8] Gosub("SIP/1001-00000020", "sub-record-check,s,1(exten,1013,dontcare)") in new stack
    -- Executing [s@sub-record-check:1] GotoIf("SIP/1001-00000020", "0?initialized") in new stack
    -- Executing [s@sub-record-check:2] Set("SIP/1001-00000020", "__REC_STATUS=INITIALIZED") in new stack
    -- Executing [s@sub-record-check:3] Set("SIP/1001-00000020", "NOW=1480737007") in new stack
    -- Executing [s@sub-record-check:4] Set("SIP/1001-00000020", "__DAY=02") in new stack
    -- Executing [s@sub-record-check:5] Set("SIP/1001-00000020", "__MONTH=12") in new stack
    -- Executing [s@sub-record-check:6] Set("SIP/1001-00000020", "__YEAR=2016") in new stack
    -- Executing [s@sub-record-check:7] Set("SIP/1001-00000020", "__TIMESTR=20161202-225007") in new stack
    -- Executing [s@sub-record-check:8] Set("SIP/1001-00000020", "__FROMEXTEN=1001") in new stack
    -- Executing [s@sub-record-check:9] Set("SIP/1001-00000020", "__MON_FMT=wav") in new stack
    -- Executing [s@sub-record-check:10] NoOp("SIP/1001-00000020", "Recordings initialized") in new stack
    -- Executing [s@sub-record-check:11] ExecIf("SIP/1001-00000020", "0?Set(ARG3=dontcare)") in new stack
    -- Executing [s@sub-record-check:12] Set("SIP/1001-00000020", "REC_POLICY_MODE_SAVE=") in new stack
    -- Executing [s@sub-record-check:13] ExecIf("SIP/1001-00000020", "0?Set(REC_STATUS=NO)") in new stack
    -- Executing [s@sub-record-check:14] GotoIf("SIP/1001-00000020", "5?checkaction") in new stack
    -- Goto (sub-record-check,s,17)
    -- Executing [s@sub-record-check:17] GotoIf("SIP/1001-00000020", "1?sub-record-check,exten,1") in new stack
    -- Goto (sub-record-check,exten,1)
    -- Executing [exten@sub-record-check:1] NoOp("SIP/1001-00000020", "Exten Recording Check between 1001 and 1013") in new stack
    -- Executing [exten@sub-record-check:2] Set("SIP/1001-00000020", "CALLTYPE=internal") in new stack
    -- Executing [exten@sub-record-check:3] ExecIf("SIP/1001-00000020", "0?Set(CALLTYPE=)") in new stack
    -- Executing [exten@sub-record-check:4] Set("SIP/1001-00000020", "CALLEE=dontcare") in new stack
    -- Executing [exten@sub-record-check:5] ExecIf("SIP/1001-00000020", "0?Set(CALLEE=dontcare)") in new stack
    -- Executing [exten@sub-record-check:6] GotoIf("SIP/1001-00000020", "0?callee") in new stack
    -- Executing [exten@sub-record-check:7] GotoIf("SIP/1001-00000020", "1?caller") in new stack
    -- Goto (sub-record-check,exten,13)
    -- Executing [exten@sub-record-check:13] Set("SIP/1001-00000020", "RECMODE=force") in new stack
    -- Executing [exten@sub-record-check:14] ExecIf("SIP/1001-00000020", "0?Set(RECMODE=dontcare)") in new stack
    -- Executing [exten@sub-record-check:15] ExecIf("SIP/1001-00000020", "0?Set(RECMODE=dontcare)") in new stack
    -- Executing [exten@sub-record-check:16] Gosub("SIP/1001-00000020", "recordcheck,1(force,internal,1013)") in new stack
    -- Executing [recordcheck@sub-record-check:1] NoOp("SIP/1001-00000020", "Starting recording check against force") in new stack
    -- Executing [recordcheck@sub-record-check:2] Goto("SIP/1001-00000020", "force") in new stack
    -- Goto (sub-record-check,recordcheck,5)
    -- Executing [recordcheck@sub-record-check:5] Set("SIP/1001-00000020", "__REC_POLICY_MODE=FORCE") in new stack
    -- Executing [recordcheck@sub-record-check:6] GotoIf("SIP/1001-00000020", "1?startrec") in new stack
    -- Goto (sub-record-check,recordcheck,16)
    -- Executing [recordcheck@sub-record-check:16] NoOp("SIP/1001-00000020", "Starting recording: internal, 1013") in new stack
    -- Executing [recordcheck@sub-record-check:17] Set("SIP/1001-00000020", "AUDIOHOOK_INHERIT(MixMonitor)=yes") in new stack
    -- Executing [recordcheck@sub-record-check:18] Set("SIP/1001-00000020", "__CALLFILENAME=internal-1013-1001-20161202-225007-1480737007.35") in new stack
    -- Executing [recordcheck@sub-record-check:19] MixMonitor("SIP/1001-00000020", "2016/12/02/internal-1013-1001-20161202-225007-1480737007.35.wav,ai(LOCAL_MIXMON_ID),") in new stack
    -- Executing [recordcheck@sub-record-check:20] Set("SIP/1001-00000020", "__MIXMON_ID=0x7ff6f0071410") in new stack
    -- Executing [recordcheck@sub-record-check:21] Set("SIP/1001-00000020", "__RECORD_ID=SIP/1001-00000020") in new stack
    -- Executing [recordcheck@sub-record-check:22] Set("SIP/1001-00000020", "__REC_STATUS=RECORDING") in new stack
    -- Executing [recordcheck@sub-record-check:23] Set("SIP/1001-00000020", "CDR(recordingfile)=internal-1013-1001-20161202-225007-1480737007.35.wav") in new stack
    -- Executing [recordcheck@sub-record-check:24] Return("SIP/1001-00000020", "") in new stack
    -- Executing [exten@sub-record-check:17] Return("SIP/1001-00000020", "") in new stack
    -- Executing [s@macro-exten-vm:9] GotoIf("SIP/1001-00000020", "1?macrodial") in new stack
    -- Goto (macro-exten-vm,s,15)
    -- Executing [s@macro-exten-vm:15] GosubIf("SIP/1001-00000020", "0?clrheader,1()") in new stack
    -- Executing [s@macro-exten-vm:16] Macro("SIP/1001-00000020", "dial-one,,Ttr,1013") in new stack
    -- Executing [s@macro-dial-one:1] Set("SIP/1001-00000020", "DEXTEN=1013") in new stack
    -- Executing [s@macro-dial-one:2] ExecIf("SIP/1001-00000020", "0?Set(EXTTOCALL=1013)") in new stack
    -- Executing [s@macro-dial-one:3] Set("SIP/1001-00000020", "DIALSTATUS_CW=") in new stack
    -- Executing [s@macro-dial-one:4] GosubIf("SIP/1001-00000020", "0?screen,1()") in new stack
    -- Executing [s@macro-dial-one:5] GosubIf("SIP/1001-00000020", "0?cf,1()") in new stack
    -- Executing [s@macro-dial-one:6] GotoIf("SIP/1001-00000020", "1?skip1") in new stack
    -- Goto (macro-dial-one,s,9)
    -- Executing [s@macro-dial-one:9] GotoIf("SIP/1001-00000020", "0?nodial") in new stack
    -- Executing [s@macro-dial-one:10] GotoIf("SIP/1001-00000020", "0?continue") in new stack
    -- Executing [s@macro-dial-one:11] Set("SIP/1001-00000020", "EXTHASCW=ENABLED") in new stack
    -- Executing [s@macro-dial-one:12] GotoIf("SIP/1001-00000020", "0?next1:cwinusebusy") in new stack
    -- Goto (macro-dial-one,s,24)
    -- Executing [s@macro-dial-one:24] GotoIf("SIP/1001-00000020", "0?next3:continue") in new stack
    -- Goto (macro-dial-one,s,26)
    -- Executing [s@macro-dial-one:26] GotoIf("SIP/1001-00000020", "0?nodial") in new stack
    -- Executing [s@macro-dial-one:27] GosubIf("SIP/1001-00000020", "1?dstring,1():dlocal,1()") in new stack
    -- Executing [dstring@macro-dial-one:1] Set("SIP/1001-00000020", "DSTRING=") in new stack
    -- Executing [dstring@macro-dial-one:2] Set("SIP/1001-00000020", "DEVICES=1013") in new stack
    -- Executing [dstring@macro-dial-one:3] ExecIf("SIP/1001-00000020", "0?Return()") in new stack
    -- Executing [dstring@macro-dial-one:4] ExecIf("SIP/1001-00000020", "0?Set(DEVICES=013)") in new stack
    -- Executing [dstring@macro-dial-one:5] Set("SIP/1001-00000020", "LOOPCNT=1") in new stack
    -- Executing [dstring@macro-dial-one:6] Set("SIP/1001-00000020", "ITER=1") in new stack
    -- Executing [dstring@macro-dial-one:7] Set("SIP/1001-00000020", "THISDIAL=SIP/1013") in new stack
    -- Executing [dstring@macro-dial-one:8] GosubIf("SIP/1001-00000020", "1?zap2dahdi,1()") in new stack
  == Begin MixMonitor Recording SIP/1001-00000020
    -- Executing [zap2dahdi@macro-dial-one:1] ExecIf("SIP/1001-00000020", "0?Return()") in new stack
    -- Executing [zap2dahdi@macro-dial-one:2] Set("SIP/1001-00000020", "NEWDIAL=") in new stack
    -- Executing [zap2dahdi@macro-dial-one:3] Set("SIP/1001-00000020", "LOOPCNT2=1") in new stack
    -- Executing [zap2dahdi@macro-dial-one:4] Set("SIP/1001-00000020", "ITER2=1") in new stack
    -- Executing [zap2dahdi@macro-dial-one:5] Set("SIP/1001-00000020", "THISPART2=SIP/1013") in new stack
    -- Executing [zap2dahdi@macro-dial-one:6] ExecIf("SIP/1001-00000020", "0?Set(THISPART2=DAHDI/1013)") in new stack
    -- Executing [zap2dahdi@macro-dial-one:7] Set("SIP/1001-00000020", "NEWDIAL=SIP/1013&") in new stack
    -- Executing [zap2dahdi@macro-dial-one:8] Set("SIP/1001-00000020", "ITER2=2") in new stack
    -- Executing [zap2dahdi@macro-dial-one:9] GotoIf("SIP/1001-00000020", "0?begin2") in new stack
    -- Executing [zap2dahdi@macro-dial-one:10] Set("SIP/1001-00000020", "THISDIAL=SIP/1013") in new stack
    -- Executing [zap2dahdi@macro-dial-one:11] Return("SIP/1001-00000020", "") in new stack
    -- Executing [dstring@macro-dial-one:9] GotoIf("SIP/1001-00000020", "1?docheck") in new stack
    -- Goto (macro-dial-one,dstring,14)
    -- Executing [dstring@macro-dial-one:14] GotoIf("SIP/1001-00000020", "0?skipset") in new stack
    -- Executing [dstring@macro-dial-one:15] Set("SIP/1001-00000020", "DSTRING=SIP/1013&") in new stack
    -- Executing [dstring@macro-dial-one:16] Set("SIP/1001-00000020", "ITER=2") in new stack
    -- Executing [dstring@macro-dial-one:17] GotoIf("SIP/1001-00000020", "0?begin") in new stack
    -- Executing [dstring@macro-dial-one:18] ExecIf("SIP/1001-00000020", "0?Return()") in new stack
    -- Executing [dstring@macro-dial-one:19] Set("SIP/1001-00000020", "DSTRING=SIP/1013") in new stack
    -- Executing [dstring@macro-dial-one:20] Return("SIP/1001-00000020", "") in new stack
    -- Executing [s@macro-dial-one:28] GotoIf("SIP/1001-00000020", "0?nodial") in new stack
    -- Executing [s@macro-dial-one:29] GotoIf("SIP/1001-00000020", "0?skiptrace") in new stack
    -- Executing [s@macro-dial-one:30] GosubIf("SIP/1001-00000020", "1?ctset,1():ctclear,1()") in new stack
    -- Executing [ctset@macro-dial-one:1] Set("SIP/1001-00000020", "DB(CALLTRACE/1013)=1001") in new stack
    -- Executing [ctset@macro-dial-one:2] Return("SIP/1001-00000020", "") in new stack
    -- Executing [s@macro-dial-one:31] Set("SIP/1001-00000020", "D_OPTIONS=Ttr") in new stack
    -- Executing [s@macro-dial-one:32] NoOp("SIP/1001-00000020", "Blind Transfer: , Attended Transfer: , User: 1001, Alert Info: ") in new stack
    -- Executing [s@macro-dial-one:33] ExecIf("SIP/1001-00000020", "1?Set(ALERT_INFO=)") in new stack
    -- Executing [s@macro-dial-one:34] ExecIf("SIP/1001-00000020", "0?Set(ALERT_INFO=)") in new stack
    -- Executing [s@macro-dial-one:35] ExecIf("SIP/1001-00000020", "0?Set(ALERT_INFO=)") in new stack
    -- Executing [s@macro-dial-one:36] ExecIf("SIP/1001-00000020", "0?Set(ALERT_INFO=;volume=)") in new stack
    -- Executing [s@macro-dial-one:37] ExecIf("SIP/1001-00000020", "0?Set(ALERT_INFO=;volume=)") in new stack
    -- Executing [s@macro-dial-one:38] GosubIf("SIP/1001-00000020", "0?func-set-sipheader,s,1(Alert-Info,)") in new stack
    -- Executing [s@macro-dial-one:39] ExecIf("SIP/1001-00000020", "0?Set(CHANNEL(musicclass)=)") in new stack
    -- Executing [s@macro-dial-one:40] GosubIf("SIP/1001-00000020", "0?qwait,1()") in new stack
    -- Executing [s@macro-dial-one:41] Set("SIP/1001-00000020", "__CWIGNORE=") in new stack
    -- Executing [s@macro-dial-one:42] Set("SIP/1001-00000020", "__KEEPCID=TRUE") in new stack
    -- Executing [s@macro-dial-one:43] GotoIf("SIP/1001-00000020", "0?usegoto,1") in new stack
    -- Executing [s@macro-dial-one:44] GotoIf("SIP/1001-00000020", "0?godial") in new stack
    -- Executing [s@macro-dial-one:45] Gosub("SIP/1001-00000020", "sub-presencestate-display,s,1(1013)") in new stack
    -- Executing [s@sub-presencestate-display:1] Goto("SIP/1001-00000020", "state-not_set,1") in new stack
    -- Goto (sub-presencestate-display,state-not_set,1)
    -- Executing [state-not_set@sub-presencestate-display:1] Set("SIP/1001-00000020", "PRESENCESTATE_DISPLAY=") in new stack
    -- Executing [state-not_set@sub-presencestate-display:2] Return("SIP/1001-00000020", "") in new stack
    -- Executing [s@macro-dial-one:46] Set("SIP/1001-00000020", "CONNECTEDLINE(name,i)=JANE DOE") in new stack
    -- Executing [s@macro-dial-one:47] Set("SIP/1001-00000020", "CONNECTEDLINE(num)=1013") in new stack
    -- Executing [s@macro-dial-one:48] Set("SIP/1001-00000020", "D_OPTIONS=TtrI") in new stack
    -- Executing [s@macro-dial-one:49] Macro("SIP/1001-00000020", "dialout-one-predial-hook,") in new stack
    -- Executing [s@macro-dialout-one-predial-hook:1] MacroExit("SIP/1001-00000020", "") in new stack
    -- Executing [s@macro-dial-one:50] ExecIf("SIP/1001-00000020", "0?Set(D_OPTIONS=trII)") in new stack
    -- Executing [s@macro-dial-one:51] Dial("SIP/1001-00000020", "SIP/1013,,TtrIb(func-apply-sipheaders^s^1)") in new stack
  == Using SIP VIDEO TOS bits 136
  == Using SIP VIDEO CoS mark 6
  == Using SIP RTP TOS bits 184
  == Using SIP RTP CoS mark 5
    -- SIP/1013-00000021 Internal Gosub(func-apply-sipheaders,s,1) start
    -- Executing [s@func-apply-sipheaders:1] NoOp("SIP/1013-00000021", "Applying SIP Headers to channel") in new stack
    -- Executing [s@func-apply-sipheaders:2] Set("SIP/1013-00000021", "SIPHEADERKEYS=") in new stack
    -- Executing [s@func-apply-sipheaders:3] While("SIP/1013-00000021", "0") in new stack
    -- Jumping to priority 7
    -- Executing [s@func-apply-sipheaders:8] Return("SIP/1013-00000021", "") in new stack
  == Spawn extension (from-internal, 1013, 1) exited non-zero on 'SIP/1013-00000021'
    -- SIP/1013-00000021 Internal Gosub(func-apply-sipheaders,s,1) complete GOSUB_RETVAL=
    -- Called SIP/1013

<--- Transmitting (NAT) to 192.168.74.70:33059 --->
SIP/2.0 180 Ringing
Via: SIP/2.0/TLS 192.168.74.70:33059;branch=z9hG4bK-524287-1---551b1274c9885cd9;received=192.168.74.70;rport=33059
From: <sip:[email protected]:5061;transport=TLS>;tag=037ff50e
To: <sip:[email protected]:5061;transport=TLS>;tag=as7be5cbbe
Call-ID: -1YlDayNRP8XGrf4hfJ47w..
CSeq: 2 INVITE
Server: FPBX-13.0.190.7(13.12.1)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Contact: <sip:[email protected]:5061;transport=TLS>
P-Asserted-Identity: "JANE DOE" <sip:[email protected]>
Content-Length: 0


<------------>
    -- Connected line update to SIP/1001-00000020 prevented.
    -- SIP/1013-00000021 is ringing

<--- Transmitting (NAT) to 192.168.74.70:33059 --->
SIP/2.0 180 Ringing
Via: SIP/2.0/TLS 192.168.74.70:33059;branch=z9hG4bK-524287-1---551b1274c9885cd9;received=192.168.74.70;rport=33059
From: <sip:[email protected]:5061;transport=TLS>;tag=037ff50e
To: <sip:[email protected]:5061;transport=TLS>;tag=as7be5cbbe
Call-ID: -1YlDayNRP8XGrf4hfJ47w..
CSeq: 2 INVITE
Server: FPBX-13.0.190.7(13.12.1)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Contact: <sip:[email protected]:5061;transport=TLS>
Content-Length: 0


<------------>
[2016-12-02 22:50:12] NOTICE[3786]: chan_sip.c:15601 sip_reregister:    -- Re-registration for  [email protected]
[2016-12-02 22:50:12] NOTICE[3786]: chan_sip.c:24394 handle_response_register: Outbound Registration: Expiry for toronto4.voip.ms is 120 sec (Scheduling reregistration in 105 s)
       > 0x7ff6f00a97b0 -- Probation passed - setting RTP source address to 192.168.74.20:51378
    -- Connected line update to SIP/1001-00000020 prevented.
    -- SIP/1013-00000021 answered SIP/1001-00000020
Audio is at 14628
Adding codec g722 to SDP
Adding non-codec 0x1 (telephone-event) to SDP

kolpinkb · December 3, 2016, 4:33am

<--- Reliably Transmitting (NAT) to 192.168.74.70:33059 --->
SIP/2.0 200 OK
Via: SIP/2.0/TLS 192.168.74.70:33059;branch=z9hG4bK-524287-1---551b1274c9885cd9;received=192.168.74.70;rport=33059
From: <sip:[email protected]:5061;transport=TLS>;tag=037ff50e
To: <sip:[email protected]:5061;transport=TLS>;tag=as7be5cbbe
Call-ID: -1YlDayNRP8XGrf4hfJ47w..
CSeq: 2 INVITE
Server: FPBX-13.0.190.7(13.12.1)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Contact: <sip:[email protected]:5061;transport=TLS>
P-Asserted-Identity: "JANE DOE" <sip:[email protected]>
Content-Type: application/sdp
Content-Length: 327

v=0
o=root 255018580 255018580 IN IP4 XXX.XXX.XXX.XXX
s=Asterisk PBX 13.12.2
c=IN IP4 XXX.XXX.XXX.XXX
t=0 0
m=audio 14628 RTP/SAVP 9 101
a=rtpmap:9 G722/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=maxptime:150
a=sendrecv
a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:7UlPjruGDmqO6n4y9fp/SBKHGg05Xj1Yo48rvf16

<------------>
    -- Channel SIP/1013-00000021 joined 'simple_bridge' basic-bridge <95c37ce6-f835-4d88-9bf2-3707c009fe7d>
    -- Channel SIP/1001-00000020 joined 'simple_bridge' basic-bridge <95c37ce6-f835-4d88-9bf2-3707c009fe7d>
       > 0x7ff6f0093eb0 -- Probation passed - setting RTP source address to 192.168.74.70:58466

<--- SIP read from TLS:192.168.74.70:33059 --->
ACK sip:[email protected]:5061;transport=TLS SIP/2.0
Via: SIP/2.0/TLS 192.168.74.70:33059;branch=z9hG4bK-524287-1---373e369e9554c16f;rport
Max-Forwards: 70
Contact: <sip:[email protected]:33059;transport=TLS>
To: <sip:[email protected]:5061;transport=TLS>;tag=as7be5cbbe
From: <sip:[email protected]:5061;transport=TLS>;tag=037ff50e
Call-ID: -1YlDayNRP8XGrf4hfJ47w..
CSeq: 2 ACK
User-Agent: Zoiper rv2.8.15
Content-Length: 0

<------------->
--- (10 headers 0 lines) ---
       > 0x7ff6f00a97b0 -- Probation passed - setting RTP source address to 192.168.74.20:51378

<--- SIP read from TLS:192.168.74.70:33059 --->

<------------->
Really destroying SIP dialog 'DlH2Df_0Vvv79JY-A1Xxjw..' Method: REGISTER
Really destroying SIP dialog 'zwSDNpoCSsJIaWdWm5G2nw..' Method: REGISTER

<--- SIP read from TLS:192.168.74.70:33059 --->
INVITE sip:[email protected]:5061;transport=TLS SIP/2.0
Via: SIP/2.0/TLS 192.168.74.70:33059;branch=z9hG4bK-524287-1---ecae9b3c03389e7f;rport
Max-Forwards: 70
Contact: <sip:[email protected]:33059;transport=TLS>
To: <sip:[email protected]:5061;transport=TLS>;tag=as7be5cbbe
From: <sip:[email protected]:5061;transport=TLS>;tag=037ff50e
Call-ID: -1YlDayNRP8XGrf4hfJ47w..
CSeq: 3 INVITE
Content-Type: application/sdp
User-Agent: Zoiper rv2.8.15
Authorization: Digest username="1001",realm="asterisk",nonce="365457f2",uri="sip:[email protected]:5061;transport=TLS",response="1647e6f8f55b58dacf5d934898e8487a",algorithm=MD5
Allow-Events: presence, kpml, talk
Content-Length: 922

v=0
o=Zoiper 0 1 IN IP4 192.168.74.70
s=Zoiper
c=IN IP4 192.168.74.70
t=0 0
m=audio 58466 RTP/SAVP 9 101
a=rtpmap:9 G722/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=sendrecv
a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:RmhGJpDw6M0wrQoQebA4tMY61maZ0Lxry0sdBIfl
m=video 58468 RTP/SAVP 118
a=rtpmap:118 H264/90000
a=sendrecv
a=crypto:5 AES_256_CM_HMAC_SHA1_80 inline:ewzbIFxe1jtlTIdZtWRt16Dj8tz6LuFgQN2TLkAovLcp+BvocsNhv8QrP9hq/g==
a=crypto:6 AES_256_CM_HMAC_SHA1_32 inline:ewzbIFxe1jtlTIdZtWRt16Dj8tz6LuFgQN2TLkAovLcp+BvocsNhv8QrP9hq/g==
a=crypto:3 AES_192_CM_HMAC_SHA1_80 inline:ewzbIFxe1jtlTIdZtWRt16Dj8tz6LuFgQN2TLkAovLcp+BvocsM=
a=crypto:4 AES_192_CM_HMAC_SHA1_32 inline:ewzbIFxe1jtlTIdZtWRt16Dj8tz6LuFgQN2TLkAovLcp+BvocsM=
a=crypto:1 AES_CM_128_HMAC_SHA1_80 inline:ewzbIFxe1jtlTIdZtWRt16Dj8tz6LuFgQN2TLkAo
a=crypto:2 AES_CM_128_HMAC_SHA1_32 inline:ewzbIFxe1jtlTIdZtWRt16Dj8tz6LuFgQN2TLkAo
<------------->
--- (13 headers 20 lines) ---
Sending to 192.168.74.70:33059 (NAT)
Found RTP audio format 9
Found RTP audio format 101
Found audio description format G722 for ID 9
Found audio description format telephone-event for ID 101
Found RTP video format 118
Found video description format H264 for ID 118
[2016-12-02 22:50:26] WARNING[15710][C-00000011]: chan_sip.c:10712 process_sdp: Rejecting secure video stream without encryption details: video 58468 RTP/SAVP 118

<--- Reliably Transmitting (NAT) to 192.168.74.70:33059 --->
SIP/2.0 488 Not acceptable here
Via: SIP/2.0/TLS 192.168.74.70:33059;branch=z9hG4bK-524287-1---ecae9b3c03389e7f;received=192.168.74.70;rport=33059
From: <sip:[email protected]:5061;transport=TLS>;tag=037ff50e
To: <sip:[email protected]:5061;transport=TLS>;tag=as7be5cbbe
Call-ID: -1YlDayNRP8XGrf4hfJ47w..
CSeq: 3 INVITE
Server: FPBX-13.0.190.7(13.12.1)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
X-Asterisk-HangupCause: Normal Clearing
X-Asterisk-HangupCauseCode: 16
Content-Length: 0

<------------>

<--- SIP read from TLS:192.168.74.70:33059 --->
ACK sip:[email protected]:5061;transport=TLS SIP/2.0
Via: SIP/2.0/TLS 192.168.74.70:33059;branch=z9hG4bK-524287-1---ecae9b3c03389e7f;rport
Max-Forwards: 70
To: <sip:[email protected]:5061;transport=TLS>;tag=as7be5cbbe
From: <sip:[email protected]:5061;transport=TLS>;tag=037ff50e
Call-ID: -1YlDayNRP8XGrf4hfJ47w..
CSeq: 3 ACK
Content-Length: 0

<------------->
--- (8 headers 0 lines) ---
[2016-12-02 22:50:34] WARNING[15668][C-00000011]: chan_sip.c:10712 process_sdp: Rejecting secure video stream without encryption details: video 51380 RTP/SAVP 118
       > 0x7ff6f00a97b0 -- Probation passed - setting RTP source address to 192.168.74.20:51378
    -- Channel SIP/1013-00000021 left 'simple_bridge' basic-bridge <95c37ce6-f835-4d88-9bf2-3707c009fe7d>
    -- Channel SIP/1001-00000020 left 'simple_bridge' basic-bridge <95c37ce6-f835-4d88-9bf2-3707c009fe7d>
  == Spawn extension (macro-dial-one, s, 51) exited non-zero on 'SIP/1001-00000020' in macro 'dial-one'
  == Spawn extension (macro-exten-vm, s, 16) exited non-zero on 'SIP/1001-00000020' in macro 'exten-vm'
  == Spawn extension (ext-local, 1013, 2) exited non-zero on 'SIP/1001-00000020'
    -- Executing [h@ext-local:1] Macro("SIP/1001-00000020", "hangupcall,") in new stack
    -- Executing [s@macro-hangupcall:1] GotoIf("SIP/1001-00000020", "1?theend") in new stack
    -- Goto (macro-hangupcall,s,3)
    -- Executing [s@macro-hangupcall:3] ExecIf("SIP/1001-00000020", "0?Set(CDR(recordingfile)=)") in new stack
    -- Executing [s@macro-hangupcall:4] Hangup("SIP/1001-00000020", "") in new stack
  == Spawn extension (macro-hangupcall, s, 4) exited non-zero on 'SIP/1001-00000020' in macro 'hangupcall'
  == Spawn extension (ext-local, h, 1) exited non-zero on 'SIP/1001-00000020'
Scheduling destruction of SIP dialog '-1YlDayNRP8XGrf4hfJ47w..' in 6400 ms (Method: ACK)
Reliably Transmitting (NAT) to 192.168.74.70:33059:
BYE sip:[email protected]:33059;transport=TLS SIP/2.0
Via: SIP/2.0/TLS XXX.XXX.XXX.XXX:5061;branch=z9hG4bK0e48adc4;rport
Max-Forwards: 70
From: <sip:[email protected]:5061;transport=TLS>;tag=as7be5cbbe
To: <sip:[email protected]:5061;transport=TLS>;tag=037ff50e
Call-ID: -1YlDayNRP8XGrf4hfJ47w..
CSeq: 102 BYE
User-Agent: FPBX-13.0.190.7(13.12.1)
Proxy-Authorization: Digest username="1001", realm="asterisk", algorithm=MD5, uri="sips:xxxxxx.xxxxxxxxxxxxxx.com", nonce="365457f2", response="1fa1e19e9f438440011420796c3e23e7"
X-Asterisk-HangupCause: Normal Clearing
X-Asterisk-HangupCauseCode: 16
Content-Length: 0

---
  == MixMonitor close filestream (mixed)
  == End MixMonitor Recording SIP/1001-00000020

<--- SIP read from TLS:192.168.74.70:33059 --->
SIP/2.0 200 OK
Via: SIP/2.0/TLS XXX.XXX.XXX.XXX:5061;branch=z9hG4bK0e48adc4;rport=5061
Contact: <sip:[email protected]:33059;transport=TLS>
To: <sip:[email protected]:5061;transport=TLS>;tag=037ff50e
From: <sip:[email protected]:5061;transport=TLS>;tag=as7be5cbbe
Call-ID: -1YlDayNRP8XGrf4hfJ47w..
CSeq: 102 BYE
User-Agent: Zoiper rv2.8.15
Content-Length: 0

<------------->
--- (9 headers 0 lines) ---
SIP Response message for INCOMING dialog BYE arrived
Really destroying SIP dialog '-1YlDayNRP8XGrf4hfJ47w..' Method: ACK
[2016-12-02 22:50:41] NOTICE[3786]: chan_sip.c:15601 sip_reregister:    -- Re-registration for  [email protected]
[2016-12-02 22:50:41] NOTICE[3786]: chan_sip.c:24394 handle_response_register: Outbound Registration: Expiry for callcentric.com is 61 sec (Scheduling reregistration in 46 s)
Reliably Transmitting (NAT) to 192.168.74.70:33059:
OPTIONS sip:[email protected]:33059;transport=TLS;rinstance=631fc073f821dcc1 SIP/2.0
Via: SIP/2.0/TLS XXX.XXX.XXX.XXX:5061;branch=z9hG4bK43b29e68;rport
Max-Forwards: 70
From: "Unknown" <sip:[email protected]>;tag=as68d97055
To: <sip:[email protected]:33059;transport=TLS;rinstance=631fc073f821dcc1>
Contact: <sip:[email protected]:5061;transport=TLS>
Call-ID: [email protected]:5061
CSeq: 102 OPTIONS
User-Agent: FPBX-13.0.190.7(13.12.1)
Date: Sat, 03 Dec 2016 03:50:47 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Content-Length: 0

---

<--- SIP read from TLS:192.168.74.70:33059 --->

<------------->

<--- SIP read from TLS:192.168.74.70:33059 --->
SIP/2.0 200 OK
Via: SIP/2.0/TLS XXX.XXX.XXX.XXX:5061;branch=z9hG4bK43b29e68;rport=5061
Contact: <sip:192.168.74.70:50207;transport=tls>
To: <sip:[email protected]:33059;transport=TLS;rinstance=631fc073f821dcc1>;tag=9789696e
From: "Unknown" <sip:[email protected]>;tag=as68d97055
Call-ID: [email protected]:5061
CSeq: 102 OPTIONS
Accept: application/sdp, application/sdp
Accept-Language: en
Allow: INVITE, ACK, CANCEL, BYE, NOTIFY, REFER, MESSAGE, OPTIONS, INFO, SUBSCRIBE
Supported: replaces, norefersub, extended-refer, timer, outbound, path, X-cisco-serviceuri
User-Agent: Zoiper rv2.8.15
Allow-Events: presence, kpml, talk
Content-Length: 0

<------------->
--- (14 headers 0 lines) ---
Really destroying SIP dialog '[email protected]:5061' Method: OPTIONS

<--- SIP read from TLS:192.168.74.70:33059 --->

<------------->
[2016-12-02 22:51:27] NOTICE[3786]: chan_sip.c:15601 sip_reregister:    -- Re-registration for  [email protected]
[2016-12-02 22:51:27] NOTICE[3786]: chan_sip.c:24394 handle_response_register: Outbound Registration: Expiry for callcentric.com is 62 sec (Scheduling reregistration in 47 s)

<--- SIP read from TLS:192.168.74.70:33059 --->
REGISTER sip:xxxxxx.xxxxxxxxxxxxxx.com:5061;transport=TLS SIP/2.0
Via: SIP/2.0/TLS 192.168.74.70:33059;branch=z9hG4bK-524287-1---1d8c4174d398121c;rport
Max-Forwards: 70
Contact: <sip:[email protected]:33059;transport=TLS;rinstance=631fc073f821dcc1>
To: <sip:[email protected]:5061;transport=TLS>
From: <sip:[email protected]:5061;transport=TLS>;tag=35e23302
Call-ID: zwSDNpoCSsJIaWdWm5G2nw..
CSeq: 3 REGISTER
Expires: 120
User-Agent: Zoiper rv2.8.15
Authorization: Digest username="1001",realm="asterisk",nonce="0967e7da",uri="sip:xxxxxx.xxxxxxxxxxxxxx.com:5061;transport=TLS",response="c6ff5de5f41d3664989e15dcb11ea75c",algorithm=MD5
Allow-Events: presence, kpml, talk
Content-Length: 0

<------------->
--- (13 headers 0 lines) ---
Sending to 192.168.74.70:33059 (no NAT)
Sending to 192.168.74.70:33059 (no NAT)

<--- Transmitting (NAT) to 192.168.74.70:33059 --->
SIP/2.0 401 Unauthorized
Via: SIP/2.0/TLS 192.168.74.70:33059;branch=z9hG4bK-524287-1---1d8c4174d398121c;received=192.168.74.70;rport=33059
From: <sip:[email protected]:5061;transport=TLS>;tag=35e23302
To: <sip:[email protected]:5061;transport=TLS>;tag=as138d8377
Call-ID: zwSDNpoCSsJIaWdWm5G2nw..
CSeq: 3 REGISTER
Server: FPBX-13.0.190.7(13.12.1)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
WWW-Authenticate: Digest algorithm=MD5, realm="asterisk", nonce="5ad16cf7"
Content-Length: 0

<------------>
Scheduling destruction of SIP dialog 'zwSDNpoCSsJIaWdWm5G2nw..' in 32000 ms (Method: REGISTER)

<--- SIP read from TLS:192.168.74.70:33059 --->
REGISTER sip:xxxxxx.xxxxxxxxxxxxxx.com:5061;transport=TLS SIP/2.0
Via: SIP/2.0/TLS 192.168.74.70:33059;branch=z9hG4bK-524287-1---da70d72e76ff5664;rport
Max-Forwards: 70
Contact: <sip:[email protected]:33059;transport=TLS;rinstance=631fc073f821dcc1>
To: <sip:[email protected]:5061;transport=TLS>
From: <sip:[email protected]:5061;transport=TLS>;tag=35e23302
Call-ID: zwSDNpoCSsJIaWdWm5G2nw..
CSeq: 4 REGISTER
Expires: 120
User-Agent: Zoiper rv2.8.15
Authorization: Digest username="1001",realm="asterisk",nonce="5ad16cf7",uri="sip:xxxxxx.xxxxxxxxxxxxxx.com:5061;transport=TLS",response="68971aeed0081000c50af32727a5707e",algorithm=MD5
Allow-Events: presence, kpml, talk
Content-Length: 0

<------------->
--- (13 headers 0 lines) ---
Sending to 192.168.74.70:33059 (NAT)
Reliably Transmitting (NAT) to 192.168.74.70:33059:
OPTIONS sip:[email protected]:33059;transport=TLS;rinstance=631fc073f821dcc1 SIP/2.0
Via: SIP/2.0/TLS XXX.XXX.XXX.XXX:5061;branch=z9hG4bK26caeef9;rport
Max-Forwards: 70
From: "Unknown" <sip:[email protected]>;tag=as6835358a
To: <sip:[email protected]:33059;transport=TLS;rinstance=631fc073f821dcc1>
Contact: <sip:[email protected]:5061;transport=TLS>
Call-ID: [email protected]:5061
CSeq: 102 OPTIONS
User-Agent: FPBX-13.0.190.7(13.12.1)
Date: Sat, 03 Dec 2016 03:51:35 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Content-Length: 0

---

<--- Transmitting (NAT) to 192.168.74.70:33059 --->
SIP/2.0 200 OK
Via: SIP/2.0/TLS 192.168.74.70:33059;branch=z9hG4bK-524287-1---da70d72e76ff5664;received=192.168.74.70;rport=33059
From: <sip:[email protected]:5061;transport=TLS>;tag=35e23302
To: <sip:[email protected]:5061;transport=TLS>;tag=as138d8377
Call-ID: zwSDNpoCSsJIaWdWm5G2nw..
CSeq: 4 REGISTER
Server: FPBX-13.0.190.7(13.12.1)
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Expires: 120
Contact: <sip:[email protected]:33059;transport=TLS;rinstance=631fc073f821dcc1>;expires=120
Date: Sat, 03 Dec 2016 03:51:35 GMT
Content-Length: 0

<------------>
Scheduling destruction of SIP dialog '[email protected]:5061' in 6400 ms (Method: NOTIFY)
Reliably Transmitting (NAT) to 192.168.74.70:33059:
NOTIFY sip:[email protected]:33059;transport=TLS;rinstance=631fc073f821dcc1 SIP/2.0
Via: SIP/2.0/TLS XXX.XXX.XXX.XXX:5061;branch=z9hG4bK41c4db96;rport
Max-Forwards: 70
From: "Unknown" <sip:[email protected]>;tag=as5ea47839
To: <sip:[email protected]:33059;transport=TLS;rinstance=631fc073f821dcc1>
Contact: <sip:[email protected]:5061;transport=TLS>
Call-ID: [email protected]:5061
CSeq: 102 NOTIFY
User-Agent: FPBX-13.0.190.7(13.12.1)
Event: message-summary
Content-Type: application/simple-message-summary
Content-Length: 104

Messages-Waiting: yes
Message-Account: sip:*[email protected];transport=TLS
Voice-Message: 4/0 (0/0)

---
Scheduling destruction of SIP dialog 'zwSDNpoCSsJIaWdWm5G2nw..' in 32000 ms (Method: REGISTER)

<--- SIP read from TLS:192.168.74.70:33059 --->
SIP/2.0 200 OK
Via: SIP/2.0/TLS XXX.XXX.XXX.XXX:5061;branch=z9hG4bK26caeef9;rport=5061
Contact: <sip:192.168.74.70:50207;transport=tls>
To: <sip:[email protected]:33059;transport=TLS;rinstance=631fc073f821dcc1>;tag=bdf7276a
From: "Unknown" <sip:[email protected]>;tag=as6835358a
Call-ID: [email protected]:5061
CSeq: 102 OPTIONS
Accept: application/sdp, application/sdp
Accept-Language: en
Allow: INVITE, ACK, CANCEL, BYE, NOTIFY, REFER, MESSAGE, OPTIONS, INFO, SUBSCRIBE
Supported: replaces, norefersub, extended-refer, timer, outbound, path, X-cisco-serviceuri
User-Agent: Zoiper rv2.8.15
Allow-Events: presence, kpml, talk
Content-Length: 0

<------------->
--- (14 headers 0 lines) ---

<--- SIP read from TLS:192.168.74.70:33059 --->
SIP/2.0 200 OK
Via: SIP/2.0/TLS XXX.XXX.XXX.XXX:5061;branch=z9hG4bK41c4db96;rport=5061
Contact: <sip:192.168.74.70:50207;transport=tls>
To: <sip:[email protected]:33059;transport=TLS;rinstance=631fc073f821dcc1>;tag=a93b4676
From: "Unknown" <sip:[email protected]>;tag=as5ea47839
Call-ID: [email protected]:5061
CSeq: 102 NOTIFY
User-Agent: Zoiper rv2.8.15
Content-Length: 0

<------------->
--- (9 headers 0 lines) ---
Really destroying SIP dialog '[email protected]:5061' Method: OPTIONS
Really destroying SIP dialog '[email protected]:5061' Method: NOTIFY
[2016-12-02 22:51:57] NOTICE[3786]: chan_sip.c:15601 sip_reregister:    -- Re-registration for  [email protected]
[2016-12-02 22:51:57] NOTICE[3786]: chan_sip.c:24394 handle_response_register: Outbound Registration: Expiry for toronto4.voip.ms is 120 sec (Scheduling reregistration in 105 s)
Really destroying SIP dialog 'zwSDNpoCSsJIaWdWm5G2nw..' Method: REGISTER

<--- SIP read from TLS:192.168.74.70:33059 --->

<------------->
[2016-12-02 22:52:14] NOTICE[3786]: chan_sip.c:15601 sip_reregister:    -- Re-registration for  [email protected]
[2016-12-02 22:52:14] NOTICE[3786]: chan_sip.c:24394 handle_response_register: Outbound Registration: Expiry for callcentric.com is 63 sec (Scheduling reregistration in 48 s)
Reliably Transmitting (NAT) to 192.168.74.70:33059:
OPTIONS sip:[email protected]:33059;transport=TLS;rinstance=631fc073f821dcc1 SIP/2.0
Via: SIP/2.0/TLS XXX.XXX.XXX.XXX:5061;branch=z9hG4bK41929880;rport
Max-Forwards: 70
From: "Unknown" <sip:[email protected]>;tag=as525ea883
To: <sip:[email protected]:33059;transport=TLS;rinstance=631fc073f821dcc1>
Contact: <sip:[email protected]:5061;transport=TLS>
Call-ID: [email protected]:5061
CSeq: 102 OPTIONS
User-Agent: FPBX-13.0.190.7(13.12.1)
Date: Sat, 03 Dec 2016 03:52:35 GMT
Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH, MESSAGE
Supported: replaces, timer
Content-Length: 0

---

<--- SIP read from TLS:192.168.74.70:33059 --->
SIP/2.0 200 OK
Via: SIP/2.0/TLS XXX.XXX.XXX.XXX:5061;branch=z9hG4bK41929880;rport=5061
Contact: <sip:192.168.74.70:50207;transport=tls>
To: <sip:[email protected]:33059;transport=TLS;rinstance=631fc073f821dcc1>;tag=dee5133b
From: "Unknown" <sip:[email protected]>;tag=as525ea883
Call-ID: [email protected]:5061
CSeq: 102 OPTIONS
Accept: application/sdp, application/sdp
Accept-Language: en
Allow: INVITE, ACK, CANCEL, BYE, NOTIFY, REFER, MESSAGE, OPTIONS, INFO, SUBSCRIBE
Supported: replaces, norefersub, extended-refer, timer, outbound, path, X-cisco-serviceuri
User-Agent: Zoiper rv2.8.15
Allow-Events: presence, kpml, talk
Content-Length: 0

<------------->
--- (14 headers 0 lines) ---
Really destroying SIP dialog '[email protected]:5061' Method: OPTIONS

<--- SIP read from TLS:192.168.74.70:33059 --->

<------------->

billsimon · December 3, 2016, 7:08pm

It looks like everything is there. I would open a bug ticket with Asterisk on this issue.