Navigation

    Kopano
    • Register
    • Login
    • Search
    • Categories
    • Get Official Kopano Support
    • Recent
    Statement regarding the closure of the Kopano community forum and the end of the community edition

    [SOLVED] Big Problem, Kopano server could not connect to MariaDB-Server

    Kopano Groupware Core
    3
    19
    5611
    Loading More Posts
    • Oldest to Newest
    • Newest to Oldest
    • Most Votes
    Reply
    • Reply as topic
    Log in to reply
    This topic has been deleted. Only users with topic management privileges can see it.
    • mkromer
      mkromer last edited by

      Hi Christian,

      no worries about your english, you’re easy to understand :) Regarding your issue: Could you please check if the connection to your db works with mysql_host = 127.0.0.1 in server.cfg (NOT localhost) - When localhost is defined, kopano-server always tries to use the socket instead. I can’t see anything obvious wrong, because your mysqld seems to run (according to your log-messages you provide) and kopano-server just bails out with not being able to connect. So I would first rule out that the socket (for whatever reason) is not accessible by kopano-server (e.g. permissions, etc.).

      - mike

      1 Reply Last reply Reply Quote 0
      • kamikaze2508
        kamikaze2508 last edited by

        Hi Mike,

        thanks for your fast response.
        Unfortunately, changing the connection type did not work. The error message in server.log has not changed much.

        Mon Jan  1 21:50:36 2018: [ notice] Starting server version 8,3,4,12, pid 1528
Mon Jan  1 21:50:36 2018: [warning] SQL [00000002] info: Try to reconnect
Mon Jan  1 21:50:36 2018: [error  ] KDatabase::Connect(): database access error -2147483641, mysql error: Can't connect to MySQL server on '127.0.0.1' (111)
Mon Jan  1 21:50:36 2018: [error  ] KDatabase::_Update() query failed: REPLACE INTO settings VALUES ('attachment_storage', 'database'): MYSQL not initialized
Mon Jan  1 21:50:36 2018: [error  ] Unable to update database settings
Mon Jan  1 21:50:36 2018: [ notice] Server shutdown complete.

        /etc/init.d/mysql status currently brings the following messages:

        mysql.service - LSB: Start and stop the mysql database server daemon
   Loaded: loaded (/etc/init.d/mysql)
   Active: active (running) since Mo 2018-01-01 21:47:09 CET; 10min ago
  Process: 550 ExecStart=/etc/init.d/mysql start (code=exited, status=0/SUCCESS)
   CGroup: /system.slice/mysql.service
           ├─ 633 /bin/bash /usr/bin/mysqld_safe
           ├─1564 /usr/sbin/mysqld --basedir=/usr --datadir=/var/lib/mysql --plugin-dir=/usr/lib/mysql/plugin --user=mysql --skip-log-error --pid-file=/var/run/mysqld/mysqld.pid --socket=/var/run/mysqld/mysqld.sock --port=3306
           └─1565 logger -t mysqld -p daemon.error

