×

INDI Library v2.0.6 is Released (02 Feb 2024)

Bi-monthly release with minor bug fixes and improvements

Unable to open sequence queue file - after already imaging several targets

  • Posts: 7
  • Thank you received: 1
I could reproduce the error using the 1 sec image as mentioned above.

1)  setup camera collection as expose 1 sec with 50 count, with filter/gain/offset as needed, give name (Lseq1sec50.....esq)
2)  setup schedule on target (Dubhe) with no track, no focus, no align, no guide using sequence from (1).  setup 20 targets with names like (Dub-1, Dub-2, Dub-3, ... as repeats)

a)  When it runs I get to Dubhe-7 set (about 350-400 images collected).
b)  Fail shows up as "invalid" and issue highlighted above.  Image attached shows sequence in middle of fail.  Second image shows (a) the list of files in D-7 set and you will see gets multiple files named file_xxxxxx_039.fits (this was the beginning of the fail).  I "reset" the camera without stopping the sequence or capture because failed on download of image. (these are the xxxx_040.fits files).  after it gets all the way through the 50 files in the set, the sequencer notes complete and all other items are "invalid", so does shutdown process and closes all items and stops.
c)  Attempt to "restart/reconnect" ekos without closing application will result in eventual kstars application crash. I restarted ekos to check the camera and crashed.  Restart of kstars, restart of ekos after crash will work OK -  this is what I normally do when I get invalid as other UI features are broken if you do not restart.
d)  attached are esl and esq files.

   
 

 
2 years 6 months ago #75513
Attachments:

Please Log in or Create an account to join the conversation.

  • Posts: 7
  • Thank you received: 1
Repeat the above sequence -- fails at section 8 file 39-40.

Collect and attach Log file!  Below / zipped.

 
2 years 6 months ago #75514
Attachments:

Please Log in or Create an account to join the conversation.

  • Posts: 7
  • Thank you received: 1
recapture the head of log for restart to show initialization as missing from log above

