[Spce-user] [EXTERNAL] Troubleshooting request

Edo edo.ekunwe at gmail.com
Mon Oct 7 09:36:40 EDT 2024


Hi Dario,

I am not sure if your earlier response of malformed invite was directed at
me so I decided to paste the sip logs from a sample call, maybe we can get
more information that may help with troubleshooting.

****

Oct  7 06:43:50.807051 spce proxy[837572]: NOTICE: DEFAULT_ROUTE <script>:
New request on proxy - M=INVITE R=«sip:xxxxxxxxxxx2607244 at XXX.XXX.XXX.XXX:5060»
F=«sip:XXCallerIDXX at XXX.XXX.86.104»
T=«sip:xxxxxxxxxxx2607244 at XXX.XXX.XXX.XXX» IP=«XXX.XXX.188.51»:«5060»
(«127.0.0.1»:«5060») ID=«3e2e30bf-6132-478a-bdd0-292e139c39c5» UA='Asterisk
PBX 18.24.3' DESTIP=«127.0.0.1»:«5062»

Oct  7 06:43:50.807084 spce proxy[837572]: NOTICE: DEFAULT_ROUTE <script>:
Sending reply S=100 Trying M=INVITE fs='«127.0.0.1»:«5062»'
du='«127.0.0.1»:«5060»' - R=«sip:xxxxxxxxxxx2607244 at XXX.XXX.XXX.XXX:5060»
ID=«3e2e30bf-6132-478a-bdd0-292e139c39c5» UA='Asterisk PBX 18.24.3'

Oct  7 06:43:50.807375 spce proxy[837572]: NOTICE:
ROUTE_LOAD_CALLEE_DOMAIN_PREF <script>: Load domain preferences for callee
'«XXX.XXX.XXX.XXX»' - R=«sip:xxxxxxxxxxx2607244 at XXX.XXX.XXX.XXX:5060»
ID=«3e2e30bf-6132-478a-bdd0-292e139c39c5» UA='Asterisk PBX 18.24.3'

Oct  7 06:43:50.811499 spce proxy[837572]: NOTICE: ROUTE_AUTH <script>:
Authentication failed, no credentials -
R=«sip:xxxxxxxxxxx2607244 at XXX.XXX.XXX.XXX:5060»
ID=«3e2e30bf-6132-478a-bdd0-292e139c39c5» UA='Asterisk PBX 18.24.3'
Auth=«<null>»

Oct  7 06:43:50.811581 spce proxy[837572]: NOTICE: ROUTE_AUTH <script>:
Sending reply S=407 fs='«127.0.0.1»:«5062»' du='«127.0.0.1»:«5060»' -
ID=«3e2e30bf-6132-478a-bdd0-292e139c39c5» UA='Asterisk PBX 18.24.3'

Oct  7 06:43:50.812257 spce proxy[837568]: NOTICE: sl:filtered-ack
<script>: New request on proxy - M=ACK
R=«sip:xxxxxxxxxxx2607244 at XXX.XXX.XXX.XXX:5060»
F=«sip:XXCallerIDXX at XXX.XXX.86.104»
T=«sip:xxxxxxxxxxx2607244 at XXX.XXX.XXX.XXX» IP=«<null>»:«<null>»
(«127.0.0.1»:«5060») ID=«3e2e30bf-6132-478a-bdd0-292e139c39c5» UA='<null>'
DESTIP=«127.0.0.1»:«5062»

Oct  7 06:43:50.872198 spce proxy[837565]: NOTICE: DEFAULT_ROUTE <script>:
New request on proxy - M=INVITE R=«sip:xxxxxxxxxxx2607244 at XXX.XXX.XXX.XXX:5060»
F=«sip:XXCallerIDXX at XXX.XXX.86.104»
T=«sip:xxxxxxxxxxx2607244 at XXX.XXX.XXX.XXX» IP=«XXX.XXX.188.51»:«5060»
(«127.0.0.1»:«5060») ID=«3e2e30bf-6132-478a-bdd0-292e139c39c5» UA='Asterisk
PBX 18.24.3' DESTIP=«127.0.0.1»:«5062»

Oct  7 06:43:50.872229 spce proxy[837565]: NOTICE: DEFAULT_ROUTE <script>:
Sending reply S=100 Trying M=INVITE fs='«127.0.0.1»:«5062»'
du='«127.0.0.1»:«5060»' - R=«sip:xxxxxxxxxxx2607244 at XXX.XXX.XXX.XXX:5060»
ID=«3e2e30bf-6132-478a-bdd0-292e139c39c5» UA='Asterisk PBX 18.24.3'

