area515 / Photonic3D

Control software for resin 3D printers
http://photonic3d.com
GNU General Public License v3.0
131 stars 115 forks source link

Zip of Images Fails to Print #271

Closed jmkao closed 7 years ago

jmkao commented 7 years ago
2016-10-22 21:07:12,528 ERROR o.a.r.j.PrintJobManager$JobCloser [PrintJobProcess
orThread-1] Job Failed:PrintJobProcessorThread-1
java.util.concurrent.ExecutionException: java.util.concurrent.ExecutionException
: java.lang.NullPointerException
        at java.util.concurrent.FutureTask.report(FutureTask.java:122) ~[?:1.8.0]
        at java.util.concurrent.FutureTask.get(FutureTask.java:192) ~[?:1.8.0]
        at org.area515.resinprinter.job.PrintJobManager$JobCloser.run(PrintJobManager.java:44) [photonic3d.jar:?]
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:1.8.0]
        at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) [?:1.8.0]
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [?:1.8.0]
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [?:1.8.0]
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [?:1.8.0]
        at java.lang.Thread.run(Thread.java:744) [?:1.8.0]
Caused by: java.util.concurrent.ExecutionException: java.lang.NullPointerException
        at java.util.concurrent.FutureTask.report(FutureTask.java:122) ~[?:1.8.0]
        at java.util.concurrent.FutureTask.get(FutureTask.java:192) ~[?:1.8.0]
        at org.area515.resinprinter.job.ZipImagesFileProcessor.processFile(ZipImagesFileProcessor.java:76) ~[photonic3d.jar:?]
        at org.area515.resinprinter.job.PrintJobProcessingThread.call(PrintJobProcessingThread.java:38) ~[photonic3d.jar:?]
        at org.area515.resinprinter.job.PrintJobProcessingThread.call(PrintJobProcessingThread.java:11) ~[photonic3d.jar:?]
        ... 6 more
Caused by: java.lang.NullPointerException
        at com.google.common.base.Preconditions.checkNotNull(Preconditions.java:212) ~[guava-19.0.jar:?]
        at com.google.common.cache.LocalCache.get(LocalCache.java:3952) ~[guava-19.0.jar:?]
        at com.google.common.cache.LocalCache.getOrLoad(LocalCache.java:3957) ~[guava-19.0.jar:?]
        at com.google.common.cache.LocalCache$LocalLoadingCache.get(LocalCache.java:4875) ~[guava-19.0.jar:?]
        at org.area515.resinprinter.job.render.RenderingCache.get(RenderingCache.java:28) ~[photonic3d.jar:?]
        at org.area515.resinprinter.job.render.RenderingCache.getSpecificLock(RenderingCache.java:36) ~[photonic3d.jar:?]
        at org.area515.resinprinter.job.render.CurrentImageRenderer.call(CurrentImageRenderer.java:61) ~[photonic3d.jar:?]
        at org.area515.resinprinter.job.render.CurrentImageRenderer.call(CurrentImageRenderer.java:20) ~[photonic3d.jar:?]
        ... 6 more
2016-10-22 21:07:12,545 DEBUG o.a.r.p.PrinterManager [PrintJobProcessorThread-1] Attempting to dissassociate job:KBHandle-Set-Framed.stl.zip assigned to printer:Titan 1(printerFirmwareSerialPort:/dev/ttyUSB1, projectorSerialPort:/dev/ttyUSB0 Display::0.0) from printer
2016-10-22 21:07:12,547 INFO o.a.r.p.PrinterManager [PrintJobProcessorThread-1] Disassociated job:KBHandle-Set-Framed.stl.zip (No Printer) from printer:Titan 1(printerFirmwareSerialPort:/dev/ttyUSB1, projectorSerialPort:/dev/ttyUSB0 Display::0.0)
WesGilster commented 7 years ago

Sorry about that, I don't test this file type enough. I'm not sure I even have an example of one. I'll help take a look as well.

jmkao commented 7 years ago

This is the type of file generated by the SLAcer.js integration, so you should be able to generate one by slicing the default file that's bundled into SLAcer.js,

I see there are a lot of changes to the threaded control flow.

What seems to be happening is that in:

public RenderedData call() throws JobManagerException {
        long startTime = System.currentTimeMillis();
        Lock lock = aid.cache.getSpecificLock(imageIndexToBuild);
        lock.lock();
        try {
            RenderedData imageData = aid.cache.get(imageIndexToBuild);
            BufferedImage image = renderImage(imageData.getPreTransformedImage());

aid.cache.getSpecificLock() is encountering a null. I'm still familiarizing myself with how you integrated the cache to understand the control flow.

jmkao commented 7 years ago

I think the problem may be in this section of ZipImageFileProcessor.processFile():

            Iterator<File> imgIter = imageFiles.values().iterator();

            // Preload first image then loop
            if (imgIter.hasNext()) {
                File imageFile = null;
                int sliceIndex = dataAid.customizer.getNextSlice();
                while (imgIter.hasNext() && sliceIndex > 0) {
                    sliceIndex--;
                    imgIter.next();
                }

                Future<RenderedData> prepareImage = Main.GLOBAL_EXECUTOR.submit(new SimpleImageRenderer(dataAid, this, imageFile));
                boolean slicePending = true;

It seems that imageFile is initialized to null, and then is never set before being passed into the constructor for new SimpleImageRenderer().

I think we want to do imageFile = imageIter.next(). Let me try this and see.

jmkao commented 7 years ago

Hmm.. no, I see... that while loop is for iterating to a point in the list of images when the user requests to start at an index. I need to set imageFile outside.

jmkao commented 7 years ago

Got it, testing now on my RPi, then will submit PR.

jmkao commented 7 years ago

Hmm.. almost, but not quite... the layerAreaMM2 computation is off. The number of non-black pixels is being computed, but the subsequent calculation of area is not working...

2016-10-22 22:49:56,961 INFO o.a.r.j.AbstractPrintFileProcessor [PrintJobProcess
orThread-3] { "layer": 2, "exposureTime": 39000, "liftDistance": 3.0, "liftSpeed
": 5.0 , "layerAreaMM2": null }
2016-10-22 22:49:57,834 INFO o.a.r.j.AbstractPrintFileProcessor [PrintJobProcess
orThread-3] ExposureStart:1477176597834
2016-10-22 22:49:58,300 INFO o.a.r.j.r.CurrentImageRenderer [PrintJobProcessorTh
read-2] Loaded /tmp/printdir/KBHandle-Set-Framed.stl.zipextract/slices/5.png  wi
th 371724 non-black pixels in 1334ms
jmkao commented 7 years ago

AbstractPrintFileProcessor.getBuildAreaMM() seems to depend on aid.cache.getCurrentArea().

The correct behavior of getCurrentArea() depends on aid.cache.setCurrentRenderingPointer() being updated at the correct point, which seems to be the responsibility of each file processor's processFile() loop

jmkao commented 7 years ago

@WesGilster Is the logic in the following code from STLFileProcessor correct?

In paarticular, the dataAid.cache.setCurrentRenderingPointer(nextRenderingPointer); followed by status = printImageAndPerformPostProcessing(dataAid, image);

It would seem that since the current rendering pointer has been incremented, but getBuildAreaMM() is called within printImageAndPerformPostProcessing(), this would result in the RenderingData (and its included area computation) that it being pointed to be either be the next image or still null.

            for (int z = startPoint; dataAid.slicingProfile.getDirection().isSliceAvailable(z, endPoint) && dataAid.printer.isPrintActive(); z += dataAid.slicingProfile.getDirection().getVector()) {

                //Performs all of the duties that are common to most print files
                JobStatus status = performPreSlice(dataAid, slicer.getStlErrors());
                if (status != null) {
                    return status;
                }

                logger.info("SliceOverheadStart:{}", ()->Log4jTimer.startTimer(STL_OVERHEAD));

                //Wait until the image has been properly rendered. Most likely, it's already done though...
                BufferedImage image = currentImage.get().getPrintableImage();

                logger.info("SliceOverhead:{}", ()->Log4jTimer.completeTimer(STL_OVERHEAD));

                //Now that the image has been rendered, we can make the switch to use the pointer that we were using while we were rendering
                dataAid.cache.setCurrentRenderingPointer(nextRenderingPointer);

                //Start the exposure timer
                // logger.info("ExposureStart:{}", ()->Log4jTimer.startTimer(EXPOSURE_TIMER));

                //Cure the current image
                //dataAid.printer.showImage(image);

                //Get the next pointer in line to start rendering the image into
                nextRenderingPointer = dataAid.cache.getNextRenderingPointer();

                //Render the next image while we are waiting for the current image to cure
                if (z < slicer.getZMaxIndex() + 1) {
                    slicer.setZIndex(z);
                    currentImage = Main.GLOBAL_EXECUTOR.submit(new STLImageRenderer(dataAid, this, nextRenderingPointer, false));
                }

                //Performs all of the duties that are common to most print files
                status = printImageAndPerformPostProcessing(dataAid, image);
                if (status != null) {
                    return status;
                }
            }

I'm wondering if rather than calling getPrintableImage() to return a BufferedImage, we should use get() and then pass a RenderedData to printImageAndPerformPostProcessing().

jmkao commented 7 years ago

Hmm.. there is also something I don't understand about the way RenderingCache is implemented.

getCurrentArea() seems to use currentImagePointer as the key into the cache to get the RenderingData. The keys seem to be implicitly inserted based on the behavior of the no-arg get(), where it looks like a new entry is created for that key if it doesn't exist.

However, while get() takes an Object (which in the case of the SimpleImageRenderer is a File), setCurrentRenderingPointer() will attempt to cast its input to a Boolean, which means anything other than a Boolean will cause a ClassCastException. That means that unless the key is a Boolean, it's not possible to update the current rendering pointer to make getCurrentArea() work correctly, but SimpleImageRenderer requires that the object used as a key be a File.

WesGilster commented 7 years ago

Wow, I've got to catch up a bit, I said I was going to look at this, but didn't. I think you are on to something here...

WesGilster commented 7 years ago

The true/false flops the current "pointer" back and forth between the currently rendered pointer and the next possible pointer. When "True" is being rendered, "false" is being shown and vise versa. However to make use of that function you actually have to be a renderer that needs that style of functionality. When I rewrote the renderers, it didn't seem as though the zipFileRenderer required that functionality since it was a direct index cache to the file it was currently rendering. Apparently I'm still dependent on that functionality though given we got a NullPointerException.

WesGilster commented 7 years ago

setCurrentRenderingPointer() should not have been casting to a boolean. That's problem number 1.

jmkao commented 7 years ago

Ok, if removing the boolean cast in setCurrentRenderingPointer is okay, then the fix is complete. I wonder, given all the caching and side-effect state, if it may be harder for people to write file processors than before this. I'll need to dig in on what all of the moving parts do any maybe come up with some kind of guide or at least a much more commented code example of what is necessary for a fully functional processor.

WesGilster commented 7 years ago

Well, then I missed the mark. Let's see what we can do to fix that since the caching and rendering rewrite was designed to help, not worsen the problem of an implementer's burden of creating new processors. The very first problem is that we need a test for each different file type that we support.

Let me explain my intent, and you can give some feedback as to how we can better reach these goals. Things that an implementer shouldn't have to do:

  1. Think about how they need to cache images
  2. Think about how to concurrently render the next image while showing the current.
  3. Think about how to plug in a new renderer into the caching and print processing pipeline.

Things that an implementer should do:

  1. Extend a known class for the purpose of rendering. Something like: CurrentImageRenderer?
  2. Extend the AbstractPrintFileProcessor and implement the remaining abstract functions?

Eventually I'd like to merge the caching of preview images with the caching of print images, but that's a ways' off...

jmkao commented 7 years ago

Hmm... I wonder then if it would be easier to invert the control flow then. Force the implementer to implement a set of methods like:

etc...

essentially making the interface a kind of iterator. Machine control (e.g. processHeader, displayImage) would be entirely centralized.

The only oddball case that wouldn't work here is the CWS file. But maybe, for this one case, it's implemented completely separately. This may also be better for the future since CWS is pretty much dead, we're not likely to see any changes for this path, and keeping it as a frozen special case would let us evolve the rest of the rendering pipeline without worrying about breaking this case.

WesGilster commented 7 years ago

That doesn't sound like a bad idea. To be honest, the CWSFile already takes a path of it's own, so I don't mind leaving that processor gather dust anyway.