Jan 01 21:50:36 rohrpostix mysqld[1565]: 180101 21:50:36 [Note] InnoDB: Highest supported file format is Barracuda.
Jan 01 21:50:36 rohrpostix mysqld[1565]: 180101 21:50:36 [Note] InnoDB: The log sequence numbers 8352532333 and 8352532333 in ibdata files do not match the log sequence number 8352532373 in the ib_logfiles!
Jan 01 21:50:36 rohrpostix mysqld[1565]: 180101 21:50:36 [Note] InnoDB: Restoring possible half-written data pages from the doublewrite buffer...
Jan 01 21:50:36 rohrpostix mysqld[1565]: 180101 21:50:36 [Note] InnoDB: 128 rollback segment(s) are active.
Jan 01 21:50:36 rohrpostix mysqld[1565]: 180101 21:50:36 [Note] InnoDB: Waiting for purge to start
Jan 01 21:50:37 rohrpostix mysqld[1565]: 180101 21:50:37 [Note] InnoDB:  Percona XtraDB (http://www.percona.com) 5.6.36-82.1 started; log sequence number 8352532373
Jan 01 21:50:37 rohrpostix mysqld[1565]: 180101 21:50:37 [Note] Plugin 'FEEDBACK' is disabled.
Jan 01 21:50:37 rohrpostix mysqld[1565]: 180101 21:50:37 [Note] Server socket created on IP: '127.0.0.1'.
Jan 01 21:50:37 rohrpostix mysqld[1565]: 180101 21:50:37 [Note] /usr/sbin/mysqld: ready for connections.
Jan 01 21:50:37 rohrpostix mysqld[1565]: Version: '10.0.32-MariaDB-0+deb8u1'  socket: '/var/run/mysqld/mysqld.sock'  port: 3306  (Debian)

        That is very strange. Everything went right before the server failed.

        Thanks again for the fast support.

        Best regards,
        Christian

        1 Reply Last reply Reply Quote 0
        • mkromer
          mkromer last edited by

          @kamikaze2508 said in Big Problem, Kopano server could not connect to MariaDB-Server:

          MYSQL not initialized

          So, not even a connect is possible, as per “Can’t connect to MySQL server on ‘127.0.0.1’ (111)”.

          Please post the output of

          netstat -tulpen | grep mysqld

          Thanks!

          - mike

          1 Reply Last reply Reply Quote 0
          • kamikaze2508
            kamikaze2508 last edited by

            OK, here it is:

            root@rohrpostix:~# netstat -tulpen | grep mysqld
tcp        0      0 127.0.0.1:3306          0.0.0.0:*               LISTEN      108        11048       1025/mysqld

            If it does work, here is the output of ps ax | grep mysqld

            root@rohrpostix:~# ps ax | grep mysqld
  634 ?        S      0:00 /bin/bash /usr/bin/mysqld_safe
 1025 ?        Sl     0:00 /usr/sbin/mysqld --basedir=/usr --datadir=/var/lib/mysql --plugin-dir=/usr/lib/mysql/plugin --user=mysql --skip-log-error --pid-file=/var/run/mysqld/mysqld.pid --socket=/var/run/mysqld/mysqld.sock --port=3306
 1026 ?        S      0:00 logger -t mysqld -p daemon.error
 1580 pts/0    S+     0:00 grep mysqld
            1 Reply Last reply Reply Quote 0
            • kamikaze2508
              kamikaze2508 last edited by kamikaze2508

              Hi Mike!

              In the meantime, I was able to find out why the Kopano server daemon was unable to connect through 127.0.0.1. I restricted the user with which Kopano wants to connect to the database to localhost. After 127.0.0.1 was added as an authorized host, it looked good at first. But a few seconds later I got the following entries in server.log:

              Tue Jan  2 06:55:42 2018: [ notice] Starting server version 8,3,4,12, pid 1923
Tue Jan  2 06:56:08 2018: [warning] SQL [00000048] info: Try to reconnect
Tue Jan  2 06:56:08 2018: [error  ] KDatabase::Connect(): database access error -2147483641, mysql error: Can't connect to MySQL server on '127.0.0.1' (111)
Tue Jan  2 06:56:08 2018: [error  ] KDatabase::_Update() query failed: UPDATE syncs SET change_id = 55730, sync_time = FROM_UNIXTIME(1514872568) WHERE id    = 1: MYSQL not initialized
Tue Jan  2 06:56:08 2018: [warning] SQL [00000000] info: Try to reconnect
Tue Jan  2 06:56:08 2018: [error  ] KDatabase::Connect(): database access error -2147483641, mysql error: Can't connect to MySQL server on '127.0.0.1' (111)
Tue Jan  2 06:56:13 2018: [warning] SQL [00000049] info: Try to reconnect
Tue Jan  2 06:56:13 2018: [warning] SQL [00000045] info: Try to reconnect
Tue Jan  2 06:56:14 2018: [warning] SQL [00000003] info: Try to reconnect
Tue Jan  2 06:56:14 2018: [error  ] KDatabase::Connect(): database access error -2147483641, mysql error: Can't connect to MySQL server on '127.0.0.1' (111)
Tue Jan  2 06:56:14 2018: [error  ] KDatabase::_Update() query failed: UPDATE syncs SET change_id = 55730, sync_time = FROM_UNIXTIME(1514872573) WHERE id    = 1: MYSQL not initialized
Tue Jan  2 06:56:14 2018: [warning] SQL [00000000] info: Try to reconnect
Tue Jan  2 06:56:14 2018: [error  ] KDatabase::Connect(): database access error -2147483641, mysql error: Can't connect to MySQL server on '127.0.0.1' (111)
Tue Jan  2 06:56:19 2018: [warning] SQL [00000046] info: Try to reconnect
Tue Jan  2 06:56:19 2018: [warning] SQL [00000047] info: Try to reconnect
Tue Jan  2 06:56:19 2018: [warning] SQL [00000003] info: Try to reconnect
Tue Jan  2 06:56:19 2018: [error  ] KDatabase::Connect(): database access error -2147483641, mysql error: Can't connect to MySQL server on '127.0.0.1' (111)
Tue Jan  2 06:56:19 2018: [error  ] KDatabase::_Update() query failed: UPDATE syncs SET change_id = 55730, sync_time = FROM_UNIXTIME(1514872579) WHERE id    = 1: MYSQL not initialized
Tue Jan  2 06:56:19 2018: [warning] SQL [00000000] info: Try to reconnect
Tue Jan  2 06:56:19 2018: [error  ] KDatabase::Connect(): database access error -2147483641, mysql error: Can't connect to MySQL server on '127.0.0.1' (111)
Tue Jan  2 06:56:24 2018: [warning] SQL [00000043] info: Try to reconnect
Tue Jan  2 06:56:24 2018: [warning] SQL [00000044] info: Try to reconnect

... and so on

              So I stoped the Daemon and started it again.
              Now I get the old message again:

              Tue Jan  2 07:11:37 2018: [ notice] Starting server version 8,3,4,12, pid 4242
Tue Jan  2 07:11:38 2018: [warning] SQL [00000004] info: Try to reconnect
Tue Jan  2 07:11:38 2018: [error  ] KDatabase::Connect(): database access error -2147483641, mysql error: Can't connect to MySQL server on '127.0.0.1' (111)
Tue Jan  2 07:11:38 2018: [error  ] KDatabase::_Update() query failed: REPLACE INTO settings VALUES ('attachment_storage', 'database'): MYSQL not initialized
Tue Jan  2 07:11:38 2018: [error  ] Unable to update database settings
Tue Jan  2 07:11:38 2018: [ notice] Server shutdown complete.

              I can log in with the Kopano database user via the mysql console without any problems. The following hosts are authorized in MariaDB:

              +------------------+------------+
| User             | Host       |
+------------------+------------+
| kopano           | %          |
| kopano           | 127.0.0.1  |
| root             | 127.0.0.1  |
| root             | ::1        |
| debian-sys-maint | localhost  |
| kopano           | localhost  |
| phpmyadmin       | localhost  |
| root             | localhost  |
| root             | rohrpostix |
+------------------+------------+
              1 Reply Last reply Reply Quote 0
              • kamikaze2508
                kamikaze2508 last edited by kamikaze2508

                Hi!
                It get’s more and more strange.
                After I try to start kopano-server sometimes kopano-server is terminated directly and sometimes it keeps running, but throw out a lot of error messages:

                Tue Jan  2 07:31:02 2018: [ notice] Starting server version 8,3,4,12, pid 5828
Tue Jan  2 07:31:22 2018: [warning] SQL [00000028] info: Try to reconnect
Tue Jan  2 07:31:22 2018: [warning] SQL [00000020] info: Try to reconnect
Tue Jan  2 07:31:22 2018: [error  ] KDatabase::Connect(): database access error -2147483641, mysql error: Can't connect to MySQL server on '127.0.0.1' (111)
Tue Jan  2 07:31:22 2018: [error  ] KDatabsae::DoSelect(): query failed: SELECT hierarchy_id FROM stores WHERE stores.user_id=3: MYSQL not initialized
Tue Jan  2 07:31:22 2018: [warning] SQL [00000000] info: Try to reconnect
Tue Jan  2 07:31:22 2018: [error  ] KDatabase::Connect(): database access error -2147483641, mysql error: Can't connect to MySQL server on '127.0.0.1' (111)
Tue Jan  2 07:31:22 2018: [error  ] KDatabase::_Update() query failed: UPDATE syncs SET change_id = 55730, sync_time = FROM_UNIXTIME(1514874682) WHERE id                                                                                                                                                              = 1: MYSQL not initialized
Tue Jan  2 07:31:22 2018: [warning] SQL [00000000] info: Try to reconnect
Tue Jan  2 07:31:22 2018: [error  ] KDatabase::Connect(): database access error -2147483641, mysql error: Can't connect to MySQL server on '127.0.0.1' (111)
Tue Jan  2 07:31:22 2018: [error  ] KDatabsae::DoSelect(): query failed: SELECT hierarchy_id FROM stores WHERE stores.user_id=3: MYSQL not initialized
Tue Jan  2 07:31:22 2018: [warning] Writeout of logon/off time cache unsuccessful
Tue Jan  2 07:31:25 2018: [warning] SQL [00000022] info: Try to reconnect
Tue Jan  2 07:31:25 2018: [warning] SQL [00000024] info: Try to reconnect
Tue Jan  2 07:31:25 2018: [warning] SQL [00000029] info: Try to reconnect
Tue Jan  2 07:31:25 2018: [warning] SQL [00000025] info: Try to reconnect
Tue Jan  2 07:31:25 2018: [warning] SQL [00000026] info: Try to reconnect
Tue Jan  2 07:31:25 2018: [warning] SQL [00000000] info: Try to reconnect
Tue Jan  2 07:31:25 2018: [warning] SQL [00000023] info: Try to reconnect
Tue Jan  2 07:31:25 2018: [warning] SQL [00000027] info: Try to reconnect
Tue Jan  2 07:31:27 2018: [warning] SQL [00000000] info: Try to reconnect
Tue Jan  2 07:31:28 2018: [warning] SQL [00000009] info: Try to reconnect
Tue Jan  2 07:31:28 2018: [warning] SQL [00000010] info: Try to reconnect
Tue Jan  2 07:31:28 2018: [warning] SQL [00000008] info: Try to reconnect
Tue Jan  2 07:31:28 2018: [error  ] KDatabase::Connect(): database access error -2147483641, mysql error: Can't connect to MySQL server on '127.0.0.1' (111)
Tue Jan  2 07:31:28 2018: [error  ] KDatabase::_Update() query failed: REPLACE INTO properties (tag, type, hierarchyid, val_hi, val_lo) VALUES(26274,64,10,30638995,1362692480): MYSQL not initialized
Tue Jan  2 07:31:28 2018: [warning] SQL [00000000] info: Try to reconnect
Tue Jan  2 07:31:28 2018: [error  ] KDatabase::Connect(): database access error -2147483641, mysql error: Can't connect to MySQL server on '127.0.0.1' (111)
Tue Jan  2 07:31:28 2018: [error  ] KDatabsae::DoSelect(): query failed: SELECT 0,properties.tag,properties.type,properties.val_ulong,properties.val_strin                                                                                                                                                             g,properties.val_binary,properties.val_double,properties.val_longint,properties.val_hi,properties.val_lo FROM properties WHERE hierarchyid=1185 AND properties.tag IN (32781,32782,32803): MYSQL not initialized
Tue Jan  2 07:31:28 2018: [error  ] KDatabase::Connect(): database access error -2147483641, mysql error: Can't connect to MySQL server on '127.0.0.1' (111)
Tue Jan  2 07:31:28 2018: [warning] Writeout of logon/off time cache unsuccessful
Tue Jan  2 07:31:28 2018: [warning] SQL [00000006] info: Try to reconnect
Tue Jan  2 07:31:28 2018: [error  ] KDatabase::Connect(): database access error -2147483641, mysql error: Can't connect to MySQL server on '127.0.0.1' (111)
Tue Jan  2 07:31:28 2018: [error  ] KDatabsae::DoSelect(): query failed: SELECT pass.propname, pass.value, o.externid, modtime.value, op.value FROM object AS o JOIN objectproperty AS op ON o.id = op.objectid JOIN objectproperty AS pass ON pass.objectid = o.id LEFT JOIN objectproperty AS modtime ON modtime.objectid = o.id AND modtime.propname = 'modtime' WHERE o.objectclass = 65537 AND op.propname = 'loginname' AND op.value = 'christian' AND pass.propname = 'password': MYSQL not initialized
Tue Jan  2 07:31:28 2018: [warning] Authentication error by plugin for user "christian": db_query: Unknown error -2147483641
Tue Jan  2 07:31:28 2018: [warning] Failed to authenticate user "christian" from "file:///var/run/kopano/server.sock" using program "apache2"
Tue Jan  2 07:31:28 2018: [warning] SQL [00000000] info: Try to reconnect
Tue Jan  2 07:31:28 2018: [error  ] KDatabase::Connect(): database access error -2147483641, mysql error: Can't connect to MySQL server on '127.0.0.1' (111)
Tue Jan  2 07:31:28 2018: [error  ] KDatabsae::DoSelect(): query failed: SELECT pass.propname, pass.value, o.externid, modtime.value, op.value FROM object AS o JOIN objectproperty AS op ON o.id = op.objectid JOIN objectproperty AS pass ON pass.objectid = o.id LEFT JOIN objectproperty AS modtime ON modtime.objectid = o.id AND modtime.propname = 'modtime' WHERE o.objectclass = 65537 AND op.propname = 'loginname' AND op.value = 'christian' AND pass.propname = 'password': MYSQL not initialized
Tue Jan  2 07:31:28 2018: [warning] Authentication error by plugin for user "christian": db_query: Unknown error -2147483641
Tue Jan  2 07:31:28 2018: [warning] Failed to authenticate user "christian" from "file:///var/run/kopano/server.sock" using program "apache2"
Tue Jan  2 07:31:29 2018: [warning] SQL [00000000] info: Try to reconnect
Tue Jan  2 07:31:29 2018: [warning] SQL [00000002] info: Try to reconnect
Tue Jan  2 07:31:29 2018: [warning] SQL [00000003] info: Try to reconnect
Tue Jan  2 07:31:29 2018: [warning] SQL [00000007] info: Try to reconnect
Tue Jan  2 07:31:29 2018: [warning] SQL [00000004] info: Try to reconnect
Tue Jan  2 07:31:33 2018: [warning] SQL [00000000] info: Try to reconnect
Tue Jan  2 07:31:33 2018: [warning] SQL [00000008] info: Try to reconnect
Tue Jan  2 07:31:33 2018: [warning] SQL [00000007] info: Try to reconnect
Tue Jan  2 07:31:33 2018: [error  ] KDatabase::Connect(): database access error -2147483641, mysql error: Can't connect to MySQL server on '127.0.0.1' (111)
Tue Jan  2 07:31:33 2018: [error  ] KDatabase::_Update() query failed: REPLACE INTO properties (tag, type, hierarchyid, val_hi, val_lo) VALUES(26275,64,10,30638995,1382692480): MYSQL not initialized
Tue Jan  2 07:31:33 2018: [error  ] KDatabsae::DoSelect(): query failed: SELECT MAX(id) FROM changes: MYSQL not initialized
Tue Jan  2 07:31:33 2018: [warning] SQL [00000000] info: Try to reconnect
Tue Jan  2 07:31:33 2018: [error  ] KDatabase::Connect(): database access error -2147483641, mysql error: Can't connect to MySQL server on '127.0.0.1' (111)
Tue Jan  2 07:31:33 2018: [error  ] KDatabsae::DoSelect(): query failed: SELECT hierarchy_id FROM stores WHERE stores.user_id=3: MYSQL not initialized
Tue Jan  2 07:31:33 2018: [warning] Writeout of logon/off time cache unsuccessful
Tue Jan  2 07:31:38 2018: [warning] SQL [00000005] info: Try to reconnect
Tue Jan  2 07:31:38 2018: [warning] SQL [00000006] info: Try to reconnect
Tue Jan  2 07:31:38 2018: [warning] SQL [00000000] info: Try to reconnect
Tue Jan  2 07:31:38 2018: [warning] SQL [00000002] info: Try to reconnect
Tue Jan  2 07:31:38 2018: [warning] SQL [00000003] info: Try to reconnect
Tue Jan  2 07:31:39 2018: [warning] SQL [00000004] info: Try to reconnect
Tue Jan  2 07:31:39 2018: [warning] SQL [00000008] info: Try to reconnect
Tue Jan  2 07:31:39 2018: [error  ] KDatabase::Connect(): database access error -2147483641, mysql error: Can't connect to MySQL server on '127.0.0.1' (111)
Tue Jan  2 07:31:39 2018: [error  ] KDatabase::_Update() query failed: UPDATE syncs SET change_id = 55730, sync_time = FROM_UNIXTIME(1514874698) WHERE id                                                                                                                                                              = 1: MYSQL not initialized
Tue Jan  2 07:31:39 2018: [warning] SQL [00000000] info: Try to reconnect
Tue Jan  2 07:31:39 2018: [error  ] KDatabase::Connect(): database access error -2147483641, mysql error: Can't connect to MySQL server on '127.0.0.1' (111)
Tue Jan  2 07:31:39 2018: [error  ] KDatabsae::DoSelect(): query failed: SELECT DISTINCT o.externid, o.objectclass, modtime.value, user.value FROM object AS o JOIN objectproperty AS user ON user.objectid = o.id AND upper(user.value) = upper('christian') AND user.propname = 'loginname' LEFT JOIN objectproperty AS modtime ON modtime.propname = 'modtime' AND modtime.objectid = o.id WHERE (o.objectclass & 0xffff0000) = 65536: MYSQL not initialized
Tue Jan  2 07:31:39 2018: [warning] Unable to resolve unknown user "christian": db_query: Unknown error -2147483641
Tue Jan  2 07:31:39 2018: [warning] SQL [00000000] info: Try to reconnect
Tue Jan  2 07:31:39 2018: [error  ] KDatabase::Connect(): database access error -2147483641, mysql error: Can't connect to MySQL server on '127.0.0.1' (111)
Tue Jan  2 07:31:39 2018: [error  ] KDatabsae::DoSelect(): query failed: SELECT pass.propname, pass.value, o.externid, modtime.value, op.value FROM object AS o JOIN objectproperty AS op ON o.id = op.objectid JOIN objectproperty AS pass ON pass.objectid = o.id LEFT JOIN objectproperty AS modtime ON modtime.objectid = o.id AND modtime.propname = 'modtime' WHERE o.objectclass = 65537 AND op.propname = 'loginname' AND op.value = 'christian' AND pass.propname = 'password': MYSQL not initialized
Tue Jan  2 07:31:39 2018: [warning] Authentication error by plugin for user "christian": db_query: Unknown error -2147483641
Tue Jan  2 07:31:39 2018: [warning] Failed to authenticate user "christian" from "file:///var/run/kopano/server.sock" using program "kopano-dagent"
Tue Jan  2 07:31:44 2018: [warning] SQL [00000007] info: Try to reconnect
Tue Jan  2 07:31:44 2018: [warning] SQL [00000000] info: Try to reconnect
Tue Jan  2 07:31:44 2018: [warning] SQL [00000003] info: Try to reconnect
Tue Jan  2 07:31:44 2018: [error  ] KDatabase::Connect(): database access error -2147483641, mysql error: Can't connect to MySQL server on '127.0.0.1' (111)
Tue Jan  2 07:31:44 2018: [error  ] KDatabase::_Update() query failed: UPDATE syncs SET change_id = 55730, sync_time = FROM_UNIXTIME(1514874704) WHERE id                                                                                                                                                              = 1: MYSQL not initialized
Tue Jan  2 07:31:44 2018: [warning] SQL [00000000] info: Try to reconnect
Tue Jan  2 07:31:44 2018: [error  ] KDatabase::Connect(): database access error -2147483641, mysql error: Can't connect to MySQL server on '127.0.0.1' (111)
Tue Jan  2 07:31:49 2018: [warning] SQL [00000000] info: Try to reconnect
Tue Jan  2 07:31:49 2018: [warning] SQL [00000005] info: Try to reconnect
Tue Jan  2 07:31:50 2018: [warning] SQL [00000003] info: Try to reconnect
Tue Jan  2 07:31:50 2018: [error  ] KDatabase::Connect(): database access error -2147483641, mysql error: Can't connect to MySQL server on '127.0.0.1' (111)
Tue Jan  2 07:31:50 2018: [error  ] KDatabase::_Update() query failed: UPDATE syncs SET change_id = 55730, sync_time = FROM_UNIXTIME(1514874709) WHERE id                                                                                                                                                              = 1: MYSQL not initialized
Tue Jan  2 07:31:50 2018: [warning] SQL [00000000] info: Try to reconnect
Tue Jan  2 07:31:50 2018: [error  ] KDatabase::Connect(): database access error -2147483641, mysql error: Can't connect to MySQL server on '127.0.0.1' (111)
Tue Jan  2 07:31:55 2018: [warning] SQL [00000004] info: Try to reconnect
Tue Jan  2 07:31:55 2018: [warning] SQL [00000003] info: Try to reconnect
Tue Jan  2 07:31:55 2018: [error  ] KDatabase::Connect(): database access error -2147483641, mysql error: Can't connect to MySQL server on '127.0.0.1' (111)
Tue Jan  2 07:31:55 2018: [error  ] KDatabase::_Update() query failed: UPDATE syncs SET change_id = 55730, sync_time = FROM_UNIXTIME(1514874715) WHERE id                                                                                                                                                              = 1: MYSQL not initialized
Tue Jan  2 07:31:55 2018: [warning] SQL [00000000] info: Try to reconnect
Tue Jan  2 07:31:55 2018: [error  ] KDatabase::Connect(): database access error -2147483641, mysql error: Can't connect to MySQL server on '127.0.0.1' (111)
Tue Jan  2 07:32:00 2018: [warning] SQL [00000005] info: Try to reconnect
Tue Jan  2 07:32:00 2018: [warning] SQL [00000006] info: Try to reconnect
Tue Jan  2 07:32:00 2018: [warning] SQL [00000003] info: Try to reconnect
Tue Jan  2 07:32:00 2018: [error  ] KDatabase::Connect(): database access error -2147483641, mysql error: Can't connect to MySQL server on '127.0.0.1' (111)
Tue Jan  2 07:32:00 2018: [error  ] KDatabase::_Update() query failed: UPDATE syncs SET change_id = 55730, sync_time = FROM_UNIXTIME(1514874720) WHERE id                                                                                                                                                              = 1: MYSQL not initialized
Tue Jan  2 07:32:00 2018: [warning] SQL [00000000] info: Try to reconnect
Tue Jan  2 07:32:00 2018: [error  ] KDatabase::Connect(): database access error -2147483641, mysql error: Can't connect to MySQL server on '127.0.0.1' (111)
Tue Jan  2 07:32:06 2018: [warning] SQL [00000002] info: Try to reconnect
Tue Jan  2 07:32:06 2018: [warning] SQL [00000000] info: Try to reconnect
Tue Jan  2 07:32:06 2018: [warning] SQL [00000003] info: Try to reconnect
Tue Jan  2 07:32:06 2018: [error  ] KDatabase::Connect(): database access error -2147483641, mysql error: Can't connect to MySQL server on '127.0.0.1' (111)
Tue Jan  2 07:32:06 2018: [error  ] KDatabase::_Update() query failed: UPDATE syncs SET change_id = 55730, sync_time = FROM_UNIXTIME(1514874726) WHERE id                                                                                                                                                              = 1: MYSQL not initialized
Tue Jan  2 07:32:06 2018: [warning] SQL [00000000] info: Try to reconnect
Tue Jan  2 07:32:06 2018: [error  ] KDatabase::Connect(): database access error -2147483641, mysql error: Can't connect to MySQL server on '127.0.0.1' (111)
Tue Jan  2 07:32:08 2018: [warning] Shutting down
Tue Jan  2 07:32:10 2018: [ notice] Server shutdown complete.

                If I try to log in via WebApp during this time, I get the following message in WebApp:
                0_1514875779082_screenshot_webapp.jpg

                1 Reply Last reply Reply Quote 0
                • kamikaze2508
                  kamikaze2508 last edited by kamikaze2508

                  Hi all!
                  In the meantime, I have made further attempts to restore the database connection.
                  After I copied the virtual machine, I tried to reinstall the MariaDB server with the command “apt-get --reinstall install mariadb-server mariadb-common mariab-server-10.0 mariadb-server-core-10.0”. The reinstallation was apparently also carried out by apt-get. The reinstallation has unfortunately brought no improvement. The connection error still exists.

                  1 Reply Last reply Reply Quote 0
                  • Coffee_is_life
                    Coffee_is_life last edited by

                    Hello @kamikaze2508,

                    you said this error occured after vm-crash. maybe the connection itself is working but it cant access the tables. Some error messages can mislead every admin :)

                    Since you reinstalled your mariadb and this didnt change a thing (cause the program itself is not the problem) there is the option to recreate the tables:

                    /usr/bin/mysqlcheck --all-databases --auto-repair --extended --optimize -u <user> -p<password>

                    Output should be following:

                    Table does not support optimize, doing recreate + analyze instead

                    and the table will be recreated. Note that the server require additional diskspace equal to the table which is currently recreating.

                    i think its worth a try even if the mysqlcheck output is

                    kopano.abchanges                                   OK
kopano.acl                                         OK
[...]

                    coffee_is_life

                    1 Reply Last reply Reply Quote 0
                    • kamikaze2508
                      kamikaze2508 last edited by kamikaze2508

                      Hello Coffe_is_life,

                      thanks for your reply.
                      If I use the command above I’ve got this Error Message:

                      mysqlcheck: Got error: 2013: Lost connection to MySQL server during query when executing 'OPTIMIZE TABLE ... '

                      I repeated the command while tracing /var/log/syslog. I’ve got this messages:

                      Jan  3 11:23:42 rohrpostix mysqld: InnoDB: Error: trying to access page number 4294962431 in space 0,
Jan  3 11:23:42 rohrpostix mysqld: InnoDB: space name ./ibdata1,
Jan  3 11:23:42 rohrpostix mysqld: InnoDB: which is outside the tablespace bounds.
Jan  3 11:23:42 rohrpostix mysqld: InnoDB: Byte offset 0, len 16384, i/o type 10.
Jan  3 11:23:42 rohrpostix mysqld: InnoDB: If you get this error at mysqld startup, please check that
Jan  3 11:23:42 rohrpostix mysqld: InnoDB: your my.cnf matches the ibdata files that you have in the
Jan  3 11:23:42 rohrpostix mysqld: InnoDB: MySQL server.
Jan  3 11:23:42 rohrpostix mysqld: 2018-01-03 11:23:42 7f1285766700  InnoDB: Assertion failure in thread 139717525268224 in file fil0fil.cc line 5601
Jan  3 11:23:42 rohrpostix mysqld: InnoDB: We intentionally generate a memory trap.
Jan  3 11:23:42 rohrpostix mysqld: InnoDB: Submit a detailed bug report to http://bugs.mysql.com.
Jan  3 11:23:42 rohrpostix mysqld: InnoDB: If you get repeated assertion failures or crashes, even
Jan  3 11:23:42 rohrpostix mysqld: InnoDB: immediately after the mysqld startup, there may be
Jan  3 11:23:42 rohrpostix mysqld: InnoDB: corruption in the InnoDB tablespace. Please refer to
Jan  3 11:23:42 rohrpostix mysqld: InnoDB: http://dev.mysql.com/doc/refman/5.6/en/forcing-innodb-recovery.html
Jan  3 11:23:42 rohrpostix mysqld: InnoDB: about forcing recovery.
Jan  3 11:23:42 rohrpostix mysqld: 180103 11:23:42 [ERROR] mysqld got signal 6 ;
Jan  3 11:23:42 rohrpostix mysqld: This could be because you hit a bug. It is also possible that this binary
Jan  3 11:23:42 rohrpostix mysqld: or one of the libraries it was linked against is corrupt, improperly built,
Jan  3 11:23:42 rohrpostix mysqld: or misconfigured. This error can also be caused by malfunctioning hardware.
Jan  3 11:23:42 rohrpostix mysqld:
Jan  3 11:23:42 rohrpostix mysqld: To report this bug, see https://mariadb.com/kb/en/reporting-bugs
Jan  3 11:23:42 rohrpostix mysqld:
Jan  3 11:23:42 rohrpostix mysqld: We will try our best to scrape up some info that will hopefully help
Jan  3 11:23:42 rohrpostix mysqld: diagnose the problem, but since we have already crashed,
Jan  3 11:23:42 rohrpostix mysqld: something is definitely wrong and this may fail.
Jan  3 11:23:42 rohrpostix mysqld:
Jan  3 11:23:42 rohrpostix mysqld: Server version: 10.0.32-MariaDB-0+deb8u1
Jan  3 11:23:42 rohrpostix mysqld: key_buffer_size=16777216
Jan  3 11:23:42 rohrpostix mysqld: read_buffer_size=131072
Jan  3 11:23:42 rohrpostix mysqld: max_used_connections=1
Jan  3 11:23:42 rohrpostix mysqld: max_threads=153
Jan  3 11:23:42 rohrpostix mysqld: thread_count=1
Jan  3 11:23:42 rohrpostix mysqld: It is possible that mysqld could use up to
Jan  3 11:23:42 rohrpostix mysqld: key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 352327 K  bytes of memory
Jan  3 11:23:42 rohrpostix mysqld: Hope that's ok; if not, decrease some variables in the equation.
Jan  3 11:23:42 rohrpostix mysqld:
Jan  3 11:23:42 rohrpostix mysqld: Thread pointer: 0x7f127124f008
Jan  3 11:23:42 rohrpostix mysqld: Attempting backtrace. You can use the following information to find out
Jan  3 11:23:42 rohrpostix mysqld: where mysqld died. If you see no messages after this, something went
Jan  3 11:23:42 rohrpostix mysqld: terribly wrong...
Jan  3 11:23:42 rohrpostix mysqld: stack_bottom = 0x7f1285765e88 thread_stack 0x30000
Jan  3 11:23:42 rohrpostix mysqld: /usr/sbin/mysqld(my_print_stacktrace+0x2e)[0xc047de]
Jan  3 11:23:42 rohrpostix mysqld: /usr/sbin/mysqld(handle_fatal_signal+0x3af)[0x7362bf]
Jan  3 11:23:42 rohrpostix mysqld: /lib/x86_64-linux-gnu/libpthread.so.0(+0xf890)[0x7f12853cf890]
Jan  3 11:23:42 rohrpostix mysqld: /lib/x86_64-linux-gnu/libc.so.6(gsignal+0x37)[0x7f1283f55067]
Jan  3 11:23:42 rohrpostix mysqld: /lib/x86_64-linux-gnu/libc.so.6(abort+0x148)[0x7f1283f56448]
Jan  3 11:23:42 rohrpostix mysqld: /usr/sbin/mysqld[0xa20229]
Jan  3 11:23:42 rohrpostix mysqld: /usr/sbin/mysqld[0x9e73b1]
Jan  3 11:23:42 rohrpostix mysqld: /usr/sbin/mysqld[0x9caaf1]
Jan  3 11:23:42 rohrpostix mysqld: /usr/sbin/mysqld[0xa2c4a3]
Jan  3 11:23:42 rohrpostix mysqld: /usr/sbin/mysqld[0x98f248]
Jan  3 11:23:42 rohrpostix mysqld: /usr/sbin/mysqld[0x97c6f5]
Jan  3 11:23:42 rohrpostix mysqld: /usr/sbin/mysqld[0x9b3d04]
Jan  3 11:23:42 rohrpostix mysqld: /usr/sbin/mysqld[0x95fde4]
Jan  3 11:23:42 rohrpostix mysqld: /usr/sbin/mysqld[0x9604fc]
Jan  3 11:23:42 rohrpostix mysqld: /usr/sbin/mysqld[0x91d750]
Jan  3 11:23:42 rohrpostix mysqld: /usr/sbin/mysqld[0x91dd32]
Jan  3 11:23:42 rohrpostix mysqld: /usr/sbin/mysqld[0x93cf02]
Jan  3 11:23:42 rohrpostix mysqld: /usr/sbin/mysqld[0x8b3feb]
Jan  3 11:23:42 rohrpostix mysqld: /usr/sbin/mysqld(_Z17mysql_alter_tableP3THDPcS1_P14HA_CREATE_INFOP10TABLE_LISTP10Alter_infojP8st_orderb+0x2c98)[0x651a28]
Jan  3 11:23:42 rohrpostix mysqld: /usr/sbin/mysqld(_Z20mysql_recreate_tableP3THDP10TABLE_LISTb+0x15c)[0x6528cc]
Jan  3 11:23:42 rohrpostix mysqld: /usr/sbin/mysqld[0x6a563b]
Jan  3 11:23:42 rohrpostix mysqld: /usr/sbin/mysqld(_ZN22Sql_cmd_optimize_table7executeEP3THD+0x8f)[0x6a624f]
Jan  3 11:23:42 rohrpostix mysqld: /usr/sbin/mysqld(_Z21mysql_execute_commandP3THD+0x60e)[0x5bf8be]
Jan  3 11:23:42 rohrpostix mysqld: /usr/sbin/mysqld(_Z11mysql_parseP3THDPcjP12Parser_state+0x1ca)[0x5c5d0a]
Jan  3 11:23:42 rohrpostix mysqld: /usr/sbin/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcj+0x1557)[0x5c77f7]
Jan  3 11:23:42 rohrpostix mysqld: /usr/sbin/mysqld(_Z24do_handle_one_connectionP3THD+0x25b)[0x6976cb]
Jan  3 11:23:42 rohrpostix mysqld: /usr/sbin/mysqld(handle_one_connection+0x39)[0x697719]
Jan  3 11:23:42 rohrpostix mysqld: /lib/x86_64-linux-gnu/libpthread.so.0(+0x8064)[0x7f12853c8064]
Jan  3 11:23:42 rohrpostix mysqld: /lib/x86_64-linux-gnu/libc.so.6(clone+0x6d)[0x7f128400862d]
Jan  3 11:23:42 rohrpostix mysqld:
Jan  3 11:23:42 rohrpostix mysqld: Trying to get some variables.
Jan  3 11:23:42 rohrpostix mysqld: Some pointers may be invalid and cause the dump to abort.
Jan  3 11:23:42 rohrpostix mysqld: Query (0x7f125ec20020): is an invalid pointer
Jan  3 11:23:42 rohrpostix mysqld: Connection ID (thread ID): 4
Jan  3 11:23:42 rohrpostix mysqld: Status: NOT_KILLED
Jan  3 11:23:42 rohrpostix mysqld:
Jan  3 11:23:42 rohrpostix mysqld: Optimizer switch: index_merge=on,index_merge_union=on,index_merge_sort_union=on,index_merge_intersection=on,index_merge_sort_intersection=off,engine_condition_pushdown=off,index_condition_pushdown=on,derived_merge=on,derived_with_keys=on,firstmatch=on,loosescan=on,materialization=on,in_to_exists=on,semijoin=on,partial_match_rowid_merge=on,partial_match_table_scan=on,subquery_cache=on,mrr=off,mrr_cost_based=off,mrr_sort_keys=off,outer_join_with_cache=on,semijoin_with_cache=on,join_cache_incremental=on,join_cache_hashed=on,join_cache_bka=on,optimize_join_buffer_size=off,table_elimination=on,extended_keys=on,exists_to_in=on
Jan  3 11:23:42 rohrpostix mysqld:
Jan  3 11:23:42 rohrpostix mysqld: The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains
Jan  3 11:23:42 rohrpostix mysqld: information that should help you find out what is causing the crash.
Jan  3 11:23:42 rohrpostix mysqld:
Jan  3 11:23:42 rohrpostix mysqld: We think the query pointer is invalid, but we will try to print it anyway.
Jan  3 11:23:42 rohrpostix mysqld: Query: OPTIMIZE TABLE `abchanges`
Jan  3 11:23:42 rohrpostix mysqld:
Jan  3 11:23:42 rohrpostix mysqld_safe: Number of processes running now: 0
Jan  3 11:23:42 rohrpostix mysqld_safe: mysqld restarted
Jan  3 11:23:42 rohrpostix mysqld: 180103 11:23:42 [Note] /usr/sbin/mysqld (mysqld 10.0.32-MariaDB-0+deb8u1) starting as process 2245 ...
Jan  3 11:23:42 rohrpostix mysqld: 180103 11:23:42 [Note] InnoDB: innodb_empty_free_list_algorithm has been changed to legacy because of small buffer pool size. In order to use backoff, increase buffer pool at least up to 20MB.
Jan  3 11:23:42 rohrpostix mysqld:
Jan  3 11:23:42 rohrpostix mysqld: 180103 11:23:42 [Note] InnoDB: Using mutexes to ref count buffer pool pages
Jan  3 11:23:42 rohrpostix mysqld: 180103 11:23:42 [Note] InnoDB: The InnoDB memory heap is disabled
Jan  3 11:23:42 rohrpostix mysqld: 180103 11:23:42 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
Jan  3 11:23:42 rohrpostix mysqld: 180103 11:23:42 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
Jan  3 11:23:42 rohrpostix mysqld: 180103 11:23:42 [Note] InnoDB: Compressed tables use zlib 1.2.8
Jan  3 11:23:42 rohrpostix mysqld: 180103 11:23:42 [Note] InnoDB: Using Linux native AIO
Jan  3 11:23:42 rohrpostix mysqld: 180103 11:23:42 [Note] InnoDB: Using CPU crc32 instructions
Jan  3 11:23:42 rohrpostix mysqld: 180103 11:23:42 [Note] InnoDB: Initializing buffer pool, size = 128.0M
Jan  3 11:23:42 rohrpostix mysqld: 180103 11:23:42 [Note] InnoDB: Completed initialization of buffer pool
Jan  3 11:23:42 rohrpostix mysqld: 180103 11:23:42 [Note] InnoDB: Highest supported file format is Barracuda.
Jan  3 11:23:42 rohrpostix mysqld: 180103 11:23:42 [Note] InnoDB: Starting crash recovery from checkpoint LSN=8352553334
Jan  3 11:23:42 rohrpostix mysqld: 180103 11:23:42 [Note] InnoDB: Restoring possible half-written data pages from the doublewrite buffer...
Jan  3 11:23:42 rohrpostix mysqld: 180103 11:23:42 [Note] InnoDB: Starting final batch to recover 11 pages from redo log
Jan  3 11:23:43 rohrpostix mysqld: 180103 11:23:43 [Note] InnoDB: 128 rollback segment(s) are active.
Jan  3 11:23:43 rohrpostix mysqld: 180103 11:23:43 [Note] InnoDB: Waiting for purge to start
Jan  3 11:23:43 rohrpostix mysqld: 180103 11:23:43 [Note] InnoDB:  Percona XtraDB (http://www.percona.com) 5.6.36-82.1 started; log sequence number 8352558259
Jan  3 11:23:43 rohrpostix mysqld: 180103 11:23:43 [Note] Plugin 'FEEDBACK' is disabled.
Jan  3 11:23:43 rohrpostix mysqld: 180103 11:23:43 [Note] Server socket created on IP: '127.0.0.1'.
Jan  3 11:23:43 rohrpostix mysqld: 180103 11:23:43 [Note] /usr/sbin/mysqld: ready for connections.
Jan  3 11:23:43 rohrpostix mysqld: Version: '10.0.32-MariaDB-0+deb8u1'  socket: '/var/run/mysqld/mysqld.sock'  port: 3306  (Debian)
                      1 Reply Last reply Reply Quote 0
                      • Coffee_is_life
                        Coffee_is_life last edited by Coffee_is_life

                        So we got definetly a problem while accessing specific tables or properties. (if you used user “root” and he should have access to everything)

                        the next step i would do to get this working is to drop every table on your (test/cloned)-Server, delete or change the data-folder and restore your previous created backup.

                        mysql <db name> -u <user> -p <password> < /path/to/DB.dmp

                        than try the recreate command again, if its working i bet kopano does aswell. if not… well thats bad :(
                        in this case its usefull to have a subsciption

                        //EDIT: Maybe the db.dmp (or kopano.sql in your case) wont work, cause the error itself can be dumped aswell… do you have backup before crashing? - maybe there is some data loss with this, but better some data than everything

                        coffee_is_life

                        1 Reply Last reply Reply Quote 0
                        • kamikaze2508
                          kamikaze2508 last edited by kamikaze2508

                          Sorry for my stupid question, but with data directory do you mean /var/lib/mysql, right? Can I just empty it completely, or do I have to leave something in there?
                          Unfortunately, I have only a database dump and a backup of configuration files.

                          1 Reply Last reply Reply Quote 0
                          • Coffee_is_life
                            Coffee_is_life last edited by

                            in standard there should be something like that in your my.cnf:

                            [mysqld]
datadir=/var/lib/mysql
socket=/var/lib/mysql/mysql.sock
default-storage-engine=InnoDB
[...]
!includedir /etc/my.cnf.d

                            BUT:
                            if you have something in your include-directory like kopano.cnf which is overwriting the datadir

                            [mysqld]
datadir=/export/data/mail/db
[...]

                            thats the right directory

                            coffee_is_life

                            1 Reply Last reply Reply Quote 0
                            • kamikaze2508
                              kamikaze2508 last edited by

                              OK, then it should be the right directory. I only have datadir=/var/lib/mysql in my my.cnf-file and there is no kopano.cnf in the include-directory /etc/mysql/conf.d. Rather, I have a subdirectory kopano in /var/lib/mysql. This looks like the right database directory for me.
                              I must say that I am particularly familiar with MySQL, so in advance sorry for any stupid questions.

                              1 Reply Last reply Reply Quote 0
                              • Coffee_is_life
                                Coffee_is_life last edited by Coffee_is_life

                                Better ask twice and maybe stupid question than doing something wrong…

                                i advise to connect to mysql (mysql kopano -u root -p <pw>)

                                than view the tables (show tables; )
                                and drop every single table (drop <table-name>; )
                                stop mariadb
                                after that delete the kopano-folder in var/lib/mysql
                                start mariadb again and restore your backup

                                coffee_is_life

                                1 Reply Last reply Reply Quote 0
                                • kamikaze2508
                                  kamikaze2508 last edited by

                                  OK, thank you so far. I’ll try that and then get in touch. But may take a while, as I copy my VM as a precaution again.

                                  1 Reply Last reply Reply Quote 0
                                  • kamikaze2508
                                    kamikaze2508 last edited by

                                    So, here I am again.
                                    I have now tried in my cloned VM to delete the tables with “drop table <Tablename>;”. As soon as I try, I get the following error message:

                                    ERROR 2013 (HY000): Lost connection to MySQL server during query

                                    At the same time I receive the following messages in the syslog:

                                    Jan  3 14:21:15 rohrpostix mysqld: InnoDB: Error: trying to access page number 4294962431 in space 0,
Jan  3 14:21:15 rohrpostix mysqld: InnoDB: space name ./ibdata1,
Jan  3 14:21:15 rohrpostix mysqld: InnoDB: which is outside the tablespace bounds.
Jan  3 14:21:15 rohrpostix mysqld: InnoDB: Byte offset 0, len 16384, i/o type 10.
Jan  3 14:21:15 rohrpostix mysqld: InnoDB: If you get this error at mysqld startup, please check that
Jan  3 14:21:15 rohrpostix mysqld: InnoDB: your my.cnf matches the ibdata files that you have in the
Jan  3 14:21:15 rohrpostix mysqld: InnoDB: MySQL server.
Jan  3 14:21:15 rohrpostix mysqld: 2018-01-03 14:21:15 7f682559e700  InnoDB: Assertion failure in thread 140085279975168 in file fil0fil.cc line 5601
Jan  3 14:21:15 rohrpostix mysqld: InnoDB: We intentionally generate a memory trap.
Jan  3 14:21:15 rohrpostix mysqld: InnoDB: Submit a detailed bug report to http://bugs.mysql.com.
Jan  3 14:21:15 rohrpostix mysqld: InnoDB: If you get repeated assertion failures or crashes, even
Jan  3 14:21:15 rohrpostix mysqld: InnoDB: immediately after the mysqld startup, there may be
Jan  3 14:21:15 rohrpostix mysqld: InnoDB: corruption in the InnoDB tablespace. Please refer to
Jan  3 14:21:15 rohrpostix mysqld: InnoDB: http://dev.mysql.com/doc/refman/5.6/en/forcing-innodb-recovery.html
Jan  3 14:21:15 rohrpostix mysqld: InnoDB: about forcing recovery.
Jan  3 14:21:15 rohrpostix mysqld: 180103 14:21:15 [ERROR] mysqld got signal 6 ;
Jan  3 14:21:15 rohrpostix mysqld: This could be because you hit a bug. It is also possible that this binary
Jan  3 14:21:15 rohrpostix mysqld: or one of the libraries it was linked against is corrupt, improperly built,
Jan  3 14:21:15 rohrpostix mysqld: or misconfigured. This error can also be caused by malfunctioning hardware.
Jan  3 14:21:15 rohrpostix mysqld:
Jan  3 14:21:15 rohrpostix mysqld: To report this bug, see https://mariadb.com/kb/en/reporting-bugs
Jan  3 14:21:15 rohrpostix mysqld:
Jan  3 14:21:15 rohrpostix mysqld: We will try our best to scrape up some info that will hopefully help
Jan  3 14:21:15 rohrpostix mysqld: diagnose the problem, but since we have already crashed,
Jan  3 14:21:15 rohrpostix mysqld: something is definitely wrong and this may fail.
Jan  3 14:21:15 rohrpostix mysqld:
Jan  3 14:21:15 rohrpostix mysqld: Server version: 10.0.32-MariaDB-0+deb8u1
Jan  3 14:21:15 rohrpostix mysqld: key_buffer_size=16777216
Jan  3 14:21:15 rohrpostix mysqld: read_buffer_size=131072
Jan  3 14:21:15 rohrpostix mysqld: max_used_connections=1
Jan  3 14:21:15 rohrpostix mysqld: max_threads=153
Jan  3 14:21:15 rohrpostix mysqld: thread_count=1
Jan  3 14:21:15 rohrpostix mysqld: It is possible that mysqld could use up to
Jan  3 14:21:15 rohrpostix mysqld: key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 352327 K  bytes of memory
Jan  3 14:21:15 rohrpostix mysqld: Hope that's ok; if not, decrease some variables in the equation.
Jan  3 14:21:15 rohrpostix mysqld:
Jan  3 14:21:15 rohrpostix mysqld: Thread pointer: 0x7f68207fb008
Jan  3 14:21:15 rohrpostix mysqld: Attempting backtrace. You can use the following information to find out
Jan  3 14:21:15 rohrpostix mysqld: where mysqld died. If you see no messages after this, something went
Jan  3 14:21:15 rohrpostix mysqld: terribly wrong...
Jan  3 14:21:15 rohrpostix mysqld: stack_bottom = 0x7f682559de88 thread_stack 0x30000
Jan  3 14:21:15 rohrpostix mysqld: /usr/sbin/mysqld(my_print_stacktrace+0x2e)[0xc047de]
Jan  3 14:21:15 rohrpostix mysqld: /usr/sbin/mysqld(handle_fatal_signal+0x3af)[0x7362bf]
Jan  3 14:21:15 rohrpostix mysqld: /lib/x86_64-linux-gnu/libpthread.so.0(+0xf890)[0x7f682520f890]
Jan  3 14:21:15 rohrpostix mysqld: /lib/x86_64-linux-gnu/libc.so.6(gsignal+0x37)[0x7f6823d95067]
Jan  3 14:21:15 rohrpostix mysqld: /lib/x86_64-linux-gnu/libc.so.6(abort+0x148)[0x7f6823d96448]
Jan  3 14:21:15 rohrpostix mysqld: /usr/sbin/mysqld[0xa20229]
Jan  3 14:21:15 rohrpostix mysqld: /usr/sbin/mysqld[0x9e73b1]
Jan  3 14:21:15 rohrpostix mysqld: /usr/sbin/mysqld[0x9caaf1]
Jan  3 14:21:15 rohrpostix mysqld: /usr/sbin/mysqld[0xa2c4a3]
Jan  3 14:21:15 rohrpostix mysqld: /usr/sbin/mysqld[0x98f248]
Jan  3 14:21:15 rohrpostix mysqld: /usr/sbin/mysqld[0x97c6f5]
Jan  3 14:21:15 rohrpostix mysqld: /usr/sbin/mysqld[0x9b3d04]
Jan  3 14:21:15 rohrpostix mysqld: /usr/sbin/mysqld[0x95f8fd]
Jan  3 14:21:15 rohrpostix mysqld: /usr/sbin/mysqld[0x9604fc]
Jan  3 14:21:15 rohrpostix mysqld: /usr/sbin/mysqld[0x91d750]
Jan  3 14:21:15 rohrpostix mysqld: /usr/sbin/mysqld[0x91dd32]
Jan  3 14:21:15 rohrpostix mysqld: /usr/sbin/mysqld[0x943894]
Jan  3 14:21:15 rohrpostix mysqld: /usr/sbin/mysqld[0x89c03a]
Jan  3 14:21:15 rohrpostix mysqld: /usr/sbin/mysqld(_Z15ha_delete_tableP3THDP10handlertonPKcS4_S4_b+0x211)[0x73a4a1]
Jan  3 14:21:15 rohrpostix mysqld: /usr/sbin/mysqld(_Z23mysql_rm_table_no_locksP3THDP10TABLE_LISTbbbbb+0x59e)[0x64641e]
Jan  3 14:21:15 rohrpostix mysqld: /usr/sbin/mysqld(_Z14mysql_rm_tableP3THDP10TABLE_LISTcc+0x163)[0x6471a3]
Jan  3 14:21:15 rohrpostix mysqld: /usr/sbin/mysqld(_Z21mysql_execute_commandP3THD+0x1650)[0x5c0900]
Jan  3 14:21:15 rohrpostix mysqld: /usr/sbin/mysqld(_Z11mysql_parseP3THDPcjP12Parser_state+0x1ca)[0x5c5d0a]
Jan  3 14:21:15 rohrpostix mysqld: /usr/sbin/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcj+0x1557)[0x5c77f7]
Jan  3 14:21:15 rohrpostix mysqld: /usr/sbin/mysqld(_Z24do_handle_one_connectionP3THD+0x25b)[0x6976cb]
Jan  3 14:21:15 rohrpostix mysqld: /usr/sbin/mysqld(handle_one_connection+0x39)[0x697719]
Jan  3 14:21:15 rohrpostix mysqld: /lib/x86_64-linux-gnu/libpthread.so.0(+0x8064)[0x7f6825208064]
Jan  3 14:21:15 rohrpostix mysqld: /lib/x86_64-linux-gnu/libc.so.6(clone+0x6d)[0x7f6823e4862d]
Jan  3 14:21:15 rohrpostix mysqld:
Jan  3 14:21:15 rohrpostix mysqld: Trying to get some variables.
Jan  3 14:21:15 rohrpostix mysqld: Some pointers may be invalid and cause the dump to abort.
Jan  3 14:21:15 rohrpostix mysqld: Query (0x7f67ff020020): is an invalid pointer
Jan  3 14:21:15 rohrpostix mysqld: Connection ID (thread ID): 2
Jan  3 14:21:15 rohrpostix mysqld: Status: NOT_KILLED
Jan  3 14:21:15 rohrpostix mysqld:
Jan  3 14:21:15 rohrpostix mysqld: Optimizer switch: index_merge=on,index_merge_union=on,index_merge_sort_union=on,index_merge_intersection=on,index_merge_sort_intersection=off,engine_condition_pushdown=off,index_condition_pushdown=on,derived_merge=on,derived_with_keys=on,firstmatch=on,loosescan=on,materialization=on,in_to_exists=on,semijoin=on,partial_match_rowid_merge=on,partial_match_table_scan=on,subquery_cache=on,mrr=off,mrr_cost_based=off,mrr_sort_keys=off,outer_join_with_cache=on,semijoin_with_cache=on,join_cache_incremental=on,join_cache_hashed=on,join_cache_bka=on,optimize_join_buffer_size=off,table_elimination=on,extended_keys=on,exists_to_in=on
Jan  3 14:21:15 rohrpostix mysqld:
Jan  3 14:21:15 rohrpostix mysqld: The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains
Jan  3 14:21:15 rohrpostix mysqld: information that should help you find out what is causing the crash.
Jan  3 14:21:15 rohrpostix mysqld:
Jan  3 14:21:15 rohrpostix mysqld: We think the query pointer is invalid, but we will try to print it anyway.
Jan  3 14:21:15 rohrpostix mysqld: Query: drop table hierarchy
Jan  3 14:21:15 rohrpostix mysqld:
Jan  3 14:21:16 rohrpostix mysqld_safe: Number of processes running now: 0
Jan  3 14:21:16 rohrpostix mysqld_safe: mysqld restarted
Jan  3 14:21:16 rohrpostix mysqld: 180103 14:21:16 [Note] /usr/sbin/mysqld (mysqld 10.0.32-MariaDB-0+deb8u1) starting as process 6491 ...
Jan  3 14:21:16 rohrpostix mysqld: 180103 14:21:16 [Note] InnoDB: innodb_empty_free_list_algorithm has been changed to legacy because of small buffer pool size. In order to use backoff, increase buffer pool at least up to 20MB.
Jan  3 14:21:16 rohrpostix mysqld:
Jan  3 14:21:16 rohrpostix mysqld: 180103 14:21:16 [Note] InnoDB: Using mutexes to ref count buffer pool pages
Jan  3 14:21:16 rohrpostix mysqld: 180103 14:21:16 [Note] InnoDB: The InnoDB memory heap is disabled
Jan  3 14:21:16 rohrpostix mysqld: 180103 14:21:16 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
Jan  3 14:21:16 rohrpostix mysqld: 180103 14:21:16 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
Jan  3 14:21:16 rohrpostix mysqld: 180103 14:21:16 [Note] InnoDB: Compressed tables use zlib 1.2.8
Jan  3 14:21:16 rohrpostix mysqld: 180103 14:21:16 [Note] InnoDB: Using Linux native AIO
Jan  3 14:21:16 rohrpostix mysqld: 180103 14:21:16 [Note] InnoDB: Using CPU crc32 instructions
Jan  3 14:21:16 rohrpostix mysqld: 180103 14:21:16 [Note] InnoDB: Initializing buffer pool, size = 128.0M
Jan  3 14:21:16 rohrpostix mysqld: 180103 14:21:16 [Note] InnoDB: Completed initialization of buffer pool
Jan  3 14:21:16 rohrpostix mysqld: 180103 14:21:16 [Note] InnoDB: Highest supported file format is Barracuda.
Jan  3 14:21:16 rohrpostix mysqld: 180103 14:21:16 [Note] InnoDB: Starting crash recovery from checkpoint LSN=8352629695
Jan  3 14:21:16 rohrpostix mysqld: 180103 14:21:16 [Note] InnoDB: Restoring possible half-written data pages from the doublewrite buffer...
Jan  3 14:21:16 rohrpostix mysqld: 180103 14:21:16 [Note] InnoDB: Starting final batch to recover 7 pages from redo log
Jan  3 14:21:17 rohrpostix mysqld: 180103 14:21:17 [Note] InnoDB: 128 rollback segment(s) are active.
Jan  3 14:21:17 rohrpostix mysqld: 180103 14:21:17 [Note] InnoDB: Waiting for purge to start
Jan  3 14:21:17 rohrpostix mysqld: 180103 14:21:17 [Note] InnoDB:  Percona XtraDB (http://www.percona.com) 5.6.36-82.1 started; log sequence number 8352649957
Jan  3 14:21:17 rohrpostix mysqld: 180103 14:21:17 [Note] Plugin 'FEEDBACK' is disabled.
Jan  3 14:21:17 rohrpostix mysqld: 180103 14:21:17 [Note] Server socket created on IP: '127.0.0.1'.
Jan  3 14:21:17 rohrpostix mysqld: 180103 14:21:17 [Note] /usr/sbin/mysqld: ready for connections.
Jan  3 14:21:17 rohrpostix mysqld: Version: '10.0.32-MariaDB-0+deb8u1'  socket: '/var/run/mysqld/mysqld.sock'  port: 3306  (Debian)

                                    It looks to me as if the mariadb-daemon crash and start again directly. Can it be that MariaDB has problems with the InnoDB tablespace?

                                    1 Reply Last reply Reply Quote 0
                                    • Coffee_is_life
                                      Coffee_is_life last edited by Coffee_is_life

                                      I’m using innoDB aswell without problems…

                                      I think the ibdata1 file is corrupt…

                                      try to stop mariadb, delete the kopano folder under /var/lib/mysql and change the datadir to something else like kopano_safe… just to give mysql another directory for data.

                                      and than restore the dump. This should create the database and its tables

                                      //EDIT: watch this page: https://dev.mysql.com/doc/refman/5.6/en/forcing-innodb-recovery.html maybe it can help
                                      coffee_is_life

                                      1 Reply Last reply Reply Quote 0
                                      • kamikaze2508
                                        kamikaze2508 last edited by kamikaze2508

                                        Hello Coffee_is_life, hello Mike,
                                        your tip helped!
                                        However, I had to take a few extra steps to get everything going again. After stopping mariadb and changing the datadir, I had to execute the following commands so that mariadb could be restarted:

                                        First, I had to reinstall the system tables. For this I had to execute the following command:

                                        mysql_install_db --user=mysql

                                        Since I run my mail server on Debian, I had to grant rights to a system user with the following commands after starting mariadb:

                                        mysql -uroot -p
mysql> grant all privileges on *.* to 'debian-sys-maint'@'localhost' identified by '<Password>' with grant option;

                                        The password to be assigned here can be found in the file /etc/mysql/debian.cnf.
                                        I have also recreated the kopano database user and authorized it with:

                                        mysql> create user 'kopano'@'%' identified by '<Password>'; 
mysql> grant all privileges on *.* to 'kopano'@'%' identified by '<Password>' with grant option;
mysql> exit

                                        Then mariadb had to be restarted.
                                        Then I had to set the password for the root user with:

                                        mysqladmin -u root password <new Password>

                                        Now I could create a new empty database and import the dump.

                                        After the import the Kopano server was restarted correctly. Access is now possible again.
                                        Now everything works as it should. :smiley:

                                        Thanks for your support. I would not have done without you!

                                        1 Reply Last reply Reply Quote 1
                                        • First post
                                          Last post