ppa assigner 500 error in _get_ppa

Bug #1347220 reported by Paul Larson
14
This bug affects 2 people
Affects Status Importance Assigned to Milestone
Ubuntu CI Engine
New
Undecided
Unassigned

Bug Description

From a fresh install today, I saw a ticket hang and never get out of queued state. When I clicked on the watch build link, I found:

Ubuntu logo for print CI Engine

    Tickets
    Engine health

14:32:19 INFO lander: Steps to run ticket: ppa_assigner, bsbuilder, image_builder, test_runner, publisher, ppa_assigner_release
14:32:19 DEBUG lander_service_wrapper: Executing service wrapper: ppa_assigner
14:32:19 INFO lander_service_wrapper: Calling via POST [http://10.0.3.152:8080/api/v1/ppa/]: {'ticket_id': 1}
14:32:19 ERROR root: Unable to handle request: HTTP Error 500: Internal Server Error: <html>
  <head>
    <title>Internal Server Error</title>
  </head>
  <body>
    <h1>Internal Server Error</h1>

  </body>
</html>
Traceback (most recent call last):
  File "/srv/ci-airline-lander/code/r703_ff73fd579057b133ecf9e543c811b9b5449419bb/lander/bin/lander_service_wrapper.py", line 350, in main
    results = handler(amqp_config, workflow)
  File "/srv/ci-airline-lander/code/r703_ff73fd579057b133ecf9e543c811b9b5449419bb/lander/bin/lander_service_wrapper.py", line 131, in _handle_ppa_assigner
    loc = _get_ppa(workflow.ppa_url, workflow.ticket_id)
  File "/srv/ci-airline-lander/code/r703_ff73fd579057b133ecf9e543c811b9b5449419bb/lander/bin/lander_service_wrapper.py", line 125, in _get_ppa
    raise e
HTTPError: HTTP Error 500: Internal Server Error
14:32:19 DEBUG lander: Step completed with rc=1
14:32:19 INFO lander: Freeing up PPA
14:32:19 DEBUG lander_service_wrapper: Executing service wrapper: ppa_assigner_release
14:32:19 INFO lander_service_wrapper: ppa was never reserved by this job
14:32:19 DEBUG lander: Step completed with rc=0

Looking a bit closer at the logs on the ppa-assigner, I also found in the cleaner.log:
pgsql settings from /srv/ci-airline-ppa-django/code/r703_ff73fd579057b133ecf9e543c811b9b5449419bb/ppa-assigner/../../../pgsql.json
ALLOWED_HOSTS from (/srv/ci-airline-ppa-django/code/r703_ff73fd579057b133ecf9e543c811b9b5449419bb/ppa-assigner/../../../allowed_hosts.json): plars-local-machine-5, plars-local-machine-5, 10.0.3.152, 10.0.3.152, localhost
Traceback (most recent call last):
  File "./ppa-assigner/manage.py", line 25, in <module>
    execute_from_command_line(sys.argv)
  File "/usr/lib/python2.7/dist-packages/django/core/management/__init__.py", line 453, in execute_from_command_line
    utility.execute()
  File "/usr/lib/python2.7/dist-packages/django/core/management/__init__.py", line 392, in execute
    self.fetch_command(subcommand).run_from_argv(self.argv)
  File "/usr/lib/python2.7/dist-packages/django/core/management/__init__.py", line 263, in fetch_command
    app_name = get_commands()[subcommand]
  File "/usr/lib/python2.7/dist-packages/django/core/management/__init__.py", line 109, in get_commands
    apps = settings.INSTALLED_APPS
  File "/usr/lib/python2.7/dist-packages/django/conf/__init__.py", line 53, in __getattr__
    self._setup(name)
  File "/usr/lib/python2.7/dist-packages/django/conf/__init__.py", line 49, in _setup
    self._configure_logging()
  File "/usr/lib/python2.7/dist-packages/django/conf/__init__.py", line 84, in _configure_logging
    logging_config_func(self.LOGGING)
  File "/usr/lib/python2.7/logging/config.py", line 777, in dictConfig
    dictConfigClass(config).configure()
  File "/usr/lib/python2.7/logging/config.py", line 575, in configure
    '%r: %s' % (name, e))
ValueError: Unable to configure handler 'file': [Errno 13] Permission denied: u'/srv/ci-airline-ppa-django/logs/django.log'

root@plars-local-machine-5:/srv/ci-airline-ppa-django/logs# ls -l
total 596
-rw-r--r-- 1 www-data www-data 1692 Jul 22 16:05 access.log
-rw-r--r-- 1 root root 92772 Jul 22 15:04 cleaner.log
-rw-r--r-- 1 root root 497196 Jul 22 17:18 django.log
-rw-r--r-- 1 www-data www-data 4799 Jul 22 16:05 gunicorn.log

This looked a little similar to https://bugs.launchpad.net/uci-engine/+bug/1336842 but this time it's the log itself that has the wrong permissions. Talking to Celso, he thinks it might be a side-effect of having the db migration run during the charm install (wsgi-app change), maybe some sort of race. I haven't tried to reproduce just yet, but wanted to capture as much as I could. If I fix the ownership of django.log and restart the ppa-cleaner, it seems to proceed ok, but the ticket is still stuck.

To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Duplicates of this bug

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.