<pre><code>#!KAMAILIO

log_stderror=yes
mpath="modules/"

loadmodule "xlog.so"
loadmodule "textops.so"
loadmodule "debugger.so"
modparam("debugger", "cfgtrace", 1)
modparam("debugger", "mod_level_mode", 1)
modparam("debugger", "mod_hash_size", 4)
modparam("debugger", "mod_level", "core=3")

request_route
{
        route(ENTRY);
        route(TEST_1);
}

route[ENTRY]
{
        xlog("L_NOTICE", "New request\n");
        if (is_method("BYE")) xinfo('BYE');
}
route[TEST_2]
{
        xlog("L_NOTICE", "End\n");
        if (is_method("BYE")) xinfo('BYE');
}
route[TEST_1]
{
        xlog("L_NOTICE", "I'm here\n");
        if (is_method("BYE"))
        {
                xlog("L_NOTICE", "I'm here, again\n");
                route(TEST_2);
        }
        xlog("L_NOTICE", "I'm still here\n");
        return;
}
</code></pre>
<p>without the patch</p>
<pre><code> 9(3432) DEBUG: <core> [core/udp_server.c:491]: udp_rcv_loop(): received on udp socket: (109/100/509) [[INVITE sip:service@127.0.1.1:5060 SIP/2.0 0D  0A Via: SIP/2.0/UDP 127.0.1.1:5061;branch=z9hG4bK-32445-1-0 0D ]]
 9(3432) DEBUG: <core> [core/parser/msg_parser.c:610]: parse_msg(): SIP Request:
 9(3432) DEBUG: <core> [core/parser/msg_parser.c:612]: parse_msg():  method:  <INVITE>
 9(3432) DEBUG: <core> [core/parser/msg_parser.c:614]: parse_msg():  uri:     <sip:service@127.0.1.1:5060>
 9(3432) DEBUG: <core> [core/parser/msg_parser.c:616]: parse_msg():  version: <SIP/2.0>
 9(3432) DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 232, <branch> = <z9hG4bK-32445-1-0>; state=16
 9(3432) DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): end of header reached, state=5
 9(3432) DEBUG: <core> [core/parser/msg_parser.c:498]: parse_headers(): Via found, flags=2
 9(3432) DEBUG: <core> [core/parser/msg_parser.c:500]: parse_headers(): this is the first via
 9(3432) DEBUG: <core> [core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header reached, state=10
 9(3432) DEBUG: <core> [core/parser/msg_parser.c:171]: get_hdr_field(): <To> [38]; uri=[sip:service@127.0.1.1:5060]
 9(3432) DEBUG: <core> [core/parser/msg_parser.c:174]: get_hdr_field(): to body [service <sip:service@127.0.1.1:5060>
], to tag []
 9(3432) DEBUG: <core> [core/parser/msg_parser.c:152]: get_hdr_field(): cseq <CSeq>: <1> <INVITE>
 9(3432) DEBUG: <core> [core/receive.c:240]: receive_msg(): --- received sip message - request - call-id: [1-32445@127.0.1.1] - cseq: [1 INVITE]
 9(3432) DEBUG: <core> [core/receive.c:295]: receive_msg(): preparing to run routing scripts...
 9(3432) ERROR: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/code/src/../etc/test.cfg] l=16 a=5 n=route
 9(3432) ERROR: *** cfgtrace:request_route=[ENTRY] c=[/code/src/../etc/test.cfg] l=22 a=26 n=xlog
 9(3432) ERROR: *** cfgtrace:request_route=[ENTRY] c=[/code/src/../etc/test.cfg] l=24 a=16 n=if
 9(3432) ERROR: *** cfgtrace:request_route=[ENTRY] c=[/code/src/../etc/test.cfg] l=23 a=25 n=is_method
 9(3432) ERROR: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/code/src/../etc/test.cfg] l=17 a=5 n=route
 9(3432) ERROR: *** cfgtrace:request_route=[TEST_1] c=[/code/src/../etc/test.cfg] l=32 a=26 n=xlog
 9(3432) ERROR: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/code/src/../etc/test.cfg] l=38 a=16 n=if
 9(3432) ERROR: *** cfgtrace:request_route=[TEST_1] c=[/code/src/../etc/test.cfg] l=33 a=25 n=is_method
 9(3432) ERROR: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/code/src/../etc/test.cfg] l=38 a=26 n=xlog
 9(3432) ERROR: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/code/src/../etc/test.cfg] l=39 a=2 n=return
 9(3432) DEBUG: <core> [core/receive.c:353]: receive_msg(): request-route executed in: 156 usec
