strmbase: Improve QualityControl tracing.

dlls/qcap/avimux.c

@@ -1539,7 +1539,10 @@ static HRESULT WINAPI AviMuxOut_QualityControl_Notify(IQualityControl *iface,
         IBaseFilter *pSelf, Quality q)
 {
     AviMux *This = impl_from_out_IQualityControl(iface);
-    FIXME("(%p)->(%p Quality)\n", This, pSelf);
+    FIXME("(%p)->(%p { 0x%x %u %s %s })\n", This, pSelf,
+            q.Type, q.Proportion,
+            wine_dbgstr_longlong(q.Late),
+            wine_dbgstr_longlong(q.TimeStamp));
     return E_NOTIMPL;
 }
 
@@ -2273,7 +2276,10 @@ static HRESULT WINAPI AviMuxIn_QualityControl_Notify(IQualityControl *iface,
 {
     AviMuxIn *avimuxin = AviMuxIn_from_IQualityControl(iface);
     AviMux *This = impl_from_in_IPin(&avimuxin->pin.pin.IPin_iface);
-    FIXME("(%p:%s)->(%p Quality)\n", This, debugstr_w(avimuxin->pin.pin.pinInfo.achName), pSelf);
+    FIXME("(%p:%s)->(%p { 0x%x %u %s %s })\n", This, debugstr_w(avimuxin->pin.pin.pinInfo.achName), pSelf,
+            q.Type, q.Proportion,
+            wine_dbgstr_longlong(q.Late),
+            wine_dbgstr_longlong(q.TimeStamp));
     return E_NOTIMPL;
 }
 

dlls/strmbase/qualitycontrol.c

@@ -36,8 +36,13 @@
 
 WINE_DEFAULT_DEBUG_CHANNEL(strmbase_qc);
 
-HRESULT QualityControlImpl_Create(IPin *input, IBaseFilter *self, QualityControlImpl **ppv) {
+#define XTIME_FMT "%u.%03u"
+#define XTIME(u) (int)(u/10000000), (int)((u / 10000)%1000)
+
+HRESULT QualityControlImpl_Create(IPin *input, IBaseFilter *self, QualityControlImpl **ppv)
+{
     QualityControlImpl *This;
+    TRACE("%p, %p, %p\n", input, self, ppv);
     *ppv = HeapAlloc(GetProcessHeap(),0,sizeof(QualityControlImpl));
     if (!*ppv)
         return E_OUTOFMEMORY;
@@ -46,6 +51,7 @@ HRESULT QualityControlImpl_Create(IPin *input, IBaseFilter *self, QualityControl
     This->self = self;
     This->tonotify = NULL;
     This->clock = NULL;
+    TRACE("-> %p\n", This);
     return S_OK;
 }
 
@@ -54,26 +60,36 @@ void QualityControlImpl_Destroy(QualityControlImpl *This)
     HeapFree(GetProcessHeap(),0,This);
 }
 
-HRESULT WINAPI QualityControlImpl_QueryInterface(IQualityControl *iface, REFIID riid, void **ppv) {
+HRESULT WINAPI QualityControlImpl_QueryInterface(IQualityControl *iface, REFIID riid, void **ppv)
+{
     QualityControlImpl *This = (QualityControlImpl*)iface;
     return IBaseFilter_QueryInterface(This->self, riid, ppv);
 }
 
-ULONG WINAPI QualityControlImpl_AddRef(IQualityControl *iface) {
+ULONG WINAPI QualityControlImpl_AddRef(IQualityControl *iface)
+{
     QualityControlImpl *This = (QualityControlImpl*)iface;
     return IBaseFilter_AddRef(This->self);
 }
 
-ULONG WINAPI QualityControlImpl_Release(IQualityControl *iface) {
+ULONG WINAPI QualityControlImpl_Release(IQualityControl *iface)
+{
     QualityControlImpl *This = (QualityControlImpl*)iface;
     return IBaseFilter_Release(This->self);
 }
 
-HRESULT WINAPI QualityControlImpl_Notify(IQualityControl *iface, IBaseFilter *sender, Quality qm) {
+HRESULT WINAPI QualityControlImpl_Notify(IQualityControl *iface, IBaseFilter *sender, Quality qm)
+{
     HRESULT hr = S_FALSE;
     QualityControlImpl *This = (QualityControlImpl*)iface;
+
+    TRACE("%p %p { 0x%x %u " XTIME_FMT " " XTIME_FMT " }\n",
+            This, sender, qm.Type, qm.Proportion,
+            XTIME(qm.Late), XTIME(qm.TimeStamp));
+
     if (This->tonotify)
         return IQualityControl_Notify(This->tonotify, This->self, qm);
+
     if (This->input) {
         IPin *to = NULL;
         IPin_ConnectedTo(This->input, &to);
@@ -87,11 +103,14 @@ HRESULT WINAPI QualityControlImpl_Notify(IQualityControl *iface, IBaseFilter *se
             IPin_Release(to);
         }
     }
+
     return hr;
 }
 
-HRESULT WINAPI QualityControlImpl_SetSink(IQualityControl *iface, IQualityControl *tonotify) {
+HRESULT WINAPI QualityControlImpl_SetSink(IQualityControl *iface, IQualityControl *tonotify)
+{
     QualityControlImpl *This = (QualityControlImpl*)iface;
+    TRACE("%p %p\n", This, tonotify);
     This->tonotify = tonotify;
     return S_OK;
 }
@@ -108,7 +127,9 @@ HRESULT WINAPI QualityControlImpl_SetSink(IQualityControl *iface, IQualityContro
 #define UPDATE_RUNNING_AVG_P(avg,val) DO_RUNNING_AVG(avg,val,16)
 #define UPDATE_RUNNING_AVG_N(avg,val) DO_RUNNING_AVG(avg,val,4)
 
-void QualityControlRender_Start(QualityControlImpl *This, REFERENCE_TIME tStart) {
+void QualityControlRender_Start(QualityControlImpl *This, REFERENCE_TIME tStart)
+{
+    TRACE("%p " XTIME_FMT "\n", This, XTIME(tStart));
     This->avg_render = This->last_in_time = This->last_left = This->avg_duration = This->avg_pt = -1;
     This->clockstart = tStart;
     This->avg_rate = -1.0;
@@ -118,7 +139,9 @@ void QualityControlRender_Start(QualityControlImpl *This, REFERENCE_TIME tStart)
 }
 
 
-void QualityControlRender_SetClock(QualityControlImpl *This, IReferenceClock *clock) {
+void QualityControlRender_SetClock(QualityControlImpl *This, IReferenceClock *clock)
+{
+    TRACE("%p %p\n", This, clock);
     This->clock = clock;
 }
 
@@ -127,6 +150,9 @@ static BOOL QualityControlRender_IsLate(QualityControlImpl *This, REFERENCE_TIME
 {
     REFERENCE_TIME max_lateness = 200000;
 
+    TRACE("%p " XTIME_FMT " " XTIME_FMT " " XTIME_FMT "\n",
+            This, XTIME(jitter), XTIME(start), XTIME(stop));
+
     /* we can add a valid stop time */
     if (stop >= start)
         max_lateness += stop;
@@ -148,8 +174,12 @@ static BOOL QualityControlRender_IsLate(QualityControlImpl *This, REFERENCE_TIME
     return FALSE;
 }
 
-HRESULT QualityControlRender_WaitFor(QualityControlImpl *This, IMediaSample *sample, HANDLE ev) {
+HRESULT QualityControlRender_WaitFor(QualityControlImpl *This, IMediaSample *sample, HANDLE ev)
+{
     REFERENCE_TIME start = -1, stop = -1, jitter = 0;
+
+    TRACE("%p %p %p\n", This, sample, ev);
+
     This->current_rstart = This->current_rstop = -1;
     This->current_jitter = 0;
     if (!This->clock || FAILED(IMediaSample_GetTime(sample, &start, &stop)))
@@ -189,6 +219,8 @@ void QualityControlRender_DoQOS(QualityControlImpl *priv)
     REFERENCE_TIME start, stop, jitter, pt, entered, left, duration;
     double rate;
 
+    TRACE("%p\n", priv);
+
     if (!priv->clock || priv->current_rstart < 0)
         return;
 
@@ -228,14 +260,12 @@ void QualityControlRender_DoQOS(QualityControlImpl *priv)
         pt = priv->avg_pt;
     }
 
-#define XTIME(u) (int)(u/10000000), (int)((u / 10000)%1000)
-    TRACE("start: %u.%03u, entered %u.%03u, left %u.%03u, pt: %u.%03u, "
-          "duration %u.%03u, jitter %u.%03u\n", XTIME(start), XTIME(entered),
+    TRACE("start: " XTIME_FMT ", entered " XTIME_FMT ", left " XTIME_FMT ", pt: " XTIME_FMT ", "
+          "duration " XTIME_FMT ", jitter " XTIME_FMT "\n", XTIME(start), XTIME(entered),
           XTIME(left), XTIME(pt), XTIME(duration), XTIME(jitter));
 
-    TRACE("avg_duration: %u.%03u, avg_pt: %u.%03u, avg_rate: %g\n",
+    TRACE("avg_duration: " XTIME_FMT ", avg_pt: " XTIME_FMT ", avg_rate: %g\n",
       XTIME(priv->avg_duration), XTIME(priv->avg_pt), priv->avg_rate);
-#undef XTIME
 
     /* collect running averages. for first observations, we copy the
     * values */
@@ -297,15 +327,25 @@ void QualityControlRender_DoQOS(QualityControlImpl *priv)
 }
 
 
-void QualityControlRender_BeginRender(QualityControlImpl *This) {
+void QualityControlRender_BeginRender(QualityControlImpl *This)
+{
+    TRACE("%p\n", This);
+
     This->start = -1;
+
     if (!This->clock)
         return;
+
     IReferenceClock_GetTime(This->clock, &This->start);
+    TRACE("at: " XTIME_FMT "\n", XTIME(This->start));
 }
 
-void QualityControlRender_EndRender(QualityControlImpl *This) {
+void QualityControlRender_EndRender(QualityControlImpl *This)
+{
     REFERENCE_TIME elapsed;
+
+    TRACE("%p\n", This);
+
     if (!This->clock || This->start < 0 || FAILED(IReferenceClock_GetTime(This->clock, &This->stop)))
         return;
 

dlls/winegstreamer/gstdemux.c

@@ -1664,7 +1664,10 @@ static HRESULT WINAPI GST_QualityControl_Notify(IQualityControl *iface, IBaseFil
 {
     GSTOutPin *pin = impl_from_IQualityControl(iface);
     REFERENCE_TIME late = qm.Late;
-    TRACE("(%p)->(%p, qm)\n", pin, sender);
+    TRACE("(%p)->(%p, { 0x%x %u %s %s })\n", pin, sender,
+            qm.Type, qm.Proportion,
+            wine_dbgstr_longlong(qm.Late),
+            wine_dbgstr_longlong(qm.TimeStamp));
     mark_wine_thread();
     if (qm.Late < 0 && -qm.Late > qm.TimeStamp)
         late = -qm.TimeStamp;

dlls/winegstreamer/gsttffilter.c

@@ -478,7 +478,10 @@ static HRESULT WINAPI Gstreamer_transform_QOS(TransformFilter *iface, IBaseFilte
     GstTfImpl *This = (GstTfImpl*)iface;
     REFERENCE_TIME late = qm.Late;
 
-    TRACE("%p %p qm\n", This, sender);
+    TRACE("%p %p { 0x%x %u %s %s }\n", This, sender,
+            qm.Type, qm.Proportion,
+            wine_dbgstr_longlong(qm.Late),
+            wine_dbgstr_longlong(qm.TimeStamp));
 
     mark_wine_thread();