Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Retried Run sporadically in both succeeded and failed state #1077

Open
tscurtu opened this issue Oct 11, 2023 · 0 comments
Open

Retried Run sporadically in both succeeded and failed state #1077

tscurtu opened this issue Oct 11, 2023 · 0 comments
Labels
bug Something isn't working db observability ui UI related work

Comments

@tscurtu
Copy link
Contributor

tscurtu commented Oct 11, 2023

A failing retry Run is displayed as failed in the Dashboard, but is considered successful by the pipeline.

Apparently, the Dashboard displays a different Run job than the final, successful job. This was observed only once, hinting to a potential race condition.

Reproduction command:

$ bazel run sematic/examples/testing_pipeline:__main__ -- \
              --cloud \
              --detach \
              --max-parallelism 10 \
              --inline \
              --nested \
              --no-input \
              --sleep 10 \
              --spam-logs 1000 \
              --fan-out 10 \
              --raise-retry 0.7 \
              --external-resource \
              --expand-shared-memory \
              --mount-host-path /tmp /test \
              --mount-host-path /tmp /test2 \
              --cache-namespace test \
              --images \
              --virtual-funcs \
              --fork-subprocess return 0 \
              --fork-subprocess exit 0 \
              --fork-subprocess exit 1 \
              --fork-subprocess signal 2 \
              --fork-subprocess signal 15

Visualization:
image

Run metadata:

{
  "content": {
    "cache_key":null,
    "container_image_uri":"XXX",
    "created_at":"2023-10-11T19:34:58.314969+00:00",
    "description":"Raises a ValueError with the given probability, with a total of 10 retries.",
    "ended_at":null,
    "exception_metadata_json":{
      "ancestors":["builtins.Exception"],
      "module":"builtins",
      "name":"ValueError",
      "repr":"Traceback (most recent call last):\n\n  File \"/app/sematic/examples/testing_pipeline/__main___default_image.binary.runfiles/sematic/sematic/function.py\", line 191, in execute\n    output = self.func(**kwargs)\n\n  File \"/app/sematic/examples/testing_pipeline/__main___default_image.binary.runfiles/sematic/sematic/examples/testing_pipeline/pipeline.py\", line 336, in do_retry\n    raise ValueError(\"test retriable exception\")\n\nValueError: test retriable exception\n"
    },
    "external_exception_metadata_json":null,
    "failed_at":"2023-10-11T19:38:55.331107+00:00",
    "function_path":"sematic.examples.testing_pipeline.pipeline.do_retry",
    "future_state":"FAILED",
    "id":"6151fcdd593447eead94bcb06af41050",
    "name":"do_retry",
    "nested_future_id":null,
    "organization_id":null,
    "original_run_id":null,
    "parent_id":"0acd44363b2a45c79643861c4fd7e584",
    "resolved_at":"2023-10-11T19:38:28.288709+00:00",
    "resource_requirements_json":null,
    "root_id":"0acd44363b2a45c79643861c4fd7e584",
    "source_code":"@sematic.func(\n    standalone=True, retry=sematic.RetrySettings(exceptions=(ValueError,), retries=10)\n)\ndef do_retry(val: float, failure_probability: float = 0.5) -> float:\n    \"\"\"\n    Raises a ValueError with the given probability, with a total of 10 retries.\n    \"\"\"\n    logger.info(\n        \"Executing: do_retry(val=%s, failure_probability=%s)\", val, failure_probability\n    )\n    time.sleep(5)\n    if random.random() < failure_probability:\n        raise ValueError(\"test retriable exception\")\n    return val\n",
    "started_at":"2023-10-11T19:38:13.219016+00:00",
    "tags":[],
    "updated_at":"2023-10-11T19:38:55.375822+00:00",
    "user":{
      "avatar_url":"XXX",
      "created_at":"2023-07-14T10:33:29.468698+00:00",
      "first_name":"Tudor",
      "id":"XXX",
      "last_name":"Scurtu",
      "updated_at":"2023-10-11T19:27:26.589870+00:00"
    },
    "user_id":"XXX"
  }
}

Server logs pertaining to this Run:

$ kubectl logs sematic-server-555d8c6d99-m5rvq | grep 6151fcdd593447eead94bcb06af41050
2023-10-11 19:35:01,188 72661743d [INFO] sematic.api.endpoints.runs: Graph update, run 6151fcdd593447eead94bcb06af41050 is in state CREATED
2023-10-11 19:35:02,041 72661743d [INFO] root: Generated metric sematic.run_count for run 6151fcdd593447eead94bcb06af41050 with value 1
2023-10-11 19:35:49,690 0e03efb38 [INFO] sematic.api.endpoints.runs: Graph update, run 6151fcdd593447eead94bcb06af41050 is in state CREATED
2023-10-11 19:35:49,917 c0adcd754 [INFO] sematic.api.server: Request start: 10.42.37.172 python-requests/2.28.2 POST /api/v1/runs/6151fcdd593447eead94bcb06af41050/schedule
2023-10-11 19:35:49,990 c0adcd754 [INFO] sematic.scheduling.kubernetes: Scheduling job stage/sematic-worker-6151fcdd593447eead94bcb06af41050-c3c8d5 with image 558717131297.dkr.ecr.us-west-2.amazonaws.com/sematic-dev@sha256:77fcae4412a38432835be94343669e22f8d7b9a3698336c0974168f320d4d746
2023-10-11 19:35:50,033 c0adcd754 [INFO] sematic.scheduling.job_scheduler: After schedule, jobs: [Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-c3c8d5, run_id=6151fcdd593447eead94bcb06af41050, state=Requested, ...)]
2023-10-11 19:35:50,034 c0adcd754 [INFO] sematic.api.endpoints.runs: Scheduled run with job: Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-c3c8d5, run_id=6151fcdd593447eead94bcb06af41050, state=Requested, ...)
2023-10-11 19:35:50,109 c0adcd754 [INFO] sematic.api.server: Request end: 10.42.37.172 python-requests/2.28.2 POST /api/v1/runs/6151fcdd593447eead94bcb06af41050/schedule 200
2023-10-11 19:36:22,078 67a4b7745 [INFO] sematic.api.server: Request start: 10.42.37.219 python-requests/2.28.2 GET /api/v1/runs/6151fcdd593447eead94bcb06af41050/graph?root=0
2023-10-11 19:36:22,096 67a4b7745 [INFO] sematic.api.server: Request end: 10.42.37.219 python-requests/2.28.2 GET /api/v1/runs/6151fcdd593447eead94bcb06af41050/graph?root=0 200
2023-10-11 19:36:29,996 e2c48c997 [INFO] sematic.api.endpoints.runs: Graph update, run 6151fcdd593447eead94bcb06af41050 is in state FAILED
2023-10-11 19:36:30,030 e2c48c997 [INFO] sematic.api.endpoints.runs: Ensuring jobs for 6151fcdd593447eead94bcb06af41050 are stopped FAILED
2023-10-11 19:36:30,170 01a30f135 [INFO] sematic.api.server: Request start: 10.42.37.219 python-requests/2.28.2 GET /api/v1/storage/logs/v2/run_id/6151fcdd593447eead94bcb06af41050/worker/1697052990134.log/location?origin=http://sematic-server
2023-10-11 19:36:30,179 01a30f135 [INFO] sematic.plugins.storage.s3_storage: Generating S3 presigned url for logs/v2/run_id/6151fcdd593447eead94bcb06af41050/worker/1697052990134.log
2023-10-11 19:36:30,195 01a30f135 [INFO] sematic.api.server: Request end: 10.42.37.219 python-requests/2.28.2 GET /api/v1/storage/logs/v2/run_id/6151fcdd593447eead94bcb06af41050/worker/1697052990134.log/location?origin=http://sematic-server 200
2023-10-11 19:36:43,833 572d36325 [INFO] sematic.api.server: Request start: 10.42.37.172 python-requests/2.28.2 GET /api/v1/runs/6151fcdd593447eead94bcb06af41050/graph?root=0
2023-10-11 19:36:43,863 572d36325 [INFO] sematic.api.server: Request end: 10.42.37.172 python-requests/2.28.2 GET /api/v1/runs/6151fcdd593447eead94bcb06af41050/graph?root=0 200
2023-10-11 19:36:49,328 f46d4464e [INFO] sematic.api.endpoints.runs: Graph update, run 6151fcdd593447eead94bcb06af41050 is in state RETRYING
2023-10-11 19:36:49,361 5af82df1b [INFO] sematic.api.server: Request start: 10.42.37.172 python-requests/2.28.2 GET /api/v1/runs/6151fcdd593447eead94bcb06af41050
2023-10-11 19:36:49,391 5af82df1b [INFO] sematic.api.server: Request end: 10.42.37.172 python-requests/2.28.2 GET /api/v1/runs/6151fcdd593447eead94bcb06af41050 200
2023-10-11 19:36:49,484 c20488576 [INFO] sematic.api.endpoints.runs: Graph update, run 6151fcdd593447eead94bcb06af41050 is in state RETRYING
2023-10-11 19:36:49,812 81602b20f [INFO] sematic.api.server: Request start: 10.42.37.172 python-requests/2.28.2 POST /api/v1/runs/6151fcdd593447eead94bcb06af41050/schedule
2023-10-11 19:36:49,867 81602b20f [WARNING] sematic.scheduling.kubernetes: Got 404 while looking for job stage/sematic-worker-6151fcdd593447eead94bcb06af41050-c3c8d5
2023-10-11 19:36:49,869 81602b20f [INFO] sematic.scheduling.kubernetes: Scheduling job stage/sematic-worker-6151fcdd593447eead94bcb06af41050-071d9c with image 558717131297.dkr.ecr.us-west-2.amazonaws.com/sematic-dev@sha256:77fcae4412a38432835be94343669e22f8d7b9a3698336c0974168f320d4d746
2023-10-11 19:36:49,908 81602b20f [INFO] sematic.scheduling.job_scheduler: After schedule, jobs: [Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-c3c8d5, run_id=6151fcdd593447eead94bcb06af41050, state=Requested, ...), Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-071d9c, run_id=6151fcdd593447eead94bcb06af41050, state=Requested, ...)]
2023-10-11 19:36:49,909 81602b20f [INFO] sematic.api.endpoints.runs: Scheduled run with job: Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-071d9c, run_id=6151fcdd593447eead94bcb06af41050, state=Requested, ...)
2023-10-11 19:36:50,032 81602b20f [INFO] sematic.api.server: Request end: 10.42.37.172 python-requests/2.28.2 POST /api/v1/runs/6151fcdd593447eead94bcb06af41050/schedule 200
2023-10-11 19:36:54,553 852b3a5cd [INFO] sematic.api.endpoints.runs: Updating state for runs: ['6151fcdd593447eead94bcb06af41050', '15a39fccdb4147629f7c4f113ea1feb2', '8fb1d37172ef45baaa3f7bc43eb675fe', '3d910da7c84e4da99f6c103e5da6d078', 'f5b5a18f976449fa9b4122263a986a65', '8e385864654d4ff8a030480b8f1b9d61', '93af64ba41744f93b5f8187fd776a6b8', '8e9e412295754ae882cb8d17d4591331', '614cad1f94b94ec8b3a109fbb1ee0ba4', 'de5e2e3b1f3d455c853100012e2c6044']
2023-10-11 19:36:54,965 852b3a5cd [WARNING] sematic.scheduling.kubernetes: Got 404 while looking for job stage/sematic-worker-6151fcdd593447eead94bcb06af41050-c3c8d5
2023-10-11 19:36:55,043 852b3a5cd [INFO] sematic.scheduling.kubernetes: Setting has_started=True for job stage/sematic-worker-6151fcdd593447eead94bcb06af41050-071d9c at timestamp 1697053009.0
2023-10-11 19:36:55,086 852b3a5cd [INFO] sematic.api.endpoints.runs: Updating run's jobs: [Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-c3c8d5, run_id=6151fcdd593447eead94bcb06af41050, state=Requested, ...), Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-071d9c, run_id=6151fcdd593447eead94bcb06af41050, state=Running, ...)]
2023-10-11 19:36:59,846 e03047d0e [INFO] sematic.api.endpoints.runs: Updating state for runs: ['6151fcdd593447eead94bcb06af41050', '15a39fccdb4147629f7c4f113ea1feb2', '8fb1d37172ef45baaa3f7bc43eb675fe', '3d910da7c84e4da99f6c103e5da6d078', 'f5b5a18f976449fa9b4122263a986a65', '8e385864654d4ff8a030480b8f1b9d61', '93af64ba41744f93b5f8187fd776a6b8', '8e9e412295754ae882cb8d17d4591331', '614cad1f94b94ec8b3a109fbb1ee0ba4', 'de5e2e3b1f3d455c853100012e2c6044']
2023-10-11 19:37:00,246 e03047d0e [WARNING] sematic.scheduling.kubernetes: Got 404 while looking for job stage/sematic-worker-6151fcdd593447eead94bcb06af41050-c3c8d5
2023-10-11 19:37:00,319 e03047d0e [INFO] sematic.api.endpoints.runs: Updating run's jobs: [Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-c3c8d5, run_id=6151fcdd593447eead94bcb06af41050, state=Requested, ...), Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-071d9c, run_id=6151fcdd593447eead94bcb06af41050, state=Running, ...)]
2023-10-11 19:37:13,461 507ed6aea [INFO] sematic.api.endpoints.runs: Updating state for runs: ['6151fcdd593447eead94bcb06af41050', '8fb1d37172ef45baaa3f7bc43eb675fe', '3d910da7c84e4da99f6c103e5da6d078', 'f5b5a18f976449fa9b4122263a986a65', '8e385864654d4ff8a030480b8f1b9d61', '93af64ba41744f93b5f8187fd776a6b8', '8e9e412295754ae882cb8d17d4591331', '614cad1f94b94ec8b3a109fbb1ee0ba4', 'de5e2e3b1f3d455c853100012e2c6044', '1ded015d28674761bebf43e9adac4803']
2023-10-11 19:37:13,633 507ed6aea [WARNING] sematic.scheduling.kubernetes: Got 404 while looking for job stage/sematic-worker-6151fcdd593447eead94bcb06af41050-c3c8d5
2023-10-11 19:37:13,741 507ed6aea [INFO] sematic.api.endpoints.runs: Updating run's jobs: [Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-c3c8d5, run_id=6151fcdd593447eead94bcb06af41050, state=Requested, ...), Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-071d9c, run_id=6151fcdd593447eead94bcb06af41050, state=Running, ...)]
2023-10-11 19:37:20,585 2f25f22d4 [INFO] sematic.api.endpoints.runs: Updating state for runs: ['6151fcdd593447eead94bcb06af41050', '3d910da7c84e4da99f6c103e5da6d078', 'f5b5a18f976449fa9b4122263a986a65', '8e385864654d4ff8a030480b8f1b9d61', '8e9e412295754ae882cb8d17d4591331', '614cad1f94b94ec8b3a109fbb1ee0ba4', 'de5e2e3b1f3d455c853100012e2c6044', '1ded015d28674761bebf43e9adac4803', 'ca1e2cd675b943ce9b3a7086217322bc', '95986aa50ea545df903e83d5db1b45aa']
2023-10-11 19:37:21,001 2f25f22d4 [WARNING] sematic.scheduling.kubernetes: Got 404 while looking for job stage/sematic-worker-6151fcdd593447eead94bcb06af41050-c3c8d5
2023-10-11 19:37:21,494 2f25f22d4 [INFO] sematic.api.endpoints.runs: Updating run's jobs: [Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-c3c8d5, run_id=6151fcdd593447eead94bcb06af41050, state=Requested, ...), Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-071d9c, run_id=6151fcdd593447eead94bcb06af41050, state=Running, ...)]
2023-10-11 19:37:24,912 c60a36b68 [INFO] sematic.api.endpoints.runs: Updating state for runs: ['6151fcdd593447eead94bcb06af41050', '3d910da7c84e4da99f6c103e5da6d078', 'f5b5a18f976449fa9b4122263a986a65', '8e385864654d4ff8a030480b8f1b9d61', '8e9e412295754ae882cb8d17d4591331', 'de5e2e3b1f3d455c853100012e2c6044', '1ded015d28674761bebf43e9adac4803', 'ca1e2cd675b943ce9b3a7086217322bc', '95986aa50ea545df903e83d5db1b45aa', '7b103613e41e469da4d3efc505b63e2d']
2023-10-11 19:37:25,351 c60a36b68 [WARNING] sematic.scheduling.kubernetes: Got 404 while looking for job stage/sematic-worker-6151fcdd593447eead94bcb06af41050-c3c8d5
2023-10-11 19:37:25,428 c60a36b68 [INFO] sematic.api.endpoints.runs: Updating run's jobs: [Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-c3c8d5, run_id=6151fcdd593447eead94bcb06af41050, state=Requested, ...), Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-071d9c, run_id=6151fcdd593447eead94bcb06af41050, state=Running, ...)]
2023-10-11 19:37:35,574 fba67452f [INFO] sematic.api.endpoints.runs: Graph update, run 6151fcdd593447eead94bcb06af41050 is in state FAILED
2023-10-11 19:37:35,606 fba67452f [INFO] sematic.api.endpoints.runs: Ensuring jobs for 6151fcdd593447eead94bcb06af41050 are stopped FAILED
2023-10-11 19:37:35,616 fba67452f [INFO] sematic.scheduling.kubernetes: No need to cancel Kubernetes job stage/sematic-worker-6151fcdd593447eead94bcb06af41050-c3c8d5, as it no longer exists
2023-10-11 19:37:38,804 f998f20d0 [INFO] sematic.api.server: Request start: 10.42.37.172 python-requests/2.28.2 GET /api/v1/runs/6151fcdd593447eead94bcb06af41050/graph?root=0
2023-10-11 19:37:38,821 f998f20d0 [INFO] sematic.api.server: Request end: 10.42.37.172 python-requests/2.28.2 GET /api/v1/runs/6151fcdd593447eead94bcb06af41050/graph?root=0 200
2023-10-11 19:37:38,838 1b18a4baa [INFO] sematic.api.server: Request start: 10.42.37.172 python-requests/2.28.2 GET /api/v1/runs/6151fcdd593447eead94bcb06af41050
2023-10-11 19:37:38,852 1b18a4baa [INFO] sematic.api.server: Request end: 10.42.37.172 python-requests/2.28.2 GET /api/v1/runs/6151fcdd593447eead94bcb06af41050 200
2023-10-11 19:37:38,867 fe0ff39ae [INFO] sematic.api.server: Request start: 10.42.37.172 python-requests/2.28.2 GET /api/v1/runs/6151fcdd593447eead94bcb06af41050
2023-10-11 19:37:38,889 fe0ff39ae [INFO] sematic.api.server: Request end: 10.42.37.172 python-requests/2.28.2 GET /api/v1/runs/6151fcdd593447eead94bcb06af41050 200
2023-10-11 19:37:38,905 0fd67a1be [INFO] sematic.api.endpoints.runs: Graph update, run 6151fcdd593447eead94bcb06af41050 is in state RETRYING
2023-10-11 19:37:39,961 7ec219fd2 [INFO] sematic.api.endpoints.runs: Graph update, run 6151fcdd593447eead94bcb06af41050 is in state RETRYING
2023-10-11 19:37:40,154 76dac85b6 [INFO] sematic.api.server: Request start: 10.42.37.172 python-requests/2.28.2 POST /api/v1/runs/6151fcdd593447eead94bcb06af41050/schedule
2023-10-11 19:37:40,202 76dac85b6 [INFO] sematic.scheduling.kubernetes: Scheduling job stage/sematic-worker-6151fcdd593447eead94bcb06af41050-04db9b with image 558717131297.dkr.ecr.us-west-2.amazonaws.com/sematic-dev@sha256:77fcae4412a38432835be94343669e22f8d7b9a3698336c0974168f320d4d746
2023-10-11 19:37:40,244 76dac85b6 [INFO] sematic.scheduling.job_scheduler: After schedule, jobs: [Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-c3c8d5, run_id=6151fcdd593447eead94bcb06af41050, state=Deleted, ...), Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-071d9c, run_id=6151fcdd593447eead94bcb06af41050, state=Deleted, ...), Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-04db9b, run_id=6151fcdd593447eead94bcb06af41050, state=Requested, ...)]
2023-10-11 19:37:40,245 76dac85b6 [INFO] sematic.api.endpoints.runs: Scheduled run with job: Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-04db9b, run_id=6151fcdd593447eead94bcb06af41050, state=Requested, ...)
2023-10-11 19:37:40,400 76dac85b6 [INFO] sematic.api.server: Request end: 10.42.37.172 python-requests/2.28.2 POST /api/v1/runs/6151fcdd593447eead94bcb06af41050/schedule 200
2023-10-11 19:37:43,182 34e6d0e80 [INFO] sematic.api.endpoints.runs: Updating state for runs: ['6151fcdd593447eead94bcb06af41050', '8e9e412295754ae882cb8d17d4591331', 'de5e2e3b1f3d455c853100012e2c6044', '1ded015d28674761bebf43e9adac4803', '7b103613e41e469da4d3efc505b63e2d', 'ed45480a0e63444cadbd78aec190a775', '6e57c22e4d25481790018117f12ec493', '49ab4a65a66a4794a3139fca51c2347c', '2f3f1866a86747b78f7d06b082eb98b8', '62cec0334ddc450b8ba543616b057c7c']
2023-10-11 19:37:43,383 34e6d0e80 [INFO] sematic.scheduling.kubernetes: Setting has_started=True for job stage/sematic-worker-6151fcdd593447eead94bcb06af41050-04db9b at timestamp 1697053060.0
Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-04db9b, run_id=6151fcdd593447eead94bcb06af41050, state=Running, ...)
 Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-c3c8d5, run_id=6151fcdd593447eead94bcb06af41050, state=Deleted, ...)
 Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-071d9c, run_id=6151fcdd593447eead94bcb06af41050, state=Deleted, ...)
