Re: [RFC][PATCH] New message-logging API (kprint)

Previous thread: [PATCH 2/2] Version 5 (2.6.23-rc8-mm2) Smack: Simplified Mandatory Access Control Kernel by Casey Schaufler on Thursday, October 4, 2007 - 11:23 am. (1 message)

Next thread: pm qos infrastructure and interface by Mark Gross on Thursday, October 4, 2007 - 2:51 pm. (4 messages)
From: Vegard Nossum
Date: Thursday, October 4, 2007 - 1:04 pm

Description: This patch largely implements the kprint API as previously
posted to the LKML and described in Documentation/kprint.txt (see patch).

The main purpose of this change is provide a unified logging API to the
kernel and at the same time make it easy to add extensions, now and later.

My changes and additions are as follows:

1. A general-purpose ring-buffer data structure. This is used by kprint to
   store the messages, similarly to what printk() does. I've looked, but
   couldn't find something like this in the kernel already.

2. A generalized printf()-like function (currently called by the somewhat
   confusing name of args_printf). The function, instead of writing to a
   string, calls one of several functions submitted through a struct args_ops.

   This allows us to skip all the characters from the format string and only
   output the characters resulting from argument conversion.

   It should be noted that this function is a generalization of, and largely
   copies, the existing snprintf() function. It would be possible to implement
   snprintf() in terms of the new function if that is preferred.

3. kprint header and source files. These files implements separating the
   format string from its arguments, and saving them along with extension-
   specific attributes (for example the current time) to the log.

4. A redefinition of the legacy printk(). The new definition redirects calls
   made from C to the new kprint() system in a mostly backwards-compatible
   way. The incompatibility stems from the fact that kprint() does not return
   the number of characters written to the log. There are several reasons for
   this; firstly, in order to filter out certain log-levels, the actual call
   must happen from within an if-block, and thus no value can be returned.

5. Changes to calls in the rest of the kernel that expects kprint() to return
   a value. These changes are few and mostly trivial. One of the pitfalls of
   actually using the return value of ...
From: Randy Dunlap
Date: Thursday, October 4, 2007 - 1:17 pm

$ diffstat -p1 -w70 kprint.patch 
 Documentation/kprint.txt                 |  238 ++++++++++++++
 arch/i386/kernel/traps.c                 |    2 
 arch/um/include/user.h                   |    6 
 crypto/tcrypt.c                          |    5 
 drivers/char/mem.c                       |   10 
 drivers/ide/ide-lib.c                    |    3 
 drivers/md/md.c                          |    5 
 drivers/media/dvb/frontends/tda10021.c   |   13 
 drivers/media/dvb/frontends/tda10023.c   |   13 
 drivers/media/dvb/frontends/ves1820.c    |    9 
 drivers/media/video/em28xx/em28xx-core.c |   16 
 drivers/media/video/usbvideo/usbvideo.h  |    7 
 drivers/net/e100.c                       |   10 
 drivers/net/e1000/e1000.h                |   12 
 drivers/net/irda/ma600.c                 |    5 
 drivers/net/ixgb/ixgb.h                  |   11 
 drivers/net/lib8390.c                    |   17 -
 drivers/net/pcmcia/axnet_cs.c            |   12 
 drivers/pcmcia/rsrc_nonstatic.c          |   10 
 drivers/scsi/advansys.c                  |    2 
 include/asm-generic/pgtable-nopmd.h      |    5 
 include/asm-generic/pgtable-nopud.h      |    5 
 include/linux/args.h                     |   29 +
 include/linux/kernel.h                   |   27 +
 include/linux/kprint-light.h             |   25 +
 include/linux/kprint.h                   |  201 ++++++++++++
 include/linux/ringbuffer.h               |   34 ++
 include/net/sctp/sctp.h                  |    6 
 include/scsi/scsi_device.h               |   14 
 include/scsi/sd.h                        |   13 
 init/Kconfig                             |    2 
 init/do_mounts_initrd.c                  |    2 
 kernel/Kconfig.kprint                    |  125 +++++++
 kernel/Makefile                          |    2 
 kernel/kprint.c                          |  345 +++++++++++++++++++++
 kernel/printk.c                          |    9 
 lib/Makefile                             |    3 
 lib/ringbuffer.c                         |  155 ...
From: Rob Landley
Date: Thursday, October 4, 2007 - 6:59 pm

I started this thread by posting an idea I had for shrinking the kernel by 
allowing more code to be configured out.  The API change was exactly one new 
parameter, with a direct 1->1 mapping from the old API to the new one, which 
was trivial to convert and which the compiler would catch if you missed one.

