502 Bad Gateway on LMS after fresh production install

[Benedict]

Hi everybody,

I've installed the production stack on a single t2.medium server on EC2, with the pre-packaged AMI (following these instructions). After the install, studio works fine, but both the LMS and [myurl.org]/admin give me a 

 

502 Bad Gateway
nginx/1.1.19

This also happens when I install the master branch (for edx-platform and configuration).

I'm not sure if it helps, but the log in /edx/var/log/nginx/error.log says:

2014/11/19 15:48:35 [error] 1065#0: *2551 connect() failed (111: Connection refused) while connecting to upstream, client: [...], server: , request: "GET / HTTP/1.1", upstream: "http://127.0.0.1:8000/", host: "[...]"

Does anybody know why this is and what is going on?

Thanks a lot!
Benedict

[Ali Hasan]

It looks like the LMS is not running, try to do

sudo /edx/bin/supervisorctl -c /edx/etc/supervisord.conf restart edxapp:

And then watch the logs, 

sudo tail -f `sudo find /edx/var/log -name "*.log"`

[Benedict]

Hi Ali,

Thanks a lot for your answer!

I restarted the LMS, and tailed the logs. The 502 error stays, and the logs give me a whole lot of errors:

==> /edx/var/log/nginx/error.log <==
2014/11/20 14:14:33 [error] 7095#0: *124738 connect() failed (111: Connection refused) while connecting to upstream, client: 123.123.123.123, server: , request: "GET / HTTP/1.1", upstream: "http://127.0.0.1:8000/", host: "321.321.321.321"
2014/11/20 14:14:35 [error] 7095#0: *124738 connect() failed (111: Connection refused) while connecting to upstream, client: 123.123.123.123, server: , request: "GET / HTTP/1.1", upstream: "http://127.0.0.1:8000/", host: "321.321.321.321"

==> /edx/var/log/xqueue/edx.log <==
Nov 20 14:17:30 ip-123-123-123-123 [service_variant=xqueue][pika.adapters.base_connection][env:sandbox] ERROR [ip-123-123-123-123  1747] [base_connection.py:260] - Socket Error on fd 15: 104
Nov 20 14:17:31 ip-123-123-123-123 [service_variant=xqueue][queue.management.commands.run_consumer][env:sandbox] INFO [ip-123-123-123-123  1267] [run_consumer.py:118] -  [8254] Worker failed
Nov 20 14:17:31 ip-123-123-123-123 [service_variant=xqueue][queue.management.commands.run_consumer][env:sandbox] INFO [ip-123-123-123-123  1267] [run_consumer.py:124] -  [8255] Starting worker
Nov 20 14:17:31 ip-123-123-123-123 [service_variant=xqueue][queue.consumer][env:sandbox] INFO [ip-123-123-123-123  17949] [consumer.py:270] -  [8255] Starting consumer for queue edX-Open_DemoX

==> /edx/var/log/supervisor/lmstderr.log <==
    auth.authenticate(credentials, sock_info, self.__simple_command)
  File "/edx/app/edxapp/venvs/edxapp/local/lib/python2.7/site-packages/pymongo/auth.py", line 243, in authenticate
    auth_func(credentials[1:], sock_info, cmd_func)
  File "/edx/app/edxapp/venvs/edxapp/local/lib/python2.7/site-packages/pymongo/auth.py", line 222, in _authenticate_mongo_cr
    cmd_func(sock_info, source, query)
  File "/edx/app/edxapp/venvs/edxapp/local/lib/python2.7/site-packages/pymongo/mongo_client.py", line 693, in __simple_command
    helpers._check_command_response(response, None, msg)
  File "/edx/app/edxapp/venvs/edxapp/local/lib/python2.7/site-packages/pymongo/helpers.py", line 178, in _check_command_response
    raise OperationFailure(msg % errmsg, code, response)
pymongo.errors.OperationFailure: command SON([('authenticate', 1), ('user', u'edxapp'), ('nonce', u'123ABC123ABC'), ('key', u'123ABC123ABC123')]) failed: auth fails

==> /edx/var/log/supervisor/xqueue_consumertderr.log <==
    return self._handle_error(error)
  File "/edx/app/xqueue/venvs/xqueue/src/pika/pika/adapters/base_connection.py", line 263, in _handle_error
    self._handle_disconnect()
  File "/edx/app/xqueue/venvs/xqueue/src/pika/pika/adapters/base_connection.py", line 212, in _handle_disconnect
    self._adapter_disconnect()
  File "/edx/app/xqueue/venvs/xqueue/src/pika/pika/adapters/base_connection.py", line 126, in _adapter_disconnect
    self._check_state_on_disconnect()
  File "/edx/app/xqueue/venvs/xqueue/src/pika/pika/adapters/base_connection.py", line 141, in _check_state_on_disconnect
    raise exceptions.ProbableAuthenticationError
