search

sipwise / rtpengine

The Sipwise media proxy for Kamailio
GNU General Public License v3.0
788 stars 371 forks source link

no available proxies #939

Open nicoonline opened 4 years ago

nicoonline commented 4 years ago

Hello, I have sometimes this error in the logs, 3 times a day..

Feb 21 16:00:359proxy1 /usr/sbin/kamailio[2203]: ERROR: rtpengine [rtpengine.c:2744]: send_rtpp_command(): timeout waiting reply for command "offer" from RTP proxy Feb 21 16:00:352proxy1 /usr/sbin/kamailio[2203]: ERROR: rtpengine [rtpengine.c:2969]: select_rtpp_node(): rtpengine failed to select new for calllen=32 callid=b89f8b289157eab2a532a2f54095448f Feb 21 16:00:352proxy1 /usr/sbin/kamailio[2203]: ERROR: rtpengine [rtpengine.c:2440]: rtpp_function_call(): no available proxies

Any ideas ?

[root@proxy1 ~]# /etc/kamailio/rtpengine -v Version: git-mr6.5.5-44828a6

nicoonline commented 4 years ago

in logs:

Feb 21 16:00:29 proxy1 rtpengine[1426]: INFO: [b89f8b289157eab2a532a2f54095448f]: Received command 'offer' from 127.0.0.1:52937 Feb 21 16:00:29 proxy1 rtpengine[1426]: NOTICE: [b89f8b289157eab2a532a2f54095448f]: Creating new call Feb 21 16:00:29 proxy1 rtpengine[1426]: NOTICE: [b89f8b289157eab2a532a2f54095448f]: Turning on call recording. Feb 21 16:00:29 proxy1 rtpengine[1426]: INFO: [b89f8b289157eab2a532a2f54095448f]: Replying to 'offer' from 127.0.0.1:52937 (elapsed time 0.013739 sec) Feb 21 16:00:34 proxy1 rtpengine[1426]: INFO: [b89f8b289157eab2a532a2f54095448f]: Received command 'delete' from 127.0.0.1:54599 Feb 21 16:00:34 proxy1 rtpengine[1426]: INFO: [b89f8b289157eab2a532a2f54095448f]: Scheduling deletion of call branch '02890fc59e9094be' (via-branch '') in 30 seconds Feb 21 16:00:34 proxy1 rtpengine[1426]: INFO: [b89f8b289157eab2a532a2f54095448f]: Replying to 'delete' from 127.0.0.1:54599 (elapsed time 0.000124 sec) Feb 21 16:00:34 proxy1 rtpengine[1426]: INFO: [b89f8b289157eab2a532a2f54095448f]: Received command 'offer' from 127.0.0.1:54599 Feb 21 16:00:35 proxy1 rtpengine[1426]: INFO: [b89f8b289157eab2a532a2f54095448f]: Replying to 'offer' from 127.0.0.1:54599 (elapsed time 0.422809 sec) Feb 21 16:00:36 proxy1 rtpengine[1426]: INFO: [b89f8b289157eab2a532a2f54095448f]: Received command 'answer' from 127.0.0.1:33454 Feb 21 16:00:36 proxy1 rtpengine[1426]: INFO: [b89f8b289157eab2a532a2f54095448f]: Replying to 'answer' from 127.0.0.1:33454 (elapsed time 0.004797 sec) Feb 21 16:00:36 proxy1 rtpengine-recording[1463]: WARNING: [C b89f8b289157eab2a532a2f54095448f-2bff3d52a1058943.meta] [S tag-0-media-1-component-1-RTP-id-2] Failed to parse packet headers

rfuchs commented 4 years ago

Daemon overloaded, CPU maxed out? Almost half a second to reply to an offer is a long time.

nicoonline commented 4 years ago

no. this is indeed strange..

Feb 24 14:17:31 proxy1 rtpengine[1426]: INFO: Replying to 'ping' from 127.0.0.1:35725 (elapsed time 0.000001 sec) Feb 24 14:17:32 proxy1 rtpengine[1426]: INFO: [ef06e70ce909d311ad09009033080625@192.168.50.50]: Replying to 'offer' from 127.0.0.1:35725 (elapsed time 0.904529 sec) Feb 24 14:17:32 proxy1 rtpengine[1426]: INFO: Detected command from 127.0.0.1:35725 as a duplicate Feb 24 14:17:32 proxy1 rtpengine[1426]: INFO: Detected command from 127.0.0.1:35725 as a duplicate Feb 24 14:17:32 proxy1 rtpengine[1426]: INFO: Detected command from 127.0.0.1:35725 as a duplicate Feb 24 14:17:32 proxy1 rtpengine[1426]: INFO: Detected command from 127.0.0.1:35725 as a duplicate Feb 24 14:17:32 proxy1 rtpengine[1426]: INFO: Increasing timer run interval to 2 seconds

nicoonline commented 4 years ago

[root@proxy1 ~]# grep Increasing /var/log/rtpengine.log Feb 24 05:21:57 proxy1 rtpengine[1426]: INFO: Increasing timer run interval to 2 seconds Feb 24 06:29:05 proxy1 rtpengine[1426]: INFO: Increasing timer run interval to 2 seconds Feb 24 06:36:06 proxy1 rtpengine[1426]: INFO: Increasing timer run interval to 2 seconds Feb 24 07:53:28 proxy1 rtpengine[1426]: INFO: Increasing timer run interval to 2 seconds Feb 24 08:07:23 proxy1 rtpengine[1426]: INFO: Increasing timer run interval to 2 seconds Feb 24 08:12:27 proxy1 rtpengine[1426]: INFO: Increasing timer run interval to 2 seconds Feb 24 08:12:41 proxy1 rtpengine[1426]: INFO: Increasing timer run interval to 2 seconds Feb 24 08:15:53 proxy1 rtpengine[1426]: INFO: Increasing timer run interval to 2 seconds Feb 24 08:23:38 proxy1 rtpengine[1426]: INFO: Increasing timer run interval to 2 seconds Feb 24 08:52:51 proxy1 rtpengine[1426]: INFO: Increasing timer run interval to 2 seconds Feb 24 09:06:44 proxy1 rtpengine[1426]: INFO: Increasing timer run interval to 2 seconds Feb 24 09:14:14 proxy1 rtpengine[1426]: INFO: Increasing timer run interval to 2 seconds Feb 24 09:14:37 proxy1 rtpengine[1426]: INFO: Increasing timer run interval to 2 seconds Feb 24 09:20:24 proxy1 rtpengine[1426]: INFO: Increasing timer run interval to 2 seconds Feb 24 09:25:54 proxy1 rtpengine[1426]: INFO: Increasing timer run interval to 2 seconds Feb 24 09:26:03 proxy1 rtpengine[1426]: INFO: Increasing timer run interval to 2 seconds Feb 24 09:26:47 proxy1 rtpengine[1426]: INFO: Increasing timer run interval to 2 seconds Feb 24 09:28:42 proxy1 rtpengine[1426]: INFO: Increasing timer run interval to 2 seconds Feb 24 09:29:09 proxy1 rtpengine[1426]: INFO: Increasing timer run interval to 2 seconds ....

rfuchs commented 4 years ago

Timer run interval doesn't really have anything to do with it.

Something is stalling the daemon and keeps it from responding in time. Usually this points to some kind of resource bottleneck.

nicoonline commented 4 years ago

checking what. Updating to 6.5.7 and disabled the recording... :) Will keep informed.

nicoonline commented 4 years ago

Hello,

Seems we have this problem when we enable the rtp recording on the calls.

rfuchs commented 4 years ago

So your recording daemon is probably maxing out the CPU? There's only so many calls that you can record at the same time with it.

nicoonline commented 4 years ago

No we have only a few calls so cpu is not maxed out.