Slow opening tiff images with RRD

[gaopeng]

The following are the times in milliseconds for opening tiff images with and without RRD. On average, it took about 500 ms with RRD, and only about 20 ms without. A subset of test images, slowopen.zip, is at ​ftp://GDAL@ftp.esri.com.

Testing Script:

double millis = CurrentTimeMillis(); GDALDataset* pDataset = (GDALDataset *)GDALOpen(String816(fullname), GA_ReadOnly); if (pDataset) {

TRACE2(_T("Time: %lf (%s)\n"), (CurrentTimeMillis()-millis), (LPCTSTR)fullname); GDALClose(pDataset);

}

Timing:

RRD

Time: 78.000000 (C:\Data\Sea_Island_TIFF\17RMQ590440_200309_0x1500m_CL.tif) Time: 93.000000 (C:\Data\Sea_Island_TIFF\17RMQ605425_200309_0x1500m_CL.tif) Time: 625.000000 (C:\Data\Sea_Island_TIFF\17RMQ605440_200309_0x1500m_CL.tif) Time: 922.000000 (C:\Data\Sea_Island_TIFF\17RMQ605455_200309_0x1500m_CL.tif) Time: 125.000000 (C:\Data\Sea_Island_TIFF\17RMQ605470_200309_0x1500m_CL.tif) Time: 766.000000 (C:\Data\Sea_Island_TIFF\17RMQ620425_200309_0x1500m_CL.tif) Time: 641.000000 (C:\Data\Sea_Island_TIFF\17RMQ620440_200309_0x1500m_CL.tif) Time: 593.000000 (C:\Data\Sea_Island_TIFF\17RMQ620455_200309_0x1500m_CL.tif) Time: 657.000000 (C:\Data\Sea_Island_TIFF\17RMQ620470_200309_0x1500m_CL.tif) Time: 360.000000 (C:\Data\Sea_Island_TIFF\17RMQ620485_200309_0x1500m_CL.tif) Time: 1609.000000 (C:\Data\Sea_Island_TIFF\17RMQ635440_200309_0x1500m_CL.tif) Time: 625.000000 (C:\Data\Sea_Island_TIFF\17RMQ635455_200309_0x1500m_CL.tif) Time: 1657.000000 (C:\Data\Sea_Island_TIFF\17RMQ635470_200309_0x1500m_CL.tif) Time: 672.000000 (C:\Data\Sea_Island_TIFF\17RMQ635485_200309_0x1500m_CL.tif) Time: 578.000000 (C:\Data\Sea_Island_TIFF\17RMQ635500_200309_0x1500m_CL.tif) Time: 625.000000 (C:\Data\Sea_Island_TIFF\17RMQ635515_200309_0x1500m_CL.tif) Time: 485.000000 (C:\Data\Sea_Island_TIFF\17RMQ650440_200309_0x1500m_CL.tif) Time: 641.000000 (C:\Data\Sea_Island_TIFF\17RMQ650455_200309_0x1500m_CL.tif) Time: 1375.000000 (C:\Data\Sea_Island_TIFF\17RMQ650470_200309_0x1500m_CL.tif) Time: 719.000000 (C:\Data\Sea_Island_TIFF\17RMQ650485_200309_0x1500m_CL.tif) Time: 781.000000 (C:\Data\Sea_Island_TIFF\17RMQ650500_200309_0x1500m_CL.tif) Time: 594.000000 (C:\Data\Sea_Island_TIFF\17RMQ650515_200309_0x1500m_CL.tif) Time: 547.000000 (C:\Data\Sea_Island_TIFF\17RMQ650530_200309_0x1500m_CL.tif) Time: 93.000000 (C:\Data\Sea_Island_TIFF\17RMQ650545_200309_0x1500m_CL.tif) Time: 78.000000 (C:\Data\Sea_Island_TIFF\17RMQ665455_200309_0x1500m_CL.tif) Time: 438.000000 (C:\Data\Sea_Island_TIFF\17RMQ665470_200309_0x1500m_CL.tif) Time: 1266.000000 (C:\Data\Sea_Island_TIFF\17RMQ665485_200309_0x1500m_CL.tif) Time: 1687.000000 (C:\Data\Sea_Island_TIFF\17RMQ665500_200309_0x1500m_CL.tif) Time: 1438.000000 (C:\Data\Sea_Island_TIFF\17RMQ665515_200309_0x1500m_CL.tif) Time: 469.000000 (C:\Data\Sea_Island_TIFF\17RMQ665530_200309_0x1500m_CL.tif) Time: 515.000000 (C:\Data\Sea_Island_TIFF\17RMQ665545_200309_0x1500m_CL.tif) Time: 438.000000 (C:\Data\Sea_Island_TIFF\17RMQ665560_200309_0x1500m_CL.tif) Time: 79.000000 (C:\Data\Sea_Island_TIFF\17RMQ680485_200309_0x1500m_CL.tif) Time: 531.000000 (C:\Data\Sea_Island_TIFF\17RMQ680500_200309_0x1500m_CL.tif) Time: 594.000000 (C:\Data\Sea_Island_TIFF\17RMQ680515_200309_0x1500m_CL.tif) Time: 562.000000 (C:\Data\Sea_Island_TIFF\17RMQ680530_200309_0x1500m_CL.tif) Time: 531.000000 (C:\Data\Sea_Island_TIFF\17RMQ680545_200309_0x1500m_CL.tif) Time: 547.000000 (C:\Data\Sea_Island_TIFF\17RMQ680560_200309_0x1500m_CL.tif) Time: 78.000000 (C:\Data\Sea_Island_TIFF\17RMQ695500_200309_0x1500m_CL.tif) Time: 578.000000 (C:\Data\Sea_Island_TIFF\17RMQ695515_200309_0x1500m_CL.tif) Time: 516.000000 (C:\Data\Sea_Island_TIFF\17RMQ695530_200309_0x1500m_CL.tif) Time: 500.000000 (C:\Data\Sea_Island_TIFF\17RMQ695545_200309_0x1500m_CL.tif) Time: 422.000000 (C:\Data\Sea_Island_TIFF\17RMQ695560_200309_0x1500m_CL.tif)

