Isis3: spiceinit is 4 times slower in 4.2.0 than 4.1.0

[kberryUSGS]

ISIS version(s) affected: 4.2.0+

Description
Issue reported via email by Rodney Heyd (@rheyd):

spiceinit in ISIS 4.2 takes more than 4 times longer to run than it does in v. 4.0 and 4.1. This is really significant for
the CaSSIS pipeline, adding ~30 minutes to the pipeline run time.

Here is a table containing timing comparison information:

Test Run | Isis 4.0 | Isis 4.1 | Isis 4.2
-- | -- | -- | --
1 | 429 | 430 | 1848
2 | 428 | 423 | 1855
3 | 435 | 425 | 1855
4 | 441 | 426 | 1805
5 | 435 | 426 | 1856
6 | 430 | 423 | 1872
7 | 436 | 429 | 1828
8 | 422 | 427 | 1867
9 | 417 | 427 | 1881
10 | 420 | 432 | 1904

How to reproduce

Possible Solution

Additional context

[jessemapel]

@kberryUSGS Can you find out what version of ALE they have for each version of ISIS because I think there's something going on in ALE::load that is slower than it should be. Locally at the ASC we have ISIS4.1 -> ALE 0.7.2 and ISIS4.2 - > ALE 0.8.4

[lwellerastro]

I apologize if this is out of context, but I can confirm spiceinit is noticeably slower under 4.2.0 +, even on small framing camera files.

[rheyd]

@jessemapel You caught us just in time, we were about to delete our v4.1 installation and move on to 4.3 (Note, I haven't tested spiceinit under 4.3 yet...) Our current Isis installations are a straightforward install of the conda distributions.

I just took a look at what is installed in our Isis410 and Isis420 environments, and it mirrors what you have. Isis410 has libale.so.0.7.2 and Isis420 has libale.so.0.8.4 in their respective lib directories...

[jessemapel]

I spent some time this week looking into this but haven't found a good solution. So, I'm going to push this to the dedicated support sprint. So here's the problem:

Between the different versions of ALE, many different drivers were added. Because of this, the try/fail/continue scheme that ale::load uses has grown slower and slower. Both of these are really issues in ALE and not ISIS. There are two paths forward that I see:

1. Make each driver take less time. All of the drivers are setup so that they quickly check the instrument ID and fail if it's incorrect. The problem is that each driver has to re-ingest the image label before doing this. We specifically decided to do this for drivers such as HRSC where we need the file to get prefix/postfix data and not just the label. We could also add the ability to pass just the label or label and a file when creating the driver. This should significantly cut down on time because constantly re-opening and re-parsing the same file doesn't make sense and is time consuming for large images.
2. Modify ale::load so that it doesn't grow linearly in complexity as we add more drivers. We thought about this before but decided it was too complex and potentially not worth it.

[AustinSanders]

The slowdown was addressed in ALE PR 395. A new version of ALE has been released, so as long as the environment is built with the latest version of ALE, this fix should be in place.

[kberryUSGS]

CaSSIS team reports that this is still an issue, and will provide more detailed information when possible.

[jessemapel]

I think I'm running into this too. Something is happening where the pre-parsing isn't happening anymore. The PVL library doesn't seem happy with how we're passing the Grammars.

[jessemapel]

Yep, found a bug where we were trying to pass the grammar class instead of a grammar object. Can probably get a patch out this week for this.

[kberryUSGS]

@jessemapel Did you end up having time to do the patch, or should this issue get flagged for the next support sprint? (or potentially continuous support.) It takes the team 40 extra minutes to run each observation due to this issue, so getting this fixed is a priority for the team.

[jessemapel]

I'm working on getting patch build for this out right now https://github.com/conda-forge/ale-feedstock/pull/36

[acpaquette]

@jessemapel Is this closeable?

[jessemapel]

I need to do a final test but both ALE 0.8.6 and 0.8.5 build 3 have this fixed in them.

[jessemapel]

Finally finished testing this. I used CAS-MCO-2016-11-26T22.32.14.582 to test. For ALE 0.8.5 py36h605e78d_3 it took 1m 1.887s to spiceinit every framelet. For ALE 0.8.5 py36h605e78d_1 it took 3m 33.197s to spiceinit every framelet.

So it looks like the new build of 0.8.5 has fixed this. You can install the new Linux build by running conda install -c conda-forge ale=0.8.5=py36h605e78d_3. For the Mac build instead run conda install -c conda-forge ale=0.8.5=py36hc61eee1_3

[rheyd]

Thanks Jesse, Our initial testing indicates that the run times are now similar to what they were prior to the Isis 4.2 release. This is great! Thank you!