Re: [PATCH 0/6] loglevel=pci:8,acpi:8,apic=8 support v5

Previous thread: 2008 Linux Foundation technical advisory board election results by Jonathan Corbet on Tuesday, September 16, 2008 - 11:52 pm. (1 message)

Next thread: Re: [RFC PATCH 0/1]: timers: Timer Migration by Andrew Paprocki on Wednesday, September 17, 2008 - 12:35 am. (1 message)
From: Yinghai Lu
Date: Wednesday, September 17, 2008 - 12:10 am

KERN_PCI
    KERN_ACPI
v4: fix some checkpatch error and warning
v5: add default with DEFINE_LOGLEVE_SETUP_DEF
    KERN_APIC

usage:
	in .h to have
		#define KERN_PCI "<pci>"
	in .c to have
		DEFINE_LOGLEVEL_SETUP(pci, KERN_PCI, "pci:");
	then could use
		printk(KERN_DEBUG KERN_PCI fmt, ...);
	and command line
		loglevel=3,pci:8

you can add different printk to different files of one subsys if you like
not just one susbsys one tag, and don't need to update kernel.h to add more tags

YH
--

From: Yinghai Lu
Date: Wednesday, September 17, 2008 - 12:10 am

so could make subsys easy to add loglevel and xxx_printk
v2: make it more genric, so subsys user only need to two line macro
v3: add back nameStr, so could find out iommu: and iommu_gart: and etc
v4: use printk intead of pci_printk
v5: fix checkpatch error and warning
v6: add DEFINE_LOGLEVEL_SETUP_DEF to take default

usage:
	in .h to have
		#define KERN_PCI "<pci>"
	in .c to have
		DEFINE_LOGLEVEL_SETUP(pci, KERN_PCI, "pci:");
	then could use
		printk(KERN_DEBUG KERN_PCI fmt, ...);
	and command line
		loglevel=pci:8

you can add different printk to different files of one subsys if you like

Signed-off-by: Yinghai Lu <yhlu.kernel@gmail.com>
---
 arch/x86/kernel/vmlinux_32.lds.S  |    1 
 arch/x86/kernel/vmlinux_64.lds.S  |    2 
 include/asm-generic/vmlinux.lds.h |    8 +++
 include/linux/init.h              |   22 ++++++++++
 include/linux/kernel.h            |    9 ++++
 init/main.c                       |   77 +++++++++++++++++++++++++++++++++++++-
 kernel/printk.c                   |   28 +++++++++++--
 7 files changed, 142 insertions(+), 5 deletions(-)

Index: linux-2.6/arch/x86/kernel/vmlinux_32.lds.S
===================================================================
--- linux-2.6.orig/arch/x86/kernel/vmlinux_32.lds.S
+++ linux-2.6/arch/x86/kernel/vmlinux_32.lds.S
@@ -145,6 +145,7 @@ SECTIONS
 	*(.x86_cpu_dev.init)
 	__x86_cpu_dev_end = .;
   }
+  LOGLEVEL_SETUP_INIT(8)
   DYN_ARRAY_INIT(8)
   SECURITY_INIT
   . = ALIGN(4);
Index: linux-2.6/arch/x86/kernel/vmlinux_64.lds.S
===================================================================
--- linux-2.6.orig/arch/x86/kernel/vmlinux_64.lds.S
+++ linux-2.6/arch/x86/kernel/vmlinux_64.lds.S
@@ -174,6 +174,8 @@ SECTIONS
   }
   __x86_cpu_dev_end = .;
 
+  LOGLEVEL_SETUP_INIT(8)
+
   DYN_ARRAY_INIT(8)
 
   SECURITY_INIT
Index: linux-2.6/include/asm-generic/vmlinux.lds.h
===================================================================
--- linux-2.6.orig/include/asm-generic/vmlinux.lds.h
+++ ...
From: Yinghai Lu
Date: Wednesday, September 17, 2008 - 12:10 am

use DEFINE_LOGLEVEL_SETUP to set loglevel for pci

Signed-off-by: Yinghai Lu <yhlu.kernel@gmail.com>
---
 drivers/pci/pci.c   |    2 ++
 include/linux/pci.h |    2 ++
 2 files changed, 4 insertions(+)

Index: linux-2.6/drivers/pci/pci.c
===================================================================
--- linux-2.6.orig/drivers/pci/pci.c
+++ linux-2.6/drivers/pci/pci.c
@@ -1953,6 +1953,8 @@ static int __devinit pci_setup(char *str
 }
 early_param("pci", pci_setup);
 
+DEFINE_LOGLEVEL_SETUP(pci, KERN_PCI, "pci:");
+
 device_initcall_sync(pci_init);
 
 EXPORT_SYMBOL(pci_reenable_device);
Index: linux-2.6/include/linux/pci.h
===================================================================
--- linux-2.6.orig/include/linux/pci.h
+++ linux-2.6/include/linux/pci.h
@@ -55,6 +55,8 @@
 /* Include the ID list */
 #include <linux/pci_ids.h>
 
+#define KERN_PCI "<pci>"
+
 /* pci_slot represents a physical slot */
 struct pci_slot {
 	struct pci_bus *bus;		/* The bus this slot is on */
--

From: Yinghai Lu
Date: Wednesday, September 17, 2008 - 12:10 am

v2: use printk(KERN_DEBUG KERN_PCI ...
v3: fix checkpatch error and warning

Signed-off-by: Yinghai Lu <yhlu.kernel@gmail.com>

---
 drivers/pci/probe.c |   28 +++++++++++++++++-----------
 1 file changed, 17 insertions(+), 11 deletions(-)

Index: linux-2.6/drivers/pci/probe.c
===================================================================
--- linux-2.6.orig/drivers/pci/probe.c
+++ linux-2.6/drivers/pci/probe.c
@@ -304,7 +304,8 @@ static int __pci_read_base(struct pci_de
 		} else {
 			res->start = l64;
 			res->end = l64 + sz64;
-			printk(KERN_DEBUG "PCI: %s reg %x 64bit mmio: [%llx, %llx]\n",
+			printk(KERN_DEBUG KERN_PCI
+				 "PCI: %s reg %x 64bit mmio: [%llx, %llx]\n",
 				 pci_name(dev), pos, res->start, res->end);
 		}
 	} else {
@@ -315,9 +316,10 @@ static int __pci_read_base(struct pci_de
 
 		res->start = l;
 		res->end = l + sz;
-		printk(KERN_DEBUG "PCI: %s reg %x %s: [%llx, %llx]\n", pci_name(dev),
-			 pos, (res->flags & IORESOURCE_IO) ? "io port":"32bit mmio",
-			 res->start, res->end);
+		printk(KERN_DEBUG KERN_PCI "PCI: %s reg %x %s: [%llx, %llx]\n",
+			pci_name(dev), pos,
+			(res->flags & IORESOURCE_IO) ? "io port" : "32bit mmio",
+			res->start, res->end);
 	}
 
  out:
@@ -388,8 +390,9 @@ void __devinit pci_read_bridge_bases(str
 			res->start = base;
 		if (!res->end)
 			res->end = limit + 0xfff;
-		printk(KERN_DEBUG "PCI: bridge %s io port: [%llx, %llx]\n",
-				 pci_name(dev), res->start, res->end);
+		printk(KERN_DEBUG KERN_PCI
+			 "PCI: bridge %s io port: [%llx, %llx]\n",
+			 pci_name(dev), res->start, res->end);
 	}
 
 	res = child->resource[1];
@@ -401,8 +404,9 @@ void __devinit pci_read_bridge_bases(str
 		res->flags = (mem_base_lo & PCI_MEMORY_RANGE_TYPE_MASK) | IORESOURCE_MEM;
 		res->start = base;
 		res->end = limit + 0xfffff;
-		printk(KERN_DEBUG "PCI: bridge %s 32bit mmio: [%llx, %llx]\n",
-				 pci_name(dev), res->start, res->end);
+		printk(KERN_DEBUG KERN_PCI
+			 "PCI: bridge %s 32bit mmio: [%llx, ...
From: Yinghai Lu
Date: Wednesday, September 17, 2008 - 12:10 am

use DEFINE_LOGLEVEL_SETUP to set loglevel for acpi
v2: use <acpi, "acpi:"> instead
v3: use KERN_ACPI

Signed-off-by: Yinghai Lu <yhlu.kernel@gmail.com>

---
 drivers/acpi/osl.c   |    2 ++
 include/linux/acpi.h |    1 +
 2 files changed, 3 insertions(+)

Index: linux-2.6/drivers/acpi/osl.c
===================================================================
--- linux-2.6.orig/drivers/acpi/osl.c
+++ linux-2.6/drivers/acpi/osl.c
@@ -75,6 +75,8 @@ EXPORT_SYMBOL(acpi_in_debugger);
 extern char line_buf[80];
 #endif				/*ENABLE_DEBUGGER */
 
+DEFINE_LOGLEVEL_SETUP(acpi, KERN_ACPI, "acpi:");
+
 static unsigned int acpi_irq_irq;
 static acpi_osd_handler acpi_irq_handler;
 static void *acpi_irq_context;
Index: linux-2.6/include/linux/acpi.h
===================================================================
--- linux-2.6.orig/include/linux/acpi.h
+++ linux-2.6/include/linux/acpi.h
@@ -43,6 +43,7 @@
 #include <asm/acpi.h>
 #include <linux/dmi.h>
 
+#define KERN_ACPI "<acpi>"
 
 enum acpi_irq_model_id {
 	ACPI_IRQ_MODEL_PIC = 0,
--

From: Yinghai Lu
Date: Wednesday, September 17, 2008 - 12:10 am

Signed-off-by: Yinghai Lu <yhlu.kernel@gmail.com>

---
 drivers/acpi/numa.c |    9 +++++++++
 1 file changed, 9 insertions(+)

Index: linux-2.6/drivers/acpi/numa.c
===================================================================
--- linux-2.6.orig/drivers/acpi/numa.c
+++ linux-2.6/drivers/acpi/numa.c
@@ -150,6 +150,15 @@ static __init int slit_valid(struct acpi
 {
 	int i, j;
 	int d = slit->locality_count;
+	printk(KERN_DEBUG KERN_ACPI "ACPI: SLIT: nodes = %d\n", d);
+	for (i = 0; i < d; i++) {
+		printk(KERN_DEBUG KERN_ACPI "  ");
+		for (j = 0; j < d; j++)  {
+			u8 val = slit->entry[d*i + j];
+			printk(KERN_CONT KERN_ACPI " %d", val);
+		}
+		printk(KERN_CONT KERN_ACPI "\n");
+	}
 	for (i = 0; i < d; i++) {
 		for (j = 0; j < d; j++)  {
 			u8 val = slit->entry[d*i + j];
--

From: Yinghai Lu
Date: Wednesday, September 17, 2008 - 12:10 am

and kill apic_printk
using loglevel=apic:8 intead

Signed-off-by: Yinghai Lu <yhlu.kernel@gmail.com>

---
 Documentation/kernel-parameters.txt         |    6 
 arch/x86/kernel/apic.c                      |  108 +++++-------
 arch/x86/kernel/io_apic.c                   |  235 +++++++++++++---------------
 arch/x86/kernel/mpparse.c                   |   10 -
 arch/x86/kernel/smpboot.c                   |   11 -
 include/asm-x86/apic.h                      |   20 --
 include/asm-x86/es7000/wakecpu.h            |    6 
 include/asm-x86/mach-default/mach_wakecpu.h |    6 
 8 files changed, 178 insertions(+), 224 deletions(-)

Index: linux-2.6/Documentation/kernel-parameters.txt
===================================================================
--- linux-2.6.orig/Documentation/kernel-parameters.txt
+++ linux-2.6/Documentation/kernel-parameters.txt
@@ -306,12 +306,6 @@ and is between 256 and 4096 characters.
 			not play well with APC CPU idle - disable it if you have
 			APC and your system crashes randomly.
 
-	apic=		[APIC,i386] Advanced Programmable Interrupt Controller
-			Change the output verbosity whilst booting
-			Format: { quiet (default) | verbose | debug }
-			Change the amount of debugging information output
-			when initialising the APIC and IO-APIC components.
-
 	apm=		[APM] Advanced Power Management
 			See header of arch/x86/kernel/apm_32.c.
 
Index: linux-2.6/arch/x86/kernel/apic.c
===================================================================
--- linux-2.6.orig/arch/x86/kernel/apic.c
+++ linux-2.6/arch/x86/kernel/apic.c
@@ -58,6 +58,8 @@
 # error SPURIOUS_APIC_VECTOR definition error
 #endif
 
+DEFINE_LOGLEVEL_SETUP_DEF(apic, KERN_APIC, "apic:", 6);
+
 #ifdef CONFIG_X86_32
 /*
  * Knob to control our willingness to enable the local APIC.
@@ -123,8 +125,6 @@ char system_vectors[NR_VECTORS] = { [0 .
 /*
  * Debug level, exported for io_apic.c
  */
-unsigned int apic_verbosity;
-
 int pic_mode;
 
 /* Have we found an MP table */
@@ -549,7 ...
From: Alexey Dobriyan
Date: Wednesday, September 17, 2008 - 12:30 am

I think all of this is overdesigned and stupid.

People expecting that loglevels are exactly right so they can calm messages
are like security-savvy people who expect all security relevant bugfixes carry
CVE tag.

grep says there are 50757 printk calls, only 32129 of them carry KERN_ tag.

Oh, and new and improved logs:

	[    0.340326] pci 0000:00:01.0: PME# supported from D0 D3hot D3cold
	[    0.340326] pci 0000:00:01.0: PME# disabled
	[    0.340326] <pci>PCI: 0000:00:1a.0 reg 20 io port: [dc00, dc1f]
	[    0.340413] <pci>PCI: 0000:00:1a.1 reg 20 io port: [e000, e01f]
	[    0.340549] <pci>PCI: 0000:00:1a.7 reg 10 32bit mmio: [febffc00, febfffff]
		       ^^^^^^^^^

How this can be an improvement for those who boot with ignore_loglevel,
I don't know.
--

From: Ingo Molnar
Date: Wednesday, September 17, 2008 - 1:47 am

the subsystem tags should be cut out by dmesg by default, just like the 
normal <1> tags are cut out.

about your general point: it's valid observations. The idea would be to 
end this never ending unstable conflict of people adding printks for 
debug reasons versus people removing printks who'd like to have a nice 
looking bootup log.

Both point of views are correct in different usecases - and IMO the best 
solution is the consolidation hpa suggested and what Yinghai is working 
towards: to replace all the current ad-hoc debug printouts (with 
different switchlets strewn all across the kernel) with an ASCII based 
generic printk facility and a generic boot line option.

people adding printks without any KERN_ tag is fine - this facility is 
only interesting to subsystems who'd like to make use of it. (core code, 
ec. - the items that have a disproportionate weight in terms of system 
stability, and which thus have a disproportionate need to stay 
debuggable and regression-free)

[ and we also need a dynamic facility to change the filters via debugfs 
  btw - it should be possible to modify these printk filters after 
  bootup, runtime. Many subsystems have debug printks that make sense to 
  enable/disable after the system has booted up. ]

and it's bad and a showstopper if the default output of 'dmesg' 
degrades, like your noticed - those are bugs in the concept and need to 
be fixed.

	Ingo
--

From: Alexey Dobriyan
Date: Wednesday, September 17, 2008 - 2:25 am

Simply nice looking log is irrational. I can understand if by default
messages do not fit into printk buffer before userspace can save them.
This is indeed harmful and loses information.

OTOH, all these loglevel games ultimately lead to missed messages (by design).
I remember myself wasting time debugging wrong path simply because box
wasn't booted with ignore_loglevel and critical debugging printk wasn't on
serial console, but only in dmesg.

So, in some cases useless information will not be shown, but in some

--

From: Ingo Molnar
Date: Wednesday, September 17, 2008 - 2:40 am

yes, i had that happen too, and i am quite sure that the most sensible 
way out is to provide a _single_ point for users to enable 'all things 
debug'. I.e. a "loglevel=debug" (or loglevel=all) boot parameter.

Instead of the current list of zillions of ad-hoc switchlets that are 
scattered all around the kernel. Tell me, within 10 seconds, which one 
of these are the correct options and which ones are typos:

 lapic
 lapic=verbose 
 apic=debug
 ignore-loglevel 
 initcalldebug
 early_printk=vga
 ignoreloglevel
 debug
 verbose
 ignore_loglevel
 initcall_debug
 apic=verbose
 initcall=debug
 earlyprintk=vga

(i'm willing to bet a good beer that you probably have not found the 
right solution in time :-)

People dont really want to individually enable pci or apic or smp 
debugging or whatnot - when it's about boot debugging they (and we) just 
want something really verbose. (_Sometimes_ we want more accurate 
filters for runtime debugging, especially if something can produce a log 
of continuing printks during userspace bootup - but that is an 
afterthought IMO.)

with such a facility in place we could just hide all non-essential 
messages by default, and have the perpetual possibility to get a verbose 
bootup without users having to rebuild their (often distro-built) 
kernel.

The only ongoing work would be to occasionally convert a stray 
informational printk that seemed to be useful during early development 
to a subsystem printk that hides it by default. The printk is not 
actually _lost_ and is utmost trivial to activate it again, should the 
need arise - which loss is why the "get rid of printks" patches are 
opposed most of the time.

So i think we'll hit multiple birds with the same stone.

	Ingo
--

From: Yinghai Lu
Date: Wednesday, September 17, 2008 - 9:23 am

v6 should fix the problem, to support several seperate loglevel.

YH
--

From: H. Peter Anvin
Date: Wednesday, September 17, 2008 - 10:07 am

It's probably worth pointing out that we had similar transition pains 
when we introduced the loglevel tags.  If you used an old dmesg/klogd 
you got the loglevel tags; we cleaned them up.

	-hpa
--

From: Yinghai Lu
Date: Wednesday, September 17, 2008 - 11:10 am

want to expand loglevel tags to two digi bits, hope the dmesg/klogd
could handle it.

YH
--

From: H. Peter Anvin
Date: Wednesday, September 17, 2008 - 11:17 am

I doubt they'd be written to handle that already.

	-hpa
--

From: Yinghai Lu
Date: Wednesday, September 17, 2008 - 12:05 pm

dmesg util in opensuse 10.3 does support two digi bits loglevel tags.

YH
--

Previous thread: 2008 Linux Foundation technical advisory board election results by Jonathan Corbet on Tuesday, September 16, 2008 - 11:52 pm. (1 message)

Next thread: Re: [RFC PATCH 0/1]: timers: Timer Migration by Andrew Paprocki on Wednesday, September 17, 2008 - 12:35 am. (1 message)