[MDEV-7329] plugins.pam_cleartext fails sporadically in buildbot Created: 2014-12-15  Updated: 2016-08-04  Resolved: 2016-08-04

Status: Closed
Project: MariaDB Server
Component/s: Tests
Affects Version/s: 5.5, 10.0, 10.1
Fix Version/s: 5.5.51, 10.1.17, 10.0.27

Type: Bug Priority: Critical
Reporter: Elena Stepanova Assignee: Sergei Golubchik
Resolution: Fixed Votes: 0
Labels: buildbot, tests

Issue Links:
Relates
relates to MDEV-7069 Fix buildbot failures in main server ... Stalled
Sprint: 5.5.51 & 10.2.2

 Description   

http://buildbot.askmonty.org/buildbot/builders/work-amd64-valgrind/builds/6489/steps/test/logs/stdio

plugins.pam_cleartext                    w3 [ fail ]
 
        Test ended at 2014-12-15 14:14:44
 
 
 
CURRENT_TEST: plugins.pam_cleartext
 
mysqltest: Could not open connection 'default': 0 
--- /var/lib/buildbot/maria-slave/work-opensuse-amd64/build/mysql-test/suite/plugins/r/pam_cleartext.result	2014-12-15 11:23:46.000000000 +0200
 
+++ /var/lib/buildbot/maria-slave/work-opensuse-amd64/build/mysql-test/suite/plugins/r/pam_cleartext.reject	2014-12-15 14:14:43.000000000 +0200
 
@@ -8,3 +8,5 @@
 
 drop user test_pam;
 
 drop user pam_test;
 
 uninstall plugin pam;
 
+Warnings:
 
+Warning	1620	Plugin is busy and will be uninstalled on shutdown
 
 
 
mysqltest: Result length mismatch



 Comments   
Comment by Elena Stepanova [ 2016-01-04 ]

Recent occasion: http://buildbot.askmonty.org/buildbot/builders/work-amd64-valgrind/builds/8171/steps/test/logs/stdio

Comment by Sergey Vojtovich [ 2016-06-30 ]

Fails reliably on valgrind builder with this patch:

diff --git a/sql/sql_acl.cc b/sql/sql_acl.cc
 
index 0a1c11e..e4d81aa 100644
 
--- a/sql/sql_acl.cc
 
+++ b/sql/sql_acl.cc
 
@@ -9061,7 +9061,10 @@ static int do_auth_once(THD *thd, const LEX_STRING *auth_plugin_name,
 
     }
 
 
 
     if (unlock_plugin)
 
