[Nice] nicesrc outbuf overwritten before read

[Daniel Lindström]

Hi

"How often does that happen?"
Looking at the log it seems to me it happens about once every jpeg
frame sent, that is about once every fifth packet. However, I don't
think it's random. I know we tried earlier to decreasing the size of
the frames so that one frame needed two packets to fit. If I remember
correctly, that resulted in that the nicesrc behaved like that on one
packet out of two. I might be mistaken though.


"Also, what does wireshark tell you, why are you receiving something
on the TURN socket, if it uses the host candidates then you shouldn't
be receiving anything on the TURN socket (other than binding requests
which should not translate to any user callback being called)."
I guess you are refering to the "received message on TURN socket"
message? I can't say I fully understand what's going on underneath,
but that message makes me a bit confused. Looking at wireshark, I
don't get anything on any other ports than the one used for the RTP
traffic for the host candidate.

Anyway, your solution works fine for me, and your help is appreciated.
Thank you.

About farsight, I have not really looked into it, but I get the
feeling it's more than we need. I think libnice fits pretty good
though.

Thank you
 -Daniel


2011/6/24 Youness Alaoui <youness.alaoui at collabora.co.uk>:
> Hi,
>
> Thanks for the log, that's what I needed to see. forget about that "set it to
> NULL", the outbuf was already set to NULL (in _create), so all that was needed
> was "check if outbuf is NULL in read_callback", but it's not necessary anymore
> considering the log you've given me.
>
> I really don't understand why this is happening, after main_loop-quit is called,
> it shouldn't call the read_callback anymore. How often does that happen? for
> every packet? or once in a while ? Also, what does wireshark tell you, why are
> you receiving something on the TURN socket, if it uses the host candidates then
> you shouldn't be receiving anything on the TURN socket (other than binding
> requests which should not translate to any user callback being called).
> Anyways, I thought of a solution to this issue, and I committed a fix here :
> http://cgit.collabora.com/git/user/kakaroto/libnice.git/commit/?id=dc9ea0899e400403d010d9d49fc2dce624b60e7f
> Let me know if it's all good now.
>
> I would still like to know why this was happening in the first place though, so
> if you could help track down this issue, that would be helpful.
>
> p.s: You said you're doing a VoIP/video call, why are you not using Farsight?
> That's what it is for!
>
> Thank you,
> Youness.
>
>
> On 06/22/2011 05:02 AM, Daniel Lindström wrote:
>> Thank you for your answers. I will try to provide some more details.
>>
>> Yes, it is a VoIP (and video) call I'm trying to do, but currently
>> only with video for simplicity. I think it's strange as well that
>> set_relay_info triggers it, but it is a fact that it does. It is also
>> what triggers the finding of the other candidates, so maybe the fact
>> that we find both server reflective candidates  and relay candidates
>> has anything to do with it the problem. It still uses the host
>> candidate though.  Using wireshark I can see that the RTP  data goes
>> through the loopback interface.
>>
>> I did as you told me and added some extra debug messages. I',m not
>> sure what you want me to set to NULL though, since if I set outbuf to
>> NULL I can't return it in the create method. I wrote “calling xxx”
>> before calling main_loop_quit and main_loop_run, and “xxx called”
>> after.
>>
>> This is how the debug messages looks when not working. It is about one
>> packet per (jpeg) frame it behaves like this..
>>
>> 0:01:59.792968918  9308  0x948a8e0 LOG                  nicesrc
>> gstnicesrc.c:311:gst_nice_src_create:<nicesrc_video> create called.
>> 0:01:59.792985957  9308  0x948a8e0 LOG                  nicesrc
>> gstnicesrc.c:323:gst_nice_src_create:<nicesrc_video> calling
>> g_main_loop_run
>>
>> (GtkLauncher:9308): libnice-DEBUG: Agent 0x920aea8 : Packet received
>> on local socket 13 from [172.16.0.27]:49381 (1412 octets).
>> STUN error: RTP or other non-protocol packet!
>> 0:01:59.837100543  9308  0x948a8e0 LOG                  nicesrc
>> gstnicesrc.c:197:gst_nice_src_read_callback:<NiceAgent at 0x920aea8>
>> gst_nice_src_read_callback called. stream_id = 2, component_id = 1,
>> len = 1412, buf = 0xb15d3cb2
>> 0:01:59.837135197  9308  0x948a8e0 LOG                  nicesrc
>> gstnicesrc.c:201:gst_nice_src_read_callback:<NiceAgent at 0x920aea8> Got
>> buffer, getting out of the main loop. basesrc = 0x947b010, nicesrc =
>> 0x947b010
>> 0:01:59.837170065  9308  0x948a8e0 LOG                  nicesrc
>> gstnicesrc.c:208:gst_nice_src_read_callback:<NiceAgent at 0x920aea8>
>> Copied buffer (0xb15d3cb2) of size 1412 to address: 0xaea1e0e8
>> 0:01:59.837195246  9308  0x948a8e0 LOG                  nicesrc
>> gstnicesrc.c:212:gst_nice_src_read_callback:<nicesrc_video> calling
>> g_main_loop_quit
>> 0:01:59.837218697  9308  0x948a8e0 LOG                  nicesrc
>> gstnicesrc.c:214:gst_nice_src_read_callback:<nicesrc_video>
>> g_main_loop_quit called
>>
>> (GtkLauncher:9308): libnice-DEBUG: received message on TURN socket
>> (GtkLauncher:9308): libnice-DEBUG: Agent 0x920aea8 : Packet received
>> on local socket 13 from [172.16.0.27]:49381 (1412 octets).
>> STUN error: RTP or other non-protocol packet!
>> 0:01:59.837293440  9308  0x948a8e0 LOG                  nicesrc
>> gstnicesrc.c:197:gst_nice_src_read_callback:<NiceAgent at 0x920aea8>
>> gst_nice_src_read_callback called. stream_id = 2, component_id = 1,
>> len = 1412, buf = 0xb15d3cb2
>> 0:01:59.837313889  9308  0x948a8e0 LOG                  nicesrc
>> gstnicesrc.c:201:gst_nice_src_read_callback:<NiceAgent at 0x920aea8> Got
>> buffer, getting out of the main loop. basesrc = 0x947b010, nicesrc =
>> 0x947b010
>> 0:01:59.837334916  9308  0x948a8e0 LOG                  nicesrc
>> gstnicesrc.c:208:gst_nice_src_read_callback:<NiceAgent at 0x920aea8>
>> Copied buffer (0xb15d3cb2) of size 1412 to address: 0xaea1bb60
>> 0:01:59.837350780  9308  0x948a8e0 LOG                  nicesrc
>> gstnicesrc.c:212:gst_nice_src_read_callback:<nicesrc_video> calling
>> g_main_loop_quit
>> 0:01:59.837364900  9308  0x948a8e0 LOG                  nicesrc
>> gstnicesrc.c:214:gst_nice_src_read_callback:<nicesrc_video>
>> g_main_loop_quit called
>>
>> 0:01:59.837380223  9308  0x948a8e0 LOG                  nicesrc
>> gstnicesrc.c:325:gst_nice_src_create:<nicesrc_video> g_main_loop_run
>> called
>> 0:01:59.837394056  9308  0x948a8e0 LOG                  nicesrc
>> gstnicesrc.c:328:gst_nice_src_create:<nicesrc_video> Got buffer,
>> pushing
>> 0:01:59.837414500  9308  0x948a8e0 DEBUG           rtpjpegdepay
>> gstrtpjpegdepay.c:539:gst_rtp_jpeg_depay_process:<depay> frag 1260,
>> type 0, Q 255, width 320, height 240
>> ....
>>
>> The row “(GtkLauncher:9308): libnice-DEBUG: received message on TURN
>> socket” also appears about once every frame, can that be related
>> somehow?
>>
>> The behaiviour Im getting in the end is a lot of broken jpeg frames,
>> so when trying to play the video it appears like broken frames,
>> extremly low framerate (a couple per minute), or nothing at all.
>> I know for sure I dont have any packetloss since I'm running over
>> loopback interface.
>>
>> I noticed I had digest mode enabled on the mailing list, so I could
>> not answer the mail directly. I pasted the old mails in the bottom.
>>
>> Thank you
>>  - Daniel
>>
>>> Hi,
>>>
>>> I hope I can help you with your issue, but I'm not sure exactly what's going on.
>>> First of all, you want to do VoIP using gstreamer? then why not use farsight
>>> directly ?
>>> the set_relay_info should not affect in any way the bug you are describing so I
>>> don't think/see how it's related.
>>> Also, the code does not loop internally, so when the read_callback is called,
>>> and g_main_loop_quit is called within it, then the mainloop should quit and the
>>> callback should not be called twice.
>>> Can you add debug messages in the read_callback and before+after the
>>> g_main_loop_run and get me proof that that's what's happening?
>>> Also maybe assign NULL to outbuf after its pointer is copied into *buffer, and
>>> print the value of outbuf in the read_callback to make sure that it is actually
>>> NULL all the time.
>>> Also, what is the exact behavior you're getting, so I know why you've looked
>>> into this.. was it that some data is lost ? If it is, then maybe data was lost
>>> and you thought that it was overwritten by nicesrc but it actually never
>>> arrived, don't forget that libnice uses UDP, so it's not reliable. If you want a
>>> reliable socket, use nice_agent_new_reliable.
>>> Let me know if you did your tests with reliable mode or not.
>>>
>>> Thanks,
>>> Youness.
>>>
>>>> On 06/21/2011 10:30 AM, Daniel Lindström wrote:
>>>> Hi
>>>>
>>>> I have some problem and was hoping I could get some help from this
>>>> mailing list. I'm trying to send video from A to B with libnice and
>>>> gstreamer. The scenario not working for me is when A and B are on the
>>>> same computer, so the host candidates are used. If I do not set the
>>>> relay server (nice_agent_set_relay_info) everything works fine and it
>>>> uses the host candidate. If I do set the relay server it still uses
>>>> the host candidate as intended, but something goes wrong between
>>>> libnice and nicesrc, or nicesrc and rtpjpegpayload in the gstreamer
>>>> pipeline.
>>>>
>>>> What happends seems to be the following scenario:
>>>>
>>>> gst_nice_src_create is called and it calls g_main_loop_run to wait for a buffer
>>>> gst_nice_src_read_callback is called from libnice with a buffer which
>>>> is saved to the outbuf of the nicesrc. When done it calls
>>>> g_main_loop_quit.
>>>>
>>>> Now I would expect gst_nice_src_create to continue the execution, but
>>>> instead gst_nice_src_read_callback is called again and the allocated
>>>> outbuf is overwritten.
>>>>
>>>> For some reason it also works if the frame is small enough to fit in
>>>> one MTU (by coding it really small or raising the MTU on rtpjpegpay)..
>>>> However, I don't think there is any problem in the payload packitizer
>>>> depackitizer since the fact that it does not matter if I use any
>>>> other kind of payload, and it does work if I do net set the relay
>>>> information.
>>>>
>>>> Can it be that I have misunderstood how some component should be used,
>>>> or is there a bug somewhere? I'm thankful for all help.
>>>>
>>>> Regards,
>>>>
>>>> - Daniel
>> _______________________________________________
>> Nice mailing list
>> Nice at lists.freedesktop.org
>> http://lists.freedesktop.org/mailman/listinfo/nice
>
>
>
> _______________________________________________
> Nice mailing list
> Nice at lists.freedesktop.org
> http://lists.freedesktop.org/mailman/listinfo/nice
>
>