一、前言

在使用VS学习VLC源码时，可以打断点分析变量数据，跟踪代码流程，方便我们理解源码。但是在定位音视频卡顿、延时等疑难问题时，这一招就不管用了，因为打上断点就会导致实时计算的pts值不准确，影响复现真实场景。所以音视频卡顿、延时类问题，更需要我们抓包、打印每一帧数据的Timestamp、pts及clock转换中的关键数据。这里引入一个简单的方法：增加收流、解码、渲染一条线上的时间戳，便于分析。

二、时间戳日志打印具体方法

1、将live/liveMedia/include/RTPSource.hh中的fCurPacketRTPTimestamp变量修改为pubilc类型

class RTPSource: public FramedSource {
public:
    <span style="color:#3333FF;">u_int32_t fCurPacketRTPTimestamp;</span>

  static Boolean lookupByName(UsageEnvironment& env, char const* sourceName,
			      RTPSource*& resultSource);

2、在live\liveMedia\FramedSource.cpp中包含RTPSource.hh头文件，修改FramedSource::afterGetting函数，将裸码流中的Timestamp传递出去

void FramedSource::afterGetting(FramedSource* source) {
  source->fIsCurrentlyAwaitingData = False;
      // indicates that we can be read again
      // Note that this needs to be done here, in case the "fAfterFunc"
      // called below tries to read another frame (which it usually will)
  <span style="color:#3333FF;">// m by yagerfgcs begin 用时间戳fCurPacketRTPTimestamp替换fDurationInMicroseconds，传递到live555::StreamRead函数中
  if (source->fAfterGettingFunc != NULL) {
    (*(source->fAfterGettingFunc))(source->fAfterGettingClientData,
				   source->fFrameSize, source->fNumTruncatedBytes,
				   source->fPresentationTime,
                   ((RTPSource*)source)->fCurPacketRTPTimestamp);
  }
  
  /*if (source->fAfterGettingFunc != NULL) {
      (*(source->fAfterGettingFunc))(source->fAfterGettingClientData,
      source->fFrameSize, source->fNumTruncatedBytes,
      source->fPresentationTime,
      source->fDurationInMicroseconds);
      }*/
  // end</span>

}

3、在modules\access\live555.cpp中StreamRead函数中借用p_block->i_dts存储Timestamp。传递出去

    /* Update our global npt value */
    if( tk->f_npt > 0 &&
        ( tk->f_npt < p_sys->f_npt_length || p_sys->f_npt_length <= 0 ) )
        p_sys->f_npt = tk->f_npt;

