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