Log an error when the Build.pk differs from the pk in Build.error message

[humitos]

This is my last card played trying to get more debug information to understand what is happening with the Build.pk and the Build.error.

Example: https://readthedocs.org/projects/libmodule/builds/7015103/

[humitos]

@agjohnson please, take a look at this and let me know if this could be a good way to get more debugging information from production environment.

[humitos]

What else could I add here relevant to this issue?

[stsewd]

@humitos there are others examples of this? I didn't find anything with that one :/

[stsewd]

Also, that id exists? I think the instance of the build dictionary is being shared on calls (something similar to what I experimented here #3764 (comment))

Edit: I was able to replicate this on my local instance.

[stsewd]

From pdb

(Pdb) id(self); self.project; self.build
140249780871504
<APIProject: bookpy-2>
{'project': 199282, u'commands': [], u'state_display': u'Triggered', u'success': False, u'state': u'finished', u'setup': u'', u'exit_code': 1, u'output': u'', u'cold_storage': None, u'length': 3
30, 'version': 554, u'id': 367, u'error': 'There was a problem with Read the Docs while building your documentation. Please report this to us with your build id (367).', u'date': u'2018-04-12T00
:56:24.935195', u'commit': u'2c1475517fbfcfe333ed028c27f633313bab65a7', u'setup_error': u'', u'type': u'html', u'builder': u'stsewd'}
(Pdb) c
> /home/stsewd/rtd/readthedocs.org/readthedocs/doc_builder/environments.py(577)update_build()
-> api_v2.build(self.build['id']).put(self.build)
(Pdb) id(self); self.project; self.build
140249780871504
<APIProject: bookpy-2>
{'project': 199282, u'commands': [], u'state_display': u'Triggered', u'success': False, u'state': u'finished', u'setup': u'', u'exit_code': 1, u'output': u'', u'cold_storage': None, u'length': 6
3, 'version': 554, u'id': 367, u'error': 'There was a problem with Read the Docs while building your documentation. Please report this to us with your build id (366).', u'date': u'2018-04-12T00:
56:24.935195', u'commit': u'2c1475517fbfcfe333ed028c27f633313bab65a7', u'setup_error': u'', u'type': u'html', u'builder': u'stsewd'}

Here you can see how the message is changed (error key), the breakpoints are on

https://github.com/rtfd/readthedocs.org/blob/64def2d3b73b98c0593185ee901d25091d07f8a0/readthedocs/doc_builder/environments.py#L512

https://github.com/rtfd/readthedocs.org/blob/64def2d3b73b98c0593185ee901d25091d07f8a0/readthedocs/doc_builder/environments.py#L575

I going to keep investigating.

[stsewd]

OK, I got it.

The other build id comes from here

https://github.com/rtfd/readthedocs.org/blob/64def2d3b73b98c0593185ee901d25091d07f8a0/readthedocs/projects/tasks.py#L300-L316

Before that the build is shown as failed and with the correct id, then update_build gets executed and updates the build with another id.

pdb session (before self.build_env.update_build(BUILD_STATE_FINISHED) )

(Pdb) > /home/stsewd/.pyenv/versions/rtd/lib/python2.7/site-packages/celery/app/task.py(741)appl
(Pdb) self.build_env.build; build_pk
(Pdb) {'project': 199282, u'commands': [], u'state_display': u'Triggered', u'success': False, u'
state': u'finished', u'setup': u'', u'exit_code': 1, u'output': u'', u'cold_storage': None, u'le
ngth': 0, 'version': 554, u'id': 383, u'error': 'There was a problem with Read the Docs while bu
ilding your documentation. Please report this to us with your build id (383).', u'date': u'2018-
04-12T02:36:15.045631', u'commit': u'2c1475517fbfcfe333ed028c27f633313bab65a7', u'setup_error':
u'', u'type': u'html', u'builder': u'stsewd'}
382

[stsewd]

With the above information, I think that piece of code needs to check for the type of exception before running the update. But, still is curious why the ids are different 🤔

[humitos]

@stsewd thanks for taking a look at this. I'm really confused at the moment :(

I wasn't able to reproduce this in my local instance and I don't really understand the steps you followed to reproduce this in yours. Can you enumerate those steps and how you did the project fail and where the exception has to be raised?

[stsewd]

@humitos, sorry, I forgot to write the steps here. Well, because I'm lazy I just turn off my docker daemon and trigger two builds consecutively. Anyway, the exception would happen here
https://github.com/rtfd/readthedocs.org/blob/64def2d3b73b98c0593185ee901d25091d07f8a0/readthedocs/doc_builder/environments.py#L838

[agjohnson]

I'm going to close this. We discovered the underlying issue and don't need this anymore. PR is open at #3946