Failing to connect FreePBX to PSTN using SPA3102

guff666 · April 8, 2020, 1:00pm

I’ve got an old (genuine) SPA3102 that I want to use to add a call screening facility into my home. My proposed architecture is:
PSTN line (virginmedia) connected to SPA3102 PSTN
Internal DECT phones connected to SPA3102 Line1
RasPBX.

I’ve followed the guide in http://www.aoakley.com/articles/2008-01-08.php to setup the SPA3102 for UK networks and the guide in https://frag.co.uk/2017/08/14/cisco-spa-3102-freepbx-uk-caller-id/ to configure the SPA3102 and FreePBX. However, I am not seeing the SPA’s Line 1 register on FreePBX and I’m getting a “501” error when the outbound trunk tries to register with the SPA3102.

I’ve tried a number of other approaches but can’t get to where I need to be.
Rather than asking what’s wrong, what I need are:

(ideally) a comprehensive guide to getting this working as the other two references are quite old.
or
A strategy for debugging this (I’m confused by the hundreds of lines appearing in the asterisk -r output)

Gareth

arielgrin · April 8, 2020, 1:07pm

Most important thing is that the UDP port for the FXO port is 5061.

Chose a numeric username for the SPA3102 and name the trunk with the same chosen username.

You might wish to post the configuration on both SPA3102 and FreePBX in order for us to try to help.

guff666 · April 8, 2020, 3:15pm

Thanks. I’ll feed back my experiences.

guff666 · April 9, 2020, 2:56pm

OK, I can now make outbound calls, but not receive inbound. Callers get “the number you have dialled is not in service”.

The SPA 3102 PSTN Line is configured as follows:

The trunk is configured as follows:

What I’m seeing in the log is:

[2020-04-09 15:54:26] VERBOSE[1338] pbx_variables.c: Setting global variable 'SIPDOMAIN' to '172.29.12.6'
[2020-04-09 15:54:26] VERBOSE[4881][C-00000006] pbx.c: Executing [01480351661@from-sip-external:1] NoOp("PJSIP/anonymous-00000005", "Received incoming SIP connection from unknown peer to 01480351661") in new stack
[2020-04-09 15:54:26] VERBOSE[4881][C-00000006] pbx.c: Executing [01480351661@from-sip-external:2] Set("PJSIP/anonymous-00000005", "DID=01480351661") in new stack
[2020-04-09 15:54:26] VERBOSE[4881][C-00000006] pbx.c: Executing [01480351661@from-sip-external:3] Goto("PJSIP/anonymous-00000005", "s,1") in new stack
[2020-04-09 15:54:26] VERBOSE[4881][C-00000006] pbx_builtins.c: Goto (from-sip-external,s,1)
[2020-04-09 15:54:26] VERBOSE[4881][C-00000006] pbx.c: Executing [s@from-sip-external:1] GotoIf("PJSIP/anonymous-00000005", "1?setlanguage:checkanon") in new stack
[2020-04-09 15:54:26] VERBOSE[4881][C-00000006] pbx_builtins.c: Goto (from-sip-external,s,2)
[2020-04-09 15:54:26] VERBOSE[4881][C-00000006] pbx.c: Executing [s@from-sip-external:2] Set("PJSIP/anonymous-00000005", "CHANNEL(language)=en_GB") in new stack
[2020-04-09 15:54:26] VERBOSE[4881][C-00000006] pbx.c: Executing [s@from-sip-external:3] GotoIf("PJSIP/anonymous-00000005", "1?noanonymous") in new stack
[2020-04-09 15:54:26] VERBOSE[4881][C-00000006] pbx_builtins.c: Goto (from-sip-external,s,5)
[2020-04-09 15:54:26] VERBOSE[4881][C-00000006] pbx.c: Executing [s@from-sip-external:5] Set("PJSIP/anonymous-00000005", "TIMEOUT(absolute)=15") in new stack
[2020-04-09 15:54:26] VERBOSE[4881][C-00000006] func_timeout.c: Channel will hangup at 2020-04-09 15:54:41.953 BST.
[2020-04-09 15:54:26] VERBOSE[4881][C-00000006] pbx.c: Executing [s@from-sip-external:6] Set("PJSIP/anonymous-00000005", "receveip=pjsip,remote_addr") in new stack
[2020-04-09 15:54:26] VERBOSE[4881][C-00000006] pbx.c: Executing [s@from-sip-external:7] Log("PJSIP/anonymous-00000005", "WARNING,"Rejecting unknown SIP connection from 172.29.12.9:5062"") in new stack
[2020-04-09 15:54:26] WARNING[4881][C-00000006] Ext. s: "Rejecting unknown SIP connection from 172.29.12.9:5062"
[2020-04-09 15:54:26] VERBOSE[4881][C-00000006] pbx.c: Executing [s@from-sip-external:8] Answer("PJSIP/anonymous-00000005", "") in new stack
[2020-04-09 15:54:26] WARNING[4881][C-00000006] translate.c: No translator path: (starting codec is not valid)
[2020-04-09 15:54:26] WARNING[4881][C-00000006] translate.c: No translator path: (starting codec is not valid)
[2020-04-09 15:54:26] VERBOSE[4881][C-00000006] pbx.c: Executing [s@from-sip-external:9] Wait("PJSIP/anonymous-00000005", "2") in new stack
[2020-04-09 15:54:28] WARNING[4881][C-00000006] channel.c: Unable to find a codec translation path: (g723) -> (ulaw)
[2020-04-09 15:54:28] ERROR[4881][C-00000006] channel.c: Could not return write format to its original state
[2020-04-09 15:54:28] VERBOSE[4881][C-00000006] pbx.c: Executing [s@from-sip-external:10] Playback("PJSIP/anonymous-00000005", "ss-noservice") in new stack
[2020-04-09 15:54:28] VERBOSE[4881][C-00000006] file.c: <PJSIP/anonymous-00000005> Playing 'ss-noservice.ulaw' (language 'en_GB')
[2020-04-09 15:54:34] VERBOSE[4881][C-00000006] pbx.c: Executing [s@from-sip-external:11] PlayTones("PJSIP/anonymous-00000005", "congestion") in new stack
[2020-04-09 15:54:34] VERBOSE[4881][C-00000006] pbx.c: Executing [s@from-sip-external:12] Congestion("PJSIP/anonymous-00000005", "5") in new stack
[2020-04-09 15:54:37] VERBOSE[4881][C-00000006] pbx.c: Spawn extension (from-sip-external, s, 12) exited non-zero on 'PJSIP/anonymous-00000005'
[2020-04-09 15:54:37] VERBOSE[4881][C-00000006] pbx.c: Executing [h@from-sip-external:1] Hangup("PJSIP/anonymous-00000005", "") in new stack
[2020-04-09 15:54:37] VERBOSE[4881][C-00000006] pbx.c: Spawn extension (from-sip-external, h, 1) exited non-zero on 'PJSIP/anonymous-00000005'

