Sync Feeder controller

[geo0rpo]

Hello friends!

Referring to previous thread:

https://groups.google.com/g/openpnp/c/LGACfo77sW8/m/VO5yKcFJAQAJ

I need to sync the machine to my custom auto feeder board which is connected to a second USB com port.

I have set my feeder controller as GcodeAsycDriver to:

* listen for M400 and FEED1, FEED2, FEED3, FEED4 etc commands.

* On each FEEDx command the controller responds ^ok.* immediately then starts feeding operation.

* On each M400 command the controller responds ^ok.* immediately if there is no Feed operation active or pending.

* If a feed operation is still in progress while receiving M400, the controller responds  ^ok.* only after the feed operation is  finished.

(All the above tested outside openpnp with realterm)

In the actuator I have enabled Machine coordination before and after.

Please also see below:

But when I press the "perform a feed and pick" button, the feeder starts feeding, the machines starts moving to the feeder position but goes down on Z before the feeding is complete.

I must say that with the M400 placed in the "Move_To_Complete_Command" I never see the M400 in log. M400 is not sent! 

Maybe the actuation is not considered a "move" so the "Move_To_Complete_Command" never fires.

If I put it under the Actuate Double command like this:

FEED{IntegerValue}

M400

then I see the M400 in the log but again the machine is not in sync with the feeder operation.

Log with M400 in Move_To_Complete_Command :

2021-12-30 23:57:35.768 GcodeAsyncDriver DEBUG: serial://COM5 commandQueue.offer(FEED1, 5000)...
2021-12-30 23:57:35.768 GcodeDriver TRACE: [serial://COM5] confirmed FEED1
2021-12-30 23:57:35.768 GcodeAsyncDriver$WriterThread TRACE: [serial://COM5] >> FEED1
2021-12-30 23:57:35.777 GcodeDriver$ReaderThread TRACE: [serial://COM5] << ok

M400 was never sent!

Log with:

FEED{IntegerValue}

M400

2021-12-31 00:35:00.512 GcodeAsyncDriver DEBUG: serial://COM5 commandQueue.offer(FEED1, 5000)...
2021-12-31 00:35:00.512 GcodeAsyncDriver DEBUG: serial://COM5 commandQueue.offer(M400, 5000)...
2021-12-31 00:35:00.512 GcodeDriver TRACE: [serial://COM5] confirmed M400
2021-12-31 00:35:00.512 GcodeAsyncDriver$WriterThread TRACE: [serial://COM5] >> FEED1
2021-12-31 00:35:00.573 GcodeDriver$ReaderThread TRACE: [serial://COM5] << ok
2021-12-31 00:35:00.573 GcodeDriver TRACE: [serial://COM5] confirmed FEED1
2021-12-31 00:35:00.573 GcodeAsyncDriver$WriterThread TRACE: [serial://COM5] >> M400
2021-12-31 00:35:01.309 GcodeDriver$ReaderThread TRACE: [serial://COM5] << ok

Is M400 supposed to tell openpnp to wait for OK?

Thanks for the support.

[mark maker]

Hi geo0rpo

OpenPnP usually only sends the MOVE_TO_COMPLETE_COMMAND (M400) when it knows that a motion is pending. As the feeder driver has no axes assigned, this is never the case.

But you can enable the After Actuation option here:

https://github.com/openpnp/openpnp/wiki/Motion-Planner#actuator-machine-coordination

However, this wait will immediately happen when the feed operation takes place. An "smart" overlap of the  X/Y-motion with the feed actuation, but not on the Z-motion, is not currently possible.

_Mark

--
You received this message because you are subscribed to the Google Groups "OpenPnP" group.
To unsubscribe from this group and stop receiving emails from it, send an email to openpnp+u...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/openpnp/7bea555b-0da3-4d8b-8ef7-e2ffee8e1635n%40googlegroups.com.

[geo0rpo]

Hello Mark and best wishes for the new year.

I wish health for you and your family and patience to support us :)

I have enabled After Actuation and yes the feeding motion overlaps in time with the X/Y motion but it does not wait for the feeder controller to reply OK before going down on Z.

So I will change back to GcodeDrive (not Async) and just wait for the feeding operation to complete before picking.

I was left with the impression that if I implement M400 correctly in my controller, this could work.

Once again thanks!

[mark maker]

No, wait. This should not happen.  Can you provide a log?

_Mark

To view this discussion on the web visit https://groups.google.com/d/msgid/openpnp/d23437bb-56ba-4a95-ae9a-c978b418666en%40googlegroups.com.

[geo0rpo]

please see the log in my first post.

Can you explain about M400? does it do anything to openpnp? 

What would the proper sequence be? 

You received this message because you are subscribed to a topic in the Google Groups "OpenPnP" group.
To unsubscribe from this topic, visit https://groups.google.com/d/topic/openpnp/2jx2SCEEQtk/unsubscribe.
To unsubscribe from this group and all its topics, send an email to openpnp+u...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/openpnp/39e1d048-5d9e-bd29-532e-8efd26561e7f%40makr.zone.

[mark maker]

> Can you explain about M400? does it do anything to openpnp?

MOVE_TO_COMPLETE_COMMAND (M400) is only sent when OpenPnP thinks it is needed. If there was no motion, it things it is not needed.

But when you enable After Actuation, then the MOVE_TO_COMPLETE_COMMAND is forced and OpenPnP will wait until the "ok" for that comes back.

I need a new log, with the enabled After Actuation.

_Mark

To view this discussion on the web visit https://groups.google.com/d/msgid/openpnp/CANKvoS1k99crGY-ArNkAh1-spR4qP6DBo5n0ChL-TQEUnJ2AqA%40mail.gmail.com.

[geo0rpo]

OK, I am setting up to prepare a new log.

Please confirm the following:

I have set my feeder controller as GcodeAsycDriver to:

* listen for M400 and FEED1, FEED2, FEED3, FEED4 etc commands.

* On each FEEDx command the controller responds  "ok\n"  immediately and then starts feeding operation which takes about 2" to complete because of slow 4RPM motor pulling the tape cover. No further response is sent after the feeding is complete!

* On each M400 command the controller responds   "ok\n"   immediately if there is no Feed operation in progress.

* If a feed operation is still in progress while receiving M400, the controller responds   "ok\n"   only after the feed operation is  finished.

Please confirm the above is as it should be.

In the Gcode settings of the AsyncFeeder driver I will put  "FEED{IntegerValue}" in the Actuate Double command and M400 in the MOVE_TO_COMPLETE_COMMAND. 

In the default gcode settings I only add the ^ok.* command confirm regex.

Also in the actuator I will enable both  Before and After Actuation.

Please confirm the above is as it should be.

[mark maker]

First: confirmed.

Second: confirmed. You might disable the Before Actuation, to gain a bit of speed, if a move is still pending at that time.

_Mark

To view this discussion on the web visit https://groups.google.com/d/msgid/openpnp/4d62dfba-a367-4c41-89b8-eba7933cd3bcn%40googlegroups.com.

[geo0rpo]

OK, here is the video: https://youtu.be/PIjp-nciES0

Each time I click "perform a feed and pick" from the "FEEDERS" tab.

com3 is smoothieboard

com5 my feeder controller

Here is the log:

2022-01-02 20:08:41.143 AbstractHeadMountable DEBUG: N1.moveToSafeZ(0.71)
2022-01-02 20:08:41.144 ReferenceActuator DEBUG: FEEDER.actuate(1.0)
2022-01-02 20:08:41.144 GcodeAsyncDriver DEBUG: serial://COM5 commandQueue.offer(FEED1, 5000)...
2022-01-02 20:08:41.144 GcodeDriver TRACE: [serial://COM5] confirmed FEED1
2022-01-02 20:08:41.144 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M400, 28169)...
2022-01-02 20:08:41.144 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M114 ; get position, -1)...
2022-01-02 20:08:41.144 GcodeAsyncDriver$WriterThread TRACE: [serial://COM5] >> FEED1
2022-01-02 20:08:41.144 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M400
2022-01-02 20:08:41.145 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M114
2022-01-02 20:08:41.145 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-02 20:08:41.146 GcodeDriver$ReaderThread TRACE: [serial://COM5] << ok
2022-01-02 20:08:41.146 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok C: X:310.6229 Y:69.7151 Z:0.0000 A:0.0000 B:180.0000
2022-01-02 20:08:41.146 GcodeDriver TRACE: Position report: ok C: X:310.6229 Y:69.7151 Z:0.0000 A:0.0000 B:180.0000
2022-01-02 20:08:41.146 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:310.622900, Y:69.715100, Z:0.000000, Rot_N1:0.000000, Rot_N2:180.000000)
2022-01-02 20:08:41.147 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete.
2022-01-02 20:08:41.147 ReferenceBottomVision DEBUG: C1206-1K5.canHandle(true) => {}
2022-01-02 20:08:41.147 ReferenceHead DEBUG: H1.moveToSafeZ(0.71)
2022-01-02 20:08:41.148 AbstractHeadMountable DEBUG: N1.moveToSafeZ(0.71)
2022-01-02 20:08:41.148 AbstractHeadMountable DEBUG: N2.moveToSafeZ(0.71)
2022-01-02 20:08:41.149 AbstractHeadMountable DEBUG: HeadCamera.moveToSafeZ(0.71)
2022-01-02 20:08:41.149 AbstractHeadMountable DEBUG: N1.moveTo((50.290000, 50.003000, 0.000000, 0.000000 mm), 0.71)
2022-01-02 20:08:41.149 ReferenceNozzle TRACE: N1.toHeadLocation((50.267895, 50.093258, 0.000000, 0.000000 mm), ...) runout compensation (0.022105, -0.090258, 0.000000, 0.000000 mm)
2022-01-02 20:08:41.150 AbstractHeadMountable DEBUG: N1.moveTo((50.290000, 50.003000, -12.500000, 0.000000 mm), 0.71)
2022-01-02 20:08:41.150 ReferenceNozzle TRACE: N1.toHeadLocation((50.267895, 50.093258, -12.500000, 0.000000 mm), ...) runout compensation (0.022105, -0.090258, 0.000000, 0.000000 mm)
2022-01-02 20:08:41.152 ReferenceNozzle DEBUG: N1.pick()
2022-01-02 20:08:41.152 Scripting TRACE: Scripting.on Nozzle.BeforePick
2022-01-02 20:08:41.152 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M204 S2613.63 G1 X100.5689 Y12.0881    F25768.18 ; move to target, 20000)...
2022-01-02 20:08:41.152 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M204S2613.63G1X100.5689Y12.0881F25768.18
2022-01-02 20:08:41.152 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M204 S2772.55 G1   Z-12.5000   F11169.81 ; move to target, 20000)...
2022-01-02 20:08:41.153 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M400, 28169)...
2022-01-02 20:08:41.153 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M114 ; get position, -1)...
2022-01-02 20:08:41.153 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M204S2772.55G1Z-12.5F11169.81
2022-01-02 20:08:41.154 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-02 20:08:41.154 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M400
2022-01-02 20:08:41.155 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M114
2022-01-02 20:08:41.155 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-02 20:08:41.959 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-02 20:08:41.960 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok C: X:100.5689 Y:12.0881 Z:-12.5000 A:0.0000 B:180.0000
2022-01-02 20:08:41.961 GcodeDriver TRACE: Position report: ok C: X:100.5689 Y:12.0881 Z:-12.5000 A:0.0000 B:180.0000
2022-01-02 20:08:41.961 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:100.568900, Y:12.088100, Z:-12.500000, Rot_N1:0.000000, Rot_N2:180.000000)
2022-01-02 20:08:41.961 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete.
2022-01-02 20:08:41.961 ReferenceActuator DEBUG: DummyPump.actuate(true)
2022-01-02 20:08:41.962 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M400, 28169)...
2022-01-02 20:08:41.962 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M114 ; get position, -1)...
2022-01-02 20:08:41.962 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M400
2022-01-02 20:08:41.962 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-02 20:08:41.962 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M114
2022-01-02 20:08:41.964 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok C: X:100.5689 Y:12.0881 Z:-12.5000 A:0.0000 B:180.0000
2022-01-02 20:08:41.964 GcodeDriver TRACE: Position report: ok C: X:100.5689 Y:12.0881 Z:-12.5000 A:0.0000 B:180.0000
2022-01-02 20:08:41.964 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:100.568900, Y:12.088100, Z:-12.500000, Rot_N1:0.000000, Rot_N2:180.000000)
2022-01-02 20:08:41.964 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete.
2022-01-02 20:08:41.965 ReferenceActuator DEBUG: Pump1.actuate(true)
2022-01-02 20:08:41.965 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M800, 20000)...
2022-01-02 20:08:41.966 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M400, 28169)...
2022-01-02 20:08:41.966 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M114 ; get position, -1)...
2022-01-02 20:08:41.966 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M800
2022-01-02 20:08:41.966 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-02 20:08:41.966 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M400
2022-01-02 20:08:41.966 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M114
2022-01-02 20:08:41.967 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-02 20:08:41.968 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok C: X:100.5689 Y:12.0881 Z:-12.5000 A:0.0000 B:180.0000
2022-01-02 20:08:41.968 GcodeDriver TRACE: Position report: ok C: X:100.5689 Y:12.0881 Z:-12.5000 A:0.0000 B:180.0000
2022-01-02 20:08:41.968 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:100.568900, Y:12.088100, Z:-12.500000, Rot_N1:0.000000, Rot_N2:180.000000)
2022-01-02 20:08:41.968 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete.
2022-01-02 20:08:42.469 Scripting TRACE: Scripting.on Nozzle.AfterPick
2022-01-02 20:08:42.469 AbstractHeadMountable DEBUG: N1.moveToSafeZ(0.71)
2022-01-02 20:08:42.470 AbstractHeadMountable DEBUG: N1.moveTo((50.290000, 50.003000, 0.000000, 0.000000 mm), 0.71)
2022-01-02 20:08:42.470 ReferenceNozzle TRACE: N1.toHeadLocation((50.267895, 50.093258, 0.000000, 0.000000 mm), ...) runout compensation (0.022105, -0.090258, 0.000000, 0.000000 mm)
2022-01-02 20:08:42.472 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M204 S2772.55 G1   Z0.0000   F11169.81 ; move to target, 20000)...
2022-01-02 20:08:42.473 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M204S2772.55G1Z0F11169.81
2022-01-02 20:08:42.474 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-02 20:08:44.245 AbstractHeadMountable DEBUG: N1.moveToSafeZ(0.71)
2022-01-02 20:08:44.245 ReferenceActuator DEBUG: FEEDER.actuate(1.0)
2022-01-02 20:08:44.246 GcodeAsyncDriver DEBUG: serial://COM5 commandQueue.offer(FEED1, 5000)...
2022-01-02 20:08:44.246 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M400, 28169)...
2022-01-02 20:08:44.246 GcodeDriver TRACE: [serial://COM5] confirmed FEED1
2022-01-02 20:08:44.246 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M114 ; get position, -1)...
2022-01-02 20:08:44.246 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M400
2022-01-02 20:08:44.246 GcodeAsyncDriver$WriterThread TRACE: [serial://COM5] >> FEED1
2022-01-02 20:08:44.246 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M114
2022-01-02 20:08:44.246 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-02 20:08:44.248 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok C: X:100.5689 Y:12.0881 Z:0.0000 A:0.0000 B:180.0000
2022-01-02 20:08:44.248 GcodeDriver TRACE: Position report: ok C: X:100.5689 Y:12.0881 Z:0.0000 A:0.0000 B:180.0000
2022-01-02 20:08:44.248 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:100.568900, Y:12.088100, Z:0.000000, Rot_N1:0.000000, Rot_N2:180.000000)
2022-01-02 20:08:44.248 GcodeDriver$ReaderThread TRACE: [serial://COM5] << ok
2022-01-02 20:08:44.248 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete.
2022-01-02 20:08:44.249 ReferenceBottomVision DEBUG: C1206-1K5.canHandle(true) => {}
2022-01-02 20:08:44.251 AbstractHeadMountable DEBUG: N1.moveTo((50.290000, 50.003000, -12.500000, 0.000000 mm), 0.71)
2022-01-02 20:08:44.251 ReferenceNozzle TRACE: N1.toHeadLocation((50.267895, 50.093258, -12.500000, 0.000000 mm), ...) runout compensation (0.022105, -0.090258, 0.000000, 0.000000 mm)
2022-01-02 20:08:44.252 ReferenceNozzle DEBUG: N1.pick()
2022-01-02 20:08:44.252 Scripting TRACE: Scripting.on Nozzle.BeforePick
2022-01-02 20:08:44.253 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M204 S2772.55 G1   Z-12.5000   F11169.81 ; move to target, 20000)...
2022-01-02 20:08:44.253 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M400, 28169)...
2022-01-02 20:08:44.253 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M204S2772.55G1Z-12.5F11169.81
2022-01-02 20:08:44.254 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M114 ; get position, -1)...
2022-01-02 20:08:44.254 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M400
2022-01-02 20:08:44.254 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M114
2022-01-02 20:08:44.254 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-02 20:08:44.388 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-02 20:08:44.391 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok C: X:100.5689 Y:12.0881 Z:-12.5000 A:0.0000 B:180.0000
2022-01-02 20:08:44.391 GcodeDriver TRACE: Position report: ok C: X:100.5689 Y:12.0881 Z:-12.5000 A:0.0000 B:180.0000
2022-01-02 20:08:44.392 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:100.568900, Y:12.088100, Z:-12.500000, Rot_N1:0.000000, Rot_N2:180.000000)
2022-01-02 20:08:44.392 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete.
2022-01-02 20:08:44.393 ReferenceActuator DEBUG: DummyPump.actuate(true)
2022-01-02 20:08:44.393 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M400, 28169)...
2022-01-02 20:08:44.394 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M114 ; get position, -1)...
2022-01-02 20:08:44.394 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M400
2022-01-02 20:08:44.394 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M114
2022-01-02 20:08:44.394 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-02 20:08:44.396 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok C: X:100.5689 Y:12.0881 Z:-12.5000 A:0.0000 B:180.0000
2022-01-02 20:08:44.396 GcodeDriver TRACE: Position report: ok C: X:100.5689 Y:12.0881 Z:-12.5000 A:0.0000 B:180.0000
2022-01-02 20:08:44.396 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:100.568900, Y:12.088100, Z:-12.500000, Rot_N1:0.000000, Rot_N2:180.000000)
2022-01-02 20:08:44.396 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete.
2022-01-02 20:08:44.397 ReferenceActuator DEBUG: Pump1.actuate(true)
2022-01-02 20:08:44.397 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M800, 20000)...
2022-01-02 20:08:44.398 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M400, 28169)...
2022-01-02 20:08:44.398 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M114 ; get position, -1)...
2022-01-02 20:08:44.398 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M800
2022-01-02 20:08:44.398 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-02 20:08:44.398 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M400
2022-01-02 20:08:44.398 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-02 20:08:44.398 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M114
2022-01-02 20:08:44.400 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok C: X:100.5689 Y:12.0881 Z:-12.5000 A:0.0000 B:180.0000
2022-01-02 20:08:44.400 GcodeDriver TRACE: Position report: ok C: X:100.5689 Y:12.0881 Z:-12.5000 A:0.0000 B:180.0000
2022-01-02 20:08:44.400 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:100.568900, Y:12.088100, Z:-12.500000, Rot_N1:0.000000, Rot_N2:180.000000)
2022-01-02 20:08:44.400 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete.
2022-01-02 20:08:44.902 Scripting TRACE: Scripting.on Nozzle.AfterPick
2022-01-02 20:08:44.902 AbstractHeadMountable DEBUG: N1.moveToSafeZ(0.71)
2022-01-02 20:08:44.903 AbstractHeadMountable DEBUG: N1.moveTo((50.290000, 50.003000, 0.000000, 0.000000 mm), 0.71)
2022-01-02 20:08:44.903 ReferenceNozzle TRACE: N1.toHeadLocation((50.267895, 50.093258, 0.000000, 0.000000 mm), ...) runout compensation (0.022105, -0.090258, 0.000000, 0.000000 mm)
2022-01-02 20:08:44.905 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M204 S2772.55 G1   Z0.0000   F11169.81 ; move to target, 20000)...
2022-01-02 20:08:44.905 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M204S2772.55G1Z0F11169.81
2022-01-02 20:08:44.906 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-02 20:08:46.887 AbstractHeadMountable DEBUG: N1.moveToSafeZ(0.71)
2022-01-02 20:08:46.888 ReferenceActuator DEBUG: FEEDER.actuate(1.0)
2022-01-02 20:08:46.888 GcodeAsyncDriver DEBUG: serial://COM5 commandQueue.offer(FEED1, 5000)...
2022-01-02 20:08:46.888 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M400, 28169)...
2022-01-02 20:08:46.888 GcodeDriver TRACE: [serial://COM5] confirmed FEED1
2022-01-02 20:08:46.888 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M114 ; get position, -1)...
2022-01-02 20:08:46.888 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M400
2022-01-02 20:08:46.888 GcodeAsyncDriver$WriterThread TRACE: [serial://COM5] >> FEED1
2022-01-02 20:08:46.888 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M114
2022-01-02 20:08:46.889 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-02 20:08:46.890 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok C: X:100.5689 Y:12.0881 Z:0.0000 A:0.0000 B:180.0000
2022-01-02 20:08:46.890 GcodeDriver TRACE: Position report: ok C: X:100.5689 Y:12.0881 Z:0.0000 A:0.0000 B:180.0000
2022-01-02 20:08:46.890 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:100.568900, Y:12.088100, Z:0.000000, Rot_N1:0.000000, Rot_N2:180.000000)
2022-01-02 20:08:46.891 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete.
2022-01-02 20:08:46.891 ReferenceBottomVision DEBUG: C1206-1K5.canHandle(true) => {}
2022-01-02 20:08:46.892 AbstractHeadMountable DEBUG: N1.moveTo((50.290000, 50.003000, -12.500000, 0.000000 mm), 0.71)
2022-01-02 20:08:46.892 ReferenceNozzle TRACE: N1.toHeadLocation((50.267895, 50.093258, -12.500000, 0.000000 mm), ...) runout compensation (0.022105, -0.090258, 0.000000, 0.000000 mm)
2022-01-02 20:08:46.893 ReferenceNozzle DEBUG: N1.pick()
2022-01-02 20:08:46.894 Scripting TRACE: Scripting.on Nozzle.BeforePick
2022-01-02 20:08:46.894 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M204 S2772.55 G1   Z-12.5000   F11169.81 ; move to target, 20000)...
2022-01-02 20:08:46.894 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M204S2772.55G1Z-12.5F11169.81
2022-01-02 20:08:46.894 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M400, 28169)...
2022-01-02 20:08:46.895 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M400
2022-01-02 20:08:46.895 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M114 ; get position, -1)...
2022-01-02 20:08:46.895 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M114
2022-01-02 20:08:46.895 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-02 20:08:46.903 GcodeDriver$ReaderThread TRACE: [serial://COM5] << ok
2022-01-02 20:08:47.029 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-02 20:08:47.031 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok C: X:100.5689 Y:12.0881 Z:-12.5000 A:0.0000 B:180.0000
2022-01-02 20:08:47.031 GcodeDriver TRACE: Position report: ok C: X:100.5689 Y:12.0881 Z:-12.5000 A:0.0000 B:180.0000
2022-01-02 20:08:47.031 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:100.568900, Y:12.088100, Z:-12.500000, Rot_N1:0.000000, Rot_N2:180.000000)
2022-01-02 20:08:47.031 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete.
2022-01-02 20:08:47.031 ReferenceActuator DEBUG: DummyPump.actuate(true)
2022-01-02 20:08:47.031 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M400, 28169)...
2022-01-02 20:08:47.031 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M114 ; get position, -1)...
2022-01-02 20:08:47.033 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M400
2022-01-02 20:08:47.033 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M114
2022-01-02 20:08:47.033 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-02 20:08:47.034 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok C: X:100.5689 Y:12.0881 Z:-12.5000 A:0.0000 B:180.0000
2022-01-02 20:08:47.034 GcodeDriver TRACE: Position report: ok C: X:100.5689 Y:12.0881 Z:-12.5000 A:0.0000 B:180.0000
2022-01-02 20:08:47.035 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:100.568900, Y:12.088100, Z:-12.500000, Rot_N1:0.000000, Rot_N2:180.000000)
2022-01-02 20:08:47.035 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete.
2022-01-02 20:08:47.036 ReferenceActuator DEBUG: Pump1.actuate(true)
2022-01-02 20:08:47.036 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M800, 20000)...
2022-01-02 20:08:47.036 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M400, 28169)...
2022-01-02 20:08:47.036 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M114 ; get position, -1)...
2022-01-02 20:08:47.036 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M800
2022-01-02 20:08:47.037 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-02 20:08:47.038 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M400
2022-01-02 20:08:47.038 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-02 20:08:47.038 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M114
2022-01-02 20:08:47.039 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok C: X:100.5689 Y:12.0881 Z:-12.5000 A:0.0000 B:180.0000
2022-01-02 20:08:47.039 GcodeDriver TRACE: Position report: ok C: X:100.5689 Y:12.0881 Z:-12.5000 A:0.0000 B:180.0000
2022-01-02 20:08:47.040 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:100.568900, Y:12.088100, Z:-12.500000, Rot_N1:0.000000, Rot_N2:180.000000)
2022-01-02 20:08:47.040 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete.
2022-01-02 20:08:47.540 Scripting TRACE: Scripting.on Nozzle.AfterPick
2022-01-02 20:08:47.540 AbstractHeadMountable DEBUG: N1.moveToSafeZ(0.71)
2022-01-02 20:08:47.540 AbstractHeadMountable DEBUG: N1.moveTo((50.290000, 50.003000, 0.000000, 0.000000 mm), 0.71)
2022-01-02 20:08:47.541 ReferenceNozzle TRACE: N1.toHeadLocation((50.267895, 50.093258, 0.000000, 0.000000 mm), ...) runout compensation (0.022105, -0.090258, 0.000000, 0.000000 mm)
2022-01-02 20:08:47.542 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M204 S2772.55 G1   Z0.0000   F11169.81 ; move to target, 20000)...
2022-01-02 20:08:47.543 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M204S2772.55G1Z0F11169.81
2022-01-02 20:08:47.543 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-02 20:08:49.243 AbstractHeadMountable DEBUG: N1.moveToSafeZ(0.71)
2022-01-02 20:08:49.243 ReferenceActuator DEBUG: FEEDER.actuate(1.0)
2022-01-02 20:08:49.243 GcodeAsyncDriver DEBUG: serial://COM5 commandQueue.offer(FEED1, 5000)...
2022-01-02 20:08:49.243 GcodeDriver TRACE: [serial://COM5] confirmed FEED1
2022-01-02 20:08:49.243 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M400, 28169)...
2022-01-02 20:08:49.244 GcodeAsyncDriver$WriterThread TRACE: [serial://COM5] >> FEED1
2022-01-02 20:08:49.244 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M114 ; get position, -1)...
2022-01-02 20:08:49.244 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M400
2022-01-02 20:08:49.244 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M114
2022-01-02 20:08:49.244 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-02 20:08:49.246 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok C: X:100.5689 Y:12.0881 Z:0.0000 A:0.0000 B:180.0000
2022-01-02 20:08:49.246 GcodeDriver TRACE: Position report: ok C: X:100.5689 Y:12.0881 Z:0.0000 A:0.0000 B:180.0000
2022-01-02 20:08:49.246 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:100.568900, Y:12.088100, Z:0.000000, Rot_N1:0.000000, Rot_N2:180.000000)
2022-01-02 20:08:49.246 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete.
2022-01-02 20:08:49.247 ReferenceBottomVision DEBUG: C1206-1K5.canHandle(true) => {}
2022-01-02 20:08:49.247 AbstractHeadMountable DEBUG: N1.moveTo((50.290000, 50.003000, -12.500000, 0.000000 mm), 0.71)
2022-01-02 20:08:49.247 ReferenceNozzle TRACE: N1.toHeadLocation((50.267895, 50.093258, -12.500000, 0.000000 mm), ...) runout compensation (0.022105, -0.090258, 0.000000, 0.000000 mm)
2022-01-02 20:08:49.248 ReferenceNozzle DEBUG: N1.pick()
2022-01-02 20:08:49.248 Scripting TRACE: Scripting.on Nozzle.BeforePick
2022-01-02 20:08:49.249 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M204 S2772.55 G1   Z-12.5000   F11169.81 ; move to target, 20000)...
2022-01-02 20:08:49.249 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M400, 28169)...
2022-01-02 20:08:49.249 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M114 ; get position, -1)...
2022-01-02 20:08:49.249 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M204S2772.55G1Z-12.5F11169.81
2022-01-02 20:08:49.249 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M400
2022-01-02 20:08:49.250 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M114
2022-01-02 20:08:49.250 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-02 20:08:49.254 GcodeDriver$ReaderThread TRACE: [serial://COM5] << ok
2022-01-02 20:08:49.383 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-02 20:08:49.385 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok C: X:100.5689 Y:12.0881 Z:-12.5000 A:0.0000 B:180.0000
2022-01-02 20:08:49.385 GcodeDriver TRACE: Position report: ok C: X:100.5689 Y:12.0881 Z:-12.5000 A:0.0000 B:180.0000
2022-01-02 20:08:49.385 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:100.568900, Y:12.088100, Z:-12.500000, Rot_N1:0.000000, Rot_N2:180.000000)
2022-01-02 20:08:49.385 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete.
2022-01-02 20:08:49.386 ReferenceActuator DEBUG: DummyPump.actuate(true)
2022-01-02 20:08:49.386 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M400, 28169)...
2022-01-02 20:08:49.386 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M114 ; get position, -1)...
2022-01-02 20:08:49.386 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M400
2022-01-02 20:08:49.387 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-02 20:08:49.387 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M114
2022-01-02 20:08:49.388 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok C: X:100.5689 Y:12.0881 Z:-12.5000 A:0.0000 B:180.0000
2022-01-02 20:08:49.388 GcodeDriver TRACE: Position report: ok C: X:100.5689 Y:12.0881 Z:-12.5000 A:0.0000 B:180.0000
2022-01-02 20:08:49.388 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:100.568900, Y:12.088100, Z:-12.500000, Rot_N1:0.000000, Rot_N2:180.000000)
2022-01-02 20:08:49.388 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete.
2022-01-02 20:08:49.389 ReferenceActuator DEBUG: Pump1.actuate(true)
2022-01-02 20:08:49.390 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M800, 20000)...
2022-01-02 20:08:49.390 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M400, 28169)...
2022-01-02 20:08:49.390 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M114 ; get position, -1)...
2022-01-02 20:08:49.390 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M800
2022-01-02 20:08:49.390 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-02 20:08:49.390 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M400
2022-01-02 20:08:49.391 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-02 20:08:49.391 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M114
2022-01-02 20:08:49.392 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok C: X:100.5689 Y:12.0881 Z:-12.5000 A:0.0000 B:180.0000
2022-01-02 20:08:49.393 GcodeDriver TRACE: Position report: ok C: X:100.5689 Y:12.0881 Z:-12.5000 A:0.0000 B:180.0000
2022-01-02 20:08:49.393 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:100.568900, Y:12.088100, Z:-12.500000, Rot_N1:0.000000, Rot_N2:180.000000)
2022-01-02 20:08:49.393 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete.
2022-01-02 20:08:49.893 Scripting TRACE: Scripting.on Nozzle.AfterPick
2022-01-02 20:08:49.893 AbstractHeadMountable DEBUG: N1.moveToSafeZ(0.71)
2022-01-02 20:08:49.894 AbstractHeadMountable DEBUG: N1.moveTo((50.290000, 50.003000, 0.000000, 0.000000 mm), 0.71)
2022-01-02 20:08:49.894 ReferenceNozzle TRACE: N1.toHeadLocation((50.267895, 50.093258, 0.000000, 0.000000 mm), ...) runout compensation (0.022105, -0.090258, 0.000000, 0.000000 mm)
2022-01-02 20:08:49.896 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M204 S2772.55 G1   Z0.0000   F11169.81 ; move to target, 20000)...
2022-01-02 20:08:49.896 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M204S2772.55G1Z0F11169.81
2022-01-02 20:08:49.897 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-02 20:09:01.345 Scripting TRACE: Scripting.on Job.BeforeDiscard
2022-01-02 20:09:01.346 ReferenceHead DEBUG: H1.moveToSafeZ(0.71)
2022-01-02 20:09:01.346 AbstractHeadMountable DEBUG: N1.moveToSafeZ(0.71)
2022-01-02 20:09:01.346 AbstractHeadMountable DEBUG: N2.moveToSafeZ(0.71)
2022-01-02 20:09:01.347 AbstractHeadMountable DEBUG: HeadCamera.moveToSafeZ(0.71)
2022-01-02 20:09:01.347 AbstractHeadMountable DEBUG: N1.moveTo((260.344000, 107.835000, 0.000000, 0.000000 mm), 0.71)
2022-01-02 20:09:01.348 ReferenceNozzle TRACE: N1.toHeadLocation((260.321895, 107.925258, 0.000000, 0.000000 mm), ...) runout compensation (0.022105, -0.090258, 0.000000, 0.000000 mm)
2022-01-02 20:09:01.349 AbstractHeadMountable DEBUG: N1.moveTo((260.344000, 107.835000, 0.000000, 0.000000 mm), 0.71)
2022-01-02 20:09:01.349 ReferenceNozzle TRACE: N1.toHeadLocation((260.321895, 107.925258, 0.000000, 0.000000 mm), ...) runout compensation (0.022105, -0.090258, 0.000000, 0.000000 mm)
2022-01-02 20:09:01.353 ReferenceNozzle DEBUG: N1.place()
2022-01-02 20:09:01.353 Scripting TRACE: Scripting.on Nozzle.BeforePlace
2022-01-02 20:09:01.354 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M204 S2613.63 G1 X310.6229 Y69.7151    F25768.18 ; move to target, 20000)...
2022-01-02 20:09:01.355 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M400, 28169)...
2022-01-02 20:09:01.355 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M114 ; get position, -1)...
2022-01-02 20:09:01.355 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M204S2613.63G1X310.6229Y69.7151F25768.18
2022-01-02 20:09:01.355 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M400
2022-01-02 20:09:01.356 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-02 20:09:01.356 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M114
2022-01-02 20:09:02.028 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-02 20:09:02.028 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok C: X:310.6229 Y:69.7151 Z:0.0000 A:0.0000 B:180.0000
2022-01-02 20:09:02.028 GcodeDriver TRACE: Position report: ok C: X:310.6229 Y:69.7151 Z:0.0000 A:0.0000 B:180.0000
2022-01-02 20:09:02.029 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:310.622900, Y:69.715100, Z:0.000000, Rot_N1:0.000000, Rot_N2:180.000000)
2022-01-02 20:09:02.029 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete.
2022-01-02 20:09:02.029 ReferenceActuator DEBUG: Pump1.actuate(false)
2022-01-02 20:09:02.029 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M801, 20000)...
2022-01-02 20:09:02.029 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M400, 28169)...
2022-01-02 20:09:02.030 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M114 ; get position, -1)...
2022-01-02 20:09:02.030 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M801
2022-01-02 20:09:02.030 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-02 20:09:02.030 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M400
2022-01-02 20:09:02.031 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-02 20:09:02.031 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M114
2022-01-02 20:09:02.032 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok C: X:310.6229 Y:69.7151 Z:0.0000 A:0.0000 B:180.0000
2022-01-02 20:09:02.032 GcodeDriver TRACE: Position report: ok C: X:310.6229 Y:69.7151 Z:0.0000 A:0.0000 B:180.0000
2022-01-02 20:09:02.033 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:310.622900, Y:69.715100, Z:0.000000, Rot_N1:0.000000, Rot_N2:180.000000)
2022-01-02 20:09:02.033 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete.
2022-01-02 20:09:02.034 ReferenceActuator DEBUG: DummyPump.actuate(false)
2022-01-02 20:09:02.034 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M400, 28169)...
2022-01-02 20:09:02.034 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M114 ; get position, -1)...
2022-01-02 20:09:02.034 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M400
2022-01-02 20:09:02.035 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-02 20:09:02.035 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M114
2022-01-02 20:09:02.036 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok C: X:310.6229 Y:69.7151 Z:0.0000 A:0.0000 B:180.0000
2022-01-02 20:09:02.037 GcodeDriver TRACE: Position report: ok C: X:310.6229 Y:69.7151 Z:0.0000 A:0.0000 B:180.0000
2022-01-02 20:09:02.037 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:310.622900, Y:69.715100, Z:0.000000, Rot_N1:0.000000, Rot_N2:180.000000)
2022-01-02 20:09:02.037 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete.
2022-01-02 20:09:02.108 Scripting TRACE: Scripting.on Nozzle.AfterPlace
2022-01-02 20:09:02.108 AbstractHeadMountable DEBUG: N1.moveToSafeZ(0.71)
2022-01-02 20:09:02.109 Scripting TRACE: Scripting.on Job.AfterDiscard