</code></pre>
<p>with the patch:</p>
<pre><code>11(3592) DEBUG: <core> [core/udp_server.c:491]: udp_rcv_loop(): received on udp socket: (112/100/503) [[INVITE sip:service@127.0.1.1:5060 SIP/2.0 0D  0A Via: SIP/2.0/UDP 127.0.1.1:5061;branch=z9hG4bK-572-1-0 0D  0A F]]
11(3592) DEBUG: <core> [core/parser/msg_parser.c:610]: parse_msg(): SIP Request:
11(3592) DEBUG: <core> [core/parser/msg_parser.c:612]: parse_msg():  method:  <INVITE>
11(3592) DEBUG: <core> [core/parser/msg_parser.c:614]: parse_msg():  uri:     <sip:service@127.0.1.1:5060>
11(3592) DEBUG: <core> [core/parser/msg_parser.c:616]: parse_msg():  version: <SIP/2.0>
11(3592) DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 232, <branch> = <z9hG4bK-572-1-0>; state=16
11(3592) DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): end of header reached, state=5
11(3592) DEBUG: <core> [core/parser/msg_parser.c:498]: parse_headers(): Via found, flags=2
11(3592) DEBUG: <core> [core/parser/msg_parser.c:500]: parse_headers(): this is the first via
11(3592) DEBUG: <core> [core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header reached, state=10
11(3592) DEBUG: <core> [core/parser/msg_parser.c:171]: get_hdr_field(): <To> [38]; uri=[sip:service@127.0.1.1:5060]
11(3592) DEBUG: <core> [core/parser/msg_parser.c:174]: get_hdr_field(): to body [service <sip:service@127.0.1.1:5060>
], to tag []
11(3592) DEBUG: <core> [core/parser/msg_parser.c:152]: get_hdr_field(): cseq <CSeq>: <1> <INVITE>
11(3592) DEBUG: <core> [core/receive.c:240]: receive_msg(): --- received sip message - request - call-id: [1-572@127.0.1.1] - cseq: [1 INVITE]
11(3592) DEBUG: <core> [core/receive.c:295]: receive_msg(): preparing to run routing scripts...
11(3592) ERROR: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/code/src/../etc/test.cfg] l=16 a=5 n=route
11(3592) ERROR: *** cfgtrace:request_route=[ENTRY] c=[/code/src/../etc/test.cfg] l=22 a=26 n=xlog
11(3592) ERROR: *** cfgtrace:request_route=[ENTRY] c=[/code/src/../etc/test.cfg] l=24 a=16 n=if
11(3592) ERROR: *** cfgtrace:request_route=[ENTRY] c=[/code/src/../etc/test.cfg] l=23 a=25 n=is_method
11(3592) ERROR: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/code/src/../etc/test.cfg] l=17 a=5 n=route
11(3592) ERROR: *** cfgtrace:request_route=[TEST_1] c=[/code/src/../etc/test.cfg] l=32 a=26 n=xlog
11(3592) ERROR: *** cfgtrace:request_route=[TEST_1] c=[/code/src/../etc/test.cfg] l=38 a=16 n=if
11(3592) ERROR: *** cfgtrace:request_route=[TEST_1] c=[/code/src/../etc/test.cfg] l=33 a=25 n=is_method
11(3592) ERROR: *** cfgtrace:request_route=[TEST_1] c=[/code/src/../etc/test.cfg] l=38 a=26 n=xlog
11(3592) ERROR: *** cfgtrace:request_route=[TEST_1] c=[/code/src/../etc/test.cfg] l=39 a=2 n=return
11(3592) DEBUG: <core> [core/receive.c:353]: receive_msg(): request-route executed in: 422 usec
</code></pre>