ProbableAuthenticationError

==> /edx/var/log/supervisor/certstderr.log <==
    if manager.get_length() == 0:
  File "/edx/app/certs/certificates/queue.py", line 59, in get_length
    response = json.loads(request.text)
  File "/usr/lib/python2.7/json/__init__.py", line 326, in loads
    return _default_decoder.decode(s)
  File "/usr/lib/python2.7/json/decoder.py", line 366, in decode
    obj, end = self.raw_decode(s, idx=_w(s, 0).end())
  File "/usr/lib/python2.7/json/decoder.py", line 384, in raw_decode
    raise ValueError("No JSON object could be decoded")
ValueError: No JSON object could be decoded

==> /edx/var/log/xqueue/edx.log <==
Nov 20 14:17:32 ip-123-123-123-123 [service_variant=xqueue][pika.adapters.base_connection][env:sandbox] ERROR [ip-123-123-123-123  1745] [base_connection.py:260] - Socket Error on fd 13: 104
Nov 20 14:17:32 ip-123-123-123-123 [service_variant=xqueue][pika.adapters.base_connection][env:sandbox] ERROR [ip-123-123-123-123  1745] [base_connection.py:260] - Socket Error on fd 13: 104
Nov 20 14:17:32 ip-123-123-123-123 [service_variant=xqueue][django.request][env:sandbox] ERROR [ip-123-123-123-123  1745] [base.py:213] - Internal Server Error: /xqueue/get_queuelen/
Traceback (most recent call last):
  File "/edx/app/xqueue/venvs/xqueue/local/lib/python2.7/site-packages/django/core/handlers/base.py", line 109, in get_response
    response = callback(request, *callback_args, **callback_kwargs)
  File "/edx/app/xqueue/venvs/xqueue/local/lib/python2.7/site-packages/django/contrib/auth/decorators.py", line 20, in _wrapped_view
    return view_func(request, *args, **kwargs)
  File "/edx/app/xqueue/venvs/xqueue/local/lib/python2.7/site-packages/statsd.py", line 97, in wrapped
    result = func(*args, **kwargs)
  File "/edx/app/xqueue/xqueue/queue/ext_interface.py", line 39, in get_queuelen
    job_count = queue.producer.get_queue_length(queue_name)
  File "/edx/app/xqueue/xqueue/queue/producer.py", line 62, in get_queue_length
    return push_to_queue(queue_name)
  File "/edx/app/xqueue/xqueue/queue/producer.py", line 37, in push_to_queue
    raise e
AMQPConnectionError: (0, 'Not specified')

==> /edx/var/log/xqueue/edx.log <==
Nov 20 14:17:33 ip-123-123-123-123 [service_variant=xqueue][pika.adapters.base_connection][env:sandbox] ERROR [ip-123-123-123-123  1746] [base_connection.py:260] - Socket Error on fd 14: 104

==> /edx/var/log/xqueue/edx.log <==
Nov 20 14:17:33 ip-123-123-123-123 [service_variant=xqueue][pika.adapters.base_connection][env:sandbox] ERROR [ip-123-123-123-123  1747] [base_connection.py:260] - Socket Error on fd 15: 104
Nov 20 14:17:34 ip-123-123-123-123 [service_variant=xqueue][pika.adapters.base_connection][env:sandbox] ERROR [ip-123-123-123-123  17949] [base_connection.py:139] - Socket closed while authenticating indicating a probable authentication error
Nov 20 14:17:34 ip-123-123-123-123 [service_variant=xqueue][pika.adapters.base_connection][env:sandbox] ERROR [ip-123-123-123-123  17949] [base_connection.py:139] - Socket closed while authenticating indicating a probable authentication error
Nov 20 14:17:34 ip-123-123-123-123 [service_variant=xqueue][queue.consumer][env:sandbox] ERROR [ip-123-123-123-123  17949] [consumer.py:278] - [8255] Consumer for queue edX-Open_DemoX connection error:
Nov 20 14:17:34 ip-123-123-123-123 [service_variant=xqueue][queue.consumer][env:sandbox] INFO [ip-123-123-123-123  17949] [consumer.py:287] -  [8255] Consumer for queue edX-Open_DemoX stopped

