Skip to contentSkip to conversation

[PATCH-RFC} 3 of 4 - New problem logging macros, plus template generation

PATCH Larry Kessler 12 participants 32 messages Sep 24, 2002 – Oct 1, 2002 Kbuild

lore
Share & tools
lore
#0 lore raw

Please see [PATCH-RFC] README 1ST note...

Summary of this patch...

Rules.make
Creates formating templates for modules

arch/i386/vmlinux.lds.S
.log section gets DISCARDed

scripts/generate_templates.c
A user-mode utility that reads information stored in the .log section of one or more .o files, and

creates the corresponding formatting templates. (The .log section is created when compiling problem() and detail()/array_detail() invocations.)

scripts/evlib.c
Stuff copied from libevl that generate_templates.c needs.

scripts/evlib.h
Ditto

kernel/problem.c
Implements the __problem function, which is called by the problem macro.

include/linux/problem.h
Implements the introduce, problem, detail and array_detail macros.

Makefile +23 -1
diff -Naur linux.org/Makefile linux.problem.patched/Makefile
@@ -175,7 +175,7 @@
 # Helpers built in scripts/
 # ---------------------------------------------------------------------------
 
-scripts/docproc scripts/fixdep scripts/split-include : scripts ;
+scripts/docproc scripts/fixdep scripts/split-include scripts/generate_templates : scripts ;
 
 .PHONY: scripts
 scripts:
@@ -498,6 +498,9 @@
 $(patsubst %, _modinst_%, $(SUBDIRS)) :
 	@$(MAKE) -C $(patsubst _modinst_%, %, $@) modules_install
 
+.PHONY: module_templates
+module_templates: $(SUBDIRS)
+
 else # CONFIG_MODULES
 
 # Modules not configured
@@ -559,6 +562,25 @@
 	. scripts/mkversion > .version ; \
 	rpm -ta $(TOPDIR)/../$(KERNELPATH).tar.gz ; \
 	rm $(TOPDIR)/../$(KERNELPATH).tar.gz
+
+# Templates for events logged with problem()
+# ---------------------------------------------------------------------------
+TEMPLATE_HOME=/var/evlog/templates
+
+templates: scripts/generate_templates FORCE
+	rm -rf templates
+	scripts/generate_templates templates \
+		$(INIT) \
+		$(CORE_FILES) \
+		$(LIBS) \
+		$(DRIVERS) \
+		$(NETWORKS)
+ifdef CONFIG_MODULES
+	$(MAKE) module_templates MAKECMDGOALS=module_templates
+endif
+
+templates_install:
+	cp -r templates/* $(TEMPLATE_HOME)
 
 else # ifeq ($(filter $(noconfig_targets),$(MAKECMDGOALS)),)
 
Rules.make +21 -2
diff -Naur linux.org/Rules.make linux.problem.patched/Rules.make
@@ -115,10 +115,12 @@
 # contain a comma
 depfile = $(subst $(comma),_,$(@D)/.$(@F).d)
 
-# We're called for one of three purposes:
+# We're called for one of four purposes:
 # o fastdep: build module version files (.ver) for $(export-objs) in
 #   the current directory
 # o modules_install: install the modules in the current directory
+# o module_templates: for each module with a .log section, generate
+#   the corresponding event-logging templates
 # o build: When no target is given, first_rule is the default and
 #   will build the built-in and modular objects in this dir
 #   (or a subset thereof, depending on $(KBUILD_MODULES),$(KBUILD_BUILTIN)
@@ -225,12 +227,28 @@
 ifneq ($(obj-m),)
 	@echo Installing modules in $(MODLIB)/kernel/$(RELDIR)
 	@mkdir -p $(MODLIB)/kernel/$(RELDIR)
-	@cp $(obj-m) $(MODLIB)/kernel/$(RELDIR)
+	@(for o in $(obj-m); do objcopy -R .log $$o $(MODLIB)/kernel/$(RELDIR)/$$o; done)
 else
 	@echo -n
 endif
 
 else # ! modules_install
+ifeq ($(MAKECMDGOALS),module_templates)
+
+# ==========================================================================
+# Creating event-logging templates for modules
+# ==========================================================================
+
+.PHONY: module_templates
+
+module_templates: sub_dirs
+ifneq ($(obj-m),)
+	@$(TOPDIR)/scripts/generate_templates $(TOPDIR)/templates $(obj-m)
+else
+	@echo -n
+endif
+
+else # ! module_templates
 
 # ==========================================================================
 # Building
@@ -405,6 +423,7 @@
 
 targets += $(host-progs-single) $(host-progs-multi-objs) $(host-progs-multi) 
 
+endif # ! module_templates
 endif # ! modules_install
 endif # ! fastdep
 
arch/i386/vmlinux.lds.S +1 -0
diff -Naur linux.org/arch/i386/vmlinux.lds.S linux.problem.patched/arch/i386/vmlinux.lds.S
@@ -88,6 +88,7 @@
 	*(.text.exit)
 	*(.data.exit)
 	*(.exitcall.exit)
+	*(.log)
 	}
 
   /* Stabs debugging sections.  */
include/linux/problem.h +160 -0

160 lines not on this page · raw message

kernel/Makefile +2 -2
diff -Naur linux.org/kernel/Makefile linux.problem.patched/kernel/Makefile
@@ -3,7 +3,7 @@
 #
 
 export-objs = signal.o sys.o kmod.o context.o ksyms.o pm.o exec_domain.o \
-		printk.o platform.o suspend.o dma.o evlog.o
+		printk.o platform.o suspend.o dma.o evlog.o problem.o
 
 obj-y     = sched.o fork.o exec_domain.o panic.o printk.o \
 	    module.o exit.o itimer.o time.o softirq.o resource.o \
@@ -17,7 +17,7 @@
 obj-$(CONFIG_PM) += pm.o
 obj-$(CONFIG_BSD_PROCESS_ACCT) += acct.o
 obj-$(CONFIG_SOFTWARE_SUSPEND) += suspend.o
