catching the 'why' of engine.py exiting

[Vince Skahan]

Is it possible to log 'why' weewx aborts via the finally: block in engine.py ?

I'm trying to help somebody who is experiencing unusual aborts but figuring out why is pretty difficult if weewxd just stops for some reason (my guess is presumably a skin/extension blowing up).

Can a python try/finally block log why it failed to the catchall finally: block ?   I'm looking specifically around line 219 in engine.py

[Tom Keffer]

Unless I'm misunderstanding you, that's basically what the "except Exception" does at line 199 in weewxd.py.

--
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 weewx-user+...@googlegroups.com.
To view this discussion visit https://groups.google.com/d/msgid/weewx-user/a5a51863-37cf-42fd-89de-2bd57daba495n%40googlegroups.com.

[Vince Skahan]

I'm looking at the run( ) routine but not seeing except Exception, and don't understand what BreakLoop nor the commentary there means.

In this case it's a docker container with a bunch of services configured and running weewx 5.4.0 in a venv using python 3.14.6 according to the debug=1 logs.

vt-1  | 2026-08-01 08:35:18,219 weewxd[10] INFO weewx.manager: Added record 2026-08-01 08:35:00 EDT (1785587700) to database 'weewx.sdb'
vt-1  | 2026-08-01 08:35:18,267 weewxd[10] INFO weewx.manager: Added record 2026-08-01 08:35:00 EDT (1785587700) to daily summary in 'weewx.sdb'
vt-1  | 2026-08-01 08:35:19,204 weewxd[10] INFO weewx.restx: Windy: Published record 2026-08-01 08:35:00 EDT (1785587700)
vt-1  | 2026-08-01 08:35:20,694 weewxd[10] INFO user.new_belchertown: version 2.1beta2
vt-1  | 2026-08-01 08:35:54,730 weewxd[10] ERROR weewx.restx: StationRegistry: Failed to publish record 2026-08-01 08:35:00 EDT (1785587700): HTTP Error 429: TOO MANY REQUESTS
vt-1  | 2026-08-01 08:40:17,595 weewxd[10] INFO weewx.manager: Added record 2026-08-01 08:40:00 EDT (1785588000) to database 'weewx.sdb'
vt-1  | 2026-08-01 08:40:17,616 weewxd[10] INFO weewx.manager: Added record 2026-08-01 08:40:00 EDT (1785588000) to daily summary in 'weewx.sdb'
vt-1  | 2026-08-01 08:40:22,644 weewxd[10] INFO weewx.engine: Main loop exiting. Shutting engine down.
vt-1  | 2026-08-01 08:40:22,644 weewxd[10] INFO weewx.engine: Shutting down StdReport thread
vt-1  | 2026-08-01 08:40:42,644 weewxd[10] ERROR weewx.engine: Unable to shut down StdReport thread
vt-1  | 2026-08-01 08:40:43,174 weewxd[10] CRITICAL weewxd: Database OperationalError exception: database is locked
vt-1  | 2026-08-01 08:40:43,175 weewxd[10] CRITICAL weewxd:     ****  Waiting 2 minutes then retrying...
Gracefully Stopping... press Ctrl+C again to force
Container docker-vt-1 Stopping
Container docker-vt-1 Stopped

The database locked line also got our attention since no StdReport skin actually seemed to have run to completion. My initial thought is that the beta forked belchertown's service code has issues (or the container is missing something it expects) or even that it might be the python gc thing John Kline did the deepdive on recently, but I can't see any logging instrumentation in the engine to figure out what is causing the main loop to exit.

(I did ask the user (TomM) to rebuild his docker image with --no-cache and use python 3.11 or 3.12 to get a clean rebuild with the python version removed as a possibility, as well as to consider the usual slow walk before you run debugging steps ala  'disable every skin and extension, enable only Seasons, verify the core is stable, then turn things one one-by-one nice and slowly')

My guess is it's a bug in the beta belchertown service code that comes with the skin, but some logs when the engine punts would help.

Regardless, looking at engine.py I'm not seeing where it would log anything in shutdown( ) or  run( ) finally: or even any try/except logging around the gc collection if it fails, which is why I asked about if we could log something helpful when the engine punts.  Looks like a lot of places where it just can exit silently unless I'm misreading there.

Not a world-ending thing in this case but it would be helpful to try to figure out why the engine is shutting down.  We do see a few of these 'weewx exited no idea why it did so' reports occasionally...

[John Kline]

> that it might be the python gc thing John Kline did the deepdive on recently

It isn’t that.  That was a SEGV very shortly after a garbage collection and abosolutely nothing was written to the log after the garbage collection log entry.

On Aug 2, 2026, at 6:20 PM, Vince Skahan <vince...@gmail.com> wrote:



To view this discussion visit https://groups.google.com/d/msgid/weewx-user/601fbfee-f261-41cf-8997-0985112939ebn%40googlegroups.com.

[Tom Keffer]

Look in weewxd.py, not engine.py.

The function run() in engine.py is not involved in error recovery. Instead, any uncaught exceptions filter up into main(), where there is a big try/except block with different strategies for different exceptions. If all else fails the exception is logged and the program exits (line 199 of weewxd.py).

To view this discussion visit https://groups.google.com/d/msgid/weewx-user/601fbfee-f261-41cf-8997-0985112939ebn%40googlegroups.com.

[Vince Skahan]

Thanks, that helps but I was looking more toward figuring out where the issue was that caused the engine to abort before the retry magic tried to restart things.

 In the log snippet why did it silently exit the main loop 5 seconds after adding records to the db ?  Or it just a minor timing thing in how the logs got written out ?

vt-1  | 2026-08-01 08:40:17,595 weewxd[10] INFO weewx.manager: Added record 2026-08-01 08:40:00 EDT (1785588000) to database 'weewx.sdb'
vt-1  | 2026-08-01 08:40:17,616 weewxd[10] INFO weewx.manager: Added record 2026-08-01 08:40:00 EDT (1785588000) to daily summary in 'weewx.sdb'
vt-1  | 2026-08-01 08:40:22,644 weewxd[10] INFO weewx.engine: Main loop exiting. Shutting engine down.
vt-1  | 2026-08-01 08:40:22,644 weewxd[10] INFO weewx.engine: Shutting down StdReport thread
vt-1  | 2026-08-01 08:40:42,644 weewxd[10] ERROR weewx.engine: Unable to shut down StdReport thread
vt-1  | 2026-08-01 08:40:43,174 weewxd[10] CRITICAL weewxd: Database OperationalError exception: database is locked
vt-1  | 2026-08-01 08:40:43,175 weewxd[10] CRITICAL weewxd:     ****  Waiting 2 minutes then retrying...

[Tom Keffer]

You're trying to figure out why the database was locked? Beats me! That's a far more difficult problem.

It's been years since I've seen one of these errors. In the past, it was caused by a too-short retry wait, but sqlite fixed that a long time ago. 

--

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 weewx-user+...@googlegroups.com.

To view this discussion visit https://groups.google.com/d/msgid/weewx-user/25409997-6a59-4d15-adc8-6da4e7954d4cn%40googlegroups.com.

[John Kline]

It could happen if the report generation doesn’t finish before the next archive cycle.  What extensions are installed?  Do you see all the reports completing in a timely manner.

