running server-side script

[achessel]

hi all...

I seem to have trouble running server side script. Client side user script works (connecting to a processor manually launched), but if I try to launch a admin script from insight, an error window appear saying 'Cannot load the script: 11 error: "no processor available" contact your administrator' (and same with command line). For some reason, some script manage to launch the gui and fail after saying

Code: Select all

java.lang.Exception: java.lang.Exception: org.openmicroscopy.shoola.env.data.DSAccessException: Cannot access data.
Cannot run the script.
   at org.openmicroscopy.shoola.env.data.views.ProcessBatchCall.doStep(ProcessBatchCall.java:101)
   at org.openmicroscopy.shoola.util.concur.tasks.CompositeTask.doStep(CompositeTask.java:226)
   at org.openmicroscopy.shoola.env.data.views.CompositeBatchCall.doStep(CompositeBatchCall.java:126)
   at org.openmicroscopy.shoola.util.concur.tasks.ExecCommand.exec(ExecCommand.java:165)
   at org.openmicroscopy.shoola.util.concur.tasks.ExecCommand.run(ExecCommand.java:274)
   at org.openmicroscopy.shoola.util.concur.tasks.AsyncProcessor$Runner.run(AsyncProcessor.java:91)
   at java.lang.Thread.run(Thread.java:680)
Caused by: org.openmicroscopy.shoola.env.data.DSAccessException: Cannot access data.
Cannot run the script.
   at org.openmicroscopy.shoola.env.data.OMEROGateway.handleException(OMEROGateway.java:802)
   at org.openmicroscopy.shoola.env.data.OMEROGateway.runScript(OMEROGateway.java:6672)
   at org.openmicroscopy.shoola.env.data.OmeroImageServiceImpl.runScript(OmeroImageServiceImpl.java:902)
   at org.openmicroscopy.shoola.env.data.views.calls.ScriptRunner$1.initialize(ScriptRunner.java:74)
   at org.openmicroscopy.shoola.env.data.views.ProcessBatchCall.doStep(ProcessBatchCall.java:99)
   ... 6 more
Caused by: org.openmicroscopy.shoola.env.data.ProcessException: Cannot run script with ID:1777
   at org.openmicroscopy.shoola.env.data.OMEROGateway.runScript(OMEROGateway.java:515)
   at org.openmicroscopy.shoola.env.data.OMEROGateway.runScript(OMEROGateway.java:6670)
   ... 9 more
