2023-03-17 15:39:32.850 ReferenceHead DEBUG: H1.moveToSafeZ(0.64)
2023-03-17 15:39:32.851 AbstractHeadMountable DEBUG: N1.moveToSafeZ(0.64)
2023-03-17 15:39:32.857 AbstractHeadMountable DEBUG: N2.moveToSafeZ(0.64)
2023-03-17 15:39:32.858 AbstractHeadMountable DEBUG: Top Camera.moveToSafeZ(0.64)
2023-03-17 15:39:32.858 AbstractHeadMountable DEBUG: BLOW.moveToSafeZ(0.64)
2023-03-17 15:39:32.859 Scripting TRACE: Scripting.on Job.Starting
2023-03-17 15:39:32.860 Scripting TRACE: Scripting.on found Job.Starting.js
2023-03-17 15:39:32.861 Scripting TRACE: jdk.nashorn.api.scripting.NashornScriptEngine@784666c6 scripting engine borrowed from pool in 0.036624 milliseconds
2023-03-17 15:39:32.869 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(M400 ; Wait for moves to complete before returning, 15625)...
2023-03-17 15:39:32.869 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(M114 ; get position, -1)...
2023-03-17 15:39:32.869 GcodeDriver TRACE: [serial://COM9] confirmed M204S198G1X411.78Y420.781F178
2023-03-17 15:39:32.869 GcodeAsyncDriver$WriterThread TRACE: [serial://COM9] >> M400
2023-03-17 15:39:32.876 GcodeDriver$ReaderThread TRACE: [serial://COM9] << ok
2023-03-17 15:39:32.876 GcodeDriver TRACE: [serial://COM9] confirmed M400
2023-03-17 15:39:32.876 GcodeAsyncDriver$WriterThread TRACE: [serial://COM9] >> M114
2023-03-17 15:39:32.898 GcodeDriver$ReaderThread TRACE: [serial://COM9] << ok C: X:411.7800 Y:420.7810 Z:0.0000 A:6.0000 B:180.0000 C:6.0000 E:0.0000
2023-03-17 15:39:32.898 GcodeDriver TRACE: Position report: ok C: X:411.7800 Y:420.7810 Z:0.0000 A:6.0000 B:180.0000 C:6.0000 E:0.0000
2023-03-17 15:39:32.898 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:411.780000, Y:420.781000, Z:0.000000, N1:6.000000, N2:180.000000)
2023-03-17 15:39:32.899 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete.
2023-03-17 15:39:32.899 ReferenceActuator DEBUG: UPLED.actuate(true)
2023-03-17 15:39:32.899 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(M810 ; UPLED M810 on / M811 off, 10000)...
2023-03-17 15:39:32.899 GcodeDriver TRACE: [serial://COM9] confirmed M114
2023-03-17 15:39:32.900 GcodeAsyncDriver$WriterThread TRACE: [serial://COM9] >> M810
2023-03-17 15:39:32.914 GcodeDriver$ReaderThread TRACE: [serial://COM9] << ok
2023-03-17 15:39:32.950 ReferenceActuator DEBUG: VAC.actuate(true)
2023-03-17 15:39:32.950 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(; VAC M808 on / M809 off, 10000)...
2023-03-17 15:39:32.950 GcodeAsyncDriver DEBUG: serial://COM9 empty command after pre process
2023-03-17 15:39:32.950 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(M808 ; turn on vacuum pump, 10000)...
2023-03-17 15:39:32.950 GcodeDriver TRACE: [serial://COM9] confirmed M810
2023-03-17 15:39:32.951 GcodeAsyncDriver$WriterThread TRACE: [serial://COM9] >> M808
2023-03-17 15:39:32.962 GcodeDriver$ReaderThread TRACE: [serial://COM9] << ok
2023-03-17 15:39:33.002 ReferenceActuator DEBUG: CAMSW.actuate(true)
2023-03-17 15:39:33.002 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(M818 ; CAMSW M818 on / M819 off, 10000)...
2023-03-17 15:39:33.003 GcodeDriver TRACE: [serial://COM9] confirmed M808
2023-03-17 15:39:33.003 GcodeAsyncDriver$WriterThread TRACE: [serial://COM9] >> M818
2023-03-17 15:39:33.010 GcodeDriver$ReaderThread TRACE: [serial://COM9] << ok
2023-03-17 15:39:33.054 Scripting TRACE: Script Job.Starting.js executed in 185.630304 milliseconds
2023-03-17 15:39:33.055 ReferencePnpJobProcessor$Plan DEBUG: Planner complete in 0ms: [N1 (503-1) -> C2]
2023-03-17 15:39:33.055 ReferencePnpJobProcessor$Plan DEBUG: Planned placements [N1 (503-1) -> C2]
2023-03-17 15:39:33.055 ReferencePnpJobProcessor$ChangeNozzleTips DEBUG: No nozzle tip change needed for nozzle N1 N1
2023-03-17 15:39:33.055 Scripting TRACE: Scripting.on Job.Placement.Starting
2023-03-17 15:39:33.057 ReferenceDragFeeder DEBUG: feed(N1 N1)
2023-03-17 15:39:33.057 ReferenceHead DEBUG: H1.moveToSafeZ(0.64)
2023-03-17 15:39:33.058 AbstractHeadMountable DEBUG: N1.moveToSafeZ(0.64)
2023-03-17 15:39:33.058 AbstractHeadMountable DEBUG: N2.moveToSafeZ(0.64)
2023-03-17 15:39:33.058 AbstractHeadMountable DEBUG: Top Camera.moveToSafeZ(0.64)
2023-03-17 15:39:33.059 AbstractHeadMountable DEBUG: BLOW.moveToSafeZ(0.64)
2023-03-17 15:39:33.059 AbstractHeadMountable DEBUG: DRAGPIN.moveTo((73.371000, 47.348000, NaN, NaN mm), 0.64)
2023-03-17 15:39:33.060 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(M119 ; DRAGPIN endstop status, 10000)...
2023-03-17 15:39:33.060 GcodeDriver TRACE: [serial://COM9] confirmed M818
2023-03-17 15:39:33.060 GcodeAsyncDriver$WriterThread TRACE: [serial://COM9] >> M119
2023-03-17 15:39:33.081 GcodeDriver$ReaderThread TRACE: [serial://COM9] << 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-03-17 15:39:33.082 GcodeDriver$ReaderThread TRACE: [serial://COM9] << ok
2023-03-17 15:39:33.082 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-03-17 15:39:33.082 ReferenceActuator DEBUG: DRAGPIN.read(): 1
2023-03-17 15:39:33.082 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(M400 ; Wait for moves to complete before returning, 15625)...
2023-03-17 15:39:33.082 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(M114 ; get position, -1)...
2023-03-17 15:39:33.082 GcodeDriver TRACE: [serial://COM9] confirmed M119
2023-03-17 15:39:33.083 GcodeAsyncDriver$WriterThread TRACE: [serial://COM9] >> M400
2023-03-17 15:39:33.097 GcodeDriver$ReaderThread TRACE: [serial://COM9] << ok
2023-03-17 15:39:33.097 GcodeDriver TRACE: [serial://COM9] confirmed M400
2023-03-17 15:39:33.098 GcodeAsyncDriver$WriterThread TRACE: [serial://COM9] >> M114
2023-03-17 15:39:33.119 GcodeDriver$ReaderThread TRACE: [serial://COM9] << ok C: X:411.7800 Y:420.7810 Z:0.0000 A:6.0000 B:180.0000 C:6.0000 E:0.0000
2023-03-17 15:39:33.120 GcodeDriver TRACE: Position report: ok C: X:411.7800 Y:420.7810 Z:0.0000 A:6.0000 B:180.0000 C:6.0000 E:0.0000
2023-03-17 15:39:33.120 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:411.780000, Y:420.781000, Z:0.000000, N1:6.000000, N2:180.000000)
2023-03-17 15:39:33.120 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete.
2023-03-17 15:39:33.133 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(M204 S3419 G1 X24.03 Y19.911    F58560 ; move to target, 10000)...
2023-03-17 15:39:33.133 GcodeDriver TRACE: [serial://COM9] confirmed M114
2023-03-17 15:39:33.134 GcodeAsyncDriver$WriterThread TRACE: [serial://COM9] >> M204S3419G1X24.03Y19.911F58560
2023-03-17 15:39:33.134 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(M204 S198 G1 X23.97 Y19.848    F178 ; move to target, 10000)...
2023-03-17 15:39:33.134 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(M400 ; Wait for moves to complete before returning, 15625)...
2023-03-17 15:39:33.134 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(M114 ; get position, -1)...
2023-03-17 15:39:33.151 GcodeDriver$ReaderThread TRACE: [serial://COM9] << ok
2023-03-17 15:39:33.151 GcodeDriver TRACE: [serial://COM9] confirmed M204S3419G1X24.03Y19.911F58560
2023-03-17 15:39:33.151 GcodeAsyncDriver$WriterThread TRACE: [serial://COM9] >> M204S198G1X23.97Y19.848F178
2023-03-17 15:39:33.167 GcodeDriver$ReaderThread TRACE: [serial://COM9] << ok
2023-03-17 15:39:33.167 GcodeDriver TRACE: [serial://COM9] confirmed M204S198G1X23.97Y19.848F178
2023-03-17 15:39:33.168 GcodeAsyncDriver$WriterThread TRACE: [serial://COM9] >> M400
2023-03-17 15:39:34.095 GcodeDriver$ReaderThread TRACE: [serial://COM9] << ok
2023-03-17 15:39:34.095 GcodeDriver TRACE: [serial://COM9] confirmed M400
2023-03-17 15:39:34.095 GcodeAsyncDriver$WriterThread TRACE: [serial://COM9] >> M114
2023-03-17 15:39:34.118 GcodeDriver$ReaderThread TRACE: [serial://COM9] << ok C: X:23.9700 Y:19.8480 Z:0.0000 A:6.0000 B:180.0000 C:6.0000 E:0.0000
2023-03-17 15:39:34.118 GcodeDriver TRACE: Position report: ok C: X:23.9700 Y:19.8480 Z:0.0000 A:6.0000 B:180.0000 C:6.0000 E:0.0000
2023-03-17 15:39:34.118 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:23.970000, Y:19.848000, Z:0.000000, N1:6.000000, N2:180.000000)
2023-03-17 15:39:34.118 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete.
2023-03-17 15:39:34.119 ReferenceActuator DEBUG: DRAGPIN.actuate(true)
2023-03-17 15:39:34.119 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(M816 ; DRAGPIN M816 down / M817 release, 10000)...
2023-03-17 15:39:34.119 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(;G4P50 ; 50ms delay to deploy/retract, 10000)...
2023-03-17 15:39:34.119 GcodeDriver TRACE: [serial://COM9] confirmed M114
2023-03-17 15:39:34.119 GcodeAsyncDriver DEBUG: serial://COM9 empty command after pre process
2023-03-17 15:39:34.119 GcodeAsyncDriver$WriterThread TRACE: [serial://COM9] >> M816
2023-03-17 15:39:34.133 GcodeDriver$ReaderThread TRACE: [serial://COM9] << ok
2023-03-17 15:39:34.170 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(M400 ; Wait for moves to complete before returning, 15625)...
2023-03-17 15:39:34.170 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(M114 ; get position, -1)...
2023-03-17 15:39:34.170 GcodeDriver TRACE: [serial://COM9] confirmed M816
2023-03-17 15:39:34.171 GcodeAsyncDriver$WriterThread TRACE: [serial://COM9] >> M400
2023-03-17 15:39:34.181 GcodeDriver$ReaderThread TRACE: [serial://COM9] << ok
2023-03-17 15:39:34.182 GcodeDriver TRACE: [serial://COM9] confirmed M400
2023-03-17 15:39:34.182 GcodeAsyncDriver$WriterThread TRACE: [serial://COM9] >> M114
2023-03-17 15:39:34.205 GcodeDriver$ReaderThread TRACE: [serial://COM9] << ok C: X:23.9700 Y:19.8480 Z:0.0000 A:6.0000 B:180.0000 C:6.0000 E:0.0000
2023-03-17 15:39:34.205 GcodeDriver TRACE: Position report: ok C: X:23.9700 Y:19.8480 Z:0.0000 A:6.0000 B:180.0000 C:6.0000 E:0.0000
2023-03-17 15:39:34.205 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:23.970000, Y:19.848000, Z:0.000000, N1:6.000000, N2:180.000000)
2023-03-17 15:39:34.205 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete.
2023-03-17 15:39:34.206 AbstractHeadMountable DEBUG: DRAGPIN.moveTo((73.371000, 47.348000, 1.000000, 0.000000 mm), 0.64)
2023-03-17 15:39:34.207 AbstractHeadMountable DEBUG: DRAGPIN.moveTo((77.571000, 47.348000, 1.000000, 0.000000 mm), 0.64)
2023-03-17 15:39:34.207 ActuatorInterlockMonitor TRACE: DRAGPIN interlock masked by conditionalActuator DRAGPIN being true handled as ON
2023-03-17 15:39:34.213 ActuatorInterlockMonitor TRACE: DRAGPIN interlock masked by conditionalActuator DRAGPIN being true handled as ON
2023-03-17 15:39:34.213 ReferenceActuator DEBUG: PEELER.actuate(true)
2023-03-17 15:39:34.214 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(;T2G92C0G0C6, 10000)...
2023-03-17 15:39:34.214 GcodeAsyncDriver DEBUG: serial://COM9 empty command after pre process
2023-03-17 15:39:34.214 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(G92 C0 G0 C6 ; Set absolute position to 0, Move 6mm, 10000)...
2023-03-17 15:39:34.214 GcodeDriver TRACE: [serial://COM9] confirmed M114
2023-03-17 15:39:34.214 GcodeAsyncDriver$WriterThread TRACE: [serial://COM9] >> G92C0G0C6
2023-03-17 15:39:34.220 GcodeDriver$ReaderThread TRACE: [serial://COM9] << ok
2023-03-17 15:39:34.265 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(M204 S4096 G1 X28.12     F5529 ; move to target, 10000)...
2023-03-17 15:39:34.266 GcodeDriver TRACE: [serial://COM9] confirmed G92C0G0C6
2023-03-17 15:39:34.266 GcodeAsyncDriver$WriterThread TRACE: [serial://COM9] >> M204S4096G1X28.12F5529
2023-03-17 15:39:34.266 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(M204 S197 G1 X28.18     F149 ; move to target, 10000)...
2023-03-17 15:39:34.266 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(M400 ; Wait for moves to complete before returning, 15625)...
2023-03-17 15:39:34.266 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(M114 ; get position, -1)...
2023-03-17 15:39:34.284 GcodeDriver$ReaderThread TRACE: [serial://COM9] << ok
2023-03-17 15:39:34.285 GcodeDriver TRACE: [serial://COM9] confirmed M204S4096G1X28.12F5529
2023-03-17 15:39:34.285 GcodeAsyncDriver$WriterThread TRACE: [serial://COM9] >> M204S197G1X28.18F149
2023-03-17 15:39:34.300 GcodeDriver$ReaderThread TRACE: [serial://COM9] << ok
2023-03-17 15:39:34.300 GcodeDriver TRACE: [serial://COM9] confirmed M204S197G1X28.18F149
2023-03-17 15:39:34.301 GcodeAsyncDriver$WriterThread TRACE: [serial://COM9] >> M400
2023-03-17 15:39:34.764 GcodeDriver$ReaderThread TRACE: [serial://COM9] << ok
2023-03-17 15:39:34.764 GcodeDriver TRACE: [serial://COM9] confirmed M400
2023-03-17 15:39:34.764 GcodeAsyncDriver$WriterThread TRACE: [serial://COM9] >> M114
2023-03-17 15:39:34.787 GcodeDriver$ReaderThread TRACE: [serial://COM9] << ok C: X:28.1800 Y:19.8480 Z:0.0000 A:6.0000 B:180.0000 C:6.0000 E:0.0000
2023-03-17 15:39:34.787 GcodeDriver TRACE: Position report: ok C: X:28.1800 Y:19.8480 Z:0.0000 A:6.0000 B:180.0000 C:6.0000 E:0.0000
2023-03-17 15:39:34.787 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:28.180000, Y:19.848000, Z:0.000000, N1:6.000000, N2:180.000000)
2023-03-17 15:39:34.787 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete.
2023-03-17 15:39:34.788 ReferenceActuator DEBUG: PEELER.actuate(false)
2023-03-17 15:39:34.788 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(;T2G92C0G0C6, 10000)...
2023-03-17 15:39:34.788 GcodeAsyncDriver DEBUG: serial://COM9 empty command after pre process
2023-03-17 15:39:34.788 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(G92 C0 G0 C6 ; Set absolute position to 0, Move 6mm, 10000)...
2023-03-17 15:39:34.788 GcodeDriver TRACE: [serial://COM9] confirmed M114
2023-03-17 15:39:34.789 GcodeAsyncDriver$WriterThread TRACE: [serial://COM9] >> G92C0G0C6
2023-03-17 15:39:34.803 GcodeDriver$ReaderThread TRACE: [serial://COM9] << ok
2023-03-17 15:39:34.838 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(M400 ; Wait for moves to complete before returning, 15625)...
2023-03-17 15:39:34.838 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(M114 ; get position, -1)...
2023-03-17 15:39:34.838 GcodeDriver TRACE: [serial://COM9] confirmed G92C0G0C6
2023-03-17 15:39:34.838 GcodeAsyncDriver$WriterThread TRACE: [serial://COM9] >> M400
2023-03-17 15:39:35.203 GcodeDriver$ReaderThread TRACE: [serial://COM9] << ok
2023-03-17 15:39:35.203 GcodeDriver TRACE: [serial://COM9] confirmed M400
2023-03-17 15:39:35.203 GcodeAsyncDriver$WriterThread TRACE: [serial://COM9] >> M114
2023-03-17 15:39:35.226 GcodeDriver$ReaderThread TRACE: [serial://COM9] << ok C: X:28.1800 Y:19.8480 Z:0.0000 A:6.0000 B:180.0000 C:6.0000 E:0.0000
2023-03-17 15:39:35.226 GcodeDriver TRACE: Position report: ok C: X:28.1800 Y:19.8480 Z:0.0000 A:6.0000 B:180.0000 C:6.0000 E:0.0000
2023-03-17 15:39:35.227 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:28.180000, Y:19.848000, Z:0.000000, N1:6.000000, N2:180.000000)
2023-03-17 15:39:35.227 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete.
2023-03-17 15:39:35.227 AbstractHeadMountable DEBUG: DRAGPIN.moveTo((77.271000, 47.348000, 1.000000, 0.000000 mm), 0.64)
2023-03-17 15:39:35.228 ActuatorInterlockMonitor TRACE: DRAGPIN interlock masked by conditionalActuator DRAGPIN being true handled as ON
2023-03-17 15:39:35.234 ActuatorInterlockMonitor TRACE: DRAGPIN interlock masked by conditionalActuator DRAGPIN being true handled as ON
2023-03-17 15:39:35.234 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(M204 S2039 G1 X27.93     F952 ; move to target, 10000)...
2023-03-17 15:39:35.234 GcodeDriver TRACE: [serial://COM9] confirmed M114
2023-03-17 15:39:35.235 GcodeAsyncDriver$WriterThread TRACE: [serial://COM9] >> M204S2039G1X27.93F952
2023-03-17 15:39:35.235 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(M204 S197 G1 X27.87     F149 ; move to target, 10000)...
2023-03-17 15:39:35.235 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(M400 ; Wait for moves to complete before returning, 15625)...
2023-03-17 15:39:35.236 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(M114 ; get position, -1)...
2023-03-17 15:39:35.242 GcodeDriver$ReaderThread TRACE: [serial://COM9] << ok
2023-03-17 15:39:35.242 GcodeDriver TRACE: [serial://COM9] confirmed M204S2039G1X27.93F952
2023-03-17 15:39:35.242 GcodeAsyncDriver$WriterThread TRACE: [serial://COM9] >> M204S197G1X27.87F149
2023-03-17 15:39:35.258 GcodeDriver$ReaderThread TRACE: [serial://COM9] << ok
2023-03-17 15:39:35.258 GcodeDriver TRACE: [serial://COM9] confirmed M204S197G1X27.87F149
2023-03-17 15:39:35.258 GcodeAsyncDriver$WriterThread TRACE: [serial://COM9] >> M400
2023-03-17 15:39:35.322 GcodeDriver$ReaderThread TRACE: [serial://COM9] << ok
2023-03-17 15:39:35.322 GcodeDriver TRACE: [serial://COM9] confirmed M400
2023-03-17 15:39:35.322 GcodeAsyncDriver$WriterThread TRACE: [serial://COM9] >> M114
2023-03-17 15:39:35.345 GcodeDriver$ReaderThread TRACE: [serial://COM9] << ok C: X:27.8700 Y:19.8480 Z:0.0000 A:6.0000 B:180.0000 C:6.0000 E:0.0000
2023-03-17 15:39:35.345 GcodeDriver TRACE: Position report: ok C: X:27.8700 Y:19.8480 Z:0.0000 A:6.0000 B:180.0000 C:6.0000 E:0.0000
2023-03-17 15:39:35.346 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:27.870000, Y:19.848000, Z:0.000000, N1:6.000000, N2:180.000000)
2023-03-17 15:39:35.346 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete.
2023-03-17 15:39:35.346 ReferenceActuator DEBUG: DRAGPIN.actuate(false)
2023-03-17 15:39:35.346 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(M817 ; DRAGPIN M816 down / M817 release, 10000)...
2023-03-17 15:39:35.346 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(;G4P50 ; 50ms delay to deploy/retract, 10000)...
2023-03-17 15:39:35.346 GcodeDriver TRACE: [serial://COM9] confirmed M114
2023-03-17 15:39:35.346 GcodeAsyncDriver DEBUG: serial://COM9 empty command after pre process
2023-03-17 15:39:35.347 GcodeAsyncDriver$WriterThread TRACE: [serial://COM9] >> M817
2023-03-17 15:39:35.361 GcodeDriver$ReaderThread TRACE: [serial://COM9] << ok
2023-03-17 15:39:35.396 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(M400 ; Wait for moves to complete before returning, 15625)...
2023-03-17 15:39:35.396 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(M114 ; get position, -1)...
2023-03-17 15:39:35.396 GcodeDriver TRACE: [serial://COM9] confirmed M817
2023-03-17 15:39:35.396 GcodeAsyncDriver$WriterThread TRACE: [serial://COM9] >> M400
2023-03-17 15:39:35.409 GcodeDriver$ReaderThread TRACE: [serial://COM9] << ok
2023-03-17 15:39:35.409 GcodeDriver TRACE: [serial://COM9] confirmed M400
2023-03-17 15:39:35.409 GcodeAsyncDriver$WriterThread TRACE: [serial://COM9] >> M114
2023-03-17 15:39:35.431 GcodeDriver$ReaderThread TRACE: [serial://COM9] << ok C: X:27.8700 Y:19.8480 Z:0.0000 A:6.0000 B:180.0000 C:6.0000 E:0.0000
2023-03-17 15:39:35.431 GcodeDriver TRACE: Position report: ok C: X:27.8700 Y:19.8480 Z:0.0000 A:6.0000 B:180.0000 C:6.0000 E:0.0000
2023-03-17 15:39:35.431 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:27.870000, Y:19.848000, Z:0.000000, N1:6.000000, N2:180.000000)
2023-03-17 15:39:35.432 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete.
2023-03-17 15:39:35.432 ReferenceHead DEBUG: H1.moveToSafeZ(0.64)
2023-03-17 15:39:35.432 AbstractHeadMountable DEBUG: N1.moveToSafeZ(0.64)
2023-03-17 15:39:35.433 AbstractHeadMountable DEBUG: N2.moveToSafeZ(0.64)
2023-03-17 15:39:35.433 AbstractHeadMountable DEBUG: Top Camera.moveToSafeZ(0.64)
2023-03-17 15:39:35.434 AbstractHeadMountable DEBUG: BLOW.moveToSafeZ(0.64)
2023-03-17 15:39:35.434 AbstractNozzle TRACE: Set rotation mode offset: none.
2023-03-17 15:39:35.434 AbstractNozzle TRACE: Set rotation mode offset: none.
2023-03-17 15:39:35.434 ReferenceHead DEBUG: H1.moveToSafeZ(0.64)
2023-03-17 15:39:35.435 AbstractHeadMountable DEBUG: N1.moveToSafeZ(0.64)
2023-03-17 15:39:35.435 AbstractHeadMountable DEBUG: N2.moveToSafeZ(0.64)
2023-03-17 15:39:35.435 AbstractHeadMountable DEBUG: Top Camera.moveToSafeZ(0.64)
2023-03-17 15:39:35.435 AbstractHeadMountable DEBUG: BLOW.moveToSafeZ(0.64)
2023-03-17 15:39:35.436 AbstractHeadMountable DEBUG: N1.moveTo((62.201000, 43.638000, 0.000000, 90.000000 mm), 0.64)
2023-03-17 15:39:35.436 ReferenceNozzle TRACE: N1.toHeadLocation((62.224477, 43.709579, 0.000000, 90.000000 mm), ...) runout compensation (-0.023477, -0.071579, 0.000000, 0.000000 mm)
2023-03-17 15:39:35.436 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(M119 ; DRAGPIN endstop status, 10000)...
2023-03-17 15:39:35.436 GcodeDriver TRACE: [serial://COM9] confirmed M114
2023-03-17 15:39:35.437 GcodeAsyncDriver$WriterThread TRACE: [serial://COM9] >> M119
2023-03-17 15:39:35.459 GcodeDriver$ReaderThread TRACE: [serial://COM9] << 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-03-17 15:39:35.459 GcodeDriver$ReaderThread TRACE: [serial://COM9] << ok
2023-03-17 15:39:35.459 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-03-17 15:39:35.459 ReferenceActuator DEBUG: DRAGPIN.read(): 1
2023-03-17 15:39:35.460 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(M400 ; Wait for moves to complete before returning, 15625)...
2023-03-17 15:39:35.460 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(M114 ; get position, -1)...
2023-03-17 15:39:35.460 GcodeDriver TRACE: [serial://COM9] confirmed M119
2023-03-17 15:39:35.460 GcodeAsyncDriver$WriterThread TRACE: [serial://COM9] >> M400
2023-03-17 15:39:35.475 GcodeDriver$ReaderThread TRACE: [serial://COM9] << ok
2023-03-17 15:39:35.475 GcodeDriver TRACE: [serial://COM9] confirmed M400
2023-03-17 15:39:35.475 GcodeAsyncDriver$WriterThread TRACE: [serial://COM9] >> M114
2023-03-17 15:39:35.497 GcodeDriver$ReaderThread TRACE: [serial://COM9] << ok C: X:27.8700 Y:19.8480 Z:0.0000 A:6.0000 B:180.0000 C:6.0000 E:0.0000
2023-03-17 15:39:35.497 GcodeDriver TRACE: Position report: ok C: X:27.8700 Y:19.8480 Z:0.0000 A:6.0000 B:180.0000 C:6.0000 E:0.0000
2023-03-17 15:39:35.497 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:27.870000, Y:19.848000, Z:0.000000, N1:6.000000, N2:180.000000)
2023-03-17 15:39:35.498 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete.
2023-03-17 15:39:35.512 AbstractHeadMountable DEBUG: N1.moveTo((62.201000, 43.638000, -11.000000, 90.000000 mm), 0.64)
2023-03-17 15:39:35.512 ReferenceNozzle TRACE: N1.toHeadLocation((62.224477, 43.709579, -11.000000, 90.000000 mm), ...) runout compensation (-0.023477, -0.071579, 0.000000, 0.000000 mm)
2023-03-17 15:39:35.513 ReferenceNozzle DEBUG: N1.pick()
2023-03-17 15:39:35.513 Scripting TRACE: Scripting.on Nozzle.BeforePick
2023-03-17 15:39:35.515 ReferenceActuator DEBUG: VAC.actuate(true)
2023-03-17 15:39:35.515 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(; VAC M808 on / M809 off, 10000)...
2023-03-17 15:39:35.515 GcodeAsyncDriver DEBUG: serial://COM9 empty command after pre process
2023-03-17 15:39:35.515 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(M808 ; turn on vacuum pump, 10000)...
2023-03-17 15:39:35.515 GcodeDriver TRACE: [serial://COM9] confirmed M114
2023-03-17 15:39:35.516 GcodeAsyncDriver$WriterThread TRACE: [serial://COM9] >> M808
2023-03-17 15:39:35.528 GcodeDriver$ReaderThread TRACE: [serial://COM9] << ok
2023-03-17 15:39:35.566 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(M204 S2465 G1 X25.16 Y54.146  A90.0  F12356 ; move to target, 10000)...
2023-03-17 15:39:35.566 GcodeDriver TRACE: [serial://COM9] confirmed M808
2023-03-17 15:39:35.566 GcodeAsyncDriver$WriterThread TRACE: [serial://COM9] >> M204S2465G1X25.16Y54.146A90F12356
2023-03-17 15:39:35.567 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(M204 S198 G1 X25.09 Y54.209    F178 ; move to target, 10000)...
2023-03-17 15:39:35.567 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(M204 S40960 G1   Z-38.9   F38400 ; move to target, 10000)...
2023-03-17 15:39:35.567 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(M400 ; Wait for moves to complete before returning, 15625)...
2023-03-17 15:39:35.567 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(M114 ; get position, -1)...
2023-03-17 15:39:35.576 GcodeDriver$ReaderThread TRACE: [serial://COM9] << ok
2023-03-17 15:39:35.577 GcodeDriver TRACE: [serial://COM9] confirmed M204S2465G1X25.16Y54.146A90F12356
2023-03-17 15:39:35.577 GcodeAsyncDriver$WriterThread TRACE: [serial://COM9] >> M204S198G1X25.09Y54.209F178
2023-03-17 15:39:35.592 GcodeDriver$ReaderThread TRACE: [serial://COM9] << ok
2023-03-17 15:39:35.593 GcodeDriver TRACE: [serial://COM9] confirmed M204S198G1X25.09Y54.209F178
2023-03-17 15:39:35.593 GcodeAsyncDriver$WriterThread TRACE: [serial://COM9] >> M204S40960G1Z-38.9F38400
2023-03-17 15:39:35.608 GcodeDriver$ReaderThread TRACE: [serial://COM9] << ok
2023-03-17 15:39:35.609 GcodeDriver TRACE: [serial://COM9] confirmed M204S40960G1Z-38.9F38400
2023-03-17 15:39:35.609 GcodeAsyncDriver$WriterThread TRACE: [serial://COM9] >> M400
2023-03-17 15:39:36.072 GcodeDriver$ReaderThread TRACE: [serial://COM9] << ok
2023-03-17 15:39:36.072 GcodeDriver TRACE: [serial://COM9] confirmed M400
2023-03-17 15:39:36.073 GcodeAsyncDriver$WriterThread TRACE: [serial://COM9] >> M114
2023-03-17 15:39:36.095 GcodeDriver$ReaderThread TRACE: [serial://COM9] << ok C: X:25.0900 Y:54.2090 Z:-38.9000 A:90.0000 B:180.0000 C:6.0000 E:0.0000
2023-03-17 15:39:36.096 GcodeDriver TRACE: Position report: ok C: X:25.0900 Y:54.2090 Z:-38.9000 A:90.0000 B:180.0000 C:6.0000 E:0.0000
2023-03-17 15:39:36.096 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:25.090000, Y:54.209000, Z:-38.900000, N1:90.000000, N2:180.000000)
2023-03-17 15:39:36.096 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete.
2023-03-17 15:39:36.097 ReferenceActuator DEBUG: N1VAC.actuate(true)
2023-03-17 15:39:36.097 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(; H1 N1VAC ACTUATE_BOOLEAN_COMMAND, 10000)...
2023-03-17 15:39:36.097 GcodeAsyncDriver DEBUG: serial://COM9 empty command after pre process
2023-03-17 15:39:36.097 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(M800 ; on, open solenoid valve, RED led ON on soleonid, 10000)...
2023-03-17 15:39:36.098 GcodeDriver TRACE: [serial://COM9] confirmed M114
2023-03-17 15:39:36.098 GcodeAsyncDriver$WriterThread TRACE: [serial://COM9] >> M800
2023-03-17 15:39:36.111 GcodeDriver$ReaderThread TRACE: [serial://COM9] << ok
2023-03-17 15:39:36.147 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(M400 ; Wait for moves to complete before returning, 15625)...
2023-03-17 15:39:36.147 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(M114 ; get position, -1)...
2023-03-17 15:39:36.147 GcodeDriver TRACE: [serial://COM9] confirmed M800
2023-03-17 15:39:36.147 GcodeAsyncDriver$WriterThread TRACE: [serial://COM9] >> M400
2023-03-17 15:39:36.159 GcodeDriver$ReaderThread TRACE: [serial://COM9] << ok
2023-03-17 15:39:36.159 GcodeDriver TRACE: [serial://COM9] confirmed M400
2023-03-17 15:39:36.160 GcodeAsyncDriver$WriterThread TRACE: [serial://COM9] >> M114
2023-03-17 15:39:36.182 GcodeDriver$ReaderThread TRACE: [serial://COM9] << ok C: X:25.0900 Y:54.2090 Z:-38.9000 A:90.0000 B:180.0000 C:6.0000 E:0.0000
2023-03-17 15:39:36.183 GcodeDriver TRACE: Position report: ok C: X:25.0900 Y:54.2090 Z:-38.9000 A:90.0000 B:180.0000 C:6.0000 E:0.0000
2023-03-17 15:39:36.183 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:25.090000, Y:54.209000, Z:-38.900000, N1:90.000000, N2:180.000000)
2023-03-17 15:39:36.183 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete.
2023-03-17 15:39:36.184 Scripting TRACE: Scripting.on Nozzle.AfterPick
2023-03-17 15:39:36.186 AbstractHeadMountable DEBUG: N1.moveToSafeZ(0.64)
2023-03-17 15:39:36.186 AbstractHeadMountable DEBUG: N1.moveTo((62.201000, 43.638000, 0.000000, 90.000000 mm), 0.64)
2023-03-17 15:39:36.186 ReferenceNozzle TRACE: N1.toHeadLocation((62.224477, 43.709579, 0.000000, 90.000000 mm), ...) runout compensation (-0.023477, -0.071579, 0.000000, 0.000000 mm)
2023-03-17 15:39:36.188 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(M204 S40960 G1   Z0.0   F38400 ; move to target, 10000)...
2023-03-17 15:39:36.188 GcodeDriver TRACE: [serial://COM9] confirmed M114
2023-03-17 15:39:36.188 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(M400 ; Wait for moves to complete before returning, 15625)...
2023-03-17 15:39:36.188 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(M114 ; get position, -1)...
2023-03-17 15:39:36.188 GcodeAsyncDriver$WriterThread TRACE: [serial://COM9] >> M204S40960G1Z0F38400
2023-03-17 15:39:36.198 GcodeDriver$ReaderThread TRACE: [serial://COM9] << ok
2023-03-17 15:39:36.198 GcodeDriver TRACE: [serial://COM9] confirmed M204S40960G1Z0F38400
2023-03-17 15:39:36.199 GcodeAsyncDriver$WriterThread TRACE: [serial://COM9] >> M400
2023-03-17 15:39:36.358 GcodeDriver$ReaderThread TRACE: [serial://COM9] << ok
2023-03-17 15:39:36.358 GcodeDriver TRACE: [serial://COM9] confirmed M400
2023-03-17 15:39:36.359 GcodeAsyncDriver$WriterThread TRACE: [serial://COM9] >> M114
2023-03-17 15:39:36.380 GcodeDriver$ReaderThread TRACE: [serial://COM9] << ok C: X:25.0900 Y:54.2090 Z:0.0000 A:90.0000 B:180.0000 C:6.0000 E:0.0000
2023-03-17 15:39:36.381 GcodeDriver TRACE: Position report: ok C: X:25.0900 Y:54.2090 Z:0.0000 A:90.0000 B:180.0000 C:6.0000 E:0.0000
2023-03-17 15:39:36.381 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:25.090000, Y:54.209000, Z:0.000000, N1:90.000000, N2:180.000000)
2023-03-17 15:39:36.381 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete.
2023-03-17 15:39:36.381 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(; H1 N1VAC ACTUATOR_READ_COMMAND, 10000)...
2023-03-17 15:39:36.381 GcodeAsyncDriver DEBUG: serial://COM9 empty command after pre process
2023-03-17 15:39:36.382 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(M105 ; read vacuum, 10000)...
2023-03-17 15:39:36.382 GcodeDriver TRACE: [serial://COM9] confirmed M114
2023-03-17 15:39:36.382 GcodeAsyncDriver$WriterThread TRACE: [serial://COM9] >> M105
2023-03-17 15:39:36.396 GcodeDriver$ReaderThread TRACE: [serial://COM9] << ok V1:209.0 /0.0 @0 V2:126.6 /0.0 @0
2023-03-17 15:39:36.396 GcodeDriver TRACE: actuatorRead response: ok V1:209.0 /0.0 @0 V2:126.6 /0.0 @0
2023-03-17 15:39:36.396 ReferenceActuator DEBUG: N1VSENSE.read(): 209.0
2023-03-17 15:39:36.397 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(M400 ; Wait for moves to complete before returning, 15625)...
2023-03-17 15:39:36.397 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(M114 ; get position, -1)...
2023-03-17 15:39:36.397 GcodeDriver TRACE: [serial://COM9] confirmed M105
2023-03-17 15:39:36.397 GcodeAsyncDriver$WriterThread TRACE: [serial://COM9] >> M400
2023-03-17 15:39:36.412 GcodeDriver$ReaderThread TRACE: [serial://COM9] << ok
2023-03-17 15:39:36.412 GcodeDriver TRACE: [serial://COM9] confirmed M400
2023-03-17 15:39:36.412 GcodeAsyncDriver$WriterThread TRACE: [serial://COM9] >> M114
2023-03-17 15:39:36.435 GcodeDriver$ReaderThread TRACE: [serial://COM9] << ok C: X:25.0900 Y:54.2090 Z:0.0000 A:90.0000 B:180.0000 C:6.0000 E:0.0000
2023-03-17 15:39:36.435 GcodeDriver TRACE: Position report: ok C: X:25.0900 Y:54.2090 Z:0.0000 A:90.0000 B:180.0000 C:6.0000 E:0.0000
2023-03-17 15:39:36.435 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:25.090000, Y:54.209000, Z:0.000000, N1:90.000000, N2:180.000000)
2023-03-17 15:39:36.435 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete.
2023-03-17 15:39:36.436 Scripting TRACE: Scripting.on Vision.PartAlignment.Before
2023-03-17 15:39:36.439 ReferenceHead DEBUG: H1.moveToSafeZ(0.64)
2023-03-17 15:39:36.439 AbstractHeadMountable DEBUG: N1.moveToSafeZ(0.64)
2023-03-17 15:39:36.439 AbstractHeadMountable DEBUG: N2.moveToSafeZ(0.64)
2023-03-17 15:39:36.440 AbstractHeadMountable DEBUG: Top Camera.moveToSafeZ(0.64)
2023-03-17 15:39:36.440 AbstractHeadMountable DEBUG: BLOW.moveToSafeZ(0.64)
2023-03-17 15:39:36.440 AbstractHeadMountable DEBUG: N1.moveTo((169.572449, 35.183987, 0.000000, 0.000000 mm), 0.64)
2023-03-17 15:39:36.440 ReferenceNozzle TRACE: N1.toHeadLocation((169.644029, 35.160510, 0.000000, 0.000000 mm), ...) runout compensation (-0.071579, 0.023477, 0.000000, 0.000000 mm)
2023-03-17 15:39:36.441 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(M119 ; DRAGPIN endstop status, 10000)...
2023-03-17 15:39:36.441 GcodeDriver TRACE: [serial://COM9] confirmed M114
2023-03-17 15:39:36.442 GcodeAsyncDriver$WriterThread TRACE: [serial://COM9] >> M119
2023-03-17 15:39:36.464 GcodeDriver$ReaderThread TRACE: [serial://COM9] << 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-03-17 15:39:36.464 GcodeDriver$ReaderThread TRACE: [serial://COM9] << ok
2023-03-17 15:39:36.465 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-03-17 15:39:36.465 ReferenceActuator DEBUG: DRAGPIN.read(): 1
2023-03-17 15:39:36.465 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(M400 ; Wait for moves to complete before returning, 15625)...
2023-03-17 15:39:36.465 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(M114 ; get position, -1)...
2023-03-17 15:39:36.465 GcodeDriver TRACE: [serial://COM9] confirmed M119
2023-03-17 15:39:36.465 GcodeAsyncDriver$WriterThread TRACE: [serial://COM9] >> M400
2023-03-17 15:39:36.480 GcodeDriver$ReaderThread TRACE: [serial://COM9] << ok
2023-03-17 15:39:36.480 GcodeDriver TRACE: [serial://COM9] confirmed M400
2023-03-17 15:39:36.481 GcodeAsyncDriver$WriterThread TRACE: [serial://COM9] >> M114
2023-03-17 15:39:36.502 GcodeDriver$ReaderThread TRACE: [serial://COM9] << ok C: X:25.0900 Y:54.2090 Z:0.0000 A:90.0000 B:180.0000 C:6.0000 E:0.0000
2023-03-17 15:39:36.502 GcodeDriver TRACE: Position report: ok C: X:25.0900 Y:54.2090 Z:0.0000 A:90.0000 B:180.0000 C:6.0000 E:0.0000
2023-03-17 15:39:36.502 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:25.090000, Y:54.209000, Z:0.000000, N1:90.000000, N2:180.000000)
2023-03-17 15:39:36.502 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete.
2023-03-17 15:39:36.516 AbstractHeadMountable DEBUG: N1.moveTo((169.572449, 35.183987, -10.200000, 0.000000 mm), 0.64)
2023-03-17 15:39:36.517 ReferenceNozzle TRACE: N1.toHeadLocation((169.644029, 35.160510, -10.200000, 0.000000 mm), ...) runout compensation (-0.071579, 0.023477, 0.000000, 0.000000 mm)
2023-03-17 15:39:36.518 Scripting TRACE: Scripting.on Camera.BeforeSettle
2023-03-17 15:39:36.521 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(M204 S4109 G1 X132.46 Y45.701  A0.0  F28223 ; move to target, 10000)...
2023-03-17 15:39:36.521 GcodeDriver TRACE: [serial://COM9] confirmed M114
2023-03-17 15:39:36.522 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(M204 S198 G1 X132.52 Y45.639    F178 ; move to target, 10000)...
2023-03-17 15:39:36.522 GcodeAsyncDriver$WriterThread TRACE: [serial://COM9] >> M204S4109G1X132.46Y45.701A0F28223
2023-03-17 15:39:36.522 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(M204 S40960 G1   Z-35.7   F38400 ; move to target, 10000)...
2023-03-17 15:39:36.522 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(M400 ; Wait for moves to complete before returning, 15625)...
2023-03-17 15:39:36.523 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(M114 ; get position, -1)...
2023-03-17 15:39:36.534 GcodeDriver$ReaderThread TRACE: [serial://COM9] << ok
2023-03-17 15:39:36.534 GcodeDriver TRACE: [serial://COM9] confirmed M204S4109G1X132.46Y45.701A0F28223
2023-03-17 15:39:36.534 GcodeAsyncDriver$WriterThread TRACE: [serial://COM9] >> M204S198G1X132.52Y45.639F178
2023-03-17 15:39:36.550 GcodeDriver$ReaderThread TRACE: [serial://COM9] << ok
2023-03-17 15:39:36.550 GcodeDriver TRACE: [serial://COM9] confirmed M204S198G1X132.52Y45.639F178
2023-03-17 15:39:36.550 GcodeAsyncDriver$WriterThread TRACE: [serial://COM9] >> M204S40960G1Z-35.7F38400
2023-03-17 15:39:36.566 GcodeDriver$ReaderThread TRACE: [serial://COM9] << ok
2023-03-17 15:39:36.566 GcodeDriver TRACE: [serial://COM9] confirmed M204S40960G1Z-35.7F38400
2023-03-17 15:39:36.566 GcodeAsyncDriver$WriterThread TRACE: [serial://COM9] >> M400
2023-03-17 15:39:37.109 GcodeDriver$ReaderThread TRACE: [serial://COM9] << ok
2023-03-17 15:39:37.110 GcodeDriver TRACE: [serial://COM9] confirmed M400
2023-03-17 15:39:37.110 GcodeAsyncDriver$WriterThread TRACE: [serial://COM9] >> M114
2023-03-17 15:39:37.133 GcodeDriver$ReaderThread TRACE: [serial://COM9] << ok C: X:132.5200 Y:45.6390 Z:-35.7000 A:0.0000 B:180.0000 C:6.0000 E:0.0000
2023-03-17 15:39:37.133 GcodeDriver TRACE: Position report: ok C: X:132.5200 Y:45.6390 Z:-35.7000 A:0.0000 B:180.0000 C:6.0000 E:0.0000
2023-03-17 15:39:37.133 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:132.520000, Y:45.639000, Z:-35.700000, N1:0.000000, N2:180.000000)
2023-03-17 15:39:37.133 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete.
2023-03-17 15:39:37.134 Scripting TRACE: Scripting.on Camera.BeforeCapture
2023-03-17 15:39:37.152 Scripting TRACE: Scripting.on Camera.AfterCapture
2023-03-17 15:39:37.162 Scripting TRACE: Scripting.on Camera.BeforeCapture
2023-03-17 15:39:37.182 Scripting TRACE: Scripting.on Camera.AfterCapture
2023-03-17 15:39:37.198 AbstractSettlingCamera TRACE: autoSettleAndCapture t=64 auto settle score: 0.267 compute time: 14
2023-03-17 15:39:37.198 Scripting TRACE: Scripting.on Camera.BeforeCapture
2023-03-17 15:39:37.217 Scripting TRACE: Scripting.on Camera.AfterCapture
2023-03-17 15:39:37.237 AbstractSettlingCamera TRACE: autoSettleAndCapture t=103 auto settle score: 0.176 compute time: 18
2023-03-17 15:39:37.237 Scripting TRACE: Scripting.on Camera.BeforeCapture
2023-03-17 15:39:37.258 Scripting TRACE: Scripting.on Camera.AfterCapture
2023-03-17 15:39:37.273 AbstractSettlingCamera TRACE: autoSettleAndCapture t=139 auto settle score: 0.169 compute time: 13
2023-03-17 15:39:37.274 AbstractSettlingCamera DEBUG: autoSettleAndCapture in 140 ms
2023-03-17 15:39:37.274 Scripting TRACE: Scripting.on Camera.AfterSettle
2023-03-17 15:39:37.340 MaskHsv TRACE: Fraction actually masked = 0.8895243138293178
2023-03-17 15:39:37.433 ReferenceBottomVision DEBUG: Alignment result: C_0603_1608Metric-100nF
2023-03-17 15:39:37.435 ReferenceBottomVision DEBUG: Bottom vision part C_0603_1608Metric-100nF result rect { {630.4368896484375, 355.3009033203125} 338x384 * 6.1466264724731445 }
2023-03-17 15:39:37.435 ReferenceBottomVision DEBUG: Alignment result: C_0603_1608Metric-100nF  |  X:0.019 Y:0.097 C:-6.147 ?:0.099
2023-03-17 15:39:37.444 Scripting TRACE: Scripting.on Vision.PartAlignment.After
2023-03-17 15:39:37.446 ReferencePnpJobProcessor$Align DEBUG: Align id C_0603_1608Metric-100nF, name null, heightUnits Millimeters, height 0.800000, packageId (C_0603_1608Metric) with N1 N1, offsets offset ( location: (0.019368, 0.097142, 0.000000, -6.146626 mm) pre-rotatedfalse)
2023-03-17 15:39:37.446 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(; H1 N1VAC ACTUATOR_READ_COMMAND, 10000)...
2023-03-17 15:39:37.447 GcodeAsyncDriver DEBUG: serial://COM9 empty command after pre process
2023-03-17 15:39:37.447 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(M105 ; read vacuum, 10000)...
2023-03-17 15:39:37.447 GcodeDriver TRACE: [serial://COM9] confirmed M114
2023-03-17 15:39:37.447 GcodeAsyncDriver$WriterThread TRACE: [serial://COM9] >> M105
2023-03-17 15:39:37.452 GcodeDriver$ReaderThread TRACE: [serial://COM9] << ok V1:211.6 /0.0 @0 V2:126.6 /0.0 @0
2023-03-17 15:39:37.453 GcodeDriver TRACE: actuatorRead response: ok V1:211.6 /0.0 @0 V2:126.6 /0.0 @0
2023-03-17 15:39:37.453 ReferenceActuator DEBUG: N1VSENSE.read(): 211.6
2023-03-17 15:39:37.453 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(M400 ; Wait for moves to complete before returning, 15625)...
2023-03-17 15:39:37.453 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(M114 ; get position, -1)...
2023-03-17 15:39:37.453 GcodeDriver TRACE: [serial://COM9] confirmed M105
2023-03-17 15:39:37.453 GcodeAsyncDriver$WriterThread TRACE: [serial://COM9] >> M400
2023-03-17 15:39:37.468 GcodeDriver$ReaderThread TRACE: [serial://COM9] << ok
2023-03-17 15:39:37.468 GcodeDriver TRACE: [serial://COM9] confirmed M400
2023-03-17 15:39:37.469 GcodeAsyncDriver$WriterThread TRACE: [serial://COM9] >> M114
2023-03-17 15:39:37.490 GcodeDriver$ReaderThread TRACE: [serial://COM9] << ok C: X:132.5200 Y:45.6390 Z:-35.7000 A:0.0000 B:180.0000 C:6.0000 E:0.0000
2023-03-17 15:39:37.490 GcodeDriver TRACE: Position report: ok C: X:132.5200 Y:45.6390 Z:-35.7000 A:0.0000 B:180.0000 C:6.0000 E:0.0000
2023-03-17 15:39:37.490 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:132.520000, Y:45.639000, Z:-35.700000, N1:0.000000, N2:180.000000)
2023-03-17 15:39:37.491 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete.
2023-03-17 15:39:37.491 Scripting TRACE: Scripting.on Job.Placement.BeforeAssembly
2023-03-17 15:39:37.494 ReferenceHead DEBUG: H1.moveToSafeZ(0.64)
2023-03-17 15:39:37.494 AbstractHeadMountable DEBUG: N1.moveToSafeZ(0.64)
2023-03-17 15:39:37.494 AbstractHeadMountable DEBUG: N1.moveTo((169.572449, 35.183987, 0.000000, 0.000000 mm), 0.64)
2023-03-17 15:39:37.494 ReferenceNozzle TRACE: N1.toHeadLocation((169.644029, 35.160510, 0.000000, 0.000000 mm), ...) runout compensation (-0.071579, 0.023477, 0.000000, 0.000000 mm)
2023-03-17 15:39:37.495 AbstractHeadMountable DEBUG: N2.moveToSafeZ(0.64)
2023-03-17 15:39:37.496 AbstractHeadMountable DEBUG: Top Camera.moveToSafeZ(0.64)
2023-03-17 15:39:37.496 AbstractHeadMountable DEBUG: BLOW.moveToSafeZ(0.64)
2023-03-17 15:39:37.496 AbstractHeadMountable DEBUG: N1.moveTo((154.176816, 131.218892, 0.000000, 6.067218 mm), 0.64)
2023-03-17 15:39:37.496 ReferenceNozzle TRACE: N1.toHeadLocation((154.250476, 131.203112, 0.000000, 6.067218 mm), ...) runout compensation (-0.073660, 0.015780, 0.000000, 0.000000 mm)
2023-03-17 15:39:37.497 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(M119 ; DRAGPIN endstop status, 10000)...
2023-03-17 15:39:37.497 GcodeDriver TRACE: [serial://COM9] confirmed M114
2023-03-17 15:39:37.497 GcodeAsyncDriver$WriterThread TRACE: [serial://COM9] >> M119
2023-03-17 15:39:37.519 GcodeDriver$ReaderThread TRACE: [serial://COM9] << 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-03-17 15:39:37.519 GcodeDriver$ReaderThread TRACE: [serial://COM9] << ok
2023-03-17 15:39:37.519 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-03-17 15:39:37.519 ReferenceActuator DEBUG: DRAGPIN.read(): 1
2023-03-17 15:39:37.520 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(M204 S40960 G1   Z0.0   F38400 ; move to target, 10000)...
2023-03-17 15:39:37.520 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(M400 ; Wait for moves to complete before returning, 15625)...
2023-03-17 15:39:37.520 GcodeDriver TRACE: [serial://COM9] confirmed M119
2023-03-17 15:39:37.520 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(M114 ; get position, -1)...
2023-03-17 15:39:37.521 GcodeAsyncDriver$WriterThread TRACE: [serial://COM9] >> M204S40960G1Z0F38400
2023-03-17 15:39:37.535 GcodeDriver$ReaderThread TRACE: [serial://COM9] << ok
2023-03-17 15:39:37.535 GcodeDriver TRACE: [serial://COM9] confirmed M204S40960G1Z0F38400
2023-03-17 15:39:37.535 GcodeAsyncDriver$WriterThread TRACE: [serial://COM9] >> M400
2023-03-17 15:39:37.695 GcodeDriver$ReaderThread TRACE: [serial://COM9] << ok
2023-03-17 15:39:37.695 GcodeDriver TRACE: [serial://COM9] confirmed M400
2023-03-17 15:39:37.695 GcodeAsyncDriver$WriterThread TRACE: [serial://COM9] >> M114
2023-03-17 15:39:37.718 GcodeDriver$ReaderThread TRACE: [serial://COM9] << ok C: X:132.5200 Y:45.6390 Z:0.0000 A:0.0000 B:180.0000 C:6.0000 E:0.0000
2023-03-17 15:39:37.718 GcodeDriver TRACE: Position report: ok C: X:132.5200 Y:45.6390 Z:0.0000 A:0.0000 B:180.0000 C:6.0000 E:0.0000
2023-03-17 15:39:37.718 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:132.520000, Y:45.639000, Z:0.000000, N1:0.000000, N2:180.000000)
2023-03-17 15:39:37.718 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete.
2023-03-17 15:39:37.733 AbstractHeadMountable DEBUG: N1.moveTo((154.176816, 131.218892, -35.000000, 6.067218 mm), 0.64)
2023-03-17 15:39:37.733 ReferenceNozzle TRACE: N1.toHeadLocation((154.250476, 131.203112, -35.000000, 6.067218 mm), ...) runout compensation (-0.073660, 0.015780, 0.000000, 0.000000 mm)
2023-03-17 15:39:37.734 ReferenceNozzle DEBUG: N1.place()
2023-03-17 15:39:37.734 Scripting TRACE: Scripting.on Nozzle.BeforePlace
2023-03-17 15:39:37.737 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(M204 S2489 G1 X117.18 Y141.640  A6.1  F20869 ; move to target, 10000)...
2023-03-17 15:39:37.737 GcodeDriver TRACE: [serial://COM9] confirmed M114
2023-03-17 15:39:37.737 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(M204 S198 G1 X117.12 Y141.702    F178 ; move to target, 10000)...
2023-03-17 15:39:37.737 GcodeAsyncDriver$WriterThread TRACE: [serial://COM9] >> M204S2489G1X117.18Y141.64A6.1F20869
2023-03-17 15:39:37.738 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(M204 S40960 G1   Z-90.0   F38400 ; move to target, 10000)...
2023-03-17 15:39:37.738 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(M400 ; Wait for moves to complete before returning, 15625)...
2023-03-17 15:39:37.738 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(M114 ; get position, -1)...
2023-03-17 15:39:37.749 GcodeDriver$ReaderThread TRACE: [serial://COM9] << ok
2023-03-17 15:39:37.750 GcodeDriver TRACE: [serial://COM9] confirmed M204S2489G1X117.18Y141.64A6.1F20869
2023-03-17 15:39:37.750 GcodeAsyncDriver$WriterThread TRACE: [serial://COM9] >> M204S198G1X117.12Y141.702F178
2023-03-17 15:39:37.766 GcodeDriver$ReaderThread TRACE: [serial://COM9] << ok
2023-03-17 15:39:37.766 GcodeDriver TRACE: [serial://COM9] confirmed M204S198G1X117.12Y141.702F178
2023-03-17 15:39:37.767 GcodeAsyncDriver$WriterThread TRACE: [serial://COM9] >> M204S40960G1Z-90F38400
2023-03-17 15:39:37.782 GcodeDriver$ReaderThread TRACE: [serial://COM9] << ok
2023-03-17 15:39:37.782 GcodeDriver TRACE: [serial://COM9] confirmed M204S40960G1Z-90F38400
2023-03-17 15:39:37.782 GcodeAsyncDriver$WriterThread TRACE: [serial://COM9] >> M400
2023-03-17 15:39:37.782 GcodeDriver$ReaderThread TRACE: [serial://COM9] << Error: Soft Endstop Z was exceeded - entire move ignored
2023-03-17 15:39:38.261 GcodeDriver$ReaderThread TRACE: [serial://COM9] << ok
2023-03-17 15:39:38.261 GcodeDriver TRACE: [serial://COM9] confirmed M400
2023-03-17 15:39:38.262 GcodeAsyncDriver$WriterThread TRACE: [serial://COM9] >> M114
2023-03-17 15:39:38.285 GcodeDriver$ReaderThread TRACE: [serial://COM9] << ok C: X:117.1200 Y:141.7020 Z:0.0000 A:6.1000 B:180.0000 C:6.0000 E:0.0000
2023-03-17 15:39:38.285 GcodeDriver TRACE: Position report: ok C: X:117.1200 Y:141.7020 Z:0.0000 A:6.1000 B:180.0000 C:6.0000 E:0.0000
2023-03-17 15:39:38.285 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:117.120000, Y:141.702000, Z:0.000000, N1:6.100000, N2:180.000000)
2023-03-17 15:39:38.285 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete.
2023-03-17 15:39:38.285 AbstractMotionPlanner DEBUG: Reported location changes current location from (X:117.120142, Y:141.681445, Z:-90.000000, N1:6.067218, N2:180.000000) to (X:117.120000, Y:141.681200, Z:0.000000, N1:6.100000, N2:180.000000)
2023-03-17 15:39:38.286 ReferenceActuator DEBUG: N1VAC.actuate(false)
2023-03-17 15:39:38.286 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(; H1 N1VAC ACTUATE_BOOLEAN_COMMAND, 10000)...
2023-03-17 15:39:38.286 GcodeAsyncDriver DEBUG: serial://COM9 empty command after pre process
2023-03-17 15:39:38.286 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(M801 ; off, close solenoid valve, RED led OFF on soleonid, 10000)...
2023-03-17 15:39:38.287 GcodeDriver TRACE: [serial://COM9] confirmed M114
2023-03-17 15:39:38.287 GcodeAsyncDriver$WriterThread TRACE: [serial://COM9] >> M801
2023-03-17 15:39:38.300 GcodeDriver$ReaderThread TRACE: [serial://COM9] << ok
2023-03-17 15:39:38.337 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(M400 ; Wait for moves to complete before returning, 15625)...
2023-03-17 15:39:38.337 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(M114 ; get position, -1)...
2023-03-17 15:39:38.337 GcodeDriver TRACE: [serial://COM9] confirmed M801
2023-03-17 15:39:38.338 GcodeAsyncDriver$WriterThread TRACE: [serial://COM9] >> M400
2023-03-17 15:39:38.348 GcodeDriver$ReaderThread TRACE: [serial://COM9] << ok
2023-03-17 15:39:38.348 GcodeDriver TRACE: [serial://COM9] confirmed M400
2023-03-17 15:39:38.350 GcodeAsyncDriver$WriterThread TRACE: [serial://COM9] >> M114
2023-03-17 15:39:38.371 GcodeDriver$ReaderThread TRACE: [serial://COM9] << ok C: X:117.1200 Y:141.7020 Z:0.0000 A:6.1000 B:180.0000 C:6.0000 E:0.0000
2023-03-17 15:39:38.372 GcodeDriver TRACE: Position report: ok C: X:117.1200 Y:141.7020 Z:0.0000 A:6.1000 B:180.0000 C:6.0000 E:0.0000
2023-03-17 15:39:38.372 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:117.120000, Y:141.702000, Z:0.000000, N1:6.100000, N2:180.000000)
2023-03-17 15:39:38.372 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete.
2023-03-17 15:39:38.373 ReferenceActuator DEBUG: VAC.actuate(false)
2023-03-17 15:39:38.373 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(; VAC M808 on / M809 off, 10000)...
2023-03-17 15:39:38.373 GcodeAsyncDriver DEBUG: serial://COM9 empty command after pre process
2023-03-17 15:39:38.373 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(M809 ; turn off vacuum pump, 10000)...
2023-03-17 15:39:38.373 GcodeDriver TRACE: [serial://COM9] confirmed M114
2023-03-17 15:39:38.373 GcodeAsyncDriver$WriterThread TRACE: [serial://COM9] >> M809
2023-03-17 15:39:38.387 GcodeDriver$ReaderThread TRACE: [serial://COM9] << ok
2023-03-17 15:39:38.424 Scripting TRACE: Scripting.on Nozzle.AfterPlace
2023-03-17 15:39:38.426 AbstractHeadMountable DEBUG: N1.moveToSafeZ(0.64)
2023-03-17 15:39:38.427 ReferenceActuator DEBUG: VAC.actuate(true)
2023-03-17 15:39:38.427 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(; VAC M808 on / M809 off, 10000)...
2023-03-17 15:39:38.427 GcodeAsyncDriver DEBUG: serial://COM9 empty command after pre process
2023-03-17 15:39:38.427 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(M808 ; turn on vacuum pump, 10000)...
2023-03-17 15:39:38.428 GcodeDriver TRACE: [serial://COM9] confirmed M809
2023-03-17 15:39:38.428 GcodeAsyncDriver$WriterThread TRACE: [serial://COM9] >> M808
2023-03-17 15:39:38.435 GcodeDriver$ReaderThread TRACE: [serial://COM9] << ok
2023-03-17 15:39:38.478 ReferenceActuator DEBUG: N1VAC.actuate(true)
2023-03-17 15:39:38.478 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(; H1 N1VAC ACTUATE_BOOLEAN_COMMAND, 10000)...
2023-03-17 15:39:38.478 GcodeAsyncDriver DEBUG: serial://COM9 empty command after pre process
2023-03-17 15:39:38.478 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(M800 ; on, open solenoid valve, RED led ON on soleonid, 10000)...
2023-03-17 15:39:38.478 GcodeDriver TRACE: [serial://COM9] confirmed M808
2023-03-17 15:39:38.479 GcodeAsyncDriver$WriterThread TRACE: [serial://COM9] >> M800
2023-03-17 15:39:38.483 GcodeDriver$ReaderThread TRACE: [serial://COM9] << ok
2023-03-17 15:39:38.529 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(M400 ; Wait for moves to complete before returning, 15625)...
2023-03-17 15:39:38.529 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(M114 ; get position, -1)...
2023-03-17 15:39:38.529 GcodeDriver TRACE: [serial://COM9] confirmed M800
2023-03-17 15:39:38.529 GcodeAsyncDriver$WriterThread TRACE: [serial://COM9] >> M400
2023-03-17 15:39:38.532 GcodeDriver$ReaderThread TRACE: [serial://COM9] << ok
2023-03-17 15:39:38.532 GcodeDriver TRACE: [serial://COM9] confirmed M400
2023-03-17 15:39:38.532 GcodeAsyncDriver$WriterThread TRACE: [serial://COM9] >> M114
2023-03-17 15:39:38.554 GcodeDriver$ReaderThread TRACE: [serial://COM9] << ok C: X:117.1200 Y:141.7020 Z:0.0000 A:6.1000 B:180.0000 C:6.0000 E:0.0000
2023-03-17 15:39:38.554 GcodeDriver TRACE: Position report: ok C: X:117.1200 Y:141.7020 Z:0.0000 A:6.1000 B:180.0000 C:6.0000 E:0.0000
2023-03-17 15:39:38.555 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:117.120000, Y:141.702000, Z:0.000000, N1:6.100000, N2:180.000000)
2023-03-17 15:39:38.555 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete.
2023-03-17 15:39:38.655 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(; H1 N1VAC ACTUATOR_READ_COMMAND, 10000)...
2023-03-17 15:39:38.655 GcodeAsyncDriver DEBUG: serial://COM9 empty command after pre process
2023-03-17 15:39:38.655 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(M105 ; read vacuum, 10000)...
2023-03-17 15:39:38.655 GcodeDriver TRACE: [serial://COM9] confirmed M114
2023-03-17 15:39:38.656 GcodeAsyncDriver$WriterThread TRACE: [serial://COM9] >> M105
2023-03-17 15:39:38.666 GcodeDriver$ReaderThread TRACE: [serial://COM9] << ok V1:208.4 /0.0 @0 V2:126.6 /0.0 @0
2023-03-17 15:39:38.666 GcodeDriver TRACE: actuatorRead response: ok V1:208.4 /0.0 @0 V2:126.6 /0.0 @0
2023-03-17 15:39:38.666 ReferenceActuator DEBUG: N1VSENSE.read(): 208.4
2023-03-17 15:39:38.666 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(M400 ; Wait for moves to complete before returning, 15625)...
2023-03-17 15:39:38.666 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(M114 ; get position, -1)...
2023-03-17 15:39:38.666 GcodeDriver TRACE: [serial://COM9] confirmed M105
2023-03-17 15:39:38.667 GcodeAsyncDriver$WriterThread TRACE: [serial://COM9] >> M400
2023-03-17 15:39:38.681 GcodeDriver$ReaderThread TRACE: [serial://COM9] << ok
2023-03-17 15:39:38.681 GcodeDriver TRACE: [serial://COM9] confirmed M400
2023-03-17 15:39:38.682 GcodeAsyncDriver$WriterThread TRACE: [serial://COM9] >> M114
2023-03-17 15:39:38.704 GcodeDriver$ReaderThread TRACE: [serial://COM9] << ok C: X:117.1200 Y:141.7020 Z:0.0000 A:6.1000 B:180.0000 C:6.0000 E:0.0000
2023-03-17 15:39:38.704 GcodeDriver TRACE: Position report: ok C: X:117.1200 Y:141.7020 Z:0.0000 A:6.1000 B:180.0000 C:6.0000 E:0.0000
2023-03-17 15:39:38.704 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:117.120000, Y:141.702000, Z:0.000000, N1:6.100000, N2:180.000000)
2023-03-17 15:39:38.704 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete.
2023-03-17 15:39:38.706 ReferenceActuator DEBUG: N1VAC.actuate(false)
2023-03-17 15:39:38.706 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(; H1 N1VAC ACTUATE_BOOLEAN_COMMAND, 10000)...
2023-03-17 15:39:38.706 GcodeAsyncDriver DEBUG: serial://COM9 empty command after pre process
2023-03-17 15:39:38.706 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(M801 ; off, close solenoid valve, RED led OFF on soleonid, 10000)...
2023-03-17 15:39:38.706 GcodeDriver TRACE: [serial://COM9] confirmed M114
2023-03-17 15:39:38.707 GcodeAsyncDriver$WriterThread TRACE: [serial://COM9] >> M801
2023-03-17 15:39:38.720 GcodeDriver$ReaderThread TRACE: [serial://COM9] << ok
2023-03-17 15:39:38.756 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(M400 ; Wait for moves to complete before returning, 15625)...
2023-03-17 15:39:38.756 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(M114 ; get position, -1)...
2023-03-17 15:39:38.756 GcodeDriver TRACE: [serial://COM9] confirmed M801
2023-03-17 15:39:38.756 GcodeAsyncDriver$WriterThread TRACE: [serial://COM9] >> M400
2023-03-17 15:39:38.768 GcodeDriver$ReaderThread TRACE: [serial://COM9] << ok
2023-03-17 15:39:38.768 GcodeDriver TRACE: [serial://COM9] confirmed M400
2023-03-17 15:39:38.768 GcodeAsyncDriver$WriterThread TRACE: [serial://COM9] >> M114
2023-03-17 15:39:38.791 GcodeDriver$ReaderThread TRACE: [serial://COM9] << ok C: X:117.1200 Y:141.7020 Z:0.0000 A:6.1000 B:180.0000 C:6.0000 E:0.0000
2023-03-17 15:39:38.791 GcodeDriver TRACE: Position report: ok C: X:117.1200 Y:141.7020 Z:0.0000 A:6.1000 B:180.0000 C:6.0000 E:0.0000
2023-03-17 15:39:38.791 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:117.120000, Y:141.702000, Z:0.000000, N1:6.100000, N2:180.000000)
2023-03-17 15:39:38.791 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete.
2023-03-17 15:39:38.792 ReferenceActuator DEBUG: VAC.actuate(false)
2023-03-17 15:39:38.792 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(; VAC M808 on / M809 off, 10000)...
2023-03-17 15:39:38.792 GcodeAsyncDriver DEBUG: serial://COM9 empty command after pre process
2023-03-17 15:39:38.792 GcodeAsyncDriver DEBUG: serial://COM9 commandQueue.offer(M809 ; turn off vacuum pump, 10000)...
2023-03-17 15:39:38.792 GcodeDriver TRACE: [serial://COM9] confirmed M114
2023-03-17 15:39:38.793 GcodeAsyncDriver$WriterThread TRACE: [serial://COM9] >> M809
2023-03-17 15:39:38.806 GcodeDriver$ReaderThread TRACE: [serial://COM9] << ok
2023-03-17 15:39:38.842 ReferenceNozzle DEBUG: Nozzle tip 503-1 absolute vacuum level 208.4 outside PartOff range 100.0 .. 160.0
2023-03-17 15:39:38.842 AbstractMachine TRACE: Exception caught, executing pending motion: org.openpnp.spi.JobProcessor$JobProcessorException: Part vacuum-detected on nozzle after place.
	at org.openpnp.machine.reference.ReferencePnpJobProcessor$Place.checkPartOff(ReferencePnpJobProcessor.java:909)
	at org.openpnp.machine.reference.ReferencePnpJobProcessor$Place.stepImpl(ReferencePnpJobProcessor.java:852)
	at org.openpnp.machine.reference.ReferencePnpJobProcessor$PlannedPlacementStep.step(ReferencePnpJobProcessor.java:1210)
	at org.openpnp.machine.reference.ReferencePnpJobProcessor.next(ReferencePnpJobProcessor.java:117)
	at org.openpnp.gui.JobPanel.lambda$jobRun$2(JobPanel.java:909)
	at org.openpnp.spi.base.AbstractMachine$1.call(AbstractMachine.java:578)
	at java.util.concurrent.FutureTask.run(Unknown Source)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
	at java.lang.Thread.run(Unknown Source)
2023-03-17 15:39:38.843 AbstractMachine TRACE: Machine entering idle state.
2023-03-17 15:39:38.844 MessageBoxes DEBUG: Job Error: Part vacuum-detected on nozzle after place.