-
Bug
-
Resolution: Done
-
Critical
-
quay-v3.6.6
In certain situations where there are many mirroring workers present, the mirror worker will sometimes, even after a successful sync, revert tags back. In the repo mirror logs we see the following entry:
{"log": "repomirrorworker stdout | 2022-06-13 13:46:59,275 [64] [DEBUG] [peewee] ('INSERT INTO `logentry3` (`kind_id`, `account_id`, `performer_id`, `repository_id`, `datetime`, `ip`, `metadata_json`) VALUES (%s, %s, %s, %s, %s,
%s, %s)', [71, 2071, None, 17918, datetime.datetime(2022, 6, 13, 13, 46, 59, 272248), None, '{\"verb\": \"finish\", \"namespace\": \"library\", \"repo\": \"python\", \"message\": \"Source \\'docker://docker.io/library/python:late
st\\' successful sync\", \"tag\": \"latest\", \"tags\": null, \"stdout\": \"Copying 10 of 10 images...
...
which indicates that the mirorring for the tag was successful. However, immediately afterwards we see the following log as well:
"log": "repomirrorworker stdout | 2022-06-13 13:46:59,351 [64] [DEBUG] [peewee] ('INSERT INTO `logentry3` (`kind_id`, `account_id`, `performer_id`, `repository_id`, `datetime`, `ip`, `metadata_json`) VALUES (%s, %s, %s, %s, %s, %s, %s)', [68, 2071, None, 17918, datetime.datetime(2022, 6, 13, 13, 46, 59, 349068), None, '{\"verb\": \"lost\", \"namespace\": \"library\", \"repo\": \"python\", \"message\": \"\\'docker.io/library/python\\' with tag pattern \\ 'latest,3.[6789].?,3.[6789].??,3.??.?,3.??.??,3.??.??-*,3.??.?-*,3-*,3.[6789].?-*,3.[6789].??-*,3.6-*\\'\", \"tag\": null, \"tags\": null, \"stdout\": null, \"stderr\": null}'])\n", "stream": "stdout", "time": "2022-06-13T13:46:59.352337484Z"}
The verb lost is described here:
It seems that the repo mirror worker, because the job was lost, thinks that the mirroring operation failed and proceeds to revert the tag on which it failed:
# cat repomirror-log.txt | grep -i 2630422 {"log": "repomirrorworker stdout | 2022-06-13 13:47:00,121 [64] [DEBUG] [peewee] ('SELECT `t1`.`id`, `t1`.`repository_id`, `t1`.`tag_id`, `t1`.`repository_tag_id`, `t2`.`id`, `t2`.`name`, `t2`.`image_id`, `t2`.`repository_id`, `t2`.`lifetime_start_ts`, `t2`.`lifetime_end_ts`, `t2`.`hidden`, `t2`.`reversion` FROM `tagtorepositorytag` AS `t1` INNER JOIN `repositorytag` AS `t2` ON (`t1`.`repository_tag_id` = `t2`.`id`) WHERE (`t1`.`tag_id` = %s) LIMIT %s OFFSET %s', [2630422, 1, 0])\n", "stream": "stdout", "time": "2022-06-13T13:47:00.121598851Z"} {"log": "repomirrorworker stdout | 2022-06-13 13:47:00,118 [64] [DEBUG] [peewee] ('UPDATE `tag` SET `lifetime_end_ms` = %s WHERE ((`tag`.`id` = %s) AND (`tag`.`lifetime_end_ms` IS %s))', [1655128020118, 2630422, None])\n", "stream": "stdout", "time": "2022-06-13T13:47:00.118688345Z"} {"log": "repomirrorworker stdout | 2022-06-13 13:47:00,114 [64] [DEBUG] [workers.repomirrorworker] Repo mirroring rollback delete tag '<Tag> #2630422'\n", "stream": "stdout", "time": "2022-06-13T13:47:00.11508844Z"} {"log": "repomirrorworker stdout | 2022-06-13 13:47:00,114 [64] [DEBUG] [workers.repomirrorworker] Repo mirroring rollback tag '<Tag> #2630422'\n", "stream": "stdout", "time": "2022-06-13T13:47:00.115062863Z"}
The end result is that all tags defined by the regex were copied over to local Quay but not the latest tag. I wasn't able to reproduce this problem, the client is running 10 repo mirroring containers so it's possible that the number of repo-mirror pods influences its behaviour.
Can you please check?
- mentioned on
