/* * BPI-R64 quiescent nohz PPS test bench init. * * Runs as PID 1 from a baked-in initramfs or booted via init=. No shell, * no daemons, no network. Mounts procfs/sysfs/debugfs, primes CLOCK_REALTIME * from NMEA on /dev/ttyS1 (u-blox GNSS), binds hardpps to /dev/pps0, sets * adjtimex PLL/PPSFREQ/PPSTIME, then loops printing state to /dev/console * every 60 s. Goal: keep CPU0 as quiescent as possible so cycle_delta at * the PPS edge can span many-tick nohz gaps. */ #define _GNU_SOURCE #include #include #include #include #include #include #include #include #include #include #include #include #include #include #include #include #include #include #include #define PPS_DEV "/dev/pps0" #define NMEA_DEV "/dev/ttyS1" #define NTPERR "/sys/kernel/debug/pps_ntperr" #define NMEA_TIMEOUT_SEC 10 /* * Iteration of the 60s dump loop at which to stretch the GPS timepulse * period from 1s to PULSE_PERIOD_US. Gives hardpps ~5 min to lock at * 1Hz first. The pulse itself is a CPU wakeup, so 1Hz pulses cap idle * gaps at ~1s; multi-second nohz gaps need a slower pulse. hardpps * tolerates up to 9s spacing (PPS_VALID=10s watchdog). */ #define PULSE_STRETCH_ITER 4 #define PULSE_PERIOD_US 5000000 #define PULSE_LEN_US 100000 /* * Streaming variant of dump_lines for files bigger than one buffer * (e.g. the ftrace ring). Prints lines containing any needle; caps * output at max_lines to protect the 115200 console. */ static void dump_lines_stream(int cfd, const char *path, const char *const *needles, int max_lines) { char buf[4096], line[512]; unsigned int ln = 0; int printed = 0; ssize_t n; int fd = open(path, O_RDONLY); if (fd < 0) { dprintf(cfd, "# open %s: %s\n", path, strerror(errno)); return; } while (printed < max_lines && (n = read(fd, buf, sizeof(buf))) > 0) { for (ssize_t i = 0; i < n && printed < max_lines; i++) { if (buf[i] != '\n' && ln < sizeof(line) - 1) { line[ln++] = buf[i]; continue; } line[ln] = 0; ln = 0; for (int j = 0; needles[j]; j++) { if (strstr(line, needles[j])) { dprintf(cfd, "%s\n", line); printed++; break; } } } } close(fd); if (printed >= max_lines) dprintf(cfd, "# (output capped at %d lines)\n", max_lines); } #define TRACEFS "/sys/kernel/debug/tracing" static void set_sysctl(int cfd, const char *path, const char *val); static void trace_write(int cfd, const char *file, const char *val) { char path[256]; snprintf(path, sizeof(path), TRACEFS "/%s", file); set_sysctl(cfd, path, val); } static void set_sysctl(int cfd, const char *path, const char *val) { int fd = open(path, O_WRONLY); if (fd < 0 || write(fd, val, strlen(val)) < 0) dprintf(cfd, "sysctl %s=%s: %s\n", path, val, strerror(errno)); else dprintf(cfd, "sysctl %s=%s\n", path, val); if (fd >= 0) close(fd); } /* * Send UBX-CFG-TP5 to the u-blox module on NMEA_DEV to set the TIMEPULSE * period. period_us/len_us apply when locked to GNSS; when unlocked the * pulse is disabled (freqPeriod=0) so hardpps is never fed a freewheeling * pulse. Fletcher-8 checksum over class..payload. */ static void ubx_set_timepulse(int cfd, uint32_t period_us, uint32_t len_us) { uint8_t msg[8 + 32 + 2] = { 0xb5, 0x62, /* sync */ 0x06, 0x31, /* CFG-TP5 */ 32, 0, /* length LE */ /* payload */ 0, /* tpIdx: TIMEPULSE */ 1, /* version */ 0, 0, /* reserved */ 0, 0, /* antCableDelay (i16) */ 0, 0, /* rfGroupDelay (i16) */ }; uint8_t *p = msg + 6 + 8; uint32_t flags = 0x77; /* active | lockGnssFreq | lockedOtherSet | * isLength | alignToTow | polarity(rising) */ uint8_t ck_a = 0, ck_b = 0; int fd; /* freqPeriod: 0 = no pulse when unlocked */ memset(p, 0, 4); p += 4; /* freqPeriodLock */ p[0] = period_us; p[1] = period_us >> 8; p[2] = period_us >> 16; p[3] = period_us >> 24; p += 4; /* pulseLenRatio (unlocked): 0 */ memset(p, 0, 4); p += 4; /* pulseLenRatioLock */ p[0] = len_us; p[1] = len_us >> 8; p[2] = len_us >> 16; p[3] = len_us >> 24; p += 4; /* userConfigDelay */ memset(p, 0, 4); p += 4; /* flags */ p[0] = flags; p[1] = flags >> 8; p[2] = flags >> 16; p[3] = flags >> 24; for (unsigned int i = 2; i < sizeof(msg) - 2; i++) { ck_a += msg[i]; ck_b += ck_a; } msg[sizeof(msg) - 2] = ck_a; msg[sizeof(msg) - 1] = ck_b; fd = open(NMEA_DEV, O_RDWR | O_NOCTTY); if (fd < 0) { dprintf(cfd, "ubx: open %s: %s\n", NMEA_DEV, strerror(errno)); return; } /* raw 115200 -- a cooked/wrong-baud port mangles the binary frame. * Set c_cflag explicitly: cfmakeraw() does not set CREAD (no RX * without it) or CLOCAL. */ { struct termios tio; if (tcgetattr(fd, &tio) == 0) { cfmakeraw(&tio); tio.c_cflag = CS8 | CREAD | CLOCAL; cfsetispeed(&tio, B115200); cfsetospeed(&tio, B115200); tcsetattr(fd, TCSANOW, &tio); } } if (write(fd, msg, sizeof(msg)) != sizeof(msg)) { dprintf(cfd, "ubx: write: %s\n", strerror(errno)); close(fd); return; } tcdrain(fd); /* look for UBX-ACK-ACK (b5 62 05 01) vs ACK-NAK (05 00) */ { uint8_t rb[512]; ssize_t n, total = 0; time_t deadline = time(NULL) + 2; const char *verdict = "no ack seen"; while (time(NULL) < deadline && total < (ssize_t)sizeof(rb)) { struct pollfd pfd = { .fd = fd, .events = POLLIN }; if (poll(&pfd, 1, 200) <= 0) continue; n = read(fd, rb + total, sizeof(rb) - total); if (n <= 0) continue; total += n; for (ssize_t i = 0; i + 3 < total; i++) { if (rb[i] == 0xb5 && rb[i+1] == 0x62 && rb[i+2] == 0x05) { verdict = rb[i+3] == 1 ? "ACK-ACK" : "ACK-NAK"; deadline = 0; break; } } } dprintf(cfd, "ubx: timepulse period %u us (len %u us): %s\n", period_us, len_us, verdict); } close(fd); } static void die(const char *what) { dprintf(2, "FATAL: %s: %s\n", what, strerror(errno)); sync(); sleep(60); reboot(RB_AUTOBOOT); _exit(1); } static void mount_or_die(const char *src, const char *tgt, const char *type, unsigned long flags) { if (mkdir(tgt, 0755) < 0 && errno != EEXIST) die(tgt); if (mount(src, tgt, type, flags, NULL) < 0 && errno != EBUSY) die(type); } static void dump_file(int cfd, const char *path, const char *tag) { int fd = open(path, O_RDONLY); char buf[4096]; ssize_t n; if (fd < 0) { dprintf(cfd, "# %s: open %s: %s\n", tag, path, strerror(errno)); return; } dprintf(cfd, "# ---- %s ----\n", tag); while ((n = read(fd, buf, sizeof(buf))) > 0) write(cfd, buf, n); close(fd); } /* * Print only the lines of @path containing one of the needles -- keeps * the 60s serial dump short (a full /proc/interrupts is ~2.5kB down a * 115200 console, and the TX itself perturbs the quiescence we're * trying to measure). */ static void dump_lines(int cfd, const char *path, const char *const *needles) { char buf[8192]; ssize_t n, total = 0; int fd = open(path, O_RDONLY); if (fd < 0) { dprintf(cfd, "# open %s: %s\n", path, strerror(errno)); return; } while (total < (ssize_t)sizeof(buf) - 1 && (n = read(fd, buf + total, sizeof(buf) - 1 - total)) > 0) total += n; close(fd); buf[total] = 0; char *save = NULL; for (char *line = strtok_r(buf, "\n", &save); line; line = strtok_r(NULL, "\n", &save)) { for (int i = 0; needles[i]; i++) { if (strstr(line, needles[i])) { dprintf(cfd, "%s\n", line); break; } } } } /* * Parse a $G[NP]RMC sentence and set CLOCK_REALTIME to its UTC time+date * if the validity flag says 'A'. RMC arrives ~50-100ms AFTER the pulse it * refers to, so the wall clock ends up ~100ms ahead of true UTC. That is * within the ~500ms hardpps sanity window; the pulse discipline drives * the residual to zero from there. * * RMC format: * $GNRMC,hhmmss.sss,A,lat,N,lon,E,speed,course,ddmmyy,mag,ew,mode*cs * Field indices (0-based, after '$'-prefixed talker+type): * 1: time, 2: status ('A'=valid, 'V'=warning), 9: date */ static int nmea_prime_realtime(int cfd) { int fd; struct termios tio; char buf[512]; char sentence[128]; unsigned int sn = 0; time_t deadline; fd = open(NMEA_DEV, O_RDONLY | O_NOCTTY | O_NONBLOCK); if (fd < 0) { dprintf(cfd, "nmea: open %s: %s (skipping prime)\n", NMEA_DEV, strerror(errno)); return -1; } if (tcgetattr(fd, &tio) == 0) { cfmakeraw(&tio); tio.c_cflag = CS8 | CREAD | CLOCAL; cfsetispeed(&tio, B115200); cfsetospeed(&tio, B115200); tcsetattr(fd, TCSANOW, &tio); } deadline = time(NULL) + NMEA_TIMEOUT_SEC; dprintf(cfd, "nmea: reading %s for up to %d s\n", NMEA_DEV, NMEA_TIMEOUT_SEC); while (time(NULL) < deadline) { ssize_t n = read(fd, buf, sizeof(buf)); if (n <= 0) { if (errno == EAGAIN) { usleep(50 * 1000); continue; } break; } for (ssize_t i = 0; i < n; i++) { if (buf[i] == '\n' || sn >= sizeof(sentence) - 1) { sentence[sn] = 0; sn = 0; /* accept $GxRMC where x is any talker */ if (strncmp(sentence, "$G", 2) == 0 && strncmp(sentence + 3, "RMC,", 4) == 0) { /* tokenize on commas */ char *fields[16] = { 0 }; int nf = 0; char *p = sentence, *tok; while (nf < 16 && (tok = strsep(&p, ","))) { fields[nf++] = tok; } if (nf >= 10 && fields[2] && fields[2][0] == 'A' && fields[1] && strlen(fields[1]) >= 6 && fields[9] && strlen(fields[9]) >= 6) { /* time hhmmss[.sss], date ddmmyy */ char h[3] = { fields[1][0], fields[1][1], 0 }; char m[3] = { fields[1][2], fields[1][3], 0 }; char s[3] = { fields[1][4], fields[1][5], 0 }; char dd[3] = { fields[9][0], fields[9][1], 0 }; char mm[3] = { fields[9][2], fields[9][3], 0 }; char yy[3] = { fields[9][4], fields[9][5], 0 }; struct tm tm = { .tm_hour = atoi(h), .tm_min = atoi(m), .tm_sec = atoi(s), .tm_mday = atoi(dd), .tm_mon = atoi(mm) - 1, .tm_year = 100 + atoi(yy), }; setenv("TZ", "UTC0", 1); tzset(); time_t t = mktime(&tm); if (t > 0) { struct timespec ts = { .tv_sec = t, .tv_nsec = 0 }; if (clock_settime(CLOCK_REALTIME, &ts) == 0) { dprintf(cfd, "nmea: primed CLOCK_REALTIME " "to %04d-%02d-%02dT%02d:%02d:%02dZ " "(RMC ~50-100ms stale)\n", tm.tm_year + 1900, tm.tm_mon + 1, tm.tm_mday, tm.tm_hour, tm.tm_min, tm.tm_sec); close(fd); return 0; } else { dprintf(cfd, "nmea: clock_settime: %s\n", strerror(errno)); } } } } } else { if (buf[i] != '\r') sentence[sn++] = buf[i]; } } } dprintf(cfd, "nmea: no valid RMC fix within %d s " "(proceeding with unprimed clock)\n", NMEA_TIMEOUT_SEC); close(fd); return -1; } int main(int argc, char **argv) { int pps_fd, cfd = 1; /* /dev/console via stdout */ int noseed = 0; struct pps_bind_args ba = { .tsformat = PPS_TSFMT_TSPEC, .edge = PPS_CAPTUREASSERT, .consumer = PPS_KC_HARDPPS, }; struct timex tx; struct timespec ts; unsigned int iter = 0; mount_or_die("devtmpfs", "/dev", "devtmpfs", 0); mount_or_die("proc", "/proc", "proc", 0); mount_or_die("sysfs", "/sys", "sysfs", 0); mount_or_die("debugfs", "/sys/kernel/debug", "debugfs", 0); /* stdout/stderr onto /dev/console explicitly */ int c = open("/dev/console", O_WRONLY); if (c >= 0) { dup2(c, 1); dup2(c, 2); if (c > 2) close(c); } /* * "noseed" on the kernel command line (passed through to PID1 as * an argument) skips the pulse-phase step and frequency preset: * hardpps starts from the raw ~100ms NMEA offset and the raw * crystal frequency error, so the run captures the discipline's * own convergence rather than the pre-seeded floor. */ for (int i = 1; i < argc; i++) if (argv[i] && !strcmp(argv[i], "noseed")) noseed = 1; dprintf(cfd, "\n=========================================================\n"); dprintf(cfd, "ntptest-init: PID1 up, quiescent nohz PPS soak%s\n", noseed ? " (noseed)" : ""); dprintf(cfd, "=========================================================\n"); dprintf(cfd, "Press 'b' within 5s to hand off to real init (/sbin/init)\n"); { struct pollfd pfd = { .fd = 0, .events = POLLIN }; struct termios told, tnew; int has_tty = (tcgetattr(0, &told) == 0); if (has_tty) { tnew = told; tnew.c_lflag &= ~(ICANON | ECHO); tnew.c_cc[VMIN] = 0; tnew.c_cc[VTIME] = 0; tcsetattr(0, TCSANOW, &tnew); } time_t deadline = time(NULL) + 5; while (time(NULL) < deadline) { if (poll(&pfd, 1, 500) > 0 && (pfd.revents & POLLIN)) { char c; if (read(0, &c, 1) == 1 && (c == 'b' || c == 'B')) { dprintf(cfd, "\nhanding off to /sbin/init\n"); if (has_tty) tcsetattr(0, TCSANOW, &told); execl("/sbin/init", "/sbin/init", (char *)NULL); execl("/lib/systemd/systemd", "/lib/systemd/systemd", (char *)NULL); dprintf(cfd, "exec real init failed: %s\n", strerror(errno)); die("exec"); } } } if (has_tty) tcsetattr(0, TCSANOW, &told); dprintf(cfd, "no 'b' pressed, continuing as test bench\n"); } nmea_prime_realtime(cfd); /* * Stretch the timepulse to PULSE_PERIOD_US now, while the port is * warm from the NMEA read -- UBX TX only works in this window; * later sends land on a runtime-suspended 8250 and are lost (the * ACK RX path never works, so "no ack seen" is expected even on * success -- verify by the per-minute pulse count in the drains). * The PPS_FETCH prime below tolerates the long period (7s timeout) * and hardpps locks fine at 5s spacing (PPS_VALID watchdog is 10s). */ ubx_set_timepulse(cfd, PULSE_PERIOD_US, PULSE_LEN_US); pps_fd = open(PPS_DEV, O_RDWR); if (pps_fd < 0) die("open " PPS_DEV); /* * Multi-pulse seed before binding hardpps. NMEA got us within * ~100ms of UTC. Then, over several pulses: * - step out the residual phase via ADJ_SETOFFSET whenever it * exceeds a small threshold, and * - estimate the frequency error from consecutive pulse phases * and pre-set it via ADJ_FREQUENCY. * The aim is that hardpps starts with sub-µs phase and sub-ppm * freq error: with STA_PPSTIME the kernel delivers time_offset * UNDAMPED (ntp_offset_chunk returns the whole thing), so a large * initial error can command mult excursions beyond maxadj and the * discipline spirals (observed: mult overflow WARN + 300ms * "jitter" at 5s pulse spacing on cold boot). */ if (noseed) { dprintf(cfd, "pps seed: skipped (noseed) -- hardpps gets the " "raw NMEA offset and crystal freq error\n"); } else { int i; long prev_phase = 0; int have_prev = 0; for (i = 0; i < 5; i++) { struct pps_fdata fd_arg = { .timeout = { .sec = 12, .nsec = 0 }, }; long ns, phase; if (ioctl(pps_fd, PPS_FETCH, &fd_arg) < 0) { dprintf(cfd, "pps seed: PPS_FETCH: %s\n", strerror(errno)); break; } ns = fd_arg.info.assert_tu.nsec; /* signed phase vs nearest second boundary */ phase = (ns < 500000000) ? ns : ns - 1000000000L; dprintf(cfd, "pps seed: pulse %d seq=%u phase=%+ld ns\n", i, fd_arg.info.assert_sequence, phase); /* * Frequency estimate from the drift between two * consecutive un-stepped pulses. Only valid if we * did NOT step in between. */ if (have_prev) { long drift = phase - prev_phase; /* pulse period in seconds */ long per = (PULSE_PERIOD_US + 500000) / 1000000; long ppb = drift / per; struct timex ftx; memset(&ftx, 0, sizeof(ftx)); ftx.modes = 0; adjtimex(&ftx); /* freq is scaled ppm (2^-16); ppb*65536/1000 */ ftx.freq += (long)(((long long)ppb * 65536) / 1000); ftx.modes = ADJ_FREQUENCY; if (adjtimex(&ftx) < 0) dprintf(cfd, "pps seed: ADJ_FREQUENCY: %s\n", strerror(errno)); else dprintf(cfd, "pps seed: drift %+ld ns/%lds " "= %+ld ppb -> freq=%ld\n", drift, per, ppb, ftx.freq); /* * Freq is corrected; step out the remaining * phase and hand over to hardpps clean. */ if (labs(phase) > 500) { struct timex adj; long corr = -phase; memset(&adj, 0, sizeof(adj)); adj.modes = ADJ_SETOFFSET | ADJ_NANO; adj.time.tv_sec = corr / 1000000000L; adj.time.tv_usec = corr % 1000000000L; if (corr < 0 && adj.time.tv_usec != 0) { adj.time.tv_sec -= 1; adj.time.tv_usec += 1000000000L; } if (adjtimex(&adj) == 0) dprintf(cfd, "pps seed: final step %+ld ns\n", corr); } i++; break; } /* * Step out residual phase -- but only above a * threshold LARGER than one pulse period's crystal * drift (~45µs at 9ppm x 5s), else we step every * pulse and the drift pair below never survives to * estimate frequency. Below the threshold, leave the * phase for the freq estimate + hardpps to handle. */ if (labs(phase) > 150000) { struct timex adj; long corr = -phase; memset(&adj, 0, sizeof(adj)); adj.modes = ADJ_SETOFFSET | ADJ_NANO; adj.time.tv_sec = corr / 1000000000L; adj.time.tv_usec = corr % 1000000000L; if (corr < 0 && adj.time.tv_usec != 0) { adj.time.tv_sec -= 1; adj.time.tv_usec += 1000000000L; } if (adjtimex(&adj) < 0) dprintf(cfd, "pps seed: ADJ_SETOFFSET: %s\n", strerror(errno)); else dprintf(cfd, "pps seed: stepped %+ld ns\n", corr); have_prev = 0; /* step invalidates drift pair */ } else { prev_phase = phase; have_prev = 1; /* two consecutive clean sub-2µs pulses: done */ if (i >= 2 && labs(phase) <= 2000) break; } } dprintf(cfd, "pps seed: done after %d pulses\n", i + 1); } if (ioctl(pps_fd, PPS_KC_BIND, &ba) < 0) die("PPS_KC_BIND"); dprintf(cfd, "bound hardpps consumer to " PPS_DEV "\n"); memset(&tx, 0, sizeof(tx)); tx.modes = ADJ_STATUS; tx.status = STA_PPSFREQ | STA_PPSTIME | STA_PLL; if (adjtimex(&tx) < 0) die("adjtimex ADJ_STATUS"); dprintf(cfd, "adjtimex: STA_PPSFREQ|STA_PPSTIME|STA_PLL set, " "status=0x%x\n", tx.status); /* * Quiesce periodic wakeup sources so idle gaps are bounded by the * PPS pulse, not by housekeeping timers. Anything left waking at * 1Hz shows up in the iter-1 timer_list snapshot below. */ set_sysctl(cfd, "/proc/sys/vm/stat_interval", "60"); set_sysctl(cfd, "/proc/sys/kernel/watchdog", "0"); /* * Keep KERN_INFO discipline traces (hardpps-phase/ntp-so/tk-mult) * off the serial console -- 8250 TX runs with irqs masked and * corrupts pulse timestamps. They remain in the dmesg ring; * WARNs (level 4) still reach the console. */ set_sysctl(cfd, "/proc/sys/kernel/printk", "5 4 1 5"); /* * schedutil's per-CPU sugov kthreads are SCHED_DEADLINE tasks whose * dl_task_timer re-arms ~1/s on each CPU even when idle. Switch to * the performance governor to park them (fixed max freq also * removes cpufreq transitions as a jitter source). */ set_sysctl(cfd, "/sys/devices/system/cpu/cpufreq/policy0/scaling_governor", "performance"); /* * The per-CPU fair dl_server (CFS starvation protection) re-arms a * ~1s dl_task_timer on every CPU with CFS load -- the last periodic * waker capping idle gaps. Runtime 0 disables it; harmless here * (the only CFS task sleeps 60s at a time). */ set_sysctl(cfd, "/sys/kernel/debug/sched/fair_server/cpu0/runtime", "0"); set_sysctl(cfd, "/sys/kernel/debug/sched/fair_server/cpu1/runtime", "0"); /* candidate HZ/2 schedule_timeout() loops seen in the expiry trace */ set_sysctl(cfd, "/proc/sys/vm/compaction_proactiveness", "0"); set_sysctl(cfd, "/sys/kernel/mm/transparent_hugepage/khugepaged/scan_sleep_millisecs", "60000"); set_sysctl(cfd, "/sys/kernel/mm/transparent_hugepage/khugepaged/alloc_sleep_millisecs", "60000"); /* * The ethernet stack polls even with no interface up: * mt7530_stats_poll (DSA switch MIB counters) and * mtk_hw_reset_monitor_work (mtk_eth_soc reset watchdog), both * ~1s non-deferrable delayed works. Unbinding at runtime OOPSes * (mt7530_remove NULL regulator on BPI-R64), so the bench boot * env disables the ethernet node in the DT instead: * fdt addr 0x4c000000 ; fdt set /ethernet@1b100000 status disabled * If the works are seen in the expiry trace, check the boot env. */ /* * Full dumps go to disk (root is mounted rw -- we ARE running from * it); serial gets a one-line summary. Both are emitted immediately * AFTER a pulse edge (PPS_FETCH below), so the console TX and mmc * irqs land in the first ~100ms of the 5s inter-pulse window and * never corrupt a pulse timestamp. (Observed: dumping asynchronously * put 8250 TX irq-masked windows under pulses -> ±25µs timestamp * excursions + a 4-pulse recovery transient every minute.) */ int lfd = open("/root/ntptest/bench.log", O_WRONLY | O_APPEND | O_CREAT, 0644); if (lfd < 0) { dprintf(cfd, "bench.log: %s (falling back to console)\n", strerror(errno)); lfd = cfd; } /* * Drain kernel messages (incl. the KERN_INFO discipline traces * that no longer reach the serial console) to disk each iteration * -- the dmesg ring would wrap long before morning. */ int kfd = open("/dev/kmsg", O_RDONLY | O_NONBLOCK); /* main sample loop */ for (iter = 0; ; iter++) { sleep(55); /* wait for the next pulse edge, then dump in its shadow */ { struct pps_fdata fd_arg = { .timeout = { .sec = 12, .nsec = 0 }, }; ioctl(pps_fd, PPS_FETCH, &fd_arg); } clock_gettime(CLOCK_REALTIME, &ts); memset(&tx, 0, sizeof(tx)); if (adjtimex(&tx) < 0) { dprintf(cfd, "adjtimex sample: %s\n", strerror(errno)); continue; } /* full dump to disk */ dprintf(lfd, "\n==== t=%ld.%09ld iter=%u ====\n", (long)ts.tv_sec, ts.tv_nsec, iter); dprintf(lfd, "adjtimex: status=0x%x off=%ld freq=%ld " "ppsfreq=%ld jitter=%ld shift=%d stabil=%ld " "jitcnt=%ld calcnt=%ld errcnt=%ld stbcnt=%ld " "maxerror=%ld esterror=%ld\n", tx.status, tx.offset, tx.freq, tx.ppsfreq, tx.jitter, tx.shift, tx.stabil, tx.jitcnt, tx.calcnt, tx.errcnt, tx.stbcnt, tx.maxerror, tx.esterror); /* * Drain the per-pulse ring to disk, computing per-minute * summary stats of the pulse phase (col 5) and snapshot * ntp_error (col 1) for the serial heartbeat on the way. */ long ph_max = 0, ne_max = 0; long long ph_sum = 0, ne_sum = 0; int n_pulses = 0; long hist[16] = { 0 }, hist_max = 0; { char dbuf[8192], line[256]; unsigned int ln = 0; ssize_t n; int dfd = open(NTPERR, O_RDONLY); dprintf(lfd, "# ---- pps_ntperr drain ----\n"); while (dfd >= 0 && (n = read(dfd, dbuf, sizeof(dbuf))) > 0) { write(lfd, dbuf, n); for (ssize_t i = 0; i < n; i++) { if (dbuf[i] != '\n' && ln < sizeof(line) - 1) { line[ln++] = dbuf[i]; continue; } line[ln] = 0; ln = 0; long ne, ph; long long d1, d2, d3; if (sscanf(line, "%ld %lld %lld %lld %ld", &ne, &d1, &d2, &d3, &ph) == 5) { n_pulses++; ne_sum += ne; ph_sum += ph; if (labs(ne) > labs(ne_max)) ne_max = ne; if (labs(ph) > labs(ph_max)) ph_max = ph; } else if (sscanf(line, "# accum_hist (log2 intervals/advance): " "%ld %ld %ld %ld %ld %ld %ld %ld " "%ld %ld %ld %ld %ld %ld %ld %ld", &hist[0], &hist[1], &hist[2], &hist[3], &hist[4], &hist[5], &hist[6], &hist[7], &hist[8], &hist[9], &hist[10], &hist[11], &hist[12], &hist[13], &hist[14], &hist[15]) == 16) { /* captured */ } else { sscanf(line, "# accum_max_intervals: %ld", &hist_max); } } } if (dfd >= 0) close(dfd); } { static const char *const needles[] = { "arch_timer", "pps", "ttyS0", NULL }; dump_lines(lfd, "/proc/interrupts", needles); } /* append new kernel messages (one record per read) */ if (kfd >= 0) { char kbuf[1024]; ssize_t kn; dprintf(lfd, "# ---- kmsg ----\n"); while ((kn = read(kfd, kbuf, sizeof(kbuf))) > 0) write(lfd, kbuf, kn); } fsync(lfd); /* two-line heartbeat to serial */ if (lfd != cfd) { dprintf(cfd, "iter=%u t=%ld off=%ld freq=%ld jitter=%ld " "shift=%d calcnt=%ld errcnt=%ld n=%d " "phase avg=%ld max=%ld ntperr avg=%ld max=%ld\n", iter, (long)ts.tv_sec, tx.offset, tx.freq, tx.jitter, tx.shift, tx.calcnt, tx.errcnt, n_pulses, n_pulses ? (long)(ph_sum / n_pulses) : 0, ph_max, n_pulses ? (long)(ne_sum / n_pulses) : 0, ne_max); /* * Sleep stats: log2 gap histogram b0..b10+, and the * longest single advance (1250 ticks = a full 5s * pulse-to-pulse sleep; ~250 = a skew-bounded sleep * ended at the second boundary by the deferment fix). */ dprintf(cfd, " gaps b0-5=%ld b6=%ld b7=%ld b8=%ld " "b9=%ld b10=%ld max=%ld\n", hist[0] + hist[1] + hist[2] + hist[3] + hist[4] + hist[5], hist[6], hist[7], hist[8], hist[9], hist[10], hist_max); } /* * 'b' on the console at any point during the run hands off * to the real init (no power cycle -- GPS keeps its 5s * timepulse config). Checked once per iteration, in the * pulse shadow like everything else. */ { struct pollfd pfd = { .fd = 0, .events = POLLIN }; char c; while (poll(&pfd, 1, 0) > 0 && read(0, &c, 1) == 1) { if (c == 'b' || c == 'B') { /* * Warm reboot (GPS keeps its RAM * config incl. the 5s timepulse). * Catch u-boot's autoboot prompt * and 'run boot_fedora' to harvest. */ dprintf(cfd, "\nsync+reboot -- catch " "u-boot for boot_fedora\n"); fsync(lfd); sync(); reboot(RB_AUTOBOOT); } } } } return 0; }