On 2018-08-06 21:17, Alex Balashov wrote:
From the 5.1 TB transferred on the 'lo' interface (RTPEngine running on same host as Kamailio):lo: flags=73<UP,LOOPBACK,RUNNING> mtu 65536 inet 127.0.0.1 netmask 255.0.0.0 inet6 ::1 prefixlen 128 scopeid 0x10<host> loop txqueuelen 1 (Local Loopback) RX packets 27694476978 bytes 5678003789723 (5.1 TiB) RX errors 0 dropped 0 overruns 0 frame 0 TX packets 27694476978 bytes 5678003789723 (5.1 TiB) TX errors 0 dropped 0 overruns 0 carrier 0 collisions 0 ... I would surmise that this is some sort of loop / infinite loop condition, but I can't quite put my finger on what it is. From an RTPEngine logging standpoint, the scenario begins looking rather normally: Aug 6 18:11:04 gw1 rtpengine[25476]: INFO: [[email protected]]: Received command 'offer' from 127.0.0.1:48525 Aug 6 18:11:04 gw1 rtpengine[25476]: NOTICE: [[email protected]]: Creating new call Aug 6 18:11:04 gw1 rtpengine[25476]: INFO: [[email protected]]: offer time = 0.000865 sec Aug 6 18:11:04 gw1 rtpengine[25476]: INFO: [[email protected]]: Replying to 'offer' from 127.0.0.1:48525 Aug 6 18:11:14 gw1 rtpengine[25476]: INFO: [[email protected]]: Received command 'answer' from 127.0.0.1:58668 Aug 6 18:11:14 gw1 rtpengine[25476]: INFO: [[email protected]]: answer time = 0.000123 sec Aug 6 18:11:14 gw1 rtpengine[25476]: INFO: [[email protected]]: Replying to 'answer' from 127.0.0.1:58668 Aug 6 18:11:18 gw1 rtpengine[25476]: INFO: [[email protected] port 61666]: Confirmed peer address as 2.2.2.2:38236 Aug 6 18:11:23 gw1 rtpengine[25476]: INFO: [[email protected]]: Received command 'offer' from 127.0.0.1:50995 Aug 6 18:11:23 gw1 rtpengine[25476]: INFO: [[email protected]]: offer time = 0.000082 sec Aug 6 18:11:23 gw1 rtpengine[25476]: INFO: [[email protected]]: Replying to 'offer' from 127.0.0.1:50995 Aug 6 18:11:23 gw1 rtpengine[25476]: INFO: [[email protected]]: Received command 'offer' from 127.0.0.1:47321 Aug 6 18:11:23 gw1 rtpengine[25476]: INFO: [[email protected]]: offer time = 0.000151 sec Aug 6 18:11:23 gw1 rtpengine[25476]: INFO: [[email protected]]: Replying to 'offer' from 127.0.0.1:47321 Aug 6 18:11:23 gw1 rtpengine[25476]: INFO: [[email protected] port 61666]: Switching local interface to 1.1.1.1:61666 Aug 6 18:11:23 gw1 rtpengine[25476]: ERR: [[email protected] port 61666]: Too many packets in UDP receive queue (more than 50), aborting loop. Dropped packets possible [... ad nauseum... ] The only thing unusual about it from a SIP perspective is that it involves an SRTP endpoint and several reinvites which don't seem to be handled as one would expect: Aug 6 18:11:04 gw1 /usr/local/sbin/kamailio[22070]: INFO: [R-INBOUND-ROUTE-BRANCH:[email protected]] Relaying media through RTPEngine Aug 6 18:11:04 gw1 /usr/local/sbin/kamailio[22070]: INFO: [R-INBOUND-ROUTE-BRANCH:[email protected]] -> Forcing Secure RTP (SRTP) profile in offer Aug 6 18:11:04 gw1 /usr/local/sbin/kamailio[22233]: INFO: [R-MAIN-REPLY:[email protected]] Reply '100 Trying' from 3.3.3.3:54246 Aug 6 18:11:04 gw1 /usr/local/sbin/kamailio[22233]: INFO: [R-MAIN-REPLY:[email protected]] Reply '180 Ringing' from 3.3.3.3:54246 Aug 6 18:11:14 gw1 /usr/local/sbin/kamailio[22258]: INFO: [R-MAIN-REPLY:[email protected]] Reply '200 OK' from 3.3.3.3:54246 Aug 6 18:11:14 gw1 /usr/local/sbin/kamailio[22258]: INFO: [R-MAIN-REPLY:[email protected]] -> Reply contains SDP; diverting through RTPEngine Aug 6 18:11:14 gw1 /usr/local/sbin/kamailio[22112]: INFO: [R-MAIN:[email protected]] -> Other sequential ACK received from 2.2.2.2:5060 Aug 6 18:11:23 gw1 /usr/local/sbin/kamailio[22263]: INFO: [R-MAIN:[email protected]] -> Re-invite received on rtpengine'd call -- updating RTPEngine Aug 6 18:11:23 gw1 /usr/local/sbin/kamailio[22068]: INFO: [R-MAIN:[email protected]] -> Re-invite received on rtpengine'd call -- updating RTPEngine Aug 6 18:11:23 gw1 /usr/local/sbin/kamailio[22074]: INFO: [R-MAIN-REPLY:[email protected]] Reply '100 Trying' from 1.1.1.1:5060 Aug 6 18:11:23 gw1 /usr/local/sbin/kamailio[22057]: INFO: [R-MAIN-REPLY:[email protected]] Reply '100 Trying' from 2.2.2.2:5060 Aug 6 18:11:23 gw1 /usr/local/sbin/kamailio[22070]: INFO: [R-MAIN-REPLY:[email protected]] Reply '200 OK' from 2.2.2.2:5060 Aug 6 18:11:23 gw1 /usr/local/sbin/kamailio[22070]: INFO: [R-MAIN-REPLY:[email protected]] -> Reply contains SDP; diverting through RTPEngine Aug 6 18:11:27 gw1 /usr/local/sbin/kamailio[22065]: INFO: [R-MAIN-REPLY:[email protected]] Reply '200 OK' from 2.2.2.2:5060 Aug 6 18:11:27 gw1 /usr/local/sbin/kamailio[22065]: INFO: [R-MAIN-REPLY:[email protected]] -> Reply contains SDP; diverting through RTPEngine Aug 6 18:11:27 gw1 /usr/local/sbin/kamailio[22104]: INFO: [R-MAIN-REPLY:[email protected]] Reply '200 OK' from 1.1.1.1:5060 Aug 6 18:11:27 gw1 /usr/local/sbin/kamailio[22104]: INFO: [R-MAIN-REPLY:[email protected]] -> Reply contains SDP; diverting through RTPEngine Aug 6 18:11:27 gw1 /usr/local/sbin/kamailio[22088]: INFO: [R-MAIN-REPLY:[email protected]] Reply '200 OK' from 2.2.2.2:5060 Aug 6 18:11:27 gw1 /usr/local/sbin/kamailio[22088]: INFO: [R-MAIN-REPLY:[email protected]] -> Reply contains SDP; diverting through RTPEngine Aug 6 18:11:27 gw1 /usr/local/sbin/kamailio[22118]: INFO: [R-MAIN-REPLY:[email protected]] Reply '200 OK' from 1.1.1.1:5060 Aug 6 18:11:27 gw1 /usr/local/sbin/kamailio[22118]: INFO: [R-MAIN-REPLY:[email protected]] -> Reply contains SDP; diverting through RTPEngine Aug 6 18:11:27 gw1 /usr/local/sbin/kamailio[22100]: INFO: [R-MAIN-REPLY:[email protected]] Reply '200 OK' from 2.2.2.2:5060 Aug 6 18:11:27 gw1 /usr/local/sbin/kamailio[22100]: INFO: [R-MAIN-REPLY:[email protected]] -> Reply contains SDP; diverting through RTPEngine Aug 6 18:11:27 gw1 /usr/local/sbin/kamailio[22116]: INFO: [R-MAIN-REPLY:[email protected]] Reply '200 OK' from 1.1.1.1:5060 Aug 6 18:11:27 gw1 /usr/local/sbin/kamailio[22116]: INFO: [R-MAIN-REPLY:[email protected]] -> Reply contains SDP; diverting through RTPEngine Aug 6 18:11:27 gw1 /usr/local/sbin/kamailio[22094]: INFO: [R-MAIN-REPLY:[email protected]] Reply '200 OK' from 1.1.1.1:5060 Aug 6 18:11:27 gw1 /usr/local/sbin/kamailio[22094]: INFO: [R-MAIN-REPLY:[email protected]] -> Reply contains SDP; diverting through RTPEngine Aug 6 18:11:27 gw1 /usr/local/sbin/kamailio[22263]: INFO: [R-MAIN:[email protected]] -> Other sequential ACK received from 3.3.3.3:54246 Aug 6 18:11:27 gw1 /usr/local/sbin/kamailio[22090]: INFO: [R-MAIN:[email protected]] -> Other sequential ACK received from 1.1.1.1:5060 Aug 6 18:11:27 gw1 /usr/local/sbin/kamailio[22263]: INFO: [R-MAIN:[email protected]] -> Other sequential ACK received from 3.3.3.3:54246 Aug 6 18:11:27 gw1 /usr/local/sbin/kamailio[22263]: INFO: [R-MAIN:[email protected]] -> Other sequential ACK received from 3.3.3.3:54246 Aug 6 18:11:27 gw1 /usr/local/sbin/kamailio[22074]: INFO: [R-MAIN:[email protected]] -> Other sequential ACK received from 1.1.1.1:5060 Aug 6 18:11:27 gw1 /usr/local/sbin/kamailio[22068]: INFO: [R-MAIN:[email protected]] -> Other sequential ACK received from 1.1.1.1:5060 Aug 6 18:11:27 gw1 /usr/local/sbin/kamailio[22263]: INFO: [R-MAIN:[email protected]] -> Other sequential ACK received from 3.3.3.3:54246 Aug 6 18:11:27 gw1 /usr/local/sbin/kamailio[22098]: INFO: [R-MAIN:[email protected]] -> Other sequential ACK received from 1.1.1.1:5060 Aug 6 18:11:58 gw1 /usr/local/sbin/kamailio[22211]: INFO: [R-MAIN:[email protected]] -> BYE (hangup) received from 3.3.3.3:54246 Aug 6 18:11:58 gw1 /usr/local/sbin/kamailio[22211]: INFO: [R-MAIN:[email protected]] -> BYE received - tearing down rtpengine session Aug 6 18:12:02 gw1 /usr/local/sbin/kamailio[22104]: INFO: [R-MAIN:[email protected]] -> BYE (hangup) received from 1.1.1.1:5060 Aug 6 18:12:02 gw1 /usr/local/sbin/kamailio[22104]: INFO: [R-MAIN:[email protected]] -> BYE received - tearing down rtpengine session Aug 6 18:12:02 gw1 /usr/local/sbin/kamailio[22211]: INFO: [R-MAIN:[email protected]] -> BYE (hangup) received from 3.3.3.3:54246 Aug 6 18:12:02 gw1 /usr/local/sbin/kamailio[22211]: INFO: [R-MAIN:[email protected]] -> BYE received - tearing down rtpengine session Aug 6 18:12:02 gw1 /usr/local/sbin/kamailio[22211]: INFO: [R-MAIN:[email protected]] -> BYE (hangup) received from 3.3.3.3:54246 Aug 6 18:12:02 gw1 /usr/local/sbin/kamailio[22211]: INFO: [R-MAIN:[email protected]] -> BYE received - tearing down rtpengine session Aug 6 18:12:02 gw1 /usr/local/sbin/kamailio[22211]: INFO: [R-MAIN:[email protected]] -> BYE (hangup) received from 3.3.3.3:54246 Aug 6 18:12:02 gw1 /usr/local/sbin/kamailio[22211]: INFO: [R-MAIN:[email protected]] -> BYE received - tearing down rtpengine session Aug 6 18:12:02 gw1 /usr/local/sbin/kamailio[22211]: INFO: [R-MAIN:[email protected]] -> BYE (hangup) received from 3.3.3.3:54246 Aug 6 18:12:02 gw1 /usr/local/sbin/kamailio[22211]: INFO: [R-MAIN:[email protected]] -> BYE received - tearing down rtpengine session But while this signalling chronology is anomalous, it doesn't explain a continuous queue overflow of some kind which lasted several hours?
This can happen if the output SDP (rewritten by rtpengine) is fed back into rtpengine as an input SDP for the same call/branch. Then rtpengine will start looping media back to itself. There are some safeguards in the code to prevent this from happening, but if the underlying signalling is broken, it can still happen.
Cheers _______________________________________________ Kamailio (SER) - Users Mailing List [email protected] https://lists.kamailio.org/cgi-bin/mailman/listinfo/sr-users
