This is an automated email from the ASF dual-hosted git repository.
ggregory pushed a commit to branch master
in repository https://gitbox.apache.org/repos/asf/commons-daemon.git
The following commit(s) were added to refs/heads/master by this push:
new f0b4524 Arrange the timeout logic and values (#238)
f0b4524 is described below
commit f0b4524ac6981cc6b50d69612ab124c14d2f7d86
Author: Jean-Frederic Clere <jfcl...@gmail.com>
AuthorDate: Thu May 15 16:58:45 2025 +0200
Arrange the timeout logic and values (#238)
Change ONE_MINUTE to ONE_MINUTE_AS_MILLIS and ONE_MINUTE_SEC to
ONE_MINUTE_AS_SEC.
Don't allow to install service with negative StopTimeout value.
Arrange explaination for StopTimeout
Use ERROR and display the already waited time in case StopTimeout is too
small.
---
src/native/windows/apps/prunsrv/prunsrv.c | 191 ++++++++++++++++++++++++------
src/native/windows/src/javajni.c | 4 +-
src/native/windows/src/rprocess.c | 16 +++
src/site/xdoc/procrun.xml | 12 +-
4 files changed, 181 insertions(+), 42 deletions(-)
diff --git a/src/native/windows/apps/prunsrv/prunsrv.c
b/src/native/windows/apps/prunsrv/prunsrv.c
index ce01b88..771b87f 100644
--- a/src/native/windows/apps/prunsrv/prunsrv.c
+++ b/src/native/windows/apps/prunsrv/prunsrv.c
@@ -41,7 +41,8 @@
#define STDIN_FILENO 0
#define STDOUT_FILENO 1
#define STDERR_FILENO 2
-#define ONE_MINUTE (60 * 1000)
+#define ONE_MINUTE_AS_MILLIS (60 * 1000)
+#define ONE_MINUTE_AS_SEC 60
#ifdef _WIN64
#define KREG_WOW6432 KEY_WOW64_32KEY
@@ -258,6 +259,8 @@ static BOOL gSignalValid = TRUE;
static APXJAVA_THREADARGS gRargs;
static APXJAVA_THREADARGS gSargs;
+static DWORD stopCalledTime = 0; /* Not stop not started */
+
DWORD WINAPI eventThread(LPVOID lpParam)
{
DWORD dwRotateCnt = SO_LOGROTATE;
@@ -289,6 +292,21 @@ DWORD WINAPI eventThread(LPVOID lpParam)
UNREFERENCED_PARAMETER(lpParam);
}
+/* Calculate how much time we already spent stopping the service */
+static DWORD waitedSinceStopCmd()
+{
+ DWORD now = 0;
+ DWORD waited = 0;
+ now = GetTickCount();
+ if (now >= stopCalledTime)
+ waited = now - stopCalledTime;
+ else {
+ /* we have wrapped to zero */
+ waited = (0xFFFFFFFF - stopCalledTime) + now;
+ }
+ return waited;
+}
+
/* redirect console stdout/stderr to files
* so that Java messages can get logged
* If stderrfile is not specified it will
@@ -777,6 +795,12 @@ static BOOL docmdInstallService(LPAPXCMDLINE lpCmdline)
apxLogWrite(APXLOG_MARK_ERROR "Unable to open the Service Manager.");
return FALSE;
}
+
+ /* Check the stop timeout value */
+ if (SO_STOPTIMEOUT > 0x7FFFFFFF) {
+ apxLogWrite(APXLOG_MARK_ERROR "StopTimeout can't be lower that 0");
+ return FALSE;
+ }
/* Check the startup mode */
if (ST_STARTUP & APXCMDOPT_FOUND) {
if (lstrcmpiW(SO_STARTUP, PRSRV_AUTO) == 0) {
@@ -940,6 +964,7 @@ static BOOL docmdStopService(LPAPXCMDLINE lpCmdline)
return FALSE;
}
+ stopCalledTime = GetTickCount();
SetLastError(ERROR_SUCCESS);
/* Open the service */
if (apxServiceOpen(hService, lpCmdline->szApplication,
@@ -951,15 +976,34 @@ static BOOL docmdStopService(LPAPXCMDLINE lpCmdline)
NULL);
if (!rv) {
/* Wait for the timeout if any */
- int timeout = SO_STOPTIMEOUT;
- if (timeout) {
- int i;
- for (i = 0; i < timeout; i++) {
- rv = apxServiceCheckStop(hService);
- apxLogWrite(APXLOG_MARK_DEBUG "apxServiceCheck returns
%d.", rv);
- if (rv)
- break;
- }
+ int timeout = SO_STOPTIMEOUT;
+ int waited = waitedSinceStopCmd();
+ int i;
+ if (!timeout) {
+ /* waiting for ever doesn't look OK here */
+ timeout = ONE_MINUTE_AS_SEC;
+ }
+ apxLogWrite(APXLOG_MARK_DEBUG "docmdStopService Waited %d timeout
%d", waited, timeout*1000);
+ if (timeout*1000 > waited) {
+ /*
+ * it took waited to send the command, the service starts
+ * counting the timeout once it receives the STOP command
+ * that is probably after waited but that depends on the
+ * box we are using, we add 1 second just to be sure.
+ */
+ timeout = timeout*1000 + waited + 1000;
+ } else {
+ apxLogWrite(APXLOG_MARK_DEBUG "docmdStopService timeout %d too
small.", timeout*1000);
+ timeout = 1000; /* we might wait 1 s too much but we check if
we have already stopped */
+ }
+ apxLogWrite(APXLOG_MARK_DEBUG "docmdStopService estimated timeout
%d milliseconds.", timeout);
+ /* the SO_STOPTIMEOUT applies to the stop command and to the time
service needs to stop */
+ for (i = 0; i < timeout; i=i+1000) {
+ /* apxServiceCheckStop waits 1000 ms */
+ rv = apxServiceCheckStop(hService);
+ apxLogWrite(APXLOG_MARK_DEBUG "apxServiceCheck returns %d.",
rv);
+ if (rv)
+ break;
}
}
if (rv)
@@ -1223,16 +1267,26 @@ static DWORD WINAPI serviceStop(LPVOID lpParameter)
BOOL wait_to_die = FALSE;
DWORD timeout = SO_STOPTIMEOUT * 1000;
DWORD dwCtrlType = (DWORD)((BYTE *)lpParameter - (BYTE *)0);
+ DWORD waited = 0;
apxLogWrite(APXLOG_MARK_INFO "Stopping service...");
+ stopCalledTime = GetTickCount();
+ if (dwCtrlType == SERVICE_CONTROL_SHUTDOWN)
+ timeout = MIN(timeout, apxGetMaxServiceTimeout(gPool));
+ if (!timeout) {
+ /* Use 1 minute default */
+ timeout = ONE_MINUTE_AS_MILLIS;
+ }
+ apxLogWrite(APXLOG_MARK_INFO "Stopping service...timeout %d", timeout);
+ /* give a hint for shutdown time */
+ reportServiceStatus(SERVICE_STOP_PENDING, NO_ERROR, timeout);
if (IS_INVALID_HANDLE(gWorker)) {
apxLogWrite(APXLOG_MARK_INFO "Worker is not defined.");
return TRUE; /* Nothing to do */
}
- if (timeout > 0x7FFFFFFF)
- timeout = INFINITE; /* If the timeout was '-1' wait forewer */
if (_jni_shutdown) {
+ apxLogWrite(APXLOG_MARK_INFO "Stopping service...timeout %d
_jni_shutdown", timeout);
if (!IS_VALID_STRING(SO_STARTPATH) && IS_VALID_STRING(SO_STOPPATH)) {
/* If the Working path is specified change the current directory
* but only if the start path wasn't specified already.
@@ -1269,16 +1323,14 @@ static DWORD WINAPI serviceStop(LPVOID lpParameter)
}
else {
if (lstrcmpA(_jni_sclass, "java/lang/System") == 0) {
- reportServiceStatus(SERVICE_STOP_PENDING, NO_ERROR, 20 * 1000);
+ /* report progress */
+ reportServiceStatus(SERVICE_STOP_PENDING, NO_ERROR, timeout);
apxLogWrite(APXLOG_MARK_DEBUG "Forcing Java JNI System.exit()
worker to finish...");
return 0;
}
else {
apxLogWrite(APXLOG_MARK_DEBUG "Waiting for Java JNI stop
worker to finish for %s:%s...", _jni_sclass, _jni_smethod);
- if (!timeout)
- apxJavaWait(hWorker, INFINITE, FALSE);
- else
- apxJavaWait(hWorker, timeout, FALSE);
+ apxJavaWait(hWorker, timeout, FALSE);
apxLogWrite(APXLOG_MARK_DEBUG "Java JNI stop worker
finished.");
}
}
@@ -1351,10 +1403,7 @@ static DWORD WINAPI serviceStop(LPVOID lpParameter)
goto cleanup;
} else {
apxLogWrite(APXLOG_MARK_DEBUG "Waiting for stop worker to
finish...");
- if (!timeout)
- apxHandleWait(hWorker, INFINITE, FALSE);
- else
- apxHandleWait(hWorker, timeout, FALSE);
+ apxHandleWait(hWorker, timeout, FALSE);
apxLogWrite(APXLOG_MARK_DEBUG "Stop worker finished.");
}
wait_to_die = TRUE;
@@ -1375,12 +1424,21 @@ cleanup:
CloseHandle(gSignalThread);
gSignalEvent = NULL;
}
- if (wait_to_die && !timeout)
- timeout = 300 * 1000; /* Use the 5 minute default shutdown */
- if (dwCtrlType == SERVICE_CONTROL_SHUTDOWN)
- timeout = MIN(timeout, apxGetMaxServiceTimeout(gPool));
- reportServiceStatus(SERVICE_STOP_PENDING, NO_ERROR, timeout);
+ /* We already waited here timeout is msec */
+ waited = waitedSinceStopCmd();
+ apxLogWrite(APXLOG_MARK_DEBUG "Waited %d timeout (%d)", waited, timeout);
+ if (timeout > waited) {
+ timeout = timeout - waited;
+ /* renew the hint message */
+ reportServiceStatus(SERVICE_STOP_PENDING, NO_ERROR, timeout);
+ } else {
+ /* something is wrong, the timeout is too small */
+ apxLogWrite(APXLOG_MARK_DEBUG "Waiting more than the specified timeout
(%d)", timeout);
+ /* tell we fail */
+ reportServiceStatus(SERVICE_STOP_PENDING,
ERROR_SERVICE_REQUEST_TIMEOUT, 0);
+ }
+
if (timeout) {
FILETIME fts, fte;
@@ -1609,11 +1667,14 @@ void WINAPI service_ctrl_handler(DWORD dwCtrlCode)
case SERVICE_CONTROL_STOP:
apxLogWrite(APXLOG_MARK_INFO "Service SERVICE_CONTROL_STOP
signalled.");
_exe_shutdown = TRUE;
- if (SO_STOPTIMEOUT > 0) {
+ stopCalledTime = GetTickCount();
+ /* hint for shutdown time */
+ if (SO_STOPTIMEOUT) {
reportServiceStatus(SERVICE_STOP_PENDING, NO_ERROR,
SO_STOPTIMEOUT * 1000);
}
else {
- reportServiceStatus(SERVICE_STOP_PENDING, NO_ERROR, 3 * 1000);
+ /* Use 1 minute default */
+ reportServiceStatus(SERVICE_STOP_PENDING, NO_ERROR,
ONE_MINUTE_AS_MILLIS);
}
/* Stop the service asynchronously */
stopThread = CreateThread(NULL, 0,
@@ -1838,9 +1899,13 @@ void WINAPI serviceMain(DWORD argc, LPTSTR *argv)
SetConsoleCtrlHandler((PHANDLER_ROUTINE)console_handler, TRUE);
if (SO_STOPTIMEOUT) {
- /* we have a stop timeout */
+ /* we wait until the service has stopped or crashed, printing a
debug message every 2 seconds */
+ /* we also warn in case the service doesn't stop before the stop
timeout */
BOOL bLoopWarningIssued = FALSE;
+ int waited = 0;
+ int timeout = SO_STOPTIMEOUT;
do {
+ DWORD count = 0;
/* wait 2 seconds */
DWORD rv = apxHandleWait(gWorker, 2000, FALSE);
if (rv == WAIT_OBJECT_0 && !_exe_shutdown) {
@@ -1848,12 +1913,31 @@ void WINAPI serviceMain(DWORD argc, LPTSTR *argv)
apxLogWrite(APXLOG_MARK_WARN "Start method returned
before stop method was called. This should not happen. Using loop with a fixed
sleep of 2 seconds waiting for stop method to be called.");
bLoopWarningIssued = TRUE;
}
+ /* XXXX apart error are we getting there??? */
Sleep(2000);
+ count = count + 2;
+ if (count >= SO_STOPTIMEOUT) {
+ apxLogWrite(APXLOG_MARK_WARN "waited %d sec, Timeout
reached!" , count);
+ break;
+ }
}
+ if (rv == WAIT_OBJECT_0)
+ apxLogWrite(APXLOG_MARK_WARN "Worker has crashed or
stopped!");
+ else
+ apxLogWrite(APXLOG_MARK_DEBUG "waiting until Worker is
done...");
} while (!_exe_shutdown);
- apxLogWrite(APXLOG_MARK_DEBUG "waiting %d sec... shutdown: %d",
SO_STOPTIMEOUT, _exe_shutdown);
- apxHandleWait(gWorker, SO_STOPTIMEOUT*1000, FALSE);
+
+ /* calculate remaing timeout */
+ waited = waitedSinceStopCmd();
+ if (timeout*1000 > waited) {
+ timeout = timeout*1000 - waited;
+ } else {
+ timeout = 1000; /* 1000 ms in the worse case */
+ }
+ apxLogWrite(APXLOG_MARK_DEBUG "waiting %d milliseconds...
shutdown: %d", timeout, _exe_shutdown);
+ apxHandleWait(gWorker, timeout, FALSE);
} else {
+ apxLogWrite(APXLOG_MARK_DEBUG "waiting until Worker is done...");
apxHandleWait(gWorker, INFINITE, FALSE);
}
apxLogWrite(APXLOG_MARK_DEBUG "Worker finished.");
@@ -1863,21 +1947,52 @@ void WINAPI serviceMain(DWORD argc, LPTSTR *argv)
goto cleanup;
}
if (gShutdownEvent) {
+ int waited = waitedSinceStopCmd();
+ int timeout = SO_STOPTIMEOUT;
+ BOOL btimeoutelapsed = FALSE;
/* Ensure that shutdown thread exits before us */
apxLogWrite(APXLOG_MARK_DEBUG "Waiting for ShutdownEvent.");
- reportServiceStatus(SERVICE_STOP_PENDING, NO_ERROR, ONE_MINUTE);
- WaitForSingleObject(gShutdownEvent, ONE_MINUTE);
+ reportServiceStatus(SERVICE_STOP_PENDING, NO_ERROR,
ONE_MINUTE_AS_MILLIS);
+ WaitForSingleObject(gShutdownEvent, ONE_MINUTE_AS_MILLIS);
apxLogWrite(APXLOG_MARK_DEBUG "ShutdownEvent signaled.");
CloseHandle(gShutdownEvent);
gShutdownEvent = NULL;
+ /* calculate the next timeout here timeout is sec */
+ if (!timeout)
+ timeout = ONE_MINUTE_AS_SEC;
+ apxLogWrite(APXLOG_MARK_DEBUG "Waited %d timeout (%d)", waited,
timeout*1000);
+ if (timeout*1000 > waited) {
+ timeout = timeout*1000 - waited;
+ } else {
+ /* something is wrong, the timeout is too small */
+ apxLogWrite(APXLOG_MARK_ERROR "Waiting more than the specified
timeout (%d) already waited for %d", timeout, waited/1000);
+ timeout = ONE_MINUTE_AS_MILLIS;
+ btimeoutelapsed = TRUE;
+ }
+
/* This will cause to wait for all threads to exit
*/
- apxLogWrite(APXLOG_MARK_DEBUG "Waiting 1 minute for all threads to
exit.");
- reportServiceStatus(SERVICE_STOP_PENDING, NO_ERROR, ONE_MINUTE);
- apxDestroyJvm(ONE_MINUTE);
- /* if we are not using JAVA apxDestroyJvm does nothing, check the chid
processes in case they hang */
+ apxLogWrite(APXLOG_MARK_DEBUG "Waiting %d milliseconds for all threads
to exit.", timeout);
+ reportServiceStatus(SERVICE_STOP_PENDING, NO_ERROR,
ONE_MINUTE_AS_MILLIS);
+ if (!apxDestroyJvm(timeout)) {
+ /* if we are not using JAVA apxDestroyJvm does nothing, check the
chid processes in case they hang */
+ apxLogWrite(APXLOG_MARK_DEBUG "apxDestroyJvm did nothing or
failed");
+ for (;;) {
+ if (!apxProcessTerminateChild( GetCurrentProcessId(), TRUE)) {
+ /* Just print the children processes once for debugging */
+ if (btimeoutelapsed)
+ break;
+ waited = waitedSinceStopCmd();
+ if (waited >= timeout)
+ break; /* Done */
+ Sleep(1000);
+ } else {
+ break;
+ }
+ }
+ }
apxProcessTerminateChild( GetCurrentProcessId(), FALSE); /* FALSE
kills! */
}
else {
@@ -1887,7 +2002,7 @@ void WINAPI serviceMain(DWORD argc, LPTSTR *argv)
*/
apxLogWrite(APXLOG_MARK_DEBUG "Waiting for all threads to exit.");
apxDestroyJvm(INFINITE);
- reportServiceStatus(SERVICE_STOP_PENDING, NO_ERROR, 0);
+ reportServiceStatus(SERVICE_STOP_PENDING, NO_ERROR,
ONE_MINUTE_AS_MILLIS);
}
apxLogWrite(APXLOG_MARK_DEBUG "JVM destroyed.");
reportServiceStatusStopped(apxGetVmExitCode());
diff --git a/src/native/windows/src/javajni.c b/src/native/windows/src/javajni.c
index 1aad2e1..e98630e 100644
--- a/src/native/windows/src/javajni.c
+++ b/src/native/windows/src/javajni.c
@@ -486,8 +486,10 @@ apxDestroyJvm(DWORD dwTimeout)
CloseHandle(hWaiter);
return rv;
}
- else
+ else {
+ apxLogWrite(APXLOG_MARK_DEBUG "apxDestroyJvm No JVM so Done");
return FALSE;
+ }
}
static BOOL __apxIsJava9()
diff --git a/src/native/windows/src/rprocess.c
b/src/native/windows/src/rprocess.c
index 46ca36f..3e23883 100644
--- a/src/native/windows/src/rprocess.c
+++ b/src/native/windows/src/rprocess.c
@@ -408,6 +408,22 @@ BOOL apxProcessTerminateChild(DWORD dwProcessId, BOOL
dryrun)
apxLogWrite(APXLOG_MARK_DEBUG "Process ID: 0x%08X (%d)
Termination failed!", treeProcessId[i], treeProcessId[i]);
}
}
+ } else {
+ /* Check if we have child processes and return FALSE if not */
+ HANDLE hProcess;
+ for (i=0; i<maxProcessId; i++) {
+ if (treeProcessId[i] == 0) {
+ break; /* Done */
+ }
+ hProcess = OpenProcess(PROCESS_ALL_ACCESS, FALSE, treeProcessId[i]);
+ if(hProcess != NULL) {
+ apxLogWrite(APXLOG_MARK_DEBUG "Process ID: 0x%08X (%d) Still
here!", treeProcessId[i], treeProcessId[i]);
+ CloseHandle(hProcess);
+ CloseHandle(hProcessSnap);
+ return(FALSE);
+ }
+ }
+
}
CloseHandle(hProcessSnap);
diff --git a/src/site/xdoc/procrun.xml b/src/site/xdoc/procrun.xml
index 13213d1..f42a6a0 100644
--- a/src/site/xdoc/procrun.xml
+++ b/src/site/xdoc/procrun.xml
@@ -530,9 +530,15 @@ will add the new value(s) to any existing value(s).
</tr>
<tr>
<td>--StopTimeout</td>
- <td>No Timeout</td>
- <td>Defines the timeout in seconds that procrun waits for service to
- exit gracefully.</td>
+ <td>60 seconds</td>
+ <td>Defines the timeout in seconds that procrun waits for service
+ to stop.
+ <b>The timeout applies to the stop command and to the time service
needs to stop</b>
+ Negative values are not allowed.
+ Note: Make sure you use a value big enough to give time for
+ procrun to stop the service. Once the time out is elapsed,
+ procrun will try to kill the whole process tree the service
+ has created.</td>
</tr>
<tr>
<td>--LogPath</td>
