fix(engine): Skip ByteArray Deletion when Updating Var

[psavidis]

Problem Description: During Set Variable and Read Variable operations, the following partial ORM operations can occur in a problematic sequence:

• Thread A reads an Object Variable, thus associated with a byte array value
• Thread B reads the same Object Variable and updates its value to the db
• Now Thread A has a leaking byte array reference that is null

Solution: Instead of deleting an updating the byte array value, during the update, the deletion is simply skipped. The fix was verified with the customer.

The above behaviour introduces leftover byte-array state on type change. Thus, only during a type change, the byte-array is deleted.

Unit-tests: This commit introduces unit tests that verify the correct state of the variables on type change.

Limitations Accepted: The issue could not be reproduced with a unit test. However, this is accepted since the fix follows a common theme for value update across all the project and is not expected to produce a regression. Moreover, the mere reproduction of the problem using private calls doesn't give any extra value.

Co-authored-by: tasso94, petros.savvidis, yanavasileva Related-to: https://github.com/camunda/camunda-bpm-platform/issues/4324, https://jira.camunda.com/browse/SUPPORT-21494

[psavidis]

Notes for the Reviewer

• The behaviour to skip deleting the ByteArray introduces the side-effect of having a leftover byte-array state when the type changes e.g from Object to Long
• To mitigate that problem, the test shouldUpdateVariableStateOnVariableTypeChangeObjectToLong was added to verify that the correct state is populated when the variable has type object, but also when the variable changes to long.
  • That test fails on passes on master because on master, each update will always delete the byte-array
  • On SUPPORT-21721, the test fails without the fix on type change.

Note: The other two tests for Double-to-Object, String-to-Object type changes were added despite the fact that they do not fail on both branches. It is still important to add that coverage for other types

[psavidis]

Applied all points as suggested.

[psavidis]

❌ I doubt this change fixes the problem of the customer.

When I look at the following logs, I see that the byte array with this change is still deleted and reinserted:

 09:51:38.596 [main] DEBUG o.c.b.e.i.p.e.V.insertByteArray - ==>  Preparing: insert into ACT_GE_BYTEARRAY(ID_, NAME_, BYTES_, DEPLOYMENT_ID_, TENANT_ID_, TYPE_, CREATE_TIME_, ROOT_PROC_INST_ID_, REMOVAL_TIME_, REV_) values ( ?, ?, ?, ?, ?, ?, ?, ?, ?, 1 )
 09:51:38.597 [main] DEBUG o.c.b.e.i.p.e.V.insertByteArray - ==> Parameters: 16(String), myVar(String), java.io.ByteArrayInputStream@196d684b(ByteArrayInputStream), null, null, 2(Integer), 2024-06-20 09:51:38.586(Timestamp), null, null
 09:51:38.597 [main] DEBUG org.camunda.bpm.engine.persistence - ENGINE-03009 SQL operation: 'INSERT'; Entity: 'ByteArrayEntity[id=17]'
 09:51:38.597 [main] DEBUG o.c.b.e.i.p.e.V.insertByteArray - ==> Parameters: 17(String), myVar(String), java.io.ByteArrayInputStream@45d38165(ByteArrayInputStream), null, null, 3(Integer), 2024-06-20 09:51:38.587(Timestamp), 5(String), null
 09:51:38.597 [main] DEBUG org.camunda.bpm.engine.persistence - ENGINE-03009 SQL operation: 'INSERT'; Entity: 'ByteArrayEntity[id=19]'
 09:51:38.597 [main] DEBUG o.c.b.e.i.p.e.V.insertByteArray - ==> Parameters: 19(String), myVar(String), java.io.ByteArrayInputStream@1f3f434(ByteArrayInputStream), null, null, 3(Integer), 2024-06-20 09:51:38.588(Timestamp), 5(String), null
 09:51:38.597 [main] DEBUG org.camunda.bpm.engine.persistence - ENGINE-03009 SQL operation: 'DELETE'; Entity: 'MessageEntity[id=12]'
 09:51:38.597 [main] DEBUG org.camunda.bpm.engine.persistence - ENGINE-03009 SQL operation: 'UPDATE'; Entity: 'VariableInstanceEntity[id=7]'
 09:51:38.597 [main] DEBUG o.c.b.e.i.p.e.V.updateVariableInstance - ==>  Preparing: update ACT_RU_VARIABLE set REV_ = ?, EXECUTION_ID_ = ?, VAR_SCOPE_ = ?, TYPE_ = ?, BYTEARRAY_ID_ = ?, DOUBLE_ = ?, LONG_ = ?, TEXT_ = ?, TEXT2_ = ?, SEQUENCE_COUNTER_ = ? where ID_ = ? and REV_ = ?
 09:51:38.598 [main] DEBUG o.c.b.e.i.p.e.V.updateVariableInstance - ==> Parameters: 2(Integer), 5(String), 5(String), serializable(String), 16(String), null, null, null, org.camunda.bpm.engine.test.bpmn.scripttask.MySerializable(String), 2(Long), 7(String), 1(Integer)
 09:51:38.598 [main] DEBUG org.camunda.bpm.engine.persistence - ENGINE-03009 SQL operation: 'DELETE'; Entity: 'ByteArrayEntity[id=10]'
 09:51:38.598 [main] DEBUG o.c.b.e.i.p.e.V.deleteByteArray - ==>  Preparing: delete from ACT_GE_BYTEARRAY where ID_ = ? and REV_ = ?
 09:51:38.598 [main] DEBUG o.c.b.e.i.p.e.V.deleteByteArray - ==> Parameters: 10(String), 1(Integer)
 09:51:38.598 [main] DEBUG org.camunda.bpm.engine.persistence - ENGINE-03009 SQL operation: 'DELETE'; Entity: 'ByteArrayEntity[id=6]'
 09:51:38.598 [main] DEBUG o.c.b.e.i.p.e.V.deleteByteArray - ==> Parameters: 6(String), 1(Integer)

