Delay ~10 sec in app_dial.c or dial.c

PotatoCaptain · March 18, 2020, 6:55am

Hello.

Asterisk 13.21.1, FreePBX 14.0.13.26

Sometimes there is a delay in calls:

[2020-03-17 18:15:34] VERBOSE[44751][C-000070ab] app_stack.c: PJSIP/012-0000cd81 Internal Gosub(agent-dial,transfer-dtmf,1) start
[2020-03-17 18:15:34] VERBOSE[44751][C-000070ab] pbx.c: Executing [transfer-dtmf@agent-dial:1] NoOp("PJSIP/012-0000cd81", "") in new stack
[2020-03-17 18:15:34] VERBOSE[44751][C-000070ab] pbx.c: Executing [transfer-dtmf@agent-dial:2] Set("PJSIP/012-0000cd81", "DYNAMIC_FEATURES=ATXFi-0#ATXFi-1#ATXFi-3#ATXFi-4#ATXFi-6#ATXFi-7#ATXFi-8#ATXFi-9#fax-send#fax-start#nway-start#nway-ok") in new stack
[2020-03-17 18:15:34] VERBOSE[44751][C-000070ab] pbx.c: Executing [transfer-dtmf@agent-dial:3] Verbose("PJSIP/012-0000cd81", "0, In callee pre-dial handler!") in new stack
[2020-03-17 18:15:34] VERBOSE[44751][C-000070ab] app_verbose.c:  In callee pre-dial handler!
[2020-03-17 18:15:34] VERBOSE[44751][C-000070ab] pbx.c: Executing [transfer-dtmf@agent-dial:4] Return("PJSIP/012-0000cd81", "") in new stack
[2020-03-17 18:15:34] VERBOSE[44751][C-000070ab] app_stack.c: Spawn extension (all-agent, a-78-012, 1) exited non-zero on 'PJSIP/012-0000cd81'
[2020-03-17 18:15:34] VERBOSE[44751][C-000070ab] app_stack.c: PJSIP/012-0000cd81 Internal Gosub(agent-dial,transfer-dtmf,1) complete GOSUB_RETVAL=
[2020-03-17 **18:15:34**] VERBOSE[44751][C-000070ab] app_dial.c: Called PJSIP/012
[2020-03-17 **18:15:44**] VERBOSE[44751][C-000070ab] app_dial.c: PJSIP/012-0000cd81 is ringing

[2020-03-17 17:39:27] VERBOSE[19170] dial.c: Called 012
[2020-03-17 17:39:27] VERBOSE[41769] netsock2.c: Using SIP RTP Audio TOS bits 184
[2020-03-17 17:39:27] VERBOSE[41769] netsock2.c: Using SIP RTP Audio TOS bits 184 in TCLASS field.
[2020-03-17 **17:39:27**] VERBOSE[41769] netsock2.c: Using SIP RTP Audio CoS mark 5
[2020-03-17 **17:39:37**] VERBOSE[19170] dial.c: PJSIP/012-0000cd1d is ringing

In tcpdump its see, how asterisk sends invite with delay

jcolp · March 18, 2020, 9:35am

Have you confirmed the INVITE isn’t sent at that time with “pjsip set logger on”? What is the endpoint/AOR/contact for it?

david551 · March 18, 2020, 10:32am

I’d suggest you are having a DNS timeout and fallback.

PotatoCaptain · March 19, 2020, 1:21am

pjsip logger is disabled.

Problem is not only with him. Problem with all pjsip clients.

doctora*CLI> pjsip show aor 012

      Aor:  <Aor..............................................>  <MaxContact>
    Contact:  <Aor/ContactUri............................> <Hash....> <Status> <RTT(ms)..>
