[BUG] Transform _search API calls don't have timeout parameter

[petardz]

What is the bug?
Transform _search API calls don't have timeout parameter (default value is NO_TIMEOUT). This can result in JobScheduler's lock to expire(30mins is expiry).

How can one reproduce the bug?
Steps to reproduce the behavior:

1. Setup Transform job on heavy index where _search API call would last more then 30mins, for example 45mins
2. Set Schedule to something small, for example 5mins
3. Observe lock being released and another transform job acquiring it, before current job finished

What is the expected behavior?
We should keep track of time under lock and renew it when needed. All _search API calls should have appropriate timeout parameter which will give us a chance to renew lock before expiring.

[stevanbz]

Hi.
Tnx for the explanation and for proposal. I think you are right and I think that I managed to reproduce the issue, but with some "hackish" things which I will try to explain:

1. Reduce the Transform (https://github.com/opensearch-project/index-management/blob/main/src/main/kotlin/org/opensearch/indexmanagement/transform/model/Transform.kt#L269) to 60 seconds
2. In TransformRunner, after the lock is being acquired (https://github.com/opensearch-project/index-management/blob/main/src/main/kotlin/org/opensearch/indexmanagement/transform/TransformRunner.kt#L117) add some sleeping of the current thread ie. Thread.sleep(5000L)
3. In TransformRunner (https://github.com/opensearch-project/index-management/blob/main/src/main/kotlin/org/opensearch/indexmanagement/transform/TransformRunner.kt#L292), before the search request is being sent against the cluster, add thread sleeping that is greater than 60 seconds ie. Thread.sleep(70000L) (maybe steps 3 and 4 can be "merged" in reproducing the issue)
4. Schedule a Transform that will be triggered every one minute against the (test) index
5. NPE is being raised with a message
   java.lang.NullPointerException: Cannot invoke "org.opensearch.jobscheduler.spi.LockModel.getLockDurationSeconds()" because "renewedLock" is null at org.opensearch.jobscheduler.spi.utils.LockService.lambda$renewLock$13(LockService.java:339) ~[?:?] at org.opensearch.action.ActionListener$1.onResponse(ActionListener.java:80) ~[opensearch-2.3.0-SNAPSHOT.jar:2.3.0-SNAPSHOT] at org.opensearch.jobscheduler.spi.utils.LockService.lambda$updateLock$5(LockService.java:208) ~[?:?] at org.opensearch.action.ActionListener$1.onFailure(ActionListener.java:88) ~[opensearch-2.3.0-SNAPSHOT.jar:2.3.0-SNAPSHOT] at org.opensearch.action.support.TransportAction$1.onFailure(TransportAction.java:122) ~[opensearch-2.3.0-SNAPSHOT.jar:2.3.0-SNAPSHOT] at org.opensearch.action.support.single.instance.TransportInstanceSingleOperationAction$AsyncSingleAction$1.handleException(TransportInstanceSingleOperationAction.java:245) ~[opensearch-2.3.0-SNAPSHOT.jar:2.3.0-SNAPSHOT] at org.opensearch.transport.TransportService$ContextRestoreResponseHandler.handleException(TransportService.java:1379) ~[opensearch-2.3.0-SNAPSHOT.jar:2.3.0-SNAPSHOT] at org.opensearch.transport.TransportService$DirectResponseChannel.processException(TransportService.java:1493) ~[opensearch-2.3.0-SNAPSHOT.jar:2.3.0-SNAPSHOT] at org.opensearch.transport.TransportService$DirectResponseChannel.sendResponse(TransportService.java:1467) ~[opensearch-2.3.0-SNAPSHOT.jar:2.3.0-SNAPSHOT] at org.opensearch.transport.TaskTransportChannel.sendResponse(TaskTransportChannel.java:79) ~[opensearch-2.3.0-SNAPSHOT.jar:2.3.0-SNAPSHOT] at org.opensearch.action.support.single.instance.TransportInstanceSingleOperationAction$ShardTransportHandler$1.onFailure(TransportInstanceSingleOperationAction.java:312) ~[opensearch-2.3.0-SNAPSHOT.jar:2.3.0-SNAPSHOT] at org.opensearch.common.util.concurrent.ThreadContext$ContextPreservingAbstractRunnable.onFailure(ThreadContext.java:794) ~[opensearch-2.3.0-SNAPSHOT.jar:2.3.0-SNAPSHOT] at org.opensearch.common.util.concurrent.AbstractRunnable.run(AbstractRunnable.java:54) ~[opensearch-2.3.0-SNAPSHOT.jar:2.3.0-SNAPSHOT] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1136) ~[?:?] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:635) ~[?:?] at java.lang.Thread.run(Thread.java:833) ~[?:?] [2022-10-11T10:32:00,983][WARN ][JobSchedulerUtils ] [integTest-0] Could not release lock for job test-transform-1

Explanation of the steps 3 and 4.
The transform job we are scheduling is occurred every one minute - that means that every minute one job execution will be triggered. Each job execution is being run in a separate thread. In order not to create the overload on the cluster (since transform job execution does at least two queries against the target index which can be huge), job executions of the same transform are waiting for the lock to be released (they are blocked by using a lock object) before entering the critical section of a runner code. To be able to reproduce the issue, we selected the lowest time period in which we can trigger multiple transform executions (which is 1 minute). To be sure that previous started job is not finished and that the lock is expired we are adding a sleeping that is greater then 60 seconds.

Problem explanation
The NPE that is being raised clearly says that the previously ran transform job execution (let's name it job1) is trying to continue the execution by re-fetching the lock, but in the meantime another transform job execution (job2) for the same transform already took the lock.
That means that now job2 holds the lock, while job1 failed with the NPE for the given transform.

Idea
Hopefully, I will have a solution very soon for this, which will, like you described have the timeout period (ie. transformJobLockExpiration - now) for the requests that are being sent on the cluster and which will try-catch the error if the cluster failed to deliver in the given period of time. If the cluster timeout happened, job execution will renew the lock, and trigger a request with a new timeout. The previous explanation of the idea is abstract, but I think you will get the point.

[stevanbz]

In order to see if this bugfix is working and if the request is being retried if the timeout period of transform search request is breached I had to do couple of changes:

1. Hard-coded the timeout value in the code to extremely low value like 1ms in this line: https://github.com/opensearch-project/index-management/pull/576/files#diff-a95909b62294ea757b769650a9ebeaebb0bdd49a25de737e1381d5fea84c383bR303
2. Create a transform job that will be executed in one minute
3. Follow how the retry mechanism behaves (https://github.com/opensearch-project/index-management/pull/576/files#diff-d37065eae0ee05638987e8907236c697757b3cf02c3fd3fa1b2e090ded9da1eeR38), and check the value of the timeout parameter (if it is always renewed)