Ignore:
Timestamp:
May 7, 2010 3:15:39 PM (10 years ago)
Author:
nanang
Message:

Re #1067: Added feature of JB operation tracing to CSV file in stream.

File:
1 edited

Legend:

Unmodified
Added
Removed
  • pjproject/trunk/pjmedia/src/pjmedia/stream.c

    r3072 r3161  
    5050 */ 
    5151#define MAX_PLC_MSEC                    PJMEDIA_MAX_PLC_DURATION_MSEC 
     52 
     53 
     54/* Tracing jitter buffer operations in a stream session to a CSV file. 
     55 * The trace will contain JB operation timestamp, frame info, RTP info, and 
     56 * the JB state right after the operation. 
     57 */ 
     58#define TRACE_JB                        0       /* Enable/disable trace.    */ 
     59#define TRACE_JB_PATH_PREFIX            ""      /* Optional path/prefix 
     60                                                   for the CSV filename.    */ 
     61#if TRACE_JB 
     62#   include <pj/file_io.h> 
     63#   define TRACE_JB_INVALID_FD          ((pj_oshandle_t)-1) 
     64#   define TRACE_JB_OPENED(s)           (s->trace_jb_fd != TRACE_JB_INVALID_FD) 
     65#endif 
     66 
     67 
    5268 
    5369/** 
     
    185201                                                    packet                  */ 
    186202#endif 
     203 
     204#if TRACE_JB 
     205    pj_oshandle_t           trace_jb_fd;            /**< Jitter tracing file handle.*/ 
     206    char                   *trace_jb_buf;           /**< Jitter tracing buffer.     */ 
     207#endif 
    187208}; 
    188209 
     
    208229    PJ_LOG(4,(sender, "%s: %s [err:%d]", title, errmsg, status)); 
    209230} 
     231 
     232 
     233#if TRACE_JB 
     234 
     235PJ_INLINE(int) trace_jb_print_timestamp(char **buf, pj_ssize_t len) 
     236{ 
     237    pj_time_val now; 
     238    pj_parsed_time ptime; 
     239    char *p = *buf; 
     240 
     241    if (len < 14) 
     242        return -1; 
     243 
     244    pj_gettimeofday(&now); 
     245    pj_time_decode(&now, &ptime); 
     246    p += pj_utoa_pad(ptime.hour, p, 2, '0'); 
     247    *p++ = ':'; 
     248    p += pj_utoa_pad(ptime.min, p, 2, '0'); 
     249    *p++ = ':'; 
     250    p += pj_utoa_pad(ptime.sec, p, 2, '0'); 
     251    *p++ = '.'; 
     252    p += pj_utoa_pad(ptime.msec, p, 3, '0'); 
     253    *p++ = ','; 
     254 
     255    *buf = p; 
     256 
     257    return 0; 
     258} 
     259 
     260PJ_INLINE(int) trace_jb_print_state(pjmedia_stream *stream,  
     261                                    char **buf, pj_ssize_t len) 
     262{ 
     263    char *p = *buf; 
     264    char *endp = *buf + len; 
     265    pjmedia_jb_state state; 
     266 
     267    pjmedia_jbuf_get_state(stream->jb, &state); 
     268 
     269    len = pj_ansi_snprintf(p, endp-p, "%d, %d, %d", 
     270                           state.size, state.burst, state.prefetch); 
     271    if ((len < 0) || (len >= endp-p)) 
     272        return -1; 
     273 
     274    p += len; 
     275    *buf = p; 
     276    return 0; 
     277} 
     278 
     279static void trace_jb_get(pjmedia_stream *stream, pjmedia_jb_frame_type ft, 
     280                         pj_size_t fsize) 
     281{ 
     282    char *p = stream->trace_jb_buf; 
     283    char *endp = stream->trace_jb_buf + PJ_LOG_MAX_SIZE; 
     284    pj_ssize_t len = 0; 
     285    const char* ft_st; 
     286 
     287    if (!TRACE_JB_OPENED(stream)) 
     288        return; 
     289 
     290    /* Print timestamp. */ 
     291    if (trace_jb_print_timestamp(&p, endp-p)) 
     292        goto on_insuff_buffer; 
     293 
     294    /* Print frame type and size */ 
     295    switch(ft) { 
     296        case PJMEDIA_JB_MISSING_FRAME: 
     297            ft_st = "missing"; 
     298            break; 
     299        case PJMEDIA_JB_NORMAL_FRAME: 
     300            ft_st = "normal"; 
     301            break; 
     302        case PJMEDIA_JB_ZERO_PREFETCH_FRAME: 
     303            ft_st = "prefetch"; 
     304            break; 
     305        case PJMEDIA_JB_ZERO_EMPTY_FRAME: 
     306            ft_st = "empty"; 
     307            break; 
     308        default: 
     309            ft_st = "unknown"; 
     310            break; 
     311    } 
     312 
     313    /* Print operation, size, frame count, frame type */ 
     314    len = pj_ansi_snprintf(p, endp-p, "GET,%d,1,%s,,,,", fsize, ft_st); 
     315    if ((len < 0) || (len >= endp-p)) 
     316        goto on_insuff_buffer; 
     317    p += len; 
     318 
     319    /* Print JB state */ 
     320    if (trace_jb_print_state(stream, &p, endp-p)) 
     321        goto on_insuff_buffer; 
     322 
     323    /* Print end of line */ 
     324    if (endp-p < 2) 
     325        goto on_insuff_buffer; 
     326    *p++ = '\n'; 
     327 
     328    /* Write and flush */ 
     329    len = p - stream->trace_jb_buf; 
     330    pj_file_write(stream->trace_jb_fd, stream->trace_jb_buf, &len); 
     331    pj_file_flush(stream->trace_jb_fd); 
     332    return; 
     333 
     334on_insuff_buffer: 
     335    pj_assert(!"Trace buffer too small, check PJ_LOG_MAX_SIZE!"); 
     336} 
     337 
     338static void trace_jb_put(pjmedia_stream *stream, const pjmedia_rtp_hdr *hdr, 
     339                         unsigned payloadlen, unsigned frame_cnt) 
     340{ 
     341    char *p = stream->trace_jb_buf; 
     342    char *endp = stream->trace_jb_buf + PJ_LOG_MAX_SIZE; 
     343    pj_ssize_t len = 0; 
     344 
     345    if (!TRACE_JB_OPENED(stream)) 
     346        return; 
     347 
     348    /* Print timestamp. */ 
     349    if (trace_jb_print_timestamp(&p, endp-p)) 
     350        goto on_insuff_buffer; 
     351 
     352    /* Print operation, size, frame count, RTP info */ 
     353    len = pj_ansi_snprintf(p, endp-p, 
     354                           "PUT,%d,%d,,%d,%d,%d,", 
     355                           payloadlen, frame_cnt, 
     356                           pj_ntohs(hdr->seq), pj_ntohl(hdr->ts), hdr->m); 
     357    if ((len < 0) || (len >= endp-p)) 
     358        goto on_insuff_buffer; 
     359    p += len; 
     360 
     361    /* Print JB state */ 
     362    if (trace_jb_print_state(stream, &p, endp-p)) 
     363        goto on_insuff_buffer; 
     364 
     365    /* Print end of line */ 
     366    if (endp-p < 2) 
     367        goto on_insuff_buffer; 
     368    *p++ = '\n'; 
     369 
     370    /* Write and flush */ 
     371    len = p - stream->trace_jb_buf; 
     372    pj_file_write(stream->trace_jb_fd, stream->trace_jb_buf, &len); 
     373    pj_file_flush(stream->trace_jb_fd); 
     374    return; 
     375 
     376on_insuff_buffer: 
     377    pj_assert(!"Trace buffer too small, check PJ_LOG_MAX_SIZE!"); 
     378} 
     379 
     380#endif /* TRACE_JB */ 
     381 
    210382 
    211383#if defined(PJMEDIA_STREAM_ENABLE_KA) && PJMEDIA_STREAM_ENABLE_KA != 0 
     
    301473        pjmedia_jbuf_get_frame2(stream->jb, channel->out_pkt, &frame_size, 
    302474                                &frame_type, &bit_info); 
    303          
     475 
     476#if TRACE_JB 
     477        trace_jb_get(stream, frame_type, frame_size); 
     478#endif 
     479 
    304480        if (frame_type == PJMEDIA_JB_MISSING_FRAME) { 
    305481             
     
    554730        pjmedia_jbuf_get_frame2(stream->jb, channel->out_pkt, &frame_size, 
    555731                                &frame_type, &bit_info); 
     732 
     733#if TRACE_JB 
     734        trace_jb_get(stream, frame_type, frame_size); 
     735#endif 
    556736         
    557737        /* Unlock jitter buffer mutex. */ 
     
    15691749                pkt_discarded = PJ_TRUE; 
    15701750        } 
     1751 
     1752#if TRACE_JB 
     1753        trace_jb_put(stream, hdr, payloadlen, count); 
     1754#endif 
     1755 
    15711756    } 
    15721757    pj_mutex_unlock( stream->jb_mutex ); 
     
    20792264#endif 
    20802265 
     2266#if TRACE_JB 
     2267    { 
     2268        char trace_name[PJ_MAXPATH]; 
     2269        pj_ssize_t len; 
     2270 
     2271        pj_ansi_snprintf(trace_name, sizeof(trace_name),  
     2272                         TRACE_JB_PATH_PREFIX "%s.csv", 
     2273                         stream->port.info.name.ptr); 
     2274        status = pj_file_open(pool, trace_name, PJ_O_RDWR, &stream->trace_jb_fd); 
     2275        if (status != PJ_SUCCESS) { 
     2276            stream->trace_jb_fd = TRACE_JB_INVALID_FD; 
     2277            PJ_LOG(3,(THIS_FILE, "Failed creating RTP trace file '%s'",  
     2278                      trace_name)); 
     2279        } else { 
     2280            stream->trace_jb_buf = (char*)pj_pool_alloc(pool, PJ_LOG_MAX_SIZE); 
     2281 
     2282            /* Print column header */ 
     2283            len = pj_ansi_snprintf(stream->trace_jb_buf, PJ_LOG_MAX_SIZE, 
     2284                                   "Time, Operation, Size, Frame Count, " 
     2285                                   "Frame type, RTP Seq, RTP TS, RTP M, " 
     2286                                   "JB size, JB burst level, JB prefetch\n"); 
     2287            pj_file_write(stream->trace_jb_fd, stream->trace_jb_buf, &len); 
     2288            pj_file_flush(stream->trace_jb_fd); 
     2289        } 
     2290    } 
     2291#endif 
     2292 
    20812293    /* Success! */ 
    20822294    *p_stream = stream; 
     
    21812393    if (stream->jb) 
    21822394        pjmedia_jbuf_destroy(stream->jb); 
     2395 
     2396#if TRACE_JB 
     2397    if (TRACE_JB_OPENED(stream)) { 
     2398        pj_file_close(stream->trace_jb_fd); 
     2399        stream->trace_jb_fd = TRACE_JB_INVALID_FD; 
     2400    } 
     2401#endif 
    21832402 
    21842403    return PJ_SUCCESS; 
Note: See TracChangeset for help on using the changeset viewer.