From: Tetsuo Handa <penguin-kernel@i-love.sakura.ne.jp>
To: Sergey Senozhatsky <sergey.senozhatsky.work@gmail.com>
Cc: Petr Mladek <pmladek@suse.com>,
Dmitry Vyukov <dvyukov@google.com>,
Sergey Senozhatsky <sergey.senozhatsky.work@gmail.com>,
Sergey Senozhatsky <sergey.senozhatsky@gmail.com>,
Steven Rostedt <rostedt@goodmis.org>,
Linus Torvalds <torvalds@linux-foundation.org>,
Andrew Morton <akpm@linux-foundation.org>,
LKML <linux-kernel@vger.kernel.org>,
syzkaller <syzkaller@googlegroups.com>
Subject: Re: [PATCH] printk: Add caller information to printk() output.
Date: Fri, 07 Dec 2018 13:58:29 +0900 [thread overview]
Message-ID: <201812070458.wB74wTYu074308@www262.sakura.ne.jp> (raw)
In-Reply-To: <20181205115041.GB453@jagdpanzerIV>
Sergey Senozhatsky wrote:
> Do we need PIDs at all?
Yes. I don't like truncating caller information, for I think that PID is
used for not only reconstructing messages but also serving as a clue for
understanding what the process was doing.
> PIDs don't tell that much. When you are grepping serial log you can't
> actually tell if PID 15000 there and PID 15000 here, 200000 log lines
> apart, are same processes; or did PIDs wrap around? And you probably
> don't even care.
I don't care whether PIDs wrapped around. If the goal were to check whether PIDs
wrapped around, we would print "struct task_struct"->[real_]start_time together.
> All you need is a way to reconstruct a message around
> some very specific place in the log - say in a range [-500, +500] lines,
> assuming that a backtrace you are trying to reconstruct is badly fragmented.
> I think, even 3 lower digits of a PID should do the trick.
3 lower digits is insufficient for reconstructing PID of interest; it can
conflict at 1/1000 probability.
3 lower hexadecimal digits might be better but is insufficient; it can still
conflict at 1/4096.
3 lower base64 characters might be sufficient; it conflicts at only 1/262144.
4 base64 characters is sufficient, for 64*64*64*64 > PID_MAX_LIMIT.
But what do you feel from example output shown below? While no truncation of
caller information, it is hard for humans to understand.
----------------------------------------
@@ -1227,39 +1254,47 @@ static inline void boot_delay_msec(int level)
static bool printk_time = IS_ENABLED(CONFIG_PRINTK_TIME);
module_param_named(time, printk_time, bool, S_IRUGO | S_IWUSR);
-static size_t print_time(u64 ts, char *buf)
-{
- unsigned long rem_nsec = do_div(ts, 1000000000);
-
- if (!buf)
- return snprintf(NULL, 0, "[%5lu.000000] ", (unsigned long)ts);
-
- return sprintf(buf, "[%5lu.%06lu] ",
- (unsigned long)ts, rem_nsec / 1000);
-}
-
static size_t print_prefix(const struct printk_log *msg, bool syslog,
bool time, char *buf)
{
size_t len = 0;
- unsigned int prefix = (msg->facility << 3) | msg->level;
+ char tmp[PREFIX_MAX];
+ if (!buf)
+ buf = tmp;
if (syslog) {
- if (buf) {
- len += sprintf(buf, "<%u>", prefix);
- } else {
- len += 3;
- if (prefix > 999)
- len += 3;
- else if (prefix > 99)
- len += 2;
- else if (prefix > 9)
- len++;
- }
+ unsigned int prefix = (msg->facility << 3) | msg->level;
+
+ len += sprintf(buf, "<%u>", prefix);
}
+#ifdef CONFIG_PRINTK_FROM
+ buf[len++] = '[';
+ if (time) {
+ u64 ts = msg->ts_nsec;
+ unsigned long rem_nsec = do_div(ts, 1000000000);
- if (time)
- len += print_time(msg->ts_nsec, buf ? buf + len : NULL);
+ len += sprintf(buf + len, "%lu.%06lu", (unsigned long)ts,
+ rem_nsec / 1000);
+ }
+ {
+ static const char base64[64] = "ABCDEFGHIJKLMNOPQRSTUVWXYZ"
+ "abcdefghijklmnopqrstuvwxyz0123456789+/";
+ u32 id = msg->from_id;
+
+ len += sprintf(buf + len, "%c%c%c%c%c] ",
+ (id & 0x80000000 ? 'C' : 'T'),
+ base64[(id >> 18) & 63], base64[(id >> 12) & 63],
+ base64[(id >> 6) & 63], base64[id & 63]);
+ }
+#else
+ if (time) {
+ u64 ts = msg->ts_nsec;
+ unsigned long rem_nsec = do_div(ts, 1000000000);
+
+ len += sprintf(buf + len, "[%5lu.%06lu] ", (unsigned long)ts,
+ rem_nsec / 1000);
+ }
+#endif
return len;
}
----------------------------------------
----------------------------------------
[0.000000TAAAA] Disabled fast string operations
[1.023286TAAAB] Performance Events: Skylake events, core PMU driver.
[5.624742TAACc] systemd-fstab-g (156) used greatest stack depth: 13656 bytes left
[5.680184TAAA+] input: ImPS/2 Generic Wheel Mouse as /devices/platform/i8042/serio1/input/input3
[5.681783TAACb] dracut-rootfs-g (155) used greatest stack depth: 13640 bytes left
[9.299727TAAu+] ata8: SATA link down (SStatus 0 SControl 300)
[15.922239TABI/] e1000: ens32 NIC Link is Up 1000 Mbps Full Duplex, Flow Control: None
[15.923927TABYb] IPv6: ADDRCONF(NETDEV_UP): ens32: link is not ready
[15.930537TABI/] IPv6: ADDRCONF(NETDEV_CHANGE): ens32: link becomes ready
[40.506011CAAAA] random: crng init done
[926.716687TAAAB] reboot: Power down
----------------------------------------
After all, printing all digits without truncation will be the better.
next prev parent reply other threads:[~2018-12-07 5:01 UTC|newest]
Thread overview: 38+ messages / expand[flat|nested] mbox.gz Atom feed top
2018-11-24 7:37 [PATCH] printk: Add caller information to printk() output Tetsuo Handa
2018-11-30 15:40 ` Petr Mladek
2018-12-01 14:44 ` Tetsuo Handa
2018-12-02 11:23 ` Tetsuo Handa
2018-12-04 2:02 ` Sergey Senozhatsky
2018-12-04 10:16 ` Tetsuo Handa
2018-12-04 10:38 ` Sergey Senozhatsky
2018-12-04 15:31 ` Petr Mladek
2018-12-03 15:06 ` Petr Mladek
2018-12-03 21:10 ` Tetsuo Handa
2018-12-04 15:27 ` Petr Mladek
2018-12-05 10:42 ` Tetsuo Handa
2018-12-05 11:50 ` Sergey Senozhatsky
2018-12-07 4:58 ` Tetsuo Handa [this message]
2018-12-07 5:31 ` Sergey Senozhatsky
2018-12-10 13:09 ` Petr Mladek
2018-12-10 14:01 ` Tetsuo Handa
2018-12-11 10:26 ` Tetsuo Handa
2018-12-12 2:25 ` Sergey Senozhatsky
2018-12-12 2:29 ` Sergey Senozhatsky
2018-12-13 12:18 ` Petr Mladek
2018-12-13 12:42 ` Sergey Senozhatsky
2018-12-17 14:54 ` Petr Mladek
2018-12-17 15:40 ` Sergey Senozhatsky
2018-12-17 21:05 ` Tetsuo Handa
2018-12-18 8:39 ` Petr Mladek
2018-12-18 8:58 ` Sergey Senozhatsky
2019-01-02 16:09 ` Dmitry Vyukov
2019-01-03 18:27 ` Dmitry Vyukov
2019-01-04 7:33 ` Fengguang Wu
2019-01-11 19:34 ` Kevin Hilman
2019-01-10 11:27 ` Tetsuo Handa
2018-12-18 8:55 ` Sergey Senozhatsky
2018-12-18 10:01 ` Petr Mladek
2018-12-18 10:10 ` Sergey Senozhatsky
2019-03-21 2:59 ` Michael Ellerman
2019-03-21 10:20 ` Petr Mladek
2019-03-22 0:48 ` Michael Ellerman
Reply instructions:
You may reply publicly to this message via plain-text email
using any one of the following methods:
* Save the following mbox file, import it into your mail client,
and reply-to-all from there: mbox
Avoid top-posting and favor interleaved quoting:
https://en.wikipedia.org/wiki/Posting_style#Interleaved_style
* Reply using the --to, --cc, and --in-reply-to
switches of git-send-email(1):
git send-email \
--in-reply-to=201812070458.wB74wTYu074308@www262.sakura.ne.jp \
--to=penguin-kernel@i-love.sakura.ne.jp \
--cc=akpm@linux-foundation.org \
--cc=dvyukov@google.com \
--cc=linux-kernel@vger.kernel.org \
--cc=pmladek@suse.com \
--cc=rostedt@goodmis.org \
--cc=sergey.senozhatsky.work@gmail.com \
--cc=sergey.senozhatsky@gmail.com \
--cc=syzkaller@googlegroups.com \
--cc=torvalds@linux-foundation.org \
/path/to/YOUR_REPLY
https://kernel.org/pub/software/scm/git/docs/git-send-email.html
* If your mail client supports setting the In-Reply-To header
via mailto: links, try the mailto: link
Be sure your reply has a Subject: header at the top and a blank line
before the message body.
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).