I produce these logs with the following test case in ScriptTaskTest:

  @Test
  public void produceLogsForupdateByteArrayBehavior() {
    deployProcess(Bpmn.createExecutableProcess("testProcess")
        .startEvent().camundaAsyncAfter()
        .scriptTask()
        .scriptFormat("groovy")
        .scriptText("println 'var ' + myVar")
        .scriptTask()
        .scriptFormat("groovy")
        .scriptText("execution.setVariable('myVar', new org.camunda.bpm.engine.test.bpmn.scripttask.MySerializable('test2'))")
        .userTask()
        .endEvent()
        .done());

    ProcessInstance pi = runtimeService.startProcessInstanceByKey("testProcess",
        Variables.createVariables().putValue("myVar", new org.camunda.bpm.engine.test.bpmn.scripttask.MySerializable("test")));

    String id = managementService.createJobQuery().singleResult().getId();
    managementService.executeJob(id);
  }

Instead, the logs should look like this:

09:59:21.892 [main] DEBUG o.c.b.e.i.p.e.V.insertByteArray - ==>  Preparing: insert into ACT_GE_BYTEARRAY(ID_, NAME_, BYTES_, DEPLOYMENT_ID_, TENANT_ID_, TYPE_, CREATE_TIME_, ROOT_PROC_INST_ID_, REMOVAL_TIME_, REV_) values ( ?, ?, ?, ?, ?, ?, ?, ?, ?, 1 )
09:59:21.901 [main] DEBUG o.c.b.e.i.p.e.V.insertByteArray - ==> Parameters: 10(String), myVar(String), java.io.ByteArrayInputStream@1d8be7b9(ByteArrayInputStream), null, null, 3(Integer), 2024-06-20 09:59:21.868(Timestamp), 5(String), null
09:59:21.901 [main] DEBUG o.c.b.e.i.p.e.V.insertByteArray - ==> Parameters: 6(String), myVar(String), java.io.ByteArrayInputStream@48277712(ByteArrayInputStream), null, null, 2(Integer), 2024-06-20 09:59:21.856(Timestamp), null, null
09:59:21.901 [main] DEBUG o.c.b.e.i.p.e.V.insertByteArray - ==> Parameters: 8(String), myVar(String), java.io.ByteArrayInputStream@3d53e876(ByteArrayInputStream), null, null, 3(Integer), 2024-06-20 09:59:21.863(Timestamp), 5(String), null
09:59:21.901 [main] DEBUG o.c.b.e.i.p.e.V.insertVariableInstance - ==>  Preparing: insert into ACT_RU_VARIABLE ( ID_, TYPE_, NAME_, PROC_DEF_ID_, PROC_INST_ID_, EXECUTION_ID_, CASE_INST_ID_, CASE_EXECUTION_ID_, TASK_ID_, BATCH_ID_, BYTEARRAY_ID_, DOUBLE_, LONG_, TEXT_, TEXT2_, VAR_SCOPE_, SEQUENCE_COUNTER_, IS_CONCURRENT_LOCAL_, TENANT_ID_, REV_ ) values ( ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, 1 )
09:59:21.902 [main] DEBUG o.c.b.e.i.p.e.V.insertVariableInstance - ==> Parameters: 7(String), serializable(String), myVar(String), testProcess:1:3(String), 5(String), 5(String), null, null, null, null, 6(String), null, null, null, org.camunda.bpm.engine.test.bpmn.scripttask.MySerializable(String), 5(String), 1(Long), false(Boolean), null
09:59:43.311 [main] DEBUG o.c.b.e.i.p.e.V.selectVariablesByExecutionId - ==>  Preparing: SELECT RES.*, ( case when RES.TASK_ID_ is not null and RES.EXECUTION_ID_ is not null then EXECUTION.ACT_INST_ID_ when RES.CASE_EXECUTION_ID_ is not null then RES.CASE_EXECUTION_ID_ when EXECUTION.PARENT_ID_ is null and RES.IS_CONCURRENT_LOCAL_ = false then EXECUTION.ID_ when EXECUTION.IS_SCOPE_ = true and EXECUTION.PARENT_ID_ is not null and RES.IS_CONCURRENT_LOCAL_ = false then PARENT_EXECUTION.ACT_INST_ID_ else EXECUTION.ACT_INST_ID_ end ) ACT_INST_ID_ FROM ACT_RU_VARIABLE RES LEFT JOIN ACT_RU_EXECUTION EXECUTION ON RES.EXECUTION_ID_ = EXECUTION.ID_ LEFT JOIN ACT_RU_EXECUTION PARENT_EXECUTION ON EXECUTION.PARENT_ID_ = PARENT_EXECUTION.ID_ WHERE EXECUTION_ID_ = ? AND TASK_ID_ is null
09:59:43.311 [main] DEBUG o.c.b.e.i.p.e.V.selectVariablesByExecutionId - ==> Parameters: 5(String)
09:59:43.318 [main] DEBUG o.c.b.e.i.p.e.V.selectVariablesByExecutionId - <==      Total: 1
09:59:43.318 [main] DEBUG o.c.b.e.i.p.e.V.selectByteArray - ==>  Preparing: select * from ACT_GE_BYTEARRAY where ID_ = ?
09:59:43.318 [main] DEBUG o.c.b.e.i.p.e.V.selectByteArray - ==> Parameters: 6(String)
09:59:43.320 [main] DEBUG o.c.b.e.i.p.e.V.selectByteArray - <==      Total: 1
var org.camunda.bpm.engine.test.bpmn.scripttask.MySerializable@6dde1bf5
09:59:43.363 [main] DEBUG o.c.b.e.i.p.e.V.selectByteArray - ==>  Preparing: select * from ACT_GE_BYTEARRAY where ID_ = ?
09:59:43.364 [main] DEBUG o.c.b.e.i.p.e.V.selectByteArray - ==> Parameters: 10(String)
09:59:43.364 [main] DEBUG o.c.b.e.i.p.e.V.selectByteArray - <==      Total: 1
09:59:43.375 [main] DEBUG o.c.b.e.i.p.e.V.insertByteArray - ==>  Preparing: insert into ACT_GE_BYTEARRAY(ID_, NAME_, BYTES_, DEPLOYMENT_ID_, TENANT_ID_, TYPE_, CREATE_TIME_, ROOT_PROC_INST_ID_, REMOVAL_TIME_, REV_) values ( ?, ?, ?, ?, ?, ?, ?, ?, ?, 1 )
09:59:43.376 [main] DEBUG o.c.b.e.i.p.e.V.insertByteArray - ==> Parameters: 16(String), myVar(String), java.io.ByteArrayInputStream@18dbc1b(ByteArrayInputStream), null, null, 3(Integer), 2024-06-20 09:59:43.363(Timestamp), 5(String), null
09:59:43.376 [main] DEBUG o.c.b.e.i.p.e.V.insertByteArray - ==> Parameters: 18(String), myVar(String), java.io.ByteArrayInputStream@2a510e0e(ByteArrayInputStream), null, null, 3(Integer), 2024-06-20 09:59:43.364(Timestamp), 5(String), null
09:59:43.377 [main] DEBUG o.c.b.e.i.p.e.V.updateVariableInstance - ==>  Preparing: update ACT_RU_VARIABLE set REV_ = ?, EXECUTION_ID_ = ?, VAR_SCOPE_ = ?, TYPE_ = ?, BYTEARRAY_ID_ = ?, DOUBLE_ = ?, LONG_ = ?, TEXT_ = ?, TEXT2_ = ?, SEQUENCE_COUNTER_ = ? where ID_ = ? and REV_ = ?
09:59:43.377 [main] DEBUG o.c.b.e.i.p.e.V.updateVariableInstance - ==> Parameters: 2(Integer), 5(String), 5(String), serializable(String), 6(String), null, null, null, org.camunda.bpm.engine.test.bpmn.scripttask.MySerializable(String), 2(Long), 7(String), 1(Integer)
09:59:43.377 [main] DEBUG o.c.b.e.i.p.e.V.updateByteArray - ==>  Preparing: update ACT_GE_BYTEARRAY set REV_ = ?, BYTES_ = ? where ID_ = ? and REV_ = ?
09:59:43.377 [main] DEBUG o.c.b.e.i.p.e.V.updateByteArray - ==> Parameters: 2(Integer), java.io.ByteArrayInputStream@7c5ac0(ByteArrayInputStream), 6(String), 1(Integer)
09:59:43.377 [main] DEBUG o.c.b.e.i.p.e.V.deleteByteArray - ==>  Preparing: delete from ACT_GE_BYTEARRAY where ID_ = ? and REV_ = ?
09:59:43.377 [main] DEBUG o.c.b.e.i.p.e.V.deleteByteArray - ==> Parameters: 10(String), 1(Integer)

Thanks for the detailed test case. I've incorporated and adjusted it into the VariableInstanceTest to have a failing test for the issue with the type change.

• The problematic behaviour was the type change detection which was using the class names (the MySerializable was returning Object as a type name).
• I've added a test which checks the byteArrayId before and after the update to detect if there's been an delete / insert on the byte array which fails without the fix
• The fix uses the class from the value of the variable to make the comparison.

[psavidis]

❌ Please add the following test cases:

• the new value is null, the old value is not null.
• the old value is null the new value is not null.

Added two more test cases as recommended:

1. Update Variable: null -> not-null (shouldDeleteByteArrayOnUpdateOfExistingNullVariable)
2. Update Variable: non-null -> null (shouldDeleteByteArrayOnNullifyOfExistingNonNullVariable)

For both test cases, null is considered a separate type, therefore a type change and the byte array should be deleted.