There is currently no way to know whether a graph is currently replaying all invocations which prevents using some use cases like fetching the output of a replaying invocation.
What
This PR makes it possible to do:
g.replay_invocations()
while g.metadata().replaying: # <- New capability
time.sleep(1)
print("Replaying...")
output = g.output(invocation_id, fn_name="update2")
In order to do so, some system task refactoring was needed. Here is what changed:
System tasks used to be removed when all invocations to be replayed would be queued up. This is no longer the case. Now, the system task will only be removed when all of the replaying invocations are finished.
When a new replay invocation starts, we increment the number of running invocations on the system task
When an invocation started by a system task finished, we are decrement the number of running invocations on the system task
The system task executor received an event whenever a decrement happens or a system task is created or a deleted.
This change ensures that no two reruns can happen in parallel. This was somehow prevented before, but could still happen if replaying invocations continued running after the system task queued up all tasks.
This change simplifies the bookkeeping necessary to keep track of whether a compute graph is replaying or not. We can now mark it as replaying when creating a system task and mark it as not replaying when the system task is removed/deleted.
Note: You can see an alternative approach to solve this problem in https://github.com/tensorlakeai/indexify/pull/999. But it was decided to simplify system tasks which was done as part of this PR.
Testing
The test tests/test_graph_update.py was leveraged to test this feature.
Details
```
2024-11-15T21:15:58.392766Z INFO indexify_server::service: starting scheduler
2024-11-15T21:15:58.392768Z INFO indexify_server::service: starting system tasks executor
2024-11-15T21:15:58.392767Z INFO indexify_server::service: starting garbage collector
2024-11-15T21:15:58.393296Z INFO indexify_server::service: created default namespace
2024-11-15T21:15:58.393309Z INFO indexify_server::service: server api listening on 0.0.0.0:8900
2024-11-15T21:15:58.393338Z INFO indexify_server::system_tasks: no system tasks to process
2024-11-15T21:16:01.996349Z DEBUG request: tower_http::trace::on_request: started processing request method="POST" uri="/internal/executors/N--EqyG4Eaw86QAp3MpOR/tasks" matched_path="/internal/executors/:id/tasks"
2024-11-15T21:16:01.996915Z DEBUG request: tower_http::trace::on_response: finished processing request latency=0 ms status=200 method="POST" uri="/internal/executors/N--EqyG4Eaw86QAp3MpOR/tasks" matched_path="/internal/executors/:id/tasks"
2024-11-15T21:16:03.402596Z DEBUG request: tower_http::trace::on_request: started processing request method="POST" uri="/namespaces/default/compute_graphs" matched_path="/namespaces/:namespace/compute_graphs"
2024-11-15T21:16:03.404146Z INFO request: indexify_server::routes: compute graph created: __main__.TestGraphUpdate.test_graph_update method="POST" uri="/namespaces/default/compute_graphs" matched_path="/namespaces/:namespace/compute_graphs"
2024-11-15T21:16:03.404180Z DEBUG request: tower_http::trace::on_response: finished processing request latency=1 ms status=200 method="POST" uri="/namespaces/default/compute_graphs" matched_path="/namespaces/:namespace/compute_graphs"
2024-11-15T21:16:03.418112Z DEBUG request: tower_http::trace::on_request: started processing request method="POST" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invoke_object?block_until_finish=true" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invoke_object"
2024-11-15T21:16:03.420137Z DEBUG request: tower_http::trace::on_response: finished processing request latency=2 ms status=200 method="POST" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invoke_object?block_until_finish=true" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invoke_object"
2024-11-15T21:16:03.421102Z INFO task_scheduler: assigning task TaskId("115d2d97-6ed4-4ca4-b984-bb0bc5839f8a") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:03.423827Z DEBUG request: tower_http::trace::on_request: started processing request method="GET" uri="/internal/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/code" matched_path="/internal/namespaces/:namespace/compute_graphs/:compute_graph/code"
2024-11-15T21:16:03.424061Z DEBUG request: tower_http::trace::on_response: finished processing request latency=0 ms status=200 method="GET" uri="/internal/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/code" matched_path="/internal/namespaces/:namespace/compute_graphs/:compute_graph/code"
2024-11-15T21:16:03.425327Z DEBUG request: tower_http::trace::on_request: started processing request method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/1adaad644b88fddf/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload"
2024-11-15T21:16:03.425491Z DEBUG request: tower_http::trace::on_response: finished processing request latency=0 ms status=200 method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/1adaad644b88fddf/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload"
2024-11-15T21:16:03.430567Z DEBUG request: tower_http::trace::on_request: started processing request method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files"
2024-11-15T21:16:03.430728Z INFO request: indexify_server::routes::internal_ingest: writing to blob store, file name = "default.__main__.TestGraphUpdate.test_graph_update.update.1adaad644b88fddf.115d2d97-6ed4-4ca4-b984-bb0bc5839f8a.0" method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files"
2024-11-15T21:16:03.432299Z DEBUG request: tower_http::trace::on_response: finished processing request latency=1 ms status=200 method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files"
2024-11-15T21:16:03.432779Z INFO task_scheduler::task_creator: compute graph __main__.TestGraphUpdate.test_graph_update invocation finished: false
2024-11-15T21:16:03.432824Z INFO state_store::state_machine: Marking invocation finished: default __main__.TestGraphUpdate.test_graph_update 1adaad644b88fddf
2024-11-15T21:16:03.433478Z DEBUG request: tower_http::trace::on_request: started processing request method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/1adaad644b88fddf/outputs" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/outputs"
2024-11-15T21:16:03.433727Z DEBUG request: tower_http::trace::on_response: finished processing request latency=0 ms status=200 method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/1adaad644b88fddf/outputs" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/outputs"
2024-11-15T21:16:03.434204Z DEBUG request: tower_http::trace::on_request: started processing request method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/1adaad644b88fddf/fn/update/output/948ba598e53ed761" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/fn/:fn_name/output/:id"
2024-11-15T21:16:03.434391Z DEBUG request: tower_http::trace::on_response: finished processing request latency=0 ms status=200 method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/1adaad644b88fddf/fn/update/output/948ba598e53ed761" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/fn/:fn_name/output/:id"
2024-11-15T21:16:03.448696Z DEBUG request: tower_http::trace::on_request: started processing request method="POST" uri="/namespaces/default/compute_graphs" matched_path="/namespaces/:namespace/compute_graphs"
2024-11-15T21:16:03.450318Z INFO request: indexify_server::routes: compute graph created: __main__.TestGraphUpdate.test_graph_update method="POST" uri="/namespaces/default/compute_graphs" matched_path="/namespaces/:namespace/compute_graphs"
2024-11-15T21:16:03.450383Z DEBUG request: tower_http::trace::on_response: finished processing request latency=1 ms status=200 method="POST" uri="/namespaces/default/compute_graphs" matched_path="/namespaces/:namespace/compute_graphs"
2024-11-15T21:16:03.451045Z DEBUG request: tower_http::trace::on_request: started processing request method="POST" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/replay" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/replay"
2024-11-15T21:16:03.451665Z DEBUG request: tower_http::trace::on_response: finished processing request latency=0 ms status=200 method="POST" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/replay" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/replay"
2024-11-15T21:16:03.451862Z INFO system_task: indexify_server::system_tasks: queueing invocations queuing=1 task="default|__main__.TestGraphUpdate.test_graph_update" type="replay"
2024-11-15T21:16:03.452459Z INFO system_task: indexify_server::system_tasks: waiting for all invotations to finish before completing the task running_invocations=1 task="default|__main__.TestGraphUpdate.test_graph_update" type="replay"
2024-11-15T21:16:03.453357Z INFO task_scheduler: assigning task TaskId("bb6ad8fd-2f64-492f-a5f8-0f79274d0100") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:03.453761Z DEBUG request: tower_http::trace::on_request: started processing request method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph"
2024-11-15T21:16:03.453891Z DEBUG request: tower_http::trace::on_response: finished processing request latency=0 ms status=200 method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph"
2024-11-15T21:16:03.454960Z DEBUG request: tower_http::trace::on_request: started processing request method="GET" uri="/internal/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/code" matched_path="/internal/namespaces/:namespace/compute_graphs/:compute_graph/code"
2024-11-15T21:16:03.455197Z DEBUG request: tower_http::trace::on_response: finished processing request latency=0 ms status=200 method="GET" uri="/internal/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/code" matched_path="/internal/namespaces/:namespace/compute_graphs/:compute_graph/code"
2024-11-15T21:16:03.456212Z DEBUG request: tower_http::trace::on_request: started processing request method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/1adaad644b88fddf/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload"
2024-11-15T21:16:03.456374Z DEBUG request: tower_http::trace::on_response: finished processing request latency=0 ms status=200 method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/1adaad644b88fddf/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload"
2024-11-15T21:16:03.458808Z DEBUG request: tower_http::trace::on_request: started processing request method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files"
2024-11-15T21:16:03.459008Z INFO request: indexify_server::routes::internal_ingest: writing to blob store, file name = "default.__main__.TestGraphUpdate.test_graph_update.update2.1adaad644b88fddf.bb6ad8fd-2f64-492f-a5f8-0f79274d0100.0" method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files"
2024-11-15T21:16:03.460483Z DEBUG request: tower_http::trace::on_response: finished processing request latency=1 ms status=200 method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files"
2024-11-15T21:16:03.460890Z INFO task_scheduler::task_creator: compute graph __main__.TestGraphUpdate.test_graph_update invocation finished: false
2024-11-15T21:16:03.460931Z INFO state_store::state_machine: Marking invocation finished: default __main__.TestGraphUpdate.test_graph_update 1adaad644b88fddf
2024-11-15T21:16:03.461075Z ERROR state_store: failed to send invocation state change: SendError(InvocationFinished(InvocationFinishedEvent { id: "1adaad644b88fddf" }))
2024-11-15T21:16:03.461227Z INFO system_task: indexify_server::system_tasks: completed task="default|__main__.TestGraphUpdate.test_graph_update" type="replay"
2024-11-15T21:16:03.461428Z INFO indexify_server::system_tasks: no system tasks to process
2024-11-15T21:16:04.462233Z DEBUG request: tower_http::trace::on_request: started processing request method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph"
2024-11-15T21:16:04.463549Z DEBUG request: tower_http::trace::on_response: finished processing request latency=1 ms status=200 method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph"
2024-11-15T21:16:04.466759Z DEBUG request: tower_http::trace::on_request: started processing request method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/1adaad644b88fddf/outputs" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/outputs"
2024-11-15T21:16:04.468028Z DEBUG request: tower_http::trace::on_response: finished processing request latency=1 ms status=200 method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/1adaad644b88fddf/outputs" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/outputs"
2024-11-15T21:16:04.478023Z DEBUG request: tower_http::trace::on_request: started processing request method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/1adaad644b88fddf/fn/update2/output/c809135cac89ad7f" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/fn/:fn_name/output/:id"
2024-11-15T21:16:04.478714Z DEBUG request: tower_http::trace::on_response: finished processing request latency=0 ms status=200 method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/1adaad644b88fddf/fn/update2/output/c809135cac89ad7f" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/fn/:fn_name/output/:id"
2024-11-15T21:16:04.501679Z DEBUG request: tower_http::trace::on_request: started processing request method="POST" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invoke_object?block_until_finish=true" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invoke_object"
2024-11-15T21:16:04.504179Z DEBUG request: tower_http::trace::on_response: finished processing request latency=2 ms status=200 method="POST" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invoke_object?block_until_finish=true" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invoke_object"
2024-11-15T21:16:04.505411Z INFO task_scheduler: assigning task TaskId("1971913c-ce96-47fd-b89b-ca52fee82d61") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.507361Z DEBUG request: tower_http::trace::on_request: started processing request method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/b7fabce39e8a8e9a/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload"
2024-11-15T21:16:04.507594Z DEBUG request: tower_http::trace::on_response: finished processing request latency=0 ms status=200 method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/b7fabce39e8a8e9a/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload"
2024-11-15T21:16:04.510057Z DEBUG request: tower_http::trace::on_request: started processing request method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files"
2024-11-15T21:16:04.510248Z INFO request: indexify_server::routes::internal_ingest: writing to blob store, file name = "default.__main__.TestGraphUpdate.test_graph_update.update2.b7fabce39e8a8e9a.1971913c-ce96-47fd-b89b-ca52fee82d61.0" method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files"
2024-11-15T21:16:04.512112Z DEBUG request: tower_http::trace::on_response: finished processing request latency=2 ms status=200 method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files"
2024-11-15T21:16:04.512739Z INFO task_scheduler::task_creator: compute graph __main__.TestGraphUpdate.test_graph_update invocation finished: false
2024-11-15T21:16:04.512830Z INFO state_store::state_machine: Marking invocation finished: default __main__.TestGraphUpdate.test_graph_update b7fabce39e8a8e9a
2024-11-15T21:16:04.529248Z DEBUG request: tower_http::trace::on_request: started processing request method="POST" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invoke_object?block_until_finish=true" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invoke_object"
2024-11-15T21:16:04.531498Z DEBUG request: tower_http::trace::on_response: finished processing request latency=2 ms status=200 method="POST" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invoke_object?block_until_finish=true" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invoke_object"
2024-11-15T21:16:04.532585Z INFO task_scheduler: assigning task TaskId("d014a246-4fb2-45a4-a575-21bfee407e0e") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.534381Z DEBUG request: tower_http::trace::on_request: started processing request method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/1a1a202bcb77ca40/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload"
2024-11-15T21:16:04.534620Z DEBUG request: tower_http::trace::on_response: finished processing request latency=0 ms status=200 method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/1a1a202bcb77ca40/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload"
2024-11-15T21:16:04.536699Z DEBUG request: tower_http::trace::on_request: started processing request method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files"
2024-11-15T21:16:04.536869Z INFO request: indexify_server::routes::internal_ingest: writing to blob store, file name = "default.__main__.TestGraphUpdate.test_graph_update.update2.1a1a202bcb77ca40.d014a246-4fb2-45a4-a575-21bfee407e0e.0" method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files"
2024-11-15T21:16:04.538543Z DEBUG request: tower_http::trace::on_response: finished processing request latency=1 ms status=200 method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files"
2024-11-15T21:16:04.538994Z INFO task_scheduler::task_creator: compute graph __main__.TestGraphUpdate.test_graph_update invocation finished: false
2024-11-15T21:16:04.539042Z INFO state_store::state_machine: Marking invocation finished: default __main__.TestGraphUpdate.test_graph_update 1a1a202bcb77ca40
2024-11-15T21:16:04.552994Z DEBUG request: tower_http::trace::on_request: started processing request method="POST" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invoke_object?block_until_finish=true" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invoke_object"
2024-11-15T21:16:04.554911Z DEBUG request: tower_http::trace::on_response: finished processing request latency=1 ms status=200 method="POST" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invoke_object?block_until_finish=true" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invoke_object"
2024-11-15T21:16:04.555821Z INFO task_scheduler: assigning task TaskId("a1d6b518-5792-4aa2-b1fb-5e18403b93e0") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.557317Z DEBUG request: tower_http::trace::on_request: started processing request method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/205684db422504d4/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload"
2024-11-15T21:16:04.557540Z DEBUG request: tower_http::trace::on_response: finished processing request latency=0 ms status=200 method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/205684db422504d4/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload"
2024-11-15T21:16:04.559394Z DEBUG request: tower_http::trace::on_request: started processing request method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files"
2024-11-15T21:16:04.559527Z INFO request: indexify_server::routes::internal_ingest: writing to blob store, file name = "default.__main__.TestGraphUpdate.test_graph_update.update2.205684db422504d4.a1d6b518-5792-4aa2-b1fb-5e18403b93e0.0" method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files"
2024-11-15T21:16:04.560924Z DEBUG request: tower_http::trace::on_response: finished processing request latency=1 ms status=200 method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files"
2024-11-15T21:16:04.561314Z INFO task_scheduler::task_creator: compute graph __main__.TestGraphUpdate.test_graph_update invocation finished: false
2024-11-15T21:16:04.561355Z INFO state_store::state_machine: Marking invocation finished: default __main__.TestGraphUpdate.test_graph_update 205684db422504d4
2024-11-15T21:16:04.574587Z DEBUG request: tower_http::trace::on_request: started processing request method="POST" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invoke_object?block_until_finish=true" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invoke_object"
2024-11-15T21:16:04.576272Z DEBUG request: tower_http::trace::on_response: finished processing request latency=1 ms status=200 method="POST" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invoke_object?block_until_finish=true" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invoke_object"
2024-11-15T21:16:04.577064Z INFO task_scheduler: assigning task TaskId("cfb2fc0f-36bc-4c64-9a7b-2368a5a139b6") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.578431Z DEBUG request: tower_http::trace::on_request: started processing request method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/31931e6c0c28803b/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload"
2024-11-15T21:16:04.578648Z DEBUG request: tower_http::trace::on_response: finished processing request latency=0 ms status=200 method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/31931e6c0c28803b/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload"
2024-11-15T21:16:04.580745Z DEBUG request: tower_http::trace::on_request: started processing request method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files"
2024-11-15T21:16:04.580895Z INFO request: indexify_server::routes::internal_ingest: writing to blob store, file name = "default.__main__.TestGraphUpdate.test_graph_update.update2.31931e6c0c28803b.cfb2fc0f-36bc-4c64-9a7b-2368a5a139b6.0" method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files"
2024-11-15T21:16:04.582492Z DEBUG request: tower_http::trace::on_response: finished processing request latency=1 ms status=200 method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files"
2024-11-15T21:16:04.582927Z INFO task_scheduler::task_creator: compute graph __main__.TestGraphUpdate.test_graph_update invocation finished: false
2024-11-15T21:16:04.582972Z INFO state_store::state_machine: Marking invocation finished: default __main__.TestGraphUpdate.test_graph_update 31931e6c0c28803b
2024-11-15T21:16:04.596233Z DEBUG request: tower_http::trace::on_request: started processing request method="POST" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invoke_object?block_until_finish=true" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invoke_object"
2024-11-15T21:16:04.598019Z DEBUG request: tower_http::trace::on_response: finished processing request latency=1 ms status=200 method="POST" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invoke_object?block_until_finish=true" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invoke_object"
2024-11-15T21:16:04.598950Z INFO task_scheduler: assigning task TaskId("a857a0d7-de0e-4dab-aedf-ff37333aa4d3") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.600527Z DEBUG request: tower_http::trace::on_request: started processing request method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/6144e7fa455f8a48/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload"
2024-11-15T21:16:04.600758Z DEBUG request: tower_http::trace::on_response: finished processing request latency=0 ms status=200 method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/6144e7fa455f8a48/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload"
2024-11-15T21:16:04.602738Z DEBUG request: tower_http::trace::on_request: started processing request method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files"
2024-11-15T21:16:04.602898Z INFO request: indexify_server::routes::internal_ingest: writing to blob store, file name = "default.__main__.TestGraphUpdate.test_graph_update.update2.6144e7fa455f8a48.a857a0d7-de0e-4dab-aedf-ff37333aa4d3.0" method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files"
2024-11-15T21:16:04.604337Z DEBUG request: tower_http::trace::on_response: finished processing request latency=1 ms status=200 method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files"
2024-11-15T21:16:04.604760Z INFO task_scheduler::task_creator: compute graph __main__.TestGraphUpdate.test_graph_update invocation finished: false
2024-11-15T21:16:04.604804Z INFO state_store::state_machine: Marking invocation finished: default __main__.TestGraphUpdate.test_graph_update 6144e7fa455f8a48
2024-11-15T21:16:04.617455Z DEBUG request: tower_http::trace::on_request: started processing request method="POST" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invoke_object?block_until_finish=true" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invoke_object"
2024-11-15T21:16:04.619236Z DEBUG request: tower_http::trace::on_response: finished processing request latency=1 ms status=200 method="POST" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invoke_object?block_until_finish=true" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invoke_object"
2024-11-15T21:16:04.620107Z INFO task_scheduler: assigning task TaskId("19989dad-f753-48da-8a9e-8821bbf03084") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.621612Z DEBUG request: tower_http::trace::on_request: started processing request method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/f33202d46cf93963/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload"
2024-11-15T21:16:04.621813Z DEBUG request: tower_http::trace::on_response: finished processing request latency=0 ms status=200 method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/f33202d46cf93963/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload"
2024-11-15T21:16:04.623699Z DEBUG request: tower_http::trace::on_request: started processing request method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files"
2024-11-15T21:16:04.623845Z INFO request: indexify_server::routes::internal_ingest: writing to blob store, file name = "default.__main__.TestGraphUpdate.test_graph_update.update2.f33202d46cf93963.19989dad-f753-48da-8a9e-8821bbf03084.0" method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files"
2024-11-15T21:16:04.625251Z DEBUG request: tower_http::trace::on_response: finished processing request latency=1 ms status=200 method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files"
2024-11-15T21:16:04.625646Z INFO task_scheduler::task_creator: compute graph __main__.TestGraphUpdate.test_graph_update invocation finished: false
2024-11-15T21:16:04.625686Z INFO state_store::state_machine: Marking invocation finished: default __main__.TestGraphUpdate.test_graph_update f33202d46cf93963
2024-11-15T21:16:04.638921Z DEBUG request: tower_http::trace::on_request: started processing request method="POST" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invoke_object?block_until_finish=true" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invoke_object"
2024-11-15T21:16:04.640636Z DEBUG request: tower_http::trace::on_response: finished processing request latency=1 ms status=200 method="POST" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invoke_object?block_until_finish=true" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invoke_object"
2024-11-15T21:16:04.641443Z INFO task_scheduler: assigning task TaskId("5b41c2bb-67ce-4be9-9e7e-79f1f997c1d7") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.642899Z DEBUG request: tower_http::trace::on_request: started processing request method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/7b8346f2537b2f74/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload"
2024-11-15T21:16:04.643079Z DEBUG request: tower_http::trace::on_response: finished processing request latency=0 ms status=200 method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/7b8346f2537b2f74/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload"
2024-11-15T21:16:04.644915Z DEBUG request: tower_http::trace::on_request: started processing request method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files"
2024-11-15T21:16:04.645072Z INFO request: indexify_server::routes::internal_ingest: writing to blob store, file name = "default.__main__.TestGraphUpdate.test_graph_update.update2.7b8346f2537b2f74.5b41c2bb-67ce-4be9-9e7e-79f1f997c1d7.0" method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files"
2024-11-15T21:16:04.646516Z DEBUG request: tower_http::trace::on_response: finished processing request latency=1 ms status=200 method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files"
2024-11-15T21:16:04.646926Z INFO task_scheduler::task_creator: compute graph __main__.TestGraphUpdate.test_graph_update invocation finished: false
2024-11-15T21:16:04.646972Z INFO state_store::state_machine: Marking invocation finished: default __main__.TestGraphUpdate.test_graph_update 7b8346f2537b2f74
2024-11-15T21:16:04.660081Z DEBUG request: tower_http::trace::on_request: started processing request method="POST" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invoke_object?block_until_finish=true" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invoke_object"
2024-11-15T21:16:04.661811Z DEBUG request: tower_http::trace::on_response: finished processing request latency=1 ms status=200 method="POST" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invoke_object?block_until_finish=true" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invoke_object"
2024-11-15T21:16:04.662674Z INFO task_scheduler: assigning task TaskId("f46f0a80-78a9-4812-93ac-c05b6def6356") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.664101Z DEBUG request: tower_http::trace::on_request: started processing request method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/f9c203d1cc58c0e9/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload"
2024-11-15T21:16:04.664305Z DEBUG request: tower_http::trace::on_response: finished processing request latency=0 ms status=200 method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/f9c203d1cc58c0e9/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload"
2024-11-15T21:16:04.666352Z DEBUG request: tower_http::trace::on_request: started processing request method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files"
2024-11-15T21:16:04.666505Z INFO request: indexify_server::routes::internal_ingest: writing to blob store, file name = "default.__main__.TestGraphUpdate.test_graph_update.update2.f9c203d1cc58c0e9.f46f0a80-78a9-4812-93ac-c05b6def6356.0" method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files"
2024-11-15T21:16:04.668051Z DEBUG request: tower_http::trace::on_response: finished processing request latency=1 ms status=200 method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files"
2024-11-15T21:16:04.668462Z INFO task_scheduler::task_creator: compute graph __main__.TestGraphUpdate.test_graph_update invocation finished: false
2024-11-15T21:16:04.668505Z INFO state_store::state_machine: Marking invocation finished: default __main__.TestGraphUpdate.test_graph_update f9c203d1cc58c0e9
2024-11-15T21:16:04.681457Z DEBUG request: tower_http::trace::on_request: started processing request method="POST" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invoke_object?block_until_finish=true" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invoke_object"
2024-11-15T21:16:04.683283Z DEBUG request: tower_http::trace::on_response: finished processing request latency=1 ms status=200 method="POST" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invoke_object?block_until_finish=true" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invoke_object"
2024-11-15T21:16:04.684151Z INFO task_scheduler: assigning task TaskId("3023ad50-6c66-4ff5-9c28-ecbb13c54143") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.685676Z DEBUG request: tower_http::trace::on_request: started processing request method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/83055aff366013da/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload"
2024-11-15T21:16:04.685915Z DEBUG request: tower_http::trace::on_response: finished processing request latency=0 ms status=200 method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/83055aff366013da/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload"
2024-11-15T21:16:04.688026Z DEBUG request: tower_http::trace::on_request: started processing request method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files"
2024-11-15T21:16:04.688193Z INFO request: indexify_server::routes::internal_ingest: writing to blob store, file name = "default.__main__.TestGraphUpdate.test_graph_update.update2.83055aff366013da.3023ad50-6c66-4ff5-9c28-ecbb13c54143.0" method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files"
2024-11-15T21:16:04.689774Z DEBUG request: tower_http::trace::on_response: finished processing request latency=1 ms status=200 method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files"
2024-11-15T21:16:04.690202Z INFO task_scheduler::task_creator: compute graph __main__.TestGraphUpdate.test_graph_update invocation finished: false
2024-11-15T21:16:04.690246Z INFO state_store::state_machine: Marking invocation finished: default __main__.TestGraphUpdate.test_graph_update 83055aff366013da
2024-11-15T21:16:04.703373Z DEBUG request: tower_http::trace::on_request: started processing request method="POST" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invoke_object?block_until_finish=true" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invoke_object"
2024-11-15T21:16:04.705086Z DEBUG request: tower_http::trace::on_response: finished processing request latency=1 ms status=200 method="POST" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invoke_object?block_until_finish=true" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invoke_object"
2024-11-15T21:16:04.705904Z INFO task_scheduler: assigning task TaskId("6ce7853f-9bf4-4ac0-9a05-09188855c6b6") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.707369Z DEBUG request: tower_http::trace::on_request: started processing request method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/56d71cdb35ce5f30/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload"
2024-11-15T21:16:04.707569Z DEBUG request: tower_http::trace::on_response: finished processing request latency=0 ms status=200 method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/56d71cdb35ce5f30/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload"
2024-11-15T21:16:04.709552Z DEBUG request: tower_http::trace::on_request: started processing request method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files"
2024-11-15T21:16:04.709704Z INFO request: indexify_server::routes::internal_ingest: writing to blob store, file name = "default.__main__.TestGraphUpdate.test_graph_update.update2.56d71cdb35ce5f30.6ce7853f-9bf4-4ac0-9a05-09188855c6b6.0" method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files"
2024-11-15T21:16:04.711141Z DEBUG request: tower_http::trace::on_response: finished processing request latency=1 ms status=200 method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files"
2024-11-15T21:16:04.711558Z INFO task_scheduler::task_creator: compute graph __main__.TestGraphUpdate.test_graph_update invocation finished: false
2024-11-15T21:16:04.711599Z INFO state_store::state_machine: Marking invocation finished: default __main__.TestGraphUpdate.test_graph_update 56d71cdb35ce5f30
2024-11-15T21:16:04.712150Z DEBUG request: tower_http::trace::on_request: started processing request method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/56d71cdb35ce5f30/outputs" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/outputs"
2024-11-15T21:16:04.712395Z DEBUG request: tower_http::trace::on_response: finished processing request latency=0 ms status=200 method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/56d71cdb35ce5f30/outputs" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/outputs"
2024-11-15T21:16:04.712880Z DEBUG request: tower_http::trace::on_request: started processing request method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/56d71cdb35ce5f30/fn/update2/output/a8b0df3d2569069f" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/fn/:fn_name/output/:id"
2024-11-15T21:16:04.713081Z DEBUG request: tower_http::trace::on_response: finished processing request latency=0 ms status=200 method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/56d71cdb35ce5f30/fn/update2/output/a8b0df3d2569069f" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/fn/:fn_name/output/:id"
2024-11-15T21:16:04.727336Z DEBUG request: tower_http::trace::on_request: started processing request method="POST" uri="/namespaces/default/compute_graphs" matched_path="/namespaces/:namespace/compute_graphs"
2024-11-15T21:16:04.728696Z INFO request: indexify_server::routes: compute graph created: __main__.TestGraphUpdate.test_graph_update method="POST" uri="/namespaces/default/compute_graphs" matched_path="/namespaces/:namespace/compute_graphs"
2024-11-15T21:16:04.728738Z DEBUG request: tower_http::trace::on_response: finished processing request latency=1 ms status=200 method="POST" uri="/namespaces/default/compute_graphs" matched_path="/namespaces/:namespace/compute_graphs"
2024-11-15T21:16:04.729184Z DEBUG request: tower_http::trace::on_request: started processing request method="POST" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/replay" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/replay"
2024-11-15T21:16:04.729653Z DEBUG request: tower_http::trace::on_response: finished processing request latency=0 ms status=200 method="POST" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/replay" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/replay"
2024-11-15T21:16:04.729893Z INFO system_task: indexify_server::system_tasks: queueing invocations queuing=10 task="default|__main__.TestGraphUpdate.test_graph_update" type="replay"
2024-11-15T21:16:04.736832Z INFO task_scheduler: assigning task TaskId("3b78b1f4-0f4a-401f-b329-47642a3215cc") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.737007Z INFO task_scheduler: assigning task TaskId("54449d2d-5323-4fe8-bf91-2812d2f5696b") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.737169Z INFO task_scheduler: assigning task TaskId("9d48963f-a470-4a27-aa3c-c0f6ac9a9696") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.737330Z INFO task_scheduler: assigning task TaskId("4b0ad9e6-924b-492a-b240-bf31c8a76f7e") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.737489Z INFO task_scheduler: assigning task TaskId("4c8d0eff-6b66-41db-bf7b-c2e08f6cef29") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.737648Z INFO task_scheduler: assigning task TaskId("2103d87a-97d3-40a0-b3dc-2072f696ed01") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.737807Z INFO task_scheduler: assigning task TaskId("64612829-9884-495b-9dab-8a93e008ed46") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.737966Z INFO task_scheduler: assigning task TaskId("d289fa65-5d20-4a5a-8ea8-82016bdca52d") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.738127Z INFO task_scheduler: assigning task TaskId("c61ed87c-01aa-4c99-9730-04f465f545f3") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.738287Z INFO task_scheduler: assigning task TaskId("47ff8be7-c927-488c-94f9-cf4e923085ff") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.738962Z INFO task_scheduler: assigning task TaskId("3b78b1f4-0f4a-401f-b329-47642a3215cc") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.739133Z INFO task_scheduler: assigning task TaskId("54449d2d-5323-4fe8-bf91-2812d2f5696b") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.739292Z INFO task_scheduler: assigning task TaskId("9d48963f-a470-4a27-aa3c-c0f6ac9a9696") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.739449Z INFO task_scheduler: assigning task TaskId("4b0ad9e6-924b-492a-b240-bf31c8a76f7e") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.739607Z INFO task_scheduler: assigning task TaskId("4c8d0eff-6b66-41db-bf7b-c2e08f6cef29") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.739765Z INFO task_scheduler: assigning task TaskId("2103d87a-97d3-40a0-b3dc-2072f696ed01") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.739924Z INFO task_scheduler: assigning task TaskId("64612829-9884-495b-9dab-8a93e008ed46") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.740082Z INFO task_scheduler: assigning task TaskId("d289fa65-5d20-4a5a-8ea8-82016bdca52d") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.740240Z INFO task_scheduler: assigning task TaskId("c61ed87c-01aa-4c99-9730-04f465f545f3") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.740391Z INFO task_scheduler: assigning task TaskId("47ff8be7-c927-488c-94f9-cf4e923085ff") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.741069Z INFO task_scheduler: assigning task TaskId("3b78b1f4-0f4a-401f-b329-47642a3215cc") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.741279Z INFO task_scheduler: assigning task TaskId("54449d2d-5323-4fe8-bf91-2812d2f5696b") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.741455Z INFO task_scheduler: assigning task TaskId("9d48963f-a470-4a27-aa3c-c0f6ac9a9696") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.741620Z INFO task_scheduler: assigning task TaskId("4b0ad9e6-924b-492a-b240-bf31c8a76f7e") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.741782Z INFO task_scheduler: assigning task TaskId("4c8d0eff-6b66-41db-bf7b-c2e08f6cef29") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.741944Z INFO task_scheduler: assigning task TaskId("2103d87a-97d3-40a0-b3dc-2072f696ed01") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.742115Z INFO task_scheduler: assigning task TaskId("64612829-9884-495b-9dab-8a93e008ed46") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.742304Z INFO task_scheduler: assigning task TaskId("d289fa65-5d20-4a5a-8ea8-82016bdca52d") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.742464Z INFO task_scheduler: assigning task TaskId("c61ed87c-01aa-4c99-9730-04f465f545f3") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.742622Z INFO task_scheduler: assigning task TaskId("47ff8be7-c927-488c-94f9-cf4e923085ff") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.743318Z INFO task_scheduler: assigning task TaskId("3b78b1f4-0f4a-401f-b329-47642a3215cc") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.743482Z INFO task_scheduler: assigning task TaskId("54449d2d-5323-4fe8-bf91-2812d2f5696b") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.743658Z INFO task_scheduler: assigning task TaskId("9d48963f-a470-4a27-aa3c-c0f6ac9a9696") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.743817Z INFO task_scheduler: assigning task TaskId("4b0ad9e6-924b-492a-b240-bf31c8a76f7e") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.743978Z INFO task_scheduler: assigning task TaskId("4c8d0eff-6b66-41db-bf7b-c2e08f6cef29") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.744139Z INFO task_scheduler: assigning task TaskId("2103d87a-97d3-40a0-b3dc-2072f696ed01") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.744297Z INFO task_scheduler: assigning task TaskId("64612829-9884-495b-9dab-8a93e008ed46") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.744470Z INFO task_scheduler: assigning task TaskId("d289fa65-5d20-4a5a-8ea8-82016bdca52d") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.744635Z INFO task_scheduler: assigning task TaskId("c61ed87c-01aa-4c99-9730-04f465f545f3") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.744812Z INFO task_scheduler: assigning task TaskId("47ff8be7-c927-488c-94f9-cf4e923085ff") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.745564Z INFO task_scheduler: assigning task TaskId("3b78b1f4-0f4a-401f-b329-47642a3215cc") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.745737Z INFO task_scheduler: assigning task TaskId("54449d2d-5323-4fe8-bf91-2812d2f5696b") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.745902Z INFO task_scheduler: assigning task TaskId("9d48963f-a470-4a27-aa3c-c0f6ac9a9696") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.746068Z INFO task_scheduler: assigning task TaskId("4b0ad9e6-924b-492a-b240-bf31c8a76f7e") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.746241Z INFO task_scheduler: assigning task TaskId("4c8d0eff-6b66-41db-bf7b-c2e08f6cef29") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.746422Z INFO task_scheduler: assigning task TaskId("2103d87a-97d3-40a0-b3dc-2072f696ed01") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.746589Z INFO task_scheduler: assigning task TaskId("64612829-9884-495b-9dab-8a93e008ed46") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.746755Z INFO task_scheduler: assigning task TaskId("d289fa65-5d20-4a5a-8ea8-82016bdca52d") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.746907Z INFO task_scheduler: assigning task TaskId("c61ed87c-01aa-4c99-9730-04f465f545f3") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.747072Z INFO task_scheduler: assigning task TaskId("47ff8be7-c927-488c-94f9-cf4e923085ff") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.747772Z INFO task_scheduler: assigning task TaskId("3b78b1f4-0f4a-401f-b329-47642a3215cc") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.747932Z INFO task_scheduler: assigning task TaskId("54449d2d-5323-4fe8-bf91-2812d2f5696b") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.748121Z INFO task_scheduler: assigning task TaskId("9d48963f-a470-4a27-aa3c-c0f6ac9a9696") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.748280Z INFO task_scheduler: assigning task TaskId("4b0ad9e6-924b-492a-b240-bf31c8a76f7e") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.748459Z INFO task_scheduler: assigning task TaskId("4c8d0eff-6b66-41db-bf7b-c2e08f6cef29") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.748618Z INFO task_scheduler: assigning task TaskId("2103d87a-97d3-40a0-b3dc-2072f696ed01") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.748776Z INFO task_scheduler: assigning task TaskId("64612829-9884-495b-9dab-8a93e008ed46") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.748963Z INFO task_scheduler: assigning task TaskId("d289fa65-5d20-4a5a-8ea8-82016bdca52d") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.749131Z INFO task_scheduler: assigning task TaskId("c61ed87c-01aa-4c99-9730-04f465f545f3") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.749301Z INFO task_scheduler: assigning task TaskId("47ff8be7-c927-488c-94f9-cf4e923085ff") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.750014Z INFO task_scheduler: assigning task TaskId("3b78b1f4-0f4a-401f-b329-47642a3215cc") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.750209Z INFO task_scheduler: assigning task TaskId("54449d2d-5323-4fe8-bf91-2812d2f5696b") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.750382Z INFO task_scheduler: assigning task TaskId("9d48963f-a470-4a27-aa3c-c0f6ac9a9696") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.750561Z INFO task_scheduler: assigning task TaskId("4b0ad9e6-924b-492a-b240-bf31c8a76f7e") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.750734Z INFO task_scheduler: assigning task TaskId("4c8d0eff-6b66-41db-bf7b-c2e08f6cef29") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.750902Z INFO task_scheduler: assigning task TaskId("2103d87a-97d3-40a0-b3dc-2072f696ed01") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.751077Z INFO task_scheduler: assigning task TaskId("64612829-9884-495b-9dab-8a93e008ed46") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.751261Z INFO task_scheduler: assigning task TaskId("d289fa65-5d20-4a5a-8ea8-82016bdca52d") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.751419Z INFO task_scheduler: assigning task TaskId("c61ed87c-01aa-4c99-9730-04f465f545f3") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.751589Z INFO task_scheduler: assigning task TaskId("47ff8be7-c927-488c-94f9-cf4e923085ff") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.752300Z INFO task_scheduler: assigning task TaskId("3b78b1f4-0f4a-401f-b329-47642a3215cc") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.752473Z INFO task_scheduler: assigning task TaskId("54449d2d-5323-4fe8-bf91-2812d2f5696b") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.752642Z INFO task_scheduler: assigning task TaskId("9d48963f-a470-4a27-aa3c-c0f6ac9a9696") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.752809Z INFO task_scheduler: assigning task TaskId("4b0ad9e6-924b-492a-b240-bf31c8a76f7e") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.752993Z INFO task_scheduler: assigning task TaskId("4c8d0eff-6b66-41db-bf7b-c2e08f6cef29") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.753162Z INFO task_scheduler: assigning task TaskId("2103d87a-97d3-40a0-b3dc-2072f696ed01") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.753363Z INFO task_scheduler: assigning task TaskId("64612829-9884-495b-9dab-8a93e008ed46") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.753524Z INFO task_scheduler: assigning task TaskId("d289fa65-5d20-4a5a-8ea8-82016bdca52d") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.753692Z INFO task_scheduler: assigning task TaskId("c61ed87c-01aa-4c99-9730-04f465f545f3") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.753852Z INFO task_scheduler: assigning task TaskId("47ff8be7-c927-488c-94f9-cf4e923085ff") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.754548Z INFO task_scheduler: assigning task TaskId("3b78b1f4-0f4a-401f-b329-47642a3215cc") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.754719Z INFO task_scheduler: assigning task TaskId("54449d2d-5323-4fe8-bf91-2812d2f5696b") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.754889Z INFO task_scheduler: assigning task TaskId("9d48963f-a470-4a27-aa3c-c0f6ac9a9696") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.755060Z INFO task_scheduler: assigning task TaskId("4b0ad9e6-924b-492a-b240-bf31c8a76f7e") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.755228Z INFO task_scheduler: assigning task TaskId("4c8d0eff-6b66-41db-bf7b-c2e08f6cef29") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.755397Z INFO task_scheduler: assigning task TaskId("2103d87a-97d3-40a0-b3dc-2072f696ed01") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.755571Z INFO task_scheduler: assigning task TaskId("64612829-9884-495b-9dab-8a93e008ed46") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.755738Z INFO task_scheduler: assigning task TaskId("d289fa65-5d20-4a5a-8ea8-82016bdca52d") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.755906Z INFO task_scheduler: assigning task TaskId("c61ed87c-01aa-4c99-9730-04f465f545f3") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.756094Z INFO task_scheduler: assigning task TaskId("47ff8be7-c927-488c-94f9-cf4e923085ff") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.756797Z INFO task_scheduler: assigning task TaskId("3b78b1f4-0f4a-401f-b329-47642a3215cc") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.756966Z INFO task_scheduler: assigning task TaskId("54449d2d-5323-4fe8-bf91-2812d2f5696b") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.757135Z INFO task_scheduler: assigning task TaskId("9d48963f-a470-4a27-aa3c-c0f6ac9a9696") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.757303Z INFO task_scheduler: assigning task TaskId("4b0ad9e6-924b-492a-b240-bf31c8a76f7e") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.757474Z INFO task_scheduler: assigning task TaskId("4c8d0eff-6b66-41db-bf7b-c2e08f6cef29") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.757662Z INFO task_scheduler: assigning task TaskId("2103d87a-97d3-40a0-b3dc-2072f696ed01") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.757827Z INFO task_scheduler: assigning task TaskId("64612829-9884-495b-9dab-8a93e008ed46") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.757993Z INFO task_scheduler: assigning task TaskId("d289fa65-5d20-4a5a-8ea8-82016bdca52d") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.758155Z INFO task_scheduler: assigning task TaskId("c61ed87c-01aa-4c99-9730-04f465f545f3") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.758324Z INFO task_scheduler: assigning task TaskId("47ff8be7-c927-488c-94f9-cf4e923085ff") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.762507Z DEBUG request: tower_http::trace::on_request: started processing request method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph"
2024-11-15T21:16:04.762647Z DEBUG request: tower_http::trace::on_response: finished processing request latency=0 ms status=200 method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph"
2024-11-15T21:16:04.765144Z DEBUG request: tower_http::trace::on_request: started processing request method="GET" uri="/internal/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/code" matched_path="/internal/namespaces/:namespace/compute_graphs/:compute_graph/code"
2024-11-15T21:16:04.765408Z DEBUG request: tower_http::trace::on_response: finished processing request latency=0 ms status=200 method="GET" uri="/internal/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/code" matched_path="/internal/namespaces/:namespace/compute_graphs/:compute_graph/code"
2024-11-15T21:16:04.766516Z DEBUG request: tower_http::trace::on_request: started processing request method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/83055aff366013da/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload"
2024-11-15T21:16:04.766709Z DEBUG request: tower_http::trace::on_response: finished processing request latency=0 ms status=200 method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/83055aff366013da/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload"
2024-11-15T21:16:04.767387Z DEBUG request: tower_http::trace::on_request: started processing request method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/205684db422504d4/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload"
2024-11-15T21:16:04.767542Z DEBUG request: tower_http::trace::on_response: finished processing request latency=0 ms status=200 method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/205684db422504d4/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload"
2024-11-15T21:16:04.768173Z DEBUG request: tower_http::trace::on_request: started processing request method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/56d71cdb35ce5f30/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload"
2024-11-15T21:16:04.768315Z DEBUG request: tower_http::trace::on_response: finished processing request latency=0 ms status=200 method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/56d71cdb35ce5f30/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload"
2024-11-15T21:16:04.768947Z DEBUG request: tower_http::trace::on_request: started processing request method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/7b8346f2537b2f74/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload"
2024-11-15T21:16:04.769070Z DEBUG request: tower_http::trace::on_response: finished processing request latency=0 ms status=200 method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/7b8346f2537b2f74/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload"
2024-11-15T21:16:04.769655Z DEBUG request: tower_http::trace::on_request: started processing request method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/1a1a202bcb77ca40/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload"
2024-11-15T21:16:04.769783Z DEBUG request: tower_http::trace::on_response: finished processing request latency=0 ms status=200 method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/1a1a202bcb77ca40/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload"
2024-11-15T21:16:04.770536Z DEBUG request: tower_http::trace::on_request: started processing request method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/31931e6c0c28803b/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload"
2024-11-15T21:16:04.770678Z DEBUG request: tower_http::trace::on_response: finished processing request latency=0 ms status=200 method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/31931e6c0c28803b/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload"
2024-11-15T21:16:04.771270Z DEBUG request: tower_http::trace::on_request: started processing request method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/f33202d46cf93963/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload"
2024-11-15T21:16:04.771386Z DEBUG request: tower_http::trace::on_response: finished processing request latency=0 ms status=200 method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/f33202d46cf93963/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload"
2024-11-15T21:16:04.771956Z DEBUG request: tower_http::trace::on_request: started processing request method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/b7fabce39e8a8e9a/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload"
2024-11-15T21:16:04.772074Z DEBUG request: tower_http::trace::on_response: finished processing request latency=0 ms status=200 method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/b7fabce39e8a8e9a/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload"
2024-11-15T21:16:04.772646Z DEBUG request: tower_http::trace::on_request: started processing request method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/6144e7fa455f8a48/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload"
2024-11-15T21:16:04.772756Z DEBUG request: tower_http::trace::on_response: finished processing request latency=0 ms status=200 method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/6144e7fa455f8a48/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload"
2024-11-15T21:16:04.773366Z DEBUG request: tower_http::trace::on_request: started processing request method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/1adaad644b88fddf/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload"
2024-11-15T21:16:04.773484Z DEBUG request: tower_http::trace::on_response: finished processing request latency=0 ms status=200 method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/1adaad644b88fddf/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload"
2024-11-15T21:16:04.780541Z DEBUG request: tower_http::trace::on_request: started processing request method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files"
2024-11-15T21:16:04.780647Z INFO request: indexify_server::routes::internal_ingest: writing to blob store, file name = "default.__main__.TestGraphUpdate.test_graph_update.update.f33202d46cf93963.47ff8be7-c927-488c-94f9-cf4e923085ff.0" method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files"
2024-11-15T21:16:04.782319Z DEBUG request: tower_http::trace::on_response: finished processing request latency=1 ms status=200 method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files"
2024-11-15T21:16:04.783568Z DEBUG request: tower_http::trace::on_request: started processing request method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files"
2024-11-15T21:16:04.783593Z INFO task_scheduler::task_creator: compute graph __main__.TestGraphUpdate.test_graph_update invocation finished: false
2024-11-15T21:16:04.783643Z INFO state_store::state_machine: Marking invocation finished: default __main__.TestGraphUpdate.test_graph_update f33202d46cf93963
2024-11-15T21:16:04.783702Z INFO request: indexify_server::routes::internal_ingest: writing to blob store, file name = "default.__main__.TestGraphUpdate.test_graph_update.update.7b8346f2537b2f74.64612829-9884-495b-9dab-8a93e008ed46.0" method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files"
2024-11-15T21:16:04.783914Z ERROR state_store: failed to send invocation state change: SendError(InvocationFinished(InvocationFinishedEvent { id: "f33202d46cf93963" }))
2024-11-15T21:16:04.784156Z INFO system_task: indexify_server::system_tasks: queueing invocations queuing=1 task="default|__main__.TestGraphUpdate.test_graph_update" type="replay"
2024-11-15T21:16:04.785070Z INFO system_task: indexify_server::system_tasks: waiting for all invotations to finish before completing the task running_invocations=10 task="default|__main__.TestGraphUpdate.test_graph_update" type="replay"
2024-11-15T21:16:04.785328Z DEBUG request: tower_http::trace::on_response: finished processing request latency=1 ms status=200 method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files"
2024-11-15T21:16:04.786418Z DEBUG request: tower_http::trace::on_request: started processing request method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files"
2024-11-15T21:16:04.786550Z INFO request: indexify_server::routes::internal_ingest: writing to blob store, file name = "default.__main__.TestGraphUpdate.test_graph_update.update.1adaad644b88fddf.54449d2d-5323-4fe8-bf91-2812d2f5696b.0" method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files"
2024-11-15T21:16:04.786765Z INFO task_scheduler::task_creator: compute graph __main__.TestGraphUpdate.test_graph_update invocation finished: false
2024-11-15T21:16:04.787115Z INFO task_scheduler: assigning task TaskId("e87bfb36-75c7-4a14-af73-9c0120cad470") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR")
2024-11-15T21:16:04.787163Z INFO state_store::state_machine: Marking invocation finished: default __main__.TestGraphUpdate.test_graph_update 7b8346f2537b2f74
2024-11-15T21:16:04.787376Z ERROR state_store: failed to send invocation state change: SendError(InvocationFinished(InvocationFinishedEvent { id: "7b8346f2537b2f74" }))
2024-11-15T21:16:04.787615Z INFO system_task: indexify_server::system_tasks: waiting for all invotations to finish before completing the task running_invocations=9 task="default|__main__.TestGraphUpdate.test_graph_update" type="replay"
2024-11-15T21:16:04.788198Z DEBUG request: tower_http::trace::on_response: finished processing request latency=1 ms status=200 method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files"
2024-11-15T21:16:04.789094Z INFO task_scheduler::task_creator: compute graph __main__.TestGraphUpdate.test_graph_update invocation finished: false
2024-11-15T21:16:04.789144Z INFO state_store::state_machine: Marking invocation finished: default __main__.TestGraphUpdate.test_graph_update 1adaad644b88fddf
2024-11-15T21:16:04.789315Z DEBUG request: tower_http::trace::on_request: started processing request method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files"
2024-11-15T21:16:04.789366Z ERROR state_store: failed to send invocation state change: SendError(InvocationFinished(InvocationFinishedEvent { id: "1adaad644b88fddf" }))
2024-11-15T21:16:04.789417Z INFO request: indexify_server::routes::internal_ingest: writing to blob store, file name = "default.__main__.TestGraphUpdate.test_graph_update.update.6144e7fa455f8a48.2103d87a-97d3-40a0-b3dc-2072f696ed01.0" method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files"
2024-11-15T21:16:04.789531Z INFO system_task: indexify_server::system_tasks: waiting for all invotations to finish before completing the task running_invocations=8 task="default|__main__.TestGraphUpdate.test_graph_update" type="replay"
2024-11-15T21:16:04.790951Z DEBUG request: tower_http::trace::on_response: finished processing request latency=1 ms status=200 method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files"
2024-11-15T21:16:04.791790Z INFO task_scheduler::task_creator: compute graph __main__.TestGraphUpdate.test_graph_update invocation finished: false
2024-11-15T21:16:04.791830Z INFO state_store::state_machine: Marking invocation finished: default __main__.TestGraphUpdate.test_graph_update 6144e7fa455f8a48
2024-11-15T21:16:04.792045Z DEBUG request: tower_http::trace::on_request: started processing request method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files"
2024-11-15T21:16:04.792115Z ERROR state_store: failed to send invocation state change: SendError(InvocationFinished(InvocationFinishedEvent { id: "6144e7fa455f8a48" }))
2024-11-15T21:16:04.792133Z INFO request: indexify_server::routes::internal_ingest: writing to blob store, file name = "default.__main__.TestGraphUpdate.test_graph_update.update.31931e6c0c28803b.4b0ad9e6-924b-492a-b240-bf31c8a76f7e.0" method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files"
2024-11-15T21:16:04.792272Z INFO system_task: indexify_server::system_tasks: waiting for all invotations to finish before completing the task running_invocations=7 task="default|__main__.TestGraphUpdate.test_graph_update" type="replay"
2024-11-15T21:16:04.793449Z DEBUG request: tower_http::trace::on_response: finished processing request latency=1 ms status=200 method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files"
2024-11-15T21:16:04.794408Z INFO task_scheduler::task_creator: compute graph __main__.TestGraphUpdate.test_graph_update invocation finished: false
2024-11-15T21:16:04.794450Z INFO state_store::state_machine: Marking invocation finished: default __main__.TestGraphUpdate.test_graph_update 31931e6c0c28803b
2024-11-15T21:16:04.794452Z DEBUG request: tower_http::trace::on_request: started processing request method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files"
2024-11-15T21:16:04.794570Z INFO request: indexify_server::routes::internal_ingest: writing to blob store, file name = "default.__main__.TestGraphUpdate.test_graph_update.update.83055aff366013da.d289fa65-5d20-4a5a-8ea8-82016bdca52d.0" method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files"
2024-11-15T21:16:04.794584Z ERROR state_store: failed to send invocation state change: SendError(InvocationFinished(InvocationFinishedEvent { id: "31931e6c0c28803b" }))
2024-11-15T21:16:04.794738Z INFO system_task: indexify_server::system_tasks: waiting for all invotations to finish before completing the task running_invocations=6 task="default|__main__.TestGraphUpdate.test_graph_update" type="replay"
2024-11-15T21:16:04.795903Z DEBUG request: tower_http::trace::on_response: finished processing request latency=1 ms status=200 method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files"
2024-11-15T21:16:04.796830Z INFO task_scheduler::task_creator: compute graph __main__.TestGraphUpdate.test_graph_update invocation finished: false
2024-11-15T21:16:04.796839Z DEBUG request: tower_http::trace::on_request: started processing request method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files"
2024-11-15T21:16:04.796896Z INFO state_store::state_machine: Marking invocation finished: default __main__.TestGraphUpdate.test_graph_update 83055aff366013da
2024-11-15T21:16:04.796955Z INFO request: indexify_server::routes::internal_ingest: writing to blob store, file name = "default.__main__.TestGraphUpdate.test_graph_update.update.b7fabce39e8a8e9a.c61ed87c-01aa-4c99-9730-04f465f545f3.0" method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files"
2024-11-15T21:16:04.797026Z ERROR state_store: failed to send invocation state change: SendError(InvocationFinished(InvocationFinishedEvent { id: "83055aff366013da" }))
2024-11-15T21:16:04.797193Z INFO system_task: indexify_server::system_tasks: waiting for all invotations to finish before completing the task running_invocations=5 task="default|__main__.TestGraphUpdate.test_graph_update" type="replay"
2024-11-15T21:16:04.798389Z DEBUG request: tower_http::trace::on_response: finished processing request latency=1 ms status=200 method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files"
2024-11-15T21:16:04.799168Z INFO task_scheduler::task_creator: compute graph __main__.TestGraphUpdate.test_graph_update invocation finished: false
2024-11-15T21:16:04.799219Z INFO state_store::state_machine: Marking invocation finished: default __main__.TestGraphUpdate.test_graph_update b7fabce39e8a8e9a
2024-11-15T21:16:04.799379Z ERROR state_store: failed to send invocation state change: SendError(InvocationFinished(InvocationFinishedEvent { id: "b7fabce39e8a8e9a" }))
2024-11-15T21:16:04.799487Z DEBUG request: tower_http::trace::on_request: started processing request method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files"
2024-11-15T21:16:04.799565Z INFO system_task: indexify_server::system_tasks: waiting for all invotations to finish before completing the task running_invocations=4 task="default|__main__.TestGraphUpdate.test_graph_update" type="replay"
2024-11-15T21:16:04.799637Z INFO request: indexify_server::routes::internal_ingest: writing to blob store, file name = "default.__main__.TestGraphUpdate.test_graph_update.update.205684db422504d4.9d48963f-a470-4a27-aa3c-c0f6ac9a9696.0" method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files"
2024-11-15T21:16:04.800961Z DEBUG request: tower_http::trace::on_response: finished processing request latency=1 ms status=200 method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files"
2024-11-15T21:16:04.801612Z INFO task_scheduler::task_creator: compute graph __main__.TestGraphUpdate.test_graph_update invocation finished: false
2024-11-15T21:16:04.801661Z INFO state_store::state_machine: Marking invocation finished: default __main__.TestGraphUpdate.test_graph_update 205684db422504d4
2024-11-15T21:16:04.801793Z ERROR state_store: failed to send invocation state change: SendError(InvocationFinished(InvocationFinishedEvent { id: "205684db422504d4" }))
2024-11-15T21:16:04.801887Z DEBUG request: tower_http::trace::on_request: started processing request method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files"
2024-11-15T21:16:04.801954Z INFO system_task: indexify_server::system_tasks: waiting for all invotations to finish before completing the task running_invocations=3 task="default|__main__.TestGraphUpdate.test_graph_update" type="replay"
2024-11-15T21:16:04.802012Z INFO request: indexify_server::routes::internal_ingest: writing to blob store, file name = "default.__main__.TestGraphUpdate.test_graph_update.update.1a1a202bcb77ca40.3b78b1f4-0f4a-401f-b329-47642a3215cc.0" method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files"
2024-11-15T21:16:04.803306Z DEBUG request: tower_http::trace::on_response: finished processing request latency=1 ms status=200 method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files"
2024-11-15T21:16:04.803858Z INFO task_scheduler::task_creator: compute graph __main__.TestGraphUpdate.test_graph_update invocation finished: false
2024-11-15T21:16:04.803892Z INFO state_store::state_machine: Marking invocation finished: default __main__.TestGraphUpdate.test_graph_update 1a1a202bcb77ca40
2024-11-15T21:16:04.804020Z ERROR state_store: failed to send invocation state change: SendError(InvocationFinished(InvocationFinishedEvent { id: "1a1a202bcb77ca40" }))
2024-11-15T21:16:04.804157Z INFO system_task: indexify_server::system_tasks: waiting for all invotations to finish before completing the task running_invocations=2 task="default|__main__.TestGraphUpdate.test_graph_update" type="replay"
2024-11-15T21:16:04.804338Z DEBUG request: tower_http::trace::on_request: started processing request method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files"
2024-11-15T21:16:04.804442Z INFO request: indexify_server::routes::internal_ingest: writing to blob store, file name = "default.__main__.TestGraphUpdate.test_graph_update.update.56d71cdb35ce5f30.4c8d0eff-6b66-41db-bf7b-c2e08f6cef29.0" method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files"
2024-11-15T21:16:04.805740Z DEBUG request: tower_http::trace::on_response: finished processing request latency=1 ms status=200 method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files"
2024-11-15T21:16:04.806225Z INFO task_scheduler::task_creator: compute graph __main__.TestGraphUpdate.test_graph_update invocation finished: false
2024-11-15T21:16:04.806269Z INFO state_store::state_machine: Marking invocation finished: default __main__.TestGraphUpdate.test_graph_update 56d71cdb35ce5f30
2024-11-15T21:16:04.806407Z ERROR state_store: failed to send invocation state change: SendError(InvocationFinished(InvocationFinishedEvent { id: "56d71cdb35ce5f30" }))
2024-11-15T21:16:04.806589Z INFO system_task: indexify_server::system_tasks: waiting for all invotations to finish before completing the task running_invocations=1 task="default|__main__.TestGraphUpdate.test_graph_update" type="replay"
2024-11-15T21:16:04.807195Z DEBUG request: tower_http::trace::on_request: started processing request method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/f9c203d1cc58c0e9/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload"
2024-11-15T21:16:04.807395Z DEBUG request: tower_http::trace::on_response: finished processing request latency=0 ms status=200 method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/f9c203d1cc58c0e9/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload"
2024-11-15T21:16:04.809126Z DEBUG request: tower_http::trace::on_request: started processing request method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files"
2024-11-15T21:16:04.809277Z INFO request: indexify_server::routes::internal_ingest: writing to blob store, file name = "default.__main__.TestGraphUpdate.test_graph_update.update.f9c203d1cc58c0e9.e87bfb36-75c7-4a14-af73-9c0120cad470.0" method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files"
2024-11-15T21:16:04.810691Z DEBUG request: tower_http::trace::on_response: finished processing request latency=1 ms status=200 method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files"
2024-11-15T21:16:04.811090Z INFO task_scheduler::task_creator: compute graph __main__.TestGraphUpdate.test_graph_update invocation finished: false
2024-11-15T21:16:04.811128Z INFO state_store::state_machine: Marking invocation finished: default __main__.TestGraphUpdate.test_graph_update f9c203d1cc58c0e9
2024-11-15T21:16:04.811261Z ERROR state_store: failed to send invocation state change: SendError(InvocationFinished(InvocationFinishedEvent { id: "f9c203d1cc58c0e9" }))
2024-11-15T21:16:04.811405Z INFO system_task: indexify_server::system_tasks: completed task="default|__main__.TestGraphUpdate.test_graph_update" type="replay"
2024-11-15T21:16:04.811603Z INFO indexify_server::system_tasks: no system tasks to process
2024-11-15T21:16:06.769853Z DEBUG request: tower_http::trace::on_request: started processing request method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph"
2024-11-15T21:16:06.770721Z DEBUG request: tower_http::trace::on_response: finished processing request latency=0 ms status=200 method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph"
2024-11-15T21:16:06.772963Z DEBUG request: tower_http::trace::on_request: started processing request method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/56d71cdb35ce5f30/outputs" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/outputs"
2024-11-15T21:16:06.774148Z DEBUG request: tower_http::trace::on_response: finished processing request latency=1 ms status=200 method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/56d71cdb35ce5f30/outputs" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/outputs"
2024-11-15T21:16:06.776137Z DEBUG request: tower_http::trace::on_request: started processing request method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/56d71cdb35ce5f30/fn/update/output/d388509bb723640d" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/fn/:fn_name/output/:id"
2024-11-15T21:16:06.777187Z DEBUG request: tower_http::trace::on_response: finished processing request latency=1 ms status=200 method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/56d71cdb35ce5f30/fn/update/output/d388509bb723640d" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/fn/:fn_name/output/:id"
```
Contribution Checklist
[x] If the python-sdk was changed, please run make fmt in python-sdk/.
[x] If the server was changed, please run make fmt in server/.
Context
Fixes #1028
There is currently no way to know whether a graph is currently replaying all invocations which prevents using some use cases like fetching the output of a replaying invocation.
What
This PR makes it possible to do:
In order to do so, some system task refactoring was needed. Here is what changed:
Note: You can see an alternative approach to solve this problem in https://github.com/tensorlakeai/indexify/pull/999. But it was decided to simplify system tasks which was done as part of this PR.
Testing
The test
tests/test_graph_update.pywas leveraged to test this feature.Details
``` 2024-11-15T21:15:58.392766Z INFO indexify_server::service: starting scheduler 2024-11-15T21:15:58.392768Z INFO indexify_server::service: starting system tasks executor 2024-11-15T21:15:58.392767Z INFO indexify_server::service: starting garbage collector 2024-11-15T21:15:58.393296Z INFO indexify_server::service: created default namespace 2024-11-15T21:15:58.393309Z INFO indexify_server::service: server api listening on 0.0.0.0:8900 2024-11-15T21:15:58.393338Z INFO indexify_server::system_tasks: no system tasks to process 2024-11-15T21:16:01.996349Z DEBUG request: tower_http::trace::on_request: started processing request method="POST" uri="/internal/executors/N--EqyG4Eaw86QAp3MpOR/tasks" matched_path="/internal/executors/:id/tasks" 2024-11-15T21:16:01.996915Z DEBUG request: tower_http::trace::on_response: finished processing request latency=0 ms status=200 method="POST" uri="/internal/executors/N--EqyG4Eaw86QAp3MpOR/tasks" matched_path="/internal/executors/:id/tasks" 2024-11-15T21:16:03.402596Z DEBUG request: tower_http::trace::on_request: started processing request method="POST" uri="/namespaces/default/compute_graphs" matched_path="/namespaces/:namespace/compute_graphs" 2024-11-15T21:16:03.404146Z INFO request: indexify_server::routes: compute graph created: __main__.TestGraphUpdate.test_graph_update method="POST" uri="/namespaces/default/compute_graphs" matched_path="/namespaces/:namespace/compute_graphs" 2024-11-15T21:16:03.404180Z DEBUG request: tower_http::trace::on_response: finished processing request latency=1 ms status=200 method="POST" uri="/namespaces/default/compute_graphs" matched_path="/namespaces/:namespace/compute_graphs" 2024-11-15T21:16:03.418112Z DEBUG request: tower_http::trace::on_request: started processing request method="POST" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invoke_object?block_until_finish=true" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invoke_object" 2024-11-15T21:16:03.420137Z DEBUG request: tower_http::trace::on_response: finished processing request latency=2 ms status=200 method="POST" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invoke_object?block_until_finish=true" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invoke_object" 2024-11-15T21:16:03.421102Z INFO task_scheduler: assigning task TaskId("115d2d97-6ed4-4ca4-b984-bb0bc5839f8a") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:03.423827Z DEBUG request: tower_http::trace::on_request: started processing request method="GET" uri="/internal/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/code" matched_path="/internal/namespaces/:namespace/compute_graphs/:compute_graph/code" 2024-11-15T21:16:03.424061Z DEBUG request: tower_http::trace::on_response: finished processing request latency=0 ms status=200 method="GET" uri="/internal/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/code" matched_path="/internal/namespaces/:namespace/compute_graphs/:compute_graph/code" 2024-11-15T21:16:03.425327Z DEBUG request: tower_http::trace::on_request: started processing request method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/1adaad644b88fddf/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload" 2024-11-15T21:16:03.425491Z DEBUG request: tower_http::trace::on_response: finished processing request latency=0 ms status=200 method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/1adaad644b88fddf/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload" 2024-11-15T21:16:03.430567Z DEBUG request: tower_http::trace::on_request: started processing request method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files" 2024-11-15T21:16:03.430728Z INFO request: indexify_server::routes::internal_ingest: writing to blob store, file name = "default.__main__.TestGraphUpdate.test_graph_update.update.1adaad644b88fddf.115d2d97-6ed4-4ca4-b984-bb0bc5839f8a.0" method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files" 2024-11-15T21:16:03.432299Z DEBUG request: tower_http::trace::on_response: finished processing request latency=1 ms status=200 method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files" 2024-11-15T21:16:03.432779Z INFO task_scheduler::task_creator: compute graph __main__.TestGraphUpdate.test_graph_update invocation finished: false 2024-11-15T21:16:03.432824Z INFO state_store::state_machine: Marking invocation finished: default __main__.TestGraphUpdate.test_graph_update 1adaad644b88fddf 2024-11-15T21:16:03.433478Z DEBUG request: tower_http::trace::on_request: started processing request method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/1adaad644b88fddf/outputs" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/outputs" 2024-11-15T21:16:03.433727Z DEBUG request: tower_http::trace::on_response: finished processing request latency=0 ms status=200 method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/1adaad644b88fddf/outputs" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/outputs" 2024-11-15T21:16:03.434204Z DEBUG request: tower_http::trace::on_request: started processing request method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/1adaad644b88fddf/fn/update/output/948ba598e53ed761" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/fn/:fn_name/output/:id" 2024-11-15T21:16:03.434391Z DEBUG request: tower_http::trace::on_response: finished processing request latency=0 ms status=200 method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/1adaad644b88fddf/fn/update/output/948ba598e53ed761" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/fn/:fn_name/output/:id" 2024-11-15T21:16:03.448696Z DEBUG request: tower_http::trace::on_request: started processing request method="POST" uri="/namespaces/default/compute_graphs" matched_path="/namespaces/:namespace/compute_graphs" 2024-11-15T21:16:03.450318Z INFO request: indexify_server::routes: compute graph created: __main__.TestGraphUpdate.test_graph_update method="POST" uri="/namespaces/default/compute_graphs" matched_path="/namespaces/:namespace/compute_graphs" 2024-11-15T21:16:03.450383Z DEBUG request: tower_http::trace::on_response: finished processing request latency=1 ms status=200 method="POST" uri="/namespaces/default/compute_graphs" matched_path="/namespaces/:namespace/compute_graphs" 2024-11-15T21:16:03.451045Z DEBUG request: tower_http::trace::on_request: started processing request method="POST" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/replay" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/replay" 2024-11-15T21:16:03.451665Z DEBUG request: tower_http::trace::on_response: finished processing request latency=0 ms status=200 method="POST" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/replay" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/replay" 2024-11-15T21:16:03.451862Z INFO system_task: indexify_server::system_tasks: queueing invocations queuing=1 task="default|__main__.TestGraphUpdate.test_graph_update" type="replay" 2024-11-15T21:16:03.452459Z INFO system_task: indexify_server::system_tasks: waiting for all invotations to finish before completing the task running_invocations=1 task="default|__main__.TestGraphUpdate.test_graph_update" type="replay" 2024-11-15T21:16:03.453357Z INFO task_scheduler: assigning task TaskId("bb6ad8fd-2f64-492f-a5f8-0f79274d0100") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:03.453761Z DEBUG request: tower_http::trace::on_request: started processing request method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph" 2024-11-15T21:16:03.453891Z DEBUG request: tower_http::trace::on_response: finished processing request latency=0 ms status=200 method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph" 2024-11-15T21:16:03.454960Z DEBUG request: tower_http::trace::on_request: started processing request method="GET" uri="/internal/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/code" matched_path="/internal/namespaces/:namespace/compute_graphs/:compute_graph/code" 2024-11-15T21:16:03.455197Z DEBUG request: tower_http::trace::on_response: finished processing request latency=0 ms status=200 method="GET" uri="/internal/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/code" matched_path="/internal/namespaces/:namespace/compute_graphs/:compute_graph/code" 2024-11-15T21:16:03.456212Z DEBUG request: tower_http::trace::on_request: started processing request method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/1adaad644b88fddf/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload" 2024-11-15T21:16:03.456374Z DEBUG request: tower_http::trace::on_response: finished processing request latency=0 ms status=200 method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/1adaad644b88fddf/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload" 2024-11-15T21:16:03.458808Z DEBUG request: tower_http::trace::on_request: started processing request method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files" 2024-11-15T21:16:03.459008Z INFO request: indexify_server::routes::internal_ingest: writing to blob store, file name = "default.__main__.TestGraphUpdate.test_graph_update.update2.1adaad644b88fddf.bb6ad8fd-2f64-492f-a5f8-0f79274d0100.0" method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files" 2024-11-15T21:16:03.460483Z DEBUG request: tower_http::trace::on_response: finished processing request latency=1 ms status=200 method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files" 2024-11-15T21:16:03.460890Z INFO task_scheduler::task_creator: compute graph __main__.TestGraphUpdate.test_graph_update invocation finished: false 2024-11-15T21:16:03.460931Z INFO state_store::state_machine: Marking invocation finished: default __main__.TestGraphUpdate.test_graph_update 1adaad644b88fddf 2024-11-15T21:16:03.461075Z ERROR state_store: failed to send invocation state change: SendError(InvocationFinished(InvocationFinishedEvent { id: "1adaad644b88fddf" })) 2024-11-15T21:16:03.461227Z INFO system_task: indexify_server::system_tasks: completed task="default|__main__.TestGraphUpdate.test_graph_update" type="replay" 2024-11-15T21:16:03.461428Z INFO indexify_server::system_tasks: no system tasks to process 2024-11-15T21:16:04.462233Z DEBUG request: tower_http::trace::on_request: started processing request method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph" 2024-11-15T21:16:04.463549Z DEBUG request: tower_http::trace::on_response: finished processing request latency=1 ms status=200 method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph" 2024-11-15T21:16:04.466759Z DEBUG request: tower_http::trace::on_request: started processing request method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/1adaad644b88fddf/outputs" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/outputs" 2024-11-15T21:16:04.468028Z DEBUG request: tower_http::trace::on_response: finished processing request latency=1 ms status=200 method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/1adaad644b88fddf/outputs" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/outputs" 2024-11-15T21:16:04.478023Z DEBUG request: tower_http::trace::on_request: started processing request method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/1adaad644b88fddf/fn/update2/output/c809135cac89ad7f" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/fn/:fn_name/output/:id" 2024-11-15T21:16:04.478714Z DEBUG request: tower_http::trace::on_response: finished processing request latency=0 ms status=200 method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/1adaad644b88fddf/fn/update2/output/c809135cac89ad7f" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/fn/:fn_name/output/:id" 2024-11-15T21:16:04.501679Z DEBUG request: tower_http::trace::on_request: started processing request method="POST" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invoke_object?block_until_finish=true" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invoke_object" 2024-11-15T21:16:04.504179Z DEBUG request: tower_http::trace::on_response: finished processing request latency=2 ms status=200 method="POST" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invoke_object?block_until_finish=true" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invoke_object" 2024-11-15T21:16:04.505411Z INFO task_scheduler: assigning task TaskId("1971913c-ce96-47fd-b89b-ca52fee82d61") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.507361Z DEBUG request: tower_http::trace::on_request: started processing request method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/b7fabce39e8a8e9a/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload" 2024-11-15T21:16:04.507594Z DEBUG request: tower_http::trace::on_response: finished processing request latency=0 ms status=200 method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/b7fabce39e8a8e9a/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload" 2024-11-15T21:16:04.510057Z DEBUG request: tower_http::trace::on_request: started processing request method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files" 2024-11-15T21:16:04.510248Z INFO request: indexify_server::routes::internal_ingest: writing to blob store, file name = "default.__main__.TestGraphUpdate.test_graph_update.update2.b7fabce39e8a8e9a.1971913c-ce96-47fd-b89b-ca52fee82d61.0" method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files" 2024-11-15T21:16:04.512112Z DEBUG request: tower_http::trace::on_response: finished processing request latency=2 ms status=200 method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files" 2024-11-15T21:16:04.512739Z INFO task_scheduler::task_creator: compute graph __main__.TestGraphUpdate.test_graph_update invocation finished: false 2024-11-15T21:16:04.512830Z INFO state_store::state_machine: Marking invocation finished: default __main__.TestGraphUpdate.test_graph_update b7fabce39e8a8e9a 2024-11-15T21:16:04.529248Z DEBUG request: tower_http::trace::on_request: started processing request method="POST" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invoke_object?block_until_finish=true" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invoke_object" 2024-11-15T21:16:04.531498Z DEBUG request: tower_http::trace::on_response: finished processing request latency=2 ms status=200 method="POST" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invoke_object?block_until_finish=true" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invoke_object" 2024-11-15T21:16:04.532585Z INFO task_scheduler: assigning task TaskId("d014a246-4fb2-45a4-a575-21bfee407e0e") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.534381Z DEBUG request: tower_http::trace::on_request: started processing request method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/1a1a202bcb77ca40/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload" 2024-11-15T21:16:04.534620Z DEBUG request: tower_http::trace::on_response: finished processing request latency=0 ms status=200 method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/1a1a202bcb77ca40/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload" 2024-11-15T21:16:04.536699Z DEBUG request: tower_http::trace::on_request: started processing request method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files" 2024-11-15T21:16:04.536869Z INFO request: indexify_server::routes::internal_ingest: writing to blob store, file name = "default.__main__.TestGraphUpdate.test_graph_update.update2.1a1a202bcb77ca40.d014a246-4fb2-45a4-a575-21bfee407e0e.0" method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files" 2024-11-15T21:16:04.538543Z DEBUG request: tower_http::trace::on_response: finished processing request latency=1 ms status=200 method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files" 2024-11-15T21:16:04.538994Z INFO task_scheduler::task_creator: compute graph __main__.TestGraphUpdate.test_graph_update invocation finished: false 2024-11-15T21:16:04.539042Z INFO state_store::state_machine: Marking invocation finished: default __main__.TestGraphUpdate.test_graph_update 1a1a202bcb77ca40 2024-11-15T21:16:04.552994Z DEBUG request: tower_http::trace::on_request: started processing request method="POST" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invoke_object?block_until_finish=true" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invoke_object" 2024-11-15T21:16:04.554911Z DEBUG request: tower_http::trace::on_response: finished processing request latency=1 ms status=200 method="POST" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invoke_object?block_until_finish=true" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invoke_object" 2024-11-15T21:16:04.555821Z INFO task_scheduler: assigning task TaskId("a1d6b518-5792-4aa2-b1fb-5e18403b93e0") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.557317Z DEBUG request: tower_http::trace::on_request: started processing request method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/205684db422504d4/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload" 2024-11-15T21:16:04.557540Z DEBUG request: tower_http::trace::on_response: finished processing request latency=0 ms status=200 method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/205684db422504d4/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload" 2024-11-15T21:16:04.559394Z DEBUG request: tower_http::trace::on_request: started processing request method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files" 2024-11-15T21:16:04.559527Z INFO request: indexify_server::routes::internal_ingest: writing to blob store, file name = "default.__main__.TestGraphUpdate.test_graph_update.update2.205684db422504d4.a1d6b518-5792-4aa2-b1fb-5e18403b93e0.0" method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files" 2024-11-15T21:16:04.560924Z DEBUG request: tower_http::trace::on_response: finished processing request latency=1 ms status=200 method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files" 2024-11-15T21:16:04.561314Z INFO task_scheduler::task_creator: compute graph __main__.TestGraphUpdate.test_graph_update invocation finished: false 2024-11-15T21:16:04.561355Z INFO state_store::state_machine: Marking invocation finished: default __main__.TestGraphUpdate.test_graph_update 205684db422504d4 2024-11-15T21:16:04.574587Z DEBUG request: tower_http::trace::on_request: started processing request method="POST" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invoke_object?block_until_finish=true" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invoke_object" 2024-11-15T21:16:04.576272Z DEBUG request: tower_http::trace::on_response: finished processing request latency=1 ms status=200 method="POST" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invoke_object?block_until_finish=true" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invoke_object" 2024-11-15T21:16:04.577064Z INFO task_scheduler: assigning task TaskId("cfb2fc0f-36bc-4c64-9a7b-2368a5a139b6") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.578431Z DEBUG request: tower_http::trace::on_request: started processing request method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/31931e6c0c28803b/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload" 2024-11-15T21:16:04.578648Z DEBUG request: tower_http::trace::on_response: finished processing request latency=0 ms status=200 method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/31931e6c0c28803b/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload" 2024-11-15T21:16:04.580745Z DEBUG request: tower_http::trace::on_request: started processing request method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files" 2024-11-15T21:16:04.580895Z INFO request: indexify_server::routes::internal_ingest: writing to blob store, file name = "default.__main__.TestGraphUpdate.test_graph_update.update2.31931e6c0c28803b.cfb2fc0f-36bc-4c64-9a7b-2368a5a139b6.0" method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files" 2024-11-15T21:16:04.582492Z DEBUG request: tower_http::trace::on_response: finished processing request latency=1 ms status=200 method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files" 2024-11-15T21:16:04.582927Z INFO task_scheduler::task_creator: compute graph __main__.TestGraphUpdate.test_graph_update invocation finished: false 2024-11-15T21:16:04.582972Z INFO state_store::state_machine: Marking invocation finished: default __main__.TestGraphUpdate.test_graph_update 31931e6c0c28803b 2024-11-15T21:16:04.596233Z DEBUG request: tower_http::trace::on_request: started processing request method="POST" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invoke_object?block_until_finish=true" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invoke_object" 2024-11-15T21:16:04.598019Z DEBUG request: tower_http::trace::on_response: finished processing request latency=1 ms status=200 method="POST" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invoke_object?block_until_finish=true" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invoke_object" 2024-11-15T21:16:04.598950Z INFO task_scheduler: assigning task TaskId("a857a0d7-de0e-4dab-aedf-ff37333aa4d3") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.600527Z DEBUG request: tower_http::trace::on_request: started processing request method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/6144e7fa455f8a48/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload" 2024-11-15T21:16:04.600758Z DEBUG request: tower_http::trace::on_response: finished processing request latency=0 ms status=200 method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/6144e7fa455f8a48/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload" 2024-11-15T21:16:04.602738Z DEBUG request: tower_http::trace::on_request: started processing request method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files" 2024-11-15T21:16:04.602898Z INFO request: indexify_server::routes::internal_ingest: writing to blob store, file name = "default.__main__.TestGraphUpdate.test_graph_update.update2.6144e7fa455f8a48.a857a0d7-de0e-4dab-aedf-ff37333aa4d3.0" method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files" 2024-11-15T21:16:04.604337Z DEBUG request: tower_http::trace::on_response: finished processing request latency=1 ms status=200 method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files" 2024-11-15T21:16:04.604760Z INFO task_scheduler::task_creator: compute graph __main__.TestGraphUpdate.test_graph_update invocation finished: false 2024-11-15T21:16:04.604804Z INFO state_store::state_machine: Marking invocation finished: default __main__.TestGraphUpdate.test_graph_update 6144e7fa455f8a48 2024-11-15T21:16:04.617455Z DEBUG request: tower_http::trace::on_request: started processing request method="POST" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invoke_object?block_until_finish=true" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invoke_object" 2024-11-15T21:16:04.619236Z DEBUG request: tower_http::trace::on_response: finished processing request latency=1 ms status=200 method="POST" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invoke_object?block_until_finish=true" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invoke_object" 2024-11-15T21:16:04.620107Z INFO task_scheduler: assigning task TaskId("19989dad-f753-48da-8a9e-8821bbf03084") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.621612Z DEBUG request: tower_http::trace::on_request: started processing request method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/f33202d46cf93963/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload" 2024-11-15T21:16:04.621813Z DEBUG request: tower_http::trace::on_response: finished processing request latency=0 ms status=200 method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/f33202d46cf93963/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload" 2024-11-15T21:16:04.623699Z DEBUG request: tower_http::trace::on_request: started processing request method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files" 2024-11-15T21:16:04.623845Z INFO request: indexify_server::routes::internal_ingest: writing to blob store, file name = "default.__main__.TestGraphUpdate.test_graph_update.update2.f33202d46cf93963.19989dad-f753-48da-8a9e-8821bbf03084.0" method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files" 2024-11-15T21:16:04.625251Z DEBUG request: tower_http::trace::on_response: finished processing request latency=1 ms status=200 method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files" 2024-11-15T21:16:04.625646Z INFO task_scheduler::task_creator: compute graph __main__.TestGraphUpdate.test_graph_update invocation finished: false 2024-11-15T21:16:04.625686Z INFO state_store::state_machine: Marking invocation finished: default __main__.TestGraphUpdate.test_graph_update f33202d46cf93963 2024-11-15T21:16:04.638921Z DEBUG request: tower_http::trace::on_request: started processing request method="POST" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invoke_object?block_until_finish=true" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invoke_object" 2024-11-15T21:16:04.640636Z DEBUG request: tower_http::trace::on_response: finished processing request latency=1 ms status=200 method="POST" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invoke_object?block_until_finish=true" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invoke_object" 2024-11-15T21:16:04.641443Z INFO task_scheduler: assigning task TaskId("5b41c2bb-67ce-4be9-9e7e-79f1f997c1d7") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.642899Z DEBUG request: tower_http::trace::on_request: started processing request method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/7b8346f2537b2f74/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload" 2024-11-15T21:16:04.643079Z DEBUG request: tower_http::trace::on_response: finished processing request latency=0 ms status=200 method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/7b8346f2537b2f74/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload" 2024-11-15T21:16:04.644915Z DEBUG request: tower_http::trace::on_request: started processing request method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files" 2024-11-15T21:16:04.645072Z INFO request: indexify_server::routes::internal_ingest: writing to blob store, file name = "default.__main__.TestGraphUpdate.test_graph_update.update2.7b8346f2537b2f74.5b41c2bb-67ce-4be9-9e7e-79f1f997c1d7.0" method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files" 2024-11-15T21:16:04.646516Z DEBUG request: tower_http::trace::on_response: finished processing request latency=1 ms status=200 method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files" 2024-11-15T21:16:04.646926Z INFO task_scheduler::task_creator: compute graph __main__.TestGraphUpdate.test_graph_update invocation finished: false 2024-11-15T21:16:04.646972Z INFO state_store::state_machine: Marking invocation finished: default __main__.TestGraphUpdate.test_graph_update 7b8346f2537b2f74 2024-11-15T21:16:04.660081Z DEBUG request: tower_http::trace::on_request: started processing request method="POST" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invoke_object?block_until_finish=true" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invoke_object" 2024-11-15T21:16:04.661811Z DEBUG request: tower_http::trace::on_response: finished processing request latency=1 ms status=200 method="POST" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invoke_object?block_until_finish=true" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invoke_object" 2024-11-15T21:16:04.662674Z INFO task_scheduler: assigning task TaskId("f46f0a80-78a9-4812-93ac-c05b6def6356") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.664101Z DEBUG request: tower_http::trace::on_request: started processing request method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/f9c203d1cc58c0e9/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload" 2024-11-15T21:16:04.664305Z DEBUG request: tower_http::trace::on_response: finished processing request latency=0 ms status=200 method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/f9c203d1cc58c0e9/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload" 2024-11-15T21:16:04.666352Z DEBUG request: tower_http::trace::on_request: started processing request method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files" 2024-11-15T21:16:04.666505Z INFO request: indexify_server::routes::internal_ingest: writing to blob store, file name = "default.__main__.TestGraphUpdate.test_graph_update.update2.f9c203d1cc58c0e9.f46f0a80-78a9-4812-93ac-c05b6def6356.0" method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files" 2024-11-15T21:16:04.668051Z DEBUG request: tower_http::trace::on_response: finished processing request latency=1 ms status=200 method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files" 2024-11-15T21:16:04.668462Z INFO task_scheduler::task_creator: compute graph __main__.TestGraphUpdate.test_graph_update invocation finished: false 2024-11-15T21:16:04.668505Z INFO state_store::state_machine: Marking invocation finished: default __main__.TestGraphUpdate.test_graph_update f9c203d1cc58c0e9 2024-11-15T21:16:04.681457Z DEBUG request: tower_http::trace::on_request: started processing request method="POST" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invoke_object?block_until_finish=true" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invoke_object" 2024-11-15T21:16:04.683283Z DEBUG request: tower_http::trace::on_response: finished processing request latency=1 ms status=200 method="POST" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invoke_object?block_until_finish=true" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invoke_object" 2024-11-15T21:16:04.684151Z INFO task_scheduler: assigning task TaskId("3023ad50-6c66-4ff5-9c28-ecbb13c54143") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.685676Z DEBUG request: tower_http::trace::on_request: started processing request method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/83055aff366013da/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload" 2024-11-15T21:16:04.685915Z DEBUG request: tower_http::trace::on_response: finished processing request latency=0 ms status=200 method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/83055aff366013da/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload" 2024-11-15T21:16:04.688026Z DEBUG request: tower_http::trace::on_request: started processing request method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files" 2024-11-15T21:16:04.688193Z INFO request: indexify_server::routes::internal_ingest: writing to blob store, file name = "default.__main__.TestGraphUpdate.test_graph_update.update2.83055aff366013da.3023ad50-6c66-4ff5-9c28-ecbb13c54143.0" method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files" 2024-11-15T21:16:04.689774Z DEBUG request: tower_http::trace::on_response: finished processing request latency=1 ms status=200 method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files" 2024-11-15T21:16:04.690202Z INFO task_scheduler::task_creator: compute graph __main__.TestGraphUpdate.test_graph_update invocation finished: false 2024-11-15T21:16:04.690246Z INFO state_store::state_machine: Marking invocation finished: default __main__.TestGraphUpdate.test_graph_update 83055aff366013da 2024-11-15T21:16:04.703373Z DEBUG request: tower_http::trace::on_request: started processing request method="POST" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invoke_object?block_until_finish=true" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invoke_object" 2024-11-15T21:16:04.705086Z DEBUG request: tower_http::trace::on_response: finished processing request latency=1 ms status=200 method="POST" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invoke_object?block_until_finish=true" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invoke_object" 2024-11-15T21:16:04.705904Z INFO task_scheduler: assigning task TaskId("6ce7853f-9bf4-4ac0-9a05-09188855c6b6") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.707369Z DEBUG request: tower_http::trace::on_request: started processing request method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/56d71cdb35ce5f30/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload" 2024-11-15T21:16:04.707569Z DEBUG request: tower_http::trace::on_response: finished processing request latency=0 ms status=200 method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/56d71cdb35ce5f30/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload" 2024-11-15T21:16:04.709552Z DEBUG request: tower_http::trace::on_request: started processing request method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files" 2024-11-15T21:16:04.709704Z INFO request: indexify_server::routes::internal_ingest: writing to blob store, file name = "default.__main__.TestGraphUpdate.test_graph_update.update2.56d71cdb35ce5f30.6ce7853f-9bf4-4ac0-9a05-09188855c6b6.0" method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files" 2024-11-15T21:16:04.711141Z DEBUG request: tower_http::trace::on_response: finished processing request latency=1 ms status=200 method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files" 2024-11-15T21:16:04.711558Z INFO task_scheduler::task_creator: compute graph __main__.TestGraphUpdate.test_graph_update invocation finished: false 2024-11-15T21:16:04.711599Z INFO state_store::state_machine: Marking invocation finished: default __main__.TestGraphUpdate.test_graph_update 56d71cdb35ce5f30 2024-11-15T21:16:04.712150Z DEBUG request: tower_http::trace::on_request: started processing request method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/56d71cdb35ce5f30/outputs" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/outputs" 2024-11-15T21:16:04.712395Z DEBUG request: tower_http::trace::on_response: finished processing request latency=0 ms status=200 method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/56d71cdb35ce5f30/outputs" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/outputs" 2024-11-15T21:16:04.712880Z DEBUG request: tower_http::trace::on_request: started processing request method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/56d71cdb35ce5f30/fn/update2/output/a8b0df3d2569069f" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/fn/:fn_name/output/:id" 2024-11-15T21:16:04.713081Z DEBUG request: tower_http::trace::on_response: finished processing request latency=0 ms status=200 method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/56d71cdb35ce5f30/fn/update2/output/a8b0df3d2569069f" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/fn/:fn_name/output/:id" 2024-11-15T21:16:04.727336Z DEBUG request: tower_http::trace::on_request: started processing request method="POST" uri="/namespaces/default/compute_graphs" matched_path="/namespaces/:namespace/compute_graphs" 2024-11-15T21:16:04.728696Z INFO request: indexify_server::routes: compute graph created: __main__.TestGraphUpdate.test_graph_update method="POST" uri="/namespaces/default/compute_graphs" matched_path="/namespaces/:namespace/compute_graphs" 2024-11-15T21:16:04.728738Z DEBUG request: tower_http::trace::on_response: finished processing request latency=1 ms status=200 method="POST" uri="/namespaces/default/compute_graphs" matched_path="/namespaces/:namespace/compute_graphs" 2024-11-15T21:16:04.729184Z DEBUG request: tower_http::trace::on_request: started processing request method="POST" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/replay" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/replay" 2024-11-15T21:16:04.729653Z DEBUG request: tower_http::trace::on_response: finished processing request latency=0 ms status=200 method="POST" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/replay" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/replay" 2024-11-15T21:16:04.729893Z INFO system_task: indexify_server::system_tasks: queueing invocations queuing=10 task="default|__main__.TestGraphUpdate.test_graph_update" type="replay" 2024-11-15T21:16:04.736832Z INFO task_scheduler: assigning task TaskId("3b78b1f4-0f4a-401f-b329-47642a3215cc") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.737007Z INFO task_scheduler: assigning task TaskId("54449d2d-5323-4fe8-bf91-2812d2f5696b") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.737169Z INFO task_scheduler: assigning task TaskId("9d48963f-a470-4a27-aa3c-c0f6ac9a9696") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.737330Z INFO task_scheduler: assigning task TaskId("4b0ad9e6-924b-492a-b240-bf31c8a76f7e") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.737489Z INFO task_scheduler: assigning task TaskId("4c8d0eff-6b66-41db-bf7b-c2e08f6cef29") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.737648Z INFO task_scheduler: assigning task TaskId("2103d87a-97d3-40a0-b3dc-2072f696ed01") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.737807Z INFO task_scheduler: assigning task TaskId("64612829-9884-495b-9dab-8a93e008ed46") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.737966Z INFO task_scheduler: assigning task TaskId("d289fa65-5d20-4a5a-8ea8-82016bdca52d") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.738127Z INFO task_scheduler: assigning task TaskId("c61ed87c-01aa-4c99-9730-04f465f545f3") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.738287Z INFO task_scheduler: assigning task TaskId("47ff8be7-c927-488c-94f9-cf4e923085ff") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.738962Z INFO task_scheduler: assigning task TaskId("3b78b1f4-0f4a-401f-b329-47642a3215cc") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.739133Z INFO task_scheduler: assigning task TaskId("54449d2d-5323-4fe8-bf91-2812d2f5696b") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.739292Z INFO task_scheduler: assigning task TaskId("9d48963f-a470-4a27-aa3c-c0f6ac9a9696") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.739449Z INFO task_scheduler: assigning task TaskId("4b0ad9e6-924b-492a-b240-bf31c8a76f7e") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.739607Z INFO task_scheduler: assigning task TaskId("4c8d0eff-6b66-41db-bf7b-c2e08f6cef29") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.739765Z INFO task_scheduler: assigning task TaskId("2103d87a-97d3-40a0-b3dc-2072f696ed01") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.739924Z INFO task_scheduler: assigning task TaskId("64612829-9884-495b-9dab-8a93e008ed46") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.740082Z INFO task_scheduler: assigning task TaskId("d289fa65-5d20-4a5a-8ea8-82016bdca52d") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.740240Z INFO task_scheduler: assigning task TaskId("c61ed87c-01aa-4c99-9730-04f465f545f3") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.740391Z INFO task_scheduler: assigning task TaskId("47ff8be7-c927-488c-94f9-cf4e923085ff") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.741069Z INFO task_scheduler: assigning task TaskId("3b78b1f4-0f4a-401f-b329-47642a3215cc") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.741279Z INFO task_scheduler: assigning task TaskId("54449d2d-5323-4fe8-bf91-2812d2f5696b") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.741455Z INFO task_scheduler: assigning task TaskId("9d48963f-a470-4a27-aa3c-c0f6ac9a9696") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.741620Z INFO task_scheduler: assigning task TaskId("4b0ad9e6-924b-492a-b240-bf31c8a76f7e") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.741782Z INFO task_scheduler: assigning task TaskId("4c8d0eff-6b66-41db-bf7b-c2e08f6cef29") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.741944Z INFO task_scheduler: assigning task TaskId("2103d87a-97d3-40a0-b3dc-2072f696ed01") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.742115Z INFO task_scheduler: assigning task TaskId("64612829-9884-495b-9dab-8a93e008ed46") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.742304Z INFO task_scheduler: assigning task TaskId("d289fa65-5d20-4a5a-8ea8-82016bdca52d") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.742464Z INFO task_scheduler: assigning task TaskId("c61ed87c-01aa-4c99-9730-04f465f545f3") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.742622Z INFO task_scheduler: assigning task TaskId("47ff8be7-c927-488c-94f9-cf4e923085ff") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.743318Z INFO task_scheduler: assigning task TaskId("3b78b1f4-0f4a-401f-b329-47642a3215cc") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.743482Z INFO task_scheduler: assigning task TaskId("54449d2d-5323-4fe8-bf91-2812d2f5696b") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.743658Z INFO task_scheduler: assigning task TaskId("9d48963f-a470-4a27-aa3c-c0f6ac9a9696") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.743817Z INFO task_scheduler: assigning task TaskId("4b0ad9e6-924b-492a-b240-bf31c8a76f7e") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.743978Z INFO task_scheduler: assigning task TaskId("4c8d0eff-6b66-41db-bf7b-c2e08f6cef29") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.744139Z INFO task_scheduler: assigning task TaskId("2103d87a-97d3-40a0-b3dc-2072f696ed01") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.744297Z INFO task_scheduler: assigning task TaskId("64612829-9884-495b-9dab-8a93e008ed46") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.744470Z INFO task_scheduler: assigning task TaskId("d289fa65-5d20-4a5a-8ea8-82016bdca52d") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.744635Z INFO task_scheduler: assigning task TaskId("c61ed87c-01aa-4c99-9730-04f465f545f3") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.744812Z INFO task_scheduler: assigning task TaskId("47ff8be7-c927-488c-94f9-cf4e923085ff") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.745564Z INFO task_scheduler: assigning task TaskId("3b78b1f4-0f4a-401f-b329-47642a3215cc") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.745737Z INFO task_scheduler: assigning task TaskId("54449d2d-5323-4fe8-bf91-2812d2f5696b") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.745902Z INFO task_scheduler: assigning task TaskId("9d48963f-a470-4a27-aa3c-c0f6ac9a9696") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.746068Z INFO task_scheduler: assigning task TaskId("4b0ad9e6-924b-492a-b240-bf31c8a76f7e") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.746241Z INFO task_scheduler: assigning task TaskId("4c8d0eff-6b66-41db-bf7b-c2e08f6cef29") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.746422Z INFO task_scheduler: assigning task TaskId("2103d87a-97d3-40a0-b3dc-2072f696ed01") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.746589Z INFO task_scheduler: assigning task TaskId("64612829-9884-495b-9dab-8a93e008ed46") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.746755Z INFO task_scheduler: assigning task TaskId("d289fa65-5d20-4a5a-8ea8-82016bdca52d") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.746907Z INFO task_scheduler: assigning task TaskId("c61ed87c-01aa-4c99-9730-04f465f545f3") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.747072Z INFO task_scheduler: assigning task TaskId("47ff8be7-c927-488c-94f9-cf4e923085ff") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.747772Z INFO task_scheduler: assigning task TaskId("3b78b1f4-0f4a-401f-b329-47642a3215cc") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.747932Z INFO task_scheduler: assigning task TaskId("54449d2d-5323-4fe8-bf91-2812d2f5696b") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.748121Z INFO task_scheduler: assigning task TaskId("9d48963f-a470-4a27-aa3c-c0f6ac9a9696") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.748280Z INFO task_scheduler: assigning task TaskId("4b0ad9e6-924b-492a-b240-bf31c8a76f7e") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.748459Z INFO task_scheduler: assigning task TaskId("4c8d0eff-6b66-41db-bf7b-c2e08f6cef29") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.748618Z INFO task_scheduler: assigning task TaskId("2103d87a-97d3-40a0-b3dc-2072f696ed01") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.748776Z INFO task_scheduler: assigning task TaskId("64612829-9884-495b-9dab-8a93e008ed46") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.748963Z INFO task_scheduler: assigning task TaskId("d289fa65-5d20-4a5a-8ea8-82016bdca52d") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.749131Z INFO task_scheduler: assigning task TaskId("c61ed87c-01aa-4c99-9730-04f465f545f3") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.749301Z INFO task_scheduler: assigning task TaskId("47ff8be7-c927-488c-94f9-cf4e923085ff") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.750014Z INFO task_scheduler: assigning task TaskId("3b78b1f4-0f4a-401f-b329-47642a3215cc") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.750209Z INFO task_scheduler: assigning task TaskId("54449d2d-5323-4fe8-bf91-2812d2f5696b") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.750382Z INFO task_scheduler: assigning task TaskId("9d48963f-a470-4a27-aa3c-c0f6ac9a9696") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.750561Z INFO task_scheduler: assigning task TaskId("4b0ad9e6-924b-492a-b240-bf31c8a76f7e") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.750734Z INFO task_scheduler: assigning task TaskId("4c8d0eff-6b66-41db-bf7b-c2e08f6cef29") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.750902Z INFO task_scheduler: assigning task TaskId("2103d87a-97d3-40a0-b3dc-2072f696ed01") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.751077Z INFO task_scheduler: assigning task TaskId("64612829-9884-495b-9dab-8a93e008ed46") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.751261Z INFO task_scheduler: assigning task TaskId("d289fa65-5d20-4a5a-8ea8-82016bdca52d") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.751419Z INFO task_scheduler: assigning task TaskId("c61ed87c-01aa-4c99-9730-04f465f545f3") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.751589Z INFO task_scheduler: assigning task TaskId("47ff8be7-c927-488c-94f9-cf4e923085ff") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.752300Z INFO task_scheduler: assigning task TaskId("3b78b1f4-0f4a-401f-b329-47642a3215cc") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.752473Z INFO task_scheduler: assigning task TaskId("54449d2d-5323-4fe8-bf91-2812d2f5696b") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.752642Z INFO task_scheduler: assigning task TaskId("9d48963f-a470-4a27-aa3c-c0f6ac9a9696") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.752809Z INFO task_scheduler: assigning task TaskId("4b0ad9e6-924b-492a-b240-bf31c8a76f7e") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.752993Z INFO task_scheduler: assigning task TaskId("4c8d0eff-6b66-41db-bf7b-c2e08f6cef29") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.753162Z INFO task_scheduler: assigning task TaskId("2103d87a-97d3-40a0-b3dc-2072f696ed01") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.753363Z INFO task_scheduler: assigning task TaskId("64612829-9884-495b-9dab-8a93e008ed46") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.753524Z INFO task_scheduler: assigning task TaskId("d289fa65-5d20-4a5a-8ea8-82016bdca52d") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.753692Z INFO task_scheduler: assigning task TaskId("c61ed87c-01aa-4c99-9730-04f465f545f3") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.753852Z INFO task_scheduler: assigning task TaskId("47ff8be7-c927-488c-94f9-cf4e923085ff") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.754548Z INFO task_scheduler: assigning task TaskId("3b78b1f4-0f4a-401f-b329-47642a3215cc") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.754719Z INFO task_scheduler: assigning task TaskId("54449d2d-5323-4fe8-bf91-2812d2f5696b") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.754889Z INFO task_scheduler: assigning task TaskId("9d48963f-a470-4a27-aa3c-c0f6ac9a9696") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.755060Z INFO task_scheduler: assigning task TaskId("4b0ad9e6-924b-492a-b240-bf31c8a76f7e") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.755228Z INFO task_scheduler: assigning task TaskId("4c8d0eff-6b66-41db-bf7b-c2e08f6cef29") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.755397Z INFO task_scheduler: assigning task TaskId("2103d87a-97d3-40a0-b3dc-2072f696ed01") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.755571Z INFO task_scheduler: assigning task TaskId("64612829-9884-495b-9dab-8a93e008ed46") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.755738Z INFO task_scheduler: assigning task TaskId("d289fa65-5d20-4a5a-8ea8-82016bdca52d") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.755906Z INFO task_scheduler: assigning task TaskId("c61ed87c-01aa-4c99-9730-04f465f545f3") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.756094Z INFO task_scheduler: assigning task TaskId("47ff8be7-c927-488c-94f9-cf4e923085ff") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.756797Z INFO task_scheduler: assigning task TaskId("3b78b1f4-0f4a-401f-b329-47642a3215cc") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.756966Z INFO task_scheduler: assigning task TaskId("54449d2d-5323-4fe8-bf91-2812d2f5696b") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.757135Z INFO task_scheduler: assigning task TaskId("9d48963f-a470-4a27-aa3c-c0f6ac9a9696") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.757303Z INFO task_scheduler: assigning task TaskId("4b0ad9e6-924b-492a-b240-bf31c8a76f7e") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.757474Z INFO task_scheduler: assigning task TaskId("4c8d0eff-6b66-41db-bf7b-c2e08f6cef29") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.757662Z INFO task_scheduler: assigning task TaskId("2103d87a-97d3-40a0-b3dc-2072f696ed01") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.757827Z INFO task_scheduler: assigning task TaskId("64612829-9884-495b-9dab-8a93e008ed46") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.757993Z INFO task_scheduler: assigning task TaskId("d289fa65-5d20-4a5a-8ea8-82016bdca52d") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.758155Z INFO task_scheduler: assigning task TaskId("c61ed87c-01aa-4c99-9730-04f465f545f3") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.758324Z INFO task_scheduler: assigning task TaskId("47ff8be7-c927-488c-94f9-cf4e923085ff") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.762507Z DEBUG request: tower_http::trace::on_request: started processing request method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph" 2024-11-15T21:16:04.762647Z DEBUG request: tower_http::trace::on_response: finished processing request latency=0 ms status=200 method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph" 2024-11-15T21:16:04.765144Z DEBUG request: tower_http::trace::on_request: started processing request method="GET" uri="/internal/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/code" matched_path="/internal/namespaces/:namespace/compute_graphs/:compute_graph/code" 2024-11-15T21:16:04.765408Z DEBUG request: tower_http::trace::on_response: finished processing request latency=0 ms status=200 method="GET" uri="/internal/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/code" matched_path="/internal/namespaces/:namespace/compute_graphs/:compute_graph/code" 2024-11-15T21:16:04.766516Z DEBUG request: tower_http::trace::on_request: started processing request method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/83055aff366013da/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload" 2024-11-15T21:16:04.766709Z DEBUG request: tower_http::trace::on_response: finished processing request latency=0 ms status=200 method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/83055aff366013da/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload" 2024-11-15T21:16:04.767387Z DEBUG request: tower_http::trace::on_request: started processing request method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/205684db422504d4/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload" 2024-11-15T21:16:04.767542Z DEBUG request: tower_http::trace::on_response: finished processing request latency=0 ms status=200 method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/205684db422504d4/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload" 2024-11-15T21:16:04.768173Z DEBUG request: tower_http::trace::on_request: started processing request method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/56d71cdb35ce5f30/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload" 2024-11-15T21:16:04.768315Z DEBUG request: tower_http::trace::on_response: finished processing request latency=0 ms status=200 method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/56d71cdb35ce5f30/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload" 2024-11-15T21:16:04.768947Z DEBUG request: tower_http::trace::on_request: started processing request method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/7b8346f2537b2f74/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload" 2024-11-15T21:16:04.769070Z DEBUG request: tower_http::trace::on_response: finished processing request latency=0 ms status=200 method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/7b8346f2537b2f74/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload" 2024-11-15T21:16:04.769655Z DEBUG request: tower_http::trace::on_request: started processing request method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/1a1a202bcb77ca40/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload" 2024-11-15T21:16:04.769783Z DEBUG request: tower_http::trace::on_response: finished processing request latency=0 ms status=200 method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/1a1a202bcb77ca40/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload" 2024-11-15T21:16:04.770536Z DEBUG request: tower_http::trace::on_request: started processing request method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/31931e6c0c28803b/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload" 2024-11-15T21:16:04.770678Z DEBUG request: tower_http::trace::on_response: finished processing request latency=0 ms status=200 method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/31931e6c0c28803b/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload" 2024-11-15T21:16:04.771270Z DEBUG request: tower_http::trace::on_request: started processing request method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/f33202d46cf93963/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload" 2024-11-15T21:16:04.771386Z DEBUG request: tower_http::trace::on_response: finished processing request latency=0 ms status=200 method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/f33202d46cf93963/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload" 2024-11-15T21:16:04.771956Z DEBUG request: tower_http::trace::on_request: started processing request method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/b7fabce39e8a8e9a/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload" 2024-11-15T21:16:04.772074Z DEBUG request: tower_http::trace::on_response: finished processing request latency=0 ms status=200 method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/b7fabce39e8a8e9a/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload" 2024-11-15T21:16:04.772646Z DEBUG request: tower_http::trace::on_request: started processing request method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/6144e7fa455f8a48/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload" 2024-11-15T21:16:04.772756Z DEBUG request: tower_http::trace::on_response: finished processing request latency=0 ms status=200 method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/6144e7fa455f8a48/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload" 2024-11-15T21:16:04.773366Z DEBUG request: tower_http::trace::on_request: started processing request method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/1adaad644b88fddf/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload" 2024-11-15T21:16:04.773484Z DEBUG request: tower_http::trace::on_response: finished processing request latency=0 ms status=200 method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/1adaad644b88fddf/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload" 2024-11-15T21:16:04.780541Z DEBUG request: tower_http::trace::on_request: started processing request method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files" 2024-11-15T21:16:04.780647Z INFO request: indexify_server::routes::internal_ingest: writing to blob store, file name = "default.__main__.TestGraphUpdate.test_graph_update.update.f33202d46cf93963.47ff8be7-c927-488c-94f9-cf4e923085ff.0" method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files" 2024-11-15T21:16:04.782319Z DEBUG request: tower_http::trace::on_response: finished processing request latency=1 ms status=200 method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files" 2024-11-15T21:16:04.783568Z DEBUG request: tower_http::trace::on_request: started processing request method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files" 2024-11-15T21:16:04.783593Z INFO task_scheduler::task_creator: compute graph __main__.TestGraphUpdate.test_graph_update invocation finished: false 2024-11-15T21:16:04.783643Z INFO state_store::state_machine: Marking invocation finished: default __main__.TestGraphUpdate.test_graph_update f33202d46cf93963 2024-11-15T21:16:04.783702Z INFO request: indexify_server::routes::internal_ingest: writing to blob store, file name = "default.__main__.TestGraphUpdate.test_graph_update.update.7b8346f2537b2f74.64612829-9884-495b-9dab-8a93e008ed46.0" method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files" 2024-11-15T21:16:04.783914Z ERROR state_store: failed to send invocation state change: SendError(InvocationFinished(InvocationFinishedEvent { id: "f33202d46cf93963" })) 2024-11-15T21:16:04.784156Z INFO system_task: indexify_server::system_tasks: queueing invocations queuing=1 task="default|__main__.TestGraphUpdate.test_graph_update" type="replay" 2024-11-15T21:16:04.785070Z INFO system_task: indexify_server::system_tasks: waiting for all invotations to finish before completing the task running_invocations=10 task="default|__main__.TestGraphUpdate.test_graph_update" type="replay" 2024-11-15T21:16:04.785328Z DEBUG request: tower_http::trace::on_response: finished processing request latency=1 ms status=200 method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files" 2024-11-15T21:16:04.786418Z DEBUG request: tower_http::trace::on_request: started processing request method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files" 2024-11-15T21:16:04.786550Z INFO request: indexify_server::routes::internal_ingest: writing to blob store, file name = "default.__main__.TestGraphUpdate.test_graph_update.update.1adaad644b88fddf.54449d2d-5323-4fe8-bf91-2812d2f5696b.0" method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files" 2024-11-15T21:16:04.786765Z INFO task_scheduler::task_creator: compute graph __main__.TestGraphUpdate.test_graph_update invocation finished: false 2024-11-15T21:16:04.787115Z INFO task_scheduler: assigning task TaskId("e87bfb36-75c7-4a14-af73-9c0120cad470") to executor ExecutorId("N--EqyG4Eaw86QAp3MpOR") 2024-11-15T21:16:04.787163Z INFO state_store::state_machine: Marking invocation finished: default __main__.TestGraphUpdate.test_graph_update 7b8346f2537b2f74 2024-11-15T21:16:04.787376Z ERROR state_store: failed to send invocation state change: SendError(InvocationFinished(InvocationFinishedEvent { id: "7b8346f2537b2f74" })) 2024-11-15T21:16:04.787615Z INFO system_task: indexify_server::system_tasks: waiting for all invotations to finish before completing the task running_invocations=9 task="default|__main__.TestGraphUpdate.test_graph_update" type="replay" 2024-11-15T21:16:04.788198Z DEBUG request: tower_http::trace::on_response: finished processing request latency=1 ms status=200 method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files" 2024-11-15T21:16:04.789094Z INFO task_scheduler::task_creator: compute graph __main__.TestGraphUpdate.test_graph_update invocation finished: false 2024-11-15T21:16:04.789144Z INFO state_store::state_machine: Marking invocation finished: default __main__.TestGraphUpdate.test_graph_update 1adaad644b88fddf 2024-11-15T21:16:04.789315Z DEBUG request: tower_http::trace::on_request: started processing request method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files" 2024-11-15T21:16:04.789366Z ERROR state_store: failed to send invocation state change: SendError(InvocationFinished(InvocationFinishedEvent { id: "1adaad644b88fddf" })) 2024-11-15T21:16:04.789417Z INFO request: indexify_server::routes::internal_ingest: writing to blob store, file name = "default.__main__.TestGraphUpdate.test_graph_update.update.6144e7fa455f8a48.2103d87a-97d3-40a0-b3dc-2072f696ed01.0" method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files" 2024-11-15T21:16:04.789531Z INFO system_task: indexify_server::system_tasks: waiting for all invotations to finish before completing the task running_invocations=8 task="default|__main__.TestGraphUpdate.test_graph_update" type="replay" 2024-11-15T21:16:04.790951Z DEBUG request: tower_http::trace::on_response: finished processing request latency=1 ms status=200 method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files" 2024-11-15T21:16:04.791790Z INFO task_scheduler::task_creator: compute graph __main__.TestGraphUpdate.test_graph_update invocation finished: false 2024-11-15T21:16:04.791830Z INFO state_store::state_machine: Marking invocation finished: default __main__.TestGraphUpdate.test_graph_update 6144e7fa455f8a48 2024-11-15T21:16:04.792045Z DEBUG request: tower_http::trace::on_request: started processing request method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files" 2024-11-15T21:16:04.792115Z ERROR state_store: failed to send invocation state change: SendError(InvocationFinished(InvocationFinishedEvent { id: "6144e7fa455f8a48" })) 2024-11-15T21:16:04.792133Z INFO request: indexify_server::routes::internal_ingest: writing to blob store, file name = "default.__main__.TestGraphUpdate.test_graph_update.update.31931e6c0c28803b.4b0ad9e6-924b-492a-b240-bf31c8a76f7e.0" method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files" 2024-11-15T21:16:04.792272Z INFO system_task: indexify_server::system_tasks: waiting for all invotations to finish before completing the task running_invocations=7 task="default|__main__.TestGraphUpdate.test_graph_update" type="replay" 2024-11-15T21:16:04.793449Z DEBUG request: tower_http::trace::on_response: finished processing request latency=1 ms status=200 method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files" 2024-11-15T21:16:04.794408Z INFO task_scheduler::task_creator: compute graph __main__.TestGraphUpdate.test_graph_update invocation finished: false 2024-11-15T21:16:04.794450Z INFO state_store::state_machine: Marking invocation finished: default __main__.TestGraphUpdate.test_graph_update 31931e6c0c28803b 2024-11-15T21:16:04.794452Z DEBUG request: tower_http::trace::on_request: started processing request method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files" 2024-11-15T21:16:04.794570Z INFO request: indexify_server::routes::internal_ingest: writing to blob store, file name = "default.__main__.TestGraphUpdate.test_graph_update.update.83055aff366013da.d289fa65-5d20-4a5a-8ea8-82016bdca52d.0" method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files" 2024-11-15T21:16:04.794584Z ERROR state_store: failed to send invocation state change: SendError(InvocationFinished(InvocationFinishedEvent { id: "31931e6c0c28803b" })) 2024-11-15T21:16:04.794738Z INFO system_task: indexify_server::system_tasks: waiting for all invotations to finish before completing the task running_invocations=6 task="default|__main__.TestGraphUpdate.test_graph_update" type="replay" 2024-11-15T21:16:04.795903Z DEBUG request: tower_http::trace::on_response: finished processing request latency=1 ms status=200 method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files" 2024-11-15T21:16:04.796830Z INFO task_scheduler::task_creator: compute graph __main__.TestGraphUpdate.test_graph_update invocation finished: false 2024-11-15T21:16:04.796839Z DEBUG request: tower_http::trace::on_request: started processing request method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files" 2024-11-15T21:16:04.796896Z INFO state_store::state_machine: Marking invocation finished: default __main__.TestGraphUpdate.test_graph_update 83055aff366013da 2024-11-15T21:16:04.796955Z INFO request: indexify_server::routes::internal_ingest: writing to blob store, file name = "default.__main__.TestGraphUpdate.test_graph_update.update.b7fabce39e8a8e9a.c61ed87c-01aa-4c99-9730-04f465f545f3.0" method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files" 2024-11-15T21:16:04.797026Z ERROR state_store: failed to send invocation state change: SendError(InvocationFinished(InvocationFinishedEvent { id: "83055aff366013da" })) 2024-11-15T21:16:04.797193Z INFO system_task: indexify_server::system_tasks: waiting for all invotations to finish before completing the task running_invocations=5 task="default|__main__.TestGraphUpdate.test_graph_update" type="replay" 2024-11-15T21:16:04.798389Z DEBUG request: tower_http::trace::on_response: finished processing request latency=1 ms status=200 method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files" 2024-11-15T21:16:04.799168Z INFO task_scheduler::task_creator: compute graph __main__.TestGraphUpdate.test_graph_update invocation finished: false 2024-11-15T21:16:04.799219Z INFO state_store::state_machine: Marking invocation finished: default __main__.TestGraphUpdate.test_graph_update b7fabce39e8a8e9a 2024-11-15T21:16:04.799379Z ERROR state_store: failed to send invocation state change: SendError(InvocationFinished(InvocationFinishedEvent { id: "b7fabce39e8a8e9a" })) 2024-11-15T21:16:04.799487Z DEBUG request: tower_http::trace::on_request: started processing request method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files" 2024-11-15T21:16:04.799565Z INFO system_task: indexify_server::system_tasks: waiting for all invotations to finish before completing the task running_invocations=4 task="default|__main__.TestGraphUpdate.test_graph_update" type="replay" 2024-11-15T21:16:04.799637Z INFO request: indexify_server::routes::internal_ingest: writing to blob store, file name = "default.__main__.TestGraphUpdate.test_graph_update.update.205684db422504d4.9d48963f-a470-4a27-aa3c-c0f6ac9a9696.0" method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files" 2024-11-15T21:16:04.800961Z DEBUG request: tower_http::trace::on_response: finished processing request latency=1 ms status=200 method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files" 2024-11-15T21:16:04.801612Z INFO task_scheduler::task_creator: compute graph __main__.TestGraphUpdate.test_graph_update invocation finished: false 2024-11-15T21:16:04.801661Z INFO state_store::state_machine: Marking invocation finished: default __main__.TestGraphUpdate.test_graph_update 205684db422504d4 2024-11-15T21:16:04.801793Z ERROR state_store: failed to send invocation state change: SendError(InvocationFinished(InvocationFinishedEvent { id: "205684db422504d4" })) 2024-11-15T21:16:04.801887Z DEBUG request: tower_http::trace::on_request: started processing request method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files" 2024-11-15T21:16:04.801954Z INFO system_task: indexify_server::system_tasks: waiting for all invotations to finish before completing the task running_invocations=3 task="default|__main__.TestGraphUpdate.test_graph_update" type="replay" 2024-11-15T21:16:04.802012Z INFO request: indexify_server::routes::internal_ingest: writing to blob store, file name = "default.__main__.TestGraphUpdate.test_graph_update.update.1a1a202bcb77ca40.3b78b1f4-0f4a-401f-b329-47642a3215cc.0" method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files" 2024-11-15T21:16:04.803306Z DEBUG request: tower_http::trace::on_response: finished processing request latency=1 ms status=200 method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files" 2024-11-15T21:16:04.803858Z INFO task_scheduler::task_creator: compute graph __main__.TestGraphUpdate.test_graph_update invocation finished: false 2024-11-15T21:16:04.803892Z INFO state_store::state_machine: Marking invocation finished: default __main__.TestGraphUpdate.test_graph_update 1a1a202bcb77ca40 2024-11-15T21:16:04.804020Z ERROR state_store: failed to send invocation state change: SendError(InvocationFinished(InvocationFinishedEvent { id: "1a1a202bcb77ca40" })) 2024-11-15T21:16:04.804157Z INFO system_task: indexify_server::system_tasks: waiting for all invotations to finish before completing the task running_invocations=2 task="default|__main__.TestGraphUpdate.test_graph_update" type="replay" 2024-11-15T21:16:04.804338Z DEBUG request: tower_http::trace::on_request: started processing request method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files" 2024-11-15T21:16:04.804442Z INFO request: indexify_server::routes::internal_ingest: writing to blob store, file name = "default.__main__.TestGraphUpdate.test_graph_update.update.56d71cdb35ce5f30.4c8d0eff-6b66-41db-bf7b-c2e08f6cef29.0" method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files" 2024-11-15T21:16:04.805740Z DEBUG request: tower_http::trace::on_response: finished processing request latency=1 ms status=200 method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files" 2024-11-15T21:16:04.806225Z INFO task_scheduler::task_creator: compute graph __main__.TestGraphUpdate.test_graph_update invocation finished: false 2024-11-15T21:16:04.806269Z INFO state_store::state_machine: Marking invocation finished: default __main__.TestGraphUpdate.test_graph_update 56d71cdb35ce5f30 2024-11-15T21:16:04.806407Z ERROR state_store: failed to send invocation state change: SendError(InvocationFinished(InvocationFinishedEvent { id: "56d71cdb35ce5f30" })) 2024-11-15T21:16:04.806589Z INFO system_task: indexify_server::system_tasks: waiting for all invotations to finish before completing the task running_invocations=1 task="default|__main__.TestGraphUpdate.test_graph_update" type="replay" 2024-11-15T21:16:04.807195Z DEBUG request: tower_http::trace::on_request: started processing request method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/f9c203d1cc58c0e9/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload" 2024-11-15T21:16:04.807395Z DEBUG request: tower_http::trace::on_response: finished processing request latency=0 ms status=200 method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/f9c203d1cc58c0e9/payload" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/payload" 2024-11-15T21:16:04.809126Z DEBUG request: tower_http::trace::on_request: started processing request method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files" 2024-11-15T21:16:04.809277Z INFO request: indexify_server::routes::internal_ingest: writing to blob store, file name = "default.__main__.TestGraphUpdate.test_graph_update.update.f9c203d1cc58c0e9.e87bfb36-75c7-4a14-af73-9c0120cad470.0" method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files" 2024-11-15T21:16:04.810691Z DEBUG request: tower_http::trace::on_response: finished processing request latency=1 ms status=200 method="POST" uri="/internal/ingest_files" matched_path="/internal/ingest_files" 2024-11-15T21:16:04.811090Z INFO task_scheduler::task_creator: compute graph __main__.TestGraphUpdate.test_graph_update invocation finished: false 2024-11-15T21:16:04.811128Z INFO state_store::state_machine: Marking invocation finished: default __main__.TestGraphUpdate.test_graph_update f9c203d1cc58c0e9 2024-11-15T21:16:04.811261Z ERROR state_store: failed to send invocation state change: SendError(InvocationFinished(InvocationFinishedEvent { id: "f9c203d1cc58c0e9" })) 2024-11-15T21:16:04.811405Z INFO system_task: indexify_server::system_tasks: completed task="default|__main__.TestGraphUpdate.test_graph_update" type="replay" 2024-11-15T21:16:04.811603Z INFO indexify_server::system_tasks: no system tasks to process 2024-11-15T21:16:06.769853Z DEBUG request: tower_http::trace::on_request: started processing request method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph" 2024-11-15T21:16:06.770721Z DEBUG request: tower_http::trace::on_response: finished processing request latency=0 ms status=200 method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph" 2024-11-15T21:16:06.772963Z DEBUG request: tower_http::trace::on_request: started processing request method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/56d71cdb35ce5f30/outputs" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/outputs" 2024-11-15T21:16:06.774148Z DEBUG request: tower_http::trace::on_response: finished processing request latency=1 ms status=200 method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/56d71cdb35ce5f30/outputs" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/outputs" 2024-11-15T21:16:06.776137Z DEBUG request: tower_http::trace::on_request: started processing request method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/56d71cdb35ce5f30/fn/update/output/d388509bb723640d" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/fn/:fn_name/output/:id" 2024-11-15T21:16:06.777187Z DEBUG request: tower_http::trace::on_response: finished processing request latency=1 ms status=200 method="GET" uri="/namespaces/default/compute_graphs/__main__.TestGraphUpdate.test_graph_update/invocations/56d71cdb35ce5f30/fn/update/output/d388509bb723640d" matched_path="/namespaces/:namespace/compute_graphs/:compute_graph/invocations/:invocation_id/fn/:fn_name/output/:id" ```Contribution Checklist
make fmtinpython-sdk/.make fmtinserver/.