[SCIFIO] SCIFIO does not seem to release memory of closed, images
Mark Hiner
hinerm at gmail.com
Tue Jul 15 11:18:05 CDT 2014
Hello again Burkhard,
Thank you for your persistence in this issue. After looking at it again
today, I realized that there must be a memory leak in how we try to map and
synchronize ImageJ 1.x ImagePluses with ImageJ2 data structures.
Indeed, that was exactly what I found... however, the solution is
non-trivial.
I have filed a new issue for this here:
https://github.com/imagej/imagej-legacy/issues/67. It is something I would
like to resolve quickly, but because it is an involved issue that requires
additional investigation and discussion, it's at a lower priority than some
necessary grant work this week.
Thanks again for the report - it is, at least, good to know where the
problem is now.
- Mark
On Mon, Jul 14, 2014 at 1:39 PM, Burkhard Höckendorf <
burkhard.hoeckendorf at web.de> wrote:
> Hi Mark,
>
> Thanks for the speedy response. I've rewritten my macro to perhaps
> illustrate my point more clearly. It now opens the file and immediately
> closes it again, for 50 iterations.
>
> With scifio enabled I do not get an out of memory error, but it still
> accumulates memory to the point that it can not open the entire image
> anymore but instead opens virtual stacks. Without scifio this does not
> occur.
>
> Also note that reading the full image into memory without scifio is
> performance-wise much closer to opening a scifio virtual image than reading
> the full image with scifio.
>
> Below is the macro and its output.
> Best,
> Burkhard
>
> nOpenTimes = 50;
> file = "/path/to/image";
>
> for (i=1; i<=nOpenTimes; i+=1) {
> msToOpen = getTime();
> open(file);
> msToOpen = getTime() - msToOpen;
>
> msg = ""+ i +": "+ IJ.currentMemory() +" mem, "+ msToOpen +" ms";
> if (is("Virtual Stack"))
> msg += " (virtual)";
> print(msg);
>
> close();
> }
>
> Using SCIFIO:
> 1: 3822648536 mem, 15984 ms
> 2: 7572956280 mem, 14986 ms
> 3: 9998931400 mem, 14821 ms
> 4: 13784264296 mem, 14895 ms
> 5: 16885256128 mem, 15019 ms
> 6: 19656427040 mem, 15036 ms
> 7: 24079096808 mem, 15212 ms
> 8: 27510832552 mem, 15179 ms
> 9: 32077394688 mem, 15427 ms
> 10: 34409304040 mem, 15482 ms
> 11: 36859610432 mem, 15227 ms
> 12: 43061552320 mem, 15607 ms
> 13: 42104714576 mem, 15359 ms
> 14: 47910156296 mem, 15073 ms
> 15: 48044651592 mem, 3053 ms (virtual)
> 16: 48170004824 mem, 2502 ms (virtual)
> 17: 48295208256 mem, 2522 ms (virtual)
> 18: 48422832064 mem, 2495 ms (virtual)
> 19: 48550863920 mem, 2504 ms (virtual)
> 20: 48228290696 mem, 2615 ms (virtual)
> 21: 48343976264 mem, 2482 ms (virtual)
> 22: 48461224352 mem, 2495 ms (virtual)
> 23: 48577275224 mem, 2482 ms (virtual)
> 24: 48696021320 mem, 2493 ms (virtual)
> 25: 48815302152 mem, 2513 ms (virtual)
> 26: 48512671680 mem, 2682 ms (virtual)
> 27: 48624380048 mem, 2493 ms (virtual)
> 28: 48734321624 mem, 2487 ms (virtual)
> 29: 48847280096 mem, 2504 ms (virtual)
> 30: 48958189928 mem, 2491 ms (virtual)
> 31: 49069385672 mem, 2499 ms (virtual)
> 32: 48787137328 mem, 2614 ms (virtual)
> 33: 48896061816 mem, 2500 ms (virtual)
> 34: 49004784912 mem, 2488 ms (virtual)
> 35: 49116572664 mem, 2516 ms (virtual)
> 36: 49226035440 mem, 2497 ms (virtual)
> 37: 49334418896 mem, 2500 ms (virtual)
> 38: 49074728512 mem, 2660 ms (virtual)
> 39: 49183254768 mem, 2506 ms (virtual)
> 40: 49290891152 mem, 2491 ms (virtual)
> 41: 49399382336 mem, 2499 ms (virtual)
> 42: 49505843008 mem, 2487 ms (virtual)
> 43: 49613438808 mem, 2487 ms (virtual)
> 44: 49721198184 mem, 2481 ms (virtual)
> 45: 49441266864 mem, 2709 ms (virtual)
> 46: 49548934656 mem, 2485 ms (virtual)
> 47: 49656785920 mem, 2501 ms (virtual)
> 48: 49764127512 mem, 2480 ms (virtual)
> 49: 49872069552 mem, 2495 ms (virtual)
> 50: 49979814216 mem, 2482 ms (virtual)
>
> Not using SCIFIO:
> 1: 3107094592 mem, 3921 ms
> 2: 3109153032 mem, 3837 ms
> 3: 3109836568 mem, 3631 ms
> 4: 3109512264 mem, 3581 ms
> 5: 3109478728 mem, 3633 ms
> 6: 3123692656 mem, 4145 ms
> 7: 3112714624 mem, 3301 ms
> 8: 3128373632 mem, 3202 ms
> 9: 3117798216 mem, 3235 ms
> 10: 3133595872 mem, 3190 ms
> 11: 3123048664 mem, 3229 ms
> 12: 5754899128 mem, 3404 ms
> 13: 3128308704 mem, 3307 ms
> 14: 3117759024 mem, 3219 ms
> 15: 5910573440 mem, 3112 ms
> 16: 5488969832 mem, 3222 ms
> 17: 3112824736 mem, 3273 ms
> 18: 3128647888 mem, 3147 ms
> 19: 3118094280 mem, 3208 ms
> 20: 5902184440 mem, 3281 ms
> 21: 3123372736 mem, 3224 ms
> 22: 3112825408 mem, 3259 ms
> 23: 3128648960 mem, 3146 ms
> 24: 3118100760 mem, 3230 ms
> 25: 3133941888 mem, 3119 ms
> 26: 5488982136 mem, 3225 ms
> 27: 3112820248 mem, 3249 ms
> 28: 3128655064 mem, 3154 ms
> 29: 3118110296 mem, 3241 ms
> 30: 3133956392 mem, 3176 ms
> 31: 3123381976 mem, 3220 ms
> 32: 3112831584 mem, 3264 ms
> 33: 3128664576 mem, 3170 ms
> 34: 3118103400 mem, 3209 ms
> 35: 3133956744 mem, 3163 ms
> 36: 3123387312 mem, 3233 ms
> 37: 3112827304 mem, 3279 ms
> 38: 3128664688 mem, 3158 ms
> 39: 3118115152 mem, 3256 ms
> 40: 3133956432 mem, 3128 ms
> 41: 5488994224 mem, 3214 ms
> 42: 5746873888 mem, 3266 ms
> 43: 3128666592 mem, 3174 ms
> 44: 3118109984 mem, 3215 ms
> 45: 3133949360 mem, 3131 ms
> 46: 3123388320 mem, 3207 ms
> 47: 3112843792 mem, 3269 ms
> 48: 3128683960 mem, 3144 ms
> 49: 5617941896 mem, 3201 ms
> 50: 5902216016 mem, 3131 ms
>
>
> Date: Mon, 14 Jul 2014 08:34:45 -0500
>> From: Mark Hiner <hinerm at gmail.com>
>> To: Burkhard H?ckendorf <burkhard.hoeckendorf at web.de>
>> Cc: "scifio at scif.io" <scifio at scif.io>
>> Subject: Re: [SCIFIO] SCIFIO does not seem to release memory of closed
>> images
>> Message-ID:
>> <CA+B=mGqx47SkUzM_FHGkoyAy3vbpf8+NMMbURUOSJ65UfeCf3w at mail.
>> gmail.com>
>> Content-Type: text/plain; charset="utf-8"
>>
>> Hi Burkhard,
>>
>> > run("Collect Garbage");
>>
>> This just calls System.gc().. twice, actually. There are many articles
>> and
>> StackOverflow posts about why System.gc() is unreliable
>> <http://stackoverflow.com/questions/2414105/why-is-it-a-
>> bad-practice-to-call-system-gc>.
>> I personally have seen endlessly repeated System.gc() calls effectively do
>> nothing, necessitating the creation of large objects to force memory to be
>> released.
>>
>> Also, the JVM should automatically attempt to run the garbage collector
>> when memory is requested for allocation in excess of the JVM's memory
>> limits. So the best way to test if SCIFIO has a memory leak would be:
>>
>> 1) Open datasets that occupy slightly less than the max memory allocated
>> to
>> your Fiji
>> 2) Close these datasets
>> 3) Try opening more datasets (of a size such that, if the original
>> datasets
>> not released, the total memory used would exceed the max allocation)
>>
>> If you see OutOfMemory errors then there could quite possibly be a leak.
>>
>> Note also that we have unit tests in place designed to catch these leaks:
>> https://github.com/scifio/scifio/blob/master/src/test/
>> java/io/scif/img/cell/cache/utests/CacheServiceTest.java.
>> An excellent way to demonstrate the memory error would be to come up with
>> another test in this class that fails.
>>
>> Thanks,
>> Mark
>>
>>
>> On Sat, Jul 12, 2014 at 1:54 PM, Burkhard H?ckendorf <
>> burkhard.hoeckendorf at web.de> wrote:
>>
>> Dear List,
>>>
>>> First of all thanks for developing scifio and doing that open source. I
>>> have started to use it with ImageJ, since Fiji now offers the option to
>>> use
>>> it. Having said that, I may also have stumbled upon an issue. I'm unsure
>>> when (or whether) scifio releases the corresponding memory after images
>>> are
>>> closed. To look at this in a somewhat systematic way, I ran a macro (see
>>> below) to repeatedly open and close a 3GB single file uncompressed TIFF
>>> stack (2048x2048x367x16bits) and record some performance stats along the
>>> way. I ran this using a new download of Fiji.
>>>
>>> Here are the results with scifio disabled:
>>> 11450 ms to open files
>>> 28578184 mem before opening files
>>> 9282667288 mem after opening files
>>> 9272732560 mem after opening files & GC
>>> 9272780080 mem after closing files
>>> 24220936 mem after closing files & GC
>>>
>>> And here with scifio enabled:
>>> 43715 ms to open files
>>> 26765224 mem before opening files
>>> 10517954400 mem after opening files
>>> 9327459480 mem after opening files & GC
>>> 9327506440 mem after closing files
>>> 9314822896 mem after closing files & GC
>>>
>>> I have also checked, whether memory is freed a couple of minutes after
>>> closing the images, which does not appear to be the case.
>>>
>>> Note that scifio is also somewhat slower, although I'm a bit hesitant to
>>> bring this up, because it is still relatively young and I can see a few
>>> "improve ... performance" tickets in the issue tracker.
>>>
>>> Below is the macro.
>>> Kind regards,
>>> Burkhard
>>>
>>>
>>> nOpenTimes = 3;
>>> file = "/path/to/stack";
>>>
>>> run("Collect Garbage");
>>> memBefore = IJ.currentMemory();
>>>
>>> msToOpen = getTime();
>>> for (i=0; i<nOpenTimes; i+=1) {
>>> open(file);
>>> }
>>> msToOpen = getTime() - msToOpen;
>>>
>>> memFilesOpen = IJ.currentMemory();
>>> run("Collect Garbage");
>>> memFilesOpenGC = IJ.currentMemory();
>>>
>>> for (i=0; i<nOpenTimes; i+=1) {
>>> close();
>>> }
>>> memFilesClosed = IJ.currentMemory();
>>> run("Collect Garbage");
>>> memFilesClosedGC = IJ.currentMemory();
>>>
>>> print(""+ msToOpen + " ms to open files");
>>> print(""+ memBefore + " mem before opening files");
>>> print(""+ memFilesOpen + " mem after opening files");
>>> print(""+ memFilesOpenGC + " mem after opening files & GC");
>>> print(""+ memFilesClosed + " mem after closing files");
>>> print(""+ memFilesClosedGC + " mem after closing files & GC");
>>>
>>> _______________________________________________
>>> SCIFIO mailing list
>>> SCIFIO at scif.io
>>> http://scif.io/mailman/listinfo/scifio
>>>
>>> -------------- next part --------------
>> An HTML attachment was scrubbed...
>> URL: <http://scif.io/pipermail/scifio/attachments/20140714/
>> 0e7f8b63/attachment-0001.html>
>>
>> ------------------------------
>>
>> _______________________________________________
>> SCIFIO mailing list
>> SCIFIO at scif.io
>> http://scif.io/mailman/listinfo/scifio
>>
>>
>> End of SCIFIO Digest, Vol 11, Issue 5
>> *************************************
>>
>>
> _______________________________________________
> SCIFIO mailing list
> SCIFIO at scif.io
> http://scif.io/mailman/listinfo/scifio
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://scif.io/pipermail/scifio/attachments/20140715/d4dc0809/attachment-0002.html>
More information about the SCIFIO
mailing list