NOTICE! This is a static HTML version of a legacy Fiji BugZilla bug.

The Fiji project now uses GitHub Issues for issue tracking.

Please file all new issues there.

Bug 899 - IJ2 under Vista: very long delay opening image file
IJ2 under Vista: very long delay opening image file
Status: RESOLVED FIXED
Product: Fiji
Classification: Unclassified
Component: Plugins
unspecified
PC Windows
: P4 normal
Assigned To: Curtis Rueden
Depends on:
Blocks:
 
Reported: 2014-08-13 09:20 CDT by Chris
Modified: 2015-10-26 13:51 CDT
4 users (show)

See Also:

Description Chris 2014-08-13 09:20:39 CDT
Hardware: Intel 4770K 4-core at 4.4 GHz, 3 GB memory

Old IJ1 --   (v 1.49e if I recall)
--------
Any small file (10mpx 3 MB JPG or 20 MB PNG) would snap-load in under 1 second.  

New IJ2
----------
With SCIFIO disabled, load time is ~10 seconds before image appears on screen.  All cores run high during this time.  Way too long to be useful.

With SCIFIO enabled, total load time is ~30 seconds before image appears on screen.  Unusable.
  >> There is no CPU activity (ie 1%) for 22 seconds, then all cores run high for ~10 seconds, and then the image appears.

COMMENTS
The same behavior occurs with macros loading files, causing very lethargic performance especially with Setbatchmode(false).  However, once a file is loaded, image processing functions like unsharp mask and gaussian blur appear to run at the same high speed of IJ1, so that part is OK.

Presumably, "SCIFIO disabled" should be legacy IJ1 compatible -- it is not even that.  Since I started using IJ2 a week ago, this is a serious setback because I no longer have throughput I had with IJ1.  Several updates have not resolved so I bring it to yor attention.  Thank you.

Information about your version of Java:

  os.arch => x86
  os.name => Windows Vista
  os.version => 6.0
  java.version => 1.6.0_24
  java.vendor => Sun Microsystems Inc.
  java.runtime.name => Java(TM) SE Runtime Environment
  java.runtime.version => 1.6.0_24-b07
  java.vm.name => Java HotSpot(TM) Client VM
  java.vm.version => 19.1-b02
  java.vm.vendor => Sun Microsystems Inc.
  java.vm.info => mixed mode
  java.awt.graphicsenv => sun.awt.Win32GraphicsEnvironment
  java.specification.name => Java Platform API Specification
  java.specification.version => 1.6
  sun.cpu.endian => little
  sun.desktop => windows
  file.separator => \

The up-to-date check says: REMIND_LATER

Information relevant to JAVA_HOME related problems:

  JAVA_HOME is set to: C:\Users\chris\Programs\Fiji.app/java/win32/jdk1.6.0_24//jre
  imagej.dir => C:\Users\chris\Programs\Fiji.app

Information about the version of each plugin:

Activated update sites:
ImageJ: http://update.imagej.net/ (last check:20140812134706)
Fiji: http://fiji.sc/update/ (last check:20140808140226)

Files not up-to-date:
  a7f56258 (LOCAL_ONLY) 20131108015300 macros/cjb_4x4_DoAll_(3648x2736)to(1280x960).ijm
  67ead821 (LOCAL_ONLY) 20131108124601 macros/cjb_4x4_deconv3_(3648x2736)to(1920x1440).ijm
  28326cd8 (LOCAL_ONLY) 20131109053300 macros/cjb_4x4_stitch3_(1920x1440)to(1280x960).ijm
  16069083 (LOCAL_ONLY) 20131107024712 macros/cjb_DEPRECATED/cjb_4x4_deconv1_(3648x2736)to(1920x1440).ijm
  db92b79f (LOCAL_ONLY) 20131107152109 macros/cjb_DEPRECATED/cjb_4x4_deconv2_(3648x2736)to(1920x1440).ijm
  ea29c5b8 (LOCAL_ONLY) 20131107160821 macros/cjb_DEPRECATED/cjb_4x4_stitch2_(1920x1440)to(1280x960).ijm
  b50a9a74 (LOCAL_ONLY) 20131107041247 macros/cjb_DEPRECATED/cjb_4x4_stitch_(1920x1440)to(1280x960).ijm
  94e93757 (LOCAL_ONLY) 20131024100624 macros/cjb_DEPRECATED/cjb_deconv1_(3648x2736)to(1920x1440).ijm
  7eec3aa4 (LOCAL_ONLY) 20131109200335 macros/cjb_MxN_DoAll_1.ijm
  1d394c95 (LOCAL_ONLY) 20131110193310 macros/cjb_MxN_DoAll_2.ijm
  1424b4bb (LOCAL_ONLY) 20131114234949 macros/cjb_MxN_DoAll_3.ijm
  af38f778 (LOCAL_ONLY) 20131110010243 macros/cjb_MxN_deconv_1.ijm
  d4c84608 (LOCAL_ONLY) 20131110022739 macros/cjb_MxN_deconv_2.ijm
  646d46de (LOCAL_ONLY) 20131117181437 macros/cjb_MxN_deconv_3.ijm
  1b4d0706 (LOCAL_ONLY) 20131109224120 macros/cjb_MxN_stitch_1.ijm
  4b1d620b (LOCAL_ONLY) 20131110131851 macros/cjb_MxN_stitch_2.ijm
  96ae2566 (LOCAL_ONLY) 20131111000936 macros/cjb_MxN_stitch_3.ijm
  5e7df4d9 (LOCAL_ONLY) 20131025002740 macros/cjb_Quit.ijm
  0f17b9ec (LOCAL_ONLY) 20140804095937 macros/cjb_RGB_shift.ijm
  2c445345 (LOCAL_ONLY) 20140101082855 macros/cjb_beads_01.ijm
  262bc3ff (LOCAL_ONLY) 20140804084659 macros/cjb_deconv_profile_01.ijm
  d9ebe757 (LOCAL_ONLY) 20131028111802 macros/cjb_flat_field_1.ijm
  5022304f (LOCAL_ONLY) 20140514102917 macros/cjb_proc_flr_image.ijm
  dbf434fa (LOCAL_ONLY) 20140804151032 macros/cjb_restore_1.ijm
  0d62acf8 (LOCAL_ONLY) 20140811213028 macros/cjb_restore_2.ijm
  0b936a76 (LOCAL_ONLY) 20140812211831 macros/cjb_restore_3.ijm
  2c9f6e58 (LOCAL_ONLY) 20140813085252 macros/cjb_restore_4.ijm
  6d02d259 (LOCAL_ONLY) 20131105023524 macros/cjb_test.ijm
  52e4f6be (LOCAL_ONLY) 20140803160222 macros/cjb_test_sharpen.ijm
  8b86ad73 (LOCAL_ONLY) 20131128004341 macros/cjb_test_yellow.ijm
  59ed901f (LOCAL_ONLY) 20131108012234 macros/test_remote.ijm
Comment 1 Chris 2014-08-13 09:32:07 CDT
edit:
  >> File->Open.  After <enter> there is no CPU activity (ie 1%) for 22 seconds, then all cores run high for ~10 seconds, and then the image appears.
Comment 2 Chris 2014-08-13 10:13:46 CDT
Example of macro lethargy.  With IJ1 my image processing macro executed in a very respectable 6-7 seconds.  

In IJ2 with SCIFIO disabled, the same macro takes ~15 seconds to execute, high CPU activity for the full 15 seconds.  

With SCIFIO enabled [with setBatchMode(true), images suppressed], that jumps to 50 seconds.  There is the 22-second CPU idle period but it occurs after ~8 seconds into the macro.  It's as though IJ2 waits for ~22 seconds before resuming high CPU activity for the remainder 20 seconds of the macro (total 50 seconds).

The timings of this strange activity seem related to manual Open, but are "inverted."
Comment 3 Chris 2014-08-13 10:48:44 CDT
In short, there are two issues IJ2:
  1 - 10X longer image file open times (10s vs 1s of IJ1)
  2 - an additional 22-second CPU idle time when SCIFIO is enabled during File Open and during a macro that opens an image file.