The result of the discussion is a patch adding 1600 lines to the kernel, 
without removing anything.

Last I checked, the current prink() worked just fine.  Why is this _not_ the 
dreaded "infrastructure in search of a use"?  What exactly can we _not_ do 
with the current code?  What does this allow us to remove and simplify?

I'm confused about what people are trying to accomplish here...

Rob
-- 
"One of my most productive days was throwing away 1000 lines of code."
  - Ken Thompson.
-

From: Miguel Ojeda
Date: Friday, October 5, 2007 - 12:01 am

I think we all are trying to give ideas to improve the current logging API.

If something works, it's great; but it doesn't mean that it can't be
improved, right?

-- 
Miguel Ojeda
http://maxextreme.googlepages.com/index.htm
-

From: Rob Landley
Date: Friday, October 5, 2007 - 9:26 am

I'm all for improving the kernel, but my definition of "improved" does not 
include every possible change.  I balance "smaller and simpler" with "more 
features".  Complexity is a cost, we should get something in return.

Making the same functionality simpler makes it "cheaper" from a development 
standpoint.  Smaller and simpler means less overhead, less to understand, 
less to go wrong.  It's also attractive to me personally, because I am a Bear 
of Very Little Brain and between the dozen or so projects I try to follow, I 
have trouble fitting all the details in my head when they're tricky or they 
change ever time I look at them.  (Especially when I get distracted from one 
of those projects for 3-6 months and come back to find it changed.)

I recognize constantly having to learn new things as part of the cost of 
living, and making things more complicated happens as you add features.  But 
when somebody reinvents the wheel it's really nice to have clearly spelled 
out the advantages of the new wheel vs the old one.  It's nice for there to 
_be_ clear advantages, offsetting the increased complexity cost.

In this case, upon asking, the only potential advantage here seems to be "now 
we can translate dmesg output into Chinese more easily", which is something 
you could already do in userspace already via regular expressions in a 
translating dmesg, and which has the primary effect of making the resulting 
dmesg useless to report to lkml without really improving the amount of sense 
it makes to nontechnical end users (who really aren't the target of the 
english dmesg output, either).  The "linux developer who can't read english" 
niche is inherently somewhat problematic, as has been discussed here before.

The cost of this patch is making the kernel bigger, the in-kernel printk api 
more complicated, and the userspace dmesg noticeably more complex just to 
implement the same functionality against the new API.  Documenting the 
changes is nice, but doesn't reduce this increase ...
From: Miguel Ojeda
Date: Friday, October 5, 2007 - 4:01 pm

I fully agree. However, I just gave away some ideas that I believe
they can make printk() easier and more understandable than it is right
now (for example, standardizing kprint_[registered,detected,...]
messages is something that I think it can simplify everyday use of
messages, both to people who has to code it, review/search the code

I got your point, and I agree. However, I also see the possibilities
that a change of the logging API can bring: If someday it gets
improved, maybe such day should be improved as far as possible. This
kind of stuff that affect so many things are not going to change for
long periods of time, as you said.

Still, I know some kind of changes can be really complex and maybe are
unproductive. I think the point is to get a middle point between new


I didn't talk about internationalization (in fact, I think it is going
to be pretty complex to get it right and, worse, to get it up-to-date

Take a look to other suggested changes, maybe you like some of them

-- 
Miguel Ojeda
http://maxextreme.googlepages.com/index.htm
-

From: Stephen Hemminger
Date: Friday, October 5, 2007 - 5:34 pm

On Sat, 6 Oct 2007 01:01:10 +0200


The beauty of printk is it's current simplicity.  And even with that developers
get it wrong.  The changes seem like added complexity with little real gain.

Plus none of the changes address the issue of getting better information.
The kernel is already so noisy that most distributions boot with the quiet


-- 
Stephen Hemminger <shemminger@linux-foundation.org>
-

From: Miguel Ojeda
Date: Sunday, October 7, 2007 - 3:20 am

I agree. On the one hand, some changes are complex (like "blocks"
implementation) and maybe they will not help at all. I'm not agreeing
with every change :)

On the other hand, the new tags (more standarized messages and
simplified code) and all the information given by the new syslog
retrieved from userspace (formatted messages => better information
possibly) can do a lot of good (and maybe even more in the future,
with a lot more stuff inside the kernel), without creating noise at
boot at all. That kind of changes I think they would do more good than
bad.

-- 
Miguel Ojeda
http://maxextreme.googlepages.com/index.htm
-

From: Rob Landley
Date: Sunday, October 7, 2007 - 2:56 pm

Is there any way to serialize the changes?  It's hard to review a big lump.

Rob
-- 
"One of my most productive days was throwing away 1000 lines of code."
  - Ken Thompson.
