Re: [RFC] New kernel-message logging API (take 2)
On 9/28/07, Rob Landley <[EMAIL PROTECTED]> wrote: > On Friday 28 September 2007 7:11:03 am Vegard Nossum wrote: > > wrong. We can, however, use KBUILD_MODNAME as a default value for > > KPRINT_DRIVER, like: > > static const char *KPRINT_DRIVER = KBUILD_MODNAME; > > which would pre-process to something like: > > static const char *KPRINT_DRIVER = "bcm43xx"; > > Which has been known to result in the string getting written out to the .o > file even if it's never used, just in case something tries to take its > address. This is not the same as a #define. Logic tells me that an unused static variable should never go into the .o. If something tries to take its address, it's no longer unused. > > This value can still be overridden using #define KPRINT_DRIVER "new > > name". > > Not with -D on the command line though. Your #define would have to come after > the declaration or else the declaration turns into 'char *"fred" = "george";' > and you have a syntax error. Again, not synonymous with a #define... Yeah, that's exactly what my e-mail was about. The macros KPRINT_SUBSYSTEM and KPRINT_DRIVER are not defined on the command line, but in each source file that wants this prefix, after the variables with the same names have been declared in kprint.h. This is intentional; they can be overridden with a define, otherwise, they'll default to static-const string variables. Vegard - To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to [EMAIL PROTECTED] More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
Re: [RFC] New kernel-message logging API (take 2)
On Friday 28 September 2007 7:11:03 am Vegard Nossum wrote: > wrong. We can, however, use KBUILD_MODNAME as a default value for > KPRINT_DRIVER, like: > static const char *KPRINT_DRIVER = KBUILD_MODNAME; > which would pre-process to something like: > static const char *KPRINT_DRIVER = "bcm43xx"; Which has been known to result in the string getting written out to the .o file even if it's never used, just in case something tries to take its address. This is not the same as a #define. > This value can still be overridden using #define KPRINT_DRIVER "new > name". Not with -D on the command line though. Your #define would have to come after the declaration or else the declaration turns into 'char *"fred" = "george";' and you have a syntax error. Again, not synonymous with a #define... Rob -- "One of my most productive days was throwing away 1000 lines of code." - Ken Thompson. - To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to [EMAIL PROTECTED] More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
Re: [RFC] New kernel-message logging API (take 2)
On 9/28/07, Vegard Nossum <[EMAIL PROTECTED]> wrote: > On 9/28/07, Miguel Ojeda <[EMAIL PROTECTED]> wrote: > > On 9/28/07, Vegard Nossum <[EMAIL PROTECTED]> wrote: > > > reason we can't use KBUILD_MODNAME is that this is defined on the > > > command line. The declaration inside the header would thus be horribly > > > wrong. We can, however, use KBUILD_MODNAME as a default value for > > > KPRINT_DRIVER, like: > > > static const char *KPRINT_DRIVER = KBUILD_MODNAME; > > > which would pre-process to something like: > > > static const char *KPRINT_DRIVER = "bcm43xx"; > > > > > > This value can still be overridden using #define KPRINT_DRIVER "new > > > name". In this case, it is possible that the original KPRINT_DRIVER > > > symbol can cause an "unused variable"-warning. I guess this is fixable > > > with the gcc "unused" variable attribute. > > > > Yep, then, in a year or two, we will be able to delete such attribute. > > Actually, no, since it will throw a warning only if a source file > #defines KPRINT_SUBSYSTEM (i.e. overrides the constant variable > (oxymoron!) with the same name). What you're hoping is that some time > in the future, EVERY source file will come equipped with these > definitions, and yes, at that point, the entire declaration can be > removed, BUT I think that's... well. Yes. Yes, that was my point. Far far far away, but possible, and if this RFC ever meets the real kernel, then bringing every source file to the API should be a objective. A good project for kernel janitors, for example. > > > Will there be a team to change main subsystems/drivers to the new API? > > No. First of all, this is a specification draft; there is no code yet. > Also, very possibly, this is such a violent change that nobody really > wants to use it anyway. But we can hope. ;-) Sure, this is speculation. :) > > Vegard > -- Miguel Ojeda http://maxextreme.googlepages.com/index.htm - To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to [EMAIL PROTECTED] More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
Re: [RFC] New kernel-message logging API (take 2)
On 9/28/07, Miguel Ojeda <[EMAIL PROTECTED]> wrote: > On 9/28/07, Vegard Nossum <[EMAIL PROTECTED]> wrote: > > reason we can't use KBUILD_MODNAME is that this is defined on the > > command line. The declaration inside the header would thus be horribly > > wrong. We can, however, use KBUILD_MODNAME as a default value for > > KPRINT_DRIVER, like: > > static const char *KPRINT_DRIVER = KBUILD_MODNAME; > > which would pre-process to something like: > > static const char *KPRINT_DRIVER = "bcm43xx"; > > > > This value can still be overridden using #define KPRINT_DRIVER "new > > name". In this case, it is possible that the original KPRINT_DRIVER > > symbol can cause an "unused variable"-warning. I guess this is fixable > > with the gcc "unused" variable attribute. > > Yep, then, in a year or two, we will be able to delete such attribute. Actually, no, since it will throw a warning only if a source file #defines KPRINT_SUBSYSTEM (i.e. overrides the constant variable (oxymoron!) with the same name). What you're hoping is that some time in the future, EVERY source file will come equipped with these definitions, and yes, at that point, the entire declaration can be removed, BUT I think that's... well. Yes. > Will there be a team to change main subsystems/drivers to the new API? No. First of all, this is a specification draft; there is no code yet. Also, very possibly, this is such a violent change that nobody really wants to use it anyway. But we can hope. ;-) Vegard - To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to [EMAIL PROTECTED] More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
Re: [RFC] New kernel-message logging API (take 2)
On 9/28/07, Vegard Nossum <[EMAIL PROTECTED]> wrote: > On 9/27/07, Vegard Nossum <[EMAIL PROTECTED]> wrote: > > * Use SUBSYSTEM and KBUILD_MODNAME > > snip. > > > 2.1.5. Subsystem/driver tags > > > > Many parts of the kernel already prefix their log messages with a > > subsystem and/or driver tag to identify the source of a particular > > message. With the kprint interface, these tags are redundant. Instead, > > the macros SUBSYSTEM and KBUILD_MODNAME are used and recorded along > > with each log message. Therefore, each source file should define the > > macro SUBSYSTEM before any of the kprint functions are used. If this > > macro is not defined, the recorded subsystem will be an empty string. > > [6][7] > > This changes to KPRINT_SUBSYSTEM and KPRINT_DRIVER. The KPRINT_ prefix > is to clearly say that this is something related to logging. The Nice. Although the word "DRIVER" may not represent every module, I think it is the correct option as I suggested, as the word is meaningful (speaks by itself) and almost every message in the kernel is printed out by drivers (whatever the big subsystem they belong to: drivers/, fs/, net/ ...). > reason we can't use KBUILD_MODNAME is that this is defined on the > command line. The declaration inside the header would thus be horribly > wrong. We can, however, use KBUILD_MODNAME as a default value for > KPRINT_DRIVER, like: > static const char *KPRINT_DRIVER = KBUILD_MODNAME; > which would pre-process to something like: > static const char *KPRINT_DRIVER = "bcm43xx"; > > This value can still be overridden using #define KPRINT_DRIVER "new > name". In this case, it is possible that the original KPRINT_DRIVER > symbol can cause an "unused variable"-warning. I guess this is fixable > with the gcc "unused" variable attribute. Yep, then, in a year or two, we will be able to delete such attribute. Will there be a team to change main subsystems/drivers to the new API? -- Miguel Ojeda http://maxextreme.googlepages.com/index.htm - To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to [EMAIL PROTECTED] More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
Re: [RFC] New kernel-message logging API (take 2)
On 9/27/07, Vegard Nossum <[EMAIL PROTECTED]> wrote: > * Use SUBSYSTEM and KBUILD_MODNAME snip. > 2.1.5. Subsystem/driver tags > > Many parts of the kernel already prefix their log messages with a > subsystem and/or driver tag to identify the source of a particular > message. With the kprint interface, these tags are redundant. Instead, > the macros SUBSYSTEM and KBUILD_MODNAME are used and recorded along > with each log message. Therefore, each source file should define the > macro SUBSYSTEM before any of the kprint functions are used. If this > macro is not defined, the recorded subsystem will be an empty string. > [6][7] This changes to KPRINT_SUBSYSTEM and KPRINT_DRIVER. The KPRINT_ prefix is to clearly say that this is something related to logging. The reason we can't use KBUILD_MODNAME is that this is defined on the command line. The declaration inside the header would thus be horribly wrong. We can, however, use KBUILD_MODNAME as a default value for KPRINT_DRIVER, like: static const char *KPRINT_DRIVER = KBUILD_MODNAME; which would pre-process to something like: static const char *KPRINT_DRIVER = "bcm43xx"; This value can still be overridden using #define KPRINT_DRIVER "new name". In this case, it is possible that the original KPRINT_DRIVER symbol can cause an "unused variable"-warning. I guess this is fixable with the gcc "unused" variable attribute. Vegard - To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to [EMAIL PROTECTED] More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
Re: [RFC] New kernel-message logging API (take 2)
On 9/28/07, Jan Engelhardt <[EMAIL PROTECTED]> wrote: > > On Sep 27 2007 23:18, Vegard Nossum wrote: > > * kprint_() is better than kprint( >case of the default log-level, the argument can be omitted. > > * Memory allocated for entries and arguments is done in a ring-buffer > >with variable-sized chunks. Arguments are chained with a singly- > >linked list. > > * Use SUBSYSTEM and KBUILD_MODNAME > > * Rename kprint buffers to kprint blocks > > This is overall, quite a lot. I suggest one-thing-at-a-time, > starting with kprint_() that is compiled out if desired > and no fancy block or newline stuff. > > _Then_, will see how it flies. All of this smells like a bit of > overdesigning, aka http://en.wikipedia.org/wiki/YAGNI Well, that's why I'm writing it down before actually coding it. Designing is also trying to make things fit together without actually having the physical parts at hand. So I'm trying to make an interface that CAN support multi-line blocks in the future, since it's obviously a desired (and currently missing) feature. But I agree; It *is* hard to see how multi-line blocks can be implemented without actually spelling it out in code. I've tried to do it, and failed. Until a brilliant solution comes up, I'll skip it. Vegard - To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to [EMAIL PROTECTED] More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
Re: [RFC] New kernel-message logging API (take 2)
On 9/28/07, Kyle Moffett <[EMAIL PROTECTED]> wrote:
> On Sep 28, 2007, at 03:31:11, Geert Uytterhoeven wrote:
> > Can't you store the loglevel in the kprint_block and check it in
> > all successive kprint_*() macros? If gcc knows it's constant, it
> > can optimize the non-wanted code away. As other fields in struct
> > kprint_block cannot be constant (they store internal state), you
> > have to split it like:
> >
> > struct kprint_block {
> > int loglevel;
> > struct real_kprint_block real; /* internal state */
> > }
> >
> > and pass () instead of to all successive internal
> > functions. I haven't tried this, so let's hope gcc is actually
> > smart enough...
>
> Well actually, I believe you could just do:
>
> struct kprint_block {
> const int loglevel;
> [...];
> };
>
> Then cast away the constness to actually set it initially:
> *((int *)) = LOGLEVEL;
This doesn't seem to work either (i.e. it is not optimized out). I
tried initializing the struct statically too, to no avail. But thanks
for the tip.
Vegard
-
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to [EMAIL PROTECTED]
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
Re: [RFC] New kernel-message logging API (take 2)
> If-blocks spanning macros are really dangerous!
>
> E.g. an Ethernet driver may want to do:
>
> kprint_block(, "MAC ");
> for (i = 0; i < 6; i++) {
> card->mac[i] = obtain_mac_byte_from_hw(i);
> kprint_block(, "%02x", card->mac[i]);
> }
>
> This looks (and should be) innocent, but the actual MAC addres retrieval
> would never be executed if loglevel <= CONFIG_KPRINT_LOGLEVEL_MAX.
Yup. Okay, so it's definitely NOT an option.
> Can't you store the loglevel in the kprint_block and check it in all
> successive kprint_*() macros? If gcc knows it's constant, it can optimize
> the non-wanted code away. As other fields in struct kprint_block cannot be
> constant (they store internal state), you have to split it like:
>
> struct kprint_block {
> int loglevel;
> struct real_kprint_block real; /* internal state */
> }
>
> and pass () instead of to all successive internal functions.
> I haven't tried this, so let's hope gcc is actually smart enough...
It isn't, apparently. Or not with my test, anyway. Either way, it's
probably better not to make those assumptions about or rely too much
on the smartness of the compiler (we don't have *any* guarantees).
The best solution for now is probably to pass the log-level into each
line, as Dick Streefland suggested, though it would lead to a hairier
syntax, or just skip the whole interface for now, as Jan Engelhardt
suggested. Thanks.
Vegard
-
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to [EMAIL PROTECTED]
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
Re: [RFC] New kernel-message logging API (take 2)
On Sep 27 2007 23:18, Vegard Nossum wrote: > * kprint_() is better than kprint(case of the default log-level, the argument can be omitted. > * Memory allocated for entries and arguments is done in a ring-buffer >with variable-sized chunks. Arguments are chained with a singly- >linked list. > * Use SUBSYSTEM and KBUILD_MODNAME > * Rename kprint buffers to kprint blocks This is overall, quite a lot. I suggest one-thing-at-a-time, starting with kprint_() that is compiled out if desired and no fancy block or newline stuff. _Then_, will see how it flies. All of this smells like a bit of overdesigning, aka http://en.wikipedia.org/wiki/YAGNI - To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to [EMAIL PROTECTED] More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
Re: [RFC] New kernel-message logging API (take 2)
"Vegard Nossum" <[EMAIL PROTECTED]> wrote:
| It should be possible to optimize out multi-line (block) entries
| based on log-level filtering even though the log-level is only given
| in the first call (the initializer). It may take the shape of an
| if-block that spans several macros. This is not very elegant or robust
| if the macros are used incorrectly, however. Aborting a message can
| also be hard this way (since the abort would usually appear inside an
| if-statement that tests for some abnormal condition, thus appear in a
| different block, and thoroughly mess up the bracket order).
|
| Example: {
| #define kprint_block_init(block, loglevel) \
| if(loglevel > CONFIG_KPRINT_LOGLEVEL_MAX) { \
| kprint_real_block_init(block, loglevel);
|
| #define kprint_block(block, fmt, ...) \
| kprint_real_block(block, fmt, ## __VA_ARGS__);
|
| #define kprint_block_flush(block) \
| kprint_real_block_flush(block); \
| }
As you point out yourself, this is not very elegant or robust. In fact,
it is very dangerous. Why not simply pass the loglevel to each macro?
--
Dick Streefland Altium BV
[EMAIL PROTECTED] (@ @) http://www.altium.com
oOO--(_)--OOo---
-
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to [EMAIL PROTECTED]
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
Re: [RFC] New kernel-message logging API (take 2)
On Sep 28, 2007, at 03:31:11, Geert Uytterhoeven wrote:
Can't you store the loglevel in the kprint_block and check it in
all successive kprint_*() macros? If gcc knows it's constant, it
can optimize the non-wanted code away. As other fields in struct
kprint_block cannot be constant (they store internal state), you
have to split it like:
struct kprint_block {
int loglevel;
struct real_kprint_block real; /* internal state */
}
and pass () instead of to all successive internal
functions. I haven't tried this, so let's hope gcc is actually
smart enough...
Well actually, I believe you could just do:
struct kprint_block {
const int loglevel;
[...];
};
Then cast away the constness to actually set it initially:
*((int *)) = LOGLEVEL;
Cheers,
Kyle Moffett
-
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to [EMAIL PROTECTED]
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
Re: [RFC] New kernel-message logging API (take 2)
On Thu, 27 Sep 2007, Vegard Nossum wrote:
> It should be possible to optimize out multi-line (block) entries
> based on log-level filtering even though the log-level is only given
> in the first call (the initializer). It may take the shape of an
> if-block that spans several macros. This is not very elegant or robust
> if the macros are used incorrectly, however. Aborting a message can
> also be hard this way (since the abort would usually appear inside an
> if-statement that tests for some abnormal condition, thus appear in a
> different block, and thoroughly mess up the bracket order).
>
> Example: {
> #define kprint_block_init(block, loglevel) \
> if(loglevel > CONFIG_KPRINT_LOGLEVEL_MAX) { \
> kprint_real_block_init(block, loglevel);
>
> #define kprint_block(block, fmt, ...) \
> kprint_real_block(block, fmt, ## __VA_ARGS__);
>
> #define kprint_block_flush(block) \
> kprint_real_block_flush(block); \
> }
>
> /* Thus, this C code: */
> kprint_block_init(, KPRINT_INFO);
> kprint_block(, "Hello world");
> kprint_block_flush();
>
> /* Would pre-process into this: */
> if(6 < 4) {
> kprint_real_block_init(, 6);
> kprint_real_block(, "Hello world");
> kprint_block_flush();
> }
> }
If-blocks spanning macros are really dangerous!
E.g. an Ethernet driver may want to do:
kprint_block(, "MAC ");
for (i = 0; i < 6; i++) {
card->mac[i] = obtain_mac_byte_from_hw(i);
kprint_block(, "%02x", card->mac[i]);
}
This looks (and should be) innocent, but the actual MAC addres retrieval
would never be executed if loglevel <= CONFIG_KPRINT_LOGLEVEL_MAX.
Can't you store the loglevel in the kprint_block and check it in all
successive kprint_*() macros? If gcc knows it's constant, it can optimize
the non-wanted code away. As other fields in struct kprint_block cannot be
constant (they store internal state), you have to split it like:
struct kprint_block {
int loglevel;
struct real_kprint_block real; /* internal state */
}
and pass () instead of to all successive internal functions.
I haven't tried this, so let's hope gcc is actually smart enough...
Gr{oetje,eeting}s,
Geert
--
Geert Uytterhoeven -- There's lots of Linux beyond ia32 -- [EMAIL PROTECTED]
In personal conversations with technical people, I call myself a hacker. But
when I'm talking to journalists I just say "programmer" or something like that.
-- Linus Torvalds
-
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to [EMAIL PROTECTED]
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
Re: [RFC] New kernel-message logging API (take 2)
On Thu, 27 Sep 2007, Vegard Nossum wrote:
It should be possible to optimize out multi-line (block) entries
based on log-level filtering even though the log-level is only given
in the first call (the initializer). It may take the shape of an
if-block that spans several macros. This is not very elegant or robust
if the macros are used incorrectly, however. Aborting a message can
also be hard this way (since the abort would usually appear inside an
if-statement that tests for some abnormal condition, thus appear in a
different block, and thoroughly mess up the bracket order).
Example: {
#define kprint_block_init(block, loglevel) \
if(loglevel CONFIG_KPRINT_LOGLEVEL_MAX) { \
kprint_real_block_init(block, loglevel);
#define kprint_block(block, fmt, ...) \
kprint_real_block(block, fmt, ## __VA_ARGS__);
#define kprint_block_flush(block) \
kprint_real_block_flush(block); \
}
/* Thus, this C code: */
kprint_block_init(block, KPRINT_INFO);
kprint_block(block, Hello world);
kprint_block_flush(block);
/* Would pre-process into this: */
if(6 4) {
kprint_real_block_init(block, 6);
kprint_real_block(block, Hello world);
kprint_block_flush(block);
}
}
If-blocks spanning macros are really dangerous!
E.g. an Ethernet driver may want to do:
kprint_block(block, MAC );
for (i = 0; i 6; i++) {
card-mac[i] = obtain_mac_byte_from_hw(i);
kprint_block(block, %02x, card-mac[i]);
}
This looks (and should be) innocent, but the actual MAC addres retrieval
would never be executed if loglevel = CONFIG_KPRINT_LOGLEVEL_MAX.
Can't you store the loglevel in the kprint_block and check it in all
successive kprint_*() macros? If gcc knows it's constant, it can optimize
the non-wanted code away. As other fields in struct kprint_block cannot be
constant (they store internal state), you have to split it like:
struct kprint_block {
int loglevel;
struct real_kprint_block real; /* internal state */
}
and pass block.real() instead of block to all successive internal functions.
I haven't tried this, so let's hope gcc is actually smart enough...
Gr{oetje,eeting}s,
Geert
--
Geert Uytterhoeven -- There's lots of Linux beyond ia32 -- [EMAIL PROTECTED]
In personal conversations with technical people, I call myself a hacker. But
when I'm talking to journalists I just say programmer or something like that.
-- Linus Torvalds
-
To unsubscribe from this list: send the line unsubscribe linux-kernel in
the body of a message to [EMAIL PROTECTED]
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
Re: [RFC] New kernel-message logging API (take 2)
On Sep 28, 2007, at 03:31:11, Geert Uytterhoeven wrote:
Can't you store the loglevel in the kprint_block and check it in
all successive kprint_*() macros? If gcc knows it's constant, it
can optimize the non-wanted code away. As other fields in struct
kprint_block cannot be constant (they store internal state), you
have to split it like:
struct kprint_block {
int loglevel;
struct real_kprint_block real; /* internal state */
}
and pass block.real() instead of block to all successive internal
functions. I haven't tried this, so let's hope gcc is actually
smart enough...
Well actually, I believe you could just do:
struct kprint_block {
const int loglevel;
[...];
};
Then cast away the constness to actually set it initially:
*((int *)block.loglevel) = LOGLEVEL;
Cheers,
Kyle Moffett
-
To unsubscribe from this list: send the line unsubscribe linux-kernel in
the body of a message to [EMAIL PROTECTED]
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
Re: [RFC] New kernel-message logging API (take 2)
On 9/28/07, Jan Engelhardt [EMAIL PROTECTED] wrote: On Sep 27 2007 23:18, Vegard Nossum wrote: * kprint_level() is better than kprint(level), ) because in the case of the default log-level, the argument can be omitted. * Memory allocated for entries and arguments is done in a ring-buffer with variable-sized chunks. Arguments are chained with a singly- linked list. * Use SUBSYSTEM and KBUILD_MODNAME * Rename kprint buffers to kprint blocks This is overall, quite a lot. I suggest one-thing-at-a-time, starting with kprint_level() that is compiled out if desired and no fancy block or newline stuff. _Then_, will see how it flies. All of this smells like a bit of overdesigning, aka http://en.wikipedia.org/wiki/YAGNI Well, that's why I'm writing it down before actually coding it. Designing is also trying to make things fit together without actually having the physical parts at hand. So I'm trying to make an interface that CAN support multi-line blocks in the future, since it's obviously a desired (and currently missing) feature. But I agree; It *is* hard to see how multi-line blocks can be implemented without actually spelling it out in code. I've tried to do it, and failed. Until a brilliant solution comes up, I'll skip it. Vegard - To unsubscribe from this list: send the line unsubscribe linux-kernel in the body of a message to [EMAIL PROTECTED] More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
Re: [RFC] New kernel-message logging API (take 2)
On 9/28/07, Miguel Ojeda [EMAIL PROTECTED] wrote: On 9/28/07, Vegard Nossum [EMAIL PROTECTED] wrote: reason we can't use KBUILD_MODNAME is that this is defined on the command line. The declaration inside the header would thus be horribly wrong. We can, however, use KBUILD_MODNAME as a default value for KPRINT_DRIVER, like: static const char *KPRINT_DRIVER = KBUILD_MODNAME; which would pre-process to something like: static const char *KPRINT_DRIVER = bcm43xx; This value can still be overridden using #define KPRINT_DRIVER new name. In this case, it is possible that the original KPRINT_DRIVER symbol can cause an unused variable-warning. I guess this is fixable with the gcc unused variable attribute. Yep, then, in a year or two, we will be able to delete such attribute. Actually, no, since it will throw a warning only if a source file #defines KPRINT_SUBSYSTEM (i.e. overrides the constant variable (oxymoron!) with the same name). What you're hoping is that some time in the future, EVERY source file will come equipped with these definitions, and yes, at that point, the entire declaration can be removed, BUT I think that's... well. Yes. Will there be a team to change main subsystems/drivers to the new API? No. First of all, this is a specification draft; there is no code yet. Also, very possibly, this is such a violent change that nobody really wants to use it anyway. But we can hope. ;-) Vegard - To unsubscribe from this list: send the line unsubscribe linux-kernel in the body of a message to [EMAIL PROTECTED] More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
Re: [RFC] New kernel-message logging API (take 2)
On 9/28/07, Vegard Nossum [EMAIL PROTECTED] wrote: On 9/28/07, Miguel Ojeda [EMAIL PROTECTED] wrote: On 9/28/07, Vegard Nossum [EMAIL PROTECTED] wrote: reason we can't use KBUILD_MODNAME is that this is defined on the command line. The declaration inside the header would thus be horribly wrong. We can, however, use KBUILD_MODNAME as a default value for KPRINT_DRIVER, like: static const char *KPRINT_DRIVER = KBUILD_MODNAME; which would pre-process to something like: static const char *KPRINT_DRIVER = bcm43xx; This value can still be overridden using #define KPRINT_DRIVER new name. In this case, it is possible that the original KPRINT_DRIVER symbol can cause an unused variable-warning. I guess this is fixable with the gcc unused variable attribute. Yep, then, in a year or two, we will be able to delete such attribute. Actually, no, since it will throw a warning only if a source file #defines KPRINT_SUBSYSTEM (i.e. overrides the constant variable (oxymoron!) with the same name). What you're hoping is that some time in the future, EVERY source file will come equipped with these definitions, and yes, at that point, the entire declaration can be removed, BUT I think that's... well. Yes. Yes, that was my point. Far far far away, but possible, and if this RFC ever meets the real kernel, then bringing every source file to the API should be a objective. A good project for kernel janitors, for example. Will there be a team to change main subsystems/drivers to the new API? No. First of all, this is a specification draft; there is no code yet. Also, very possibly, this is such a violent change that nobody really wants to use it anyway. But we can hope. ;-) Sure, this is speculation. :) Vegard -- Miguel Ojeda http://maxextreme.googlepages.com/index.htm - To unsubscribe from this list: send the line unsubscribe linux-kernel in the body of a message to [EMAIL PROTECTED] More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
Re: [RFC] New kernel-message logging API (take 2)
On 9/28/07, Vegard Nossum [EMAIL PROTECTED] wrote: On 9/27/07, Vegard Nossum [EMAIL PROTECTED] wrote: * Use SUBSYSTEM and KBUILD_MODNAME snip. 2.1.5. Subsystem/driver tags Many parts of the kernel already prefix their log messages with a subsystem and/or driver tag to identify the source of a particular message. With the kprint interface, these tags are redundant. Instead, the macros SUBSYSTEM and KBUILD_MODNAME are used and recorded along with each log message. Therefore, each source file should define the macro SUBSYSTEM before any of the kprint functions are used. If this macro is not defined, the recorded subsystem will be an empty string. [6][7] This changes to KPRINT_SUBSYSTEM and KPRINT_DRIVER. The KPRINT_ prefix is to clearly say that this is something related to logging. The Nice. Although the word DRIVER may not represent every module, I think it is the correct option as I suggested, as the word is meaningful (speaks by itself) and almost every message in the kernel is printed out by drivers (whatever the big subsystem they belong to: drivers/, fs/, net/ ...). reason we can't use KBUILD_MODNAME is that this is defined on the command line. The declaration inside the header would thus be horribly wrong. We can, however, use KBUILD_MODNAME as a default value for KPRINT_DRIVER, like: static const char *KPRINT_DRIVER = KBUILD_MODNAME; which would pre-process to something like: static const char *KPRINT_DRIVER = bcm43xx; This value can still be overridden using #define KPRINT_DRIVER new name. In this case, it is possible that the original KPRINT_DRIVER symbol can cause an unused variable-warning. I guess this is fixable with the gcc unused variable attribute. Yep, then, in a year or two, we will be able to delete such attribute. Will there be a team to change main subsystems/drivers to the new API? -- Miguel Ojeda http://maxextreme.googlepages.com/index.htm - To unsubscribe from this list: send the line unsubscribe linux-kernel in the body of a message to [EMAIL PROTECTED] More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
Re: [RFC] New kernel-message logging API (take 2)
On 9/27/07, Vegard Nossum [EMAIL PROTECTED] wrote: * Use SUBSYSTEM and KBUILD_MODNAME snip. 2.1.5. Subsystem/driver tags Many parts of the kernel already prefix their log messages with a subsystem and/or driver tag to identify the source of a particular message. With the kprint interface, these tags are redundant. Instead, the macros SUBSYSTEM and KBUILD_MODNAME are used and recorded along with each log message. Therefore, each source file should define the macro SUBSYSTEM before any of the kprint functions are used. If this macro is not defined, the recorded subsystem will be an empty string. [6][7] This changes to KPRINT_SUBSYSTEM and KPRINT_DRIVER. The KPRINT_ prefix is to clearly say that this is something related to logging. The reason we can't use KBUILD_MODNAME is that this is defined on the command line. The declaration inside the header would thus be horribly wrong. We can, however, use KBUILD_MODNAME as a default value for KPRINT_DRIVER, like: static const char *KPRINT_DRIVER = KBUILD_MODNAME; which would pre-process to something like: static const char *KPRINT_DRIVER = bcm43xx; This value can still be overridden using #define KPRINT_DRIVER new name. In this case, it is possible that the original KPRINT_DRIVER symbol can cause an unused variable-warning. I guess this is fixable with the gcc unused variable attribute. Vegard - To unsubscribe from this list: send the line unsubscribe linux-kernel in the body of a message to [EMAIL PROTECTED] More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
Re: [RFC] New kernel-message logging API (take 2)
On 9/28/07, Kyle Moffett [EMAIL PROTECTED] wrote:
On Sep 28, 2007, at 03:31:11, Geert Uytterhoeven wrote:
Can't you store the loglevel in the kprint_block and check it in
all successive kprint_*() macros? If gcc knows it's constant, it
can optimize the non-wanted code away. As other fields in struct
kprint_block cannot be constant (they store internal state), you
have to split it like:
struct kprint_block {
int loglevel;
struct real_kprint_block real; /* internal state */
}
and pass block.real() instead of block to all successive internal
functions. I haven't tried this, so let's hope gcc is actually
smart enough...
Well actually, I believe you could just do:
struct kprint_block {
const int loglevel;
[...];
};
Then cast away the constness to actually set it initially:
*((int *)block.loglevel) = LOGLEVEL;
This doesn't seem to work either (i.e. it is not optimized out). I
tried initializing the struct statically too, to no avail. But thanks
for the tip.
Vegard
-
To unsubscribe from this list: send the line unsubscribe linux-kernel in
the body of a message to [EMAIL PROTECTED]
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
Re: [RFC] New kernel-message logging API (take 2)
If-blocks spanning macros are really dangerous!
E.g. an Ethernet driver may want to do:
kprint_block(block, MAC );
for (i = 0; i 6; i++) {
card-mac[i] = obtain_mac_byte_from_hw(i);
kprint_block(block, %02x, card-mac[i]);
}
This looks (and should be) innocent, but the actual MAC addres retrieval
would never be executed if loglevel = CONFIG_KPRINT_LOGLEVEL_MAX.
Yup. Okay, so it's definitely NOT an option.
Can't you store the loglevel in the kprint_block and check it in all
successive kprint_*() macros? If gcc knows it's constant, it can optimize
the non-wanted code away. As other fields in struct kprint_block cannot be
constant (they store internal state), you have to split it like:
struct kprint_block {
int loglevel;
struct real_kprint_block real; /* internal state */
}
and pass block.real() instead of block to all successive internal functions.
I haven't tried this, so let's hope gcc is actually smart enough...
It isn't, apparently. Or not with my test, anyway. Either way, it's
probably better not to make those assumptions about or rely too much
on the smartness of the compiler (we don't have *any* guarantees).
The best solution for now is probably to pass the log-level into each
line, as Dick Streefland suggested, though it would lead to a hairier
syntax, or just skip the whole interface for now, as Jan Engelhardt
suggested. Thanks.
Vegard
-
To unsubscribe from this list: send the line unsubscribe linux-kernel in
the body of a message to [EMAIL PROTECTED]
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
Re: [RFC] New kernel-message logging API (take 2)
Vegard Nossum [EMAIL PROTECTED] wrote:
| It should be possible to optimize out multi-line (block) entries
| based on log-level filtering even though the log-level is only given
| in the first call (the initializer). It may take the shape of an
| if-block that spans several macros. This is not very elegant or robust
| if the macros are used incorrectly, however. Aborting a message can
| also be hard this way (since the abort would usually appear inside an
| if-statement that tests for some abnormal condition, thus appear in a
| different block, and thoroughly mess up the bracket order).
|
| Example: {
| #define kprint_block_init(block, loglevel) \
| if(loglevel CONFIG_KPRINT_LOGLEVEL_MAX) { \
| kprint_real_block_init(block, loglevel);
|
| #define kprint_block(block, fmt, ...) \
| kprint_real_block(block, fmt, ## __VA_ARGS__);
|
| #define kprint_block_flush(block) \
| kprint_real_block_flush(block); \
| }
As you point out yourself, this is not very elegant or robust. In fact,
it is very dangerous. Why not simply pass the loglevel to each macro?
--
Dick Streefland Altium BV
[EMAIL PROTECTED] (@ @) http://www.altium.com
oOO--(_)--OOo---
-
To unsubscribe from this list: send the line unsubscribe linux-kernel in
the body of a message to [EMAIL PROTECTED]
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
Re: [RFC] New kernel-message logging API (take 2)
On Sep 27 2007 23:18, Vegard Nossum wrote: * kprint_level() is better than kprint(level), ) because in the case of the default log-level, the argument can be omitted. * Memory allocated for entries and arguments is done in a ring-buffer with variable-sized chunks. Arguments are chained with a singly- linked list. * Use SUBSYSTEM and KBUILD_MODNAME * Rename kprint buffers to kprint blocks This is overall, quite a lot. I suggest one-thing-at-a-time, starting with kprint_level() that is compiled out if desired and no fancy block or newline stuff. _Then_, will see how it flies. All of this smells like a bit of overdesigning, aka http://en.wikipedia.org/wiki/YAGNI - To unsubscribe from this list: send the line unsubscribe linux-kernel in the body of a message to [EMAIL PROTECTED] More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
Re: [RFC] New kernel-message logging API (take 2)
On Friday 28 September 2007 7:11:03 am Vegard Nossum wrote: wrong. We can, however, use KBUILD_MODNAME as a default value for KPRINT_DRIVER, like: static const char *KPRINT_DRIVER = KBUILD_MODNAME; which would pre-process to something like: static const char *KPRINT_DRIVER = bcm43xx; Which has been known to result in the string getting written out to the .o file even if it's never used, just in case something tries to take its address. This is not the same as a #define. This value can still be overridden using #define KPRINT_DRIVER new name. Not with -D on the command line though. Your #define would have to come after the declaration or else the declaration turns into 'char *fred = george;' and you have a syntax error. Again, not synonymous with a #define... Rob -- One of my most productive days was throwing away 1000 lines of code. - Ken Thompson. - To unsubscribe from this list: send the line unsubscribe linux-kernel in the body of a message to [EMAIL PROTECTED] More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
Re: [RFC] New kernel-message logging API (take 2)
On 9/28/07, Rob Landley [EMAIL PROTECTED] wrote: On Friday 28 September 2007 7:11:03 am Vegard Nossum wrote: wrong. We can, however, use KBUILD_MODNAME as a default value for KPRINT_DRIVER, like: static const char *KPRINT_DRIVER = KBUILD_MODNAME; which would pre-process to something like: static const char *KPRINT_DRIVER = bcm43xx; Which has been known to result in the string getting written out to the .o file even if it's never used, just in case something tries to take its address. This is not the same as a #define. Logic tells me that an unused static variable should never go into the .o. If something tries to take its address, it's no longer unused. This value can still be overridden using #define KPRINT_DRIVER new name. Not with -D on the command line though. Your #define would have to come after the declaration or else the declaration turns into 'char *fred = george;' and you have a syntax error. Again, not synonymous with a #define... Yeah, that's exactly what my e-mail was about. The macros KPRINT_SUBSYSTEM and KPRINT_DRIVER are not defined on the command line, but in each source file that wants this prefix, after the variables with the same names have been declared in kprint.h. This is intentional; they can be overridden with a define, otherwise, they'll default to static-const string variables. Vegard - To unsubscribe from this list: send the line unsubscribe linux-kernel in the body of a message to [EMAIL PROTECTED] More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
Re: [RFC] New kernel-message logging API (take 2)
> Example: {
> struct kprint_block out;
> kprint_block_init(, KPRINT_DEBUG);
> kprint_block(, "Stack trace:");
>
> while(unwind_stack()) {
> kprint_block(, "%p %s", address, symbol);
> }
> kprint_block_flush();
> }
Assuming that kprint_block_flush() is a combination of
kprint_block_printit() and kprint_block_abort(), you
coulld make a macro wrapper for this to preclude leaks:
#define KPRINT_BLOCK(block, level, code) \
do { \
struct kprint_block block; \
kprint_block_init(, KPRINT_##level); \
do { \
code ; \
kprint_block_printit(); \
while (0); \
kprint_block_abort(); \
} while(0)
The inner do { } while(0) region is so you can abort with "break".
(Or you can split it into KPRINT_BEGIN() and KPRINT_END() macros,
if that works out to be cleaner.)
-
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to [EMAIL PROTECTED]
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
[RFC] New kernel-message logging API (take 2)
Hello,
A big thanks to everybody who read and replied to my first e-mail; I
have tried my best to incorporate your feedback and suggestions. I
also added some CCs who recently participated in logging-related
discussions.
Changes (since Sept. 22):
* Extensibility -> Allowing the compiler to eliminate messages below
a certain threshold requires changing the API.
* Add some special-purpose logging functions
(printk_detected(), _registered(), _settings(), and _copyright())
* Fine-grained log-level control. "Everything above" or "everything
below" can be emulated by turning the specific log-levels on or off.
* Define an extra header containing the (optional) secondary
interface (err()/warn()/info())
* Remove kprint_*() aliases.
* kprint_() is better than kprint( CONFIG_KPRINT_LOGLEVEL_MAX) { \
kprint_real_block_init(block, loglevel);
#define kprint_block(block, fmt, ...) \
kprint_real_block(block, fmt, ## __VA_ARGS__);
#define kprint_block_flush(block) \
kprint_real_block_flush(block); \
}
/* Thus, this C code: */
kprint_block_init(, KPRINT_INFO);
kprint_block(, "Hello world");
kprint_block_flush();
/* Would pre-process into this: */
if(6 < 4) {
kprint_real_block_init(, 6);
kprint_real_block(, "Hello world");
kprint_block_flush();
}
}
References
[1] http://lkml.org/lkml/2007/9/21/267 (Joe Perches)
[2] http://lkml.org/lkml/2007/9/20/352 (Rob Landley)
[3] http://lkml.org/lkml/2007/9/21/151 (Dick Streefland)
[4] http://lkml.org/lkml/2007/6/13/146 (Michael Holzheu)
[5] http://lkml.org/lkml/2007/9/24/320 (Jesse Barnes)
[6] http://lkml.org/lkml/2007/9/22/162 (Miguel Ojeda)
[7] http://lkml.org/lkml/2007/9/25/62 (Vegard Nossum)
[8] http://lkml.org/lkml/2007/9/22/157 (Joe Perches)
-
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to [EMAIL PROTECTED]
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
[RFC] New kernel-message logging API (take 2)
Hello,
A big thanks to everybody who read and replied to my first e-mail; I
have tried my best to incorporate your feedback and suggestions. I
also added some CCs who recently participated in logging-related
discussions.
Changes (since Sept. 22):
* Extensibility - Allowing the compiler to eliminate messages below
a certain threshold requires changing the API.
* Add some special-purpose logging functions
(printk_detected(), _registered(), _settings(), and _copyright())
* Fine-grained log-level control. Everything above or everything
below can be emulated by turning the specific log-levels on or off.
* Define an extra header containing the (optional) secondary
interface (err()/warn()/info())
* Remove kprint_*() aliases.
* kprint_level() is better than kprint(level), ) because in the
case of the default log-level, the argument can be omitted.
* Memory allocated for entries and arguments is done in a ring-buffer
with variable-sized chunks. Arguments are chained with a singly-
linked list.
* Use SUBSYSTEM and KBUILD_MODNAME
* Rename kprint buffers to kprint blocks
Vegard
1. Requirements
* Backwards compatibility with printk(), syslog(), etc. There is no
way the whole kernel can be converted to a new interface in one go.
printk() is used all over the kernel, in many different ways,
including calls from assembly, multi-line prints spread over several
calls, etc.
* Extensibility. Features like eliminating messages below a given
threshold or recording the location (i.e. source file/line) of a
message [1] should be both selectable at compile-time and (if compiled
in) at run-time.
2. API
2.1. linux/kprint.h
This header defines the primary (i.e. lowest-level) interface to
kprint that is made available to the rest of the kernel.
2.1.1. kprint()
#define kprint(fmt, ...)
This function is the equivalent of the old printk(), except that it
does not take a log-level parameter, but emits messages using the
default log-level. The string must be a single line of information
(i.e. it must not contain any newlines). kprint() is implemented as a
macro, and must not be called from assembly.
2.1.2. Log-levels
To support the different log-levels, there exists one kprint_*()
function for each log-level, for example kprint_info(). This contrasts
with the printk() interface, but allows the log-level argument to be
passed as an argument (instead of prepending it to the message string)
and omitted if the default log-level should be used.
The string must be a single line of information. Calling
kprint_emerg(Oops.) is equivalent to calling printk(KERN_EMERG
Oops.\n). These functions are implemented as macros, and must not be
called from assembly. The different log-levels (and their functions)
are:
enum kprint_loglevel {
KPRINT_EMERG, /* kprint_emerg() */
KPRINT_ALERT, /* kprint_alert() */
KPRINT_CRIT,/* kprint_crit() */
KPRINT_ERROR, /* kprint_err() */
KPRINT_WARNING, /* kprint_warn() */
KPRINT_NOTICE, /* kprint_notice() */
KPRINT_INFO,/* kprint_info() */
KPRINT_DEBUG, /* kprint_debug() */
};
The individual log-levels can be enabled/disabled in the kernel
configuration and subsequently removed from the kernel (by the
compiler) entirely. It is not an option to filter out messages that
are simply above a certain log-level, although it could be more
convenient; controlling each log-level is the more general approach
and can be used to emulate the threshold filter. [8]
2.1.3. Classification tags
It turns out that many messages share a similar purpose. It would be
useful to classify these by a different scheme than severity [6].
Therefore, an additional four special-purpose macros are defined:
* printk_detected()A hardware detected message
* printk_registered() A device driver (un-)registered message
* printk_setting() A hardware setting change message
* printk_copyright() A copyright message, such as module authorship
information
Each message will be assigned the appropriate log-level for the
message class in question.
2.1.4. Blocks
In order to print several related lines as one chunk, the emitter
should first allocate an object of the type struct kprint_block. This
struct is initialized with the function kprint_block_init() which
takes as arguments a pointer to an object of the type struct
kprint_block followed by the log-level number. The emitter may then
make as many or as few calls to kprint_block() that is desired. A
final call to kprint_block_flush() appends the messages to the kernel
message log in a single, atomic operation. After it has been flushed,
the struct is not usable again (unless it is re-initialized). If for
any reason the struct should be de-initialized without writing it to
the log, a call to kprint_block_abort()
Re: [RFC] New kernel-message logging API (take 2)
Example: {
struct kprint_block out;
kprint_block_init(out, KPRINT_DEBUG);
kprint_block(out, Stack trace:);
while(unwind_stack()) {
kprint_block(out, %p %s, address, symbol);
}
kprint_block_flush(out);
}
Assuming that kprint_block_flush() is a combination of
kprint_block_printit() and kprint_block_abort(), you
coulld make a macro wrapper for this to preclude leaks:
#define KPRINT_BLOCK(block, level, code) \
do { \
struct kprint_block block; \
kprint_block_init(block, KPRINT_##level); \
do { \
code ; \
kprint_block_printit(block); \
while (0); \
kprint_block_abort(block); \
} while(0)
The inner do { } while(0) region is so you can abort with break.
(Or you can split it into KPRINT_BEGIN() and KPRINT_END() macros,
if that works out to be cleaner.)
-
To unsubscribe from this list: send the line unsubscribe linux-kernel in
the body of a message to [EMAIL PROTECTED]
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
Re: [RFC] New kernel-message logging API
On 9/25/07, Vegard Nossum <[EMAIL PROTECTED]> wrote:
> On 9/23/07, Miguel Ojeda <[EMAIL PROTECTED]> wrote:
> > Nice. I would suggest having some kind of standard way to show the
> > information on the screen/dmesg. I mean, instead of having plain lines
> > being written to the log, having something very short like:
>
> Thanks for the idea. Is this something you want to (manually) insert
> in each printk, or would it be passed like a parameter?
No parameters if possible: As you said, one or two #define's in the
beggining of the file can tell printk what to print as subsystem and
driver/...; and the reason (printk_xxx) could tell the loglevel. For
example: "detected", "registered" or "copyright" messages will have
always some low level priority; and "errors" or "alerts" high
priorities. This can help whenever selecting what loglevel priorities
to log, as all drivers will log most common messages in the same
loglevel.
So, with your change to printk_xxx, we can add real meaning to the
messages, and forget about selecting a priority for most common
messages. And that does not break your idea of writing printk_yyy,
being yyy all the priorities, as we will be able to use that functions
for uncommon kind of messages.
To clarify what I'm saying, here is an example:
#define PRINTK_SUBSYSTEM "video"
#define PRINTK_DRIVER "some123ag"
...
printk_copyright("Pretty Systems Inc. (C) <[EMAIL PROTECTED]>");
...
printk_detected("Some Pro 123ag VGA");
...
printk_registered("Framebuffer /dev/fb1");
...
if (really_weird_stuff_happened)
printk_emerg("Video card appears to be disconnected!");
As you see, each message will write to the correct priority. Even,
things like "printk_copyright" could have a macro like:
#define PRINTK_COPYRIGHT(who, year, email) printk_copyright(who " (C)
" year " <" email ">");
But I think that its going too far.
> For the subsystem part, it might be possible to #define a subsystem name at
> the beginning of each file and have printing functions automatically
> use this. But otherwise, I think the usefulness of this is perhaps a
> little low compared to the effort needed (ie. for this to be useful,
> each and every printk of the kernel would need to be changed). Also
Right... But in the long time, it can help a lot. For now, every
maintainer should add the #define line in each file and write the
reason while changing the function name (that is something we will
have to do anyway if you change printk).
> notice, even in your examples, that most subsystems/drivers already
> prefix their messages to identify the source. Perhaps a better effort
> spent would be to go through the ones that are missing this "source"
> prefix and fix them?
I would say 70% do it. Also, they just write the name of the
subsystem/driver, a ':' and then a non-standard string. I mean, most
of the messages are about a new detected device, an error encountered,
a registered/mounted device/link, the copyright, the authors, ... Some
of them say "registered XXX", others "XXX registered", other just say
"new XXX" or split the message in two lines, etc.
My point is: Most of the messages are inside five or six categories,
so if people is ready to change/improve printk() API, let's finish all
the duplication, as we usually do with code.
Also, I think it could help a lot in the future if we categorize the
messages by subsystem/driver and level/reason: then we could write
more useful tools for debugging, logging... We could "grep" it, or
select what we want to log, etc.
I'm sure this idea is maybe overwhelming at first, but I think that in
the future will help a lot. Linux is growing everyday more and more,
and if printk() is about to change, as soon as we introduce new
features, easier will be.
>
> Vegard
>
Thanks for your interest in the idea.
--
Miguel Ojeda
http://maxextreme.googlepages.com/index.htm
-
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to [EMAIL PROTECTED]
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
Re: [RFC] New kernel-message logging API
On Mon, 2007-09-24 at 08:19 -0700, Joe Perches wrote: > On Mon, 2007-09-24 at 11:22 +0200, Michael Holzheu wrote: > > Together with the idea of not allowing multiple lines in the kprint_xxx > > functions, that would go with our approach having message numbers to > > identify a message. > > How does this equate/give message numbers? It does not give us message numbers. It allows us to tag printks, which have more than one line, with exactly one number. Michael - To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to [EMAIL PROTECTED] More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
Re: [RFC] New kernel-message logging API
On 9/25/07, Joe Perches <[EMAIL PROTECTED]> wrote:
> On Tue, 2007-09-25 at 00:58 -0400, [EMAIL PROTECTED] wrote:
> > Even the "kp_" prefix is actually pretty unnecessary. It's "info"
> > and a human-readable string that make it recognizable as a log message.
>
> While I agree a prefix isn't necessary, info, warn, err
> are already frequently #define'd and used.
>
> kp_ isn't currently in use.
>
> $ egrep -r -l --include=*.[ch]
> "^[[:space:]]*#[[:space:]]*define[[:space:]]+(info|err|warn)\b" * | wc -l
> 29
Yes, this is a very good point, they're already used. If they hadn't
been, everything would have been perfect. Actually, I'd have preferred
info/warn/err over kprint_ if it wasn't for the fact that
they're used (and in slightly different ways too).
As I wrote initially, one of the absolute requirements of a new API is
to retain full backwards compatibility with printk(). Which means that
using simply err()/info()/warn() is out of the question *for now*.
That is not to say we can't change this at a later time.
I think it would be good to have a base layer containing the functions
kprint_(), just to have something that 1) has a meaningful
name, and 2) doesn't disturb anybody else's names. err/info/warn or
kp_err/info/warn() (in order to have shorter names) can then be
implemented in terms of this.
I suppose that another goal of a new API would be to unify the
somewhat-a-mess of API that is now, i.e. many alternatives that do the
same thing is also not good. But this can be changed with patches (to
convert to new API) later.
If you look closer at the current definitions of erro/warn/info, it
turns out that most of them also do this to automatically prefix all
messages with the driver name. This makes me realize that there really
is a need for a way to automatically prefix messages or store a
per-message "subsystem" field. I propose the following solution:
The kprint.h header file looks like this:
/* This is a back-up string to be used if the source file doesn't
define this as a macro. */
const char *SUBSYSTEM = "";
/* Call this macro whatever you want, it's just an example anyway. */
#define info(msg, ...) printf("%s: " msg, SUBSYSTEM, ## __VA_ARGS__)
Then you can have a C file that overrides SUBSYSTEM by defining it as a macro:
#include
#define SUBSYSTEM "usb"
info("test");
--> results in printf("%s: " "test", "usb");
Or, a C file that doesn't:
#include
info("test");
--> results in printf("%s: " "test", SYBSYSTEM);
--> output is ": test"
Though, instead of actually incorporating this SUBSYSTEM name into the
string, I suggest passing it off as an argument into the real kprint()
machinery, to be stored along (but seperately) with timestamp, etc.
Hm, that's a digression. But thanks for the idea :)
Vegard
-
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to [EMAIL PROTECTED]
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
Re: [RFC] New kernel-message logging API
>> Even the "kp_" prefix is actually pretty unnecessary. It's "info" >> and a human-readable string that make it recognizable as a log message. > While I agree a prefix isn't necessary, info, warn, err > are already frequently #define'd and used. > > kp_ isn't currently in use. > > $ egrep -r -l --include=*.[ch] > "^[[:space:]]*#[[:space:]]*define[[:space:]]+(info|err|warn)\b" * | wc -l > 29 Sorry for being unclear. I wasn't seriously recommending no prefix, due to name collisions (exactly your point), but rather saying that no prefix is necessary for human understanding. Something to avoid the ambiguity is still useful. I was just saying that it can be pretty much anything withouyt confusing the casual reader. We're in violent agreement, I just didn't say it very well the first time. - To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to [EMAIL PROTECTED] More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
Re: [RFC] New kernel-message logging API
On Tue, 2007-09-25 at 00:58 -0400, [EMAIL PROTECTED] wrote: > Even the "kp_" prefix is actually pretty unnecessary. It's "info" > and a human-readable string that make it recognizable as a log message. While I agree a prefix isn't necessary, info, warn, err are already frequently #define'd and used. kp_ isn't currently in use. $ egrep -r -l --include=*.[ch] "^[[:space:]]*#[[:space:]]*define[[:space:]]+(info|err|warn)\b" * | wc -l 29 - To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to [EMAIL PROTECTED] More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
Re: [RFC] New kernel-message logging API
On Tue, 2007-09-25 at 00:58 -0400, [EMAIL PROTECTED] wrote: Even the kp_ prefix is actually pretty unnecessary. It's info and a human-readable string that make it recognizable as a log message. While I agree a prefix isn't necessary, info, warn, err are already frequently #define'd and used. kp_level isn't currently in use. $ egrep -r -l --include=*.[ch] ^[[:space:]]*#[[:space:]]*define[[:space:]]+(info|err|warn)\b * | wc -l 29 - To unsubscribe from this list: send the line unsubscribe linux-kernel in the body of a message to [EMAIL PROTECTED] More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
Re: [RFC] New kernel-message logging API
Even the kp_ prefix is actually pretty unnecessary. It's info and a human-readable string that make it recognizable as a log message. While I agree a prefix isn't necessary, info, warn, err are already frequently #define'd and used. kp_level isn't currently in use. $ egrep -r -l --include=*.[ch] ^[[:space:]]*#[[:space:]]*define[[:space:]]+(info|err|warn)\b * | wc -l 29 Sorry for being unclear. I wasn't seriously recommending no prefix, due to name collisions (exactly your point), but rather saying that no prefix is necessary for human understanding. Something to avoid the ambiguity is still useful. I was just saying that it can be pretty much anything withouyt confusing the casual reader. We're in violent agreement, I just didn't say it very well the first time. - To unsubscribe from this list: send the line unsubscribe linux-kernel in the body of a message to [EMAIL PROTECTED] More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
Re: [RFC] New kernel-message logging API
On 9/25/07, Joe Perches [EMAIL PROTECTED] wrote: On Tue, 2007-09-25 at 00:58 -0400, [EMAIL PROTECTED] wrote: Even the kp_ prefix is actually pretty unnecessary. It's info and a human-readable string that make it recognizable as a log message. While I agree a prefix isn't necessary, info, warn, err are already frequently #define'd and used. kp_level isn't currently in use. $ egrep -r -l --include=*.[ch] ^[[:space:]]*#[[:space:]]*define[[:space:]]+(info|err|warn)\b * | wc -l 29 Yes, this is a very good point, they're already used. If they hadn't been, everything would have been perfect. Actually, I'd have preferred info/warn/err over kprint_level if it wasn't for the fact that they're used (and in slightly different ways too). As I wrote initially, one of the absolute requirements of a new API is to retain full backwards compatibility with printk(). Which means that using simply err()/info()/warn() is out of the question *for now*. That is not to say we can't change this at a later time. I think it would be good to have a base layer containing the functions kprint_level(), just to have something that 1) has a meaningful name, and 2) doesn't disturb anybody else's names. err/info/warn or kp_err/info/warn() (in order to have shorter names) can then be implemented in terms of this. I suppose that another goal of a new API would be to unify the somewhat-a-mess of API that is now, i.e. many alternatives that do the same thing is also not good. But this can be changed with patches (to convert to new API) later. If you look closer at the current definitions of erro/warn/info, it turns out that most of them also do this to automatically prefix all messages with the driver name. This makes me realize that there really is a need for a way to automatically prefix messages or store a per-message subsystem field. I propose the following solution: The kprint.h header file looks like this: /* This is a back-up string to be used if the source file doesn't define this as a macro. */ const char *SUBSYSTEM = ; /* Call this macro whatever you want, it's just an example anyway. */ #define info(msg, ...) printf(%s: msg, SUBSYSTEM, ## __VA_ARGS__) Then you can have a C file that overrides SUBSYSTEM by defining it as a macro: #include linux/kprint.h #define SUBSYSTEM usb info(test); -- results in printf(%s: test, usb); Or, a C file that doesn't: #include linux/kprint.h info(test); -- results in printf(%s: test, SYBSYSTEM); -- output is : test Though, instead of actually incorporating this SUBSYSTEM name into the string, I suggest passing it off as an argument into the real kprint() machinery, to be stored along (but seperately) with timestamp, etc. Hm, that's a digression. But thanks for the idea :) Vegard - To unsubscribe from this list: send the line unsubscribe linux-kernel in the body of a message to [EMAIL PROTECTED] More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
Re: [RFC] New kernel-message logging API
On Mon, 2007-09-24 at 08:19 -0700, Joe Perches wrote: On Mon, 2007-09-24 at 11:22 +0200, Michael Holzheu wrote: Together with the idea of not allowing multiple lines in the kprint_xxx functions, that would go with our approach having message numbers to identify a message. How does this equate/give message numbers? It does not give us message numbers. It allows us to tag printks, which have more than one line, with exactly one number. Michael - To unsubscribe from this list: send the line unsubscribe linux-kernel in the body of a message to [EMAIL PROTECTED] More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
Re: [RFC] New kernel-message logging API
On 9/25/07, Vegard Nossum [EMAIL PROTECTED] wrote: On 9/23/07, Miguel Ojeda [EMAIL PROTECTED] wrote: Nice. I would suggest having some kind of standard way to show the information on the screen/dmesg. I mean, instead of having plain lines being written to the log, having something very short like: Thanks for the idea. Is this something you want to (manually) insert in each printk, or would it be passed like a parameter? No parameters if possible: As you said, one or two #define's in the beggining of the file can tell printk what to print as subsystem and driver/...; and the reason (printk_xxx) could tell the loglevel. For example: detected, registered or copyright messages will have always some low level priority; and errors or alerts high priorities. This can help whenever selecting what loglevel priorities to log, as all drivers will log most common messages in the same loglevel. So, with your change to printk_xxx, we can add real meaning to the messages, and forget about selecting a priority for most common messages. And that does not break your idea of writing printk_yyy, being yyy all the priorities, as we will be able to use that functions for uncommon kind of messages. To clarify what I'm saying, here is an example: #define PRINTK_SUBSYSTEM video #define PRINTK_DRIVER some123ag ... printk_copyright(Pretty Systems Inc. (C) [EMAIL PROTECTED]); ... printk_detected(Some Pro 123ag VGA); ... printk_registered(Framebuffer /dev/fb1); ... if (really_weird_stuff_happened) printk_emerg(Video card appears to be disconnected!); As you see, each message will write to the correct priority. Even, things like printk_copyright could have a macro like: #define PRINTK_COPYRIGHT(who, year, email) printk_copyright(who (C) year email ); But I think that its going too far. For the subsystem part, it might be possible to #define a subsystem name at the beginning of each file and have printing functions automatically use this. But otherwise, I think the usefulness of this is perhaps a little low compared to the effort needed (ie. for this to be useful, each and every printk of the kernel would need to be changed). Also Right... But in the long time, it can help a lot. For now, every maintainer should add the #define line in each file and write the reason while changing the function name (that is something we will have to do anyway if you change printk). notice, even in your examples, that most subsystems/drivers already prefix their messages to identify the source. Perhaps a better effort spent would be to go through the ones that are missing this source prefix and fix them? I would say 70% do it. Also, they just write the name of the subsystem/driver, a ':' and then a non-standard string. I mean, most of the messages are about a new detected device, an error encountered, a registered/mounted device/link, the copyright, the authors, ... Some of them say registered XXX, others XXX registered, other just say new XXX or split the message in two lines, etc. My point is: Most of the messages are inside five or six categories, so if people is ready to change/improve printk() API, let's finish all the duplication, as we usually do with code. Also, I think it could help a lot in the future if we categorize the messages by subsystem/driver and level/reason: then we could write more useful tools for debugging, logging... We could grep it, or select what we want to log, etc. I'm sure this idea is maybe overwhelming at first, but I think that in the future will help a lot. Linux is growing everyday more and more, and if printk() is about to change, as soon as we introduce new features, easier will be. Vegard Thanks for your interest in the idea. -- Miguel Ojeda http://maxextreme.googlepages.com/index.htm - To unsubscribe from this list: send the line unsubscribe linux-kernel in the body of a message to [EMAIL PROTECTED] More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
Re: [RFC] New kernel-message logging API
On 9/23/07, Miguel Ojeda <[EMAIL PROTECTED]> wrote: > Nice. I would suggest having some kind of standard way to show the > information on the screen/dmesg. I mean, instead of having plain lines > being written to the log, having something very short like: Thanks for the idea. Is this something you want to (manually) insert in each printk, or would it be passed like a parameter? For the subsystem part, it might be possible to #define a subsystem name at the beginning of each file and have printing functions automatically use this. But otherwise, I think the usefulness of this is perhaps a little low compared to the effort needed (ie. for this to be useful, each and every printk of the kernel would need to be changed). Also notice, even in your examples, that most subsystems/drivers already prefix their messages to identify the source. Perhaps a better effort spent would be to go through the ones that are missing this "source" prefix and fix them? Vegard - To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to [EMAIL PROTECTED] More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
Re: [RFC] New kernel-message logging API
> I don't know. Compare the following two lines:
>
> printk(KERN_INFO "Message.\n");
> kprint_info("Message.");
>
> By dropping the lengthy macro (it's not like it's going to change
> while we're running anyway, so why not make it a part of the function
> name?) and the final newline, we actually end up with a net decrease
> in line length.
Agreed. In fact, you may want to write a header that implements the
kprint_ functions in terms of printk for out-of-core driver writers to
incorporate into their code bases, so they can upgrade their API while
maintaining backward compatibility. (If it were me, I'd also give it
a very permissive license, like outright public domain, to encourage use.)
> I thought it would be nice to have something that looks familiar,
> since that would ease an eventual transition. klog is a valid
> alternative, but isn't kp a bit cryptic?
Well, in context:
kp_info("Message.");
Even the "kp_" prefix is actually pretty unnecessary. It's "info"
and a human-readable string that make it recognizable as a log message.
Another reason to keep it short is just that it's going to get typed a LOT.
Anyway, just MHO.
-
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to [EMAIL PROTECTED]
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
Re: [RFC] New kernel-message logging API
On Monday 24 September 2007 7:10:32 pm Joe Perches wrote: > On Mon, 2007-09-24 at 18:51 -0500, Rob Landley wrote: > > > An added pass between gcc preprocessor and compiler could compact > > > or compress the format string without modifying the conversion > > > specifications so __attribute__ ((format (printf)) would still work. > > > > This does not address my problem. Spitting out a proprietary hash code > > instead of a human readable message is not a solution for my use case. > > What is your problem Rob? The single largest space savings in the existing -tiny patches comes from removing printk() calls and strings. I would like to be able to selectively do this based on severity level, which is information most existing printk() calls already have. I proposed a minimal change to how printk() works, allowing the compiler to remove unused code that wouldn't be below the displayed level of printk() anyway in the deployed product so wouldn't actually lose any output. The kernel image is usually already compressed in flash and decompressed to dram during boot. (Not always, sometimes it's run directly out of flash, but there's often a speed penalty for doing this, you have to set it up specially, and dram is cheaper than flash anyway.) This means recompressing it doesn't help save flash. If you want to save dram, have printk and associated strings be a function in a module that's demand loaded and unloaded again after each call. Then you can foist compression off on userspace, and we're already used to modules having to match a given kernel version exactly. Why come up with new infrastructure? Rob -- "One of my most productive days was throwing away 1000 lines of code." - Ken Thompson. - To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to [EMAIL PROTECTED] More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
Re: [RFC] New kernel-message logging API
On Monday 24 September 2007 3:37:55 pm Vegard Nossum wrote: > On 9/24/07, Joe Perches <[EMAIL PROTECTED]> wrote: > > On Mon, 2007-09-24 at 18:43 +0200, Vegard Nossum wrote: > > > Storing the format-string separately allows us to hash THAT instead of > > > the formatted (ie. console output) message. Since this will never > > > change from message to message, it can be looked up in a table or > > > whatever and allow user-space to do translations without for example > > > regular expressions. > > > > That hash will change with each linux version given the > > inevitable spelling fixes, message reformatting and such. > > But we can keep the old ones too. That shouldn't be much of a problem. > I mean, it probably wouldn't rely on a hash alone. The format string > itself can be compared with the translation database. I point out that the thread started with a comment about how to _reduce_ bloat. Just sayin'. Rob -- "One of my most productive days was throwing away 1000 lines of code." - Ken Thompson. - To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to [EMAIL PROTECTED] More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
Re: [RFC] New kernel-message logging API
On Mon, 2007-09-24 at 18:51 -0500, Rob Landley wrote: > > An added pass between gcc preprocessor and compiler could compact > > or compress the format string without modifying the conversion > > specifications so __attribute__ ((format (printf)) would still work. > This does not address my problem. Spitting out a proprietary hash code > instead of a human readable message is not a solution for my use case. What is your problem Rob? I think message numbers are difficult to produce from format strings. I think kernel version/file/func/line is enough to identify messages for normal use but not too useful for embedded. I think losslessly compressing, not hashing, the format string would be useful. The format string would be expanded by printk. The kernel size would be smaller and more easily fit in minimal RAM. Losslessly compressing the format strings probably won't reduce flash image size. cheers, Joe - To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to [EMAIL PROTECTED] More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
Re: [RFC] New kernel-message logging API
On Monday 24 September 2007 10:19:16 am Joe Perches wrote: > On Mon, 2007-09-24 at 11:22 +0200, Michael Holzheu wrote: > > Together with the idea of not allowing multiple lines in the kprint_xxx > > functions, that would go with our approach having message numbers to > > identify a message. > > How does this equate/give message numbers? I actively want to avoid giving message numbers. My interest is in selectively removing messages from the kernel to shrink the binary size (and NOT make it up in either a larger userspace utility to translate them, or else magic proprietary numbers you can only diagnose if you pay my support staff). > An added pass between gcc preprocessor and compiler could compact > or compress the format string without modifying the conversion > specifications so __attribute__ ((format (printf)) would still work. This does not address my problem. Spitting out a proprietary hash code instead of a human readable message is not a solution for my use case. Rob -- "One of my most productive days was throwing away 1000 lines of code." - Ken Thompson. - To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to [EMAIL PROTECTED] More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
Re: [RFC] New kernel-message logging API
On 9/24/07, Joe Perches <[EMAIL PROTECTED]> wrote:
> On Mon, 2007-09-24 at 18:43 +0200, Vegard Nossum wrote:
> > Storing the format-string separately allows us to hash THAT instead of
> > the formatted (ie. console output) message. Since this will never
> > change from message to message, it can be looked up in a table or
> > whatever and allow user-space to do translations without for example
> > regular expressions.
>
> That hash will change with each linux version given the
> inevitable spelling fixes, message reformatting and such.
But we can keep the old ones too. That shouldn't be much of a problem.
I mean, it probably wouldn't rely on a hash alone. The format string
itself can be compared with the translation database.
> > I will follow up with some code to demonstrate as soon as I can.
>
> Looking forward to it.
Okay, so I have one huge file that does more or less what I want. The
main problem with this, as I see it, is that it largely duplicates
vsnprintf() from lib/vsprintf.c (minus the functions I coped verbatim
from the same file). This is bad because the job of maintaining that
is now doubled (or worse). Hopefully it won't change much in the
future either.
For now, the main() function is most important. This demonstrates that
what I want is in fact possible. printf() is now split in two --
args_printf_prepare() and args_snprintf(). The former takes your
arguments as you would pass them to any *printff() function, but only
converts your arguments (and stores them in a struct args). The latter
takes the format string and the stored struct args and puts the whole
thing in a buffer (just like snprintf()).
I know Gmail isn't too friendly with code formatting, but this is just
an example program anyway, so it shouldn't really matter. Also, a
disclaimer: Almost completely untested.
Vegard
#define _GNU_SOURCE
#include
#include
#include
#include
#include
#include
/* This was shamelessly copied form include/asm-generic/div64.h */
# define do_div(n,base) ({ \
uint32_t __base = (base); \
uint32_t __rem; \
__rem = ((uint64_t)(n)) % __base; \
(n) = ((uint64_t)(n)) / __base; \
__rem; \
})
/* This was shamelessly copied from lib/vsprintf.c */
static char* put_dec_trunc(char *buf, unsigned q)
{
unsigned d3, d2, d1, d0;
d1 = (q>>4) & 0xf;
d2 = (q>>8) & 0xf;
d3 = (q>>12);
d0 = 6*(d3 + d2 + d1) + (q & 0xf);
q = (d0 * 0xcd) >> 11;
d0 = d0 - 10*q;
*buf++ = d0 + '0'; /* least significant digit */
d1 = q + 9*d3 + 5*d2 + d1;
if (d1 != 0) {
q = (d1 * 0xcd) >> 11;
d1 = d1 - 10*q;
*buf++ = d1 + '0'; /* next digit */
d2 = q + 2*d2;
if ((d2 != 0) || (d3 != 0)) {
q = (d2 * 0xd) >> 7;
d2 = d2 - 10*q;
*buf++ = d2 + '0'; /* next digit */
d3 = q + 4*d3;
if (d3 != 0) {
q = (d3 * 0xcd) >> 11;
d3 = d3 - 10*q;
*buf++ = d3 + '0'; /* next digit */
if (q != 0)
*buf++ = q + '0'; /* most sign. digit
*/
}
}
}
return buf;
}
static char* put_dec_full(char *buf, unsigned q)
{
unsigned d3, d2, d1, d0;
d1 = (q>>4) & 0xf;
d2 = (q>>8) & 0xf;
d3 = (q>>12);
d0 = 6*(d3 + d2 + d1) + (q & 0xf);
q = (d0 * 0xcd) >> 11;
d0 = d0 - 10*q;
*buf++ = d0 + '0';
d1 = q + 9*d3 + 5*d2 + d1;
q = (d1 * 0xcd) >> 11;
d1 = d1 - 10*q;
*buf++ = d1 + '0';
d2 = q + 2*d2;
q = (d2 * 0xd) >> 7;
d2 = d2 - 10*q;
*buf++ = d2 + '0';
d3 = q + 4*d3;
q = (d3 * 0xcd) >> 11; /* - shorter code */
d3 = d3 - 10*q;
*buf++ = d3 + '0';
*buf++ = q + '0';
return buf;
}
static char* put_dec(char *buf, unsigned long long num)
{
while (1) {
unsigned rem;
if (num < 10)
return put_dec_trunc(buf, num);
rem = do_div(num, 10);
buf = put_dec_full(buf, rem);
}
}
#define ZEROPAD 1 /* pad with zero */
#define SIGN2 /* unsigned/signed long */
#define PLUS4 /* show plus */
#define SPACE 8 /* space if
Re: [RFC] New kernel-message logging API
On Saturday, September 22, 2007 12:27 pm Vegard Nossum wrote:
> enum kprint_loglevel {
> KPRINT_EMERG, /* kprint_emerg() */
> KPRINT_ALERT, /* kprint_alert() */
> KPRINT_CRIT,/* kprint_crit() */
> KPRINT_ERROR, /* kprint_error() and/or kprint_err() */
> KPRINT_WARNING, /* kprint_warning() and/or kprint_warn() */
> KPRINT_NOTICE, /* kprint_notice() */
> KPRINT_INFO,/* kprint_info() */
> KPRINT_DEBUG, /* kprint_debug() */
> };
I wonder if all these levels are still needed (though I really like the
error/err & warning/warn aliases, those always get me :).
It seems like fewer levels would make things easier on both kernel
developers and administrators; looking at current counts may help
figure out which ones could be combined (warning, very naive grep -r
data):
KERN_EMERG: 371
KERN_ALERT: 236
KERN_CRIT: 602
KERN_ERR: 11961
KERN_WARNING: 6463
KERN_NOTICE: 1142
KERN_INFO: 8491
KERN_DEBUG: 6125
So KERN_ERR is the most common by a pretty large margin, though it seems
to me that KERN_NOTICE, KERN_INFO and KERN_DEBUG are mostly redundant
and probably make up a majority of the "SIMD FPU exception support was
enabled" (as if I care) type messages. Likewise, ERR, ALERT, CRIT and
EMERG serve very similar purposes (i.e. something unrecoverable
occurred), maybe they could be condensed into one or two levels rather
than four? So that would drop us to three levels:
KERN_ERR /* something really bad happened, machine is dead or near so */
KERN_WARNING /* you really ought to know about this */
KERN_INFO /* no one but the kernel developer likely cares about this */
But maybe I'm just living in a dream world where then number of printks
the kernel spits out suddenly drops by 99% and only actually important
messages make it to my log...
Jesse
-
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to [EMAIL PROTECTED]
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
Re: [RFC] New kernel-message logging API
On Mon, 2007-09-24 at 18:43 +0200, Vegard Nossum wrote: > Storing the format-string separately allows us to hash THAT instead of > the formatted (ie. console output) message. Since this will never > change from message to message, it can be looked up in a table or > whatever and allow user-space to do translations without for example > regular expressions. That hash will change with each linux version given the inevitable spelling fixes, message reformatting and such. > I will follow up with some code to demonstrate as soon as I can. Looking forward to it. - To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to [EMAIL PROTECTED] More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
Re: [RFC] New kernel-message logging API
On 9/24/07, Joe Perches <[EMAIL PROTECTED]> wrote: > On Mon, 2007-09-24 at 11:22 +0200, Michael Holzheu wrote: > > Together with the idea of not allowing multiple lines in the kprint_xxx > > functions, that would go with our approach having message numbers to > > identify a message. > > How does this equate/give message numbers? Storing the format-string separately allows us to hash THAT instead of the formatted (ie. console output) message. Since this will never change from message to message, it can be looked up in a table or whatever and allow user-space to do translations without for example regular expressions. I'm pretty sure this *would* be possible to do with existing printk(), but I'm betting it also wouldn't look very nice (i.e. hackery). > > If you do it like that, you can't support "%s", since then you would > > store only the pointer and not the whole string. I think, that we can't > > live without %s. > > long long would not work either. > > Perhaps it's better to scan the format string or indirect the > printk formatting logic. The idea was to not use snprintf() for the stored message, but have a printf-like function that instead writes the output of each format specifier to its own string (ie. each argument produces a new char* object). Also needed would be an additional function that reads the format string but uses the stored arguments. This turned out to be slightly harder than I assumed at first, though it's of course not impossible. The downside of this approach is of course the need to maintain normal vsnprintf() and new functions side by side, with little possibility of reusing the format parsing of vsnprintf(). I will follow up with some code to demonstrate as soon as I can. Vegard - To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to [EMAIL PROTECTED] More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
Re: [RFC] New kernel-message logging API
On Mon, 2007-09-24 at 11:22 +0200, Michael Holzheu wrote: > Together with the idea of not allowing multiple lines in the kprint_xxx > functions, that would go with our approach having message numbers to > identify a message. How does this equate/give message numbers? > If you do it like that, you can't support "%s", since then you would > store only the pointer and not the whole string. I think, that we can't > live without %s. long long would not work either. Perhaps it's better to scan the format string or indirect the printk formatting logic. Another possibility: An added pass between gcc preprocessor and compiler could compact or compress the format string without modifying the conversion specifications so __attribute__ ((format (printf)) would still work. printk could expand the compacted/compressed format. - To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to [EMAIL PROTECTED] More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
Re: [RFC] New kernel-message logging API
Hi Vegard,
On Sat, 2007-09-22 at 21:27 +0200, Vegard Nossum wrote:
> After recent discussions on LKML and a general dissatisfaction at the
> current printk() kernel-message logging interface, I've decided to
> write down some of the ideas for a better system.
Good luck :-)
[snip]
> Example: {
> struct kprint_buffer buf;
>
> kprint_buffer_init(, KPRINT_DEBUG);
> kprint_buffer(, "Stack trace:");
>
> while(unwind_stack()) {
> kprint_buffer(, "%p %s", address, symbol);
> }
>
> kprint_buffer_flush();
> }
>
Together with the idea of not allowing multiple lines in the kprint_xxx
functions, that would go with our approach having message numbers to
identify a message. Multiple lines are combined explicitly to one
message. I think it is a good idea to be able to identify, which lines
of a message belong together.
[snip]
> With such a modular interface, message attributes (for example the
> current time) and arguments can be recorded separately from the actual
> format string, instead of written formatted to a ring buffer as a
> sequence of characters. Parameters would be formatted to their own
> strings (regardless of the original type) and saved in an array.
>
> Example: {
> struct kprint_message {
> const char *format;
>
> unsigned int argc;
> char **argv;
>
> #ifdef KPRINT_TIMESTAMP
> unsigned long long timestamp;
> #endif
>
> #ifndef KPRINT_LOCATION
> const char *file;
> unsigned int line;
>
> const char *function;
> #endif
> };
> }
[snip]
> The message entry and a message's arguments are kept separately. Most
> likely, there will be a huge number of tiny allocations. I am not sure
> how well this is handled in the kernel. Or we could try to merge the
> allocation of the struct kprint_message and its arguments into a
> single allocation by looking at the arguments before they're
> formatted. After all, the arguments cannot exist without the message
> or vice versa. Alternatively, a statically-sized ring buffer of struct
> kprint_message objects could be used, and then only arguments would
> need to be allocated dynamically. Either way, I think it should be
> possible to come up with a fairly memory-efficient system even for
> this method of storing the kernel log.
Would be nice to have some code here. How do you want to implement that?
You have to allocate / preallocate memory for the argv array. Something
like:
kprint_err(const char* fmt, ...)
{
va_list ap;
struct kprint_message *msg;
msg = _arry[current];
va_start(ap, fmt);
msg->argv = kmalloc(sizeof(long) * argc, GFP_KERNEL);
...
for (i = 0; i < argc, i++) {
msg->argv[i] = va_arg(ap, long);
}
If you do it like that, you can't support "%s", since then you would
store only the pointer and not the whole string. I think, that we can't
live without %s.
Michael
-
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to [EMAIL PROTECTED]
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
Re: [RFC] New kernel-message logging API
Hi Vegard,
On Sat, 2007-09-22 at 21:27 +0200, Vegard Nossum wrote:
After recent discussions on LKML and a general dissatisfaction at the
current printk() kernel-message logging interface, I've decided to
write down some of the ideas for a better system.
Good luck :-)
[snip]
Example: {
struct kprint_buffer buf;
kprint_buffer_init(buf, KPRINT_DEBUG);
kprint_buffer(buf, Stack trace:);
while(unwind_stack()) {
kprint_buffer(buf, %p %s, address, symbol);
}
kprint_buffer_flush(buf);
}
Together with the idea of not allowing multiple lines in the kprint_xxx
functions, that would go with our approach having message numbers to
identify a message. Multiple lines are combined explicitly to one
message. I think it is a good idea to be able to identify, which lines
of a message belong together.
[snip]
With such a modular interface, message attributes (for example the
current time) and arguments can be recorded separately from the actual
format string, instead of written formatted to a ring buffer as a
sequence of characters. Parameters would be formatted to their own
strings (regardless of the original type) and saved in an array.
Example: {
struct kprint_message {
const char *format;
unsigned int argc;
char **argv;
#ifdef KPRINT_TIMESTAMP
unsigned long long timestamp;
#endif
#ifndef KPRINT_LOCATION
const char *file;
unsigned int line;
const char *function;
#endif
};
}
[snip]
The message entry and a message's arguments are kept separately. Most
likely, there will be a huge number of tiny allocations. I am not sure
how well this is handled in the kernel. Or we could try to merge the
allocation of the struct kprint_message and its arguments into a
single allocation by looking at the arguments before they're
formatted. After all, the arguments cannot exist without the message
or vice versa. Alternatively, a statically-sized ring buffer of struct
kprint_message objects could be used, and then only arguments would
need to be allocated dynamically. Either way, I think it should be
possible to come up with a fairly memory-efficient system even for
this method of storing the kernel log.
Would be nice to have some code here. How do you want to implement that?
You have to allocate / preallocate memory for the argv array. Something
like:
kprint_err(const char* fmt, ...)
{
va_list ap;
struct kprint_message *msg;
msg = message_arry[current];
va_start(ap, fmt);
msg-argv = kmalloc(sizeof(long) * argc, GFP_KERNEL);
...
for (i = 0; i argc, i++) {
msg-argv[i] = va_arg(ap, long);
}
If you do it like that, you can't support %s, since then you would
store only the pointer and not the whole string. I think, that we can't
live without %s.
Michael
-
To unsubscribe from this list: send the line unsubscribe linux-kernel in
the body of a message to [EMAIL PROTECTED]
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
Re: [RFC] New kernel-message logging API
On Mon, 2007-09-24 at 11:22 +0200, Michael Holzheu wrote: Together with the idea of not allowing multiple lines in the kprint_xxx functions, that would go with our approach having message numbers to identify a message. How does this equate/give message numbers? If you do it like that, you can't support %s, since then you would store only the pointer and not the whole string. I think, that we can't live without %s. long long would not work either. Perhaps it's better to scan the format string or indirect the printk formatting logic. Another possibility: An added pass between gcc preprocessor and compiler could compact or compress the format string without modifying the conversion specifications so __attribute__ ((format (printf)) would still work. printk could expand the compacted/compressed format. - To unsubscribe from this list: send the line unsubscribe linux-kernel in the body of a message to [EMAIL PROTECTED] More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
Re: [RFC] New kernel-message logging API
On 9/24/07, Joe Perches [EMAIL PROTECTED] wrote: On Mon, 2007-09-24 at 11:22 +0200, Michael Holzheu wrote: Together with the idea of not allowing multiple lines in the kprint_xxx functions, that would go with our approach having message numbers to identify a message. How does this equate/give message numbers? Storing the format-string separately allows us to hash THAT instead of the formatted (ie. console output) message. Since this will never change from message to message, it can be looked up in a table or whatever and allow user-space to do translations without for example regular expressions. I'm pretty sure this *would* be possible to do with existing printk(), but I'm betting it also wouldn't look very nice (i.e. hackery). If you do it like that, you can't support %s, since then you would store only the pointer and not the whole string. I think, that we can't live without %s. long long would not work either. Perhaps it's better to scan the format string or indirect the printk formatting logic. The idea was to not use snprintf() for the stored message, but have a printf-like function that instead writes the output of each format specifier to its own string (ie. each argument produces a new char* object). Also needed would be an additional function that reads the format string but uses the stored arguments. This turned out to be slightly harder than I assumed at first, though it's of course not impossible. The downside of this approach is of course the need to maintain normal vsnprintf() and new functions side by side, with little possibility of reusing the format parsing of vsnprintf(). I will follow up with some code to demonstrate as soon as I can. Vegard - To unsubscribe from this list: send the line unsubscribe linux-kernel in the body of a message to [EMAIL PROTECTED] More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
Re: [RFC] New kernel-message logging API
On Mon, 2007-09-24 at 18:43 +0200, Vegard Nossum wrote: Storing the format-string separately allows us to hash THAT instead of the formatted (ie. console output) message. Since this will never change from message to message, it can be looked up in a table or whatever and allow user-space to do translations without for example regular expressions. That hash will change with each linux version given the inevitable spelling fixes, message reformatting and such. I will follow up with some code to demonstrate as soon as I can. Looking forward to it. - To unsubscribe from this list: send the line unsubscribe linux-kernel in the body of a message to [EMAIL PROTECTED] More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
Re: [RFC] New kernel-message logging API
On Saturday, September 22, 2007 12:27 pm Vegard Nossum wrote:
enum kprint_loglevel {
KPRINT_EMERG, /* kprint_emerg() */
KPRINT_ALERT, /* kprint_alert() */
KPRINT_CRIT,/* kprint_crit() */
KPRINT_ERROR, /* kprint_error() and/or kprint_err() */
KPRINT_WARNING, /* kprint_warning() and/or kprint_warn() */
KPRINT_NOTICE, /* kprint_notice() */
KPRINT_INFO,/* kprint_info() */
KPRINT_DEBUG, /* kprint_debug() */
};
I wonder if all these levels are still needed (though I really like the
error/err warning/warn aliases, those always get me :).
It seems like fewer levels would make things easier on both kernel
developers and administrators; looking at current counts may help
figure out which ones could be combined (warning, very naive grep -r
data):
KERN_EMERG: 371
KERN_ALERT: 236
KERN_CRIT: 602
KERN_ERR: 11961
KERN_WARNING: 6463
KERN_NOTICE: 1142
KERN_INFO: 8491
KERN_DEBUG: 6125
So KERN_ERR is the most common by a pretty large margin, though it seems
to me that KERN_NOTICE, KERN_INFO and KERN_DEBUG are mostly redundant
and probably make up a majority of the SIMD FPU exception support was
enabled (as if I care) type messages. Likewise, ERR, ALERT, CRIT and
EMERG serve very similar purposes (i.e. something unrecoverable
occurred), maybe they could be condensed into one or two levels rather
than four? So that would drop us to three levels:
KERN_ERR /* something really bad happened, machine is dead or near so */
KERN_WARNING /* you really ought to know about this */
KERN_INFO /* no one but the kernel developer likely cares about this */
But maybe I'm just living in a dream world where then number of printks
the kernel spits out suddenly drops by 99% and only actually important
messages make it to my log...
Jesse
-
To unsubscribe from this list: send the line unsubscribe linux-kernel in
the body of a message to [EMAIL PROTECTED]
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
Re: [RFC] New kernel-message logging API
On 9/24/07, Joe Perches [EMAIL PROTECTED] wrote:
On Mon, 2007-09-24 at 18:43 +0200, Vegard Nossum wrote:
Storing the format-string separately allows us to hash THAT instead of
the formatted (ie. console output) message. Since this will never
change from message to message, it can be looked up in a table or
whatever and allow user-space to do translations without for example
regular expressions.
That hash will change with each linux version given the
inevitable spelling fixes, message reformatting and such.
But we can keep the old ones too. That shouldn't be much of a problem.
I mean, it probably wouldn't rely on a hash alone. The format string
itself can be compared with the translation database.
I will follow up with some code to demonstrate as soon as I can.
Looking forward to it.
Okay, so I have one huge file that does more or less what I want. The
main problem with this, as I see it, is that it largely duplicates
vsnprintf() from lib/vsprintf.c (minus the functions I coped verbatim
from the same file). This is bad because the job of maintaining that
is now doubled (or worse). Hopefully it won't change much in the
future either.
For now, the main() function is most important. This demonstrates that
what I want is in fact possible. printf() is now split in two --
args_printf_prepare() and args_snprintf(). The former takes your
arguments as you would pass them to any *printff() function, but only
converts your arguments (and stores them in a struct args). The latter
takes the format string and the stored struct args and puts the whole
thing in a buffer (just like snprintf()).
I know Gmail isn't too friendly with code formatting, but this is just
an example program anyway, so it shouldn't really matter. Also, a
disclaimer: Almost completely untested.
Vegard
#define _GNU_SOURCE
#include ctype.h
#include stdarg.h
#include stdint.h
#include stdio.h
#include stdlib.h
#include string.h
/* This was shamelessly copied form include/asm-generic/div64.h */
# define do_div(n,base) ({ \
uint32_t __base = (base); \
uint32_t __rem; \
__rem = ((uint64_t)(n)) % __base; \
(n) = ((uint64_t)(n)) / __base; \
__rem; \
})
/* This was shamelessly copied from lib/vsprintf.c */
static char* put_dec_trunc(char *buf, unsigned q)
{
unsigned d3, d2, d1, d0;
d1 = (q4) 0xf;
d2 = (q8) 0xf;
d3 = (q12);
d0 = 6*(d3 + d2 + d1) + (q 0xf);
q = (d0 * 0xcd) 11;
d0 = d0 - 10*q;
*buf++ = d0 + '0'; /* least significant digit */
d1 = q + 9*d3 + 5*d2 + d1;
if (d1 != 0) {
q = (d1 * 0xcd) 11;
d1 = d1 - 10*q;
*buf++ = d1 + '0'; /* next digit */
d2 = q + 2*d2;
if ((d2 != 0) || (d3 != 0)) {
q = (d2 * 0xd) 7;
d2 = d2 - 10*q;
*buf++ = d2 + '0'; /* next digit */
d3 = q + 4*d3;
if (d3 != 0) {
q = (d3 * 0xcd) 11;
d3 = d3 - 10*q;
*buf++ = d3 + '0'; /* next digit */
if (q != 0)
*buf++ = q + '0'; /* most sign. digit
*/
}
}
}
return buf;
}
static char* put_dec_full(char *buf, unsigned q)
{
unsigned d3, d2, d1, d0;
d1 = (q4) 0xf;
d2 = (q8) 0xf;
d3 = (q12);
d0 = 6*(d3 + d2 + d1) + (q 0xf);
q = (d0 * 0xcd) 11;
d0 = d0 - 10*q;
*buf++ = d0 + '0';
d1 = q + 9*d3 + 5*d2 + d1;
q = (d1 * 0xcd) 11;
d1 = d1 - 10*q;
*buf++ = d1 + '0';
d2 = q + 2*d2;
q = (d2 * 0xd) 7;
d2 = d2 - 10*q;
*buf++ = d2 + '0';
d3 = q + 4*d3;
q = (d3 * 0xcd) 11; /* - shorter code */
d3 = d3 - 10*q;
*buf++ = d3 + '0';
*buf++ = q + '0';
return buf;
}
static char* put_dec(char *buf, unsigned long long num)
{
while (1) {
unsigned rem;
if (num 10)
return put_dec_trunc(buf, num);
rem = do_div(num, 10);
buf = put_dec_full(buf, rem);
}
}
#define ZEROPAD 1 /* pad with zero */
#define SIGN2 /* unsigned/signed long */
#define PLUS4 /* show plus */
#define SPACE 8 /* space if plus */
Re: [RFC] New kernel-message logging API
On Monday 24 September 2007 10:19:16 am Joe Perches wrote: On Mon, 2007-09-24 at 11:22 +0200, Michael Holzheu wrote: Together with the idea of not allowing multiple lines in the kprint_xxx functions, that would go with our approach having message numbers to identify a message. How does this equate/give message numbers? I actively want to avoid giving message numbers. My interest is in selectively removing messages from the kernel to shrink the binary size (and NOT make it up in either a larger userspace utility to translate them, or else magic proprietary numbers you can only diagnose if you pay my support staff). An added pass between gcc preprocessor and compiler could compact or compress the format string without modifying the conversion specifications so __attribute__ ((format (printf)) would still work. This does not address my problem. Spitting out a proprietary hash code instead of a human readable message is not a solution for my use case. Rob -- One of my most productive days was throwing away 1000 lines of code. - Ken Thompson. - To unsubscribe from this list: send the line unsubscribe linux-kernel in the body of a message to [EMAIL PROTECTED] More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
Re: [RFC] New kernel-message logging API
On Mon, 2007-09-24 at 18:51 -0500, Rob Landley wrote: An added pass between gcc preprocessor and compiler could compact or compress the format string without modifying the conversion specifications so __attribute__ ((format (printf)) would still work. This does not address my problem. Spitting out a proprietary hash code instead of a human readable message is not a solution for my use case. What is your problem Rob? I think message numbers are difficult to produce from format strings. I think kernel version/file/func/line is enough to identify messages for normal use but not too useful for embedded. I think losslessly compressing, not hashing, the format string would be useful. The format string would be expanded by printk. The kernel size would be smaller and more easily fit in minimal RAM. Losslessly compressing the format strings probably won't reduce flash image size. cheers, Joe - To unsubscribe from this list: send the line unsubscribe linux-kernel in the body of a message to [EMAIL PROTECTED] More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
Re: [RFC] New kernel-message logging API
On Monday 24 September 2007 3:37:55 pm Vegard Nossum wrote: On 9/24/07, Joe Perches [EMAIL PROTECTED] wrote: On Mon, 2007-09-24 at 18:43 +0200, Vegard Nossum wrote: Storing the format-string separately allows us to hash THAT instead of the formatted (ie. console output) message. Since this will never change from message to message, it can be looked up in a table or whatever and allow user-space to do translations without for example regular expressions. That hash will change with each linux version given the inevitable spelling fixes, message reformatting and such. But we can keep the old ones too. That shouldn't be much of a problem. I mean, it probably wouldn't rely on a hash alone. The format string itself can be compared with the translation database. I point out that the thread started with a comment about how to _reduce_ bloat. Just sayin'. Rob -- One of my most productive days was throwing away 1000 lines of code. - Ken Thompson. - To unsubscribe from this list: send the line unsubscribe linux-kernel in the body of a message to [EMAIL PROTECTED] More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
Re: [RFC] New kernel-message logging API
On Monday 24 September 2007 7:10:32 pm Joe Perches wrote: On Mon, 2007-09-24 at 18:51 -0500, Rob Landley wrote: An added pass between gcc preprocessor and compiler could compact or compress the format string without modifying the conversion specifications so __attribute__ ((format (printf)) would still work. This does not address my problem. Spitting out a proprietary hash code instead of a human readable message is not a solution for my use case. What is your problem Rob? The single largest space savings in the existing -tiny patches comes from removing printk() calls and strings. I would like to be able to selectively do this based on severity level, which is information most existing printk() calls already have. I proposed a minimal change to how printk() works, allowing the compiler to remove unused code that wouldn't be below the displayed level of printk() anyway in the deployed product so wouldn't actually lose any output. The kernel image is usually already compressed in flash and decompressed to dram during boot. (Not always, sometimes it's run directly out of flash, but there's often a speed penalty for doing this, you have to set it up specially, and dram is cheaper than flash anyway.) This means recompressing it doesn't help save flash. If you want to save dram, have printk and associated strings be a function in a module that's demand loaded and unloaded again after each call. Then you can foist compression off on userspace, and we're already used to modules having to match a given kernel version exactly. Why come up with new infrastructure? Rob -- One of my most productive days was throwing away 1000 lines of code. - Ken Thompson. - To unsubscribe from this list: send the line unsubscribe linux-kernel in the body of a message to [EMAIL PROTECTED] More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
Re: [RFC] New kernel-message logging API
I don't know. Compare the following two lines: printk(KERN_INFO Message.\n); kprint_info(Message.); By dropping the lengthy macro (it's not like it's going to change while we're running anyway, so why not make it a part of the function name?) and the final newline, we actually end up with a net decrease in line length. Agreed. In fact, you may want to write a header that implements the kprint_ functions in terms of printk for out-of-core driver writers to incorporate into their code bases, so they can upgrade their API while maintaining backward compatibility. (If it were me, I'd also give it a very permissive license, like outright public domain, to encourage use.) I thought it would be nice to have something that looks familiar, since that would ease an eventual transition. klog is a valid alternative, but isn't kp a bit cryptic? Well, in context: kp_info(Message.); Even the kp_ prefix is actually pretty unnecessary. It's info and a human-readable string that make it recognizable as a log message. Another reason to keep it short is just that it's going to get typed a LOT. Anyway, just MHO. - To unsubscribe from this list: send the line unsubscribe linux-kernel in the body of a message to [EMAIL PROTECTED] More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
Re: [RFC] New kernel-message logging API
On 9/23/07, Miguel Ojeda [EMAIL PROTECTED] wrote: Nice. I would suggest having some kind of standard way to show the information on the screen/dmesg. I mean, instead of having plain lines being written to the log, having something very short like: Thanks for the idea. Is this something you want to (manually) insert in each printk, or would it be passed like a parameter? For the subsystem part, it might be possible to #define a subsystem name at the beginning of each file and have printing functions automatically use this. But otherwise, I think the usefulness of this is perhaps a little low compared to the effort needed (ie. for this to be useful, each and every printk of the kernel would need to be changed). Also notice, even in your examples, that most subsystems/drivers already prefix their messages to identify the source. Perhaps a better effort spent would be to go through the ones that are missing this source prefix and fix them? Vegard - To unsubscribe from this list: send the line unsubscribe linux-kernel in the body of a message to [EMAIL PROTECTED] More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
Re: [RFC] New kernel-message logging API
On Saturday 22 September 2007 2:27:29 pm Vegard Nossum wrote: > After recent discussions on LKML and a general dissatisfaction at the > current printk() kernel-message logging interface, I've decided to > write down some of the ideas for a better system. > > > Requirements > > > * Backwards compatibility with printk(), syslog(), etc. I.E. what we have now works just fine for what it does. > * Extensibility. Features like timestamping or file/line recording > [1] should be both selectable at compile-time and (if compiled in) at > run-time. That doesn't require changing the API. Allowing the compiler to eliminate messages below a threshold requires changing the API. > > API > === > > #define kprint(fmt, ...) > > The main part of the kprint interface should be the kprint() function. And then you propose not having a single kprint() function... > To support the different log-levels, there exists one kprint_*() > function for each log-level, for example kprint_info(). Why is this better than feeding the level in as an argument to the macro? > In order to print several related lines as one chunk, the emitter > should first allocate an object of the type struct kprint_buffer. You know, I'm pretty happy with a first pass that doesn't address this issue at all. Why bundle three unrelated problems into a single all-or-nothing pass? Rob -- "One of my most productive days was throwing away 1000 lines of code." - Ken Thompson. - To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to [EMAIL PROTECTED] More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
Re: [RFC] New kernel-message logging API
On Sun, 2007-09-23 at 10:45 +0200, Jan Engelhardt wrote:
> I'd rather fix up code to reduce its indent rather than
> trying microoptimizations at the function name level!
I think that's a different discussion.
You could fix some of them whenever you like.
$ egrep -r -l --include=*.c "^[[:cntrl:]]{6,}printk" *
cheers, Joe
-
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to [EMAIL PROTECTED]
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
Re: [RFC] New kernel-message logging API
On Sun, 2007-09-23 at 10:39 +0200, Vegard Nossum wrote:
> On 9/23/07, Joe Perches <[EMAIL PROTECTED]> wrote:
> > Given the number of 80 column zealots, character naming length
> > matters.
> I don't know. Compare the following two lines:
> printk(KERN_INFO "Message.\n");
> kprint_info("Message.");
The problem isn't printk(KERN_ to kprint_(.
The problems are the no level printk(foo)s to kprint_(foo)
and the pr_() to kprint_() translations.
> By dropping the lengthy macro (it's not like it's going to change
> while we're running anyway, so why not make it a part of the function
> name?) and the final newline, we actually end up with a net decrease
> in line length.
Which I do appreciate and think good.
> I thought it would be nice to have something that looks familiar,
> since that would ease an eventual transition. klog is a valid
> alternative, but isn't kp a bit cryptic?
Probably no more than pr_ is today.
cheers, Joe
-
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to [EMAIL PROTECTED]
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
Re: [RFC] New kernel-message logging API
On Sep 23 2007 11:20, Vegard Nossum wrote:
>> >printk(KERN_INFO "Message.\n");
>> >kprint_info("Message.");
>>
>> I'd rather fix up code to reduce its indent rather than
>> trying microoptimizations at the function name level!
>
>Well, that's a different discussion, really. Is fixing the body of
>[v]printk() enough?
I mean the bodies of functions calling printk. (where possible)
Like this:
diff --git a/fs/quota_v2.c b/fs/quota_v2.c
index c519a58..49e04e7 100644
--- a/fs/quota_v2.c
+++ b/fs/quota_v2.c
@@ -86,12 +86,12 @@ static int v2_write_file_info(struct super_block *sb, int
type)
dinfo.dqi_free_entry = cpu_to_le32(info->u.v2_i.dqi_free_entry);
size = sb->s_op->quota_write(sb, type, (char *),
sizeof(struct v2_disk_dqinfo), V2_DQINFOOFF);
- if (size != sizeof(struct v2_disk_dqinfo)) {
- printk(KERN_WARNING "Can't write info structure on device
%s.\n",
- sb->s_id);
- return -1;
- }
- return 0;
+ if (size == sizeof(struct v2_disk_dqinfo))
+ return 0;
+
+ printk(KERN_WARNING "Can't write info structure on device %s.\n",
+ sb->s_id);
+ return -1;
}
static void disk2memdqb(struct mem_dqblk *m, struct v2_disk_dqblk *d)
I gained 8 columns _without_ fiddling with the names.
-
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to [EMAIL PROTECTED]
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
Re: [RFC] New kernel-message logging API
On 9/23/07, Jan Engelhardt <[EMAIL PROTECTED]> wrote:
>
> On Sep 23 2007 10:39, Vegard Nossum wrote:
> >On 9/23/07, Joe Perches <[EMAIL PROTECTED]> wrote:
> >> On Sat, 2007-09-22 at 21:27 +0200, Vegard Nossum wrote:
> >> > #define kprint(fmt, ...)
> >>
> >> Good ideas. Perhaps a prefix of klog or kp_ instead?
> >> Given the number of 80 column zealots, character naming length matters.
> >
> >I don't know. Compare the following two lines:
> >
> >printk(KERN_INFO "Message.\n");
> >kprint_info("Message.");
> >
> >By dropping the lengthy macro (it's not like it's going to change
> >while we're running anyway, so why not make it a part of the function
> >name?) and the final newline, we actually end up with a net decrease
> >in line length.
> >
> >I thought it would be nice to have something that looks familiar,
> >since that would ease an eventual transition. klog is a valid
> >alternative, but isn't kp a bit cryptic?
>
> I'd rather fix up code to reduce its indent rather than
> trying microoptimizations at the function name level!
Well, that's a different discussion, really. Is fixing the body of
[v]printk() enough? I don't think it's possible if you want to do
everything that I described in my original post.
It's not even an optimization from my point of view; I think Joe
Perches was arguing that code should be kept short. I was arguing that
it's already shorter than with the current situation.
Vegard
-
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to [EMAIL PROTECTED]
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
Re: [RFC] New kernel-message logging API
On Sep 23 2007 10:39, Vegard Nossum wrote:
>On 9/23/07, Joe Perches <[EMAIL PROTECTED]> wrote:
>> On Sat, 2007-09-22 at 21:27 +0200, Vegard Nossum wrote:
>> > #define kprint(fmt, ...)
>>
>> Good ideas. Perhaps a prefix of klog or kp_ instead?
>> Given the number of 80 column zealots, character naming length matters.
>
>I don't know. Compare the following two lines:
>
>printk(KERN_INFO "Message.\n");
>kprint_info("Message.");
>
>By dropping the lengthy macro (it's not like it's going to change
>while we're running anyway, so why not make it a part of the function
>name?) and the final newline, we actually end up with a net decrease
>in line length.
>
>I thought it would be nice to have something that looks familiar,
>since that would ease an eventual transition. klog is a valid
>alternative, but isn't kp a bit cryptic?
I'd rather fix up code to reduce its indent rather than
trying microoptimizations at the function name level!
-
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to [EMAIL PROTECTED]
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
Re: [RFC] New kernel-message logging API
On 9/23/07, Joe Perches <[EMAIL PROTECTED]> wrote:
> On Sat, 2007-09-22 at 21:27 +0200, Vegard Nossum wrote:
> > #define kprint(fmt, ...)
>
> Good ideas. Perhaps a prefix of klog or kp_ instead?
> Given the number of 80 column zealots, character naming length matters.
I don't know. Compare the following two lines:
printk(KERN_INFO "Message.\n");
kprint_info("Message.");
By dropping the lengthy macro (it's not like it's going to change
while we're running anyway, so why not make it a part of the function
name?) and the final newline, we actually end up with a net decrease
in line length.
I thought it would be nice to have something that looks familiar,
since that would ease an eventual transition. klog is a valid
alternative, but isn't kp a bit cryptic?
Vegard
-
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to [EMAIL PROTECTED]
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
Re: [RFC] New kernel-message logging API
On 9/23/07, Joe Perches [EMAIL PROTECTED] wrote: On Sat, 2007-09-22 at 21:27 +0200, Vegard Nossum wrote: #define kprint(fmt, ...) Good ideas. Perhaps a prefix of klog or kp_ instead? Given the number of 80 column zealots, character naming length matters. I don't know. Compare the following two lines: printk(KERN_INFO Message.\n); kprint_info(Message.); By dropping the lengthy macro (it's not like it's going to change while we're running anyway, so why not make it a part of the function name?) and the final newline, we actually end up with a net decrease in line length. I thought it would be nice to have something that looks familiar, since that would ease an eventual transition. klog is a valid alternative, but isn't kp a bit cryptic? Vegard - To unsubscribe from this list: send the line unsubscribe linux-kernel in the body of a message to [EMAIL PROTECTED] More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
Re: [RFC] New kernel-message logging API
On Sep 23 2007 10:39, Vegard Nossum wrote: On 9/23/07, Joe Perches [EMAIL PROTECTED] wrote: On Sat, 2007-09-22 at 21:27 +0200, Vegard Nossum wrote: #define kprint(fmt, ...) Good ideas. Perhaps a prefix of klog or kp_ instead? Given the number of 80 column zealots, character naming length matters. I don't know. Compare the following two lines: printk(KERN_INFO Message.\n); kprint_info(Message.); By dropping the lengthy macro (it's not like it's going to change while we're running anyway, so why not make it a part of the function name?) and the final newline, we actually end up with a net decrease in line length. I thought it would be nice to have something that looks familiar, since that would ease an eventual transition. klog is a valid alternative, but isn't kp a bit cryptic? I'd rather fix up code to reduce its indent rather than trying microoptimizations at the function name level! - To unsubscribe from this list: send the line unsubscribe linux-kernel in the body of a message to [EMAIL PROTECTED] More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
Re: [RFC] New kernel-message logging API
On 9/23/07, Jan Engelhardt [EMAIL PROTECTED] wrote: On Sep 23 2007 10:39, Vegard Nossum wrote: On 9/23/07, Joe Perches [EMAIL PROTECTED] wrote: On Sat, 2007-09-22 at 21:27 +0200, Vegard Nossum wrote: #define kprint(fmt, ...) Good ideas. Perhaps a prefix of klog or kp_ instead? Given the number of 80 column zealots, character naming length matters. I don't know. Compare the following two lines: printk(KERN_INFO Message.\n); kprint_info(Message.); By dropping the lengthy macro (it's not like it's going to change while we're running anyway, so why not make it a part of the function name?) and the final newline, we actually end up with a net decrease in line length. I thought it would be nice to have something that looks familiar, since that would ease an eventual transition. klog is a valid alternative, but isn't kp a bit cryptic? I'd rather fix up code to reduce its indent rather than trying microoptimizations at the function name level! Well, that's a different discussion, really. Is fixing the body of [v]printk() enough? I don't think it's possible if you want to do everything that I described in my original post. It's not even an optimization from my point of view; I think Joe Perches was arguing that code should be kept short. I was arguing that it's already shorter than with the current situation. Vegard - To unsubscribe from this list: send the line unsubscribe linux-kernel in the body of a message to [EMAIL PROTECTED] More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
Re: [RFC] New kernel-message logging API
On Sep 23 2007 11:20, Vegard Nossum wrote:
printk(KERN_INFO Message.\n);
kprint_info(Message.);
I'd rather fix up code to reduce its indent rather than
trying microoptimizations at the function name level!
Well, that's a different discussion, really. Is fixing the body of
[v]printk() enough?
I mean the bodies of functions calling printk. (where possible)
Like this:
diff --git a/fs/quota_v2.c b/fs/quota_v2.c
index c519a58..49e04e7 100644
--- a/fs/quota_v2.c
+++ b/fs/quota_v2.c
@@ -86,12 +86,12 @@ static int v2_write_file_info(struct super_block *sb, int
type)
dinfo.dqi_free_entry = cpu_to_le32(info-u.v2_i.dqi_free_entry);
size = sb-s_op-quota_write(sb, type, (char *)dinfo,
sizeof(struct v2_disk_dqinfo), V2_DQINFOOFF);
- if (size != sizeof(struct v2_disk_dqinfo)) {
- printk(KERN_WARNING Can't write info structure on device
%s.\n,
- sb-s_id);
- return -1;
- }
- return 0;
+ if (size == sizeof(struct v2_disk_dqinfo))
+ return 0;
+
+ printk(KERN_WARNING Can't write info structure on device %s.\n,
+ sb-s_id);
+ return -1;
}
static void disk2memdqb(struct mem_dqblk *m, struct v2_disk_dqblk *d)
I gained 8 columns _without_ fiddling with the names.
-
To unsubscribe from this list: send the line unsubscribe linux-kernel in
the body of a message to [EMAIL PROTECTED]
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
Re: [RFC] New kernel-message logging API
On Sun, 2007-09-23 at 10:45 +0200, Jan Engelhardt wrote:
I'd rather fix up code to reduce its indent rather than
trying microoptimizations at the function name level!
I think that's a different discussion.
You could fix some of them whenever you like.
$ egrep -r -l --include=*.c ^[[:cntrl:]]{6,}printk *
cheers, Joe
-
To unsubscribe from this list: send the line unsubscribe linux-kernel in
the body of a message to [EMAIL PROTECTED]
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
Re: [RFC] New kernel-message logging API
On Sun, 2007-09-23 at 10:39 +0200, Vegard Nossum wrote: On 9/23/07, Joe Perches [EMAIL PROTECTED] wrote: Given the number of 80 column zealots, character naming length matters. I don't know. Compare the following two lines: printk(KERN_INFO Message.\n); kprint_info(Message.); The problem isn't printk(KERN_level to kprint_level(. The problems are the no level printk(foo)s to kprint_level(foo) and the pr_level() to kprint_level() translations. By dropping the lengthy macro (it's not like it's going to change while we're running anyway, so why not make it a part of the function name?) and the final newline, we actually end up with a net decrease in line length. Which I do appreciate and think good. I thought it would be nice to have something that looks familiar, since that would ease an eventual transition. klog is a valid alternative, but isn't kp a bit cryptic? Probably no more than pr_level is today. cheers, Joe - To unsubscribe from this list: send the line unsubscribe linux-kernel in the body of a message to [EMAIL PROTECTED] More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
Re: [RFC] New kernel-message logging API
On Saturday 22 September 2007 2:27:29 pm Vegard Nossum wrote: After recent discussions on LKML and a general dissatisfaction at the current printk() kernel-message logging interface, I've decided to write down some of the ideas for a better system. Requirements * Backwards compatibility with printk(), syslog(), etc. I.E. what we have now works just fine for what it does. * Extensibility. Features like timestamping or file/line recording [1] should be both selectable at compile-time and (if compiled in) at run-time. That doesn't require changing the API. Allowing the compiler to eliminate messages below a threshold requires changing the API. API === #define kprint(fmt, ...) The main part of the kprint interface should be the kprint() function. And then you propose not having a single kprint() function... To support the different log-levels, there exists one kprint_*() function for each log-level, for example kprint_info(). Why is this better than feeding the level in as an argument to the macro? In order to print several related lines as one chunk, the emitter should first allocate an object of the type struct kprint_buffer. You know, I'm pretty happy with a first pass that doesn't address this issue at all. Why bundle three unrelated problems into a single all-or-nothing pass? Rob -- One of my most productive days was throwing away 1000 lines of code. - Ken Thompson. - To unsubscribe from this list: send the line unsubscribe linux-kernel in the body of a message to [EMAIL PROTECTED] More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
Re: [RFC] New kernel-message logging API
On Sep 22, 2007, at 20:47:21, Joe Perches wrote:
On Sat, 2007-09-22 at 20:40 -0400, Kyle Moffett wrote:
Severity is *exactly* "desirability of logging".
Disagree.
What's info to someone is an alert to someone else. The problem is
the valuation of the reasoning.
It's all opinion.
For starters, I think "its all opinion" is bogus; the value of each
log level is pretty standardly defined for the kernel:
EMERG: The system is completely failing right NOW. Immediate admin
action is definitely required
ALERT: The system is about to fail or halfway-failing. Immediate
admin action may be required.
ERR: Something went badly wrong. We are able to continue without
endangering the overall system.
NOTICE: Something unusual happened but it's either not a device/code
failure or it's an expected failure.
INFO:Something useful happened, like a device probe or a major
system-wide event
DEBUG: Something happened that only a developer or somebody looking
for bugs would care about.
All of those are basically defined as: "This is how much the admin
probably wants to see this message". If you find a message which
doesn't seem to match the log level it's logged at, please submit a
patch.
Even assuming its not a bogus argument, what you actually want is
*NOT* "Show me INFO and DEBUG, but not EMERG, ALERT, ERR, or NOTICE",
you actually want multiple metrics by which to measure things. We
already have multiple ways of filtering log messages:
1) Log-level (greater than $LEVEL).
2) Userspace textual post-processing filters and classifiers (EG:
logcheck)
3) CONFIG_${SUBSYS}_DEBUG and CONFIG_${DRIVER}_DEBUG
Perhaps what you want is something like the syslog "facility" parameter?
The only real reason to add more kconfig options for logging is to
decrease the size of the kernel binary; most anything else can be
better done in userspace in something like logcheck. If you're going
to add new kconfig options then you aren't going to configure them
generically since they're inherently subsystem/driver specific. In
that case you might add a per-driver "CONFIG_${DRIVER}_NOLOG" for the
drivers you care about or a "CONFIG_MAX_LOG_LEVEL" to globally limit
by severity but any other qualifiers inherently don't fit in a single
scalar
Cheers,
Kyle Moffett
-
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to [EMAIL PROTECTED]
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
Re: [RFC] New kernel-message logging API
On 9/22/07, Vegard Nossum <[EMAIL PROTECTED]> wrote:
> After recent discussions on LKML and a general dissatisfaction at the
> current printk() kernel-message logging interface, I've decided to
> write down some of the ideas for a better system.
Nice. I would suggest having some kind of standard way to show the
information on the screen/dmesg. I mean, instead of having plain lines
being written to the log, having something very short like:
SSL: Message sent.
Being:
SS - Subsystem ("EA" for early code, "MM" for memory managment, "PU"
for processor stuff, "HD" for hard disks, "PP" for parallel port, "NT"
for networking, "VI" for video stuff, "FB" for framebuffers, "SN" for
sound stuff, "KE" for keyboard, "MO" for mouse, ... I think you get
the idea, just generic things).
L - Log level (0 for emerg, ..., 7 for debug)
And maybe some other character for other information. This would be
great to read pretty easily dmesg and for grepping, like:
$ dmesg | grep ^FB
for getting just information about framebuffers, or
$ dmesg | grep ^..[0123]
to get all the problems of the whole kernel/system.
So, for example, userspace scripts will be able to separate into
different log files the kernel stuff:
#!/bin/sh
dmesg | grep ^..[0123] > klog.errors
dmesg | grep ^NT > klog.networking
dmesg | grep ^HD > klog.harddisks
dmesg | grep ^FB > klog.framebuffers
Maybe its weird at first, but I think it will speed up the reading of
plain dmesg's outputs for everyone at the cost of 3-5 more characters
at every line in dmesg.
Also, it may help to make printk()'s messages to be more uniform,
instead of having every .c file having differents ways to express
similar things.
Getting more complex, lets add another character:
SSLR: Message sent.
being R the reason of the message (D for information about a
probed-and-detected hardware [like a PCI card], R for a new
succesfully registered device [like a framebuffer], S for new settings
in a device [like taking up a ethernet link, or that messages about
IRQs], C for copyright/about/info lines, ...).
Now we have at some dmesg (for example):
eth0: Broadcom 4400 10/100BaseT Ethernet 00:1f:a2:0c:4a:72
ieee80211_crypt: registered algorithm 'TKIP'
ipw3945: Intel(R) PRO/Wireless 3945 Network Connection 1.2.2d
ipw3945: Copyright(c) 2003-2006 Intel Corporation
ACPI: PCI Interrupt :0c:00.0[A] -> GSI 17 (level, low) -> IRQ 17
PCI: Setting latency timer of device :0c:00.0 to 64
ipw3945: Detected Intel PRO/Wireless 3945ABG Network Connection
ipw3945: Detected geography ABG (13 802.11bg channels, 23 802.11a channels)
usb 6-1: new low speed USB device using uhci_hcd and address 2
usb 6-1: configuration #1 chosen from 1 choice
usbcore: registered new interface driver hiddev
and we could have:
NT6R eth0: Broadcom 4400 10/100BaseT Ethernet 00:1f:a2:0c:4a:72
NT6R ieee80211_crypt: algorithm 'TKIP'
NT6C ipw3945: Intel(R) PRO/Wireless 3945 Network Connection driver 1.2.2d
NT7C ipw3945: Copyright(c) 2003-2006 Intel Corporation
XX6S ACPI: PCI Interrupt :0c:00.0[A] -> GSI 17 (level, low) -> IRQ 17
XX6S PCI: Latency timer of device :0c:00.0 to 64
NT6R ipw3945: Intel PRO/Wireless 3945ABG Network Connection
NT6D ipw3945: geography ABG (13 802.11bg channels, 23 802.11a channels)
US6R usb 6-1: low speed USB device using uhci_hcd and address 2
US6S usb 6-1: configuration #1 chosen from 1 choice
US6R usbcore: new interface driver hiddev
which I think its much more clear... Wanna know about registered
networking-related devices? Then grep using "^NT.R":
NT6R eth0: Broadcom 4400 10/100BaseT Ethernet 00:1f:a2:0c:4a:72
NT6R ieee80211_crypt: algorithm 'TKIP'
NT6R ipw3945: Intel PRO/Wireless 3945ABG Network Connection
...
Nothing more, thanks for reading :)
--
Miguel Ojeda
http://maxextreme.googlepages.com/index.htm
-
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to [EMAIL PROTECTED]
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
Re: [RFC] New kernel-message logging API
On Sat, 2007-09-22 at 20:40 -0400, Kyle Moffett wrote: > Severity is *exactly* "desirability of logging". Disagree. What's info to someone is an alert to someone else. The problem is the valuation of the reasoning. It's all opinion. cheers, Joe - To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to [EMAIL PROTECTED] More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
Re: [RFC] New kernel-message logging API
On Sep 22, 2007, at 20:13:03, Joe Perches wrote: On Sat, 2007-09-22 at 21:27 +0200, Vegard Nossum wrote: Additionally, this would allow the compiler to completely optimize out calls that are below a certain log-level severity level [2][3]. Severity doesn't really equate to desire to log. I'd prefer arbitrary control of log levels. Umm, actually... Severity is *exactly* "desirability of logging". If you find any place that's otherwise then please provide patches to fix it (or at least notify the maintainer with a useful bug report and reasoning. Cheers, Kyle Moffett - To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to [EMAIL PROTECTED] More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
Re: [RFC] New kernel-message logging API
On Sat, 2007-09-22 at 21:27 +0200, Vegard Nossum wrote: > #define kprint(fmt, ...) Good ideas. Perhaps a prefix of klog or kp_ instead? Given the number of 80 column zealots, character naming length matters. > Additionally, this would allow the compiler to completely optimize out > calls that are below a certain log-level severity level [2][3]. Severity doesn't really equate to desire to log. I'd prefer arbitrary control of log levels. cheers, Joe - To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to [EMAIL PROTECTED] More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
[RFC] New kernel-message logging API
After recent discussions on LKML and a general dissatisfaction at the
current printk() kernel-message logging interface, I've decided to
write down some of the ideas for a better system.
Requirements
* Backwards compatibility with printk(), syslog(), etc. There is no
way the whole kernel can be converted to a new interface in one go.
printk() is used all over the kernel, in many different ways,
including calls from assembly, multi-line prints spread over several
calls, etc.
* Extensibility. Features like timestamping or file/line recording
[1] should be both selectable at compile-time and (if compiled in) at
run-time.
API
===
#define kprint(fmt, ...)
The main part of the kprint interface should be the kprint() function.
The string must be a single line of information (ie. it must not
contain any newlines). Calling kprint("Hello world") is equivalent to
calling printk("Hello world\n"). kprint() may be implemented as a
macro, and must not be called from assembly.
To support the different log-levels, there exists one kprint_*()
function for each log-level, for example kprint_info(). The string
must be a single line of information. Calling kprint_emerg("Oops.") is
equivalent to calling printk(KERN_EMERG "Oops.\n"). These functions
may also be implemented as macros, and must also not be called from
assembly. The different log-levels (and their functions) are:
enum kprint_loglevel {
KPRINT_EMERG, /* kprint_emerg() */
KPRINT_ALERT, /* kprint_alert() */
KPRINT_CRIT,/* kprint_crit() */
KPRINT_ERROR, /* kprint_error() and/or kprint_err() */
KPRINT_WARNING, /* kprint_warning() and/or kprint_warn() */
KPRINT_NOTICE, /* kprint_notice() */
KPRINT_INFO,/* kprint_info() */
KPRINT_DEBUG, /* kprint_debug() */
};
In order to print several related lines as one chunk, the emitter
should first allocate an object of the type struct kprint_buffer. This
buffer is initialized with the function kprint_buffer_init() which
takes as arguments a pointer to an object of the type struct
kprint_buffer followed by the log-level number. The emitter may then
make as many or as few calls to kprint_buffer() that is desired.
kprint_buffer() is a function that takes a literal string followed by
a variable number of arguments, similarly to the kprint() function. A
final call to kprint_buffer_flush() appends the messages to the kernel
message log in a single, atomic call. After it has been flushed, the
buffer is not usable again (unless it is re-initialized). If for any
reason the buffer should be de-initialized without writing it to the
log, a call to kprint_buffer_abort() must be made.
Example: {
struct kprint_buffer buf;
kprint_buffer_init(, KPRINT_DEBUG);
kprint_buffer(, "Stack trace:");
while(unwind_stack()) {
kprint_buffer(, "%p %s", address, symbol);
}
kprint_buffer_flush();
}
It may happen that certain parts of the kernel might wish to emit
messages to the log (and console, if any) in an early part of the boot
procedure, for example before the main memory allocation routines have
been set up properly. For this purpose, a function kprint_early()
exists. This "early" is a minimal way for the kernel to log its
functions, and may as such not include all the features of the full
kprint system. When the kernel is beyond the critical "early" point,
the messages (if any) in the "early" log may be moved into the main
logging store and kprint_early() must not be used again.
kprint_early() is a function and may be called from assembly.
To allow non-early calls from assembly, a function kprint_asm()
exists. This function takes a log-level number followed by a string
literal followed by a variable number of arguments.
The then legacy printk() function must be replaced by a
backwards-compatible but different interface. In short, printk should
parse messages, remove (and convert) initial log-level tokens, remove
any newlines (splitting the string into several lines), and call the
apropriate kprint()-system functions.
Internals
=
The kprint() and its log-level variants are implemented as macros in
order to be able to transparently pass extra information into the main
kprint() machinery. As an example, it might happen that an extra
feature is added that prepends the current file and line (the __FILE__
and __LINE__ macros) to the message, but in such a way that it can be
discarded at run-time, or recorded along with the messages.
Additionally, this would allow the compiler to completely optimize out
calls that are below a certain log-level severity level [2][3].
With such a modular interface, message attributes (for example the
current time) and arguments can be recorded separately from the actual
format string, instead of written formatted to a ring buffer as a
sequence of characters. Parameters would be formatted to their own
strings (regardless of the original
[RFC] New kernel-message logging API
After recent discussions on LKML and a general dissatisfaction at the
current printk() kernel-message logging interface, I've decided to
write down some of the ideas for a better system.
Requirements
* Backwards compatibility with printk(), syslog(), etc. There is no
way the whole kernel can be converted to a new interface in one go.
printk() is used all over the kernel, in many different ways,
including calls from assembly, multi-line prints spread over several
calls, etc.
* Extensibility. Features like timestamping or file/line recording
[1] should be both selectable at compile-time and (if compiled in) at
run-time.
API
===
#define kprint(fmt, ...)
The main part of the kprint interface should be the kprint() function.
The string must be a single line of information (ie. it must not
contain any newlines). Calling kprint(Hello world) is equivalent to
calling printk(Hello world\n). kprint() may be implemented as a
macro, and must not be called from assembly.
To support the different log-levels, there exists one kprint_*()
function for each log-level, for example kprint_info(). The string
must be a single line of information. Calling kprint_emerg(Oops.) is
equivalent to calling printk(KERN_EMERG Oops.\n). These functions
may also be implemented as macros, and must also not be called from
assembly. The different log-levels (and their functions) are:
enum kprint_loglevel {
KPRINT_EMERG, /* kprint_emerg() */
KPRINT_ALERT, /* kprint_alert() */
KPRINT_CRIT,/* kprint_crit() */
KPRINT_ERROR, /* kprint_error() and/or kprint_err() */
KPRINT_WARNING, /* kprint_warning() and/or kprint_warn() */
KPRINT_NOTICE, /* kprint_notice() */
KPRINT_INFO,/* kprint_info() */
KPRINT_DEBUG, /* kprint_debug() */
};
In order to print several related lines as one chunk, the emitter
should first allocate an object of the type struct kprint_buffer. This
buffer is initialized with the function kprint_buffer_init() which
takes as arguments a pointer to an object of the type struct
kprint_buffer followed by the log-level number. The emitter may then
make as many or as few calls to kprint_buffer() that is desired.
kprint_buffer() is a function that takes a literal string followed by
a variable number of arguments, similarly to the kprint() function. A
final call to kprint_buffer_flush() appends the messages to the kernel
message log in a single, atomic call. After it has been flushed, the
buffer is not usable again (unless it is re-initialized). If for any
reason the buffer should be de-initialized without writing it to the
log, a call to kprint_buffer_abort() must be made.
Example: {
struct kprint_buffer buf;
kprint_buffer_init(buf, KPRINT_DEBUG);
kprint_buffer(buf, Stack trace:);
while(unwind_stack()) {
kprint_buffer(buf, %p %s, address, symbol);
}
kprint_buffer_flush(buf);
}
It may happen that certain parts of the kernel might wish to emit
messages to the log (and console, if any) in an early part of the boot
procedure, for example before the main memory allocation routines have
been set up properly. For this purpose, a function kprint_early()
exists. This early is a minimal way for the kernel to log its
functions, and may as such not include all the features of the full
kprint system. When the kernel is beyond the critical early point,
the messages (if any) in the early log may be moved into the main
logging store and kprint_early() must not be used again.
kprint_early() is a function and may be called from assembly.
To allow non-early calls from assembly, a function kprint_asm()
exists. This function takes a log-level number followed by a string
literal followed by a variable number of arguments.
The then legacy printk() function must be replaced by a
backwards-compatible but different interface. In short, printk should
parse messages, remove (and convert) initial log-level tokens, remove
any newlines (splitting the string into several lines), and call the
apropriate kprint()-system functions.
Internals
=
The kprint() and its log-level variants are implemented as macros in
order to be able to transparently pass extra information into the main
kprint() machinery. As an example, it might happen that an extra
feature is added that prepends the current file and line (the __FILE__
and __LINE__ macros) to the message, but in such a way that it can be
discarded at run-time, or recorded along with the messages.
Additionally, this would allow the compiler to completely optimize out
calls that are below a certain log-level severity level [2][3].
With such a modular interface, message attributes (for example the
current time) and arguments can be recorded separately from the actual
format string, instead of written formatted to a ring buffer as a
sequence of characters. Parameters would be formatted to their own
strings (regardless of the original type) and
Re: [RFC] New kernel-message logging API
On Sat, 2007-09-22 at 21:27 +0200, Vegard Nossum wrote: #define kprint(fmt, ...) Good ideas. Perhaps a prefix of klog or kp_ instead? Given the number of 80 column zealots, character naming length matters. Additionally, this would allow the compiler to completely optimize out calls that are below a certain log-level severity level [2][3]. Severity doesn't really equate to desire to log. I'd prefer arbitrary control of log levels. cheers, Joe - To unsubscribe from this list: send the line unsubscribe linux-kernel in the body of a message to [EMAIL PROTECTED] More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
Re: [RFC] New kernel-message logging API
On Sep 22, 2007, at 20:13:03, Joe Perches wrote: On Sat, 2007-09-22 at 21:27 +0200, Vegard Nossum wrote: Additionally, this would allow the compiler to completely optimize out calls that are below a certain log-level severity level [2][3]. Severity doesn't really equate to desire to log. I'd prefer arbitrary control of log levels. Umm, actually... Severity is *exactly* desirability of logging. If you find any place that's otherwise then please provide patches to fix it (or at least notify the maintainer with a useful bug report and reasoning. Cheers, Kyle Moffett - To unsubscribe from this list: send the line unsubscribe linux-kernel in the body of a message to [EMAIL PROTECTED] More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
Re: [RFC] New kernel-message logging API
On Sat, 2007-09-22 at 20:40 -0400, Kyle Moffett wrote: Severity is *exactly* desirability of logging. Disagree. What's info to someone is an alert to someone else. The problem is the valuation of the reasoning. It's all opinion. cheers, Joe - To unsubscribe from this list: send the line unsubscribe linux-kernel in the body of a message to [EMAIL PROTECTED] More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
Re: [RFC] New kernel-message logging API
On 9/22/07, Vegard Nossum [EMAIL PROTECTED] wrote: After recent discussions on LKML and a general dissatisfaction at the current printk() kernel-message logging interface, I've decided to write down some of the ideas for a better system. Nice. I would suggest having some kind of standard way to show the information on the screen/dmesg. I mean, instead of having plain lines being written to the log, having something very short like: SSL: Message sent. Being: SS - Subsystem (EA for early code, MM for memory managment, PU for processor stuff, HD for hard disks, PP for parallel port, NT for networking, VI for video stuff, FB for framebuffers, SN for sound stuff, KE for keyboard, MO for mouse, ... I think you get the idea, just generic things). L - Log level (0 for emerg, ..., 7 for debug) And maybe some other character for other information. This would be great to read pretty easily dmesg and for grepping, like: $ dmesg | grep ^FB for getting just information about framebuffers, or $ dmesg | grep ^..[0123] to get all the problems of the whole kernel/system. So, for example, userspace scripts will be able to separate into different log files the kernel stuff: #!/bin/sh dmesg | grep ^..[0123] klog.errors dmesg | grep ^NT klog.networking dmesg | grep ^HD klog.harddisks dmesg | grep ^FB klog.framebuffers Maybe its weird at first, but I think it will speed up the reading of plain dmesg's outputs for everyone at the cost of 3-5 more characters at every line in dmesg. Also, it may help to make printk()'s messages to be more uniform, instead of having every .c file having differents ways to express similar things. Getting more complex, lets add another character: SSLR: Message sent. being R the reason of the message (D for information about a probed-and-detected hardware [like a PCI card], R for a new succesfully registered device [like a framebuffer], S for new settings in a device [like taking up a ethernet link, or that messages about IRQs], C for copyright/about/info lines, ...). Now we have at some dmesg (for example): eth0: Broadcom 4400 10/100BaseT Ethernet 00:1f:a2:0c:4a:72 ieee80211_crypt: registered algorithm 'TKIP' ipw3945: Intel(R) PRO/Wireless 3945 Network Connection 1.2.2d ipw3945: Copyright(c) 2003-2006 Intel Corporation ACPI: PCI Interrupt :0c:00.0[A] - GSI 17 (level, low) - IRQ 17 PCI: Setting latency timer of device :0c:00.0 to 64 ipw3945: Detected Intel PRO/Wireless 3945ABG Network Connection ipw3945: Detected geography ABG (13 802.11bg channels, 23 802.11a channels) usb 6-1: new low speed USB device using uhci_hcd and address 2 usb 6-1: configuration #1 chosen from 1 choice usbcore: registered new interface driver hiddev and we could have: NT6R eth0: Broadcom 4400 10/100BaseT Ethernet 00:1f:a2:0c:4a:72 NT6R ieee80211_crypt: algorithm 'TKIP' NT6C ipw3945: Intel(R) PRO/Wireless 3945 Network Connection driver 1.2.2d NT7C ipw3945: Copyright(c) 2003-2006 Intel Corporation XX6S ACPI: PCI Interrupt :0c:00.0[A] - GSI 17 (level, low) - IRQ 17 XX6S PCI: Latency timer of device :0c:00.0 to 64 NT6R ipw3945: Intel PRO/Wireless 3945ABG Network Connection NT6D ipw3945: geography ABG (13 802.11bg channels, 23 802.11a channels) US6R usb 6-1: low speed USB device using uhci_hcd and address 2 US6S usb 6-1: configuration #1 chosen from 1 choice US6R usbcore: new interface driver hiddev which I think its much more clear... Wanna know about registered networking-related devices? Then grep using ^NT.R: NT6R eth0: Broadcom 4400 10/100BaseT Ethernet 00:1f:a2:0c:4a:72 NT6R ieee80211_crypt: algorithm 'TKIP' NT6R ipw3945: Intel PRO/Wireless 3945ABG Network Connection ... Nothing more, thanks for reading :) -- Miguel Ojeda http://maxextreme.googlepages.com/index.htm - To unsubscribe from this list: send the line unsubscribe linux-kernel in the body of a message to [EMAIL PROTECTED] More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
Re: [RFC] New kernel-message logging API
On Sep 22, 2007, at 20:47:21, Joe Perches wrote:
On Sat, 2007-09-22 at 20:40 -0400, Kyle Moffett wrote:
Severity is *exactly* desirability of logging.
Disagree.
What's info to someone is an alert to someone else. The problem is
the valuation of the reasoning.
It's all opinion.
For starters, I think its all opinion is bogus; the value of each
log level is pretty standardly defined for the kernel:
EMERG: The system is completely failing right NOW. Immediate admin
action is definitely required
ALERT: The system is about to fail or halfway-failing. Immediate
admin action may be required.
ERR: Something went badly wrong. We are able to continue without
endangering the overall system.
NOTICE: Something unusual happened but it's either not a device/code
failure or it's an expected failure.
INFO:Something useful happened, like a device probe or a major
system-wide event
DEBUG: Something happened that only a developer or somebody looking
for bugs would care about.
All of those are basically defined as: This is how much the admin
probably wants to see this message. If you find a message which
doesn't seem to match the log level it's logged at, please submit a
patch.
Even assuming its not a bogus argument, what you actually want is
*NOT* Show me INFO and DEBUG, but not EMERG, ALERT, ERR, or NOTICE,
you actually want multiple metrics by which to measure things. We
already have multiple ways of filtering log messages:
1) Log-level (greater than $LEVEL).
2) Userspace textual post-processing filters and classifiers (EG:
logcheck)
3) CONFIG_${SUBSYS}_DEBUG and CONFIG_${DRIVER}_DEBUG
Perhaps what you want is something like the syslog facility parameter?
The only real reason to add more kconfig options for logging is to
decrease the size of the kernel binary; most anything else can be
better done in userspace in something like logcheck. If you're going
to add new kconfig options then you aren't going to configure them
generically since they're inherently subsystem/driver specific. In
that case you might add a per-driver CONFIG_${DRIVER}_NOLOG for the
drivers you care about or a CONFIG_MAX_LOG_LEVEL to globally limit
by severity but any other qualifiers inherently don't fit in a single
scalar
Cheers,
Kyle Moffett
-
To unsubscribe from this list: send the line unsubscribe linux-kernel in
the body of a message to [EMAIL PROTECTED]
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