==========================================================================================

      Aor:  012                                                  1
    Contact:  012/sip:012@192.168.4.232:5060               b1473d2a5d Avail         5.021


 ParameterName        : ParameterValue
 =================================================
 authenticate_qualify : false
 contact              : sip:012@192.168.4.232:5060
 default_expiration   : 3600
 mailboxes            : 012@device
 max_contacts         : 1
 maximum_expiration   : 7200
 minimum_expiration   : 60
 outbound_proxy       : 
 qualify_frequency    : 60
 qualify_timeout      : 3.000000
 remove_existing      : true
 support_path         : false
 voicemail_extension  :

doctora*CLI> pjsip show endpoint 012

 Endpoint:  <Endpoint/CID.....................................>  <State.....>  <Channels.>
    I/OAuth:  <AuthId/UserName...........................................................>
        Aor:  <Aor............................................>  <MaxContact>
      Contact:  <Aor/ContactUri..........................> <Hash....> <Status> <RTT(ms)..>
  Transport:  <TransportId........>  <Type>  <cos>  <tos>  <BindAddress..................>
   Identify:  <Identify/Endpoint.........................................................>
        Match:  <criteria.........................>
    Channel:  <ChannelId......................................>  <State.....>  <Time.....>
        Exten: <DialedExten...........>  CLCID: <ConnectedLineCID.......>
==========================================================================================

 Endpoint:  012/012                                              Not in use    0 of inf
     InAuth:  012-auth/012
        Aor:  012                                                1
      Contact:  012/sip:012@192.168.4.232:5060             b1473d2a5d Avail         4.696


 ParameterName                      : ParameterValue
 =========================================================
 100rel                             : yes
 accountcode                        : 
 acl                                : 
 aggregate_mwi                      : true
 allow                              : (alaw|ulaw|g722)
 allow_overlap                      : true
 allow_subscribe                    : true
 allow_transfer                     : true
 aors                               : 012
 asymmetric_rtp_codec               : false
 auth                               : 012-auth
 bind_rtp_to_media_address          : false
 call_group                         : 
 callerid                           : "CallCenter" <012>
 callerid_privacy                   : allowed_not_screened
 callerid_tag                       : 
 connected_line_method              : invite
 contact_acl                        : 
 context                            : all-agent
 cos_audio                          : 5
 cos_video                          : 4
 device_state_busy_at               : 0
 direct_media                       : true
 direct_media_glare_mitigation      : none
 direct_media_method                : invite
 disable_direct_media_on_nat        : false
 dtls_ca_file                       : 
 dtls_ca_path                       : 
 dtls_cert_file                     : 
 dtls_cipher                        : 
 dtls_fingerprint                   : SHA-256
 dtls_private_key                   : 
 dtls_rekey                         : 0
 dtls_setup                         : active
 dtls_verify                        : No
 dtmf_mode                          : rfc4733
 fax_detect                         : false
 fax_detect_timeout                 : 0
 force_avp                          : false
 force_rport                        : true
 from_domain                        : 
 from_user                          : 
 g726_non_standard                  : false
 ice_support                        : false
 identify_by                        : username,ip
 inband_progress                    : false
 incoming_mwi_mailbox               : 
 language                           : ru
 mailboxes                          : 012@device
 media_address                      : 
 media_encryption                   : no
 media_encryption_optimistic        : false
 media_use_received_transport       : false
 message_context                    : 
 moh_suggest                        : default
 mwi_from_user                      : 
 mwi_subscribe_replaces_unsolicited : true
 named_call_group                   : 
 named_pickup_group                 : 
 notify_early_inuse_ringing         : false
 one_touch_recording                : true
 outbound_auth                      : 
 outbound_proxy                     : 
 pickup_group                       : 
 record_off_feature                 : apprecord
 record_on_feature                  : apprecord
 refer_blind_progress               : true
 rewrite_contact                    : true
 rpid_immediate                     : false
 rtcp_mux                           : false
 rtp_engine                         : asterisk
 rtp_ipv6                           : false
 rtp_keepalive                      : 0
 rtp_symmetric                      : true
 rtp_timeout                        : 0
 rtp_timeout_hold                   : 0
 sdp_owner                          : -
 sdp_session                        : Asterisk
 send_diversion                     : true
 send_pai                           : true
 send_rpid                          : false
 set_var                            : 
 srtp_tag_32                        : false
 sub_min_expiry                     : 0
 subscribe_context                  : 
 t38_udptl                          : false
 t38_udptl_ec                       : none
 t38_udptl_ipv6                     : false
 t38_udptl_maxdatagram              : 0
 t38_udptl_nat                      : false
 timers                             : yes
 timers_min_se                      : 90
 timers_sess_expires                : 1800
 tone_zone                          : 
 tos_audio                          : 184
 tos_video                          : 136
 transport                          : 
 trust_id_inbound                   : true
 trust_id_outbound                  : false
 use_avpf                           : false
 use_ptime                          : false
 user_eq_phone                      : false
 voicemail_extension                :

