03/09/26 16:41
I spent most of today tracking down a bug with sending notifications to Matrix in BirdNET-Pi.
BirdNET-Pi is a project where you deploy a computer (like a raspberry pi) with a microphone, and it identifies bird songs, and shows statistics about which species it hears.
It can use Apprise to send notifications when birds are detected. Apprise is a tool that can send notifications to ~155 different services, so you don't need to implement notifications for every service from scratch.
For a long time, I'd been sending notifications to Telegram without issue, and I switched to sending them to a Matrix room on my homeserver when I moved away from Telegram to Matrix. At some point around this time, the notifications stopped working. I can't remember if I updated BirdNET before the switch, or the bug is specific to Matrix, but either way, I wasn't recieving them.
The behaviour was pretty inconsistent. Sending test notifications worked fine. If I restarted the Pi, or just restarted the services, it would send one notification succesfully - and then no more. Except, the occasional extremely-delayed notification in the small hours of the morning, for a notification hours earlier in the day.
I spent a long time trying to track down the issue. I found this open issue suggesting it could be a difference between the system time and the time PHP is using. Not unreasonable, it's BST here in the UK right now, so there was a difference. However, updating timezones did not fix it.
I started digging into the code. First, I needed to understand how notification sending is actually triggered. In ~/BirdNET-Pi/scripts/, there's species_notifier.sh and send_test_notification.py. However, these are only for testing, and running them did send succesful notifications. It was just the notifying on actual detection that was failing.
Next, I tried checking logs. Unfortunately, there aren't any. systemctl list-units | grep -i notif didn't find any notification service - most things in BirdNET-Pi run as their own service, but not notifications. I checked the logs of the birdnet_analysis service with journalctl -u birdnet_analysis.service | tail -f - this turned out to just be the same logs available in the web UI, which doesn't say anything about notifications.
So, I looked into /usr/local/bin/birdnet_analysis.py itself. I found a function, handle_reporting_queue, which ran apprise(file, detections). I spent quite some time poking at this line of code, adding logging around it to see what was going on.
I didn't learn much from this - it ran succesfully once and returned [apprise][INFO] Loaded 1 entries from file://BirdNET-Pi/apprise.txt?encoding=utf-8&cache=yes, and then never returned anything in subsequent runs. The other code around it, such as sending data to BirdWeather, also ran fine. I figured maybe since it's calling these different services asynchronously, it could be crashing without blocking anything, leaving bird detection working normally while failing to send notifications.
I dug out strace, and checked what the analysis service was doing with sudo strace -f -tt -T -p $(pgrep -f birdnet_analysis.py) -e trace=network,read,write,close. I'm not great at interpreting strace output, but even I could tell it was succesfully connecting to my homeserver, doing TLS, etc. So it seemed likely it was trying to send something, at least.
I decided to try another angle - check the logs on my Matrix homeserver, and see if anything was actually being sent to it. First I tried checking the continuwuity logs with docker compose logs homeserver --follow. However, they were not verbose enough to see individual messages. I needed more verbose logs, so in the server's admin room, I ran !admin debug change-log-level verbose. Unfortunately, this didn't do anything - they were already set to verbose. I blanked on what's more verbose than verbose, so I asked for help in the #Continuwuity Support room. Stratself helpfully advised of the existence of debug and trace levels. I tried debug, which generated a lot of logs - multiple lines per second. I tried grep'ing them, but wasn't having much luck finding anything. Stratself made the even more helpful suggestion of checking the logs on my reverse proxy instead. Thanks Stratself!
I can't believe I didn't think of that - I mean, I set up a whole monitoring stack and everything only a few days ago. Anyway, it took a while, but I managed to find the requests BirdNET-Pi was sending by searching for requests to /_matrix/client/v3/rooms/{room ID}/send/m.room.message/* on the host matrix.ryankrage77.me.
This proved to be the smoking gun - there were multiple log entries over several minutes with the same transaction ID, like this:
2026-09-03 15:39:27.397 /_matrix/client/v3/rooms/{room ID}/send/m.room.message/249f8169-3c1d-490a-929d-80583700f126
2026-09-03 15:40:12.599 /_matrix/client/v3/rooms/{room ID}/send/m.room.message/249f8169-3c1d-490a-929d-80583700f126
2026-09-03 15:42:57.399 /_matrix/client/v3/rooms/{room ID}/send/m.room.message/249f8169-3c1d-490a-929d-80583700f126
In Matrix, the transaction ID should be unique per message, otherwise it's considered a retransmission, and the server silently de-duplicates it. Ergo, the message is never seen to arrive.
So why was it was re-using the ID? At first I thought this behaviour might be coming from Apprise, as BirdNET-Pi ships with an old version - 1.9.5. I updated to 1.13.1 by running $HOME/BirdNET-Pi/birdnet/bin/pip install --upgrade apprise, and re-started the birdnet_analysis service - but the issue persisted. So, it's not a bug in Apprise. Or if it is, I didn't find the bug at any rate
Instead, I checked how BirdNET-Pi was using it. I tracked down what that apprise(file, detections) line from earlier was actually doing. The relevant code is in scripts/utils/notifications.py, and the offending function is this:
def notify(body, title, attached=""):
global apobj
if apobj is None:
asset = apprise.AppriseAsset(
plugin_paths=[
userDir + "/.apprise/plugins",
userDir + "/.config/apprise/plugins",
]
)
apobj = apprise.Apprise(asset=asset)
config = apprise.AppriseConfig()
config.add(APPRISE_CONFIG)
apobj.add(config)
if attached != "":
apobj.notify(
body=body,
title=title,
attach=attached,
)
else:
apobj.notify(
body=body,
title=title,
)
This persists apobj for the entire lifetime of the birdnet_analysis service - it creates it once, and then re-uses it. As a side effect, this means the transaction ID does not get updated when it is used again. Persisting it is probably more efficient, and there probably is a way to disable the caching. However, at this point I'd been at it for a while, so I just re-wrote notify() to re-create apobj every time:
def notify(body, title, attached=""):
asset = apprise.AppriseAsset(
plugin_paths=[
userDir + "/.apprise/plugins",
userDir + "/.config/apprise/plugins",
]
)
apobj = apprise.Apprise(asset=asset)
config = apprise.AppriseConfig()
config.add(APPRISE_CONFIG)
apobj.add(config)
if attached != "":
apobj.notify(
body=body,
title=title,
attach=attached,
)
else:
apobj.notify(
body=body,
title=title,
)
And then re-started the birdnet_analysis service once again. Of course, at this point, the birds could sense my misery, and went quiet. There were no detections for a painful fifteen minutes or so, as I anxiously waited to see if the fix had worked. Then just to spite me, a Robin piped up and called a dozen times in a row, triggering a flurry of notifications in the Matrix room. I checked the logs, and saw unique transaction IDs for each one.
Hurray! The problem is solved - not elegantly, but good enough. I opened a PR just in case anyone running into notification issues finds it useful. Not sure it will ever be accepted, as Nachtzuster seems to have other priorities at the moment and things have not been updated in a while, but maybe it will show up if someone searches the same or a related issue.