2023-10-11 19:37:43,405 34e6d0e80 [INFO] sematic.api.endpoints.runs: Updating run's jobs: [Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-04db9b, run_id=6151fcdd593447eead94bcb06af41050, state=Running, ...), Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-c3c8d5, run_id=6151fcdd593447eead94bcb06af41050, state=Deleted, ...), Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-071d9c, run_id=6151fcdd593447eead94bcb06af41050, state=Deleted, ...)]
2023-10-11 19:37:43,405 34e6d0e80 [INFO] sematic.api.endpoints.runs: Updating run 6151fcdd593447eead94bcb06af41050 from FutureState.SCHEDULED to FutureState.FAILED. Message: None
2023-10-11 19:37:44,503 34e6d0e80 [INFO] root: Generated metric sematic.func_success_rate for run 6151fcdd593447eead94bcb06af41050 with value 0
2023-10-11 19:37:44,732 b762b7743 [INFO] sematic.api.server: Request start: 10.42.37.172 python-requests/2.28.2 GET /api/v1/runs/6151fcdd593447eead94bcb06af41050/graph?root=0
2023-10-11 19:37:44,757 b762b7743 [INFO] sematic.api.server: Request end: 10.42.37.172 python-requests/2.28.2 GET /api/v1/runs/6151fcdd593447eead94bcb06af41050/graph?root=0 200
2023-10-11 19:37:44,842 466665ef7 [INFO] sematic.api.server: Request start: 10.42.37.172 python-requests/2.28.2 GET /api/v1/runs/6151fcdd593447eead94bcb06af41050
2023-10-11 19:37:44,859 466665ef7 [INFO] sematic.api.server: Request end: 10.42.37.172 python-requests/2.28.2 GET /api/v1/runs/6151fcdd593447eead94bcb06af41050 200
2023-10-11 19:37:44,879 f07de7d96 [INFO] sematic.api.endpoints.runs: Graph update, run 6151fcdd593447eead94bcb06af41050 is in state RETRYING
2023-10-11 19:37:45,734 a5c88a013 [INFO] sematic.api.server: Request start: 10.42.37.172 python-requests/2.28.2 GET /api/v1/runs/6151fcdd593447eead94bcb06af41050
2023-10-11 19:37:45,747 a5c88a013 [INFO] sematic.api.server: Request end: 10.42.37.172 python-requests/2.28.2 GET /api/v1/runs/6151fcdd593447eead94bcb06af41050 200
2023-10-11 19:37:46,277 e0f4dec63 [INFO] sematic.api.server: Request start: 10.42.37.172 python-requests/2.28.2 GET /api/v1/runs/6151fcdd593447eead94bcb06af41050
2023-10-11 19:37:46,299 e0f4dec63 [INFO] sematic.api.server: Request end: 10.42.37.172 python-requests/2.28.2 GET /api/v1/runs/6151fcdd593447eead94bcb06af41050 200
2023-10-11 19:37:46,311 85588ddf8 [INFO] sematic.api.server: Request start: 10.42.37.172 python-requests/2.28.2 POST /api/v1/runs/6151fcdd593447eead94bcb06af41050/schedule
2023-10-11 19:37:46,389 85588ddf8 [INFO] sematic.scheduling.kubernetes: Scheduling job stage/sematic-worker-6151fcdd593447eead94bcb06af41050-ded644 with image 558717131297.dkr.ecr.us-west-2.amazonaws.com/sematic-dev@sha256:77fcae4412a38432835be94343669e22f8d7b9a3698336c0974168f320d4d746
2023-10-11 19:37:46,420 85588ddf8 [INFO] sematic.scheduling.job_scheduler: After schedule, jobs: [Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-04db9b, run_id=6151fcdd593447eead94bcb06af41050, state=Running, ...), Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-c3c8d5, run_id=6151fcdd593447eead94bcb06af41050, state=Deleted, ...), Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-071d9c, run_id=6151fcdd593447eead94bcb06af41050, state=Deleted, ...), Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-ded644, run_id=6151fcdd593447eead94bcb06af41050, state=Requested, ...)]
2023-10-11 19:37:46,420 85588ddf8 [INFO] sematic.api.endpoints.runs: Scheduled run with job: Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-ded644, run_id=6151fcdd593447eead94bcb06af41050, state=Requested, ...)
2023-10-11 19:37:46,530 85588ddf8 [INFO] sematic.api.server: Request end: 10.42.37.172 python-requests/2.28.2 POST /api/v1/runs/6151fcdd593447eead94bcb06af41050/schedule 200
2023-10-11 19:37:51,054 0923ef941 [INFO] sematic.api.endpoints.runs: Updating state for runs: ['6151fcdd593447eead94bcb06af41050', 'de5e2e3b1f3d455c853100012e2c6044', '1ded015d28674761bebf43e9adac4803', '7b103613e41e469da4d3efc505b63e2d', 'ed45480a0e63444cadbd78aec190a775', '6e57c22e4d25481790018117f12ec493', '49ab4a65a66a4794a3139fca51c2347c', '2f3f1866a86747b78f7d06b082eb98b8', '62cec0334ddc450b8ba543616b057c7c', '6839a7449f9b4c7ca4ff052a397d7a1c']
2023-10-11 19:37:51,227 0923ef941 [INFO] sematic.api.endpoints.runs: Updating run's jobs: [Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-c3c8d5, run_id=6151fcdd593447eead94bcb06af41050, state=Deleted, ...), Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-071d9c, run_id=6151fcdd593447eead94bcb06af41050, state=Deleted, ...), Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-04db9b, run_id=6151fcdd593447eead94bcb06af41050, state=Running, ...), Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-ded644, run_id=6151fcdd593447eead94bcb06af41050, state=Running, ...)]
2023-10-11 19:37:53,571 381608669 [INFO] sematic.api.endpoints.runs: Updating state for runs: ['6151fcdd593447eead94bcb06af41050', 'de5e2e3b1f3d455c853100012e2c6044', '1ded015d28674761bebf43e9adac4803', '7b103613e41e469da4d3efc505b63e2d', 'ed45480a0e63444cadbd78aec190a775', '6e57c22e4d25481790018117f12ec493', '49ab4a65a66a4794a3139fca51c2347c', '2f3f1866a86747b78f7d06b082eb98b8', '62cec0334ddc450b8ba543616b057c7c', '6839a7449f9b4c7ca4ff052a397d7a1c']
2023-10-11 19:37:53,712 381608669 [INFO] sematic.api.endpoints.runs: Updating run's jobs: [Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-c3c8d5, run_id=6151fcdd593447eead94bcb06af41050, state=Deleted, ...), Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-071d9c, run_id=6151fcdd593447eead94bcb06af41050, state=Deleted, ...), Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-04db9b, run_id=6151fcdd593447eead94bcb06af41050, state=Running, ...), Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-ded644, run_id=6151fcdd593447eead94bcb06af41050, state=Running, ...)]
2023-10-11 19:37:59,514 4bbdde44e [INFO] sematic.api.endpoints.runs: Updating state for runs: ['6151fcdd593447eead94bcb06af41050', '1ded015d28674761bebf43e9adac4803', '7b103613e41e469da4d3efc505b63e2d', 'ed45480a0e63444cadbd78aec190a775', '6e57c22e4d25481790018117f12ec493', '49ab4a65a66a4794a3139fca51c2347c', '2f3f1866a86747b78f7d06b082eb98b8', '62cec0334ddc450b8ba543616b057c7c', '6839a7449f9b4c7ca4ff052a397d7a1c', '53db73c5976b4fa49257aae24a8c841d']
2023-10-11 19:37:59,688 4bbdde44e [INFO] sematic.api.endpoints.runs: Updating run's jobs: [Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-c3c8d5, run_id=6151fcdd593447eead94bcb06af41050, state=Deleted, ...), Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-071d9c, run_id=6151fcdd593447eead94bcb06af41050, state=Deleted, ...), Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-04db9b, run_id=6151fcdd593447eead94bcb06af41050, state=Running, ...), Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-ded644, run_id=6151fcdd593447eead94bcb06af41050, state=Running, ...)]
2023-10-11 19:38:01,845 626a293cc [INFO] sematic.api.endpoints.runs: Updating state for runs: ['6151fcdd593447eead94bcb06af41050', '1ded015d28674761bebf43e9adac4803', '7b103613e41e469da4d3efc505b63e2d', 'ed45480a0e63444cadbd78aec190a775', '6e57c22e4d25481790018117f12ec493', '49ab4a65a66a4794a3139fca51c2347c', '2f3f1866a86747b78f7d06b082eb98b8', '62cec0334ddc450b8ba543616b057c7c', '6839a7449f9b4c7ca4ff052a397d7a1c', '53db73c5976b4fa49257aae24a8c841d']
2023-10-11 19:38:01,852 626a293cc [WARNING] sematic.scheduling.job_scheduler: There are still active jobs for run in state FutureState.FAILED (will refresh jobs): [Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-c3c8d5, run_id=6151fcdd593447eead94bcb06af41050, state=Deleted, ...), Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-071d9c, run_id=6151fcdd593447eead94bcb06af41050, state=Deleted, ...), Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-04db9b, run_id=6151fcdd593447eead94bcb06af41050, state=Running, ...), Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-ded644, run_id=6151fcdd593447eead94bcb06af41050, state=Running, ...)]
2023-10-11 19:38:01,875 626a293cc [WARNING] sematic.scheduling.kubernetes: Got 404 while looking for job stage/sematic-worker-6151fcdd593447eead94bcb06af41050-04db9b
2023-10-11 19:38:01,894 626a293cc [WARNING] sematic.scheduling.kubernetes: Got 404 while looking for job stage/sematic-worker-6151fcdd593447eead94bcb06af41050-ded644
2023-10-11 19:38:01,896 626a293cc [WARNING] sematic.scheduling.job_scheduler: After refresh, jobs are: [Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-c3c8d5, run_id=6151fcdd593447eead94bcb06af41050, state=Deleted, ...), Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-071d9c, run_id=6151fcdd593447eead94bcb06af41050, state=Deleted, ...), Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-04db9b, run_id=6151fcdd593447eead94bcb06af41050, state=Deleted, ...), Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-ded644, run_id=6151fcdd593447eead94bcb06af41050, state=Deleted, ...)]
2023-10-11 19:38:01,902 626a293cc [INFO] sematic.api.endpoints.runs: Updating run's jobs: [Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-c3c8d5, run_id=6151fcdd593447eead94bcb06af41050, state=Deleted, ...), Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-071d9c, run_id=6151fcdd593447eead94bcb06af41050, state=Deleted, ...), Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-04db9b, run_id=6151fcdd593447eead94bcb06af41050, state=Deleted, ...), Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-ded644, run_id=6151fcdd593447eead94bcb06af41050, state=Deleted, ...)]
2023-10-11 19:38:03,297 626a293cc [INFO] root: Generated metric sematic.func_success_rate for run 6151fcdd593447eead94bcb06af41050 with value 0
2023-10-11 19:38:04,406 b1150d205 [INFO] sematic.api.endpoints.runs: Graph update, run 6151fcdd593447eead94bcb06af41050 is in state RETRYING
2023-10-11 19:38:04,726 016e81e89 [INFO] sematic.api.server: Request start: 10.42.37.172 python-requests/2.28.2 POST /api/v1/runs/6151fcdd593447eead94bcb06af41050/schedule
2023-10-11 19:38:04,748 016e81e89 [INFO] sematic.scheduling.kubernetes: Scheduling job stage/sematic-worker-6151fcdd593447eead94bcb06af41050-829b0a with image 558717131297.dkr.ecr.us-west-2.amazonaws.com/sematic-dev@sha256:77fcae4412a38432835be94343669e22f8d7b9a3698336c0974168f320d4d746
2023-10-11 19:38:04,798 016e81e89 [INFO] sematic.scheduling.job_scheduler: After schedule, jobs: [Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-c3c8d5, run_id=6151fcdd593447eead94bcb06af41050, state=Deleted, ...), Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-071d9c, run_id=6151fcdd593447eead94bcb06af41050, state=Deleted, ...), Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-04db9b, run_id=6151fcdd593447eead94bcb06af41050, state=Deleted, ...), Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-ded644, run_id=6151fcdd593447eead94bcb06af41050, state=Deleted, ...), Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-829b0a, run_id=6151fcdd593447eead94bcb06af41050, state=Requested, ...)]
2023-10-11 19:38:04,799 016e81e89 [INFO] sematic.api.endpoints.runs: Scheduled run with job: Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-829b0a, run_id=6151fcdd593447eead94bcb06af41050, state=Requested, ...)
2023-10-11 19:38:04,898 016e81e89 [INFO] sematic.api.server: Request end: 10.42.37.172 python-requests/2.28.2 POST /api/v1/runs/6151fcdd593447eead94bcb06af41050/schedule 200
2023-10-11 19:38:05,754 85fe32f09 [INFO] sematic.api.endpoints.runs: Updating state for runs: ['6151fcdd593447eead94bcb06af41050', '1ded015d28674761bebf43e9adac4803', '7b103613e41e469da4d3efc505b63e2d', 'ed45480a0e63444cadbd78aec190a775', '6e57c22e4d25481790018117f12ec493', '49ab4a65a66a4794a3139fca51c2347c', '62cec0334ddc450b8ba543616b057c7c', '6839a7449f9b4c7ca4ff052a397d7a1c', '53db73c5976b4fa49257aae24a8c841d', '70756517773848bbbc556f508bfd1260']
2023-10-11 19:38:05,807 85fe32f09 [INFO] sematic.scheduling.kubernetes: Setting has_started=True for job stage/sematic-worker-6151fcdd593447eead94bcb06af41050-829b0a at timestamp 1697053084.0
Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-829b0a, run_id=6151fcdd593447eead94bcb06af41050, state=Pending, ...)
 Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-c3c8d5, run_id=6151fcdd593447eead94bcb06af41050, state=Deleted, ...)
 Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-071d9c, run_id=6151fcdd593447eead94bcb06af41050, state=Deleted, ...)
 Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-04db9b, run_id=6151fcdd593447eead94bcb06af41050, state=Deleted, ...)
 Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-ded644, run_id=6151fcdd593447eead94bcb06af41050, state=Deleted, ...)