    if( p_block )
    {
        if( !tk->b_muxed && !tk->b_asf )
        {
            if( i_pts != tk->i_pts )
                p_block->i_pts = VLC_TS_0 + i_pts;

            /*FIXME: for h264 you should check that packetization-mode=1 in sdp-file */
            p_block->i_dts = ( tk->fmt.i_codec == VLC_CODEC_MPGV ) ? VLC_TS_INVALID : (VLC_TS_0 + i_pts);

            <span style="color:#3333FF;">// yagerfgcs for 借dts值赋值给timestamp;
            p_block->i_dts = duration;</span>
        }

        if( tk->b_muxed )
            stream_DemuxSend( tk->p_out_muxed, p_block );
        else if( tk->b_asf )
            stream_DemuxSend( p_sys->p_out_asf, p_block );
        else
            es_out_Send(p_demux->out, tk->p_es, p_block);
    }

4、在src\input\es_out.c中EsOutSend函数中可以分别打印音视频码流时间戳timestamp、显示时间戳pts。也可以在此处屏蔽音频或视频的输入，避免送入到解码模块。

static int EsOutSend( es_out_t *out, es_out_id_t *es, block_t *p_block )
{
    es_out_sys_t   *p_sys = out->p_sys;
    input_thread_t *p_input = p_sys->p_input;

    if( libvlc_stats( p_input ) )
    {
        uint64_t i_total;

        vlc_mutex_lock( &p_input->p->counters.counters_lock );
        stats_Update( p_input->p->counters.p_demux_read,
                      p_block->i_buffer, &i_total );
        stats_Update( p_input->p->counters.p_demux_bitrate, i_total, NULL );

        /* Update number of corrupted data packats */
        if( p_block->i_flags & BLOCK_FLAG_CORRUPTED )
        {
            stats_Update( p_input->p->counters.p_demux_corrupted, 1, NULL );
        }
        /* Update number of discontinuities */
        if( p_block->i_flags & BLOCK_FLAG_DISCONTINUITY )
        {
            stats_Update( p_input->p->counters.p_demux_discontinuity, 1, NULL );
        }
        vlc_mutex_unlock( &p_input->p->counters.counters_lock );
    }

    vlc_mutex_lock( &p_sys->lock );

    /* Mark preroll blocks */
    if( p_sys->i_preroll_end >= 0 )
    {
        int64_t i_date = p_block->i_pts;
        if( p_block->i_pts <= VLC_TS_INVALID )
            i_date = p_block->i_dts;

        if( i_date < p_sys->i_preroll_end )
            p_block->i_flags |= BLOCK_FLAG_PREROLL;
    }

    if( !es->p_dec )
    {
        block_Release( p_block );
        vlc_mutex_unlock( &p_sys->lock );
        return VLC_SUCCESS;
    }

    /* Check for sout mode */
    if( p_input->p->p_sout )
    {
        /* FIXME review this, proper lock may be missing */
        if( p_input->p->p_sout->i_out_pace_nocontrol > 0 &&
            p_input->p->b_out_pace_control )
        {
            msg_Dbg( p_input, "switching to sync mode" );
            p_input->p->b_out_pace_control = false;
        }
        else if( p_input->p->p_sout->i_out_pace_nocontrol <= 0 &&
                 !p_input->p->b_out_pace_control )
        {
            msg_Dbg( p_input, "switching to async mode" );
            p_input->p->b_out_pace_control = true;
        }
    }
<span style="color:#FF0000;">
   <span style="color:#3333FF;"> // add by yagerfgcs for log 音视频打印不同日志，便于定位
    if (es->p_dec->fmt_out.i_cat == VIDEO_ES)
    {
        msg_Dbg(p_input, "[TS es_out::EsOutSend] video pts[%llu] timestamp[%llu]", p_block->i_pts, p_block->i_dts);
    }
    else if (es->p_dec->fmt_out.i_cat == AUDIO_ES)
    {
        msg_Dbg(p_input, "[TS es_out::EsOutSend] audio pts[%llu] timestamp[%llu]", p_block->i_pts, p_block->i_dts);
    }
    // end by add</span></span>

    /* Decode */
    if( es->p_dec_record )
    {
        block_t *p_dup = block_Duplicate( p_block );
        if( p_dup )
            input_DecoderDecode( es->p_dec_record, p_dup,
                                 p_input->p->b_out_pace_control );
    }

    input_DecoderDecode(es->p_dec, p_block,
                        p_input->p->b_out_pace_control);

<span style="color:#FF0000;">    <span style="color:#3333FF;">// yagerfgcs test for:有时在定位视频问题时，为了排查干扰，可以屏蔽音频。反之亦然。需要的同仁，可以放开这段代码。
    /*if (es->p_dec->fmt_out.i_cat == VIDEO_ES)
    {
        input_DecoderDecode(es->p_dec, p_block,
            p_input->p->b_out_pace_control);
    }
    else
    {
        block_Release(p_block);
    }*/</span></span>
    
    es_format_t fmt_dsc;
    vlc_meta_t  *p_meta_dsc;
    if( input_DecoderHasFormatChanged( es->p_dec, &fmt_dsc, &p_meta_dsc ) )
    {
        EsOutUpdateInfo( out, es, &fmt_dsc, p_meta_dsc );

        es_format_Clean( &fmt_dsc );
        if( p_meta_dsc )
            vlc_meta_Delete( p_meta_dsc );
    }

    /* Check CC status */
    bool pb_cc[4];

    input_DecoderIsCcPresent( es->p_dec, pb_cc );
    for( int i = 0; i < 4; i++ )
    {
        es_format_t fmt;

        if(  es->pb_cc_present[i] || !pb_cc[i] )
            continue;
        msg_Dbg( p_input, "Adding CC track %d for es[%d]", 1+i, es->i_id );

        es_format_Init( &fmt, SPU_ES, EsOutFourccClosedCaptions[i] );
        fmt.i_group = es->fmt.i_group;
        if( asprintf( &fmt.psz_description,
                      _("Closed captions %u"), 1 + i ) == -1 )
            fmt.psz_description = NULL;
        es->pp_cc_es[i] = EsOutAdd( out, &fmt );
        es->pp_cc_es[i]->p_master = es;
        es_format_Clean( &fmt );

        /* */
        es->pb_cc_present[i] = true;
    }

    vlc_mutex_unlock( &p_sys->lock );

    return VLC_SUCCESS;
}

5、在src\input\decoder.c中DecoderProcess函数中打印音视频时间戳

static void DecoderProcess( decoder_t *p_dec, block_t *p_block )
{
    decoder_owner_sys_t *p_owner = (decoder_owner_sys_t *)p_dec->p_owner;
    const bool b_flush_request = p_block && (p_block->i_flags & BLOCK_FLAG_CORE_FLUSH);

    if( p_dec->b_error )
    {
        if( p_block )
            block_Release( p_block );
        goto flush;
    }

    if( p_block && p_block->i_buffer <= 0 )
    {
        assert( !b_flush_request );
        block_Release( p_block );
        return;
    }

#ifdef ENABLE_SOUT
    if( p_owner->b_packetizer )
    {
        if( p_block )
            p_block->i_flags &= ~BLOCK_FLAG_CORE_PRIVATE_MASK;

        DecoderProcessSout( p_dec, p_block );
    }
    else
#endif
    {
        bool b_flush = false;

        if( p_block )
        {
            const bool b_flushing = p_owner->i_preroll_end == INT64_MAX;
            DecoderUpdatePreroll( &p_owner->i_preroll_end, p_block );

            b_flush = !b_flushing && b_flush_request;

            p_block->i_flags &= ~BLOCK_FLAG_CORE_PRIVATE_MASK;
        }

        if( p_dec->fmt_out.i_cat == AUDIO_ES )
        {
            <span style="color:#3333FF;">//add by yagerfgcs for log
            if (p_block)
            {
                msg_Dbg(p_dec, "[DS 01 decoder::DecoderProcess] audio pts[%llu]", p_block->i_pts);
            }
            //end</span>
            
            DecoderProcessAudio( p_dec, p_block, b_flush );
        }
        else if( p_dec->fmt_out.i_cat == VIDEO_ES )
        {
            <span style="color:#3333FF;">//add by yagerfgcs for log
            if (p_block)
            {
                msg_Dbg(p_dec, "[DS 01 decoder::DecoderProcess] video pts[%llu]", p_block->i_pts);
            }
            //end</span>

            DecoderProcessVideo( p_dec, p_block, b_flush );
        }
        else if( p_dec->fmt_out.i_cat == SPU_ES )
        {
            DecoderProcessSpu( p_dec, p_block, b_flush );
        }
        else
        {
            msg_Err( p_dec, "unknown ES format" );
            p_dec->b_error = true;
        }
    }

    /* */
flush:
    if( b_flush_request )
        DecoderProcessOnFlush( p_dec );
}

6、在modules\codec\avcodec\video.c中DecodeVideo函数增加日志

picture_t *DecodeVideo( decoder_t *p_dec, block_t **pp_block )
{
    .................

    if( p_block)
    {
       <span style="color:#3333FF;"> //yagerfgcs for log
        msg_Dbg(p_dec, "[DS 02 video::DecodeVideo] video pts[%llu]", p_block->i_pts);</span>

        if( p_block->i_flags & (BLOCK_FLAG_DISCONTINUITY|BLOCK_FLAG_CORRUPTED) )
        {
            p_sys->i_pts = VLC_TS_INVALID; /* To make sure we recover properly */

            p_sys->i_late_frames = 0;

            post_mt( p_sys );
            if( p_block->i_flags & BLOCK_FLAG_DISCONTINUITY )
                avcodec_flush_buffers( p_context );
            wait_mt( p_sys );

            block_Release( p_block );
            return NULL;
        }

        if( p_block->i_flags & BLOCK_FLAG_PREROLL )
        {
            /* Do not care about late frames when prerolling
             * TODO avoid decoding of non reference frame
             * (ie all B except for H264 where it depends only on nal_ref_idc) */
            p_sys->i_late_frames = 0;

            <span style="color:#3333FF;">//yagerfgcs for log
            msg_Dbg(p_dec, "[DS video::DecodeVideo] p_block->i_flags == BLOCK_FLAG_PREROLL");</span>
        }
    }
    ....................
}

7、src\input\decoder.c中DecoderProcess函数

static void DecoderDecodeVideo( decoder_t *p_dec, block_t *p_block )
{
    decoder_owner_sys_t *p_owner = p_dec->p_owner;
    picture_t      *p_pic;
    int i_lost = 0;
    int i_decoded = 0;
    int i_displayed = 0;

    while( (p_pic = p_dec->pf_decode_video( p_dec, &p_block )) )
    {
        <span style="color:#3333FF;">//yagerfgcs for log
        msg_Dbg(p_dec, "[DS 03 decoder::DecoderDecodeVideo] video pts[%llu]", p_pic->date);</span>

        vout_thread_t  *p_vout = p_owner->p_vout;
        if( DecoderIsExitRequested( p_dec ) )
        {
            /* It prevent freezing VLC in case of broken decoder */
            vout_ReleasePicture( p_vout, p_pic );
            if( p_block )
                block_Release( p_block );
            break;
        }
        .....................
     }
     ......................
}

8、src\input\decoder.c中DecoderProcess函数

static void DecoderPlayVideo( decoder_t *p_dec, picture_t *p_picture,
                              int *pi_played_sum, int *pi_lost_sum )
{
    ...........................
    const bool b_dated = p_picture->date > VLC_TS_INVALID;
    int i_rate = INPUT_RATE_DEFAULT;
    
    mtime_t dateBefore = p_picture->date;
    
    DecoderFixTs( p_dec, &p_picture->date, NULL, NULL,
                  &i_rate, DECODER_BOGUS_VIDEO_DELAY );

    <span style="color:#3333FF;">//yagerfgcs for log
    msg_Dbg(p_dec, "[DS 04 decoder::DecoderPlayVideo] video date before[%llu] after DecoderFixTs[%llu]", 
            dateBefore, p_picture->date);</span>

    vlc_mutex_unlock( &p_owner->lock );

    /* */
    if( !p_picture->b_force && p_picture->date <= VLC_TS_INVALID ) // FIXME --VLC_TS_INVALID verify video_output/*
        b_reject = true;
    ............................
} 

三、让VLC默认打印debug日志，方便保存的方法

1、通过VLC菜单->工具->消息，可以将日志级别改为“2（调试）”，这样就可以打印出所有的调试日志，点击“另存为”可保存到文件中

2、也可以通过修改代码，让vlc默认打印debug日志

在modules\gui\qt4\dialogs\messages.cpp中MessagesDialog::MessagesDialog函数，修改默认级别

MessagesDialog::MessagesDialog( intf_thread_t *_p_intf)
               : QVLCFrame( _p_intf )
{
    setWindowTitle( qtr( "Messages" ) );
    setWindowRole( "vlc-messages" );
    /* Build Ui */
    ui.setupUi( this );
    ui.bottomButtonsBox->addButton( new QPushButton( qtr("&Close"), this ),
                                         QDialogButtonBox::RejectRole );

    /* Modules tree */
    ui.modulesTree->setHeaderHidden( true );

    /* Buttons and general layout */
    ui.saveLogButton->setToolTip( qtr( "Saves all the displayed logs to a file" ) );

    <span style="color:#3333FF;">int i_verbosity = 2;// var_InheritInteger(p_intf, "verbose");</span>
    changeVerbosity( i_verbosity );
    ui.verbosityBox->setValue( qMin( i_verbosity, 2 ) );
    ................
}