1 /*
2  * Licensed to the Apache Software Foundation (ASF) under one
3  * or more contributor license agreements. See the NOTICE file
4  * distributed with this work for additional information
5  * regarding copyright ownership. The ASF licenses this file
6  * to you under the Apache License, Version 2.0 (the
7  * "License"); you may not use this file except in compliance
8  * with the License. You may obtain a copy of the License at
9  *
10  *   http://www.apache.org/licenses/LICENSE-2.0
11  *
12  * Unless required by applicable law or agreed to in writing,
13  * software distributed under the License is distributed on an
14  * "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
15  * KIND, either express or implied. See the License for the
16  * specific language governing permissions and limitations
17  * under the License.
18  */
19 
20 #include <thrift/Thrift.h>
21 
22 // Do nothing if virtual call profiling is not enabled
23 #if T_GLOBAL_DEBUG_VIRTUAL > 1
24 
25 // TODO: This code only works with g++ (since we rely on the fact
26 // that all std::type_info instances referring to a particular type
27 // always return the exact same pointer value from name().)
28 #ifndef __GNUG__
29 #error "Thrift virtual function profiling currently only works with gcc"
30 #endif // !__GNUG__
31 
32 // TODO: We also require glibc for the backtrace() and backtrace_symbols()
33 // functions.
34 #ifndef __GLIBC__
35 #error "Thrift virtual function profiling currently requires glibc"
36 #endif // !__GLIBC__
37 
38 #include <thrift/concurrency/Mutex.h>
39 
40 #include <ext/hash_map>
41 #include <execinfo.h>
42 #include <stdio.h>
43 
44 namespace apache {
45 namespace thrift {
46 
47 using ::apache::thrift::concurrency::Mutex;
48 using ::apache::thrift::concurrency::Guard;
49 
50 static const unsigned int MAX_STACK_DEPTH = 15;
51 
52 /**
53  * A stack trace
54  */
55 class Backtrace {
56 public:
57   Backtrace(int skip = 0);
58   Backtrace(Backtrace const& bt);
59 
operator =(Backtrace const & bt)60   void operator=(Backtrace const& bt) {
61     numCallers_ = bt.numCallers_;
62     if (numCallers_ >= 0) {
63       memcpy(callers_, bt.callers_, numCallers_ * sizeof(void*));
64     }
65   }
66 
operator ==(Backtrace const & bt) const67   bool operator==(Backtrace const& bt) const { return (cmp(bt) == 0); }
68 
hash() const69   size_t hash() const {
70     intptr_t ret = 0;
71     for (int n = 0; n < numCallers_; ++n) {
72       ret ^= reinterpret_cast<intptr_t>(callers_[n]);
73     }
74     return static_cast<size_t>(ret);
75   }
76 
cmp(Backtrace const & bt) const77   int cmp(Backtrace const& bt) const {
78     int depth_diff = (numCallers_ - bt.numCallers_);
79     if (depth_diff != 0) {
80       return depth_diff;
81     }
82 
83     for (int n = 0; n < numCallers_; ++n) {
84       int diff = reinterpret_cast<intptr_t>(callers_[n])
85                  - reinterpret_cast<intptr_t>(bt.callers_[n]);
86       if (diff != 0) {
87         return diff;
88       }
89     }
90 
91     return 0;
92   }
93 
print(FILE * f,int indent=0,int start=0) const94   void print(FILE* f, int indent = 0, int start = 0) const {
95     char** strings = backtrace_symbols(callers_, numCallers_);
96     if (strings) {
97       start += skip_;
98       if (start < 0) {
99         start = 0;
100       }
101       for (int n = start; n < numCallers_; ++n) {
102         fprintf(f, "%*s#%-2d %s\n", indent, "", n, strings[n]);
103       }
104       free(strings);
105     } else {
106       fprintf(f, "%*s<failed to determine symbols>\n", indent, "");
107     }
108   }
109 
getDepth() const110   int getDepth() const { return numCallers_ - skip_; }
111 
getFrame(int index) const112   void* getFrame(int index) const {
113     int adjusted_index = index + skip_;
114     if (adjusted_index < 0 || adjusted_index >= numCallers_) {
115       return nullptr;
116     }
117     return callers_[adjusted_index];
118   }
119 
120 private:
121   void* callers_[MAX_STACK_DEPTH];
122   int numCallers_;
123   int skip_;
124 };
125 
126 // Define the constructors non-inline, so they consistently add a single
127 // frame to the stack trace, regardless of whether optimization is enabled
Backtrace(int skip)128 Backtrace::Backtrace(int skip)
129   : skip_(skip + 1) // ignore the constructor itself
130 {
131   numCallers_ = backtrace(callers_, MAX_STACK_DEPTH);
132   if (skip_ > numCallers_) {
133     skip_ = numCallers_;
134   }
135 }
136 
Backtrace(Backtrace const & bt)137 Backtrace::Backtrace(Backtrace const& bt) : numCallers_(bt.numCallers_), skip_(bt.skip_) {
138   if (numCallers_ >= 0) {
139     memcpy(callers_, bt.callers_, numCallers_ * sizeof(void*));
140   }
141 }
142 
143 /**
144  * A backtrace, plus one or two type names
145  */
146 class Key {
147 public:
148   class Hash {
149   public:
operator ()(Key const & k) const150     size_t operator()(Key const& k) const { return k.hash(); }
151   };
152 
Key(const Backtrace * bt,const std::type_info & type_info)153   Key(const Backtrace* bt, const std::type_info& type_info)
154     : backtrace_(bt), typeName1_(type_info.name()), typeName2_(nullptr) {}
155 
Key(const Backtrace * bt,const std::type_info & type_info1,const std::type_info & type_info2)156   Key(const Backtrace* bt, const std::type_info& type_info1, const std::type_info& type_info2)
157     : backtrace_(bt), typeName1_(type_info1.name()), typeName2_(type_info2.name()) {}
158 
Key(const Key & k)159   Key(const Key& k)
160     : backtrace_(k.backtrace_), typeName1_(k.typeName1_), typeName2_(k.typeName2_) {}
161 
operator =(const Key & k)162   void operator=(const Key& k) {
163     backtrace_ = k.backtrace_;
164     typeName1_ = k.typeName1_;
165     typeName2_ = k.typeName2_;
166   }
167 
getBacktrace() const168   const Backtrace* getBacktrace() const { return backtrace_; }
169 
getTypeName() const170   const char* getTypeName() const { return typeName1_; }
171 
getTypeName2() const172   const char* getTypeName2() const { return typeName2_; }
173 
makePersistent()174   void makePersistent() {
175     // Copy the Backtrace object
176     backtrace_ = new Backtrace(*backtrace_);
177 
178     // NOTE: We don't copy the type name.
179     // The GNU libstdc++ implementation of type_info::name() returns a value
180     // that will be valid for the lifetime of the program.  (Although the C++
181     // standard doesn't guarantee this will be true on all implementations.)
182   }
183 
184   /**
185    * Clean up memory allocated by makePersistent()
186    *
187    * Should only be invoked if makePersistent() has previously been called.
188    * The Key should no longer be used after cleanup() is called.
189    */
cleanup()190   void cleanup() {
191     delete backtrace_;
192     backtrace_ = nullptr;
193   }
194 
cmp(const Key & k) const195   int cmp(const Key& k) const {
196     int ret = backtrace_->cmp(*k.backtrace_);
197     if (ret != 0) {
198       return ret;
199     }
200 
201     // NOTE: We compare just the name pointers.
202     // With GNU libstdc++, every type_info object for the same type points to
203     // exactly the same name string.  (Although this isn't guaranteed by the
204     // C++ standard.)
205     ret = k.typeName1_ - typeName1_;
206     if (ret != 0) {
207       return ret;
208     }
209     return k.typeName2_ - typeName2_;
210   }
211 
operator ==(const Key & k) const212   bool operator==(const Key& k) const { return cmp(k) == 0; }
213 
hash() const214   size_t hash() const {
215     // NOTE: As above, we just use the name pointer value.
216     // Works with GNU libstdc++, but not guaranteed to be correct on all
217     // implementations.
218     return backtrace_->hash() ^ reinterpret_cast<size_t>(typeName1_)
219            ^ reinterpret_cast<size_t>(typeName2_);
220   }
221 
222 private:
223   const Backtrace* backtrace_;
224   const char* typeName1_;
225   const char* typeName2_;
226 };
227 
228 /**
229  * A functor that determines which of two BacktraceMap entries
230  * has a higher count.
231  */
232 class CountGreater {
233 public:
operator ()(std::pair<Key,size_t> bt1,std::pair<Key,size_t> bt2) const234   bool operator()(std::pair<Key, size_t> bt1, std::pair<Key, size_t> bt2) const {
235     return bt1.second > bt2.second;
236   }
237 };
238 
239 typedef __gnu_cxx::hash_map<Key, size_t, Key::Hash> BacktraceMap;
240 
241 /**
242  * A map describing how many times T_VIRTUAL_CALL() has been invoked.
243  */
244 BacktraceMap virtual_calls;
245 Mutex virtual_calls_mutex;
246 
247 /**
248  * A map describing how many times T_GENERIC_PROTOCOL() has been invoked.
249  */
250 BacktraceMap generic_calls;
251 Mutex generic_calls_mutex;
252 
_record_backtrace(BacktraceMap * map,const Mutex & mutex,Key * k)253 void _record_backtrace(BacktraceMap* map, const Mutex& mutex, Key* k) {
254   Guard guard(mutex);
255 
256   BacktraceMap::iterator it = map->find(*k);
257   if (it == map->end()) {
258     k->makePersistent();
259     map->insert(std::make_pair(*k, 1));
260   } else {
261     // increment the count
262     // NOTE: we could assert if it->second is 0 afterwards, since that would
263     // mean we've wrapped.
264     ++(it->second);
265   }
266 }
267 
268 /**
269  * Record an unnecessary virtual function call.
270  *
271  * This method is invoked by the T_VIRTUAL_CALL() macro.
272  */
profile_virtual_call(const std::type_info & type)273 void profile_virtual_call(const std::type_info& type) {
274   int const skip = 1; // ignore this frame
275   Backtrace bt(skip);
276   Key k(&bt, type);
277   _record_backtrace(&virtual_calls, virtual_calls_mutex, &k);
278 }
279 
280 /**
281  * Record a call to a template processor with a protocol that is not the one
282  * specified in the template parameter.
283  *
284  * This method is invoked by the T_GENERIC_PROTOCOL() macro.
285  */
profile_generic_protocol(const std::type_info & template_type,const std::type_info & prot_type)286 void profile_generic_protocol(const std::type_info& template_type,
287                               const std::type_info& prot_type) {
288   int const skip = 1; // ignore this frame
289   Backtrace bt(skip);
290   Key k(&bt, template_type, prot_type);
291   _record_backtrace(&generic_calls, generic_calls_mutex, &k);
292 }
293 
294 /**
295  * Print the recorded profiling information to the specified file.
296  */
profile_print_info(FILE * f)297 void profile_print_info(FILE* f) {
298   typedef std::vector<std::pair<Key, size_t> > BacktraceVector;
299 
300   CountGreater is_greater;
301 
302   // Grab both locks for the duration of the print operation,
303   // to ensure the output is a consistent snapshot of a single point in time
304   Guard generic_calls_guard(generic_calls_mutex);
305   Guard virtual_calls_guard(virtual_calls_mutex);
306 
307   // print the info from generic_calls, sorted by frequency
308   //
309   // We print the generic_calls info ahead of virtual_calls, since it is more
310   // useful in some cases.  All T_GENERIC_PROTOCOL calls can be eliminated
311   // from most programs.  Not all T_VIRTUAL_CALLs will be eliminated by
312   // converting to templates.
313   BacktraceVector gp_sorted(generic_calls.begin(), generic_calls.end());
314   std::sort(gp_sorted.begin(), gp_sorted.end(), is_greater);
315 
316   for (BacktraceVector::const_iterator it = gp_sorted.begin(); it != gp_sorted.end(); ++it) {
317     Key const& key = it->first;
318     size_t const count = it->second;
319     fprintf(f,
320             "T_GENERIC_PROTOCOL: %zu calls to %s with a %s:\n",
321             count,
322             key.getTypeName(),
323             key.getTypeName2());
324     key.getBacktrace()->print(f, 2);
325     fprintf(f, "\n");
326   }
327 
328   // print the info from virtual_calls, sorted by frequency
329   BacktraceVector vc_sorted(virtual_calls.begin(), virtual_calls.end());
330   std::sort(vc_sorted.begin(), vc_sorted.end(), is_greater);
331 
332   for (BacktraceVector::const_iterator it = vc_sorted.begin(); it != vc_sorted.end(); ++it) {
333     Key const& key = it->first;
334     size_t const count = it->second;
335     fprintf(f, "T_VIRTUAL_CALL: %zu calls on %s:\n", count, key.getTypeName());
336     key.getBacktrace()->print(f, 2);
337     fprintf(f, "\n");
338   }
339 }
340 
341 /**
342  * Print the recorded profiling information to stdout.
343  */
profile_print_info()344 void profile_print_info() {
345   profile_print_info(stdout);
346 }
347 
348 /**
349  * Write a BacktraceMap as Google CPU profiler binary data.
350  */
profile_write_pprof_file(FILE * f,BacktraceMap const & map)351 static void profile_write_pprof_file(FILE* f, BacktraceMap const& map) {
352   // Write the header
353   uintptr_t header[5] = {0, 3, 0, 0, 0};
354   fwrite(&header, sizeof(header), 1, f);
355 
356   // Write the profile records
357   for (BacktraceMap::const_iterator it = map.begin(); it != map.end(); ++it) {
358     uintptr_t count = it->second;
359     fwrite(&count, sizeof(count), 1, f);
360 
361     Backtrace const* bt = it->first.getBacktrace();
362     uintptr_t num_pcs = bt->getDepth();
363     fwrite(&num_pcs, sizeof(num_pcs), 1, f);
364 
365     for (uintptr_t n = 0; n < num_pcs; ++n) {
366       void* pc = bt->getFrame(n);
367       fwrite(&pc, sizeof(pc), 1, f);
368     }
369   }
370 
371   // Write the trailer
372   uintptr_t trailer[3] = {0, 1, 0};
373   fwrite(&trailer, sizeof(trailer), 1, f);
374 
375   // Write /proc/self/maps
376   // TODO(simpkins): This only works on linux
377   FILE* proc_maps = fopen("/proc/self/maps", "r");
378   if (proc_maps) {
379     uint8_t buf[4096];
380     while (true) {
381       size_t bytes_read = fread(buf, 1, sizeof(buf), proc_maps);
382       if (bytes_read == 0) {
383         break;
384       }
385       fwrite(buf, 1, bytes_read, f);
386     }
387     fclose(proc_maps);
388   }
389 }
390 
391 /**
392  * Write the recorded profiling information as pprof files.
393  *
394  * This writes the information using the Google CPU profiler binary data
395  * format, so it can be analyzed with pprof.  Note that information about the
396  * protocol/transport data types cannot be stored in this file format.
397  *
398  * See http://code.google.com/p/google-perftools/ for more details.
399  *
400  * @param gen_calls_f     The information about calls to
401  *                        profile_generic_protocol() will be written to this
402  *                        file.
403  * @param virtual_calls_f The information about calls to
404  *                        profile_virtual_call() will be written to this file.
405  */
profile_write_pprof(FILE * gen_calls_f,FILE * virtual_calls_f)406 void profile_write_pprof(FILE* gen_calls_f, FILE* virtual_calls_f) {
407   typedef std::vector<std::pair<Key, size_t> > BacktraceVector;
408 
409   CountGreater is_greater;
410 
411   // Grab both locks for the duration of the print operation,
412   // to ensure the output is a consistent snapshot of a single point in time
413   Guard generic_calls_guard(generic_calls_mutex);
414   Guard virtual_calls_guard(virtual_calls_mutex);
415 
416   // write the info from generic_calls
417   profile_write_pprof_file(gen_calls_f, generic_calls);
418 
419   // write the info from virtual_calls
420   profile_write_pprof_file(virtual_calls_f, virtual_calls);
421 }
422 }
423 } // apache::thrift
424 
425 #endif // T_GLOBAL_PROFILE_VIRTUAL > 0
426