Comment 4 Chris 2014-08-13 12:19:28 CDT
The delay behavior is worst, ie most obvious, when opening regular JPG files.  Mine are 10 mpx image files, typically 2-4 MB JPGs.
Comment 5 Curtis Rueden 2014-08-14 17:14:11 CDT
Thanks for the excellent bug report, Stick. This is a very serious issue which we will address as soon as possible.
Comment 6 Chris 2014-08-14 19:13:30 CDT
Sure Curtis, my pleasure.  

Also useful (give 'im an inch and he'll take a mile) .... if you or a colleague are dabbling in that area, it would be useful to give us a programmatic get/set of SCIFIO flag, eg. flag = getSCIFIOflag().  The reason macro knowledge is needed is that SCIFIO seems to treat some files differently with SCIFIO disabled (like IJ1).  

For example, with SCIFIO off, a 16-bit PNG gets opened in IJ1 style as an 8-bit RGB (like an 8-bit JPG), with I presume resolution loss due to mapping to lo-res.  With SCIFIO on, the same PNG file is opened as a 3-plane hyperstack (with the 1/3 etc color slider on bottom) preserving its original 16-bit per plane resolution.  

However, that results in a different window naming convention for SCIFIO ON|OFF after I do "Split Channels" for either state, which I then have to handle with different code paths (that's OK).  While true 16-bittiness offered by SCIFIO is very welcome, at present, without knowing SCIFIO state programmatically, I can't automate subsequent image processing.

Thanks.
Comment 7 Curtis Rueden 2014-08-15 08:21:27 CDT
Please file an issue at https://github.com/imagej/imagej-legacy/issues for the feature request regarding macro interrogation of the SCIFIO status.

As for this bug, I think I found the problem, and I fear it will take some work to resolve properly. A stack trace during the initial display of a largish image shows:

"Open..." prio=4 tid=11c85d000 nid=0x128101000 runnable [1280ff000]
   java.lang.Thread.State: RUNNABLE
	at net.imglib2.display.projector.composite.CompositeXYProjector.map(CompositeXYProjector.java:193)
	at net.imagej.display.DefaultDatasetView.rebuild(DefaultDatasetView.java:401)
	- locked <6d1c538f8> (a net.imagej.display.DefaultDatasetView)
	at net.imagej.display.DefaultImageDisplay.rebuild(DefaultImageDisplay.java:136)
	at net.imagej.display.DefaultImageDisplay.display(DefaultImageDisplay.java:274)

This is in the ImageJ2 display layer: it is trying to build a projection of the image for use in the ImageJ2 UI, even though that UI is inactive. In other words: ImageJ is doing twice as much work as necessary, rendering both the IJ1 and IJ2 image planes. Furthermore, the IJ2/ImgLib2 rendering layer is very much unoptimized at the moment, so the (unnecessary!) IJ2 part of that work tanks performance rather severely, especially with images over 1 MPx.

The proper fix is to render image data on the IJ2 side only as needed to actually paint pixels. But we'll need another design iteration of the display architecture (which has numerous problems) in order to accommodate that.

In the meantime, I'll see about putting a hack somewhere to suppress this undesirable behavior.
Comment 8 Curtis Rueden 2014-08-15 10:11:25 CDT
To avoid this sort of issue for most users most of the time, I added a toggle to the ImageJ2 options. Work (unfinished) is at:

   https://github.com/imagej/imagej-legacy/compare/ij2-sync

I'll file a PR when it's ready.
Comment 9 Curtis Rueden 2014-08-15 14:55:31 CDT
There is now a tentative fix:
  https://github.com/imagej/imagej-legacy/pull/82

Some testing would be helpful. If you check out the branch, you can build using "mvn clean package" and then copy "target/imagej-legacy-0.8.2-SNAPSHOT.jar" into your ImageJ.app/jars, deleting the old "target/imagej-legacy-0.8.1.jar".

If you then launch ImageJ and run Edit > Options > ImageJ2 you'll see a new option, "Enable ImageJ2 data structures", off by default. As long as that option stays off, performance _should_ return to what it was in the pure IJ1 days.

I tested this only lightly, since I am actually out of the office today. We will do more thorough testing on Monday, and if all is well, merge and release.
Comment 10 Chris 2014-08-16 09:16:27 CDT
Curtis, I'm not sure if your previous comment was intended for me, but I expect I don't have js build capability, unless it's included by default in the java package that runs fiji in Vista and there's a way of getting at it that I don't know.  

Nonetheless, this morning I am noting these differences:

  a) There is no new toggle (yet, expected I suppose) in Options->ImageJ that you describe.

