B7A: QMI DMS time vs VNIIFTRI NTP (DMS = UTC - 0.28 s, sigma 1 ms; NITZ = DMS truncated to 1 s). B7B: a 1970 -> 2026 date -s step is harmless for the modem stack. B7C: aurora-modem probes DMS/NITZ along the start flow and steps CLOCK_REALTIME once at the first valid sample (REG registered/attached), never RTC; background SNTP check (query only) after START OK. 3/3 class-A cold boots PASS (residual +0.04/+0.36/+0.84 s), cache 14fe453a written (B7C_WRITE_VERIFIED) and verified by a normal power-on (V1, +0.26 s). Also publishes the prerequisite R2 (boot-hang / lk eMMC investigation, T4 telnet baseline that B7C builds on) and R3 (autonomous cold boot, NCM loss) material, and extends tools/publish-sanitize.py to r2/, r3/, b7/. Binary images, initramfs, busybox and raw logs stay out (see b7/*/SHA256SUMS).
82 lines
6.7 KiB
Text
82 lines
6.7 KiB
Text
19:07:16.795 [ 0.000000] Linux version 7.2.7-aurora-bam1 (q@aiaiai) (aarch64-linux-gnu-gcc (Debian 14.2.0-19) 14.2.0, GNU ld (GNU Binutils for Debian) 2.44) #5 SMP PREEMPT Wed Sep 30 04:59:18 +06 2026
|
|
19:07:18.399 [ 1.178073] mmc0: new HS200 MMC card at address 0001
|
|
19:07:19.199 EMMC-RO-SUMMARY devices=30 all_ro=YES
|
|
19:07:24.207 [init] network: usb0 172.16[ 6.973070] [init] T4: telnetd started on 172.16.42.1:23
|
|
19:07:24.207 [init] T4: telnetd started on 172.16.42.1:23
|
|
19:07:26.610 B1_OK=1
|
|
19:07:26.610 ~ # [ 9.364871] [aurora-modem] === START (conf /etc/aurora/modem.conf, apn 'internet.beeline.ru', ip-type ipv4)
|
|
19:07:26.810 [ 9.446223] [aurora-modem] STATE OFF -> RMTFS_READY
|
|
19:07:26.810 [ 9.451354] [aurora-modem] STATE RMTFS_READY -> MPSS_BOOTING
|
|
19:07:27.410 [ 10.133331] [aurora-modem] STATE MPSS_BOOTING -> MPSS_RUNNING
|
|
19:07:30.411 [ 13.176702] [aurora-modem] STATE MPSS_RUNNING -> QMI_READY
|
|
19:07:30.612 [ 13.299537] [aurora-modem] TIME probe 1 [QMI_READY]: dms_ms=3230 dms_utc=315964803.230 nitz=none dms-nitz=- clock=331 -> INVALID (year<2026)
|
|
19:07:30.612 [ 13.353995] [aurora-modem] STATE QMI_READY -> SIM_READY
|
|
19:07:30.812 [ 13.463943] [aurora-modem] TIME probe 2 [SIM_READY]: dms_ms=3398 dms_utc=315964803.398 nitz=none dms-nitz=- clock=331 -> INVALID (year<2026)
|
|
19:07:34.019 [ 16.727535] [aurora-modem] STATE SIM_READY -> RADIO_ONLINE
|
|
19:07:34.219 [ 16.832714] [aurora-modem] TIME probe 3 [RADIO_ONLINE]: dms_ms=6766 dms_utc=315964806.766 nitz=none dms-nitz=- clock=334 -> INVALID (year<2026)
|
|
19:07:34.419 [ 17.174631] [aurora-modem] REG t+0.3s: not-registered-searching / PS detached / limited (limited-regional, camped) 250-99 pci=55 si=/156465929 cl=7661/156465929
|
|
19:07:34.619 [ 17.276741] [aurora-modem] TIME probe 4 [REG:not-registered-searching/detached]: dms_ms=7211 dms_utc=315964807.211 nitz=1980-01-06 00:00:07 dms-nitz=+0.25 clock=335 -> INVALID (year<2026)
|
|
19:07:37.820 [ 20.570023] [aurora-modem] REG t+3.7s: registered / PS attached / available (none, ps) 250-99 pci=55 si=7661/156465929 cl=7661/156465929
|
|
19:07:38.021 [ 20.675797] [aurora-modem] TIME probe 5 [REG:registered/attached]: dms_ms=1474992457208 dms_utc=1790957257.208 nitz=2026-10-02 16:07:37 dms-nitz=+0.24 clock=338 -> VALID (ok)
|
|
19:07:38.621 [ 21.412637] [aurora-modem] TIME SET rc=0 source=qmi-dms phase=REG:registered/attached old=339 (1970-01-01 00:05:39) new=1790957258 (2026-10-02 16:07:38) uptime=21.26 dms-nitz=+0.24 validation=VALID rtc=untouched
|
|
19:07:38.621 [ 21.426186] [aurora-modem] registered: MCC: '250' MNC: '99' Description: 'Beeline' MCC: '250' MNC: '99' after 4.6s
|
|
19:07:38.821 [ 21.438517] [aurora-modem] STATE RADIO_ONLINE -> REGISTERED
|
|
19:07:38.821 [ 21.548383] [aurora-modem] TIME probe 6 [REGISTERED]: dms_ms=1474992458078 dms_utc=1790957258.078 nitz=2026-10-02 16:07:38 dms-nitz=+0.11 clock=1790957258 -> VALID (ok)
|
|
19:07:53.058 <<<<<< message = "Allocate CID" (0x0022)
|
|
19:07:53.059 <<<<<< message = "Allocate CID" (0x0022)
|
|
19:07:53.460 <<<<<< message = "Allocate CID" (0x0022)
|
|
19:07:53.460 <<<<<< message = "Release CID" (0x0023)
|
|
19:07:53.460 <<<<<< message = "Allocate CID" (0x0022)
|
|
19:07:53.661 <<<<<< message = "Allocate CID" (0x0022)
|
|
19:07:53.661 <<<<<< message = "Release CID" (0x0023)
|
|
19:07:53.861 <<<<<< message = "Allocate CID" (0x0022)
|
|
19:07:53.861 <<<<<< message = "Allocate CID" (0x0022)
|
|
19:07:53.862 <<<<<< message = "Allocate CID" (0x0022)
|
|
19:07:54.062 <<<<<< message = "Allocate CID" (0x0022)
|
|
19:07:54.062 <<<<<< message = "Allocate CID" (0x0022)
|
|
19:07:54.263 <<<<<< message = "Allocate CID" (0x0022)
|
|
19:07:54.264 <<<<<< message = "Allocate CID" (0x0022)
|
|
19:07:54.464 <<<<<< message = "Allocate CID" (0x0022)
|
|
19:07:54.465 <<<<<< message = "Allocate CID" (0x0022)
|
|
19:07:54.466 <<<<<< message = "Allocate CID" (0x0022)
|
|
19:07:54.666 <<<<<< message = "Allocate CID" (0x0022)
|
|
19:07:54.667 <<<<<< message = "Allocate CID" (0x0022)
|
|
19:07:54.667 <<<<<< message = "Allocate CID" (0x0022)
|
|
19:07:54.874 <<<<<< message = "Allocate CID" (0x0022)
|
|
19:07:54.874 <<<<<< message = "Allocate CID" (0x0022)
|
|
19:07:54.874 <<<<<< message = "Allocate CID" (0x0022)
|
|
19:07:55.075 <<<<<< message = "Allocate CID" (0x0022)
|
|
19:08:02.488 <<<<<< translated = FAILURE: NotSupported
|
|
19:08:02.689 [1766]: <dbg> [1790957281.852195] [modem0] setup SIM hot swap (5/8): no need to register for SIM ICCID refresh events
|
|
19:08:02.889 <<<<<< translated = FAILURE: NotSupported
|
|
19:08:03.291 <<<<<< message = "UIM Get ICCID" (0x003C)
|
|
19:08:03.292 <<<<<< message = "UIM Get ICCID" (0x003C)
|
|
19:08:03.292 <<<<<< type = "ICCID" (0x01)
|
|
19:08:04.295 <<<<<< translated = FAILURE: NotProvisioned
|
|
19:08:04.496 <<<<<< translated = FAILURE: NotProvisioned
|
|
19:08:04.497 <<<<<< translated = FAILURE: NotProvisioned
|
|
19:08:06.304 <<<<<< type = "CID 3GPP" (0x1e)
|
|
19:08:28.125 [ 70.917784] [aurora-modem] STATE REGISTERED -> MM_READY
|
|
19:08:29.127 <<<<<< message = "UIM Get ICCID" (0x003C)
|
|
19:08:29.327 <<<<<< message = "UIM Get ICCID" (0x003C)
|
|
19:08:29.327 <<<<<< type = "ICCID" (0x01)
|
|
19:08:30.741 <<<<<< translated = FAILURE: InvalidQmiCommand
|
|
19:08:31.544 <<<<<< translated = FAILURE: MissingArgument
|
|
19:08:31.946 <<<<<< translated = FAILURE: DeviceNotReady
|
|
19:08:32.147 <<<<<< translated = FAILURE: InvalidArgument
|
|
19:08:32.348 <<<<<< translated = FAILURE: InvalidArgument
|
|
19:08:32.548 <<<<<< translated = FAILURE: MissingArgument
|
|
19:08:32.549 <<<<<< translated = FAILURE: DeviceNotReady
|
|
19:08:32.951 <<<<<< translated = FAILURE: InvalidArgument
|
|
19:08:33.151 <<<<<< translated = FAILURE: InvalidArgument
|
|
19:08:35.964 <<<<<< message = "Allocate CID" (0x0022)
|
|
19:08:36.165 <<<<<< message = "Allocate CID" (0x0022)
|
|
19:08:36.768 <<<<<< message = "Allocate CID" (0x0022)
|
|
19:08:36.968 <<<<<< message = "Release CID" (0x0023)
|
|
19:08:36.969 <<<<<< message = "Allocate CID" (0x0022)
|
|
19:08:36.969 <<<<<< message = "Release CID" (0x0023)
|
|
19:08:39.581 [ 82.322603] [aurora-modem] STATE MM_READY -> BEARER_CONNECTED
|
|
19:08:39.581 [ 82.337256] [aurora-modem] === START OK in 73.0s (wwan0 10.40.58.166/30, routes: 10.10.22.3 194.186.191.1 77.88.8.8 1.1.1.1 )
|
|
19:08:39.781 [ 82.445973] [aurora-modem] TIME probe 7 [BEARER_CONNECTED]: dms_ms=1474992518975 dms_utc=1790957318.975 nitz=2026-10-02 16:08:39 dms-nitz=+0.01 clock=1790957319 -> VALID (ok)
|
|
19:08:55.002 [ 97.777138] [aurora-modem] SNTP check ( 89.109.251.21 89.109.251.22 89.109.251.23): 12 replies; best offset delay server: +0.579549 0.050561 89.109.251.23: (offset > 0 = clock behind)
|
|
19:08:55.002 [ 97.782978] [aurora-modem] SNTP: |offset| < 1s - clock kept (no slew: STA_UNSYNC stays, RTC_SYSTOHC never engages)
|