[SCIFIO] SCIFIO does not seem to release memory of closed, images

Burkhard Höckendorf burkhard.hoeckendorf at web.de
Mon Jul 14 13:39:29 CDT 2014


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
> *************************************
>




More information about the SCIFIO mailing list