pick@pick-n-place:~$ /opt/openpnp/OpenPnP
WARNING: An illegal reflective access operation has occurred
WARNING: Illegal reflective access by javassist.util.proxy.SecurityActions (file:/opt/openpnp/lib/javassist-3.27.0-GA.jar) to method java.lang.ClassLoader.defineClass(java.lang.String,byte[],int,int,java.security.ProtectionDomain)
WARNING: Please consider reporting this to the maintainers of javassist.util.proxy.SecurityActions
WARNING: Use --illegal-access=warn to enable warnings of further illegal reflective access operations
WARNING: All illegal access operations will be denied in a future release
Gtk-Message: 19:56:30.936: Failed to load module "canberra-gtk-module"
2022-09-12 19:56:35.837 Main INFO: Bienvenue, Bienvenido, Willkommen, Hello, Namaskar, Welkom, Bonjour to OpenPnP version 2022-08-01_18-07-09.2a36a8d.
2022-09-12 19:56:35.843 Scripting TRACE: Scripting.on Startup
2022-09-12 19:56:35.892 CameraView DEBUG: Failed to load camera specific reticle, checking default.
2022-09-12 19:56:35.892 CameraView DEBUG: No reticle preference found.
[DBG ] FOURCC = MJPG
[ERR ] setProperty (ID=1) failed on VIDIOC_S_CTRL (errno 5)
[ERR ] getPropertyLimits (ID=2) failed on VIDIOC_QUERYCTRL (errno 22)
[ERR ] getAutoProperty (ID=2) failed on VIDIOC_G_CTRL (errno 22)
[ERR ] getPropertyLimits (ID=2) failed on VIDIOC_QUERYCTRL (errno 22)
[ERR ] getPropertyLimits (ID=2) failed on VIDIOC_QUERYCTRL (errno 22)
[ERR ] getPropertyLimits (ID=2) failed on VIDIOC_QUERYCTRL (errno 22)
[ERR ] getProperty (ID=2) failed on VIDIOC_G_CTRL (errno 22)
[ERR ] getAutoProperty (ID=2) failed on VIDIOC_G_CTRL (errno 22)
[ERR ] getAutoProperty (ID=5) failed on VIDIOC_G_CTRL (errno 22)
[ERR ] getAutoProperty (ID=5) failed on VIDIOC_G_CTRL (errno 22)
[ERR ] setProperty (ID=4) failed on VIDIOC_S_CTRL (errno 5)
2022-09-12 19:56:36.497 AbstractBroadcastingCamera TRACE: Camera HeadCamera thread 33 started.
2022-09-12 19:56:36.504 CameraView DEBUG: Failed to load camera specific reticle, checking default.
2022-09-12 19:56:36.507 CameraView DEBUG: No reticle preference found.
[DBG ] FOURCC = MJPG
[ERR ] setProperty (ID=1) failed on VIDIOC_S_CTRL (errno 5)
[ERR ] getPropertyLimits (ID=2) failed on VIDIOC_QUERYCTRL (errno 22)
[ERR ] getAutoProperty (ID=2) failed on VIDIOC_G_CTRL (errno 22)
[ERR ] getPropertyLimits (ID=2) failed on VIDIOC_QUERYCTRL (errno 22)
[ERR ] getPropertyLimits (ID=2) failed on VIDIOC_QUERYCTRL (errno 22)
[ERR ] getPropertyLimits (ID=2) failed on VIDIOC_QUERYCTRL (errno 22)
[ERR ] getProperty (ID=2) failed on VIDIOC_G_CTRL (errno 22)
[ERR ] getAutoProperty (ID=2) failed on VIDIOC_G_CTRL (errno 22)
[ERR ] getAutoProperty (ID=5) failed on VIDIOC_G_CTRL (errno 22)
[ERR ] getAutoProperty (ID=5) failed on VIDIOC_G_CTRL (errno 22)
[ERR ] setProperty (ID=4) failed on VIDIOC_S_CTRL (errno 5)
2022-09-12 19:56:36.985 AbstractBroadcastingCamera TRACE: Camera PartVerif Cam thread 35 started.
2022-09-12 19:56:40.756 AbstractMachine TRACE: Machine not enabled, task ignored.
2022-09-12 19:56:44.021 ReferenceMachine DEBUG: setEnabled(true)
2022-09-12 19:56:44.065 GcodeDriver$ReaderThread TRACE: [serial://ttyACM0] << Smoothie
2022-09-12 19:56:44.066 GcodeDriver$ReaderThread TRACE: [serial://ttyACM0] << ok
2022-09-12 19:56:47.065 GcodeDriver DEBUG: [serial://ttyACM0] >> G21 ; Set millimeters mode, 10000
2022-09-12 19:56:47.108 GcodeDriver$ReaderThread TRACE: [serial://ttyACM0] << ok
2022-09-12 19:56:47.113 GcodeDriver TRACE: [serial://ttyACM0] confirmed G21 ; Set millimeters mode
2022-09-12 19:56:47.115 GcodeDriver DEBUG: [serial://ttyACM0] >> G90 ; Set absolute positioning mode, 10000
2022-09-12 19:56:47.116 GcodeDriver$ReaderThread TRACE: [serial://ttyACM0] << ok
2022-09-12 19:56:47.117 GcodeDriver TRACE: [serial://ttyACM0] confirmed G90 ; Set absolute positioning mode
2022-09-12 19:56:58.466 ReferenceActuator DEBUG: LIGHT_TOP.actuate(true)
2022-09-12 19:56:58.468 GcodeDriver DEBUG: [serial://ttyACM0] >> M106, 10000
2022-09-12 19:56:58.469 GcodeDriver$ReaderThread TRACE: [serial://ttyACM0] << ok
2022-09-12 19:56:58.470 GcodeDriver TRACE: [serial://ttyACM0] confirmed M106
2022-09-12 19:56:58.471 Scripting TRACE: Scripting.on Camera.BeforeSettle
2022-09-12 19:56:58.723 Scripting TRACE: Scripting.on Camera.BeforeCapture
2022-09-12 19:56:58.743 Scripting TRACE: Scripting.on Camera.AfterCapture
2022-09-12 19:56:58.764 Scripting TRACE: Scripting.on Camera.AfterSettle
2022-09-12 19:56:59.120 Scripting TRACE: Scripting.on Camera.BeforeSettle
2022-09-12 19:56:59.371 Scripting TRACE: Scripting.on Camera.BeforeCapture
2022-09-12 19:56:59.402 Scripting TRACE: Scripting.on Camera.AfterCapture
2022-09-12 19:56:59.403 Scripting TRACE: Scripting.on Camera.AfterSettle
2022-09-12 19:57:02.133 Scripting TRACE: Scripting.on Camera.BeforeSettle
2022-09-12 19:57:02.383 Scripting TRACE: Scripting.on Camera.BeforeCapture
2022-09-12 19:57:02.408 Scripting TRACE: Scripting.on Camera.AfterCapture
2022-09-12 19:57:02.408 Scripting TRACE: Scripting.on Camera.AfterSettle
2022-09-12 19:57:05.567 Scripting TRACE: Scripting.on Camera.BeforeSettle
2022-09-12 19:57:05.818 Scripting TRACE: Scripting.on Camera.BeforeCapture
2022-09-12 19:57:05.867 Scripting TRACE: Scripting.on Camera.AfterCapture
2022-09-12 19:57:05.901 Scripting TRACE: Scripting.on Camera.AfterSettle
2022-09-12 19:57:06.085 ReferenceHead DEBUG: H1.moveToSafeZ(1.0)
2022-09-12 19:57:06.085 AbstractHeadMountable DEBUG: N.moveToSafeZ(1.0)
2022-09-12 19:57:06.086 AbstractHeadMountable DEBUG: HeadCamera.moveToSafeZ(1.0)
2022-09-12 19:57:06.086 AbstractHeadMountable DEBUG: HeadCamera.moveTo((84.700000, 3.800000, 0.000000, 0.000000 mm), 1.0)
2022-09-12 19:57:06.160 GcodeDriver DEBUG: [serial://ttyACM0] >> M204 S801.23 G1 X1.5000 Y1.0000   F2280.35 ; move to target, 10000
2022-09-12 19:57:06.164 GcodeDriver$ReaderThread TRACE: [serial://ttyACM0] << ok
2022-09-12 19:57:06.164 GcodeDriver TRACE: [serial://ttyACM0] confirmed M204 S801.23 G1 X1.5000 Y1.0000   F2280.35 ; move to target
2022-09-12 19:57:06.165 GcodeDriver DEBUG: [serial://ttyACM0] >> M400 ; Wait for moves to complete before returning, 10000
2022-09-12 19:57:13.819 GcodeDriver$ReaderThread TRACE: [serial://ttyACM0] << ok
2022-09-12 19:57:13.820 GcodeDriver TRACE: [serial://ttyACM0] confirmed M400 ; Wait for moves to complete before returning
2022-09-12 19:57:23.823 ReferenceHead DEBUG: H1.moveToSafeZ(1.0)
2022-09-12 19:57:23.823 AbstractHeadMountable DEBUG: N.moveToSafeZ(1.0)
2022-09-12 19:57:23.823 AbstractHeadMountable DEBUG: HeadCamera.moveToSafeZ(1.0)
2022-09-12 19:57:23.823 AbstractHeadMountable DEBUG: HeadCamera.moveTo((84.200000, 3.800000, 0.000000, 0.000000 mm), 1.0)
2022-09-12 19:57:23.839 GcodeDriver DEBUG: [serial://ttyACM0] >> M204 S666.67 G1 X1.0000    F1095.45 ; move to target, 10000
2022-09-12 19:57:23.841 GcodeDriver$ReaderThread TRACE: [serial://ttyACM0] << ok
2022-09-12 19:57:23.842 GcodeDriver TRACE: [serial://ttyACM0] confirmed M204 S666.67 G1 X1.0000    F1095.45 ; move to target
2022-09-12 19:57:23.845 GcodeDriver DEBUG: [serial://ttyACM0] >> M400 ; Wait for moves to complete before returning, 10000
2022-09-12 19:57:23.915 GcodeDriver$ReaderThread TRACE: [serial://ttyACM0] << ok
2022-09-12 19:57:23.916 GcodeDriver TRACE: [serial://ttyACM0] confirmed M400 ; Wait for moves to complete before returning
2022-09-12 19:57:33.917 AbstractMachine TRACE: Exception caught, executing pending motion: java.lang.Exception: Timed out waiting for move to complete.
	at org.openpnp.machine.reference.driver.GcodeDriver.lambda$waitForCompletion$4(GcodeDriver.java:873)
	at org.openpnp.machine.reference.driver.GcodeDriver.receiveResponses(GcodeDriver.java:1145)
	at org.openpnp.machine.reference.driver.GcodeDriver.waitForCompletion(GcodeDriver.java:870)
	at org.openpnp.machine.reference.driver.AbstractMotionPlanner.waitForDriverCompletion(AbstractMotionPlanner.java:799)
	at org.openpnp.machine.reference.driver.AbstractMotionPlanner.waitForCompletion(AbstractMotionPlanner.java:716)
	at org.openpnp.machine.reference.driver.NullMotionPlanner.moveTo(NullMotionPlanner.java:50)
	at org.openpnp.machine.reference.ReferenceHead.moveTo(ReferenceHead.java:150)
	at org.openpnp.spi.base.AbstractHeadMountable.moveTo(AbstractHeadMountable.java:242)
	at org.openpnp.util.MovableUtils.moveToLocationAtSafeZ(MovableUtils.java:50)
	at org.openpnp.util.MovableUtils.moveToLocationAtSafeZ(MovableUtils.java:57)
	at org.openpnp.machine.reference.solutions.VisionSolutions.zeroKnowledgeMoveTo(VisionSolutions.java:1463)
	at org.openpnp.machine.reference.solutions.VisionSolutions.autoCalibrateCamera(VisionSolutions.java:1248)
	at org.openpnp.machine.reference.solutions.VisionSolutions$1.lambda$setState$0(VisionSolutions.java:390)
	at org.openpnp.spi.base.AbstractMachine$1.call(AbstractMachine.java:571)
	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
	at java.base/java.lang.Thread.run(Thread.java:829)
2022-09-12 19:57:33.922 GcodeDriver DEBUG: [serial://ttyACM0] >> M400 ; Wait for moves to complete before returning, 10000
2022-09-12 19:57:33.923 GcodeDriver$ReaderThread TRACE: [serial://ttyACM0] << ok
2022-09-12 19:57:33.929 GcodeDriver TRACE: [serial://ttyACM0] confirmed M400 ; Wait for moves to complete before returning
2022-09-12 19:57:33.931 MessageBoxes DEBUG: Error: java.lang.Exception: Timed out waiting for move to complete.
^CLOGGER ERROR: Failed to write log entry (java.io.IOException: Stream Closed)
2022-09-12 19:59:29.299 GcodeDriver$ReaderThread ERROR: Read error: java.io.IOException: Read error.
	at org.openpnp.machine.reference.driver.SerialPortCommunications.read(SerialPortCommunications.java:147)
	at org.openpnp.machine.reference.driver.ReferenceDriverCommunications.readUntil(ReferenceDriverCommunications.java:92)
	at org.openpnp.machine.reference.driver.ReferenceDriverCommunications.readLine(ReferenceDriverCommunications.java:72)
	at org.openpnp.machine.reference.driver.GcodeDriver$ReaderThread.run(GcodeDriver.java:1274)
pick@pick-n-place:~$