Uploaded image for project: 'MariaDB Server'
  1. MariaDB Server
  2. MDEV-9749

InnoDB receives 'Bad file descriptor' error, possibly related to feedback plugin

    Details

      Description

      A user is seeing MariaDB Galera Cluster constantly abort due to 'Bad file descriptor' errors received by InnoDB. 100% of these failures look like the following:

      1. The node writes non-sensical feedback plugin error messages to the log every two minutes.
      2. The node writes some gcache.page files.
      3. The node writes another feedback plugin error message to the log that says the following: error:140770FC:SSL routines:SSL23_GET_SERVER_HELLO:unknown protocol
      4. Then InnoDB reports a 'Bad file descriptor' error.
      5. mysqld on the node then aborts.

      This has happened on different nodes in the same cluster at different times.

      This never happened when the user was running MariaDB Galera Cluster 10.0.21. It only started happening after the user upgraded to 10.0.22.

      Here are some examples:

      160225 23:14:08 [ERROR] feedback plugin: ssl failed for url 'https://mariadb.org/feedback_plugin/post' error:00000000:lib(0):func(0):reason(0)
      160225 23:16:11 [ERROR] feedback plugin: ssl failed for url 'https://mariadb.org/feedback_plugin/post' error:00000000:lib(0):func(0):reason(0)
      160225 23:18:14 [ERROR] feedback plugin: ssl failed for url 'https://mariadb.org/feedback_plugin/post' error:00000000:lib(0):func(0):reason(0)
      160225 23:20:17 [ERROR] feedback plugin: ssl failed for url 'https://mariadb.org/feedback_plugin/post' error:00000000:lib(0):func(0):reason(0)
      160225 23:22:12 [Note] WSREP: Created page /var/lib/mysql/data/gcache.page.000025 of size 157236726 bytes
      160225 23:22:14 [Note] WSREP: Deleted page /var/lib/mysql/data/gcache.page.000025
      160225 23:22:20 [ERROR] feedback plugin: ssl failed for url 'https://mariadb.org/feedback_plugin/post' error:140770FC:SSL routines:SSL23_GET_SERVER_HELLO:unknown protocol
      2016-02-25 23:22:20 7f3ea0fb4700 InnoDB: Error: Write to file ./testdb/tab1.ibd failed at offset 180224.
      InnoDB: 32768 bytes should have been written, only 0 were written.
      InnoDB: Operating system error number 9.
      InnoDB: Check that your OS and file system support files of this size.
      InnoDB: Check also that the disk is not full or a disk quota exceeded.
      InnoDB: Error number 9 means 'Bad file descriptor'.
      InnoDB: Some operating system error numbers are described at
      InnoDB: http://dev.mysql.com/doc/refman/5.6/en/operating-system-error-codes.html
      2016-02-25 23:22:20 7f3ea0fb4700  InnoDB: Operating system error number 9 in a file operation.
      InnoDB: Error number 9 means 'Bad file descriptor'.
      InnoDB: Some operating system error numbers are described at
      InnoDB: http://dev.mysql.com/doc/refman/5.6/en/operating-system-error-codes.html
      160225 23:22:20 [ERROR] InnoDB: File ./testdb/tab1.ibd: 'os_file_write_func' returned OS error 109. Cannot continue operation
      160225 23:22:20 mysqld_safe Number of processes running now: 0
      160225 23:22:20 mysqld_safe WSREP: not restarting wsrep node automatically
      160225 23:22:20 mysqld_safe mysqld from pid file /var/lib/mysql/org.local.pid ended
      

      160302  2:30:40 [ERROR] feedback plugin: ssl failed for url 'https://mariadb.org/feedback_plugin/post' error:00000000:lib(0):func(0):reason(0)
      160302  2:32:43 [ERROR] feedback plugin: ssl failed for url 'https://mariadb.org/feedback_plugin/post' error:00000000:lib(0):func(0):reason(0)
      160302  2:34:46 [ERROR] feedback plugin: ssl failed for url 'https://mariadb.org/feedback_plugin/post' error:00000000:lib(0):func(0):reason(0)
      160302  2:36:49 [ERROR] feedback plugin: ssl failed for url 'https://mariadb.org/feedback_plugin/post' error:00000000:lib(0):func(0):reason(0)
      160302  2:38:00 [Note] WSREP: Created page /var/lib/mysql/data/gcache.page.000058 of size 157334503 bytes
      160302  2:38:03 [Note] WSREP: Deleted page /var/lib/mysql/data/gcache.page.000058
      160302  2:38:36 [Note] WSREP: Created page /var/lib/mysql/data/gcache.page.000059 of size 247299600 bytes
      160302  2:38:39 [Note] WSREP: Deleted page /var/lib/mysql/data/gcache.page.000059
      160302  2:38:52 [ERROR] feedback plugin: ssl failed for url 'https://mariadb.org/feedback_plugin/post' error:140770FC:SSL routines:SSL23_GET_SERVER_HELLO:unknown protocol
      2016-03-02 02:38:52 7fcda2db7700 InnoDB: Error: Write to file ./testdb/tab2.ibd failed at offset 180224.
      InnoDB: 32768 bytes should have been written, only 0 were written.
      InnoDB: Operating system error number 9.
      InnoDB: Check that your OS and file system support files of this size.
      InnoDB: Check also that the disk is not full or a disk quota exceeded.
      InnoDB: Error number 9 means 'Bad file descriptor'.
      InnoDB: Some operating system error numbers are described at
      InnoDB: http://dev.mysql.com/doc/refman/5.6/en/operating-system-error-codes.html
      2016-03-02 02:38:52 7fcda2db7700  InnoDB: Operating system error number 9 in a file operation.
      InnoDB: Error number 9 means 'Bad file descriptor'.
      InnoDB: Some operating system error numbers are described at
      InnoDB: http://dev.mysql.com/doc/refman/5.6/en/operating-system-error-codes.html
      160302  2:38:52 [ERROR] InnoDB: File ./testdb/tab2.ibd: 'os_file_write_func' returned OS error 109. Cannot continue operation
      160302 02:38:52 mysqld_safe Number of processes running now: 0
      160302 02:38:52 mysqld_safe WSREP: not restarting wsrep node automatically
      160302 02:38:52 mysqld_safe mysqld from pid file /var/lib/mysql/org.local.pid ended
      

      160316  1:33:27 [ERROR] feedback plugin: ssl failed for url 'https://mariadb.org/feedback_plugin/post' error:00000000:lib(0):func(0):reason(0)
      160316  1:35:30 [ERROR] feedback plugin: ssl failed for url 'https://mariadb.org/feedback_plugin/post' error:00000000:lib(0):func(0):reason(0)
      160316  1:37:33 [ERROR] feedback plugin: ssl failed for url 'https://mariadb.org/feedback_plugin/post' error:00000000:lib(0):func(0):reason(0)
      160316  1:39:36 [ERROR] feedback plugin: ssl failed for url 'https://mariadb.org/feedback_plugin/post' error:00000000:lib(0):func(0):reason(0)
      160316  1:40:20 [Note] WSREP: Created page /var/lib/mysql/data/gcache.page.000034 of size 157462628 bytes
      160316  1:40:23 [Note] WSREP: Deleted page /var/lib/mysql/data/gcache.page.000034
      160316  1:41:07 [Note] WSREP: Created page /var/lib/mysql/data/gcache.page.000035 of size 249125066 bytes
      160316  1:41:11 [Note] WSREP: Deleted page /var/lib/mysql/data/gcache.page.000035
      160316  1:41:39 [ERROR] feedback plugin: ssl failed for url 'https://mariadb.org/feedback_plugin/post' error:140770FC:SSL routines:SSL23_GET_SERVER_HELLO:unknown protocol
      2016-03-16 01:41:40 7f26babb4700 InnoDB: Error: Write to file ./testdb/tab3.ibd failed at offset 196608.
      InnoDB: 32768 bytes should have been written, only 0 were written.
      InnoDB: Operating system error number 9.
      InnoDB: Check that your OS and file system support files of this size.
      InnoDB: Check also that the disk is not full or a disk quota exceeded.
      InnoDB: Error number 9 means 'Bad file descriptor'.
      InnoDB: Some operating system error numbers are described at
      InnoDB: http://dev.mysql.com/doc/refman/5.6/en/operating-system-error-codes.html
      2016-03-16 01:41:40 7f26babb4700  InnoDB: Operating system error number 9 in a file operation.
      InnoDB: Error number 9 means 'Bad file descriptor'.
      InnoDB: Some operating system error numbers are described at
      InnoDB: http://dev.mysql.com/doc/refman/5.6/en/operating-system-error-codes.html
      160316  1:41:40 [ERROR] InnoDB: File ./testdb/tab3.ibd: 'os_file_write_func' returned OS error 109. Cannot continue operation
      160316 01:41:40 mysqld_safe Number of processes running now: 0
      160316 01:41:40 mysqld_safe WSREP: not restarting wsrep node automatically
      160316 01:41:40 mysqld_safe mysqld from pid file /var/lib/mysql/org.local.pid ended
      

      160225 23:14:08 [ERROR] feedback plugin: ssl failed for url 'https://mariadb.org/feedback_plugin/post' error:00000000:lib(0):func(0):reason(0)
      160225 23:16:11 [ERROR] feedback plugin: ssl failed for url 'https://mariadb.org/feedback_plugin/post' error:00000000:lib(0):func(0):reason(0)
      160225 23:18:14 [ERROR] feedback plugin: ssl failed for url 'https://mariadb.org/feedback_plugin/post' error:00000000:lib(0):func(0):reason(0)
      160225 23:20:17 [ERROR] feedback plugin: ssl failed for url 'https://mariadb.org/feedback_plugin/post' error:00000000:lib(0):func(0):reason(0)
      160225 23:22:12 [Note] WSREP: Created page /var/lib/mysql/data/gcache.page.000025 of size 157236726 bytes
      160225 23:22:14 [Note] WSREP: Deleted page /var/lib/mysql/data/gcache.page.000025
      160225 23:22:20 [ERROR] feedback plugin: ssl failed for url 'https://mariadb.org/feedback_plugin/post' error:140770FC:SSL routines:SSL23_GET_SERVER_HELLO:unknown protocol
      2016-02-25 23:22:20 7f3ea0fb4700 InnoDB: Error: Write to file ./testdb/tab1.ibd failed at offset 180224.
      InnoDB: 32768 bytes should have been written, only 0 were written.
      InnoDB: Operating system error number 9.
      InnoDB: Check that your OS and file system support files of this size.
      InnoDB: Check also that the disk is not full or a disk quota exceeded.
      InnoDB: Error number 9 means 'Bad file descriptor'.
      InnoDB: Some operating system error numbers are described at
      InnoDB: http://dev.mysql.com/doc/refman/5.6/en/operating-system-error-codes.html
      2016-02-25 23:22:20 7f3ea0fb4700  InnoDB: Operating system error number 9 in a file operation.
      InnoDB: Error number 9 means 'Bad file descriptor'.
      InnoDB: Some operating system error numbers are described at
      InnoDB: http://dev.mysql.com/doc/refman/5.6/en/operating-system-error-codes.html
      160225 23:22:20 [ERROR] InnoDB: File ./testdb/tab1.ibd: 'os_file_write_func' returned OS error 109. Cannot continue operation
      160225 23:22:20 mysqld_safe Number of processes running now: 0
      160225 23:22:20 mysqld_safe WSREP: not restarting wsrep node automatically
      160225 23:22:20 mysqld_safe mysqld from pid file /var/lib/mysql/org.local.pid ended
      

        Attachments

          Issue Links

            Activity

              People

              • Assignee:
                serg Sergei Golubchik
                Reporter:
                GeoffMontee Geoff Montee
              • Votes:
                0 Vote for this issue
                Watchers:
                4 Start watching this issue

                Dates

                • Created:
                  Updated:
                  Resolved: