RAMPS: M400 error using Marlin firmware

[pchiang5]

Hi,

An error occurred when using the Marlin firmware:

2024-06-24T10:15:39.629991 tid25672 [IFO,Core] Will initialize device RAMPSHub
2024-06-24T10:15:39.630003 tid25672 [WRN,Core:dev:COM6] Setting of pre-init property (Verbose) not permitted on initialized device (this will be an error in a future version of MMCore; for now we continue with the operation anyway, even though it might not be safe)
2024-06-24T10:15:39.630006 tid25672 [dbg,Core:dev:COM6] Will set property "Verbose" to "1"
2024-06-24T10:15:39.630011 tid25672 [dbg,Core:dev:COM6] Did set property "Verbose" to "1"
2024-06-24T10:15:41.631017 tid25672 [dbg,dev:COM6] SetCommand -> M115\r
2024-06-24T10:15:41.631059 tid25672 [WRN,Core:dev:COM6] Setting of pre-init property (AnswerTimeout) not permitted on initialized device (this will be an error in a future version of MMCore; for now we continue with the operation anyway, even though it might not be safe)
2024-06-24T10:15:41.631063 tid25672 [dbg,Core:dev:COM6] Will set property "AnswerTimeout" to "300.00"
2024-06-24T10:15:41.631068 tid25672 [dbg,Core:dev:COM6] Did set property "AnswerTimeout" to "300.00"
2024-06-24T10:15:41.677024 tid25672 [dbg,dev:COM6] GetAnswer <- FIRMWARE_NAME:Marlin 2.1.2.4 (Jun 24 2024 10:11:54) SOURCE_CODE_URL:github.com/MarlinFirmware/Marlin PROTOCOL_VERSION:1.0 MACHINE_TYPE:3D Printer EXTRUDER_COUNT:1 UUID:cede2a2f-41a2-4748-9b12-c55c62f367ff\n
2024-06-24T10:15:41.677056 tid25672 [WRN,Core:dev:COM6] Setting of pre-init property (AnswerTimeout) not permitted on initialized device (this will be an error in a future version of MMCore; for now we continue with the operation anyway, even though it might not be safe)
2024-06-24T10:15:41.677060 tid25672 [dbg,Core:dev:COM6] Will set property "AnswerTimeout" to "500.0000"
2024-06-24T10:15:41.677067 tid25672 [dbg,Core:dev:COM6] Did set property "AnswerTimeout" to "500.0000"
2024-06-24T10:15:41.677085 tid25672 [WRN,Core:dev:COM6] Setting of pre-init property (AnswerTimeout) not permitted on initialized device (this will be an error in a future version of MMCore; for now we continue with the operation anyway, even though it might not be safe)
2024-06-24T10:15:41.677088 tid25672 [dbg,Core:dev:COM6] Will set property "AnswerTimeout" to "300.00"
2024-06-24T10:15:41.677091 tid25672 [dbg,Core:dev:COM6] Did set property "AnswerTimeout" to "300.00"
2024-06-24T10:15:41.677099 tid25672 [dbg,dev:COM6] GetAnswer <- Cap:SERIAL_XON_XOFF:0\n
2024-06-24T10:15:41.677103 tid25672 [WRN,Core:dev:COM6] Setting of pre-init property (AnswerTimeout) not permitted on initialized device (this will be an error in a future version of MMCore; for now we continue with the operation anyway, even though it might not be safe)
2024-06-24T10:15:41.677105 tid25672 [dbg,Core:dev:COM6] Will set property "AnswerTimeout" to "500.0000"
2024-06-24T10:15:41.677108 tid25672 [dbg,Core:dev:COM6] Did set property "AnswerTimeout" to "500.0000"
2024-06-24T10:15:41.677137 tid25672 [dbg,dev:COM6] SetCommand -> M203 X240.00 Y240.00 Z240.00\r
2024-06-24T10:15:41.677147 tid25672 [WRN,Core:dev:COM6] Setting of pre-init property (AnswerTimeout) not permitted on initialized device (this will be an error in a future version of MMCore; for now we continue with the operation anyway, even though it might not be safe)
2024-06-24T10:15:41.677149 tid25672 [dbg,Core:dev:COM6] Will set property "AnswerTimeout" to "300.00"
2024-06-24T10:15:41.677152 tid25672 [dbg,Core:dev:COM6] Did set property "AnswerTimeout" to "300.00"
2024-06-24T10:15:41.736986 tid25672 [dbg,dev:COM6] GetAnswer <- p:EMERGENCY_PARSER:0\n
2024-06-24T10:15:41.737002 tid25672 [WRN,Core:dev:COM6] Setting of pre-init property (AnswerTimeout) not permitted on initialized device (this will be an error in a future version of MMCore; for now we continue with the operation anyway, even though it might not be safe)
2024-06-24T10:15:41.737005 tid25672 [dbg,Core:dev:COM6] Will set property "AnswerTimeout" to "500.0000"
2024-06-24T10:15:41.737010 tid25672 [dbg,Core:dev:COM6] Did set property "AnswerTimeout" to "500.0000"
2024-06-24T10:15:41.737042 tid25672 [dbg,dev:COM6] SetCommand -> M201 X10.00 Y10.00 Z10.00\r
2024-06-24T10:15:41.737055 tid25672 [WRN,Core:dev:COM6] Setting of pre-init property (AnswerTimeout) not permitted on initialized device (this will be an error in a future version of MMCore; for now we continue with the operation anyway, even though it might not be safe)
2024-06-24T10:15:41.737058 tid25672 [dbg,Core:dev:COM6] Will set property "AnswerTimeout" to "300.00"
2024-06-24T10:15:41.737060 tid25672 [dbg,Core:dev:COM6] Did set property "AnswerTimeout" to "300.00"
2024-06-24T10:15:41.768993 tid25672 [dbg,dev:COM6] GetAnswer <- ok\n
2024-06-24T10:15:41.769011 tid25672 [WRN,Core:dev:COM6] Setting of pre-init property (AnswerTimeout) not permitted on initialized device (this will be an error in a future version of MMCore; for now we continue with the operation anyway, even though it might not be safe)
2024-06-24T10:15:41.769016 tid25672 [dbg,Core:dev:COM6] Will set property "AnswerTimeout" to "500.0000"
2024-06-24T10:15:41.769021 tid25672 [dbg,Core:dev:COM6] Did set property "AnswerTimeout" to "500.0000"
2024-06-24T10:15:41.769025 tid25672 [IFO,dev:RAMPSHub] Expected OK
2024-06-24T10:15:41.769038 tid25672 [dbg,dev:COM6] SetCommand -> M400\r
2024-06-24T10:15:41.769055 tid25672 [WRN,Core:dev:COM6] Setting of pre-init property (AnswerTimeout) not permitted on initialized device (this will be an error in a future version of MMCore; for now we continue with the operation anyway, even though it might not be safe)
2024-06-24T10:15:41.769057 tid25672 [dbg,Core:dev:COM6] Will set property "AnswerTimeout" to "30000.00"
2024-06-24T10:15:41.769060 tid25672 [dbg,Core:dev:COM6] Did set property "AnswerTimeout" to "30000.00"
2024-06-24T10:15:41.799163 tid25672 [dbg,dev:COM6] GetAnswer <- ok\n
2024-06-24T10:15:41.799325 tid25672 [WRN,Core:dev:COM6] Setting of pre-init property (AnswerTimeout) not permitted on initialized device (this will be an error in a future version of MMCore; for now we continue with the operation anyway, even though it might not be safe)
2024-06-24T10:15:41.799345 tid25672 [dbg,Core:dev:COM6] Will set property "AnswerTimeout" to "500.0000"
2024-06-24T10:15:41.799357 tid25672 [dbg,Core:dev:COM6] Did set property "AnswerTimeout" to "500.0000"
2024-06-24T10:15:41.799390 tid25672 [IFO,dev:RAMPSHub] busy expected OK, didn't get it.
2024-06-24T10:15:41.799398 tid25672 [IFO,dev:RAMPSHub] ok
2024-06-24T10:15:41.799479 tid25672 [ERR,Core:dev:RAMPSHub] Error in device "RAMPSHub": (Error message unavailable) (110)
2024-06-24T10:15:41.799859 tid25672 [dbg,App] Notification from MMCore ignored
2024-06-24T10:15:41.800468 tid25672 [IFO,Core] Unloading all devices after failure to load system configuration
2024-06-24T10:15:41.800504 tid25672 [dbg,Core] Will unload all devices

When I input M400 in the Arduino sketch, it showed 'ok'. Also, the hardware loaded well with the ancient Sprinter firmware. Since the updated Marlin firmware is required for functionalities like encoder incorporation, is it possible to resolve this issue? Thanks.

2024-06-24T10:27:44.077440 tid20440 [IFO,Core] Will initialize device RAMPSHub
2024-06-24T10:27:44.077462 tid20440 [WRN,Core:dev:COM6] Setting of pre-init property (Verbose) not permitted on initialized device (this will be an error in a future version of MMCore; for now we continue with the operation anyway, even though it might not be safe)
2024-06-24T10:27:44.077465 tid20440 [dbg,Core:dev:COM6] Will set property "Verbose" to "1"
2024-06-24T10:27:44.077469 tid20440 [dbg,Core:dev:COM6] Did set property "Verbose" to "1"
2024-06-24T10:27:46.078337 tid20440 [dbg,dev:COM6] SetCommand -> M115\r
2024-06-24T10:27:46.078380 tid20440 [WRN,Core:dev:COM6] Setting of pre-init property (AnswerTimeout) not permitted on initialized device (this will be an error in a future version of MMCore; for now we continue with the operation anyway, even though it might not be safe)
2024-06-24T10:27:46.078384 tid20440 [dbg,Core:dev:COM6] Will set property "AnswerTimeout" to "300.00"
2024-06-24T10:27:46.078390 tid20440 [dbg,Core:dev:COM6] Did set property "AnswerTimeout" to "300.00"
2024-06-24T10:27:46.130443 tid20440 [dbg,dev:COM6] GetAnswer <- SD init fail\r\n
2024-06-24T10:27:46.130459 tid20440 [WRN,Core:dev:COM6] Setting of pre-init property (AnswerTimeout) not permitted on initialized device (this will be an error in a future version of MMCore; for now we continue with the operation anyway, even though it might not be safe)
2024-06-24T10:27:46.130462 tid20440 [dbg,Core:dev:COM6] Will set property "AnswerTimeout" to "500.0000"
2024-06-24T10:27:46.130467 tid20440 [dbg,Core:dev:COM6] Did set property "AnswerTimeout" to "500.0000"
2024-06-24T10:27:46.130481 tid20440 [WRN,Core:dev:COM6] Setting of pre-init property (AnswerTimeout) not permitted on initialized device (this will be an error in a future version of MMCore; for now we continue with the operation anyway, even though it might not be safe)
2024-06-24T10:27:46.130483 tid20440 [dbg,Core:dev:COM6] Will set property "AnswerTimeout" to "300.00"
2024-06-24T10:27:46.130486 tid20440 [dbg,Core:dev:COM6] Did set property "AnswerTimeout" to "300.00"
2024-06-24T10:27:46.130492 tid20440 [dbg,dev:COM6] GetAnswer <- Soft PWM Init\r\n
2024-06-24T10:27:46.130495 tid20440 [WRN,Core:dev:COM6] Setting of pre-init property (AnswerTimeout) not permitted on initialized device (this will be an error in a future version of MMCore; for now we continue with the operation anyway, even though it might not be safe)
2024-06-24T10:27:46.130497 tid20440 [dbg,Core:dev:COM6] Will set property "AnswerTimeout" to "500.0000"
2024-06-24T10:27:46.130500 tid20440 [dbg,Core:dev:COM6] Did set property "AnswerTimeout" to "500.0000"
2024-06-24T10:27:46.130526 tid20440 [dbg,dev:COM6] SetCommand -> M203 X240.00 Y240.00 Z240.00\r
2024-06-24T10:27:46.130537 tid20440 [WRN,Core:dev:COM6] Setting of pre-init property (AnswerTimeout) not permitted on initialized device (this will be an error in a future version of MMCore; for now we continue with the operation anyway, even though it might not be safe)
2024-06-24T10:27:46.130539 tid20440 [dbg,Core:dev:COM6] Will set property "AnswerTimeout" to "300.00"
2024-06-24T10:27:46.130541 tid20440 [dbg,Core:dev:COM6] Did set property "AnswerTimeout" to "300.00"
2024-06-24T10:27:46.160478 tid20440 [dbg,dev:COM6] GetAnswer <- ok\r\n
2024-06-24T10:27:46.160492 tid20440 [WRN,Core:dev:COM6] Setting of pre-init property (AnswerTimeout) not permitted on initialized device (this will be an error in a future version of MMCore; for now we continue with the operation anyway, even though it might not be safe)
2024-06-24T10:27:46.160495 tid20440 [dbg,Core:dev:COM6] Will set property "AnswerTimeout" to "500.0000"
2024-06-24T10:27:46.160500 tid20440 [dbg,Core:dev:COM6] Did set property "AnswerTimeout" to "500.0000"
2024-06-24T10:27:46.160519 tid20440 [dbg,dev:COM6] SetCommand -> M201 X10.00 Y10.00 Z10.00\r
2024-06-24T10:27:46.160532 tid20440 [WRN,Core:dev:COM6] Setting of pre-init property (AnswerTimeout) not permitted on initialized device (this will be an error in a future version of MMCore; for now we continue with the operation anyway, even though it might not be safe)
2024-06-24T10:27:46.160534 tid20440 [dbg,Core:dev:COM6] Will set property "AnswerTimeout" to "300.00"
2024-06-24T10:27:46.160536 tid20440 [dbg,Core:dev:COM6] Did set property "AnswerTimeout" to "300.00"
2024-06-24T10:27:46.192572 tid20440 [dbg,dev:COM6] GetAnswer <- ok\r\n
2024-06-24T10:27:46.192586 tid20440 [WRN,Core:dev:COM6] Setting of pre-init property (AnswerTimeout) not permitted on initialized device (this will be an error in a future version of MMCore; for now we continue with the operation anyway, even though it might not be safe)
2024-06-24T10:27:46.192591 tid20440 [dbg,Core:dev:COM6] Will set property "AnswerTimeout" to "500.0000"
2024-06-24T10:27:46.192595 tid20440 [dbg,Core:dev:COM6] Did set property "AnswerTimeout" to "500.0000"
2024-06-24T10:27:46.192608 tid20440 [dbg,dev:COM6] SetCommand -> M400\r
2024-06-24T10:27:46.192622 tid20440 [WRN,Core:dev:COM6] Setting of pre-init property (AnswerTimeout) not permitted on initialized device (this will be an error in a future version of MMCore; for now we continue with the operation anyway, even though it might not be safe)
2024-06-24T10:27:46.192625 tid20440 [dbg,Core:dev:COM6] Will set property "AnswerTimeout" to "30000.00"
2024-06-24T10:27:46.192628 tid20440 [dbg,Core:dev:COM6] Did set property "AnswerTimeout" to "30000.00"
2024-06-24T10:27:46.222614 tid20440 [dbg,dev:COM6] GetAnswer <- ok\r\n
2024-06-24T10:27:46.222628 tid20440 [WRN,Core:dev:COM6] Setting of pre-init property (AnswerTimeout) not permitted on initialized device (this will be an error in a future version of MMCore; for now we continue with the operation anyway, even though it might not be safe)
2024-06-24T10:27:46.222633 tid20440 [dbg,Core:dev:COM6] Will set property "AnswerTimeout" to "500.0000"
2024-06-24T10:27:46.222638 tid20440 [dbg,Core:dev:COM6] Did set property "AnswerTimeout" to "500.0000"
2024-06-24T10:27:46.222649 tid20440 [dbg,dev:COM6] SetCommand -> M114\r
2024-06-24T10:27:46.222663 tid20440 [WRN,Core:dev:COM6] Setting of pre-init property (AnswerTimeout) not permitted on initialized device (this will be an error in a future version of MMCore; for now we continue with the operation anyway, even though it might not be safe)
2024-06-24T10:27:46.222665 tid20440 [dbg,Core:dev:COM6] Will set property "AnswerTimeout" to "300.00"
2024-06-24T10:27:46.222668 tid20440 [dbg,Core:dev:COM6] Did set property "AnswerTimeout" to "300.00"
2024-06-24T10:27:46.254689 tid20440 [dbg,dev:COM6] GetAnswer <- X:0.00Y:0.00Z:0E:0.00\r\n
2024-06-24T10:27:46.254703 tid20440 [WRN,Core:dev:COM6] Setting of pre-init property (AnswerTimeout) not permitted on initialized device (this will be an error in a future version of MMCore; for now we continue with the operation anyway, even though it might not be safe)
2024-06-24T10:27:46.254706 tid20440 [dbg,Core:dev:COM6] Will set property "AnswerTimeout" to "500.0000"
2024-06-24T10:27:46.254710 tid20440 [dbg,Core:dev:COM6] Did set property "AnswerTimeout" to "500.0000"
2024-06-24T10:27:46.254740 tid20440 [WRN,Core:dev:COM6] Setting of pre-init property (AnswerTimeout) not permitted on initialized device (this will be an error in a future version of MMCore; for now we continue with the operation anyway, even though it might not be safe)
2024-06-24T10:27:46.254742 tid20440 [dbg,Core:dev:COM6] Will set property "AnswerTimeout" to "300.00"
2024-06-24T10:27:46.254745 tid20440 [dbg,Core:dev:COM6] Did set property "AnswerTimeout" to "300.00"
2024-06-24T10:27:46.254749 tid20440 [dbg,dev:COM6] GetAnswer <- ok\r\n
2024-06-24T10:27:46.254752 tid20440 [WRN,Core:dev:COM6] Setting of pre-init property (AnswerTimeout) not permitted on initialized device (this will be an error in a future version of MMCore; for now we continue with the operation anyway, even though it might not be safe)
2024-06-24T10:27:46.254755 tid20440 [dbg,Core:dev:COM6] Will set property "AnswerTimeout" to "500.0000"
2024-06-24T10:27:46.254757 tid20440 [dbg,Core:dev:COM6] Did set property "AnswerTimeout" to "500.0000"
2024-06-24T10:27:46.254776 tid20440 [IFO,Core] Did initialize device RAMPSHub

[marktsuchida]

What exactly are you doing to cause this error?

[pchiang5]

@marktsuchida

"Hardware Configuration Wizard" ==> "RAMPS" ==> "*RAMPSHub: RAMPS Hub" ==> "Add" ==> select COM port and set BaudRate ==> "OK"

[marktsuchida]

Thanks. It looks like this is the part of the log that is relevant (with WRN entries removed, since they are not the problem here):

2024-06-24T10:15:41.769038 tid25672 [dbg,dev:COM6] SetCommand -> M400\r
2024-06-24T10:15:41.769057 tid25672 [dbg,Core:dev:COM6] Will set property "AnswerTimeout" to "30000.00"
2024-06-24T10:15:41.769060 tid25672 [dbg,Core:dev:COM6] Did set property "AnswerTimeout" to "30000.00"
2024-06-24T10:15:41.799163 tid25672 [dbg,dev:COM6] GetAnswer <- ok\n
2024-06-24T10:15:41.799345 tid25672 [dbg,Core:dev:COM6] Will set property "AnswerTimeout" to "500.0000"
2024-06-24T10:15:41.799357 tid25672 [dbg,Core:dev:COM6] Did set property "AnswerTimeout" to "500.0000"
2024-06-24T10:15:41.799390 tid25672 [IFO,dev:RAMPSHub] busy expected OK, didn't get it.
2024-06-24T10:15:41.799398 tid25672 [IFO,dev:RAMPSHub] ok
2024-06-24T10:15:41.799479 tid25672 [ERR,Core:dev:RAMPSHub] Error in device "RAMPSHub": (Error message unavailable) (110)

All but the last line above are logged during a call to the Busy() function:

mmCoreAndDevices/DeviceAdapters/CNCMicroscope/RAMPSStage/RAMPS.cpp

Lines 204 to 229 in 7416f5d

	bool RAMPSHub::Busy() {
	if (!sent_busy_) {
	int ret = SendCommand("M400");
	if (ret != DEVICE_OK) {
	LogMessage("error requesting dwell.");
	return true;
	}
	sent_busy_ = true;
	}
	std::string answer;
	int ret = ReadResponse(answer, 30000);
	if (ret != DEVICE_OK) {
	status_ = "Busy";
	return true;
	}
	if (!answer.compare("ok")) {
	LogMessage(std::string("busy expected OK, didn't get it."));
	LogMessage(answer);
	return true;
	}
	sent_busy_ = false;
	status_ = "Idle";
	return false;
	}

The error code 110 is ERR_STAGE_MOVING, which is only returned from GetStatus():

mmCoreAndDevices/DeviceAdapters/CNCMicroscope/RAMPSStage/RAMPS.cpp

Lines 487 to 495 in 7416f5d

	int RAMPSHub::GetStatus()
	{
	std::string returnString;
	if(!portAvailable_)
	return ERR_NO_PORT_SET;
	if (Busy()) return ERR_STAGE_MOVING;

The error is a consequence of Busy() returning true, but the cause is not that the stage was actually moving but that Busy() checked for the answer ok and thought it didn't match. It prints the answer it got (at 41.799398), where it appears to be correct: ok.

The first thing that comes to mind is that there might be a whitespace, newline, or terminator mismatch. Indeed, in your working (Sprinter) example, the responses from the device are terminated with \r\n rather than just \n.

The strange thing here is that I could understand the behavior if it were the opposite: ReadResponse() expects \n as the terminator, so it should return ok from ok\n; ok\r from ok\r\n. Busy() checks this against ok, so I'd expect it to work with ok but not ok\r. But the observed result is the opposite.

I must be missing something, but this is as far as I've gotten so far. Will come back to this, but let me know if you have any ideas.