Oct  7 06:43:50.872504 spce proxy[837565]: NOTICE:
ROUTE_LOAD_CALLEE_DOMAIN_PREF <script>: Load domain preferences for callee
'«XXX.XXX.XXX.XXX»' - R=«sip:xxxxxxxxxxx2607244 at XXX.XXX.XXX.XXX:5060»
ID=«3e2e30bf-6132-478a-bdd0-292e139c39c5» UA='Asterisk PBX 18.24.3'

Oct  7 06:43:50.877414 spce proxy[837565]: NOTICE: ROUTE_FIND_CALLER
<script>: Sending reply S=101 Connecting fs='«127.0.0.1»:«5062»'
du='«127.0.0.1»:«5060»' - R=«sip:xxxxxxxxxxx2607244 at XXX.XXX.XXX.XXX:5060»
ID=«3e2e30bf-6132-478a-bdd0-292e139c39c5» UA='Asterisk PBX 18.24.3'

Oct  7 06:43:50.877751 spce proxy[837565]: NOTICE: ROUTE_LOAD_CALLER_PREF
<script>: Load caller preferences for uuid
'«86ba28d9-153f-4cee-800c-f34c1efea74a»' and domain '«XXX.XXX.86.104»' -
R=«sip:xxxxxxxxxxx2607244 at XXX.XXX.XXX.XXX:5060»
ID=«3e2e30bf-6132-478a-bdd0-292e139c39c5» UA='Asterisk PBX 18.24.3'

Oct  7 06:43:50.883279 spce proxy[837565]: NOTICE:
ROUTE_LOAD_CALLER_CONTRACT_PREF <script>: Load caller contract preferences
for contract id '«2»' and ip '«XXX.XXX.188.51»' -
R=«sip:xxxxxxxxxxx2607244 at XXX.XXX.XXX.XXX:5060»
ID=«3e2e30bf-6132-478a-bdd0-292e139c39c5» UA='Asterisk PBX 18.24.3'

Oct  7 06:43:50.883583 spce proxy[837565]: NOTICE:
ROUTE_LOAD_CALLER_RESELLER_PREF <script>: Load caller reseller preferences
for reseller id '«1»' - R=«sip:xxxxxxxxxxx2607244 at XXX.XXX.XXX.XXX:5060»
ID=«3e2e30bf-6132-478a-bdd0-292e139c39c5» UA='Asterisk PBX 18.24.3'

Oct  7 06:43:50.884273 spce proxy[837565]: NOTICE: ROUTE_DLG_MANAGE
<script>: Dialog managed,
lua_dlg_callid:[«3e2e30bf-6132-478a-bdd0-292e139c39c5»] -
R=«sip:xxxxxxxxxxx2607244 at XXX.XXX.XXX.XXX:5060»
ID=«3e2e30bf-6132-478a-bdd0-292e139c39c5» UA='Asterisk PBX 18.24.3'

Oct  7 06:43:50.884348 spce proxy[837565]: NOTICE: ROUTE_GET_CALLER_CLI
<script>: User-Provided CLI '«XXCallerIDXX»' taken from From-User -
R=«sip:xxxxxxxxxxx2607244 at XXX.XXX.XXX.XXX:5060»
ID=«3e2e30bf-6132-478a-bdd0-292e139c39c5» UA='Asterisk PBX 18.24.3'

Oct  7 06:43:50.888566 spce proxy[837565]: NOTICE: ROUTE_APPLY_REWRITE_RULE
<script>: Applying caller-in usr/domain rewrite rules on user-provided CLI
using dpid '7' - R=«sip:xxxxxxxxxxx2607244 at XXX.XXX.XXX.XXX:5060»
ID=«3e2e30bf-6132-478a-bdd0-292e139c39c5» UA='Asterisk PBX 18.24.3'

Oct  7 06:43:50.888839 spce proxy[837565]: NOTICE: ROUTE_CHECK_CLI_ALLOWED
<script>: User-provided CLI '«XXCallerIDXX»' accepted (matched user
preference) - R=«sip:xxxxxxxxxxx2607244 at XXX.XXX.XXX.XXX:5060»
ID=«3e2e30bf-6132-478a-bdd0-292e139c39c5» UA='Asterisk PBX 18.24.3'

