#8922 koji not regenerating buildroots in a timely manner
Closed: Fixed by kevin. Opened by ignatenkobrain.

Hello,

The koji builds are picked up by noticeably slower than usual. I am not sure what is happening, but probably some kojid processes got stuck?

Also kojira seems to not regenerate f33-build repository, so I have to call regen-repo myself at least 15 times by now.


We have been having issues with the ppc64le builders of late OOM killing kojid. I restarted some of those this morning. Does it seem better now?

No idea on the f33-build... I see kojira now making repos as expected. ;(

So, it seems like to me was back to normal after that yesterday...

Can you confirm? or do we need to look further?

Metadata Update from @kevin:
- Issue priority set to: Waiting on Reporter (was: Needs Review)
- Issue tagged with: koji

Builders are ok now, but kojira is quite slow....

By slow I mean that I am already waiting for 1hr for build to appear in f33-build. I am not going to wait more, so I will kick regen-repo right away now.

https://koji.fedoraproject.org/koji/taskinfo?taskID=44700199

yeah, it does appear its being slow, but we have no time to investigate. Especially when we are moving to new insfrastructure in about 3 weeks... if this persists there we can devote more time to debugging it and if it's gone we won't have to worry about it.

@kevin I think this is happening basically every second day or so. I know that @churchyard has had very bad experience regarding this in side tags so that I had to regenerate repos for him multiple times. Also he said that python3.9 will be very painful if there is not going to be working kojira.

I guess meantime we can just grant him permissions, but I think we really need to investigate this problem and make a fix.

Things are going to be slow and painful for the next 6-9 weeks.. people are going to have to be patient. We have absolutely no spare cycles until this move is over.

So... I watched kojira this morning while the openshift playbook was running. It seemed not super great, but for example f33-python regenerated in about 10min.

Tag: f33-python [22287]
Arches: armv7hl i686 x86_64 aarch64 ppc64le s390x
Groups: appliance-build, build, livecd-build, livemedia-build, srpm-build
Tag options:
Targets that build into this tag:
  f33-python (f33-python, repo#1530414: 2020-05-20 17:54:46.014411)
This tag is a buildroot for one or more targets
Current repo: repo#1530414: 2020-05-20 17:54:46.014411
Targets that build from this tag:
  f33-python
Inheritance:
  0    .... f33-build [18677]

Then a new f33 build finished:

1509130 vagrant-2.2.9-2.fc33 pvalena 2020-05-20 18:00:06

Tag: f33-python [22287]
Arches: armv7hl i686 x86_64 aarch64 ppc64le s390x
Groups: appliance-build, build, livecd-build, livemedia-build, srpm-build
Tag options:
Targets that build into this tag:
  f33-python (f33-python, repo#1530477: 2020-05-20 18:09:39.768460)
This tag is a buildroot for one or more targets
Current repo: repo#1530477: 2020-05-20 18:09:39.768460
Targets that build from this tag:
  f33-python
Inheritance:
  0    .... f33-build [18677]

So, that seems pretty normal. Can you and @churchyard gather information for when you are seeing things slow? ie, the taginfo on what repo it's using, when a build landed and when it finally regenned?

Perhaps this is only affecting somehow the side tags that are not manually made?

I will provide the data once the builds start

first two builds waited within minutes, will report back if I get any difficulties.

There are some bumps:

Successfully waited 7:03 for python3.9-3.9.0~b1-2.fc33 to appear in the f33-python repo
Successfully waited 7:42 for python-setuptools-46.4.0-2.fc33~bootstrap to appear in the f33-python repo
Successfully waited 8:33 for python-wheel-0.33.6-4.fc33~bootstrap to appear in the f33-python repo
Successfully waited 7:57 for python-pip-20.1.1-2.fc33 to appear in the f33-python repo
Successfully waited 11:20 for python-setuptools-46.4.0-3.fc33 to appear in the f33-python repo
Successfully waited 8:57 for pyparsing-2.4.7-2.fc33 to appear in the f33-python repo
Successfully waited 8:58 for python3.9-3.9.0~b1-3.fc33 to appear in the f33-python repo
Here I saw a kojira newRepo task but none of the builds were in it, so had to restart (the 2 builds were in parallel):
    Successfully waited 17:31 for dblatex-0.3.11-5.fc33 to appear in the f33-python repo
    Successfully waited 18:16 for python-pytoml-0.1.18-9.fc33 to appear in the f33-python repo
Successfully waited 11:01 for python-six-1.14.0-3.fc33 to appear in the f33-python repo
Successfully waited 8:10 for python-setuptools_scm-3.5.0-2.fc33 to appear in the f33-python repo
Successfully waited 10:09 for python-py-1.8.0-9.fc33 to appear in the f33-python repo
Successfully waited 7:24 for python-iniparse-0.4-41.fc33 to appear in the f33-python repo
Successfully waited 10:37 for python-chardet-3.0.4-16.fc33 to appear in the f33-python repo
Successfully waited 7:06 for python-pbr-5.4.3-4.fc33~bootstrap to appear in the f33-python repo
Successfully waited 8:06 for python-contextlib2-0.5.5-14.fc33 to appear in the f33-python repo
Successfully waited 9:16 for python-funcsigs-1.0.2-20.fc33 to appear in the f33-python repo
Successfully waited 7:10 for python-mock-3.0.5-9.fc33 to appear in the f33-python repo
Successfully waited 9:07 for python-mimeparse-1.6.0-14.fc33 to appear in the f33-python repo
Successfully waited 7:21 for python-extras-1.0.0-12.fc33 to appear in the f33-python repo
Successfully waited 7:16 for python-coverage-5.1-2.fc33 to appear in the f33-python repo
Successfully waited 7:14 for python-nose-1.3.7-31.fc33 to appear in the f33-python repo
Successfully waited 9:41 for python-attrs-19.3.0-3.fc33 to appear in the f33-python repo
Successfully waited 7:32 for python-pluggy-0.13.0-3.fc33 to appear in the f33-python repo
No kojira task seen in a reasonable time (got impatient, went manual):
    Successfully waited 10:50 for python-sortedcontainers-2.1.0-7.fc33 to appear in the f33-python repo
Successfully waited 9:17 for python-hypothesis-5.15.1-2.fc33 to appear in the f33-python repo
Successfully waited 9:58 for python-decorator-4.4.2-2.fc33 to appear in the f33-python repo
Here I saw a kojira newRepo task but the build was not it, so had to restart:
    Successfully waited 9:58 for python-decorator-4.4.2-2.fc33 to appear in the f33-python repo
No kojira task seen in a reasonable time (went manual):
    Successfully waited 23:14 for python-markupsafe-1.1.1-6.fc33 to appear in the f33-python repo

When I say "no kojira task seen" it means that when I reloaded https://koji.fedoraproject.org/koji/tasks?view=tree&owner=kojira&state=active&method=newRepo&order=-id it wasn't there. Maybe it run, but the build was missing, as with the other problematic builds.

At this point, the kojira regen-repo tasks don't start at all, so I run them manually:

Successfully waited 20:21 for python-pysocks-1.7.1-5.fc33 to appear in the f33-python repo
Successfully waited 17:34 for python-atomicwrites-1.4.0-3.fc33 to appear in the f33-python repo
Successfully waited 10:53 for python-testtools-2.4.0-5.fc33 to appear in the f33-python repo

The database load was really high and a number of ppc64le builders had dropped out. I restarted the db and re-started kojid on the builders.
Is it getting better again now?

Successfully waited 14:55 for python-urllib3-1.25.8-2.fc33 to appear in the f33-python repo

that is after a manual regen repo :(

Well, manual doesn't tell me much. ;) If you manually do one, kojira sees it and says "oh, someone did a newrepo, I don't need to now, let me drop that one from my list until it next needs regen"

manual means I haven't seen kojira job for a while and hence I triggered my own. 14:55 is the time for kojira job to not show up + the time of my job to finish.

When I don't run regen-repo manually, the kojira job doesn't start at all in 30+ minutes.

See also https://pagure.io/releng/issue/9494

https://koji.fedoraproject.org/koji/taskinfo?taskID=45345174

is the recent example of waiting 40+ minutes for build to appear in rawhide. I could not wait more, so I triggered newRepo myself (https://koji.fedoraproject.org/koji/taskinfo?taskID=45347349).

See also another example: https://lists.fedoraproject.org/archives/list/devel@lists.fedoraproject.org/message/7SVD4AKZCVR2DZOA5CL3TIK5TZFWBCOI/

So, a number of things that could be related here:

  • bodhi was sometimes not deleting side-tags when they merged.
  • due to a kojira bug, no old repos were being deleted (this caused us to almost fill up storage)

kojira is not likely back to normal yet... it's busy now deleting repo after old repo... once thats done we can look at what the performance looks like.

I've been investigating this and am asking upstream for help in debugging it.

It seems like there's still a ton of old skipped repos and it's not doing newrepos as efficently as it could...

It also looks like koji is not deleting automatically empty sidetags.

 [cverna@localhost]  $ koji list-tagged f33-build-side-24783
Build                                     Tag                   Built by
----------------------------------------  --------------------  ----------------

Opened https://pagure.io/koji/issue/2335

ok. I think this should be fixed now.

I worked with koji upstream on it and there are a number of kojira changes coming in the next release that we are already running.

  • The place it checks for how many newRepos are running was moved closer to the place it was tested against.
  • deletes of expired repos are moved to their own thread.
  • I upped the limits on our config to max of 30, and put more builders in the createrepo channel.
  • koji is in general faster in the new datacenter
  • I cleaned up a bunch of old side tags people were not using. (We are down to 37 side tags from a high of about 150)
  • We changed sidetags to delete the side-tag after all builds were untagged from it.

Finally, new kojira can make a queue file of buildroots, their score and how expired they are. I have enabled that and exposed it on the web:

https://koji.fedoraproject.org/kojira/queue

I'm going to close this now, but if you see delays or issues, feel free to re-open or file a new issue. If you could gather the queue at that time that might be helpful info also.

Thanks for your patience.

Metadata Update from @kevin:
- Issue close_status updated to: Fixed
- Issue status updated to: Closed (was: Open)

Metadata