player: simplify an aspect of buffering determination

Calculate the buffering percentage in the same code which determines
whether the player is or should be buffering. In particular it can't
happen that percentage and buffering state are slightly out of sync due
to calling DEMUXER_CTRL_GET_READER_STATE and reusing it with the
previously determined buffering state.

Now it's also easier to guarantee that the buffering state is updated
properly.

Add some more verbose output as well.

(Damn I hate this code, why did I write it?)

player/command.c

@@ -1518,10 +1518,10 @@ static int mp_property_cache_buffering(void *ctx, struct m_property *prop,
                                        int action, void *arg)
 {
     MPContext *mpctx = ctx;
-    double state = get_cache_buffering_percentage(mpctx);
+    int state = get_cache_buffering_percentage(mpctx);
     if (state < 0)
         return M_PROPERTY_UNAVAILABLE;
-    return m_property_int_ro(action, arg, state * 100);
+    return m_property_int_ro(action, arg, state);
 }
 
 static int mp_property_clock(void *ctx, struct m_property *prop,

player/core.h

@@ -398,6 +398,7 @@ typedef struct MPContext {
 
     bool paused_for_cache;
     double cache_stop_time, cache_wait_time;
+    int cache_buffer;
 
     // Set after showing warning about decoding being too slow for realtime
     // playback rate. Used to avoid showing it multiple times.
@@ -515,7 +516,7 @@ char *chapter_display_name(struct MPContext *mpctx, int chapter);
 char *chapter_name(struct MPContext *mpctx, int chapter);
 double chapter_start_time(struct MPContext *mpctx, int chapter);
 int get_chapter_count(struct MPContext *mpctx);
-double get_cache_buffering_percentage(struct MPContext *mpctx);
+int get_cache_buffering_percentage(struct MPContext *mpctx);
 void execute_queued_seek(struct MPContext *mpctx);
 void run_playloop(struct MPContext *mpctx);
 void mp_idle(struct MPContext *mpctx);

player/loadfile.c

@@ -973,6 +973,7 @@ static void play_current_file(struct MPContext *mpctx)
     mpctx->last_chapter = -2;
     mpctx->paused = false;
     mpctx->paused_for_cache = false;
+    mpctx->cache_buffer = -1;
     mpctx->playing_msg_shown = false;
     mpctx->max_frames = -1;
     mpctx->video_speed = mpctx->audio_speed = opts->playback_speed;

player/playloop.c

@@ -518,6 +518,7 @@ static void handle_osd_redraw(struct MPContext *mpctx)
 
 static void handle_pause_on_low_cache(struct MPContext *mpctx)
 {
+    bool force_update = false;
     struct MPOpts *opts = mpctx->opts;
     if (!mpctx->demuxer)
         return;
@@ -529,6 +530,8 @@ static void handle_pause_on_low_cache(struct MPContext *mpctx)
     struct demux_ctrl_reader_state s = {.idle = true, .ts_duration = -1};
     demux_control(mpctx->demuxer, DEMUXER_CTRL_GET_READER_STATE, &s);
 
+    int cache_buffer = 100;
+
     if (mpctx->restart_complete && idle != -1) {
         if (mpctx->paused && mpctx->paused_for_cache) {
             if (!opts->cache_pausing || s.ts_duration >= mpctx->cache_wait_time
@@ -543,7 +546,7 @@ static void handle_pause_on_low_cache(struct MPContext *mpctx)
                 mpctx->paused_for_cache = false;
                 if (!opts->pause)
                     unpause_player(mpctx);
-                mp_notify(mpctx, MP_EVENT_CACHE_UPDATE, NULL);
+                force_update = true;
             }
             mpctx->sleeptime = MPMIN(mpctx->sleeptime, 0.2);
         } else {
@@ -553,10 +556,14 @@ static void handle_pause_on_low_cache(struct MPContext *mpctx)
                 mpctx->paused_for_cache = true;
                 opts->pause = prev_paused_user;
                 mpctx->cache_stop_time = mp_time_sec();
-                mp_notify(mpctx, MP_EVENT_CACHE_UPDATE, NULL);
+                force_update = true;
             }
         }
         mpctx->cache_wait_time = MPCLAMP(mpctx->cache_wait_time, 1, 10);
+        if (mpctx->paused_for_cache) {
+            cache_buffer =
+                100 * MPCLAMP(s.ts_duration / mpctx->cache_wait_time, 0, 0.99);
+        }
     }
 
     // Also update cache properties.
@@ -569,28 +576,36 @@ static void handle_pause_on_low_cache(struct MPContext *mpctx)
         double now = mp_time_sec();
         if (mpctx->next_cache_update <= now) {
             mpctx->next_cache_update = busy ? now + 0.25 : 0;
-            mp_notify(mpctx, MP_EVENT_CACHE_UPDATE, NULL);
+            force_update = true;
         }
         if (mpctx->next_cache_update > 0) {
             mpctx->sleeptime =
                 MPMIN(mpctx->sleeptime, mpctx->next_cache_update - now);
         }
     }
+
+    if (mpctx->cache_buffer != cache_buffer) {
+        if (mpctx->cache_buffer >= 0 &&
+            (mpctx->cache_buffer == 100) != (cache_buffer == 100))
+        {
+            if (cache_buffer < 100) {
+                MP_VERBOSE(mpctx, "Enter buffering.\n");
+            } else {
+                double t = mp_time_sec() - mpctx->cache_stop_time;
+                MP_VERBOSE(mpctx, "End buffering (waited %f secs).\n", t);
+            }
+        }
+        mpctx->cache_buffer = cache_buffer;
+        force_update = true;
+    }
+
+    if (force_update)
+        mp_notify(mpctx, MP_EVENT_CACHE_UPDATE, NULL);
 }
 
-double get_cache_buffering_percentage(struct MPContext *mpctx)
+int get_cache_buffering_percentage(struct MPContext *mpctx)
 {
-    if (mpctx->demuxer && mpctx->paused_for_cache && mpctx->cache_wait_time > 0) {
-        struct demux_ctrl_reader_state s = {.idle = true, .ts_duration = -1};
-        demux_control(mpctx->demuxer, DEMUXER_CTRL_GET_READER_STATE, &s);
-        if (s.ts_duration < 0)
-            s.ts_duration = 0;
-
-        return MPCLAMP(s.ts_duration / mpctx->cache_wait_time, 0.0, 1.0);
-    }
-    if (mpctx->demuxer && !mpctx->paused_for_cache)
-        return 1.0;
-    return -1;
+    return mpctx->demuxer ? mpctx->cache_buffer : -1;
 }
 
 static void handle_heartbeat_cmd(struct MPContext *mpctx)