==> /edx/var/log/supervisor/xqueue_consumertderr.log <==
Process Worker-8256:
Traceback (most recent call last):
  File "/usr/lib/python2.7/multiprocessing/process.py", line 258, in _bootstrap
    self.run()
  File "/edx/app/xqueue/xqueue/queue/consumer.py", line 275, in run
    self.connection.ioloop.start()
  File "/edx/app/xqueue/venvs/xqueue/src/pika/pika/adapters/select_connection.py", line 101, in start
    self.poller.start()
  File "/edx/app/xqueue/venvs/xqueue/src/pika/pika/adapters/select_connection.py", line 385, in start
    self.poll()
  File "/edx/app/xqueue/venvs/xqueue/src/pika/pika/adapters/select_connection.py", line 440, in poll
    self._handler(fileno, event, write_only=write_only)
  File "/edx/app/xqueue/venvs/xqueue/src/pika/pika/adapters/base_connection.py", line 283, in _handle_events
    self._handle_read()
  File "/edx/app/xqueue/venvs/xqueue/src/pika/pika/adapters/base_connection.py", line 299, in _handle_read
    return self._handle_error(error)
  File "/edx/app/xqueue/venvs/xqueue/src/pika/pika/adapters/base_connection.py", line 263, in _handle_error
    self._handle_disconnect()
  File "/edx/app/xqueue/venvs/xqueue/src/pika/pika/adapters/base_connection.py", line 212, in _handle_disconnect
    self._adapter_disconnect()
  File "/edx/app/xqueue/venvs/xqueue/src/pika/pika/adapters/base_connection.py", line 126, in _adapter_disconnect
    self._check_state_on_disconnect()
  File "/edx/app/xqueue/venvs/xqueue/src/pika/pika/adapters/base_connection.py", line 141, in _check_state_on_disconnect
    raise exceptions.ProbableAuthenticationError
ProbableAuthenticationError

==> /edx/var/log/supervisor/lmstderr.log <==
Traceback (most recent call last):
  File "/edx/app/edxapp/venvs/edxapp/bin/gunicorn", line 9, in <module>
[...]
pymongo.errors.OperationFailure: command SON([('authenticate', 1), ('user', u'edxapp'), ('nonce', u'123ABC123ABC'), ('key', u'123ABC123ABC123')]) failed: auth fails

Also, when I call 

sudo /edx/bin/supervisorctl -c /edx/etc/supervisord.conf status edxapp:

it switches between telling me that the LMS is running, and that it is starting.

Any insights?

Thanks a lot!
Benedict

[Ali Hasan]

As a start the main issue is 

  File "/edx/app/edxapp/venvs/edxapp/local/lib/python2.7/site-packages/pymongo/helpers.py", line 178, in_check_command_response
    raise OperationFailure(msg % errmsg, code, response)


pymongo.errors.OperationFailure: command SON([('authenticate', 1), ('user', u'edxapp'), ('nonce', u'123ABC123ABC'), ('key',u'123ABC123ABC123')]) failed: auth fails


Let us work on that.

--

Ali Hasan

Software Engineer, Edraak.org

Queen Rania Foundation

for Education & Development

T +962 6 4016464  Ext.701

M +962 7 88450926

E aha...@qrf.org

Confidentiality Notice:

This e-mail and attached electronic document(s) is/are intended for the above named person(s) only and may contain confidential and/or privilege information. This entire electronic transmission may not be used by anyone who is not the original intended recipient(s). Any review, print, copy, reliance or distribution by others or forwarding without explicit permission is strictly prohibited. If you have received this email in error, kindly notify the sender immediately by reply email and delete this email and any attachment(s) from your mailbox and/or any other storage mechanism. Karajah & Associates Law Firm  can not guarantee that this message is free from any harmful computer viruses and/or any other malicious programs which may harm the recipient's computer.

[Ali Hasan]

Run the mongo ansible role again :-

cd /edx/app/edx_ansible/edx_ansible/playbooks && sudo /edx/app/edx_ansible/venvs/edx_ansible/bin/ansible-playbook -i localhost, -c local run_role.yml -e 'role=mongo' -e 'mongo_create_users=True'

[Benedict]

Hi Ali,

That solved it - fantastic! Should I update the instructions page?

Also, do you have any good pointers as to what read up on so that I can solve such a problem myself next time around?

Thanks a lot for your help!

Benedict

...

[Ali Hasan]

The instructions is fine. The thing needed to be done is to rebuild the AWS AMI's to include the latest updates. And I think the edx Ops already knows about it.

[Sarina Canelake]

I just ran into this issue today on a fresh install; the command

cd /edx/app/edx_ansible/edx_ansible/playbooks && sudo /edx/app/edx_ansible/venvs/edx_ansible/bin/ansible-playbook -i localhost, -c local run_role.yml -e 'role=mongo' -e 'mongo_create_users=True'

