[sr-dev] [kamailio/kamailio] cfgtrace reports strange call route (#1668)

[Victor Seva]

```
#!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;
}
```
without the patch
```
 9(3432) DEBUG: <core> [core/udp_server.c:491]: udp_rcv_loop(): received on udp socket: (109/100/509) [[INVITE sip:service at 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 at 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 at 127.0.1.1:5060]
 9(3432) DEBUG: <core> [core/parser/msg_parser.c:174]: get_hdr_field(): to body [service <sip:service at 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 at 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
```
with the patch:
```
11(3592) DEBUG: <core> [core/udp_server.c:491]: udp_rcv_loop(): received on udp socket: (112/100/503) [[INVITE sip:service at 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 at 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 at 127.0.1.1:5060]
11(3592) DEBUG: <core> [core/parser/msg_parser.c:174]: get_hdr_field(): to body [service <sip:service at 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 at 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
```

-- 
You are receiving this because you are subscribed to this thread.
Reply to this email directly or view it on GitHub:
https://github.com/kamailio/kamailio/issues/1668#issuecomment-430575150
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.kamailio.org/pipermail/sr-dev/attachments/20181017/48781697/attachment-0001.html>