-obj-$(CONFIG_EVLOG) += evlog.o
+obj-$(CONFIG_EVLOG) += evlog.o problem.o
 
 ifneq ($(CONFIG_IA64),y)
 # According to Alan Modra <[email protected]>, the -fno-omit-frame-pointer is
kernel/problem.c +297 -0

297 lines not on this page · raw message

scripts/Makefile +5 -1
diff -Naur linux.org/scripts/Makefile linux.problem.patched/scripts/Makefile
@@ -8,8 +8,10 @@
 # docproc: 	 Preprocess .tmpl file in order to generate .sgml documentation
 # conmakehash:	 Create arrays for initializing the kernel console tables
 # tkparse: 	 Used by xconfig
+# generate_templates:	Used to generate a formatting template for each
+#		problem() call in the kernel
 
-all: fixdep split-include docproc conmakehash __chmod
+all: fixdep split-include docproc conmakehash __chmod generate_templates
 
 # The following temporary rule will make sure that people's
 # trees get updated to the right permissions, since patch(1)
@@ -63,3 +65,5 @@
 	@rm -f core $(host-progs)
 	@$(MAKE) -C lxdialog mrproper
 
+generate_templates: generate_templates.c evlib.c evlib.h
+	$(HOSTCC) $(HOSTCFLAGS) -o generate_templates generate_templates.c evlib.c -lbfd -liberty
scripts/evlib.c +398 -0

398 lines not on this page · raw message

scripts/evlib.h +78 -0

78 lines not on this page · raw message

scripts/generate_templates.c +392 -0

392 lines not on this page · raw message

#1 lore raw
Quoted 8 lines

+/*
+ * introduce(), problem(), and detail() macros
+ * Sample usage:
+ * problem(LOG_ALERT, "Disk on fire!",
+ * detail(disk, "%s", drive->name),
+ * detail(temperature, "%d", drive->degC),
+ * detail(action, "%s", "Put out fire; run fsck."));
+ */

action is policy, it does not belong in the kernel at all. Further, I not sure we need to add all this new infrastructure when we could obtain the same result via [off the top of my head] printk standards in key drivers.

Why don't you start out with a list of requirements that you want to see from drivers? Only then can we objectively evaluate our needs.

You are proposing a solution without really making it clear what problems you are solving.

Jeff

#2 lore raw

In message <[email protected]> you write:

Quoted 11 lines
Quoted 8 lines

+/*
+ * introduce(), problem(), and detail() macros
+ * Sample usage:
+ * problem(LOG_ALERT, "Disk on fire!",
+ * detail(disk, "%s", drive->name),
+ * detail(temperature, "%d", drive->degC),
+ * detail(action, "%s", "Put out fire; run fsck."));
+ */

action is policy, it does not belong in the kernel at all.

Yes, it's a bad example, but...

Quoted 3 lines

Further, I not sure we need to add all this new infrastructure when we could obtain the same result via [off the top of my head] printk standards in key drivers.

They want to formalize it so you can template it. Noone wants "ERR:
400001020567" on their console, so having a method of generating that number from something which is readable in source (and by default turns into a pretty printk) makes sense.

Quoted 5 lines

Why don't you start out with a list of requirements that you want to see from drivers? Only then can we objectively evaluate our needs.

You are proposing a solution without really making it clear what problems you are solving.

Driver error collection and reporting. You want an automated catalogue of all the error messages the kernel can produce. You want them to be consistent. You want to be able to control the verbosity. You want to be able to attach other mechanisms to collect them. You want to combine them with your userspace logging systems to give a picture of machine state (think thousands of remotely administered machines).

You *can* do this with printk, but only the most disciplined of drivers do (eg. Becker net drivers are really good at putting "eth0:" etc in messages, others are not so great).

For this to be useful, it has to be ubiquitous, and for that it has to be *easier* than printk to use correctly (which is a hard challenge).

Quoted 6 lines

If you actually want to standardize some diagnostic messages, it is a huge mistake [as your scsi driver example shows] to continue to use random text strings followed by a typed attribute list. If you really wanted to standardize logging, why continue to allow driver authors to printk driver-specific text strings in lieu of a standard string that applies to the same situation in N drivers.

I disagree. In their non-printk backend, the strings are simply hashed (with the driver name) into tokens: they're remarkably robust against driver linenumber changes and minor code changes.

We don't have that much structure in the kernel: the helper macros the minimal sufficient to ensure that the device is identified with every problem.

There are nice things you can do with ratelimiting these messages sanely as well, and translations.

I think the architecture is fairly sound, although the implementation needs some tweaking.

Rusty.
--
Anyone who quotes me in their sig is an idiot. -- Rusty Russell.

#3 lore raw
Quoted 10 lines · Rusty Russell

In message <[email protected]> [Jeff Garzik] write[s]:

Quoted 3 lines

Further, I not sure we need to add all this new infrastructure when we could obtain the same result via [off the top of my head] printk standards in key drivers.

They want to formalize it so you can template it. Noone wants "ERR:
400001020567" on their console, so having a method of generating that number from something which is readable in source (and by default turns into a pretty printk) makes sense.

Agreed. But changing every printk in the kernel does not make sense.

Clean up and standardize the printks(), then post-process the printk() info.

Quoted 13 lines
Quoted 3 lines

Why don't you start out with a list of requirements that you want to see from drivers? Only then can we objectively evaluate our needs.

You are proposing a solution without really making it clear what problems you are solving.

Driver error collection and reporting. You want an automated catalogue of all the error messages the kernel can produce. You want them to be consistent. You want to be able to control the verbosity. You want to be able to attach other mechanisms to collect them. You want to combine them with your userspace logging systems to give a picture of machine state (think thousands of remotely administered machines).

Quoted 6 lines

You *can* do this with printk, but only the most disciplined of drivers do (eg. Becker net drivers are really good at putting "eth0:" etc in messages, others are not so great).

For this to be useful, it has to be ubiquitous, and for that it has to be *easier* than printk to use correctly (which is a hard challenge).

If you note, the net drivers I write from scratch follow the Becker style of messaging as well. It is not difficult to have a style guide and adhere to it. We don't need a new API for that.

Quoted 6 lines
Quoted 1 line

If you actually want to standardize some diagnostic messages, it is a huge mistake [as your scsi driver example shows] to continue to use random text strings followed by a typed attribute list. If you really wanted to standardize logging, why continue to allow driver authors to printk driver-specific text strings in lieu of a standard string that applies to the same situation in N drivers.

I disagree. In their non-printk backend, the strings are simply hashed (with the driver name) into tokens: they're remarkably robust against driver linenumber changes and minor code changes.

I think you misunderstand... If you want to standardize the messages, you change the text in the strings, and perhaps the args passed to printk, so that they look the same from driver to driver.

This is useful, needed work that benefits POSIX event logging -- while at the same time providing better value to normal printk() users.

Quoted 9 lines

We don't have that much structure in the kernel: the helper macros the minimal sufficient to ensure that the device is identified with every problem.

There are nice things you can do with ratelimiting these messages sanely as well, and translations.

I think the architecture is fairly sound, although the implementation needs some tweaking.

The backend is fairly sound. And I agree in general event logging is useful, and I fully support integrating [sane] support into the kernel.

But the kernel API is utter crap.

Adding <foo>_problem.h for every subsystem?
Adding <foo>_introduce() for every subsystem?
Changing every printk() in the damn kernel?

Come on dude, I _know_ you have more taste than that.

Jeff

#4 lore raw

In message <[email protected]> you write:

Quoted 6 lines

The backend is fairly sound. And I agree in general event logging is useful, and I fully support integrating [sane] support into the kernel.

But the kernel API is utter crap.

Adding <foo>_problem.h for every subsystem?

<sigh>. That's an extension, designed to make things *easier* on the author, for example to share code between network drivers. But I'm more than happy to grow them on demand (you know IBM programmers, they're always want "completeness").

Quoted 3 lines

Changing every printk() in the damn kernel?

Come on dude, I _know_ you have more taste than that.

I'm not interested in changing all the printks. I'm interested in designing the simplest regularized logging interface I can. If it's done right, driver authors will migrate to it because it's easier for them, and their bug reports become clearer, and sysadmins get happier.

And even though they don't care about the eventlogging tools, all that stuff becomes exponentially more useful as a bonus.

Rusty.
--
Anyone who quotes me in their sig is an idiot. -- Rusty Russell.

#5 lore raw
Quoted 8 lines · Rusty Russell

In message <[email protected]> [Jeff Garzik] write[s]:

Quoted 2 lines

Changing every printk() in the damn kernel? Come on dude, I _know_ you have more taste than that.

I'm not interested in changing all the printks. I'm interested in designing the simplest regularized logging interface I can. If it's done right, driver authors will migrate to it because it's easier for them, and their bug reports become clearer, and sysadmins get happier.

Thanks for saying that out loud.

So, IOW, IBM makes the API, and expects everyone else to step up and do the huge amount of grunt work... Nice.

"If it's done right," there need not be massive changes at all. More tomorrow.

Jeff, just another unpaid IBM worker...

#6 lore raw

In message <[email protected]> you write:

Quoted 2 lines

So, IOW, IBM makes the API, and expects everyone else to step up and do the huge amount of grunt work... Nice.

Like those zero-copy guys who didn't port all the drivers? Or those NAPI guys? Bastards! 8)

Quoted 2 lines

"If it's done right," there need not be massive changes at all. More tomorrow.

Hmm, is this like "how do you keep an idiot in suspense?" 8)

Quoted 1 line

Jeff, just another unpaid IBM worker...

Yes, back to the salt mines, Jeff! YA!
Rusty.
--
Anyone who quotes me in their sig is an idiot. -- Rusty Russell.

#7 lore raw

alternate event logging proposal

Here's my suggestion, which will maintain compatibility with 2.2 and 2.4 kernels, and require a -very- minimal kernel update, to support event logging.

