I have decided to discard most of the logging code and rewrite it to be more readable. It even worked in preliminary tests. TODO: - Should "-o -" be a no-op which just redirects stderr to stdout? Right now "-" is treated as regular file name, but most Unix utilities are unable to handle a file with that name (try "less -" for amusement). - Add man page entry - Is the log level difference for screen/logfile a good thing, and should we default the logfile level to dbg2 instead of dbg?
Add log file support to flashrom.
If you use cli_classic, the log file will always contain messages at a level which is one higher than the one specified. That way we get all verbose messages in the log even if the user doesn't specify -V.
Convert all printf() after start of logging to msg_*().
Allow separate control of log level for screen and logfile in case other frontends (e.g. GUI, cli_mfg) want that.
Signed-off-by: Carl-Daniel Hailfinger c-d.hailfinger.devel.2006@gmx.net
Index: flashrom-logfile/flash.h =================================================================== --- flashrom-logfile/flash.h (Revision 1528) +++ flashrom-logfile/flash.h (Arbeitskopie) @@ -228,7 +228,8 @@ write_gran_1byte, write_gran_256bytes, }; -extern int verbose; +extern int verbose_screen; +extern int verbose_logfile; extern const char flashrom_version[]; extern char *chip_to_probe; void map_flash_registers(struct flashctx *flash); @@ -268,13 +269,20 @@ #define ERROR_FLASHROM_LIMIT -201
/* cli_output.c */ +#ifndef STANDALONE +int open_logfile(const char * const filename); +int close_logfile(void); +void start_logging(void); +#endif /* Let gcc and clang check for correct printf-style format strings. */ -int print(int type, const char *fmt, ...) __attribute__((format(printf, 2, 3))); -#define MSG_ERROR 0 -#define MSG_INFO 1 -#define MSG_DEBUG 2 -#define MSG_DEBUG2 3 -#define MSG_BARF 4 +enum msglevel { + MSG_ERROR = 0, + MSG_INFO = 1, + MSG_DEBUG = 2, + MSG_DEBUG2 = 3, + MSG_BARF = 4, +}; +int print(enum msglevel level, const char *fmt, ...) __attribute__((format(printf, 2, 3))); #define msg_gerr(...) print(MSG_ERROR, __VA_ARGS__) /* general errors */ #define msg_perr(...) print(MSG_ERROR, __VA_ARGS__) /* programmer errors */ #define msg_cerr(...) print(MSG_ERROR, __VA_ARGS__) /* chip errors */ Index: flashrom-logfile/cli_output.c =================================================================== --- flashrom-logfile/cli_output.c (Revision 1528) +++ flashrom-logfile/cli_output.c (Arbeitskopie) @@ -2,6 +2,7 @@ * This file is part of the flashrom project. * * Copyright (C) 2009 Sean Nelson audiohacked@gmail.com + * Copyright (C) 2011 Carl-Daniel Hailfinger * * This program is free software; you can redistribute it and/or modify * it under the terms of the GNU General Public License as published by @@ -20,36 +21,80 @@
#include <stdio.h> #include <stdarg.h> +#include <string.h> +#include <errno.h> #include "flash.h"
-int print(int type, const char *fmt, ...) +static FILE *logfile = NULL; + +#ifndef STANDALONE +int close_logfile(void) { + if (logfile && fclose(logfile)) { + /* fclose returned an error. Stop writing to be safe. */ + logfile = NULL; + msg_perr("Closing the log file returned error %s\n", + strerror(errno)); + return 1; + } + logfile = NULL; + return 0; +} + +int open_logfile(const char * const filename) +{ + if (!filename) { + msg_gerr("No filename specified.\n"); + return 1; + } + if ((logfile = fopen(filename, "w")) == NULL) { + perror(filename); + return 1; + } + return 0; +} + +void start_logging(void) +{ + enum msglevel oldverbose_screen = verbose_screen; + enum msglevel oldverbose_logfile = verbose_logfile; + + /* Shut up the console. */ + verbose_screen = MSG_ERROR; + verbose_logfile = MSG_DEBUG; + print_version(); + verbose_screen = oldverbose_screen; + verbose_logfile = oldverbose_logfile; +} +#endif /* STANDALONE */ + +/* Please note that level is the verbosity, not the importance of the message. + */ +int print(enum msglevel level, const char *fmt, ...) +{ va_list ap; - int ret; - FILE *output_type; + int ret = 0; + FILE *output_level = stdout;
- switch (type) { - case MSG_ERROR: - output_type = stderr; - break; - case MSG_BARF: - if (verbose < 3) - return 0; - case MSG_DEBUG2: - if (verbose < 2) - return 0; - case MSG_DEBUG: - if (verbose < 1) - return 0; - case MSG_INFO: - default: - output_type = stdout; - break; + if (level == MSG_ERROR) + output_level = stderr; + + if (level <= verbose_screen) { + va_start(ap, fmt); + ret = vfprintf(output_level, fmt, ap); + va_end(ap); + /* msg_*spew usually happens inside chip accessors in possibly + * time-critical operations. Don't slow them down by flushing. + */ + if (level != MSG_BARF) + fflush(output_level); } - - va_start(ap, fmt); - ret = vfprintf(output_type, fmt, ap); - va_end(ap); - fflush(output_type); + if ((level <= verbose_logfile) && logfile) { + va_start(ap, fmt); + ret = vfprintf(logfile, fmt, ap); + va_end(ap); + if (level != MSG_BARF) + fflush(logfile); + } return ret; } Index: flashrom-logfile/cli_classic.c =================================================================== --- flashrom-logfile/cli_classic.c (Revision 1528) +++ flashrom-logfile/cli_classic.c (Arbeitskopie) @@ -106,7 +106,7 @@ "-z|" #endif "-E|-r <file>|-w <file>|-v <file>]\n" - " [-c <chipname>] [-l <file>]\n" + " [-c <chipname>] [-l <file>] [-o <file>]\n" " [-i <image>] [-p <programmername>[:<parameters>]]\n\n");
printf("Please note that the command line interface for flashrom has " @@ -135,6 +135,7 @@ "<file>\n" " -i | --image <name> only flash image <name> " "from flash layout\n" + " -o | --output <name> log to file <name>\n" " -L | --list-supported print supported devices\n" #if CONFIG_PRINT_WIKI == 1 " -z | --list-supported-wiki print supported devices " @@ -177,7 +178,7 @@ enum programmer prog = PROGRAMMER_INVALID; int ret = 0;
- static const char optstring[] = "r:Rw:v:nVEfc:l:i:p:Lzh"; + static const char optstring[] = "r:Rw:v:nVEfc:l:i:p:Lzho:"; static const struct option long_options[] = { {"read", 1, NULL, 'r'}, {"write", 1, NULL, 'w'}, @@ -194,11 +195,13 @@ {"programmer", 1, NULL, 'p'}, {"help", 0, NULL, 'h'}, {"version", 0, NULL, 'R'}, + {"output", 1, NULL, 'o'}, {NULL, 0, NULL, 0}, };
char *filename = NULL; char *layoutfile = NULL; + char *log_name = NULL; char *tempstr = NULL; char *pparam = NULL;
@@ -260,7 +263,8 @@ chip_to_probe = strdup(optarg); break; case 'V': - verbose++; + verbose_screen++; + verbose_logfile++; break; case 'E': if (++operation_specified > 1) { @@ -366,6 +370,19 @@ cli_classic_usage(argv[0]); exit(0); break; + case 'o': +#ifdef STANDALONE + fprintf(stderr, "Log file not supported in standalone " + "mode. Aborting.\n"); + cli_classic_abort_usage(); +#else /* STANDALONE */ + log_name = strdup(optarg); + if (log_name[0] == '\0') { + fprintf(stderr, "No log filename specified.\n"); + cli_classic_abort_usage(); + } +#endif /* STANDALONE */ + break; default: cli_classic_abort_usage(); break; @@ -377,20 +394,40 @@ cli_classic_abort_usage(); }
- /* FIXME: Print the actions flashrom will take. */ - - if (list_supported) { - print_supported(); - exit(0); + if ((read_it | write_it | verify_it) && !filename) { + fprintf(stderr, "Error: No filename specified.\n"); + cli_classic_abort_usage(); } + if (filename && (filename[0] == '\0')) { + fprintf(stderr, "Error: No filename specified.\n"); + cli_classic_abort_usage(); + } + if (filename && (filename[0] == '-')) + fprintf(stderr, "Warning: Supplied file name starts with -\n");
+#ifndef STANDALONE + if (log_name && (log_name[0] == '-')) + fprintf(stderr, "Warning: Supplied file name starts with -\n"); + if (log_name && open_logfile(log_name)) + return 1; +#endif /* !STANDALONE */ + #if CONFIG_PRINT_WIKI == 1 if (list_supported_wiki) { print_supported_wiki(); - exit(0); + ret = 0; + goto out; } #endif
+ if (list_supported) { + print_supported(); + ret = 0; + goto out; + } + + // FIXME: cli_classic_abort_usage() does exit(1) and we rely on the OS + // to flush log file buffers. Is that behaviour guaranteed? if (layoutfile && read_romlayout(layoutfile)) cli_classic_abort_usage(); if (process_include_args()) @@ -415,11 +452,22 @@ if (prog == PROGRAMMER_INVALID) prog = default_programmer;
+#ifndef STANDALONE + start_logging(); +#endif /* STANDALONE */ + + msg_gdbg("Command line:"); + for (i = 0; i < argc; i++) { + msg_gdbg(" %s", argv[i]); + } + msg_gdbg("\n"); + + /* FIXME: Delay calibration should happen in programmer code. */ myusec_calibrate_delay();
if (programmer_init(prog, pparam)) { - fprintf(stderr, "Error: Programmer initialization failed.\n"); + msg_perr("Error: Programmer initialization failed.\n"); ret = 1; goto out_shutdown; } @@ -442,25 +490,25 @@ }
if (chipcount > 1) { - printf("Multiple flash chips were detected: "%s"", - flashes[0].name); + msg_cinfo("Multiple flash chips were detected: "%s"", + flashes[0].name); for (i = 1; i < chipcount; i++) - printf(", "%s"", flashes[i].name); - printf("\nPlease specify which chip to use with the " - "-c <chipname> option.\n"); + msg_cinfo(", "%s"", flashes[i].name); + msg_cinfo("\nPlease specify which chip to use with the -c " + "<chipname> option.\n"); ret = 1; goto out_shutdown; } else if (!chipcount) { - printf("No EEPROM/flash device found.\n"); + msg_cinfo("No EEPROM/flash device found.\n"); if (!force || !chip_to_probe) { - printf("Note: flashrom can never write if the flash " - "chip isn't found automatically.\n"); + msg_cinfo("Note: flashrom can never write if the flash " + "chip isn't found automatically.\n"); } if (force && read_it && chip_to_probe) { struct registered_programmer *pgm; int compatible_programmers = 0; - printf("Force read (-f -r -c) requested, pretending " - "the chip is there:\n"); + msg_cinfo("Force read (-f -r -c) requested, pretending " + "the chip is there:\n"); /* This loop just counts compatible controllers. */ for (j = 0; j < registered_programmer_count; j++) { pgm = ®istered_programmers[j]; @@ -468,9 +516,9 @@ compatible_programmers++; } if (compatible_programmers > 1) - printf("More than one compatible controller " - "found for the requested flash chip, " - "using the first one.\n"); + msg_cinfo("More than one compatible controller " + "found for the requested flash chip, " + "using the first one.\n"); for (j = 0; j < registered_programmer_count; j++) { pgm = ®istered_programmers[j]; startchip = probe_flash(pgm, 0, &flashes[0], 1); @@ -478,14 +526,15 @@ break; } if (startchip == -1) { - printf("Probing for flash chip '%s' failed.\n", - chip_to_probe); + msg_cinfo("Probing for flash chip '%s' failed." + "\n", chip_to_probe); ret = 1; goto out_shutdown; } - printf("Please note that forced reads most likely " - "contain garbage.\n"); - return read_flash_to_file(&flashes[0], filename); + msg_cinfo("Please note that forced reads most likely " + "contain garbage.\n"); + ret = read_flash_to_file(&flashes[0], filename); + goto out_shutdown; } ret = 1; goto out_shutdown; @@ -505,23 +554,17 @@ size = fill_flash->total_size * 1024; if (check_max_decode(fill_flash->pgm->buses_supported & fill_flash->bustype, size) && (!force)) { - fprintf(stderr, "Chip is too big for this programmer " - "(-V gives details). Use --force to override.\n"); + msg_cerr("Chip is too big for this programmer " + "(-V gives details). Use --force to override.\n"); ret = 1; goto out_shutdown; }
if (!(read_it | write_it | verify_it | erase_it)) { - printf("No operations were specified.\n"); + msg_ginfo("No operations were specified.\n"); goto out_shutdown; }
- if (!filename && !erase_it) { - printf("Error: No filename specified.\n"); - ret = 1; - goto out_shutdown; - } - /* Always verify write operations unless -n is used. */ if (write_it && !dont_verify_it) verify_it = 1; @@ -531,9 +574,13 @@ * Give the chip time to settle. */ programmer_delay(100000); - return doit(fill_flash, force, filename, read_it, write_it, erase_it, verify_it); + ret |= doit(fill_flash, force, filename, read_it, write_it, erase_it, verify_it);
out_shutdown: programmer_shutdown(); +out: +#ifndef STANDALONE + ret |= close_logfile(); +#endif return ret; } Index: flashrom-logfile/flashrom.c =================================================================== --- flashrom-logfile/flashrom.c (Revision 1528) +++ flashrom-logfile/flashrom.c (Arbeitskopie) @@ -40,7 +40,8 @@
const char flashrom_version[] = FLASHROM_VERSION; char *chip_to_probe = NULL; -int verbose = 0; +int verbose_screen = MSG_INFO; +int verbose_logfile = MSG_DEBUG;
static enum programmer programmer = PROGRAMMER_INVALID;
@@ -1457,27 +1458,27 @@ if (firstline) firstline = 0; else - printf("\n"); + msg_ginfo("\n"); for (i = 0; i < startcol; i++) - printf(" "); + msg_ginfo(" "); remaining = cols - startcol; } else { - printf(" "); + msg_ginfo(" "); remaining--; } if (paren && (p == 0)) { - printf("("); + msg_ginfo("("); remaining--; } - printf("%s", pname); + msg_ginfo("%s", pname); remaining -= pnamelen; if (p < PROGRAMMER_INVALID - 1) { - printf(","); + msg_ginfo(","); remaining--; } else { if (paren) - printf(")"); - printf("\n"); + msg_ginfo(")"); + msg_ginfo("\n"); } } } @@ -1493,35 +1494,35 @@ #else msg_ginfo(" on unknown machine"); #endif - msg_ginfo(", built with"); + msg_gdbg(", built with"); #if NEED_PCI == 1 #ifdef PCILIB_VERSION - msg_ginfo(" libpci %s,", PCILIB_VERSION); + msg_gdbg(" libpci %s,", PCILIB_VERSION); #else - msg_ginfo(" unknown PCI library,"); + msg_gdbg(" unknown PCI library,"); #endif #endif #ifdef __clang__ - msg_ginfo(" LLVM Clang"); + msg_gdbg(" LLVM Clang"); #ifdef __clang_version__ - msg_ginfo(" %s,", __clang_version__); + msg_gdbg(" %s,", __clang_version__); #else - msg_ginfo(" unknown version (before r102686),"); + msg_gdbg(" unknown version (before r102686),"); #endif #elif defined(__GNUC__) - msg_ginfo(" GCC"); + msg_gdbg(" GCC"); #ifdef __VERSION__ - msg_ginfo(" %s,", __VERSION__); + msg_gdbg(" %s,", __VERSION__); #else - msg_ginfo(" unknown version,"); + msg_gdbg(" unknown version,"); #endif #else - msg_ginfo(" unknown compiler,"); + msg_gdbg(" unknown compiler,"); #endif #if defined (__FLASHROM_LITTLE_ENDIAN__) - msg_ginfo(" little endian"); + msg_gdbg(" little endian"); #else - msg_ginfo(" big endian"); + msg_gdbg(" big endian"); #endif msg_ginfo("\n"); } @@ -1534,7 +1535,7 @@
void print_banner(void) { - msg_ginfo("flashrom is free software, get the source code at " + msg_ginfo("flashrom is free software. Get the source code at " "http://www.flashrom.org%5Cn"); msg_ginfo("\n"); } @@ -1840,6 +1841,5 @@ free(oldcontents); free(newcontents); out_nofree: - programmer_shutdown(); return ret; }