From: divverent Date: Tue, 7 Jan 2014 16:29:25 +0000 (+0000) Subject: COVERAGE! Also fixes prvm always running as PRVMSLOWINTERPRETER :( X-Git-Tag: xonotic-v0.8.1~29^2~116 X-Git-Url: https://git.rm.cloudns.org/?a=commitdiff_plain;h=f77d65db40fde1a5e3191628c8b1f9a47b76ba08;p=xonotic%2Fdarkplaces.git COVERAGE! Also fixes prvm always running as PRVMSLOWINTERPRETER :( Very basic implementation. Needs a persistent store later, I suppose, as well as better output (e.g. for statements and coverage(), also show function, file and line). prvm_coverage 1: report function call coverage prvm_coverage 2: report coverage() builtin coverage (compiler aided) prvm_coverage 4: report statement coverage (SLOW) git-svn-id: svn://svn.icculus.org/twilight/trunk/darkplaces@12042 d7cf8633-e32d-0410-b094-e92efae38249 --- diff --git a/clvm_cmds.c b/clvm_cmds.c index 20d71a30..0099933a 100644 --- a/clvm_cmds.c +++ b/clvm_cmds.c @@ -4980,6 +4980,8 @@ VM_CL_RotateMoves, // #638 VM_digest_hex, // #639 VM_CL_V_CalcRefdef, // #640 void(entity e) V_CalcRefdef (DP_CSQC_V_CALCREFDEF) NULL, // #641 +VM_coverage, // #642 +NULL }; const int vm_cl_numbuiltins = sizeof(vm_cl_builtins) / sizeof(prvm_builtin_t); diff --git a/dpdefs/csprogsdefs.qc b/dpdefs/csprogsdefs.qc index f858afba..7e173f04 100644 --- a/dpdefs/csprogsdefs.qc +++ b/dpdefs/csprogsdefs.qc @@ -1428,6 +1428,12 @@ void(float fh, entity e) writetofile = #606; float(string s) isfunction = #607; void(entity e, string s) parseentitydata = #608; +//DP_COVERAGE +//idea: divVerent +//darkplaces implementation: divVerent +//function definitions: +void coverage() = #642; // Reports a coverage event. The engine counts for each of the calls to this builtin whether it has been called. + // assorted builtins const float STAT_MOVEVARS_TICRATE = 240; const float STAT_MOVEVARS_TIMESCALE = 241; diff --git a/dpdefs/dpextensions.qc b/dpdefs/dpextensions.qc index 0a550439..dfd260bf 100644 --- a/dpdefs/dpextensions.qc +++ b/dpdefs/dpextensions.qc @@ -2544,7 +2544,11 @@ void(float pause) setpause = #531; // //Note: it is worth considering that network-related functions may be called during the pause (including customizeentityforclient for example), and it is also important to consider the continued use of the KRIMZON_SV_PARSECLIENTCOMMAND extension while paused (chatting players, etc), players may also join/leave during the pause. In other words, the only things that are not called are think and other time-related functions. - +//DP_COVERAGE +//idea: divVerent +//darkplaces implementation: divVerent +//function definitions: +void coverage() = #642; // Reports a coverage event. The engine counts for each of the calls to this builtin whether it has been called. // EXPERIMENTAL (not finalized) EXTENSIONS: diff --git a/dpdefs/menudefs.qc b/dpdefs/menudefs.qc index 1f817cd2..cb7ef55a 100644 --- a/dpdefs/menudefs.qc +++ b/dpdefs/menudefs.qc @@ -530,6 +530,12 @@ float FIELD_FUNCTION = 6; //getentityfieldstring returns data as would be written to a savegame, eg... "0.05" (float), "0 0 1" (vector), or "Hello World!" (string). Function names can also be returned. //putentityfieldstring puts the data returned by getentityfieldstring back into the entity. +//DP_COVERAGE +//idea: divVerent +//darkplaces implementation: divVerent +//function definitions: +void coverage() = #642; // Reports a coverage event. The engine counts for each of the calls to this builtin whether it has been called. + // assorted undocumented extensions string(string, float) netaddress_resolve = #625; string(string search, string replace, string subject) strreplace = #484; diff --git a/mvm_cmds.c b/mvm_cmds.c index 12fcecdf..1b915c1f 100644 --- a/mvm_cmds.c +++ b/mvm_cmds.c @@ -13,8 +13,9 @@ const char *vm_m_extensions = "BX_WAL_SUPPORT " "DP_CINEMATIC_DPV " -"DP_CSQC_BINDMAPS " +"DP_COVERAGE " "DP_CRYPTO " +"DP_CSQC_BINDMAPS " "DP_GFX_FONTS " "DP_GFX_FONTS_FREETYPE " "DP_UTF8 " @@ -1583,6 +1584,7 @@ NULL, // #638 VM_digest_hex, // #639 NULL, // #640 VM_M_crypto_getmyidstatus, // #641 float(float i) crypto_getmyidstatus +VM_coverage, // #642 NULL }; diff --git a/progsvm.h b/progsvm.h index e1fd5055..fb40545e 100644 --- a/progsvm.h +++ b/progsvm.h @@ -534,6 +534,7 @@ typedef struct prvm_prog_s double profiletime; // system time when last PRVM_CallProfile was called (or PRVM_Prog_Load initially) unsigned int id; // increasing unique id of progs instance mfunction_t *functions; + int functions_covered; char *strings; int stringssize; ddef_t *fielddefs; @@ -565,6 +566,10 @@ typedef struct prvm_prog_s int *statement_columnnums; // NULL if not available double *statement_profile; // only incremented if prvm_statementprofiling is on + int statements_covered; + double *explicit_profile; // only incremented if prvm_statementprofiling is on + int explicit_covered; + int numexplicitcoveragestatements; union { prvm_vec_t *fp; @@ -892,4 +897,6 @@ void VM_FrameBlendFromFrameGroupBlend(frameblend_t *frameblend, const framegroup void VM_UpdateEdictSkeleton(prvm_prog_t *prog, prvm_edict_t *ed, const dp_model_t *edmodel, const frameblend_t *frameblend); void VM_RemoveEdictSkeleton(prvm_prog_t *prog, prvm_edict_t *ed); +void PRVM_ExplicitCoverageEvent(prvm_prog_t *prog, int statement); + #endif diff --git a/prvm_cmds.c b/prvm_cmds.c index 00c9ede9..e375a50d 100644 --- a/prvm_cmds.c +++ b/prvm_cmds.c @@ -7340,3 +7340,11 @@ void VM_physics_addtorque(prvm_prog_t *prog) VectorCopy(PRVM_G_VECTOR(OFS_PARM1), f.v1); VM_physics_ApplyCmd(ed, &f); } + +extern cvar_t prvm_coverage; +void VM_coverage(prvm_prog_t *prog) +{ + VM_SAFEPARMCOUNT(0, VM_coverage); + if (prog->explicit_profile[prog->xstatement]++ == 0 && (prvm_coverage.integer & 2)) + PRVM_ExplicitCoverageEvent(prog, prog->xstatement); +} diff --git a/prvm_cmds.h b/prvm_cmds.h index 75589dea..708a3621 100644 --- a/prvm_cmds.h +++ b/prvm_cmds.h @@ -488,4 +488,6 @@ void VM_physics_enable(prvm_prog_t *prog); void VM_physics_addforce(prvm_prog_t *prog); void VM_physics_addtorque(prvm_prog_t *prog); +void VM_coverage(prvm_prog_t *prog); + #endif diff --git a/prvm_edict.c b/prvm_edict.c index 882a558a..b83ae1a0 100644 --- a/prvm_edict.c +++ b/prvm_edict.c @@ -35,6 +35,7 @@ cvar_t prvm_traceqc = {0, "prvm_traceqc", "0", "prints every QuakeC statement as // LordHavoc: counts usage of each QuakeC statement cvar_t prvm_statementprofiling = {0, "prvm_statementprofiling", "0", "counts how many times each QuakeC statement has been executed, these counts are displayed in prvm_printfunction output (if enabled)"}; cvar_t prvm_timeprofiling = {0, "prvm_timeprofiling", "0", "counts how long each function has been executed, these counts are displayed in prvm_profile output (if enabled)"}; +cvar_t prvm_coverage = {0, "prvm_coverage", "0", "report and count coverage events (1: per-function, 2: coverage() builtin, 4: per-statement)"}; cvar_t prvm_backtraceforwarnings = {0, "prvm_backtraceforwarnings", "0", "print a backtrace for warnings too"}; cvar_t prvm_leaktest = {0, "prvm_leaktest", "0", "try to detect memory leaks in strings or entities"}; cvar_t prvm_leaktest_ignore_classnames = {0, "prvm_leaktest_ignore_classnames", "", "classnames of entities to NOT leak check because they are found by find(world, classname, ...) but are actually spawned by QC code (NOT map entities)"}; @@ -2010,6 +2011,7 @@ void PRVM_Prog_Load(prvm_prog_t *prog, const char * filename, unsigned char * da prog->statements = (mstatement_t *)Mem_Alloc(prog->progs_mempool, prog->progs_numstatements * sizeof(mstatement_t)); // allocate space for profiling statement usage prog->statement_profile = (double *)Mem_Alloc(prog->progs_mempool, prog->progs_numstatements * sizeof(*prog->statement_profile)); + prog->explicit_profile = (double *)Mem_Alloc(prog->progs_mempool, prog->progs_numstatements * sizeof(*prog->statement_profile)); // functions need to be converted to the memory format prog->functions = (mfunction_t *)Mem_Alloc(prog->progs_mempool, sizeof(mfunction_t) * prog->progs_numfunctions); @@ -2215,6 +2217,11 @@ void PRVM_Prog_Load(prvm_prog_t *prog, const char * filename, unsigned char * da break; // 1 global case OP_CALL0: + if ( a < prog->progs_numglobals) + if ( prog->globals.ip[remapglobal(a)] >= 0 ) + if ( prog->globals.ip[remapglobal(a)] < prog->progs_numfunctions ) + if ( !prog->functions[prog->globals.ip[remapglobal(a)]].first_statement == -642 ) + ++prog->numexplicitcoveragestatements; case OP_CALL1: case OP_CALL2: case OP_CALL3: @@ -2901,6 +2908,7 @@ void PRVM_Init (void) Cvar_RegisterVariable (&prvm_traceqc); Cvar_RegisterVariable (&prvm_statementprofiling); Cvar_RegisterVariable (&prvm_timeprofiling); + Cvar_RegisterVariable (&prvm_coverage); Cvar_RegisterVariable (&prvm_backtraceforwarnings); Cvar_RegisterVariable (&prvm_leaktest); Cvar_RegisterVariable (&prvm_leaktest_ignore_classnames); diff --git a/prvm_exec.c b/prvm_exec.c index 40b19d44..1be07894 100644 --- a/prvm_exec.c +++ b/prvm_exec.c @@ -119,6 +119,7 @@ const char *prvm_opnames[] = PRVM_PrintStatement ================= */ +extern cvar_t prvm_coverage; extern cvar_t prvm_statementprofiling; extern cvar_t prvm_timeprofiling; static void PRVM_PrintStatement(prvm_prog_t *prog, mstatement_t *s) @@ -185,8 +186,11 @@ void PRVM_PrintFunctionStatements (prvm_prog_t *prog, const char *name) for (i = firststatement;i < endstatement;i++) { PRVM_PrintStatement(prog, prog->statements + i); - prog->statement_profile[i] = 0; + if (!(prvm_coverage.integer & 4)) + prog->statement_profile[i] = 0; } + if (prvm_coverage.integer & 4) + Con_Printf("Collecting statement coverage, not flushing statement profile.\n"); } /* @@ -455,6 +459,12 @@ void PRVM_Profile_f (void) prvm_prog_t *prog; int howmany; + if (prvm_coverage.integer & 1) + { + Con_Printf("Collecting function coverage, cannot profile - sorry!\n"); + return; + } + howmany = 1<<30; if (Cmd_Argc() == 3) howmany = atoi(Cmd_Argv(2)); @@ -475,6 +485,12 @@ void PRVM_ChildProfile_f (void) prvm_prog_t *prog; int howmany; + if (prvm_coverage.integer & 1) + { + Con_Printf("Collecting function coverage, cannot profile - sorry!\n"); + return; + } + howmany = 1<<30; if (Cmd_Argc() == 3) howmany = atoi(Cmd_Argv(2)); @@ -664,6 +680,28 @@ void PRVM_Init_Exec(prvm_prog_t *prog) // nothing here yet } +/* +================== +Coverage +================== +*/ +static void PRVM_FunctionCoverageEvent(prvm_prog_t *prog, mfunction_t *func) +{ + ++prog->functions_covered; + Con_Printf("prvm_coverage: %s just called %s for the first time. Coverage: %.2f%%.\n", prog->name, PRVM_GetString(prog, func->s_name), prog->functions_covered * 100.0 / prog->numfunctions); +} +void PRVM_ExplicitCoverageEvent(prvm_prog_t *prog, int statement) +{ + ++prog->explicit_covered; + Con_Printf("prvm_coverage: %s just executed a coverage() statement for the first time. Coverage: %.2f%%.\n", prog->name, prog->explicit_covered * 100.0 / prog->numexplicitcoveragestatements); +} +static void PRVM_StatementCoverageEvent(prvm_prog_t *prog, int statement) +{ + ++prog->statements_covered; + Con_Printf("prvm_coverage: %s just executed a statement for the first time. Coverage: %.2f%%.\n", prog->name, prog->statements_covered * 100.0 / prog->numstatements); +} + + #define OPA ((prvm_eval_t *)&prog->globals.fp[st->operand[0]]) #define OPB ((prvm_eval_t *)&prog->globals.fp[st->operand[1]]) #define OPC ((prvm_eval_t *)&prog->globals.fp[st->operand[2]]) @@ -732,11 +770,12 @@ void MVM_ExecuteProgram (prvm_prog_t *prog, func_t fnum, const char *errormessag // instead of counting instructions, we count jumps jumpcount = 0; // add one to the callcount of this function because otherwise engine-called functions aren't counted - prog->xfunction->callcount++; + if (prog->xfunction->callcount++ == 0 && (prvm_coverage.integer & 1)) + PRVM_FunctionCoverageEvent(prog, prog->xfunction); chooseexecprogram: cachedpr_trace = prog->trace; - if (prvm_statementprofiling.integer || prog->trace || prog->watch_global >= 0 || prog->watch_edict >= 0 || prog->break_statement >= 0) + if (prvm_statementprofiling.integer || prog->trace || prog->watch_global_type != ev_void || prog->watch_field_type != ev_void || prog->break_statement >= 0 || (prvm_coverage.integer & 4)) { #define PRVMSLOWINTERPRETER 1 if (prvm_timeprofiling.integer) @@ -838,11 +877,12 @@ void CLVM_ExecuteProgram (prvm_prog_t *prog, func_t fnum, const char *errormessa // instead of counting instructions, we count jumps jumpcount = 0; // add one to the callcount of this function because otherwise engine-called functions aren't counted - prog->xfunction->callcount++; + if (prog->xfunction->callcount++ == 0 && (prvm_coverage.integer & 1)) + PRVM_FunctionCoverageEvent(prog, prog->xfunction); chooseexecprogram: cachedpr_trace = prog->trace; - if (prvm_statementprofiling.integer || prog->trace || prog->watch_global >= 0 || prog->watch_edict >= 0 || prog->break_statement >= 0) + if (prvm_statementprofiling.integer || prog->trace || prog->watch_global_type != ev_void || prog->watch_field_type != ev_void || prog->break_statement >= 0 || (prvm_coverage.integer & 4)) { #define PRVMSLOWINTERPRETER 1 if (prvm_timeprofiling.integer) @@ -948,11 +988,12 @@ void PRVM_ExecuteProgram (prvm_prog_t *prog, func_t fnum, const char *errormessa // instead of counting instructions, we count jumps jumpcount = 0; // add one to the callcount of this function because otherwise engine-called functions aren't counted - prog->xfunction->callcount++; + if (prog->xfunction->callcount++ == 0 && (prvm_coverage.integer & 1)) + PRVM_FunctionCoverageEvent(prog, prog->xfunction); chooseexecprogram: cachedpr_trace = prog->trace; - if (prvm_statementprofiling.integer || prog->trace || prog->watch_global >= 0 || prog->watch_edict >= 0 || prog->break_statement >= 0) + if (prvm_statementprofiling.integer || prog->trace || prog->watch_global_type != ev_void || prog->watch_field_type != ev_void || prog->break_statement >= 0 || (prvm_coverage.integer & 4)) { #define PRVMSLOWINTERPRETER 1 if (prvm_timeprofiling.integer) diff --git a/prvm_execprogram.h b/prvm_execprogram.h index 02b444b8..ea2ba374 100644 --- a/prvm_execprogram.h +++ b/prvm_execprogram.h @@ -36,7 +36,8 @@ #if PRVMSLOWINTERPRETER if (prog->trace) PRVM_PrintStatement(prog, st); - prog->statement_profile[st - cached_statements]++; + if (prog->statement_profile[st - cached_statements]++ == 0 && (prvm_coverage.integer & 4)) + PRVM_StatementCoverageEvent(prog, st - cached_statements); if (prog->break_statement >= 0) if ((st - cached_statements) == prog->break_statement) { @@ -372,7 +373,8 @@ } newf = &prog->functions[OPA->function]; - newf->callcount++; + if (newf->callcount++ == 0 && (prvm_coverage.integer & 1)) + PRVM_FunctionCoverageEvent(prog, newf); if (newf->first_statement < 0) { diff --git a/svvm_cmds.c b/svvm_cmds.c index c75dd077..11fa9598 100644 --- a/svvm_cmds.c +++ b/svvm_cmds.c @@ -19,6 +19,7 @@ const char *vm_sv_extensions = "DP_CON_SET " "DP_CON_SETA " "DP_CON_STARTMAP " +"DP_COVERAGE " "DP_CRYPTO " "DP_CSQC_BINDMAPS " "DP_CSQC_ENTITYWORLDOBJECT " @@ -3823,6 +3824,9 @@ NULL, // #637 NULL, // #638 VM_digest_hex, // #639 NULL, // #640 +NULL, // #641 +VM_coverage, // #642 +NULL, // #643 }; const int vm_sv_numbuiltins = sizeof(vm_sv_builtins) / sizeof(prvm_builtin_t);