nanoDLP

macdarren

Member

Registered: 2017-03-20

Posts: 411

Better Understanding NanoDLP Log

In an effort to better understand what is happening in NanoDLP, so I can maybe tune my printer better I have started looking at the log files.

My first question is are the log entries perhaps generated asynchronously and thus possibly the times are log times vs when an event actually happened?

It seems like things like shutter opening and image
display are out of order (I would assume the image would be displayed then the shutter opens then the shutter closes after
the cure time then the image is cleared) but from the log it doesn't appear that way....maybe shutter speed and delays cause some
out of sync issue?  It clearly works as is but I am trying to understand what I am seeing in the logs.

Below is a log snippet.... from shutter open to shutter open so it should be a full layer.

I'd love to know what the "Unknown command: ' '" is but it doesn't seem to hurt anything.
I print with an exposure time of 12 seconds I am trying to find where that exact time is in the log....
I assumed it was between shutter open and shutter close but that seems wrong, maybe it is between
display image and clear image but that too is not 12 seconds...close but not really at computer speeds.
The one second delay between the logging of the delay and the Shutter Open, seems about right on..

TIA

Debug    19    2019-11-17 19:27:26.253272    Shutter    Shutter Open
Notice    19    2019-11-17 19:27:25.269685    Terminal    Received Data From Controller: ok
Notice    19    2019-11-17 19:27:25.269559    Terminal    Received Data From Controller: echo:Unknown command: ' '
Notice    19    2019-11-17 19:27:25.269237    Terminal    Received Data From Controller: ok
Notice    19    2019-11-17 19:27:25.269087    Terminal    Received Data From Controller: echo:Unknown command: ' '
Debug    19    2019-11-17 19:27:25.252984    Gcode    Delay Printing For 1 Seconds
Debug    19    2019-11-17 19:27:25.252907    Gcode    Transferring Data
Notice    19    2019-11-17 19:27:25.252864    Gcode    Position set to 1.9
Notice    19    2019-11-17 19:27:25.252771    Terminal    Received Data From Controller: Z_move_comp
Debug    19    2019-11-17 19:27:25.252679    Gcode    Transferring Data
Info    19    2019-11-17 19:27:25.252638    Controller Sync    Waiting for Z_move_comp response from Controller
Info    19    2019-11-17 19:27:25.252561    Controller Sync    Done message from Controller has been received
Notice    19    2019-11-17 19:27:23.223912    Terminal    Received Data From Controller: ok
Notice    19    2019-11-17 19:27:23.223786    Terminal    Received Data From Controller: ok
Notice    19    2019-11-17 19:27:23.223621    Terminal    Received Data From Controller: echo:Unknown command: ' '
Notice    19    2019-11-17 19:27:23.223296    Terminal    Received Data From Controller: ok
Notice    19    2019-11-17 19:27:23.223138    Terminal    Received Data From Controller: echo:Unknown command: ' '
Debug    19    2019-11-17 19:27:23.208926    Gcode    Transferring Data G1 Z1.9 F400.0000
Debug    18    2019-11-17 19:27:23.208169    Gcode    Transferring Data
Notice    18    2019-11-17 19:27:23.208135    Gcode    Position change 5 to 6.8
Notice    18    2019-11-17 19:27:23.208073    Terminal    Received Data From Controller: Z_move_comp
Debug    18    2019-11-17 19:27:23.207957    Gcode    Transferring Data
Info    18    2019-11-17 19:27:23.207893    Controller Sync    Done message from Controller has been received
Info    18    2019-11-17 19:27:23.207823    Controller Sync    Waiting for Z_move_comp response from Controller
Notice    18    2019-11-17 19:27:21.64265    Terminal    Received Data From Controller: ok
Notice    18    2019-11-17 19:27:21.642526    Terminal    Received Data From Controller: ok
Notice    18    2019-11-17 19:27:21.642405    Terminal    Received Data From Controller: echo:Unknown command: ' '
Notice    18    2019-11-17 19:27:21.642085    Terminal    Received Data From Controller: ok
Notice    18    2019-11-17 19:27:21.641955    Terminal    Received Data From Controller: echo:Unknown command: ' '
Debug    18    2019-11-17 19:27:21.625753    Gcode    Transferring Data

G1 Z6.8000 F400.0000
Notice    18    2019-11-17 19:27:21.625684    Terminal    Received Data From Controller: Z_move_comp
Debug    18    2019-11-17 19:27:21.625632    Gcode    Transferring Data
Info    18    2019-11-17 19:27:21.625568    Controller Sync    Waiting for Z_move_comp response from Controller
Info    18    2019-11-17 19:27:21.625483    Controller Sync    Done message from Controller has been received
Notice    18    2019-11-17 19:27:19.947686    Terminal    Received Data From Controller: ok
Notice    18    2019-11-17 19:27:19.947484    Terminal    Received Data From Controller: ok
Debug    18    2019-11-17 19:27:19.939139    Gcode    Transferring Data M107
G1 Z3.8000 F80.0000
Debug    18    2019-11-17 19:27:19.42974    Shutter    Shutter Close
Debug    18    2019-11-17 19:27:19.429557    Image    Clear screen
Debug    18    2019-11-17 19:27:07.378708    Printing    Curing for 12 seconds
Warning    18    2019-11-17 19:27:07.242372    Image    Display layer public/plates/232/18.png
Debug    18    2019-11-17 19:27:06.74219    Shutter    Shutter Open

Last edited by macdarren (2019-11-18 03:57:49)

Shahin

Administrator

Registered: 2016-02-17

Posts: 3,546

Re: Better Understanding NanoDLP Log

The most of actions and loggings are async. So no guarantee log orders are correct.  Unknown command being passed from RAMPS so something could not recognized by RAMPS.
Curetime looks a bit more than what actually should be as it count time which gpu acknowledge displaying layer but logging happens as soon as nanodlp try displaying a layer.
So actual cure time is less that what recorded here.