On Aug 3, 2026, at 2:12 PM, Tom Keffer <tke...@gmail.com> wrote:



To view this discussion visit https://groups.google.com/d/msgid/weewx-user/CAPq0zEBy92cG-8Le19HBnvc%3DpywTLZczNLW3YTE%2Bk0708pa7KQ%40mail.gmail.com.

[Vince Skahan]

I’m going to have to defer to TomM who is the user at this point to provide any added info.

Setup is sqlite3 venv in docker based on a python base image with skyfield, the dev branch of the belchertown fork, mqtt publishing, and the vantage driver plus some of the usual uploaders. I think he said no other skins.

John was correct it was not the python version FWIW.

[Rich Bell]

I’ve definitely seen this. The reports run in a separate thread, which can lock out the main thread (so technically any extension with threads could cause this)

rich

To view this discussion visit https://groups.google.com/d/msgid/weewx-user/8183CDE9-EBB2-487F-AB16-D524374104AF%40johnkline.com.

[Greg Troxel]

Is there really full locking, vs using transactions? SERIALIZABLE, or
just READ COMMITTED?

[Pablo Sanchez]

SQL lite only allows a single writer at the file level. The OP stated (in the original thread) that he had multiple weewx instances running.

---

pablo

On August 3, 2026 18:10:52 Greg Troxel <g...@lexort.com> wrote:

Is there really full locking, vs using transactions?  SERIALIZABLE, or

just READ COMMITTED?

-- 

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 weewx-user+...@googlegroups.com.

To view this discussion visit https://groups.google.com/d/msgid/weewx-user/rmi8q6mhn2x.fsf%40s1.lexort.com.

[John Kline]

> The OP stated (in the original thread) that he had multiple weewx instances running.

If the OP has multiple weewx instances running and writing to the same SQLite db, there is nothing to investigate.  Is that really the case?

On Aug 3, 2026, at 4:11 PM, Pablo Sanchez <pa...@hillsandlakes.com> wrote:



To view this discussion visit https://groups.google.com/d/msgid/weewx-user/19fc9e4a240.2848.44b74f35a7a433c111dbfaee4cca1c2d%40hillsandlakes.com.

[Vince Skahan]

No it doesn’t say that in anything I’ve read or have been told via email.

https://github.com/uajqq/weewx-belchertown-new/issues/298 has the github issue and more info. Short description is version X works and version Y does not, so it sounds like a version issue to me,

I suppose it is remotely possible there is a hung docker container holding the file open but that’s unlikely. The o.p. is an experienced docker user.

[John Kline]

Well it does say in the link you just provided:

DB lock exception after long report run

Read locks can be shared, but weewx won’t be able to acquire a write lock at archive time if there is still a read lock.

On Aug 3, 2026, at 4:58 PM, Vince Skahan <vince...@gmail.com> wrote:

No it doesn’t say that in anything I’ve read or have been told via email.

To view this discussion visit https://groups.google.com/d/msgid/weewx-user/650a2beb-76c1-4058-b0d1-5c1123b780c2n%40googlegroups.com.

[Pablo Sanchez]

My bad. I forgot that OP said two threads, not two weewx instances.

Sorry about that!

---

pablo

To view this discussion visit https://groups.google.com/d/msgid/weewx-user/650a2beb-76c1-4058-b0d1-5c1123b780c2n%40googlegroups.com.

[John Kline]

When I read more on that issue, he is saying exactly the issue:

I should add that I am able to replicate this using the mitct02/weewx Docker image. v5.4.0-5 is Belchertown-new beta3 and 5.4.0-6 is Belchertown-new 2.0. If I merely swap in the 5.4.0-6 image, the report cycle completes in well under the archive interval and this issue does not surface, though I do suspect it would in the event of a huge database.

So, we know why the db was locked.  The issue to be investigated is why the long report cycles.  Since he swap in different betchlertown versions and produce the long report cycles (keeping all other extensions the same), we kind of know what enervation to look at, no?

John

On Aug 3, 2026, at 5:34 PM, Pablo Sanchez <pa...@hillsandlakes.com> wrote:



To view this discussion visit https://groups.google.com/d/msgid/weewx-user/19fca31d010.2848.44b74f35a7a433c111dbfaee4cca1c2d%40hillsandlakes.com.

[Rich Bell]

Sounds like the new version is hitting the database “hard”. Should be easy enough for the extension writer to know what SQL queries were introduced and possibly create a “debug version” to see what is going on.

Disclaimer: I have not followed the link, only following this discussion.

rich

To view this discussion visit https://groups.google.com/d/msgid/weewx-user/650a2beb-76c1-4058-b0d1-5c1123b780c2n%40googlegroups.com.

[Vince Skahan]

I suggested trying to bisect the commits by trying versions between what worked and what doesn’t to try to pin down which commit was the one that triggered the issue, but that’s a lot of work.

John did you run the simulator or vs a davis station ?  I can try to test on a rebuilt pi4 tomorrow or even build my own docker image pretty easily vs a very big db but only vs the sim. Don’t want to break my prod pi :-)

[John Kline]

I did not run anything.  I probably didn’t clearly identify a quote I included.

Off topic, but since I’ve been looking at the log:

LOG SNIPPET:

vt-1 | 2026-07-31 10:23:08,908 weewxd[8] ERROR weewx.cheetahgenerator: **** Ignoring template /home/weewx/weewx-data/skins/new-belchertown/json/weewx_data.json.tmpl

vt-1 | 2026-07-31 10:23:08,910 weewxd[8] ERROR weewx.cheetahgenerator: **** Reason: [Errno 2] No such file or directory: '/home/weewx/weewx-data/almanac_daylight_data.inc'

END OF LOG SNIPPET

It is looking for almanac_daylight_data.inc in the wrong place.  And I don’t think that file is part of Betchlertown 2.0.

On Aug 3, 2026, at 7:04 PM, Vince Skahan <vince...@gmail.com> wrote:

I suggested trying to bisect the commits by trying versions between what worked and what doesn’t to try to pin down which commit was the one that triggered the issue, but that’s a lot of work.

To view this discussion visit https://groups.google.com/d/msgid/weewx-user/9c49e70a-d2b2-4d1d-9e12-f8e1cd0b34f8n%40googlegroups.com.

[t...@tom.org]

OP here, lol. As I said in the issue discussion, this deployment is a reference implementation for poor performance. I think the important issue is that in this instance, when the report cycle exceeded the archive interval, weewx didn't tell me that since another report was running, it would abort this cycle. It just tried to run a new cycle while the other one was still running. I get that it's not optimal for instances to take that long to run a report cycle, but it happens and weewx is designed and built to handle it. For some reason, it just plows ahead with another run which starts the crud happening.

The beta4 fixes get my instance under the threshold so it runs, but it's a ticking time bomb I think.

[John Kline]

My what twists and turns this is taking for people, including me, who are jumping into the discussion without reading everthing.

Do I have it right that you are not interested in why the reporting cycle is taking too long and spilling into the next archive cycle?

What are you interested in?  The fact that weewx couldn’t get a write lock on the next archive cycle?

On Aug 3, 2026, at 7:17 PM, t...@tom.org <t...@tom.org> wrote:

OP here, lol. As I said in the issue discussion, this deployment is a reference implementation for poor performance. I think the important issue is that in this instance, when the report cycle exceeded the archive interval, weewx didn't tell me that since another report was running, it would abort this cycle. It just tried to run a new cycle while the other one was still running. I get that it's not optimal for instances to take that long to run a report cycle, but it happens and weewx is designed and built to handle it. For some reason, it just plows ahead with another run which starts the crud happening.

To view this discussion visit https://groups.google.com/d/msgid/weewx-user/084f02e7-129e-4903-a500-2b9b61afd018n%40googlegroups.com.

[John Kline]

Surely, the fatal error is weewx not being able to get a write lock to write the archive record. It says just that.

Let’s find out what is stuck in the report cycle.

I’m not a Docker guy, so I’ve had to Google the following. Please chime in with docker corrections as needed:

Install py-spy on the machine running Docker (not inside the container) and run:

docker top <container> — to get the host PID for weewxd

sudo py-spy dump --pid <host-pid>

Run the py-spy every 30 seconds or so starting when the report cycle begins. Repeated samples landing in the same frame will show where it’s stuck.

John

[John Smith]

weewx is designed and built to handle it

For those of us not using SQLite, weeWX can handle it just fine, but that's the inherit limitation of using SQLite.

To view this discussion visit https://groups.google.com/d/msgid/weewx-user/084f02e7-129e-4903-a500-2b9b61afd018n%40googlegroups.com.

[Greg Troxel]

"'John Kline' via weewx-user" <weewx...@googlegroups.com> writes:

> Do I have it right that you are not interested in why the reporting
> cycle is taking too long and spilling into the next archive cycle?

I think the OP is pointing out that if a reporting cycle takes too
long -- which could happen for lots of reasons, including database
access bloat in new versions, loads other than weewx, etc. -- then weewx
can end up starting a new reporting cycle when the other one has not
finished, and this seems like a bug.

It seems obvious (dangerous logic I know) that only one report should
run at a time, and that if things are backed up doing every nth one is
better than crashing. I would expect a mutex/etc. to guard against two
reports at the same time.

And agreed that for a healthy system one needs to address the overlength
reports. But that's separable from reasonable behavior when they are
too long.

[John Kline]

I don’t see another report cycle starting in the logs.  Perhaps we are looking at different logs?

• 10:00:18 — archive record written; report thread launches (Belchertown 2.1beta3 logs at 10:00:21)

• 10:00:21 → 10:04:11 — that thread is doing network I/O: forecast download finishes 10:02:34, Xweather AQI fallback 10:04:11. No “Generated N files” line ever appears, so it never finished

• 10:05:18 — next archive record written fine

• 10:05:23.827 — Main loop exiting. Shutting engine down.  The engine is dying (not rotating a report cycle). 

• 10:05:43.827 — Unable to shut down StdReport thread, exactly 20.000 s later (join() timeout expiring).

• 10:05:44 — database is locked

On Aug 4, 2026, at 4:47 AM, Greg Troxel <g...@lexort.com> wrote:

--
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 weewx-user+...@googlegroups.com.

To view this discussion visit https://groups.google.com/d/msgid/weewx-user/rmimrv2f6pr.fsf%40s1.lexort.com.

[matthew wall]

i might be hallucinating, but i remember at one point the code that starts reports would check to see if a report was still running. if the report was still running, it would skip that report and go to the next, with a log entry that the report was skipped.

a quick scan of reportengine.py does not show any of that behavior, so i must be remembering logic from a previous implementation or something that never made it to master.

a per-report mutex/lock could be done in reportengine.py. but it might be better to do it within each report, since the report has more detail (and could thus provide better logs) about what is happening.

i suppose that starting a thread for each report could lead to much complexity if reports try to write to the database, not just read from it

there have *always* been issues with shutting down the reporting thread. if something in the report thread has a unresponsive file handle open (e.g., slow nfs link) or a network socket open, then the thread does not shut down immediately when the engine does a shutdown.

m

[John Kline]

The code is still there. max_wait defaults to 60s, so it will start another report cycle after 10m (assuming max_wait is overrridden somewher).

def launch_report_thread(self, _event):
"""Called after the packet LOOP. Processes any new data."""
import weewx.reportengine
# Do not launch the reporting thread if an old one is still alive.
# To guard against a zombie thread (alive, but doing nothing) launch
# anyway if enough time has passed.
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)

try:
self.thread = weewx.reportengine.StdReportEngine(self.config_dict,
self.engine.stn_info,
self.record,
first_run=not self.launch_time)
self.thread.start()
self.launch_time = time.time()
except threading.ThreadError:
log.error("Unable to launch report thread.")
self.thread = None

> On Aug 4, 2026, at 5:24 AM, matthew wall <mwall...@gmail.com> wrote:
>
> i might be hallucinating, but i remember at one point the code that starts reports would check to see if a report was still running. if the report was still running, it would skip that report and go to the next, with a log entry that the report was skipped.

> --
> 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 weewx-user+...@googlegroups.com.

> To view this discussion visit https://groups.google.com/d/msgid/weewx-user/C69E9E4C-0B2F-44E8-B437-75990351E842%40gmail.com.

[t...@tom.org]

Yes this is the behavior I have seen (Matthew is not hallucinating!) for a long time and it is not happening here. Also, John showed in the logs that the extension name and version are only printed to the console on the first run. Subsequent runs are silent until the message about how many files were generated, so while it looks like there is no evidence of a rogue report run, it's happening silently (and you can see it on CPU too).

[John Kline]

Small correction first: I didn’t show that. The version-logged-once-per-process point is your reading of the log, not something I demonstrated — and I don’t think the log can settle it either way. That engine started at 09:56 and died at 10:05:23, so it only ever got one report launch. A single version 2.1beta3 line is equally consistent with “logs once per process” and with “only one cycle ran.” You may well be right about the skin’s logging behavior, but that log isn’t evidence for it.

On the substance, you’re right that a successful launch is silent. launch_report_thread() logs nothing on the happy path, so a report cycle can start with no trace in the weewx log.

But a blocked launch is not silent:

    log.info("Launch of report thread aborted: existing report thread still running")

Which leaves two possibilities: POST_LOOP never fired, because the OperationalError killed the main loop first — or the 10:00 cycle had already finished and a fresh one launched silently. The second requires the 10:00 cycle to have completed without ever logging Generated N files, which I’d want evidence for.

On CPU: a busy CPU doesn’t distinguish a second run from the first one still grinding. The orphaned thread from 10:00 explains it by itself — nothing joined it, and self.thread gets reassigned on the next launch, so it just keeps running untracked.

py-spy dump on the running process lists every thread with its stack. One StdReportEngine or two stops being a matter of interpretation at that point.

On Aug 4, 2026, at 5:51 AM, t...@tom.org <t...@tom.org> wrote:

Yes this is the behavior I have seen (Matthew is not hallucinating!) for a long time and it is not happening here. Also, John showed in the logs that the extension name and version are only printed to the console on the first run. Subsequent runs are silent until the message about how many files were generated, so while it looks like there is no evidence of a rogue report run, it's happening silently (and you can see it on CPU too).

To view this discussion visit https://groups.google.com/d/msgid/weewx-user/d8fc89c7-0550-43b0-aaed-9a7dfb8f2711n%40googlegroups.com.

[John Kline]

One more thing, remembering that the OP is NOT focused on the database lock; but rather, another report cycle starting, adding

[StdReport]

max_wait = 999999999

will give the OP what he is asking for.

On Aug 4, 2026, at 6:03 AM, John Kline <jo...@johnkline.com> wrote:



[t...@tom.org]

Yes, John, except changing max_wait had no effect in my case.

[John Kline]

What did you see that told you it had no effect — a second report thread launching, or the database is locked crashes continuing?

If it’s the crashes, that’s expected. max_wait only suppresses the second launch; the first report keeps holding the database either way, which is what takes weewx down.

If it’s an actual second thread launching, I’d want to see it — with max_wait at 31.7 years. Worth confirming the setting landed in [StdReport] and that weewx was restarted after the change.

On Aug 4, 2026, at 6:11 AM, t...@tom.org <t...@tom.org> wrote:

Yes, John, except changing max_wait had no effect in my case.

To view this discussion visit https://groups.google.com/d/msgid/weewx-user/72d6e8b1-5f4f-4adc-ae77-2a1ceada1276n%40googlegroups.com.

[John Kline]

If anyone wants to see where a report cycle is actually spending its time, py-spy will tell you without modifying anything. Install it into a throwaway venv and dump the running weewxd:

python3 -m venv ~/pyspy-venv

~/pyspy-venv/bin/pip install py-spy

pgrep -af weewxd

sudo ~/pyspy-venv/bin/py-spy dump –pid <pid>

It attaches to the live process, prints a stack for every thread, and detaches. No restart, no config change, no debug logging.

I run weewx from a pip install, not in a container. My understanding is that under Docker you’d run py-spy on the host and point it at the host-side PID of the weewxd process rather than the one you see inside the container, and that there may be a ptrace permission to sort out. I haven’t done it, so someone who uses containers should confirm.

Here’s one from my system (WeeWX 5.4.0, LiveSeasons (personal skin), Pi 5), taken during a report cycle. I’ve cut the idle service threads:

Thread 1767872 (idle): “MainThread”

read (serial/serialposix.py:565)

…

[seven idle service threads elided]

Thread 379811 (active): “ReportThread”

execute (weedb/sqlite.py:249)

guarded_fn (weedb/sqlite.py:38)

getSql (weewx/manager.py:586)

firstGoodStamp (weewx/manager.py:326)

create_sync (weewx/manager.py:303)

sync (weewx/manager.py:307)

init (weewx/manager.py:142)

open (weewx/manager.py:187)

open_manager (weewx/manager.py:921)

getLatestForecastRows (user/nws.py:1702)

alerts (user/nws.py:1620)

respond (cheetah…alerts_inc….py:297)

handleCheetahInclude (Cheetah/Template.py:1712)

respond (cheetah_…alerts_html_tmpl….py:167)

generate (weewx/cheetahgenerator.py:335)

generate (weewx/cheetahgenerator.py:226)

generate (weewx/cheetahgenerator.py:226)

run (weewx/cheetahgenerator.py:166)

start (weewx/reportengine.py:482)

run (weewx/reportengine.py:252)

_bootstrap_inner (threading.py:1043)

_bootstrap (threading.py:1014)

The report thread is named ReportThread, so it’s easy to find in the output.

Two things this makes visible. First, exactly what the cycle is doing at that instant — which generator, which template, which query, right down to the line.

Second — and more to the point of this thread — it settles the concurrency question directly. Every thread in the process is listed, so if two report cycles are running at once, you get two entries with two distinct thread IDs. One dump answers it. No inferring from CPU load, no relying on what does or doesn’t get logged.

For what it’s worth, I don’t think a second report thread is being launched in the log posted here. weewx will launch one alongside a running cycle, but only once the existing thread has been alive for max_wait seconds (600 by default). In that log the report thread was about 300 seconds old when the process took the database-locked exception and shut down, and the restart resets the launch time — so the 600 s threshold never gets close. That’s also why changing max_wait had no effect: neither branch of that test is being reached.

On Aug 4, 2026, at 6:26 AM, John Kline <jo...@johnkline.com> wrote:



[John Kline]

I *may* have found the regression. It’s new in beta3 and it’s a full table scan of the archive table on every report cycle.

beta3 adds a local-AQI path to bin/user/new_belchertown.py. The core helper:

def _archive_latest_numeric(archive_manager, column_name):

    row = archive_manager.getSql(

    f"SELECT dateTime, {column_name} FROM archive "

    f"WHERE {column_name} IS NOT NULL "

    "ORDER BY dateTime DESC LIMIT 1"

    )

_archive_local_aqi_payload() calls it for pm2_5_aqi, and if that comes back empty, falls through to _archive_pm25_nowcast_payload(), which calls it again for pm2_5. Neither function exists in 2.0 — all of this is new.

dateTime is the archive table’s INTEGER PRIMARY KEY, so SQLite walks backwards from the newest row. If the column has recent data it stops on the first row and costs nothing. If the column exists in the schema but is empty, SQLite has to read every row in the table to prove there’s no non-NULL value anywhere. That’s a full scan, disk-bound, holding a SQLite read lock for its entire duration — which is what blocks the archive writer and produces “database is locked”.

It’s gated on aqi_enabled, which defaults to 0. Your log shows “Xweather AQI fallback cached to forecast.json”, so you have it on.

I measured this on my own system — WeeWX 5.4.0, Pi 5, 785,666 archive records (~7.5 years), NVMe. Same query shape, comparing a populated column against an empty one:

populated column (pm2_5):     0.001 s

empty column (hail), warm:    0.219 s

empty column (hail), cold:    1.120 s

The cold number is after dropping caches. User CPU time is identical between the warm and cold runs, so the extra second is purely waiting on disk.

Scaling to 13 years is roughly 1.75x my row count, so ~2 s per query cold, ~4 s for the pair. On slower storage — an ordinary SD card, where random page reads are an order of magnitude worse than NVMe — that could easily be 15-30 s per query.

Two queries would confirm it on your database:

.timer on

SELECT dateTime, pm2_5_aqi FROM archive WHERE pm2_5_aqi IS NOT NULL ORDER BY dateTime DESC LIMIT 1;

SELECT dateTime, pm2_5 FROM archive WHERE pm2_5 IS NOT NULL ORDER BY dateTime DESC LIMIT 1;

A parse error means the column isn’t in your schema and that one is harmless. A fast result means the column has recent data. A slow result is the bug.

BTW, storing pm2_5_aqi in the database is a guaranteed way to get the wrong answer for AQI.  AQI is defined as a formula to be applied to the average pm2.5 for any given time period.  It is NOT defined as the average of AQI calculations over said time period.  I had a recent discussion with a user of one of my air quality sensor extensions.  By adding AQI to the db, which he did, he was disabling the XType which comes with the weewx-purple, weewx-airlink and weewx-airgradient extensions that would properly calculate the AQI.  And it saved virtually no time in getting the wrong answer.  All of the time is the database access and it's doing the same accesses either way--one is getting AQI, the other pm2.5.

On Aug 4, 2026, at 8:10 AM, John Kline <jo...@johnkline.com> wrote:



[John Kline]

Two more findings, both of which make the scan cost considerably worse than I described.

