Failure to update after firmware mod

[pcweber57]

After changing the z-axis max from 210 to 205 to accommodate the copperhead hotend adapter this plug-in fails to function, hanging after passing the g80 command.

Send: G81 Recv: Num X,Y: 7,7 Recv: Z search height: 5.00 Recv: Measured points: Recv: 0.12500 0.17000 0.11000 0.12250 0.15500 0.14000 0.11500 Recv: 0.08500 0.10750 0.08250 0.07000 0.10500 0.11750 0.11000 Recv: 0.09000 0.12250 0.10750 0.10687 0.12750 0.13000 0.11000 Recv: 0.13000 0.10750 0.09250 0.12250 0.12000 0.10500 0.10250 Recv: 0.12750 0.14000 0.12500 0.11500 0.12500 0.13750 0.11000 Recv: 0.13000 0.14000 0.12250 0.08750 0.10750 0.12000 0.08250 Recv: 0.13250 0.16250 0.10250 0.11000 0.12250 0.12750 0.12750 Recv: ok

[scottrini]

Sorry, but the fw adjustment has to be a red herring here. All of my printers have the same fw adjustment (every one has a bondtech, including several with mosquito magnums). They all had this when the plugin was first developed and now and it still continues to function.

[edspeds]

I can confirm this is an issue, though it may be more related to 3.9.0. Background, I run two MK3's off of octoprint. One printer is running 3.9.0 RC1 and the other is running Vertigo235's modified 3.9.0. Prusa Leveling guide works as it should on the 3.9.0 RC1 FW but gives the same issue as PCWeber57 has on Vertigo235's release. Below is a link to his FW that is to correct issues with Prusa's release.

https://github.com/vertigo235/Prusa-Firmware/releases/tag/MK3_3.9.1_LA15_ALTFAN_FIX_AGAIN

[scottrini]

@edspeds His firmware is exactly what I run on all my MK3S's and I don't run into this problem, unfortunately.

If you'd like to debug and submit a PR for your issue, I'd certainly take a look.

[edspeds]

@edspeds His firmware is exactly what I run on all my MK3S's and I don't run into this problem, unfortunately.

If you'd like to debug and submit a PR for your issue, I'd certainly take a look.

Now I'm really confused as I run both printers off of the same instance of Octoprint, I just select a different printer to connect to. But if we're both using the same FW then it has to be something on my end, hmmm.

[scottrini]

@edspeds after I commented, I was thinking about it and realized the only difference is I build his fw myself. I have some prints going, but I'll give one of his precompiled hexes a shot on one of the printers when it's finished. Might as well completely rule it out.

[scottrini]

Well, I was just able to reproduce it after reflashing. Something in the changes is causing it to ignore the M400 and continue...

[scottrini]

Unfortunately, this does seem to be an issue in the latest vertigo235 firmware mods. I can switch back to the previous vertigo235 hexes I use on my printers and everything runs fine. I've reached out to the vertigo235 maintainer to see if I can get some help figuring out the change.

[edspeds]

Thanks so much for your hard work!

[edspeds]

I reverted to 3.8.1 and all is well now.

[scottrini]

I can even get it working on vertigo235's 3.9.0. It's only when I pull in the 3.9.1 changes, nothing seems to work. I don't think it's any changes he's made, I think it's new changes Prusa is working on in the 3.9.1 branch. I did see some changes for serial functionality, but couldn't pinpoint why it would affect this at all. What octoprint is receiving between 3.9.0 and 3.9.1 seem to be identical, but it might be how the terminal window is interpreting it. I haven't been able to pinpoint the exact change that's causing it, I just hope it's resolved before 3.9.1 is released.

[pcweber57]

I've simply done a G80 from the terminal followed by a G81. Then I grab the output and paste it into a file and execute gen.rb and with the output I'm satisfactorily adjusting the nylock modified bed.

Phil

On Thu, Aug 6, 2020 at 7:36 PM Scott Rini notifications@github.com wrote:

I can even get it working on vertigo235's 3.9.0. It's only when I pull in the 3.9.1 changes, nothing seems to work. I don't think it's any changes he's made, I think it's new changes Prusa is working on in the 3.9.1 branch. I did see some changes for serial functionality, but couldn't pinpoint why it would affect this at all. What octoprint is receiving between 3.9.0 and 3.9.1 seem to be identical, but it might be how the terminal window is interpreting it. I haven't been able to pinpoint the exact change that's causing it, I just hope it's resolved before 3.9.1 is released.

— You are receiving this because you authored the thread. Reply to this email directly, view it on GitHub https://github.com/scottrini/OctoPrint-PrusaLevelingGuide/issues/20#issuecomment-670074786, or unsubscribe https://github.com/notifications/unsubscribe-auth/AJVQLRTYLQ6AWGCKDCDKYELR7LS3BANCNFSM4O54JIUA .

[scottrini]

If I was bypassing the plugin, I'd omit generating a file and running a command and just use the relative g81 page: https://pcboy.github.io/g81_relative/

But I'd prefer to keep this thread on topic and about the plugin and fixing it with 3.9.1.

[wavexx]

I was pointed here to look at this :) I'm not sure I follow what is going on. Does the FW stalls, or does it just ignore the M400? I don't think anything changed significantly in 3.9.1 compared to 3.9.0, but I'd like to make sure we didn't break anything.

Do you have a sample gcode (the smallest you can get) I could try to run to reproduce the issue?

[pcweber57]

I've not delved into the code but as soon as the leveling is complete, the extruder stops as if it was in a loop waiting for something.

[wavexx]

Can you post a serial log starting from a printer reset to the moment it does this? I could try to replay it locally.

[wavexx]

Ok, I managed to reproduce this. It's a bug indeed, M400 doesn't properly handle G28 in this case. Using a short delay (such as G4 S0.1) could work-around this until it's properly fixed.

[scottrini]

Oh hey, thanks! I had been trying to poke through the code for 3.9.1 and saw some serial changes and was thinking that was the culprit, but clearly not. The M400 is in place because the fw sets a timeout to wait for the G81 response. When I was submitting my plugin to the plugins repository, foosel/Gina didn't like how I was waiting for every gcode and comparing it to the regex (which is what the PrusaMeshMap plugin does).

The M400 is in place so there's a wait between G80 and G81. It needs to complete the mesh bed leveling of G80 before running G81 to capture the results. The G28 doesn't really matter, actually, and can just be removed.

[wavexx]

At least currently only moves (G1) are waited-for correctly by M400.

G28/G80 might or might not be, depending on the exact time they're received on the serial (since they generate moves internally, they usually are, but M400 can still escape before they complete fully), but just looking at this I can see many other commands that don't follow this rule properly.

This was also the case before (any FW before 3.9 really). We might have moved some stuff around to make it more likely perhaps.

If you add an useless move command just before the M400 you can ensure it's always waited for, since the move will act as a barrier. It's definitely ugly, I know ;)

[scottrini]

@wavexx The M400 is a red herring in why this is breaking, though. The new 3.9.1 fw also breaks PrusaMeshMap (https://github.com/PrusaOwners/OctoPrint-PrusaMeshMap/blob/master/octoprint_PrusaMeshMap/__init__.py#L86). The regex never matches on the returned information from the G81 response. Even if I disable my timeout and completely remove the need for M400, I have the same issue. I did notice there were some serial changes in 3.9.1, so I was assuming it was probably related to those.

[wavexx]

Looking at the code between 3.8.1 and 3.9.1 I don't see changes in output though (and also at a first glance, the end result itself).

Looking at the output of G81, the regex seems wrong. This is the output on 3.8.1:

> Num X,Y: 7,7
Z search height: 5.00
Measured points:
  -0.13000  -0.10861  -0.09944  -0.10250  -0.11778  -0.14528  -0.18500
  -0.12222  -0.09877  -0.08840  -0.09111  -0.10691  -0.13580  -0.17778
  -0.10889  -0.08349  -0.07117  -0.07194  -0.08580  -0.11275  -0.15278
  -0.09000  -0.06278  -0.04778  -0.04500  -0.05444  -0.07611  -0.11000
  -0.06556  -0.03664  -0.01821  -0.01028  -0.01284  -0.02590  -0.04944
  -0.03556  -0.00506  0.01753  0.03222  0.03901  0.03790  0.02889
  0.00000  0.03194  0.05944  0.08250  0.10111  0.11528  0.12500
ok

There's no number that "^( -?\d+.\d+)+$" would match if "line" is a full line as received from serial because of the anchoring.

Do I read the code wrong?

[scottrini]

@wavexx For the regex to be wrong, it wouldn't have been working in the PrusaMeshMap plugin for months/years. It currently works in both this plugin and the PrusaMeshMap plugin as long the printer is flashed with 3.9.0 and not 3.9.1.

The PrusaMeshMap plugin existed way before mine did and I just nabbed the regex for them. I just have mine compile at octoprint startup and not recompile for every single gcode received...https://github.com/scottrini/OctoPrint-PrusaLevelingGuide/blob/master/octoprint_PrusaLevelingGuide/__init__.py#L25

If I insert my regex and the first line from what you pasted into regex101.com, I get a match: https://regex101.com/r/1EAMzB/1

I'm at a loss myself because I can't see any differences in the output between the two firmware versions, but for some reason, the regex matches on the previous firmware, but not on the new one.

[scottrini]

I just want to say I really appreciate any help/feedback here. Like I said, I'm totally stumped because I can't see any difference myself. My only theory is a possible encoded/double byte character or something simple I'm missing. Like it's using the two space characters in the regex, so I thought something might have been changed there, but I haven't seen any evidence of that. So I'm totally grasping at straws to figure it out.

[wavexx]

No problem, I also want to make sure we didn't break stuff. Looking now again I see there's a + operator after the parens, so ok, this should match the line as a whole.

I'm away from the printer now, but what about an invisible \r in there, confusing $? AFAIK octoprint moved to python3 recently, this could cause stuff like this to appear.

I'd log "line" using console.log(JSON.stringify(line)) in that function to expose unexpected stuff. If you run both old FW versions and the new maybe we can spot the difference.

[scottrini]

I'm still using python 2.7 and can duplicate, so I don't think it's related to python. console.log/JSON.stringify is JS and this is happening in python. Previously, I had it logging the output and didn't see anything, but I wasn't using json.dumps. I'll give it another try in a little bit with additional logging and compare and I'll post it here.

[scottrini]

Here's the before, with 3.9.0 - https://pastebin.com/tkX1QK16

I added the logging to PrusaMeshMap:

def mesh_level_check(self, comm, line, *args, **kwargs): self._logger.info(json.dumps(line)) if re.match(r"^( -?\d+.\d+)+$", line): self.mesh_level_responses.append(line) self._logger.info("FOUND: " + line) self.mesh_level_generate() return line else: return line

[scottrini]

Yep, that's exactly it. A carriage return is added in 3.9.1 that wasn't there before - https://pastebin.com/4Xcbkjts

[scottrini]

So yeah, just removing the $ from the regex clears this up. I'll push a fix now and bump the version.

[wavexx]

Ok, I see where this is coming from. Arguably it should have been there since the beginning.. this resulted from a cleanup done to conserve extra flash space.

I wouldn't remove the $. I'd rstrip the string before the match.

@leptun should we bring back the old behavior here?

[wavexx]

I wonder how many plugins depend on this output.

[scottrini]

@wavexx I agree, seems like it should have been there from the beginning, most other lines include both carriage return and newline. I also changed it to remove the carriage return prior to performing the regex. I only know of PrusaMeshMap and my own.

[scottrini]

@pcweber57 @edspeds This is now fixed in 1.0.9. You can feel free to update to the (pre-release) 3.9.1 vertigo235 build.