Server down, MariaDB update failed.

Discussion in 'Server Operation' started by justinsane, Jan 29, 2016.

  1. justinsane

    justinsane New Member

    I ran apt-get update and apt-get upgrade a few days ago on my Debian Jessie Ispconfig 3.0.5.4p8 server.
    Things started to go wrong when I saw this:
    Setting up mariadb-server-10.0 (10.0.23-0+deb8u1) ...
    dpkg: error processing package mariadb-server-10.0 (--configure):
    subprocess installed post-installation script returned error exit status 7
    And this:
    dpkg: dependency problems prevent configuration of mariadb-server:
    mariadb-server depends on mariadb-server-10.0 (>= 10.0.23-0+deb8u1); however:
    Package mariadb-server-10.0 is not configured yet.
    dpkg: error processing package mariadb-server (--configure):
    dependency problems - leaving unconfigured
    And this:
    Errors were encountered while processing:
    mariadb-server-10.0
    mariadb-server
    E: Sub-process /usr/bin/dpkg returned an error code (1)
    You have mail in /var/mail/root
    root@s1:~#
    Now the database isn't working and the server is down.
    How do I fix this?
     
  2. till

    till Super Moderator Staff Member ISPConfig Developer

    Try:

    apt-get -f install

    and check the syslog why mariadb fails.
     
  3. justinsane

    justinsane New Member

    Thanks Till.
    Here are the relevant logs in case anyone else runs into this.
    It appears that the problem occurred because I had the audit plugin installed from here:
    https://mariadb.com/kb/en/mariadb/about-the-mariadb-audit-plugin/
    So I could log connections to the server. It was working fine until the update.

    Commenting out these lines in my.cnf allowed apt-get -f install to fix the problem and the server is now up again.
    #server_audit_events=CONNECT
    #server_audit_logging=on
    But those lines did not cause any issue until the update.

    Perhaps someone somewhere should know that that plugin breaks updates.

    Jan 26 12:24:51 s1 mysqld_safe[25500]: 160126 12:24:51 [Note] /usr/sbin/mysqld (mysqld 10.0.23-MariaDB-0+deb8u1) starting as process 25526 ...
    Jan 26 12:24:54 s1 mysqld_safe[25500]:
    Jan 26 12:24:54 s1 mysqld_safe[25500]: Installation of system tables failed! Examine the logs in
    Jan 26 12:24:54 s1 mysqld_safe[25500]: /var/lib/mysql for more information.
    Jan 26 12:24:54 s1 mysqld_safe[25500]:
    Jan 26 12:24:54 s1 mysqld_safe[25500]: The problem could be conflicting information in an external
    Jan 26 12:24:54 s1 mysqld_safe[25500]: my.cnf files. You can ignore these by doing:
    Jan 26 12:24:54 s1 mysqld_safe[25500]:
    Jan 26 12:24:54 s1 mysqld_safe[25500]: shell> /usr/scripts/scripts/mysql_install_db --defaults-file=~/.my.cnf
    Jan 26 12:24:54 s1 mysqld_safe[25500]:
    Jan 26 12:24:54 s1 mysqld_safe[25500]: You can also try to start the mysqld daemon with:
    Jan 26 12:24:54 s1 mysqld_safe[25500]:
    Jan 26 12:24:54 s1 mysqld_safe[25500]: shell> /usr/sbin/mysqld --skip-grant --general-log &
    Jan 26 12:24:54 s1 mysqld_safe[25500]:
    Jan 26 12:24:54 s1 mysqld_safe[25500]: and use the command line tool /usr/bin/mysql
    Jan 26 12:24:54 s1 mysqld_safe[25500]: to connect to the mysql database and look at the grant tables:
    Jan 26 12:24:54 s1 mysqld_safe[25500]:
    Jan 26 12:24:54 s1 mysqld_safe[25500]: shell> /usr/bin/mysql -u root mysql
    Jan 26 12:24:54 s1 mysqld_safe[25500]: mysql> show tables;
    Jan 26 12:24:54 s1 mysqld_safe[25500]:
    Jan 26 12:24:54 s1 mysqld_safe[25500]: Try 'mysqld --help' if you have problems with paths. Using
    Jan 26 12:24:54 s1 mysqld_safe[25500]: --general-log gives you a log in /var/lib/mysql that may be helpful.
    Jan 26 12:24:54 s1 mysqld_safe[25500]:
    Jan 26 12:24:54 s1 mysqld_safe[25500]: The latest information about mysql_install_db is available at
    Jan 26 12:24:54 s1 mysqld_safe[25500]: https://mariadb.com/kb/en/installing-system-tables-mysql_install_db
    Jan 26 12:24:54 s1 mysqld_safe[25500]: MariaDB is hosted on launchpad; You can find the latest source and
    Jan 26 12:24:54 s1 mysqld_safe[25500]: email lists at http://launchpad.net/maria
    Jan 26 12:24:54 s1 mysqld_safe[25500]:
    Jan 26 12:24:54 s1 mysqld_safe[25500]: Please check all of the above before submitting a bug report
    Jan 26 12:24:54 s1 mysqld_safe[25500]: at http://mariadb.org/jira
    Jan 26 12:24:54 s1 mysqld_safe[25500]:
    Jan 26 12:24:54 s1 mysqld_safe[25563]: 160126 12:24:54 [Note] /usr/sbin/mysqld (mysqld 10.0.23-MariaDB-0+deb8u1) starting as process 25562 ...

    root@s1:~# apt-get -f install
    Reading package lists... Done
    Building dependency tree
    Reading state information... Done
    0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded.
    2 not fully installed or removed.
    After this operation, 0 B of additional disk space will be used.
    Setting up mariadb-server-10.0 (10.0.23-0+deb8u1) ...
    dpkg: error processing package mariadb-server-10.0 (--configure):
    subprocess installed post-installation script returned error exit status 7
    dpkg: dependency problems prevent configuration of mariadb-server:
    mariadb-server depends on mariadb-server-10.0 (>= 10.0.23-0+deb8u1); however:
    Package mariadb-server-10.0 is not configured yet.

    dpkg: error processing package mariadb-server (--configure):
    dependency problems - leaving unconfigured
    Errors were encountered while processing:
    mariadb-server-10.0
    mariadb-server
    E: Sub-process /usr/bin/dpkg returned an error code (1)
    root@s1:~#


    160126 12:28:14 [Note] InnoDB: Using mutexes to ref count buffer pool pages
    160126 12:28:14 [Note] InnoDB: The InnoDB memory heap is disabled
    160126 12:28:14 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
    160126 12:28:14 [Note] InnoDB: Memory barrier is not used
    160126 12:28:14 [Note] InnoDB: Compressed tables use zlib 1.2.8
    160126 12:28:14 [Note] InnoDB: Using Linux native AIO
    160126 12:28:14 [Note] InnoDB: Using CPU crc32 instructions
    160126 12:28:14 [Note] InnoDB: Initializing buffer pool, size = 128.0M
    160126 12:28:14 [Note] InnoDB: Completed initialization of buffer pool
    160126 12:28:14 [Note] InnoDB: Highest supported file format is Barracuda.
    160126 12:28:14 [Note] InnoDB: 128 rollback segment(s) are active.
    160126 12:28:14 [Note] InnoDB: Waiting for purge to start
    160126 12:28:14 [Note] InnoDB: Percona XtraDB (http://www.percona.com) 5.6.26-76.0 started; log sequence number 12901364
    160126 12:28:14 [ERROR] /usr/sbin/mysqld: unknown variable 'server_audit_events=CONNECT'
    160126 12:28:14 [ERROR] Aborting

    160126 12:28:14 [Note] InnoDB: FTS optimize thread exiting.
    160126 12:28:14 [Note] InnoDB: Starting shutdown...
    160126 12:28:16 [Note] InnoDB: Shutdown completed; log sequence number 12901390
    160126 12:28:16 [Note] /usr/sbin/mysqld: Shutdown complete

    160126 12:28:16 [Note] InnoDB: Using mutexes to ref count buffer pool pages
    160126 12:28:16 [Note] InnoDB: The InnoDB memory heap is disabled
    160126 12:28:16 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
    160126 12:28:16 [Note] InnoDB: Memory barrier is not used
    160126 12:28:16 [Note] InnoDB: Compressed tables use zlib 1.2.8
    160126 12:28:16 [Note] InnoDB: Using Linux native AIO
    160126 12:28:16 [Note] InnoDB: Using CPU crc32 instructions
    160126 12:28:16 [Note] InnoDB: Initializing buffer pool, size = 128.0M
    160126 12:28:16 [Note] InnoDB: Completed initialization of buffer pool
    160126 12:28:16 [Note] InnoDB: Highest supported file format is Barracuda.
    160126 12:28:16 [Note] InnoDB: 128 rollback segment(s) are active.
    160126 12:28:16 [Note] InnoDB: Waiting for purge to start
    160126 12:28:16 [Note] InnoDB: Percona XtraDB (http://www.percona.com) 5.6.26-76.0 started; log sequence number 12901390
    160126 12:28:16 [Note] Plugin 'FEEDBACK' is disabled.
    160126 12:28:16 [ERROR] /usr/sbin/mysqld: unknown variable 'server_audit_events=CONNECT'
    160126 12:28:16 [ERROR] Aborting

    160126 12:28:16 [Note] InnoDB: FTS optimize thread exiting.
    160126 12:28:16 [Note] InnoDB: Starting shutdown...
    160126 12:28:18 [Note] InnoDB: Shutdown completed; log sequence number 12901400
    160126 12:28:18 [Note] /usr/sbin/mysqld: Shutdown complete
     
  4. justinsane

    justinsane New Member

    Just as a follow on to this I found out that I can uncomment the following lines in the [mysqld] section of my.cnf after the update.
    server_audit_events=CONNECT
    server_audit_logging=on
    And reboot the server.
    Logging then resumes as if nothing had happened.

    Does anyone know where I can file a bug report with MariaDB about this?
     
  5. BlueT

    BlueT New Member

    I'm experiencing exactly the same issue.
    mariadb-server-10.0

    @justinsane thanks for the hint. Did you find the root cause?

     

Share This Page