Service unavailable for a specific extension

Matthai · October 10, 2023, 5:30pm

I have very weird problem. I have RasPBX installed and I am using old Aastra SIP phone and Zoiper on mobile phone and on computer (three extensions). All these devices are connected through VPN. On a computer and mobile phone I have Wireguard client installed, but old SIP phone is connected to VPN through iNet.Gli Shadow router, which is a small ARM-based pocket size device.

And just a note (possibly important), I have disabled UDP and enabled TCP in FreePBX settings.

These are the extensions:

7000: Aastra SIP phone
3000: Zoiper on mobile phone
1000: Zoiper on computer

First weird thing is, that Aastra phone says it is connected to the RasPBX server. Status on a phone is “Registered”. I can also call from this extension (7000) to the other two extensions (1000 and 3000) and all is working normally.

But when I go to the Asterisk Info (in FreePBX web interface), it says that this extension (7000) is OFFLINE, while the other two (1000 and 3000) are ONLINE.

But the real problem is, that I can not call to extension 7000. 1000 and 3000 can call each other. 7000 can call them too. But 1000 and 3000 can not call 7000! They just get the message “Service Unavailable”.

I thought it may be some router problem, so I connected computer (via Ethernet cable) to VPN through iNet.Gli Shadow router. Yes, I disabled VPN client on a computer first, so VPN connection was done through router. Guess what - I was able to call from computer (3000) to mobile phone (1000) and vice versa without any problems. So it must be something on that extension 7000, that is not accepting calls from others. But what?

I went through setting, but unfortunately I was not able to find anything suspicious. Here are the relevant logs, if anyone has an idea what is going on:

14483	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [7000@from-internal:1] GotoIf("PJSIP/1000-00000042", "1?ext-local,7000,1:followme-check,7000,1") in new stack	
14484	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [7000@ext-local:1] Set("PJSIP/1000-00000042", "__RINGTIMER=15") in new stack	
14485	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [7000@ext-local:2] ExecIf("PJSIP/1000-00000042", "0?Set(__CWIGNORE=)") in new stack	
14486	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [7000@ext-local:3] Macro("PJSIP/1000-00000042", "exten-vm,novm,7000,0,0,0") in new stack	
14487	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@macro-exten-vm:1] Macro("PJSIP/1000-00000042", "user-callerid,") in new stack	
14488	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@macro-user-callerid:1] Set("PJSIP/1000-00000042", "TOUCH_MONITOR=1696955256.119") in new stack	
14489	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@macro-user-callerid:2] Set("PJSIP/1000-00000042", "CHANCONTEXT=") in new stack	
14490	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@macro-user-callerid:3] Set("PJSIP/1000-00000042", "CHANCONTEXT=") in new stack	
14491	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@macro-user-callerid:4] Set("PJSIP/1000-00000042", "CHANEXTENCONTEXT=1000-00000042") in new stack	
14492	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@macro-user-callerid:5] Set("PJSIP/1000-00000042", "CHANEXTEN=1000-00000042") in new stack	
14493	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@macro-user-callerid:6] Set("PJSIP/1000-00000042", "CALLERID(number)=1000") in new stack	
14494	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@macro-user-callerid:7] Set("PJSIP/1000-00000042", "AMPUSER=1000") in new stack	
14495	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@macro-user-callerid:8] Set("PJSIP/1000-00000042", "HOTDESCKCHAN=1000-00000042") in new stack	
14496	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@macro-user-callerid:9] Set("PJSIP/1000-00000042", "HOTDESKEXTEN=1000") in new stack	
14497	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@macro-user-callerid:10] Set("PJSIP/1000-00000042", "HOTDESKCALL=0") in new stack	
14498	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@macro-user-callerid:11] ExecIf("PJSIP/1000-00000042", "0?Set(HOTDESKCALL=1)") in new stack	
14499	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@macro-user-callerid:12] ExecIf("PJSIP/1000-00000042", "0?Set(CALLERID(name)=)") in new stack	
14500	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@macro-user-callerid:13] GotoIf("PJSIP/1000-00000042", "0?report") in new stack	
14501	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@macro-user-callerid:14] ExecIf("PJSIP/1000-00000042", "1?Set(REALCALLERIDNUM=1000)") in new stack	
14502	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@macro-user-callerid:15] Set("PJSIP/1000-00000042", "AMPUSER=1000") in new stack	
14503	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@macro-user-callerid:16] GotoIf("PJSIP/1000-00000042", "0?limit") in new stack	
14504	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@macro-user-callerid:17] Set("PJSIP/1000-00000042", "AMPUSERCIDNAME=Matej - racunalnik") in new stack	
14505	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@macro-user-callerid:18] ExecIf("PJSIP/1000-00000042", "0?Set(__CIDMASQUERADING=TRUE)") in new stack	
14506	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@macro-user-callerid:19] GotoIf("PJSIP/1000-00000042", "0?report") in new stack	
14507	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@macro-user-callerid:20] Set("PJSIP/1000-00000042", "AMPUSERCID=1000") in new stack	
14508	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@macro-user-callerid:21] Set("PJSIP/1000-00000042", "__DIAL_OPTIONS=HhTtr") in new stack	
14509	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@macro-user-callerid:22] Set("PJSIP/1000-00000042", "CALLERID(all)="Matej - racunalnik" <1000>") in new stack	
14510	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@macro-user-callerid:23] ExecIf("PJSIP/1000-00000042", "0?Set(CUSDIAL=7000)") in new stack	
14511	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@macro-user-callerid:24] ExecIf("PJSIP/1000-00000042", "0?Set(CALLERID(all)="Matej - racunalnik" <1000>)") in new stack	
14512	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@macro-user-callerid:25] GotoIf("PJSIP/1000-00000042", "0?limit") in new stack	
14513	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@macro-user-callerid:26] ExecIf("PJSIP/1000-00000042", "0?Set(GROUP(concurrency_limit)=1000)") in new stack	
14514	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@macro-user-callerid:27] NoOp("PJSIP/1000-00000042", "Macro Depth is 2") in new stack	
14515	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@macro-user-callerid:28] GotoIf("PJSIP/1000-00000042", "1?report2:macroerror") in new stack	
14516	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@macro-user-callerid:29] GotoIf("PJSIP/1000-00000042", "0?continue") in new stack	
14517	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@macro-user-callerid:30] Set("PJSIP/1000-00000042", "__TTL=64") in new stack	
14518	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@macro-user-callerid:31] GotoIf("PJSIP/1000-00000042", "1?continue") in new stack	
14519	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@macro-user-callerid:47] Set("PJSIP/1000-00000042", "CALLERID(number)=1000") in new stack	
14520	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@macro-user-callerid:48] Set("PJSIP/1000-00000042", "CALLERID(name)=Matej - racunalnik") in new stack	
14521	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@macro-user-callerid:49] GotoIf("PJSIP/1000-00000042", "0?cnum") in new stack	
14522	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@macro-user-callerid:50] Set("PJSIP/1000-00000042", "CDR(cnam)=Matej - racunalnik") in new stack	
14523	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@macro-user-callerid:51] Set("PJSIP/1000-00000042", "CDR(cnum)=1000") in new stack	
14524	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@macro-user-callerid:52] Set("PJSIP/1000-00000042", "CHANNEL(language)=en") in new stack	
14525	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@macro-exten-vm:2] Set("PJSIP/1000-00000042", "RingGroupMethod=none") in new stack	
14526	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@macro-exten-vm:3] Set("PJSIP/1000-00000042", "__EXTTOCALL=7000") in new stack	
14527	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@macro-exten-vm:4] Set("PJSIP/1000-00000042", "__PICKUPMARK=7000") in new stack	
14528	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@macro-exten-vm:5] Set("PJSIP/1000-00000042", "RT=") in new stack	
14529	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@macro-exten-vm:6] ExecIf("PJSIP/1000-00000042", "0?Macro(vm,novm,DIRECTDIAL,)") in new stack	
14530	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@macro-exten-vm:7] ExecIf("PJSIP/1000-00000042", "0?MacroExit()") in new stack	
14531	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@macro-exten-vm:8] ExecIf("PJSIP/1000-00000042", "0?Gosub(ext-intercom,*807000,1())") in new stack	
14532	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@macro-exten-vm:9] ExecIf("PJSIP/1000-00000042", "0?MacroExit()") in new stack	
14533	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@macro-exten-vm:10] ExecIf("PJSIP/1000-00000042", "0?ChanSpy(PJSIP/7000,q)") in new stack	
14534	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@macro-exten-vm:11] ExecIf("PJSIP/1000-00000042", "0?MacroExit()") in new stack	
14535	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@macro-exten-vm:12] ExecIf("PJSIP/1000-00000042", "0?Macro(vm,novm,DIRECTDIAL,)") in new stack	
14536	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@macro-exten-vm:13] ExecIf("PJSIP/1000-00000042", "0?MacroExit()") in new stack	
14537	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@macro-exten-vm:14] ExecIf("PJSIP/1000-00000042", "0?Gosub(ext-intercom,*807000,1())") in new stack	
14538	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@macro-exten-vm:15] ExecIf("PJSIP/1000-00000042", "0?MacroExit()") in new stack	
14539	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@macro-exten-vm:16] ExecIf("PJSIP/1000-00000042", "0?ChanSpy(PJSIP/7000,q)") in new stack	
14540	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@macro-exten-vm:17] ExecIf("PJSIP/1000-00000042", "0?MacroExit()") in new stack	
14541	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@macro-exten-vm:18] Gosub("PJSIP/1000-00000042", "sub-record-check,s,1(exten,7000,dontcare)") in new stack	
14542	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@sub-record-check:1] GotoIf("PJSIP/1000-00000042", "0?initialized") in new stack	
14543	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@sub-record-check:2] Set("PJSIP/1000-00000042", "__REC_STATUS=INITIALIZED") in new stack	
14544	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@sub-record-check:3] Set("PJSIP/1000-00000042", "NOW=1696955256") in new stack	
14545	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@sub-record-check:4] Set("PJSIP/1000-00000042", "__DAY=10") in new stack	
14546	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@sub-record-check:5] Set("PJSIP/1000-00000042", "__MONTH=10") in new stack	
14547	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@sub-record-check:6] Set("PJSIP/1000-00000042", "__YEAR=2023") in new stack	
14548	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@sub-record-check:7] Set("PJSIP/1000-00000042", "__TIMESTR=20231010-182736") in new stack	
14549	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@sub-record-check:8] Set("PJSIP/1000-00000042", "__FROMEXTEN=1000") in new stack	
14550	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@sub-record-check:9] Set("PJSIP/1000-00000042", "__MON_FMT=wav") in new stack	
14551	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@sub-record-check:10] NoOp("PJSIP/1000-00000042", "Recordings initialized") in new stack	
14552	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@sub-record-check:11] ExecIf("PJSIP/1000-00000042", "0?Set(ARG3=dontcare)") in new stack	
14553	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@sub-record-check:12] Set("PJSIP/1000-00000042", "REC_POLICY_MODE_SAVE=") in new stack	
14554	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@sub-record-check:13] ExecIf("PJSIP/1000-00000042", "0?Set(REC_STATUS=NO)") in new stack	
14555	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@sub-record-check:14] GotoIf("PJSIP/1000-00000042", "5?checkaction") in new stack	
14556	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@sub-record-check:17] GotoIf("PJSIP/1000-00000042", "1?sub-record-check,exten,1") in new stack	
14557	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [exten@sub-record-check:1] NoOp("PJSIP/1000-00000042", "Exten Recording Check between 1000 and 7000") in new stack	
14558	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [exten@sub-record-check:2] Set("PJSIP/1000-00000042", "CALLTYPE=internal") in new stack	
14559	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [exten@sub-record-check:3] ExecIf("PJSIP/1000-00000042", "0?Set(CALLTYPE=)") in new stack	
14560	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [exten@sub-record-check:4] Set("PJSIP/1000-00000042", "CALLEE=dontcare") in new stack	
14561	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [exten@sub-record-check:5] ExecIf("PJSIP/1000-00000042", "0?Set(CALLEE=dontcare)") in new stack	
14562	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [exten@sub-record-check:6] GotoIf("PJSIP/1000-00000042", "0?callee") in new stack	
14563	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [exten@sub-record-check:7] GotoIf("PJSIP/1000-00000042", "1?caller") in new stack	
14564	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [exten@sub-record-check:13] Set("PJSIP/1000-00000042", "RECMODE=dontcare") in new stack	
14565	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [exten@sub-record-check:14] Set("PJSIP/1000-00000042", "CALLERRECMODE=dontcare") in new stack	
14566	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [exten@sub-record-check:15] Set("PJSIP/1000-00000042", "CALEERECMODE=dontcare") in new stack	
14567	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [exten@sub-record-check:16] GotoIf("PJSIP/1000-00000042", "0?processnormal") in new stack	
14568	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [exten@sub-record-check:17] ExecIf("PJSIP/1000-00000042", "0?Set(RECMODE=dontcare)") in new stack	
14569	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [exten@sub-record-check:18] ExecIf("PJSIP/1000-00000042", "0?Set(RECMODE=dontcare)") in new stack	
14570	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [exten@sub-record-check:19] ExecIf("PJSIP/1000-00000042", "0?Set(RECMODE=dontcare)") in new stack	
14571	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [exten@sub-record-check:20] ExecIf("PJSIP/1000-00000042", "0?Set(RECMODE=dontcare)") in new stack	
14572	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [exten@sub-record-check:21] ExecIf("PJSIP/1000-00000042", "0?Set(RECMODE=dontcare)") in new stack	
14573	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [exten@sub-record-check:22] ExecIf("PJSIP/1000-00000042", "1?Set(RECMODE=dontcare)") in new stack	
14574	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [exten@sub-record-check:23] Gosub("PJSIP/1000-00000042", "recordcheck,1(dontcare,internal,7000)") in new stack	
14575	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [recordcheck@sub-record-check:1] NoOp("PJSIP/1000-00000042", "Starting recording check against dontcare") in new stack	
14576	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [recordcheck@sub-record-check:2] Goto("PJSIP/1000-00000042", "dontcare") in new stack	
14577	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [recordcheck@sub-record-check:3] Return("PJSIP/1000-00000042", "") in new stack	
14578	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [exten@sub-record-check:24] Return("PJSIP/1000-00000042", "") in new stack	
14579	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@macro-exten-vm:19] GotoIf("PJSIP/1000-00000042", "1?macrodial") in new stack	
14580	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@macro-exten-vm:25] GosubIf("PJSIP/1000-00000042", "0?clrheader,1()") in new stack	
14581	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@macro-exten-vm:26] Macro("PJSIP/1000-00000042", "dial-one,,HhTtr,7000") in new stack	
14582	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@macro-dial-one:1] Set("PJSIP/1000-00000042", "DEXTEN=7000") in new stack	
14583	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@macro-dial-one:2] ExecIf("PJSIP/1000-00000042", "0?Set(__EXTTOCALL=7000)") in new stack	
14584	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@macro-dial-one:3] Set("PJSIP/1000-00000042", "DIALSTATUS_CW=") in new stack	
14585	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@macro-dial-one:4] GosubIf("PJSIP/1000-00000042", "0?screen,1()") in new stack	
14586	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@macro-dial-one:5] GosubIf("PJSIP/1000-00000042", "0?cf,1()") in new stack	
14587	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@macro-dial-one:6] GotoIf("PJSIP/1000-00000042", "1?skip1") in new stack	
14588	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@macro-dial-one:9] GotoIf("PJSIP/1000-00000042", "0?nodial") in new stack	
14589	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@macro-dial-one:10] GotoIf("PJSIP/1000-00000042", "0?continue") in new stack	
14590	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@macro-dial-one:11] Set("PJSIP/1000-00000042", "EXTHASCW=ENABLED") in new stack	
14591	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@macro-dial-one:12] GotoIf("PJSIP/1000-00000042", "0?next1:cwinusebusy") in new stack	
14592	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@macro-dial-one:24] GotoIf("PJSIP/1000-00000042", "0?next3:continue") in new stack	
14593	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@macro-dial-one:26] GotoIf("PJSIP/1000-00000042", "0?nodial") in new stack	
14594	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@macro-dial-one:27] GosubIf("PJSIP/1000-00000042", "1?dstring,1():dlocal,1()") in new stack	
14595	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [dstring@macro-dial-one:1] Set("PJSIP/1000-00000042", "DSTRING=") in new stack	
14596	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [dstring@macro-dial-one:2] Set("PJSIP/1000-00000042", "DEVICES=7000") in new stack	
14597	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [dstring@macro-dial-one:3] ExecIf("PJSIP/1000-00000042", "0?Return()") in new stack	
14598	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [dstring@macro-dial-one:4] ExecIf("PJSIP/1000-00000042", "0?Set(DEVICES=000)") in new stack	
14599	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [dstring@macro-dial-one:5] Set("PJSIP/1000-00000042", "LOOPCNT=1") in new stack	
14600	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [dstring@macro-dial-one:6] Set("PJSIP/1000-00000042", "ITER=1") in new stack	
14601	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [dstring@macro-dial-one:7] Set("PJSIP/1000-00000042", "THISDIAL=PJSIP/7000") in new stack	
14602	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [dstring@macro-dial-one:8] GotoIf("PJSIP/1000-00000042", "0?docheck") in new stack	
14603	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [dstring@macro-dial-one:9] NoOp("PJSIP/1000-00000042", "Debug: Found PJSIP Destination PJSIP/7000") in new stack	
14604	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [dstring@macro-dial-one:10] GotoIf("PJSIP/1000-00000042", "0?doset") in new stack	
14605	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [dstring@macro-dial-one:11] NoOp("PJSIP/1000-00000042", "Debug: Updating PJSIP Destination with PJSIP_DIAL_CONTACTS") in new stack	
14606	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [dstring@macro-dial-one:12] Set("PJSIP/1000-00000042", "THISDIAL=") in new stack	
14607	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [dstring@macro-dial-one:13] ExecIf("PJSIP/1000-00000042", "1?Set(DIALSTATUS=CHANUNAVAIL)") in new stack	
14608	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [dstring@macro-dial-one:14] GotoIf("PJSIP/1000-00000042", "1?skipset") in new stack	
14609	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [dstring@macro-dial-one:16] Set("PJSIP/1000-00000042", "ITER=2") in new stack	
14610	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [dstring@macro-dial-one:17] GotoIf("PJSIP/1000-00000042", "0?begin") in new stack	
14611	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [dstring@macro-dial-one:18] ExecIf("PJSIP/1000-00000042", "1?Return()") in new stack	
14612	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@macro-dial-one:28] GotoIf("PJSIP/1000-00000042", "1?nodial") in new stack	
14613	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@macro-dial-one:60] NoOp("PJSIP/1000-00000042", "") in new stack	
14614	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@macro-dial-one:61] ExecIf("PJSIP/1000-00000042", "0?Set(DIALSTATUS=NOANSWER)") in new stack	
14615	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@macro-dial-one:62] NoOp("PJSIP/1000-00000042", "Returned from dial-one with nothing to call and DIALSTATUS: CHANUNAVAIL") in new stack	
14616	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@macro-dial-one:63] MacroExit("PJSIP/1000-00000042", "") in new stack	
14617	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@macro-exten-vm:27] Set("PJSIP/1000-00000042", "SV_DIALSTATUS=CHANUNAVAIL") in new stack	
14618	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@macro-exten-vm:28] GosubIf("PJSIP/1000-00000042", "0?docfu,1()") in new stack	
14619	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@macro-exten-vm:29] GosubIf("PJSIP/1000-00000042", "0?docfb,1()") in new stack	
14620	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@macro-exten-vm:30] Set("PJSIP/1000-00000042", "DIALSTATUS=CHANUNAVAIL") in new stack	
14621	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@macro-exten-vm:31] ExecIf("PJSIP/1000-00000042", "0?MacroExit()") in new stack	
14622	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@macro-exten-vm:32] GotoIf("PJSIP/1000-00000042", "1?s-CHANUNAVAIL,1") in new stack	
14623	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s-CHANUNAVAIL@macro-exten-vm:1] GotoIf("PJSIP/1000-00000042", "0?exit,1") in new stack	
14624	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s-CHANUNAVAIL@macro-exten-vm:2] PlayTones("PJSIP/1000-00000042", "congestion") in new stack	
14625	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s-CHANUNAVAIL@macro-exten-vm:3] Congestion("PJSIP/1000-00000042", "10") in new stack	
14626	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] app_macro.c: Spawn extension (macro-exten-vm, s-CHANUNAVAIL, 3) exited non-zero on 'PJSIP/1000-00000042' in macro 'exten-vm'	
14627	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Spawn extension (ext-local, 7000, 3) exited non-zero on 'PJSIP/1000-00000042'	
14628	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [h@ext-local:1] Macro("PJSIP/1000-00000042", "hangupcall,") in new stack	
14629	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@macro-hangupcall:1] GotoIf("PJSIP/1000-00000042", "1?theend") in new stack	
14630	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@macro-hangupcall:3] ExecIf("PJSIP/1000-00000042", "0?Set(CDR(recordingfile)=)") in new stack	
14631	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Executing [s@macro-hangupcall:4] Hangup("PJSIP/1000-00000042", "") in new stack	
14632	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] app_macro.c: Spawn extension (macro-hangupcall, s, 4) exited non-zero on 'PJSIP/1000-00000042' in macro 'hangupcall'	
14633	[2023-10-10 18:27:36] VERBOSE[18859][C-00000048] pbx.c: Spawn extension (ext-local, h, 1) exited non-zero on 'PJSIP/1000-00000042'	
14634	[2023-10-10 18:27:36] VERBOSE[16451] res_pjsip_registrar.c: Removed contact 'sip:[email protected]:38013;transport=TCP;rinstance=48302d8f72980734' from AOR '1000' due to shutdown	
14635	[2023-10-10 18:27:36] VERBOSE[16451] res_pjsip/pjsip_options.c: Contact 1000/sip:[email protected]:38013;transport=TCP;rinstance=48302d8f72980734 has been deleted	
14636	[2023-10-10 18:27:36] VERBOSE[16451] res_pjsip/pjsip_configuration.c: Endpoint 1000 is now Unreachable	
14637	[2023-10-10 18:27:36] VERBOSE[16451] res_pjsip_registrar.c: Attempted to remove non-existent contact 'sip:[email protected]:42629;transport=TCP;rinstance=48302d8f72980734' from AOR '1000' by request	
14638	[2023-10-10 18:27:37] VERBOSE[16451] res_pjsip_registrar.c: Added contact 'sip:[email protected]:42629;transport=TCP;rinstance=d2288cdbc79c3e71' to AOR '1000' with expiration of 600 seconds	
14669	[2023-10-10 18:27:37] VERBOSE[4501] res_pjsip/pjsip_configuration.c: Endpoint 1000 is now Reachable	
14670	[2023-10-10 18:27:37] VERBOSE[4501] res_pjsip/pjsip_options.c: Contact 1000/sip:[email protected]:42629;transport=TCP;rinstance=d2288cdbc79c3e71 is now Reachable. RTT: 98.868 msec	
14671	[2023-10-10 18:27:37] VERBOSE[16451] res_pjsip_registrar.c: Removed contact 'sip:[email protected]:42629;transport=TCP;rinstance=d2288cdbc79c3e71' from AOR '1000' due to request	
14672	[2023-10-10 18:27:37] VERBOSE[18867] res_pjsip/pjsip_options.c: Contact 1000/sip:[email protected]:42629;transport=TCP;rinstance=d2288cdbc79c3e71 has been deleted	
14673	[2023-10-10 18:27:37] VERBOSE[18867] res_pjsip/pjsip_configuration.c: Endpoint 1000 is now Unreachable	
14674	[2023-10-10 18:27:37] VERBOSE[16451] res_pjsip_registrar.c: Added contact 'sip:[email protected]:42629;transport=TCP;rinstance=6b2f068a5cad1e3a' to AOR '1000' with expiration of 600 seconds	
14675	[2023-10-10 18:27:37] VERBOSE[16451] res_pjsip/pjsip_configuration.c: Endpoint 1000 is now Reachable	
14676	[2023-10-10 18:27:37] VERBOSE[16451] res_pjsip/pjsip_options.c: Contact 1000/sip:[email protected]:42629;transport=TCP;rinstance=6b2f068a5cad1e3a is now Reachable. RTT: 105.223 msec

