Cannot read file, error code 1 (5 times in 2 days)

Vlad

yes
https://www.amazon.com/dp/B06XYT37NK/ Sandisk Extreme Pro, Class 10, U3. This is the fastest card on a market, and any card can handle this pretty much. This card is roughly 100x faster than even needed for this task.
I only use Sandisk brand, and I tried 4 different card models. All these cards work flawlessly with everything supporting extremely high data transfer rates.
stepper cables are as far as they can possible be from that location.
File system: FAT32, Cluster 64KB (also tried 32 and 4). Tried cards capacities: 16GB, 32GB, 64GB.
Also if such problem exists, I don't understand why the printer completely fails/stops/cancels print after this error instead of simply retrying to read the same line for numerous times. Wouldn't it make more sense and at least reduce a trouble?
Worth noting that it almost always stops at small sections with a lot of commands per second (small cylinders), seems as CPU is struggling to read larger amounts of lines, which never happened even on 8 bit boards with me they would throttle there instead, but never failed like this. Printer is Cartesian - the lightest geometry in terms of calculation power requirement. Pressure advance is on. microstepping is 32.

6/23/2019, 1:37:14 PM: Connected to 192.168.1.145
6/23/2019, 1:37:32 PM: Emergency stop, attempting to reconnect...
6/23/2019, 1:37:43 PM: Connection established
6/23/2019, 1:39:19 PM: M122: === Diagnostics ===
RepRapFirmware for Duet 2 WiFi/Ethernet version 2.02(RTOS) running on Duet WiFi 1.02 or later
Board ID: 08DGM-917DA-G4MS8-6JKD0-3S86J-K9SBA
Used output buffers: 3 of 20 (16 max)
=== RTOS ===
Static ram: 25524
Dynamic ram: 98588 of which 0 recycled
Exception stack ram used: 376
Never used ram: 6584
Tasks: NETWORK(ready,648) HEAT(blocked,1232) MAIN(running,3780) IDLE(ready,200)
Owned mutexes:
=== Platform ===
Last reset 00:01:44 ago, cause: software
Last software reset at 2019-06-23 13:37, reason: User, spinning module GCodes, available RAM 6568 bytes (slot 3)
Software reset code 0x0003 HFSR 0x00000000 CFSR 0x00000000 ICSR 0x0041f000 BFAR 0xe000ed38 SP 0xffffffff Task 0x4e49414d
Error status: 0
Free file entries: 10
SD card 0 detected, interface speed: 20.0MBytes/sec
SD card longest block write time: 0.0ms, max retries 0
MCU temperature: min 32.0, current 34.2, max 34.5
Supply voltage: min 23.8, current 24.0, max 24.3, under voltage events: 0, over voltage events: 0, power good: yes
Driver 0: standstill, SG min/max 0/121
Driver 1: standstill, SG min/max 0/9
Driver 2: standstill, SG min/max 0/526
Driver 3: standstill, SG min/max not available
Driver 4: standstill, SG min/max not available
Date/time: 2019-06-23 13:39:18
Cache data hit count 382935555
Slowest loop: 7.91ms; fastest: 0.07ms
I2C nak errors 0, send timeouts 0, receive timeouts 0, finishTimeouts 0
=== Move ===
Hiccups: 0, StepErrors: 0, LaErrors: 0, FreeDm: 240, MinFreeDm: 238, MaxWait: 21138ms, Underruns: 0, 0
Scheduled moves: 9, completed moves: 9
Bed compensation in use: none
Bed probe heights: 0.000 0.000 0.000 0.000 0.000
=== Heat ===
Bed heaters = 0 -1 -1 -1, chamberHeaters = -1 -1
Heater 0 is on, I-accum = 0.0
Heater 1 is on, I-accum = 0.0
=== GCodes ===
Segments left: 0
Stack records: 1 allocated, 0 in use
Movement lock held by null
http is idle in state(s) 0
telnet is idle in state(s) 0
file is idle in state(s) 0
serial is idle in state(s) 0
aux is idle in state(s) 0
daemon is idle in state(s) 0
queue is idle in state(s) 0
autopause is idle in state(s) 0
Code queue is empty.
=== Network ===
Slowest loop: 22.74ms; fastest: 0.00ms
Responder states: HTTP(0) HTTP(0) HTTP(0) HTTP(0) FTP(0) Telnet(0) Telnet(0)
HTTP sessions: 1 of 8