It runs once per generated file, not once per report cycle.

In weewx/cheetahgenerator.py, _getSearchList() is called at line 309, inside the per-file loop that begins at line 270. That means the search list extension — and therefore both table scans — runs once for every file the skin generates.

beta3’s skin.conf ships 14 template sections: 12 under ToDate, plus NOAA_month and NOAA_year. In steady state that’s 14 files per cycle, so 28 full table scans. No stale_age is set on any section, so nothing is skipped on that basis.

Past NOAA files are skipped cheaply — line 291 continues before the search list is built, so an existing month or year file costs only an os.path.exists() call. Only the current month and current year regenerate each cycle. But that skip depends on the files being there. If your NOAA directory doesn’t persist across container restarts, every restart regenerates 13 years of monthly and yearly files — about 169 extra files, each paying two scans, before it reaches the regular pages. Worth checking whether that folder survives a restart in your setup.

The scans happen before the forecast download, not after.

_archive_local_aqi_payload() is called at the top of the AQI block, ahead of all the forecast-fetch code. In your log, the gap from “version 2.1beta3” at 10:00:21 to “New forecast file downloaded” at 10:02:34 is 133 seconds, and the scans are inside that window.

Also worth noting: every urlopen call in beta3 passes DEFAULT_HTTP_TIMEOUT, which is 15 seconds. So no single HTTP request can account for 133 seconds — that would take nine consecutive timeouts. The time is more likely going to the database work.

One question that would help narrow the storage side: where does weewx.sdb actually live — local disk on the Docker host, or a mounted volume? SQLite’s documentation recommends against keeping database files on network filesystems, since POSIX advisory locking is buggy or unimplemented on many of them. Probably not what’s happening here, but it’s cheap to rule out.

On Aug 4, 2026, at 11:41 AM, John Kline <jo...@johnkline.com> wrote:



[t...@tom.org]

John, I am really glad you're looking at this! I don't have the Python chops to solve this.

This application's deployment is the worst! It (a Docker container) runs along with 3 other weewx containers and another unrelated container on a little box in the cloud (1 vCPU, 1G), so you can see very little resources available. To add to the madness, I have the sdb and public_html directories mapped to, you guessed it, block storage. I do this because I frequently nuke & pave the server so it is a simple backup solution. I map public_html to the block storage because since creating NOAA reports is expensive, I like having a cache. All of the HTML is rsync'd to a web server so no performance requirement.

I am trying to keep my costs as low as possible, and since weewx is effectively a batch system (with enough real-time via MQTT), eventually consistent is good enough for me for my hobby weather data right now.

I doubt that the block storage is anything but a performance drag in my case. When I ran the exact same image with the same database I use in 'production,' I experienced the exact same issues with the database on local storage.

All that said, I think we are burying the lede here. Matthew mentioned the abort logic if a report thread is already running, and I have used that (and max_wait) historically for situations just like this in the past. In all of this, I have not seen that message as I would expect to. If the code is still there, why is it not being invoked if that's exactly what is going on? And when weewx says it's exiting in the logs, it doesn't (or can't). To me, that is why we're seeing this lock stuff going on but I can't prove it.

I hope this helps. FWIW, the fixes in beta4 (just out yesterday) got my performance (even as described above) down below the archive interval. But again, I think there's a bigger issue than my performance issue or environment.

I hope this helps and again, I am happy to see you looking at this!

[John Kline]

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.

[Tom Keffer]

Thanks, John, for your thorough analysis.

Adding a "please commit suicide" signal to the shutdown mechanism is easy enough. The report thread would monitor it, probably within the Cheetah generator loop and the image generator loop. 

As for retrying "database is locked" errors, the database manager code is the most twisted part of WeeWX. I tread lightly when I get in there, but it clearly needs a rewrite. Unfortunately, it touches almost everything so it is likely to be a profound rewrite. Let me think about this. 

-tk

--
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 weewx-user+...@googlegroups.com.

To view this discussion visit https://groups.google.com/d/msgid/weewx-user/EFF848BB-B01B-4B73-B7C1-A3E7C06A718A%40johnkline.com.

[John Kline]

Thanks, Tom.

On the shutdown signal — a flag checked in the generator loops sounds right.

On the database manager, measure twice and cut once. This situation is rare, and the shutdown signal may be all that’s needed — without an orphaned report thread surviving into the next engine, it doesn’t compound.

On Aug 4, 2026, at 3:32 PM, Tom Keffer <tke...@gmail.com> wrote:



To view this discussion visit https://groups.google.com/d/msgid/weewx-user/CAPq0zEC9LT%3DnW6JOQ1-D5iEt20u23up3Z%2B0-nKa4s3y3dbRLgg%40mail.gmail.com.

[Vince Skahan]

John -  I see no aqi_source in the weectl debug the o.p. sent me.  He must be running whatever the default is unless he edited skin.conf to set it there.

There is no mention of aqi_source nor its options anywhere in the wiki or instructions that I can find.  It 'is' buried and set to 'auto' in skin.conf with no commentary at all.

[John Kline]

Vince,

That’s worth noting — if he has no aqi_source set, he’s on the “auto” default, which is one of the values that still triggers the archive scan in beta4. So whatever got his cycle time down, it wasn’t that gate, and I don’t know what did.  We also don’t know if the OP has pm2_5_aqi as a column in the database; nor do we know if his archive records have values for pm2_5.  As such, we haven’t reached any conclusions on what is causing the slowdown.

My advice to the skin author still stands. The effort to find a non-null pm2_5_aqi or pm2_5 should be bounded by the last day or two; and not go back 13 years (in this case).

John

On Aug 4, 2026, at 4:27 PM, Vince Skahan <vince...@gmail.com> wrote:

John -  I see no aqi_source in the weectl debug the o.p. sent me.  He must be running whatever the default is unless he edited skin.conf to set it there.

--

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 weewx-user+...@googlegroups.com.

To view this discussion visit https://groups.google.com/d/msgid/weewx-user/b0f4e2d7-ceef-4ea6-a48d-aa1030f08707n%40googlegroups.com.

[t...@tom.org]

OP here. No skin.conf and no aqi_source configured:

aqi_enabled = 1
aqi_location_enabled = 1

There is a pm2_5 column in my database but all values are null

[John Kline]

pm2_5 all null is the pathological case.

Would you run this against your database and post the time?

sqlite3 weewx.sdb

.timer on

SELECT dateTime, pm2_5 FROM archive WHERE pm2_5 IS NOT NULL ORDER BY dateTime DESC LIMIT 1;

On Aug 4, 2026, at 5:01 PM, t...@tom.org <t...@tom.org> wrote:

OP here. No skin.conf and no aqi_source configured:

To view this discussion visit https://groups.google.com/d/msgid/weewx-user/d91d8619-53dd-49b0-b3f0-76292f8737c8n%40googlegroups.com.

[Greg Troxel]

Not the OP, but for a random datapoint on a slow machine that is capable
of weewx, I ran the query against a DB that starts roughly 2017-12-26,
on a 1G RPI3 with filesystem on uSD, and got no rows and:

Run Time: real 17.919584 user 1.634768 sys 1.655089


The same query for outTemp

sqlite> SELECT dateTime, outTemp FROM archive WHERE outTemp IS NOT NULL ORDER BY dateTime DESC LIMIT 1;
╭────────────┬─────────╮
│ dateTime │ outTemp │
╞════════════╪═════════╡
│ 1785889200 │ 72.4 │
╰────────────┴─────────╯
Run Time: real 0.000624 user 0.000455 sys 0.000182

[John Kline]

Hi Greg,

Let’s assume that is the cold scan. Would you run twice in a row and give me the second time for a warm scan?

> On Aug 4, 2026, at 5:24 PM, Greg Troxel <g...@lexort.com> wrote:
>
> Not the OP, but for a random datapoint on a slow machine that is capable

> --
> 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 weewx-user+...@googlegroups.com.

> To view this discussion visit https://groups.google.com/d/msgid/weewx-user/rmiv79pbejf.fsf%40s1.lexort.com.

[Tom Keffer]

I have added retry logic to the database manager in the case where the database is locked. It retries 5 times with exponential backoff. There's also a cheap regression test, but it all seems to work. It wasn't as bad as I thought.

Commit eb99b3f

On to the shutdown signal.

To view this discussion visit https://groups.google.com/d/msgid/weewx-user/55F7E600-C97B-4AF1-8ECD-3A75FEC5E9EC%40johnkline.com.

[Greg Troxel]

I rebooted the machine and then ran the query 3 times.

$ sqlite3 weewx.sdb
SQLite version 3.53.2 2026-06-03 19:12:13
Enter ".help" for usage hints.
sqlite> .timer on
sqlite> SELECT dateTime, pm2_5 FROM archive WHERE pm2_5 IS NOT NULL ORDER BY dateTime DESC LIMIT 1;
Run Time: real 20.939687 user 1.811444 sys 1.555754
sqlite> SELECT dateTime, pm2_5 FROM archive WHERE pm2_5 IS NOT NULL ORDER BY dateTime DESC LIMIT 1;
Run Time: real 2.640085 user 1.682205 sys 0.956678
sqlite> SELECT dateTime, pm2_5 FROM archive WHERE pm2_5 IS NOT NULL ORDER BY dateTime DESC LIMIT 1;
Run Time: real 2.675249 user 1.669083 sys 1.004916
sqlite>

$ ls -lh weewx.sdb
-rw-r--r-- 1 gdt users 242M Aug 4 20:30 weewx.sdb

[John Kline]

The warm figure is the interesting one: 2.64 s wall, with user+sys accounting for essentially all of it. Once the 242 MB is cached, the cost is pure CPU — SQLite examining every row in the table. Storage speed stops mattering; that 2.6 s is the floor on that hardware no matter what the database sits on.

That matters for the fix. Bounding the lookback isn’t an I/O optimization — it caps the worst case. Unbounded, an empty column means a full pass over the table: 700K rows on your database, which is where your 2.6 s goes; 1.4M on the OP’s 13 years, and growing every five minutes. Bounded to a couple of days, the query examines at most a few hundred rows no matter how big the database gets — and for a station with current PM data it still stops at the first row, same as your outTemp result.

For scale: the search list extension runs once per generated file, not once per report cycle, and beta3 ships 14 template sections. At your warm number that’s around 37 s of scanning per cycle, and more when weewxd is competing for the same page cache in 1 GB.

Your outTemp comparison is the cleanest demonstration in this thread, incidentally. Same query shape, same table, 30,000× difference — and the only variable is whether the first row examined has a value in it.

[John Kline]

I found what actually made beta4 faster — it isn’t the aqi_source gate.

beta4 caches the search list across generated files. get_extension_list() now builds everything once on the first file of a report run, saves the result, and hands every subsequent file a copy, refreshing only the per-template pieces (the timespan binder and the NOAA file index). The comment in init says it plainly: one search-list extension instance per report run.

In beta3 the full build ran for every one of the 14 generated files — 28 archive scans per cycle. In beta4 it runs once — 2 scans per cycle. That’s the speedup, and it’s the right change on its own merits: rebuilding forecasts and config for every file was waste regardless.

But the scan itself is unchanged: still unbounded, still a full pass over the table when the pm2_5 column is empty. On slow hardware that’s one ~20-second query per cycle holding a read lock against the archive writer — a smaller window than beta3’s, but the same mechanism. It should still be bounded: a WHERE dateTime >= ? window of a day or two returns the same answer for any station with current PM data and costs almost nothing no matter how large the database is.

I think this lays this thread to rest. If the OP gets back to me with the sql timing (OP, please run it twice), we can’t look at those numbers; but I don’t think there are any other open items. (And I want to get back to weewx-skyfield.)

> On Aug 4, 2026, at 6:00 PM, John Kline <jo...@johnkline.com> wrote:
>
> The warm figure is the interesting one: 2.64 s wall, with user+sys accounting for essentially all of it. Once the 242 MB is cached, the cost is pure CPU — SQLite examining every row in the table. Storage speed stops mattering; that 2.6 s is the floor on that hardware no matter what the database sits on.

[Tom Mitchell]

sqlite> SELECT dateTime, pm2_5 FROM archive WHERE pm2_5 IS NOT NULL ORDER BY dateTime DESC LIMIT 1;

Run Time: real 193.630 user 3.783819 sys 8.312705

sqlite> SELECT dateTime, pm2_5 FROM archive WHERE pm2_5 IS NOT NULL ORDER BY dateTime DESC LIMIT 1;

Run Time: real 147.827 user 3.478416 sys 8.748866
sqlite> SELECT COUNT(*) FROM archive;
1391014
Run Time: real 9.171 user 0.119921 sys 0.614045
sqlite> SELECT MIN(dateTime) from archive;
1367620800
Run Time: real 0.003 user 0.000164 sys 0.000395

--
Tom Mitchell
t...@tom.org

"The whole problem with the world
  is that fools and fanatics are
  always so certain of themselves,
  and wiser people so full of doubts."
  - Bertrand Russell

--
You received this message because you are subscribed to a topic in the Google Groups "weewx-user" group.
To unsubscribe from this topic, visit https://groups.google.com/d/topic/weewx-user/9AIS1DRHl00/unsubscribe.
To unsubscribe from this group and all its topics, send an email to weewx-user+...@googlegroups.com.
To view this discussion visit https://groups.google.com/d/msgid/weewx-user/B54515BC-B58E-4A04-961F-EB8E915183CC%40johnkline.com.

[John Kline]

Tom, thank you — those numbers settle it, and they’re worse than my extrapolation.

The second run is the telling one. On the RPi3 datapoint earlier in the thread, the repeat query dropped from 21 s to 2.6 s once the table was in page cache. Yours barely moved: 193 s cold, 147 s on the repeat, with user+sys only about 12 s of that. So roughly 135 seconds of every scan is I/O wait, even on a repeat — with 1 GB shared across five containers, your 1.4M-row table doesn’t stay cached at all. The 9-second COUNT(*) says the same thing independently.

Your MIN(dateTime) at 0.003 s is the perfect control: same table, satisfied straight from the primary key, instant. The pm2_5 scan is slow for exactly one reason — the column is empty, so SQLite must examine all 1.4M rows to prove there’s no value anywhere.

