Hello, @wmoon, and thanks for your input.
The registration process seems to be ok. The LED in the SPA regarding the PSTN line lights up right away.
Here is the output from the SPA debug server:
Jul 8 19:23:52 192.168.10.3
Jul 8 19:23:52 192.168.10.3 [1]<<192.168.10.207:5060(423)
Jul 8 19:23:52 192.168.10.3 [1]<<192.168.10.207:5060(423)
Jul 8 19:23:52 192.168.10.3 SIP/2.0 200 OK#015#012Via: SIP/2.0/UDP 192.168.10.3:5060;rport=5060;received=192.168.10.3;branch=z9hG4bK-fd16b031#015#012Call-ID: [email protected]#015#012From: <sip:[email protected]>;tag=5bf5750a713a329do1#015#012To: <sip:[email protected]>;tag=z9hG4bK-fd16b031#015#012CSeq: 1637 REGISTER#015#012Date: Wed, 08 Jul 2020 22:23:52 GMT#015#012Contact: <sip:[email protected]:5060>;expires=3599#015#012Server: FPBX-15.0.16.61(16.9.0)#015#012Content-Length: 0#015#012#015
Jul 8 19:23:52 192.168.10.3
Jul 8 19:23:52 192.168.10.3
Jul 8 19:23:52 192.168.10.3 [1]RegOK. NextReg in 3570 (0)
Jul 8 19:23:52 192.168.10.3 AUD: Stop PSTN Tone
Jul 8 19:23:52 192.168.10.3 [1]<<192.168.10.207:5060(430)
Jul 8 19:23:52 192.168.10.3 [1]<<192.168.10.207:5060(430)
Jul 8 19:23:52 192.168.10.3
Jul 8 19:23:52 192.168.10.3
Jul 8 19:23:52 192.168.10.3 [1]->192.168.10.207:5060(455)
Jul 8 19:23:52 192.168.10.3 [1]->192.168.10.207:5060(455)
Jul 8 19:23:52 192.168.10.3 SIP/2.0 200 OK#015#012To: <sip:[email protected]>;tag=edf4f34edda52929i1#015#012From: <sip:[email protected]>;tag=304a61b0-8ff1-4905-a12e-dfb58bfa1664#015#012Call-ID: 8e3bde99-aae2-4ed6-9f3a-e3f2a61d0dc9#015#012CSeq: 56954 OPTIONS#015#012Via: SIP/2.0/UDP 192.168.10.207:5060;branch=z9hG4bKPj1285d738-ff78-4f19-bd66-93f03bd8c448#015#012Server: Linksys/SPA3102-5.2.13(GW002)#015#012Content-Length: 0#015#012Allow: ACK, BYE, CANCEL, INFO, INVITE, NOTIFY, OPTIONS, REFER#015#012Supported: x-sipura, replaces#015#012#015
Jul 8 19:23:52 192.168.10.3
Jul 8 19:23:52 192.168.10.3
Jul 8 19:23:52 192.168.10.3 [0]RegOK. NextReg in 3570 (1)
Jul 8 19:23:59 192.168.10.3 IDBG: st--995
Jul 8 19:24:00 192.168.10.3 fs: 11817:11890:65536
Jul 8 19:24:00 192.168.10.3 fls: af:1:0:0
Jul 8 19:24:00 192.168.10.3 fbr: 0:3000:3000:03f44:0016:0015:5.2.13(GW002)
Jul 8 19:24:00 192.168.10.3 fhs: 01:0:0003:upg:app:2:3.2.6(GWa)
Jul 8 19:24:00 192.168.10.3 fhs: 02:0:0004:upg:app:0:5.1.5(GWa)
Jul 8 19:24:00 192.168.10.3 fhs: 03:0:0005:upg:app:1:5.1.5(GWa)
Jul 8 19:24:00 192.168.10.3 fhs: 04:0:0006:upg:app:2:5.1.5(GWa)
Jul 8 19:24:00 192.168.10.3 fhs: 05:0:0007:upg:app:0:5.1.7(GW)
Jul 8 19:24:00 192.168.10.3 fhs: 06:0:0008:upg:app:1:5.1.7(GW)
Jul 8 19:24:00 192.168.10.3 fhs: 07:0:0009:upg:app:2:5.1.7(GW)
Jul 8 19:24:00 192.168.10.3 fhs: 08:0:000a:upg:app:0:5.1.7(GW)
Jul 8 19:24:00 192.168.10.3 fhs: 09:0:000b:upg:app:1:5.1.7(GW)
Jul 8 19:24:00 192.168.10.3 fhs: 0a:0:000c:upg:app:2:5.1.7(GW)
Jul 8 19:24:00 192.168.10.3 fhs: 0b:0:000d:upg:app:0:5.1.10(GW)
Jul 8 19:24:00 192.168.10.3 fhs: 0c:0:000e:upg:app:1:5.1.10(GW)
Jul 8 19:24:00 192.168.10.3 fhs: 0d:0:000f:upg:app:2:5.1.10(GW)
Jul 8 19:24:00 192.168.10.3 fhs: 0e:0:0010:upg:app:0:5.2.13(GW002)
Jul 8 19:24:00 192.168.10.3 fhs: 0f:0:0011:upg:app:1:5.2.13(GW002)
Jul 8 19:24:00 192.168.10.3 fhs: 10:0:0012:upg:app:2:5.2.13(GW002)
Jul 8 19:24:00 192.168.10.3 PLKUP: 2048, 768, 11, 1.5
Jul 8 19:24:00 192.168.10.3 fu: 0:3f6b, 0003 0001
Jul 8 19:24:52 192.168.10.3 [1]<<192.168.10.207:5060(430)
Jul 8 19:24:52 192.168.10.3 [1]<<192.168.10.207:5060(430)
Jul 8 19:24:52 192.168.10.3
And here is the output in the asterisk -rvvv console:
freepbx*CLI>
-- Added contact 'sip:[email protected]:5060' to AOR 'pstn' with expiration of 3600 seconds
== Endpoint pstn is now Reachable
-- Contact pstn/sip:[email protected]:5060 is now Reachable. RTT: 10.610 msec
freepbx*CLI>
These are the trunk settings:
The inbound route (the only one in the system) is as follows:
And the SPA dial plan is like this:
Sometimes I get a “no service message” when I try to call the PSTN Line:
freepbx*CLI>
-- Added contact 'sip:[email protected]:5060' to AOR 'pstn' with expiration of 3600 seconds
== Endpoint pstn is now Reachable
-- Contact pstn/sip:[email protected]:5060 is now Reachable. RTT: 10.610 msec
== Setting global variable 'SIPDOMAIN' to '192.168.10.207'
-- Executing [1125386356@from-sip-external:1] NoOp("PJSIP/anonymous-00000015", "Received incoming SIP connection from unknown peer to 1125386356") in new stack
-- Executing [1125386356@from-sip-external:2] Set("PJSIP/anonymous-00000015", "DID=1125386356") in new stack
-- Executing [1125386356@from-sip-external:3] Goto("PJSIP/anonymous-00000015", "s,1") in new stack
-- Goto (from-sip-external,s,1)
-- Executing [s@from-sip-external:1] GotoIf("PJSIP/anonymous-00000015", "1?setlanguage:checkanon") in new stack
-- Goto (from-sip-external,s,2)
-- Executing [s@from-sip-external:2] Set("PJSIP/anonymous-00000015", "CHANNEL(language)=en") in new stack
-- Executing [s@from-sip-external:3] GotoIf("PJSIP/anonymous-00000015", "1?noanonymous") in new stack
-- Goto (from-sip-external,s,5)
-- Executing [s@from-sip-external:5] Set("PJSIP/anonymous-00000015", "TIMEOUT(absolute)=15") in new stack
-- Channel will hangup at 2020-07-08 22:31:55.006 UTC.
-- Executing [s@from-sip-external:6] Set("PJSIP/anonymous-00000015", "receveip=pjsip,remote_addr") in new stack
-- Executing [s@from-sip-external:7] Log("PJSIP/anonymous-00000015", "WARNING,"Rejecting unknown SIP connection from 192.168.10.3:5060"") in new stack
[2020-07-08 22:31:40] WARNING[5401][C-0000001a]: Ext. s:7 @ from-sip-external: "Rejecting unknown SIP connection from 192.168.10.3:5060"
-- Executing [s@from-sip-external:8] Answer("PJSIP/anonymous-00000015", "") in new stack
[2020-07-08 22:31:40] WARNING[5401][C-0000001a]: translate.c:488 ast_translator_build_path: No translator path: (starting codec is not valid)
[2020-07-08 22:31:40] WARNING[5401][C-0000001a]: translate.c:488 ast_translator_build_path: No translator path: (starting codec is not valid)
-- Executing [s@from-sip-external:9] Wait("PJSIP/anonymous-00000015", "2") in new stack
[2020-07-08 22:31:42] WARNING[5401][C-0000001a]: channel.c:5688 set_format: Unable to find a codec translation path: (g723) -> (ulaw)
[2020-07-08 22:31:42] ERROR[5401][C-0000001a]: channel.c:8184 ast_channel_stop_silence_generator: Could not return write format to its original state
-- Executing [s@from-sip-external:10] Playback("PJSIP/anonymous-00000015", "ss-noservice") in new stack
-- <PJSIP/anonymous-00000015> Playing 'ss-noservice.ulaw' (language 'en')
-- Executing [s@from-sip-external:11] PlayTones("PJSIP/anonymous-00000015", "congestion") in new stack
-- Executing [s@from-sip-external:12] Congestion("PJSIP/anonymous-00000015", "5") in new stack
== Spawn extension (from-sip-external, s, 12) exited non-zero on 'PJSIP/anonymous-00000015'
-- Executing [h@from-sip-external:1] Hangup("PJSIP/anonymous-00000015", "") in new stack
== Spawn extension (from-sip-external, h, 1) exited non-zero on 'PJSIP/anonymous-00000015'
freepbx*CLI>
And sometimes I get that weird behaviour of not being able to correctly pick up the call, as described in the original post. It either keeps ringing or it drops right after the pick up.
Thanks!