Failures on New Install

[jacobabehm]

I have an install that's been running for a few days. Every few hours, it hangs on an error. The following from log is a successful connection followed by a failure:

12:49:02 server.py[28213]: [ACTIVE CONNECTIONS] 1
12:49:02 server.py[28213]: READING AUDIO DATA... DONE! READ 5 CHUNKS.
12:49:02 server.py[28213]: FULL FILENAME: -/home/dnkn/BirdSongs/May-2022/10-Tuesday/2022-05-10-birdnet-12:48:47.wav-
12:49:02 server.py[28213]: Date-time: 2022-05-10 12:48:47
12:49:04 birdnet_analysis.sh[52834]: 0.0;3.0-('Cardinalis cardinalis_Northern Cardinal', 0.20219456)
12:49:04 birdnet_analysis.sh[52834]: 3.0;6.0-('Spizella pusilla_Field Sparrow', 0.051027566)
12:49:04 birdnet_analysis.sh[52834]: 6.0;9.0-('Vireo gilvus_Warbling Vireo', 0.10197324)
12:49:04 birdnet_analysis.sh[52834]: 9.0;12.0-('Branta canadensis_Canada Goose', 0.24285354)
12:49:04 birdnet_analysis.sh[52834]: 12.0;15.0-('Scolopax minor_American Woodcock', 0.042452153)
12:49:04 systemd[1]: birdnet_analysis.service: Succeeded.
12:49:06 systemd[1]: birdnet_analysis.service: Scheduled restart job, restart counter is at 135.
12:49:06 systemd[1]: Stopped BirdNET Analysis.
12:49:06 systemd[1]: Started BirdNET Analysis.
12:49:07 birdnet_analysis.sh[52860]: Files loaded
12:49:07 birdnet_analysis.sh[52860]: RECORDING_LENGTH set to 15
12:49:07 env[52894]: Line = 2022-05-10-birdnet-12:48:47.wav.csv
12:49:27 birdnet_analysis.sh[52860]: analyze.py --i /home/dnkn/BirdSongs/May-2022/10-Tuesday/2022-05-10-birdnet-12:49:02.wav --o /home/dnkn/BirdSongs/May-2022/10-Tuesday/2022-05-10-birdnet-12:49:02.wav.csv --lat 44.9863 --lon -92.7278 --week 18 --overlap 0.0 --sensitivity 1.25 --min_conf 0.7
12:49:27 server.py[28213]: ANALYZING AUDIO... DONE! Time 1.5 SECONDS
12:49:27 server.py[28213]: WRITING RESULTS TO /home/dnkn/BirdSongs/May-2022/10-Tuesday/2022-05-10-birdnet-12:48:47.wav.csv ... DONE! WROTE 0 RESULTS.
12:49:27 server.py[28213]: [NEW CONNECTION] ('127.0.0.1', 49272) connected.
12:49:27 server.py[28213]: [ACTIVE CONNECTIONS] 1
12:49:28 server.py[28213]: READING AUDIO DATA... /home/dnkn/BirdNET-Pi/birdnet/lib/python3.9/site-packages/librosa/util/decorators.py:88: UserWarning: PySoundFile failed. Trying audioread instead.
12:49:28 server.py[28213]:   return f(*args, **kwargs)
12:49:28 server.py[28213]: Exception in thread Thread-174:
12:49:28 server.py[28213]: Traceback (most recent call last):
12:49:28 server.py[28213]:   File "/home/dnkn/BirdNET-Pi/birdnet/lib/python3.9/site-packages/librosa/core/audio.py", line 155, in load
12:49:28 server.py[28213]:     context = sf.SoundFile(path)
12:49:28 server.py[28213]:   File "/home/dnkn/BirdNET-Pi/birdnet/lib/python3.9/site-packages/soundfile.py", line 629, in __init__
12:49:28 server.py[28213]:     self._file = self._open(file, mode_int, closefd)
12:49:28 server.py[28213]:   File "/home/dnkn/BirdNET-Pi/birdnet/lib/python3.9/site-packages/soundfile.py", line 1183, in _open
12:49:28 server.py[28213]:     _error_check(_snd.sf_error(file_ptr),
12:49:28 server.py[28213]:   File "/home/dnkn/BirdNET-Pi/birdnet/lib/python3.9/site-packages/soundfile.py", line 1357, in _error_check
12:49:28 server.py[28213]:     raise RuntimeError(prefix + _ffi.string(err_str).decode('utf-8', 'replace'))
12:49:28 server.py[28213]: RuntimeError: Error opening '/home/dnkn/BirdSongs/May-2022/10-Tuesday/2022-05-10-birdnet-12:49:02.wav': System error.
12:49:28 server.py[28213]: During handling of the above exception, another exception occurred:
12:49:28 server.py[28213]: Traceback (most recent call last):
12:49:28 server.py[28213]:   File "/usr/lib/python3.9/threading.py", line 954, in _bootstrap_inner
12:49:28 server.py[28213]:     self.run()
12:49:28 server.py[28213]:   File "/usr/lib/python3.9/threading.py", line 892, in run
12:49:28 server.py[28213]:     self._target(*self._args, **self._kwargs)
12:49:28 server.py[28213]:   File "/usr/local/bin/server.py", line 334, in handle_client
12:49:28 server.py[28213]:     audioData = readAudioData(args.i, args.overlap)
12:49:28 server.py[28213]:   File "/usr/local/bin/server.py", line 125, in readAudioData
12:49:28 server.py[28213]:     sig, rate = librosa.load(path, sr=sample_rate, mono=True, res_type='kaiser_fast')
12:49:28 server.py[28213]:   File "/home/dnkn/BirdNET-Pi/birdnet/lib/python3.9/site-packages/librosa/util/decorators.py", line 88, in inner_f
12:49:28 server.py[28213]:     return f(*args, **kwargs)
12:49:28 server.py[28213]:   File "/home/dnkn/BirdNET-Pi/birdnet/lib/python3.9/site-packages/librosa/core/audio.py", line 174, in load
12:49:28 server.py[28213]:     y, sr_native = __audioread_load(path, offset, duration, dtype)
12:49:28 server.py[28213]:   File "/home/dnkn/BirdNET-Pi/birdnet/lib/python3.9/site-packages/librosa/core/audio.py", line 198, in __audioread_load
12:49:28 server.py[28213]:     with audioread.audio_open(path) as input_file:
12:49:28 server.py[28213]:   File "/home/dnkn/BirdNET-Pi/birdnet/lib/python3.9/site-packages/audioread/__init__.py", line 111, in audio_open
12:49:28 server.py[28213]:     return BackendClass(path)
12:49:28 server.py[28213]:   File "/home/dnkn/BirdNET-Pi/birdnet/lib/python3.9/site-packages/audioread/rawread.py", line 62, in __init__
12:49:28 server.py[28213]:     self._fh = open(filename, 'rb')
12:49:28 server.py[28213]: FileNotFoundError: [Errno 2] No such file or directory: '/home/dnkn/BirdSongs/May-2022/10-Tuesday/2022-05-10-birdnet-12:49:02.wav'

Also, I was getting a different failure after the most recent upgrade:

12:05:34 server.py[17047]: [NEW CONNECTION] ('127.0.0.1', 48902) connected.
12:05:34 server.py[17047]: [ACTIVE CONNECTIONS] 1
12:05:34 server.py[17047]: READING AUDIO DATA... DONE! READ 5 CHUNKS.
12:05:34 server.py[17047]: FULL FILENAME: -/home/dnkn/BirdSongs/May-2022/10-Tuesday/2022-05-10-birdnet-12:05:19.wav-
12:05:34 server.py[17047]: Date-time: 2022-05-10 12:05:19
12:05:36 server.py[17047]: ANALYZING AUDIO... Exception in thread Thread-45:
12:05:36 server.py[17047]: Traceback (most recent call last):
12:05:36 server.py[17047]:   File "/usr/lib/python3.9/threading.py", line 954, in _bootstrap_inner
12:05:36 server.py[17047]:     self.run()
12:05:36 server.py[17047]:   File "/usr/lib/python3.9/threading.py", line 892, in run
12:05:36 server.py[17047]:     self._target(*self._args, **self._kwargs)
12:05:36 server.py[17047]:   File "/usr/local/bin/server.py", line 363, in handle_client
12:05:36 server.py[17047]:     writeResultsToFile(detections, min_conf, args.o)
12:05:36 server.py[17047]:   File "/usr/local/bin/server.py", line 256, in writeResultsToFile
12:05:36 server.py[17047]:     sendAppriseNotifications(str(entry[0]),str(entry[1]));
12:05:36 server.py[17047]:   File "/usr/local/bin/server.py", line 229, in sendAppriseNotifications
12:05:36 server.py[17047]:     if os.path.getsize(userDir + '/BirdNET-Pi/apprise.txt') > 0:
12:05:36 server.py[17047]:   File "/usr/lib/python3.9/genericpath.py", line 50, in getsize
12:05:36 server.py[17047]:     return os.stat(filename).st_size
12:05:36 server.py[17047]: FileNotFoundError: [Errno 2] No such file or directory: '/home/dnkn/BirdNET-Pi/apprise.txt'

I think this failure only occurred when there was a new results to write. If the job complete with "DONE! WROTE 0 RESULTS", no failure. There was no "apprise.txt" file, so I created one. The jobs now seem to complete fine with the above exception. Nothing is ever written to "apprise.txt".

Any idea what's going on?

[mcguirepr89]

Hi, @jacobabehm -- thanks for installing BirdNET-Pi! I'm sorry it seems you've installed a lemon, so to speak. I'm sure we'll get to the bottom of this and figure out a way to prevent it from happening.

The second failure was addressed recently so I'm hopeful that we won't see this again for too many others (it only went unfixed for 4-6 hours), and you're correct that it is only a failure about the presence of ~/BirdNET-Pi/apprise.txt when trying to send notifications for new detections. apprise.txt is a new Notifications configuration file that is populated when configured in "Tools" > "Settings". You've already fixed this bug manually by creating the file 👍, but an update as of the last few hours would likely have address this also (along with a restart of services).

The first failure, however, is more concerning, as I don't know how to explain it at all. It came from birdnet_server.service's log and there's not much more verbosity I'm able to add to that. We can try adding some debugging to the birdnet_analysis.service which sends the audio data to the analysis server.

I'm not sure what is easiest for you to edit the file, (vim, nano, "Tools" > "File Manager", etc.), but you can enable debugging by removing the #comment from 3 ~/BirdNET-Pi/scripts/birdnet_analysis.sh
from

#set -x

to this

set -x

You won't need to restart any services manually for that change to take effect (unless it is hung as it seems could be the case).

There might be some context for the logs at that point which could explain why server.py complained about a file going missing.

My best,
Patrick

[jacobabehm]

Thank you Patrick. I've edited the birdnet_analysis.sh script as described. I'll post the results when/if it hangs again.

Speaking of notifications, is there a notification method that doesn't use the pushed service? The app won't run on my device, and I see from the reviews that this isn't unusual.

[ehpersonal38]

Pushed was actually removed with the most recent update and replaced with Apprise! Now you can use many many notification services through Apprise, like email, telegram, discord, etc etc. 😃

[mcguirepr89]

Yes! Added just today! If you go to "Tools" > "Settings" you will see that Pushed.co support has been subsumed into Apprise notifications. You will find a link there which will take you to the repo for Apprise to get familiar with their myriad notification options for easy, one-line configuration on the settings page thanks to @ehpersonal38 ~~

https://github.com/caronc/apprise Check it out!

[kaeltis]

Theres also an indentation error here: a6a8c3b#commitcomment-73344158

[jacobabehm]

Just failed again:

16:51:02 server.py[115570]: [NEW CONNECTION] ('127.0.0.1', 51324) connected.
16:51:02 server.py[115570]: [ACTIVE CONNECTIONS] 1
16:51:02 server.py[115570]: READING AUDIO DATA... /home/dnkn/BirdNET-Pi/birdnet/lib/python3.9/site-packages/librosa/util/decorators.py:88: UserWarning: PySoundFile failed. Trying audioread instead.
16:51:02 server.py[115570]:   return f(*args, **kwargs)
16:51:02 birdnet_analysis.sh[198798]: + '[' -z '198249
16:51:02 birdnet_analysis.sh[198798]: 198928' ']'
16:51:02 birdnet_analysis.sh[198798]: + sleep 2
16:51:02 birdnet_analysis.sh[198798]: + '[' 8 -ge 15 ']'
16:51:02 birdnet_analysis.sh[198798]: + a=10
16:51:02 birdnet_analysis.sh[198934]: ++ lsof -t /home/dnkn/BirdSongs/May-2022/10-Tuesday/2022-05-10-birdnet-16:50:33.wav
16:51:02 birdnet_analysis.sh[198798]: + '[' -z '198249
16:51:02 birdnet_analysis.sh[198798]: 198928' ']'
16:51:02 birdnet_analysis.sh[198798]: + sleep 2
16:51:02 birdnet_analysis.sh[198798]: + '[' 10 -ge 15 ']'
16:51:02 birdnet_analysis.sh[198798]: + a=12
16:51:02 birdnet_analysis.sh[198938]: ++ lsof -t /home/dnkn/BirdSongs/May-2022/10-Tuesday/2022-05-10-birdnet-16:50:33.wav
16:51:02 birdnet_analysis.sh[198798]: + '[' -z '198249
16:51:02 birdnet_analysis.sh[198798]: 198928' ']'
16:51:02 birdnet_analysis.sh[198798]: + sleep 2
16:51:02 birdnet_analysis.sh[198798]: + '[' 12 -ge 15 ']'
16:51:02 birdnet_analysis.sh[198798]: + a=14
16:51:02 birdnet_analysis.sh[198947]: ++ lsof -t /home/dnkn/BirdSongs/May-2022/10-Tuesday/2022-05-10-birdnet-16:50:33.wav
16:51:02 birdnet_analysis.sh[198798]: + '[' -z '198249
16:51:02 birdnet_analysis.sh[198798]: 198928' ']'
16:51:02 birdnet_analysis.sh[198798]: + sleep 2
16:51:02 birdnet_analysis.sh[198798]: + '[' 14 -ge 15 ']'
16:51:02 birdnet_analysis.sh[198798]: + a=16
16:51:02 birdnet_analysis.sh[198956]: ++ lsof -t /home/dnkn/BirdSongs/May-2022/10-Tuesday/2022-05-10-birdnet-16:50:33.wav
16:51:02 birdnet_analysis.sh[198798]: + '[' -z '198249
16:51:02 birdnet_analysis.sh[198798]: 198928' ']'
16:51:02 birdnet_analysis.sh[198798]: + sleep 2
16:51:02 birdnet_analysis.sh[198798]: + '[' 16 -ge 15 ']'
16:51:02 birdnet_analysis.sh[198798]: + rm -f /home/dnkn/BirdSongs/May-2022/10-Tuesday/2022-05-10-birdnet-16:50:33.wav
16:51:02 birdnet_analysis.sh[198798]: + break
16:51:02 birdnet_analysis.sh[198798]: + grep 5050 /dev/fd/63
16:51:02 birdnet_analysis.sh[198976]: ++ netstat -tulpn
16:51:02 birdnet_analysis.sh[198798]: + '[' -f null ']'
16:51:02 birdnet_analysis.sh[198798]: + INCLUDEPARAM=
16:51:02 birdnet_analysis.sh[198798]: + '[' -f null ']'
16:51:02 birdnet_analysis.sh[198798]: + EXCLUDEPARAM=
16:51:02 birdnet_analysis.sh[198798]: + '[' '!' -z ']'
16:51:02 birdnet_analysis.sh[198798]: + BIRDWEATHER_ID_PARAM=
16:51:02 birdnet_analysis.sh[198798]: + BIRDWEATHER_ID_LOG=
16:51:02 birdnet_analysis.sh[198798]: + echo analyze.py --i /home/dnkn/BirdSongs/May-2022/10-Tuesday/2022-05-10-birdnet-16:50:33.wav --o /home/dnkn/BirdSongs/May-2022/10-Tuesday/2022-05-10-birdnet-16:50:33.wav.csv --lat 44.9863 --lon -92.7278 --week 18 --overlap 0.0 --sensitivity 1.25 --min_conf 0.7
16:51:02 birdnet_analysis.sh[198798]: analyze.py --i /home/dnkn/BirdSongs/May-2022/10-Tuesday/2022-05-10-birdnet-16:50:33.wav --o /home/dnkn/BirdSongs/May-2022/10-Tuesday/2022-05-10-birdnet-16:50:33.wav.csv --lat 44.9863 --lon -92.7278 --week 18 --overlap 0.0 --sensitivity 1.25 --min_conf 0.7
16:51:02 birdnet_analysis.sh[198798]: + analyze.py --i /home/dnkn/BirdSongs/May-2022/10-Tuesday/2022-05-10-birdnet-16:50:33.wav --o /home/dnkn/BirdSongs/May-2022/10-Tuesday/2022-05-10-birdnet-16:50:33.wav.csv --lat 44.9863 --lon -92.7278 --week 18 --overlap 0.0 --sensitivity 1.25 --min_conf 0.7
16:51:03 server.py[115570]: Exception in thread Thread-574:
16:51:03 server.py[115570]: Traceback (most recent call last):
16:51:03 server.py[115570]:   File "/home/dnkn/BirdNET-Pi/birdnet/lib/python3.9/site-packages/librosa/core/audio.py", line 155, in load
16:51:03 server.py[115570]:     context = sf.SoundFile(path)
16:51:03 server.py[115570]:   File "/home/dnkn/BirdNET-Pi/birdnet/lib/python3.9/site-packages/soundfile.py", line 629, in __init__
16:51:03 server.py[115570]:     self._file = self._open(file, mode_int, closefd)
16:51:03 server.py[115570]:   File "/home/dnkn/BirdNET-Pi/birdnet/lib/python3.9/site-packages/soundfile.py", line 1183, in _open
16:51:03 server.py[115570]:     _error_check(_snd.sf_error(file_ptr),
16:51:03 server.py[115570]:   File "/home/dnkn/BirdNET-Pi/birdnet/lib/python3.9/site-packages/soundfile.py", line 1357, in _error_check
16:51:03 server.py[115570]:     raise RuntimeError(prefix + _ffi.string(err_str).decode('utf-8', 'replace'))
16:51:03 server.py[115570]: RuntimeError: Error opening '/home/dnkn/BirdSongs/May-2022/10-Tuesday/2022-05-10-birdnet-16:50:33.wav': System error.
16:51:03 server.py[115570]: During handling of the above exception, another exception occurred:
16:51:03 server.py[115570]: Traceback (most recent call last):
16:51:03 server.py[115570]:   File "/usr/lib/python3.9/threading.py", line 954, in _bootstrap_inner
16:51:03 server.py[115570]:     self.run()
16:51:03 server.py[115570]:   File "/usr/lib/python3.9/threading.py", line 892, in run
16:51:03 server.py[115570]:     self._target(*self._args, **self._kwargs)
16:51:03 server.py[115570]:   File "/usr/local/bin/server.py", line 334, in handle_client
16:51:03 server.py[115570]:     audioData = readAudioData(args.i, args.overlap)
16:51:03 server.py[115570]:   File "/usr/local/bin/server.py", line 125, in readAudioData
16:51:03 server.py[115570]:     sig, rate = librosa.load(path, sr=sample_rate, mono=True, res_type='kaiser_fast')
16:51:03 server.py[115570]:   File "/home/dnkn/BirdNET-Pi/birdnet/lib/python3.9/site-packages/librosa/util/decorators.py", line 88, in inner_f
16:51:03 server.py[115570]:     return f(*args, **kwargs)
16:51:03 server.py[115570]:   File "/home/dnkn/BirdNET-Pi/birdnet/lib/python3.9/site-packages/librosa/core/audio.py", line 174, in load
16:51:03 server.py[115570]:     y, sr_native = __audioread_load(path, offset, duration, dtype)
16:51:03 server.py[115570]:   File "/home/dnkn/BirdNET-Pi/birdnet/lib/python3.9/site-packages/librosa/core/audio.py", line 198, in __audioread_load
16:51:03 server.py[115570]:     with audioread.audio_open(path) as input_file:
16:51:03 server.py[115570]:   File "/home/dnkn/BirdNET-Pi/birdnet/lib/python3.9/site-packages/audioread/__init__.py", line 111, in audio_open
16:51:03 server.py[115570]:     return BackendClass(path)
16:51:03 server.py[115570]:   File "/home/dnkn/BirdNET-Pi/birdnet/lib/python3.9/site-packages/audioread/rawread.py", line 62, in __init__
16:51:03 server.py[115570]:     self._fh = open(filename, 'rb')
16:51:03 server.py[115570]: FileNotFoundError: [Errno 2] No such file or directory: '/home/dnkn/BirdSongs/May-2022/10-Tuesday/2022-05-10-birdnet-16:50:33.wav'

Thanks, @jacobabehm

I think @ehpersonal38 may have identified the issue. I have access to another test system which I will be going through today and testing the new fix. I will keep you up to date with that.

I hope you'll stick around while we get this figured out, as I do think the system itself is worth the trouble

[ehpersonal38]

I'm going to go out on a limb and say this commit broke it : c914c64

So maybe sleeping longer could help? Of course why does it need to sleep at all? That's a question Patrick can hopefully answer and resolve this! 😃

[mcguirepr89]

I think you're right about that commit being the "culprit" and that it needs to sleep a little longer to ensure the file is closed and has the expected header's EOF. I think increasing the sleep by 1 second would suffice and is worth testing. Thank you for looking deeper into things 👍

[mcguirepr89]

I was able to identify the bug -- please see the comment (referenced from the issue) below

[mcguirepr89]

#266 (comment)

[jacobabehm]

Thank you team. It seems to working fine now.

I'm having a blast with this project. I do have a few more general questions, I hope this is the right forum to ask. Please tell me if not:

1. Just for kicks, I've been using Merlin Sound ID to listen to the live audio output of BirdNET. In the last 20 minutes, Merlin has made 12 detections to BirdNET's 0, and that's starting with BirdNET's audio signal, and then combining it with all the noise in my room. I see most if not all of the detections scroll by in the log, but with confidence numbers too low to post. Does Merlin use a much lower confidence threshold? Whatever Merlin uses, it seems very accurate in my limited experience. Where do you all have your confidence threshold set? Any other explanations for the disparity between Merlin and BirdNET?

2. I'm trying out different microphones. I have a selection of pro audio gear, so I've tried Behringer ECM8000, Rode NTG4+, Rode NT5, and several other Rode mics. Are any of these mics suited for the purpose? I want to get the best audio possible, within reason of course. I'm not going to go out and spend $1000 on a mic. But if I could get significant improvements using something else in the $1-200, I wouldn't hesitate. I've also read through some of the threads about DIY condensers, but will those offer an improvement over what I'm already using? What are you all using?

[ehpersonal38]

I personally have my confidence level at 0.4. I found that even with quality recordings of a Northern Cardinal, the confidence of the model was still only about 0.5, so I went slightly lower than that, and so far most birds that I hear outside end up getting detected. So I'm happy with that.

So maybe try an approach like that to find your optimal confidence level? Best of luck.

[CaiusX]

Hi team

I think a new thread microphone settings/model settings should be started - we also have overlap & sensitivity parameters at our disposal.

[bigfish69]

Have reinstalleed BirdNET Pi a few times, even on different microSD cards but get the following only after a few minutes to an hour

18:56:46--- sig, rate = librosa.load(path, sr=sample_rate, mono=True, res_type='kaiser_fast')
18:56:46--- File "BirdNET-Pi/birdnet/lib/python3.9/site-packages/librosa/util/decorators.py", line 88, in inner_f
18:56:46--- return f(*args, **kwargs)
18:56:46--- File "BirdNET-Pi/birdnet/lib/python3.9/site-packages/librosa/core/audio.py", line 170, in load
18:56:46--- y, sr_native = __audioread_load(path, offset, duration, dtype)
18:56:46--- File "BirdNET-Pi/birdnet/lib/python3.9/site-packages/librosa/core/audio.py", line 226, in __audioread_load
18:56:46--- reader = audioread.audio_open(path)
18:56:46--- File "BirdNET-Pi/birdnet/lib/python3.9/site-packages/audioread/init.py", line 132, in audio_open
18:56:46--- raise NoBackendError()
18:56:46---audioread.exceptions.NoBackendError

Any idea of how to resolve this please?