Stewart1 · October 10, 2023, 6:49pm

If extension 7000 and RasPBX are in the same location, please explain why you are using VPN for this connection – the extension and PBX should be on the same LAN subnet and the extension can register directly.

If they are in different locations, explain the overall networking setup. What device is the VPN client? What is the server? VPN technology (OpenVPN, Wireguard, etc.)? Are these devices also the router/firewall at the respective locations? Does the tunnel connection involve any NAT? For example, can you ping the Aastra phone from the PBX command line?

Matthai · October 10, 2023, 7:22pm

OK, the whole network setup is very detailed explained here:

Basically, I have tested the setup on local network and it was working. So the next step was to put all SIP devices to the VPN. I tested OpenVPN and Wireguard - both are working fine. Currently I am using Wireguard, but I also tried “mixed” VPN network - some devices on WG and some on OVPN (however RasPBX is a client of both networks). And all worked just great.

And this is what has been working well:

github.com

MatejKovacic/RasPBX-install/blob/main/english.md#connecting-voip-phone-to-the-vpn

# Installation of RasPBX

*RasPBX installation for beginners.*

- [Basic concepts](#basic-concepts)
- [What you will need](#what-you-will-need)
- [Installation of the operating system](#installation-of-the-operating-system)
  - [Write the RasPBX image to a SD card](#write-the-raspbx-image-to-a-sd-card)
  - [Log in to the RasPBX device](#log-in-to-the-raspbx-device)
  - [First things to do after login](#first-things-to-do-after-login)
- [PBX installation and configuration](#pbx-installation-and-configuration)
  - [Setting up the e-mail system](#setting-up-the-e-mail-system)
  - [Set up VPN client](#set-up-vpn-client)
  - [Set up NTP](#set-up-ntp)
- [The security of your system](#the-security-of-your-system)
  - [Secure SSH](#secure-ssh)
    - [Login with SSH key](#login-with-ssh-key)
  - [Disable *root* user](#disable-root-user)
  - [Install intrusion prevention](#install-intrusion-prevention)
    - [How to unban IP address](#how-to-unban-ip-address)

This file has been truncated. show original

However, in that case I was using RaspberryPi as an intermediate device. What I am trying to do now is to use this ARM based router.

Anyway, I am thinking (but I am not sure) it does not really matter, because as I explained, I thought it may be some router problem, so I connected computer to this iNet.Gli Shadow router, and in that case it was working.

So I guess it must be some setting on that extension 7000, that is stopping calls from others.

Matthai · October 10, 2023, 7:50pm

Okaay, that is weird, but I managed to solve the problem.

It was indeed the setting of the extension.

Under Link to a Different Default User: there was None, and after I selected 7000, everything started to work.

Matthai · October 10, 2023, 10:04pm

Hmm, false solution. It seems there is some other problem.

Previous solution seemed to work, but then after some time calls t0 extension 7000 were still not possible. Until I reset the phone.

So what happens is that immediately after rebooting the Aastra phone (extension 7000), I can call it, but after a minute or two, I can not call it anymore. However, I can call from that extension to other phones.

Matthai · October 11, 2023, 10:49am

I was able to finally solve the problem. In the web management of the VoIP phone I changed so called SIP keep-alive settings. I did this under Advanced Settings → Line 1 and changed Registration Period (under Basic SIP Network Settings) to 0.

This setting has been originally set to 60 (seconds), which is exactly that one minute when my extension went from ONLINE to OFFLINE.

Hope this helps someone else.

system · November 11, 2023, 10:49am

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