MySQL Bugs: #50414: valgrind warnings: invalid file descriptor -1 in syscall write()/read()

Bug #50414	valgrind warnings: invalid file descriptor -1 in syscall write()/read()
Submitted:	18 Jan 2010 14:06	Modified:	21 Jun 2010 0:47
Reporter:	Bjørn Munch	Email Updates:
Status:	Closed	Impact on me:	None
Category:	MySQL Server: Replication	Severity:	S3 (Non-critical)
Version:	5.1+	OS:	Linux
Assigned to:	Daogang Qu	CPU Architecture:	Any
Tags:	valgrind

Description:
A number of tests fail with valgrind warnings:

Warning: invalid file descriptor -1 in syscall write()
(or the same with read())

This is not seen in the main branches (yet) because valgrind there is run with --quiet. But in the -mtr branches this is off.

In all -mtr branches from 5.1 up, these tests fail with the warning on write():

main.mysql_client_test
rpl.rpl_slave_load_remove_tmpfile

Looking in the log after rpl.rpl_slave_load_remove_tmpfile, I see an error like this just after the warning:

100118 16:34:54 [ERROR] Slave SQL: Error in Begin_load_query event: write to '../../tmp/SQL_LOAD-2-1-1.data' failed, Error_code: 9

However, after main.mysql_client_test's warning I do not see this.

And in next-mr-mtr and 6.0-codebase-mtr after I merged from the main branches 2009-12-21 (previous merge 2009-12-16), these tests also fail on write():

main.flush_read_lock_kill
rpl.rpl_relayspace
rpl.rpl_extraColmaster_myisam

These fail on write() but apparently not always:

rpl.rpl_extraColmaster_innodb
rpl.rpl_semi_sync_event 

These fail on read() more or less frequently:

rpl.rpl_semi_sync
rpl.rpl_auto_increment
rpl.rpl_bug26395
rpl.rpl_idempotency
rpl.rpl_server_id_ignore
rpl.rpl_ssl
rpl.rpl_bug41902
rpl.rpl_extraColmaster_myisam (read() and write())
rpl.rpl_stm_log
rpl.rpl_start_stop_slave
rpl.rpl_row_log
rpl.rpl_do_grant

After running one of these manually, I see this near the warning:

100118 16:59:35 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:130
10',replication started in log 'FIRST' at position 4
100118 16:59:35 [Note] Slave SQL thread initialized, starting replication in log
 'FIRST' at position 0, relay log './slave-relay-bin.000001' position: 4
100118 16:59:36 [Note] next log './slave-relay-bin.000002' is currently active
100118 16:59:36 [Note] next log './slave-relay-bin.000003' is currently active
==22694== Warning: invalid file descriptor -1 in syscall read()
100118 16:59:39 [ERROR] Error reading packet from server: Lost connection to MyS
QL server during query ( server_errno=2013)

There may be more. Unfortunately, valgrind does not print any call stack so we cannot see from logs where this happens, nor can we link to any particular spot in the test.

How to repeat:
Build with valgrind then e.g.:

./mtr --valgrind rpl.rpl_slave_load_remove_tmpfile

Suggested fix:
It is of course possible to add this particular warning to the global suppression list.

Thank you for the report.

Verified as described.

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/98526

3339 Dao-Gang.Qu@sun.com	2010-01-29
      Bug #50414  	valgrind warnings: invalid file descriptor -1 in syscall write()/read()
      
      There is no certain condition that cause the valgrind warnings:
      invalid file descriptor -1 in syscall write()/read(), which will
      not cause any error and memory leak. So we should suppress the
      valgrind warnings globally as a number of tests failed with the
      valgrind warnings.
      
      To fix the problem, add the valgrind warnings to the global
      suppression list to suppress it.
     @ mysql-test/include/mtr_warnings.sql
        Added code to suppress valgrind warnings: invalid file descriptor
        -1 in syscall write()/read().

You might extend the pattern to

"==[0-9]+== Warning: invalid file descriptor -1 in syscall read()"

, to ensure/clarify this just covers the valgrind warning.

I need to get this into the -mtr trees before I can merge those to the main trees.

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/98935

2886 Dao-Gang.Qu@sun.com	2010-02-02
      Bug #50414  	valgrind warnings: invalid file descriptor -1 in syscall
      write()/read()
      
      Sometimes stop/restart master or stop/restart salve can cause
      network error, which can cause the 'invalid file descriptor
      -1 in syscall write()/read()' warnings. All involved test
      cases except rpl_slave_load_remove_tmpfile belong to the
      kind of network error. So they are expected.
      The 'rpl_slave_load_remove_tmpfile' belongs to file error,
      but it is testing the file error as following code:
      DBUG_EXECUTE_IF("remove_slave_load_file_before_write",
      my_close(fd,MYF(0)); fd= -1; my_delete(fname, MYF(0)););
      So it's expected too.
      
      To fix the problem, add the valgrind warnings to the global
      suppression list to suppress it.
     @ mysql-test/include/mtr_warnings.sql
        Added code to suppress valgrind warnings: invalid file
        descriptor -1 in syscall write()/read().

Fix and explanation look fine, OK!

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/99007

2886 Dao-Gang.Qu@sun.com	2010-02-03
      Bug #50414  	valgrind warnings: invalid file descriptor -1 in syscall
      write()/read()
      
      Sometimes stop/restart master or stop/restart salve can cause
      network error, which can cause the 'invalid file descriptor
      -1 in syscall write()/read()' warnings. All involved test
      cases except rpl_slave_load_remove_tmpfile belong to the
      kind of network error. So they are expected.
      The 'rpl_slave_load_remove_tmpfile' belongs to file error,
      but it is testing the file error as following code:
      DBUG_EXECUTE_IF("remove_slave_load_file_before_write",
      my_close(fd,MYF(0)); fd= -1; my_delete(fname, MYF(0)););
      So it's expected too.
      
      To fix the problem, add the valgrind warnings to the global
      suppression list to suppress it.
     @ mysql-test/include/mtr_warnings.sql
        Added code to suppress valgrind warnings: invalid file
        descriptor -1 in syscall write()/read().

Pushed to mysql-5.1-mtr. Bjorn, please take care of upmerge to the other -mtr trees as you recommended.

Pished to trunk-mtr, next-mr-mtr and 6.0-codebase-mtr (after verifying the fix in 6.0-codebase-mtr)

Pushed into 6.0.14-alpha (revid:alik@sun.com-20100220092844-jh07ayojyxn8uh9p) (version source revid:bjorn.munch@sun.com-20100203093000-sm5tkanq19w5vgpx) (merge vers: 6.0.14-alpha) (pib:16)

Pushed into 5.5.3-m2 (revid:alik@sun.com-20100220092622-wvhh1vfy5tjq4mhu) (version source revid:bjorn.munch@sun.com-20100203092553-1x855pw0aintk7yh) (merge vers: 5.5.1-m2) (pib:16)

Pushed into mysql-next-mr (revid:alik@sun.com-20100220092730-paoo5t9gcajs5dq8) (version source revid:bjorn.munch@sun.com-20100203092817-93ablyd2s5332736) (pib:16)

Changes to test suite. No changelog entry needed.

Setting report to Need Merge pending push to 5.1.x.

Pushed into 5.1.45 (revid:joro@sun.com-20100301083827-xnimmrjg6bh33o1o) (version source revid:azundris@mysql.com-20100222175719-viuh0f3gdsrkgv0r) (merge vers: 5.1.45) (pib:16)

Change affects testing only.

Closed without further action.

Pushed into 5.1.47-ndb-7.0.16 (revid:martin.skold@mysql.com-20100617114014-bva0dy24yyd67697) (version source revid:vasil.dimov@oracle.com-20100331130613-8ja7n0vh36a80457) (merge vers: 5.1.46) (pib:16)

Pushed into 5.1.47-ndb-6.2.19 (revid:martin.skold@mysql.com-20100617115448-idrbic6gbki37h1c) (version source revid:martin.skold@mysql.com-20100609140708-52rvuyq4q500sxkq) (merge vers: 5.1.45-ndb-6.2.19) (pib:16)

Pushed into 5.1.47-ndb-6.3.35 (revid:martin.skold@mysql.com-20100617114611-61aqbb52j752y116) (version source revid:vasil.dimov@oracle.com-20100331130613-8ja7n0vh36a80457) (merge vers: 5.1.46) (pib:16)