Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

It looks like the Debug out put is all scrambled... #4263

Closed
lrpirlet opened this issue Jul 10, 2016 · 8 comments
Closed

It looks like the Debug out put is all scrambled... #4263

lrpirlet opened this issue Jul 10, 2016 · 8 comments

Comments

@lrpirlet
Copy link
Contributor

I used the latest RCBugFix... I just moved my Configuration.H and Configuration_adv.h from my MMBL_2_LRP branch https://github.com/lrpirlet/Marlin.git

Here is the output of G28...

@thinkyhead
Do you know if any of the #defined macros related to debug or to printing on the console did change recently??

22:43:45.491 : ok
22:43:59.055 : N17 M111 S255*85
22:43:59.055 : echo:DEBUG:ECHO,INFO,ERRORS,DRYRUN,COMMUNICATION,LEVELING
22:43:59.055 : ok
22:44:09.588 : N22 M113 S60*101
22:44:09.588 : echo:N22 M113 S60*101
22:44:09.588 : ok
22:44:15.979 : N25 G28*36
22:44:15.979 : echo:N25 G28*36
22:44:15.979 : >>> gcode_G28
22:44:15.979 : setup_for_endstop_or_probe_move(0.00, 0.00, 0.00)
22:44:15.995 : > current_position> endstops.enable(true)
22:44:15.995 : Raise Z (before homing) to 3.00
22:44:18.167 : >>> homeaxis(0)
22:44:18.167 : sync_plan_position(0.00, 0.00, 3.00)
22:44:18.182 : > current_positionsync_plan_position(0.00, 0.00, 3.00)
22:44:18.792 : > current_position> TRIGGER ENDSTOP(0.00, 0.00, 3.00)
22:44:18.792 : > current_position>>> set_axis_is_at_home(0)
22:44:18.792 : > home_offset[axis]==0.00(0.00, 0.00, 3.00)
22:44:18.807 : > current_position<<< set_axis_is_at_home(0)
22:44:18.807 : sync_plan_position(0.00, 0.00, 3.00)
22:44:18.807 : > current_position> AFTER set_axis_is_at_home(0.00, 0.00, 3.00)
22:44:18.807 : > current_position<<< homeaxis(0)
22:44:18.823 : > homeX(0.00, 0.00, 3.00)
22:44:18.823 : > current_position>>> homeaxis(1)
22:44:18.823 : sync_plan_position(0.00, 0.00, 3.00)
22:44:18.839 : > current_positionsync_plan_position(0.00, 0.00, 3.00)
22:44:19.511 : > current_position> TRIGGER ENDSTOP(0.00, 0.00, 3.00)
22:44:19.511 : > current_position>>> set_axis_is_at_home(1)
22:44:19.511 : > home_offset[axis]==0.00(0.00, 0.00, 3.00)
22:44:19.511 : > current_position<<< set_axis_is_at_home(1)
22:44:19.526 : sync_plan_position(0.00, 0.00, 3.00)
22:44:19.526 : > current_position> AFTER set_axis_is_at_home(0.00, 0.00, 3.00)
22:44:19.526 : > current_position<<< homeaxis(1)
22:44:19.526 : > homeY(0.00, 0.00, 3.00)
22:44:19.526 : > current_position>>> homeaxis(2)
22:44:19.542 : > set_probe_deployed(0.00, 0.00, 3.00)
22:44:19.542 : > current_positiondeploy: 1do_probe_raise(5.00)
22:44:19.542 : (0.00, 0.00, 9.33)
22:44:24.386 : do_blocking_move_to(0.00, 0.00, 9.33)
22:44:24.386 : do_blocking_move_tosync_plan_position(0.00, 0.00, 0.00)
22:44:34.653 : > current_positionsync_plan_position(0.00, 0.00, 0.00)
22:44:41.872 : > current_position> TRIGGER ENDSTOP(0.00, 0.00, 0.00)
22:44:41.872 : > current_position>>> set_axis_is_at_home(2)
22:44:41.872 : > zprobe_zoffset==-4.33
22:44:41.888 : > home_offset[axis]==0.00(0.00, 0.00, 4.33)
22:44:41.888 : > current_position<<< set_axis_is_at_home(2)
22:44:41.888 : sync_plan_position(0.00, 0.00, 4.33)
22:44:41.888 : > current_position> AFTER set_axis_is_at_home(0.00, 0.00, 4.33)
22:44:41.904 : > current_position> set_probe_deployed(0.00, 0.00, 4.33)
22:44:41.904 : > current_positiondeploy: 0do_probe_raise(5.00)
22:44:41.904 : (0.00, 0.00, 9.33)
22:44:45.810 : do_blocking_move_to(0.00, 0.00, 9.33)
22:44:45.810 : do_blocking_move_to<<< homeaxis(2)
22:44:45.810 : > (home_all_axis || homeZ) > final(0.00, 0.00, 9.33)
22:44:45.826 : > current_positionsync_plan_position(0.00, 0.00, 9.33)
22:44:45.826 : > current_position> endstops.not_homing()
22:44:45.826 : clean_up_after_endstop_or_probe_move(0.00, 0.00, 9.33)
22:44:45.826 : > current_position<<< gcode_G28
22:44:45.842 : X:0.00 Y:0.00 Z:9.33 E:0.00 Count X: 0 Y:0 Z:37320
22:44:45.842 : ok
@Blue-Marlin
Copy link
Contributor

