Troubleshooting - django.db.utils.OperationalError: (1045, "Access denied for user 'openedx'@'172.21.0.9' (using password: YES)")

Bug description
After clean deployment and changing the docker-compose to remove the trailing “/”, I was able to get all the containers started. But when I try to access the default domain, I get 502 Bad Gateway

Environment
Windows 10 20H2
WSL2 - Ubuntu 20.04 LTS
tutor, version 12.1.6

Error Log:

❯ tutor local logs --tail=100 -f
docker-compose -f /home/<USER>/.local/share/tutor/env/local/docker-compose.yml -f /home/<USER>/.local/share/tutor/env/local/docker-compose.prod.yml --project-name tutor_local logs --follow --tail 100
tutor_local-nginx-1  | /docker-entrypoint.sh: /docker-entrypoint.d/ is not empty, will attempt to perform configuration
tutor_local-nginx-1  | /docker-entrypoint.sh: Looking for shell scripts in /docker-entrypoint.d/
tutor_local-nginx-1  | /docker-entrypoint.sh: Launching /docker-entrypoint.d/10-listen-on-ipv6-by-default.sh
tutor_local-nginx-1  | 10-listen-on-ipv6-by-default.sh: info: /etc/nginx/conf.d/default.conf is not a file or does not exist
tutor_local-nginx-1  | /docker-entrypoint.sh: Launching /docker-entrypoint.d/20-envsubst-on-templates.sh
tutor_local-smtp-1   | + sed -ri '
tutor_local-smtp-1   |  s/^#?(dc_local_interfaces)=.*/\1='\''[0.0.0.0]:25 ; [::0]:25'\''/;
tutor_local-smtp-1   |  s/^#?(dc_other_hostnames)=.*/\1='\'''\''/;
tutor_local-smtp-1   |  s/^#?(dc_relay_nets)=.*/\1='\''172.21.0.2\/16'\''/;
tutor_local-smtp-1   |  s/^#?(dc_eximconfig_configtype)=.*/\1='\''internet'\''/;
tutor_local-smtp-1   | ' /etc/exim4/update-exim4.conf.conf
tutor_local-nginx-1  | /docker-entrypoint.sh: Launching /docker-entrypoint.d/30-tune-worker-processes.sh
tutor_local-nginx-1  | /docker-entrypoint.sh: Configuration complete; ready for start up
tutor_local-nginx-1  | 172.21.0.7 - - [09/Nov/2021:05:14:41 +0000] http://local.overhang.io "GET / HTTP/1.1" 502 552 "-" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/95.0.4638.69 Safari/537.36" "172.21.0.1"
...
...
...
tutor_local-lms-1         |
tutor_local-lms-1         | Traceback (most recent call last):
tutor_local-cms-worker-1  |
tutor_local-lms-1         |   File "/openedx/venv/lib/python3.8/site-packages/django/db/backends/base/base.py", line 217, in ensure_connection
tutor_local-forum-1       | ERROR: ElasticSearch configuration validation failed. "rake search:validate_indices" failed with the following message: [404] {"error":{"root_cause":[{"type":"index_not_found_exception","reason":"no such index [comments]","resource.type":"index_or_alias","resource.id":"comments","index_uuid":"_na_","index":"comments"}],"type":"index_not_found_exception","reason":"no such index [comments]","resource.type":"index_or_alias","resource.id":"comments","index_uuid":"_na_","index":"comments"},"status":404}
tutor_local-forum-1       | Waiting for mongodb/elasticsearch...
tutor_local-forum-1       | 2021/11/09 05:40:00 Waiting for: tcp://mongodb:27017
tutor_local-forum-1       | 2021/11/09 05:40:00 Waiting for: http://elasticsearch:9200
tutor_local-forum-1       | 2021/11/09 05:40:00 Connected to tcp://mongodb:27017
tutor_local-forum-1       | 2021/11/09 05:40:00 Received 200 from http://elasticsearch:9200
tutor_local-forum-1       | W, [2021-11-09T05:40:01.808790 #16]  WARN -- : Overwriting existing field _id in class User.
tutor_local-mongodb-1     | 2021-11-09T05:39:06.303+0000 I NETWORK  [listener] connection accepted from 172.21.0.8:50312 #154 (4 connections now open)
tutor_local-mongodb-1     | 2021-11-09T05:39:06.303+0000 I NETWORK  [conn154] received client metadata from 172.21.0.8:50312 conn154: { driver: { name: "mongo-ruby-driver", version: "2.5.3" }, os: { type: "linux", name: "linux-gnu", architecture: "x86_64" }, platform: "mongoid-7.0.5, 2.5.7, x86_64-linux, x86_64-pc-linux-gnu" }
tutor_local-mongodb-1     | 2021-11-09T05:39:06.306+0000 I NETWORK  [listener] connection accepted from 172.21.0.8:50314 #155 (5 connections now open)
tutor_local-mongodb-1     | 2021-11-09T05:39:06.306+0000 I NETWORK  [conn155] received client metadata from 172.21.0.8:50314 conn155: { driver: { name: "mongo-ruby-driver", version: "2.5.3" }, os: { type: "linux", name: "linux-gnu", architecture: "x86_64" }, platform: "mongoid-7.0.5, 2.5.7, x86_64-linux, x86_64-pc-linux-gnu" }
tutor_local-mongodb-1     | 2021-11-09T05:39:06.315+0000 I NETWORK  [conn155] end connection 172.21.0.8:50314 (4 connections now open)
tutor_local-cms-worker-1  | User information: uid=0 euid=0 gid=0 egid=0
tutor_local-cms-worker-1  |
tutor_local-cms-worker-1  |   warnings.warn(RuntimeWarning(ROOT_DISCOURAGED.format(
tutor_local-cms-worker-1  | [2021-11-09 05:14:48,129: INFO/MainProcess] Connected to redis://redis:6379/0
tutor_local-cms-worker-1  | [2021-11-09 05:14:48,141: INFO/MainProcess] mingle: searching for neighbors
tutor_local-cms-worker-1  | [2021-11-09 05:14:49,173: INFO/MainProcess] mingle: all alone
tutor_local-cms-worker-1  | [2021-11-09 05:14:49,202: INFO/MainProcess] celery@edx.cms.core.default.%19ce8f3e3261 ready.
tutor_local-cms-1         | uWSGI http bound on 0.0.0.0:8000 fd 4
tutor_local-cms-1         | spawned uWSGI http 1 (pid: 8)
tutor_local-cms-1         | uwsgi socket 0 bound to TCP address 127.0.0.1:43303 (port auto-assigned) fd 3
tutor_local-cms-1         | uWSGI running as root, you can use --uid/--gid/--chroot options
tutor_local-cms-1         | *** WARNING: you are running uWSGI as root !!! (use the --uid flag) ***
tutor_local-cms-1         | Python version: 3.8.6 (default, Nov  2 2021, 09:52:24)  [GCC 9.3.0]
tutor_local-cms-1         | Python main interpreter initialized at 0x55b690e9a6b0
tutor_local-cms-1         | uWSGI running as root, you can use --uid/--gid/--chroot options
tutor_local-cms-1         | *** WARNING: you are running uWSGI as root !!! (use the --uid flag) ***
tutor_local-cms-1         | python threads support enabled
tutor_local-cms-1         | your server socket listen backlog is limited to 100 connections
tutor_local-cms-1         | your mercy for graceful operations on workers is 60 seconds
tutor_local-cms-1         | mapped 154032 bytes (150 KB) for 2 cores
tutor_local-cms-1         | *** Operational MODE: preforking ***
tutor_local-cms-1         | WSGI app 0 (mountpoint='') ready in 14 seconds on interpreter 0x55b690e9a6b0 pid: 7 (default app)
tutor_local-cms-1         | uWSGI running as root, you can use --uid/--gid/--chroot options
tutor_local-cms-1         | *** WARNING: you are running uWSGI as root !!! (use the --uid flag) ***
tutor_local-cms-1         | spawned uWSGI worker 1 (pid: 7, cores: 1)
tutor_local-lms-1         |     self.connect()
tutor_local-lms-1         |   File "/openedx/venv/lib/python3.8/site-packages/django/db/backends/base/base.py", line 195, in connect
tutor_local-lms-1         |     self.connection = self.get_new_connection(conn_params)
tutor_local-lms-1         |   File "/openedx/venv/lib/python3.8/site-packages/django/db/backends/mysql/base.py", line 227, in get_new_connection
tutor_local-lms-worker-1  | /openedx/venv/lib/python3.8/site-packages/celery/platforms.py:800: RuntimeWarning: You're running the worker with superuser privileges: this is
tutor_local-lms-worker-1  | absolutely not recommended!
tutor_local-lms-worker-1  |
tutor_local-lms-worker-1  | Please specify a different user using the --uid option.
tutor_local-lms-worker-1  |
tutor_local-lms-worker-1  | User information: uid=0 euid=0 gid=0 egid=0
tutor_local-lms-worker-1  |
tutor_local-lms-worker-1  |   warnings.warn(RuntimeWarning(ROOT_DISCOURAGED.format(
tutor_local-lms-worker-1  | 2021-11-09 05:14:48,246 INFO 1 [celery.worker.consumer.connection] [user None] [ip None] connection.py:24 - Connected to redis://redis:6379/0
tutor_local-lms-worker-1  | 2021-11-09 05:14:48,264 INFO 1 [celery.worker.consumer.mingle] [user None] [ip None] mingle.py:43 - mingle: searching for neighbors
tutor_local-lms-worker-1  | 2021-11-09 05:14:49,290 INFO 1 [celery.worker.consumer.mingle] [user None] [ip None] mingle.py:52 - mingle: all alone
tutor_local-lms-worker-1     | 2021-11-09 05:14:49,339 INFO 1 [celery.apps.worker] [user None] [ip None] worker.py:161 - celery@edx.lms.core.default.%b5cd51e12ee1 ready.
tutor_local-forum-1       | W, [2021-11-09T05:40:01.837345 #16]  WARN -- : MONGODB | Unsupported client option 'max_retries'. It will be ignored.
tutor_local-forum-1          | W, [2021-11-09T05:40:01.837410 #16]  WARN -- : MONGODB | Unsupported client option 'retry_interval'. It will be ignored.
tutor_local-forum-1          | W, [2021-11-09T05:40:01.837429 #16]  WARN -- : MONGODB | Unsupported client option 'timeout'. It will be ignored.
tutor_local-forum-1          | ERROR: ElasticSearch configuration validation failed. "rake search:validate_indices" failed with the following message: [404] {"error":{"root_cause":[{"type":"index_not_found_exception","reason":"no such index [comments]","resource.type":"index_or_alias","resource.id":"comments","index_uuid":"_na_","index":"comments"}],"type":"index_not_found_exception","reason":"no such index [comments]","resource.type":"index_or_alias","resource.id":"comments","index_uuid":"_na_","index":"comments"},"status":404}
tutor_local-forum-1          | Waiting for mongodb/elasticsearch...
tutor_local-forum-1          | 2021/11/09 05:40:53 Waiting for: tcp://mongodb:27017
tutor_local-forum-1          | 2021/11/09 05:40:53 Waiting for: http://elasticsearch:9200
tutor_local-forum-1          | 2021/11/09 05:40:53 Connected to tcp://mongodb:27017
tutor_local-forum-1          | 2021/11/09 05:40:53 Received 200 from http://elasticsearch:9200
tutor_local-forum-1          | W, [2021-11-09T05:40:54.900422 #17]  WARN -- : Overwriting existing field _id in class User.
tutor_local-mongodb-1     | 2021-11-09T05:39:11.366+0000 I NETWORK  [conn158] received client metadata from 172.21.0.8:50324 conn158: { driver: { name: "mongo-ruby-driver", version: "2.5.3" }, os: { type: "linux", name: "linux-gnu", architecture: "x86_64" }, platform: "mongoid-7.0.5, 2.5.7, x86_64-linux, x86_64-pc-linux-gnu" }
tutor_local-mongodb-1        | 2021-11-09T05:39:11.368+0000 I NETWORK  [listener] connection accepted from 172.21.0.8:50326 #159 (5 connections now open)
tutor_local-mongodb-1        | 2021-11-09T05:39:11.368+0000 I NETWORK  [conn159] received client metadata from 172.21.0.8:50326 conn159: { driver: { name: "mongo-ruby-driver", version: "2.5.3" }, os: { type: "linux", name: "linux-gnu", architecture: "x86_64" }, platform: "mongoid-7.0.5, 2.5.7, x86_64-linux, x86_64-pc-linux-gnu" }
tutor_local-elasticsearch-1  | {"type": "server", "timestamp": "2021-11-09T05:14:24,776Z", "level": "INFO", "component": "o.e.n.Node", "cluster.name": "openedx", "node.name": "749900cc3b01", "message": "JVM arguments [-Xshare:auto, -Des.networkaddress.cache.ttl=60, -Des.networkaddress.cache.negative.ttl=10, -XX:+AlwaysPreTouch, -Xss1m, -Djava.awt.headless=true, -Dfile.encoding=UTF-8, -Djna.nosys=true, -XX:-OmitStackTraceInFastThrow, -XX:+ShowCodeDetailsInExceptionMessages, -Dio.netty.noUnsafe=true, -Dio.netty.noKeySetOptimization=true, -Dio.netty.recycler.maxCapacityPerThread=0, -Dio.netty.allocator.numDirectArenas=0, -Dlog4j.shutdownHookEnabled=false, -Dlog4j2.disable.jmx=true, -Djava.locale.providers=SPI,COMPAT, -Xms1g, -Xmx1g, -XX:+UseG1GC, -XX:G1ReservePercent=25, -XX:InitiatingHeapOccupancyPercent=30, -Djava.io.tmpdir=/tmp/elasticsearch-10144792345139330572, -XX:+HeapDumpOnOutOfMemoryError, -XX:HeapDumpPath=data, -XX:ErrorFile=logs/hs_err_pid%p.log, -Xlog:gc*,gc+age=trace,safepoint:file=logs/gc.log:utctime,pid,tags:filecount=32,filesize=64m, -Des.cgroups.hierarchy.override=/, -Xms1g, -Xmx1g, -XX:MaxDirectMemorySize=536870912, -Des.path.home=/usr/share/elasticsearch, -Des.path.conf=/usr/share/elasticsearch/config, -Des.distribution.flavor=default, -Des.distribution.type=docker, -Des.bundled_jdk=true]" }
tutor_local-elasticsearch-1  | {"type": "server", "timestamp": "2021-11-09T05:14:29,530Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "openedx", "node.name": "749900cc3b01", "message": "loaded module [aggs-matrix-stats]" }
tutor_local-elasticsearch-1  | {"type": "server", "timestamp": "2021-11-09T05:14:29,544Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "openedx", "node.name": "749900cc3b01", "message": "loaded module [reindex]" }
tutor_local-cms-1         | spawned uWSGI worker 2 (pid: 129, cores: 1)
tutor_local-lms-1         |     return Database.connect(**conn_params)
tutor_local-lms-1            |   File "/openedx/venv/lib/python3.8/site-packages/MySQLdb/__init__.py", line 130, in Connect
tutor_local-lms-1            |     return Connection(*args, **kwargs)
tutor_local-elasticsearch-1  | {"type": "server", "timestamp": "2021-11-09T05:14:29,545Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "openedx", "node.name": "749900cc3b01", "message": "loaded module [repository-url]" }
tutor_local-elasticsearch-1  | {"type": "server", "timestamp": "2021-11-09T05:14:29,545Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "openedx", "node.name": "749900cc3b01", "message": "loaded module [search-business-rules]" }
tutor_local-lms-1            |   File "/openedx/venv/lib/python3.8/site-packages/MySQLdb/connections.py", line 185, in __init__
tutor_local-elasticsearch-1  | {"type": "server", "timestamp": "2021-11-09T05:14:29,546Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "openedx", "node.name": "749900cc3b01", "message": "loaded module [searchable-snapshots]" }
tutor_local-lms-1            |     super().__init__(*args, **kwargs2)
tutor_local-caddy-1          | {"level":"info","ts":1636434861.8913026,"msg":"using provided configuration","config_file":"/etc/caddy/Caddyfile","config_adapter":"caddyfile"}
tutor_local-caddy-1          | {"level":"info","ts":1636434861.8928695,"logger":"admin","msg":"admin endpoint started","address":"tcp/localhost:2019","enforce_origin":false,"origins":["localhost:2019","[::1]:2019","127.0.0.1:2019"]}
tutor_local-caddy-1          | {"level":"info","ts":1636434861.8930943,"logger":"http","msg":"server is listening only on the HTTP port, so no automatic HTTPS will be applied to this server","server_name":"srv0","http_port":80}
tutor_local-caddy-1          | {"level":"info","ts":1636434861.8932815,"logger":"tls.cache.maintenance","msg":"started background certificate maintenance","cache":"0xc00043b340"}
tutor_local-caddy-1          | {"level":"info","ts":1636434861.8936236,"logger":"tls","msg":"cleaned up storage units"}
tutor_local-caddy-1          | {"level":"info","ts":1636434861.8936782,"msg":"autosaved config","file":"/config/caddy/autosave.json"}
tutor_local-elasticsearch-1  | {"type": "server", "timestamp": "2021-11-09T05:14:29,546Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "openedx", "node.name": "749900cc3b01", "message": "loaded module [spatial]" }
tutor_local-elasticsearch-1  | {"type": "server", "timestamp": "2021-11-09T05:14:29,547Z", "level": "INFO", "component": "o.e.p.PluginsService", "cluster.name": "openedx", "node.name": "749900cc3b01", "message": "loaded module [tasks]" }
tutor_local-lms-1            | MySQLdb._exceptions.OperationalError: (1045, "Access denied for user 'openedx'@'172.21.0.9' (using password: YES)")
tutor_local-lms-1            |
tutor_local-lms-1            | The above exception was the direct cause of the following exception:
tutor_local-lms-1            |
tutor_local-lms-1            | Traceback (most recent call last):
tutor_local-lms-1            |   File "/openedx/venv/lib/python3.8/site-packages/django/core/handlers/wsgi.py", line 141, in __call__
tutor_local-lms-1            |     response = self.get_response(request)
tutor_local-lms-1            |   File "/openedx/venv/lib/python3.8/site-packages/django/core/handlers/base.py", line 75, in get_response
tutor_local-lms-1            |     response = self._middleware_chain(request)
tutor_local-lms-1            |   File "/openedx/venv/lib/python3.8/site-packages/django/core/handlers/exception.py", line 36, in inner
tutor_local-lms-1            |     response = response_for_exception(request, exc)
tutor_local-lms-1            |   File "/openedx/venv/lib/python3.8/site-packages/django/core/handlers/exception.py", line 90, in response_for_exception
tutor_local-lms-1            |     response = handle_uncaught_exception(request, get_resolver(get_urlconf()), sys.exc_info())
tutor_local-lms-1            |   File "/openedx/venv/lib/python3.8/site-packages/django/core/handlers/exception.py", line 129, in handle_uncaught_exception
tutor_local-lms-1            |     return callback(request, **param_dict)
tutor_local-lms-1            |   File "/openedx/edx-platform/common/djangoapps/util/views.py", line 95, in wrapper
tutor_local-forum-1          | W, [2021-11-09T05:40:54.932178 #17]  WARN -- : MONGODB | Unsupported client option 'max_retries'. It will be ignored.
tutor_local-forum-1          | W, [2021-11-09T05:40:54.932257 #17]  WARN -- : MONGODB | Unsupported client option 'retry_interval'. It will be ignored.
tutor_local-forum-1          | W, [2021-11-09T05:40:54.932280 #17]  WARN -- : MONGODB | Unsupported client option 'timeout'. It will be ignored.
tutor_local-forum-1          | ERROR: ElasticSearch configuration validation failed. "rake search:validate_indices" failed with the following message: [404] {"error":{"root_cause":[{"type":"index_not_found_exception","reason":"no such index [comments]","resource.type":"index_or_alias","resource.id":"comments","index_uuid":"_na_","index":"comments"}],"type":"index_not_found_exception","reason":"no such index [comments]","resource.type":"index_or_alias","resource.id":"comments","index_uuid":"_na_","index":"comments"},"status":404}
tutor_local-forum-1          | Waiting for mongodb/elasticsearch...
tutor_local-forum-1          | 2021/11/09 05:41:55 Waiting for: tcp://mongodb:27017
tutor_local-forum-1          | 2021/11/09 05:41:55 Waiting for: http://elasticsearch:9200
tutor_local-forum-1          | 2021/11/09 05:41:55 Connected to tcp://mongodb:27017
tutor_local-forum-1          | 2021/11/09 05:41:55 Received 200 from http://elasticsearch:9200
tutor_local-forum-1          | W, [2021-11-09T05:41:56.893418 #19]  WARN -- : Overwriting existing field _id in class User.
tutor_local-forum-1          | W, [2021-11-09T05:41:56.926201 #19]  WARN -- : MONGODB | Unsupported client option 'max_retries'. It will be ignored.
tutor_local-forum-1          | W, [2021-11-09T05:41:56.926279 #19]  WARN -- : MONGODB | Unsupported client option 'retry_interval'. It will be ignored.
tutor_local-forum-1          | W, [2021-11-09T05:41:56.926302 #19]  WARN -- : MONGODB | Unsupported client option 'timeout'. It will be ignored.
tutor_local-caddy-1          | {"level":"info","ts":1636434861.8936853,"msg":"serving initial configuration"}

Did you initialize the databases with tutor local init or tutor local quickstart?

Apologies for the delayed response.
In order to avoid issue 522 where my compose file kept being overwritten causing the containers to unable to start, I ran tutor local quickstart the first time then edited the compose files and ran tutor local start which resulted in this error.

Issue resolved. It seems like this was caused due to improper database initialization caused by bad docker-compose file(#522). But after testing it with a new pull request (#524), everything seems to be working as expected.

This topic was automatically closed 90 days after the last reply. New replies are no longer allowed.