Issue with Canceling a job

[johnml1135]

Sometimes a job is told to cancel from the API, but it doesn't cancel.

• slow cancel - "/api/v1/translation/engines/66c646da2c3a820e41266b83/builds/6707ebe5f324bff3134d715e",

[2024-10-10 15:15:59] info: System.Net.Http.HttpClient.machine_api.LogicalHandler[100]
      Start processing HTTP request POST https://qa.serval-api.org/api/v1/translation/engines/66c646da2c3a820e41266b83/current-build/cancel
[2024-10-10 15:15:59] info: System.Net.Http.HttpClient.machine_api.ClientHandler[100]
      Sending HTTP request POST https://qa.serval-api.org/api/v1/translation/engines/66c646da2c3a820e41266b83/current-build/cancel
[2024-10-10 15:15:59] info: System.Net.Http.HttpClient.machine_api.ClientHandler[101]
      Received HTTP response headers after 373.1305ms - 204
[2024-10-10 15:15:59] info: System.Net.Http.HttpClient.machine_api.LogicalHandler[101]
      End processing HTTP request after 373.44ms - 204
[2024-10-10 15:15:59] info: System.Net.Http.HttpClient.machine_api.LogicalHandler[100]
      Start processing HTTP request GET https://qa.serval-api.org/api/v1/translation/engines/66c646da2c3a820e41266b83/current-build
[2024-10-10 15:15:59] info: System.Net.Http.HttpClient.machine_api.ClientHandler[100]
      Sending HTTP request GET https://qa.serval-api.org/api/v1/translation/engines/66c646da2c3a820e41266b83/current-build
[2024-10-10 15:15:59] info: System.Net.Http.HttpClient.machine_api.ClientHandler[101]
      Received HTTP response headers after 194.7167ms - 200
[2024-10-10 15:15:59] info: System.Net.Http.HttpClient.machine_api.LogicalHandler[101]
      End processing HTTP request after 195.1597ms - 200
[2024-10-10 15:15:59] info: System.Net.Http.HttpClient.machine_api.LogicalHandler[100]
      Start processing HTTP request GET https://qa.serval-api.org/api/v1/translation/engines/66c646da2c3a820e41266b83/current-build
[2024-10-10 15:15:59] info: System.Net.Http.HttpClient.machine_api.ClientHandler[100]
      Sending HTTP request GET https://qa.serval-api.org/api/v1/translation/engines/66c646da2c3a820e41266b83/current-build
[2024-10-10 15:15:59] info: System.Net.Http.HttpClient.machine_api.ClientHandler[101]
      Received HTTP response headers after 195.3227ms - 200
[2024-10-10 15:15:59] info: System.Net.Http.HttpClient.machine_api.LogicalHandler[101]
      End processing HTTP request after 195.6328ms - 200

[ddaspit]

Is this an NMT or SMT engine?

[johnml1135]

• Serval instance: https://qa.serval-api.org/
• Engine 66c646da2c3a820e41266b83
• Type Nmt
• Build 6707ebe5f324bff3134d715e.
• Languages - Spanish and English
• ClearML job: https://app.sil.hosted.allegro.ai/projects/*/experiments/2c3c25d5c18c4f91ae58750f4cea2e4c/execution?columns=selected&columns=type&columns=name&columns=tags&columns=status&columns=project.name&columns=users&columns=started&columns=last_update&columns=last_iteration&columns=parent.name&order=-last_update&filter=&deep=true&q=6707ebe5f324bff3134d715e
• It was a job built to test out the learning rate
• Started (as per ClearML): Oct 10 2024 10:59
• Ended (as per ClearML): Oct 10 2024 14:03
• Helpful query: https://rancher.languagetechnology.org/k8s/clusters/c-f947m/api/v1/namespaces/cattle-monitoring-system/services/http:rancher-monitoring-grafana:80/proxy/explore?orgId=16&left=%7B%22datasource%22:%22efnG1asVz%22,%22queries%22:%5B%7B%22refId%22:%22A%22,%22editorMode%22:%22code%22,%22expr%22:%22%7Bnamespace%3D%5C%22serval%5C%22%7D%20%21%3D%20%5C%22Serval.Machine.Shared.Services.ClearML%5C%22%22,%22queryType%22:%22range%22%7D%5D,%22range%22:%7B%22from%22:%221728532800000%22,%22to%22:%221728619199000%22%7D%7D
• Log - getting a lot of pretranslations: 2024-10-10 10:32:49
  {"log":"info: Serval.Translation.Controllers.TranslationEnginesController[0]\n Returning 1795 pretranslations for engine 66c646da2c3a820e41266b83, corpus 66c646dd2c3a820e41266b86, and query GEN\n","stream":"stdout","time":"2024-10-10T14:32:22.301438723Z","type":"info","source":"Serval.Translation.Controllers.TranslationEnginesController"}
• Should have started build, but no logs showing that Serval started the job (though obviously it did)
• Cancellation requests started around 2024-10-10 11:01:40 - but "model was not building"
• Build

{
    "id": "6707ebe5f324bff3134d715e",
    "url": "/api/v1/translation/engines/66c646da2c3a820e41266b83/builds/6707ebe5f324bff3134d715e",
    "revision": 108,
    "engine": {
      "id": "66c646da2c3a820e41266b83",
      "url": "/api/v1/translation/engines/66c646da2c3a820e41266b83"
    },
    "trainOn": [
      {
        "corpus": {
          "id": "66f3006ff324bff3134ae5eb",
          "url": "/api/v1/translation/engines/66c646da2c3a820e41266b83/corpora/66f3006ff324bff3134ae5eb"
        },
        "scriptureRange": "MAT;MRK;LUK;JHN;ACT;ROM;1CO;2CO;GAL;EPH;PHP;COL;1TH;2TH;1TI;2TI;TIT;PHM;HEB;JAS;1PE;2PE;1JN;2JN;3JN;JUD;REV"
      }
    ],
    "pretranslate": [
      {
        "corpus": {
          "id": "66c646dd2c3a820e41266b86",
          "url": "/api/v1/translation/engines/66c646da2c3a820e41266b83/corpora/66c646dd2c3a820e41266b86"
        },
        "scriptureRange": "GEN"
      }
    ],
    "step": 5000,
    "percentCompleted": 1,
    "message": "Canceled",
    "queueDepth": 0,
    "state": "Canceled",
    "dateFinished": "2024-10-10T18:03:16.816Z",
    "options": {
      "train_params": {
        "warmup_steps": 1000,
        "learning_rate": 0.0002,
        "lr_scheduler_type": "cosine",
        "max_steps": 5000
      }
    }
  }

[johnml1135]

I don't quite know what happened.

• Completed: 2024-09-27T17:15:30.651Z,
• Completed: 2024-10-08T15:38:17.99Z,
• 6707ebe5f324bff3134d715e - Canceled: 2024-10-10T18:03:16.816Z -> ClearML - completed
• 67093902f324bff3134d80d8 - Canceled: 2024-10-11T15:18:33.362Z, -> ClearML - aborted
• 670ed5d4694f517c27c639b8 - Completed: 2024-10-16T04:08:01.022Z, ClearML - completed.
  Loki logs only go back a week, but only the 10-16 build shows up in the Loki logs (the 10-11 and 10-10 one should as well). The 10-11 one correctly shows in ClearML as cancelled (aborted), but the 10-10 one completed. What is going on?