[0.80.3] server keeps sending commands during M190/M109
I know I started a thread about this months ago, but I can't find it now. When I switched to one of the Marlin RC branches, I lost the ability to print from the RS web interface. Whenever I start a print, the server keeps sending the gcode to the printer even though the printer is stopped with an M190 or M109 command waiting for the the bed or the hotend to heat up ending up with a mess and I have to stop the print immediately.
After that, I only printed from the SD card or from scripts I wrote that would upload gcode to the SD card and then I would also start the SD card print via a script as well.
I also didn't print a lot over the past few months and have been doing some printer upgrades, etc.
Well now I'm running the latest Marlin bugfix-1.1.x branch code and I decided to give RS a try again, but it did the same thing. Below I'm including a snippet from the beginning of the gcode I uploaded to RS and the log output from RS.
This is with the armel version of RS running on a pcduino2 board. Everything used to work fine when I was running the old 1.0 release of Marlin, but newer releases aren't working for me.
GCODE beginning:
Repetier Server Log Beginning
After that, I only printed from the SD card or from scripts I wrote that would upload gcode to the SD card and then I would also start the SD card print via a script as well.
I also didn't print a lot over the past few months and have been doing some printer upgrades, etc.
Well now I'm running the latest Marlin bugfix-1.1.x branch code and I decided to give RS a try again, but it did the same thing. Below I'm including a snippet from the beginning of the gcode I uploaded to RS and the log output from RS.
This is with the armel version of RS running on a pcduino2 board. Everything used to work fine when I was running the old 1.0 release of Marlin, but newer releases aren't working for me.
GCODE beginning:
; generated by Slic3r 1.2.9 on 2017-06-21 at 00:59:48
; external perimeters extrusion width = 0.40mm
; perimeters extrusion width = 0.56mm
; infill extrusion width = 0.56mm
; solid infill extrusion width = 0.56mm
; top infill extrusion width = 0.56mm
M107
M190 S125 ; set bed temperature
M104 S255 ; set temperature
;G1 Z10 F150 ; lift nozzle
M109 S255 ; wait for temperature to be reached
G21 ; set units to millimeters
G90 ; use absolute coordinates
M82 ; use absolute distances for extrusion
G92 E0
G10 ; retract
G92 E0
G1 Z0.320 F7800.000
G1 X83.943 Y80.601 F7800.000
G11 ; unretract
G92 E0
G1 X85.590 Y79.651 E0.14623 F1200.000
Repetier Server Log Beginning
< 1:22:46.915: N108 M532 X0 L0
> 1:22:46.964: ok
< 1:22:46.965: N109 M531 ripple-test
< 1:22:46.965: N110 M530 S1 L80
> 1:22:46.970: ok
< 1:22:47.001: N111 <U+FEFF>; generated by Slic3r 1.2.9 on 2017-06-21 at 00:59:48
< 1:22:47.001: N112 M107
< 1:22:47.002: N113 M190 S125 ; set bed temperature
< 1:22:47.002: N114 M104 S255 ; set temperature
> 1:22:47.003: ok
< 1:22:47.003: N115 M109 S255 ; wait for temperature to be reached
< 1:22:47.004: N116 G21 ; set units to millimeters
> 1:22:47.011: echo:Unknown command: " "
> 1:22:47.011: ok
> 1:22:47.011: ok
< 1:22:47.012: N117 G90 ; use absolute coordinates
< 1:22:47.012: N118 M82 ; use absolute distances for extrusion
> 1:22:47.015: T:28.50 /0.00 B:120.00 /125.00 @:0 B@:65 W:?
> 1:22:47.130: T:28.69 /0.00 B:120.00 /125.00 @:0 B@:127
> 1:22:48.014: T:28.69 /0.00 B:120.00 /125.00 @:0 B@:127 W:?
> 1:22:48.133: T:28.75 /0.00 B:120.02 /125.00 @:0 B@:127
> 1:22:49.014: T:28.69 /0.00 B:120.15 /125.00 @:0 B@:127 W:?
> 1:22:49.133: T:28.69 /0.00 B:120.15 /125.00 @:0 B@:127
> 1:22:50.013: T:28.62 /0.00 B:120.30 /125.00 @:0 B@:127 W:?
> 1:22:50.133: T:28.62 /0.00 B:120.30 /125.00 @:0 B@:127
> 1:22:51.013: Warning: Communication timeout - resetting communication buffer.
> 1:22:51.013: Connection status: Buffered:92, Manual Commands: 0, Job Commands: 5000
> 1:22:51.013: Buffer used:92 Enforced free byte:15 lines stored:6
< 1:22:51.014: N119 G92 E0
> 1:22:51.014: T:28.81 /0.00 B:120.56 /125.00 @:0 B@:127 W:?
< 1:22:51.015: N120 G10 ; retract
< 1:22:51.015: N121 G92 E0
< 1:22:51.016: N122 G1 Z0.320 F7800.000
> 1:22:51.132: T:28.81 /0.00 B:120.56 /125.00 @:0 B@:127
> 1:22:52.013: T:28.91 /0.00 B:120.75 /125.00 @:0 B@:127 W:?
> 1:22:52.131: T:28.91 /0.00 B:120.75 /125.00 @:0 B@:127
Comments
N111 <U+FEFF>; generated by Slic3r 1.2.9 on 2017-06-21 at 00:59:48
shows that the file contains a utf-8 BOM. But that helps analysing in this case. Last ok therefore belongs to M109. Since it works with old marlin my guess is that the ok from M109 now comes before it is finished. But that should be ok anyway. Will try upgrading my latest marlin and see if I can reproduce it.
N111 <U+FEFF>; generated by Slic3r 1.2.9 on 2017-06-21 at 00:59:48
Normally it looks like RS doesn't send comments to the printer, but in this case it's sending this line along which is probably generating the:
1:22:47.011: echo:Unknown command: " "
Maybe that's throwing everything off after that.
That was the log file unaltered taken from the server, but displayed in a terminal which is why that BOM showed up like that.
Also, which timeout are you referring to that's set to 4 seconds? I don't think I knowingly changed any setting regarding a communication timeout. When running gcode from my scripts, I do see the busy messages coming in from the printer.
Timeout is in printer configuration Connection->Communication Timeout
but a sI said if firmware has busy enabled (advanced config I guess) it should not happen. Maybe also the reason I did not see the problem.
What happens with this simple script:
M190 S55
M117 Hi
should show no timeout also it has to wait for M117.
I then started a print from the SD card via a script which allows me to capture the output from the printer. I'll put the beginning of the gcode file from the SD card and the messages that were being received from the printer.
I'll try the two commands you posted above to see what happens. BTW, my communication timeout in the RS UI shows 3 seconds. I'm not sure if that's the default or if I ever modified that value or not.
Beginning of logfile from a no BOM version of the gcode
Beginning gcode from SD card
Captured printer output when printing above SD card file
Also I see my simple test gets no timeout. So that leaves your gcode sample for testing.
Could you put your firmware config in a dropbox or so for testing in case I can not reproduce it.
So, in actuality, your 2 line gcode didn't show that printing was complete until the bed was heated up to temperature, but it didn't stop issuing the commands at the M190. The progress bar in the UI went to 100% almost immediately, but that didn't go away until the bed finished heating and RS got the rest of the "oks" from Marlin.
I'll zip up my config files and put them on google drive.
https://drive.google.com/open?id=0ByWKg0tckgv2YU9oak54aWhCNm8
In any case I have reported the missing busy problem to marlin and also added a reset timeout on "ok" received. To me it appeared after M190 was finished so it put out M109 from active commands and then saw it took more then timeout seconds. This would be catched by the reset on "ok".
Your log looks a bit different since it started during M109, but you are also not using the develop version which already disables temp. fetching with M105 what might make a difference. Will do some more tests with it enabled.
<response type="autoreportTempSupported">^Cap:AUTOREPORT_TEMP:(\d)</response>
So when marlin has cap feature on server will detect it and enable. You can comment out that line if you do not want this.
Here is a link to the full log of the entire print: https://drive.google.com/open?id=0ByWKg0tckgv2Z3NPQ2pSOGtqQ2M
After that you might try enabling ping-pong mode. Then it must wait for the ok before sending next line which might help until we know what is confusing here the server.
Here's a link to the complete log file for the entire print with advanced ok:
https://drive.google.com/open?id=0ByWKg0tckgv2V1Fmb3lNZ2V6YXM
This gcode will print one layer, but will not extrude anything.
https://drive.google.com/open?id=0ByWKg0tckgv2Ti1aZlFMVkh0SGM
ok are a line up or down from different timings, but as you see no timeout also my timeout is 4s. So last thing I can imagine is that your printer config in server has somehow an influence. Can you post that as well? You have on home screen of serve a export function for each printers config.
Ok and maybe the last thing that could be different: On which os and device are you running the server? If linux which of the 5 versions?
I'll get you the configs later today. Any idea why ping pong mode doesn't seem to be working? That probably would solve the issue for the most part.
One other questions is, what would happen if you preheat the bed. Then M190 is finished fast so next waitingcommand would be M109 - does it also time out then for you?
https://drive.google.com/open?id=0ByWKg0tckgv2ZnJNaXdqdWJ2aTQ
I ran a test where I pre-heated the bed to 80, then ran that same gcode. It did return immediately from the M190, and when it hit the M109 for the extruder, it still kept sending commands even without an ok, and had the communication timeout. After that, I changed my timeout to 4 secs to match yours, but still the same.
Do you think the problem is that because it doesn't seem to stop at the M190 command and because it won't get an OK until the bed is heated up, that's why it thinks the communication timed out?
Is it RS that's timing and triggering that communication timeout message, or is it a hardware timeout. Does RS send a command and if it hasn't received an OK or some response back in 4 seconds, it generates that error? Seems like temperature responses are coming back, however.
Could you try and run it from server on windows instead of pcduino? That is the only thing I could not test as I have none. I used a raspberry pi 3 with armhf version, so that I have at least the same compilation.
1) Each line of gcode is being sent and RS is waiting for the ok response (ping pong mode).
2) RS sends the M190 command, but for some reason doesn't recognize that as a blocking code, so it waits for the ok and sends nothing else.
3) After 4 seconds waiting for the ok, it generates the timeout error.
4) The timeout error seems to make it now skip waiting for the ok on the M190 and it sends the next command.
5) Since the bed is heating up still, that next command times out after 4 seconds and another timeout error is generated.
6) Since ping pong mode seems to be working now, this pattern continues. RS sends a command, waits 4 seconds, the timeout message gets generated, then the next command is sent, and so on until everything is heated up and all the lines get resent and the print continues.
So, to me, the root of all the evil here is why on my system, it's not recognizing the commands listed in the <blockingCommands> section of the marlin.xml file.
Would it be possible to do a special build that puts out some extra logging around the portion of the code that compares the incoming gcode to the blocking commands to try and pinpoint why it's not recognizing a match?
Here's a link to my last logfile:
https://drive.google.com/open?id=0ByWKg0tckgv2WjFiZWtxUHU4WWs
2 possible solutions:
1. Disabale busy in marlin
2. Disable detection in server. In marlin.xml you have a line
Comment it out or delete it and restart server. Then it does not detect you have busy so it does not rely on faulty implementation.
I ran it a 4th time. Here's how the total progression went:
1) Fresh install of RS, first print, waited for M190, didn't wait for M109
2) 2nd run of print job (same session), didn't wait for M190 or M109.
3) At about 98% of the 2nd print job above, the server process seemed to lock up. I could not stop the service and had to restart Windows
4) First try at printing after rebooting, Waited for M190, but didn't wait for M109.
5) Second try at printing in same session, didn't wait for M190 or M109.
Now in the first runs, I didn't see any busy message in the logfile between the M190 and M109 commands (see below). But I do see 6 instances of busy responses later on in the log.
So, if I comment out the busy detection, what will happen during normal printing when a busy message actually gets sent? I imagine it might get a timeout, but that will probably be ok because the server will resend that line after it's not busy, right? Since that's only usually a few seconds I would guess that won't be a big issue.
I'm going to switch back to the pcduino and try your theory out. Crossing my fingers...
> 1:59:52.083: T:26.84 /0.00 B:50.10 /50.00 @:0 B@:51 W:0