PotatoCaptain · March 19, 2020, 1:47am

DNS problem occurs only in SIP, but i use PJSIP.
OR am I wrong?

PotatoCaptain · March 19, 2020, 1:57am

its intermittent problem…1 of 5-10 calls with delay

[2020-03-19 11:48:32] VERBOSE[35273][C-000079a3] pbx.c: Executing [transfer-dtmf@agent-dial:3] Verbose("PJSIP/033-0000de16", "0, In callee pre-dial handler!") in new stack
[2020-03-19 11:48:32] VERBOSE[35273][C-000079a3] app_verbose.c:  In callee pre-dial handler!
[2020-03-19 11:48:32] VERBOSE[35273][C-000079a3] pbx.c: Executing [transfer-dtmf@agent-dial:4] Return("PJSIP/033-0000de16", "") in new stack
[2020-03-19 11:48:32] VERBOSE[35273][C-000079a3] app_stack.c: Spawn extension (all-agent, a-54-033, 1) exited non-zero on 'PJSIP/033-0000de16'
[2020-03-19 11:48:32] VERBOSE[35273][C-000079a3] app_stack.c: PJSIP/033-0000de16 Internal Gosub(agent-dial,transfer-dtmf,1) complete GOSUB_RETVAL=
[2020-03-19 11:48:32] VERBOSE[35273][C-000079a3] app_dial.c: Called PJSIP/033
[2020-03-19 11:48:42] VERBOSE[35273][C-000079a3] app_dial.c: PJSIP/033-0000de16 is ringing
[2020-03-19 11:48:42] VERBOSE[34766][C-000079a3] app_queue.c: Local/a-54-033@agent-dial-00006435;1 is ringing
[2020-03-19 11:48:46] VERBOSE[35273][C-000079a3] app_dial.c: PJSIP/033-0000de16 answered Local/a-54-033@agent-dial-00006435;2
[2020-03-19 11:48:46] VERBOSE[35273][C-000079a3] app_stack.c: PJSIP/033-0000de16 Internal Gosub(agent-sub-answer,s,1) start

jcolp · March 19, 2020, 10:26am

Do you have /etc/hosts configured with the hostname of the system?

PotatoCaptain · March 19, 2020, 11:18pm

[root@doctora etc]# cat /etc/hosts
127.0.0.1 localhost LXC_NAME
# --- BEGIN PVE ---
::1 localhost.localnet localhost
193.233.5.56 ccnew-idle.avantele.com ccnew-idle
# --- END PVE ---
[root@doctora etc]#

jcolp · March 20, 2020, 10:05am

Your hostname appears to be “doctora” and is not in the /etc/hosts file. Some things look up the local hostname to determine what the local IP address is. If it’s not in /etc/hosts then this can result in DNS blocking for a period of time as it is looked up.

PotatoCaptain · March 23, 2020, 12:50am

Yes, its working!
Write in /etc/hosts
127.0.0.1 doctora
and the delay is gone.
Thank you very much!!

system · April 22, 2020, 12:50am

This topic was automatically closed 30 days after the last reply. New replies are no longer allowed.