Blue-Marlin commented Jul 10, 2016

@@ -572,15 +572,15 @@ void serial_echopair_P(const char* s_P, unsigned long v) { serialprintPGM(s_P);

 static void report_current_position();

 #if ENABLED(DEBUG_LEVELING_FEATURE)
   void print_xyz(const char* suffix, const float x, const float y, const float z) {
+    SERIAL_ECHO(suffix);
     SERIAL_ECHOPAIR("(", x);
     SERIAL_ECHOPAIR(", ", y);
     SERIAL_ECHOPAIR(", ", z);
     SERIAL_ECHOLNPGM(") ");
-    SERIAL_ECHO(suffix);
   }
   void print_xyz(const char* suffix, const float xyz[]) {
     print_xyz(suffix, xyz[X_AXIS], xyz[Y_AXIS], xyz[Z_AXIS]);
   }
   #if ENABLED(AUTO_BED_LEVELING_FEATURE)
@@ -1963,10 +1963,11 @@ static void clean_up_after_endstop_or_probe_move() {

     #if ENABLED(DEBUG_LEVELING_FEATURE)
       if (DEBUGGING(LEVELING)) {
         DEBUG_POS("set_probe_deployed", current_position);
         SERIAL_ECHOPAIR("deploy: ", deploy);
+        SERIAL_EOL;
       }
     #endif

     if (endstops.z_probe_enabled == deploy) return false;

is looking a lot nicer.
Where suffix is now a suffix to the previous text but a prefix to the array.

@Blue-Marlin
Copy link
Contributor

Blue-Marlin commented Jul 10, 2016

Even better is

@@ -572,18 +572,25 @@ void serial_echopair_P(const char* s_P, unsigned long v) { serialprintPGM(s_P);

 static void report_current_position();

 #if ENABLED(DEBUG_LEVELING_FEATURE)
   void print_xyz(const char* suffix, const float x, const float y, const float z) {
+    SERIAL_ECHO(suffix);
     SERIAL_ECHOPAIR("(", x);
     SERIAL_ECHOPAIR(", ", y);
     SERIAL_ECHOPAIR(", ", z);
     SERIAL_ECHOLNPGM(") ");
-    SERIAL_ECHO(suffix);
   }
   void print_xyz(const char* suffix, const float xyz[]) {
-    print_xyz(suffix, xyz[X_AXIS], xyz[Y_AXIS], xyz[Z_AXIS]);
+    if (xyz[X_AXIS] == current_position[X_AXIS] && xyz[Y_AXIS] == current_position[Y_AXIS] && xyz[Z_AXIS] == current_position[Z_AXIS]) {
+      SERIAL_ECHO(suffix);
+      SERIAL_ECHOPGM(" > ");
+      report_current_position();
+    }
+    else {
+      print_xyz(suffix, xyz[X_AXIS], xyz[Y_AXIS], xyz[Z_AXIS]);
+    }
   }
   #if ENABLED(AUTO_BED_LEVELING_FEATURE)
     void print_xyz(const char* suffix, const vector_3 &xyz) {
       print_xyz(suffix, xyz.x, xyz.y, xyz.z);
     }
@@ -1963,10 +1970,11 @@ static void clean_up_after_endstop_or_probe_move() {

     #if ENABLED(DEBUG_LEVELING_FEATURE)
       if (DEBUGGING(LEVELING)) {
         DEBUG_POS("set_probe_deployed", current_position);
         SERIAL_ECHOPAIR("deploy: ", deploy);
+        SERIAL_EOL;
       }
     #endif

     if (endstops.z_probe_enabled == deploy) return false;

A bit complicated but exactly what we are looking for when debugging the stepper coordinate system.

@thinkyhead
Copy link
Member

thinkyhead commented Jul 11, 2016

Recently I changed the debug output so it would show the coordinates first and the given text as a suffix. This makes it easier to see coordinates in comparison to each other. If the text is used as a prefix, the coordinates are staggered, making them harder to compare.

@thinkyhead
Copy link
Member

thinkyhead commented Jul 11, 2016

- if (xyz[X_AXIS] == current_position[X_AXIS] && xyz[Y_AXIS] == current_position[Y_AXIS] && xyz[Z_AXIS] == current_position[Z_AXIS])
+ if (xyz == current_position) { // should work

Cool: Since report_current_position updates the host's current position, this allows you to debug coordinates by watching the Octoprint screen or host control panel.

@lrpirlet
Copy link
Contributor Author

Thanks a lot, this looks a lot better... I will prepare a patch.

@thinkyhead Please give @Blue-Marlin and yourself due recognition on that patch.

BTW, is void print_xyz an example of a CPP function that produce a different result depending on the data type?

15:16:33.977 : N25 M111 S255*84
15:16:33.977 : echo:DEBUG:ECHO,INFO,ERRORS,DRYRUN,COMMUNICATION,LEVELING
15:16:33.977 : ok
15:16:39.415 : N28 M113 S60*111
15:16:39.415 : echo:N28 M113 S60*111
15:16:39.415 : ok
15:16:49.119 : N32 G28*34
15:16:49.119 : echo:N32 G28*34
15:16:49.119 : >>> gcode_G28
15:16:49.135 : setup_for_endstop_or_probe_move > current_position > X:0.00 Y:0.00 Z:0.00 E:0.00 Count X: 0 Y:0 Z:0
15:16:49.135 : > endstops.enable(true)
15:16:49.135 : Raise Z (before homing) to 3.00
15:16:51.307 : >>> homeaxis(0)
15:16:51.307 : sync_plan_position > current_position > X:0.00 Y:0.00 Z:3.00 E:0.00 Count X: 0 Y:0 Z:12000
15:16:51.323 : sync_plan_position > current_position > X:0.00 Y:0.00 Z:3.00 E:0.00 Count X: -2 Y:0 Z:12000
15:16:51.963 : > TRIGGER ENDSTOP > current_position > X:0.00 Y:0.00 Z:3.00 E:0.00 Count X: 3 Y:0 Z:12000
15:16:51.963 : >>> set_axis_is_at_home(0)
15:16:51.963 : > home_offset[axis]==0.00 > current_position > X:0.00 Y:0.00 Z:3.00 E:0.00 Count X: 3 Y:0 Z:12000
15:16:51.963 : <<< set_axis_is_at_home(0)
15:16:51.979 : sync_plan_position > current_position > X:0.00 Y:0.00 Z:3.00 E:0.00 Count X: 3 Y:0 Z:12000
15:16:51.979 : > AFTER set_axis_is_at_home > current_position > X:0.00 Y:0.00 Z:3.00 E:0.00 Count X: 0 Y:0 Z:12000
15:16:51.979 : <<< homeaxis(0)
15:16:51.994 : > homeX > current_position > X:0.00 Y:0.00 Z:3.00 E:0.00 Count X: 0 Y:0 Z:12000
15:16:51.994 : >>> homeaxis(1)
15:16:52.010 : sync_plan_position > current_position > X:0.00 Y:0.00 Z:3.00 E:0.00 Count X: 0 Y:0 Z:12000
15:16:52.010 : sync_plan_position > current_position > X:0.00 Y:0.00 Z:3.00 E:0.00 Count X: 0 Y:-2 Z:12000
15:16:52.635 : > TRIGGER ENDSTOP > current_position > X:0.00 Y:0.00 Z:3.00 E:0.00 Count X: 0 Y:3 Z:12000
15:16:52.635 : >>> set_axis_is_at_home(1)
15:16:52.635 : > home_offset[axis]==0.00 > current_position > X:0.00 Y:0.00 Z:3.00 E:0.00 Count X: 0 Y:3 Z:12000
15:16:52.651 : <<< set_axis_is_at_home(1)
15:16:52.651 : sync_plan_position > current_position > X:0.00 Y:0.00 Z:3.00 E:0.00 Count X: 0 Y:3 Z:12000
15:16:52.666 : > AFTER set_axis_is_at_home > current_position > X:0.00 Y:0.00 Z:3.00 E:0.00 Count X: 0 Y:0 Z:12000
15:16:52.666 : <<< homeaxis(1)
15:16:52.666 : > homeY > current_position > X:0.00 Y:0.00 Z:3.00 E:0.00 Count X: 0 Y:0 Z:12000
15:16:52.666 : >>> homeaxis(2)
15:16:52.682 : > set_probe_deployed > current_position > X:0.00 Y:0.00 Z:3.00 E:0.00 Count X: 0 Y:0 Z:12000
15:16:52.682 : deploy: 1
15:16:52.682 : do_probe_raise(5.00)
15:16:52.682 : do_blocking_move_to(0.00, 0.00, 9.33)
15:16:57.526 : do_blocking_move_to(0.00, 0.00, 9.33)
15:16:57.526 : sync_plan_position > current_position > X:0.00 Y:0.00 Z:0.00 E:0.00 Count X: 0 Y:0 Z:37320
15:17:07.793 : sync_plan_position > current_position > X:0.00 Y:0.00 Z:0.00 E:0.00 Count X: 0 Y:0 Z:-57236
15:17:14.981 : > TRIGGER ENDSTOP > current_position > X:0.00 Y:0.00 Z:0.00 E:0.00 Count X: 0 Y:0 Z:-30
15:17:14.981 : >>> set_axis_is_at_home(2)
15:17:14.981 : > zprobe_zoffset==-4.33
15:17:14.997 : > home_offset[axis]==0.00 > current_position > X:0.00 Y:0.00 Z:4.33 E:0.00 Count X: 0 Y:0 Z:-30
15:17:14.997 : <<< set_axis_is_at_home(2)
15:17:14.997 : sync_plan_position > current_position > X:0.00 Y:0.00 Z:4.33 E:0.00 Count X: 0 Y:0 Z:-30
15:17:15.013 : > AFTER set_axis_is_at_home > current_position > X:0.00 Y:0.00 Z:4.33 E:0.00 Count X: 0 Y:0 Z:17320
15:17:15.013 : > set_probe_deployed > current_position > X:0.00 Y:0.00 Z:4.33 E:0.00 Count X: 0 Y:0 Z:17320
15:17:15.013 : deploy: 0
15:17:15.028 : do_probe_raise(5.00)
15:17:15.028 : do_blocking_move_to(0.00, 0.00, 9.33)
15:17:18.935 : do_blocking_move_to(0.00, 0.00, 9.33)
15:17:18.935 : <<< homeaxis(2)
15:17:18.935 : > (home_all_axis || homeZ) > final > current_position > X:0.00 Y:0.00 Z:9.33 E:0.00 Count X: 0 Y:0 Z:37320
15:17:18.950 : sync_plan_position > current_position > X:0.00 Y:0.00 Z:9.33 E:0.00 Count X: 0 Y:0 Z:37320
15:17:18.950 : > endstops.not_homing()
15:17:18.966 : clean_up_after_endstop_or_probe_move > current_position > X:0.00 Y:0.00 Z:9.33 E:0.00 Count X: 0 Y:0 Z:37320
15:17:18.966 : <<< gcode_G28
15:17:18.966 : X:0.00 Y:0.00 Z:9.33 E:0.00 Count X: 0 Y:0 Z:37320
15:17:18.966 : ok

@jbrazio
Copy link
Contributor

jbrazio commented Jul 11, 2016

Closed by #4269

@jbrazio jbrazio closed this as completed Jul 11, 2016
@thinkyhead
Copy link
Member

thinkyhead commented Jul 12, 2016

Is print_xyz an example of a CPP function that produce a different result depending on the data type?

Yes. C++, in essence, allows you to give two functions the same name as long as the arguments differ. And it figures out which one you mean by the arguments in the call. "Polymorphism."

@github-actions
Copy link

github-actions bot commented Apr 7, 2022

This issue has been automatically locked since there has not been any recent activity after it was closed. Please open a new issue for related bugs.

@github-actions github-actions bot locked and limited conversation to collaborators Apr 7, 2022
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
None yet
Projects
None yet
Development

No branches or pull requests

4 participants