Oct  7 06:43:50.888915 spce proxy[837565]: NOTICE: ROUTE_INVITE <script>:
Setting '«XXCallerIDXX»@«XXX.XXX.86.104»' as initiating user-provided CLI -
R=«sip:xxxxxxxxxxx2607244 at XXX.XXX.XXX.XXX:5060»
ID=«3e2e30bf-6132-478a-bdd0-292e139c39c5» UA='Asterisk PBX 18.24.3'

Oct  7 06:43:50.888963 spce proxy[837565]: NOTICE: ROUTE_INVITE <script>:
Setting '«XXCallerIDXX»@«XXX.XXX.86.104»' as initiating network-provided
CLI - R=«sip:xxxxxxxxxxx2607244 at XXX.XXX.XXX.XXX:5060»
ID=«3e2e30bf-6132-478a-bdd0-292e139c39c5» UA='Asterisk PBX 18.24.3'

Oct  7 06:43:50.889037 spce proxy[837565]: NOTICE: ROUTE_APPLY_REWRITE_RULE
<script>: Applying callee-in usr/domain rewrite rules on called party using
dpid '8' - R=«sip:xxxxxxxxxxx2607244 at XXX.XXX.XXX.XXX:5060»
ID=«3e2e30bf-6132-478a-bdd0-292e139c39c5» UA='Asterisk PBX 18.24.3'

Oct  7 06:43:50.890596 spce proxy[837565]: NOTICE: ROUTE_FIND_CALLEE
<script>: Callee is not local - R=«sip:xxxxxxxxxxx2607244 at XXX.XXX.XXX.XXX:5060»
ID=«3e2e30bf-6132-478a-bdd0-292e139c39c5» UA='Asterisk PBX 18.24.3'

Oct  7 06:43:50.890869 spce proxy[837565]: NOTICE: ROUTE_PSTN <script>:
Call to SIP Peering - R=«sip:xxxxxxxxxxx2607244 at XXX.XXX.XXX.XXX:5060»
ID=«3e2e30bf-6132-478a-bdd0-292e139c39c5» UA='Asterisk PBX 18.24.3'

Oct  7 06:43:50.890924 spce proxy[837565]: NOTICE: ROUTE_PSTN <script>:
Load gws matching calling part '«sip:XXCallerIDXX at XXX.XXX.86.104»' and
called user '«xxxxxxxxxxx2607244»' and called part
'«sip:xxxxxxxxxxx2607244 at XXX.XXX.XXX.XXX:5060»' -
R=«sip:xxxxxxxxxxx2607244 at XXX.XXX.XXX.XXX:5060»
ID=«3e2e30bf-6132-478a-bdd0-292e139c39c5» UA='Asterisk PBX 18.24.3'

Oct  7 06:43:50.891692 spce proxy[837565]: ERROR: ROUTE_PSTN_SELECT_PEER pv
[pv_core.c:336]: pv_get_ruri_attr(): failed to parse the R-URI

Oct  7 06:43:50.891806 spce proxy[837565]: ERROR: ROUTE_LOAD_PEER_OUT_PREF
pv [pv_core.c:261]: pv_get_ruri(): failed to parse the R-URI

Oct  7 06:43:50.891827 spce proxy[837565]: NOTICE: ROUTE_LOAD_PEER_OUT_PREF
<script>: Load peer preferences for peer host '1' - R=«<null>»
ID=«3e2e30bf-6132-478a-bdd0-292e139c39c5» UA='Asterisk PBX 18.24.3'

Oct  7 06:43:50.893690 spce proxy[837565]: ERROR: ROUTE_PSTN pv
[pv_core.c:336]: pv_get_ruri_attr(): failed to parse the R-URI

Oct  7 06:43:50.895431 spce proxy[837565]: ERROR: ROUTE_PSTN pv
[pv_core.c:336]: pv_get_ruri_attr(): failed to parse the R-URI

Oct  7 06:43:50.895538 spce proxy[837565]: ERROR: <null> pv
[pv_core.c:336]: pv_get_ruri_attr(): failed to parse the R-URI

Oct  7 06:43:50.895558 spce proxy[837565]: ERROR: <null> pv
[pv_core.c:336]: pv_get_ruri_attr(): failed to parse the R-URI

