Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Unable to log in via basic CKAN authentication after installing LDAP extension #71

Closed
reedv opened this issue Mar 10, 2021 · 9 comments
Closed
Labels

Comments

@reedv
Copy link

reedv commented Mar 10, 2021

Description
A clear and concise description of what the bug is.
Docs say that extension...

Allows to have LDAP only authentication, or combine LDAP and basic CKAN authentication;

...but when attempting to sign in as a user (a sysadmin) account that was created via...

ckan -c /etc/ckan/default/ckan.ini sysadmin add admin email=myadmin@myorg.org name=admin

...am given a "Bad username or password" error.

Expected Behaviour
What you expected to happen instead.
Expect to be able to log into CKAN web UI with non-ldap users that were created on the system via ckan CLI.

To Reproduce
Steps to reproduce the bug.

  1. Create a native/system CKAN user via something like ckan -c /etc/ckan/default/ckan.ini sysadmin add admin email=myadmin@myorg.org name=admin
  2. Install ckanext-ldap extension
  3. Attempt to log in using the native/system user

Error Log
Paste any relevant error logs below:
Could not see anything in the /var/log/ckan/ckan-uwsgi.stderr.log or /var/log/ckan/ckan-worker.stderr.log files that seemed related to this or indicating any errors at all from around the timestamp that this testing was done, but can provide more logged info if there is anything specific to look for.

Screenshots
Add screenshots to illustrate the bug if you want.

Your Setup

  • CKAN version: 2.9.1
  • Commit/version of this repo: (Installed via package)
  • Browser (if relevant): [e.g. chrome, safari]

Anything Else?
...

@reedv reedv added the bug label Mar 10, 2021
@jrdh
Copy link
Member

jrdh commented Mar 10, 2021

Hi @reedv - the extension definitely supports the functionality you quote (Allows to have LDAP only authentication, or combine LDAP and basic CKAN authentication) so there must be something else going on here.

If we assume the error message is correct then there wouldn't be anything in the logs as the error is a user error - Bad username or password. Can you check your CKAN credentials that you're using are correct or post some LDAP extension-related logging? Does it work if you don't have the LDAP extension in your ckan.plugins list?

Unfortunately, there's not much for me to go on here and it may not even be a problem in the LDAP extension at all!

@reedv
Copy link
Author

reedv commented Mar 10, 2021

Yes, I can log in using the system CKAN credentials when I remove the ldap extension from the ckan.plugin property in the ckan.ini file and reload CKAN via sudo supervisorctl reload; sudo service nginx restart.

I agree, it is odd (but again, the fact that it works after removing the ldap plugin is what makes me think it is in fact the extension that is causing the problem). Is there any example of the kinds of words I could grep for in the logs in case I'm missing something (because I don't see anything abnormal when looking at the logs around the timestamp that I'm testing this though)?

Note that I've modified my search.py file for the extension to look as described here (#70 (comment)), but again I see nothing in the logs pointing to this piece of code (plus the fact that the plugin is removed in this case).

@reedv
Copy link
Author

reedv commented Mar 11, 2021

Testing again (which failed and produced that same "Bad username or password" error message in the UI) and checking the logs around this timestamp in ckan-uwsgi.stderr.log I see...

