Bug 48 - Windows service not stopped properly on system shutdown or restart
Summary: Windows service not stopped properly on system shutdown or restart
Status: IN_PROGRESS
Alias: None
Product: Orthanc
Classification: Unclassified
Component: Orthanc Core (show other bugs)
Version: unspecified
Hardware: All All
: --- normal
Assignee: Sébastien Jodogne
URL:
Depends on:
Blocks:
 
Reported: 2020-06-29 15:12 CEST by Sébastien Jodogne
Modified: 2021-01-19 11:39 CET (History)
1 user (show)

See Also:


Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description Sébastien Jodogne 2020-06-29 15:12:27 CEST
[BitBucket user: Alain Mazy]
[BitBucket date: 2017-05-19.15:25:31]

Configuration:
-------------
- Windows 10 64-bit, running on VMware virtual machine
- Orthanc 1.2.0, from OrthancInstaller-Win64-1.2.0.2546.exe, using the default config file(s)

How to reproduce:
----------------
When shutting down or restarting the system, the log file shows the "Orthanc is stopping" message, but does not reach the "Orthanc has stopped".

```
W0519 16:26:05.936933 main.cpp:702] Orthanc is stopping
W0519 16:26:06.015061 main.cpp:762]     HTTP server has stopped
W0519 16:26:06.391246 main.cpp:838]     DICOM server has stopped
```
For comparison, when manually restarting the service from the Windows Services panel, the log file output is:
```
W0519 16:47:23.673209 main.cpp:702] Orthanc is stopping
W0519 16:47:23.799281 main.cpp:762]     HTTP server has stopped
W0519 16:47:23.908824 main.cpp:838]     DICOM server has stopped
W0519 16:47:25.019654 PluginsManager.cpp:218] Unregistering plugin 'dicom-web' (version 0.3)
W0519 16:47:25.019654 PluginsManager.cpp:218] Unregistering plugin 'osimis-web-viewer' (version 0.5.4.0-aaa3eeb)
W0519 16:47:25.019654 PluginsManager.cpp:167] Finalizing the Web viewer
W0519 16:47:25.034970 PluginsManager.cpp:218] Unregistering plugin 'postgresql-index' (version 2.0)
W0519 16:47:25.034970 PluginsManager.cpp:167] PostgreSQL index is finalizing
W0519 16:47:25.034970 PluginsManager.cpp:218] Unregistering plugin 'postgresql-storage' (version 2.0)
W0519 16:47:25.034970 PluginsManager.cpp:167] Storage plugin is finalizing
W0519 16:47:25.034970 PluginsManager.cpp:218] Unregistering plugin 'serve-folders' (version 1.2.0)
W0519 16:47:25.034970 PluginsManager.cpp:218] Unregistering plugin 'web-viewer' (version 2.2)
W0519 16:47:25.034970 PluginsManager.cpp:167] Finalizing the Web viewer
W0519 16:47:25.975463 PluginsManager.cpp:218] Unregistering plugin 'worklists' (version 1.2.0)
W0519 16:47:25.975463 PluginsManager.cpp:167] Sample worklist plugin is finalizing
W0519 16:47:25.975463 PluginsManager.cpp:218] Unregistering plugin 'wsi' (version 0.3)
W0519 16:47:25.975463 main.cpp:1297] Orthanc has stopped
```

Additional information:
----------------------
When using the MSSQL index plugin to access a (local or remote) MSSQL database, the same scenario results in a 'database locked' error after restart.

This could, however, also result from the plugin losing access to the database because of the order of shutdown operations.

As a workaround, adding "Lock": false in the plugin configuration solves the 'database locked' error, but not the interrupted service stop issue.

Another workaround has been implemented in the Windows Service to launch Orthanc with --unlock option.

