2024-04-04 06:49:55.219 Main INFO: Bienvenue, Bienvenido, Willkommen, Hello, Namaskar, Welkom, Bonjour to OpenPnP version 2024-03-27_09-59-31.0b0aca0. 2024-04-04 06:49:55.221 Scripting TRACE: Scripting.on Startup 2024-04-04 06:49:56.822 AbstractBroadcastingCamera TRACE: Camera DOWN thread 49 started. 2024-04-04 06:49:58.929 AbstractBroadcastingCamera TRACE: Camera Up_Logitech thread 51 started. 2024-04-04 06:50:01.310 ReferenceMachine DEBUG: setEnabled(true) 2024-04-04 06:50:01.312 GcodeDriver DEBUG: [Smoothie:COM4] Connect 2024-04-04 06:50:01.350 GcodeDriver TRACE: Smoothie waiting for connection 15000ms 2024-04-04 06:50:16.351 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> G21 ; 2024-04-04 06:50:16.352 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> G90 ; Set absolute positioning mode 2024-04-04 06:50:16.353 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 06:50:16.352 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> G21 ; 2024-04-04 06:50:16.363 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M82 ; Set absolute mode for extruder 2024-04-04 06:50:16.364 GcodeDriver TRACE: Send-on-change logic for Feed Rate, Acceleration and Jerk reset 2024-04-04 06:50:16.364 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> G90 ; Set absolute positioning mode 2024-04-04 06:50:16.364 GcodeDriver DEBUG: [Schultz:COM3] Connect 2024-04-04 06:50:16.364 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M82 ; Set absolute mode for extruder 2024-04-04 06:50:16.364 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 06:50:16.365 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 06:50:16.374 GcodeDriver TRACE: Schultz waiting for connection 3000ms 2024-04-04 06:50:16.438 GcodeDriver$ReaderThread TRACE: [Schultz:COM3] << Controller starting... 2024-04-04 06:50:16.440 GcodeDriver$ReaderThread TRACE: [Schultz:COM3] << Controller ready. 2024-04-04 06:50:19.375 GcodeAsyncDriver DEBUG: [Schultz:COM3] commandQueue offer >> G21 ; Set millimeters mode 2024-04-04 06:50:19.375 GcodeAsyncDriver DEBUG: [Schultz:COM3] commandQueue offer >> G90 ; Set absolute positioning mode 2024-04-04 06:50:19.375 GcodeDriver TRACE: Send-on-change logic for Feed Rate, Acceleration and Jerk reset 2024-04-04 06:50:19.375 GcodeAsyncDriver$WriterThread TRACE: [Schultz:COM3] >> G21 ; Set millimeters mode 2024-04-04 06:50:19.378 GcodeDriver$ReaderThread TRACE: [Schultz:COM3] << G21 ; Set millimeters mode 2024-04-04 06:50:19.381 GcodeDriver$ReaderThread TRACE: [Schultz:COM3] << ok unknown or empty command ignored 2024-04-04 06:50:19.381 GcodeDriver TRACE: [Schultz:COM3] confirmed G21 ; Set millimeters mode 2024-04-04 06:50:19.381 GcodeAsyncDriver$WriterThread TRACE: [Schultz:COM3] >> G90 ; Set absolute positioning mode 2024-04-04 06:50:19.385 GcodeDriver$ReaderThread TRACE: [Schultz:COM3] << G90 ; Set absolute positioning mode 2024-04-04 06:50:19.388 GcodeDriver$ReaderThread TRACE: [Schultz:COM3] << ok unknown or empty command ignored 2024-04-04 06:50:19.389 AbstractMachine TRACE: Machine entering idle state. 2024-04-04 06:51:01.879 ReferenceMachine DEBUG: homing machine 2024-04-04 06:51:01.881 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S1000 ; set a low acceleration 2024-04-04 06:51:01.881 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> G28 A0 Z0 2024-04-04 06:51:01.881 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> G28 X88 Y42 B0 C0; Home all axes 2024-04-04 06:51:01.881 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> G92 X0 Y0 Z0 A0 B0 C0; Set coordinates to zero. 2024-04-04 06:51:01.882 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S1000 ; set a low acceleration 2024-04-04 06:51:01.882 GcodeDriver TRACE: Send-on-change logic for Feed Rate, Acceleration and Jerk reset 2024-04-04 06:51:01.882 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> G28 A0 Z0 2024-04-04 06:51:01.882 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 06:51:01.882 GcodeAsyncDriver DEBUG: [Schultz:COM3] commandQueue offer >> G28 ; Home all axes 2024-04-04 06:51:01.882 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> G28 X88 Y42 B0 C0; Home all axes 2024-04-04 06:51:01.882 GcodeDriver TRACE: [Schultz:COM3] confirmed G90 ; Set absolute positioning mode 2024-04-04 06:51:01.882 GcodeDriver TRACE: Send-on-change logic for Feed Rate, Acceleration and Jerk reset 2024-04-04 06:51:01.882 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> G92 X0 Y0 Z0 A0 B0 C0; Set coordinates to zero. 2024-04-04 06:51:01.882 GcodeAsyncDriver$WriterThread TRACE: [Schultz:COM3] >> G28 ; Home all axes 2024-04-04 06:51:01.883 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M400 ; Wait for moves to complete before returning 2024-04-04 06:51:01.883 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M114 ; get position 2024-04-04 06:51:01.883 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M400 ; Wait for moves to complete before returning 2024-04-04 06:51:01.883 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M114 ; get position 2024-04-04 06:51:01.884 GcodeDriver$ReaderThread TRACE: [Schultz:COM3] << G28 ; Home all axes 2024-04-04 06:51:01.888 GcodeDriver$ReaderThread TRACE: [Schultz:COM3] << ok unknown or empty command ignored 2024-04-04 06:51:02.961 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 06:51:07.121 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 06:51:07.121 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 06:51:07.121 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 06:51:07.122 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok C: X:0.0000 Y:0.0000 Z:0.0000 A:0.0000 B:0.0000 C:0.0000 2024-04-04 06:51:07.122 GcodeDriver TRACE: Position report: ok C: X:0.0000 Y:0.0000 Z:0.0000 A:0.0000 B:0.0000 C:0.0000 2024-04-04 06:51:07.122 GcodeDriver TRACE: Smoothie got lastReportedLocation (x:0.000000, y:0.000000, z1:0.000000, z2:0.000000, c1:0.000000, c2:0.000000) 2024-04-04 06:51:07.122 GcodeAsyncDriver TRACE: Smoothie confirmation complete. 2024-04-04 06:51:07.122 GcodeAsyncDriver DEBUG: [Schultz:COM3] commandQueue offer >> M400 ; Wait for moves to complete before returning 2024-04-04 06:51:07.124 GcodeDriver TRACE: [Schultz:COM3] confirmed G28 ; Home all axes 2024-04-04 06:51:07.124 GcodeAsyncDriver$WriterThread TRACE: [Schultz:COM3] >> M400 ; Wait for moves to complete before returning 2024-04-04 06:51:07.128 GcodeDriver$ReaderThread TRACE: [Schultz:COM3] << M400 ; Wait for moves to complete before returning 2024-04-04 06:51:07.131 GcodeDriver$ReaderThread TRACE: [Schultz:COM3] << ok unknown or empty command ignored 2024-04-04 06:51:07.131 GcodeDriver TRACE: [Schultz:COM3] confirmed M400 ; Wait for moves to complete before returning 2024-04-04 06:51:07.131 GcodeAsyncDriver TRACE: Schultz waited 9ms to drain command queue. 2024-04-04 06:51:07.131 GcodeAsyncDriver TRACE: Schultz confirmation complete. 2024-04-04 06:51:07.132 ReferenceHead DEBUG: H1.home() 2024-04-04 06:51:07.132 ReferenceFiducialLocator DEBUG: Looking for FIDUCIAL-HOME at (110.000000, 43.500000, -25.000000, 0.000000 mm) 2024-04-04 06:51:07.133 ReferenceHead DEBUG: H1.moveToSafeZ(0.9) 2024-04-04 06:51:07.134 AbstractHeadMountable DEBUG: N1.moveToSafeZ(0.9) 2024-04-04 06:51:07.134 AbstractHeadMountable DEBUG: N2.moveToSafeZ(0.9) 2024-04-04 06:51:07.134 AbstractHeadMountable DEBUG: N3.moveToSafeZ(0.9) 2024-04-04 06:51:07.134 AbstractHeadMountable DEBUG: N4.moveToSafeZ(0.9) 2024-04-04 06:51:07.134 AbstractHeadMountable DEBUG: DOWN.moveToSafeZ(0.9) 2024-04-04 06:51:07.135 AbstractHeadMountable DEBUG: DOWN.moveTo((110.000000, 43.500000, 0.000000, 0.000000 mm), 0.9) 2024-04-04 06:51:07.144 AbstractHeadMountable DEBUG: DOWN.moveTo((110.000000, 43.500000, -25.000000, 0.000000 mm), 0.9) 2024-04-04 06:51:07.151 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S2611 G1 X109.3513 Y42.9913 F33233 ; move to target 2024-04-04 06:51:07.152 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S2611 G1 X109.3513 Y42.9913 F33233 ; move to target 2024-04-04 06:51:07.153 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S94 G1 X109.3213 Y43.4438 F392 ; move to target 2024-04-04 06:51:07.153 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 06:51:07.153 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S94 G1 X109.3213 Y43.4438 F392 ; move to target 2024-04-04 06:51:07.154 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M400 ; Wait for moves to complete before returning 2024-04-04 06:51:07.156 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 06:51:07.156 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M114 ; get position 2024-04-04 06:51:07.157 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M400 ; Wait for moves to complete before returning 2024-04-04 06:51:07.157 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M114 ; get position 2024-04-04 06:51:07.688 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 06:51:07.689 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok C: X:109.3213 Y:43.4438 Z:0.0000 A:0.0000 B:0.0000 C:0.0000 2024-04-04 06:51:07.689 GcodeDriver TRACE: Position report: ok C: X:109.3213 Y:43.4438 Z:0.0000 A:0.0000 B:0.0000 C:0.0000 2024-04-04 06:51:07.689 GcodeDriver TRACE: Smoothie got lastReportedLocation (x:109.321300, y:43.443800, z1:0.000000, z2:0.000000, c1:0.000000, c2:0.000000) 2024-04-04 06:51:07.690 GcodeAsyncDriver TRACE: Smoothie confirmation complete. 2024-04-04 06:51:07.690 ReferenceActuator DEBUG: UpCamLight.actuate(false) 2024-04-04 06:51:07.691 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M811 ; turn off Light 2024-04-04 06:51:07.691 Scripting TRACE: Scripting.on Camera.BeforeSettle 2024-04-04 06:51:07.691 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M811 ; turn off Light 2024-04-04 06:51:07.693 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 06:51:07.694 Scripting TRACE: Scripting.on Camera.BeforeCapture 2024-04-04 06:51:07.708 Scripting TRACE: Scripting.on Camera.AfterCapture 2024-04-04 06:51:07.716 Scripting TRACE: Scripting.on Camera.BeforeCapture 2024-04-04 06:51:07.734 Scripting TRACE: Scripting.on Camera.AfterCapture 2024-04-04 06:51:07.742 AbstractSettlingCamera TRACE: autoSettleAndCapture t=46 auto settle score: 93.333 compute time: 5 2024-04-04 06:51:07.742 Scripting TRACE: Scripting.on Camera.BeforeCapture 2024-04-04 06:51:07.766 Scripting TRACE: Scripting.on Camera.AfterCapture 2024-04-04 06:51:07.774 AbstractSettlingCamera TRACE: autoSettleAndCapture t=81 auto settle score: 18.431 compute time: 7 2024-04-04 06:51:07.775 Scripting TRACE: Scripting.on Camera.BeforeCapture 2024-04-04 06:51:07.797 Scripting TRACE: Scripting.on Camera.AfterCapture 2024-04-04 06:51:07.801 AbstractSettlingCamera TRACE: autoSettleAndCapture t=107 auto settle score: 26.275 compute time: 3 2024-04-04 06:51:07.802 AbstractSettlingCamera DEBUG: autoSettleAndCapture in 108 ms 2024-04-04 06:51:07.802 Scripting TRACE: Scripting.on Camera.AfterSettle 2024-04-04 06:51:07.823 CvPipeline DEBUG: Stage "6" throws CvException [org.opencv.core.CvException: cv::Exception: OpenCV(4.5.5) C:\build\master_winpack-bindings-win64-vc14-static\opencv\modules\imgproc\src\thresh.cpp:1555: error: (-2:Unspecified error) in function 'double __cdecl cv::threshold(const class cv::_InputArray &,const class cv::_OutputArray &,double,double,int)' > THRESH_OTSU mode: > 'src_type == CV_8UC1 || src_type == CV_16UC1' > where > 'src_type' is 16 (CV_8UC3) ] 2024-04-04 06:51:07.866 ReferenceFiducialLocator DEBUG: FIDUCIAL-HOME located at (112.652663, 44.936028, -25.000000, 0.000000 mm) 2024-04-04 06:51:07.867 AbstractHeadMountable DEBUG: DOWN.moveTo((112.652663, 44.936028, -25.000000, 0.000000 mm), 0.9) 2024-04-04 06:51:07.872 Scripting TRACE: Scripting.on Camera.BeforeSettle 2024-04-04 06:51:07.875 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S2588 G1 X112.0040 Y44.4273 F5160 ; move to target 2024-04-04 06:51:07.876 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S2588 G1 X112.0040 Y44.4273 F5160 ; move to target 2024-04-04 06:51:07.876 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S94 G1 X111.9739 Y44.8798 F392 ; move to target 2024-04-04 06:51:07.876 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 06:51:07.876 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M400 ; Wait for moves to complete before returning 2024-04-04 06:51:07.877 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S94 G1 X111.9739 Y44.8798 F392 ; move to target 2024-04-04 06:51:07.877 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M400 ; Wait for moves to complete before returning 2024-04-04 06:51:07.877 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M114 ; get position 2024-04-04 06:51:07.877 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M114 ; get position 2024-04-04 06:51:07.878 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 06:51:08.051 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 06:51:08.052 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok C: X:111.9739 Y:44.8798 Z:0.0000 A:0.0000 B:0.0000 C:0.0000 2024-04-04 06:51:08.053 GcodeDriver TRACE: Position report: ok C: X:111.9739 Y:44.8798 Z:0.0000 A:0.0000 B:0.0000 C:0.0000 2024-04-04 06:51:08.053 GcodeDriver TRACE: Smoothie got lastReportedLocation (x:111.973900, y:44.879800, z1:0.000000, z2:0.000000, c1:0.000000, c2:0.000000) 2024-04-04 06:51:08.053 GcodeAsyncDriver TRACE: Smoothie confirmation complete. 2024-04-04 06:51:08.053 Scripting TRACE: Scripting.on Camera.BeforeCapture 2024-04-04 06:51:08.067 Scripting TRACE: Scripting.on Camera.AfterCapture 2024-04-04 06:51:08.074 Scripting TRACE: Scripting.on Camera.BeforeCapture 2024-04-04 06:51:08.101 Scripting TRACE: Scripting.on Camera.AfterCapture 2024-04-04 06:51:08.108 AbstractSettlingCamera TRACE: autoSettleAndCapture t=54 auto settle score: 98.431 compute time: 6 2024-04-04 06:51:08.108 Scripting TRACE: Scripting.on Camera.BeforeCapture 2024-04-04 06:51:08.120 Scripting TRACE: Scripting.on Camera.AfterCapture 2024-04-04 06:51:08.127 AbstractSettlingCamera TRACE: autoSettleAndCapture t=74 auto settle score: 98.824 compute time: 4 2024-04-04 06:51:08.128 Scripting TRACE: Scripting.on Camera.BeforeCapture 2024-04-04 06:51:08.141 Scripting TRACE: Scripting.on Camera.AfterCapture 2024-04-04 06:51:08.148 AbstractSettlingCamera TRACE: autoSettleAndCapture t=94 auto settle score: 28.235 compute time: 6 2024-04-04 06:51:08.148 Scripting TRACE: Scripting.on Camera.BeforeCapture 2024-04-04 06:51:08.164 Scripting TRACE: Scripting.on Camera.AfterCapture 2024-04-04 06:51:08.171 AbstractSettlingCamera TRACE: autoSettleAndCapture t=117 auto settle score: 35.294 compute time: 6 2024-04-04 06:51:08.172 AbstractSettlingCamera DEBUG: autoSettleAndCapture in 118 ms 2024-04-04 06:51:08.172 Scripting TRACE: Scripting.on Camera.AfterSettle 2024-04-04 06:51:08.193 CvPipeline DEBUG: Stage "6" throws CvException [org.opencv.core.CvException: cv::Exception: OpenCV(4.5.5) C:\build\master_winpack-bindings-win64-vc14-static\opencv\modules\imgproc\src\thresh.cpp:1555: error: (-2:Unspecified error) in function 'double __cdecl cv::threshold(const class cv::_InputArray &,const class cv::_OutputArray &,double,double,int)' > THRESH_OTSU mode: > 'src_type == CV_8UC1 || src_type == CV_16UC1' > where > 'src_type' is 16 (CV_8UC3) ] 2024-04-04 06:51:08.231 ReferenceFiducialLocator DEBUG: FIDUCIAL-HOME located at (112.672607, 45.015807, -25.000000, 0.000000 mm) 2024-04-04 06:51:08.232 ReferenceFiducialLocator TRACE: FIDUCIAL-HOME less than max. linear offset 0.082mm < 0.200mm, locator satisfied. 2024-04-04 06:51:08.235 AbstractHeadMountable DEBUG: DOWN.moveTo((112.672607, 45.015807, -25.000000, 0.000000 mm), 0.9) 2024-04-04 06:51:08.238 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S2430 G1 X112.0239 F661 ; move to target 2024-04-04 06:51:08.238 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S2430 G1 X112.0239 F661 ; move to target 2024-04-04 06:51:08.239 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S100 G1 X111.9939 Y44.9596 F175 ; move to target 2024-04-04 06:51:08.239 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 06:51:08.240 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S100 G1 X111.9939 Y44.9596 F175 ; move to target 2024-04-04 06:51:08.241 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 06:51:08.241 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> G92 X-0.6787 Y-0.0562 ; reset coordinates 2024-04-04 06:51:08.241 ReferenceNozzle DEBUG: N1.home() 2024-04-04 06:51:08.241 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> G92 X-0.6787 Y-0.0562 ; reset coordinates 2024-04-04 06:51:08.241 ReferenceNozzle DEBUG: N2.home() 2024-04-04 06:51:08.241 ReferenceNozzle DEBUG: N3.home() 2024-04-04 06:51:08.242 ReferenceNozzle DEBUG: N3.home() nozzle tip 504 ID1.5 calibration reset 2024-04-04 06:51:08.242 ReferenceNozzle DEBUG: N3.home() nozzle tip 506 ID5.0 calibration reset 2024-04-04 06:51:08.242 ReferenceNozzle DEBUG: N3.home() nozzle tip 505 ID3.5 calibration reset 2024-04-04 06:51:08.242 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 06:51:08.242 ReferenceNozzle DEBUG: N4.home() 2024-04-04 06:51:08.242 ReferenceNozzle DEBUG: N4.home() nozzle tip 504 ID1.5 calibration reset 2024-04-04 06:51:08.243 ReferenceNozzle DEBUG: N4.home() nozzle tip 506 ID5.0 calibration reset 2024-04-04 06:51:08.243 ReferenceNozzle DEBUG: N4.home() nozzle tip 505 ID3.5 calibration reset 2024-04-04 06:51:08.744 Scripting TRACE: Scripting.on Machine.AfterHoming 2024-04-04 06:51:08.746 ReferenceMachine INFO: setHomed(true) 2024-04-04 06:51:08.747 AbstractMachine TRACE: Machine entering idle state. 2024-04-04 06:51:15.756 AbstractHeadMountable DEBUG: N1.moveTo((45.600259, 22.600471, 0.000000, 0.000000 mm), 0.9) 2024-04-04 06:51:15.759 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S2430 G1 X9.3513 F9367 ; move to target 2024-04-04 06:51:15.759 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S2430 G1 X9.3513 F9367 ; move to target 2024-04-04 06:51:15.760 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S2430 G1 X9.3213 F513 ; move to target 2024-04-04 06:51:15.760 AbstractMachine TRACE: Machine entering idle state. 2024-04-04 06:51:15.760 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S2430 G1 X9.3213 F513 ; move to target 2024-04-04 06:51:15.761 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 06:51:15.761 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 06:51:16.414 AbstractHeadMountable DEBUG: N1.moveTo((55.600259, 22.600471, 0.000000, 0.000000 mm), 0.9) 2024-04-04 06:51:16.416 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S2430 G1 X19.3513 F9367 ; move to target 2024-04-04 06:51:16.417 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S2430 G1 X19.3513 F9367 ; move to target 2024-04-04 06:51:16.417 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S2430 G1 X19.3213 F513 ; move to target 2024-04-04 06:51:16.417 AbstractMachine TRACE: Machine entering idle state. 2024-04-04 06:51:16.417 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S2430 G1 X19.3213 F513 ; move to target 2024-04-04 06:51:16.418 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 06:51:16.418 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 06:51:16.672 AbstractHeadMountable DEBUG: N1.moveTo((65.600259, 22.600471, 0.000000, 0.000000 mm), 0.9) 2024-04-04 06:51:16.675 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S2430 G1 X29.3513 F9367 ; move to target 2024-04-04 06:51:16.676 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S2430 G1 X29.3513 F9367 ; move to target 2024-04-04 06:51:16.676 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S2430 G1 X29.3213 F513 ; move to target 2024-04-04 06:51:16.676 AbstractMachine TRACE: Machine entering idle state. 2024-04-04 06:51:16.676 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S2430 G1 X29.3213 F513 ; move to target 2024-04-04 06:51:16.677 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 06:51:16.677 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 06:51:17.037 AbstractHeadMountable DEBUG: N1.moveTo((75.600259, 22.600471, 0.000000, 0.000000 mm), 0.9) 2024-04-04 06:51:17.039 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S2430 G1 X39.3513 F9367 ; move to target 2024-04-04 06:51:17.039 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S2430 G1 X39.3513 F9367 ; move to target 2024-04-04 06:51:17.039 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S2430 G1 X39.3213 F513 ; move to target 2024-04-04 06:51:17.039 AbstractMachine TRACE: Machine entering idle state. 2024-04-04 06:51:17.040 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S2430 G1 X39.3213 F513 ; move to target 2024-04-04 06:51:17.040 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 06:51:17.041 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 06:51:17.305 AbstractHeadMountable DEBUG: N1.moveTo((85.600259, 22.600471, 0.000000, 0.000000 mm), 0.9) 2024-04-04 06:51:17.307 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S2430 G1 X49.3513 F9367 ; move to target 2024-04-04 06:51:17.308 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S2430 G1 X49.3213 F513 ; move to target 2024-04-04 06:51:17.308 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S2430 G1 X49.3513 F9367 ; move to target 2024-04-04 06:51:17.308 AbstractMachine TRACE: Machine entering idle state. 2024-04-04 06:51:17.308 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S2430 G1 X49.3213 F513 ; move to target 2024-04-04 06:51:17.309 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 06:51:17.309 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 06:51:18.599 AbstractHeadMountable DEBUG: N1.moveTo((85.600259, 32.600471, 0.000000, 0.000000 mm), 0.9) 2024-04-04 06:51:18.601 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S1215 G1 Y9.4913 F6462 ; move to target 2024-04-04 06:51:18.601 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S1215 G1 Y9.4913 F6462 ; move to target 2024-04-04 06:51:18.602 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S94 G1 Y9.9438 F391 ; move to target 2024-04-04 06:51:18.602 AbstractMachine TRACE: Machine entering idle state. 2024-04-04 06:51:18.602 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S94 G1 Y9.9438 F391 ; move to target 2024-04-04 06:51:18.603 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 06:51:18.604 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 06:51:19.813 AbstractHeadMountable DEBUG: N1.moveTo((85.600259, 42.600471, 0.000000, 0.000000 mm), 0.9) 2024-04-04 06:51:19.816 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S1215 G1 Y19.4913 F6462 ; move to target 2024-04-04 06:51:19.816 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S1215 G1 Y19.4913 F6462 ; move to target 2024-04-04 06:51:19.816 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S94 G1 Y19.9438 F391 ; move to target 2024-04-04 06:51:19.816 AbstractMachine TRACE: Machine entering idle state. 2024-04-04 06:51:19.816 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S94 G1 Y19.9438 F391 ; move to target 2024-04-04 06:51:19.817 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 06:51:19.818 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 06:51:20.629 AbstractHeadMountable DEBUG: N1.moveTo((85.600259, 52.600471, 0.000000, 0.000000 mm), 0.9) 2024-04-04 06:51:20.631 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S1215 G1 Y29.4913 F6462 ; move to target 2024-04-04 06:51:20.631 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S1215 G1 Y29.4913 F6462 ; move to target 2024-04-04 06:51:20.632 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S94 G1 Y29.9438 F391 ; move to target 2024-04-04 06:51:20.632 AbstractMachine TRACE: Machine entering idle state. 2024-04-04 06:51:20.632 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S94 G1 Y29.9438 F391 ; move to target 2024-04-04 06:51:20.633 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 06:51:20.633 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 06:51:25.182 AbstractHeadMountable DEBUG: N1.moveTo((85.600259, 152.600471, 0.000000, 0.000000 mm), 0.9) 2024-04-04 06:51:25.184 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S1215 G1 Y129.4913 F20867 ; move to target 2024-04-04 06:51:25.185 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S1215 G1 Y129.4913 F20867 ; move to target 2024-04-04 06:51:25.185 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S94 G1 Y129.9438 F391 ; move to target 2024-04-04 06:51:25.185 AbstractMachine TRACE: Machine entering idle state. 2024-04-04 06:51:25.185 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S94 G1 Y129.9438 F391 ; move to target 2024-04-04 06:51:25.186 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 06:51:25.186 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 06:51:27.419 AbstractHeadMountable DEBUG: N1.moveTo((185.600259, 152.600471, 0.000000, 0.000000 mm), 0.9) 2024-04-04 06:51:27.421 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S2430 G1 X149.3513 F29581 ; move to target 2024-04-04 06:51:27.421 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S2430 G1 X149.3513 F29581 ; move to target 2024-04-04 06:51:27.421 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S2430 G1 X149.3213 F513 ; move to target 2024-04-04 06:51:27.421 AbstractMachine TRACE: Machine entering idle state. 2024-04-04 06:51:27.421 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S2430 G1 X149.3213 F513 ; move to target 2024-04-04 06:51:27.422 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 06:51:27.423 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 06:51:29.895 AbstractHeadMountable DEBUG: N1.moveTo((85.600259, 152.600471, 0.000000, 0.000000 mm), 0.9) 2024-04-04 06:51:29.896 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S2430 G1 X49.3513 F29573 ; move to target 2024-04-04 06:51:29.897 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S2430 G1 X49.3513 F29573 ; move to target 2024-04-04 06:51:29.897 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S2430 G1 X49.3213 F513 ; move to target 2024-04-04 06:51:29.897 AbstractMachine TRACE: Machine entering idle state. 2024-04-04 06:51:29.897 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S2430 G1 X49.3213 F513 ; move to target 2024-04-04 06:51:29.898 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 06:51:29.899 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 06:51:31.819 AbstractHeadMountable DEBUG: N1.moveTo((185.600259, 152.600471, 0.000000, 0.000000 mm), 0.9) 2024-04-04 06:51:31.821 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S2430 G1 X149.3513 F29581 ; move to target 2024-04-04 06:51:31.822 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S2430 G1 X149.3513 F29581 ; move to target 2024-04-04 06:51:31.822 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S2430 G1 X149.3213 F513 ; move to target 2024-04-04 06:51:31.822 AbstractMachine TRACE: Machine entering idle state. 2024-04-04 06:51:31.822 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S2430 G1 X149.3213 F513 ; move to target 2024-04-04 06:51:31.823 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 06:51:31.823 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 06:51:33.282 AbstractHeadMountable DEBUG: N1.moveTo((285.600259, 152.600471, 0.000000, 0.000000 mm), 0.9) 2024-04-04 06:51:33.284 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S2430 G1 X249.3513 F29581 ; move to target 2024-04-04 06:51:33.284 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S2430 G1 X249.3513 F29581 ; move to target 2024-04-04 06:51:33.284 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S2430 G1 X249.3213 F513 ; move to target 2024-04-04 06:51:33.284 AbstractMachine TRACE: Machine entering idle state. 2024-04-04 06:51:33.284 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S2430 G1 X249.3213 F513 ; move to target 2024-04-04 06:51:33.286 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 06:51:33.286 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 06:51:35.847 AbstractHeadMountable DEBUG: N1.moveTo((185.600259, 152.600471, 0.000000, 0.000000 mm), 0.9) 2024-04-04 06:51:35.848 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S2430 G1 X149.3513 F29573 ; move to target 2024-04-04 06:51:35.849 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S2430 G1 X149.3213 F513 ; move to target 2024-04-04 06:51:35.849 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S2430 G1 X149.3513 F29573 ; move to target 2024-04-04 06:51:35.849 AbstractMachine TRACE: Machine entering idle state. 2024-04-04 06:51:35.849 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S2430 G1 X149.3213 F513 ; move to target 2024-04-04 06:51:35.850 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 06:51:35.851 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 06:51:51.849 AbstractHeadMountable DEBUG: N1.moveTo((185.600259, 152.600471, 10.000000, 0.000000 mm), 0.9) 2024-04-04 06:51:51.851 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S1215 G1 Z-10.0000 F6614 ; move to target 2024-04-04 06:51:51.851 AbstractMachine TRACE: Machine entering idle state. 2024-04-04 06:51:51.851 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S1215 G1 Z-10.0000 F6614 ; move to target 2024-04-04 06:51:51.852 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 06:51:52.860 AbstractHeadMountable DEBUG: N1.moveTo((185.600259, 152.600471, 20.000000, 0.000000 mm), 0.9) 2024-04-04 06:51:52.861 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S1215 G1 Z-20.0000 F6614 ; move to target 2024-04-04 06:51:52.861 AbstractMachine TRACE: Machine entering idle state. 2024-04-04 06:51:52.861 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S1215 G1 Z-20.0000 F6614 ; move to target 2024-04-04 06:51:52.862 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 06:51:54.638 AbstractHeadMountable DEBUG: N1.moveTo((185.600259, 152.600471, 10.000000, 0.000000 mm), 0.9) 2024-04-04 06:51:54.639 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S1215 G1 Z-10.0000 F6614 ; move to target 2024-04-04 06:51:54.639 AbstractMachine TRACE: Machine entering idle state. 2024-04-04 06:51:54.641 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 06:51:54.641 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S1215 G1 Z-10.0000 F6614 ; move to target 2024-04-04 06:51:55.219 AbstractHeadMountable DEBUG: N1.moveTo((185.600259, 152.600471, 0.000000, 0.000000 mm), 0.9) 2024-04-04 06:51:55.221 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S1215 G1 Z0.0000 F6614 ; move to target 2024-04-04 06:51:55.221 AbstractMachine TRACE: Machine entering idle state. 2024-04-04 06:51:55.221 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S1215 G1 Z0.0000 F6614 ; move to target 2024-04-04 06:51:55.222 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 06:52:00.785 AbstractHeadMountable DEBUG: N1.moveTo((185.600259, 152.600471, 0.000000, -10.000000 mm), 0.9) 2024-04-04 06:52:00.795 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S405 G1 B-10.0000 F1800 ; move to target 2024-04-04 06:52:00.795 AbstractMachine TRACE: Machine entering idle state. 2024-04-04 06:52:00.795 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S405 G1 B-10.0000 F1800 ; move to target 2024-04-04 06:52:00.796 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 06:52:01.742 AbstractHeadMountable DEBUG: N1.moveTo((185.600259, 152.600471, 0.000000, -20.000000 mm), 0.9) 2024-04-04 06:52:01.743 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S405 G1 B-20.0000 F1800 ; move to target 2024-04-04 06:52:01.743 AbstractMachine TRACE: Machine entering idle state. 2024-04-04 06:52:01.743 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S405 G1 B-20.0000 F1800 ; move to target 2024-04-04 06:52:01.745 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 06:52:02.631 AbstractHeadMountable DEBUG: N1.moveTo((185.600259, 152.600471, 0.000000, -30.000000 mm), 0.9) 2024-04-04 06:52:02.633 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S405 G1 B-30.0000 F1800 ; move to target 2024-04-04 06:52:02.633 AbstractMachine TRACE: Machine entering idle state. 2024-04-04 06:52:02.633 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S405 G1 B-30.0000 F1800 ; move to target 2024-04-04 06:52:02.635 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 06:52:04.894 AbstractHeadMountable DEBUG: N1.moveTo((185.600259, 152.600471, 0.000000, -20.000000 mm), 0.9) 2024-04-04 06:52:04.895 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S405 G1 B-20.0000 F1800 ; move to target 2024-04-04 06:52:04.896 AbstractMachine TRACE: Machine entering idle state. 2024-04-04 06:52:04.896 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S405 G1 B-20.0000 F1800 ; move to target 2024-04-04 06:52:04.897 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 06:52:05.823 AbstractHeadMountable DEBUG: N1.moveTo((185.600259, 152.600471, 0.000000, -10.000000 mm), 0.9) 2024-04-04 06:52:05.824 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S405 G1 B-10.0000 F1800 ; move to target 2024-04-04 06:52:05.825 AbstractMachine TRACE: Machine entering idle state. 2024-04-04 06:52:05.825 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S405 G1 B-10.0000 F1800 ; move to target 2024-04-04 06:52:05.826 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 06:52:06.959 AbstractHeadMountable DEBUG: N1.moveTo((185.600259, 152.600471, 0.000000, 0.000000 mm), 0.9) 2024-04-04 06:52:06.960 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S405 G1 B0.0000 F1800 ; move to target 2024-04-04 06:52:06.960 AbstractMachine TRACE: Machine entering idle state. 2024-04-04 06:52:06.960 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S405 G1 B0.0000 F1800 ; move to target 2024-04-04 06:52:06.962 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 06:52:13.357 AbstractHeadMountable DEBUG: N1.moveTo((195.600259, 152.600471, 0.000000, 0.000000 mm), 0.9) 2024-04-04 06:52:13.359 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S2430 G1 X159.3513 F9367 ; move to target 2024-04-04 06:52:13.359 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S2430 G1 X159.3513 F9367 ; move to target 2024-04-04 06:52:13.359 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S2430 G1 X159.3213 F513 ; move to target 2024-04-04 06:52:13.360 AbstractMachine TRACE: Machine entering idle state. 2024-04-04 06:52:13.360 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S2430 G1 X159.3213 F513 ; move to target 2024-04-04 06:52:13.361 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 06:52:13.363 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 06:52:14.271 AbstractHeadMountable DEBUG: N1.moveTo((185.600259, 152.600471, 0.000000, 0.000000 mm), 0.9) 2024-04-04 06:52:14.273 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S2430 G1 X149.3513 F9339 ; move to target 2024-04-04 06:52:14.273 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S2430 G1 X149.3513 F9339 ; move to target 2024-04-04 06:52:14.273 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S2430 G1 X149.3213 F513 ; move to target 2024-04-04 06:52:14.273 AbstractMachine TRACE: Machine entering idle state. 2024-04-04 06:52:14.273 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S2430 G1 X149.3213 F513 ; move to target 2024-04-04 06:52:14.275 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 06:52:14.276 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 06:52:15.048 AbstractHeadMountable DEBUG: N1.moveTo((185.600259, 142.600471, 0.000000, 0.000000 mm), 0.9) 2024-04-04 06:52:15.052 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S1215 G1 Y120.3430 F6480 ; move to target 2024-04-04 06:52:15.052 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S1215 G1 Y120.3430 F6480 ; move to target 2024-04-04 06:52:15.052 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S94 G1 Y119.8905 F391 ; move to target 2024-04-04 06:52:15.052 AbstractMachine TRACE: Machine entering idle state. 2024-04-04 06:52:15.052 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S94 G1 Y119.8905 F391 ; move to target 2024-04-04 06:52:15.054 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 06:52:15.055 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 06:52:15.811 AbstractHeadMountable DEBUG: N1.moveTo((185.600259, 152.600471, 0.000000, 0.000000 mm), 0.9) 2024-04-04 06:52:15.812 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S1215 G1 Y129.4913 F6480 ; move to target 2024-04-04 06:52:15.813 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S1215 G1 Y129.4913 F6480 ; move to target 2024-04-04 06:52:15.813 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S94 G1 Y129.9438 F391 ; move to target 2024-04-04 06:52:15.813 AbstractMachine TRACE: Machine entering idle state. 2024-04-04 06:52:15.814 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S94 G1 Y129.9438 F391 ; move to target 2024-04-04 06:52:15.815 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 06:52:15.816 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 06:52:24.357 GcodeDriver$ReaderThread ERROR: [Smoothie:COM4] Read error: java.io.IOException: Read error. at org.openpnp.machine.reference.driver.SerialPortCommunications.read(SerialPortCommunications.java:150) at org.openpnp.machine.reference.driver.ReferenceDriverCommunications.readUntil(ReferenceDriverCommunications.java:108) at org.openpnp.machine.reference.driver.ReferenceDriverCommunications.readLine(ReferenceDriverCommunications.java:86) at org.openpnp.machine.reference.driver.GcodeDriver$ReaderThread.run(GcodeDriver.java:1487) 2024-04-04 07:02:41.431 AbstractHeadMountable DEBUG: N1.moveTo((195.600259, 152.600471, 0.000000, 0.000000 mm), 0.9) 2024-04-04 07:02:41.463 AbstractMachine TRACE: Exception caught, executing pending motion: java.lang.Exception: Smoothie:COM4 IO Error on reading from the controller. at org.openpnp.machine.reference.driver.GcodeDriver.bailOnError(GcodeDriver.java:1280) at org.openpnp.machine.reference.driver.GcodeAsyncDriver.bailOnError(GcodeAsyncDriver.java:293) at org.openpnp.machine.reference.driver.GcodeAsyncDriver.sendCommand(GcodeAsyncDriver.java:310) at org.openpnp.machine.reference.driver.GcodeDriver.sendGcode(GcodeDriver.java:1214) at org.openpnp.machine.reference.driver.GcodeDriver.sendGcode(GcodeDriver.java:1196) at org.openpnp.machine.reference.driver.GcodeDriver.moveTo(GcodeDriver.java:995) at org.openpnp.machine.reference.driver.AbstractMotionPlanner.executeMoveTo(AbstractMotionPlanner.java:505) at org.openpnp.machine.reference.driver.AbstractMotionPlanner.executeMotionPlan(AbstractMotionPlanner.java:463) at org.openpnp.machine.reference.driver.AbstractMotionPlanner.waitForCompletion(AbstractMotionPlanner.java:760) at org.openpnp.spi.base.AbstractMachine$1.call(AbstractMachine.java:579) at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) at java.base/java.lang.Thread.run(Thread.java:833) 2024-04-04 07:02:41.464 AbstractMachine ERROR: Secondary exception when executing pending motion planner commands: java.lang.Exception: Smoothie:COM4 IO Error on reading from the controller. at org.openpnp.machine.reference.driver.GcodeDriver.bailOnError(GcodeDriver.java:1280) at org.openpnp.machine.reference.driver.GcodeAsyncDriver.bailOnError(GcodeAsyncDriver.java:293) at org.openpnp.machine.reference.driver.GcodeAsyncDriver.sendCommand(GcodeAsyncDriver.java:310) at org.openpnp.machine.reference.driver.GcodeDriver.sendGcode(GcodeDriver.java:1214) at org.openpnp.machine.reference.driver.GcodeDriver.waitForCompletion(GcodeDriver.java:1017) at org.openpnp.machine.reference.driver.GcodeAsyncDriver.waitForCompletion(GcodeAsyncDriver.java:375) at org.openpnp.machine.reference.driver.AbstractMotionPlanner.waitForDriverCompletion(AbstractMotionPlanner.java:853) at org.openpnp.machine.reference.driver.AbstractMotionPlanner.waitForCompletion(AbstractMotionPlanner.java:764) at org.openpnp.spi.base.AbstractMachine$1.call(AbstractMachine.java:593) at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) at java.base/java.lang.Thread.run(Thread.java:833) 2024-04-04 07:02:41.467 AbstractMachine TRACE: Machine entering idle state. 2024-04-04 07:02:41.467 MessageBoxes DEBUG: Error: java.lang.Exception: Smoothie:COM4 IO Error on reading from the controller. 2024-04-04 07:02:45.067 ReferenceMachine DEBUG: homing machine 2024-04-04 07:02:45.068 ReferenceMachine INFO: setHomed(false) 2024-04-04 07:02:45.068 AbstractMachine TRACE: Exception caught, executing pending motion: java.lang.Exception: Smoothie:COM4 IO Error on reading from the controller. at org.openpnp.machine.reference.driver.GcodeDriver.bailOnError(GcodeDriver.java:1280) at org.openpnp.machine.reference.driver.GcodeAsyncDriver.bailOnError(GcodeAsyncDriver.java:293) at org.openpnp.machine.reference.driver.GcodeAsyncDriver.sendCommand(GcodeAsyncDriver.java:310) at org.openpnp.machine.reference.driver.GcodeDriver.sendGcode(GcodeDriver.java:1214) at org.openpnp.machine.reference.driver.GcodeDriver.home(GcodeDriver.java:648) at org.openpnp.machine.reference.driver.GcodeAsyncDriver.home(GcodeAsyncDriver.java:117) at org.openpnp.machine.reference.driver.AbstractMotionPlanner.home(AbstractMotionPlanner.java:101) at org.openpnp.machine.reference.ReferenceMachine.home(ReferenceMachine.java:530) at org.openpnp.gui.MachineControlsPanel$HomeAction.lambda$actionPerformed$0(MachineControlsPanel.java:420) at org.openpnp.util.UiUtils.lambda$submitUiMachineTask$0(UiUtils.java:67) at org.openpnp.spi.base.AbstractMachine$1.call(AbstractMachine.java:575) at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) at java.base/java.lang.Thread.run(Thread.java:833) 2024-04-04 07:02:45.068 AbstractMachine ERROR: Secondary exception when executing pending motion planner commands: java.lang.Exception: Smoothie:COM4 IO Error on reading from the controller. at org.openpnp.machine.reference.driver.GcodeDriver.bailOnError(GcodeDriver.java:1280) at org.openpnp.machine.reference.driver.GcodeAsyncDriver.bailOnError(GcodeAsyncDriver.java:293) at org.openpnp.machine.reference.driver.GcodeAsyncDriver.sendCommand(GcodeAsyncDriver.java:310) at org.openpnp.machine.reference.driver.GcodeDriver.sendGcode(GcodeDriver.java:1214) at org.openpnp.machine.reference.driver.GcodeDriver.waitForCompletion(GcodeDriver.java:1017) at org.openpnp.machine.reference.driver.GcodeAsyncDriver.waitForCompletion(GcodeAsyncDriver.java:375) at org.openpnp.machine.reference.driver.AbstractMotionPlanner.waitForDriverCompletion(AbstractMotionPlanner.java:853) at org.openpnp.machine.reference.driver.AbstractMotionPlanner.waitForCompletion(AbstractMotionPlanner.java:764) at org.openpnp.spi.base.AbstractMachine$1.call(AbstractMachine.java:593) at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) at java.base/java.lang.Thread.run(Thread.java:833) 2024-04-04 07:02:45.068 AbstractMachine TRACE: Machine entering idle state. 2024-04-04 07:02:45.071 MessageBoxes DEBUG: Error: java.lang.Exception: Smoothie:COM4 IO Error on reading from the controller. 2024-04-04 07:02:48.295 ReferenceMachine DEBUG: setEnabled(false) 2024-04-04 07:02:48.295 ReferenceMachine INFO: setHomed(false) 2024-04-04 07:02:48.296 GcodeDriver$ReaderThread TRACE: [Schultz:COM3] Read error while disconnecting (expected) 2024-04-04 07:02:48.397 GcodeAsyncDriver$WriterThread TRACE: [Schultz:COM3] disconnectRequested, bye-bye. 2024-04-04 07:02:48.498 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] disconnectRequested, bye-bye. 2024-04-04 07:02:48.516 AbstractMachine TRACE: Machine entering idle state. 2024-04-04 07:02:49.609 ReferenceMachine DEBUG: setEnabled(true) 2024-04-04 07:02:49.609 GcodeDriver DEBUG: [Smoothie:COM4] Connect 2024-04-04 07:02:49.626 GcodeDriver TRACE: Smoothie waiting for connection 15000ms 2024-04-04 07:03:04.629 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> G21 ; 2024-04-04 07:03:04.629 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> G90 ; Set absolute positioning mode 2024-04-04 07:03:04.629 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M82 ; Set absolute mode for extruder 2024-04-04 07:03:04.629 GcodeDriver TRACE: Send-on-change logic for Feed Rate, Acceleration and Jerk reset 2024-04-04 07:03:04.629 GcodeDriver DEBUG: [Schultz:COM3] Connect 2024-04-04 07:03:04.629 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> G21 ; 2024-04-04 07:03:04.629 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:03:04.629 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> G90 ; Set absolute positioning mode 2024-04-04 07:03:04.629 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M82 ; Set absolute mode for extruder 2024-04-04 07:03:04.629 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:03:04.630 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:03:04.643 GcodeDriver TRACE: Schultz waiting for connection 3000ms 2024-04-04 07:03:04.702 GcodeDriver$ReaderThread TRACE: [Schultz:COM3] << Controller starting... 2024-04-04 07:03:04.705 GcodeDriver$ReaderThread TRACE: [Schultz:COM3] << Controller ready. 2024-04-04 07:03:07.644 GcodeAsyncDriver DEBUG: [Schultz:COM3] commandQueue offer >> G21 ; Set millimeters mode 2024-04-04 07:03:07.644 GcodeAsyncDriver DEBUG: [Schultz:COM3] commandQueue offer >> G90 ; Set absolute positioning mode 2024-04-04 07:03:07.644 GcodeDriver TRACE: Send-on-change logic for Feed Rate, Acceleration and Jerk reset 2024-04-04 07:03:07.644 GcodeAsyncDriver$WriterThread TRACE: [Schultz:COM3] >> G21 ; Set millimeters mode 2024-04-04 07:03:07.647 GcodeDriver$ReaderThread TRACE: [Schultz:COM3] << G21 ; Set millimeters mode 2024-04-04 07:03:07.650 GcodeDriver$ReaderThread TRACE: [Schultz:COM3] << ok unknown or empty command ignored 2024-04-04 07:03:07.650 GcodeDriver TRACE: [Schultz:COM3] confirmed G21 ; Set millimeters mode 2024-04-04 07:03:07.650 GcodeAsyncDriver$WriterThread TRACE: [Schultz:COM3] >> G90 ; Set absolute positioning mode 2024-04-04 07:03:07.654 GcodeDriver$ReaderThread TRACE: [Schultz:COM3] << G90 ; Set absolute positioning mode 2024-04-04 07:03:07.654 AbstractMachine TRACE: Machine entering idle state. 2024-04-04 07:03:07.657 GcodeDriver$ReaderThread TRACE: [Schultz:COM3] << ok unknown or empty command ignored 2024-04-04 07:03:09.412 ReferenceMachine DEBUG: homing machine 2024-04-04 07:03:09.413 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S1000 ; set a low acceleration 2024-04-04 07:03:09.414 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> G28 A0 Z0 2024-04-04 07:03:09.414 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> G28 X88 Y42 B0 C0; Home all axes 2024-04-04 07:03:09.414 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> G92 X0 Y0 Z0 A0 B0 C0; Set coordinates to zero. 2024-04-04 07:03:09.414 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S1000 ; set a low acceleration 2024-04-04 07:03:09.414 GcodeDriver TRACE: Send-on-change logic for Feed Rate, Acceleration and Jerk reset 2024-04-04 07:03:09.414 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> G28 A0 Z0 2024-04-04 07:03:09.414 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:03:09.414 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> G28 X88 Y42 B0 C0; Home all axes 2024-04-04 07:03:09.414 GcodeAsyncDriver DEBUG: [Schultz:COM3] commandQueue offer >> G28 ; Home all axes 2024-04-04 07:03:09.415 GcodeDriver TRACE: [Schultz:COM3] confirmed G90 ; Set absolute positioning mode 2024-04-04 07:03:09.415 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> G92 X0 Y0 Z0 A0 B0 C0; Set coordinates to zero. 2024-04-04 07:03:09.415 GcodeDriver TRACE: Send-on-change logic for Feed Rate, Acceleration and Jerk reset 2024-04-04 07:03:09.415 GcodeAsyncDriver$WriterThread TRACE: [Schultz:COM3] >> G28 ; Home all axes 2024-04-04 07:03:09.415 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M400 ; Wait for moves to complete before returning 2024-04-04 07:03:09.415 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M114 ; get position 2024-04-04 07:03:09.415 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M400 ; Wait for moves to complete before returning 2024-04-04 07:03:09.415 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M114 ; get position 2024-04-04 07:03:09.417 GcodeDriver$ReaderThread TRACE: [Schultz:COM3] << G28 ; Home all axes 2024-04-04 07:03:09.419 GcodeDriver$ReaderThread TRACE: [Schultz:COM3] << ok unknown or empty command ignored 2024-04-04 07:03:10.489 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:03:15.049 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:03:15.049 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:03:15.050 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:03:15.051 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok C: X:0.0000 Y:0.0000 Z:0.0000 A:0.0000 B:0.0000 C:0.0000 2024-04-04 07:03:15.051 GcodeDriver TRACE: Position report: ok C: X:0.0000 Y:0.0000 Z:0.0000 A:0.0000 B:0.0000 C:0.0000 2024-04-04 07:03:15.051 GcodeDriver TRACE: Smoothie got lastReportedLocation (x:0.000000, y:0.000000, z1:0.000000, z2:0.000000, c1:0.000000, c2:0.000000) 2024-04-04 07:03:15.051 GcodeAsyncDriver TRACE: Smoothie confirmation complete. 2024-04-04 07:03:15.051 GcodeAsyncDriver DEBUG: [Schultz:COM3] commandQueue offer >> M400 ; Wait for moves to complete before returning 2024-04-04 07:03:15.052 GcodeDriver TRACE: [Schultz:COM3] confirmed G28 ; Home all axes 2024-04-04 07:03:15.052 GcodeAsyncDriver$WriterThread TRACE: [Schultz:COM3] >> M400 ; Wait for moves to complete before returning 2024-04-04 07:03:15.058 GcodeDriver$ReaderThread TRACE: [Schultz:COM3] << M400 ; Wait for moves to complete before returning 2024-04-04 07:03:15.061 GcodeDriver$ReaderThread TRACE: [Schultz:COM3] << ok unknown or empty command ignored 2024-04-04 07:03:15.061 GcodeDriver TRACE: [Schultz:COM3] confirmed M400 ; Wait for moves to complete before returning 2024-04-04 07:03:15.061 GcodeAsyncDriver TRACE: Schultz waited 9ms to drain command queue. 2024-04-04 07:03:15.061 GcodeAsyncDriver TRACE: Schultz confirmation complete. 2024-04-04 07:03:15.062 AbstractMotionPlanner DEBUG: Reported location changes current location from (x:159.321259, y:129.890471, z1:0.000000, z2:0.000000, c1:0.000000, c2:0.000000) to (x:0.000000, y:0.000000, z1:0.000000, z2:0.000000, c1:0.000000, c2:0.000000) 2024-04-04 07:03:15.062 ReferenceHead DEBUG: H1.home() 2024-04-04 07:03:15.062 ReferenceFiducialLocator DEBUG: Looking for FIDUCIAL-HOME at (110.000000, 43.500000, -25.000000, 0.000000 mm) 2024-04-04 07:03:15.062 ReferenceHead DEBUG: H1.moveToSafeZ(0.9) 2024-04-04 07:03:15.062 AbstractHeadMountable DEBUG: N1.moveToSafeZ(0.9) 2024-04-04 07:03:15.062 AbstractHeadMountable DEBUG: N2.moveToSafeZ(0.9) 2024-04-04 07:03:15.062 AbstractHeadMountable DEBUG: N3.moveToSafeZ(0.9) 2024-04-04 07:03:15.063 AbstractHeadMountable DEBUG: N4.moveToSafeZ(0.9) 2024-04-04 07:03:15.063 AbstractHeadMountable DEBUG: DOWN.moveToSafeZ(0.9) 2024-04-04 07:03:15.063 AbstractHeadMountable DEBUG: DOWN.moveTo((110.000000, 43.500000, 0.000000, 0.000000 mm), 0.9) 2024-04-04 07:03:15.069 AbstractHeadMountable DEBUG: DOWN.moveTo((110.000000, 43.500000, -25.000000, 0.000000 mm), 0.9) 2024-04-04 07:03:15.081 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S1533 G1 X109.3513 Y42.9913 F18008 ; move to target 2024-04-04 07:03:15.081 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S1533 G1 X109.3513 Y42.9913 F18008 ; move to target 2024-04-04 07:03:15.081 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S18 G1 X109.3213 Y43.4438 F120 ; move to target 2024-04-04 07:03:15.082 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M400 ; Wait for moves to complete before returning 2024-04-04 07:03:15.082 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S18 G1 X109.3213 Y43.4438 F120 ; move to target 2024-04-04 07:03:15.082 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M114 ; get position 2024-04-04 07:03:15.082 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M400 ; Wait for moves to complete before returning 2024-04-04 07:03:15.082 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:03:15.083 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M114 ; get position 2024-04-04 07:03:15.083 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:03:15.954 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:03:15.955 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok C: X:109.3213 Y:43.4438 Z:0.0000 A:0.0000 B:0.0000 C:0.0000 2024-04-04 07:03:15.955 GcodeDriver TRACE: Position report: ok C: X:109.3213 Y:43.4438 Z:0.0000 A:0.0000 B:0.0000 C:0.0000 2024-04-04 07:03:15.955 GcodeDriver TRACE: Smoothie got lastReportedLocation (x:109.321300, y:43.443800, z1:0.000000, z2:0.000000, c1:0.000000, c2:0.000000) 2024-04-04 07:03:15.956 GcodeAsyncDriver TRACE: Smoothie confirmation complete. 2024-04-04 07:03:15.956 ReferenceActuator DEBUG: UpCamLight.actuate(false) 2024-04-04 07:03:15.956 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M811 ; turn off Light 2024-04-04 07:03:15.956 Scripting TRACE: Scripting.on Camera.BeforeSettle 2024-04-04 07:03:15.956 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M811 ; turn off Light 2024-04-04 07:03:15.957 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:03:15.957 Scripting TRACE: Scripting.on Camera.BeforeCapture 2024-04-04 07:03:15.969 Scripting TRACE: Scripting.on Camera.AfterCapture 2024-04-04 07:03:15.974 Scripting TRACE: Scripting.on Camera.BeforeCapture 2024-04-04 07:03:15.988 Scripting TRACE: Scripting.on Camera.AfterCapture 2024-04-04 07:03:16.006 AbstractSettlingCamera TRACE: autoSettleAndCapture t=49 auto settle score: 40.000 compute time: 16 2024-04-04 07:03:16.006 Scripting TRACE: Scripting.on Camera.BeforeCapture 2024-04-04 07:03:16.020 Scripting TRACE: Scripting.on Camera.AfterCapture 2024-04-04 07:03:16.027 AbstractSettlingCamera TRACE: autoSettleAndCapture t=70 auto settle score: 27.843 compute time: 5 2024-04-04 07:03:16.030 Scripting TRACE: Scripting.on Camera.BeforeCapture 2024-04-04 07:03:16.052 Scripting TRACE: Scripting.on Camera.AfterCapture 2024-04-04 07:03:16.059 AbstractSettlingCamera TRACE: autoSettleAndCapture t=103 auto settle score: 25.098 compute time: 7 2024-04-04 07:03:16.060 AbstractSettlingCamera DEBUG: autoSettleAndCapture in 104 ms 2024-04-04 07:03:16.060 Scripting TRACE: Scripting.on Camera.AfterSettle 2024-04-04 07:03:16.089 CvPipeline DEBUG: Stage "6" throws CvException [org.opencv.core.CvException: cv::Exception: OpenCV(4.5.5) C:\build\master_winpack-bindings-win64-vc14-static\opencv\modules\imgproc\src\thresh.cpp:1555: error: (-2:Unspecified error) in function 'double __cdecl cv::threshold(const class cv::_InputArray &,const class cv::_OutputArray &,double,double,int)' > THRESH_OTSU mode: > 'src_type == CV_8UC1 || src_type == CV_16UC1' > where > 'src_type' is 16 (CV_8UC3) ] 2024-04-04 07:03:16.142 ReferenceFiducialLocator DEBUG: FIDUCIAL-HOME located at (114.088691, 40.548165, -25.000000, 0.000000 mm) 2024-04-04 07:03:16.142 AbstractHeadMountable DEBUG: DOWN.moveTo((114.088691, 40.548165, -25.000000, 0.000000 mm), 0.9) 2024-04-04 07:03:16.149 Scripting TRACE: Scripting.on Camera.BeforeSettle 2024-04-04 07:03:16.163 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S563 G1 X113.4400 Y40.8912 F2215 ; move to target 2024-04-04 07:03:16.166 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S563 G1 X113.4400 Y40.8912 F2215 ; move to target 2024-04-04 07:03:16.167 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S18 G1 X113.4099 Y40.4386 F120 ; move to target 2024-04-04 07:03:16.167 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M400 ; Wait for moves to complete before returning 2024-04-04 07:03:16.167 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S18 G1 X113.4099 Y40.4386 F120 ; move to target 2024-04-04 07:03:16.167 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M114 ; get position 2024-04-04 07:03:16.167 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M400 ; Wait for moves to complete before returning 2024-04-04 07:03:16.167 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M114 ; get position 2024-04-04 07:03:16.168 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:03:16.169 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:03:16.645 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:03:16.646 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok C: X:113.4099 Y:40.4386 Z:0.0000 A:0.0000 B:0.0000 C:0.0000 2024-04-04 07:03:16.646 GcodeDriver TRACE: Position report: ok C: X:113.4099 Y:40.4386 Z:0.0000 A:0.0000 B:0.0000 C:0.0000 2024-04-04 07:03:16.647 GcodeDriver TRACE: Smoothie got lastReportedLocation (x:113.409900, y:40.438600, z1:0.000000, z2:0.000000, c1:0.000000, c2:0.000000) 2024-04-04 07:03:16.647 GcodeAsyncDriver TRACE: Smoothie confirmation complete. 2024-04-04 07:03:16.647 Scripting TRACE: Scripting.on Camera.BeforeCapture 2024-04-04 07:03:16.660 Scripting TRACE: Scripting.on Camera.AfterCapture 2024-04-04 07:03:16.666 Scripting TRACE: Scripting.on Camera.BeforeCapture 2024-04-04 07:03:16.700 Scripting TRACE: Scripting.on Camera.AfterCapture 2024-04-04 07:03:16.708 AbstractSettlingCamera TRACE: autoSettleAndCapture t=60 auto settle score: 29.020 compute time: 7 2024-04-04 07:03:16.708 Scripting TRACE: Scripting.on Camera.BeforeCapture 2024-04-04 07:03:16.727 Scripting TRACE: Scripting.on Camera.AfterCapture 2024-04-04 07:03:16.735 AbstractSettlingCamera TRACE: autoSettleAndCapture t=88 auto settle score: 27.451 compute time: 8 2024-04-04 07:03:16.735 Scripting TRACE: Scripting.on Camera.BeforeCapture 2024-04-04 07:03:16.758 Scripting TRACE: Scripting.on Camera.AfterCapture 2024-04-04 07:03:16.765 AbstractSettlingCamera TRACE: autoSettleAndCapture t=118 auto settle score: 27.059 compute time: 7 2024-04-04 07:03:16.766 AbstractSettlingCamera DEBUG: autoSettleAndCapture in 118 ms 2024-04-04 07:03:16.766 Scripting TRACE: Scripting.on Camera.AfterSettle 2024-04-04 07:03:16.797 CvPipeline DEBUG: Stage "6" throws CvException [org.opencv.core.CvException: cv::Exception: OpenCV(4.5.5) C:\build\master_winpack-bindings-win64-vc14-static\opencv\modules\imgproc\src\thresh.cpp:1555: error: (-2:Unspecified error) in function 'double __cdecl cv::threshold(const class cv::_InputArray &,const class cv::_OutputArray &,double,double,int)' > THRESH_OTSU mode: > 'src_type == CV_8UC1 || src_type == CV_16UC1' > where > 'src_type' is 16 (CV_8UC3) ] 2024-04-04 07:03:16.855 ReferenceFiducialLocator DEBUG: FIDUCIAL-HOME located at (115.903670, 38.832909, -25.000000, 0.000000 mm) 2024-04-04 07:03:16.855 AbstractHeadMountable DEBUG: DOWN.moveTo((115.903670, 38.832909, -25.000000, 0.000000 mm), 0.9) 2024-04-04 07:03:16.864 Scripting TRACE: Scripting.on Camera.BeforeSettle 2024-04-04 07:03:16.879 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S444 G1 X115.2550 Y39.1759 F1336 ; move to target 2024-04-04 07:03:16.880 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S444 G1 X115.2550 Y39.1759 F1336 ; move to target 2024-04-04 07:03:16.880 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S18 G1 X115.2249 Y38.7234 F120 ; move to target 2024-04-04 07:03:16.880 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M400 ; Wait for moves to complete before returning 2024-04-04 07:03:16.880 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S18 G1 X115.2249 Y38.7234 F120 ; move to target 2024-04-04 07:03:16.880 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M114 ; get position 2024-04-04 07:03:16.880 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M400 ; Wait for moves to complete before returning 2024-04-04 07:03:16.881 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M114 ; get position 2024-04-04 07:03:16.881 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:03:16.882 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:03:17.312 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:03:17.313 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok C: X:115.2249 Y:38.7234 Z:0.0000 A:0.0000 B:0.0000 C:0.0000 2024-04-04 07:03:17.313 GcodeDriver TRACE: Position report: ok C: X:115.2249 Y:38.7234 Z:0.0000 A:0.0000 B:0.0000 C:0.0000 2024-04-04 07:03:17.313 GcodeDriver TRACE: Smoothie got lastReportedLocation (x:115.224900, y:38.723400, z1:0.000000, z2:0.000000, c1:0.000000, c2:0.000000) 2024-04-04 07:03:17.313 GcodeAsyncDriver TRACE: Smoothie confirmation complete. 2024-04-04 07:03:17.313 Scripting TRACE: Scripting.on Camera.BeforeCapture 2024-04-04 07:03:17.321 Scripting TRACE: Scripting.on Camera.AfterCapture 2024-04-04 07:03:17.325 Scripting TRACE: Scripting.on Camera.BeforeCapture 2024-04-04 07:03:17.343 Scripting TRACE: Scripting.on Camera.AfterCapture 2024-04-04 07:03:17.347 AbstractSettlingCamera TRACE: autoSettleAndCapture t=33 auto settle score: 31.765 compute time: 3 2024-04-04 07:03:17.348 Scripting TRACE: Scripting.on Camera.BeforeCapture 2024-04-04 07:03:17.376 Scripting TRACE: Scripting.on Camera.AfterCapture 2024-04-04 07:03:17.381 AbstractSettlingCamera TRACE: autoSettleAndCapture t=67 auto settle score: 32.549 compute time: 4 2024-04-04 07:03:17.381 Scripting TRACE: Scripting.on Camera.BeforeCapture 2024-04-04 07:03:17.406 Scripting TRACE: Scripting.on Camera.AfterCapture 2024-04-04 07:03:17.411 AbstractSettlingCamera TRACE: autoSettleAndCapture t=97 auto settle score: 28.235 compute time: 4 2024-04-04 07:03:17.412 Scripting TRACE: Scripting.on Camera.BeforeCapture 2024-04-04 07:03:17.455 Scripting TRACE: Scripting.on Camera.AfterCapture 2024-04-04 07:03:17.460 AbstractSettlingCamera TRACE: autoSettleAndCapture t=146 auto settle score: 28.235 compute time: 5 2024-04-04 07:03:17.460 AbstractSettlingCamera DEBUG: autoSettleAndCapture in 146 ms 2024-04-04 07:03:17.460 Scripting TRACE: Scripting.on Camera.AfterSettle 2024-04-04 07:03:17.482 CvPipeline DEBUG: Stage "6" throws CvException [org.opencv.core.CvException: cv::Exception: OpenCV(4.5.5) C:\build\master_winpack-bindings-win64-vc14-static\opencv\modules\imgproc\src\thresh.cpp:1555: error: (-2:Unspecified error) in function 'double __cdecl cv::threshold(const class cv::_InputArray &,const class cv::_OutputArray &,double,double,int)' > THRESH_OTSU mode: > 'src_type == CV_8UC1 || src_type == CV_16UC1' > where > 'src_type' is 16 (CV_8UC3) ] 2024-04-04 07:03:17.521 ReferenceFiducialLocator DEBUG: FIDUCIAL-HOME located at (116.402291, 36.878316, -25.000000, 0.000000 mm) 2024-04-04 07:03:17.521 AbstractHeadMountable DEBUG: DOWN.moveTo((116.402291, 36.878316, -25.000000, 0.000000 mm), 0.9) 2024-04-04 07:03:17.527 ReferenceFiducialLocator DEBUG: FIDUCIAL-HOME averaged location is at (116.152981, 37.855613, -25.000000, 0.000000 mm) 2024-04-04 07:03:17.528 AbstractMachine TRACE: Exception caught, executing pending motion: java.lang.Exception: Fiducial FIDUCIAL-HOME detected too far away. at org.openpnp.machine.reference.vision.ReferenceFiducialLocator.getFiducialLocation(ReferenceFiducialLocator.java:512) at org.openpnp.machine.reference.vision.ReferenceFiducialLocator.getHomeFiducialLocation(ReferenceFiducialLocator.java:344) at org.openpnp.machine.reference.ReferenceHead.visualHome(ReferenceHead.java:77) at org.openpnp.machine.reference.ReferenceHead.home(ReferenceHead.java:56) at org.openpnp.spi.base.AbstractMachine.home(AbstractMachine.java:301) at org.openpnp.machine.reference.ReferenceMachine.home(ReferenceMachine.java:531) at org.openpnp.gui.MachineControlsPanel$HomeAction.lambda$actionPerformed$0(MachineControlsPanel.java:420) at org.openpnp.util.UiUtils.lambda$submitUiMachineTask$0(UiUtils.java:67) at org.openpnp.spi.base.AbstractMachine$1.call(AbstractMachine.java:575) at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) at java.base/java.lang.Thread.run(Thread.java:833) 2024-04-04 07:03:17.536 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S362 G1 X115.7536 Y37.2213 F1019 ; move to target 2024-04-04 07:03:17.537 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S362 G1 X115.7536 Y37.2213 F1019 ; move to target 2024-04-04 07:03:17.537 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S18 G1 X115.7236 Y36.7688 F120 ; move to target 2024-04-04 07:03:17.537 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M400 ; Wait for moves to complete before returning 2024-04-04 07:03:17.537 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M114 ; get position 2024-04-04 07:03:17.537 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S18 G1 X115.7236 Y36.7688 F120 ; move to target 2024-04-04 07:03:17.537 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M400 ; Wait for moves to complete before returning 2024-04-04 07:03:17.539 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M114 ; get position 2024-04-04 07:03:17.539 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:03:17.540 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:03:17.958 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:03:17.959 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok C: X:115.7236 Y:36.7688 Z:0.0000 A:0.0000 B:0.0000 C:0.0000 2024-04-04 07:03:17.959 GcodeDriver TRACE: Position report: ok C: X:115.7236 Y:36.7688 Z:0.0000 A:0.0000 B:0.0000 C:0.0000 2024-04-04 07:03:17.959 GcodeDriver TRACE: Smoothie got lastReportedLocation (x:115.723600, y:36.768800, z1:0.000000, z2:0.000000, c1:0.000000, c2:0.000000) 2024-04-04 07:03:17.959 GcodeAsyncDriver TRACE: Smoothie confirmation complete. 2024-04-04 07:03:17.959 AbstractMachine TRACE: Machine entering idle state. 2024-04-04 07:03:17.959 MessageBoxes DEBUG: Error: java.lang.Exception: Fiducial FIDUCIAL-HOME detected too far away. 2024-04-04 07:03:22.333 ReferenceMachine DEBUG: homing machine 2024-04-04 07:03:22.334 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S1000 ; set a low acceleration 2024-04-04 07:03:22.334 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> G28 A0 Z0 2024-04-04 07:03:22.334 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> G28 X88 Y42 B0 C0; Home all axes 2024-04-04 07:03:22.334 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> G92 X0 Y0 Z0 A0 B0 C0; Set coordinates to zero. 2024-04-04 07:03:22.334 GcodeDriver TRACE: Send-on-change logic for Feed Rate, Acceleration and Jerk reset 2024-04-04 07:03:22.334 GcodeAsyncDriver DEBUG: [Schultz:COM3] commandQueue offer >> G28 ; Home all axes 2024-04-04 07:03:22.335 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S1000 ; set a low acceleration 2024-04-04 07:03:22.335 GcodeDriver TRACE: Send-on-change logic for Feed Rate, Acceleration and Jerk reset 2024-04-04 07:03:22.335 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> G28 A0 Z0 2024-04-04 07:03:22.335 GcodeAsyncDriver$WriterThread TRACE: [Schultz:COM3] >> G28 ; Home all axes 2024-04-04 07:03:22.335 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M400 ; Wait for moves to complete before returning 2024-04-04 07:03:22.335 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M114 ; get position 2024-04-04 07:03:22.335 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> G28 X88 Y42 B0 C0; Home all axes 2024-04-04 07:03:22.335 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:03:22.335 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> G92 X0 Y0 Z0 A0 B0 C0; Set coordinates to zero. 2024-04-04 07:03:22.335 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M400 ; Wait for moves to complete before returning 2024-04-04 07:03:22.336 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M114 ; get position 2024-04-04 07:03:22.337 GcodeDriver$ReaderThread TRACE: [Schultz:COM3] << G28 ; Home all axes 2024-04-04 07:03:22.340 GcodeDriver$ReaderThread TRACE: [Schultz:COM3] << ok unknown or empty command ignored 2024-04-04 07:03:23.411 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:03:25.948 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:03:25.948 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:03:25.948 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:03:25.949 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok C: X:0.0000 Y:0.0000 Z:0.0000 A:0.0000 B:0.0000 C:0.0000 2024-04-04 07:03:25.949 GcodeDriver TRACE: Position report: ok C: X:0.0000 Y:0.0000 Z:0.0000 A:0.0000 B:0.0000 C:0.0000 2024-04-04 07:03:25.949 GcodeDriver TRACE: Smoothie got lastReportedLocation (x:0.000000, y:0.000000, z1:0.000000, z2:0.000000, c1:0.000000, c2:0.000000) 2024-04-04 07:03:25.949 GcodeAsyncDriver TRACE: Smoothie confirmation complete. 2024-04-04 07:03:25.950 GcodeAsyncDriver DEBUG: [Schultz:COM3] commandQueue offer >> M400 ; Wait for moves to complete before returning 2024-04-04 07:03:25.950 GcodeDriver TRACE: [Schultz:COM3] confirmed G28 ; Home all axes 2024-04-04 07:03:25.950 GcodeAsyncDriver$WriterThread TRACE: [Schultz:COM3] >> M400 ; Wait for moves to complete before returning 2024-04-04 07:03:25.955 GcodeDriver$ReaderThread TRACE: [Schultz:COM3] << M400 ; Wait for moves to complete before returning 2024-04-04 07:03:25.959 GcodeDriver$ReaderThread TRACE: [Schultz:COM3] << ok unknown or empty command ignored 2024-04-04 07:03:25.959 GcodeDriver TRACE: [Schultz:COM3] confirmed M400 ; Wait for moves to complete before returning 2024-04-04 07:03:25.959 GcodeAsyncDriver TRACE: Schultz waited 9ms to drain command queue. 2024-04-04 07:03:25.959 GcodeAsyncDriver TRACE: Schultz confirmation complete. 2024-04-04 07:03:25.959 AbstractMotionPlanner DEBUG: Reported location changes current location from (x:115.723550, y:36.768787, z1:0.000000, z2:0.000000, c1:0.000000, c2:0.000000) to (x:0.000000, y:0.000000, z1:0.000000, z2:0.000000, c1:0.000000, c2:0.000000) 2024-04-04 07:03:25.959 ReferenceHead DEBUG: H1.home() 2024-04-04 07:03:25.959 ReferenceFiducialLocator DEBUG: Looking for FIDUCIAL-HOME at (110.000000, 43.500000, -25.000000, 0.000000 mm) 2024-04-04 07:03:25.959 ReferenceHead DEBUG: H1.moveToSafeZ(0.9) 2024-04-04 07:03:25.960 AbstractHeadMountable DEBUG: N1.moveToSafeZ(0.9) 2024-04-04 07:03:25.960 AbstractHeadMountable DEBUG: N2.moveToSafeZ(0.9) 2024-04-04 07:03:25.960 AbstractHeadMountable DEBUG: N3.moveToSafeZ(0.9) 2024-04-04 07:03:25.960 AbstractHeadMountable DEBUG: N4.moveToSafeZ(0.9) 2024-04-04 07:03:25.960 AbstractHeadMountable DEBUG: DOWN.moveToSafeZ(0.9) 2024-04-04 07:03:25.960 AbstractHeadMountable DEBUG: DOWN.moveTo((110.000000, 43.500000, 0.000000, 0.000000 mm), 0.9) 2024-04-04 07:03:25.964 AbstractHeadMountable DEBUG: DOWN.moveTo((110.000000, 43.500000, -25.000000, 0.000000 mm), 0.9) 2024-04-04 07:03:25.964 Scripting TRACE: Scripting.on Camera.BeforeSettle 2024-04-04 07:03:25.972 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S1533 G1 X109.3513 Y42.9913 F18008 ; move to target 2024-04-04 07:03:25.972 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S1533 G1 X109.3513 Y42.9913 F18008 ; move to target 2024-04-04 07:03:25.973 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S18 G1 X109.3213 Y43.4438 F120 ; move to target 2024-04-04 07:03:25.973 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M400 ; Wait for moves to complete before returning 2024-04-04 07:03:25.973 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S18 G1 X109.3213 Y43.4438 F120 ; move to target 2024-04-04 07:03:25.973 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M114 ; get position 2024-04-04 07:03:25.973 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M400 ; Wait for moves to complete before returning 2024-04-04 07:03:25.973 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M114 ; get position 2024-04-04 07:03:25.974 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:03:25.975 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:03:26.845 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:03:26.846 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok C: X:109.3213 Y:43.4438 Z:0.0000 A:0.0000 B:0.0000 C:0.0000 2024-04-04 07:03:26.846 GcodeDriver TRACE: Position report: ok C: X:109.3213 Y:43.4438 Z:0.0000 A:0.0000 B:0.0000 C:0.0000 2024-04-04 07:03:26.846 GcodeDriver TRACE: Smoothie got lastReportedLocation (x:109.321300, y:43.443800, z1:0.000000, z2:0.000000, c1:0.000000, c2:0.000000) 2024-04-04 07:03:26.846 GcodeAsyncDriver TRACE: Smoothie confirmation complete. 2024-04-04 07:03:26.846 Scripting TRACE: Scripting.on Camera.BeforeCapture 2024-04-04 07:03:26.858 Scripting TRACE: Scripting.on Camera.AfterCapture 2024-04-04 07:03:26.862 Scripting TRACE: Scripting.on Camera.BeforeCapture 2024-04-04 07:03:26.892 Scripting TRACE: Scripting.on Camera.AfterCapture 2024-04-04 07:03:26.897 AbstractSettlingCamera TRACE: autoSettleAndCapture t=51 auto settle score: 37.647 compute time: 4 2024-04-04 07:03:26.897 Scripting TRACE: Scripting.on Camera.BeforeCapture 2024-04-04 07:03:26.916 Scripting TRACE: Scripting.on Camera.AfterCapture 2024-04-04 07:03:26.947 AbstractSettlingCamera TRACE: autoSettleAndCapture t=101 auto settle score: 26.667 compute time: 23 2024-04-04 07:03:26.947 AbstractSettlingCamera DEBUG: autoSettleAndCapture in 102 ms 2024-04-04 07:03:26.947 Scripting TRACE: Scripting.on Camera.AfterSettle 2024-04-04 07:03:26.972 CvPipeline DEBUG: Stage "6" throws CvException [org.opencv.core.CvException: cv::Exception: OpenCV(4.5.5) C:\build\master_winpack-bindings-win64-vc14-static\opencv\modules\imgproc\src\thresh.cpp:1555: error: (-2:Unspecified error) in function 'double __cdecl cv::threshold(const class cv::_InputArray &,const class cv::_OutputArray &,double,double,int)' > THRESH_OTSU mode: > 'src_type == CV_8UC1 || src_type == CV_16UC1' > where > 'src_type' is 16 (CV_8UC3) ] 2024-04-04 07:03:27.011 ReferenceFiducialLocator DEBUG: FIDUCIAL-HOME located at (112.413325, 44.856249, -25.000000, 0.000000 mm) 2024-04-04 07:03:27.011 AbstractHeadMountable DEBUG: DOWN.moveTo((112.413325, 44.856249, -25.000000, 0.000000 mm), 0.9) 2024-04-04 07:03:27.016 Scripting TRACE: Scripting.on Camera.BeforeSettle 2024-04-04 07:03:27.024 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S429 G1 X111.7646 Y44.3475 F1418 ; move to target 2024-04-04 07:03:27.024 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S429 G1 X111.7646 Y44.3475 F1418 ; move to target 2024-04-04 07:03:27.024 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S18 G1 X111.7346 Y44.8001 F120 ; move to target 2024-04-04 07:03:27.024 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S18 G1 X111.7346 Y44.8001 F120 ; move to target 2024-04-04 07:03:27.024 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M400 ; Wait for moves to complete before returning 2024-04-04 07:03:27.025 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M114 ; get position 2024-04-04 07:03:27.025 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M400 ; Wait for moves to complete before returning 2024-04-04 07:03:27.025 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M114 ; get position 2024-04-04 07:03:27.025 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:03:27.026 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:03:27.472 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:03:27.473 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok C: X:111.7346 Y:44.8001 Z:0.0000 A:0.0000 B:0.0000 C:0.0000 2024-04-04 07:03:27.473 GcodeDriver TRACE: Position report: ok C: X:111.7346 Y:44.8001 Z:0.0000 A:0.0000 B:0.0000 C:0.0000 2024-04-04 07:03:27.473 GcodeDriver TRACE: Smoothie got lastReportedLocation (x:111.734600, y:44.800100, z1:0.000000, z2:0.000000, c1:0.000000, c2:0.000000) 2024-04-04 07:03:27.473 GcodeAsyncDriver TRACE: Smoothie confirmation complete. 2024-04-04 07:03:27.473 Scripting TRACE: Scripting.on Camera.BeforeCapture 2024-04-04 07:03:27.482 Scripting TRACE: Scripting.on Camera.AfterCapture 2024-04-04 07:03:27.486 Scripting TRACE: Scripting.on Camera.BeforeCapture 2024-04-04 07:03:27.495 Scripting TRACE: Scripting.on Camera.AfterCapture 2024-04-04 07:03:27.499 AbstractSettlingCamera TRACE: autoSettleAndCapture t=27 auto settle score: 63.137 compute time: 4 2024-04-04 07:03:27.500 Scripting TRACE: Scripting.on Camera.BeforeCapture 2024-04-04 07:03:27.519 Scripting TRACE: Scripting.on Camera.AfterCapture 2024-04-04 07:03:27.523 AbstractSettlingCamera TRACE: autoSettleAndCapture t=50 auto settle score: 26.667 compute time: 4 2024-04-04 07:03:27.523 Scripting TRACE: Scripting.on Camera.BeforeCapture 2024-04-04 07:03:27.550 Scripting TRACE: Scripting.on Camera.AfterCapture 2024-04-04 07:03:27.555 AbstractSettlingCamera TRACE: autoSettleAndCapture t=82 auto settle score: 28.235 compute time: 4 2024-04-04 07:03:27.555 Scripting TRACE: Scripting.on Camera.BeforeCapture 2024-04-04 07:03:27.583 Scripting TRACE: Scripting.on Camera.AfterCapture 2024-04-04 07:03:27.588 AbstractSettlingCamera TRACE: autoSettleAndCapture t=115 auto settle score: 27.059 compute time: 4 2024-04-04 07:03:27.588 AbstractSettlingCamera DEBUG: autoSettleAndCapture in 115 ms 2024-04-04 07:03:27.588 Scripting TRACE: Scripting.on Camera.AfterSettle 2024-04-04 07:03:27.611 CvPipeline DEBUG: Stage "6" throws CvException [org.opencv.core.CvException: cv::Exception: OpenCV(4.5.5) C:\build\master_winpack-bindings-win64-vc14-static\opencv\modules\imgproc\src\thresh.cpp:1555: error: (-2:Unspecified error) in function 'double __cdecl cv::threshold(const class cv::_InputArray &,const class cv::_OutputArray &,double,double,int)' > THRESH_OTSU mode: > 'src_type == CV_8UC1 || src_type == CV_16UC1' > where > 'src_type' is 16 (CV_8UC3) ] 2024-04-04 07:03:27.647 ReferenceFiducialLocator DEBUG: FIDUCIAL-HOME located at (112.433269, 44.936028, -25.000000, 0.000000 mm) 2024-04-04 07:03:27.647 ReferenceFiducialLocator TRACE: FIDUCIAL-HOME less than max. linear offset 0.082mm < 0.200mm, locator satisfied. 2024-04-04 07:03:27.650 AbstractHeadMountable DEBUG: DOWN.moveTo((112.433269, 44.936028, -25.000000, 0.000000 mm), 0.9) 2024-04-04 07:03:27.664 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S110 G1 X111.7846 F99 ; move to target 2024-04-04 07:03:27.665 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S110 G1 X111.7846 F99 ; move to target 2024-04-04 07:03:27.665 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S11 G1 X111.7545 Y44.8798 F60 ; move to target 2024-04-04 07:03:27.665 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S11 G1 X111.7545 Y44.8798 F60 ; move to target 2024-04-04 07:03:27.665 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> G92 X-0.6787 Y-0.0562 ; reset coordinates 2024-04-04 07:03:27.665 ReferenceNozzle DEBUG: N1.home() 2024-04-04 07:03:27.665 ReferenceNozzle DEBUG: N2.home() 2024-04-04 07:03:27.665 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> G92 X-0.6787 Y-0.0562 ; reset coordinates 2024-04-04 07:03:27.665 ReferenceNozzle DEBUG: N3.home() 2024-04-04 07:03:27.665 ReferenceNozzle DEBUG: N3.home() nozzle tip 504 ID1.5 calibration reset 2024-04-04 07:03:27.665 ReferenceNozzle DEBUG: N3.home() nozzle tip 506 ID5.0 calibration reset 2024-04-04 07:03:27.665 ReferenceNozzle DEBUG: N3.home() nozzle tip 505 ID3.5 calibration reset 2024-04-04 07:03:27.665 ReferenceNozzle DEBUG: N4.home() 2024-04-04 07:03:27.665 ReferenceNozzle DEBUG: N4.home() nozzle tip 504 ID1.5 calibration reset 2024-04-04 07:03:27.666 ReferenceNozzle DEBUG: N4.home() nozzle tip 506 ID5.0 calibration reset 2024-04-04 07:03:27.666 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:03:27.666 ReferenceNozzle DEBUG: N4.home() nozzle tip 505 ID3.5 calibration reset 2024-04-04 07:03:27.667 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:03:27.667 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:03:28.198 Scripting TRACE: Scripting.on Machine.AfterHoming 2024-04-04 07:03:28.199 ReferenceMachine INFO: setHomed(true) 2024-04-04 07:03:28.199 AbstractMachine TRACE: Machine entering idle state. 2024-04-04 07:03:30.747 AbstractHeadMountable DEBUG: N1.moveTo((45.600259, 22.600471, 0.000000, 0.000000 mm), 0.9) 2024-04-04 07:03:30.760 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S644 G1 X9.3513 F3409 ; move to target 2024-04-04 07:03:30.760 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S644 G1 X9.3513 F3409 ; move to target 2024-04-04 07:03:30.760 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S93 G1 X9.3213 F71 ; move to target 2024-04-04 07:03:30.761 AbstractMachine TRACE: Machine entering idle state. 2024-04-04 07:03:30.761 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S93 G1 X9.3213 F71 ; move to target 2024-04-04 07:03:30.761 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:03:30.762 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:03:31.496 AbstractHeadMountable DEBUG: N1.moveTo((55.600259, 22.600471, 0.000000, 0.000000 mm), 0.9) 2024-04-04 07:03:31.509 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S644 G1 X19.3513 F3409 ; move to target 2024-04-04 07:03:31.509 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S93 G1 X19.3213 F71 ; move to target 2024-04-04 07:03:31.509 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S644 G1 X19.3513 F3409 ; move to target 2024-04-04 07:03:31.509 AbstractMachine TRACE: Machine entering idle state. 2024-04-04 07:03:31.509 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S93 G1 X19.3213 F71 ; move to target 2024-04-04 07:03:31.510 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:03:31.511 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:03:32.212 AbstractHeadMountable DEBUG: N1.moveTo((65.600259, 22.600471, 0.000000, 0.000000 mm), 0.9) 2024-04-04 07:03:32.224 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S644 G1 X29.3513 F3409 ; move to target 2024-04-04 07:03:32.225 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S644 G1 X29.3513 F3409 ; move to target 2024-04-04 07:03:32.225 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S93 G1 X29.3213 F71 ; move to target 2024-04-04 07:03:32.225 AbstractMachine TRACE: Machine entering idle state. 2024-04-04 07:03:32.225 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S93 G1 X29.3213 F71 ; move to target 2024-04-04 07:03:32.226 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:03:32.227 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:03:32.460 AbstractHeadMountable DEBUG: N1.moveTo((75.600259, 22.600471, 0.000000, 0.000000 mm), 0.9) 2024-04-04 07:03:32.469 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S644 G1 X39.3513 F3409 ; move to target 2024-04-04 07:03:32.470 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S93 G1 X39.3213 F71 ; move to target 2024-04-04 07:03:32.470 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S644 G1 X39.3513 F3409 ; move to target 2024-04-04 07:03:32.470 AbstractMachine TRACE: Machine entering idle state. 2024-04-04 07:03:32.470 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S93 G1 X39.3213 F71 ; move to target 2024-04-04 07:03:32.471 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:03:32.472 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:03:35.115 AbstractHeadMountable DEBUG: N1.moveTo((85.600259, 22.600471, 0.000000, 0.000000 mm), 0.9) 2024-04-04 07:03:35.127 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S644 G1 X49.3513 F3409 ; move to target 2024-04-04 07:03:35.128 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S644 G1 X49.3513 F3409 ; move to target 2024-04-04 07:03:35.128 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S93 G1 X49.3213 F71 ; move to target 2024-04-04 07:03:35.128 AbstractMachine TRACE: Machine entering idle state. 2024-04-04 07:03:35.128 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S93 G1 X49.3213 F71 ; move to target 2024-04-04 07:03:35.129 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:03:35.130 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:03:36.995 AbstractHeadMountable DEBUG: N1.moveTo((185.600259, 22.600471, 0.000000, 0.000000 mm), 0.9) 2024-04-04 07:03:37.006 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S1385 G1 X149.3513 F15793 ; move to target 2024-04-04 07:03:37.006 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S93 G1 X149.3213 F71 ; move to target 2024-04-04 07:03:37.007 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S1385 G1 X149.3513 F15793 ; move to target 2024-04-04 07:03:37.007 AbstractMachine TRACE: Machine entering idle state. 2024-04-04 07:03:37.007 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S93 G1 X149.3213 F71 ; move to target 2024-04-04 07:03:37.007 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M400 ; Wait for moves to complete before returning 2024-04-04 07:03:37.007 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M114 ; get position 2024-04-04 07:03:37.007 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M400 ; Wait for moves to complete before returning 2024-04-04 07:03:37.007 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M114 ; get position 2024-04-04 07:03:37.007 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:03:37.008 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:03:37.617 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:03:37.618 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok C: X:149.3213 Y:-0.0562 Z:0.0000 A:0.0000 B:0.0000 C:0.0000 2024-04-04 07:03:37.618 GcodeDriver TRACE: Position report: ok C: X:149.3213 Y:-0.0562 Z:0.0000 A:0.0000 B:0.0000 C:0.0000 2024-04-04 07:03:37.618 GcodeDriver TRACE: Smoothie got lastReportedLocation (x:149.321300, y:-0.056200, z1:0.000000, z2:0.000000, c1:0.000000, c2:0.000000) 2024-04-04 07:03:37.618 GcodeAsyncDriver TRACE: Smoothie confirmation complete. 2024-04-04 07:03:37.618 ReferenceActuator DEBUG: UpCamLight.actuate(true) 2024-04-04 07:03:37.618 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M810 ; turn on Light 2024-04-04 07:03:37.619 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M810 ; turn on Light 2024-04-04 07:03:37.619 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:03:38.905 AbstractHeadMountable DEBUG: N1.moveTo((185.600259, 122.600471, 0.000000, 0.000000 mm), 0.9) 2024-04-04 07:03:38.910 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S1215 G1 Y99.4913 F15658 ; move to target 2024-04-04 07:03:38.911 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S1215 G1 Y99.4913 F15658 ; move to target 2024-04-04 07:03:38.911 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S18 G1 Y99.9438 F120 ; move to target 2024-04-04 07:03:38.911 AbstractMachine TRACE: Machine entering idle state. 2024-04-04 07:03:38.911 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S18 G1 Y99.9438 F120 ; move to target 2024-04-04 07:03:38.912 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:03:38.913 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:03:40.618 AbstractHeadMountable DEBUG: N1.moveTo((185.600259, 222.600471, 0.000000, 0.000000 mm), 0.9) 2024-04-04 07:03:40.623 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S1215 G1 Y199.4913 F15658 ; move to target 2024-04-04 07:03:40.624 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S18 G1 Y199.9438 F120 ; move to target 2024-04-04 07:03:40.624 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S1215 G1 Y199.4913 F15658 ; move to target 2024-04-04 07:03:40.624 AbstractMachine TRACE: Machine entering idle state. 2024-04-04 07:03:40.624 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S18 G1 Y199.9438 F120 ; move to target 2024-04-04 07:03:40.625 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:03:40.626 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:03:42.979 AbstractHeadMountable DEBUG: N1.moveTo((185.600259, 122.600471, 0.000000, 0.000000 mm), 0.9) 2024-04-04 07:03:42.984 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S1215 G1 Y100.3430 F15663 ; move to target 2024-04-04 07:03:42.984 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S1215 G1 Y100.3430 F15663 ; move to target 2024-04-04 07:03:42.984 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S18 G1 Y99.8905 F120 ; move to target 2024-04-04 07:03:42.985 AbstractMachine TRACE: Machine entering idle state. 2024-04-04 07:03:42.985 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S18 G1 Y99.8905 F120 ; move to target 2024-04-04 07:03:42.985 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:03:42.986 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:03:45.392 AbstractHeadMountable DEBUG: N1.moveTo((285.600259, 122.600471, 0.000000, 0.000000 mm), 0.9) 2024-04-04 07:03:45.405 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S1385 G1 X249.3513 F15793 ; move to target 2024-04-04 07:03:45.405 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S1385 G1 X249.3513 F15793 ; move to target 2024-04-04 07:03:45.405 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S93 G1 X249.3213 F71 ; move to target 2024-04-04 07:03:45.406 AbstractMachine TRACE: Machine entering idle state. 2024-04-04 07:03:45.406 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S93 G1 X249.3213 F71 ; move to target 2024-04-04 07:03:45.406 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:03:45.407 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:03:47.331 AbstractHeadMountable DEBUG: N1.moveTo((185.600259, 122.600471, 0.000000, 0.000000 mm), 0.9) 2024-04-04 07:03:47.338 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S1385 G1 X149.3513 F15790 ; move to target 2024-04-04 07:03:47.339 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S1385 G1 X149.3513 F15790 ; move to target 2024-04-04 07:03:47.339 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S212 G1 X149.3213 F186 ; move to target 2024-04-04 07:03:47.339 AbstractMachine TRACE: Machine entering idle state. 2024-04-04 07:03:47.340 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S212 G1 X149.3213 F186 ; move to target 2024-04-04 07:03:47.340 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:03:47.341 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:03:48.381 AbstractHeadMountable DEBUG: N1.moveTo((185.600259, 222.600471, 0.000000, 0.000000 mm), 0.9) 2024-04-04 07:03:48.386 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S1215 G1 Y199.4913 F15663 ; move to target 2024-04-04 07:03:48.386 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S18 G1 Y199.9438 F120 ; move to target 2024-04-04 07:03:48.386 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S1215 G1 Y199.4913 F15663 ; move to target 2024-04-04 07:03:48.386 AbstractMachine TRACE: Machine entering idle state. 2024-04-04 07:03:48.386 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S18 G1 Y199.9438 F120 ; move to target 2024-04-04 07:03:48.387 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:03:48.388 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:03:51.346 AbstractHeadMountable DEBUG: N1.moveTo((185.600259, 122.600471, 0.000000, 0.000000 mm), 0.9) 2024-04-04 07:03:51.351 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S1215 G1 Y100.3430 F15663 ; move to target 2024-04-04 07:03:51.351 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S18 G1 Y99.8905 F120 ; move to target 2024-04-04 07:03:51.351 AbstractMachine TRACE: Machine entering idle state. 2024-04-04 07:03:51.351 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S1215 G1 Y100.3430 F15663 ; move to target 2024-04-04 07:03:51.352 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S18 G1 Y99.8905 F120 ; move to target 2024-04-04 07:03:51.352 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:03:51.353 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:04:02.049 AbstractHeadMountable DEBUG: N1.moveTo((185.600259, 122.600471, 0.000000, -100.000000 mm), 0.9) 2024-04-04 07:04:02.050 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S21 G1 B-100.0000 F1800 ; move to target 2024-04-04 07:04:02.050 AbstractMachine TRACE: Machine entering idle state. 2024-04-04 07:04:02.050 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S21 G1 B-100.0000 F1800 ; move to target 2024-04-04 07:04:02.051 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:04:03.169 AbstractHeadMountable DEBUG: N1.moveTo((185.600259, 122.600471, 0.000000, -200.000000 mm), 0.9) 2024-04-04 07:04:03.171 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S21 G1 B160.0000 F1800 ; move to target 2024-04-04 07:04:03.171 AbstractMachine TRACE: Machine entering idle state. 2024-04-04 07:04:03.171 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S21 G1 B160.0000 F1800 ; move to target 2024-04-04 07:04:03.173 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:04:03.784 AbstractHeadMountable DEBUG: N1.moveTo((185.600259, 122.600471, 0.000000, 60.000000 mm), 0.9) 2024-04-04 07:04:03.785 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S21 G1 B60.0000 F1800 ; move to target 2024-04-04 07:04:03.786 AbstractMachine TRACE: Machine entering idle state. 2024-04-04 07:04:03.786 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S21 G1 B60.0000 F1800 ; move to target 2024-04-04 07:04:03.787 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:04:04.845 AbstractHeadMountable DEBUG: N1.moveTo((185.600259, 122.600471, 0.000000, 160.000000 mm), 0.9) 2024-04-04 07:04:04.847 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S21 G1 B160.0000 F1800 ; move to target 2024-04-04 07:04:04.847 AbstractMachine TRACE: Machine entering idle state. 2024-04-04 07:04:04.847 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S21 G1 B160.0000 F1800 ; move to target 2024-04-04 07:04:04.849 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:04:05.438 AbstractHeadMountable DEBUG: N1.moveTo((185.600259, 122.600471, 0.000000, 260.000000 mm), 0.9) 2024-04-04 07:04:05.439 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S21 G1 B-100.0000 F1800 ; move to target 2024-04-04 07:04:05.440 AbstractMachine TRACE: Machine entering idle state. 2024-04-04 07:04:05.440 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S21 G1 B-100.0000 F1800 ; move to target 2024-04-04 07:04:05.441 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:04:05.867 AbstractHeadMountable DEBUG: N1.moveTo((185.600259, 122.600471, 0.000000, 0.000000 mm), 0.9) 2024-04-04 07:04:05.868 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S21 G1 B0.0000 F1800 ; move to target 2024-04-04 07:04:05.869 AbstractMachine TRACE: Machine entering idle state. 2024-04-04 07:04:05.869 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S21 G1 B0.0000 F1800 ; move to target 2024-04-04 07:04:05.870 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:04:06.472 AbstractHeadMountable DEBUG: N1.moveTo((185.600259, 122.600471, 0.000000, 100.000000 mm), 0.9) 2024-04-04 07:04:06.473 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S21 G1 B100.0000 F1800 ; move to target 2024-04-04 07:04:06.473 AbstractMachine TRACE: Machine entering idle state. 2024-04-04 07:04:06.474 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S21 G1 B100.0000 F1800 ; move to target 2024-04-04 07:04:06.475 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:04:51.422 ReferenceMachine DEBUG: setEnabled(false) 2024-04-04 07:04:51.422 ReferenceMachine INFO: setHomed(false) 2024-04-04 07:04:51.423 GcodeDriver$ReaderThread TRACE: [Schultz:COM3] Read error while disconnecting (expected) 2024-04-04 07:04:51.523 GcodeAsyncDriver$WriterThread TRACE: [Schultz:COM3] disconnectRequested, bye-bye. 2024-04-04 07:04:51.523 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] Read error while disconnecting (expected) 2024-04-04 07:04:51.624 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] disconnectRequested, bye-bye. 2024-04-04 07:04:51.636 AbstractMachine TRACE: Machine entering idle state. 2024-04-04 07:17:06.975 ReferenceMachine DEBUG: setEnabled(true) 2024-04-04 07:17:06.975 GcodeDriver DEBUG: [Smoothie:COM4] Connect 2024-04-04 07:17:06.993 GcodeDriver TRACE: Smoothie waiting for connection 15000ms 2024-04-04 07:17:21.995 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> G21 ; 2024-04-04 07:17:21.995 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> G90 ; Set absolute positioning mode 2024-04-04 07:17:21.995 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M82 ; Set absolute mode for extruder 2024-04-04 07:17:21.995 GcodeDriver TRACE: Send-on-change logic for Feed Rate, Acceleration and Jerk reset 2024-04-04 07:17:21.995 GcodeDriver DEBUG: [Schultz:COM3] Connect 2024-04-04 07:17:21.995 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> G21 ; 2024-04-04 07:17:21.996 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:17:21.996 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> G90 ; Set absolute positioning mode 2024-04-04 07:17:21.996 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M82 ; Set absolute mode for extruder 2024-04-04 07:17:21.996 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:17:21.997 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:17:22.011 GcodeDriver TRACE: Schultz waiting for connection 3000ms 2024-04-04 07:17:22.068 GcodeDriver$ReaderThread TRACE: [Schultz:COM3] << Controller starting... 2024-04-04 07:17:22.070 GcodeDriver$ReaderThread TRACE: [Schultz:COM3] << Controller ready. 2024-04-04 07:17:25.011 GcodeAsyncDriver DEBUG: [Schultz:COM3] commandQueue offer >> G21 ; Set millimeters mode 2024-04-04 07:17:25.011 GcodeAsyncDriver DEBUG: [Schultz:COM3] commandQueue offer >> G90 ; Set absolute positioning mode 2024-04-04 07:17:25.011 GcodeDriver TRACE: Send-on-change logic for Feed Rate, Acceleration and Jerk reset 2024-04-04 07:17:25.011 GcodeAsyncDriver$WriterThread TRACE: [Schultz:COM3] >> G21 ; Set millimeters mode 2024-04-04 07:17:25.014 GcodeDriver$ReaderThread TRACE: [Schultz:COM3] << G21 ; Set millimeters mode 2024-04-04 07:17:25.017 GcodeDriver$ReaderThread TRACE: [Schultz:COM3] << ok unknown or empty command ignored 2024-04-04 07:17:25.017 GcodeDriver TRACE: [Schultz:COM3] confirmed G21 ; Set millimeters mode 2024-04-04 07:17:25.017 GcodeAsyncDriver$WriterThread TRACE: [Schultz:COM3] >> G90 ; Set absolute positioning mode 2024-04-04 07:17:25.019 AbstractMachine TRACE: Machine entering idle state. 2024-04-04 07:17:25.021 GcodeDriver$ReaderThread TRACE: [Schultz:COM3] << G90 ; Set absolute positioning mode 2024-04-04 07:17:25.024 GcodeDriver$ReaderThread TRACE: [Schultz:COM3] << ok unknown or empty command ignored 2024-04-04 07:19:08.829 ReferenceMachine DEBUG: homing machine 2024-04-04 07:19:08.829 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S1000 ; set a low acceleration 2024-04-04 07:19:08.829 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> G28 A0 Z0 2024-04-04 07:19:08.829 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> G28 X88 Y42 B0 C0; Home all axes 2024-04-04 07:19:08.829 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> G92 X0 Y0 Z0 A0 B0 C0; Set coordinates to zero. 2024-04-04 07:19:08.829 GcodeDriver TRACE: Send-on-change logic for Feed Rate, Acceleration and Jerk reset 2024-04-04 07:19:08.830 GcodeAsyncDriver DEBUG: [Schultz:COM3] commandQueue offer >> G28 ; Home all axes 2024-04-04 07:19:08.830 GcodeDriver TRACE: Send-on-change logic for Feed Rate, Acceleration and Jerk reset 2024-04-04 07:19:08.830 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S1000 ; set a low acceleration 2024-04-04 07:19:08.830 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M400 ; Wait for moves to complete before returning 2024-04-04 07:19:08.830 GcodeDriver TRACE: [Schultz:COM3] confirmed G90 ; Set absolute positioning mode 2024-04-04 07:19:08.830 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M114 ; get position 2024-04-04 07:19:08.830 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> G28 A0 Z0 2024-04-04 07:19:08.830 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:19:08.830 GcodeAsyncDriver$WriterThread TRACE: [Schultz:COM3] >> G28 ; Home all axes 2024-04-04 07:19:08.830 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> G28 X88 Y42 B0 C0; Home all axes 2024-04-04 07:19:08.830 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> G92 X0 Y0 Z0 A0 B0 C0; Set coordinates to zero. 2024-04-04 07:19:08.830 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M400 ; Wait for moves to complete before returning 2024-04-04 07:19:08.831 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M114 ; get position 2024-04-04 07:19:08.832 GcodeDriver$ReaderThread TRACE: [Schultz:COM3] << G28 ; Home all axes 2024-04-04 07:19:08.835 GcodeDriver$ReaderThread TRACE: [Schultz:COM3] << ok unknown or empty command ignored 2024-04-04 07:19:09.910 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:19:14.469 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:19:14.469 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:19:14.469 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:19:14.470 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok C: X:0.0000 Y:0.0000 Z:0.0000 A:0.0000 B:0.0000 C:0.0000 2024-04-04 07:19:14.470 GcodeDriver TRACE: Position report: ok C: X:0.0000 Y:0.0000 Z:0.0000 A:0.0000 B:0.0000 C:0.0000 2024-04-04 07:19:14.470 GcodeDriver TRACE: Smoothie got lastReportedLocation (x:0.000000, y:0.000000, z1:0.000000, z2:0.000000, c1:0.000000, c2:0.000000) 2024-04-04 07:19:14.470 GcodeAsyncDriver TRACE: Smoothie confirmation complete. 2024-04-04 07:19:14.470 GcodeAsyncDriver DEBUG: [Schultz:COM3] commandQueue offer >> M400 ; Wait for moves to complete before returning 2024-04-04 07:19:14.471 GcodeDriver TRACE: [Schultz:COM3] confirmed G28 ; Home all axes 2024-04-04 07:19:14.471 GcodeAsyncDriver$WriterThread TRACE: [Schultz:COM3] >> M400 ; Wait for moves to complete before returning 2024-04-04 07:19:14.476 GcodeDriver$ReaderThread TRACE: [Schultz:COM3] << M400 ; Wait for moves to complete before returning 2024-04-04 07:19:14.479 GcodeDriver$ReaderThread TRACE: [Schultz:COM3] << ok unknown or empty command ignored 2024-04-04 07:19:14.479 GcodeDriver TRACE: [Schultz:COM3] confirmed M400 ; Wait for moves to complete before returning 2024-04-04 07:19:14.479 GcodeAsyncDriver TRACE: Schultz waited 9ms to drain command queue. 2024-04-04 07:19:14.479 GcodeAsyncDriver TRACE: Schultz confirmation complete. 2024-04-04 07:19:14.479 AbstractMotionPlanner DEBUG: Reported location changes current location from (x:149.321259, y:99.890471, z1:0.000000, z2:0.000000, c1:100.000000, c2:0.000000) to (x:0.000000, y:0.000000, z1:0.000000, z2:0.000000, c1:0.000000, c2:0.000000) 2024-04-04 07:19:14.479 ReferenceHead DEBUG: H1.home() 2024-04-04 07:19:14.479 ReferenceFiducialLocator DEBUG: Looking for FIDUCIAL-HOME at (110.000000, 43.500000, -25.000000, 0.000000 mm) 2024-04-04 07:19:14.479 ReferenceHead DEBUG: H1.moveToSafeZ(0.9) 2024-04-04 07:19:14.480 AbstractHeadMountable DEBUG: N1.moveToSafeZ(0.9) 2024-04-04 07:19:14.480 AbstractHeadMountable DEBUG: N2.moveToSafeZ(0.9) 2024-04-04 07:19:14.480 AbstractHeadMountable DEBUG: N3.moveToSafeZ(0.9) 2024-04-04 07:19:14.480 AbstractHeadMountable DEBUG: N4.moveToSafeZ(0.9) 2024-04-04 07:19:14.480 AbstractHeadMountable DEBUG: DOWN.moveToSafeZ(0.9) 2024-04-04 07:19:14.480 AbstractHeadMountable DEBUG: DOWN.moveTo((110.000000, 43.500000, 0.000000, 0.000000 mm), 0.9) 2024-04-04 07:19:14.483 AbstractHeadMountable DEBUG: DOWN.moveTo((110.000000, 43.500000, -25.000000, 0.000000 mm), 0.9) 2024-04-04 07:19:14.489 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S1533 G1 X109.3513 Y42.9913 F18008 ; move to target 2024-04-04 07:19:14.490 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S1533 G1 X109.3513 Y42.9913 F18008 ; move to target 2024-04-04 07:19:14.490 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S18 G1 X109.3213 Y43.4438 F120 ; move to target 2024-04-04 07:19:14.490 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M400 ; Wait for moves to complete before returning 2024-04-04 07:19:14.490 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S18 G1 X109.3213 Y43.4438 F120 ; move to target 2024-04-04 07:19:14.490 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M114 ; get position 2024-04-04 07:19:14.490 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M400 ; Wait for moves to complete before returning 2024-04-04 07:19:14.491 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M114 ; get position 2024-04-04 07:19:14.491 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:19:14.492 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:19:15.361 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:19:15.362 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok C: X:109.3213 Y:43.4438 Z:0.0000 A:0.0000 B:0.0000 C:0.0000 2024-04-04 07:19:15.362 GcodeDriver TRACE: Position report: ok C: X:109.3213 Y:43.4438 Z:0.0000 A:0.0000 B:0.0000 C:0.0000 2024-04-04 07:19:15.363 GcodeDriver TRACE: Smoothie got lastReportedLocation (x:109.321300, y:43.443800, z1:0.000000, z2:0.000000, c1:0.000000, c2:0.000000) 2024-04-04 07:19:15.363 GcodeAsyncDriver TRACE: Smoothie confirmation complete. 2024-04-04 07:19:15.363 ReferenceActuator DEBUG: UpCamLight.actuate(false) 2024-04-04 07:19:15.363 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M811 ; turn off Light 2024-04-04 07:19:15.363 Scripting TRACE: Scripting.on Camera.BeforeSettle 2024-04-04 07:19:15.363 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M811 ; turn off Light 2024-04-04 07:19:15.364 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:19:15.364 Scripting TRACE: Scripting.on Camera.BeforeCapture 2024-04-04 07:19:15.377 Scripting TRACE: Scripting.on Camera.AfterCapture 2024-04-04 07:19:15.382 Scripting TRACE: Scripting.on Camera.BeforeCapture 2024-04-04 07:19:15.398 Scripting TRACE: Scripting.on Camera.AfterCapture 2024-04-04 07:19:15.404 AbstractSettlingCamera TRACE: autoSettleAndCapture t=41 auto settle score: 60.784 compute time: 5 2024-04-04 07:19:15.405 Scripting TRACE: Scripting.on Camera.BeforeCapture 2024-04-04 07:19:15.415 Scripting TRACE: Scripting.on Camera.AfterCapture 2024-04-04 07:19:15.422 AbstractSettlingCamera TRACE: autoSettleAndCapture t=58 auto settle score: 34.118 compute time: 6 2024-04-04 07:19:15.422 Scripting TRACE: Scripting.on Camera.BeforeCapture 2024-04-04 07:19:15.441 Scripting TRACE: Scripting.on Camera.AfterCapture 2024-04-04 07:19:15.446 AbstractSettlingCamera TRACE: autoSettleAndCapture t=83 auto settle score: 23.922 compute time: 5 2024-04-04 07:19:15.447 Scripting TRACE: Scripting.on Camera.BeforeCapture 2024-04-04 07:19:15.472 Scripting TRACE: Scripting.on Camera.AfterCapture 2024-04-04 07:19:15.477 AbstractSettlingCamera TRACE: autoSettleAndCapture t=113 auto settle score: 22.353 compute time: 4 2024-04-04 07:19:15.478 AbstractSettlingCamera DEBUG: autoSettleAndCapture in 114 ms 2024-04-04 07:19:15.478 Scripting TRACE: Scripting.on Camera.AfterSettle 2024-04-04 07:19:15.504 CvPipeline DEBUG: Stage "6" throws CvException [org.opencv.core.CvException: cv::Exception: OpenCV(4.5.5) C:\build\master_winpack-bindings-win64-vc14-static\opencv\modules\imgproc\src\thresh.cpp:1555: error: (-2:Unspecified error) in function 'double __cdecl cv::threshold(const class cv::_InputArray &,const class cv::_OutputArray &,double,double,int)' > THRESH_OTSU mode: > 'src_type == CV_8UC1 || src_type == CV_16UC1' > where > 'src_type' is 16 (CV_8UC3) ] 2024-04-04 07:19:15.549 ReferenceFiducialLocator DEBUG: FIDUCIAL-HOME located at (112.453214, 45.095587, -25.000000, 0.000000 mm) 2024-04-04 07:19:15.549 AbstractHeadMountable DEBUG: DOWN.moveTo((112.453214, 45.095587, -25.000000, 0.000000 mm), 0.9) 2024-04-04 07:19:15.555 Scripting TRACE: Scripting.on Camera.BeforeSettle 2024-04-04 07:19:15.562 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S445 G1 X111.8045 Y44.5868 F1480 ; move to target 2024-04-04 07:19:15.563 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S445 G1 X111.8045 Y44.5868 F1480 ; move to target 2024-04-04 07:19:15.563 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S18 G1 X111.7745 Y45.0394 F120 ; move to target 2024-04-04 07:19:15.563 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M400 ; Wait for moves to complete before returning 2024-04-04 07:19:15.563 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S18 G1 X111.7745 Y45.0394 F120 ; move to target 2024-04-04 07:19:15.563 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M114 ; get position 2024-04-04 07:19:15.563 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M400 ; Wait for moves to complete before returning 2024-04-04 07:19:15.564 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M114 ; get position 2024-04-04 07:19:15.564 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:19:15.565 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:19:16.011 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:19:16.012 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok C: X:111.7745 Y:45.0394 Z:0.0000 A:0.0000 B:0.0000 C:0.0000 2024-04-04 07:19:16.012 GcodeDriver TRACE: Position report: ok C: X:111.7745 Y:45.0394 Z:0.0000 A:0.0000 B:0.0000 C:0.0000 2024-04-04 07:19:16.012 GcodeDriver TRACE: Smoothie got lastReportedLocation (x:111.774500, y:45.039400, z1:0.000000, z2:0.000000, c1:0.000000, c2:0.000000) 2024-04-04 07:19:16.012 GcodeAsyncDriver TRACE: Smoothie confirmation complete. 2024-04-04 07:19:16.012 Scripting TRACE: Scripting.on Camera.BeforeCapture 2024-04-04 07:19:16.023 Scripting TRACE: Scripting.on Camera.AfterCapture 2024-04-04 07:19:16.029 Scripting TRACE: Scripting.on Camera.BeforeCapture 2024-04-04 07:19:16.056 Scripting TRACE: Scripting.on Camera.AfterCapture 2024-04-04 07:19:16.061 AbstractSettlingCamera TRACE: autoSettleAndCapture t=49 auto settle score: 52.157 compute time: 5 2024-04-04 07:19:16.062 Scripting TRACE: Scripting.on Camera.BeforeCapture 2024-04-04 07:19:16.090 Scripting TRACE: Scripting.on Camera.AfterCapture 2024-04-04 07:19:16.097 AbstractSettlingCamera TRACE: autoSettleAndCapture t=84 auto settle score: 32.941 compute time: 6 2024-04-04 07:19:16.097 Scripting TRACE: Scripting.on Camera.BeforeCapture 2024-04-04 07:19:16.116 Scripting TRACE: Scripting.on Camera.AfterCapture 2024-04-04 07:19:16.121 AbstractSettlingCamera TRACE: autoSettleAndCapture t=109 auto settle score: 34.118 compute time: 5 2024-04-04 07:19:16.122 AbstractSettlingCamera DEBUG: autoSettleAndCapture in 109 ms 2024-04-04 07:19:16.122 Scripting TRACE: Scripting.on Camera.AfterSettle 2024-04-04 07:19:16.145 CvPipeline DEBUG: Stage "6" throws CvException [org.opencv.core.CvException: cv::Exception: OpenCV(4.5.5) C:\build\master_winpack-bindings-win64-vc14-static\opencv\modules\imgproc\src\thresh.cpp:1555: error: (-2:Unspecified error) in function 'double __cdecl cv::threshold(const class cv::_InputArray &,const class cv::_OutputArray &,double,double,int)' > THRESH_OTSU mode: > 'src_type == CV_8UC1 || src_type == CV_16UC1' > where > 'src_type' is 16 (CV_8UC3) ] 2024-04-04 07:19:16.191 ReferenceFiducialLocator DEBUG: FIDUCIAL-HOME located at (113.470401, 50.839698, -25.000000, 0.000000 mm) 2024-04-04 07:19:16.191 AbstractHeadMountable DEBUG: DOWN.moveTo((113.470401, 50.839698, -25.000000, 0.000000 mm), 0.9) 2024-04-04 07:19:16.198 Scripting TRACE: Scripting.on Camera.BeforeSettle 2024-04-04 07:19:16.205 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S530 G1 X112.8217 Y50.3310 F2269 ; move to target 2024-04-04 07:19:16.205 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S530 G1 X112.8217 Y50.3310 F2269 ; move to target 2024-04-04 07:19:16.205 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S18 G1 X112.7917 Y50.7835 F120 ; move to target 2024-04-04 07:19:16.206 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M400 ; Wait for moves to complete before returning 2024-04-04 07:19:16.206 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S18 G1 X112.7917 Y50.7835 F120 ; move to target 2024-04-04 07:19:16.206 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M114 ; get position 2024-04-04 07:19:16.206 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M400 ; Wait for moves to complete before returning 2024-04-04 07:19:16.206 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M114 ; get position 2024-04-04 07:19:16.207 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:19:16.208 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:19:16.702 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:19:16.703 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok C: X:112.7917 Y:50.7835 Z:0.0000 A:0.0000 B:0.0000 C:0.0000 2024-04-04 07:19:16.703 GcodeDriver TRACE: Position report: ok C: X:112.7917 Y:50.7835 Z:0.0000 A:0.0000 B:0.0000 C:0.0000 2024-04-04 07:19:16.703 GcodeDriver TRACE: Smoothie got lastReportedLocation (x:112.791700, y:50.783500, z1:0.000000, z2:0.000000, c1:0.000000, c2:0.000000) 2024-04-04 07:19:16.703 GcodeAsyncDriver TRACE: Smoothie confirmation complete. 2024-04-04 07:19:16.703 Scripting TRACE: Scripting.on Camera.BeforeCapture 2024-04-04 07:19:16.714 Scripting TRACE: Scripting.on Camera.AfterCapture 2024-04-04 07:19:16.719 Scripting TRACE: Scripting.on Camera.BeforeCapture 2024-04-04 07:19:16.746 Scripting TRACE: Scripting.on Camera.AfterCapture 2024-04-04 07:19:16.752 AbstractSettlingCamera TRACE: autoSettleAndCapture t=49 auto settle score: 51.373 compute time: 5 2024-04-04 07:19:16.753 Scripting TRACE: Scripting.on Camera.BeforeCapture 2024-04-04 07:19:16.768 Scripting TRACE: Scripting.on Camera.AfterCapture 2024-04-04 07:19:16.775 AbstractSettlingCamera TRACE: autoSettleAndCapture t=72 auto settle score: 30.980 compute time: 7 2024-04-04 07:19:16.775 Scripting TRACE: Scripting.on Camera.BeforeCapture 2024-04-04 07:19:16.802 Scripting TRACE: Scripting.on Camera.AfterCapture 2024-04-04 07:19:16.807 AbstractSettlingCamera TRACE: autoSettleAndCapture t=105 auto settle score: 25.098 compute time: 6 2024-04-04 07:19:16.808 AbstractSettlingCamera DEBUG: autoSettleAndCapture in 106 ms 2024-04-04 07:19:16.808 Scripting TRACE: Scripting.on Camera.AfterSettle 2024-04-04 07:19:16.837 CvPipeline DEBUG: Stage "6" throws CvException [org.opencv.core.CvException: cv::Exception: OpenCV(4.5.5) C:\build\master_winpack-bindings-win64-vc14-static\opencv\modules\imgproc\src\thresh.cpp:1555: error: (-2:Unspecified error) in function 'double __cdecl cv::threshold(const class cv::_InputArray &,const class cv::_OutputArray &,double,double,int)' > THRESH_OTSU mode: > 'src_type == CV_8UC1 || src_type == CV_16UC1' > where > 'src_type' is 16 (CV_8UC3) ] 2024-04-04 07:19:16.883 ReferenceFiducialLocator DEBUG: FIDUCIAL-HOME located at (113.570125, 53.671864, -25.000000, 0.000000 mm) 2024-04-04 07:19:16.883 AbstractHeadMountable DEBUG: DOWN.moveTo((113.570125, 53.671864, -25.000000, 0.000000 mm), 0.9) 2024-04-04 07:19:16.888 ReferenceFiducialLocator DEBUG: FIDUCIAL-HOME averaged location is at (113.520263, 52.255781, -25.000000, 0.000000 mm) 2024-04-04 07:19:16.889 AbstractMachine TRACE: Exception caught, executing pending motion: java.lang.Exception: Fiducial FIDUCIAL-HOME detected too far away. at org.openpnp.machine.reference.vision.ReferenceFiducialLocator.getFiducialLocation(ReferenceFiducialLocator.java:512) at org.openpnp.machine.reference.vision.ReferenceFiducialLocator.getHomeFiducialLocation(ReferenceFiducialLocator.java:344) at org.openpnp.machine.reference.ReferenceHead.visualHome(ReferenceHead.java:77) at org.openpnp.machine.reference.ReferenceHead.home(ReferenceHead.java:56) at org.openpnp.spi.base.AbstractMachine.home(AbstractMachine.java:301) at org.openpnp.machine.reference.ReferenceMachine.home(ReferenceMachine.java:531) at org.openpnp.gui.MachineControlsPanel$HomeAction.lambda$actionPerformed$0(MachineControlsPanel.java:420) at org.openpnp.util.UiUtils.lambda$submitUiMachineTask$0(UiUtils.java:67) at org.openpnp.spi.base.AbstractMachine$1.call(AbstractMachine.java:575) at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) at java.base/java.lang.Thread.run(Thread.java:833) 2024-04-04 07:19:16.897 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S399 G1 X112.9214 Y53.1631 F1308 ; move to target 2024-04-04 07:19:16.897 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S399 G1 X112.9214 Y53.1631 F1308 ; move to target 2024-04-04 07:19:16.897 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S18 G1 X112.8914 Y53.6157 F120 ; move to target 2024-04-04 07:19:16.900 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:19:16.900 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S18 G1 X112.8914 Y53.6157 F120 ; move to target 2024-04-04 07:19:16.900 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M400 ; Wait for moves to complete before returning 2024-04-04 07:19:16.901 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M114 ; get position 2024-04-04 07:19:16.901 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M400 ; Wait for moves to complete before returning 2024-04-04 07:19:16.901 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M114 ; get position 2024-04-04 07:19:16.901 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:19:17.344 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:19:17.345 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok C: X:112.8914 Y:53.6157 Z:0.0000 A:0.0000 B:0.0000 C:0.0000 2024-04-04 07:19:17.345 GcodeDriver TRACE: Position report: ok C: X:112.8914 Y:53.6157 Z:0.0000 A:0.0000 B:0.0000 C:0.0000 2024-04-04 07:19:17.345 GcodeDriver TRACE: Smoothie got lastReportedLocation (x:112.891400, y:53.615700, z1:0.000000, z2:0.000000, c1:0.000000, c2:0.000000) 2024-04-04 07:19:17.345 GcodeAsyncDriver TRACE: Smoothie confirmation complete. 2024-04-04 07:19:17.346 AbstractMachine TRACE: Machine entering idle state. 2024-04-04 07:19:17.346 MessageBoxes DEBUG: Error: java.lang.Exception: Fiducial FIDUCIAL-HOME detected too far away. 2024-04-04 07:19:20.981 ReferenceMachine DEBUG: homing machine 2024-04-04 07:19:20.982 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S1000 ; set a low acceleration 2024-04-04 07:19:20.982 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> G28 A0 Z0 2024-04-04 07:19:20.982 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> G28 X88 Y42 B0 C0; Home all axes 2024-04-04 07:19:20.982 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> G92 X0 Y0 Z0 A0 B0 C0; Set coordinates to zero. 2024-04-04 07:19:20.982 GcodeDriver TRACE: Send-on-change logic for Feed Rate, Acceleration and Jerk reset 2024-04-04 07:19:20.982 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S1000 ; set a low acceleration 2024-04-04 07:19:20.982 GcodeAsyncDriver DEBUG: [Schultz:COM3] commandQueue offer >> G28 ; Home all axes 2024-04-04 07:19:20.982 GcodeDriver TRACE: Send-on-change logic for Feed Rate, Acceleration and Jerk reset 2024-04-04 07:19:20.982 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> G28 A0 Z0 2024-04-04 07:19:20.982 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M400 ; Wait for moves to complete before returning 2024-04-04 07:19:20.982 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M114 ; get position 2024-04-04 07:19:20.982 GcodeAsyncDriver$WriterThread TRACE: [Schultz:COM3] >> G28 ; Home all axes 2024-04-04 07:19:20.982 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> G28 X88 Y42 B0 C0; Home all axes 2024-04-04 07:19:20.982 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:19:20.983 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> G92 X0 Y0 Z0 A0 B0 C0; Set coordinates to zero. 2024-04-04 07:19:20.983 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M400 ; Wait for moves to complete before returning 2024-04-04 07:19:20.983 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M114 ; get position 2024-04-04 07:19:20.984 GcodeDriver$ReaderThread TRACE: [Schultz:COM3] << G28 ; Home all axes 2024-04-04 07:19:20.987 GcodeDriver$ReaderThread TRACE: [Schultz:COM3] << ok unknown or empty command ignored 2024-04-04 07:19:22.059 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:19:24.558 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:19:24.558 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:19:24.558 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:19:24.559 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok C: X:0.0000 Y:0.0000 Z:0.0000 A:0.0000 B:0.0000 C:0.0000 2024-04-04 07:19:24.559 GcodeDriver TRACE: Position report: ok C: X:0.0000 Y:0.0000 Z:0.0000 A:0.0000 B:0.0000 C:0.0000 2024-04-04 07:19:24.560 GcodeDriver TRACE: Smoothie got lastReportedLocation (x:0.000000, y:0.000000, z1:0.000000, z2:0.000000, c1:0.000000, c2:0.000000) 2024-04-04 07:19:24.560 GcodeAsyncDriver TRACE: Smoothie confirmation complete. 2024-04-04 07:19:24.560 GcodeAsyncDriver DEBUG: [Schultz:COM3] commandQueue offer >> M400 ; Wait for moves to complete before returning 2024-04-04 07:19:24.560 GcodeDriver TRACE: [Schultz:COM3] confirmed G28 ; Home all axes 2024-04-04 07:19:24.561 GcodeAsyncDriver$WriterThread TRACE: [Schultz:COM3] >> M400 ; Wait for moves to complete before returning 2024-04-04 07:19:24.566 GcodeDriver$ReaderThread TRACE: [Schultz:COM3] << M400 ; Wait for moves to complete before returning 2024-04-04 07:19:24.569 GcodeDriver$ReaderThread TRACE: [Schultz:COM3] << ok unknown or empty command ignored 2024-04-04 07:19:24.569 GcodeDriver TRACE: [Schultz:COM3] confirmed M400 ; Wait for moves to complete before returning 2024-04-04 07:19:24.569 GcodeAsyncDriver TRACE: Schultz waited 9ms to drain command queue. 2024-04-04 07:19:24.569 GcodeAsyncDriver TRACE: Schultz confirmation complete. 2024-04-04 07:19:24.569 AbstractMotionPlanner DEBUG: Reported location changes current location from (x:112.891384, y:53.562335, z1:0.000000, z2:0.000000, c1:0.000000, c2:0.000000) to (x:0.000000, y:0.000000, z1:0.000000, z2:0.000000, c1:0.000000, c2:0.000000) 2024-04-04 07:19:24.569 ReferenceHead DEBUG: H1.home() 2024-04-04 07:19:24.569 ReferenceFiducialLocator DEBUG: Looking for FIDUCIAL-HOME at (110.000000, 43.500000, -25.000000, 0.000000 mm) 2024-04-04 07:19:24.569 ReferenceHead DEBUG: H1.moveToSafeZ(0.9) 2024-04-04 07:19:24.570 AbstractHeadMountable DEBUG: N1.moveToSafeZ(0.9) 2024-04-04 07:19:24.570 AbstractHeadMountable DEBUG: N2.moveToSafeZ(0.9) 2024-04-04 07:19:24.570 AbstractHeadMountable DEBUG: N3.moveToSafeZ(0.9) 2024-04-04 07:19:24.570 AbstractHeadMountable DEBUG: N4.moveToSafeZ(0.9) 2024-04-04 07:19:24.570 AbstractHeadMountable DEBUG: DOWN.moveToSafeZ(0.9) 2024-04-04 07:19:24.570 AbstractHeadMountable DEBUG: DOWN.moveTo((110.000000, 43.500000, 0.000000, 0.000000 mm), 0.9) 2024-04-04 07:19:24.573 AbstractHeadMountable DEBUG: DOWN.moveTo((110.000000, 43.500000, -25.000000, 0.000000 mm), 0.9) 2024-04-04 07:19:24.573 Scripting TRACE: Scripting.on Camera.BeforeSettle 2024-04-04 07:19:24.581 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S1533 G1 X109.3513 Y42.9913 F18008 ; move to target 2024-04-04 07:19:24.581 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S1533 G1 X109.3513 Y42.9913 F18008 ; move to target 2024-04-04 07:19:24.581 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S18 G1 X109.3213 Y43.4438 F120 ; move to target 2024-04-04 07:19:24.581 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M400 ; Wait for moves to complete before returning 2024-04-04 07:19:24.581 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S18 G1 X109.3213 Y43.4438 F120 ; move to target 2024-04-04 07:19:24.581 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M114 ; get position 2024-04-04 07:19:24.581 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M400 ; Wait for moves to complete before returning 2024-04-04 07:19:24.582 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M114 ; get position 2024-04-04 07:19:24.582 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:19:24.583 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:19:25.454 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:19:25.454 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok C: X:109.3213 Y:43.4438 Z:0.0000 A:0.0000 B:0.0000 C:0.0000 2024-04-04 07:19:25.455 GcodeDriver TRACE: Position report: ok C: X:109.3213 Y:43.4438 Z:0.0000 A:0.0000 B:0.0000 C:0.0000 2024-04-04 07:19:25.455 GcodeDriver TRACE: Smoothie got lastReportedLocation (x:109.321300, y:43.443800, z1:0.000000, z2:0.000000, c1:0.000000, c2:0.000000) 2024-04-04 07:19:25.455 GcodeAsyncDriver TRACE: Smoothie confirmation complete. 2024-04-04 07:19:25.455 Scripting TRACE: Scripting.on Camera.BeforeCapture 2024-04-04 07:19:25.468 Scripting TRACE: Scripting.on Camera.AfterCapture 2024-04-04 07:19:25.473 Scripting TRACE: Scripting.on Camera.BeforeCapture 2024-04-04 07:19:25.485 Scripting TRACE: Scripting.on Camera.AfterCapture 2024-04-04 07:19:25.500 AbstractSettlingCamera TRACE: autoSettleAndCapture t=45 auto settle score: 48.235 compute time: 14 2024-04-04 07:19:25.500 Scripting TRACE: Scripting.on Camera.BeforeCapture 2024-04-04 07:19:25.512 Scripting TRACE: Scripting.on Camera.AfterCapture 2024-04-04 07:19:25.520 AbstractSettlingCamera TRACE: autoSettleAndCapture t=66 auto settle score: 27.843 compute time: 7 2024-04-04 07:19:25.521 Scripting TRACE: Scripting.on Camera.BeforeCapture 2024-04-04 07:19:25.541 Scripting TRACE: Scripting.on Camera.AfterCapture 2024-04-04 07:19:25.547 AbstractSettlingCamera TRACE: autoSettleAndCapture t=93 auto settle score: 23.529 compute time: 6 2024-04-04 07:19:25.548 Scripting TRACE: Scripting.on Camera.BeforeCapture 2024-04-04 07:19:25.569 Scripting TRACE: Scripting.on Camera.AfterCapture 2024-04-04 07:19:25.574 AbstractSettlingCamera TRACE: autoSettleAndCapture t=119 auto settle score: 22.353 compute time: 4 2024-04-04 07:19:25.574 AbstractSettlingCamera DEBUG: autoSettleAndCapture in 120 ms 2024-04-04 07:19:25.575 Scripting TRACE: Scripting.on Camera.AfterSettle 2024-04-04 07:19:25.601 CvPipeline DEBUG: Stage "6" throws CvException [org.opencv.core.CvException: cv::Exception: OpenCV(4.5.5) C:\build\master_winpack-bindings-win64-vc14-static\opencv\modules\imgproc\src\thresh.cpp:1555: error: (-2:Unspecified error) in function 'double __cdecl cv::threshold(const class cv::_InputArray &,const class cv::_OutputArray &,double,double,int)' > THRESH_OTSU mode: > 'src_type == CV_8UC1 || src_type == CV_16UC1' > where > 'src_type' is 16 (CV_8UC3) ] 2024-04-04 07:19:25.647 ReferenceFiducialLocator DEBUG: FIDUCIAL-HOME located at (112.572883, 44.975918, -25.000000, 0.000000 mm) 2024-04-04 07:19:25.647 AbstractHeadMountable DEBUG: DOWN.moveTo((112.572883, 44.975918, -25.000000, 0.000000 mm), 0.9) 2024-04-04 07:19:25.652 Scripting TRACE: Scripting.on Camera.BeforeSettle 2024-04-04 07:19:25.665 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S441 G1 X111.9242 Y44.4672 F1490 ; move to target 2024-04-04 07:19:25.666 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S441 G1 X111.9242 Y44.4672 F1490 ; move to target 2024-04-04 07:19:25.666 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S18 G1 X111.8941 Y44.9197 F120 ; move to target 2024-04-04 07:19:25.666 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S18 G1 X111.8941 Y44.9197 F120 ; move to target 2024-04-04 07:19:25.666 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M400 ; Wait for moves to complete before returning 2024-04-04 07:19:25.666 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M400 ; Wait for moves to complete before returning 2024-04-04 07:19:25.666 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M114 ; get position 2024-04-04 07:19:25.666 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M114 ; get position 2024-04-04 07:19:25.667 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:19:25.668 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:19:26.115 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:19:26.117 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok C: X:111.8941 Y:44.9197 Z:0.0000 A:0.0000 B:0.0000 C:0.0000 2024-04-04 07:19:26.117 GcodeDriver TRACE: Position report: ok C: X:111.8941 Y:44.9197 Z:0.0000 A:0.0000 B:0.0000 C:0.0000 2024-04-04 07:19:26.117 GcodeDriver TRACE: Smoothie got lastReportedLocation (x:111.894100, y:44.919700, z1:0.000000, z2:0.000000, c1:0.000000, c2:0.000000) 2024-04-04 07:19:26.117 GcodeAsyncDriver TRACE: Smoothie confirmation complete. 2024-04-04 07:19:26.118 Scripting TRACE: Scripting.on Camera.BeforeCapture 2024-04-04 07:19:26.127 Scripting TRACE: Scripting.on Camera.AfterCapture 2024-04-04 07:19:26.131 Scripting TRACE: Scripting.on Camera.BeforeCapture 2024-04-04 07:19:26.142 Scripting TRACE: Scripting.on Camera.AfterCapture 2024-04-04 07:19:26.147 AbstractSettlingCamera TRACE: autoSettleAndCapture t=30 auto settle score: 49.020 compute time: 3 2024-04-04 07:19:26.147 Scripting TRACE: Scripting.on Camera.BeforeCapture 2024-04-04 07:19:26.173 Scripting TRACE: Scripting.on Camera.AfterCapture 2024-04-04 07:19:26.178 AbstractSettlingCamera TRACE: autoSettleAndCapture t=62 auto settle score: 25.490 compute time: 4 2024-04-04 07:19:26.178 Scripting TRACE: Scripting.on Camera.BeforeCapture 2024-04-04 07:19:26.205 Scripting TRACE: Scripting.on Camera.AfterCapture 2024-04-04 07:19:26.212 AbstractSettlingCamera TRACE: autoSettleAndCapture t=95 auto settle score: 30.980 compute time: 5 2024-04-04 07:19:26.212 Scripting TRACE: Scripting.on Camera.BeforeCapture 2024-04-04 07:19:26.238 Scripting TRACE: Scripting.on Camera.AfterCapture 2024-04-04 07:19:26.243 AbstractSettlingCamera TRACE: autoSettleAndCapture t=126 auto settle score: 27.451 compute time: 4 2024-04-04 07:19:26.243 AbstractSettlingCamera DEBUG: autoSettleAndCapture in 127 ms 2024-04-04 07:19:26.244 Scripting TRACE: Scripting.on Camera.AfterSettle 2024-04-04 07:19:26.267 CvPipeline DEBUG: Stage "6" throws CvException [org.opencv.core.CvException: cv::Exception: OpenCV(4.5.5) C:\build\master_winpack-bindings-win64-vc14-static\opencv\modules\imgproc\src\thresh.cpp:1555: error: (-2:Unspecified error) in function 'double __cdecl cv::threshold(const class cv::_InputArray &,const class cv::_OutputArray &,double,double,int)' > THRESH_OTSU mode: > 'src_type == CV_8UC1 || src_type == CV_16UC1' > where > 'src_type' is 16 (CV_8UC3) ] 2024-04-04 07:19:26.311 ReferenceFiducialLocator DEBUG: FIDUCIAL-HOME located at (112.433269, 44.816359, -25.000000, 0.000000 mm) 2024-04-04 07:19:26.311 AbstractHeadMountable DEBUG: DOWN.moveTo((112.433269, 44.816359, -25.000000, 0.000000 mm), 0.9) 2024-04-04 07:19:26.316 Scripting TRACE: Scripting.on Camera.BeforeSettle 2024-04-04 07:19:26.323 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S204 G1 X111.7846 Y45.1594 F311 ; move to target 2024-04-04 07:19:26.324 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S18 G1 X111.7545 Y44.7068 F120 ; move to target 2024-04-04 07:19:26.324 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S204 G1 X111.7846 Y45.1594 F311 ; move to target 2024-04-04 07:19:26.324 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M400 ; Wait for moves to complete before returning 2024-04-04 07:19:26.324 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M114 ; get position 2024-04-04 07:19:26.324 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S18 G1 X111.7545 Y44.7068 F120 ; move to target 2024-04-04 07:19:26.324 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M400 ; Wait for moves to complete before returning 2024-04-04 07:19:26.325 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M114 ; get position 2024-04-04 07:19:26.325 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:19:26.326 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:19:26.713 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:19:26.713 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok C: X:111.7545 Y:44.7068 Z:0.0000 A:0.0000 B:0.0000 C:0.0000 2024-04-04 07:19:26.714 GcodeDriver TRACE: Position report: ok C: X:111.7545 Y:44.7068 Z:0.0000 A:0.0000 B:0.0000 C:0.0000 2024-04-04 07:19:26.714 GcodeDriver TRACE: Smoothie got lastReportedLocation (x:111.754500, y:44.706800, z1:0.000000, z2:0.000000, c1:0.000000, c2:0.000000) 2024-04-04 07:19:26.714 GcodeAsyncDriver TRACE: Smoothie confirmation complete. 2024-04-04 07:19:26.714 Scripting TRACE: Scripting.on Camera.BeforeCapture 2024-04-04 07:19:26.723 Scripting TRACE: Scripting.on Camera.AfterCapture 2024-04-04 07:19:26.728 Scripting TRACE: Scripting.on Camera.BeforeCapture 2024-04-04 07:19:26.738 Scripting TRACE: Scripting.on Camera.AfterCapture 2024-04-04 07:19:26.743 AbstractSettlingCamera TRACE: autoSettleAndCapture t=29 auto settle score: 49.020 compute time: 5 2024-04-04 07:19:26.743 Scripting TRACE: Scripting.on Camera.BeforeCapture 2024-04-04 07:19:26.766 Scripting TRACE: Scripting.on Camera.AfterCapture 2024-04-04 07:19:26.771 AbstractSettlingCamera TRACE: autoSettleAndCapture t=57 auto settle score: 33.333 compute time: 4 2024-04-04 07:19:26.771 Scripting TRACE: Scripting.on Camera.BeforeCapture 2024-04-04 07:19:26.798 Scripting TRACE: Scripting.on Camera.AfterCapture 2024-04-04 07:19:26.804 AbstractSettlingCamera TRACE: autoSettleAndCapture t=90 auto settle score: 29.020 compute time: 5 2024-04-04 07:19:26.804 Scripting TRACE: Scripting.on Camera.BeforeCapture 2024-04-04 07:19:26.829 Scripting TRACE: Scripting.on Camera.AfterCapture 2024-04-04 07:19:26.835 AbstractSettlingCamera TRACE: autoSettleAndCapture t=121 auto settle score: 26.667 compute time: 4 2024-04-04 07:19:26.835 AbstractSettlingCamera DEBUG: autoSettleAndCapture in 122 ms 2024-04-04 07:19:26.835 Scripting TRACE: Scripting.on Camera.AfterSettle 2024-04-04 07:19:26.858 CvPipeline DEBUG: Stage "6" throws CvException [org.opencv.core.CvException: cv::Exception: OpenCV(4.5.5) C:\build\master_winpack-bindings-win64-vc14-static\opencv\modules\imgproc\src\thresh.cpp:1555: error: (-2:Unspecified error) in function 'double __cdecl cv::threshold(const class cv::_InputArray &,const class cv::_OutputArray &,double,double,int)' > THRESH_OTSU mode: > 'src_type == CV_8UC1 || src_type == CV_16UC1' > where > 'src_type' is 16 (CV_8UC3) ] 2024-04-04 07:19:26.901 ReferenceFiducialLocator DEBUG: FIDUCIAL-HOME located at (112.453214, 44.936028, -25.000000, 0.000000 mm) 2024-04-04 07:19:26.901 ReferenceFiducialLocator TRACE: FIDUCIAL-HOME less than max. linear offset 0.121mm < 0.200mm, locator satisfied. 2024-04-04 07:19:26.904 AbstractHeadMountable DEBUG: DOWN.moveTo((112.453214, 44.936028, -25.000000, 0.000000 mm), 0.9) 2024-04-04 07:19:26.913 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S198 G1 X111.8045 Y44.4273 F318 ; move to target 2024-04-04 07:19:26.913 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S18 G1 X111.7745 Y44.8798 F120 ; move to target 2024-04-04 07:19:26.913 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S198 G1 X111.8045 Y44.4273 F318 ; move to target 2024-04-04 07:19:26.913 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> G92 X-0.6787 Y-0.0562 ; reset coordinates 2024-04-04 07:19:26.913 ReferenceNozzle DEBUG: N1.home() 2024-04-04 07:19:26.913 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S18 G1 X111.7745 Y44.8798 F120 ; move to target 2024-04-04 07:19:26.913 ReferenceNozzle DEBUG: N2.home() 2024-04-04 07:19:26.913 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> G92 X-0.6787 Y-0.0562 ; reset coordinates 2024-04-04 07:19:26.913 ReferenceNozzle DEBUG: N3.home() 2024-04-04 07:19:26.913 ReferenceNozzle DEBUG: N3.home() nozzle tip 504 ID1.5 calibration reset 2024-04-04 07:19:26.913 ReferenceNozzle DEBUG: N3.home() nozzle tip 506 ID5.0 calibration reset 2024-04-04 07:19:26.913 ReferenceNozzle DEBUG: N3.home() nozzle tip 505 ID3.5 calibration reset 2024-04-04 07:19:26.913 ReferenceNozzle DEBUG: N4.home() 2024-04-04 07:19:26.913 ReferenceNozzle DEBUG: N4.home() nozzle tip 504 ID1.5 calibration reset 2024-04-04 07:19:26.915 ReferenceNozzle DEBUG: N4.home() nozzle tip 506 ID5.0 calibration reset 2024-04-04 07:19:26.915 ReferenceNozzle DEBUG: N4.home() nozzle tip 505 ID3.5 calibration reset 2024-04-04 07:19:26.915 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:19:26.916 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:19:26.916 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:19:27.442 Scripting TRACE: Scripting.on Machine.AfterHoming 2024-04-04 07:19:27.443 ReferenceMachine INFO: setHomed(true) 2024-04-04 07:19:27.444 AbstractMachine TRACE: Machine entering idle state. 2024-04-04 07:19:31.665 AbstractHeadMountable DEBUG: N1.moveTo((135.600259, 22.600471, 0.000000, 0.000000 mm), 0.9) 2024-04-04 07:19:31.679 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S1385 G1 X99.3513 F15793 ; move to target 2024-04-04 07:19:31.679 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S1385 G1 X99.3513 F15793 ; move to target 2024-04-04 07:19:31.679 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S93 G1 X99.3213 F71 ; move to target 2024-04-04 07:19:31.680 AbstractMachine TRACE: Machine entering idle state. 2024-04-04 07:19:31.680 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S93 G1 X99.3213 F71 ; move to target 2024-04-04 07:19:31.680 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M400 ; Wait for moves to complete before returning 2024-04-04 07:19:31.680 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M114 ; get position 2024-04-04 07:19:31.680 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M400 ; Wait for moves to complete before returning 2024-04-04 07:19:31.680 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M114 ; get position 2024-04-04 07:19:31.680 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:19:31.681 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:19:32.289 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:19:32.290 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok C: X:99.3213 Y:-0.0562 Z:0.0000 A:0.0000 B:0.0000 C:0.0000 2024-04-04 07:19:32.290 GcodeDriver TRACE: Position report: ok C: X:99.3213 Y:-0.0562 Z:0.0000 A:0.0000 B:0.0000 C:0.0000 2024-04-04 07:19:32.290 GcodeDriver TRACE: Smoothie got lastReportedLocation (x:99.321300, y:-0.056200, z1:0.000000, z2:0.000000, c1:0.000000, c2:0.000000) 2024-04-04 07:19:32.290 GcodeAsyncDriver TRACE: Smoothie confirmation complete. 2024-04-04 07:19:32.290 ReferenceActuator DEBUG: UpCamLight.actuate(true) 2024-04-04 07:19:32.290 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M810 ; turn on Light 2024-04-04 07:19:32.292 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M810 ; turn on Light 2024-04-04 07:19:32.292 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:19:32.425 AbstractHeadMountable DEBUG: N1.moveTo((235.600259, 22.600471, 0.000000, 0.000000 mm), 0.9) 2024-04-04 07:19:32.436 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S1385 G1 X199.3513 F15793 ; move to target 2024-04-04 07:19:32.436 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S93 G1 X199.3213 F71 ; move to target 2024-04-04 07:19:32.436 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S1385 G1 X199.3513 F15793 ; move to target 2024-04-04 07:19:32.437 AbstractMachine TRACE: Machine entering idle state. 2024-04-04 07:19:32.437 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S93 G1 X199.3213 F71 ; move to target 2024-04-04 07:19:32.438 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:19:32.438 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:19:33.552 AbstractHeadMountable DEBUG: N1.moveTo((235.600259, 122.600471, 0.000000, 0.000000 mm), 0.9) 2024-04-04 07:19:33.557 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S1215 G1 Y99.4913 F15658 ; move to target 2024-04-04 07:19:33.558 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S18 G1 Y99.9438 F120 ; move to target 2024-04-04 07:19:33.558 AbstractMachine TRACE: Machine entering idle state. 2024-04-04 07:19:33.558 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S1215 G1 Y99.4913 F15658 ; move to target 2024-04-04 07:19:33.558 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S18 G1 Y99.9438 F120 ; move to target 2024-04-04 07:19:33.559 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:19:33.560 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:19:34.568 AbstractHeadMountable DEBUG: N1.moveTo((235.600259, 222.600471, 0.000000, 0.000000 mm), 0.9) 2024-04-04 07:19:34.574 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S1215 G1 Y199.4913 F15658 ; move to target 2024-04-04 07:19:34.575 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S18 G1 Y199.9438 F120 ; move to target 2024-04-04 07:19:34.575 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S1215 G1 Y199.4913 F15658 ; move to target 2024-04-04 07:19:34.575 AbstractMachine TRACE: Machine entering idle state. 2024-04-04 07:19:34.575 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S18 G1 Y199.9438 F120 ; move to target 2024-04-04 07:19:34.576 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:19:34.577 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:19:37.277 AbstractHeadMountable DEBUG: N1.moveTo((235.600259, 122.600471, 0.000000, 0.000000 mm), 0.9) 2024-04-04 07:19:37.284 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S1215 G1 Y100.3430 F15663 ; move to target 2024-04-04 07:19:37.286 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S18 G1 Y99.8905 F120 ; move to target 2024-04-04 07:19:37.286 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S1215 G1 Y100.3430 F15663 ; move to target 2024-04-04 07:19:37.286 AbstractMachine TRACE: Machine entering idle state. 2024-04-04 07:19:37.286 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S18 G1 Y99.8905 F120 ; move to target 2024-04-04 07:19:37.287 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:19:37.288 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:19:40.026 AbstractHeadMountable DEBUG: N1.moveTo((235.600259, 222.600471, 0.000000, 0.000000 mm), 0.9) 2024-04-04 07:19:40.031 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S1215 G1 Y199.4913 F15663 ; move to target 2024-04-04 07:19:40.031 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S1215 G1 Y199.4913 F15663 ; move to target 2024-04-04 07:19:40.031 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S18 G1 Y199.9438 F120 ; move to target 2024-04-04 07:19:40.032 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S18 G1 Y199.9438 F120 ; move to target 2024-04-04 07:19:40.032 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:19:40.032 AbstractMachine TRACE: Machine entering idle state. 2024-04-04 07:19:40.033 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:19:41.204 AbstractHeadMountable DEBUG: N1.moveTo((135.600259, 222.600471, 0.000000, 0.000000 mm), 0.9) 2024-04-04 07:19:41.209 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S1385 G1 X99.3513 F15790 ; move to target 2024-04-04 07:19:41.209 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S212 G1 X99.3213 F186 ; move to target 2024-04-04 07:19:41.210 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S1385 G1 X99.3513 F15790 ; move to target 2024-04-04 07:19:41.210 AbstractMachine TRACE: Machine entering idle state. 2024-04-04 07:19:41.210 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S212 G1 X99.3213 F186 ; move to target 2024-04-04 07:19:41.211 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:19:41.211 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:19:42.392 AbstractHeadMountable DEBUG: N1.moveTo((235.600259, 222.600471, 0.000000, 0.000000 mm), 0.9) 2024-04-04 07:19:42.400 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S1385 G1 X199.3513 F15793 ; move to target 2024-04-04 07:19:42.401 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S93 G1 X199.3213 F71 ; move to target 2024-04-04 07:19:42.401 AbstractMachine TRACE: Machine entering idle state. 2024-04-04 07:19:42.401 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S1385 G1 X199.3513 F15793 ; move to target 2024-04-04 07:19:42.401 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S93 G1 X199.3213 F71 ; move to target 2024-04-04 07:19:42.402 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:19:42.403 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:19:47.251 AbstractHeadMountable DEBUG: N1.moveTo((335.600259, 222.600471, 0.000000, 0.000000 mm), 0.67) 2024-04-04 07:19:47.261 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S768 G1 X299.3513 F11757 ; move to target 2024-04-04 07:19:47.262 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S51 G1 X299.3213 F60 ; move to target 2024-04-04 07:19:47.262 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S768 G1 X299.3513 F11757 ; move to target 2024-04-04 07:19:47.262 AbstractMachine TRACE: Machine entering idle state. 2024-04-04 07:19:47.262 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S51 G1 X299.3213 F60 ; move to target 2024-04-04 07:19:47.262 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:19:47.263 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:19:49.046 AbstractHeadMountable DEBUG: N1.moveTo((235.600259, 222.600471, 0.000000, 0.000000 mm), 0.67) 2024-04-04 07:19:49.053 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S768 G1 X199.3513 F11755 ; move to target 2024-04-04 07:19:49.053 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S118 G1 X199.3213 F138 ; move to target 2024-04-04 07:19:49.053 AbstractMachine TRACE: Machine entering idle state. 2024-04-04 07:19:49.053 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S768 G1 X199.3513 F11755 ; move to target 2024-04-04 07:19:49.053 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S118 G1 X199.3213 F138 ; move to target 2024-04-04 07:19:49.054 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:19:49.055 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:19:50.356 AbstractHeadMountable DEBUG: N1.moveTo((235.600259, 322.600471, 0.000000, 0.000000 mm), 0.67) 2024-04-04 07:19:50.362 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S673 G1 Y299.4913 F11657 ; move to target 2024-04-04 07:19:50.362 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S18 G1 Y299.9438 F120 ; move to target 2024-04-04 07:19:50.362 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S673 G1 Y299.4913 F11657 ; move to target 2024-04-04 07:19:50.362 AbstractMachine TRACE: Machine entering idle state. 2024-04-04 07:19:50.362 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S18 G1 Y299.9438 F120 ; move to target 2024-04-04 07:19:50.362 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:19:50.363 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:19:52.041 AbstractHeadMountable DEBUG: N1.moveTo((235.600259, 222.600471, 0.000000, 0.000000 mm), 0.67) 2024-04-04 07:19:52.046 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S673 G1 Y200.3430 F11661 ; move to target 2024-04-04 07:19:52.046 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S18 G1 Y199.8905 F120 ; move to target 2024-04-04 07:19:52.046 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S673 G1 Y200.3430 F11661 ; move to target 2024-04-04 07:19:52.046 AbstractMachine TRACE: Machine entering idle state. 2024-04-04 07:19:52.047 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S18 G1 Y199.8905 F120 ; move to target 2024-04-04 07:19:52.047 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:19:52.048 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:19:57.201 AbstractHeadMountable DEBUG: N1.moveTo((235.600259, 222.600471, 0.000000, -100.000000 mm), 0.86) 2024-04-04 07:19:57.202 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S1479 G1 B-100.0000 F21104 ; move to target 2024-04-04 07:19:57.202 AbstractMachine TRACE: Machine entering idle state. 2024-04-04 07:19:57.202 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S1479 G1 B-100.0000 F21104 ; move to target 2024-04-04 07:19:57.203 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:19:59.311 AbstractHeadMountable DEBUG: N1.moveTo((235.600259, 222.600471, 0.000000, 0.000000 mm), 0.86) 2024-04-04 07:19:59.312 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S1479 G1 B0.0000 F21104 ; move to target 2024-04-04 07:19:59.312 AbstractMachine TRACE: Machine entering idle state. 2024-04-04 07:19:59.313 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S1479 G1 B0.0000 F21104 ; move to target 2024-04-04 07:19:59.314 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:20:00.653 AbstractHeadMountable DEBUG: N1.moveTo((235.600259, 222.600471, 0.000000, 100.000000 mm), 0.86) 2024-04-04 07:20:00.654 GcodeAsyncDriver DEBUG: [Smoothie:COM4] commandQueue offer >> M204 S1479 G1 B100.0000 F21104 ; move to target 2024-04-04 07:20:00.655 AbstractMachine TRACE: Machine entering idle state. 2024-04-04 07:20:00.655 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] >> M204 S1479 G1 B100.0000 F21104 ; move to target 2024-04-04 07:20:00.657 GcodeDriver$ReaderThread TRACE: [Smoothie:COM4] << ok 2024-04-04 07:20:44.410 GcodeDriver$ReaderThread ERROR: [Smoothie:COM4] Read error: java.io.IOException: Read error. at org.openpnp.machine.reference.driver.SerialPortCommunications.read(SerialPortCommunications.java:150) at org.openpnp.machine.reference.driver.ReferenceDriverCommunications.readUntil(ReferenceDriverCommunications.java:108) at org.openpnp.machine.reference.driver.ReferenceDriverCommunications.readLine(ReferenceDriverCommunications.java:86) at org.openpnp.machine.reference.driver.GcodeDriver$ReaderThread.run(GcodeDriver.java:1487) 2024-04-04 07:21:04.737 ReferenceMachine DEBUG: setEnabled(false) 2024-04-04 07:21:04.738 ReferenceMachine INFO: setHomed(false) 2024-04-04 07:21:04.738 GcodeDriver$ReaderThread TRACE: [Schultz:COM3] Read error while disconnecting (expected) 2024-04-04 07:21:04.839 GcodeAsyncDriver$WriterThread TRACE: [Schultz:COM3] disconnectRequested, bye-bye. 2024-04-04 07:21:04.942 GcodeAsyncDriver$WriterThread TRACE: [Smoothie:COM4] disconnectRequested, bye-bye. 2024-04-04 07:21:04.951 AbstractMachine TRACE: Machine entering idle state.