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.
    • kamikaze2508
      kamikaze2508 last edited by kamikaze2508

      Hello everybody!

      First I want to apologize for my bad English. I hope you understand my problem description.
      After my ESXi-Host crashes, I restart my VMs, also my Kopano Mailserver. At first everything looked ok. But after a few minutes I realized that Kopano was not working. The daemon kopano-server did not work. So I tried to start it manually with /etc/init.d/kopano-server start. This did not work, I received an error instead with “An error occurred (80000007). Please check /var/log/kopano/server.log for details.” So I looked at the server.log and saw the following entries:

      Mon Jan  1 19:12:57 2018: [ notice] Starting server version 8,3,4,12, pid 869
      Mon Jan  1 19:12:59 2018: [warning] SQL [00000004] info: Try to reconnect
      Mon Jan  1 19:12:59 2018: [error  ] KDatabase::Connect(): database access error -2147483641, mysql error: Can't connect to local MySQL server through socket '/var/run/mysqld/mysqld.sock' (111)
      Mon Jan  1 19:12:59 2018: [error  ] KDatabase::_Update() query failed: REPLACE INTO settings VALUES ('attachment_storage', 'database'): MYSQL not initialized
      Mon Jan  1 19:12:59 2018: [error  ] Unable to update database settings
      Mon Jan  1 19:12:59 2018: [ notice] Server shutdown complete.
      

      The MySQL daemon, however, seemed to be running. But a “/etc/init.d/mysql status” gave the following messages:

      Jan 01 19:12:59 rohrpostix mysqld[1024]: 180101 19:12:59 [Note] InnoDB: Highest supported file format is Barracuda.
      Jan 01 19:12:59 rohrpostix mysqld[1024]: 180101 19:12:59 [Note] InnoDB: The log sequence numbers 8352532263 and 8352532263 in ibdata files do not...logfiles!
      Jan 01 19:12:59 rohrpostix mysqld[1024]: 180101 19:12:59 [Note] InnoDB: Restoring possible half-written data pages from the doublewrite buffer...
      Jan 01 19:12:59 rohrpostix mysqld[1024]: 180101 19:12:59 [Note] InnoDB: 128 rollback segment(s) are active.
      Jan 01 19:12:59 rohrpostix mysqld[1024]: 180101 19:12:59 [Note] InnoDB: Waiting for purge to start
      Jan 01 19:12:59 rohrpostix mysqld[1024]: 180101 19:12:59 [Note] InnoDB:  Percona XtraDB (http://www.percona.com) 5.6.36-82.1 started; log sequenc...352532273
      Jan 01 19:12:59 rohrpostix mysqld[1024]: 180101 19:12:59 [Note] Plugin 'FEEDBACK' is disabled.
      Jan 01 19:12:59 rohrpostix mysqld[1024]: 180101 19:12:59 [Note] Server socket created on IP: '127.0.0.1'.
      Jan 01 19:12:59 rohrpostix mysqld[1024]: 180101 19:12:59 [Note] /usr/sbin/mysqld: ready for connections.
      Jan 01 19:12:59 rohrpostix mysqld[1024]: Version: '10.0.32-MariaDB-0+deb8u1'  socket: '/var/run/mysqld/mysqld.sock'  port: 3306  (Debian)
      Hint: Some lines were ellipsized, use -l to show in full.
      

      After that, I repeated the start of the kopano server daemon while watching kopano / server.log with tail -f. The following messages have now been generated:

      Mon Jan  1 19:59:54 2018: [ notice] Starting server version 8,3,4,12, pid 5639
      Mon Jan  1 19:59:55 2018: [warning] SQL [00000002] info: Try to reconnect
      Mon Jan  1 19:59:55 2018: [error  ] KDatabase::Connect(): database access error -2147483641, mysql error: Can't connect to local MySQL server through socket '/var/run/mysqld/mysqld.sock' (111)
      Mon Jan  1 19:59:55 2018: [error  ] KDatabase::_Update() query failed: REPLACE INTO settings VALUES ('attachment_storage', 'database'): MYSQL not initialized
      Mon Jan  1 19:59:55 2018: [error  ] Unable to update database settings
      Mon Jan  1 19:59:55 2018: [ notice] Server shutdown complete.
      

      With “mysql -u root -p” I can connect to the MariaDB server.
      Then I checked the Kopano database for errors with “mysqlcheck -u root -p --check --databases kopano”. Result:

      kopano.abchanges                                   OK
      kopano.acl                                         OK
      kopano.changes                                     OK
      kopano.clientupdatestatus                          OK
      kopano.deferredupdate                              OK
      kopano.hierarchy                                   OK
      kopano.indexedproperties                           OK
      kopano.lob                                         OK
      kopano.mvproperties                                OK
      kopano.names                                       OK
      kopano.object                                      OK
      kopano.objectmvproperty                            OK
      kopano.objectproperty                              OK
      kopano.objectrelation                              OK
      kopano.outgoingqueue                               OK
      kopano.properties                                  OK
      kopano.receivefolder                               OK
      kopano.searchresults                               OK
      kopano.settings                                    OK
      kopano.singleinstances                             OK
      kopano.stores                                      OK
      kopano.syncedmessages                              OK
      kopano.syncs                                       OK
      kopano.tproperties                                 OK
      kopano.users                                       OK
      kopano.versions                                    OK
      

      Now I tried to backup the database with “mysqldump -v --single-transaction --password = xxx kopano> /<backuppath>/kopano.sql”. That, too, has apparently worked.

      I do not know what to do next. Therefore I urge you for your help.

      The following data to your info:
      Debian Version: 8.9
      Kopano Version: 8.3.4.12-0+23.1
      MariaDB-Version: 10.0.32-0+deb8u1

      I hope you find this information useful.

      Thanks in advance

      Christian

      1 Reply Last reply Reply Quote 0
      • 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