commons-commits mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From ggreg...@apache.org
Subject svn commit: r1801253 - in /commons/proper/daemon/trunk/src: changes/changes.xml native/windows/apps/prunsrv/prunsrv.c native/windows/src/javajni.c native/windows/src/rprocess.c native/windows/src/service.c
Date Sat, 08 Jul 2017 01:49:43 GMT
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



Mime
View raw message