#8101 Pushing to src.fp.o: remote: (ProgrammingError) permission denied for relation pull_requests
Closed: Fixed 11 days ago by pingou. Opened a month ago by churchyard.

I've noticed this for a coupe dozens pushes recently:

+ git push
Enumerating objects: 5, done.
Counting objects: 100% (5/5), done.
Delta compression using up to 8 threads
Compressing objects: 100% (3/3), done.
Writing objects: 100% (3/3), 344 bytes | 344.00 KiB/s, done.
Total 3 (delta 2), reused 0 (delta 0)
remote: Emitting a message to the fedmsg bus.
remote: * Publishing information for 1 commits
remote: Traceback (most recent call last):
remote:   File "/usr/lib/python2.7/site-packages/pagure/hooks/__init__.py", line 394, in run_project_hooks
remote:     changes=changes,
remote:   File "/usr/lib/python2.7/site-packages/pagure/hooks/__init__.py", line 111, in runhook
remote:     changes=changes,
remote:   File "/usr/lib/python2.7/site-packages/pagure/hooks/default.py", line 421, in post_receive
remote:     but_uids=pr_uids,
remote:   File "/usr/lib/python2.7/site-packages/celery/local.py", line 191, in __call__
remote:     return self._get_current_object()(*a, **kw)
remote:   File "/usr/lib/python2.7/site-packages/celery/app/task.py", line 375, in __call__
remote:     return self.run(*args, **kwargs)
remote:   File "/usr/lib/python2.7/site-packages/pagure/lib/tasks_utils.py", line 36, in decorated_function
remote:     return function(self, session, *args, **kwargs)
remote:   File "/usr/lib/python2.7/site-packages/pagure/lib/tasks.py", line 696, in refresh_pr_cache
remote:     session, project, but_uids=but_uids
remote:   File "/usr/lib/python2.7/site-packages/pagure/lib/query.py", line 3411, in reset_status_pull_request
remote:     {model.PullRequest.merge_status: None}, synchronize_session=False
remote:   File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/query.py", line 2796, in update
remote:     update_op.exec_()
remote:   File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/persistence.py", line 897, in exec_
remote:     self._do_exec()
remote:   File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/persistence.py", line 995, in _do_exec
remote:     update_stmt, params=self.query._params)
remote:   File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/session.py", line 991, in execute
remote:     bind, close_with_result=True).execute(clause, params or {})
remote:   File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 729, in execute
remote:     return meth(self, multiparams, params)
remote:   File "/usr/lib64/python2.7/site-packages/sqlalchemy/sql/elements.py", line 322, in _execute_on_connection
remote:     return connection._execute_clauseelement(self, multiparams, params)
remote:   File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 826, in _execute_clauseelement
remote:     compiled_sql, distilled_params
remote:   File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 958, in _execute_context
remote:     context)
remote:   File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 1159, in _handle_dbapi_exception
remote:     exc_info
remote:   File "/usr/lib64/python2.7/site-packages/sqlalchemy/util/compat.py", line 199, in raise_from_cause
remote:     reraise(type(exception), exception, tb=exc_tb)
remote:   File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 951, in _execute_context
remote:     context)
remote:   File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/default.py", line 436, in do_execute
remote:     cursor.execute(statement, parameters)
remote: ProgrammingError: (ProgrammingError) permission denied for relation pull_requests
remote:  'UPDATE pull_requests SET merge_status=%(merge_status)s, last_updated=%(last_updated)s WHERE pull_requests.project_id = %(project_id_1)s AND pull_requests.status = %(status_1)s' {'project_id_1': 19334, 'last_updated': datetime.datetime(2019, 8, 17, 14, 8, 42, 968444), 'merge_status': None, 'status_1': u'Open'}
remote: Sending to redis to log activity and send commit notification emails
remote: * Publishing information for 1 commits
To ssh://pkgs.fedoraproject.org/rpms/python-werkzeug
   7e438b0..ecea607  master -> master

The system was in a very weird state with various processes not OOM'd. I have tried to fix this. Could you test again and let me know?

(Note that the push succeeds, so it is not critical from my POV.)

Can you (and @ignatenkobrain who also saw this) see if it's still happening now?

Can you (and @ignatenkobrain who also saw this) see if it's still happening now?

