diff mbox series

[4/7] simple-ipc/ipc-win32: add trace2 debugging

Message ID 30b7bb247c3c8531119f99e293d84b1836297251.1631738177.git.gitgitgadget@gmail.com (mailing list archive)
State Superseded
Headers show
Series Builtin FSMonitor Part 1 | expand

Commit Message

Jeff Hostetler Sept. 15, 2021, 8:36 p.m. UTC 
From: Jeff Hostetler <jeffhost@microsoft.com>

Create "ipc-debug" category events to log unexpected errors
when creating Simple-IPC connections.

Signed-off-by: Jeff Hostetler <jeffhost@microsoft.com>
---
 compat/simple-ipc/ipc-win32.c | 22 ++++++++++++++++++++++
 1 file changed, 22 insertions(+)

Comments

Ævar Arnfjörð Bjarmason Sept. 16, 2021, 5:40 a.m. UTC | #1 
On Wed, Sep 15 2021, Jeff Hostetler via GitGitGadget wrote:

> @@ -112,6 +115,11 @@ static enum ipc_active_state connect_to_server(
>  				if (GetLastError() == ERROR_SEM_TIMEOUT)
>  					return IPC_STATE__NOT_LISTENING;
>  
> +				gle = GetLastError();
> +				trace2_data_intmax("ipc-debug", NULL,
> +						   "connect/waitpipe/gle",
> +						   (intmax_t)gle);
> +
>  				return IPC_STATE__OTHER_ERROR;
>  			}
>  

I've never used this Win32 API (or well, any Win32 API) but I'm guessing
that GetLastError() isn't here to check an error in GetLastError() itself.

Earlier in this function added in your 59c7b88198a (simple-ipc: add
win32 implementation, 2021-03-15) we assign to "gle", I'd really expect...:

>  	if (!SetNamedPipeHandleState(hPipe, &mode, NULL, NULL)) {
> +		gle = GetLastError();
> +		trace2_data_intmax("ipc-debug", NULL,
> +				   "connect/setpipestate/gle",
> +				   (intmax_t)gle);
> +
>  		CloseHandle(hPipe);
>  		return IPC_STATE__OTHER_ERROR;
>  	}
>  
>  	*pfd = _open_osfhandle((intptr_t)hPipe, O_RDWR|O_BINARY);
>  	if (*pfd < 0) {
> +		gle = GetLastError();
> +		trace2_data_intmax("ipc-debug", NULL,
> +				   "connect/openosfhandle/gle",
> +				   (intmax_t)gle);
> +
>  		CloseHandle(hPipe);
>  		return IPC_STATE__OTHER_ERROR;
>  	}

...something that looks exactly like this. I.e. as shown by the below
hunk-at-the-end, as it is I'm either missing some subtlety that could
really use explaining. I.e. this reads like:

    int saved_errno = errno;
    if (syscall()) {
        if (errno)
            die("bad");
        saved_errno = errno;
        log_it("...%d", saved_errno);
    }

When surely we want either of:

    int saved_errno = errno;
    if (syscall()) {
        if (errno)
            die("bad");
        log_it("...%d", errno);
    }

Or better yet (and consistent with the rest of your code):

    int saved_errno = errno;
    if (syscall()) {
        saved_errno = errno;
        if (saved_errno)
            die("bad");
        log_it("...%d", saved_errno);
    }

