Upstream prematurely closed connection while reading response header from upstream

[MaH Relinace]

Hello Taiga group.

Something went wrong with the database.
After this was reported I tested with 2 Taiga users.

The error being displayed is:

Oops something happened...
Our oompa Loompas are sad, your changes were not saved!

The front-end and the back-end are hosted on the same server. We have a second server with Taiga installed for test purposes. For the installation I followed the Taiga production mode documentation.

Symptoms:

• In project A users are unable to add a comments to user stories, this project does not contain issues.
• In project B users are unable to change the status of an issues, but it is possible to add comments to users stories.
• In project C and in the example projects everything works fine.

Recent events:

• Both servers moved to another vlan. I don't think this is connected.
• Installed htop. Dont think this is connected.
• Distribution upgrade (apt-get dist-upgrade).

Analysis:
gunicorn.stderr.log:

Trying import local.py settings...
Monkey patching...
WARNING    Property: Unknown Property name. [6:51: -webkit-text-size-adjust]
WARNING    Property: Unknown Property name. [6:82: -ms-text-size-adjust]
WARNING    Property: Unknown Property name. [7:23: mso-table-lspace]
WARNING    Property: Unknown Property name. [7:45: mso-table-rspace]
WARNING    Property: Unknown Property name. [8:17: -ms-interpolation-mode]
ERROR    Property: Invalid value for "CSS Level 2.1" property: 0.8rem 3rem [178:17: padding]
WARNING    Property: Unknown Property name. [277:55: -webkit-text-size-adjust]
WARNING    Property: Unknown Property name.
WORKER TIMEOUT (pid:6263)

This does not look to good, but I have no clue what to do about this, or how serious this is. But when I look at the beginning of the log, I can see these errors were already logged before the current problem arose.

Saw the following message several times in the nginx.error.log:

2015/02/17 16:10:11 [error] 5966#0: *19 upstream prematurely closed connection while reading response header from upstream, client: 185.22.192.11, server: _, request: "POST /api/v1/users/password_recovery HTTP/1.1", upstream: "http://127.0.0.1:8001/api/v1/users/password_recovery", host: "brasdv001.reliance.nl", referrer: "http://brasdv001.reliance.nl/forgot-password"

So I added "fastcgi_read_timeout 150;" to the /etc/nginx/sites-enables/taiga file, which gives a new error message in the nginx log:

2015/02/17 14:20:36 [error] 1009#0: *1086 upstream timed out (110: Connection timed out) while reading response header from upstream, client: 185.22.192.11, server: _, request: "PATCH /api/v1/issues/76 HTTP/1.1", upstream: "http://127.0.0.1:8001/api/v1/issues/76", host: "77.245.89.64", referrer: "http://77.245.89.64/project/admin-rascore/issue/85"
2015/02/17 15:11:12 [error] 1022#0: *1 upstream timed out (110: Connection timed out) while reading response header from upstream, client: 185.22.192.11, server: _, request: "PATCH /api/v1/userstories/246 HTTP/1.1", upstream: "http://127.0.0.1:8001/api/v1/userstories/246", host: "77.245.89.64", referrer: "http://77.245.89.64/project/maarten-offline-demo/us/68"

You might note differences in IP addresses/host names, this is due to the vlan migration.
Due to time outs I moved the server back to the old vlan, but that did not change anything.

The database was the next suspect, when I noticed the problems are project specific. I did not stop the database before updating Ubuntu, as I never had problems with MySQL and updates and expected the database would be shut down automatically if needed.
So I made a pg_dump and imported that to the test server. Now the test server has exactly the same problems.
I don't think the database is corrupt, as it is possible to make changes to the issue via the Django administration, only not via Taiga. Later the change was visible in Taiga.
To check I opened the database in a SQL browser and the row looks fine:
"76";"{taiga}";8;FALSE;"''";85;"2015-02-06 11:02:47.456532+01";"2015-02-09 15:12:44.82861+01";"";"Emoticons show as Picture not found";"''";15;;17;20;7;32;44;19;""

The userstories_userstory table also looks fine in the sql browser. Perhaps I should search elsewhere in the database? Maybe there are inconsistencies between certain tables, that cause the problem.

A pg_dumpall is made daily. I could restore the old database or even restore the whole virtual machine, and suspect that will solve the problem. But maybe others have an idea how to restore functionality without losing a few hours of data?

After this experience I wonder if I should manually stop Taiga and or postgres before updating or doing things that might interrupt connectivity. As I am still uncertain of the cause of this problem.

Thanks in advance,

Maarten.

[Alejandro Alonso]

Hello Taiga group.

Hello Maarten!,

