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