Re: [RFC V2] printk: add warning while drop partial text in msg

2017-10-17 Thread pierre kuo
hi Petr and Sergey:
> I wonder what is the motivation for the extra buffering. Did you
> have troubles with direct printk() calls? For example, because
> of performance, mixed messages, deadlocks?

Yes, when using direct printk() calls, we suffer performance and mix
message issues.
(Since originally we try to collect the status of hardware and driver
at different places,
then use a work queue periodically for printk() the results of above
collections or
also do some simple analysis and calculation before printk().)

>
> Note that any buffering is potentially dangerous. You might miss
> the messages if the system dies before they are flushed. Also
> you might lose messages if the buffer is too small.
> You might go around this by flushing the buffer line by line.

Yes, you are right.
Except flushing the buffer line by line, we try to shrink the buffer size
to the number that plus prefix words will not over the size of
textbuf[], say 992 Bytes.
(that mean "size of buffer + 18*(number of "\n") < 992 Bytes")


> Well, it might get quite complicated, see printk_safe_flush_buffer().

BTW,  after checking printk_safe_flush_buffer() and related functions,
we have one question:
a) Why in printk_safe_log_store(), we need to use  atomic_ operation in it?
printk_safe_log_store() will be called in either one of below case
i) PRINTK_NMI_CONTEXT_MASK
ii) PRINTK_SAFE_CONTEXT_MASK
and each of them will bring each CPU's own nmi_print_seq or
safe_print_seq separately.
why it still need atomic_xxx operations like below *** show?

kernel/printk/printk_safe.c
-->static __printf(2, 0) int printk_safe_log_store(struct
printk_safe_seq_buf *s,
const char *fmt, va_list args)
{
int add;
size_t len;
again:
len = atomic_read(>len);  **


> Another question is if the buffering makes sense then.
We explained our initial thought above.

Appreciate you and Sergey's great comment and help,


Re: [RFC V2] printk: add warning while drop partial text in msg

2017-10-17 Thread pierre kuo
hi:
> There are several possible solutions:
>
> + We could update vprintk_emit() to detect all newlines and
>   call log_store() for each part. But this would be a waste
>   of the space.
>
> + We could increase the size provided by syslog_printk().
>   But this is ugly.
>
> + We could go back to the original idea and print a warning
>   about shrunken message when the first record is not fully
>   stored by msg_print_text().
>
> I think that the last solution is the best. Note that the
> original patch was wrong because it warned in any
> msg_print_text() and not only the first one.

Would you mind to let me know more about the wrong places you mean
about the patch?
(since I cannot quite understand the "warned in any msg_print_text()
and not only the first one" mean)

In Aug. 11, https://lkml.org/lkml/2017/8/10/707,
Only if below a) and b) are both true, the patch will try to put
warning message at the end of output buffer.
a) sizeof((the next phrase cut by "\n" token ) + prefix composed by
(level | facility | timestamp)) > left length of output buffer
b) (the left length of output buffer) > strlen ("");

so If any one of above a) or b) is not satisfied, there will be no
warning message.
Meanwhile, console_seq, clear_seq and syslog_seq will still increase
for next msg_print_text() run.
So the warning message will not always shows.

diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index fc47863..fcd1dd4 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -557,6 +557,7 @@ static u32 msg_used_size(u16 text_len, u16
dict_len, u32 *pad_len)
  */
 #define MAX_LOG_TAKE_PART 4
 static const char trunc_msg[] = "";
