/* cl_demo.c demo playback support Copyright (C) 1996-1997 Id Software, Inc. This program is free software; you can redistribute it and/or modify it under the terms of the GNU General Public License as published by the Free Software Foundation; either version 2 of the License, or (at your option) any later version. This program is distributed in the hope that it will be useful, but WITHOUT ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU General Public License for more details. You should have received a copy of the GNU General Public License along with this program; if not, write to: Free Software Foundation, Inc. 59 Temple Place - Suite 330 Boston, MA 02111-1307, USA */ #ifdef HAVE_CONFIG_H # include "config.h" #endif #ifdef HAVE_STRING_H # include #endif #ifdef HAVE_STRINGS_H # include #endif #include #include #include "QF/cmd.h" #include "QF/cvar.h" #include "QF/dstring.h" #include "QF/keys.h" #include "QF/msg.h" #include "QF/qendian.h" #include "QF/sys.h" #include "QF/va.h" #include "QF/scene/scene.h" #include "QF/plugin/vid_render.h" #include "compat.h" #include "client/world.h" #include "nq/include/client.h" #include "nq/include/host.h" typedef struct { int frames; double time; double fps; } td_stats_t; static int demo_timeframes_isactive; static int demo_timeframes_index; static dstring_t *demoname; static double *demo_timeframes_array; #define CL_TIMEFRAMES_ARRAYBLOCK 4096 static int timedemo_count; static int timedemo_runs; static td_stats_t *timedemo_data; static void CL_FinishTimeDemo (void); static void CL_TimeFrames_DumpLog (void); static void CL_TimeFrames_AddTimestamp (void); static void CL_TimeFrames_Reset (void); int demo_gzip; static cvar_t demo_gzip_cvar = { .name = "demo_gzip", .description = "Compress demos using gzip. 0 = none, 1 = least compression, 9 = most " "compression. Compressed demos (1-9) will have .gz appended to the " "name", .default_value = "0", .flags = CVAR_ARCHIVE, .value = { .type = &cexpr_int, .value = &demo_gzip }, }; float demo_speed; static cvar_t demo_speed_cvar = { .name = "demo_speed", .description = "adjust demo playback speed. 1.0 = normal, < 1 slow-mo, > 1 timelapse", .default_value = "1.0", .flags = CVAR_NONE, .value = { .type = &cexpr_float, .value = &demo_speed }, }; int demo_debug; static cvar_t demo_debug_cvar = { .name = "demo_debug", .description = "set demo_speed to 0 when the packet count reaches this value (0 to " "disable)", .default_value = "0", .flags = CVAR_NONE, .value = { .type = &cexpr_int, .value = &demo_debug }, }; int demo_quit; static cvar_t demo_quit_cvar = { .name = "demo_quit", .description = "automaticly quit after a timedemo has finished", .default_value = "0", .flags = CVAR_NONE, .value = { .type = &cexpr_int, .value = &demo_quit }, }; int demo_timeframes; static cvar_t demo_timeframes_cvar = { .name = "demo_timeframes", .description = "write timestamps for every frame", .default_value = "0", .flags = CVAR_NONE, .value = { .type = &cexpr_int, .value = &demo_timeframes }, }; #define MAX_DEMMSG (MAX_MSGLEN) /* DEMO CODE When a demo is playing back, all NET_SendMessages are skipped, and NET_GetMessages are read from the demo file. Whenever cl.time gets past the last received message, another message is read from the demo file. */ /* CL_WriteDemoMessage Dumps the current net message, prefixed by the length and view angles */ static void CL_WriteDemoMessage (sizebuf_t *msg) { float f; int len; int i; len = LittleLong (msg->cursize); Qwrite (cls.demofile, &len, 4); for (i = 0; i < 3; i++) { f = LittleFloat (cl.viewstate.player_angles[i]); Qwrite (cls.demofile, &f, 4); } Qwrite (cls.demofile, msg->data, msg->cursize); Qflush (cls.demofile); } /* CL_StopPlayback Called when a demo file runs out, or the user starts a game */ void CL_StopPlayback (void) { if (!cls.demoplayback) return; Qclose (cls.demofile); cls.demofile = NULL; CL_SetState (ca_disconnected); cls.demo_capture = 0; cls.demoplayback = 0; cl.viewstate.demoplayback = 0; if (cls.timedemo) CL_FinishTimeDemo (); } void CL_StopRecording (void) { // write a disconnect message to the demo file SZ_Clear (net_message->message); MSG_WriteByte (net_message->message, svc_disconnect); CL_WriteDemoMessage (net_message->message); // finish up Qclose (cls.demofile); cls.demofile = NULL; cls.demorecording = false; Sys_Printf ("Completed demo\n"); } // decide if it is time to grab the next message static int check_next_demopacket (void) { if (cls.state == ca_active) { // always grab until fully connected if (cls.timedemo) { if (host_framecount == cls.td_lastframe) return 0; // already read this frame's message cls.td_lastframe = host_framecount; // if this is the second frame, grab the real td_starttime // so the bogus time on the first frame doesn't count if (host_framecount == cls.td_startframe + 1) cls.td_starttime = Sys_DoubleTime (); } else if (cl.time <= cl.mtime[0]) { return 0; // don't need another message yet } } return 1; } // get the next message static int read_demopacket (void) { int i; unsigned r; float f; Qread (cls.demofile, &net_message->message->cursize, 4); net_message->message->cursize = LittleLong (net_message->message->cursize); if (net_message->message->cursize > MAX_DEMMSG) Host_Error ("Demo message > MAX_DEMMSG: %d/%d", net_message->message->cursize, MAX_DEMMSG); VectorCopy (cl.frameViewAngles[0], cl.frameViewAngles[1]); for (i = 0; i < 3; i++) { r = Qread (cls.demofile, &f, 4); if (r != 4) { CL_StopPlayback (); return 0; } cl.frameViewAngles[0][i] = LittleFloat (f); } r = Qread (cls.demofile, net_message->message->data, net_message->message->cursize); if (r != net_message->message->cursize) { CL_StopPlayback (); return 0; } return 1; } static int CL_GetDemoMessage (void) { if (!check_next_demopacket ()) return 0; return read_demopacket (); } static int CL_GetPacket (void) { int r; while (1) { r = NET_GetMessage (cls.netcon); if (r != 1 && r != 2) return r; // discard nop keepalive message if (net_message->message->cursize == 1 && net_message->message->data[0] == svc_nop) Sys_Printf ("<-- server to client keepalive\n"); else break; } return r; } /* CL_GetMessage Handles recording and playback of demos, on top of NET_ code */ int CL_GetMessage (void) { if (cls.demoplayback) { int ret = CL_GetDemoMessage (); if (demo_debug) { static int packet_count = 0; if (ret) { packet_count++; if (packet_count == demo_debug) { demo_speed = 0; } } r_funcs->Draw_String (32, 64, va (0, "%4d", packet_count)); } if (!ret && demo_timeframes_isactive && cls.td_starttime) { CL_TimeFrames_AddTimestamp (); } return ret; } if (!CL_GetPacket ()) return 0; if (cls.demorecording) CL_WriteDemoMessage (net_message->message); return 1; } /* CL_Stop_f stop recording a demo */ static void CL_Stop_f (void) { if (cmd_source != src_command) return; if (!cls.demorecording) { Sys_Printf ("Not recording a demo.\n"); return; } CL_StopRecording (); } /* CL_Record_f record [cd track] */ static void CL_Record_f (void) { int c; int track; if (cmd_source != src_command) return; c = Cmd_Argc (); if (c > 4) { Sys_Printf ("record [ [ [cd track]]]\n"); return; } if (c >= 2 && strstr (Cmd_Argv (1), "..")) { Sys_Printf ("Relative pathnames are not allowed.\n"); return; } if (c == 2 && cls.state >= ca_connected) { Sys_Printf ("Can not record - already connected to server\nClient demo recording must be started before connecting\n"); return; } // write the forced cd track number, or -1 if (c == 4) { track = atoi (Cmd_Argv (3)); Sys_Printf ("Forcing CD track to %i\n", cls.forcetrack); } else track = -1; // start up the map if (c > 2) Cmd_ExecuteString (va (0, "map %s", Cmd_Argv (2)), src_command); CL_Record (Cmd_Argv (1), track); } static dstring_t * demo_default_name (const char *argv1) { dstring_t *name; const char *mapname; int mapname_len; char timestring[20]; time_t tim; name = dstring_new (); if (argv1) { dsprintf (name, "%s/%s", qfs_gamedir->dir.def, argv1); return name; } // Get time to a useable format time (&tim); strftime (timestring, 19, "%Y-%m-%d-%H-%M", localtime (&tim)); // the leading path-name is to be removed from cl_world.worldmodel->name mapname = QFS_SkipPath (cl_world.scene->worldmodel->path); // the map name is cut off after any "." because this would prevent // an extension being appended for (mapname_len = 0; mapname[mapname_len]; mapname_len++) if (mapname[mapname_len] == '.') break; dsprintf (name, "%s/%s-%.*s", qfs_gamedir->dir.def, timestring, mapname_len, mapname); return name; } static void demo_start_recording (int track) { cls.forcetrack = track; Qprintf (cls.demofile, "%i\n", cls.forcetrack); } void CL_Record (const char *argv1, int track) { dstring_t *name; name = demo_default_name (argv1); // open the demo file #ifdef HAVE_ZLIB if (demo_gzip) { QFS_DefaultExtension (name, ".dem.gz"); cls.demofile = QFS_WOpen (name->str, demo_gzip); } else #endif { QFS_DefaultExtension (name, ".dem"); cls.demofile = QFS_WOpen (name->str, 0); } if (!cls.demofile) { Sys_Printf ("ERROR: couldn't open.\n"); dstring_delete (name); return; } Sys_Printf ("recording to %s.\n", name->str); dstring_delete (name); cls.demorecording = true; demo_start_recording (track); } static int demo_check_dem (void) { int c, ret = 0; uint32_t len, bytes; // .dem demo files begin with an ascii integer (possibly negative) // representing the forced bgm track, followed by a newline c = Qgetc (cls.demofile); while (isspace (c)) // hipnotic demos have leading whitespace :P c = Qgetc (cls.demofile); if (c == '-') c = Qgetc (cls.demofile); while (isdigit (c)) c = Qgetc (cls.demofile); if (c != '\n') goto done; // After the bgm track comes the packet length plus 3 floats for view // angles (not included in the packet length) Qread (cls.demofile, &len, sizeof (len)); len = LittleLong (len); if (len > MAX_DEMMSG) goto done; Qseek (cls.demofile, 3 * 4, SEEK_CUR); // 3 * float (angles) // Normally, svc_serverinfo is the first command in the packet, but some // servers (eg, fitzquake) add in an svc_print command first. Allow // multiple svc_print commands (but nothing else) before the svc_serverinfo net_message->message->cursize = len; bytes = Qread (cls.demofile, net_message->message->data, len); if (bytes != len) goto done; MSG_BeginReading (net_message); while (!ret) { if (net_message->badread) goto done; c = MSG_ReadByte (net_message); switch (c) { case svc_print: MSG_ReadString (net_message); break; case svc_serverinfo: ret = 1; break; default: goto done; } } done: Qseek (cls.demofile, 0, SEEK_SET); return ret; } static void CL_StartDemo (void) { dstring_t *name; int c; bool neg = false; // disconnect from server CL_Disconnect (); // open the demo file name = dstring_strdup (demoname->str); QFS_DefaultExtension (name, ".dem"); Sys_Printf ("Playing demo from %s.\n", name->str); cls.demofile = QFS_FOpenFile (name->str); if (!cls.demofile) { Sys_Printf ("ERROR: couldn't open.\n"); cls.demonum = -1; // stop demo loop dstring_delete (name); return; } if (!demo_check_dem ()) { Sys_Printf ("%s is not a valid .dem file.\n", name->str); cls.demonum = -1; // stop demo loop dstring_delete (name); Qclose (cls.demofile); cls.demofile = 0; return; } cls.demoplayback = true; cl.viewstate.demoplayback = 1; CL_SetState (ca_connected); cls.forcetrack = 0; while ((c = Qgetc (cls.demofile)) != '\n') if (c == '-') neg = true; else cls.forcetrack = cls.forcetrack * 10 + (c - '0'); if (neg) cls.forcetrack = -cls.forcetrack; dstring_delete (name); } /* CL_PlayDemo_f play [demoname] */ static void CL_PlayDemo_f (void) { if (cmd_source != src_command) return; switch (Cmd_Argc ()) { case 1: if (!demoname->str[0]) goto playdemo_error; // fall through case 2: cls.demo_capture = 0; break; case 3: if (!strcmp (Cmd_Argv (2), "rec")) { cls.demo_capture = 1; break; } // fall through default: playdemo_error: Sys_Printf ("play : plays a demo\n"); return; } timedemo_runs = timedemo_count = 1; // make sure looped timedemos stop if (Cmd_Argc () > 1) dstring_copystr (demoname, Cmd_Argv (1)); CL_StartDemo (); } static void CL_StartTimeDemo (void) { CL_StartDemo (); // cls.td_starttime will be grabbed at the second frame of the demo, so // all the loading time doesn't get counted cls.timedemo = true; cls.td_starttime = 0; cls.td_startframe = host_framecount; cls.td_lastframe = -1; // get a new message this frame CL_TimeFrames_Reset (); if (demo_timeframes) demo_timeframes_isactive = 1; } static inline double sqr (double x) { return x * x; } static void CL_FinishTimeDemo (void) { int frames; float time; cls.timedemo = false; // the first frame didn't count frames = (host_framecount - cls.td_startframe) - 1; time = Sys_DoubleTime () - cls.td_starttime; if (!time) time = 1; Sys_Printf ("%i frame%s %.4g seconds %.4g fps\n", frames, frames == 1 ? "" : "s", time, frames / time); CL_TimeFrames_DumpLog (); demo_timeframes_isactive = 0; timedemo_count--; if (timedemo_data) { timedemo_data[timedemo_count].frames = frames; timedemo_data[timedemo_count].time = time; timedemo_data[timedemo_count].fps = frames / time; } if (timedemo_count > 0) { CL_StartTimeDemo (); } else { if (--timedemo_runs > 0 && timedemo_data) { double average = 0; double variance = 0; double min, max; int i; min = max = timedemo_data[0].fps; for (i = 0; i < timedemo_runs; i++) { average += timedemo_data[i].fps; min = min (min, timedemo_data[i].fps); max = max (max, timedemo_data[i].fps); } average /= timedemo_runs; for (i = 0; i < timedemo_runs; i++) variance += sqr (timedemo_data[i].fps - average); variance /= timedemo_runs; Sys_Printf ("timedemo stats for %d runs:\n", timedemo_runs); Sys_Printf (" average fps: %.3f\n", average); Sys_Printf (" min/max fps: %.3f/%.3f\n", min, max); Sys_Printf ("std deviation: %.3f fps\n", sqrt (variance)); } if (demo_quit) Cbuf_InsertText (host_cbuf, "quit\n"); } } /* CL_TimeDemo_f timedemo [demoname] */ static void CL_TimeDemo_f (void) { int count = 1; if (cmd_source != src_command) return; if (Cmd_Argc () < 2 || Cmd_Argc () > 3) { Sys_Printf ("timedemo [count]: gets demo speeds\n"); return; } timedemo_runs = timedemo_count = 1; // make sure looped timedemos stop if (Cmd_Argc () == 3) count = atoi (Cmd_Argv (2)); if (timedemo_data) { free (timedemo_data); timedemo_data = 0; } dstring_copystr (demoname, Cmd_Argv (1)); CL_StartTimeDemo (); timedemo_runs = timedemo_count = max (count, 1); timedemo_data = calloc (timedemo_runs, sizeof (td_stats_t)); } void CL_Demo_Init (void) { demoname = dstring_newstr (); demo_timeframes_isactive = 0; demo_timeframes_index = 0; demo_timeframes_array = NULL; Cvar_Register (&demo_gzip_cvar, 0, 0); Cvar_Register (&demo_speed_cvar, 0, 0); Cvar_Register (&demo_debug_cvar, 0, 0); Cvar_Register (&demo_quit_cvar, 0, 0); Cvar_Register (&demo_timeframes_cvar, 0, 0); Cmd_AddCommand ("record", CL_Record_f, "Record a demo, if no filename " "argument is given\n" "the demo will be called Year-Month-Day-Hour-Minute-" "Mapname"); Cmd_AddCommand ("stop", CL_Stop_f, "Stop recording a demo"); Cmd_AddCommand ("playdemo", CL_PlayDemo_f, "Play a recorded demo"); Cmd_AddCommand ("timedemo", CL_TimeDemo_f, "Play a demo as fast as your " "hardware can. Useful for benchmarking."); } static void CL_TimeFrames_Reset (void) { demo_timeframes_index = 0; free (demo_timeframes_array); demo_timeframes_array = NULL; } static void CL_TimeFrames_AddTimestamp (void) { if (!(demo_timeframes_index % CL_TIMEFRAMES_ARRAYBLOCK)) demo_timeframes_array = realloc (demo_timeframes_array, sizeof (demo_timeframes_array[0]) * ((demo_timeframes_index / CL_TIMEFRAMES_ARRAYBLOCK) + 1) * CL_TIMEFRAMES_ARRAYBLOCK); if (demo_timeframes_array == NULL) Sys_Error ("Unable to allocate timeframes buffer"); demo_timeframes_array[demo_timeframes_index] = Sys_DoubleTime (); demo_timeframes_index++; } static void CL_TimeFrames_DumpLog (void) { const char *filename = "timeframes.txt"; int i; long frame; QFile *outputfile; if (demo_timeframes_isactive == 0) return; Sys_Printf ("Dumping Timed Frames log: %s\n", filename); outputfile = QFS_Open (filename, "w"); if (!outputfile) { Sys_Printf ("Could not open: %s\n", filename); return; } for (i = 1; i < demo_timeframes_index; i++) { frame = (demo_timeframes_array[i] - demo_timeframes_array[i - 1]) * 1e6; Qprintf (outputfile, "%09ld\n", frame); } Qclose (outputfile); }