instruction pointer storing profiling

This commit is contained in:
dzaima 2023-03-24 18:07:48 +02:00
parent e4c95dce22
commit 830c752e87
2 changed files with 119 additions and 62 deletions

View File

@ -548,7 +548,7 @@ static NOINLINE i64 readInt(char** p) {
#endif #endif
static NOINLINE B gsc_exec_inplace(B src, B path, B args) { NOINLINE B gsc_exec_inplace(B src, B path, B args) {
Block* block = bqn_compSc(src, path, args, gsc, true); Block* block = bqn_compSc(src, path, args, gsc, true);
ptr_dec(gsc->body); // redirect new errors to the newly executed code; initial scope had 0 vars, so this is safe ptr_dec(gsc->body); // redirect new errors to the newly executed code; initial scope had 0 vars, so this is safe
gsc->body = ptr_inc(block->bodies[0]); gsc->body = ptr_inc(block->bodies[0]);
@ -558,7 +558,7 @@ static NOINLINE B gsc_exec_inplace(B src, B path, B args) {
} }
bool profiler_alloc(void); bool profiler_alloc(void);
bool profiler_start(i64 hz); bool profiler_start(i32 mode, i64 hz);
bool profiler_stop(void); bool profiler_stop(void);
void profiler_free(void); void profiler_free(void);
void profiler_displayResults(void); void profiler_displayResults(void);
@ -599,7 +599,7 @@ void cbqn_runLine0(char* ln, i64 read) {
B code; B code;
int output; // 0-no; 1-formatter; 2-internal int output; // 0-no; 1-formatter; 2-internal
int mode = 0; // 0: regular execution; 1: single timing; 2: many timings; 3: second-limited timing; 4: profile int mode = 0; // 0: regular execution; 1: single timing; 2: many timings; 3: second-limited timing; 4: profile; 4: profile ip
i32 timeRep = 0; i32 timeRep = 0;
f64 timeNanos = -1; f64 timeNanos = -1;
i64 profile = -1; i64 profile = -1;
@ -629,12 +629,18 @@ void cbqn_runLine0(char* ln, i64 read) {
output = 0; output = 0;
} else if (isCmd(cmdS, &cmdE, "profile ") || isCmd(cmdS, &cmdE, "profile@")) { } else if (isCmd(cmdS, &cmdE, "profile ") || isCmd(cmdS, &cmdE, "profile@")) {
mode = 4; mode = 4;
goto profile_init; profile_init:;
char* cpos = cmdE; char* cpos = cmdE;
profile = '@'==*(cpos-1)? readInt(&cpos) : 5000; profile = '@'==*(cpos-1)? readInt(&cpos) : 5000;
if (profile==0) { printf("Cannot profile with 0hz sampling frequency\n"); return; } if (profile==0) { printf("Cannot profile with 0hz sampling frequency\n"); return; }
if (profile>999999) { printf("Cannot profile with >999999hz frequency\n"); return; } if (profile>999999) { printf("Cannot profile with >999999hz frequency\n"); return; }
code = utf8Decode0(cpos); code = utf8Decode0(cpos);
output = 0; output = 0;
#if PROFILE_IP
} else if (isCmd(cmdS, &cmdE, "profileip ") || isCmd(cmdS, &cmdE, "profileip@")) {
mode = 5;
goto profile_init;
#endif
} else if (isCmd(cmdS, &cmdE, "t:") || isCmd(cmdS, &cmdE, "time:")) { } else if (isCmd(cmdS, &cmdE, "t:") || isCmd(cmdS, &cmdE, "time:")) {
char* repE = cmdE; char* repE = cmdE;
mode = 2; mode = 2;
@ -829,9 +835,9 @@ void cbqn_runLine0(char* ln, i64 read) {
else r1 = r2; else r1 = r2;
} }
printTime(tns / rt); printTime(tns / rt);
} else if (mode==4) { } else if (mode==4 || mode==5) {
if (CATCH) { profiler_stop(); profiler_free(); rethrow(); } if (CATCH) { profiler_stop(); profiler_free(); rethrow(); }
if (profiler_alloc() && profiler_start(profile)) { if (profiler_alloc() && profiler_start(mode==5? 2 : 1, profile)) {
res = execBlockInplace(block, gsc); res = execBlockInplace(block, gsc);
profiler_stop(); profiler_stop();
profiler_displayResults(); profiler_displayResults();

161
src/vm.c
View File

@ -1,3 +1,8 @@
#if PROFILE_IP
#define _GNU_SOURCE 1
#include <sys/ucontext.h>
#endif
#include "core.h" #include "core.h"
#include "vm.h" #include "vm.h"
#include "ns.h" #include "ns.h"
@ -1415,20 +1420,25 @@ NOINLINE void vm_pstLive() {
#include <signal.h> #include <signal.h>
#define PROFILE_BUFFER (1ULL<<25) // number of `Profiler_ent`s #define PROFILE_BUFFER (1ULL<<25) // number of `Profiler_ent`s
typedef struct Profiler_ent { #define PROFILE_BUFFER_CHECK \
Comp* comp; Profiler_ent* bn = profiler_buf_c+1; \
usz bcPos; if (RARE(bn>=profiler_buf_e)) { profile_buf_full = true; return; }
typedef union Profiler_ent {
struct {
Comp* comp;
usz bcPos;
};
u64 ip;
} Profiler_ent; } Profiler_ent;
Profiler_ent* profiler_buf_s; Profiler_ent* profiler_buf_s;
Profiler_ent* profiler_buf_c; Profiler_ent* profiler_buf_c;
Profiler_ent* profiler_buf_e; Profiler_ent* profiler_buf_e;
bool profile_buf_full; bool profile_buf_full;
void profiler_sigHandler(int x) {
Profiler_ent* bn = profiler_buf_c+1;
if (RARE(bn>=profiler_buf_e)) { void profiler_bc_handler(int x) {
profile_buf_full = true; PROFILE_BUFFER_CHECK;
return;
}
if (envCurr<envStart) return; if (envCurr<envStart) return;
Env e = *envCurr; Env e = *envCurr;
@ -1439,9 +1449,35 @@ void profiler_sigHandler(int x) {
profiler_buf_c = bn; profiler_buf_c = bn;
} }
static bool setProfHandler(bool b) { #if PROFILE_IP
void profiler_ip_handler(int x, siginfo_t* info, void* context) {
PROFILE_BUFFER_CHECK;
ucontext_t* ctx = (ucontext_t*)context;
u64 ptr;
#if __x86_64__
ptr = ctx->uc_mcontext.gregs[REG_RIP];
#elif __aarch64__
ptr = ctx->uc_mcontext.pc;
#else
#error "don't know how to get instruction pointer on current arch"
#endif
*profiler_buf_c = (Profiler_ent){.ip = ptr};
profiler_buf_c = bn;
}
NOINLINE B gsc_exec_inplace(B src, B path, B args);
#endif
static bool setProfHandler(i32 mode) {
struct sigaction act = {}; struct sigaction act = {};
act.sa_handler = b? profiler_sigHandler : SIG_DFL; switch (mode) {
default: printf("Unsupported profiling mode\n"); return false;
case 0: act.sa_handler = SIG_DFL; break;
case 1: act.sa_handler = profiler_bc_handler; break;
#if PROFILE_IP
case 2: act.sa_sigaction = profiler_ip_handler; act.sa_flags=SA_SIGINFO;
#endif
}
if (sigaction(SIGALRM/*SIGPROF*/, &act, NULL)) { if (sigaction(SIGALRM/*SIGPROF*/, &act, NULL)) {
printf("Failed to set profiling signal handler\n"); printf("Failed to set profiling signal handler\n");
return false; return false;
@ -1465,6 +1501,9 @@ void* profiler_makeMap(void);
i32 profiler_index(void** mapRaw, B comp); i32 profiler_index(void** mapRaw, B comp);
void profiler_freeMap(void* mapRaw); void profiler_freeMap(void* mapRaw);
i32 profiler_mode; // 0: freed; 1: bytecode; 2: instruction pointers
bool profiler_active;
bool profiler_alloc(void) { bool profiler_alloc(void) {
profiler_buf_s = profiler_buf_c = mmap(NULL, PROFILE_BUFFER*sizeof(Profiler_ent), PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0); profiler_buf_s = profiler_buf_c = mmap(NULL, PROFILE_BUFFER*sizeof(Profiler_ent), PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0);
if (profiler_buf_s == MAP_FAILED) { if (profiler_buf_s == MAP_FAILED) {
@ -1476,20 +1515,22 @@ bool profiler_alloc(void) {
return true; return true;
} }
void profiler_free(void) { void profiler_free(void) {
profiler_mode = 0;
munmap(profiler_buf_s, PROFILE_BUFFER*sizeof(Profiler_ent)); munmap(profiler_buf_s, PROFILE_BUFFER*sizeof(Profiler_ent));
} }
bool profiler_active; bool profiler_start(i32 mode, i64 hz) { // 1: bytecode; 2: instruction pointers
bool profiler_start(i64 hz) { assert(mode==1 || mode==2);
i64 us = 999999/hz; i64 us = 999999/hz;
profiler_mode = mode;
profiler_active = true; profiler_active = true;
return setProfHandler(true) && setProfTimer(us); return setProfHandler(mode) && setProfTimer(us);
} }
bool profiler_stop(void) { bool profiler_stop(void) {
if (!profiler_active) return false; if (profiler_mode==0) return false;
profiler_active = false; profiler_active = false;
if (profile_buf_full) fprintf(stderr, "Profiler buffer ran out in the middle of execution. Only timings of the first "N64u" samples will be shown.\n", (u64)PROFILE_BUFFER); if (profile_buf_full) fprintf(stderr, "Profiler buffer ran out in the middle of execution. Only timings of the first "N64u" samples will be shown.\n", (u64)PROFILE_BUFFER);
return setProfTimer(0) && setProfHandler(false); return setProfTimer(0) && setProfHandler(0);
} }
@ -1497,6 +1538,7 @@ static bool isPathREPL(B path) {
return isArr(path) && IA(path)==1 && IGetU(path,0).u==m_c32('.').u; return isArr(path) && IA(path)==1 && IGetU(path,0).u==m_c32('.').u;
} }
usz profiler_getResults(B* compListRes, B* mapListRes, bool keyPath) { usz profiler_getResults(B* compListRes, B* mapListRes, bool keyPath) {
if (profiler_mode!=1) err("profiler_getResults called on mode!=1");
Profiler_ent* c = profiler_buf_s; Profiler_ent* c = profiler_buf_s;
B compList = emptyHVec(); B compList = emptyHVec();
@ -1536,51 +1578,60 @@ usz profiler_getResults(B* compListRes, B* mapListRes, bool keyPath) {
} }
void profiler_displayResults(void) { void profiler_displayResults(void) {
printf("Got "N64u" samples\n", (u64)(profiler_buf_c-profiler_buf_s)); ux count = (u64)(profiler_buf_c-profiler_buf_s);
printf("Got "N64u" samples\n", count);
if (profiler_mode==1) {
B compList, mapList;
usz compCount = profiler_getResults(&compList, &mapList, true);
B compList, mapList; SGetU(compList) SGetU(mapList)
usz compCount = profiler_getResults(&compList, &mapList, true); for (usz i = 0; i < compCount; i++) {
Comp* c = c(Comp, GetU(compList, i));
B mapObj = GetU(mapList, i);
i32* m = i32arr_ptr(mapObj);
SGetU(compList) SGetU(mapList) u64 sum = 0;
for (usz i = 0; i < compCount; i++) { usz ia = IA(mapObj);
Comp* c = c(Comp, GetU(compList, i)); for (usz i = 0; i < ia; i++) sum+= m[i];
B mapObj = GetU(mapList, i);
i32* m = i32arr_ptr(mapObj);
u64 sum = 0; if (q_N(c->path)) printf("(anonymous)");
usz ia = IA(mapObj); else if (isPathREPL(c->path)) printf("(REPL)");
for (usz i = 0; i < ia; i++) sum+= m[i]; else printsB(c->path);
if (q_N(c->src)) {
if (q_N(c->path)) printf("(anonymous)"); printf(": "N64d" samples\n", sum);
else if (isPathREPL(c->path)) printf("(REPL)"); } else {
else printsB(c->path); printf(": "N64d" samples:\n", sum);
if (q_N(c->src)) { B src = c->src;
printf(": "N64d" samples\n", sum); SGetU(src)
} else { usz sia = IA(src);
printf(": "N64d" samples:\n", sum); usz pi = 0;
B src = c->src; i32 curr = 0;
SGetU(src) for (usz i = 0; i < sia; i++) {
usz sia = IA(src); u32 c = o2cG(GetU(src, i));
usz pi = 0; curr+= m[i];
i32 curr = 0; if (c=='\n' || i==sia-1) {
for (usz i = 0; i < sia; i++) { Arr* sl = arr_shVec(TI(src,slice)(incG(src), pi, i-pi+(c=='\n'?0:1)));
u32 c = o2cG(GetU(src, i)); if (curr==0) printf("");
curr+= m[i]; else printf("%6d│", curr);
if (c=='\n' || i==sia-1) { printsB(taga(sl));
Arr* sl = arr_shVec(TI(src,slice)(incG(src), pi, i-pi+(c=='\n'?0:1))); printf("\n");
if (curr==0) printf(""); ptr_dec(sl);
else printf("%6d│", curr); curr = 0;
printsB(taga(sl)); pi = i+1;
printf("\n"); }
ptr_dec(sl);
curr = 0;
pi = i+1;
} }
} }
} }
} dec(compList);
dec(compList); dec(mapList);
dec(mapList); #if PROFILE_IP
} else if (profiler_mode==2) {
f64* rp; B r = m_f64arrv(&rp, count);
PLAINLOOP for (ux i = 0; i < count; i++) rp[i] = profiler_buf_s[i].ip;
gsc_exec_inplace(utf8Decode0("profilerResult←•args⋄@"), bi_N, r);
printf("wrote result to profilerResult\n");
#endif
} else err("profiler_displayResults called with unexpected active mode");
} }
#else #else
bool profiler_alloc() { bool profiler_alloc() {