vintagepc / MK404

A functional Simulator for Prusa (Mini/Einsy) Rambo based printers
https://vintagepc.github.io/MK404/
GNU General Public License v3.0
70 stars 9 forks source link

Print from SD WDR, take 2 #182

Closed vintagepc closed 4 years ago

vintagepc commented 4 years ago

Seems this is still an issue with the file checking causing a WDR on certain files.

Once more into the breach... (Re-visit of #115)

vintagepc commented 4 years ago

Interesting find... despite various attempts and debugging efforts, the command processing seems to stall at a certain point and not process (dequeue) any more lines from the command buffer - even if I extend the WDR cycle count.

For some reason, disabling the WDR, it will hang until after the WDR fires, and then resume processing the queue: (debug output truncated to the first 3 chars of the command, so that the serial time does not add too much overhead and skew the analysis)

G1 .
G1 .
M10.
G1 .
M70.
<< waits for 2-3 seconds as I extended the WDR timer by 50% (4s -> 6s) >>
Would have WDRed <-- Output I added to indicate when the WDR fires
G4 .
M22.
M90.
M10.
M14.
M10.
G1 .
G0 .
M84.
G4 .
M30.
M73.
M73.
echo:enqueing "M23 5cubes~1.gco"..
echo:enqueing "M24"..
OnCmdReady activating 4 bits mode

I wonder if there's an issue somewhere in retrieving the last block of a file from the card or something... Any immediate thoughts on this or areas I should look at extra carefully, @leptun?

Alas I don't have an SPI capable DSO, or I could sniff and compare the SD traffic to the VCD trace for the same file...

leptun commented 4 years ago

@vintagepc As luck would have it, I've recently played with a hardware implementation of the SD emulation. I've used an STM32F4 at a reduced SPI clock frequency and I was able to "Print from USB" with small modifications to the SD automaton. There was only one edge case where the simulator had an impossible advantage as it was able to instantly respond with the right message on the same clock cycle (it should only be able to respond on the second request by the master).

This honestly stinks a lot like a firmware bug with the cmdqueue. I've recently found a gcode which seems to make the printer reset when printing it at a certain line. Maybe you can do a bit of debugging in the cmdqueue and maybe find out what happens. I tested it on:

vintagepc commented 4 years ago

iiiiiiiinteresting.I do know the queue is (somewhat) easily corruptbile - pronterface's temperature requests (M107) can get entered as M1s and make the printer pause if they come in just at the right time during MBL or another "busy" state. This particular issue is also very sensitive to what line it is on, if you shorten the gcode slightly or extend it so M84 is in a different position in the SD block, it comes and goes away

I'll definitely dig in, this is one of the last major "breaking" issues I want fixed before we can call it 1.0

vintagepc commented 4 years ago

OK, I got somewhere further. Seems that the "delay" is not a pause, rather, the printer is busy chewing through the block of comments at the end of the gcode file while trying to refill the command queue - pre-empting it finding the already-enqueued M84 until it's too late.

Now to find out why this is taking so much longer in the sim vs the real thing...

vintagepc commented 4 years ago

Leaving a breadcrumb... seems to be a large chunk of time between the final data byte from the file and the CRC being sent. That could be adding up... image Edit: OK, that's not the simulated card, the CRC is going out on the very next byte in.

vintagepc commented 4 years ago

I think we have a winner... avr_cycle_timer_register_usec(avr, 100, avr_spi_raise, p); // should be speed dependent That's artificially throttling the SPI bus output to something slower than the board is used to - simavr ignores SPCR and SPSR entirely.

vintagepc commented 4 years ago

Closing and creating a separate issue for the SPI sim.

vintagepc commented 4 years ago

I did look at your file. Looks like something is causing an overflow and corrupting memory - note the output at the very end:

+G01 X105.5379954438 Y40.1633950622 F2540.8002046466..
-G01.
+G01 X96.3072354438 Y47.0786515787 F2540.8002046466..
-G01.
+G01 X87.0764754438 Y53.9939080952 F2540.8002046466..
-G01.
-G01.
-G01.
-G01.
-G01.
Done printing file..
echo:0 hours 1 minutes..
Done printing file..
echo:0 hours 1 minutes..
Done printing file..
echo:0 hours 1 minutes..
Done printing file..
echo:0 hours 1 minutes..
Done printing file..
echo:0 hours 1 minutes..
Done printing file..
echo:0 hours 1 minutes..
Done printing file..
echo:0 hours 1 minutes..
Done printing file..
echo:0 hours 1 minutes..
Done printing file..
echo:0 hours 1 minutes..
Done printing file..
echo:0 hours 1 minutes..
Done printing file..
echo:0 hours 1 minutes..
Done printing file..
echo:0 hours 1 minutes..
Done printing file..
echo:0 hours 1 minutes..
Done printing file..
echo:0 hours 1 minutes..
Done printing file..
echo:0 hours 1 minutes..
Done printing file..
echo:0 hours 1 minutes..
Done printing file..
echo:0 hours 1 minutes..
Done printing file..
echo:0 hours 1 minutes..
Done printing file..
echo:0 hours 1 minutes..
Done printing file..
echo:0 hours 1 minutes..
Done printing file..
echo:0 hours 1 minutes..
Done printing file..
echo:0 hours 1 minutes.....=��..
Done printing file..
echo:0 hours 1 miqvtes..
MCUSR: 08
RESET
vintagepc commented 4 years ago

It is dequeueing every line in the file, so something weird is happening at the end when it runs past the last line.

leptun commented 4 years ago

I’ll look into this file this week. I’m glad that the SD card implementation works correctly now. The only thing I might look into (not really decided at this point) is fixing the impossible advantage I saw in the real hardware. But that’s for later.

vintagepc commented 4 years ago

Yes, it's relatively straightforward to toss a couple of "hang on, busy" replies before the card is ready to supply data. (Research suggests the read latency for a typical SD card can be ~1ms. (I researched this when I was exploring the same, i.e. whether our card was "too good" and preempting the regular processing because it always had data ready)