[bootserver] Revamp boot server logs
- Show in a single line progress spin, percentage, file size,
transfer speed, and file path.
- Indicate transmitting the last packet by a dot "." in "MB/s."
- Reword: "got beacon" to "Received request"
- Mark entire path in green color rather than the basename.
- Use GB, MB, KB, B in file size and tranfer speed.
Test: Mac OS host, gLinux host
Change-Id: Ieb641fdbda7729d1e31c1fa4cdf175ab765c8079
diff --git a/system/host/bootserver/bootserver.c b/system/host/bootserver/bootserver.c
index 39d4920..fe39f6c 100644
--- a/system/host/bootserver/bootserver.c
+++ b/system/host/bootserver/bootserver.c
@@ -35,7 +35,7 @@
#define ANSI_MAGENTA "\x1b[35m"
#define ANSI_CYAN "\x1b[36m"
#define ANSI_RESET "\x1b[0m"
-#define ANSI_LINESTART "\33[2K\r"
+#define ANSI_CLEARLINE "\33[2K\r"
#define MAX_FVM_IMAGES 4
@@ -57,6 +57,7 @@
static bool file_info_printed;
static int progress_reported;
static int packets_sent;
+static char filename_in_flight[PATH_MAX];
static struct timeval start_time, end_time;
static bool is_redirected;
static const char spinner[] = {'|', '/', '-', '\\'};
@@ -80,37 +81,25 @@
return buf;
}
-static void print_file_info(const char* name, size_t size) {
- size_t prefix_len = strlen(NB_FILENAME_PREFIX);
- const char* base_name;
- if (!strncmp(name, NB_FILENAME_PREFIX, prefix_len)) {
- base_name = &name[prefix_len];
- } else {
- base_name = name;
- }
-
- char path1[PATH_MAX]; // dirname(), basename() modify in situ.
- char path2[PATH_MAX];
- snprintf(path1, PATH_MAX, "%s", name);
- snprintf(path2, PATH_MAX, "%s", name);
-
- log("Transfer starts [%5.1f MB] %s/%s%s%s (%zu bytes)",
- (float)size / 1024.0 / 1024.0,
- dirname(path1), ANSI(GREEN), basename(path2), ANSI(RESET), size);
-}
-
void initialize_status(const char* name, size_t size) {
total_file_size = size;
progress_reported = 0;
packets_sent = 0;
-
- if (!file_info_printed) {
- print_file_info(name, size);
- file_info_printed = true;
- }
+ snprintf(filename_in_flight, sizeof(filename_in_flight),
+ "%s%s%s", ANSI(GREEN), name, ANSI(RESET));
}
void update_status(size_t bytes_so_far) {
+ char progress_str[PATH_MAX];
+ size_t offset = 0;
+
+#define UPDATE_LOG(args...) \
+ do { \
+ if (offset < PATH_MAX) { \
+ offset += snprintf(progress_str + offset, PATH_MAX - offset, args); \
+ } \
+ } while (false)
+
packets_sent++;
bool is_last_piece = (bytes_so_far == total_file_size);
@@ -127,28 +116,45 @@
} else {
if (packets_sent > 1024 || is_last_piece) {
packets_sent = 0;
- float bw = 0;
static int spin = 0;
+ size_t divider = (total_file_size > 0) ? total_file_size : 1;
+ UPDATE_LOG("[%c] %4.01f%% of ", spinner[(spin++) % 4],
+ 100.0 * (float)bytes_so_far / (float)divider);
+ if (total_file_size < 1024) {
+ UPDATE_LOG(" %3zu.0 B", total_file_size);
+ } else if (total_file_size < 1024 * 1024) {
+ UPDATE_LOG(" %5.1f KB", (float)total_file_size / 1024.0);
+ } else if (total_file_size < 1024 * 1024 * 1024) {
+ UPDATE_LOG(" %5.1f MB", (float)total_file_size / 1024.0 / 1024.0);
+ } else {
+ UPDATE_LOG(" %5.1f GB", (float)total_file_size / 1024.0 / 1024.0 / 1024.0);
+ }
+
struct timeval now;
gettimeofday(&now, NULL);
int64_t sec = (int64_t)(now.tv_sec - start_time.tv_sec);
int64_t usec = (int64_t)(now.tv_usec - start_time.tv_usec);
int64_t elapsed_usec = sec * 1000000 + usec;
- bw = (float)bytes_so_far * 1000000 / (1024.0 * 1024.0 * ((float)elapsed_usec));
-
- fprintf(stderr, "%s", ANSI_LINESTART);
- if (total_file_size > 0) {
- fprintf(stderr, "\t%c %.01f%%", spinner[(spin++) % 4],
- 100.0 * (float)bytes_so_far / (float)total_file_size);
+ float bytes_in_sec;
+ bytes_in_sec = (float)bytes_so_far * 1000000 / ((float)elapsed_usec);
+ if (bytes_in_sec < 1024) {
+ UPDATE_LOG(" %5.1f B/s", bytes_in_sec);
+ } else if (bytes_in_sec < 1024 * 1024) {
+ UPDATE_LOG(" %5.1f KB/s", bytes_in_sec / 1024.0);
+ } else if (bytes_in_sec < 1024 * 1024 * 1024) {
+ UPDATE_LOG(" %5.1f MB/s", bytes_in_sec / 1024.0 / 1024.0);
} else {
- fprintf(stderr, "\t%c", spinner[(spin++) % 4]);
+ UPDATE_LOG(" %5.1f GB/s", bytes_in_sec / 1024.0 / 1024.0 / 1024.0);
}
- fprintf(stderr, "\t %.01fMB/s", bw);
+
if (is_last_piece) {
- fprintf(stderr, "\tTook %" PRId64 ".%" PRId64 " sec",
- elapsed_usec / 1000000, elapsed_usec % 1000000);
+ UPDATE_LOG(".");
+ } else {
+ UPDATE_LOG(" ");
}
+ UPDATE_LOG(" %s", filename_in_flight);
+ fprintf(stderr, "%s%s", ANSI_CLEARLINE, progress_str);
}
}
}
@@ -570,7 +576,7 @@
continue;
}
- log("got beacon from %s", sockaddr_str(&ra));
+ log("Received request from %s", sockaddr_str(&ra));
// ensure any payload is null-terminated
buf[r] = 0;
@@ -606,6 +612,7 @@
continue;
}
+ log("Transfer starts");
if (cmdline[0]) {
status = xfer(&ra, "(cmdline)", cmdline);
} else {
@@ -652,11 +659,14 @@
status = xfer(&ra, kernel_fn, NB_KERNEL_FILENAME);
}
if (status == 0) {
+ log("Transfer ends successfully.");
if (kernel_fn) {
send_boot_command(&ra);
} else {
send_reboot_command(&ra);
}
+ } else {
+ log("Transfer ends incompletely.");
}
if (once) {
close(s);