lavato commented 8 years ago

After stopping a print, new print shifts toward X0 about 20mm and Z axes shifts ~0.2mm down. Not sure about y, as it may not be noticeable.

I am not sure how far into the print you need to be or how many stopped prints you need to have before this happens but the behavior is diffidently related to stopping a print and it happened many times.

Technical info: Cartesian type printer RAMPS 1.4 Prusa i3 RC6

Blue-Marlin commented 8 years ago

What do you mean with stop? M410?

lavato commented 8 years ago

I stop via LCD menu

Blue-Marlin commented 8 years ago

That's basically the same. Both call Stepper::quick_stop()

/**
 * M410: Quickstop - Abort all planned moves
 *
 * This will stop the carriages mid-move, so most likely they
 * will be out of sync with the stepper position after this.
 */
inline void gcode_M410() { stepper.quick_stop(); }

How about homing for the new print?

lavato commented 8 years ago

Once the new print starts e,g, I select a file from my SD card using LCD, G28 / G29 is re-executed. Obviously if I reset Marlin everything is OK.

Blue-Marlin commented 8 years ago

Is your EEPROM active? When booting the EEPROM content is shown. Is your output different from

21:24:25.189 : echo:Home offset (mm):
21:24:25.189 : echo:  M206 X0.00 Y0.00 Z0.00

Or do you set the home_offsets by will?

lavato commented 8 years ago

I don't connect Pronteface that often so I don't know. EEPROM is active.

What do you mean by "do you set the home_offsets by will"?

Blue-Marlin commented 8 years ago

What do you mean by "do you set the home_offsets by will"?

Sending or having in a file

M206 X? Y? Z?

lavato commented 8 years ago

I don't have this in my Custom Script section, only

G28
G29
G1 Z5 F5000

I also don't send this - just use the LCD

thinkyhead commented 8 years ago

You can easily see if there's any M206 offset set, because when you use "Auto Home" from the LCD (G28) the XYZ will be something other than X0 Y0 Z0. If they are not all zero, the M206 offsets may be cleared from the LCD. First do "Auto Home." Then immediately do "Set Home Offset." Then "Save to EEPROM."

lavato commented 8 years ago

I don't think I used Auto Home and this issue does not always happen but I will try observering xyz when I re-start the print next time.

Just to clarify, the issue can be reproduced in a following way:

Steps:

Insert SD
Start Print - by going to SD menu - e.g. Print starts at x80, y80, z0.2
Stop print - by using the menu option (e.g. because of some issue)
Start print - by going to SD menu - e.g. Print starts at x80, y80, z0.2
Stop Print - by using the menu option (e.g. because of some issue)
Start print - Print offsets as described above) - e.g. Print starts at x60, ~y80, z0.0

Sometimes it happens after just one stop, I think. :/

thinkyhead commented 8 years ago

@lavato The fact that it occurs spuriously lends some credence to my theory that the current_position is getting out-of-sync with the planner's position and the steppers' step_count values. This could occur because moves in the planner are being thrown away, but after the main loop has updated its current_position. The solution, I believe, will be to reset the current_position based on the stepper/planner position/step_count whenever a print is resumed. Hopefully, this will be a simple fix. I will investigate…

thinkyhead commented 8 years ago

After checking into the code…

Both the LCD "Stop print" menu item and the M410 GCode call stepper.quick_stop() which throws away planned moves, as mentioned above. So neither of these should be used for stopping a print that you intend to resume. Instead, you should always use the "Pause print" command.

If you are using "Pause print" then we should look further.

thinkyhead commented 8 years ago

As long as we're patching known issues, I've submitted #3939 to get the current_position from the steppers after planner moves have been thrown away and the stepper has finished its blocks.

Blue-Marlin commented 8 years ago

@thinkyhead

3939 is great, completely logic in it selves and will improve the shift a lot.

A small error will remain because of the sudden, not de-accelerated stop from quick_stop() when disabling the stepper interrupt. Some steps might be lost there, depending on the speed when the quick_stop occurs.

The thing i do not understand is, how the shift could survive a homing. @lavato Do your files on the SD have a G28 in?

thinkyhead commented 8 years ago

Some steps might be lost there

On my machines the number of steps/mm is pretty large. So I don't imagine most machines will get thrown off by a very large amount.

Something about #3939 occurred to me as being flawed…. Ah, now I remember. It doesn't work for DELTA because we don't have the equations in the code yet for forward kinematics.

lavato commented 8 years ago

I only noticed the issue because the hotend noticeably moves about 2cm when I start a new print from my SD card. (after stopping)

It is also worth mentioning that I use ABL using a sensor.

@Blue-Marlin

Yes they do all have G28. (Slic3r)

@thinkyhead

I cannot remember if I used Pause prints between me stopping the print but I will keep in mind to report back if I do.

thinkyhead commented 8 years ago

the hotend noticeably moves about 2cm when I start a new print from my SD card

I've applied the changes to the latest code, so on non-DELTA machines the position is grabbed from the steppers after you stop the print. Hopefully this will eliminate that huge 2cm shift in position.

lavato commented 8 years ago

Great! I will download the latest BugFix and come back with results Currently, I am always resting since when I have a large print it becomes an issue. (hot end hits the edge)

AnHardt commented 8 years ago

@thinkyhead If you are looking for delta forward kinematics. Please have a look at https://github.com/AnHardt/Marlin/pull/44 and the related test program at https://gist.github.com/AnHardt/62ce0d150b09dca1e75b10fcf6cf3c67

thinkyhead commented 8 years ago

@AnHardt That's a good concise forward kinematics function. Where did you find it?

It seems like it might need a couple of tweaks to fit into Marlin. For example, we might need to add home_offset – at least the Z axis. And if there's any kind of bed leveling enabled, then the "idealized" coordinates returned by the forwardKinematics function will need to be transformed by the inverse plane (or mesh). I'm not sure how many of the M665 values need to come into play, but possibly some of those factors need to be added into this function too.

AnHardt commented 8 years ago

@thinkyhead My source was http://fab.cba.mit.edu/classes/863.15/section.CBA/people/Spielberg/Rostock_Delta_Kinematics_3.pdf I know that you know the article and have had a little conversation with Steve Graves about the setup of the first array. That information plus two days of work was enough to make a C version from the Java stub and squezing it into Marlins environment. ( Ok. One day and an other to find out about not using strings containing a "!!!" sequence with Arduino, because it causes upload errors :-( ) The current version (https://github.com/AnHardt/Marlin/pull/44) is the exact reverse of calculate_delta(), not more not less. (See the test sketch https://gist.github.com/AnHardt/62ce0d150b09dca1e75b10fcf6cf3c67 ) It already respects

DELTA_DIAGONAL_ROD
DELTA_SMOOTH_ROD_OFFSET
DELTA_EFFECTOR_OFFSET
DELTA_CARRIAGE_OFFSET
DELTA_RADIUS
DELTA_RADIUS_TRIM_TOWER_1
DELTA_RADIUS_TRIM_TOWER_2
DELTA_RADIUS_TRIM_TOWER_3
DELTA_DIAGONAL_ROD_TRIM_TOWER_1
DELTA_DIAGONAL_ROD_TRIM_TOWER_2
DELTA_DIAGONAL_ROD_TRIM_TOWER_3

Some of these can be altered by M665.

home_offset and bed leveling is not in - just the reverse of calculate_delta(). If we have x and y, recalculating the ?BL-correction needs no witchcraft. Only z is affected.
I currently don't know if home_offset is needed at all.

The test sketch sets up the delta with random delta correction parameters (original recalc_delta_settings()), picks a random possible Cartesian point in the build volume, calculates the tower positions with calculate_delta() (original), puts this values into forwardKinematics() and compares the Cartesian result with the point we put into calculate_delta(). With surprisingly exact results. Not really fast, but hopefully rarely needed.

thinkyhead commented 8 years ago

Not really fast, but hopefully rarely needed.

In fact, only when stop() is used to kill a print in progress. So it doesn't need to be fast at all.

AnHardt commented 8 years ago

A small change to adjust_delta() to get the z-correction we want. adjust_delta() adjusts delta[] directly. For the forward calculation this is the wrong direction.

    // Adjust print surface height by linear interpolation over the bed_level array.
-    void adjust_delta(float cartesian[3]) {
+    float adjust_delta(float cartesian[3]) {
-      if (delta_grid_spacing[0] == 0 || delta_grid_spacing[1] == 0) return; // G29 not done!
+      if (delta_grid_spacing[0] == 0 || delta_grid_spacing[1] == 0) return 0.0; // G29 not done!

      int half = (AUTO_BED_LEVELING_GRID_POINTS - 1) / 2;
      float h1 = 0.001 - half, h2 = half - 0.001,
            grid_x = max(h1, min(h2, cartesian[X_AXIS] / delta_grid_spacing[0])),
            grid_y = max(h1, min(h2, cartesian[Y_AXIS] / delta_grid_spacing[1]));
      int floor_x = floor(grid_x), floor_y = floor(grid_y);
      float ratio_x = grid_x - floor_x, ratio_y = grid_y - floor_y,
            z1 = bed_level[floor_x + half][floor_y + half],
            z2 = bed_level[floor_x + half][floor_y + half + 1],
            z3 = bed_level[floor_x + half + 1][floor_y + half],
            z4 = bed_level[floor_x + half + 1][floor_y + half + 1],
            left = (1 - ratio_y) * z1 + ratio_y * z2,
            right = (1 - ratio_y) * z3 + ratio_y * z4,
            offset = (1 - ratio_x) * left + ratio_x * right;

      delta[X_AXIS] += offset;
      delta[Y_AXIS] += offset;
      delta[Z_AXIS] += offset;
...
+      return offset;
    }

#if ENABLED(AUTO_BED_LEVELING_FEATURE)
  cartesian[Z_AXIS] -= adjust_delta(cartesian); // note the side effect on delta[]
#endif

thinkyhead commented 8 years ago

Do you think this would cost too many extra cycles…?

// Adjust print surface height by linear interpolation over the bed_level array.
inline float delta_offset(float cartesian[3]) {
  if (delta_grid_spacing[0] == 0 || delta_grid_spacing[1] == 0) return 0.0; // G29 not done!

  int half = (AUTO_BED_LEVELING_GRID_POINTS - 1) / 2;
  float h1 = 0.001 - half, h2 = half - 0.001,
        grid_x = max(h1, min(h2, cartesian[X_AXIS] / delta_grid_spacing[0])),
        grid_y = max(h1, min(h2, cartesian[Y_AXIS] / delta_grid_spacing[1]));
  int floor_x = floor(grid_x), floor_y = floor(grid_y);
  float ratio_x = grid_x - floor_x, ratio_y = grid_y - floor_y,
        z1 = bed_level[floor_x + half][floor_y + half],
        z2 = bed_level[floor_x + half][floor_y + half + 1],
        z3 = bed_level[floor_x + half + 1][floor_y + half],
        z4 = bed_level[floor_x + half + 1][floor_y + half + 1],
        left = (1 - ratio_y) * z1 + ratio_y * z2,
        right = (1 - ratio_y) * z3 + ratio_y * z4;

  return (1 - ratio_x) * left + ratio_x * right;
}

// Adjust print surface height by linear interpolation over the bed_level array.
void adjust_delta(float cartesian[3]) {
  float offset = delta_offset(cartesian);
  delta[X_AXIS] += offset;
  delta[Y_AXIS] += offset;
  delta[Z_AXIS] += offset;
}

#if ENABLED(AUTO_BED_LEVELING_FEATURE)
  cartesian[Z_AXIS] -= delta_offset(cartesian);
#endif

AnHardt commented 8 years ago

Sorry. I was a bit confused. Of course home_offset is needed. It's endstop_adj[] that is not needed because those are applied in homeaxis() before set_axis_is_at_home() - for deltas.

I guess its fast enough. Did you have a close look into the function? It's mesh bed leveling with some other names. Let's see how fast the mesh levelers can make their code an adopt that. (Or the other way around). Looks as if i have to make some benchmarks.

AnHardt commented 8 years ago

adjust_delta: 283.08!-0.46 adjust_delta_n: 284.04!-0.46  adjust_delta_m: 424.44! 0.17  diff1: 0.96  diff2: 140.40
adjust_delta: 285.24!-1.28 adjust_delta_n: 283.36!-1.28  adjust_delta_m: 436.84! 0.22  diff1: over  diff2: 153.48
adjust_delta: 268.72! 1.28 adjust_delta_n: 272.96! 1.28  adjust_delta_m: 425.60! 0.79  diff1: 4.24  diff2: 152.64
adjust_delta: 266.20!-0.18 adjust_delta_n: 265.88!-0.18  adjust_delta_m: 425.28! 0.71  diff1: over  diff2: 159.40
adjust_delta: 284.92!-1.36 adjust_delta_n: 290.80!-1.36  adjust_delta_m: 429.92!-0.32  diff1: 5.88  diff2: 139.12
adjust_delta: 280.68!-0.98 adjust_delta_n: 283.16!-0.98  adjust_delta_m: 433.56! 1.43  diff1: 2.48  diff2: 150.40 
adjust_delta: 279.68! 0.52 adjust_delta_n: 280.52! 0.52  adjust_delta_m: 434.44! 1.44  diff1: 0.84  diff2: 153.92

Up to now it looks as if your version is a little bit slower than mine (as expected). MBL seems to be much slower. If they'd give the the same results i'd have a bit more trust in the result. Still looking for my error. (The high diff numbers are timer overflows.)

AnHardt commented 8 years ago

Got it. One time the probed array is interpreted to be in the first quadrant (MBL) while the other wants to have 0,0 in the mid of the bed (delta). Assuming 0,0 in the mid, allows an optimization where a float subtraction can be replaced by a int subtraction. As soon as the delta algorithm is tuned to accept the 0,0-point anywhere, it takes about the same time as the mesh version.

lavato commented 8 years ago

I can confirm that this issue is still ongoing even with the latest RCBugFix, this even happens when print completes.

Steps to reproduce:

Insert SD card
Print from SD ( this can be a small test print)
Print completes
Print same object from SD card again =>> the print shifts toward X0

I think this is happening often lately.

thinkyhead commented 8 years ago

@lavato There's no position-reorientation done at the end of a normal SD print. Can you confirm that the GCode you're testing has no unusual commands like G92, M206, etc. included within it? Usually GCode files will include a G28 in the beginning. The file you're testing has no G28 at the start?

Are the coordinates simply wrong at the end of an SD print? Like, if you finish an SD print and then go to 0, 0… does the nozzle go to the wrong point?

lavato commented 8 years ago

The files have G28, in fact I was re-printing the same file when it happened 2 days ago.

I will create a small print file and try to reproduce this, possibly tonight, I will then upload the file and provide some more details.

Blue-Marlin commented 8 years ago

Could it be a slipping x-endstop?

Blue-Marlin commented 8 years ago

What does your

  #define SD_FINISHED_STEPPERRELEASE true  //if sd support and the file is finished: disable steppers?
  #define SD_FINISHED_RELEASECOMMAND "M84 X Y Z E" // You might want to keep the z enabled so your bed stays in place.

look like.

lavato commented 8 years ago

X end stop cannot slip as it is hard against the Z rod holder.

I think this is to do with dual extruder setup as it seam to move toward X0 by about 3cm which is the width between extruders. As I said above I will do a small test print and upload the g code sample if I manage to reproduce it. I will also check the two static variables later tonight.

Blue-Marlin commented 8 years ago

Mentioning "dual extruder" 30 posting before would not have hurt. :-(

No further comments to your issues from my side as long as you don't append your configs.

lavato commented 8 years ago

Mentioning "dual extruder" 30 posting before would not have hurt. :-(

Yes, if I knew which line of code caused this I would just say it. The problem is that these things are not always apparent.
At the time I have raised this (in May), I may just had one functioning extruder, as I upgraded recently.

I am attaching my config file.

Configuration.h.txt

thinkyhead commented 8 years ago

Does your GCode end with the other tool selected? Or is this happening when using only a single tool?

lavato commented 8 years ago

@thinkyhead Finally, I found the pattern when this is happening consistently!

When printing with Hot End 1 it works OK, however when I print only with Hot End 2, it shifts every time towards x.

I crated a small test print yesterday and only printed using Hot End 2 (T1), the issue happened every time.

Does your GCode end with the other tool selected?

The last T command in the G code is T1.

Originally, I thought this is relevant only when stopping, as I would repeat the print and this would happened but now it is apparent that it is happening whenever you start a print using T1.

Nowadays I always reset Marlin so I don't notice it as much. :O

thinkyhead commented 8 years ago

I added more logging for gcode_T in #4308 (now merged) so please test! Be sure to enable DEBUG_LEVELING_FEATURE and use M111 S32 before testing. Then post the log here. Hopefully it will reveal … something!

thinkyhead commented 8 years ago

@lavato Are you also, by any chance, also using Mesh Bed Leveling? I found a bug in that which can cause shifting of positions. Although the final XY should theoretically be correct. But I can't say for sure. Recursive functions are hard to follow!

Call mesh_move_to_destination()
If the line is entirely within a space, just do the move and return
If the line crosses a mesh in X to the right…
- Set a new destination XY (with the next grid's X)
- Set other axes in proportion to the amount of total line
- Recurse.
- If the new line is entirely within a space, just do the move and return
- If the new line crosses a mesh in X to the right (for example)…
  - Set a new destination XY (clipped at the adjoining grid X boundary)
  - Set other axes in proportion to the amount of total line
  - Recurse. Line may be chopped at Y next? Yes, but it will be redundant!
  - (so presumably here it could just do a line-draw, save 1 call.)
  - Set the original destination
  - Recurse. (from the split to the end)
  - Exit.
- Set the original destination
- Recurse. (from the split to the end)
- Exit.

lavato commented 8 years ago

@thinkyhead

https://github.com/thinkyhead/Marlin/tree/rc_debug_gcode_t)

The link you gave goes nowhere, what did you want to suggest for me to do with this link?

thinkyhead commented 8 years ago

The link you gave goes nowhere

Sorry. RCBugFix now has the code from there merged (and I deleted the branch), so just debug with RCBugFix.

lavato commented 8 years ago

The issue is still there. As requested, here is the log.

putty.txt

FYI: I have lowered the bed temp during print not to have to wait long

thinkyhead commented 8 years ago

The issue is still there.

Excellent. I only added logging.

AnHardt commented 8 years ago

Maybe we could see more if we'd have the stepper positions. stepper.report_positions(); or report_current_position();

thinkyhead commented 8 years ago

Easier to see with indentation and cleanup…

Homing, leveling, SD print log

``` echo:Home offset (mm) echo: M206 X0.00 Y0.00 Z0.00 echo:Z-Probe Offset (mm): echo: M851 Z-1.82 echo:DEBUG:LEVELING >>> gcode_G28 current_position=(0.00, 0.00, 0.00) : setup_for_endstop_or_probe_move > endstops.enable(true) Raise Z (before homing) to 5.00 do_blocking_move_to(0.00, 0.00, 5.00) >>> homeaxis(0) current_position=(0.00, 0.00, 5.00) : sync_plan_position current_position=(0.00, 0.00, 5.00) : sync_plan_position current_position=(0.00, 0.00, 5.00) : > TRIGGER ENDSTOP >>> set_axis_is_at_home(0) For X axis: home_offset = 0.00 position_shift = 0.00 sw_endstop_min = 0.00 sw_endstop_max = 190.00 > home_offset[X] = 0.00 current_position=(0.00, 0.00, 5.00) : <<< set_axis_is_at_home(0) current_position=(0.00, 0.00, 5.00) : sync_plan_position current_position=(0.00, 0.00, 5.00) : > AFTER set_axis_is_at_home <<< homeaxis(0) current_position=(0.00, 0.00, 5.00) : > homeX >>> homeaxis(1) current_position=(0.00, 0.00, 5.00) : sync_plan_position current_position=(0.00, 0.00, 5.00) : sync_plan_position current_position=(0.00, 0.00, 5.00) : > TRIGGER ENDSTOP >>> set_axis_is_at_home(1) For Y axis: home_offset = 0.00 position_shift = 0.00 sw_endstop_min = 0.00 sw_endstop_max = 190.00 > home_offset[Y] = 0.00 current_position=(0.00, 0.00, 5.00) : <<< set_axis_is_at_home(1) current_position=(0.00, 0.00, 5.00) : sync_plan_position current_position=(0.00, 0.00, 5.00) : > AFTER set_axis_is_at_home <<< homeaxis(1) current_position=(0.00, 0.00, 5.00) : > homeY >>> homeaxis(2) > current_position=(0.00, 0.00, 5.00) : set_probe_deployed deploy: 1 do_probe_raise(15.00) do_blocking_move_to(0.00, 0.00, 16.82) do_blocking_move_to(0.00, 0.00, 16.82) current_position=(0.00, 0.00, 0.00) : sync_plan_position current_position=(0.00, 0.00, 0.00) : sync_plan_position current_position=(0.00, 0.00, 0.00) : > TRIGGER ENDSTOP >>> set_axis_is_at_home(2) For 90 axis: home_offset = 0.00 position_shift = 0.00 sw_endstop_min = 0.00 sw_endstop_max = 180.00 > zprobe_zoffset = -1.82 > home_offset[90] = 0.00 current_position=(0.00, 0.00, 1.82) : <<< set_axis_is_at_home(2) current_position=(0.00, 0.00, 1.82) : sync_plan_position current_position=(0.00, 0.00, 1.82) : > AFTER set_axis_is_at_home > current_position=(0.00, 0.00, 1.82) : set_probe_deployed deploy: 0 do_probe_raise(15.00) do_blocking_move_to(0.00, 0.00, 16.82) do_blocking_move_to(0.00, 0.00, 16.82) <<< homeaxis(2) current_position=(0.00, 0.00, 16.82) : > (home_all_axis || homeZ) > final current_position=(0.00, 0.00, 16.82) : sync_plan_position > endstops.not_homing() current_position=(0.00, 0.00, 16.82) : clean_up_after_endstop_or_probe_move <<< gcode_G28 >>> gcode_G29 current_position=(0.00, 0.00, 16.82) : G29 Auto Bed Leveling corrected_position=(0.00, 0.00, 16.82) : BEFORE matrix.set_to_identity current_position=(0.00, 0.00, 16.82) : BEFORE matrix.set_to_identity uncorrected_position=(0.00, 0.00, 16.82) : AFTER matrix.set_to_identity current_position=(0.00, 0.00, 16.82) : sync_plan_position current_position=(0.00, 0.00, 16.82) : setup_for_endstop_or_probe_move current_position=(0.00, 0.00, 16.82) : set_probe_deployed deploy: 1 do_probe_raise(15.00) do_blocking_move_to(0.00, 0.00, 16.82) do_blocking_move_to(0.00, 0.00, 16.82) >>> probe_pt(30.00, 30.00, 1) current_position=(0.00, 0.00, 16.82) : do_probe_raise(5.00) > do_blocking_move_to_xy(0.00, 30.00) do_blocking_move_to(0.00, 30.00, 16.82) > current_position=(0.00, 30.00, 16.82) : set_probe_deployed deploy: 1 current_position=(0.00, 30.00, 1.84) : run_z_probe current_position=(0.00, 30.00, 1.84) : sync_plan_position > do_probe_raise do_probe_raise(5.00) do_blocking_move_to(0.00, 30.00, 6.82) <<< probe_pt >>> probe_pt(95.00, 30.00, 1) current_position=(0.00, 30.00, 6.82) : do_probe_raise(5.00) > do_blocking_move_to_xy(65.00, 30.00) do_blocking_move_to(65.00, 30.00, 6.82) > current_position=(65.00, 30.00, 6.82) : set_probe_deployed deploy: 1 current_position=(65.00, 30.00, 1.77) : run_z_probe current_position=(65.00, 30.00, 1.77) : sync_plan_position > do_probe_raise do_probe_raise(5.00) do_blocking_move_to(65.00, 30.00, 6.82) <<< probe_pt >>> probe_pt(160.00, 30.00, 1) current_position=(65.00, 30.00, 6.82) : do_probe_raise(5.00) > do_blocking_move_to_xy(130.00, 30.00) do_blocking_move_to(130.00, 30.00, 6.82) > current_position=(130.00, 30.00, 6.82) : set_probe_deployed deploy: 1 current_position=(130.00, 30.00, 1.96) : run_z_probe current_position=(130.00, 30.00, 1.96) : sync_plan_position > do_probe_raise do_probe_raise(5.00) do_blocking_move_to(130.00, 30.00, 6.82) <<< probe_pt >>> probe_pt(160.00, 95.00, 1) current_position=(130.00, 30.00, 6.82) : do_probe_raise(5.00) > do_blocking_move_to_xy(130.00, 95.00) do_blocking_move_to(130.00, 95.00, 6.82) > current_position=(130.00, 95.00, 6.82) : set_probe_deployed deploy: 1 current_position=(130.00, 95.00, 1.91) : run_z_probe current_position=(130.00, 95.00, 1.91) : sync_plan_position > do_probe_raise do_probe_raise(5.00) do_blocking_move_to(130.00, 95.00, 6.82) <<< probe_pt >>> probe_pt(95.00, 95.00, 1) current_position=(130.00, 95.00, 6.82) : do_probe_raise(5.00) > do_blocking_move_to_xy(65.00, 95.00) do_blocking_move_to(65.00, 95.00, 6.82) > current_position=(65.00, 95.00, 6.82) : set_probe_deployed deploy: 1 current_position=(65.00, 95.00, 1.75) : run_z_probe current_position=(65.00, 95.00, 1.75) : sync_plan_position > do_probe_raise do_probe_raise(5.00) do_blocking_move_to(65.00, 95.00, 6.82) <<< probe_pt >>> probe_pt(30.00, 95.00, 1) current_position=(65.00, 95.00, 6.82) : do_probe_raise(5.00) > do_blocking_move_to_xy(0.00, 95.00) do_blocking_move_to(0.00, 95.00, 6.82) > current_position=(0.00, 95.00, 6.82) : set_probe_deployed deploy: 1 current_position=(0.00, 95.00, 2.00) : run_z_probe current_position=(0.00, 95.00, 2.00) : sync_plan_position > do_probe_raise do_probe_raise(5.00) do_blocking_move_to(0.00, 95.00, 6.82) <<< probe_pt >>> probe_pt(30.00, 160.00, 1) current_position=(0.00, 95.00, 6.82) : do_probe_raise(5.00) > do_blocking_move_to_xy(0.00, 160.00) do_blocking_move_to(0.00, 160.00, 6.82) > current_position=(0.00, 160.00, 6.82) : set_probe_deployed deploy: 1 current_position=(0.00, 160.00, 2.02) : run_z_probe current_position=(0.00, 160.00, 2.02) : sync_plan_position > do_probe_raise do_probe_raise(5.00) do_blocking_move_to(0.00, 160.00, 6.82) <<< probe_pt >>> probe_pt(95.00, 160.00, 1) current_position=(0.00, 160.00, 6.82) : do_probe_raise(5.00) > do_blocking_move_to_xy(65.00, 160.00) do_blocking_move_to(65.00, 160.00, 6.82) > current_position=(65.00, 160.00, 6.82) : set_probe_deployed deploy: 1 current_position=(65.00, 160.00, 1.64) : run_z_probe current_position=(65.00, 160.00, 1.64) : sync_plan_position > do_probe_raise do_probe_raise(5.00) do_blocking_move_to(65.00, 160.00, 6.82) <<< probe_pt >>> probe_pt(160.00, 160.00, 1) current_position=(65.00, 160.00, 6.82) : do_probe_raise(5.00) > do_blocking_move_to_xy(130.00, 160.00) do_blocking_move_to(130.00, 160.00, 6.82) > current_position=(130.00, 160.00, 6.82) : set_probe_deployed deploy: 1 current_position=(130.00, 160.00, 1.82) : run_z_probe current_position=(130.00, 160.00, 1.82) : sync_plan_position > do_probe_raise do_probe_raise(5.00) do_blocking_move_to(130.00, 160.00, 6.82) <<< probe_pt current_position=(130.00, 160.00, 6.82) : set_probe_deployed deploy: 0 do_probe_raise(15.00) do_blocking_move_to(130.00, 160.00, 16.82) current_position=(130.00, 160.00, 16.82) : clean_up_after_endstop_or_probe_move current_position=(130.00, 160.00, 16.82) : > probing complete Eqn coefficients: a: -0.00046119 b: -0.00023700 d: 1.92299127 uncorrected_position=(130.00, 160.00, 16.82) : >>> set_bed_level_equation_lsq current_position=(130.00, 160.00, 16.82) : >>> set_bed_level_equation_lsq corrected_position=(129.99, 159.99, 16.92) : <<< set_bed_level_equation_lsq current_position=(129.99, 159.99, 16.92) : sync_plan_position Bed Level Correction Matrix: +1.000000 +0.000000 -0.000461 -0.000000 +1.000000 -0.000237 +0.000461 +0.000237 +1.000000 > BEFORE apply_rotation_xyz > stepper_z = 16.82 ... z_tmp = 16.92 > AFTER apply_rotation_xyz > z_tmp = 16.81 current_position=(129.99, 159.99, 16.90) : sync_plan_position current_position=(129.99, 159.99, 16.90) : > corrected Z in G29 <<< gcode_G29 >>> gcode_T current_position=(129.99, 159.99, 5.00) : BEFORE tmp_offset_vec x: -30.399999 y: 0.600000 z: 0.000000 act_offset_vec x: 0.000000 y: 0.000000 z: 0.000000 offset_vec (BEFORE) x: -30.399999 y: 0.600000 z: 0.000000 offset_vec (AFTER) x: -30.399995 y: 0.600003 z: -0.013878 Offset Tool XY by { -30.40, -30.40 } For X axis: home_offset = 0.00 position_shift = -30.40 sw_endstop_min = -30.40 sw_endstop_max = 159.60 For Y axis: home_offset = 0.00 position_shift = 0.60 sw_endstop_min = 0.60 sw_endstop_max = 190.60 current_position=(99.59, 160.59, 4.99) : Sync After Toolchange current_position=(99.59, 160.59, 4.99) : sync_plan_position destination=(129.99, 159.99, 5.00) : Move back current_position=(129.99, 159.99, 5.00) : AFTER <<< gcode_T Done printing file echo:enqueueing "M84 X Y Z E" echo:enqueueing "M31" >>> gcode_G28 current_position=(86.70, 102.99, 0.70) : setup_for_endstop_or_probe_move > endstops.enable(true) Raise Z (before homing) to 5.00 do_blocking_move_to(86.70, 102.99, 5.00) >>> homeaxis(0) current_position=(0.00, 102.99, 5.00) : sync_plan_position current_position=(0.00, 102.99, 5.00) : sync_plan_position current_position=(0.00, 102.99, 5.00) : > TRIGGER ENDSTOP >>> set_axis_is_at_home(0) For X axis: home_offset = 0.00 position_shift = 0.00 sw_endstop_min = 0.00 sw_endstop_max = 190.00 > home_offset[X] = 0.00 current_position=(0.00, 102.99, 5.00) : <<< set_axis_is_at_home(0) current_position=(0.00, 102.99, 5.00) : sync_plan_position current_position=(0.00, 102.99, 5.00) : > AFTER set_axis_is_at_home <<< homeaxis(0) current_position=(0.00, 102.99, 5.00) : > homeX current_position=(0.00, 102.99, 5.00) : sync_plan_position > endstops.not_homing() current_position=(0.00, 102.99, 5.00) : clean_up_after_endstop_or_probe_move <<< gcode_G28 echo:Print time 0h 4m 11s echo:enqueueing "M23 shift~1.gco" echo:enqueueing "M24" echo:Now fresh file: shift~1.gco File opened: 1797 Size: 15437 File selected echo:DEBUG:LEVELING >>> gcode_G28 current_position=(0.00, 102.99, 5.00) : setup_for_endstop_or_probe_move > endstops.enable(true) >>> homeaxis(0) current_position=(0.00, 102.99, 5.00) : sync_plan_position current_position=(0.00, 102.99, 5.00) : sync_plan_position current_position=(0.00, 102.99, 5.00) : > TRIGGER ENDSTOP >>> set_axis_is_at_home(0) For X axis: home_offset = 0.00 position_shift = 0.00 sw_endstop_min = 0.00 sw_endstop_max = 190.00 > home_offset[X] = 0.00 current_position=(0.00, 102.99, 5.00) : <<< set_axis_is_at_home(0) current_position=(0.00, 102.99, 5.00) : sync_plan_position current_position=(0.00, 102.99, 5.00) : > AFTER set_axis_is_at_home <<< homeaxis(0) current_position=(0.00, 102.99, 5.00) : > homeX >>> homeaxis(1) current_position=(0.00, 0.00, 5.00) : sync_plan_position current_position=(0.00, 0.00, 5.00) : sync_plan_position current_position=(0.00, 0.00, 5.00) : > TRIGGER ENDSTOP >>> set_axis_is_at_home(1) For Y axis: home_offset = 0.00 position_shift = 0.00 sw_endstop_min = 0.00 sw_endstop_max = 190.00 > home_offset[Y] = 0.00 current_position=(0.00, 0.00, 5.00) : <<< set_axis_is_at_home(1) current_position=(0.00, 0.00, 5.00) : sync_plan_position current_position=(0.00, 0.00, 5.00) : > AFTER set_axis_is_at_home <<< homeaxis(1) current_position=(0.00, 0.00, 5.00) : > homeY >>> homeaxis(2) > current_position=(0.00, 0.00, 5.00) : set_probe_deployed deploy: 1 do_probe_raise(15.00) do_blocking_move_to(0.00, 0.00, 16.82) do_blocking_move_to(0.00, 0.00, 16.82) current_position=(0.00, 0.00, 0.00) : sync_plan_position current_position=(0.00, 0.00, 0.00) : sync_plan_position current_position=(0.00, 0.00, 0.00) : > TRIGGER ENDSTOP >>> set_axis_is_at_home(2) For Z axis: home_offset = 0.00 position_shift = 0.00 sw_endstop_min = 0.00 sw_endstop_max = 180.00 > zprobe_zoffset = -1.82 > home_offset[Z] = 0.00 current_position=(0.00, 0.00, 1.82) : <<< set_axis_is_at_home(2) current_position=(0.00, 0.00, 1.82) : sync_plan_position current_position=(0.00, 0.00, 1.82) : > AFTER set_axis_is_at_home > current_position=(0.00, 0.00, 1.82) : set_probe_deployed deploy: 0 do_probe_raise(15.00) do_blocking_move_to(0.00, 0.00, 16.82) do_blocking_move_to(0.00, 0.00, 16.82) <<< homeaxis(2) current_position=(0.00, 0.00, 16.82) : > (home_all_axis || homeZ) > final current_position=(0.00, 0.00, 16.82) : sync_plan_position > endstops.not_homing() current_position=(0.00, 0.00, 16.82) : clean_up_after_endstop_or_probe_move <<< gcode_G28 >>> gcode_G29 current_position=(0.00, 0.00, 16.82) : G29 Auto Bed Leveling corrected_position=(0.00, 0.00, 16.82) : BEFORE matrix.set_to_identity current_position=(0.00, 0.00, 16.82) : BEFORE matrix.set_to_identity uncorrected_position=(0.00, 0.00, 16.82) : AFTER matrix.set_to_identity current_position=(0.00, 0.00, 16.82) : sync_plan_position current_position=(0.00, 0.00, 16.82) : setup_for_endstop_or_probe_move current_position=(0.00, 0.00, 16.82) : set_probe_deployed deploy: 1 do_probe_raise(15.00) do_blocking_move_to(0.00, 0.00, 16.82) do_blocking_move_to(0.00, 0.00, 16.82) >>> probe_pt(30.00, 30.00, 1) current_position=(0.00, 0.00, 16.82) : do_probe_raise(5.00) > do_blocking_move_to_xy(0.00, 30.00) do_blocking_move_to(0.00, 30.00, 16.82) > current_position=(0.00, 30.00, 16.82) : set_probe_deployed deploy: 1 current_position=(0.00, 30.00, 1.83) : run_z_probe current_position=(0.00, 30.00, 1.83) : sync_plan_position > do_probe_raise do_probe_raise(5.00) do_blocking_move_to(0.00, 30.00, 6.82) <<< probe_pt >>> probe_pt(95.00, 30.00, 1) current_position=(0.00, 30.00, 6.82) : do_probe_raise(5.00) > do_blocking_move_to_xy(65.00, 30.00) do_blocking_move_to(65.00, 30.00, 6.82) > current_position=(65.00, 30.00, 6.82) : set_probe_deployed deploy: 1 current_position=(65.00, 30.00, 1.78) : run_z_probe current_position=(65.00, 30.00, 1.78) : sync_plan_position > do_probe_raise do_probe_raise(5.00) do_blocking_move_to(65.00, 30.00, 6.82) <<< probe_pt >>> probe_pt(160.00, 30.00, 1) current_position=(65.00, 30.00, 6.82) : do_probe_raise(5.00) > do_blocking_move_to_xy(130.00, 30.00) do_blocking_move_to(130.00, 30.00, 6.82) > current_position=(130.00, 30.00, 6.82) : set_probe_deployed deploy: 1 current_position=(130.00, 30.00, 1.97) : run_z_probe current_position=(130.00, 30.00, 1.97) : sync_plan_position > do_probe_raise do_probe_raise(5.00) do_blocking_move_to(130.00, 30.00, 6.82) <<< probe_pt >>> probe_pt(160.00, 95.00, 1) current_position=(130.00, 30.00, 6.82) : do_probe_raise(5.00) > do_blocking_move_to_xy(130.00, 95.00) do_blocking_move_to(130.00, 95.00, 6.82) > current_position=(130.00, 95.00, 6.82) : set_probe_deployed deploy: 1 current_position=(130.00, 95.00, 1.92) : run_z_probe current_position=(130.00, 95.00, 1.92) : sync_plan_position > do_probe_raise do_probe_raise(5.00) do_blocking_move_to(130.00, 95.00, 6.82) <<< probe_pt >>> probe_pt(95.00, 95.00, 1) current_position=(130.00, 95.00, 6.82) : do_probe_raise(5.00) > do_blocking_move_to_xy(65.00, 95.00) do_blocking_move_to(65.00, 95.00, 6.82) > current_position=(65.00, 95.00, 6.82) : set_probe_deployed deploy: 1 current_position=(65.00, 95.00, 1.76) : run_z_probe current_position=(65.00, 95.00, 1.76) : sync_plan_position > do_probe_raise do_probe_raise(5.00) do_blocking_move_to(65.00, 95.00, 6.82) <<< probe_pt >>> probe_pt(30.00, 95.00, 1) current_position=(65.00, 95.00, 6.82) : do_probe_raise(5.00) > do_blocking_move_to_xy(0.00, 95.00) do_blocking_move_to(0.00, 95.00, 6.82) > current_position=(0.00, 95.00, 6.82) : set_probe_deployed deploy: 1 current_position=(0.00, 95.00, 1.99) : run_z_probe current_position=(0.00, 95.00, 1.99) : sync_plan_position > do_probe_raise do_probe_raise(5.00) do_blocking_move_to(0.00, 95.00, 6.82) <<< probe_pt >>> probe_pt(30.00, 160.00, 1) current_position=(0.00, 95.00, 6.82) : do_probe_raise(5.00) > do_blocking_move_to_xy(0.00, 160.00) do_blocking_move_to(0.00, 160.00, 6.82) > current_position=(0.00, 160.00, 6.82) : set_probe_deployed deploy: 1 current_position=(0.00, 160.00, 2.03) : run_z_probe current_position=(0.00, 160.00, 2.03) : sync_plan_position > do_probe_raise do_probe_raise(5.00) do_blocking_move_to(0.00, 160.00, 6.82) <<< probe_pt >>> probe_pt(95.00, 160.00, 1) current_position=(0.00, 160.00, 6.82) : do_probe_raise(5.00) > do_blocking_move_to_xy(65.00, 160.00) do_blocking_move_to(65.00, 160.00, 6.82) > current_position=(65.00, 160.00, 6.82) : set_probe_deployed deploy: 1 current_position=(65.00, 160.00, 1.67) : run_z_probe current_position=(65.00, 160.00, 1.67) : sync_plan_position > do_probe_raise do_probe_raise(5.00) do_blocking_move_to(65.00, 160.00, 6.82) <<< probe_pt >>> probe_pt(160.00, 160.00, 1) current_position=(65.00, 160.00, 6.82) : do_probe_raise(5.00) > do_blocking_move_to_xy(130.00, 160.00) do_blocking_move_to(130.00, 160.00, 6.82) > current_position=(130.00, 160.00, 6.82) : set_probe_deployed deploy: 1 current_position=(130.00, 160.00, 1.83) : run_z_probe current_position=(130.00, 160.00, 1.83) : sync_plan_position > do_probe_raise do_probe_raise(5.00) do_blocking_move_to(130.00, 160.00, 6.82) <<< probe_pt current_position=(130.00, 160.00, 6.82) : set_probe_deployed deploy: 0 do_probe_raise(15.00) do_blocking_move_to(130.00, 160.00, 16.82) do_blocking_move_to(130.00, 160.00, 16.82) current_position=(130.00, 160.00, 16.82) : clean_up_after_endstop_or_probe_move current_position=(130.00, 160.00, 16.82) : > probing complete Eqn coefficients: a: -0.00034590 b: -0.00016013 d: 1.91139736 uncorrected_position=(130.00, 160.00, 16.82) : >>> set_bed_level_equation_lsq current_position=(130.00, 160.00, 16.82) : >>> set_bed_level_equation_lsq corrected_position=(129.99, 159.99, 16.89) : <<< set_bed_level_equation_lsq current_position=(129.99, 159.99, 16.89) : sync_plan_position Bed Level Correction Matrix: +1.000000 +0.000000 -0.000346 -0.000000 +1.000000 -0.000160 +0.000346 +0.000160 +1.000000 > BEFORE apply_rotation_xyz > stepper_z = 16.82 ... z_tmp = 16.89 > AFTER apply_rotation_xyz > z_tmp = 16.81 current_position=(129.99, 159.99, 16.88) : sync_plan_position current_position=(129.99, 159.99, 16.88) : > corrected Z in G29 <<< gcode_G29 >>> gcode_T current_position=(129.99, 159.99, 5.00) : BEFORE current_position=(129.99, 159.99, 5.00) : AFTER <<< gcode_T Done printing file echo:enqueueing "M84 X Y Z E" echo:enqueueing "M31" >>> gcode_G28 current_position=(86.70, 102.99, 0.70) : setup_for_endstop_or_probe_move > endstops.enable(true) Raise Z (before homing) to 5.00 do_blocking_move_to(86.70, 102.99, 5.00) >>> homeaxis(0) current_position=(0.00, 102.99, 5.00) : sync_plan_position current_position=(0.00, 102.99, 5.00) : sync_plan_position current_position=(0.00, 102.99, 5.00) : > TRIGGER ENDSTOP >>> set_axis_is_at_home(0) For X axis: home_offset = 0.00 position_shift = 0.00 sw_endstop_min = 0.00 sw_endstop_max = 190.00 > home_offset[X] = 0.00 current_position=(0.00, 102.99, 5.00) : <<< set_axis_is_at_home(0) current_position=(0.00, 102.99, 5.00) : sync_plan_position current_position=(0.00, 102.99, 5.00) : > AFTER set_axis_is_at_home <<< homeaxis(0) current_position=(0.00, 102.99, 5.00) : > homeX current_position=(0.00, 102.99, 5.00) : sync_plan_position > endstops.not_homing() current_position=(0.00, 102.99, 5.00) : clean_up_after_endstop_or_probe_move <<< gcode_G28 echo:Print time 0h 2m 43s ```

The probed points…

current_position=(  0.00,  30.00, 1.84) : run_z_probe
current_position=( 65.00,  30.00, 1.77) : run_z_probe
current_position=(130.00,  30.00, 1.96) : run_z_probe
current_position=(130.00,  95.00, 1.91) : run_z_probe
current_position=( 65.00,  95.00, 1.75) : run_z_probe
current_position=(  0.00,  95.00, 2.00) : run_z_probe
current_position=(  0.00, 160.00, 2.02) : run_z_probe
current_position=( 65.00, 160.00, 1.64) : run_z_probe
current_position=(130.00, 160.00, 1.82) : run_z_probe

AnHardt commented 8 years ago

All i wanted to say is: " If we do not see a difference in current_position that does not mean there is no shift. It could be in the stepper system."

How are these collapsible logs made? Beautiful!

jbrazio commented 8 years ago

You do something like

<details><summary>title</summary>
log
log
log
</details>

thinkyhead commented 8 years ago

that does not mean there is no shift.

How many ways can the current_position get out of sync with the planner/stepper position?

If current_position is set, but no call to:
- some function that tells the planner to move to current_position
- some function that updates/fixes current_position, with or without a move
- sync_plan_position (or planner.set_position_mm)
If planner/steppers are moved in some way that current_position is not updated.
... ?

AnHardt commented 8 years ago

If we have a unexpected hardware endstop hit on deltas.
If

          offset_vec.apply_rotation(planner.bed_level_matrix.transpose(planner.bed_level_matrix));

          // Adjustments to the current position
          float xydiff[2] = { offset_vec.x, offset_vec.y };
          current_position[Z_AXIS] += offset_vec.z;

does not do what we expect. (where a shift of several mm is unlikely.)

thinkyhead commented 8 years ago

Well, the leveling matrix shown by that log does look a little irregular (1.64 low, 2.02 high). Could it be throwing off X and Y by very much?

a shift of several mm is unlikely

I suppose so!

MarlinFirmware / Marlin

After stopping a print, new print shifts #3899

3939 is great, completely logic in it selves and will improve the shift a lot.