Caused by: omero.ResourceError
    serverStackTrace = ""
    serverExceptionClass = ""
    message = "No processor available."
   at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
   at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:39)
   at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:27)
   at java.lang.reflect.Constructor.newInstance(Constructor.java:513)
   at java.lang.Class.newInstance0(Class.java:355)
   at java.lang.Class.newInstance(Class.java:308)
   at IceInternal.BasicStream$DynamicUserExceptionFactory.createAndThrow(BasicStream.java:2243)
   at IceInternal.BasicStream.throwException(BasicStream.java:1632)
   at IceInternal.Outgoing.throwUserException(Outgoing.java:442)
   at omero.api._IScriptDelM.runScript(_IScriptDelM.java:508)
   at omero.api.IScriptPrxHelper.runScript(IScriptPrxHelper.java:662)
   at omero.api.IScriptPrxHelper.runScript(IScriptPrxHelper.java:634)
   at org.openmicroscopy.shoola.env.data.OMEROGateway.runScript(OMEROGateway.java:511)
   ... 10 more

   at org.openmicroscopy.shoola.env.ui.UserNotifierImpl.showErrorDialog(UserNotifierImpl.java:159)
   at org.openmicroscopy.shoola.env.ui.UserNotifierImpl.notifyError(UserNotifierImpl.java:246)
   at org.openmicroscopy.shoola.env.ui.UserNotifierImpl.notifyError(UserNotifierImpl.java:218)
   at org.openmicroscopy.shoola.env.ui.ActivityComponent.showException(ActivityComponent.java:480)
   at org.openmicroscopy.shoola.env.ui.ActivityComponent.actionPerformed(ActivityComponent.java:957)
   at javax.swing.AbstractButton.fireActionPerformed(AbstractButton.java:2028)
   at javax.swing.AbstractButton$Handler.actionPerformed(AbstractButton.java:2351)
   at javax.swing.DefaultButtonModel.fireActionPerformed(DefaultButtonModel.java:387)
   at javax.swing.DefaultButtonModel.setPressed(DefaultButtonModel.java:242)
   at javax.swing.plaf.basic.BasicButtonListener.mouseReleased(BasicButtonListener.java:236)
   at java.awt.Component.processMouseEvent(Component.java:6374)
   at javax.swing.JComponent.processMouseEvent(JComponent.java:3267)
   at java.awt.Component.processEvent(Component.java:6139)
   at java.awt.Container.processEvent(Container.java:2085)
   at java.awt.Component.dispatchEventImpl(Component.java:4736)
   at java.awt.Container.dispatchEventImpl(Container.java:2143)
   at java.awt.Component.dispatchEvent(Component.java:4566)
   at java.awt.LightweightDispatcher.retargetMouseEvent(Container.java:4621)
   at java.awt.LightweightDispatcher.processMouseEvent(Container.java:4282)
   at java.awt.LightweightDispatcher.dispatchEvent(Container.java:4212)
   at java.awt.Container.dispatchEventImpl(Container.java:2129)
   at java.awt.Window.dispatchEventImpl(Window.java:2478)
   at java.awt.Component.dispatchEvent(Component.java:4566)
   at java.awt.EventQueue.dispatchEventImpl(EventQueue.java:680)
   at java.awt.EventQueue.access$000(EventQueue.java:86)
   at java.awt.EventQueue$1.run(EventQueue.java:639)
   at java.awt.EventQueue$1.run(EventQueue.java:637)
   at java.security.AccessController.doPrivileged(Native Method)
   at java.security.AccessControlContext$1.doIntersectionPrivilege(AccessControlContext.java:87)
   at java.security.AccessControlContext$1.doIntersectionPrivilege(AccessControlContext.java:98)
   at java.awt.EventQueue$2.run(EventQueue.java:653)
   at java.awt.EventQueue$2.run(EventQueue.java:651)
   at java.security.AccessController.doPrivileged(Native Method)
   at java.security.AccessControlContext$1.doIntersectionPrivilege(AccessControlContext.java:87)
   at java.awt.EventQueue.dispatchEvent(EventQueue.java:650)
   at java.awt.EventDispatchThread.pumpOneEventForFilters(EventDispatchThread.java:296)
   at java.awt.EventDispatchThread.pumpEventsForFilter(EventDispatchThread.java:211)
   at java.awt.EventDispatchThread.pumpEventsForHierarchy(EventDispatchThread.java:201)
   at java.awt.EventDispatchThread.pumpEvents(EventDispatchThread.java:196)
   at java.awt.EventDispatchThread.pumpEvents(EventDispatchThread.java:188)
   at java.awt.EventDispatchThread.run(EventDispatchThread.java:122)


The server is under windows server 2008, I haven't seen anything particular about script service during install. I seem to remember it working out of the box in an ubuntu server I had for testing... Output of the diagnostic:

Code: Select all

> .\bin\omero admin diagnostics

================================================================================
OMERO Diagnostics Beta4.2.2-r8718-Beta4.2-b56
================================================================================

Commands:   java -version                  1.6.0     (C:\Windows\system32\java.EXE)
Commands:   python -V                      2.5.5     (C:\Python25\python.EXE)
Commands:   icegridnode --version          3.3.1     (C:\Ice-3.3.1\bin\icegridnode.EXE)
Commands:   icegridadmin --version         3.3.1     (C:\Ice-3.3.1\bin\icegridadmin.EXE)
Commands:   psql --version                 not found