+    {
 
+      sleep(1);
 
       plugin_unlock(thd, plugin);
 
+    }
 
   }
 
   else
 
   {

Couldn't yet make it fail locally. Adding assertion just before this warning is issued gives the following:

Thread 2 (Thread 18245):
 
#0  0x00007f02101abcb1 in nanosleep () from /lib64/libc.so.6
 
#1  0x00007f02101abaac in sleep () from /lib64/libc.so.6
 
#2  0x00000000005902e2 in do_auth_once (thd=0x1f73f20, auth_plugin_name=0x1fba8b8, mpvio=0x7f0211a58530) at /home/svoj/mariadb/sql/sql_acl.cc:9065
 
#3  0x000000000059a0de in acl_authenticate (thd=0x1f73f20, connect_errors=0, com_change_user_pkt_len=0) at /home/svoj/mariadb/sql/sql_acl.cc:9166
 
#4  0x000000000071a4db in check_connection (thd=0x1f73f20) at /home/svoj/mariadb/sql/sql_connect.cc:972
 
#5  0x000000000071b0ab in login_connection (thd=0x1f73f20) at /home/svoj/mariadb/sql/sql_connect.cc:1029
 
#6  0x000000000071b443 in thd_prepare_connection (thd=0x1f73f20) at /home/svoj/mariadb/sql/sql_connect.cc:1194
 
#7  0x000000000071ba34 in do_handle_one_connection (thd_arg=0x1f73f20) at /home/svoj/mariadb/sql/sql_connect.cc:1261
 
#8  0x000000000071bb41 in handle_one_connection (arg=0x1f73f20) at /home/svoj/mariadb/sql/sql_connect.cc:1186
 
#9  0x0000000000995e1f in pfs_spawn_thread (arg=0x1fcf6f0) at /home/svoj/mariadb/storage/perfschema/pfs.cc:1015
 
#10 0x00007f0211646070 in start_thread () from /lib64/libpthread.so.0
 
#11 0x00007f02101dd13d in clone () from /lib64/libc.so.6
 
#12 0x0000000000000000 in ?? ()
 
 
 
Thread 1 (Thread 18240):
 
#0  0x00007f021164ac66 in pthread_kill () from /lib64/libpthread.so.0
 
#1  0x0000000000d002da in my_write_core (sig=6) at /home/svoj/mariadb/mysys/stacktrace.c:457
 
#2  0x00000000007d9da4 in handle_fatal_signal (sig=6) at /home/svoj/mariadb/sql/signal_handler.cc:262
 
#3  <signal handler called>
 
#4  0x00007f021013c645 in raise () from /lib64/libc.so.6
 
#5  0x00007f021013dc33 in abort () from /lib64/libc.so.6
 
#6  0x00007f0210135329 in __assert_fail () from /lib64/libc.so.6
 
#7  0x0000000000628a12 in do_uninstall (thd=0x1ef6ed0, table=0x1fa3350, name=0x1efad38) at /home/svoj/mariadb/sql/sql_plugin.cc:2182
 
#8  0x000000000062a6ab in mysql_uninstall_plugin (thd=0x1ef6ed0, name=0x1efad38, dl_arg=0x1efad48) at /home/svoj/mariadb/sql/sql_plugin.cc:2268
 
#9  0x000000000061e314 in mysql_execute_command (thd=0x1ef6ed0) at /home/svoj/mariadb/sql/sql_parse.cc:4425
 
#10 0x000000000061ed53 in mysql_parse (thd=0x1ef6ed0, rawbuf=0x7f0208000ef8 "uninstall plugin pam", length=20, parser_state=0x7f020d069890) at /home/svoj/mariadb/sql/sql_parse.cc:5934
 
#11 0x000000000061fb35 in dispatch_command (command=COM_QUERY, thd=0x1ef6ed0, packet=0x1f61041 "uninstall plugin pam", packet_length=20) at /home/svoj/mariadb/sql/sql_parse.cc:1079
 
#12 0x000000000062127b in do_command (thd=0x1ef6ed0) at /home/svoj/mariadb/sql/sql_parse.cc:793
 
#13 0x000000000071ba50 in do_handle_one_connection (thd_arg=0x1ef6ed0) at /home/svoj/mariadb/sql/sql_connect.cc:1270
 
#14 0x000000000071bb41 in handle_one_connection (arg=0x1ef6ed0) at /home/svoj/mariadb/sql/sql_connect.cc:1186
 
#15 0x0000000000995e1f in pfs_spawn_thread (arg=0x1ff3510) at /home/svoj/mariadb/storage/perfschema/pfs.cc:1015
 
#16 0x00007f0211646070 in start_thread () from /lib64/libpthread.so.0
 
#17 0x00007f02101dd13d in clone () from /lib64/libc.so.6
 
#18 0x0000000000000000 in ?? ()

According to cross-reference this problem occurs only with 5.5. It affected 10.0 too, but didn't appear since end of 2013.

Comment by Sergey Vojtovich [ 2016-06-30 ]

$MYSQL_TEST executed by this test case fails differently on my host and on valgrind:

My host (correct failure): mysqltest: Could not open connection 'default': 1045 Access denied for user 'test_pam'@'localhost' (using password: NO)
 
Valgrind builder (wrong failure): mysqltest: Could not open connection 'default': 0
 
Valgrind builder (correct failure): mysqltest: Could not open connection 'default': 0

$MYSQL_TEST process (on valgrind builder) exits while do_auth_once() is still being executed.

Comment by Sergey Vojtovich [ 2016-06-30 ]

On valgrind builder there's /etc/pam.d/mariadb_mtr:

auth            required        pam_mariadb_mtr.so pam_test
 
account         required        pam_mariadb_mtr.so

There is /lib64/security/pam_mariadb_mtr.so

There is this code in sql-common/client.c:

  /*
 
    net->read_pos[0] should always be 0 here if the server implements
 
    the protocol correctly
 
  */
 
  DBUG_RETURN (mysql->net.read_pos[0] != 0);                                                                                                                                       │

But apparently it's not:

(gdb) p mysql->net.read_pos
 
$1 = (unsigned char *) 0xa59670 "\004Now, the magic number!\nPIN:"

Comment by Sergey Vojtovich [ 2016-06-30 ]

Indeed it didn't fail locally because PAM returns authentication error due to missing module.

Should this test at all run on hosts having no pam_mariadb_mtr.so?

I'm raising priority of this bug since PAM auth seem to be broken.

Generated at Thu Feb 08 07:18:45 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.