MarginallyClever / Makelangelo-software

Software for plotters - especially the wall-hanging polargraph also called Makelangelo.
http://www.marginallyclever.com/
GNU General Public License v2.0
350 stars 177 forks source link

Open and close connection: popup error #479

Closed coliss86 closed 2 years ago

coliss86 commented 2 years ago

Steps to make the bug happen

  1. Start Makelangelo
  2. Go to the plotter controls, connect to the robot and home it => everything works fine
  3. Close the plotter controls
  4. Load a SVG
  5. Open the plotter controls
  6. Home it, the following dialog is displayed: image After then, the robot do not respond to anything

What was supposed to happen No Error

Platform (please complete the following information):

Log file I have removed the svg parsing from the log

2022-01-26 14:39:16,288 DEBUG c.m.makelangelo.Translator - starting translator... 
2022-01-26 14:39:16,296 DEBUG c.m.makelangelo.Translator - Default language = English 
2022-01-26 14:39:16,367 DEBUG c.m.makelangelo.Translator - loadConfig: User Preference Node: /DrawBot/Language=English 
2022-01-26 14:39:16,668 DEBUG c.m.makelangelo.paper.Paper - loadConfig() before Paper Width = 420.00 Height = 594.00 (left=-210.00 right=210.00 top=297.00 bottom=-297.00) centerShift(X= 0.00 Y= 0.00) color (255,255,255) 
2022-01-26 14:39:16,669 DEBUG c.m.makelangelo.paper.Paper - loadConfig() after Paper Width = 210.00 Height = 297.00 (left=-105.00 right=105.00 top=148.50 bottom=-148.50) centerShift(X= 0.00 Y= 0.00) color (255,255,255) 
2022-01-26 14:39:17,672 DEBUG c.m.makelangelo.Makelangelo - Locale=en_GB 
2022-01-26 14:39:17,672 DEBUG c.m.makelangelo.Makelangelo - Headless=N 
2022-01-26 14:39:17,672 DEBUG c.m.util.PropertiesFileHelper - makelangelo.version=7.31.0 
2022-01-26 14:39:17,675 DEBUG c.m.makelangelo.Makelangelo - machine style: MAKELANGELO_CUSTOM 
2022-01-26 14:39:17,688 DEBUG c.m.makelangelo.Makelangelo - Starting robot... 
2022-01-26 14:39:17,690 DEBUG c.m.makelangelo.Makelangelo - Starting virtual camera... 
2022-01-26 14:39:17,690 DEBUG c.m.makelangelo.Makelangelo - Creating GUI... 
2022-01-26 14:39:17,696 DEBUG c.m.makelangelo.Makelangelo -   adding menu bar... 
2022-01-26 14:39:17,703 DEBUG c.m.makelangelo.RecentFiles - loading recent files 
2022-01-26 14:39:17,739 DEBUG c.m.makelangelo.Makelangelo - Raspistill unavailable. 
2022-01-26 14:39:17,752 DEBUG c.m.makelangelo.Makelangelo - create content pane... 
2022-01-26 14:39:17,752 DEBUG c.m.makelangelo.Makelangelo -   create PreviewPanel... 
2022-01-26 14:39:18,890 DEBUG c.m.m.preview.PreviewPanel -   get GL capabilities... 
2022-01-26 14:39:18,892 DEBUG c.m.m.preview.PreviewPanel -   starting animator... 
2022-01-26 14:39:18,895 DEBUG c.m.makelangelo.Makelangelo -   create range slider... 
2022-01-26 14:39:18,898 DEBUG c.m.makelangelo.Makelangelo -   make visible... 
2022-01-26 14:39:19,006 DEBUG c.m.makelangelo.Makelangelo - adjust window size... 
2022-01-26 14:39:19,006 DEBUG c.m.makelangelo.Makelangelo - adding drag & drop support... 
2022-01-26 14:39:24,274 DEBUG c.m.c.NetworkSessionUIManager - Fetching connections 
2022-01-26 14:39:24,274 DEBUG c.m.c.NetworkSessionUIManager -   USB Serial 
2022-01-26 14:39:24,332 DEBUG c.m.c.NetworkSessionUIManager -     /dev/cu.Bluetooth-Incoming-Port 
2022-01-26 14:39:24,332 DEBUG c.m.c.NetworkSessionUIManager -     /dev/cu.DRAWBOT-Port 
2022-01-26 14:39:24,332 DEBUG c.m.c.NetworkSessionUIManager -     /dev/cu.SRS-XB33-BluetoothSeria 
2022-01-26 14:41:04,827 DEBUG c.m.m.p.p.ChooseConnection - onConnectAction() 
2022-01-26 14:41:07,826 DEBUG c.m.m.p.p.ChooseConnection - open to /dev/cu.DRAWBOT-Port 
2022-01-26 14:41:07,828 DEBUG c.m.m.p.p.MarlinInterface - MarlinInterface connected. 
2022-01-26 14:41:09,608 TRACE c.m.m.p.p.MarlinInterface - sending 'N1 M280 P0 S90 T50*99' 
2022-01-26 14:41:09,610 TRACE c.m.m.p.p.MarlinInterface - sending 'N2 G28 XY*48' 
2022-01-26 14:41:10,292 TRACE c.m.m.p.p.MarlinInterface - received 'ok' 
2022-01-26 14:41:12,020 TRACE c.m.m.p.p.MarlinInterface - received 'X:0.00 Y:-186.00 Z:200.00 Count X:72290 Y:72290 Z:32000' 
2022-01-26 14:41:12,021 TRACE c.m.m.p.p.MarlinInterface - sending 'N3 G0 X0.000 Y-186.000*9' 
2022-01-26 14:41:12,021 TRACE c.m.m.p.p.MarlinInterface - received 'ok' 
2022-01-26 14:41:12,030 TRACE c.m.m.p.p.MarlinInterface - received 'ok' 
2022-01-26 14:41:14,751 DEBUG c.m.m.p.p.ChooseConnection - onConnectAction() 
2022-01-26 14:41:14,751 DEBUG c.m.m.p.p.ChooseConnection - closed 
2022-01-26 14:41:15,362 DEBUG c.m.m.p.p.MarlinInterface - MarlinInterface disconnected. 
2022-01-26 14:41:16,279 DEBUG c.m.m.p.p.ChooseConnection - closed 
2022-01-26 14:41:27,054 DEBUG c.m.makelangelo.Makelangelo - Loading file /Users/guillaume/Downloads/molang.svg... 
2022-01-26 14:41:27,057 DEBUG c.m.m.makeArt.io.vector.LoadSVG - Loading... 
[...]
2022-01-26 14:41:27,273 DEBUG c.m.m.makeArt.io.vector.LoadSVG - Close path 
2022-01-26 14:41:27,273 DEBUG c.m.m.makeArt.io.vector.LoadSVG - ...parse polylines 
2022-01-26 14:41:27,273 DEBUG c.m.m.makeArt.io.vector.LoadSVG - ...parse polygons 
2022-01-26 14:41:27,273 DEBUG c.m.m.makeArt.io.vector.LoadSVG - ...parse lines 
2022-01-26 14:41:27,273 DEBUG c.m.m.makeArt.io.vector.LoadSVG - ...parse rects 
2022-01-26 14:41:27,273 DEBUG c.m.m.makeArt.io.vector.LoadSVG - ...parse circles 
2022-01-26 14:41:27,273 DEBUG c.m.m.makeArt.io.vector.LoadSVG - 0 circles. 
2022-01-26 14:41:27,274 DEBUG c.m.m.makeArt.io.vector.LoadSVG - ...parse ellipses 
2022-01-26 14:41:27,277 DEBUG c.m.m.t.t.TurtleRenderFacade - first=0 
2022-01-26 14:41:27,277 DEBUG c.m.m.t.t.TurtleRenderFacade - last=16267 
2022-01-26 14:41:27,277 DEBUG c.m.m.t.t.TurtleRenderFacade - first=0 
2022-01-26 14:41:27,277 DEBUG c.m.m.t.t.TurtleRenderFacade - last=50 
2022-01-26 14:41:27,277 DEBUG c.m.m.t.t.TurtleRenderFacade - first=0 
2022-01-26 14:41:27,277 DEBUG c.m.m.t.t.TurtleRenderFacade - last=50 
2022-01-26 14:41:27,277 DEBUG c.m.m.t.t.TurtleRenderFacade - first=0 
2022-01-26 14:41:27,277 DEBUG c.m.m.t.t.TurtleRenderFacade - last=16267 
2022-01-26 14:41:33,567 DEBUG c.m.m.t.t.TurtleRenderFacade - first=0 
2022-01-26 14:41:33,567 DEBUG c.m.m.t.t.TurtleRenderFacade - last=16267 
2022-01-26 14:41:36,713 DEBUG c.m.c.NetworkSessionUIManager - Fetching connections 
2022-01-26 14:41:36,713 DEBUG c.m.c.NetworkSessionUIManager -   USB Serial 
2022-01-26 14:41:36,717 DEBUG c.m.c.NetworkSessionUIManager -     /dev/cu.Bluetooth-Incoming-Port 
2022-01-26 14:41:36,717 DEBUG c.m.c.NetworkSessionUIManager -     /dev/cu.DRAWBOT-Port 
2022-01-26 14:41:36,717 DEBUG c.m.c.NetworkSessionUIManager -     /dev/cu.SRS-XB33-BluetoothSeria 
2022-01-26 14:41:48,656 DEBUG c.m.m.p.p.ChooseConnection - onConnectAction() 
2022-01-26 14:41:51,116 DEBUG c.m.m.p.p.ChooseConnection - open to /dev/cu.DRAWBOT-Port 
2022-01-26 14:41:51,116 DEBUG c.m.m.p.p.MarlinInterface - MarlinInterface connected. 
2022-01-26 14:41:55,366 TRACE c.m.m.p.p.MarlinInterface - sending 'N4 M280 P0 S90 T50*102' 
2022-01-26 14:41:55,366 TRACE c.m.m.p.p.MarlinInterface - sending 'N1 M280 P0 S90 T50*99' 
2022-01-26 14:41:55,366 TRACE c.m.m.p.p.MarlinInterface - sending 'N5 G28 XY*55' 
2022-01-26 14:41:55,366 TRACE c.m.m.p.p.MarlinInterface - sending 'N2 G28 XY*48' 
2022-01-26 14:41:55,407 TRACE c.m.m.p.p.MarlinInterface - received 'Error:Line Number is not Last Line Number+1, Last Line: 3' 
2022-01-26 14:41:55,407 ERROR c.m.m.p.p.MarlinInterface - Error from printer 'Error:Line Number is not Last Line Number+1, Last Line: 3' 
i-make-robots commented 2 years ago

sending 'N4 M280 P0 S90 T50*102' is the issue. How did it start on line 4?

i-make-robots commented 2 years ago

onHearError() is where the dialog happens.

i-make-robots commented 2 years ago

https://github.com/MarginallyClever/Makelangelo-software/commit/ead8a4149d7f10ec9229d0f17122154720183106#diff-4d19b6d9f314371405e605404a561089b61ddb1df76296768c24b1222a3e6315 is the commit that changed the popup dialog

coliss86 commented 2 years ago

https://github.com/MarginallyClever/Makelangelo-software/commit/c3538644617f7a2043ab374755a58a2bd1ec37a9 removed the popup but the robot still doesn't move after the 2nd opening of the dialog.

sending 'N4 M280 P0 S90 T50*102' is the issue. How did it start on line 4?

It came from the first opening of the dialog box. I didn't find in the documentation of marlin a way to reset the counter of line expected when opening a new connection. Do you know how to do it ?

Another case to reproduce the issue is :

  1. Start Makelangelo
  2. Load a file, open the plotter controls
  3. Home the robot
  4. Reset the robot with the switch on it
  5. Home the robot again

The robot will tell that the line number is not the value expected.

i-make-robots commented 2 years ago

When the serial connection is opened the robot is reset. When the robot is reset the robot's internal line number (A) is set to zero. Every command sent from the app to the robot has a line number and checksum. Every command is also queued so that if the robot says "please resend line n" it can pull that line. the queue is MarlinInterface.HISTORY_BUFFER_LIMIT long.

