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.

Sign up for GitHub

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

Jump to bottom

MySQL error (Plugin pvio_socket could not be loaded: not initialized) #44

Open
sbajic opened this issue Oct 19, 2017 · 1 comment
Open

MySQL error (Plugin pvio_socket could not be loaded: not initialized) #44

sbajic opened this issue Oct 19, 2017 · 1 comment

Comments

@sbajic
Copy link

sbajic commented Oct 19, 2017

Using MariaDB 10.2 with pam-MySQL results in the following error: MySQL error (Plugin pvio_socket could not be loaded: not initialized)

The verbose log looks like this (changed some values to protect the innocent):

Oct 19 18:55:40 hermes ker[6004]: process: pam_mysql - option verbose is set to "1"
Oct 19 18:55:40 hermes ker[6004]: process: pam_mysql - option host is set to "localhost"
Oct 19 18:55:40 hermes ker[6004]: process: pam_mysql - option db is set to "sysdb_postfix"
Oct 19 18:55:40 hermes ker[6004]: process: pam_mysql - option user is set to "sysusr_postfix"
Oct 19 18:55:40 hermes ker[6004]: process: pam_mysql - option passwd is set to "somepassword"
Oct 19 18:55:40 hermes ker[6004]: process: pam_mysql - option table is set to "mailbox"
Oct 19 18:55:40 hermes ker[6004]: process: pam_mysql - option usercolumn is set to "username"
Oct 19 18:55:40 hermes ker[6004]: process: pam_mysql - option passwdcolumn is set to "password"
Oct 19 18:55:40 hermes ker[6004]: process: pam_mysql - option crypt is set to "0"
Oct 19 18:55:40 hermes ker[6004]: process: pam_mysql - option where is set to "active='1'"
Oct 19 18:55:40 hermes ker[6004]: process: pam_mysql - pam_mysql_close_db() called.
Oct 19 18:55:40 hermes ker[6004]: process: pam_mysql - pam_sm_authenticate() called.
Oct 19 18:55:40 hermes ker[6004]: process: pam_mysql - pam_mysql_open_db() called.
Oct 19 18:55:40 hermes ker[6004]: process: pam_mysql - pam_mysql_open_db() returning 0.
Oct 19 18:55:40 hermes ker[6004]: process: pam_mysql - pam_mysql_check_passwd() called.
Oct 19 18:55:40 hermes ker[6004]: process: pam_mysql - pam_mysql_format_string() called
Oct 19 18:55:40 hermes ker[6004]: process: pam_mysql - pam_mysql_quick_escape() called.
Oct 19 18:55:40 hermes ker[6004]: process: pam_mysql - SELECT password FROM mailbox WHERE username = 'me@mydomain.ch' AND (active='1')
Oct 19 18:55:40 hermes ker[6004]: process: pam_mysql - pam_mysql_check_passwd() returning 6.
Oct 19 18:55:40 hermes ker[6004]: process: pam_mysql - pam_mysql_sql_log() called.
Oct 19 18:55:40 hermes ker[6004]: process: pam_mysql - pam_mysql_sql_log() returning 0.
Oct 19 18:55:40 hermes ker[6004]: process: pam_mysql - pam_mysql_converse() called.
Oct 19 18:55:40 hermes ker[6004]: process: pam_mysql - pam_mysql_open_db() called.
Oct 19 18:55:40 hermes ker[6004]: process: pam_mysql - pam_mysql_check_passwd() called.
Oct 19 18:55:40 hermes ker[6004]: process: pam_mysql - pam_mysql_format_string() called
Oct 19 18:55:40 hermes ker[6004]: process: pam_mysql - pam_mysql_quick_escape() called.
Oct 19 18:55:40 hermes ker[6004]: process: pam_mysql - SELECT password FROM mailbox WHERE username = 'me@mydomain.ch' AND (active='1')
Oct 19 18:55:40 hermes ker[6004]: process: pam_mysql - pam_mysql_check_passwd() returning 0.
Oct 19 18:55:40 hermes ker[6004]: process: pam_mysql - pam_mysql_sql_log() called.
Oct 19 18:55:40 hermes ker[6004]: process: pam_mysql - pam_mysql_sql_log() returning 0.
Oct 19 18:55:40 hermes ker[6004]: process: pam_mysql - pam_sm_authenticate() returning 0.
Oct 19 18:55:40 hermes ker[6004]: process: pam_mysql - option verbose is set to "1"
Oct 19 18:55:40 hermes ker[6004]: process: pam_mysql - option host is set to "localhost"
Oct 19 18:55:40 hermes ker[6004]: process: pam_mysql - option db is set to "sysdb_postfix"
Oct 19 18:55:40 hermes ker[6004]: process: pam_mysql - option user is set to "sysusr_postfix"
Oct 19 18:55:40 hermes ker[6004]: process: pam_mysql - option passwd is set to "somepassword"
Oct 19 18:55:40 hermes ker[6004]: process: pam_mysql - option table is set to "mailbox"
Oct 19 18:55:40 hermes ker[6004]: process: pam_mysql - option usercolumn is set to "username"
Oct 19 18:55:40 hermes ker[6004]: process: pam_mysql - option passwdcolumn is set to "password"
Oct 19 18:55:40 hermes ker[6004]: process: pam_mysql - option crypt is set to "0"
Oct 19 18:55:40 hermes ker[6004]: process: pam_mysql - option where is set to "active='1'"
Oct 19 18:55:40 hermes ker[6004]: process: pam_mysql - pam_mysql_close_db() called.
Oct 19 18:55:40 hermes ker[6004]: process: pam_mysql - pam_sm_acct_mgmt() called.
Oct 19 18:55:40 hermes ker[6004]: process: pam_mysql - pam_mysql_open_db() called.
Oct 19 18:55:40 hermes ker[6004]: process: pam_mysql - MySQL error (Plugin pvio_socket could not be loaded: not initialized)
Oct 19 18:55:40 hermes ker[6004]: process: pam_mysql - pam_mysql_open_db() returning 5.
Oct 19 18:55:40 hermes ker[6004]: process: pam_mysql - pam_sm_acct_mgmt() returning 9.
Oct 19 18:55:40 hermes ker[6004]: process: pam_mysql - pam_mysql_release_ctx() called.
Oct 19 18:55:40 hermes ker[6004]: process: pam_mysql - pam_mysql_destroy_ctx() called.
Oct 19 18:55:40 hermes ker[6004]: process: pam_mysql - pam_mysql_close_db() called.
Oct 19 18:55:41 hermes ker[6003]: process: pam_mysql - option verbose is set to "1"
Oct 19 18:55:41 hermes ker[6003]: process: pam_mysql - option host is set to "localhost"
Oct 19 18:55:41 hermes ker[6003]: process: pam_mysql - option db is set to "sysdb_postfix"
Oct 19 18:55:41 hermes ker[6003]: process: pam_mysql - option user is set to "sysusr_postfix"
Oct 19 18:55:41 hermes ker[6003]: process: pam_mysql - option passwd is set to "somepassword"
Oct 19 18:55:41 hermes ker[6003]: process: pam_mysql - option table is set to "mailbox"
Oct 19 18:55:41 hermes ker[6003]: process: pam_mysql - option usercolumn is set to "username"
Oct 19 18:55:41 hermes ker[6003]: process: pam_mysql - option passwdcolumn is set to "password"
Oct 19 18:55:41 hermes ker[6003]: process: pam_mysql - option crypt is set to "0"
Oct 19 18:55:41 hermes ker[6003]: process: pam_mysql - option where is set to "active='1'"
Oct 19 18:55:41 hermes ker[6003]: process: pam_mysql - pam_mysql_close_db() called.
Oct 19 18:55:41 hermes ker[6003]: process: pam_mysql - pam_sm_authenticate() called.
Oct 19 18:55:41 hermes ker[6003]: process: pam_mysql - pam_mysql_open_db() called.
Oct 19 18:55:41 hermes ker[6003]: process: pam_mysql - pam_mysql_open_db() returning 0.
Oct 19 18:55:41 hermes ker[6003]: process: pam_mysql - pam_mysql_check_passwd() called.
Oct 19 18:55:41 hermes ker[6003]: process: pam_mysql - pam_mysql_format_string() called
Oct 19 18:55:41 hermes ker[6003]: process: pam_mysql - pam_mysql_quick_escape() called.
Oct 19 18:55:41 hermes ker[6003]: process: pam_mysql - SELECT password FROM mailbox WHERE username = 'me@mydomain.ch' AND (active='1')
Oct 19 18:55:41 hermes ker[6003]: process: pam_mysql - pam_mysql_check_passwd() returning 6.
Oct 19 18:55:41 hermes ker[6003]: process: pam_mysql - pam_mysql_sql_log() called.
Oct 19 18:55:41 hermes ker[6003]: process: pam_mysql - pam_mysql_sql_log() returning 0.
Oct 19 18:55:41 hermes ker[6003]: process: pam_mysql - pam_mysql_converse() called.
Oct 19 18:55:41 hermes ker[6003]: process: pam_mysql - pam_mysql_open_db() called.
Oct 19 18:55:41 hermes ker[6003]: process: pam_mysql - pam_mysql_check_passwd() called.
Oct 19 18:55:41 hermes ker[6003]: process: pam_mysql - pam_mysql_format_string() called
Oct 19 18:55:41 hermes ker[6003]: process: pam_mysql - pam_mysql_quick_escape() called.
Oct 19 18:55:41 hermes ker[6003]: process: pam_mysql - SELECT password FROM mailbox WHERE username = 'me@mydomain.ch' AND (active='1')
Oct 19 18:55:41 hermes ker[6003]: process: pam_mysql - pam_mysql_check_passwd() returning 0.
Oct 19 18:55:41 hermes ker[6003]: process: pam_mysql - pam_mysql_sql_log() called.
Oct 19 18:55:41 hermes ker[6003]: process: pam_mysql - pam_mysql_sql_log() returning 0.
Oct 19 18:55:41 hermes ker[6003]: process: pam_mysql - pam_sm_authenticate() returning 0.
Oct 19 18:55:41 hermes ker[6003]: process: pam_mysql - option verbose is set to "1"
Oct 19 18:55:41 hermes ker[6003]: process: pam_mysql - option host is set to "localhost"
Oct 19 18:55:41 hermes ker[6003]: process: pam_mysql - option db is set to "sysdb_postfix"
Oct 19 18:55:41 hermes ker[6003]: process: pam_mysql - option user is set to "sysusr_postfix"
Oct 19 18:55:41 hermes ker[6003]: process: pam_mysql - option passwd is set to "somepassword"
Oct 19 18:55:41 hermes ker[6003]: process: pam_mysql - option table is set to "mailbox"
Oct 19 18:55:41 hermes ker[6003]: process: pam_mysql - option usercolumn is set to "username"
Oct 19 18:55:41 hermes ker[6003]: process: pam_mysql - option passwdcolumn is set to "password"
Oct 19 18:55:41 hermes ker[6003]: process: pam_mysql - option crypt is set to "0"
Oct 19 18:55:41 hermes ker[6003]: process: pam_mysql - option where is set to "active='1'"
Oct 19 18:55:41 hermes ker[6003]: process: pam_mysql - pam_mysql_close_db() called.
Oct 19 18:55:41 hermes ker[6003]: process: pam_mysql - pam_sm_acct_mgmt() called.
Oct 19 18:55:41 hermes ker[6003]: process: pam_mysql - pam_mysql_open_db() called.
Oct 19 18:55:41 hermes ker[6003]: process: pam_mysql - MySQL error (Plugin pvio_socket could not be loaded: not initialized)
Oct 19 18:55:41 hermes ker[6003]: process: pam_mysql - pam_mysql_open_db() returning 5.
Oct 19 18:55:41 hermes ker[6003]: process: pam_mysql - pam_sm_acct_mgmt() returning 9.
Oct 19 18:55:41 hermes ker[6003]: process: pam_mysql - pam_mysql_release_ctx() called.
Oct 19 18:55:41 hermes ker[6003]: process: pam_mysql - pam_mysql_destroy_ctx() called.
Oct 19 18:55:41 hermes ker[6003]: process: pam_mysql - pam_mysql_close_db() called.

The error is similar to this one here:
Icinga/icinga-core#1598
@sbajic
Copy link
Author

sbajic commented Dec 6, 2017

IMHO this here is problematic:
Oct 19 18:55:41 hermes ker[6003]: process: pam_mysql - pam_mysql_close_db() called.

The code in pam_mysql_close_db() calls mysql_library_end (which de-initializes the plugin system). From then on you need to reinitialize mysql by callin mysql_init() or you will get the above error.

Using MariaDB < 10.2.0 does not result in an error. Anything >= 10.2.0 has the above mentioned issue.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
1 participant
@sbajic