add line_profiler impl

include/pocketpy/profiler.h

@@ -1,9 +1,38 @@
 #pragma once
 
+#include "frame.h"
+
 namespace pkpy {
 
-struct LineProfiler{
+struct LineRecord{
+    int line;
+    SourceData* src;
 
+    i64 hits;
+    clock_t time;
+
+    clock_t time_per_hit() const {
+        return time / hits;
+    }
+
+    LineRecord(int line, SourceData* src): line(line), src(src), hits(0), time(0) {}
+
+    std::string_view line_content() const;
+};
+
+struct LineProfiler{
+    clock_t prev_time;
+    LineRecord* prev_record;
+    int prev_line;
+
+    // filename -> records
+    std::map<std::string_view, std::map<int, LineRecord>> records;
+
+    void begin();
+    void _step(Frame* frame);
+    void _step_end();
+    void end();
+    Str stats();
 };
 
 } // namespace pkpy

src/ceval.cpp

@@ -67,7 +67,8 @@ PyObject* VM::_run_top_frame(){
 {
 
 #define CEVAL_STEP_CALLBACK() \
-    if(_ceval_on_step) _ceval_on_step(this, frame.get(), byte);
+    if(_ceval_on_step) _ceval_on_step(this, frame.get(), byte); \
+    if(_profiler) _profiler->_step(frame.get());
 
 #define DISPATCH_OP_CALL() { frame = top_frame(); goto __NEXT_FRAME; }
 __NEXT_FRAME:

src/modules.cpp

@@ -254,10 +254,12 @@ struct LineProfilerW{
             vm->ValueError("only one profiler can be enabled at a time");
         }
         vm->_profiler = &profiler;
+        profiler.begin();
     }
 
     void disable_by_count(VM* vm){
         vm->_profiler = nullptr;
+        profiler.end();
     }
 
     static void _register(VM* vm, PyObject* mod, PyObject* type){
@@ -273,15 +275,17 @@ struct LineProfilerW{
             self.enable_by_count(vm);
             PyObject* func = view[1];
             const Tuple& args = CAST(Tuple&, view[2]);
-            for(PyObject* arg : args) vm->s_data.push(arg);
             vm->s_data.push(func);
+            vm->s_data.push(PY_NULL);
+            for(PyObject* arg : args) vm->s_data.push(arg);
             PyObject* ret = vm->vectorcall(args.size());
             self.disable_by_count(vm);
             return ret;
         });
 
         vm->bind(type, "print_stats(self)", [](VM* vm, ArgsView args){
-            // ...
+            LineProfilerW& self = PK_OBJ_GET(LineProfilerW, args[0]);
+            vm->stdout_write(self.profiler.stats());
             return vm->None;
         });
     }

src/profiler.cpp

@@ -2,6 +2,84 @@
 
 namespace pkpy{
 
+static std::string left_pad(std::string s, int width){
+    int n = width - s.size();
+    if(n <= 0) return s;
+    return std::string(n, ' ') + s;
+}
 
+static std::string to_string_1f(double x){
+    char buf[32];
+    snprintf(buf, 32, "%.1f", x);
+    return buf;
+}
+
+std::string_view LineRecord::line_content() const {
+    auto [_0, _1] = src->_get_line(line);
+    return std::string_view(_0, _1-_0);
+}
+
+void LineProfiler::begin(){
+    prev_time = 0;
+    prev_record = nullptr;
+    prev_line = -1;
+    records.clear();
+}
+
+void LineProfiler::_step(Frame *frame){
+    std::string_view filename = frame->co->src->filename.sv();
+    int line = frame->co->lines[frame->_ip];
+    // std::string_view function = frame->co->name.sv();
+
+    if(prev_record == nullptr){
+        prev_time = clock();
+    }else{
+        _step_end();
+    }
+
+    std::map<int, LineRecord>& file_records = records[filename];
+    auto [it, ok] = file_records.insert({line, LineRecord(line, frame->co->src.get())});
+    prev_record = &(it->second);
+}
+
+void LineProfiler::_step_end(){
+    clock_t now = clock();
+    clock_t delta = now - prev_time;
+    prev_time = now;
+    if(prev_record->line != prev_line){
+        prev_record->hits++;
+        prev_line = prev_record->line;
+    }
+    prev_record->time += delta;
+}
+
+void LineProfiler::end(){
+    _step_end();
+}
+
+Str LineProfiler::stats(){
+    SStream ss;
+    for(auto& [filename, file_records] : records){
+        clock_t total_time = 0;
+        for(auto& [line, record] : file_records){
+            total_time += record.time;
+        }
+        ss << "Total time: " << (double)total_time / CLOCKS_PER_SEC << "s\n";
+        ss << "File: " << filename << "\n";
+        // ss << "Function: " << "<?>" << "at line " << -1 << "\n";
+        ss << "Line #      Hits         Time  Per Hit   % Time  Line Contents\n";
+        ss << "==============================================================\n";
+        for(auto& [line, record]: file_records){
+            ss << left_pad(std::to_string(line), 6);
+            ss << left_pad(std::to_string(record.hits), 10);
+            ss << left_pad(std::to_string(record.time), 13);
+            ss << left_pad(std::to_string(record.time_per_hit()), 9);
+            ss << left_pad(to_string_1f(record.time * 100.0 / total_time), 9);
+            ss << "  " << record.line_content() << "\n";
+        }
+        ss << "\n";
+    }
+    return ss.str();
+}
 
 }   // namespace pkpy

tests/84_line_profiler.py

@@ -0,0 +1,15 @@
+from line_profiler import LineProfiler
+
+def my_func():
+    a = 0
+    for i in range(1000000):
+        a += i
+    return a
+
+lp = LineProfiler()
+
+lp.add_function(my_func)
+
+lp.runcall(my_func)
+
+lp.print_stats()