WiFi -
Network state is running
WiFi module is connected to access point
Failed messages: pending 0, notready 0, noresp 0
WiFi firmware version 1.22
WiFi MAC address *
WiFi Vcc 3.42, reset reason Turned on by main processor
WiFi flash size 4194304, free heap 29000
WiFi IP address *
WiFi signal strength -58dBm, reconnections 0, sleep mode modem
Socket states: 0 0 0 0 0 0 0 0

Vlad

@dc42 I also tried to move AC cable a bit further from that location, not sure if this can even affect this, but so far I had 4 prints without a failure. Gonna keep printing now.

No, stopped again.... Super annoying. Didn't expect the most expensive board on a market will lead me only to extra wasted time and material... Especially in the most important time when I need my printer.

dc42

Hi Vlad,

Thanks for your report. It's an unusual fault.

Please update the firmware to 2.03, because it may make a difference.

When an SD card transaction fails, RRF currently makes up to 2 more attempts before giving up. I can increase that number if you like. I can also try inserting a delay between attempts, because when our OEM encountered this issue last year, it seemed that the SD card had gone to sleep (perhaps doing wear levelling) and needed time to recover.

The M122 report includes the maximum number of SD card retries done since power up or since you last ran M122. In your report above:

SD card longest block write time: 0.0ms, max retries 0

If you still encounter that problem when you use firmware 2.03, then I'm happy to authorise a warranty replacement for that board, even though I doubt that it is caused by a hardware fault on the Duet.

Veti

@vlad said in Cannot read file, error code 1 (5 times in 2 days):

I only use Sandisk brand, and I tried 4 different card models. All these cards work flawlessly with everything supporting extremely high data transfer rates.

have you tried the sd card that came with the duet?

dc42

SanDisk should be fine, that's mostly what I use.

Vlad

@dc42 David, warranty replacement is also an inconvenience, as I will have to drive for one hour to your distributor here and replace the whole board inside. This involves a lot of time and also extra expense.

If you doubt that this is hardware fault, then what is the point of replacement, let's then fix it somehow.

So far it has been working on 2.03 firmware since yesterday with 75% success rate on prints, meaning the error is still there. And that is 30 minute prints, if I start something longer that success rate could drop drastically. As I said, what I noticed is that it would almost always stop in most "data dense" section of the print. my pressure advance is 0.03 and speeds are quite fast, do you think the CPU may be overloaded by this?

I remember having this same fault on this board the very first day I installed it, but then it never happened again for a long time. During all this time nothing was changed on this printer hardware wise, at all.

I am more than willing to run more troubleshooting attempts within firmware if you really think that can resolve the issue for good.

dc42

Two other possibilities occur to me:

It could be a power issue. Next time this problem occurs, run M122 before you do reset or power down the printer, and post the result here. It must be the result from the first time you run M122 after the problem occurs.
Do you have the USB port connected to a PC? If so then the problem might be caused by ground transients. See https://duet3d.dozuki.com/Wiki/USB_ground_loops.

Vlad

@dc42 Hi David,

I will try M122 today.
I am familiar with ground loops and no, I don't.

Vlad

@dc42 Also, if it helps, I always use the button "print another" as I am printing 200pcs. Maybe it has something to do with that.

Here is M122:

6/26/2019, 7:16:37 PM: Connected to 192.168.1.145
6/26/2019, 7:19:06 PM: Upload of B-V1.0.gcode successful after 2s
6/26/2019, 7:19:06 PM: M32 "0:/gcodes/B-V1.0.gcode": File 0:/gcodes/B-V1.0.gcode selected for printing
6/26/2019, 7:19:33 PM: : Warning: M73 command is not supported
6/26/2019, 7:21:05 PM: M566 X600 Y600 Z8 E150
6/26/2019, 7:48:08 PM: : Finished printing file 0:/gcodes/B-V1.0.gcode, print time was 0h 29m
6/26/2019, 7:56:43 PM: M32 "0:/gcodes/B-V1.0.gcode": File 0:/gcodes/NV-Box-V1.0.gcode selected for printing
6/26/2019, 7:58:01 PM: : Warning: M73 command is not supported
6/26/2019, 8:26:37 PM: : Finished printing file 0:/gcodes/NV-Box-V1.0.gcode, print time was 0h 30m
6/26/2019, 8:29:48 PM: M32 "0:/gcodes/B-V1.0.gcode": File 0:/gcodes/B-V1.0.gcode selected for printing
6/26/2019, 8:30:45 PM: : Warning: M73 command is not supported
6/26/2019, 8:31:51 PM: M566 X400 Y400 Z8 E150
6/26/2019, 8:45:16 PM: : Error: Cannot read file, error code 1
Cancelled printing file 0:/gcodes/B-V1.0.gcode, print time was 0h 15m
6/26/2019, 8:48:41 PM: M120
6/26/2019, 8:49:00 PM: M122: === Diagnostics ===
RepRapFirmware for Duet 2 WiFi/Ethernet version 2.03 running on Duet WiFi 1.02 or later
Board ID: 08DGM-917DA-G4MS8-6JKD0-3S86J-K9SBA
Used output buffers: 3 of 24 (20 max)
=== RTOS ===
Static ram: 25680
Dynamic ram: 93664 of which 0 recycled
Exception stack ram used: 452
Never used ram: 11276
Tasks: NETWORK(ready,524) HEAT(blocked,1236) MAIN(running,3748) IDLE(ready,160)
Owned mutexes:
=== Platform ===
Last reset 01:35:17 ago, cause: power up
Last software reset at 2019-06-23 22:49, reason: User, spinning module GCodes, available RAM 11380 bytes (slot 3)
Software reset code 0x0003 HFSR 0x00000000 CFSR 0x00000000 ICSR 0x0441f000 BFAR 0xe000ed38 SP 0xffffffff Task 0x4e49414d
Error status: 0
Free file entries: 10
SD card 0 detected, interface speed: 20.0MBytes/sec
SD card longest block write time: 13.4ms, max retries 0
MCU temperature: min 27.2, current 47.0, max 47.5
Supply voltage: min 23.7, current 24.1, max 24.4, under voltage events: 0, over voltage events: 0, power good: yes
Driver 0: standstill, SG min/max 0/348
Driver 1: standstill, SG min/max 0/321
Driver 2: standstill, SG min/max 0/643
Driver 3: standstill, SG min/max not available
Driver 4: standstill, SG min/max not available
Date/time: 2019-06-26 20:48:58
Cache data hit count 4294967295
Slowest loop: 546.79ms; fastest: 0.07ms
I2C nak errors 0, send timeouts 0, receive timeouts 0, finishTimeouts 0, resets 0
=== Move ===
Hiccups: 0, FreeDm: 169, MinFreeDm: 106, MaxWait: 580296ms
Bed compensation in use: none, comp offset 0.000
=== DDARing ===
Scheduled moves: 0, completed moves: 27, StepErrors: 0, LaErrors: 0, Underruns: 0, 2
=== Heat ===
Bed heaters = 0 -1 -1 -1, chamberHeaters = -1 -1
Heater 0 is on, I-accum = 0.0
Heater 1 is on, I-accum = 0.3
=== GCodes ===
Segments left: 0
Stack records: 1 allocated, 1 in use
Movement lock held by null
http is idle in state(s) 0 0
telnet is idle in state(s) 0
file is idle in state(s) 0
serial is idle in state(s) 0
aux is idle in state(s) 0
daemon is idle in state(s) 0
queue is idle in state(s) 0
autopause is idle in state(s) 0
Code queue is empty.
=== Network ===
Slowest loop: 56.64ms; fastest: 0.00ms
Responder states: HTTP(0) HTTP(0) HTTP(0) HTTP(0) FTP(0) Telnet(0) Telnet(0)
HTTP sessions: 1 of 8

WiFi -
Network state is running
WiFi module is connected to access point
Failed messages: pending 0, notready 0, noresp 0
WiFi firmware version 1.23
WiFi MAC address b4:e6:2d:53:16:0a
WiFi Vcc 3.43, reset reason Turned on by main processor
WiFi flash size 4194304, free heap 25704
WiFi IP address 192.168.1.145
WiFi signal strength -59dBm, reconnections 0, sleep mode modem
Socket states: 0 0 0 0 0 0 0 0

Vlad

@dc42 for the record, my first duet board which failed ran at exact same setup and I never had such problem on that one.