[2021-09-14T11:10:50.414 CDT INFO ][ org.kde.kstars] - Welcome to KStars 3.5.4 Stable
[2021-09-14T11:10:50.415 CDT INFO ][ org.kde.kstars] - Build: 2021-07-15T21:15:09Z
[2021-09-14T11:10:50.416 CDT INFO ][ org.kde.kstars] - OS: "raspbian"
[2021-09-14T11:10:50.417 CDT INFO ][ org.kde.kstars] - API: "arm-little_endian-ilp32-eabi-hardfloat"
[2021-09-14T11:10:50.417 CDT INFO ][ org.kde.kstars] - Arch: "arm"
[2021-09-14T11:10:50.418 CDT INFO ][ org.kde.kstars] - Kernel Type: "linux"
[2021-09-14T11:10:50.419 CDT INFO ][ org.kde.kstars] - Kernel Version: "5.10.60-v7l+"
[2021-09-14T11:10:50.419 CDT INFO ][ org.kde.kstars] - Qt Version: 5.11.3
[2021-09-14T11:10:50.438 CDT INFO ][ org.kde.kstars] - KStars is started in paused state.
[2021-09-14T11:10:50.712 CDT DEBG ][ org.kde.kstars] - Opened the User DB. Ready.
[2021-09-14T11:10:51.228 CDT INFO ][ org.kde.kstars] - Processing "unnamedstars.dat" , HTMesh Level 3
[2021-09-14T11:10:51.228 CDT INFO ][ org.kde.kstars] - Sky Mesh Size: 512
[2021-09-14T11:10:51.316 CDT INFO ][ org.kde.kstars] - Loaded DSO catalog file: "unnamedstars.dat"
[2021-09-14T11:10:51.317 CDT INFO ][ org.kde.kstars] - Processing "deepstars.dat" , HTMesh Level 3
[2021-09-14T11:10:51.318 CDT INFO ][ org.kde.kstars] - Sky Mesh Size: 512
[2021-09-14T11:10:51.318 CDT INFO ][ org.kde.kstars] - Loaded DSO catalog file: "deepstars.dat"
[2021-09-14T11:10:52.104 CDT WARN ][ org.kde.kstars] - "Star HD20794 not found."
[2021-09-14T11:10:52.140 CDT WARN ][ org.kde.kstars] - "Star HD98230 not found."
[2021-09-14T11:10:52.179 CDT INFO ][ org.kde.kstars] - Loaded DSO catalogs.
[2021-09-14T11:10:52.633 CDT DEBG ][ default] - File opened: "/home/astroberry/.local/share/kstars/comets.dat"
[2021-09-14T11:10:53.389 CDT WARN ][ org.kde.kstars] - Current icon theme is "PiXflat"
[2021-09-14T11:10:53.434 CDT DEBG ][ org.kde.kstars] - Paths to color scheme : ("/usr/share/kstars/themes")
[2021-09-14T11:10:54.404 CDT DEBG ][ org.kde.kstars] - Reporting new timestep value: 60
[2021-09-14T11:10:54.814 CDT DEBG ][ qt5ct] - D-Bus global menu: no
[2021-09-14T11:10:54.839 CDT CRIT ][ default] - Shortcut for action "get_data" "Download New Data..." set with QAction::setShortcut()! Use KActionCollection::setDefaultShortcut(s) instead.
[2021-09-14T11:10:54.985 CDT DEBG ][ org.kde.kstars] - Daylight Saving Time active
[2021-09-14T11:10:54.987 CDT DEBG ][ org.kde.kstars] - Next Daylight Savings Time change (Local Time): "Sun Nov 7 02:00:00 2021 GMT"
[2021-09-14T11:10:54.988 CDT DEBG ][ org.kde.kstars] - Next Daylight Savings Time change (UTC): "Sun Nov 7 07:00:00 2021 GMT"
[2021-09-14T11:10:55.617 CDT DEBG ][ org.kde.kstars] - Date/Time is: "Tue Sep 14 16:10:50 2021 GMT"
[2021-09-14T11:10:55.617 CDT DEBG ][ org.kde.kstars] - Location: "Home, Texas, USA"
[2021-09-14T11:10:55.618 CDT DEBG ][ org.kde.kstars] - TZ0: -6 TZ: -5
[2021-09-14T11:10:55.619 CDT WARN ][ org.kde.kstars] - Current icon theme is "breeze-dark"
[2021-09-14T11:10:55.714 CDT DEBG ][ org.kde.kstars] - "Black Body" :: "/usr/share/kstars/themes/blackbody.colors"
[2021-09-14T11:10:56.094 CDT DEBG ][ default] - glibc >= 2.1 detected. Using GNU extension sincos()
[2021-09-14T11:10:56.114 CDT DEBG ][ default] - static bool LibSecretKeyring::findPassword(const QString&, const QString&, QKeychain::JobPrivate*)
[2021-09-14T11:10:57.449 CDT DEBG ][ default] - File opened: "/home/astroberry/.local/share/kstars/comets.dat"
[2021-09-14T11:10:59.914 CDT DEBG ][ default] - File opened: "/home/astroberry/.local/share/kstars/asteroids.dat"
2 years 6 months ago #75515

Please Log in or Create an account to join the conversation.

  • Posts: 33
  • Thank you received: 7
Hi Scott

I did not dig through your logs yet - I will - but I did find this in mine from last night's crash.

[2021-09-14T04:26:06.200 BST WARN ][                       default] - QProcessPrivate::createPipe: Cannot create pipe 0x6e95414: Too many open files

In context below:

[2021-09-14T04:23:03.151 BST DEBG ][ org.kde.kstars.ekos.scheduler] - Frame map summary:
[2021-09-14T04:23:03.152 BST DEBG ][ org.kde.kstars.ekos.scheduler] -   "/universe/Pictures/AllSky/Zenith/Light/Zenith_Light" : 385
[2021-09-14T04:23:03.153 BST INFO ][ org.kde.kstars.ekos.scheduler] - "Job 'Zenith' 60x60\"  completed its sequence of 0 light frames."
[2021-09-14T04:23:03.161 BST DEBG ][ org.kde.kstars.ekos.scheduler] - "Job 'Zenith' is configured to loop until Scheduler is stopped manually, has undefined imaging time."
[2021-09-14T04:23:03.161 BST DEBG ][ org.kde.kstars.ekos.scheduler] - Capture State "Capturing"
[2021-09-14T04:23:03.173 BST DEBG ][           org.kde.kstars.indi] - INDI Server:  "2021-09-14T03:23:03: Driver indi_sx_ccd: sxClearPixels: libusb_control_transfer -> OK"
[2021-09-14T04:23:03.173 BST DEBG ][           org.kde.kstars.indi] - INDI Server:  ""
[2021-09-14T04:24:00.040 BST DEBG ][           org.kde.kstars.indi] - INDI Server:  "2021-09-14T03:24:00: Driver indi_sx_ccd: sxClearPixels: libusb_control_transfer -> OK"
[2021-09-14T04:24:00.040 BST DEBG ][           org.kde.kstars.indi] - INDI Server:  ""
[2021-09-14T04:24:03.041 BST DEBG ][           org.kde.kstars.indi] - INDI Server:  "2021-09-14T03:24:03: Driver indi_sx_ccd: sxLatchPixels: libusb_control_transfer -> OK"
[2021-09-14T04:24:03.041 BST DEBG ][           org.kde.kstars.indi] - INDI Server:  ""
[2021-09-14T04:24:03.792 BST DEBG ][           org.kde.kstars.indi] - INDI Server:  "2021-09-14T03:24:03: Driver indi_sx_ccd: sxReadPixels: libusb_control_transfer -> OK"
[2021-09-14T04:24:03.793 BST DEBG ][           org.kde.kstars.indi] - INDI Server:  ""
[2021-09-14T04:24:03.943 BST DEBG ][           org.kde.kstars.indi] - Image received. Mode: "Normal" Size: 2900160
[2021-09-14T04:24:03.950 BST INFO ][           org.kde.kstars.indi] - "FITS" file saved to "/universe/Pictures/AllSky/Zenith/Light/Zenith_Light_476.fits"
[2021-09-14T04:24:03.993 BST INFO ][   org.kde.kstars.ekos.capture] - "Download Time: 0.08 s, New Download Time Estimate: 0.08 s."
[2021-09-14T04:24:04.086 BST INFO ][   org.kde.kstars.ekos.capture] - "Received image 56 out of 60."
[2021-09-14T04:24:04.110 BST DEBG ][                       default] - WARNING: Phonon::createPath: Cannot connect  Phonon::MediaObject ( no objectName ) to  Phonon::AudioOutput ( no objectName ).
[2021-09-14T04:24:04.583 BST INFO ][ org.kde.kstars.ekos.scheduler] - Executing Job  "Zenith"
[2021-09-14T04:25:01.116 BST DEBG ][           org.kde.kstars.indi] - INDI Server:  "2021-09-14T03:25:01: Driver indi_sx_ccd: sxClearPixels: libusb_control_transfer -> OK"
[2021-09-14T04:25:01.117 BST DEBG ][           org.kde.kstars.indi] - INDI Server:  ""
[2021-09-14T04:25:04.118 BST DEBG ][           org.kde.kstars.indi] - INDI Server:  "2021-09-14T03:25:04: Driver indi_sx_ccd: sxLatchPixels: libusb_control_transfer -> OK"
[2021-09-14T04:25:04.118 BST DEBG ][           org.kde.kstars.indi] - INDI Server:  ""
[2021-09-14T04:25:04.867 BST DEBG ][           org.kde.kstars.indi] - INDI Server:  "2021-09-14T03:25:04: Driver indi_sx_ccd: sxReadPixels: libusb_control_transfer -> OK"
[2021-09-14T04:25:04.868 BST DEBG ][           org.kde.kstars.indi] - INDI Server:  ""
[2021-09-14T04:25:05.020 BST DEBG ][           org.kde.kstars.indi] - Image received. Mode: "Normal" Size: 2900160
[2021-09-14T04:25:05.024 BST INFO ][           org.kde.kstars.indi] - "FITS" file saved to "/universe/Pictures/AllSky/Zenith/Light/Zenith_Light_476.fits"
[2021-09-14T04:25:05.066 BST INFO ][   org.kde.kstars.ekos.capture] - "Download Time: 0.08 s, New Download Time Estimate: 0.08 s."
[2021-09-14T04:25:05.068 BST WARN ][                       default] - QProcessPrivate::createPipe: Cannot create pipe 0x6e95414: Too many open files
[2021-09-14T04:25:05.157 BST INFO ][   org.kde.kstars.ekos.capture] - "Received image 57 out of 60."
[2021-09-14T04:25:05.183 BST DEBG ][                       default] - WARNING: Phonon::createPath: Cannot connect  Phonon::MediaObject ( no objectName ) to  Phonon::AudioOutput ( no objectName ).
[2021-09-14T04:25:05.582 BST INFO ][ org.kde.kstars.ekos.scheduler] - Executing Job  "Zenith"
[2021-09-14T04:26:02.346 BST DEBG ][           org.kde.kstars.indi] - INDI Server:  "2021-09-14T03:26:02: Driver indi_sx_ccd: sxClearPixels: libusb_control_transfer -> OK"
[2021-09-14T04:26:02.346 BST DEBG ][           org.kde.kstars.indi] - INDI Server:  ""
[2021-09-14T04:26:05.233 BST DEBG ][           org.kde.kstars.indi] - INDI Server:  "2021-09-14T03:26:05: Driver indi_sx_ccd: sxLatchPixels: libusb_control_transfer -> OK"
[2021-09-14T04:26:05.233 BST DEBG ][           org.kde.kstars.indi] - INDI Server:  ""
[2021-09-14T04:26:05.982 BST DEBG ][           org.kde.kstars.indi] - INDI Server:  "2021-09-14T03:26:05: Driver indi_sx_ccd: sxReadPixels: libusb_control_transfer -> OK"
[2021-09-14T04:26:05.982 BST DEBG ][           org.kde.kstars.indi] - INDI Server:  ""
[2021-09-14T04:26:06.146 BST DEBG ][           org.kde.kstars.indi] - Image received. Mode: "Normal" Size: 2900160
[2021-09-14T04:26:06.153 BST INFO ][           org.kde.kstars.indi] - "FITS" file saved to "/universe/Pictures/AllSky/Zenith/Light/Zenith_Light_476.fits"
[2021-09-14T04:26:06.197 BST INFO ][   org.kde.kstars.ekos.capture] - "Download Time: 0.09 s, New Download Time Estimate: 0.08 s."
[2021-09-14T04:26:06.200 BST WARN ][                       default] - QProcessPrivate::createPipe: Cannot create pipe 0x6e95414: Too many open files
[2021-09-14T04:26:06.287 BST INFO ][   org.kde.kstars.ekos.capture] - "Received image 58 out of 60."
[2021-09-14T04:26:06.298 BST DEBG ][ org.kde.kstars.ekos.scheduler] - Capture State "Image Received"
[2021-09-14T04:26:06.299 BST DEBG ][ org.kde.kstars.ekos.scheduler] - "Searching in path '/universe/Pictures/AllSky/Zenith/Light', files 'Zenith_Light*' for prefix 'Zenith_Light'..."

