releng

#12813 f41-updates-testing compose failing sanity check and failing
Closed: Fixed with Explanation by kevin. Opened by kevin.

Closed: Fixed with Explanation
Reopen Issue

There's a f41-updates-testing compose that is failing repo sanity checks and failing to go out.

This is blocking all updates. ;(

A patial copy of the logs:

INFO/ForkPoolWorker-16] Running sanity checks on /mnt/koji/compose/updates/Fedora-41-updates-testing-20250710.0
Jul 10 02:13:04 bodhi-backend01.rdu3.fedoraproject.org celery-3[13961]: [2025-07-10 02:13:04,426: INFO/ForkPoolWorker-16] Starting sanity check on /mnt/koji/compose/updates/Fedora-41-updates-testing-20250710.0/compose/Everything/source/tree/repodata
Jul 10 02:13:04 bodhi-backend01.rdu3.fedoraproject.org celery-3[13961]: [2025-07-10 02:13:04,657: INFO/ForkPoolWorker-16] Finished sanity check on /mnt/koji/compose/updates/Fedora-41-updates-testing-20250710.0/compose/Everything/source/tree/repodata
Jul 10 02:29:02 bodhi-backend01.rdu3.fedoraproject.org celery-3[13961]: [2025-07-10 02:29:02,691: ERROR/ForkPoolWorker-16] Repodata sanity check failed, compose thrown out: (psycopg2.OperationalError) could not receive data from server: Connection timed out
Jul 10 02:29:02 bodhi-backend01.rdu3.fedoraproject.org celery-3[13961]: [SQL: SELECT composes.release_id AS composes_release_id, composes.request AS composes_request, composes.checkpoints AS composes_checkpoints, composes.error_message AS composes_error_message, composes.date_created AS composes_date_created, composes.state_date AS composes_state_date, composes.state AS composes_state
Jul 10 02:29:02 bodhi-backend01.rdu3.fedoraproject.org celery-3[13961]: FROM composes
Jul 10 02:29:02 bodhi-backend01.rdu3.fedoraproject.org celery-3[13961]: WHERE composes.release_id = %(pk_1)s AND composes.request = %(pk_2)s]
Jul 10 02:29:02 bodhi-backend01.rdu3.fedoraproject.org celery-3[13961]: [parameters: {'pk_1': 80, 'pk_2': 'testing'}]
Jul 10 02:29:02 bodhi-backend01.rdu3.fedoraproject.org celery-3[13961]: (Background on this error at: https://sqlalche.me/e/20/e3q8)
Jul 10 02:29:02 bodhi-backend01.rdu3.fedoraproject.org celery-3[13961]: Traceback (most recent call last):
Jul 10 02:29:02 bodhi-backend01.rdu3.fedoraproject.org celery-3[13961]:   File "/usr/lib64/python3.13/site-packages/sqlalchemy/engine/base.py", line 1963, in _exec_single_context
Jul 10 02:29:02 bodhi-backend01.rdu3.fedoraproject.org celery-3[13961]:     self.dialect.do_execute(
Jul 10 02:29:02 bodhi-backend01.rdu3.fedoraproject.org celery-3[13961]:     ~~~~~~~~~~~~~~~~~~~~~~~^
Jul 10 02:29:02 bodhi-backend01.rdu3.fedoraproject.org celery-3[13961]:         cursor, str_statement, effective_parameters, context
Jul 10 02:29:02 bodhi-backend01.rdu3.fedoraproject.org celery-3[13961]:         ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Jul 10 02:29:02 bodhi-backend01.rdu3.fedoraproject.org celery-3[13961]:     )
Jul 10 02:29:02 bodhi-backend01.rdu3.fedoraproject.org celery-3[13961]:     ^
Jul 10 02:29:02 bodhi-backend01.rdu3.fedoraproject.org celery-3[13961]:   File "/usr/lib64/python3.13/site-packages/sqlalchemy/engine/default.py", line 943, in do_execute

I've been adding some debugging to try and figure out where it's getting the db timeout without much luck so far.

I just fired off another one now... but I expect it to fail.

CC: @mattia

The only call to db in the sanity_check is to get the createrepo config for the release, which is performed only for arches other than sources.
So this line seems to be the culprit.
I can't imagine why it started failing now and only for F41 though.

Can you to to modify the composer like:

        from munch import munchify
        rel_data = munchify(self.compose.release)
        drpms = get_createrepo_config(rel_data).get('drpms_enabled')
        for arch in arches:
            # sanity check our repodata
            try:
                if arch == 'source':
                    repodata = os.path.join(self.path, 'compose',
                                            'Everything', arch, 'tree', 'repodata')
                    sanity_check_repodata(repodata, repo_type='source', drpms=False)
                else:
                    repodata = os.path.join(self.path, 'compose',
                                            'Everything', arch, 'os', 'repodata')
                    repo_type = 'module' if self.ctype == ContentType.module else 'yum'
                    # for module repos drpms is not considered
                    sanity_check_repodata(repodata, repo_type=repo_type, drpms=drpms)
            except Exception:
                log.exception("Repodata sanity check failed, compose thrown out")
                self._toss_out_repo()
                raise

(basically, move the drpms = line before the for loop and pass a munch object to the external method instead of the database object)

https://patch-diff.githubusercontent.com/raw/fedora-infra/bodhi/pull/5915.patch
Edited by mattia

So i got to that theory too...

I just commented the drpm call and set it to false...

                #drpms = get_createrepo_config(self.compose.release).get('drpms_enabled')
                drpms = False

That gave me:

 INFO/ForkPoolWorker-16] Finished sanity check on /mnt/koji/compose/updates/Fedora-41-updates-test
