[SOLVED] Big Problem, Kopano server could not connect to MariaDB-Server
-
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:
-
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. -
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
-
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)
-
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
-
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. -
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
-
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. -
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 backupcoffee_is_life
-
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.
-
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?
-
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 -
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!