2021-03-11 09:54:24,093 INFO  [ckan.config.middleware.flask_app]  /user/login render time 0.019 seconds
[pid: 130181|app: 0|req: 1136/1136] 127.0.0.1 () {40 vars in 891 bytes} [Thu Mar 11 09:54:24 2021] GET /user/login => generated 11605 bytes in 25 msecs (HTTP/1.0 200) 4 headers in 259 bytes (1 switches on core 0)
2021-03-11 09:54:24,126 INFO  [ckan.config.middleware.flask_app]  /webassets/base/d87ecb06_main.css render time 0.001 seconds
[pid: 130181|app: 0|req: 1137/1137] 127.0.0.1 () {38 vars in 714 bytes} [Thu Mar 11 09:54:24 2021] GET /webassets/base/d87ecb06_main.css => generated 225731 bytes in 7 msecs via sendfile() (HTTP/1.0 200) 9 headers in 430 bytes (0 switches on core 0)
2021-03-11 09:54:24,133 INFO  [ckan.config.middleware.flask_app]  /base/images/od_80x15_blue.png render time 0.001 seconds
[pid: 130181|app: 0|req: 1138/1138] 127.0.0.1 () {38 vars in 754 bytes} [Thu Mar 11 09:54:24 2021] GET /base/images/od_80x15_blue.png => generated 163 bytes in 6 msecs via sendfile() (HTTP/1.0 200) 9 headers in 412 bytes (0 switches on core 0)
2021-03-11 09:54:24,138 INFO  [ckan.config.middleware.flask_app]  /webassets/vendor/f3b8236b_select2.css render time 0.001 seconds
[pid: 130181|app: 0|req: 1139/1139] 127.0.0.1 () {38 vars in 724 bytes} [Thu Mar 11 09:54:24 2021] GET /webassets/vendor/f3b8236b_select2.css => generated 19769 bytes in 5 msecs via sendfile() (HTTP/1.0 200) 9 headers in 431 bytes (0 switches on core 0)
2021-03-11 09:54:24,144 INFO  [ckan.config.middleware.flask_app]  /webassets/vendor/0b01aef1_font-awesome.css render time 0.001 seconds
[pid: 130181|app: 0|req: 1140/1140] 127.0.0.1 () {38 vars in 734 bytes} [Thu Mar 11 09:54:24 2021] GET /webassets/vendor/0b01aef1_font-awesome.css => generated 37581 bytes in 5 msecs via sendfile() (HTTP/1.0 200) 9 headers in 431 bytes (0 switches on core 0)
2021-03-11 09:54:24,150 INFO  [ckan.config.middleware.flask_app]  /webassets/vendor/d8ae4bed_jquery.js render time 0.001 seconds
[pid: 130181|app: 0|req: 1141/1141] 127.0.0.1 () {38 vars in 705 bytes} [Thu Mar 11 09:54:24 2021] GET /webassets/vendor/d8ae4bed_jquery.js => generated 144132 bytes in 5 msecs via sendfile() (HTTP/1.0 200) 9 headers in 446 bytes (0 switches on core 0)
2021-03-11 09:54:24,156 INFO  [ckan.config.middleware.flask_app]  /webassets/vendor/ab26884f_vendor.js render time 0.001 seconds
[pid: 130181|app: 0|req: 1142/1142] 127.0.0.1 () {38 vars in 705 bytes} [Thu Mar 11 09:54:24 2021] GET /webassets/vendor/ab26884f_vendor.js => generated 449677 bytes in 5 msecs via sendfile() (HTTP/1.0 200) 9 headers in 446 bytes (0 switches on core 0)
2021-03-11 09:54:24,162 INFO  [ckan.config.middleware.flask_app]  /webassets/vendor/580fa18d_bootstrap.js render time 0.001 seconds
[pid: 130181|app: 0|req: 1143/1143] 127.0.0.1 () {38 vars in 789 bytes} [Thu Mar 11 09:54:24 2021] GET /webassets/vendor/580fa18d_bootstrap.js => generated 51115 bytes in 5 msecs via sendfile() (HTTP/1.0 200) 9 headers in 483 bytes (0 switches on core 0)
2021-03-11 09:54:24,168 INFO  [ckan.config.middleware.flask_app]  /webassets/base/5f5a82bb_main.js render time 0.001 seconds
[pid: 130181|app: 0|req: 1144/1144] 127.0.0.1 () {38 vars in 775 bytes} [Thu Mar 11 09:54:24 2021] GET /webassets/base/5f5a82bb_main.js => generated 68581 bytes in 5 msecs via sendfile() (HTTP/1.0 200) 9 headers in 484 bytes (0 switches on core 0)
2021-03-11 09:54:24,175 INFO  [ckan.config.middleware.flask_app]  /webassets/base/b81fd734_ckan.js render time 0.001 seconds
[pid: 130181|app: 0|req: 1145/1145] 127.0.0.1 () {38 vars in 775 bytes} [Thu Mar 11 09:54:24 2021] GET /webassets/base/b81fd734_ckan.js => generated 45348 bytes in 5 msecs via sendfile() (HTTP/1.0 200) 9 headers in 484 bytes (0 switches on core 0)
2021-03-11 09:54:24,223 INFO  [ckan.config.middleware.flask_app]  /base/images/bg.png render time 0.001 seconds
[pid: 130181|app: 0|req: 1146/1146] 127.0.0.1 () {38 vars in 753 bytes} [Thu Mar 11 09:54:24 2021] GET /base/images/bg.png => generated 3911 bytes in 8 msecs via sendfile() (HTTP/1.0 200) 9 headers in 414 bytes (0 switches on core 0)
2021-03-11 09:54:24,231 INFO  [ckan.config.middleware.flask_app]  /base/images/ckan-logo-footer.png render time 0.001 seconds
[pid: 130181|app: 0|req: 1147/1147] 127.0.0.1 () {38 vars in 781 bytes} [Thu Mar 11 09:54:24 2021] GET /base/images/ckan-logo-footer.png => generated 435 bytes in 6 msecs via sendfile() (HTTP/1.0 200) 9 headers in 411 bytes (0 switches on core 0)
2021-03-11 09:54:24,236 INFO  [ckan.config.middleware.flask_app]  /base/vendor/font-awesome/fonts/fontawesome-webfont.woff2 render time 0.001 seconds
[pid: 130181|app: 0|req: 1148/1148] 127.0.0.1 () {40 vars in 832 bytes} [Thu Mar 11 09:54:24 2021] GET /base/vendor/font-awesome/fonts/fontawesome-webfont.woff2?v=4.7.0 => generated 77160 bytes in 5 msecs via sendfile() (HTTP/1.0 200) 9 headers in 430 bytes (0 switches on core 0)
2021-03-11 09:54:24,321 INFO  [ckan.config.middleware.flask_app]  /api/i18n/en render time 0.001 seconds
[pid: 130181|app: 0|req: 1149/1149] 127.0.0.1 () {40 vars in 817 bytes} [Thu Mar 11 09:54:24 2021] GET /api/i18n/en => generated 2 bytes in 8 msecs (HTTP/1.0 200) 4 headers in 282 bytes (1 switches on core 0)
2021-03-11 09:54:24,345 INFO  [ckan.config.middleware.flask_app]  /base/vendor/select2/select2x2.png render time 0.001 seconds
[pid: 130181|app: 0|req: 1150/1150] 127.0.0.1 () {38 vars in 788 bytes} [Thu Mar 11 09:54:24 2021] GET /base/vendor/select2/select2x2.png => generated 845 bytes in 8 msecs via sendfile() (HTTP/1.0 200) 9 headers in 411 bytes (0 switches on core 0)
2021-03-11 09:54:34,738 INFO  [ckan.config.middleware.flask_app]  /ldap_login_handler render time 0.008 seconds
[pid: 130181|app: 0|req: 1151/1151] 127.0.0.1 () {48 vars in 1116 bytes} [Thu Mar 11 09:54:34 2021] POST /ldap_login_handler?came_from=%2Fuser%2Flogged_in => generated 313 bytes in 14 msecs (HTTP/1.0 302) 4 headers in 199 bytes (1 switches on core 0)
2021-03-11 09:54:34,783 INFO  [ckan.config.middleware.flask_app]  /user/login render time 0.025 seconds
[pid: 130181|app: 0|req: 1152/1152] 127.0.0.1 () {42 vars in 967 bytes} [Thu Mar 11 09:54:34 2021] GET /user/login?__no_cache__=True => generated 12687 bytes in 31 msecs (HTTP/1.0 200) 4 headers in 259 bytes (1 switches on core 0)
2021-03-11 09:54:34,827 INFO  [ckan.config.middleware.flask_app]  /webassets/vendor/f3b8236b_select2.css render time 0.001 seconds
[pid: 130181|app: 0|req: 1153/1153] 127.0.0.1 () {38 vars in 742 bytes} [Thu Mar 11 09:54:34 2021] GET /webassets/vendor/f3b8236b_select2.css => generated 19769 bytes in 7 msecs via sendfile() (HTTP/1.0 200) 9 headers in 431 bytes (0 switches on core 0)
2021-03-11 09:54:34,834 INFO  [ckan.config.middleware.flask_app]  /webassets/base/d87ecb06_main.css render time 0.001 seconds
[pid: 130181|app: 0|req: 1154/1154] 127.0.0.1 () {38 vars in 732 bytes} [Thu Mar 11 09:54:34 2021] GET /webassets/base/d87ecb06_main.css => generated 225731 bytes in 6 msecs via sendfile() (HTTP/1.0 200) 9 headers in 430 bytes (0 switches on core 0)
2021-03-11 09:54:34,841 INFO  [ckan.config.middleware.flask_app]  /base/images/od_80x15_blue.png render time 0.001 seconds
[pid: 130181|app: 0|req: 1155/1155] 127.0.0.1 () {38 vars in 772 bytes} [Thu Mar 11 09:54:34 2021] GET /base/images/od_80x15_blue.png => generated 163 bytes in 6 msecs via sendfile() (HTTP/1.0 200) 9 headers in 412 bytes (0 switches on core 0)
2021-03-11 09:54:34,847 INFO  [ckan.config.middleware.flask_app]  /webassets/vendor/0b01aef1_font-awesome.css render time 0.001 seconds
[pid: 130181|app: 0|req: 1156/1156] 127.0.0.1 () {38 vars in 752 bytes} [Thu Mar 11 09:54:34 2021] GET /webassets/vendor/0b01aef1_font-awesome.css => generated 37581 bytes in 6 msecs via sendfile() (HTTP/1.0 200) 9 headers in 431 bytes (0 switches on core 0)
2021-03-11 09:54:34,853 INFO  [ckan.config.middleware.flask_app]  /webassets/vendor/d8ae4bed_jquery.js render time 0.001 seconds
[pid: 130181|app: 0|req: 1157/1157] 127.0.0.1 () {38 vars in 723 bytes} [Thu Mar 11 09:54:34 2021] GET /webassets/vendor/d8ae4bed_jquery.js => generated 144132 bytes in 6 msecs via sendfile() (HTTP/1.0 200) 9 headers in 446 bytes (0 switches on core 0)
2021-03-11 09:54:34,861 INFO  [ckan.config.middleware.flask_app]  /webassets/vendor/ab26884f_vendor.js render time 0.001 seconds
[pid: 130181|app: 0|req: 1158/1158] 127.0.0.1 () {38 vars in 723 bytes} [Thu Mar 11 09:54:34 2021] GET /webassets/vendor/ab26884f_vendor.js => generated 449677 bytes in 7 msecs via sendfile() (HTTP/1.0 200) 9 headers in 446 bytes (0 switches on core 0)
2021-03-11 09:54:34,867 INFO  [ckan.config.middleware.flask_app]  /webassets/vendor/580fa18d_bootstrap.js render time 0.001 seconds
[pid: 130181|app: 0|req: 1159/1159] 127.0.0.1 () {38 vars in 808 bytes} [Thu Mar 11 09:54:34 2021] GET /webassets/vendor/580fa18d_bootstrap.js => generated 51115 bytes in 6 msecs via sendfile() (HTTP/1.0 200) 9 headers in 483 bytes (0 switches on core 0)
2021-03-11 09:54:34,875 INFO  [ckan.config.middleware.flask_app]  /webassets/base/5f5a82bb_main.js render time 0.001 seconds
[pid: 130181|app: 0|req: 1160/1160] 127.0.0.1 () {38 vars in 794 bytes} [Thu Mar 11 09:54:34 2021] GET /webassets/base/5f5a82bb_main.js => generated 68581 bytes in 7 msecs via sendfile() (HTTP/1.0 200) 9 headers in 484 bytes (0 switches on core 0)
2021-03-11 09:54:34,897 INFO  [ckan.config.middleware.flask_app]  /webassets/base/b81fd734_ckan.js render time 0.001 seconds
[pid: 130181|app: 0|req: 1161/1161] 127.0.0.1 () {38 vars in 794 bytes} [Thu Mar 11 09:54:34 2021] GET /webassets/base/b81fd734_ckan.js => generated 45348 bytes in 7 msecs via sendfile() (HTTP/1.0 200) 9 headers in 484 bytes (0 switches on core 0)
2021-03-11 09:54:34,948 INFO  [ckan.config.middleware.flask_app]  /base/images/bg.png render time 0.001 seconds
[pid: 130181|app: 0|req: 1162/1162] 127.0.0.1 () {38 vars in 754 bytes} [Thu Mar 11 09:54:34 2021] GET /base/images/bg.png => generated 3911 bytes in 7 msecs via sendfile() (HTTP/1.0 200) 9 headers in 414 bytes (0 switches on core 0)
2021-03-11 09:54:34,955 INFO  [ckan.config.middleware.flask_app]  /base/images/ckan-logo-footer.png render time 0.001 seconds
[pid: 130181|app: 0|req: 1163/1163] 127.0.0.1 () {38 vars in 782 bytes} [Thu Mar 11 09:54:34 2021] GET /base/images/ckan-logo-footer.png => generated 435 bytes in 6 msecs via sendfile() (HTTP/1.0 200) 9 headers in 411 bytes (0 switches on core 0)
2021-03-11 09:54:34,963 INFO  [ckan.config.middleware.flask_app]  /base/vendor/font-awesome/fonts/fontawesome-webfont.woff2 render time 0.001 seconds
[pid: 130181|app: 0|req: 1164/1164] 127.0.0.1 () {40 vars in 833 bytes} [Thu Mar 11 09:54:34 2021] GET /base/vendor/font-awesome/fonts/fontawesome-webfont.woff2?v=4.7.0 => generated 77160 bytes in 7 msecs via sendfile() (HTTP/1.0 200) 9 headers in 430 bytes (0 switches on core 0)
2021-03-11 09:54:35,142 INFO  [ckan.config.middleware.flask_app]  /api/i18n/en render time 0.001 seconds
[pid: 130181|app: 0|req: 1165/1165] 127.0.0.1 () {40 vars in 836 bytes} [Thu Mar 11 09:54:35 2021] GET /api/i18n/en => generated 2 bytes in 8 msecs (HTTP/1.0 200) 4 headers in 282 bytes (1 switches on core 0)
2021-03-11 09:54:35,182 INFO  [ckan.config.middleware.flask_app]  /base/vendor/select2/select2x2.png render time 0.001 seconds
[pid: 130181|app: 0|req: 1166/1166] 127.0.0.1 () {38 vars in 789 bytes} [Thu Mar 11 09:54:35 2021] GET /base/vendor/select2/select2x2.png => generated 845 bytes in 8 msecs via sendfile() (HTTP/1.0 200) 9 headers in 411 bytes (0 switches on core 0)

(did not notice these earlier because they are not error messages).
Notice the lines

2021-03-11 09:54:24,093 INFO  [ckan.config.middleware.flask_app]  /user/login render time 0.019 seconds
[pid: 130181|app: 0|req: 1136/1136] 127.0.0.1 () {40 vars in 891 bytes} [Thu Mar 11 09:54:24 2021] GET /user/login => generated 11605 bytes in 25 msecs (HTTP/1.0 200) 4 headers in 259 bytes (1 switches on core 0)**
2021-03-11 09:54:34,738 INFO  [ckan.config.middleware.flask_app]  /ldap_login_handler render time 0.008 seconds
[pid: 130181|app: 0|req: 1151/1151] 127.0.0.1 () {48 vars in 1116 bytes} [Thu Mar 11 09:54:34 2021] POST /ldap_login_handler?came_from=%2Fuser%2Flogged_in => generated 313 bytes in 14 msecs (HTTP/1.0 302) 4 headers in 199 bytes (1 switches on core 0)
2021-03-11 09:54:34,783 INFO  [ckan.config.middleware.flask_app]  /user/login render time 0.025 seconds
[pid: 130181|app: 0|req: 1152/1152] 127.0.0.1 () {42 vars in 967 bytes} [Thu Mar 11 09:54:34 2021] GET /user/login?__no_cache__=True => generated 12687 bytes in 31 msecs (HTTP/1.0 200) 4 headers in 259 bytes (1 switches on core 0)
2021-03-11 09:54:34,827 INFO  [ckan.config.middleware.flask_app]  /webassets/vendor/f3b8236b_select2.css render time 0.001 seconds

