CommandService returns null instead of Future

ij2command
scijava
Tags: #<Tag:0x00007fb87ad0fa68> #<Tag:0x00007fb87ad0f928>

#1

Hi All,

@ctrueden @imagejan

I am using the CommandService to run a command. This works in principle, however it does not return a future but null in below code.

  1. Can I do something to make it return a valid future?

  2. Can I influence what is returned by the future.get() method? I guess this would have to happen partly in the executed command?


#2

Could you try enabling debug mode via logService.setLevel(LogLevel.DEBUG)? And see if any more information is produced when you call commandService.run then?


#3

Is the RotateImageCommand picked up as a Command at all? Is it shown in the menu when you start your project with a UI?


#4

Hi All,

Thanks for the answers!

I did some changes to my pom (for other reasons) and now it does return a valid future object; unfortunately I don’t understand why, but OK, nice it works now :slight_smile:

However, now I am stuck at the next step, which is that the future.get() method does not return.

Using the debugger I can see that it executes all the steps in the run() method of the Command to be executed:

Below is the output of the LogService:

[INFO] Overriding Test; identifier: command:LocalSSH; jar: file:/Users/tischer/Documents/fiji-slurm/target/test-classes/
[DEBUG] publish(
	context = org.scijava.Context@1976f674
	consumed = false
	module = de.embl.cba.cluster.commands.RotateImageCommand,null,null), called from non-EDT Thread:null
[DEBUG] publish(
	context = org.scijava.Context@1976f674
	consumed = false
	progress = -1
	maximum = -1
	status = Running command: Rotate Image
	warning = false,null,null), called from non-EDT Thread:null
[DEBUG] publish(
	context = org.scijava.Context@1976f674
	consumed = false
	module = de.embl.cba.cluster.commands.RotateImageCommand,null,null), called from non-EDT Thread:null
[INFO] # Rotate Image
[INFO] Loading: /Users/tischer/Documents/fiji-slurm/src/test/resources/horizontal-line.tif
[INFO] Rotating by [degrees]: 50.0
[INFO] Saving: /Users/tischer/Documents/fiji-slurm/src/test/resources/horizontal-line-rot.tif
[INFO] Done.
[DEBUG] publish(
	context = org.scijava.Context@1976f674
	consumed = false
	module = de.embl.cba.cluster.commands.RotateImageCommand,null,null), called from non-EDT Thread:null
[DEBUG] publish(
	context = org.scijava.Context@1976f674
	consumed = false
	module = de.embl.cba.cluster.commands.RotateImageCommand,null,null), called from non-EDT Thread:null
[DEBUG] publish(
	context = org.scijava.Context@1976f674
	consumed = false
	progress = -1
	maximum = -1
	status = Command finished: Rotate Image
	warning = false,null,null), called from non-EDT Thread:null
[DEBUG] publish(
	context = org.scijava.Context@1976f674
	consumed = false
	module = RotateImageDemo,null,null), called from non-EDT Thread:null
[DEBUG] INPUTS:
[DEBUG] 	threadService = org.scijava.thread.DefaultThreadService [priority = 0.0]
[DEBUG] 	password = aaa
[DEBUG] 	statusService = org.scijava.app.DefaultStatusService [priority = 0.0]
[DEBUG] 	opService = net.imagej.ops.DefaultOpService [priority = 0.0]
[DEBUG] 	datasetService = io.scif.services.SCIFIODatasetService [priority = 1.0]
[DEBUG] 	logService = org.scijava.log.StderrLogService [priority = -100.0]
[DEBUG] 	uiService = org.scijava.ui.DefaultUIService [priority = 0.0]
[DEBUG] 	commandService = org.scijava.command.DefaultCommandService [priority = 0.0]
[DEBUG] OUTPUTS:
[DEBUG] publish(
	context = org.scijava.Context@1976f674
	consumed = false
	module = RotateImageDemo
	processor = org.scijava.module.process.DebugPostprocessor@2da8984f,null,null), called from non-EDT Thread:null
