latenighttales/alcali

Unable to login as admin or anything else

mlcpap opened this issue · 6 comments

Describe the bug
I am unable to login as the admin after installing alcali as a salt formula onto a new salt-master running 3004.1.

To Reproduce
Attempt to login via web browser and get invalid login error in red.

Expected behavior
Successful login

Desktop (please complete the following information):

  • OS: Windows 10 21H2
  • Browser: Chrome 98.0.4758.102

Additional context
Server OS is the latest release of Almalinux as of this date.
I found no alcali command but created a shell script containing this as a shortcut:
ENV_PATH=/opt/alcali /opt/alcali/.venv/bin/python3 /opt/alcali/code/manage.py "$@"

alcali check works, as does changepassword, createsuperuser, etc. And the db has the extra tables created by alcali in addition to the default ones needed for salt. Salt is also actively populating that db.

I have tried with and without LDAP, but my current obfuscated .env shows:
AUTH_BACKEND="ldap"
DB_BACKEND="mysql"
DB_NAME="salt"
DB_USER="alcali"
DB_PASS="dbpassword"
DB_HOST="localhost"
DB_PORT="3306"
MASTER_MINION_ID="saltmaster.dom.pri"
SECRET_KEY="thisisnotagoodsecret.orisit?"
ALLOWED_HOSTS=""
SALT_URL="https://saltmaster.dom.pri:8080"
SALT_AUTH="alcali"
AUTH_LDAP_SERVER_URI="ldaps://ad.dom.ctrl.dom.pri"
AUTH_LDAP_USER_BASE_CN="dc=dom,dc=pri"
AUTH_LDAP_USER_SEARCH_FILTER="(objectClass=
)"
AUTH_LDAP_BIND_DN="FullDN of LDAP query user"
AUTH_LDAP_BIND_PASSWORD="binddn_password"

Removing AUTH_BACKEND or setting to "None" has the same effect.
Also, fwiw, my salt formula is being picked up and applied but the /srv/pillar/alcali.sls file appears to not get used at all.
In there I am attempting to install the latest version 3003.2.
I have had to adjust some of the pkg installs since we are also using Percona instead of mysqld or mariadb. But the db does appear to be working otherwise.

I added the following to my .env
AUTH_LDAP_USER_SEARCH_FILTER=(sAMAccountName=%(user)s)

and I edited /etc/systemd/system/alcali.service to enable logging to syslog:
ExecStart=/opt/alcali/.venv/bin/gunicorn --log-syslog config.wsgi:application --bind 0.0.0.0:5000 -w 4 -t 300

And now I see the following in /var/log/messages when I attempt to login as my AD user:
Feb 25 08:17:56 saltmaster alcali[116437]: search_s('OU=IT,DC=dom,DC=pri', 2, '(sAMAccountName=%(user)s)') returned 1 objects: cn=first.last,ou=it,dc=dom,dc=pri
Feb 25 08:17:56 saltmaster alcali[116437]: Populating Django user first.last

I ran alcali dbshell and manually updated the db so that my user is_staff=1.

However, I still get the "Invalid Login / Password" message. This might be because of a logging error. Not sure if this was introduced by the fact that I am logging at all now and it also wants access log and error log defined for the django instance. This is not logged every time, and perhaps only after the 3rd or 4th time I try to login:

