Bug #390
openLibflashrom progress goes backwards for erase and write operations
0%
Description
When flashrom runs with --progress argument in the command line, it shows % progress for all operations. % is working nicely for read and verify operations.
However for erase and write operations % starts with 0, goes up and then goes backwards to 0 again. By its nature, % progress should not go backwards.
Bug can be reproduced with dummyflasher.
Small repro case with just erase:
$ ./flashrom -p dummy:emulate=W25Q128FV -E --progress
flashrom v1.2-759-gcba5de5 on Linux 5.16.18-1rodete2-amd64 (x86_64)
flashrom is free software, get the source code at https://flashrom.org
Using clock_gettime for delay loops (clk_id: 1, resolution: 1ns).
Found Winbond flash chip "W25Q128.V" (16384 kB, SPI) on dummy.
Erasing and writing flash chip... [READ] 100% complete... [READ] 0% complete...
Erase/write done.
Longer repro case where you can see that read and verify works, but erase and write do not:
$ ./flashrom -p dummy:emulate=W25Q128FV,image=/tmp/rom -w /tmp/16m_rand.bin --progress
flashrom v1.2-763-gb10d55049 on Linux 5.18.1-arch1-1 (x86_64)
flashrom is free software, get the source code at https://flashrom.org
Using clock_gettime for delay loops (clk_id: 1, resolution: 1ns).
Found Winbond flash chip "W25Q128.V" (16384 kB, SPI) on dummy.
Reading old flash chip contents... [READ] 0% complete... [READ] 1% complete... [READ] 2% complete... [READ] 3% complete... [READ] 4% complete... [READ] 5% complete... [READ] 6% complete... [READ] 7% complete... [READ] 8% complete... [READ] 9% complete... [READ] 10% complete... [READ] 11% complete... [READ] 12% complete... [READ] 13% complete... [READ] 14% complete... [READ] 15% complete... [READ] 16% complete... [READ] 17% complete... [READ] 18% complete... [READ] 19% complete... [READ] 20% complete... [READ] 21% complete... [READ] 22% complete... [READ] 23% complete... [READ] 24% complete... [READ] 25% complete... [READ] 26% complete... [READ] 27% complete... [READ] 28% complete... [READ] 29% complete... [READ] 30% complete... [READ] 31% complete... [READ] 32% complete... [READ] 33% complete... [READ] 34% complete... [READ] 35% complete... [READ] 36% complete... [READ] 37% complete... [READ] 38% complete... [READ] 39% complete... [READ] 40% complete... [READ] 41% complete... [READ] 42% complete... [READ] 43% complete... [READ] 44% complete... [READ] 45% complete... [READ] 46% complete... [READ] 47% complete... [READ] 48% complete... [READ] 49% complete... [READ] 50% complete... [READ] 51% complete... [READ] 52% complete... [READ] 53% complete... [READ] 54% complete... [READ] 55% complete... [READ] 56% complete... [READ] 57% complete... [READ] 58% complete... [READ] 59% complete... [READ] 60% complete... [READ] 61% complete... [READ] 62% complete... [READ] 63% complete... [READ] 64% complete... [READ] 65% complete... [READ] 66% complete... [READ] 67% complete... [READ] 68% complete... [READ] 69% complete... [READ] 70% complete... [READ] 71% complete... [READ] 72% complete... [READ] 73% complete... [READ] 74% complete... [READ] 75% complete... [READ] 76% complete... [READ] 77% complete... [READ] 78% complete... [READ] 79% complete... [READ] 80% complete... [READ] 81% complete... [READ] 82% complete... [READ] 83% complete... [READ] 84% complete... [READ] 85% complete... [READ] 86% complete... [READ] 87% complete... [READ] 88% complete... [READ] 89% complete... [READ] 90% complete... [READ] 91% complete... [READ] 92% complete... [READ] 93% complete... [READ] 94% complete... [READ] 95% complete... [READ] 96% complete... [READ] 97% complete... [READ] 98% complete... [READ] 99% complete... [READ] 100% complete... done.
Erasing and writing flash chip... [WRITE] 6% complete... [READ] 0% complete... [WRITE] 0% complete... Erase/write done.
Verifying flash... [READ] 1% complete... [READ] 2% complete... [READ] 3% complete... [READ] 4% complete... [READ] 5% complete... [READ] 6% complete... [READ] 7% complete... [READ] 8% complete... [READ] 9% complete... [READ] 10% complete... [READ] 11% complete... [READ] 12% complete... [READ] 13% complete... [READ] 14% complete... [READ] 15% complete... [READ] 16% complete... [READ] 17% complete... [READ] 18% complete... [READ] 19% complete... [READ] 20% complete... [READ] 21% complete... [READ] 22% complete... [READ] 23% complete... [READ] 24% complete... [READ] 25% complete... [READ] 26% complete... [READ] 27% complete... [READ] 28% complete... [READ] 29% complete... [READ] 30% complete... [READ] 31% complete... [READ] 32% complete... [READ] 33% complete... [READ] 34% complete... [READ] 35% complete... [READ] 36% complete... [READ] 37% complete... [READ] 38% complete... [READ] 39% complete... [READ] 40% complete... [READ] 41% complete... [READ] 42% complete... [READ] 43% complete... [READ] 44% complete... [READ] 45% complete... [READ] 46% complete... [READ] 47% complete... [READ] 48% complete... [READ] 49% complete... [READ] 50% complete... [READ] 51% complete... [READ] 52% complete... [READ] 53% complete... [READ] 54% complete... [READ] 55% complete... [READ] 56% complete... [READ] 57% complete... [READ] 58% complete... [READ] 59% complete... [READ] 60% complete... [READ] 61% complete... [READ] 62% complete... [READ] 63% complete... [READ] 64% complete... [READ] 65% complete... [READ] 66% complete... [READ] 67% complete... [READ] 68% complete... [READ] 69% complete... [READ] 70% complete... [READ] 71% complete... [READ] 72% complete... [READ] 73% complete... [READ] 74% complete... [READ] 75% complete... [READ] 76% complete... [READ] 77% complete... [READ] 78% complete... [READ] 79% complete... [READ] 80% complete... [READ] 81% complete... [READ] 82% complete... [READ] 83% complete... [READ] 84% complete... [READ] 85% complete... [READ] 86% complete... [READ] 87% complete... [READ] 88% complete... [READ] 89% complete... [READ] 90% complete... [READ] 91% complete... [READ] 92% complete... [READ] 93% complete... [READ] 94% complete... [READ] 95% complete... [READ] 96% complete... [READ] 97% complete... [READ] 98% complete... [READ] 99% complete... [READ] 100% complete... VERIFIED.
Updated by Anastasia Klimchuk over 1 year ago
The code might change after the work on optimising erase algorithm, so nothing to do right now, we need to return back later.
Updated by Anastasia Klimchuk over 1 year ago
- Assignee set to Anastasia Klimchuk
Updated by Nico Huber over 1 year ago
Anastasia Klimchuk wrote in #note-1:
The code might change after the work on optimising erase algorithm, so nothing to do right now, we need to return back later.
I noticed this reasoning for procrastination somewhere in the review comments of CB:64663. I hope I understood it correctly as it seems somewhat confusing to me. If I misunderstood the situation, please ignore all the following.
I don't see how CB:49643 could collide with the erase optimizations. But assuming that it would, wouldn't that mean
- we'd let a GSoC student work on a broken, incomprehensible code base, which can only make their work harder?
- we'd maximize bugs at a particular point? Assuming that a big rework like the erase optimization is more likely to introduce issues than to fix any by chance, right after merging it we'd have the currently known bugs plus potentially additional ones.
Also, assuming that we still want to do a release from the master branch, this seems like a deadlock to me:
- Bugs in progress feature [P] block a release [R].
- Fixing P waits for erase optimizations [E].
- E waits for R because we shouldn't merge bigger changes right before a release.
Updated by Anastasia Klimchuk over 1 year ago
"procrastination"? This sounds overdramatic.
Let's get back to the technical points.
My previous comment was to capture the result of discussing this bug with "erase optimisation project" team, and with all the other people present at the meeting at that day. So the question whether the code collides a not was discussed with people working on the EOP team.
The decision was "nothing to do right now, we need to return back later" so the bug will be revisited soon.
There a revert patch prepared at the moment, if that would be the decision we can go ahead with the revert and re-implement the feature after the release.
Updated by Angel Pons over 1 year ago
Regarding the "procrastination" term, it feels unnecessarily loaded. While it made sense to put this on hold because of the GSoC project about optimizing erase function selection, the GSoC project should be complete now. So there's no reason to postpone working on this issue. Even if there are plans to do a release. For example, we'll revert CB:49643 in the 1.3.x release branch, and we could fix the implementation and land CB:64663 in master.
TL;DR let's get this moving again.
Updated by Anastasia Klimchuk over 1 year ago
Yep, it's just about time to get back to this.
Given that we have 1.3.x branch ready, the plan now is to revert https://review.coreboot.org/c/flashrom/+/49643 on 1.3.x (next week most likely).
As for master branch, long-term plan, I think I found some resources to fix the bug :)
So I will keep this bug as is for right now, but when the revert to 1.3.x is pushed/tested/merged I will unlink this bug from parent, which means release is unblocked and the bug remains for master branch.
Updated by Anastasia Klimchuk over 1 year ago
- Target version changed from 1.3 to main
- Parent task deleted (
#353)
Revert in 1.3.x is merged as https://review.coreboot.org/c/flashrom/+/69283
I am unlinking this bug from 353 and the work to fix the bug will be going on master.
Updated by Anastasia Klimchuk 12 months ago
This needs to be tested with new erase/write logic.
To enable it , change in flashrom.c
-static bool use_legacy_erase_path = true;
+static bool use_legacy_erase_path = false;
Updated by Anastasia Klimchuk 12 months ago
Just tested the same scenarios with new logic, things look differently now. There is no strict "going backwards" situation, but the progress goes from 0 to 100 more than once.
In the first case (erase dummy with W25Q128FV emulation) progress goes from 0 to 100 three times
Repro:
./flashrom -p dummy:emulate=W25Q128FV -E --progress
In the second case (write dummy with W25Q128FV emulation) progress goes from 0 to 100 two times
Repro:
./flashrom -p dummy:emulate=W25Q128FV -r /tmp/dump.bin --progress
head -c 8388608 /tmp/image.bin
./flashrom -p dummy:image=/tmp/image.bin,emulate=W25Q128FV -w /tmp/dump.bin --progress