WARNING[23750][C-00000c7a] func_curl.c: Connection timed out after 5001 milliseconds

[Metehan]

Hi There,

I have been getting these errors from the last 1 monthly dynamic routing service and they have been increasing

[2024-09-23 08:57:57] WARNING[21933][C-00000c5e] func_curl.c: Connection timed out after 5001 milliseconds (‘https://customcrmapi:3300/’)

Is there a solution to this issue?

Thansk and regards,

[comtech]

Find out why the query is timing out. Is it a resource constraint? If yes, which side? Is it a routing issue? Are there other log messages that might be contributing to the delayed experience? These are good places to start looking for issues.

[Metehan]

Thaks for reply @comtech ,

If there is a timeout, I connect the extension directly. But there is no reason for a timeout on the url side.

Before and after time out as logs.

[2024-09-23 05:06:08] VERBOSE[9928][C-0000006c] netsock2.c: Using SIP RTP TOS bits 184

[2024-09-23 05:06:08] VERBOSE[9928][C-0000006c] netsock2.c: Using SIP RTP CoS mark 5

[2024-09-23 05:06:08] VERBOSE[24562][C-0000006c] pbx.c: Executing [9021XXXXXXXX@from-trunk:1] Set(“SIP/9021XXXXXXXX-0000001d”, “__DIRECTION=INBOUND”) in new stack

[2024-09-23 05:06:08] VERBOSE[24562][C-0000006c] pbx.c: Executing [9021XXXXXXXX@from-trunk:2] Gosub(“SIP/9021XXXXXXXX-0000001d”, “sub-record-check,s,1(in,9021XXXXXXXX,dontcare)”) in new stack

[2024-09-23 05:06:08] VERBOSE[24562][C-0000006c] pbx.c: Executing [s@sub-record-check:1] GotoIf(“SIP/9021XXXXXXXX-0000001d”, “0?initialized”) in new stack

[2024-09-23 05:06:08] VERBOSE[24562][C-0000006c] pbx.c: Executing [s@sub-record-check:2] Set(“SIP/9021XXXXXXXX-0000001d”, “__REC_STATUS=INITIALIZED”) in new stack

[2024-09-23 05:06:08] VERBOSE[24562][C-0000006c] pbx.c: Executing [s@sub-record-check:3] Set(“SIP/9021XXXXXXXX-0000001d”, “NOW=1727067968”) in new stack

[2024-09-23 05:06:08] VERBOSE[24562][C-0000006c] pbx.c: Executing [s@sub-record-check:4] Set(“SIP/9021XXXXXXXX-0000001d”, “__DAY=23”) in new stack

[2024-09-23 05:06:08] VERBOSE[24562][C-0000006c] pbx.c: Executing [s@sub-record-check:5] Set(“SIP/9021XXXXXXXX-0000001d”, “__MONTH=09”) in new stack

[2024-09-23 05:06:08] VERBOSE[24562][C-0000006c] pbx.c: Executing [s@sub-record-check:6] Set(“SIP/9021XXXXXXXX-0000001d”, “__YEAR=2024”) in new stack

[2024-09-23 05:06:08] VERBOSE[24562][C-0000006c] pbx.c: Executing [s@sub-record-check:7] Set(“SIP/9021XXXXXXXX-0000001d”, “__TIMESTR=20240923-050608”) in new stack

[2024-09-23 05:06:08] VERBOSE[24562][C-0000006c] pbx.c: Executing [s@sub-record-check:8] Set(“SIP/9021XXXXXXXX-0000001d”, “__FROMEXTEN=unknown”) in new stack

[2024-09-23 05:06:08] VERBOSE[24562][C-0000006c] pbx.c: Executing [s@sub-record-check:9] Set(“SIP/9021XXXXXXXX-0000001d”, “__MON_FMT=wav”) in new stack

[2024-09-23 05:06:08] VERBOSE[24562][C-0000006c] pbx.c: Executing [s@sub-record-check:10] NoOp(“SIP/9021XXXXXXXX-0000001d”, “Recordings initialized”) in new stack

[2024-09-23 05:06:08] VERBOSE[24562][C-0000006c] pbx.c: Executing [s@sub-record-check:11] ExecIf(“SIP/9021XXXXXXXX-0000001d”, “0?Set(ARG3=dontcare)”) in new stack

[2024-09-23 05:06:08] VERBOSE[24562][C-0000006c] pbx.c: Executing [s@sub-record-check:12] Set(“SIP/9021XXXXXXXX-0000001d”, “REC_POLICY_MODE_SAVE=”) in new stack

[2024-09-23 05:06:08] VERBOSE[24562][C-0000006c] pbx.c: Executing [s@sub-record-check:13] ExecIf(“SIP/9021XXXXXXXX-0000001d”, “0?Set(REC_STATUS=NO)”) in new stack

[2024-09-23 05:06:08] VERBOSE[24562][C-0000006c] pbx.c: Executing [s@sub-record-check:14] GotoIf(“SIP/9021XXXXXXXX-0000001d”, “2?checkaction”) in new stack

[2024-09-23 05:06:08] VERBOSE[24562][C-0000006c] pbx_builtins.c: Goto (sub-record-check,s,17)

[2024-09-23 05:06:08] VERBOSE[24562][C-0000006c] pbx.c: Executing [s@sub-record-check:17] GotoIf(“SIP/9021XXXXXXXX-0000001d”, “1?sub-record-check,in,1”) in new stack

[2024-09-23 05:06:08] VERBOSE[24562][C-0000006c] pbx_builtins.c: Goto (sub-record-check,in,1)

[2024-09-23 05:06:08] VERBOSE[24562][C-0000006c] pbx.c: Executing [in@sub-record-check:1] NoOp(“SIP/9021XXXXXXXX-0000001d”, “Inbound Recording Check to 9021XXXXXXXX”) in new stack

[2024-09-23 05:06:08] VERBOSE[24562][C-0000006c] pbx.c: Executing [in@sub-record-check:2] Set(“SIP/9021XXXXXXXX-0000001d”, “FROMEXTEN=unknown”) in new stack

[2024-09-23 05:06:08] VERBOSE[24562][C-0000006c] pbx.c: Executing [in@sub-record-check:3] ExecIf(“SIP/9021XXXXXXXX-0000001d”, “11?Set(FROMEXTEN=053XXXXXXXX)”) in new stack

[2024-09-23 05:06:08] VERBOSE[24562][C-0000006c] pbx.c: Executing [in@sub-record-check:4] Gosub(“SIP/9021XXXXXXXX-0000001d”, “recordcheck,1(dontcare,in,9021XXXXXXXX)”) in new stack

[2024-09-23 05:06:08] VERBOSE[24562][C-0000006c] pbx.c: Executing [recordcheck@sub-record-check:1] NoOp(“SIP/9021XXXXXXXX-0000001d”, “Starting recording check against dontcare”) in new stack

[2024-09-23 05:06:08] VERBOSE[24562][C-0000006c] pbx.c: Executing [recordcheck@sub-record-check:2] Goto(“SIP/9021XXXXXXXX-0000001d”, “dontcare”) in new stack

[2024-09-23 05:06:08] VERBOSE[24562][C-0000006c] pbx_builtins.c: Goto (sub-record-check,recordcheck,3)

[2024-09-23 05:06:08] VERBOSE[24562][C-0000006c] pbx.c: Executing [recordcheck@sub-record-check:3] Return(“SIP/9021XXXXXXXX-0000001d”, “”) in new stack

[2024-09-23 05:06:08] VERBOSE[24562][C-0000006c] pbx.c: Executing [in@sub-record-check:5] Return(“SIP/9021XXXXXXXX-0000001d”, “”) in new stack

[2024-09-23 05:06:08] VERBOSE[24562][C-0000006c] pbx.c: Executing [9021XXXXXXXX@from-trunk:3] Set(“SIP/9021XXXXXXXX-0000001d”, “CHANNEL(tonezone)=us”) in new stack

[2024-09-23 05:06:08] VERBOSE[24562][C-0000006c] pbx.c: Executing [9021XXXXXXXX@from-trunk:4] Set(“SIP/9021XXXXXXXX-0000001d”, “__FROM_DID=9021XXXXXXXX”) in new stack

[2024-09-23 05:06:08] VERBOSE[24562][C-0000006c] pbx.c: Executing [9021XXXXXXXX@from-trunk:5] Set(“SIP/9021XXXXXXXX-0000001d”, “returnhere=1”) in new stack

[2024-09-23 05:06:08] VERBOSE[24562][C-0000006c] pbx.c: Executing [9021XXXXXXXX@from-trunk:6] Gosub(“SIP/9021XXXXXXXX-0000001d”, “app-blacklist-check,s,1()”) in new stack

[2024-09-23 05:06:08] VERBOSE[24562][C-0000006c] pbx.c: Executing [s@app-blacklist-check:1] GotoIf(“SIP/9021XXXXXXXX-0000001d”, “0?blacklisted”) in new stack

[2024-09-23 05:06:08] VERBOSE[24562][C-0000006c] pbx.c: Executing [s@app-blacklist-check:2] Set(“SIP/9021XXXXXXXX-0000001d”, “CALLED_BLACKLIST=1”) in new stack

[2024-09-23 05:06:08] VERBOSE[24562][C-0000006c] pbx.c: Executing [s@app-blacklist-check:3] Return(“SIP/9021XXXXXXXX-0000001d”, “”) in new stack

[2024-09-23 05:06:08] VERBOSE[24562][C-0000006c] pbx.c: Executing [9021XXXXXXXX@from-trunk:7] Set(“SIP/9021XXXXXXXX-0000001d”, “CDR(did)=9021XXXXXXXX”) in new stack

[2024-09-23 05:06:08] VERBOSE[24562][C-0000006c] pbx.c: Executing [9021XXXXXXXX@from-trunk:8] GotoIf(“SIP/9021XXXXXXXX-0000001d”, “0?”) in new stack

[2024-09-23 05:06:08] VERBOSE[24562][C-0000006c] pbx.c: Executing [9021XXXXXXXX@from-trunk:9] ExecIf(“SIP/9021XXXXXXXX-0000001d”, “0 ?Set(CALLERID(name)=053XXXXXXXX)”) in new stack

[2024-09-23 05:06:08] VERBOSE[24562][C-0000006c] pbx.c: Executing [9021XXXXXXXX@from-trunk:10] Set(“SIP/9021XXXXXXXX-0000001d”, “__MOHCLASS=”) in new stack

[2024-09-23 05:06:08] VERBOSE[24562][C-0000006c] pbx.c: Executing [9021XXXXXXXX@from-trunk:11] Set(“SIP/9021XXXXXXXX-0000001d”, “__REVERSAL_REJECT=FALSE”) in new stack

[2024-09-23 05:06:08] VERBOSE[24562][C-0000006c] pbx.c: Executing [9021XXXXXXXX@from-trunk:12] GotoIf(“SIP/9021XXXXXXXX-0000001d”, “1?post-reverse-charge”) in new stack

[2024-09-23 05:06:08] VERBOSE[24562][C-0000006c] pbx_builtins.c: Goto (from-trunk,9021XXXXXXXX,14)

[2024-09-23 05:06:08] VERBOSE[24562][C-0000006c] pbx.c: Executing [9021XXXXXXXX@from-trunk:14] NoOp(“SIP/9021XXXXXXXX-0000001d”, “”) in new stack

[2024-09-23 05:06:08] VERBOSE[24562][C-0000006c] pbx.c: Executing [9021XXXXXXXX@from-trunk:15] Set(“SIP/9021XXXXXXXX-0000001d”, “__CALLINGNAMEPRES_SV=allowed_not_screened”) in new stack

[2024-09-23 05:06:08] VERBOSE[24562][C-0000006c] pbx.c: Executing [9021XXXXXXXX@from-trunk:16] Set(“SIP/9021XXXXXXXX-0000001d”, “__CALLINGNUMPRES_SV=allowed_not_screened”) in new stack

[2024-09-23 05:06:08] VERBOSE[24562][C-0000006c] pbx.c: Executing [9021XXXXXXXX@from-trunk:17] Set(“SIP/9021XXXXXXXX-0000001d”, “CALLERID(name-pres)=allowed_not_screened”) in new stack

[2024-09-23 05:06:08] VERBOSE[24562][C-0000006c] pbx.c: Executing [9021XXXXXXXX@from-trunk:18] Set(“SIP/9021XXXXXXXX-0000001d”, “CALLERID(num-pres)=allowed_not_screened”) in new stack

[2024-09-23 05:06:08] VERBOSE[24562][C-0000006c] pbx.c: Executing [9021XXXXXXXX@from-trunk:19] NoOp(“SIP/9021XXXXXXXX-0000001d”, “CallerID Entry Point”) in new stack

[2024-09-23 05:06:08] VERBOSE[24562][C-0000006c] pbx.c: Executing [9021XXXXXXXX@from-trunk:20] Set(“SIP/9021XXXXXXXX-0000001d”, “__CRM_DIRECTION=INBOUND”) in new stack

[2024-09-23 05:06:08] VERBOSE[24562][C-0000006c] pbx.c: Executing [9021XXXXXXXX@from-trunk:21] Set(“SIP/9021XXXXXXXX-0000001d”, “__CRM_SOURCE=053XXXXXXXX”) in new stack

[2024-09-23 05:06:08] VERBOSE[24562][C-0000006c] pbx.c: Executing [9021XXXXXXXX@from-trunk:22] Set(“SIP/9021XXXXXXXX-0000001d”, “__CRM_LINKEDID=1727067968.29”) in new stack

[2024-09-23 05:06:08] VERBOSE[24562][C-0000006c] pbx.c: Executing [9021XXXXXXXX@from-trunk:23] AGI(“SIP/9021XXXXXXXX-0000001d”, “agi://127.0.0.1/sangomacrm.agi,true”) in new stack

[2024-09-23 05:06:09] VERBOSE[24562][C-0000006c] res_agi.c: <SIP/9021XXXXXXXX-0000001d>AGI Script agi://127.0.0.1/sangomacrm.agi completed, returning 0

[2024-09-23 05:06:09] VERBOSE[24562][C-0000006c] pbx.c: Executing [9021XXXXXXXX@from-trunk:24] ExecIf(“SIP/9021XXXXXXXX-0000001d”, “1?Set(CHANNEL(hangup_handler_push)=crm-hangup,s,1)”) in new stack

[2024-09-23 05:06:09] VERBOSE[24562][C-0000006c] pbx.c: Executing [9021XXXXXXXX@from-trunk:25] Goto(“SIP/9021XXXXXXXX-0000001d”, “dynroute-191,s,1”) in new stack

[2024-09-23 05:06:09] VERBOSE[24562][C-0000006c] pbx_builtins.c: Goto (dynroute-191,s,1)

[2024-09-23 05:06:09] VERBOSE[24562][C-0000006c] pbx.c: Executing [s@dynroute-191:1] Set(“SIP/9021XXXXXXXX-0000001d”, “dynroute=”) in new stack

[2024-09-23 05:06:09] VERBOSE[24562][C-0000006c] pbx.c: Executing [s@dynroute-191:2] Set(“SIP/9021XXXXXXXX-0000001d”, “CURLOPT(dnstimeout)=5”) in new stack

[2024-09-23 05:06:09] VERBOSE[24562][C-0000006c] pbx.c: Executing [s@dynroute-191:3] Set(“SIP/9021XXXXXXXX-0000001d”, “CURLOPT(conntimeout)=5”) in new stack

[2024-09-23 05:06:09] VERBOSE[24562][C-0000006c] pbx.c: Executing [s@dynroute-191:4] Set(“SIP/9021XXXXXXXX-0000001d”, “CURLOPT(ftptimeout)=5”) in new stack

[2024-09-23 05:06:09] VERBOSE[24562][C-0000006c] pbx.c: Executing [s@dynroute-191:5] Set(“SIP/9021XXXXXXXX-0000001d”, “CURLOPT(httptimeout)=5”) in new stack

[2024-09-23 05:06:14] WARNING[24562][C-0000006c] func_curl.c: Connection timed out after 5001 milliseconds ('https://customcrmapilink:3300/customers/customerExist?phone=053XXXXXXXX&did=9021XXXXXXXX&privateKey=XXXXX’)

[2024-09-23 05:06:14] VERBOSE[24562][C-0000006c] pbx.c: Executing [s@dynroute-191:6] Set(“SIP/9021XXXXXXXX-0000001d”, “dynroute=”) in new stack

[2024-09-23 05:06:14] VERBOSE[24562][C-0000006c] pbx.c: Executing [s@dynroute-191:7] Set(“SIP/9021XXXXXXXX-0000001d”, “dynroute=”) in new stack

[2024-09-23 05:06:14] VERBOSE[24562][C-0000006c] pbx.c: Executing [s@dynroute-191:8] GotoIf(“SIP/9021XXXXXXXX-0000001d”, “1?dynroute-191,1,1”) in new stack

[2024-09-23 05:06:14] VERBOSE[24562][C-0000006c] pbx_builtins.c: Goto (dynroute-191,1,1)

[2024-09-23 05:06:14] VERBOSE[24562][C-0000006c] pbx.c: Executing [1@dynroute-191:1] Goto(“SIP/9021XXXXXXXX-0000001d”, “ext-group,9021XXXXXXXX,1”) in new stack

[2024-09-23 05:06:14] VERBOSE[24562][C-0000006c] pbx_builtins.c: Goto (ext-group,9021XXXXXXXX,1)

[2024-09-23 05:06:14] VERBOSE[24562][C-0000006c] pbx.c: Executing [9021XXXXXXXX@ext-group:1] GotoIf(“SIP/9021XXXXXXXX-0000001d”, “0?cid”) in new stack

[2024-09-23 05:06:14] VERBOSE[24562][C-0000006c] pbx.c: Executing [9021XXXXXXXX@ext-group:2] Set(“SIP/9021XXXXXXXX-0000001d”, “__MCGROUP=9021XXXXXXXX”) in new stack

[2024-09-23 05:06:14] VERBOSE[24562][C-0000006c] pbx.c: Executing [9021XXXXXXXX@ext-group:3] PlayTones(“SIP/9021XXXXXXXX-0000001d”, “ring”) in new stack

[2024-09-23 05:06:14] VERBOSE[24562][C-0000006c] pbx.c: Executing [9021XXXXXXXX@ext-group:4] Progress(“SIP/9021XXXXXXXX-0000001d”, “”) in new stack

[2024-09-23 05:06:14] VERBOSE[24562][C-0000006c] pbx.c: Executing [9021XXXXXXXX@ext-group:5] Macro(“SIP/9021XXXXXXXX-0000001d”, “user-callerid,”) in new stack

[2024-09-23 05:06:14] VERBOSE[24562][C-0000006c] pbx.c: Executing [s@macro-user-callerid:1] Set(“SIP/9021XXXXXXXX-0000001d”, “TOUCH_MONITOR=1727067968.29”) in new stack

[2024-09-23 05:06:14] VERBOSE[24562][C-0000006c] pbx.c: Executing [s@macro-user-callerid:2] Set(“SIP/9021XXXXXXXX-0000001d”, “CHANCONTEXT=”) in new stack

[2024-09-23 05:06:14] VERBOSE[24562][C-0000006c] pbx.c: Executing [s@macro-user-callerid:3] Progress(“SIP/9021XXXXXXXX-0000001d”, “”) in new stack

[2024-09-23 05:06:14] VERBOSE[24562][C-0000006c] pbx.c: Executing [s@macro-user-callerid:4] Set(“SIP/9021XXXXXXXX-0000001d”, “CHANCONTEXT=”) in new stack

[2024-09-23 05:06:14] VERBOSE[24562][C-0000006c] pbx.c: Executing [s@macro-user-callerid:5] Set(“SIP/9021XXXXXXXX-0000001d”, “CHANEXTENCONTEXT=9021XXXXXXXX-0000001d”) in new stack

[2024-09-23 05:06:14] VERBOSE[24562][C-0000006c] pbx.c: Executing [s@macro-user-callerid:6] Set(“SIP/9021XXXXXXXX-0000001d”, “CHANEXTEN=9021XXXXXXXX-0000001d”) in new stack

[2024-09-23 05:06:14] VERBOSE[24562][C-0000006c] pbx.c: Executing [s@macro-user-callerid:7] Set(“SIP/9021XXXXXXXX-0000001d”, “CALLERID(number)=053XXXXXXXX”) in new stack

[2024-09-23 05:06:14] VERBOSE[24562][C-0000006c] pbx.c: Executing [s@macro-user-callerid:8] Set(“SIP/9021XXXXXXXX-0000001d”, “AMPUSER=053XXXXXXXX”) in new stack

[2024-09-23 05:06:14] VERBOSE[24562][C-0000006c] pbx.c: Executing [s@macro-user-callerid:9] Set(“SIP/9021XXXXXXXX-0000001d”, “HOTDESCKCHAN=9021XXXXXXXX-0000001d”) in new stack

[2024-09-23 05:06:14] VERBOSE[24562][C-0000006c] pbx.c: Executing [s@macro-user-callerid:10] Set(“SIP/9021XXXXXXXX-0000001d”, “HOTDESKEXTEN=9021XXXXXXXX”) in new stack

[comtech]

The log is clear that the curl is being called and a response is not provided. Since there is no response the dynamic route value is blank. Can you check on the customcrmapilink server to see if there is record of the attempt.

Really the only things I can think of at this point is that the query server is too busy or the network is having an issue. You would need to setup a trace and watch what happens on a failed query to diagnose why its failing on the network.