The arithmetic on beta3, on your hardware: the search list ran once per generated file, 14 files per cycle. Your schema has no pm2_5_aqi column, so that query fails instantly and only the pm2_5 scan runs — one scan per file, 14 per cycle, at ~150 s each. That’s on the order of 35 minutes per report cycle against a 300-second archive interval — seven times over budget. Not “seldom completes”; structurally can’t.  And every scan held a read lock the archive writer eventually collided with.

beta4 runs that scan once per cycle instead of 14 times — ~150 s, which fits inside your 300 s interval with room for the rest of the cycle. That matches what you reported.

Either way, the fix I’ve been advocating stands, and your numbers are the best case for it: bound the lookback to a day or two and that 150-second scan becomes milliseconds, on any hardware, at any database size.

On Aug 4, 2026, at 6:38 PM, Tom Mitchell <t...@tom.org> wrote:



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 weewx-user+...@googlegroups.com.
To view this discussion visit https://groups.google.com/d/msgid/weewx-user/CAKVzASCkqR8J1Hc9cDQcmreuQRvFPN2f45MLxEGNd7-0vktK2w%40mail.gmail.com.

[Tom Mitchell]

Well the hits keep coming. When I started the container back up after running the queries against the db, for some reason the report cycle that had been taking 120-150 seconds took almost 10 minutes, and beta4/weewx did as I originally expected. The only changes I made are those in the beta4 update. I am curious why it does what I expect.

vt-1  | 2026-08-04 21:43:35,179 weewxd[8] INFO weewx.engine: Loading station type Vantage (weewx.drivers.vantage)
vt-1  | 2026-08-04 21:43:41,211 weewxd[8] INFO user.wxskyfield: Service version: 1.14
vt-1  | 2026-08-04 21:43:41,211 weewxd[8] INFO user.wxskyfield: WxSkyfield status: enabled...continuing.
vt-1  | 2026-08-04 21:43:41,213 weewxd[8] INFO user.wxskyfield: stars    : True
vt-1  | 2026-08-04 21:43:41,213 weewxd[8] INFO user.wxskyfield: user_root: /home/weewx/weewx-data/bin/user
vt-1  | 2026-08-04 21:43:41,214 weewxd[8] INFO user.wxskyfield: Skyfield version: 1.54.
vt-1  | 2026-08-04 21:43:41,299 weewxd[8] INFO user.wxskyfield: Loaded 420 named stars from the Hipparcos catalog.
vt-1  | 2026-08-04 21:43:41,301 weewxd[8] INFO user.wxskyfield: Skyfield almanac registered; reports will use Skyfield for almanac computations.
vt-1  | 2026-08-04 21:43:41,303 weewxd[8] INFO weewx.engine: StdConvert target unit is 0x1
vt-1  | 2026-08-04 21:43:41,303 weewxd[8] INFO weewx.wxservices: StdWXCalculate will use data binding wx_binding
vt-1  | 2026-08-04 21:43:41,310 weewxd[8] INFO weewx.engine: Archive will use data binding wx_binding
vt-1  | 2026-08-04 21:43:41,310 weewxd[8] INFO weewx.engine: Record generation will be attempted in 'hardware'
vt-1  | 2026-08-04 21:43:41,311 weewxd[8] INFO weewx.engine: Using archive interval of 300 seconds (specified by hardware)
vt-1  | 2026-08-04 21:43:41,313 weewxd[8] INFO weewx.restx: StationRegistry: Station will be registered.
vt-1  | 2026-08-04 21:43:41,315 weewxd[8] INFO weewx.restx: Wunderground-RF: Data for station KVTLUNEN4 will be posted
vt-1  | 2026-08-04 21:43:41,319 weewxd[8] INFO weewx.restx: PWSWeather: Data for station KVTLUNEN4 will be posted
vt-1  | 2026-08-04 21:43:41,328 weewxd[8] INFO weewx.restx: CWOP: Data for station EW2749 will be posted
vt-1  | 2026-08-04 21:43:41,334 weewxd[8] INFO weewx.restx: WOW: Data for station 5419f9b8-2beb-e711-bd60-0003ff5962e0 will be posted to https://wow.metoffice.gov.uk/automaticreading
vt-1  | 2026-08-04 21:43:41,336 weewxd[8] INFO weewx.restx: AWEKAS: No config info. Skipped.
vt-1  | 2026-08-04 21:43:41,336 weewxd[8] INFO user.mqtt: service version is 0.24
vt-1  | 2026-08-04 21:43:41,336 weewxd[8] INFO user.mqtt: binding to ['archive', 'loop']
vt-1  | 2026-08-04 21:43:41,336 weewxd[8] INFO user.mqtt: data_binding is wx_binding
vt-1  | 2026-08-04 21:43:41,342 weewxd[8] INFO user.mqtt: topic is weather/vt
vt-1  | 2026-08-04 21:43:41,342 weewxd[8] INFO user.mqtt: desired unit system is US
vt-1  | 2026-08-04 21:43:41,343 weewxd[8] INFO user.mqtt: data will be uploaded to mqtt://tom:x...@msg.tom.org:1883
vt-1  | 2026-08-04 21:43:41,344 weewxd[8] INFO user.windy: version is 0.8
vt-1  | 2026-08-04 21:43:41,356 weewxd[8] INFO user.windy: Data will be uploaded to https://stations.windy.com/api/v2/observation/update
vt-1  | 2026-08-04 21:43:41,357 weewxd[8] INFO weewx.engine: 'pyephem' not detected, extended almanac data is not available
vt-1  | 2026-08-04 21:43:41,360 weewxd[8] INFO weewxd: Starting up weewx version 5.4.0
vt-1  | 2026-08-04 21:43:43,363 weewxd[8] INFO weewx.engine: Clock error is -0.36 seconds (positive is fast)
vt-1  | 2026-08-04 21:43:43,363 weewxd[8] INFO weewx.engine: Using binding 'wx_binding' to database 'weewx.sdb'
vt-1  | 2026-08-04 21:43:43,364 weewxd[8] INFO weewx.manager: Starting backfill of daily summaries
vt-1  | 2026-08-04 21:43:43,364 weewxd[8] INFO weewx.manager: Daily summaries up to date
vt-1  | 2026-08-04 21:43:45,867 weewxd[8] INFO weewx.engine: Starting main packet loop.
vt-1  | 2026-08-04 21:43:49,968 weewxd[8] INFO user.mqtt: client established for mqtt://tom:x...@msg.tom.org:1883
vt-1  | 2026-08-04 21:45:19,339 weewxd[8] INFO weewx.manager: Added record 2026-08-04 21:45:00 EDT (1785894300) to database 'weewx.sdb'
vt-1  | 2026-08-04 21:45:19,391 weewxd[8] INFO weewx.manager: Added record 2026-08-04 21:45:00 EDT (1785894300) to daily summary in 'weewx.sdb'
vt-1  | 2026-08-04 21:45:20,063 weewxd[8] INFO weewx.restx: Windy: Published record 2026-08-04 21:45:00 EDT (1785894300)
vt-1  | 2026-08-04 21:45:21,746 weewxd[8] INFO user.new_belchertown: version 2.1beta4
vt-1  | 2026-08-04 21:45:44,763 weewxd[8] ERROR weewx.restx: StationRegistry: Failed to publish record 2026-08-04 21:45:00 EDT (1785894300): HTTP Error 429: TOO MANY REQUESTS
vt-1  | 2026-08-04 21:50:19,565 weewxd[8] INFO weewx.manager: Added record 2026-08-04 21:50:00 EDT (1785894600) to database 'weewx.sdb'
vt-1  | 2026-08-04 21:50:19,704 weewxd[8] INFO weewx.manager: Added record 2026-08-04 21:50:00 EDT (1785894600) to daily summary in 'weewx.sdb'
vt-1  | 2026-08-04 21:50:20,134 weewxd[8] INFO weewx.engine: Launch of report thread aborted: existing report thread still running
vt-1  | 2026-08-04 21:50:20,815 weewxd[8] INFO weewx.restx: Windy: Published record 2026-08-04 21:50:00 EDT (1785894600)
vt-1  | 2026-08-04 21:54:00,639 weewxd[8] INFO weewx.cheetahgenerator: Generated 16 files for report new-belchertown in 519.73 seconds
vt-1  | 2026-08-04 21:54:06,452 weewxd[8] INFO weeutil.rsyncupload: rsync'd 61 files (5,013,997 bytes) in 1.33 seconds
vt-1  | 2026-08-04 21:55:19,799 weewxd[8] INFO weewx.manager: Added record 2026-08-04 21:55:00 EDT (1785894900) to database 'weewx.sdb'
vt-1  | 2026-08-04 21:55:19,871 weewxd[8] INFO weewx.manager: Added record 2026-08-04 21:55:00 EDT (1785894900) to daily summary in 'weewx.sdb'
vt-1  | 2026-08-04 21:55:20,682 weewxd[8] INFO weewx.restx: Windy: Published record 2026-08-04 21:55:00 EDT (1785894900)
vt-1  | 2026-08-04 21:56:04,272 weewxd[8] INFO user.new_belchertown: New forecast Current Conditions file downloaded to /home/weewx/weewx-data/public_html/belchertown/json/current_conditions.json
vt-1  | 2026-08-04 21:57:03,975 weewxd[8] INFO weewx.cheetahgenerator: Generated 16 files for report new-belchertown in 103.70 seconds
vt-1  | 2026-08-04 21:57:09,611 weewxd[8] INFO weeutil.rsyncupload: rsync'd 26 files (4,826,059 bytes) in 1.25 seconds

