[BUG] Error after capturing night

[MadMacMad]

hello, get it all running well but now after switching to PNG i'll get this error every morning... images are there and i'll only save in the night... if i'll do ~/allsky/scripts $ endOfNight.sh 20231111 it works fine... so me think that is a bug...

here the log:

Nov 13 06:56:00 wetter allsky[10341]: -----
Nov 13 06:56:00 wetter allsky[10341]: STARTING EXPOSURE at: 2023-11-13 06:56:00   @ 1.0 sec
Nov 13 06:56:00 wetter allsky[10341]:  > Running: libcamera-still --output '/home/holle/allsky/tmp/AllSky-20231113065600.png' --tuning-file '/usr/share/libcamera/ipa/rpi/vc4/imx477_scientific.json' --encoding png --timeout 1 --nopreview --width 4056 --height 3040 --shutter 1000000 --analoggain 10 --awb auto --quality 9
Nov 13 06:56:01 wetter allsky[10341]:   > Sleeping from failed exposure: 2.5 seconds
Nov 13 06:56:01 wetter allsky[21963]: INFO: Adding Image Fields took 0.00023 seconds. Elapsed time 0.695547 seconds.
Nov 13 06:56:01 wetter allsky[21963]: INFO: Saving Final Image took 0.008578 seconds. Elapsed time 0.704179 seconds.
Nov 13 06:56:01 wetter allsky[21963]: INFO: Writing debug data took 5.3e-05 seconds. Elapsed time 0.70425 seconds.
Nov 13 06:56:01 wetter allsky[21963]: INFO: Debug information written to /home/holle/allsky/tmp/overlaydebug.txt
Nov 13 06:56:01 wetter allsky[21963]: INFO: Annotation Complete Elapsed time 0.706844 seconds.
Nov 13 06:56:01 wetter allsky[21963]: INFO: Overlay Complete.
Nov 13 06:56:01 wetter allsky[21963]: INFO: Module allsky_overlay.py ran ok in 0.72s
Nov 13 06:56:01 wetter allsky[21963]: INFO: ----------------------- Running Module allsky_saveimage.py -----------------------
Nov 13 06:56:01 wetter allsky[21963]: INFO: Attempting to load allsky_saveimage
Nov 13 06:56:01 wetter allsky[21963]: INFO: Image /home/holle/allsky/tmp/AllSky-20231113065542.png Saved, quality 3
Nov 13 06:56:01 wetter allsky[21963]: INFO: Ignoring watchdog for module saveimage
Nov 13 06:56:01 wetter allsky[21963]: INFO: day flow Complete...
Nov 13 06:56:03 wetter allsky[10341]: Executing sunwait poll exit angle -8.0000 52.2N 7.18E > /dev/null
Nov 13 06:56:03 wetter allsky[10341]: -----
Nov 13 06:56:03 wetter allsky[10341]: STARTING EXPOSURE at: 2023-11-13 06:56:03   @ 1.0 sec
Nov 13 06:56:03 wetter allsky[10341]:  > Running: libcamera-still --output '/home/holle/allsky/tmp/AllSky-20231113065603.png' --tuning-file '/usr/share/libcamera/ipa/rpi/vc4/imx477_scientific.json' --encoding png --timeout 1 --nopreview --width 4056 --height 3040 --shutter 1000000 --analoggain 10 --awb auto --quality 9
Nov 13 06:56:04 wetter allsky[10341]:   > Sleeping from failed exposure: 2.5 seconds
Nov 13 06:56:07 wetter allsky[10341]: Executing sunwait poll exit angle -8.0000 52.2N 7.18E > /dev/null
Nov 13 06:56:07 wetter allsky[10341]: -----
Nov 13 06:56:07 wetter allsky[10341]: STARTING EXPOSURE at: 2023-11-13 06:56:07   @ 1.0 sec
Nov 13 06:56:07 wetter allsky[10341]:  > Running: libcamera-still --output '/home/holle/allsky/tmp/AllSky-20231113065607.png' --tuning-file '/usr/share/libcamera/ipa/rpi/vc4/imx477_scientific.json' --encoding png --timeout 1 --nopreview --width 4056 --height 3040 --shutter 1000000 --analoggain 10 --awb auto --quality 9
Nov 13 06:56:08 wetter allsky[10341]:   > Sleeping from failed exposure: 2.5 seconds
Nov 13 06:56:10 wetter allsky[10341]: Executing sunwait poll exit angle -8.0000 52.2N 7.18E > /dev/null
Nov 13 06:56:10 wetter allsky[10341]: -----
Nov 13 06:56:10 wetter allsky[10341]: STARTING EXPOSURE at: 2023-11-13 06:56:10   @ 1.0 sec
Nov 13 06:56:10 wetter allsky[10341]:  > Running: libcamera-still --output '/home/holle/allsky/tmp/AllSky-20231113065610.png' --tuning-file '/usr/share/libcamera/ipa/rpi/vc4/imx477_scientific.json' --encoding png --timeout 1 --nopreview --width 4056 --height 3040 --shutter 1000000 --analoggain 10 --awb auto --quality 9
Nov 13 06:56:11 wetter allsky[10341]: *** /home/holle/allsky/bin/capture_RPi: ERROR: maximum number of consecutive errors of 4 reached; capture program stopped.
Nov 13 06:56:11 wetter allsky[10341]: Executing /home/holle/allsky/scripts/addMessage.sh error '*** /home/holle/allsky/bin/capture_RPi: ERROR: maximum number of consecutive errors of 4 reached; capture program stopped.'
Nov 13 06:56:11 wetter allsky[10341]: Make sure cable between camera and Pi is all the way in.
Nov 13 06:56:11 wetter allsky[10341]: Executing /home/holle/allsky/scripts/addMessage.sh info 'Make sure cable between camera and Pi is all the way in.'
Nov 13 06:56:11 wetter allsky[10341]: Calling system(/home/holle/allsky/scripts/copy_notification_image.sh --expires 2 NotRunning &)
Nov 13 06:56:14 wetter allsky[10341]:      ***** Stopping AllSky *****
Nov 13 06:56:14 wetter allsky[10224]: ***
Nov 13 06:56:14 wetter allsky[10224]: *** After fixing, restart the allsky service. ***
Nov 13 06:56:14 wetter allsky[10224]: ***
Nov 13 06:56:15 wetter allsky[10224]:      ***** AllSky Stopped *****