NO RRD Time: 0.000000 (C:\Data\Sea_Island_TIFF_NORRD\17RMQ590440_200309_0x1500m_CL.tif) Time: 0.000000 (C:\Data\Sea_Island_TIFF_NORRD\17RMQ605425_200309_0x1500m_CL.tif) Time: 16.000000 (C:\Data\Sea_Island_TIFF_NORRD\17RMQ605440_200309_0x1500m_CL.tif) Time: 0.000000 (C:\Data\Sea_Island_TIFF_NORRD\17RMQ605455_200309_0x1500m_CL.tif) Time: 16.000000 (C:\Data\Sea_Island_TIFF_NORRD\17RMQ605470_200309_0x1500m_CL.tif) Time: 0.000000 (C:\Data\Sea_Island_TIFF_NORRD\17RMQ620425_200309_0x1500m_CL.tif) Time: 15.000000 (C:\Data\Sea_Island_TIFF_NORRD\17RMQ620440_200309_0x1500m_CL.tif) Time: 0.000000 (C:\Data\Sea_Island_TIFF_NORRD\17RMQ620455_200309_0x1500m_CL.tif) Time: 0.000000 (C:\Data\Sea_Island_TIFF_NORRD\17RMQ620470_200309_0x1500m_CL.tif) Time: 0.000000 (C:\Data\Sea_Island_TIFF_NORRD\17RMQ620485_200309_0x1500m_CL.tif) Time: 0.000000 (C:\Data\Sea_Island_TIFF_NORRD\17RMQ635440_200309_0x1500m_CL.tif) Time: 0.000000 (C:\Data\Sea_Island_TIFF_NORRD\17RMQ635455_200309_0x1500m_CL.tif) Time: 0.000000 (C:\Data\Sea_Island_TIFF_NORRD\17RMQ635470_200309_0x1500m_CL.tif) Time: 16.000000 (C:\Data\Sea_Island_TIFF_NORRD\17RMQ635485_200309_0x1500m_CL.tif) Time: 0.000000 (C:\Data\Sea_Island_TIFF_NORRD\17RMQ635500_200309_0x1500m_CL.tif) Time: 16.000000 (C:\Data\Sea_Island_TIFF_NORRD\17RMQ635515_200309_0x1500m_CL.tif) Time: 0.000000 (C:\Data\Sea_Island_TIFF_NORRD\17RMQ650440_200309_0x1500m_CL.tif) Time: 15.000000 (C:\Data\Sea_Island_TIFF_NORRD\17RMQ650455_200309_0x1500m_CL.tif) Time: 0.000000 (C:\Data\Sea_Island_TIFF_NORRD\17RMQ650470_200309_0x1500m_CL.tif) Time: 0.000000 (C:\Data\Sea_Island_TIFF_NORRD\17RMQ650485_200309_0x1500m_CL.tif) Time: 0.000000 (C:\Data\Sea_Island_TIFF_NORRD\17RMQ650500_200309_0x1500m_CL.tif) Time: 0.000000 (C:\Data\Sea_Island_TIFF_NORRD\17RMQ650515_200309_0x1500m_CL.tif) Time: 16.000000 (C:\Data\Sea_Island_TIFF_NORRD\17RMQ650530_200309_0x1500m_CL.tif) Time: 0.000000 (C:\Data\Sea_Island_TIFF_NORRD\17RMQ650545_200309_0x1500m_CL.tif) Time: 15.000000 (C:\Data\Sea_Island_TIFF_NORRD\17RMQ665455_200309_0x1500m_CL.tif) Time: 0.000000 (C:\Data\Sea_Island_TIFF_NORRD\17RMQ665470_200309_0x1500m_CL.tif) Time: 0.000000 (C:\Data\Sea_Island_TIFF_NORRD\17RMQ665485_200309_0x1500m_CL.tif) Time: 0.000000 (C:\Data\Sea_Island_TIFF_NORRD\17RMQ665500_200309_0x1500m_CL.tif) Time: 0.000000 (C:\Data\Sea_Island_TIFF_NORRD\17RMQ665515_200309_0x1500m_CL.tif) Time: 0.000000 (C:\Data\Sea_Island_TIFF_NORRD\17RMQ665530_200309_0x1500m_CL.tif) Time: 0.000000 (C:\Data\Sea_Island_TIFF_NORRD\17RMQ665545_200309_0x1500m_CL.tif) Time: 16.000000 (C:\Data\Sea_Island_TIFF_NORRD\17RMQ665560_200309_0x1500m_CL.tif) Time: 0.000000 (C:\Data\Sea_Island_TIFF_NORRD\17RMQ680485_200309_0x1500m_CL.tif) Time: 0.000000 (C:\Data\Sea_Island_TIFF_NORRD\17RMQ680500_200309_0x1500m_CL.tif) Time: 0.000000 (C:\Data\Sea_Island_TIFF_NORRD\17RMQ680515_200309_0x1500m_CL.tif) Time: 0.000000 (C:\Data\Sea_Island_TIFF_NORRD\17RMQ680530_200309_0x1500m_CL.tif) Time: 0.000000 (C:\Data\Sea_Island_TIFF_NORRD\17RMQ680545_200309_0x1500m_CL.tif) Time: 0.000000 (C:\Data\Sea_Island_TIFF_NORRD\17RMQ680560_200309_0x1500m_CL.tif) Time: 16.000000 (C:\Data\Sea_Island_TIFF_NORRD\17RMQ695500_200309_0x1500m_CL.tif) Time: 0.000000 (C:\Data\Sea_Island_TIFF_NORRD\17RMQ695515_200309_0x1500m_CL.tif) Time: 0.000000 (C:\Data\Sea_Island_TIFF_NORRD\17RMQ695530_200309_0x1500m_CL.tif) Time: 0.000000 (C:\Data\Sea_Island_TIFF_NORRD\17RMQ695545_200309_0x1500m_CL.tif) Time: 0.000000 (C:\Data\Sea_Island_TIFF_NORRD\17RMQ695560_200309_0x1500m_CL.tif)

