| Message ID | 1370310406-413-3-git-send-email-computersforpeace@gmail.com |
|---|---|
| State | New, archived |
| Headers | show |
于 2013年06月04日 09:46, Brian Norris 写道: > After various tests, it seems simply that the timeout is not long enough > for my system; increasing it by a few jiffies prevented all failures > (testing for 12+ hours). There is no harm in increasing the timeout, but > there is harm in having it too short, as evidenced here. > I like the patch1 and patch 2. But extending the timeout from 1ms to 10ms is like a workaround. :) From the NOR's spec, even the maximum write-to-buffer only costs several hundreds us, such as 200us. I GUESS your problem is caused by the timer system, not the MTD code. I ever met this type of bug. The bug is in the kernel 3.5.7, but the latest kernel has fixed it with NO_HZ_IDLE/NO_HZ_COMMON features. I do not meet the issue the latest linux-next tree. I try to describe the jiffies bug with my poor english: [1] background: CONFIG_HZ=100, CONFIG_NO_HZ=y [2] call nand_wait() when we write a nand page. [3] The jiffies was not updated at a _even_ speed. In the nand_wait(), you wait for 20ms(2 jiffies) for a page write, and the timeout occurs during the page write. Of course, you think that we have already waited for 20ms. But in actually, we only waited for 1ms or less! How do i know this? I use the gettimeofday to check the real time when the timeout occur. [4] if i disable the local timer, the bug disappears. So, could you check the real time when the timeout occurs? Btw: My NOR's timeout is proved to be a silicon bug by Micron. thanks Huang Shijie
On Tue, Jun 4, 2013 at 12:03 AM, Huang Shijie <b32955@freescale.com> wrote: > 于 2013年06月04日 09:46, Brian Norris 写道: >> After various tests, it seems simply that the timeout is not long enough >> for my system; increasing it by a few jiffies prevented all failures >> (testing for 12+ hours). There is no harm in increasing the timeout, but >> there is harm in having it too short, as evidenced here. >> > I like the patch1 and patch 2. > > But extending the timeout from 1ms to 10ms is like a workaround. :) I was afraid you might say that; that's why I stuck the first two patches first ;) > From the NOR's spec, even the maximum write-to-buffer only costs several > hundreds us, > such as 200us. > > I GUESS your problem is caused by the timer system, not the MTD code. I > ever met this type of bug. I suspected similarly, but I didn't (until now) believe that's the case here. See below. > The bug is in the kernel 3.5.7, but the latest kernel has fixed it with > NO_HZ_IDLE/NO_HZ_COMMON features. Did you track your bug down to a particular commit? 3.5.7 is the stable kernel; do you know what mainline rev it showed up in? I'm not quite interested in backporting all of the new 3.10 features! > I do not meet the issue the latest linux-next tree. > > I try to describe the jiffies bug with my poor english: > > [1] background: > CONFIG_HZ=100, CONFIG_NO_HZ=y > > [2] call nand_wait() when we write a nand page. > > [3] The jiffies was not updated at a _even_ speed. > > In the nand_wait(), you wait for 20ms(2 jiffies) for a page write, > and the timeout occurs during the page write. Of course, you think that > we have already waited for 20ms. > But in actually, we only waited for 1ms or less! > How do i know this? I use the gettimeofday to check the real time when > the timeout occur. I suspected this very type of thing, since this has come up in a few different contexts. And for some time, with a number of different checks, it appeared that this *wasn't* the case. But while writing this very email, I had the bright idea that my time checkpoint was in slightly the wrong place; so sure enough, I found that I was timing out after only 72519 ns! (That is, 72 us, or well below the max write buffer time.) I'm testing on MIPS with a 3.3 kernel, by the way, but I believe this sort of bug has been around a while. > [4] if i disable the local timer, the bug disappears. > > So, could you check the real time when the timeout occurs? > > > > Btw: My NOR's timeout is proved to be a silicon bug by Micron. Interesting. Brian
Adding a few others For reference, this thread started with this patch: http://lists.infradead.org/pipermail/linux-mtd/2013-June/047164.html On Wed, Jun 5, 2013 at 11:01 AM, Brian Norris <computersforpeace@gmail.com> wrote: > On Tue, Jun 4, 2013 at 12:03 AM, Huang Shijie <b32955@freescale.com> wrote: >> 于 2013年06月04日 09:46, Brian Norris 写道: >>> After various tests, it seems simply that the timeout is not long enough >>> for my system; increasing it by a few jiffies prevented all failures >>> (testing for 12+ hours). There is no harm in increasing the timeout, but >>> there is harm in having it too short, as evidenced here. >>> >> I like the patch1 and patch 2. >> >> But extending the timeout from 1ms to 10ms is like a workaround. :) > > I was afraid you might say that; that's why I stuck the first two > patches first ;) ... >> I GUESS your problem is caused by the timer system, not the MTD code. I >> ever met this type of bug. ... >> I try to describe the jiffies bug with my poor english: >> >> [1] background: >> CONFIG_HZ=100, CONFIG_NO_HZ=y >> >> [2] call nand_wait() when we write a nand page. >> >> [3] The jiffies was not updated at a _even_ speed. >> >> In the nand_wait(), you wait for 20ms(2 jiffies) for a page write, >> and the timeout occurs during the page write. Of course, you think that >> we have already waited for 20ms. >> But in actually, we only waited for 1ms or less! >> How do i know this? I use the gettimeofday to check the real time when >> the timeout occur. > > I suspected this very type of thing, since this has come up in a few > different contexts. And for some time, with a number of different > checks, it appeared that this *wasn't* the case. But while writing > this very email, I had the bright idea that my time checkpoint was in > slightly the wrong place; so sure enough, I found that I was timing > out after only 72519 ns! (That is, 72 us, or well below the max write > buffer time.) So I can confirm that with the 1ms timeout, I actually am sometimes timing out at 40 to 70 microseconds. I think this may have multiple causes: (1) uneven timer interrupts, as suggested by Huang? (2) a jiffies timeout of 1 is two short (with HZ=1000, msecs_to_jiffies(1) is 1) Regarding reason (2): My thought (which matches with Imre's comments from his [1]) is that one problem here is that we do not know how long it will be until the *next* timer tick -- "waiting 1 jiffy" is really just waiting until the next timer tick, which very well might be in 40us! So the correct timeout calculation is something like: uWriteTimeout = msecs_to_jiffies(1) + 1; or with Imre's proposed methods (not merged upstream yet), just: uWriteTimeout = msecs_to_jiffies_timeout(1); Thoughts? Note that a 2-jiffy timeout does not, in fact, totally resolve my problems; with a timeout of 2 jiffies, I still get a timeout that (according to getnstimeofday()) occurs after only 56us. It does decrease its rate of occurrence, but Huang may still be right that reason (1) is involved. Brian [1] http://marc.info/?l=linux-kernel&m=136854294730957
On Wed, 2013-06-05 at 14:08 -0700, Brian Norris wrote: > Adding a few others > > For reference, this thread started with this patch: > > http://lists.infradead.org/pipermail/linux-mtd/2013-June/047164.html > > On Wed, Jun 5, 2013 at 11:01 AM, Brian Norris > <computersforpeace@gmail.com> wrote: > > On Tue, Jun 4, 2013 at 12:03 AM, Huang Shijie <b32955@freescale.com> wrote: > >> 于 2013年06月04日 09:46, Brian Norris 写道: > >>> After various tests, it seems simply that the timeout is not long enough > >>> for my system; increasing it by a few jiffies prevented all failures > >>> (testing for 12+ hours). There is no harm in increasing the timeout, but > >>> there is harm in having it too short, as evidenced here. > >>> > >> I like the patch1 and patch 2. > >> > >> But extending the timeout from 1ms to 10ms is like a workaround. :) > > > > I was afraid you might say that; that's why I stuck the first two > > patches first ;) > ... > >> I GUESS your problem is caused by the timer system, not the MTD code. I > >> ever met this type of bug. > ... > >> I try to describe the jiffies bug with my poor english: > >> > >> [1] background: > >> CONFIG_HZ=100, CONFIG_NO_HZ=y > >> > >> [2] call nand_wait() when we write a nand page. > >> > >> [3] The jiffies was not updated at a _even_ speed. > >> > >> In the nand_wait(), you wait for 20ms(2 jiffies) for a page write, > >> and the timeout occurs during the page write. Of course, you think that > >> we have already waited for 20ms. > >> But in actually, we only waited for 1ms or less! > >> How do i know this? I use the gettimeofday to check the real time when > >> the timeout occur. > > > > I suspected this very type of thing, since this has come up in a few > > different contexts. And for some time, with a number of different > > checks, it appeared that this *wasn't* the case. But while writing > > this very email, I had the bright idea that my time checkpoint was in > > slightly the wrong place; so sure enough, I found that I was timing > > out after only 72519 ns! (That is, 72 us, or well below the max write > > buffer time.) > > So I can confirm that with the 1ms timeout, I actually am sometimes > timing out at 40 to 70 microseconds. I think this may have multiple > causes: > (1) uneven timer interrupts, as suggested by Huang? > (2) a jiffies timeout of 1 is two short (with HZ=1000, msecs_to_jiffies(1) is 1) > > Regarding reason (2): > > My thought (which matches with Imre's comments from his [1]) is that > one problem here is that we do not know how long it will be until the > *next* timer tick -- "waiting 1 jiffy" is really just waiting until > the next timer tick, which very well might be in 40us! So the correct > timeout calculation is something like: > > uWriteTimeout = msecs_to_jiffies(1) + 1; > > or with Imre's proposed methods (not merged upstream yet), just: > > uWriteTimeout = msecs_to_jiffies_timeout(1); > > Thoughts? I think what you describe at (2) wouldn't cause a premature timeout in your case. The driver uses the returned jiffy value something like the following in all cases (before applying the patch with the +1 change): uWriteTimeout = msecs_to_jiffies(1); timeout = jiffies + uWriteTimeout; while (!condition) if (time_after(jiffies, timeout)) return -ETIMEDOUT; Here using time_after() as opposed to time_after_eq() serves as an implicit +1 and thus guarantees that you wait at least 1 msec. A bit off-topic: Though using msecs_to_jiffies() is not a problem here, I think in this case and almost always it would need less thinking and thus be safer to still use msecs_to_jiffies_timeout(). A rare exception would be when the +1 adjustment would accumulate to a significant error, like in the following polling loop: for (i = 0; i <= 50; i++) { if (poll_condition) return 0; schedule_timeout(msecs_to_jiffies(1)); } return -ETIMEDOUT; Here on HZ=1000 we would time out in average after 100 msec using msecs_to_jiffies_timeout(1), whereas the intention was 50 msecs. --Imre > Note that a 2-jiffy timeout does not, in fact, totally resolve my > problems; with a timeout of 2 jiffies, I still get a timeout that > (according to getnstimeofday()) occurs after only 56us. It does > decrease its rate of occurrence, but Huang may still be right that > reason (1) is involved. > > Brian > > [1] http://marc.info/?l=linux-kernel&m=136854294730957
于 2013年06月06日 05:08, Brian Norris 写道: > Note that a 2-jiffy timeout does not, in fact, totally resolve my > problems; with a timeout of 2 jiffies, I still get a timeout that > (according to getnstimeofday()) occurs after only 56us. It does since the 2-jiffy does not resolve your problem, i suggest you try the latest linux-next tree. thanks Huang Shijie
diff --git a/drivers/mtd/chips/cfi_cmdset_0002.c b/drivers/mtd/chips/cfi_cmdset_0002.c index 4e28081..45de025 100644 --- a/drivers/mtd/chips/cfi_cmdset_0002.c +++ b/drivers/mtd/chips/cfi_cmdset_0002.c @@ -1228,14 +1228,11 @@ static int __xipram do_write_oneword(struct map_info *map, struct flchip *chip, struct cfi_private *cfi = map->fldrv_priv; unsigned long timeo; /* - * We use a 1ms generic timeout for writes (most devices have a max - * write time of a few hundreds usec). However, we should use the - * maximum timeout value given by the chip at probe time instead. - * Unfortunately, struct flchip does have a field for maximum timeout, - * only for typical which can be far too short depending of the - * conditions. + * We use a 10ms generic timeout for writes. Most devices have a max + * write time of a few hundreds usec, but timeouts have been seen with + * too few jiffies. */ - unsigned long uWriteTimeout = msecs_to_jiffies(1); + unsigned long uWriteTimeout = msecs_to_jiffies(10); int ret = 0; map_word oldd; int retry_cnt = 0; @@ -1465,7 +1462,7 @@ static int __xipram do_write_buffer(struct map_info *map, struct flchip *chip, struct cfi_private *cfi = map->fldrv_priv; unsigned long timeo; /* see comments in do_write_oneword() regarding uWriteTimeout */ - unsigned long uWriteTimeout = msecs_to_jiffies(1); + unsigned long uWriteTimeout = msecs_to_jiffies(10); int ret = -EIO; unsigned long cmd_adr; int z, words; @@ -1716,7 +1713,7 @@ static int cfi_amdstd_panic_wait(struct map_info *map, struct flchip *chip, static int do_panic_write_oneword(struct map_info *map, struct flchip *chip, unsigned long adr, map_word datum) { - const unsigned long uWriteTimeout = msecs_to_jiffies(1); + const unsigned long uWriteTimeout = msecs_to_jiffies(10); struct cfi_private *cfi = map->fldrv_priv; int retry_cnt = 0; map_word oldd;
I have seen various failures like this while doing a simple reboot + mount UBIFS test: UBIFS: recovery needed MTD do_write_buffer(): software timeout UBI error: ubi_io_write: error -5 while writing 512 bytes to PEB 365:43648, written 192 bytes (This message doens't exactly match the message in the current head of tree, as Huang edited the timeout message.) I'm using a 64Mbyte Spansion S29GL512 NOR flash. I've also seen reports of the same failure on Micron 128Mbyte NOR flash AM29EWLD. After various tests, it seems simply that the timeout is not long enough for my system; increasing it by a few jiffies prevented all failures (testing for 12+ hours). There is no harm in increasing the timeout, but there is harm in having it too short, as evidenced here. This patch increases the timeout value in 3 locations, as they all are referencing the do_write_oneword function. I have only ever seen the timeout in do_write_buffer(). Signed-off-by: Brian Norris <computersforpeace@gmail.com> --- drivers/mtd/chips/cfi_cmdset_0002.c | 15 ++++++--------- 1 file changed, 6 insertions(+), 9 deletions(-)