Feb 25 08:21:22 saltmaster alcali[116437]: --- Logging error ---
Feb 25 08:21:22 saltmaster alcali[116437]: Traceback (most recent call last):
Feb 25 08:21:22 saltmaster alcali[116437]: File "/usr/lib64/python3.6/logging/handlers.py", line 942, in emit
Feb 25 08:21:22 saltmaster alcali[116437]: self.socket.sendto(msg, self.address)
Feb 25 08:21:22 saltmaster alcali[116437]: OSError: [Errno 9] Bad file descriptor
Feb 25 08:21:22 saltmaster alcali[116437]: Call stack:
Feb 25 08:21:22 saltmaster alcali[116437]: File "/opt/alcali/.venv/bin/gunicorn", line 8, in
Feb 25 08:21:22 saltmaster alcali[116437]: sys.exit(run())
Feb 25 08:21:22 saltmaster alcali[116437]: File "/opt/alcali/.venv/lib/python3.6/site-packages/gunicorn/app/wsgiapp.py", line 58, in run
Feb 25 08:21:22 saltmaster alcali[116437]: WSGIApplication("%(prog)s [OPTIONS] [APP_MODULE]").run()
Feb 25 08:21:22 saltmaster alcali[116437]: File "/opt/alcali/.venv/lib/python3.6/site-packages/gunicorn/app/base.py", line 228, in run
Feb 25 08:21:22 saltmaster alcali[116437]: super().run()
Feb 25 08:21:22 saltmaster alcali[116437]: File "/opt/alcali/.venv/lib/python3.6/site-packages/gunicorn/app/base.py", line 72, in run
Feb 25 08:21:22 saltmaster alcali[116437]: Arbiter(self).run()
Feb 25 08:21:22 saltmaster alcali[116437]: File "/opt/alcali/.venv/lib/python3.6/site-packages/gunicorn/arbiter.py", line 202, in run
Feb 25 08:21:22 saltmaster alcali[116437]: self.manage_workers()
Feb 25 08:21:22 saltmaster alcali[116437]: File "/opt/alcali/.venv/lib/python3.6/site-packages/gunicorn/arbiter.py", line 545, in manage_workers
Feb 25 08:21:22 saltmaster alcali[116437]: self.spawn_workers()
Feb 25 08:21:22 saltmaster alcali[116437]: File "/opt/alcali/.venv/lib/python3.6/site-packages/gunicorn/arbiter.py", line 616, in spawn_workers
Feb 25 08:21:22 saltmaster alcali[116437]: self.spawn_worker()
Feb 25 08:21:22 saltmaster alcali[116437]: File "/opt/alcali/.venv/lib/python3.6/site-packages/gunicorn/arbiter.py", line 583, in spawn_worker
Feb 25 08:21:22 saltmaster alcali[116437]: worker.init_process()
Feb 25 08:21:22 saltmaster alcali[116437]: File "/opt/alcali/.venv/lib/python3.6/site-packages/gunicorn/workers/base.py", line 140, in init_process
Feb 25 08:21:22 saltmaster alcali[116437]: self.run()
Feb 25 08:21:22 saltmaster alcali[116437]: File "/opt/alcali/.venv/lib/python3.6/site-packages/gunicorn/workers/sync.py", line 123, in run
Feb 25 08:21:22 saltmaster alcali[116437]: self.run_for_one(timeout)
Feb 25 08:21:22 saltmaster alcali[116437]: File "/opt/alcali/.venv/lib/python3.6/site-packages/gunicorn/workers/sync.py", line 67, in run_for_one
Feb 25 08:21:22 saltmaster alcali[116437]: self.accept(listener)
Feb 25 08:21:22 saltmaster alcali[116437]: File "/opt/alcali/.venv/lib/python3.6/site-packages/gunicorn/workers/sync.py", line 29, in accept
Feb 25 08:21:22 saltmaster alcali[116437]: self.handle(listener, client, addr)
Feb 25 08:21:22 saltmaster alcali[116437]: File "/opt/alcali/.venv/lib/python3.6/site-packages/gunicorn/workers/sync.py", line 134, in handle
Feb 25 08:21:22 saltmaster alcali[116437]: self.handle_request(listener, req, client, addr)
Feb 25 08:21:22 saltmaster alcali[116437]: File "/opt/alcali/.venv/lib/python3.6/site-packages/gunicorn/workers/sync.py", line 184, in handle_request
Feb 25 08:21:22 saltmaster alcali[116437]: self.log.access(resp, req, environ, request_time)
Feb 25 08:21:22 saltmaster alcali[116437]: File "/opt/alcali/.venv/lib/python3.6/site-packages/gunicorn/glogging.py", line 344, in access
Feb 25 08:21:22 saltmaster alcali[116437]: self.access_log.info(self.cfg.access_log_format, safe_atoms)

Seems to die right after POST /api/token and the successful ldap check.

Digging much deeper, it seems that login calls validate() in MyTokenObtainPairSerializer from api/serializers.
This reaches into /opt/alcali/.venv/lib/python3.6/site-packages/rest_framework_simplejwt/serializers.py to perform auth against the backend. With debug added, I pass all of the steps here.
This serializers.py calls out to authenticate() in /opt/alcali/.venv/lib/python3.6/site-packages/django/contrib/auth/init.py

I can get debug out of all of the above, but the original validate function exits:

class MyTokenObtainPairSerializer(TokenObtainPairSerializer):
    def validate(self, attrs):
        # /opt/alcali/.venv/lib/python3.6/site-packages/django/contrib/auth/__init__.py
        # /opt/alcali/.venv/lib/python3.6/site-packages/rest_framework_simplejwt/serializers.py
        print("Calling validate for:")
        print(attrs)
        data = super().validate(attrs) <---- correctly calls code in rest_framework and django.contrib.auth, which can be made to print debug output showing that the login is successful
        print("Validated user " + self.user.username) <--------------not printed
        print(type(data)) <--------------- not printed
        refresh = self.get_token(self.user)
        data["refresh"] = str(refresh)

Since my AD user is first.last, could it be dieing because of the '.' ? EDIT: No, that isn't it.

Turns out I am running into this instead upon successful login:
File "/opt/alcali/.venv/lib/python3.6/site-packages/rest_framework_simplejwt/backends.py", line 43, in encode
return token.decode('utf-8')
AttributeError: 'str' object has no attribute 'decode'
If I change that function to return token instead of token.decode, I get logged in. Of course I cannot auth to salt at that point but there is some progress...

Pretty well non-standard since it is a mod of the django code, but
"/opt/alcali/.venv/lib/python3.6/site-packages/rest_framework_simplejwt/backends.py":

        if (type(token) == str):
            return token
        return token.decode('utf-8')

This lets me login and get around in Alcali without error. However, about the only thing I can see are events, which stands to reason since mysql is working. But, no errors when I run gunicorn in foreground with debug but no content from salt.