From d952f28e527175cc3df9ebd91e739e34df2194c9 Mon Sep 17 00:00:00 2001 From: rich cannings Date: Tue, 1 Mar 2011 15:40:09 -0800 Subject: qemu logging extensions (1) Clear the logs upon receiving a SIGUSR1 signal (2) Add logging timestamps for network connections (3) Extended TCP redirect logs to include local src ip/port and fixed byte-ordering in log files Change-Id: I51e7293c8eeb5979a92e67f52f1c6416400d83c6 --- slirp-android/libslirp.h | 5 +++ slirp-android/slirp.c | 8 +++++ slirp-android/socket.c | 7 ++-- slirp-android/tcp_subr.c | 60 +++++++++++++++++++-------------- slirp-android/udp.c | 26 ++++++++------ vl-android.c | 88 ++++++++++++++++++++++++++++++++++++++++++++++-- 6 files changed, 152 insertions(+), 42 deletions(-) diff --git a/slirp-android/libslirp.h b/slirp-android/libslirp.h index 120e3d3..e8b63a8 100644 --- a/slirp-android/libslirp.h +++ b/slirp-android/libslirp.h @@ -43,6 +43,9 @@ void slirp_drop_tcp(); void slirp_add_allow(unsigned long dst_addr, int dst_lport, int dst_hport, u_int8_t proto); void slirp_drop_log_fd(FILE* fd); + +/** Get the drop log fd */ +FILE* get_slirp_drop_log_fd(void); int slirp_should_drop(unsigned long dst_addr, int dst_port, u_int8_t proto); @@ -64,6 +67,8 @@ int slirp_should_net_forward(unsigned long remote_ip, int remote_port, */ void slirp_dns_log_fd(FILE* fd); +/** Get the dns log fd */ +FILE* get_slirp_dns_log_fd(void); /** Logs the DNS name in DNS query issued by the VM. */ int slirp_log_dns(struct mbuf* m, int dropped); /** IP packet dump of DNS queris and responses. */ diff --git a/slirp-android/slirp.c b/slirp-android/slirp.c index 015918f..6a62e4b 100644 --- a/slirp-android/slirp.c +++ b/slirp-android/slirp.c @@ -923,6 +923,14 @@ void slirp_dns_log_fd(FILE* fd) { dns_log_fd = fd; } +FILE* get_slirp_drop_log_fd(void) { + return drop_log_fd; +} + +FILE* get_slirp_dns_log_fd(void) { + return dns_log_fd; +} + /* Address and ports are in host byte order */ int slirp_should_drop(unsigned long dst_addr, int dst_port, diff --git a/slirp-android/socket.c b/slirp-android/socket.c index 285a8ef..439590a 100644 --- a/slirp-android/socket.c +++ b/slirp-android/socket.c @@ -578,12 +578,13 @@ sosendto(struct socket *so, struct mbuf *m) int fport = addr_port; if (slirp_should_net_forward(faddr, fport, &faddr, &fport)) { - slirp_drop_log( + time_t timestamp = time(NULL); + slirp_drop_log( "Redirected UDP: src: 0x%08lx:0x%04x org dst: 0x%08lx:0x%04x " - "new dst: 0x%08lx:0x%04x\n", + "new dst: 0x%08lx:0x%04x %ld\n", so->so_laddr_ip, so->so_laddr_port, addr_ip, addr_port, - faddr, fport + faddr, fport, timestamp ); } addr_ip = faddr; diff --git a/slirp-android/tcp_subr.c b/slirp-android/tcp_subr.c index 0550d4b..cfcc3cb 100644 --- a/slirp-android/tcp_subr.c +++ b/slirp-android/tcp_subr.c @@ -384,7 +384,7 @@ tcp_proxy_event( struct socket* so, */ int is_qemu_special_address(unsigned long dst_addr, unsigned long *redir_addr) { - if ((dst_addr & htonl(0xffffff00)) == special_addr_ip) { + if ((dst_addr & 0xffffff00) == special_addr_ip) { /* It's an alias */ int last_byte = dst_addr & 0xff; @@ -416,6 +416,7 @@ int tcp_fconnect(struct socket *so) SockAddress sockaddr; unsigned long sock_ip; int sock_port; + int redirect_happened = 0; /* for logging new src ip/port after connect */ DEBUG_CALL("tcp_fconnect"); DEBUG_ARG("so = %lx", (long )so); @@ -423,7 +424,7 @@ int tcp_fconnect(struct socket *so) /* when true, a connection that otherwise would be dropped will instead be * redirected to the sink ('-net-forward-tcp2sink') */ int forward_dropped_to_sink = 0; - + time_t timestamp = time(NULL); /*-------------------------------------------------------------*/ /* User mode network stack restrictions */ @@ -432,22 +433,24 @@ int tcp_fconnect(struct socket *so) /* If forwarding to sink is enabled, don't actually drop it */ if (slirp_should_forward_dropped_tcp2sink()) { slirp_drop_log( - "About to be dropped TCP forwarded to sink: " - "src: 0x%08lx:0x%04x dst: 0x%08lx:0x%04x\n", + "About to be dropped TCP allowed to sink: " + "0x%08lx:0x%04x -> 0x%08lx:0x%04x %ld\n", so->so_laddr_ip, so->so_laddr_port, so->so_faddr_ip, - so->so_faddr_port + so->so_faddr_port, + timestamp ); forward_dropped_to_sink = 1; } else { slirp_drop_log( - "Dropped TCP: src: 0x%08lx:0x%04x dst: 0x%08lx:0x%04x\n", + "Dropped TCP: 0x%08lx:0x%04x -> 0x%08lx:0x%04x %ld\n", so->so_laddr_ip, so->so_laddr_port, so->so_faddr_ip, - so->so_faddr_port + so->so_faddr_port, + timestamp ); //errno = ENETUNREACH; errno = ECONNREFUSED; @@ -455,11 +458,12 @@ int tcp_fconnect(struct socket *so) } } else { slirp_drop_log( - "Allowed TCP: src: 0x%08lx:0x%04x dst: 0x%08lx:0x%04x\n", + "Allowed TCP: 0x%08lx:0x%04x -> 0x%08lx:0x%04x %ld\n", so->so_laddr_ip, so->so_laddr_port, so->so_faddr_ip, - so->so_faddr_port + so->so_faddr_port, + timestamp ); } /*-------------------------------------------------------------*/ @@ -479,14 +483,7 @@ int tcp_fconnect(struct socket *so) * dropped connections is enabled, redirect it to the sink */ sock_ip = slirp_get_tcp_sink_ip(); sock_port= slirp_get_tcp_sink_port(); - slirp_drop_log( - "Redirected would-be dropped TCP to sink: " - "src: 0x%08lx:0x%04x org dst: 0x%08lx:0x%04x " - "new dst: 0x%08lx:0x%04x\n", - so->so_laddr_ip, so->so_laddr_port, - so->so_faddr_ip, so->so_faddr_port, - sock_ip, sock_port - ); + redirect_happened = 1; } else { /* An allowed connection */ @@ -498,19 +495,13 @@ int tcp_fconnect(struct socket *so) /* faddr and fport are modified only on success */ if (slirp_should_net_forward(so->so_faddr_ip, so->so_faddr_port, &faddr, &fport)) { - slirp_drop_log( - "Redirected TCP: src: 0x%08lx:0x%04x org dst: 0x%08lx:0x%04x " - "new dst: 0x%08lx:0x%04x\n", - so->so_laddr_ip, so->so_laddr_port, - so->so_faddr_ip, so->so_faddr_port, - faddr, fport - ); + redirect_happened = 1; sock_ip = faddr; /* forced dst addr */ sock_port= fport; /* forced dst port */ } /* Determine if this is a connection to a special qemu service, * and change the destination address accordingly. - * 'faddr' is modified only onsuccess */ + * 'faddr' is modified only on success */ else if (is_qemu_special_address(so->so_faddr_ip, &faddr)) { /* We keep the original destination port. If a special service @@ -548,7 +539,24 @@ int tcp_fconnect(struct socket *so) /* We don't care what port we get */ socket_connect(s, &sockaddr); - /* + if (redirect_happened) { + SockAddress local_addr; + if (socket_get_address(s, &local_addr)) { + fprintf (stderr, + "Warning: tcp_fconnect: could not get socket name\n"); + } + slirp_drop_log( + "Redirected TCP: orig 0x%08lx:0x%04x -> 0x%08lx:0x%04x " + "new 0x%08lx:0x%04x -> 0x%08lx:0x%04x %ld\n", + so->so_laddr_ip, so->so_laddr_port, + so->so_faddr_ip, so->so_laddr_port, + sock_address_get_ip(&local_addr), + sock_address_get_port(&local_addr), + sock_ip, sock_port, timestamp + ); + } + + /* * If it's not in progress, it failed, so we just return 0, * without clearing SS_NOFDREF */ diff --git a/slirp-android/udp.c b/slirp-android/udp.c index a9c9a82..1de938a 100644 --- a/slirp-android/udp.c +++ b/slirp-android/udp.c @@ -129,24 +129,28 @@ udp_input(register struct mbuf *m, int iphlen) /* ------------------------------------------------------*/ /* User mode network stack restrictions */ /* slirp_should_drop requires host byte ordering in arguments */ + time_t timestamp = time(NULL); + if (slirp_should_drop(ntohl(ip->ip_dst.addr), ntohs(uh->uh_dport.port), IPPROTO_UDP)) { slirp_drop_log( - "Dropped UDP: src: 0x%08lx:0x%04x dst: 0x%08lx:0x%04x\n", - ip->ip_src.addr, - uh->uh_sport.port, - ip->ip_dst.addr, - uh->uh_dport.port + "Dropped UDP: src: 0x%08lx:0x%04x dst: 0x%08lx:0x%04x %ld\n", + ntohl(ip->ip_src.addr), + ntohs(uh->uh_sport.port), + ntohl(ip->ip_dst.addr), + ntohs(uh->uh_dport.port), + timestamp ); goto bad; /* drop the packet */ } else { slirp_drop_log( - "Allowed UDP: src: 0x%08lx:0x%04x dst: 0x%08lx:0x%04x\n", - ip->ip_src.addr, - uh->uh_sport.port, - ip->ip_dst.addr, - uh->uh_dport.port + "Allowed UDP: src: 0x%08lx:0x%04x dst: 0x%08lx:0x%04x %ld\n", + ntohl(ip->ip_src.addr), + ntohs(uh->uh_sport.port), + ntohl(ip->ip_dst.addr), + ntohs(uh->uh_dport.port), + timestamp ); } /* ------------------------------------------------------*/ @@ -354,7 +358,7 @@ int udp_output2_(struct socket *so, struct mbuf *m, STAT(udpstat.udps_opackets++); // DNS logging - if (so != NULL && so->so_faddr_port == htons(53)) { + if (so != NULL && so->so_faddr_port == 53) { /*so has host byte order */ if (!slirp_dump_dns(m)) { DEBUG_MISC((dfd,"Error logging DNS packet")); } diff --git a/vl-android.c b/vl-android.c index d94bec0..cb32eb2 100644 --- a/vl-android.c +++ b/vl-android.c @@ -406,6 +406,10 @@ extern int android_display_bpp; extern void dprint( const char* format, ... ); +const char* dns_log_filename = NULL; +const char* drop_log_filename = NULL; +static int rotate_logs_requested = 0; + const char* savevm_on_exit = NULL; #define TFR(expr) do { if ((expr) != -1) break; } while (errno == EINTR) @@ -512,6 +516,52 @@ static void default_ioport_writel(void *opaque, uint32_t address, uint32_t data) #endif } +/* + * Sets a flag (rotate_logs_requested) to clear both the DNS and the + * drop logs upon receiving a SIGUSR1 signal. We need to clear the logs + * between the tasks that do not require restarting Qemu. + */ +void rotate_qemu_logs_handler(int signum) { + rotate_logs_requested = 1; +} + +/* + * Resets the rotate_log_requested_flag. Normally called after qemu + * logs has been rotated. + */ +void reset_rotate_qemu_logs_request(void) { + rotate_logs_requested = 0; +} + +/* + * Clears the passed qemu log when the rotate_logs_requested + * is set. We need to clear the logs between the tasks that do not + * require restarting Qemu. + */ +FILE* rotate_qemu_log(FILE* old_log_fd, const char* filename) { + FILE* new_log_fd = NULL; + if (old_log_fd) { + if (fclose(old_log_fd) == -1) { + fprintf(stderr, "Cannot close old_log fd\n"); + exit(errno); + } + } + + if (!filename) { + fprintf(stderr, "The log filename to be rotated is not provided"); + exit(-1); + } + + new_log_fd = fopen(filename , "wb+"); + if (new_log_fd == NULL) { + fprintf(stderr, "Cannot open the log file: %s for write.\n", + filename); + exit(1); + } + + return new_log_fd; +} + /***********************************************************/ void hw_error(const char *fmt, ...) { @@ -3122,6 +3172,17 @@ static void main_loop(void) #ifdef CONFIG_PROFILER dev_time += profile_getclock() - ti; #endif + + if (rotate_logs_requested) { + FILE* new_dns_log_fd = rotate_qemu_log(get_slirp_dns_log_fd(), + dns_log_filename); + FILE* new_drop_log_fd = rotate_qemu_log(get_slirp_drop_log_fd(), + drop_log_filename); + slirp_dns_log_fd(new_dns_log_fd); + slirp_drop_log_fd(new_drop_log_fd); + reset_rotate_qemu_logs_request(); + } + } while (vm_can_run()); if (qemu_debug_requested()) @@ -3623,6 +3684,23 @@ parse_int(const char *str, int *result) return 0; } +#ifndef _WIN32 +/* + * Initializes the SIGUSR1 signal handler to clear Qemu logs. + */ +void init_qemu_clear_logs_sig() { + struct sigaction act; + sigfillset(&act.sa_mask); + act.sa_flags = 0; + act.sa_handler = rotate_qemu_logs_handler; + if (sigaction(SIGUSR1, &act, NULL) == -1) { + fprintf(stderr, "Failed to setup SIGUSR1 handler to clear Qemu logs\n"); + exit(-1); + } +} +#endif + + /* parses a null-terminated string specifying a network port (e.g., "80") or * port range (e.g., "[6666-7000]"). In case of a single port, lport and hport @@ -4580,7 +4658,8 @@ int main(int argc, char **argv, char **envp) case QEMU_OPTION_drop_log: { FILE* drop_log_fd; - drop_log_fd = fopen(optarg, "w"); + drop_log_filename = optarg; + drop_log_fd = fopen(optarg, "w+"); if (!drop_log_fd) { fprintf(stderr, "Cannot open drop log: %s\n", optarg); @@ -4594,7 +4673,8 @@ int main(int argc, char **argv, char **envp) case QEMU_OPTION_dns_log: { FILE* dns_log_fd; - dns_log_fd = fopen(optarg, "wb"); + dns_log_filename = optarg; + dns_log_fd = fopen(optarg, "wb+"); if (dns_log_fd == NULL) { fprintf(stderr, "Cannot open dns log: %s\n", optarg); @@ -5359,6 +5439,10 @@ int main(int argc, char **argv, char **envp) } #endif +#ifndef _WIN32 + init_qemu_clear_logs_sig(); +#endif + /* init the dynamic translator */ cpu_exec_init_all(tb_size * 1024 * 1024); -- cgit v1.1