Author: ggregory
Date: Sat Jul 8 01:49:43 2017
New Revision: 1801253
URL: http://svn.apache.org/viewvc?rev=1801253&view=rev
Log:
[DAEMON-368] Add DEBUG and ERROR logging to help diagnose problems when
starting a Windows Service.
Modified:
commons/proper/daemon/trunk/src/changes/changes.xml
commons/proper/daemon/trunk/src/native/windows/apps/prunsrv/prunsrv.c
commons/proper/daemon/trunk/src/native/windows/src/javajni.c
commons/proper/daemon/trunk/src/native/windows/src/rprocess.c
commons/proper/daemon/trunk/src/native/windows/src/service.c
Modified: commons/proper/daemon/trunk/src/changes/changes.xml
URL:
http://svn.apache.org/viewvc/commons/proper/daemon/trunk/src/changes/changes.xml?rev=1801253&r1=1801252&r2=1801253&view=diff
==============================================================================
--- commons/proper/daemon/trunk/src/changes/changes.xml (original)
+++ commons/proper/daemon/trunk/src/changes/changes.xml Sat Jul 8 01:49:43 2017
@@ -39,6 +39,9 @@
</properties>
<body>
<release version="1.1.0" date="2017-MM-DD" description="Feature and bug
fix release">
+ <action issue="DAEMON-368" type="update" dev="ggregory" type="add">
+ Add DEBUG and ERROR logging to help diagnose problems when starting a
Windows Service.
+ </action>
<action type="update" dev="markt">
Increase minimum Java version to Java 5.
</action>
Modified: commons/proper/daemon/trunk/src/native/windows/apps/prunsrv/prunsrv.c
URL:
http://svn.apache.org/viewvc/commons/proper/daemon/trunk/src/native/windows/apps/prunsrv/prunsrv.c?rev=1801253&r1=1801252&r2=1801253&view=diff
==============================================================================
--- commons/proper/daemon/trunk/src/native/windows/apps/prunsrv/prunsrv.c
(original)
+++ commons/proper/daemon/trunk/src/native/windows/apps/prunsrv/prunsrv.c Sat
Jul 8 01:49:43 2017
@@ -740,18 +740,18 @@ static BOOL docmdStartService(LPAPXCMDLI
NULL,
NULL);
if (rv)
- apxLogWrite(APXLOG_MARK_INFO "Service '%S' started",
+ apxLogWrite(APXLOG_MARK_INFO "Started service '%S'",
lpCmdline->szApplication);
else
- apxLogWrite(APXLOG_MARK_ERROR "Failed to start '%S' service",
+ apxLogWrite(APXLOG_MARK_ERROR "Failed to start service '%S'",
lpCmdline->szApplication);
}
else
- apxDisplayError(FALSE, NULL, 0, "Unable to open '%S' service",
+ apxDisplayError(FALSE, NULL, 0, "Unable to open service '%S'",
lpCmdline->szApplication);
apxCloseHandle(hService);
- apxLogWrite(APXLOG_MARK_INFO "Start service finished.");
+ apxLogWrite(APXLOG_MARK_INFO "Start service finished, returning %d", rv);
return rv;
}
@@ -841,7 +841,7 @@ static BOOL reportServiceStatusE(DWORD d
static DWORD dwCheckPoint = 1;
BOOL fResult = TRUE;
- apxLogWrite(APXLOG_MARK_DEBUG "reportServiceStatusE: %d, %d, %d, %d",
+ apxLogWrite(APXLOG_MARK_DEBUG "reportServiceStatusE: dwCurrentState = %d,
dwWin32ExitCode = %d, dwWaitHint = %d, dwServiceSpecificExitCode = %d",
dwCurrentState, dwWin32ExitCode, dwWaitHint,
dwServiceSpecificExitCode);
if (_service_mode && _service_status_handle) {
@@ -977,19 +977,19 @@ static DWORD WINAPI serviceStop(LPVOID l
/* Create shutdown event */
gShutdownEvent = CreateEvent(NULL, TRUE, FALSE, NULL);
if (!apxJavaStart(&gSargs)) {
- apxLogWrite(APXLOG_MARK_ERROR "Failed starting java");
+ apxLogWrite(APXLOG_MARK_ERROR "Failed starting Java");
rv = 3;
}
else {
if (lstrcmpA(_jni_sclass, "java/lang/System") == 0) {
reportServiceStatus(SERVICE_STOP_PENDING, NO_ERROR, 20 * 1000);
- apxLogWrite(APXLOG_MARK_DEBUG "Forcing java jni System.exit
worker to finish...");
+ 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...");
+ apxLogWrite(APXLOG_MARK_DEBUG "Waiting for java JNI stop
worker to finish...");
apxJavaWait(hWorker, INFINITE, FALSE);
- apxLogWrite(APXLOG_MARK_DEBUG "Java jni stop worker
finished.");
+ apxLogWrite(APXLOG_MARK_DEBUG "Java JNI stop worker
finished.");
}
}
wait_to_die = TRUE;
Modified: commons/proper/daemon/trunk/src/native/windows/src/javajni.c
URL:
http://svn.apache.org/viewvc/commons/proper/daemon/trunk/src/native/windows/src/javajni.c?rev=1801253&r1=1801252&r2=1801253&view=diff
==============================================================================
--- commons/proper/daemon/trunk/src/native/windows/src/javajni.c (original)
+++ commons/proper/daemon/trunk/src/native/windows/src/javajni.c Sat Jul 8
01:49:43 2017
@@ -961,7 +961,7 @@ static DWORD WINAPI __apxJavaWorkerThrea
finished:
if (lpJava) {
lpJava->dwWorkerStatus = 0;
- apxLogWrite(APXLOG_MARK_DEBUG "Java Worker thread finished %s:%s with
status=%d",
+ apxLogWrite(APXLOG_MARK_DEBUG "Java Worker thread finished %s:%s with
status = %d",
lpJava->clWorker.sClazz, lpJava->clWorker.sMethod, rv);
SetEvent(lpJava->hWorkerInit);
}
Modified: commons/proper/daemon/trunk/src/native/windows/src/rprocess.c
URL:
http://svn.apache.org/viewvc/commons/proper/daemon/trunk/src/native/windows/src/rprocess.c?rev=1801253&r1=1801252&r2=1801253&view=diff
==============================================================================
--- commons/proper/daemon/trunk/src/native/windows/src/rprocess.c (original)
+++ commons/proper/daemon/trunk/src/native/windows/src/rprocess.c Sat Jul 8
01:49:43 2017
@@ -262,7 +262,9 @@ static DWORD __apxProcessWrite(LPAPXPROC
/** Helper functions */
static BOOL __apxProcCreateChildPipes(LPAPXPROCESS lpProc)
{
- BOOL rv = FALSE;
+ apxLogWrite(APXLOG_MARK_DEBUG "Commons Daemon procrun
__apxProcCreateChildPipes()");
+
+ BOOL rv = FALSE;
if (!CreatePipe(&(lpProc->hChildStdInp),
&(lpProc->hChildInpWr),
@@ -568,19 +570,24 @@ apxProcessExecute(APXHANDLE hProcess)
DWORD id;
BOOL bS = FALSE;
- if (hProcess->dwType != APXHANDLE_TYPE_PROCESS)
- return FALSE;
+ apxLogWrite(APXLOG_MARK_DEBUG "Apache Commons Daemon
apxProcessExecute()");
+ if (hProcess->dwType != APXHANDLE_TYPE_PROCESS) {
+
+ return FALSE;
+ }
lpProc = APXHANDLE_DATA(hProcess);
/* don't allow multiple execute calls on the same object */
- if (lpProc->dwChildStatus & PROC_INITIALIZED)
- return FALSE;
+ if (lpProc->dwChildStatus & PROC_INITIALIZED) {
+ return FALSE;
+ }
lpProc->bSaveHandles = TRUE;
SAVE_STD_HANDLES(lpProc);
if (!__apxProcCreateChildPipes(lpProc))
goto cleanup;
REDIRECT_STD_HANDLES(lpProc);
- AplZeroMemory(&si, sizeof(STARTUPINFO));
+ apxLogWrite(APXLOG_MARK_DEBUG "Apache Commons Daemon AplZeroMemory()");
+ AplZeroMemory(&si, sizeof(STARTUPINFO));
si.cb = sizeof(STARTUPINFO);
si.dwFlags = STARTF_USESTDHANDLES | STARTF_USESHOWWINDOW;
@@ -590,13 +597,17 @@ apxProcessExecute(APXHANDLE hProcess)
si.hStdError = lpProc->hChildStdErr;
si.hStdInput = lpProc->hChildStdInp;
- if (lpProc->lpEnvironment)
- FreeEnvironmentStringsW(lpProc->lpEnvironment);
- lpProc->lpEnvironment = GetEnvironmentStringsW();
+ if (lpProc->lpEnvironment) {
+ apxLogWrite(APXLOG_MARK_DEBUG "Apache Commons Daemon
FreeEnvironmentStringsW()");
+ FreeEnvironmentStringsW(lpProc->lpEnvironment);
+ }
+ apxLogWrite(APXLOG_MARK_DEBUG "Apache Commons Daemon
GetEnvironmentStringsW()");
+ lpProc->lpEnvironment = GetEnvironmentStringsW();
if (!IS_INVALID_HANDLE(lpProc->hUserToken)) {
si.lpDesktop = _desktop_name;
- bS = CreateProcessAsUserW(lpProc->hUserToken,
+ apxLogWrite(APXLOG_MARK_DEBUG "Apache Commons Daemon
CreateProcessAsUserW()");
+ bS = CreateProcessAsUserW(lpProc->hUserToken,
lpProc->szApplicationExec,
lpProc->szCommandLine,
lpProc->lpSA,
@@ -612,7 +623,8 @@ apxProcessExecute(APXHANDLE hProcess)
OutputDebugStringW(lpProc->szApplicationExec);
OutputDebugStringW(lpProc->szCommandLine);
- bS = CreateProcessW(lpProc->szApplicationExec,
+ apxLogWrite(APXLOG_MARK_DEBUG "Apache Commons Daemon
CreateProcessW()");
+ bS = CreateProcessW(lpProc->szApplicationExec,
lpProc->szCommandLine,
lpProc->lpSA,
NULL,
@@ -627,29 +639,36 @@ apxProcessExecute(APXHANDLE hProcess)
SAFE_CLOSE_HANDLE(lpProc->hChildStdInp);
SAFE_CLOSE_HANDLE(lpProc->hChildStdOut);
SAFE_CLOSE_HANDLE(lpProc->hChildStdErr);
- if (!bS)
- goto cleanup;
+ if (!bS) {
+ goto cleanup;
+ }
/* Set the running flag */
lpProc->dwChildStatus |= (CHILD_RUNNING | PROC_INITIALIZED);
- lpProc->hWorkerThreads[0] = CreateThread(NULL, 0, __apxProcStdoutThread,
+ apxLogWrite(APXLOG_MARK_DEBUG "Apache Commons Daemon CreateThread()");
+ lpProc->hWorkerThreads[0] = CreateThread(NULL, 0, __apxProcStdoutThread,
hProcess, 0, &id);
- lpProc->hWorkerThreads[1] = CreateThread(NULL, 0, __apxProcStderrThread,
+ apxLogWrite(APXLOG_MARK_DEBUG "Apache Commons Daemon CreateThread()");
+ lpProc->hWorkerThreads[1] = CreateThread(NULL, 0, __apxProcStderrThread,
hProcess, 0, &id);
- ResumeThread(lpProc->stProcInfo.hThread);
- lpProc->hWorkerThreads[2] = CreateThread(NULL, 0, __apxProcWorkerThread,
+ apxLogWrite(APXLOG_MARK_DEBUG "Apache Commons Daemon ResumeThread()");
+ ResumeThread(lpProc->stProcInfo.hThread);
+ apxLogWrite(APXLOG_MARK_DEBUG "Apache Commons Daemon CreateThread()");
+ lpProc->hWorkerThreads[2] = CreateThread(NULL, 0, __apxProcWorkerThread,
hProcess, 0, &id);
SAFE_CLOSE_HANDLE(lpProc->stProcInfo.hThread);
/* Close child handles first */
- return TRUE;
+ apxLogWrite(APXLOG_MARK_DEBUG "Apache Commons Daemon
apxProcessExecute() returning TRUE");
+ return TRUE;
cleanup:
- /* Close parent side of the pipes */
+ /* Close parent side of the pipes */
SAFE_CLOSE_HANDLE(lpProc->hChildInpWr);
SAFE_CLOSE_HANDLE(lpProc->hChildOutRd);
SAFE_CLOSE_HANDLE(lpProc->hChildErrRd);
- return FALSE;
+ apxLogWrite(APXLOG_MARK_DEBUG "Apache Commons Daemon
apxProcessExecute() returning FALSE");
+ return FALSE;
}
BOOL
Modified: commons/proper/daemon/trunk/src/native/windows/src/service.c
URL:
http://svn.apache.org/viewvc/commons/proper/daemon/trunk/src/native/windows/src/service.c?rev=1801253&r1=1801252&r2=1801253&view=diff
==============================================================================
--- commons/proper/daemon/trunk/src/native/windows/src/service.c (original)
+++ commons/proper/daemon/trunk/src/native/windows/src/service.c Sat Jul 8
01:49:43 2017
@@ -378,11 +378,15 @@ apxServiceControl(APXHANDLE hService, DW
lpService = APXHANDLE_DATA(hService);
/* Manager mode cannot handle services */
- if (lpService->bManagerMode)
- return FALSE;
+ if (lpService->bManagerMode) {
+ apxLogWrite(APXLOG_MARK_ERROR "apxServiceControl(): Manager
mode cannot handle services, returning FALSE");
+ return FALSE;
+ }
/* Check if the ServiceOpen has been called */
- if (IS_INVALID_HANDLE(lpService->hService))
- return FALSE;
+ if (IS_INVALID_HANDLE(lpService->hService)) {
+ apxLogWrite(APXLOG_MARK_ERROR "apxServiceControl(): Service is
not open, returning FALSE");
+ return FALSE;
+ }
switch (dwControl) {
case SERVICE_CONTROL_CONTINUE:
dwPending = SERVICE_START_PENDING;
@@ -425,11 +429,17 @@ apxServiceControl(APXHANDLE hService, DW
break;
}
}
- if (!dwPending && !dwState)
- return FALSE;
+ if (!dwPending && !dwState) {
+ apxLogWrite(APXLOG_MARK_ERROR
+ "apxServiceControl(): !dwPending(%d) && !dwState(%d);
returning FALSE",
+ dwPending,
+ dwState);
+ return FALSE;
+ }
/* Now lets control */
if (!QueryServiceStatus(lpService->hService, &stStatus)) {
- apxLogWrite(APXLOG_MARK_SYSERR);
+ apxLogWrite(APXLOG_MARK_ERROR "apxServiceControl():
QueryServiceStatus failure, returning FALSE");
+ apxLogWrite(APXLOG_MARK_SYSERR);
return FALSE;
}
/* signal that we are about to control the service */
@@ -493,18 +503,36 @@ apxServiceControl(APXHANDLE hService, DW
if (fnControlCallback)
(*fnControlCallback)(lpCbData, uMsg, (WPARAM)3, (LPARAM)0);
/* Check if we are in the desired state */
- Sleep(1000);
+ DWORD sleepMillis = 1000;
+ apxLogWrite(APXLOG_MARK_DEBUG "apxServiceControl(): Sleeping %d
milliseconds", sleepMillis);
+ Sleep(sleepMillis);
if (QueryServiceStatus(lpService->hService, &stStatus)) {
- if (fnControlCallback)
- (*fnControlCallback)(lpCbData, uMsg, (WPARAM)4,
- (LPARAM)&stStatus);
- if (stStatus.dwCurrentState == dwState)
- return TRUE;
-
- }
+ apxLogWrite(APXLOG_MARK_DEBUG "apxServiceControl():
QueryServiceStatus OK");
+ if (fnControlCallback) {
+ apxLogWrite(APXLOG_MARK_DEBUG "apxServiceControl():
Calling fnControlCallback()");
+ (*fnControlCallback)(lpCbData, uMsg, (WPARAM)4,
(LPARAM)&stStatus);
+ apxLogWrite(APXLOG_MARK_DEBUG "apxServiceControl():
Returned from fnControlCallback()");
+ }
+ if (stStatus.dwCurrentState == dwState) {
+ return TRUE;
+ } else {
+ apxLogWrite(APXLOG_MARK_ERROR
+ "apxServiceControl(): dwState(%d) !=
dwCurrentState(%d); "
+ "dwWin32ExitCode = %d, dwWaitHint = %d,
dwServiceSpecificExitCode = %d",
+ dwState,
+ stStatus.dwCurrentState,
+ stStatus.dwWin32ExitCode,
+ stStatus.dwWaitHint,
+ stStatus.dwServiceSpecificExitCode);
+ }
+
+ } else {
+ apxLogWrite(APXLOG_MARK_ERROR "apxServiceControl():
QueryServiceStatus failure");
+ }
- return FALSE;
+ apxLogWrite(APXLOG_MARK_ERROR "apxServiceControl(): returning FALSE");
+ return FALSE;
}
BOOL
