Index: libs/libmythtv/avformatdecoder.cpp =================================================================== --- libs/libmythtv/avformatdecoder.cpp (revision 8602) +++ libs/libmythtv/avformatdecoder.cpp (working copy) @@ -1563,7 +1605,7 @@ { long long startpos = pkt->pos; - VERBOSE(VB_PLAYBACK, LOC + + VERBOSE(VB_PLAYBACK|VB_TIMESTAMP, LOC + QString("positionMap[ %1 ] == %2.") .arg(prevgoppos / keyframedist) .arg((int)startpos)); @@ -2474,6 +2535,10 @@ (curstream->codec->channels * 2) / curstream->codec->sample_rate); + VERBOSE(VB_PLAYBACK|VB_TIMESTAMP, LOC + QString("audio timecode %1 %2 %3 %4") + .arg(pkt->pts) + .arg(pkt->dts) + .arg(temppts).arg(lastapts)); GetNVP()->AddAudioData((char *)audioSamples, data_size, temppts); @@ -2565,6 +2630,10 @@ else temppts = lastvpts; + VERBOSE(VB_PLAYBACK|VB_TIMESTAMP, LOC + QString("video timecode %1 %2 %3 %4") + .arg(pkt->pts) + .arg(pkt->dts) + .arg(temppts).arg(lastvpts)); /* XXX: Broken. if (mpa_pic.qscale_table != NULL && mpa_pic.qstride > 0 && context->height == picframe->height) Index: libs/libmythtv/NuppelVideoPlayer.cpp =================================================================== --- libs/libmythtv/NuppelVideoPlayer.cpp (revision 8602) +++ libs/libmythtv/NuppelVideoPlayer.cpp (working copy) @@ -1413,9 +1414,18 @@ warpfactor_avg = (warpfactor + (warpfactor_avg * (WARPAVLEN - 1))) / WARPAVLEN; - //cerr << "Divergence: " << divergence << " Rate: " << rate - //<< " Warpfactor: " << warpfactor << " warpfactor_avg: " - //<< warpfactor_avg << endl; +#if 1 + VERBOSE(VB_PLAYBACK|VB_TIMESTAMP, QString("A/V " + "Divergence: %1 " + " Rate: %2" + " Warpfactor: %3" + " warpfactor_avg: %4") + .arg(divergence) + .arg(rate) + .arg(warpfactor) + .arg(warpfactor_avg) + ); +#endif return divergence; } @@ -1496,7 +1506,7 @@ if (diverge < -MAXDIVERGE) { // If video is way ahead of audio, adjust for it... - QString dbg = QString("Video is %1 frames ahead of audio, ") + QString dbg = QString("Audio is %1 frames ahead of video, ") .arg(-diverge); // Reset A/V Sync @@ -1511,12 +1521,12 @@ // decoding; display the frame, but don't wait for A/V Sync. videoOutput->PrepareFrame(buffer, ps); videoOutput->Show(m_scan); - VERBOSE(VB_PLAYBACK, LOC + dbg + "skipping A/V wait."); + VERBOSE(VB_PLAYBACK|VB_TIMESTAMP, LOC + dbg + "skipping A/V wait."); } else { // If we are using software decoding, skip this frame altogether. - VERBOSE(VB_PLAYBACK, LOC + dbg + "dropping frame."); + VERBOSE(VB_PLAYBACK|VB_TIMESTAMP, LOC + dbg + "dropping frame."); } } else if (!using_null_videoout) @@ -1557,10 +1569,17 @@ if (output_jmeter && output_jmeter->RecordCycleTime()) { - //cerr << "avsync_delay: " << avsync_delay / 1000 - // << ", avsync_avg: " << avsync_avg / 1000 - // << ", warpfactor: " << warpfactor - // << ", warpfactor_avg: " << warpfactor_avg << endl; +#if 1 + VERBOSE(VB_PLAYBACK|VB_TIMESTAMP, QString("A/V " + "avsync_delay: %1" + ", avsync_avg: %2" + ", warpfactor: %3" + ", warpfactor_avg: %4") + .arg(avsync_delay / 1000) + .arg(avsync_avg / 1000) + .arg(warpfactor) + .arg(warpfactor_avg)); +#endif } videosync->AdvanceTrigger(); @@ -1571,18 +1590,18 @@ // If audio is way ahead of video, adjust for it... // by cutting the frame rate in half for the length of this frame avsync_adjustment = frame_interval; lastsync = true; - VERBOSE(VB_PLAYBACK, LOC + - QString("Audio is %1 frames ahead of video,\n" + VERBOSE(VB_PLAYBACK|VB_TIMESTAMP, LOC + + QString("Video is %1 frames ahead of audio,\n" "\t\t\tdoubling video frame interval.").arg(diverge)); } if (audioOutput && normal_speed) { long long currentaudiotime = audioOutput->GetAudiotime(); #if 0 - VERBOSE(VB_PLAYBACK, QString( + VERBOSE(VB_PLAYBACK|VB_TIMESTAMP, QString( "A/V timecodes audio %1 video %2 frameinterval %3 " "avdel %4 avg %5 tcoffset %6") .arg(currentaudiotime) Index: libs/libmyth/audiooutputbase.cpp =================================================================== --- libs/libmyth/audiooutputbase.cpp (revision 8602) +++ libs/libmyth/audiooutputbase.cpp (working copy) @@ -452,13 +1007,18 @@ // NOTE: This function is not threadsafe int afree = audiofree(true); int len = samples * audio_bytes_per_sample; // Check we have enough space to write the data if (need_resampler && src_ctx) len = (int)ceilf(float(len) * src_data.src_ratio); if ((len > afree) && !blocking) + { + VERBOSE(VB_AUDIO|VB_TIMESTAMP, QString("AddSamples FAILED bytes=%1, used=%2, free=%3, timecode=%4") + .arg(len) + .arg(AUDBUFSIZE-afree).arg(afree).arg(LONGLONGCONVERT timecode)); return false; // would overflow + } // resample input if necessary if (need_resampler && src_ctx) @@ -492,7 +1052,7 @@ { if (blocking) { - VERBOSE(VB_AUDIO, "Waiting for free space"); + VERBOSE(VB_AUDIO|VB_TIMESTAMP, "Waiting for free space"); // wait for more space pthread_cond_wait(&audio_bufsig, &audio_buflock); afree = audiofree(false); @@ -533,7 +1096,7 @@ int afree = audiofree(false); - VERBOSE(VB_AUDIO, QString("_AddSamples bytes=%1, used=%2, free=%3, timecode=%4") + VERBOSE(VB_AUDIO|VB_TIMESTAMP, QString("_AddSamples bytes=%1, used=%2, free=%3, timecode=%4") .arg(samples * audio_bytes_per_sample) .arg(AUDBUFSIZE-afree).arg(afree).arg((long)timecode)); @@ -687,7 +1325,7 @@ space_on_soundcard = getSpaceOnSoundcard(); if (space_on_soundcard != last_space_on_soundcard) { - VERBOSE(VB_AUDIO, QString("%1 bytes free on soundcard") + VERBOSE(VB_AUDIO|VB_TIMESTAMP, QString("%1 bytes free on soundcard") .arg(space_on_soundcard)); last_space_on_soundcard = space_on_soundcard; } @@ -700,7 +1338,7 @@ WriteAudio(zeros, fragment_size); } else { // this should never happen now -dag - VERBOSE(VB_AUDIO, + VERBOSE(VB_AUDIO|VB_TIMESTAMP, QString("waiting for space on soundcard " "to write zeros: have %1 need %2") .arg(space_on_soundcard).arg(fragment_size)); @@ -736,12 +1374,12 @@ if (fragment_size > audiolen(true)) { if (audiolen(true) > 0) // only log if we're sending some audio - VERBOSE(VB_AUDIO, + VERBOSE(VB_AUDIO|VB_TIMESTAMP, QString("audio waiting for buffer to fill: " "have %1 want %2") .arg(audiolen(true)).arg(fragment_size)); - VERBOSE(VB_AUDIO, "Broadcasting free space avail"); + //VERBOSE(VB_AUDIO|VB_TIMESTAMP, "Broadcasting free space avail"); pthread_mutex_lock(&audio_buflock); pthread_cond_broadcast(&audio_bufsig); pthread_mutex_unlock(&audio_buflock); @@ -755,7 +1393,7 @@ if (fragment_size > space_on_soundcard) { if (space_on_soundcard != last_space_on_soundcard) { - VERBOSE(VB_AUDIO, + VERBOSE(VB_AUDIO|VB_TIMESTAMP, QString("audio waiting for space on soundcard: " "have %1 need %2") .arg(space_on_soundcard).arg(fragment_size)); @@ -817,7 +1455,7 @@ /* update raud */ raud = (raud + fragment_size) % AUDBUFSIZE; - VERBOSE(VB_AUDIO, "Broadcasting free space avail"); + //VERBOSE(VB_AUDIO|VB_TIMESTAMP, "Broadcasting free space avail"); pthread_cond_broadcast(&audio_bufsig); written_size = fragment_size; Index: libs/libmyth/audiooutputalsa.cpp =================================================================== --- libs/libmyth/audiooutputalsa.cpp (revision 8602) +++ libs/libmyth/audiooutputalsa.cpp (working copy) @@ -148,7 +150,7 @@ tmpbuf = aubuf; - VERBOSE(VB_AUDIO, QString("WriteAudio: Preparing %1 bytes (%2 frames)") + VERBOSE(VB_AUDIO|VB_TIMESTAMP, QString("WriteAudio: Preparing %1 bytes (%2 frames)") .arg(size).arg(frames)); while (frames > 0) Index: programs/mythcommflag/main.cpp =================================================================== --- programs/mythcommflag/main.cpp (revision 8602) +++ programs/mythcommflag/main.cpp (working copy) @@ -848,10 +848,10 @@ time_now = time(NULL); if (!quiet) { - VERBOSE(VB_ALL, QString("%1 version: %2 www.mythtv.org") + VERBOSE(VB_IMPORTANT, QString("%1 version: %2 www.mythtv.org") .arg(binname).arg(MYTH_BINARY_VERSION)); - VERBOSE(VB_ALL, QString("Enabled verbose msgs: %1").arg(verboseString)); + VERBOSE(VB_IMPORTANT, QString("Enabled verbose msgs: %1").arg(verboseString)); cerr << "\nMythTV Commercial Flagger, started at " << ctime(&time_now);