20 Jun
2018
20 Jun
'18
9:19 a.m.
### 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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)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(a)pbx.example.com.
CSeq: 1 BYE.
Server: kamailio (5.2.0-dev4 (x86_64/linux)).
Content-Length: 0.
```
### Possible Solutions
No idea
### Additional Information
* **Kamailio Version** - output of `kamailio -v`
```
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
```
* **Operating System**:
```
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 or view it on GitHub:
https://github.com/kamailio/kamailio/issues/1569
20 Jun
20 Jun
12:48 p.m.
I tried the same with stable Kamailio version
```
# kamailio -v
version: kamailio 5.1.4 (x86_64/linux)
flags: STATS: Off, USE_TCP, USE_TLS, USE_SCTP, TLS_HOOKS, USE_RAW_SOCKS, 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 08:12:48 Jun 20 2018 with gcc 6.3.0
```
And noticed a small difference. Kamailio is trying to find
`[b:x:INVITE:1e004b4343c496750f1de6f156c779e8@pbx.example.com:as34fa3a8d]`
but when using kamailio 5.1.4 there is only
`b:x:INVITE:1e004b4343c496750f1de6f156c779e8@pbx.example.com:h7g4Esbg_07000304592032`.
The difference between 5.2 and 5.1 is that in 5.2 there is nothing even close to that on
redis and in 5.1 the tags seems to be switched.
On 183 Session progress and 180 Ringing:
```
Jun 20 13:09:53 edge3 /usr/local/sbin/kamailio[3686]: DEBUG: topos_redis
[topos_redis_storage.c:363]: tps_redis_insert_invite_branch(): inserting branch record for
[b:x:INVITE:1e004b4343c496750f1de6f156c779e8@pbx.example.com:h7g4Esbg_07000304592032] with
argc 6
```
On BYE:
```
Jun 20 13:10:11 edge3 /usr/local/sbin/kamailio[3689]: DEBUG: topos_redis
[topos_redis_storage.c:610]: tps_redis_load_invite_branch(): loading branch record for
[b:x:INVITE:1e004b4343c496750f1de6f156c779e8@pbx.example.com:as34fa3a8d]
Jun 20 13:10:11 edge3 /usr/local/sbin/kamailio[3689]: DEBUG: ndb_redis
[redis_client.c:878]: redisc_exec_argv(): rsrv->ctxRedis = 0x564c726d7e90
Jun 20 13:10:11 edge3 /usr/local/sbin/kamailio[3689]: DEBUG: topos_redis
[topos_redis_storage.c:628]: tps_redis_load_invite_branch(): hmap with key
[b:x:INVITE:1e004b4343c496750f1de6f156c779e8@pbx.example.comas34fa3a8d] not found
```
On SIP messages tags are as follows:
Initial INVITE:
```
From: "UserName" <sip:sip:user@domain.tld>;tag=as34fa3a8d.
To: <sip:user@domain.tld>.
```
183 Session Progess:
```
From: "UserName" <sip:sip:user@domain.tld>;tag=as34fa3a8d.
To: <sip:user@domain.tld>;tag=h7g4Esbg_07000304592032.
```
BYE message from receiving end:
```
From: <sip:user@domain.tld>;tag=h7g4Esbg_07000304592032.
To: "UserName" <sip:sip:user@domain.tld>;tag=as34fa3a8d.
```
--
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/1569#issuecomment-398707074
2:24 p.m.
For speed reasons, the event_route was designed to allow testing only destination address
and decide to do topos or not, meaning that all traffic with an ip is either with topos
processing or without.
In your case I understand that you want calls initiated by Asterisk to be with topos, but
not the calls towards Asterisk. This would require testing at a later point in topos
processing, so this can be another event_route to get access to the SIP message and other
related attributes, so this would be a feature request. It was somehow discussed when
added the current event route, but the needs at that time were for address checking and
the speed was considered relevant, otherwise is not something that complex to add.
If you want it, then open a new issue as a feature request.
Now here, I want to clarify your second comment, where I got it like you report a
different behaviour between master and 5.1 branches, am I right? Is it a bug that you
discovered? Not sure if the record was not found by topos_redis because you dropped topos
for INVITE or there was some different scenario that you tried.
I think master and 5.1 branches should be the same from perspective of topos/topos_redis
modules.
--
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/1569#issuecomment-398730229
3:11 p.m.
Thank you for your fast and clarifying response.
The problem here is that I simply can't use event_route to disable topos on calls
destined to Asterisk since it will break every call made to another direction. That means
that current event_route feature allows topos to be disabled but only if the SIP peers are
for one-way traffic?
About my second comment on differences between branches, I noticed that for some reason
when I tested with 5.2 I had different kind of keys on redis than on my tests on 5.1. The
call scenario was exactly the same on both cases. I managed to reproduce this and I
can't find the following log row on 5.2.0-dev4 kamailio at all:
```
Jun 20 13:09:53 edge3 /usr/local/sbin/kamailio[3686]: DEBUG: topos_redis
[topos_redis_storage.c:363]: tps_redis_insert_invite_branch(): inserting branch record for
[b:x:INVITE:1e004b4343c496750f1de6f156c779e8@pbx.example.com:h7g4Esbg_07000304592032] with
argc 6
```
which happens at kamailio 5.1.4.
Also only the following keys are present in redis when using 5.2.0-dev4:
```
1) "d:z:atpsh-5b2a4f80-218-1"
2) "b:x:z9hG4bKb1d4.26a1938596920d3714191be44ad2684a.0"
```
When 5.1.4 had also
`b:x:INVITE:1e004b4343c496750f1de6f156c779e8@pbx.example.com:h7g4Esbg_07000304592032`
Call case is the same, configuration is the same and all of the participants are the same.
I only rebuilt kamailio and retried.
--
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/1569#issuecomment-398742935
3:22 p.m.
The request at that time was to disable traffic to a peer, you can search on the closed
issues or pull requests here, the discussion was a while ago and the needs were limited to
ip destination matching, with concerns to keep the speed of processing as fast as
possible.
Is it 5.1.4 from tarball/packages or the git branch 5.1 that you are using? I will try to
compare and see what is different between the two.
--
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/1569#issuecomment-398746357
3:31 p.m.
Ok, I will place a feature request on another event_route that can be called with full SIP
headers so this problem can be then resolved via that.
I used the git branch 5.1 and master to rebuild between 5.1.4 and 5.2.0-dev4.
--
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/1569#issuecomment-398749011
22 Jun
22 Jun
10:26 a.m.
I looked at the code and the only significant difference between 5.1 and master branches
for topos module is related to matching KDMQ method, so the behaviour should be the same.
I am closing this one, you said you are going to open another issue as feature request for
a new event route.
--
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/1569#issuecomment-399364375
10:26 a.m.
Closed #1569.
--
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/1569#event-1695418823
2352
days inactive
2354
days old
7 comments
2 participants
participants (2)
-
Daniel-Constantin Mierla -
Joonas Keskitalo