When CONFIG_EVLOG is defined, printk outputs a tagged ASCII format: KERN_xxx, the format string (verbatim), and 0 or more argument values. Since this loses the argument tags (names) from the current IBM event logging code, you can re-gain this info by post-processing the printk. Post-processing can be done by a hacked cpp (see http://www.tinycc.org/ for a tiny, steal-able one) or a simple Perl script.

The only real difference at that point between IBM's implementation and my proposal is that some argument tags are expressions, not simple C identifiers (flag ? "true" : "false") instead of "flag". This is a problem if you want to do SQLish queries on the tags in the event log, but its a work-around-able problem, IMO.

This scheme should fit with the backend code already created by IBM, which isn't too bad IMO.

Even if the details are disagreeable, I really think that we should work towards making printk (or 'warn', 'error', etc.) log the desired information, while still keeping older drivers useful, and keeping drivers source-compatible with older kernels.

Now, turning to a tangent topic that relates to either scheme...

With either your proposal or mine, event logging is far more useful if similar drivers spit out similar diagnostics. i.e. it's less useful if 8139too net driver spits out 'status16' in one interrupt event, and 8139cp net driver spits out 'status32' in another. Though they are different hardware and the values mean different things, my point is the concepts are similar, and thus better diagnostics are achieved with subsystem diagnostic standards.

Such standards are in actuality independent of event logging per se, but if IBM wants to push this thing, I would like to see some proposals as to what IBM actually wants drivers to log. I have not seen that at all, and think that such proposals should be an integral part of an event logging system. Otherwise the diagnostics are less useful, and IBM would have failed to demonstrate an adequate grasp of the problem domain [which then leads to other, typical software engineering problems...]

"What do you want to log?" is as important to me as "how do you want to log it?" And the answers to the two questions are very much intertwined.

Comments?

Jeff

#8 lore raw

Re: alternate event logging proposal

Quoted 1 line · Jeff Garzik

"What do you want to log?" is as important to me as "how do you want to log it?" And the answers to the two questions are very much intertwined.

Also related is "how can userspace be notified of kernel events?". There is no way for a userspace app to be notified that, for instance, an ATM device got a loss of signal. The drivers print it out, but the userspace app has no clue.

I think that there should be a relatively generic way for drivers to distribute events such as this and for userspace to register interest in them.

Maybe netlink is the way to go, but its not exactly a simple interface.

Chris

#9 lore raw

Re: alternate event logging proposal

Quoted 3 lines · Chris Friesen

Also related is "how can userspace be notified of kernel events?". There is no way for a userspace app to be notified that, for instance, an ATM device got a loss of signal. The drivers print it out, but the userspace app has no clue.

Maybe netlink is the way to go, but its not exactly a simple interface.

Well, the eventual intention [whenever <somebody> codes it up] for ethernet devices is to have netlink proactively deliver link up/down events, and perhaps other events. For this specific problem, at least, I think netlink is the way to go. ATM drivers, or ethernet drivers, simply need some helper functions they can call. The library code for those helper functions is the only place where netlink complexity is needed...

In existing drivers that call netif_carrier_{on,off}, it is perhaps even possible to have them send netlink messages with no driver-specific code changes at all.

Jeff

#10 lore raw

Re: alternate event logging proposal

Quoted 1 line · Jeff Garzik

In existing drivers that call netif_carrier_{on,off}, it is perhaps even possible to have them send netlink messages with no driver-specific code changes at all.

This is something that I have been asked to look at, here. Jeff, how (or is?) any of the netlink info pushed up to userspace? The idea that someone came to me with was to have something in (driverfs? netdevfs?) that was poll()able and read()able. read() giving current state, and poll() waking on changes. Or maybe two different files, but something.
Of course it'd be greate to be generic. I just assumed it would come
from netif_* for netdevices.

Is this something planned? wanted? something I should bang out into 2.5.x before end of next month?

We could have a generic device-events file (akin to acpi events) that a daemon dispatches events into user-land, or we could have a kernel->user callback a la /sbin/hotplug, or we could have many device/subsys specific files.

Anyone have a preference?

Tim

Signature · 4 lines
Tim Hockin
Systems Software Engineer
Sun Microsystems, Linux Kernel Engineering
[email protected]
#11 lore raw

Re: alternate event logging proposal

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

Quoted 13 lines · Tim Hockin
Quoted 3 lines · Jeff Garzik

In existing drivers that call netif_carrier_{on,off}, it is perhaps even possible to have them send netlink messages with no driver-specific code changes at all.

This is something that I have been asked to look at, here. Jeff, how (or is?) any of the netlink info pushed up to userspace? The idea that someone came to me with was to have something in (driverfs? netdevfs?) that was poll()able and read()able. read() giving current state, and poll() waking on changes. Or maybe two different files, but something.
Of course it'd be greate to be generic. I just assumed it would come
from netif_* for netdevices.

Quoted 2 lines

Is this something planned? wanted? something I should bang out into 2.5.x before end of next month?

Wanted.
Example: In desktop / consumer applications, you can use link-state change to do things like invoke the DHCP client daemon, or get yourself a link-local IP address.

Quoted 6 lines

We could have a generic device-events file (akin to acpi events) that a daemon dispatches events into user-land, or we could have a kernel->user callback a la /sbin/hotplug, or we could have many device/subsys specific files.

Anyone have a preference?

I liked the /sbin/hotplug arrangement (aka call_usermode_helper). In fact, my plan was to add the call_usermode_helper call to the netif_carrier_[on,off] functions. Unfortuantely, I've been to too many of Rusty's talks, and know that calling a function that is only safe in user context is unlikely to be a good idea in netif_carrier_[on,off], which are more than likely running in interrupt context.

Conceptually, I don't see (hot-plugging) a CAT-5 cable into a NIC to be that much different (from a userland view) to plugging the NIC into the PCI bus.

My big problem is that I am clueless, and call_usermode_helper isn't nice code. If someone in kernel-land could make call_usermode_helper safe in interrupt context, at least link-state reporting would be fairly trivial. It shouldn't be that hard - it's already using keventd. I just have no idea about clone_thread and stuff like that.

Brad

- --
http://conf.linux.org.au. 22-25Jan2003. Perth, Aust. Tickets booked. -----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.0.6 (GNU/Linux)
Comment: For info see http://www.gnupg.org

iD8DBQE9kOgDW6pHgIdAuOMRAqojAJ0aiXkHtK0eo6/1Bg+Yo8zSzBCMSQCfXK0x 5CSmDWhwRiamJwttaxF6Eac=
=hqKf
-----END PGP SIGNATURE-----

#12 lore raw

Re: alternate event logging proposal

Quoted 1 line · Brad Hards

I liked the /sbin/hotplug arrangement (aka call_usermode_helper). In fact, my plan was to add the call_usermode_helper call to the netif_carrier_[on,off] functions. Unfortuantely, I've been to too many of Rusty's talks, and know that calling a function that is only safe in user context is unlikely to be a good idea in netif_carrier_[on,off], which are more than likely running in interrupt context.

You really want something where a userspace app can sleep on an fd, to be awakened when link changes (or some other interesting event occurs)

Jeff

#13 lore raw

Re: alternate event logging proposal

Quoted 7 lines · Jeff Garzik
Quoted 1 line · Brad Hards

I liked the /sbin/hotplug arrangement (aka call_usermode_helper). In fact, my plan was to add the call_usermode_helper call to the netif_carrier_[on,off] functions. Unfortuantely, I've been to too many of Rusty's talks, and know that calling a function that is only safe in user context is unlikely to be a good idea in netif_carrier_[on,off], which are more than likely running in interrupt context.

You really want something where a userspace app can sleep on an fd, to be awakened when link changes (or some other interesting event occurs)

I tend to agree - I like either of the models:

a bunch of little single-value files that can be polled and read

or

a single device_event file that a daemon reads and dispatches events (I like this one because the daemon is already written, just poorly named - acpid)

For things like netif_carrier, poll() is probably best - the DHCP client can be fully self contained, and not need an eventd to alert it to a signal change. Of course, acpid does support UNIX socket connections from apps like DHCP....

Signature · 4 lines
Tim Hockin
Systems Software Engineer
Sun Microsystems, Linux Kernel Engineering
[email protected]
#14 lore raw

Re: alternate event logging proposal

Quoted 1 line · Tim Hockin

a single device_event file that a daemon reads and dispatches events (I like this one because the daemon is already written, just poorly named - acpid)

Couldn't you just have the message sent to every process that has opened the file (and have every interested process open the file and read it in a non-blocking or blocking mode?)

That seems to negate the need for something like acpid, but it does not preclude it's use.

Quoted 2 lines

For things like netif_carrier, poll() is probably best - the DHCP client can be fully self contained, and not need an eventd to alert it to a signal change. Of course, acpid does support UNIX socket connections from apps like DHCP....

I would prefer an event, and it can still be self contained if my idea above is actually workable.

Ben

Quoted 3 lines
Signature · 3 lines
Ben Greear <[email protected]>       <Ben_Greear AT excite.com>
President of Candela Technologies Inc      http://www.candelatech.com
ScryMUD:  http://scry.wanfear.com     http://scry.wanfear.com/~greear
#15 lore raw

Re: alternate event logging proposal

Quoted 7 lines
Quoted 3 lines

a single device_event file that a daemon reads and dispatches events (I like this one because the daemon is already written, just poorly named - acpid)

Couldn't you just have the message sent to every process that has opened the file (and have every interested process open the file and read it in a non-blocking or blocking mode?)

Sure, but then every process that is concerned with a single event has to not only receive every event, but parse every event. And if this is to be truly generic, that could be a lot of events.

Quoted 2 lines

That seems to negate the need for something like acpid, but it does not preclude it's use.

True, and if a dev_event file were created, I'd consider doing it that way. But in that case it's easier for apps to talk to eventd (nee acpid) and get only the messages they want.

Tim

#16 lore raw

Re: alternate event logging proposal

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

Quoted 11 lines · Tim Hockin
Quoted 7 lines
Quoted 3 lines

a single device_event file that a daemon reads and dispatches events (I like this one because the daemon is already written, just poorly named
- acpid)

Couldn't you just have the message sent to every process that has opened the file (and have every interested process open the file and read it in a non-blocking or blocking mode?)

Sure, but then every process that is concerned with a single event has to not only receive every event, but parse every event. And if this is to be truly generic, that could be a lot of events.

To what level would you see this going?
I'm currently doing some documentation work on the input subsystem, and it produces events (/dev/input/eventX) for every mouse movement, every key press (and release), etc. Now most of the application interested in those events will get them via X (we just need to interface the input subsystem event interface to the X event interface). I see this as a separate daemon or daemons.
Basically you get eventd on every system, and inputd for each console (in a multiheaded, multiuser setup).

Quoted 6 lines
Quoted 2 lines

That seems to negate the need for something like acpid, but it does not preclude it's use.

True, and if a dev_event file were created, I'd consider doing it that way. But in that case it's easier for apps to talk to eventd (nee acpid) and get only the messages they want.

I think that the eventd advantage is that it is easy to do integration with non-event aware apps. Example: eventd re-writes the config file and SIGHUPs the application.

Brad

- --
http://conf.linux.org.au. 22-25Jan2003. Perth, Aust. Tickets booked. -----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.0.6 (GNU/Linux)
Comment: For info see http://www.gnupg.org

iD8DBQE9kQ4NW6pHgIdAuOMRAtEyAKC2t5lKponBvUHH14bONYfjbSWFxgCeMh1O 9pjS0UjK627edrI8WJDBXp0=
=V0sd
-----END PGP SIGNATURE-----

#17 lore raw

Re: alternate event logging proposal

Quoted 1 line

To what level would you see this going?

Not sure - someone talked about receiving all sorts of device events. Certainly do-able, but it may be desirable to really limit the domain.

Quoted 3 lines

I'm currently doing some documentation work on the input subsystem, and it produces events (/dev/input/eventX) for every mouse movement, every key press (and release), etc. Now most of the application interested in those events

So I'd say this level of heavy traffic probably deserves it's own event mechanism that is more lightweight than eventd. The more generic it is, the more each event costs (currently O(n) - 1 regex comparison for each client/config). Putting high volume mouse/kb events would likely suck.

Quoted 7 lines
Quoted 3 lines

True, and if a dev_event file were created, I'd consider doing it that way. But in that case it's easier for apps to talk to eventd (nee acpid) and get only the messages they want.

I think that the eventd advantage is that it is easy to do integration with non-event aware apps. Example: eventd re-writes the config file and SIGHUPs the application.

This eventd I'm speaking of is what currently exists as acpid. It reads ACPI events and does just that - runs some user-defined handlers and alerts processes on a UNIX socket.

It does make it possible to do things like not modify DHCP client at all, and just thump it with a HUP. It also means everyone needs to be running eventd. And then you still have the 'need-an-edge' problem. If DHCP starts and hangs because it can't find the network (assume an unplugged NIC), nothing is going to come along and tell it there is no link because there was no edge.

By making something like (just for argument) /netdevfs/eth0/link, dhcp could read that, find a "0" and go to sleep on a poll() of that same fd. But you need to modify DHCP.

Advantages and disadvantages to all models. Which is why I brought it up for debate. IFF it is even attainable for 2.5.x. It certainly is for just netif style events. On a broader scope? Maybe not. Another drawback of the generic event file is that you now have a lot more people to please with a generic enough protocol.

Tim

#18 lore raw

Re: alternate event logging proposal

In reply to Jeff Garzik

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

Quoted 10 lines · Jeff Garzik
Quoted 6 lines · Brad Hards

I liked the /sbin/hotplug arrangement (aka call_usermode_helper). In fact, my plan was to add the call_usermode_helper call to the netif_carrier_[on,off] functions. Unfortuantely, I've been to too many of Rusty's talks, and know that calling a function that is only safe in user context is unlikely to be a good idea in netif_carrier_[on,off], which are more than likely running in interrupt context.

You really want something where a userspace app can sleep on an fd, to be awakened when link changes (or some other interesting event occurs)

Maybe - I've been thinking of a "hotplug" daemon, that can take notifications from the kernel _and_ from other userspace apps. The integrated solution somehow needs to incorporate device hotplugging (eg USB, PCI), network device events (netlink), userspace reconfiguration (eg X colour depth and resolution) and maybe network infrastructure (external to the machine, probably SLPv2 or similar), and reconfigure kernel and applications to match.

Brad
- --
http://conf.linux.org.au. 22-25Jan2003. Perth, Aust. Tickets booked. -----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.0.6 (GNU/Linux)
Comment: For info see http://www.gnupg.org

iD4DBQE9kPcwW6pHgIdAuOMRAoaDAJ9PnK962eJCuKdobU64SfY/2SRemQCYxSUS CfTiTN9hOq+gfldzcgDzCQ==
=bDjx
-----END PGP SIGNATURE-----

#19 lore raw

Re: alternate event logging proposal

Quoted 4 lines · Brad Hards
Quoted 2 lines

You really want something where a userspace app can sleep on an fd, to be awakened when link changes (or some other interesting event occurs)

Maybe - I've been thinking of a "hotplug" daemon, that can take notifications from the kernel _and_ from other userspace apps. The integrated solution somehow needs to incorporate device hotplugging (eg USB, PCI), network device events (netlink), userspace reconfiguration (eg X colour depth and resolution) and maybe network infrastructure (external to the machine, probably SLPv2 or similar), and reconfigure kernel and applications to match.

See my previous about acpid - it is capable of most of this. In short:

Open kernel event file
read config files: map regexes to actions
open a named UNIX socket
while 1

	wait for event or data on socket
	if it's an event {
		read event
		for each config'ed regex {
			if it matches this event
				run the associated action
		}
		for each UNIX connection {
			notify the connection of the event
		}
	} else if it's a connection on the socket {
		add the connection to the list of notifications
	}
}

