13345a6884c488ff3a535c2c9acdd33d74b37e311Iain Merrick// Copyright (c) 2010 The Chromium Authors. All rights reserved. 2c7f5f8508d98d5952d42ed7648c2a8f30a4da156Patrick Scott// Use of this source code is governed by a BSD-style license that can be 3c7f5f8508d98d5952d42ed7648c2a8f30a4da156Patrick Scott// found in the LICENSE file. 4c7f5f8508d98d5952d42ed7648c2a8f30a4da156Patrick Scott 5513209b27ff55e2841eac0e4120199c23acce758Ben Murdoch#include "base/debug/trace_event.h" 6c7f5f8508d98d5952d42ed7648c2a8f30a4da156Patrick Scott 7c7f5f8508d98d5952d42ed7648c2a8f30a4da156Patrick Scott#include "base/format_macros.h" 8c7f5f8508d98d5952d42ed7648c2a8f30a4da156Patrick Scott#include "base/file_path.h" 9c7f5f8508d98d5952d42ed7648c2a8f30a4da156Patrick Scott#include "base/file_util.h" 10c7f5f8508d98d5952d42ed7648c2a8f30a4da156Patrick Scott#include "base/path_service.h" 11408e341a50962061e47be3d6a8f50ee299fae1edKristian Monsen#include "base/platform_thread.h" 12c7f5f8508d98d5952d42ed7648c2a8f30a4da156Patrick Scott#include "base/process_util.h" 133345a6884c488ff3a535c2c9acdd33d74b37e311Iain Merrick#include "base/stringprintf.h" 14c7f5f8508d98d5952d42ed7648c2a8f30a4da156Patrick Scott#include "base/utf_string_conversions.h" 15c7f5f8508d98d5952d42ed7648c2a8f30a4da156Patrick Scott#include "base/time.h" 16c7f5f8508d98d5952d42ed7648c2a8f30a4da156Patrick Scott 17c7f5f8508d98d5952d42ed7648c2a8f30a4da156Patrick Scott#define USE_UNRELIABLE_NOW 18c7f5f8508d98d5952d42ed7648c2a8f30a4da156Patrick Scott 19c7f5f8508d98d5952d42ed7648c2a8f30a4da156Patrick Scottnamespace base { 20513209b27ff55e2841eac0e4120199c23acce758Ben Murdochnamespace debug { 21c7f5f8508d98d5952d42ed7648c2a8f30a4da156Patrick Scott 22c7f5f8508d98d5952d42ed7648c2a8f30a4da156Patrick Scottstatic const char* kEventTypeNames[] = { 23c7f5f8508d98d5952d42ed7648c2a8f30a4da156Patrick Scott "BEGIN", 24c7f5f8508d98d5952d42ed7648c2a8f30a4da156Patrick Scott "END", 25c7f5f8508d98d5952d42ed7648c2a8f30a4da156Patrick Scott "INSTANT" 26c7f5f8508d98d5952d42ed7648c2a8f30a4da156Patrick Scott}; 27c7f5f8508d98d5952d42ed7648c2a8f30a4da156Patrick Scott 28c7f5f8508d98d5952d42ed7648c2a8f30a4da156Patrick Scottstatic const FilePath::CharType* kLogFileName = 29c7f5f8508d98d5952d42ed7648c2a8f30a4da156Patrick Scott FILE_PATH_LITERAL("trace_%d.log"); 30c7f5f8508d98d5952d42ed7648c2a8f30a4da156Patrick Scott 31c7f5f8508d98d5952d42ed7648c2a8f30a4da156Patrick Scott// static 3221d179b334e59e9a3bfcaed4c4430bef1bc5759dKristian MonsenTraceLog* TraceLog::GetInstance() { 3321d179b334e59e9a3bfcaed4c4430bef1bc5759dKristian Monsen return Singleton<TraceLog, DefaultSingletonTraits<TraceLog> >::get(); 3421d179b334e59e9a3bfcaed4c4430bef1bc5759dKristian Monsen} 3521d179b334e59e9a3bfcaed4c4430bef1bc5759dKristian Monsen 3621d179b334e59e9a3bfcaed4c4430bef1bc5759dKristian Monsen// static 37c7f5f8508d98d5952d42ed7648c2a8f30a4da156Patrick Scottbool TraceLog::IsTracing() { 3821d179b334e59e9a3bfcaed4c4430bef1bc5759dKristian Monsen return TraceLog::GetInstance()->enabled_; 39c7f5f8508d98d5952d42ed7648c2a8f30a4da156Patrick Scott} 40c7f5f8508d98d5952d42ed7648c2a8f30a4da156Patrick Scott 41c7f5f8508d98d5952d42ed7648c2a8f30a4da156Patrick Scott// static 42c7f5f8508d98d5952d42ed7648c2a8f30a4da156Patrick Scottbool TraceLog::StartTracing() { 4321d179b334e59e9a3bfcaed4c4430bef1bc5759dKristian Monsen return TraceLog::GetInstance()->Start(); 44c7f5f8508d98d5952d42ed7648c2a8f30a4da156Patrick Scott} 45c7f5f8508d98d5952d42ed7648c2a8f30a4da156Patrick Scott 46c7f5f8508d98d5952d42ed7648c2a8f30a4da156Patrick Scott// static 47c7f5f8508d98d5952d42ed7648c2a8f30a4da156Patrick Scottvoid TraceLog::StopTracing() { 4821d179b334e59e9a3bfcaed4c4430bef1bc5759dKristian Monsen return TraceLog::GetInstance()->Stop(); 49c7f5f8508d98d5952d42ed7648c2a8f30a4da156Patrick Scott} 50c7f5f8508d98d5952d42ed7648c2a8f30a4da156Patrick Scott 51c7f5f8508d98d5952d42ed7648c2a8f30a4da156Patrick Scottvoid TraceLog::Trace(const std::string& name, 52c7f5f8508d98d5952d42ed7648c2a8f30a4da156Patrick Scott EventType type, 53c7f5f8508d98d5952d42ed7648c2a8f30a4da156Patrick Scott const void* id, 54c7f5f8508d98d5952d42ed7648c2a8f30a4da156Patrick Scott const std::wstring& extra, 55c7f5f8508d98d5952d42ed7648c2a8f30a4da156Patrick Scott const char* file, 56c7f5f8508d98d5952d42ed7648c2a8f30a4da156Patrick Scott int line) { 57c7f5f8508d98d5952d42ed7648c2a8f30a4da156Patrick Scott if (!enabled_) 58c7f5f8508d98d5952d42ed7648c2a8f30a4da156Patrick Scott return; 59c7f5f8508d98d5952d42ed7648c2a8f30a4da156Patrick Scott Trace(name, type, id, WideToUTF8(extra), file, line); 60c7f5f8508d98d5952d42ed7648c2a8f30a4da156Patrick Scott} 61c7f5f8508d98d5952d42ed7648c2a8f30a4da156Patrick Scott 62c7f5f8508d98d5952d42ed7648c2a8f30a4da156Patrick Scottvoid TraceLog::Trace(const std::string& name, 63c7f5f8508d98d5952d42ed7648c2a8f30a4da156Patrick Scott EventType type, 64c7f5f8508d98d5952d42ed7648c2a8f30a4da156Patrick Scott const void* id, 65c7f5f8508d98d5952d42ed7648c2a8f30a4da156Patrick Scott const std::string& extra, 66c7f5f8508d98d5952d42ed7648c2a8f30a4da156Patrick Scott const char* file, 67c7f5f8508d98d5952d42ed7648c2a8f30a4da156Patrick Scott int line) { 68c7f5f8508d98d5952d42ed7648c2a8f30a4da156Patrick Scott if (!enabled_) 69c7f5f8508d98d5952d42ed7648c2a8f30a4da156Patrick Scott return; 70c7f5f8508d98d5952d42ed7648c2a8f30a4da156Patrick Scott 71c7f5f8508d98d5952d42ed7648c2a8f30a4da156Patrick Scott#ifdef USE_UNRELIABLE_NOW 72c7f5f8508d98d5952d42ed7648c2a8f30a4da156Patrick Scott TimeTicks tick = TimeTicks::HighResNow(); 73c7f5f8508d98d5952d42ed7648c2a8f30a4da156Patrick Scott#else 74c7f5f8508d98d5952d42ed7648c2a8f30a4da156Patrick Scott TimeTicks tick = TimeTicks::Now(); 75c7f5f8508d98d5952d42ed7648c2a8f30a4da156Patrick Scott#endif 76c7f5f8508d98d5952d42ed7648c2a8f30a4da156Patrick Scott TimeDelta delta = tick - trace_start_time_; 77c7f5f8508d98d5952d42ed7648c2a8f30a4da156Patrick Scott int64 usec = delta.InMicroseconds(); 78c7f5f8508d98d5952d42ed7648c2a8f30a4da156Patrick Scott std::string msg = 79c7f5f8508d98d5952d42ed7648c2a8f30a4da156Patrick Scott StringPrintf("{'pid':'0x%lx', 'tid':'0x%lx', 'type':'%s', " 80c7f5f8508d98d5952d42ed7648c2a8f30a4da156Patrick Scott "'name':'%s', 'id':'%p', 'extra':'%s', 'file':'%s', " 81c7f5f8508d98d5952d42ed7648c2a8f30a4da156Patrick Scott "'line_number':'%d', 'usec_begin': %" PRId64 "},\n", 82c7f5f8508d98d5952d42ed7648c2a8f30a4da156Patrick Scott static_cast<unsigned long>(base::GetCurrentProcId()), 83c7f5f8508d98d5952d42ed7648c2a8f30a4da156Patrick Scott static_cast<unsigned long>(PlatformThread::CurrentId()), 84c7f5f8508d98d5952d42ed7648c2a8f30a4da156Patrick Scott kEventTypeNames[type], 85c7f5f8508d98d5952d42ed7648c2a8f30a4da156Patrick Scott name.c_str(), 86c7f5f8508d98d5952d42ed7648c2a8f30a4da156Patrick Scott id, 87c7f5f8508d98d5952d42ed7648c2a8f30a4da156Patrick Scott extra.c_str(), 88c7f5f8508d98d5952d42ed7648c2a8f30a4da156Patrick Scott file, 89c7f5f8508d98d5952d42ed7648c2a8f30a4da156Patrick Scott line, 90c7f5f8508d98d5952d42ed7648c2a8f30a4da156Patrick Scott usec); 91c7f5f8508d98d5952d42ed7648c2a8f30a4da156Patrick Scott 92c7f5f8508d98d5952d42ed7648c2a8f30a4da156Patrick Scott Log(msg); 93c7f5f8508d98d5952d42ed7648c2a8f30a4da156Patrick Scott} 94c7f5f8508d98d5952d42ed7648c2a8f30a4da156Patrick Scott 9572a454cd3513ac24fbdd0e0cb9ad70b86a99b801Kristian MonsenTraceLog::TraceLog() : enabled_(false), log_file_(NULL) { 9672a454cd3513ac24fbdd0e0cb9ad70b86a99b801Kristian Monsen base::ProcessHandle proc = base::GetCurrentProcessHandle(); 9772a454cd3513ac24fbdd0e0cb9ad70b86a99b801Kristian Monsen#if !defined(OS_MACOSX) 9872a454cd3513ac24fbdd0e0cb9ad70b86a99b801Kristian Monsen process_metrics_.reset(base::ProcessMetrics::CreateProcessMetrics(proc)); 9972a454cd3513ac24fbdd0e0cb9ad70b86a99b801Kristian Monsen#else 10072a454cd3513ac24fbdd0e0cb9ad70b86a99b801Kristian Monsen // The default port provider is sufficient to get data for the current 10172a454cd3513ac24fbdd0e0cb9ad70b86a99b801Kristian Monsen // process. 10272a454cd3513ac24fbdd0e0cb9ad70b86a99b801Kristian Monsen process_metrics_.reset(base::ProcessMetrics::CreateProcessMetrics(proc, 10372a454cd3513ac24fbdd0e0cb9ad70b86a99b801Kristian Monsen NULL)); 10472a454cd3513ac24fbdd0e0cb9ad70b86a99b801Kristian Monsen#endif 10572a454cd3513ac24fbdd0e0cb9ad70b86a99b801Kristian Monsen} 10672a454cd3513ac24fbdd0e0cb9ad70b86a99b801Kristian Monsen 10772a454cd3513ac24fbdd0e0cb9ad70b86a99b801Kristian MonsenTraceLog::~TraceLog() { 10872a454cd3513ac24fbdd0e0cb9ad70b86a99b801Kristian Monsen Stop(); 10972a454cd3513ac24fbdd0e0cb9ad70b86a99b801Kristian Monsen} 11072a454cd3513ac24fbdd0e0cb9ad70b86a99b801Kristian Monsen 11172a454cd3513ac24fbdd0e0cb9ad70b86a99b801Kristian Monsenbool TraceLog::OpenLogFile() { 11272a454cd3513ac24fbdd0e0cb9ad70b86a99b801Kristian Monsen FilePath::StringType pid_filename = 11372a454cd3513ac24fbdd0e0cb9ad70b86a99b801Kristian Monsen StringPrintf(kLogFileName, base::GetCurrentProcId()); 11472a454cd3513ac24fbdd0e0cb9ad70b86a99b801Kristian Monsen FilePath log_file_path; 11572a454cd3513ac24fbdd0e0cb9ad70b86a99b801Kristian Monsen if (!PathService::Get(base::DIR_EXE, &log_file_path)) 11672a454cd3513ac24fbdd0e0cb9ad70b86a99b801Kristian Monsen return false; 11772a454cd3513ac24fbdd0e0cb9ad70b86a99b801Kristian Monsen log_file_path = log_file_path.Append(pid_filename); 11872a454cd3513ac24fbdd0e0cb9ad70b86a99b801Kristian Monsen log_file_ = file_util::OpenFile(log_file_path, "a"); 11972a454cd3513ac24fbdd0e0cb9ad70b86a99b801Kristian Monsen if (!log_file_) { 12072a454cd3513ac24fbdd0e0cb9ad70b86a99b801Kristian Monsen // try the current directory 12172a454cd3513ac24fbdd0e0cb9ad70b86a99b801Kristian Monsen log_file_ = file_util::OpenFile(FilePath(pid_filename), "a"); 12272a454cd3513ac24fbdd0e0cb9ad70b86a99b801Kristian Monsen if (!log_file_) { 12372a454cd3513ac24fbdd0e0cb9ad70b86a99b801Kristian Monsen return false; 12472a454cd3513ac24fbdd0e0cb9ad70b86a99b801Kristian Monsen } 12572a454cd3513ac24fbdd0e0cb9ad70b86a99b801Kristian Monsen } 12672a454cd3513ac24fbdd0e0cb9ad70b86a99b801Kristian Monsen return true; 12772a454cd3513ac24fbdd0e0cb9ad70b86a99b801Kristian Monsen} 12872a454cd3513ac24fbdd0e0cb9ad70b86a99b801Kristian Monsen 12972a454cd3513ac24fbdd0e0cb9ad70b86a99b801Kristian Monsenvoid TraceLog::CloseLogFile() { 13072a454cd3513ac24fbdd0e0cb9ad70b86a99b801Kristian Monsen if (log_file_) { 13172a454cd3513ac24fbdd0e0cb9ad70b86a99b801Kristian Monsen file_util::CloseFile(log_file_); 13272a454cd3513ac24fbdd0e0cb9ad70b86a99b801Kristian Monsen } 13372a454cd3513ac24fbdd0e0cb9ad70b86a99b801Kristian Monsen} 13472a454cd3513ac24fbdd0e0cb9ad70b86a99b801Kristian Monsen 13572a454cd3513ac24fbdd0e0cb9ad70b86a99b801Kristian Monsenbool TraceLog::Start() { 13672a454cd3513ac24fbdd0e0cb9ad70b86a99b801Kristian Monsen if (enabled_) 13772a454cd3513ac24fbdd0e0cb9ad70b86a99b801Kristian Monsen return true; 13872a454cd3513ac24fbdd0e0cb9ad70b86a99b801Kristian Monsen enabled_ = OpenLogFile(); 13972a454cd3513ac24fbdd0e0cb9ad70b86a99b801Kristian Monsen if (enabled_) { 14072a454cd3513ac24fbdd0e0cb9ad70b86a99b801Kristian Monsen Log("var raw_trace_events = [\n"); 14172a454cd3513ac24fbdd0e0cb9ad70b86a99b801Kristian Monsen trace_start_time_ = TimeTicks::Now(); 14272a454cd3513ac24fbdd0e0cb9ad70b86a99b801Kristian Monsen timer_.Start(TimeDelta::FromMilliseconds(250), this, &TraceLog::Heartbeat); 14372a454cd3513ac24fbdd0e0cb9ad70b86a99b801Kristian Monsen } 14472a454cd3513ac24fbdd0e0cb9ad70b86a99b801Kristian Monsen return enabled_; 14572a454cd3513ac24fbdd0e0cb9ad70b86a99b801Kristian Monsen} 14672a454cd3513ac24fbdd0e0cb9ad70b86a99b801Kristian Monsen 14772a454cd3513ac24fbdd0e0cb9ad70b86a99b801Kristian Monsenvoid TraceLog::Stop() { 14872a454cd3513ac24fbdd0e0cb9ad70b86a99b801Kristian Monsen if (enabled_) { 14972a454cd3513ac24fbdd0e0cb9ad70b86a99b801Kristian Monsen enabled_ = false; 15072a454cd3513ac24fbdd0e0cb9ad70b86a99b801Kristian Monsen Log("];\n"); 15172a454cd3513ac24fbdd0e0cb9ad70b86a99b801Kristian Monsen CloseLogFile(); 15272a454cd3513ac24fbdd0e0cb9ad70b86a99b801Kristian Monsen timer_.Stop(); 15372a454cd3513ac24fbdd0e0cb9ad70b86a99b801Kristian Monsen } 15472a454cd3513ac24fbdd0e0cb9ad70b86a99b801Kristian Monsen} 15572a454cd3513ac24fbdd0e0cb9ad70b86a99b801Kristian Monsen 15672a454cd3513ac24fbdd0e0cb9ad70b86a99b801Kristian Monsenvoid TraceLog::Heartbeat() { 15772a454cd3513ac24fbdd0e0cb9ad70b86a99b801Kristian Monsen std::string cpu = StringPrintf("%.0f", process_metrics_->GetCPUUsage()); 15872a454cd3513ac24fbdd0e0cb9ad70b86a99b801Kristian Monsen TRACE_EVENT_INSTANT("heartbeat.cpu", 0, cpu); 15972a454cd3513ac24fbdd0e0cb9ad70b86a99b801Kristian Monsen} 16072a454cd3513ac24fbdd0e0cb9ad70b86a99b801Kristian Monsen 161c7f5f8508d98d5952d42ed7648c2a8f30a4da156Patrick Scottvoid TraceLog::Log(const std::string& msg) { 162c7f5f8508d98d5952d42ed7648c2a8f30a4da156Patrick Scott AutoLock lock(file_lock_); 163c7f5f8508d98d5952d42ed7648c2a8f30a4da156Patrick Scott 164c7f5f8508d98d5952d42ed7648c2a8f30a4da156Patrick Scott fprintf(log_file_, "%s", msg.c_str()); 165c7f5f8508d98d5952d42ed7648c2a8f30a4da156Patrick Scott} 166c7f5f8508d98d5952d42ed7648c2a8f30a4da156Patrick Scott 167513209b27ff55e2841eac0e4120199c23acce758Ben Murdoch} // namespace debug 168513209b27ff55e2841eac0e4120199c23acce758Ben Murdoch} // namespace base 169