Details
-
Bug
-
Status: Closed (View Workflow)
-
Critical
-
Resolution: Fixed
-
10.4(EOL), 10.5, 10.6
Description
The test galera.galera_pc_recovery fails to start up. Due to a deficiency of mtr, this failure is not flagged on buildbot. Locally, I can repeat this at least starting with 10.4 (not sure about 10.2 and 10.3).
worker[48] mysql-test-run: WARNING: Timeout after mysql-test-run waited 180 seconds for the process [mysqld.2 - pid: 792954, winpid: 792954] to create a pid file.
|
worker[48] mysql-test-run: *** ERROR: Failed to start mysqld mysqld.2 with command /dev/shm/10.4/sql/mysqld
|
galera.galera_sst_mysqldump 'debug,innodb' w38 [ pass ] 141742
|
|
|
Only 445 of 446 completed.
|
--------------------------------------------------------------------------
|
The servers were restarted 152 times
|
Spent 3429.559 of 231 seconds executing testcases
|
|
|
Completed: Failed 2/361 tests, 99.45% were successful.
|
|
|
Failing test(s): galera.galera_bf_lock_wait galera_sr.galera-features#56
|
In var/48/log/mysqld.1.err there is evidence of this test starting up:
CURRENT_TEST: galera.galera_pc_recovery
|
2021-03-19 11:20:36 0 [Warning] WSREP: option --wsrep-causal-reads is deprecated
|
2021-03-19 11:20:36 0 [Note] /dev/shm/10.4/sql/mysqld (mysqld 10.4.19-MariaDB-debug-log) starting as process 776028 ...
|
2021-03-19 11:20:36 0 [Warning] Could not increase number of max_open_files to more than 1024 (request: 32222)
|
2021-03-19 11:20:36 0 [Warning] Changed limits: max_open_files: 1024 max_connections: 151 (was 151) table_cache: 421 (was 2000)
|
2021-03-19 11:20:36 0 [Warning] WSREP: wsrep_sst_receive_address is set to '127.0.0.1:16964' which makes it impossible for another host to reach this one. Please set it to the address which this node can be connected at by other cluster members.
|
2021-03-19 11:20:36 0 [Note] WSREP: Loading provider /usr/lib/galera/libgalera_smm.so initial position: 00000000-0000-0000-0000-000000000000:-1
|
2021-03-19 11:20:36 0 [Note] WSREP: wsrep_load(): loading provider library '/usr/lib/galera/libgalera_smm.so'
|
2021-03-19 11:20:36 0 [Note] WSREP: wsrep_load(): Galera 4.7(rbac8171) by Codership Oy <info@codership.com> loaded successfully.
|
2021-03-19 11:20:36 0 [Note] WSREP: CRC-32C: using 64-bit x86 acceleration.
|
2021-03-19 11:20:36 0 [Warning] WSREP: Could not open state file for reading: '/dev/shm/10.4/mysql-test/var/48/mysqld.1/data//grastate.dat'
|
…
|
In var/log/stdout.log there is no occurrence of galera.galera_pc_recovery.
The mysqld.2.err ends in the following:
2021-03-19 11:20:59 2 [Note] WSREP: Starting rollbacker thread 2
|
2021-03-19 11:20:59 0 [Warning] WSREP: last inactive check more than PT1.5S ago (PT3.50143S), skipping check
|
The last lines in mysqld.1.err were sent before those timestamps:
2021-03-19 11:20:40 0 [Note] WSREP: async IST sender starting to serve tcp://127.0.0.1:16966 sending 2-2, preload starts from 2
|
2021-03-19 11:20:40 0 [Note] WSREP: IST sender 2 -> 2
|
2021-03-19 11:20:40 0 [Note] WSREP: Donor monitor thread started to monitor
|
2021-03-19 11:20:40 0 [Note] WSREP: Running: 'wsrep_sst_rsync --role 'donor' --address '127.0.0.2:16967/rsync_sst' --socket '/dev/shm/10.4/mysql-test/var/tmp/48/mysqld.1.sock' --datadir '/dev/shm/10.4/mysql-test/var/48/mysqld.1/data/' --defaults-file '/dev/shm/10.4/mysql-test/var/48/my.cnf' --defaults-group-suffix '.1' --gtid '5d019f5e-8894-11eb-a1b7-2b3fae821768:2' --gtid-domain-id '0' --binlog-index 'mysqld-bin.index' --mysqld-args --defaults-group-suffix=.1 --defaults-file=/dev/shm/10.4/mysql-test/var/48/my.cnf --log-output=file --innodb --innodb-cmpmem --innodb-cmp-per-index --innodb-trx --innodb-locks --innodb-lock-waits --innodb-metrics --innodb-buffer-pool-stats --innodb-buffer-page --innodb-buffer-page-lru --innodb-sys-columns --innodb-sys-fields --innodb-sys-foreign --innodb-sys-foreign-cols --innodb-sys-indexes --innodb-sys-tables --innodb-sys-virtual --core-file --loose-debug-sync-timeout=300'
|
2021-03-19 11:20:40 2 [Note] WSREP: sst_donor_thread signaled with 0
|
2021-03-19 11:20:40 0 [Note] WSREP: Flushing tables for SST...
|
2021-03-19 11:20:40 0 [Note] WSREP: pause
|
2021-03-19 11:20:40 0 [Note] WSREP: Provider paused at 5d019f5e-8894-11eb-a1b7-2b3fae821768:2 (5)
|
2021-03-19 11:20:40 0 [Note] WSREP: Server paused at: 2
|
2021-03-19 11:20:40 0 [Note] WSREP: Tables flushed.
|
2021-03-19 11:20:41 0 [Note] WSREP: resume
|
2021-03-19 11:20:41 0 [Note] WSREP: resuming provider at 5
|
2021-03-19 11:20:41 0 [Note] WSREP: Provider resumed.
|
2021-03-19 11:20:41 0 [Note] WSREP: SST sent: 5d019f5e-8894-11eb-a1b7-2b3fae821768:2
|
2021-03-19 11:20:41 0 [Note] WSREP: Server status change donor -> joined
|
2021-03-19 11:20:41 0 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
|
2021-03-19 11:20:41 0 [Note] WSREP: 0.0 (jyty): State transfer to 1.0 (jyty) complete.
|
2021-03-19 11:20:41 0 [Note] WSREP: Shifting DONOR/DESYNCED -> JOINED (TO: 2)
|
2021-03-19 11:20:41 0 [Note] WSREP: Member 0.0 (jyty) synced with group.
|
2021-03-19 11:20:41 0 [Note] WSREP: Shifting JOINED -> SYNCED (TO: 2)
|
2021-03-19 11:20:41 2 [Note] WSREP: Server jyty synced with group
|
2021-03-19 11:20:41 2 [Note] WSREP: Server status change joined -> synced
|
2021-03-19 11:20:41 2 [Note] WSREP: Synchronized with group, ready for connections
|
2021-03-19 11:20:41 2 [Note] WSREP: wsrep_notify_cmd is not defined, skipping notification.
|
2021-03-19 11:20:41 0 [Note] WSREP: Donor monitor thread ended with total time 1 sec
|
2021-03-19 11:20:42 0 [Note] WSREP: (5cfe4bac-b52e, 'tcp://0.0.0.0:16962') turning message relay requesting off
|
2021-03-19 11:20:45 0 [Note] WSREP: async IST sender served
|
2021-03-19 11:20:45 0 [Note] WSREP: 1.0 (jyty): State transfer from 0.0 (jyty) complete.
|
2021-03-19 11:20:45 0 [Note] WSREP: Member 1.0 (jyty) synced with group.
|
The test ended at 11:24:16.
Attachments
Issue Links
- blocks
-
-
- Stalled
-