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

rpl.rpl_semi_sync_event 'innodb_plugin,row' sporadically produces warnings in buildbot on P8

    Details

    • Type: Bug
    • Status: Closed (View Workflow)
    • Priority: Minor
    • Resolution: Cannot Reproduce
    • Affects Version/s: 5.5
    • Fix Version/s: N/A
    • Component/s: Tests
    • Labels:

      Description

      http://buildbot.askmonty.org/buildbot/builders/p8-rhel71-bintar-debug/builds/230/steps/test/logs/stdio

      rpl.rpl_semi_sync_event 'innodb_plugin,row' w2 [ pass ]  25556
      worker[2] > Restart [mysqld.1 - pid: 12005, winpid: 12005] - running with different options '--binlog-format=row --ignore-builtin-innodb --plugin-load=ha_innodb.so --innodb --innodb-cmpmem --innodb-trx --innodb-buffer-pool-stats --innodb-buffer-page --innodb-buffer-page-lru --log-bin=master-bin' != '--binlog-format=row --ignore-builtin-innodb --plugin-load=ha_innodb.so --innodb --innodb-cmpmem --innodb-trx --innodb-buffer-pool-stats --innodb-buffer-page --innodb-buffer-page-lru --log-bin=master-bin --max-connections=40'
      worker[2] > Restart [mysqld.2 - pid: 12012, winpid: 12012] - running with different options '--binlog-format=row --ignore-builtin-innodb --plugin-load=ha_innodb.so --innodb --innodb-cmpmem --innodb-trx --innodb-buffer-pool-stats --innodb-buffer-page --innodb-buffer-page-lru --log-bin=slave-bin --loose-innodb-lock-wait-timeout=4 --slave-transaction-retries=2 --max-relay-log-size=4096' != '--binlog-format=row --ignore-builtin-innodb --plugin-load=ha_innodb.so --innodb --innodb-cmpmem --innodb-trx --innodb-buffer-pool-stats --innodb-buffer-page --innodb-buffer-page-lru --log-bin=slave-bin'
      ***Warnings generated in error logs during shutdown after running tests: rpl.rpl_semi_sync_event
       
      Warning:  520 bytes lost, allocated at sql/rpl_handler.cc:266, sql/log.cc:6053, sql/log.cc:5893, sql/log.cc:5856, sql/log.cc:1661, sql/log.cc:1741, sql/log.cc:7470, sql/handler.cc:1322

      Error log

      CURRENT_TEST: rpl.rpl_semi_sync_event
      150416  6:42:49 [Note] Plugin 'XTRADB_ADMIN_COMMAND' is disabled.
      150416  6:42:49 [Note] Plugin 'partition' is disabled.
      150416  6:42:49 InnoDB: !!!!!!!! UNIV_DEBUG switched on !!!!!!!!!
      150416  6:42:49 InnoDB: The InnoDB memory heap is disabled
      150416  6:42:49 InnoDB: Mutexes and rw_locks use GCC atomic builtins
      150416  6:42:49 InnoDB: Compressed tables use zlib 1.2.8
      150416  6:42:49 InnoDB: Using Linux native AIO
      150416  6:42:49 InnoDB: Initializing buffer pool, size = 8.0M
      150416  6:42:49 InnoDB: Completed initialization of buffer pool
      InnoDB: The first specified data file ./ibdata1 did not exist:
      InnoDB: a new database to be created!
      150416  6:42:49  InnoDB: Setting file ./ibdata1 size to 10 MB
      InnoDB: Database physically writes the file full: wait...
      150416  6:42:51  InnoDB: Log file ./ib_logfile0 did not exist: new to be created
      InnoDB: Setting log file ./ib_logfile0 size to 5 MB
      InnoDB: Database physically writes the file full: wait...
      150416  6:42:53  InnoDB: Log file ./ib_logfile1 did not exist: new to be created
      InnoDB: Setting log file ./ib_logfile1 size to 5 MB
      InnoDB: Database physically writes the file full: wait...
      InnoDB: Doublewrite buffer not found: creating new
      InnoDB: Doublewrite buffer created
      InnoDB: 127 rollback segment(s) active.
      InnoDB: Creating foreign key constraint system tables
      InnoDB: Foreign key constraint system tables created
      150416  6:43:10  InnoDB: Waiting for the background threads to start
      150416  6:43:11 InnoDB: 5.5.42-MariaDB started; log sequence number 0
      150416  6:43:11 [Note] Plugin 'INNODB_LOCK_WAITS' is disabled.
      150416  6:43:11 [Note] Plugin 'INNODB_CMP' is disabled.
      150416  6:43:11 [Note] Plugin 'INNODB_CMP_RESET' is disabled.
      150416  6:43:11 [Note] Plugin 'INNODB_CMPMEM_RESET' is disabled.
      150416  6:43:11 [Warning] /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/sql/mysqld: unknown variable 'loose-feedback-user-info=mysql-test'
      150416  6:43:11 [Warning] /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/sql/mysqld: unknown option '--loose-skip-innodb-buffer-pool-pages'
      150416  6:43:11 [Warning] /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/sql/mysqld: unknown option '--loose-skip-innodb-buffer-pool-pages-blob'
      150416  6:43:11 [Warning] /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/sql/mysqld: unknown option '--loose-skip-innodb-buffer-pool-pages-index'
      150416  6:43:11 [Warning] /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/sql/mysqld: unknown option '--loose-skip-innodb-changed-pages'
      150416  6:43:11 [Warning] /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/sql/mysqld: unknown option '--loose-skip-innodb-index-stats'
      150416  6:43:11 [Warning] /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/sql/mysqld: unknown option '--loose-skip-innodb-rseg'
      150416  6:43:11 [Warning] /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/sql/mysqld: unknown option '--loose-skip-innodb-sys-columns'
      150416  6:43:11 [Warning] /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/sql/mysqld: unknown option '--loose-skip-innodb-sys-fields'
      150416  6:43:11 [Warning] /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/sql/mysqld: unknown option '--loose-skip-innodb-sys-foreign'
      150416  6:43:11 [Warning] /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/sql/mysqld: unknown option '--loose-skip-innodb-sys-foreign-cols'
      150416  6:43:11 [Warning] /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/sql/mysqld: unknown option '--loose-skip-innodb-sys-indexes'
      150416  6:43:11 [Warning] /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/sql/mysqld: unknown option '--loose-skip-innodb-sys-stats'
      150416  6:43:11 [Warning] /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/sql/mysqld: unknown option '--loose-skip-innodb-sys-tables'
      150416  6:43:11 [Warning] /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/sql/mysqld: unknown option '--loose-skip-innodb-sys-tablestats'
      150416  6:43:11 [Warning] /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/sql/mysqld: unknown option '--loose-skip-innodb-table-stats'
      150416  6:43:11 [Warning] /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/sql/mysqld: unknown option '--loose-skip-innodb-undo-logs'
      150416  6:43:11 [Note] Server socket created on IP: '0.0.0.0'.
      150416  6:43:11 [Note] Event Scheduler: Loaded 0 events
      150416  6:43:11 [Note] /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/sql/mysqld: ready for connections.
      Version: '5.5.42-MariaDB-debug-log'  socket: '/home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/mysql-test/var/tmp/2/mysqld.1.sock'  port: 16040  Source distribution
      150416  6:43:14 [Note] Semi-sync replication initialized for transactions.
      150416  6:43:14 [Note] Semi-sync replication enabled on the master.
      150416  6:43:15 [Note] Start semi-sync binlog_dump to slave (server_id: 2), pos(master-bin.000001, 1333)
      150416  6:43:15 [Note] Stop asynchronous binlog_dump to slave (server_id: 2)
      150416  6:43:15 [Note] Event Scheduler: scheduler thread started with id 9
      150416  6:43:15 [ERROR] Read semi-sync reply network error:  (errno: 1158)
      150416  6:43:15 [Note] Stop semi-sync binlog_dump to slave (server_id: 2)
      150416  6:43:16 [Note] Event Scheduler: Killing the scheduler thread, thread id 9
      150416  6:43:16 [Note] Event Scheduler: Waiting for the scheduler thread to reply
      150416  6:43:16 [Note] Event Scheduler: Stopped
      150416  6:43:25 [Warning] Timeout waiting for reply of binlog (file: master-bin.000001, pos: 2770), semi-sync up to file master-bin.000001, position 2583.
      150416  6:43:25 [Note] Semi-sync replication switched OFF.
      150416  6:43:25 [Note] unregister_replicator OK
      150416  6:43:40 [Note] /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/sql/mysqld: Normal shutdown
       
      150416  6:43:40 [Note] Event Scheduler: Purging the queue. 0 events
      150416  6:43:40  InnoDB: Starting shutdown...
      150416  6:43:43  InnoDB: Shutdown completed; log sequence number 1632968
      150416  6:43:43 [Note] Debug sync points hit:                   4073
      150416  6:43:43 [Note] Debug sync points executed:              0
      150416  6:43:43 [Note] Debug sync points max active per thread: 0
      150416  6:43:43 [Note] /home/buildbot/maria-slave/power8-vlp06-bintar-debug/build/sql/mysqld: Shutdown complete
       
      Warning:  520 bytes lost, allocated at sql/rpl_handler.cc:266, sql/log.cc:6053, sql/log.cc:5893, sql/log.cc:5856, sql/log.cc:1661, sql/log.cc:1741, sql/log.cc:7470, sql/handler.cc:1322
      Memory lost: 520 bytes in 1 chunks

      It's hard to say how often it happens, because it's not recorded as a failure in buildbot.

        Attachments

          Issue Links

            Activity

              People

              • Assignee:
                jplindst Jan Lindström
                Reporter:
                elenst Elena Stepanova
              • Votes:
                0 Vote for this issue
                Watchers:
                2 Start watching this issue

                Dates

                • Created:
                  Updated:
                  Resolved: