Two things need untangling here, because they’re being conflated.
The abort logic was never removed. weewx 5.4.0, weewx/engine.py,
StdReport.launch_report_thread(), around line 867:
if self.thread and self.thread.is_alive():
thread_age = time.time() - self.launch_time
if thread_age < self.max_wait:
log.info("Launch of report thread aborted: existing report thread still
running")
return
else:
log.warning("Previous report thread has been running"
" %s seconds. Launching report thread anyway.", thread_age)
max_wait defaults to 600 (line 847). The behavior you and Matthew remember is
intact.
Why you never see the message. Callbacks for an event run in registration order
— bind() appends to a list, dispatchEvent() walks it (lines 224-241). Services
register in the order they’re loaded, and the archive service registers for
POST_LOOP ahead of the report service. Your own log shows the consequence: the
archive record was written at 10:05:18, which happens inside the archive
service’s POST_LOOP handler — so POST_LOOP was mid-dispatch when the
OperationalError hit at 10:05:23. An exception in one callback aborts the whole
dispatch. launch_report_thread(), later in the chain, was never called. The
guard didn’t fail to log; it never ran.
That’s also the answer to “why did changing max_wait have no effect”: neither
branch of that test is being reached.
A second report cycle did not start. Two independent reasons. The guard logs on
both paths — the abort message under 600 seconds, the “Launching report thread
anyway” warning over it — and neither appears anywhere in your log, which
plainly isn’t filtering INFO. And the arithmetic forbids it anyway: the report
thread launched at 10:00:21 and the engine died at 10:05:23. It was 302 seconds
old. It cannot have reached the 600-second threshold, and the restart resets
the launch clock, so nothing carries over.
If you want this settled by observation instead of argument, py-spy dump lists
every thread in the process with its stack. Two report engines would be two
entries. One dump ends the debate.
Where weewx could be better. It just isn’t the abort logic. Four things, and
they compound:
1. There is no way to interrupt a running generator. shutDown() calls
join(20.0), and that is the entire shutdown mechanism — no flag, no exception
injected, nothing signalled. The report thread isn’t ignoring a request to
stop; no request exists. “Unable to shut down StdReport thread” is a wait that
expired, worded like an attempt that was refused.
2. The surviving thread becomes untracked. When the engine restarts, the new
StdReport starts with self.thread = None. The orphan is no longer joined,
checked, or counted — it is invisible to the very guard we’ve been discussing.
The protection you’re asking about stops applying to the one thread that most
needs it.
3. weewxd restarts the engine in the same process immediately after being told
the shutdown failed. The orphan survives into the new engine’s lifetime, still
holding database reads. Exiting the process and letting the supervisor restart
it would kill the orphan for free.
4. The result is self-sustaining. The orphan holds reads; the new engine’s
archive write collides with them; the engine dies with the same error; repeat.
Your 10:07 restart is iteration two: up at 10:07:44, record at 10:07:55, dead
at 10:08:00 — and no “Shutting down StdReport thread” line this time, because
the new engine had no report thread of its own. On 1 vCPU, the orphan is also
competing with the main loop for your only core.
Arguably a fifth: treating “database is locked” as fatal. It’s a transient
condition; retrying the write would be proportionate. Tearing down the engine
is what converts a slow report into a crash loop.
On beta4. I diffed it against beta3. The scan is unchanged — same
_archive_latest_numeric, same unbounded query. What changed is the gating: a
new aqi_source option (auto / local / forecast), with the archive path running
only when
local_aqi_enabled = aqi_enabled and aqi_source in (“auto”, “local”)
aqi_source defaults to “auto” — which is in that tuple. On defaults, beta4
still runs the scans. So: which did you set? If you set aqi_source = forecast,
that explains your speedup, and the bug remains live for anyone on defaults
with a big database. If you’re on auto and it’s still fast, my diagnosis is
incomplete and something else in beta4 deserves credit.
For the skin author: bound the lookback instead of gating the caller. The query
walks backwards from the newest row — instant when the column has current data,
a full scan of the table when it doesn’t. A WHERE dateTime >= ? window of a day
or two gives the identical answer for any station with a working PM sensor and
costs nothing for one without. Config gating leaves the landmine armed for the
next person with thirteen years of data who never touches aqi_source.
--
You received this message because you are subscribed to the Google Groups
"weewx-user" group.
To unsubscribe from this group and stop receiving emails from it, send an email
to [email protected].
To view this discussion visit
https://groups.google.com/d/msgid/weewx-user/EFF848BB-B01B-4B73-B7C1-A3E7C06A718A%40johnkline.com.
