Re: [flashrom] [PATCH] Clean up msg_*

[Carl-Daniel Hailfinger]

Am 12.05.2012 01:48 schrieb Stefan Tauner:
> On Fri, 11 May 2012 07:10:08 +0200
> Carl-Daniel Hailfinger  wrote:
> > Am 09.05.2012 12:28 schrieb Carl-Daniel Hailfinger:
> > > Convert printf to msg_* where appropriate.
> > > Clean up cli_output.c to be more readable.
> > > Use enum instead of #define for message levels.
> > > Kill a few exit(0) calls.
> > > Print the command line arguments in verbose mode.
> > > Move actions (--list-supported etc.) after argument sanity checks.
> > > Reduce the number of code paths which have their own programmer_shutdown().
> > >
> > > Note: This patch was formerly part of the logfile patch, but that made
> > > review harder.
> >
> > New version.
> > The only remaining issue mentioned in review is "WARNING" vs. "Warning"
> > capitalization. We could postpone that decision, or decide now.
> >
> > Signed-off-by: Carl-Daniel Hailfinger
>
> comments starting with * are mandatory for the ack below.

Thanks for the review.
> > Index: flashrom-message_reorg/cli_output.c
> >
> > --- flashrom-message_reorg/cli_output.c	(Revision 1534)
> > +++ flashrom-message_reorg/cli_output.c	(Arbeitskopie)
> > @@ -22,34 +22,25 @@
> > [..]
> > va_start(ap, fmt);
> > ret = vfprintf(output_type, fmt, ap);
> > va_end(ap);
> > fflush(output_type);
> > if (level <= verbose) {
> > va_start(ap, fmt);
> > ret = vfprintf(output_type, fmt, ap);
> > va_end(ap);
> > /* msg_*spew usually happens inside chip accessors in possibly
> >  * time-critical operations. Don't slow them down by flushing.
>
> counter-proposal:
> /* msg_*spew * * happens inside chip accessors in possibly
>  * time-critical operations *too*. Don't slow them down by flushing.
>
> is it really *usually*?
> hm most often in the resulting output, yes maybe...

I'd even say "almost always", but that's probably a bit extreme.
> > Index: flashrom-message_reorg/cli_classic.c
> >
> > --- flashrom-message_reorg/cli_classic.c	(Revision 1534)
> > +++ flashrom-message_reorg/cli_classic.c	(Arbeitskopie)
> > @@ -415,11 +426,17 @@
> >    if (prog == PROGRAMMER_INVALID)
> >    	prog = default_programmer;
> > msg_gdbg("Command line:");
> > for (i = 0; i < argc; i++) {
> > msg_gdbg(" %s", argv[i]);
>
> additional " " would ease debugging really stupid shell problems, but
> would make it less readable in almost all circumstances.
> making them appear in -VVV output would be an option but waaaay too
> overkill... sorry that little prefectionist[1] crept out again ;)
>
> ./flashrom -p dummy:emulate=MX25L6436,spi_status=0x1 -V -c "SFDP-capable chip" -w bla
> [...]
> Command line: ./flashrom -p dummy:emulate=MX25L6436,spi_status=0x1 -V -c SFDP-capable chip -w bla
>
> note the missing " on the -c option.

Can be debugged easily with the new argument count in the command line echo.
> > 		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;
>
> hm... the programmer shutdown was never called in this code path before
> the patch?

Indeed, that was a bug.
> if so and you want to revert the shutdown change (see below), please
> add an explicit call here.

The shutdown change was reverted, the goto was kept. Bug fixed.
> > Index: flashrom-message_reorg/flashrom.c
> >
> > --- flashrom-message_reorg/flashrom.c	(Revision 1534)
> > +++ flashrom-message_reorg/flashrom.c	(Arbeitskopie)
> > @@ -40,7 +40,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");
> >
> > }
>
> i have never understood why flashrom prints that - even with a \n\n
> effectively, although the main developer argues about every other
> wasteful line printed ;)
>
> could be joined to a single loc (well or at least 2 if you want to
> leave the stray \n) due to our new line length limit...

Extra empty line will be killed, reformatting will be done in a followup
patch.
> > @@ -1840,6 +1840,5 @@
> >    free(oldcontents);
> >    free(newcontents);
> >  out_nofree:
> > programmer_shutdown();
>
> i guess this breaks google's cli?

It would, yes. Reverted for now.
> i dont see why this part should actually move into the cli file(s).
> rather the stuff from cli_classic.c starting from the
> myusec_calibrate_delay call should move into flashrom.c (or somewhere else).

Indeed. We would have to handle the additional functionality Google
needs from flashrom, though. AFAIK that's status register access
(read/write) and region unlocking/locking. We want that anyway sometime
in the future.
> yes there are some ui-related messages in there, but they are
> everywhere... and should be made ui-agnostic or ui-refering
> (i.e. printing messages depending on the current ui).
> i think dropping this change and the related ones in cli_classic.c
> for now is the best option. your choice though, since i think it does
> not *break* stuff in the trunk and may ease later refactoring of that
> code to a proper location.

Reverted for now.
> this was way harder to review than expected and although there is
> quite some place for nit-picking and further discussion i think it
> improves the code after all, hence this is
> Acked-by: Stefan Tauner 
> if the notes starting with * are all thought through two or more times :)

I changed some more stuff to make error handling more consistent. A nice
bonus are more killed exit(...) calls.

Signed-off-by: Carl-Daniel Hailfinger

Index: flashrom-message_reorg/flash.h
===================================================================
--- flashrom-message_reorg/flash.h	(Revision 1534)
+++ flashrom-message_reorg/flash.h	(Arbeitskopie)
@@ -268,13 +268,15 @@
 #define ERROR_FLASHROM_LIMIT -201

/* cli_output.c */
+enum msglevel {
+	MSG_ERROR	= 0,
+	MSG_INFO	= 1,
+	MSG_DEBUG	= 2,
+	MSG_DEBUG2	= 3,
+	MSG_SPEW	= 4,
+};
 /* 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
+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 */
@@ -287,9 +289,9 @@
 #define msg_gdbg2(...)	print(MSG_DEBUG2, __VA_ARGS__)	/* general debug2 */
 #define msg_pdbg2(...)	print(MSG_DEBUG2, __VA_ARGS__)	/* programmer debug2 */
 #define msg_cdbg2(...)	print(MSG_DEBUG2, __VA_ARGS__)	/* chip debug2 */
-#define msg_gspew(...)	print(MSG_BARF, __VA_ARGS__)	/* general debug barf  */
-#define msg_pspew(...)	print(MSG_BARF, __VA_ARGS__)	/* programmer debug barf  */
-#define msg_cspew(...)	print(MSG_BARF, __VA_ARGS__)	/* chip debug barf  */
+#define msg_gspew(...)	print(MSG_SPEW, __VA_ARGS__)	/* general debug spew  */
+#define msg_pspew(...)	print(MSG_SPEW, __VA_ARGS__)	/* programmer debug spew  */
+#define msg_cspew(...)	print(MSG_SPEW, __VA_ARGS__)	/* chip debug spew  */

/* layout.c */
 int register_include_arg(char *name);
Index: flashrom-message_reorg/cli_output.c
===================================================================
--- flashrom-message_reorg/cli_output.c	(Revision 1534)
+++ flashrom-message_reorg/cli_output.c	(Arbeitskopie)
@@ -22,34 +22,25 @@
 #include <stdarg.h>
 #include "flash.h"

-int print(int type, const char *fmt, ...)
+/* 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_type = stdout;

-	switch (type) {
-	case MSG_ERROR:
+	if (level == 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;
-	}

-	va_start(ap, fmt);
-	ret = vfprintf(output_type, fmt, ap);
-	va_end(ap);
-	fflush(output_type);
+	if (level <= verbose) {
+		va_start(ap, fmt);
+		ret = vfprintf(output_type, 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_SPEW)
+			fflush(output_type);
+	}
    return ret;
 }
Index: flashrom-message_reorg/cli_classic.c
===================================================================
--- flashrom-message_reorg/cli_classic.c	(Revision 1534)
+++ flashrom-message_reorg/cli_classic.c	(Arbeitskopie)
@@ -159,6 +159,22 @@
    exit(1);
 }

+static int check_filename(char *filename, char *type)
+{
+	if (!filename) {
+		fprintf(stderr, "Error: No %s file specified.\n", type);
+		return 1;
+	}
+	if (filename[0] == '\0') {
+		fprintf(stderr, "Error: No %s file specified.\n", type);
+		return 1;
+	}
+	/* Not an error, but maybe the user intended to specify a CLI option instead of a file name. */
+	if (filename[0] == '-')
+		fprintf(stderr, "Warning: Supplied %s file name starts with -\n", type);
+	return 0;
+}
+
 int main(int argc, char *argv[])
 {
    unsigned long size;
@@ -377,36 +393,51 @@
    	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) && check_filename(filename, "image")) {
+		cli_classic_abort_usage();
    }
