From ce8d9be9ca238aa45272fda94040275e30248708 Mon Sep 17 00:00:00 2001 From: Daniel Collins Date: Sun, 3 Nov 2024 12:37:56 +0000 Subject: [PATCH] Stream logs back to test script in 30-ip-ipx.t --- mkstubs.pl | 30 ++++++- src/common.c | 36 ++++++-- src/common.h | 3 +- src/config.c | 6 ++ src/config.h | 4 +- src/directplay.c | 6 +- src/dpwsockx_stubs.txt | 11 +++ src/ipxwrapper.c | 2 + src/ipxwrapper_stubs.txt | 11 +++ src/log.c | 121 +++++++++++++++++++------- src/mswsock_stubs.txt | 11 +++ src/stubdll.c | 2 + src/wsock32_stubs.txt | 11 +++ tests/30-ip-ipx.t | 22 +++++ tests/lib/IPXWrapper/LogServer.pm | 135 ++++++++++++++++++++++++++++++ 15 files changed, 370 insertions(+), 41 deletions(-) create mode 100644 tests/lib/IPXWrapper/LogServer.pm diff --git a/mkstubs.pl b/mkstubs.pl index 90e3ea8..431487b 100644 --- a/mkstubs.pl +++ b/mkstubs.pl @@ -1,5 +1,5 @@ # IPXWrapper - Generate assembly stub functions -# Copyright (C) 2008-2023 Daniel Collins +# Copyright (C) 2008-2024 Daniel Collins # # This program is free software; you can redistribute it and/or modify it # under the terms of the GNU General Public License version 2 as published by @@ -72,6 +72,7 @@ print CODE <<"END"; extern _QueryPerformanceCounter\@4 extern _find_sym +extern _find_sym_direct extern _log_call extern _fprof_record_timed extern _fprof_record_untimed @@ -146,7 +147,32 @@ END foreach my $func(@stubs) { - if(defined $func->{params}) + if($func->{name} =~ m/_DIRECT$/) + { + # XXX_DIRECT functions jump straight to the target function without any logging to + # avoid unintended recursion within our own code. + + print CODE <<"END"; + global _$func->{name} + _$func->{name}: + ; Check if we have address cached + cmp dword [$func->{name}_addr], 0 + jne $func->{name}_go + + ; Fetch target function address + push $func->{name}_target_func + push dword $func->{target_dll_index} + call _find_sym_direct + mov dword [$func->{name}_addr], eax + + $func->{name}_go: + + ; Jump into target function. We have left the stack as we found it + ; so it can take over our frame. + jmp [$func->{name}_addr] +END + } + elsif(defined $func->{params}) { my $to_copy = $func->{params}; diff --git a/src/common.c b/src/common.c index ca00218..508f0a3 100644 --- a/src/common.c +++ b/src/common.c @@ -312,15 +312,20 @@ bool reg_set_string(HKEY key, const char *name, const char *value) return false; } -void load_dll(unsigned int dllnum) { +void load_dll(unsigned int dllnum, bool direct) { char path[512]; const char *dll; if(dllnum && dllnum != 5) { GetSystemDirectory(path, sizeof(path)); - if(strlen(path) + strlen(dll_names[dllnum]) + 2 > sizeof(path)) { - log_printf(LOG_ERROR, "Path buffer too small, cannot load %s", dll_names[dllnum]); + if(strlen(path) + strlen(dll_names[dllnum]) + 2 > sizeof(path)) + { + if(!direct) + { + log_printf(LOG_ERROR, "Path buffer too small, cannot load %s", dll_names[dllnum]); + } + abort(); } @@ -334,8 +339,13 @@ void load_dll(unsigned int dllnum) { } dll_handles[dllnum] = LoadLibrary(dll); - if(!dll_handles[dllnum]) { - log_printf(LOG_ERROR, "Error loading %s: %s", dll, w32_error(GetLastError())); + if(!dll_handles[dllnum]) + { + if(!direct) + { + log_printf(LOG_ERROR, "Error loading %s: %s", dll, w32_error(GetLastError())); + } + abort(); } } @@ -363,7 +373,7 @@ void unload_dlls(void) { void __stdcall *find_sym(unsigned int dllnum, const char *symbol) { if(!dll_handles[dllnum]) { - load_dll(dllnum); + load_dll(dllnum, false); } void *ptr = GetProcAddress(dll_handles[dllnum], symbol); @@ -375,6 +385,20 @@ void __stdcall *find_sym(unsigned int dllnum, const char *symbol) { return ptr; } +void __stdcall *find_sym_direct(unsigned int dllnum, const char *symbol) { + if(!dll_handles[dllnum]) { + load_dll(dllnum, true); + } + + void *ptr = GetProcAddress(dll_handles[dllnum], symbol); + if(!ptr) + { + abort(); + } + + return ptr; +} + void __stdcall log_call(unsigned int entry, const char *symbol, unsigned int target) { log_printf(LOG_CALL, "%s:%s -> %s", dll_names[entry], symbol, dll_names[target]); diff --git a/src/common.h b/src/common.h index 7cdb589..d86f0ab 100644 --- a/src/common.h +++ b/src/common.h @@ -70,7 +70,7 @@ bool reg_set_addr48(HKEY key, const char *name, addr48_t value); char *reg_get_string(HKEY key, const char *name, const char *default_value); bool reg_set_string(HKEY key, const char *name, const char *value); -void load_dll(unsigned int dllnum); +void load_dll(unsigned int dllnum, bool direct); void unload_dlls(void); void __stdcall *find_sym(unsigned int dllnum, const char *symbol); void __stdcall log_call(unsigned int entry, const char *symbol, unsigned int target); @@ -85,6 +85,7 @@ bool windows_at_least_2000(); void log_init(); void log_open(const char *file); void log_close(); +void log_connect(const char *log_server_addr, uint16_t log_server_port); void log_printf(enum ipx_log_level level, const char *fmt, ...); #ifdef __cplusplus diff --git a/src/config.c b/src/config.c index 98c8295..68fe557 100644 --- a/src/config.c +++ b/src/config.c @@ -39,6 +39,9 @@ main_config_t get_main_config(bool ignore_ini) config.log_level = LOG_INFO; config.profile = false; + config.log_server_addr = NULL; + config.log_server_port = 0; + config.dosbox_server_addr = NULL; config.dosbox_server_port = 213; config.dosbox_coalesce = false; @@ -96,6 +99,9 @@ main_config_t get_main_config(bool ignore_ini) config.log_level = reg_get_dword(reg, "log_level", config.log_level); config.profile = reg_get_dword(reg, "profile", config.profile); + config.log_server_addr = reg_get_string(reg, "log_server_addr", ""); + config.log_server_port = reg_get_dword(reg, "log_server_port", config.log_server_port); + config.dosbox_server_addr = reg_get_string(reg, "dosbox_server_addr", ""); config.dosbox_server_port = reg_get_dword(reg, "dosbox_server_port", config.dosbox_server_port); config.dosbox_coalesce = reg_get_dword(reg, "dosbox_coalesce", config.dosbox_coalesce); diff --git a/src/config.h b/src/config.h index 247b24f..8c7bcb2 100644 --- a/src/config.h +++ b/src/config.h @@ -1,5 +1,5 @@ /* ipxwrapper - Configuration header - * Copyright (C) 2011-2021 Daniel Collins + * Copyright (C) 2011-2024 Daniel Collins * * This program is free software; you can redistribute it and/or modify it * under the terms of the GNU General Public License version 2 as published by @@ -54,6 +54,8 @@ typedef struct main_config { enum ipx_log_level log_level; bool profile; + char *log_server_addr; + uint16_t log_server_port; } main_config_t; struct v1_global_config { diff --git a/src/directplay.c b/src/directplay.c index 831c424..51961a5 100644 --- a/src/directplay.c +++ b/src/directplay.c @@ -727,7 +727,11 @@ BOOL WINAPI DllMain(HINSTANCE hinstDLL, DWORD fdwReason, LPVOID lpvReserved) { log_init(); - min_log_level = get_main_config(false).log_level; + main_config_t config = get_main_config(false); + + min_log_level = config.log_level; + + log_connect(config.log_server_addr, config.log_server_port); } else if(fdwReason == DLL_PROCESS_DETACH) { diff --git a/src/dpwsockx_stubs.txt b/src/dpwsockx_stubs.txt index ef627aa..833d206 100644 --- a/src/dpwsockx_stubs.txt +++ b/src/dpwsockx_stubs.txt @@ -8,3 +8,14 @@ WSACloseEvent ws2_32.dll WSACloseEvent WSAEventSelect ws2_32.dll WSAEventSelect WSAResetEvent ws2_32.dll WSAResetEvent WSASetEvent ws2_32.dll WSASetEvent + +wsock32_closesocket_DIRECT wsock32.dll closesocket 4 +wsock32_connect_DIRECT wsock32.dll connect 12 +wsock32_htons_DIRECT wsock32.dll htons 4 +wsock32_inet_addr_DIRECT wsock32.dll inet_addr 4 +wsock32_send_DIRECT wsock32.dll send 16 +wsock32_setsockopt_DIRECT wsock32.dll setsockopt 20 +wsock32_socket_DIRECT wsock32.dll socket 12 +wsock32_WSAGetLastError_DIRECT wsock32.dll WSAGetLastError 0 +wsock32_WSASetLastError_DIRECT wsock32.dll WSASetLastError 4 +wsock32_WSAStartup_DIRECT wsock32.dll WSAStartup 8 diff --git a/src/ipxwrapper.c b/src/ipxwrapper.c index f16aa0e..635b3f2 100644 --- a/src/ipxwrapper.c +++ b/src/ipxwrapper.c @@ -124,6 +124,8 @@ BOOL WINAPI DllMain(HINSTANCE hinstDLL, DWORD fdwReason, LPVOID lpvReserved) min_log_level = main_config.log_level; ipx_encap_type = main_config.encap_type; + log_connect(main_config.log_server_addr, main_config.log_server_port); + log_printf(LOG_INFO, "IPXWrapper %s", version_string); log_printf(LOG_INFO, "Compiled at %s", compile_time); log_printf(LOG_INFO, "Performance counter: %lld Hz", perf_counter_freq); diff --git a/src/ipxwrapper_stubs.txt b/src/ipxwrapper_stubs.txt index 67e9661..628f0e2 100644 --- a/src/ipxwrapper_stubs.txt +++ b/src/ipxwrapper_stubs.txt @@ -48,3 +48,14 @@ pcap_getevent wpcap.dll pcap_getevent pcap_dispatch wpcap.dll pcap_dispatch pcap_geterr wpcap.dll pcap_geterr pcap_sendpacket wpcap.dll pcap_sendpacket + +wsock32_closesocket_DIRECT wsock32.dll closesocket 4 +wsock32_connect_DIRECT wsock32.dll connect 12 +wsock32_htons_DIRECT wsock32.dll htons 4 +wsock32_inet_addr_DIRECT wsock32.dll inet_addr 4 +wsock32_send_DIRECT wsock32.dll send 16 +wsock32_setsockopt_DIRECT wsock32.dll setsockopt 20 +wsock32_socket_DIRECT wsock32.dll socket 12 +wsock32_WSAGetLastError_DIRECT wsock32.dll WSAGetLastError 0 +wsock32_WSASetLastError_DIRECT wsock32.dll WSASetLastError 4 +wsock32_WSAStartup_DIRECT wsock32.dll WSAStartup 8 diff --git a/src/log.c b/src/log.c index b6ef0c2..8d701ec 100644 --- a/src/log.c +++ b/src/log.c @@ -27,6 +27,18 @@ static HANDLE log_fh = NULL; static HANDLE log_mutex = NULL; +static int log_sock = -1; + +int wsock32_WSAStartup_DIRECT(WORD wVersionRequired, LPWSADATA lpWSAData); +SOCKET WSAAPI wsock32_socket_DIRECT(int af, int type, int protocol); +int PASCAL wsock32_connect_DIRECT(SOCKET s, const struct sockaddr *name, int namelen); +unsigned long WSAAPI wsock32_inet_addr_DIRECT(const char *cp); +u_short WSAAPI wsock32_htons_DIRECT(u_short hostshort); +int WSAAPI wsock32_closesocket_DIRECT(SOCKET s); +int PASCAL wsock32_send_DIRECT(SOCKET s, const char *buf, int len, int flags); +int WSAAPI wsock32_setsockopt_DIRECT(SOCKET s, int level, int optname, const char *optval, int optlen); +int WSAAPI wsock32_WSAGetLastError_DIRECT(); +void WSAAPI wsock32_WSASetLastError_DIRECT(int iError); void log_init() { @@ -64,12 +76,55 @@ void log_open(const char *file) { } } +void log_connect(const char *log_server_addr, uint16_t log_server_port) +{ + if(strcmp(log_server_addr, "") == 0) + { + return; + } + + WSADATA wsdata; + int err = wsock32_WSAStartup_DIRECT(MAKEWORD(1,1), &wsdata); + if(err) + { + return; + } + + log_sock = wsock32_socket_DIRECT(AF_INET, SOCK_STREAM, 0); + if(log_sock == -1) + { + return; + } + + struct sockaddr_in addr; + memset(&addr, 0, sizeof(addr)); + + addr.sin_family = AF_INET; + addr.sin_addr.s_addr = wsock32_inet_addr_DIRECT(log_server_addr); + addr.sin_port = wsock32_htons_DIRECT(log_server_port); + + if(wsock32_connect_DIRECT(log_sock, (const struct sockaddr*)(&addr), sizeof(addr)) != 0) + { + wsock32_closesocket_DIRECT(log_sock); + log_sock = -1; + } + + DWORD nodelay = TRUE; + wsock32_setsockopt_DIRECT(log_sock, IPPROTO_TCP, TCP_NODELAY, (const char*)(&nodelay), sizeof(nodelay)); +} + void log_close() { if(log_fh) { CloseHandle(log_fh); log_fh = NULL; } + if(log_sock != -1) + { + wsock32_closesocket_DIRECT(log_sock); + log_sock = -1; + } + if(log_mutex) { CloseHandle(log_mutex); log_mutex = NULL; @@ -89,11 +144,6 @@ void log_printf(enum ipx_log_level level, const char *fmt, ...) { log_open("ipxwrapper.log"); } - if(!log_fh) { - ReleaseMutex(log_mutex); - return; - } - va_list argv; static char line[1024]; @@ -107,34 +157,45 @@ void log_printf(enum ipx_log_level level, const char *fmt, ...) { memcpy((line + line_len), "\r\n", 2); line_len += 2; - /* File locking isn't implemented on Windows 98, so we instead use a - * single global mutex to syncronise log file access between all - * processes and skip the file locking. - */ - bool use_locking = windows_at_least_2000(); - - if(use_locking) + if(log_sock != -1) { - OVERLAPPED off; - off.Offset = 0; - off.OffsetHigh = 0; - off.hEvent = 0; + /* send() will reset the error code, so save it. */ + DWORD saved_error = wsock32_WSAGetLastError_DIRECT(); + wsock32_send_DIRECT(log_sock, line, line_len, 0); + wsock32_WSASetLastError_DIRECT(saved_error); + } + + if(log_fh != NULL) + { + /* File locking isn't implemented on Windows 98, so we instead use a + * single global mutex to syncronise log file access between all + * processes and skip the file locking. + */ + bool use_locking = windows_at_least_2000(); - // ERROR_CALL_NOT_IMPLEMENTED - if(!LockFileEx(log_fh, LOCKFILE_EXCLUSIVE_LOCK, 0, 1, 0, &off)) { - ReleaseMutex(log_mutex); - return; + if(use_locking) + { + OVERLAPPED off; + off.Offset = 0; + off.OffsetHigh = 0; + off.hEvent = 0; + + // ERROR_CALL_NOT_IMPLEMENTED + if(!LockFileEx(log_fh, LOCKFILE_EXCLUSIVE_LOCK, 0, 1, 0, &off)) { + ReleaseMutex(log_mutex); + return; + } + } + + if(SetFilePointer(log_fh, 0, NULL, FILE_END) != INVALID_SET_FILE_POINTER) { + DWORD written; + WriteFile(log_fh, line, line_len, &written, NULL); + } + + if(use_locking) + { + UnlockFile(log_fh, 0, 0, 1, 0); } - } - - if(SetFilePointer(log_fh, 0, NULL, FILE_END) != INVALID_SET_FILE_POINTER) { - DWORD written; - WriteFile(log_fh, line, line_len, &written, NULL); - } - - if(use_locking) - { - UnlockFile(log_fh, 0, 0, 1, 0); } ReleaseMutex(log_mutex); diff --git a/src/mswsock_stubs.txt b/src/mswsock_stubs.txt index 56d2ef6..27b9980 100644 --- a/src/mswsock_stubs.txt +++ b/src/mswsock_stubs.txt @@ -35,3 +35,14 @@ sethostname mswsock.dll sethostname inet_addr mswsock.dll inet_addr 4 WSHEnumProtocols ipxwrapper.dll WSHEnumProtocols 16 ntohs wsock32.dll ntohs 4 + +wsock32_closesocket_DIRECT wsock32.dll closesocket 4 +wsock32_connect_DIRECT wsock32.dll connect 12 +wsock32_htons_DIRECT wsock32.dll htons 4 +wsock32_inet_addr_DIRECT wsock32.dll inet_addr 4 +wsock32_send_DIRECT wsock32.dll send 16 +wsock32_setsockopt_DIRECT wsock32.dll setsockopt 20 +wsock32_socket_DIRECT wsock32.dll socket 12 +wsock32_WSAGetLastError_DIRECT wsock32.dll WSAGetLastError 0 +wsock32_WSASetLastError_DIRECT wsock32.dll WSASetLastError 4 +wsock32_WSAStartup_DIRECT wsock32.dll WSAStartup 8 diff --git a/src/stubdll.c b/src/stubdll.c index e6da58a..49574b9 100644 --- a/src/stubdll.c +++ b/src/stubdll.c @@ -39,6 +39,8 @@ BOOL WINAPI DllMain(HINSTANCE hinstDLL, DWORD fdwReason, LPVOID lpvReserved) { min_log_level = config.log_level; + log_connect(config.log_server_addr, config.log_server_port); + if(config.profile) { stubs_enable_profile = true; diff --git a/src/wsock32_stubs.txt b/src/wsock32_stubs.txt index cdd42a2..f0b5eac 100644 --- a/src/wsock32_stubs.txt +++ b/src/wsock32_stubs.txt @@ -81,3 +81,14 @@ Asend wsock32.dll Asend NSPStartup wsock32.dll NSPStartup WsControl wsock32.dll WsControl closesockinfo wsock32.dll closesockinfo + +wsock32_closesocket_DIRECT wsock32.dll closesocket 4 +wsock32_connect_DIRECT wsock32.dll connect 12 +wsock32_htons_DIRECT wsock32.dll htons 4 +wsock32_inet_addr_DIRECT wsock32.dll inet_addr 4 +wsock32_send_DIRECT wsock32.dll send 16 +wsock32_setsockopt_DIRECT wsock32.dll setsockopt 20 +wsock32_socket_DIRECT wsock32.dll socket 12 +wsock32_WSAGetLastError_DIRECT wsock32.dll WSAGetLastError 0 +wsock32_WSASetLastError_DIRECT wsock32.dll WSASetLastError 4 +wsock32_WSAStartup_DIRECT wsock32.dll WSAStartup 8 diff --git a/tests/30-ip-ipx.t b/tests/30-ip-ipx.t index e2c1443..324efe2 100644 --- a/tests/30-ip-ipx.t +++ b/tests/30-ip-ipx.t @@ -23,6 +23,7 @@ use FindBin; use lib "$FindBin::Bin/lib/"; use IPXWrapper::Capture::IPXOverUDP; +use IPXWrapper::LogServer; use IPXWrapper::Tool::IPXISR; use IPXWrapper::Tool::IPXRecv; use IPXWrapper::Util; @@ -58,6 +59,27 @@ describe "IPXWrapper using IP encapsulation" => sub $node_c_net = "00:00:00:02"; }; + my $log = undef; + + before each => sub + { + $log = IPXWrapper::LogServer->new(); + + reg_set_string($remote_ip_a, "HKCU\\Software\\IPXWrapper", "log_server_addr", $local_ip_a); + reg_set_dword( $remote_ip_a, "HKCU\\Software\\IPXWrapper", "log_server_port", $log->port()); + }; + + after each => sub + { + # TODO: Call this if the test succeeded. + # + # If a test fails due to an exception, the after blocks won't be called, however a + # test failing due to an assertion still calls the after blocks. I haven't found + # any way to actually determine if the test passed from code. + + # $log->discard(); + }; + describe "packets received on the shared port" => sub { they "are only accepted from the bound interface" => sub diff --git a/tests/lib/IPXWrapper/LogServer.pm b/tests/lib/IPXWrapper/LogServer.pm new file mode 100644 index 0000000..63cdc83 --- /dev/null +++ b/tests/lib/IPXWrapper/LogServer.pm @@ -0,0 +1,135 @@ +# IPXWrapper test suite +# Copyright (C) 2024 Daniel Collins +# +# This program is free software; you can redistribute it and/or modify it +# under the terms of the GNU General Public License version 2 as published by +# the Free Software Foundation. +# +# This program is distributed in the hope that it will be useful, but WITHOUT +# ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or +# FITNESS FOR A PARTICULAR PURPOSE. See the GNU General Public License for +# more details. +# +# You should have received a copy of the GNU General Public License along with +# this program; if not, write to the Free Software Foundation, Inc., 51 +# Franklin Street, Fifth Floor, Boston, MA 02110-1301, USA. + +use strict; +use warnings; + +package IPXWrapper::LogServer; + +use POSIX qw(:signal_h); + +use IO::Select; +use IO::Socket::INET; + +sub new +{ + my ($class) = @_; + + my $listener = IO::Socket::INET->new( + Listen => 10, + LocalAddr => "0.0.0.0", + LocalPort => 0, + Proto => "tcp"); + + my $pid = fork() // die "fork: $!"; + + if($pid == 0) + { + my $logbuf = ""; + my @clients = (); + + $SIG{TERM} = sub + { + exit(0); + }; + + $SIG{USR1} = sub + { + print STDERR $logbuf; + $logbuf = ""; + + exit(0); + }; + + my $select = IO::Select->new(); + $select->add($listener); + + while(1) + { + my @ready = $select->can_read(); + + foreach my $sock(@ready) + { + if($sock eq $listener) + { + my $new_sock = $listener->accept(); + + push(@clients, { sock => $new_sock, buf => "" }); + $select->add($new_sock); + } + else{ + my ($client) = grep { $_->{sock} eq $sock } @clients; + + my $buf = ""; + if(defined($sock->recv($buf, 1024)) && length($buf) > 0) + { + $client->{buf} .= $buf; + + if($client->{buf} =~ m/\n/) + { + my ($buf1, $buf2) = ($client->{buf} =~ m/^(.*\n)([^\n]*)$/s); + + # print STDERR "> $buf1"; + + $logbuf .= $buf1; + $client->{buf} = $buf2; + } + } + else{ + $select->remove($sock); + @clients = grep { $_->{sock} ne $sock } @clients; + } + } + } + } + } + + return bless({ listener => $listener, pid => $pid }, $class); +} + +sub port +{ + my ($self) = @_; + return $self->{listener}->sockport(); +} + +sub discard +{ + my ($self) = @_; + + if(defined $self->{pid}) + { + kill(SIGTERM, $self->{pid}); + waitpid($self->{pid}, 0); + + delete $self->{pid}; + } +} + +sub DESTROY +{ + my ($self) = @_; + + if(defined $self->{pid}) + { + kill(SIGUSR1, $self->{pid}); + waitpid($self->{pid}, 0); + + delete $self->{pid}; + } +} + +1;