(Re)ExportAll Optimizations, Better Logging

[djbrooke]

We have a a few issues reported about Exportall (#6826, #6594, #4682, #6302) that I'm going to close and consolidate here. There are some stack traces in those issues (especially #4682) that may be helpful as we start to investigate this. From #6826 @landreev suggests:

For the purposes of defining something we can prioritize and work on, I can think of 2 possible chilld issues that this can be split into:

• Investigate why export is such a resource hog. The main offender appears to be full DDI export of datasets with large numbers of tabular files (with large numbers of variables). Worth checking if this is how it's always been vs. whether it's gotten worse. We've recently made some extra variable-level metadata editable; which at some point noticeably affected the performance of variable indexing. (note: it didn't make it better/faster). Is this something similar?

• Regardless of the performance, the current reexport system is a bit unwieldy, making it hard to, for example, reexport in smaller batches. (will elaborate/add more info).

In the same issue, @kcondon asks for some additional logging:

While we're at it, please add better logging for export progress. Currently, there is a separate export log in logs. That is fine but it does not indicate how many datasets will be exported up front and so looking at it does not indicate whether it has completed, only the success or failure of individual datasets to be exported. Might be nice, like index does, to stamp server log with "exportall" started, exporting y datasets and when finished, exportall finished, x of y datasets exported. No need to stamp x of y in server log but maybe add a number to export log: exporting y datasets, then for each dataset stamp x of y there.

I think any of these three would be good issues to create and pull into a sprint, or this could be moved through as a larger issue by itself. I see more exporting in our future releases and I think it would be good to spend time on this optimization right now. Moving to Needs Discussion for @scolapasta and others to determine the best approach.

[stevenferey]

Hello,

Possibly additional elements on this subject:

We are also seeing a slowdown with the reExportAll job. It runs for several days and crashes without terminating the execution: No end tag!
It's problematic for our production environment

The last exported datasets contain errors in the logs:

<record> <date>2021-08-14T02:55:47</date> <millis>1628902547385</millis> <sequence>343018</sequence> <logger>edu.harvard.iq.dataverse.harvest.client.DatasetServiceBean.ExportAll2021-08-05T19-05-46</logger> <level>INFO</level> <class>edu.harvard.iq.dataverse.DatasetServiceBean</class> <method>exportAllDatasets</method> <thread>219</thread> <message>Error exporting dataset: INRA:Lucerne:LR3-114A doi:10.15454/LQIRFR; Cannot instantiate a S3 client; check your AWS credentials and region</message> </record>

<record> <date>2021-08-14T03:19:09</date> <millis>1628903949533</millis> <sequence>343019</sequence> <logger>edu.harvard.iq.dataverse.harvest.client.DatasetServiceBean.ExportAll2021-08-05T19-05-46</logger> <level>INFO</level> <class>edu.harvard.iq.dataverse.DatasetServiceBean</class> <method>exportAllDatasets</method> <thread>219</thread> <message>Error exporting dataset: INRA:Lucerne:LR3-142 doi:10.15454/POUW9W; Cannot instantiate a S3 client; check your AWS credentials and region</message> </record>

<record> <date>2021-08-14T03:44:44</date> <millis>1628905484700</millis> <sequence>343020</sequence> <logger>edu.harvard.iq.dataverse.harvest.client.DatasetServiceBean.ExportAll2021-08-05T19-05-46</logger> <level>INFO</level> <class>edu.harvard.iq.dataverse.DatasetServiceBean</class> <method>exportAllDatasets</method> <thread>219</thread> <message>Error exporting dataset: INRA:Lucerne:LR3-144 doi:10.15454/CMNYK9; Cannot instantiate a S3 client; check your AWS credentials and region</message> </record>

The link with our S3 is OK during and after the job execution from the dataverse interface.

In addition, before blocking, each dataset export takes around 15-20min even though it does not contain any files.

thank you so much

[qqmyers]

@stevenferey - have you looked at the dataverse.files..connection-pool-size parameter that was introduced in 5.1.1? Raising it from the default of 256 might help by allowing Dataverse to open more connections to S3.

[stevenferey]

@qqmyers - Hello and sorry for the delay.

Yes, we tested the "dataverse.files..connection-pool-size" parameter with a value of 4096.
This problem is still present with this parameter (Dataverse v5.3).

[PaulBoon]

Hi,

I just bumped on this OOM problem on our (acceptance) test server while doing a reExportAll. Running Dataverse version 5.6.
And we are using the local filesystem, so no S3.

The last export related log message before the OOM is

[2022-05-11T10:05:46.178+0200] [Payara 5.2021.5] [INFO] [] [edu.harvard.iq.dataverse.export.ddi.DdiExportUtil] [tid: _ThreadID=286 _ThreadName=__ejb-thread-pool5] [timeMillis : 1652256346178] [levelValue: 800] [[ Pub?: DataverseNL]]

So it might be DDI specific.

The real problem is, that if this happens on production and the metadata really needs to be updated there is no way to skip the 'failing' datasets (can't see which one either) and continue with the others.
When handling problems with reindexing, we do have options to reindex specific datasets.

While hoping that our beefier production server won't have the problem, I would like to know what to do if reExportAll fails.
Any tips are welcome; @pdurbin or @qqmyers .

[pdurbin]

@PaulBoon I had a look through the issues above and the code but I'm afraid I don't have a great answer to your question about what if you see "reexport all" failures and out of memory in production. I agree with what you're saying and "the current reexport system is a bit unwieldy, making it hard to, for example, reexport in smaller batches" above.

It looks like ultimately, recordService.exportAllFormatsInNewTransaction(dataset) gets called over and over. Like you're saying, maybe as we do with indexing, we could have an API endpoint where you pass in a single dataset to reexport the various formats. I don't think that would be controversial if you'd like to create a pull request (and a dedicated "small chunk" issue) for this, if you think it would help, of course.

[PaulBoon]

Hi @pdurbin, Not sure if a reindex of a specific datasets is the best solution.
If there was a way to continue the export where it left instead of redoing all, that might be useful. Comment in the reExportAll code states: 'regardless of the lastexporttime value'.
With reindexing you can 'clear' the timestamp and then reindex, maybe we should have this for the export as wel. We then clear the timestamp and run the exportAll (without the 're') to re-export all. If that fails, the exports that must still be done have the timestamp cleared and will be picked up with a next call.
Most likely it starts with the datasets that causes the troubles and fails again. So it would also be great if we can somehow make it skip that one, maybe by exporting it via the UI?

[PaulBoon]

Small PR under way... #8721

[pdurbin]

With reindexing you can 'clear' the timestamp and then reindex, maybe we should have this for the export as well.

@PaulBoon from some internal discussion, it sounds like we may have most of this solution already. What's especially missing is the ability to clear the timestamps from export (for indexing there's a "clear" API endpoint). This currently must be done in the database ("lastexporttime" in the "dataset" table, I believe). So if you want, you could add a "clear" endpoint for export.

With the index API we have an explicit "continue" API endpoint. From what I understand, for exports, doing a re-export is the same as continue. Datasets with no export time will be run.

I hope this helps. I'm really just passing along information I haven't tested myself. Something to play with at least, I hope.

[pdurbin]

@PaulBoon and others, what's the state of play now that this pull request has been merged and will be in 5.12?

• 8720 allow metadata re export in smaller batches #8721

How much does it help? What else is needed? Do we have a clear "definition of done" for this issue?