Oct  7 06:43:50.901133 spce proxy[837565]: ERROR: ROUTE_OUTBOUND pv
[pv_core.c:336]: pv_get_ruri_attr(): failed to parse the R-URI

Oct  7 06:43:50.901156 spce proxy[837565]: ERROR: ROUTE_OUTBOUND pv
[pv_core.c:336]: pv_get_ruri_attr(): failed to parse the R-URI

Oct  7 06:43:50.901829 spce proxy[837565]: ERROR: ROUTE_APPLY_REWRITE_RULE
pv [pv_core.c:261]: pv_get_ruri(): failed to parse the R-URI

Oct  7 06:43:50.901850 spce proxy[837565]: NOTICE: ROUTE_APPLY_REWRITE_RULE
<script>: Applying acc caller-out peer rewrite rules on acc caller party
using dpid '3' - R=«<null>» ID=«3e2e30bf-6132-478a-bdd0-292e139c39c5»
UA='Asterisk PBX 18.24.3'

Oct  7 06:43:50.902770 spce proxy[837565]: ERROR: ROUTE_ACC_CALLER pv
[pv_core.c:261]: pv_get_ruri(): failed to parse the R-URI

Oct  7 06:43:50.902792 spce proxy[837565]: NOTICE: ROUTE_ACC_CALLER
<script>: Setting acc source-leg for uuid
'«86ba28d9-153f-4cee-800c-f34c1efea74a»':
'«{"gpp":["70770",null,null,null,null,null,null,null,null,null],"clir":0,"uuid":"86ba28d9-153f-4cee-800c-f34c1efea74a","u":"XXCallerIDXX","d":"XXX.XXX.86.104","cli":"XXCallerIDXX","s_id":"70770","c_id":"70770","a_id":2,"pau":"","par":"","s":"call","ip":"XXX.XXX.188.51","t":1728276230.902101,"lnp_p":"","cli_out":"XXCallerIDXX","lnp_t":"","pai":"","ppi":"","div":"","last_hih":"","cid":"","u2u":"","lcr":0,"cc_quota":"","cc_sub":"1","cc_cust":"1"}»'
- R=«<null>» ID=«3e2e30bf-6132-478a-bdd0-292e139c39c5» UA='Asterisk PBX
18.24.3'

Oct  7 06:43:50.903156 spce proxy[837565]: ERROR: ROUTE_APPLY_REWRITE_RULE
pv [pv_core.c:261]: pv_get_ruri(): failed to parse the R-URI

Oct  7 06:43:50.903176 spce proxy[837565]: NOTICE: ROUTE_APPLY_REWRITE_RULE
<script>: Applying acc callee-out peer rewrite rules on acc called party
using dpid '4' - R=«<null>» ID=«3e2e30bf-6132-478a-bdd0-292e139c39c5»
UA='Asterisk PBX 18.24.3'

Oct  7 06:43:50.903656 spce proxy[837565]: ERROR: ROUTE_ACC_CALLEE pv
[pv_core.c:261]: pv_get_ruri(): failed to parse the R-URI

Oct  7 06:43:50.903679 spce proxy[837565]: NOTICE: ROUTE_ACC_CALLEE
<script>: Setting acc destination-leg for uuid '«0»':
'«{"gpp":[null,null,null,null,null,null,null,null,null,null],"plu":0,"s_id":"","c_id":"","a_id":0,"dialed":"xxxxxxxxxxx2607244","uuid":"0","u":"<null>","d":"<null>","u_in":"xxxxxxxxxxx2607244","d_in":"XXX.XXX.XXX.XXX","lcr":1,"lnp_p":"","u_out":"0","lnp_t":"","fci":"","cc_quota":"","cc_sub":"1","cc_cust":""}»'
- R=«<null>» ID=«3e2e30bf-6132-478a-bdd0-292e139c39c5» UA='Asterisk PBX
18.24.3'

Oct  7 06:43:50.903837 spce proxy[837565]: ERROR: ROUTE_OUTBOUND tm
[t_lookup.c:1827]: new_t(): uri invalid

Oct  7 06:43:50.903858 spce proxy[837565]: ERROR: ROUTE_OUTBOUND tm
[t_lookup.c:1979]: t_newtran(): new_t failed

Oct  7 06:43:50.903913 spce proxy[837565]: ERROR: ROUTE_OUTBOUND sl
[sl_funcs.c:428]: sl_reply_error(): stateless error reply used: I'm
terribly sorry, server error occurred (1/SL)