The load + open PlotterControls fills the ProgramInterface with commands. Home sends N1 to the robot. reset/reconnect puts A back to zero. send home again is now N2. mismatch. The only way the app could know the robot reset is by watching in onDataReceived() for the first message from Marlin. This is very do-able.

The N4 M280 P0 S90 T50*102 error should not exist because PlotterControls was closed and reopened. The state of the MarlinInterface should be completely reset back to N0, as well.

coliss86 commented 2 years ago

When the serial connection is opened the robot is reset.

I don't observed this :-( Here is what I did to be sure:

  1. reset the robot
  2. start Makelangelo
  3. connect to the robot
  4. home it
  5. close plotter control
  6. close Makelangelo
  7. start Makelangelo
  8. connect to the robot
  9. home it

here is the log I see:

2022-01-29 16:28:34,243 DEBUG c.m.c.NetworkSessionUIManager - Fetching connections 
2022-01-29 16:28:34,243 DEBUG c.m.c.NetworkSessionUIManager -   USB Serial 
2022-01-29 16:28:34,303 DEBUG c.m.c.NetworkSessionUIManager -     /dev/cu.Bluetooth-Incoming-Port 
2022-01-29 16:28:34,303 DEBUG c.m.c.NetworkSessionUIManager -     /dev/cu.DRAWBOT-Port 
2022-01-29 16:28:34,303 DEBUG c.m.c.NetworkSessionUIManager -     /dev/cu.SRS-XB33-BluetoothSeria 
2022-01-29 16:28:37,269 DEBUG c.m.m.p.p.ChooseConnection - onConnectAction() 
2022-01-29 16:28:38,758 DEBUG c.m.m.p.p.ChooseConnection - open to /dev/cu.DRAWBOT-Port 
2022-01-29 16:28:38,760 DEBUG c.m.m.p.p.MarlinInterface - MarlinInterface connected. 
2022-01-29 16:28:39,776 DEBUG c.m.m.p.p.MarlinInterface - sendQueuedCommand history [MarlinCommand{lineNumber=1, command='N1 G28 XY*51'}] 
2022-01-29 16:28:39,776 TRACE c.m.m.p.p.MarlinInterface - 1 sending 'N1 G28 XY*51' 
2022-01-29 16:28:39,817 TRACE c.m.m.p.p.MarlinInterface - received 'Error:Line Number is not Last Line Number+1, Last Line: 2' 
2022-01-29 16:28:39,817 ERROR c.m.m.p.p.MarlinInterface - Error from printer 'Error:Line Number is not Last Line Number+1, Last Line: 2' 
2022-01-29 16:28:39,817 TRACE c.m.m.p.p.MarlinInterface - received 'Resend: 3' 

