update_repos commands fails

[xrmx]

Details

On a local rtd instance installed from git 09f8282, call python manage.py repos pip fails. The project data is from python manage.py loaddata test_data.

Expected Result

Command to works fine

Actual Result

$ python manage.py update_repos pip
[28/Feb/2018 04:43:25] root:124[23847]: INFO Generating grammar tables from /usr/lib/python2.7/lib2to3/Grammar.txt
[28/Feb/2018 04:43:25] root:124[23847]: INFO Generating grammar tables from /usr/lib/python2.7/lib2to3/PatternGrammar.txt
System check identified some issues:

WARNINGS:
?: (1_8.W001) The standalone TEMPLATE_* settings were deprecated in Django 1.8 and the TEMPLATES dictionary takes precedence. You must put the values of the following settings into your default TEMPLATES dict: TEMPLATE_DEBUG.
?: (guardian.W001) Guardian authentication backend is not hooked. You can add this in settings as eg: `AUTHENTICATION_BACKENDS = ('django.contrib.auth.backends.ModelBackend', 'guardian.backends.ObjectPermissionBackend')`.
[28/Feb/2018 04:43:27] readthedocs.core.management.commands.update_repos:80[23847]: INFO Building Pip
[28/Feb/2018 04:43:27] requests.packages.urllib3.connectionpool:207[23847]: INFO Starting new HTTP connection (1): localhost
[28/Feb/2018 04:43:27] requests.packages.urllib3.connectionpool:242[23847]: INFO Resetting dropped connection: localhost
[28/Feb/2018 04:43:27] readthedocs.projects.tasks:233[23847]: INFO (Build) [pip:latest] Updating docs from VCS
[28/Feb/2018 04:43:27] readthedocs.projects.tasks:233[23847]: INFO (Build) [pip:latest] Checking out version latest: master
[28/Feb/2018 04:43:27] readthedocs.doc_builder.environments:117[23847]: INFO Running: 'git status' [/home/rm/src/readthedocs/rtd/checkouts/readthedocs.org/user_builds/pip/checkouts/latest]
[28/Feb/2018 04:43:27] readthedocs.doc_builder.environments:117[23847]: INFO Running: 'git remote set-url origin https://github.com/pypa/pip' [/home/rm/src/readthedocs/rtd/checkouts/readthedocs.org/user_builds/pip/checkouts/latest]
[28/Feb/2018 04:43:27] readthedocs.doc_builder.environments:117[23847]: INFO Running: 'git fetch --tags --prune' [/home/rm/src/readthedocs/rtd/checkouts/readthedocs.org/user_builds/pip/checkouts/latest]
[28/Feb/2018 04:43:29] readthedocs.doc_builder.environments:117[23847]: INFO Running: 'git show-ref remotes/origin/master' [/home/rm/src/readthedocs/rtd/checkouts/readthedocs.org/user_builds/pip/checkouts/latest]
[28/Feb/2018 04:43:29] readthedocs.doc_builder.environments:193[23847]: WARNING Recording command exit_code as success
[28/Feb/2018 04:43:29] requests.packages.urllib3.connectionpool:242[23847]: INFO Resetting dropped connection: localhost
[28/Feb/2018 04:43:29] readthedocs.vcs_support.utils:101[23847]: INFO Lock (pip): Releasing
[28/Feb/2018 04:43:29] readthedocs.doc_builder.environments:450[23847]: ERROR (Build) [pip:latest] Client Error 400: http://localhost:8000/api/v2/command/
Traceback (most recent call last):
  File "/home/rm/src/readthedocs/rtd/checkouts/readthedocs.org/readthedocs/projects/tasks.py", line 333, in run_setup
    self.setup_vcs()
  File "/home/rm/src/readthedocs/rtd/checkouts/readthedocs.org/readthedocs/projects/tasks.py", line 452, in setup_vcs
    self.sync_repo()
  File "/home/rm/src/readthedocs/rtd/checkouts/readthedocs.org/readthedocs/projects/tasks.py", line 124, in sync_repo
    version_repo.checkout(self.version.identifier)
  File "/home/rm/src/readthedocs/rtd/checkouts/readthedocs.org/readthedocs/vcs_support/backends/git.py", line 183, in checkout
    identifier = self.find_ref(identifier)
  File "/home/rm/src/readthedocs/rtd/checkouts/readthedocs.org/readthedocs/vcs_support/backends/git.py", line 207, in find_ref
    if self.ref_exists('remotes/origin/' + ref):
  File "/home/rm/src/readthedocs/rtd/checkouts/readthedocs.org/readthedocs/vcs_support/backends/git.py", line 213, in ref_exists
    code, _, _ = self.run('git', 'show-ref', ref, record_as_success=True)
  File "/home/rm/src/readthedocs/rtd/checkouts/readthedocs.org/readthedocs/vcs_support/base.py", line 97, in run
    build_cmd = self.environment.run(*cmd, **kwargs)
  File "/home/rm/src/readthedocs/rtd/checkouts/readthedocs.org/readthedocs/doc_builder/environments.py", line 470, in run
    return super(BuildEnvironment, self).run(*cmd, **kwargs)
  File "/home/rm/src/readthedocs/rtd/checkouts/readthedocs.org/readthedocs/doc_builder/environments.py", line 310, in run
    return self.run_command_class(cls=self.command_class, cmd=cmd, **kwargs)
  File "/home/rm/src/readthedocs/rtd/checkouts/readthedocs.org/readthedocs/doc_builder/environments.py", line 476, in run_command_class
    return super(BuildEnvironment, self).run_command_class(*cmd, **kwargs)
  File "/home/rm/src/readthedocs/rtd/checkouts/readthedocs.org/readthedocs/doc_builder/environments.py", line 356, in run_command_class
    self.record_command(build_cmd)
  File "/home/rm/src/readthedocs/rtd/checkouts/readthedocs.org/readthedocs/doc_builder/environments.py", line 456, in record_command
    command.save()
  File "/home/rm/src/readthedocs/rtd/checkouts/readthedocs.org/readthedocs/doc_builder/environments.py", line 205, in save
    api_v2.command.post(data)
  File "/home/rm/src/readthedocs/rtd/local/lib/python2.7/site-packages/slumber/__init__.py", line 167, in post
    resp = self._request("POST", data=data, files=files, params=kwargs)
  File "/home/rm/src/readthedocs/rtd/local/lib/python2.7/site-packages/slumber/__init__.py", line 101, in _request
    raise exception_class("Client Error %s: %s" % (resp.status_code, url), response=resp, content=resp.content)