2023-10-11 19:38:05,813 85fe32f09 [INFO] sematic.api.endpoints.runs: Updating run's jobs: [Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-829b0a, run_id=6151fcdd593447eead94bcb06af41050, state=Pending, ...), Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-c3c8d5, run_id=6151fcdd593447eead94bcb06af41050, state=Deleted, ...), Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-071d9c, run_id=6151fcdd593447eead94bcb06af41050, state=Deleted, ...), Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-04db9b, run_id=6151fcdd593447eead94bcb06af41050, state=Deleted, ...), Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-ded644, run_id=6151fcdd593447eead94bcb06af41050, state=Deleted, ...)]
2023-10-11 19:38:05,814 85fe32f09 [INFO] sematic.api.endpoints.runs: Updating run 6151fcdd593447eead94bcb06af41050 from FutureState.SCHEDULED to FutureState.FAILED. Message: None
2023-10-11 19:38:06,829 85fe32f09 [INFO] root: Generated metric sematic.func_success_rate for run 6151fcdd593447eead94bcb06af41050 with value 0
2023-10-11 19:38:06,909 19661568b [INFO] sematic.api.server: Request start: 10.42.37.172 python-requests/2.28.2 GET /api/v1/runs/6151fcdd593447eead94bcb06af41050/graph?root=0
2023-10-11 19:38:06,927 19661568b [INFO] sematic.api.server: Request end: 10.42.37.172 python-requests/2.28.2 GET /api/v1/runs/6151fcdd593447eead94bcb06af41050/graph?root=0 200
2023-10-11 19:38:07,046 39b7fd376 [INFO] sematic.api.server: Request start: 10.42.37.172 python-requests/2.28.2 GET /api/v1/runs/6151fcdd593447eead94bcb06af41050
2023-10-11 19:38:07,060 39b7fd376 [INFO] sematic.api.server: Request end: 10.42.37.172 python-requests/2.28.2 GET /api/v1/runs/6151fcdd593447eead94bcb06af41050 200
2023-10-11 19:38:07,070 f07ae4e0e [INFO] sematic.api.server: Request start: 10.42.37.172 python-requests/2.28.2 GET /api/v1/runs/6151fcdd593447eead94bcb06af41050
2023-10-11 19:38:07,084 f07ae4e0e [INFO] sematic.api.server: Request end: 10.42.37.172 python-requests/2.28.2 GET /api/v1/runs/6151fcdd593447eead94bcb06af41050 200
2023-10-11 19:38:07,254 c83e44a33 [INFO] sematic.api.server: Request start: 10.42.37.172 python-requests/2.28.2 GET /api/v1/runs/6151fcdd593447eead94bcb06af41050
2023-10-11 19:38:07,268 c83e44a33 [INFO] sematic.api.server: Request end: 10.42.37.172 python-requests/2.28.2 GET /api/v1/runs/6151fcdd593447eead94bcb06af41050 200
2023-10-11 19:38:07,311 a4ed490da [INFO] sematic.api.endpoints.runs: Graph update, run 6151fcdd593447eead94bcb06af41050 is in state RETRYING
2023-10-11 19:38:08,982 1c228199c [INFO] sematic.api.server: Request start: 10.42.35.232 Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/116.0.0.0 Safari/537.36 GET /api/v1/runs/6151fcdd593447eead94bcb06af41050/logs?DEBUG=BOOTSTRAP_1&max_lines=2000
2023-10-11 19:38:08,987 1c228199c [INFO] sematic.log_reader: Starting log line loading for: run_id=6151fcdd593447eead94bcb06af41050, forward_cursor_token=None, reverse_cursor_token=None, max_lines=2000, filter_strings=[], reverse=False
2023-10-11 19:38:09,266 1c228199c [INFO] sematic.api.server: Request end: 10.42.35.232 Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/116.0.0.0 Safari/537.36 GET /api/v1/runs/6151fcdd593447eead94bcb06af41050/logs?DEBUG=BOOTSTRAP_1&max_lines=2000 200
2023-10-11 19:38:10,940 db7e7bf9e [INFO] sematic.api.server: Request start: 10.42.37.172 python-requests/2.28.2 GET /api/v1/runs/6151fcdd593447eead94bcb06af41050/graph?root=0
2023-10-11 19:38:10,957 db7e7bf9e [INFO] sematic.api.server: Request end: 10.42.37.172 python-requests/2.28.2 GET /api/v1/runs/6151fcdd593447eead94bcb06af41050/graph?root=0 200
2023-10-11 19:38:10,989 a55f08c5d [INFO] sematic.api.server: Request start: 10.42.37.172 python-requests/2.28.2 GET /api/v1/runs/6151fcdd593447eead94bcb06af41050
2023-10-11 19:38:11,002 a55f08c5d [INFO] sematic.api.server: Request end: 10.42.37.172 python-requests/2.28.2 GET /api/v1/runs/6151fcdd593447eead94bcb06af41050 200
2023-10-11 19:38:12,436 15fc423be [INFO] sematic.api.server: Request start: 10.42.37.172 python-requests/2.28.2 GET /api/v1/runs/6151fcdd593447eead94bcb06af41050
2023-10-11 19:38:12,450 15fc423be [INFO] sematic.api.server: Request end: 10.42.37.172 python-requests/2.28.2 GET /api/v1/runs/6151fcdd593447eead94bcb06af41050 200
2023-10-11 19:38:12,489 35afcd65a [INFO] sematic.api.endpoints.runs: Graph update, run 6151fcdd593447eead94bcb06af41050 is in state RETRYING
2023-10-11 19:38:12,730 0d349680a [INFO] sematic.api.server: Request start: 10.42.37.172 python-requests/2.28.2 GET /api/v1/runs/6151fcdd593447eead94bcb06af41050
2023-10-11 19:38:12,796 0d349680a [INFO] sematic.api.server: Request end: 10.42.37.172 python-requests/2.28.2 GET /api/v1/runs/6151fcdd593447eead94bcb06af41050 200
2023-10-11 19:38:14,264 fd5a6fdd7 [INFO] sematic.api.endpoints.runs: Updating state for runs: ['6151fcdd593447eead94bcb06af41050', '7b103613e41e469da4d3efc505b63e2d', 'ed45480a0e63444cadbd78aec190a775', '6e57c22e4d25481790018117f12ec493', '49ab4a65a66a4794a3139fca51c2347c', '62cec0334ddc450b8ba543616b057c7c', '6839a7449f9b4c7ca4ff052a397d7a1c', '53db73c5976b4fa49257aae24a8c841d', '70756517773848bbbc556f508bfd1260', '48475358cf9e4fbfb198e8cba647e06c']
2023-10-11 19:38:14,540 fd5a6fdd7 [INFO] sematic.scheduling.kubernetes: Setting has_started=True for job stage/sematic-worker-6151fcdd593447eead94bcb06af41050-ee3fc6 at timestamp 1697053093.0
Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-829b0a, run_id=6151fcdd593447eead94bcb06af41050, state=Running, ...)
 Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-7bc5f5, run_id=6151fcdd593447eead94bcb06af41050, state=Running, ...)
 Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-ee3fc6, run_id=6151fcdd593447eead94bcb06af41050, state=Pending, ...)
 Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-c3c8d5, run_id=6151fcdd593447eead94bcb06af41050, state=Deleted, ...)
 Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-071d9c, run_id=6151fcdd593447eead94bcb06af41050, state=Deleted, ...)
 Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-04db9b, run_id=6151fcdd593447eead94bcb06af41050, state=Deleted, ...)
 Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-ded644, run_id=6151fcdd593447eead94bcb06af41050, state=Deleted, ...)