--
Tom Mitchell
t...@tom.org

"The whole problem with the world
  is that fools and fanatics are
  always so certain of themselves,
  and wiser people so full of doubts."
  - Bertrand Russell

[John Kline]

The 519 s cycle was a cold start: you’d just scanned the database from sqlite3 and restarted the container, so nothing was cached and the first cycle paid your measured ~190 s cold scan plus first-run forecast work. The next cycle — 103 s — is your real steady state, right in line with your ~150 s warm scan doing most of the work.

And note 21:50:20: “Launch of report thread aborted: existing report thread still running.” That’s the message this thread began by saying never appears. It was always there — it just needs the process to survive to the next archive boundary, and beta4’s shorter lock windows finally let it.

Your cycles are still spending most of their time on that one empty-column scan. Bound the lookback and they drop from ~100 s to ~10.

John

[Greg Troxel]

"'John Kline' via weewx-user" <weewx...@googlegroups.com> writes:

> The warm figure is the interesting one: 2.64 s wall, with user+sys
> accounting for essentially all of it. Once the 242 MB is cached, the
> cost is pure CPU — SQLite examining every row in the table. Storage
> speed stops mattering; that 2.6 s is the floor on that hardware no
> matter what the database sits on.

Yes, except that 242 MB is a very high fraction of system memory, and
reading that into cache is surely displacing other caching uses,
resulting in other things having to be read later, when maybe they
wouldn't. But that's very tricky to assess. I therefore think that the
true cost should be viewed somewhere in between the cold and warm cases.

The RPI3 I tested on runs weewx, only (VP2/5minutes). Classic skin x2
(Fred Flintstone units and metric), and mqtt publisher. Plus a few
small system daemons. I reran the query this morning:

sqlite> SELECT dateTime, pm2_5 FROM archive WHERE pm2_5 IS NOT NULL ORDER BY dateTime DESC LIMIT 1;

Run Time: real 17.837007 user 1.703541 sys 1.534109

which shows that most of weewx.sdb is no longer cached.

[Agreed that a query that has to sequential scan is not ok, when a
bounded query will result in the same semantics in the end.]

> Your outTemp comparison is the cleanest demonstration in this thread,
> incidentally. Same query shape, same table, 30,000× difference — and
> the only variable is whether the first row examined has a value in it.

It just seemed like an obvious thing to run....

[Tom Keffer]

Question: StdReport comes with a set of generators: cheetah, image, ftp, copy, rsync. Does anyone know of any extensions that create and use custom report generators? 

I'd like to change the signature of these various generators to include a flag to stop the thread, but I'm reluctant to do so if it would break skins that use custom generators.

-tk

--

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 weewx-user+...@googlegroups.com.
To view this discussion visit https://groups.google.com/d/msgid/weewx-user/rmiecgcbyfd.fsf%40s1.lexort.com.

[Vince Skahan]

How would we check ? 

If you're looking for anything with a generator_list that has custom things I found a few in their skin.conf files....

StackedWindRose skin/extension (from Gary) has the following:

[Generators]
    generator_list = user.stackedwindrose.StackedWindRoseImageGenerator

Similarly new belchertown skin

[Generators]
    generator_list = weewx.cheetahgenerator.CheetahGenerator, weewx.reportengine.CopyGenerator, user.new_belchertown.HighchartsJsonGenerator, user.new_belchertown.PostRenderMinifyGenerator

Original belchertown skin from Pat

[Generators]
    generator_list = weewx.cheetahgenerator.CheetahGenerator, weewx.reportengine.CopyGenerator, user.belchertown.HighchartsJsonGenerator

From 'compare' that comes with weewx-forecast:

[Generators]
        generator_list = user.forecast.ForecastPlotGenerator

[Tom Keffer]

Thanks, vince!

I don't have a copy of the StackedWindRose extension, but all of the others use __init__ from their base class (ReportGenerator), so we should be OK.

The advantage of changing the signature of ReportGenerator is that I can stop the thread between processing files or images, instead of only between generators. 

--
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 weewx-user+...@googlegroups.com.

To view this discussion visit https://groups.google.com/d/msgid/weewx-user/432b6d34-7aee-4e68-a13b-d000f355c741n%40googlegroups.com.

[Vince Skahan]

https://github.com/weewx-contrib/stackedwindrose-extension

[Tom Keffer]

Dang. That one does its own initializer, so the signature in __init__ would have to be changed.

To view this discussion visit https://groups.google.com/d/msgid/weewx-user/9e1a986b-2dcb-4aee-9afe-e6f16830f005n%40googlegroups.com.

[Vince Skahan]

Gimme a diff or PR and I can update it there,

[Tom Keffer]

I've added a flag to notify the StdReport thread when it's time to exit. It's inside the Cheetah and Image generator loops, so it does change the signature of ReportGenerator.

Development branch. Commit b830d03 

To view this discussion visit https://groups.google.com/d/msgid/weewx-user/b8a1201d-aa28-4cbb-b341-ba3cd9c8d971n%40googlegroups.com.