[sr-dev] [kamailio/kamailio] icmp failover (#2377)

sergey-safarov notifications at github.com
Fri Jun 26 17:50:11 CEST 2020


### Description
I found that kamailio ignores ICMP messages from remote hosts

### Expected behavior
Immediately failover after ICMP message.

#### Actual observed behavior
kamailio ignores ICMP messages

#### How to reproduce
Create kamailio config
```
loadmodule "pv.so"
loadmodule "tm.so"

listen = udp:eth0

request_route {
  $du = "sip:127.0.0.1";
  t_relay();
}
```

Start kamailio using the command
```
kamailio -DD -E -ddd
```
Make a call.

#### Debugging Data
None

#### Log Messages
```
1(20746) DEBUG: <core> [core/udp_server.c:498]: udp_rcv_loop(): received on udp socket: (106/100/712) [[INVITE sip:6003 at office.nga911.com SIP/2.0 0D  0A Via: SIP/2.0/UDP 192.168.2.10:17082;rport;branch=z9hG4bK1]]
 1(20746) DEBUG: <core> [core/parser/msg_parser.c:610]: parse_msg(): SIP Request:
 1(20746) DEBUG: <core> [core/parser/msg_parser.c:612]: parse_msg():  method:  <INVITE>
 1(20746) DEBUG: <core> [core/parser/msg_parser.c:614]: parse_msg():  uri:     <sip:6003 at office.nga911.com>
 1(20746) DEBUG: <core> [core/parser/msg_parser.c:616]: parse_msg():  version: <SIP/2.0>
 1(20746) DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 235, <rport> = <n/a>; state=6
 1(20746) DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 232, <branch> = <z9hG4bK194358777>; state=16
 1(20746) DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): end of header reached, state=5
 1(20746) DEBUG: <core> [core/parser/msg_parser.c:498]: parse_headers(): Via found, flags=2
 1(20746) DEBUG: <core> [core/parser/msg_parser.c:500]: parse_headers(): this is the first via
 1(20746) DEBUG: <core> [core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header reached, state=10
 1(20746) DEBUG: <core> [core/parser/msg_parser.c:171]: get_hdr_field(): <To> [30]; uri=[sip:6003 at office.nga911.com]
 1(20746) DEBUG: <core> [core/parser/msg_parser.c:174]: get_hdr_field(): to body [<sip:6003 at office.nga911.com>
], to tag []
 1(20746) DEBUG: <core> [core/parser/msg_parser.c:152]: get_hdr_field(): cseq <CSeq>: <20> <INVITE>
 1(20746) DEBUG: <core> [core/receive.c:319]: receive_msg(): --- received sip message - request - call-id: [943928765] - cseq: [20 INVITE]
 1(20746) DEBUG: <core> [core/receive.c:379]: receive_msg(): preparing to run routing scripts...
 1(20746) DEBUG: tm [t_lookup.c:1328]: t_newtran(): msg (0x7fcf6e57b720) id=1/20746 global id=0/0 T start=0xffffffffffffffff
 1(20746) DEBUG: <core> [core/parser/msg_parser.c:185]: get_hdr_field(): content_length=212
 1(20746) DEBUG: <core> [core/parser/msg_parser.c:89]: get_hdr_field(): found end of header
 1(20746) DEBUG: tm [t_lookup.c:497]: t_lookup_request(): start searching: hash=911, isACK=0
 1(20746) DEBUG: tm [t_lookup.c:455]: matching_3261(): RFC3261 transaction matching failed - via branch [z9hG4bK194358777]
 1(20746) DEBUG: tm [t_lookup.c:675]: t_lookup_request(): no transaction found
 1(20746) DEBUG: <core> [core/parser/parse_addr_spec.c:185]: parse_to_param(): add param: tag=1971363051
 1(20746) DEBUG: <core> [core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header reached, state=29
 1(20746) DEBUG: <core> [core/md5utils.c:67]: MD5StringArray(): MD5 calculated: 5806eb9c98c0f8e99344758d43fcc364
 1(20746) DEBUG: tm [t_funcs.c:325]: t_relay_to(): new INVITE
 1(20746) DEBUG: tm [t_reply.c:610]: _reply_light(): reply sent out. buf=0x7fcf6e57cde0: SIP/2.0 100 trying -..., shmem=0x7fcf69bd11b8: SIP/2.0 100 trying -
 1(20746) DEBUG: tm [t_reply.c:621]: _reply_light(): finished
 1(20746) DEBUG: <core> [core/msg_translator.c:1765]: check_boundaries(): no multi-part body
 1(20746) DEBUG: tm [t_funcs.c:373]: t_relay_to(): new transaction forwarded
 1(20746) DEBUG: <core> [core/receive.c:437]: receive_msg(): request-route executed in: 845 usec
 1(20746) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
 1(20746) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
 1(20746) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
 1(20746) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
 1(20746) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
 1(20746) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
 1(20746) DEBUG: <core> [core/xavp.c:529]: xavp_destroy_list(): destroying xavp list (nil)
 1(20746) DEBUG: <core> [core/receive.c:528]: receive_msg(): cleaning up


 9(20754) DEBUG: tm [t_reply.c:1274]: t_should_relay_response(): ->>>>>>>>> T_code=100, new_code=408
 9(20754) DEBUG: tm [t_reply.c:1500]: t_should_relay_response(): rps completed - uas status: 100 branch: 0
 9(20754) DEBUG: tm [t_reply.c:1823]: relay_reply(): reply status=4 branch=0, save=0, relay=0 icode=0 msg status=408
 9(20754) DEBUG: tm [t_reply.c:2016]: relay_reply(): reply buffer sent out
 3(20748) DEBUG: <core> [core/udp_server.c:498]: udp_rcv_loop(): received on udp socket: (106/100/341) [[ACK sip:6003 at office.nga911.com SIP/2.0 0D  0A Via: SIP/2.0/UDP 192.168.2.10:17082;rport;branch=z9hG4bK1943]]
 3(20748) DEBUG: <core> [core/parser/msg_parser.c:610]: parse_msg(): SIP Request:
 3(20748) DEBUG: <core> [core/parser/msg_parser.c:612]: parse_msg():  method:  <ACK>
 3(20748) DEBUG: <core> [core/parser/msg_parser.c:614]: parse_msg():  uri:     <sip:6003 at office.nga911.com>
 3(20748) DEBUG: <core> [core/parser/msg_parser.c:616]: parse_msg():  version: <SIP/2.0>
 3(20748) DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 235, <rport> = <n/a>; state=6
 3(20748) DEBUG: <core> [core/parser/parse_via.c:1303]: parse_via_param(): Found param type 232, <branch> = <z9hG4bK194358777>; state=16
 3(20748) DEBUG: <core> [core/parser/parse_via.c:2639]: parse_via(): end of header reached, state=5
 3(20748) DEBUG: <core> [core/parser/msg_parser.c:498]: parse_headers(): Via found, flags=2
 3(20748) DEBUG: <core> [core/parser/msg_parser.c:500]: parse_headers(): this is the first via
 3(20748) DEBUG: <core> [core/parser/parse_addr_spec.c:185]: parse_to_param(): add param: tag=5e29a5d2a0b42789624a70ddd04f640f-81ca6283
 3(20748) DEBUG: <core> [core/parser/parse_addr_spec.c:864]: parse_addr_spec(): end of header reached, state=29
 3(20748) DEBUG: <core> [core/parser/msg_parser.c:171]: get_hdr_field(): <To> [76]; uri=[sip:6003 at office.nga911.com]
 3(20748) DEBUG: <core> [core/parser/msg_parser.c:174]: get_hdr_field(): to body [<sip:6003 at office.nga911.com>], to tag [5e29a5d2a0b42789624a70ddd04f640f-81ca6283]
 3(20748) DEBUG: <core> [core/parser/msg_parser.c:152]: get_hdr_field(): cseq <CSeq>: <20> <ACK>
 3(20748) DEBUG: <core> [core/receive.c:319]: receive_msg(): --- received sip message - request - call-id: [943928765] - cseq: [20 ACK]
 3(20748) DEBUG: <core> [core/receive.c:379]: receive_msg(): preparing to run routing scripts...
 3(20748) DEBUG: tm [t_lookup.c:1328]: t_newtran(): msg (0x7fcf6e57b720) id=1/20748 global id=0/0 T start=0xffffffffffffffff
 3(20748) DEBUG: <core> [core/parser/msg_parser.c:185]: get_hdr_field(): content_length=0
 3(20748) DEBUG: <core> [core/parser/msg_parser.c:89]: get_hdr_field(): found end of header
 3(20748) DEBUG: tm [t_lookup.c:497]: t_lookup_request(): start searching: hash=911, isACK=1
 3(20748) DEBUG: tm [t_lookup.c:439]: matching_3261(): RFC3261 transaction matched, tid=194358777
 3(20748) DEBUG: tm [t_lookup.c:692]: t_lookup_request(): transaction found (T=0x7fcf69bce838)
 3(20748) DEBUG: tm [t_reply.c:1667]: cleanup_uac_timers(): RETR/FR timers reset
 3(20748) DEBUG: <core> [core/timer.c:557]: timer_add_safe(): timer_add called on an active timer 0x7fcf69bce8c0 (0x7fcf699a8720, 0x7fcf699a8720), flags 201
 3(20748) DEBUG: tm [t_funcs.c:146]: put_on_wait(): transaction 0x7fcf69bce838 already on wait
 3(20748) DEBUG: <core> [core/receive.c:437]: receive_msg(): request-route executed in: 237 usec
 3(20748) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
 3(20748) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
 3(20748) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
 3(20748) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
 3(20748) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
 3(20748) DEBUG: <core> [core/usr_avp.c:636]: destroy_avp_list(): destroying list (nil)
 3(20748) DEBUG: <core> [core/xavp.c:529]: xavp_destroy_list(): destroying xavp list (nil)
 3(20748) DEBUG: <core> [core/receive.c:528]: receive_msg(): cleaning up
```

#### SIP Traffic
Call signaling in attached file

[icmp.pcap.gz](https://github.com/kamailio/kamailio/files/4837863/icmp.pcap.gz)

### Possible Solutions
Not Know

### Additional Information

  * **Kamailio Version** - output of `kamailio -v`

```
version: kamailio 5.3.4 (x86_64/linux) 117ff9
flags: USE_TCP, USE_TLS, USE_SCTP, TLS_HOOKS, USE_RAW_SOCKS, DISABLE_NAGLE, USE_MCAST, DNS_IP_HACK, 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, TLS_PTHREAD_MUTEX_SHARED
ADAPTIVE_WAIT_LOOPS 1024, MAX_RECV_BUFFER_SIZE 262144, MAX_URI_SIZE 1024, BUF_SIZE 65535, DEFAULT PKG_SIZE 8MB
poll method support: poll, epoll_lt, epoll_et, sigio_rt, select.
id: 117ff9 
compiled on 15:31:51 May  6 2020 with gcc 8.3.1
```

* **Operating System**:
```
[centos at ip-172-22-6-233 ~]$ cat /etc/os-release 
NAME="CentOS Linux"
VERSION="8 (Core)"
ID="centos"
ID_LIKE="rhel fedora"
VERSION_ID="8"
PLATFORM_ID="platform:el8"
PRETTY_NAME="CentOS Linux 8 (Core)"
ANSI_COLOR="0;31"
CPE_NAME="cpe:/o:centos:centos:8"
HOME_URL="https://www.centos.org/"
BUG_REPORT_URL="https://bugs.centos.org/"

CENTOS_MANTISBT_PROJECT="CentOS-8"
CENTOS_MANTISBT_PROJECT_VERSION="8"
REDHAT_SUPPORT_PRODUCT="centos"
REDHAT_SUPPORT_PRODUCT_VERSION="8"
```

-- 
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/2377
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.kamailio.org/pipermail/sr-dev/attachments/20200626/dc524b64/attachment.html>


More information about the sr-dev mailing list