+	if (layoutfile && check_filename(layoutfile, "layout")) {
+		cli_classic_abort_usage();
+	}

#if CONFIG_PRINT_WIKI == 1
    if (list_supported_wiki) {
    	print_supported_wiki();
-		exit(0);
+		ret = 0;
+		goto out;
    }
 #endif

-	if (layoutfile && read_romlayout(layoutfile))
-		cli_classic_abort_usage();
-	if (process_include_args())
-		cli_classic_abort_usage();
+	if (list_supported) {
+		print_supported();
+		ret = 0;
+		goto out;
+	}

+	msg_gdbg("Command line (%i args):", argc - 1);
+	for (i = 0; i < argc; i++) {
+		msg_gdbg(" %s", argv[i]);
+	}
+	msg_gdbg("\n");
+
+	if (layoutfile && read_romlayout(layoutfile)) {
+		ret = 1;
+		goto out;
+	}
+	if (process_include_args()) {
+		ret = 1;
+		goto out;
+	}
    /* Does a chip with the requested name exist in the flashchips array? */
    if (chip_to_probe) {
    	for (flash = flashchips; flash && flash->name; flash++)
    		if (!strcmp(flash->name, chip_to_probe))
    			break;
    	if (!flash || !flash->name) {
-			fprintf(stderr, "Error: Unknown chip '%s' specified.\n",
-				chip_to_probe);
-			printf("Run flashrom -L to view the hardware supported "
-			       "in this flashrom version.\n");
-			exit(1);
+			msg_cerr("Error: Unknown chip '%s' specified.\n", chip_to_probe);
+			msg_gerr("Run flashrom -L to view the hardware supported in this flashrom version.\n");
+			ret = 1;
+			goto out;
    	}
    	/* Clean up after the check. */
    	flash = NULL;
@@ -419,7 +450,7 @@
    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 +473,22 @@
    }

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 = &registered_programmers[j];
@@ -468,9 +496,8 @@
    				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 = &registered_programmers[j];
    			startchip = probe_flash(pgm, 0, &flashes[0], 1);
@@ -478,14 +505,13 @@
    				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;
@@ -503,25 +529,17 @@
    check_chip_supported(fill_flash);

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");
+	if (check_max_decode(fill_flash->pgm->buses_supported & fill_flash->bustype, size) && (!force)) {
+		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 +549,12 @@
     * 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);
+	/* Note: doit() already calls programmer_shutdown(). */
+	goto out;

out_shutdown:
    programmer_shutdown();
+out:
    return ret;
 }
Index: flashrom-message_reorg/flashrom.c
===================================================================
--- flashrom-message_reorg/flashrom.c	(Revision 1534)
+++ flashrom-message_reorg/flashrom.c	(Arbeitskopie)
@@ -40,7 +40,7 @@

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

static enum programmer programmer = PROGRAMMER_INVALID;

@@ -1457,27 +1457,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");
    	}
    }
 }