arielgrin · April 9, 2020, 2:58pm

You have a codec mismatch between g723 and ulaw. Correct that.

arielgrin · April 9, 2020, 3:05pm

This is the codec mismatch warning

guff666:

[2020-04-09 15:54:26] WARNING[4881][C-00000006] translate.c: No translator path: (starting codec is not valid) [2020-04-09 15:54:26] WARNING[4881][C-00000006] translate.c: No translator path: (starting codec is not valid) [2020-04-09 15:54:26] VERBOSE[4881][C-00000006] pbx.c: Executing [s@from-sip-external:9] Wait(“PJSIP/anonymous-00000005”, “2”) in new stack [2020-04-09 15:54:28] WARNING[4881][C-00000006] channel.c: Unable to find a codec translation path: (g723) -> (ulaw) [2020-04-09 15:54:28] ERROR[4881][C-00000006] channel.c: Could not return write format to its original state [2020-04-09 15:54:28] VERBOSE[4881][C-00000006] pbx.c: Executing [s@from-sip-external:10] Playback(“PJSIP/anonymous-00000005”, “ss-noservice”) in new stack [2020-04-09 15:54:28] VERBOSE[4881][C-00000006] file.c: <PJSIP/anonymous-00000005> Playing ‘ss-noservice.ulaw’ (language ‘en_GB’)

guff666 · April 9, 2020, 3:32pm

I’ve put

disallow=all
allow=ulaw

into the trunk’s sip settings, but it makes no difference. The SPA is set to use G711u (which I thought was ulaw).

