Re: [PATCH] [RFC] emit-crash-char: Allow diversion of printk output for crash logging
Tim Bird wrote: David VomLehn wrote: Our use case is: 1. We register a panic handler 2. The kernel panics and calls our panic handler 3. We register a function to log printk output 4. We print registers, stack, memory, and various other pieces of information using standard kernel functions, which all use printk 5. As printk output is generated, we store it in memory 6. We unregister the printk logging function 7. The panic handler exits 8. The kernel does the rest of its usual panic handling ... I'm not sure exactly what triggers the transition from step 5 to 6 in your steps above. That is, how do you know when to unregister the printk logging function? The printk logging function is unregistered when we are done printing everything we're interested in. But, taking a step back, instead of storing the information somewhere else, why not just use the log buffer as the storage medium, and transfer that all-at-once when you've collected the information you want? An interesting suggestion, but we've seen cases where the logging itself causes subsequent faults. In such cases, you would get nothing at all if you waited to store information until you've collected everything. A partial report, particularly if you've tried to print the most useful things first, is better than none at all. In addition, there is the risk that, for a particularly long report, you might wrap the log buffer and lose the first part of your output. -- David VomLehn -- To unsubscribe from this list: send the line "unsubscribe linux-embedded" in the body of a message to [EMAIL PROTECTED] More majordomo info at http://vger.kernel.org/majordomo-info.html
Re: [PATCH] [RFC] emit-crash-char: Allow diversion of printk output for crash logging
David VomLehn wrote: > Our use case is: > 1. We register a panic handler > 2. The kernel panics and calls our panic handler > 3. We register a function to log printk output > 4. We print registers, stack, memory, and various other pieces of >information using standard kernel functions, which all use printk > 5. As printk output is generated, we store it in memory > 6. We unregister the printk logging function > 7. The panic handler exits > 8. The kernel does the rest of its usual panic handling > > I'm not proposing storing the data in a specific place; that will be up > to the platform. We will be storing in a piece of memory set aside for > this purpose, but storing it in NOR flash makes a lot of sense, too, or > using NAND flash or possibly even disk. All I'm proposing is a small > framework that will allow plugging in a logging function when needed and > removing it when done. I'll do the common piece that looks like a fake > console and we, and other people, can use the simpler interface it > provides. I'm not sure exactly what triggers the transition from step 5 to 6 in your steps above. That is, how do you know when to unregister the printk logging function? But, taking a step back, instead of storing the information somewhere else, why not just use the log buffer as the storage medium, and transfer that all-at-once when you've collected the information you want? That is, change your steps to: 1. Register a panic handler 2. The kernel panics and calls our panic handler 3. Record the current position of the log buffer insertion point 4. Print registers, stack, memory, and various other pieces of information using standard kernel functions, which all use printk 5. As printk output is generated - it is stored by the kernel in the log buffer (no change to printk code is needed). ** (not sure what the trigger is to stop, here) ** 6. Record the current position of the log buffer, and transfer data logged between steps 3 and 6 to wherever you like. That is, copy it directly from the log buffer. 7. The panic handler exits 8. The kernel does the rest of its usual panic handling This reduces your intrusion to just your trigger points, and grabbing the log buffer position. (Side Note - the way the log buffer position is stored is a bit funky. It is an absolute value that monotonically increases, and is masked when used to refer to the buffer. This is why the log buffer size is constrained to a power of two). -- Tim = Tim Bird Architecture Group Chair, CE Linux Forum Senior Staff Engineer, Sony Corporation of America = -- To unsubscribe from this list: send the line "unsubscribe linux-embedded" in the body of a message to [EMAIL PROTECTED] More majordomo info at http://vger.kernel.org/majordomo-info.html
Re: [PATCH] [RFC] emit-crash-char: Allow diversion of printk output for crash logging
Grant Likely wrote: On Tue, Aug 12, 2008 at 06:30:54PM -0700, David VomLehn wrote: Regardless of implementation, it seems to me that it could be of use for some other embedded platforms. Any suggestions as to where it should go in the tree? drivers/char? drivers/misc? Depends on what you're storing to. Can you send more details about the specific use case that you will use this interface for? The system I'm working on is a settop box. It is in an environment where it is connected to a central server. The settop box doesn't have enough space to hold core dumps and the upstream connection to the server has too little bandwidth to upload them if we did store them. We have found that we can usually diagnose and fix problems with much less information than a core dump however, so we want to be able to capture that information and send it upstream. Our use case is: 1. We register a panic handler 2. The kernel panics and calls our panic handler 3. We register a function to log printk output 4. We print registers, stack, memory, and various other pieces of information using standard kernel functions, which all use printk 5. As printk output is generated, we store it in memory 6. We unregister the printk logging function 7. The panic handler exits 8. The kernel does the rest of its usual panic handling I'm not proposing storing the data in a specific place; that will be up to the platform. We will be storing in a piece of memory set aside for this purpose, but storing it in NOR flash makes a lot of sense, too, or using NAND flash or possibly even disk. All I'm proposing is a small framework that will allow plugging in a logging function when needed and removing it when done. I'll do the common piece that looks like a fake console and we, and other people, can use the simpler interface it provides. g. -- David VomLehn -- To unsubscribe from this list: send the line "unsubscribe linux-embedded" in the body of a message to [EMAIL PROTECTED] More majordomo info at http://vger.kernel.org/majordomo-info.html
Re: [PATCH] [RFC] emit-crash-char: Allow diversion of printk output for crash logging
On Tue, Aug 12, 2008 at 06:30:54PM -0700, David VomLehn wrote: > Grant Likely wrote: > >> I'm not thrilled with this patch. It seems so much more straight >> forward in your special case, but it comes at the expense of making >> the code path more complex in every other case. >> >> I would much rather see this be done using the existing console driver >> interface. The only possible reason I could see wanting to do things >> this way is if you don't trust the console code to call your console >> driver, which I think is a pretty unlikely case. > > I'll buy that reasoning. > > Regardless of implementation, it seems to me that it could be of use for > some other embedded platforms. Any suggestions as to where it should go > in the tree? drivers/char? drivers/misc? Depends on what you're storing to. Can you send more details about the specific use case that you will use this interface for? g. -- To unsubscribe from this list: send the line "unsubscribe linux-embedded" in the body of a message to [EMAIL PROTECTED] More majordomo info at http://vger.kernel.org/majordomo-info.html
Re: [PATCH] [RFC] emit-crash-char: Allow diversion of printk output for crash logging
Grant Likely wrote: I'm not thrilled with this patch. It seems so much more straight forward in your special case, but it comes at the expense of making the code path more complex in every other case. I would much rather see this be done using the existing console driver interface. The only possible reason I could see wanting to do things this way is if you don't trust the console code to call your console driver, which I think is a pretty unlikely case. I'll buy that reasoning. Regardless of implementation, it seems to me that it could be of use for some other embedded platforms. Any suggestions as to where it should go in the tree? drivers/char? drivers/misc? -- Grant Likely, B.Sc., P.Eng. Secret Lab Technologies Ltd. -- David VomLehn -- To unsubscribe from this list: send the line "unsubscribe linux-embedded" in the body of a message to [EMAIL PROTECTED] More majordomo info at http://vger.kernel.org/majordomo-info.html
Re: [PATCH] [RFC] emit-crash-char: Allow diversion of printk output for crash logging
On Mon, Aug 11, 2008 at 5:34 PM, David VomLehn <[EMAIL PROTECTED]> wrote:
>
> Daniel Walker wrote:
>>
>> On Thu, 2008-08-07 at 19:20 -0700, David VomLehn wrote:
>>>
>>> Allow diversion of characters generated through printk so that they can
>>> be logged separately. The printk_time variables is made externally visible
>>> so that functions processing the diverted characters can parse off the
>>> time added if CONFIG_PRINTK_TIME is enabled.
>>
>>> +
>>> static void emit_log_char(char c)
>>> {
>>> + emit_crash_char(c);
>>> +
>>>LOG_BUF(log_end) = c;
>>
>> Isn't this duplicating the making of a custom console driver? I'm not a
>> console expect, but I think you could have a console driver which
>> catches this output and logs it..
>
> Yes, you could, but this seems *so much* more straight-forward. Another
> option I
> considered was changing things so that the first level interface would simply
> output
> a character, possibly also passing some sort of context pointer. Then
> whatever was
> called by that interface could call a console driver, if appropriate. Even
> though I
> think this is really a cleaner way to do this, it also involves many more
> changes
> than I think are warranted just to get this little piece of functionality.
I'm not thrilled with this patch. It seems so much more straight
forward in your special case, but it comes at the expense of making
the code path more complex in every other case.
I would much rather see this be done using the existing console driver
interface. The only possible reason I could see wanting to do things
this way is if you don't trust the console code to call your console
driver, which I think is a pretty unlikely case.
g.
--
Grant Likely, B.Sc., P.Eng.
Secret Lab Technologies Ltd.
--
To unsubscribe from this list: send the line "unsubscribe linux-embedded" in
the body of a message to [EMAIL PROTECTED]
More majordomo info at http://vger.kernel.org/majordomo-info.html
Re: [PATCH] [RFC] emit-crash-char: Allow diversion of printk output for crash logging
Daniel Walker wrote:
On Thu, 2008-08-07 at 19:20 -0700, David VomLehn wrote:
Allow diversion of characters generated through printk so that they can
be logged separately. The printk_time variables is made externally visible
so that functions processing the diverted characters can parse off the
time added if CONFIG_PRINTK_TIME is enabled.
+
static void emit_log_char(char c)
{
+ emit_crash_char(c);
+
LOG_BUF(log_end) = c;
Isn't this duplicating the making of a custom console driver? I'm not a
console expect, but I think you could have a console driver which
catches this output and logs it..
Yes, you could, but this seems *so much* more straight-forward. Another option I
considered was changing things so that the first level interface would simply
output a character, possibly also passing some sort of context pointer. Then
whatever was called by that interface could call a console driver, if
appropriate. Even though I think this is really a cleaner way to do this, it also
involves many more changes than I think are warranted just to get this little
piece of functionality.
Another note, usually when submitting new interfaces like this you
should also submit the code that uses the interface .. In your case you
might not be able to do that, but it could never be accepted without at
least one user.
A highly valid criticism. I actually quoted your message to my management in
order to underscore how important it is that Cisco becomes a good open source
citizen. Personally, I view it as an absolute must.
Daniel
--
To unsubscribe from this list: send the line "unsubscribe linux-embedded" in
the body of a message to [EMAIL PROTECTED]
More majordomo info at http://vger.kernel.org/majordomo-info.html
Re: [PATCH] [RFC] emit-crash-char: Allow diversion of printk output for crash logging
On Fri, 2008-08-08 at 16:13 -0400, Mike Frysinger wrote: > same sort of things as the point of David's code. early/crash > scenarios for people to safely extract portions of the kernel log > buffer for transmission/storage elsewhere. as was explained in the > original thread behind the commit. How is that code suppose to help anyone if you aren't calling it from anyplace in the kernel? Clearly your using it, right? Where is the code your calling these functions from? Daniel -- To unsubscribe from this list: send the line "unsubscribe linux-embedded" in the body of a message to [EMAIL PROTECTED] More majordomo info at http://vger.kernel.org/majordomo-info.html
Re: [PATCH] [RFC] emit-crash-char: Allow diversion of printk output for crash logging
On Fri, Aug 8, 2008 at 4:10 PM, Daniel Walker wrote: > On Fri, 2008-08-08 at 14:09 -0400, Mike Frysinger wrote: >> > I invite you to give some of the "plenty of >> > examples in the tree", you might surprise me.. >> >> look at all the new syscalls added without any userspace code in place >> (still) to use it. or Linus' recent printk modifier extension. or my >> printk extensions for extracting portions of the kernel log buffer. >> people usually submit interfaces with backend extesions, or the intent >> to use it is obvious. > > Syscalls and Userspace are unrelated .. You clearly can't add userspace > code to the kernel .. If you add a _kernel_ interface like David has > done you need at least one user of the interface.. Otherwise it's just > plain bloat inside the kernel which no one wants. > > Your changes for extracting part of the kernel log buffer (commit > 0b15d04af3dd996035d8fa81fc849d049171f9c3), > > with: > textdata bss dec hex filename > 4322000 386760 2592768 7301528 6f6998 vmlinux > without: > textdata bss dec hex filename > 4321876 386760 2592768 7301404 6f691c vmlinux > > Adds roughly 120bytes of bloat to my kernel, since 2007 .. What's the > point? I grepped for users , and there are none .. same sort of things as the point of David's code. early/crash scenarios for people to safely extract portions of the kernel log buffer for transmission/storage elsewhere. as was explained in the original thread behind the commit. -mike -- To unsubscribe from this list: send the line "unsubscribe linux-embedded" in the body of a message to [EMAIL PROTECTED] More majordomo info at http://vger.kernel.org/majordomo-info.html
Re: [PATCH] [RFC] emit-crash-char: Allow diversion of printk output for crash logging
On Fri, 2008-08-08 at 14:09 -0400, Mike Frysinger wrote: > you said "usually people submit new interfaces", not "it is usually > not accepted without at least one user". Well, usually people do submit the users, and if they don't it's usually not accepted.. > > I invite you to give some of the "plenty of > > examples in the tree", you might surprise me.. > > look at all the new syscalls added without any userspace code in place > (still) to use it. or Linus' recent printk modifier extension. or my > printk extensions for extracting portions of the kernel log buffer. > people usually submit interfaces with backend extesions, or the intent > to use it is obvious. Syscalls and Userspace are unrelated .. You clearly can't add userspace code to the kernel .. If you add a _kernel_ interface like David has done you need at least one user of the interface.. Otherwise it's just plain bloat inside the kernel which no one wants. Your changes for extracting part of the kernel log buffer (commit 0b15d04af3dd996035d8fa81fc849d049171f9c3), with: textdata bss dec hex filename 4322000 386760 2592768 7301528 6f6998 vmlinux without: textdata bss dec hex filename 4321876 386760 2592768 7301404 6f691c vmlinux Adds roughly 120bytes of bloat to my kernel, since 2007 .. What's the point? I grepped for users , and there are none .. Daniel -- To unsubscribe from this list: send the line "unsubscribe linux-embedded" in the body of a message to [EMAIL PROTECTED] More majordomo info at http://vger.kernel.org/majordomo-info.html
Re: [PATCH] [RFC] emit-crash-char: Allow diversion of printk output for crash logging
On Fri, Aug 8, 2008 at 12:17 PM, Daniel Walker wrote: > On Fri, 2008-08-08 at 12:05 -0400, Mike Frysinger wrote: >> On Fri, Aug 8, 2008 at 11:55 AM, Daniel Walker wrote: >> > Another note, usually when submitting new interfaces like this you >> > should also submit the code that uses the interface .. In your case you >> > might not be able to do that, but it could never be accepted without at >> > least one user. >> >> i really doubt that. lack of existing tangible users makes it a >> harder case, but it certainly is not a "never" case. there is plenty >> of examples in the tree where things were merged without any users and >> the commit wouldnt be immediately leveraged. > > Well, I did say "usually" .. you said "usually people submit new interfaces", not "it is usually not accepted without at least one user". > I invite you to give some of the "plenty of > examples in the tree", you might surprise me.. look at all the new syscalls added without any userspace code in place (still) to use it. or Linus' recent printk modifier extension. or my printk extensions for extracting portions of the kernel log buffer. people usually submit interfaces with backend extesions, or the intent to use it is obvious. -mike -- To unsubscribe from this list: send the line "unsubscribe linux-embedded" in the body of a message to [EMAIL PROTECTED] More majordomo info at http://vger.kernel.org/majordomo-info.html
Re: [PATCH] [RFC] emit-crash-char: Allow diversion of printk output for crash logging
On Fri, 2008-08-08 at 12:05 -0400, Mike Frysinger wrote: > On Fri, Aug 8, 2008 at 11:55 AM, Daniel Walker wrote: > > Another note, usually when submitting new interfaces like this you > > should also submit the code that uses the interface .. In your case you > > might not be able to do that, but it could never be accepted without at > > least one user. > > i really doubt that. lack of existing tangible users makes it a > harder case, but it certainly is not a "never" case. there is plenty > of examples in the tree where things were merged without any users and > the commit wouldnt be immediately leveraged. Well, I did say "usually" .. I invite you to give some of the "plenty of examples in the tree", you might surprise me.. Daniel -- To unsubscribe from this list: send the line "unsubscribe linux-embedded" in the body of a message to [EMAIL PROTECTED] More majordomo info at http://vger.kernel.org/majordomo-info.html
Re: [PATCH] [RFC] emit-crash-char: Allow diversion of printk output for crash logging
On Fri, Aug 8, 2008 at 11:55 AM, Daniel Walker wrote: > Another note, usually when submitting new interfaces like this you > should also submit the code that uses the interface .. In your case you > might not be able to do that, but it could never be accepted without at > least one user. i really doubt that. lack of existing tangible users makes it a harder case, but it certainly is not a "never" case. there is plenty of examples in the tree where things were merged without any users and the commit wouldnt be immediately leveraged. -mike -- To unsubscribe from this list: send the line "unsubscribe linux-embedded" in the body of a message to [EMAIL PROTECTED] More majordomo info at http://vger.kernel.org/majordomo-info.html
Re: [PATCH] [RFC] emit-crash-char: Allow diversion of printk output for crash logging
On Thu, 2008-08-07 at 19:20 -0700, David VomLehn wrote:
> Allow diversion of characters generated through printk so that they can
> be logged separately. The printk_time variables is made externally visible
> so that functions processing the diverted characters can parse off the
> time added if CONFIG_PRINTK_TIME is enabled.
> +
> static void emit_log_char(char c)
> {
> + emit_crash_char(c);
> +
> LOG_BUF(log_end) = c;
Isn't this duplicating the making of a custom console driver? I'm not a
console expect, but I think you could have a console driver which
catches this output and logs it..
Another note, usually when submitting new interfaces like this you
should also submit the code that uses the interface .. In your case you
might not be able to do that, but it could never be accepted without at
least one user.
Daniel
--
To unsubscribe from this list: send the line "unsubscribe linux-embedded" in
the body of a message to [EMAIL PROTECTED]
More majordomo info at http://vger.kernel.org/majordomo-info.html
[PATCH] [RFC] emit-crash-char: Allow diversion of printk output for crash logging
Allow diversion of characters generated through printk so that they can
be logged separately. The printk_time variables is made externally visible
so that functions processing the diverted characters can parse off the
time added if CONFIG_PRINTK_TIME is enabled.
Signed-off-by: David VomLehn <[EMAIL PROTECTED]>
---
I apologize for the crufty disclaimer Cisco adds. It is on a long list on
things that make us awkward open source community members but things change
slowly at many large companies.
Rationale for this patch: The ability to divert characters is useful for
embedded systems when a panic occurs. It is frequently the case that there
is insufficient storage to hold a crash dump and too little, if any, upstream
network bandwith to upload a dump if one could be stored. Instead, we rely upon
the report written to the console for most of our debugging. The ability to
capture that report and either store it or send it upstream is a fundamental
part of our ability to support our systems in the lab and in the field.
include/linux/kernel.h |5
kernel/printk.c| 56 ++-
2 files changed, 59 insertions(+), 2 deletions(-)
diff --git a/include/linux/kernel.h b/include/linux/kernel.h
index aaa998f..1848260 100644
--- a/include/linux/kernel.h
+++ b/include/linux/kernel.h
@@ -200,6 +200,8 @@ extern struct ratelimit_state printk_ratelimit_state;
extern int printk_ratelimit(void);
extern bool printk_timed_ratelimit(unsigned long *caller_jiffies,
unsigned int interval_msec);
+extern void register_emit_crash_char(void (*fn)(char c));
+extern void unregister_emit_crash_char(void);
#else
static inline int vprintk(const char *s, va_list args)
__attribute__ ((format (printf, 1, 0)));
@@ -211,6 +213,8 @@ static inline int printk_ratelimit(void) { return 0; }
static inline bool printk_timed_ratelimit(unsigned long *caller_jiffies, \
unsigned int interval_msec) \
{ return false; }
+static inline void register_emit_crash_char(void (*fn)(char c)) {}
+static inline void unregister_emit_crash_char() {}
#endif
extern void asmlinkage __attribute__((format(printf, 1, 2)))
@@ -229,6 +233,7 @@ static inline void console_verbose(void)
console_loglevel = 15;
}
+extern int printk_time;
extern void bust_spinlocks(int yes);
extern void wake_up_klogd(void);
extern int oops_in_progress;/* If set, an oops, panic(), BUG() or
die() is in progress */
diff --git a/kernel/printk.c b/kernel/printk.c
index b51b156..35a4d81 100644
--- a/kernel/printk.c
+++ b/kernel/printk.c
@@ -67,6 +67,9 @@ int console_printk[4] = {
int oops_in_progress;
EXPORT_SYMBOL(oops_in_progress);
+static void (*emit_crash_char_fn)(char c);
+static bool recursive_emit_crash_char;
+
/*
* console_sem protects the console_drivers list, and also
* provides serialisation for access to the entire console
@@ -520,8 +523,35 @@ static void call_console_drivers(unsigned start, unsigned
end)
_call_console_drivers(start_print, end, msg_level);
}
+/*
+ * This emits a character intended for a crash log. We take special care
+ * to avoid recursive use so that we don't end up in an crash reporting loop.
+ */
+static void emit_crash_char(char c)
+{
+ static bool in_call;
+
+ if (emit_crash_char_fn != NULL) {
+ /* Detect recursive calls and ignore them. This could happen
+* if the function we use to emit the character to the crash
+* log failed and called printk. Though we ignore the output,
+* we remember that we had a recursive call so that we can
+* report it later. */
+ if (in_call)
+ recursive_emit_crash_char = true;
+
+ else {
+ in_call = true;
+ emit_crash_char_fn(c);
+ in_call = false;
+ }
+ }
+}
+
static void emit_log_char(char c)
{
+ emit_crash_char(c);
+
LOG_BUF(log_end) = c;
log_end++;
if (log_end - log_start > log_buf_len)
@@ -533,6 +563,28 @@ static void emit_log_char(char c)
}
/*
+ * Register a function to emit a crash character
+ * @fn:Function to register
+ */
+void register_emit_crash_char(void (*fn)(char c))
+{
+ emit_crash_char_fn = fn;
+}
+
+/*
+ * Unregister a function emiting a crash character
+ */
+void unregister_emit_crash_char()
+{
+ emit_crash_char_fn = NULL;
+
+ if (recursive_emit_crash_char) {
+ pr_err("emit_crash_char was called recursively!\n");
+ recursive_emit_crash_char = false;
+ }
+}
+
+/*
* Zap console related locks when oopsing. Only zap at most once
* every 10 seconds, to leave time for slow consoles to print a
* full oops.
@@ -554,9 +606,9 @@ static void zap_locks(void)
}
#if defined(CONFIG_PRINTK_TIME)
-static int printk_time = 1;
+
