Ticket #7285: media_mixer.diff

src/kits/media/MediaEventLooper.cpp

@@ -222 +222 @@
             // only the scheduling latency). 
 
             latency = fEventLatency + fSchedulingLatency;
-            if (fEventQueue.HasEvents() && (TimeSource()->Now() - latency) >= fEventQueue.FirstEventTime()) {
-//              printf("node %02d waiting for %12Ld that has already happened, now %12Ld\n", ID(), fEventQueue.FirstEventTime(), system_time());
+            if (fEventQueue.HasEvents()
+                && (TimeSource()->Now() + latency) >= fEventQueue.FirstEventTime()) {
+//              printf("node %02ld waiting for %12Ld that already happened, now %12Ld(%Ld)\n",
+//              ID(), fEventQueue.FirstEventTime(), TimeSource()->Now(), system_time());
                 is_realtime = false;
                 break;
             }
-            if (fRealTimeQueue.HasEvents() && (TimeSource()->RealTime() - fSchedulingLatency) >= fRealTimeQueue.FirstEventTime()) {
+            if (fRealTimeQueue.HasEvents()
+                && (TimeSource()->RealTime() + fSchedulingLatency) >= fRealTimeQueue.FirstEventTime()) {
                 latency = fSchedulingLatency;
                 is_realtime = true;
                 break;
@@ -235 +238 @@
             waituntil = B_INFINITE_TIMEOUT;
             if (fEventQueue.HasEvents()) {
                 waituntil = TimeSource()->RealTimeFor(fEventQueue.FirstEventTime(), latency);
-//              printf("node %02d waiting for %12Ld that will happen at %12Ld\n", ID(), fEventQueue.FirstEventTime(), waituntil);
+//              printf("node %02ld waiting for %12Ld that will happen at %12Ld\n",
+//                  ID(), fEventQueue.FirstEventTime(), waituntil);
                 is_realtime = false;
             }
             if (fRealTimeQueue.HasEvents()) {
@@ -265 +269 @@
             if (is_realtime)
                 lateness = TimeSource()->RealTime() - event.event_time;
             else
-                lateness = TimeSource()->RealTime() - TimeSource()->RealTimeFor(event.event_time, 0) + fEventLatency;
+                lateness =
+                    TimeSource()->RealTime() - TimeSource()->RealTimeFor(event.event_time, 0) + fEventLatency;
             DispatchEvent(&event, lateness, is_realtime);
         }
     }

src/add-ons/media/media-add-ons/mixer/AudioMixer.cpp

@@ -86 +86 @@
 #define FORMAT_USER_DATA_MAGIC_1    0xc84173bd
 #define FORMAT_USER_DATA_MAGIC_2    0x4af62b7d
 
-
 const static bigtime_t kMaxLatency = 150000;
     // 150 ms is the maximum latency we publish
 
@@ -109 +108 @@
     fInternalLatency(1),
     fDisableStop(false),
     fLastLateNotification(0)
+//  fBlockRepeatNotify(0)
 {
     BMediaNode::AddNodeKind(B_SYSTEM_MIXER);
 
@@ -302 +302 @@
 
     //PRINT(4, "buffer received at %12Ld, should arrive at %12Ld, delta %12Ld\n", TimeSource()->Now(), buffer->Header()->start_time, TimeSource()->Now() - buffer->Header()->start_time);
 
+    bigtime_t lateness =
+        TimeSource()->RealTime() + EventLatency()
+        - TimeSource()->RealTimeFor(buffer->Header()->start_time, 0);
+    if (lateness > kMaxJitter) {
+        printf("Buffer start=%Ld: received %Ld usec late at %Ld EventLatency=%Ld\n",
+            buffer->Header()->start_time, lateness, TimeSource()->Now(),
+            EventLatency());
+// I believe this is pointless here, because the relevant run mode is the source, mot the mixer!
+//      if (RunMode() == B_DROP_DATA || RunMode() == B_DECREASE_PRECISION
+//          || RunMode() == B_INCREASE_LATENCY) {
+        // Increase latency only if we didn't do it recently:
+        if (TimeSource()->Now() >= fLastLateNotification) {
+            debug_printf("mixer sending notify\n");
+
+            // Build a media_source out of the header data
+            media_source source = media_source::null;
+            source.port = buffer->Header()->source_port;
+            source.id = buffer->Header()->source;
+
+            NotifyLateProducer(source, lateness, TimeSource()->Now());
+            // Don't send another before this:
+            fLastLateNotification = buffer->Header()->start_time;
+        }
+
+        if (RunMode() == B_DROP_DATA || lateness > EventLatency()) { // Experimental limit
+            debug_printf("Mixer dropping buffer\n");
+            return;
+        }
+    }
     // to receive the buffer at the right time,
     // push it through the event looper
     media_timed_event event(buffer->Header()->start_time,
         BTimedEventQueue::B_HANDLE_BUFFER, buffer,
         BTimedEventQueue::B_RECYCLE_BUFFER);
     EventQueue()->AddEvent(event);
+
 }
 
 
 void
 AudioMixer::HandleInputBuffer(BBuffer* buffer, bigtime_t lateness)
 {
-    if (lateness > kMaxJitter) {
-        debug_printf("Received buffer %Ld usec late\n", lateness);
-        if (RunMode() == B_DROP_DATA || RunMode() == B_DECREASE_PRECISION
-            || RunMode() == B_INCREASE_LATENCY) {
-            debug_printf("sending notify\n");
-
-            // Build a media_source out of the header data
-            media_source source = media_source::null;
-            source.port = buffer->Header()->source_port;
-            source.id = buffer->Header()->source;
-
-            NotifyLateProducer(source, lateness, TimeSource()->Now());
-
-            if (RunMode() == B_DROP_DATA) {
-                debug_printf("dropping buffer\n");
-                return;
-            }
-        }
+    // Handle possible 'blackouts' in MediaEventLooper timing:
+    bigtime_t real_lateness = TimeSource()->RealTime() + fDownstreamLatency
+        - TimeSource()->RealTimeFor(buffer->Header()->start_time, 0);
+    // Increase latency only if we didn't do it recently
+    // -- because we don't want to respond to multiple reports from buffers in the queue
+    if (real_lateness > kMaxJitter && TimeSource()->Now() >= fLastLateNotification) {
+        fInternalLatency += real_lateness;
+        SetEventLatency(fDownstreamLatency + fInternalLatency);
+        printf("Mixer: perftime %Ld actual lateness = %Ld reset event latency=%Ld\n",
+            buffer->Header()->start_time, real_lateness,  EventLatency());
+        PublishEventLatencyChange();
+        fLastLateNotification = buffer->Header()->start_time;
     }
 
     //  printf("Received buffer with lateness %Ld\n", lateness);
@@ -998 +1022 @@
 
     ERROR("AudioMixer::LateNoticeReceived, %Ld too late at %Ld\n", howMuch,
         performanceTime);
+    printf("AudioMixer::LateNoticeReceived, %Ld too late at %Ld\n", howMuch,
+        performanceTime);
 
     if (what == fCore->Output()->MediaOutput().source
         && RunMode() == B_INCREASE_LATENCY) {
-        // We need to ignore subsequent notices whose performance time
-        // lies before the performance time of the last notification
+        // We need to ignore subsequent notices whose arrival time here
+        // lies within the latency, because queued-up buffers will all be 'late'
         if (performanceTime < fLastLateNotification)
             return;
 
         fInternalLatency += howMuch;
 
         // At some point a too large latency can get annoying
+        // (actually more than annoying, as there won't be enough buffers long before this!)
         if (fInternalLatency > kMaxLatency)
             fInternalLatency = kMaxLatency;
 
-        fLastLateNotification = TimeSource()->Now();
+        fLastLateNotification = TimeSource()->Now() + EventLatency();
 
         debug_printf("AudioMixer: increasing internal latency to %Ld usec\n", fInternalLatency);
+        printf("AudioMixer: increasing internal latency to %Ld usec\n", fInternalLatency);
         SetEventLatency(fDownstreamLatency + fInternalLatency);
 
         PublishEventLatencyChange();
@@ -1066 +1094 @@
     switch (event->type) {
         case BTimedEventQueue::B_HANDLE_BUFFER:
         {
+//          printf("Mixer HandleInputBuffer at %Ld\n", system_time());
             HandleInputBuffer((BBuffer *)event->pointer, lateness);
             ((BBuffer *)event->pointer)->Recycle();
             break;