ing-20250710.2/compose/Everything/x86_64/os/repodata                                              
Jul 10 06:29:23 bodhi-backend01.rdu3.fedoraproject.org celery-3[159680]: [2025-07-10 06:29:23,967:
 INFO/ForkPoolWorker-16] Not waiting for a repo signature                                         
Jul 10 06:29:23 bodhi-backend01.rdu3.fedoraproject.org celery-3[159680]: [2025-07-10 06:29:23,969:
 INFO/ForkPoolWorker-16] Creating symlink: /mnt/koji/compose/updates/f41-updates-testing => /mnt/k
oji/compose/updates/Fedora-41-updates-testing-20250710.2                                          
Jul 10 06:45:23 bodhi-backend01.rdu3.fedoraproject.org celery-3[159680]: [2025-07-10 06:45:23,173:
 ERROR/ForkPoolWorker-16] Exception in ComposerThread(f41-updates-testing)                        
Jul 10 06:45:23 bodhi-backend01.rdu3.fedoraproject.org celery-3[159680]: Traceback (most recent ca
ll last):                                                                                         
Jul 10 06:45:23 bodhi-backend01.rdu3.fedoraproject.org celery-3[159680]:   File "/usr/lib64/python
3.13/site-packages/sqlalchemy/engine/base.py", line 1963, in _exec_single_context                 
Jul 10 06:45:23 bodhi-backend01.rdu3.fedoraproject.org celery-3[159680]:     self.dialect.do_execu
te(                                                                                               
Jul 10 06:45:23 bodhi-backend01.rdu3.fedoraproject.org celery-3[159680]:     ~~~~~~~~~~~~~~~~~~~~~
~~^
Jul 10 06:45:23 bodhi-backend01.rdu3.fedoraproject.org celery-3[159680]:         cursor, str_state
ment, effective_parameters, context
Jul 10 06:45:23 bodhi-backend01.rdu3.fedoraproject.org celery-3[159680]:         ^^^^^^^^^^^^^^^^^
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
Jul 10 06:45:23 bodhi-backend01.rdu3.fedoraproject.org celery-3[159680]:     )
Jul 10 06:45:23 bodhi-backend01.rdu3.fedoraproject.org celery-3[159680]:     ^
Jul 10 06:45:23 bodhi-backend01.rdu3.fedoraproject.org celery-3[159680]:   File "/usr/lib64/python
3.13/site-packages/sqlalchemy/engine/default.py", line 943, in do_execute

so it got further, but then failed after sanity check.

I guess I'll try resuming again?

ok, it finished.

I guess lets try another...

worked. Trying more.

But of course we should still try and figure out whats going on...

Metadata Update from @phsmoura:
- Issue tagged with: high-gain, high-trouble, ops

So, the rest finished, but f41-updates-testing failed the same way... resumed it and it completed.

Sadly, more failures today, F42 testing this time. ☹️

I very much wonder if this is the same thing @abompard tracked down in https://pagure.io/fedora-infrastructure/issue/12622

ie, a tcp timeout between a build vlan thing and db01.

I very much wonder if this is the same thing @abompard tracked down in https://pagure.io/fedora-infrastructure/issue/12622

ie, a tcp timeout between a build vlan thing and db01.

This can be verified by hacking the lines
https://github.com/fedora-infra/bodhi/blob/05517fb58871639267aff39639d8119aa95c134f/bodhi-server/bodhi/server/init.py#L171
like:

            connect_args={
                'timeout': 10,
                'options': f'-c statement_timeout={config["sqlalchemy_extra.statement_timeout"]}'
            }

@abompard suggested adding:

sqlalchemy.pool_recycle = 600

to have it recycle idle connections after 600 seconds.
I've put that in place manually now, will see if it gets things happy in tonights push.

So, I think that was it. No problems yesterday. We can watch today's...

+1 i looked and monitored it today and yesterday as well, no problem found

Yeah, I think that was it indeed. Thanks everyone!

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

high-gain high-trouble ops

None
None
None
Static archive. pagure.io was sunset in 2026; this is a read-only snapshot.
Red Hat Logo

Fedora is sponsored by Red Hat. Learn more about the relationship between Red Hat and Fedora »

© Red Hat, Inc. and others.