to me it looks like the endOfNight.sh get called to early ... allsky is not finished writing the png ... one love M.

[EricClaeys]

Would you please post your allsky/config/settings.json file as well as allsky/config/config.sh ? You will need to append .txt to their names.

The error isn't related to endOfNight.sh. For whatever reason, libcamera cannot take pictures. Does this happen all the time, or just in the morning?

Did you delete some entries in the log file? It looks like your Debug Level is 4 in the WebUI, but there should have been a lot more log output that I might need to debug the problem. If it's at 4, what's in /tmp/capture_RPi_debug.txt ?

If this problem happens all the time, try running this manually.

libcamera-still --output '/home/holle/allsky/tmp/AllSky-20231113065607.png' --tuning-file '/usr/share/libcamera/ipa/rpi/vc4/imx477_scientific.json' --encoding png --timeout 1 --nopreview --width 4056 --height 3040 --shutter 1000000 --analoggain 10 --awb auto --quality 9

[MadMacMad]

hello, thx for quick reply! yes happen only after finishing nightshot's in the morning ...until than it works all well... pictures are there and no errors... i'll did not post the complete log... it's too huge 65MB but i've uploaded to my server: https://www.smart-app.dev/Down/allsky.log.zip settings.json.txt config.sh.txt i'll did not see /tmp/capture_RPi_debug.txt

after the Error happen in the morning i'll need to reboot the PI ... Hardware: PI Model 4B Revision 1.4 (8 GB) using external SSD to boot & run allsky Raspberry HQ Camera with 2.7mm F2.5 15MP 1/2.3" lens

