Very weird partial missing output when running G35 #1103

duk3luk3 · 2020-09-06T05:15:21Z

Printrun version: 2.0.0rc6 / master ff056a0

Printer firmware: Customized Marlin branched off of bugfix-2.x.0 / e492c613f7698c82adc5d2317e4b1247536f42fa

I am using the G35 command: https://marlinfw.org/docs/gcode/G035.html which I have customized quite a bit but mainly to add debug printing and debug this issue.

Pronterface appears to be swallowing the "Clockwise" / "Counter-Clockwise" line occasionally. In the base Marlin code, where it is all printed on one line, the line seems to only appear when it says "Clockwise", if it says (should say) "Counter-Clockwise" it appears to be swallowed whole.

Output from minicom - Good

Probing point 0 (Front-Left) X19.00 Y21.00 Z-0.05375
echo:busy: processing
Probing point 1 (Front-Right) X190.00 Y21.00 Z-0.24500
Probing point 2 (Back-Right) X190.00 Y195.00 Z-0.25625
echo:busy: processing
Probing point 3 (Back-Left) X19.00 Y195.00 Z-0.23375
Evaluating Front-Right
Evaluated Front-Right: diff = 0.19125; adjust = 0.27321
Turn Front-Right
 Clockwise
 by 0 turns
 and 16 minutes (98 degrees)
Done Front-Right
Evaluating Back-Right
Evaluated Back-Right: diff = 0.20250; adjust = 0.28929
Turn Back-Right
 Clockwise
 by 0 turns
 and 17 minutes (104 degrees)
Done Back-Right
Evaluating Back-Left
Evaluated Back-Left: diff = 0.18000; adjust = 0.25714
Turn Back-Left
 Clockwise
 by 0 turns
 and 15 minutes (92 degrees)
Done Back-Left
ok

Output from pronterface - bad

>>> G35 V2 Z0 S40
SENDING:G35 V2 Z0 S40
Probing point 0 (Front-Left) X19.00 Y21.00 Z-0.23062
Probing point 1 (Front-Right) X190.00 Y21.00 Z-0.22187
Probing point 2 (Back-Right) X190.00 Y195.00 Z-0.24687
Probing point 3 (Back-Left) X19.00 Y195.00 Z-0.22937
Evaluating Front-Right
Evaluated Front-Right: diff = -0.00875; adjust = -0.01250
Turn Front-Right
 by 0 turns
 and 0 minutes (4 degrees)
Done Front-Right
Evaluating Back-Right
Evaluated Back-Right: diff = 0.01625; adjust = 0.02321
Turn Back-Right
 Clockwise
 by 0 turns
 and 1 minutes (8 degrees)
Done Back-Right
Evaluating Back-Left
Evaluated Back-Left: diff = -0.00125; adjust = -0.00179
Turn Back-Left
 by 0 turns
Done Back-Left

pronsole - bad

(venv) erlacher@laprbg12 Printrun(master|✔) % ./pronsole.py                                                                                                                                                             ~/git/printos/Printrun
WARNING:root:Memory-efficient GCoder implementation unavailable: cannot import name 'gcoder_line' from 'printrun' (/home/erlacher/git/printos/Printrun/printrun/__init__.py)
WARNING:root:Could not setup DBus for sleep inhibition: org.freedesktop.DBus.Error.ServiceUnknown: The name org.freedesktop.ScreenSaver was not provided by any .service files
*** Unknown syntax: button 0 "LF" G0 X19 Y21 Z5
*** Unknown syntax: button 1 "RF" G0 X190 Y21 Z5
*** Unknown syntax: button 2 "RB" G0 X190 Y195 Z5
*** Unknown syntax: button 3 "LB" G0 X19 Y195 Z5
*** Unknown syntax: button 4 "M48 P4" M48 P4 V4
*** Unknown syntax: button 5 "G28 (Level)" G28
Welcome to the printer console! Type "help" for a list of available commands.
offline> help

Documented commands (type help <topic>):
========================================
bedtemp             exit     home     move   resume            set      upload
block_until_online  extrude  load     off    reverse           settemp
connect             gcodes   ls       pause  run_gcode_script  shell  
disconnect          gettemp  macro    print  run_script        slice  
eta                 help     monitor  reset  sdprint           tool   

Undocumented commands:
======================
extrude_final

offline> connect
No port specified - connecting to /dev/ttyACM0 at 250000bps
Printer is now online
ttyACM0 20°> G28
SENDING:G28
ttyACM0 20°> G35
SENDING:G35
Evaluating Front-Right
Evaluated Front-Right: diff = -0.01937; adjust = -0.03875
Turn Front-Right
 by 0 turns    
 and 2 minutes (13 degrees)
