Module: wine Branch: master Commit: a9b87a8216ba62ceee7202fa51ce3644de6dadfc URL: https://source.winehq.org/git/wine.git/?a=commit;h=a9b87a8216ba62ceee7202fa5...
Author: Zebediah Figura z.figura12@gmail.com Date: Sat Oct 5 19:18:49 2019 -0500
strmbase: Introduce a helper to trace reference time.
Signed-off-by: Zebediah Figura z.figura12@gmail.com Signed-off-by: Alexandre Julliard julliard@winehq.org
---
dlls/strmbase/filter.c | 2 +- dlls/strmbase/pin.c | 6 ++++-- dlls/strmbase/pospass.c | 6 +++--- dlls/strmbase/qualitycontrol.c | 32 ++++++++++++++------------------ dlls/strmbase/renderer.c | 3 ++- dlls/strmbase/strmbase_private.h | 18 ++++++++++++++++++ dlls/strmbase/transform.c | 5 +++-- 7 files changed, 45 insertions(+), 27 deletions(-)
diff --git a/dlls/strmbase/filter.c b/dlls/strmbase/filter.c index 2de0a78f7a..c9d15e31c7 100644 --- a/dlls/strmbase/filter.c +++ b/dlls/strmbase/filter.c @@ -153,7 +153,7 @@ HRESULT WINAPI BaseFilterImpl_Run(IBaseFilter *iface, REFERENCE_TIME start) { struct strmbase_filter *filter = impl_from_IBaseFilter(iface);
- TRACE("iface %p, start %s.\n", iface, wine_dbgstr_longlong(start)); + TRACE("iface %p, start %s.\n", iface, debugstr_time(start));
EnterCriticalSection(&filter->csFilter); filter->state = State_Running; diff --git a/dlls/strmbase/pin.c b/dlls/strmbase/pin.c index cc7db119fa..42b150be67 100644 --- a/dlls/strmbase/pin.c +++ b/dlls/strmbase/pin.c @@ -346,7 +346,8 @@ HRESULT WINAPI BasePinImpl_NewSegment(IPin * iface, REFERENCE_TIME tStart, REFER { struct strmbase_pin *This = impl_from_IPin(iface);
- TRACE("(%p)->(%s, %s, %e)\n", This, wine_dbgstr_longlong(tStart), wine_dbgstr_longlong(tStop), dRate); + TRACE("iface %p, start %s, stop %s, rate %.16e.\n", + iface, debugstr_time(tStart), debugstr_time(tStop), dRate);
This->tStart = tStart; This->tStop = tStop; @@ -858,7 +859,8 @@ HRESULT WINAPI BaseInputPinImpl_NewSegment(IPin * iface, REFERENCE_TIME tStart, BaseInputPin *This = impl_BaseInputPin_from_IPin(iface); newsegmentargs args;
- TRACE("(%p)->(%s, %s, %e)\n", This, wine_dbgstr_longlong(tStart), wine_dbgstr_longlong(tStop), dRate); + TRACE("iface %p, start %s, stop %s, rate %.16e.\n", + iface, debugstr_time(tStart), debugstr_time(tStop), dRate);
args.tStart = This->pin.tStart = tStart; args.tStop = This->pin.tStop = tStop; diff --git a/dlls/strmbase/pospass.c b/dlls/strmbase/pospass.c index 2c5c274bba..148d4fae3c 100644 --- a/dlls/strmbase/pospass.c +++ b/dlls/strmbase/pospass.c @@ -743,7 +743,7 @@ static HRESULT WINAPI MediaPositionPassThru_put_CurrentPosition(IMediaPosition * IMediaPosition *pos; HRESULT hr;
- TRACE("(%s)\n", wine_dbgstr_longlong(llTime)); + TRACE("iface %p, time %.16e.\n", iface, llTime);
hr = get_connected(This, &IID_IMediaPosition, (LPVOID*)&pos); if (SUCCEEDED(hr)) { @@ -797,7 +797,7 @@ static HRESULT WINAPI MediaPositionPassThru_put_StopTime(IMediaPosition *iface, IMediaPosition *pos; HRESULT hr;
- TRACE("(%s)\n", wine_dbgstr_longlong(llTime)); + TRACE("iface %p, time %.16e.\n", iface, llTime);
hr = get_connected(This, &IID_IMediaPosition, (LPVOID*)&pos); if (SUCCEEDED(hr)) { @@ -833,7 +833,7 @@ static HRESULT WINAPI MediaPositionPassThru_put_PrerollTime(IMediaPosition *ifac IMediaPosition *pos; HRESULT hr;
- TRACE("(%s)\n", wine_dbgstr_longlong(llTime)); + TRACE("iface %p, time %.16e.\n", iface, llTime);
hr = get_connected(This, &IID_IMediaPosition, (LPVOID*)&pos); if (SUCCEEDED(hr)) { diff --git a/dlls/strmbase/qualitycontrol.c b/dlls/strmbase/qualitycontrol.c index 139c4dfe86..b3e93b7baa 100644 --- a/dlls/strmbase/qualitycontrol.c +++ b/dlls/strmbase/qualitycontrol.c @@ -27,9 +27,6 @@
WINE_DEFAULT_DEBUG_CHANNEL(strmbase_qc);
-#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; @@ -80,9 +77,8 @@ HRESULT WINAPI QualityControlImpl_Notify(IQualityControl *iface, IBaseFilter *se QualityControlImpl *This = impl_from_IQualityControl(iface); HRESULT hr = S_FALSE;
- TRACE("%p %p { 0x%x %u " XTIME_FMT " " XTIME_FMT " }\n", - This, sender, qm.Type, qm.Proportion, - XTIME(qm.Late), XTIME(qm.TimeStamp)); + TRACE("iface %p, sender %p, type %#x, proportion %u, late %s, timestamp %s.\n", + iface, sender, qm.Type, qm.Proportion, debugstr_time(qm.Late), debugstr_time(qm.TimeStamp));
if (This->tonotify) return IQualityControl_Notify(This->tonotify, This->self, qm); @@ -126,7 +122,6 @@ HRESULT WINAPI QualityControlImpl_SetSink(IQualityControl *iface, IQualityContro
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; @@ -147,8 +142,8 @@ 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)); + TRACE("jitter %s, start %s, stop %s.\n", debugstr_time(jitter), + debugstr_time(start), debugstr_time(stop));
/* we can add a valid stop time */ if (stop >= start) @@ -217,12 +212,12 @@ void QualityControlRender_DoQOS(QualityControlImpl *priv) pt = priv->avg_pt; }
- 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("start %s, entered %s, left %s, pt %s, duration %s, jitter %s.\n", + debugstr_time(start), debugstr_time(entered), debugstr_time(left), + debugstr_time(pt), debugstr_time(duration), debugstr_time(jitter));
- TRACE("avg_duration: " XTIME_FMT ", avg_pt: " XTIME_FMT ", avg_rate: %g\n", - XTIME(priv->avg_duration), XTIME(priv->avg_pt), priv->avg_rate); + TRACE("average duration %s, average pt %s, average rate %.16e.\n", + debugstr_time(priv->avg_duration), debugstr_time(priv->avg_pt), priv->avg_rate);
/* collect running averages. for first observations, we copy the * values */ @@ -274,7 +269,7 @@ void QualityControlRender_DoQOS(QualityControlImpl *priv) q.Proportion = 5000; q.Late = priv->current_jitter; q.TimeStamp = priv->current_rstart; - TRACE("Late: %i from %i, rate: %g\n", (int)(q.Late/10000), (int)(q.TimeStamp/10000), 1./priv->avg_rate); + TRACE("Late: %s from %s, rate: %g\n", debugstr_time(q.Late), debugstr_time(q.TimeStamp), 1./priv->avg_rate); hr = IQualityControl_Notify(&priv->IQualityControl_iface, priv->self, q); priv->qos_handled = hr == S_OK; } @@ -302,8 +297,8 @@ void QualityControlRender_BeginRender(QualityControlImpl *This, REFERENCE_TIME s
/* FIXME: This isn't correct; we don't drop samples, nor should. */ This->is_dropped = QualityControlRender_IsLate(This, This->current_jitter, start, stop); - TRACE("Dropped: %i %i %i %i\n", This->is_dropped, (int)(start/10000), - (int)(stop/10000), (int)(This->current_jitter / 10000)); + TRACE("dropped %d, start %s, stop %s, jitter %s.\n", This->is_dropped, + debugstr_time(start), debugstr_time(stop), debugstr_time(This->current_jitter)); if (This->is_dropped) This->dropped++; else @@ -313,7 +308,8 @@ void QualityControlRender_BeginRender(QualityControlImpl *This, REFERENCE_TIME s return;
IReferenceClock_GetTime(This->clock, &This->start); - TRACE("at: " XTIME_FMT "\n", XTIME(This->start)); + + TRACE("Starting at %s.\n", debugstr_time(This->start)); }
void QualityControlRender_EndRender(QualityControlImpl *This) diff --git a/dlls/strmbase/renderer.c b/dlls/strmbase/renderer.c index 7d8420e73c..270a6f260f 100644 --- a/dlls/strmbase/renderer.c +++ b/dlls/strmbase/renderer.c @@ -426,7 +426,8 @@ HRESULT WINAPI BaseRendererImpl_Stop(IBaseFilter * iface) HRESULT WINAPI BaseRendererImpl_Run(IBaseFilter * iface, REFERENCE_TIME tStart) { BaseRenderer *This = impl_from_IBaseFilter(iface); - TRACE("(%p)->(%s)\n", This, wine_dbgstr_longlong(tStart)); + + TRACE("iface %p, start %s.\n", iface, debugstr_time(tStart));
EnterCriticalSection(&This->csRenderLock); This->stream_start = tStart; diff --git a/dlls/strmbase/strmbase_private.h b/dlls/strmbase/strmbase_private.h index 4dd7caa924..d0f5029765 100644 --- a/dlls/strmbase/strmbase_private.h +++ b/dlls/strmbase/strmbase_private.h @@ -32,6 +32,24 @@ #include "wine/list.h" #include "wine/strmbase.h"
+static inline const char *debugstr_time(REFERENCE_TIME time) +{ + unsigned int i = 0, j = 0; + char buffer[22], rev[22]; + + while (time || i <= 8) + { + buffer[i++] = '0' + (time % 10); + time /= 10; + if (i == 7) buffer[i++] = '.'; + } + + while (i--) rev[j++] = buffer[i]; + rev[j] = 0; + + return wine_dbg_sprintf("%s", rev); +} + /* Quality Control */ typedef struct QualityControlImpl { IQualityControl IQualityControl_iface; diff --git a/dlls/strmbase/transform.c b/dlls/strmbase/transform.c index abf5ed34b3..bd70b8a90c 100644 --- a/dlls/strmbase/transform.c +++ b/dlls/strmbase/transform.c @@ -254,7 +254,7 @@ static HRESULT WINAPI TransformFilterImpl_Run(IBaseFilter *iface, REFERENCE_TIME HRESULT hr = S_OK; TransformFilter *This = impl_from_IBaseFilter(iface);
- TRACE("(%p/%p)->(%s)\n", This, iface, wine_dbgstr_longlong(tStart)); + TRACE("iface %p, start %s.\n", iface, debugstr_time(tStart));
EnterCriticalSection(&This->csReceive); { @@ -453,7 +453,8 @@ static HRESULT WINAPI TransformFilter_InputPin_NewSegment(IPin * iface, REFERENC TransformFilter *pTransform = impl_from_sink_IPin(iface); HRESULT hr = S_OK;
- TRACE("(%p)->(%s %s %e)\n", iface, wine_dbgstr_longlong(tStart), wine_dbgstr_longlong(tStop), dRate); + TRACE("iface %p, start %s, stop %s, rate %.16e.\n", + iface, debugstr_time(tStart), debugstr_time(tStop), dRate);
EnterCriticalSection(&pTransform->filter.csFilter); if (pTransform->pFuncsTable->pfnNewSegment)