stewartsmith / libeatmydata

libeatmydata - because fsync() should be a no-op
https://www.flamingspork.com/projects/libeatmydata/
GNU General Public License v3.0
409 stars 21 forks source link

MySQL Server 5.7.17 unit tests fail when run with LD_PRELOAD=libeatmydata.so #1

Closed percona-ysorokin closed 7 years ago

percona-ysorokin commented 7 years ago

[yura@localhost mysql-build]$ LD_PRELOAD=/home/yura/ws/libeatmydata/.libs/libeatmydata.so ./mysql-test/mtr --debug-server 1st --unit-tests-report --debug-server

MySQL Version 5.7.17
Checking supported features...
 - SSL connections supported
 - binaries are debug compiled
Collecting tests...
Removing old var directory...
Creating var directory '/home/yura/ws/mysql-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
main.1st                                 [ pass ]      2
unit_tests                               [ fail ]
        Test ended at 2017-01-24 18:40:04

ctest failed with exit code 2048, see result below

--------------------------------------------------------------------------
Test project /home/yura/ws/mysql-build
      Start  1: hp_test1
 1/77 Test  #1: hp_test1 ................................................................................................................   Passed    0.01 sec
      Start  2: hp_test2
 2/77 Test  #2: hp_test2 ................................................................................................................   Passed    0.63 sec
      Start  3: pfs_instr_class
 3/77 Test  #3: pfs_instr_class .........................................................................................................   Passed    0.01 sec
      Start  4: pfs_instr_class-oom
 4/77 Test  #4: pfs_instr_class-oom .....................................................................................................   Passed    0.02 sec
      Start  5: pfs_instr
 5/77 Test  #5: pfs_instr ...............................................................................................................   Passed    0.02 sec
      Start  6: pfs_instr-oom
 6/77 Test  #6: pfs_instr-oom ...........................................................................................................   Passed    0.02 sec
      Start  7: pfs_account-oom
 7/77 Test  #7: pfs_account-oom .........................................................................................................   Passed    0.02 sec
      Start  8: pfs_host-oom
 8/77 Test  #8: pfs_host-oom ............................................................................................................   Passed    0.14 sec
      Start  9: pfs_user-oom
 9/77 Test  #9: pfs_user-oom ............................................................................................................   Passed    0.14 sec
      Start 10: pfs_noop
10/77 Test #10: pfs_noop ................................................................................................................   Passed    0.01 sec
      Start 11: pfs
11/77 Test #11: pfs .....................................................................................................................   Passed    0.97 sec
      Start 12: pfs_misc
12/77 Test #12: pfs_misc ................................................................................................................   Passed    0.01 sec
      Start 13: pfs_connect_attr
13/77 Test #13: pfs_connect_attr ........................................................................................................   Passed    0.11 sec
      Start 14: regex1
14/77 Test #14: regex1 ..................................................................................................................   Passed    0.01 sec
      Start 15: regex2
15/77 Test #15: regex2 ..................................................................................................................   Passed    0.01 sec
      Start 16: regex3
16/77 Test #16: regex3 ..................................................................................................................   Passed    0.01 sec
      Start 17: queues_test
17/77 Test #17: queues_test .............................................................................................................   Passed    0.37 sec
      Start 18: merge_large_tests
18/77 Test #18: merge_large_tests .......................................................................................................   Passed    6.06 sec
      Start 19: merge_small_tests
19/77 Test #19: merge_small_tests .......................................................................................................   Passed    2.17 sec
      Start 20: merge_innodb_tests
20/77 Test #20: merge_innodb_tests ......................................................................................................   Passed    0.57 sec
      Start 21: merge_keyring_file_tests
21/77 Test #21: merge_keyring_file_tests ................................................................................................***Failed    0.06 sec
# Running 55 tests from 6 test cases
1..55
# Global test environment set-up
# Run 1 Keyring_api_test.StoreFetchRemove
ok 1
# Run 2 Keyring_api_test.CheckIfInmemoryKeyIsXORed
ok 2
# Run 3 Keyring_api_test.FetchNotExisting
ok 3
# Run 4 Keyring_api_test.RemoveNotExisting
ok 4
# Run 5 Keyring_api_test.StoreFetchNotExisting
ok 5
# Run 6 Keyring_api_test.StoreStoreStoreFetchRemove
ok 6
# Run 7 Keyring_api_test.StoreValidTypes
ok 7
# Run 8 Keyring_api_test.StoreInvalidType
ok 8
# Run 9 Keyring_api_test.StoreTwiceTheSameDifferentTypes
ok 9
# Run 10 Keyring_api_test.KeyGenerate
ok 10
# Run 11 Keyring_api_test.KeyringFileChange
ok 11
# Run 12 Keyring_api_test.NullUser
ok 12
# Run 13 Keyring_api_test.NullKeyId
ok 13
# Run 14 Keys_container_test.InitWithFileWithCorrectStruct
ok 14
# Run 15 Keys_container_test.InitWithFileWithIncorrectKeyringVersion
ok 15
# Run 16 Keys_container_test.InitWithFileWithIncorrectTAG
ok 16
# Run 17 Keys_container_test.StoreFetchRemove
ok 17
# Run 18 Keys_container_test.FetchNotExisting
ok 18
# Run 19 Keys_container_test.RemoveNotExisting
ok 19
# Run 20 Keys_container_test.StoreFetchNotExisting
ok 20
# Run 21 Keys_container_test.StoreRemoveNotExisting
ok 21
# Run 22 Keys_container_test.StoreStoreStoreFetchRemove
ok 22
# Run 23 Keys_container_test.StoreTwiceTheSame
ok 23
# Run 24 Keys_container_test_dont_close.CheckIfCorrectBackupFileIsCreatedAfterStoringOneKey
ok 24
# Run 25 Keys_container_test_dont_close.CheckIfCorrectBackupFileIsCreatedAfterStoringTwoKeys
ok 25
# Run 26 Keys_container_test_dont_close.CheckIfCorrectBackupFileIsCreatedBeforeRemovingKey
ok 26
# Run 27 Keys_container_test_dont_close.CheckIfBackupFileIsNotCreatedForFetching
ok 27
# Run 28 Keys_container_test_dont_close.KeyringfileIsMalformedCheckIfBackupIsLoaded
ok 28
# Run 29 Keys_container_test_dont_close.BackupfileIsMalformedCheckItIsIgnoredAndDeleted
ok 29
# Run 30 Keys_container_test_dont_close.CheckIfKeyringIsNotRecreatedWhenKeyringfileDoesnotExist
ok 30
# Run 31 Keys_container_test_dont_close.CheckIfKeyringIsNotRecreatedWhenBackupFileExistsAndKeyringFileDoesnot
ok 31
# Run 32 Keys_container_test_dont_close.CheckIfKeyIsNotDumpedIntoKeyringFileIfKeyringFileHasBeenChanged
ok 32
# Run 33 Keys_container_with_mocked_io_test.ErrorFromIODuringInitOnGettingSerializedObject
ok 33
# Run 34 Keys_container_with_mocked_io_test.ErrorFromIODuringInitInvalidKeyAndMockedSerializedObject
ok 34
# Run 35 Keys_container_with_mocked_io_test.ErrorFromIODuringInitInvalidKey
ok 35
# Run 36 Keys_container_with_mocked_io_test.ErrorFromSerializerOnFlushToBackupWhenStoringKey
ok 36
# Run 37 Keys_container_with_mocked_io_test.ErrorFromSerializerOnFlushToKeyringWhenStoringKey
ok 37
# Run 38 Keys_container_with_mocked_io_test.ErrorFromSerializerOnFlushToBackupWhenRemovingKey
ok 38
# Run 39 Keys_container_with_mocked_io_test.ErrorFromSerializerOnFlushToKeyringWhenRemovingKey
ok 39
# Run 40 Keys_container_with_mocked_io_test.StoreAndRemoveKey
ok 40
# Run 41 Keys_container_with_mocked_io_test.ErrorFromIOWhileRemovingKeyAfterAdding2Keys
ok 41
# Run 42 Keys_container_with_mocked_io_test.Store2KeysAndRemoveThem
ok 42
# Run 43 Buffered_file_io_test.InitWithNotExisitingKeyringFile
ok 43
# Run 44 Buffered_file_io_test.WriteAndFetchKey
ok 44
# Run 45 Buffered_file_io_test.Write2KeysAndFetchKeys
ok 45
# Run 46 File_io_test.OpenNotExistingFile
ok 46
# Run 47 File_io_test.CloseTwiceTheSame
ok 47
# Run 48 File_io_test.ReadFromInvalidFileDescriptor
ok 48
# Run 49 File_io_test.WriteToInvalidFileDescriptor
ok 49
# Run 50 File_io_test.SeekOnInvalidFileDescriptor
ok 50
# Run 51 File_io_test.TellOnInvalidFileDescriptor
ok 51
# Run 52 File_io_test.SyncOnInvalidFileDescriptor
/home/yura/ws/mysql-server/unittest/gunit/keyring/file_io-t.cc:160: FailureValue of: file_io.sync(file, MYF(MY_WME)) != 0
  Actual: false
Expected: true
/home/yura/ws/mysql-server/unittest/gunit/keyring/file_io-t.cc:159: FailureActual function call count doesn't match EXPECT_CALL(*logger, log(MY_ERROR_LEVEL, StrEq("Can't sync file 'UNKNOWN' to disk " "(Errcode: 9 - Bad file descriptor)")))...
         Expected: to be called once
           Actual: never called - unsatisfied and active
not ok 52
# Run 53 File_io_test.FStatOnInvalidFileDescriptor
ok 53
# Run 54 File_io_test.RemoveNotExistingFile
ok 54
# Run 55 File_io_test.TruncateOnNotExistingFile
ok 55
# Global test environment tear-down
# Ran 55 tests from 6 test cases
# Passed 54 tests
# Failed 1 test

      Start 22: simple
22/77 Test #22: simple ..................................................................................................................   Passed    0.35 sec
      Start 23: skip
23/77 Test #23: skip ....................................................................................................................   Passed    0.00 sec
      Start 24: todo
24/77 Test #24: todo ....................................................................................................................   Passed    0.00 sec
      Start 25: skip_all
25/77 Test #25: skip_all ................................................................................................................   Passed    0.00 sec
      Start 26: no_plan
26/77 Test #26: no_plan .................................................................................................................   Passed    0.00 sec
      Start 27: basic
27/77 Test #27: basic ...................................................................................................................   Passed    0.00 sec
      Start 28: group_replication_member_info
28/77 Test #28: group_replication_member_info ...........................................................................................   Passed    0.02 sec
      Start 29: group_replication_compatibility_module
29/77 Test #29: group_replication_compatibility_module ..................................................................................   Passed    0.02 sec
      Start 30: group_replication_member_version
30/77 Test #30: group_replication_member_version ........................................................................................   Passed    0.02 sec
      Start 31: Admin_command_arguments_object_test
31/77 Test #31: Admin_command_arguments_object_test .....................................................................................   Passed    0.03 sec
      Start 32: Callback_command_delegate_testsuite
32/77 Test #32: Callback_command_delegate_testsuite .....................................................................................   Passed    0.02 sec
      Start 33: CapabilitiesConfiguratorTestSuite
33/77 Test #33: CapabilitiesConfiguratorTestSuite .......................................................................................   Passed    0.02 sec
      Start 34: CapabilityHanderTlsTestSuite
34/77 Test #34: CapabilityHanderTlsTestSuite ............................................................................................   Passed    0.02 sec
      Start 35: CapabilityHanderAuthMechTestSuite
35/77 Test #35: CapabilityHanderAuthMechTestSuite .......................................................................................   Passed    0.02 sec
      Start 36: Crud_statement_builder_test
36/77 Test #36: Crud_statement_builder_test .............................................................................................   Passed    0.02 sec
      Start 37: Delete_statement_builder_test
37/77 Test #37: Delete_statement_builder_test ...........................................................................................   Passed    0.02 sec
      Start 38: expect
38/77 Test #38: expect ..................................................................................................................   Passed    0.02 sec
      Start 39: xpl_expr_generator
39/77 Test #39: xpl_expr_generator ......................................................................................................   Passed    0.02 sec
      Start 40: Find_statement_builder_test
40/77 Test #40: Find_statement_builder_test .............................................................................................   Passed    0.02 sec
      Start 41: Getter_any_testsuite
41/77 Test #41: Getter_any_testsuite ....................................................................................................   Passed    0.02 sec
      Start 42: Insert_statement_builder_test
42/77 Test #42: Insert_statement_builder_test ...........................................................................................   Passed    0.02 sec
      Start 43: Listener_tcp_testsuite
43/77 Test #43: Listener_tcp_testsuite ..................................................................................................   Passed    0.02 sec
      Start 44: Listener_unix_socket_testsuite
44/77 Test #44: Listener_unix_socket_testsuite ..........................................................................................   Passed    0.02 sec
      Start 45: message_builder
45/77 Test #45: message_builder .........................................................................................................   Passed    0.01 sec
      Start 46: OBuffer
46/77 Test #46: OBuffer .................................................................................................................   Passed    0.03 sec
      Start 47: Query_string_builder_testsuite
47/77 Test #47: Query_string_builder_testsuite ..........................................................................................   Passed    0.01 sec
      Start 48: row_builder
48/77 Test #48: row_builder .............................................................................................................   Passed    0.02 sec
      Start 49: SaslAuthenticationTestSuite
49/77 Test #49: SaslAuthenticationTestSuite .............................................................................................   Passed    0.02 sec
      Start 50: ExpectedValuesSaslAuthenticationTestSuite
50/77 Test #50: ExpectedValuesSaslAuthenticationTestSuite ...............................................................................   Passed    0.02 sec
      Start 51: PartialMockSaslAuthenticationTestSuite
51/77 Test #51: PartialMockSaslAuthenticationTestSuite ..................................................................................   Passed    0.02 sec
      Start 52: xpl_scheduler_dynamic
52/77 Test #52: xpl_scheduler_dynamic ...................................................................................................   Passed    0.01 sec
      Start 53: Ngs_sync_variable
53/77 Test #53: Ngs_sync_variable .......................................................................................................   Passed    0.02 sec
      Start 54: Update_statement_builder_test
54/77 Test #54: Update_statement_builder_test ...........................................................................................   Passed    0.02 sec
      Start 55: User_verification_test
55/77 Test #55: User_verification_test ..................................................................................................   Passed    0.02 sec
      Start 56: View_statement_builder_test
56/77 Test #56: View_statement_builder_test .............................................................................................   Passed    0.02 sec
      Start 57: xdatetime
57/77 Test #57: xdatetime ...............................................................................................................   Passed    0.01 sec
      Start 58: xdecimal
58/77 Test #58: xdecimal ................................................................................................................   Passed    0.01 sec
      Start 59: SuccessInstantiation/SuccessSetCapabilityHanderTlsTestSuite
59/77 Test #59: SuccessInstantiation/SuccessSetCapabilityHanderTlsTestSuite .............................................................   Passed    0.02 sec
      Start 60: FaildInstantiationAlreadySet/FaildSetCapabilityHanderTlsTestSuite
60/77 Test #60: FaildInstantiationAlreadySet/FaildSetCapabilityHanderTlsTestSuite .......................................................   Passed    0.02 sec
      Start 61: FaildInstantiationCantDisable/FaildSetCapabilityHanderTlsTestSuite
61/77 Test #61: FaildInstantiationCantDisable/FaildSetCapabilityHanderTlsTestSuite ......................................................   Passed    0.02 sec
      Start 62: FaildInstantiationAlreadyDisabled/FaildSetCapabilityHanderTlsTestSuite
62/77 Test #62: FaildInstantiationAlreadyDisabled/FaildSetCapabilityHanderTlsTestSuite ..................................................   Passed    0.01 sec
      Start 63: InstantiationNegativeTests/Getter_any_type_testsuite
63/77 Test #63: InstantiationNegativeTests/Getter_any_type_testsuite ....................................................................   Passed    0.01 sec
      Start 64: InstantiationNegativeTests/Getter_scalar_type_testsuite
64/77 Test #64: InstantiationNegativeTests/Getter_scalar_type_testsuite .................................................................   Passed    0.01 sec
      Start 65: Instantiation_tcp_retry_when_already_in_use/Listener_tcp_retry_testsuite
65/77 Test #65: Instantiation_tcp_retry_when_already_in_use/Listener_tcp_retry_testsuite ................................................   Passed    0.02 sec
      Start 66: Native_mysql_functions/Mysql_function_names_pass_test
66/77 Test #66: Native_mysql_functions/Mysql_function_names_pass_test ...................................................................   Passed    0.02 sec
      Start 67: Special_mysql_functions/Mysql_function_names_pass_test
67/77 Test #67: Special_mysql_functions/Mysql_function_names_pass_test ..................................................................   Passed    0.01 sec
      Start 68: Other_mysql_functions/Mysql_function_names_pass_test
68/77 Test #68: Other_mysql_functions/Mysql_function_names_pass_test ....................................................................   Passed    0.02 sec
      Start 69: Mysql_function_names_fail/Mysql_function_names_fail_test
69/77 Test #69: Mysql_function_names_fail/Mysql_function_names_fail_test ................................................................   Passed    0.01 sec
      Start 70: InstantiationPositiveTest/Query_string_builder_param_testsuite
70/77 Test #70: InstantiationPositiveTest/Query_string_builder_param_testsuite ..........................................................   Passed    0.01 sec
      Start 71: InstantiationPositiveTests/Query_string_builder_multiple_tags_param_testsuite
71/77 Test #71: InstantiationPositiveTests/Query_string_builder_multiple_tags_param_testsuite ...........................................   Passed    0.01 sec
      Start 72: InstantiationPositiveTestsQueryOrValuesWithEscapedChars/Query_string_builder_multiple_tags_param_testsuite
72/77 Test #72: InstantiationPositiveTestsQueryOrValuesWithEscapedChars/Query_string_builder_multiple_tags_param_testsuite ..............   Passed    0.01 sec
      Start 73: InstantiationPositiveTestsQueryWithComment/Query_string_builder_multiple_tags_param_testsuite
73/77 Test #73: InstantiationPositiveTestsQueryWithComment/Query_string_builder_multiple_tags_param_testsuite ...........................   Passed    0.02 sec
      Start 74: InstantiationNegativeTest/Query_string_builder_multiple_too_many_tags_param_testsuite
74/77 Test #74: InstantiationNegativeTest/Query_string_builder_multiple_too_many_tags_param_testsuite ...................................   Passed    0.02 sec
      Start 75: Range_from_0_to_9/User_verification_param_test
75/77 Test #75: Range_from_0_to_9/User_verification_param_test ..........................................................................   Passed    0.02 sec
      Start 76: Supported_connection_type_require_transport_combinations/User_verification_param_test_with_supported_combinations
76/77 Test #76: Supported_connection_type_require_transport_combinations/User_verification_param_test_with_supported_combinations .......   Passed    0.02 sec
      Start 77: Unsupported_connection_type_require_transport_combinations/User_verification_param_test_with_unsupported_combinations
77/77 Test #77: Unsupported_connection_type_require_transport_combinations/User_verification_param_test_with_unsupported_combinations ...   Passed    0.02 sec

99% tests passed, 1 tests failed out of 77

Total Test time (real) =  12.65 sec

The following tests FAILED:
         21 - merge_keyring_file_tests (Failed)
Errors while running CTest

Unit tests: 99% tests passed, 1 tests failed out of 77
  The following tests FAILED:
         21 - merge_keyring_file_tests (Failed)
Report from unit tests in /home/yura/ws/mysql-build/mysql-test/var/ctest.log
--------------------------------------------------------------------------
The servers were restarted 0 times
Spent 0.002 of 19 seconds executing testcases

Completed: Failed 1/2 tests, 50.00% were successful.

Failing test(s): unit_tests

The log files in var/log may give you some hint of what went wrong.

If you want to report this error, please read first the documentation
at http://dev.mysql.com/doc/mysql/en/mysql-test-suite.html

mysql-test-run: *** ERROR: there were failing test cases

A simplified command with the same effect (running ctest directly) LD_PRELOAD=/home/yura/ws/libeatmydata/.libs/libeatmydata.so ctest -V -R merge_keyring_file_tests

This does not happen without LD_PRELOAD.

Observed with MySQL Server 5.7.17 Debug compiled from source and with the latest version of libeatmydata library compiled from source (commit 3cfd8c1)

laurynas-biveinis commented 7 years ago

It looks like the testcase expects fsync to return EBADF for bad fd, but libeatmydata implementation accepts any fd.

percona-ysorokin commented 7 years ago

Here is a code fragment which can be used to reproduce the issue (compiled and run on CentOS 7 x64)

#include <stdio.h>
#include <errno.h>
#include <unistd.h>

int main(int argc, char* argv[])
{
  int fd = 42; // non-existing file descriptor
  int res = fdatasync(fd);
  printf("fdatasync(fd) returned %d, errno = %d\n", res, errno);
  return 0;
}

When run without libeatmydata

[yura@localhost host-ws]$ ./libeatmydata_fdatasync_issue
fdatasync(fd) returned -1, errno = 9

When it is enabled

[yura@localhost host-ws]$ LD_PRELOAD=./libeatmydata.so ./libeatmydata_fdatasync_issue
fdatasync(fd) returned 0, errno = 0
stewartsmith commented 7 years ago

Does https://github.com/stewartsmith/libeatmydata/tree/EBADF-fix fix it?

percona-ysorokin commented 7 years ago

Yes, I confirm. This patch fixes the problem.

stewartsmith commented 7 years ago

thanks! Pushed to master