With SCIFIO enabled .....
    
  b) If I manually open a 10 mpx 3 MB JPG there is still that 22s of CPU idle time before the image appears.  It takes a total of ~35s for the image to show up.

  c) But, if I open a 16-bit 40 MB PNG version of the same image, it shows up in ~12s with no idle time -- much better.  So there must be an improvement here.

  d) The macro that executed in ~50s a few days ago now runs in ~30s.  I see cores run high with no ~22s CPU idle time, so the idle time appears to be eliminated.  The interesting thing here is that there is no idle time either for PNGs or JPGs, which is curious because with PNGs performance agrees with (c) but for JPGs contradicts (b), to the better of course!

Moral of the story ... if you can make (b) work like (c) then I expect (not tested yet) that SetBatchMode(false) for debugging my macros will give me better performance too.
Comment 11 Chris 2014-08-16 09:31:24 CDT
After some more thought, the "curiosity" in (d) vs (b) seems to be related to setBatchMode().  I am wondering if what I'm reporting above makes any sense.
Comment 12 Curtis Rueden 2014-08-18 16:56:34 CDT
I uploaded the fix. So now you can test simply by running Help > Update and installing the updates.

Chris, I am not sure why you saw a discrepancy in your second round of testing, since this fix was not yet uploaded to the ImageJ update site. Perhaps there is an intermittent timing issue. But in any case, the fix should completely sidestep the issue, returning the behavior to pre-ImageJ2 days unless you explicitly toggle ImageJ2 syncing and/or SCIFIO in the Edit > Options > ImageJ2... dialog (which I would not recommend doing at this time).
Comment 13 Chris 2014-08-18 21:36:19 CDT
RESULTS
-------

IJ2 data structs OFF
SCIFIO ON

Manually open 3 MB 10 mpx JPG:  12s, no CPU idle
Manually open 40 MB 10 mpx 16-bit PNG: 12s, no CPU idle
Macro with 16-bit PNG: 28s, no CPU idle
Macro with JPG: not supported format (expected - due to SCIFIO not being detected yet in my macro)

IJ2 data structs OFF
SCIFIO OFF

Manually open 3 MB 10 mpx JPG:  less than 1s - crazy good
Manually open 40 MB 10 mpx 16-bit PNG: less than 2s -- crazy good
Macro with 16-bit PNG:  not supported format (expected - due to SCIFIO not being detected yet in my macro)
Macro with JPG: 18s, OK, passes

IJ2 data structs ON
SCIFIO ON

Manually open 3 MB 10 mpx JPG:  11s, no CPU idle
Manually open 40 MB 10 mpx 16-bit PNG: 11s, no CPU idle
Macro with 16-bit PNG: 28s, no CPU idle
Macro with JPG: 28s, no CPU idle

