From 822b307dec1be1c5cf86c6477e3ac190f0f9e1c6 Mon Sep 17 00:00:00 2001 From: Daniel Collins Date: Tue, 21 Nov 2023 20:18:19 +0000 Subject: [PATCH] Record more profiling info. --- src/funcprof.c | 3 ++- src/ipxwrapper.c | 18 ++++++++++++++++++ src/ipxwrapper.h | 3 +++ src/ipxwrapper_prof_defs.h | 2 ++ src/router.c | 8 ++++++++ src/winsock.c | 13 +++++++++++++ 6 files changed, 46 insertions(+), 1 deletion(-) diff --git a/src/funcprof.c b/src/funcprof.c index 144a8fe..545252f 100644 --- a/src/funcprof.c +++ b/src/funcprof.c @@ -108,10 +108,11 @@ void fprof_report(const char *dll_name, struct FuncStats *fstats, size_t n_fstat if(total_time > 0.0) { log_printf(LOG_INFO, - "%s:%s was called %u times duration min %fus max %fus avg %fus", + "%s:%s was called %u times duration total %fus min %fus max %fus avg %fus", dll_name, fstats[i].func_name, n_calls, + (total_time / TICKS_PER_USEC), (min_time / TICKS_PER_USEC), (max_time / TICKS_PER_USEC), ((total_time / (float)(n_calls)) / TICKS_PER_USEC)); diff --git a/src/ipxwrapper.c b/src/ipxwrapper.c index 1cebd5f..11070c0 100644 --- a/src/ipxwrapper.c +++ b/src/ipxwrapper.c @@ -59,6 +59,9 @@ struct FuncStats ipxwrapper_fstats[] = { const unsigned int ipxwrapper_fstats_size = sizeof(ipxwrapper_fstats) / sizeof(*ipxwrapper_fstats); +unsigned int send_packets = 0, send_bytes = 0; /* Sent from emulated socket */ +unsigned int recv_packets = 0, recv_bytes = 0; /* Forwarded to emulated socket */ + static void init_cs(CRITICAL_SECTION *cs) { if(!InitializeCriticalSectionAndSpinCount(cs, 0x80000000)) @@ -71,6 +74,18 @@ static void init_cs(CRITICAL_SECTION *cs) static HANDLE prof_thread_handle = NULL; static HANDLE prof_thread_exit = NULL; +static void report_packet_stats(void) +{ + unsigned int my_send_packets = __atomic_exchange_n(&send_packets, 0, __ATOMIC_RELAXED); + unsigned int my_send_bytes = __atomic_exchange_n(&send_bytes, 0, __ATOMIC_RELAXED); + + unsigned int my_recv_packets = __atomic_exchange_n(&recv_packets, 0, __ATOMIC_RELAXED); + unsigned int my_recv_bytes = __atomic_exchange_n(&recv_bytes, 0, __ATOMIC_RELAXED); + + log_printf(LOG_INFO, "IPX sockets sent %u packets (%u bytes)", my_send_packets, my_send_bytes); + log_printf(LOG_INFO, "IPX sockets received %u packets (%u bytes)", my_recv_packets, my_recv_bytes); +} + static DWORD WINAPI prof_thread_main(LPVOID lpParameter) { static const int PROF_INTERVAL_MS = 10000; @@ -79,6 +94,7 @@ static DWORD WINAPI prof_thread_main(LPVOID lpParameter) { fprof_report(STUBS_DLL_NAME, stub_fstats, NUM_STUBS); fprof_report("ipxwrapper.dll", ipxwrapper_fstats, ipxwrapper_fstats_size); + report_packet_stats(); } return 0; @@ -206,6 +222,8 @@ BOOL WINAPI DllMain(HINSTANCE hinstDLL, DWORD fdwReason, LPVOID lpvReserved) { fprof_report(STUBS_DLL_NAME, stub_fstats, NUM_STUBS); fprof_report("ipxwrapper.dll", ipxwrapper_fstats, ipxwrapper_fstats_size); + + report_packet_stats(); } log_close(); diff --git a/src/ipxwrapper.h b/src/ipxwrapper.h index 57806bc..1b7e17c 100644 --- a/src/ipxwrapper.h +++ b/src/ipxwrapper.h @@ -197,6 +197,9 @@ enum { #undef FPROF_DECL }; +extern unsigned int send_packets, send_bytes; /* Sent from emulated socket */ +extern unsigned int recv_packets, recv_bytes; /* Forwarded to emulated socket */ + ipx_socket *get_socket(SOCKET sockfd); ipx_socket *get_socket_wait_for_ready(SOCKET sockfd, int timeout_ms); void lock_sockets(void); diff --git a/src/ipxwrapper_prof_defs.h b/src/ipxwrapper_prof_defs.h index 147e89d..052f52a 100644 --- a/src/ipxwrapper_prof_defs.h +++ b/src/ipxwrapper_prof_defs.h @@ -1,3 +1,5 @@ FPROF_DECL(_deliver_packet) FPROF_DECL(_handle_udp_recv) +FPROF_DECL(_handle_dosbox_recv) +FPROF_DECL(_handle_pcap_frame) FPROF_DECL(lock_sockets) diff --git a/src/router.c b/src/router.c index 5391e2d..53c660b 100644 --- a/src/router.c +++ b/src/router.c @@ -347,6 +347,10 @@ static void _deliver_packet( { log_printf(LOG_ERROR, "Error relaying packet: %s", w32_error(WSAGetLastError())); } + else{ + __atomic_add_fetch(&recv_packets, 1, __ATOMIC_RELAXED); + __atomic_add_fetch(&recv_bytes, data_size, __ATOMIC_RELAXED); + } free(packet); } @@ -541,6 +545,8 @@ static void _handle_dosbox_registration_response(novell_ipx_packet *packet, size static void _handle_dosbox_recv(novell_ipx_packet *packet, size_t packet_size) { + FPROF_RECORD_SCOPE(&(ipxwrapper_fstats[IPXWRAPPER_FSTATS__handle_dosbox_recv])); + if(packet_size < sizeof(novell_ipx_packet) || ntohs(packet->length) != packet_size) { /* Doesn't look valid. */ @@ -622,6 +628,8 @@ static bool _do_udp_recv(int fd) static void _handle_pcap_frame(u_char *user, const struct pcap_pkthdr *pkt_header, const u_char *pkt_data) { + FPROF_RECORD_SCOPE(&(ipxwrapper_fstats[IPXWRAPPER_FSTATS__handle_pcap_frame])); + ipx_interface_t *iface = (ipx_interface_t*)(user); const novell_ipx_packet *ipx; diff --git a/src/winsock.c b/src/winsock.c index b1a9ba3..3bb3fac 100644 --- a/src/winsock.c +++ b/src/winsock.c @@ -1475,6 +1475,9 @@ static DWORD ipx_send_packet( if(pcap_sendpacket(iface->pcap, (void*)(frame), frame_size) == 0) { + __atomic_add_fetch(&send_packets, 1, __ATOMIC_RELAXED); + __atomic_add_fetch(&send_bytes, data_size, __ATOMIC_RELAXED); + free(frame); return ERROR_SUCCESS; } @@ -1531,6 +1534,10 @@ static DWORD ipx_send_packet( error = WSAGetLastError(); log_printf(LOG_ERROR, "Error sending DOSBox IPX packet: %s", w32_error(error)); } + else{ + __atomic_add_fetch(&send_packets, 1, __ATOMIC_RELAXED); + __atomic_add_fetch(&send_bytes, data_size, __ATOMIC_RELAXED); + } free(packet); @@ -1635,6 +1642,12 @@ static DWORD ipx_send_packet( free(packet); + if(send_ok) + { + __atomic_add_fetch(&send_packets, 1, __ATOMIC_RELAXED); + __atomic_add_fetch(&send_bytes, data_size, __ATOMIC_RELAXED); + } + return send_ok ? ERROR_SUCCESS : send_error;