2021-09-27 08:19:31.868 GcodeDriver$ReaderThread TRACE: [serial://COM5] << wait
2021-09-27 08:19:32.870 GcodeDriver$ReaderThread TRACE: [serial://COM5] << wait
2021-09-27 08:19:33.870 GcodeDriver$ReaderThread TRACE: [serial://COM5] << wait
2021-09-27 08:19:34.021 ReferenceHead DEBUG: H1.moveToSafeZ(1.0)
2021-09-27 08:19:34.021 AbstractHeadMountable DEBUG: N.moveToSafeZ(1.0)
2021-09-27 08:19:34.021 AbstractHeadMountable DEBUG: DownCamera.moveToSafeZ(1.0)
2021-09-27 08:19:34.022 Scripting TRACE: Scripting.on Job.Starting
2021-09-27 08:19:34.022 ReferencePnpJobProcessor$Plan DEBUG: Planner complete in 0ms: [N (NT1) -> D1]
2021-09-27 08:19:34.022 ReferencePnpJobProcessor$Plan DEBUG: Planned placements [N (NT1) -> D1]
2021-09-27 08:19:34.022 ReferencePnpJobProcessor$ChangeNozzleTips DEBUG: No nozzle tip change needed for nozzle N N1
2021-09-27 08:19:34.022 Scripting TRACE: Scripting.on Job.Placement.Starting
2021-09-27 08:19:34.055 ReferenceHead DEBUG: H1.moveToSafeZ(1.0)
2021-09-27 08:19:34.055 AbstractHeadMountable DEBUG: N.moveToSafeZ(1.0)
2021-09-27 08:19:34.055 AbstractHeadMountable DEBUG: DownCamera.moveToSafeZ(1.0)
2021-09-27 08:19:34.055 AbstractHeadMountable DEBUG: DownCamera.moveTo((28.825303, 226.186260, 0.000000, 0.000000 mm), 1.0)
2021-09-27 08:19:34.056 GcodeDriver DEBUG: [serial://COM5] >> G1 X28.83 Y226.19   F10000, 10000
2021-09-27 08:19:34.062 GcodeDriver$ReaderThread TRACE: [serial://COM5] << ok 0
2021-09-27 08:19:34.063 GcodeDriver TRACE: [serial://COM5] confirmed G1 X28.83 Y226.19   F10000
2021-09-27 08:19:34.063 GcodeDriver DEBUG: [serial://COM5] >> G4 P1, 10000
2021-09-27 08:19:34.066 GcodeDriver$ReaderThread TRACE: [serial://COM5] << ok 0
2021-09-27 08:19:34.067 GcodeDriver TRACE: [serial://COM5] confirmed G4 P1
2021-09-27 08:19:34.067 AbstractHeadMountable DEBUG: DownCamera.moveTo((28.825303, 226.186260, -21.700000, 0.000000 mm), 1.0)
2021-09-27 08:19:34.068 ReferenceActuator DEBUG: DownCameraLED.actuate(true)
2021-09-27 08:19:34.068 GcodeDriver DEBUG: [serial://COM5] >> M42 P6 S150, 10000
2021-09-27 08:19:35.751 GcodeDriver$ReaderThread TRACE: [serial://COM5] << ok 0
2021-09-27 08:19:35.752 GcodeDriver TRACE: [serial://COM5] confirmed M42 P6 S150
2021-09-27 08:19:35.752 GcodeDriver$ReaderThread TRACE: [serial://COM5] << Set output: 6 to 150
2021-09-27 08:19:35.752 Scripting TRACE: Scripting.on Camera.BeforeSettle
2021-09-27 08:19:36.003 Scripting TRACE: Scripting.on Camera.BeforeCapture
2021-09-27 08:19:36.007 Scripting TRACE: Scripting.on Camera.AfterCapture
2021-09-27 08:19:36.007 Scripting TRACE: Scripting.on Camera.AfterSettle
2021-09-27 08:19:36.009 ReferenceActuator DEBUG: DownCameraLED.actuate(false)
2021-09-27 08:19:36.009 GcodeDriver DEBUG: [serial://COM5] >> M42 P6 S0, 10000
2021-09-27 08:19:36.015 GcodeDriver$ReaderThread TRACE: [serial://COM5] << ok 0
2021-09-27 08:19:36.016 GcodeDriver TRACE: [serial://COM5] confirmed M42 P6 S0
2021-09-27 08:19:36.016 GcodeDriver$ReaderThread TRACE: [serial://COM5] << Set output: 6 to 0
2021-09-27 08:19:36.053 ReferenceHead DEBUG: H1.moveToSafeZ(1.0)
2021-09-27 08:19:36.054 AbstractHeadMountable DEBUG: N.moveToSafeZ(1.0)
2021-09-27 08:19:36.054 AbstractHeadMountable DEBUG: DownCamera.moveToSafeZ(1.0)
2021-09-27 08:19:36.054 AbstractHeadMountable DEBUG: DownCamera.moveTo((28.825303, 226.186260, 0.000000, 0.000000 mm), 1.0)
2021-09-27 08:19:36.055 AbstractHeadMountable DEBUG: N.moveTo((26.650989, 229.580721, 1.000000, 2.896611 mm), 1.0)
2021-09-27 08:19:36.056 GcodeDriver DEBUG: [serial://COM5] >> G1 X54.95 Y201.08  E2.90 F10000, 10000
2021-09-27 08:19:36.066 GcodeDriver$ReaderThread TRACE: [serial://COM5] << ok 0
2021-09-27 08:19:36.069 GcodeDriver TRACE: [serial://COM5] confirmed G1 X54.95 Y201.08  E2.90 F10000
2021-09-27 08:19:36.069 GcodeDriver DEBUG: [serial://COM5] >> G4 P1, 10000
2021-09-27 08:19:36.073 GcodeDriver$ReaderThread TRACE: [serial://COM5] << ok 0
2021-09-27 08:19:36.074 GcodeDriver TRACE: [serial://COM5] confirmed G4 P1
2021-09-27 08:19:36.074 AbstractHeadMountable DEBUG: N.moveTo((26.650989, 229.580721, -21.700000, 2.896611 mm), 1.0)
2021-09-27 08:19:36.075 GcodeDriver DEBUG: [serial://COM5] >> G1   Z-21.70  F10000, 10000
2021-09-27 08:19:36.480 GcodeDriver$ReaderThread TRACE: [serial://COM5] << ok 0
2021-09-27 08:19:36.482 GcodeDriver TRACE: [serial://COM5] confirmed G1   Z-21.70  F10000
2021-09-27 08:19:36.483 GcodeDriver DEBUG: [serial://COM5] >> G4 P1, 10000
2021-09-27 08:19:36.486 GcodeDriver$ReaderThread TRACE: [serial://COM5] << ok 0
2021-09-27 08:19:36.486 GcodeDriver TRACE: [serial://COM5] confirmed G4 P1
2021-09-27 08:19:36.487 ReferenceNozzle DEBUG: N.pick()
2021-09-27 08:19:36.487 Scripting TRACE: Scripting.on Nozzle.BeforePick
2021-09-27 08:19:36.488 ReferenceActuator DEBUG: Selenoid.actuate(true)
2021-09-27 08:19:36.488 GcodeDriver DEBUG: [serial://COM5] >> M42 P29 S250, 10000
2021-09-27 08:19:37.073 GcodeDriver$ReaderThread TRACE: [serial://COM5] << ok 0
2021-09-27 08:19:37.074 GcodeDriver$ReaderThread TRACE: [serial://COM5] << Set output: 29 to 250
2021-09-27 08:19:37.078 GcodeDriver TRACE: [serial://COM5] confirmed M42 P29 S250
2021-09-27 08:19:37.084 Scripting TRACE: Scripting.on Nozzle.AfterPick
2021-09-27 08:19:37.084 AbstractHeadMountable DEBUG: N.moveToSafeZ(1.0)
2021-09-27 08:19:37.084 AbstractHeadMountable DEBUG: N.moveTo((26.650989, 229.580721, 1.000000, 2.896611 mm), 1.0)
2021-09-27 08:19:37.085 GcodeDriver DEBUG: [serial://COM5] >> G1   Z1.00  F10000, 10000
2021-09-27 08:19:37.090 GcodeDriver$ReaderThread TRACE: [serial://COM5] << ok 0
2021-09-27 08:19:37.093 GcodeDriver TRACE: [serial://COM5] confirmed G1   Z1.00  F10000
2021-09-27 08:19:37.093 GcodeDriver DEBUG: [serial://COM5] >> G4 P1, 10000
2021-09-27 08:19:37.097 GcodeDriver$ReaderThread TRACE: [serial://COM5] << ok 0
2021-09-27 08:19:37.097 GcodeDriver TRACE: [serial://COM5] confirmed G4 P1
2021-09-27 08:19:37.098 ReferenceBottomVision DEBUG: DIODE_SOT-23-BAV99.canHandle(false) => {}
2021-09-27 08:19:37.098 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-27 08:19:37.098 Scripting TRACE: Scripting.on Job.Placement.BeforeAssembly
2021-09-27 08:19:37.098 ReferenceHead DEBUG: H1.moveToSafeZ(1.0)
2021-09-27 08:19:37.099 AbstractHeadMountable DEBUG: N.moveToSafeZ(1.0)
2021-09-27 08:19:37.099 AbstractHeadMountable DEBUG: DownCamera.moveToSafeZ(1.0)
2021-09-27 08:19:37.099 AbstractHeadMountable DEBUG: N.moveTo((59.578000, 114.232000, 1.000000, 180.000000 mm), 1.0)
2021-09-27 08:19:37.101 GcodeDriver DEBUG: [serial://COM5] >> G1 X87.88 Y85.73  E180.00 F10000, 10000
2021-09-27 08:19:37.681 GcodeDriver$ReaderThread TRACE: [serial://COM5] << ok 0
2021-09-27 08:19:37.682 GcodeDriver TRACE: [serial://COM5] confirmed G1 X87.88 Y85.73  E180.00 F10000
2021-09-27 08:19:37.682 GcodeDriver DEBUG: [serial://COM5] >> G4 P1, 10000
2021-09-27 08:19:37.685 GcodeDriver$ReaderThread TRACE: [serial://COM5] << ok 0
2021-09-27 08:19:37.685 GcodeDriver TRACE: [serial://COM5] confirmed G4 P1
2021-09-27 08:19:37.686 AbstractHeadMountable DEBUG: N.moveTo((59.578000, 114.232000, -16.500000, 180.000000 mm), 1.0)
2021-09-27 08:19:37.687 GcodeDriver DEBUG: [serial://COM5] >> G1   Z-16.50  F10000, 10000
2021-09-27 08:19:38.603 GcodeDriver$ReaderThread TRACE: [serial://COM5] << ok 0
2021-09-27 08:19:38.610 GcodeDriver TRACE: [serial://COM5] confirmed G1   Z-16.50  F10000
2021-09-27 08:19:38.611 GcodeDriver DEBUG: [serial://COM5] >> G4 P1, 10000
2021-09-27 08:19:38.615 GcodeDriver$ReaderThread TRACE: [serial://COM5] << ok 0
2021-09-27 08:19:38.615 GcodeDriver TRACE: [serial://COM5] confirmed G4 P1
2021-09-27 08:19:38.616 ReferenceNozzle DEBUG: N.place()
2021-09-27 08:19:38.616 Scripting TRACE: Scripting.on Nozzle.BeforePlace
2021-09-27 08:19:38.616 ReferenceActuator DEBUG: Selenoid.actuate(false)
2021-09-27 08:19:38.616 GcodeDriver DEBUG: [serial://COM5] >> M42 P29 S0, 10000
2021-09-27 08:19:39.120 GcodeDriver$ReaderThread TRACE: [serial://COM5] << ok 0
2021-09-27 08:19:39.120 GcodeDriver TRACE: [serial://COM5] confirmed M42 P29 S0
2021-09-27 08:19:39.120 GcodeDriver$ReaderThread TRACE: [serial://COM5] << Set output: 29 to 0
2021-09-27 08:19:40.120 GcodeDriver$ReaderThread TRACE: [serial://COM5] << wait
2021-09-27 08:19:40.121 Scripting TRACE: Scripting.on Nozzle.AfterPlace
2021-09-27 08:19:40.121 AbstractHeadMountable DEBUG: N.moveToSafeZ(1.0)
2021-09-27 08:19:40.121 AbstractHeadMountable DEBUG: N.moveTo((59.578000, 114.232000, 1.000000, 180.000000 mm), 1.0)
2021-09-27 08:19:40.135 GcodeDriver DEBUG: [serial://COM5] >> G1   Z1.00  F10000, 10000
2021-09-27 08:19:40.143 GcodeDriver$ReaderThread TRACE: [serial://COM5] << ok 0
2021-09-27 08:19:40.150 GcodeDriver TRACE: [serial://COM5] confirmed G1   Z1.00  F10000
2021-09-27 08:19:40.150 GcodeDriver DEBUG: [serial://COM5] >> G4 P1, 10000
2021-09-27 08:19:40.154 GcodeDriver$ReaderThread TRACE: [serial://COM5] << ok 0
2021-09-27 08:19:40.154 GcodeDriver TRACE: [serial://COM5] confirmed G4 P1
2021-09-27 08:19:40.155 Scripting TRACE: Scripting.on Job.Placement.Complete
2021-09-27 08:19:40.156 ReferenceHead DEBUG: H1.moveToSafeZ(1.0)
2021-09-27 08:19:40.156 AbstractHeadMountable DEBUG: N.moveToSafeZ(1.0)
2021-09-27 08:19:40.156 AbstractHeadMountable DEBUG: DownCamera.moveToSafeZ(1.0)
2021-09-27 08:19:40.156 ReferenceHead DEBUG: H1.moveToSafeZ(1.0)
2021-09-27 08:19:40.156 AbstractHeadMountable DEBUG: N.moveToSafeZ(1.0)
2021-09-27 08:19:40.157 AbstractHeadMountable DEBUG: DownCamera.moveToSafeZ(1.0)
2021-09-27 08:19:40.157 ReferenceHead DEBUG: H1.moveToSafeZ(1.0)
2021-09-27 08:19:40.158 AbstractHeadMountable DEBUG: N.moveToSafeZ(1.0)
2021-09-27 08:19:40.158 AbstractHeadMountable DEBUG: DownCamera.moveToSafeZ(1.0)
2021-09-27 08:19:40.158 AbstractHeadMountable DEBUG: DownCamera.moveTo((214.000000, 390.000000, NaN, NaN mm), 1.0)
2021-09-27 08:19:40.159 GcodeDriver DEBUG: [serial://COM5] >> G1 X214.00 Y390.00   F10000, 10000
2021-09-27 08:19:40.684 GcodeDriver$ReaderThread TRACE: [serial://COM5] << ok 0
2021-09-27 08:19:40.685 GcodeDriver TRACE: [serial://COM5] confirmed G1 X214.00 Y390.00   F10000
2021-09-27 08:19:40.685 GcodeDriver DEBUG: [serial://COM5] >> G4 P1, 10000
2021-09-27 08:19:40.689 GcodeDriver$ReaderThread TRACE: [serial://COM5] << ok 0
2021-09-27 08:19:40.689 GcodeDriver TRACE: [serial://COM5] confirmed G4 P1
2021-09-27 08:19:40.691 ReferencePnpJobProcessor$Finish INFO: Job finished 1 parts in 6.7 sec. This is 539.6 CPH
2021-09-27 08:19:40.691 Scripting TRACE: Scripting.on Job.Finished
2021-09-27 08:19:42.855 GcodeDriver$ReaderThread TRACE: [serial://COM5] << wait