What is strange, is that I checked retries on this report and you can see it is zero there.

SD card longest block write time: 13.4ms, max retries 0

dc42

Yes, that is odd.

As I said before, I'll support your warranty claim if you want to exchange the Duet.

Vlad

@dc42 Ok, how do I proceed with it, what is the process? I purchased this at matterhackers. I will be at their store next week.

dc42

@vlad, I suggest you email them and direct them to this thread.

Matterhackers, please exchange Vlad's board.

Vlad

@dc42 ok, will do, thanks!

Vlad

Hi David @dc42 While I am still trying to find a time to drive to matterhackers, I installed another Duet board on this machine that I had handy, and it gives me exact same issue. I am starting to believe that there is no reason to exchange the board if it's gonna have exact same issue.

Is it possible that I am exceeding a cap for number of commands or reads per second for this MCU?

Also is it possible to have a workaround in firmware where it reattempts the read again instead of freezing forever? Possibly increase command buffer maybe? Occasional stall wouldn't be so disastrous if firmware could resume printing at least. I usually print high resolution models and at relatively high speeds, but nothing crazy. It froze now at 220mm/s at the curve/fillet location. Never freezes at straight line, so I guess it has to do with some processing cap being reached.

As a side note, I already reached a cap of print speed with 256 microstepping at 200mm/s. So I have to drop microstepping to 128, and 256 is not really achievable in this case, even on my simple Cartesian machine. Hope you guys soon come up with faster chip

P.S: I can also provide a factory file from S3D if you want to try to replicate the issue on your machine.

Vlad

@dc42 another thought: has anyone actually printed fast with this board? maybe I am overloading the MCU with 150mm/s? But to be honest my average speeds that are in 150mm/s area, are not really any fast... Reducing STL resolution seems to do nothing. I am out of thoughts. Also I closed web server window in last 4 prints just to see, and all 4 completed fine. Regardless I think this is serious and valid firmware bug that it simply cancels everything instead of continuing the print after reattempting to read card. MKS SBASE was lagging in similar way, it could freeze for up to 20 seconds, but it will eventually continue and print wasn't wasted.

dc42

Firmware 2.0 and later already retries reading from the SD card several times. See lines 192 onwards at https://github.com/dc42/RepRapFirmware/blob/dev/src/Libraries/Fatfs/diskio.cpp. The constant MaxSdCardTries is set to 3 and SdCardRetryDelay is set to 30.

dc42

@vlad said in Cannot read file, error code 1 (5 times in 2 days):

As a side note, I already reached a cap of print speed with 256 microstepping at 200mm/s. So I have to drop microstepping to 128, and 256 is not really achievable in this case, even on my simple Cartesian machine.

That is expected. The Trinamic chips can interpolate x16 microstepping to x256, and that is the setting we recommend for most purposes.

Vlad

@dc42 As soon as printer freezes, I get error message about SD card and everything is cancelled that exact moment, and it is never retried.

I have the latest firmware (just installed this week). And error message says it is cancelled and that happens immediately. No way it is retrying anything. Another thought, is that my web interface is very jerky when it comes to uploading files (cursor is acting weird), so I tried to close web interface in my browser while printing, and so far 5 prints went without problem with web interface closed. Do you think web client can cause this possibly?
I tried to play with enabling interpolation, but it seems to do nothing. Maybe I am wrong, but I expected interpolation to have the same effect on stepper noise. For example 16x is noisy, 256x is silent. So I was expecting 16x with interpolation enabled to become more silent vs 16x without interpolation, which is not the case. I even tested on super noisy 2x setting and enabling interpolation does nothing to noise, which I thought it should.
Another problem that I reported about a year ago still there too - that is incorrect values for current/accel/jerk on a first printer move after power on. Even if I set for example 0.2A current, and restart the machine, it will be very obviously getting some "default" setting instead, until the first command, after that command everything is read front he config file normally. Any progress on this bug at all? This also persists on all boards, my friends confirmed the same behavior on their Duets.

Vlad

@dc42

Doesn't look like it was retrying anything at all David. Will this bug be looked at at all? My board is unusable pretty much now and exchanging it is not going to do anything, as I mentioned before. This doesn't look like the issue only on this board.

Tried enabling logging, does nothing, not catching any useful information at all... Not even sure what it is trying to write during printing...