Does not work (no 'wurb_recordings' dir and no WAV-files in it) after FastAPI update to 0.65.2.

[slowglow]

With a fresh install of latest development and latest release version (0.9.0) I cannot get a recording, although the web interface seems to run OK. There's not even the directory which is supposed to hold the recordings.

I imagined there may be a permission problem, but on the command line I can easily make a new directory in the /home/pi dir.

I doubt it has any relation to the issue, but during install (raspberry pi and RaspAP) I changed the usernames and device names to values different from what is recommended in the installation instructions.

Here's the latest entries in the wurb_rec_debug_log.txt, if it is any help.

2021-06-11 19:22:24,045 DEBUG : API called: rpi-control:rpi_status. 2021-06-11 19:22:24,136 DEBUG : Sound card: bcm2835 Headphones Index: 0 2021-06-11 19:22:24,137 DEBUG : Sound card: UltraMic384K 16bit r0 Index: 1 2021-06-11 19:22:24,137 DEBUG : Sound cards capture: [1] 2021-06-11 19:22:24,137 DEBUG : Sound cards playback: [0] 2021-06-11 19:22:24,142 INFO : Connected microphone: UltraMic384K 16bit r0 Frequency: 384000 Hz. 2021-06-11 19:22:24,142 INFO : Can't calculate solartime. Lat/long is missing. 2021-06-11 19:22:28,092 DEBUG : API called: rpi-control:rpi_status. 2021-06-11 19:22:28,192 DEBUG : Sound card: bcm2835 Headphones Index: 0 2021-06-11 19:22:28,193 DEBUG : Sound card: UltraMic384K 16bit r0 Index: 1 2021-06-11 19:22:28,193 DEBUG : Sound cards capture: [1] 2021-06-11 19:22:28,193 DEBUG : Sound cards playback: [0] 2021-06-11 19:22:28,198 INFO : Connected microphone: UltraMic384K 16bit r0 Frequency: 384000 Hz. 2021-06-11 19:22:28,199 INFO : Can't calculate solartime. Lat/long is missing. 2021-06-11 19:22:43,189 DEBUG : API called: set-audio-feedback. 2021-06-11 19:22:43,190 DEBUG : Exception: WurbPitchShifting: setup: unsupported operand type(s) for /: 'NoneType' and 'int' 2021-06-11 19:23:33,357 DEBUG : API called: manual-trigger. 2021-06-11 19:23:33,358 INFO : Manually triggered. 2021-06-11 19:23:45,268 DEBUG : API called: manual-trigger. 2021-06-11 19:23:45,269 INFO : Manually triggered. 2021-06-11 19:23:48,042 DEBUG : API called: manual-trigger. 2021-06-11 19:23:48,043 INFO : Manually triggered. 2021-06-11 19:23:48,937 DEBUG : API called: manual-trigger. 2021-06-11 19:23:48,938 INFO : Manually triggered. 2021-06-11 19:23:56,954 DEBUG : API called: rpi-control:rpi_status. 2021-06-11 19:23:57,069 DEBUG : Sound card: bcm2835 Headphones Index: 0 2021-06-11 19:23:57,070 DEBUG : Sound card: UltraMic384K 16bit r0 Index: 1 2021-06-11 19:23:57,070 DEBUG : Sound cards capture: [1] 2021-06-11 19:23:57,070 DEBUG : Sound cards playback: [0] 2021-06-11 19:23:57,076 INFO : Connected microphone: UltraMic384K 16bit r0 Frequency: 384000 Hz. 2021-06-11 19:23:57,077 INFO : Can't calculate solartime. Lat/long is missing. 2021-06-11 19:24:10,325 DEBUG : API called: rpi-control:rpi_status. 2021-06-11 19:24:10,425 DEBUG : Sound card: bcm2835 Headphones Index: 0 2021-06-11 19:24:10,426 DEBUG : Sound card: UltraMic384K 16bit r0 Index: 1 2021-06-11 19:24:10,426 DEBUG : Sound cards capture: [1] 2021-06-11 19:24:10,426 DEBUG : Sound cards playback: [0] 2021-06-11 19:24:10,432 INFO : Connected microphone: UltraMic384K 16bit r0 Frequency: 384000 Hz. 2021-06-11 19:24:10,432 INFO : Can't calculate solartime. Lat/long is missing. 2021-06-11 19:24:28,885 DEBUG : API called: webpage. 2021-06-11 19:24:29,307 DEBUG : API called: get-location. 2021-06-11 19:24:29,313 DEBUG : API called: get-settings. 2021-06-11 19:24:29,452 DEBUG : API Websocket initiated. 2021-06-11 19:24:30,868 DEBUG : API called: webpage. 2021-06-11 19:24:31,289 DEBUG : API called: get-location. 2021-06-11 19:24:31,295 DEBUG : API called: get-settings. 2021-06-11 19:24:31,404 DEBUG : API Websocket initiated.