[warmerdam]

Gao,

I have downloaded just the 17RMQ665485_200309_0x1500m_CL.* dataset, and run the following program against it on a pretty outdated system. It runs in 2s wall clock time or about 20ms per GDALOpen() call. This is all the same file, so of course after the first call it is benefiting from disk caching.

#include "gdal.h"

int main()

{
    int  i;
    GDALDatasetH hDS;
    const char *filename = "17RMQ665485_200309_0x1500m_CL.tif";

    GDALAllRegister();

    for( i = 0; i < 100; i++ )
    {
        hDS = GDALOpen( filename, GA_ReadOnly );

        printf( "%s: %dP x %d: x %dC\n",
                filename,
                GDALGetRasterXSize(hDS),
                GDALGetRasterYSize(hDS),
                GDALGetRasterCount(hDS) );

        printf( "  Overviews: %d\n",
                GDALGetOverviewCount(GDALGetRasterBand(hDS,1)) );

        GDALClose( hDS );
    }
}

Could you perhaps confirm that you get similar results with the above program?

Assuming you get similar results, I would guess the issue is that GDALOpen() is triggering too much reading of the block indexes and stuff from the .rrd file and the fix would be to try and defer that till the overviews are actually requested. I'll start poking around at that now.

[gaopeng]

I was getting about 500ms per GDALOpen call on different tiff files.