[geo0rpo]

...and machine.xml

[geo0rpo]

Also I am not sure about the following:

2022-01-02 21:27:15.877 GcodeAsyncDriver DEBUG: serial://COM5 commandQueue.offer(M400, 5000)...
2022-01-02 21:27:15.878 GcodeDriver TRACE: [serial://COM5] confirmed M400
2022-01-02 21:27:15.878 GcodeAsyncDriver$WriterThread TRACE: [serial://COM5] >> M400
2022-01-02 21:27:15.889 GcodeDriver$ReaderThread TRACE: [serial://COM5] << ok

First the command is confirmed before it was even sent? Is it from a previous OK response?

For the above I send M400 from the console.

[geo0rpo]

In any case, since my controller responds OK immediately after receiving the FEED command

 and since openpnp never "asks" my controller if it finished or is still busy by sending M400 they cannot be in sync.

[tonyl...@gmail.com]

I don't see a  MOVE_TO_COMPLETE_COMMAND defined for your feeder controller - it only has a  COMMAND_CONFIRM_REGEX:

<driver class="org.openpnp.machine.reference.driver.GcodeAsyncDriver" id="DRV16c6859654d9b0c8" name="FEEDERASYNC" motion-control-type="ToolpathFeedRate" communications="serial" connection-keep-alive="false" sync-initial-location="false" units="Millimeters" max-feed-rate="1000" backlash-offset-x="-1.0" backlash-offset-y="-1.0" backlash-offset-z="0.0" backlash-offset-r="0.0" non-squareness-factor="0.0" backlash-feed-rate-factor="0.1" timeout-milliseconds="5000" connect-wait-time-milliseconds="3000" visual-homing-enabled="true" backslash-escaped-characters-enabled="false" remove-comments="false" compress-gcode="false" logging-gcode="false" supporting-pre-move="false" using-letter-variables="true" infinity-timeout-milliseconds="60000" writer-polling-interval="100" writer-queue-timeout="60000" max-commands-queued="1000" confirmation-flow-control="true" reported-location-confirmation="false" interpolation-max-steps="32" interpolation-jerk-steps="4" interpolation-time-step="0.001" interpolation-min-step="16">

<serial line-ending-type="LF" port-name="COM5" baud="115200" flow-control="Off" data-bits="Eight" stop-bits="One" parity="None" set-dtr="false" set-rts="false" name="SerialPortCommunications"/>

<tcp line-ending-type="LF" ip-address="127.0.0.1" port="23" name="TcpCommunications"/>

<simulated line-ending-type="LF"/>

<homing-fiducial-location units="Millimeters" x="0.0" y="0.0" z="0.0" rotation="0.0"/>

<command type="COMMAND_CONFIRM_REGEX">

<text>

<![CDATA[ ^ok.* ]]>

</text>

</command>

<junction-deviation value="0.02" units="Millimeters"/>

</driver>

[geo0rpo]

You are right. Sorry I uploaded wrong file.

[tonyl...@gmail.com]

What about the log you posted? I doesn't ever show an M400 being sent to com5.  BTW - best if you can attach the entire log file rather pasting portions.

[geo0rpo]

yes, that's part of my question. I do not see M400 sent to COM5 but as Mark said openpnp decides to send or not. 

To view this discussion on the web visit https://groups.google.com/d/msgid/openpnp/9e84259d-606d-42fe-a164-81c34cd5f882n%40googlegroups.com.

[tonyl...@gmail.com]

So this little snippet you posted does show it being sent:

Also I am not sure about the following:

2022-01-02 21:27:15.877 GcodeAsyncDriver DEBUG: serial://COM5 commandQueue.offer(M400, 5000)...
2022-01-02 21:27:15.878 GcodeDriver TRACE: [serial://COM5] confirmed M400
2022-01-02 21:27:15.878 GcodeAsyncDriver$WriterThread TRACE: [serial://COM5] >> M400
2022-01-02 21:27:15.889 GcodeDriver$ReaderThread TRACE: [serial://COM5] << ok

but that snippet is not from the same log you posted above.

[geo0rpo]

Yes it does show it being sent but I wrote it manually in the console tab just to check that my controller responds.

[mark maker]

Thanks for documenting it. Clearly, the M400 is never sent to the feeder controller. And in-deed I found a bug on the planner level: a driver without any axes does not enforce waiting.

I'll fix it.

_Mark

To view this discussion on the web visit https://groups.google.com/d/msgid/openpnp/58b0366f-e249-4f6b-9c34-c36f4752ac65n%40googlegroups.com.

[geo0rpo]

Hi Mark,

Many thanks for your effort!

When you fix it please update this thread if possible.

Thanks again!!!

[mark maker]

Hi geo0rpo,

It should now be fixed in both regular and testing versions. Please upgrade and confirm.

Thanks again for helping root this out.

_Mark

To view this discussion on the web visit https://groups.google.com/d/msgid/openpnp/806beb6c-8276-4bc0-911c-ad96f89f0db9n%40googlegroups.com.

[mark maker]

Sorry, mail "escaped" too early, please wait ~10 minutes until the new version is deployed.

To view this discussion on the web visit https://groups.google.com/d/msgid/openpnp/8a19a943-260b-6698-dfe3-bbe87a495d08%40makr.zone.

[geo0rpo]

Great! I will test as soon as I finish work after about 5 hours.

Please tell me where can I see the revision history so each time I know what the changes are?

The "show comments" does not say much.

[mark maker]

This is for the regular version of OpenPnP 2.0 (develop branch):

https://github.com/openpnp/openpnp/pulls?q=is%3Apr+is%3Amerged+sort%3Aupdated-desc+base%3Adevelop

This is for the testing version (test branch):

https://github.com/openpnp/openpnp/pulls?q=is%3Apr+is%3Amerged+sort%3Aupdated-desc+base%3Atest

Sometimes you see  "Merge Develop into Test" or (rarely) vice versa and from then on the history obviously becomes a mixture of the two:

https://github.com/openpnp/openpnp/pulls?q=is%3Apr+is%3Amerged+sort%3Aupdated-desc+

_Mark

To view this discussion on the web visit https://groups.google.com/d/msgid/openpnp/775faff9-1ba1-4831-a7a1-998cfea85d5en%40googlegroups.com.

[geo0rpo]

I just tried with 2022-01-03_13-02-54.fc5da2e/ but I had the same behaviour.

I will now try 2022-01-03_10-18-17.6e61dcd/

[mark maker]

Both should fix this.

Please send machine.xml and full log.

_Mark

To view this discussion on the web visit https://groups.google.com/d/msgid/openpnp/de5b5bb5-ab2c-4fa3-8162-d462dcc7cd5cn%40googlegroups.com.

[geo0rpo]

No change, same behaviour like my previous video.

2022-01-03 17:43:33.772 AbstractHeadMountable DEBUG: N1.moveToSafeZ(0.71)
2022-01-03 17:43:33.773 ReferenceActuator DEBUG: FEEDER.actuate(1.0)
2022-01-03 17:43:33.773 GcodeAsyncDriver DEBUG: serial://COM5 commandQueue.offer(FEED1, 5000)...
2022-01-03 17:43:33.774 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M400, 28169)...
2022-01-03 17:43:33.774 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M114 ; get position, -1)...
2022-01-03 17:43:33.774 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M400
2022-01-03 17:43:33.774 GcodeAsyncDriver$WriterThread TRACE: [serial://COM5] >> FEED1
2022-01-03 17:43:33.774 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M114
2022-01-03 17:43:33.775 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:43:33.776 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok C: X:193.5529 Y:98.8127 Z:0.0000 A:180.0000 B:180.0000
2022-01-03 17:43:33.776 GcodeDriver TRACE: Position report: ok C: X:193.5529 Y:98.8127 Z:0.0000 A:180.0000 B:180.0000
2022-01-03 17:43:33.776 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:193.552900, Y:98.812700, Z:0.000000, Rot_N1:180.000000, Rot_N2:180.000000)
2022-01-03 17:43:33.776 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete.
2022-01-03 17:43:33.787 GcodeDriver$ReaderThread TRACE: [serial://COM5] << ok
2022-01-03 17:43:33.788 GcodeDriver TRACE: [serial://COM5] confirmed FEED1
2022-01-03 17:43:33.788 GcodeAsyncDriver TRACE: FEEDERASYNC confirmation complete.
2022-01-03 17:43:33.790 ReferenceHead DEBUG: H1.moveToSafeZ(0.71)
2022-01-03 17:43:33.790 AbstractHeadMountable DEBUG: N1.moveToSafeZ(0.71)
2022-01-03 17:43:33.790 AbstractHeadMountable DEBUG: N2.moveToSafeZ(0.71)
2022-01-03 17:43:33.791 AbstractHeadMountable DEBUG: HeadCamera.moveToSafeZ(0.71)
2022-01-03 17:43:33.792 AbstractHeadMountable DEBUG: N1.moveTo((50.290000, 50.003000, 0.000000, 0.000000 mm), 0.71)
2022-01-03 17:43:33.792 ReferenceNozzle TRACE: N1.toHeadLocation((50.315823, 49.966849, 0.000000, 0.000000 mm), ...) runout compensation (-0.025823, 0.036151, 0.000000, 0.000000 mm)
2022-01-03 17:43:33.795 AbstractHeadMountable DEBUG: N1.moveTo((50.290000, 50.003000, -12.500000, 0.000000 mm), 0.71)
2022-01-03 17:43:33.795 ReferenceNozzle TRACE: N1.toHeadLocation((50.315823, 49.966849, -12.500000, 0.000000 mm), ...) runout compensation (-0.025823, 0.036151, 0.000000, 0.000000 mm)
2022-01-03 17:43:33.797 ReferenceNozzle DEBUG: N1.pick()
2022-01-03 17:43:33.797 Scripting TRACE: Scripting.on Nozzle.BeforePick
2022-01-03 17:43:33.798 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M204 S1182.55 G1 X100.6168 Y11.9616  A0.0000  F30631.98 ; move to target, 20000)...
2022-01-03 17:43:33.798 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M204S1182.55G1X100.6168Y11.9616A0F30631.98
2022-01-03 17:43:33.798 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M204 S2772.55 G1   Z-12.5000   F11169.81 ; move to target, 20000)...
2022-01-03 17:43:33.798 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M204S2772.55G1Z-12.5F11169.81
2022-01-03 17:43:33.798 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M400, 28169)...
2022-01-03 17:43:33.798 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M114 ; get position, -1)...
2022-01-03 17:43:33.799 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:43:33.799 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M400
2022-01-03 17:43:33.800 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M114
2022-01-03 17:43:33.800 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:43:34.819 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:43:34.820 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok C: X:100.6168 Y:11.9616 Z:-12.5000 A:0.0000 B:180.0000
2022-01-03 17:43:34.820 GcodeDriver TRACE: Position report: ok C: X:100.6168 Y:11.9616 Z:-12.5000 A:0.0000 B:180.0000
2022-01-03 17:43:34.821 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:100.616800, Y:11.961600, Z:-12.500000, Rot_N1:0.000000, Rot_N2:180.000000)
2022-01-03 17:43:34.821 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete.
2022-01-03 17:43:34.821 ReferenceActuator DEBUG: DummyPump.actuate(true)
2022-01-03 17:43:34.821 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M400, 28169)...
2022-01-03 17:43:34.822 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M114 ; get position, -1)...
2022-01-03 17:43:34.823 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M400
2022-01-03 17:43:34.823 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:43:34.823 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M114
2022-01-03 17:43:34.824 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok C: X:100.6168 Y:11.9616 Z:-12.5000 A:0.0000 B:180.0000
2022-01-03 17:43:34.825 GcodeDriver TRACE: Position report: ok C: X:100.6168 Y:11.9616 Z:-12.5000 A:0.0000 B:180.0000
2022-01-03 17:43:34.825 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:100.616800, Y:11.961600, Z:-12.500000, Rot_N1:0.000000, Rot_N2:180.000000)
2022-01-03 17:43:34.825 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete.
2022-01-03 17:43:34.825 GcodeAsyncDriver TRACE: FEEDERASYNC confirmation complete.
2022-01-03 17:43:34.826 ReferenceActuator DEBUG: Pump1.actuate(true)
2022-01-03 17:43:34.827 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M800, 20000)...
2022-01-03 17:43:34.827 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M800
2022-01-03 17:43:34.827 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M400, 28169)...
2022-01-03 17:43:34.827 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M114 ; get position, -1)...
2022-01-03 17:43:34.827 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M400
2022-01-03 17:43:34.827 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:43:34.827 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M114
2022-01-03 17:43:34.828 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:43:34.829 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok C: X:100.6168 Y:11.9616 Z:-12.5000 A:0.0000 B:180.0000
2022-01-03 17:43:34.829 GcodeDriver TRACE: Position report: ok C: X:100.6168 Y:11.9616 Z:-12.5000 A:0.0000 B:180.0000
2022-01-03 17:43:34.829 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:100.616800, Y:11.961600, Z:-12.500000, Rot_N1:0.000000, Rot_N2:180.000000)
2022-01-03 17:43:34.830 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete.
2022-01-03 17:43:34.830 GcodeAsyncDriver TRACE: FEEDERASYNC confirmation complete.
2022-01-03 17:43:35.330 Scripting TRACE: Scripting.on Nozzle.AfterPick
2022-01-03 17:43:35.330 AbstractHeadMountable DEBUG: N1.moveToSafeZ(0.71)
2022-01-03 17:43:35.331 AbstractHeadMountable DEBUG: N1.moveTo((50.290000, 50.003000, 0.000000, 0.000000 mm), 0.71)
2022-01-03 17:43:35.331 ReferenceNozzle TRACE: N1.toHeadLocation((50.315823, 49.966849, 0.000000, 0.000000 mm), ...) runout compensation (-0.025823, 0.036151, 0.000000, 0.000000 mm)
2022-01-03 17:43:35.333 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M204 S2772.55 G1   Z0.0000   F11169.81 ; move to target, 20000)...
2022-01-03 17:43:35.333 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M204S2772.55G1Z0F11169.81
2022-01-03 17:43:35.334 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:43:45.951 AbstractHeadMountable DEBUG: N1.moveToSafeZ(0.71)
2022-01-03 17:43:45.951 ReferenceActuator DEBUG: FEEDER.actuate(1.0)
2022-01-03 17:43:45.952 GcodeAsyncDriver DEBUG: serial://COM5 commandQueue.offer(FEED1, 5000)...
2022-01-03 17:43:45.952 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M400, 28169)...
2022-01-03 17:43:45.952 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M114 ; get position, -1)...
2022-01-03 17:43:45.952 GcodeAsyncDriver$WriterThread TRACE: [serial://COM5] >> FEED1
2022-01-03 17:43:45.952 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M400
2022-01-03 17:43:45.952 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:43:45.952 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M114
2022-01-03 17:43:45.954 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok C: X:100.6168 Y:11.9616 Z:0.0000 A:0.0000 B:180.0000
2022-01-03 17:43:45.955 GcodeDriver$ReaderThread TRACE: [serial://COM5] << ok
2022-01-03 17:43:45.955 GcodeDriver TRACE: Position report: ok C: X:100.6168 Y:11.9616 Z:0.0000 A:0.0000 B:180.0000
2022-01-03 17:43:45.955 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:100.616800, Y:11.961600, Z:0.000000, Rot_N1:0.000000, Rot_N2:180.000000)
2022-01-03 17:43:45.955 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete.
2022-01-03 17:43:45.955 GcodeDriver TRACE: [serial://COM5] confirmed FEED1
2022-01-03 17:43:45.956 GcodeAsyncDriver TRACE: FEEDERASYNC confirmation complete.
2022-01-03 17:43:45.957 AbstractHeadMountable DEBUG: N1.moveTo((50.290000, 50.003000, -12.500000, 0.000000 mm), 0.71)
2022-01-03 17:43:45.957 ReferenceNozzle TRACE: N1.toHeadLocation((50.315823, 49.966849, -12.500000, 0.000000 mm), ...) runout compensation (-0.025823, 0.036151, 0.000000, 0.000000 mm)
2022-01-03 17:43:45.958 ReferenceNozzle DEBUG: N1.pick()
2022-01-03 17:43:45.958 Scripting TRACE: Scripting.on Nozzle.BeforePick
2022-01-03 17:43:45.959 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M204 S2772.55 G1   Z-12.5000   F11169.81 ; move to target, 20000)...
2022-01-03 17:43:45.959 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M204S2772.55G1Z-12.5F11169.81
2022-01-03 17:43:45.960 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M400, 28169)...
2022-01-03 17:43:45.960 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:43:45.960 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M400
2022-01-03 17:43:45.960 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M114 ; get position, -1)...
2022-01-03 17:43:45.960 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M114
2022-01-03 17:43:46.094 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:43:46.095 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok C: X:100.6168 Y:11.9616 Z:-12.5000 A:0.0000 B:180.0000
2022-01-03 17:43:46.096 GcodeDriver TRACE: Position report: ok C: X:100.6168 Y:11.9616 Z:-12.5000 A:0.0000 B:180.0000
2022-01-03 17:43:46.096 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:100.616800, Y:11.961600, Z:-12.500000, Rot_N1:0.000000, Rot_N2:180.000000)
2022-01-03 17:43:46.096 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete.
2022-01-03 17:43:46.096 ReferenceActuator DEBUG: DummyPump.actuate(true)
2022-01-03 17:43:46.097 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M400, 28169)...
2022-01-03 17:43:46.097 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M114 ; get position, -1)...
2022-01-03 17:43:46.097 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M400
2022-01-03 17:43:46.097 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:43:46.097 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M114
2022-01-03 17:43:46.099 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok C: X:100.6168 Y:11.9616 Z:-12.5000 A:0.0000 B:180.0000
2022-01-03 17:43:46.099 GcodeDriver TRACE: Position report: ok C: X:100.6168 Y:11.9616 Z:-12.5000 A:0.0000 B:180.0000
2022-01-03 17:43:46.099 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:100.616800, Y:11.961600, Z:-12.500000, Rot_N1:0.000000, Rot_N2:180.000000)
2022-01-03 17:43:46.099 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete.
2022-01-03 17:43:46.099 GcodeAsyncDriver TRACE: FEEDERASYNC confirmation complete.
2022-01-03 17:43:46.101 ReferenceActuator DEBUG: Pump1.actuate(true)
2022-01-03 17:43:46.101 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M800, 20000)...
2022-01-03 17:43:46.101 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M400, 28169)...
2022-01-03 17:43:46.101 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M114 ; get position, -1)...
2022-01-03 17:43:46.101 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M800
2022-01-03 17:43:46.101 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:43:46.101 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M400
2022-01-03 17:43:46.102 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:43:46.102 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M114
2022-01-03 17:43:46.104 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok C: X:100.6168 Y:11.9616 Z:-12.5000 A:0.0000 B:180.0000
2022-01-03 17:43:46.104 GcodeDriver TRACE: Position report: ok C: X:100.6168 Y:11.9616 Z:-12.5000 A:0.0000 B:180.0000
2022-01-03 17:43:46.104 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:100.616800, Y:11.961600, Z:-12.500000, Rot_N1:0.000000, Rot_N2:180.000000)
2022-01-03 17:43:46.104 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete.
2022-01-03 17:43:46.104 GcodeAsyncDriver TRACE: FEEDERASYNC confirmation complete.
2022-01-03 17:43:46.605 Scripting TRACE: Scripting.on Nozzle.AfterPick
2022-01-03 17:43:46.605 AbstractHeadMountable DEBUG: N1.moveToSafeZ(0.71)
2022-01-03 17:43:46.606 AbstractHeadMountable DEBUG: N1.moveTo((50.290000, 50.003000, 0.000000, 0.000000 mm), 0.71)
2022-01-03 17:43:46.606 ReferenceNozzle TRACE: N1.toHeadLocation((50.315823, 49.966849, 0.000000, 0.000000 mm), ...) runout compensation (-0.025823, 0.036151, 0.000000, 0.000000 mm)
2022-01-03 17:43:46.608 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M204 S2772.55 G1   Z0.0000   F11169.81 ; move to target, 20000)...
2022-01-03 17:43:46.609 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M204S2772.55G1Z0F11169.81
2022-01-03 17:43:46.609 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:43:47.479 AbstractHeadMountable DEBUG: N1.moveToSafeZ(0.71)
2022-01-03 17:43:47.480 ReferenceActuator DEBUG: FEEDER.actuate(1.0)
2022-01-03 17:43:47.480 GcodeAsyncDriver DEBUG: serial://COM5 commandQueue.offer(FEED1, 5000)...
2022-01-03 17:43:47.480 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M400, 28169)...
2022-01-03 17:43:47.480 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M114 ; get position, -1)...
2022-01-03 17:43:47.480 GcodeAsyncDriver$WriterThread TRACE: [serial://COM5] >> FEED1
2022-01-03 17:43:47.480 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M400
2022-01-03 17:43:47.481 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:43:47.481 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M114
2022-01-03 17:43:47.482 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok C: X:100.6168 Y:11.9616 Z:0.0000 A:0.0000 B:180.0000
2022-01-03 17:43:47.482 GcodeDriver TRACE: Position report: ok C: X:100.6168 Y:11.9616 Z:0.0000 A:0.0000 B:180.0000
2022-01-03 17:43:47.483 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:100.616800, Y:11.961600, Z:0.000000, Rot_N1:0.000000, Rot_N2:180.000000)
2022-01-03 17:43:47.483 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete.
2022-01-03 17:43:47.490 GcodeDriver$ReaderThread TRACE: [serial://COM5] << ok
2022-01-03 17:43:47.490 GcodeDriver TRACE: [serial://COM5] confirmed FEED1
2022-01-03 17:43:47.490 GcodeAsyncDriver TRACE: FEEDERASYNC confirmation complete.
2022-01-03 17:43:47.491 AbstractHeadMountable DEBUG: N1.moveTo((50.290000, 50.003000, -12.500000, 0.000000 mm), 0.71)
2022-01-03 17:43:47.492 ReferenceNozzle TRACE: N1.toHeadLocation((50.315823, 49.966849, -12.500000, 0.000000 mm), ...) runout compensation (-0.025823, 0.036151, 0.000000, 0.000000 mm)
2022-01-03 17:43:47.493 ReferenceNozzle DEBUG: N1.pick()
2022-01-03 17:43:47.493 Scripting TRACE: Scripting.on Nozzle.BeforePick
2022-01-03 17:43:47.493 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M204 S2772.55 G1   Z-12.5000   F11169.81 ; move to target, 20000)...
2022-01-03 17:43:47.494 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M400, 28169)...
2022-01-03 17:43:47.494 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M114 ; get position, -1)...
2022-01-03 17:43:47.494 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M204S2772.55G1Z-12.5F11169.81
2022-01-03 17:43:47.494 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M400
2022-01-03 17:43:47.495 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:43:47.495 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M114
2022-01-03 17:43:47.628 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:43:47.629 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok C: X:100.6168 Y:11.9616 Z:-12.5000 A:0.0000 B:180.0000
2022-01-03 17:43:47.629 GcodeDriver TRACE: Position report: ok C: X:100.6168 Y:11.9616 Z:-12.5000 A:0.0000 B:180.0000
2022-01-03 17:43:47.629 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:100.616800, Y:11.961600, Z:-12.500000, Rot_N1:0.000000, Rot_N2:180.000000)
2022-01-03 17:43:47.629 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete.
2022-01-03 17:43:47.630 ReferenceActuator DEBUG: DummyPump.actuate(true)
2022-01-03 17:43:47.630 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M400, 28169)...
2022-01-03 17:43:47.630 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M114 ; get position, -1)...
2022-01-03 17:43:47.631 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M400
2022-01-03 17:43:47.631 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:43:47.631 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M114
2022-01-03 17:43:47.633 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok C: X:100.6168 Y:11.9616 Z:-12.5000 A:0.0000 B:180.0000
2022-01-03 17:43:47.633 GcodeDriver TRACE: Position report: ok C: X:100.6168 Y:11.9616 Z:-12.5000 A:0.0000 B:180.0000
2022-01-03 17:43:47.633 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:100.616800, Y:11.961600, Z:-12.500000, Rot_N1:0.000000, Rot_N2:180.000000)
2022-01-03 17:43:47.633 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete.
2022-01-03 17:43:47.633 GcodeAsyncDriver TRACE: FEEDERASYNC confirmation complete.
2022-01-03 17:43:47.635 ReferenceActuator DEBUG: Pump1.actuate(true)
2022-01-03 17:43:47.635 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M800, 20000)...
2022-01-03 17:43:47.635 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M400, 28169)...
2022-01-03 17:43:47.636 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M114 ; get position, -1)...
2022-01-03 17:43:47.636 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M800
2022-01-03 17:43:47.636 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:43:47.636 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M400
2022-01-03 17:43:47.636 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:43:47.636 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M114
2022-01-03 17:43:47.638 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok C: X:100.6168 Y:11.9616 Z:-12.5000 A:0.0000 B:180.0000
2022-01-03 17:43:47.638 GcodeDriver TRACE: Position report: ok C: X:100.6168 Y:11.9616 Z:-12.5000 A:0.0000 B:180.0000
2022-01-03 17:43:47.638 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:100.616800, Y:11.961600, Z:-12.500000, Rot_N1:0.000000, Rot_N2:180.000000)
2022-01-03 17:43:47.638 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete.
2022-01-03 17:43:47.638 GcodeAsyncDriver TRACE: FEEDERASYNC confirmation complete.
2022-01-03 17:43:48.141 Scripting TRACE: Scripting.on Nozzle.AfterPick
2022-01-03 17:43:48.141 AbstractHeadMountable DEBUG: N1.moveToSafeZ(0.71)
2022-01-03 17:43:48.142 AbstractHeadMountable DEBUG: N1.moveTo((50.290000, 50.003000, 0.000000, 0.000000 mm), 0.71)
2022-01-03 17:43:48.142 ReferenceNozzle TRACE: N1.toHeadLocation((50.315823, 49.966849, 0.000000, 0.000000 mm), ...) runout compensation (-0.025823, 0.036151, 0.000000, 0.000000 mm)
2022-01-03 17:43:48.144 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M204 S2772.55 G1   Z0.0000   F11169.81 ; move to target, 20000)...
2022-01-03 17:43:48.144 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M204S2772.55G1Z0F11169.81
2022-01-03 17:43:48.145 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:44:23.760 Scripting TRACE: Scripting.on Job.BeforeDiscard
2022-01-03 17:44:23.761 ReferenceHead DEBUG: H1.moveToSafeZ(0.71)
2022-01-03 17:44:23.761 AbstractHeadMountable DEBUG: N1.moveToSafeZ(0.71)
2022-01-03 17:44:23.762 AbstractHeadMountable DEBUG: N2.moveToSafeZ(0.71)
2022-01-03 17:44:23.762 AbstractHeadMountable DEBUG: HeadCamera.moveToSafeZ(0.71)
2022-01-03 17:44:23.764 AbstractHeadMountable DEBUG: N1.moveTo((260.344000, 107.835000, 0.000000, 0.000000 mm), 0.71)
2022-01-03 17:44:23.764 ReferenceNozzle TRACE: N1.toHeadLocation((260.369823, 107.798849, 0.000000, 0.000000 mm), ...) runout compensation (-0.025823, 0.036151, 0.000000, 0.000000 mm)
2022-01-03 17:44:23.765 AbstractHeadMountable DEBUG: N1.moveTo((260.344000, 107.835000, 0.000000, 0.000000 mm), 0.71)
2022-01-03 17:44:23.765 ReferenceNozzle TRACE: N1.toHeadLocation((260.369823, 107.798849, 0.000000, 0.000000 mm), ...) runout compensation (-0.025823, 0.036151, 0.000000, 0.000000 mm)
2022-01-03 17:44:23.767 ReferenceNozzle DEBUG: N1.place()
2022-01-03 17:44:23.767 Scripting TRACE: Scripting.on Nozzle.BeforePlace
2022-01-03 17:44:23.768 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M204 S2613.63 G1 X310.6708 Y69.5886    F25768.18 ; move to target, 20000)...
2022-01-03 17:44:23.768 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M400, 28169)...
2022-01-03 17:44:23.768 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M114 ; get position, -1)...
2022-01-03 17:44:23.768 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M204S2613.63G1X310.6708Y69.5886F25768.18
2022-01-03 17:44:23.768 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M400
2022-01-03 17:44:23.769 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:44:23.769 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M114
2022-01-03 17:44:24.441 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:44:24.442 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok C: X:310.6708 Y:69.5886 Z:0.0000 A:0.0000 B:180.0000
2022-01-03 17:44:24.442 GcodeDriver TRACE: Position report: ok C: X:310.6708 Y:69.5886 Z:0.0000 A:0.0000 B:180.0000
2022-01-03 17:44:24.442 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:310.670800, Y:69.588600, Z:0.000000, Rot_N1:0.000000, Rot_N2:180.000000)
2022-01-03 17:44:24.442 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete.
2022-01-03 17:44:24.443 ReferenceActuator DEBUG: Pump1.actuate(false)
2022-01-03 17:44:24.443 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M801, 20000)...
2022-01-03 17:44:24.443 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M400, 28169)...
2022-01-03 17:44:24.443 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M114 ; get position, -1)...
2022-01-03 17:44:24.443 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M801
2022-01-03 17:44:24.444 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:44:24.444 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M400
2022-01-03 17:44:24.444 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:44:24.444 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M114
2022-01-03 17:44:24.446 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok C: X:310.6708 Y:69.5886 Z:0.0000 A:0.0000 B:180.0000
2022-01-03 17:44:24.446 GcodeDriver TRACE: Position report: ok C: X:310.6708 Y:69.5886 Z:0.0000 A:0.0000 B:180.0000
2022-01-03 17:44:24.446 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:310.670800, Y:69.588600, Z:0.000000, Rot_N1:0.000000, Rot_N2:180.000000)
2022-01-03 17:44:24.446 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete.
2022-01-03 17:44:24.446 GcodeAsyncDriver TRACE: FEEDERASYNC confirmation complete.
2022-01-03 17:44:24.447 ReferenceActuator DEBUG: DummyPump.actuate(false)
2022-01-03 17:44:24.448 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M400, 28169)...
2022-01-03 17:44:24.448 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M114 ; get position, -1)...
2022-01-03 17:44:24.448 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M400
2022-01-03 17:44:24.448 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M114
2022-01-03 17:44:24.448 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:44:24.450 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok C: X:310.6708 Y:69.5886 Z:0.0000 A:0.0000 B:180.0000
2022-01-03 17:44:24.451 GcodeDriver TRACE: Position report: ok C: X:310.6708 Y:69.5886 Z:0.0000 A:0.0000 B:180.0000
2022-01-03 17:44:24.451 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:310.670800, Y:69.588600, Z:0.000000, Rot_N1:0.000000, Rot_N2:180.000000)
2022-01-03 17:44:24.451 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete.
2022-01-03 17:44:24.451 GcodeAsyncDriver TRACE: FEEDERASYNC confirmation complete.
2022-01-03 17:44:24.522 Scripting TRACE: Scripting.on Nozzle.AfterPlace
2022-01-03 17:44:24.522 AbstractHeadMountable DEBUG: N1.moveToSafeZ(0.71)
2022-01-03 17:44:24.523 Scripting TRACE: Scripting.on Job.AfterDiscard