2023-10-11 19:38:14,603 fd5a6fdd7 [INFO] sematic.api.endpoints.runs: Updating run's jobs: [Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-829b0a, run_id=6151fcdd593447eead94bcb06af41050, state=Running, ...), Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-7bc5f5, run_id=6151fcdd593447eead94bcb06af41050, state=Running, ...), Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-ee3fc6, run_id=6151fcdd593447eead94bcb06af41050, state=Pending, ...), Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-c3c8d5, run_id=6151fcdd593447eead94bcb06af41050, state=Deleted, ...), Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-071d9c, run_id=6151fcdd593447eead94bcb06af41050, state=Deleted, ...), Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-04db9b, run_id=6151fcdd593447eead94bcb06af41050, state=Deleted, ...), Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-ded644, run_id=6151fcdd593447eead94bcb06af41050, state=Deleted, ...)]
2023-10-11 19:38:14,604 fd5a6fdd7 [INFO] sematic.api.endpoints.runs: Updating run 6151fcdd593447eead94bcb06af41050 from FutureState.SCHEDULED to FutureState.FAILED. Message: None
2023-10-11 19:38:25,636 fd5a6fdd7 [INFO] sematic.api.endpoints.runs: Updating state for runs: ['6151fcdd593447eead94bcb06af41050', '7b103613e41e469da4d3efc505b63e2d', 'ed45480a0e63444cadbd78aec190a775', '6e57c22e4d25481790018117f12ec493', '49ab4a65a66a4794a3139fca51c2347c', '62cec0334ddc450b8ba543616b057c7c', '6839a7449f9b4c7ca4ff052a397d7a1c', '53db73c5976b4fa49257aae24a8c841d', '70756517773848bbbc556f508bfd1260', '48475358cf9e4fbfb198e8cba647e06c']
2023-10-11 19:38:25,644 fd5a6fdd7 [WARNING] sematic.scheduling.job_scheduler: There are still active jobs for run in state FutureState.FAILED (will refresh jobs): [Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-829b0a, run_id=6151fcdd593447eead94bcb06af41050, state=Running, ...), Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-7bc5f5, run_id=6151fcdd593447eead94bcb06af41050, state=Running, ...), Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-ee3fc6, run_id=6151fcdd593447eead94bcb06af41050, state=Pending, ...), Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-c3c8d5, run_id=6151fcdd593447eead94bcb06af41050, state=Deleted, ...), Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-071d9c, run_id=6151fcdd593447eead94bcb06af41050, state=Deleted, ...), Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-04db9b, run_id=6151fcdd593447eead94bcb06af41050, state=Deleted, ...), Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-ded644, run_id=6151fcdd593447eead94bcb06af41050, state=Deleted, ...)]
2023-10-11 19:38:25,949 fd5a6fdd7 [WARNING] sematic.scheduling.job_scheduler: After refresh, jobs are: [Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-829b0a, run_id=6151fcdd593447eead94bcb06af41050, state=Running, ...), Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-7bc5f5, run_id=6151fcdd593447eead94bcb06af41050, state=Running, ...), Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-ee3fc6, run_id=6151fcdd593447eead94bcb06af41050, state=Running, ...), Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-c3c8d5, run_id=6151fcdd593447eead94bcb06af41050, state=Deleted, ...), Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-071d9c, run_id=6151fcdd593447eead94bcb06af41050, state=Deleted, ...), Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-04db9b, run_id=6151fcdd593447eead94bcb06af41050, state=Deleted, ...), Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-ded644, run_id=6151fcdd593447eead94bcb06af41050, state=Deleted, ...)]
2023-10-11 19:38:25,963 fd5a6fdd7 [INFO] sematic.api.endpoints.runs: Updating run's jobs: [Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-829b0a, run_id=6151fcdd593447eead94bcb06af41050, state=Running, ...), Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-7bc5f5, run_id=6151fcdd593447eead94bcb06af41050, state=Running, ...), Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-ee3fc6, run_id=6151fcdd593447eead94bcb06af41050, state=Running, ...), Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-c3c8d5, run_id=6151fcdd593447eead94bcb06af41050, state=Deleted, ...), Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-071d9c, run_id=6151fcdd593447eead94bcb06af41050, state=Deleted, ...), Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-04db9b, run_id=6151fcdd593447eead94bcb06af41050, state=Deleted, ...), Job(name=sematic-worker-6151fcdd593447eead94bcb06af41050-ded644, run_id=6151fcdd593447eead94bcb06af41050, state=Deleted, ...)]
2023-10-11 19:38:26,935 fd5a6fdd7 [INFO] root: Generated metric sematic.func_success_rate for run 6151fcdd593447eead94bcb06af41050 with value 0
2023-10-11 19:38:27,009 985870ed9 [INFO] sematic.api.server: Request start: 10.42.37.172 python-requests/2.28.2 GET /api/v1/runs/6151fcdd593447eead94bcb06af41050/graph?root=0
2023-10-11 19:38:27,101 985870ed9 [INFO] sematic.api.server: Request end: 10.42.37.172 python-requests/2.28.2 GET /api/v1/runs/6151fcdd593447eead94bcb06af41050/graph?root=0 200
2023-10-11 19:38:27,909 d8b6c57a8 [INFO] sematic.api.server: Request start: 10.42.40.76 python-requests/2.28.2 GET /api/v1/storage/logs/v2/run_id/6151fcdd593447eead94bcb06af41050/worker/1697053106416.log/location?origin=http://sematic-server
2023-10-11 19:38:27,915 d8b6c57a8 [INFO] sematic.plugins.storage.s3_storage: Generating S3 presigned url for logs/v2/run_id/6151fcdd593447eead94bcb06af41050/worker/1697053106416.log
2023-10-11 19:38:27,988 d8b6c57a8 [INFO] sematic.api.server: Request end: 10.42.40.76 python-requests/2.28.2 GET /api/v1/storage/logs/v2/run_id/6151fcdd593447eead94bcb06af41050/worker/1697053106416.log/location?origin=http://sematic-server 200
2023-10-11 19:38:28,042 5a504586a [INFO] sematic.api.server: Request start: 10.42.37.172 python-requests/2.28.2 GET /api/v1/runs/6151fcdd593447eead94bcb06af41050/graph?root=0
2023-10-11 19:38:28,090 5a504586a [INFO] sematic.api.server: Request end: 10.42.37.172 python-requests/2.28.2 GET /api/v1/runs/6151fcdd593447eead94bcb06af41050/graph?root=0 200
2023-10-11 19:38:28,269 104ba2ee2 [INFO] sematic.api.server: Request start: 10.42.37.172 python-requests/2.28.2 GET /api/v1/runs/6151fcdd593447eead94bcb06af41050
2023-10-11 19:38:28,284 104ba2ee2 [INFO] sematic.api.server: Request end: 10.42.37.172 python-requests/2.28.2 GET /api/v1/runs/6151fcdd593447eead94bcb06af41050 200
2023-10-11 19:38:43,118 66d3f5988 [INFO] sematic.api.server: Request start: 10.42.42.181 python-requests/2.28.2 GET /api/v1/runs/6151fcdd593447eead94bcb06af41050/graph?root=0
2023-10-11 19:38:43,135 66d3f5988 [INFO] sematic.api.server: Request end: 10.42.42.181 python-requests/2.28.2 GET /api/v1/runs/6151fcdd593447eead94bcb06af41050/graph?root=0 200
2023-10-11 19:38:54,611 eff17460f [INFO] sematic.api.server: Request start: 10.42.37.144 python-requests/2.28.2 GET /api/v1/storage/logs/v2/run_id/6151fcdd593447eead94bcb06af41050/worker/1697053134572.log/location?origin=http://sematic-server
2023-10-11 19:38:54,616 eff17460f [INFO] sematic.plugins.storage.s3_storage: Generating S3 presigned url for logs/v2/run_id/6151fcdd593447eead94bcb06af41050/worker/1697053134572.log
2023-10-11 19:38:54,631 eff17460f [INFO] sematic.api.server: Request end: 10.42.37.144 python-requests/2.28.2 GET /api/v1/storage/logs/v2/run_id/6151fcdd593447eead94bcb06af41050/worker/1697053134572.log/location?origin=http://sematic-server 200
2023-10-11 19:38:55,567 81ac4f9a5 [INFO] sematic.api.server: Request start: 10.42.37.144 python-requests/2.28.2 GET /api/v1/storage/logs/v2/run_id/6151fcdd593447eead94bcb06af41050/worker/1697053135551.log/location?origin=http://sematic-server
2023-10-11 19:38:55,574 81ac4f9a5 [INFO] sematic.plugins.storage.s3_storage: Generating S3 presigned url for logs/v2/run_id/6151fcdd593447eead94bcb06af41050/worker/1697053135551.log
2023-10-11 19:38:55,595 81ac4f9a5 [INFO] sematic.api.server: Request end: 10.42.37.144 python-requests/2.28.2 GET /api/v1/storage/logs/v2/run_id/6151fcdd593447eead94bcb06af41050/worker/1697053135551.log/location?origin=http://sematic-server 200
2023-10-11 19:39:35,902 1fe911d0e [INFO] sematic.api.server: Request start: 10.42.35.232 Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/116.0.0.0 Safari/537.36 GET /api/v1/runs/6151fcdd593447eead94bcb06af41050/logs?DEBUG=BOOTSTRAP_1&max_lines=2000
2023-10-11 19:39:35,907 1fe911d0e [INFO] sematic.log_reader: Starting log line loading for: run_id=6151fcdd593447eead94bcb06af41050, forward_cursor_token=None, reverse_cursor_token=None, max_lines=2000, filter_strings=[], reverse=False
2023-10-11 19:39:36,255 1fe911d0e [INFO] sematic.api.server: Request end: 10.42.35.232 Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/116.0.0.0 Safari/537.36 GET /api/v1/runs/6151fcdd593447eead94bcb06af41050/logs?DEBUG=BOOTSTRAP_1&max_lines=2000 200
2023-10-11 19:39:42,486 430cbf95 [INFO] sematic.api.server: Request start: 10.42.35.232 Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/116.0.0.0 Safari/537.36 GET /api/v1/runs/6151fcdd593447eead94bcb06af41050/logs?DEBUG=BOOTSTRAP_1&max_lines=2000
2023-10-11 19:39:42,490 430cbf95 [INFO] sematic.log_reader: Starting log line loading for: run_id=6151fcdd593447eead94bcb06af41050, forward_cursor_token=None, reverse_cursor_token=None, max_lines=2000, filter_strings=[], reverse=False
2023-10-11 19:39:43,086 430cbf95 [INFO] sematic.api.server: Request end: 10.42.35.232 Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/116.0.0.0 Safari/537.36 GET /api/v1/runs/6151fcdd593447eead94bcb06af41050/logs?DEBUG=BOOTSTRAP_1&max_lines=2000 200
2023-10-11 19:40:58,906 d5e848285 [INFO] sematic.api.server: Request start: 10.42.5.39 Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/116.0.0.0 Safari/537.36 GET /api/v1/runs/6151fcdd593447eead94bcb06af41050/logs?DEBUG=BOOTSTRAP_1&max_lines=2000
2023-10-11 19:40:58,911 d5e848285 [INFO] sematic.log_reader: Starting log line loading for: run_id=6151fcdd593447eead94bcb06af41050, forward_cursor_token=None, reverse_cursor_token=None, max_lines=2000, filter_strings=[], reverse=False
2023-10-11 19:40:59,260 d5e848285 [INFO] sematic.api.server: Request end: 10.42.5.39 Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/116.0.0.0 Safari/537.36 GET /api/v1/runs/6151fcdd593447eead94bcb06af41050/logs?DEBUG=BOOTSTRAP_1&max_lines=2000 200
@tscurtu tscurtu added bug Something isn't working ui UI related work observability db labels Oct 11, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
bug Something isn't working db observability ui UI related work
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
1 participant
@tscurtu