Commit 70333f4f authored by Petr Mladek's avatar Petr Mladek

Merge branch 'printk-rework' into for-linus

parents 4e797e6e 0463d04e
......@@ -170,57 +170,103 @@ document trapinfo
address the kernel panicked.
end
define dump_log_idx
set $idx = $arg0
if ($argc > 1)
set $prev_flags = $arg1
define dump_record
set var $desc = $arg0
set var $info = $arg1
if ($argc > 2)
set var $prev_flags = $arg2
else
set $prev_flags = 0
set var $prev_flags = 0
end
set $msg = ((struct printk_log *) (log_buf + $idx))
set $prefix = 1
set $newline = 1
set $log = log_buf + $idx + sizeof(*$msg)
# prev & LOG_CONT && !(msg->flags & LOG_PREIX)
if (($prev_flags & 8) && !($msg->flags & 4))
set $prefix = 0
set var $prefix = 1
set var $newline = 1
set var $begin = $desc->text_blk_lpos.begin % (1U << prb->text_data_ring.size_bits)
set var $next = $desc->text_blk_lpos.next % (1U << prb->text_data_ring.size_bits)
# handle data-less record
if ($begin & 1)
set var $text_len = 0
set var $log = ""
else
# handle wrapping data block
if ($begin > $next)
set var $begin = 0
end
# skip over descriptor id
set var $begin = $begin + sizeof(long)
# handle truncated message
if ($next - $begin < $info->text_len)
set var $text_len = $next - $begin
else
set var $text_len = $info->text_len
end
set var $log = &prb->text_data_ring.data[$begin]
end
# prev & LOG_CONT && !(info->flags & LOG_PREIX)
if (($prev_flags & 8) && !($info->flags & 4))
set var $prefix = 0
end
# msg->flags & LOG_CONT
if ($msg->flags & 8)
# info->flags & LOG_CONT
if ($info->flags & 8)
# (prev & LOG_CONT && !(prev & LOG_NEWLINE))
if (($prev_flags & 8) && !($prev_flags & 2))
set $prefix = 0
set var $prefix = 0
end
# (!(msg->flags & LOG_NEWLINE))
if (!($msg->flags & 2))
set $newline = 0
# (!(info->flags & LOG_NEWLINE))
if (!($info->flags & 2))
set var $newline = 0
end
end
if ($prefix)
printf "[%5lu.%06lu] ", $msg->ts_nsec / 1000000000, $msg->ts_nsec % 1000000000
printf "[%5lu.%06lu] ", $info->ts_nsec / 1000000000, $info->ts_nsec % 1000000000
end
if ($msg->text_len != 0)
eval "printf \"%%%d.%ds\", $log", $msg->text_len, $msg->text_len
if ($text_len)
eval "printf \"%%%d.%ds\", $log", $text_len, $text_len
end
if ($newline)
printf "\n"
end
if ($msg->dict_len > 0)
set $dict = $log + $msg->text_len
set $idx = 0
set $line = 1
while ($idx < $msg->dict_len)
if ($line)
printf " "
set $line = 0
end
set $c = $dict[$idx]
# handle dictionary data
set var $dict = &$info->dev_info.subsystem[0]
set var $dict_len = sizeof($info->dev_info.subsystem)
if ($dict[0] != '\0')
printf " SUBSYSTEM="
set var $idx = 0
while ($idx < $dict_len)
set var $c = $dict[$idx]
if ($c == '\0')
loop_break
else
if ($c < ' ' || $c >= 127 || $c == '\\')
printf "\\x%02x", $c
else
printf "%c", $c
end
end
set var $idx = $idx + 1
end
printf "\n"
set $line = 1
end
set var $dict = &$info->dev_info.device[0]
set var $dict_len = sizeof($info->dev_info.device)
if ($dict[0] != '\0')
printf " DEVICE="
set var $idx = 0
while ($idx < $dict_len)
set var $c = $dict[$idx]
if ($c == '\0')
loop_break
else
if ($c < ' ' || $c >= 127 || $c == '\\')
printf "\\x%02x", $c
......@@ -228,33 +274,46 @@ define dump_log_idx
printf "%c", $c
end
end
set $idx = $idx + 1
set var $idx = $idx + 1
end
printf "\n"
end
end
document dump_log_idx
Dump a single log given its index in the log buffer. The first
parameter is the index into log_buf, the second is optional and
specified the previous log buffer's flags, used for properly
formatting continued lines.
document dump_record
Dump a single record. The first parameter is the descriptor,
the second parameter is the info, the third parameter is
optional and specifies the previous record's flags, used for
properly formatting continued lines.
end
define dmesg
set $i = log_first_idx
set $end_idx = log_first_idx
set $prev_flags = 0
# definitions from kernel/printk/printk_ringbuffer.h
set var $desc_committed = 1
set var $desc_finalized = 2
set var $desc_sv_bits = sizeof(long) * 8
set var $desc_flags_shift = $desc_sv_bits - 2
set var $desc_flags_mask = 3 << $desc_flags_shift
set var $id_mask = ~$desc_flags_mask
set var $desc_count = 1U << prb->desc_ring.count_bits
set var $prev_flags = 0
set var $id = prb->desc_ring.tail_id.counter
set var $end_id = prb->desc_ring.head_id.counter
while (1)
set $msg = ((struct printk_log *) (log_buf + $i))
if ($msg->len == 0)
set $i = 0
else
dump_log_idx $i $prev_flags
set $i = $i + $msg->len
set $prev_flags = $msg->flags
set var $desc = &prb->desc_ring.descs[$id % $desc_count]
set var $info = &prb->desc_ring.infos[$id % $desc_count]
# skip non-committed record
set var $state = 3 & ($desc->state_var.counter >> $desc_flags_shift)
if ($state == $desc_committed || $state == $desc_finalized)
dump_record $desc $info $prev_flags
set var $prev_flags = $info->flags
end
if ($i == $end_idx)
set var $id = ($id + 1) & $id_mask
if ($id == $end_id)
loop_break
end
end
......
......@@ -189,50 +189,123 @@ from this.
Free areas descriptor. User-space tools use this value to iterate the
free_area ranges. MAX_ORDER is used by the zone buddy allocator.
log_first_idx
prb
---
A pointer to the printk ringbuffer (struct printk_ringbuffer). This
may be pointing to the static boot ringbuffer or the dynamically
allocated ringbuffer, depending on when the the core dump occurred.
Used by user-space tools to read the active kernel log buffer.
printk_rb_static
----------------
A pointer to the static boot printk ringbuffer. If @prb has a
different value, this is useful for viewing the initial boot messages,
which may have been overwritten in the dynamically allocated
ringbuffer.
clear_seq
---------
The sequence number of the printk() record after the last clear
command. It indicates the first record after the last
SYSLOG_ACTION_CLEAR, like issued by 'dmesg -c'. Used by user-space
tools to dump a subset of the dmesg log.
printk_ringbuffer
-----------------
The size of a printk_ringbuffer structure. This structure contains all
information required for accessing the various components of the
kernel log buffer.
(printk_ringbuffer, desc_ring|text_data_ring|dict_data_ring|fail)
-----------------------------------------------------------------
Offsets for the various components of the printk ringbuffer. Used by
user-space tools to view the kernel log buffer without requiring the
declaration of the structure.
prb_desc_ring
-------------
Index of the first record stored in the buffer log_buf. Used by
user-space tools to read the strings in the log_buf.
The size of the prb_desc_ring structure. This structure contains
information about the set of record descriptors.
log_buf
-------
(prb_desc_ring, count_bits|descs|head_id|tail_id)
-------------------------------------------------
Offsets for the fields describing the set of record descriptors. Used
by user-space tools to be able to traverse the descriptors without
requiring the declaration of the structure.
prb_desc
--------
The size of the prb_desc structure. This structure contains
information about a single record descriptor.
(prb_desc, info|state_var|text_blk_lpos|dict_blk_lpos)
------------------------------------------------------
Offsets for the fields describing a record descriptors. Used by
user-space tools to be able to read descriptors without requiring
the declaration of the structure.
prb_data_blk_lpos
-----------------
The size of the prb_data_blk_lpos structure. This structure contains
information about where the text or dictionary data (data block) is
located within the respective data ring.
(prb_data_blk_lpos, begin|next)
-------------------------------
Console output is written to the ring buffer log_buf at index
log_first_idx. Used to get the kernel log.
Offsets for the fields describing the location of a data block. Used
by user-space tools to be able to locate data blocks without
requiring the declaration of the structure.
log_buf_len
printk_info
-----------
log_buf's length.
The size of the printk_info structure. This structure contains all
the meta-data for a record.
clear_idx
---------
(printk_info, seq|ts_nsec|text_len|dict_len|caller_id)
------------------------------------------------------
The index that the next printk() record to read after the last clear
command. It indicates the first record after the last SYSLOG_ACTION
_CLEAR, like issued by 'dmesg -c'. Used by user-space tools to dump
the dmesg log.
Offsets for the fields providing the meta-data for a record. Used by
user-space tools to be able to read the information without requiring
the declaration of the structure.
log_next_idx
------------
prb_data_ring
-------------
The index of the next record to store in the buffer log_buf. Used to
compute the index of the current buffer position.
The size of the prb_data_ring structure. This structure contains
information about a set of data blocks.
printk_log
----------
(prb_data_ring, size_bits|data|head_lpos|tail_lpos)
---------------------------------------------------
The size of a structure printk_log. Used to compute the size of
messages, and extract dmesg log. It encapsulates header information for
log_buf, such as timestamp, syslog level, etc.
Offsets for the fields describing a set of data blocks. Used by
user-space tools to be able to access the data blocks without
requiring the declaration of the structure.
(printk_log, ts_nsec|len|text_len|dict_len)
-------------------------------------------
atomic_long_t
-------------
The size of the atomic_long_t structure. Used by user-space tools to
be able to copy the full structure, regardless of its
architecture-specific implementation.
(atomic_long_t, counter)
------------------------
It represents field offsets in struct printk_log. User space tools
parse it and check whether the values of printk_log's members have been
changed.
Offset for the long value of an atomic_long_t variable. Used by
user-space tools to access the long value without requiring the
architecture-specific declaration.
(free_area.free_list, MIGRATE_TYPES)
------------------------------------
......
......@@ -13838,6 +13838,7 @@ PRINTK
M: Petr Mladek <pmladek@suse.com>
M: Sergey Senozhatsky <sergey.senozhatsky@gmail.com>
R: Steven Rostedt <rostedt@goodmis.org>
R: John Ogness <john.ogness@linutronix.de>
S: Maintained
F: include/linux/printk.h
F: kernel/printk/
......
......@@ -3835,22 +3835,21 @@ void device_shutdown(void)
*/
#ifdef CONFIG_PRINTK
static int
create_syslog_header(const struct device *dev, char *hdr, size_t hdrlen)
static void
set_dev_info(const struct device *dev, struct dev_printk_info *dev_info)
{
const char *subsys;
size_t pos = 0;
memset(dev_info, 0, sizeof(*dev_info));
if (dev->class)
subsys = dev->class->name;
else if (dev->bus)
subsys = dev->bus->name;
else
return 0;
return;
pos += snprintf(hdr + pos, hdrlen - pos, "SUBSYSTEM=%s", subsys);
if (pos >= hdrlen)
goto overflow;
strscpy(dev_info->subsystem, subsys, sizeof(dev_info->subsystem));
/*
* Add device identifier DEVICE=:
......@@ -3866,41 +3865,28 @@ create_syslog_header(const struct device *dev, char *hdr, size_t hdrlen)
c = 'b';
else
c = 'c';
pos++;
pos += snprintf(hdr + pos, hdrlen - pos,
"DEVICE=%c%u:%u",
c, MAJOR(dev->devt), MINOR(dev->devt));
snprintf(dev_info->device, sizeof(dev_info->device),
"%c%u:%u", c, MAJOR(dev->devt), MINOR(dev->devt));
} else if (strcmp(subsys, "net") == 0) {
struct net_device *net = to_net_dev(dev);
pos++;
pos += snprintf(hdr + pos, hdrlen - pos,
"DEVICE=n%u", net->ifindex);
snprintf(dev_info->device, sizeof(dev_info->device),
"n%u", net->ifindex);
} else {
pos++;
pos += snprintf(hdr + pos, hdrlen - pos,
"DEVICE=+%s:%s", subsys, dev_name(dev));
snprintf(dev_info->device, sizeof(dev_info->device),
"+%s:%s", subsys, dev_name(dev));
}
if (pos >= hdrlen)
goto overflow;
return pos;
overflow:
dev_WARN(dev, "device/subsystem name too long");
return 0;
}
int dev_vprintk_emit(int level, const struct device *dev,
const char *fmt, va_list args)
{
char hdr[128];
size_t hdrlen;
struct dev_printk_info dev_info;
hdrlen = create_syslog_header(dev, hdr, sizeof(hdr));
set_dev_info(dev, &dev_info);
return vprintk_emit(0, level, hdrlen ? hdr : NULL, hdrlen, fmt, args);
return vprintk_emit(0, level, &dev_info, fmt, args);
}
EXPORT_SYMBOL(dev_vprintk_emit);
......
......@@ -53,6 +53,9 @@ phys_addr_t paddr_vmcoreinfo_note(void);
#define VMCOREINFO_OFFSET(name, field) \
vmcoreinfo_append_str("OFFSET(%s.%s)=%lu\n", #name, #field, \
(unsigned long)offsetof(struct name, field))
#define VMCOREINFO_TYPE_OFFSET(name, field) \
vmcoreinfo_append_str("OFFSET(%s.%s)=%lu\n", #name, #field, \
(unsigned long)offsetof(name, field))
#define VMCOREINFO_LENGTH(name, value) \
vmcoreinfo_append_str("LENGTH(%s)=%lu\n", #name, (unsigned long)value)
#define VMCOREINFO_NUMBER(name) \
......
......@@ -21,6 +21,14 @@
struct device;
#define PRINTK_INFO_SUBSYSTEM_LEN 16
#define PRINTK_INFO_DEVICE_LEN 48
struct dev_printk_info {
char subsystem[PRINTK_INFO_SUBSYSTEM_LEN];
char device[PRINTK_INFO_DEVICE_LEN];
};
#ifdef CONFIG_PRINTK
__printf(3, 0) __cold
......
......@@ -161,10 +161,12 @@ static inline void printk_nmi_direct_enter(void) { }
static inline void printk_nmi_direct_exit(void) { }
#endif /* PRINTK_NMI */
struct dev_printk_info;
#ifdef CONFIG_PRINTK
asmlinkage __printf(5, 0)
asmlinkage __printf(4, 0)
int vprintk_emit(int facility, int level,
const char *dict, size_t dictlen,
const struct dev_printk_info *dev_info,
const char *fmt, va_list args);
asmlinkage __printf(1, 0)
......
......@@ -682,7 +682,8 @@ config IKHEADERS
config LOG_BUF_SHIFT
int "Kernel log buffer size (16 => 64KB, 17 => 128KB)"
range 12 25
range 12 25 if !H8300
range 12 19 if H8300
default 17
depends on PRINTK
help
......
......@@ -2,3 +2,4 @@
obj-y = printk.o
obj-$(CONFIG_PRINTK) += printk_safe.o
obj-$(CONFIG_A11Y_BRAILLE_CONSOLE) += braille.o
obj-$(CONFIG_PRINTK) += printk_ringbuffer.o
......@@ -14,9 +14,9 @@
extern raw_spinlock_t logbuf_lock;
__printf(5, 0)
__printf(4, 0)
int vprintk_store(int facility, int level,
const char *dict, size_t dictlen,
const struct dev_printk_info *dev_info,
const char *fmt, va_list args);
__printf(1, 0) int vprintk_default(const char *fmt, va_list args);
......
This diff is collapsed.
This diff is collapsed.
This diff is collapsed.
......@@ -375,7 +375,7 @@ __printf(1, 0) int vprintk_func(const char *fmt, va_list args)
raw_spin_trylock(&logbuf_lock)) {
int len;
len = vprintk_store(0, LOGLEVEL_DEFAULT, NULL, 0, fmt, args);
len = vprintk_store(0, LOGLEVEL_DEFAULT, NULL, fmt, args);
raw_spin_unlock(&logbuf_lock);
defer_console_output();
return len;
......
......@@ -16,8 +16,13 @@ import sys
from linux import utils
printk_log_type = utils.CachedType("struct printk_log")
printk_info_type = utils.CachedType("struct printk_info")
prb_data_blk_lpos_type = utils.CachedType("struct prb_data_blk_lpos")
prb_desc_type = utils.CachedType("struct prb_desc")
prb_desc_ring_type = utils.CachedType("struct prb_desc_ring")
prb_data_ring_type = utils.CachedType("struct prb_data_ring")
printk_ringbuffer_type = utils.CachedType("struct printk_ringbuffer")
atomic_long_type = utils.CachedType("atomic_long_t")
class LxDmesg(gdb.Command):
"""Print Linux kernel log buffer."""
......@@ -26,44 +31,110 @@ class LxDmesg(gdb.Command):
super(LxDmesg, self).__init__("lx-dmesg", gdb.COMMAND_DATA)
def invoke(self, arg, from_tty):
log_buf_addr = int(str(gdb.parse_and_eval(
"(void *)'printk.c'::log_buf")).split()[0], 16)
log_first_idx = int(gdb.parse_and_eval("'printk.c'::log_first_idx"))
log_next_idx = int(gdb.parse_and_eval("'printk.c'::log_next_idx"))
log_buf_len = int(gdb.parse_and_eval("'printk.c'::log_buf_len"))
inf = gdb.inferiors()[0]
start = log_buf_addr + log_first_idx
if log_first_idx < log_next_idx:
log_buf_2nd_half = -1
length = log_next_idx - log_first_idx
log_buf = utils.read_memoryview(inf, start, length).tobytes()
else:
log_buf_2nd_half = log_buf_len - log_first_idx
a = utils.read_memoryview(inf, start, log_buf_2nd_half)
b = utils.read_memoryview(inf, log_buf_addr, log_next_idx)
log_buf = a.tobytes() + b.tobytes()
length_offset = printk_log_type.get_type()['len'].bitpos // 8
text_len_offset = printk_log_type.get_type()['text_len'].bitpos // 8
time_stamp_offset = printk_log_type.get_type()['ts_nsec'].bitpos // 8
text_offset = printk_log_type.get_type().sizeof
pos = 0
while pos < log_buf.__len__():
length = utils.read_u16(log_buf, pos + length_offset)
if length == 0:
if log_buf_2nd_half == -1:
gdb.write("Corrupted log buffer!\n")
# read in prb structure
prb_addr = int(str(gdb.parse_and_eval("(void *)'printk.c'::prb")).split()[0], 16)
sz = printk_ringbuffer_type.get_type().sizeof
prb = utils.read_memoryview(inf, prb_addr, sz).tobytes()
# read in descriptor ring structure
off = printk_ringbuffer_type.get_type()['desc_ring'].bitpos // 8
addr = prb_addr + off
sz = prb_desc_ring_type.get_type().sizeof
desc_ring = utils.read_memoryview(inf, addr, sz).tobytes()
# read in descriptor array
off = prb_desc_ring_type.get_type()['count_bits'].bitpos // 8
desc_ring_count = 1 << utils.read_u32(desc_ring, off)
desc_sz = prb_desc_type.get_type().sizeof
off = prb_desc_ring_type.get_type()['descs'].bitpos // 8
addr = utils.read_ulong(desc_ring, off)
descs = utils.read_memoryview(inf, addr, desc_sz * desc_ring_count).tobytes()
# read in info array
info_sz = printk_info_type.get_type().sizeof
off = prb_desc_ring_type.get_type()['infos'].bitpos // 8
addr = utils.read_ulong(desc_ring, off)
infos = utils.read_memoryview(inf, addr, info_sz * desc_ring_count).tobytes()
# read in text data ring structure
off = printk_ringbuffer_type.get_type()['text_data_ring'].bitpos // 8
addr = prb_addr + off
sz = prb_data_ring_type.get_type().sizeof
text_data_ring = utils.read_memoryview(inf, addr, sz).tobytes()
# read in text data
off = prb_data_ring_type.get_type()['size_bits'].bitpos // 8
text_data_sz = 1 << utils.read_u32(text_data_ring, off)
off = prb_data_ring_type.get_type()['data'].bitpos // 8
addr = utils.read_ulong(text_data_ring, off)
text_data = utils.read_memoryview(inf, addr, text_data_sz).tobytes()
counter_off = atomic_long_type.get_type()['counter'].bitpos // 8
sv_off = prb_desc_type.get_type()['state_var'].bitpos // 8
off = prb_desc_type.get_type()['text_blk_lpos'].bitpos // 8
begin_off = off + (prb_data_blk_lpos_type.get_type()['begin'].bitpos // 8)
next_off = off + (prb_data_blk_lpos_type.get_type()['next'].bitpos // 8)
ts_off = printk_info_type.get_type()['ts_nsec'].bitpos // 8
len_off = printk_info_type.get_type()['text_len'].bitpos // 8
# definitions from kernel/printk/printk_ringbuffer.h
desc_committed = 1
desc_finalized = 2
desc_sv_bits = utils.get_long_type().sizeof * 8
desc_flags_shift = desc_sv_bits - 2
desc_flags_mask = 3 << desc_flags_shift
desc_id_mask = ~desc_flags_mask
# read in tail and head descriptor ids
off = prb_desc_ring_type.get_type()['tail_id'].bitpos // 8
tail_id = utils.read_u64(desc_ring, off + counter_off)
off = prb_desc_ring_type.get_type()['head_id'].bitpos // 8
head_id = utils.read_u64(desc_ring, off + counter_off)
did = tail_id
while True:
ind = did % desc_ring_count
desc_off = desc_sz * ind
info_off = info_sz * ind
# skip non-committed record
state = 3 & (utils.read_u64(descs, desc_off + sv_off +
counter_off) >> desc_flags_shift)
if state != desc_committed and state != desc_finalized:
if did == head_id:
break
pos = log_buf_2nd_half
did = (did + 1) & desc_id_mask
continue
text_len = utils.read_u16(log_buf, pos + text_len_offset)
text_start = pos + text_offset
text = log_buf[text_start:text_start + text_len].decode(
begin = utils.read_ulong(descs, desc_off + begin_off) % text_data_sz
end = utils.read_ulong(descs, desc_off + next_off) % text_data_sz
# handle data-less record
if begin & 1 == 1:
text = ""
else:
# handle wrapping data block
if begin > end:
begin = 0
# skip over descriptor id
text_start = begin + utils.get_long_type().sizeof
text_len = utils.read_u16(infos, info_off + len_off)
# handle truncated message
if end - text_start < text_len:
text_len = end - text_start
text = text_data[text_start:text_start + text_len].decode(
encoding='utf8', errors='replace')
time_stamp = utils.read_u64(log_buf, pos + time_stamp_offset)
time_stamp = utils.read_u64(infos, info_off + ts_off)
for line in text.splitlines():
msg = u"[{time:12.6f}] {line}\n".format(
......@@ -75,7 +146,9 @@ class LxDmesg(gdb.Command):
msg = msg.encode(encoding='utf8', errors='replace')
gdb.write(msg)
pos += length
if did == head_id:
break
did = (did + 1) & desc_id_mask
LxDmesg()
......@@ -123,6 +123,13 @@ def read_u64(buffer, offset):
return read_u32(buffer, offset + 4) + (read_u32(buffer, offset) << 32)
def read_ulong(buffer, offset):
if get_long_type().sizeof == 8:
return read_u64(buffer, offset)
else:
return read_u32(buffer, offset)
target_arch = None
......
Markdown is supported
0%
or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment