Bug #48340 rpl_cross_version: Found warnings/errors in server log file!
| Submitted: | 27 Oct 2009 7:42 | Modified: | 12 Mar 2010 17:06 |
|---|---|---|---|
| Reporter: | Daogang Qu | Email Updates: | |
| Status: | Closed | Impact on me: | |
| Category: | MySQL Server: Replication | Severity: | S3 (Non-critical) |
| Version: | 5.1+ | OS: | Any |
| Assigned to: | Luis Soares | CPU Architecture: | Any |
[2 Nov 2009 10:24]
Daogang Qu
The failure is found on test-valgrind-linux-x86_64 (tyr79) platform base on 'mysql-5.1-bugteam' tree.
[17 Nov 2009 14:34]
Luis Soares
Hi,
I could repeat this using the following steps:
bzr clone $MY_LOCAL_CLONES_DIR/mysql-5.1-bugteam
cd mysql-5.1-bugteam
./BUILD/compile-pentium64-valgrind-max
cd mysql-test
perl mysql-test-run.pl --mysqld=--binlog-format=mix --valgrind --valgrind-options="--gen-suppressions=all --show-reachable=yes" rpl_cross_version
The original error is reported by PB2 on a valgrind run, more
precisely, on mysql-5.1-bugteam tree. This is still failing in
PB2. Details for recent failure:
Where Build Test Run Suite Case Mode When
mysql-5.1-bugteam
686585 binary-debug_valgrind-linux-x86_64-tar-gz
686668 tyr33 test-valgrind-linux-x86_64
689896 tyr77 n_mix rpl rpl_cross_version None 2009-11-13 13:20:23
rpl.rpl_cross_version [ exp-fail ] Found warnings/errors in server log file!
Test ended at 2009-11-14 13:56:48
mysqltest: Logging to ''.
mysqltest: Results saved in ''.
mysqltest: Connecting to server localhost:13010 (socket /export/home2/pb2/test/sb_1-966965-1258180371.12/tmp/0T4PmhlCcD/mysqld.1.sock) as 'root', connection 'default', attempt 0 ...
mysqltest: ... Connected.
mysqltest: Start processing test commands from './include/check-warnings.test' ...
line
==24854== Thread 4:
==24854== Conditional jump or move depends on uninitialised value(s)
==24854== at 0x8145CA: write_execute_load_query_log_event(THD*, sql_exchange*, char const*, char const*, enum_duplicates, bool, bool, int) (sql_load.cc:620)
==24854== by 0x816220: mysql_load(THD*, sql_exchange*, TABLE_LIST*, List<Item>&, List<Item>&, List<Item>&, enum_duplicates, bool, bool) (sql_load.cc:555)
==24854== by 0x79FBFA: Load_log_event::do_apply_event(st_net*, Relay_log_info const*, bool) (log_event.cc:4673)
==24854== by 0x7A56F2: Execute_load_log_event::do_apply_event(Relay_log_info const*) (log_event.cc:6568)
==24854== by 0x852BF3: Log_event::apply_event(Relay_log_info const*) (log_event.h:1059)
==24854== by 0x84CB62: apply_event_and_update_pos(Log_event*, THD*, Relay_log_info*) (slave.cc:2136)
==24854== by 0x84D057: exec_relay_log_event(THD*, Relay_log_info*) (slave.cc:2277)
==24854== by 0x84DB7B: handle_slave_sql (slave.cc:3023)
==24854== by 0x3F6D606366: start_thread (in /lib64/libpthread-2.5.so)
==24854== by 0x3F6CAD30AC: clone (in /lib64/libc-2.5.so)
^ Found warnings in /export/home2/pb2/test/sb_1-966965-1258180371.12/mysql-5.1.41-linux-x86_64-test/mysql-test/var-n_mix/log/mysqld.1.err
mysqltest: ... Done processing test commands.
mysqltest: Test has succeeded!
[17 Nov 2009 15:25]
MySQL Verification Team
Verified according Luis's instructions:
miguel@quetzal3:~/bzr/5.1-bugteam$ cd mysql-test
miguel@quetzal3:~/bzr/5.1-bugteam/mysql-test$ perl mysql-test-run.pl --mysqld=--binlog-format=mix --valgrind --valgrind-options="--gen-suppressions=all --show-reachable=yes" rpl_cross_version
Logging: mysql-test-run.pl --mysqld=--binlog-format=mix --valgrind --valgrind-options=--gen-suppressions=all --show-reachable=yes rpl_cross_version
091117 13:22:24 [Note] Plugin 'FEDERATED' is disabled.
091117 13:22:24 [Note] Plugin 'ndbcluster' is disabled.
MySQL Version 5.1.41
Using binlog format 'mix'
Turning on valgrind for all executables
Running valgrind with options " --gen-suppressions=all --show-reachable=yes --quiet "
Checking supported features...
- using ndbcluster when necessary, mysqld supports it
- SSL connections supported
- binaries are debug compiled
Using "../libtool" when running valgrind or debugger
Collecting tests...
- adding combinations for rpl
vardir: /home/miguel/bzr/5.1-bugteam/mysql-test/var
Removing old var directory...
Creating var directory '/home/miguel/bzr/5.1-bugteam/mysql-test/var'...
Installing system database...
Using server port 57390
==============================================================================
TEST RESULT TIME (ms)
------------------------------------------------------------
worker[1] Using MTR_BUILD_THREAD 300, with reserved ports 13000..13009
rpl.rpl_cross_version [ fail ] Found warnings/errors in server log file!
Test ended at 2009-11-17 13:22:52
mysqltest: Logging to ''.
mysqltest: Results saved in ''.
mysqltest: Connecting to server localhost:13000 (socket /home/miguel/bzr/5.1-bugteam/mysql-test/var/tmp/mysqld.1.sock) as 'root', connection 'default', attempt 0 ...
mysqltest: ... Connected.
mysqltest: Start processing test commands from './include/check-warnings.test' ...
line
==13366== Thread 4:
==13366== Conditional jump or move depends on uninitialised value(s)
==13366== at 0x85719B: write_execute_load_query_log_event(THD*, sql_exchange*, char c
[24 Nov 2009 20:04]
Bugs System
A patch for this bug has been committed. After review, it may be pushed to the relevant source trees for release in the next version. You can access the patch from: http://lists.mysql.com/commits/91471 3201 Luis Soares 2009-11-24 BUG#48340: rpl_cross_version: Found warnings/errors in server log file! Valgrind reports a conditional jump that depends on uninitialized data while doing a LOAD DATA and for this test case only. This test case, tests that loading data from a 4.0 or 4.1 instance into a 5.1 instance is working. As such it handles old binary log with a different set of events than currently 5.1 codebase uses. See the following reference for details: http://forge.mysql.com/wiki/MySQL_Internals_Binary_Log#LOAD_DATA_INFILE_Events Problem: The server is handling an Execute_load_log_event, which results in reading a Load_log_event from the binary log and applying it. When applying the Load_log_event, some variable setup is done and then mysql_load is called. Late in mysql_load execution, if not in row mode logging, the event is binlogged write_execute_load_query_log_event. In write_execute_load_query_log_event, thd->lex->local_file is inspected. The problem is that it has not been set before in the execution stack. This causes valgrind to report the warning. Fix: We fix this by initializing thd->lex->local_file to be the same as the value of Load_log_event::local_fname, when lex_start is called inside Load_log_event::do_apply_event.
[1 Dec 2009 8:40]
Daogang Qu
The 'rpl_cross_version' test case is added to experimental test list due to the bug#48340.
[19 Dec 2009 8:28]
Bugs System
Pushed into 6.0.14-alpha (revid:alik@sun.com-20091219082307-f3i4fn0tm8trb3c0) (version source revid:alik@sun.com-20091216180721-eoa754i79j4ssd3m) (merge vers: 6.0.14-alpha) (pib:15)
[19 Dec 2009 8:32]
Bugs System
Pushed into 5.5.1-m2 (revid:alik@sun.com-20091219082021-f34nq4jytwamozz0) (version source revid:alexey.kopytov@sun.com-20091211164058-ycpe0f20d1c4h1gl) (merge vers: 5.5.0-beta) (pib:15)
[19 Dec 2009 8:36]
Bugs System
Pushed into mysql-next-mr (revid:alik@sun.com-20091219082213-nhjjgmphote4ntxj) (version source revid:alik@sun.com-20091216180221-a5ps59gajad3pip9) (pib:15)
[11 Jan 2010 17:47]
Paul DuBois
Noted in 5.5.1, 6.0.14 changelogs. Valgrind warnings related to binary logging of LOAD DATA INFILE statements were corrected. Setting report to NDI pending push to 5.1.x, Celosia.
[15 Jan 2010 8:58]
Bugs System
Pushed into 5.1.43 (revid:joro@sun.com-20100115085139-qkh0i0fpohd9u9p5) (version source revid:luis.soares@sun.com-20091206233607-ae6i2ffhx270bp5u) (merge vers: 5.1.42) (pib:16)
[15 Jan 2010 19:06]
Paul DuBois
Noted in 5.1.43 changelog. Setting report to NDI pending push to Celosia.
[12 Mar 2010 14:20]
Bugs System
Pushed into 5.1.44-ndb-7.0.14 (revid:jonas@mysql.com-20100312135944-t0z8s1da2orvl66x) (version source revid:jonas@mysql.com-20100312115609-woou0te4a6s4ae9y) (merge vers: 5.1.44-ndb-7.0.14) (pib:16)
[12 Mar 2010 14:34]
Bugs System
Pushed into 5.1.44-ndb-6.2.19 (revid:jonas@mysql.com-20100312134846-tuqhd9w3tv4xgl3d) (version source revid:jonas@mysql.com-20100312060623-mx6407w2vx76h3by) (merge vers: 5.1.44-ndb-6.2.19) (pib:16)
[12 Mar 2010 14:51]
Bugs System
Pushed into 5.1.44-ndb-6.3.33 (revid:jonas@mysql.com-20100312135724-xcw8vw2lu3mijrhn) (version source revid:jonas@mysql.com-20100312103652-snkltsd197l7q2yg) (merge vers: 5.1.44-ndb-6.3.33) (pib:16)
[12 Mar 2010 17:06]
Paul DuBois
Fixed in earlier 5.1.x, 5.5.x.
Portions of this website are copyright © 2001, 2002 The PHP Group
Page generated in 0.050 sec. using MySQL 8.4.7-u6-cloud
Timestamp references displayed by the system are UTC.
Content reproduced on this site is the property of the
respective copyright holders.
It is not reviewed in advance
by Oracle and does not necessarily represent the opinion of
Oracle or any other party.
Description: rpl.rpl_cross_version [ fail ] Found warnings/errors in server log file! Test ended at 2009-10-26 00:26:40 mysqltest: Logging to ''. mysqltest: Results saved in ''. mysqltest: Connecting to server localhost:13000 (socket /export/home2/pb2/test/sb_1-884023-1256498343.82/tmp/aN5s2FSE4I/mysqld.1.sock) as 'root', connection 'default', attempt 0 ... mysqltest: ... Connected. mysqltest: Start processing test commands from './include/check-warnings.test' ... line ==30332== Thread 4: ==30332== Conditional jump or move depends on uninitialised value(s) ==30332== at 0x80BC85: write_execute_load_query_log_event(THD*, sql_exchange*, char const*, char const*, enum_duplicates, bool, bool, int) (sql_load.cc:638) ==30332== by 0x80D9CC: mysql_load(THD*, sql_exchange*, TABLE_LIST*, List<Item>&, List<Item>&, List<Item>&, enum_duplicates, bool, bool) (sql_load.cc:592) ==30332== by 0x7939B6: Load_log_event::do_apply_event(st_net*, Relay_log_info const*, bool) (log_event.cc:4668) ==30332== by 0x7994A8: Execute_load_log_event::do_apply_event(Relay_log_info const*) (log_event.cc:6563) ==30332== by 0x84A083: Log_event::apply_event(Relay_log_info const*) (log_event.h:1059) ==30332== by 0x843F82: apply_event_and_update_pos(Log_event*, THD*, Relay_log_info*) (slave.cc:2136) ==30332== by 0x844477: exec_relay_log_event(THD*, Relay_log_info*) (slave.cc:2277) ==30332== by 0x844FA9: handle_slave_sql (slave.cc:3023) ==30332== by 0x3895A06366: start_thread (in /lib64/libpthread-2.5.so) ==30332== by 0x3894ED30AC: clone (in /lib64/libc-2.5.so) ^ Found warnings in /export/home2/pb2/test/sb_1-884023-1256498343.82/mysql-5.5.0-beta-linux-x86_64-test/mysql-test/var-n_mix/log/mysqld.1.err mysqltest: ... Done processing test commands. mysqltest: Test has succeeded! ok - saving '/export/home2/pb2/test/sb_1-884023-1256498343.82/mysql-5.5.0-beta-linux-x86_64-test/mysql-test/var-n_mix/log/rpl.rpl_cross_version/' to '/export/home2/pb2/test/sb_1-884023-1256498343.82/mysql-5.5.0-beta-linux-x86_64-test/mysql-test/var-n_mix/log/rpl.rpl_cross_version/' Retrying test, attempt(2/3)... How to repeat: http://pb2.norway.sun.com/web.py?template=mysql_show_test_failure&test_failure_id=2413446