Server:     icegridnode                    running
Server:     Blitz-0                        active (pid = 724, enabled)
Server:     DropBox                        inactive (disabled)
Server:     FileServer                     active (pid = 4480, enabled)
Server:     Indexer-0                      active (pid = 4452, enabled)
Server:     MonitorServer                  inactive (disabled)
Server:     OMERO.Glacier2                 active (pid = 5168, enabled)
Server:     OMERO.IceStorm                 active (pid = 5192, enabled)
Server:     Processor-0                    active (pid = 5200, enabled)
Server:     Repository-1                   error: node `repo' couldn't be reached:
the node is not active
Server:     Tables-0                       inactive (disabled)
Server:     TestDropBox                    inactive (enabled)

Log dir:    C:\Users\omero\Desktop\OMERO.server-Beta-4.2.2\var\log exists

Log files:  Blitz-0.log                    273.0 MB      errors=4215 warnings=73334
Log files:  Blitz-0.log.1                  512.0 MB      errors=6482 warnings=3467
Log files:  Blitz-0.log.2                  512.0 MB      errors=701  warnings=441
Log files:  DropBox.log                    12.0 KB       errors=30   warnings=0
Log files:  FileServer.log                 4.0 KB
Log files:  Indexer-0.log                  2.0 MB        errors=11   warnings=1106
Log files:  MonitorServer.log              15.0 KB       errors=15   warnings=0
Log files:  OMEROweb.log                   44.0 KB       errors=355  warnings=1
Log files:  Processor-0.log                298.0 KB      errors=0    warnings=1
Log files:  Processor-0.log.1              4.0 MB        errors=0    warnings=15
Log files:  Processor-0.log.2              4.0 MB
Log files:  Processor-0.log.3              4.0 MB
Log files:  Processor-0.log.4              4.0 MB        errors=39   warnings=314
Log files:  Tables-0.log                   n/a
Log files:  TestDropBox.log                n/a
Log files:  master.err                     0.0 KB
Log files:  master.out                     0.0 KB
Log files:  Total size                     1320.42 MB

Parsing Blitz-0.log:[line:434565] => Server restarted <=

Environment:OMERO_HOME=(unset)
Environment:OMERO_NODE=(unset)
Environment:OMERO_MASTER=(unset)
Environment:PATH=C:\Windows\system32\WindowsPowerShell\v1.0\;'C:\Program Files (x86)\Java\jre6\bin\';C:\Python25\;C:\Win
dows\system32;C:\Windows;C:\Windows\System32\Wbem;C:\Windows\System32\WindowsPowerShell\v1.0\;C:\Ice-3.3.1\bin
Environment:ICE_HOME=(unset)
Environment:LD_LIBRARY_PATH=(unset)
Environment:DYLD_LIBRARY_PATH=(unset)

OMERO data dir: 'E:\\OMERO'     Exists? True    Is writable? True
OMERO.web status... [NOT STARTED]


Did I miss anything in the install? Thanks for the answer...

[jmoore]

Hi,

could you upload your var\log\Processor-0.log* files, especially what was:

Processor-0.log.4 4.0 MB errors=39 warnings=314

nothing that the number may have changed as the log files got rolled over. Something certainly seems to have gone wrong, and that should tell us what.

Cheers,
~Josh.

[achessel]

Well it seems that a reboot of the omero server actually cured the problem. Thats what I should have begun with maybe, but the diagnostic said Processor-0 was active...

Here are the maybe relevant lines from the last Processor-0.log, from when I rebooted (I don't think the old ones are related as I had a couple issues during install), in case something interesting actually happened (before that there is megs of 'Meth: ProcessI.poll' stuff, after that it seems ok; seems something went wrong in the 2011-05-12 reboot?... ):

Code: Select all

2011-05-12 15:53:21,615 INFO  [                            omero.remote] (Thread-2  )  Meth: ProcessI.poll
2011-05-12 15:53:21,615 INFO  [                            omero.remote] (Thread-2  )  Rslt: object #0 (::omero::RInt)
{
    _val = 1
}
2011-05-12 15:54:21,628 INFO  [                            omero.remote] (Thread-2  )  Meth: ProcessI.poll
2011-05-12 15:54:21,628 INFO  [                            omero.remote] (Thread-2  )  Rslt: object #0 (::omero::RInt)
{
    _val = 1
}
2011-05-12 15:55:21,641 INFO  [                            omero.remote] (Thread-2  )  Meth: ProcessI.poll
2011-05-12 15:55:21,641 INFO  [                            omero.remote] (Thread-2  )  Rslt: object #0 (::omero::RInt)
{
    _val = 1
}
2011-05-12 15:55:54,667 INFO  [                       omero.util.Server] (MainThread) Cleanup
2011-05-12 15:55:54,667 INFO  [              omero.processor.ProcessorI] (MainThread) Cleaning up
2011-05-12 15:55:54,667 INFO  [              omero.processor.ProcessorI] (MainThread) Done
2011-05-12 15:55:54,713 INFO  [                    omero.util.Resources] (Thread-2  ) Halted
2011-05-12 15:55:56,710 WARNI [                omero.util.ServerContext] (MainThread) Connection failure: Ice.ConnectionRefusedException:
Unknown error
2011-05-12 15:55:56,710 INFO  [                       omero.util.Server] (MainThread) Stopped
2011-05-12 15:55:56,710 INFO  [                       omero.util.Server] (MainThread) ********************************************************************************
2011-05-12 16:55:01,697 INFO  [                       omero.util.Server] (MainThread) ********************************************************************************
2011-05-12 16:55:01,713 INFO  [                       omero.util.Server] (MainThread) Starting
2011-05-12 16:55:01,713 INFO  [                    omero.util.Resources] (Thread-2  ) Starting
2011-05-12 16:56:00,368 INFO  [                             omero.utils] (MainThread) Failed to get session on attempt 1
2011-05-12 16:56:10,368 INFO  [                             omero.utils] (MainThread) Failed to get session on attempt 2
2011-05-12 16:56:20,493 INFO  [              omero.processor.ProcessorI] (MainThread) Registering processor Processor -t @ Processor-0.ProcessorAdapter
2011-05-12 16:56:20,539 INFO  [                       omero.util.Server] (MainThread) Entering main loop
2011-05-24 13:01:13,934 INFO  [                       omero.util.Server] (MainThread) Cleanup
2011-05-24 13:01:14,029 INFO  [                    omero.util.Resources] (Thread-2  ) Halted
2011-05-24 13:01:14,216 INFO  [              omero.processor.ProcessorI] (MainThread) Cleaning up
2011-05-24 13:01:14,246 INFO  [              omero.processor.ProcessorI] (MainThread) Done
2011-05-24 13:01:16,415 WARNI [                omero.util.ServerContext] (MainThread) Connection failure: Ice.ConnectionRefusedException:
Unknown error
2011-05-24 13:01:16,430 INFO  [                       omero.util.Server] (MainThread) Stopped
2011-05-24 13:01:16,430 INFO  [                       omero.util.Server] (MainThread) ********************************************************************************
2011-05-24 13:02:19,660 INFO  [                       omero.util.Server] (MainThread) ********************************************************************************
2011-05-24 13:02:19,660 INFO  [                       omero.util.Server] (MainThread) Starting
2011-05-24 13:02:19,676 INFO  [                    omero.util.Resources] (Thread-2  ) Starting
2011-05-24 13:03:18,237 INFO  [                             omero.utils] (MainThread) Failed to get session on attempt 1
2011-05-24 13:03:28,237 INFO  [                             omero.utils] (MainThread) Failed to get session on attempt 2
2011-05-24 13:03:38,346 INFO  [              omero.processor.ProcessorI] (MainThread) Registering processor Processor -t @ Processor-0.ProcessorAdapter
2011-05-24 13:03:38,424 INFO  [                       omero.util.Server] (MainThread) Entering main loop
2011-05-24 13:10:55,709 INFO  [                            omero.remote] (Dummy-3   )  Meth: ProcessorI.willAccept
2011-05-24 13:10:55,770 INFO  [                            omero.remote] (Dummy-3   )  Rslt: True
2011-05-24 13:10:55,959 INFO  [                            omero.remote] (Dummy-4   )  Meth: ProcessorI.parseJob
2011-05-24 13:10:55,959 INFO  [              omero.processor.ProcessorI] (Dummy-4   ) parseJob: Session = 889c8778-a6c0-471c-976b-40e98a9309d5, JobId = 451
2011-05-24 13:10:57,207 INFO  [                omero.processor.ProcessI] (Dummy-4   ) Created 889c8778-a6c0-471c-976b-40e98a9309d5 in C:\Windows\system32\config\systemprofile\AppData\Roaming\omero\tmp\omero_RCS-PC1$\5788\processhoskcy.dir
2011-05-24 13:10:57,221 INFO  [              omero.processor.ProcessorI] (Dummy-4   ) Downloaded file: 4


[jmoore]

Good to hear that a reboot started. If you can find any "ERROR" messages in the older files, it'd be good to know how the Processor got into this "active but faulty" state, so we can prevent it from happening again.

Best wishes,
~Josh.