[2020-04-09 16:29:55] VERBOSE[1338] pbx_variables.c: Setting global variable 'SIPDOMAIN' to '172.29.12.6'
[2020-04-09 16:29:55] VERBOSE[7945][C-00000008] pbx.c: Executing [01480351661@from-sip-external:1] NoOp("PJSIP/anonymous-00000007", "Received incoming SIP connection from unknown peer to 01480351661") in new stack
[2020-04-09 16:29:55] VERBOSE[7945][C-00000008] pbx.c: Executing [01480351661@from-sip-external:2] Set("PJSIP/anonymous-00000007", "DID=01480351661") in new stack
[2020-04-09 16:29:55] VERBOSE[7945][C-00000008] pbx.c: Executing [01480351661@from-sip-external:3] Goto("PJSIP/anonymous-00000007", "s,1") in new stack
[2020-04-09 16:29:55] VERBOSE[7945][C-00000008] pbx_builtins.c: Goto (from-sip-external,s,1)
[2020-04-09 16:29:55] VERBOSE[7945][C-00000008] pbx.c: Executing [s@from-sip-external:1] GotoIf("PJSIP/anonymous-00000007", "1?setlanguage:checkanon") in new stack
[2020-04-09 16:29:55] VERBOSE[7945][C-00000008] pbx_builtins.c: Goto (from-sip-external,s,2)
[2020-04-09 16:29:55] VERBOSE[7945][C-00000008] pbx.c: Executing [s@from-sip-external:2] Set("PJSIP/anonymous-00000007", "CHANNEL(language)=en_GB") in new stack
[2020-04-09 16:29:55] VERBOSE[7945][C-00000008] pbx.c: Executing [s@from-sip-external:3] GotoIf("PJSIP/anonymous-00000007", "1?noanonymous") in new stack
[2020-04-09 16:29:55] VERBOSE[7945][C-00000008] pbx_builtins.c: Goto (from-sip-external,s,5)
[2020-04-09 16:29:55] VERBOSE[7945][C-00000008] pbx.c: Executing [s@from-sip-external:5] Set("PJSIP/anonymous-00000007", "TIMEOUT(absolute)=15") in new stack
[2020-04-09 16:29:55] VERBOSE[7945][C-00000008] func_timeout.c: Channel will hangup at 2020-04-09 16:30:10.676 BST.
[2020-04-09 16:29:55] VERBOSE[7945][C-00000008] pbx.c: Executing [s@from-sip-external:6] Set("PJSIP/anonymous-00000007", "receveip=pjsip,remote_addr") in new stack
[2020-04-09 16:29:55] VERBOSE[7945][C-00000008] pbx.c: Executing [s@from-sip-external:7] Log("PJSIP/anonymous-00000007", "WARNING,"Rejecting unknown SIP connection from 172.29.12.9:5062"") in new stack
[2020-04-09 16:29:55] WARNING[7945][C-00000008] Ext. s: "Rejecting unknown SIP connection from 172.29.12.9:5062"
[2020-04-09 16:29:55] VERBOSE[7945][C-00000008] pbx.c: Executing [s@from-sip-external:8] Answer("PJSIP/anonymous-00000007", "") in new stack
[2020-04-09 16:29:55] WARNING[7945][C-00000008] translate.c: No translator path: (starting codec is not valid)
[2020-04-09 16:29:55] WARNING[7945][C-00000008] translate.c: No translator path: (starting codec is not valid)
[2020-04-09 16:29:55] VERBOSE[7945][C-00000008] pbx.c: Executing [s@from-sip-external:9] Wait("PJSIP/anonymous-00000007", "2") in new stack
[2020-04-09 16:29:57] WARNING[7945][C-00000008] channel.c: Unable to find a codec translation path: (g723) -> (ulaw)
[2020-04-09 16:29:57] ERROR[7945][C-00000008] channel.c: Could not return write format to its original state
[2020-04-09 16:29:57] VERBOSE[7945][C-00000008] pbx.c: Executing [s@from-sip-external:10] Playback("PJSIP/anonymous-00000007", "ss-noservice") in new stack
[2020-04-09 16:29:57] VERBOSE[7945][C-00000008] file.c: <PJSIP/anonymous-00000007> Playing 'ss-noservice.ulaw' (language 'en_GB')
[2020-04-09 16:30:03] VERBOSE[7945][C-00000008] pbx.c: Executing [s@from-sip-external:11] PlayTones("PJSIP/anonymous-00000007", "congestion") in new stack
[2020-04-09 16:30:03] VERBOSE[7945][C-00000008] pbx.c: Executing [s@from-sip-external:12] Congestion("PJSIP/anonymous-00000007", "5") in new stack
[2020-04-09 16:30:05] VERBOSE[7945][C-00000008] pbx.c: Spawn extension (from-sip-external, s, 12) exited non-zero on 'PJSIP/anonymous-00000007'
[2020-04-09 16:30:05] VERBOSE[7945][C-00000008] pbx.c: Executing [h@from-sip-external:1] Hangup("PJSIP/anonymous-00000007", "") in new stack
[2020-04-09 16:30:05] VERBOSE[7945][C-00000008] pbx.c: Spawn extension (from-sip-external, h, 1) exited non-zero on 'PJSIP/anonymous-00000007'