diff --git a/compat/simple-ipc/ipc-win32.c b/compat/simple-ipc/ipc-win32.c
index 8dc7bda087d..b0c422e4867 100644
--- a/compat/simple-ipc/ipc-win32.c
+++ b/compat/simple-ipc/ipc-win32.c
@@ -109,9 +109,12 @@ static enum ipc_active_state connect_to_server(
 			t_start_ms = (DWORD)(getnanotime() / 1000000);
 
 			if (!WaitNamedPipeW(wpath, timeout_ms)) {
-				if (GetLastError() == ERROR_SEM_TIMEOUT)
+				gle = GetLastError();
+				if (gle == ERROR_SEM_TIMEOUT)
 					return IPC_STATE__NOT_LISTENING;
 
+				/* ...rest of your patch */
+
 				return IPC_STATE__OTHER_ERROR;
 			}
Jeff Hostetler Sept. 17, 2021, 5:27 p.m. UTC | #2 
On 9/16/21 1:40 AM, Ævar Arnfjörð Bjarmason wrote:
> 
> On Wed, Sep 15 2021, Jeff Hostetler via GitGitGadget wrote:
> 
>> @@ -112,6 +115,11 @@ static enum ipc_active_state connect_to_server(
>>   				if (GetLastError() == ERROR_SEM_TIMEOUT)
>>   					return IPC_STATE__NOT_LISTENING;
>>   
>> +				gle = GetLastError();
>> +				trace2_data_intmax("ipc-debug", NULL,
>> +						   "connect/waitpipe/gle",
>> +						   (intmax_t)gle);
>> +
>>   				return IPC_STATE__OTHER_ERROR;
>>   			}
>>   
>... 
 >
> @@ -109,9 +109,12 @@ static enum ipc_active_state connect_to_server(
>   			t_start_ms = (DWORD)(getnanotime() / 1000000);
>   
>   			if (!WaitNamedPipeW(wpath, timeout_ms)) {
> -				if (GetLastError() == ERROR_SEM_TIMEOUT)
> +				gle = GetLastError();
> +				if (gle == ERROR_SEM_TIMEOUT)
>   					return IPC_STATE__NOT_LISTENING;
>   
> +				/* ...rest of your patch */
> +
>   				return IPC_STATE__OTHER_ERROR;
>   			}
>   
> 

Yeah, I was just trying to minimize the size of the diff
and at the time was considering those debug messages to be
temporary, but I kind of like having them so it makes sense
to clean up a bit as you've indicated.

Thanks
Jeff
diff mbox series

Patch

diff --git a/compat/simple-ipc/ipc-win32.c b/compat/simple-ipc/ipc-win32.c
index 8e889d6a506..6c8a308de13 100644
--- a/compat/simple-ipc/ipc-win32.c
+++ b/compat/simple-ipc/ipc-win32.c
@@ -49,6 +49,9 @@  static enum ipc_active_state get_active_state(wchar_t *pipe_path)
 	if (GetLastError() == ERROR_FILE_NOT_FOUND)
 		return IPC_STATE__PATH_NOT_FOUND;
 
+	trace2_data_intmax("ipc-debug", NULL, "getstate/waitpipe/gle",
+			   (intmax_t)GetLastError());
+
 	return IPC_STATE__OTHER_ERROR;
 }
 
@@ -112,6 +115,11 @@  static enum ipc_active_state connect_to_server(
 				if (GetLastError() == ERROR_SEM_TIMEOUT)
 					return IPC_STATE__NOT_LISTENING;
 
+				gle = GetLastError();
+				trace2_data_intmax("ipc-debug", NULL,
+						   "connect/waitpipe/gle",
+						   (intmax_t)gle);
+
 				return IPC_STATE__OTHER_ERROR;
 			}
 
@@ -133,17 +141,31 @@  static enum ipc_active_state connect_to_server(
 			break; /* try again */
 
 		default:
+			trace2_data_intmax("ipc-debug", NULL,
+					   "connect/createfile/gle",
+					   (intmax_t)gle);
+
 			return IPC_STATE__OTHER_ERROR;
 		}
 	}
 
 	if (!SetNamedPipeHandleState(hPipe, &mode, NULL, NULL)) {
+		gle = GetLastError();
+		trace2_data_intmax("ipc-debug", NULL,
+				   "connect/setpipestate/gle",
+				   (intmax_t)gle);
+
 		CloseHandle(hPipe);
 		return IPC_STATE__OTHER_ERROR;
 	}
 
 	*pfd = _open_osfhandle((intptr_t)hPipe, O_RDWR|O_BINARY);
 	if (*pfd < 0) {
+		gle = GetLastError();
+		trace2_data_intmax("ipc-debug", NULL,
+				   "connect/openosfhandle/gle",
+				   (intmax_t)gle);
+
 		CloseHandle(hPipe);
 		return IPC_STATE__OTHER_ERROR;
 	}