Skip to content

Commit

Permalink
Big log level reduction...
Browse files Browse the repository at this point in the history 
90% of what we print isn't useful to a normal user. This
dramatically reduces the amount of messages printed by
OPAL in normal circumstances.

We still need to add a way to bump the log level at boot
based on a BMC scratch register or some HDAT property.

Signed-off-by: Benjamin Herrenschmidt <benh@kernel.crashing.org>
Signed-off-by: Michael Neuling <mikey@neuling.org>
Signed-off-by: Stewart Smith <stewart@linux.vnet.ibm.com>
  • Loading branch information
@ozbenh @stewartsmith
ozbenh authored and stewartsmith committed Jun 26, 2017
1 parent 562a10c commit 7fab123
Show file tree
Hide file tree
Showing 15 changed files with 46 additions and 51 deletions.
2 changes: 1 addition & 1 deletion core/device.c
View file
Expand Up @@ -893,7 +893,7 @@ int dt_expand_node(struct dt_node *node, const void *fdt, int fdt_node)

void dt_expand(const void *fdt)
{
printf("FDT: Parsing fdt @%p\n", fdt);
prlog(PR_DEBUG, "FDT: Parsing fdt @%p\n", fdt);

if (dt_expand_node(dt_root, fdt, 0) < 0)
abort();
Expand Down
17 changes: 9 additions & 8 deletions core/init.c
View file
Expand Up @@ -119,8 +119,8 @@ static bool try_load_elf64_le(struct elf_hdr *header)
kernel_size = le64_to_cpu(kh->e_shoff) +
(le16_to_cpu(kh->e_shentsize) * le16_to_cpu(kh->e_shnum));

printf("INIT: 64-bit kernel entry at 0x%llx, size 0x%lx\n",
kernel_entry, kernel_size);
prlog(PR_DEBUG, "INIT: 64-bit kernel entry at 0x%llx, size 0x%lx\n",
kernel_entry, kernel_size);

return true;
}
Expand Down Expand Up @@ -371,7 +371,7 @@ static bool load_kernel(void)
if (dt_has_node_property(dt_chosen, "kernel-base-address", NULL)) {
kernel_entry = dt_prop_get_u64(dt_chosen,
"kernel-base-address");
printf("INIT: Kernel image at 0x%llx\n",kernel_entry);
prlog(PR_DEBUG, "INIT: Kernel image at 0x%llx\n", kernel_entry);
kh = (struct elf_hdr *)kernel_entry;
/*
* If the kernel is at 0, restore it as it was overwritten
Expand All @@ -398,11 +398,12 @@ static bool load_kernel(void)
}
}

printf("INIT: Kernel loaded, size: %zu bytes (0 = unknown preload)\n",
kernel_size);
prlog(PR_DEBUG,
"INIT: Kernel loaded, size: %zu bytes (0 = unknown preload)\n",
kernel_size);

if (kh->ei_ident != ELF_IDENT) {
printf("INIT: ELF header not found. Assuming raw binary.\n");
prerror("INIT: ELF header not found. Assuming raw binary.\n");
return true;
}

Expand All @@ -413,7 +414,7 @@ static bool load_kernel(void)
if (!try_load_elf32(kh))
return false;
} else {
printf("INIT: Neither ELF32 not ELF64 ?\n");
prerror("INIT: Neither ELF32 not ELF64 ?\n");
return false;
}

Expand Down Expand Up @@ -542,7 +543,7 @@ void __noreturn load_and_boot_kernel(bool is_reboot)

/* Dump the selected console */
stdoutp = dt_prop_get_def(dt_chosen, "linux,stdout-path", NULL);
printf("INIT: stdout-path: %s\n", stdoutp ? stdoutp : "");
prlog(PR_DEBUG, "INIT: stdout-path: %s\n", stdoutp ? stdoutp : "");


printf("INIT: Starting kernel at 0x%llx, fdt at %p %u bytes)\n",
Expand Down
4 changes: 2 additions & 2 deletions core/interrupts.c
View file
Expand Up @@ -230,8 +230,8 @@ void add_opal_interrupts(void)
continue;
name = is->ops->name ? is->ops->name(is, isn) : NULL;
ns = name ? strlen(name) : 0;
printf("irq %x name: %s (%d/%d)\n",
isn, name ? name : "<null>", ns, tns);
prlog(PR_DEBUG, "irq %x name: %s (%d/%d)\n",
isn, name ? name : "<null>", ns, tns);
names = realloc(names, tns + ns + 1);
if (name) {
strcpy(names + tns, name);
Expand Down
2 changes: 1 addition & 1 deletion core/mem_region.c
View file
Expand Up @@ -926,7 +926,7 @@ static void mem_region_parse_reserved_properties(void)
const struct dt_property *names, *ranges;
struct mem_region *region;

prlog(PR_INFO, "MEM: parsing reserved memory from "
prlog(PR_DEBUG, "MEM: parsing reserved memory from "
"reserved-names/-ranges properties\n");

names = dt_find_property(dt_root, "reserved-names");
Expand Down
9 changes: 3 additions & 6 deletions core/nvram-format.c
View file
Expand Up @@ -156,12 +156,12 @@ int nvram_check(void *nvram_image, const uint32_t nvram_size)
}
}
if (!found_common) {
prerror("NVRAM: Common partition not found !\n");
prlog_once(PR_ERR, "NVRAM: Common partition not found !\n");
goto failed;
}

if (!skiboot_part_hdr) {
prerror("NVRAM: Skiboot private partition not found !\n");
prlog_once(PR_ERR, "NVRAM: Skiboot private partition not found !\n");
goto failed;
} else {
/*
Expand Down Expand Up @@ -222,11 +222,8 @@ const char *nvram_query(const char *key)
*
* NB: nvram_validate() can update skiboot_part_hdr
*/
if (!nvram_validate()) {
prerror("NVRAM: Look up for '%s' failed due to bad format!\n",
key);
if (!nvram_validate())
return NULL;
}

part_end = (const char *) skiboot_part_hdr
+ be16_to_cpu(skiboot_part_hdr->len) * 16 - 1;
Expand Down
4 changes: 2 additions & 2 deletions core/opal.c
View file
Expand Up @@ -64,8 +64,8 @@ void opal_table_init(void)
struct opal_table_entry *s = __opal_table_start;
struct opal_table_entry *e = __opal_table_end;

printf("OPAL table: %p .. %p, branch table: %p\n",
s, e, opal_branch_table);
prlog(PR_DEBUG, "OPAL table: %p .. %p, branch table: %p\n",
s, e, opal_branch_table);
while(s < e) {
opal_branch_table[s->token] = function_entry_address(s->func);
opal_num_args[s->token] = s->nargs;
Expand Down
2 changes: 1 addition & 1 deletion core/pci.c
View file
Expand Up @@ -1737,7 +1737,7 @@ void pci_init_slots(void)
if (platform.pre_pci_fixup)
platform.pre_pci_fixup();

prlog(PR_NOTICE, "PCI: Resetting PHBs...\n");
prlog(PR_INFO, "PCI: Resetting PHBs...\n");
pci_do_jobs(pci_reset_phb);

prlog(PR_NOTICE, "PCI: Probing slots...\n");
Expand Down
2 changes: 1 addition & 1 deletion hdata/spira.c
View file
Expand Up @@ -1301,7 +1301,7 @@ int parse_hdat(bool is_opal)

add_stop_levels();

prlog(PR_INFO, "Parsing HDAT...done\n");
prlog(PR_DEBUG, "Parsing HDAT...done\n");

return 0;
}
7 changes: 4 additions & 3 deletions hw/lpc.c
View file
Expand Up @@ -1186,8 +1186,8 @@ static void lpc_init_chip_p9(struct dt_node *opb_node)
val &= 0xf0000000;
opb_write(lpc, opb_master_reg_base + 0xc, val, 4);

printf("LPC[%03x]: Initialized, access via MMIO @%p\n",
gcid, lpc->mbase);
prlog(PR_INFO, "LPC[%03x]: Initialized\n", gcid);
prlog(PR_DEBUG,"access via MMIO @%p\n", lpc->mbase);

chip->lpc = lpc;
}
Expand All @@ -1210,7 +1210,8 @@ void lpc_init(void)
}
}
if (lpc_default_chip_id >= 0)
printf("LPC: Default bus on chip 0x%x\n", lpc_default_chip_id);
prlog(PR_DEBUG, "Default bus on chip 0x%x\n",
lpc_default_chip_id);