<p style="font-size:small;-webkit-text-size-adjust:none;color:#666;">—<br />You are receiving this because you are subscribed to this thread.<br />Reply to this email directly, <a href="https://github.com/kamailio/kamailio/issues/1668#issuecomment-430575150">view it on GitHub</a>, or <a href="https://github.com/notifications/unsubscribe-auth/AF36ZS51cpfev_9Of3Oj_HPM63vKl5_aks5ulwV3gaJpZM4XKZZl">mute the thread</a>.<img src="https://github.com/notifications/beacon/AF36ZXQFhm9Yrrnhr0Zil-MtAgu_IU51ks5ulwV3gaJpZM4XKZZl.gif" height="1" width="1" alt="" /></p>
<script type="application/json" data-scope="inboxmarkup">{"api_version":"1.0","publisher":{"api_key":"05dde50f1d1a384dd78767c55493e4bb","name":"GitHub"},"entity":{"external_key":"github/kamailio/kamailio","title":"kamailio/kamailio","subtitle":"GitHub repository","main_image_url":"https://assets-cdn.github.com/images/email/message_cards/header.png","avatar_image_url":"https://assets-cdn.github.com/images/email/message_cards/avatar.png","action":{"name":"Open in GitHub","url":"https://github.com/kamailio/kamailio"}},"updates":{"snippets":[{"icon":"PERSON","message":"@linuxmaniac in #1668: ```\r\n#!KAMAILIO\r\n\r\nlog_stderror=yes\r\nmpath=\"modules/\"\r\n\r\nloadmodule \"xlog.so\"\r\nloadmodule \"textops.so\"\r\nloadmodule \"debugger.so\"\r\nmodparam(\"debugger\", \"cfgtrace\", 1)\r\nmodparam(\"debugger\", \"mod_level_mode\", 1)\r\nmodparam(\"debugger\", \"mod_hash_size\", 4)\r\nmodparam(\"debugger\", \"mod_level\", \"core=3\")\r\n\r\nrequest_route\r\n{\r\n        route(ENTRY);\r\n        route(TEST_1);\r\n}\r\n\r\nroute[ENTRY]\r\n{\r\n        xlog(\"L_NOTICE\", \"New request\\n\");\r\n        if (is_method(\"BYE\")) xinfo('BYE');\r\n}\r\nroute[TEST_2]\r\n{\r\n        xlog(\"L_NOTICE\", \"End\\n\");\r\n        if (is_method(\"BYE\")) xinfo('BYE');\r\n}\r\nroute[TEST_1]\r\n{\r\n        xlog(\"L_NOTICE\", \"I'm here\\n\");\r\n        if (is_method(\"BYE\"))\r\n        {\r\n                xlog(\"L_NOTICE\", \"I'm here, again\\n\");\r\n                route(TEST_2);\r\n        }\r\n        xlog(\"L_NOTICE\", \"I'm still here\\n\");\r\n        return;\r\n}\r\n```\r\nwithout the patch\r\n```\r\n 9(3432) DEBUG: \u003ccore\u003e [core/udp_server.c:491]: udp_rcv_loop(): received on udp socket: (109/100/509) [[INVITE sip:service@127.0.1.1:5060 SIP/2.0 0D  0A Via: SIP/2.0/UDP 127.0.1.1:5061;branch=z9hG4bK-32445-1-0 0D ]]\r\n 9(3432) DEBUG: \u003ccore\u003e [core/parser/msg_parser.c:610]: parse_msg(): SIP Request:\r\n 9(3432) DEBUG: \u003ccore\u003e [core/parser/msg_parser.c:612]: parse_msg():  method:  \u003cINVITE\u003e\r\n 9(3432) DEBUG: \u003ccore\u003e [core/parser/msg_parser.c:614]: parse_msg():  uri:     \u003csip:service@127.0.1.1:5060\u003e\r\n 9(3432) DEBUG: \u003ccore\u003e [core/parser/msg_parser.c:616]: parse_msg():  version: \u003cSIP/2.0\u003e\r\n 9(3432) DEBUG: \u003ccore\u003e [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 232, \u003cbranch\u003e = \u003cz9hG4bK-32445-1-0\u003e; state=16\r\n 9(3432) DEBUG: \u003ccore\u003e [core/parser/parse_via.c:2639]: parse_via(): end of header reached, state=5\r\n 9(3432) DEBUG: \u003ccore\u003e [core/parser/msg_parser.c:498]: parse_headers(): Via found, flags=2\r\n 9(3432) DEBUG: \u003ccore\u003e [core/parser/msg_parser.c:500]: parse_headers(): this is the first via\r\n 9(3432) DEBUG: \u003ccore\u003e [core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header reached, state=10\r\n 9(3432) DEBUG: \u003ccore\u003e [core/parser/msg_parser.c:171]: get_hdr_field(): \u003cTo\u003e [38]; uri=[sip:service@127.0.1.1:5060]\r\n 9(3432) DEBUG: \u003ccore\u003e [core/parser/msg_parser.c:174]: get_hdr_field(): to body [service \u003csip:service@127.0.1.1:5060\u003e\r\n], to tag []\r\n 9(3432) DEBUG: \u003ccore\u003e [core/parser/msg_parser.c:152]: get_hdr_field(): cseq \u003cCSeq\u003e: \u003c1\u003e \u003cINVITE\u003e\r\n 9(3432) DEBUG: \u003ccore\u003e [core/receive.c:240]: receive_msg(): --- received sip message - request - call-id: [1-32445@127.0.1.1] - cseq: [1 INVITE]\r\n 9(3432) DEBUG: \u003ccore\u003e [core/receive.c:295]: receive_msg(): preparing to run routing scripts...\r\n 9(3432) ERROR: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/code/src/../etc/test.cfg] l=16 a=5 n=route\r\n 9(3432) ERROR: *** cfgtrace:request_route=[ENTRY] c=[/code/src/../etc/test.cfg] l=22 a=26 n=xlog\r\n 9(3432) ERROR: *** cfgtrace:request_route=[ENTRY] c=[/code/src/../etc/test.cfg] l=24 a=16 n=if\r\n 9(3432) ERROR: *** cfgtrace:request_route=[ENTRY] c=[/code/src/../etc/test.cfg] l=23 a=25 n=is_method\r\n 9(3432) ERROR: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/code/src/../etc/test.cfg] l=17 a=5 n=route\r\n 9(3432) ERROR: *** cfgtrace:request_route=[TEST_1] c=[/code/src/../etc/test.cfg] l=32 a=26 n=xlog\r\n 9(3432) ERROR: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/code/src/../etc/test.cfg] l=38 a=16 n=if\r\n 9(3432) ERROR: *** cfgtrace:request_route=[TEST_1] c=[/code/src/../etc/test.cfg] l=33 a=25 n=is_method\r\n 9(3432) ERROR: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/code/src/../etc/test.cfg] l=38 a=26 n=xlog\r\n 9(3432) ERROR: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/code/src/../etc/test.cfg] l=39 a=2 n=return\r\n 9(3432) DEBUG: \u003ccore\u003e [core/receive.c:353]: receive_msg(): request-route executed in: 156 usec\r\n```\r\nwith the patch:\r\n```\r\n11(3592) DEBUG: \u003ccore\u003e [core/udp_server.c:491]: udp_rcv_loop(): received on udp socket: (112/100/503) [[INVITE sip:service@127.0.1.1:5060 SIP/2.0 0D  0A Via: SIP/2.0/UDP 127.0.1.1:5061;branch=z9hG4bK-572-1-0 0D  0A F]]\r\n11(3592) DEBUG: \u003ccore\u003e [core/parser/msg_parser.c:610]: parse_msg(): SIP Request:\r\n11(3592) DEBUG: \u003ccore\u003e [core/parser/msg_parser.c:612]: parse_msg():  method:  \u003cINVITE\u003e\r\n11(3592) DEBUG: \u003ccore\u003e [core/parser/msg_parser.c:614]: parse_msg():  uri:     \u003csip:service@127.0.1.1:5060\u003e\r\n11(3592) DEBUG: \u003ccore\u003e [core/parser/msg_parser.c:616]: parse_msg():  version: \u003cSIP/2.0\u003e\r\n11(3592) DEBUG: \u003ccore\u003e [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 232, \u003cbranch\u003e = \u003cz9hG4bK-572-1-0\u003e; state=16\r\n11(3592) DEBUG: \u003ccore\u003e [core/parser/parse_via.c:2639]: parse_via(): end of header reached, state=5\r\n11(3592) DEBUG: \u003ccore\u003e [core/parser/msg_parser.c:498]: parse_headers(): Via found, flags=2\r\n11(3592) DEBUG: \u003ccore\u003e [core/parser/msg_parser.c:500]: parse_headers(): this is the first via\r\n11(3592) DEBUG: \u003ccore\u003e [core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header reached, state=10\r\n11(3592) DEBUG: \u003ccore\u003e [core/parser/msg_parser.c:171]: get_hdr_field(): \u003cTo\u003e [38]; uri=[sip:service@127.0.1.1:5060]\r\n11(3592) DEBUG: \u003ccore\u003e [core/parser/msg_parser.c:174]: get_hdr_field(): to body [service \u003csip:service@127.0.1.1:5060\u003e\r\n], to tag []\r\n11(3592) DEBUG: \u003ccore\u003e [core/parser/msg_parser.c:152]: get_hdr_field(): cseq \u003cCSeq\u003e: \u003c1\u003e \u003cINVITE\u003e\r\n11(3592) DEBUG: \u003ccore\u003e [core/receive.c:240]: receive_msg(): --- received sip message - request - call-id: [1-572@127.0.1.1] - cseq: [1 INVITE]\r\n11(3592) DEBUG: \u003ccore\u003e [core/receive.c:295]: receive_msg(): preparing to run routing scripts...\r\n11(3592) ERROR: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/code/src/../etc/test.cfg] l=16 a=5 n=route\r\n11(3592) ERROR: *** cfgtrace:request_route=[ENTRY] c=[/code/src/../etc/test.cfg] l=22 a=26 n=xlog\r\n11(3592) ERROR: *** cfgtrace:request_route=[ENTRY] c=[/code/src/../etc/test.cfg] l=24 a=16 n=if\r\n11(3592) ERROR: *** cfgtrace:request_route=[ENTRY] c=[/code/src/../etc/test.cfg] l=23 a=25 n=is_method\r\n11(3592) ERROR: *** cfgtrace:request_route=[DEFAULT_ROUTE] c=[/code/src/../etc/test.cfg] l=17 a=5 n=route\r\n11(3592) ERROR: *** cfgtrace:request_route=[TEST_1] c=[/code/src/../etc/test.cfg] l=32 a=26 n=xlog\r\n11(3592) ERROR: *** cfgtrace:request_route=[TEST_1] c=[/code/src/../etc/test.cfg] l=38 a=16 n=if\r\n11(3592) ERROR: *** cfgtrace:request_route=[TEST_1] c=[/code/src/../etc/test.cfg] l=33 a=25 n=is_method\r\n11(3592) ERROR: *** cfgtrace:request_route=[TEST_1] c=[/code/src/../etc/test.cfg] l=38 a=26 n=xlog\r\n11(3592) ERROR: *** cfgtrace:request_route=[TEST_1] c=[/code/src/../etc/test.cfg] l=39 a=2 n=return\r\n11(3592) DEBUG: \u003ccore\u003e [core/receive.c:353]: receive_msg(): request-route executed in: 422 usec\r\n```"}],"action":{"name":"View Issue","url":"https://github.com/kamailio/kamailio/issues/1668#issuecomment-430575150"}}}</script>
<script type="application/ld+json">[
{
"@context": "http://schema.org",
"@type": "EmailMessage",
"potentialAction": {
"@type": "ViewAction",
"target": "https://github.com/kamailio/kamailio/issues/1668#issuecomment-430575150",
"url": "https://github.com/kamailio/kamailio/issues/1668#issuecomment-430575150",
"name": "View Issue"
},
"description": "View this Issue on GitHub",
"publisher": {
"@type": "Organization",
"name": "GitHub",
"url": "https://github.com"
}
},
{
"@type": "MessageCard",
"@context": "http://schema.org/extensions",
"hideOriginalBody": "false",
"originator": "AF6C5A86-E920-430C-9C59-A73278B5EFEB",
"title": "Re: [kamailio/kamailio] cfgtrace reports strange call route (#1668)",
"sections": [
{
"text": "",
"activityTitle": "**Victor Seva**",
"activityImage": "https://assets-cdn.github.com/images/email/message_cards/avatar.png",
"activitySubtitle": "@linuxmaniac",
"facts": [

]
}
],
"potentialAction": [
{
"name": "Add a comment",
"@type": "ActionCard",
"inputs": [
{
"isMultiLine": true,
"@type": "TextInput",
"id": "IssueComment",
"isRequired": false
}
],
"actions": [
{
"name": "Comment",
"@type": "HttpPOST",
"target": "https://api.github.com",
"body": "{\n\"commandName\": \"IssueComment\",\n\"repositoryFullName\": \"kamailio/kamailio\",\n\"issueId\": 1668,\n\"IssueComment\": \"{{IssueComment.value}}\"\n}"
}
]
},
{
"name": "Close issue",
"@type": "HttpPOST",
"target": "https://api.github.com",
"body": "{\n\"commandName\": \"IssueClose\",\n\"repositoryFullName\": \"kamailio/kamailio\",\n\"issueId\": 1668\n}"
},
{
"targets": [
{
"os": "default",
"uri": "https://github.com/kamailio/kamailio/issues/1668#issuecomment-430575150"
}
],
"@type": "OpenUri",
"name": "View on GitHub"
},
{
"name": "Unsubscribe",
"@type": "HttpPOST",
"target": "https://api.github.com",
"body": "{\n\"commandName\": \"MuteNotification\",\n\"threadId\": 388601445\n}"
}
],
"themeColor": "26292E"
}
]</script>