[flashrom] [PATCH 1/2] convert programmer print messages to msg_p*

Carl-Daniel Hailfinger c-d.hailfinger.devel.2006 at gmx.net
Tue Mar 30 07:33:35 CEST 2010


On 27.03.2010 21:12, Sean Nelson wrote:
> ---
>  board_enable.c   |   93 +++++++++++------------
>  cbtable.c        |   26 +++---
>  chipset_enable.c |  216 +++++++++++++++++++++++++++---------------------------
>  dmi.c            |   12 ++--
>  hwaccess.c       |    2 +-
>  ichspi.c         |   77 ++++++++-----------
>  internal.c       |    4 +-
>  pcidev.c         |   12 ++--
>  physmap.c        |   34 ++++----
>  spi.c            |    8 +-
>  10 files changed, 235 insertions(+), 249 deletions(-)
>
> diff --git a/board_enable.c b/board_enable.c
> index 9b05f76..9112011 100644
> --- a/board_enable.c
> +++ b/board_enable.c
> @@ -77,48 +77,48 @@ static int enable_flash_decode_superio(void)
>  	case SUPERIO_VENDOR_NONE:
>  		ret = -1;
>  		break;
>  	case SUPERIO_VENDOR_ITE:
>  		enter_conf_mode_ite(superio.port);
>  		/* Enable flash mapping. Works for most old ITE style Super I/O. */
>  		tmp = sio_read(superio.port, 0x24);
>  		tmp |= 0xfc;
>  		sio_write(superio.port, 0x24, tmp);
>  		exit_conf_mode_ite(superio.port);
>  		ret = 0;
>  		break;
>  	default:
> -		printf_debug("Unhandled Super I/O type!\n");
> +		msg_perr("Unhandled Super I/O type!\n");
>   

Until we have generic SuperIO support for all common SuperIO chips, this
isn't an error, and not even info level. _pdbg please.