The WARNING and ERROR about css are not "serious", it's complaining about the format of the outgoing email, we also have that kind of logs in our server, the worker timeout is the bad one.

 

Saw the following message several times in the nginx.error.log:

2015/02/17 16:10:11 [error] 5966#0: *19 upstream prematurely closed connection while reading response header from upstream, client: 185.22.192.11, server: _, request: "POST /api/v1/users/password_recovery HTTP/1.1", upstream: "http://127.0.0.1:8001/api/v1/users/password_recovery", host: "brasdv001.reliance.nl", referrer: "http://brasdv001.reliance.nl/forgot-password"

So I added "fastcgi_read_timeout 150;" to the /etc/nginx/sites-enables/taiga file, which gives a new error message in the nginx log:

2015/02/17 14:20:36 [error] 1009#0: *1086 upstream timed out (110: Connection timed out) while reading response header from upstream, client: 185.22.192.11, server: _, request: "PATCH /api/v1/issues/76 HTTP/1.1", upstream: "http://127.0.0.1:8001/api/v1/issues/76", host: "77.245.89.64", referrer: "http://77.245.89.64/project/admin-rascore/issue/85"
2015/02/17 15:11:12 [error] 1022#0: *1 upstream timed out (110: Connection timed out) while reading response header from upstream, client: 185.22.192.11, server: _, request: "PATCH /api/v1/userstories/246 HTTP/1.1", upstream: "http://127.0.0.1:8001/api/v1/userstories/246", host: "77.245.89.64", referrer: "http://77.245.89.64/project/maarten-offline-demo/us/68"

You might note differences in IP addresses/host names, this is due to the vlan migration.
Due to time outs I moved the server back to the old vlan, but that did not change anything.

The database was the next suspect, when I noticed the problems are project specific. I did not stop the database before updating Ubuntu, as I never had problems with MySQL and updates and expected the database would be shut down automatically if needed.
So I made a pg_dump and imported that to the test server. Now the test server has exactly the same problems.
I don't think the database is corrupt, as it is possible to make changes to the issue via the Django administration, only not via Taiga. Later the change was visible in Taiga.
To check I opened the database in a SQL browser and the row looks fine:
"76";"{taiga}";8;FALSE;"''";85;"2015-02-06 11:02:47.456532+01";"2015-02-09 15:12:44.82861+01";"";"Emoticons show as Picture not found";"''";15;;17;20;7;32;44;19;""

The userstories_userstory table also looks fine in the sql browser. Perhaps I should search elsewhere in the database? Maybe there are inconsistencies between certain tables, that cause the problem.

A pg_dumpall is made daily. I could restore the old database or even restore the whole virtual machine, and suspect that will solve the problem. But maybe others have an idea how to restore functionality without losing a few hours of data?

After this experience I wonder if I should manually stop Taiga and or postgres before updating or doing things that might interrupt connectivity. As I am still uncertain of the cause of this problem.

It doesn't sound like a database problem, I think it could be related to your email configuration, in some projects there could be notifications that need to be sent that are failing. What's your email configuration?. 

Taiga can send notification emails in an asynchronous way, you could the following setting in your local.py:

CHANGE_NOTIFICATIONS_MIN_INTERVAL = 10 #seconds

With this settings notification only will be sent when you manually call "python manage.py send_notifications" (we call it from a crontab entry). If enabling it your modifications work again it means you have a problem with your email settings.

Regards,

--

Alejandro Alonso Fernández   CIO & Co-founder alejandr...@kaleidos.net  | Tel: (+34) 627263808 | (+34) 913562995 www.kaleidos.net/FC8EAC/

[MaH Relinace]

Hi Alejandro,

I would never have guessed that to be the cause, thanks!

Luckily the worker time out is only on the test server, I might have to look at this later. Currently the tail of the gunicorn.sterr.log looks better on the test server:

Trying import local.py settings...
Monkey patching...
Trying import local.py settings...
Monkey patching...
Trying import local.py settings...
Monkey patching...
Trying import local.py settings...
Monkey patching...
Trying import local.py settings...
Monkey patching...

On both servers the mail part of the local.py now looks like this:

CHANGE_NOTIFICATIONS_MIN_INTERVAL = 10 #seconds
DEFAULT_FROM_EMAIL = "obsc...@forGoogle.groups"
SERVER_EMAIL = DEFAULT_FROM_EMAIL

# Uncomment and populate with proper connection parameters
# for enable email sending.
EMAIL_BACKEND = "django.core.mail.backends.smtp.EmailBackend"
EMAIL_USE_TLS = False
EMAIL_HOST = "192.168.145.33"
#EMAIL_HOST_USER = ""
#EMAIL_HOST_PASSWORD = ""
EMAIL_PORT = 25