+static const char drop_msg[] = "";

 static u32 truncate_msg(u16 *text_len, u16 *trunc_msg_len,
u16 *dict_len, u32 *pad_len)
@@ -1264,8 +1265,14 @@ static size_t msg_print_text(const struct
printk_log *msg, bool syslog, char *bu

if (buf) {
if (print_prefix(msg, syslog, NULL) +
-   text_len + 1 >= size - len)
+   text_len + 1 >= size - len) {
+   /* below adding warning message
+* related information into output buffer
+*/
+   if ((size - len) > strlen(drop_msg))
+   memcpy(buf + len, drop_msg,
strlen(drop_msg));
break;
+   }

>Another question is that printk() is used a wrong way here.
>I will comment this in another mail in this thread.
please see my answer in another mail.


Re: [RFC V2] printk: add warning while drop partial text in msg

2017-09-27 Thread pierre kuo
hi:
> printk_deferred("%s", local_string[2048]) makes no sense anyway,
> since we limit the message size to 1024 - HEADER chars in
> vprintk_emit()  // see static char textbuf[LOG_LINE_MAX].

In local_string[2048], it will all be 0 from [590] to [2047].
And vprintk_emit() will cut message from [LOG_LINE_MAX(992)] to [2047].

so, from [0] to [589], whole messages are saved in msg->text as
expected, from "this is the 0 line\n" to "this is the 29 line\n"
No truncating happen in this stage.
(sorry for declaring local_string[] as 2048 makes people confused.)

Below is what msg->text saved:
560 + 30 = 590
^^  ^^^
 ||
 |--> 30 "\n"
 |
 --> 560 chars without "\n" from  "this is the 0 line" to "this is the 29 line"

Below is complete message size output from msg_print_text:
18*30 + 590 = 540 + 590 = 1130 Bytes
^ ^^^
  |   |
  |   --> 590 chars of msg->text
  |
  -->30 lines with each 18 chars in the prefix(15 for timesatmap and 3
for levle and facility)

Below is the constituents that msg_print_text sent to buf[1024]
(the size of buf, 1024, pass to msg_print_text is < 1130)
18*27 + 530= 486 + 530=  1016 Bytes
^ ^^^
  |   |
  |   -->max chars found by memchr with "\n" as copying unit
to meet the upper bound, 1024.
  |   (from "this is the 0 line" to "this is the 26 line")
  |
  --> 27 lines with each 18 character in the prefix

so characters left in msg->text not putting to the buffer are 590 -
530 = 60 chars.
(Truncate the message from "this is the 27 line\n" to "this is the 29 line\n".)

We use the example in this mail since we try to collect the message at
different places in our driver.
And batch to printk for saving individual output time and group
message together.

> I'm not quite following what were you trying to prove, sorry.
>does any function in the upstream kernel printk()-s buffers
>larger than LOG_LINE_MAX? which one?

You are correct.
The upstream kernel printk()-s buffers are indeed smaller LOG_LINE_MAX
and not with multi "\n" like this example did.

> we are straggling to resolve the _existing_ printk issues, so
> _theoretical_ and never seen problems are not on my radar.

Got it and really appreciate your kind explanation.


Re: [RFC V2] printk: add warning while drop partial text in msg

2017-09-12 Thread pierre kuo
hi Sergey and Petr
> Hi,
> On (08/11/17 00:55), pierre kuo wrote:
> [..]
>> And people will be hard to find out some part of message is left behind.
>> (since the tail of original message is elegantly dropped by "\n")
>> That is the reason I try to add such warning in msg_print_text.
>
> have you ever seen it (the truncation) in real life?
The experimental steps are list as follows.
Feel free to give your comments.

Prerequisite:
a) kernel version:
commit: a80099a152d0 ("Merge tag 'xfs-4.13-merge-6' of
git://git.kernel.org/pub/scm/fs/xfs/xfs-linux")

1. Add below patch in log_store to tell the content and length of log
that saved in log_text(msg) for below step #2 .
@@ -629,6 +629,11 @@ static int log_store(int facility, int level,
msg->len = size;

/* insert message */
+   if (msg->text_len > 512) {
+   trace_printk("%s\n", log_text(msg));
+   trace_printk("msg->text_len %d\n", msg->text_len);
+   }
+
log_next_idx += msg->len;
log_next_seq++;

2. Use below kernel thread sample for adding the string to msg.
int per_cpu_thread_fn(void* data)
{
unsigned int index = 0;
unsigned int len = 0;
char* local_string = kzalloc(2048, GFP_KERNEL);

do {
len += sprintf((local_string + len), "this is the %d line\n", index++);
}while(len < 576);
printk_deferred("%s", local_string);
return 0;
}

3. After running above #2, here is trace output from #1
(from the output, total "29 lines" of local_string has successfully
saved in log_buf)
# cat /sys/kernel/debug/tracing/trace;
# tracer: nop
#
#  _-=> irqs-off
# / _=> need-resched
#| / _---=> hardirq/softirq
#|| / _--=> preempt-depth
#||| / delay
#   TASK-PID   CPU#  TIMESTAMP  FUNCTION
#  | |   |      | |
  per_cpu_thread-81[000] d..126.555745: log_store: this is the 0 line
this is the 1 line
this is the 2 line
this is the 3 line
this is the 4 line
this is the 5 line
this is the 6 line
this is the 7 line
this is the 8 line
this is the 9 line
this is the 10 line
this is the 11 line
this is the 12 line
this is the 13 line
this is the 14 line
this is the 15 line
this is the 16 line
this is the 17 line
this is the 18 line
this is the 19 line
this is the 20 line
this is the 21 line
this is the 22 line
this is the 23 line
this is the 24 line
this is the 25 line
this is the 26 line
this is the 27 line
this is the 28 line
this is the 29 line
  per_cpu_thread-81[000] d..126.555753: log_store: msg->text_len 589

4. Write a user mode programs with buffer size 2MB, triple size bigger
than the text length in msg we saved in above #2, and repeatedly
calling SYSLOG_ACTION_READ for getting the log.
Then the log we got will _NOT_ show over than "this is the 26 line" as
below, that mean line#27 ~ line#29 are missing.
(the source is attached as "simple_log.tar.bz2")
<4>[   39.467710] this is the 0 line
<4>[   39.467710] this is the 1 line
<4>[   39.467710] this is the 2 line
<4>[   39.467710] this is the 3 line
<4>[   39.467710] this is the 4 line
<4>[   39.467710] this is the 5 line
<4>[   39.467710] this is the 6 line
<4>[   39.467710] this is the 7 line
<4>[   39.467710] this is the 8 line
<4>[   39.467710] this is the 9 line
<4>[   39.467710] this is the 10 line
<4>[   39.467710] this is the 11 line
<4>[   39.467710] this is the 12 line
<4>[   39.467710] this is the 13 line
<4>[   39.467710] this is the 14 line
<4>[   39.467710] this is the 15 line
<4>[   39.467710] this is the 16 line
<4>[   39.467710] this is the 17 line
<4>[   39.467710] this is the 18 line
<4>[   39.467710] this is the 19 line
<4>[   39.467710] this is the 20 line
<4>[   39.467710] this is the 21 line
<4>[   39.467710] this is the 22 line
<4>[   39.467710] this is the 23 line
<4>[   39.467710] this is the 24 line
<4>[   39.467710] this is the 25 line
<4>[   39.467710] this is the 26 line


simple_log.tar.bz2
Description: BZip2 compressed data


Re: [RFC V2] printk: add warning while drop partial text in msg

2017-08-10 Thread pierre kuo
hi Sergey:
(Please ignore previous mail, I apologize for pressing send button too early :)
>> this is not the only place that can truncate the message.
>> vprintk_emit() can do so as well /* vscnprintf() */. but
>> I think we don't care that much. a user likely will  notice
>> truncated messages. we report lost messages, because this
>> is a completely different sort of problem.
Usually people will more easily find message truncated from semantics
by vscnprintf, since it brute force truncate input message by the
upper limit of output buffer.

In msg_print_text, it use memchr to find "\n" as copying unit while
memcping msg->text to output buffer.
And people will be hard to find out some part of message is left behind.
(since the tail of original message is elegantly dropped by "\n")
That is the reason I try to add such warning in msg_print_text.

> your log_store(), invoked from msg_print_text(), will append the error
> message to the logbuf (tail), possibly far-far-far away from console_idx.
> so your "characters dropped" warning will appear much later.
Got ur point and thanks for your advising.

>>   len += print_prefix(msg, syslog, buf + len);
>>   memcpy(buf + len, text, text_len);
>
>
> but more importantly, msg_print_text() is called from several places. and
> can even be called from a user space, potentially triggering the same
> "" error log_store() over and over again, wiping out
> the actually important kernel messages. which is
> a) not nice
> and
> b) can be used to deliberately "hide" something really important.
>
how about we directly adding warning message in buffer instead of
log_store like below?
Appreciate your review and advising.

diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index fc47863..fcd1dd4 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -557,6 +557,7 @@ static u32 msg_used_size(u16 text_len, u16
dict_len, u32 *pad_len)
  */
 #define MAX_LOG_TAKE_PART 4
 static const char trunc_msg[] = "";
+static const char drop_msg[] = "";

 static u32 truncate_msg(u16 *text_len, u16 *trunc_msg_len,
u16 *dict_len, u32 *pad_len)
@@ -1264,8 +1265,14 @@ static size_t msg_print_text(const struct
printk_log *msg, bool syslog, char *bu

if (buf) {
if (print_prefix(msg, syslog, NULL) +
-   text_len + 1 >= size - len)
+   text_len + 1 >= size - len) {
+   /* below adding warning message
+* related information into output buffer
+*/
+   if ((size - len) > strlen(drop_msg))
+   memcpy(buf + len, drop_msg,
strlen(drop_msg));
break;
+   }

len += print_prefix(msg, syslog, buf + len);
memcpy(buf + len, text, text_len);


Re: [RFC V2] printk: add warning while drop partial text in msg

2017-08-10 Thread pierre kuo
hi Sergey
> this is not the only place that can truncate the message.
> vprintk_emit() can do so as well /* vscnprintf() */. but
> I think we don't care that much. a user likely will  notice
> truncated messages. we report lost messages, because this
> is a completely different sort of problem.
Usually people will more easily find message truncated from semantics
by vscnprintf,
since it brute force truncate input message by the upper limit of output buffer.

In msg_print_text, it use memchr to find "\n" as copying unit while
memcping msg->text to output buffer.
People will more difficultly to find out some part of message is left behind.
That is the reason I try to add such warning in msg_print_text.

>
>
> [..]
>> @@ -1264,8 +1270,23 @@ static size_t msg_print_text(const struct printk_log 
>> *msg, bool syslog, char *bu
>>
>>   if (buf) {
>>   if (print_prefix(msg, syslog, NULL) +
>> - text_len + 1 >= size - len)
>> + text_len + 1 >= size - len) {
>> + /* below stores dropped characters
>> +  * related information in next msg
>> +  */
>> + size_t drop_len;
>> +
>> + drop_len = scnprintf(drop_msg,
>> + MAX_DROP_MSG_LENGTH,
>> + "<%u characters dropped>",
>> + (next) ?
>> + (unsigned int)(text_size + next - 
>> text) :
>> + (unsigned int)text_size);
>> + drop_msg[drop_len] = 0;
>> + log_store(msg->facility, msg->level, 
>> msg->flags,
>> + 0, NULL, 0, drop_msg, 
>> strlen(drop_msg));
>>   break;
>> + }
>
> this change, most likely, will confuse people. because msg_print_text() is
> called on a message that is being currently processed, which is not
> necessarily the last message in the logbuf. for example, see console_unlock().
> we do something like this:
>
> while (console_seq != log_next_seq) {
> msg = log_from_idx(console_idx);
> msg_print_text(msg);
> console_idx = log_next(console_idx);
> console_seq++;
> }
>
> your log_store(), invoked from msg_print_text(), will append the error
> message to the logbuf (tail), possibly far-far-far away from console_idx.
> so your "characters dropped" warning will appear much later.
>
>
>>   len += print_prefix(msg, syslog, buf + len);
>>   memcpy(buf + len, text, text_len);
>
>
> but more importantly, msg_print_text() is called from several places. and
> can even be called from a user space, potentially triggering the same
> "" error log_store() over and over again, wiping out
> the actually important kernel messages. which is
> a) not nice
> and
> b) can be used to deliberately "hide" something really important.
>
>
> so, no. sorry, I don't like this change.
>
> -ss


