Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

PyramidOMETiffWriter close() duration scales as a (number of planes)^2 #4204

Open
NicoKiaru opened this issue Jun 27, 2024 · 4 comments
Open
Milestone

Comments

@NicoKiaru
Copy link
Contributor

NicoKiaru commented Jun 27, 2024

Hello,

Original post: https://forum.image.sc/t/pyramidometiffwriter-really-bad-performance-when-closing-the-writer/95294

There is a (very big) performance issue when saving an OME TIFF file with PyramidOMETiffWriter as the close() method duration scales as the number of planes squared.

I've tested to save a 512x512 pixel file on my computer and increase the number of timepoints by powers of 2 (nT). I've measured the time required to save the file and split the required time between what happens before calling close, and the close duration:

Export Time (ms) = Data writing (ms) + Reader.close() duration (ms) 
nPixX nPixY nT Export Time (s) Reader.close() duration (s) Data writing (s) Reader close duration in total export time (%)
512 512 1 0.5 0.2 0.4 32 %
512 512 2 0.7 0.2 0.5 27 %
512 512 4 0.7 0.2 0.5 32 %
512 512 8 1.0 0.3 0.7 30 %
512 512 16 1.4 0.4 1.0 29 %
512 512 32 2.1 0.7 1.4 31 %
512 512 64 3.8 1.7 2.2 43 %
512 512 128 8.9 5.2 3.7 59 %
512 512 256 20.2 14.4 5.8 71 %
512 512 512 64.0 51.6 12.5 80 %
512 512 1024 290.4 262.6 27.8 90 %
             
16384 16384 1 86.2 0.08 86.1 0.1 %

The data writing time scales linearly with the number of timepoints, which is what we expect. However the close time is multiplied by 4 each time the number of timepoints is multiplied by 2.

As a result, 'close' takes 90% of the total export time when there are 1024 timepoints.

I've narrowed the issue to the call of TiffParser#getIFDOffsets for all planes, getIFDOffsets walking the whole file from the start. This scales very badly.

  • PyramidOMETiffWriter#close loops through all planes:

  • and calls within the loop TiffSaver#overwriteIFDValue

saver.overwriteIFDValue(in, currentFullResolution, IFD.SUB_IFD, subIFDOffsets);

  • which calls TiffParser#getIFDOffsets

long[] offsets = parser.getIFDOffsets();

  • and TiffParser#getIFDOffsets walks through the whole file

