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

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

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

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

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                : 

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

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

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

[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]#

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.

2 Likes

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