With the machined parked I started it with one part selected for placement. The first movement is it moving to the feeder which is slower than the movements after where it goes to the camera, then to the board and places the part. It then finishes at the home position.
2024-01-18 14:59:49.698 ReferenceHead DEBUG: H1.moveToSafeZ(1.0)
2024-01-18 14:59:49.699 AbstractHeadMountable DEBUG: N1.moveToSafeZ(1.0)
2024-01-18 14:59:49.699 AbstractHeadMountable DEBUG: N2.moveToSafeZ(1.0)
2024-01-18 14:59:49.699 AbstractHeadMountable DEBUG: Top.moveToSafeZ(1.0)
2024-01-18 14:59:49.699 Scripting TRACE: Scripting.on Job.Starting
2024-01-18 14:59:49.700 ReferencePnpJobProcessor$Plan DEBUG: Planner complete in 0ms: [N1 (504) -> R1]
2024-01-18 14:59:49.700 ReferencePnpJobProcessor$Plan DEBUG: Planned placements [N1 (504) -> R1]
2024-01-18 14:59:49.700 ReferencePnpJobProcessor$ChangeNozzleTips DEBUG: No nozzle tip change needed for nozzle N1 N1
2024-01-18 14:59:49.700 Scripting TRACE: Scripting.on Job.Placement.Starting
2024-01-18 14:59:49.701 ReferenceHead DEBUG: H1.moveToSafeZ(1.0)
2024-01-18 14:59:49.701 AbstractHeadMountable DEBUG: N1.moveToSafeZ(1.0)
2024-01-18 14:59:49.701 AbstractHeadMountable DEBUG: N2.moveToSafeZ(1.0)
2024-01-18 14:59:49.701 AbstractHeadMountable DEBUG: Top.moveToSafeZ(1.0)
2024-01-18 14:59:49.702 AbstractHeadMountable DEBUG: N1.moveTo((53.275000, 390.417000, 31.000000, 90.000000 mm), 1.0)
2024-01-18 14:59:49.702 ReferenceNozzle TRACE: N1.toHeadLocation((53.380130, 390.435337, 31.000000, 90.000000 mm), ...) runout compensation (-0.105130, -0.018337, 0.000000, 0.000000 mm)
2024-01-18 14:59:49.703 AbstractHeadMountable DEBUG: N1.moveTo((53.275000, 390.417000, NaN, 90.000000 mm), 1.0)
2024-01-18 14:59:49.703 ReferenceNozzle TRACE: N1.toHeadLocation((53.380130, 390.435337, 31.000000, 90.000000 mm), ...) runout compensation (-0.105130, -0.018337, 0.000000, 0.000000 mm)
2024-01-18 14:59:49.705 GcodeAsyncDriver DEBUG: [Duet3D:COM3] commandQueue offer >> M204 S457.1 G1 X73.8036 Y465.5115 Z80.0000 {U:U%.4f} {V:V%.4f} F28223 ; move to target
2024-01-18 14:59:49.706 GcodeAsyncDriver$WriterThread TRACE: [Duet3D:COM3] >> M204S457.1G1X73.8036Y465.5115Z80{U:U%.4f}{V:V%.4f}F28223
2024-01-18 14:59:49.706 GcodeAsyncDriver DEBUG: [Duet3D:COM3] commandQueue offer >> M204 S257.7 G1 X73.8436 Y465.6715 {U:U%.4f} {V:V%.4f} F391 ; move to target
2024-01-18 14:59:49.706 GcodeAsyncDriver DEBUG: [Duet3D:COM3] commandQueue offer >> M400 ; Wait for moves to complete before returning
2024-01-18 14:59:49.706 GcodeAsyncDriver$WriterThread TRACE: [Duet3D:COM3] >> M204S257.7G1X73.8436Y465.6715{U:U%.4f}{V:V%.4f}F391
2024-01-18 14:59:49.706 GcodeAsyncDriver DEBUG: [Duet3D:COM3] commandQueue offer >> M114 ; get position
2024-01-18 14:59:49.706 GcodeAsyncDriver$WriterThread TRACE: [Duet3D:COM3] >> M400
2024-01-18 14:59:49.707 GcodeAsyncDriver$WriterThread TRACE: [Duet3D:COM3] >> M114
2024-01-18 14:59:49.707 GcodeDriver$ReaderThread TRACE: [Duet3D:COM3] << ok
2024-01-18 14:59:49.708 GcodeDriver$ReaderThread TRACE: [Duet3D:COM3] << ok
2024-01-18 14:59:51.824 GcodeDriver$ReaderThread TRACE: [Duet3D:COM3] << ok
2024-01-18 14:59:51.825 GcodeDriver$ReaderThread TRACE: [Duet3D:COM3] << X:73.844 Y:465.672 Z:80.000 U:-15.875 V:0.000 E:0.000 Count 5907 37254 6400 -127 0 Machine 73.844 465.672 80.000 -15.875 0.000 Bed comp 0.000
2024-01-18 14:59:51.825 GcodeDriver TRACE: Position report: X:73.844 Y:465.672 Z:80.000 U:-15.875 V:0.000 E:0.000 Count 5907 37254 6400 -127 0 Machine 73.844 465.672 80.000 -15.875 0.000 Bed comp 0.000
2024-01-18 14:59:51.825 GcodeDriver$ReaderThread TRACE: [Duet3D:COM3] << ok
2024-01-18 14:59:51.825 GcodeDriver TRACE: Duet3D got lastReportedLocation (X:73.844000, Y:465.672000, Z:80.000000, A:-15.875000, B:0.000000)
2024-01-18 14:59:51.825 GcodeAsyncDriver TRACE: Duet3D confirmation complete.
2024-01-18 14:59:51.825 AbstractMotionPlanner DEBUG: Reported location changes current location from (X:73.830015, Y:465.635297, Z:80.000000, A:90.000000, B:0.000000) to (X:73.830408, Y:465.635804, Z:80.000000, A:-15.875000, B:0.000000)
2024-01-18 14:59:51.828 ReferenceActuator DEBUG: PRE_FEED.actuate(1.0)
2024-01-18 14:59:51.829 GcodeDriver DEBUG: [Feeder:COM5] >> M600 N1, 50
2024-01-18 14:59:51.829 GcodeDriver WARNING: Feeder configuration error: COMMAND_CONFIRM_REGEX missing. Not waiting for confirmation.
2024-01-18 14:59:51.830 AbstractNozzle TRACE: Set rotation mode offset: none.
2024-01-18 14:59:51.830 AbstractNozzle TRACE: Set rotation mode offset: none.
2024-01-18 14:59:51.831 ReferenceHead DEBUG: H1.moveToSafeZ(1.0)
2024-01-18 14:59:51.831 AbstractHeadMountable DEBUG: N1.moveToSafeZ(1.0)
2024-01-18 14:59:51.831 AbstractHeadMountable DEBUG: N2.moveToSafeZ(1.0)
2024-01-18 14:59:51.831 AbstractHeadMountable DEBUG: Top.moveToSafeZ(1.0)
2024-01-18 14:59:51.832 AbstractHeadMountable DEBUG: N1.moveTo((53.275000, 390.417000, 1.000000, 90.000000 mm), 1.0)
2024-01-18 14:59:51.832 ReferenceNozzle TRACE: N1.toHeadLocation((53.380130, 390.435337, 1.000000, 90.000000 mm), ...) runout compensation (-0.105130, -0.018337, 0.000000, 0.000000 mm)
2024-01-18 14:59:51.833 AbstractHeadMountable DEBUG: N1.moveTo((53.275000, 390.417000, -38.900000, 90.000000 mm), 1.0)
2024-01-18 14:59:51.833 ReferenceNozzle TRACE: N1.toHeadLocation((53.380130, 390.435337, -38.900000, 90.000000 mm), ...) runout compensation (-0.105130, -0.018337, 0.000000, 0.000000 mm)
2024-01-18 14:59:51.834 ReferenceNozzle DEBUG: N1.pick()
2024-01-18 14:59:51.834 Scripting TRACE: Scripting.on Nozzle.BeforePick
2024-01-18 14:59:51.834 GcodeDriver$ReaderThread TRACE: [Feeder:COM5] << M600 N1
2024-01-18 14:59:51.835 GcodeAsyncDriver DEBUG: [Duet3D:COM3] commandQueue offer >> M204 S103.9 G1 X73.8700 Y465.7953 Z50.0000 {U:U%.4f} {V:V%.4f} F6417 ; move to target
2024-01-18 14:59:51.836 GcodeAsyncDriver$WriterThread TRACE: [Duet3D:COM3] >> M204S103.9G1X73.87Y465.7953Z50{U:U%.4f}{V:V%.4f}F6417
2024-01-18 14:59:51.836 GcodeAsyncDriver DEBUG: [Duet3D:COM3] commandQueue offer >> M204 S257.7 G1 X73.8300 Y465.6353 {U:U%.4f} {V:V%.4f} F391 ; move to target
2024-01-18 14:59:51.836 GcodeAsyncDriver$WriterThread TRACE: [Duet3D:COM3] >> M204S257.7G1X73.83Y465.6353{U:U%.4f}{V:V%.4f}F391
2024-01-18 14:59:51.836 GcodeAsyncDriver DEBUG: [Duet3D:COM3] commandQueue offer >> M204 S1500.0 G1 Z10.1000 {U:U%.4f} {V:V%.4f} F14679 ; move to target
2024-01-18 14:59:51.836 GcodeAsyncDriver DEBUG: [Duet3D:COM3] commandQueue offer >> M400 ; Wait for moves to complete before returning
2024-01-18 14:59:51.836 GcodeAsyncDriver$WriterThread TRACE: [Duet3D:COM3] >> M204S1500G1Z10.1{U:U%.4f}{V:V%.4f}F14679
2024-01-18 14:59:51.836 GcodeAsyncDriver DEBUG: [Duet3D:COM3] commandQueue offer >> M114 ; get position
2024-01-18 14:59:51.836 GcodeAsyncDriver$WriterThread TRACE: [Duet3D:COM3] >> M400
2024-01-18 14:59:51.837 GcodeAsyncDriver$WriterThread TRACE: [Duet3D:COM3] >> M114
2024-01-18 14:59:51.837 GcodeDriver$ReaderThread TRACE: [Duet3D:COM3] << ok
2024-01-18 14:59:51.837 GcodeDriver$ReaderThread TRACE: [Duet3D:COM3] << ok
2024-01-18 14:59:51.838 GcodeDriver$ReaderThread TRACE: [Duet3D:COM3] << ok
2024-01-18 14:59:52.076 GcodeDriver$ReaderThread TRACE: [Feeder:COM5] << ok, advancing cycle completed
2024-01-18 14:59:53.516 GcodeDriver$ReaderThread TRACE: [Duet3D:COM3] << ok
2024-01-18 14:59:53.518 GcodeDriver$ReaderThread TRACE: [Duet3D:COM3] << X:73.830 Y:465.635 Z:10.100 U:-15.875 V:0.000 E:0.000 Count 5906 37251 808 -127 0 Machine 73.830 465.635 10.100 -15.875 0.000 Bed comp 0.000
2024-01-18 14:59:53.518 GcodeDriver TRACE: Position report: X:73.830 Y:465.635 Z:10.100 U:-15.875 V:0.000 E:0.000 Count 5906 37251 808 -127 0 Machine 73.830 465.635 10.100 -15.875 0.000 Bed comp 0.000
2024-01-18 14:59:53.518 GcodeDriver$ReaderThread TRACE: [Duet3D:COM3] << ok
2024-01-18 14:59:53.518 GcodeDriver TRACE: Duet3D got lastReportedLocation (X:73.830000, Y:465.635000, Z:10.100000, A:-15.875000, B:0.000000)
2024-01-18 14:59:53.518 GcodeAsyncDriver TRACE: Duet3D confirmation complete.
2024-01-18 14:59:53.518 AbstractMotionPlanner DEBUG: Reported location changes current location from (X:73.830015, Y:465.635297, Z:10.100000, A:90.000000, B:0.000000) to (X:73.830000, Y:465.635000, Z:10.100000, A:-15.875000, B:0.000000)
2024-01-18 14:59:53.518 ReferenceActuator DEBUG: PUMP.actuate(true)
2024-01-18 14:59:53.519 GcodeAsyncDriver DEBUG: [Duet3D:COM3] commandQueue offer >> M42 P9 S1
2024-01-18 14:59:53.519 AbstractHead TRACE: H1 dwell for pump on 0ms
2024-01-18 14:59:53.519 GcodeAsyncDriver$WriterThread TRACE: [Duet3D:COM3] >> M42P9S1
2024-01-18 14:59:53.519 ReferenceActuator DEBUG: PUMP.actuate(true)
2024-01-18 14:59:53.519 GcodeAsyncDriver DEBUG: [Duet3D:COM3] commandQueue offer >> M42 P9 S1
2024-01-18 14:59:53.520 ReferenceNozzle TRACE: N1 dwell for pick vacuum 50ms
2024-01-18 14:59:53.520 GcodeAsyncDriver$WriterThread TRACE: [Duet3D:COM3] >> M42P9S1
2024-01-18 14:59:53.520 GcodeDriver$ReaderThread TRACE: [Duet3D:COM3] << ok
2024-01-18 14:59:53.521 GcodeDriver$ReaderThread TRACE: [Duet3D:COM3] << ok
2024-01-18 14:59:53.571 Scripting TRACE: Scripting.on Nozzle.AfterPick
2024-01-18 14:59:53.571 AbstractHeadMountable DEBUG: N1.moveToSafeZ(1.0)
2024-01-18 14:59:53.571 AbstractHeadMountable DEBUG: N1.moveTo((53.391235, 390.541176, 1.500000, -15.875000 mm), 1.0)
2024-01-18 14:59:53.572 ReferenceNozzle TRACE: N1.toHeadLocation((53.380115, 390.435040, 1.500000, -15.875000 mm), ...) runout compensation (0.011120, 0.106136, 0.000000, 0.000000 mm)
2024-01-18 14:59:53.573 GcodeAsyncDriver DEBUG: [Duet3D:COM3] commandQueue offer >> M204 S1500.0 G1 Z50.5000 {U:U%.4f} {V:V%.4f} F14770 ; move to target
2024-01-18 14:59:53.573 GcodeAsyncDriver DEBUG: [Duet3D:COM3] commandQueue offer >> M400 ; Wait for moves to complete before returning
2024-01-18 14:59:53.573 GcodeAsyncDriver$WriterThread TRACE: [Duet3D:COM3] >> M204S1500G1Z50.5{U:U%.4f}{V:V%.4f}F14770
2024-01-18 14:59:53.574 GcodeAsyncDriver DEBUG: [Duet3D:COM3] commandQueue offer >> M114 ; get position
2024-01-18 14:59:53.574 GcodeAsyncDriver$WriterThread TRACE: [Duet3D:COM3] >> M400
2024-01-18 14:59:53.574 GcodeAsyncDriver$WriterThread TRACE: [Duet3D:COM3] >> M114
2024-01-18 14:59:53.575 GcodeDriver$ReaderThread TRACE: [Duet3D:COM3] << ok
2024-01-18 14:59:54.203 GcodeDriver$ReaderThread TRACE: [Duet3D:COM3] << ok
2024-01-18 14:59:54.205 GcodeDriver$ReaderThread TRACE: [Duet3D:COM3] << X:73.830 Y:465.635 Z:50.500 U:-15.875 V:0.000 E:0.000 Count 5906 37251 4040 -127 0 Machine 73.830 465.635 50.500 -15.875 0.000 Bed comp 0.000
2024-01-18 14:59:54.205 GcodeDriver TRACE: Position report: X:73.830 Y:465.635 Z:50.500 U:-15.875 V:0.000 E:0.000 Count 5906 37251 4040 -127 0 Machine 73.830 465.635 50.500 -15.875 0.000 Bed comp 0.000
2024-01-18 14:59:54.205 GcodeDriver$ReaderThread TRACE: [Duet3D:COM3] << ok
2024-01-18 14:59:54.205 GcodeDriver TRACE: Duet3D got lastReportedLocation (X:73.830000, Y:465.635000, Z:50.500000, A:-15.875000, B:0.000000)
2024-01-18 14:59:54.207 GcodeAsyncDriver TRACE: Duet3D confirmation complete.
2024-01-18 14:59:54.208 ReferenceActuator DEBUG: POST_FEED.actuate(1.0)
2024-01-18 14:59:54.208 GcodeDriver DEBUG: [Feeder:COM5] >> M601 N1, 50
2024-01-18 14:59:54.209 GcodeDriver WARNING: Feeder configuration error: COMMAND_CONFIRM_REGEX missing. Not waiting for confirmation.
2024-01-18 14:59:54.209 Scripting TRACE: Scripting.on Vision.PartAlignment.Before
2024-01-18 14:59:54.213 ReferenceHead DEBUG: H1.moveToSafeZ(1.0)
2024-01-18 14:59:54.213 AbstractHeadMountable DEBUG: N1.moveToSafeZ(1.0)
2024-01-18 14:59:54.214 GcodeDriver$ReaderThread TRACE: [Feeder:COM5] << M601 N1
2024-01-18 14:59:54.214 AbstractHeadMountable DEBUG: N2.moveToSafeZ(1.0)
2024-01-18 14:59:54.214 AbstractHeadMountable DEBUG: Top.moveToSafeZ(1.0)
2024-01-18 14:59:54.214 AbstractHeadMountable DEBUG: N1.moveTo((12014.927713, 16075.342354, 59.055118, 0.000000 mil), 1.0)
2024-01-18 14:59:54.215 ReferenceNozzle TRACE: N1.toHeadLocation((12015.649629, 16071.203368, 59.055118, 0.000000 mil), ...) runout compensation (-0.018337, 0.105130, 0.000000, 0.000000 mm)
2024-01-18 14:59:54.216 AbstractHeadMountable DEBUG: N1.moveTo((12014.927713, 16075.342354, -793.438320, 0.000000 mil), 1.0)
2024-01-18 14:59:54.216 ReferenceNozzle TRACE: N1.toHeadLocation((12015.649629, 16071.203368, -793.438320, 0.000000 mil), ...) runout compensation (-0.018337, 0.105130, 0.000000, 0.000000 mm)
2024-01-18 14:59:54.217 GcodeDriver$ReaderThread TRACE: [Feeder:COM5] << ok feeder postPickRetract done if needed
2024-01-18 14:59:54.218 CvPipeline DEBUG: Stage "pDetail" throws java.lang.Exception: Stage "filterContours" not found
2024-01-18 14:59:54.220 GcodeAsyncDriver DEBUG: [Duet3D:COM3] commandQueue offer >> M204 S1593.1 G1 X325.6210 Y483.2847 {U:U%.4f} {V:V%.4f} F38085 ; move to target
2024-01-18 14:59:54.220 GcodeAsyncDriver$WriterThread TRACE: [Duet3D:COM3] >> M204S1593.1G1X325.621Y483.2847{U:U%.4f}{V:V%.4f}F38085
2024-01-18 14:59:54.220 GcodeAsyncDriver DEBUG: [Duet3D:COM3] commandQueue offer >> M204 S257.7 G1 X325.6610 Y483.4447 {U:U%.4f} {V:V%.4f} F391 ; move to target
2024-01-18 14:59:54.221 GcodeAsyncDriver$WriterThread TRACE: [Duet3D:COM3] >> M204S257.7G1X325.661Y483.4447{U:U%.4f}{V:V%.4f}F391
2024-01-18 14:59:54.221 GcodeDriver$ReaderThread TRACE: [Duet3D:COM3] << ok
2024-01-18 14:59:54.221 GcodeAsyncDriver DEBUG: [Duet3D:COM3] commandQueue offer >> M204 S1500.0 G1 Z28.8467 {U:U%.4f} {V:V%.4f} F10813 ; move to target
2024-01-18 14:59:54.221 GcodeAsyncDriver$WriterThread TRACE: [Duet3D:COM3] >> M204S1500G1Z28.8467{U:U%.4f}{V:V%.4f}F10813
2024-01-18 14:59:54.221 GcodeAsyncDriver DEBUG: [Duet3D:COM3] commandQueue offer >> M400 ; Wait for moves to complete before returning
2024-01-18 14:59:54.221 GcodeAsyncDriver DEBUG: [Duet3D:COM3] commandQueue offer >> M114 ; get position
2024-01-18 14:59:54.222 GcodeAsyncDriver$WriterThread TRACE: [Duet3D:COM3] >> M400
2024-01-18 14:59:54.222 GcodeAsyncDriver$WriterThread TRACE: [Duet3D:COM3] >> M114
2024-01-18 14:59:54.222 GcodeDriver$ReaderThread TRACE: [Duet3D:COM3] << ok
2024-01-18 14:59:54.223 GcodeDriver$ReaderThread TRACE: [Duet3D:COM3] << ok
2024-01-18 14:59:55.529 GcodeDriver$ReaderThread TRACE: [Duet3D:COM3] << ok
2024-01-18 14:59:55.531 GcodeDriver$ReaderThread TRACE: [Duet3D:COM3] << X:325.661 Y:483.445 Z:28.847 U:-15.875 V:0.000 E:0.000 Count 26053 38676 2308 -127 0 Machine 325.661 483.445 28.847 -15.875 0.000 Bed comp 0.000
2024-01-18 14:59:55.531 GcodeDriver TRACE: Position report: X:325.661 Y:483.445 Z:28.847 U:-15.875 V:0.000 E:0.000 Count 26053 38676 2308 -127 0 Machine 325.661 483.445 28.847 -15.875 0.000 Bed comp 0.000
2024-01-18 14:59:55.531 GcodeDriver$ReaderThread TRACE: [Duet3D:COM3] << ok
2024-01-18 14:59:55.531 GcodeDriver TRACE: Duet3D got lastReportedLocation (X:325.661000, Y:483.445000, Z:28.847000, A:-15.875000, B:0.000000)
2024-01-18 14:59:55.531 GcodeAsyncDriver TRACE: Duet3D confirmation complete.
2024-01-18 14:59:55.531 AbstractMotionPlanner DEBUG: Reported location changes current location from (X:325.647386, Y:483.408526, Z:28.846667, A:0.000000, B:0.000000) to (X:325.647408, Y:483.408804, Z:28.847000, A:-15.875000, B:0.000000)
2024-01-18 14:59:55.532 ReferenceActuator DEBUG: DnLight.actuate(false)
2024-01-18 14:59:55.532 GcodeAsyncDriver DEBUG: [Duet3D:COM3] commandQueue offer >> M42 P7 S0
2024-01-18 14:59:55.532 GcodeAsyncDriver$WriterThread TRACE: [Duet3D:COM3] >> M42P7S0
2024-01-18 14:59:55.532 ReferenceActuator DEBUG: UpLight.actuate(true)
2024-01-18 14:59:55.532 GcodeAsyncDriver DEBUG: [Duet3D:COM3] commandQueue offer >> M42 P8 S1;
2024-01-18 14:59:55.533 Scripting TRACE: Scripting.on Camera.BeforeSettle
2024-01-18 14:59:55.533 GcodeAsyncDriver$WriterThread TRACE: [Duet3D:COM3] >> M42P8S1
2024-01-18 14:59:55.533 GcodeDriver$ReaderThread TRACE: [Duet3D:COM3] << ok
2024-01-18 14:59:55.533 AbstractSettlingCamera TRACE: UpCamera settling fixed time 100ms
2024-01-18 14:59:55.534 GcodeDriver$ReaderThread TRACE: [Duet3D:COM3] << ok
2024-01-18 14:59:55.635 Scripting TRACE: Scripting.on Camera.BeforeCapture
2024-01-18 14:59:55.648 Scripting TRACE: Scripting.on Camera.AfterCapture
2024-01-18 14:59:55.649 Scripting TRACE: Scripting.on Camera.AfterSettle
2024-01-18 14:59:56.599 ReferenceBottomVision DEBUG: Alignment result: R0402-1K
2024-01-18 14:59:56.599 ReferenceBottomVision DEBUG: Bottom vision part R0402-1K result rect { {608.6729209516869, 372.19605393117376} 14x6 * -27.903141024128455 }
2024-01-18 14:59:56.607 ReferenceBottomVision DEBUG: Alignment result: R0402-1K | X:-0.649 Y:-0.399 C:27.903 Δ:0.762
2024-01-18 14:59:56.612 AbstractNozzle TRACE: Set rotation mode offset: 27.903141024128455°.
2024-01-18 14:59:56.612 Scripting TRACE: Scripting.on Vision.PartAlignment.After
2024-01-18 14:59:56.612 ReferencePnpJobProcessor$Align DEBUG: Align id R0402-1K, name null, heightUnits Millimeters, height 0.500000, packageId (R0402) with N1 N1, offsets offset ( location: (-0.649376, -0.399445, 0.000000, 0.000000 mm) pre-rotatedfalse)
2024-01-18 14:59:56.613 Scripting TRACE: Scripting.on Job.Placement.BeforeAssembly
2024-01-18 14:59:56.613 ReferenceHead DEBUG: H1.moveToSafeZ(1.0)
2024-01-18 14:59:56.614 AbstractHeadMountable DEBUG: N1.moveToSafeZ(1.0)
2024-01-18 14:59:56.614 AbstractHeadMountable DEBUG: N1.moveTo((305.208643, 408.314980, 1.500000, 12.028141 mm), 1.0)
2024-01-18 14:59:56.614 ReferenceNozzle TRACE: N1.toHeadLocation((305.208643, 408.314980, 1.500000, -15.875000 mm), ...) rotation mode offset 27.903141024128455
2024-01-18 14:59:56.614 ReferenceNozzle TRACE: N1.toHeadLocation((305.197523, 408.208844, 1.500000, -15.875000 mm), ...) runout compensation (0.011120, 0.106136, 0.000000, 0.000000 mm)
2024-01-18 14:59:56.615 AbstractHeadMountable DEBUG: N2.moveToSafeZ(1.0)
2024-01-18 14:59:56.616 AbstractHeadMountable DEBUG: Top.moveToSafeZ(1.0)
2024-01-18 14:59:56.616 AbstractHeadMountable DEBUG: N1.moveTo((384.160283, 176.791767, 1.500000, 0.719946 mm), 1.0)
2024-01-18 14:59:56.616 ReferenceNozzle TRACE: N1.toHeadLocation((384.160283, 176.791767, 1.500000, -27.183195 mm), ...) rotation mode offset 27.903141024128455
2024-01-18 14:59:56.616 ReferenceNozzle TRACE: N1.toHeadLocation((384.128567, 176.689872, 1.500000, -27.183195 mm), ...) runout compensation (0.031716, 0.101896, 0.000000, 0.000000 mm)
2024-01-18 14:59:56.617 AbstractHeadMountable DEBUG: N1.moveTo((384.160283, 176.791767, -39.500000, 0.719946 mm), 1.0)
2024-01-18 14:59:56.617 ReferenceNozzle TRACE: N1.toHeadLocation((384.160283, 176.791767, -39.500000, -27.183195 mm), ...) rotation mode offset 27.903141024128455
2024-01-18 14:59:56.617 ReferenceNozzle TRACE: N1.toHeadLocation((384.128567, 176.689872, -39.500000, -27.183195 mm), ...) runout compensation (0.031716, 0.101896, 0.000000, 0.000000 mm)
2024-01-18 14:59:56.618 ReferenceNozzle DEBUG: N1.place()
2024-01-18 14:59:56.618 Scripting TRACE: Scripting.on Nozzle.BeforePlace
2024-01-18 14:59:56.620 GcodeAsyncDriver DEBUG: [Duet3D:COM3] commandQueue offer >> M204 S1500.0 G1 Z50.5000 {U:U%.4f} {V:V%.4f} F10813 ; move to target
2024-01-18 14:59:56.620 GcodeAsyncDriver$WriterThread TRACE: [Duet3D:COM3] >> M204S1500G1Z50.5{U:U%.4f}{V:V%.4f}F10813
2024-01-18 14:59:56.621 GcodeAsyncDriver DEBUG: [Duet3D:COM3] commandQueue offer >> M204 S2164.2 G1 X404.5520 Y252.0498 {U:U%.4f} {V:V%.4f} F43667 ; move to target
2024-01-18 14:59:56.621 GcodeAsyncDriver$WriterThread TRACE: [Duet3D:COM3] >> M204S2164.2G1X404.552Y252.0498{U:U%.4f}{V:V%.4f}F43667
2024-01-18 14:59:56.621 GcodeAsyncDriver DEBUG: [Duet3D:COM3] commandQueue offer >> M204 S257.7 G1 X404.5920 Y251.8898 {U:U%.4f} {V:V%.4f} F391 ; move to target
2024-01-18 14:59:56.622 GcodeDriver$ReaderThread TRACE: [Duet3D:COM3] << ok
2024-01-18 14:59:56.622 GcodeAsyncDriver$WriterThread TRACE: [Duet3D:COM3] >> M204S257.7G1X404.592Y251.8898{U:U%.4f}{V:V%.4f}F391
2024-01-18 14:59:56.622 GcodeAsyncDriver DEBUG: [Duet3D:COM3] commandQueue offer >> M204 S1500.0 G1 Z9.5000 {U:U%.4f} {V:V%.4f} F14880 ; move to target
2024-01-18 14:59:56.622 GcodeAsyncDriver DEBUG: [Duet3D:COM3] commandQueue offer >> M400 ; Wait for moves to complete before returning
2024-01-18 14:59:56.622 GcodeAsyncDriver$WriterThread TRACE: [Duet3D:COM3] >> M204S1500G1Z9.5{U:U%.4f}{V:V%.4f}F14880
2024-01-18 14:59:56.622 GcodeAsyncDriver DEBUG: [Duet3D:COM3] commandQueue offer >> M114 ; get position
2024-01-18 14:59:56.622 GcodeAsyncDriver$WriterThread TRACE: [Duet3D:COM3] >> M400
2024-01-18 14:59:56.622 GcodeAsyncDriver$WriterThread TRACE: [Duet3D:COM3] >> M114
2024-01-18 14:59:56.623 GcodeDriver$ReaderThread TRACE: [Duet3D:COM3] << ok
2024-01-18 14:59:56.624 GcodeDriver$ReaderThread TRACE: [Duet3D:COM3] << ok
2024-01-18 14:59:56.625 GcodeDriver$ReaderThread TRACE: [Duet3D:COM3] << ok
2024-01-18 14:59:58.381 GcodeDriver$ReaderThread TRACE: [Duet3D:COM3] << ok
2024-01-18 14:59:58.381 GcodeDriver$ReaderThread TRACE: [Duet3D:COM3] << X:404.592 Y:251.890 Z:9.500 U:-15.875 V:0.000 E:0.000 Count 32367 20151 760 -127 0 Machine 404.592 251.890 9.500 -15.875 0.000 Bed comp 0.000
2024-01-18 14:59:58.381 GcodeDriver TRACE: Position report: X:404.592 Y:251.890 Z:9.500 U:-15.875 V:0.000 E:0.000 Count 32367 20151 760 -127 0 Machine 404.592 251.890 9.500 -15.875 0.000 Bed comp 0.000
2024-01-18 14:59:58.382 GcodeDriver$ReaderThread TRACE: [Duet3D:COM3] << ok
2024-01-18 14:59:58.382 GcodeDriver TRACE: Duet3D got lastReportedLocation (X:404.592000, Y:251.890000, Z:9.500000, A:-15.875000, B:0.000000)
2024-01-18 14:59:58.382 GcodeAsyncDriver TRACE: Duet3D confirmation complete.
2024-01-18 14:59:58.382 AbstractMotionPlanner DEBUG: Reported location changes current location from (X:404.578452, Y:251.889832, Z:9.500000, A:-27.183195, B:0.000000) to (X:404.578408, Y:251.890000, Z:9.500000, A:-15.875000, B:0.000000)
2024-01-18 14:59:58.382 ReferenceActuator DEBUG: PUMP.actuate(false)
2024-01-18 14:59:58.382 GcodeAsyncDriver DEBUG: [Duet3D:COM3] commandQueue offer >> M42 P9 S0
2024-01-18 14:59:58.382 GcodeAsyncDriver$WriterThread TRACE: [Duet3D:COM3] >> M42P9S0
2024-01-18 14:59:58.383 ReferenceActuator DEBUG: PUMP.actuate(false)
2024-01-18 14:59:58.383 GcodeAsyncDriver DEBUG: [Duet3D:COM3] commandQueue offer >> M42 P9 S0
2024-01-18 14:59:58.383 ReferenceNozzle TRACE: N1 dwell for place vacuum dissipation 50ms
2024-01-18 14:59:58.383 GcodeAsyncDriver$WriterThread TRACE: [Duet3D:COM3] >> M42P9S0
2024-01-18 14:59:58.383 GcodeDriver$ReaderThread TRACE: [Duet3D:COM3] << ok
2024-01-18 14:59:58.384 GcodeDriver$ReaderThread TRACE: [Duet3D:COM3] << ok
2024-01-18 14:59:58.433 AbstractNozzle TRACE: Set rotation mode offset: none.
2024-01-18 14:59:58.433 Scripting TRACE: Scripting.on Nozzle.AfterPlace
2024-01-18 14:59:58.434 AbstractHeadMountable DEBUG: N1.moveToSafeZ(1.0)
2024-01-18 14:59:58.434 AbstractHeadMountable DEBUG: N1.moveTo((384.139643, 176.796176, 1.000000, -15.875000 mm), 1.0)
2024-01-18 14:59:58.434 ReferenceNozzle TRACE: N1.toHeadLocation((384.128523, 176.690040, 1.000000, -15.875000 mm), ...) runout compensation (0.011120, 0.106136, 0.000000, 0.000000 mm)
2024-01-18 14:59:58.435 Scripting TRACE: Scripting.on Job.Placement.Complete
2024-01-18 14:59:58.435 ReferenceHead DEBUG: H1.moveToSafeZ(1.0)
2024-01-18 14:59:58.435 AbstractHeadMountable DEBUG: N1.moveToSafeZ(1.0)
2024-01-18 14:59:58.435 AbstractHeadMountable DEBUG: N2.moveToSafeZ(1.0)
2024-01-18 14:59:58.435 AbstractHeadMountable DEBUG: Top.moveToSafeZ(1.0)
2024-01-18 14:59:58.437 ReferenceHead DEBUG: H1.moveToSafeZ(1.0)
2024-01-18 14:59:58.437 AbstractHeadMountable DEBUG: N1.moveToSafeZ(1.0)
2024-01-18 14:59:58.437 AbstractHeadMountable DEBUG: N2.moveToSafeZ(1.0)
2024-01-18 14:59:58.437 AbstractHeadMountable DEBUG: Top.moveToSafeZ(1.0)
2024-01-18 14:59:58.438 ReferenceHead DEBUG: H1.moveToSafeZ(1.0)
2024-01-18 14:59:58.438 AbstractHeadMountable DEBUG: N1.moveToSafeZ(1.0)
2024-01-18 14:59:58.438 AbstractHeadMountable DEBUG: N2.moveToSafeZ(1.0)
2024-01-18 14:59:58.438 AbstractHeadMountable DEBUG: Top.moveToSafeZ(1.0)
2024-01-18 14:59:58.438 AbstractHeadMountable DEBUG: Top.moveTo((0.000000, 0.000000, NaN, NaN mm), 1.0)
2024-01-18 14:59:58.440 ReferencePnpJobProcessor$Finish INFO: Job finished 1 parts in 8.7 sec. This is 411.9 CPH
2024-01-18 14:59:58.440 Scripting TRACE: Scripting.on Job.Finished
2024-01-18 14:59:58.463 GcodeAsyncDriver DEBUG: [Duet3D:COM3] commandQueue offer >> M204 S1500.0 G1 Z50.0000 {U:U%.4f} {V:V%.4f} F14789 ; move to target
2024-01-18 14:59:58.464 GcodeAsyncDriver$WriterThread TRACE: [Duet3D:COM3] >> M204S1500G1Z50{U:U%.4f}{V:V%.4f}F14789
2024-01-18 14:59:58.464 GcodeAsyncDriver DEBUG: [Duet3D:COM3] commandQueue offer >> M204 S3533.4 G1 X0.0400 Y0.1600 {U:U%.4f} {V:V%.4f} F77851 ; move to target
2024-01-18 14:59:58.464 GcodeAsyncDriver$WriterThread TRACE: [Duet3D:COM3] >> M204S3533.4G1X0.04Y0.16{U:U%.4f}{V:V%.4f}F77851
2024-01-18 14:59:58.464 GcodeAsyncDriver DEBUG: [Duet3D:COM3] commandQueue offer >> M204 S257.7 G1 X0.0000 Y0.0000 {U:U%.4f} {V:V%.4f} F391 ; move to target
2024-01-18 14:59:58.464 GcodeAsyncDriver$WriterThread TRACE: [Duet3D:COM3] >> M204S257.7G1X0Y0{U:U%.4f}{V:V%.4f}F391
2024-01-18 14:59:58.464 AbstractMachine TRACE: Machine entering idle state.
2024-01-18 14:59:58.465 GcodeDriver$ReaderThread TRACE: [Duet3D:COM3] << ok
2024-01-18 14:59:58.466 GcodeDriver$ReaderThread TRACE: [Duet3D:COM3] << ok
2024-01-18 14:59:58.466 GcodeDriver$ReaderThread TRACE: [Duet3D:COM3] << ok