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 
> [email protected].\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 <[email protected]>

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/


_______________________________________________
flashrom mailing list
[email protected]
http://www.flashrom.org/mailman/listinfo/flashrom

Reply via email to