rocksdb.prefix_extractor_override fails: At line 80: Test assertion failed in assert.inc

General

Escalation

General

Escalation

Description

$ ./mtr --force rocksdb.prefix_extractor_override
Logging: /var/tmp/portage/dev-db/percona-server-5.7.24.27/work/mysql/mysql-test/mysql-test-run.pl  --force 
rocksdb.prefix_extractor_override
MySQL Version 5.7.24
Too long tmpdir path 
'/var/tmp/portage/dev-db/percona-server-5.7.24.27/work/percona-server-5.7.24.27_build/mysql-test/var/tmp'  
creating a shorter one...
 - using tmpdir: '/tmp/VKUz2BWKRo'

Checking supported features...
 - SSL connections supported
Collecting tests...
 - adding combinations for rocksdb
Removing old var directory...
Creating var directory 
'/var/tmp/portage/dev-db/percona-server-5.7.24.27/work/percona-server-5.7.24.27_build/mysql-test/var'...
Installing system database...
Using parallel: 1

==============================================================================

TEST                                      RESULT   TIME (ms) or COMMENT
--------------------------------------------------------------------------

worker[1] Using MTR_BUILD_THREAD 300, with reserved ports 13000..13009
[ 50%] rocksdb.prefix_extractor_override 'write_prepared' [ fail ]
        Test ended at 2018-12-19 20:02:18

CURRENT_TEST: rocksdb.prefix_extractor_override
mysqltest: In included file ./include/assert.inc at line 81:
included from 
/var/tmp/portage/dev-db/percona-server-5.7.24.27/work/mysql/mysql-test/suite/rocksdb/t/prefix_extractor_override.test 
at line 50:
At line 80: Test assertion failed in assert.inc

The result from queries just before the failure was:
SET @orig_rocksdb_update_cf_options = @@global.rocksdb_update_cf_options;
CREATE TABLE t1 (id1 BIGINT, id2 BIGINT, id3 BIGINT, id4 BIGINT, PRIMARY KEY (id1, id2, id3, id4) comment 'cf1') 
ENGINE=rocksdb collate latin1_bin;
set global rocksdb_force_flush_memtable_now = 1;

Original Prefix Extractor:

SELECT * FROM information_schema.rocksdb_cf_options WHERE option_type like '%prefix_extractor%';
CF_NAME OPTION_TYPE     VALUE
__system__      PREFIX_EXTRACTOR        rocksdb.CappedPrefix.24
cf1     PREFIX_EXTRACTOR        rocksdb.CappedPrefix.24
default PREFIX_EXTRACTOR        rocksdb.CappedPrefix.24
select variable_value into @u from performance_schema.global_status where 
variable_name='rocksdb_bloom_filter_prefix_checked';
SELECT COUNT(*) FROM t1 WHERE id1=1 AND id2=1 AND id3=1;
COUNT(*)
1
include/assert.inc ["Expected exactly one bloom filter prefix check"]

Prefix Extractor (after override_cf_options set, should not be changed):

SELECT * FROM information_schema.rocksdb_cf_options WHERE option_type like '%prefix_extractor%';
CF_NAME OPTION_TYPE     VALUE
__system__      PREFIX_EXTRACTOR        rocksdb.CappedPrefix.24
cf1     PREFIX_EXTRACTOR        rocksdb.CappedPrefix.24
default PREFIX_EXTRACTOR        rocksdb.CappedPrefix.24
SET @@global.rocksdb_update_cf_options = 'cf1={prefix_extractor=capped:26};';

Changed Prefix Extractor (after update_cf_options set, without restart):

SELECT * FROM information_schema.rocksdb_cf_options WHERE option_type like '%prefix_extractor%';
CF_NAME OPTION_TYPE     VALUE
__system__      PREFIX_EXTRACTOR        rocksdb.CappedPrefix.24
cf1     PREFIX_EXTRACTOR        rocksdb.CappedPrefix.24
default PREFIX_EXTRACTOR        rocksdb.CappedPrefix.24
select variable_value into @u from performance_schema.global_status where 
variable_name='rocksdb_bloom_filter_prefix_checked';
SELECT COUNT(*) FROM t1 WHERE id1=1 AND id2=1 AND id3=1;
COUNT(*)
1
include/assert.inc ["Expected no bloom filter prefix check"]
######## Test assertion failed: "Expected no bloom filter prefix check" ########
Dumping debug info:
Assertion text: '"Expected no bloom filter prefix check"'
Assertion condition: '"[select variable_value-@u from performance_schema.global_status where 
variable_name=\'rocksdb_bloom_filter_prefix_checked\']" = 0'
Assertion condition, interpolated: '"1" = 0'
Assertion result: '0'
safe_process[33273]: Child process: 33274, exit: 1



Server [mysqld.1 - pid: 33239, winpid: 33239] log:
Server log from this test:
----------SERVER LOG START-----------
2018-12-19T19:02:18.196305Z 0 [Warning] Insecure configuration for --secure-file-priv: Data directory is 
accessible through --secure-file-priv. Consider choosing a different directory.
2018-12-19T19:02:18.196358Z 0 [Warning] Insecure configuration for --secure-file-priv: Location is accessible to 
all OS users. Consider choosing a different directory.
2018-12-19T19:02:18.196378Z 0 [Note] 
/var/tmp/portage/dev-db/percona-server-5.7.24.27/work/percona-server-5.7.24.27_build/sql/mysqld (mysqld 
5.7.24-27-log) starting as process 33240 ...
2018-12-19T19:02:18.199194Z 0 [Note] InnoDB: PUNCH HOLE support available
2018-12-19T19:02:18.199220Z 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2018-12-19T19:02:18.199226Z 0 [Note] InnoDB: Uses event mutexes
2018-12-19T19:02:18.199231Z 0 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
2018-12-19T19:02:18.199236Z 0 [Note] InnoDB: Compressed tables use zlib 1.2.11
2018-12-19T19:02:18.199241Z 0 [Note] InnoDB: Using Linux native AIO
2018-12-19T19:02:18.199499Z 0 [Note] InnoDB: Number of pools: 1
2018-12-19T19:02:18.199617Z 0 [Note] InnoDB: Using CPU crc32 instructions
2018-12-19T19:02:18.201248Z 0 [Note] InnoDB: Initializing buffer pool, total size = 24M, instances = 1, chunk 
size = 24M
2018-12-19T19:02:18.202392Z 0 [Note] InnoDB: Completed initialization of buffer pool
2018-12-19T19:02:18.203591Z 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread 
priority can be changed. See the man page of setpriority().
2018-12-19T19:02:18.215125Z 0 [Note] InnoDB: Crash recovery did not find the parallel doublewrite buffer at 
/var/tmp/portage/dev-db/percona-server-5.7.24.27/work/percona-server-5.7.24.27_build/mysql-test/var/mysqld.1/data/xb_doublewrite
2018-12-19T19:02:18.215764Z 0 [Note] InnoDB: Highest supported file format is Barracuda.
2018-12-19T19:02:18.230164Z 0 [Note] InnoDB: Created parallel doublewrite buffer at 
/var/tmp/portage/dev-db/percona-server-5.7.24.27/work/percona-server-5.7.24.27_build/mysql-test/var/mysqld.1/data/xb_doublewrite, 
size 3932160 bytes
2018-12-19T19:02:18.233643Z 0 [Note] InnoDB: Creating shared tablespace for temporary tables
2018-12-19T19:02:18.233696Z 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file 
full; Please wait ...
2018-12-19T19:02:18.265106Z 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
2018-12-19T19:02:18.265909Z 0 [Note] InnoDB: 96 redo rollback segment(s) found. 96 redo rollback segment(s) are 
active.
2018-12-19T19:02:18.265923Z 0 [Note] InnoDB: 32 non-redo rollback segment(s) are active.
2018-12-19T19:02:18.266653Z 0 [Note] InnoDB: Waiting for purge to start
2018-12-19T19:02:18.317805Z 0 [Note] InnoDB: Percona XtraDB (http://www.percona.com) 5.7.24-27 started; log 
sequence number 1355541
2018-12-19T19:02:18.318364Z 0 [Note] InnoDB: Loading buffer pool(s) from 
/var/tmp/portage/dev-db/percona-server-5.7.24.27/work/percona-server-5.7.24.27_build/mysql-test/var/mysqld.1/data/ib_buffer_pool
2018-12-19T19:02:18.318911Z 0 [Note] Plugin 'FEDERATED' is disabled.
2018-12-19T19:02:18.321382Z 0 [Note] InnoDB: Buffer pool(s) load completed at 181219 22:02:18
2018-12-19T19:02:18.338031Z 0 [Note] RocksDB: Got ENOENT when listing column families
2018-12-19T19:02:18.338051Z 0 [Note] RocksDB:   assuming that we're creating a new database
2018-12-19T19:02:18.338152Z 0 [Note] RocksDB: Column Families at start:
2018-12-19T19:02:18.338181Z 0 [Note]   cf=default
2018-12-19T19:02:18.338189Z 0 [Note]     write_buffer_size=65536
2018-12-19T19:02:18.338194Z 0 [Note]     target_file_size_base=67108864
2018-12-19T19:02:18.365237Z 0 [Note] RocksDB: creating a column family __system__
2018-12-19T19:02:18.365270Z 0 [Note]     write_buffer_size=65536
2018-12-19T19:02:18.365275Z 0 [Note]     target_file_size_base=67108864
2018-12-19T19:02:18.382120Z 0 [Note] RocksDB: Table_store: loaded DDL data for 0 tables
2018-12-19T19:02:18.382271Z 0 [Note] RocksDB instance opened
2018-12-19T19:02:18.382326Z 0 [Warning] unknown variable 'loose-mysqlx-port=13009'
2018-12-19T19:02:18.382339Z 0 [Warning] unknown variable 'loose-mysqlx-socket=/tmp/VKUz2BWKRo/mysqlx.1.sock'
2018-12-19T19:02:18.382343Z 0 [Warning] unknown variable 'loose-debug-sync-timeout=600'
2018-12-19T19:02:18.385405Z 0 [Note] Salting uuid generator variables, current_pid: 33240, server_start_time: 
1545246138, bytes_sent: 0,
2018-12-19T19:02:18.385452Z 0 [Note] Generated uuid: '9b31e9af-03c0-11e9-87d7-000c29545adf', server_start_time: 
9356228227407484818, bytes_sent: 94084374039824
2018-12-19T19:02:18.385469Z 0 [Warning] No existing UUID has been found, so we assume that this is the first 
time that this server has been started. Generating a new UUID: 9b31e9af-03c0-11e9-87d7-000c29545adf.
2018-12-19T19:02:18.388432Z 0 [Note] Skipping generation of SSL certificates as options related to SSL are 
specified.
2018-12-19T19:02:18.389073Z 0 [Warning] CA certificate 
/var/tmp/portage/dev-db/percona-server-5.7.24.27/work/mysql/mysql-test/std_data/cacert.pem is self signed.
2018-12-19T19:02:18.389139Z 0 [Note] Skipping generation of RSA key pair as 
--sha256_password_auto_generate_rsa_keys is set to OFF.
2018-12-19T19:02:18.389158Z 0 [Warning] RSA private key file not found: 
/var/tmp/portage/dev-db/percona-server-5.7.24.27/work/percona-server-5.7.24.27_build/mysql-test/var/mysqld.1/data//private_key.pem. 
Some authentication plugins will not work.
2018-12-19T19:02:18.389168Z 0 [Warning] RSA public key file not found: 
/var/tmp/portage/dev-db/percona-server-5.7.24.27/work/percona-server-5.7.24.27_build/mysql-test/var/mysqld.1/data//public_key.pem. 
Some authentication plugins will not work.
2018-12-19T19:02:18.389176Z 0 [Note] Server hostname (bind-address): '*'; port: 13001
2018-12-19T19:02:18.389198Z 0 [Note] IPv6 is available.
2018-12-19T19:02:18.389206Z 0 [Note]   - '::' resolves to '::';
2018-12-19T19:02:18.389264Z 0 [Note] Server socket created on IP: '::'.
2018-12-19T19:02:18.390101Z 0 [Warning] Insecure configuration for --pid-file: Location '/var/tmp' in the path 
is accessible to all OS users. Consider choosing a different directory.
2018-12-19T19:02:18.393952Z 0 [Note] Failed to start slave threads for channel ''
2018-12-19T19:02:18.400828Z 0 [Note] Event Scheduler: Loaded 0 events
2018-12-19T19:02:18.401243Z 0 [Note] 
/var/tmp/portage/dev-db/percona-server-5.7.24.27/work/percona-server-5.7.24.27_build/sql/mysqld: ready for 
connections.
Version: '5.7.24-27-log'  socket: '/tmp/VKUz2BWKRo/mysqld.1.sock'  port: 13001  Gentoo Linux 
percona-server-5.7.24.27
2018-12-19T19:02:18.557962Z 3 [Note] RocksDB: creating a column family cf1
2018-12-19T19:02:18.557978Z 3 [Note]     write_buffer_size=65536
2018-12-19T19:02:18.557982Z 3 [Note]     target_file_size_base=67108864
2018-12-19T19:02:18.626094Z 3 [Note] RocksDB: Manual memtable flush.
2018-12-19T19:02:18.641712Z 3 [Warning] MyRocks: failed to apply the options for column family 'cf1'. Invalid 
argument: Option not changeable: prefix_extractor
----------SERVER LOG END-------------

[...]

Test rocksdb.prefix_extractor_override has failed 2 times, no more retries!

--------------------------------------------------------------------------
The servers were restarted 2 times
Spent 0.000 of 7 seconds executing testcases

Completed: Failed 2/2 tests, 0.00% were successful.

Failing test(s): rocksdb.prefix_extractor_override

Environment

# emerge --info                                                                                [315/319]
Portage 2.3.52 (python 3.6.6-final-0, default/linux/amd64/17.1, gcc-8.2.0, glibc-2.28-r3, 4.19.10-gentoo x86_64)
=================================================================
System uname: Linux-4.19.10-gentoo-x86_64-Intel-R-_Core-TM-_i7-3770K_CPU_@_3.50GHz-with-gentoo-2.6
KiB Mem:     8123076 total,   3611580 free
KiB Swap:    1048572 total,   1048572 free
Timestamp of repository gentoo: Wed, 19 Dec 2018 09:44:19 +0000
Head commit of repository gentoo: b2397d16b6d37bccdc0ceceab66ff452ff5d165e

sh bash 4.4_p23 
ld GNU ld (Gentoo 2.31.1 p4) 2.31.1                                                                                     ccache version 3.5 [disabled]
app-shells/bash:          4.4_p23::gentoo
dev-java/java-config:     2.2.0-r4::gentoo
dev-lang/perl:            5.26.2::gentoo
dev-lang/python:          2.7.15::gentoo, 3.6.6::gentoo, 3.7.0::gentoo
dev-util/ccache:          3.5-r1::gentoo                                                                                dev-util/cmake:           3.13.2::gentoo                                                                                dev-util/pkgconfig:       0.29.2::gentoo
sys-apps/baselayout:      2.6-r1::gentoo                                                                                sys-apps/openrc:          0.40.2::gentoo
sys-apps/sandbox:         2.14::gentoo
sys-devel/autoconf:       2.13::gentoo, 2.69-r4::gentoo
sys-devel/automake:       1.13.4-r2::gentoo, 1.16.1-r1::gentoo
sys-devel/binutils:       2.31.1-r2::gentoo
sys-devel/gcc:            7.3.0-r6::gentoo, 8.2.0-r5::gentoo
sys-devel/gcc-config:     2.0::gentoo
sys-devel/libtool:        2.4.6-r5::gentoo
sys-devel/make:           4.2.1-r4::gentoo
sys-kernel/linux-headers: 4.19::gentoo (virtual/os-headers)
sys-libs/glibc:           2.28-r3::gentoo

While our patches should be unrelated, they can be found at https://gitweb.gentoo.org/proj/mysql-extras.git/tree/?h=mysql-extras-20181017-2201Z

Attachments

19 Dec 2018, 07:11 PM

Smart Checklist

Activity

Show:

Julia Vural March 4, 2025 at 9:07 PM

It appears that this issue is no longer being worked on, so we are closing it for housekeeping purposes. If you believe the issue still exists, please open a new ticket after confirming it's present in the latest release.

Won't Do

Details
Assignee
Unassigned
Reporter
Whissi
Labels
test-failure
Components
MyRocks
Priority
Medium

Smart Checklist

Created December 19, 2018 at 7:14 PM

Updated March 4, 2025 at 9:07 PM

Resolved March 4, 2025 at 9:07 PM

Configure

rocksdb.prefix_extractor_override fails: At line 80: Test assertion failed in assert.inc

Description

Environment

Attachments

Smart Checklist

Activity

Julia Vural March 4, 2025 at 9:07 PM

Details
Assignee
Unassigned
Reporter
Whissi
Labels
test-failure
Components
MyRocks
Priority
Medium

Details

Assignee

Reporter

Labels

Components

Priority

Smart Checklist

Smart Checklist

Flag notifications

Something's gone wrong

rocksdb.prefix_extractor_override fails: At line 80: Test assertion failed in assert.inc

Description

Environment

Attachments

Smart Checklist

Activity

Julia Vural March 4, 2025 at 9:07 PM

DetailsAssigneeUnassignedUnassignedReporterWhissiWhissiLabelstest-failureComponentsMyRocksPriorityMedium

Details

Assignee

Reporter

Labels

Components

Priority

Smart ChecklistOpen Smart Checklist

Smart Checklist

Flag notifications

Something's gone wrong

Details
Assignee
Unassigned
Reporter
Whissi
Labels
test-failure
Components
MyRocks
Priority
Medium

Smart Checklist