/src/zeek/src/ScriptProfile.cc
Line | Count | Source |
1 | | // See the file "COPYING" in the main distribution directory for copyright. |
2 | | |
3 | | #include "zeek/ScriptProfile.h" |
4 | | |
5 | | #include <cinttypes> |
6 | | |
7 | | namespace zeek { |
8 | | |
9 | | namespace detail { |
10 | | |
11 | 0 | void ScriptProfile::StartActivation() { |
12 | 0 | NewCall(); |
13 | |
|
14 | 0 | uint64_t start_memory; |
15 | 0 | util::get_memory_usage(&start_memory, nullptr); |
16 | 0 | start_stats.SetStats(util::curr_CPU_time(), start_memory); |
17 | 0 | } |
18 | | |
19 | 0 | void ScriptProfile::EndActivation(const std::string& stack) { |
20 | 0 | uint64_t end_memory; |
21 | 0 | util::get_memory_usage(&end_memory, nullptr); |
22 | |
|
23 | 0 | delta_stats.SetStats(util::curr_CPU_time() - start_stats.CPUTime(), end_memory - start_stats.Memory()); |
24 | |
|
25 | 0 | AddIn(&delta_stats, false, stack); |
26 | 0 | } |
27 | | |
28 | 0 | void ScriptProfile::ChildFinished(const ScriptProfile* child) { |
29 | 0 | child_stats.AddIn(child->DeltaCPUTime(), child->DeltaMemory()); |
30 | 0 | } |
31 | | |
32 | 0 | void ScriptProfile::Report(FILE* f, bool with_traces) const { |
33 | 0 | std::string l; |
34 | |
|
35 | 0 | if ( loc.FirstLine() == 0 ) |
36 | | // Rather than just formatting the no-location loc, we'd like |
37 | | // a version that doesn't have a funky "line 0" in it, nor |
38 | | // an embedded blank. |
39 | 0 | l = "<no-location>"; |
40 | 0 | else |
41 | 0 | l = util::fmt("%s:%d", loc.FileName(), loc.FirstLine()); |
42 | |
|
43 | 0 | std::string ftype = is_BiF ? "BiF" : func->GetType()->FlavorString(); |
44 | 0 | std::string call_stacks; |
45 | |
|
46 | 0 | if ( with_traces ) { |
47 | 0 | std::string calls; |
48 | 0 | std::string counts; |
49 | 0 | std::string cpu; |
50 | 0 | std::string memory; |
51 | |
|
52 | 0 | for ( const auto& [s, stats] : Stacks() ) { |
53 | 0 | calls += util::fmt("%s|", s.c_str()); |
54 | 0 | counts += util::fmt("%d|", stats.call_count); |
55 | 0 | cpu += util::fmt("%f|", stats.cpu_time); |
56 | 0 | memory += util::fmt("%" PRIu64 "|", stats.memory); |
57 | 0 | } |
58 | |
|
59 | 0 | calls.pop_back(); |
60 | 0 | counts.pop_back(); |
61 | 0 | cpu.pop_back(); |
62 | 0 | memory.pop_back(); |
63 | |
|
64 | 0 | call_stacks = util::fmt("\t%s\t%s\t%s\t%s", calls.c_str(), counts.c_str(), cpu.c_str(), memory.c_str()); |
65 | 0 | } |
66 | |
|
67 | 0 | fprintf(f, "%s\t%s\t%s\t%d\t%.06f\t%.06f\t%" PRIu64 "\t%" PRIu64 "\t%s\n", Name().c_str(), l.c_str(), ftype.c_str(), |
68 | 0 | NumCalls(), CPUTime(), child_stats.CPUTime(), Memory(), child_stats.Memory(), call_stacks.c_str()); |
69 | 0 | } |
70 | | |
71 | 0 | void ScriptProfileStats::AddIn(const ScriptProfileStats* eps, bool bump_num_calls, const std::string& stack) { |
72 | 0 | if ( bump_num_calls ) |
73 | 0 | ncalls += eps->NumCalls(); |
74 | |
|
75 | 0 | CPU_time += eps->CPUTime(); |
76 | 0 | memory += eps->Memory(); |
77 | |
|
78 | 0 | if ( ! stack.empty() ) { |
79 | 0 | auto& data = stacks[stack]; |
80 | 0 | data.call_count++; |
81 | 0 | data.cpu_time += eps->CPUTime(); |
82 | 0 | data.memory += eps->Memory(); |
83 | 0 | } |
84 | 0 | } |
85 | | |
86 | 0 | ScriptProfileMgr::ScriptProfileMgr(FILE* _f) : f(_f), non_scripts() { non_scripts.StartActivation(); } |
87 | | |
88 | 0 | ScriptProfileMgr::~ScriptProfileMgr() { |
89 | 0 | ASSERT(call_stack.empty()); |
90 | | |
91 | 0 | non_scripts.EndActivation(); |
92 | |
|
93 | 0 | ScriptProfileStats total_stats; |
94 | 0 | ScriptProfileStats BiF_stats; |
95 | 0 | std::unordered_map<const Func*, ScriptProfileStats> func_stats; |
96 | |
|
97 | 0 | std::string call_stack_header; |
98 | 0 | std::string call_stack_types; |
99 | 0 | std::string call_stack_nulls; |
100 | |
|
101 | 0 | if ( with_traces ) { |
102 | 0 | call_stack_header = "\tstacks\tstack_calls\tstack_CPU\tstack_memory"; |
103 | 0 | call_stack_types = "\tstring\tstring\tstring\tstring"; |
104 | 0 | call_stack_nulls = "\t-\t-\t-\t-"; |
105 | 0 | } |
106 | |
|
107 | 0 | fprintf(f, |
108 | 0 | "#fields\tfunction\tlocation\ttype\tncall\ttot_CPU\tchild_CPU\ttot_Mem\tchild_" |
109 | 0 | "Mem%s\n", |
110 | 0 | call_stack_header.c_str()); |
111 | 0 | fprintf(f, "#types\tstring\tstring\tstring\tcount\tinterval\tinterval\tcount\tcount%s\n", call_stack_types.c_str()); |
112 | |
|
113 | 0 | for ( auto o : objs ) { |
114 | 0 | auto p = profiles[o].get(); |
115 | 0 | profiles[o]->Report(f, with_traces); |
116 | |
|
117 | 0 | total_stats.AddInstance(); |
118 | 0 | total_stats.AddIn(p); |
119 | |
|
120 | 0 | if ( p->IsBiF() ) { |
121 | 0 | BiF_stats.AddInstance(); |
122 | 0 | BiF_stats.AddIn(p); |
123 | 0 | } |
124 | 0 | else { |
125 | 0 | ASSERT(body_to_func.contains(o)); |
126 | 0 | auto func = body_to_func[o]; |
127 | |
|
128 | 0 | if ( ! func_stats.contains(func) ) |
129 | 0 | func_stats[func] = ScriptProfileStats(func->GetName()); |
130 | |
|
131 | 0 | func_stats[func].AddIn(p); |
132 | 0 | } |
133 | 0 | } |
134 | | |
135 | 0 | for ( auto& fs : func_stats ) { |
136 | 0 | auto func = fs.first; |
137 | 0 | auto& fp = fs.second; |
138 | 0 | auto n = func->GetBodies().size(); |
139 | 0 | if ( n > 1 ) |
140 | 0 | fprintf(f, "%s\t%zu-locations\t%s\t%d\t%.06f\t%0.6f\t%" PRIu64 "\t%lld%s\n", fp.Name().c_str(), n, |
141 | 0 | func->GetType()->FlavorString().c_str(), fp.NumCalls(), fp.CPUTime(), 0.0, fp.Memory(), 0LL, |
142 | 0 | call_stack_nulls.c_str()); |
143 | 0 | } |
144 | |
|
145 | 0 | fprintf(f, "all-BiFs\t%d-locations\tBiF\t%d\t%.06f\t%.06f\t%" PRIu64 "\t%lld%s\n", BiF_stats.NumInstances(), |
146 | 0 | BiF_stats.NumCalls(), BiF_stats.CPUTime(), 0.0, BiF_stats.Memory(), 0LL, call_stack_nulls.c_str()); |
147 | |
|
148 | 0 | fprintf(f, "total\t%d-locations\tTOTAL\t%d\t%.06f\t%.06f\t%" PRIu64 "\t%lld%s\n", total_stats.NumInstances(), |
149 | 0 | total_stats.NumCalls(), total_stats.CPUTime(), 0.0, total_stats.Memory(), 0LL, call_stack_nulls.c_str()); |
150 | |
|
151 | 0 | fprintf(f, "non-scripts\t<no-location>\tTOTAL\t%d\t%.06f\t%.06f\t%" PRIu64 "\t%lld%s\n", non_scripts.NumCalls(), |
152 | 0 | non_scripts.CPUTime(), 0.0, non_scripts.Memory(), 0LL, call_stack_nulls.c_str()); |
153 | |
|
154 | 0 | if ( f != stdout ) |
155 | 0 | fclose(f); |
156 | 0 | } |
157 | | |
158 | 0 | void ScriptProfileMgr::StartInvocation(const Func* f, const detail::StmtPtr& body) { |
159 | 0 | if ( call_stack.empty() ) |
160 | 0 | non_scripts.EndActivation(); |
161 | |
|
162 | 0 | const Obj* o = body ? static_cast<Obj*>(body.get()) : f; |
163 | 0 | auto associated_prof = profiles.find(o); |
164 | 0 | ScriptProfile* ep; |
165 | |
|
166 | 0 | if ( associated_prof == profiles.end() ) { |
167 | 0 | auto new_ep = std::make_unique<ScriptProfile>(f, body); |
168 | 0 | ep = new_ep.get(); |
169 | 0 | profiles[o] = std::move(new_ep); |
170 | 0 | objs.push_back(o); |
171 | |
|
172 | 0 | if ( body ) |
173 | 0 | body_to_func[o] = f; |
174 | 0 | } |
175 | 0 | else |
176 | 0 | ep = associated_prof->second.get(); |
177 | |
|
178 | 0 | ep->StartActivation(); |
179 | 0 | call_stack.push_back(ep); |
180 | 0 | } |
181 | | |
182 | 0 | void ScriptProfileMgr::EndInvocation() { |
183 | 0 | ASSERT(! call_stack.empty()); |
184 | 0 | auto ep = call_stack.back(); |
185 | |
|
186 | 0 | call_stack.pop_back(); |
187 | |
|
188 | 0 | std::string stack_string = ep->Name(); |
189 | 0 | for ( const auto& sep : call_stack ) { |
190 | 0 | stack_string.append(";"); |
191 | 0 | stack_string.append(sep->Name()); |
192 | 0 | } |
193 | |
|
194 | 0 | ep->EndActivation(stack_string); |
195 | |
|
196 | 0 | if ( call_stack.empty() ) |
197 | 0 | non_scripts.StartActivation(); |
198 | 0 | else { |
199 | 0 | auto parent = call_stack.back(); |
200 | 0 | parent->ChildFinished(ep); |
201 | 0 | } |
202 | 0 | } |
203 | | |
204 | | std::unique_ptr<ScriptProfileMgr> spm; |
205 | | |
206 | | } // namespace detail |
207 | | |
208 | 0 | void activate_script_profiling(const char* fn, bool with_traces) { |
209 | 0 | FILE* f; |
210 | |
|
211 | 0 | if ( fn ) { |
212 | 0 | f = fopen(fn, "w"); |
213 | 0 | if ( ! f ) { |
214 | 0 | fprintf(stderr, "ERROR: Can't open %s to record scripting profile\n", fn); |
215 | 0 | exit(1); |
216 | 0 | } |
217 | 0 | } |
218 | 0 | else |
219 | 0 | f = stdout; |
220 | | |
221 | 0 | detail::spm = std::make_unique<detail::ScriptProfileMgr>(f); |
222 | |
|
223 | 0 | if ( with_traces ) |
224 | 0 | detail::spm->EnableTraces(); |
225 | 0 | } |
226 | | |
227 | | } // namespace zeek |