Yes, opening rrd, specifically, following call took the most of the time.

/* -------------------------------------------------------------------- */
/*      Check for external overviews.                                   */
/* -------------------------------------------------------------------- */
    poDS->oOvManager.Initialize( poDS, pszFilename );

[warmerdam]

Gao,

Can you confirm that my test program runs at a similar speed for your (ie. 2s or so)?

I'm trying to figure out if there is some issue in your build that isn't found in mine.

[gaopeng]

The total time for opening the same file for 100 times is 57s on my build/machine.

Time: 57875.000000 (C:/Data/Sea_Island_TIFF/17RMQ665485_200309_0x1500m_CL.tif)

The following is the config options I used.

    CPLSetConfigOption("GDAL_PAM_ENABLED", "YES");
    CPLSetConfigOption("GDAL_CACHEMAX", "64");
    CPLSetConfigOption("HFA_USE_RRD", "YES");
    CPLSetConfigOption("SIMPLE_JPEG_MAGIC", "YES");
    CPLSetConfigOption("GDAL_DISABLE_READDIR_ON_OPEN", "YES");
    CPLSetConfigOption("COMPRESS_OVERVIEW", "LZW");
    CPLSetConfigOption("GDAL_VALIDATE_CREATION_OPTIONS", "NO");
    // limits ECW cache size to 64M
    CPLSetConfigOption("GDAL_ECW_CACHE_MAXMEM", "67108864");

[warmerdam]

Gao, I tried with all those settings and get essentially the same 2 seconds. In my case I only have the following files in the directory. Do you have a lot of files in the same directory? Could you try with a restricted set?

28/09/2009  04:05 PM    <DIR>          ..
14/05/2009  05:25 PM            43,441 17RMQ665485_200309_0x1500m_CL.aux
14/05/2009  05:25 PM        26,379,368 17RMQ665485_200309_0x1500m_CL.rrd
14/05/2009  05:25 PM       303,480,421 17RMQ665485_200309_0x1500m_CL.tif
14/05/2009  05:25 PM            12,034 17RMQ665485_200309_0x1500m_CL.tif.xml
28/09/2009  04:05 PM            52,500 log
28/09/2009  03:23 PM               578 test1.cpp
28/09/2009  03:23 PM             4,096 test1.exe
28/09/2009  03:23 PM             1,313 test1.obj

It sounds like there is an effect you are running into that I am not. I want to make sure I'm attacking the right problem.

[gaopeng]

I copied the tiff image (4 files) into a separate folder, and run the test again. The total time is about 53s.

[warmerdam]

I have done a non-debug build from the 1.6-esri branch (with hdf,mrsid,etc omitted) and I'm still seeing about 2s for the full run of test1.exe. I am not sure why there is such difference between our situations.

Are you able to run test1.exe in the debugger and break a few times to get a more detailed idea of where the time is being spent?

One possibility is that one of the drivers I omitted is extra-ordinarily expensive for some reason.

[warmerdam]

I have implemented changes in the HFA driver, and the GDALDefaultOverviews classes to support deferred scanning and opening of overview files. With these changes overview files should not now be opened until a request like GetFileList(), GetOverviewCount(), or GetOverview() is made.

Changes are in trunk (r17710 - HFA, r17711 - GDALDefaultOverviews).

As implemented the GDALDefaultOverviews changes alter the size of the GDALDefaultOverviews object, embedded in GDALDataset, and so alter the C++ ABI. As such they are not suitable to backport into 1.6 or 1.6-esri as is. If it is desirable to backport to 1.6-esri I can investigate ways of avoiding this effect.

[gaopeng]

There must be something wrong with my machine. I keep getting the slow opening times (~500ms per open). Deferring opening RRD doesn't help me in this case since I will need to know # of overviews (call GetOverviewCount()). I need it to open RRD faster.

I made a small fix that skips opening attribute tables for RRD.

    if( iOverview == -1 )
    {
        if( !EQUAL(CPLGetExtension( hHFA->pszFilename ), "aux") )
            poDefaultRAT = ReadNamedRAT( "Descriptor_Table" );
    }

[Even Rouault]

Milestone 1.6.4 deleted