Oct  7 06:43:50.904591 spce proxy[837570]: NOTICE: sl:filtered-ack
<script>: New request on proxy - M=ACK
R=«sip:xxxxxxxxxxx2607244 at XXX.XXX.XXX.XXX:5060»
F=«sip:XXCallerIDXX at XXX.XXX.86.104»
T=«sip:xxxxxxxxxxx2607244 at XXX.XXX.XXX.XXX» IP=«<null>»:«<null>»
(«127.0.0.1»:«5060») ID=«3e2e30bf-6132-478a-bdd0-292e139c39c5» UA='<null>'
DESTIP=«127.0.0.1»:«5062»


****

Thanks


On Mon, Oct 7, 2024 at 1:11 AM Dario Busso <dbusso at sipwise.com> wrote:

> Looking at the error log, it seems that the INVITE received by SPCE is
> malformed.
> You need to check the peer system setup, not the SPCE.
>
>
> Dario B.
>
>
> Il lun 7 ott 2024, 06:50 Edo <edo.ekunwe at gmail.com> ha scritto:
>
>> Hi,
>>
>> I tried to make a call to a subscriber (SIP Trunk setup) and I got the
>> following error message.
>> *****
>>
>> Oct  7 06:43:50.891692 spce proxy[837565]: ERROR: ROUTE_PSTN_SELECT_PEER
>> pv [pv_core.c:336]: pv_get_ruri_attr(): failed to parse the R-URI
>>
>> Oct  7 06:43:50.891806 spce proxy[837565]: ERROR:
>> ROUTE_LOAD_PEER_OUT_PREF pv [pv_core.c:261]: pv_get_ruri(): failed to parse
>> the R-URI
>>
>> Oct  7 06:43:50.891827 spce proxy[837565]: NOTICE:
>> ROUTE_LOAD_PEER_OUT_PREF <script>: Load peer preferences for peer host '1'
>> - R=«<null>» ID=«3e2e30bf-6132-478a-bdd0-292e139c39c5» UA='Asterisk PBX
>> 18.24.3'
>>
>> Oct  7 06:43:50.893690 spce proxy[837565]: ERROR: ROUTE_PSTN pv
>> [pv_core.c:336]: pv_get_ruri_attr(): failed to parse the R-URI
>>
>> Oct  7 06:43:50.895431 spce proxy[837565]: ERROR: ROUTE_PSTN pv
>> [pv_core.c:336]: pv_get_ruri_attr(): failed to parse the R-URI
>>
>> Oct  7 06:43:50.895538 spce proxy[837565]: ERROR: <null> pv
>> [pv_core.c:336]: pv_get_ruri_attr(): failed to parse the R-URI
>>
>> Oct  7 06:43:50.895558 spce proxy[837565]: ERROR: <null> pv
>> [pv_core.c:336]: pv_get_ruri_attr(): failed to parse the R-URI
>>
>> Oct  7 06:43:50.901133 spce proxy[837565]: ERROR: ROUTE_OUTBOUND pv
>> [pv_core.c:336]: pv_get_ruri_attr(): failed to parse the R-URI
>>
>> Oct  7 06:43:50.901156 spce proxy[837565]: ERROR: ROUTE_OUTBOUND pv
>> [pv_core.c:336]: pv_get_ruri_attr(): failed to parse the R-URI
>>
>> Oct  7 06:43:50.901829 spce proxy[837565]: ERROR:
>> ROUTE_APPLY_REWRITE_RULE pv [pv_core.c:261]: pv_get_ruri(): failed to parse
>> the R-URI
>> *****
>>  I am looking for where I can set the system to a specific R-URI or check
>> the system to use network provided R-RURI.
>>
>> Please help.
>>
>> Thanks
>>
>>
>> --
>> -----
>> Ekunwe
>> Tel: 601.497.3932
>> --
>> Spce-user mailing list
>> Spce-user at lists.sipwise.com
>> http://lists.sipwise.com/mailman/listinfo/spce-user_lists.sipwise.com
>>
>

-- 
-----
Ekunwe
Tel: 601.497.3932
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.sipwise.com/pipermail/spce-user_lists.sipwise.com/attachments/20241007/4f6722c4/attachment-0001.htm>


More information about the Spce-user mailing list