Call count profiling for estimation of relative hotness of function call frequency

Instances of a call stack executing in a database management system and separated by a sampling interval can be compared and upwardly traversed until reaching a point of difference between the instances. A call counter can be incremented for each new frame identified in the second instance of the call stack since the point of difference such that relative call count frequencies of multiple frames (which can include function calls) can be determined. Systems, methods, and computer program products are described.

TECHNICAL FIELD

The subject matter described herein relates to estimation of function call frequency for functions and/or other computing workloads imposed on a computing system, such as for example a database management system.

BACKGROUND

Performance of computing loads in a computing system, such as for example a database management system (DBMS), can be improved if an intrinsic capability to perform time-based profiling of central processing unit utilization and wait latency incurred by execution of workloads imposed on the computing system is available. In addition, a determination of how often the “hot” routines (e.g. the most frequently used routines) in a function profile output are invoked can also be advantageous in determining how to best optimize the runtime performance of the DBMS. For example, some functions invoked by a DBMS may result in particularly high central processing unit (CPU) utilization because they are called very frequently, while other functions that are not called so often may result in extended runtimes for other reasons (such as, for example, nested programming loops). In the former case, there may be a need to optimize the context of caller functions (e.g. to reduce unnecessary calls to a callee function, or to re-factor a design to reduce unnecessarily repetitive calls). The latter case may be indicative of a need to investigate one or more hot program lines of a callee function to debug slow running pieces of logic.

SUMMARY

Implementations of the current subject matter relate to providing a technique to help diagnose and solve resource use overheads that may result from unnecessarily frequent function calls. In one aspect, a method includes comparing a first sampled instance and a second sampled instance of a call stack executing in a database management system at a first time and a second time separated by a sampling interval. The method further includes upwardly traversing the first sampled instance (i.e. older in time) and the second sampled instance (i.e. newer in time) of the call stack using a bottom-most function or frame in the call stack as a starting point until reaching a difference between the first instance and the second instance, and incrementing a call counter for each new function or frame identified in the second instance of the call stack since the point of difference.

In optional variations, one or more of the following features can be included in any feasible combination. The upwardly traversing of the first instance and the second instance of the call stack can include eliminating of frames which are called in the same order in both of the first instance and the second instance. The call counters for the plurality of frames can be stored in a data structure. The first call stack can occurs on a previous sample run, and a method can further include attaching the first call stack into a heap memory of each executing light weight process thread for the call stack.

The details of one or more variations of the subject matter described herein are set forth in the accompanying drawings and the description below. Other features and advantages of the subject matter described herein will be apparent from the description and drawings, and from the claims. While certain features of the currently disclosed subject matter are described for illustrative purposes in relation to a high speed, in-memory database system, it should be readily understood that such features are not intended to be limiting. Additionally, this disclosure uses the term “DBMS” for convenience in describing various examples. However, it will be understood that certain features of the current subject matter may also be applicable to other computing systems since the technique of profiling function call stacks is generic in nature. The claims that follow this disclosure are intended to define the scope of the protected subject matter.

DETAILED DESCRIPTION

A profiler is an example of an approach via which function call profiling data can be collected, for example via a stack-based sampling approach in which a dedicated profiler thread of the running process traverses all the executing threads of the process by firing signals and collecting information on the running stack of each thread using a fast custom implementation of unwinding the program stacks. A stack, as the term is used herein, is a call chain, e.g. an order in which functions are called to perform operations on a database. In an analytical environment such as with online analytical processing (OLAP), multiple threads can be involved in query execution. A profiling approach can be especially useful for performance analysis situations that demand higher visibility into the relative execution overheads of data server routines. For a modern, high speed, in-memory database system (such as for example the HANA architecture available from SAP SE of Walldorf, Germany), a profiler technique can be quite fast. With a reasonably high-resolution sampling interval of 1 millisecond (ms) as a minimum profiling interval, the profiler can incur approximately 10% overheads depending on the usage scenario.

The profiling process can be understood by reference to three phases: a data population phase, a sample aggregation phase, and a profile visualization phase. However, it will be understood that the described operations may be performed using fewer (or more) than three distinct phases.

In a data population phase of a profiler, logic is implemented to collect CPU samples associated with function stacks. The profiler regularly iterates over all threads/contexts, but skips “inactive” threads that are either waiting for work and for which no other thread or other database or application component is waiting for results. Next, call stacks of the threads are obtained to allow implicit determinations of whether the thread is in a wait state. The profiler receives User and System time in microseconds via a /proc file system (e.g. a pseudo-file system which provides an interface to kernel data structures for presenting information about processes and other system information in a hierarchical file-like structure, and which can be implemented in some examples as /proc/<pid>/stat) and also stores a wait time for the profiled threads. Threads blocked in critical sections (e.g. synchronization of multiple threads sharing a same resource via a mutex) contribute to the wait time. The call stack can be used as the key in a fast in-memory data structure like hash map, and are mapped to USER/SYSTEM/WAIT times. For example, the user and system time of an executing thread are read on Linux from “cat /proc/7278/stat” from the parameters utime and stime respectively. The utime parameter can indicate an amount of time that a process has been scheduled in user mode, measured in clock ticks (e.g. divide by sysconf(_SC_CLK_TCK)), which can include guest time (time spent running a virtual CPU), so that applications that are not aware of the guest time field do not lose that time from their calculations. The stime parameter can indicate an amount of time that a process has been scheduled in kernel mode, measured in clock ticks (e.g. divide by sysconf(_SC_CLK_TCK).

A sample aggregation phase can include operations for implementing logic and data structures to aggregate the samples and stacks for the profiler. A map of nodes is created where each frame of any of the call stacks is mapped to an “inclusive” or an “exclusive” time of one of three types: user, system and wait. Only the topmost frame in a call stack contributes to the three “exclusive” times. All other frames, including an artificial “0” frame denoting “root,” can contribute to the three “inclusive” times. An “edge” map can be created where each caller frame (parent function) creates an edge to its callee frame (child function). As used herein, a frame can include a call to a function. The edge can be annotated with “inclusive” times from corresponding call stack in hash map.FIG. 1shows an illustrative example of a call stack100that triggers increments of exclusive and inclusive times of a sample aggregation phase of a profiler approach. For the topmost routine (#0), both the <Exclusive> and <Inclusive> counters are incremented. For all the other routines in the stack, only the <Inclusive> counters are incremented.

A profile visualization phase of a profiler approach can include the logic to create a graphical representation (e.g. a *.dot file) to report the profiling result to the end user. A dotty (*.dot) file is created as per the following rules. Only nodes/symbols contributing above a given minimum percentage (e.g. 1%) are retained, while others are filtered and hidden from the report. Additionally, nodes from the node map are printed in dotty format, including the (C++ demangled) frame name, inclusive times, and exclusive times. Two graphs can be created and/or shown: one for waiting threads and the other for busy threads. A “busy” CPU graph can show both system and user times. Edges from the node map can be printed in a dotty format. The label of the edges can be the % fraction of the inclusive time of callee stored in the edge map with respect to the inclusive time of caller. In case of a CPU profile, the inclusive time of the callee would equal a sum total of <User> and <System> times.

FIG. 2shows a diagram200illustrating features of an example of a CPU profile report created by profiler approach. The CPU profile report is generated with external user commands run within an administrator utility usable by a database administrator (e.g. the SAP HANA Console Admin available in the SAP HANA database product available from SAP SE of Walldorf, Germany). Commands available within such a utility can include starting/stopping the profiler, profiler print, and the like. A CPU profile report can contain information about the relative time spent in individual functions and the critical path of hotspots (marked in shades of grey in increasing order of hotness ranging from light shade to darker shade).

In many situations, it may also be found helpful to be able to determine how often the hot routines in a function profile output are invoked. Some functions may have a particularly high percentage of CPU utilization because they are called very frequently, while some others are not called so often but suffer longer runtimes instead. The former is a case in which optimization of the context of callers (e.g. reducing unnecessary calls to a callee, or refactoring a loop-based design to reduce the repetitive calls) may be needed, while the latter is an example in which investigation (or drilldown) into one or more “hot” program lines of the callee and debugging of any slow running pieces of logic is advisable. Superior insights into any CPU related slowdown can be achieved if the profiling tool can also provide estimates on how often a particular function may have been called during a sampling interval. It is also important to control how much of a performance penalty such a feature of function profiler will impose on the query runtime when activated.

Consistent with some implementations of the current subject matter, a stack-based sampling approach can include treating each consecutive instance of a call stack from the topmost function to the bottommost as a single call, and different stacks as new calls. Though the number of calls estimated with such a method may be several magnitudes lower than the actual value, the resultant count can be helpful in situations requiring relative comparisons (e.g. Run A vs Run B). A potentially valuable advantage of such approach in certain high-speed in-memory DBMS implementations (such as for example SAP HANA) is the ability to sample a fixed thread and compare the stack routines across readings to detect any plausible changes that suggest and possibly imply call boundaries. A light weight process (LWP) thread-based model can result in a significant advantage in terms of such event-based inference techniques. The feature may be externally activated using an additional switch interface (call count=ON|OFF) added with the profiler's start command. For instance, an example of pseudocode for implementing call count features via an administrative command interface, such as is discussed above, can be expressed as hdbcons> profiler start --callcount on.

In some implementations of the current subject matter that include a call count feature, a call stack from a last sample run can be attached into the heap memory of each executing LWP thread. During the next sample run, for each thread the previous call stack can be compared versus a current call stack for the thread. The shared portion of a call stack (e.g. as viewed in a bottom-up order of call sequence) can be ignored for purposes of the relative call-count estimation, while the remainder portion from the later call stack is interpreted as “new” and “interesting” events and used for populating the call counts.

This approach can be better understood by reference to a “previous” (e.g. older) call stack #(N)300and a “current” (e.g. newer) call stack #(N+1)350shown respectively inFIG. 3AandFIG. 3B. The unbolded frames in the two stacks (#5 to #8 in the previous call stack300and #4 to #7 in the current call stack350) are identical, starting from the root until the first different frame (an example of an “excluded” frame). For the bolded frames in the current call stack350, the number of calls is increment by +1 in a structure “map<void*, size_t>” that maps <frame pointer> to <# of calls>. The table400inFIG. 4illustrates a state of the counters after a (N+1)th call stack (e.g. the current call stack350inFIG. 3B) assuming these functions were never called before.

As noted before, the approach used in implementations of the current subject matter is sample-based technique in which the “sampled call count” is usually far lower than “real call count”. The measurement is nevertheless valuable, for example in a case in which there is a need to check whether there an infinite loop within a routine or if it is instead genuinely called several times. The former scenario would show a negligible call count, while the latter would reflect a very high estimated value. It may be noted that compiler-inlined functions would not show up in profiling reports, and would instead contribute to the caller's runtime (or call counts).

FIG. 5shows a diagram illustrating a node graph500listing results of a profiler approach enhanced with call count profiling consistent with implementations of the current subject matter. As can be seen from comparison of the call count505for the function ltt::allocator::allocate in the node graph500, which represents the estimated number of calls to allocators of a Memory Manager, with the value510in the table515labeled Memory Information, which corresponds to a cell position with a row named “Sum” and a column named “#a” representing an actual number of allocation calls for this function, there is a sizable difference between the two values. The reason behind this difference is the use of a user-specified non-zero sampling interval (e.g. ≧1 milliseconds) of delay induced between collections of two successive call stacks by the profiler. Doing so can result in loss of the new samples that might have executed on top (or intermediate portions) of the stack within this sampling interval. Such continuous changes in the call chain would never be captured, since an approach consistent with implementations of the current subject matter only looks at two end points of a sampling window and compares the respective stack frames at those positions.

Reducing the sampling interval to a near-zero wait generally improves the accuracy of counts by a tiny margin. For example, the call count of ltt::allocator::allocate in the above example may be improved by about 4% with such a change. This small benefit in accuracy may result because a single iteration of the stack collection across all threads itself adds up a non-trivial delay. However, in other implementations in which the overhead of the callstack collection across all threads can be further minimized, a higher boost in the accuracy of estimated call counts may be obtained by reducing the sampling interval. However, it should be noted that this increased accuracy can come at a price of higher overheads imposed by the profiler on the query runtimes.

FIG. 6shows a process flow chart600illustrating features of a process constituent with implementations of the current subject matter. At610, a first instance and a second instance of a call stack executing in a database management system are compared at a first time and a second time separated by a sampling interval. Using a bottom-most frame in the call stack as a starting point, the first instance and the second instance of the call stack are upwardly traversed at620until reaching a point of difference between the first instance and the second instance. A call counter is incremented at630for each new frame identified in the second instance of the call stack since the point of the difference. At640, the call counters for each of the new frames (and for any other frame for which a counter exists) can be stored in a data structure, which can be a fast internal data structure such as a hashmap. Relative call count frequencies can be estimated based on the call counters for the plurality of frames, and such information can optionally be displayed graphically using an approach similar to those depicted inFIG. 5.

Implementations of the current subject matter can provide a variety of technical advantages. For example, the provided sampling method to estimate function call counts of multi-threaded programs is low cost (in terms of CPU and/or memory usage) relative to other possible solutions. The current subject matter provides a DBMS-integrated (internal) profiler with add-on of counting capability that neither relies on external nor third-party tools nor requires special permission (e.g. superuser or the like) to initiate profiling. No hardware or platform assumptions are required (as can be the case with an external solution, such as for example external solutions like the Vtune product available from Intel Corporation of Santa Clara, Calif.). Such external solutions can calculate call counts statistically (e.g. exact call count values are not generated). A ‘zero’ value means that the function was called just a relatively few times and there might still be 100s (or 1000s) of calls. Additionally, call count collection for such solutions is generally done using hardware counters and hence imposes additional overheads of 20% or more, albeit much lower than the situation if precise call counts were collected with binary instrumentation or using debugger (e.g. GDB).

The provided solution can work seamlessly across various specific Linux implementations. Additionally, the solution does not require use of any special library or system calls, instead relying completely on an event detection mechanism using a conventional program call stack. Because the stack is collected using custom code (C/ASM) it can be unwound very quickly. The provided intrinsic application-based profiler does not require special installations, usage trainings, license costs, or the like. The results can be easily collected by customer-side DBAs/Analysts and reported to DBMS product engineering teams to help debug cases of performance slowdown.

FIG. 7shows a diagram illustrating various features of an example computing environment700in which the current subject matter can be implemented. A database management system702can include various functions704that can be called in various orders as part of call stacks706A,706B, . . . ,706N to perform operations on a database708. A profiler710can be executed on the one or more processors executing the features of the DBMS702, and can implement one or more of the features described above.