Done Front-Right
Evaluating Back-Right
Evaluated Back-Right: diff = -0.00500; adjust = -0.01000
Turn Back-Right
 by 0 turns    
 and 0 minutes (3 degrees)
Done Back-Right
Evaluating Back-Left
Evaluated Back-Left: diff = -0.02125; adjust = -0.04250
Turn Back-Left 
 by 0 turns    
 and 2 minutes (15 degrees)
Done Back-Left

With debug communications enabled it works:

>>> G35 V2 Z0 S40
SENT: G35 V2 Z0 S40
RECV: Probing point 0 (Front-Left) X19.00 Y21.00 Z-0.21937
RECV: echo:busy: processing
RECV: Probing point 1 (Front-Right) X190.00 Y21.00 Z-0.21437
RECV: Probing point 2 (Back-Right) X190.00 Y195.00 Z-0.22250
RECV: echo:busy: processing
RECV: Probing point 3 (Back-Left) X19.00 Y195.00 Z-0.22437
RECV: Evaluating Front-Right
RECV: Evaluated Front-Right: diff = -0.00500; adjust = -0.00714
RECV: Turn Front-Right
RECV:  Counter-Clockwise
RECV:  by 0 turns
RECV:  and 0 minutes (2 degrees)
RECV: Done Front-Right
RECV: Evaluating Back-Right
RECV: Evaluated Back-Right: diff = 0.00312; adjust = 0.00446
RECV: Turn Back-Right
RECV:  Clockwise
RECV:  by 0 turns
RECV:  and 0 minutes (1 degrees)
RECV: Done Back-Right
RECV: Evaluating Back-Left
RECV: Evaluated Back-Left: diff = 0.00500; adjust = 0.00714
RECV: Turn Back-Left
RECV:  Clockwise
RECV:  by 0 turns
RECV:  and 0 minutes (2 degrees)
RECV: Done Back-Left
RECV: ok

The text was updated successfully, but these errors were encountered:

duk3luk3 · 2020-09-06T05:44:04Z

It appears to suppress any line that contains the string "Count" - Code:

        SERIAL_ECHOLNPGM(" Counter-Clockwise");
        SERIAL_ECHOLNPGM(" Counter-");
        SERIAL_ECHOLNPGM(" Counter");
        SERIAL_ECHOLNPGM(" Count");
        SERIAL_ECHOLNPGM(" Coun ter-Clockwise");
        SERIAL_ECHOLNPGM(" Coun ter-");
        SERIAL_ECHOLNPGM(" Coun ter");
        SERIAL_ECHOLNPGM(" Count");
        SERIAL_ECHOLNPGM(" Cou");
        SERIAL_ECHOLNPGM(" C");
        SERIAL_ECHOLNPGM(" ");
      } else {

Output:

 Coun ter-Clockwise
 Coun ter-     
 Coun ter      
 Cou           
 C

EDIT: Going to take a guess the problem is here: https://github.com/kliment/Printrun/blob/master/printrun/pronsole.py#L1295

ellensp · 2020-09-06T06:06:56Z

Count is a keyword used in M114 output.

duk3luk3 · 2020-09-06T06:26:28Z

Yeah, so does this mean outputting "Count" in commands other than M114 is an issue, or does it mean the parsing in pronterface needs to be refined?

Does Marlin define "reserved keywords" in output?

kliment · 2020-09-06T06:39:52Z

I think the "Count" is meant to detect "Extruder Count" so we can probably refine it. Can you check what M114's output is (as emitted by firmware) on your system?

duk3luk3 · 2020-09-06T07:00:37Z

This is the Marlin M114 implementation: https://github.com/MarlinFirmware/Marlin/blob/2.0.x/Marlin/src/gcode/host/M114.cpp

Looks to be pretty complicated and not immediately obvious where this branches off to.

This is the output from my machine, captured using minicom:

M114                                                                                         
X:-10.00 Y:-13.00 Z:0.00 E:0.00 Count X:-800 Y:-1040 Z:0

Maybe matching for " Count " with surrounding spaces would work better?

kliment · 2020-09-06T07:04:35Z

Excellent idea - can you try it out on your setup and verify it works correctly?

Any line containing "Count" is being detected as M114 output, so for example any string containing the word "Counter-Clockwise" gets swallowed. By changing the test to ``" Count "`` this should be improved. Fixes kliment#1103

duk3luk3 · 2020-09-06T07:51:31Z

Testing #1104, G35 looks good in pronsole:

ttyACM0 20°> G35
SENDING:G35
Evaluating Front-Right
Evaluated Front-Right: diff = 0.01813; adjust = 0.03625
Turn Front-Right
 Clockwise     
 by 0 turns    
 and 2 minutes (13 degrees)
Done Front-Right
Evaluating Back-Right
Evaluated Back-Right: diff = 0.13125; adjust = 0.26250
Turn Back-Right
 Clockwise     
 by 0 turns    
 and 15 minutes (94 degrees)
Done Back-Right
Evaluating Back-Left
Evaluated Back-Left: diff = -0.00688; adjust = -0.01375
Turn Back-Left 
 Counter-Clockwise
 Counter-      
 Counter       
 Count         
 Coun ter-Clockwise
 Coun ter-     
 Coun ter      
 Count         
 Cou           
 C             
               
 by 0 turns    
 and 0 minutes (4 degrees)
Done Back-Left

I can't test M114 detection with a real print (monitoring) right now, so I added a little hack to the recvcb (See "DEBUG PRINT" comment):

    def recvcb(self, l):
        l = l.rstrip()
        for listener in self.recvlisteners:
            listener(l)
        if not self.recvcb_actions(l):
            report_type = self.recvcb_report(l)
            if report_type & REPORT_TEMP:
                self.status.update_tempreading(l)
            if not self.lineignorepattern.match(l) and l[:4] != "wait" and not self.sdlisting \
               and not self.monitoring and (report_type == REPORT_NONE or report_type & REPORT_MANUAL):
                if (report_type & REPORT_MANUAL):
                    self.log("\r" + 'REPORT_MANUAL') # <= DEBUG PRINT
                if l[:5] == "echo:":
                    l = l[5:].lstrip()
                if self.silent is False: self.log("\r" + l.ljust(15))
                sys.stdout.write(self.promptf())
                sys.stdout.flush()

And this prints as expected:

ttyACM0 20°> M114
SENDING:M114
REPORT_MANUAL
X:110.00 Y:110.00 Z:8.00 E:0.00 Count X:8800 Y:8800 Z:12800

duk3luk3 · 2020-09-06T08:09:51Z

I have raised a Marlin issue to discuss the broader issue of Marlin realtime output being hard to parse: MarlinFirmware/Marlin#19272

duk3luk3 mentioned this issue Sep 6, 2020

Fix 1103: Make M114 "Count" detection more specific #1104

Merged

duk3luk3 mentioned this issue Sep 6, 2020

[BUG] M114 (and other realtime commands) are hard and ambiguous to detect & parse MarlinFirmware/Marlin#19272

Closed

kliment closed this as completed in #1104 Sep 6, 2020

This was referenced Oct 7, 2020

[FIX] G35 Serial output (change counter to anti) MarlinFirmware/Marlin#19577

Merged

[BUG] Assisted tramming text issue MarlinFirmware/Marlin#19555

Closed

qwewer0 mentioned this issue Dec 29, 2020

G35 assisted tramming improvements MarlinFirmware/Marlin#20298

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Very weird partial missing output when running G35 #1103

Very weird partial missing output when running G35 #1103

duk3luk3 commented Sep 6, 2020 •

edited

Loading

duk3luk3 commented Sep 6, 2020 •

edited

Loading

ellensp commented Sep 6, 2020

duk3luk3 commented Sep 6, 2020 •

edited

Loading

kliment commented Sep 6, 2020

duk3luk3 commented Sep 6, 2020 •

edited

Loading

kliment commented Sep 6, 2020

duk3luk3 commented Sep 6, 2020

duk3luk3 commented Sep 6, 2020

Very weird partial missing output when running G35 #1103

Very weird partial missing output when running G35 #1103

Comments

duk3luk3 commented Sep 6, 2020 • edited Loading

duk3luk3 commented Sep 6, 2020 • edited Loading

ellensp commented Sep 6, 2020

duk3luk3 commented Sep 6, 2020 • edited Loading

kliment commented Sep 6, 2020

duk3luk3 commented Sep 6, 2020 • edited Loading

kliment commented Sep 6, 2020

duk3luk3 commented Sep 6, 2020

duk3luk3 commented Sep 6, 2020

duk3luk3 commented Sep 6, 2020 •

edited

Loading

duk3luk3 commented Sep 6, 2020 •

edited

Loading

duk3luk3 commented Sep 6, 2020 •

edited

Loading

duk3luk3 commented Sep 6, 2020 •

edited

Loading