[arnoldandreasson]

Hi, and thank you for the report. It is good to have users that check the debug log, I like that :)

One basic problem is that I have to add more logging points in the code that makes it easier to follow whats happening inside the detector, for example when pressing the button for manually triggering as you did here. In this case there should either be a log row about the saved file, or an exception row describing why it fails.

The other part is to find out whats fails i your case.

• The changed device name should not be a problem, I use different names of all of them, but the user name may be a problem.
• The directory for recordings is only created when the first file is written to it. In this case somethings happens before that.
• Can you try to attach an USB memory? The detector check there first, then for "/home/pi" and finally use the current directory when trying to create a "wurb_recordings" directory.

I don't understand exactly how the username was changed. Maybe you need to change "sudo -u pi bash..." in "/etc/rc.local" and "sudo -u pi devmon &" in "wurb_rec_start.sh".

Please report back, it is a good thing to replace the "pi" user if a detector is opened up for public use and I have to look into that myself.

[slowglow]

Hi, thanks for your response. I like software that produces verbose logs, though in most cases they are not very helpful to me as a user. But they are useful to someone who knows the inner workings, so thumbs up for the good development practice.

• Sorry, I was too vague about usernames and device name changes: I changed the RasAP admin user, but I did keep the pi user on the Raspberry. The Raspberry device name was also changed, but you mentioned that it is not a problem.
• Good to know, that recordings directory is created on the first write. Maybe I don't have any data to write?
• I did attach a 8GB NTFS-formated USB disk -> nothing. Maybe it has to be ext3/4 or other *nix file system?

Any ideas what else to try? I have a bad feeling about the web-interface: whenever I press "Show status" button, no matter what "mode" i selected before that, mode is switched to "microphone - off" and status shows the name of my mic for a second and then disappears.

Regarding the username changes on the raspberry pi, I've done it as recently as last month, while setting up my home NAS, but I can't find my notes and it makes me a bit nervous. The workflow is very well explained in the official Raspberry Pi documentation on security settings. I have a nagging feeling that my notes mentioned the difference of using adduser or useradd, and a few warnings about not to forget to add the new user to the sudoers group before deleting the pi user, but I won't know for sure until find my notes. Hope this helps.

[arnoldandreasson]

NTFS is not installed by default. I think it is owned my Microsoft and can't be a part of the debian distribution. But you are allowed to install support for it yourself.

The jump to "microphone - off" indicates that the detector is not allowed to update the settings file. The name of the mic in the status field for a few seconds is a bug that will be fixed someday, it is mostly cosmetic, thanks for the hint. Try to remove "cloudedbats_wurb2020" and the directories starting with "wurb", then repeat the installation from "CloudedBats software" in the installation guide.

Yesterday I found a really useful page: https://raspberrypi-guide.github.io/ Under "Other/Increasing security" both changing the default user and adding a firewall are included. I have started to open up one detector for safe read-only access over SFTP and need that for that detector. The installation for that will be found in the guide for advanced users that can be found in the "docs" section. Maybe also useful to expose a home NAS?

[slowglow]

Hi, it's me again :-).

I did delete dirs and reinstall the development version -> no change. However, digging further leads me to believe the problems is with the settings passed to FastAPI.

After first killing the server, then manually restarting it and playing around in the web UI, here is what I get back at the Raspi console:

(venv) pi@edgedaq01:~/cloudedbats_wurb_2020 $ kill -9 $(ps -A | grep python3 | awk '{print $1}')
(venv) pi@edgedaq01:~/cloudedbats_wurb_2020 $ python3 wurb_rec_start.py
INFO:     Started server process [1226]
INFO:     Waiting for application startup.
INFO:     Application startup complete.
INFO:     Uvicorn running on http://0.0.0.0:8000 (Press CTRL+C to quit)
INFO:     ('10.3.141.58', 54245) - "WebSocket /ws" [accepted]
2021-06-14 04:12:18
Mon Jun 14 04:12:18 JST 2021
INFO:     10.3.141.58:54246 - "GET /set-time/?posixtime=1623611538424 HTTP/1.1" 200 OK
INFO:     10.3.141.58:54247 - "POST /save-settings/ HTTP/1.1" 422 Unprocessable Entity
INFO:     10.3.141.58:54247 - "GET /rec-manual-trigger/ HTTP/1.1" 200 OK
INFO:     10.3.141.58:54248 - "GET /rec-manual-trigger/ HTTP/1.1" 200 OK
INFO:     10.3.141.58:54249 - "POST /save-settings/ HTTP/1.1" 422 Unprocessable Entity
INFO:     10.3.141.58:54249 - "GET /rpi-control/?command=rpi_status HTTP/1.1" 200 OK

[arnoldandreasson]

Hi, this is strange. Completely new to me, but if it happens to you it may happens to others as well. It seems like the 422 error is related to FastAPI and the format checking part. And people complains because it does not tell what is wrong.

I started it up in my development mode (Mac - Parallels - Ubuntu - vscode) and it works as expected. But this maybe happens before my code is executed, otherwise there should be an error log about it when you run it. Then I activated "Web developer - Web developer tools" in Firefox. Then "Network", clicked on the Save button in the detectors UI and then checked the respons in raw format. This is what I got when it works and the response code is 200 OK:

{"rec_mode":"mode-off","file_directory":"Station-1","file_directory_date_option":"date-post-before","filename_prefix":"wurb","detection_limit_khz":"17","detection_sensitivity_dbfs":"-50","detection_algorithm":"detection-simple","rec_length_s":"6","rec_type":"FS","feedback_on_off":"feedback-off","feedback_volume":"50","feedback_pitch":"30","feedback_filter_low_khz":"15","feedback_filter_high_khz":"150","startup_option":"","scheduler_start_event":"on-sunset","scheduler_start_adjust":"-15","scheduler_stop_event":"off-sunrise","scheduler_stop_adjust":"15","scheduler_post_action":"post-none","scheduler_post_action_delay":"5"}

Another thing that can happen is that html and javascript files are out of sync. I try to increase a version number for js-files in the html file to avoid that, but strange things may happen anyway. Have you tried from another browser or mobile phone?

[arnoldandreasson]

Yes, you are right. It is related to the latest release of FastAPI. I upgraded to version FastAPI 0.65.2 and got the same error. It was release 5 days ago. Try to downgrade to FastAPI 0.63.0: pip uninstall fastapi pip install "fastapi==0.63.0"

I hope it will work until I have fixed the code.

[slowglow]

Fantastic! I can confirm that after reverting to the older version of FastAPI, the recorder works as expected.

Just a reminder to anyone trying to do the downgrade, to activate the virtual environment before uninstall/re-install like this:

source venv/bin/activate
pip uninstall fastapi
pip install "fastapi==0.63.0"

Although this solves the problem for me, you indicated that you consider it a workaround until you fix the code. So I am leaving this issue open for now. I took the liberty to simplify the title and point to cause of the problem.

I am really happy to have worked with you through this and I am looking forward to giving you useful feedback in the future. Just for comparison, I'd mention that at work I've had to deal with bugs in the toolboxes of a well-known software maker, where days go by before they acknowledge the (paid) support request, a week goes by to have it confirmed as a problem, and a promise that it will be fixed in a future version 1/2 years or 1 year later depending on the workload and priorities of the developers.
5 stars (*****)!

[arnoldandreasson]

The code is corrected and checked in to the main branch. FastAPI did a security upgrade and json is now only accepted in requests if content-type is set to application/json. It wasn't for POST requests, but they are now. I also added a note in the readme file if someone want to run older versions of the wurb.

And a really big thank you to slowglow who found the bug and also pointed out the right direction where to look. It was a tricky one, but we managed it together :)

[slowglow]

I am a happy user and closing this.