These are the only things that seemed related, but really IDK how to interpret this.

@alycejenni
Copy link
Member

There are three places in the extension code where you might get a 'Bad username or password' error (all in login.py). If you temporarily change the error messages (e.g. to 'bad username 1', 'bad username 2', etc.), you can see where it's stopping and we might be able to help further.

(Alternatively, if you have a debugger set up, stepping through the code in login.py would probably be very helpful).

@reedv
Copy link
Author

reedv commented Mar 12, 2021

IC, interesting. I get what you're saying (the different return _helpers.login_failed lines).
Will do.
If I were to try to run a debugger on the file for the login_handler(), how would I do this / what would the test input look like?

@reedv
Copy link
Author

reedv commented Mar 17, 2021

Editing the login.py file to include more descriptive error messages like...

.
.
.
        elif ldap_user_dict:
            # There is an LDAP user, but the auth is wrong. There could be a
            # CKAN user of the same name if the LDAP user had been created
            # later - in which case we have a conflict we can't solve.
            if toolkit.config['ckanext.ldap.ckan_fallback']:
                exists = _helpers.ckan_user_exists(login)
                if exists['exists'] and not exists['is_ldap']:
                    return _helpers.login_failed(error=toolkit._(
                        'Username conflict. Please contact the site administrator.'))
            return _helpers.login_failed(error=toolkit._('Bad username or password. LDAP, but auth is wrong'))
        elif toolkit.config['ckanext.ldap.ckan_fallback']:
            # No LDAP user match, see if we have a CKAN user match
            try:
                user_dict = _helpers.get_user_dict(login)
                # We need the model to validate the password
                user = User.by_name(user_dict['name'])
            except toolkit.ObjectNotFound:
                user = None
            if user and user.validate_password(password):
                return _helpers.login_success(user.name, came_from=came_from)
            else:
                return _helpers.login_failed(
                    error=toolkit._('Bad username or password. No LDAP match, checked CKAN'))
        else:
            return _helpers.login_failed(error=toolkit._('Bad username or password. Catchall'))
