Re: [flashrom] [PATCH] Add logfile support to flashrom

[Carl-Daniel Hailfinger]

Am 18.05.2012 00:59 schrieb Stefan Tauner:
> On Wed, 16 May 2012 08:26:32 +0200
> Carl-Daniel Hailfinger  wrote:
> > Am 10.05.2012 00:48 schrieb Carl-Daniel Hailfinger:
> > > Am 09.05.2012 15:54 schrieb Stefan Tauner:
> > > > On Wed, 09 May 2012 15:16:04 +0200 Carl-Daniel Hailfinger wrote: 
> > > > we use both - WARNING and Warning - throughout the code. is that
> > > > intended? if so what's the policy? if not then we should fix it. i
> > > > think (without looking at any specific case) that WARNING is warranted
> > > > because it sticks out more (especially in verbose outputs). as long as
> > > > we dont want to play with bold or colored text... :)
> > >
> > > <blink>WARNING</blink>
> > >
> > > The point about "Warning" vs. "WARNING" is intricately linked to whether
> > > you believe there should be one or two levels of warnings ("retrying a
> > > different erase command"  vs "your EC is stuck, and we just erased its
> > > firmware"). Even a really serious warning is not an error because
> > > flashrom may be theoretically able to fix this while it is still running.
> > > That's largely nitpicking, though. I have no really strong feelings
> > > about this.
> >
> > Besides that, we need msg_*warn in addition to msg_*err.
>
> and msg_*warn2: if you really want to distinguish between WARNING and
> Warning, this should be done explicitly and with some policy similar to
> how the rest of the verbosity scheme works.
> > Anyway, here is a new log file patch. It should work, and I hope I
> > killed most/all of the controversial points.
> > Well, except the programmer_shutdown changes which might be unnecessary
> > with the new code flow introduced in the msg_* cleanup.
> > The print_version() change is in this patch because it's a behavioural
> > change needed for reasonable log file writing.
>
> what changes exactly?
> the verbosity changes in print_sysinfo are useless regarding the log
> file support: stdout/err and log file are equal with and without those
> changes. they should have been in the previous cleanup patch imho.
> > Signed-off-by: Carl-Daniel Hailfinger
> > Index: flashrom-logfile/flash.h
> >
> > --- flashrom-logfile/flash.h	(Revision 1536)
> > +++ flashrom-logfile/flash.h	(Arbeitskopie)
> > […]
> >  /* cli_output.c */
> > +#ifndef STANDALONE
> > +int open_logfile(const char * const filename);
> > +int close_logfile(void);
> > +void start_logging(void);
> > +#endif
>
> hm... while logging is not useful inside coreboot, it certainly is
> somewhat useful in code using libflashrom...
> side note: the name STANDALONE sucks.
> > Index: flashrom-logfile/cli_output.c
> >
> > --- flashrom-logfile/cli_output.c	(Revision 1536)
> > +++ flashrom-logfile/cli_output.c	(Arbeitskopie)
> > @@ -2,6 +2,7 @@
> > This file is part of the flashrom project.
> > Copyright (C) 2009 Sean Nelson
> > 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,8 +21,53 @@
> >
> > #include <stdio.h>
> >  #include <stdarg.h>
> > +#include <string.h>
> > +#include <errno.h>
> >  #include "flash.h"
> >
> > +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));
>
> new line limit
> > 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
>
> temporarily. */
> > verbose_screen = MSG_ERROR;
> > verbose_logfile = MSG_DEBUG;
> > print_version();
> > verbose_screen = oldverbose_screen;
> > verbose_logfile = oldverbose_logfile;
> >
> > +}
> > +#endif /* STANDALONE */
>
> actually it is !STANDALONE... that comment is worse than none imho.
> > /* Please note that level is the verbosity, not the importance of the message. */
> >  int print(enum msglevel level, const char *fmt, ...)
> >  {
> > @@ -32,7 +78,7 @@
> >    if (level == MSG_ERROR)
> >    	output_type = stderr;
> > if (level <= verbose) {
> > if (level <= verbose_screen) {
> > va_start(ap, fmt);
> > ret = vfprintf(output_type, fmt, ap);
> > va_end(ap);
> >
> > @@ -42,5 +88,12 @@
> >    	if (level != MSG_SPEW)
> >    		fflush(output_type);
> >    }
> > if ((level <= verbose_logfile) && logfile) {
> > va_start(ap, fmt);
> > ret = vfprintf(logfile, fmt, ap);
> > va_end(ap);
> > if (level != MSG_SPEW)
> > 	fflush(logfile);
> > }
> > return ret;
> >
> > }
> > Index: flashrom-logfile/cli_classic.c
> > ===================================================================
> > --- flashrom-logfile/cli_classic.c	(Revision 1536)
> > +++ 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 "
> > @@ -189,7 +190,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'},
> >
> > @@ -206,11 +207,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;
>
> the variable names for the different filenames are not very consistent.
>
> image_file
> layout_file
> log_file
> > char *tempstr = NULL;
> >    char *pparam = NULL;
> >
> > @@ -272,7 +275,8 @@
> >    		chip_to_probe = strdup(optarg);
> >    		break;
> >    	case 'V':
> > 	verbose++;
> > 	verbose_screen++;
> > 	verbose_logfile++;
> > break;
> > case 'E':
> > 	if (++operation_specified > 1) {
> >
> > @@ -378,6 +382,19 @@
> >    		cli_classic_usage(argv[0]);
> >    		exit(0);
> >    		break;
> > case 'o':
> >
> > +#ifdef STANDALONE
> > 	fprintf(stderr, "Log file not supported in standalone "
> > 		"mode. Aborting.\n");
>
> new line limit
> > 	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;
> >
> > @@ -396,6 +413,13 @@
> >    	cli_classic_abort_usage();
> >    }
> >
> > +#ifndef STANDALONE
> > if (log_name && check_filename(log_name, "log"))
> > cli_classic_abort_usage();
> > if (log_name && open_logfile(log_name))
> > return 1;
> >
> > +#endif /* !STANDALONE */
> >
> > #if CONFIG_PRINT_WIKI == 1
> >    if (list_supported_wiki) {
> >    	print_supported_wiki();
> > @@ -410,6 +434,10 @@
> >    	goto out;
> >    }
> >
> > +#ifndef STANDALONE
> > start_logging();
> >
> > +#endif /* STANDALONE */
> > msg_gdbg("Command line (%i args):", argc - 1);
> >  for (i = 0; i < argc; i++) {
> >   msg_gdbg(" %s", argv[i]);
> >
> > @@ -546,11 +574,12 @@
> >     */
> >    programmer_delay(100000);
> >    ret |= doit(fill_flash, force, filename, read_it, write_it, erase_it, verify_it);
> > /* Note: doit() already calls programmer_shutdown(). */
> > goto out;
> >
> > out_shutdown:
> >    programmer_shutdown();
> >  out:
> > +#ifndef STANDALONE
> > ret |= close_logfile();
> >
> > +#endif
> >    return ret;
> >  }
> > Index: flashrom-logfile/flashrom.c
> > ===================================================================
> > --- flashrom-logfile/flashrom.c	(Revision 1536)
> > +++ flashrom-logfile/flashrom.c	(Arbeitskopie)
> > @@ -40,7 +40,8 @@
> >
> > const char flashrom_version[] = FLASHROM_VERSION;
> >  char *chip_to_probe = NULL;
> > -int verbose = MSG_INFO;
> > +int verbose_screen = MSG_INFO;
> > +int verbose_logfile = MSG_DEBUG;
> >
> > static enum programmer programmer = PROGRAMMER_INVALID;
> >
> > @@ -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");
> >  }
> > @@ -1840,6 +1841,5 @@
> >    free(oldcontents);
> >    free(newcontents);
> >  out_nofree:
> > programmer_shutdown();
> > return ret;
> >
> > }
>
> TODO:
> minimum verbosity handling
>
> apart from that it would have been ack-able i think. looks very nice,
> small, clean and sane. thanks!
> pity we took so long.
> NB: i have not thoroughly tested it yet.

