#599 Meedia keep alive with rtpproxy

1.8.x
open
modules (454)
7
2013-01-22
2012-12-05
No

While using the Meedia keep alive mothod with RTP Proxy, we've noticed that there should be some error with the OpenSIPS and RTP Proxy communication.

Due this error, when the RTP traffic stops and the the RTP Proxy send a signal to the SIP Proxy to kill the dialog this error appear on he log and the Media Keep Alive does not work:

Dec 5 11:27:33 HOST /sbin/opensips[19666]: ERROR:rtpproxy:timeout_listener_process: Wrong formated message received from rtpproxy - invalid dialog entry [74#0123645]
Dec 5 11:27:33 HOST /sbin/opensips[19666]: ERROR:rtpproxy:timeout_listener_process: Wrong formated message received from rtpproxy - invalid dialog entry [1763555126#0123083]
Dec 5 11:28:12 HOST /sbin/opensips[19666]: ERROR:rtpproxy:timeout_listener_process: Wrong formated message received from rtpproxy - invalid dialog entry [52365#0123359]

Maybe the problem is the # on the dialog string, but its not and common erros, it not happens every time.

Discussion

    • labels: --> modules
    • milestone: --> 1.8.x
     
    • assigned_to: nobody --> razvancrainea
    • priority: 5 --> 7
     
  • Razvan Crainea
    Razvan Crainea
    2013-01-22

    Hi, Carlos!

    Can you specify the exact version of RTPProxy and OpenSIPS you are using?

    Best regards,
    Răzvan

     
  • Carlos, any input here ?

     
  • Razavan, sorry my absence.

    I'm using OpenSIPS (1.8.2-notls (x86_64/linux)) and RTP Proxy Basic version: 20040107

     
  • Razvan Crainea
    Razvan Crainea
    2013-01-30

    Hi, Carlos!

    I will attach a patch that treats the timeout messages received from RTPProxy differently. Can you please apply it to your sources and let me know if you still have these kind of issues?

    Best regards,
    Răzvan

     
  • This the message after the patch.

    Dec 20 14:59:28 /sbin/opensips[6978]: ERROR:rtpproxy:timeout_listener_process: Wrong formated message received from rtpproxy [1]

    Dec 20 14:59:28 /sbin/opensips[6978]: INFO:rtpproxy:timeout_listener_process: RTPProxy buffer: [255] <3066.74196691#0121744.870880408#0121968.1268777973#012949.1984340712#01274.448511458#012860.999375735#0121893.793805873#0122451.492975819#0123796.1055294097#012485.853875076#0122426.1713554641#0122310.1069754522#012555.1176777710#0123225.315833604#0122922.440360056#012976.780586176#0122899.1149567571#0121>

     
  • The problem occurred again in January 10. It is strange that in the whole month it happened only once, but five times in the same day.

    Jan 10 16:52:10 /sbin/opensips[17205]: ERROR:rtpproxy:timeout_listener_process: Wrong formated message received from rtpproxy [36]
    Jan 10 16:52:10 /sbin/opensips[17205]: INFO:rtpproxy:timeout_listener_process: RTPProxy buffer: [255] <3915.459709268#0121158.922138438#012105.505573334#0121941.1175281095#0123613.1439412707#0121426.486871715#0122492.960764962#0121681.1325307#01270.415490414#0122086.1078799294#0123236.1814649025#01268.985453293#0124001.420803067#012920.629061337#0122600.1036453804#0122691.1059400723#0122821.562408438#01236>
    Jan 10 16:52:10 /sbin/opensips[17205]: ERROR:rtpproxy:timeout_listener_process: Wrong formated message received from rtpproxy - invalid dialog entry [743#0122720]
    Jan 10 16:52:10 /sbin/opensips[17205]: INFO:rtpproxy:timeout_listener_process: RTPProxy buffer: [255] <743#0122720.536914266#0122384.481076560#0123532.317916971#012527.101763809#0122137.713736854#0122527.1365726924#0123021.1394784068#0121511.1564218745#01269.1462570833#012303.279115809#0122093.471362058#0122779.1140796292#01258.1352036018#012849.483564012#012622.1290974860#0122933.2000065865#012495.1806059>
    Jan 10 16:52:10 FALEMAIS-01 /sbin/opensips[17205]: ERROR:rtpproxy:timeout_listener_process: Wrong formated message received from rtpproxy - invalid dialog entry [278#012293]
    Jan 10 16:52:10 /sbin/opensips[17205]: INFO:rtpproxy:timeout_listener_process: RTPProxy buffer: [255] <278#012293.590754173#0122114.490936113#012229.1844167156#0121350.1503904380#0121213.314288460#0121020.2016504033#0123987.651311895#0121025.1886766440#0122125.483951387#0123158.1904220345#0121977.1489024023#0122394.263001709#0121428.227540943#0121225.1572870527#0123.1682500917#0122684.453182189#012661.8982>
    Jan 10 16:52:10 FALEMAIS-01 /sbin/opensips[17205]: ERROR:rtpproxy:timeout_listener_process: Wrong formated message received from rtpproxy - invalid dialog entry [42420#0122402]
    Jan 10 16:52:10 /sbin/opensips[17205]: INFO:rtpproxy:timeout_listener_process: RTPProxy buffer: [146] <42420#0122402.2093291960#0121420.1818050192#0121710.697760088#0121243.2075148525#012433.680515521#0121585.1552333464#0122403.1029852252#0123780.1462234266#0121987.445633556#012>

     
  • Analyzing further I have found in the same second the following message:

    ERROR:rtpproxy:force_rtp_proxy_body: incorrect port 0 in reply from rtp proxy
    Jan 10 16:52:10 /sbin/opensips[17256]: SCRIPT: onreply_1 RTPPROXY activated [INVITE/f=sip:8131980900@z.y.z.w:5060/r=<null>/ct=<sip:8897#552194151061@z.x.y.w:5060>/ci=DSX005438f555c5ffa86d61390562f747ce.187.63.142.10/1z.y.x.z]

     
  • Razvan Crainea
    Razvan Crainea
    2013-01-31

    Hi, Flavio!

    So you are saying that after applying the patch, you still have this warning:

    Dec 20 14:59:28 /sbin/opensips[6978]: ERROR:rtpproxy:timeout_listener_process: Wrong formated message received from rtpproxy [1]
    Dec 20 14:59:28 /sbin/opensips[6978]: INFO:rtpproxy:timeout_listener_process: RTPProxy buffer: [255] ...

    Is the date of the machine altered, or these might be older logs? Because, for example, the RTPProxy buffer has been increased from 255 to 4096, and it doesn't really make sense.

    Best regards,
    Razvan

     
  • Hi Razvan,

    Actually the patch is just the message increase. The log is being done to a ramdrive (SCRIPT, INFO, ERROR...) but with 2GB it was full. That's why I saw the error just from january 10th. I have restarted the log today. It is intermittent, it happens once in weeks. I will check in the next week.