2 +----------------------------------------------------------------------+
4 +----------------------------------------------------------------------+
5 | Copyright (c) 2010-2014 Facebook, Inc. (http://www.facebook.com) |
6 +----------------------------------------------------------------------+
7 | This source file is subject to version 3.01 of the PHP license, |
8 | that is bundled with this package in the file LICENSE, and is |
9 | available through the world-wide-web at the following url: |
10 | http://www.php.net/license/3_01.txt |
11 | If you did not receive a copy of the PHP license and are unable to |
12 | obtain it through the world-wide-web, please send a note to |
13 | license@php.net so we can mail you a copy immediately. |
14 +----------------------------------------------------------------------+
16 #include "hphp/util/boot-stats.h"
20 #include <folly/portability/Unistd.h>
22 #include "hphp/util/logger.h"
23 #include "hphp/util/process.h"
24 #include "hphp/util/struct-log.h"
25 #include "hphp/util/timer.h"
26 #include "hphp/util/trace.h"
30 ///////////////////////////////////////////////////////////////////////////////
32 ResourceUsage
ResourceUsage::sinceEpoch() {
34 std::chrono::duration_cast
<TimeUnit
>(
35 std::chrono::steady_clock::now().time_since_epoch()),
36 std::chrono::duration_cast
<TimeUnit
>(
37 std::chrono::microseconds(
38 HPHP::Timer::GetRusageMicros(Timer::TotalCPU
, Timer::Self
))),
39 Process::GetMemUsageMb());
42 std::string
ResourceUsage::toString() const {
43 return folly::sformat(
44 "{}ms wall, {}ms cpu, {} MB RSS",
45 std::chrono::duration_cast
<std::chrono::milliseconds
>(wall()).count(),
46 std::chrono::duration_cast
<std::chrono::milliseconds
>(cpu()).count(),
50 void ResourceUsage::operator=(const ResourceUsage
& rhs
) {
53 m_rssMb
= rhs
.m_rssMb
;
56 ResourceUsage
ResourceUsage::operator-(const ResourceUsage
& rhs
) const {
57 return ResourceUsage(m_wall
- rhs
.m_wall
,
59 m_rssMb
- rhs
.m_rssMb
);
62 ResourceUsage
ResourceUsage::operator+(const ResourceUsage
& rhs
) const {
63 return ResourceUsage(m_wall
+ rhs
.m_wall
,
65 m_rssMb
+ rhs
.m_rssMb
);
68 ///////////////////////////////////////////////////////////////////////////////
70 struct BootStats::Impl
{
71 Impl() : m_last(ResourceUsage::sinceEpoch()) {
74 void add(const std::string
& info
, ResourceUsage value
);
76 ResourceUsage
computeDeltaFromLast();
78 friend struct BootStats
;
81 // Must hold when updating m_last
82 std::mutex m_last_guard_
;
84 std::mutex m_marks_guard_
;
85 std::map
<std::string
, ResourceUsage
> m_marks
;
88 void BootStats::Impl::add(const std::string
& info
, ResourceUsage value
) {
89 std::lock_guard
<std::mutex
> lock(m_marks_guard_
);
90 m_marks
[info
] = m_marks
[info
] + value
;
93 void BootStats::Impl::dumpMarks() {
94 for (const auto& it
: m_marks
) {
96 folly::sformat("BootStats: {} = {}", it
.first
, it
.second
.toString()));
100 ResourceUsage
BootStats::Impl::computeDeltaFromLast() {
101 std::lock_guard
<std::mutex
> lock(m_last_guard_
);
102 auto now
= ResourceUsage::sinceEpoch();
103 auto ret
= now
- m_last
;
108 ///////////////////////////////////////////////////////////////////////////////
110 BootStats::Block::Block(const std::string
& name
)
111 : m_name(name
), m_start(ResourceUsage::sinceEpoch()) {
112 Logger::Info(folly::sformat("BootStats: {}...", name
));
115 BootStats::Block::~Block() {
116 auto total
= ResourceUsage::sinceEpoch() - m_start
;
119 "BootStats: {} block done, took {}", m_name
, total
.toString()));
120 BootStats::add(m_name
, total
);
123 ///////////////////////////////////////////////////////////////////////////////
125 bool BootStats::s_started
;
126 ResourceUsage
BootStats::s_start
;
127 std::unique_ptr
<BootStats::Impl
> BootStats::s_instance
;
129 void BootStats::start() {
130 BootStats::s_started
= true;
131 BootStats::s_start
= ResourceUsage::sinceEpoch();
132 BootStats::s_instance
= std::make_unique
<BootStats::Impl
>();
135 void BootStats::done() {
136 if (!s_started
) return;
139 auto total
= ResourceUsage::sinceEpoch() - s_start
;
141 folly::sformat("BootStats: all done, took {} total", total
.toString()));
143 BootStats::s_instance
->add("TOTAL", total
);
144 BootStats::s_instance
->dumpMarks();
146 if (StructuredLog::enabled()) {
147 std::lock_guard
<std::mutex
> lock(s_instance
->m_marks_guard_
);
148 StructuredLogEntry cols
;
149 for (auto sample
: s_instance
->m_marks
) {
150 cols
.setInt(sample
.first
, sample
.second
.wall().count());
151 cols
.setInt(sample
.first
+ " CPU", sample
.second
.cpu().count());
153 StructuredLog::log("hhvm_boot_timer", cols
);
155 for (auto sample
: s_instance
->m_marks
) {
156 cols
.setInt(sample
.first
, sample
.second
.rssMb() * (1 << 20)); // To bytes.
158 StructuredLog::log("hhvm_boot_memory", cols
);
162 void BootStats::mark(const std::string
& info
) {
163 if (!s_started
) return;
164 auto elapsed
= BootStats::s_instance
->computeDeltaFromLast();
166 folly::sformat("BootStats: {} done, took {}", info
, elapsed
.toString()));
167 BootStats::s_instance
->add(info
, elapsed
);
170 void BootStats::add(const std::string
& info
, const ResourceUsage value
) {
171 if (!s_started
) return;
172 BootStats::s_instance
->add(info
, value
);
175 ///////////////////////////////////////////////////////////////////////////////