delta-io/connectors

Non-optimal read for newly created Delta table from S3

dnskr opened this issue · 4 comments

dnskr commented

Standalone connector is used in PrestoDB delta connector.
There is a performance issue when I read newly created Delta table (without _last_checkpoint) stored on S3.
The reason of the issue is here Checkpoints.scala#L133

  private def loadMetadataFromFile(tries: Int): Option[CheckpointMetaData] = {
    var checkpointMetadataJson: CloseableIterator[String] = null
    try {
      checkpointMetadataJson = store.read(LAST_CHECKPOINT, hadoopConf)
      val checkpointMetadata =
        JsonUtils.mapper.readValue[CheckpointMetaData](checkpointMetadataJson.next())
      Some(checkpointMetadata)
    } catch {
      case _: FileNotFoundException =>
        None
      case NonFatal(e) if tries < 3 =>
        logWarning(s"Failed to parse $LAST_CHECKPOINT. This may happen if there was an error " +
          "during read operation, or a file appears to be partial. Sleeping and trying again.", e)
        Thread.sleep(1000)
        loadMetadataFromFile(tries + 1)

For local file system the flow for missing _last_checkpoint goes to FileNotFoundException, but in my case it goes to NonFatal(e) if tries < 3, because a different exception is catched.
As a result, this code tries to read _last_checkpoint 3 times with 1 second delay what downgrades read performance.
Also it seems Presto tries to execute this up to 5 times, so it adds +15 seconds to the execution time of a simple select query.
There is a log with stacktrace:

2022-09-07T13:51:16.040Z        WARN    Query-20220907_135115_00006_up6te-593   io.delta.standalone.internal.DeltaLogImpl       Failed to parse s3a://data-warehouse/my_database/my_table/_delta_log/_last_checkpoint. This may happen if there was an error during read operation, or a file appears to be partial. Sleeping and trying again.
com.facebook.presto.hive.s3.PrestoS3FileSystem$UnrecoverableS3OperationException: com.amazonaws.services.s3.model.AmazonS3Exception: The specified key does not exist. (Service: Amazon S3; Status Code: 404; Error Code: NoSuchKey; Request ID: 1712984EA7667136; S3 Extended Request ID: 0aa37532-b31a-403d-9632-343d5975c4e9), S3 Extended Request ID: 0aa37532-b31a-403d-9632-343d5975c4e9 (Path: s3a://data-warehouse/my_database/my_table/_delta_log/_last_checkpoint)
        at com.facebook.presto.hive.s3.PrestoS3FileSystem$PrestoS3InputStream.lambda$openStream$2(PrestoS3FileSystem.java:1114)
        at com.facebook.presto.hive.RetryDriver.run(RetryDriver.java:139)
        at com.facebook.presto.hive.s3.PrestoS3FileSystem$PrestoS3InputStream.openStream(PrestoS3FileSystem.java:1099)
zsxwing commented

Hm, good catch. Should this be fixed in PrestoS3FileSystem instead? We assume FileNotFoundException when a file doesn't exist.

dnskr commented

@zsxwing Thanks! You are right, I've checked and it can be fixed in PrestoS3FileSystem class.

Btw, I wonder if it's ok that the normal flow in loadMetadataFromFile goes through exceptions? I assume that missing _last_checkpoint is the normal case for newly created table.

zsxwing commented

loadMetadataFromFile may hit transient exceptions on some storage such as Azure when _last_checkpoint is being overwritten. We do the retry to workaround such rare case.

zsxwing commented

Thanks for creating the PR to fix the issue in Presto. I will close this as there is no action item in Delta Lake side.

  • 👍1