long offset = getFirstOffset();
while (offset > 0 && offset < in.length()) {

Is there a way to fix this ?


This issue could be related to these other issues:

#3983
#3480

@imagesc-bot
Copy link

This issue has been mentioned on Image.sc Forum. There might be relevant details there:

https://forum.image.sc/t/pyramidometiffwriter-really-bad-performance-when-closing-the-writer/95294/10

@melissalinkert melissalinkert added this to the 8.0.0 milestone Sep 10, 2024
@melissalinkert
Copy link
Member

With a test based on https://github.com/ome/bioformats/blob/develop/components/formats-gpl/utils/MinimumPyramidWriter.java that writes one pyramid resolution:

https://gist.github.com/melissalinkert/aaa9ac52c42a6b9c7596037cbadde4a3

I can see similar degradation of close() performance:

$ for i in `cat timepoint-counts.txt`; do java SmallPyramidWriter $i.ome.tiff $i; done
Populating metadata...
Writing image to '1.ome.tiff'...
init: 47 ms
image writing: 473 ms
close: 334 ms
Done.
Populating metadata...
Writing image to '8.ome.tiff'...
init: 39 ms
image writing: 858 ms
close: 374 ms
Done.
Populating metadata...
Writing image to '64.ome.tiff'...
init: 47 ms
image writing: 4335 ms
close: 2906 ms
Done.
Populating metadata...
Writing image to '128.ome.tiff'...
init: 39 ms
image writing: 9324 ms
close: 10617 ms
Done.
Populating metadata...
Writing image to '512.ome.tiff'...
init: 52 ms
image writing: 83372 ms
close: 152463 ms
Done.
Populating metadata...
Writing image to '1024.ome.tiff'...
init: 46 ms
image writing: 346121 ms
close: 604924 ms
Done.
Populating metadata...
Writing image to '2048.ome.tiff'...
Switching to BigTIFF (by file size)
init: 49 ms
image writing: 1154836 ms
close: 2157835 ms
Done.

I also see that data writing does not exactly scale linearly either, but obviously not as badly as close().

Incidentally, with a similar test that writes multiple resolutions:

https://gist.github.com/melissalinkert/ef601854820ee1a2ce970f09559a0cb0

I could easily reproduce #3907 using:

$ java FullPyramidWriter 2.ome.tiff 2
Populating metadata...
Writing image to '2.ome.tiff'...
Exception in thread "main" java.lang.ArrayIndexOutOfBoundsException: Index 6 out of bounds for length 5
	at loci.formats.out.PyramidOMETiffWriter.close(PyramidOMETiffWriter.java:141)
	at loci.formats.ImageWriter.close(ImageWriter.java:488)
	at FullPyramidWriter.main(FullPyramidWriter.java:102)

All four related issues (this, #3983, #3480, and now #3907) are now scheduled for 8.0.0, as discussed with @joshmoore and @sbesson.

@NicoKiaru
Copy link
Contributor Author

With the patch of @melissalinkert in this issue vanishes:

69809b0f-4755-4fd2-80ca-c36ba2945601

in log scale:

173459da-9b55-4906-a627-baf98aa0dc29


Raw perf data:

Number of Planes (nT) Close Time with Patch (ms) Export Time with Patch (ms) Close Time without Patch (ms) Export Time without Patch (ms)
1 91 329 92 336
2 13 58 16 60
4 18 92 20 96
8 29 154 37 161
16 41 286 72 332
32 78 555 220 685
64 139 1049 713 1646
128 278 2130 2262 4076
256 515 4238 7796 11426
512 946 8132 29776 37011
1024 1806 16327 119085 133443

Code used (ijp-kheops lib):

/*-
 * #%L
 * %%
 * %%
 * This program is free software: you can redistribute it and/or modify
 * it under the terms of the GNU General Public License as
 * published by the Free Software Foundation, either version 2 of the
 * License, or (at your option) any later version.
 * 
 * This program is distributed in the hope that it will be useful,
 * but WITHOUT ANY WARRANTY; without even the implied warranty of
 * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
 * GNU General Public License for more details.
 * 
 * You should have received a copy of the GNU General Public
 * License along with this program.  If not, see
 * <http://www.gnu.org/licenses/gpl-2.0.html>.
 * #L%
 */
import ch.epfl.biop.kheops.ometiff.OMETiffExporter;
import loci.common.DebugTools;
import net.imagej.ImageJ;
import net.imglib2.FinalInterval;
import net.imglib2.RandomAccessibleInterval;
import net.imglib2.position.FunctionRandomAccessible;
import net.imglib2.type.numeric.ARGBType;
import net.imglib2.view.Views;
import org.scijava.task.TaskService;

import java.time.Duration;
import java.time.Instant;

public class DemoExport {

    public static void main( String[] args )
    {
        ImageJ ij = new ImageJ();
        DebugTools.setRootLevel("Off");
        ij.ui().showUI();
        int sizeInPixelX = 512;
        int sizeInPixelY = 512;
        int tileSize = 512;
        //int nT = 512;
        for (int nT = 1; nT<=1024; nT*=2) {
            final FunctionRandomAccessible<ARGBType> checkerboard = new FunctionRandomAccessible<>(
                    2,
                    (location, value) -> {
                        value.set(
                                ARGBType.rgba(location.getIntPosition(0), location.getIntPosition(1), location.getIntPosition(0) * 0, 255)
                        );
                    },
                    ARGBType::new);

            RandomAccessibleInterval<ARGBType> img = Views.interval(checkerboard, new FinalInterval(new long[]{0, 0}, new long[]{sizeInPixelX - 1, sizeInPixelY - 1}));

            DebugTools.setRootLevel("OFF");

            try {
                //String path = "C:\\Users\\nicol\\Desktop\\ometiff\\ntest-" + sizeInPixelX + "x"+sizeInPixelY+"px-" + tileSize + "tile.ome.tiff";
                String path = "C:\\kheops\\test_x-" + sizeInPixelX + "_y-" + sizeInPixelY + "_tile-" + tileSize + "_nT-" + nT + ".ome.tiff";
                System.out.println("Saving " + path);

                Instant start = Instant.now();

                OMETiffExporter.OMETiffExporterBuilder.Data.DataBuilder dataBuilder = OMETiffExporter.builder();

                for (int t = 0; t < nT; t++) {
                    dataBuilder.putXYZRAI(0, t, img);
                }

                dataBuilder.defineMetaData("Image")
                        .imageName("Bob")
                        .voxelPhysicalSizeMicrometer(10, 10, 2)
                        .pixelsTimeIncrementInS(0.35)
                        .defineWriteOptions()
                        .tileSize(tileSize, tileSize)
                        .monitor(ij.get(TaskService.class))
                        .savePath(path)
                        .create()
                        .export();

                Instant end = Instant.now();

                System.out.println("Export time (ms) \t" + Duration.between(start, end).toMillis());

            } catch (Exception e) {
                // TODO Auto-generated catch block
                e.printStackTrace();
            }

            System.out.println("done");
        }


    }

}

(report made with the help of chatgpt)

@melissalinkert
Copy link
Member

Thank you @NicoKiaru - this report is very helpful!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

3 participants