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".
StaticInstance(CountOperation count_operation,const TraceLevel level)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 
GetTrace(const TraceLevel level)55 TraceImpl* TraceImpl::GetTrace(const TraceLevel level) {
56   return StaticInstance(kAddRefNoCreate, level);
57 }
58 
CreateInstance()59 TraceImpl* TraceImpl::CreateInstance() {
60 #if defined(_WIN32)
61   return new TraceWindows();
62 #else
63   return new TracePosix();
64 #endif
65 }
66 
TraceImpl()67 TraceImpl::TraceImpl()
68     : callback_(NULL),
69       row_count_text_(0),
70       file_count_text_(0),
71       trace_file_(FileWrapper::Create()) {
72 }
73 
~TraceImpl()74 TraceImpl::~TraceImpl() {
75   trace_file_->Flush();
76   trace_file_->CloseFile();
77 }
78 
AddThreadId(char * trace_message) const79 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 
AddLevel(char * sz_message,const TraceLevel level) const85 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 
AddModuleAndId(char * trace_message,const TraceModule module,const int32_t id) const134 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 
SetTraceFileImpl(const char * file_name_utf8,const bool add_file_counter)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 
TraceFileImpl(char file_name_utf8[FileWrapper::kMaxFileNameSize])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 
SetTraceCallbackImpl(TraceCallback * callback)321 int32_t TraceImpl::SetTraceCallbackImpl(TraceCallback* callback) {
322   rtc::CritScope lock(&crit_);
323   callback_ = callback;
324   return 0;
325 }
326 
AddMessage(char * trace_message,const char msg[WEBRTC_TRACE_MAX_MESSAGE_SIZE],const uint16_t written_so_far) const327 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 
AddMessageToList(const char trace_message[WEBRTC_TRACE_MAX_MESSAGE_SIZE],const uint16_t length,const TraceLevel level)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 
WriteToFile(const char * msg,uint16_t length)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 
AddImpl(const TraceLevel level,const TraceModule module,const int32_t id,const char msg[WEBRTC_TRACE_MAX_MESSAGE_SIZE])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 
TraceCheck(const TraceLevel level) const460 bool TraceImpl::TraceCheck(const TraceLevel level) const {
461   return (level & level_filter()) ? true : false;
462 }
463 
UpdateFileName(const char file_name_utf8[FileWrapper::kMaxFileNameSize],char file_name_with_counter_utf8[FileWrapper::kMaxFileNameSize],const uint32_t new_count) const464 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 
CreateFileName(const char file_name_utf8[FileWrapper::kMaxFileNameSize],char file_name_with_counter_utf8[FileWrapper::kMaxFileNameSize],const uint32_t new_count) const500 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
CreateTrace()529 void Trace::CreateTrace() {
530   TraceImpl::StaticInstance(kAddRef);
531 }
532 
533 // static
ReturnTrace()534 void Trace::ReturnTrace() {
535   TraceImpl::StaticInstance(kRelease);
536 }
537 
538 // static
TraceFile(char file_name[FileWrapper::kMaxFileNameSize])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
set_level_filter(int filter)550 void Trace::set_level_filter(int filter) {
551   rtc::AtomicOps::ReleaseStore(&level_filter_, filter);
552 }
553 
554 // static
level_filter()555 int Trace::level_filter() {
556   return rtc::AtomicOps::AcquireLoad(&level_filter_);
557 }
558 
559 // static
SetTraceFile(const char * file_name,const bool add_file_counter)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 
SetTraceCallback(TraceCallback * callback)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 
Add(const TraceLevel level,const TraceModule module,const int32_t id,const char * msg,...)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