Description

I have a following problem with TOPOS module. I am trying to achieve a scenario where TOPOS will be activated in all other target peers but one and I managed to do this with event_route as described in TOPOS documentation:

event_route[topos:msg-outgoing] {
  if($sndto(ip)=="10.20.234.47") {
    drop;
  }
}

This seems to work fine and when a call is coming from this peer, since 10.20.234.47 is not a target peer, TOPOS will be activated.

However when call is terminated from the receiving end and BYE message is destined to peer 10.20.234.47, kamailio at 10.30.160.60 answers '404 Not Here message'. I believe this has something to do with event_route below since this problem does not occur when I am not using event_route.

Troubleshooting

I have debug logs from two examples, one with event_route enabled and another without event_route. For some reason when event_route is activated, topos will not populate BYE request with correct record routes but tries to find a branch from topos, which does not exist.

Reproduction

This issue can be reproduced with clean install of latest Kamailio dev from github.

Debugging Data

With event_route enabled

Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: DEBUG: <core> [core/udp_server.c:491]: udp_rcv_loop(): received on udp socket: (112/100/501) [[BYE sip:btpsh-5b29f766-6a9d-1@10.30.160.60 SIP/2.0 0D  0A Max-Forwards: 68 0D  0A Via: SIP/2.0/UDP 10.20.234.25]]
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: DEBUG: <core> [core/parser/msg_parser.c:604]: parse_msg(): SIP Request:
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: DEBUG: <core> [core/parser/msg_parser.c:606]: parse_msg():  method:  <BYE>
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: DEBUG: <core> [core/parser/msg_parser.c:608]: parse_msg():  uri:     <sip:btpsh-5b29f766-6a9d-1@10.30.160.60>
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: DEBUG: <core> [core/parser/msg_parser.c:610]: parse_msg():  version: <SIP/2.0>
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 232, <branch> = <z9hG4bK1ddd.efe198483f089826149438b9f015168d.0>; state=16
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): end of header reached, state=5
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: DEBUG: <core> [core/parser/msg_parser.c:492]: parse_headers(): Via found, flags=2
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: DEBUG: <core> [core/parser/msg_parser.c:494]: parse_headers(): this is the first via
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 232, <branch> = <z9hG4bKiwfg921gzhgpevsckfsgwvhgs>; state=16
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): end of header reached, state=5
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: DEBUG: <core> [core/parser/msg_parser.c:492]: parse_headers(): Via found, flags=4
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: DEBUG: <core> [core/parser/msg_parser.c:505]: parse_headers(): this is the second via
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: DEBUG: <core> [core/parser/parse_addr_spec.c:185]: parse_to_param(): add param: tag=as0af8e4f1
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: DEBUG: <core> [core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header reached, state=29
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: DEBUG: <core> [core/parser/msg_parser.c:171]: get_hdr_field(): <To> [69]; uri=[sip:+358900000002@pbx.example.com]
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: DEBUG: <core> [core/parser/msg_parser.c:172]: get_hdr_field(): to body ["Joonas Keskitalo" <sip:+358900000002@pbx.example.com>]
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: DEBUG: <core> [core/parser/msg_parser.c:152]: get_hdr_field(): cseq <CSeq>: <1> <BYE>
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: DEBUG: <core> [core/parser/msg_parser.c:183]: get_hdr_field(): content_length=0
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: DEBUG: <core> [core/parser/msg_parser.c:89]: get_hdr_field(): found end of header
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: DEBUG: <core> [core/parser/parse_addr_spec.c:185]: parse_to_param(): add param: tag=h7g4Esbg_12001692187037
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: DEBUG: <core> [core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header reached, state=29
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: DEBUG: topos [tps_msg.c:742]: tps_request_received(): handling incoming request
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: DEBUG: topos [tps_msg.c:376]: tps_pack_message(): compacted headers - x_via1: [SIP/2.0/UDP 10.20.234.25;branch=z9hG4bK1ddd.efe198483f089826149438b9f015168d.0](78) - x_via2: [SIP/2.0/UDP 212.146.3.173:5060;branch=z9hG4bKiwfg921gzhgpevsckfsgwvhgs](70) - x_vbranch1: [z9hG4bK1ddd.efe198483f089826149438b9f015168d.0](46)
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: DEBUG: topos [tps_msg.c:485]: tps_pack_message(): compacted headers - a_rr: [](0) - b_rr: [](0) - s_rr: [](0)
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: DEBUG: topos [tps_msg.c:490]: tps_pack_message(): compacted headers - as_contact: [](0) - bs_contact: [](0)
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: DEBUG: topos [tps_storage.c:124]: tps_storage_lock_get(): tps lock get: 410
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: DEBUG: ndb_redis [redis_client.c:301]: redisc_get_server(): Hash 2100282977 (srv8)
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: DEBUG: ndb_redis [redis_client.c:305]: redisc_get_server(): Entry 2100282977 (srv8)
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: DEBUG: topos_redis [topos_redis_storage.c:962]: tps_redis_load_dialog(): loading dialog record for [d:z:atpsh-5b29f766-6a9d-1]
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: DEBUG: ndb_redis [redis_client.c:943]: redisc_exec_argv(): rsrv->ctxRedis = 0x5621e54bde90
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: DEBUG: topos_redis [topos_redis_storage.c:1008]: tps_redis_load_dialog(): r[1]: s[<sip:btpsh-5b29f766-6a9d-1@10.30.160.60>]
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: DEBUG: topos_redis [topos_redis_storage.c:1008]: tps_redis_load_dialog(): r[3]: s[sip:+358900000002@10.20.234.47:5060;transport=TCP]
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: DEBUG: topos_redis [topos_redis_storage.c:1008]: tps_redis_load_dialog(): r[5]: s[INVITE]
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: DEBUG: topos_redis [topos_redis_storage.c:1008]: tps_redis_load_dialog(): r[7]: s[btpsh-5b29f766-6a9d-1]
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: DEBUG: topos_redis [topos_redis_storage.c:1008]: tps_redis_load_dialog(): r[9]: s[as0af8e4f1]
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: DEBUG: topos_redis [topos_redis_storage.c:1008]: tps_redis_load_dialog(): r[11]: s[102]
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: DEBUG: topos_redis [topos_redis_storage.c:1008]: tps_redis_load_dialog(): r[13]: s[atpsh-5b29f766-6a9d-1]
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: DEBUG: topos_redis [topos_redis_storage.c:1008]: tps_redis_load_dialog(): r[15]: s[<sip:212.146.3.173;transport=udp;lr>,<sip:10.20.234.25;lr;pm>]
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: DEBUG: topos_redis [topos_redis_storage.c:1008]: tps_redis_load_dialog(): r[17]: s[<sip:atpsh-5b29f766-6a9d-1@10.30.160.60;transport=tcp>]
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: DEBUG: topos_redis [topos_redis_storage.c:1008]: tps_redis_load_dialog(): r[19]: s[<sip:10.30.160.60;r2=on;lr>,<sip:10.30.160.60;transport=tcp;r2=on;lr>]
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: DEBUG: topos_redis [topos_redis_storage.c:1008]: tps_redis_load_dialog(): r[21]: s[h7g4Esbg_12001692187037]
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: DEBUG: topos_redis [topos_redis_storage.c:1008]: tps_redis_load_dialog(): r[23]: s[1529476980]
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: DEBUG: topos_redis [topos_redis_storage.c:1008]: tps_redis_load_dialog(): r[25]: s[2]
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: DEBUG: topos_redis [topos_redis_storage.c:1008]: tps_redis_load_dialog(): r[27]: s[02fc9c2217271d3b1195aa686164b509@pbx.example.com]
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: DEBUG: ndb_redis [redis_client.c:301]: redisc_get_server(): Hash 2100282977 (srv8)
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: DEBUG: ndb_redis [redis_client.c:305]: redisc_get_server(): Entry 2100282977 (srv8)
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: DEBUG: ndb_redis [redis_client.c:301]: redisc_get_server(): Hash 2100282977 (srv8)
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: DEBUG: ndb_redis [redis_client.c:305]: redisc_get_server(): Entry 2100282977 (srv8)
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: DEBUG: topos_redis [topos_redis_storage.c:610]: tps_redis_load_invite_branch(): loading branch record for [b:x:INVITE:02fc9c2217271d3b1195aa686164b509@pbx.example.com:as0af8e4f1]
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: DEBUG: ndb_redis [redis_client.c:943]: redisc_exec_argv(): rsrv->ctxRedis = 0x5621e54bde90
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: DEBUG: topos_redis [topos_redis_storage.c:628]: tps_redis_load_invite_branch(): hmap with key [b:x:INVITE:02fc9c2217271d3b1195aa686164b509@pbx.example.com:as0af8e4f1] not found
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: DEBUG: topos_redis [topos_redis_storage.c:759]: tps_redis_load_branch(): loading branch record for [b:x:]
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: DEBUG: ndb_redis [redis_client.c:943]: redisc_exec_argv(): rsrv->ctxRedis = 0x5621e54bde90
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: DEBUG: topos_redis [topos_redis_storage.c:777]: tps_redis_load_branch(): hmap with key [b:x:] not found
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: DEBUG: topos [tps_storage.c:136]: tps_storage_lock_release(): tps lock release: 410
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: DEBUG: <core> [core/parser/msg_parser.c:604]: parse_msg(): SIP Request:
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: DEBUG: <core> [core/parser/msg_parser.c:606]: parse_msg():  method:  <BYE>
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: DEBUG: <core> [core/parser/msg_parser.c:608]: parse_msg():  uri:     <sip:btpsh-5b29f766-6a9d-1@10.30.160.60>
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: DEBUG: <core> [core/parser/msg_parser.c:610]: parse_msg():  version: <SIP/2.0>
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 232, <branch> = <z9hG4bK1ddd.efe198483f089826149438b9f015168d.0>; state=16
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): end of header reached, state=5
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: DEBUG: <core> [core/parser/msg_parser.c:492]: parse_headers(): Via found, flags=2
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: DEBUG: <core> [core/parser/msg_parser.c:494]: parse_headers(): this is the first via
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 232, <branch> = <z9hG4bKiwfg921gzhgpevsckfsgwvhgs>; state=16
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): end of header reached, state=5
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: DEBUG: <core> [core/parser/msg_parser.c:492]: parse_headers(): Via found, flags=78
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: DEBUG: <core> [core/parser/msg_parser.c:505]: parse_headers(): this is the second via
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: DEBUG: <core> [core/parser/parse_addr_spec.c:185]: parse_to_param(): add param: tag=as0af8e4f1
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: DEBUG: <core> [core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header reached, state=29
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: DEBUG: <core> [core/parser/msg_parser.c:171]: get_hdr_field(): <To> [69]; uri=[sip:+358900000002@pbx.example.com]
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: DEBUG: <core> [core/parser/msg_parser.c:172]: get_hdr_field(): to body ["Joonas Keskitalo" <sip:+358900000002@pbx.example.com>]
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: DEBUG: <core> [core/parser/msg_parser.c:152]: get_hdr_field(): cseq <CSeq>: <1> <BYE>
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: DEBUG: <core> [core/receive.c:200]: receive_msg(): --- received sip message - request - call-id: [02fc9c2217271d3b1195aa686164b509@pbx.example.com] - cseq: [1 BYE]
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: DEBUG: <core> [core/parser/msg_parser.c:183]: get_hdr_field(): content_length=0
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: DEBUG: <core> [core/parser/msg_parser.c:89]: get_hdr_field(): found end of header
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: {1 1 BYE 02fc9c2217271d3b1195aa686164b509@pbx.example.com} DEBUG: <core> [core/receive.c:248]: receive_msg(): preparing to run routing scripts...
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: {1 1 BYE 02fc9c2217271d3b1195aa686164b509@pbx.example.com} DEBUG: pv [pv_core.c:966]: pv_get_useragent(): no User-Agent header
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: {1 1 BYE 02fc9c2217271d3b1195aa686164b509@pbx.example.com} DEBUG: maxfwd [mf_funcs.c:74]: is_maxfwd_present(): value = 68
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: {1 1 BYE 02fc9c2217271d3b1195aa686164b509@pbx.example.com} DEBUG: <core> [core/parser/parse_addr_spec.c:185]: parse_to_param(): add param: tag=h7g4Esbg_12001692187037
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: {1 1 BYE 02fc9c2217271d3b1195aa686164b509@pbx.example.com} DEBUG: <core> [core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header reached, state=29
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: {1 1 BYE 02fc9c2217271d3b1195aa686164b509@pbx.example.com} DEBUG: sanity [sanity_mod.c:256]: w_sanity_check(): sanity checks result: 1
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: {1 1 BYE 02fc9c2217271d3b1195aa686164b509@pbx.example.com} INFO: <script>: Received BYE from 10.20.234.25 to local IP 10.30.160.60, will do the needful.
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: {1 1 BYE 02fc9c2217271d3b1195aa686164b509@pbx.example.com} DEBUG: tm [t_lookup.c:1018]: t_check_msg(): msg (0x7f3ab052c930) id=1 global id=0 T start=0xffffffffffffffff
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: {1 1 BYE 02fc9c2217271d3b1195aa686164b509@pbx.example.com} DEBUG: tm [t_lookup.c:476]: t_lookup_request(): start searching: hash=56785, isACK=0
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: {1 1 BYE 02fc9c2217271d3b1195aa686164b509@pbx.example.com} DEBUG: tm [t_lookup.c:435]: matching_3261(): RFC3261 transaction matching failed
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: {1 1 BYE 02fc9c2217271d3b1195aa686164b509@pbx.example.com} DEBUG: tm [t_lookup.c:659]: t_lookup_request(): no transaction found
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: {1 1 BYE 02fc9c2217271d3b1195aa686164b509@pbx.example.com} DEBUG: tm [t_lookup.c:1087]: t_check_msg(): msg (0x7f3ab052c930) id=1 global id=1 T end=(nil)
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: {1 1 BYE 02fc9c2217271d3b1195aa686164b509@pbx.example.com} DEBUG: siputils [checks.c:123]: has_totag(): totag found
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: {1 1 BYE 02fc9c2217271d3b1195aa686164b509@pbx.example.com} DEBUG: rr [loose.c:113]: find_first_route(): No Route headers found
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: {1 1 BYE 02fc9c2217271d3b1195aa686164b509@pbx.example.com} DEBUG: rr [loose.c:960]: loose_route(): There is no Route HF
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: {1 1 BYE 02fc9c2217271d3b1195aa686164b509@pbx.example.com} DEBUG: <core> [core/msg_translator.c:159]: check_via_address(): (10.20.234.25, 10.20.234.25, 0)
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: {1 1 BYE 02fc9c2217271d3b1195aa686164b509@pbx.example.com} DEBUG: topos [topos_mod.c:460]: tps_execute_event_route(): executing event_route[topos:...] (1)
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: {1 1 BYE 02fc9c2217271d3b1195aa686164b509@pbx.example.com} DEBUG: <core> [core/parser/msg_parser.c:614]: parse_msg(): SIP Reply  (status):
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: {1 1 BYE 02fc9c2217271d3b1195aa686164b509@pbx.example.com} DEBUG: <core> [core/parser/msg_parser.c:616]: parse_msg():  version: <SIP/2.0>
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: {1 1 BYE 02fc9c2217271d3b1195aa686164b509@pbx.example.com} DEBUG: <core> [core/parser/msg_parser.c:618]: parse_msg():  status:  <404>
Jun 20 09:43:11 edge3 /usr/local/sbin/kamailio[26884]: {1 1 BYE 02fc9c2217271d3b1195aa686164b509@pbx.example.com} DEBUG: <core> [core/parser/msg_parser.c:620]: parse_msg():  reason:  <Not here>

Without event_route

Jun 20 09:33:57 edge3 /usr/local/sbin/kamailio[26395]: DEBUG: <core> [core/udp_server.c:491]: udp_rcv_loop(): received on udp socket: (112/100/501) [[BYE sip:btpsh-5b29f51c-68b4-1@10.30.160.60 SIP/2.0 0D  0A Max-Forwards: 68 0D  0A Via: SIP/2.0/UDP 10.20.234.25]]
Jun 20 09:33:57 edge3 /usr/local/sbin/kamailio[26395]: DEBUG: <core> [core/parser/msg_parser.c:604]: parse_msg(): SIP Request:
Jun 20 09:33:57 edge3 /usr/local/sbin/kamailio[26395]: DEBUG: <core> [core/parser/msg_parser.c:606]: parse_msg():  method:  <BYE>
Jun 20 09:33:57 edge3 /usr/local/sbin/kamailio[26395]: DEBUG: <core> [core/parser/msg_parser.c:608]: parse_msg():  uri:     <sip:btpsh-5b29f51c-68b4-1@10.30.160.60>
Jun 20 09:33:57 edge3 /usr/local/sbin/kamailio[26395]: DEBUG: <core> [core/parser/msg_parser.c:610]: parse_msg():  version: <SIP/2.0>
Jun 20 09:33:57 edge3 /usr/local/sbin/kamailio[26395]: DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 232, <branch> = <z9hG4bKc0da.006a721652ca40dc9f2f4d5d8eb387c0.0>; state=16
Jun 20 09:33:57 edge3 /usr/local/sbin/kamailio[26395]: DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): end of header reached, state=5
Jun 20 09:33:57 edge3 /usr/local/sbin/kamailio[26395]: DEBUG: <core> [core/parser/msg_parser.c:492]: parse_headers(): Via found, flags=2
Jun 20 09:33:57 edge3 /usr/local/sbin/kamailio[26395]: DEBUG: <core> [core/parser/msg_parser.c:494]: parse_headers(): this is the first via
Jun 20 09:33:57 edge3 /usr/local/sbin/kamailio[26395]: DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 232, <branch> = <z9hG4bKmozhccfz7thfkrmo7uikimq16>; state=16
Jun 20 09:33:57 edge3 /usr/local/sbin/kamailio[26395]: DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): end of header reached, state=5
Jun 20 09:33:57 edge3 /usr/local/sbin/kamailio[26395]: DEBUG: <core> [core/parser/msg_parser.c:492]: parse_headers(): Via found, flags=4
Jun 20 09:33:57 edge3 /usr/local/sbin/kamailio[26395]: DEBUG: <core> [core/parser/msg_parser.c:505]: parse_headers(): this is the second via
Jun 20 09:33:57 edge3 /usr/local/sbin/kamailio[26395]: DEBUG: <core> [core/parser/parse_addr_spec.c:185]: parse_to_param(): add param: tag=as1e60e740
Jun 20 09:33:57 edge3 /usr/local/sbin/kamailio[26395]: DEBUG: <core> [core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header reached, state=29
Jun 20 09:33:57 edge3 /usr/local/sbin/kamailio[26395]: DEBUG: <core> [core/parser/msg_parser.c:171]: get_hdr_field(): <To> [69]; uri=[sip:+35890000002@pbx.example.com]
Jun 20 09:33:57 edge3 /usr/local/sbin/kamailio[26395]: DEBUG: <core> [core/parser/msg_parser.c:172]: get_hdr_field(): to body ["Joonas Keskitalo" <sip:+35890000002@pbx.example.com>]
Jun 20 09:33:57 edge3 /usr/local/sbin/kamailio[26395]: DEBUG: <core> [core/parser/msg_parser.c:152]: get_hdr_field(): cseq <CSeq>: <1> <BYE>
Jun 20 09:33:57 edge3 /usr/local/sbin/kamailio[26395]: DEBUG: <core> [core/parser/msg_parser.c:183]: get_hdr_field(): content_length=0
Jun 20 09:33:57 edge3 /usr/local/sbin/kamailio[26395]: DEBUG: <core> [core/parser/msg_parser.c:89]: get_hdr_field(): found end of header
Jun 20 09:33:57 edge3 /usr/local/sbin/kamailio[26395]: DEBUG: <core> [core/parser/parse_addr_spec.c:185]: parse_to_param(): add param: tag=h7g4Esbg_14000437127532
Jun 20 09:33:57 edge3 /usr/local/sbin/kamailio[26395]: DEBUG: <core> [core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header reached, state=29
Jun 20 09:33:57 edge3 /usr/local/sbin/kamailio[26395]: DEBUG: topos [tps_msg.c:742]: tps_request_received(): handling incoming request
Jun 20 09:33:57 edge3 /usr/local/sbin/kamailio[26395]: DEBUG: topos [tps_msg.c:376]: tps_pack_message(): compacted headers - x_via1: [SIP/2.0/UDP 10.20.234.25;branch=z9hG4bKc0da.006a721652ca40dc9f2f4d5d8eb387c0.0](78) - x_via2: [SIP/2.0/UDP 212.146.3.165:5060;branch=z9hG4bKmozhccfz7thfkrmo7uikimq16](70) - x_vbranch1: [z9hG4bKc0da.006a721652ca40dc9f2f4d5d8eb387c0.0](46)
Jun 20 09:33:57 edge3 /usr/local/sbin/kamailio[26395]: DEBUG: topos [tps_msg.c:485]: tps_pack_message(): compacted headers - a_rr: [](0) - b_rr: [](0) - s_rr: [](0)
Jun 20 09:33:57 edge3 /usr/local/sbin/kamailio[26395]: DEBUG: topos [tps_msg.c:490]: tps_pack_message(): compacted headers - as_contact: [](0) - bs_contact: [](0)
Jun 20 09:33:57 edge3 /usr/local/sbin/kamailio[26395]: DEBUG: topos [tps_storage.c:124]: tps_storage_lock_get(): tps lock get: 213
Jun 20 09:33:57 edge3 /usr/local/sbin/kamailio[26395]: DEBUG: ndb_redis [redis_client.c:301]: redisc_get_server(): Hash 2100282977 (srv8)
Jun 20 09:33:57 edge3 /usr/local/sbin/kamailio[26395]: DEBUG: ndb_redis [redis_client.c:305]: redisc_get_server(): Entry 2100282977 (srv8)
Jun 20 09:33:57 edge3 /usr/local/sbin/kamailio[26395]: DEBUG: topos_redis [topos_redis_storage.c:962]: tps_redis_load_dialog(): loading dialog record for [d:z:atpsh-5b29f51c-68b4-1]
Jun 20 09:33:57 edge3 /usr/local/sbin/kamailio[26395]: DEBUG: ndb_redis [redis_client.c:943]: redisc_exec_argv(): rsrv->ctxRedis = 0x561a7d6dbe90
Jun 20 09:33:57 edge3 /usr/local/sbin/kamailio[26395]: DEBUG: topos_redis [topos_redis_storage.c:1008]: tps_redis_load_dialog(): r[1]: s[sip:sgc_c@212.146.3.165;transport=udp]
Jun 20 09:33:57 edge3 /usr/local/sbin/kamailio[26395]: DEBUG: topos_redis [topos_redis_storage.c:1008]: tps_redis_load_dialog(): r[3]: s[<sip:btpsh-5b29f51c-68b4-1@10.30.160.60>]
Jun 20 09:33:57 edge3 /usr/local/sbin/kamailio[26395]: DEBUG: topos_redis [topos_redis_storage.c:1008]: tps_redis_load_dialog(): r[5]: s[sip:+35890000002@10.20.234.47:5060;transport=TCP]
Jun 20 09:33:57 edge3 /usr/local/sbin/kamailio[26395]: DEBUG: topos_redis [topos_redis_storage.c:1008]: tps_redis_load_dialog(): r[7]: s[INVITE]
Jun 20 09:33:57 edge3 /usr/local/sbin/kamailio[26395]: DEBUG: topos_redis [topos_redis_storage.c:1008]: tps_redis_load_dialog(): r[9]: s[btpsh-5b29f51c-68b4-1]
Jun 20 09:33:57 edge3 /usr/local/sbin/kamailio[26395]: DEBUG: topos_redis [topos_redis_storage.c:1008]: tps_redis_load_dialog(): r[11]: s[as1e60e740]
Jun 20 09:33:57 edge3 /usr/local/sbin/kamailio[26395]: DEBUG: topos_redis [topos_redis_storage.c:1008]: tps_redis_load_dialog(): r[13]: s[102]
Jun 20 09:33:57 edge3 /usr/local/sbin/kamailio[26395]: DEBUG: topos_redis [topos_redis_storage.c:1008]: tps_redis_load_dialog(): r[15]: s[atpsh-5b29f51c-68b4-1]
Jun 20 09:33:57 edge3 /usr/local/sbin/kamailio[26395]: DEBUG: topos_redis [topos_redis_storage.c:1008]: tps_redis_load_dialog(): r[17]: s[<sip:212.146.3.165;transport=udp;lr>,<sip:10.20.234.25;lr;pm>]
Jun 20 09:33:57 edge3 /usr/local/sbin/kamailio[26395]: DEBUG: topos_redis [topos_redis_storage.c:1008]: tps_redis_load_dialog(): r[19]: s[<sip:atpsh-5b29f51c-68b4-1@10.30.160.60;transport=tcp>]
Jun 20 09:33:57 edge3 /usr/local/sbin/kamailio[26395]: DEBUG: topos_redis [topos_redis_storage.c:1008]: tps_redis_load_dialog(): r[21]: s[<sip:10.30.160.60;r2=on;lr>,<sip:10.30.160.60;transport=tcp;r2=on;lr>]
Jun 20 09:33:57 edge3 /usr/local/sbin/kamailio[26395]: DEBUG: topos_redis [topos_redis_storage.c:1008]: tps_redis_load_dialog(): r[23]: s[h7g4Esbg_14000437127532]
Jun 20 09:33:57 edge3 /usr/local/sbin/kamailio[26395]: DEBUG: topos_redis [topos_redis_storage.c:1008]: tps_redis_load_dialog(): r[25]: s[1529476419]
Jun 20 09:33:57 edge3 /usr/local/sbin/kamailio[26395]: DEBUG: topos_redis [topos_redis_storage.c:1008]: tps_redis_load_dialog(): r[27]: s[0]
Jun 20 09:33:57 edge3 /usr/local/sbin/kamailio[26395]: DEBUG: topos_redis [topos_redis_storage.c:1008]: tps_redis_load_dialog(): r[29]: s[415ec07600838eb414117d5c66d67717@pbx.example.com]
Jun 20 09:33:57 edge3 /usr/local/sbin/kamailio[26395]: DEBUG: topos [tps_storage.c:136]: tps_storage_lock_release(): tps lock release: 213
Jun 20 09:33:57 edge3 /usr/local/sbin/kamailio[26395]: DEBUG: topos [tps_msg.c:816]: tps_request_received(): r-uri updated to: [sip:+35890000002@10.20.234.47:5060;transport=TCP]
Jun 20 09:33:57 edge3 /usr/local/sbin/kamailio[26395]: DEBUG: topos [tps_msg.c:182]: tps_add_headers(): adding to headers(0) - [Route: <sip:10.30.160.60;r2=on;lr>,<sip:10.30.160.60;transport=tcp;r2=on;lr>#015#012]
Jun 20 09:33:57 edge3 /usr/local/sbin/kamailio[26395]: DEBUG: topos [tps_msg.c:182]: tps_add_headers(): adding to headers(0) - [P-SR-XUID: atpsh-5b29f51c-68b4-1#015#012]
Jun 20 09:33:57 edge3 /usr/local/sbin/kamailio[26395]: DEBUG: <core> [core/parser/msg_parser.c:604]: parse_msg(): SIP Request:
Jun 20 09:33:57 edge3 /usr/local/sbin/kamailio[26395]: DEBUG: <core> [core/parser/msg_parser.c:606]: parse_msg():  method:  <BYE>
...
<After this normal message parsing happens and BYE is routed to 10.20.234.47>

Log Messages

There is nothing related to this issue on normal logging.

SIP Traffic

Only event_route case is available, but basically it is the same case.

 T 2018/06/20 06:42:59.980340 10.20.234.47:35408 -> 10.30.160.60:5060 [AP]
 INVITE sip:+358000000001@10.30.160.60 SIP/2.0.
 Via: SIP/2.0/TCP 10.20.234.47:5060;branch=z9hG4bK2ef81edd.
 Max-Forwards: 70.
 From: "Joonas Keskitalo" <sip:+358900000002@pbx.example.com>;tag=as0af8e4f1.
 To: <sip:+358000000001@10.30.160.60>.
 Contact: <sip:+358900000002@10.20.234.47:5060;transport=TCP>.
 Call-ID: 02fc9c2217271d3b1195aa686164b509@pbx.example.com.
 CSeq: 102 INVITE.
 User-Agent: nmc.
 Date: Wed, 20 Jun 2018 06:42:59 GMT.
 Session-Expires: 1800.
 Min-SE: 90.
 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH.
 Supported: replaces, timer.
 P-Asserted-Identity: "Joonas Keskitalo" <sip:+358900000002@pbx.example.com>.
 Content-Type: application/sdp.
 Content-Length: 266.
 .
 v=0.
 o=noc 1822366190 1822366190 IN IP4 10.20.234.47.
 s=nmc.
 c=IN IP4 10.20.234.47.
 t=0 0.
 m=audio 18644 RTP/AVP 8 9 0 101.
 a=rtpmap:8 PCMA/8000.
 a=rtpmap:9 G722/8000.
 a=rtpmap:0 PCMU/8000.
 a=rtpmap:101 telephone-event/8000.
 a=fmtp:101 0-16.
 a=ptime:20.
 a=sendrecv.
 

 T 2018/06/20 06:43:00.005934 10.30.160.60:5060 -> 10.20.234.47:35408 [AP]
 SIP/2.0 100 trying -- your call is important to us.
 Via: SIP/2.0/TCP 10.20.234.47:5060;branch=z9hG4bK2ef81edd;rport=35408.
 From: "Joonas Keskitalo" <sip:+358900000002@pbx.example.com>;tag=as0af8e4f1.
 To: <sip:+358000000001@10.30.160.60>.
 Call-ID: 02fc9c2217271d3b1195aa686164b509@pbx.example.com.
 CSeq: 102 INVITE.
 Server: kamailio (5.2.0-dev4 (x86_64/linux)).
 Content-Length: 0.
 .
 

 U 2018/06/20 06:43:00.008814 10.30.160.60:5060 -> 10.20.234.25:5060
 INVITE sip:+358000000001@10.20.234.25 SIP/2.0.
 Via: SIP/2.0/UDP 10.30.160.60;branch=z9hG4bK96cf.e1a6c393f0e655e25dec09a13d5463ab.0;i=1.
 Max-Forwards: 69.
 From: "Joonas Keskitalo" <sip:+358900000002@pbx.example.com>;tag=as0af8e4f1.
 To: <sip:+358000000001@10.30.160.60>.
 Call-ID: 02fc9c2217271d3b1195aa686164b509@pbx.example.com.
 CSeq: 102 INVITE.
 User-Agent: nmc.
 Date: Wed, 20 Jun 2018 06:42:59 GMT.
 Session-Expires: 1800.
 Min-SE: 90.
 Allow: INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, SUBSCRIBE, NOTIFY, INFO, PUBLISH.
 Supported: replaces, timer.
 P-Asserted-Identity: "Joonas Keskitalo" <sip:+358900000002@pbx.example.com>.
 Content-Type: application/sdp.
 Content-Length: 266.
 P-hint: outbound.
 Contact: <sip:btpsh-5b29f766-6a9d-1@10.30.160.60>.
 .
 v=0.
 o=noc 1822366190 1822366190 IN IP4 10.20.234.47.
 s=nmc.
 c=IN IP4 10.20.234.47.
 t=0 0.
 m=audio 18644 RTP/AVP 8 9 0 101.
 a=rtpmap:8 PCMA/8000.
 a=rtpmap:9 G722/8000.
 a=rtpmap:0 PCMU/8000.
 a=rtpmap:101 telephone-event/8000.
 a=fmtp:101 0-16.
 a=ptime:20.
 a=sendrecv.
 

 U 2018/06/20 06:43:00.010152 10.20.234.25:5060 -> 10.30.160.60:5060
 SIP/2.0 100 Trying.
 Via: SIP/2.0/UDP 10.30.160.60;branch=z9hG4bK96cf.e1a6c393f0e655e25dec09a13d5463ab.0;i=1.
 From: "Joonas Keskitalo" <sip:+358900000002@pbx.example.com>;tag=as0af8e4f1.
 To: <sip:+358000000001@10.30.160.60>.
 Call-ID: 02fc9c2217271d3b1195aa686164b509@pbx.example.com.
 CSeq: 102 INVITE.
 Content-Length: 0.
 .
 

 U 2018/06/20 06:43:03.101376 10.20.234.25:5060 -> 10.30.160.60:5060
 SIP/2.0 183 Session Progress.
 Via: SIP/2.0/UDP 10.30.160.60;branch=z9hG4bK96cf.e1a6c393f0e655e25dec09a13d5463ab.0;i=1.
 To: <sip:+358000000001@mrandom.example.com;user=phone>;tag=h7g4Esbg_12001692187037.
 From: "Joonas Keskitalo" <sip:+358900000002@pbx.example.com>;tag=as0af8e4f1.
 Call-ID: 02fc9c2217271d3b1195aa686164b509@pbx.example.com.
 CSeq: 102 INVITE.
 Contact: <sip:sgc_c@212.146.3.173;transport=udp>.
 Record-Route: <sip:212.146.3.173;transport=udp;lr>.
 Record-Route: <sip:10.20.234.25;lr;pm>.
 Content-Type: application/sdp.
 Content-Length: 251.
 Allow: INVITE,ACK,OPTIONS,BYE,CANCEL,PRACK,UPDATE.
 .
 v=0.
 o=- 2372765 2372765 IN IP4 212.146.3.173.
 s=-.
 c=IN IP4 10.20.232.34.
 t=0 0.
 a=sendrecv.
 m=audio 10810 RTP/AVP 8 101.
 c=IN IP4 10.20.232.34.
 b=RR:0.
 b=RS:0.
 a=rtpmap:8 PCMA/8000.
 a=rtpmap:101 telephone-event/8000.
 a=fmtp:101 0-15.
 a=maxptime:40.


 T 2018/06/20 06:43:03.105310 10.30.160.60:5060 -> 10.20.234.47:35408 [AP]
 SIP/2.0 183 Session Progress.
 To: <sip:+358000000001@mrandom.example.com;user=phone>;tag=h7g4Esbg_12001692187037.
 From: "Joonas Keskitalo" <sip:+358900000002@pbx.example.com>;tag=as0af8e4f1.
 Call-ID: 02fc9c2217271d3b1195aa686164b509@pbx.example.com.
 CSeq: 102 INVITE.
 Contact: <sip:sgc_c@212.146.3.173;transport=udp>.
 Record-Route: <sip:212.146.3.173;transport=udp;lr>.
 Record-Route: <sip:10.20.234.25;lr;pm>.
 Content-Type: application/sdp.
 Content-Length: 251.
 Allow: INVITE,ACK,OPTIONS,BYE,CANCEL,PRACK,UPDATE.
 Via: SIP/2.0/TCP 10.20.234.47:5060;rport=35408;branch=z9hG4bK2ef81edd.
 Record-Route: <sip:10.30.160.60;r2=on;lr>,<sip:10.30.160.60;transport=tcp;r2=on;lr>.
 P-SR-XBranch: z9hG4bK96cf.e1a6c393f0e655e25dec09a13d5463ab.0.
 .
 v=0.
 o=- 2372765 2372765 IN IP4 212.146.3.173.
 s=-.
 c=IN IP4 10.20.232.34.
 t=0 0.
 a=sendrecv.
 m=audio 10810 RTP/AVP 8 101.
 c=IN IP4 10.20.232.34.
 b=RR:0.
 b=RS:0.
 a=rtpmap:8 PCMA/8000.
 a=rtpmap:101 telephone-event/8000.
 a=fmtp:101 0-15.
 a=maxptime:40.
 

 U 2018/06/20 06:43:04.030579 10.20.234.25:5060 -> 10.30.160.60:5060
 SIP/2.0 180 Ringing.
 Via: SIP/2.0/UDP 10.30.160.60;branch=z9hG4bK96cf.e1a6c393f0e655e25dec09a13d5463ab.0;i=1.
 To: <sip:+358000000001@mrandom.example.com;user=phone>;tag=h7g4Esbg_12001692187037.
 From: "Joonas Keskitalo" <sip:+358900000002@pbx.example.com>;tag=as0af8e4f1.
 Call-ID: 02fc9c2217271d3b1195aa686164b509@pbx.example.com.
 CSeq: 102 INVITE.
 Contact: <sip:sgc_c@212.146.3.173;transport=udp>.
 Record-Route: <sip:212.146.3.173;transport=udp;lr>.
 Record-Route: <sip:10.20.234.25;lr;pm>.
 Content-Length: 0.
 .
 

 T 2018/06/20 06:43:04.034058 10.30.160.60:5060 -> 10.20.234.47:35408 [AP]
 SIP/2.0 180 Ringing.
 To: <sip:+358000000001@mrandom.example.com;user=phone>;tag=h7g4Esbg_12001692187037.
 From: "Joonas Keskitalo" <sip:+358900000002@pbx.example.com>;tag=as0af8e4f1.
 Call-ID: 02fc9c2217271d3b1195aa686164b509@pbx.example.com.
 CSeq: 102 INVITE.
 Contact: <sip:sgc_c@212.146.3.173;transport=udp>.
 Record-Route: <sip:212.146.3.173;transport=udp;lr>.
 Record-Route: <sip:10.20.234.25;lr;pm>.
 Content-Length: 0.
 Via: SIP/2.0/TCP 10.20.234.47:5060;rport=35408;branch=z9hG4bK2ef81edd.
 Record-Route: <sip:10.30.160.60;r2=on;lr>,<sip:10.30.160.60;transport=tcp;r2=on;lr>.
 P-SR-XBranch: z9hG4bK96cf.e1a6c393f0e655e25dec09a13d5463ab.0.
 .
 

 U 2018/06/20 06:43:07.037526 10.20.234.25:5060 -> 10.30.160.60:5060
 SIP/2.0 200 OK.
 Via: SIP/2.0/UDP 10.30.160.60;branch=z9hG4bK96cf.e1a6c393f0e655e25dec09a13d5463ab.0;i=1.
 To: <sip:+358000000001@mrandom.example.com;user=phone>;tag=h7g4Esbg_12001692187037.
 From: "Joonas Keskitalo" <sip:+358900000002@212.146.3.173>;tag=as0af8e4f1.
 Call-ID: 02fc9c2217271d3b1195aa686164b509@pbx.example.com.
 CSeq: 102 INVITE.
 Contact: <sip:sgc_c@212.146.3.173;transport=udp>.
 Record-Route: <sip:212.146.3.173;transport=udp;lr>.
 Record-Route: <sip:10.20.234.25;lr;pm>.
 Content-Type: application/sdp.
 Content-Length: 251.
 Allow: INVITE,ACK,OPTIONS,BYE,CANCEL,PRACK,UPDATE.
 Accept: application/sdp.
 .
 v=0.
 o=- 2372765 2372765 IN IP4 212.146.3.173.
 s=-.
 c=IN IP4 10.20.232.34.
 t=0 0.
 a=sendrecv.
 m=audio 10810 RTP/AVP 8 101.
 c=IN IP4 10.20.232.34.
 b=RR:0.
 b=RS:0.
 a=rtpmap:8 PCMA/8000.
 a=rtpmap:101 telephone-event/8000.
 a=fmtp:101 0-15.
 a=maxptime:40.
 

 T 2018/06/20 06:43:07.041369 10.30.160.60:5060 -> 10.20.234.47:35408 [AP]
 SIP/2.0 200 OK.
 To: <sip:+358000000001@mrandom.example.com;user=phone>;tag=h7g4Esbg_12001692187037.
 From: "Joonas Keskitalo" <sip:+358900000002@212.146.3.173>;tag=as0af8e4f1.
 Call-ID: 02fc9c2217271d3b1195aa686164b509@pbx.example.com.
 CSeq: 102 INVITE.
 Contact: <sip:sgc_c@212.146.3.173;transport=udp>.
 Record-Route: <sip:212.146.3.173;transport=udp;lr>.
 Record-Route: <sip:10.20.234.25;lr;pm>.
 Content-Type: application/sdp.
 Content-Length: 251.
 Allow: INVITE,ACK,OPTIONS,BYE,CANCEL,PRACK,UPDATE.
 Accept: application/sdp.
 Via: SIP/2.0/TCP 10.20.234.47:5060;rport=35408;branch=z9hG4bK2ef81edd.
 Record-Route: <sip:10.30.160.60;r2=on;lr>,<sip:10.30.160.60;transport=tcp;r2=on;lr>.
 P-SR-XBranch: z9hG4bK96cf.e1a6c393f0e655e25dec09a13d5463ab.0.
 .
 v=0.
 o=- 2372765 2372765 IN IP4 212.146.3.173.
 s=-.
 c=IN IP4 10.20.232.34.
 t=0 0.
 a=sendrecv.
 m=audio 10810 RTP/AVP 8 101.
 c=IN IP4 10.20.232.34.
 b=RR:0.
 b=RS:0.
 a=rtpmap:8 PCMA/8000.
 a=rtpmap:101 telephone-event/8000.
 a=fmtp:101 0-15.
 a=maxptime:40.
 

 T 2018/06/20 06:43:07.042687 10.20.234.47:35408 -> 10.30.160.60:5060 [AP]
 ACK sip:sgc_c@212.146.3.173;transport=udp SIP/2.0.
 Via: SIP/2.0/TCP 10.20.234.47:5060;branch=z9hG4bK76432850.
 Route: <sip:10.30.160.60;transport=tcp;r2=on;lr>,<sip:10.30.160.60;r2=on;lr>,<sip:10.20.234.25;lr;pm>,<sip:212.146.3.173;transport=udp;lr>.
 Max-Forwards: 70.
 From: "Joonas Keskitalo" <sip:+358900000002@pbx.example.com>;tag=as0af8e4f1.
 To: <sip:+358000000001@10.30.160.60>;tag=h7g4Esbg_12001692187037.
 Contact: <sip:+358900000002@10.20.234.47:5060;transport=TCP>.
 Call-ID: 02fc9c2217271d3b1195aa686164b509@pbx.example.com.
 CSeq: 102 ACK.
 User-Agent: nmc.
 Content-Length: 0.
 .
 

 U 2018/06/20 06:43:07.140001 10.30.160.60:5060 -> 10.20.234.25:5060
 ACK sip:sgc_c@212.146.3.173;transport=udp SIP/2.0.
 Via: SIP/2.0/UDP 10.30.160.60;branch=z9hG4bK96cf.d1c298d0a34b6f6327f0e0c15abced89.0;i=1.
 Via: SIP/2.0/TCP 10.20.234.47:5060;rport=35408;branch=z9hG4bK76432850.
 Route: <sip:10.20.234.25;lr;pm>,<sip:212.146.3.173;transport=udp;lr>.
 Max-Forwards: 69.
 From: "Joonas Keskitalo" <sip:+358900000002@pbx.example.com>;tag=as0af8e4f1.
 To: <sip:+358000000001@10.30.160.60>;tag=h7g4Esbg_12001692187037.
 Contact: <sip:+358900000002@10.20.234.47:5060;transport=TCP>.
 Call-ID: 02fc9c2217271d3b1195aa686164b509@pbx.example.com.
 CSeq: 102 ACK.
 User-Agent: nmc.
 Content-Length: 0.
 .
 

 U 2018/06/20 06:43:11.802426 10.20.234.25:5060 -> 10.30.160.60:5060
 BYE sip:btpsh-5b29f766-6a9d-1@10.30.160.60 SIP/2.0.
 Max-Forwards: 68.
 Via: SIP/2.0/UDP 10.20.234.25;branch=z9hG4bK1ddd.efe198483f089826149438b9f015168d.0.
 Via: SIP/2.0/UDP 212.146.3.173:5060;branch=z9hG4bKiwfg921gzhgpevsckfsgwvhgs.
 To: "Joonas Keskitalo" <sip:+358900000002@pbx.example.com>;tag=as0af8e4f1.
 From: <sip:+358000000001@212.146.3.173;user=phone>;tag=h7g4Esbg_12001692187037.
 Call-ID: 02fc9c2217271d3b1195aa686164b509@pbx.example.com.
 CSeq: 1 BYE.
 Reason: Q.850;cause=16.
 Content-Length: 0.
 .
 

 U 2018/06/20 06:43:11.806533 10.30.160.60:5060 -> 10.20.234.25:5060
 SIP/2.0 404 Not here.
 Via: SIP/2.0/UDP 10.20.234.25;branch=z9hG4bK1ddd.efe198483f089826149438b9f015168d.0;rport=5060.
 Via: SIP/2.0/UDP 212.146.3.173:5060;branch=z9hG4bKiwfg921gzhgpevsckfsgwvhgs.
 To: "Joonas Keskitalo" <sip:+358900000002@pbx.example.com>;tag=as0af8e4f1.
 From: <sip:+358000000001@212.146.3.173;user=phone>;tag=h7g4Esbg_12001692187037.
 Call-ID: 02fc9c2217271d3b1195aa686164b509@pbx.example.com.
 CSeq: 1 BYE.
 Server: kamailio (5.2.0-dev4 (x86_64/linux)).
 Content-Length: 0.

Possible Solutions

No idea

Additional Information

version: kamailio 5.2.0-dev4 (x86_64/linux) 
flags: STATS: Off, USE_TCP, USE_TLS, USE_SCTP, TLS_HOOKS, DISABLE_NAGLE, USE_MCAST, DNS_IP_HACK, SHM_MEM, SHM_MMAP, PKG_MALLOC, Q_MALLOC, F_MALLOC, TLSF_MALLOC, DBG_SR_MEMORY, USE_FUTEX, FAST_LOCK-ADAPTIVE_WAIT, USE_DNS_CACHE, USE_DNS_FAILOVER, USE_NAPTR, USE_DST_BLACKLIST, HAVE_RESOLV_RES
ADAPTIVE_WAIT_LOOPS=1024, MAX_RECV_BUFFER_SIZE 262144, MAX_LISTEN 16, MAX_URI_SIZE 1024, BUF_SIZE 65535, DEFAULT PKG_SIZE 8MB
poll method support: poll, epoll_lt, epoll_et, sigio_rt, select.
id: unknown 
compiled on 14:01:18 Mar  9 2018 with gcc 6.3.0

Linux edge3 4.9.0-6-amd64 #1 SMP Debian 4.9.82-1+deb9u3 (2018-03-02) x86_64 GNU/Linux

—
You are receiving this because you are subscribed to this thread.
Reply to this email directly, view it on GitHub, or mute the thread.