Home | History | Annotate | Download | only in source 
      1 /*
      2  *  Copyright (c) 2012 The WebRTC project authors. All Rights Reserved.
      3  *
      4  *  Use of this source code is governed by a BSD-style license
      5  *  that can be found in the LICENSE file in the root of the source
      6  *  tree. An additional intellectual property rights grant can be found
      7  *  in the file PATENTS.  All contributing project authors may
      8  *  be found in the AUTHORS file in the root of the source tree.
      9  */
     10 
     11 #include "webrtc/system_wrappers/source/trace_impl.h"
     12 
     13 #include <assert.h>
     14 #include <stdarg.h>
     15 #include <stdio.h>
     16 #include <string.h>
     17 
     18 #include "webrtc/base/atomicops.h"
     19 #include "webrtc/base/platform_thread.h"
     20 #ifdef _WIN32
     21 #include "webrtc/system_wrappers/source/trace_win.h"
     22 #else
     23 #include "webrtc/system_wrappers/source/trace_posix.h"
     24 #endif  // _WIN32
     25 
     26 #define KEY_LEN_CHARS 31
     27 
     28 #ifdef _WIN32
     29 #pragma warning(disable:4355)
     30 #endif  // _WIN32
     31 
     32 namespace webrtc {
     33 
     34 const int Trace::kBoilerplateLength = 71;
     35 const int Trace::kTimestampPosition = 13;
     36 const int Trace::kTimestampLength = 12;
     37 volatile int Trace::level_filter_ = kTraceDefault;
     38 
     39 // Construct On First Use idiom. Avoids "static initialization order fiasco".
     40 TraceImpl* TraceImpl::StaticInstance(CountOperation count_operation,
     41                                      const TraceLevel level) {
     42   // Sanities to avoid taking lock unless absolutely necessary (for
     43   // performance reasons). count_operation == kAddRefNoCreate implies that a
     44   // message will be written to file.
     45   if ((level != kTraceAll) && (count_operation == kAddRefNoCreate)) {
     46     if (!(level & level_filter())) {
     47       return NULL;
     48     }
     49   }
     50   TraceImpl* impl =
     51     GetStaticInstance<TraceImpl>(count_operation);
     52   return impl;
     53 }
     54 
     55 TraceImpl* TraceImpl::GetTrace(const TraceLevel level) {
     56   return StaticInstance(kAddRefNoCreate, level);
     57 }
     58 
     59 TraceImpl* TraceImpl::CreateInstance() {
     60 #if defined(_WIN32)
     61   return new TraceWindows();
     62 #else
     63   return new TracePosix();
     64 #endif
     65 }
     66 
     67 TraceImpl::TraceImpl()
     68     : callback_(NULL),
     69       row_count_text_(0),
     70       file_count_text_(0),
     71       trace_file_(FileWrapper::Create()) {
     72 }
     73 
     74 TraceImpl::~TraceImpl() {
     75   trace_file_->Flush();
     76   trace_file_->CloseFile();
     77 }
     78 
     79 int32_t TraceImpl::AddThreadId(char* trace_message) const {
     80   uint32_t thread_id = rtc::CurrentThreadId();
     81   // Messages is 12 characters.
     82   return sprintf(trace_message, "%10u; ", thread_id);
     83 }
     84 
     85 int32_t TraceImpl::AddLevel(char* sz_message, const TraceLevel level) const {
     86   const int kMessageLength = 12;
     87   switch (level) {
     88     case kTraceTerseInfo:
     89       // Add the appropriate amount of whitespace.
     90       memset(sz_message, ' ', kMessageLength);
     91       sz_message[kMessageLength] = '\0';
     92       break;
     93     case kTraceStateInfo:
     94       sprintf(sz_message, "STATEINFO ; ");
     95       break;
     96     case kTraceWarning:
     97       sprintf(sz_message, "WARNING   ; ");
     98       break;
     99     case kTraceError:
    100       sprintf(sz_message, "ERROR     ; ");
    101       break;
    102     case kTraceCritical:
    103       sprintf(sz_message, "CRITICAL  ; ");
    104       break;
    105     case kTraceInfo:
    106       sprintf(sz_message, "DEBUGINFO ; ");
    107       break;
    108     case kTraceModuleCall:
    109       sprintf(sz_message, "MODULECALL; ");
    110       break;
    111     case kTraceMemory:
    112       sprintf(sz_message, "MEMORY    ; ");
    113       break;
    114     case kTraceTimer:
    115       sprintf(sz_message, "TIMER     ; ");
    116       break;
    117     case kTraceStream:
    118       sprintf(sz_message, "STREAM    ; ");
    119       break;
    120     case kTraceApiCall:
    121       sprintf(sz_message, "APICALL   ; ");
    122       break;
    123     case kTraceDebug:
    124       sprintf(sz_message, "DEBUG     ; ");
    125       break;
    126     default:
    127       assert(false);
    128       return 0;
    129   }
    130   // All messages are 12 characters.
    131   return kMessageLength;
    132 }
    133 
    134 int32_t TraceImpl::AddModuleAndId(char* trace_message,
    135                                   const TraceModule module,
    136                                   const int32_t id) const {
    137   // Use long int to prevent problems with different definitions of
    138   // int32_t.
    139   // TODO(hellner): is this actually a problem? If so, it should be better to
    140   //                clean up int32_t
    141   const long int idl = id;
    142   const int kMessageLength = 25;
    143   if (idl != -1) {
    144     const unsigned long int id_engine = id >> 16;
    145     const unsigned long int id_channel = id & 0xffff;
    146 
    147     switch (module) {
    148       case kTraceUndefined:
    149         // Add the appropriate amount of whitespace.
    150         memset(trace_message, ' ', kMessageLength);
    151         trace_message[kMessageLength] = '\0';
    152         break;
    153       case kTraceVoice:
    154         sprintf(trace_message, "       VOICE:%5ld %5ld;", id_engine,
    155                 id_channel);
    156         break;
    157       case kTraceVideo:
    158         sprintf(trace_message, "       VIDEO:%5ld %5ld;", id_engine,
    159                 id_channel);
    160         break;
    161       case kTraceUtility:
    162         sprintf(trace_message, "     UTILITY:%5ld %5ld;", id_engine,
    163                 id_channel);
    164         break;
    165       case kTraceRtpRtcp:
    166         sprintf(trace_message, "    RTP/RTCP:%5ld %5ld;", id_engine,
    167                 id_channel);
    168         break;
    169       case kTraceTransport:
    170         sprintf(trace_message, "   TRANSPORT:%5ld %5ld;", id_engine,
    171                 id_channel);
    172         break;
    173       case kTraceAudioCoding:
    174         sprintf(trace_message, "AUDIO CODING:%5ld %5ld;", id_engine,
    175                 id_channel);
    176         break;
    177       case kTraceSrtp:
    178         sprintf(trace_message, "        SRTP:%5ld %5ld;", id_engine,
    179                 id_channel);
    180         break;
    181       case kTraceAudioMixerServer:
    182         sprintf(trace_message, " AUDIO MIX/S:%5ld %5ld;", id_engine,
    183                 id_channel);
    184         break;
    185       case kTraceAudioMixerClient:
    186         sprintf(trace_message, " AUDIO MIX/C:%5ld %5ld;", id_engine,
    187                 id_channel);
    188         break;
    189       case kTraceVideoCoding:
    190         sprintf(trace_message, "VIDEO CODING:%5ld %5ld;", id_engine,
    191                 id_channel);
    192         break;
    193       case kTraceVideoMixer:
    194         // Print sleep time and API call
    195         sprintf(trace_message, "   VIDEO MIX:%5ld %5ld;", id_engine,
    196                 id_channel);
    197         break;
    198       case kTraceFile:
    199         sprintf(trace_message, "        FILE:%5ld %5ld;", id_engine,
    200                 id_channel);
    201         break;
    202       case kTraceAudioProcessing:
    203         sprintf(trace_message, "  AUDIO PROC:%5ld %5ld;", id_engine,
    204                 id_channel);
    205         break;
    206       case kTraceAudioDevice:
    207         sprintf(trace_message, "AUDIO DEVICE:%5ld %5ld;", id_engine,
    208                 id_channel);
    209         break;
    210       case kTraceVideoRenderer:
    211         sprintf(trace_message, "VIDEO RENDER:%5ld %5ld;", id_engine,
    212                 id_channel);
    213         break;
    214       case kTraceVideoCapture:
    215         sprintf(trace_message, "VIDEO CAPTUR:%5ld %5ld;", id_engine,
    216                 id_channel);
    217         break;
    218       case kTraceRemoteBitrateEstimator:
    219         sprintf(trace_message, "     BWE RBE:%5ld %5ld;", id_engine,
    220                 id_channel);
    221         break;
    222     }
    223   } else {
    224     switch (module) {
    225       case kTraceUndefined:
    226         // Add the appropriate amount of whitespace.
    227         memset(trace_message, ' ', kMessageLength);
    228         trace_message[kMessageLength] = '\0';
    229         break;
    230       case kTraceVoice:
    231         sprintf(trace_message, "       VOICE:%11ld;", idl);
    232         break;
    233       case kTraceVideo:
    234         sprintf(trace_message, "       VIDEO:%11ld;", idl);
    235         break;
    236       case kTraceUtility:
    237         sprintf(trace_message, "     UTILITY:%11ld;", idl);
    238         break;
    239       case kTraceRtpRtcp:
    240         sprintf(trace_message, "    RTP/RTCP:%11ld;", idl);
    241         break;
    242       case kTraceTransport:
    243         sprintf(trace_message, "   TRANSPORT:%11ld;", idl);
    244         break;
    245       case kTraceAudioCoding:
    246         sprintf(trace_message, "AUDIO CODING:%11ld;", idl);
    247         break;
    248       case kTraceSrtp:
    249         sprintf(trace_message, "        SRTP:%11ld;", idl);
    250         break;
    251       case kTraceAudioMixerServer:
    252         sprintf(trace_message, " AUDIO MIX/S:%11ld;", idl);
    253         break;
    254       case kTraceAudioMixerClient:
    255         sprintf(trace_message, " AUDIO MIX/C:%11ld;", idl);
    256         break;
    257       case kTraceVideoCoding:
    258         sprintf(trace_message, "VIDEO CODING:%11ld;", idl);
    259         break;
    260       case kTraceVideoMixer:
    261         sprintf(trace_message, "   VIDEO MIX:%11ld;", idl);
    262         break;
    263       case kTraceFile:
    264         sprintf(trace_message, "        FILE:%11ld;", idl);
    265         break;
    266       case kTraceAudioProcessing:
    267         sprintf(trace_message, "  AUDIO PROC:%11ld;", idl);
    268         break;
    269       case kTraceAudioDevice:
    270         sprintf(trace_message, "AUDIO DEVICE:%11ld;", idl);
    271         break;
    272       case kTraceVideoRenderer:
    273         sprintf(trace_message, "VIDEO RENDER:%11ld;", idl);
    274         break;
    275       case kTraceVideoCapture:
    276         sprintf(trace_message, "VIDEO CAPTUR:%11ld;", idl);
    277         break;
    278       case kTraceRemoteBitrateEstimator:
    279         sprintf(trace_message, "     BWE RBE:%11ld;", idl);
    280         break;
    281     }
    282   }
    283   return kMessageLength;
    284 }
    285 
    286 int32_t TraceImpl::SetTraceFileImpl(const char* file_name_utf8,
    287                                     const bool add_file_counter) {
    288   rtc::CritScope lock(&crit_);
    289 
    290   trace_file_->Flush();
    291   trace_file_->CloseFile();
    292 
    293   if (file_name_utf8) {
    294     if (add_file_counter) {
    295       file_count_text_ = 1;
    296 
    297       char file_name_with_counter_utf8[FileWrapper::kMaxFileNameSize];
    298       CreateFileName(file_name_utf8, file_name_with_counter_utf8,
    299                      file_count_text_);
    300       if (trace_file_->OpenFile(file_name_with_counter_utf8, false, false,
    301                                true) == -1) {
    302         return -1;
    303       }
    304     } else {
    305       file_count_text_ = 0;
    306       if (trace_file_->OpenFile(file_name_utf8, false, false, true) == -1) {
    307         return -1;
    308       }
    309     }
    310   }
    311   row_count_text_ = 0;
    312   return 0;
    313 }
    314 
    315 int32_t TraceImpl::TraceFileImpl(
    316     char file_name_utf8[FileWrapper::kMaxFileNameSize]) {
    317   rtc::CritScope lock(&crit_);
    318   return trace_file_->FileName(file_name_utf8, FileWrapper::kMaxFileNameSize);
    319 }
    320 
    321 int32_t TraceImpl::SetTraceCallbackImpl(TraceCallback* callback) {
    322   rtc::CritScope lock(&crit_);
    323   callback_ = callback;
    324   return 0;
    325 }
    326 
    327 int32_t TraceImpl::AddMessage(
    328     char* trace_message,
    329     const char msg[WEBRTC_TRACE_MAX_MESSAGE_SIZE],
    330     const uint16_t written_so_far) const {
    331   int length = 0;
    332   if (written_so_far >= WEBRTC_TRACE_MAX_MESSAGE_SIZE) {
    333     return -1;
    334   }
    335   // - 2 to leave room for newline and NULL termination.
    336 #ifdef _WIN32
    337   length = _snprintf(trace_message,
    338                      WEBRTC_TRACE_MAX_MESSAGE_SIZE - written_so_far - 2,
    339                      "%s", msg);
    340   if (length < 0) {
    341     length = WEBRTC_TRACE_MAX_MESSAGE_SIZE - written_so_far - 2;
    342     trace_message[length] = 0;
    343   }
    344 #else
    345   length = snprintf(trace_message,
    346                     WEBRTC_TRACE_MAX_MESSAGE_SIZE - written_so_far - 2,
    347                     "%s", msg);
    348   if (length < 0 ||
    349       length > WEBRTC_TRACE_MAX_MESSAGE_SIZE - written_so_far - 2) {
    350     length = WEBRTC_TRACE_MAX_MESSAGE_SIZE - written_so_far - 2;
    351     trace_message[length] = 0;
    352   }
    353 #endif
    354   // Length with NULL termination.
    355   return length + 1;
    356 }
    357 
    358 void TraceImpl::AddMessageToList(
    359     const char trace_message[WEBRTC_TRACE_MAX_MESSAGE_SIZE],
    360     const uint16_t length,
    361     const TraceLevel level) {
    362   rtc::CritScope lock(&crit_);
    363   if (callback_)
    364     callback_->Print(level, trace_message, length);
    365   WriteToFile(trace_message, length);
    366 }
    367 
    368 void TraceImpl::WriteToFile(const char* msg, uint16_t length) {
    369   if (!trace_file_->Open())
    370     return;
    371 
    372   if (row_count_text_ > WEBRTC_TRACE_MAX_FILE_SIZE) {
    373     // wrap file
    374     row_count_text_ = 0;
    375     trace_file_->Flush();
    376 
    377     if (file_count_text_ == 0) {
    378       trace_file_->Rewind();
    379     } else {
    380       char old_file_name[FileWrapper::kMaxFileNameSize];
    381       char new_file_name[FileWrapper::kMaxFileNameSize];
    382 
    383       // get current name
    384       trace_file_->FileName(old_file_name, FileWrapper::kMaxFileNameSize);
    385       trace_file_->CloseFile();
    386 
    387       file_count_text_++;
    388 
    389       UpdateFileName(old_file_name, new_file_name, file_count_text_);
    390 
    391       if (trace_file_->OpenFile(new_file_name, false, false, true) == -1) {
    392         return;
    393       }
    394     }
    395   }
    396   if (row_count_text_ == 0) {
    397     char message[WEBRTC_TRACE_MAX_MESSAGE_SIZE + 1];
    398     int32_t length = AddDateTimeInfo(message);
    399     if (length != -1) {
    400       message[length] = 0;
    401       message[length - 1] = '\n';
    402       trace_file_->Write(message, length);
    403       row_count_text_++;
    404     }
    405   }
    406 
    407   char trace_message[WEBRTC_TRACE_MAX_MESSAGE_SIZE];
    408   memcpy(trace_message, msg, length);
    409   trace_message[length] = 0;
    410   trace_message[length - 1] = '\n';
    411   trace_file_->Write(trace_message, length);
    412   row_count_text_++;
    413 }
    414 
    415 void TraceImpl::AddImpl(const TraceLevel level,
    416                         const TraceModule module,
    417                         const int32_t id,
    418                         const char msg[WEBRTC_TRACE_MAX_MESSAGE_SIZE]) {
    419   if (!TraceCheck(level))
    420     return;
    421 
    422   char trace_message[WEBRTC_TRACE_MAX_MESSAGE_SIZE];
    423   char* message_ptr = &trace_message[0];
    424   int32_t len = AddLevel(message_ptr, level);
    425   if (len == -1)
    426     return;
    427 
    428   message_ptr += len;
    429   int32_t ack_len = len;
    430 
    431   len = AddTime(message_ptr, level);
    432   if (len == -1)
    433     return;
    434 
    435   message_ptr += len;
    436   ack_len += len;
    437 
    438   len = AddModuleAndId(message_ptr, module, id);
    439   if (len == -1)
    440     return;
    441 
    442   message_ptr += len;
    443   ack_len += len;
    444 
    445   len = AddThreadId(message_ptr);
    446   if (len < 0)
    447     return;
    448 
    449   message_ptr += len;
    450   ack_len += len;
    451 
    452   len = AddMessage(message_ptr, msg, static_cast<uint16_t>(ack_len));
    453   if (len == -1)
    454     return;
    455 
    456   ack_len += len;
    457   AddMessageToList(trace_message, static_cast<uint16_t>(ack_len), level);
    458 }
    459 
    460 bool TraceImpl::TraceCheck(const TraceLevel level) const {
    461   return (level & level_filter()) ? true : false;
    462 }
    463 
    464 bool TraceImpl::UpdateFileName(
    465     const char file_name_utf8[FileWrapper::kMaxFileNameSize],
    466     char file_name_with_counter_utf8[FileWrapper::kMaxFileNameSize],
    467     const uint32_t new_count) const {
    468   int32_t length = (int32_t)strlen(file_name_utf8);
    469   if (length < 0) {
    470     return false;
    471   }
    472 
    473   int32_t length_without_file_ending = length - 1;
    474   while (length_without_file_ending > 0) {
    475     if (file_name_utf8[length_without_file_ending] == '.') {
    476       break;
    477     } else {
    478       length_without_file_ending--;
    479     }
    480   }
    481   if (length_without_file_ending == 0) {
    482     length_without_file_ending = length;
    483   }
    484   int32_t length_to_ = length_without_file_ending - 1;
    485   while (length_to_ > 0) {
    486     if (file_name_utf8[length_to_] == '_') {
    487       break;
    488     } else {
    489       length_to_--;
    490     }
    491   }
    492 
    493   memcpy(file_name_with_counter_utf8, file_name_utf8, length_to_);
    494   sprintf(file_name_with_counter_utf8 + length_to_, "_%lu%s",
    495           static_cast<long unsigned int>(new_count),
    496           file_name_utf8 + length_without_file_ending);
    497   return true;
    498 }
    499 
    500 bool TraceImpl::CreateFileName(
    501     const char file_name_utf8[FileWrapper::kMaxFileNameSize],
    502     char file_name_with_counter_utf8[FileWrapper::kMaxFileNameSize],
    503     const uint32_t new_count) const {
    504   int32_t length = (int32_t)strlen(file_name_utf8);
    505   if (length < 0) {
    506     return false;
    507   }
    508 
    509   int32_t length_without_file_ending = length - 1;
    510   while (length_without_file_ending > 0) {
    511     if (file_name_utf8[length_without_file_ending] == '.') {
    512       break;
    513     } else {
    514       length_without_file_ending--;
    515     }
    516   }
    517   if (length_without_file_ending == 0) {
    518     length_without_file_ending = length;
    519   }
    520   memcpy(file_name_with_counter_utf8, file_name_utf8,
    521          length_without_file_ending);
    522   sprintf(file_name_with_counter_utf8 + length_without_file_ending, "_%lu%s",
    523           static_cast<long unsigned int>(new_count),
    524           file_name_utf8 + length_without_file_ending);
    525   return true;
    526 }
    527 
    528 // static
    529 void Trace::CreateTrace() {
    530   TraceImpl::StaticInstance(kAddRef);
    531 }
    532 
    533 // static
    534 void Trace::ReturnTrace() {
    535   TraceImpl::StaticInstance(kRelease);
    536 }
    537 
    538 // static
    539 int32_t Trace::TraceFile(char file_name[FileWrapper::kMaxFileNameSize]) {
    540   TraceImpl* trace = TraceImpl::GetTrace();
    541   if (trace) {
    542     int ret_val = trace->TraceFileImpl(file_name);
    543     ReturnTrace();
    544     return ret_val;
    545   }
    546   return -1;
    547 }
    548 
    549 // static
    550 void Trace::set_level_filter(int filter) {
    551   rtc::AtomicOps::ReleaseStore(&level_filter_, filter);
    552 }
    553 
    554 // static
    555 int Trace::level_filter() {
    556   return rtc::AtomicOps::AcquireLoad(&level_filter_);
    557 }
    558 
    559 // static
    560 int32_t Trace::SetTraceFile(const char* file_name,
    561                             const bool add_file_counter) {
    562   TraceImpl* trace = TraceImpl::GetTrace();
    563   if (trace) {
    564     int ret_val = trace->SetTraceFileImpl(file_name, add_file_counter);
    565     ReturnTrace();
    566     return ret_val;
    567   }
    568   return -1;
    569 }
    570 
    571 int32_t Trace::SetTraceCallback(TraceCallback* callback) {
    572   TraceImpl* trace = TraceImpl::GetTrace();
    573   if (trace) {
    574     int ret_val = trace->SetTraceCallbackImpl(callback);
    575     ReturnTrace();
    576     return ret_val;
    577   }
    578   return -1;
    579 }
    580 
    581 void Trace::Add(const TraceLevel level, const TraceModule module,
    582                 const int32_t id, const char* msg, ...) {
    583   TraceImpl* trace = TraceImpl::GetTrace(level);
    584   if (trace) {
    585     if (trace->TraceCheck(level)) {
    586       char temp_buff[WEBRTC_TRACE_MAX_MESSAGE_SIZE];
    587       char* buff = 0;
    588       if (msg) {
    589         va_list args;
    590         va_start(args, msg);
    591 #ifdef _WIN32
    592         _vsnprintf(temp_buff, WEBRTC_TRACE_MAX_MESSAGE_SIZE - 1, msg, args);
    593 #else
    594         vsnprintf(temp_buff, WEBRTC_TRACE_MAX_MESSAGE_SIZE - 1, msg, args);
    595 #endif
    596         va_end(args);
    597         buff = temp_buff;
    598       }
    599       trace->AddImpl(level, module, id, buff);
    600     }
    601     ReturnTrace();
    602   }
    603 }
    604 
    605 }  // namespace webrtc
    606