And from the moment the "CHANGE_NOTIFICATIONS_MIN_INTERVAL = 10 #seconds" line was applied, the problem was solved. This is great!

Some additional steps were required to get this to work.
manage.py can't find the cssutils module:

taiga@brasDV001:~/taiga-back$ python manage.py send_notifications
Traceback (most recent call last):
  File "manage.py", line 8, in <module>
    from django.core.management import execute_from_command_line
ImportError: No module named django.core.management
taiga@brasDV001:~/taiga-back$ workon taiga
(taiga)taiga@brasDV001:~/taiga-back$ python manage.py send_notifications

Trying import local.py settings...
Monkey patching...

Traceback (most recent call last):
  File "manage.py", line 10, in <module>
    execute_from_command_line(sys.argv)
  File "/home/taiga/.virtualenvs/taiga/lib/python3.4/site-packages/django/core/management/__init__.py", line 385, in execute_from_command_line
    utility.execute()
  File "/home/taiga/.virtualenvs/taiga/lib/python3.4/site-packages/django/core/management/__init__.py", line 377, in execute
    self.fetch_command(subcommand).run_from_argv(self.argv)
  File "/home/taiga/.virtualenvs/taiga/lib/python3.4/site-packages/django/core/management/base.py", line 288, in run_from_argv
    self.execute(*args, **options.__dict__)
  File "/home/taiga/.virtualenvs/taiga/lib/python3.4/site-packages/django/core/management/base.py", line 338, in execute
    output = self.handle(*args, **options)
  File "/home/taiga/taiga-back/taiga/projects/notifications/management/commands/send_notifications.py", line 29, in handle
    send_sync_notifications(change_notification.pk)
  File "/home/taiga/.virtualenvs/taiga/lib/python3.4/site-packages/django/db/transaction.py", line 394, in inner
    return func(*args, **kwargs)
  File "/home/taiga/taiga-back/taiga/projects/notifications/services.py", line 265, in send_sync_notifications
    email.send(user.email, context)
  File "/home/taiga/.virtualenvs/taiga/lib/python3.4/site-packages/djmail/template_mail.py", line 149, in send
    email = self.make_email_object(to, context, **kwargs)
  File "/home/taiga/.virtualenvs/taiga/lib/python3.4/site-packages/djmail/template_mail.py", line 144, in make_email_object
    self._attach_body_to_email_instance(email, context)
  File "/home/taiga/.virtualenvs/taiga/lib/python3.4/site-packages/djmail/template_mail.py", line 124, in _attach_body_to_email_instance
    body_html = self._render_message_body_as_html(context)
  File "/home/taiga/.virtualenvs/taiga/lib/python3.4/site-packages/djmail/template_mail.py", line 157, in _render_message_body_as_html
    import premailer
  File "/home/taiga/.virtualenvs/taiga/lib/python3.4/site-packages/premailer/__init__.py", line 2, in <module>
    from .premailer import Premailer, transform
  File "/home/taiga/.virtualenvs/taiga/lib/python3.4/site-packages/premailer/premailer.py", line 32, in <module>
    import cssutils
ImportError: No module named 'cssutils'

So I installed cssutils through easy_install:

taiga@brasDV001:~/.virtualenvs/taiga/lib/python3.4/site-packages$ workon taiga

And hit the next missing module "cssselect". After installing it with pip things look better:

(taiga)taiga@brasDV001:~/taiga-back$ python /home/taiga/taiga-back/manage.py send_notifications

Trying import local.py settings...
Monkey patching...
WARNING    Property: Unknown Property name. [6:51: -webkit-text-size-adjust]

...
TimeoutError: [Errno 110] Connection timed out

The move to the other vlan was the cause, moving the server back did not help. Taiga was probably waiting and not trying again.
In the new vlan the mail relay is not accessible. I can't ping or telnet it.

After the mail relay is available in the new vlan, I will post another message here stating if the problem is completely solved, but for now I think this is the solution.
Thanks again for the great support!!

Regards,

Maarten.

Op donderdag 19 februari 2015 07:23:50 UTC+1 schreef Alejandro Alonso:

2015/02/17 16:10:11 [error] 5966#0: *19 upstream prematurely closed connection while reading response header from upstream, client: 185.22.192.11, server: _, request: "POST /api/v1/users/password_recovery HTTP/1.1", upstream: "http://127.0.0.1:8001/api/v1/users/password_recovery - private", host: "brasdv001.reliance.nl - private", referrer: "http://brasdv001.reliance.nl/forgot-password - private"

So I added "fastcgi_read_timeout 150;" to the /etc/nginx/sites-enables/taiga file, which gives a new error message in the nginx log:

2015/02/17 14:20:36 [error] 1009#0: *1086 upstream timed out (110: Connection timed out) while reading response header from upstream, client: 185.22.192.11, server: _, request: "PATCH /api/v1/issues/76 HTTP/1.1", upstream: "http://127.0.0.1:8001/api/v1/issues/76 - private", host: "77.245.89.64", referrer: "http://77.245.89.64/project/admin-rascore/issue/85 - private"
2015/02/17 15:11:12 [error] 1022#0: *1 upstream timed out (110: Connection timed out) while reading response header from upstream, client: 185.22.192.11, server: _, request: "PATCH /api/v1/userstories/246 HTTP/1.1", upstream: "http://127.0.0.1:8001/api/v1/userstories/246 - private", host: "77.245.89.64", referrer: "http://77.245.89.64/project/maarten-offline-demo/us/68 - private"

You might note differences in IP addresses/host names, this is due to the vlan migration.
Due to time outs I moved the server back to the old vlan, but that did not change anything.

The database was the next suspect, when I noticed the problems are project specific. I did not stop the database before updating Ubuntu, as I never had problems with MySQL and updates and expected the database would be shut down automatically if needed.
So I made a pg_dump and imported that to the test server. Now the test server has exactly the same problems.
I don't think the database is corrupt, as it is possible to make changes to the issue via the Django administration, only not via Taiga. Later the change was visible in Taiga.
To check I opened the database in a SQL browser and the row looks fine:
"76";"{taiga}";8;FALSE;"''";85;"2015-02-06 11:02:47.456532+01";"2015-02-09 15:12:44.82861+01";"";"Emoticons show as Picture not found";"''";15;;17;20;7;32;44;19;""

The userstories_userstory table also looks fine in the sql browser. Perhaps I should search elsewhere in the database? Maybe there are inconsistencies between certain tables, that cause the problem.

A pg_dumpall is made daily. I could restore the old database or even restore the whole virtual machine, and suspect that will solve the problem. But maybe others have an idea how to restore functionality without losing a few hours of data?

After this experience I wonder if I should manually stop Taiga and or postgres before updating or doing things that might interrupt connectivity. As I am still uncertain of the cause of this problem.

It doesn't sound like a database problem, I think it could be related to your email configuration, in some projects there could be notifications that need to be sent that are failing. What's your email configuration?. 

Taiga can send notification emails in an asynchronous way, you could the following setting in your local.py:

CHANGE_NOTIFICATIONS_MIN_INTERVAL = 10 #seconds

With this settings notification only will be sent when you manually call "python manage.py send_notifications" (we call it from a crontab entry). If enabling it your modifications work again it means you have a problem with your email settings.

Regards,

--

Alejandro Alonso Fernández   CIO & Co-founder alejandr...@kaleidos.net  | Tel: (+34) 627263808 | (+34) 913562995

www.kaleidos.net/FC8EAC/ - private  - private

[MaH Relinace]

For those who might reference this in the future, the former post contains a c/p mistake. The command to install cssutils is.

pip install cssutils

[Alejandro Alonso]

Hi Alejandro,

I would never have guessed that to be the cause, thanks!

You are welcome!, I'm very glad we finally found the issue

 

Luckily the worker time out is only on the test server, I might have to look at this later. Currently the tail of the gunicorn.sterr.log looks better on the test server:

Trying import local.py settings...
Monkey patching...
Trying import local.py settings...
Monkey patching...
Trying import local.py settings...
Monkey patching...
Trying import local.py settings...
Monkey patching...
Trying import local.py settings...
Monkey patching...

Cool! :)

Requirements.txt adds the premailer package and it install those dependancies:

pip show premailer                         
---
Name: premailer
Version: 2.8.1
Location: /home/superalex/Envs/taiga/lib/python3.4/site-packages
Requires: lxml, cssutils, cssselect

Probably there was some failure while you were installing the requirements and it couldn't complete totally

 

The move to the other vlan was the cause, moving the server back did not help. Taiga was probably waiting and not trying again.
In the new vlan the mail relay is not accessible. I can't ping or telnet it.

After the mail relay is available in the new vlan, I will post another message here stating if the problem is completely solved, but for now I think this is the solution.

Great!

 

Thanks again for the great support!!

You are welcome!, thanks for using Taiga :)

 

Regards,

Maarten.

Regards!,

[MaH Relinace]

Hey Alejandro,

Fix confirmed :->)

Regards,

Maarten

Op donderdag 19 februari 2015 17:33:11 UTC+1 schreef Alejandro Alonso:

www.kaleidos.net/FC8EAC/ - private  - private