Marlin Communication Crash RC5 + MAX31855

[Grogyan]

RAMPS 1.4 Full Graphic Display MAX31855

Now that my printer is up and going, I have tried several ties to do a rather longish print, which should take about 1 hour. With every try the print abruptly stops, randomly, then giving the error below;

Error: MAXTEMP triggered, system stopped! Heater_ID: 0

I don't know if any changes from RC5 to RC6 would affect this, but does seem like the temperature monitoring gets prematurely interrupted, so I don't know if it is related to the ISR.

[snowzach]

I had a similar problem at one point recently with the bed maxtemp. I think there was a buffer overrun with the temp monitoring code that was just fixed a couple days ago. If you haven't pulled in the last 2-3 days I would try that first.

[snowzach]

Although I say that now and literally moments later my machine did something similar. Both my hot-ends shut off it looks like... I have use this same GCODE before. (Printing Benchy to calibrate my printer)

Recv: ok T:200.0 /225.0 B:100.1 /100.0 T0:205.0 /225.0 T1:200.0 /225.0 B@:0 @:127 @0:127 @1:127
Recv: ok T:197.5 /225.0 B:99.9 /100.0 T0:201.7 /225.0 T1:197.5 /225.0 B@:0 @:127 @0:127 @1:127
Recv: ok T:194.7 /225.0 B:99.8 /100.0 T0:198.5 /225.0 T1:194.7 /225.0 B@:127 @:127 @0:127 @1:127
Recv: Error:Thermal Runaway, system stopped! Heater_ID: 1
Changing monitoring state from 'Printing' to 'Error: Thermal Runaway, system stopped! Heater_ID: 1
'
Recv: Error:Printer halted. kill() called!

[Blue-Marlin]

@snowzach You definitely have a completely different problem than @Grogyan.

From the 3 lines of M105 data you prove, i can see: You are printing with T1. In the first line T1 is 25° too cold and further dropping (~30°) while the heater is heating at max. power. About the same is true for T0. Here we begin 20° too low and end ~26° too low - while heating full. The bed seems to work normally. Bering too far from the target temperature for too long a time is the designed reason for the 'Thermal Runaway Error'. So that kill worked perfectly.

So why did your nozzle heaters not have enough power to keep the temperature? My Crystal Ball sees two likely reasons:

• You are printing the 'Benchy's' chimney. The layer time drops below the threshold -> the part fan starts to work 100% -> too much of the airflow is directed to the nozzles -> the heaters can't keep up.
• If you have a RAMPS board, control the temperature of the smaller polyfuse. If very warm (and/or making noise) a bit more airflow in that area may help. This fuse is for 5A. 2 x 40W for the heaters at 12V -> ~ 6.66A + Fans + Steppers may be a bit too much without cooling.

If this is not helping with your problem - please open your own issue. (Please no further answers here)

[snowzach]

Maybe it was the polyfuse... I just reprinted the same GCODE and it worked. It was only about 10-20 layers in when it died. if I run into it again, I'll open a different issue.

[Grogyan]

My problem is quite different, the temperature doesn't drop at all, until the error occurs, then the automatic shutdown then occurs preventing overheating.

I was going to have a quick go at trying to add a check for the SD card SS pin, before the MAX6675/MAX31855 code executes.

On Tue, Apr 19, 2016 at 2:40 AM, snowzach notifications@github.com wrote:

Maybe it was the polyfuse... I just reprinted the same GCODE and it worked. It was only about 10-20 layers in when it died. if I run into it again, I'll open a different issue.

— You are receiving this because you were mentioned. Reply to this email directly or view it on GitHub https://github.com/MarlinFirmware/Marlin/issues/3548#issuecomment-211407803

[Grogyan]

Possible to include a state check on SDSS pulled highbefore a measurement is run?

Not sure how to do this, vice versa for SD card comms when MAX6675_SS is pulled high

[thinkyhead]

Perhaps it will help to add more logging in code sections where max_temp_error is being called.

  #if ENABLED(HEATER_0_USES_MAX6675)
    float ct = current_temperature[0];
    if (ct > min(HEATER_0_MAXTEMP, 1023)) {
      SERIAL_ECHOPAIR("current_temperature over HEATER_0_MAXTEMP: ", ct);
      SERIAL_EOL;
      max_temp_error(0);
    }
    if (ct < max(HEATER_0_MINTEMP, 0.01)) {
      min_temp_error(0);
    }
  #endif

