Improvement: warnings that should be info level

[irfanguder]

I am seeing these lines of warnings for the same two days several times in the logs. Does this lead to problem?
Thanks

W (09:08:59.179) edf_gen: STR.edf: 20260807 session 8 window 1444..1449 min is outside the day — entry skipped
W (09:08:59.217) edf_gen: STR.edf: 20260805 session 0 window 1333..1449 min is outside the day — entry skipped
W (09:09:16.266) edf_gen: STR.edf: 20260807 session 8 window 1444..1449 min is outside the day — entry skipped
W (09:09:16.301) edf_gen: STR.edf: 20260805 session 0 window 1333..1449 min is outside the day — entry skipped
W (09:09:19.510) edf_gen: STR.edf: 20260807 session 8 window 1444..1449 min is outside the day — entry skipped
W (09:09:19.547) edf_gen: STR.edf: 20260805 session 0 window 1333..1449 min is outside the day — entry skipped
W (09:09:22.245) edf_gen: STR.edf: 20260807 session 8 window 1444..1449 min is outside the day — entry skipped
W (09:09:22.282) edf_gen: STR.edf: 20260805 session 0 window 1333..1449 min is outside the day — entry skipped
W (09:09:24.937) edf_gen: STR.edf: 20260807 session 8 window 1444..1449 min is outside the day — entry skipped
W (09:09:24.974) edf_gen: STR.edf: 20260805 session 0 window 1333..1449 min is outside the day — entry skipped
W (09:09:42.740) edf_gen: STR.edf: 20260807 session 8 window 1444..1449 min is outside the day — entry skipped
W (09:09:42.775) edf_gen: STR.edf: 20260805 session 0 window 1333..1449 min is outside the day — entry skipped
W (09:09:46.063) edf_gen: STR.edf: 20260807 session 8 window 1444..1449 min is outside the day — entry skipped

[ilyakruchinin]

Thank you for raising this. I'll check and will get back to you.

[ilyakruchinin]

I'm wondering if there is something else to it.
Could you please provide the full log file?

[irfanguder]

I will recreate all EDF and reset state, after that I will send you the log files, but meanwhile I see these lines in the logs. They may help

I (11:05:38.512) netprov: recreate_edfs_task: upload window = 10 days (newest first)
W (11:05:38.701) netprov: recreate_edfs: skipping 20260705_153040 (invalid start_epoch_ms=0)
W (11:05:38.746) netprov: recreate_edfs: skipping 20260705_205251 (invalid start_epoch_ms=0)
I (11:05:39.562) netprov: recreate_edfs_task: found 88 sessions

W (11:10:58.934) edf_gen: session 20260807_052559 has no ident.json (recovered session?) — using /somnotrace/.somnotrace/sessions/streams/20260806/20260807_095644_ident.json from the same day

[irfanguder]

Log file

somnotrace-logs.3.txt

[ilyakruchinin]

Analysis of "outside the day — entry skipped" Warnings and Irfan's Log

1. What is the Warning: "window X..Y min is outside the day — entry skipped"?

The Context & Invariant

In ResMed AirSense 11 data architecture, STR.edf is the multi-day summary file. Each record in STR.edf represents one 24-hour "noon-day" running from 12:00 PM local time to 12:00 PM the following day.

Inside STR.edf, the signals MaskOn and MaskOff (along with mask_on_extra and mask_off_extra) store the start and end of each therapy session expressed in minutes from noon:

• Valid range: 0 to 1440 minutes.
• The Consumer Invariant (OSCAR): If any session interval falls outside 0..1440 (e.g. < 0 or > 1440), OSCAR declares:
  "Mask times are out of range. Possible SDcard corruption"
  and discards the entire day's session times and mask metrics.

To prevent generating corrupt files that OSCAR will reject, SomnoTrace has a safety guard in main/edf_summary.c:905-911:

• If min_from_noon < 0 or min_from_noon + dur > 1440, SomnoTrace skips that specific session entry and logs the warning instead of writing an out-of-bounds value.

---

Why Does it Compute Out-of-Bounds Windows?

This occurs when NTP clock drift shifts an edge session across the 12:00 PM noon boundary:

1. Inside the AS11 Summary Spool (.spool):

   • The AS11 stamps PeriodStart at its internal noon (e.g. 12:00:00 AS11 time).
   • It records each session's start timestamp ts in AS11 time.
   • On the AS11 itself, all sessions for that day naturally fall within [0, 1440] minutes of PeriodStart.

2. How SomnoTrace Evaluates the Timestamp:

   • SomnoTrace computes: event_ntp_ms = session_ts + clock_drift_ms.
   • It computes noon_epoch_ms from civil calendar noon (as11_time_local_noon_epoch()).