Now it would be easy to make UNIX-connecting apps specify one or more regexes, instead of getting broadcasted. It would be similarly easy to make it read multiple sources and handle that - acpi, dev_events, user_events (UNIX socket or FIFO).

http://acpid.sourceforge.net - it's kind of stale, because it does everything it needs to do for now :) It's small, well tested and easy to understand. Best of all, it's already written.

Tim

Signature · 4 lines
Tim Hockin
Systems Software Engineer
Sun Microsystems, Linux Kernel Engineering
[email protected]
#20 lore raw

Re: alternate event logging proposal

In reply to Chris Friesen
Quoted 1 line · Chris Friesen

Also related is "how can userspace be notified of kernel events?". There is no way for a userspace app to be notified that, for instance, an ATM device got a loss of signal. The drivers print it out, but the userspace app has no clue.

(sorry for the second reply)

To address your more general point, a general way to notify interested, credentialed (is that a word?) 3rd party processes of device events would indeed be useful. Since such events are essential out-of-band info, netlink might indeed be applicable.

Jeff

#21 lore raw

Re: [evlog-dev] Re: alternate event logging proposal

Quoted 7 lines · Jeff Garzik
Quoted 4 lines · Chris Friesen

Also related is "how can userspace be notified of kernel events?". There is no way for a userspace app to be notified that, for instance, an ATM device got a loss of signal. The drivers print it out, but the userspace app has no clue.

