2023-03-22 09:54:49.128 Main INFO: Bienvenue, Bienvenido, Willkommen, Hello, Namaskar, Welkom, Bonjour to OpenPnP version 2023-03-21_19-17-30.72b18df.
2023-03-22 09:54:49.139 Scripting TRACE: Scripting.on Startup
2023-03-22 09:54:49.170 CameraView DEBUG: Failed to load camera specific reticle, checking default.
2023-03-22 09:54:49.170 CameraView DEBUG: No reticle preference found.
2023-03-22 09:54:49.171 OpenCvCamera DEBUG: Setting property CAP_PROP_BRIGHTNESS on camera Down Camera to 40.0
2023-03-22 09:54:49.172 OpenCvCamera DEBUG: Setting camera Down Camera width to 1600
2023-03-22 09:54:49.172 OpenCvCamera DEBUG: Camera Down Camera reports width 0.0
2023-03-22 09:54:49.172 OpenCvCamera DEBUG: Setting camera Down Camera height to 1200
2023-03-22 09:54:49.201 OpenCvCamera DEBUG: Camera Down Camera reports height 0.0
2023-03-22 09:54:50.878 OpenCvCamera TRACE: Down Camera CAP_PROP_POS_MSEC = 0.0
2023-03-22 09:54:50.878 OpenCvCamera TRACE: Down Camera CAP_PROP_POS_FRAMES = 0.0
2023-03-22 09:54:50.878 OpenCvCamera TRACE: Down Camera CAP_PROP_POS_AVI_RATIO = -1.0
2023-03-22 09:54:50.878 OpenCvCamera TRACE: Down Camera CAP_PROP_FRAME_WIDTH = 640.0
2023-03-22 09:54:50.878 OpenCvCamera TRACE: Down Camera CAP_PROP_FRAME_HEIGHT = 480.0
2023-03-22 09:54:50.878 OpenCvCamera TRACE: Down Camera CAP_PROP_FPS = 30.0
2023-03-22 09:54:50.878 OpenCvCamera TRACE: Down Camera CAP_PROP_FOURCC = 20.0
2023-03-22 09:54:50.878 OpenCvCamera TRACE: Down Camera CAP_PROP_FRAME_COUNT = -1.0
2023-03-22 09:54:50.878 OpenCvCamera TRACE: Down Camera CAP_PROP_FORMAT = -1.0
2023-03-22 09:54:50.878 OpenCvCamera TRACE: Down Camera CAP_PROP_MODE = 0.0
2023-03-22 09:54:50.878 OpenCvCamera TRACE: Down Camera CAP_PROP_BRIGHTNESS = 0.0
2023-03-22 09:54:50.878 OpenCvCamera TRACE: Down Camera CAP_PROP_CONTRAST = 32.0
2023-03-22 09:54:50.878 OpenCvCamera TRACE: Down Camera CAP_PROP_SATURATION = 72.0
2023-03-22 09:54:50.878 OpenCvCamera TRACE: Down Camera CAP_PROP_HUE = -5.0
2023-03-22 09:54:50.878 OpenCvCamera TRACE: Down Camera CAP_PROP_GAIN = 0.0
2023-03-22 09:54:50.878 OpenCvCamera TRACE: Down Camera CAP_PROP_EXPOSURE = -6.0
2023-03-22 09:54:50.878 OpenCvCamera TRACE: Down Camera CAP_PROP_CONVERT_RGB = 1.0
2023-03-22 09:54:50.878 OpenCvCamera TRACE: Down Camera CAP_PROP_WHITE_BALANCE_BLUE_U = -1.0
2023-03-22 09:54:50.878 OpenCvCamera TRACE: Down Camera CAP_PROP_RECTIFICATION = -1.0
2023-03-22 09:54:50.878 OpenCvCamera TRACE: Down Camera CAP_PROP_MONOCHROME = -1.0
2023-03-22 09:54:50.894 OpenCvCamera TRACE: Down Camera CAP_PROP_SHARPNESS = 7.0
2023-03-22 09:54:50.894 OpenCvCamera TRACE: Down Camera CAP_PROP_AUTO_EXPOSURE = 0.0
2023-03-22 09:54:50.894 OpenCvCamera TRACE: Down Camera CAP_PROP_GAMMA = 100.0
2023-03-22 09:54:50.894 OpenCvCamera TRACE: Down Camera CAP_PROP_TEMPERATURE = 6500.0
2023-03-22 09:54:50.894 OpenCvCamera TRACE: Down Camera CAP_PROP_TRIGGER = -1.0
2023-03-22 09:54:50.894 OpenCvCamera TRACE: Down Camera CAP_PROP_TRIGGER_DELAY = -1.0
2023-03-22 09:54:50.894 OpenCvCamera TRACE: Down Camera CAP_PROP_WHITE_BALANCE_RED_V = -1.0
2023-03-22 09:54:50.894 OpenCvCamera TRACE: Down Camera CAP_PROP_ZOOM = -1.0
2023-03-22 09:54:50.894 OpenCvCamera TRACE: Down Camera CAP_PROP_FOCUS = -1.0
2023-03-22 09:54:50.894 OpenCvCamera TRACE: Down Camera CAP_PROP_GUID = -1.0
2023-03-22 09:54:50.894 OpenCvCamera TRACE: Down Camera CAP_PROP_ISO_SPEED = -1.0
2023-03-22 09:54:50.909 OpenCvCamera TRACE: Down Camera CAP_PROP_BACKLIGHT = 1.0
2023-03-22 09:54:50.909 OpenCvCamera TRACE: Down Camera CAP_PROP_PAN = -1.0
2023-03-22 09:54:50.909 OpenCvCamera TRACE: Down Camera CAP_PROP_TILT = -1.0
2023-03-22 09:54:50.909 OpenCvCamera TRACE: Down Camera CAP_PROP_ROLL = -1.0
2023-03-22 09:54:50.909 OpenCvCamera TRACE: Down Camera CAP_PROP_IRIS = -1.0
2023-03-22 09:54:50.909 OpenCvCamera TRACE: Down Camera CAP_PROP_SETTINGS = -1.0
2023-03-22 09:54:50.909 OpenCvCamera TRACE: Down Camera CAP_PROP_BUFFERSIZE = -1.0
2023-03-22 09:54:50.909 OpenCvCamera TRACE: Down Camera CAP_PROP_AUTOFOCUS = -1.0
2023-03-22 09:54:50.909 OpenCvCamera DEBUG: Setting camera Down Camera width to 1600
2023-03-22 09:54:51.665 OpenCvCamera DEBUG: Camera Down Camera reports width 1600.0
2023-03-22 09:54:51.665 OpenCvCamera DEBUG: Setting camera Down Camera height to 1200
2023-03-22 09:54:52.429 OpenCvCamera DEBUG: Camera Down Camera reports height 1200.0
2023-03-22 09:54:52.429 AbstractBroadcastingCamera TRACE: Camera Down Camera thread 29 started.
2023-03-22 09:54:52.429 CameraView DEBUG: Failed to load camera specific reticle, checking default.
2023-03-22 09:54:52.429 CameraView DEBUG: No reticle preference found.
2023-03-22 09:54:52.892 AbstractBroadcastingCamera TRACE: Camera OpenPnpCaptureCamera thread 31 started.
2023-03-22 09:54:53.883 AbstractMachine TRACE: Machine not enabled, task ignored.
2023-03-22 09:55:07.343 ReferenceMachine DEBUG: setEnabled(true)
2023-03-22 09:55:17.422 GcodeDriver DEBUG: [serial://COM3] >> $ex=0, 20000
2023-03-22 09:55:17.445 GcodeDriver$ReaderThread TRACE: [serial://COM3] << [ex]  enable flow control         0 [0=off,1=XON/XOFF, 2=RTS/CTS]
2023-03-22 09:55:17.446 GcodeDriver$ReaderThread TRACE: [serial://COM3] << tinyg [mm] ok>
2023-03-22 09:55:17.446 GcodeDriver TRACE: [serial://COM3] confirmed $ex=0
2023-03-22 09:55:17.447 GcodeDriver DEBUG: [serial://COM3] >> $SV=2, 20000
2023-03-22 09:55:17.481 GcodeDriver$ReaderThread TRACE: [serial://COM3] << [sv]  status report verbosity     2 [0=off,1=filtered,2=verbose]
2023-03-22 09:55:17.490 GcodeDriver$ReaderThread TRACE: [serial://COM3] << tinyg [mm] ok>
2023-03-22 09:55:17.493 GcodeDriver TRACE: [serial://COM3] confirmed $SV=2
2023-03-22 09:55:17.494 GcodeDriver DEBUG: [serial://COM3] >> $ME, 20000
2023-03-22 09:55:17.501 GcodeDriver$ReaderThread TRACE: [serial://COM3] << $ME
2023-03-22 09:55:17.502 GcodeDriver$ReaderThread TRACE: [serial://COM3] << tinyg [mm] ok>
2023-03-22 09:55:17.502 GcodeDriver TRACE: [serial://COM3] confirmed $ME
2023-03-22 09:55:17.502 GcodeDriver DEBUG: [serial://COM3] >> $1pm=0, 20000
2023-03-22 09:55:17.558 GcodeDriver$ReaderThread TRACE: [serial://COM3] << [1pm] m1 power management         0 [0=disabled,1=always on,2=in cycle,3=when moving]
2023-03-22 09:55:17.559 GcodeDriver$ReaderThread TRACE: [serial://COM3] << tinyg [mm] ok>
2023-03-22 09:55:17.563 GcodeDriver TRACE: [serial://COM3] confirmed $1pm=0
2023-03-22 09:55:17.565 GcodeDriver DEBUG: [serial://COM3] >> $2pm=0, 20000
2023-03-22 09:55:17.622 GcodeDriver$ReaderThread TRACE: [serial://COM3] << [2pm] m2 power management         0 [0=disabled,1=always on,2=in cycle,3=when moving]
2023-03-22 09:55:17.623 GcodeDriver$ReaderThread TRACE: [serial://COM3] << tinyg [mm] ok>
2023-03-22 09:55:17.629 GcodeDriver TRACE: [serial://COM3] confirmed $2pm=0
2023-03-22 09:55:17.629 GcodeDriver DEBUG: [serial://COM3] >> $3pm=0, 20000
2023-03-22 09:55:17.685 GcodeDriver$ReaderThread TRACE: [serial://COM3] << [3pm] m3 power management         0 [0=disabled,1=always on,2=in cycle,3=when moving]
2023-03-22 09:55:17.687 GcodeDriver$ReaderThread TRACE: [serial://COM3] << tinyg [mm] ok>
2023-03-22 09:55:17.690 GcodeDriver TRACE: [serial://COM3] confirmed $3pm=0
2023-03-22 09:55:17.691 GcodeDriver DEBUG: [serial://COM3] >> $4pm=0, 20000
2023-03-22 09:55:17.749 GcodeDriver$ReaderThread TRACE: [serial://COM3] << [4pm] m4 power management         0 [0=disabled,1=always on,2=in cycle,3=when moving]
2023-03-22 09:55:17.750 GcodeDriver$ReaderThread TRACE: [serial://COM3] << tinyg [mm] ok>
2023-03-22 09:55:17.752 GcodeDriver TRACE: [serial://COM3] confirmed $4pm=0
2023-03-22 09:55:17.752 GcodeDriver DEBUG: [serial://COM3] >> $mt=1000000000, 20000
2023-03-22 09:55:17.797 GcodeDriver$ReaderThread TRACE: [serial://COM3] << [mt]  motor idle timeout 1000000000.00 Sec
2023-03-22 09:55:17.798 GcodeDriver$ReaderThread TRACE: [serial://COM3] << tinyg [mm] ok>
2023-03-22 09:55:17.804 GcodeDriver TRACE: [serial://COM3] confirmed $mt=1000000000
2023-03-22 09:55:17.804 GcodeDriver DEBUG: [serial://COM3] >> G21 G90 G92 X0 Y0 Z0 A0 M8 M5, 20000
2023-03-22 09:55:17.814 GcodeDriver$ReaderThread TRACE: [serial://COM3] << tinyg [mm] ok>
2023-03-22 09:55:17.815 GcodeDriver TRACE: [serial://COM3] confirmed G21 G90 G92 X0 Y0 Z0 A0 M8 M5
2023-03-22 09:55:17.815 GcodeDriver DEBUG: [serial://COM3] >> $xjm=1000, 20000
2023-03-22 09:55:17.838 GcodeDriver$ReaderThread TRACE: [serial://COM3] << [xjm] x jerk maximum           1000 mm/min^3 * 1 million
2023-03-22 09:55:17.839 GcodeDriver$ReaderThread TRACE: [serial://COM3] << tinyg [mm] ok>
2023-03-22 09:55:17.841 GcodeDriver TRACE: [serial://COM3] confirmed $xjm=1000
2023-03-22 09:55:17.841 GcodeDriver DEBUG: [serial://COM3] >> $xvm=10000, 20000
2023-03-22 09:55:17.854 GcodeDriver$ReaderThread TRACE: [serial://COM3] << [xvm] x velocity maximum      10000 mm/min
2023-03-22 09:55:17.855 GcodeDriver$ReaderThread TRACE: [serial://COM3] << tinyg [mm] ok>
2023-03-22 09:55:17.855 GcodeDriver TRACE: [serial://COM3] confirmed $xvm=10000
2023-03-22 09:55:17.856 GcodeDriver DEBUG: [serial://COM3] >> $xsv=1000, 20000
2023-03-22 09:55:17.871 GcodeDriver$ReaderThread TRACE: [serial://COM3] << [xsv] x search velocity        1000 mm/min
2023-03-22 09:55:17.873 GcodeDriver$ReaderThread TRACE: [serial://COM3] << tinyg [mm] ok>
2023-03-22 09:55:17.874 GcodeDriver TRACE: [serial://COM3] confirmed $xsv=1000
2023-03-22 09:55:17.874 GcodeDriver DEBUG: [serial://COM3] >> $xsn=3, 20000
2023-03-22 09:55:17.897 GcodeDriver$ReaderThread TRACE: [serial://COM3] << [xsn] x switch min                3 [0=off,1=homing,2=limit,3=limit+homing]
2023-03-22 09:55:17.900 GcodeDriver$ReaderThread TRACE: [serial://COM3] << tinyg [mm] ok>
2023-03-22 09:55:17.902 GcodeDriver TRACE: [serial://COM3] confirmed $xsn=3
2023-03-22 09:55:17.902 GcodeDriver DEBUG: [serial://COM3] >> $xjh=1000, 20000
2023-03-22 09:55:17.926 GcodeDriver$ReaderThread TRACE: [serial://COM3] << [xjh] x jerk homing            1000 mm/min^3 * 1 million
2023-03-22 09:55:17.928 GcodeDriver$ReaderThread TRACE: [serial://COM3] << tinyg [mm] ok>
2023-03-22 09:55:17.937 GcodeDriver TRACE: [serial://COM3] confirmed $xjh=1000
2023-03-22 09:55:17.937 GcodeDriver DEBUG: [serial://COM3] >> $xsx=2, 20000
2023-03-22 09:55:17.963 GcodeDriver$ReaderThread TRACE: [serial://COM3] << [xsx] x switch max                2 [0=off,1=homing,2=limit,3=limit+homing]
2023-03-22 09:55:17.967 GcodeDriver$ReaderThread TRACE: [serial://COM3] << tinyg [mm] ok>
2023-03-22 09:55:17.967 GcodeDriver TRACE: [serial://COM3] confirmed $xsx=2
2023-03-22 09:55:17.967 GcodeDriver DEBUG: [serial://COM3] >> $1mi=10, 20000
2023-03-22 09:55:17.995 GcodeDriver$ReaderThread TRACE: [serial://COM3] << [1mi] m1 microsteps              10 [1,2,4,8]
2023-03-22 09:55:17.996 GcodeDriver$ReaderThread TRACE: [serial://COM3] << *** WARNING *** Setting non-standard microstep value
2023-03-22 09:55:17.998 GcodeDriver$ReaderThread TRACE: [serial://COM3] << tinyg [mm] ok> *** WARNING *** Setting non-standard microstep value
2023-03-22 09:55:17.998 GcodeDriver TRACE: [serial://COM3] confirmed $1mi=10
2023-03-22 09:55:17.998 GcodeDriver DEBUG: [serial://COM3] >> $1sa=0.900, 20000
2023-03-22 09:55:18.013 GcodeDriver$ReaderThread TRACE: [serial://COM3] << [1sa] m1 step angle               0.900 deg
2023-03-22 09:55:18.017 GcodeDriver$ReaderThread TRACE: [serial://COM3] << tinyg [mm] ok>
2023-03-22 09:55:18.018 GcodeDriver TRACE: [serial://COM3] confirmed $1sa=0.900
2023-03-22 09:55:18.018 GcodeDriver DEBUG: [serial://COM3] >> $1tr=39.982, 20000
2023-03-22 09:55:18.028 GcodeDriver$ReaderThread TRACE: [serial://COM3] << [1tr] m1 travel per revolution   39.9820 mm
2023-03-22 09:55:18.031 GcodeDriver$ReaderThread TRACE: [serial://COM3] << tinyg [mm] ok>
2023-03-22 09:55:18.032 GcodeDriver TRACE: [serial://COM3] confirmed $1tr=39.982
2023-03-22 09:55:18.033 GcodeDriver DEBUG: [serial://COM3] >> $yjm=1000, 20000
2023-03-22 09:55:18.055 GcodeDriver$ReaderThread TRACE: [serial://COM3] << [yjm] y jerk maximum           1000 mm/min^3 * 1 million
2023-03-22 09:55:18.056 GcodeDriver$ReaderThread TRACE: [serial://COM3] << tinyg [mm] ok>
2023-03-22 09:55:18.058 GcodeDriver TRACE: [serial://COM3] confirmed $yjm=1000
2023-03-22 09:55:18.059 GcodeDriver DEBUG: [serial://COM3] >> $yvm=10000, 20000
2023-03-22 09:55:18.072 GcodeDriver$ReaderThread TRACE: [serial://COM3] << [yvm] y velocity maximum      10000 mm/min
2023-03-22 09:55:18.074 GcodeDriver$ReaderThread TRACE: [serial://COM3] << tinyg [mm] ok>
2023-03-22 09:55:18.074 GcodeDriver TRACE: [serial://COM3] confirmed $yvm=10000
2023-03-22 09:55:18.075 GcodeDriver DEBUG: [serial://COM3] >> $ysn=3, 20000
2023-03-22 09:55:18.098 GcodeDriver$ReaderThread TRACE: [serial://COM3] << [ysn] y switch min                3 [0=off,1=homing,2=limit,3=limit+homing]
2023-03-22 09:55:18.099 GcodeDriver$ReaderThread TRACE: [serial://COM3] << tinyg [mm] ok>
2023-03-22 09:55:18.099 GcodeDriver TRACE: [serial://COM3] confirmed $ysn=3
2023-03-22 09:55:18.099 GcodeDriver DEBUG: [serial://COM3] >> $ysx=2, 20000
2023-03-22 09:55:18.122 GcodeDriver$ReaderThread TRACE: [serial://COM3] << [ysx] y switch max                2 [0=off,1=homing,2=limit,3=limit+homing]
2023-03-22 09:55:18.122 GcodeDriver$ReaderThread TRACE: [serial://COM3] << tinyg [mm] ok>
2023-03-22 09:55:18.125 GcodeDriver TRACE: [serial://COM3] confirmed $ysx=2
2023-03-22 09:55:18.125 GcodeDriver DEBUG: [serial://COM3] >> $yjh=1000, 20000
2023-03-22 09:55:18.149 GcodeDriver$ReaderThread TRACE: [serial://COM3] << [yjh] y jerk homing            1000 mm/min^3 * 1 million
2023-03-22 09:55:18.149 GcodeDriver$ReaderThread TRACE: [serial://COM3] << tinyg [mm] ok>
2023-03-22 09:55:18.149 GcodeDriver TRACE: [serial://COM3] confirmed $yjh=1000
2023-03-22 09:55:18.150 GcodeDriver DEBUG: [serial://COM3] >> $ysv=1000, 20000
2023-03-22 09:55:18.164 GcodeDriver$ReaderThread TRACE: [serial://COM3] << [ysv] y search velocity        1000 mm/min
2023-03-22 09:55:18.165 GcodeDriver$ReaderThread TRACE: [serial://COM3] << tinyg [mm] ok>
2023-03-22 09:55:18.165 GcodeDriver TRACE: [serial://COM3] confirmed $ysv=1000
2023-03-22 09:55:18.165 GcodeDriver DEBUG: [serial://COM3] >> $2mi=10, 20000
2023-03-22 09:55:18.194 GcodeDriver$ReaderThread TRACE: [serial://COM3] << [2mi] m2 microsteps              10 [1,2,4,8]
2023-03-22 09:55:18.198 GcodeDriver$ReaderThread TRACE: [serial://COM3] << *** WARNING *** Setting non-standard microstep value
2023-03-22 09:55:18.202 GcodeDriver$ReaderThread TRACE: [serial://COM3] << tinyg [mm] ok> *** WARNING *** Setting non-standard microstep value
2023-03-22 09:55:18.205 GcodeDriver TRACE: [serial://COM3] confirmed $2mi=10
2023-03-22 09:55:18.206 GcodeDriver DEBUG: [serial://COM3] >> $2sa=0.900, 20000
2023-03-22 09:55:18.225 GcodeDriver$ReaderThread TRACE: [serial://COM3] << [2sa] m2 step angle               0.900 deg
2023-03-22 09:55:18.226 GcodeDriver$ReaderThread TRACE: [serial://COM3] << tinyg [mm] ok>
2023-03-22 09:55:18.226 GcodeDriver TRACE: [serial://COM3] confirmed $2sa=0.900
2023-03-22 09:55:18.226 GcodeDriver DEBUG: [serial://COM3] >> $2tr=39.97, 20000
2023-03-22 09:55:18.242 GcodeDriver$ReaderThread TRACE: [serial://COM3] << [2tr] m2 travel per revolution   39.9700 mm
2023-03-22 09:55:18.242 GcodeDriver$ReaderThread TRACE: [serial://COM3] << tinyg [mm] ok>
2023-03-22 09:55:18.243 GcodeDriver TRACE: [serial://COM3] confirmed $2tr=39.97
2023-03-22 09:55:18.243 GcodeDriver DEBUG: [serial://COM3] >> $zjm=200, 20000
2023-03-22 09:55:18.267 GcodeDriver$ReaderThread TRACE: [serial://COM3] << [zjm] z jerk maximum            200 mm/min^3 * 1 million
2023-03-22 09:55:18.270 GcodeDriver$ReaderThread TRACE: [serial://COM3] << tinyg [mm] ok>
2023-03-22 09:55:18.270 GcodeDriver TRACE: [serial://COM3] confirmed $zjm=200
2023-03-22 09:55:18.270 GcodeDriver DEBUG: [serial://COM3] >> $zvm=1000, 20000
2023-03-22 09:55:18.282 GcodeDriver$ReaderThread TRACE: [serial://COM3] << [zvm] z velocity maximum       1000 mm/min
2023-03-22 09:55:18.284 GcodeDriver$ReaderThread TRACE: [serial://COM3] << tinyg [mm] ok>
2023-03-22 09:55:18.284 GcodeDriver TRACE: [serial://COM3] confirmed $zvm=1000
2023-03-22 09:55:18.284 GcodeDriver DEBUG: [serial://COM3] >> $zjh=500, 20000
2023-03-22 09:55:18.307 GcodeDriver$ReaderThread TRACE: [serial://COM3] << [zjh] z jerk homing             500 mm/min^3 * 1 million
2023-03-22 09:55:18.307 GcodeDriver$ReaderThread TRACE: [serial://COM3] << tinyg [mm] ok>
2023-03-22 09:55:18.307 GcodeDriver TRACE: [serial://COM3] confirmed $zjh=500
2023-03-22 09:55:18.307 GcodeDriver DEBUG: [serial://COM3] >> $zsv=1000, 20000
2023-03-22 09:55:18.322 GcodeDriver$ReaderThread TRACE: [serial://COM3] << [zsv] z search velocity        1000 mm/min
2023-03-22 09:55:18.323 GcodeDriver$ReaderThread TRACE: [serial://COM3] << tinyg [mm] ok>
2023-03-22 09:55:18.323 GcodeDriver TRACE: [serial://COM3] confirmed $zsv=1000
2023-03-22 09:55:18.323 GcodeDriver DEBUG: [serial://COM3] >> $xfr=10000, 20000
2023-03-22 09:55:18.370 GcodeDriver$ReaderThread TRACE: [serial://COM3] << [xfr] x feedrate maximum      10000 mm/min
2023-03-22 09:55:18.371 GcodeDriver$ReaderThread TRACE: [serial://COM3] << tinyg [mm] ok>
2023-03-22 09:55:18.373 GcodeDriver TRACE: [serial://COM3] confirmed $xfr=10000
2023-03-22 09:55:18.373 GcodeDriver DEBUG: [serial://COM3] >> $yfr=10000, 20000
2023-03-22 09:55:18.419 GcodeDriver$ReaderThread TRACE: [serial://COM3] << [yfr] y feedrate maximum      10000 mm/min
2023-03-22 09:55:18.421 GcodeDriver$ReaderThread TRACE: [serial://COM3] << tinyg [mm] ok>
2023-03-22 09:55:18.423 GcodeDriver TRACE: [serial://COM3] confirmed $yfr=10000
2023-03-22 09:55:18.424 GcodeDriver DEBUG: [serial://COM3] >> $zfr=1000, 20000
2023-03-22 09:55:18.435 GcodeDriver$ReaderThread TRACE: [serial://COM3] << [zfr] z feedrate maximum       1000 mm/min
2023-03-22 09:55:18.439 GcodeDriver$ReaderThread TRACE: [serial://COM3] << tinyg [mm] ok>
2023-03-22 09:55:18.440 GcodeDriver TRACE: [serial://COM3] confirmed $zfr=1000
2023-03-22 09:55:18.440 GcodeDriver DEBUG: [serial://COM3] >> $afr=300000, 20000
2023-03-22 09:55:18.467 GcodeDriver$ReaderThread TRACE: [serial://COM3] << [afr] a feedrate maximum     300000 deg/min
2023-03-22 09:55:18.467 GcodeDriver$ReaderThread TRACE: [serial://COM3] << tinyg [mm] ok>
2023-03-22 09:55:18.467 GcodeDriver TRACE: [serial://COM3] confirmed $afr=300000
2023-03-22 09:55:18.467 GcodeDriver DEBUG: [serial://COM3] >> $3mi=8, 20000
2023-03-22 09:55:18.491 GcodeDriver$ReaderThread TRACE: [serial://COM3] << [3mi] m3 microsteps               8 [1,2,4,8]
2023-03-22 09:55:18.492 GcodeDriver$ReaderThread TRACE: [serial://COM3] << tinyg [mm] ok>
2023-03-22 09:55:18.494 GcodeDriver TRACE: [serial://COM3] confirmed $3mi=8
2023-03-22 09:55:18.496 GcodeDriver DEBUG: [serial://COM3] >> $3sa=1.800, 20000
2023-03-22 09:55:18.507 GcodeDriver$ReaderThread TRACE: [serial://COM3] << [3sa] m3 step angle               1.800 deg
2023-03-22 09:55:18.507 GcodeDriver$ReaderThread TRACE: [serial://COM3] << tinyg [mm] ok>
2023-03-22 09:55:18.507 GcodeDriver TRACE: [serial://COM3] confirmed $3sa=1.800
2023-03-22 09:55:18.508 GcodeDriver DEBUG: [serial://COM3] >> $3tr=8.0000, 20000
2023-03-22 09:55:18.523 GcodeDriver$ReaderThread TRACE: [serial://COM3] << [3tr] m3 travel per revolution    8.0000 mm
2023-03-22 09:55:18.523 GcodeDriver$ReaderThread TRACE: [serial://COM3] << tinyg [mm] ok>
2023-03-22 09:55:18.523 GcodeDriver TRACE: [serial://COM3] confirmed $3tr=8.0000
2023-03-22 09:55:18.523 GcodeDriver DEBUG: [serial://COM3] >> $ajm=25000, 20000
2023-03-22 09:55:18.547 GcodeDriver$ReaderThread TRACE: [serial://COM3] << [ajm] a jerk maximum          25000 deg/min^3 * 1 million
2023-03-22 09:55:18.548 GcodeDriver$ReaderThread TRACE: [serial://COM3] << tinyg [mm] ok>
2023-03-22 09:55:18.549 GcodeDriver TRACE: [serial://COM3] confirmed $ajm=25000
2023-03-22 09:55:18.549 GcodeDriver DEBUG: [serial://COM3] >> $avm=300000, 20000
2023-03-22 09:55:18.564 GcodeDriver$ReaderThread TRACE: [serial://COM3] << [avm] a velocity maximum     300000 deg/min
2023-03-22 09:55:18.565 GcodeDriver$ReaderThread TRACE: [serial://COM3] << tinyg [mm] ok>
2023-03-22 09:55:18.565 GcodeDriver TRACE: [serial://COM3] confirmed $avm=300000
2023-03-22 09:55:18.565 GcodeDriver DEBUG: [serial://COM3] >> $4mi=8, 20000
2023-03-22 09:55:18.588 GcodeDriver$ReaderThread TRACE: [serial://COM3] << [4mi] m4 microsteps               8 [1,2,4,8]
2023-03-22 09:55:18.588 GcodeDriver$ReaderThread TRACE: [serial://COM3] << tinyg [mm] ok>
2023-03-22 09:55:18.588 GcodeDriver TRACE: [serial://COM3] confirmed $4mi=8
2023-03-22 09:55:18.589 GcodeDriver DEBUG: [serial://COM3] >> $4sa=0.900, 20000
2023-03-22 09:55:18.604 GcodeDriver$ReaderThread TRACE: [serial://COM3] << [4sa] m4 step angle               0.900 deg
2023-03-22 09:55:18.606 GcodeDriver$ReaderThread TRACE: [serial://COM3] << tinyg [mm] ok>
2023-03-22 09:55:18.607 GcodeDriver TRACE: [serial://COM3] confirmed $4sa=0.900
2023-03-22 09:55:18.607 GcodeDriver DEBUG: [serial://COM3] >> $4tr=160.0000, 20000
2023-03-22 09:55:18.620 GcodeDriver$ReaderThread TRACE: [serial://COM3] << [4tr] m4 travel per revolution  160.0000 mm
2023-03-22 09:55:18.620 GcodeDriver$ReaderThread TRACE: [serial://COM3] << tinyg [mm] ok>
2023-03-22 09:55:18.620 GcodeDriver TRACE: [serial://COM3] confirmed $4tr=160.0000
2023-03-22 09:55:18.620 GcodeDriver DEBUG: [serial://COM3] >> $mt=300.00, 20000
2023-03-22 09:55:18.668 GcodeDriver$ReaderThread TRACE: [serial://COM3] << [mt]  motor idle timeout        300.00 Sec
2023-03-22 09:55:18.672 GcodeDriver$ReaderThread TRACE: [serial://COM3] << tinyg [mm] ok>
2023-03-22 09:55:18.675 GcodeDriver TRACE: [serial://COM3] confirmed $mt=300.00
2023-03-22 09:55:18.675 GcodeDriver DEBUG: [serial://COM3] >> $zzb=2, 20000
2023-03-22 09:55:18.684 GcodeDriver$ReaderThread TRACE: [serial://COM3] << [zzb] z zero backoff              2.000 mm
2023-03-22 09:55:18.684 GcodeDriver$ReaderThread TRACE: [serial://COM3] << tinyg [mm] ok>
2023-03-22 09:55:18.685 GcodeDriver TRACE: [serial://COM3] confirmed $zzb=2
2023-03-22 09:55:18.685 GcodeDriver DEBUG: [serial://COM3] >> $3po=1, 20000
2023-03-22 09:55:18.708 GcodeDriver$ReaderThread TRACE: [serial://COM3] << [3po] m3 polarity                 1 [0=normal,1=reverse]
2023-03-22 09:55:18.708 GcodeDriver$ReaderThread TRACE: [serial://COM3] << tinyg [mm] ok>
2023-03-22 09:55:18.709 GcodeDriver TRACE: [serial://COM3] confirmed $3po=1
2023-03-22 09:55:18.709 GcodeDriver DEBUG: [serial://COM3] >> $zsx=3, 20000
2023-03-22 09:55:18.732 GcodeDriver$ReaderThread TRACE: [serial://COM3] << [zsx] z switch max                3 [0=off,1=homing,2=limit,3=limit+homing]
2023-03-22 09:55:18.733 GcodeDriver$ReaderThread TRACE: [serial://COM3] << tinyg [mm] ok>
2023-03-22 09:55:18.735 GcodeDriver TRACE: [serial://COM3] confirmed $zsx=3
2023-03-22 09:55:18.735 GcodeDriver DEBUG: [serial://COM3] >> $zsn=0, 20000
2023-03-22 09:55:18.758 GcodeDriver$ReaderThread TRACE: [serial://COM3] << [zsn] z switch min                0 [0=off,1=homing,2=limit,3=limit+homing]
2023-03-22 09:55:18.759 GcodeDriver$ReaderThread TRACE: [serial://COM3] << tinyg [mm] ok>
2023-03-22 09:55:18.759 GcodeDriver TRACE: [serial://COM3] confirmed $zsn=0
2023-03-22 09:55:18.759 GcodeDriver DEBUG: [serial://COM3] >> $xfr=12000, 20000
2023-03-22 09:55:18.806 GcodeDriver$ReaderThread TRACE: [serial://COM3] << [xfr] x feedrate maximum      12000 mm/min
2023-03-22 09:55:18.810 GcodeDriver$ReaderThread TRACE: [serial://COM3] << tinyg [mm] ok>
2023-03-22 09:55:18.810 GcodeDriver TRACE: [serial://COM3] confirmed $xfr=12000
2023-03-22 09:55:18.810 GcodeDriver DEBUG: [serial://COM3] >> $yfr=12000, 20000
2023-03-22 09:55:18.854 GcodeDriver$ReaderThread TRACE: [serial://COM3] << [yfr] y feedrate maximum      12000 mm/min
2023-03-22 09:55:18.870 GcodeDriver$ReaderThread TRACE: [serial://COM3] << tinyg [mm] ok>
2023-03-22 09:55:18.871 GcodeDriver TRACE: [serial://COM3] confirmed $yfr=12000
2023-03-22 09:55:18.872 GcodeDriver DEBUG: [serial://COM3] >> $1pm=1, 20000
2023-03-22 09:55:18.928 GcodeDriver$ReaderThread TRACE: [serial://COM3] << [1pm] m1 power management         1 [0=disabled,1=always on,2=in cycle,3=when moving]
2023-03-22 09:55:18.929 GcodeDriver$ReaderThread TRACE: [serial://COM3] << tinyg [mm] ok>
2023-03-22 09:55:18.931 GcodeDriver TRACE: [serial://COM3] confirmed $1pm=1
2023-03-22 09:55:18.932 GcodeDriver DEBUG: [serial://COM3] >> $2pm=1, 20000
2023-03-22 09:55:18.988 GcodeDriver$ReaderThread TRACE: [serial://COM3] << [2pm] m2 power management         1 [0=disabled,1=always on,2=in cycle,3=when moving]
2023-03-22 09:55:18.989 GcodeDriver$ReaderThread TRACE: [serial://COM3] << tinyg [mm] ok>
2023-03-22 09:55:18.991 GcodeDriver TRACE: [serial://COM3] confirmed $2pm=1
2023-03-22 09:55:18.992 GcodeDriver DEBUG: [serial://COM3] >> $3pm=1, 20000
2023-03-22 09:55:19.048 GcodeDriver$ReaderThread TRACE: [serial://COM3] << [3pm] m3 power management         1 [0=disabled,1=always on,2=in cycle,3=when moving]
2023-03-22 09:55:19.048 GcodeDriver$ReaderThread TRACE: [serial://COM3] << tinyg [mm] ok>
2023-03-22 09:55:19.052 GcodeDriver TRACE: [serial://COM3] confirmed $3pm=1
2023-03-22 09:55:19.053 GcodeDriver DEBUG: [serial://COM3] >> $4pm=1, 20000
2023-03-22 09:55:19.109 GcodeDriver$ReaderThread TRACE: [serial://COM3] << [4pm] m4 power management         1 [0=disabled,1=always on,2=in cycle,3=when moving]
2023-03-22 09:55:19.109 GcodeDriver$ReaderThread TRACE: [serial://COM3] << tinyg [mm] ok>
2023-03-22 09:55:19.117 GcodeDriver TRACE: [serial://COM3] confirmed $4pm=1
2023-03-22 09:55:19.117 GcodeDriver DEBUG: [serial://COM3] >> G21 M9, 20000
2023-03-22 09:55:19.125 GcodeDriver$ReaderThread TRACE: [serial://COM3] << tinyg [mm] ok>
2023-03-22 09:55:19.126 GcodeDriver TRACE: [serial://COM3] confirmed G21 M9
2023-03-22 09:56:10.404 ReferenceMachine DEBUG: homing machine
2023-03-22 09:56:10.411 GcodeDriver DEBUG: [serial://COM3] >> G28.2 X0 Y0 Z0, -1
2023-03-22 09:56:10.440 GcodeDriver$ReaderThread TRACE: [serial://COM3] << tinyg [mm] ok>
2023-03-22 09:56:10.440 GcodeDriver TRACE: [serial://COM3] confirmed G28.2 X0 Y0 Z0
2023-03-22 09:56:10.440 GcodeDriver DEBUG: [serial://COM3] >> G28.3 X0 Y0 Z0, -1
2023-03-22 09:56:10.441 GcodeDriver$ReaderThread TRACE: [serial://COM3] << posx:0.000,posy:0.000,posz:0.000,posa:0.000,feed:0.00,vel:0.00,unit:1,coor:0,dist:1,frmo:1,stat:9
2023-03-22 09:56:10.932 GcodeDriver$ReaderThread TRACE: [serial://COM3] << posx:0.000,posy:0.000,posz:-4.954,posa:0.000,feed:1000.00,vel:146.36,unit:1,coor:0,dist:1,frmo:1,stat:9
2023-03-22 09:56:11.007 GcodeDriver$ReaderThread TRACE: [serial://COM3] << posx:0.000,posy:0.000,posz:-5.000,posa:0.000,feed:1000.00,vel:0.00,unit:1,coor:0,dist:1,frmo:1,stat:9
2023-03-22 09:56:11.498 GcodeDriver$ReaderThread TRACE: [serial://COM3] << posx:0.000,posy:0.000,posz:1.659,posa:0.000,feed:1000.00,vel:1000.00,unit:1,coor:0,dist:1,frmo:1,stat:9
2023-03-22 09:56:11.984 GcodeDriver$ReaderThread TRACE: [serial://COM3] << posx:0.000,posy:0.000,posz:9.817,posa:0.000,feed:1000.00,vel:1000.00,unit:1,coor:0,dist:1,frmo:1,stat:9
2023-03-22 09:56:12.471 GcodeDriver$ReaderThread TRACE: [serial://COM3] << posx:0.000,posy:0.000,posz:17.892,posa:0.000,feed:1000.00,vel:1000.00,unit:1,coor:0,dist:1,frmo:1,stat:9
2023-03-22 09:56:12.959 GcodeDriver$ReaderThread TRACE: [serial://COM3] << posx:0.000,posy:0.000,posz:26.051,posa:0.000,feed:1000.00,vel:1000.00,unit:1,coor:0,dist:1,frmo:1,stat:9
2023-03-22 09:56:13.446 GcodeDriver$ReaderThread TRACE: [serial://COM3] << posx:0.000,posy:0.000,posz:33.640,posa:0.000,feed:1000.00,vel:263.19,unit:1,coor:0,dist:1,frmo:1,stat:9
2023-03-22 09:56:13.516 GcodeDriver$ReaderThread TRACE: [serial://COM3] << posx:0.000,posy:0.000,posz:33.709,posa:0.000,feed:1000.00,vel:0.03,unit:1,coor:0,dist:1,frmo:1,stat:9
2023-03-22 09:56:13.517 GcodeDriver$ReaderThread TRACE: [serial://COM3] << tinyg [mm] ok>
2023-03-22 09:56:13.529 GcodeDriver$ReaderThread TRACE: [serial://COM3] << posx:0.000,posy:0.000,posz:0.000,posa:0.000,feed:0.00,vel:0.00,unit:1,coor:1,dist:0,frmo:1,stat:3
2023-03-22 09:56:13.529 GcodeDriver TRACE: [serial://COM3] confirmed G28.3 X0 Y0 Z0
2023-03-22 09:56:13.532 GcodeDriver DEBUG: [serial://COM3] >> M400 ; Wait for moves to complete before returning, -1
2023-03-22 09:56:13.547 GcodeDriver$ReaderThread TRACE: [serial://COM3] << tinyg [mm] ok>
2023-03-22 09:56:13.551 GcodeDriver TRACE: [serial://COM3] confirmed M400 ; Wait for moves to complete before returning
2023-03-22 09:56:13.560 ReferenceHead DEBUG: H1.home()
2023-03-22 09:56:13.563 ReferenceFiducialLocator DEBUG: Looking for FIDUCIAL-HOME at (0.000000, 0.000000, -22.500000, 0.000000 mm)
2023-03-22 09:56:13.566 ReferenceHead DEBUG: H1.moveToSafeZ(1.0)
2023-03-22 09:56:13.567 AbstractHeadMountable DEBUG: N.moveToSafeZ(1.0)
2023-03-22 09:56:13.569 AbstractHeadMountable DEBUG: Down Camera.moveToSafeZ(1.0)
2023-03-22 09:56:13.572 AbstractHeadMountable DEBUG: Down Camera.moveTo((0.000000, 0.000000, 0.000000, 0.000000 mm), 1.0)
2023-03-22 09:56:13.643 GcodeDriver DEBUG: [serial://COM3] >> M201.3 X340 Y1000, 20000
2023-03-22 09:56:13.660 GcodeDriver$ReaderThread TRACE: [serial://COM3] << tinyg [mm] ok>
2023-03-22 09:56:13.662 GcodeDriver TRACE: [serial://COM3] confirmed M201.3 X340 Y1000
2023-03-22 09:56:13.663 GcodeDriver DEBUG: [serial://COM3] >> G1 X0.3420 Y-1.0069   F401.02 ; move to target, 20000
2023-03-22 09:56:13.675 GcodeDriver$ReaderThread TRACE: [serial://COM3] << tinyg [mm] ok>
2023-03-22 09:56:13.677 GcodeDriver TRACE: [serial://COM3] confirmed G1 X0.3420 Y-1.0069   F401.02 ; move to target
2023-03-22 09:56:13.682 GcodeDriver DEBUG: [serial://COM3] >> M400 ; Wait for moves to complete before returning, 20000
2023-03-22 09:56:14.005 GcodeDriver$ReaderThread TRACE: [serial://COM3] << posx:0.342,posy:-1.007,posz:0.000,posa:0.000,feed:401.02,vel:0.00,unit:1,coor:1,dist:0,frmo:1,stat:3
2023-03-22 09:56:14.005 GcodeDriver$ReaderThread TRACE: [serial://COM3] << tinyg [mm] ok>
2023-03-22 09:56:14.008 GcodeDriver TRACE: [serial://COM3] confirmed M400 ; Wait for moves to complete before returning
2023-03-22 09:56:14.009 AbstractHeadMountable DEBUG: Down Camera.moveTo((0.000000, 0.000000, -22.500000, 0.000000 mm), 1.0)
2023-03-22 09:56:14.033 Scripting TRACE: Scripting.on Camera.BeforeSettle
2023-03-22 09:56:16.054 Scripting TRACE: Scripting.on Camera.BeforeCapture
2023-03-22 09:56:16.094 Scripting TRACE: Scripting.on Camera.AfterCapture
2023-03-22 09:56:16.099 Scripting TRACE: Scripting.on Camera.AfterSettle
2023-03-22 09:56:16.661 AbstractMachine TRACE: Exception caught, executing pending motion: java.lang.Exception: FIDUCIAL-HOME no matches found.
	at org.openpnp.machine.reference.vision.ReferenceFiducialLocator.getFiducialLocation(ReferenceFiducialLocator.java:442)
	at org.openpnp.machine.reference.vision.ReferenceFiducialLocator.getHomeFiducialLocation(ReferenceFiducialLocator.java:327)
	at org.openpnp.machine.reference.ReferenceHead.visualHome(ReferenceHead.java:76)
	at org.openpnp.machine.reference.ReferenceHead.home(ReferenceHead.java:55)
	at org.openpnp.spi.base.AbstractMachine.home(AbstractMachine.java:301)
	at org.openpnp.machine.reference.ReferenceMachine.home(ReferenceMachine.java:491)
	at org.openpnp.gui.MachineControlsPanel$HomeAction.lambda$actionPerformed$0(MachineControlsPanel.java:333)
	at org.openpnp.util.UiUtils.lambda$submitUiMachineTask$0(UiUtils.java:39)
	at org.openpnp.spi.base.AbstractMachine$1.call(AbstractMachine.java:571)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at java.lang.Thread.run(Thread.java:748)
2023-03-22 09:56:16.665 MessageBoxes DEBUG: Error: java.lang.Exception: FIDUCIAL-HOME no matches found.