Wrong progress on channel update

ivanistheone commented 4 years ago

Observed behavior

While trying to update ASB channel on kolibridemo, I went through the wizard that showed me the version "changelog" then when I started update task I saw it jump to 100% progress right away:

Expected behavior

Progress bar steadily growing from 0 to 100%.

User-facing consequences

Confusing since UI says 100% but task is still running.

Errors and logs

From the netowrk tab, I saw polling of the task api url with the following response:

[
  {
    "status": "COMPLETED",
    "exception": "None",
    "cancellable": false,
    "traceback": "",
    "percentage": 0,
    "id": "0a0a6712ad624b7ea563a220e4d3a16e"
  },
  {
    "status": "COMPLETED",
    "exception": "None",
    "cancellable": false,
    "traceback": "",
    "percentage": 0,
    "id": "ec68f2bf7e354406a20f4d981ae36945"
  },
  {
    "status": "RUNNING",
    "exception": "None",
    "started_by_username": "admin",
    "new_version": 24,
    "node_ids": [
      "529175b4246e525e8d709c66e5c4982c",
      "a2cd0fded0245abba2075b4ec226fd7d",
      "a6dbf2bf66155fc0afe256a891ad001d",
      "a1f99346ef2854368f28085ca04e17be",
      ">>>>>>  6000+ more rows go here (redacted for brevity..... LOTS A JSON) <<<<<<<<<<<<<<<<<<<<",
      "9e8b227b665c50ad9ec95521654e41c5",
      "cc0695941b3654468fefdbdb396d07ae",
      "b5a13b940a5e5407a32901875a548917"
    ],
    "cancellable": true,
    "traceback": "",
    "baseurl": "https://studio.learningequality.org",
    "exclude_node_ids": null,
    "started_by": "8b4c6655776a9ab94f560c5748803a93",
    "channel_id": "f9d3e0e46ea25789bbed672ff6a399ed",
    "percentage": 1,
    "peer_id": null,
    "type": "UPDATECHANNEL",
    "id": "2927be07345d44119e67bdebf666e1c9",
    "channel_name": "African Storybook"
  }
]

I'm not sure what the COMPLETED tasks are, but the UPDATECHANNEL channel task percentage shouldn't be 1.0.

Also the "node_ids" was a huge list of 6000+ rows, which seems weird to be including in the status progress polling, but did not cause any noticeable slowdown. It's just text.

Steps to reproduce

Given Kolibri with channel vN installed
Publish v(N+1) of the channel on Studio with changed files
Go through the Kolibri update channel wizard (should result in similar list of node_ids to update for all the changed files)

Context

https://kolibridemo.learningequality.org/
Kolibri 0.13.1
Chrome

pcenov commented 3 years ago

@rtibbles I'm able to replicate this issue in v0.14.7-rc1. The percentage bar always goes right to 100% and I can see in the Network tab multiple api calls with response: [{"status":"COMPLETED","exception":"None","traceback":"","percentage":0,"id":"d0d7038858a74f4d8c0a069fc0a26001","cancellable":false,"clearable":true},{"status":"COMPLETED","exception":"None","traceback":"","percentage":1.0,"id":"2f10550b8a914b27b02256380115fc60","cancellable":true,"clearable":true,"channel_id":"171ade4c27294b03a1fbff97d3079e15","channel_name":"Studio Test Channel 4","exclude_node_ids":null,"node_ids":null,"started_by":"1db2f06922620cab9f41d05188c14431","started_by_username":"pcenov","baseurl":"https://studio.learningequality.org","peer_id":null,"type":"UPDATECHANNEL","new_version":19,"database_ready":true,"file_size":50411,"total_resources":2,"transferred_file_size":50411,"transferred_resources":2}]

rtibbles commented 3 years ago

Thanks @pcenov!

rtibbles commented 3 years ago

This issue is caused by sequential updates to the job object within the task. When job.update_progress is called here: https://github.com/learningequality/kolibri/blob/develop/kolibri/core/tasks/api.py#L1185 the subsequent calls to save_metadata inadvertently overwrite the progress data, because it is never set on the job itself.

To fix this, the update_progress method https://github.com/learningequality/kolibri/blob/44bf1ed3591321f4b7ef7c4e5c6ceda8c01db7ae/kolibri/core/tasks/job.py#L126 should also set progress and total_progress onto self, as well as putting it into the storage with the method.

learningequality / kolibri