[RFC V2] printk: add warning while drop partial text in msg

2017-07-30 Thread pierre Kuo
If the buffer pass to msg_print_text is not big enough to put both all
prefixes and log_text(msg), kernel will quietly break.
That means the user may not have the chance to know whether the
log_text(msg) is fully printed into buffer or not.

In this patch, once above case happened, we try to calculate how many
characters of log_text(msg) are dropped and add warning for debugging
purpose.

Signed-off-by: pierre Kuo <vichy@gmail.com>
---
Changes since v2:
 * fix typo in commit message from "waring for debugging purpose" to "warning 
for debugging purpose"

 kernel/printk/printk.c | 23 ++-
 1 file changed, 22 insertions(+), 1 deletion(-)

diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index fc47863..6cbb3699 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -558,6 +558,12 @@ static u32 msg_used_size(u16 text_len, u16 dict_len, u32 
*pad_len)
 #define MAX_LOG_TAKE_PART 4
 static const char trunc_msg[] = "";
 
+/*
+ * Define max drop msg length that we put in next msg
+ */
+#define MAX_DROP_MSG_LENGTH 32
+static char drop_msg[MAX_DROP_MSG_LENGTH];
+
 static u32 truncate_msg(u16 *text_len, u16 *trunc_msg_len,
u16 *dict_len, u32 *pad_len)
 {
@@ -1264,8 +1270,23 @@ static size_t msg_print_text(const struct printk_log 
*msg, bool syslog, char *bu
 
if (buf) {
if (print_prefix(msg, syslog, NULL) +
-   text_len + 1 >= size - len)
+   text_len + 1 >= size - len) {
+   /* below stores dropped characters
+* related information in next msg
+*/
+   size_t drop_len;
+
+   drop_len = scnprintf(drop_msg,
+   MAX_DROP_MSG_LENGTH,
+   "<%u characters dropped>",
+   (next) ?
+   (unsigned int)(text_size + next - text) 
:
+   (unsigned int)text_size);
+   drop_msg[drop_len] = 0;
+   log_store(msg->facility, msg->level, msg->flags,
+   0, NULL, 0, drop_msg, strlen(drop_msg));
break;
+   }
 
len += print_prefix(msg, syslog, buf + len);
memcpy(buf + len, text, text_len);
-- 
1.9.1



[RFC] printk: add warning while drop partial text in msg

2017-07-28 Thread pierre Kuo
If the buffer pass to msg_print_text is not big enough to put both all
prefixes and log_text(msg), kernel will quietly break.
That means the user may not have the chance to know whether the
log_text(msg) is fully printed into buffer or not.

In this patch, once above case happened, we try to calculate how many
characters of log_text(msg) are dropped and add waring for debugging
purpose.

Signed-off-by: pierre Kuo <vichy@gmail.com>
---
 kernel/printk/printk.c | 23 ++-
 1 file changed, 22 insertions(+), 1 deletion(-)

diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index fc47863..6cbb3699 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -558,6 +558,12 @@ static u32 msg_used_size(u16 text_len, u16 dict_len, u32 
*pad_len)
 #define MAX_LOG_TAKE_PART 4
 static const char trunc_msg[] = "";
 
+/*
+ * Define max drop msg length that we put in next msg
+ */
+#define MAX_DROP_MSG_LENGTH 32
+static char drop_msg[MAX_DROP_MSG_LENGTH];
+
 static u32 truncate_msg(u16 *text_len, u16 *trunc_msg_len,
u16 *dict_len, u32 *pad_len)
 {
@@ -1264,8 +1270,23 @@ static size_t msg_print_text(const struct printk_log 
*msg, bool syslog, char *bu
 
if (buf) {
if (print_prefix(msg, syslog, NULL) +
-   text_len + 1 >= size - len)
+   text_len + 1 >= size - len) {
+   /* below stores dropped characters
+* related information in next msg
+*/
+   size_t drop_len;
+
+   drop_len = scnprintf(drop_msg,
+   MAX_DROP_MSG_LENGTH,
+   "<%u characters dropped>",
+   (next) ?
+   (unsigned int)(text_size + next - text) 
:
+   (unsigned int)text_size);
+   drop_msg[drop_len] = 0;
+   log_store(msg->facility, msg->level, msg->flags,
+   0, NULL, 0, drop_msg, strlen(drop_msg));
break;
+   }
 
len += print_prefix(msg, syslog, buf + len);
memcpy(buf + len, text, text_len);
-- 
1.9.1



Re: [PATCH] printk: modify console_unlock with printk-safe macros

2017-07-17 Thread pierre kuo
hi Sergey and Andy:
> On (07/15/17 18:36), Pierre Kuo wrote:
> [..]
>> diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
>> index fc47863..21557cc 100644
>> --- a/kernel/printk/printk.c
>> +++ b/kernel/printk/printk.c
>> @@ -2194,8 +2194,7 @@ void console_unlock(void)
>>   size_t ext_len = 0;
>>   size_t len;
>>
>> - printk_safe_enter_irqsave(flags);
>> - raw_spin_lock(_lock);
>> + logbuf_lock_irqsave(flags);
>>   if (seen_seq != log_next_seq) {
>>   wake_klogd = true;
>>   seen_seq = log_next_seq;
>> @@ -2267,8 +2266,7 @@ void console_unlock(void)
>>*/
>>   raw_spin_lock(_lock);
>>   retry = console_seq != log_next_seq;
>> - raw_spin_unlock(_lock);
>> - printk_safe_exit_irqrestore(flags);
>> + logbuf_unlock_irqrestore(flags);
>>
>>   if (retry && console_trylock())
>>   goto again;
>
> I did it that particular way for a reason - console_unlock() does a
> bunch of tricks: unlocking logbuf in the middle of printing loop,
> breaking out of loop with local IRQs disabled, re-taking the logbuf
> after the loop still will local IRQs disabled, etc. etc. I didn't
> want to (and still don't) mix-in logbuf macros; we do things that
> macros don't cover anyway. sorry, I don't agree that the patch
> improves readability.
Got ur points and appreciate for your illustration. ^^
Thanks a lot,


[PATCH] printk: modify console_unlock with printk-safe macros

2017-07-15 Thread Pierre Kuo
From: pierre Kuo <vichy@gmail.com>

In commit de6fcbdb68b2 ("printk: convert the rest to printk-safe"), we
create 4 helper macros to make printk-safe usage easier.
Here we modify some part of console_unlock with above marcros.

Signed-off-by: Pierre Kuo <vichy@gmail.com>
---
 kernel/printk/printk.c |6 ++
 1 file changed, 2 insertions(+), 4 deletions(-)

diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index fc47863..21557cc 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -2194,8 +2194,7 @@ void console_unlock(void)
size_t ext_len = 0;
size_t len;
 
-   printk_safe_enter_irqsave(flags);
-   raw_spin_lock(_lock);
+   logbuf_lock_irqsave(flags);
if (seen_seq != log_next_seq) {
wake_klogd = true;
seen_seq = log_next_seq;
@@ -2267,8 +2266,7 @@ void console_unlock(void)
 */
raw_spin_lock(_lock);
retry = console_seq != log_next_seq;
-   raw_spin_unlock(_lock);
-   printk_safe_exit_irqrestore(flags);
+   logbuf_unlock_irqrestore(flags);
 
if (retry && console_trylock())
goto again;
-- 
1.7.9.5



[PATCH v2] printk: Modify operators of printed_len and text_len

2017-07-11 Thread Pierre Kuo
With commit  ("printk: report lost messages in printk
safe/nmi contexts") and commit <8b1742c9c207> ("printk: remove zap_locks()
function"), it seems we can remove initialization, "=0", of text_len and
directly assign result of log_output to printed_len.

Signed-off-by: Pierre Kuo <vichy@gmail.com>
Reviewed-by: Sergey Senozhatsky <sergey.senozhat...@gmail.com>
---
Changes since v2:
 * Per Petr's friendly reminder, add description of  ("printk: 
report lost messages in printk
safe/nmi contexts") and remove "=0", the initialization, of text_len.

 kernel/printk/printk.c |6 +++---
 1 file changed, 3 insertions(+), 3 deletions(-)

diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index fc47863..229fbdcb 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -1698,10 +1698,10 @@ asmlinkage int vprintk_emit(int facility, int level,
 {
static char textbuf[LOG_LINE_MAX];
char *text = textbuf;
-   size_t text_len = 0;
+   size_t text_len;
enum log_flags lflags = 0;
unsigned long flags;
-   int printed_len = 0;
+   int printed_len;
bool in_sched = false;
 
if (level == LOGLEVEL_SCHED) {
@@ -1754,7 +1754,7 @@ asmlinkage int vprintk_emit(int facility, int level,
if (dict)
lflags |= LOG_PREFIX|LOG_NEWLINE;
 
-   printed_len += log_output(facility, level, lflags, dict, dictlen, text, 
text_len);
+   printed_len = log_output(facility, level, lflags, dict, dictlen, text, 
text_len);
 
logbuf_unlock_irqrestore(flags);
 
-- 
1.7.9.5



Re: [PATCH] printk: Modify operators of printed_len

2017-07-10 Thread pierre kuo
hi Petr
> I just noticed that the same applies also to text_len
> variable. Well, it was caused by another commit ddb9baa822265b55
> ("printk: report lost messages in printk safe/nmi contexts").
> Could you please send a patch for this as well?
sure and it is my pleasure.

>
> This seems to be your first patch sent to the kernel mailing list.
Yes :-)

> There is a standard format how to reference older commits. It is
> 'commit <12+ chars of sha1> ("")', see my comment above
> for an example.
>
> A good practice is to run ./scripts/checkpatch.pl  before
> you send the patch. Well, you need to use a common sense and ignore
> false positives or hints that make a particular patch less readable
> in the end.
>
> Also it is handy to bump the version of the patch when it is
> updated, e.g. use [PATCH v2] in the subject. People also
> summarize changes against the previous version(s) below
> the --- line. Well, this is more useful when there is a longer
> delay between the versions and the changes are more complicated.
Really appreciate hints you provided and I will send the v2 patch soon.

Best Regards.


[PATCH] printk: Modify operators of printed_len

2017-07-07 Thread Pierre Kuo
In 8b1742c9c207, we remove printk-recursion detection code in
vprintk_emit(), where it is the first place that printed_len calculated.
After removing above detection, it seems we can directly assign the
result of log_output to printed_len.

Signed-off-by: Pierre Kuo <vichy@gmail.com>
---
 kernel/printk/printk.c |4 ++--
 1 file changed, 2 insertions(+), 2 deletions(-)

diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index fc47863..a2a8cac 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -1701,7 +1701,7 @@ asmlinkage int vprintk_emit(int facility, int level,
size_t text_len = 0;
enum log_flags lflags = 0;
unsigned long flags;
-   int printed_len = 0;
+   int printed_len;
bool in_sched = false;
 
if (level == LOGLEVEL_SCHED) {
@@ -1754,7 +1754,7 @@ asmlinkage int vprintk_emit(int facility, int level,
if (dict)
lflags |= LOG_PREFIX|LOG_NEWLINE;
 
-   printed_len += log_output(facility, level, lflags, dict, dictlen, text, 
text_len);
+   printed_len = log_output(facility, level, lflags, dict, dictlen, text, 
text_len);
 
logbuf_unlock_irqrestore(flags);
 
-- 
1.7.9.5



Re: [PATCH] printk: Modify operators of printed_len

2017-07-07 Thread pierre kuo
hi Joe
>> > []
>> > > diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
>> >
>> > []
>> > > @@ -1754,7 +1754,7 @@ asmlinkage int vprintk_emit(int facility, int 
>> > > level,
>> > >   if (dict)
>> > >   lflags |= LOG_PREFIX|LOG_NEWLINE;
>> > >
>> > > - printed_len += log_output(facility, level, lflags, dict, dictlen, 
>> > > text, text_len);
>> > > + printed_len = log_output(facility, level, lflags, dict, dictlen, 
>> > > text, text_len);
>> >
>> > If this is appropriate, this should also remove the
>> > initialization of printed_len and perhaps rename it too.
>>
>> I cannot quite understand the reason why need to rename.
>> printed_len seems meet the meaning we expect for here.
>
> Verbosity.  To me, len would be adequate.
>
> Anyway, the real point was the declaration of printed_len could
> remove the " = 0" as it's now only set once.
Got it and I will resend the patch again.

Appreciate your kind advice.


Re: [PATCH] printk: Modify operators of printed_len

2017-07-07 Thread pierre kuo
hi Joe:
2017-07-08 1:12 GMT+08:00 Joe Perches <j...@perches.com>:
> On Sat, 2017-07-08 at 00:30 +0800, Pierre Kuo wrote:
>> In 8b1742c9c207, we remove printk-recursion detection code in
>> vprintk_emit(), where it is the first place that printed_len calculated.
>> After removing above detection, it seems we can directly assign the
>> result of log_output to printed_len.
> []
>> diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
> []
>> @@ -1754,7 +1754,7 @@ asmlinkage int vprintk_emit(int facility, int level,
>>   if (dict)
>>   lflags |= LOG_PREFIX|LOG_NEWLINE;
>>
>> - printed_len += log_output(facility, level, lflags, dict, dictlen, 
>> text, text_len);
>> + printed_len = log_output(facility, level, lflags, dict, dictlen, text, 
>> text_len);
>
> If this is appropriate, this should also remove the
> initialization of printed_len and perhaps rename it too.
I cannot quite understand the reason why need to rename.
printed_len seems meet the meaning we expect for here.

thanks for your friendly comment.


[PATCH] printk: Modify operators of printed_len

2017-07-07 Thread Pierre Kuo
In 8b1742c9c207, we remove printk-recursion detection code in
vprintk_emit(), where it is the first place that printed_len calculated.
After removing above detection, it seems we can directly assign the
result of log_output to printed_len.

Signed-off-by: Pierre Kuo <vichy@gmail.com>
---
 kernel/printk/printk.c |2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/kernel/printk/printk.c b/kernel/printk/printk.c
index fc47863..16f3a61 100644
--- a/kernel/printk/printk.c
+++ b/kernel/printk/printk.c
@@ -1754,7 +1754,7 @@ asmlinkage int vprintk_emit(int facility, int level,
if (dict)
lflags |= LOG_PREFIX|LOG_NEWLINE;
 
-   printed_len += log_output(facility, level, lflags, dict, dictlen, text, 
text_len);
+   printed_len = log_output(facility, level, lflags, dict, dictlen, text, 
text_len);
 
logbuf_unlock_irqrestore(flags);
 
-- 
1.7.9.5