1. Stefan B Avatar Stefan B
  2. nina
  3. NINA
  4. Issues

Windows Reboot During Imaging

Issue #1127 resolved
Bill Richards created an issue

I don’t know what caused this, but last night in the middle of an imaging session my laptop appears to have rebooted for no apparent reason. It may be a Windows issue, it may have been NINA, or perhaps something else. My hope is that someone can look at the tail end of the NINA log file (pasted below) and tell me if there are any clues there. Obviously, this is very troubling because I have to have confidence that an imagin session will run reliably all night.

‌

2022-06-26T02:21:39.5081|INFO|PHD2Guider.cs|StartGuidingPrivate|464|Phd2 - App is already guiding. Skipping start guiding
2022-06-26T02:21:39.5081|INFO|SequenceItem.cs|Run|224|Finishing Category: Guider, Item: StartGuiding
2022-06-26T02:21:39.5081|INFO|SequenceItem.cs|Run|224|Finishing Category: * Instruction Set *, Item: NINA.Sequencer.Container.SequentialContainer, Strategy: SequentialStrategy, Items: 1, Conditions: Triggers:
2022-06-26T02:21:39.5091|INFO|SequenceItem.cs|Run|206|Starting Category: Camera, Item: TakeExposure, ExposureTime 180, Gain 100, Offset 50, ImageType LIGHT, Binning 1x1
2022-06-26T02:21:39.5137|INFO|CameraVM.cs|Capture|729|Starting Exposure - Exposure Time: 180s; Filter: ; Gain: 100; Offset 50; Binning: 1x1;
2022-06-26T02:24:40.4400|DEBUG|ImageSaveController.cs|Enqueue|51|Enqueuing image to be saved with id 142
2022-06-26T02:24:40.4400|DEBUG|ImageSaveController.cs|DoWork|60|Dequeuing image to be saved with id 142
2022-06-26T02:24:40.4769|DEBUG|ImageUtility.cs|Debayer|238|Debayering pattern RGGB
2022-06-26T02:24:40.5487|INFO|SequenceItem.cs|Run|224|Finishing Category: Camera, Item: TakeExposure, ExposureTime 180, Gain 100, Offset 50, ImageType LIGHT, Binning 1x1
2022-06-26T02:24:40.5510|DEBUG|AutofocusAfterHFRIncreaseTrigger.cs|ShouldTrigger|214|Autofocus condition extrapolated original HFR: 3.07562481496283 extrapolated current HFR: 3.18806355221416
2022-06-26T02:24:40.5517|INFO|MeridianFlipTrigger.cs|ShouldTrigger|207|Meridian Flip - Flip for the current target already happened at 6/26/2022 12:49:30 AM. Skip flip evaluation
2022-06-26T02:24:40.5517|INFO|SequenceTrigger.cs|Run|111|Starting Trigger: RestoreGuiding
2022-06-26T02:24:40.5517|INFO|SequenceItem.cs|Run|206|Starting Category: * Instruction Set *, Item: NINA.Sequencer.Container.SequentialContainer, Strategy: SequentialStrategy, Items: 1, Conditions: Triggers:
2022-06-26T02:24:40.5517|INFO|SequenceItem.cs|Run|206|Starting Category: Guider, Item: StartGuiding
2022-06-26T02:24:40.5517|DEBUG|PHD2Guider.cs|SendMessage|753|Phd2 - Sending message '{"id":"99","method":"get_app_state"}'
2022-06-26T02:24:40.5617|DEBUG|PHD2Guider.cs|SendMessage|773|Phd2 - Received message answer '{"jsonrpc":"2.0","result":"Guiding","id":"99"}'
2022-06-26T02:24:40.5617|INFO|PHD2Guider.cs|StartGuidingPrivate|464|Phd2 - App is already guiding. Skipping start guiding
2022-06-26T02:24:40.5617|INFO|SequenceItem.cs|Run|224|Finishing Category: Guider, Item: StartGuiding
2022-06-26T02:24:40.5617|INFO|SequenceItem.cs|Run|224|Finishing Category: * Instruction Set *, Item: NINA.Sequencer.Container.SequentialContainer, Strategy: SequentialStrategy, Items: 1, Conditions: Triggers:
2022-06-26T02:24:40.5617|INFO|SequenceItem.cs|Run|206|Starting Category: Camera, Item: TakeExposure, ExposureTime 180, Gain 100, Offset 50, ImageType LIGHT, Binning 1x1
2022-06-26T02:24:40.5676|INFO|CameraVM.cs|Capture|729|Starting Exposure - Exposure Time: 180s; Filter: ; Gain: 100; Offset 50; Binning: 1x1;
2022-06-26T02:24:40.7295|DEBUG|BaseImageData.cs|PrepareSave|110|Saved temporary image at C:\Users\BillR\Pictures\NINA\65137096-f6b7-49de-a179-7c9dd2635c44.fits
2022-06-26T02:24:43.2948|INFO|StarDetection.cs|Detect|246|Average HFR: 3.21331872163762, HFR σ: 1.1552987036819, Detected Stars 1059, Sensitivity Normal, ResizeFactor: 0.25
2022-06-26T02:24:43.4962|INFO|BaseImageData.cs|FinalizeSave|153|Saving image at C:\Users\BillR\Pictures\NINA\M 16\LIGHT\180.00s\2022-06-26_02-21-39_180.00s_-9.60C.fits
2022-06-26T02:26:03.0262|DEBUG|ApplicationVM.cs|ClosingApplication|180|Releasing profile
2022-06-26T02:26:03.0282|DEBUG|ApplicationVM.cs|ClosingApplication|184|Saving user.settings
2022-06-26T02:26:03.0581|DEBUG|ApplicationVM.cs|ClosingApplication|189|Shutting down ImageSaveMediator
2022-06-26T02:26:03.0691|DEBUG|ApplicationVM.cs|ClosingApplication|197|Tearing down plugin Hocus Focus