-

From: Randy Dunlap
Date: Sunday, October 7, 2007 - 3:32 pm

There are also parts of the patch that could be submitted
independently of any message-logging API changes.

---
~Randy
-

From: Vegard Nossum
Date: Friday, October 5, 2007 - 11:10 pm

This is wrong. The patch provides log-level-based filtering at compile

I agree; you are right about the other things, Maybe I can try to fit
some of these things into printk itself (thanks for the tip, Alan),
and we'll see how far we can get.

Thanks.

Vegard
-

From: Rob Landley
Date: Sunday, October 7, 2007 - 2:50 pm

I made it about halfway through the patch and the only compile time filtering 
I found was:

--- a/drivers/md/md.c
+++ b/drivers/md/md.c
@@ -62,7 +62,10 @@
 #define MdpMinorShift 6
 
 #define DEBUG 0
-#define dprintk(x...) ((void)(DEBUG && printk(x)))
+#define dprintk(x...)          \
+       if(DEBUG) {             \
+                printk(x);     \
+       }

If you say it does, I'll take your word for it, but there's so much churn in 
there I didn't find it before my interest ran out...

Rob
-- 
"One of my most productive days was throwing away 1000 lines of code."
  - Ken Thompson.
-

From: Stephen Hemminger
Date: Monday, October 8, 2007 - 8:25 am

On Sun, 7 Oct 2007 16:50:49 -0500

BTW that change might actually break code (dangling else problems).  
The original way was safer.

-- 
Stephen Hemminger <shemminger@linux-foundation.org>
-

From: Vegard Nossum
Date: Monday, October 8, 2007 - 8:33 am

Yep, thanks. I think containing it in do {} while(0) should fix, though, no?

Vegard
-

From: Stephen Hemminger
Date: Monday, October 8, 2007 - 8:42 am

On Mon, 8 Oct 2007 17:33:53 +0200

The correct fix is to just replace dprintk() with pr_debug()

-- 
Stephen Hemminger <shemminger@linux-foundation.org>
-

From: Vegard Nossum
Date: Friday, October 5, 2007 - 6:13 am

Of course. If you look at the diffstat, as kindly posted by Randy,
you'll notice that about 500-600 of those lines are documentation,
configuration files, and headers.

What's really a concern (and a valid argument) is the overhead
introduced for each call to printk(); the defconfig kernel on x86

With the current code, localisation is not possible to do in a sane
way. My change is a "catch all" in desired features -- not just
removing some unwanted printks.


Vegard
-

From: Rob Landley
Date: Friday, October 5, 2007 - 9:05 am

Yay documentation, and I read it, but it's still adding complexity:

  > 6. Calling syslog (in glibc, klogctl()) with a (type|0x10) will access the
  >    new kprint buffer instead of the regular log buffer. The kprint buffer
  >    is different in that it doesn't record the actual formatted message,
  >    but the format string and the (formatted) arguments. Example:

This adds a new buffer in parallel with the old buffer.  The new one is 
significantly more complex to use from userspace, and has no advantages for 
the _current_ uses of it, therefore the old one will never _stop_ being used, 
and thus can probably never be removed.


Run dmesg through a filter in userspace using lots of regular expressions.  
Your average perl junkie could knock out a basic prototype in 20 minutes.

This also gives you the option of _not_ using the filter to get the raw dmesg 
output in english, which is the only thing this list can diagnose.

If you think that's going to break when kernel guys change the code each 

That's a good thing?  It's infrastructure in search of a use, implementing 
things that might, at some future date, be interesting, and complicating the 
code to do it in both the kernel and userspace.

I'm missing the "advantage" part.  I'm not close to perfect so I could just be 

Rob
-- 
"One of my most productive days was throwing away 1000 lines of code."
  - Ken Thompson.
-

From: Alan Cox
Date: Friday, October 5, 2007 - 10:01 am

He did say "sane".

Good internationalisation requires you know where the messages are and
where the substitutions (%foo) are. So the entire operation would in fact
require

1.	An option to set "translation friendly please"

2.	A tiny modification to the snprintfoo code to support putting
some kind of marker before/after arguments and maybe doubling a symbol to
avoid vagueness

The submission is overkill compared to what is required for translation
tools and syslog.

Alan
-

Previous thread: [PATCH 2/2] Version 5 (2.6.23-rc8-mm2) Smack: Simplified Mandatory Access Control Kernel by Casey Schaufler on Thursday, October 4, 2007 - 11:23 am. (1 message)

Next thread: pm qos infrastructure and interface by Mark Gross on Thursday, October 4, 2007 - 2:51 pm. (4 messages)