arielgrin · April 9, 2020, 3:37pm

Is that the IP of the SPA3102 ? If so, you have misconfigured the trunk

Also, the codec issue persists, you need to fix that.

Stewart1 · April 9, 2020, 3:50pm

In the SPA, set Proxy: 172.29.12.6:5160
assuming that you have not changed chan_sip Bind Port from the default of 5160.

guff666 · April 9, 2020, 3:59pm

Thanks
Yes, that is the IP of the SPA. Unfortunately, I don’t know enough to be able to determine how the trunk is misconfigured. Neither do I know how to fix the codec issue. This is a plain vanilla instal of RasPBX.

guff666 · April 9, 2020, 4:03pm

Tried that.
Got an error:

[2020-04-09 16:53:04] ERROR[1353] chan_sip.c: Peer '1-pstn' is trying to register, but not configured as host=dynamic
[2020-04-09 16:53:04] NOTICE[1353] chan_sip.c: Registration from 'PSTN CALL <sip:[email protected]:5160>' failed for '172.29.12.9:5062' - Peer is not supposed to register
[2020-04-09 16:53:04] ERROR[1353] chan_sip.c: Peer '1-pstn' is trying to register, but not configured as host=dynamic
[2020-04-09 16:53:04] NOTICE[1353] chan_sip.c: Registration from 'PSTN CALL <sip:[email protected]:5160>' failed for '172.29.12.9:5062' - Peer is not supposed to register

So I changed the sip settings to have

type=friend
host=dynamic

That error disappeared but the problem persists. I’m still seeing

WARNING[10806][C-0000000a] Ext. s: "Rejecting unknown SIP connection from 172.29.12.9"