[DEBUG] publish(
	context = org.scijava.Context@1976f674
	consumed = false
	module = RotateImageDemo
	processor = net.imagej.table.process.ResultsPostprocessor@55d61f6b,null,null), called from non-EDT Thread:null
[DEBUG] publish(
	context = org.scijava.Context@1976f674
	consumed = false
	module = RotateImageDemo
	processor = net.imagej.legacy.plugin.MacroRecorderPostprocessor@126e9f62,null,null), called from non-EDT Thread:null
[DEBUG] publish(
	context = org.scijava.Context@1976f674
	consumed = false
	module = RotateImageDemo
	processor = org.scijava.display.DisplayPostprocessor@16a36169,null,null), called from non-EDT Thread:null
[DEBUG] publish(
	context = org.scijava.Context@1976f674
	consumed = false
	module = RotateImageDemo,null,null), called from non-EDT Thread:null
[DEBUG] publish(
	context = org.scijava.Context@1976f674
	consumed = false
	progress = -1
	maximum = -1
	status = Command finished: Test
	warning = false,null,null), called from non-EDT Thread:null

#5

What is that SciJava thread doing, then? If you generate a stack trace, what do you see? Check If ImageJ freezes or hangs for instructions.


#6

Please find the stack trace below:

"AWT-EventQueue-0" prio=6 id=17 group=main
   java.lang.Thread.State: RUNNABLE
	at java.security.AccessController.doPrivileged(Native Method)
	at java.security.ProtectionDomain$JavaSecurityAccessImpl.doIntersectionPrivilege(ProtectionDomain.java:80)
	at java.security.ProtectionDomain$JavaSecurityAccessImpl.doIntersectionPrivilege(ProtectionDomain.java:90)
	at java.awt.EventQueue$4.run(EventQueue.java:731)
	at java.awt.EventQueue$4.run(EventQueue.java:729)
	at java.security.AccessController.doPrivileged(Native Method)
	at java.security.ProtectionDomain$JavaSecurityAccessImpl.doIntersectionPrivilege(ProtectionDomain.java:80)
	at java.awt.EventQueue.dispatchEvent(EventQueue.java:728)
	at java.awt.EventDispatchThread.pumpOneEventForFilters(EventDispatchThread.java:201)
	at java.awt.EventDispatchThread.pumpEventsForFilter(EventDispatchThread.java:116)
	at java.awt.EventDispatchThread.pumpEventsForHierarchy(EventDispatchThread.java:105)
	at java.awt.EventDispatchThread.pumpEvents(EventDispatchThread.java:101)
	at java.awt.EventDispatchThread.pumpEvents(EventDispatchThread.java:93)
	at java.awt.EventDispatchThread.run(EventDispatchThread.java:82)

"AWT-Shutdown" prio=5 id=14 group=system
   java.lang.Thread.State: WAITING
	at java.lang.Object.wait(Native Method)
	at java.lang.Object.wait(Object.java:502)
	at sun.awt.AWTAutoShutdown.run(AWTAutoShutdown.java:295)
	at java.lang.Thread.run(Thread.java:748)

"AppKit Thread" daemon prio=5 id=13 group=system
   java.lang.Thread.State: RUNNABLE

"DestroyJavaVM" prio=5 id=24 group=main
   java.lang.Thread.State: RUNNABLE

"Finalizer" daemon prio=8 id=3 group=system
   java.lang.Thread.State: WAITING
	at java.lang.Object.wait(Native Method)
	at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:143)
	at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:164)
	at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:209)

"Java2D Disposer" daemon prio=10 id=16 group=system
   java.lang.Thread.State: WAITING
	at java.lang.Object.wait(Native Method)
	at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:143)
	at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:164)
	at sun.java2d.Disposer.run(Disposer.java:148)
	at java.lang.Thread.run(Thread.java:748)

"Java2D Queue Flusher" daemon prio=10 id=15 group=system
   java.lang.Thread.State: TIMED_WAITING
	at java.lang.Object.wait(Native Method)
	at sun.java2d.opengl.OGLRenderQueue$QueueFlusher.run(OGLRenderQueue.java:203)

