Wow. Confirmed, speedup is at least factor 5. And better yet, the fsync() overhead is reduced from ~50 ms to < 10 ms as well, the performance impact of SD logging is now fully acceptable for every day use. All of my beta testers use SD cards to provide debug logs. Some also have been doing CAN logging, which helped debug some timing issues. I'll need another 3.1 module anyway, but the testers will most likely want to continue using their modules. I'll forward your rework offer and the info on how to solve this themselves if they're capable of doing micro-soldering. Regards, Michael Am 17.05.2018 um 10:40 schrieb Mark Webb-Johnson:
It is a lot faster when working correctly. To me, it seems much more than 25%. Maybe four or five times faster?
You can try:
config set sdcard maxfreq.khz 20000
then reboot and power from USB. Then try your speed test. Perhaps vfs cp from SD to SD to test?
Regards, Mark.
On 17 May 2018, at 4:15 PM, Michael Balzer <dexter@expeedo.de <mailto:dexter@expeedo.de>> wrote:
Thanks for the analysis and solution!
What kind of speedup is achievable by replacing the cp2102? Is it just linear 16 → 20 MHz = 25%?
Or does this also solve hidden retransmission issues?
balzer@leela:~/esp/Open-Vehicle-Monitoring-System-3/vehicle/OVMS.V3> time ssh dexze85.local "vfs ls /sd/logs" 541.7k 22-Apr-2018 22:34 can-180422 449.0k 17-May-2018 09:56 log 580.8k 01-May-2018 18:15 dm 1.0M 30-Apr-2018 00:51 log.20180430-005121 1.0M 30-Apr-2018 10:27 log.20180430-102732 1.0M 30-Apr-2018 19:41 log.20180430-194146 1.0M 01-May-2018 02:21 log.20180501-022128 1.0M 01-May-2018 11:03 log.20180501-110318 80 01-May-2018 14:09 can-180501 1.0M 01-May-2018 17:56 log.20180501-175658 1.1M 01-May-2018 18:17 dm2 2.0M 01-May-2018 18:28 dm3 1.3M 01-May-2018 20:21 dm4 1.0M 02-May-2018 04:06 log.20180502-040605 1.0M 02-May-2018 13:38 log.20180502-133816 1.0M 03-May-2018 00:04 log.20180503-000415 1.0M 03-May-2018 10:38 log.20180503-103815 1.0M 03-May-2018 19:46 log.20180503-194654 1.0M 04-May-2018 06:22 log.20180504-062242 1.0M 04-May-2018 17:23 log.20180504-172311 1.0M 05-May-2018 03:50 log.20180505-035002 1.0M 05-May-2018 15:01 log.20180505-150115 1.0M 06-May-2018 01:22 log.20180506-012241 1.0M 06-May-2018 09:42 log.20180506-094249 1.0M 06-May-2018 16:58 log.20180506-165842 1.0M 07-May-2018 02:08 log.20180507-020820 1.0M 07-May-2018 09:08 log.20180507-090846 1.0M 07-May-2018 13:10 log.20180507-131042 630.2k 23-Apr-2018 23:51 can-180423 1.0M 07-May-2018 16:40 log.20180507-164032 3.6M 24-Apr-2018 00:30 can-180424 1.0M 24-Apr-2018 01:09 log.20180424-010932 1.0M 24-Apr-2018 11:36 log.20180424-113642 1.0M 24-Apr-2018 18:41 log.20180424-184124 1.0M 25-Apr-2018 02:54 log.20180425-025415 1.0M 25-Apr-2018 13:10 log.20180425-131000 1.0M 25-Apr-2018 23:40 log.20180425-234048 1.0M 26-Apr-2018 08:23 log.20180426-082309 1.0M 26-Apr-2018 13:17 log.20180426-131718 1.0M 26-Apr-2018 17:32 log.20180426-173218 1.0M 26-Apr-2018 22:26 log.20180426-222645 1.0M 27-Apr-2018 06:19 log.20180427-061932 1.0M 27-Apr-2018 11:45 log.20180427-114534 1.0M 27-Apr-2018 16:07 log.20180427-160751 1.0M 28-Apr-2018 05:07 log.20180428-050703 1.0M 28-Apr-2018 14:39 log.20180428-143956 1.0M 29-Apr-2018 00:07 log.20180429-000755 1.0M 29-Apr-2018 10:26 log.20180429-102600 1.0M 29-Apr-2018 14:09 log.20180429-140942 1.0M 07-May-2018 18:39 log.20180507-183951 1.0M 07-May-2018 21:18 log.20180507-211821 1.0M 08-May-2018 01:06 log.20180508-010616 1.0M 08-May-2018 08:12 log.20180508-081232 1.0M 08-May-2018 13:31 log.20180508-133133 1.0M 08-May-2018 14:52 log.20180508-145232 1.0M 08-May-2018 15:55 log.20180508-155530 1.0M 08-May-2018 16:18 log.20180508-161814 1.0M 08-May-2018 16:33 log.20180508-163344 1.0M 08-May-2018 16:51 log.20180508-165156 1.0M 08-May-2018 18:40 log.20180508-184035 1.0M 09-May-2018 02:13 log.20180509-021338 1.0M 09-May-2018 11:28 log.20180509-112803 1.0M 09-May-2018 13:10 log.20180509-131042 1.0M 09-May-2018 13:30 log.20180509-133049 1.0M 09-May-2018 13:46 log.20180509-134607 1.0M 09-May-2018 14:02 log.20180509-140208 1.0M 09-May-2018 14:17 log.20180509-141725 1.0M 09-May-2018 14:31 log.20180509-143108 1.0M 09-May-2018 14:44 log.20180509-144407 1.0M 09-May-2018 14:58 log.20180509-145806 1.0M 09-May-2018 15:20 log.20180509-152009 1.0M 09-May-2018 18:59 log.20180509-185904 1.0M 10-May-2018 00:10 log.20180510-001018 1.0M 10-May-2018 09:11 log.20180510-091155 1.0M 10-May-2018 13:57 log.20180510-135727 1.0M 10-May-2018 21:50 log.20180510-215045 1.0M 11-May-2018 07:34 log.20180511-073403 1.0M 11-May-2018 13:24 log.20180511-132440 1.0M 11-May-2018 17:13 log.20180511-171332 1.0M 11-May-2018 22:00 log.20180511-220047 1.0M 12-May-2018 11:08 log.20180512-110827 1.0M 12-May-2018 15:30 log.20180512-153022 1.0M 12-May-2018 17:42 log.20180512-174248 1.0M 12-May-2018 22:29 log.20180512-222949 1.0M 13-May-2018 10:03 log.20180513-100341 1.0M 13-May-2018 14:26 log.20180513-142603 1.0M 13-May-2018 22:53 log.20180513-225343 1.0M 14-May-2018 07:58 log.20180514-075805 1.0M 14-May-2018 11:35 log.20180514-113524 1.0M 14-May-2018 16:27 log.20180514-162753 1.0M 15-May-2018 01:31 log.20180515-013153 1.0M 15-May-2018 08:58 log.20180515-085847 1.0M 15-May-2018 12:30 log.20180515-123053 1.0M 15-May-2018 18:24 log.20180515-182435 1.0M 16-May-2018 07:25 log.20180516-072553 1.0M 16-May-2018 08:55 log.20180516-085501 1.0M 16-May-2018 12:01 log.20180516-120115 1.0M 16-May-2018 19:46 log.20180516-194613 1.0M 17-May-2018 06:14 log.20180517-061451
*real 0m18.965s* user 0m0.018s sys 0m0.009s
Am 17.05.2018 um 04:22 schrieb Mark Webb-Johnson:
Good grief. A year into this, and still writing about SD CARD issues with ESP32. If I could get into a room with the engineer who decided to share boot strapping pins with SDCARD pins, and to hard wire the SDIO controller to specific pins, I would literally try to slap some sense into him.
The China guys and I have been struggling for the past couple of months trying to work out why we can’t get as much speed out of the SD CARD as we wanted. If we raise the speed to the normal 20MHz, we randomly get errors (timeouts, checksums, etc). It looked like interference on the bus lines, but scoping those we can’t find any. Dropping the speed to 16MHz works around the issue, but SD CARD accesses are slow.
Then, we worked out it wasn’t random. It was based on whether we were powering from USB or external 12V. On the bench it works fine. In the car the problem appears. Simply put, if the USB was plugged in the ‘interference’ disappeared. If USB was unplugged, it came back. USB + external 12V combination also didn’t suffer from the issue, so the problem is not coming from the 12v side. The issue often appeared on only the second test of SD CARD, not the first. We didn’t see this problem on either the v3.0 developer modules, or v3.1 prototypes.
We looked at the capacitors and pull-up resistors on that side of the circuit, without success. Whatever we did made little difference (or randomly changed things for the better/worse). We thought maybe ground-line interference, but nope. We spent some time looking at C20, C22, C23 to see if the manufacturers had messed up the component values - they hadn’t.
Anyway, to cut a long story short, we finally found the culprit. The CP2102 chip itself.
We’d already had to change the power supply design early on in the project to cope with a bug in CP2102 not correctly handling USB host disconnect and not properly going into suspend mode (to reduce power consumption of cp2101 circuit when usb was disconnected) - our current design completely powers down the cp2102 chip when the USB cable is disconnected. Michael Stegen had previously warned me about clones of this chip (see https://wiki.sha2017.org/w/Projects:Badge and what they went through), and we had added the extra resistor already to cope with that eventuality. But, from what we can tell this is not a clone part issue. Here is what we found:
1. OVMS v3.0 and early v3.1 prototypes use CP2102 v1412+. For that chip, when the USB cable is disconnected, CSL-TXD is 3.3v. 2. OVMS v3.1 first production batch use a newer CP2102 v1708+. For that chip, when the USB cable is disconnected, CSL-TXD is pulled down to 0.78v. 3. We have replaced the cp2102 on a v3.1 first production module with v1412+, and SD CARD resumes normal operation (even with usb disconnected). 4. The version number seems to be a date code. YYWW (year, week), I guess. 5. We have absolutely no idea why this would be affecting the SD CARD performance or interference. Somehow, that CSL-TXD line is going through the ESP32 chip and affecting the SDIO controller (perhaps related to the bootstrapping pins dual use). The interference we see is inside the ESP32, not on the lines going from ESP32 to the SDCARD (which is why we couldn’t see it on the scope).
I tried shutting down the pins on the ESP32 for CSL-TXD and CSL-RXD, to see if I could work around the problem in firmware, but couldn’t get it to work. There is no way of knowing whether the USB is connected, and even if we did know, setting CSL-TXD and CSL-RXD pins to output mode, or float, doesn’t seem to make any difference.
The good news is that we’ve at least identified the problem. We are (a) checking the revision of cp2102 chip in the upcoming production batch, and (b) changing QC procedures to set SD CARD bus speed to default (20MHz) and randomly test modules twice on 12V power. Latest production batch is now using v1742+, and that has been tested as working. Going forward, we can resolve this.
As for the first production batch units, they are what they are. For normal SD CARD operation (copying files, flashing firmware, etc), it makes little difference. I guess most users don’t even have an SD CARD inserted. The speed limitation really only becomes an issue if you are trying to log lots of data to SD CARD (such as CAN bus dumps). If the USB is connected, you can 'config set sdcard maxfreq.khz 20000’ and it will work faster. The CP2102 chip can be changed, and I’ll do that for anyone that needs it. I’m asking China to send me some from the latest production batch that we know works. Replacement is relatively straightforward, but involves micro-soldering (the cp2102 is a surface mount chip, very small footprint, with lots of other components near it on the board).
Regards, Mark.
_______________________________________________ OvmsDev mailing list OvmsDev@lists.openvehicles.com http://lists.openvehicles.com/mailman/listinfo/ovmsdev
-- Michael Balzer * Helkenberger Weg 9 * D-58256 Ennepetal Fon 02333 / 833 5735 * Handy 0176 / 206 989 26 _______________________________________________ OvmsDev mailing list OvmsDev@lists.openvehicles.com <mailto:OvmsDev@lists.openvehicles.com> http://lists.openvehicles.com/mailman/listinfo/ovmsdev
_______________________________________________ OvmsDev mailing list OvmsDev@lists.openvehicles.com http://lists.openvehicles.com/mailman/listinfo/ovmsdev
-- Michael Balzer * Helkenberger Weg 9 * D-58256 Ennepetal Fon 02333 / 833 5735 * Handy 0176 / 206 989 26