Problem with "Invalid JSON in log record" when reading a DLT pipeline generated delta table through S3

[JKerppola]

I have a DLT pipeline that generates SCD table (both 1 and 2 types). Generated tables are stored in S3. I am trying to query those tables using deltalake-python package, using the approach explained in this blog post - though I am using the latest version of deltalake package (0.10.1).

Currently I am facing an error that states:

Response
{
  "errorMessage": "Invalid JSON in log record, version=4, line=`{\"metaData\":{\"id\":\"c7248184-c0c1-43ac-be2c-40a4a738dd43\",\"format\":{\"provider\":\"parquet\",\"options\":{}},\"partitionColumns\":[],\"configuration\":{},\"createdTime\":1688454128491}}`, err=`missing field `schemaString` at line 1 column 171`",
  "errorType": "DeltaProtocolError",
  "requestId": "a42ea8c6-c782-425d-b4ca-2da3f2612f1e",
  "stackTrace": [
    "  File \"/var/task/lambda_function.py\", line 9, in lambda_handler\n    dt = DeltaTable(path)\n",
    "  File \"/opt/python/deltalake/table.py\", line 238, in __init__\n    self._table = RawDeltaTable(\n"
  ]
}

I've tried to go through related issues and found these

• Fix Delta metadata transaction schema #531
• Failed to apply transaction log: Invalid JSON in log record while reading delta table #524

From which 531 was commented to resolve the issue in 524 and fix the invalid JSON error. However, the error still seems to arise with DLT generated tables, or at least I am stuck with the issue and it is unclear to me what is the actual root cause. I have checked the corresponding _delta_log JSON-file and it does seem to contain the schemaString (or at least the 00000..00.json file contains the value and I am guessing it is used). Here is the content of the JSON-file:

{"commitInfo":{"timestamp":1688454128904,"userId":"7010873492968111","userName":"bd19aa54-440a-44d7-871c-88e8299dde3d","operation":"DLT SETUP","operationParameters":{"pipelineId":"48ca61ce-d162-43cd-8768-5de37ab6d4f7","updateId":"5b786fed-c7ad-4223-a677-1dbe8b7297a6"},"clusterId":"0704-065816-hnekup46","isolationLevel":"WriteSerializable","isBlindAppend":false,"operationMetrics":{},"engineInfo":"Databricks-Runtime/dlt:12.2-delta-pipelines-33a695c-80beb56-3dbb155-custom-local","txnId":"10269722-7002-4fe6-aafd-82e289e16a4d"}}
{"protocol":{"minReaderVersion":1,"minWriterVersion":2}}
{"metaData":{"id":"c7248184-c0c1-43ac-be2c-40a4a738dd43","name":"users_history","format":{"provider":"parquet","options":{}},"schemaString":"{\"type\":\"struct\",\"fields\":[{\"name\":\"kinesisUid\",\"type\":\"string\",\"nullable\":true,\"metadata\":{}},{\"name\":\"_pk\",\"type\":\"string\",\"nullable\":true,\"metadata\":{}},{\"name\":\"_sk\",\"type\":\"string\",\"nullable\":true,\"metadata\":{}},{\"name\":\"tenantId\",\"type\":\"string\",\"nullable\":true,\"metadata\":{}},{\"name\":\"userId\",\"type\":\"string\",\"nullable\":true,\"metadata\":{}},{\"name\":\"email\",\"type\":\"string\",\"nullable\":true,\"metadata\":{}},{\"name\":\"name\",\"type\":\"string\",\"nullable\":true,\"metadata\":{}},{\"name\":\"department\",\"type\":\"string\",\"nullable\":true,\"metadata\":{}},{\"name\":\"language\",\"type\":\"string\",\"nullable\":true,\"metadata\":{}},{\"name\":\"picture\",\"type\":\"string\",\"nullable\":true,\"metadata\":{}},{\"name\":\"position\",\"type\":\"string\",\"nullable\":true,\"metadata\":{}},{\"name\":\"roles\",\"type\":{\"type\":\"array\",\"elementType\":\"string\",\"containsNull\":true},\"nullable\":true,\"metadata\":{}},{\"name\":\"secondaryTenantIds\",\"type\":{\"type\":\"array\",\"elementType\":\"string\",\"containsNull\":true},\"nullable\":true,\"metadata\":{}},{\"name\":\"systemRoles\",\"type\":{\"type\":\"array\",\"elementType\":\"string\",\"containsNull\":true},\"nullable\":true,\"metadata\":{}},{\"name\":\"userRole\",\"type\":\"string\",\"nullable\":true,\"metadata\":{}},{\"name\":\"modifiedAt\",\"type\":\"string\",\"nullable\":true,\"metadata\":{}},{\"name\":\"createdAt\",\"type\":\"string\",\"nullable\":true,\"metadata\":{}},{\"name\":\"connection\",\"type\":{\"type\":\"struct\",\"fields\":[{\"name\":\"id\",\"type\":\"string\",\"nullable\":true,\"metadata\":{}},{\"name\":\"name\",\"type\":\"string\",\"nullable\":true,\"metadata\":{}},{\"name\":\"strategy\",\"type\":\"string\",\"nullable\":true,\"metadata\":{}}]},\"nullable\":true,\"metadata\":{}},{\"name\":\"__START_AT\",\"type\":\"string\",\"nullable\":true,\"metadata\":{}},{\"name\":\"__END_AT\",\"type\":\"string\",\"nullable\":true,\"metadata\":{}}]}","partitionColumns":[],"configuration":{"pipelines.metastore.tableName":"`iam_data`.`users_history`","pipelines.pipelineId":"48ca61ce-d162-43cd-8768-5de37ab6d4f7"},"createdTime":1688454128491}}