HttpClientError: Client Error 400: http://localhost:8000/api/v2/command/
[28/Feb/2018 04:43:29] readthedocs.doc_builder.environments:431[23847]: INFO (Build) [pip:latest] Build finished
[28/Feb/2018 04:43:29] readthedocs.projects.tasks:233[23847]: INFO (Build) [pip:latest] Failing build because of setup failure: Client Error 400: http://localhost:8000/api/v2/command/
[28/Feb/2018 04:43:29] readthedocs.projects.tasks:284[23847]: ERROR An unhandled exception was raised during build setup
Traceback (most recent call last):
  File "/home/rm/src/readthedocs/rtd/checkouts/readthedocs.org/readthedocs/projects/tasks.py", line 276, in run
    setup_successful = self.run_setup(record=record)
  File "/home/rm/src/readthedocs/rtd/checkouts/readthedocs.org/readthedocs/projects/tasks.py", line 355, in run_setup
    self.send_notifications()
  File "/home/rm/src/readthedocs/rtd/checkouts/readthedocs.org/readthedocs/projects/tasks.py", line 663, in send_notifications
    send_notifications.delay(self.version.pk, build_pk=self.build['id'])
KeyError: 'id'
[28/Feb/2018 04:43:29] celery.app.trace:123[23847]: INFO Task readthedocs.projects.tasks.update_docs[87cb2b57-91fb-48b7-b97b-ec22c31099f1] succeeded in 1.796398073s: False

[stsewd]

I was able to replicate this on my local instance, I'm going to see what's happening.

[stsewd]

I found that the error happens here

https://github.com/rtfd/readthedocs.org/blob/09f8282be35c20dcca42c85d3f845bba8b784cfe/readthedocs/doc_builder/environments.py#L205

This is the error that I catch from pdb '{"build":["This field may not be null."]}'

I'm going to investigate more deeper why build is None.

[stsewd]

I found the error, indeed is a bug on the code.

Here is called the task for update the docs, but from command line record is false, so build and build_pk are None

https://github.com/rtfd/readthedocs.org/blob/4b00f3ff2f1cfe89819d2dc3f0689f2fad53f4e3/readthedocs/core/utils/__init__.py#L131-L132

From the docstrings, says that if those parameters are None, the command isn't saved.

https://github.com/rtfd/readthedocs.org/blob/4b00f3ff2f1cfe89819d2dc3f0689f2fad53f4e3/readthedocs/projects/tasks.py#L256

But later on the code it tries to save the command with build equals None, so it gives an error on the request.

Anyone feel free to fix this bug if I have not done it in the next days :)

• We need to see how this class is used on others parts of the code
• Probably a test should be written
• Fix according to first step

If the solution is more deeper, probably we may want to wait to #3687.

[stsewd]

Thanks to @humitos I learn that this command is also used here
https://github.com/rtfd/readthedocs.org/blob/78b5781ad071de656451a262d39458c612c45be0/readthedocs/projects/management/commands/import_project_from_live.py#L69

So this command python manage.py -r update_repos {repo} works!

I'm not complete sure if -r should be always true, any case where we may not want to no record the build? If this option should be always true, then we need to change the docs (docstrings too?).

[agjohnson]

Yeah, perhaps just setting -r to always True is the best.