When I am trying to diagnose a call problem I can generally tell which dialplans are in use by looking at the regex pass/fail logs. But when I send a fax using the web interface the logs do not show any regex tests. It is almost like the fax server is not using any dialplan and going directly to the gateway. Does this make sense?
Outbound fax gives no dialplan info in the logs
- Thread starter grandpa_sam
- Start date
You are using an out of date browser. It may not display this or other websites correctly.
You should upgrade or use an alternative browser.
You should upgrade or use an alternative browser.
- Status
- Not open for further replies.
I figured out that the outbound route is not necessarily being ignored its just the actions inside the dial plan are. It is able to bridge to the gateway but the secure media export is not being applied. Here is the logs I am seeing when I try to send a fax:
Code:
tport.c:2770 tport_wakeup_pri() tport_wakeup_pri(0x7f1048004e90): events IN
tport.c:2893 tport_recv_event() tport_recv_event(0x7f1048004e90)
tport.c:3234 tport_recv_iovec() tport_recv_iovec(0x7f1048004e90) msg 0x7f1048041b60 from (udp/192.168.1.154:5060) has 2 bytes, veclen = 1
tport.c:3052 tport_deliver() tport_deliver(0x7f1048004e90): bad msg 0x7f1048041b60 (2 bytes) from udp/192.168.1.1:5060/sip next=(nil)
2021-04-20 11:49:46.801622 [DEBUG] switch_ivr_originate.c:2242 Parsing global variables
2021-04-20 11:49:46.801622 [NOTICE] switch_channel.c:1118 New Channel sofia/external/+150XXXXXXXX [4c7b587d-ce16-4137-9841-dbe6aa7a8dba]
2021-04-20 11:49:46.801622 [DEBUG] mod_sofia.c:5089 (sofia/external/+150XXXXXXXX) State Change CS_NEW -> CS_INIT
2021-04-20 11:49:46.801622 [DEBUG] switch_core_state_machine.c:585 (sofia/external/+150XXXXXXXX) Running State Change CS_INIT (Cur 1 Tot 87)
2021-04-20 11:49:46.801622 [DEBUG] switch_core_state_machine.c:628 (sofia/external/+150XXXXXXXX) State INIT
2021-04-20 11:49:46.801622 [DEBUG] mod_sofia.c:93 sofia/external/+150XXXXXXXX SOFIA INIT
nua_common.c:108 nh_create_handle() nua: nh_create_handle: entering
nua.c:346 nua_handle_bind() nua: nua_handle_bind: entering
2021-04-20 11:49:46.801622 [DEBUG] sofia_glue.c:1618 sofia/external/+150XXXXXXXX sending invite version: 1.10.5 -release-17-25569c1631 64bit
Local SDP:
v=0
o=FreeSWITCH 1618918270 1618918271 IN IP4 70.50.150.80
s=FreeSWITCH
c=IN IP4 70.50.150.80
t=0 0
m=audio 26316 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
nua.c:637 nua_invite() nua: nua_invite: entering
nua_stack.c:529 nua_signal() nua(0x7f10540259c0): sent signal r_invite
2021-04-20 11:49:46.801622 [DEBUG] switch_core_state_machine.c:40 sofia/external/+150XXXXXXXX Standard INIT
2021-04-20 11:49:46.801622 [DEBUG] switch_core_state_machine.c:48 (sofia/external/+150XXXXXXXX) State Change CS_INIT -> CS_ROUTING
2021-04-20 11:49:46.801622 [DEBUG] switch_core_state_machine.c:628 (sofia/external/+150XXXXXXXX) State INIT going to sleep
nua_stack.c:569 nua_stack_signal() nua(0x7f10540259c0): recv signal r_invite
nua_params.c:484 nua_stack_set_params() nua: nua_stack_set_params: entering
soa.c:280 soa_clone() soa_clone(static::0x7f1054001b90, 0x7f1054001390, 0x7f10540259c0) called
soa.c:403 soa_set_params() soa_set_params(static::0x7f1054069170, ...) called
soa.c:403 soa_set_params() soa_set_params(static::0x7f1054069170, ...) called
soa.c:1052 soa_set_user_sdp() soa_set_user_sdp(static::0x7f1054069170, (nil), 0x7f105404783b, -1) called
soa.c:890 soa_set_capability_sdp() soa_set_capability_sdp(static::0x7f1054069170, (nil), 0x7f105404783b, -1) called
2021-04-20 11:49:46.801622 [DEBUG] switch_core_state_machine.c:585 (sofia/external/+150XXXXXXXX) Running State Change CS_ROUTING (Cur 1 Tot 87)
nua_dialog.c:338 nua_dialog_usage_add() nua(0x7f10540259c0): adding session usage
nta.c:4446 nta_leg_tcreate() nta_leg_tcreate(0x7f1054019a80)
2021-04-20 11:49:46.801622 [DEBUG] switch_core_state_machine.c:644 (sofia/external/+150XXXXXXXX) State ROUTING
soa.c:1302 soa_init_offer_answer() soa_init_offer_answer(static::0x7f1054069170) called
soa.c:1426 soa_generate_offer() soa_generate_offer(static::0x7f1054069170, 0) called
2021-04-20 11:49:46.801622 [DEBUG] mod_sofia.c:154 sofia/external/+150XXXXXXXX SOFIA ROUTING
2021-04-20 11:49:46.801622 [DEBUG] switch_ivr_originate.c:67 (sofia/external/+150XXXXXXXX) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2021-04-20 11:49:46.801622 [DEBUG] switch_core_state_machine.c:644 (sofia/external/+150XXXXXXXX) State ROUTING going to sleep
soa_static.c:1148 offer_answer_step() soa_static_offer_answer_action(0x7f1054069170, soa_generate_offer): called
soa_static.c:1189 offer_answer_step() soa_static(0x7f1054069170, soa_generate_offer): generating local description
soa_static.c:1217 offer_answer_step() soa_static(0x7f1054069170, soa_generate_offer): upgrade with local description
2021-04-20 11:49:46.801622 [DEBUG] switch_core_state_machine.c:585 (sofia/external/+150XXXXXXXX) Running State Change CS_CONSUME_MEDIA (Cur 1 Tot 87)
soa_static.c:1029 soa_sdp_mode_set() soa_sdp_mode_set(0x7f107d626820, (nil), ""): called
soa_static.c:1446 offer_answer_step() soa_static(0x7f1054069170, soa_generate_offer): storing local description
soa.c:1270 soa_get_local_sdp() soa_get_local_sdp(static::0x7f1054069170, [(nil)], [0x7f107d6289a0], [0x7f107d62899c]) called
nta.c:2694 nta_tpn_by_url() nta: selecting scheme sip
2021-04-20 11:49:46.801622 [DEBUG] switch_core_state_machine.c:663 (sofia/external/+150XXXXXXXX) State CONSUME_MEDIA
sres_cache.c:272 sres_cache_get() sres_cache_get(0x7f10540044b0, SRV, "_sips._tcp.pbx.pstn.twilio.com.") called
2021-04-20 11:49:46.801622 [DEBUG] switch_core_state_machine.c:663 (sofia/external/+150XXXXXXXX) State CONSUME_MEDIA going to sleep
nta.c:10683 outgoing_query_srv() nta: for "pbx.pstn.twilio.com" query "_sips._tcp.pbx.pstn.twilio.com" SRV
sres.c:968 sres_query() sres_query(0x7f10540041d0, 0x7f1054046d00, SRV, "_sips._tcp.pbx.pstn.twilio.com") called
sres.c:2731 sres_send_dns_query() sres_send_dns_query(0x7f10540041d0, 0x7f1054065810) called
sres.c:2820 sres_send_dns_query() sres_send_dns_query(0x7f10540041d0, 0x7f1054065810) id=25929 SRV _sips._tcp.pbx.pstn.twilio.com (to [192.168.1.1]:53)
nua_session.c:4140 signal_call_state_change() nua(0x7f10540259c0): call state changed: init -> calling, sent offer
soa.c:1270 soa_get_local_sdp() soa_get_local_sdp(static::0x7f1054069170, [0x7f107d628980], [0x7f107d628988], [(nil)]) called
nua_stack.c:269 nua_stack_event() nua(0x7f10540259c0): event i_state INVITE sent
nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
nua.c:370 nua_handle_magic() nua: nua_handle_magic: entering
2021-04-20 11:49:46.801622 [DEBUG] sofia.c:7326 Channel sofia/external/+150XXXXXXXX entering state [calling][0]
nua.c:370 nua_handle_magic() nua: nua_handle_magic: entering
sres.c:3468 sres_resolver_receive() sres_resolver_receive(0x7f10540041d0, 84) called
sres.c:3782 sres_create_record() AUTHORITY RR received twilio.com. SOA IN 180 rdlen=44
sres.c:3573 sres_log_response() sres_resolver_receive(0x7f10540041d0, 0x7f1054065810) id=25929 (from [192.168.1.1]:53)
sres.c:2988 sres_query_report_error() sres(q=0x7f1054065810): reporting error RECORD_ERR for SRV _sips._tcp.pbx.pstn.twilio.com
sres_cache.c:272 sres_cache_get() sres_cache_get(0x7f10540044b0, A, "pbx.pstn.twilio.com.") called
nta.c:10891 outgoing_query_a() nta: for "pbx.pstn.twilio.com" query "pbx.pstn.twilio.com" A
sres.c:968 sres_query() sres_query(0x7f10540041d0, 0x7f1054046d00, A, "pbx.pstn.twilio.com") called
sres.c:2731 sres_send_dns_query() sres_send_dns_query(0x7f10540041d0, 0x7f10540b2870) called
sres.c:2820 sres_send_dns_query() sres_send_dns_query(0x7f10540041d0, 0x7f10540b2870) id=25930 A pbx.pstn.twilio.com (to [192.168.1.1]:53)
sres.c:3468 sres_resolver_receive() sres_resolver_receive(0x7f10540041d0, 84) called
sres.c:3782 sres_create_record() ANSWER RR received pbx.pstn.twilio.com. A IN 600 rdlen=4
sres.c:3782 sres_create_record() ANSWER RR received pbx.pstn.twilio.com. A IN 600 rdlen=4
sres.c:3782 sres_create_record() ANSWER RR received pbx.pstn.twilio.com. A IN 600 rdlen=4
sres.c:3782 sres_create_record() ANSWER RR received pbx.pstn.twilio.com. A IN 600 rdlen=4
sres.c:3573 sres_log_response() sres_resolver_receive(0x7f10540041d0, 0x7f10540b2870) id=25930 (from [192.168.1.1]:53)
nta.c:10944 outgoing_answer_a() nta: pbx.pstn.twilio.com. IN A 54.172.60.0
nta.c:10946 outgoing_answer_a() nta(0x7f1054046d00): A 54.172.60.1
nta.c:10946 outgoing_answer_a() nta(0x7f1054046d00): A 54.172.60.2
nta.c:10946 outgoing_answer_a() nta(0x7f1054046d00): A 54.172.60.3
tport.c:3286 tport_tsend() tport_tsend(0x7f1054006d10) tpn = tls/54.172.60.0:5061
tport.c:4075 tport_resolve() tport_resolve addrinfo = 54.172.60.0:5061
tport.c:4709 tport_by_addrinfo() tport_by_addrinfo(0x7f1054006d10): not found by name tls/54.172.60.0:5061
tport.c:862 tport_alloc_secondary() tport_alloc_secondary(0x7f1054006d10): new secondary tport 0x7f105404bd30
tport_type_tcp.c:203 tport_tcp_init_secondary() tport_tcp_init_secondary(0x7f105404bd30): Setting TCP_KEEPIDLE to 30
tport_type_tcp.c:209 tport_tcp_init_secondary() tport_tcp_init_secondary(0x7f105404bd30): Setting TCP_KEEPINTVL to 30
tport_type_tls.c:686 tport_tls_connect() tport_tls_connect(0x7f105404bd30): connecting to tls/54.172.60.0:5061/sips
tport.c:2311 tport_set_secondary_timer() tport(0x7f105404bd30): reset timer
tport.c:3811 tport_queue() tport_queue(0x7f105404bd30): queueing 0x7f1054066cd0 for tls/54.172.60.0:5061
nta.c:8348 outgoing_send() nta: sent INVITE (34918502) to tls/54.172.60.0:5061
tport.c:4189 tport_pend() tport_pend(0x7f105404bd30): pending 0x7f1054066cd0 for tls/54.172.60.0:5061 (already 0)
nta.c:1354 set_timeout() nta: timer set to 32000 ms
tport_tls.c:960 tls_connect() tls_connect(0x7f105404bd30): events CONNECTING
tport_tls.c:960 tls_connect() tls_connect(0x7f105404bd30): events NEGOTIATING
tport_tls.c:960 tls_connect() tls_connect(0x7f105404bd30): events NEGOTIATING
tport_tls.c:603 tls_post_connection_check() tls_post_connection_check(0x7f105404bd30): TLS cipher chosen (name): ECDHE-RSA-AES128-GCM-SHA256
tport_tls.c:605 tls_post_connection_check() tls_post_connection_check(0x7f105404bd30): TLS cipher chosen (version): TLSv1.2
tport_tls.c:608 tls_post_connection_check() tls_post_connection_check(0x7f105404bd30): TLS cipher chosen (bits/alg_bits): 128/128
tport_tls.c:611 tls_post_connection_check() tls_post_connection_check(0x7f105404bd30): TLS cipher chosen (description): ECDHE-RSA-AES128-GCM-SHA256 TLSv1.2 Kx=ECDH Au=RSA Enc=AESGCM(128) Mac=AEAD
tport_tls.c:698 tls_post_connection_check() tls_post_connection_check(0x7f105404bd30): Peer Certificate Subject 0: *.pstn.twilio.com
tport_tls.c:698 tls_post_connection_check() tls_post_connection_check(0x7f105404bd30): Peer Certificate Subject 1: *.sip.twilio.com
tport_tls.c:698 tls_post_connection_check() tls_post_connection_check(0x7f105404bd30): Peer Certificate Subject 2: *.pstn.us1.twilio.com
tport_tls.c:698 tls_post_connection_check() tls_post_connection_check(0x7f105404bd30): Peer Certificate Subject 3: *.sip.us1.twilio.com
tport.c:3952 tport_send_event() tport_send_event(0x7f105404bd30) - ready to send to (tls/54.172.60.0:5061)
tport_type_tls.c:537 tport_tls_send() tport_tls_writevec: vec 0x7f1054029410 0x7f105405d5e0 874 (874)
tport_type_tls.c:537 tport_tls_send() tport_tls_writevec: vec 0x7f1054029410 0x7f1054053e30 271 (271)
tport.c:3623 tport_vsend() tport_vsend(0x7f105404bd30): 1145 bytes of 1145 to tls/54.172.60.0:5061
tport.c:3521 tport_send_msg() tport_vsend returned 1145
send 1145 bytes to tls/[54.172.60.0]:5061 at 11:49:49.408095:
------------------------------------------------------------------------
INVITE sip:+150XXXXXXXX@pbx.pstn.twilio.com;transport=tls SIP/2.0
Via: SIP/2.0/TLS 70.50.150.80:5081;rport;branch=z9hG4bKBgHyDm9QK8NyH
Max-Forwards: 70
From: <sip:36XXXXXXXX@70.50.150.80>;tag=yecr2v4K79Brg
To: <sip:+150XXXXXXXX@pbx.pstn.twilio.com>
Call-ID: 0651de59-1cac-123a-ca8b-a41f7259508a
CSeq: 34918502 INVITE
Contact: <sip:gw+f0079869-728a-4d02-8e24-41bed917685a@70.50.150.80:5081;transport=tls;transport=tls;gw=f0079869-728a-4d02-8e24-41bed917685a>
User-Agent: FreeSWITCH
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY
Supported: timer, path, replaces
Allow-Events: talk, hold, conference, refer
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 271
X-FS-Support: update_display,send_info
Remote-Party-ID: <sip:36XXXXXXXX@70.50.150.80>;party=calling;screen=yes;privacy=off
v=0
o=FreeSWITCH 1618918270 1618918271 IN IP4 70.50.150.80
s=FreeSWITCH
c=IN IP4 70.50.150.80
t=0 0
m=audio 26316 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
tport_type_tls.c:338 tport_tls_set_events() tport_tls_set_events(0x7f105404bd30): logical events IN real IN
tport.c:2311 tport_set_secondary_timer() tport(0x7f105404bd30): reset timer
tport.c:2795 tport_wakeup() tport_wakeup(0x7f105404bd30): events IN
tport.c:2893 tport_recv_event() tport_recv_event(0x7f105404bd30)
tport_type_tls.c:434 tport_tls_recv() tport_tls_recv(0x7f105404bd30): tls_read() returned 367
tport.c:3234 tport_recv_iovec() tport_recv_iovec(0x7f105404bd30) msg 0x7f1054048950 from (tls/54.172.60.0:5061) has 367 bytes, veclen = 1
recv 367 bytes from tls/[54.172.60.0]:5061 at 11:49:49.501913:
------------------------------------------------------------------------
SIP/2.0 100 trying -- your call is important to us
Via: SIP/2.0/TLS 70.50.150.80:5081;rport=60637;branch=z9hG4bKBgHyDm9QK8NyH;received=70.50.150.80
From: <sip:36XXXXXXXX@70.50.150.80>;tag=yecr2v4K79Brg
To: <sip:+150XXXXXXXX@pbx.pstn.twilio.com>
Call-ID: 0651de59-1cac-123a-ca8b-a41f7259508a
CSeq: 34918502 INVITE
Server: Twilio Gateway
Content-Length: 0
tport.c:3052 tport_deliver() tport_deliver(0x7f105404bd30): msg 0x7f1054048950 (367 bytes) from tls/54.172.60.0:5061/sips next=(nil)
nta.c:3328 agent_recv_response() nta: received 100 trying -- your call is important to us for INVITE (34918502)
nta.c:3395 agent_recv_response() nta: 100 trying -- your call is important to us is going to a transaction
nta.c:9642 outgoing_estimate_delay() nta_outgoing: RTT is 366.405 ms
tport.c:4251 tport_release() tport_release(0x7f105404bd30): 0x7f1054066cd0 by 0x7f1054046d00 with 0x7f1054048950 (preliminary)
tport.c:2311 tport_set_secondary_timer() tport(0x7f105404bd30): reset timer
tport.c:2795 tport_wakeup() tport_wakeup(0x7f105404bd30): events IN
tport.c:2893 tport_recv_event() tport_recv_event(0x7f105404bd30)
tport_type_tls.c:434 tport_tls_recv() tport_tls_recv(0x7f105404bd30): tls_read() returned 603
tport.c:3234 tport_recv_iovec() tport_recv_iovec(0x7f105404bd30) msg 0x7f1054024ff0 from (tls/54.172.60.0:5061) has 603 bytes, veclen = 1
recv 603 bytes from tls/[54.172.60.0]:5061 at 11:49:49.510719:
------------------------------------------------------------------------
SIP/2.0 407 Proxy Authentication required
CSeq: 34918502 INVITE
Call-ID: 0651de59-1cac-123a-ca8b-a41f7259508a
From: <sip:36XXXXXXXX@70.50.150.80>;tag=yecr2v4K79Brg
To: <sip:+150XXXXXXXX@pbx.pstn.twilio.com>;tag=36445672_6772d868_d6dde871-19bd-4d08-9a9f-5ab87e65e20e
Via: SIP/2.0/TLS 70.50.150.80:5081;received=70.50.150.80;rport=60637;branch=z9hG4bKBgHyDm9QK8NyH
Server: Twilio
Contact: <sip:172.25.80.6:5060>
Proxy-Authenticate: Digest realm="sip.twilio.com",qop="auth",nonce="hhjbzv19RkLruSlgYhI-S4fmG69Y8OA1HqIykPVCnXxsRSbx",opaque="782c8f33f68f63a535910c20cbd8baef"
Content-Length: 0
tport.c:3052 tport_deliver() tport_deliver(0x7f105404bd30): msg 0x7f1054024ff0 (603 bytes) from tls/54.172.60.0:5061/sips next=(nil)
nta.c:3328 agent_recv_response() nta: received 407 Proxy Authentication required for INVITE (34918502)
nta.c:3395 agent_recv_response() nta: 407 Proxy Authentication required is going to a transaction
tport.c:4251 tport_release() tport_release(0x7f105404bd30): 0x7f1054066cd0 by 0x7f1054046d00 with 0x7f1054024ff0
tport.c:4617 tport_by_name() tport(0x7f1054006d10): found 0x7f105404bd30 by name tls/54.172.60.0:5061
tport.c:3286 tport_tsend() tport_tsend(0x7f105404bd30) tpn = tls/54.172.60.0:5061
tport_type_tls.c:537 tport_tls_send() tport_tls_writevec: vec 0x7f1054029410 0x7f105404aff0 404 (404)
tport.c:3623 tport_vsend() tport_vsend(0x7f105404bd30): 404 bytes of 404 to tls/54.172.60.0:5061
tport.c:3521 tport_send_msg() tport_vsend returned 404
send 404 bytes to tls/[54.172.60.0]:5061 at 11:49:49.510835:
------------------------------------------------------------------------
ACK sip:+150XXXXXXXX@pbx.pstn.twilio.com;transport=tls SIP/2.0
Via: SIP/2.0/TLS 70.50.150.80:5081;rport;branch=z9hG4bKBgHyDm9QK8NyH
Max-Forwards: 70
From: <sip:36XXXXXXXX@70.50.150.80>;tag=yecr2v4K79Brg
To: <sip:+150XXXXXXXX@pbx.pstn.twilio.com>;tag=36445672_6772d868_d6dde871-19bd-4d08-9a9f-5ab87e65e20e
Call-ID: 0651de59-1cac-123a-ca8b-a41f7259508a
CSeq: 34918502 ACK
Content-Length: 0
tport.c:2311 tport_set_secondary_timer() tport(0x7f105404bd30): reset timer
nta.c:8348 outgoing_send() nta: sent ACK (34918502) to tls/54.172.60.0:5061
nta.c:8774 outgoing_free() nta: outgoing_free(0x7f1054046980)
auth_digest.c:105 auth_digest_challenge_get() auth_digest_challenge_get(): got 5
nua_stack.c:271 nua_stack_event() nua(0x7f10540259c0): event r_invite 407 Proxy Authentication required
tport.c:2311 tport_set_secondary_timer() tport(0x7f105404bd30): reset timer
nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
nua.c:370 nua_handle_magic() nua: nua_handle_magic: entering
nua.c:838 nua_authenticate() nua: nua_authenticate: entering
nua_stack.c:569 nua_stack_signal() nua(0x7f10540259c0): recv signal r_authenticate
nua_stack.c:529 nua_signal() nua(0x7f10540259c0): sent signal r_authenticate
nua.c:370 nua_handle_magic() nua: nua_handle_magic: entering
soa.c:1302 soa_init_offer_answer() soa_init_offer_answer(static::0x7f1054069170) called
soa.c:1426 soa_generate_offer() soa_generate_offer(static::0x7f1054069170, 0) called
soa_static.c:1148 offer_answer_step() soa_static_offer_answer_action(0x7f1054069170, soa_generate_offer): called
soa_static.c:1029 soa_sdp_mode_set() soa_sdp_mode_set(0x7f10380076a0, (nil), ""): called
soa.c:1270 soa_get_local_sdp() soa_get_local_sdp(static::0x7f1054069170, [(nil)], [0x7f107d6289e0], [0x7f107d6289dc]) called
auth_digest.c:226 auth_digest_a1() auth_digest_a1() has A1 = MD5(authUser:sip.twilio.com:pass) = c7a8d2e983c8cba15f50a83463d9106a
auth_digest.c:318 auth_digest_response() A2 = MD5(INVITE:sip:+150XXXXXXXX@pbx.pstn.twilio.com;transport=tls)
auth_digest.c:348 auth_digest_response() auth_response: 66a58ddcdb377df9196f0ac44d407c5a = MD5(c7a8d2e983c8cba15f50a83463d9106a:hhjbzv19RkLruSlgYhI-S4fmG69Y8OA1HqIykPVCnXxsRSbx:00000001:Bo+61RysEjqLyqQfcllQig:auth:ae4172f103f8b421e4cf875140333c91) (qop=auth)
nta.c:2694 nta_tpn_by_url() nta: selecting scheme sip
sres_cache.c:272 sres_cache_get() sres_cache_get(0x7f10540044b0, SRV, "_sips._tcp.pbx.pstn.twilio.com.") called
sres_cache.c:318 sres_cache_get() sres_cache_get(0x7f10540044b0, SRV, "_sips._tcp.pbx.pstn.twilio.com.") returned 1 entries
nta.c:10683 outgoing_query_srv() nta: for "pbx.pstn.twilio.com" query "_sips._tcp.pbx.pstn.twilio.com" SRV (cached)
sres_cache.c:272 sres_cache_get() sres_cache_get(0x7f10540044b0, A, "pbx.pstn.twilio.com.") called
sres_cache.c:318 sres_cache_get() sres_cache_get(0x7f10540044b0, A, "pbx.pstn.twilio.com.") returned 4 entries
nta.c:10891 outgoing_query_a() nta: for "pbx.pstn.twilio.com" query "pbx.pstn.twilio.com" A (cached)
nta.c:10944 outgoing_answer_a() nta: pbx.pstn.twilio.com. IN A 54.172.60.1
nta.c:10946 outgoing_answer_a() nta(0x7f1054029650): A 54.172.60.2
nta.c:10946 outgoing_answer_a() nta(0x7f1054029650): A 54.172.60.3
nta.c:10946 outgoing_answer_a() nta(0x7f1054029650): A 54.172.60.0
tport.c:3286 tport_tsend() tport_tsend(0x7f1054006d10) tpn = tls/54.172.60.1:5061
tport.c:4075 tport_resolve() tport_resolve addrinfo = 54.172.60.1:5061
tport.c:4709 tport_by_addrinfo() tport_by_addrinfo(0x7f1054006d10): not found by name tls/54.172.60.1:5061
tport.c:862 tport_alloc_secondary() tport_alloc_secondary(0x7f1054006d10): new secondary tport 0x7f10540388a0
tport_type_tcp.c:203 tport_tcp_init_secondary() tport_tcp_init_secondary(0x7f10540388a0): Setting TCP_KEEPIDLE to 30
tport_type_tcp.c:209 tport_tcp_init_secondary() tport_tcp_init_secondary(0x7f10540388a0): Setting TCP_KEEPINTVL to 30
tport_type_tls.c:686 tport_tls_connect() tport_tls_connect(0x7f10540388a0): connecting to tls/54.172.60.1:5061/sips
tport.c:2311 tport_set_secondary_timer() tport(0x7f10540388a0): reset timer
tport.c:3811 tport_queue() tport_queue(0x7f10540388a0): queueing 0x7f1054048950 for tls/54.172.60.1:5061
nta.c:8348 outgoing_send() nta: sent INVITE (34918503) to tls/54.172.60.1:5061
tport.c:4189 tport_pend() tport_pend(0x7f10540388a0): pending 0x7f1054048950 for tls/54.172.60.1:5061 (already 0)
nua_session.c:4140 signal_call_state_change() nua(0x7f10540259c0): call state changed: calling -> calling, sent offer
soa.c:1270 soa_get_local_sdp() soa_get_local_sdp(static::0x7f1054069170, [0x7f107d6289c0], [0x7f107d6289c8], [(nil)]) called
nua_stack.c:269 nua_stack_event() nua(0x7f10540259c0): event i_state INVITE sent
nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
nua.c:370 nua_handle_magic() nua: nua_handle_magic: entering
2021-04-20 11:49:47.221614 [DEBUG] sofia.c:7326 Channel sofia/external/+150XXXXXXXX entering state [calling][0]
nua.c:370 nua_handle_magic() nua: nua_handle_magic: entering
tport_tls.c:960 tls_connect() tls_connect(0x7f10540388a0): events CONNECTING
tport_tls.c:960 tls_connect() tls_connect(0x7f10540388a0): events NEGOTIATING
tport_tls.c:960 tls_connect() tls_connect(0x7f10540388a0): events NEGOTIATING
tport_tls.c:603 tls_post_connection_check() tls_post_connection_check(0x7f10540388a0): TLS cipher chosen (name): ECDHE-RSA-AES128-GCM-SHA256
tport_tls.c:605 tls_post_connection_check() tls_post_connection_check(0x7f10540388a0): TLS cipher chosen (version): TLSv1.2
tport_tls.c:608 tls_post_connection_check() tls_post_connection_check(0x7f10540388a0): TLS cipher chosen (bits/alg_bits): 128/128
tport_tls.c:611 tls_post_connection_check() tls_post_connection_check(0x7f10540388a0): TLS cipher chosen (description): ECDHE-RSA-AES128-GCM-SHA256 TLSv1.2 Kx=ECDH Au=RSA Enc=AESGCM(128) Mac=AEAD
tport_tls.c:698 tls_post_connection_check() tls_post_connection_check(0x7f10540388a0): Peer Certificate Subject 0: *.pstn.twilio.com
tport_tls.c:698 tls_post_connection_check() tls_post_connection_check(0x7f10540388a0): Peer Certificate Subject 1: *.sip.twilio.com
tport_tls.c:698 tls_post_connection_check() tls_post_connection_check(0x7f10540388a0): Peer Certificate Subject 2: *.pstn.us1.twilio.com
tport_tls.c:698 tls_post_connection_check() tls_post_connection_check(0x7f10540388a0): Peer Certificate Subject 3: *.sip.us1.twilio.com
tport.c:3952 tport_send_event() tport_send_event(0x7f10540388a0) - ready to send to (tls/54.172.60.1:5061)
tport_type_tls.c:537 tport_tls_send() tport_tls_writevec: vec 0x7f10540327e0 0x7f105404aff0 1016 (1016)
tport_type_tls.c:537 tport_tls_send() tport_tls_writevec: vec 0x7f10540327e0 0x7f105401eaf0 209 (209)
tport_type_tls.c:537 tport_tls_send() tport_tls_writevec: vec 0x7f10540327e0 0x7f105401c250 271 (271)
tport.c:3623 tport_vsend() tport_vsend(0x7f10540388a0): 1496 bytes of 1496 to tls/54.172.60.1:5061
tport.c:3521 tport_send_msg() tport_vsend returned 1496
send 1496 bytes to tls/[54.172.60.1]:5061 at 11:49:49.791459:
------------------------------------------------------------------------
INVITE sip:+150XXXXXXXX@pbx.pstn.twilio.com;transport=tls SIP/2.0
Via: SIP/2.0/TLS 70.50.150.80:5081;rport;branch=z9hG4bKcSaQFFtUgHcHD
Max-Forwards: 70
From: <sip:36XXXXXXXX@70.50.150.80>;tag=yecr2v4K79Brg
To: <sip:+150XXXXXXXX@pbx.pstn.twilio.com>
Call-ID: 0651de59-1cac-123a-ca8b-a41f7259508a
CSeq: 34918503 INVITE
Contact: <sip:gw+f0079869-728a-4d02-8e24-41bed917685a@70.50.150.80:5081;transport=tls;transport=tls;gw=f0079869-728a-4d02-8e24-41bed917685a>
User-Agent: FreeSWITCH
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY
Supported: timer, path, replaces
Allow-Events: talk, hold, conference, refer
Proxy-Authorization: Digest username="authUser", realm="sip.twilio.com", nonce="hhjbzv19RkLruSlgYhI-S4fmG69Y8OA1HqIykPVCnXxsRSbx", cnonce="Bo+61RysEjqLyqQfcllQig", opaque="782c8f33f68f63a535910c20cbd8baef", algorithm=MD5, uri="sip:+150XXXXXXXX@pbx.pstn.twilio.com;transport=tls", response="66a58ddcdb377df9196f0ac44d407c5a", qop=auth, nc=00000001
Content-Type: application/sdp
Content-Disposition: session
Content-Length: 271
X-FS-Support: update_display,send_info
Remote-Party-ID: <sip:36XXXXXXXX@70.50.150.80>;party=calling;screen=yes;privacy=off
v=0
o=FreeSWITCH 1618918270 1618918271 IN IP4 70.50.150.80
s=FreeSWITCH
c=IN IP4 70.50.150.80
t=0 0
m=audio 26316 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
tport_type_tls.c:338 tport_tls_set_events() tport_tls_set_events(0x7f10540388a0): logical events IN real IN
tport.c:2311 tport_set_secondary_timer() tport(0x7f10540388a0): reset timer
tport.c:2795 tport_wakeup() tport_wakeup(0x7f10540388a0): events IN
tport.c:2893 tport_recv_event() tport_recv_event(0x7f10540388a0)
tport_type_tls.c:434 tport_tls_recv() tport_tls_recv(0x7f10540388a0): tls_read() returned 367
tport.c:3234 tport_recv_iovec() tport_recv_iovec(0x7f10540388a0) msg 0x7f1054027460 from (tls/54.172.60.1:5061) has 367 bytes, veclen = 1
recv 367 bytes from tls/[54.172.60.1]:5061 at 11:49:49.883358:
------------------------------------------------------------------------
SIP/2.0 100 trying -- your call is important to us
Via: SIP/2.0/TLS 70.50.150.80:5081;rport=41995;branch=z9hG4bKcSaQFFtUgHcHD;received=70.50.150.80
From: <sip:36XXXXXXXX@70.50.150.80>;tag=yecr2v4K79Brg
To: <sip:+150XXXXXXXX@pbx.pstn.twilio.com>
Call-ID: 0651de59-1cac-123a-ca8b-a41f7259508a
CSeq: 34918503 INVITE
Server: Twilio Gateway
Content-Length: 0
tport.c:3052 tport_deliver() tport_deliver(0x7f10540388a0): msg 0x7f1054027460 (367 bytes) from tls/54.172.60.1:5061/sips next=(nil)
nta.c:3328 agent_recv_response() nta: received 100 trying -- your call is important to us for INVITE (34918503)
nta.c:3395 agent_recv_response() nta: 100 trying -- your call is important to us is going to a transaction
nta.c:9642 outgoing_estimate_delay() nta_outgoing: RTT is 372.104 ms
tport.c:4251 tport_release() tport_release(0x7f10540388a0): 0x7f1054048950 by 0x7f1054029650 with 0x7f1054027460 (preliminary)
tport.c:2311 tport_set_secondary_timer() tport(0x7f10540388a0): reset timer
tport.c:2795 tport_wakeup() tport_wakeup(0x7f10540388a0): events IN
tport.c:2893 tport_recv_event() tport_recv_event(0x7f10540388a0)
tport_type_tls.c:434 tport_tls_recv() tport_tls_recv(0x7f10540388a0): tls_read() returned 518
tport.c:3234 tport_recv_iovec() tport_recv_iovec(0x7f10540388a0) msg 0x7f1054069650 from (tls/54.172.60.1:5061) has 518 bytes, veclen = 1
recv 518 bytes from tls/[54.172.60.1]:5061 at 11:49:49.898930:
------------------------------------------------------------------------
SIP/2.0 488 Secure media required
CSeq: 34918503 INVITE
Call-ID: 0651de59-1cac-123a-ca8b-a41f7259508a
From: <sip:36XXXXXXXX@70.50.150.80>;tag=yecr2v4K79Brg
To: <sip:+150XXXXXXXX@pbx.pstn.twilio.com>;tag=02555165_6772d868_3ba09843-8937-4126-8da0-a0f6432ab7ec
Via: SIP/2.0/TLS 70.50.150.80:5081;received=70.50.150.80;rport=41995;branch=z9hG4bKcSaQFFtUgHcHD
Server: Twilio
Contact: <sip:172.25.72.90:5060>
X-Twilio-Error: 32208 SIP trunk or domain is required to use secure media (SRTP).
Content-Length: 0
tport.c:3052 tport_deliver() tport_deliver(0x7f10540388a0): msg 0x7f1054069650 (518 bytes) from tls/54.172.60.1:5061/sips next=(nil)
nta.c:3328 agent_recv_response() nta: received 488 Secure media required for INVITE (34918503)
nta.c:3395 agent_recv_response() nta: 488 Secure media required is going to a transaction
tport.c:4251 tport_release() tport_release(0x7f10540388a0): 0x7f1054048950 by 0x7f1054029650 with 0x7f1054069650
tport.c:4617 tport_by_name() tport(0x7f1054006d10): found 0x7f10540388a0 by name tls/54.172.60.1:5061
tport.c:3286 tport_tsend() tport_tsend(0x7f10540388a0) tpn = tls/54.172.60.1:5061
tport_type_tls.c:537 tport_tls_send() tport_tls_writevec: vec 0x7f10540327e0 0x7f1054075090 404 (404)
tport.c:3623 tport_vsend() tport_vsend(0x7f10540388a0): 404 bytes of 404 to tls/54.172.60.1:5061
tport.c:3521 tport_send_msg() tport_vsend returned 404
send 404 bytes to tls/[54.172.60.1]:5061 at 11:49:49.899040:
------------------------------------------------------------------------
ACK sip:+150XXXXXXXX@pbx.pstn.twilio.com;transport=tls SIP/2.0
Via: SIP/2.0/TLS 70.50.150.80:5081;rport;branch=z9hG4bKcSaQFFtUgHcHD
Max-Forwards: 70
From: <sip:36XXXXXXXX@70.50.150.80>;tag=yecr2v4K79Brg
To: <sip:+150XXXXXXXX@pbx.pstn.twilio.com>;tag=02555165_6772d868_3ba09843-8937-4126-8da0-a0f6432ab7ec
Call-ID: 0651de59-1cac-123a-ca8b-a41f7259508a
CSeq: 34918503 ACK
Content-Length: 0
tport.c:2311 tport_set_secondary_timer() tport(0x7f10540388a0): reset timer
nta.c:8348 outgoing_send() nta: sent ACK (34918503) to tls/54.172.60.1:5061
nta.c:8774 outgoing_free() nta: outgoing_free(0x7f1054055910)
nua_stack.c:271 nua_stack_event() nua(0x7f10540259c0): event r_invite 488 Secure media required
nua_session.c:4140 signal_call_state_change() nua(0x7f10540259c0): call state changed: calling -> init
nua_stack.c:271 nua_stack_event() nua(0x7f10540259c0): event i_state 488 Secure media required
nua_stack.c:271 nua_stack_event() nua(0x7f10540259c0): event i_terminated 488 Secure media required
nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
nua_dialog.c:397 nua_dialog_usage_remove_at() nua(0x7f10540259c0): removing session usage
soa.c:356 soa_destroy() soa_destroy(static::0x7f1054069170) called
nta.c:4499 nta_leg_destroy() nta_leg_destroy(0x7f1054019a80)
tport.c:2311 tport_set_secondary_timer() tport(0x7f10540388a0): reset timer
nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
nua.c:370 nua_handle_magic() nua: nua_handle_magic: entering
nua.c:370 nua_handle_magic() nua: nua_handle_magic: entering
nua.c:370 nua_handle_magic() nua: nua_handle_magic: entering
2021-04-20 11:49:47.601614 [DEBUG] sofia.c:7326 Channel sofia/external/+150XXXXXXXX entering state [terminated][488]
2021-04-20 11:49:47.601614 [NOTICE] sofia.c:8559 Hangup sofia/external/+150XXXXXXXX [CS_CONSUME_MEDIA] [INCOMPATIBLE_DESTINATION]
nua.c:346 nua_handle_bind() nua: nua_handle_bind: entering
nua.c:925 nua_handle_destroy() nua: nua_handle_destroy: entering
nua_stack.c:529 nua_signal() nua(0x7f10540259c0): sent signal r_destroy
nua.c:370 nua_handle_magic() nua: nua_handle_magic: entering
nua.c:346 nua_handle_bind() nua: nua_handle_bind: entering
nua.c:925 nua_handle_destroy() nua: nua_handle_destroy: entering
nua.c:370 nua_handle_magic() nua: nua_handle_magic: entering
nua_stack.c:569 nua_stack_signal() nua(0x7f10540259c0): recv signal r_destroy
nua.c:370 nua_handle_magic() nua: nua_handle_magic: entering
nua.c:925 nua_handle_destroy() nua: nua_handle_destroy: entering
nta.c:4499 nta_leg_destroy() nta_leg_destroy((nil))
2021-04-20 11:49:47.601614 [DEBUG] switch_core_state_machine.c:585 (sofia/external/+150XXXXXXXX) Running State Change CS_HANGUP (Cur 1 Tot 87)
2021-04-20 11:49:47.601614 [DEBUG] switch_core_state_machine.c:848 (sofia/external/+150XXXXXXXX) Callstate Change DOWN -> HANGUP
2021-04-20 11:49:47.601614 [DEBUG] switch_core_state_machine.c:850 (sofia/external/+150XXXXXXXX) State HANGUP
2021-04-20 11:49:47.601614 [DEBUG] mod_sofia.c:453 Channel sofia/external/+150XXXXXXXX hanging up, cause: INCOMPATIBLE_DESTINATION
2021-04-20 11:49:47.601614 [DEBUG] switch_core_state_machine.c:60 sofia/external/+150XXXXXXXX Standard HANGUP, cause: INCOMPATIBLE_DESTINATION
2021-04-20 11:49:47.601614 [DEBUG] switch_core_state_machine.c:850 (sofia/external/+150XXXXXXXX) State HANGUP going to sleep
2021-04-20 11:49:47.601614 [DEBUG] switch_ivr_originate.c:3995 Originate Resulted in Error Cause: 88 [INCOMPATIBLE_DESTINATION]
2021-04-20 11:49:47.641637 [INFO] switch_cpp.cpp:1447 [FAX] Success: '0'
2021-04-20 11:49:47.641637 [INFO] switch_cpp.cpp:1447 [FAX] fax_result_text: 'FS_NOT_SET'
2021-04-20 11:49:47.641637 [INFO] switch_cpp.cpp:1447 [FAX] fax_file: '/var/lib/freeswitch/storage/fax/MainDomain/700/temp/cad3c8c5-4f80-4837-aba5-6ff1fe6310b1.tif'
2021-04-20 11:49:47.641637 [INFO] switch_cpp.cpp:1447 [FAX] uuid: '4c7b587d-ce16-4137-9841-dbe6aa7a8dba'
2021-04-20 11:49:47.641637 [INFO] switch_cpp.cpp:1447 [FAX] fax_retry_attempts: 1
2021-04-20 11:49:47.641637 [INFO] switch_cpp.cpp:1447 [FAX] fax_retry_limit: 20
2021-04-20 11:49:47.641637 [INFO] switch_cpp.cpp:1447 [FAX] fax_retry_sleep: 30
2021-04-20 11:49:47.641637 [INFO] switch_cpp.cpp:1447 [FAX] fax_uri: 'sofia/gateway/f0079869-728a-4d02-8e24-41bed917685a/+150XXXXXXXX'
2021-04-20 11:49:47.641637 [INFO] switch_cpp.cpp:1447 [FAX] accountcode: 'MainDomain'
2021-04-20 11:49:47.641637 [INFO] switch_cpp.cpp:1447 [FAX] origination_caller_id_name: 000000000000000
2021-04-20 11:49:47.641637 [INFO] switch_cpp.cpp:1447 [FAX] origination_caller_id_number: 36XXXXXXXX
2021-04-20 11:49:47.641637 [INFO] switch_cpp.cpp:1447 [FAX] fax_result_code: 2
2021-04-20 11:49:47.641637 [INFO] switch_cpp.cpp:1447 [FAX] mailfrom_address: wouldyukindly@gmail.com
2021-04-20 11:49:47.641637 [INFO] switch_cpp.cpp:1447 [FAX] mailto_address: wouldyukindly@gmail.com
2021-04-20 11:49:47.641637 [INFO] switch_cpp.cpp:1447 [FAX] hangup_cause_q850: '88'
2021-04-20 11:49:47.641637 [INFO] switch_cpp.cpp:1447 [FAX] Last Fax Failed, try a different way. Wait first.
tport.c:2770 tport_wakeup_pri() tport_wakeup_pri(0x7f1048004e90): events IN
tport.c:2893 tport_recv_event() tport_recv_event(0x7f1048004e90)
tport.c:3234 tport_recv_iovec() tport_recv_iovec(0x7f1048004e90) msg 0x7f1048041b60 from (udp/192.168.1.154:5060) has 2 bytes, veclen = 1
tport.c:3052 tport_deliver() tport_deliver(0x7f1048004e90): bad msg 0x7f1048041b60 (2 bytes) from udp/192.168.1.1:5060/sip next=(nil)- Status
- Not open for further replies.