[MDEV-23933] main.failed_auth_unixsocket fails on arm Created: 2020-10-10  Updated: 2021-06-22  Resolved: 2021-06-09

Status: Closed
Project: MariaDB Server
Component/s: Tests
Affects Version/s: 10.5.5
Fix Version/s: 10.4.21, 10.5.12, 10.6.3

Type: Bug Priority: Major
Reporter: Otto Kekäläinen Assignee: Sergei Golubchik
Resolution: Fixed Votes: 0
Labels: None

Attachments: PNG File image-2020-10-10-22-09-38-762.png     File strace.log    

 Description   

While importing MariaDB 10.5 to Debian, I noticed that the test main.failed_auth_unixsocket fails on arch armhf and 386 (but arm64 or amd64) when the Debian autopkgtests run.

The test failure:

main.failed_auth_unixsocket              w4 [ fail ]
 
        Test ended at 2020-10-09 20:55:21
 
 
 
CURRENT_TEST: main.failed_auth_unixsocket
 
mysqltest: At line 18: query 'connect  fail,localhost,$USER' failed with wrong errno 1045: 'Access denied for user 'debci'@'localhost' (using password: NO)', instead of 1698...
 
 
 
The result from queries just before the failure was:
 
update mysql.global_priv set priv=json_insert(priv, '$.plugin', 'unix_socket')  where user='root';
 
flush privileges;
 
connect(localhost,USER,,test,MASTER_PORT,MASTER_SOCKET);

Full logs:

This did not occur with previous MariaDB 10.3 in Debian.

What are Debian autopkgtests?

See https://wiki.debian.org/ContinuousIntegration/autopkgtest

Debian has this massive CI system where each upload of a package triggers CI testing of other packages that depend on it: https://ci.debian.net/status/

The tests mariadb-10.5 runs are in the path debian/tests.

In MariaDB 10.5 we run mtr from the debian/tests/upstream test to re-use the existing test suite. Why this seems to end differently on debci from when run in post-build armhf and i386 builds is unknown.

On Debian buildd post-build mtr passes on main.failed_auth_unixsocket fine, e.g.

Debci regressions are also automatically listed on the package tracker page and prevents unstable->testing migration:

https://tracker.debian.org/pkg/mariadb-10.5

Potential solutions

Maybe the error code 1045 is just fine and test can be extended to accept it?

Or we can in Debian skip this one test in the autopkgtests to ignore it.

Previous work

The test ./mysql-test/main/failed_auth_unixsocket.* has been touched in the past by sanja and serg

 Comments   
Comment by Otto Kekäläinen [ 2020-10-12 ]

Cannot repeat on Launchpad builds:
https://launchpadlibrarian.net/501713384/buildlog_ubuntu-groovy-armhf.mariadb-10.5_1%3A10.5.5-4~ubuntu20.10.1~1602488010.9ccdf6955.master.next_BUILDING.txt.gz

main.failed_auth_unixsocket              w4 [ pass ]   1020

It must somehow be related to how debci runs the test.

Comment by Otto Kekäläinen [ 2020-10-12 ]

This can reportedly be reproduced by running:

autopkgtest --apt-upgrade --setup-commands='adduser debci' --user debci --shell-fail mariadb-10.5 -- lxc --sudo autopkgtest-unstable-i386

Container created with

autopkgtest-build-lxc debian unstable i386

Recreating the exact same scenario is likely not needed here, if somebody just can otherwise figure our why armhf and i386 yield different "access denied" code 1045 than the other archs 1698.

Comment by Otto Kekäläinen [ 2020-10-13 ]

Test contents:

cat ./mysql-test/main/failed_auth_unixsocket.test
 
--source include/have_unix_socket.inc
 
 
 
#
 
# MDEV-3909 remote user enumeration
 
# unix_socket tests
 
#
 
update mysql.global_priv set priv=json_insert(priv, '$.plugin', 'unix_socket')  where user='root';
 
flush privileges;
 
 
 
# Make sure that the replace works, even if $USER is 'user' or something else
 
# that matches other parts of the error message.
 
let $replace=Access denied for user '$USER';
 
 
 
--echo connect(localhost,USER,,test,MASTER_PORT,MASTER_SOCKET);
 
--replace_result $replace "Access denied for user 'USER'"
 
--disable_query_log
 
--error ER_ACCESS_DENIED_NO_PASSWORD_ERROR
 
connect (fail,localhost,$USER);
 
--enable_query_log
 
 
 
--replace_result $replace "Access denied for user 'USER'"
 
--error ER_ACCESS_DENIED_NO_PASSWORD_ERROR
 
change_user $USER;

The #define ER_ACCESS_DENIED_NO_PASSWORD_ERROR 1698 is defined in libmariadb/include/mysqld_error.h (which the test references) while the 1045 is from #define ER_ACCESS_DENIED_ERROR 1045 in the same file.

Maybe georg could help shed some insight into why we are seeing such a test error?

Comment by Otto Kekäläinen [ 2020-10-13 ]

The file sql/sql_acl.h has this:

static inline int access_denied_error_code(int passwd_used)
 
{
 
#ifdef mysqld_error_find_printf_error_used
 
  return 0;
 
#else
 
  return passwd_used == 2 ? ER_ACCESS_DENIED_NO_PASSWORD_ERROR
 
                          : ER_ACCESS_DENIED_ERROR;
 
#endif
 
}

And table.cc has

          if (thd->password == 2)
 
            my_error(ER_ACCESS_DENIED_NO_PASSWORD_ERROR, MYF(0),
 
                     thd->security_ctx->priv_user,
 
                     thd->security_ctx->priv_host);
 
          else
 
            my_error(ER_ACCESS_DENIED_ERROR, MYF(0),
 
                     thd->security_ctx->priv_user,
 
                     thd->security_ctx->priv_host,
 
                     (thd->password ?  ER_THD(thd, ER_YES) :
 
                      ER_THD(thd, ER_NO)));

Either one could be a potential source for sometimes emitting 1045 and some times 1698?

Comment by Georg Richter [ 2020-10-15 ]

otto Error codes were sent by server - not set by client (client only sets errors with values > 2000.

Comment by Otto Kekäläinen [ 2020-10-20 ]

I will now try https://salsa.debian.org/mariadb-team/mariadb-10.5/-/commit/f452db78a6b0df2f8003b2d75e7d8b2a48a34a2a

--- a/sql/sql_acl.h
 
+++ b/sql/sql_acl.h
 
@@ -66,7 +66,7 @@ static inline int access_denied_error_co
 
   return 0;
 
 #else
 
   return passwd_used == 2 ? ER_ACCESS_DENIED_NO_PASSWORD_ERROR
 
-                          : ER_ACCESS_DENIED_ERROR;
 
+                          : ER_ACCESS_DENIED_NO_PASSWORD_ERROR;
 
 #endif
 
 }
 
 
--- a/sql/table.cc
 
+++ b/sql/table.cc
 
@@ -6376,7 +6376,7 @@ bool TABLE_LIST::prepare_view_security_c
 
                      thd->security_ctx->priv_user,
 
                      thd->security_ctx->priv_host);
 
           else
 
-            my_error(ER_ACCESS_DENIED_ERROR, MYF(0),
 
+            my_error(ER_ACCESS_DENIED_NO_PASSWORD_ERROR, MYF(0),
 
                      thd->security_ctx->priv_user,
 
                      thd->security_ctx->priv_host,
 
                      (thd->password ?  ER_THD(thd, ER_YES) :

Comment by Otto Kekäläinen [ 2020-10-20 ]

Nope, the approach above does will not work. Next, looking at wrapper:

/**
 
  a helper function to report an access denied error in most proper places
 
*/
 
static void login_failed_error(THD *thd)
 
{
 
  my_error(access_denied_error_code(thd->password), MYF(0),
 
           thd->main_security_ctx.user,
 
           thd->main_security_ctx.host_or_ip,
 
           thd->password ? ER_THD(thd, ER_YES) : ER_THD(thd, ER_NO));
 
  general_log_print(thd, COM_CONNECT,
 
                    ER_THD(thd, access_denied_error_code(thd->password)),
 
                    thd->main_security_ctx.user,
 
                    thd->main_security_ctx.host_or_ip,
 
                    thd->password ? ER_THD(thd, ER_YES) : ER_THD(thd, ER_NO));
 
  status_var_increment(thd->status_var.access_denied_errors);
 
  /*
 
    Log access denied messages to the error log when log-warnings = 2
 
    so that the overhead of the general query log is not required to track
 
    failed connections.
 
  */
 
  if (global_system_variables.log_warnings > 1)
 
  {
 
    sql_print_warning(ER_THD(thd, access_denied_error_code(thd->password)),
 
                      thd->main_security_ctx.user,
 
                      thd->main_security_ctx.host_or_ip,
 
                      thd->password ? ER_THD(thd, ER_YES) : ER_THD(thd, ER_NO));
 
  }
 
}

Could the code above have something that behaves differently in armhf/i386 on debci vs amd64 on debci?

Or maybe this? At least the comment field looks fishy:

if (!mpvio->acl_user)
 
  {
 
    /*
 
      A matching user was not found. Fake it. Take any user, make the
 
      authentication fail later.
 
      This way we get a realistically looking failure, with occasional
 
      "change auth plugin" requests even for nonexistent users. The ratio
 
      of "change auth plugin" request will be the same for real and
 
      nonexistent users.
 
      Note, that we cannot pick any user at random, it must always be
 
      the same user account for the incoming sctx->user name.
 
    */
 
    ulong nr1=1, nr2=4;
 
    CHARSET_INFO *cs= &my_charset_latin1;
 
    cs->hash_sort((uchar*) sctx->user, strlen(sctx->user), &nr1, &nr2);
 
 
 
    mysql_mutex_lock(&acl_cache->lock);
 
    if (!acl_users.elements)
 
    {
 
      mysql_mutex_unlock(&acl_cache->lock);
 
      login_failed_error(mpvio->auth_info.thd);
 
      DBUG_RETURN(1);
 
    }

Comment by Otto Kekäläinen [ 2020-10-22 ]

This has not been assigned to anybody, and unlikely to be fixed in a reasonable amount of time, so I'll try to hack around the issue by selectively disabling this test in https://salsa.debian.org/mariadb-team/mariadb-10.5/-/commit/74601f8b31a6c59e825089c52a1ca21545062813

Comment by Daniel Black [ 2020-10-26 ]

strace form nikitamalyavin (Arch)

The strace shows it doesn't lookup the unix socket user using a syscall before issuing the denial. Odd.
SO_PEERCRED (getsockopt)
FYI eworm

Comment by Otto Kekäläinen [ 2020-12-20 ]

This is still unsolved and unassigned. Maybe julien.fritsch wants to decide if it needs to be fixed or not?

Generated at Thu Feb 08 09:26:09 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.