We have tried to increase the registry key HKEY_LOCAL_MACHINE\SYSTEM\CurrentControlSet\Control\WaitToKillServiceTimeout to 50000ms but this did not help. (http://stackoverflow.com/questions/13454054/what-is-the-maximum-time-windows-service-wait-to-process-stop-request-and-how-to)
Comment 1 Sébastien Jodogne 2020-06-29 15:19:54 CEST
[BitBucket user: Alain Mazy]
[BitBucket date: 2017-05-19.15:54:47]

To evaluate:  The Orthanc service launches Orthanc as a separate process.  It's very likely that this process is killed by the shutdown since Windows does not realize that it's related to a service.

=> we should check if there is a flag that could prevent windows from killing this process.
Comment 2 Sébastien Jodogne 2020-06-29 15:19:56 CEST
[BitBucket user: Alain Mazy]
[BitBucket date: 2017-05-20.10:06:25]

An executable can delay Windows shutdown by performing its cleanup while handling the WM_QUERYENDSESSION windows message (https://msdn.microsoft.com/en-us/library/windows/desktop/aa376890(v=vs.85).aspx).  In our case, Orthanc.exe would have to handle this message correctly.

2 solutions to solve this issue:
- Orthanc.exe handles the WM_QUERYENDSESSION message -> we must implement windows message handling in Orthanc.exe
- Orthanc is included as a DLL inside the Orthanc Service and it will be shutdown correctly.

First solution is cleaner since that would also make sure shutdowns are handled correctly for Orthanc processes that are not started by a service.
Comment 3 Sébastien Jodogne 2020-06-29 15:19:57 CEST
[BitBucket user: Sébastien Jodogne]
[BitBucket date: 2017-05-20.10:11:08]

Handling WM_QUERYENDSESSION is clearly the way to go.
Comment 4 Benjamin Golinvaux 2021-01-19 09:55:51 CET
The following changes have been brought in CL 8ab6399, 5c1695c, 2403546 and be26d8a of the orthanc-builder repository:

- When the service process launches the Orthanc The CREATE_NEW_PROCESS_GROUP is not used anymore. This should prevent a Windows shutdown process to kill Orthanc (only top-level processes are killed)

- SIGINT is only sent to the child process when stopping the service, not when shutting down Windows, since the OS, in the latter case, sends a SIGINT automatically. This prevents the second extraneous signal from being sent.

- The service process itself does not allocate a permanent console. This is cleaner since services should not be attached a console. A console is only temporarily attached when required (i.e. to send the SIGINT signal to Orthanc.exe)

- Instead of an idle waiting period while the service is stopping, the service now properly reports the pending stop operation progress to the Service Control Manager, requesting extra shutdown time until properly stopped.

- The installer process, at uninstall time, now propertly waits for the Orthanc service to stop. This prevents stray files from being left in the install folders (although some files, such as the potentially user-customized configuration files amd the logs are not removed by the installer...)

These fixes greatly improve the situation. Currently, the OS still forcefully kills Orthanc after a few seconds when shutting down an HyperV guest VM running Windows 10 1909). In most scenarios, there should be enough time for Orthanc to properly stop.

This is being investigated.
Comment 5 Benjamin Golinvaux 2021-01-19 11:11:04 CET
After some tests where physical installations of Windows 10 behave in the same way (i.e. forcefully killing Orthanc after 5 seconds) and more research, the conclusion is the following :

"Windows normally waits 5 seconds for background services to clean up and close when you tell your computer to shut down."

This delay can be customized through the WaitToKillServiceTimeout registry value.

"Some applications may change this value when you install them, giving their background services extra time to clean up."

(Note: Orthanc does NOT modify this value, neither at installation time or at runtime!)

If you notice that Orthanc (or any service, for that matter) is forcefully killed before being properly shut down (you can check this by performing a shutdown and checking whether the last log line "Orthanc is stopped" can be found in the log after restart), you can change this delay by modifying the 

WaitToKillServiceTimeout value in the HKEY_LOCAL_MACHINE\SYSTEM\CurrentControlSet\Control registry key.

The values are expressed in milliseconds.

"Double-click the WaitToKillServiceTimeout value and enter a number of milliseconds. The default is 5000 milliseconds, or 5 seconds. To set it to 20 seconds, you’d enter “20000”."


Info has been taken here: https://www.howtogeek.com/282062/control-how-long-windows-waits-before-killing-apps-at-shutdown/