Quoted 6 lines

(sorry for the second reply)

To address your more general point, a general way to notify interested, credentialed (is that a word?) 3rd party processes of device events would indeed be useful. Since such events are essential out-of-band info, netlink might indeed be applicable.

Event Logging has both a command and an API for apps in user-space to
register for specific events (kernel or userspace). The user must have
read access to the log file and the proper credentials in the allow/deny file scheme (that's modeled after crontab).

Larry Kessler
http://evlog.sourceforge.net/

#22 lore raw

Re: [evlog-dev] Re: alternate event logging proposal

Quoted 10 lines · Larry Kessler
Quoted 4 lines · Jeff Garzik

To address your more general point, a general way to notify interested, credentialed (is that a word?) 3rd party processes of device events would indeed be useful. Since such events are essential out-of-band info, netlink might indeed be applicable.

Event Logging has both a command and an API for apps in user-space to
register for specific events (kernel or userspace). The user must have
read access to the log file and the proper credentials in the allow/deny file scheme (that's modeled after crontab).

Ok. And? It sounds like event logging could possibly use netlink as the event delivery mechanism.

Jeff

#23 lore raw

Re: [evlog-dev] Re: alternate event logging proposal

Quoted 9 lines · Jeff Garzik
Quoted 7 lines · Larry Kessler
Quoted 4 lines · Jeff Garzik

To address your more general point, a general way to notify interested, credentialed (is that a word?) 3rd party processes of device events would indeed be useful. Since such events are essential out-of-band info, netlink might indeed be applicable.

Quoted 7 lines
Quoted 4 lines

Event Logging has both a command and an API for apps in user-space to
register for specific events (kernel or userspace). The user must have
read access to the log file and the proper credentials in the allow/deny file scheme (that's modeled after crontab).

Ok. And? It sounds like event logging could possibly use netlink as the event delivery mechanism.

Event logging uses real-time signaling to notify a process that's registered for notification that an event matching the criteria defined during registration has been written to the event log. When notified, the process can read the entire event from the event log and then do whatever.
.
It's intended to satisfys the requirement for a "general way to notify...processes". To read more, go to...
http://evlog.sourceforge.net/posix_evlog.html#_Toc525541312

#24 lore raw

Re: [evlog-dev] Re: alternate event logging proposal

Quoted 3 lines · Larry Kessler

Event logging uses real-time signaling to notify a process that's registered
for notification that an event matching the criteria defined during registration has been written to the event log. When notified, the process can read the entire event from the event log and then do whatever.

I've already seen the event logging userspace API, thanks.

Are you saying that netlink is not useful for event delivery inside the kernel? It seems useful to me. Are you saying that netlink is incompatible with the POSIX event logging interface? My initial thinking is that it seems compatible, just the syscalls[interface] is a bit different.

Both your messages simply described and re-described POSIX event logging, without actually responding to my suggestion. Are you just quoting specifications because you would rather not look into netlink and explore new options?

I would rather avoid the kernel bloat of two pieces of kernel code doing the pretty much the same thing internally.

Jeff

#25 lore raw

Re: [evlog-dev] Re: alternate event logging proposal

Quoted 2 lines · Jeff Garzik

I've already seen the event logging userspace API, thanks.

You're welcome.

Quoted 5 lines

Are you saying that netlink is not useful for event delivery inside the kernel? It seems useful to me. Are you saying that netlink is incompatible with the POSIX event logging interface? My initial thinking is that it seems compatible, just the syscalls[interface] is a bit different.

Yes, the evlogd daemon could use netlink to capture in-kernel events, as you are suggesting, but we chose a more general approach where events written with native evlog functions (like problem() ;-) as well as "forwarded printks" (which was not included in yesterday's patches for sake of brevity ;-) are queued in an in-kernel event buffer. Don't worry, except for an added function call, printk is otherwise unchanged when CONFIG_EVLOG is defined.

The evlogd daemon then calls do_syslog() to read events from the in-kernel buffer, write them into an event log, generates event notification, etc. So unlike netlink, setting up event notification is stictly done in userspace. Also, the notification mechanism works for userspace events as well as kernel events.

Now, at the risk of diverting attention away from the problem()
macros proposal, we've also been prototyping an enhancement to
the "printk forwarding", which is nearly identical to what you've
proposed...
the format string (verbatim), and 0 or more argument values,
along with the return address of the calling fucnction, is captured
in the event record (instead of just storing the pre-formatted printk
in the event record, like we do now). Re-combining fragmented printks (since multiple printks are non-atomic) is done by the evlogd.

By keeping the format strings verbatim in the event records, you could do translations in user-space, and possibly even fabricate argument tags after-the-fact. Some prototyping to munge the printk event records in userspace is being worked, but its technical feasibility still remains to be proven.

Quoted 18 lines

Now, turning to a tangent topic that relates to either scheme...

With either your proposal or mine, event logging is far more useful if similar drivers spit out similar diagnostics. i.e. it's less useful if 8139too net driver spits out 'status16' in one interrupt event, and 8139cp net driver spits out 'status32' in another. Though they are different hardware and the values mean different things, my point is the concepts are similar, and thus better diagnostics are achieved with subsystem diagnostic standards.

Such standards are in actuality independent of event logging per se, but if IBM wants to push this thing, I would like to see some proposals as to what IBM actually wants drivers to log. I have not seen that at all, and think that such proposals should be an integral part of an event logging system. Otherwise the diagnostics are less useful, and IBM would have failed to demonstrate an adequate grasp of the problem domain [which then leads to other, typical software engineering problems...]

Quoted 2 lines

"What do you want to log?" is as important to me as "how do you want to log it?" And the answers to the two questions are very much intertwined.

Yes, agreed. But, once we've all agreed on WHAT to log
(and achieved world peace), we're still left with the question of "what is/are the best logging interface(s) to use ?" As long as we've acknowledged the need to do better logging, why not re-engineer the logging interface before developers start re-instrumenting their device drivers ?

The verdict is still out, but with some more tweaking and tuning I think that "problem()" has advantages over printk, perhaps not so much for developers, but for anyone who has to interpret and act upon information being logged in the kernel. I won't elaborate on the disadvantages...you've already done a throrugh job of that :-), just as Rusty has done a good job elaborating on the advantages.

...

#26 lore raw

Re: [evlog-dev] Re: alternate event logging proposal

In reply to Larry Kessler

Larry Kessler <[email protected]> said:

[...]

Quoted 4 lines

Event logging uses real-time signaling to notify a process that's registered for notification that an event matching the criteria defined during registration has been written to the event log. When notified, the process can read the entire event from the event log and then do whatever.

How is said event found? By scanning the whole log?

Signature · 4 lines
Dr. Horst H. von Brand                   User #22616 counter.li.org
Departamento de Informatica                     Fono: +56 32 654431
Universidad Tecnica Federico Santa Maria              +56 32 654239
Casilla 110-V, Valparaiso, Chile                Fax:  +56 32 797513
#27 lore raw

Re: [evlog-dev] Re: alternate event logging proposal

Quoted 11 lines · Horst von Brand

Larry Kessler <[email protected]> said:

[...]

Quoted 4 lines

Event logging uses real-time signaling to notify a process that's registered for notification that an event matching the criteria defined during registration has been written to the event log. When notified, the process can read the entire event from the event log and then do whatever.

How is said event found? By scanning the whole log?

No, the record id of the associated event is obtained by calling a function after your process is notified. See link in previous note for full API descriptions.

#28 lore raw

Re: alternate event logging proposal

In reply to Chris Friesen

On 2002-09-24T15:57:36,
Chris Friesen <[email protected]> said:

I have cut the Cc/To list severely. Couldn't stand it.

Quoted 6 lines
Quoted 2 lines

"What do you want to log?" is as important to me as "how do you want to log it?" And the answers to the two questions are very much intertwined.

Also related is "how can userspace be notified of kernel events?". There is no way for a userspace app to be notified that, for instance, an ATM device got a loss of signal. The drivers print it out, but the userspace app has no clue.

This is a very generic problem. For example, the Open Clustering Framework also has a lots of events going back and forth - node membership changes, distributed locks gained or lost, messages pending etc.

The interesting issue here is that the provider or consumer may be implemented in kernel or user space depending on the task and the given implementation; ie, what we would ideally need is a common coherent infrastructure for event distribution on Linux, as I expect this to be a common task for many scenarios.

Joe DiMartino of OSDL has developed a very nice Event API (I think) for user-space (a fixed version with some updates we agreed upon in the last two weeks is pending), and we are currently evaluating how to interface with the kernel space.

It would be _very nice_ if someone would pick up the lead wrt to "Event Processing", so that work is not duplicated between so many (already overloaded) groups.

Just my few euro-cents.

Sincerely,
Lars Marowsky-Brée <[email protected]>

Signature · 5 lines
Principal Squirrel
Research and Development, SuSE Linux AG
 
``Immortality is an adequate definition of high availability for me.''
	--- Gregory F. Pfister
#29 lore raw

Re: [evlog-dev] alternate event logging proposal

In reply to Jeff Garzik

On Tuesday 24 September 2002 12:48 pm, Jeff Garzik wrote:

[snip)

Quoted 18 lines

Now, turning to a tangent topic that relates to either scheme...

With either your proposal or mine, event logging is far more useful if similar drivers spit out similar diagnostics. i.e. it's less useful if 8139too net driver spits out 'status16' in one interrupt event, and 8139cp net driver spits out 'status32' in another. Though they are different hardware and the values mean different things, my point is the concepts are similar, and thus better diagnostics are achieved with subsystem diagnostic standards.

Such standards are in actuality independent of event logging per se, but if IBM wants to push this thing, I would like to see some proposals as to what IBM actually wants drivers to log. I have not seen that at all, and think that such proposals should be an integral part of an event logging system. Otherwise the diagnostics are less useful, and IBM would have failed to demonstrate an adequate grasp of the problem domain [which then leads to other, typical software engineering problems...]

Quoted 4 lines

"What do you want to log?" is as important to me as "how do you want to log it?" And the answers to the two questions are very much intertwined.

Comments?

I agree with you that there needs to be a strategy for what is logged by a driver and how it is logged. We believe log analysis is an essential part of diagnosing errors. Log messages, when generated consistently, could indicate what drivers were loaded, when they were loaded, what their current version is, and what errors they have encountered. How the messages are formatted, whether they follow certain rules, can greatly aid User Space diagnostic applications.

We propose standardizing what should be logged and how those log messages should look.

What:

- Drivers should log initialization and uninitialization information for both drivers and devices. Knowning when a driver is loaded or unloaded is useful information.

- Initialization information should include name of the device, name of the driver, and the current version or release levels. Any errors encountered during initialization - e.g. from running self tests - should be properly logged.

- Errors during operation should be logged.

How:

- Messages should be human readable.

- Messages should be succinct.

- Messages should uniquely identify the driver and the device, such as many drivers already do by prefixing messages with the driver name.

- Beware of log pollution - log only relevant information. Avoid frequently recurring messages.

- Use defined severity levels.

- Make sure that consitent logging and terminology is used throughout the driver.

Most of what I just outlined is common sense, but it's worth stating.

Any comments?

Dan

Quoted 14 lines

Jeff

-------------------------------------------------------
This sf.net email is sponsored by:ThinkGeek
Welcome to geek heaven.
http://thinkgeek.com/sf
_______________________________________________
evlog-developers mailing list
[email protected]
https://lists.sourceforge.net/lists/listinfo/evlog-developers

#30 lore raw

Re: [evlog-dev] alternate event logging proposal

Quoted 3 lines · Daniel E. F. Stekloff

I agree with you that there needs to be a strategy for what is logged by a driver and how it is logged. We believe log analysis is an essential part of diagnosing errors. Log messages, when generated consistently, could indicate what drivers were loaded, when they were loaded, what their current version is, and what errors they have encountered. How the messages are formatted, whether they follow certain rules, can greatly aid User Space diagnostic applications.

We propose standardizing what should be logged and how those log messages should look.

[snip]

Quoted 1 line

Any comments?

I agree with the generalities... I am looking for something far more specific, though.

My point in the second half of my proposal message was trying to drive home the point that IBM doesn't appear to know, at this time, what the diagnostic messages the 8139too net driver should output. Or the aic7xxxx scsi driver. Or the piix ATA driver.

And until IBM knows those things, I cannot see how any proposal can be put forward. _what data_ should be logged? "useful data" is not an answer. "eeprom checksum failure, with failed checksum value" is an answer. If IBM does not know these things, it is putting forward a solution when the problem has not clearly been examined or even defined.

I want all my net drivers to log useful data. I also want world peace.
The devil is in the details.

Jeff

#31 lore raw

Re: [evlog-dev] alternate event logging proposal

In reply to Daniel E. F. Stekloff

Hi!

Quoted 3 lines

- Drivers should log initialization and uninitialization information for both drivers and devices. Knowning when a driver is loaded or unloaded is useful information.

[snip]

Quoted 2 lines

- Beware of log pollution - log only relevant information. Avoid frequently recurring messages.

You should not report *driver* initialization but only hardware one, or you are going to overrun dmesg very fast (log pollution).

Driver version is useless -- you already know what kernel you are booting -- right?
Pavel

Signature · 1 line
When do you have heart between your knees?