#8101 Pushing to src.fp.o: remote: (ProgrammingError) permission denied for relation pull_requests
Closed: Fixed by pingou. Opened 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?

Still happens.

(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 #" 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 #" message in them.

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

these commits are likely using a "Fixes/Merges/Close #" 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)

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)

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)

No inconvenience at all. Thanks for the fix.

Metadata