[Grogyan]

@thinkyhead thanks for the code to debug this. I am also currently trying out increasing MAX6675_HEAT_INTERVAL to 500us

Furthermore, I am also toying with the idea of moving away from the hardware SPI port, and just setup a serialIn() bit bang read.

[zylantha]

I am getting the same issue as the OP.

Printing over USB from Simplify3D, midway through the print I will repeatedly get a serial disconnect and it will stop printing.

In addition, I've found that when an SD card is inserted, I can reliably reproduce this error during the OctoPrint startup sequence. It seems to occur when OctoPrint requests an SD card file list (note this printer is cold and no heatup commands have been issued):

2016-04-19 14:05:27,368 - SERIAL - DEBUG - Send: M20
2016-04-19 14:05:27,374 - SERIAL - DEBUG - Recv: Begin file list
2016-04-19 14:05:27,846 - SERIAL - DEBUG - Recv: KOSSEL~1.GCO
2016-04-19 14:05:27,849 - SERIAL - DEBUG - Recv: EXTENS~1.GCO
2016-04-19 14:05:30,320 - SERIAL - DEBUG - Recv: Error:MAXTEMP triggered, system stopped! Heater_ID: 0
2016-04-19 14:05:30,324 - SERIAL - DEBUG - Changing monitoring state from 'Operational' to 'Error: MAXTEMP triggered, system stopped! Heater_ID: 0

[zylantha]

I should add that without the SD card inserted, OctoPrint will connect to the printer fine (however I haven't attempted to print anything yet, as it seems almost certain it will fail).

Also - printing direct from SD card seems perfectly fine. It's only when printing over USB that the printer will die with this error in the middle of the print.

[Blue-Marlin]

@zylantha And your printer really has a MAX31855 where the temperature measurement is completely different from a thermistor?

[Grogyan]

@zylantha From your error, I can see that it does look like an interrupt issue, where it was loading the list of files on the SD card before the crash occurred. I too was getting more crashes when the SD card was inserted. Can you please confirm?

• You are using a MAX31855
• Printing from USB
• Was there a crash when printing from the SD card?
• Was there periodic stopping while it was printing?

Because these are the areas I'm concerned with. The first is the interrupt triggering prematurely. The other is maybe there is a problem with the print buffer.

[zylantha]

@Blue-Marlin Sorry - same symptom, different configuration. My printer has ordinary 100K thermistors.

@Grogyan -

You are using a MAX31855

No - standard thermistors.

Printing from USB

The alert seems to trigger during printing over USB even when there is no thermal runaway or reason for it to occur (and no SD card inserted).

Was there a crash when printing from the SD card

No crashes when printing from SD card.

Was there periodic stopping while it was printing?

Now that you ask - I think that there has been. The print quality has been terrible since I have been printing from SD instead of over USB - there are lots of 'loops' left over, some of these stuck to the edges of the print, others get knocked off and left on the print bed. I was not getting these with RC3.

I had initially blamed the issues on setup and a different filament, however now that I think about it, they are probably caused by pauses in printing without a retract - with the filament 'oozing' out while the print head is stopped on the edge of the print (this is a long distance bowden on a Kossel XL so there is a lot of pressure left in the tube if there is no retraction to stop it).

[thinkyhead]

If the issue isn't specific to thermocouples, then I guess the logging code I suggested won't catch anything useful. In any case, this topic is starting to sound more interesting…

[Grogyan]

Unfortuntely I ran out of time to do thorough testing last night. Waiting for my work day to end so I can zoom home and do some testing.

If it is a USB serial comms issue, then that is outside the scope of testing as it depends on the USB to serial device used. I'm currently using a Funduino, which uses the Atmel 16U2 for USB to serial comms.

Firstly I gotta check to see if increasing the MAX6675_HEAT_INTERVAL makes any difference.

[zylantha]

Can we at least agree that it is a bug that needs further investigation?

I will try to update to the latest rcbugfix tonight, and find a test print that I can use to confirm the pauses during printing while I am watching it.

[thinkyhead]

I'm looking forward to your results, and any insights that you are able to glean.

[Grogyan]

@ThinkyHead Is there a way to get a dump what is in the buffer when the crash occurs?

[thinkyhead]

Is there a way to get a dump what is in the buffer when the crash occurs?

@Grogyan No, we are pretty much limited to adding log output to try to catch things in action.

[Grogyan]

Been struggling with testing this evening due Bed Levelling issues. I managed to get a little more detail about the error

Recv: current_temperature over HEATER_0_MAXTEMP: 1000.00
Recv: Error:MAXTEMP triggered, system stopped! Heater_ID: 0
Changing monitoring state from 'Operational' to 'Error: MAXTEMP triggered, system stopped! Heater_ID: 0
Recv: Error:Printer halted. kill() called!`

Only got it once, while printing from SD card

From there I added read for the SPI Data and Control registers, to glean more information, but couldn't continue due to bed not levelling properly, even when migrating all the settings/logs to RCBugFix that I pulled down, to hopefully fix the bed.

I digress, long story short I didn't have enough time this evening, again, to test this further. But at least we're in the right area for the MAX31855.

[zylantha]

The error I get with an ordinary thermistor is identical. I wouldn't automatically assume it is caused by thermocouple code - as @grogyan suggested it looks like it could be an interrupt issue.

[thinkyhead]

If it's caused by the ADC conversion code, we should try using some older Marlin code for that part of ISR(TIMER0_COMPB_vect) and compare to see what has changed. The timing between prepare (ADC) and measure is still only one interrupt cycle. Timing between updates of the same thermistor is 12 interrupt cycles.

[Grogyan]

@ThinkyHead I had a quick chat on hangouts with zylantha. I think that it is maybe a problem with the SPI, not the temperature monitoring itself. We have a few things to try out, and report back.

[Grogyan]

Sorry I haven't had time to test out RC6 to see if the problem still exists

[jbrazio]

Looking forward for the outcome.

[Grogyan]

Tested with RC 6 with Logging of; Current Temperature SPCR state SPDR state

http://pastebin.com/eF7aTsXw

[thinkyhead]

Looks like the RAW temperature reported 4000 (which I believe is the max raw temperature it will report) and this was converted (divided by 4) to give "1000" by analog2temp.

[Grogyan]

I have put in a counter to see if it is just a 1 off or successive failure. Limit to 3 counts.

#if ENABLED(HEATER_0_USES_MAX6675)
    float ct = current_temperature[0];
    char count = 0;
    if (ct > min(HEATER_0_MAXTEMP, 1023)) 
    {
      count = count + 1;
      SERIAL_ECHOPAIR("current_temperature over HEATER_0_MAXTEMP: ", ct);
      SERIAL_EOL;
      SERIAL_ECHOPAIR("current SPCR: ", SPCR);
      SERIAL_EOL;
      SERIAL_ECHOPAIR("current SPDR: ", SPDR);
      SERIAL_EOL;
      SERIAL_ECHOPAIR("counter: ", count);
      SERIAL_EOL;
      if (count == 3)
      {
      max_temp_error(0);
      }
    }
    if (ct < max(HEATER_0_MINTEMP, 0.01)) {
      min_temp_error(0);
    }
  #endif

I still don't know yet what is causing this, whether it be the SD interrupt being called during a temp read, or the MAX31855 hasn't been bit shifted correctly (unlikely). I'll try again later this evening

[thinkyhead]

@Grogyan Three backticks for multi-line code. I've done the correction for you above.

Adding a counter to deal with "spurious" errors seems like a good idea to me.

[Grogyan]

Made a small mistake with the counting, but anyways it worked out just fine. I just gotta watch it do the entire print now. For safety. Pic

Have uploaded the log of those glitches.

current_temperature over HEATER_0_MAXTEMP: 1000.00
current SPCR: 81
current SPDR: 146
current_temperature over HEATER_0_MAXTEMP: 1000.00
current SPCR: 80
current SPDR: 192
current_temperature over HEATER_0_MAXTEMP: 1000.00
current SPCR: 81
current SPDR: 162
current_temperature over HEATER_0_MAXTEMP: 1000.00
current SPCR: 81
current SPDR: 82
current_temperature over HEATER_0_MAXTEMP: 1000.00
current SPCR: 81
current SPDR: 82
current_temperature over HEATER_0_MAXTEMP: 1000.00
current SPCR: 81
current SPDR: 34
current_temperature over HEATER_0_MAXTEMP: 1000.00
current SPCR: 81
current SPDR: 34
current_temperature over HEATER_0_MAXTEMP: 1000.00
current SPCR: 81
current SPDR: 18
current_temperature over HEATER_0_MAXTEMP: 1000.00
current SPCR: 80
current SPDR: 192

More detailed serial log http://pastebin.com/1gRmUNJh

[thinkyhead]

We'll have to try to get feedback from someone who knows more about SPI than I do. Have you posted a topic on the RepRap forums about this also? You may also find help in the RepRap / RepStrap Facebook groups.

[Grogyan]

I have not been back on the RepRap forums for many years. However, from what I remember, not many people know enough about details about certain things.

I am wondering whether it is best to go back to Bit Bang, and move the the pins to D0, D1 and D58 on AUX1 for the RAMPS 1.4. How difficult would it be to change the MAX6675/MAX31855 to those pins?

[thinkyhead]

Truly, you shouldn't need to do anything special. The thermocouple should "just work." If there's a real software error here, we should do our best to find it. So far the thermocouple code looks harmless to me, but I don't know how it interacts with the SD code.

The logging that we have done so far comes a little late in the process. You might be able to glean more about the condition by "logging" the read_max6675 function. (Store some data to a buffer in that function, but log it in the main loop().)

The source of the error temperature (4000) is probably this:

    if (max6675_temp & MAX6675_ERROR_MASK)
      max6675_temp = 4000; // thermocouple open
    else
      max6675_temp >>= MAX6675_DISCARD_BITS;

It may be that some bits are out-of-sequence, indicating a timing or communication issue. It would be best to narrow it down.

[Grogyan]

Perhaps it is too late for 1.10, i'm still hoping for there to be a patch.

A couple of this I want to try out is get debugging of max6675_tmp and to move the MAX6675 SS moved to the end of the function, and similarly, add to the start of the function forcing SD SS. I have a few experiments to try and so very little time at the end of every day

[thinkyhead]

Another report I've gotten says that the problem only manifests when the E axis is moving. So here's an idea. Let's try turning off interrupts while reading the sensor in the read_max6675 function:

    CRITICAL_SECTION_START;

    WRITE(MAX6675_SS, 0); // enable TT_MAX6675

    // ensure 100ns delay - a bit extra is fine
    asm("nop");//50ns on 20Mhz, 62.5ns on 16Mhz
    asm("nop");//50ns on 20Mhz, 62.5ns on 16Mhz

    // Read a big-endian temperature value
    max6675_temp = 0;
    for (uint8_t i = sizeof(max6675_temp); i--;) {
      SPDR = 0;
      for (;!TEST(SPSR, SPIF););
      max6675_temp |= SPDR;
      if (i > 0) max6675_temp <<= 8; // shift left if not the last byte
    }

    CRITICAL_SECTION_END;

[Grogyan]

Just to follow up with what I have been doing.

Whilst probing the BLTouch, to see how much voltage drain there was, accidentally damaged my Arduino Mega a few days ago. and only just got it back up and running.

While there does seem to be excessive power drain, which i'll make a separate modded supply for the BLTouch, this shouldn't have affected the interrupt. Likewise with changing the Arduino Mega, should show the same glitch.

Have just been going through possible hardware causes.

I also have been through the code line by line, trying to make sense of the ISR, have a small concern regarding using the ISR for temperature monitoring as well as providing the PWM for the heaters and Fan. Where it could be that running 8bit processors to their absolute limits might cause glitching.

I can understand trying to use as few timers as possible for processor boards which have limited timers available, and use that as the basis for other processors which may have more, like the ATMEGA 2560 which has 4 16bit timers and 2 8bit timer, leaving timers on the ATMEGA 2560 and others, underutilized (I may be wrong on this).

Am still going through all my crazy ideas of why this is occurring.

[Grogyan]

Over the weekend; Have replaced my power supply to an ATX, as the power supply for the bed originally seemed to be buzzing too much (The SMPS) for my liking. Also ran Auto PID again, and again, in case that was the cause. Reaffixed my thermocouple. Have now eliminated all hardware issues.

Now am back to the SPCR reading of 0x81 In binary 10000001

Using Arduino SPI as a basis, this would suggest that the SPI Master control bit has been turned off. I gotta double check this when I get home from work tonight

[thinkyhead]

Some of these missed bits (could there just be missed or misplaced bits?) could be connected to the stepper ISR, which might lately be taking longer than previously. But if that was the case, you should see worse results with RCBugFix than with RC6. Anyway, if you added the CRITICAL_SECTION directives that I described above, and that didn't help, then perhaps it is indeed the SPI Master control bit.

[Grogyan]

My mistake the output of the SPCR register is ‭01010001‬, which is correct for both normal and over temp readings, all bits that need to be set are correct. The CRITICAL_SECTION is added, and made no difference Added debug to see if the Sd card was triggered as the interrupt. Nope.

I'm not sure how the temperature ISR could get corrupted.

[Grogyan]

Had my 24V 10A supply arrive today, so have rewired my RAMPS and printer to use that as the supply for the bed

Added code to see if perhaps there is a signal failure on the MAX31855 late last night, and tested after work today.

WRITE(MAX6675_SS, 1); // disable TT_MAX6675

      //check thermocouple status
      if (max6675_temp & 1){
      SERIAL_ECHOPAIR("Error Mask: ", max6675_temp);
      SERIAL_EOL;
      max6675_temp = 4000; // thermocouple open
      SERIAL_ECHOPAIR("Thermocouple Open ", max6675_temp);
      SERIAL_EOL;
      }

      else if (max6675_temp & 2){
      SERIAL_ECHOPAIR("Error Mask: ", max6675_temp);
      SERIAL_EOL;
      max6675_temp = 4000; // thermocouple open
      SERIAL_ECHOPAIR("Short to Ground: ", max6675_temp);
      SERIAL_EOL;
      }

      else if (max6675_temp & 4){
      SERIAL_ECHOPAIR("Error Mask: ", max6675_temp);
      SERIAL_EOL;
      max6675_temp = 4000; // thermocouple open
      SERIAL_ECHOPAIR("Short to VCC ", max6675_temp);
      SERIAL_EOL;
      }

      else if (max6675_temp & MAX6675_ERROR_MASK){
      SERIAL_ECHOPAIR("Error Mask: ", max6675_temp);
      SERIAL_EOL;
      max6675_temp = 4000; // thermocouple open
      SERIAL_ECHOPAIR("Something is terribly wrong: ", max6675_temp);
      SERIAL_EOL;
      }
      else
      max6675_temp >>= MAX6675_DISCARD_BITS;

22:07:42.472 : echo:Thermal Thermal Runaway Running. Heater ID: 0 ;  State:1 ;  Timer:223715 ;  Temperature:188.00 ;  Target Temp:210.00
22:07:42.660 : Error Mask: 197466242
22:07:42.660 : Short to Ground: 4000
22:07:42.660 : current_temperature over HEATER_0_MAXTEMP: 1000.00
22:07:42.676 : current SPCR: 81
22:07:42.676 : current SPDR: 130 ;  Target Temp:4947
22:07:42.676 : counter: 1
22:07:42.676 : echo:Thermal Thermal Runaway Running. Heater ID: 0 ;  State:1 ;  Timer:223715 ;  Temperature:1000.00 ;  Target Temp:210.00
22:07:42.863 : current_temperature over HEATER_0_MAXTEMP: 1000.00
22:07:42.863 : current SPCR: 81
22:07:42.863 : current SPDR: 130 ;  Target Temp:4947
22:07:42.863 : counter: 2

18:49:41.025 : Error Mask: 217389378
18:49:41.025 : Short to Ground: 4000
18:49:41.025 : current_temperature over HEATER_0_MAXTEMP: 1000.00
18:49:41.025 : current SPCR: 81
18:49:41.025 : current SPDR: 66 ;  Target Temp:4947
18:49:41.025 : counter: 5
18:49:41.041 : echo:Thermal Thermal Runaway Running. Heater ID: 0 ;  State:2 ;  Timer:284467 ;  Temperature:1000.00 ;  Target Temp:210.00
18:49:41.229 : current_temperature over HEATER_0_MAXTEMP: 1000.00
18:49:41.229 : current SPCR: 81
18:49:41.229 : current SPDR: 66 ;  Target Temp:4947
18:49:41.229 : counter: 6
18:49:41.229 : echo:Thermal Thermal Runaway Running. Heater ID: 0 ;  State:2 ;  Timer:284671 ;  Temperature:1000.00 ;  Target Temp:210.00
18:49:41.416 : Error Mask: 217389378
18:49:41.416 : Short to Ground: 4000
18:49:41.416 : current_temperature over HEATER_0_MAXTEMP: 1000.00
18:49:41.416 : current SPCR: 81
18:49:41.416 : current SPDR: 66 ;  Target Temp:4947
18:49:41.416 : counter: 7
18:49:41.432 : echo:Thermal Thermal Runaway Running. Heater ID: 0 ;  State:2 ;  Timer:284866 ;  Temperature:1000.00 ;  Target Temp:210.00
18:49:41.619 : current_temperature over HEATER_0_MAXTEMP: 1000.00
18:49:41.619 : current SPCR: 81
18:49:41.619 : current SPDR: 66 ;  Target Temp:4947
18:49:41.619 : counter: 8

All instances state that the thermocouple went short circuit to ground. The MAX31855 and thermocouple wires are well secured. So what I am seeing is perhaps bit shift problem, where an incorrect number of bits are being shifted.

[Grogyan]

I am out of time again tonight :( One very quick test with both _BV(SPR1) | _BV(SPR0) bits being set, ie a serial speed of 250KHz. A quick try of a 5 minute print resulted in no lost bits.

I will have to try a longer print probably over the weekend.

[thinkyhead]

So this is the change you are finding works?

-    SPCR = _BV(MSTR) | _BV(SPE) | _BV(SPR0);
+    SPCR = _BV(MSTR) | _BV(SPE) | _BV(SPR0) | _BV(SPR1);

According to my reading, this should make the SPI clock run 8 times slower (clock÷128 versus clock÷16). And it also says the clock speed should be set according to the slowest device you have on the SPI bus, so going slower seems to be the right idea.

[Grogyan]

@thinkyhead yes, but I will need to do more than a 5 minute print to see if the reduced baud is a permanent fix

[thinkyhead]

Did you also find that using just _BV(SPR1) by itself (clock÷64) is still too fast?

[Grogyan]

I did not have time last night to see if _BV(SPR1) bit alone (500,000 baud) would work.

[Grogyan]

I did a 2 hour print today with _BV(SPR0) and _BV(SPR1) bits set ie 250KHz worked flawlessly

Dialed it up enabling bit _BV(SPR1) and still no issues seen with this a much longer print starting an hour ago.

No issues seen either with SD card printing, as all the tests I have done thus far have been with an SD card.

[jbrazio]

@thinkyhead @Grogyan do we need to submit a patch do close this issue, or can it just be closed ?

[Grogyan]

@jbrazio A patch would need to created. Though I don't know if you guys want to have the debugging code for the thermocouple faults, for which there are 4 bits for the MAX31855, and only 2 for the MAX6675.

[thinkyhead]

do we need to submit a patch do close this issue…?

I think so. To sum up, the fix is to run the SPI bus slower.

But I'm not clear on whether this fix applies universally, or only to certain setups. Currently the SPI is being set with a divisor of 16. Evidently a divisor of 64 works for @Grogyan. But apparently so does a divisor of 128. So it's unclear whether it would be better to run 4 times slower or 8 times slower. Perhaps this should be made configurable, because on some machines the divisor of 16 might be okay, while others need 64, and still others need 128.

debugging code for the thermocouple faults

It could be good to have. Of course, if the issue is SPI speed, and the bits might be out of order, then the error bits might not always be meaningful.

[Grogyan]

@thinkyhead looking at he datasheet for the MAX31855, 1MHz ie 1/16th freq of the osc, is the upper most limit for transitions. Whereas 250KHz, 1/64th freq of the osc, is well within the transition time limits of the device. I'm referring to the rise/fall/transition time forthe CS pin