What does that mean? What is the cause for this?
I can't tell you that from the logs, but the trouble actually starts slightly earlier at 09:44:37.974 (from evr.log) :
Code:
12-09-2013 09:36:32.670 [1984]Present first sample - end
12-09-2013 09:44:37.974 [1984]Dropping frame, nextSampleTime -21.31 ms, last sleep 1.50 ms, last pres -51.00 ms, paint 2.86 ms, queue count 4, SOP 176, EOP 338, RawFRRatio 1, dropped 1, drawn 24229
12-09-2013 09:44:37.979 [1984]Dropping frame, nextSampleTime -6.27 ms, last sleep 3.10 ms, last pres -56.00 ms, paint 2.86 ms, queue count 4, SOP 176, EOP 338, RawFRRatio 1, dropped 2, drawn 24229
12-09-2013 09:44:38.029 [1984]Dropping frame, nextSampleTime -16.23 ms, last sleep 0.00 ms, last pres -47.00 ms, paint 2.89 ms, queue count 3, SOP 272, EOP 435, RawFRRatio 1, dropped 3, drawn 24230
12-09-2013 09:44:38.040 [1984]Dropping frame, nextSampleTime -7.22 ms, last sleep 2.60 ms, last pres -58.00 ms, paint 2.89 ms, queue count 4, SOP 272, EOP 435, RawFRRatio 1, dropped 4, drawn 24230
12-09-2013 09:44:38.293 [1984]Dropping frame, nextSampleTime -20.84 ms, last sleep 2.09 ms, last pres -50.00 ms, paint 3.00 ms, queue count 4, SOP 176, EOP 346, RawFRRatio 1, dropped 5, drawn 24241
12-09-2013 09:44:38.299 [1984]Dropping frame, nextSampleTime -6.86 ms, last sleep 3.58 ms, last pres -56.00 ms, paint 3.00 ms, queue count 4, SOP 176, EOP 346, RawFRRatio 1, dropped 6, drawn 24241
12-09-2013 09:44:39.323 [1984]Dropping frame, nextSampleTime -869.48 ms, last sleep 1.09 ms, last pres -900.00 ms, paint 5.10 ms, queue count 4, SOP 176, EOP 464, RawFRRatio 1, dropped 7, drawn 24248
12-09-2013 09:44:39.323 [1ee8]Scheduling sample from the past (774.33 ms, last call to NotifyWorker: 0.39 ms, Queue: 4)
12-09-2013 09:44:39.325 [1984]Dropping frame, nextSampleTime -851.21 ms, last sleep 1.09 ms, last pres -901.00 ms, paint 5.10 ms, queue count 3, SOP 176, EOP 464, RawFRRatio 1, dropped 8, drawn 24248
12-09-2013 09:44:39.325 [1ee8]Scheduling sample from the past (755.96 ms, last call to NotifyWorker: 0.29 ms, Queue: 3)
12-09-2013 09:44:39.327 [1984]Dropping frame, nextSampleTime -833.21 ms, last sleep 1.09 ms, last pres -903.00 ms, paint 5.10 ms, queue count 2, SOP 176, EOP 464, RawFRRatio 1, dropped 9, drawn 24248
12-09-2013 09:44:39.327 [1ee8]Scheduling sample from the past (738.32 ms, last call to NotifyWorker: 0.33 ms, Queue: 2)
12-09-2013 09:44:39.329 [1984]Dropping frame, nextSampleTime -815.50 ms, last sleep 1.09 ms, last pres -905.00 ms, paint 5.10 ms, queue count 1, SOP 176, EOP 464, RawFRRatio 1, dropped 10, drawn 24248
12-09-2013 09:44:39.329 [1ee8]Scheduling sample from the past (720.20 ms, last call to NotifyWorker: 0.24 ms, Queue: 1)
12-09-2013 09:44:39.332 [1984]Dropping frame, nextSampleTime -798.72 ms, last sleep 1.09 ms, last pres -908.00 ms, paint 5.10 ms, queue count 0, SOP 176, EOP 464, RawFRRatio 1, dropped 11, drawn 24248
12-09-2013 09:44:39.332 [1ee8]Scheduling sample from the past (703.55 ms, last call to NotifyWorker: 0.31 ms, Queue: 0)
12-09-2013 09:44:39.334 [1ee8]Scheduling sample from the past (685.45 ms, last call to NotifyWorker: 2.22 ms, Queue: 0)
...the "Dropping frame, nextSampleTime -869.48 ms, last sleep 1.09 ms, last pres -900.00 ms" means that it hasn't rendered (presented) any video frames to the screen for 900ms, which is probably because something has blocked it for 900ms - which could be MP, the OS, video drivers, some other driver hogging the system etc etc.
All the dropped frames/late samples afterwards are because the queued up video frames are now late (relative to the render clock), so they have to be discarded to maintain A/V sync, It almost manages to do this, but it gets hit by another stall of 990ms :
Code:
12-09-2013 09:44:42.293 [1984]Dropping frame, nextSampleTime -960.67 ms, last sleep 1.50 ms, last pres -990.00 ms, paint 5.10 ms, queue count 4, SOP 177, EOP 465, RawFRRatio 1, dropped 38, drawn 24289
Last edited: