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

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.

About this issue

  • Original URL
  • State: closed
  • Created 4 years ago
  • Comments: 66 (36 by maintainers)

Commits related to this issue

Most upvoted comments

Does this issue affect Go 1.13 in addition to 1.14, or was it introduced in 1.14?

Go 1.13 is good. We introduced this bug in Go 1.14. See https://github.com/golang/go/issues/40074#issuecomment-659952395 for details.

Alex

Thanks very much. The backport issues have been approved, so it’s a matter of getting the cherry pick CLs +2ed, run trybots, and then a release manager can submit them. We are targeting September 1st or so for the next minor releases.

I’m not opposed to this approach, just looking to understand this better. This is a long thread and from reading it, my brief understanding so far is that the Go 1.16 fix is better but may need additional work/testing, while the Go 1.15+1.14 backports are larger code changes but deemed safer/smaller difference in behavior. Or is it something else? Thank you.

That is exactly correct.

Already submitted fix on current master has not many lines of code, but is riskier - it removes exit(2) and assumes that Windows will do the right thing on its own. And it affects all Go programs. This fix is more “logically correct”, but is new, and needs more time to be tested / verified.

Backports to go1.14 and go1.15 have more lines of code, but they only affects Windows service programs (limited set of all Windows programs - these programs are specifically designed to be started when Windows boots, and they have to comply with a specific protocol, because of that). And the change just removes code that was not intended to run in Windows service https://github.com/golang/go/issues/40074#issuecomment-659952395

I hope it explains.

Alex

Sorry for the churn. The two backports are https://golang.org/cl/244958 and https://golang.org/cl/244959.

Thanks a lot guys for helping me out. These kinds of issues are really tough to resolve.

@networkimprov @zx2c4 All windows services run in session 0 since Vista. Golang requires Windows 7.

Have fun injecting into windows sessionId==0. 😃

I’m probably misunderstanding you here but it’s trivial to start a process in session 0. We do this all the time. In fact, it’s encouraged by Microsoft because it’s a sandbox with lots of wings clipped. Just run it from a service running in session 0. We run a bunch of powershell stuff from there.

It is much harder to start a process from session 0 in another session though. We do this too though, it just requires a bit of extra yanking of the Windows chain.

The lifecycle of a Windows program is hard to generalize. All golang programs ship with the console ctrl handler set. This is unexpected when writing services or user32/gdi32 programs. It raises a lot of ambiguity in how those programs react to lifecycle events. A service written in golang crashes upon shutdown, but not if user32 has been touched. This is not something that’s obviously understood when interacting with the api. @zx2c4 patches solve this issue which is great.

If things were written from scratch though, I would argue to either a) remove the console ctrl handler entirely in the runtime or b) inject a hidden window into all golang programs that use the signals package to map WM_ENDSESSION/WM_CLOSE to whatever they need to do as these events are more predictable and remove ambiguity from having two paths for handling ctrl-c events.

Right, in theory I agree with you. In practice I’m a bit more hesitant to remove the exit(2) because I don’t have documentation from the original author detailing considerations, and I haven’t worked through enough edge cases to reunderstand the entire problem space myself. But indeed on inspection it looks like the second patch is much much better.

I agree. I prefer to remove exit(2) too.

What I suspect we should do is merge patch (1) now, for 1.15 and 1.14, because it fixes the bug. Then, we can merge (2) at the very beginning of the 1.16 cycle and see if it breaks anything.

I agree. This is the safest thing to do. We can revert patch (1) before applying patch (2), so it is nice and clean change.

We just need agreement from someone from Go Team. Maybe @ianlancetaylor or @aclements

Thank you.

Alex

To me, the second one makes more sense. I don’t see the reason for exiting like that. It’s better to under-specify behavior when dealing with Windows.

Right, in theory I agree with you. In practice I’m a bit more hesitant to remove the exit(2) because I don’t have documentation from the original author detailing considerations, and I haven’t worked through enough edge cases to reunderstand the entire problem space myself. But indeed on inspection it looks like the second patch is much much better.

What I suspect we should do is merge patch (1) now, for 1.15 and 1.14, because it fixes the bug. Then, we can merge (2) at the very beginning of the 1.16 cycle and see if it breaks anything.

@alexbrainman What do you think of that plan?