Andrew Hecox wrote: > hello, > > I'm looking at a customer issue where diskdumpmsg is unable to read a > vmcore file. It is not clear if this a problem with the vmcore file or > diskdumpmsg. I can load the vmcore with crash and in my naive usage of > it, can see no problems. However, I'm new to the tool so that doesn't > give me a lot of confidence. > > Does anyone have any suggestions on how or if I can use crash to help > determine if there's corruption in the vmcore file? Or any other way of > approaching the problem? > > Thanks much, > > Andrew > I'm not sure what you expect the crash utility to do -- if it comes up to a prompt with no error or warning messages, it means that the ELF header contains what appears to be valid usable information, and that the minimum kernel memory contents required to set up the crash utility's notion of the running system are all in place. That's not to say that there is no chance that the vmcore contains some corruption that was not recognized.

With respect to diskdumpmsg, as I understand it, it was fairly recently changed from a perl script to a C file so that it could be run earlier in time so as to be able to use the swap partition. Looking at main() in the diskdumpmsg.c file (version 1.4.1-2), there are numerous error types and associated error messages. What do you mean when you say that "diskdumpmsg is unable to read a vmcore file"?

Dave

Andrew Hecox wrote: > On Thu, 2008-02-07 at 11:27 -0500, Dave Anderson wrote: >> Andrew Hecox wrote: >>> On Thu, 2008-02-07 at 10:32 -0500, Dave Anderson wrote: >>>> Andrew Hecox wrote: >>>>> hello, >>>>> >>>>> I'm looking at a customer issue where diskdumpmsg is unable to read a >>>>> vmcore file. It is not clear if this a problem with the vmcore file or >>>>> diskdumpmsg. I can load the vmcore with crash and in my naive usage of >>>>> it, can see no problems. However, I'm new to the tool so that doesn't >>>>> give me a lot of confidence. >>>>> >>>>> Does anyone have any suggestions on how or if I can use crash to help >>>>> determine if there's corruption in the vmcore file? Or any other way of >>>>> approaching the problem? >>>>> >>>>> Thanks much, >>>>> >>>>> Andrew >>>>> >>>> I'm not sure what you expect the crash utility to do -- if it comes >>>> up to a prompt with no error or warning messages, it means that the >>>> ELF header contains what appears to be valid usable information, >>>> and that the minimum kernel memory contents required to set up the >>>> crash utility's notion of the running system are all in place. That's >>>> not to say that there is no chance that the vmcore contains some >>>> corruption that was not recognized. >>>> >>> Thanks. Any other suggestions on how to determine if a vmcore is "valid" >>> or is that not even a reasonable question to try and ask? The problem >>> I'm trying to solve is described better below: >>> >>>> With respect to diskdumpmsg, as I understand it, it was fairly recently >>>> changed from a perl script to a C file so that it could be run >>>> earlier in time so as to be able to use the swap partition. Looking >>>> at main() in the diskdumpmsg.c file (version 1.4.1-2), there are numerous >>>> error types and associated error messages. What do you mean when you >>>> say that "diskdumpmsg is unable to read a vmcore file"? >>> Specifically: >>> >>> - user reported a floating point exception from diskdump on startup >>> - the result was reproducible locally but only with their vmcore file >>> - fpe occurred in get_logbuf: >>> log_end %= log_buf_len; >>> - log_buf_len had been set to 0 in read_buffer >>> if (!page_is_dumpable(pfn, dump->device)) { >>> memset(buf, 0, copy_len); >>> } else { >>> - I don't know enough to say if the page really wasn't dumpable. >>> static inline bool page_is_dumpable(unsigned int nr, DumpDevice *device) >>> { >>> return device->dumpable_bitmap[nr>>3] & (1 << (nr & 7)); >>> } >>> - I wrote a patch with one way to avoid the FPE (attached) and sent it >>> to SEG. >>> >>> Now I'm trying to determine if the vmcore file should be readable by >>> diskdumpmsg. In other words, is this a problem in diskdumpmsg post-crash >>> or a problem with the vmcore file prior to it getting to diskdumpmsg. >>> Unfortunately, I don't understand the problem domain very well at all, >>> hence the probably naive questions :) >>> >>> Any suggestions are appreciated. >>> >>> -Andrew >> So it appears that the page containing the log_buf_len symbol is not >> readable or contained in the dumpfile. BTW, is this a compressed >> dumpfile or an ELF formatted dumpfile? And what "dump_level" did >> they configure? >> > > compressed, level is 19. > >> Anyway, back to the log_buf_len symbol read, what happens when you >> enter the "log" command while in a crash session? It attempts to >> read that symbol immediately. >> > > I get what appears to be a full and valid dump of the kernel message > buffer. > The crash utility has the same page_is_dumpable() function, which I presume looks at precisely the same bitmap data from the dumpfile. And that must be working, given that the "log" command works as expected. One difference is that diskdumpmsg uses /boot/System.map-<release> for the symbol values, whereas crash uses the vmlinux file. It might be of interest to determine whether the value of "log_buf_len" used by diskdumpmsg is the same symbol value as used by crash.