"Reference Handler" daemon prio=10 id=2 group=system
   java.lang.Thread.State: WAITING
	at java.lang.Object.wait(Native Method)
	at java.lang.Object.wait(Object.java:502)
	at java.lang.ref.Reference.tryHandlePending(Reference.java:191)
	at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:153)

"Run$_SciJava-28b32300-Thread-2" prio=5 id=23 group=main
   java.lang.Thread.State: TIMED_WAITING
	at sun.misc.Unsafe.park(Native Method)
	at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
	at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460)
	at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)
	at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941)
	at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1073)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at java.lang.Thread.run(Thread.java:748)

"SciJava-28b32300-Thread-0" prio=5 id=21 group=main
   java.lang.Thread.State: RUNNABLE
	at java.lang.Thread.dumpThreads(Native Method)
	at java.lang.Thread.getAllStackTraces(Thread.java:1610)
	at org.scijava.plugins.commands.debug.DumpStack.run(DumpStack.java:81)
	at org.scijava.command.CommandModule.run(CommandModule.java:199)
	at org.scijava.module.ModuleRunner.run(ModuleRunner.java:168)
	at org.scijava.module.ModuleRunner.call(ModuleRunner.java:127)
	at org.scijava.module.ModuleRunner.call(ModuleRunner.java:66)
	at org.scijava.thread.DefaultThreadService$3.call(DefaultThreadService.java:238)
	at java.util.concurrent.FutureTask.run$$$capture(FutureTask.java:266)
	at java.util.concurrent.FutureTask.run(FutureTask.java)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at java.lang.Thread.run(Thread.java:748)

"SciJava-28b32300-Thread-1" prio=5 id=22 group=main
   java.lang.Thread.State: TIMED_WAITING
	at sun.misc.Unsafe.park(Native Method)
	at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
	at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460)
	at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)
	at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941)
	at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1073)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at java.lang.Thread.run(Thread.java:748)

"Signal Dispatcher" daemon prio=9 id=4 group=system
   java.lang.Thread.State: RUNNABLE

"Timer-0" daemon prio=5 id=18 group=main
   java.lang.Thread.State: TIMED_WAITING
	at java.lang.Object.wait(Native Method)
	at java.util.TimerThread.mainLoop(Timer.java:552)
	at java.util.TimerThread.run(Timer.java:505)

"TimerQueue" daemon prio=5 id=25 group=system
   java.lang.Thread.State: WAITING
	at sun.misc.Unsafe.park(Native Method)
	at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
	at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
	at java.util.concurrent.DelayQueue.take(DelayQueue.java:211)
	at javax.swing.TimerQueue.run(TimerQueue.java:174)
	at java.lang.Thread.run(Thread.java:748)

#7

Thanks @Christian_Tischer. But I am confused. Are you sure future.get() is not returning? Because if it is stuck, you should see a call to get() in the stack trace somewhere, on whatever thread is doing the blocking call.

Is the issue just that the program isn’t quitting? Or that it does quit, but too early? If the latter, it could be because your code calls System.exit(0) which (if I read it correctly) will happen as part of the command execution.


#8

Many thanks also to you @ctrueden for looking into this!

Man, I am really sorry and I don’t know what is going on. In fact, it does return now!
I am really sorry for asking all this stuff that somehow resolves itself…!

OK, but maybe now finally one question that hopefully does make some sense: How could i populate the outputs (or resolvedOutputs) of the Command? Do I somehow have to turn the Command into a CommandModule? If so, is there somewhere an example for this?

Below is what the future that I am getting looks like:


#9

In your RotateImageCommand, declare outputs as follows:

@Parameter(type = ItemIO.OUTPUT)
private String message;

and then in your run() method you can assign them as normal; e.g.:

public void run() {
  // ... do lots of things
  message = "Everything worked perfectly.";
}

And then the message will be available from the CommandModule instance by calling getOutput("message").