This is due to our setup of pagure on dist-git. Basically (I didn't check so let
me know if that's not the case), these commits are likely using a
"Fixes/Merges/Close #<id>" message in them.
These are meant to allow actions on tickets or PR via git commits. However, on
dist-git since packagers have a shell access on the machine and these hooks are
run under the packager's user. So for security reasons the hook only have a
read-only access to the database.

IIRC we did change pagure to make these actions async and via a worker (on
dist-git) to solve this issue though, so if it still happens, it's likely a
configuration error (or, more annoying a bug).

Can you (and @ignatenkobrain who also saw this) see if it's still happening now?

No longer. Thanks.

these commits are likely using a "Fixes/Merges/Close #<id>" message in them.

They are not. The message is "Rebuilt for Python 3.8".

these commits are likely using a "Fixes/Merges/Close #<id>" message in them.

They are not. The message is "Rebuilt for Python 3.8".

Hm, so likely something else

Thanks for the feedback!

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

a month ago

This happens again: https://lists.fedoraproject.org/archives/list/devel@lists.fedoraproject.org/message/XYWLXIETEE564PGCSQ5A72SDSCJOCLQA/

$ git push
Enumerating objects: 5, done.
Counting objects: 100% (5/5), done.
Delta compression using up to 8 threads
Compressing objects: 100% (3/3), done.
Writing objects: 100% (3/3), 613 bytes | 613.00 KiB/s, done.
Total 3 (delta 1), reused 0 (delta 0)
remote: Emitting a message to the fedmsg bus.
remote: * Publishing information for 1 commits
remote: Traceback (most recent call last):
remote:   File "/usr/lib/python2.7/site-packages/pagure/hooks/__init__.py", line 394, in run_project_hooks
remote:     changes=changes,
remote:   File "/usr/lib/python2.7/site-packages/pagure/hooks/__init__.py", line 111, in runhook
remote:     changes=changes,
remote:   File "/usr/lib/python2.7/site-packages/pagure/hooks/default.py", line 421, in post_receive
remote:     but_uids=pr_uids,
remote:   File "/usr/lib/python2.7/site-packages/celery/local.py", line 191, in __call__
remote:     return self._get_current_object()(*a, **kw)
remote:   File "/usr/lib/python2.7/site-packages/celery/app/task.py", line 375, in __call__
remote:     return self.run(*args, **kwargs)
remote:   File "/usr/lib/python2.7/site-packages/pagure/lib/tasks_utils.py", line 36, in decorated_function
remote:     return function(self, session, *args, **kwargs)
remote:   File "/usr/lib/python2.7/site-packages/pagure/lib/tasks.py", line 696, in refresh_pr_cache
remote:     session, project, but_uids=but_uids
remote:   File "/usr/lib/python2.7/site-packages/pagure/lib/query.py", line 3411, in reset_status_pull_request
remote:     {model.PullRequest.merge_status: None}, synchronize_session=False
remote:   File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/query.py", line 2796, in update
remote:     update_op.exec_()
remote:   File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/persistence.py", line 897, in exec_
remote:     self._do_exec()
remote:   File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/persistence.py", line 995, in _do_exec
remote:     update_stmt, params=self.query._params)
remote:   File "/usr/lib64/python2.7/site-packages/sqlalchemy/orm/session.py", line 991, in execute
remote:     bind, close_with_result=True).execute(clause, params or {})
remote:   File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 729, in execute
remote:     return meth(self, multiparams, params)
remote:   File "/usr/lib64/python2.7/site-packages/sqlalchemy/sql/elements.py", line 322, in _execute_on_connection
remote:     return connection._execute_clauseelement(self, multiparams, params)
remote:   File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 826, in _execute_clauseelement
remote:     compiled_sql, distilled_params
remote:   File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 958, in _execute_context
remote:     context)
remote:   File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 1159, in _handle_dbapi_exception
remote:     exc_info
remote:   File "/usr/lib64/python2.7/site-packages/sqlalchemy/util/compat.py", line 199, in raise_from_cause
remote:     reraise(type(exception), exception, tb=exc_tb)
remote:   File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/base.py", line 951, in _execute_context
remote:     context)
remote:   File "/usr/lib64/python2.7/site-packages/sqlalchemy/engine/default.py", line 436, in do_execute
remote:     cursor.execute(statement, parameters)
remote: ProgrammingError: (ProgrammingError) permission denied for relation pull_requests
remote:  'UPDATE pull_requests SET merge_status=%(merge_status)s, last_updated=%(last_updated)s WHERE pull_requests.project_id = %(project_id_1)s AND pull_requests.status = %(status_1)s' {'project_id_1': 19256, 'last_updated': datetime.datetime(2019, 9, 3, 8, 36, 56, 952956), 'merge_status': None, 'status_1': u'Open'}
remote: Sending to redis to log activity and send commit notification emails
remote: * Publishing information for 1 commits

Metadata Update from @churchyard:
- Issue status updated to: Open (was: Closed)

12 days ago

Ok, I've found and (hot)fixed the issue I believe.

Going to push it upstream and likely cut a release as I have another fix I'd like to get out there :)

Sorry for the inconvenience and please let me know if it happens again!

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

11 days ago

No inconvenience at all. Thanks for the fix.

Login to comment on this ticket.

Metadata