3. The Effect of Clock Drift on Boundary Sessions:

   • In Your Log (Negative Drift: -492,355 ms ≈ -8.2 minutes):
     • Your AS11 clock was running ~8 minutes ahead of real time.
     • You had a brief blip/session at 12:04 PM AS11 time (+4 min from AS11 noon).
     • SomnoTrace applied the -8.2 min drift: 4 - 8.2 = -4.2 min (rounded to -3 min).
     • Because -3 < 0, it fell before civil noon and the guard dropped it:
       STR.edf: 20260703 session 0 window -3..-3 min is outside the day — entry skipped
   • In Irfan's Log (Positive Drift: +628,028 ms ≈ +10.5 minutes):
     • Irfan's AS11 clock was running ~10 minutes behind real time.
     • Irfan had a therapy session ending at 11:58 AM AS11 time (+1438 min).
     • SomnoTrace applied the +10.5 min drift: 1438 + 10.5 = 1448.5 min (1449 min).
     • Because 1449 > 1440, it fell past civil noon the next day and the guard dropped it:
       STR.edf: 20260807 session 8 window 1444..1449 min is outside the day — entry skipped
STR.edf: 20260805 session 0 window 1333..1449 min is outside the day — entry skipped

---

Why Did the Warning Repeat So Many Times in Irfan's Log?

• In Irfan's log, Irfan executed the web UI action: recreate ALL EDFs (destructive).
• This initiated a batch rebuild across 88 historical sessions.
• Each time a session was rebuilt, STR.edf was regenerated from all historical summary spools.
• Because days 20260807 and 20260805 contained those boundary sessions, the warning was logged once per rebuild iteration (over 30 times).

---

2. Full Audit of Other Warnings and Errors in Irfan's Log

Analysis of all 4,378 lines in somnotrace-logs.irfan-outside-the-day.txt reveals zero fatal crashes (ESP_LOGE), but highlights several background conditions:

A. SleepHQ Import Finalization Failures (Lines 3483, 3605, 4253, 4375)

• Log message:
  upload_shq: import processing failed for day 20260807, resetting TLS connection
up_sched: sleephq: finalise failed for 20260807 — day stays pending
up_sched: sleephq: cooldown 1 min (remote finalise failed)
• Cause: SleepHQ's cloud ingestion API returned status: failed when asked to process the uploaded bundle for days 20260807 and 20260808.
• Behavior: SomnoTrace safely backed off, closed the TLS connection, initiated a cooldown, and marked the days as pending retry.

B. The Batch Invalidation Re-Upload Loop (Line 3608)

• Log message:
  up_sched: day 20260819 invalidated — will re-upload
up_index: forgot day 20260819 — will re-upload
• Cause: In the older firmware version Irfan was running, exporting any day's EDF triggered uploader_on_day_invalidated() across the entire index. This is the exact issue resolved in PR fix(session_writer): queue a deferred export when EDF generation fails after a stop #187.

C. Skipping Incomplete/Zero-Epoch Test Sessions (Line 38)

• Log message:
  netprov: recreate_edfs: skipping 20260705_153040 (invalid start_epoch_ms=0)
• Cause: Irfan had leftover directories from test runs where the device rebooted or disconnected before timestamps were established. The regenerator safely skipped them.

D. Missing Metadata Fallback on Fragmented Sessions (Line 351)

• Log message:
  edf_gen: session 20260807_165512 has no ident.json (recovered session?) — using .../20260807_164150_ident.json from the same day
• Cause: An abrupt session stop prevented ident.json and settings.json from being saved. edf_gen successfully borrowed the metadata from an earlier session on the same day.

E. Web Dashboard Disconnects (Line 1962)

• Log message:
  httpd_txrx: httpd_sock_err: error in recv : 104
httpd_ws: httpd_ws_recv_frame: WS frame is not properly masked.
• Cause: Routine browser socket closes (TCP ECONNRESET / error 104) when Irfan refreshed or closed the web dashboard page.

F. SD Card Upload Lease Contention (Line 1970)

• Log message:
  sd_storage: upload lease busy (export in progress)
• Cause: The background uploader probed for SD card access while recreate_edfs was actively writing files. The lease prevented file contention and deferred the upload.

---

3. Implications Summary

1. "outside the day" Warnings:
   • Data Integrity: Fully protected. The guard prevents writing values outside 0..1440, ensuring OSCAR does not flag the SD card as corrupted.
   • Omission Impact: Only the boundary session interval itself (typically a short test, mask fit, or drying cycle at noon) is excluded from STR.edf's mask timeline. All clinical metrics (AHI, median/95th percentile pressure, leak rates) for that night remain intact.
2. SleepHQ Finalization Failures:
   • Days 20260807 and 20260808 remain in the pending queue to retry automatically once the cloud-side ingestion succeeds.

[ilyakruchinin]

In short, everything is fine.
One of the issues will be fixed in the next version, but it's not a reason for concern.

[ilyakruchinin]

Days 20260807 and 20260808 are the ones to monitor (not certain why SHQ rejected them).

[ilyakruchinin]

This is not an issue by itself, but we should demote the Warning status to Informational

[ilyakruchinin]

This was fixed in v2.0.1. Closing.