Clobbered file after jffs2 mount
Hello,
This falls under the category of bizarre behavior and I'm hoping someone on this list can help.
I have a jffs2 filesystem on my target (IXP455 processor) running Linux 2.6.16.29. Sometimes the first time that Linux mounts the jffs2 filesystem after reflashing the jffs2 image, sshd would strangely misbehave and not allow incoming connections. After much troubleshooting, it was discovered that the md5sum of the sshd file was different than the expected md5sum. However, if the system is rebooted, then sshd works correctly and the md5sum of sshd on the target magically corrected itself to the expected value.
I patched jffs2reader.c with the set of 4 patches found in this thread to help me extract the sshd that is found in the physical medium:
http://lists.infradead.org/pipermail/linux-mtd/2005-October/014066.html
The correct md5sum for sshd is: 9e7e08056641d4029d239dc3c6028de9
[root@isc1 ~]# md5sum /usr/sbin/sshd 8c56d103db48c6ec69bba8189f3e64bf /usr/sbin/sshd
[root@isc1 ~]# cp /dev/mtd1 /tmp/jffs2.dmp
[root@isc1 ~]# jffs2reader -b -f /usr/sbin/sshd /tmp/jffs2.dmp > /tmp/sshd [root@isc1 ~]# md5sum /tmp/sshd 9e7e08056641d4029d239dc3c6028de9 /tmp/sshd
I then did a hexdump of both files and found that there are two 32 bit values that got clobbered:
[root@isc1 ~]# hexdump -C /usr/sbin/sshd > /tmp/sshd.bad.hex [root@isc1 ~]# hexdump -C /tmp/sshd > /tmp/sshd.good.hex
(The following diff has been hand edited slightly just to avoid line wrap by email) [root@isc1 ~]# diff -u /tmp/sshd.bad.hex /tmp/sshd.good.hex
tmp/sshd.good.hex 2007-09-21 09:43:06 +0000 renamed from tmp/sshd.bad.hex 2007-09-21 09:42:55 +0000 +0 -0
@@ -9817,7 +9817,7 @@
00026630 e3a030cc ebffe64b e59f04b0 ebffee5b |..0....K.......[| 00026640 e5993048 e3130001 01a00009 0bffff77 |..0H...........w| 00026650 e3a01000 e2890024 ebfffef8 e28d1024 |.......$.......$| -00026660 00000023 e1a00005 ebfffef4 e58d001c |...#............| +00026660 e58d0020 e1a00005 ebfffef4 e58d001c |... ............| 00026670 e5993014 e3530000 159d1020 059d2020 |..0..S..... .. | 00026680 059d301c 158d0018 e3a0b000 158d1014 |..0.............| 00026690 058d2018 058d3014 e3a00040 ebfff933 |.. [email protected]| @@ -9945,7 +9945,7 @@ 00026e30 e2466004 e1a01007 81a02004 859f00d0 |.F`....... .....| 00026e40 8a000011 ebff7108 e1a02004 e1a01007 |......q... .....| 00026e50 e1a00005 ebff727b e1a00008 ebff719e |......r{......q.| -00026e60 00000073 e1a02fc3 e0833ea2 e1a041c3 |...s../...>...A.| +00026e60 e2803007 e1a02fc3 e0833ea2 e1a041c3 |..0.../...>...A.| 00026e70 e2443040 e3530d1f e1a01007 e1a00008 |[email protected]..........| 00026e80 9a000003 e59f008c e1a02004 e59f1088 |.......... .....| 00026e90 ebffe21b ebff70f4 e1a01007 e1a02004 |......p....... .|
It would seem that the underlying image of sshd on the physical medium is correct, however the image of sshd as presented via Linux's VFS and JFFS2 has damaged the image.
Does anyone have any suggestions?
Thanks,
Jon
Quoted 4 lines · Jon Ringle
Hello,
This falls under the category of bizarre behavior and I'm hoping someone on this list can help.
Yes, that is indeed bizarre.
Quoted 8 lines
I have a jffs2 filesystem on my target (IXP455 processor) running Linux 2.6.16.29. Sometimes the first time that Linux mounts the jffs2 filesystem after reflashing the jffs2 image, sshd would strangely misbehave and not allow incoming connections. After much troubleshooting, it was discovered that the md5sum of the sshd file was different than the expected md5sum. However, if the system is rebooted, then sshd works correctly and the md5sum of sshd on the target magically corrected itself to the expected value.
My first inclination is to suspect that somehow the pages of sshd got scribbled on in RAM. Is the corruption repeatable?
Can you instrument jffs2_read_inode_range() to print a hex dump of the "offending" bytes as soon as they've been read?
Can you boot directly into a shell (init=/bin/sh) and then md5sum the offending file?
Signature · 1 line
dwmw2
Quoted 2 lines · David Woodhouse
Quoted 1 line · Jon Ringle
I have a jffs2 filesystem on my target (IXP455 processor) running
Linux
Quoted 4 lines
Quoted 4 lines
2.6.16.29. Sometimes the first time that Linux mounts the jffs2 filesystem after reflashing the jffs2 image, sshd would strangely misbehave and not allow incoming connections. After much troubleshooting, it was discovered that the md5sum of the sshd file
was
Quoted 1 line
Quoted 1 line
different than the expected md5sum. However, if the system is
rebooted,
Quoted 1 line
Quoted 1 line
then sshd works correctly and the md5sum of sshd on the target
magically
Quoted 4 lines
Quoted 1 line
corrected itself to the expected value.
My first inclination is to suspect that somehow the pages of sshd got scribbled on in RAM. Is the corruption repeatable?
This is also what I suspect. The corruption is repeatable on the first boot after a reflash of the jffs2 filesystem about 90% of the time. One thing that is different on the first boot is that ssh keys get generated on that first boot.
Quoted 3 lines
Can you instrument
jffs2_read_inode_range()to print a hex dump of the "offending" bytes as soon as they've been read?
Thanks David. This information will help further my investigation now that you've pointed me towards how I can find the sshd image in RAM pages. I will attach my JTAG debugger when I'm next in the office and use GDB to extract a dump of the RAM sshd image using a conditional breakpoint with sshd's inode number in jffs2_read_inode_range(). I will also try to locate the clobbered bytes so I can put a data breakpoint on it to see if I can get a backtrace pointing to what is causing the corruption.
Quoted 3 lines
Can you boot directly into a shell (init=/bin/sh) and then md5sum the offending file?
I tried init=/bin/sh on a first boot after reflash and the md5sum of sshd was correct. I then rebooted again normally and the ssh keys were generated. When I logged in, the md5sum of sshd was wrong. The corruption that I observe is always the same incorrect md5sum.
Jon
Quoted 4 lines · Jon Ringle
I tried init=/bin/sh on a first boot after reflash and the md5sum of sshd was correct. I then rebooted again normally and the ssh keys were generated. When I logged in, the md5sum of sshd was wrong. The corruption that I observe is always the same incorrect md5sum.
But there's no corruption on the _flash_ -- if you boot with init=/bin/sh again after the keys are generated, you again get the _correct_ md5sum? I'm fairly certain of that, since the failure mode you'll get if you manage to scribble on the flash is that the data CRC will fail and you'll get zeroes where the offending nodes go missing.
It's going to be something scribbling on the RAM pages after the file is read from the file system. Be thankful it looks fairly repeatable. Can you put a hardware watchpoint on the offending page in the page cache, after it's read? And can you disable _everything_ in the system which uses DMA, one at a time?
Signature · 1 line
dwmw2
Been reading this thread, and I was wondering what kind of hardware this is running on? I remember running into something like this a few years ago on my companies own embedded hardware, and the cause turned out to be a problem with an internal Multitech modem's firmware on the same bus which was interfering with reading the jffs2 file system.
I would see many ( but not all ) of the sym links on the file system pointing to garbage links like syslogd -> /m/m/m/m/m/m/m/s/s/s/s/e/e/e/ and also other programs on the system would not run properly. After a reboot they would be fine for days to weeks.
Thought I would offer that up.
-Brian
Quoted 18 lines · Jon Ringle
Quoted 4 lines
I tried init=/bin/sh on a first boot after reflash and the md5sum of sshd was correct. I then rebooted again normally and the ssh keys were generated. When I logged in, the md5sum of sshd was wrong. The corruption that I observe is always the same incorrect md5sum.
But there's no corruption on the _flash_ -- if you boot with init=/bin/sh again after the keys are generated, you again get the _correct_ md5sum? I'm fairly certain of that, since the failure mode you'll get if you manage to scribble on the flash is that the data CRC will fail and you'll get zeroes where the offending nodes go missing.
It's going to be something scribbling on the RAM pages after the file is read from the file system. Be thankful it looks fairly repeatable. Can you put a hardware watchpoint on the offending page in the page cache, after it's read? And can you disable _everything_ in the system which uses DMA, one at a time?
Quoted 1 line · Brian T
Been reading this thread, and I was wondering what kind of hardware
this
Quoted 1 line
is running on? I remember running into something like this a few years
ago > on my companies own embedded hardware, and the cause turned out to be a
Quoted 1 line
problem with an internal Multitech modem's firmware on the same bus
which > was interfering with reading the jffs2 file system.
Quoted 3 lines
I would see many ( but not all ) of the sym links on the file system pointing to garbage links like syslogd ->
/m/m/m/m/m/m/m/s/s/s/s/e/e/e/
Quoted 4 lines
and also other programs on the system would not run properly. After a reboot they would be fine for days to weeks.
Thought I would offer that up.
Brian, I find that quite interesting. This is on our companies own hardware. We have an IXP455 in PCI option mode using an Intel StrataFlash P30 that is on CS0 of the IXP's expansion bus. The PCI host does perform some read-only access of the P30 flash via a PCI bus -> Expansion bus -> P30 flash data path to read info such as serial number, mac address and IP address of the IXP that is stored on the flash. We know that sometimes when the PCI host does this, it happens to do so when the IXP happens to be doing a write operation to flash, so the read operation by the PCI host returns "garbage". This is ok, because the data that the PCI host is reading is checksumed and all that the PCI host needs to do is retry the read again later.
I've been pouring over the P30 datasheet flowcharts to see if there is some race condition where a spurious flash read operation by the PCI host could interfere with the way that the IXP reads the contents of flash. So far, I haven't been able to find something like that.
How did you determine that the modem was causing your problem? It sure sounds like similar symptoms.
I decided to create a script that allows me to scan all the files in the jffs2 image and have found that when this problem doesn't appear in sshd, that I see this in other files with the same replacement of either 0x00000023 or 0x00000073 on some 32 bit value. I've seen this now show up in /etc/sshd_config and also /lib/libcrypto.so.0.9.7
When I get to the office tomorrow, I'll hook up the JTAG and try some of the things that David suggested.
Jon
Hi John,
Quoted 2 lines
How did you determine that the modem was causing your problem? It sure sounds like similar symptoms.
I talked to our hardware engineer this morning who reminded me of what the problem was. It was with a Conexant modem ( not Multitech like I had stated before ). These are basically his words, though I don't follow it fully ( which is why I am in software, and not hardware ;) )
"Basically, on our hardware, the Conexant modem was connected using it's Parallel port to save a UART on the main board. But while in this mode, it's address lines could become "output". The Intel flash we use is on 0xa0-0xa2, and the Conexant modem could sometimes "jam" 0xa1-0xa2 and cause use to see a temp corruption on the file system. "
After a new firmware for the modem was released, it should have fixed the problem, but by that time, our hardware engineer has switched the modem to be connected through it's serial interface.
Not sure if this makes sense. If you need me to revise I can ask him to clarify the fuzzy parts. Not sure if this helps you identify the problem you are seeing, but it might accidentally =)
-Brian
Quoted 1 line · David Woodhouse
It's going to be something scribbling on the RAM pages after the file
is
Quoted 4 lines
read from the file system. Be thankful it looks fairly repeatable. Can you put a hardware watchpoint on the offending page in the page cache, after it's read? And can you disable _everything_ in the system which uses DMA, one at a time?
I was able to disable everything else that had external hardware access to flash and the IXP's memory and the problem still appeared. I have now been able to determine that the fault lies with some memory scribbling done by one of our own kernel modules.
There is no need to further bother this mailing list with this issue.
Thanks David and Brian for your input in this problem :)
Jon