Do you see similar logging?  I did wonder if maybe there is some loose handling around counting the number of files in the target directory which causes the ulimit number of files to be exceeded.

And what is this?

default] - WARNING: Phonon::createPath: Cannot connect  Phonon::MediaObject ( no objectName ) to  Phonon::AudioOutput ( no objectName ).

I did set

ulimit -n 4096 (previous llimit was 1024) but checking just now with ulimit -a shows it has not taken the setting (or maybe I rebooted after setting).

astroberry@astroberry:~ $ ulimit -a
core file size          (blocks, -c) 0
data seg size           (kbytes, -d) unlimited
scheduling priority             (-e) 0
file size               (blocks, -f) unlimited
pending signals                 (-i) 62253
max locked memory       (kbytes, -l) unlimited
max memory size         (kbytes, -m) unlimited
open files                      (-n) 1024
pipe size            (512 bytes, -p) 8
POSIX message queues     (bytes, -q) 819200
real-time priority              (-r) 95
stack size              (kbytes, -s) 8192
cpu time               (seconds, -t) unlimited
max user processes              (-u) 62253
virtual memory          (kbytes, -v) unlimited
file locks                      (-x) unlimited

Jasem - can you check the code around this area to see if file handles might be being left open during the counting please?  Also maybe worth checking your ulimit values since you may have increased this - I know I have done this previously when coding.  Maybe this is why you could not reproduce the issue locally?

Without setting up a full C++ dev environment I don't know how much code investigation I can provide (I am a Java dev) and I know it is C/C++ code.  But if you can point me to the git source and the class(es) involved in the file counting I can see if I can understand it a but more?

I'll try and set a gdb session up for tonight's run and see if that helps.

Cheers!
Iain
2 years 6 months ago #75522

Please Log in or Create an account to join the conversation.

  • Posts: 19
  • Thank you received: 1
I recently did a full upgrade on AstroBerry so will try this again as I've not had a chance to do much testing since my original post.

One thing to note from memory I had the error in the following two circumstances (1) one target with a lot of images all going into the same folder, and (2) multiple targets with different folders.

I am sure there are some out there asking why take hundreds of images of a target like this, but lucky imaging can be very good for splitting double stars.
The following user(s) said Thank You: Iain Melville
2 years 6 months ago #75523

Please Log in or Create an account to join the conversation.

  • Posts: 33
  • Thank you received: 7
Glad to see you contributing James.  It does seem that large numbers of files can lead to this issue, however that’s still a valid use case in my eyes.  I found another AllSky camera user who had reported the same thing.

Right now I’m looking for an easy way to obtain the ekosdebugger package/application which should help us to diagnose the issue.

I have cloned the source from git but seems there are many dependencies to apt-get before I can build it locally.

If anyone has the repository info where I can apt-get it directly then that would be appreciated.

Many thanks
Iain
 
Last edit: 2 years 6 months ago by Iain Melville. Reason: Typo
2 years 6 months ago #75526

Please Log in or Create an account to join the conversation.

  • Posts: 19
  • Thank you received: 1
Well I tried this evening and couldn't replicate the issue using some test scripts (on KStars version 3.5.4 Stable (Build 2021-07-15T21:15:09Z)).

I tried the following: (1) one target with 1000 images, and (2) 25 targets with 50 images each (for ease they were actually all the same target to be quick).

Thinking out loud the obvious variables which are different from last time (software versions put aside of course!) are (1) I did not load a .esl sequence file, I manually created it then ran it, (2) only one target used, with no focus etc and (3) a single .esq file used for each target.

I will have to wait for some better weather and test in anger as they say.
2 years 6 months ago #75529

Please Log in or Create an account to join the conversation.

  • Posts: 33
  • Thank you received: 7
I thought I had it fixed!

I just now installed/re-installed a load of packages in order to build and run the ekosdebugger, which I have now done. 

See my post here  for what I did.

After launching kstars in ekosdebugger this time, I ran my 'test' again, and got up to 931 files before the crash (a record).

Could my installing dependency packages have stabilised my system?  Perhaps.

While the process was still up but non-responsive, I decided to do some investigating.  I ran:
lsof -p 17864 > ~/Documents/kstars_file_descriptors_on_crash.txt
 

17864 was the pid of kstars.

I'm attaching the output.  There were over 100,000 file descriptors in use at the time of the crash and most of them seem to be labelled as type=STREAM.  I wonder if it's something to do with trying to play an audio file on successful capture of an image and failing while leaving the FD open?

Cheers
Iain
2 years 6 months ago #75535
Attachments:

Please Log in or Create an account to join the conversation.

  • Posts: 7
  • Thank you received: 1
on my example above I ran without alignment so I did not have to worry about platesolve and all that. I did my test with lens cover on and no tracking in parked position and was able to get the problem so is not part of those subsystems (align, focus, track, guide we all "unchecked" in the scheduler, although available in load and running.
2 years 6 months ago #75539

Please Log in or Create an account to join the conversation.

WARNING: Phonon::createPath: Cannot connect  Phonon::MediaObject ( no objectName ) to  Phonon::AudioOutput ( no objectName ).

That actually could be the culprit. Phonon failing to play notification sounds. One option is to go to Settings --> Configuration Notifications --> and then then off ALL sound notifications. Can you replicate the issue afterwards?
The following user(s) said Thank You: Iain Melville, Scott Bushman
2 years 6 months ago #75542

Please Log in or Create an account to join the conversation.

  • Posts: 33
  • Thank you received: 7
Hi Jasem

Indeed, this was the cause of the issue.  By de-configuring all the sound alerts I was able to eliminate the problem.

The number of file handles in use by the kstars process has dropped significantly as a result.  Previously I was seeing >100,000 file handles in use at the point where the issue occurred.  Now I see a steady 331 file handles throughout the capture.

There's a problem with the sound playing function where no audio device is attached which is leaking file descriptors/objects => memory - suggest a ticket for this?

Results of a successful test are attached!  I'm looking forward to not restarting kstars every morning now!

This is after a successful capture of >1000 images - prior to the test, the number was 331.

astroberry@astroberry:/universe/Pictures/AllSky/Zenith/Light $ lsof -p 17482 | wc -l
lsof: WARNING: can't stat() tracefs file system /sys/kernel/debug/tracing
      Output information may be incomplete.
332

Many thanks and if you need any help recreating then I'm happy to provide it.
Iain
2 years 6 months ago #75549
Attachments:

Please Log in or Create an account to join the conversation.

  • Posts: 33
  • Thank you received: 7
Just confirmed a full night's run without the issue.

FIXED.

Thanks and regards
Iain
The following user(s) said Thank You: Scott Bushman
2 years 6 months ago #75588

Please Log in or Create an account to join the conversation.

Time to create page: 1.056 seconds