when allsky is not running the command works without issues... libcamera-still --output '/home/holle/allsky/tmp/AllSky-20231113065607.png' --tuning-file '/usr/share/libcamera/ipa/rpi/vc4/imx477_scientific.json' --encoding png --timeout 1 --nopreview --width 4056 --height 3040 --shutter 1000000 --analoggain 10 --awb auto --quality 9 [2:14:27.706627307] [21794] INFO Camera camera_manager.cpp:297 libcamera v0.0.5+83-bde9b04f [2:14:27.757436459] [21795] INFO RPI vc4.cpp:437 Registered camera /base/soc/i2c0mux/i2c@1/imx477@1a to Unicam device /dev/media4 and ISP device /dev/media1 [2:14:27.757557495] [21795] INFO RPI pipeline_base.cpp:1101 Using configuration file '/usr/share/libcamera/pipeline/rpi/vc4/rpi_apps.yaml' [2:14:27.759193252] [21794] INFO Camera camera.cpp:1033 configuring streams: (0) 2028x1520-YUV420 [2:14:27.760130295] [21795] INFO RPI vc4.cpp:565 Sensor: /base/soc/i2c0mux/i2c@1/imx477@1a - Selected sensor format: 2028x1520-SBGGR12_1X12 - Selected unicam format: 2028x1520-pBCC Stream configuration adjusted [2:14:28.520299497] [21794] INFO Camera camera.cpp:1033 configuring streams: (0) 4056x3040-BGR888 (1) 4056x3040-SBGGR12_CSI2P [2:14:28.521575481] [21795] INFO RPI vc4.cpp:565 Sensor: /base/soc/i2c0mux/i2c@1/imx477@1a - Selected sensor format: 4056x3040-SBGGR12_1X12 - Selected unicam format: 4056x3040-pBCC Still capture image received

and again... the issue is only in the morning when capturing stopp's and it start's to run the scripts... me think still it need's little delay before the scripts get fired ... think it's still writing the last bit's the PNG file is around 20MB in size ... my SSD is fast enough ... and space is plenty like RAM (8GB)

i'll like the quality of the PNG much much more than the JPG ... maybe in future version we can get the RAW output from the HQ camera? If you have the space like me ... 1TB is enough for some time to capture in RAW .. and if there is some nice action in the Sky... me thing many would be happy to have best quality as possible... the quality of the PNG is already good if you tweak the settings ... did all test's like JPG 50-100% and PNG 0-9 ... while JPG 75% gave best result's with file size and quality... was best quality 95% ... PNG 3 ...

if there is anything else i'll can do let me know. many thx & great work!

[EricClaeys]

@MadMacMad, I am pretty sure your daytime Delay is too short. Saving .png files takes longer than .jpg files since there is no hardware support for .png. While keograms/ startrails/ timelapse are being created the cpu is very busy which makes saving .png files take even longer, and one image is still being processed while the next image is being taken. Allsky only allows one libcamera to run at a time, so if it finds one running when it wants to take another image it kills the first one. I suspect that's what's happening. Before changing anything, please install the prerelease of Point Release 4 which outputs an error message when libcamera is killed. To install it, run the "git clone" command adding --branch Point-Release-4 to the command line. Then change Debug Level to 3 and restart Allsky. When it fails again tomorrow upload /var/log/allsky.log which should be much smaller. Danke - Eric

[MadMacMad]

hello, just installed PR4 ... easy to do and straight forward process ... all settings and everything is there... no issues... so i've run cd ~/allsky; scripts/check_allsky.sh

---------- Warnings (items that may keep parts of Allsky running) ----------

The minimum delay of 10 ms may be too short
given the maximum expected time to save and process
an image (5000 ms).
A new image may appear before the prior one has finished processing.
Consider increasing your delay.
-----
Timelapse videos are being created (TIMELAPSE='true') but not uploaded (UPLOAD_VIDEO='false')
-----
Keograms are being created (KEOGRAM='true') but not uploaded (UPLOAD_KEOGRAM='false')
-----
Startrails are being created (STARTRAILS='true') but not uploaded (UPLOAD_STARTRAILS='false')