[geo0rpo]

machine.xml

[mark maker]

please send the full log, so I can confirm the version. It would not be the first time that an update does not take.

_Mark

To view this discussion on the web visit https://groups.google.com/d/msgid/openpnp/21a6da07-25d7-4161-ae64-8d89fb10ebb0n%40googlegroups.com.

[geo0rpo]

Version is OK. I also saw the new vision tab.

OK, I am preparing a full log right now.

[mark maker]

OK, found it:

You have the MOVE_TO_COMPLETE_COMMAND assigned to the Actuator. I see how you can get this idea, but unfortunately it does not work that way. Without any axes in play, there are no associations with HeadMountables possible, the wait for completion is driver-wide.

Please assign it to Default.

I agree this is not self-explanatory. Probably needs an Issues & Solutions warning against doing it.

_Mark

To view this discussion on the web visit https://groups.google.com/d/msgid/openpnp/1d6d35e4-4234-054f-e407-495d4e10ba0b%40makr.zone.

[geo0rpo]

2022-01-03 17:55:17.008 Main INFO: Bienvenue, Bienvenido, Willkommen, Hello, Namaskar, Welkom, Bonjour to OpenPnP version 2022-01-03_10-18-17.6e61dcd.
2022-01-03 17:55:17.010 Scripting TRACE: Scripting.on Startup
2022-01-03 17:55:18.336 AbstractBroadcastingCamera TRACE: Camera HeadCamera thread 28 started.
2022-01-03 17:55:19.612 AbstractBroadcastingCamera TRACE: Camera BottomCamera thread 30 started.
2022-01-03 17:55:28.635 ReferenceMachine DEBUG: setEnabled(true)
2022-01-03 17:55:48.675 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(G21 ; Set millimeters mode, 20000)...
2022-01-03 17:55:48.676 GcodeDriver$ReaderThread TRACE: [serial://COM3] << Smoothie
2022-01-03 17:55:48.676 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(G90 ; Set absolute positioning mode, 20000)...
2022-01-03 17:55:48.676 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:55:48.677 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> G21
2022-01-03 17:55:48.677 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:55:48.677 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> G90
2022-01-03 17:55:48.677 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:55:58.462 ReferenceMachine DEBUG: homing machine
2022-01-03 17:55:58.465 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(G28                 ;HOME, -1)...
2022-01-03 17:55:58.465 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(G92 Z0                 ;Set Z to zero, -1)...
2022-01-03 17:55:58.465 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(G1  Z-4.5         ;Move to balance, -1)...
2022-01-03 17:55:58.465 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> G28                
2022-01-03 17:55:58.465 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> G92Z0                
2022-01-03 17:55:58.465 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(G92 Z0                 ;Set Z to zero, -1)...
2022-01-03 17:55:58.466 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> G1Z-4.5        
2022-01-03 17:55:58.466 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> G92Z0                
2022-01-03 17:55:58.466 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(G92 A0                 ;Set N1 rotation to zero, -1)...
2022-01-03 17:55:58.466 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> G92A0                
2022-01-03 17:55:58.466 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(G92 B0                 ;Set N2 rotation to zero, -1)...
2022-01-03 17:55:58.467 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> G92B0                
2022-01-03 17:55:58.468 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M400, -1)...
2022-01-03 17:55:58.468 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M400
2022-01-03 17:55:58.468 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M114 ; get position, -1)...
2022-01-03 17:55:58.469 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M114
2022-01-03 17:56:09.151 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:56:09.152 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:56:09.152 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:56:09.153 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:56:09.153 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:56:09.153 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:56:09.235 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:56:09.236 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok C: X:4.8294 Y:5.0534 Z:0.0000 A:0.0000 B:0.0000
2022-01-03 17:56:09.236 GcodeDriver TRACE: Position report: ok C: X:4.8294 Y:5.0534 Z:0.0000 A:0.0000 B:0.0000
2022-01-03 17:56:09.245 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:4.829400, Y:5.053400, Z:0.000000, Rot_N1:0.000000, Rot_N2:0.000000)
2022-01-03 17:56:09.246 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete.
2022-01-03 17:56:09.246 GcodeAsyncDriver TRACE: FEEDERASYNC confirmation complete.
2022-01-03 17:56:09.247 AbstractMotionPlanner DEBUG: Reported location changes current location from (X:0.000000, Y:0.000000, Z:0.000000, Rot_N1:0.000000, Rot_N2:0.000000) to (X:4.829400, Y:5.053400, Z:0.000000, Rot_N1:0.000000, Rot_N2:0.000000)
2022-01-03 17:56:09.250 ReferenceHead DEBUG: H1.home()
2022-01-03 17:56:09.251 ReferenceFiducialLocator DEBUG: Looking for FIDUCIAL-HOME at (195.490000, 181.170000, 0.000000, 0.000000 mm)
2022-01-03 17:56:09.252 ReferenceHead DEBUG: H1.moveToSafeZ(0.71)
2022-01-03 17:56:09.252 AbstractHeadMountable DEBUG: N1.moveToSafeZ(0.71)
2022-01-03 17:56:09.253 AbstractHeadMountable DEBUG: N2.moveToSafeZ(0.71)
2022-01-03 17:56:09.254 AbstractHeadMountable DEBUG: HeadCamera.moveToSafeZ(0.71)
2022-01-03 17:56:09.255 AbstractHeadMountable DEBUG: HeadCamera.moveTo((195.490000, 181.170000, 0.000000, 0.000000 mm), 0.71)
2022-01-03 17:56:09.267 AbstractHeadMountable DEBUG: HeadCamera.moveTo((195.490000, 181.170000, 0.000000, 0.000000 mm), 0.71)
2022-01-03 17:56:09.276 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M204 S2973.44 G1 X195.4900 Y180.9792    F33812.48 ; move to target, 20000)...
2022-01-03 17:56:09.277 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M204S2973.44G1X195.49Y180.9792F33812.48
2022-01-03 17:56:09.278 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:56:09.278 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M400, 28169)...
2022-01-03 17:56:09.279 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M400
2022-01-03 17:56:09.280 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M114 ; get position, -1)...
2022-01-03 17:56:09.280 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M114
2022-01-03 17:56:09.930 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:56:09.931 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok C: X:195.4900 Y:180.9792 Z:0.0000 A:0.0000 B:0.0000
2022-01-03 17:56:09.932 GcodeDriver TRACE: Position report: ok C: X:195.4900 Y:180.9792 Z:0.0000 A:0.0000 B:0.0000
2022-01-03 17:56:09.932 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:195.490000, Y:180.979200, Z:0.000000, Rot_N1:0.000000, Rot_N2:0.000000)
2022-01-03 17:56:09.932 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete.
2022-01-03 17:56:09.933 ReferenceActuator DEBUG: Top_Light.actuate(15.0)
2022-01-03 17:56:09.934 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M804 S15, 20000)...
2022-01-03 17:56:09.934 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M400, 28169)...
2022-01-03 17:56:09.934 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M804S15
2022-01-03 17:56:09.934 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M114 ; get position, -1)...
2022-01-03 17:56:09.934 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M400
2022-01-03 17:56:09.935 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:56:09.935 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M114
2022-01-03 17:56:09.935 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:56:09.936 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok C: X:195.4900 Y:180.9792 Z:0.0000 A:0.0000 B:0.0000
2022-01-03 17:56:09.937 GcodeDriver TRACE: Position report: ok C: X:195.4900 Y:180.9792 Z:0.0000 A:0.0000 B:0.0000
2022-01-03 17:56:09.937 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:195.490000, Y:180.979200, Z:0.000000, Rot_N1:0.000000, Rot_N2:0.000000)
2022-01-03 17:56:09.937 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete.
2022-01-03 17:56:09.937 GcodeAsyncDriver TRACE: FEEDERASYNC confirmation complete.
2022-01-03 17:56:09.938 Scripting TRACE: Scripting.on Camera.BeforeSettle
2022-01-03 17:56:09.939 Scripting TRACE: Scripting.on Camera.BeforeCapture
2022-01-03 17:56:09.955 Scripting TRACE: Scripting.on Camera.AfterCapture
2022-01-03 17:56:09.958 Scripting TRACE: Scripting.on Camera.BeforeCapture
2022-01-03 17:56:09.974 Scripting TRACE: Scripting.on Camera.AfterCapture
2022-01-03 17:56:09.979 AbstractCamera TRACE: autoSettleAndCapture t=40 auto settle score: 28.627450980392155
2022-01-03 17:56:09.979 Scripting TRACE: Scripting.on Camera.BeforeCapture
2022-01-03 17:56:09.995 Scripting TRACE: Scripting.on Camera.AfterCapture
2022-01-03 17:56:09.999 AbstractCamera TRACE: autoSettleAndCapture t=60 auto settle score: 49.80392156862745
2022-01-03 17:56:10.000 Scripting TRACE: Scripting.on Camera.BeforeCapture
2022-01-03 17:56:10.039 Scripting TRACE: Scripting.on Camera.AfterCapture
2022-01-03 17:56:10.044 AbstractCamera TRACE: autoSettleAndCapture t=105 auto settle score: 47.84313725490196
2022-01-03 17:56:10.044 Scripting TRACE: Scripting.on Camera.BeforeCapture
2022-01-03 17:56:10.071 Scripting TRACE: Scripting.on Camera.AfterCapture
2022-01-03 17:56:10.076 AbstractCamera TRACE: autoSettleAndCapture t=137 auto settle score: 22.35294117647059
2022-01-03 17:56:10.076 Scripting TRACE: Scripting.on Camera.BeforeCapture
2022-01-03 17:56:10.119 Scripting TRACE: Scripting.on Camera.AfterCapture
2022-01-03 17:56:10.123 AbstractCamera TRACE: autoSettleAndCapture t=184 auto settle score: 23.137254901960784
2022-01-03 17:56:10.124 Scripting TRACE: Scripting.on Camera.BeforeCapture
2022-01-03 17:56:10.151 Scripting TRACE: Scripting.on Camera.AfterCapture
2022-01-03 17:56:10.156 AbstractCamera TRACE: autoSettleAndCapture t=217 auto settle score: 20.0
2022-01-03 17:56:10.156 Scripting TRACE: Scripting.on Camera.BeforeCapture
2022-01-03 17:56:10.198 Scripting TRACE: Scripting.on Camera.AfterCapture
2022-01-03 17:56:10.202 AbstractCamera TRACE: autoSettleAndCapture t=263 auto settle score: 19.607843137254903
2022-01-03 17:56:10.202 Scripting TRACE: Scripting.on Camera.BeforeCapture
2022-01-03 17:56:10.248 Scripting TRACE: Scripting.on Camera.AfterCapture
2022-01-03 17:56:10.274 AbstractCamera TRACE: autoSettleAndCapture t=335 auto settle score: 19.215686274509807
2022-01-03 17:56:10.279 AbstractCamera DEBUG: autoSettleAndCapture in 340 ms
2022-01-03 17:56:10.280 Scripting TRACE: Scripting.on Camera.AfterSettle
2022-01-03 17:56:10.437 ReferenceFiducialLocator DEBUG: FIDUCIAL-HOME located at (195.476877, 181.143404, 0.000000, 0.000000 mm)
2022-01-03 17:56:10.438 AbstractHeadMountable DEBUG: HeadCamera.moveTo((195.476877, 181.143404, 0.000000, 0.000000 mm), 0.71)
2022-01-03 17:56:10.443 Scripting TRACE: Scripting.on Camera.BeforeSettle
2022-01-03 17:56:10.445 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M204 S2248.73 G1 X195.4769 Y180.9526    F489.89 ; move to target, 20000)...
2022-01-03 17:56:10.445 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M204S2248.73G1X195.4769Y180.9526F489.89
2022-01-03 17:56:10.446 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M400, 28169)...
2022-01-03 17:56:10.446 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M400
2022-01-03 17:56:10.446 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M114 ; get position, -1)...
2022-01-03 17:56:10.447 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M114
2022-01-03 17:56:10.447 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:56:10.454 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:56:10.455 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok C: X:195.4769 Y:180.9526 Z:0.0000 A:0.0000 B:0.0000
2022-01-03 17:56:10.455 GcodeDriver TRACE: Position report: ok C: X:195.4769 Y:180.9526 Z:0.0000 A:0.0000 B:0.0000
2022-01-03 17:56:10.456 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:195.476900, Y:180.952600, Z:0.000000, Rot_N1:0.000000, Rot_N2:0.000000)
2022-01-03 17:56:10.456 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete.
2022-01-03 17:56:10.456 Scripting TRACE: Scripting.on Camera.BeforeCapture
2022-01-03 17:56:10.471 Scripting TRACE: Scripting.on Camera.AfterCapture
2022-01-03 17:56:10.477 Scripting TRACE: Scripting.on Camera.BeforeCapture
2022-01-03 17:56:10.519 Scripting TRACE: Scripting.on Camera.AfterCapture
2022-01-03 17:56:10.524 AbstractCamera TRACE: autoSettleAndCapture t=68 auto settle score: 23.92156862745098
2022-01-03 17:56:10.524 Scripting TRACE: Scripting.on Camera.BeforeCapture
2022-01-03 17:56:10.553 Scripting TRACE: Scripting.on Camera.AfterCapture
2022-01-03 17:56:10.558 AbstractCamera TRACE: autoSettleAndCapture t=102 auto settle score: 29.411764705882355
2022-01-03 17:56:10.558 Scripting TRACE: Scripting.on Camera.BeforeCapture
2022-01-03 17:56:10.598 Scripting TRACE: Scripting.on Camera.AfterCapture
2022-01-03 17:56:10.602 AbstractCamera TRACE: autoSettleAndCapture t=146 auto settle score: 31.372549019607842
2022-01-03 17:56:10.602 Scripting TRACE: Scripting.on Camera.BeforeCapture
2022-01-03 17:56:10.630 Scripting TRACE: Scripting.on Camera.AfterCapture
2022-01-03 17:56:10.634 AbstractCamera TRACE: autoSettleAndCapture t=178 auto settle score: 29.01960784313726
2022-01-03 17:56:10.634 Scripting TRACE: Scripting.on Camera.BeforeCapture
2022-01-03 17:56:10.661 Scripting TRACE: Scripting.on Camera.AfterCapture
2022-01-03 17:56:10.665 AbstractCamera TRACE: autoSettleAndCapture t=209 auto settle score: 27.84313725490196
2022-01-03 17:56:10.665 Scripting TRACE: Scripting.on Camera.BeforeCapture
2022-01-03 17:56:10.709 Scripting TRACE: Scripting.on Camera.AfterCapture
2022-01-03 17:56:10.713 AbstractCamera TRACE: autoSettleAndCapture t=257 auto settle score: 22.35294117647059
2022-01-03 17:56:10.714 Scripting TRACE: Scripting.on Camera.BeforeCapture
2022-01-03 17:56:10.767 Scripting TRACE: Scripting.on Camera.AfterCapture
2022-01-03 17:56:10.773 AbstractCamera TRACE: autoSettleAndCapture t=317 auto settle score: 25.882352941176475
2022-01-03 17:56:10.774 AbstractCamera DEBUG: autoSettleAndCapture in 318 ms
2022-01-03 17:56:10.774 Scripting TRACE: Scripting.on Camera.AfterSettle
2022-01-03 17:56:10.909 ReferenceFiducialLocator DEBUG: FIDUCIAL-HOME located at (195.490000, 181.143404, 0.000000, 0.000000 mm)
2022-01-03 17:56:10.909 AbstractHeadMountable DEBUG: HeadCamera.moveTo((195.490000, 181.143404, 0.000000, 0.000000 mm), 0.71)
2022-01-03 17:56:10.914 Scripting TRACE: Scripting.on Camera.BeforeSettle
2022-01-03 17:56:10.917 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M204 S2520.50 G1 X195.4900     F345.08 ; move to target, 20000)...
2022-01-03 17:56:10.917 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M204S2520.5G1X195.49F345.08
2022-01-03 17:56:10.918 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M400, 28169)...
2022-01-03 17:56:10.918 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M400
2022-01-03 17:56:10.918 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M114 ; get position, -1)...
2022-01-03 17:56:10.918 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M114
2022-01-03 17:56:10.919 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:56:10.923 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:56:10.924 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok C: X:195.4900 Y:180.9526 Z:0.0000 A:0.0000 B:0.0000
2022-01-03 17:56:10.925 GcodeDriver TRACE: Position report: ok C: X:195.4900 Y:180.9526 Z:0.0000 A:0.0000 B:0.0000
2022-01-03 17:56:10.925 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:195.490000, Y:180.952600, Z:0.000000, Rot_N1:0.000000, Rot_N2:0.000000)
2022-01-03 17:56:10.925 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete.
2022-01-03 17:56:10.925 Scripting TRACE: Scripting.on Camera.BeforeCapture
2022-01-03 17:56:10.943 Scripting TRACE: Scripting.on Camera.AfterCapture
2022-01-03 17:56:10.947 Scripting TRACE: Scripting.on Camera.BeforeCapture
2022-01-03 17:56:10.961 Scripting TRACE: Scripting.on Camera.AfterCapture
2022-01-03 17:56:10.966 AbstractCamera TRACE: autoSettleAndCapture t=41 auto settle score: 23.92156862745098
2022-01-03 17:56:10.966 Scripting TRACE: Scripting.on Camera.BeforeCapture
2022-01-03 17:56:10.984 Scripting TRACE: Scripting.on Camera.AfterCapture
2022-01-03 17:56:10.989 AbstractCamera TRACE: autoSettleAndCapture t=64 auto settle score: 24.313725490196077
2022-01-03 17:56:10.989 Scripting TRACE: Scripting.on Camera.BeforeCapture
2022-01-03 17:56:11.029 Scripting TRACE: Scripting.on Camera.AfterCapture
2022-01-03 17:56:11.034 AbstractCamera TRACE: autoSettleAndCapture t=108 auto settle score: 32.15686274509804
2022-01-03 17:56:11.034 Scripting TRACE: Scripting.on Camera.BeforeCapture
2022-01-03 17:56:11.061 Scripting TRACE: Scripting.on Camera.AfterCapture
2022-01-03 17:56:11.065 AbstractCamera TRACE: autoSettleAndCapture t=140 auto settle score: 21.96078431372549
2022-01-03 17:56:11.066 Scripting TRACE: Scripting.on Camera.BeforeCapture
2022-01-03 17:56:11.111 Scripting TRACE: Scripting.on Camera.AfterCapture
2022-01-03 17:56:11.115 AbstractCamera TRACE: autoSettleAndCapture t=190 auto settle score: 20.392156862745097
2022-01-03 17:56:11.115 Scripting TRACE: Scripting.on Camera.BeforeCapture
2022-01-03 17:56:11.141 Scripting TRACE: Scripting.on Camera.AfterCapture
2022-01-03 17:56:11.145 AbstractCamera TRACE: autoSettleAndCapture t=220 auto settle score: 28.235294117647058
2022-01-03 17:56:11.146 Scripting TRACE: Scripting.on Camera.BeforeCapture
2022-01-03 17:56:11.191 Scripting TRACE: Scripting.on Camera.AfterCapture
2022-01-03 17:56:11.195 AbstractCamera TRACE: autoSettleAndCapture t=270 auto settle score: 15.686274509803921
2022-01-03 17:56:11.195 Scripting TRACE: Scripting.on Camera.BeforeCapture
2022-01-03 17:56:11.223 Scripting TRACE: Scripting.on Camera.AfterCapture
2022-01-03 17:56:11.227 AbstractCamera TRACE: autoSettleAndCapture t=302 auto settle score: 28.627450980392155
2022-01-03 17:56:11.228 AbstractCamera DEBUG: autoSettleAndCapture in 303 ms
2022-01-03 17:56:11.228 Scripting TRACE: Scripting.on Camera.AfterSettle
2022-01-03 17:56:11.363 ReferenceFiducialLocator DEBUG: FIDUCIAL-HOME located at (195.476877, 181.143404, 0.000000, 0.000000 mm)
2022-01-03 17:56:11.364 AbstractHeadMountable DEBUG: HeadCamera.moveTo((195.476877, 181.143404, 0.000000, 0.000000 mm), 0.71)
2022-01-03 17:56:11.369 Scripting TRACE: Scripting.on Camera.BeforeSettle
2022-01-03 17:56:11.371 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M204 S2520.50 G1 X195.4769     F345.08 ; move to target, 20000)...
2022-01-03 17:56:11.371 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M204S2520.5G1X195.4769F345.08
2022-01-03 17:56:11.371 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M400, 28169)...
2022-01-03 17:56:11.371 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M400
2022-01-03 17:56:11.371 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M114 ; get position, -1)...
2022-01-03 17:56:11.372 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:56:11.372 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M114
2022-01-03 17:56:11.376 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:56:11.378 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok C: X:195.4769 Y:180.9526 Z:0.0000 A:0.0000 B:0.0000
2022-01-03 17:56:11.378 GcodeDriver TRACE: Position report: ok C: X:195.4769 Y:180.9526 Z:0.0000 A:0.0000 B:0.0000
2022-01-03 17:56:11.378 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:195.476900, Y:180.952600, Z:0.000000, Rot_N1:0.000000, Rot_N2:0.000000)
2022-01-03 17:56:11.379 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete.
2022-01-03 17:56:11.379 Scripting TRACE: Scripting.on Camera.BeforeCapture
2022-01-03 17:56:11.392 Scripting TRACE: Scripting.on Camera.AfterCapture
2022-01-03 17:56:11.396 Scripting TRACE: Scripting.on Camera.BeforeCapture
2022-01-03 17:56:11.429 Scripting TRACE: Scripting.on Camera.AfterCapture
2022-01-03 17:56:11.434 AbstractCamera TRACE: autoSettleAndCapture t=54 auto settle score: 20.784313725490197
2022-01-03 17:56:11.434 Scripting TRACE: Scripting.on Camera.BeforeCapture
2022-01-03 17:56:11.461 Scripting TRACE: Scripting.on Camera.AfterCapture
2022-01-03 17:56:11.465 AbstractCamera TRACE: autoSettleAndCapture t=86 auto settle score: 23.137254901960784
2022-01-03 17:56:11.465 Scripting TRACE: Scripting.on Camera.BeforeCapture
2022-01-03 17:56:11.511 Scripting TRACE: Scripting.on Camera.AfterCapture
2022-01-03 17:56:11.515 AbstractCamera TRACE: autoSettleAndCapture t=136 auto settle score: 20.392156862745097
2022-01-03 17:56:11.515 Scripting TRACE: Scripting.on Camera.BeforeCapture
2022-01-03 17:56:11.541 Scripting TRACE: Scripting.on Camera.AfterCapture
2022-01-03 17:56:11.545 AbstractCamera TRACE: autoSettleAndCapture t=166 auto settle score: 24.313725490196077
2022-01-03 17:56:11.545 Scripting TRACE: Scripting.on Camera.BeforeCapture
2022-01-03 17:56:11.591 Scripting TRACE: Scripting.on Camera.AfterCapture
2022-01-03 17:56:11.595 AbstractCamera TRACE: autoSettleAndCapture t=216 auto settle score: 29.01960784313726
2022-01-03 17:56:11.595 Scripting TRACE: Scripting.on Camera.BeforeCapture
2022-01-03 17:56:11.623 Scripting TRACE: Scripting.on Camera.AfterCapture
2022-01-03 17:56:11.627 AbstractCamera TRACE: autoSettleAndCapture t=248 auto settle score: 26.27450980392157
2022-01-03 17:56:11.627 Scripting TRACE: Scripting.on Camera.BeforeCapture
2022-01-03 17:56:11.669 Scripting TRACE: Scripting.on Camera.AfterCapture
2022-01-03 17:56:11.673 AbstractCamera TRACE: autoSettleAndCapture t=294 auto settle score: 26.27450980392157
2022-01-03 17:56:11.673 Scripting TRACE: Scripting.on Camera.BeforeCapture
2022-01-03 17:56:11.701 Scripting TRACE: Scripting.on Camera.AfterCapture
2022-01-03 17:56:11.706 AbstractCamera TRACE: autoSettleAndCapture t=327 auto settle score: 24.313725490196077
2022-01-03 17:56:11.707 AbstractCamera DEBUG: autoSettleAndCapture in 328 ms
2022-01-03 17:56:11.707 Scripting TRACE: Scripting.on Camera.AfterSettle
2022-01-03 17:56:11.844 ReferenceFiducialLocator DEBUG: FIDUCIAL-HOME located at (195.490000, 181.143404, 0.000000, 0.000000 mm)
2022-01-03 17:56:11.845 AbstractHeadMountable DEBUG: HeadCamera.moveTo((195.490000, 181.143404, 0.000000, 0.000000 mm), 0.71)
2022-01-03 17:56:11.849 ReferenceFiducialLocator DEBUG: FIDUCIAL-HOME averaged location is at (195.485626, 181.143404, 0.000000, 0.000000 mm)
2022-01-03 17:56:11.850 AbstractHeadMountable DEBUG: HeadCamera.moveTo((195.485626, 181.143404, 0.000000, 0.000000 mm), 0.71)
2022-01-03 17:56:11.852 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M204 S2520.50 G1 X195.4900     F345.08 ; move to target, 20000)...
2022-01-03 17:56:11.852 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M204S2520.5G1X195.49F345.08
2022-01-03 17:56:11.853 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(G92 X195.4900 Y180.9792    ; reset coordinates, -1)...
2022-01-03 17:56:11.853 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:56:11.853 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> G92X195.49Y180.9792
2022-01-03 17:56:11.853 ReferenceNozzle DEBUG: N1.home()
2022-01-03 17:56:11.853 ReferenceNozzle DEBUG: N1.home() nozzle tip Tip:502a calibration reset
2022-01-03 17:56:11.854 ReferenceNozzle DEBUG: N1.home() nozzle tip Tip:506 calibration reset
2022-01-03 17:56:11.854 ReferenceNozzle DEBUG: N1.home() nozzle tip Tip:503a calibration neeeded
2022-01-03 17:56:11.854 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:56:11.854 Scripting TRACE: Scripting.on NozzleCalibration.Starting
2022-01-03 17:56:11.855 ReferenceHead DEBUG: H1.moveToSafeZ(0.71)
2022-01-03 17:56:11.855 AbstractHeadMountable DEBUG: N1.moveToSafeZ(0.71)
2022-01-03 17:56:11.856 AbstractHeadMountable DEBUG: N2.moveToSafeZ(0.71)
2022-01-03 17:56:11.856 AbstractHeadMountable DEBUG: HeadCamera.moveToSafeZ(0.71)
2022-01-03 17:56:11.857 AbstractHeadMountable DEBUG: N1.moveTo((193.716098, 136.812355, 0.000000, -180.000000 mm), 0.71)
2022-01-03 17:56:11.864 AbstractHeadMountable DEBUG: N1.moveTo((193.716098, 136.812355, 0.000000, -180.000000 mm), 0.71)
2022-01-03 17:56:11.866 ReferenceNozzleTipCalibration DEBUG: [nozzleTipCalibration]starting measurement; angleStart: -180.0, angleStop: 180.0, angleIncrement: 60.0, angleSubdivisions: 5
2022-01-03 17:56:11.866 ReferenceNozzleTipCalibration DEBUG: [nozzleTipCalibration]i: 0, measureAngle: -180.0
2022-01-03 17:56:11.866 AbstractHeadMountable DEBUG: N1.moveTo((193.716098, 136.812355, 0.000000, -180.000000 mm), 0.71)
2022-01-03 17:56:11.868 Scripting TRACE: Scripting.on Camera.BeforeSettle
2022-01-03 17:56:11.870 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M204 S1093.38 G1 X244.0171 Y98.6672  A-180.0000  F28322.19 ; move to target, 20000)...
2022-01-03 17:56:11.871 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M204S1093.38G1X244.0171Y98.6672A-180F28322.19
2022-01-03 17:56:11.872 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:56:11.873 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M400, 28169)...
2022-01-03 17:56:11.873 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M400
2022-01-03 17:56:11.873 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M114 ; get position, -1)...
2022-01-03 17:56:11.873 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M114
2022-01-03 17:56:12.763 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:56:12.764 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok C: X:244.0171 Y:98.6672 Z:0.0000 A:-180.0000 B:0.0000
2022-01-03 17:56:12.764 GcodeDriver TRACE: Position report: ok C: X:244.0171 Y:98.6672 Z:0.0000 A:-180.0000 B:0.0000
2022-01-03 17:56:12.764 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:244.017100, Y:98.667200, Z:0.000000, Rot_N1:-180.000000, Rot_N2:0.000000)
2022-01-03 17:56:12.765 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete.
2022-01-03 17:56:12.765 Scripting TRACE: Scripting.on Camera.BeforeCapture
2022-01-03 17:56:12.783 Scripting TRACE: Scripting.on Camera.AfterCapture
2022-01-03 17:56:12.788 Scripting TRACE: Scripting.on Camera.BeforeCapture
2022-01-03 17:56:12.806 Scripting TRACE: Scripting.on Camera.AfterCapture
2022-01-03 17:56:12.811 AbstractCamera TRACE: autoSettleAndCapture t=46 auto settle score: 58.03921568627452
2022-01-03 17:56:12.811 Scripting TRACE: Scripting.on Camera.BeforeCapture
2022-01-03 17:56:12.838 Scripting TRACE: Scripting.on Camera.AfterCapture
2022-01-03 17:56:12.842 AbstractCamera TRACE: autoSettleAndCapture t=77 auto settle score: 64.31372549019608
2022-01-03 17:56:12.843 Scripting TRACE: Scripting.on Camera.BeforeCapture
2022-01-03 17:56:12.869 Scripting TRACE: Scripting.on Camera.AfterCapture
2022-01-03 17:56:12.873 AbstractCamera TRACE: autoSettleAndCapture t=108 auto settle score: 15.686274509803921
2022-01-03 17:56:12.874 AbstractCamera DEBUG: autoSettleAndCapture in 109 ms
2022-01-03 17:56:12.874 Scripting TRACE: Scripting.on Camera.AfterSettle
2022-01-03 17:56:12.947 ReferenceNozzleTipCalibration TRACE: [nozzleTipCalibration]measured offset: (-0.025575, 0.025063, 0.000000, -180.000000 mm)
2022-01-03 17:56:12.947 ReferenceNozzleTipCalibration DEBUG: [nozzleTipCalibration]i: 1, measureAngle: -120.0
2022-01-03 17:56:12.948 AbstractHeadMountable DEBUG: N1.moveTo((193.716098, 136.812355, 0.000000, -120.000000 mm), 0.71)
2022-01-03 17:56:12.954 Scripting TRACE: Scripting.on Camera.BeforeSettle
2022-01-03 17:56:12.955 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M204 S669.60 G1    A-120.0000  F12026.38 ; move to target, 20000)...
2022-01-03 17:56:12.955 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M204S669.6G1A-120F12026.38
2022-01-03 17:56:12.955 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M400, 28169)...
2022-01-03 17:56:12.955 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M400
2022-01-03 17:56:12.955 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M114 ; get position, -1)...
2022-01-03 17:56:12.956 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M114
2022-01-03 17:56:12.956 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:56:13.553 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:56:13.555 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok C: X:244.0171 Y:98.6672 Z:0.0000 A:-120.0000 B:0.0000
2022-01-03 17:56:13.555 GcodeDriver TRACE: Position report: ok C: X:244.0171 Y:98.6672 Z:0.0000 A:-120.0000 B:0.0000
2022-01-03 17:56:13.555 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:244.017100, Y:98.667200, Z:0.000000, Rot_N1:-120.000000, Rot_N2:0.000000)
2022-01-03 17:56:13.555 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete.
2022-01-03 17:56:13.556 Scripting TRACE: Scripting.on Camera.BeforeCapture
2022-01-03 17:56:13.575 Scripting TRACE: Scripting.on Camera.AfterCapture
2022-01-03 17:56:13.580 Scripting TRACE: Scripting.on Camera.BeforeCapture
2022-01-03 17:56:13.606 Scripting TRACE: Scripting.on Camera.AfterCapture
2022-01-03 17:56:13.611 AbstractCamera TRACE: autoSettleAndCapture t=55 auto settle score: 8.627450980392156
2022-01-03 17:56:13.611 Scripting TRACE: Scripting.on Camera.BeforeCapture
2022-01-03 17:56:13.639 Scripting TRACE: Scripting.on Camera.AfterCapture
2022-01-03 17:56:13.644 AbstractCamera TRACE: autoSettleAndCapture t=88 auto settle score: 8.235294117647058
2022-01-03 17:56:13.644 Scripting TRACE: Scripting.on Camera.BeforeCapture
2022-01-03 17:56:13.670 Scripting TRACE: Scripting.on Camera.AfterCapture
2022-01-03 17:56:13.675 AbstractCamera TRACE: autoSettleAndCapture t=119 auto settle score: 8.627450980392156
2022-01-03 17:56:13.676 AbstractCamera DEBUG: autoSettleAndCapture in 120 ms
2022-01-03 17:56:13.676 Scripting TRACE: Scripting.on Camera.AfterSettle
2022-01-03 17:56:13.762 ReferenceNozzleTipCalibration TRACE: [nozzleTipCalibration]measured offset: (-0.051151, 0.050125, 0.000000, -120.000000 mm)
2022-01-03 17:56:13.762 ReferenceNozzleTipCalibration DEBUG: [nozzleTipCalibration]i: 2, measureAngle: -60.0
2022-01-03 17:56:13.762 AbstractHeadMountable DEBUG: N1.moveTo((193.716098, 136.812355, 0.000000, -60.000000 mm), 0.71)
2022-01-03 17:56:13.772 Scripting TRACE: Scripting.on Camera.BeforeSettle
2022-01-03 17:56:13.772 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M204 S669.60 G1    A-60.0000  F12026.38 ; move to target, 20000)...
2022-01-03 17:56:13.773 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M400, 28169)...
2022-01-03 17:56:13.773 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M204S669.6G1A-60F12026.38
2022-01-03 17:56:13.773 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M400
2022-01-03 17:56:13.773 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M114 ; get position, -1)...
2022-01-03 17:56:13.774 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:56:13.774 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M114
2022-01-03 17:56:14.372 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:56:14.373 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok C: X:244.0171 Y:98.6672 Z:0.0000 A:-60.0000 B:0.0000
2022-01-03 17:56:14.373 GcodeDriver TRACE: Position report: ok C: X:244.0171 Y:98.6672 Z:0.0000 A:-60.0000 B:0.0000
2022-01-03 17:56:14.373 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:244.017100, Y:98.667200, Z:0.000000, Rot_N1:-60.000000, Rot_N2:0.000000)
2022-01-03 17:56:14.374 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete.
2022-01-03 17:56:14.374 Scripting TRACE: Scripting.on Camera.BeforeCapture
2022-01-03 17:56:14.393 Scripting TRACE: Scripting.on Camera.AfterCapture
2022-01-03 17:56:14.398 Scripting TRACE: Scripting.on Camera.BeforeCapture
2022-01-03 17:56:14.416 Scripting TRACE: Scripting.on Camera.AfterCapture
2022-01-03 17:56:14.421 AbstractCamera TRACE: autoSettleAndCapture t=47 auto settle score: 10.980392156862745
2022-01-03 17:56:14.421 Scripting TRACE: Scripting.on Camera.BeforeCapture
2022-01-03 17:56:14.440 Scripting TRACE: Scripting.on Camera.AfterCapture
2022-01-03 17:56:14.444 AbstractCamera TRACE: autoSettleAndCapture t=70 auto settle score: 8.627450980392156
2022-01-03 17:56:14.444 Scripting TRACE: Scripting.on Camera.BeforeCapture
2022-01-03 17:56:14.468 Scripting TRACE: Scripting.on Camera.AfterCapture
2022-01-03 17:56:14.473 AbstractCamera TRACE: autoSettleAndCapture t=99 auto settle score: 8.627450980392156
2022-01-03 17:56:14.474 Scripting TRACE: Scripting.on Camera.BeforeCapture
2022-01-03 17:56:14.500 Scripting TRACE: Scripting.on Camera.AfterCapture
2022-01-03 17:56:14.505 AbstractCamera TRACE: autoSettleAndCapture t=131 auto settle score: 8.627450980392156
2022-01-03 17:56:14.506 AbstractCamera DEBUG: autoSettleAndCapture in 132 ms
2022-01-03 17:56:14.506 Scripting TRACE: Scripting.on Camera.AfterSettle
2022-01-03 17:56:14.579 ReferenceNozzleTipCalibration TRACE: [nozzleTipCalibration]measured offset: (-0.102302, -0.050125, 0.000000, -60.000000 mm)
2022-01-03 17:56:14.579 ReferenceNozzleTipCalibration DEBUG: [nozzleTipCalibration]i: 3, measureAngle: 0.0
2022-01-03 17:56:14.579 AbstractHeadMountable DEBUG: N1.moveTo((193.716098, 136.812355, 0.000000, 0.000000 mm), 0.71)
2022-01-03 17:56:14.586 Scripting TRACE: Scripting.on Camera.BeforeSettle
2022-01-03 17:56:14.589 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M204 S669.60 G1    A0.0000  F12026.38 ; move to target, 20000)...
2022-01-03 17:56:14.589 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M204S669.6G1A0F12026.38
2022-01-03 17:56:14.589 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M400, 28169)...
2022-01-03 17:56:14.590 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M400
2022-01-03 17:56:14.589 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M114 ; get position, -1)...
2022-01-03 17:56:14.590 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M114
2022-01-03 17:56:14.590 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:56:15.188 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:56:15.189 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok C: X:244.0171 Y:98.6672 Z:0.0000 A:0.0000 B:0.0000
2022-01-03 17:56:15.190 GcodeDriver TRACE: Position report: ok C: X:244.0171 Y:98.6672 Z:0.0000 A:0.0000 B:0.0000
2022-01-03 17:56:15.190 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:244.017100, Y:98.667200, Z:0.000000, Rot_N1:0.000000, Rot_N2:0.000000)
2022-01-03 17:56:15.190 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete.
2022-01-03 17:56:15.191 Scripting TRACE: Scripting.on Camera.BeforeCapture
2022-01-03 17:56:15.212 Scripting TRACE: Scripting.on Camera.AfterCapture
2022-01-03 17:56:15.216 Scripting TRACE: Scripting.on Camera.BeforeCapture
2022-01-03 17:56:15.260 Scripting TRACE: Scripting.on Camera.AfterCapture
2022-01-03 17:56:15.264 AbstractCamera TRACE: autoSettleAndCapture t=73 auto settle score: 10.196078431372548
2022-01-03 17:56:15.264 Scripting TRACE: Scripting.on Camera.BeforeCapture
2022-01-03 17:56:15.285 Scripting TRACE: Scripting.on Camera.AfterCapture
2022-01-03 17:56:15.291 AbstractCamera TRACE: autoSettleAndCapture t=100 auto settle score: 7.0588235294117645
2022-01-03 17:56:15.291 Scripting TRACE: Scripting.on Camera.BeforeCapture
2022-01-03 17:56:15.309 Scripting TRACE: Scripting.on Camera.AfterCapture
2022-01-03 17:56:15.315 AbstractCamera TRACE: autoSettleAndCapture t=124 auto settle score: 9.019607843137255
2022-01-03 17:56:15.315 AbstractCamera DEBUG: autoSettleAndCapture in 124 ms
2022-01-03 17:56:15.315 Scripting TRACE: Scripting.on Camera.AfterSettle
2022-01-03 17:56:15.388 ReferenceNozzleTipCalibration TRACE: [nozzleTipCalibration]measured offset: (-0.076726, 0.025063, 0.000000, 0.000000 mm)
2022-01-03 17:56:15.388 ReferenceNozzleTipCalibration DEBUG: [nozzleTipCalibration]i: 4, measureAngle: 60.0
2022-01-03 17:56:15.388 AbstractHeadMountable DEBUG: N1.moveTo((193.716098, 136.812355, 0.000000, 60.000000 mm), 0.71)
2022-01-03 17:56:15.393 Scripting TRACE: Scripting.on Camera.BeforeSettle
2022-01-03 17:56:15.394 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M204 S669.60 G1    A60.0000  F12026.38 ; move to target, 20000)...
2022-01-03 17:56:15.395 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M204S669.6G1A60F12026.38
2022-01-03 17:56:15.395 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M400, 28169)...
2022-01-03 17:56:15.395 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M400
2022-01-03 17:56:15.395 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M114 ; get position, -1)...
2022-01-03 17:56:15.395 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:56:15.396 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M114
2022-01-03 17:56:15.993 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:56:15.994 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok C: X:244.0171 Y:98.6672 Z:0.0000 A:60.0000 B:0.0000
2022-01-03 17:56:15.994 GcodeDriver TRACE: Position report: ok C: X:244.0171 Y:98.6672 Z:0.0000 A:60.0000 B:0.0000
2022-01-03 17:56:15.995 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:244.017100, Y:98.667200, Z:0.000000, Rot_N1:60.000000, Rot_N2:0.000000)
2022-01-03 17:56:15.995 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete.
2022-01-03 17:56:15.996 Scripting TRACE: Scripting.on Camera.BeforeCapture
2022-01-03 17:56:16.018 Scripting TRACE: Scripting.on Camera.AfterCapture
2022-01-03 17:56:16.022 Scripting TRACE: Scripting.on Camera.BeforeCapture
2022-01-03 17:56:16.042 Scripting TRACE: Scripting.on Camera.AfterCapture
2022-01-03 17:56:16.047 AbstractCamera TRACE: autoSettleAndCapture t=51 auto settle score: 7.8431372549019605
2022-01-03 17:56:16.047 Scripting TRACE: Scripting.on Camera.BeforeCapture
2022-01-03 17:56:16.067 Scripting TRACE: Scripting.on Camera.AfterCapture
2022-01-03 17:56:16.072 AbstractCamera TRACE: autoSettleAndCapture t=76 auto settle score: 7.450980392156863
2022-01-03 17:56:16.072 Scripting TRACE: Scripting.on Camera.BeforeCapture
2022-01-03 17:56:16.100 Scripting TRACE: Scripting.on Camera.AfterCapture
2022-01-03 17:56:16.104 AbstractCamera TRACE: autoSettleAndCapture t=108 auto settle score: 7.0588235294117645
2022-01-03 17:56:16.105 AbstractCamera DEBUG: autoSettleAndCapture in 109 ms
2022-01-03 17:56:16.105 Scripting TRACE: Scripting.on Camera.AfterSettle
2022-01-03 17:56:16.177 ReferenceNozzleTipCalibration TRACE: [nozzleTipCalibration]measured offset: (-0.051151, 0.025063, 0.000000, 60.000000 mm)
2022-01-03 17:56:16.177 ReferenceNozzleTipCalibration DEBUG: [nozzleTipCalibration]i: 5, measureAngle: 120.0
2022-01-03 17:56:16.178 AbstractHeadMountable DEBUG: N1.moveTo((193.716098, 136.812355, 0.000000, 120.000000 mm), 0.71)
2022-01-03 17:56:16.185 Scripting TRACE: Scripting.on Camera.BeforeSettle
2022-01-03 17:56:16.186 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M204 S669.60 G1    A120.0000  F12026.38 ; move to target, 20000)...
2022-01-03 17:56:16.186 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M204S669.6G1A120F12026.38
2022-01-03 17:56:16.186 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M400, 28169)...
2022-01-03 17:56:16.186 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M400
2022-01-03 17:56:16.186 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M114 ; get position, -1)...
2022-01-03 17:56:16.187 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:56:16.187 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M114
2022-01-03 17:56:16.784 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:56:16.785 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok C: X:244.0171 Y:98.6672 Z:0.0000 A:120.0000 B:0.0000
2022-01-03 17:56:16.785 GcodeDriver TRACE: Position report: ok C: X:244.0171 Y:98.6672 Z:0.0000 A:120.0000 B:0.0000
2022-01-03 17:56:16.786 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:244.017100, Y:98.667200, Z:0.000000, Rot_N1:120.000000, Rot_N2:0.000000)
2022-01-03 17:56:16.786 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete.
2022-01-03 17:56:16.787 Scripting TRACE: Scripting.on Camera.BeforeCapture
2022-01-03 17:56:16.804 Scripting TRACE: Scripting.on Camera.AfterCapture
2022-01-03 17:56:16.808 Scripting TRACE: Scripting.on Camera.BeforeCapture
2022-01-03 17:56:16.838 Scripting TRACE: Scripting.on Camera.AfterCapture
2022-01-03 17:56:16.843 AbstractCamera TRACE: autoSettleAndCapture t=56 auto settle score: 9.803921568627452
2022-01-03 17:56:16.843 Scripting TRACE: Scripting.on Camera.BeforeCapture
2022-01-03 17:56:16.875 Scripting TRACE: Scripting.on Camera.AfterCapture
2022-01-03 17:56:16.880 AbstractCamera TRACE: autoSettleAndCapture t=93 auto settle score: 7.0588235294117645
2022-01-03 17:56:16.880 Scripting TRACE: Scripting.on Camera.BeforeCapture
2022-01-03 17:56:16.903 Scripting TRACE: Scripting.on Camera.AfterCapture
2022-01-03 17:56:16.908 AbstractCamera TRACE: autoSettleAndCapture t=121 auto settle score: 6.666666666666667
2022-01-03 17:56:16.909 AbstractCamera DEBUG: autoSettleAndCapture in 122 ms
2022-01-03 17:56:16.909 Scripting TRACE: Scripting.on Camera.AfterSettle
2022-01-03 17:56:16.984 ReferenceNozzleTipCalibration TRACE: [nozzleTipCalibration]measured offset: (-0.051151, 0.025063, 0.000000, 120.000000 mm)
2022-01-03 17:56:16.984 Scripting TRACE: Scripting.on NozzleCalibration.Finished
2022-01-03 17:56:17.003 Utils2D DEBUG: Correcting for reflection...
2022-01-03 17:56:17.007 ReferenceNozzleTipCalibration$ModelBasedRunoutCompensation TRACE: [nozzleTipCalibration]nozzle tip affine transform = scale (0.030550, 0.004038) shear (-5.021281, 0.0) rotation (-139.814568 deg) translation (-0.059676 mm, 0.016708 mm)
2022-01-03 17:56:17.007 ReferenceNozzleTipCalibration$ModelBasedRunoutCompensation TRACE: [nozzleTipCalibration]compare measured = (-0.025575, 0.025063, 0.000000, -180.000000 mm), modeled = (-0.051191, 0.023875, 0.000000, 0.000000 mm)
2022-01-03 17:56:17.007 ReferenceNozzleTipCalibration$ModelBasedRunoutCompensation TRACE: [nozzleTipCalibration]compare measured = (-0.051151, 0.050125, 0.000000, -120.000000 mm), modeled = (-0.061640, 0.027640, 0.000000, 0.000000 mm)
2022-01-03 17:56:17.007 ReferenceNozzleTipCalibration$ModelBasedRunoutCompensation TRACE: [nozzleTipCalibration]compare measured = (-0.102302, -0.050125, 0.000000, -60.000000 mm), modeled = (-0.070125, 0.020473, 0.000000, 0.000000 mm)
2022-01-03 17:56:17.007 ReferenceNozzleTipCalibration$ModelBasedRunoutCompensation TRACE: [nozzleTipCalibration]compare measured = (-0.076726, 0.025063, 0.000000, 0.000000 mm), modeled = (-0.068161, 0.009542, 0.000000, 0.000000 mm)
2022-01-03 17:56:17.008 ReferenceNozzleTipCalibration$ModelBasedRunoutCompensation TRACE: [nozzleTipCalibration]compare measured = (-0.051151, 0.025063, 0.000000, 60.000000 mm), modeled = (-0.057712, 0.005777, 0.000000, 0.000000 mm)
2022-01-03 17:56:17.008 ReferenceNozzleTipCalibration$ModelBasedRunoutCompensation TRACE: [nozzleTipCalibration]compare measured = (-0.051151, 0.025063, 0.000000, 120.000000 mm), modeled = (-0.049227, 0.012944, 0.000000, 0.000000 mm)
2022-01-03 17:56:17.008 ReferenceNozzleTipCalibration$ModelBasedRunoutCompensation TRACE: [nozzleTipCalibration]peak error location = (-0.102302, -0.050125, 0.000000, -60.000000 mm), error = 0.07758549335462729
2022-01-03 17:56:17.008 ReferenceNozzleTipCalibration$ModelBasedRunoutCompensation DEBUG: [nozzleTipCalibration]calculated nozzleEccentricity: Camera position offset -0.060, 0.017, Runout 0.011, Phase 139.815, Peak err 0.078, RMS err 0.037 mm
2022-01-03 17:56:17.008 AbstractHeadMountable DEBUG: N1.moveTo((193.775774, 136.795646, 0.000000, 180.000000 mm), 0.71)
2022-01-03 17:56:17.008 ReferenceNozzle TRACE: N1.toHeadLocation((193.767289, 136.788480, 0.000000, 180.000000 mm), ...) runout compensation (0.008485, 0.007167, 0.000000, 0.000000 mm)
2022-01-03 17:56:17.012 AbstractHeadMountable DEBUG: N1.moveToSafeZ(0.71)
2022-01-03 17:56:17.014 ReferenceNozzle DEBUG: N1.home() nozzle tip Tip:507 calibration reset
2022-01-03 17:56:17.014 ReferenceNozzle DEBUG: N1.home() nozzle tip Tip:504a calibration reset
2022-01-03 17:56:17.014 ReferenceNozzle DEBUG: N1.home() nozzle tip Tip:505 calibration reset
2022-01-03 17:56:17.014 ReferenceNozzle DEBUG: N2.home()
2022-01-03 17:56:17.014 ReferenceNozzle DEBUG: N2.home() nozzle tip Tip:505b calibration reset
2022-01-03 17:56:17.014 ReferenceNozzle DEBUG: N2.home() nozzle tip Tip:503b calibration neeeded
2022-01-03 17:56:17.014 Scripting TRACE: Scripting.on NozzleCalibration.Starting
2022-01-03 17:56:17.015 ReferenceHead DEBUG: H1.moveToSafeZ(0.71)
2022-01-03 17:56:17.015 AbstractHeadMountable DEBUG: N1.moveToSafeZ(0.71)
2022-01-03 17:56:17.016 AbstractHeadMountable DEBUG: N2.moveToSafeZ(0.71)
2022-01-03 17:56:17.016 AbstractHeadMountable DEBUG: HeadCamera.moveToSafeZ(0.71)
2022-01-03 17:56:17.017 AbstractHeadMountable DEBUG: N2.moveTo((193.716098, 136.812355, 0.000000, -180.000000 mm), 0.71)
2022-01-03 17:56:17.038 AbstractHeadMountable DEBUG: N2.moveTo((193.716098, 136.812355, 0.000000, -180.000000 mm), 0.71)
2022-01-03 17:56:17.039 ReferenceNozzleTipCalibration DEBUG: [nozzleTipCalibration]starting measurement; angleStart: -180.0, angleStop: 180.0, angleIncrement: 60.0, angleSubdivisions: 5
2022-01-03 17:56:17.040 ReferenceNozzleTipCalibration DEBUG: [nozzleTipCalibration]i: 0, measureAngle: -180.0
2022-01-03 17:56:17.040 AbstractHeadMountable DEBUG: N2.moveTo((193.716098, 136.812355, 0.000000, -180.000000 mm), 0.71)
2022-01-03 17:56:17.041 Scripting TRACE: Scripting.on Camera.BeforeSettle
2022-01-03 17:56:17.042 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M204 S669.60 G1 X244.0683 Y98.6433  A180.0000  F12026.39 ; move to target, 20000)...
2022-01-03 17:56:17.042 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M204S669.6G1X244.0683Y98.6433A180F12026.39
2022-01-03 17:56:17.043 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M204 S1003.19 G1 X193.4561 Y98.9035   B-180.0000 F25986.05 ; move to target, 20000)...
2022-01-03 17:56:17.043 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M204S1003.19G1X193.4561Y98.9035B-180F25986.05
2022-01-03 17:56:17.043 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M400, 28169)...
2022-01-03 17:56:17.043 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M114 ; get position, -1)...
2022-01-03 17:56:17.044 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:56:17.044 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M400
2022-01-03 17:56:17.045 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:56:17.045 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M114
2022-01-03 17:56:18.528 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:56:18.530 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok C: X:193.4561 Y:98.9035 Z:0.0000 A:180.0000 B:-180.0000
2022-01-03 17:56:18.530 GcodeDriver TRACE: Position report: ok C: X:193.4561 Y:98.9035 Z:0.0000 A:180.0000 B:-180.0000
2022-01-03 17:56:18.531 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:193.456100, Y:98.903500, Z:0.000000, Rot_N1:180.000000, Rot_N2:-180.000000)
2022-01-03 17:56:18.531 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete.
2022-01-03 17:56:18.532 Scripting TRACE: Scripting.on Camera.BeforeCapture
2022-01-03 17:56:18.558 Scripting TRACE: Scripting.on Camera.AfterCapture
2022-01-03 17:56:18.563 Scripting TRACE: Scripting.on Camera.BeforeCapture
2022-01-03 17:56:18.583 Scripting TRACE: Scripting.on Camera.AfterCapture
2022-01-03 17:56:18.588 AbstractCamera TRACE: autoSettleAndCapture t=56 auto settle score: 62.35294117647059
2022-01-03 17:56:18.588 Scripting TRACE: Scripting.on Camera.BeforeCapture
2022-01-03 17:56:18.608 Scripting TRACE: Scripting.on Camera.AfterCapture
2022-01-03 17:56:18.613 AbstractCamera TRACE: autoSettleAndCapture t=81 auto settle score: 63.52941176470588
2022-01-03 17:56:18.613 Scripting TRACE: Scripting.on Camera.BeforeCapture
2022-01-03 17:56:18.630 Scripting TRACE: Scripting.on Camera.AfterCapture
2022-01-03 17:56:18.635 AbstractCamera TRACE: autoSettleAndCapture t=103 auto settle score: 27.058823529411764
2022-01-03 17:56:18.635 AbstractCamera DEBUG: autoSettleAndCapture in 103 ms
2022-01-03 17:56:18.635 Scripting TRACE: Scripting.on Camera.AfterSettle
2022-01-03 17:56:18.671 ReferenceNozzleTipCalibration TRACE: [nozzleTipCalibration]measured offset: (-0.153453, 0.050125, 0.000000, -180.000000 mm)
2022-01-03 17:56:18.672 ReferenceNozzleTipCalibration DEBUG: [nozzleTipCalibration]i: 1, measureAngle: -120.0
2022-01-03 17:56:18.672 AbstractHeadMountable DEBUG: N2.moveTo((193.716098, 136.812355, 0.000000, -120.000000 mm), 0.71)
2022-01-03 17:56:18.676 Scripting TRACE: Scripting.on Camera.BeforeSettle
2022-01-03 17:56:18.679 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M204 S669.60 G1     B-120.0000 F12026.38 ; move to target, 20000)...
2022-01-03 17:56:18.679 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M204S669.6G1B-120F12026.38
2022-01-03 17:56:18.679 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M400, 28169)...
2022-01-03 17:56:18.680 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M400
2022-01-03 17:56:18.679 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M114 ; get position, -1)...
2022-01-03 17:56:18.680 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M114
2022-01-03 17:56:18.680 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:56:19.277 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:56:19.281 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok C: X:193.4561 Y:98.9035 Z:0.0000 A:180.0000 B:-120.0000
2022-01-03 17:56:19.281 GcodeDriver TRACE: Position report: ok C: X:193.4561 Y:98.9035 Z:0.0000 A:180.0000 B:-120.0000
2022-01-03 17:56:19.282 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:193.456100, Y:98.903500, Z:0.000000, Rot_N1:180.000000, Rot_N2:-120.000000)
2022-01-03 17:56:19.282 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete.
2022-01-03 17:56:19.284 Scripting TRACE: Scripting.on Camera.BeforeCapture
2022-01-03 17:56:19.311 Scripting TRACE: Scripting.on Camera.AfterCapture
2022-01-03 17:56:19.315 Scripting TRACE: Scripting.on Camera.BeforeCapture
2022-01-03 17:56:19.333 Scripting TRACE: Scripting.on Camera.AfterCapture
2022-01-03 17:56:19.338 AbstractCamera TRACE: autoSettleAndCapture t=54 auto settle score: 9.411764705882353
2022-01-03 17:56:19.339 Scripting TRACE: Scripting.on Camera.BeforeCapture
2022-01-03 17:56:19.365 Scripting TRACE: Scripting.on Camera.AfterCapture
2022-01-03 17:56:19.370 AbstractCamera TRACE: autoSettleAndCapture t=86 auto settle score: 7.0588235294117645
2022-01-03 17:56:19.370 Scripting TRACE: Scripting.on Camera.BeforeCapture
2022-01-03 17:56:19.397 Scripting TRACE: Scripting.on Camera.AfterCapture
2022-01-03 17:56:19.403 AbstractCamera TRACE: autoSettleAndCapture t=119 auto settle score: 7.8431372549019605
2022-01-03 17:56:19.404 AbstractCamera DEBUG: autoSettleAndCapture in 120 ms
2022-01-03 17:56:19.404 Scripting TRACE: Scripting.on Camera.AfterSettle
2022-01-03 17:56:19.440 ReferenceNozzleTipCalibration TRACE: [nozzleTipCalibration]measured offset: (-0.127877, 0.000000, 0.000000, -120.000000 mm)
2022-01-03 17:56:19.441 ReferenceNozzleTipCalibration DEBUG: [nozzleTipCalibration]i: 2, measureAngle: -60.0
2022-01-03 17:56:19.441 AbstractHeadMountable DEBUG: N2.moveTo((193.716098, 136.812355, 0.000000, -60.000000 mm), 0.71)
2022-01-03 17:56:19.448 Scripting TRACE: Scripting.on Camera.BeforeSettle
2022-01-03 17:56:19.448 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M204 S669.60 G1     B-60.0000 F12026.38 ; move to target, 20000)...
2022-01-03 17:56:19.448 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M400, 28169)...
2022-01-03 17:56:19.449 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M204S669.6G1B-60F12026.38
2022-01-03 17:56:19.449 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M114 ; get position, -1)...
2022-01-03 17:56:19.449 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M400
2022-01-03 17:56:19.449 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M114
2022-01-03 17:56:19.449 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:56:20.047 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:56:20.048 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok C: X:193.4561 Y:98.9035 Z:0.0000 A:180.0000 B:-60.0000
2022-01-03 17:56:20.048 GcodeDriver TRACE: Position report: ok C: X:193.4561 Y:98.9035 Z:0.0000 A:180.0000 B:-60.0000
2022-01-03 17:56:20.049 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:193.456100, Y:98.903500, Z:0.000000, Rot_N1:180.000000, Rot_N2:-60.000000)
2022-01-03 17:56:20.049 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete.
2022-01-03 17:56:20.050 Scripting TRACE: Scripting.on Camera.BeforeCapture
2022-01-03 17:56:20.098 Scripting TRACE: Scripting.on Camera.AfterCapture
2022-01-03 17:56:20.103 Scripting TRACE: Scripting.on Camera.BeforeCapture
2022-01-03 17:56:20.130 Scripting TRACE: Scripting.on Camera.AfterCapture
2022-01-03 17:56:20.135 AbstractCamera TRACE: autoSettleAndCapture t=86 auto settle score: 7.0588235294117645
2022-01-03 17:56:20.135 Scripting TRACE: Scripting.on Camera.BeforeCapture
2022-01-03 17:56:20.163 Scripting TRACE: Scripting.on Camera.AfterCapture
2022-01-03 17:56:20.167 AbstractCamera TRACE: autoSettleAndCapture t=118 auto settle score: 10.588235294117647
2022-01-03 17:56:20.168 AbstractCamera DEBUG: autoSettleAndCapture in 119 ms
2022-01-03 17:56:20.168 Scripting TRACE: Scripting.on Camera.AfterSettle
2022-01-03 17:56:20.203 ReferenceNozzleTipCalibration TRACE: [nozzleTipCalibration]measured offset: (-0.076726, 0.050125, 0.000000, -60.000000 mm)
2022-01-03 17:56:20.203 ReferenceNozzleTipCalibration DEBUG: [nozzleTipCalibration]i: 3, measureAngle: 0.0
2022-01-03 17:56:20.203 AbstractHeadMountable DEBUG: N2.moveTo((193.716098, 136.812355, 0.000000, 0.000000 mm), 0.71)
2022-01-03 17:56:20.207 Scripting TRACE: Scripting.on Camera.BeforeSettle
2022-01-03 17:56:20.207 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M204 S669.60 G1     B0.0000 F12026.38 ; move to target, 20000)...
2022-01-03 17:56:20.208 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M204S669.6G1B0F12026.38
2022-01-03 17:56:20.208 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M400, 28169)...
2022-01-03 17:56:20.208 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M114 ; get position, -1)...
2022-01-03 17:56:20.208 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M400
2022-01-03 17:56:20.208 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M114
2022-01-03 17:56:20.208 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:56:20.806 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:56:20.807 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok C: X:193.4561 Y:98.9035 Z:0.0000 A:180.0000 B:0.0000
2022-01-03 17:56:20.807 GcodeDriver TRACE: Position report: ok C: X:193.4561 Y:98.9035 Z:0.0000 A:180.0000 B:0.0000
2022-01-03 17:56:20.808 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:193.456100, Y:98.903500, Z:0.000000, Rot_N1:180.000000, Rot_N2:0.000000)
2022-01-03 17:56:20.808 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete.
2022-01-03 17:56:20.808 Scripting TRACE: Scripting.on Camera.BeforeCapture
2022-01-03 17:56:20.826 Scripting TRACE: Scripting.on Camera.AfterCapture
2022-01-03 17:56:20.830 Scripting TRACE: Scripting.on Camera.BeforeCapture
2022-01-03 17:56:20.867 Scripting TRACE: Scripting.on Camera.AfterCapture
2022-01-03 17:56:20.871 AbstractCamera TRACE: autoSettleAndCapture t=63 auto settle score: 6.666666666666667
2022-01-03 17:56:20.872 Scripting TRACE: Scripting.on Camera.BeforeCapture
2022-01-03 17:56:20.899 Scripting TRACE: Scripting.on Camera.AfterCapture
2022-01-03 17:56:20.904 AbstractCamera TRACE: autoSettleAndCapture t=96 auto settle score: 6.2745098039215685
2022-01-03 17:56:20.904 Scripting TRACE: Scripting.on Camera.BeforeCapture
2022-01-03 17:56:20.931 Scripting TRACE: Scripting.on Camera.AfterCapture
2022-01-03 17:56:20.936 AbstractCamera TRACE: autoSettleAndCapture t=128 auto settle score: 9.019607843137255
2022-01-03 17:56:20.936 AbstractCamera DEBUG: autoSettleAndCapture in 128 ms
2022-01-03 17:56:20.936 Scripting TRACE: Scripting.on Camera.AfterSettle
2022-01-03 17:56:20.972 ReferenceNozzleTipCalibration TRACE: [nozzleTipCalibration]measured offset: (-0.076726, 0.050125, 0.000000, 0.000000 mm)
2022-01-03 17:56:20.972 ReferenceNozzleTipCalibration DEBUG: [nozzleTipCalibration]i: 4, measureAngle: 60.0
2022-01-03 17:56:20.972 AbstractHeadMountable DEBUG: N2.moveTo((193.716098, 136.812355, 0.000000, 60.000000 mm), 0.71)
2022-01-03 17:56:20.975 Scripting TRACE: Scripting.on Camera.BeforeSettle
2022-01-03 17:56:20.976 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M204 S669.60 G1     B60.0000 F12026.38 ; move to target, 20000)...
2022-01-03 17:56:20.976 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M204S669.6G1B60F12026.38
2022-01-03 17:56:20.976 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M400, 28169)...
2022-01-03 17:56:20.976 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M114 ; get position, -1)...
2022-01-03 17:56:20.976 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M400
2022-01-03 17:56:20.977 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:56:20.977 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M114
2022-01-03 17:56:21.575 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:56:21.577 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok C: X:193.4561 Y:98.9035 Z:0.0000 A:180.0000 B:60.0000
2022-01-03 17:56:21.577 GcodeDriver TRACE: Position report: ok C: X:193.4561 Y:98.9035 Z:0.0000 A:180.0000 B:60.0000
2022-01-03 17:56:21.578 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:193.456100, Y:98.903500, Z:0.000000, Rot_N1:180.000000, Rot_N2:60.000000)
2022-01-03 17:56:21.578 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete.
2022-01-03 17:56:21.580 Scripting TRACE: Scripting.on Camera.BeforeCapture
2022-01-03 17:56:21.605 Scripting TRACE: Scripting.on Camera.AfterCapture
2022-01-03 17:56:21.610 Scripting TRACE: Scripting.on Camera.BeforeCapture
2022-01-03 17:56:21.627 Scripting TRACE: Scripting.on Camera.AfterCapture
2022-01-03 17:56:21.632 AbstractCamera TRACE: autoSettleAndCapture t=53 auto settle score: 8.235294117647058
2022-01-03 17:56:21.632 Scripting TRACE: Scripting.on Camera.BeforeCapture
2022-01-03 17:56:21.666 Scripting TRACE: Scripting.on Camera.AfterCapture
2022-01-03 17:56:21.671 AbstractCamera TRACE: autoSettleAndCapture t=92 auto settle score: 8.235294117647058
2022-01-03 17:56:21.671 Scripting TRACE: Scripting.on Camera.BeforeCapture
2022-01-03 17:56:21.699 Scripting TRACE: Scripting.on Camera.AfterCapture
2022-01-03 17:56:21.704 AbstractCamera TRACE: autoSettleAndCapture t=125 auto settle score: 7.8431372549019605
2022-01-03 17:56:21.704 AbstractCamera DEBUG: autoSettleAndCapture in 125 ms
2022-01-03 17:56:21.704 Scripting TRACE: Scripting.on Camera.AfterSettle
2022-01-03 17:56:21.744 ReferenceNozzleTipCalibration TRACE: [nozzleTipCalibration]measured offset: (-0.102302, 0.100251, 0.000000, 60.000000 mm)
2022-01-03 17:56:21.744 ReferenceNozzleTipCalibration DEBUG: [nozzleTipCalibration]i: 5, measureAngle: 120.0
2022-01-03 17:56:21.744 AbstractHeadMountable DEBUG: N2.moveTo((193.716098, 136.812355, 0.000000, 120.000000 mm), 0.71)
2022-01-03 17:56:21.749 Scripting TRACE: Scripting.on Camera.BeforeSettle
2022-01-03 17:56:21.750 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M204 S669.60 G1     B120.0000 F12026.38 ; move to target, 20000)...
2022-01-03 17:56:21.750 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M204S669.6G1B120F12026.38
2022-01-03 17:56:21.750 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M400, 28169)...
2022-01-03 17:56:21.751 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M400
2022-01-03 17:56:21.751 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M114 ; get position, -1)...
2022-01-03 17:56:21.751 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:56:21.751 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M114
2022-01-03 17:56:22.349 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:56:22.351 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok C: X:193.4561 Y:98.9035 Z:0.0000 A:180.0000 B:120.0000
2022-01-03 17:56:22.351 GcodeDriver TRACE: Position report: ok C: X:193.4561 Y:98.9035 Z:0.0000 A:180.0000 B:120.0000
2022-01-03 17:56:22.351 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:193.456100, Y:98.903500, Z:0.000000, Rot_N1:180.000000, Rot_N2:120.000000)
2022-01-03 17:56:22.351 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete.
2022-01-03 17:56:22.352 Scripting TRACE: Scripting.on Camera.BeforeCapture
2022-01-03 17:56:22.373 Scripting TRACE: Scripting.on Camera.AfterCapture
2022-01-03 17:56:22.377 Scripting TRACE: Scripting.on Camera.BeforeCapture
2022-01-03 17:56:22.397 Scripting TRACE: Scripting.on Camera.AfterCapture
2022-01-03 17:56:22.402 AbstractCamera TRACE: autoSettleAndCapture t=50 auto settle score: 9.411764705882353
2022-01-03 17:56:22.402 Scripting TRACE: Scripting.on Camera.BeforeCapture
2022-01-03 17:56:22.420 Scripting TRACE: Scripting.on Camera.AfterCapture
2022-01-03 17:56:22.424 AbstractCamera TRACE: autoSettleAndCapture t=72 auto settle score: 7.0588235294117645
2022-01-03 17:56:22.425 Scripting TRACE: Scripting.on Camera.BeforeCapture
2022-01-03 17:56:22.466 Scripting TRACE: Scripting.on Camera.AfterCapture
2022-01-03 17:56:22.471 AbstractCamera TRACE: autoSettleAndCapture t=119 auto settle score: 9.019607843137255
2022-01-03 17:56:22.471 AbstractCamera DEBUG: autoSettleAndCapture in 119 ms
2022-01-03 17:56:22.471 Scripting TRACE: Scripting.on Camera.AfterSettle
2022-01-03 17:56:22.509 ReferenceNozzleTipCalibration TRACE: [nozzleTipCalibration]measured offset: (-0.153453, 0.025063, 0.000000, 120.000000 mm)
2022-01-03 17:56:22.509 Scripting TRACE: Scripting.on NozzleCalibration.Finished
2022-01-03 17:56:22.510 ReferenceNozzleTipCalibration$ModelBasedRunoutCompensation TRACE: [nozzleTipCalibration]nozzle tip affine transform = scale (0.047467, 0.025988) shear (-0.142749, 0.0) rotation (26.103697 deg) translation (-0.115090 mm, 0.045948 mm)
2022-01-03 17:56:22.510 ReferenceNozzleTipCalibration$ModelBasedRunoutCompensation TRACE: [nozzleTipCalibration]compare measured = (-0.153453, 0.050125, 0.000000, -180.000000 mm), modeled = (-0.146629, 0.030494, 0.000000, 0.000000 mm)
2022-01-03 17:56:22.510 ReferenceNozzleTipCalibration$ModelBasedRunoutCompensation TRACE: [nozzleTipCalibration]compare measured = (-0.127877, 0.000000, 0.000000, -120.000000 mm), modeled = (-0.117476, 0.010907, 0.000000, 0.000000 mm)
2022-01-03 17:56:22.510 ReferenceNozzleTipCalibration$ModelBasedRunoutCompensation TRACE: [nozzleTipCalibration]compare measured = (-0.076726, 0.050125, 0.000000, -60.000000 mm), modeled = (-0.085936, 0.026361, 0.000000, 0.000000 mm)
2022-01-03 17:56:22.510 ReferenceNozzleTipCalibration$ModelBasedRunoutCompensation TRACE: [nozzleTipCalibration]compare measured = (-0.076726, 0.050125, 0.000000, 0.000000 mm), modeled = (-0.083550, 0.061402, 0.000000, 0.000000 mm)
2022-01-03 17:56:22.510 ReferenceNozzleTipCalibration$ModelBasedRunoutCompensation TRACE: [nozzleTipCalibration]compare measured = (-0.102302, 0.100251, 0.000000, 60.000000 mm), modeled = (-0.112703, 0.080989, 0.000000, 0.000000 mm)
2022-01-03 17:56:22.510 ReferenceNozzleTipCalibration$ModelBasedRunoutCompensation TRACE: [nozzleTipCalibration]compare measured = (-0.153453, 0.025063, 0.000000, 120.000000 mm), modeled = (-0.144243, 0.065536, 0.000000, 0.000000 mm)
2022-01-03 17:56:22.510 ReferenceNozzleTipCalibration$ModelBasedRunoutCompensation TRACE: [nozzleTipCalibration]peak error location = (-0.153453, 0.025063, 0.000000, 120.000000 mm), error = 0.04150767726400801
2022-01-03 17:56:22.510 ReferenceNozzleTipCalibration$ModelBasedRunoutCompensation DEBUG: [nozzleTipCalibration]calculated nozzleEccentricity: Camera position offset -0.115, 0.046, Runout 0.035, Phase -26.104, Peak err 0.042, RMS err 0.025 mm
2022-01-03 17:56:22.510 AbstractHeadMountable DEBUG: N2.moveTo((193.831187, 136.766407, 0.000000, 180.000000 mm), 0.71)
2022-01-03 17:56:22.511 ReferenceNozzle TRACE: N2.toHeadLocation((193.862727, 136.781860, 0.000000, 180.000000 mm), ...) runout compensation (-0.031540, -0.015454, 0.000000, 0.000000 mm)
2022-01-03 17:56:22.514 AbstractHeadMountable DEBUG: N2.moveToSafeZ(0.71)
2022-01-03 17:56:22.515 Scripting TRACE: Scripting.on Machine.AfterHoming
2022-01-03 17:56:22.515 ReferenceMachine INFO: setHomed(true)
2022-01-03 17:56:22.516 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M204 S669.60 G1 X193.6027 Y98.8729   B180.0000 F12026.42 ; move to target, 20000)...
2022-01-03 17:56:22.516 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M204S669.6G1X193.6027Y98.8729B180F12026.42
2022-01-03 17:56:22.518 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:56:35.131 AbstractHeadMountable DEBUG: N1.moveToSafeZ(0.71)
2022-01-03 17:56:35.132 ReferenceHead DEBUG: H1.moveToSafeZ(0.71)
2022-01-03 17:56:35.132 AbstractHeadMountable DEBUG: N1.moveToSafeZ(0.71)
2022-01-03 17:56:35.133 AbstractHeadMountable DEBUG: N2.moveToSafeZ(0.71)
2022-01-03 17:56:35.134 AbstractHeadMountable DEBUG: HeadCamera.moveToSafeZ(0.71)
2022-01-03 17:56:35.134 AbstractHeadMountable DEBUG: N1.moveTo((50.290000, 50.003000, 0.000000, 0.000000 mm), 0.71)
2022-01-03 17:56:35.134 ReferenceNozzle TRACE: N1.toHeadLocation((50.298485, 50.010167, 0.000000, 0.000000 mm), ...) runout compensation (-0.008485, -0.007167, 0.000000, 0.000000 mm)
2022-01-03 17:56:35.138 AbstractHeadMountable DEBUG: N1.moveTo((50.290000, 50.003000, NaN, 0.000000 mm), 0.71)
2022-01-03 17:56:35.138 ReferenceNozzle TRACE: N1.toHeadLocation((50.298485, 50.010167, 0.000000, 0.000000 mm), ...) runout compensation (-0.008485, -0.007167, 0.000000, 0.000000 mm)
2022-01-03 17:56:35.139 ReferenceActuator DEBUG: FEEDER.actuate(1.0)
2022-01-03 17:56:35.139 GcodeAsyncDriver DEBUG: serial://COM5 commandQueue.offer(FEED1, 5000)...
2022-01-03 17:56:35.140 GcodeAsyncDriver$WriterThread TRACE: [serial://COM5] >> FEED1
2022-01-03 17:56:35.140 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M204 S1182.73 G1 X100.5995 Y12.0050  A0.0000  F30636.81 ; move to target, 20000)...
2022-01-03 17:56:35.140 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M400, 28169)...
2022-01-03 17:56:35.140 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M114 ; get position, -1)...
2022-01-03 17:56:35.141 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M204S1182.73G1X100.5995Y12.005A0F30636.81
2022-01-03 17:56:35.141 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M400
2022-01-03 17:56:35.141 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M114
2022-01-03 17:56:35.141 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:56:35.151 GcodeDriver$ReaderThread TRACE: [serial://COM5] << ok
2022-01-03 17:56:36.028 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:56:36.029 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok C: X:100.5995 Y:12.0050 Z:0.0000 A:0.0000 B:180.0000
2022-01-03 17:56:36.029 GcodeDriver TRACE: Position report: ok C: X:100.5995 Y:12.0050 Z:0.0000 A:0.0000 B:180.0000
2022-01-03 17:56:36.029 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:100.599500, Y:12.005000, Z:0.000000, Rot_N1:0.000000, Rot_N2:180.000000)
2022-01-03 17:56:36.029 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete.
2022-01-03 17:56:36.030 GcodeDriver TRACE: [serial://COM5] confirmed FEED1
2022-01-03 17:56:36.030 GcodeAsyncDriver TRACE: FEEDERASYNC confirmation complete.
2022-01-03 17:56:36.031 AbstractHeadMountable DEBUG: N1.moveTo((50.290000, 50.003000, -12.500000, 0.000000 mm), 0.71)
2022-01-03 17:56:36.031 ReferenceNozzle TRACE: N1.toHeadLocation((50.298485, 50.010167, -12.500000, 0.000000 mm), ...) runout compensation (-0.008485, -0.007167, 0.000000, 0.000000 mm)
2022-01-03 17:56:36.033 ReferenceNozzle DEBUG: N1.pick()
2022-01-03 17:56:36.033 Scripting TRACE: Scripting.on Nozzle.BeforePick
2022-01-03 17:56:36.034 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M204 S2772.55 G1   Z-12.5000   F11169.81 ; move to target, 20000)...
2022-01-03 17:56:36.034 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M400, 28169)...
2022-01-03 17:56:36.034 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M204S2772.55G1Z-12.5F11169.81
2022-01-03 17:56:36.034 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M114 ; get position, -1)...
2022-01-03 17:56:36.034 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M400
2022-01-03 17:56:36.035 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:56:36.035 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M114
2022-01-03 17:56:36.168 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:56:36.170 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok C: X:100.5995 Y:12.0050 Z:-12.5000 A:0.0000 B:180.0000
2022-01-03 17:56:36.170 GcodeDriver TRACE: Position report: ok C: X:100.5995 Y:12.0050 Z:-12.5000 A:0.0000 B:180.0000
2022-01-03 17:56:36.170 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:100.599500, Y:12.005000, Z:-12.500000, Rot_N1:0.000000, Rot_N2:180.000000)
2022-01-03 17:56:36.170 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete.
2022-01-03 17:56:36.171 ReferenceActuator DEBUG: DummyPump.actuate(true)
2022-01-03 17:56:36.171 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M400, 28169)...
2022-01-03 17:56:36.171 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M114 ; get position, -1)...
2022-01-03 17:56:36.171 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M400
2022-01-03 17:56:36.172 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:56:36.172 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M114
2022-01-03 17:56:36.173 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok C: X:100.5995 Y:12.0050 Z:-12.5000 A:0.0000 B:180.0000
2022-01-03 17:56:36.174 GcodeDriver TRACE: Position report: ok C: X:100.5995 Y:12.0050 Z:-12.5000 A:0.0000 B:180.0000
2022-01-03 17:56:36.174 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:100.599500, Y:12.005000, Z:-12.500000, Rot_N1:0.000000, Rot_N2:180.000000)
2022-01-03 17:56:36.174 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete.
2022-01-03 17:56:36.174 GcodeAsyncDriver TRACE: FEEDERASYNC confirmation complete.
2022-01-03 17:56:36.176 ReferenceActuator DEBUG: Pump1.actuate(true)
2022-01-03 17:56:36.176 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M800, 20000)...
2022-01-03 17:56:36.176 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M400, 28169)...
2022-01-03 17:56:36.176 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M114 ; get position, -1)...
2022-01-03 17:56:36.176 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M800
2022-01-03 17:56:36.176 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:56:36.176 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M400
2022-01-03 17:56:36.177 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M114
2022-01-03 17:56:36.177 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:56:36.179 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok C: X:100.5995 Y:12.0050 Z:-12.5000 A:0.0000 B:180.0000
2022-01-03 17:56:36.179 GcodeDriver TRACE: Position report: ok C: X:100.5995 Y:12.0050 Z:-12.5000 A:0.0000 B:180.0000
2022-01-03 17:56:36.179 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:100.599500, Y:12.005000, Z:-12.500000, Rot_N1:0.000000, Rot_N2:180.000000)
2022-01-03 17:56:36.179 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete.
2022-01-03 17:56:36.179 GcodeAsyncDriver TRACE: FEEDERASYNC confirmation complete.
2022-01-03 17:56:36.680 Scripting TRACE: Scripting.on Nozzle.AfterPick
2022-01-03 17:56:36.680 AbstractHeadMountable DEBUG: N1.moveToSafeZ(0.71)
2022-01-03 17:56:36.681 AbstractHeadMountable DEBUG: N1.moveTo((50.290000, 50.003000, 0.000000, 0.000000 mm), 0.71)
2022-01-03 17:56:36.681 ReferenceNozzle TRACE: N1.toHeadLocation((50.298485, 50.010167, 0.000000, 0.000000 mm), ...) runout compensation (-0.008485, -0.007167, 0.000000, 0.000000 mm)
2022-01-03 17:56:36.683 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M204 S2772.55 G1   Z0.0000   F11169.81 ; move to target, 20000)...
2022-01-03 17:56:36.683 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M204S2772.55G1Z0F11169.81
2022-01-03 17:56:36.684 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:56:37.828 AbstractHeadMountable DEBUG: N1.moveToSafeZ(0.71)
2022-01-03 17:56:37.829 AbstractHeadMountable DEBUG: N1.moveTo((50.290000, 50.003000, NaN, 0.000000 mm), 0.71)
2022-01-03 17:56:37.829 ReferenceNozzle TRACE: N1.toHeadLocation((50.298485, 50.010167, 0.000000, 0.000000 mm), ...) runout compensation (-0.008485, -0.007167, 0.000000, 0.000000 mm)
2022-01-03 17:56:37.831 ReferenceActuator DEBUG: FEEDER.actuate(1.0)
2022-01-03 17:56:37.831 GcodeAsyncDriver DEBUG: serial://COM5 commandQueue.offer(FEED1, 5000)...
2022-01-03 17:56:37.832 GcodeAsyncDriver$WriterThread TRACE: [serial://COM5] >> FEED1
2022-01-03 17:56:37.832 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M400, 28169)...
2022-01-03 17:56:37.832 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M114 ; get position, -1)...
2022-01-03 17:56:37.832 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M400
2022-01-03 17:56:37.832 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M114
2022-01-03 17:56:37.832 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:56:37.834 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok C: X:100.5995 Y:12.0050 Z:0.0000 A:0.0000 B:180.0000
2022-01-03 17:56:37.834 GcodeDriver TRACE: Position report: ok C: X:100.5995 Y:12.0050 Z:0.0000 A:0.0000 B:180.0000
2022-01-03 17:56:37.836 GcodeDriver$ReaderThread TRACE: [serial://COM5] << ok
2022-01-03 17:56:37.839 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:100.599500, Y:12.005000, Z:0.000000, Rot_N1:0.000000, Rot_N2:180.000000)
2022-01-03 17:56:37.839 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete.
2022-01-03 17:56:37.839 GcodeDriver TRACE: [serial://COM5] confirmed FEED1
2022-01-03 17:56:37.840 GcodeAsyncDriver TRACE: FEEDERASYNC confirmation complete.
2022-01-03 17:56:37.841 AbstractHeadMountable DEBUG: N1.moveTo((50.290000, 50.003000, -12.500000, 0.000000 mm), 0.71)
2022-01-03 17:56:37.841 ReferenceNozzle TRACE: N1.toHeadLocation((50.298485, 50.010167, -12.500000, 0.000000 mm), ...) runout compensation (-0.008485, -0.007167, 0.000000, 0.000000 mm)
2022-01-03 17:56:37.842 ReferenceNozzle DEBUG: N1.pick()
2022-01-03 17:56:37.843 Scripting TRACE: Scripting.on Nozzle.BeforePick
2022-01-03 17:56:37.843 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M204 S2772.55 G1   Z-12.5000   F11169.81 ; move to target, 20000)...
2022-01-03 17:56:37.843 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M400, 28169)...
2022-01-03 17:56:37.844 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M204S2772.55G1Z-12.5F11169.81
2022-01-03 17:56:37.844 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M400
2022-01-03 17:56:37.844 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M114 ; get position, -1)...
2022-01-03 17:56:37.844 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:56:37.844 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M114
2022-01-03 17:56:37.978 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:56:37.979 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok C: X:100.5995 Y:12.0050 Z:-12.5000 A:0.0000 B:180.0000
2022-01-03 17:56:37.980 GcodeDriver TRACE: Position report: ok C: X:100.5995 Y:12.0050 Z:-12.5000 A:0.0000 B:180.0000
2022-01-03 17:56:37.980 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:100.599500, Y:12.005000, Z:-12.500000, Rot_N1:0.000000, Rot_N2:180.000000)
2022-01-03 17:56:37.980 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete.
2022-01-03 17:56:37.981 ReferenceActuator DEBUG: DummyPump.actuate(true)
2022-01-03 17:56:37.981 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M400, 28169)...
2022-01-03 17:56:37.981 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M114 ; get position, -1)...
2022-01-03 17:56:37.982 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M400
2022-01-03 17:56:37.982 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:56:37.982 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M114
2022-01-03 17:56:37.984 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok C: X:100.5995 Y:12.0050 Z:-12.5000 A:0.0000 B:180.0000
2022-01-03 17:56:37.985 GcodeDriver TRACE: Position report: ok C: X:100.5995 Y:12.0050 Z:-12.5000 A:0.0000 B:180.0000
2022-01-03 17:56:37.985 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:100.599500, Y:12.005000, Z:-12.500000, Rot_N1:0.000000, Rot_N2:180.000000)
2022-01-03 17:56:37.985 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete.
2022-01-03 17:56:37.985 GcodeAsyncDriver TRACE: FEEDERASYNC confirmation complete.
2022-01-03 17:56:37.986 ReferenceActuator DEBUG: Pump1.actuate(true)
2022-01-03 17:56:37.986 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M800, 20000)...
2022-01-03 17:56:37.986 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M400, 28169)...
2022-01-03 17:56:37.986 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M114 ; get position, -1)...
2022-01-03 17:56:37.988 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M800
2022-01-03 17:56:37.988 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:56:37.988 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M400
2022-01-03 17:56:37.988 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:56:37.988 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M114
2022-01-03 17:56:37.990 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok C: X:100.5995 Y:12.0050 Z:-12.5000 A:0.0000 B:180.0000
2022-01-03 17:56:37.990 GcodeDriver TRACE: Position report: ok C: X:100.5995 Y:12.0050 Z:-12.5000 A:0.0000 B:180.0000
2022-01-03 17:56:37.990 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:100.599500, Y:12.005000, Z:-12.500000, Rot_N1:0.000000, Rot_N2:180.000000)
2022-01-03 17:56:37.990 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete.
2022-01-03 17:56:37.991 GcodeAsyncDriver TRACE: FEEDERASYNC confirmation complete.
2022-01-03 17:56:38.491 Scripting TRACE: Scripting.on Nozzle.AfterPick
2022-01-03 17:56:38.491 AbstractHeadMountable DEBUG: N1.moveToSafeZ(0.71)
2022-01-03 17:56:38.491 AbstractHeadMountable DEBUG: N1.moveTo((50.290000, 50.003000, 0.000000, 0.000000 mm), 0.71)
2022-01-03 17:56:38.492 ReferenceNozzle TRACE: N1.toHeadLocation((50.298485, 50.010167, 0.000000, 0.000000 mm), ...) runout compensation (-0.008485, -0.007167, 0.000000, 0.000000 mm)
2022-01-03 17:56:38.494 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M204 S2772.55 G1   Z0.0000   F11169.81 ; move to target, 20000)...
2022-01-03 17:56:38.494 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M204S2772.55G1Z0F11169.81
2022-01-03 17:56:38.495 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:56:39.322 AbstractHeadMountable DEBUG: N1.moveToSafeZ(0.71)
2022-01-03 17:56:39.323 AbstractHeadMountable DEBUG: N1.moveTo((50.290000, 50.003000, NaN, 0.000000 mm), 0.71)
2022-01-03 17:56:39.323 ReferenceNozzle TRACE: N1.toHeadLocation((50.298485, 50.010167, 0.000000, 0.000000 mm), ...) runout compensation (-0.008485, -0.007167, 0.000000, 0.000000 mm)
2022-01-03 17:56:39.324 ReferenceActuator DEBUG: FEEDER.actuate(1.0)
2022-01-03 17:56:39.324 GcodeAsyncDriver DEBUG: serial://COM5 commandQueue.offer(FEED1, 5000)...
2022-01-03 17:56:39.324 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M400, 28169)...
2022-01-03 17:56:39.325 GcodeAsyncDriver$WriterThread TRACE: [serial://COM5] >> FEED1
2022-01-03 17:56:39.325 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M114 ; get position, -1)...
2022-01-03 17:56:39.325 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M400
2022-01-03 17:56:39.325 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M114
2022-01-03 17:56:39.325 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:56:39.326 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok C: X:100.5995 Y:12.0050 Z:0.0000 A:0.0000 B:180.0000
2022-01-03 17:56:39.327 GcodeDriver TRACE: Position report: ok C: X:100.5995 Y:12.0050 Z:0.0000 A:0.0000 B:180.0000
2022-01-03 17:56:39.327 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:100.599500, Y:12.005000, Z:0.000000, Rot_N1:0.000000, Rot_N2:180.000000)
2022-01-03 17:56:39.327 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete.
2022-01-03 17:56:39.340 GcodeDriver$ReaderThread TRACE: [serial://COM5] << ok
2022-01-03 17:56:39.340 GcodeDriver TRACE: [serial://COM5] confirmed FEED1
2022-01-03 17:56:39.340 GcodeAsyncDriver TRACE: FEEDERASYNC confirmation complete.
2022-01-03 17:56:39.341 AbstractHeadMountable DEBUG: N1.moveTo((50.290000, 50.003000, -12.500000, 0.000000 mm), 0.71)
2022-01-03 17:56:39.341 ReferenceNozzle TRACE: N1.toHeadLocation((50.298485, 50.010167, -12.500000, 0.000000 mm), ...) runout compensation (-0.008485, -0.007167, 0.000000, 0.000000 mm)
2022-01-03 17:56:39.343 ReferenceNozzle DEBUG: N1.pick()
2022-01-03 17:56:39.343 Scripting TRACE: Scripting.on Nozzle.BeforePick
2022-01-03 17:56:39.343 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M204 S2772.55 G1   Z-12.5000   F11169.81 ; move to target, 20000)...
2022-01-03 17:56:39.343 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M400, 28169)...
2022-01-03 17:56:39.343 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M114 ; get position, -1)...
2022-01-03 17:56:39.344 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M204S2772.55G1Z-12.5F11169.81
2022-01-03 17:56:39.344 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M400
2022-01-03 17:56:39.344 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:56:39.344 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M114
2022-01-03 17:56:39.478 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:56:39.479 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok C: X:100.5995 Y:12.0050 Z:-12.5000 A:0.0000 B:180.0000
2022-01-03 17:56:39.479 GcodeDriver TRACE: Position report: ok C: X:100.5995 Y:12.0050 Z:-12.5000 A:0.0000 B:180.0000
2022-01-03 17:56:39.480 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:100.599500, Y:12.005000, Z:-12.500000, Rot_N1:0.000000, Rot_N2:180.000000)
2022-01-03 17:56:39.480 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete.
2022-01-03 17:56:39.480 ReferenceActuator DEBUG: DummyPump.actuate(true)
2022-01-03 17:56:39.480 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M400, 28169)...
2022-01-03 17:56:39.480 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M114 ; get position, -1)...
2022-01-03 17:56:39.481 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M400
2022-01-03 17:56:39.481 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:56:39.481 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M114
2022-01-03 17:56:39.483 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok C: X:100.5995 Y:12.0050 Z:-12.5000 A:0.0000 B:180.0000
2022-01-03 17:56:39.483 GcodeDriver TRACE: Position report: ok C: X:100.5995 Y:12.0050 Z:-12.5000 A:0.0000 B:180.0000
2022-01-03 17:56:39.483 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:100.599500, Y:12.005000, Z:-12.500000, Rot_N1:0.000000, Rot_N2:180.000000)
2022-01-03 17:56:39.483 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete.
2022-01-03 17:56:39.484 GcodeAsyncDriver TRACE: FEEDERASYNC confirmation complete.
2022-01-03 17:56:39.485 ReferenceActuator DEBUG: Pump1.actuate(true)
2022-01-03 17:56:39.485 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M800, 20000)...
2022-01-03 17:56:39.485 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M400, 28169)...
2022-01-03 17:56:39.485 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M114 ; get position, -1)...
2022-01-03 17:56:39.486 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M800
2022-01-03 17:56:39.486 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:56:39.486 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M400
2022-01-03 17:56:39.486 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:56:39.487 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M114
2022-01-03 17:56:39.488 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok C: X:100.5995 Y:12.0050 Z:-12.5000 A:0.0000 B:180.0000
2022-01-03 17:56:39.488 GcodeDriver TRACE: Position report: ok C: X:100.5995 Y:12.0050 Z:-12.5000 A:0.0000 B:180.0000
2022-01-03 17:56:39.489 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:100.599500, Y:12.005000, Z:-12.500000, Rot_N1:0.000000, Rot_N2:180.000000)
2022-01-03 17:56:39.489 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete.
2022-01-03 17:56:39.489 GcodeAsyncDriver TRACE: FEEDERASYNC confirmation complete.
2022-01-03 17:56:39.990 Scripting TRACE: Scripting.on Nozzle.AfterPick
2022-01-03 17:56:39.990 AbstractHeadMountable DEBUG: N1.moveToSafeZ(0.71)
2022-01-03 17:56:39.990 AbstractHeadMountable DEBUG: N1.moveTo((50.290000, 50.003000, 0.000000, 0.000000 mm), 0.71)
2022-01-03 17:56:39.991 ReferenceNozzle TRACE: N1.toHeadLocation((50.298485, 50.010167, 0.000000, 0.000000 mm), ...) runout compensation (-0.008485, -0.007167, 0.000000, 0.000000 mm)
2022-01-03 17:56:39.993 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M204 S2772.55 G1   Z0.0000   F11169.81 ; move to target, 20000)...
2022-01-03 17:56:39.993 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M204S2772.55G1Z0F11169.81
2022-01-03 17:56:39.994 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:56:44.077 Scripting TRACE: Scripting.on Job.BeforeDiscard
2022-01-03 17:56:44.078 ReferenceHead DEBUG: H1.moveToSafeZ(0.71)
2022-01-03 17:56:44.078 AbstractHeadMountable DEBUG: N1.moveToSafeZ(0.71)
2022-01-03 17:56:44.079 AbstractHeadMountable DEBUG: N2.moveToSafeZ(0.71)
2022-01-03 17:56:44.080 AbstractHeadMountable DEBUG: HeadCamera.moveToSafeZ(0.71)
2022-01-03 17:56:44.081 AbstractHeadMountable DEBUG: N1.moveTo((260.344000, 107.835000, 0.000000, 0.000000 mm), 0.71)
2022-01-03 17:56:44.081 ReferenceNozzle TRACE: N1.toHeadLocation((260.352485, 107.842167, 0.000000, 0.000000 mm), ...) runout compensation (-0.008485, -0.007167, 0.000000, 0.000000 mm)
2022-01-03 17:56:44.083 AbstractHeadMountable DEBUG: N1.moveTo((260.344000, 107.835000, 0.000000, 0.000000 mm), 0.71)
2022-01-03 17:56:44.083 ReferenceNozzle TRACE: N1.toHeadLocation((260.352485, 107.842167, 0.000000, 0.000000 mm), ...) runout compensation (-0.008485, -0.007167, 0.000000, 0.000000 mm)
2022-01-03 17:56:44.085 ReferenceNozzle DEBUG: N1.place()
2022-01-03 17:56:44.085 Scripting TRACE: Scripting.on Nozzle.BeforePlace
2022-01-03 17:56:44.086 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M204 S2613.63 G1 X310.6535 Y69.6320    F25768.18 ; move to target, 20000)...
2022-01-03 17:56:44.086 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M204S2613.63G1X310.6535Y69.632F25768.18
2022-01-03 17:56:44.086 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M400, 28169)...
2022-01-03 17:56:44.086 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M400
2022-01-03 17:56:44.086 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M114 ; get position, -1)...
2022-01-03 17:56:44.087 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:56:44.087 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M114
2022-01-03 17:56:44.758 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:56:44.759 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok C: X:310.6535 Y:69.6320 Z:0.0000 A:0.0000 B:180.0000
2022-01-03 17:56:44.759 GcodeDriver TRACE: Position report: ok C: X:310.6535 Y:69.6320 Z:0.0000 A:0.0000 B:180.0000
2022-01-03 17:56:44.760 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:310.653500, Y:69.632000, Z:0.000000, Rot_N1:0.000000, Rot_N2:180.000000)
2022-01-03 17:56:44.760 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete.
2022-01-03 17:56:44.760 ReferenceActuator DEBUG: Pump1.actuate(false)
2022-01-03 17:56:44.760 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M801, 20000)...
2022-01-03 17:56:44.761 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M400, 28169)...
2022-01-03 17:56:44.761 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M801
2022-01-03 17:56:44.761 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M114 ; get position, -1)...
2022-01-03 17:56:44.761 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M400
2022-01-03 17:56:44.761 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:56:44.761 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M114
2022-01-03 17:56:44.762 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:56:44.763 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok C: X:310.6535 Y:69.6320 Z:0.0000 A:0.0000 B:180.0000
2022-01-03 17:56:44.763 GcodeDriver TRACE: Position report: ok C: X:310.6535 Y:69.6320 Z:0.0000 A:0.0000 B:180.0000
2022-01-03 17:56:44.763 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:310.653500, Y:69.632000, Z:0.000000, Rot_N1:0.000000, Rot_N2:180.000000)
2022-01-03 17:56:44.764 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete.
2022-01-03 17:56:44.764 GcodeAsyncDriver TRACE: FEEDERASYNC confirmation complete.
2022-01-03 17:56:44.765 ReferenceActuator DEBUG: DummyPump.actuate(false)
2022-01-03 17:56:44.765 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M400, 28169)...
2022-01-03 17:56:44.765 GcodeAsyncDriver DEBUG: serial://COM3 commandQueue.offer(M114 ; get position, -1)...
2022-01-03 17:56:44.766 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M400
2022-01-03 17:56:44.766 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok
2022-01-03 17:56:44.766 GcodeAsyncDriver$WriterThread TRACE: [serial://COM3] >> M114
2022-01-03 17:56:44.767 GcodeDriver$ReaderThread TRACE: [serial://COM3] << ok C: X:310.6535 Y:69.6320 Z:0.0000 A:0.0000 B:180.0000
2022-01-03 17:56:44.767 GcodeDriver TRACE: Position report: ok C: X:310.6535 Y:69.6320 Z:0.0000 A:0.0000 B:180.0000
2022-01-03 17:56:44.768 GcodeDriver TRACE: GcodeDriver got lastReportedLocation (X:310.653500, Y:69.632000, Z:0.000000, Rot_N1:0.000000, Rot_N2:180.000000)
2022-01-03 17:56:44.768 GcodeAsyncDriver TRACE: GcodeDriver confirmation complete.
2022-01-03 17:56:44.768 GcodeAsyncDriver TRACE: FEEDERASYNC confirmation complete.
2022-01-03 17:56:44.840 Scripting TRACE: Scripting.on Nozzle.AfterPlace
2022-01-03 17:56:44.840 AbstractHeadMountable DEBUG: N1.moveToSafeZ(0.71)
2022-01-03 17:56:44.841 Scripting TRACE: Scripting.on Job.AfterDiscard

[geo0rpo]

CONFIRMED!!! It works as expected!

[geo0rpo]

I will try again with  2022-01-03_13-02-54.fc5da2e but I guess it is the same thing.

Mark, a million thanks my friend, wish I could buy you a beer :)

[mark maker]

Hi geo0rpo,

> wish I could buy you a beer :)

I think I'll grant myself one in your name. 😉

I assume your next question would be why this cannot be optimized. The machine is now sitting idly,  waiting for the feed op to be completed, right?  Note: I'm talking about running a Job with multiple parts, not testing it from the GUI.

I think you should be able to do it. But no guarantees!

1. Switch off the After Actuate coordination on the feed Actuator.
   
2. Create a new Actuator with Interlock.
   https://github.com/openpnp/openpnp/wiki/Axis-Interlock-Actuator
3. Interlock Type: Signal Axes Moving
4. Assign all the Z axes of your machine.
   
5. Switch on the After Actuate coordination on the new Interlock Actuator.

If I'm not missing something, this should do the feed operations in parallel to the machine motion moving towards the feeder, but it should wait, before going down in Z.

This will interlock each time the nozzle wants to got down or up (not only in the pick, but also over the camera and in the placement), so this will add a tiny delay there. But I guess even many of these tiny delays are smaller than what you can gain by moving towards the feeder, while waiting for the feed operation to complete.

It is possible that this will not yet work in a job, because there is a Safe Z move after the feed ops. In this case I guess I could fix that in the JobProcessor, making sure the SafeZ is done before the feed ops.

I leave it to you to try if it's worth your while 😁

_Mark

To view this discussion on the web visit https://groups.google.com/d/msgid/openpnp/5c07924c-73bc-4e7e-8cdd-a9a47e2a0238n%40googlegroups.com.

[geo0rpo]

If I'm not missing something, this should do the feed operations in parallel to the machine motion moving towards the feeder, but it should wait, before going down in Z.

But is is already working this way. The head is moving towards the feeder and it waits for the feeding to complete before going down on Z.  So, the head movement is parallel to the feed operation. 

And now I see M400 sent to my controller :)

What more are you suggesting? I did not get it.

[geo0rpo]

https://www.youtube.com/watch?v=ndKhauZQ0qQ

[mark maker]

Cool, I guess this means you are using the ReferenceAutoFeeder Move before feed option, right?

That's an even better option. I wasn't aware that it only moves X/Y, but not Z, so this is perfect.

And you switched off  the Before Actuation, right?

This is a nice example of why the GcodeAsyncDriver makes sense even for a pure feeder controller. I'm happy this could now be demonstrated! 😁

_Mark

To view this discussion on the web visit https://groups.google.com/d/msgid/openpnp/48d3052e-6218-44a6-8838-72935a01074fn%40googlegroups.com.

[geo0rpo]

Here is a small test on double sided tape.

https://www.youtube.com/watch?v=z89BQnrPahQ

Yes exactly.  Move before feed option in ReferenceAutoFeeder and  switched off  the Before Actuation.

It works perfectly!!!