New version. IIRC the only remaining problem is the name of the variable
storing the log file name.

Signed-off-by: Carl-Daniel Hailfinger

Index: flashrom-logfile/flash.h
===================================================================
--- flashrom-logfile/flash.h	(Revision 1539)
+++ 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);
@@ -244,6 +245,7 @@
 int need_erase(uint8_t *have, uint8_t *want, unsigned int len, enum write_granularity gran);
 char *strcat_realloc(char *dest, const char *src);
 void print_version(void);
+void print_buildinfo(void);
 void print_banner(void);
 void list_programmers_linebreak(int startcol, int cols, int paren);
 int selfcheck(void);
@@ -268,6 +270,11 @@
 #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
 enum msglevel {
    MSG_ERROR	= 0,
    MSG_INFO	= 1,
Index: flashrom-logfile/cli_output.c
===================================================================
--- flashrom-logfile/cli_output.c	(Revision 1539)
+++ flashrom-logfile/cli_output.c	(Arbeitskopie)
@@ -2,6 +2,7 @@
  * This file is part of the flashrom project.
  *
  * Copyright (C) 2009 Sean Nelson 
+ * 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,8 +21,49 @@

#include <stdio.h>
 #include <stdarg.h>
+#include <string.h>
+#include <errno.h>
 #include "flash.h"

+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;
+
+	/* Shut up the console. */
+	verbose_screen = MSG_ERROR;
+	print_version();
+	verbose_screen = oldverbose_screen;
+}
+#endif /* !STANDALONE */
+
 /* Please note that level is the verbosity, not the importance of the message. */
 int print(enum msglevel level, const char *fmt, ...)
 {
@@ -32,7 +74,7 @@
    if (level == MSG_ERROR)
    	output_type = stderr;

-	if (level <= verbose) {
+	if (level <= verbose_screen) {
    	va_start(ap, fmt);
    	ret = vfprintf(output_type, fmt, ap);
    	va_end(ap);
@@ -42,5 +84,12 @@
    	if (level != MSG_SPEW)
    		fflush(output_type);
    }
+	if ((level <= verbose_logfile) && logfile) {
+		va_start(ap, fmt);
+		ret = vfprintf(logfile, fmt, ap);
+		va_end(ap);
+		if (level != MSG_SPEW)
+			fflush(logfile);
+	}
    return ret;
 }
Index: flashrom-logfile/cli_classic.c
===================================================================
--- flashrom-logfile/cli_classic.c	(Revision 1539)
+++ 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 "
@@ -189,7 +190,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'},
@@ -206,11 +207,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 *logfile = NULL;
    char *tempstr = NULL;
    char *pparam = NULL;

@@ -272,7 +275,9 @@
    		chip_to_probe = strdup(optarg);
    		break;
    	case 'V':
-			verbose++;
+			verbose_screen++;
+			if (verbose_screen > MSG_DEBUG2)
+				verbose_logfile = verbose_screen;
    		break;
    	case 'E':
    		if (++operation_specified > 1) {
@@ -378,6 +383,18 @@
    		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 */
+			logfile = strdup(optarg);
+			if (logfile[0] == '\0') {
+				fprintf(stderr, "No log filename specified.\n");
+				cli_classic_abort_usage();
+			}
+#endif /* STANDALONE */
+			break;
    	default:
    		cli_classic_abort_usage();
    		break;
@@ -396,6 +413,13 @@
    	cli_classic_abort_usage();
    }

+#ifndef STANDALONE
+	if (logfile && check_filename(logfile, "log"))
+		cli_classic_abort_usage();
+	if (logfile && open_logfile(logfile))
+		return 1;
+#endif /* !STANDALONE */
+
 #if CONFIG_PRINT_WIKI == 1
    if (list_supported_wiki) {
    	print_supported_wiki();
@@ -410,6 +434,11 @@
    	goto out;
    }

+#ifndef STANDALONE
+	start_logging();
+#endif /* !STANDALONE */
+
+	print_buildinfo();
    msg_gdbg("Command line (%i args):", argc - 1);
    for (i = 0; i < argc; i++) {
    	msg_gdbg(" %s", argv[i]);
@@ -552,5 +581,8 @@
 out_shutdown:
    programmer_shutdown();
 out:
+#ifndef STANDALONE
+	ret |= close_logfile();
+#endif /* !STANDALONE */
    return ret;
 }
Index: flashrom-logfile/flashrom.c
===================================================================
--- flashrom-logfile/flashrom.c	(Revision 1539)
+++ flashrom-logfile/flashrom.c	(Arbeitskopie)
@@ -40,7 +40,8 @@

const char flashrom_version[] = FLASHROM_VERSION;
 char *chip_to_probe = NULL;
-int verbose = MSG_INFO;
+int verbose_screen = MSG_INFO;
+int verbose_logfile = MSG_DEBUG2;

static enum programmer programmer = PROGRAMMER_INVALID;

@@ -1493,35 +1494,39 @@
 #else
    msg_ginfo(" on unknown machine");
 #endif
-	msg_ginfo(", built with");
+}
+
+void print_buildinfo(void)
+{
+	msg_gdbg("flashrom was 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");
 }
@@ -1530,6 +1535,7 @@
 {
    msg_ginfo("flashrom v%s", flashrom_version);
    print_sysinfo();
+	msg_ginfo("\n");
 }

void print_banner(void)