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