if (has_lpc) {
opal_register(OPAL_LPC_WRITE, opal_lpc_write, 5);
Expand Down
18 changes: 7 additions & 11 deletions hw/phb4.c
View file
Expand Up @@ -308,9 +308,10 @@ static int64_t phb4_rc_write(struct phb4 *p, uint32_t offset, uint8_t sz,
break;
}

if (old != oldold)
PHBDBG(p, "Rewrote %x to %x for reg %x for W1C\n",
oldold, old, reg);
if (old != oldold) {
PHBLOGCFG(p, "Rewrote %x to %x for reg %x for W1C\n",
oldold, old, reg);
}

if (sz == 1) {
shift = (offset & 3) << 3;
Expand Down Expand Up @@ -4259,7 +4260,7 @@ static void phb4_probe_stack(struct dt_node *stk_node, uint32_t pec_index,
stk_index = dt_prop_get_u32(stk_node, "reg");
phb_num = dt_prop_get_u32(stk_node, "ibm,phb-index");
path = dt_get_path(stk_node);
prlog(PR_NOTICE, "PHB: Chip %d Found PHB4 PBCQ%d Stack %d at %s\n",
prlog(PR_INFO, "PHB: Chip %d Found PHB4 PBCQ%d Stack %d at %s\n",
gcid, pec_index, stk_index, path);
free(path);

Expand Down Expand Up @@ -4297,11 +4298,6 @@ static void phb4_probe_stack(struct dt_node *stk_node, uint32_t pec_index,
xscom_write(gcid, nest_stack + XPEC_NEST_STK_MMIO_BAR1_MASK, mmio1_bmask << 8);
bar_en |= XPEC_NEST_STK_BAR_EN_MMIO0 | XPEC_NEST_STK_BAR_EN_MMIO1;

prlog(PR_ERR, "PHB[%d:%d] PHB@0x%016llx IRQ@0x%016llx\n",
gcid, phb_num, phb_bar, irq_bar);
prlog(PR_ERR, "PHB[%d:%d] MMIO0@0x%016llx MMIO1@0x%016llx \n",
gcid, phb_num, mmio0_bar, mmio1_bar);

/* Build MMIO windows list */
mmio_win_sz = 0;
if (mmio0_bar) {
Expand All @@ -4328,13 +4324,13 @@ static void phb4_probe_stack(struct dt_node *stk_node, uint32_t pec_index,

/* Check ETU reset */
xscom_read(gcid, pci_stack + XPEC_PCI_STK_ETU_RESET, &val);
prlog_once(PR_ERR, "ETU reset: %llx\n", val);
prlog_once(PR_DEBUG, "ETU reset: %llx\n", val);
xscom_write(gcid, pci_stack + XPEC_PCI_STK_ETU_RESET, 0);
time_wait_ms(1);

// show we can read phb mmio space
foo = (void *)(phb_bar + 0x800); // phb version register
prlog_once(PR_ERR, "Version reg: 0x%016llx\n", in_be64(foo));
prlog_once(PR_DEBUG, "Version reg: 0x%016llx\n", in_be64(foo));

/* Create PHB node */
reg[0] = phb_bar;
Expand Down
2 changes: 1 addition & 1 deletion hw/phys-map.c
View file
Expand Up @@ -195,7 +195,7 @@ void phys_map_init(void)
phys_map = &phys_map_nimbus;
}

prlog(PR_NOTICE, "Assigning physical memory map table for %s\n", name);
prlog(PR_DEBUG, "Assigning physical memory map table for %s\n", name);

}

4 changes: 2 additions & 2 deletions hw/psi.c
View file
Expand Up @@ -1108,8 +1108,8 @@ static bool psi_init_psihb(struct dt_node *psihb)
psi_init_interrupts(psi);
psi_create_mm_dtnode(psi);

printf("PSI[0x%03x]: Found PSI bridge [active=%d]\n",
psi->chip_id, psi->active);
prlog(PR_INFO, "PSI[0x%03x]: Found PSI bridge [active=%d]\n",
psi->chip_id, psi->active);
return true;
}

Expand Down
4 changes: 2 additions & 2 deletions hw/slw.c
View file
Expand Up @@ -307,7 +307,7 @@ static bool slw_set_overrides_p9(struct proc_chip *chip, struct cpu_thread *c)
rc = xscom_read(chip->id,
XSCOM_ADDR_P9_EC_SLAVE(core, EC_PPM_SPECIAL_WKUP_HYP),
&tmp);
prlog(PR_NOTICE, "SLW: EC_PPM_SPECIAL_WKUP_HYP read 0x%016llx\n", tmp);
prlog(PR_DEBUG, "SLW: EC_PPM_SPECIAL_WKUP_HYP read 0x%016llx\n", tmp);
rc = xscom_read(chip->id,
XSCOM_ADDR_P9_EC_SLAVE(core, EC_PPM_SPECIAL_WKUP_OTR),
&tmp);
Expand Down Expand Up @@ -1145,7 +1145,7 @@ static void slw_init_chip_p9(struct proc_chip *chip)
{
struct cpu_thread *c;

prlog(PR_NOTICE, "SLW: Init chip 0x%x\n", chip->id);
prlog(PR_DEBUG, "SLW: Init chip 0x%x\n", chip->id);

/* At power ON setup inits for power-mgt */
for_each_available_core_in_chip(c, chip->id)
Expand Down
16 changes: 8 additions & 8 deletions hw/xscom.c
View file
Expand Up @@ -740,22 +740,22 @@ void xscom_init(void)
else
chip_name = chip_names[chip->type];

printf("XSCOM: chip 0x%x at 0x%llx [%s DD%x.%x]\n",
gcid, chip->xscom_base,
chip_name,
chip->ec_level >> 4,
chip->ec_level & 0xf);
/* We keep a "CHIP" prefix to make the log more user-friendly */
prlog(PR_NOTICE, "CHIP: Chip ID %04x type: %s DD%x.%x\n",
gcid, chip_name, chip->ec_level >> 4,
chip->ec_level & 0xf);
prlog(PR_DEBUG, "XSCOM: Base address: 0x%llx\n", chip->xscom_base);
}

/* Collect details to trigger xstop via XSCOM write */
p = dt_find_property(dt_root, "ibm,sw-checkstop-fir");
if (p) {
xstop_xscom.addr = dt_property_get_cell(p, 0);
xstop_xscom.fir_bit = dt_property_get_cell(p, 1);
prlog(PR_INFO, "XSTOP: XSCOM addr = 0x%llx, FIR bit = %lld\n",
xstop_xscom.addr, xstop_xscom.fir_bit);
prlog(PR_DEBUG, "XSTOP: XSCOM addr = 0x%llx, FIR bit = %lld\n",
xstop_xscom.addr, xstop_xscom.fir_bit);
} else
prlog(PR_INFO, "XSTOP: ibm,sw-checkstop-fir prop not found\n");
prlog(PR_DEBUG, "XSTOP: ibm,sw-checkstop-fir prop not found\n");
}

void xscom_used_by_console(void)
Expand Down
4 changes: 2 additions & 2 deletions libstb/stb.c
View file
Expand Up @@ -206,7 +206,7 @@ int tb_measure(enum resource_id id, void *buf, size_t len)

digestp = NULL;
if (!trusted_mode) {
prlog(PR_NOTICE, "STB: %s skipped resource %d, "
prlog(PR_INFO, "STB: %s skipped resource %d, "
"trusted_mode=0\n", __func__, id);
return STB_TRUSTED_MODE_DISABLED;
}
Expand Down Expand Up @@ -291,7 +291,7 @@ int sb_verify(enum resource_id id, void *buf, size_t len)
const char *name = NULL;

if (!secure_mode) {
prlog(PR_NOTICE, "STB: %s skipped resource %d, "
prlog(PR_INFO, "STB: %s skipped resource %d, "
"secure_mode=0\n", __func__, id);
return STB_SECURE_MODE_DISABLED;
}
Expand Down

0 comments on commit 7fab123

Please sign in to comment.