‌

‌

Comments (15)

  1. Marc Blank

    The log shows NINA shutting itself down as if the session was done. Definitely not in the middle of a session from NINAs point of view.

    A crash wouldn’t show up in a NINA log but rather in the Windows event log.

  2. Bill Richards reporter

    Thanks, Marc. But NINA was definitely not done with the session. It was supposed to run for another 20 minutes, then slew to a 2nd target and take another 90 minutes of exposures. So what caused it to shut down early?

    Also, how do I find the Windows Event Log?

  3. Dale Ghent

    The Windows Event Viewer would log the reboot and possibly the reason. Just search for Event Viewer in Windows and you’ll find it. It’s a bult-in Windows administrative app(let).

  4. Bill Richards reporter

    Yeah - I found it, but I’m now qualified to interpret it. I don’t see anything indicating a reboot occurred, but I had 7 apps running (iOptron Commander, iPolar, Stellarium, NINA, PHD2, Adobe Acrobat, and Windows File Explorer) and for some inexpliable reason they all shut down at 02:26.

    Is there some place I can upload the Window Event Log incase someone else knows how to interpret it better than I?

  5. Dale Ghent

    Since knowing the cause of a mysterious/unexpected reboot or shutdown in Windows is generally a good skill to have, it’s advisable to learn how to get to that. Here’s a good step-through for how to sift that info out of the Event Viewer.

    https://stackoverflow.com/a/24206626

  6. Bill Richards reporter

    Not sure if this helps, but the PHD2 Debug Log shows a discontinuity starting at 02:26:05 but no shutdown info - just a restart at 02:46:30 when I noticed the problem.

    02:26:04.911 00.000 13288 move complete, result=0
    02:26:04.911 00.000 13288 worker thread done servicing request
    02:26:04.911 00.000 13288 Worker thread wakes up
    02:26:04.911 00.000 13288 worker thread servicing REQUEST_EXPOSE 2500
    02:26:04.911 00.000 13288 Handling exposure in thread, d=2500 o=3 r=(717,904,31,31)
    02:26:05.072 00.161 5436 GuideStep: -0.4 px 22 ms EAST, -0.1 px 0 ms NORTH
    02:46:30.839 00.004 4352 PHD2 version 2.6.11 begins execution with:
    02:46:30.839 00.000 4352 Windows 10 (build 19044), 64-bit edition
    02:46:30.839 00.000 4352 wxWidgets 3.0.5
    02:46:30.839 00.000 4352 cfitsio 3.47

  7. Bill Richards reporter

    Hi Dale,

    Thanks for replying. I looked over the Stackoverflow instructions and followed them, but it shows the last unexpected shutdown was on 2/1/2022; none last night. So it remains a mystery as to what caused all 7 apps to close down for no apparent reason.

  8. Bill Richards reporter

    Aha! In whte Windows log at 02:26:05, there was the following Information entry:

    “Application popup: NINA.exe - Application Error : The exception unknown software exception (0xc0020001) occurred in the application at location 0x00007FF8CA214FD9.

    Click on OK to terminate the program”

    That’s precisely when all the apps closed. What does this mean?

  9. Stefan B repo owner

    Looking at the timestamp it is 2 seconds after the nina logs indicate that the nina application is going to shut down. So i guess the application just ran into an error while shutting down, but what caused this shutdown is still unclear

  10. Bill Richards reporter

    Well, something bad happened that caused NINA to crash and kill my imaging session. Is there nothing in either log that would shed any light on what it was? This is very troubling to me for obvious reasons - I need to have confidence that an imaging session will run reliably when I’m not watching over it.

  11. Stefan B repo owner

    Have you checked the event viewer if a logoff event occurred?
    EventViewer → Windows Logs → Security → Go to the right side and click on “Filter Current Log” → replace “<all event ids>” with “4647” and you will see all logout events

    The same can be done in the Application tab and entering multiple id codes to see all events e.g. “41,1074,1076,6005,6006,6008”

  12. Bill Richards reporter

    According to the Windows Event log, there was a “user initiated logoff” at 02:26:11AM. But what does that mean? I was asleep and nowhere near the laptop at that time. What could cause a “user initiated logoff” when there is no one at the computer?

    When I entered all the codes you listed in the Application tab filter, it came up empty.

  13. Bill Richards reporter

    I’m closing this issue as it is more likely to be a Windows issue, albeit unexplained.

  16. Log in to comment
Assignee
–
Type
bug
Priority
major
Status
resolved
Component
General
Version
–
Votes
0
Watchers
1
Jira: the preferred issue tracker for Bitbucket. Join the team!