diff --git a/Makefile b/Makefile index 30fcda8..c821358 100644 --- a/Makefile +++ b/Makefile @@ -17,7 +17,7 @@ CFLAGS := -Wall CXXFLAGS := -Wall -IPXWRAPPER_DEPS := src/ipxwrapper.o src/winsock.o src/ipxwrapper_stubs.o src/ipxwrapper.def +IPXWRAPPER_DEPS := src/ipxwrapper.o src/winsock.o src/ipxwrapper_stubs.o src/log.o src/ipxwrapper.def all: ipxwrapper.dll wsock32.dll mswsock.dll ipxconfig.exe @@ -46,7 +46,7 @@ src/wsock32_stubs.s: src/wsock32_stubs.txt src/mswsock_stubs.s: src/mswsock_stubs.txt perl mkstubs.pl src/mswsock_stubs.txt src/mswsock_stubs.s mswsock.dll -%.dll: src/stubdll.o src/%_stubs.o src/%.def +%.dll: src/stubdll.o src/%_stubs.o src/log.o src/%.def $(CC) $(CFLAGS) -Wl,--enable-stdcall-fixup,-s -shared -o $@ $^ src/%_stubs.o: src/%_stubs.s diff --git a/changes.txt b/changes.txt index 50997cf..d878b47 100644 --- a/changes.txt +++ b/changes.txt @@ -14,6 +14,11 @@ Version 0.2.1: Bugfix: Store correct DLL name in stub DLLs. Cleanup: Replace assert calls with proper error checks in ipxconfig. + + Cleanup: Cleaned up logging code and added timestamps using GetTickCount. + + Cleanup: Call r_ winsock calls directly in router code to prevent it from + generating extra log messages. Version 0.2: Implemented ioctlsocket() function with support for FIONREAD. diff --git a/src/ipxwrapper.c b/src/ipxwrapper.c index 02fed63..7eabcd4 100644 --- a/src/ipxwrapper.c +++ b/src/ipxwrapper.c @@ -45,7 +45,6 @@ HMODULE winsock2_dll = NULL; HMODULE mswsock_dll = NULL; HMODULE wsock32_dll = NULL; -static FILE *debug_fh = NULL; static HANDLE mutex = NULL; static HANDLE router_thread = NULL; static DWORD router_tid = 0; @@ -59,9 +58,7 @@ static BOOL load_nics(void); BOOL WINAPI DllMain(HINSTANCE me, DWORD why, LPVOID res) { if(why == DLL_PROCESS_ATTACH) { - #ifdef DEBUG - debug_fh = fopen(DEBUG, "w"); - #endif + log_open(); winsock2_dll = load_sysdll("ws2_32.dll"); mswsock_dll = load_sysdll("mswsock.dll"); @@ -81,7 +78,7 @@ BOOL WINAPI DllMain(HINSTANCE me, DWORD why, LPVOID res) { if(reg_err != ERROR_SUCCESS) { regkey = NULL; - debug("Could not open registry: %s", w32_error(reg_err)); + log_printf("Could not open registry: %s", w32_error(reg_err)); } DWORD gsize = sizeof(global_conf); @@ -99,14 +96,14 @@ BOOL WINAPI DllMain(HINSTANCE me, DWORD why, LPVOID res) { mutex = CreateMutex(NULL, FALSE, NULL); if(!mutex) { - debug("Failed to create mutex"); + log_printf("Failed to create mutex"); return FALSE; } WSADATA wsdata; int err = WSAStartup(MAKEWORD(1,1), &wsdata); if(err) { - debug("Failed to initialize winsock: %s", w32_error(err)); + log_printf("Failed to initialize winsock: %s", w32_error(err)); return FALSE; } @@ -142,6 +139,8 @@ BOOL WINAPI DllMain(HINSTANCE me, DWORD why, LPVOID res) { DLL_UNLOAD(winsock2_dll); DLL_UNLOAD(mswsock_dll); DLL_UNLOAD(wsock32_dll); + + log_close(); } return TRUE; @@ -158,27 +157,13 @@ void __stdcall *find_sym(char const *symbol) { } if(!addr) { - debug("Unknown symbol: %s", symbol); + log_printf("Unknown symbol: %s", symbol); abort(); } return addr; } -void debug(char const *fmt, ...) { - char msg[1024]; - va_list argv; - - if(debug_fh) { - va_start(argv, fmt); - vsnprintf(msg, 1024, fmt, argv); - va_end(argv); - - fprintf(debug_fh, "%s\n", msg); - fflush(debug_fh); - } -} - /* Lock the mutex and search the sockets list for an ipx_socket structure with * the requested fd, if no matching fd is found, unlock the mutex * @@ -251,7 +236,7 @@ static HMODULE load_sysdll(char const *name) { ret = LoadLibrary(path); if(!ret) { - debug("Error loading %s: %s", path, w32_error(GetLastError())); + log_printf("Error loading %s: %s", path, w32_error(GetLastError())); } return ret; @@ -259,9 +244,9 @@ static HMODULE load_sysdll(char const *name) { /* Initialize and start the router thread */ static int init_router(void) { - net_fd = socket(AF_INET, SOCK_DGRAM, 0); + net_fd = r_socket(AF_INET, SOCK_DGRAM, 0); if(net_fd == -1) { - debug("Failed to create network socket: %s", w32_error(WSAGetLastError())); + log_printf("Failed to create network socket: %s", w32_error(WSAGetLastError())); return 0; } @@ -270,27 +255,27 @@ static int init_router(void) { bind_addr.sin_addr.s_addr = INADDR_ANY; bind_addr.sin_port = htons(global_conf.udp_port); - if(bind(net_fd, (struct sockaddr*)&bind_addr, sizeof(bind_addr)) == -1) { - debug("Failed to bind network socket: %s", w32_error(WSAGetLastError())); + if(r_bind(net_fd, (struct sockaddr*)&bind_addr, sizeof(bind_addr)) == -1) { + log_printf("Failed to bind network socket: %s", w32_error(WSAGetLastError())); return 0; } BOOL broadcast = TRUE; int bufsize = 524288; /* 512KiB */ - setsockopt(net_fd, SOL_SOCKET, SO_BROADCAST, (char*)&broadcast, sizeof(BOOL)); - setsockopt(net_fd, SOL_SOCKET, SO_RCVBUF, (char*)&bufsize, sizeof(int)); - setsockopt(net_fd, SOL_SOCKET, SO_SNDBUF, (char*)&bufsize, sizeof(int)); + r_setsockopt(net_fd, SOL_SOCKET, SO_BROADCAST, (char*)&broadcast, sizeof(BOOL)); + r_setsockopt(net_fd, SOL_SOCKET, SO_RCVBUF, (char*)&bufsize, sizeof(int)); + r_setsockopt(net_fd, SOL_SOCKET, SO_SNDBUF, (char*)&bufsize, sizeof(int)); router_buf = malloc(PACKET_BUF_SIZE); if(!router_buf) { - debug("Not enough memory for router buffer (64KiB)"); + log_printf("Not enough memory for router buffer (64KiB)"); return 0; } router_thread = CreateThread(NULL, 0, &router_main, NULL, 0, &router_tid); if(!router_thread) { - debug("Failed to create router thread"); + log_printf("Failed to create router thread"); return 0; } @@ -311,9 +296,9 @@ static DWORD WINAPI router_main(LPVOID notused) { while(1) { addrlen = sizeof(addr); - rval = recvfrom(net_fd, (char*)packet, PACKET_BUF_SIZE, 0, (struct sockaddr*)&addr, &addrlen); + rval = r_recvfrom(net_fd, (char*)packet, PACKET_BUF_SIZE, 0, (struct sockaddr*)&addr, &addrlen); if(rval <= 0) { - debug("Error recieving packet: %s", w32_error(WSAGetLastError())); + log_printf("Error recieving packet: %s", w32_error(WSAGetLastError())); continue; } @@ -337,7 +322,7 @@ static DWORD WINAPI router_main(LPVOID notused) { packet->size = ntohs(packet->size); if(packet->size > MAX_PACKET_SIZE || packet->size+sizeof(ipx_packet)-1 != rval) { - debug("Recieved packet with incorrect size field, discarding"); + log_printf("Recieved packet with incorrect size field, discarding"); continue; } @@ -374,7 +359,7 @@ static DWORD WINAPI router_main(LPVOID notused) { sval = r_sendto(sockptr->fd, (char*)packet, rval, 0, (struct sockaddr*)&addr, addrlen); if(sval == -1) { - debug("Error relaying packet: %s", w32_error(WSAGetLastError())); + log_printf("Error relaying packet: %s", w32_error(WSAGetLastError())); } } } @@ -411,7 +396,7 @@ static void add_host(const unsigned char *net, const unsigned char *node, uint32 hptr = malloc(sizeof(ipx_host)); if(!hptr) { - debug("No memory for hosts list entry"); + log_printf("No memory for hosts list entry"); return; } @@ -461,7 +446,7 @@ static BOOL load_nics(void) { ipx_nic *enic = NULL; if(!ifptr) { - debug("No NICs: %s", w32_error(WSAGetLastError())); + log_printf("No NICs: %s", w32_error(WSAGetLastError())); } while(ifptr) { diff --git a/src/ipxwrapper.h b/src/ipxwrapper.h index bccdb3c..e84ccf9 100644 --- a/src/ipxwrapper.h +++ b/src/ipxwrapper.h @@ -25,8 +25,6 @@ #include "config.h" -#define DEBUG "ipxwrapper.log" - /* Maximum UDP data size is 65467, we use a smaller value to ensure we have * plenty of space to play with for headers, etc */ @@ -141,7 +139,6 @@ extern HMODULE mswsock_dll; extern HMODULE wsock32_dll; void __stdcall *find_sym(char const *sym); -void debug(char const *fmt, ...); ipx_socket *get_socket(SOCKET fd); void lock_mutex(void); void unlock_mutex(void); @@ -149,6 +146,10 @@ IP_ADAPTER_INFO *get_nics(void); char const *w32_error(DWORD errnum); ipx_host *find_host(const unsigned char *net, const unsigned char *node); +void log_open(); +void log_close(); +void log_printf(const char *fmt, ...); + INT APIENTRY r_EnumProtocolsA(LPINT,LPVOID,LPDWORD); INT APIENTRY r_EnumProtocolsW(LPINT,LPVOID,LPDWORD); int PASCAL FAR r_WSARecvEx(SOCKET,char*,int,int*); diff --git a/src/log.c b/src/log.c new file mode 100644 index 0000000..8c6aeb6 --- /dev/null +++ b/src/log.c @@ -0,0 +1,100 @@ +/* ipxwrapper - Logging functions + * Copyright (C) 2011 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. +*/ + +#include +#include +#include +#include + +#include "ipxwrapper.h" + +static HANDLE log_fh = NULL; +static HANDLE log_mutex = NULL; + +void log_open() { + if(!(log_mutex = CreateMutex(NULL, FALSE, NULL))) { + abort(); + } + + log_fh = CreateFile( + "ipxwrapper.log", + GENERIC_READ | GENERIC_WRITE, + FILE_SHARE_DELETE | FILE_SHARE_READ | FILE_SHARE_WRITE, + NULL, + OPEN_ALWAYS, + FILE_ATTRIBUTE_NORMAL, + NULL + ); + + if(log_fh == INVALID_HANDLE_VALUE) { + log_fh = NULL; + } +} + +void log_close() { + if(log_fh) { + CloseHandle(log_fh); + log_fh = NULL; + } + + CloseHandle(log_mutex); + log_mutex = NULL; +} + +void log_printf(const char *fmt, ...) { + DWORD called = GetTickCount(); + + WaitForSingleObject(log_mutex, INFINITE); + + if(!log_fh) { + ReleaseMutex(log_mutex); + return; + } + + va_list argv; + char msg[1024], tstr[32]; + + va_start(argv, fmt); + vsnprintf(msg, 1024, fmt, argv); + va_end(argv); + + snprintf(tstr, 32, "[%u.%u] ", (unsigned int)(called/1000), (unsigned int)((called % 1000) / 10)); + + OVERLAPPED off; + off.Offset = 0; + off.OffsetHigh = 0; + off.hEvent = 0; + + 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, tstr, strlen(tstr), &written, NULL); + WriteFile(log_fh, msg, strlen(msg), &written, NULL); + WriteFile(log_fh, "\r\n", 2, &written, NULL); + + FlushFileBuffers(log_fh); + } + + UnlockFile(log_fh, 0, 0, 1, 0); + + ReleaseMutex(log_mutex); +} diff --git a/src/stubdll.c b/src/stubdll.c index ac9e1fc..29c8dfd 100644 --- a/src/stubdll.c +++ b/src/stubdll.c @@ -25,8 +25,9 @@ extern char const *dllname; FILE *call_log = NULL; -void __stdcall *find_sym(char const *symbol); -void debug(char const *fmt, ...); +void log_open(); +void log_close(); +void log_printf(const char *fmt, ...); static void load_dlls() { char sysdir[1024], path[1024]; @@ -47,6 +48,8 @@ static void load_dlls() { BOOL WINAPI DllMain(HINSTANCE me, DWORD why, LPVOID res) { if(why == DLL_PROCESS_ATTACH) { + log_open(); + HKEY key; if(RegOpenKeyEx(HKEY_CURRENT_USER, "Software\\IPXWrapper", 0, KEY_QUERY_VALUE, &key) == ERROR_SUCCESS) { @@ -62,9 +65,7 @@ BOOL WINAPI DllMain(HINSTANCE me, DWORD why, LPVOID res) { RegCloseKey(key); } - } - - if(why == DLL_PROCESS_DETACH) { + }else if(why == DLL_PROCESS_DETACH) { if(sysdll) { FreeLibrary(sysdll); sysdll = NULL; @@ -79,6 +80,8 @@ BOOL WINAPI DllMain(HINSTANCE me, DWORD why, LPVOID res) { fclose(call_log); call_log = NULL; } + + log_close(); } return TRUE; @@ -96,26 +99,9 @@ void __stdcall *find_sym(char const *symbol) { } if(!ptr) { - debug("Missing symbol in %s: %s", dllname, symbol); + log_printf("Missing symbol in %s: %s", dllname, symbol); abort(); } return ptr; } - -void debug(char const *fmt, ...) { - static void (*real_debug)(char const*,...) = NULL; - char msgbuf[1024]; - va_list argv; - - if(ipxdll && !real_debug) { - real_debug = (void*)GetProcAddress(ipxdll, "debug"); - } - if(real_debug) { - va_start(argv, fmt); - vsnprintf(msgbuf, 1024, fmt, argv); - va_end(argv); - - real_debug("%s", msgbuf); - } -} diff --git a/src/winsock.c b/src/winsock.c index 7df99fa..8a83a20 100644 --- a/src/winsock.c +++ b/src/winsock.c @@ -128,7 +128,7 @@ INT APIENTRY EnumProtocolsW(LPINT protocols, LPVOID buf, LPDWORD bsptr) { } SOCKET WSAAPI socket(int af, int type, int protocol) { - debug("socket(%d, %d, %d)", af, type, protocol); + log_printf("socket(%d, %d, %d)", af, type, protocol); if(af == AF_IPX) { ipx_socket *nsock = malloc(sizeof(ipx_socket)); @@ -138,7 +138,7 @@ SOCKET WSAAPI socket(int af, int type, int protocol) { nsock->fd = r_socket(AF_INET, SOCK_DGRAM, 0); if(nsock->fd == -1) { - debug("Creating fake socket failed: %s", w32_error(WSAGetLastError())); + log_printf("Creating fake socket failed: %s", w32_error(WSAGetLastError())); free(nsock); RETURN(-1); @@ -152,7 +152,7 @@ SOCKET WSAAPI socket(int af, int type, int protocol) { nsock->next = sockets; sockets = nsock; - debug("IPX socket created (fd = %d)", nsock->fd); + log_printf("IPX socket created (fd = %d)", nsock->fd); RETURN(nsock->fd); }else{ @@ -172,11 +172,11 @@ int WSAAPI closesocket(SOCKET fd) { } if(ret == SOCKET_ERROR) { - debug("closesocket(%d) failed: %s", fd, w32_error(WSAGetLastError())); + log_printf("closesocket(%d) failed: %s", fd, w32_error(WSAGetLastError())); RETURN(SOCKET_ERROR); } - debug("IPX socket closed (fd = %d)", fd); + log_printf("IPX socket closed (fd = %d)", fd); if(ptr == sockets) { sockets = ptr->next; @@ -205,10 +205,10 @@ int WSAAPI bind(SOCKET fd, const struct sockaddr *addr, int addrlen) { NET_TO_STRING(net_s, ipxaddr->sa_netnum); NODE_TO_STRING(node_s, ipxaddr->sa_nodenum); - debug("bind(%d, net=%s node=%s socket=%hu)", fd, net_s, node_s, ntohs(ipxaddr->sa_socket)); + log_printf("bind(%d, net=%s node=%s socket=%hu)", fd, net_s, node_s, ntohs(ipxaddr->sa_socket)); if(ptr->flags & IPX_BOUND) { - debug("bind failed: socket already bound"); + log_printf("bind failed: socket already bound"); RETURN_WSA(WSAEINVAL, -1); } @@ -240,7 +240,7 @@ int WSAAPI bind(SOCKET fd, const struct sockaddr *addr, int addrlen) { } if(!nic) { - debug("bind failed: no such address"); + log_printf("bind failed: no such address"); RETURN_WSA(WSAEADDRNOTAVAIL, -1); } @@ -258,7 +258,7 @@ int WSAAPI bind(SOCKET fd, const struct sockaddr *addr, int addrlen) { while(socket) { if(ntohs(socket->socket) == s && socket->flags & IPX_BOUND) { if(s == 65535) { - debug("bind failed: out of sockets?!"); + log_printf("bind failed: out of sockets?!"); RETURN_WSA(WSAEADDRNOTAVAIL, -1); } @@ -279,7 +279,7 @@ int WSAAPI bind(SOCKET fd, const struct sockaddr *addr, int addrlen) { while(socket) { if(socket->socket == ipxaddr->sa_socket && socket->flags & IPX_BOUND) { - debug("bind failed: requested socket in use"); + log_printf("bind failed: requested socket in use"); RETURN_WSA(WSAEADDRINUSE, -1); } @@ -292,7 +292,7 @@ int WSAAPI bind(SOCKET fd, const struct sockaddr *addr, int addrlen) { NET_TO_STRING(net_s, nic->ipx_net); NODE_TO_STRING(node_s, nic->ipx_node); - debug("bind address: net=%s node=%s socket=%hu", net_s, node_s, ntohs(ptr->socket)); + log_printf("bind address: net=%s node=%s socket=%hu", net_s, node_s, ntohs(ptr->socket)); /* TODO: Bind fake socket in socket() call rather than here? * @@ -311,7 +311,7 @@ int WSAAPI bind(SOCKET fd, const struct sockaddr *addr, int addrlen) { if(rval == 0) { ptr->flags |= IPX_BOUND; }else{ - debug("Binding fake socket failed: %s", w32_error(WSAGetLastError())); + log_printf("Binding fake socket failed: %s", w32_error(WSAGetLastError())); } RETURN(rval); @@ -612,7 +612,7 @@ int WSAAPI sendto(SOCKET fd, const char *buf, int len, int flags, const struct s } if(!(sockptr->flags & IPX_BOUND)) { - debug("sendto() on unbound socket, attempting implicit bind"); + log_printf("sendto() on unbound socket, attempting implicit bind"); struct sockaddr_ipx bind_addr;