Hello community, here is the log from the commit of package makedumpfile for openSUSE:Factory checked in at 2013-02-11 11:05:41 ++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++ Comparing /work/SRC/openSUSE:Factory/makedumpfile (Old) and /work/SRC/openSUSE:Factory/.makedumpfile.new (New) ++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++
Package is "makedumpfile", Maintainer is "ptesa...@suse.com" Changes: -------- --- /work/SRC/openSUSE:Factory/makedumpfile/makedumpfile.changes 2012-12-09 14:10:13.000000000 +0100 +++ /work/SRC/openSUSE:Factory/.makedumpfile.new/makedumpfile.changes 2013-02-11 11:05:44.000000000 +0100 @@ -1,0 +2,5 @@ +Mon Jan 28 22:46:29 UTC 2013 - je...@suse.com + +- Added support for structured logging added in Linux v3.5. (bnc#801063) + +------------------------------------------------------------------- New: ---- makedumpfile-handle-structured-log_buf ++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++ Other differences: ------------------ ++++++ makedumpfile.spec ++++++ --- /var/tmp/diff_new_pack.EbaeyH/_old 2013-02-11 11:05:45.000000000 +0100 +++ /var/tmp/diff_new_pack.EbaeyH/_new 2013-02-11 11:05:45.000000000 +0100 @@ -1,7 +1,7 @@ # # spec file for package makedumpfile # -# Copyright (c) 2012 SUSE LINUX Products GmbH, Nuernberg, Germany. +# Copyright (c) 2013 SUSE LINUX Products GmbH, Nuernberg, Germany. # # All modifications and additions to the file contributed by third parties # remain the property of their copyright owners, unless otherwise agreed @@ -37,6 +37,7 @@ Source: %{name}-%{version}.tar.bz2 Source1: README.static Patch0: %{name}-coptflags.diff +Patch1: %{name}-handle-structured-log_buf BuildRoot: %{_tmppath}/%{name}-%{version}-build ExclusiveArch: %ix86 x86_64 ia64 ppc64 s390x %arm @@ -55,6 +56,7 @@ %prep %setup -q %patch0 -p1 +%patch1 -p1 %build LIBS_STATIC= ++++++ makedumpfile-handle-structured-log_buf ++++++ From: Jeff Mahoney <je...@suse.com> Subject: Handle Linux >= v3.5 structured logging properly Patch-mainline: https://sourceforge.net/tracker/?func=detail&aid=3602521&group_id=178938&atid=887142 References: bnc#801063 Linux v3.5 added structured logging which needs different handling than the simple ring buffer used in previous revisions. Each log entry consists of a header, text, and an optional dictionary of key/value pairs. As a result, we need to parse the headers and pull the text out of the records. The result is the same flat text file everyone is used to seeing. Signed-off-by: Jeff Mahoney <je...@suse.com> --- makedumpfile.c | 398 ++++++++++++++++++++++++++++++++++++++++++++++++++------- makedumpfile.h | 13 + 2 files changed, 363 insertions(+), 48 deletions(-) --- a/makedumpfile.c +++ b/makedumpfile.c @@ -848,6 +848,8 @@ get_symbol_info(void) SYMBOL_INIT(log_buf, "log_buf"); SYMBOL_INIT(log_buf_len, "log_buf_len"); SYMBOL_INIT(log_end, "log_end"); + SYMBOL_INIT(log_first_idx, "log_first_idx"); + SYMBOL_INIT(log_next_idx, "log_next_idx"); SYMBOL_INIT(max_pfn, "max_pfn"); SYMBOL_INIT(modules, "modules"); SYMBOL_INIT(high_memory, "high_memory"); @@ -1175,6 +1177,14 @@ get_structure_info(void) OFFSET_INIT(elf64_phdr.p_paddr, "elf64_phdr", "p_paddr"); OFFSET_INIT(elf64_phdr.p_memsz, "elf64_phdr", "p_memsz"); + /* Structure sizes for structured logging */ + SIZE_INIT(log, "log"); + OFFSET_INIT(log.ts_nsec, "log", "ts_nsec"); + OFFSET_INIT(log.len, "log", "len"); + OFFSET_INIT(log.text_len, "log", "text_len"); + OFFSET_INIT(log.dict_len, "log", "dict_len"); + OFFSET_INIT(log.flags, "log", "flags"); + return TRUE; } @@ -1353,6 +1363,8 @@ write_vmcoreinfo_data(void) WRITE_SYMBOL("log_buf", log_buf); WRITE_SYMBOL("log_buf_len", log_buf_len); WRITE_SYMBOL("log_end", log_end); + WRITE_SYMBOL("log_first_idx", log_first_idx); + WRITE_SYMBOL("log_next_idx", log_next_idx); WRITE_SYMBOL("max_pfn", max_pfn); WRITE_SYMBOL("high_memory", high_memory); WRITE_SYMBOL("node_remap_start_vaddr", node_remap_start_vaddr); @@ -1371,6 +1383,7 @@ write_vmcoreinfo_data(void) WRITE_STRUCTURE_SIZE("node_memblk_s", node_memblk_s); WRITE_STRUCTURE_SIZE("nodemask_t", nodemask_t); WRITE_STRUCTURE_SIZE("pageflags", pageflags); + WRITE_STRUCTURE_SIZE("log", log); /* * write the member offset of 1st kernel @@ -1404,6 +1417,12 @@ write_vmcoreinfo_data(void) WRITE_MEMBER_OFFSET("node_memblk_s.nid", node_memblk_s.nid); WRITE_MEMBER_OFFSET("vm_struct.addr", vm_struct.addr); + WRITE_MEMBER_OFFSET("log.ts_nsec", log.ts_nsec); + WRITE_MEMBER_OFFSET("log.len", log.len); + WRITE_MEMBER_OFFSET("log.text_len", log.text_len); + WRITE_MEMBER_OFFSET("log.dict_len", log.dict_len); + WRITE_MEMBER_OFFSET("log.flags", log.flags); + if (SYMBOL(node_data) != NOT_FOUND_SYMBOL) WRITE_ARRAY_LENGTH("node_data", node_data); if (SYMBOL(pgdat_list) != NOT_FOUND_SYMBOL) @@ -1662,6 +1681,8 @@ read_vmcoreinfo(void) READ_SYMBOL("log_buf", log_buf); READ_SYMBOL("log_buf_len", log_buf_len); READ_SYMBOL("log_end", log_end); + READ_SYMBOL("log_first_idx", log_first_idx); + READ_SYMBOL("log_next_idx", log_next_idx); READ_SYMBOL("max_pfn", max_pfn); READ_SYMBOL("high_memory", high_memory); READ_SYMBOL("node_remap_start_vaddr", node_remap_start_vaddr); @@ -1677,6 +1698,7 @@ read_vmcoreinfo(void) READ_STRUCTURE_SIZE("node_memblk_s", node_memblk_s); READ_STRUCTURE_SIZE("nodemask_t", nodemask_t); READ_STRUCTURE_SIZE("pageflags", pageflags); + READ_STRUCTURE_SIZE("log", log); READ_MEMBER_OFFSET("page.flags", page.flags); READ_MEMBER_OFFSET("page._count", page._count); @@ -1726,6 +1748,12 @@ read_vmcoreinfo(void) READ_NUMBER("PAGE_BUDDY_MAPCOUNT_VALUE", PAGE_BUDDY_MAPCOUNT_VALUE); + READ_MEMBER_OFFSET("log.ts_nsec", log.ts_nsec); + READ_MEMBER_OFFSET("log.len", log.len); + READ_MEMBER_OFFSET("log.text_len", log.text_len); + READ_MEMBER_OFFSET("log.dict_len", log.dict_len); + READ_MEMBER_OFFSET("log.flags", log.flags); + return TRUE; } @@ -3444,14 +3472,310 @@ reset_bitmap_of_free_pages(unsigned long return TRUE; } -int -dump_dmesg() +typedef void * printk_msg_t; +#define printk_msg_len(msg) (USHORT(msg + OFFSET(log.len))) +#define printk_msg_text_len(msg) (USHORT(msg + OFFSET(log.text_len))) + +enum log_flags { + LOG_NOCONS = 1, /* already flushed, do not print to console */ + LOG_NEWLINE = 2, /* text ended with a newline */ + LOG_PREFIX = 4, /* text started with a prefix */ + LOG_CONT = 8, /* text is a fragment of a continuation line */ +}; + +static inline uint8_t printk_msg_flags(printk_msg_t msg) +{ + /* This will need handling once bitfields are exported properly */ + if (OFFSET(log.flags) != INVALID_STRUCTURE_DATA) { + return 0; + } + return 0; +} + +/* get record by index; idx must point to valid msg */ +static printk_msg_t log_from_idx(char *log_buf, uint32_t idx) +{ + printk_msg_t msg = (printk_msg_t)(log_buf + idx); + + /* + * A length == 0 record is the end of buffer marker. Wrap around and + * read the message at the start of the buffer. + */ + if (!printk_msg_len(msg)) + return (printk_msg_t)log_buf; + return msg; +} + +/* get next record; idx must point to valid msg */ +static uint32_t log_next(char *log_buf, uint32_t idx) +{ + printk_msg_t msg = (printk_msg_t)(log_buf + idx); + + /* length == 0 indicates the end of the buffer; wrap */ + /* + * A length == 0 record is the end of buffer marker. Wrap around and + * read the message at the start of the buffer as *this* one, and + * return the one after that. + */ + if (!printk_msg_len(msg)) { + msg = (printk_msg_t )log_buf; + return printk_msg_len(msg); + } + return idx + printk_msg_len(msg); +} + +/* human readable text of the record */ +static char *printk_msg_text(const printk_msg_t msg) +{ + return (char *)msg + SIZE(log); +} + +static size_t print_time(const printk_msg_t msg, char *logbuf) +{ + unsigned long rem_nsec; + uint64_t ts = U64(msg + OFFSET(log.ts_nsec)); + + if (!logbuf) + return 15; + + rem_nsec = ts % 1000000000UL; + ts /= 1000000000UL; + return sprintf(logbuf, "[%5lu.%06lu] ", + (unsigned long)ts, rem_nsec / 1000); +} + +static size_t msg_print_text(const printk_msg_t msg, enum log_flags prev, + char *logbuf, size_t size) +{ + const char *text = printk_msg_text(msg); + size_t text_size = printk_msg_text_len(msg); + int prefix = TRUE; + int newline = TRUE; + size_t len = 0; + + if ((prev & LOG_CONT) && !(printk_msg_flags(msg) & LOG_PREFIX)) + prefix = FALSE; + + if (printk_msg_flags(msg) & LOG_CONT) { + if ((prev & LOG_CONT) && !(prev & LOG_NEWLINE)) + prefix = FALSE; + + if (!(printk_msg_flags(msg) & LOG_NEWLINE)) + newline = FALSE; + } + + do { + const char *next = memchr(text, '\n', text_size); + size_t text_len; + + if (next) { + text_len = next - text; + next++; + text_size -= next - text; + } else { + text_len = text_size; + } + + if (print_time(msg, NULL) + text_len + 1 >= size - len) + break; + + if (prefix) + len += print_time(msg, logbuf + len); + memcpy(logbuf + len, text, text_len); + len += text_len; + if (next || newline) + logbuf[len++] = '\n'; + + prefix = TRUE; + text = next; + } while (text); + + return len; +} + +static char * +handle_structured_log(unsigned long log_buf_vaddr, int log_buf_len, + int *ret_buflen) +{ + char *log_buf, *out_buffer; + size_t buflen, len = 0; + uint32_t idx, first_idx, next_idx; + uint8_t flags = 0; + int count = 0; + + if (SYMBOL(log_first_idx) == NOT_FOUND_SYMBOL) { + ERRMSG("Can't find log_first_idx for structured logging.\n"); + return NULL; + } + + if (SYMBOL(log_next_idx) == NOT_FOUND_SYMBOL) { + ERRMSG("Can't find log_next_idx for structured logging.\n"); + return NULL; + } + + if (SIZE(log) == NOT_FOUND_STRUCTURE) { + ERRMSG("Can't find struct log for structured logging.\n"); + return NULL; + } + + if (OFFSET(log.len) == INVALID_STRUCTURE_DATA) { + ERRMSG("Can't find struct log.len for structured logging.\n"); + return NULL; + } + + if (OFFSET(log.ts_nsec) == INVALID_STRUCTURE_DATA) { + ERRMSG("Can't find struct log.ts_nsec for structured logging.\n"); + return NULL; + } + + /* struct log's flags member isn't exported yet, so we can't do + * things like honor continuation or prefix bits */ + if (OFFSET(log.flags) == INVALID_STRUCTURE_DATA) + ERRMSG("Can't find struct log.flags - dmesg output may be inconsistent.\n"); + + if (!readmem(VADDR, SYMBOL(log_first_idx), &first_idx, + sizeof(first_idx))) { + ERRMSG("Can't read log_first_idx. %s\n", strerror(errno)); + return NULL; + } + + if (!readmem(VADDR, SYMBOL(log_next_idx), &next_idx, + sizeof(next_idx))) { + ERRMSG("Can't read log_first_idx. %s\n", strerror(errno)); + return NULL; + } + + log_buf = malloc(log_buf_len); + if (!log_buf) { + ERRMSG("Can't allocate buffer to read kernel log. %s\n", + strerror(errno)); + return NULL; + } + + if (!readmem(VADDR, log_buf_vaddr, log_buf, log_buf_len)) { + ERRMSG("Can't read kernel log for structured log input. %s\n", + strerror(errno)); + goto out_fail; + } + + idx = first_idx; + while (idx != next_idx && len < log_buf_len) { + printk_msg_t msg; + msg = log_from_idx(log_buf, idx); + count++; + len += SIZE(log) + printk_msg_len(msg); + idx = log_next(log_buf, idx); + } + DEBUG_MSG("Found %d kernel log entries\n", count); + + /* Buffer length + timestamps */ + buflen = log_buf_len + 16 * count; + out_buffer = malloc(buflen); + if (!out_buffer) { + ERRMSG("Can't allocate memory for structured log output. %s\n", + strerror(errno)); + goto out_fail; + } + + idx = first_idx; + len = 0; + while (len < buflen && idx != next_idx) { + printk_msg_t msg = log_from_idx(log_buf, idx); + size_t textlen; + + textlen = msg_print_text(msg, flags, out_buffer + len, + buflen - len); + if (textlen < 0) + break; + + len += textlen; + + flags = printk_msg_flags(msg); + idx = log_next(log_buf, idx); + } + + *ret_buflen = len; + + return out_buffer; +out_fail: + if (out_buffer) + free(out_buffer); + if (log_buf) + free(log_buf); + return NULL; +} + +static char * +handle_unstructured_log(unsigned long log_buf_vaddr, int log_buf_len, + int *ret_buflen) { - int log_buf_len, length_log, length_oldlog, ret = FALSE; - unsigned long log_buf, log_end, index; + int length_log, length_oldlog; + unsigned long log_end, index; unsigned long log_end_2_6_24; unsigned log_end_2_6_25; + char *log_buf = malloc(log_buf_len); + + if (!log_buf) { + ERRMSG("Can't allocate memory for unstructured log output. %s\n", + strerror(errno)); + return NULL; + } + + if (info->kernel_version >= KERNEL_VERSION(2, 6, 25)) { + if (!readmem(VADDR, SYMBOL(log_end), &log_end_2_6_25, + sizeof(log_end_2_6_25))) { + ERRMSG("Can't get log_end. (>= v2.6.25)\n"); + goto out_fail; + } + log_end = log_end_2_6_25; + } else { + if (!readmem(VADDR, SYMBOL(log_end), &log_end_2_6_24, + sizeof(log_end_2_6_24))) { + ERRMSG("Can't get log_end. (< v2.6.25)\n"); + goto out_fail; + } + log_end = log_end_2_6_24; + } + DEBUG_MSG("log_end : %lx\n", log_end); + + if (log_end < log_buf_len) { + length_log = log_end; + if(!readmem(VADDR, log_buf_vaddr, log_buf, length_log)) { + ERRMSG("Can't read dmesg log.\n"); + goto out_fail; + } + } else { + index = log_end & (log_buf_len - 1); + DEBUG_MSG("index : %lx\n", index); + length_log = log_buf_len; + length_oldlog = log_buf_len - index; + if(!readmem(VADDR, log_buf_vaddr + index, + log_buf, length_oldlog)) { + ERRMSG("Can't read old dmesg log.\n"); + goto out_fail; + } + if(!readmem(VADDR, log_buf_vaddr, log_buf + length_oldlog, + index)) { + ERRMSG("Can't read new dmesg log.\n"); + goto out_fail; + } + } + + *ret_buflen = length_log; + return log_buf; +out_fail: + free(log_buf); + return NULL; +} + +int +dump_dmesg() +{ + int length_log = 0; + int ret = FALSE; char *log_buffer = NULL; + unsigned long log_buf; + int log_buf_len; /* * log_end has been changed to "unsigned" since linux-2.6.25. @@ -3468,67 +3792,45 @@ dump_dmesg() if (!initial()) return FALSE; - if ((SYMBOL(log_buf) == NOT_FOUND_SYMBOL) - || (SYMBOL(log_buf_len) == NOT_FOUND_SYMBOL) - || (SYMBOL(log_end) == NOT_FOUND_SYMBOL)) { - ERRMSG("Can't find some symbols for log_buf.\n"); + if (SYMBOL(log_buf) == NOT_FOUND_SYMBOL) { + ERRMSG("Can't find log_buf for dmesg dumping.\n"); + return FALSE; + } + + if (SYMBOL(log_buf_len) == NOT_FOUND_SYMBOL) { + ERRMSG("Can't find log_buf_len for dmesg dumping.\n"); return FALSE; } + if (!readmem(VADDR, SYMBOL(log_buf), &log_buf, sizeof(log_buf))) { ERRMSG("Can't get log_buf.\n"); return FALSE; } - if (info->kernel_version >= KERNEL_VERSION(2, 6, 25)) { - if (!readmem(VADDR, SYMBOL(log_end), &log_end_2_6_25, - sizeof(log_end_2_6_25))) { - ERRMSG("Can't to get log_end.\n"); - return FALSE; - } - log_end = log_end_2_6_25; - } else { - if (!readmem(VADDR, SYMBOL(log_end), &log_end_2_6_24, - sizeof(log_end_2_6_24))) { - ERRMSG("Can't to get log_end.\n"); - return FALSE; - } - log_end = log_end_2_6_24; - } + if (!readmem(VADDR, SYMBOL(log_buf_len), &log_buf_len, sizeof(log_buf_len))) { ERRMSG("Can't get log_buf_len.\n"); return FALSE; } + DEBUG_MSG("\n"); DEBUG_MSG("log_buf : %lx\n", log_buf); - DEBUG_MSG("log_end : %lx\n", log_end); DEBUG_MSG("log_buf_len : %d\n", log_buf_len); - if ((log_buffer = malloc(log_buf_len)) == NULL) { - ERRMSG("Can't allocate memory for log_buf. %s\n", - strerror(errno)); + if (SYMBOL(log_end) != NOT_FOUND_SYMBOL) + log_buffer = handle_unstructured_log(log_buf, log_buf_len, + &length_log); + else if (SYMBOL(log_first_idx) != NOT_FOUND_SYMBOL) + /* Kernels v3.2 and newer use structured logging */ + log_buffer = handle_structured_log(log_buf, log_buf_len, + &length_log); + else + ERRMSG("Can't find log_end or log_first_idx. " + "Can't read log.\n"); + + if (!log_buffer) return FALSE; - } - if (log_end < log_buf_len) { - length_log = log_end; - if(!readmem(VADDR, log_buf, log_buffer, length_log)) { - ERRMSG("Can't read dmesg log.\n"); - goto out; - } - } else { - index = log_end & (log_buf_len - 1); - DEBUG_MSG("index : %lx\n", index); - length_log = log_buf_len; - length_oldlog = log_buf_len - index; - if(!readmem(VADDR, log_buf + index, log_buffer, length_oldlog)) { - ERRMSG("Can't read old dmesg log.\n"); - goto out; - } - if(!readmem(VADDR, log_buf, log_buffer + length_oldlog, index)) { - ERRMSG("Can't read new dmesg log.\n"); - goto out; - } - } DEBUG_MSG("length_log : %d\n", length_log); if (!open_dump_file()) { --- a/makedumpfile.h +++ b/makedumpfile.h @@ -216,9 +216,11 @@ isAnon(unsigned long mapping) #define STRNEQ(A, B) (A && B && \ (strncmp((char *)(A), (char *)(B), strlen((char *)(B))) == 0)) +#define UCHAR(ADDR) *((unsigned char *)(ADDR)) #define USHORT(ADDR) *((unsigned short *)(ADDR)) #define UINT(ADDR) *((unsigned int *)(ADDR)) #define ULONG(ADDR) *((unsigned long *)(ADDR)) +#define U64(ADDR) *((uint64_t *)(ADDR)) /* * for symbol @@ -1090,6 +1092,8 @@ struct symbol_table { unsigned long long log_buf; unsigned long long log_buf_len; unsigned long long log_end; + unsigned long long log_first_idx; + unsigned long long log_next_idx; unsigned long long max_pfn; unsigned long long node_remap_start_vaddr; unsigned long long node_remap_end_vaddr; @@ -1171,6 +1175,7 @@ struct size_table { long elf64_hdr; long pageflags; + long log; }; struct offset_table { @@ -1302,6 +1307,14 @@ struct offset_table { long p_paddr; long p_memsz; } elf64_phdr; + + struct log { + long ts_nsec; + long len; + long text_len; + long dict_len; + long flags; + } log; }; /* -- To unsubscribe, e-mail: opensuse-commit+unsubscr...@opensuse.org For additional commands, e-mail: opensuse-commit+h...@opensuse.org