Skip to content

runtime: Windows service lifecycle events behave incorrectly when called within a golang environment #40167

Closed
@JohanKnutzen

Description

@JohanKnutzen

What version of Go are you using (go version)?

$ go version
go version go1.14.3 windows/amd64

Does this issue reproduce with the latest release?

Yes.

What operating system and processor architecture are you using (go env)?

go env Output
$ go env
set GO111MODULE=
set GOARCH=amd64
set GOBIN=
set GOCACHE=C:\Users\knutz\AppData\Local\go-build
set GOENV=C:\Users\knutz\AppData\Roaming\go\env
set GOEXE=.exe
set GOFLAGS=
set GOHOSTARCH=amd64
set GOHOSTOS=windows
set GOINSECURE=
set GONOPROXY=
set GONOSUMDB=
set GOOS=windows
set GOPATH=C:\Users\knutz\go
set GOPRIVATE=
set GOPROXY=https://proxy.golang.org,direct
set GOROOT=c:\go
set GOSUMDB=sum.golang.org
set GOTMPDIR=
set GOTOOLDIR=c:\go\pkg\tool\windows_amd64
set GCCGO=gccgo
set AR=ar
set CC=gcc
set CXX=g++
set CGO_ENABLED=1
set GOMOD=C:\tmp\test2\svcshutdownbug\go.mod
set CGO_CFLAGS=-g -O2
set CGO_CPPFLAGS=
set CGO_CXXFLAGS=-g -O2
set CGO_FFLAGS=-g -O2
set CGO_LDFLAGS=-g -O2
set PKG_CONFIG=pkg-config
set GOGCCFLAGS=-m64 -mthreads -fno-caret-diagnostics -Qunused-arguments -fmessage-length=0 -fdebug-prefix-map=C:\Users\knutz\AppData\Local\Temp\go-build509631438=/tmp/go-build -gno-record-gcc-switches

What did you do?

Upon further narrowing of a minimal example that reproduces 40157, it seems that the golang runtime is preventing emitting of SERVICE_CONTROL_SHUTDOWN events.

I've written a program in c as well as in golang that logs this event. The order of syscalls are identical.

Source code

main.go
package main

import (
	"fmt"
	"os"
	"syscall"
	"unsafe"
)

const ()

const (
	SERVICE_WIN32_OWN_PROCESS = uint32(0x00000010)

	SERVICE_CONTROL_STOP     = uint32(0x00000001)
	SERVICE_CONTROL_SHUTDOWN = uint32(0x00000005)

	SERVICE_ACCEPT_STOP     = uint32(0x00000001)
	SERVICE_ACCEPT_SHUTDOWN = uint32(0x00000004)

	SERVICE_STOPPED       = uint32(0x00000001)
	SERVICE_START_PENDING = uint32(0x00000002)
	SERVICE_STOP_PENDING  = uint32(0x00000003)
	SERVICE_RUNNING       = uint32(0x00000004)
)

type SERVICE_TABLE_ENTRY struct {
	name *uint16
	proc uintptr
}

type SERVICE_STATUS struct {
	dwServiceType             uint32
	dwCurrentState            uint32
	dwControlsAccepted        uint32
	dwWin32ExitCode           uint32
	dwServiceSpecificExitCode uint32
	dwCheckPoint              uint32
	dwWaitHint                uint32
}

var (
	advapi32                         = syscall.NewLazyDLL("Advapi32.dll")
	procStartServiceCtrlDispatcher   = advapi32.NewProc("StartServiceCtrlDispatcherW")
	procRegisterServiceCtrlHandlerEx = advapi32.NewProc("RegisterServiceCtrlHandlerExW")
	procSetServiceStatus             = advapi32.NewProc("SetServiceStatus")
)

const svcName = "svctest"

var stopped = make(chan bool)

func log(text string) {
	filename := os.TempDir() + "\\" + "svctest.log"
	f, err := os.OpenFile(filename, os.O_APPEND|os.O_CREATE|os.O_WRONLY, 0600)
	if err != nil {
		panic(err)
	}
	defer f.Close()

	if _, err = f.WriteString(text); err != nil {
		panic(err)
	}
}

func ctrlHandlerEx(ctrlCode uint32, eventType uint32, eventData uintptr, context uintptr) uintptr {
	switch ctrlCode {
	case SERVICE_CONTROL_STOP:
		log(fmt.Sprintf("SERVICE_CONTROL_STOP\n"))
		stopped <- true
	case SERVICE_CONTROL_SHUTDOWN:
		log(fmt.Sprintf("SERVICE_CONTROL_SHUTDOWN\n"))
		stopped <- true
	}

	return 0
}

func serviceMain(argc uint32, argv **uint16) uintptr {
	statusHandle, _, err := procRegisterServiceCtrlHandlerEx.Call(uintptr(unsafe.Pointer(syscall.StringToUTF16Ptr(svcName))),
		syscall.NewCallback(ctrlHandlerEx),
		uintptr(0))

	if 0 == statusHandle {
		log(fmt.Sprintf("Error calling StartServiceCtrlDispatcherW: %v\n", err))
		return 0
	}
	status := SERVICE_STATUS{
		dwServiceType:      SERVICE_WIN32_OWN_PROCESS,
		dwControlsAccepted: (SERVICE_ACCEPT_STOP | SERVICE_ACCEPT_SHUTDOWN),
		dwCurrentState:     SERVICE_START_PENDING,
	}

	ret, _, err := procSetServiceStatus.Call(statusHandle, uintptr(unsafe.Pointer(&status)))
	if ret == 0 {
		log(fmt.Sprintf("Error calling SetServiceStatus: %v\n", err))
	}

	status.dwCurrentState = SERVICE_RUNNING
	ret, _, err = procSetServiceStatus.Call(statusHandle, uintptr(unsafe.Pointer(&status)))
	if ret == 0 {
		log(fmt.Sprintf("Error calling SetServiceStatus: %v\n", err))
	}

	<-stopped

	status.dwCurrentState = SERVICE_STOPPED
	ret, _, err = procSetServiceStatus.Call(statusHandle, uintptr(unsafe.Pointer(&status)))
	if ret == 0 {
		log(fmt.Sprintf("Error calling SetServiceStatus: %v\n", err))
	}

	return 0
}

func main() {
	t := []SERVICE_TABLE_ENTRY{
		{
			name: syscall.StringToUTF16Ptr(svcName),
			proc: syscall.NewCallback(serviceMain),
		},
		{name: nil, proc: 0},
	}

	ret, _, err := procStartServiceCtrlDispatcher.Call(uintptr(unsafe.Pointer(&t[0])))
	if ret == 0 {
		log(fmt.Sprintf("Error calling StartServiceCtrlDispatcherW: %v\n", err))
	}
}
main.c
#include <Windows.h>
#include <tchar.h>
#include <stdio.h>


SERVICE_STATUS g_ServiceStatus = { 0 };
SERVICE_STATUS_HANDLE g_StatusHandle = NULL;
HANDLE g_ServiceStopEvent = INVALID_HANDLE_VALUE;

VOID WINAPI ServiceMain(DWORD argc, LPTSTR *argv);
DWORD WINAPI ServiceWorkerThread(LPVOID lpParam);
DWORD WINAPI ctrlHandlerEx(DWORD CtrlCode, DWORD eventType, LPVOID eventData, LPVOID context);

#define SERVICE_NAME _T("svctest")

VOID WINAPI ServiceMain(DWORD argc, LPTSTR *argv) {

  g_StatusHandle = RegisterServiceCtrlHandlerEx(SERVICE_NAME, ctrlHandlerEx,
    NULL);

  if (g_StatusHandle == NULL) {
    goto EXIT;
  }

  // Tell the service controller we are starting
  ZeroMemory( & g_ServiceStatus, sizeof(g_ServiceStatus));

  g_ServiceStatus.dwServiceType = SERVICE_WIN32_OWN_PROCESS;
  g_ServiceStatus.dwControlsAccepted = SERVICE_ACCEPT_STOP
    | SERVICE_ACCEPT_POWEREVENT | SERVICE_ACCEPT_SESSIONCHANGE
    | SERVICE_ACCEPT_SHUTDOWN;
  g_ServiceStatus.dwCurrentState = SERVICE_START_PENDING;
  g_ServiceStatus.dwWin32ExitCode = 0;
  g_ServiceStatus.dwServiceSpecificExitCode = 0;
  g_ServiceStatus.dwCheckPoint = 0;

  if (SetServiceStatus(g_StatusHandle, &g_ServiceStatus) == FALSE) {
    //...
  }

  g_ServiceStopEvent = CreateEvent(NULL, TRUE, FALSE, NULL);

  if (g_ServiceStopEvent == NULL) {
    //...
    goto EXIT;
  }

  g_ServiceStatus.dwCurrentState = SERVICE_RUNNING;
  g_ServiceStatus.dwWin32ExitCode = 0;
  g_ServiceStatus.dwCheckPoint = 0;

  if (SetServiceStatus(g_StatusHandle, &g_ServiceStatus) == FALSE) {
    //...
  }

  HANDLE hThread = CreateThread(NULL, 0, ServiceWorkerThread, NULL, 0, NULL);

  WaitForSingleObject(hThread, INFINITE);

  CloseHandle(g_ServiceStopEvent);

  g_ServiceStatus.dwCurrentState = SERVICE_STOPPED;
  g_ServiceStatus.dwWin32ExitCode = 0;
  g_ServiceStatus.dwCheckPoint = 3;

  if (SetServiceStatus(g_StatusHandle, &g_ServiceStatus) == FALSE) {

  }

EXIT: return;
}

void log(const char* str) 
{
  FILE *file = fopen("C:\\Windows\\Temp\\svctest.log", "a+");
  if(0 == file) {
    return;
  }
  fprintf(file, str);
  fclose(file);
}

DWORD WINAPI ctrlHandlerEx(DWORD CtrlCode, DWORD eventType, LPVOID eventData,
  LPVOID context) {
  switch (CtrlCode) {
  case SERVICE_CONTROL_STOP: 
    log("SERVICE_CONTROL_STOP\n\r");
    SetEvent(g_ServiceStopEvent);
    break;
  case SERVICE_CONTROL_SHUTDOWN:
    log("SERVICE_CONTROL_SHUTDOWN\n\r");
    SetEvent(g_ServiceStopEvent);
    break;
  default:
    break;
  }

  return 0;
}

DWORD WINAPI ServiceWorkerThread(LPVOID lpParam) {

  while (WaitForSingleObject(g_ServiceStopEvent, 0) != WAIT_OBJECT_0) {

    Sleep(3000);
  }

  return 0;
}

DWORD RunService() {
  SERVICE_TABLE_ENTRY serviceTable[] = { { SERVICE_NAME, ServiceMain },
    { 0, 0 } };

  if (StartServiceCtrlDispatcher(serviceTable)) {
    return 0;
  } else {
    DWORD erro = GetLastError();

    return 1;
  }
}

int _tmain(int argc, TCHAR *argv[]) {
  RunService();
  return 0;
}

Building
golang: go build
C: cl main.c /link Advapi32.lib.

Running

  1. Run sc create svctest binpath= _path_ in an administrator cmd.exe, path should be an absolute path pointing to either the c executable or the golang executable.
  2. Run sc start svctest to start the service
  3. Run shutdown /s. This will shut down the computer. Do not shutdown using the start-menu.

Cleanup
Run sc delete svctest to remove the service entry in Windows

What did you expect to see?

Both executables log SERVICE_CONTROL_STOP and SERVICE_CONTROL_SHUTDOWN to C:\Windows\Temp\svctest.log. The above steps should log a SERVICE_CONTROL_SHUTDOWN during shutdown of the computer.

What did you see instead?

Only the C program appropriately logs SERVICE_CONTROL_SHUTDOWN. You can test that both programs log SERVICE_CONTROL_STOP by right clicking on the service in the Task Manager and selecting Restart.

Metadata

Metadata

Assignees

No one assigned

    Labels

    FrozenDueToAgeNeedsFixThe path to resolution is known, but the work has not been done.OS-Windows

    Type

    No type

    Projects

    No projects

    Milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions