prvm_callprofile: a flat profile, time based, including subcalls
[divverent/darkplaces.git] / prvm_exec.c
1 /*
2 Copyright (C) 1996-1997 Id Software, Inc.
3
4 This program is free software; you can redistribute it and/or
5 modify it under the terms of the GNU General Public License
6 as published by the Free Software Foundation; either version 2
7 of the License, or (at your option) any later version.
8
9 This program is distributed in the hope that it will be useful,
10 but WITHOUT ANY WARRANTY; without even the implied warranty of
11 MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.
12
13 See the GNU General Public License for more details.
14
15 You should have received a copy of the GNU General Public License
16 along with this program; if not, write to the Free Software
17 Foundation, Inc., 59 Temple Place - Suite 330, Boston, MA  02111-1307, USA.
18
19 */
20
21 #include "quakedef.h"
22 #include "progsvm.h"
23
24 char *prvm_opnames[] =
25 {
26 "^5DONE",
27
28 "MUL_F",
29 "MUL_V",
30 "MUL_FV",
31 "MUL_VF",
32
33 "DIV",
34
35 "ADD_F",
36 "ADD_V",
37
38 "SUB_F",
39 "SUB_V",
40
41 "^2EQ_F",
42 "^2EQ_V",
43 "^2EQ_S",
44 "^2EQ_E",
45 "^2EQ_FNC",
46
47 "^2NE_F",
48 "^2NE_V",
49 "^2NE_S",
50 "^2NE_E",
51 "^2NE_FNC",
52
53 "^2LE",
54 "^2GE",
55 "^2LT",
56 "^2GT",
57
58 "^6FIELD_F",
59 "^6FIELD_V",
60 "^6FIELD_S",
61 "^6FIELD_ENT",
62 "^6FIELD_FLD",
63 "^6FIELD_FNC",
64
65 "^1ADDRESS",
66
67 "STORE_F",
68 "STORE_V",
69 "STORE_S",
70 "STORE_ENT",
71 "STORE_FLD",
72 "STORE_FNC",
73
74 "^1STOREP_F",
75 "^1STOREP_V",
76 "^1STOREP_S",
77 "^1STOREP_ENT",
78 "^1STOREP_FLD",
79 "^1STOREP_FNC",
80
81 "^5RETURN",
82
83 "^2NOT_F",
84 "^2NOT_V",
85 "^2NOT_S",
86 "^2NOT_ENT",
87 "^2NOT_FNC",
88
89 "^5IF",
90 "^5IFNOT",
91
92 "^3CALL0",
93 "^3CALL1",
94 "^3CALL2",
95 "^3CALL3",
96 "^3CALL4",
97 "^3CALL5",
98 "^3CALL6",
99 "^3CALL7",
100 "^3CALL8",
101
102 "^1STATE",
103
104 "^5GOTO",
105
106 "^2AND",
107 "^2OR",
108
109 "BITAND",
110 "BITOR"
111 };
112
113 char *PRVM_GlobalString (int ofs);
114 char *PRVM_GlobalStringNoContents (int ofs);
115
116
117 //=============================================================================
118
119 /*
120 =================
121 PRVM_PrintStatement
122 =================
123 */
124 extern cvar_t prvm_statementprofiling;
125 void PRVM_PrintStatement (dstatement_t *s)
126 {
127         size_t i;
128         int opnum = (int)(s - prog->statements);
129
130         Con_Printf("s%i: ", opnum);
131         if( prog->statement_linenums )
132                 Con_Printf( "%s:%i: ", PRVM_GetString( prog->xfunction->s_file ), prog->statement_linenums[ opnum ] );
133
134         if (prvm_statementprofiling.integer)
135                 Con_Printf("%7.0f ", prog->statement_profile[s - prog->statements]);
136
137         if ( (unsigned)s->op < sizeof(prvm_opnames)/sizeof(prvm_opnames[0]))
138         {
139                 Con_Printf("%s ",  prvm_opnames[s->op]);
140                 i = strlen(prvm_opnames[s->op]);
141                 // don't count a preceding color tag when padding the name
142                 if (prvm_opnames[s->op][0] == STRING_COLOR_TAG)
143                         i -= 2;
144                 for ( ; i<10 ; i++)
145                         Con_Print(" ");
146         }
147         if (s->op == OP_IF || s->op == OP_IFNOT)
148                 Con_Printf("%s, s%i",PRVM_GlobalString((unsigned short) s->a),(signed short)s->b + opnum);
149         else if (s->op == OP_GOTO)
150                 Con_Printf("s%i",(signed short)s->a + opnum);
151         else if ( (unsigned)(s->op - OP_STORE_F) < 6)
152         {
153                 Con_Print(PRVM_GlobalString((unsigned short) s->a));
154                 Con_Print(", ");
155                 Con_Print(PRVM_GlobalStringNoContents((unsigned short) s->b));
156         }
157         else if (s->op == OP_ADDRESS || (unsigned)(s->op - OP_LOAD_F) < 6)
158         {
159                 if (s->a)
160                         Con_Print(PRVM_GlobalString((unsigned short) s->a));
161                 if (s->b)
162                 {
163                         Con_Print(", ");
164                         Con_Print(PRVM_GlobalStringNoContents((unsigned short) s->b));
165                 }
166                 if (s->c)
167                 {
168                         Con_Print(", ");
169                         Con_Print(PRVM_GlobalStringNoContents((unsigned short) s->c));
170                 }
171         }
172         else
173         {
174                 if (s->a)
175                         Con_Print(PRVM_GlobalString((unsigned short) s->a));
176                 if (s->b)
177                 {
178                         Con_Print(", ");
179                         Con_Print(PRVM_GlobalString((unsigned short) s->b));
180                 }
181                 if (s->c)
182                 {
183                         Con_Print(", ");
184                         Con_Print(PRVM_GlobalStringNoContents((unsigned short) s->c));
185                 }
186         }
187         Con_Print("\n");
188 }
189
190 void PRVM_PrintFunctionStatements (const char *name)
191 {
192         int i, firststatement, endstatement;
193         mfunction_t *func;
194         func = PRVM_ED_FindFunction (name);
195         if (!func)
196         {
197                 Con_Printf("%s progs: no function named %s\n", PRVM_NAME, name);
198                 return;
199         }
200         firststatement = func->first_statement;
201         if (firststatement < 0)
202         {
203                 Con_Printf("%s progs: function %s is builtin #%i\n", PRVM_NAME, name, -firststatement);
204                 return;
205         }
206
207         // find the end statement
208         endstatement = prog->progs->numstatements;
209         for (i = 0;i < prog->progs->numfunctions;i++)
210                 if (endstatement > prog->functions[i].first_statement && firststatement < prog->functions[i].first_statement)
211                         endstatement = prog->functions[i].first_statement;
212
213         // now print the range of statements
214         Con_Printf("%s progs: disassembly of function %s (statements %i-%i):\n", PRVM_NAME, name, firststatement, endstatement);
215         for (i = firststatement;i < endstatement;i++)
216         {
217                 PRVM_PrintStatement(prog->statements + i);
218                 prog->statement_profile[i] = 0;
219         }
220 }
221
222 /*
223 ============
224 PRVM_PrintFunction_f
225
226 ============
227 */
228 void PRVM_PrintFunction_f (void)
229 {
230         if (Cmd_Argc() != 3)
231         {
232                 Con_Printf("usage: prvm_printfunction <program name> <function name>\n");
233                 return;
234         }
235
236         PRVM_Begin;
237         if(!PRVM_SetProgFromString(Cmd_Argv(1)))
238                 return;
239
240         PRVM_PrintFunctionStatements(Cmd_Argv(2));
241
242         PRVM_End;
243 }
244
245 /*
246 ============
247 PRVM_StackTrace
248 ============
249 */
250 void PRVM_StackTrace (void)
251 {
252         mfunction_t     *f;
253         int                     i;
254
255         prog->stack[prog->depth].s = prog->xstatement;
256         prog->stack[prog->depth].f = prog->xfunction;
257         for (i = prog->depth;i > 0;i--)
258         {
259                 f = prog->stack[i].f;
260
261                 if (!f)
262                         Con_Print("<NULL FUNCTION>\n");
263                 else
264                         Con_Printf("%12s : %s : statement %i\n", PRVM_GetString(f->s_file), PRVM_GetString(f->s_name), prog->stack[i].s - f->first_statement);
265         }
266 }
267
268
269 void PRVM_CallProfile ()
270 {
271         mfunction_t *f, *best;
272         int i;
273         double max;
274         double sum;
275
276         Con_Printf( "%s Call Profile:\n", PRVM_NAME );
277
278         sum = 0;
279         do
280         {
281                 max = 0;
282                 best = NULL;
283                 for (i=0 ; i<prog->progs->numfunctions ; i++)
284                 {
285                         f = &prog->functions[i];
286                         if (max < f->totaltime)
287                         {
288                                 max = f->totaltime;
289                                 best = f;
290                         }
291                 }
292                 if (best)
293                 {
294                         sum += best->totaltime;
295                         Con_Printf("%9.4f %s\n", best->totaltime, PRVM_GetString(best->s_name));
296                         best->totaltime = 0;
297                 }
298         } while (best);
299
300         Con_Printf("Total time since last profile reset: %9.4f\n", Sys_DoubleTime() - prog->starttime);
301         Con_Printf("       - used by QC code of this VM: %9.4f\n", sum);
302
303         prog->starttime = Sys_DoubleTime();
304 }
305
306 void PRVM_Profile (int maxfunctions, int mininstructions)
307 {
308         mfunction_t *f, *best;
309         int i, num;
310         double max;
311
312         Con_Printf( "%s Profile:\n[CallCount] [Statements] [BuiltinCost]\n", PRVM_NAME );
313
314         num = 0;
315         do
316         {
317                 max = 0;
318                 best = NULL;
319                 for (i=0 ; i<prog->progs->numfunctions ; i++)
320                 {
321                         f = &prog->functions[i];
322                         if (max < f->profile + f->builtinsprofile + f->callcount)
323                         {
324                                 max = f->profile + f->builtinsprofile + f->callcount;
325                                 best = f;
326                         }
327                 }
328                 if (best)
329                 {
330                         if (num < maxfunctions && max >= mininstructions)
331                         {
332                                 if (best->first_statement < 0)
333                                         Con_Printf("%9.0f ----- builtin ----- %s\n", best->callcount, PRVM_GetString(best->s_name));
334                                 else
335                                         Con_Printf("%9.0f %9.0f %9.0f %s\n", best->callcount, best->profile, best->builtinsprofile, PRVM_GetString(best->s_name));
336                         }
337                         num++;
338                         best->profile = 0;
339                         best->builtinsprofile = 0;
340                         best->callcount = 0;
341                 }
342         } while (best);
343 }
344
345 /*
346 ============
347 PRVM_CallProfile_f
348
349 ============
350 */
351 void PRVM_CallProfile_f (void)
352 {
353         if (Cmd_Argc() != 2)
354         {
355                 Con_Print("prvm_callprofile <program name>\n");
356                 return;
357         }
358
359         PRVM_Begin;
360         if(!PRVM_SetProgFromString(Cmd_Argv(1)))
361                 return;
362
363         PRVM_CallProfile();
364
365         PRVM_End;
366 }
367
368 /*
369 ============
370 PRVM_Profile_f
371
372 ============
373 */
374 void PRVM_Profile_f (void)
375 {
376         int howmany;
377
378         howmany = 1<<30;
379         if (Cmd_Argc() == 3)
380                 howmany = atoi(Cmd_Argv(2));
381         else if (Cmd_Argc() != 2)
382         {
383                 Con_Print("prvm_profile <program name>\n");
384                 return;
385         }
386
387         PRVM_Begin;
388         if(!PRVM_SetProgFromString(Cmd_Argv(1)))
389                 return;
390
391         PRVM_Profile(howmany, 1);
392
393         PRVM_End;
394 }
395
396 void PRVM_CrashAll()
397 {
398         int i;
399         prvm_prog_t *oldprog = prog;
400
401         for(i = 0; i < PRVM_MAXPROGS; i++)
402         {
403                 if(!PRVM_ProgLoaded(i))
404                         continue;
405                 PRVM_SetProg(i);
406                 PRVM_Crash();
407         }
408
409         prog = oldprog;
410 }
411
412 void PRVM_PrintState(void)
413 {
414         int i;
415         if (prog->xfunction)
416         {
417                 for (i = -7; i <= 0;i++)
418                         if (prog->xstatement + i >= prog->xfunction->first_statement)
419                                 PRVM_PrintStatement (prog->statements + prog->xstatement + i);
420         }
421         else
422                 Con_Print("null function executing??\n");
423         PRVM_StackTrace ();
424 }
425
426 extern sizebuf_t vm_tempstringsbuf;
427 void PRVM_Crash(void)
428 {
429         if (prog == NULL)
430                 return;
431
432         if( prog->depth > 0 )
433         {
434                 Con_Printf("QuakeC crash report for %s:\n", PRVM_NAME);
435                 PRVM_PrintState();
436         }
437
438         // dump the stack so host_error can shutdown functions
439         prog->depth = 0;
440         prog->localstack_used = 0;
441
442         // delete all tempstrings (FIXME: is this safe in VM->engine->VM recursion?)
443         vm_tempstringsbuf.cursize = 0;
444
445         // reset the prog pointer
446         prog = NULL;
447 }
448
449 /*
450 ============================================================================
451 PRVM_ExecuteProgram
452
453 The interpretation main loop
454 ============================================================================
455 */
456
457 /*
458 ====================
459 PRVM_EnterFunction
460
461 Returns the new program statement counter
462 ====================
463 */
464 int PRVM_EnterFunction (mfunction_t *f)
465 {
466         int             i, j, c, o;
467
468         if (!f)
469                 PRVM_ERROR ("PRVM_EnterFunction: NULL function in %s", PRVM_NAME);
470
471         prog->stack[prog->depth].s = prog->xstatement;
472         prog->stack[prog->depth].f = prog->xfunction;
473         prog->depth++;
474         if (prog->depth >=PRVM_MAX_STACK_DEPTH)
475                 PRVM_ERROR ("stack overflow");
476
477 // save off any locals that the new function steps on
478         c = f->locals;
479         if (prog->localstack_used + c > PRVM_LOCALSTACK_SIZE)
480                 PRVM_ERROR ("PRVM_ExecuteProgram: locals stack overflow in %s", PRVM_NAME);
481
482         for (i=0 ; i < c ; i++)
483                 prog->localstack[prog->localstack_used+i] = ((int *)prog->globals.generic)[f->parm_start + i];
484         prog->localstack_used += c;
485
486 // copy parameters
487         o = f->parm_start;
488         for (i=0 ; i<f->numparms ; i++)
489         {
490                 for (j=0 ; j<f->parm_size[i] ; j++)
491                 {
492                         ((int *)prog->globals.generic)[o] = ((int *)prog->globals.generic)[OFS_PARM0+i*3+j];
493                         o++;
494                 }
495         }
496
497         prog->xfunction = f;
498         return f->first_statement - 1;  // offset the s++
499 }
500
501 /*
502 ====================
503 PRVM_LeaveFunction
504 ====================
505 */
506 int PRVM_LeaveFunction (void)
507 {
508         int             i, c;
509
510         if (prog->depth <= 0)
511                 PRVM_ERROR ("prog stack underflow in %s", PRVM_NAME);
512
513         if (!prog->xfunction)
514                 PRVM_ERROR ("PR_LeaveFunction: NULL function in %s", PRVM_NAME);
515 // restore locals from the stack
516         c = prog->xfunction->locals;
517         prog->localstack_used -= c;
518         if (prog->localstack_used < 0)
519                 PRVM_ERROR ("PRVM_ExecuteProgram: locals stack underflow in %s", PRVM_NAME);
520
521         for (i=0 ; i < c ; i++)
522                 ((int *)prog->globals.generic)[prog->xfunction->parm_start + i] = prog->localstack[prog->localstack_used+i];
523
524 // up stack
525         prog->depth--;
526         prog->xfunction = prog->stack[prog->depth].f;
527         return prog->stack[prog->depth].s;
528 }
529
530 void PRVM_Init_Exec(void)
531 {
532         // dump the stack
533         prog->depth = 0;
534         prog->localstack_used = 0;
535         // reset the string table
536         // nothing here yet
537 }
538
539 /*
540 ====================
541 PRVM_ExecuteProgram
542 ====================
543 */
544 // LordHavoc: optimized
545 #define OPA ((prvm_eval_t *)&prog->globals.generic[(unsigned short) st->a])
546 #define OPB ((prvm_eval_t *)&prog->globals.generic[(unsigned short) st->b])
547 #define OPC ((prvm_eval_t *)&prog->globals.generic[(unsigned short) st->c])
548 extern cvar_t prvm_boundscheck;
549 extern cvar_t prvm_traceqc;
550 extern cvar_t prvm_statementprofiling;
551 extern sizebuf_t vm_tempstringsbuf;
552 void PRVM_ExecuteProgram (func_t fnum, const char *errormessage)
553 {
554         dstatement_t    *st, *startst;
555         mfunction_t     *f, *newf;
556         prvm_edict_t    *ed;
557         prvm_eval_t     *ptr;
558         int             jumpcount, cachedpr_trace, exitdepth;
559         int             restorevm_tempstringsbuf_cursize;
560         double  calltime;
561
562         calltime = Sys_DoubleTime();
563
564         if (!fnum || fnum >= (unsigned int)prog->progs->numfunctions)
565         {
566                 if (prog->globaloffsets.self >= 0 && PRVM_GLOBALFIELDVALUE(prog->globaloffsets.self)->edict)
567                         PRVM_ED_Print(PRVM_PROG_TO_EDICT(PRVM_GLOBALFIELDVALUE(prog->globaloffsets.self)->edict), NULL);
568                 PRVM_ERROR ("PRVM_ExecuteProgram: %s", errormessage);
569         }
570
571         f = &prog->functions[fnum];
572
573         // after executing this function, delete all tempstrings it created
574         restorevm_tempstringsbuf_cursize = vm_tempstringsbuf.cursize;
575
576         prog->trace = prvm_traceqc.integer;
577
578         // we know we're done when pr_depth drops to this
579         exitdepth = prog->depth;
580
581 // make a stack frame
582         st = &prog->statements[PRVM_EnterFunction (f)];
583         // save the starting statement pointer for profiling
584         // (when the function exits or jumps, the (st - startst) integer value is
585         // added to the function's profile counter)
586         startst = st;
587         // instead of counting instructions, we count jumps
588         jumpcount = 0;
589         // add one to the callcount of this function because otherwise engine-called functions aren't counted
590         prog->xfunction->callcount++;
591
592 chooseexecprogram:
593         cachedpr_trace = prog->trace;
594         if (prvm_statementprofiling.integer)
595         {
596 #define PRVMSTATEMENTPROFILING 1
597                 if (prvm_boundscheck.integer)
598                 {
599 #define PRVMBOUNDSCHECK 1
600                         if (prog->trace)
601                         {
602 #define PRVMTRACE 1
603 #include "prvm_execprogram.h"
604 #undef PRVMTRACE
605                         }
606                         else
607                         {
608 #include "prvm_execprogram.h"
609                         }
610 #undef PRVMBOUNDSCHECK
611                 }
612                 else
613                 {
614                         if (prog->trace)
615                         {
616 #define PRVMTRACE 1
617 #include "prvm_execprogram.h"
618 #undef PRVMTRACE
619                         }
620                         else
621                         {
622 #include "prvm_execprogram.h"
623                         }
624                 }
625 #undef PRVMSTATEMENTPROFILING
626         }
627         else
628         {
629                 if (prvm_boundscheck.integer)
630                 {
631 #define PRVMBOUNDSCHECK 1
632                         if (prog->trace)
633                         {
634 #define PRVMTRACE 1
635 #include "prvm_execprogram.h"
636 #undef PRVMTRACE
637                         }
638                         else
639                         {
640 #include "prvm_execprogram.h"
641                         }
642 #undef PRVMBOUNDSCHECK
643                 }
644                 else
645                 {
646                         if (prog->trace)
647                         {
648 #define PRVMTRACE 1
649 #include "prvm_execprogram.h"
650 #undef PRVMTRACE
651                         }
652                         else
653                         {
654 #include "prvm_execprogram.h"
655                         }
656                 }
657         }
658
659 cleanup:
660         if (developer.integer >= 200 && vm_tempstringsbuf.cursize > restorevm_tempstringsbuf_cursize)
661                 Con_Printf("PRVM_ExecuteProgram: %s used %i bytes of tempstrings\n", PRVM_GetString(prog->functions[fnum].s_name), vm_tempstringsbuf.cursize - restorevm_tempstringsbuf_cursize);
662         // delete tempstrings created by this function
663         vm_tempstringsbuf.cursize = restorevm_tempstringsbuf_cursize;
664
665         prog->functions[fnum].totaltime += (Sys_DoubleTime() - calltime);
666
667         SV_FlushBroadcastMessages();
668 }