[2020-04-09 17:01:43] VERBOSE[1353][C-0000000a] netsock2.c: Using SIP RTP TOS bits 184
[2020-04-09 17:01:43] VERBOSE[1353][C-0000000a] netsock2.c: Using SIP RTP CoS mark 5
[2020-04-09 17:01:43] VERBOSE[10806][C-0000000a] pbx.c: Executing [01480351661@from-sip-external:1] NoOp("SIP/172.29.12.6-00000003", "Received incoming SIP connection from unknown peer to 01480351661") in new stack
[2020-04-09 17:01:43] VERBOSE[10806][C-0000000a] pbx.c: Executing [01480351661@from-sip-external:2] Set("SIP/172.29.12.6-00000003", "DID=01480351661") in new stack
[2020-04-09 17:01:43] VERBOSE[10806][C-0000000a] pbx.c: Executing [01480351661@from-sip-external:3] Goto("SIP/172.29.12.6-00000003", "s,1") in new stack
[2020-04-09 17:01:43] VERBOSE[10806][C-0000000a] pbx_builtins.c: Goto (from-sip-external,s,1)
[2020-04-09 17:01:43] VERBOSE[10806][C-0000000a] pbx.c: Executing [s@from-sip-external:1] GotoIf("SIP/172.29.12.6-00000003", "1?setlanguage:checkanon") in new stack
[2020-04-09 17:01:43] VERBOSE[10806][C-0000000a] pbx_builtins.c: Goto (from-sip-external,s,2)
[2020-04-09 17:01:43] VERBOSE[10806][C-0000000a] pbx.c: Executing [s@from-sip-external:2] Set("SIP/172.29.12.6-00000003", "CHANNEL(language)=en_GB") in new stack
[2020-04-09 17:01:43] VERBOSE[10806][C-0000000a] pbx.c: Executing [s@from-sip-external:3] GotoIf("SIP/172.29.12.6-00000003", "1?noanonymous") in new stack
[2020-04-09 17:01:43] VERBOSE[10806][C-0000000a] pbx_builtins.c: Goto (from-sip-external,s,5)
[2020-04-09 17:01:43] VERBOSE[10806][C-0000000a] pbx.c: Executing [s@from-sip-external:5] Set("SIP/172.29.12.6-00000003", "TIMEOUT(absolute)=15") in new stack
[2020-04-09 17:01:43] VERBOSE[10806][C-0000000a] func_timeout.c: Channel will hangup at 2020-04-09 17:01:58.434 BST.
[2020-04-09 17:01:43] VERBOSE[10806][C-0000000a] pbx.c: Executing [s@from-sip-external:6] Set("SIP/172.29.12.6-00000003", "receveip=recvip") in new stack
[2020-04-09 17:01:43] VERBOSE[10806][C-0000000a] pbx.c: Executing [s@from-sip-external:7] Log("SIP/172.29.12.6-00000003", "WARNING,"Rejecting unknown SIP connection from 172.29.12.9"") in new stack
[2020-04-09 17:01:43] WARNING[10806][C-0000000a] Ext. s: "Rejecting unknown SIP connection from 172.29.12.9"
[2020-04-09 17:01:43] VERBOSE[10806][C-0000000a] pbx.c: Executing [s@from-sip-external:8] Answer("SIP/172.29.12.6-00000003", "") in new stack
[2020-04-09 17:01:43] VERBOSE[10806][C-0000000a] pbx.c: Executing [s@from-sip-external:9] Wait("SIP/172.29.12.6-00000003", "2") in new stack
[2020-04-09 17:01:45] VERBOSE[10806][C-0000000a] pbx.c: Executing [s@from-sip-external:10] Playback("SIP/172.29.12.6-00000003", "ss-noservice") in new stack
[2020-04-09 17:01:45] VERBOSE[10806][C-0000000a] file.c: <SIP/172.29.12.6-00000003> Playing 'ss-noservice.ulaw' (language 'en_GB')
[2020-04-09 17:01:51] VERBOSE[10806][C-0000000a] pbx.c: Executing [s@from-sip-external:11] PlayTones("SIP/172.29.12.6-00000003", "congestion") in new stack
[2020-04-09 17:01:51] VERBOSE[10806][C-0000000a] pbx.c: Executing [s@from-sip-external:12] Congestion("SIP/172.29.12.6-00000003", "5") in new stack
[2020-04-09 17:01:52] VERBOSE[10806][C-0000000a] pbx.c: Spawn extension (from-sip-external, s, 12) exited non-zero on 'SIP/172.29.12.6-00000003'
[2020-04-09 17:01:52] VERBOSE[10806][C-0000000a] pbx.c: Executing [h@from-sip-external:1] Hangup("SIP/172.29.12.6-00000003", "") in new stack
[2020-04-09 17:01:52] VERBOSE[10806][C-0000000a] pbx.c: Spawn extension (from-sip-external, h, 1) exited non-zero on 'SIP/172.29.12.6-00000003'

guff666 · April 9, 2020, 4:04pm

Also the SPA’s PSTN line still fails to register

Stewart1 · April 9, 2020, 4:12pm

We should first get the SPA to register.
In the PEER Details, remove the port=5062. (host=dynamic implies a dynamic port)
Confirm that the value of secret matches what you entered for Password on the PSTN Line page.

If it still won’t register, at the Asterisk command prompt, type
sip set debug on
and reboot the SPA. The registration attempts should show in the Asterisk log. Paste the relevant section at https://pastebin.freepbx.org and post the link here.

tek640 · April 9, 2020, 5:47pm

Hello
I made a similar setup with spa3000. As I remember after many hours of trial and error I didn’t make it to register to FreePBX so i try the following that worked,
First of all create a pjsip trunk to FreePBX with the following parameters:

Trunk name - PSTN
In pjsip settings tab set:
username - spa3102
password - secret
authentication - outbound
registration - none
sip server - your SPA IP
sip server port - 5062

Then submit your settings and hit the Apply config button

In SPA pstn line tab:
Proxy - your FreePBX IP:5062
Register - no
username - spa3102
password - secret
Dial plan 2 - S0(<:1234567890@FreePBX_IP:5062>)

Save your settings.

To make outbound calls you have to create rules
For Inbound calls go to FreePBX Connectivity - Inbound routes
Description - From SPA
DID - 1234567890
Set Destination - extension, IVR, Group or something

Hit submit and apply config and test it.

guff666 · April 9, 2020, 7:16pm

That seems to have done it. PSTN is now registered and calls flow in and out.
I’ll post the working configuration shortly.

guff666 · April 9, 2020, 7:20pm

This is the working configuration:
SPA PSTN line
CWOps

And for the trunk

system · May 10, 2020, 7:20pm

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