did fix things for me. This is on a "vagrant destroy; vagrant up --provision" fresh re-install. :(

So - should instructions be updated if this is now a necessary step? 

[porta...@gmail.com]

Thanks Ali!

cd /edx/app/edx_ansible/edx_ansible/playbooks && sudo /edx/app/edx_ansible/venvs/edx_ansible/bin/ansible-playbook -i localhost, -c local run_role.yml -e 'role=mongo' -e 'mongo_create_users=True'

Can confirm the above solves problems with LMS when following the instructions on AWS installation.

[Arizka Dikson]

Hi,

I'm facing the same problem and tried to run the mongo ansible role as per instruction above, but it turns out I'm facing this error:

TASK: [mongo | create super user with js] ************************************* 

failed: [localhost] => {"changed": true, "cmd": "/usr/bin/mongo admin /tmp/create_root.js\n ", "delta": "0:00:00.007581", "end": "2015-03-23 10:28:45.812864", "item": "", "rc": 1, "start": "2015-03-23 10:28:45.805283"}

stderr: Failed global initialization: BadValue Invalid or no user locale set. Please ensure LANG and/or LC_* environment variables are set correctly.

FATAL: all hosts have already failed -- aborting

PLAY RECAP ******************************************************************** 

           to retry, use: --limit @/home/ubuntu/run_role.retry

localhost                  : ok=36   changed=3    unreachable=0    failed=1   

Does anybody know how to resolve this problem? thanks.

...

[dm...@cloudera.com]

Hello,

I've got the same issue as Arizka exactly. I'm on a pristine instance on EC2 that was derived from the standard AMI ami-ad161ee8, and I followed the steps to apply the Stanford theme from git. After running 

sudo /edx/bin/update edx-platform master

The LMS service starts, but the browser interface shows "502 Bad Gateway".

Running this command... 

cd /edx/app/edx_ansible/edx_ansible/playbooks && sudo /edx/app/edx_ansible/venvs/edx_ansible/bin/ansible-playbook -i localhost, -c local run_role.yml -e 'role=mongo' -e 'mongo_create_users=True'

does not work. The error is ...

TASK: [common | Install python-pycurl] **************************************** 

failed: [localhost] => {"failed": true, "item": "", "parsed": false}

invalid output was: SUDO-SUCCESS-plajezabntaeusrfoihjjaqyzwfdijsv

Traceback (most recent call last):

  File "/home/ubuntu/.ansible/tmp/ansible-tmp-1436480144.42-266220677225155/apt", line 1565, in <module>

    main()

  File "/home/ubuntu/.ansible/tmp/ansible-tmp-1436480144.42-266220677225155/apt", line 437, in main

    cache.update()

  File "/usr/lib/python2.7/dist-packages/apt/deprecation.py", line 98, in deprecated_function

    return func(*args, **kwds)

  File "/usr/lib/python2.7/dist-packages/apt/cache.py", line 441, in update

    raise FetchFailedException(e)

apt.cache.FetchFailedException: W:Failed to fetch http://archive.ubuntu.com/ubuntu/dists/maverick/main/source/Sources  404  Not Found [IP: 91.189.91.13 80]

, W:Failed to fetch http://archive.ubuntu.com/ubuntu/dists/maverick/restricted/source/Sources  404  Not Found [IP: 91.189.91.13 80]

, W:Failed to fetch http://archive.ubuntu.com/ubuntu/dists/maverick/universe/source/Sources  404  Not Found [IP: 91.189.91.13 80]

, W:Failed to fetch http://archive.ubuntu.com/ubuntu/dists/maverick/main/binary-amd64/Packages  404  Not Found [IP: 91.189.91.13 80]

, W:Failed to fetch http://archive.ubuntu.com/ubuntu/dists/maverick/restricted/binary-amd64/Packages  404  Not Found [IP: 91.189.91.13 80]

, W:Failed to fetch http://archive.ubuntu.com/ubuntu/dists/maverick/universe/binary-amd64/Packages  404  Not Found [IP: 91.189.91.13 80]

, W:Failed to fetch http://archive.ubuntu.com/ubuntu/dists/maverick/main/binary-i386/Packages  404  Not Found [IP: 91.189.91.13 80]

, W:Failed to fetch http://archive.ubuntu.com/ubuntu/dists/maverick/restricted/binary-i386/Packages  404  Not Found [IP: 91.189.91.13 80]

, W:Failed to fetch http://archive.ubuntu.com/ubuntu/dists/maverick/universe/binary-i386/Packages  404  Not Found [IP: 91.189.91.13 80]

, E:Some index files failed to download. They have been ignored, or old ones used instead.

FATAL: all hosts have already failed -- aborting

Any ideas?

Dave

...

[Rafael Bacchi Martinez]

I'm also experiencing the same error when updating the platform and the mongo asible also fails.

...

[ali hasan]

​ Make sure you are on ubuntu 12.04, and do

sudo apt-get update && sudo apt-get upgrade

before the update, and I wouldn't recommend using the master branch. use the latest stable branch or named release instead check https://openedx.atlassian.net/wiki/display/OPEN/Named+Releases

sudo /edx/bin/update edx-platform named-release/cypress.rc2

...