> @@ -1431,44 +1428,44 @@ static struct board_pciid_enable *board_match_coreboot_name(const char *vendor,
>  
>  		if (!pci_dev_find(board->first_vendor, board->first_device))
>  			continue;
>  
>  		if (board->second_vendor &&
>  		    !pci_dev_find(board->second_vendor, board->second_device))
>  			continue;
>  
>  		if (vendor)
>  			return board;
>  
>  		if (partmatch) {
>  			/* a second entry has a matching part name */
> -			printf("AMBIGUOUS BOARD NAME: %s\n", part);
> -			printf("At least vendors '%s' and '%s' match.\n",
> +			msg_pinfo("AMBIGUOUS BOARD NAME: %s\n", part);
> +			msg_pinfo("At least vendors '%s' and '%s' match.\n",
>  			       partmatch->lb_vendor, board->lb_vendor);
> -			printf("Please use the full -m vendor:part syntax.\n");
> +			msg_pinfo("Please use the full -m vendor:part syntax.\n");
>  			return NULL;
>  		}
>  		partmatch = board;
>  	}
>  
>  	if (partmatch)
>  		return partmatch;
>  
>  	if (!partvendor_from_cbtable) {
>  		/* Only warn if the mainboard type was not gathered from the
>  		 * coreboot table. If it was, the coreboot implementor is
>  		 * expected to fix flashrom, too.
>  		 */
> -		printf("\nUnknown vendor:board from -m option: %s:%s\n\n",
> +		msg_pinfo("\nUnknown vendor:board from -m option: %s:%s\n\n",
>   

_perr please.


>  		       vendor, part);
>  	}
>  	return NULL;
>  }
>  
>  /**
>   * Match boards on PCI IDs and subsystem IDs.
>   * Second set of IDs can be main only or missing completely.
>   */
>  static struct board_pciid_enable *board_match_pci_card_ids(void)
>  {
>  	struct board_pciid_enable *board = board_pciid_enables;
>  
> @@ -1488,27 +1485,27 @@ static struct board_pciid_enable *board_match_pci_card_ids(void)
>  						   board->second_device,
>  						   board->second_card_vendor,
>  						   board->second_card_device))
>  					continue;
>  			} else {
>  				if (!pci_dev_find(board->second_vendor,
>  						  board->second_device))
>  					continue;
>  			}
>  		}
>  
>  		if (board->dmi_pattern) {
>  			if (!has_dmi_support) {
> -				fprintf(stderr, "WARNING: Can't autodetect %s %s,"
> +				msg_perr("WARNING: Can't autodetect %s %s,"
>   

Not sure about this one. Could be downgraded to _pinfo since this will
clutter up the logs on machines without dmidecode.


>  				       " DMI info unavailable.\n",
>  				       board->vendor_name, board->board_name);
>  				continue;
>  			} else {
>  				if (!dmi_match(board->dmi_pattern))
>  					continue;
>  			}
>  		}
>  
>  		return board;
>  	}
>  
>  	return NULL;
> @@ -1517,47 +1514,47 @@ static struct board_pciid_enable *board_match_pci_card_ids(void)
>  int board_flash_enable(const char *vendor, const char *part)
>  {
>  	struct board_pciid_enable *board = NULL;
>  	int ret = 0;
>  
>  	if (part)
>  		board = board_match_coreboot_name(vendor, part);
>  
>  	if (!board)
>  		board = board_match_pci_card_ids();
>  
>          if (board && board->status == NT) {
>                  if (!force_boardenable) {
> -                        printf("WARNING: Your mainboard is %s %s, but the mainboard-specific\n"
> +                        msg_pinfo("WARNING: Your mainboard is %s %s, but the mainboard-specific\n"
>                                 "code has not been tested, and thus will not not be executed by default.\n"
>                                 "Depending on your hardware environment, erasing, writing or even probing\n"
>                                 "can fail without running the board specific code.\n\n"
>                                 "Please see the man page (section PROGRAMMER SPECIFIC INFO, subsection\n"
>                                 "\"internal programmer\") for details.\n",
>                                 board->vendor_name, board->board_name);
>                          board = NULL;
>                  } else {
> -                        printf("NOTE: Running an untested board enable procedure.\n"
> +                        msg_pinfo("NOTE: Running an untested board enable procedure.\n"
>                                 "Please report success/failure to flashrom at flashrom.org.\n");
>  		}
>          }
>  
>  	if (board) {
>  		if (board->max_rom_decode_parallel)
>  			max_rom_decode.parallel =
>  				board->max_rom_decode_parallel * 1024;
>  
>  		if (board->enable != NULL) {
> -			printf("Disabling flash write protection for "
> +			msg_pinfo("Disabling flash write protection for "
>  			       "board \"%s %s\"... ", board->vendor_name,
>  			       board->board_name);
>  
>  			ret = board->enable(board->vendor_name);
>  			if (ret)
> -				printf("FAILED!\n");
> +				msg_pinfo("FAILED!\n");
>   

Mh. _perr?


>  			else
> -				printf("OK.\n");
> +				msg_pinfo("OK.\n");
>  		}
>  	}
>  
>  	return ret;
>  }
> diff --git a/cbtable.c b/cbtable.c
> index c12354c..ce74381 100644
> --- a/cbtable.c
> +++ b/cbtable.c
> @@ -102,76 +102,76 @@ static int count_lb_records(struct lb_header *head)
>  static struct lb_header *find_lb_table(void *base, unsigned long start,
>  				       unsigned long end)
>  {
>  	unsigned long addr;
>  
>  	/* For now be stupid.... */
>  	for (addr = start; addr < end; addr += 16) {
>  		struct lb_header *head =
>  		    (struct lb_header *)(((char *)base) + addr);
>  		struct lb_record *recs =
>  		    (struct lb_record *)(((char *)base) + addr + sizeof(*head));
>  		if (memcmp(head->signature, "LBIO", 4) != 0)
>  			continue;
> -		printf_debug("Found candidate at: %08lx-%08lx\n",
> +		msg_pdbg("Found candidate at: %08lx-%08lx\n",
>  			     addr, addr + head->table_bytes);
>  		if (head->header_bytes != sizeof(*head)) {
> -			fprintf(stderr, "Header bytes of %d are incorrect.\n",
> +			msg_pdbg("Header bytes of %d are incorrect.\n",
>   

Since this is a warning about a corrupt cbtable, maybe we should indeed
use _perr.


>  				head->header_bytes);
>  			continue;
>  		}
>  		if (count_lb_records(head) != head->table_entries) {
> -			fprintf(stderr, "Bad record count: %d.\n",
> +			msg_pdbg("Bad record count: %d.\n",
>   

dito


>  				head->table_entries);
>  			continue;
>  		}
>  		if (compute_checksum((uint8_t *) head, sizeof(*head)) != 0) {
> -			fprintf(stderr, "Bad header checksum.\n");
> +			msg_pdbg("Bad header checksum.\n");
>   

dito


>  			continue;
>  		}
>  		if (compute_checksum(recs, head->table_bytes)
>  		    != head->table_checksum) {
> -			fprintf(stderr, "Bad table checksum: %04x.\n",
> +			msg_pdbg("Bad table checksum: %04x.\n",
>   

dito


>  				head->table_checksum);
>  			continue;
>  		}
> -		printf_debug("Found coreboot table at 0x%08lx.\n", addr);
> +		msg_pdbg("Found coreboot table at 0x%08lx.\n", addr);
>  		return head;
>  
>  	};
>  
>  	return 0;
>  }
>  
> @@ -200,55 +200,55 @@ int coreboot_init(void)
>  	struct lb_header *lb_table;
>  	struct lb_record *rec, *last;
>  
>  #ifdef __DARWIN__
>  	/* This is a hack. DirectIO fails to map physical address 0x00000000.
>  	 * Why?
>  	 */
>  	start = 0x400;
>  #else
>  	start = 0x0;
>  #endif
>  	table_area = physmap_try_ro("low megabyte", start, BYTES_TO_MAP - start);
>  	if (!table_area) {
> -		msg_perr("Failed getting access to coreboot low tables.\n");
> +		msg_pdbg("Failed getting access to coreboot low tables.\n");
>   

I'd say this is definitely _perr.


>  		return -1;
>  	}
>  
>  	lb_table = find_lb_table(table_area, 0x00000, 0x1000);
>  	if (!lb_table)
>  		lb_table = find_lb_table(table_area, 0xf0000 - start, BYTES_TO_MAP - start);
>  	if (lb_table) {
>  		struct lb_forward *forward = (struct lb_forward *)
>  			(((char *)lb_table) + lb_table->header_bytes);
>  		if (forward->tag == LB_TAG_FORWARD) {
>  			start = forward->forward;
>  			start &= ~(getpagesize() - 1);
>  			physunmap(table_area, BYTES_TO_MAP);
>  			table_area = physmap_try_ro("high tables", start, BYTES_TO_MAP);
>  			if (!table_area) {
> -				msg_perr("Failed getting access to coreboot "
> +				msg_pdbg("Failed getting access to coreboot "
>   

Same here. We complain loudly if DMI is inaccessible, so this should be
similar.


> diff --git a/chipset_enable.c b/chipset_enable.c
> index fc60484..f447685 100644
> --- a/chipset_enable.c
> +++ b/chipset_enable.c
> @@ -64,46 +64,46 @@ static int enable_flash_sis85c496(struct pci_dev *dev, const char *name)
>  
>  static int enable_flash_sis_mapping(struct pci_dev *dev, const char *name)
>  {
>  	uint8_t new, newer;
>  
>  	/* Extended BIOS enable = 1, Lower BIOS Enable = 1 */
>  	/* This is 0xFFF8000~0xFFFF0000 decoding on SiS 540/630. */
>  	new = pci_read_byte(dev, 0x40);
>  	new &= (~0x04); /* No idea why we clear bit 2. */
>  	new |= 0xb; /* 0x3 for some chipsets, bit 7 seems to be don't care. */
>  	pci_write_byte(dev, 0x40, new);
>  	newer = pci_read_byte(dev, 0x40);
>  	if (newer != new) {
> -		printf_debug("tried to set register 0x%x to 0x%x on %s failed (WARNING ONLY)\n", 0x40, new, name);
> -		printf_debug("Stuck at 0x%x\n", newer);
> +		msg_pdbg("tried to set register 0x%x to 0x%x on %s failed (WARNING ONLY)\n", 0x40, new, name);
> +		msg_pdbg("Stuck at 0x%x\n", newer);
>   

Mh. _pinfo or even _perr?


> @@ -152,54 +152,54 @@ static int enable_flash_sis530(struct pci_dev *dev, const char *name)
>  
>  	sbdev = find_southbridge(dev->vendor_id, name);
>  	if (!sbdev)
>  		return -1;
>  
>  	ret = enable_flash_sis_mapping(sbdev, name);
>  
>  	new = pci_read_byte(sbdev, 0x45);
>  	new &= (~0x20);
>  	new |= 0x4;
>  	pci_write_byte(sbdev, 0x45, new);
>  	newer = pci_read_byte(sbdev, 0x45);
>  	if (newer != new) {
> -		printf_debug("tried to set register 0x%x to 0x%x on %s failed (WARNING ONLY)\n", 0x45, new, name);
> -		printf_debug("Stuck at 0x%x\n", newer);
> +		msg_pdbg("tried to set register 0x%x to 0x%x on %s failed (WARNING ONLY)\n", 0x45, new, name);
> +		msg_pdbg("Stuck at 0x%x\n", newer);
>   

_pinfo or even _perr?


>  		ret = -1;
>  	}
>  
>  	return ret;
>  }
>  
>  static int enable_flash_sis540(struct pci_dev *dev, const char *name)
>  {
>  	uint8_t new, newer;
>  	int ret = 0;
>  	struct pci_dev *sbdev;
>  
>  	sbdev = find_southbridge(dev->vendor_id, name);
>  	if (!sbdev)
>  		return -1;
>  
>  	ret = enable_flash_sis_mapping(sbdev, name);
>  
>  	new = pci_read_byte(sbdev, 0x45);
>  	new &= (~0x80);
>  	new |= 0x40;
>  	pci_write_byte(sbdev, 0x45, new);
>  	newer = pci_read_byte(sbdev, 0x45);
>  	if (newer != new) {
> -		printf_debug("tried to set register 0x%x to 0x%x on %s failed (WARNING ONLY)\n", 0x45, new, name);
> -		printf_debug("Stuck at 0x%x\n", newer);
> +		msg_pdbg("tried to set register 0x%x to 0x%x on %s failed (WARNING ONLY)\n", 0x45, new, name);
> +		msg_pdbg("Stuck at 0x%x\n", newer);
>   

_pinfo or even _perr?


>  		ret = -1;
>  	}
>  
>  	return ret;
>  }
>  
> @@ -225,63 +225,63 @@ static int enable_flash_piix4(struct pci_dev *dev, const char *name)
>  	 */
>  	if (dev->device_id == 0x122e || dev->device_id == 0x7000
>  	    || dev->device_id == 0x1234)
>  		new = old | 0x00c4; /* PIIX/PIIX3/MPIIX: Bit 9 is reserved. */
>  	else
>  		new = old | 0x02c4;
>  
>  	if (new == old)
>  		return 0;
>  
>  	pci_write_word(dev, xbcs, new);
>  
>  	if (pci_read_word(dev, xbcs) != new) {
> -		printf_debug("tried to set 0x%x to 0x%x on %s failed (WARNING ONLY)\n", xbcs, new, name);
> +		msg_pdbg("tried to set 0x%x to 0x%x on %s failed (WARNING ONLY)\n", xbcs, new, name);
>   

_pinfo or even _perr?


>  		return -1;
>  	}
>  
>  	return 0;
>  }
>  
>  /*
>   * See ie. page 375 of "Intel I/O Controller Hub 7 (ICH7) Family Datasheet"
>   * http://download.intel.com/design/chipsets/datashts/30701303.pdf
>   */
>  static int enable_flash_ich(struct pci_dev *dev, const char *name,
>  			    int bios_cntl)
>  {
>  	uint8_t old, new;
>  
>  	/*
>  	 * Note: the ICH0-ICH5 BIOS_CNTL register is actually 16 bit wide, but
>  	 * just treating it as 8 bit wide seems to work fine in practice.
>  	 */
>  	old = pci_read_byte(dev, bios_cntl);
>  
> -	printf_debug("\nBIOS Lock Enable: %sabled, ",
> +	msg_pdbg("\nBIOS Lock Enable: %sabled, ",
>  		     (old & (1 << 1)) ? "en" : "dis");
> -	printf_debug("BIOS Write Enable: %sabled, ",
> +	msg_pdbg("BIOS Write Enable: %sabled, ",
>  		     (old & (1 << 0)) ? "en" : "dis");
> -	printf_debug("BIOS_CNTL is 0x%x\n", old);
> +	msg_pdbg("BIOS_CNTL is 0x%x\n", old);
>  
>  	new = old | 1;
>  
>  	if (new == old)
>  		return 0;
>  
>  	pci_write_byte(dev, bios_cntl, new);
>  
>  	if (pci_read_byte(dev, bios_cntl) != new) {
> -		printf_debug("tried to set 0x%x to 0x%x on %s failed (WARNING ONLY)\n", bios_cntl, new, name);
> +		msg_pdbg("tried to set 0x%x to 0x%x on %s failed (WARNING ONLY)\n", bios_cntl, new, name);
>   

_pinfo or even _perr?


>  		return -1;
>  	}
>  
>  	return 0;
>  }
>  
>  static int enable_flash_ich_4e(struct pci_dev *dev, const char *name)
>  {
>  	/*
>  	 * Note: ICH5 has registers similar to FWH_SEL1, FWH_SEL2 and
>  	 * FWH_DEC_EN1, but they are called FB_SEL1, FB_SEL2, FB_DEC_EN1 and
>  	 * FB_DEC_EN2.
>  	 */
> @@ -296,137 +296,137 @@ static int enable_flash_ich_dc(struct pci_dev *dev, const char *name)
>  	int tmp;
>  	int max_decode_fwh_idsel = 0;
>  	int max_decode_fwh_decode = 0;
>  	int contiguous = 1;
>  
>  	if (programmer_param)
>  		idsel = strstr(programmer_param, "fwh_idsel=");
>  
>  	if (idsel) {
>  		idsel += strlen("fwh_idsel=");
>  		fwh_conf = (uint32_t)strtoul(idsel, NULL, 0);
>  
>  		/* FIXME: Need to undo this on shutdown. */
> -		printf("\nSetting IDSEL=0x%x for top 16 MB", fwh_conf);
> +		msg_pdbg("\nSetting IDSEL=0x%x for top 16 MB", fwh_conf);
>   

This one is a bit difficult. We change some settings on user request.
Should we thus make this action _pinfo?


> @@ -642,27 +642,27 @@ static int enable_flash_ich10(struct pci_dev *dev, const char *name)
>  static int enable_flash_vt823x(struct pci_dev *dev, const char *name)
>  {
>  	uint8_t val;
>  
>  	/* enable ROM decode range (1MB) FFC00000 - FFFFFFFF */
>  	pci_write_byte(dev, 0x41, 0x7f);
>  
>  	/* ROM write enable */
>  	val = pci_read_byte(dev, 0x40);
>  	val |= 0x10;
>  	pci_write_byte(dev, 0x40, val);
>  
>  	if (pci_read_byte(dev, 0x40) != val) {
> -		printf("\nWARNING: Failed to enable flash write on \"%s\"\n",
> +		msg_pinfo("\nWARNING: Failed to enable flash write on \"%s\"\n",
>  		       name);
>  		return -1;
>  	}
>  
>  	if (dev->device_id == 0x3227) { /* VT8237R */
>  	    /* All memory cycles, not just ROM ones, go to LPC. */
>  	    val = pci_read_byte(dev, 0x59);
>  	    val &= ~0x80;
>  	    pci_write_byte(dev, 0x59, val);
>  	}
>  
>  	return 0;
>  }
> @@ -759,189 +759,189 @@ static int enable_flash_cs5536(struct pci_dev *dev, const char *name)
>  #undef MSR_NORF_CTL
>  	return 0;
>  }
>  
>  static int enable_flash_sc1100(struct pci_dev *dev, const char *name)
>  {
>  	uint8_t new;
>  
>  	pci_write_byte(dev, 0x52, 0xee);
>  
>  	new = pci_read_byte(dev, 0x52);
>  
>  	if (new != 0xee) {
> -		printf_debug("tried to set register 0x%x to 0x%x on %s failed (WARNING ONLY)\n", 0x52, new, name);
> +		msg_pdbg("tried to set register 0x%x to 0x%x on %s failed (WARNING ONLY)\n", 0x52, new, name);
>   

_pinfo or even _perr?


>  		return -1;
>  	}
>  
>  	return 0;
>  }
>  
>  /* Works for AMD-8111, VIA VT82C586A/B, VIA VT82C686A/B. */
>  static int enable_flash_amd8111(struct pci_dev *dev, const char *name)
>  {
>  	uint8_t old, new;
>  
>  	/* Enable decoding at 0xffb00000 to 0xffffffff. */
>  	old = pci_read_byte(dev, 0x43);
>  	new = old | 0xC0;
>  	if (new != old) {
>  		pci_write_byte(dev, 0x43, new);
>  		if (pci_read_byte(dev, 0x43) != new) {
> -			printf_debug("tried to set 0x%x to 0x%x on %s failed (WARNING ONLY)\n", 0x43, new, name);
> +			msg_pdbg("tried to set 0x%x to 0x%x on %s failed (WARNING ONLY)\n", 0x43, new, name);
>   

_pinfo or even _perr?


>  		}
>  	}
>  
>  	/* Enable 'ROM write' bit. */
>  	old = pci_read_byte(dev, 0x40);
>  	new = old | 0x01;
>  	if (new == old)
>  		return 0;
>  	pci_write_byte(dev, 0x40, new);
>  
>  	if (pci_read_byte(dev, 0x40) != new) {
> -		printf_debug("tried to set 0x%x to 0x%x on %s failed (WARNING ONLY)\n", 0x40, new, name);
> +		msg_pdbg("tried to set 0x%x to 0x%x on %s failed (WARNING ONLY)\n", 0x40, new, name);
>   

_pinfo or even _perr?


>  		return -1;
>  	}
>  
>  	return 0;
>  }
>  
>  static int enable_flash_sb600(struct pci_dev *dev, const char *name)
>  {
>  	uint32_t tmp, prot;
>  	uint8_t reg;
>  	struct pci_dev *smbus_dev;
>  	int has_spi = 1;
>  
>  	/* Clear ROM protect 0-3. */
>  	for (reg = 0x50; reg < 0x60; reg += 4) {
>  		prot = pci_read_long(dev, reg);
>  		/* No protection flags for this region?*/
>  		if ((prot & 0x3) == 0)
>  			continue;
> -		printf_debug("SB600 %s%sprotected from %u to %u\n",
> +		msg_pdbg("SB600 %s%sprotected from %u to %u\n",
>   

_pinfo or even _perr since this may lead to read corruption and write
failures.



>  			(prot & 0x1) ? "write " : "",
>  			(prot & 0x2) ? "read " : "",
>  			(prot & 0xfffffc00),
>  			(prot & 0xfffffc00) + ((prot & 0x3ff) << 8));
>  		prot &= 0xfffffffc;
>  		pci_write_byte(dev, reg, prot);
>  		prot = pci_read_long(dev, reg);
>  		if (prot & 0x3)
> -			printf("SB600 %s%sunprotect failed from %u to %u\n",
> +			msg_pinfo("SB600 %s%sunprotect failed from %u to %u\n",
>   

_perr


>  				(prot & 0x1) ? "write " : "",
>  				(prot & 0x2) ? "read " : "",
>  				(prot & 0xfffffc00),
>  				(prot & 0xfffffc00) + ((prot & 0x3ff) << 8));
>  	}
>  
>  	/* Read SPI_BaseAddr */
>  	tmp = pci_read_long(dev, 0xa0);
>  	tmp &= 0xffffffe0;	/* remove bits 4-0 (reserved) */
> -	printf_debug("SPI base address is at 0x%x\n", tmp);
> +	msg_pdbg("SPI base address is at 0x%x\n", tmp);
>  
>  	/* If the BAR has address 0, it is unlikely SPI is used. */
>  	if (!tmp)
>  		has_spi = 0;
>  
>  	if (has_spi) {
>  		/* Physical memory has to be mapped at page (4k) boundaries. */
>  		sb600_spibar = physmap("SB600 SPI registers", tmp & 0xfffff000,
>  				       0x1000);
>  		/* The low bits of the SPI base address are used as offset into
>  		 * the mapped page.
>  		 */
>  		sb600_spibar += tmp & 0xfff;
>  
>  		tmp = pci_read_long(dev, 0xa0);
> -		printf_debug("AltSpiCSEnable=%i, SpiRomEnable=%i, "
> +		msg_pdbg("AltSpiCSEnable=%i, SpiRomEnable=%i, "
>  			     "AbortEnable=%i\n", tmp & 0x1, (tmp & 0x2) >> 1,
>  			     (tmp & 0x4) >> 2);
>  		tmp = (pci_read_byte(dev, 0xba) & 0x4) >> 2;
> -		printf_debug("PrefetchEnSPIFromIMC=%i, ", tmp);
> +		msg_pdbg("PrefetchEnSPIFromIMC=%i, ", tmp);
>  
>  		tmp = pci_read_byte(dev, 0xbb);
> -		printf_debug("PrefetchEnSPIFromHost=%i, SpiOpEnInLpcMode=%i\n",
> +		msg_pdbg("PrefetchEnSPIFromHost=%i, SpiOpEnInLpcMode=%i\n",
>  			     tmp & 0x1, (tmp & 0x20) >> 5);
>  		tmp = mmio_readl(sb600_spibar);
> -		printf_debug("SpiArbEnable=%i, SpiAccessMacRomEn=%i, "
> +		msg_pdbg("SpiArbEnable=%i, SpiAccessMacRomEn=%i, "
>  			     "SpiHostAccessRomEn=%i, ArbWaitCount=%i, "
>  			     "SpiBridgeDisable=%i, DropOneClkOnRd=%i\n",
>  			     (tmp >> 19) & 0x1, (tmp >> 22) & 0x1,
>  			     (tmp >> 23) & 0x1, (tmp >> 24) & 0x7,
>  			     (tmp >> 27) & 0x1, (tmp >> 28) & 0x1);
>  	}
>  
>  	/* Look for the SMBus device. */
>  	smbus_dev = pci_dev_find(0x1002, 0x4385);
>  
>  	if (has_spi && !smbus_dev) {
> -		fprintf(stderr, "ERROR: SMBus device not found. Not enabling SPI.\n");
> +		msg_perr("ERROR: SMBus device not found. Not enabling SPI.\n");
>  		has_spi = 0;
>  	}
>  	if (has_spi) {
>  		/* Note about the bit tests below: If a bit is zero, the GPIO is SPI. */
>  		/* GPIO11/SPI_DO and GPIO12/SPI_DI status */
>  		reg = pci_read_byte(smbus_dev, 0xAB);
>  		reg &= 0xC0;
> -		printf_debug("GPIO11 used for %s\n", (reg & (1 << 6)) ? "GPIO" : "SPI_DO");
> -		printf_debug("GPIO12 used for %s\n", (reg & (1 << 7)) ? "GPIO" : "SPI_DI");
> +		msg_pdbg("GPIO11 used for %s\n", (reg & (1 << 6)) ? "GPIO" : "SPI_DO");
> +		msg_pdbg("GPIO12 used for %s\n", (reg & (1 << 7)) ? "GPIO" : "SPI_DI");
>  		if (reg != 0x00)
>  			has_spi = 0;
>  		/* GPIO31/SPI_HOLD and GPIO32/SPI_CS status */
>  		reg = pci_read_byte(smbus_dev, 0x83);
>  		reg &= 0xC0;
> -		printf_debug("GPIO31 used for %s\n", (reg & (1 << 6)) ? "GPIO" : "SPI_HOLD");
> -		printf_debug("GPIO32 used for %s\n", (reg & (1 << 7)) ? "GPIO" : "SPI_CS");
> +		msg_pdbg("GPIO31 used for %s\n", (reg & (1 << 6)) ? "GPIO" : "SPI_HOLD");
> +		msg_pdbg("GPIO32 used for %s\n", (reg & (1 << 7)) ? "GPIO" : "SPI_CS");
>  		/* SPI_HOLD is not used on all boards, filter it out. */
>  		if ((reg & 0x80) != 0x00)
>  			has_spi = 0;
>  		/* GPIO47/SPI_CLK status */
>  		reg = pci_read_byte(smbus_dev, 0xA7);
>  		reg &= 0x40;
> -		printf_debug("GPIO47 used for %s\n", (reg & (1 << 6)) ? "GPIO" : "SPI_CLK");
> +		msg_pdbg("GPIO47 used for %s\n", (reg & (1 << 6)) ? "GPIO" : "SPI_CLK");
>  		if (reg != 0x00)
>  			has_spi = 0;
>  	}
>  
>  	buses_supported = CHIP_BUSTYPE_LPC | CHIP_BUSTYPE_FWH;
>  	if (has_spi) {
>  		buses_supported |= CHIP_BUSTYPE_SPI;
>  		spi_controller = SPI_CONTROLLER_SB600;
>  	}
>  
>  	/* Read ROM strap override register. */
>  	OUTB(0x8f, 0xcd6);
>  	reg = INB(0xcd7);
>  	reg &= 0x0e;
> -	printf_debug("ROM strap override is %sactive", (reg & 0x02) ? "" : "not ");
> +	msg_pdbg("ROM strap override is %sactive", (reg & 0x02) ? "" : "not ");
>  	if (reg & 0x02) {
>  		switch ((reg & 0x0c) >> 2) {
>  		case 0x00:
> -			printf_debug(": LPC");
> +			msg_pdbg(": LPC");
>  			break;
>  		case 0x01:
> -			printf_debug(": PCI");
> +			msg_pdbg(": PCI");
>  			break;
>  		case 0x02:
> -			printf_debug(": FWH");
> +			msg_pdbg(": FWH");
>  			break;
>  		case 0x03:
> -			printf_debug(": SPI");
> +			msg_pdbg(": SPI");
>  			break;
>  		}
>  	}
> -	printf_debug("\n");
> +	msg_pdbg("\n");
>  
>  	/* Force enable SPI ROM in SB600 PM register.
>  	 * If we enable SPI ROM here, we have to disable it after we leave.
>  	 * But how can we know which ROM we are going to handle? So we have
>  	 * to trade off. We only access LPC ROM if we boot via LPC ROM. And
>  	 * only SPI ROM if we boot via SPI ROM. If you want to access SPI on
>  	 * boards with LPC straps, you have to use the code below.
>  	 */
>  	/*
>  	OUTB(0x8f, 0xcd6);
>  	OUTB(0x0e, 0xcd7);
>  	*/
>  
> @@ -960,55 +960,55 @@ static int enable_flash_nvidia_nforce2(struct pci_dev *dev, const char *name)
>  
>  	return 0;
>  }
>  
>  static int enable_flash_ck804(struct pci_dev *dev, const char *name)
>  {
>  	uint8_t old, new;
>  
>  	old = pci_read_byte(dev, 0x88);
>  	new = old | 0xc0;
>  	if (new != old) {
>  		pci_write_byte(dev, 0x88, new);
>  		if (pci_read_byte(dev, 0x88) != new) {
> -			printf_debug("tried to set 0x%x to 0x%x on %s failed (WARNING ONLY)\n", 0x88, new, name);
> +			msg_pdbg("tried to set 0x%x to 0x%x on %s failed (WARNING ONLY)\n", 0x88, new, name);
>   

_pinfo or even _perr?


>  		}
>  	}
>  
>  	old = pci_read_byte(dev, 0x6d);
>  	new = old | 0x01;
>  	if (new == old)
>  		return 0;
>  	pci_write_byte(dev, 0x6d, new);
>  
>  	if (pci_read_byte(dev, 0x6d) != new) {
> -		printf_debug("tried to set 0x%x to 0x%x on %s failed (WARNING ONLY)\n", 0x6d, new, name);
> +		msg_pdbg("tried to set 0x%x to 0x%x on %s failed (WARNING ONLY)\n", 0x6d, new, name);
>   

_pinfo or even _perr?


>  		return -1;
>  	}
>  
>  	return 0;
>  }
>  
>  /* ATI Technologies Inc IXP SB400 PCI-ISA Bridge (rev 80) */
>  static int enable_flash_sb400(struct pci_dev *dev, const char *name)
>  {
>  	uint8_t tmp;
>  	struct pci_dev *smbusdev;
>  
>  	/* Look for the SMBus device. */
>  	smbusdev = pci_dev_find(0x1002, 0x4372);
>  
>  	if (!smbusdev) {
> -		fprintf(stderr, "ERROR: SMBus device not found. Aborting.\n");
> +		msg_perr("ERROR: SMBus device not found. Aborting.\n");
>  		exit(1);
>  	}
>  
>  	/* Enable some SMBus stuff. */
>  	tmp = pci_read_byte(smbusdev, 0x79);
>  	tmp |= 0x01;
>  	pci_write_byte(smbusdev, 0x79, tmp);
>  
>  	/* Change southbridge. */
>  	tmp = pci_read_byte(dev, 0x48);
>  	tmp |= 0x21;
>  	pci_write_byte(dev, 0x48, tmp);
>  
> @@ -1037,27 +1037,27 @@ static int enable_flash_mcp55(struct pci_dev *dev, const char *name)
>  	val |= 0xff;		/* 1M */
>  	pci_write_byte(dev, 0x8c, val);
>  	wordval = pci_read_word(dev, 0x90);
>  	wordval |= 0x7fff;	/* 16M */
>  	pci_write_word(dev, 0x90, wordval);
>  
>  	old = pci_read_byte(dev, 0x6d);
>  	new = old | 0x01;
>  	if (new == old)
>  		return 0;
>  	pci_write_byte(dev, 0x6d, new);
>  
>  	if (pci_read_byte(dev, 0x6d) != new) {
> -		printf_debug("tried to set 0x%x to 0x%x on %s failed (WARNING ONLY)\n", 0x6d, new, name);
> +		msg_pdbg("tried to set 0x%x to 0x%x on %s failed (WARNING ONLY)\n", 0x6d, new, name);
>   

_pinfo or even _perr?


>  		return -1;
>  	}
>  
>  	return 0;
>  }
>  
>  /* This is a shot in the dark. Even if the code is totally bogus for some
>   * chipsets, users will at least start to send in reports.
>   */
>  static int enable_flash_mcp6x_7x_common(struct pci_dev *dev, const char *name)
>  {
>  	int ret = 0;
>  	uint8_t val;
> @@ -1267,27 +1267,27 @@ static int get_flashbase_sc520(struct pci_dev *dev, const char *name)
>  
>  	/* 3. PARx[25] = 1b --> flashbase[29:16] = PARx[13:0]
>  	 *    PARx[25] = 0b --> flashbase[29:12] = PARx[17:0]
>  	 */
>  	if (bootcs_found) {
>  		if (parx & (1 << 25)) {
>  			parx &= (1 << 14) - 1; /* Mask [13:0] */
>  			flashbase = parx << 16;
>  		} else {
>  			parx &= (1 << 18) - 1; /* Mask [17:0] */
>  			flashbase = parx << 12;
>  		}
>  	} else {
> -		printf("AMD Elan SC520 detected, but no BOOTCS. Assuming flash at 4G\n");
> +		msg_pinfo("AMD Elan SC520 detected, but no BOOTCS. Assuming flash at 4G\n");
>  	}
>  
>  	/* 4. Clean up */
>  	physunmap(mmcr, getpagesize());
>  	return 0;
>  }
>  
>  /* Please keep this list alphabetically sorted by vendor/device. */
>  const struct penable chipset_enables[] = {
>  	{0x10B9, 0x1533, OK, "ALi", "M1533",		enable_flash_ali_m1533},
>  	{0x1022, 0x7440, OK, "AMD", "AMD-768",		enable_flash_amd8111},
>  	{0x1022, 0x7468, OK, "AMD", "AMD8111",		enable_flash_amd8111},
>  	{0x1078, 0x0100, OK, "AMD", "CS5530(A)",	enable_flash_cs5530},
> @@ -1426,29 +1426,29 @@ int chipset_flash_enable(void)
>  	struct pci_dev *dev = 0;
>  	int ret = -2;		/* Nothing! */
>  	int i;
>  
>  	/* Now let's try to find the chipset we have... */
>  	for (i = 0; chipset_enables[i].vendor_name != NULL; i++) {
>  		dev = pci_dev_find(chipset_enables[i].vendor_id,
>  				   chipset_enables[i].device_id);
>  		if (dev)
>  			break;
>  	}
>  
>  	if (dev) {
> -		printf("Found chipset \"%s %s\", enabling flash write... ",
> +		msg_pinfo("Found chipset \"%s %s\", enabling flash write... ",
>  		       chipset_enables[i].vendor_name,
>  		       chipset_enables[i].device_name);
>  
>  		ret = chipset_enables[i].doit(dev,
>  					      chipset_enables[i].device_name);
>  		if (ret)
> -			printf("FAILED!\n");
> +			msg_pinfo("FAILED!\n");
>   

_perr?


>  		else
> -			printf("OK.\n");
> +			msg_pinfo("OK.\n");
>  	}
> -	printf("This chipset supports the following protocols: %s.\n",
> +	msg_pinfo("This chipset supports the following protocols: %s.\n",
>  	       flashbuses_to_text(buses_supported));
>  
>  	return ret;
>  }
> diff --git a/dmi.c b/dmi.c
> index d9f307f..a907a18 100644
> --- a/dmi.c
> +++ b/dmi.c
> @@ -43,99 +43,99 @@ char *dmistrings[ARRAY_SIZE(dmidecode_names)];
>  #define DMI_MAX_ANSWER_LEN 4096
>  
>  static char *get_dmi_string(const char *string_name)
>  {
>  	FILE *dmidecode_pipe;
>  	char *result;
>  	char answerbuf[DMI_MAX_ANSWER_LEN];
>  	char commandline[DMI_COMMAND_LEN_MAX + 40];
>  
>  	snprintf(commandline, sizeof(commandline),
>  		 "%s -s %s", dmidecode_command, string_name);
>  	dmidecode_pipe = popen(commandline, "r");
>  	if (!dmidecode_pipe) {
> -		printf_debug("DMI pipe open error\n");
> +		msg_pdbg("DMI pipe open error\n");
>   

Hm. _pinfo or even _perr? Then again, dmidecode may not be installed on
all systems, and we don't want to clutter up the log of innocent people.


>  		return NULL;
>  	}
>  	if (!fgets(answerbuf, DMI_MAX_ANSWER_LEN, dmidecode_pipe)) {
>  		if(ferror(dmidecode_pipe)) {
> -			printf_debug("DMI pipe read error\n");
> +			msg_pdbg("DMI pipe read error\n");
>   

dito


>  			pclose(dmidecode_pipe);
>  			return NULL;
>  		} else {
>  			answerbuf[0] = 0;	/* Hit EOF */
>  		}
>  	}
>  	/* Toss all output above DMI_MAX_ANSWER_LEN away to prevent
>  	   deadlock on pclose. */
>  	while (!feof(dmidecode_pipe))
>  		getc(dmidecode_pipe);
>  	if (pclose(dmidecode_pipe) != 0) {
> -		printf_debug("DMI pipe close error\n");
> +		msg_pdbg("DMI pipe close error\n");
>   

_pinfo or even _perr? This should never happen.


>  		return NULL;
>  	}
>  
>  	/* Chomp trailing newline. */
>  	if (answerbuf[0] != 0 &&
>  	    answerbuf[strlen(answerbuf) - 1] == '\n')
>  		answerbuf[strlen(answerbuf) - 1] = 0;
> -	printf_debug("DMI string %s: \"%s\"\n", string_name, answerbuf);
> +	msg_pdbg("DMI string %s: \"%s\"\n", string_name, answerbuf);
>  
>  	result = strdup(answerbuf);
>  	if (!result)
>  		puts("WARNING: Out of memory - DMI support fails");
>  
>  	return result;
>  }
>  
>  void dmi_init(void)
>  {
>  	int i;
>  	char *chassis_type;
>  
>  	has_dmi_support = 1;
>  	for (i = 0; i < ARRAY_SIZE(dmidecode_names); i++) {
>  		dmistrings[i] = get_dmi_string(dmidecode_names[i]);
>  		if (!dmistrings[i]) {
>  			has_dmi_support = 0;
>  			return;
>  		}
>  	}
>  
>  	chassis_type = get_dmi_string("chassis-type");
>  	if (chassis_type && !strcmp(chassis_type, "Notebook")) {
> -		printf_debug("Laptop detected via DMI\n");
> +		msg_pdbg("Laptop detected via DMI\n");
>   

_pinfo please


>  		is_laptop = 1;
>  	}
>  	free(chassis_type);
>  }
>  
>  /**
>   * Does an substring/prefix/postfix/whole-string match.
>   *
>   * The pattern is matched as-is. The only metacharacters supported are '^'
>   * at the beginning and '$' at the end. So you can look for "^prefix",
>   * "suffix$", "substring" or "^complete string$".
>   *
>   * @param value The string to check.
>   * @param pattern The pattern.
>   * @return Nonzero if pattern matches.
>   */
>  static int dmi_compare(const char *value, const char *pattern)
>  {
>  	int anchored = 0;
>  	int patternlen;
>  
> -	printf_debug("matching %s against %s\n", value, pattern);
> +	msg_pdbg("matching %s against %s\n", value, pattern);
>  	/* The empty string is part of all strings! */
>  	if (pattern[0] == 0)
>  		return 1;
>  
>  	if (pattern[0] == '^') {
>  		anchored = 1;
>  		pattern++;
>  	}
>  
>  	patternlen = strlen(pattern);
>  	if (pattern[patternlen - 1] == '$') {
>  		int valuelen = strlen(value);
>  		patternlen--;
> diff --git a/hwaccess.c b/hwaccess.c
> index 10e67bd..0e889bb 100644
> --- a/hwaccess.c
> +++ b/hwaccess.c
> @@ -31,27 +31,27 @@ int io_fd;
>  #endif
>  
>  void get_io_perms(void)
>  {
>  #if defined (__sun) && (defined(__i386) || defined(__amd64))
>  	if (sysi86(SI86V86, V86SC_IOPL, PS_IOPL) != 0) {
>  #elif defined(__FreeBSD__) || defined (__DragonFly__)
>  	if ((io_fd = open("/dev/io", O_RDWR)) < 0) {
>  #elif __DJGPP__
>  	if (0) {
>  #else 
>  	if (iopl(3) != 0) {
>  #endif
> -		fprintf(stderr, "ERROR: Could not get I/O privileges (%s).\n"
> +		msg_perr("ERROR: Could not get I/O privileges (%s).\n"
>  			"You need to be root.\n", strerror(errno));
>  		exit(1);
>  	}
>  }
>  
>  void release_io_perms(void)
>  {
>  #if defined(__FreeBSD__) || defined(__DragonFly__)
>  	close(io_fd);
>  #endif
>  }
>  
>  #ifdef __DJGPP__
> diff --git a/ichspi.c b/ichspi.c
> index 35b9dbd..587fbcb 100644
> --- a/ichspi.c
> +++ b/ichspi.c
> @@ -28,37 +28,26 @@
>   * ST M25P80
>   * ST M25P16
>   * ST M25P32 already tested
>   * ST M25P64
>   * AT 25DF321 already tested
>   *
>   */
>  
>  #include <string.h>
>  #include "flash.h"
>  #include "chipdrivers.h"
>  #include "spi.h"
>  
> -/* Change this to #define if you want lowlevel debugging of commands
> - * sent to the ICH/VIA SPI controller.
> - */
> -#undef COMM_DEBUG
> -
> -#ifdef COMM_DEBUG
> -#define msg_comm_debug printf_debug
> -#else
> -#define msg_comm_debug(...) do {} while (0)
> -#endif
> -
>  /* ICH9 controller register definition */
>  #define ICH9_REG_FADDR         0x08	/* 32 Bits */
>  #define ICH9_REG_FDATA0                0x10	/* 64 Bytes */
>  
>  #define ICH9_REG_SSFS          0x90	/* 08 Bits */
>  #define SSFS_SCIP		0x00000001
>  #define SSFS_CDS		0x00000004
>  #define SSFS_FCERR		0x00000008
>  #define SSFS_AEL		0x00000010
>  
>  #define ICH9_REG_SSFC          0x91	/* 24 Bits */
>  #define SSFC_SCGO		0x00000200
>  #define SSFC_ACS		0x00000400
> @@ -227,46 +216,46 @@ static int find_preop(OPCODES *op, uint8_t preop)
>  	}
>  
>  	return -1;
>  }
>  
>  /* Create a struct OPCODES based on what we find in the locked down chipset. */
>  static int generate_opcodes(OPCODES * op)
>  {
>  	int a;
>  	uint16_t preop, optype;
>  	uint32_t opmenu[2];
>  
>  	if (op == NULL) {
> -		printf_debug("\n%s: null OPCODES pointer!\n", __func__);
> +		msg_pdbg("\n%s: null OPCODES pointer!\n", __func__);
>   

If this codepath is ever hit, we have a bug in flashrom. -> _perr I'd say.


>  		return -1;
>  	}
>  
>  	switch (spi_controller) {
>  	case SPI_CONTROLLER_ICH7:
>  	case SPI_CONTROLLER_VIA:
>  		preop = REGREAD16(ICH7_REG_PREOP);
>  		optype = REGREAD16(ICH7_REG_OPTYPE);
>  		opmenu[0] = REGREAD32(ICH7_REG_OPMENU);
>  		opmenu[1] = REGREAD32(ICH7_REG_OPMENU + 4);
>  		break;
>  	case SPI_CONTROLLER_ICH9:
>  		preop = REGREAD16(ICH9_REG_PREOP);
>  		optype = REGREAD16(ICH9_REG_OPTYPE);
>  		opmenu[0] = REGREAD32(ICH9_REG_OPMENU);
>  		opmenu[1] = REGREAD32(ICH9_REG_OPMENU + 4);
>  		break;
>  	default:
> -		printf_debug("%s: unsupported chipset\n", __func__);
> +		msg_pdbg("%s: unsupported chipset\n", __func__);
>   

_perr since it would be an implementation bug.


>  		return -1;
>  	}
>  
>  	op->preop[0] = (uint8_t) preop;
>  	op->preop[1] = (uint8_t) (preop >> 8);
>  
>  	for (a = 0; a < 8; a++) {
>  		op->opcode[a].spi_type = (uint8_t) (optype & 0x3);
>  		optype >>= 2;
>  	}
>  
>  	for (a = 0; a < 4; a++) {
>  		op->opcode[a].opcode = (uint8_t) (opmenu[0] & 0xff);
> @@ -305,79 +294,79 @@ int program_opcodes(OPCODES * op)
>  
>  	/* Program Allowable Opcodes 0 - 3 */
>  	opmenu[0] = 0;
>  	for (a = 0; a < 4; a++) {
>  		opmenu[0] |= ((uint32_t) op->opcode[a].opcode) << (a * 8);
>  	}
>  
>  	/*Program Allowable Opcodes 4 - 7 */
>  	opmenu[1] = 0;
>  	for (a = 4; a < 8; a++) {
>  		opmenu[1] |= ((uint32_t) op->opcode[a].opcode) << ((a - 4) * 8);
>  	}
>  
> -	printf_debug("\n%s: preop=%04x optype=%04x opmenu=%08x%08x\n", __func__, preop, optype, opmenu[0], opmenu[1]);
> +	msg_pdbg("\n%s: preop=%04x optype=%04x opmenu=%08x%08x\n", __func__, preop, optype, opmenu[0], opmenu[1]);
>  	switch (spi_controller) {
>  	case SPI_CONTROLLER_ICH7:
>  	case SPI_CONTROLLER_VIA:
>  		REGWRITE16(ICH7_REG_PREOP, preop);
>  		REGWRITE16(ICH7_REG_OPTYPE, optype);
>  		REGWRITE32(ICH7_REG_OPMENU, opmenu[0]);
>  		REGWRITE32(ICH7_REG_OPMENU + 4, opmenu[1]);
>  		break;
>  	case SPI_CONTROLLER_ICH9:
>  		REGWRITE16(ICH9_REG_PREOP, preop);
>  		REGWRITE16(ICH9_REG_OPTYPE, optype);
>  		REGWRITE32(ICH9_REG_OPMENU, opmenu[0]);
>  		REGWRITE32(ICH9_REG_OPMENU + 4, opmenu[1]);
>  		break;
>  	default:
> -		printf_debug("%s: unsupported chipset\n", __func__);
> +		msg_pdbg("%s: unsupported chipset\n", __func__);
>   

_perr since it would be an implementation bug.


>  		return -1;
>  	}
>  
>  	return 0;
>  }
>  
>  /* This function generates OPCODES from or programs OPCODES to ICH according to
>   * the chipset's SPI configuration lock.
>   *
>   * It should be called before ICH sends any spi command.
>   */
>  int ich_init_opcodes(void)
>  {
>  	int rc = 0;
>  	OPCODES *curopcodes_done;
>  
>  	if (curopcodes)
>  		return 0;
>  
>  	if (ichspi_lock) {
> -		printf_debug("Generating OPCODES... ");
> +		msg_pdbg("Generating OPCODES... ");
>  		curopcodes_done = &O_EXISTING;
>  		rc = generate_opcodes(curopcodes_done);
>  	} else {
> -		printf_debug("Programming OPCODES... ");
> +		msg_pdbg("Programming OPCODES... ");
>  		curopcodes_done = &O_ST_M25P;
>  		rc = program_opcodes(curopcodes_done);
>  	}
>  
>  	if (rc) {
>  		curopcodes = NULL;
> -		printf_debug("failed\n");
> +		msg_pdbg("failed\n");
>   

_perr. Can happen if the hardware acts up, and in that case we
definitely want to know.


>  		return 1;
>  	} else {
>  		curopcodes = curopcodes_done;
> -		printf_debug("done\n");
> +		msg_pdbg("done\n");
>  		return 0;
>  	}
>  }
>  
>  static int ich7_run_opcode(OPCODE op, uint32_t offset,
>  			   uint8_t datalength, uint8_t * data, int maxdata)
>  {
>  	int write_cmd = 0;
>  	int timeout;
>  	uint32_t temp32 = 0;
>  	uint16_t temp16;
>  	uint32_t a;
>  	uint64_t opmenu;
> @@ -429,27 +418,27 @@ static int ich7_run_opcode(OPCODE op, uint32_t offset,
>  	}
>  
>  	/* Select opcode */
>  	opmenu = REGREAD32(ICH7_REG_OPMENU);
>  	opmenu |= ((uint64_t)REGREAD32(ICH7_REG_OPMENU + 4)) << 32;
>  
>  	for (opcode_index = 0; opcode_index < 8; opcode_index++) {
>  		if ((opmenu & 0xff) == op.opcode) {
>  			break;
>  		}
>  		opmenu >>= 8;
>  	}
>  	if (opcode_index == 8) {
> -		printf_debug("Opcode %x not found.\n", op.opcode);
> +		msg_pdbg("Opcode %x not found.\n", op.opcode);
>  		return 1;
>  	}
>  	temp16 |= ((uint16_t) (opcode_index & 0x07)) << 4;
>  
>  	/* Handle Atomic */
>  	switch (op.atomic) {
>  	case 2:
>  		/* Select second preop. */
>  		temp16 |= SPIC_SPOP;
>  		/* And fall through. */
>  	case 1:
>  		/* Atomic command (preop+op) */
>  		temp16 |= SPIC_ACS;
> @@ -458,31 +447,31 @@ static int ich7_run_opcode(OPCODE op, uint32_t offset,
>  
>  	/* Start */
>  	temp16 |= SPIC_SCGO;
>  
>  	/* write it */
>  	REGWRITE16(ICH7_REG_SPIC, temp16);
>  
>  	/* wait for cycle complete */
>  	timeout = 100 * 1000 * 60;	// 60s is a looong timeout.
>  	while (((REGREAD16(ICH7_REG_SPIS) & SPIS_CDS) == 0) && --timeout) {
>  		programmer_delay(10);
>  	}
>  	if (!timeout) {
> -		printf_debug("timeout\n");
> +		msg_pdbg("timeout\n");
>   

I'd argue for _perr here because timeouts mean possible corruption.


>  	}
>  
>  	if ((REGREAD16(ICH7_REG_SPIS) & SPIS_FCERR) != 0) {
> -		printf_debug("Transaction error!\n");
> +		msg_pdbg("Transaction error!\n");
>   

It would be desirable to use _perr. Then again, a transaction error can
happen even during probe (REMS/RES take an address, and we simply pick 0
instead of BBAR). I'd say _pdbg is fine for now, but we should add a
FIXME comment:
/* FIXME make sure we do not needlessly cause transaction errors. */


>  		return 1;
>  	}
>  
>  	if ((!write_cmd) && (datalength != 0)) {
>  		for (a = 0; a < datalength; a++) {
>  			if ((a % 4) == 0) {
>  				temp32 = REGREAD32(ICH7_REG_SPID0 + (a));
>  			}
>  
>  			data[a] =
>  			    (temp32 & (((uint32_t) 0xff) << ((a % 4) * 8)))
>  			    >> ((a % 4) * 8);
>  		}
> @@ -547,27 +536,27 @@ static int ich9_run_opcode(OPCODE op, uint32_t offset,
>  	}
>  
>  	/* Select opcode */
>  	opmenu = REGREAD32(ICH9_REG_OPMENU);
>  	opmenu |= ((uint64_t)REGREAD32(ICH9_REG_OPMENU + 4)) << 32;
>  
>  	for (opcode_index = 0; opcode_index < 8; opcode_index++) {
>  		if ((opmenu & 0xff) == op.opcode) {
>  			break;
>  		}
>  		opmenu >>= 8;
>  	}
>  	if (opcode_index == 8) {
> -		printf_debug("Opcode %x not found.\n", op.opcode);
> +		msg_pdbg("Opcode %x not found.\n", op.opcode);
>  		return 1;
>  	}
>  	temp32 |= ((uint32_t) (opcode_index & 0x07)) << (8 + 4);
>  
>  	/* Handle Atomic */
>  	switch (op.atomic) {
>  	case 2:
>  		/* Select second preop. */
>  		temp32 |= SSFC_SPOP;
>  		/* And fall through. */
>  	case 1:
>  		/* Atomic command (preop+op) */
>  		temp32 |= SSFC_ACS;
> @@ -576,100 +565,100 @@ static int ich9_run_opcode(OPCODE op, uint32_t offset,
>  
>  	/* Start */
>  	temp32 |= SSFC_SCGO;
>  
>  	/* write it */
>  	REGWRITE32(ICH9_REG_SSFS, temp32);
>  
>  	/*wait for cycle complete */
>  	timeout = 100 * 1000 * 60;	// 60s is a looong timeout.
>  	while (((REGREAD32(ICH9_REG_SSFS) & SSFS_CDS) == 0) && --timeout) {
>  		programmer_delay(10);
>  	}
>  	if (!timeout) {
> -		printf_debug("timeout\n");
> +		msg_pdbg("timeout\n");
>   

_perr (see above)


>  	}
>  
>  	if ((REGREAD32(ICH9_REG_SSFS) & SSFS_FCERR) != 0) {
> -		printf_debug("Transaction error!\n");
> +		msg_pdbg("Transaction error!\n");
>   

_perr or FIXME comment (see above)


>  		return 1;
>  	}
>  
>  	if ((!write_cmd) && (datalength != 0)) {
>  		for (a = 0; a < datalength; a++) {
>  			if ((a % 4) == 0) {
>  				temp32 = REGREAD32(ICH9_REG_FDATA0 + (a));
>  			}
>  
>  			data[a] =
>  			    (temp32 & (((uint32_t) 0xff) << ((a % 4) * 8)))
>  			    >> ((a % 4) * 8);
>  		}
>  	}
>  
>  	return 0;
>  }
>  
>  static int run_opcode(OPCODE op, uint32_t offset,
>  		      uint8_t datalength, uint8_t * data)
>  {
>  	switch (spi_controller) {
>  	case SPI_CONTROLLER_VIA:
>  		if (datalength > 16) {
> -			fprintf(stderr, "%s: Internal command size error for "
> +			msg_pdbg("%s: Internal command size error for "
>   

_perr because it is an implementation bug if we hit this


>  				"opcode 0x%02x, got datalength=%i, want <=16\n",
>  				__func__, op.opcode, datalength);
>  			return SPI_INVALID_LENGTH;
>  		}
>  		return ich7_run_opcode(op, offset, datalength, data, 16);
>  	case SPI_CONTROLLER_ICH7:
>  		if (datalength > 64) {
> -			fprintf(stderr, "%s: Internal command size error for "
> +			msg_pdbg("%s: Internal command size error for "
>   

_perr (see above)


>  				"opcode 0x%02x, got datalength=%i, want <=16\n",
>  				__func__, op.opcode, datalength);
>  			return SPI_INVALID_LENGTH;
>  		}
>  		return ich7_run_opcode(op, offset, datalength, data, 64);
>  	case SPI_CONTROLLER_ICH9:
>  		if (datalength > 64) {
> -			fprintf(stderr, "%s: Internal command size error for "
> +			msg_pdbg("%s: Internal command size error for "
>   

_perr


>  				"opcode 0x%02x, got datalength=%i, want <=16\n",
>  				__func__, op.opcode, datalength);
>  			return SPI_INVALID_LENGTH;
>  		}
>  		return ich9_run_opcode(op, offset, datalength, data);
>  	default:
> -		printf_debug("%s: unsupported chipset\n", __func__);
> +		msg_pdbg("%s: unsupported chipset\n", __func__);
>   

_perr


>  	}
>  
>  	/* If we ever get here, something really weird happened */
>  	return -1;
>  }
>  
>  static int ich_spi_write_page(struct flashchip *flash, uint8_t * bytes,
>  			      int offset, int maxdata)
>  {
>  	int page_size = flash->page_size;
>  	uint32_t remaining = page_size;
>  	int towrite;
>  
> -	msg_comm_debug("ich_spi_write_page: offset=%d, number=%d, buf=%p\n",
> +	msg_pspew("ich_spi_write_page: offset=%d, number=%d, buf=%p\n",
>  		     offset, page_size, bytes);
>  
>  	for (; remaining > 0; remaining -= towrite) {
>  		towrite = min(remaining, maxdata);
>  		if (spi_nbyte_program(offset + (page_size - remaining),
>  				      &bytes[page_size - remaining], towrite)) {
> -			printf_debug("Error writing");
> +			msg_pdbg("Error writing");
>   

_perr


>  			return 1;
>  		}
>  	}
>  
>  	return 0;
>  }
>  
>  int ich_spi_read(struct flashchip *flash, uint8_t * buf, int start, int len)
>  {
>  	int maxdata = 64;
>  
>  	if (spi_controller == SPI_CONTROLLER_VIA)
>  		maxdata = 16;
> @@ -677,169 +666,169 @@ int ich_spi_read(struct flashchip *flash, uint8_t * buf, int start, int len)
>  	return spi_read_chunked(flash, buf, start, len, maxdata);
>  }
>  
>  int ich_spi_write_256(struct flashchip *flash, uint8_t * buf)
>  {
>  	int i, j, rc = 0;
>  	int total_size = flash->total_size * 1024;
>  	int page_size = flash->page_size;
>  	int erase_size = 64 * 1024;
>  	int maxdata = 64;
>  
>  	spi_disable_blockprotect();
>  	/* Erase first */
> -	printf("Erasing flash before programming... ");
> +	msg_pinfo("Erasing flash before programming... ");
>  	if (erase_flash(flash)) {
> -		fprintf(stderr, "ERASE FAILED!\n");
> +		msg_perr("ERASE FAILED!\n");
>  		return -1;
>  	}
> -	printf("done.\n");
> +	msg_pinfo("done.\n");
>  
> -	printf("Programming page: \n");
> +	msg_pinfo("Programming page: \n");
>  	for (i = 0; i < total_size / erase_size; i++) {
>  		if (spi_controller == SPI_CONTROLLER_VIA)
>  			maxdata = 16;
>  
>  		for (j = 0; j < erase_size / page_size; j++) {
>  			ich_spi_write_page(flash,
>  			   (void *)(buf + (i * erase_size) + (j * page_size)),
>  			   (i * erase_size) + (j * page_size), maxdata);
>  		}
>  	}
>  
> -	printf("\n");
> +	msg_pinfo("\n");
>  
>  	return rc;
>  }
>  
>  int ich_spi_send_command(unsigned int writecnt, unsigned int readcnt,
>  		    const unsigned char *writearr, unsigned char *readarr)
>  {
>  	int result;
>  	int opcode_index = -1;
>  	const unsigned char cmd = *writearr;
>  	OPCODE *opcode;
>  	uint32_t addr = 0;
>  	uint8_t *data;
>  	int count;
>  
>  	/* find cmd in opcodes-table */
>  	opcode_index = find_opcode(curopcodes, cmd);
>  	if (opcode_index == -1) {
>  		/* FIXME: Reprogram opcodes if possible. Autodetect type of
>  		 * opcode by checking readcnt/writecnt.
>  		 */
> -		printf_debug("Invalid OPCODE 0x%02x\n", cmd);
> +		msg_pdbg("Invalid OPCODE 0x%02x\n", cmd);
>  		return SPI_INVALID_OPCODE;
>  	}
>  
>  	opcode = &(curopcodes->opcode[opcode_index]);
>  
>  	/* The following valid writecnt/readcnt combinations exist:
>  	 * writecnt  = 4, readcnt >= 0
>  	 * writecnt  = 1, readcnt >= 0
>  	 * writecnt >= 4, readcnt  = 0
>  	 * writecnt >= 1, readcnt  = 0
>  	 * writecnt >= 1 is guaranteed for all commands.
>  	 */
>  	if ((opcode->spi_type == SPI_OPCODE_TYPE_READ_WITH_ADDRESS) &&
>  	    (writecnt != 4)) {
> -		fprintf(stderr, "%s: Internal command size error for opcode "
> +		msg_pdbg("%s: Internal command size error for opcode "
>   

_perr because it would be an implementation bug


>  			"0x%02x, got writecnt=%i, want =4\n", __func__, cmd,
>  			writecnt);
>  		return SPI_INVALID_LENGTH;
>  	}
>  	if ((opcode->spi_type == SPI_OPCODE_TYPE_READ_NO_ADDRESS) &&
>  	    (writecnt != 1)) {
> -		fprintf(stderr, "%s: Internal command size error for opcode "
> +		msg_pdbg("%s: Internal command size error for opcode "
>   

_perr because it would be an implementation bug


>  			"0x%02x, got writecnt=%i, want =1\n", __func__, cmd,
>  			writecnt);
>  		return SPI_INVALID_LENGTH;
>  	}
>  	if ((opcode->spi_type == SPI_OPCODE_TYPE_WRITE_WITH_ADDRESS) &&
>  	    (writecnt < 4)) {
> -		fprintf(stderr, "%s: Internal command size error for opcode "
> +		msg_pdbg("%s: Internal command size error for opcode "
>   

_perr because it would be an implementation bug


>  			"0x%02x, got writecnt=%i, want >=4\n", __func__, cmd,
>  			writecnt);
>  		return SPI_INVALID_LENGTH;
>  	}
>  	if (((opcode->spi_type == SPI_OPCODE_TYPE_WRITE_WITH_ADDRESS) ||
>  	     (opcode->spi_type == SPI_OPCODE_TYPE_WRITE_NO_ADDRESS)) &&
>  	    (readcnt)) {
> -		fprintf(stderr, "%s: Internal command size error for opcode "
> +		msg_pdbg("%s: Internal command size error for opcode "
>   

_perr because it would be an implementation bug


>  			"0x%02x, got readcnt=%i, want =0\n", __func__, cmd,
>  			readcnt);
>  		return SPI_INVALID_LENGTH;
>  	}
>  
>  	/* if opcode-type requires an address */
>  	if (opcode->spi_type == SPI_OPCODE_TYPE_READ_WITH_ADDRESS ||
>  	    opcode->spi_type == SPI_OPCODE_TYPE_WRITE_WITH_ADDRESS) {
>  		addr = (writearr[1] << 16) |
>  		    (writearr[2] << 8) | (writearr[3] << 0);
>  	}
>  
>  	/* translate read/write array/count */
>  	if (opcode->spi_type == SPI_OPCODE_TYPE_WRITE_NO_ADDRESS) {
>  		data = (uint8_t *) (writearr + 1);
>  		count = writecnt - 1;
>  	} else if (opcode->spi_type == SPI_OPCODE_TYPE_WRITE_WITH_ADDRESS) {
>  		data = (uint8_t *) (writearr + 4);
>  		count = writecnt - 4;
>  	} else {
>  		data = (uint8_t *) readarr;
>  		count = readcnt;
>  	}
>  
>  	result = run_opcode(*opcode, addr, count, data);
>  	if (result) {
> -		printf_debug("run OPCODE 0x%02x failed\n", opcode->opcode);
> +		msg_pdbg("run OPCODE 0x%02x failed\n", opcode->opcode);
>   

Mh. Not sure about this one. Can happen in production if the chipset is
locked down. In fact, it can happen quite often. We need _perr_ratelimit
or somesuch. Heh. I think _pdbg is good for now.


>  	}
>  
>  	return result;
>  }
>  
>  int ich_spi_send_multicommand(struct spi_command *cmds)
>  {
>  	int ret = 0;
>  	int i;
>  	int oppos, preoppos;
>  	for (; (cmds->writecnt || cmds->readcnt) && !ret; cmds++) {
>  		if ((cmds + 1)->writecnt || (cmds + 1)->readcnt) {
>  			/* Next command is valid. */
>  			preoppos = find_preop(curopcodes, cmds->writearr[0]);
>  			oppos = find_opcode(curopcodes, (cmds + 1)->writearr[0]);
>  			if ((oppos == -1) && (preoppos != -1)) {
>  				/* Current command is listed as preopcode in
>  				 * ICH struct OPCODES, but next command is not
>  				 * listed as opcode in that struct.
>  				 * Check for command sanity, then
>  				 * try to reprogram the ICH opcode list.
>  				 */
>  				if (find_preop(curopcodes,
>  					       (cmds + 1)->writearr[0]) != -1) {
> -					fprintf(stderr, "%s: Two subsequent "
> +					msg_pdbg("%s: Two subsequent "
>   

_perr because it would be an implementation bug


>  						"preopcodes 0x%02x and 0x%02x, "
>  						"ignoring the first.\n",
>  						__func__, cmds->writearr[0],
>  						(cmds + 1)->writearr[0]);
>  					continue;
>  				}
>  				/* If the chipset is locked down, we'll fail
>  				 * during execution of the next command anyway.
>  				 * No need to bother with fixups.
>  				 */
>  				if (!ichspi_lock) {
> -					printf_debug("%s: FIXME: Add on-the-fly"
> +					msg_pdbg("%s: FIXME: Add on-the-fly"
>  						     " reprogramming of the "
>  						     "chipset opcode list.\n",
>  						     __func__);
>  				 	/* FIXME: Reprogram opcode menu.
>  					 * Find a less-useful opcode, replace it
>  					 * with the wanted opcode, detect optype
>  					 * and reprogram the opcode menu.
>  					 * Update oppos so the next if-statement
>  					 * can do something useful.
>  					 */
>  					//curopcodes.opcode[lessusefulindex] = (cmds + 1)->writearr[0]);
>  					//update_optypes(curopcodes);
>  					//program_opcodes(curopcodes);
> diff --git a/physmap.c b/physmap.c
> index 38a395c..efd641c 100644
> --- a/physmap.c
> +++ b/physmap.c
> @@ -160,76 +160,76 @@ void *sys_physmap_ro_cached(unsigned long phys_addr, size_t len)
>  			perror("Critical error: open(" MEM_DEV ")");
>   

Hm. How do we handle perror? It should definitely not happen in a library.


>  			exit(2);
>  		}
>  	}
>  
>  	virt_addr = mmap(0, len, PROT_READ, MAP_SHARED,
>  			 fd_mem_cached, (off_t)phys_addr);
>  	return MAP_FAILED == virt_addr ? NULL : virt_addr;
>  }
>  
>  void physunmap(void *virt_addr, size_t len)
>  {
>  	if (len == 0) {
> -		printf_debug("Not unmapping zero size at %p\n", virt_addr);
> +		msg_pdbg("Not unmapping zero size at %p\n", virt_addr);
>   

Maybe even _pspew? This message will be printed for all generic SPI chips.


>  		return;
>  	}
>  		
>  	munmap(virt_addr, len);
>  }
>  #endif
>  
>  #define PHYSMAP_NOFAIL	0
>  #define PHYSMAP_MAYFAIL	1
>  #define PHYSMAP_RW	0
>  #define PHYSMAP_RO	1
>  
>  void *physmap_common(const char *descr, unsigned long phys_addr, size_t len, int mayfail, int readonly)
>  {
>  	void *virt_addr;
>  
>  	if (len == 0) {
> -		printf_debug("Not mapping %s, zero size at 0x%08lx.\n",
> +		msg_pdbg("Not mapping %s, zero size at 0x%08lx.\n",
>   

Maybe even _pspew?


>  			     descr, phys_addr);
>  		return NULL;
>  	}
>  		
>  	if ((getpagesize() - 1) & len) {
> -		fprintf(stderr, "Mapping %s at 0x%08lx, unaligned size 0x%lx.\n",
> +		msg_perr("Mapping %s at 0x%08lx, unaligned size 0x%lx.\n",
>  			descr, phys_addr, (unsigned long)len);
>  	}
>  
>  	if ((getpagesize() - 1) & phys_addr) {
> -		fprintf(stderr, "Mapping %s, 0x%lx bytes at unaligned 0x%08lx.\n",
> +		msg_perr("Mapping %s, 0x%lx bytes at unaligned 0x%08lx.\n",
>  			descr, (unsigned long)len, phys_addr);
>  	}
>  
>  	if (readonly) {
>  		virt_addr = sys_physmap_ro_cached(phys_addr, len);
>  	} else {
>  		virt_addr = sys_physmap_rw_uncached(phys_addr, len);
>  	}
>  
>  	if (NULL == virt_addr) {
>  		if (NULL == descr)
>  			descr = "memory";
> -		fprintf(stderr, "Error accessing %s, 0x%lx bytes at 0x%08lx\n", descr, (unsigned long)len, phys_addr);
> +		msg_perr("Error accessing %s, 0x%lx bytes at 0x%08lx\n", descr, (unsigned long)len, phys_addr);
>  		perror(MEM_DEV " mmap failed");
>  		if (EINVAL == errno) {
> -			fprintf(stderr, "In Linux this error can be caused by the CONFIG_NONPROMISC_DEVMEM (<2.6.27),\n");
> -			fprintf(stderr, "CONFIG_STRICT_DEVMEM (>=2.6.27) and CONFIG_X86_PAT kernel options.\n");
> -			fprintf(stderr, "Please check if either is enabled in your kernel before reporting a failure.\n");
> -			fprintf(stderr, "You can override CONFIG_X86_PAT at boot with the nopat kernel parameter but\n");
> -			fprintf(stderr, "disabling the other option unfortunately requires a kernel recompile. Sorry!\n");
> +			msg_perr("In Linux this error can be caused by the CONFIG_NONPROMISC_DEVMEM (<2.6.27),\n");
> +			msg_perr("CONFIG_STRICT_DEVMEM (>=2.6.27) and CONFIG_X86_PAT kernel options.\n");
> +			msg_perr("Please check if either is enabled in your kernel before reporting a failure.\n");
> +			msg_perr("You can override CONFIG_X86_PAT at boot with the nopat kernel parameter but\n");
> +			msg_perr("disabling the other option unfortunately requires a kernel recompile. Sorry!\n");
>   

This message should be #ifdef linux or somesuch. It is utterly useless
and confusing on any non-Linux platform. Besides that, it shouldn't
happen anymore since we fixed the low mem mapping. Not sure which
#define we should check for.


>  		}
>  		if (!mayfail)
>  			exit(3);
>  	}
>  
>  	return virt_addr;
>  }
>  
>  void *physmap(const char *descr, unsigned long phys_addr, size_t len)
>  {
>  	return physmap_common(descr, phys_addr, len, PHYSMAP_NOFAIL, PHYSMAP_RW);
>  }
>  
>   

With the changes requested above:
Acked-by: Carl-Daniel Hailfinger <c-d.hailfinger.devel.2006 at gmx.net>

Please check if it still compiles without warnings after all changes.
Thanks.

It would be appreciated if you could combine this with the msg_g* patch
into one commit.

Regards,
Carl-Daniel

-- 
http://www.hailfinger.org/





More information about the flashrom mailing list