Additionally, to make this more tangled, the SCD type 1 table (one that doesn't contain history) can be read and it doesn't generate the same error even though the _delta_log JSON-file is nearly identical:

{"commitInfo":{"timestamp":1688454126507,"userId":"7010873492968111","userName":"bd19aa54-440a-44d7-871c-88e8299dde3d","operation":"DLT SETUP","operationParameters":{"pipelineId":"48ca61ce-d162-43cd-8768-5de37ab6d4f7","updateId":"5b786fed-c7ad-4223-a677-1dbe8b7297a6"},"clusterId":"0704-065816-hnekup46","isolationLevel":"WriteSerializable","isBlindAppend":false,"operationMetrics":{},"engineInfo":"Databricks-Runtime/dlt:12.2-delta-pipelines-33a695c-80beb56-3dbb155-custom-local","txnId":"f97811f7-b4a3-4f43-8669-a44911687fac"}}
{"protocol":{"minReaderVersion":1,"minWriterVersion":2}}
{"metaData":{"id":"3bfb9aed-c632-4d89-b43b-35d1dbb1997b","name":"users_latest","format":{"provider":"parquet","options":{}},"schemaString":"{\"type\":\"struct\",\"fields\":[{\"name\":\"kinesisUid\",\"type\":\"string\",\"nullable\":true,\"metadata\":{}},{\"name\":\"_pk\",\"type\":\"string\",\"nullable\":true,\"metadata\":{}},{\"name\":\"_sk\",\"type\":\"string\",\"nullable\":true,\"metadata\":{}},{\"name\":\"tenantId\",\"type\":\"string\",\"nullable\":true,\"metadata\":{}},{\"name\":\"userId\",\"type\":\"string\",\"nullable\":true,\"metadata\":{}},{\"name\":\"email\",\"type\":\"string\",\"nullable\":true,\"metadata\":{}},{\"name\":\"name\",\"type\":\"string\",\"nullable\":true,\"metadata\":{}},{\"name\":\"department\",\"type\":\"string\",\"nullable\":true,\"metadata\":{}},{\"name\":\"language\",\"type\":\"string\",\"nullable\":true,\"metadata\":{}},{\"name\":\"picture\",\"type\":\"string\",\"nullable\":true,\"metadata\":{}},{\"name\":\"position\",\"type\":\"string\",\"nullable\":true,\"metadata\":{}},{\"name\":\"roles\",\"type\":{\"type\":\"array\",\"elementType\":\"string\",\"containsNull\":true},\"nullable\":true,\"metadata\":{}},{\"name\":\"secondaryTenantIds\",\"type\":{\"type\":\"array\",\"elementType\":\"string\",\"containsNull\":true},\"nullable\":true,\"metadata\":{}},{\"name\":\"systemRoles\",\"type\":{\"type\":\"array\",\"elementType\":\"string\",\"containsNull\":true},\"nullable\":true,\"metadata\":{}},{\"name\":\"userRole\",\"type\":\"string\",\"nullable\":true,\"metadata\":{}},{\"name\":\"modifiedAt\",\"type\":\"string\",\"nullable\":true,\"metadata\":{}},{\"name\":\"createdAt\",\"type\":\"string\",\"nullable\":true,\"metadata\":{}},{\"name\":\"connection\",\"type\":{\"type\":\"struct\",\"fields\":[{\"name\":\"id\",\"type\":\"string\",\"nullable\":true,\"metadata\":{}},{\"name\":\"name\",\"type\":\"string\",\"nullable\":true,\"metadata\":{}},{\"name\":\"strategy\",\"type\":\"string\",\"nullable\":true,\"metadata\":{}}]},\"nullable\":true,\"metadata\":{}},{\"name\":\"__Timestamp\",\"type\":\"long\",\"nullable\":true,\"metadata\":{}},{\"name\":\"__DeleteVersion\",\"type\":\"string\",\"nullable\":true,\"metadata\":{}},{\"name\":\"__UpsertVersion\",\"type\":\"string\",\"nullable\":true,\"metadata\":{}}]}","partitionColumns":[],"configuration":{"pipelines.metastore.tableName":"`iam_data`.`users_latest`","pipelines.pipelineId":"48ca61ce-d162-43cd-8768-5de37ab6d4f7"},"createdTime":1688454126133}}

Any ideas on what I am missing here?

Thanks,
Juho

---

Edit.
Related issue (#1557) where DLT pipeline first creates a DLT REFRESH operation on the table and after that the actual metadata file with DLT SETUP. This produces same type of DeltaProtocolError that we are experiencing. In our case the first metadata file is intact but a DLT REFRESH operation has been done in version 4 and then the DLT SETUP step in version 5. The code then uses the version 4 metadata file, which originates from the REFRESH-step and doesn't contain any schemaString

Additionally there seems to be an issue #1302 and a draft PR #1305 to fix this. Related specifically to DLT generated tables, when metadata contains no schema information.

[a-martikainen]

This has probably now been fixed here: #1647