2023-04-03 14:12:02.571 Scripting TRACE: Scripting.on Vision.PartAlignment.Before 2023-04-03 14:12:02.575 ReferenceHead DEBUG: H1.moveToSafeZ(1.0) 2023-04-03 14:12:02.575 AbstractHeadMountable DEBUG: N1.moveToSafeZ(1.0) 2023-04-03 14:12:02.576 AbstractHeadMountable DEBUG: N2.moveToSafeZ(1.0) 2023-04-03 14:12:02.576 AbstractHeadMountable DEBUG: Down Locking.moveToSafeZ(1.0) 2023-04-03 14:12:02.576 AbstractHeadMountable DEBUG: N2.moveTo((160.447146, 28.707672, -1.477176, 90.000000 mm), 1.0) 2023-04-03 14:12:02.576 ReferenceNozzle TRACE: N2.toHeadLocation((160.447146, 28.707672, -1.477176, 22.500000 mm), ...) rotation mode offset 67.5 2023-04-03 14:12:02.576 ReferenceNozzle TRACE: N2.toHeadLocation((160.380331, 28.765621, -1.477176, 22.500000 mm), ...) runout compensation (0.066815, -0.057948, 0.000000, 0.000000 mm) 2023-04-03 14:12:02.576 GcodeAsyncDriver DEBUG: serial://ttyUSB0 commandQueue.offer(M119 ; DRAGPIN endstop status, 10000)... 2023-04-03 14:12:02.576 GcodeAsyncDriver$WriterThread TRACE: [serial://ttyUSB0] >> M119 2023-04-03 14:12:02.577 GcodeDriver$ReaderThread TRACE: [serial://ttyUSB0] << X_min:0 Y_min:0 Z_min:0 pins- (X)P4.4:0 (Y)P4.3:0 (Z)P2.13:0 (Z)P4.2:1 2023-04-03 14:12:02.577 GcodeDriver$ReaderThread TRACE: [serial://ttyUSB0] << ok 2023-04-03 14:12:02.577 GcodeDriver TRACE: actuatorRead response: X_min:0 Y_min:0 Z_min:0 pins- (X)P4.4:0 (Y)P4.3:0 (Z)P2.13:0 (Z)P4.2:1 2023-04-03 14:12:02.577 ReferenceActuator DEBUG: DRAGPIN.read(): 1 2023-04-03 14:12:02.592 AbstractHeadMountable DEBUG: N2.moveTo((160.447146, 28.707672, -6.327176, 90.000000 mm), 1.0) 2023-04-03 14:12:02.592 ReferenceNozzle TRACE: N2.toHeadLocation((160.447146, 28.707672, -6.327176, 22.500000 mm), ...) rotation mode offset 67.5 2023-04-03 14:12:02.592 ReferenceNozzle TRACE: N2.toHeadLocation((160.380331, 28.765621, -6.327176, 22.500000 mm), ...) runout compensation (0.066815, -0.057948, 0.000000, 0.000000 mm) 2023-04-03 14:12:02.594 GcodeAsyncDriver DEBUG: serial://ttyUSB0 commandQueue.offer(M204 S50.76 G1 X103.4307 Y47.1038 B22.5000 F7282.79 ; move to target, 10000)... 2023-04-03 14:12:02.594 GcodeAsyncDriver$WriterThread TRACE: [serial://ttyUSB0] >> M204S50.76G1X103.4307Y47.1038B22.5F7282.79 2023-04-03 14:12:02.595 GcodeDriver$ReaderThread TRACE: [serial://ttyUSB0] << ok 2023-04-03 14:12:02.600 GcodeAsyncDriver DEBUG: serial://ttyUSB0 commandQueue.offer(M204 S15.49 G1 X103.3682 Y47.0283 F600.00 ; move to target, 10000)... 2023-04-03 14:12:02.601 GcodeAsyncDriver$WriterThread TRACE: [serial://ttyUSB0] >> M204S15.49G1X103.3682Y47.0283F600 2023-04-03 14:12:02.601 GcodeDriver$ReaderThread TRACE: [serial://ttyUSB0] << ok 2023-04-03 14:12:02.601 GcodeAsyncDriver DEBUG: serial://ttyUSB0 commandQueue.offer(M204 S909.09 G1 Z19.2959 F6000.00 ; move to target, 10000)... 2023-04-03 14:12:02.602 GcodeAsyncDriver$WriterThread TRACE: [serial://ttyUSB0] >> M204S909.09G1Z19.2959F6000 2023-04-03 14:12:02.602 GcodeDriver$ReaderThread TRACE: [serial://ttyUSB0] << ok 2023-04-03 14:12:02.606 GcodeAsyncDriver DEBUG: serial://ttyUSB0 commandQueue.offer(M400 ; Wait for moves to complete before returning, 10000)... 2023-04-03 14:12:02.606 GcodeAsyncDriver DEBUG: serial://ttyUSB0 commandQueue.offer(M114 ; get position, -1)... 2023-04-03 14:12:02.607 GcodeAsyncDriver$WriterThread TRACE: [serial://ttyUSB0] >> M400 2023-04-03 14:12:02.607 GcodeAsyncDriver$WriterThread TRACE: [serial://ttyUSB0] >> M114 2023-04-03 14:12:07.917 GcodeDriver$ReaderThread TRACE: [serial://ttyUSB0] << ok 2023-04-03 14:12:07.917 GcodeDriver$ReaderThread TRACE: [serial://ttyUSB0] << ok C: X:103.3682 Y:47.0283 Z:19.2959 A:-111.3761 B:22.5000 C:0.0000 D:0.0000 2023-04-03 14:12:07.917 GcodeDriver TRACE: Position report: ok C: X:103.3682 Y:47.0283 Z:19.2959 A:-111.3761 B:22.5000 C:0.0000 D:0.0000 2023-04-03 14:12:07.917 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:103.368200, Y:47.028300, ZN:19.295900, C1:-111.376100, C2:22.500000) 2023-04-03 14:12:07.917 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete. 2023-04-03 14:12:07.917 ReferenceActuator DEBUG: UPLED.actuate(true) 2023-04-03 14:12:07.918 GcodeAsyncDriver DEBUG: serial://ttyUSB0 commandQueue.offer(M810 ; UPLED M810 on / M811 off, 10000)... 2023-04-03 14:12:07.918 GcodeAsyncDriver$WriterThread TRACE: [serial://ttyUSB0] >> M810 2023-04-03 14:12:07.918 GcodeDriver$ReaderThread TRACE: [serial://ttyUSB0] << ok 2023-04-03 14:12:07.968 Scripting TRACE: Scripting.on Camera.BeforeSettle 2023-04-03 14:12:07.968 Scripting TRACE: Scripting.on Camera.BeforeCapture 2023-04-03 14:12:07.978 Scripting TRACE: Scripting.on Camera.AfterCapture 2023-04-03 14:12:07.980 Scripting TRACE: Scripting.on Camera.BeforeCapture 2023-04-03 14:12:07.990 Scripting TRACE: Scripting.on Camera.AfterCapture 2023-04-03 14:12:07.993 AbstractSettlingCamera TRACE: autoSettleAndCapture t=24 auto settle score: 0.203 compute time: 2 2023-04-03 14:12:07.993 Scripting TRACE: Scripting.on Camera.BeforeCapture 2023-04-03 14:12:08.017 Scripting TRACE: Scripting.on Camera.AfterCapture 2023-04-03 14:12:08.020 AbstractSettlingCamera TRACE: autoSettleAndCapture t=51 auto settle score: 0.180 compute time: 2 2023-04-03 14:12:08.020 Scripting TRACE: Scripting.on Camera.BeforeCapture 2023-04-03 14:12:08.036 Scripting TRACE: Scripting.on Camera.AfterCapture 2023-04-03 14:12:08.038 AbstractSettlingCamera TRACE: autoSettleAndCapture t=69 auto settle score: 0.171 compute time: 2 2023-04-03 14:12:08.038 AbstractSettlingCamera DEBUG: autoSettleAndCapture in 70 ms 2023-04-03 14:12:08.038 Scripting TRACE: Scripting.on Camera.AfterSettle 2023-04-03 14:12:08.038 ReferenceActuator DEBUG: UPLED.actuate(false) 2023-04-03 14:12:08.039 GcodeAsyncDriver DEBUG: serial://ttyUSB0 commandQueue.offer(M811 ; UPLED M810 on / M811 off, 10000)... 2023-04-03 14:12:08.039 GcodeAsyncDriver$WriterThread TRACE: [serial://ttyUSB0] >> M811 2023-04-03 14:12:08.039 GcodeDriver$ReaderThread TRACE: [serial://ttyUSB0] << ok 2023-04-03 14:12:08.122 MaskHsv TRACE: Fraction actually masked = 0.24285714285714288 2023-04-03 14:12:08.125 MaskHsv TRACE: Fraction actually masked = 0.9678099678099679 2023-04-03 14:12:08.167 ReferenceBottomVision DEBUG: Alignment result: DF40HC70DS-DF40HC3.0-70DS 2023-04-03 14:12:08.168 AbstractHeadMountable DEBUG: N2.moveTo((174.247146, 28.707672, -6.327176, 90.000000 mm), 1.0) 2023-04-03 14:12:08.168 ReferenceNozzle TRACE: N2.toHeadLocation((174.247146, 28.707672, -6.327176, 22.500000 mm), ...) rotation mode offset 67.5 2023-04-03 14:12:08.168 ReferenceNozzle TRACE: N2.toHeadLocation((174.180331, 28.765621, -6.327176, 22.500000 mm), ...) runout compensation (0.066815, -0.057948, 0.000000, 0.000000 mm) 2023-04-03 14:12:08.168 GcodeAsyncDriver DEBUG: serial://ttyUSB0 commandQueue.offer(M119 ; DRAGPIN endstop status, 10000)... 2023-04-03 14:12:08.168 GcodeAsyncDriver$WriterThread TRACE: [serial://ttyUSB0] >> M119 2023-04-03 14:12:08.168 GcodeDriver$ReaderThread TRACE: [serial://ttyUSB0] << X_min:0 Y_min:0 Z_min:0 pins- (X)P4.4:0 (Y)P4.3:0 (Z)P2.13:0 (Z)P4.2:1 2023-04-03 14:12:08.168 GcodeDriver$ReaderThread TRACE: [serial://ttyUSB0] << ok 2023-04-03 14:12:08.168 GcodeDriver TRACE: actuatorRead response: X_min:0 Y_min:0 Z_min:0 pins- (X)P4.4:0 (Y)P4.3:0 (Z)P2.13:0 (Z)P4.2:1 2023-04-03 14:12:08.169 ReferenceActuator DEBUG: DRAGPIN.read(): 1 2023-04-03 14:12:08.170 GcodeAsyncDriver DEBUG: serial://ttyUSB0 commandQueue.offer(M204 S91.85 G1 X117.1201 F2132.43 ; move to target, 10000)... 2023-04-03 14:12:08.170 GcodeAsyncDriver$WriterThread TRACE: [serial://ttyUSB0] >> M204S91.85G1X117.1201F2132.43 2023-04-03 14:12:08.171 GcodeAsyncDriver DEBUG: serial://ttyUSB0 commandQueue.offer(M204 S15.75 G1 X117.1826 F600.00 ; move to target, 10000)... 2023-04-03 14:12:08.171 GcodeDriver$ReaderThread TRACE: [serial://ttyUSB0] << ok 2023-04-03 14:12:08.171 GcodeAsyncDriver$WriterThread TRACE: [serial://ttyUSB0] >> M204S15.75G1X117.1826F600 2023-04-03 14:12:08.171 GcodeDriver$ReaderThread TRACE: [serial://ttyUSB0] << ok 2023-04-03 14:12:08.171 GcodeAsyncDriver DEBUG: serial://ttyUSB0 commandQueue.offer(M400 ; Wait for moves to complete before returning, 10000)... 2023-04-03 14:12:08.171 GcodeAsyncDriver DEBUG: serial://ttyUSB0 commandQueue.offer(M114 ; get position, -1)... 2023-04-03 14:12:08.171 GcodeAsyncDriver$WriterThread TRACE: [serial://ttyUSB0] >> M400 2023-04-03 14:12:08.171 GcodeAsyncDriver$WriterThread TRACE: [serial://ttyUSB0] >> M114 2023-04-03 14:12:09.050 GcodeDriver$ReaderThread TRACE: [serial://ttyUSB0] << ok 2023-04-03 14:12:09.050 GcodeDriver$ReaderThread TRACE: [serial://ttyUSB0] << ok C: X:117.1826 Y:47.0283 Z:19.2959 A:-111.3761 B:22.5000 C:0.0000 D:0.0000 2023-04-03 14:12:09.050 GcodeDriver TRACE: Position report: ok C: X:117.1826 Y:47.0283 Z:19.2959 A:-111.3761 B:22.5000 C:0.0000 D:0.0000 2023-04-03 14:12:09.050 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:117.182600, Y:47.028300, ZN:19.295900, C1:-111.376100, C2:22.500000) 2023-04-03 14:12:09.050 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete. 2023-04-03 14:12:09.050 ReferenceActuator DEBUG: UPLED.actuate(true) 2023-04-03 14:12:09.050 GcodeAsyncDriver DEBUG: serial://ttyUSB0 commandQueue.offer(M810 ; UPLED M810 on / M811 off, 10000)... 2023-04-03 14:12:09.051 GcodeAsyncDriver$WriterThread TRACE: [serial://ttyUSB0] >> M810 2023-04-03 14:12:09.051 GcodeDriver$ReaderThread TRACE: [serial://ttyUSB0] << ok 2023-04-03 14:12:09.101 Scripting TRACE: Scripting.on Camera.BeforeSettle 2023-04-03 14:12:09.101 Scripting TRACE: Scripting.on Camera.BeforeCapture 2023-04-03 14:12:09.110 Scripting TRACE: Scripting.on Camera.AfterCapture 2023-04-03 14:12:09.111 Scripting TRACE: Scripting.on Camera.BeforeCapture 2023-04-03 14:12:09.126 Scripting TRACE: Scripting.on Camera.AfterCapture 2023-04-03 14:12:09.129 AbstractSettlingCamera TRACE: autoSettleAndCapture t=27 auto settle score: 0.170 compute time: 2 2023-04-03 14:12:09.129 Scripting TRACE: Scripting.on Camera.BeforeCapture 2023-04-03 14:12:09.145 Scripting TRACE: Scripting.on Camera.AfterCapture 2023-04-03 14:12:09.147 AbstractSettlingCamera TRACE: autoSettleAndCapture t=46 auto settle score: 0.169 compute time: 2 2023-04-03 14:12:09.147 Scripting TRACE: Scripting.on Camera.BeforeCapture 2023-04-03 14:12:09.170 Scripting TRACE: Scripting.on Camera.AfterCapture 2023-04-03 14:12:09.172 AbstractSettlingCamera TRACE: autoSettleAndCapture t=71 auto settle score: 0.165 compute time: 3 2023-04-03 14:12:09.173 AbstractSettlingCamera DEBUG: autoSettleAndCapture in 71 ms 2023-04-03 14:12:09.173 Scripting TRACE: Scripting.on Camera.AfterSettle 2023-04-03 14:12:09.173 ReferenceActuator DEBUG: UPLED.actuate(false) 2023-04-03 14:12:09.173 GcodeAsyncDriver DEBUG: serial://ttyUSB0 commandQueue.offer(M811 ; UPLED M810 on / M811 off, 10000)... 2023-04-03 14:12:09.173 GcodeAsyncDriver$WriterThread TRACE: [serial://ttyUSB0] >> M811 2023-04-03 14:12:09.173 GcodeDriver$ReaderThread TRACE: [serial://ttyUSB0] << ok 2023-04-03 14:12:09.253 MaskHsv TRACE: Fraction actually masked = 0.2789164539164539 2023-04-03 14:12:09.256 MaskHsv TRACE: Fraction actually masked = 0.9777611277611278 2023-04-03 14:12:09.294 ReferenceBottomVision DEBUG: Alignment result: DF40HC70DS-DF40HC3.0-70DS 2023-04-03 14:12:09.294 ReferenceBottomVision DEBUG: Bottom vision part DF40HC70DS-DF40HC3.0-70DS result rect { {202.87959366318069, 368.91333521715256} 687x845 * -75.95769586615347 } 2023-04-03 14:12:09.294 ReferenceBottomVision DEBUG: Offsets too large (-6.592261, 1.871646, 0.000000, -14.042304 mm) : center offset 6.852807311494815 > 1.0 2023-04-03 14:12:09.295 AbstractHeadMountable DEBUG: N2.moveTo((180.839407, 26.836026, -6.327176, 104.042304 mm), 1.0) 2023-04-03 14:12:09.295 ReferenceNozzle TRACE: N2.toHeadLocation((180.839407, 26.836026, -6.327176, 36.542304 mm), ...) rotation mode offset 67.5 2023-04-03 14:12:09.295 ReferenceNozzle TRACE: N2.toHeadLocation((180.760528, 26.876031, -6.327176, 36.542304 mm), ...) runout compensation (0.078879, -0.040005, 0.000000, 0.000000 mm) 2023-04-03 14:12:09.295 GcodeAsyncDriver DEBUG: serial://ttyUSB0 commandQueue.offer(M119 ; DRAGPIN endstop status, 10000)... 2023-04-03 14:12:09.296 GcodeAsyncDriver$WriterThread TRACE: [serial://ttyUSB0] >> M119 2023-04-03 14:12:09.296 GcodeDriver$ReaderThread TRACE: [serial://ttyUSB0] << X_min:0 Y_min:0 Z_min:0 pins- (X)P4.4:0 (Y)P4.3:0 (Z)P2.13:0 (Z)P4.2:1 2023-04-03 14:12:09.296 GcodeDriver$ReaderThread TRACE: [serial://ttyUSB0] << ok 2023-04-03 14:12:09.296 GcodeDriver TRACE: actuatorRead response: X_min:0 Y_min:0 Z_min:0 pins- (X)P4.4:0 (Y)P4.3:0 (Z)P2.13:0 (Z)P4.2:1 2023-04-03 14:12:09.296 ReferenceActuator DEBUG: DRAGPIN.read(): 1 2023-04-03 14:12:09.298 GcodeAsyncDriver DEBUG: serial://ttyUSB0 commandQueue.offer(M204 S177.28 G1 X123.7003 Y45.2142 B36.5423 F3153.99 ; move to target, 10000)... 2023-04-03 14:12:09.298 GcodeAsyncDriver$WriterThread TRACE: [serial://ttyUSB0] >> M204S177.28G1X123.7003Y45.2142B36.5423F3153.99 2023-04-03 14:12:09.298 GcodeDriver$ReaderThread TRACE: [serial://ttyUSB0] << ok 2023-04-03 14:12:09.299 GcodeAsyncDriver DEBUG: serial://ttyUSB0 commandQueue.offer(M204 S15.49 G1 X123.7628 Y45.1387 F600.00 ; move to target, 10000)... 2023-04-03 14:12:09.299 GcodeAsyncDriver$WriterThread TRACE: [serial://ttyUSB0] >> M204S15.49G1X123.7628Y45.1387F600 2023-04-03 14:12:09.299 GcodeDriver$ReaderThread TRACE: [serial://ttyUSB0] << ok 2023-04-03 14:12:09.301 GcodeAsyncDriver DEBUG: serial://ttyUSB0 commandQueue.offer(M400 ; Wait for moves to complete before returning, 10000)... 2023-04-03 14:12:09.301 GcodeAsyncDriver DEBUG: serial://ttyUSB0 commandQueue.offer(M114 ; get position, -1)... 2023-04-03 14:12:09.301 GcodeAsyncDriver$WriterThread TRACE: [serial://ttyUSB0] >> M400 2023-04-03 14:12:09.301 GcodeAsyncDriver$WriterThread TRACE: [serial://ttyUSB0] >> M114 2023-04-03 14:12:10.044 GcodeDriver$ReaderThread TRACE: [serial://ttyUSB0] << ok 2023-04-03 14:12:10.045 GcodeDriver$ReaderThread TRACE: [serial://ttyUSB0] << ok C: X:123.7628 Y:45.1387 Z:19.2959 A:-111.3761 B:36.5423 C:0.0000 D:0.0000 2023-04-03 14:12:10.045 GcodeDriver TRACE: Position report: ok C: X:123.7628 Y:45.1387 Z:19.2959 A:-111.3761 B:36.5423 C:0.0000 D:0.0000 2023-04-03 14:12:10.045 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:123.762800, Y:45.138700, ZN:19.295900, C1:-111.376100, C2:36.542300) 2023-04-03 14:12:10.046 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete. 2023-04-03 14:12:10.046 ReferenceActuator DEBUG: UPLED.actuate(true) 2023-04-03 14:12:10.046 GcodeAsyncDriver DEBUG: serial://ttyUSB0 commandQueue.offer(M810 ; UPLED M810 on / M811 off, 10000)... 2023-04-03 14:12:10.046 GcodeAsyncDriver$WriterThread TRACE: [serial://ttyUSB0] >> M810 2023-04-03 14:12:10.046 GcodeDriver$ReaderThread TRACE: [serial://ttyUSB0] << ok 2023-04-03 14:12:10.096 Scripting TRACE: Scripting.on Camera.BeforeSettle 2023-04-03 14:12:10.097 Scripting TRACE: Scripting.on Camera.BeforeCapture 2023-04-03 14:12:10.118 Scripting TRACE: Scripting.on Camera.AfterCapture 2023-04-03 14:12:10.120 Scripting TRACE: Scripting.on Camera.BeforeCapture 2023-04-03 14:12:10.139 Scripting TRACE: Scripting.on Camera.AfterCapture 2023-04-03 14:12:10.141 AbstractSettlingCamera TRACE: autoSettleAndCapture t=44 auto settle score: 0.162 compute time: 2 2023-04-03 14:12:10.141 Scripting TRACE: Scripting.on Camera.BeforeCapture 2023-04-03 14:12:10.158 Scripting TRACE: Scripting.on Camera.AfterCapture 2023-04-03 14:12:10.160 AbstractSettlingCamera TRACE: autoSettleAndCapture t=64 auto settle score: 0.161 compute time: 3 2023-04-03 14:12:10.160 Scripting TRACE: Scripting.on Camera.BeforeCapture 2023-04-03 14:12:10.176 Scripting TRACE: Scripting.on Camera.AfterCapture 2023-04-03 14:12:10.178 AbstractSettlingCamera TRACE: autoSettleAndCapture t=81 auto settle score: 0.162 compute time: 2 2023-04-03 14:12:10.178 AbstractSettlingCamera DEBUG: autoSettleAndCapture in 81 ms 2023-04-03 14:12:10.178 Scripting TRACE: Scripting.on Camera.AfterSettle 2023-04-03 14:12:10.178 ReferenceActuator DEBUG: UPLED.actuate(false) 2023-04-03 14:12:10.178 GcodeAsyncDriver DEBUG: serial://ttyUSB0 commandQueue.offer(M811 ; UPLED M810 on / M811 off, 10000)... 2023-04-03 14:12:10.178 GcodeAsyncDriver$WriterThread TRACE: [serial://ttyUSB0] >> M811 2023-04-03 14:12:10.178 GcodeDriver$ReaderThread TRACE: [serial://ttyUSB0] << ok 2023-04-03 14:12:10.259 MaskHsv TRACE: Fraction actually masked = 0.3008759758759759 2023-04-03 14:12:10.262 MaskHsv TRACE: Fraction actually masked = 0.9999491249491249 2023-04-03 14:12:10.295 ReferenceBottomVision DEBUG: Alignment result: DF40HC70DS-DF40HC3.0-70DS 2023-04-03 14:12:10.296 AbstractHeadMountable DEBUG: N2.moveTo((167.039407, 26.836026, -6.327176, 104.042304 mm), 1.0) 2023-04-03 14:12:10.296 ReferenceNozzle TRACE: N2.toHeadLocation((167.039407, 26.836026, -6.327176, 36.542304 mm), ...) rotation mode offset 67.5 2023-04-03 14:12:10.296 ReferenceNozzle TRACE: N2.toHeadLocation((166.960528, 26.876031, -6.327176, 36.542304 mm), ...) runout compensation (0.078879, -0.040005, 0.000000, 0.000000 mm) 2023-04-03 14:12:10.296 GcodeAsyncDriver DEBUG: serial://ttyUSB0 commandQueue.offer(M119 ; DRAGPIN endstop status, 10000)... 2023-04-03 14:12:10.296 GcodeAsyncDriver$WriterThread TRACE: [serial://ttyUSB0] >> M119 2023-04-03 14:12:10.297 GcodeDriver$ReaderThread TRACE: [serial://ttyUSB0] << X_min:0 Y_min:0 Z_min:0 pins- (X)P4.4:0 (Y)P4.3:0 (Z)P2.13:0 (Z)P4.2:1 2023-04-03 14:12:10.297 GcodeDriver$ReaderThread TRACE: [serial://ttyUSB0] << ok 2023-04-03 14:12:10.297 GcodeDriver TRACE: actuatorRead response: X_min:0 Y_min:0 Z_min:0 pins- (X)P4.4:0 (Y)P4.3:0 (Z)P2.13:0 (Z)P4.2:1 2023-04-03 14:12:10.297 ReferenceActuator DEBUG: DRAGPIN.read(): 1 2023-04-03 14:12:10.298 GcodeAsyncDriver DEBUG: serial://ttyUSB0 commandQueue.offer(M204 S91.85 G1 X110.0109 F2132.43 ; move to target, 10000)... 2023-04-03 14:12:10.298 GcodeAsyncDriver$WriterThread TRACE: [serial://ttyUSB0] >> M204S91.85G1X110.0109F2132.43 2023-04-03 14:12:10.299 GcodeAsyncDriver DEBUG: serial://ttyUSB0 commandQueue.offer(M204 S15.75 G1 X109.9484 F600.00 ; move to target, 10000)... 2023-04-03 14:12:10.299 GcodeDriver$ReaderThread TRACE: [serial://ttyUSB0] << ok 2023-04-03 14:12:10.299 GcodeAsyncDriver$WriterThread TRACE: [serial://ttyUSB0] >> M204S15.75G1X109.9484F600 2023-04-03 14:12:10.299 GcodeDriver$ReaderThread TRACE: [serial://ttyUSB0] << ok 2023-04-03 14:12:10.299 GcodeAsyncDriver DEBUG: serial://ttyUSB0 commandQueue.offer(M400 ; Wait for moves to complete before returning, 10000)... 2023-04-03 14:12:10.299 GcodeAsyncDriver DEBUG: serial://ttyUSB0 commandQueue.offer(M114 ; get position, -1)... 2023-04-03 14:12:10.299 GcodeAsyncDriver$WriterThread TRACE: [serial://ttyUSB0] >> M400 2023-04-03 14:12:10.299 GcodeAsyncDriver$WriterThread TRACE: [serial://ttyUSB0] >> M114 2023-04-03 14:12:11.178 GcodeDriver$ReaderThread TRACE: [serial://ttyUSB0] << ok 2023-04-03 14:12:11.178 GcodeDriver$ReaderThread TRACE: [serial://ttyUSB0] << ok C: X:109.9484 Y:45.1387 Z:19.2959 A:-111.3761 B:36.5423 C:0.0000 D:0.0000 2023-04-03 14:12:11.178 GcodeDriver TRACE: Position report: ok C: X:109.9484 Y:45.1387 Z:19.2959 A:-111.3761 B:36.5423 C:0.0000 D:0.0000 2023-04-03 14:12:11.179 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:109.948400, Y:45.138700, ZN:19.295900, C1:-111.376100, C2:36.542300) 2023-04-03 14:12:11.179 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete. 2023-04-03 14:12:11.179 ReferenceActuator DEBUG: UPLED.actuate(true) 2023-04-03 14:12:11.179 GcodeAsyncDriver DEBUG: serial://ttyUSB0 commandQueue.offer(M810 ; UPLED M810 on / M811 off, 10000)... 2023-04-03 14:12:11.179 GcodeAsyncDriver$WriterThread TRACE: [serial://ttyUSB0] >> M810 2023-04-03 14:12:11.179 GcodeDriver$ReaderThread TRACE: [serial://ttyUSB0] << ok 2023-04-03 14:12:11.229 Scripting TRACE: Scripting.on Camera.BeforeSettle 2023-04-03 14:12:11.229 Scripting TRACE: Scripting.on Camera.BeforeCapture 2023-04-03 14:12:11.245 Scripting TRACE: Scripting.on Camera.AfterCapture 2023-04-03 14:12:11.246 Scripting TRACE: Scripting.on Camera.BeforeCapture 2023-04-03 14:12:11.265 Scripting TRACE: Scripting.on Camera.AfterCapture 2023-04-03 14:12:11.268 AbstractSettlingCamera TRACE: autoSettleAndCapture t=38 auto settle score: 0.175 compute time: 2 2023-04-03 14:12:11.268 Scripting TRACE: Scripting.on Camera.BeforeCapture 2023-04-03 14:12:11.285 Scripting TRACE: Scripting.on Camera.AfterCapture 2023-04-03 14:12:11.288 AbstractSettlingCamera TRACE: autoSettleAndCapture t=58 auto settle score: 0.170 compute time: 2 2023-04-03 14:12:11.288 Scripting TRACE: Scripting.on Camera.BeforeCapture 2023-04-03 14:12:11.309 Scripting TRACE: Scripting.on Camera.AfterCapture 2023-04-03 14:12:11.312 AbstractSettlingCamera TRACE: autoSettleAndCapture t=82 auto settle score: 0.169 compute time: 2 2023-04-03 14:12:11.312 AbstractSettlingCamera DEBUG: autoSettleAndCapture in 82 ms 2023-04-03 14:12:11.312 Scripting TRACE: Scripting.on Camera.AfterSettle 2023-04-03 14:12:11.312 ReferenceActuator DEBUG: UPLED.actuate(false) 2023-04-03 14:12:11.312 GcodeAsyncDriver DEBUG: serial://ttyUSB0 commandQueue.offer(M811 ; UPLED M810 on / M811 off, 10000)... 2023-04-03 14:12:11.312 GcodeAsyncDriver$WriterThread TRACE: [serial://ttyUSB0] >> M811 2023-04-03 14:12:11.312 GcodeDriver$ReaderThread TRACE: [serial://ttyUSB0] << ok 2023-04-03 14:12:11.395 MaskHsv TRACE: Fraction actually masked = 0.21752044252044256 2023-04-03 14:12:11.397 MaskHsv TRACE: Fraction actually masked = 0.9857993857993858 2023-04-03 14:12:11.436 ReferenceBottomVision DEBUG: Alignment result: DF40HC70DS-DF40HC3.0-70DS 2023-04-03 14:12:11.437 ReferenceBottomVision DEBUG: Bottom vision part DF40HC70DS-DF40HC3.0-70DS result rect { {326.7921862043182, 589.4876224654} 318x1183 * -103.18255929707085 } 2023-04-03 14:12:11.437 ReferenceBottomVision DEBUG: Offsets too large (-3.601488, -0.171049, 0.000000, 13.182559 mm) : center offset 3.60554731300386 > 1.0 2023-04-03 14:12:11.438 AbstractHeadMountable DEBUG: N2.moveTo((170.640895, 27.007075, -6.327176, 90.859745 mm), 1.0) 2023-04-03 14:12:11.438 ReferenceNozzle TRACE: N2.toHeadLocation((170.640895, 27.007075, -6.327176, 23.359745 mm), ...) rotation mode offset 67.5 2023-04-03 14:12:11.438 ReferenceNozzle TRACE: N2.toHeadLocation((170.573218, 27.064014, -6.327176, 23.359745 mm), ...) runout compensation (0.067677, -0.056939, 0.000000, 0.000000 mm) 2023-04-03 14:12:11.438 GcodeAsyncDriver DEBUG: serial://ttyUSB0 commandQueue.offer(M119 ; DRAGPIN endstop status, 10000)... 2023-04-03 14:12:11.438 GcodeAsyncDriver$WriterThread TRACE: [serial://ttyUSB0] >> M119 2023-04-03 14:12:11.438 GcodeDriver$ReaderThread TRACE: [serial://ttyUSB0] << X_min:0 Y_min:0 Z_min:0 pins- (X)P4.4:0 (Y)P4.3:0 (Z)P2.13:0 (Z)P4.2:1 2023-04-03 14:12:11.438 GcodeDriver$ReaderThread TRACE: [serial://ttyUSB0] << ok 2023-04-03 14:12:11.438 GcodeDriver TRACE: actuatorRead response: X_min:0 Y_min:0 Z_min:0 pins- (X)P4.4:0 (Y)P4.3:0 (Z)P2.13:0 (Z)P4.2:1 2023-04-03 14:12:11.439 ReferenceActuator DEBUG: DRAGPIN.read(): 1 2023-04-03 14:12:11.441 GcodeAsyncDriver DEBUG: serial://ttyUSB0 commandQueue.offer(M204 S232.26 G1 X113.5130 Y45.2889 B23.3597 F3379.17 ; move to target, 10000)... 2023-04-03 14:12:11.441 GcodeAsyncDriver$WriterThread TRACE: [serial://ttyUSB0] >> M204S232.26G1X113.513Y45.2889B23.3597F3379.17 2023-04-03 14:12:11.441 GcodeDriver$ReaderThread TRACE: [serial://ttyUSB0] << ok 2023-04-03 14:12:11.441 GcodeAsyncDriver DEBUG: serial://ttyUSB0 commandQueue.offer(M204 S15.49 G1 X113.5755 Y45.3645 F600.00 ; move to target, 10000)... 2023-04-03 14:12:11.442 GcodeAsyncDriver$WriterThread TRACE: [serial://ttyUSB0] >> M204S15.49G1X113.5755Y45.3645F600 2023-04-03 14:12:11.442 GcodeDriver$ReaderThread TRACE: [serial://ttyUSB0] << ok 2023-04-03 14:12:11.443 GcodeAsyncDriver DEBUG: serial://ttyUSB0 commandQueue.offer(M400 ; Wait for moves to complete before returning, 10000)... 2023-04-03 14:12:11.443 GcodeAsyncDriver DEBUG: serial://ttyUSB0 commandQueue.offer(M114 ; get position, -1)... 2023-04-03 14:12:11.443 GcodeAsyncDriver$WriterThread TRACE: [serial://ttyUSB0] >> M400 2023-04-03 14:12:11.444 GcodeAsyncDriver$WriterThread TRACE: [serial://ttyUSB0] >> M114 2023-04-03 14:12:12.080 GcodeDriver$ReaderThread TRACE: [serial://ttyUSB0] << ok 2023-04-03 14:12:12.080 GcodeDriver$ReaderThread TRACE: [serial://ttyUSB0] << ok C: X:113.5755 Y:45.3645 Z:19.2959 A:-111.3761 B:23.3597 C:0.0000 D:0.0000 2023-04-03 14:12:12.081 GcodeDriver TRACE: Position report: ok C: X:113.5755 Y:45.3645 Z:19.2959 A:-111.3761 B:23.3597 C:0.0000 D:0.0000 2023-04-03 14:12:12.081 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:113.575500, Y:45.364500, ZN:19.295900, C1:-111.376100, C2:23.359700) 2023-04-03 14:12:12.081 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete. 2023-04-03 14:12:12.081 ReferenceActuator DEBUG: UPLED.actuate(true) 2023-04-03 14:12:12.081 GcodeAsyncDriver DEBUG: serial://ttyUSB0 commandQueue.offer(M810 ; UPLED M810 on / M811 off, 10000)... 2023-04-03 14:12:12.081 GcodeAsyncDriver$WriterThread TRACE: [serial://ttyUSB0] >> M810 2023-04-03 14:12:12.081 GcodeDriver$ReaderThread TRACE: [serial://ttyUSB0] << ok 2023-04-03 14:12:12.131 Scripting TRACE: Scripting.on Camera.BeforeSettle 2023-04-03 14:12:12.131 Scripting TRACE: Scripting.on Camera.BeforeCapture 2023-04-03 14:12:12.140 Scripting TRACE: Scripting.on Camera.AfterCapture 2023-04-03 14:12:12.142 Scripting TRACE: Scripting.on Camera.BeforeCapture 2023-04-03 14:12:12.161 Scripting TRACE: Scripting.on Camera.AfterCapture 2023-04-03 14:12:12.163 AbstractSettlingCamera TRACE: autoSettleAndCapture t=32 auto settle score: 0.244 compute time: 3 2023-04-03 14:12:12.163 Scripting TRACE: Scripting.on Camera.BeforeCapture 2023-04-03 14:12:12.199 Scripting TRACE: Scripting.on Camera.AfterCapture 2023-04-03 14:12:12.202 AbstractSettlingCamera TRACE: autoSettleAndCapture t=70 auto settle score: 0.171 compute time: 2 2023-04-03 14:12:12.202 Scripting TRACE: Scripting.on Camera.BeforeCapture 2023-04-03 14:12:12.228 Scripting TRACE: Scripting.on Camera.AfterCapture 2023-04-03 14:12:12.231 AbstractSettlingCamera TRACE: autoSettleAndCapture t=99 auto settle score: 0.181 compute time: 2 2023-04-03 14:12:12.231 AbstractSettlingCamera DEBUG: autoSettleAndCapture in 99 ms 2023-04-03 14:12:12.231 Scripting TRACE: Scripting.on Camera.AfterSettle 2023-04-03 14:12:12.231 ReferenceActuator DEBUG: UPLED.actuate(false) 2023-04-03 14:12:12.231 GcodeAsyncDriver DEBUG: serial://ttyUSB0 commandQueue.offer(M811 ; UPLED M810 on / M811 off, 10000)... 2023-04-03 14:12:12.231 GcodeAsyncDriver$WriterThread TRACE: [serial://ttyUSB0] >> M811 2023-04-03 14:12:12.231 GcodeDriver$ReaderThread TRACE: [serial://ttyUSB0] << ok 2023-04-03 14:12:12.312 MaskHsv TRACE: Fraction actually masked = 0.24427424427424427 2023-04-03 14:12:12.313 MaskHsv TRACE: Fraction actually masked = 0.9877465127465127 2023-04-03 14:12:12.353 ReferenceBottomVision DEBUG: Alignment result: DF40HC70DS-DF40HC3.0-70DS 2023-04-03 14:12:12.354 AbstractHeadMountable DEBUG: N2.moveTo((184.440895, 27.007075, -6.327176, 90.859745 mm), 1.0) 2023-04-03 14:12:12.354 ReferenceNozzle TRACE: N2.toHeadLocation((184.440895, 27.007075, -6.327176, 23.359745 mm), ...) rotation mode offset 67.5 2023-04-03 14:12:12.354 ReferenceNozzle TRACE: N2.toHeadLocation((184.373218, 27.064014, -6.327176, 23.359745 mm), ...) runout compensation (0.067677, -0.056939, 0.000000, 0.000000 mm) 2023-04-03 14:12:12.354 GcodeAsyncDriver DEBUG: serial://ttyUSB0 commandQueue.offer(M119 ; DRAGPIN endstop status, 10000)... 2023-04-03 14:12:12.354 GcodeAsyncDriver$WriterThread TRACE: [serial://ttyUSB0] >> M119 2023-04-03 14:12:12.354 GcodeDriver$ReaderThread TRACE: [serial://ttyUSB0] << X_min:0 Y_min:0 Z_min:0 pins- (X)P4.4:0 (Y)P4.3:0 (Z)P2.13:0 (Z)P4.2:1 2023-04-03 14:12:12.355 GcodeDriver$ReaderThread TRACE: [serial://ttyUSB0] << ok 2023-04-03 14:12:12.355 GcodeDriver TRACE: actuatorRead response: X_min:0 Y_min:0 Z_min:0 pins- (X)P4.4:0 (Y)P4.3:0 (Z)P2.13:0 (Z)P4.2:1 2023-04-03 14:12:12.355 ReferenceActuator DEBUG: DRAGPIN.read(): 1 2023-04-03 14:12:12.356 GcodeAsyncDriver DEBUG: serial://ttyUSB0 commandQueue.offer(M204 S91.83 G1 X127.3130 F2131.04 ; move to target, 10000)... 2023-04-03 14:12:12.356 GcodeAsyncDriver$WriterThread TRACE: [serial://ttyUSB0] >> M204S91.83G1X127.313F2131.04 2023-04-03 14:12:12.357 GcodeDriver$ReaderThread TRACE: [serial://ttyUSB0] << ok 2023-04-03 14:12:12.357 GcodeAsyncDriver DEBUG: serial://ttyUSB0 commandQueue.offer(M204 S15.75 G1 X127.3755 F600.00 ; move to target, 10000)... 2023-04-03 14:12:12.357 GcodeAsyncDriver$WriterThread TRACE: [serial://ttyUSB0] >> M204S15.75G1X127.3755F600 2023-04-03 14:12:12.357 GcodeDriver$ReaderThread TRACE: [serial://ttyUSB0] << ok 2023-04-03 14:12:12.357 GcodeAsyncDriver DEBUG: serial://ttyUSB0 commandQueue.offer(M400 ; Wait for moves to complete before returning, 10000)... 2023-04-03 14:12:12.357 GcodeAsyncDriver DEBUG: serial://ttyUSB0 commandQueue.offer(M114 ; get position, -1)... 2023-04-03 14:12:12.357 GcodeAsyncDriver$WriterThread TRACE: [serial://ttyUSB0] >> M400 2023-04-03 14:12:12.357 GcodeAsyncDriver$WriterThread TRACE: [serial://ttyUSB0] >> M114 2023-04-03 14:12:13.236 GcodeDriver$ReaderThread TRACE: [serial://ttyUSB0] << ok 2023-04-03 14:12:13.236 GcodeDriver$ReaderThread TRACE: [serial://ttyUSB0] << ok C: X:127.3755 Y:45.3645 Z:19.2959 A:-111.3761 B:23.3597 C:0.0000 D:0.0000 2023-04-03 14:12:13.236 GcodeDriver TRACE: Position report: ok C: X:127.3755 Y:45.3645 Z:19.2959 A:-111.3761 B:23.3597 C:0.0000 D:0.0000 2023-04-03 14:12:13.236 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:127.375500, Y:45.364500, ZN:19.295900, C1:-111.376100, C2:23.359700) 2023-04-03 14:12:13.237 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete. 2023-04-03 14:12:13.237 ReferenceActuator DEBUG: UPLED.actuate(true) 2023-04-03 14:12:13.237 GcodeAsyncDriver DEBUG: serial://ttyUSB0 commandQueue.offer(M810 ; UPLED M810 on / M811 off, 10000)... 2023-04-03 14:12:13.237 GcodeAsyncDriver$WriterThread TRACE: [serial://ttyUSB0] >> M810 2023-04-03 14:12:13.237 GcodeDriver$ReaderThread TRACE: [serial://ttyUSB0] << ok 2023-04-03 14:12:13.287 Scripting TRACE: Scripting.on Camera.BeforeSettle 2023-04-03 14:12:13.287 Scripting TRACE: Scripting.on Camera.BeforeCapture 2023-04-03 14:12:13.304 Scripting TRACE: Scripting.on Camera.AfterCapture 2023-04-03 14:12:13.305 Scripting TRACE: Scripting.on Camera.BeforeCapture 2023-04-03 14:12:13.326 Scripting TRACE: Scripting.on Camera.AfterCapture 2023-04-03 14:12:13.328 AbstractSettlingCamera TRACE: autoSettleAndCapture t=41 auto settle score: 0.168 compute time: 2 2023-04-03 14:12:13.328 Scripting TRACE: Scripting.on Camera.BeforeCapture 2023-04-03 14:12:13.344 Scripting TRACE: Scripting.on Camera.AfterCapture 2023-04-03 14:12:13.347 AbstractSettlingCamera TRACE: autoSettleAndCapture t=59 auto settle score: 0.168 compute time: 2 2023-04-03 14:12:13.347 Scripting TRACE: Scripting.on Camera.BeforeCapture 2023-04-03 14:12:13.368 Scripting TRACE: Scripting.on Camera.AfterCapture 2023-04-03 14:12:13.371 AbstractSettlingCamera TRACE: autoSettleAndCapture t=83 auto settle score: 0.168 compute time: 2 2023-04-03 14:12:13.371 AbstractSettlingCamera DEBUG: autoSettleAndCapture in 83 ms 2023-04-03 14:12:13.371 Scripting TRACE: Scripting.on Camera.AfterSettle 2023-04-03 14:12:13.371 ReferenceActuator DEBUG: UPLED.actuate(false) 2023-04-03 14:12:13.371 GcodeAsyncDriver DEBUG: serial://ttyUSB0 commandQueue.offer(M811 ; UPLED M810 on / M811 off, 10000)... 2023-04-03 14:12:13.371 GcodeAsyncDriver$WriterThread TRACE: [serial://ttyUSB0] >> M811 2023-04-03 14:12:13.371 GcodeDriver$ReaderThread TRACE: [serial://ttyUSB0] << ok 2023-04-03 14:12:13.449 MaskHsv TRACE: Fraction actually masked = 0.27862507862507857 2023-04-03 14:12:13.452 MaskHsv TRACE: Fraction actually masked = 1.0 2023-04-03 14:12:13.484 Scripting TRACE: Scripting.on Vision.PartAlignment.After 2023-04-03 14:12:13.484 AbstractMachine TRACE: Exception caught, executing pending motion: java.lang.Exception: ReferenceBottomVision (DF40HC70DS-DF40HC3.0-70DS): No result found. at org.openpnp.machine.reference.vision.ReferenceBottomVision.processPipelineAndGetResult(ReferenceBottomVision.java:570) at org.openpnp.machine.reference.vision.ReferenceBottomVision.findOffsetsPreRotate(ReferenceBottomVision.java:212) at org.openpnp.machine.reference.vision.ReferenceBottomVision.findOffsets(ReferenceBottomVision.java:126) at org.openpnp.util.VisionUtils.findPartAlignmentOffsets(VisionUtils.java:275) at org.openpnp.machine.reference.vision.wizards.BottomVisionSettingsConfigurationWizard.alignAndCenter(BottomVisionSettingsConfigurationWizard.java:572) at org.openpnp.machine.reference.vision.wizards.BottomVisionSettingsConfigurationWizard.testAlignment(BottomVisionSettingsConfigurationWizard.java:564) at org.openpnp.machine.reference.vision.wizards.BottomVisionSettingsConfigurationWizard.lambda$null$7(BottomVisionSettingsConfigurationWizard.java:352) at org.openpnp.util.UiUtils.lambda$submitUiMachineTask$0(UiUtils.java:39) at org.openpnp.spi.base.AbstractMachine$1.call(AbstractMachine.java:578) at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264) at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) at java.base/java.lang.Thread.run(Thread.java:829) 2023-04-03 14:12:13.484 AbstractMachine TRACE: Machine entering idle state. 2023-04-03 14:12:13.484 ReferenceActuator DEBUG: UPLED.actuate(true) 2023-04-03 14:12:13.484 MessageBoxes DEBUG: Error: java.lang.Exception: ReferenceBottomVision (DF40HC70DS-DF40HC3.0-70DS): No result found. 2023-04-03 14:12:13.484 GcodeAsyncDriver DEBUG: serial://ttyUSB0 commandQueue.offer(M810 ; UPLED M810 on / M811 off, 10000)... 2023-04-03 14:12:13.484 GcodeAsyncDriver$WriterThread TRACE: [serial://ttyUSB0] >> M810 2023-04-03 14:12:13.485 GcodeDriver$ReaderThread TRACE: [serial://ttyUSB0] << ok