[SERVICES] Fix services delay on stopping (#7375)

Retry of @yagoulas PR #1225.

JIRA issues: CORE-16949
and CORE-15064

base/system/services/database.c

@@ -852,6 +852,105 @@ ScmDeleteServiceRecord(PSERVICE lpService)
     DPRINT("Done\n");
 }
 
+DWORD
+Int_EnumDependentServicesW(HKEY hServicesKey,
+                           PSERVICE lpService,
+                           DWORD dwServiceState,
+                           PSERVICE *lpServices,
+                           LPDWORD pcbBytesNeeded,
+                           LPDWORD lpServicesReturned);
+
+DWORD ScmDeleteService(PSERVICE lpService)
+{
+    DWORD dwError;
+    DWORD pcbBytesNeeded = 0;
+    DWORD dwServicesReturned = 0;
+    HKEY hServicesKey;
+
+    ASSERT(lpService->RefCount == 0);
+
+    /* Open the Services Reg key */
+    dwError = RegOpenKeyExW(HKEY_LOCAL_MACHINE,
+                            L"System\\CurrentControlSet\\Services",
+                            0,
+                            KEY_SET_VALUE | KEY_READ,
+                            &hServicesKey);
+    if (dwError != ERROR_SUCCESS)
+    {
+        DPRINT1("Failed to open services key\n");
+        return dwError;
+    }
+
+    /* Call the function with NULL, just to get bytes we need */
+    Int_EnumDependentServicesW(hServicesKey,
+                               lpService,
+                               SERVICE_ACTIVE,
+                               NULL,
+                               &pcbBytesNeeded,
+                               &dwServicesReturned);
+
+    /* If pcbBytesNeeded returned a value then there are services running that are dependent on this service */
+    if (pcbBytesNeeded)
+    {
+        DPRINT1("Deletion failed due to running dependencies\n");
+        RegCloseKey(hServicesKey);
+        return ERROR_DEPENDENT_SERVICES_RUNNING;
+    }
+
+    /* There are no references and no running dependencies,
+       it is now safe to delete the service */
+
+    /* Delete the Service Key */
+    dwError = ScmDeleteRegKey(hServicesKey, lpService->lpServiceName);
+
+    RegCloseKey(hServicesKey);
+
+    if (dwError != ERROR_SUCCESS)
+    {
+        DPRINT1("Failed to delete the Service Registry key\n");
+        return dwError;
+    }
+
+    /* Delete the Service */
+    ScmDeleteServiceRecord(lpService);
+
+    return ERROR_SUCCESS;
+}
+
+/*
+ * This function allows the caller to be sure that the service won't be freed unexpectedly.
+ * In order to be sure that lpService will be valid until the reference is added
+ * the caller needs to hold the database lock.
+ * A running service will keep a reference for the whole time it is not SERVICE_STOPPED.
+ * A service handle will also keep a reference to a service. Keeping a reference is
+ * really needed so that ScmControlService can be called without keeping the database locked.
+ * This means that eventually the correct order of operations to send a control message to
+ * a service looks like: lock, reference, unlock, send control, lock, dereference, unlock.
+ */
+DWORD
+ScmReferenceService(PSERVICE lpService)
+{
+    return InterlockedIncrement(&lpService->RefCount);
+}
+
+/* This function must be called with the database lock held exclusively as
+   it can end up deleting the service */
+DWORD
+ScmDereferenceService(PSERVICE lpService)
+{
+    DWORD ref;
+
+    ASSERT(lpService->RefCount > 0);
+
+    ref = InterlockedDecrement(&lpService->RefCount);
+
+    if (ref == 0 && lpService->bDeleted &&
+        lpService->Status.dwCurrentState == SERVICE_STOPPED)
+    {
+        ScmDeleteService(lpService);
+    }
+    return ref;
+}
 
 static DWORD
 CreateServiceListEntry(LPCWSTR lpServiceName,
@@ -1310,6 +1409,10 @@ ScmGetBootAndSystemDriverState(VOID)
 }
 
 
+/*
+ * ScmControlService must never be called with the database lock being held.
+ * The service passed must always be referenced instead.
+ */
 DWORD
 ScmControlService(HANDLE hControlPipe,
                   PWSTR pServiceName,
@@ -1327,7 +1430,7 @@ ScmControlService(HANDLE hControlPipe,
     BOOL bResult;
     OVERLAPPED Overlapped = {0};
 
-    DPRINT("ScmControlService() called\n");
+    DPRINT("ScmControlService(%S, %d) called\n", pServiceName, dwControl);
 
     /* Acquire the service control critical section, to synchronize requests */
     EnterCriticalSection(&ControlServiceCriticalSection);
@@ -1364,23 +1467,24 @@ ScmControlService(HANDLE hControlPipe,
                         &Overlapped);
     if (bResult == FALSE)
     {
-        DPRINT("WriteFile() returned FALSE\n");
+        DPRINT1("WriteFile(%S, %d) returned FALSE\n", pServiceName, dwControl);
 
         dwError = GetLastError();
         if (dwError == ERROR_IO_PENDING)
         {
-            DPRINT("dwError: ERROR_IO_PENDING\n");
+            DPRINT("(%S, %d) dwError: ERROR_IO_PENDING\n", pServiceName, dwControl);
 
             dwError = WaitForSingleObject(hControlPipe,
                                           PipeTimeout);
-            DPRINT("WaitForSingleObject() returned %lu\n", dwError);
+            DPRINT("WaitForSingleObject(%S, %d) returned %lu\n", pServiceName, dwControl, dwError);
 
             if (dwError == WAIT_TIMEOUT)
             {
+                DPRINT1("WaitForSingleObject(%S, %d) timed out\n", pServiceName, dwControl, dwError);
                 bResult = CancelIo(hControlPipe);
                 if (bResult == FALSE)
                 {
-                    DPRINT1("CancelIo() failed (Error: %lu)\n", GetLastError());
+                    DPRINT1("CancelIo(%S, %d) failed (Error: %lu)\n", pServiceName, dwControl, GetLastError());
                 }
 
                 dwError = ERROR_SERVICE_REQUEST_TIMEOUT;
@@ -1395,7 +1499,7 @@ ScmControlService(HANDLE hControlPipe,
                 if (bResult == FALSE)
                 {
                     dwError = GetLastError();
-                    DPRINT1("GetOverlappedResult() failed (Error %lu)\n", dwError);
+                    DPRINT1("GetOverlappedResult(%S, %d) failed (Error %lu)\n", pServiceName, dwControl, dwError);
 
                     goto Done;
                 }
@@ -1403,7 +1507,7 @@ ScmControlService(HANDLE hControlPipe,
         }
         else
         {
-            DPRINT1("WriteFile() failed (Error %lu)\n", dwError);
+            DPRINT1("WriteFile(%S, %d) failed (Error %lu)\n", pServiceName, dwControl, dwError);
             goto Done;
         }
     }
@@ -1418,23 +1522,24 @@ ScmControlService(HANDLE hControlPipe,
                        &Overlapped);
     if (bResult == FALSE)
     {
-        DPRINT("ReadFile() returned FALSE\n");
+        DPRINT1("ReadFile(%S, %d) returned FALSE\n", pServiceName, dwControl);
 
         dwError = GetLastError();
         if (dwError == ERROR_IO_PENDING)
         {
-            DPRINT("dwError: ERROR_IO_PENDING\n");
+            DPRINT("(%S, %d) dwError: ERROR_IO_PENDING\n", pServiceName, dwControl);
 
             dwError = WaitForSingleObject(hControlPipe,
                                           PipeTimeout);
-            DPRINT("WaitForSingleObject() returned %lu\n", dwError);
+            DPRINT("WaitForSingleObject(%S, %d) returned %lu\n", pServiceName, dwControl, dwError);
 
             if (dwError == WAIT_TIMEOUT)
             {
+                DPRINT1("WaitForSingleObject(%S, %d) timed out\n", pServiceName, dwControl, dwError);
                 bResult = CancelIo(hControlPipe);
                 if (bResult == FALSE)
                 {
-                    DPRINT1("CancelIo() failed (Error: %lu)\n", GetLastError());
+                    DPRINT1("CancelIo(%S, %d) failed (Error: %lu)\n", pServiceName, dwControl, GetLastError());
                 }
 
                 dwError = ERROR_SERVICE_REQUEST_TIMEOUT;
@@ -1449,7 +1554,7 @@ ScmControlService(HANDLE hControlPipe,
                 if (bResult == FALSE)
                 {
                     dwError = GetLastError();
-                    DPRINT1("GetOverlappedResult() failed (Error %lu)\n", dwError);
+                    DPRINT1("GetOverlappedResult(%S, %d) failed (Error %lu)\n", pServiceName, dwControl, dwError);
 
                     goto Done;
                 }
@@ -1457,7 +1562,7 @@ ScmControlService(HANDLE hControlPipe,
         }
         else
         {
-            DPRINT1("ReadFile() failed (Error %lu)\n", dwError);
+            DPRINT1("ReadFile(%S, %d) failed (Error %lu)\n", pServiceName, dwControl, dwError);
             goto Done;
         }
     }
@@ -1475,7 +1580,7 @@ Done:
 
     LeaveCriticalSection(&ControlServiceCriticalSection);
 
-    DPRINT("ScmControlService() done\n");
+    DPRINT("ScmControlService(%S, %d) done\n", pServiceName, dwControl);
 
     return dwError;
 }
@@ -2052,6 +2157,7 @@ ScmLoadService(PSERVICE Service,
             {
                 Service->Status.dwCurrentState = SERVICE_START_PENDING;
                 Service->Status.dwControlsAccepted = 0;
+                ScmReferenceService(Service);
             }
             else
             {

base/system/services/rpcserver.c

@@ -777,9 +777,8 @@ ScmCanonDriverImagePath(DWORD dwStartType,
 }
 
 
-/* Internal recursive function */
+/* Recursively search for every dependency on every service */
-/* Need to search for every dependency on every service */
+DWORD
-static DWORD
 Int_EnumDependentServicesW(HKEY hServicesKey,
                            PSERVICE lpService,
                            DWORD dwServiceState,
@@ -939,10 +938,6 @@ RCloseServiceHandle(
     PMANAGER_HANDLE hManager;
     PSERVICE_HANDLE hService;
     PSERVICE lpService;
-    HKEY hServicesKey;
-    DWORD dwError;
-    DWORD pcbBytesNeeded = 0;
-    DWORD dwServicesReturned = 0;
 
     DPRINT("RCloseServiceHandle() called\n");
 
@@ -986,68 +981,9 @@ RCloseServiceHandle(
         HeapFree(GetProcessHeap(), 0, hService);
         hService = NULL;
 
-        ASSERT(lpService->dwRefCount > 0);
 
-        lpService->dwRefCount--;
+        DPRINT("Closing service %S with %d references\n", lpService->lpServiceName, lpService->RefCount);
-        DPRINT("CloseServiceHandle - lpService->dwRefCount %u\n",
+        ScmDereferenceService(lpService);
-               lpService->dwRefCount);
-
-        if (lpService->dwRefCount == 0)
-        {
-            /* If this service has been marked for deletion */
-            if (lpService->bDeleted &&
-                lpService->Status.dwCurrentState == SERVICE_STOPPED)
-            {
-                /* Open the Services Reg key */
-                dwError = RegOpenKeyExW(HKEY_LOCAL_MACHINE,
-                                        L"System\\CurrentControlSet\\Services",
-                                        0,
-                                        KEY_SET_VALUE | KEY_READ,
-                                        &hServicesKey);
-                if (dwError != ERROR_SUCCESS)
-                {
-                    DPRINT("Failed to open services key\n");
-                    ScmUnlockDatabase();
-                    return dwError;
-                }
-
-                /* Call the internal function with NULL, just to get bytes we need */
-                Int_EnumDependentServicesW(hServicesKey,
-                                           lpService,
-                                           SERVICE_ACTIVE,
-                                           NULL,
-                                           &pcbBytesNeeded,
-                                           &dwServicesReturned);
-
-                /* If pcbBytesNeeded returned a value then there are services running that are dependent on this service */
-                if (pcbBytesNeeded)
-                {
-                    DPRINT("Deletion failed due to running dependencies\n");
-                    RegCloseKey(hServicesKey);
-                    ScmUnlockDatabase();
-                    return ERROR_SUCCESS;
-                }
-
-                /* There are no references and no running dependencies,
-                   it is now safe to delete the service */
-
-                /* Delete the Service Key */
-                dwError = ScmDeleteRegKey(hServicesKey,
-                                          lpService->lpServiceName);
-
-                RegCloseKey(hServicesKey);
-
-                if (dwError != ERROR_SUCCESS)
-                {
-                    DPRINT("Failed to Delete the Service Registry key\n");
-                    ScmUnlockDatabase();
-                    return dwError;
-                }
-
-                /* Delete the Service */
-                ScmDeleteServiceRecord(lpService);
-            }
-        }
 
         ScmUnlockDatabase();
 
@@ -1672,6 +1608,81 @@ ScmIsValidServiceState(DWORD dwCurrentState)
     }
 }
 
+static
+DWORD
+WINAPI
+ScmStopThread(PVOID pParam)
+{
+    PSERVICE lpService = (PSERVICE)pParam;
+    WCHAR szLogBuffer[80];
+    LPCWSTR lpLogStrings[2];
+
+    /* Check if we are about to stop this service */
+    if (lpService->lpImage->dwImageRunCount == 1)
+    {
+        /* Stop the dispatcher thread.
+         * We must not send a control message while holding the database lock, otherwise it can cause timeouts
+         * We are sure that the service won't be deleted in the meantime because we still have a reference to it. */
+        DPRINT("Stopping the dispatcher thread for service %S\n", lpService->lpServiceName);
+        ScmControlService(lpService->lpImage->hControlPipe,
+                          L"",
+                          (SERVICE_STATUS_HANDLE)lpService,
+                          SERVICE_CONTROL_STOP);
+    }
+
+    /* Lock the service database exclusively */
+    ScmLockDatabaseExclusive();
+
+    DPRINT("Service %S image count:%d\n", lpService->lpServiceName, lpService->lpImage->dwImageRunCount);
+
+    /* Decrement the image run counter */
+    lpService->lpImage->dwImageRunCount--;
+
+    /* If we just stopped the last running service... */
+    if (lpService->lpImage->dwImageRunCount == 0)
+    {
+        /* Remove the service image */
+        DPRINT("Removing service image for %S\n", lpService->lpServiceName);
+        ScmRemoveServiceImage(lpService->lpImage);
+        lpService->lpImage = NULL;
+    }
+
+    /* Report the results of the status change here */
+    if (lpService->Status.dwWin32ExitCode != ERROR_SUCCESS)
+    {
+        /* Log a failed service stop */
+        StringCchPrintfW(szLogBuffer, ARRAYSIZE(szLogBuffer),
+                         L"%lu", lpService->Status.dwWin32ExitCode);
+        lpLogStrings[0] = lpService->lpDisplayName;
+        lpLogStrings[1] = szLogBuffer;
+
+        ScmLogEvent(EVENT_SERVICE_EXIT_FAILED,
+                    EVENTLOG_ERROR_TYPE,
+                    ARRAYSIZE(lpLogStrings),
+                    lpLogStrings);
+    }
+    else
+    {
+        /* Log a successful service status change */
+        LoadStringW(GetModuleHandle(NULL), IDS_SERVICE_STOPPED, szLogBuffer, ARRAYSIZE(szLogBuffer));
+        lpLogStrings[0] = lpService->lpDisplayName;
+        lpLogStrings[1] = szLogBuffer;
+
+        ScmLogEvent(EVENT_SERVICE_STATUS_SUCCESS,
+                    EVENTLOG_INFORMATION_TYPE,
+                    ARRAYSIZE(lpLogStrings),
+                    lpLogStrings);
+    }
+
+    /* Remove the reference that was added when the service started */
+    DPRINT("Service %S has %d references while stoping\n", lpService->lpServiceName, lpService->RefCount);
+    ScmDereferenceService(lpService);
+
+    /* Unlock the service database */
+    ScmUnlockDatabase();
+
+    return 0;
+}
 
 /* Function 7 */
 DWORD
@@ -1754,58 +1765,62 @@ RSetServiceStatus(
     /* Restore the previous service type */
     lpService->Status.dwServiceType = dwPreviousType;
 
-    /* Dereference a stopped service */
+    DPRINT("Service %S changed state %d to %d\n", lpService->lpServiceName, dwPreviousState, lpServiceStatus->dwCurrentState);
-    if ((lpServiceStatus->dwServiceType & SERVICE_WIN32) &&
+
-        (lpServiceStatus->dwCurrentState == SERVICE_STOPPED))
+    if (lpServiceStatus->dwCurrentState != SERVICE_STOPPED &&
+        dwPreviousState == SERVICE_STOPPED)
     {
-        /* Decrement the image run counter */
+        /* Keep a reference on all non stopped services */
-        lpService->lpImage->dwImageRunCount--;
+        ScmReferenceService(lpService);
+        DPRINT("Service %S has %d references after starting\n", lpService->lpServiceName, lpService->RefCount);
+    }
 
-        /* If we just stopped the last running service... */
+    /* Check if the service just stopped */
-        if (lpService->lpImage->dwImageRunCount == 0)
+    if (lpServiceStatus->dwCurrentState == SERVICE_STOPPED &&
+        dwPreviousState != SERVICE_STOPPED)
+    {
+        HANDLE hStopThread;
+        DWORD dwStopThreadId;
+        DPRINT("Service %S, currentstate: %d, prev: %d\n", lpService->lpServiceName, lpServiceStatus->dwCurrentState, dwPreviousState);
+
+        /*
+         * The service just changed its status to stopped.
+         * Create a thread that will complete the stop sequence.
+         * This thread will remove the reference that was added when the service started.
+         * This will ensure that the service will remain valid as long as this reference is still held.
+         */
+        hStopThread = CreateThread(NULL,
+                                   0,
+                                   ScmStopThread,
+                                   (LPVOID)lpService,
+                                   0,
+                                   &dwStopThreadId);
+        if (hStopThread == NULL)
         {
-            /* Stop the dispatcher thread */
+            DPRINT1("Failed to create thread to complete service stop\n");
-            ScmControlService(lpService->lpImage->hControlPipe,
+            /* We can't leave without releasing the reference.
-                              L"",
+             * We also can't remove it without holding the lock. */
-                              (SERVICE_STATUS_HANDLE)lpService,
+            ScmDereferenceService(lpService);
-                              SERVICE_CONTROL_STOP);
+            DPRINT1("Service %S has %d references after stop\n", lpService->lpServiceName, lpService->RefCount);
-
+        }
-            /* Remove the service image */
+        else
-            ScmRemoveServiceImage(lpService->lpImage);
+        {
-            lpService->lpImage = NULL;
+            CloseHandle(hStopThread);
         }
     }
 
     /* Unlock the service database */
     ScmUnlockDatabase();
 
-    if ((lpServiceStatus->dwCurrentState == SERVICE_STOPPED) &&
+    /* Don't log any events here regarding a service stop as it can become invalid at any time */
-        (dwPreviousState != SERVICE_STOPPED) &&
-        (lpServiceStatus->dwWin32ExitCode != ERROR_SUCCESS))
-    {
-        /* Log a failed service stop */
-        StringCchPrintfW(szLogBuffer, ARRAYSIZE(szLogBuffer),
-                         L"%lu", lpServiceStatus->dwWin32ExitCode);
-        lpLogStrings[0] = lpService->lpDisplayName;
-        lpLogStrings[1] = szLogBuffer;
 
-        ScmLogEvent(EVENT_SERVICE_EXIT_FAILED,
+    if (lpServiceStatus->dwCurrentState != dwPreviousState &&
-                    EVENTLOG_ERROR_TYPE,
+        (lpServiceStatus->dwCurrentState == SERVICE_RUNNING ||
-                    2,
+         lpServiceStatus->dwCurrentState == SERVICE_PAUSED))
-                    lpLogStrings);
-    }
-    else if (lpServiceStatus->dwCurrentState != dwPreviousState &&
-             (lpServiceStatus->dwCurrentState == SERVICE_STOPPED ||
-              lpServiceStatus->dwCurrentState == SERVICE_RUNNING ||
-              lpServiceStatus->dwCurrentState == SERVICE_PAUSED))
     {
         /* Log a successful service status change */
         switch(lpServiceStatus->dwCurrentState)
         {
-            case SERVICE_STOPPED:
-                uID = IDS_SERVICE_STOPPED;
-                break;
-
             case SERVICE_RUNNING:
                 uID = IDS_SERVICE_RUNNING;
                 break;
@@ -2217,7 +2232,7 @@ RChangeServiceConfigW(
                     DPRINT1("ScmDecryptPassword failed (Error %lu)\n", dwError);
                     goto done;
                 }
-                DPRINT1("Clear text password: %S\n", lpClearTextPassword);
+                DPRINT("Clear text password: %S\n", lpClearTextPassword);
 
                 /* Write the password */
                 dwError = ScmSetServicePassword(lpService->szServiceName,
@@ -2641,12 +2656,12 @@ RCreateServiceW(
     if (dwError != ERROR_SUCCESS)
         goto done;
 
-    lpService->dwRefCount = 1;
+    ScmReferenceService(lpService);
 
     /* Get the service tag (if Win32) */
     ScmGenerateServiceTag(lpService);
 
-    DPRINT("CreateService - lpService->dwRefCount %u\n", lpService->dwRefCount);
+    DPRINT("CreateService - lpService->RefCount %u\n", lpService->RefCount);
 
 done:
     /* Unlock the service database */
@@ -2981,8 +2996,8 @@ ROpenServiceW(
         goto Done;
     }
 
-    lpService->dwRefCount++;
+    ScmReferenceService(lpService);
-    DPRINT("OpenService - lpService->dwRefCount %u\n",lpService->dwRefCount);
+    DPRINT("OpenService %S - lpService->RefCount %u\n", lpService->lpServiceName, lpService->RefCount);
 
     *lpServiceHandle = (SC_RPC_HANDLE)hHandle;
     DPRINT("*hService = %p\n", *lpServiceHandle);
@@ -6725,7 +6740,7 @@ RI_ScValidatePnPService(
     hManager = ScmGetServiceManagerFromHandle(hSCManager);
     if (hManager == NULL)
     {
-        DPRINT1("Invalid handle!\n");
+        DPRINT1("Invalid handle\n");
         return ERROR_INVALID_HANDLE;
     }
 
@@ -6735,7 +6750,7 @@ RI_ScValidatePnPService(
     if (!RtlAreAllAccessesGranted(hManager->Handle.DesiredAccess,
                                   SC_MANAGER_CONNECT))
     {
-        DPRINT1("No SC_MANAGER_CONNECT access!\n");
+        DPRINT1("No SC_MANAGER_CONNECT access\n");
         return ERROR_ACCESS_DENIED;
     }
 

base/system/services/services.h

@@ -65,7 +65,7 @@ typedef struct _SERVICE
     PSERVICE_IMAGE lpImage;
     BOOL bDeleted;
     DWORD dwResumeCount;
-    DWORD dwRefCount;
+    LONG RefCount;
 
     SERVICE_STATUS Status;
     DWORD dwStartType;
@@ -186,6 +186,9 @@ DWORD ScmStartService(PSERVICE Service,
                       DWORD argc,
                       LPWSTR *argv);
 
+DWORD ScmReferenceService(PSERVICE lpService);
+DWORD ScmDereferenceService(PSERVICE lpService);
+
 VOID ScmRemoveServiceImage(PSERVICE_IMAGE pServiceImage);
 PSERVICE ScmGetServiceEntryByName(LPCWSTR lpServiceName);
 PSERVICE ScmGetServiceEntryByDisplayName(LPCWSTR lpDisplayName);