2021-09-26 16:49:08.146 GcodeDriver$ReaderThread TRACE: [serial://COM5] << wait
2021-09-26 16:49:09.146 GcodeDriver$ReaderThread TRACE: [serial://COM5] << wait
2021-09-26 16:49:10.039 ReferenceHead DEBUG: H1.moveToSafeZ(1.0)
2021-09-26 16:49:10.040 AbstractHeadMountable DEBUG: N.moveToSafeZ(1.0)
2021-09-26 16:49:10.040 AbstractHeadMountable DEBUG: DownCamera.moveToSafeZ(1.0)
2021-09-26 16:49:10.040 Scripting TRACE: Scripting.on Job.Starting
2021-09-26 16:49:10.041 ReferencePnpJobProcessor$Plan DEBUG: Planner complete in 0ms: [N (NT1) -> D1]
2021-09-26 16:49:10.041 ReferencePnpJobProcessor$Plan DEBUG: Planned placements [N (NT1) -> D1]
2021-09-26 16:49:10.041 ReferencePnpJobProcessor$ChangeNozzleTips DEBUG: No nozzle tip change needed for nozzle N N1
2021-09-26 16:49:10.041 Scripting TRACE: Scripting.on Job.Placement.Starting
2021-09-26 16:49:10.110 ReferenceHead DEBUG: H1.moveToSafeZ(1.0)
2021-09-26 16:49:10.110 AbstractHeadMountable DEBUG: N.moveToSafeZ(1.0)
2021-09-26 16:49:10.110 AbstractHeadMountable DEBUG: DownCamera.moveToSafeZ(1.0)
2021-09-26 16:49:10.111 AbstractHeadMountable DEBUG: DownCamera.moveTo((28.825303, 226.186260, 0.000000, 0.000000 mm), 1.0)
2021-09-26 16:49:10.111 GcodeDriver DEBUG: [serial://COM5] >> G1 X28.83 Y226.19   F10000, 10000
2021-09-26 16:49:10.127 GcodeDriver$ReaderThread TRACE: [serial://COM5] << ok 0
2021-09-26 16:49:10.128 GcodeDriver TRACE: [serial://COM5] confirmed G1 X28.83 Y226.19   F10000
2021-09-26 16:49:10.128 GcodeDriver DEBUG: [serial://COM5] >> G4 P1, 10000
2021-09-26 16:49:10.132 GcodeDriver$ReaderThread TRACE: [serial://COM5] << ok 0
2021-09-26 16:49:10.132 GcodeDriver TRACE: [serial://COM5] confirmed G4 P1
2021-09-26 16:49:10.132 AbstractHeadMountable DEBUG: DownCamera.moveTo((28.825303, 226.186260, -21.700000, 0.000000 mm), 1.0)
2021-09-26 16:49:10.136 ReferenceActuator DEBUG: DownCameraLED.actuate(true)
2021-09-26 16:49:10.136 GcodeDriver DEBUG: [serial://COM5] >> M42 P6 S150, 10000
2021-09-26 16:49:11.809 GcodeDriver$ReaderThread TRACE: [serial://COM5] << ok 0
2021-09-26 16:49:11.809 GcodeDriver TRACE: [serial://COM5] confirmed M42 P6 S150
2021-09-26 16:49:11.809 GcodeDriver$ReaderThread TRACE: [serial://COM5] << Set output: 6 to 150
2021-09-26 16:49:11.809 Scripting TRACE: Scripting.on Camera.BeforeSettle
2021-09-26 16:49:12.060 Scripting TRACE: Scripting.on Camera.BeforeCapture
2021-09-26 16:49:12.063 Scripting TRACE: Scripting.on Camera.AfterCapture
2021-09-26 16:49:12.074 Scripting TRACE: Scripting.on Camera.AfterSettle
2021-09-26 16:49:12.075 ReferenceActuator DEBUG: DownCameraLED.actuate(false)
2021-09-26 16:49:12.075 GcodeDriver DEBUG: [serial://COM5] >> M42 P6 S0, 10000
2021-09-26 16:49:12.081 GcodeDriver$ReaderThread TRACE: [serial://COM5] << ok 0
2021-09-26 16:49:12.081 GcodeDriver$ReaderThread TRACE: [serial://COM5] << Set output: 6 to 0
2021-09-26 16:49:12.082 GcodeDriver TRACE: [serial://COM5] confirmed M42 P6 S0
2021-09-26 16:49:12.112 ReferenceHead DEBUG: H1.moveToSafeZ(1.0)
2021-09-26 16:49:12.112 AbstractHeadMountable DEBUG: N.moveToSafeZ(1.0)
2021-09-26 16:49:12.112 AbstractHeadMountable DEBUG: DownCamera.moveToSafeZ(1.0)
2021-09-26 16:49:12.112 AbstractHeadMountable DEBUG: DownCamera.moveTo((28.825303, 226.186260, 0.000000, 0.000000 mm), 1.0)
2021-09-26 16:49:12.113 AbstractHeadMountable DEBUG: N.moveTo((26.650989, 229.580721, 1.000000, 2.896611 mm), 1.0)
2021-09-26 16:49:12.114 GcodeDriver DEBUG: [serial://COM5] >> G1 X54.95 Y201.08  E2.90 F10000, 10000
2021-09-26 16:49:12.120 GcodeDriver$ReaderThread TRACE: [serial://COM5] << ok 0
2021-09-26 16:49:12.121 GcodeDriver TRACE: [serial://COM5] confirmed G1 X54.95 Y201.08  E2.90 F10000
2021-09-26 16:49:12.126 GcodeDriver DEBUG: [serial://COM5] >> G4 P1, 10000
2021-09-26 16:49:12.130 GcodeDriver$ReaderThread TRACE: [serial://COM5] << ok 0
2021-09-26 16:49:12.130 GcodeDriver TRACE: [serial://COM5] confirmed G4 P1
2021-09-26 16:49:12.130 AbstractHeadMountable DEBUG: N.moveTo((26.650989, 229.580721, -21.700000, 2.896611 mm), 1.0)
2021-09-26 16:49:12.131 GcodeDriver DEBUG: [serial://COM5] >> G1   Z-21.70  F10000, 10000
2021-09-26 16:49:12.728 GcodeDriver$ReaderThread TRACE: [serial://COM5] << ok 0
2021-09-26 16:49:12.730 GcodeDriver TRACE: [serial://COM5] confirmed G1   Z-21.70  F10000
2021-09-26 16:49:12.730 GcodeDriver DEBUG: [serial://COM5] >> G4 P1, 10000
2021-09-26 16:49:12.737 GcodeDriver$ReaderThread TRACE: [serial://COM5] << ok 0
2021-09-26 16:49:12.737 GcodeDriver TRACE: [serial://COM5] confirmed G4 P1
2021-09-26 16:49:12.737 ReferenceNozzle DEBUG: N.pick()
2021-09-26 16:49:12.737 Scripting TRACE: Scripting.on Nozzle.BeforePick
2021-09-26 16:49:12.738 ReferenceActuator DEBUG: Selenoid.actuate(true)
2021-09-26 16:49:12.738 GcodeDriver DEBUG: [serial://COM5] >> M42 P29 S250, 10000
2021-09-26 16:49:13.324 GcodeDriver$ReaderThread TRACE: [serial://COM5] << ok 0
2021-09-26 16:49:13.325 GcodeDriver$ReaderThread TRACE: [serial://COM5] << Set output: 29 to 250
2021-09-26 16:49:13.325 GcodeDriver TRACE: [serial://COM5] confirmed M42 P29 S250
2021-09-26 16:49:13.333 Scripting TRACE: Scripting.on Nozzle.AfterPick
2021-09-26 16:49:13.333 AbstractHeadMountable DEBUG: N.moveToSafeZ(1.0)
2021-09-26 16:49:13.333 AbstractHeadMountable DEBUG: N.moveTo((26.650989, 229.580721, 1.000000, 2.896611 mm), 1.0)
2021-09-26 16:49:13.335 GcodeDriver DEBUG: [serial://COM5] >> G1   Z1.00  F10000, 10000
2021-09-26 16:49:13.349 GcodeDriver$ReaderThread TRACE: [serial://COM5] << ok 0
2021-09-26 16:49:13.350 GcodeDriver TRACE: [serial://COM5] confirmed G1   Z1.00  F10000
2021-09-26 16:49:13.351 GcodeDriver DEBUG: [serial://COM5] >> G4 P1, 10000
2021-09-26 16:49:13.355 GcodeDriver$ReaderThread TRACE: [serial://COM5] << ok 0
2021-09-26 16:49:13.358 GcodeDriver TRACE: [serial://COM5] confirmed G4 P1
2021-09-26 16:49:13.359 ReferenceBottomVision DEBUG: DIODE_SOT-23-BAV99.canHandle(false) => {}
2021-09-26 16:49:13.359 ReferencePnpJobProcessor$Align DEBUG: Not aligning id DIODE_SOT-23-BAV99, name null, heightUnits Millimeters, height 1.500000, packageId (DIODE_SOT-23) as no compatible enabled aligners defined
2021-09-26 16:49:13.359 Scripting TRACE: Scripting.on Job.Placement.BeforeAssembly
2021-09-26 16:49:13.359 ReferenceHead DEBUG: H1.moveToSafeZ(1.0)
2021-09-26 16:49:13.359 AbstractHeadMountable DEBUG: N.moveToSafeZ(1.0)
2021-09-26 16:49:13.360 AbstractHeadMountable DEBUG: DownCamera.moveToSafeZ(1.0)
2021-09-26 16:49:13.360 AbstractHeadMountable DEBUG: N.moveTo((59.578000, 114.232000, 1.000000, 90.000000 mm), 1.0)
2021-09-26 16:49:13.361 GcodeDriver DEBUG: [serial://COM5] >> G1 X87.88 Y85.73  E90.00 F10000, 10000
2021-09-26 16:49:13.941 GcodeDriver$ReaderThread TRACE: [serial://COM5] << ok 0
2021-09-26 16:49:13.942 GcodeDriver TRACE: [serial://COM5] confirmed G1 X87.88 Y85.73  E90.00 F10000
2021-09-26 16:49:13.942 GcodeDriver DEBUG: [serial://COM5] >> G4 P1, 10000
2021-09-26 16:49:13.946 GcodeDriver$ReaderThread TRACE: [serial://COM5] << ok 0
2021-09-26 16:49:13.946 GcodeDriver TRACE: [serial://COM5] confirmed G4 P1
2021-09-26 16:49:13.946 AbstractHeadMountable DEBUG: N.moveTo((59.578000, 114.232000, -16.500000, 90.000000 mm), 1.0)
2021-09-26 16:49:13.947 GcodeDriver DEBUG: [serial://COM5] >> G1   Z-16.50  F10000, 10000
2021-09-26 16:49:14.862 GcodeDriver$ReaderThread TRACE: [serial://COM5] << ok 0
2021-09-26 16:49:14.862 GcodeDriver TRACE: [serial://COM5] confirmed G1   Z-16.50  F10000
2021-09-26 16:49:14.862 GcodeDriver DEBUG: [serial://COM5] >> G4 P1, 10000
2021-09-26 16:49:14.882 GcodeDriver$ReaderThread TRACE: [serial://COM5] << ok 0
2021-09-26 16:49:14.886 GcodeDriver TRACE: [serial://COM5] confirmed G4 P1
2021-09-26 16:49:14.887 ReferenceNozzle DEBUG: N.place()
2021-09-26 16:49:14.887 Scripting TRACE: Scripting.on Nozzle.BeforePlace
2021-09-26 16:49:14.887 ReferenceActuator DEBUG: Selenoid.actuate(false)
2021-09-26 16:49:14.887 GcodeDriver DEBUG: [serial://COM5] >> M42 P29 S0, 10000
2021-09-26 16:49:15.381 GcodeDriver$ReaderThread TRACE: [serial://COM5] << ok 0
2021-09-26 16:49:15.381 GcodeDriver TRACE: [serial://COM5] confirmed M42 P29 S0
2021-09-26 16:49:15.381 GcodeDriver$ReaderThread TRACE: [serial://COM5] << Set output: 29 to 0
2021-09-26 16:49:16.381 GcodeDriver$ReaderThread TRACE: [serial://COM5] << wait
2021-09-26 16:49:16.381 Scripting TRACE: Scripting.on Nozzle.AfterPlace
2021-09-26 16:49:16.382 AbstractHeadMountable DEBUG: N.moveToSafeZ(1.0)
2021-09-26 16:49:16.382 AbstractHeadMountable DEBUG: N.moveTo((59.578000, 114.232000, 1.000000, 90.000000 mm), 1.0)
2021-09-26 16:49:16.484 GcodeDriver DEBUG: [serial://COM5] >> G1   Z1.00  F10000, 10000
2021-09-26 16:49:16.490 GcodeDriver$ReaderThread TRACE: [serial://COM5] << ok 0
2021-09-26 16:49:16.491 GcodeDriver TRACE: [serial://COM5] confirmed G1   Z1.00  F10000
2021-09-26 16:49:16.491 GcodeDriver DEBUG: [serial://COM5] >> G4 P1, 10000
2021-09-26 16:49:16.496 GcodeDriver$ReaderThread TRACE: [serial://COM5] << ok 0
2021-09-26 16:49:16.496 GcodeDriver TRACE: [serial://COM5] confirmed G4 P1
2021-09-26 16:49:16.496 Scripting TRACE: Scripting.on Job.Placement.Complete
2021-09-26 16:49:16.497 ReferenceHead DEBUG: H1.moveToSafeZ(1.0)
2021-09-26 16:49:16.497 AbstractHeadMountable DEBUG: N.moveToSafeZ(1.0)
2021-09-26 16:49:16.497 AbstractHeadMountable DEBUG: DownCamera.moveToSafeZ(1.0)
2021-09-26 16:49:16.497 ReferenceHead DEBUG: H1.moveToSafeZ(1.0)
2021-09-26 16:49:16.497 AbstractHeadMountable DEBUG: N.moveToSafeZ(1.0)
2021-09-26 16:49:16.497 AbstractHeadMountable DEBUG: DownCamera.moveToSafeZ(1.0)
2021-09-26 16:49:16.498 ReferenceHead DEBUG: H1.moveToSafeZ(1.0)
2021-09-26 16:49:16.498 AbstractHeadMountable DEBUG: N.moveToSafeZ(1.0)
2021-09-26 16:49:16.498 AbstractHeadMountable DEBUG: DownCamera.moveToSafeZ(1.0)
2021-09-26 16:49:16.498 AbstractHeadMountable DEBUG: DownCamera.moveTo((214.000000, 390.000000, NaN, NaN mm), 1.0)
2021-09-26 16:49:16.500 GcodeDriver DEBUG: [serial://COM5] >> G1 X214.00 Y390.00   F10000, 10000
2021-09-26 16:49:17.030 GcodeDriver$ReaderThread TRACE: [serial://COM5] << ok 0
2021-09-26 16:49:17.030 GcodeDriver TRACE: [serial://COM5] confirmed G1 X214.00 Y390.00   F10000
2021-09-26 16:49:17.030 GcodeDriver DEBUG: [serial://COM5] >> G4 P1, 10000
2021-09-26 16:49:17.034 GcodeDriver$ReaderThread TRACE: [serial://COM5] << ok 0
2021-09-26 16:49:17.034 GcodeDriver TRACE: [serial://COM5] confirmed G4 P1
2021-09-26 16:49:17.034 ReferencePnpJobProcessor$Finish INFO: Job finished 1 parts in 7.0 sec. This is 514.7 CPH
2021-09-26 16:49:17.034 Scripting TRACE: Scripting.on Job.Finished