---------- Summary ----------

Warnings: 4

i'll changed Delay to 5000ms ... let's see tomorrow morning ... many thx

[MadMacMad]

if i'll call endofnight manually i'll get following message....

~/allsky/scripts $ ./endOfNight.sh 20231106
endOfNight.sh: ===== Posting twilight data
endOfNight.sh: ===== Generating Keogram for 20231106
endOfNight.sh: ===== Keogram complete
endOfNight.sh: ===== Generating Startrails for 20231106
Minimum: 0.0789715 maximum: 0.942084 mean: 0.17046 median: 0.138469
endOfNight.sh: ===== Startrails complete
endOfNight.sh: ===== Generating Timelapse for 20231106
endOfNight.sh: ===== Timelapse complete
endOfNight.sh: ===== Posting camera details to allsky map
import-im6.q16: unable to open X server `' @ error/import.c/ImportImageCommand/346.
import-im6.q16: unable to open X server `' @ error/import.c/ImportImageCommand/346.
import-im6.q16: unable to open X server `' @ error/import.c/ImportImageCommand/346.
import-im6.q16: unable to open X server `' @ error/import.c/ImportImageCommand/346.
import-im6.q16: unable to open X server `' @ error/import.c/ImportImageCommand/346.
/home/holle/allsky/scripts/flow-runner.py: line 6: from: command not found
import-im6.q16: unable to open X server `' @ error/import.c/ImportImageCommand/346.
/home/holle/allsky/scripts/flow-runner.py: line 8: from: command not found
import-im6.q16: unable to open X server `' @ error/import.c/ImportImageCommand/346.
import-im6.q16: unable to open X server `' @ error/import.c/ImportImageCommand/346.
import-im6.q16: unable to open X server `' @ error/import.c/ImportImageCommand/346.
/home/holle/allsky/scripts/flow-runner.py: line 18: $'\nNOTE: `valid_module_paths` must be an array, and the order specified dictates the order of search for a named module.\nIt is expected that the user supplied modules are searched first, and thus come before the distributed modules path.\nThis permits the user to copy and modify a distributed module, or create an entirely new replacement for a distributed\nmodule, thus giving the user total control.\n': command not found
/home/holle/allsky/scripts/flow-runner.py: line 19: syntax error near unexpected token `('
/home/holle/allsky/scripts/flow-runner.py: line 19: `def signalHandler(sig, frame):'

but all is made correctly... Timelapse, Keogram and Startrails are there and no issues...

[EricClaeys]

@MadMacMad, thanks for reporting that bug. We will fix it. You are running Point-Release-4, correct?

@Alex-developer, I assume anywhere we call flow-runner.py or any other .py script from a .sh script we need to source "activate" on Bookworm and call the script using python3? This bug is because flow-runner.py no longer has a shebang but is not called via python3.

[MadMacMad]

good morning, YES PR 4 ... and this morning it stopped too... here is the capture_RPi_debug.txt Stream configuration adjusted [19:02:21.974551267] [19769] ERROR V4L2 v4l2_videodevice.cpp:1241 /dev/video14[16:cap]: Unable to request 1 buffers: Cannot allocate memory ERROR: *** failed to allocate capture buffers *** and the log: allsky.log.txt

[EricClaeys]

@MadMacMad, sorry for very long delay. The bug with "@ error/import.c/ImportImageCommand/346" is fixed in the current point release 4. Please do the "git clone" of it like you did before, but BEFORE you run ./install.sh remove the exit line at the top of that file.

Assuming Allsky still stops at end of night, attach /var/log/allsky.log. Then set the Filename to image.jpg and see if it works the next morning.

[EricClaeys]

@MadMacMad, Point Release 4 is out so if you haven't installed it yet would you do so and let me know how it goes?

[MadMacMad]

Confirmed.... ! last version works without issues... thank you... well well done... runs also smooth on bookwork 64 bit with all my sensors... only installing a driver in the new virtual environment is different... and updating some old scripts ... M.