After an evaluation, GNOME has moved from Bugzilla to GitLab. Learn more about GitLab.
No new issues can be reported in GNOME Bugzilla anymore.
To report an issue in a GNOME project, go to GNOME GitLab.
Do not go to GNOME Gitlab for: Bluefish, Doxygen, GnuCash, GStreamer, java-gnome, LDTP, NetworkManager, Tomboy.
Bug 627942 - [queue2] wrong percent-filled estimation during on-disk buffering
[queue2] wrong percent-filled estimation during on-disk buffering
Status: RESOLVED NOTABUG
Product: GStreamer
Classification: Platform
Component: gstreamer (core)
git master
Other Linux
: Normal normal
: git master
Assigned To: GStreamer Maintainers
GStreamer Maintainers
Depends on:
Blocks:
 
 
Reported: 2010-08-25 13:14 UTC by Philippe Normand
Modified: 2010-08-25 20:31 UTC
See Also:
GNOME target: ---
GNOME version: ---


Attachments
queue2:5 logs (204.90 KB, application/x-bzip)
2010-08-25 13:49 UTC, Philippe Normand
  Details
queue2: fix percent calculation in case of on-disk buffering (2.00 KB, patch)
2010-08-25 15:52 UTC, Philippe Normand
none Details | Review

Description Philippe Normand 2010-08-25 13:14:45 UTC
It seems that in update_buffering() and if rate estimation is enabled the rate_time is wrongly calculated in GET_PERCENT() and percent value becomes wrong too ;)

To reproduce:

gst-launch-0.10 playbin2 flags=0x97 uri="http://chaos.troll.no/~tavestbo/webkit/mediaelement/bunny/big_buck_bunny_480p_surround-fix.avi"


0:00:04.048325005 30878  0x8ad4838 INFO                  queue2 gstqueue2.c:1720:gst_queue2_create_write:<queue20> cur_level.bytes 1025388 (max 0)
0:00:04.048438008 30878  0x8a867c8 DEBUG                 queue2 gstqueue2.c:1015:gst_queue2_have_data:<queue20> looking for offset 220056366, len 8
0:00:04.048471532 30878  0x8a867c8 DEBUG                 queue2 gstqueue2.c:536:find_range:<queue20> no range for 220056366
0:00:04.048498980 30878  0x8a867c8 INFO                  queue2 gstqueue2.c:1042:gst_queue2_have_data:<queue20> not found in any range
0:00:04.048525170 30878  0x8a867c8 DEBUG                 queue2 gstqueue2.c:1205:gst_queue2_create_read:<queue20> waiting for add
0:00:04.050303818 30878  0x8ad4838 DEBUG                 queue2 gstqueue2.c:761:apply_buffer:<queue20> last_stop updated to 0:00:00.000000000
0:00:04.050359552 30878  0x8ad4838 DEBUG                 queue2 gstqueue2.c:685:update_time_level:<queue20> sink 0:00:00.000000000, src 0:00:00.000000000
0:00:04.050393564 30878  0x8ad4838 DEBUG                 queue2 gstqueue2.c:924:update_in_rates:<queue20> rates: in 239767.595526, time 0:00:04.276591245
0:00:04.050428904 30878  0x8ad4838 DEBUG                 queue2 gstqueue2.c:1507:gst_queue2_create_write:<queue20> Writing 1440 bytes to 1033920
0:00:04.050477514 30878  0x8ad4838 INFO                  queue2 gstqueue2.c:1635:gst_queue2_create_write:<queue20> writing 1440 bytes to range [0-1033920] (rb wpos 0)
0:00:04.050508174 30878  0x8ad4838 INFO                  queue2 gstqueue2.c:1705:gst_queue2_create_write:<queue20> wrote 1440 bytes to 1033920 (0 bytes remaining to write)

The video window doesn't show up. Using a normal buffering strategy works.
Comment 1 Philippe Normand 2010-08-25 13:49:26 UTC
Created attachment 168733 [details]
queue2:5 logs
Comment 2 Philippe Normand 2010-08-25 14:06:03 UTC
These are 2 different issues:

- avi and on-disk buffering don't seem to play well together (it works with mp4/h264)
- percent value is messed up in all cases for on-disk buffering
Comment 3 Philippe Normand 2010-08-25 14:33:28 UTC
in the case where the queue2 doesn't use a ring-buffer GET_PERCENT(bytes, 0) is:

queue->cur_level.bytes * 100 / queue->max_level.bytes

example:

2766246 * 100 / 2097152 = 131 :)

So the question is, why would  queue->cur_level.bytes be superior to queue->max_level.bytes ?
Comment 4 Philippe Normand 2010-08-25 15:18:23 UTC
queue->max_level.bytes doesn't seem relevant in on-disk-buffering use-case, right?

I think in that case the percent value should be calculated depending on the duration (in BYTES), if it is known. So something like:

queue->cur_level.bytes * 100 / duration_in_bytes

Opinions? Am I totally on the wrong track? ;)
Comment 5 Philippe Normand 2010-08-25 15:52:36 UTC
Created attachment 168748 [details] [review]
queue2: fix percent calculation in case of on-disk buffering

If downloading to temp_file is enabled the percent value representing
the fill status of the queue should be relative to the media duration,
if it is known.

Fixes bug 627942.

I had some success with this patch ^^
Comment 6 Wim Taymans 2010-08-25 19:44:06 UTC
(In reply to comment #3)
> in the case where the queue2 doesn't use a ring-buffer GET_PERCENT(bytes, 0)
> is:
> 
> queue->cur_level.bytes * 100 / queue->max_level.bytes
> 
> example:
> 
> 2766246 * 100 / 2097152 = 131 :)
> 
> So the question is, why would  queue->cur_level.bytes be superior to
> queue->max_level.bytes ?

AFAIK, this can happen when the cur_level < max_level before the new buffer arrives (and so it can go into the queue) but becomes > max_level after pushing (and then the queue percent > 100, which is possible).
Comment 7 Wim Taymans 2010-08-25 19:48:00 UTC
(In reply to comment #4)
> queue->max_level.bytes doesn't seem relevant in on-disk-buffering use-case,
> right?


It does. It is used to calculate how much percent of max_level bytes is buffered.

> 
> I think in that case the percent value should be calculated depending on the
> duration (in BYTES), if it is known. So something like:
> 
> queue->cur_level.bytes * 100 / duration_in_bytes
> 
> Opinions? Am I totally on the wrong track? ;)

Yeah, that's not right. The buffer filled percent is the amount of bytes in it * 100 / max_level. Maybe you are confused about the fact that the level can be 100% when the file is only partially downloaded. The percentage is always based on the filled level of the queue relative to max_level.bytes/time etc.

What exactly do you see that you think is wrong?
Comment 8 Philippe Normand 2010-08-25 19:52:33 UTC
Right, looks like I got confused when reading the log. I didn't know it made sense to have percent > 100 ;)
Comment 9 Wim Taymans 2010-08-25 20:14:00 UTC
(In reply to comment #8)
> Right, looks like I got confused when reading the log. I didn't know it made
> sense to have percent > 100 ;)

See, the percent is for doing buffering between a high/low watermark, the high watermark is expressed with max_level (which is usually a lot less than the total size of the media) and high-percent. 

The method of operation is that you can start playback as soon as you have max_level bytes buffered in the queue (at which point the percent is 100%). For normal memory caching, this max_level is then also the point where the input is blocked and the queue is considered full (nothing goes in anymore until something has gone out); this all to not exhaust main memory. 

For on-disk caching, there is no reason to block the input because we can just write to disk as much as we want and thus the percent and max_level go past 100% easily.
Comment 10 Philippe Normand 2010-08-25 20:31:39 UTC
Thanks Wim for the explanation. It all makes sense, it's just that this "percent" value going past 100% in the logs made me wonder about a bug ;)

Maybe in the case of on-disk caching if could be named differently or just not logged. Anyway, moving on :)