Merge e80e2c0 into cb2fa50

Author: jimklimov

NEWS.adoc

@@ -143,6 +143,8 @@ but the `nutshutdown` script would bail out quickly and quietly. [PR #3008]
      in other programs. Extended public API of libupsclient and libnutscan
      to diligently arrange debug-logging when at run-time those libraries
      actually have different copies of the methods and data involved. [#3378]
+   * Revised 'dstate' machinery to track socket connections closed mid-way
+     through a call, to avoid access after `free()`. [#3302]
 
  - NUT for Windows specific updates:
    * Revised detection of (relative) paths to program and configuration files

common/wincompat.c

@@ -401,9 +401,10 @@ int win_system(const char * command)
 	si.cb = sizeof(si);
 	memset(&pi,0,sizeof(pi));
 
+	upsdebugx(4, "%s: calling CreateProcess: %s", __func__, NUT_STRARG(command));
 	res = CreateProcess(NULL,(char *)command,NULL,NULL,FALSE,0,NULL,NULL,&si,&pi);
 
-	if( res != 0 ) {
+	if (res != 0) {
 		return 0;
 	}
 
@@ -441,14 +442,17 @@ char * filter_path(const char * source)
    of chars containing the message to display (no terminal 0 required here) */
 void syslog(int priority, const char *fmt, ...)
 {
-	char pipe_name[] = "\\\\.\\pipe\\"EVENTLOG_PIPE_NAME;
+	/* At least while this is not configurable, can be static to speed up;
+	 * see https://github.com/networkupstools/nut/issues/3375
+	 */
+	static char pipe_full_name[] = "\\\\.\\pipe\\"EVENTLOG_PIPE_NAME;
 	char buf1[LARGEBUF+sizeof(DWORD)];
 	char buf2[LARGEBUF];
 	va_list ap;
 	HANDLE pipe;
 	DWORD bytesWritten = 0;
 
-	if( EventLogName == NULL ) {
+	if (EventLogName == NULL) {
 		return;
 	}
 
@@ -462,38 +466,45 @@ void syslog(int priority, const char *fmt, ...)
 
 	/* Create the frame */
 	/* first 4 bytes are priority */
-	memcpy(buf1,&priority,sizeof(DWORD));
+	memcpy(buf1, &priority, sizeof(DWORD));
 	/* then comes the message */
-	memcpy(buf1+sizeof(DWORD),buf2,sizeof(buf2));
+	memcpy(buf1+sizeof(DWORD), buf2, sizeof(buf2));
 
+	upsdebugx(6, "%s: posting to event log NAMED_PIPE: '%s'", __func__, pipe_full_name);
 	pipe = CreateFile(
-			pipe_name,	/* pipe name */
-			GENERIC_WRITE,
-			0,			/* no sharing */
-			NULL,			/* default security attributes FIXME */
-			OPEN_EXISTING,		/* opens existing pipe */
-			FILE_FLAG_OVERLAPPED,	/* enable async IO */
-			NULL);			/* no template file */
-
+		pipe_full_name,	/* pipe name */
+		GENERIC_WRITE,
+		0,			/* no sharing */
+		NULL,			/* default security attributes FIXME */
+		OPEN_EXISTING,		/* opens existing pipe */
+		FILE_FLAG_OVERLAPPED,	/* enable async IO */
+		NULL);			/* no template file */
 
 	if (pipe == INVALID_HANDLE_VALUE) {
+		upsdebug_with_errno(1,
+			"%s: SKIP: can't open existing event log NAMED_PIPE: '%s'",
+			__func__, pipe_full_name);
+
 		return;
 	}
 
-	WriteFile (pipe,buf1,strlen(buf2)+sizeof(DWORD),&bytesWritten,NULL);
+	WriteFile (pipe, buf1, strlen(buf2)+sizeof(DWORD), &bytesWritten, NULL);
 
 	/* testing result is useless. If we have an error and try to report it,
 	 * this will probably lead to a call to this function and an infinite
 	 * loop */
+	upsdebugx(6, "%s: closing event log NAMED_PIPE", __func__);
 	CloseHandle(pipe);
 }
 
 /* Signal emulation via NamedPipe */
 
 static HANDLE		pipe_connection_handle;
+static const char	*named_pipe_name=NULL;
+
+/* Note these are shared (upsd, upsmon, nut.exe...) for other named pipe uses as well */
 OVERLAPPED		pipe_connection_overlapped;
 pipe_conn_t		*pipe_connhead = NULL;
-static const char	*named_pipe_name=NULL;
 
 void pipe_create(const char * pipe_name)
 {
@@ -516,19 +527,20 @@ void pipe_create(const char * pipe_name)
 	if( pipe_connection_overlapped.hEvent != 0 ) {
 		CloseHandle(pipe_connection_overlapped.hEvent);
 	}
-	memset(&pipe_connection_overlapped,0,sizeof(pipe_connection_overlapped));
+	memset(&pipe_connection_overlapped, 0, sizeof(pipe_connection_overlapped));
+	upsdebugx(2, "%s: creating NAMED_PIPE (listener): '%s'", __func__, pipe_full_name);
 	pipe_connection_handle = CreateNamedPipe(
-			pipe_full_name,
-			PIPE_ACCESS_INBOUND |   /* to server only */
-			FILE_FLAG_OVERLAPPED,   /* async IO */
-			PIPE_TYPE_MESSAGE |
-			PIPE_READMODE_MESSAGE |
-			PIPE_WAIT,
-			PIPE_UNLIMITED_INSTANCES, /* max. instances */
-			LARGEBUF,               /* output buffer size */
-			LARGEBUF,               /* input buffer size */
-			0,                      /* client time-out */
-			NULL);  /* FIXME: default security attribute */
+		pipe_full_name,
+		PIPE_ACCESS_INBOUND	/* to server only */
+		| FILE_FLAG_OVERLAPPED,	/* async IO */
+		PIPE_TYPE_MESSAGE
+		| PIPE_READMODE_MESSAGE
+		| PIPE_WAIT,
+		PIPE_UNLIMITED_INSTANCES,	/* max. instances */
+		LARGEBUF,		/* output buffer size */
+		LARGEBUF,		/* input buffer size */
+		0,			/* client time-out */
+		NULL);			/* FIXME: default security attribute */
 
 	if (pipe_connection_handle == INVALID_HANDLE_VALUE) {
 		upslogx(LOG_ERR, "Error creating named pipe");
@@ -537,19 +549,21 @@ void pipe_create(const char * pipe_name)
 	}
 
 	/* Prepare an async wait on a connection on the pipe */
-	pipe_connection_overlapped.hEvent = CreateEvent(NULL, /*Security*/
-			FALSE, /* auto-reset*/
-			FALSE, /* inital state = non signaled*/
-			NULL /* no name*/);
-	if(pipe_connection_overlapped.hEvent == NULL ) {
+	pipe_connection_overlapped.hEvent = CreateEvent(
+		NULL,	/* Security */
+		FALSE,	/* auto-reset */
+		FALSE,	/* initial state = non signaled */
+		NULL	/* no name */
+	);
+	if (pipe_connection_overlapped.hEvent == NULL) {
 		upslogx(LOG_ERR, "Error creating event");
 		fatal_with_errno(EXIT_FAILURE, "Can't create event");
 	}
 
 	/* Wait for a connection */
-	ret = ConnectNamedPipe(pipe_connection_handle,&pipe_connection_overlapped);
-	if(ret == 0 && GetLastError() != ERROR_IO_PENDING ) {
-		upslogx(LOG_ERR,"ConnectNamedPipe error");
+	ret = ConnectNamedPipe(pipe_connection_handle, &pipe_connection_overlapped);
+	if (ret == 0 && GetLastError() != ERROR_IO_PENDING) {
+		upslogx(LOG_ERR, "ConnectNamedPipe error");
 	}
 }
 
@@ -558,22 +572,31 @@ void pipe_connect()
 	/* We have detected a connection on the opened pipe. So we start by saving its handle and create a new pipe for future connections */
 	pipe_conn_t *conn;
 
-	conn = xcalloc(1,sizeof(*conn));
+	/* TOTHINK: Here we seem to have assumptions about a general connection
+	 * via overlapped I/O being the signal to daemon (via named_pipe_name)...
+	 * might this conflict with other I/Os (driver/server sockets, dummy-ups
+	 * files, etc.)?
+	 */
+	upsdebugx(3, "%s: handle incoming connection on NAMED PIPE", __func__);
+	conn = xcalloc(1, sizeof(*conn));
 	conn->handle = pipe_connection_handle;
 
 	/* restart a new listening pipe */
 	pipe_create(NULL);
 
 	/* A new pipe waiting for new client connection has been created. We could manage the current connection now */
 	/* Start a read operation on the newly connected pipe so we could wait on the event associated to this IO */
-	memset(&conn->overlapped,0,sizeof(conn->overlapped));
-	memset(conn->buf,0,sizeof(conn->buf));
-	conn->overlapped.hEvent = CreateEvent(NULL, /*Security*/
-			FALSE, /* auto-reset*/
-			FALSE, /* inital state = non signaled*/
-			NULL /* no name*/);
-	if(conn->overlapped.hEvent == NULL ) {
-		upslogx(LOG_ERR,"Can't create event for reading event log");
+	memset(&conn->overlapped, 0, sizeof(conn->overlapped));
+	memset(conn->buf, 0, sizeof(conn->buf));
+	conn->overlapped.hEvent = CreateEvent(
+		NULL,	/* Security */
+		FALSE,	/* auto-reset */
+		FALSE,	/* initial state = non signaled */
+		NULL	/* no name */
+	);
+	if (conn->overlapped.hEvent == NULL) {
+		/* FIXME: Is this (still) about event log only? */
+		upslog_with_errno(LOG_ERR, "Can't create event for reading event log");
 		return;
 	}
 
@@ -591,19 +614,24 @@ void pipe_connect()
 
 void pipe_disconnect(pipe_conn_t *conn)
 {
-	if( conn->overlapped.hEvent != INVALID_HANDLE_VALUE) {
+	upsdebugx(3, "%s: starting", __func__);
+
+	if (conn->overlapped.hEvent != INVALID_HANDLE_VALUE) {
+		upsdebugx(4, "%s: calling CloseHandle() for conn->overlapped.hEvent", __func__);
 		CloseHandle(conn->overlapped.hEvent);
 		conn->overlapped.hEvent = INVALID_HANDLE_VALUE;
 	}
-	if( conn->handle != INVALID_HANDLE_VALUE) {
-		if ( DisconnectNamedPipe(conn->handle) == 0 ) {
-			upslogx(LOG_ERR,
-				"DisconnectNamedPipe error : %d",
-				(int)GetLastError());
+
+	if (conn->handle != INVALID_HANDLE_VALUE) {
+		upsdebugx(4, "%s: calling DisconnectNamedPipe() for not-yet-invalid conn->handle", __func__);
+		if (DisconnectNamedPipe(conn->handle) == 0) {
+			upslog_with_errno(LOG_ERR, "DisconnectNamedPipe failed");
 		}
+		upsdebugx(4, "%s: calling CloseHandle() for conn->handle", __func__);
 		CloseHandle(conn->handle);
 		conn->handle = INVALID_HANDLE_VALUE;
 	}
+
 	if (conn->prev) {
 		conn->prev->next = conn->next;
 	} else {
@@ -625,8 +653,8 @@ int pipe_ready(pipe_conn_t *conn)
 	BOOL    res;
 
 	res = GetOverlappedResult(conn->handle, &conn->overlapped, &bytesRead, FALSE);
-	if( res == 0 ) {
-		upslogx(LOG_ERR, "Pipe read error");
+	if (res == 0) {
+		upslog_with_errno(LOG_ERR, "Pipe read error");
 		pipe_disconnect(conn);
 		return 0;
 	}
@@ -639,31 +667,37 @@ int send_to_named_pipe(const char * pipe_name, const char * data)
 	HANDLE pipe;
 	BOOL result = FALSE;
 	DWORD bytesWritten = 0;
-	char buf[SMALLBUF];
+	char pipe_full_name[NUT_PATH_MAX + 1];
 
-	snprintf(buf, sizeof(buf), "\\\\.\\pipe\\%s", pipe_name);
+	snprintf(pipe_full_name, sizeof(pipe_full_name), "\\\\.\\pipe\\%s", pipe_name);
 
+	upsdebugx(6, "%s: posting to NAMED_PIPE: '%s'", __func__, pipe_full_name);
 	pipe = CreateFile(
-			buf,
-			GENERIC_WRITE,
-			0,			/* no sharing */
-			NULL,			/* default security attributes FIXME */
-			OPEN_EXISTING,		/* opens existing pipe */
-			FILE_FLAG_OVERLAPPED,	/* enable async IO */
-			NULL);			/* no template file */
-
+		pipe_full_name,
+		GENERIC_WRITE,
+		0,			/* no sharing */
+		NULL,			/* default security attributes FIXME */
+		OPEN_EXISTING,		/* opens existing pipe */
+		FILE_FLAG_OVERLAPPED,	/* enable async IO */
+		NULL);			/* no template file */
 
 	if (pipe == INVALID_HANDLE_VALUE) {
+		upsdebug_with_errno(1,
+			"%s: SKIP: can't open existing NAMED_PIPE: '%s'",
+			__func__, pipe_full_name);
+
 		return 1;
 	}
 
 	result = WriteFile (pipe,data,strlen(data)+1,&bytesWritten,NULL);
 
 	if (result == 0 || bytesWritten != strlen(data)+1 ) {
+		upsdebug_with_errno(6, "%s: closing event log NAMED_PIPE, did not write as much as expected to", __func__);
 		CloseHandle(pipe);
 		return 1;
 	}
 
+	upsdebugx(6, "%s: closing event log NAMED_PIPE", __func__);
 	CloseHandle(pipe);
 	return 0;
 }
@@ -723,7 +757,12 @@ int w32_getcomm ( serial_handler_t * h, int * flags )
 void overlapped_setup (serial_handler_t * sh)
 {
 	memset (&sh->io_status, 0, sizeof (sh->io_status));
-	sh->io_status.hEvent = CreateEvent (NULL, TRUE, FALSE, NULL);
+	sh->io_status.hEvent = CreateEvent (
+		NULL,	/* Security */
+		TRUE,	/* auto-reset */
+		FALSE,	/* initial state = non signaled */
+		NULL	/* no name */
+	);
 	sh->overlapped_armed = 0;
 }
 
@@ -873,7 +912,12 @@ int w32_serial_write (serial_handler_t * sh, const void *ptr, size_t len)
 	errno = 0;
 
 	memset (&write_status, 0, sizeof (write_status));
-	write_status.hEvent = CreateEvent (NULL, TRUE, FALSE, NULL);
+	write_status.hEvent = CreateEvent (
+		NULL,	/* Security */
+		TRUE,	/* auto-reset */
+		FALSE,	/* initial state = non signaled */
+		NULL	/* no name */
+	);
 
 	for (;;)
 	{
@@ -923,7 +967,7 @@ serial_handler_t * w32_serial_open (const char *name, int flags)
 	memset(sh,0,sizeof(serial_handler_t));
 
 	sh->handle = CreateFile(name,
-		GENERIC_READ|GENERIC_WRITE,
+		GENERIC_READ | GENERIC_WRITE,
 		0, 0, OPEN_EXISTING,
 		FILE_ATTRIBUTE_NORMAL | FILE_FLAG_OVERLAPPED,
 		0);