[Spce-user] [EXTERNAL] SIP Calls Failure with timeout on mr13.5.1LTS - Works on mr8.5.1
Marco Capetta
mcapetta at sipwise.com
Mon Nov 3 08:24:40 EST 2025
Hi,
About the error line you have reported:
"*ERROR: ROUTE_BRANCH_ACC_RTP dialog [dialog.c:1868]:
ki_dlg_get_var_helper(): invalid Call-ID parameter"*
*We have already a fix ready. We are going to test it internally and then
we will backport soon to all the supported versions.*
*About the routing issue, your configuration look correct to me.*
*I suggest you to collect a sip trace (suing sngrep or tcpdump) and double
check if the message correctly leaves NGCP LB to reach the final
destination. If the CE system correctly send out the message, then I would
move the investigation in the network components.*
*Please let me know if we can help you further in the investigation.*
*Thank you*
*Marco*
On Fri, Oct 31, 2025 at 10:39 PM list mailing <list.mailing.2025 at gmail.com>
wrote:
> Dear mailing list members,
> I was trying to deploy a new installation of sipwise CE 13.5.1 and I get
> this error when testing calls.
>
>
> *ERROR: ROUTE_BRANCH_ACC_RTP dialog [dialog.c:1868]:
> ki_dlg_get_var_helper(): invalid Call-ID parameter*
> Currently, I am in the phase of testing the basic network configuration
> before enabling peering and advanced settings. I have configured the
> network interfaces as follows:
>
> neth1: type=sip_ext and rtp_ext (To connect to a peering in the future)
> Subnet: 172.100.100.0/29
> neth2: type=sip_ext_incoming
> Subnet: 172.16.0.0/16
> neth3: type=sip_ext_incoming Public IP
>
> The tests I am conducting involve making calls between devices connected
> to these different interfaces. Additionally, I am actively monitoring SIP
> transactions during these calls to validate signaling behavior.
>
> The specific problem manifests in calls going from the neth2 interface to
> the neth3 interface. This scenario fails, and upon reviewing SIP
> transactions, we observe an "*Reply LEG_B - S=408 - Request Timeout*"
> response. However, calls in the opposite direction (from neth3 to neth2)
> function correctly, with SIP transactions completing as expected.
>
> It is important to note that this same test scenario works flawlessly on
> an older version, mr8.5.2, with the exact same network configuration and
> interfaces.
>
> I have temporarily disabled the firewall to ensure it is not the cause of
> the problem.
>
> - Has anyone experienced similar behavior with mr13.5.1 LTS, particularly
> concerning SIP signaling in flows between interfaces configured in this
> manner?
> - Could the following error be related to the problem?
>
>
>
>
> * # iptables -L target prot opt source destination
> Error: target extension not found # iptables v1.8.11 (nf_tables):
> Parsing nftables rule failed Perhaps iptables or your kernel needs to be
> upgraded.*
>
> I would appreciate any suggestions on potential points of failure in
> version mr13.5.1, or further diagnostic steps that might help identify the
> root cause in the SIP transactions.
> I'm adding a few lines of log data.
>
> Thank you in advance for your time and help.
>
> Best regards,
>
> Dario T
>
> I am also adding notes that may be useful for analysis.
>
>
>
>
>
>
>
>
>
>
>
>
> *# uname -aLinux spce 6.12.48+deb13-amd64 #1 SMP PREEMPT_DYNAMIC Debian
> 6.12.48-1 (2025-09-20) x86_64 GNU/Linux#lsmod | grep -i rtpxt_RTPENGINE
> 81920 3x_tables 53248 3
> nft_compat,xt_RTPENGINE,ip_tables# lsmod | grep -i nftnft_compat
> 20480 1nf_tables 380928 6 nft_compatnfnetlink
> 20480 3 nft_compat,nf_tablesx_tables 53248 3
> nft_compat,xt_RTPENGINE,ip_tables*
> kamailio-proxy.log
> ```log
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
>
> *Oct 29 15:11:29.635257 spce proxy[6044]: NOTICE: DEFAULT_ROUTE <script>:
> New request on proxy - M=INVITE R=«sip:51187654321 at ss.example.org:5060»
> F=«sip:alice at ss.example.org <sip%3Aalice at ss.example.org>»
> T=«sip:51187654321 at ss.example.org <sip%3A51187654321 at ss.example.org>»
> IP=«172.16.100.209»:«5060» («127.0.0.1»:«5060»)
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'
> DESTIP=«127.0.0.1»:«5062»Oct 29 15:11:29.635305 spce proxy[6044]: 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:51187654321 at ss.example.org:5060»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.635316 spce
> proxy[6044]: INFO: DEFAULT_ROUTE <script>: processing INVITE -
> R=«sip:51187654321 at ss.example.org:5060»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.635326 spce
> proxy[6044]: DEBUG: ROUTE_CHECK_TEL_URI <script>:
> x_hdr(From):«<sip:alice at ss.example.org
> <sip%3Aalice at ss.example.org>>;tag=VxUyKI6TlvPyt7OGWLD-tWDU3S5Yq9p-» -
> R=«sip:51187654321 at ss.example.org:5060»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.635336 spce
> proxy[6044]: DEBUG: DEFAULT_ROUTE <script>: pua_dialoginfo: Disable PUBLISH
> messages to caller setting FLB_PRESENCE_CALLER flag -
> R=«sip:51187654321 at ss.example.org:5060»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.635345 spce
> proxy[6044]: DEBUG: DEFAULT_ROUTE <script>: pua_dialoginfo: Disable PUBLISH
> messages to callee setting FLB_PRESENCE_CALLEE flag -
> R=«sip:51187654321 at ss.example.org:5060»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.635521 spce
> proxy[6044]: DEBUG: ROUTE_INVITE <script>: pua_dialoginfo: Set flag
> presence to activate the publish messages -
> R=«sip:51187654321 at ss.example.org:5060»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.635538 spce
> proxy[6044]: NOTICE: ROUTE_LOAD_CALLEE_DOMAIN_PREF <script>: Load domain
> preferences for callee '«ss.example.org <http://ss.example.org>»' -
> R=«sip:51187654321 at ss.example.org:5060»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.639320 spce
> proxy[6044]: INFO: ROUTE_CLEAR_CALLEE_DOMAIN_PREF <script>: Clean domain
> preferences for callee - R=«sip:51187654321 at ss.example.org:5060»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.639630 spce
> proxy[6044]: INFO: ROUTE_FIND_CALLER <script>: +++++++++++++++ find caller
> - R=«sip:51187654321 at ss.example.org:5060»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.639876 spce
> proxy[6044]: DEBUG: ROUTE_FIND_CALLER <script>: pua_dialoginfo: Set by
> default puburis_caller to a fake (random) value and disable PUBLISH
> messages to caller setting FLB_PRESENCE_CALLER flag -
> R=«sip:51187654321 at ss.example.org:5060»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.640250 spce
> proxy[6044]: NOTICE: ROUTE_AUTH <script>: Authentication failed, no
> credentials - R=«sip:51187654321 at ss.example.org:5060»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1' Auth=«<null>»Oct 29
> 15:11:29.640491 spce proxy[6044]: NOTICE: ROUTE_AUTH <script>: Sending
> reply S=407 fs='«127.0.0.1»:«5062»' du='«127.0.0.1»:«5060»' -
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.641366 spce
> proxy[6043]: NOTICE: sl:filtered-ack <script>: New request on proxy - M=ACK
> R=«sip:51187654321 at ss.example.org:5060» F=«sip:alice at ss.example.org
> <sip%3Aalice at ss.example.org>» T=«sip:51187654321 at ss.example.org
> <sip%3A51187654321 at ss.example.org>» IP=«<null>»:«<null>»
> («127.0.0.1»:«5060») ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='<null>'
> DESTIP=«127.0.0.1»:«5062»Oct 29 15:11:29.641381 spce proxy[6044]: INFO:
> ROUTE_EXIT <script>: INVITE processed -
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE»Oct 29 15:11:29.641390 spce
> proxy[6044]: INFO: ROUTE_EXIT <script>: Runtime for request M=INVITE was
> 6053 usec - ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE»Oct 29 15:11:29.645694
> spce proxy[6041]: NOTICE: DEFAULT_ROUTE <script>: New request on proxy -
> M=INVITE R=«sip:51187654321 at ss.example.org:5060»
> F=«sip:alice at ss.example.org <sip%3Aalice at ss.example.org>»
> T=«sip:51187654321 at ss.example.org <sip%3A51187654321 at ss.example.org>»
> IP=«172.16.100.209»:«5060» («127.0.0.1»:«5060»)
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'
> DESTIP=«127.0.0.1»:«5062»Oct 29 15:11:29.645727 spce proxy[6041]: 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:51187654321 at ss.example.org:5060»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.645741 spce
> proxy[6041]: INFO: DEFAULT_ROUTE <script>: processing INVITE -
> R=«sip:51187654321 at ss.example.org:5060»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.645751 spce
> proxy[6041]: DEBUG: ROUTE_CHECK_TEL_URI <script>:
> x_hdr(From):«<sip:alice at ss.example.org
> <sip%3Aalice at ss.example.org>>;tag=VxUyKI6TlvPyt7OGWLD-tWDU3S5Yq9p-» -
> R=«sip:51187654321 at ss.example.org:5060»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.645761 spce
> proxy[6041]: DEBUG: DEFAULT_ROUTE <script>: pua_dialoginfo: Disable PUBLISH
> messages to caller setting FLB_PRESENCE_CALLER flag -
> R=«sip:51187654321 at ss.example.org:5060»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.645770 spce
> proxy[6041]: DEBUG: DEFAULT_ROUTE <script>: pua_dialoginfo: Disable PUBLISH
> messages to callee setting FLB_PRESENCE_CALLEE flag -
> R=«sip:51187654321 at ss.example.org:5060»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.645779 spce
> proxy[6041]: DEBUG: ROUTE_INVITE <script>: pua_dialoginfo: Set flag
> presence to activate the publish messages -
> R=«sip:51187654321 at ss.example.org:5060»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.645788 spce
> proxy[6041]: NOTICE: ROUTE_LOAD_CALLEE_DOMAIN_PREF <script>: Load domain
> preferences for callee '«ss.example.org <http://ss.example.org>»' -
> R=«sip:51187654321 at ss.example.org:5060»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.648482 spce
> proxy[6041]: INFO: ROUTE_CLEAR_CALLEE_DOMAIN_PREF <script>: Clean domain
> preferences for callee - R=«sip:51187654321 at ss.example.org:5060»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.648876 spce
> proxy[6041]: INFO: ROUTE_FIND_CALLER <script>: +++++++++++++++ find caller
> - R=«sip:51187654321 at ss.example.org:5060»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.648898 spce
> proxy[6041]: DEBUG: ROUTE_FIND_CALLER <script>: pua_dialoginfo: Set by
> default puburis_caller to a fake (random) value and disable PUBLISH
> messages to caller setting FLB_PRESENCE_CALLER flag -
> R=«sip:51187654321 at ss.example.org:5060»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.649526 spce
> proxy[6041]: INFO: ROUTE_ADD_CALLINFO_REPLY <script>: Adding reply
> P-NGCP-Caller-Info '<sip:«alice»@«ss.example.org
> <http://ss.example.org>»>;ip=«172.16.100.209»;port=«5060»«;primary=51123456789»«»'
> - ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.649682
> spce proxy[6041]: NOTICE: ROUTE_FIND_CALLER <script>: Sending reply S=101
> Connecting fs='«127.0.0.1»:«5062»' du='«127.0.0.1»:«5060»' -
> R=«sip:51187654321 at ss.example.org:5060»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.650929 spce
> proxy[6041]: INFO: ROUTE_INVITE <script>: IMS marker, s:ims_role='<null>',
> s:caller_uuid='«03fd71a7-df7a-4f89-8eb6-7283013550dc»',
> s:callee_uuid='«<null>»', s:acc_caller_user='«alice»',
> s:acc_caller_domain='«ss.example.org <http://ss.example.org>»' -
> R=«sip:51187654321 at ss.example.org:5060»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.650941 spce
> proxy[6041]: INFO: ROUTE_CLEAR_CALLER_PREF <script>: Clear caller
> preferences - R=«sip:51187654321 at ss.example.org:5060»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.650952 spce
> proxy[6041]: NOTICE: ROUTE_LOAD_CALLER_PREF <script>: Load caller
> preferences for uuid '«03fd71a7-df7a-4f89-8eb6-7283013550dc»' and domain
> '«ss.example.org <http://ss.example.org>»' -
> R=«sip:51187654321 at ss.example.org:5060»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.654422 spce
> proxy[6041]: INFO: ROUTE_CHECK_UA <script>: Checking User-Agent filters -
> R=«sip:51187654321 at ss.example.org:5060»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.654519 spce
> proxy[6041]: INFO: ROUTE_CHECK_UA <script>: User-Agent header found, check
> filter list - R=«sip:51187654321 at ss.example.org:5060»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.654637 spce
> proxy[6041]: INFO: ROUTE_CHECK_UA <script>: UA filter mode is 'blacklist' -
> R=«sip:51187654321 at ss.example.org:5060»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.654717 spce
> proxy[6041]: INFO: ROUTE_CHECK_UA <script>: UA filter checks passed -
> R=«sip:51187654321 at ss.example.org:5060»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.654903 spce
> proxy[6041]: NOTICE: ROUTE_LOAD_CALLER_CONTRACT_PREF <script>: Load caller
> contract preferences for contract id '«2»' and ip '«172.16.100.209»' -
> R=«sip:51187654321 at ss.example.org:5060»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.655447 spce
> proxy[6041]: INFO: ROUTE_LOAD_CALLER_CONTRACT_PREF <script>: Loaded caller
> contract preferences for location id '<null>' -
> R=«sip:51187654321 at ss.example.org:5060»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.655532 spce
> proxy[6041]: NOTICE: ROUTE_LOAD_CALLER_RESELLER_PREF <script>: Load caller
> reseller preferences for reseller id '«1»' -
> R=«sip:51187654321 at ss.example.org:5060»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.656712 spce
> proxy[6041]: INFO: ROUTE_LOAD_CALLER_PREF <script>: Setting
> network-provided domain '«ss.example.org <http://ss.example.org>»' as
> acc_caller_domain - R=«sip:51187654321 at ss.example.org:5060»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.656826 spce
> proxy[6041]: INFO: ROUTE_LOAD_CALLER_PREF <script>: Use lb/rtp set id
> '«50»' for local caller - R=«sip:51187654321 at ss.example.org:5060»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.656910 spce
> proxy[6041]: INFO: ROUTE_LOAD_CALLER_PREF <script>: Fetched dialplan IDs
> caller_in='<null>', callee_in='<null>' -
> R=«sip:51187654321 at ss.example.org:5060»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.656976 spce
> proxy[6041]: INFO: ROUTE_LOAD_CALLER_PREF <script>: CDR IP header
> 'P-NGCP-Src-Ip' not found, use 'P-NGCP-Src-Ip' -
> R=«sip:51187654321 at ss.example.org:5060»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.657339 spce
> proxy[6041]: NOTICE: ROUTE_DLG_MANAGE <script>: Dialog managed,
> lua_dlg_callid:[«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE»] -
> R=«sip:51187654321 at ss.example.org:5060»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.657795 spce
> proxy[6041]: INFO: ROUTE_INVITE <script>: ccli_selector for inbound_upn has
> been set to 'from_user' - R=«sip:51187654321 at ss.example.org:5060»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.657812 spce
> proxy[6041]: NOTICE: ROUTE_GET_CALLER_CLI <script>: User-Provided CLI
> '«alice»' taken from From-User - R=«sip:51187654321 at ss.example.org:5060»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.657823 spce
> proxy[6041]: INFO: ROUTE_INVITE <script>: ccli_selector for inbound_uprn
> has been set to 'npn' - R=«sip:51187654321 at ss.example.org:5060»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.657833 spce
> proxy[6041]: INFO: ROUTE_INVITE <script>: IP authorization for caller not
> provisioned, allow call - R=«sip:51187654321 at ss.example.org:5060»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.657842 spce
> proxy[6041]: INFO: ROUTE_CALLER_BLOCK_CLI <script>: Checking UPN '«alice»'
> and NPN '«51123456789»' against blocked cli lists -
> R=«sip:51187654321 at ss.example.org:5060»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.657852 spce
> proxy[6041]: INFO: ROUTE_CALLER_BLOCK_CLI <script>: Caller UPN block mode
> is 'blacklist' - R=«sip:51187654321 at ss.example.org:5060»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.658683 spce
> proxy[6041]: INFO: ROUTE_CHECK_CLI_ALLOWED <script>: Checking User-provided
> CLI against allowed CLIs - R=«sip:51187654321 at ss.example.org:5060»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.658741 spce
> proxy[6041]: NOTICE: ROUTE_CHECK_CLI_ALLOWED <script>: User-provided CLI
> '«alice»' rejected, using network-provided CLI '«51123456789»' -
> R=«sip:51187654321 at ss.example.org:5060»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.658755 spce
> proxy[6041]: NOTICE: ROUTE_INVITE <script>: Setting
> '«51123456789»@«ss.example.org <http://ss.example.org>»' as initiating
> user-provided CLI - R=«sip:51187654321 at ss.example.org:5060»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.658779 spce
> proxy[6041]: NOTICE: ROUTE_INVITE <script>: Setting
> '«51123456789»@«ss.example.org <http://ss.example.org>»' as initiating
> network-provided CLI - R=«sip:51187654321 at ss.example.org:5060»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.658789 spce
> proxy[6041]: INFO: ROUTE_FIND_CALLEE <script>: Searching for callee -
> R=«sip:51187654321 at ss.example.org:5060»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.659866 spce
> proxy[6041]: INFO: ROUTE_FIND_CALLEE <core> [core/kemi.c:109]:
> sr_kemi_core_info():
> central:hset[out_03fd71a7-df7a-4f89-8eb6-7283013550dc]=>[true] callee:
> 51187654321 expire: 86400Oct 29 15:11:29.660240 spce proxy[6041]: INFO:
> ROUTE_FIND_CALLEE <script>: Saved outgoing recent call for uuid
> «03fd71a7-df7a-4f89-8eb6-7283013550dc» with key
> «out_03fd71a7-df7a-4f89-8eb6-7283013550dc» -
> R=«sip:51187654321 at ss.example.org:5060»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.661699 spce
> proxy[6041]: NOTICE: ROUTE_FIND_CALLEE <script>: Callee was aliased with
> base '«51187654321»' - R=«sip:bob at ss.example.org:5060»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.661847 spce
> proxy[6041]: INFO: ROUTE_CLEAR_CALLEE_PREF <script>: Clear callee
> preferences - R=«sip:bob at ss.example.org:5060»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.662224 spce
> proxy[6041]: NOTICE: ROUTE_FIND_CALLEE <script>: Callee is local,
> uuid='«99d31b34-96d5-4dbb-b89a-14847096007c»' -
> R=«sip:bob at ss.example.org:5060» ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE»
> UA='uagv1'Oct 29 15:11:29.662515 spce proxy[6041]: NOTICE:
> ROUTE_LOAD_CALLEE_PREF <script>: Load callee preferences for uuid
> '«99d31b34-96d5-4dbb-b89a-14847096007c»' domain: '«ss.example.org
> <http://ss.example.org>»'- R=«sip:bob at ss.example.org:5060»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.665512 spce
> proxy[6041]: DEBUG: ROUTE_LOAD_CALLEE_PREF <script>: pua_dialoginfo: Set
> local_identity to 'sip:bob at ss.example.org <sip%3Abob at ss.example.org>' -
> R=«sip:bob at ss.example.org:5060» ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE»
> UA='uagv1'Oct 29 15:11:29.665666 spce proxy[6041]: NOTICE:
> ROUTE_LOAD_CALLEE_CONTRACT_PREF <script>: Load callee contract preferences
> for contract id '«2» and ip '«<null>»' - R=«sip:bob at ss.example.org:5060»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.666166 spce
> proxy[6041]: INFO: ROUTE_LOAD_CALLEE_CONTRACT_PREF <script>: Loaded callee
> contract preferences for location id '«<null>»' -
> R=«sip:bob at ss.example.org:5060» ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE»
> UA='uagv1'Oct 29 15:11:29.666244 spce proxy[6041]: NOTICE:
> ROUTE_LOAD_CALLEE_RESELLER_PREF <script>: Load callee reseller preferences
> for reseller id '«1» - R=«sip:bob at ss.example.org:5060»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.666702 spce
> proxy[6041]: INFO: ROUTE_LOAD_CALLEE_PREF <script>: Use lb/rtp set id
> '«50»' for local callee - R=«sip:bob at ss.example.org:5060»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.667163 spce
> proxy[6041]: INFO: ROUTE_LOAD_CALLEE_PREF <script>: Fetched dialplan IDs
> caller_out='<null>', callee_out='<null>' - R=«sip:bob at ss.example.org:5060»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.668145 spce
> proxy[6041]: INFO: ROUTE_SET_CALLEE_DIALOG_BASE <script>: Set callee
> dialogs: user, account to '«99d31b34-96d5-4dbb-b89a-14847096007c»/2' -
> R=«sip:bob at ss.example.org:5060» ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE»
> UA='uagv1'Oct 29 15:11:29.670181 spce proxy[6041]: INFO:
> ROUTE_SET_CALLEE_DIALOG_TOTAL <script>: Set callee dialogs: totaluser,
> totalaccount,totalreseller to '«99d31b34-96d5-4dbb-b89a-14847096007c»/2/1'
> - R=«sip:bob at ss.example.org:5060» ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE»
> UA='uagv1'Oct 29 15:11:29.670200 spce proxy[6041]: INFO: ROUTE_BLOCK_IN
> <script>: Checking UPN '«51123456789»', NPN '«51123456789»', First UPN
> '«51123456789»' and First NPN '«51123456789»' against block in lists -
> R=«sip:bob at ss.example.org:5060» ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE»
> UA='uagv1'Oct 29 15:11:29.670211 spce proxy[6041]: INFO: ROUTE_BLOCK_IN
> <script>: Admin Contract callee block mode is 'blacklist' -
> R=«sip:bob at ss.example.org:5060» ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE»
> UA='uagv1'Oct 29 15:11:29.670221 spce proxy[6041]: INFO: ROUTE_BLOCK_IN
> <script>: Admin callee block mode is 'blacklist' -
> R=«sip:bob at ss.example.org:5060» ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE»
> UA='uagv1'Oct 29 15:11:29.670231 spce proxy[6041]: INFO: ROUTE_BLOCK_IN
> <script>: Contract callee block mode is 'blacklist' -
> R=«sip:bob at ss.example.org:5060» ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE»
> UA='uagv1'Oct 29 15:11:29.670240 spce proxy[6041]: INFO: ROUTE_BLOCK_IN
> <script>: Callee block mode is 'blacklist' -
> R=«sip:bob at ss.example.org:5060» ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE»
> UA='uagv1'Oct 29 15:11:29.670249 spce proxy[6041]: INFO: ROUTE_NCOS_CHECK
> <script>: Check Administrative Contract NCOS level -
> R=«sip:bob at ss.example.org:5060» ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE»
> UA='uagv1'Oct 29 15:11:29.670259 spce proxy[6041]: INFO: ROUTE_NCOS_CHECK
> <script>: Check Administrative Contract NCOS Set -
> R=«sip:bob at ss.example.org:5060» ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE»
> UA='uagv1'Oct 29 15:11:29.670268 spce proxy[6041]: INFO: ROUTE_NCOS_CHECK
> <script>: Check Administrative NCOS level - R=«sip:bob at ss.example.org:5060»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.670278 spce
> proxy[6041]: INFO: ROUTE_NCOS_CHECK <script>: Check Administrative NCOS Set
> - R=«sip:bob at ss.example.org:5060» ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE»
> UA='uagv1'Oct 29 15:11:29.670287 spce proxy[6041]: INFO: ROUTE_NCOS_CHECK
> <script>: Check Contract NCOS level - R=«sip:bob at ss.example.org:5060»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.670297 spce
> proxy[6041]: INFO: ROUTE_NCOS_CHECK <script>: Check Contract NCOS Set -
> R=«sip:bob at ss.example.org:5060» ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE»
> UA='uagv1'Oct 29 15:11:29.670306 spce proxy[6041]: INFO: ROUTE_NCOS_CHECK
> <script>: Check User NCOS level - R=«sip:bob at ss.example.org:5060»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.670315 spce
> proxy[6041]: INFO: ROUTE_NCOS_CHECK <script>: Check User NCOS Set -
> R=«sip:bob at ss.example.org:5060» ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE»
> UA='uagv1'Oct 29 15:11:29.670325 spce proxy[6041]: INFO: ROUTE_BLOCK_OUT
> <script>: Checking URI '«sip:bob at ss.example.org
> <sip%3Abob at ss.example.org>»' and CLI '«51187654321»' against admin contract
> block out lists - R=«sip:bob at ss.example.org:5060»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.670334 spce
> proxy[6041]: INFO: ROUTE_BLOCK_OUT <script>: Admin Contract caller block
> mode is 'blacklist' - R=«sip:bob at ss.example.org:5060»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.670343 spce
> proxy[6041]: INFO: ROUTE_BLOCK_OUT <script>: Checking URI
> '«sip:bob at ss.example.org <sip%3Abob at ss.example.org>»' and CLI
> '«51187654321»' against block out lists - R=«sip:bob at ss.example.org:5060»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.670352 spce
> proxy[6041]: INFO: ROUTE_BLOCK_OUT <script>: Admin caller block mode is
> 'blacklist' - R=«sip:bob at ss.example.org:5060»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.670361 spce
> proxy[6041]: INFO: ROUTE_BLOCK_OUT <script>: Checking URI
> '«sip:bob at ss.example.org <sip%3Abob at ss.example.org>»' and CLI
> '«51187654321»' against contract block out lists -
> R=«sip:bob at ss.example.org:5060» ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE»
> UA='uagv1'Oct 29 15:11:29.670370 spce proxy[6041]: INFO: ROUTE_BLOCK_OUT
> <script>: Contract caller block mode is 'blacklist' -
> R=«sip:bob at ss.example.org:5060» ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE»
> UA='uagv1'Oct 29 15:11:29.670379 spce proxy[6041]: INFO: ROUTE_BLOCK_OUT
> <script>: Caller block mode is 'blacklist' -
> R=«sip:bob at ss.example.org:5060» ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE»
> UA='uagv1'Oct 29 15:11:29.671206 spce proxy[6041]: INFO:
> ROUTE_INVITE_TO_INT <script>: Dialog set mark type to local -
> R=«sip:bob at ss.example.org:5060» ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE»
> UA='uagv1'Oct 29 15:11:29.673744 spce proxy[6041]: INFO:
> ROUTE_SET_CALLER_DIALOG_TOTAL <script>: Dialog set total -
> R=«sip:bob-c6NONwRkf6N5JRP at 192.168.1.103:43779»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.673825 spce
> proxy[6041]: INFO: ROUTE_SET_CALLER_DIALOG_TOTAL <script>: Set caller
> dialogs: totaluser, totaluserout, totalaccount, totalaccountout to
> '«03fd71a7-df7a-4f89-8eb6-7283013550dc»/«2»' -
> R=«sip:bob-c6NONwRkf6N5JRP at 192.168.1.103:43779»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.675648 spce
> proxy[6041]: INFO: ROUTE_SET_CALLER_DIALOG_BASE <script>: Set caller
> dialogs: user, userout, account, accountout to
> '«03fd71a7-df7a-4f89-8eb6-7283013550dc»/«2»' -
> R=«sip:bob-c6NONwRkf6N5JRP at 192.168.1.103:43779»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.676489 spce
> proxy[6041]: NOTICE: ROUTE_ACC_CALLER <script>: Setting acc source-leg for
> uuid '«03fd71a7-df7a-4f89-8eb6-7283013550dc»':
> '«{"gpp":[null,null,null,null,null,null,null,null,null,null],"clir":0,"uuid":"03fd71a7-df7a-4f89-8eb6-7283013550dc","u":"alice","d":"ss.example.org
> <http://ss.example.org>","cli":"51123456789","s_id":"","c_id":"","a_id":2,"pau":"","par":"","s":"call","ip":"172.16.100.209","t":1761761489.6761539,"lnp_p":"","cli_out":"51123456789","lnp_t":"","pai":"","ppi":"","div":"","last_hih":"","cid":"","u2u":"","lcr":0,"cc_quota":"","cc_sub":"1","cc_cust":"2"}»'
> - R=«sip:bob-c6NONwRkf6N5JRP at 192.168.1.103:43779»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.677193 spce
> proxy[6041]: NOTICE: ROUTE_ACC_CALLEE <script>: Setting acc destination-leg
> for uuid '«99d31b34-96d5-4dbb-b89a-14847096007c»':
> '«{"gpp":[null,null,null,null,null,null,null,null,null,null],"plu":0,"s_id":"","c_id":"","a_id":2,"dialed":"51187654321","uuid":"99d31b34-96d5-4dbb-b89a-14847096007c","u":"bob","d":"ss.example.org
> <http://ss.example.org>","u_in":"51187654321","d_in":"ss.example.org
> <http://ss.example.org>","lcr":0,"lnp_p":"","u_out":"bob","lnp_t":"","fci":"","cc_quota":"","cc_sub":"1","cc_cust":"2"}»'
> - R=«sip:bob-c6NONwRkf6N5JRP at 192.168.1.103:43779»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.677244 spce
> proxy[6041]: INFO: ROUTE_OUTBOUND <script>: Relaying request,
> du='«sip:lb at 127.0.0.1
> <sip%3Alb at 127.0.0.1>;lr;received=sip:160.1.100.100:43779;socket=sip:131.3.1.1:5060»'
> - R=«sip:bob-c6NONwRkf6N5JRP at 192.168.1.103:43779»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.677506 spce
> proxy[6041]: INFO: BRANCH_ROUTE_SBC <script>: +++ Entering branch route
> BRANCH_ROUTE_SBC with dest uri «sip:lb at 127.0.0.1
> <sip%3Alb at 127.0.0.1>;lr;received=sip:160.1.100.100:43779;socket=sip:131.3.1.1:5060»
> - R=«sip:bob-c6NONwRkf6N5JRP at 192.168.1.103:43779»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.677750 spce
> proxy[6041]: NOTICE: ROUTE_LOAD_CALLEE_CONTRACT_PREF <script>: Load callee
> contract preferences for contract id '«2» and ip '«160.1.100.100»' -
> R=«sip:bob-c6NONwRkf6N5JRP at 192.168.1.103:43779»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.678082 spce
> proxy[6041]: INFO: ROUTE_LOAD_CALLEE_CONTRACT_PREF <script>: Loaded callee
> contract preferences for location id '«<null>»' -
> R=«sip:bob-c6NONwRkf6N5JRP at 192.168.1.103:43779»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.678099 spce
> proxy[6041]: NOTICE: ROUTE_LOAD_CALLEE_RESELLER_PREF <script>: Load callee
> reseller preferences for reseller id '«1» -
> R=«sip:bob-c6NONwRkf6N5JRP at 192.168.1.103:43779»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.678297 spce
> proxy[6041]: INFO: ROUTE_SET_CALLEE_DIALOG_BASE <script>: Set callee
> dialogs: user, account to '«99d31b34-96d5-4dbb-b89a-14847096007c»/2' -
> R=«sip:bob-c6NONwRkf6N5JRP at 192.168.1.103:43779»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.678314 spce
> proxy[6041]: INFO: ROUTE_SET_CALLEE_DIALOG_TOTAL <script>: Set callee
> dialogs: totaluser, totalaccount,totalreseller to
> '«99d31b34-96d5-4dbb-b89a-14847096007c»/2/1' -
> R=«sip:bob-c6NONwRkf6N5JRP at 192.168.1.103:43779»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.678354 spce
> proxy[6041]: INFO: ROUTE_SET_BRANCH_HDRS <script>: Setting P-Caller-UUID to
> '«03fd71a7-df7a-4f89-8eb6-7283013550dc»' -
> R=«sip:bob-c6NONwRkf6N5JRP at 192.168.1.103:43779»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.678420 spce
> proxy[6041]: INFO: ROUTE_SET_BRANCH_HDRS <script>: Setting P-Callee-UUID to
> '«99d31b34-96d5-4dbb-b89a-14847096007c»' -
> R=«sip:bob-c6NONwRkf6N5JRP at 192.168.1.103:43779»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.678497 spce
> proxy[6041]: INFO: ROUTE_PREPARE_UA <script>: User Agent header removed -
> R=«sip:bob-c6NONwRkf6N5JRP at 192.168.1.103:43779»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.678588 spce
> proxy[6041]: INFO: ROUTE_SET_RUSER <script>: Local user online, using
> registered contact as user -
> R=«sip:bob-c6NONwRkf6N5JRP at 192.168.1.103:43779»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.678689 spce
> proxy[6041]: NOTICE: ROUTE_BRANCH_ACC_RTP <script>: Not Forcing RTP/AVP
> towards b2b because local service or caller/callee are not pbx users -
> R=«sip:bob-c6NONwRkf6N5JRP at 192.168.1.103:43779»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.678706 spce
> proxy[6041]: ERROR: ROUTE_BRANCH_ACC_RTP dialog [dialog.c:1868]:
> ki_dlg_get_var_helper(): invalid Call-ID parameterOct 29 15:11:29.678811
> spce proxy[6041]: INFO: ROUTE_BRANCH_ACC_RTP <script>: Use rtpengine for
> forward direction for IPv4/IPv4 -
> R=«sip:bob-c6NONwRkf6N5JRP at 192.168.1.103:43779»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.679856 spce
> proxy[6041]: INFO: ROUTE_BRANCH_ACC_RTP <script>: Remove existing ICE
> candidates (if any) for call to local service -
> R=«sip:bob-c6NONwRkf6N5JRP at 192.168.1.103:43779»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.679874 spce
> proxy[6041]: INFO: ROUTE_BRANCH_ACC_RTP <script>: Try protocol
> 'transparent' for callee - R=«sip:bob-c6NONwRkf6N5JRP at 192.168.1.103:43779»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.679884 spce
> proxy[6041]: INFO: ROUTE_BRANCH_ACC_RTP <script>: Use rtcp-mux=[demux] for
> callee - R=«sip:bob-c6NONwRkf6N5JRP at 192.168.1.103:43779»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.679896 spce
> proxy[6041]: INFO: ROUTE_BRANCH_ACC_RTP <script>: Engaging rtpengine in
> request for caller did '«50»' and callee did '«50»' -
> R=«sip:bob-c6NONwRkf6N5JRP at 192.168.1.103:43779»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.679907 spce
> proxy[6041]: INFO: ROUTE_BRANCH_ACC_RTP <script>: Setting last transport
> protocol to «transparent» - R=«sip:bob-c6NONwRkf6N5JRP at 192.168.1.103:43779»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.680001 spce
> proxy[6041]: DEBUG: ROUTE_BRANCH_ACC_RTP <script>: RTPENGINE OFFER:
> rtpp_flags:[address-family=IP4 debug transport-protocol=transparent
> rtcp-mux=[demux] ICE=remove ]-
> R=«sip:bob-c6NONwRkf6N5JRP at 192.168.1.103:43779»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.682632 spce
> proxy[6041]: INFO: ROUTE_PREPARE_SST <script>: Sessions Timers enabled,
> check configuration of caller and callee -
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.682933 spce
> proxy[6041]: INFO: ROUTE_PREPARE_SST <script>: Sessions Timers disabled for
> caller - R=«sip:bob-c6NONwRkf6N5JRP at 192.168.1.103:43779»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.683216 spce
> proxy[6041]: INFO: ROUTE_PREPARE_SST <script>: Sessions Timers disabled for
> callee - R=«sip:bob-c6NONwRkf6N5JRP at 192.168.1.103:43779»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.683226 spce
> proxy[6041]: INFO: ROUTE_REMOVE_TIMER_SUPP_REQ <script>: Timer successfully
> removed from Supported - ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE»
> UA='uagv1'Oct 29 15:11:29.683235 spce proxy[6041]: INFO:
> ROUTE_REMOVE_TIMER_SUPP_REQ <script>: Timer successfully removed from
> Require - ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29
> 15:11:29.683244 spce proxy[6041]: INFO: ROUTE_REMOVE_TIMER_SUPP_REQ
> <script>: Session-Expires successfully removed -
> R=«sip:bob-c6NONwRkf6N5JRP at 192.168.1.103:43779»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.683254 spce
> proxy[6041]: INFO: ROUTE_SET_CALLER_CLI <script>: Setting userprovided
> caller domain - R=«sip:bob-c6NONwRkf6N5JRP at 192.168.1.103:43779»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.683263 spce
> proxy[6041]: INFO: ROUTE_SET_CALLER_CLI <script>: Use first userprov caller
> domain '«ss.example.org <http://ss.example.org>»' -
> R=«sip:bob-c6NONwRkf6N5JRP at 192.168.1.103:43779»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.683272 spce
> proxy[6041]: INFO: ROUTE_SET_CALLER_CLI <script>: Prepare From display-name
> setting - R=«sip:bob-c6NONwRkf6N5JRP at 192.168.1.103:43779»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.683282 spce
> proxy[6041]: INFO: ROUTE_PREPARE_CALLER_CLI <script>: No selector set, not
> setting CLI - R=«sip:bob-c6NONwRkf6N5JRP at 192.168.1.103:43779»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.683291 spce
> proxy[6041]: INFO: ROUTE_SET_CALLER_CLI <script>: Prepare From username
> setting - R=«sip:bob-c6NONwRkf6N5JRP at 192.168.1.103:43779»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.683300 spce
> proxy[6041]: NOTICE: ROUTE_PREPARE_CALLER_CLI <script>: Setting
> caller_cli_userprov/caller_domain_userprov '«51123456789»@«ss.example.org
> <http://ss.example.org>»' for upn -
> R=«sip:bob-c6NONwRkf6N5JRP at 192.168.1.103:43779»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.683309 spce
> proxy[6041]: NOTICE: ROUTE_SET_CALLER_CLI <script>: Setting From to
> '<«sip:51123456789 at ss.example.org <sip%3A51123456789 at ss.example.org>»>' -
> R=«sip:bob-c6NONwRkf6N5JRP at 192.168.1.103:43779»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.683317 spce
> proxy[6041]: INFO: ROUTE_SET_CALLER_CLI <script>: Prepare PAI display-name
> setting - R=«sip:bob-c6NONwRkf6N5JRP at 192.168.1.103:43779»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.683327 spce
> proxy[6041]: INFO: ROUTE_PREPARE_CALLER_CLI <script>: No selector set, not
> setting CLI - R=«sip:bob-c6NONwRkf6N5JRP at 192.168.1.103:43779»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.683336 spce
> proxy[6041]: INFO: ROUTE_SET_CALLER_CLI <script>: Prepare PAI username
> setting - R=«sip:bob-c6NONwRkf6N5JRP at 192.168.1.103:43779»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.683345 spce
> proxy[6041]: NOTICE: ROUTE_PREPARE_CALLER_CLI <script>: Setting
> caller_cli_netprov/caller_domain_netprov '«51123456789»@«ss.example.org
> <http://ss.example.org>»' for npn -
> R=«sip:bob-c6NONwRkf6N5JRP at 192.168.1.103:43779»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.683354 spce
> proxy[6041]: NOTICE: ROUTE_SET_CALLER_CLI <script>: Setting PAI to
> '<«sip:51123456789 at ss.example.org <sip%3A51123456789 at ss.example.org>»>' -
> R=«sip:bob-c6NONwRkf6N5JRP at 192.168.1.103:43779»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.683363 spce
> proxy[6041]: INFO: ROUTE_SET_CALLER_CLI <script>: Prepare PPI username
> setting - R=«sip:bob-c6NONwRkf6N5JRP at 192.168.1.103:43779»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.683372 spce
> proxy[6041]: INFO: ROUTE_PREPARE_CALLER_CLI <script>: No selector set, not
> setting CLI - R=«sip:bob-c6NONwRkf6N5JRP at 192.168.1.103:43779»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.683381 spce
> proxy[6041]: INFO: ROUTE_PREPARE_CALLER_CLI <script>: No selector set, not
> setting CLI - R=«sip:bob-c6NONwRkf6N5JRP at 192.168.1.103:43779»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.683390 spce
> proxy[6041]: INFO: BRANCH_ROUTE_SBC <script>: Prepare P-Called-Party-ID
> setting using selector 'callee' -
> R=«sip:bob-c6NONwRkf6N5JRP at 192.168.1.103:43779»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.683399 spce
> proxy[6041]: NOTICE: BRANCH_ROUTE_SBC <script>: Setting P-Called-Party-ID
> '<sip:«bob-c6NONwRkf6N5JRP»@«ss.example.org <http://ss.example.org>»>' -
> R=«sip:bob-c6NONwRkf6N5JRP at 192.168.1.103:43779»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.683408 spce
> proxy[6041]: INFO: BRANCH_ROUTE_SBC <script>: Leg A info set on header
> P-NGCP-Leg-A-Info with encoded value of «FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE»
> «VxUyKI6TlvPyt7OGWLD-tWDU3S5Yq9p-» -
> R=«sip:bob-c6NONwRkf6N5JRP at 192.168.1.103:43779»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.683418 spce
> proxy[6041]: NOTICE: BRANCH_ROUTE_SBC <script>: Writing sbc parameters
> «;calltimer=21600;aleg_sst_enable=no;sst_enable=no;hold_alter_b2b_bleg=no;hold_alter_b2b_aleg=no;a_park_domain=2;b_park_domain=2»
> - R=«sip:bob-c6NONwRkf6N5JRP at 192.168.1.103:43779»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.683435 spce
> proxy[6041]: INFO: ROUTE_ADD_CALLINFO <script>: Adding P-NGCP-Caller-Info
> '<sip:«alice»@«ss.example.org
> <http://ss.example.org>»>;ip=«172.16.100.209»;port=«5060»«;primary=51123456789»«»'
> - R=«sip:bob-c6NONwRkf6N5JRP at 192.168.1.103:43779»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.683446 spce
> proxy[6041]: INFO: ROUTE_ADD_CALLINFO <script>: Adding P-NGCP-Callee-Info
> '<sip:«51187654321»@«ss.example.org
> <http://ss.example.org>»>;ip=«160.1.100.100»;port=«43779»«;primary=51187654321»«»'
> - R=«sip:bob-c6NONwRkf6N5JRP at 192.168.1.103:43779»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.683457 spce
> proxy[6041]: NOTICE: BRANCH_ROUTE_SBC <script>: Appending P-D-URI
> '«sip:lb at 127.0.0.1
> <sip%3Alb at 127.0.0.1>;lr;received=sip:160.1.100.100:43779;socket=sip:131.3.1.1:5060»'
> - R=«sip:bob-c6NONwRkf6N5JRP at 192.168.1.103:43779»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.683467 spce
> proxy[6041]: NOTICE: BRANCH_ROUTE_SBC <script>: Forcing request via B2BUA
> '«sip:127.0.0.1:5080»' - R=«sip:bob-c6NONwRkf6N5JRP at 192.168.1.103:43779»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.685494 spce
> proxy[6041]: NOTICE: DEFAULT_SEND <script>: Request leaving server,
> M=INVITE fs='«127.0.0.1»:«5062»' du='«127.0.0.1»:«5080»' -
> R=«sip:bob-c6NONwRkf6N5JRP at 192.168.1.103:43779»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:29.686675 spce
> proxy[6041]: INFO: ROUTE_EXIT <script>: INVITE processed -
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE»Oct 29 15:11:29.686686 spce
> proxy[6041]: INFO: ROUTE_EXIT <script>: Runtime for request M=INVITE was
> 38954 usec - ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE»Oct 29 15:11:29.697061
> spce proxy[6047]: NOTICE: DEFAULT_ONREPLY <script>: New reply on proxy -
> M=INVITE ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='<null>'Oct 29
> 15:11:29.697316 spce proxy[6047]: NOTICE: REPLY_ROUTE_NAT <script>:
> NAT-Reply - S=100 - Connecting M=INVITE IP=«172.16.100.209»:«5060»
> («127.0.0.1»:«5080») ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='<null>'
> DESTIP=«127.0.0.1»:«5062»Oct 29 15:11:29.697341 spce proxy[6047]: INFO:
> ROUTE_EXIT <script>: INVITE processed -
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE»Oct 29 15:11:29.697361 spce
> proxy[6047]: INFO: ROUTE_EXIT <script>: Runtime for response M=INVITE 100
> was 421 usec - ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE»Oct 29 15:11:29.698517
> spce proxy[6042]: NOTICE: DEFAULT_ROUTE <script>: New request on proxy for
> the B LEG of the call - M=INVITE
> R=«sip:bob-c6NONwRkf6N5JRP at 192.168.1.103:43779»
> F=«sip:51123456789 at ss.example.org <sip%3A51123456789 at ss.example.org>»
> T=«sip:bob-c6NONwRkf6N5JRP at ss.example.org
> <sip%3Abob-c6NONwRkf6N5JRP at ss.example.org>» IP=«<null>»:«<null>»
> («127.0.0.1»:«5080») ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE_b2b-1»
> UA='<null>' DESTIP=«127.0.0.1»:«5062»Oct 29 15:11:29.698541 spce
> proxy[6042]: INFO: ROUTE_LEG_B <script>: Original P-D-Uri saved with value
> '«sip:lb at 127.0.0.1
> <sip%3Alb at 127.0.0.1>;lr;received=sip:160.1.100.100:43779;socket=sip:131.3.1.1:5060»'
> - R=«sip:bob-c6NONwRkf6N5JRP at 192.168.1.103:43779»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE_b2b-1» UA='<null>'Oct 29
> 15:11:29.698553 spce proxy[6042]: NOTICE: ROUTE_LEG_B <script>: Sending
> request to LB - R=«sip:bob-c6NONwRkf6N5JRP at 192.168.1.103:43779»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE_b2b-1» UA='<null>'Oct 29
> 15:11:29.698856 spce proxy[6042]: NOTICE: DEFAULT_SEND <script>: Request
> leaving server, M=INVITE fs='«127.0.0.1»:«5062»' du='«127.0.0.1»:«5060»' -
> R=«sip:bob-c6NONwRkf6N5JRP at 192.168.1.103:43779»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE_b2b-1» UA='<null>'Oct 29
> 15:11:29.698865 spce proxy[6042]: INFO: ROUTE_EXIT <script>: INVITE
> processed - ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE_b2b-1»Oct 29
> 15:11:29.698874 spce proxy[6042]: INFO: ROUTE_EXIT <script>: Runtime for
> request M=INVITE was 776 usec -
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE_b2b-1»Oct 29 15:11:29.701219 spce
> proxy[6046]: NOTICE: DEFAULT_ONREPLY <script>: New reply on proxy -
> M=INVITE ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE_b2b-1» UA='<null>'Oct 29
> 15:11:29.701237 spce proxy[6046]: NOTICE: REPLY_ROUTE_LEG_B <script>: ***
> Reply LEG_B - S=100 - Trying M=INVITE IP=«<null>»:«<null>»
> («127.0.0.1»:«5060») ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE_b2b-1»
> UA='<null>' DESTIP=«127.0.0.1»:«5062»Oct 29 15:11:29.701247 spce
> proxy[6046]: INFO: ROUTE_EXIT <script>: INVITE processed -
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE_b2b-1»Oct 29 15:11:29.701256 spce
> proxy[6046]: INFO: ROUTE_EXIT <script>: Runtime for response M=INVITE 100
> was 44 usec - ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE_b2b-1»Oct 29
> 15:11:32.985838 spce proxy[6048]: WARNING: <null> db_redis
> [redis_dbase.c:1652]: db_redis_perform_query(): performing full table scan
> on table 'location' while doing the queryOct 29 15:11:32.985871 spce
> proxy[6048]: WARNING: <null> db_redis [redis_dbase.c:1656]:
> db_redis_perform_query(): scan key 0 is 'expires'Oct 29 15:11:32.985881
> spce proxy[6048]: WARNING: <null> db_redis [redis_dbase.c:1656]:
> db_redis_perform_query(): scan key 1 is 'expires'Oct 29 15:11:38.569259
> spce proxy[6063]: INFO: <script>: New XMLRPC request - M=POST
> IP=«127.0.0.1»:«45000»Oct 29 15:11:38.576817 spce proxy[6064]: INFO:
> <script>: New XMLRPC request - M=POST IP=«127.0.0.1»:«45002»Oct 29
> 15:11:38.582023 spce proxy[6065]: INFO: <script>: New XMLRPC request -
> M=POST IP=«127.0.0.1»:«45010»Oct 29 15:11:38.587812 spce proxy[6066]: INFO:
> <script>: New XMLRPC request - M=POST IP=«127.0.0.1»:«45016»Oct 29
> 15:11:38.616270 spce proxy[6063]: INFO: <script>: New XMLRPC request -
> M=POST IP=«127.0.0.1»:«45018»Oct 29 15:11:48.563611 spce proxy[6064]: INFO:
> <script>: New XMLRPC request - M=POST IP=«127.0.0.1»:«48974»Oct 29
> 15:11:48.572026 spce proxy[6065]: INFO: <script>: New XMLRPC request -
> M=POST IP=«127.0.0.1»:«48978»Oct 29 15:11:48.578170 spce proxy[6066]: INFO:
> <script>: New XMLRPC request - M=POST IP=«127.0.0.1»:«48992»Oct 29
> 15:11:48.580108 spce proxy[6063]: INFO: <script>: New XMLRPC request -
> M=POST IP=«127.0.0.1»:«49006»Oct 29 15:11:48.609483 spce proxy[6064]: INFO:
> <script>: New XMLRPC request - M=POST IP=«127.0.0.1»:«49010»Oct 29
> 15:11:58.568874 spce proxy[6065]: INFO: <script>: New XMLRPC request -
> M=POST IP=«127.0.0.1»:«59702»Oct 29 15:11:58.576701 spce proxy[6066]: INFO:
> <script>: New XMLRPC request - M=POST IP=«127.0.0.1»:«59718»Oct 29
> 15:11:58.581017 spce proxy[6063]: INFO: <script>: New XMLRPC request -
> M=POST IP=«127.0.0.1»:«59722»Oct 29 15:11:58.584099 spce proxy[6064]: INFO:
> <script>: New XMLRPC request - M=POST IP=«127.0.0.1»:«59734»Oct 29
> 15:11:58.612863 spce proxy[6065]: INFO: <script>: New XMLRPC request -
> M=POST IP=«127.0.0.1»:«59736»Oct 29 15:11:59.643786 spce proxy[6044]:
> NOTICE: DEFAULT_ONREPLY <script>: New reply on proxy - M=INVITE
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE_b2b-1» UA='<null>'Oct 29
> 15:11:59.643950 spce proxy[6044]: NOTICE: REPLY_ROUTE_LEG_B <script>: ***
> Reply LEG_B - S=408 - Request Timeout M=INVITE IP=«<null>»:«<null>»
> («127.0.0.1»:«5060») ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE_b2b-1»
> UA='<null>' DESTIP=«127.0.0.1»:«5062»Oct 29 15:11:59.645015 spce
> proxy[6044]: NOTICE: REPLY_ROUTE_LEG_B <script>: Sending reply S=408
> M=INVITE fs='«127.0.0.1»:«5062»' du='«127.0.0.1»:«5080»' -
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE_b2b-1» UA='<null>'Oct 29
> 15:11:59.645035 spce proxy[6044]: INFO: ROUTE_EXIT <script>: INVITE
> processed - ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE_b2b-1»Oct 29
> 15:11:59.645046 spce proxy[6044]: INFO: ROUTE_EXIT <script>: Runtime for
> response M=INVITE 408 was 96 usec -
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE_b2b-1»Oct 29 15:11:59.645076 spce
> proxy[6044]: NOTICE: FAILURE_ROUTE_LEG_B <script>: *** Failure route for
> leg-b call, code='408' - R=«sip:bob-c6NONwRkf6N5JRP at 192.168.1.103:43779»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE_b2b-1» UA='<null>'Oct 29
> 15:11:59.645092 spce proxy[6044]: INFO: ROUTE_EXIT <script>: INVITE
> processed - ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE_b2b-1»Oct 29
> 15:11:59.645103 spce proxy[6044]: INFO: ROUTE_EXIT <script>: Runtime for
> request M=INVITE was 33 usec -
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE_b2b-1»Oct 29 15:11:59.646131 spce
> proxy[6041]: NOTICE: DEFAULT_ROUTE <script>: New request on proxy - M=ACK
> R=«sip:bob-c6NONwRkf6N5JRP at 192.168.1.103:43779»
> F=«sip:51123456789 at ss.example.org <sip%3A51123456789 at ss.example.org>»
> T=«sip:bob-c6NONwRkf6N5JRP at ss.example.org
> <sip%3Abob-c6NONwRkf6N5JRP at ss.example.org>» IP=«127.0.0.1»:«5080»
> («127.0.0.1»:«5080») ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE_b2b-1»
> UA='<null>' DESTIP=«127.0.0.1»:«5062»Oct 29 15:11:59.646179 spce
> proxy[6041]: DEBUG: ROUTE_CHECK_TEL_URI <script>:
> x_hdr(From):«<sip:51123456789 at ss.example.org
> <sip%3A51123456789 at ss.example.org>>;tag=1E82B336-690258D1000A9ACA-8F48E6C0»
> - R=«sip:bob-c6NONwRkf6N5JRP at 192.168.1.103:43779»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE_b2b-1» UA='<null>'Oct 29
> 15:11:59.646268 spce proxy[6041]: DEBUG: DEFAULT_ROUTE <script>:
> pua_dialoginfo: Disable PUBLISH messages to caller setting
> FLB_PRESENCE_CALLER flag - R=«sip:bob-c6NONwRkf6N5JRP at 192.168.1.103:43779»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE_b2b-1» UA='<null>'Oct 29
> 15:11:59.646277 spce proxy[6041]: DEBUG: DEFAULT_ROUTE <script>:
> pua_dialoginfo: Disable PUBLISH messages to callee setting
> FLB_PRESENCE_CALLEE flag - R=«sip:bob-c6NONwRkf6N5JRP at 192.168.1.103:43779»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE_b2b-1» UA='<null>'Oct 29
> 15:11:59.649091 spce proxy[6047]: NOTICE: DEFAULT_ONREPLY <script>: New
> reply on proxy - M=INVITE ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE»
> UA='<null>'Oct 29 15:11:59.649107 spce proxy[6047]: NOTICE: REPLY_ROUTE_NAT
> <script>: NAT-Reply - S=408 - Request Timeout M=INVITE
> IP=«172.16.100.209»:«5060» («127.0.0.1»:«5080»)
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='<null>'
> DESTIP=«127.0.0.1»:«5062»Oct 29 15:11:59.649118 spce proxy[6047]: DEBUG:
> REPLY_ROUTE_NAT <script>: pua_dialoginfo: Set flag REFRESH presence to
> activate the publish messages - ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE»
> UA='<null>'Oct 29 15:11:59.649127 spce proxy[6047]: NOTICE:
> REPLY_ROUTE_NAT_CONTINUE <script>: Sending reply S=408 M=INVITE
> fs='«127.0.0.1»:«5062»' du='«127.0.0.1»:«<null>»' -
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='<null>'Oct 29 15:11:59.649137
> spce proxy[6047]: INFO: ROUTE_EXIT <script>: INVITE processed -
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE»Oct 29 15:11:59.649145 spce
> proxy[6047]: INFO: ROUTE_EXIT <script>: Runtime for response M=INVITE 408
> was 289 usec - ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE»Oct 29 15:11:59.649154
> spce proxy[6047]: NOTICE: FAILURE_ROUTE_LOCAL <script>: Failure route for
> local call, code='408' - R=«sip:bob-c6NONwRkf6N5JRP at 192.168.1.103:43779»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:59.649164 spce
> proxy[6047]: DEBUG: FAILURE_ROUTE_LOCAL <script>: pua_dialoginfo: Set
> puburis_callee to a fake (random) value and disable PUBLISH messages to
> callee setting FLB_PRESENCE_CALLEE flag -
> R=«sip:bob-c6NONwRkf6N5JRP at 192.168.1.103:43779»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:59.649173 spce
> proxy[6047]: INFO: ROUTE_STOP_RTPPROXY_BRANCH <script>: Stop rtpengine for
> current branch using first Via, caller did is '«50»' and callee did is
> '«50»' - R=«sip:bob-c6NONwRkf6N5JRP at 192.168.1.103:43779»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:59.649341 spce
> proxy[6041]: INFO: FILTER_CODECS <script>: Restoring xavp callee codecs
> filter from callee dlg_var for the downstream in-dialog 'ACK' request with
> values <null> <null> - R=«sip:bob-c6NONwRkf6N5JRP at 192.168.1.103:43779»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE_b2b-1» UA='<null>'Oct 29
> 15:11:59.649350 spce proxy[6041]: INFO: FILTER_CODECS <script>: Processing
> codecs filters - R=«sip:bob-c6NONwRkf6N5JRP at 192.168.1.103:43779»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE_b2b-1» UA='<null>'Oct 29
> 15:11:59.649359 spce proxy[6041]: INFO: ROUTE_OUTBOUND <script>: Relaying
> request, du='«<null>»' - R=«sip:bob-c6NONwRkf6N5JRP at 192.168.1.103:43779»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE_b2b-1» UA='<null>'Oct 29
> 15:11:59.649368 spce proxy[6041]: INFO: ROUTE_EXIT <script>: Runtime for
> request M=ACK was 3319 usec -
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE_b2b-1»Oct 29 15:11:59.649671 spce
> proxy[6047]: INFO: ROUTE_EARLY_REJECT <script>: Cannot call the media
> server to play an announcement -
> R=«sip:bob-c6NONwRkf6N5JRP at 192.168.1.103:43779»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:59.650688 spce
> proxy[6047]: INFO: ROUTE_ADD_CALLINFO_REPLY <script>: Adding reply
> P-NGCP-Caller-Info '<sip:«alice»@«ss.example.org
> <http://ss.example.org>»>;ip=«172.16.100.209»;port=«5060»«;primary=51123456789»«»'
> - ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:59.651741
> spce proxy[6047]: INFO: ROUTE_ADD_CALLINFO_REPLY <script>: Adding reply
> P-NGCP-Callee-Info '<sip:«51187654321»@«ss.example.org
> <http://ss.example.org>»>;ip=«192.168.1.103»;port=«43779»«;primary=51187654321»«»'
> - ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:59.651866
> spce proxy[6047]: NOTICE: ROUTE_LOCAL_REPLY <script>: Sending reply S=408
> Request Timeout fs='«127.0.0.1»:«5062»' du='«127.0.0.1»:«5060»' -
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='uagv1'Oct 29 15:11:59.653735 spce
> proxy[6047]: INFO: dialog:failed <core> [core/kemi.c:109]:
> sr_kemi_core_info(): connected to redis server[16] 127.0.0.1:6379
> <http://127.0.0.1:6379> at 4Oct 29 15:11:59.654868 spce proxy[6047]: INFO:
> dialog:failed <core> [core/kemi.c:109]: sr_kemi_core_info(): connected to
> redis server[17] 127.0.0.1:6379 <http://127.0.0.1:6379> at 3Oct 29
> 15:11:59.659105 spce proxy[6047]: NOTICE: dialog:failed <script>:
> [dialog:failed] decreased redis counters
> lua_dlg_callid:[«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE»] -
> R=«sip:you at kamailio.org <sip%3Ayou at kamailio.org>» ID=«123» UA='<null>'Oct
> 29 15:11:59.660075 spce proxy[6042]: NOTICE: DEFAULT_ROUTE <script>: New
> request on proxy - M=ACK R=«sip:51187654321 at ss.example.org:5060»
> F=«sip:alice at ss.example.org <sip%3Aalice at ss.example.org>»
> T=«sip:51187654321 at ss.example.org <sip%3A51187654321 at ss.example.org>»
> IP=«127.0.0.1»:«5060» («127.0.0.1»:«5060»)
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='<null>'
> DESTIP=«127.0.0.1»:«5062»Oct 29 15:11:59.660092 spce proxy[6042]: DEBUG:
> ROUTE_CHECK_TEL_URI <script>: x_hdr(From):«<sip:alice at ss.example.org
> <sip%3Aalice at ss.example.org>>;tag=VxUyKI6TlvPyt7OGWLD-tWDU3S5Yq9p-» -
> R=«sip:51187654321 at ss.example.org:5060»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='<null>'Oct 29 15:11:59.660104
> spce proxy[6042]: DEBUG: DEFAULT_ROUTE <script>: pua_dialoginfo: Disable
> PUBLISH messages to caller setting FLB_PRESENCE_CALLER flag -
> R=«sip:51187654321 at ss.example.org:5060»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='<null>'Oct 29 15:11:59.660114
> spce proxy[6042]: DEBUG: DEFAULT_ROUTE <script>: pua_dialoginfo: Disable
> PUBLISH messages to callee setting FLB_PRESENCE_CALLEE flag -
> R=«sip:51187654321 at ss.example.org:5060»
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE» UA='<null>'Oct 29 15:11:59.661339
> spce proxy[6047]: INFO: ROUTE_EXIT <script>: INVITE processed -
> ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE»Oct 29 15:11:59.661633 spce
> proxy[6047]: INFO: ROUTE_EXIT <script>: Runtime for request M=INVITE was
> 14969 usec - ID=«FiLArRmpsyS5gpLCFSHR7jzDRpQiYPSE»*
> ```
> --
> Spce-user mailing list
> Spce-user at lists.sipwise.com
> http://lists.sipwise.com/mailman/listinfo/spce-user_lists.sipwise.com
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.sipwise.com/pipermail/spce-user_lists.sipwise.com/attachments/20251103/41a6d2bf/attachment-0001.htm>
More information about the Spce-user
mailing list