Dave

Andrew Hecox wrote: > > I get the same: > > (/boot/System.map-2.6.9-67.0.1.ELhugemem) > > 02323bd8 d log_buf_len > > (/usr/lib/debug/lib/modules/2.6.9-67.0.1.ELhugemem/vmlinux) > > $1 = (int *) 0x2323bd8 > > -Andrew So, as Takao suggested, can you dump the incoming vaddr and resultant pfn values in diskdumpmsg.c:read_buffer()?

Dave

Andrew Hecox wrote: > On Thu, 2008-02-07 at 15:38 -0500, Dave Anderson wrote: >> Andrew Hecox wrote: >>> I get the same: >>> >>> (/boot/System.map-2.6.9-67.0.1.ELhugemem) >>> >>> 02323bd8 d log_buf_len >>> >>> (/usr/lib/debug/lib/modules/2.6.9-67.0.1.ELhugemem/vmlinux) >>> >>> $1 = (int *) 0x2323bd8 >>> >>> -Andrew >> So, as Takao suggested, can you dump the incoming vaddr and >> resultant pfn values in diskdumpmsg.c:read_buffer()? >> > > The vaddr value is: 36846552. > > -Andrew > >> Dave >> >> > OK, so the incoming vaddr is 36846552 is which is 0x2323bd8. To get a pfn, that hugemem kernel virtual address is passed through vtop() and then divided by 4096: static int read_buffer(DumpFile *dump, addr_t vaddr, size_t len, void *buf) { addr_t paddr; int block_size = get_page_size(); unsigned long pfn; int ret; size_t copy_len, offs; void *page_data; paddr = vtop(dump, vaddr); pfn = paddr / block_size; offs = paddr % block_size; When 0x2323bd8 is run through vtop(), it simply strips off the hugemem unity-map identifier: addr_t vtop(DumpFile *dump, addr_t vaddr) { if (strstr("hugemem", dump->utsname->release)) return vaddr - 0x02000000L; else return vaddr - 0xc0000000L; } leaving 0x323bd8 -- which gets divided by the page size of 4096, leaving a pfn of 0x323. But you see that the pfn was 271139 (0x42323). If that is expanded to a physical address it would be 0x42323000. It looks like it's using the non-hugemem value in vtop(), i,e, subtracting c0000000 from the incoming vaddr. In other words, 0x2323bd8 - 0xc000000 is equal to 0x42323bd8. If that is divided by 4096, you get the funky pfn of 271139 (0x42323). Print out the dump->utsname->release string in vtop(). It must not contain "hugemem".

Dave :

Andrew Hecox wrote: > On Thu, 2008-02-07 at 16:04 -0500, Dave Anderson wrote: >> Andrew Hecox wrote: >>> On Thu, 2008-02-07 at 15:38 -0500, Dave Anderson wrote: >>>> Andrew Hecox wrote: >>>>> I get the same: >>>>> >>>>> (/boot/System.map-2.6.9-67.0.1.ELhugemem) >>>>> >>>>> 02323bd8 d log_buf_len >>>>> >>>>> (/usr/lib/debug/lib/modules/2.6.9-67.0.1.ELhugemem/vmlinux) >>>>> >>>>> $1 = (int *) 0x2323bd8 >>>>> >>>>> -Andrew >>>> So, as Takao suggested, can you dump the incoming vaddr and >>>> resultant pfn values in diskdumpmsg.c:read_buffer()? >>>> >>> The vaddr value is: 36846552. >>> >>> -Andrew >>> >>>> Dave >>>> >>>> >> OK, so the incoming vaddr is 36846552 is which is 0x2323bd8. >> To get a pfn, that hugemem kernel virtual address is passed >> through vtop() and then divided by 4096: >> >> static int read_buffer(DumpFile *dump, addr_t vaddr, size_t len, void *buf) >> { >> addr_t paddr; >> int block_size = get_page_size(); >> unsigned long pfn; >> int ret; >> size_t copy_len, offs; >> void *page_data; >> >> paddr = vtop(dump, vaddr); >> pfn = paddr / block_size; >> offs = paddr % block_size; >> >> When 0x2323bd8 is run through vtop(), it simply strips off the >> hugemem unity-map identifier: >> >> addr_t vtop(DumpFile *dump, addr_t vaddr) >> { >> if (strstr("hugemem", dump->utsname->release)) >> return vaddr - 0x02000000L; >> else >> return vaddr - 0xc0000000L; >> } >> >> leaving 0x323bd8 -- which gets divided by the page size of 4096, leaving >> a pfn of 0x323. >> >> But you see that the pfn was 271139 (0x42323). If that is expanded >> to a physical address it would be 0x42323000. It looks like it's >> using the non-hugemem value in vtop(), i,e, subtracting c0000000 from >> the incoming vaddr. In other words, 0x2323bd8 - 0xc000000 is >> equal to 0x42323bd8. If that is divided by 4096, you get >> the funky pfn of 271139 (0x42323). >> >> Print out the dump->utsname->release string in vtop(). It must >> not contain "hugemem". >> > > Dave, > > I get: > > (gdb) print dump->utsname->release > $19 = "2.6.9-67.0.1.ELhugemem", '\0' <repeats 42 times> > > but then > > (gdb) s > 16 return vaddr - 0xc0000000L; > > ! oh uh. > > man strstr > > ... > char *strstr(const char *haystack, const char *needle); > ... > > It looks like > > if (strstr("hugemem", dump->utsname->release)) > > should be: > > if (strstr(dump->utsname->release,"hugemem")) Bingo -- like the man page says: char *strstr(const char *haystack, const char *needle); > > I patched, recompiled, tested and it works: > > [root@ibm-x3455-1 ~]# diskdumpmsg -f -p /var/crash/vmcore > Jan 31 05:43:08 elabhost012 kernel: --- salvaged messages from crash > dump start > Jan 31 05:43:08 elabhost012 kernel: 0218b9c0 0232d363 0232d3e0 > 0215aff6 df954fac f6db4000 eaa756c0 fffffff7 > Jan 31 05:43:08 elabhost012 kernel: f6db4000 df954000 0215b0c0 > df954fac 00000000 00000000 00000000 df954fc4 > Jan 31 05:43:08 elabhost012 kernel: Call Trace: > Jan 31 05:43:08 elabhost012 kernel: [<0220c46a>] __handle_sysrq > +0x58/0xc6 > Jan 31 05:43:08 elabhost012 kernel: [<0218b9c0>] write_sysrq_trigger > +0x37/0x3e > Jan 31 05:43:08 elabhost012 kernel: [<0215aff6>] vfs_write+0xb6/0xe2 > Jan 31 05:43:08 elabhost012 kernel: [<0215b0c0>] sys_write+0x3c/0x62 > Jan 31 05:43:08 elabhost012 kernel: Code: 11 02 c7 05 10 fd 44 02 00 00 > 00 00 c7 05 38 fd 44 02 00 00 00 00 c7 05 2c fd 44 02 6e ad 87 4b 89 15 > 28 fd 44 02 e9 8b 41 f2 ff <c6> 05 00 00 00 00 00 c3 e9 0a ff f4 ff e9 > a2 48 f5 ff 85 d2 89 > Jan 31 05:43:08 elabhost012 kernel: --- salvaged messages from crash > dump end > > Thanks much for all the help! Should I open a bz against the issue? It > looks like all i386 hugemem kernels would be similarly affected. Yep -- definitely open a BZ against component "diskdumputils".

Dave

Hi Andrew, Dave Anderson wrote: > Andrew Hecox wrote: >> On Thu, 2008-02-07 at 10:32 -0500, Dave Anderson wrote: >>> Andrew Hecox wrote: >>>> hello, >>>> >>>> I'm looking at a customer issue where diskdumpmsg is unable to read a >>>> vmcore file. It is not clear if this a problem with the vmcore file or >>>> diskdumpmsg. I can load the vmcore with crash and in my naive usage of >>>> it, can see no problems. However, I'm new to the tool so that doesn't >>>> give me a lot of confidence. >>>> Does anyone have any suggestions on how or if I can use crash to help >>>> determine if there's corruption in the vmcore file? Or any other way of >>>> approaching the problem? >>>> Thanks much, >>>> >>>> Andrew >>>> >>> I'm not sure what you expect the crash utility to do -- if it comes >>> up to a prompt with no error or warning messages, it means that the >>> ELF header contains what appears to be valid usable information, >>> and that the minimum kernel memory contents required to set up the >>> crash utility's notion of the running system are all in place. That's >>> not to say that there is no chance that the vmcore contains some >>> corruption that was not recognized. >>> >> >> Thanks. Any other suggestions on how to determine if a vmcore is "valid" >> or is that not even a reasonable question to try and ask? The problem >> I'm trying to solve is described better below: >> >>> With respect to diskdumpmsg, as I understand it, it was fairly recently >>> changed from a perl script to a C file so that it could be run >>> earlier in time so as to be able to use the swap partition. Looking >>> at main() in the diskdumpmsg.c file (version 1.4.1-2), there are >>> numerous >>> error types and associated error messages. What do you mean when you >>> say that "diskdumpmsg is unable to read a vmcore file"? >> >> Specifically: >> - user reported a floating point exception from diskdump on startup >> - the result was reproducible locally but only with their vmcore file >> - fpe occurred in get_logbuf: >> log_end %= log_buf_len; >> - log_buf_len had been set to 0 in read_buffer >> if (!page_is_dumpable(pfn, dump->device)) { >> memset(buf, 0, copy_len); >> } else { >> - I don't know enough to say if the page really wasn't dumpable. >> static inline bool page_is_dumpable(unsigned int nr, DumpDevice *device) >> { >> return device->dumpable_bitmap[nr>>3] & (1 << (nr & 7)); >> } >> - I wrote a patch with one way to avoid the FPE (attached) and sent it >> to SEG. >> >> Now I'm trying to determine if the vmcore file should be readable by >> diskdumpmsg. In other words, is this a problem in diskdumpmsg post-crash >> or a problem with the vmcore file prior to it getting to diskdumpmsg. >> Unfortunately, I don't understand the problem domain very well at all, >> hence the probably naive questions :) >> >> Any suggestions are appreciated. >> >> -Andrew > > So it appears that the page containing the log_buf_len symbol is not > readable or contained in the dumpfile. BTW, is this a compressed > dumpfile or an ELF formatted dumpfile? And what "dump_level" did > they configure? > > Anyway, back to the log_buf_len symbol read, what happens when you > enter the "log" command while in a crash session? It attempts to > read that symbol immediately. The virtual address of log_buf_len may be converted to wrong pfn. Could you check pfn value passed to "page_is_dumpable"?

Thanks, Takao Indoh