FreePBX Distro 15
asterisk 16
PJSIP
D62, D70 phones Firmware version 1.30
I’ve got about 7 phones in a ring group. This afternoon when calls come in, random phones would do a quick half ring, then go off hook on speaker with a busy tone and report call failed on the screen. The call would continue ringing on other phones in the group and could be answered.
The affected phones would continue this behavior until rebooted. Then randomely another phone would start doing the same thing. It’s happened on both D62 and older D70 models.
here’s a quick log snippet from when extension 1102 was displaying the behavior:
271331 [2021-05-24 16:15:55] VERBOSE[18228][C-000002ea] pbx.c: Executing [s@macro-dial:24] ExecIf(“PJSIP/Vi_inbound-00000c3c”, “0?Set(ds=PJSIP/1101/sip:[email protected]:5070;ob&PJSIP/1102/sip:[email protected]:5070;ob&PJSIP/1103/sip:[email protected]:5070;ob&PJSIP/1123/sip:[email protected]:5070;ob&PJSIP/1124/sip:[email protected]:5070;ob&PJSIP/1125/sip:[email protected]:5070;ob&PJSIP/1120/sip:[email protected]:5070;ob,20,HhtrQ(NO_ANSWER)M(auto-blkvm)g)”) in new stack
271332 [2021-05-24 16:15:55] VERBOSE[18228][C-000002ea] pbx.c: Executing [s@macro-dial:25] Dial(“PJSIP/Vi_inbound-00000c3c”, “PJSIP/1101/sip:[email protected]:5070;ob&PJSIP/1102/sip:[email protected]:5070;ob&PJSIP/1103/sip:[email protected]:5070;ob&PJSIP/1123/sip:[email protected]:5070;ob&PJSIP/1124/sip:[email protected]:5070;ob&PJSIP/1125/sip:[email protected]:5070;ob&PJSIP/1120/sip:[email protected]:5070;ob,20,HhtrQ(NO_ANSWER)M(auto-blkvm)b(func-apply-sipheaders^s^1),”) in new stack
271333 [2021-05-24 16:15:55] VERBOSE[18228][C-000002ea] app_stack.c: PJSIP/1102-00000c45 Internal Gosub(func-apply-sipheaders,s,1) start
271334 [2021-05-24 16:15:55] VERBOSE[18228][C-000002ea] pbx.c: Executing [s@func-apply-sipheaders:1] ExecIf(“PJSIP/1102-00000c45”, “1?Set(CHANNEL(hangup_handler_push)=crm-hangup,s,1)”) in new stack
271335 [2021-05-24 16:15:55] VERBOSE[18228][C-000002ea] pbx.c: Executing [s@func-apply-sipheaders:2] NoOp(“PJSIP/1102-00000c45”, “Applying SIP Headers to channel PJSIP/1102-00000c45”) in new stack
271336 [2021-05-24 16:15:55] VERBOSE[18228][C-000002ea] pbx.c: Executing [s@func-apply-sipheaders:3] Set(“PJSIP/1102-00000c45”, “TECH=PJSIP”) in new stack
271337 [2021-05-24 16:15:55] VERBOSE[18228][C-000002ea] pbx.c: Executing [s@func-apply-sipheaders:4] Set(“PJSIP/1102-00000c45”, “SIPHEADERKEYS=Alert-Info”) in new stack
271338 [2021-05-24 16:15:55] VERBOSE[18228][C-000002ea] pbx.c: Executing [s@func-apply-sipheaders:5] While(“PJSIP/1102-00000c45”, “1”) in new stack
271339 [2021-05-24 16:15:55] VERBOSE[18228][C-000002ea] pbx.c: Executing [s@func-apply-sipheaders:6] Set(“PJSIP/1102-00000c45”, “sipheader=Digium”) in new stack
271340 [2021-05-24 16:15:55] VERBOSE[18228][C-000002ea] pbx.c: Executing [s@func-apply-sipheaders:7] ExecIf(“PJSIP/1102-00000c45”, “0?SIPRemoveHeader(Alert-Info:)”) in new stack
271341 [2021-05-24 16:15:55] VERBOSE[18228][C-000002ea] pbx.c: Executing [s@func-apply-sipheaders:8] ExecIf(“PJSIP/1102-00000c45”, “0?Set(PJSIP_HEADER(remove,Alert-Info)=)”) in new stack
271342 [2021-05-24 16:15:55] VERBOSE[18228][C-000002ea] pbx.c: Executing [s@func-apply-sipheaders:9] ExecIf(“PJSIP/1102-00000c45”, “1?Set(sipheader=http://127.0.0.1;info=Digium)”) in new stack
271343 [2021-05-24 16:15:55] VERBOSE[18228][C-000002ea] pbx.c: Executing [s@func-apply-sipheaders:10] ExecIf(“PJSIP/1102-00000c45”, “0?Set(sipheader=http://127.0.0.1http://127.0.0.1;info=Digium)”) in new stack
271344 [2021-05-24 16:15:55] VERBOSE[18228][C-000002ea] pbx.c: Executing [s@func-apply-sipheaders:11] ExecIf(“PJSIP/1102-00000c45”, “0?SIPAddHeader(Alert-Info:http://127.0.0.1;info=Digium)”) in new stack
271345 [2021-05-24 16:15:55] VERBOSE[18228][C-000002ea] pbx.c: Executing [s@func-apply-sipheaders:12] ExecIf(“PJSIP/1102-00000c45”, “1?Set(PJSIP_HEADER(add,Alert-Info)=http://127.0.0.1;info=Digium)”) in new stack
271346 [2021-05-24 16:15:55] VERBOSE[18228][C-000002ea] pbx.c: Executing [s@func-apply-sipheaders:13] EndWhile(“PJSIP/1102-00000c45”, “”) in new stack
271347 [2021-05-24 16:15:55] VERBOSE[18228][C-000002ea] pbx.c: Executing [s@func-apply-sipheaders:5] While(“PJSIP/1102-00000c45”, “0”) in new stack
271348 [2021-05-24 16:15:55] VERBOSE[18228][C-000002ea] pbx.c: Executing [s@func-apply-sipheaders:14] Return(“PJSIP/1102-00000c45”, “”) in new stack
271349 [2021-05-24 16:15:55] VERBOSE[18228][C-000002ea] app_stack.c: Spawn extension (from-internal, 600, 1) exited non-zero on ‘PJSIP/1102-00000c45’
271350 [2021-05-24 16:15:55] VERBOSE[18228][C-000002ea] app_stack.c: PJSIP/1102-00000c45 Internal Gosub(func-apply-sipheaders,s,1) complete GOSUB_RETVAL=
271351 [2021-05-24 16:15:55] VERBOSE[18228][C-000002ea] app_dial.c: Called PJSIP/1102/sip:[email protected]:5070;ob
271352 [2021-05-24 16:15:55] VERBOSE[18228][C-000002ea] app_dial.c: PJSIP/1102-00000c45 connected line has changed. Saving it until answer for PJSIP/Vi_inbound-00000c3c
271837 [2021-05-24 16:16:05] VERBOSE[18160][C-000002e8] app_stack.c: PJSIP/1102-00000c3e Internal Gosub(crm-hangup,s,1) start
271838 [2021-05-24 16:16:05] VERBOSE[18160][C-000002e8] pbx.c: Executing [s@crm-hangup:1] NoOp(“PJSIP/1102-00000c3e”, “Sending Hangup to CRM”) in new stack
271839 [2021-05-24 16:16:05] VERBOSE[18160][C-000002e8] pbx.c: Executing [s@crm-hangup:2] NoOp(“PJSIP/1102-00000c3e”, “HANGUP CAUSE: 19”) in new stack
271840 [2021-05-24 16:16:05] VERBOSE[18160][C-000002e8] pbx.c: Executing [s@crm-hangup:3] ExecIf(“PJSIP/1102-00000c3e”, “0?Set(__CRM_VOICEMAIL=)”) in new stack
271841 [2021-05-24 16:16:05] VERBOSE[18160][C-000002e8] pbx.c: Executing [s@crm-hangup:4] NoOp(“PJSIP/1102-00000c3e”, “MASTER CHANNEL: 1621887351.3615 = 1621887331.3610”) in new stack
271842 [2021-05-24 16:16:05] VERBOSE[18160][C-000002e8] pbx.c: Executing [s@crm-hangup:5] GotoIf(“PJSIP/1102-00000c3e”, “1?return”) in new stack
271843 [2021-05-24 16:16:05] VERBOSE[18160][C-000002e8] pbx.c: Executing [s@crm-hangup:8] Return(“PJSIP/1102-00000c3e”, “”) in new stack
271844 [2021-05-24 16:16:05] VERBOSE[18160][C-000002e8] app_stack.c: Spawn extension (from-internal, 600, 1) exited non-zero on ‘PJSIP/1102-00000c3e’
271845 [2021-05-24 16:16:05] VERBOSE[18160][C-000002e8] app_stack.c: PJSIP/1102-00000c3e Internal Gosub(crm-hangup,s,1) complete GOSUB_RETVAL=
271911 [2021-05-24 16:16:08] VERBOSE[18370][C-000002eb] pbx.c: Executing [600@ext-group:18] Macro(“PJSIP/Vi_Primary_Outbound-00000c4b”, “dial,20,HhTtrQ(NO_ANSWER),1101-1102-1103-1123-1124-1125-1120”) in new stack
271912 [2021-05-24 16:16:08] VERBOSE[18370][C-000002eb] res_agi.c: agi://127.0.0.1/dialparties.agi: Added extension 1102 to extension map
271913 [2021-05-24 16:16:08] VERBOSE[18370][C-000002eb] res_agi.c: agi://127.0.0.1/dialparties.agi: Extension 1102 cf is disabled
271914 [2021-05-24 16:16:08] VERBOSE[18370][C-000002eb] res_agi.c: agi://127.0.0.1/dialparties.agi: Extension 1102 do not disturb is disabled
271915 [2021-05-24 16:16:08] VERBOSE[18370][C-000002eb] res_agi.c: agi://127.0.0.1/dialparties.agi: Discovered PJSIP Endpoint PJSIP/1102
271916 [2021-05-24 16:16:08] VERBOSE[18370][C-000002eb] res_agi.c: agi://127.0.0.1/dialparties.agi: Ended up with real PJSIP Dial string PJSIP/1102/sip:[email protected]:5070;ob
271917 [2021-05-24 16:16:08] VERBOSE[18370][C-000002eb] res_agi.c: agi://127.0.0.1/dialparties.agi: dbset CALLTRACE/1102 to 19734533066
271918 [2021-05-24 16:16:08] VERBOSE[18370][C-000002eb] res_agi.c: agi://127.0.0.1/dialparties.agi: Filtered ARG3: 1101-1102-1103-1123-1124-1125-1120
271919 [2021-05-24 16:16:08] VERBOSE[18370][C-000002eb] pbx.c: Executing [s@macro-dial:16] Set(“PJSIP/Vi_Primary_Outbound-00000c4b”, “__EXTTOCALL=1102”) in new stack
271920 [2021-05-24 16:16:08] VERBOSE[18370][C-000002eb] pbx.c: Executing [s@macro-dial:17] NoOp(“PJSIP/Vi_Primary_Outbound-00000c4b”, “Working with 1102”) in new stack
271921 [2021-05-24 16:16:08] VERBOSE[18370][C-000002eb] pbx.c: Executing [s@macro-dial:24] ExecIf(“PJSIP/Vi_Primary_Outbound-00000c4b”, “0?Set(ds=PJSIP/1101/sip:[email protected]:5070;ob&PJSIP/1102/sip:[email protected]:5070;ob&PJSIP/1103/sip:[email protected]:5070;ob&PJSIP/1123/sip:[email protected]:5070;ob&PJSIP/1124/sip:[email protected]:5070;ob&PJSIP/1125/sip:[email protected]:5070;ob&PJSIP/1120/sip:[email protected]:5070;ob,20,HhtrQ(NO_ANSWER)M(auto-blkvm)g)”) in new stack
271922 [2021-05-24 16:16:08] VERBOSE[18370][C-000002eb] pbx.c: Executing [s@macro-dial:25] Dial(“PJSIP/Vi_Primary_Outbound-00000c4b”, “PJSIP/1101/sip:[email protected]:5070;ob&PJSIP/1102/sip:[email protected]:5070;ob&PJSIP/1103/sip:[email protected]:5070;ob&PJSIP/1123/sip:[email protected]:5070;ob&PJSIP/1124/sip:[email protected]:5070;ob&PJSIP/1125/sip:[email protected]:5070;ob&PJSIP/1120/sip:[email protected]:5070;ob,20,HhtrQ(NO_ANSWER)M(auto-blkvm)b(func-apply-sipheaders^s^1),”) in new stack
271923 [2021-05-24 16:16:08] VERBOSE[18370][C-000002eb] app_stack.c: PJSIP/1102-00000c4e Internal Gosub(func-apply-sipheaders,s,1) start
271924 [2021-05-24 16:16:08] VERBOSE[18370][C-000002eb] pbx.c: Executing [s@func-apply-sipheaders:1] ExecIf(“PJSIP/1102-00000c4e”, “1?Set(CHANNEL(hangup_handler_push)=crm-hangup,s,1)”) in new stack
271925 [2021-05-24 16:16:08] VERBOSE[18370][C-000002eb] pbx.c: Executing [s@func-apply-sipheaders:2] NoOp(“PJSIP/1102-00000c4e”, “Applying SIP Headers to channel PJSIP/1102-00000c4e”) in new stack
271926 [2021-05-24 16:16:08] VERBOSE[18370][C-000002eb] pbx.c: Executing [s@func-apply-sipheaders:3] Set(“PJSIP/1102-00000c4e”, “TECH=PJSIP”) in new stack
271927 [2021-05-24 16:16:08] VERBOSE[18370][C-000002eb] pbx.c: Executing [s@func-apply-sipheaders:4] Set(“PJSIP/1102-00000c4e”, “SIPHEADERKEYS=Alert-Info”) in new stack
271928 [2021-05-24 16:16:08] VERBOSE[18370][C-000002eb] pbx.c: Executing [s@func-apply-sipheaders:5] While(“PJSIP/1102-00000c4e”, “1”) in new stack
271929 [2021-05-24 16:16:08] VERBOSE[18370][C-000002eb] pbx.c: Executing [s@func-apply-sipheaders:6] Set(“PJSIP/1102-00000c4e”, “sipheader=Digium”) in new stack
271930 [2021-05-24 16:16:08] VERBOSE[18370][C-000002eb] pbx.c: Executing [s@func-apply-sipheaders:7] ExecIf(“PJSIP/1102-00000c4e”, “0?SIPRemoveHeader(Alert-Info:)”) in new stack
271931 [2021-05-24 16:16:08] VERBOSE[18370][C-000002eb] pbx.c: Executing [s@func-apply-sipheaders:8] ExecIf(“PJSIP/1102-00000c4e”, “0?Set(PJSIP_HEADER(remove,Alert-Info)=)”) in new stack
271932 [2021-05-24 16:16:08] VERBOSE[18370][C-000002eb] pbx.c: Executing [s@func-apply-sipheaders:9] ExecIf(“PJSIP/1102-00000c4e”, “1?Set(sipheader=http://127.0.0.1;info=Digium)”) in new stack
271933 [2021-05-24 16:16:08] VERBOSE[18370][C-000002eb] pbx.c: Executing [s@func-apply-sipheaders:10] ExecIf(“PJSIP/1102-00000c4e”, “0?Set(sipheader=http://127.0.0.1http://127.0.0.1;info=Digium)”) in new stack
271934 [2021-05-24 16:16:08] VERBOSE[18370][C-000002eb] pbx.c: Executing [s@func-apply-sipheaders:11] ExecIf(“PJSIP/1102-00000c4e”, “0?SIPAddHeader(Alert-Info:http://127.0.0.1;info=Digium)”) in new stack
271935 [2021-05-24 16:16:08] VERBOSE[18370][C-000002eb] pbx.c: Executing [s@func-apply-sipheaders:12] ExecIf(“PJSIP/1102-00000c4e”, “1?Set(PJSIP_HEADER(add,Alert-Info)=http://127.0.0.1;info=Digium)”) in new stack
271936 [2021-05-24 16:16:08] VERBOSE[18370][C-000002eb] pbx.c: Executing [s@func-apply-sipheaders:13] EndWhile(“PJSIP/1102-00000c4e”, “”) in new stack
271937 [2021-05-24 16:16:08] VERBOSE[18370][C-000002eb] pbx.c: Executing [s@func-apply-sipheaders:5] While(“PJSIP/1102-00000c4e”, “0”) in new stack
271938 [2021-05-24 16:16:08] VERBOSE[18370][C-000002eb] pbx.c: Executing [s@func-apply-sipheaders:14] Return(“PJSIP/1102-00000c4e”, “”) in new stack
271939 [2021-05-24 16:16:08] VERBOSE[18370][C-000002eb] app_stack.c: Spawn extension (from-internal, 600, 1) exited non-zero on ‘PJSIP/1102-00000c4e’
271940 [2021-05-24 16:16:08] VERBOSE[18370][C-000002eb] app_stack.c: PJSIP/1102-00000c4e Internal Gosub(func-apply-sipheaders,s,1) complete GOSUB_RETVAL=
271941 [2021-05-24 16:16:08] VERBOSE[18370][C-000002eb] app_dial.c: Called PJSIP/1102/sip:[email protected]:5070;ob
271942 [2021-05-24 16:16:08] VERBOSE[18370][C-000002eb] app_dial.c: PJSIP/1102-00000c4e connected line has changed. Saving it until answer for PJSIP/Vi_Primary_Outbound-00000c4b
272278 [2021-05-24 16:16:13] VERBOSE[18370][C-000002eb] app_stack.c: PJSIP/1102-00000c4e Internal Gosub(crm-hangup,s,1) start
272279 [2021-05-24 16:16:13] VERBOSE[18370][C-000002eb] pbx.c: Executing [s@crm-hangup:1] NoOp(“PJSIP/1102-00000c4e”, “Sending Hangup to CRM”) in new stack
272280 [2021-05-24 16:16:13] VERBOSE[18370][C-000002eb] pbx.c: Executing [s@crm-hangup:2] NoOp(“PJSIP/1102-00000c4e”, “HANGUP CAUSE: 0”) in new stack
272281 [2021-05-24 16:16:13] VERBOSE[18370][C-000002eb] pbx.c: Executing [s@crm-hangup:3] ExecIf(“PJSIP/1102-00000c4e”, “0?Set(__CRM_VOICEMAIL=)”) in new stack
272282 [2021-05-24 16:16:13] VERBOSE[18370][C-000002eb] pbx.c: Executing [s@crm-hangup:4] NoOp(“PJSIP/1102-00000c4e”, “MASTER CHANNEL: 1621887368.3631 = 1621887362.3628”) in new stack
272283 [2021-05-24 16:16:13] VERBOSE[18370][C-000002eb] pbx.c: Executing [s@crm-hangup:5] GotoIf(“PJSIP/1102-00000c4e”, “1?return”) in new stack
272284 [2021-05-24 16:16:13] VERBOSE[18370][C-000002eb] pbx.c: Executing [s@crm-hangup:8] Return(“PJSIP/1102-00000c4e”, “”) in new stack
272285 [2021-05-24 16:16:13] VERBOSE[18370][C-000002eb] app_stack.c: Spawn extension (from-internal, 600, 1) exited non-zero on ‘PJSIP/1102-00000c4e’
272286 [2021-05-24 16:16:13] VERBOSE[18370][C-000002eb] app_stack.c: PJSIP/1102-00000c4e Internal Gosub(crm-hangup,s,1) complete GOSUB_RETVAL=
272372 [2021-05-24 16:16:15] VERBOSE[18228][C-000002ea] app_stack.c: PJSIP/1102-00000c45 Internal Gosub(crm-hangup,s,1) start
272373 [2021-05-24 16:16:15] VERBOSE[18228][C-000002ea] pbx.c: Executing [s@crm-hangup:1] NoOp(“PJSIP/1102-00000c45”, “Sending Hangup to CRM”) in new stack
272374 [2021-05-24 16:16:15] VERBOSE[18228][C-000002ea] pbx.c: Executing [s@crm-hangup:2] NoOp(“PJSIP/1102-00000c45”, “HANGUP CAUSE: 0”) in new stack
272375 [2021-05-24 16:16:15] VERBOSE[18228][C-000002ea] pbx.c: Executing [s@crm-hangup:3] ExecIf(“PJSIP/1102-00000c45”, “0?Set(__CRM_VOICEMAIL=)”) in new stack
272376 [2021-05-24 16:16:15] VERBOSE[18228][C-000002ea] pbx.c: Executing [s@crm-hangup:4] NoOp(“PJSIP/1102-00000c45”, “MASTER CHANNEL: 1621887355.3622 = 1621887340.3613”) in new stack
272377 [2021-05-24 16:16:15] VERBOSE[18228][C-000002ea] pbx.c: Executing [s@crm-hangup:5] GotoIf(“PJSIP/1102-00000c45”, “1?return”) in new stack
272378 [2021-05-24 16:16:15] VERBOSE[18228][C-000002ea] pbx.c: Executing [s@crm-hangup:8] Return(“PJSIP/1102-00000c45”, “”) in new stack
272379 [2021-05-24 16:16:15] VERBOSE[18228][C-000002ea] app_stack.c: Spawn extension (from-internal, 600, 1) exited non-zero on ‘PJSIP/1102-00000c45’
272380 [2021-05-24 16:16:15] VERBOSE[18228][C-000002ea] app_stack.c: PJSIP/1102-00000c45 Internal Gosub(crm-hangup,s,1) complete GOSUB_RETVAL=