so the robot is asking line 3 which was send in the first opening Makelangelo. Can you tell me what am I doing wrong please ? I woulk like to understand.

Nevertheless, there still is an issue in Makelangelo when opening and closing the plotter control, I'm digging...

coliss86 commented 2 years ago

This bug is not related to the serial communication ! the PlotterControls is instantiated once in Makelangelo.java but the listener associated to the home button is added as many times as this window is opened.

coliss86 commented 2 years ago

The issue is caused by the plotter controls recreated each times it is opened. The MarlinPlotterInterface register itself each times and then when you clicked the home button, the event PlotterEvent.HOME_FOUND is fired and 2 or more listener of MarlinPlotterInterface react to send G28.

The fix I did is to show / hide the plotter controls instead of destroying it

i-make-robots commented 2 years ago

If the PlotterControls are recreated then so is the MarlinPlotterInterface and so is the home button. I don't understand your description of the problem or the solution. Which "register" is being saved even after PlotterControls is closed and reopened?

coliss86 commented 2 years ago

When the PlotterControls is created, the constructor of MarlinPlotterInterface register it self to the plotter : https://github.com/MarginallyClever/Makelangelo-software/blob/782f02f9dcbb4866f23274a5a21da6b34f81138c/src/main/java/com/marginallyclever/makelangelo/plotter/plotterControls/MarlinPlotterInterface.java#L33. When this window is closed, the listener does not remote itself from the plotter.

When a new PlotterControls is created, the same registration occurs again.

So when the home button is click, one event PlotterEvent.HOME_FOUND is fired but there are 2 instances of MarlinPlotterInterface which will be triggered.

i-make-robots commented 2 years ago

then it seems to me the correct fix is to unregister at the right moment.

coliss86 commented 2 years ago

then it seems to me the correct fix is to unregister at the right moment.

This is another way to fix the issue, avoiding recreated the whole pane works fine too.

i-make-robots commented 2 years ago

Fixed along with #479, right?

coliss86 commented 2 years ago

With #500 :)

(#479 is this issue)