search

winder / Universal-G-Code-Sender

A cross-platform G-Code sender for GRBL, Smoothieware, TinyG and G2core.
http://winder.github.io/ugs_website/
GNU General Public License v3.0
1.88k stars 762 forks source link

Error while file is loading "error starting stream: null" #1282

Open winder opened 4 years ago

winder commented 4 years ago

Problem description

When loading a program it is possible to quickly click send and get this error. I noticed this by running a fairly large program (80k lines) on a very slow computer (Netbook from 2010, 1.6 GHz Intel Atom N270 Processor, 1 GB RAM)

It took maybe 10+ seconds before the send button worked.

Presumably this is happening because the file is processed at load time and serialized to a file, until that process finishes send has a problem.

Expected Behavior

A Better error message, or a progress indicator.

BallscrewBob commented 4 years ago

This has always been an issue / bug and the larger the file the worse it gets with some files causing UGS to just lock up. I don't think that a progress indicator would help as the root cause seems to lie in the file handling itself. A better message might be nice though.

The system speed doesn't seem to matter as the quad core AMD with 8 GB (soon to be 16) here with quite a lean and clean OS (win 7 pro but tweaked) will still see these problems.

Also when you run large files then quite often the controls on UGS will not respond during run time so better interrupts on the buttons also needs to be part of the same issue. I can see in the console that the command was issued to cancel file transfer but it simply does not do the action unless the file is a small one.

breiler commented 4 years ago

There are some issues here that may contribute to what you experience @BallscrewBob and you are probably right that this will only show the symptom of the problem. For instance, the #1197 shows that we load and hold the open streams to the file several times.

I added extra log messages for when the file is being loaded, which seems to be 4 times just when opening the file. 

INFO [com.willwinder.ugs.nbm.visualizer.RendererInputHandler]: Loading file /Users/zefal/Development/Universal-G-Code-Sender/test_files/circle.gcode
INFO [com.willwinder.ugs.nbm.visualizer.renderables.GcodeModel]: About to process {}
INFO [com.willwinder.ugs.nbm.visualizer.renderables.GcodeModel]: Done setting gcode file.
INFO [com.willwinder.universalgcodesender.model.GUIBackend]: Start preprocessing
INFO [com.willwinder.universalgcodesender.model.GUIBackend]: Preprocessing /Users/zefal/Development/Universal-G-Code-Sender/test_files/circle.gcode to /private/var/folders/3v/0fyq0c51003cc_h7cwdwbngm0000gn/T/1570947536295-0/circle.gcode_ugs_1570947536297
INFO [com.willwinder.universalgcodesender.model.GUIBackend]: Took 126ms to preprocess
INFO [com.willwinder.universalgcodesender.model.GUIBackend]: Getting processed gcode file.
INFO [com.willwinder.universalgcodesender.model.GUIBackend]: Getting processed gcode file.
INFO [com.willwinder.universalgcodesender.uielements.panels.SendStatusPanel]: Loading file circle.gcode_ugs_1570947536297
INFO [com.willwinder.universalgcodesender.model.GUIBackend]: Getting processed gcode file.
INFO [com.willwinder.ugs.nbm.visualizer.RendererInputHandler]: Loading file /var/folders/3v/0fyq0c51003cc_h7cwdwbngm0000gn/T/1570947536295-0/circle.gcode_ugs_1570947536297
INFO [com.willwinder.ugs.nbm.visualizer.renderables.GcodeModel]: About to process {}
INFO [com.willwinder.ugs.nbm.visualizer.renderables.GcodeModel]: Done setting gcode file.
INFO [com.willwinder.universalgcodesender.model.GUIBackend]: Getting processed gcode file.
INFO [com.willwinder.universalgcodesender.model.GUIBackend]: Getting processed gcode file.
INFO [com.willwinder.universalgcodesender.uielements.toolbars.SendStatusLine]: Loading file circle.gcode_ugs_1570947536297
INFO [com.willwinder.universalgcodesender.model.GUIBackend]: Getting processed gcode file.
INFO [com.willwinder.universalgcodesender.utils.SettingsFactory]: Saving settings.
INFO [org.netbeans.core.ui.focus]: External Changes Refresh on focus gain disabled

When starting the file stream the the status panel seems to open the file several times:

INFO [com.willwinder.ugs.nbp.core.actions.ConnectDisconnectAction]: openclose button, connection open: false
INFO [com.willwinder.universalgcodesender.model.GUIBackend]: Connecting to Testing (Delay) on port tty.usbmodem1421
INFO [com.willwinder.universalgcodesender.model.GUIBackend]: Setting gcode file.
INFO [com.willwinder.ugs.nbm.visualizer.RendererInputHandler]: Loading file /Users/zefal/Development/Universal-G-Code-Sender/test_files/circle.gcode
INFO [com.willwinder.ugs.nbm.visualizer.renderables.GcodeModel]: About to process {}
INFO [com.willwinder.ugs.nbm.visualizer.renderables.GcodeModel]: Done setting gcode file.
INFO [com.willwinder.universalgcodesender.model.GUIBackend]: Start preprocessing
INFO [com.willwinder.universalgcodesender.model.GUIBackend]: Preprocessing /Users/zefal/Development/Universal-G-Code-Sender/test_files/circle.gcode to /private/var/folders/3v/0fyq0c51003cc_h7cwdwbngm0000gn/T/1570947536295-0/circle.gcode_ugs_1570947717383
INFO [com.willwinder.universalgcodesender.model.GUIBackend]: Took 6ms to preprocess
INFO [com.willwinder.universalgcodesender.model.GUIBackend]: Getting processed gcode file.
INFO [com.willwinder.universalgcodesender.model.GUIBackend]: Getting processed gcode file.
INFO [com.willwinder.universalgcodesender.uielements.panels.SendStatusPanel]: Loading file circle.gcode_ugs_1570947717383
INFO [com.willwinder.universalgcodesender.model.GUIBackend]: Getting processed gcode file.
INFO [com.willwinder.ugs.nbm.visualizer.RendererInputHandler]: Loading file /var/folders/3v/0fyq0c51003cc_h7cwdwbngm0000gn/T/1570947536295-0/circle.gcode_ugs_1570947717383
INFO [com.willwinder.ugs.nbm.visualizer.renderables.GcodeModel]: About to process {}
INFO [com.willwinder.ugs.nbm.visualizer.renderables.GcodeModel]: Done setting gcode file.
INFO [com.willwinder.universalgcodesender.model.GUIBackend]: Getting processed gcode file.
INFO [com.willwinder.universalgcodesender.model.GUIBackend]: Getting processed gcode file.
INFO [com.willwinder.universalgcodesender.uielements.toolbars.SendStatusLine]: Loading file circle.gcode_ugs_1570947717383
INFO [com.willwinder.universalgcodesender.model.GUIBackend]: Getting processed gcode file.
INFO [com.willwinder.universalgcodesender.model.GUIBackend]: Applying settings.
INFO [com.willwinder.universalgcodesender.model.GUIBackend]: Setting gcode file.
INFO [com.willwinder.ugs.nbm.visualizer.RendererInputHandler]: Loading file /Users/zefal/Development/Universal-G-Code-Sender/test_files/circle.gcode
INFO [com.willwinder.ugs.nbm.visualizer.renderables.GcodeModel]: About to process {}
INFO [com.willwinder.ugs.nbm.visualizer.renderables.GcodeModel]: Done setting gcode file.
INFO [com.willwinder.universalgcodesender.model.GUIBackend]: Start preprocessing
INFO [com.willwinder.universalgcodesender.model.GUIBackend]: Preprocessing /Users/zefal/Development/Universal-G-Code-Sender/test_files/circle.gcode to /private/var/folders/3v/0fyq0c51003cc_h7cwdwbngm0000gn/T/1570947536295-0/circle.gcode_ugs_1570947717606
INFO [com.willwinder.universalgcodesender.model.GUIBackend]: Took 7ms to preprocess
INFO [com.willwinder.universalgcodesender.model.GUIBackend]: Getting processed gcode file.
INFO [com.willwinder.universalgcodesender.model.GUIBackend]: Getting processed gcode file.
INFO [com.willwinder.universalgcodesender.uielements.panels.SendStatusPanel]: Loading file circle.gcode_ugs_1570947717606
INFO [com.willwinder.universalgcodesender.model.GUIBackend]: Getting processed gcode file.
INFO [com.willwinder.ugs.nbm.visualizer.RendererInputHandler]: Loading file /var/folders/3v/0fyq0c51003cc_h7cwdwbngm0000gn/T/1570947536295-0/circle.gcode_ugs_1570947717606
INFO [com.willwinder.ugs.nbm.visualizer.renderables.GcodeModel]: About to process {}
INFO [com.willwinder.ugs.nbm.visualizer.renderables.GcodeModel]: Done setting gcode file.
INFO [com.willwinder.universalgcodesender.model.GUIBackend]: Getting processed gcode file.
INFO [com.willwinder.universalgcodesender.model.GUIBackend]: Getting processed gcode file.
INFO [com.willwinder.universalgcodesender.uielements.toolbars.SendStatusLine]: Loading file circle.gcode_ugs_1570947717606
INFO [com.willwinder.universalgcodesender.model.GUIBackend]: Getting processed gcode file.
INFO [com.willwinder.universalgcodesender.model.GUIBackend]: Start preprocessing
INFO [com.willwinder.universalgcodesender.model.GUIBackend]: Took 0ms to preprocess
WARNING [org.openide.util.ImageUtilities]: Initial slashes in Utilities.loadImage deprecated (cf. #20072): /org/netbeans/core/windows/resources/error.png
INFO [com.willwinder.universalgcodesender.model.GUIBackend]: Sending gcode file.
INFO [com.willwinder.universalgcodesender.model.GUIBackend]: Loading file circle.gcode_ugs_1570947717606

@winder I'm thinking the idea about creating a preprocessed file which later can be streamed is a great idea. But we load pretty much all the data into memory for the Visualizer anyway.

I'm wondering if we should try to rewrite the file loading mechanism, reading the whole file into memory once and then create gcodestreamers that reads from memory instead of a file stream?

BallscrewBob commented 4 years ago

From my standpoint that is a very good Idea. What dissuades me from trusting UGS in it's entirety is the so many times I have to close down the program and I am 100% sure it is in the way the file is handled as you suggest.

Just to add some side information the file is often checked by any and I do mean ANY antivirus software. This could be compounding the problem and is something I am actively testing here at the moment as I already get at least a 75% boost in load times for the program itself by adding the directory in the USER folders under Win 7 pro.

Second the idea of improved loading system.

winder commented 4 years ago

@breiler I think it's a great idea to clean up the file loading, but I'm not sure how it would cause the event delay. Maybe there is an EvokeLater in one of the event handlers which is falling behind, which could cause a compounding issue that eventually grinds the UI to a halt.

rlwoodjr commented 4 years ago

We load files on a WIndows 10 mini PC with 2Gb of ram that are over 1,000,000 lines long. The trick for us is to open the "Send Progress" window and wait for the "Rows in file" to populate, then click play. We typically close the visualizer window, but if you do not, please note that the tool path graphics will load long before the file shows in the "Send Progress" window. The wait for a million+ line file with our computer can be several minutes, but it has always loaded.

On another note, changing some windows has proven to resolve some freezing issues with large files.

  1. Change the Performance settings to max performance
  2. Turned off Notifications
  3. Turned off any background applications
  4. Disabled all all unneeded programs at startup.

Not sure if this will help, but it has seemed to for us. The UGS command do not seem to be live during these long runs, but our hard wired "pause" and "resume" buttons work.

Just for added information. Our files are cutting at 200 to 300 inches per minute, which gets slowed down by the Z most of the time. The files take 5 to 9 hours to run.

BallscrewBob commented 4 years ago

@rlwoodjr.

Whilst those steps do certainly help they never fix the issue Box here is already set for max performance and even a lot of the settings that regular people don't see are tweaked too here. Startup has also been trimmed a lot.

Speeds and feeds here can cause some minor lag when using the overrides to bump UP the job speed to MAX, and going DOWN to slower feeds does not seem to ever cause an issue and does seem to help. Similar job times here too depending on the task and the material. (Mainly wood engraving)

Additionally the UNLOCK and SOFT RESET can become unavailable during these lock ups or stalls.

rlwoodjr commented 4 years ago

My understanding from our testing is that in a large file run at a "fast" feed rate causes a lag between the GUI and the serial communications. Therefore the GUI is not live. It lags behind. When we finish a large file (spindle returns home and the project is complete), the UGS screen still has 30% to 50% of lines to process. I actually let it continue to run a few times and it does finally finish up and give you back the GUI. This is true with 16Gb dual processor or 2Gb mini computer.

With our normal production files (small and lots of straight lines) the GUI stays in sync.

BallscrewBob commented 4 years ago

I can get the same lock ups regardless of being raster or vector based with curves. Don't think it is so much the visualiser (been running without it) and not totally the speed settings either (been running default or lower speeds)

Tests over the last few days seem to indicate the console may be behind most of the issue. Going to try without the console engaged over the next few days to see if that helps.

BallscrewBob commented 4 years ago

Follow up... Two different jobs running both WITHOUT visualiser and console. I can still enter the lag / stall condition.

Next is to run the same jobs WITHOUT the DRO display as I can clearly see there are some issues there too because it stutters.

Happily the STOP / PAUSE command now appears to work a lot quicker without the the long pauses before the error box comes up. But it still does not bring the rest of the GUI back into line and most options are still greyed out / unavailable.

BallscrewBob commented 4 years ago

UPDATE Even without DRO enabled and everything else OFF visualiser etc etc there are delay and lag / stall issues with large file sizes. Oddly enough SourceRabbit doesn't give me the same issues. Just a shame I don't really like that one though as it doesn't have the feel of UGS.

breiler commented 4 years ago

I've added a modal loader dialog that could be used to "lock" the gui while the gcode-file is processed. https://github.com/winder/Universal-G-Code-Sender/blob/master/ugs-core/src/com/willwinder/universalgcodesender/uielements/helpers/LoaderDialogHelper.java