COMMENTS
--------
It looks like the new switch works.  Despite the switch, the nice thing now is that the 22s CPU idle is gone everywhere, even though I understand you didn't find it.  So it may come back to haunt us.  The issue remains also with the long file loads with IJ2 structs ON, basically ~10 sec vs ~1 sec (potential CPU idle lurking gremlin notwithstanding).  Right now thus, I would not be able to make decent use of SCIFIO on the macros where I read upwards of 36 of these image files.  Please give a heads up if you fix the load delay.
Comment 14 Chris 2014-08-19 11:02:50 CDT
If you do [test #3 JPG macro] minus [test #2 JPG macro], you get 28s-18s = 10s, the file load overhead caused by SCIFIO ON during manual load.   If you can get rid of that overhead, you'll be back to the performance of IJ1 but with the nice features of IJ2 SCIFIO.  Looking forward to a solution.
All the best,
Chris.
Comment 15 Johannes Schindelin 2014-08-19 12:08:06 CDT
> Looking forward to a solution.

Note that this is an Open Source project. That means that you can make happen what you desire to see. Or you can wait and lean on volunteers to do the work for you, at a time when their goals match yours. It is fundamentally *your* choice which route you choose.
Comment 16 Chris 2014-08-20 08:53:53 CDT
Johannes, while I know this is open source and for features specific to my projects that could also help a small group of others, I would be responsible in crafting out.  If I am not mistaken the move to IJ2 and its features was funded by the NIH, and that I presume must have been funneled to a core group of developers.  Whether Curtis is one or he could be working on IJ2 for other reasons, I don't know because I did not ask.  But who ever implemented the new functionality that impacts everyone using IJ2 at the *front* end, should be the one interested in my bug report and improve his code.  There is a good reason why there is a bug report facility in Fiji and that is what I understand it to be.
Comment 17 Curtis Rueden 2014-08-21 13:27:53 CDT
To interrogate whether SCIFIO is active in your ImageJ, you can use the OptionsService API. Here is an example Jython script:

  # @OptionsService optionsService
  from net.imagej.legacy import ImageJ2Options
  scifio = optionsService.getOptions(ImageJ2Options).isSciJavaIO()
  print("SCIFIO? " + str(scifio))

The same approach should work with any scripting language _except_ for ImageJ 1.x macros, since they do not support access to the complete Java API of ImageJ etc.

Regarding performance improvements to SCIFIO and ImageJ-Legacy: yes, they are certainly needed and planned, and will remain on the radar. But it requires a substantial retooling of the ImageJ-Common library, among other involved efforts. Thus, due to limited developer resources, I cannot promise a timeline.

Since improving SCIFIO performance is more of a feature request than a bug, and since there is a simple workaround to any performance issues (i.e.: turn off SCIFIO and ImageJ2 data structures), I am closing this bug as resolved.

In the meantime, for your 16-bit PNGs, you can force use SCIFIO via File > Import > Image... (way at the bottom of the menu! or use the Command Finder by pressing L). That way you can at least write a macro that will support all your images via case logic.
Comment 18 Chris 2014-08-21 14:57:24 CDT
I'm not yet at the level of coding Jython and the like, but I appreciate your solution offer and will return to this thread when I get up to speed.  So far macros have been working very well for me, are fast to develop and are easy to debug because of their tight relationship with menu commands. 

WRT to 16-bit PNGs ..."you can force use SCIFIO via File > Import > Image... (way at the bottom of the menu!"

Yes nice, I tried this from the menu and it worked ... I turned OFF both SCIFIO and IJ2 structs and Fiji presented the image in full 16-bit, as though both options were ON.  The same 10s delay takes place but it worked.  I got excited because this looked like a good solution for both the many 1-second JPGs and the hi-res solitary PNG as needed, but alas, macro record emitted only this line:
   run("Image... ")
without file information or other parameters in the window.  It's as though the macro script is incomplete for the command???
Comment 19 Curtis Rueden 2014-08-21 15:08:53 CDT
> alas, macro record emitted only this line: run("Image... ") without
> file information or other parameters in the window.  It's as though
> the macro script is incomplete for the command???

Right, I forgot that ImageJ2 commands do not record properly yet. The issue is that ImageJ2 commands are _not_ ImageJ 1.x plugins, and need separate handling for the recorder to emit something sensible.

It's been a known issue for quite some time, but AFAIK there was no existing issue for it. So I filed one:
   https://github.com/imagej/imagej-legacy/issues/87

And unfortunately, no workaround for this problem occurs to me at the moment.
Comment 20 Curtis Rueden 2015-10-26 13:51:58 CDT
Just a quick note that ImageJ2 commands such as File > Import > Image... were made fully macro recordable a few months ago.

See the GitHub issue (https://github.com/imagej/imagej-legacy/issues/87; now closed) for details.