stern-event-agent/gamelog.c

/* GAMELOG - a passive gameplay-event logger for Stern Spike 2.
 *
 * Logs, with RFC 3339 UTC timestamps (millisecond precision), to /dump/mode.log:
 *   EV    <event name>  - the game's bus events (game start, ball start/end,
 *                         bonus end, tilt warning, tilt), player, ball, score
 *   SHOT  <shot name>   - every shot the game dispatches while a ball is up
 *   SCORES              - all players' scores at each bonus end
 *   MODE START/END      - the game's own modes (Island Scenes and the rest of
 *                         the port's block_* set), with the score delta earned
 *                         across the mode
 *   AWARD id=<n>        - the game's award screens (extra ball = the
 *                         extra_ball_award value, default 13)
 *
 * Extra balls: an award matching extra_ball_award marks the NEXT ball start
 * as "ball N (EXTRA)" instead of advancing the ball number.
 *
 * The mode never begins(), never blocks, allocates nothing: it only watches.
 */

#include "pad_mode.h"

/* the runtime patch exposes the award screens it sees and the wall clock */
extern unsigned long gl_award_seq(void);
extern unsigned gl_last_award_id(void);
extern void gl_rfc3339(char *buf, unsigned cap);

static unsigned ball;                 /* ball in play, 1-based */
static unsigned extras_pending;       /* extra balls awarded, not yet played */
static unsigned char in_game;
static unsigned long award_seq_seen;
static unsigned extra_ball_award = 13; /* OB_SYS_EXTRA_BALL; port: value extra_ball_award */

static int ev_game_start, ev_ball_start, ev_ball_end, ev_bonus_end, ev_tilt_warn, ev_tilt;

/* the player's score, comma-separated, into a caller buffer */
static void score_str(char *out, unsigned cap, unsigned player)
{
    pm_commas(out, cap, pm_score(player));
}

static void scores_line(const char *tag)
{
    char tbuf[40], buf[128], one[32];
    unsigned p, n = 0;

    gl_rfc3339(tbuf, sizeof tbuf);
    buf[0] = 0;
    for (p = 1; p <= 4; p++) {
        score_str(one, sizeof one, p);
        n += (unsigned)pm_snprintf(buf + n, sizeof buf - n, "%sP%u=%s",
                                   n ? " " : "", p, one);
    }
    pm_log("[GAMELOG] %s %s %s", tbuf, tag, buf);
}

static void on_init(void)
{
    char tbuf[40];

    ball = 0;
    in_game = 0;
    extras_pending = 0;
    award_seq_seen = gl_award_seq();
    extra_ball_award = (unsigned)pm_port_value("extra_ball_award", 13);
    ev_game_start = pm_event("game_start");
    ev_ball_start = pm_event("ball_start");
    ev_ball_end   = pm_event("ball_end");
    ev_bonus_end  = pm_event("bonus_end");
    ev_tilt_warn  = pm_event("tilt_warning");
    ev_tilt       = pm_event("tilt");
    gl_rfc3339(tbuf, sizeof tbuf);
    pm_log("[GAMELOG] %s up: game %s %s, %d named shots; event ids %d/%d/%d/%d/%d/%d; extra_ball_award=%u",
           tbuf, pm_game(), pm_version(), pm_shot_count(),
           ev_game_start, ev_ball_start, ev_ball_end,
           ev_bonus_end, ev_tilt_warn, ev_tilt, extra_ball_award);
}

static void on_event(unsigned id)
{
    const char *name = pm_event_name(id);
    char tbuf[40], one[32];

    gl_rfc3339(tbuf, sizeof tbuf);
    if (id == (unsigned)ev_game_start) {
        ball = 0;
        extras_pending = 0;
        in_game = 1;
        pm_log("[GAMELOG] %s EV %s - GAME START", tbuf,
               name ? name : "game_start");
    } else if (id == (unsigned)ev_ball_start) {
        score_str(one, sizeof one, pm_player());
        if (extras_pending) {
            extras_pending--;
            pm_log("[GAMELOG] %s EV %s player=%u ball=%u (EXTRA BALL) score=%s", tbuf,
                   name ? name : "ball_start", pm_player(), ball, one);
        } else {
            ball++;
            pm_log("[GAMELOG] %s EV %s player=%u ball=%u score=%s", tbuf,
                   name ? name : "ball_start", pm_player(), ball, one);
        }
    } else if (id == (unsigned)ev_ball_end) {
        score_str(one, sizeof one, pm_player());
        pm_log("[GAMELOG] %s EV %s player=%u ball=%u score=%s", tbuf,
               name ? name : "ball_end", pm_player(), ball, one);
    } else if (id == (unsigned)ev_bonus_end) {
        pm_log("[GAMELOG] %s EV %s", tbuf, name ? name : "bonus_end");
        scores_line("SCORES");
    } else if (id == (unsigned)ev_tilt_warn) {
        pm_log("[GAMELOG] %s EV %s player=%u", tbuf,
               name ? name : "tilt_warning", pm_player());
    } else if (id == (unsigned)ev_tilt) {
        pm_log("[GAMELOG] %s EV %s player=%u ball=%u", tbuf,
               name ? name : "tilt", pm_player(), ball);
    }
}

static void on_shot(unsigned long long shot)
{
    const char *name;
    char tbuf[40], one[32];

    if (!in_game)                       /* attract-mode dispatches are noise */
        return;
    gl_rfc3339(tbuf, sizeof tbuf);
    name = pm_shot_name(shot);
    score_str(one, sizeof one, pm_player());
    if (name)
        pm_log("[GAMELOG] %s SHOT %s player=%u ball=%u score=%s", tbuf,
               name, pm_player(), ball, one);
    else
        pm_log("[GAMELOG] %s SHOT 0x%llx player=%u ball=%u score=%s", tbuf,
               shot, pm_player(), ball, one);
}

static void on_tick(void)
{
    /* award screens: the runtime hook counts them; log the new ones */
    while (award_seq_seen != gl_award_seq()) {
        char tbuf[40], one[32];
        award_seq_seen++;
        gl_rfc3339(tbuf, sizeof tbuf);
        if (gl_last_award_id() == extra_ball_award) {
            extras_pending++;
            pm_log("[GAMELOG] %s AWARD EXTRA BALL (id=%u) player=%u", tbuf,
                   gl_last_award_id(), pm_player());
        } else {
            score_str(one, sizeof one, pm_player());
            pm_log("[GAMELOG] %s AWARD id=%u player=%u score=%s", tbuf,
                   gl_last_award_id(), pm_player(), one);
        }
    }
}

static const struct pm_mode gamelog = {
    .name  = "GAMELOG",
    .init  = on_init,
    .tick  = on_tick,
    .event = on_event,
    .shot  = on_shot,
};

PM_REGISTER(gamelog);