.
.
.

...and running

sudo rm -rf /usr/lib/ckan/default/lib/python2.7/site-packages/ckanext_ldap*
sudo /usr/lib/ckan/default/bin/python install

...I see that it is throwing the final "catchall" error (which is odd since I'd expect my system user to be caught in the "No LDAP user match, see if we have a CKAN user match" section of the code).

Attempting to look at the user_dict object that gets assigned in line 58 (by just assigning it to a global variable and interpolating it into the error string), I see that it is a NoneType object (ie. _helpers.get_user_dict(login) is returning None). I would think this should not be happening, since (again) I can log in as this user when not using the ldap extension and I can also see this user listed when using the API user_list() action.

Had thought the problem was that your extension's _helpers.get_user_dict(user_id) function is expecting a user id (which appears to be some kind of UUID when looking at the output of the user_list API command), but the extension's login_handler is using the login username entered (tested this via the same hack used to see that the user_dict being retrieved was a NoneType as mentioned above), but testing with the API shows that it seems to accept both username OR UUID.

Note that the user's name is "admin" and they are a sysadmin user, IDK if that would be messing anything up with the _helpers.py file (I doubt it).

I'd like to examine the user_dict object and the results of _helpers.get_user_dict(user_id), but IDK how to view that / get it to show up in the logs. Would you know how to do this (simply using print() statement does not work)?

@alycejenni
Copy link
Member

You need to set ckanext.ldap.ckan_fallback = True in your config file. The default is False, which means it'll ignore all non-LDAP users.

@reedv
Copy link
Author

reedv commented Mar 17, 2021

Well, that worked, thanks. How did you figure that out / what was your chain of reasoning (ie. how could I have figured that out from the debugging into provided)?

Also for future reference, how can I print things to the ckan logs?

@alycejenni
Copy link
Member

If it was set to true, you would've seen the behaviour you expected - i.e. it would follow the second elif (which checks the config).

You have to use the logging library (py2 docs, py3 docs) and set up your config to enable the level of log messages you want.

Example of using log messages:

log = logging.getLogger(__name__)

then:

log.error('LDAP server is not reachable')

There are several loggers in the ckan.ini file and you can change the levels for each of them, e.g.

ckanext-ldap/test.ini

Lines 28 to 30 in afded53

[logger_root]
level = WARNING
handlers = console

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

No branches or pull requests

3 participants