Record more profiling info.

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));

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();

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);

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)

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;

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;