Type:
Priority:
Resolution:
Cannot Reproduce
Affects Version/s:
10.0(EOL) , 10.1(EOL) , 10.2(EOL)
There are multiple failures in different tests in buildbot which seem to have the common cause. A test runs with InnoDB or XtraDB; at some point as a part of the test flow it sigkills the server; the server gets restarted; InnoDB recovery starts; it goes like this:
Version: '10.1.13-MariaDB-debug' socket: '/home/buildbot/maria-slave/power8-vlp01-bintar-debug/build/mysql-test/var/tmp/4/mysqld.1.sock' port: 16020 Source distribution
SIGKILL myself
2016-03-30 11:51:13 17590032101456 [Note] /home/buildbot/maria-slave/power8-vlp01-bintar-debug/build/sql/mysqld (mysqld 10.1.13-MariaDB-debug) starting as process 20770 ...
2016-03-30 11:51:13 17590032101456 [Warning] Could not increase number of max_open_files to more than 1024 (request: 4162)
2016-03-30 11:51:13 17590032101456 [Note] Plugin 'SEQUENCE' is disabled.
2016-03-30 11:51:14 17590032101456 [Note] InnoDB: Using mutexes to ref count buffer pool pages
2016-03-30 11:51:14 17590032101456 [Note] InnoDB: InnoDB: !!!!!!!! UNIV_DEBUG switched on !!!!!!!!!
2016-03-30 11:51:14 17590032101456 [Note] InnoDB: InnoDB: !!!!!!!! UNIV_SYNC_DEBUG switched on !!!!!!!!!
2016-03-30 11:51:14 17590032101456 [Note] InnoDB: The InnoDB memory heap is disabled
2016-03-30 11:51:14 17590032101456 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2016-03-30 11:51:14 17590032101456 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
2016-03-30 11:51:14 17590032101456 [Note] InnoDB: Compressed tables use zlib 1.2.6
2016-03-30 11:51:14 17590032101456 [Note] InnoDB: Using Linux native AIO
2016-03-30 11:51:14 17590032101456 [Note] InnoDB: Using generic crc32 instructions
2016-03-30 11:51:14 17590032101456 [Note] InnoDB: Initializing buffer pool, size = 32.0M
2016-03-30 11:51:14 17590032101456 [Note] InnoDB: Completed initialization of buffer pool
2016-03-30 11:51:14 17590032101456 [Note] InnoDB: Highest supported file format is Barracuda.
2016-03-30 11:51:14 17590032101456 [Note] InnoDB: Log scan progressed past the checkpoint lsn 2963393
2016-03-30 11:51:14 17590032101456 [Note] InnoDB: Database was not shutdown normally!
2016-03-30 11:51:14 17590032101456 [Note] InnoDB: Starting crash recovery.
2016-03-30 11:51:14 17590032101456 [Note] InnoDB: Reading tablespace information from the .ibd files...
2016-03-30 11:51:14 17590032101456 [Note] InnoDB: Restoring possible half-written data pages
2016-03-30 11:51:14 17590032101456 [Note] InnoDB: from the doublewrite buffer...
InnoDB: Doing recovery: scanned up to log sequence number 2977463
2016-03-30 11:51:14 17590032101456 [Note] InnoDB: Starting an apply batch of log records to the database...
InnoDB: Progress in percent: 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71 72 73 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98 99
InnoDB: Apply batch completed
and nothing further. The test waits until timeout is exceeded and reports
...
mysqltest: In included file "./include/wait_until_connected_again.inc":
included from ./include/rpl_reconnect.inc at line 93:
included from ./include/rpl_start_server.inc at line 57:
included from /home/buildbot/maria-slave/power8-vlp01-bintar-debug/build/mysql-test/suite/rpl/t/rpl_domain_id_filter_master_crash.test at line 70:
At line 26: Server failed to restart
Here is the cross-reference report which selects such failures (some of them might be of a different nature, but most of them are related): cross-reference report
Recent example:http://buildbot.askmonty.org/buildbot/builders/p8-rhel6-bintar-debug/builds/1436/steps/test/logs/mysqld.1.err.4 2016-03-30 11:51:13 17590032101456 , that's where the failed server startup begins)parts.partition_debug_innodb test running on 10.1 of March 30. If you scroll the log back from the failing point, you'll see that the test does recovery many times, and only one of them failed.
According to the cross-reference report, the test failures are currently only observed on p8-rhel6-bintar-debug.
Here is an example of a similar problem, but without recovery:http://buildbot.askmonty.org/buildbot/builders/p8-rhel6-bintar-debug/builds/1445/steps/test/logs/mysqld.2.err.1
CURRENT_TEST: rpl.rpl_unsafe_statements
2016-04-01 18:05:42 17590418370640 [Note] /home/buildbot/maria-slave/power8-vlp01-bintar-debug/build/sql/mysqld (mysqld 10.2.0-MariaDB-debug) starting as process 17484 ...
2016-04-01 18:05:42 17590418370640 [Warning] Could not increase number of max_open_files to more than 1024 (request: 4162)
2016-04-01 18:05:42 17590418370640 [Note] Plugin 'partition' is disabled.
2016-04-01 18:05:42 17590418370640 [Note] Plugin 'SEQUENCE' is disabled.
2016-04-01 18:05:42 17590418370640 [Note] InnoDB: Using mutexes to ref count buffer pool pages
2016-04-01 18:05:42 17590418370640 [Note] InnoDB: InnoDB: !!!!!!!! UNIV_DEBUG switched on !!!!!!!!!
2016-04-01 18:05:42 17590418370640 [Note] InnoDB: InnoDB: !!!!!!!! UNIV_SYNC_DEBUG switched on !!!!!!!!!
2016-04-01 18:05:42 17590418370640 [Note] InnoDB: The InnoDB memory heap is disabled
2016-04-01 18:05:42 17590418370640 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2016-04-01 18:05:42 17590418370640 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
2016-04-01 18:05:42 17590418370640 [Note] InnoDB: Compressed tables use zlib 1.2.6
2016-04-01 18:05:42 17590418370640 [Note] InnoDB: Using Linux native AIO
2016-04-01 18:05:42 17590418370640 [Note] InnoDB: Using generic crc32 instructions
2016-04-01 18:05:42 17590418370640 [Note] InnoDB: Initializing buffer pool, size = 8.0M
2016-04-01 18:05:42 17590418370640 [Note] InnoDB: Completed initialization of buffer pool
2016-04-01 18:05:42 17590418370640 [Note] InnoDB: Highest supported file format is Barracuda.
CURRENT_TEST: rpl.rpl_loaddata_s
2016-04-01 18:08:45 17590534631504 [Note] /home/buildbot/maria-slave/power8-vlp01-bintar-debug/build/sql/mysqld (mysqld 10.2.0-MariaDB-debug) starting as process 23021 ...
{"report":{"fcp":766,"ttfb":144.79999995231628,"pageVisibility":"visible","entityId":56318,"key":"jira.project.issue.view-issue","isInitial":true,"threshold":1000,"elementTimings":{},"userDeviceMemory":8,"userDeviceProcessors":64,"apdex":1,"journeyId":"88dbebe9-aaea-4824-9df7-b5b7e454c365","navigationType":0,"readyForUser":832.5999999046326,"redirectCount":0,"resourceLoadedEnd":511.2999999523163,"resourceLoadedStart":150.29999995231628,"resourceTiming":[{"duration":81.29999995231628,"initiatorType":"link","name":"https://jira.mariadb.org/s/2c21342762a6a02add1c328bed317ffd-CDN/lu2bu7/820016/12ta74/0a8bac35585be7fc6c9cc5a0464cd4cf/_/download/contextbatch/css/_super/batch.css","startTime":150.29999995231628,"connectEnd":0,"connectStart":0,"domainLookupEnd":0,"domainLookupStart":0,"fetchStart":150.29999995231628,"redirectEnd":0,"redirectStart":0,"requestStart":0,"responseEnd":231.59999990463257,"responseStart":0,"secureConnectionStart":0},{"duration":157.40000009536743,"initiatorType":"link","name":"https://jira.mariadb.org/s/7ebd35e77e471bc30ff0eba799ebc151-CDN/lu2bu7/820016/12ta74/8679b4946efa1a0bb029a3a22206fb5d/_/download/contextbatch/css/jira.browse.project,project.issue.navigator,jira.view.issue,jira.general,jira.global,atl.general,-_super/batch.css?agile_global_admin_condition=true&jag=true&jira.create.linked.issue=true&slack-enabled=true","startTime":150.59999990463257,"connectEnd":0,"connectStart":0,"domainLookupEnd":0,"domainLookupStart":0,"fetchStart":150.59999990463257,"redirectEnd":0,"redirectStart":0,"requestStart":0,"responseEnd":308,"responseStart":0,"secureConnectionStart":0},{"duration":167.20000004768372,"initiatorType":"script","name":"https://jira.mariadb.org/s/fbf975c0cce4b1abf04784eeae9ba1f4-CDN/lu2bu7/820016/12ta74/0a8bac35585be7fc6c9cc5a0464cd4cf/_/download/contextbatch/js/_super/batch.js?locale=en","startTime":150.69999980926514,"connectEnd":150.69999980926514,"connectStart":150.69999980926514,"domainLookupEnd":150.69999980926514,"domainLookupStart":150.69999980926514,"fetchStart":150.69999980926514,"redirectEnd":0,"redirectStart":0,"requestStart":150.69999980926514,"responseEnd":317.89999985694885,"responseStart":317.89999985694885,"secureConnectionStart":150.69999980926514},{"duration":237,"initiatorType":"script","name":"https://jira.mariadb.org/s/099b33461394b8015fc36c0a4b96e19f-CDN/lu2bu7/820016/12ta74/8679b4946efa1a0bb029a3a22206fb5d/_/download/contextbatch/js/jira.browse.project,project.issue.navigator,jira.view.issue,jira.general,jira.global,atl.general,-_super/batch.js?agile_global_admin_condition=true&jag=true&jira.create.linked.issue=true&locale=en&slack-enabled=true","startTime":150.79999995231628,"connectEnd":150.79999995231628,"connectStart":150.79999995231628,"domainLookupEnd":150.79999995231628,"domainLookupStart":150.79999995231628,"fetchStart":150.79999995231628,"redirectEnd":0,"redirectStart":0,"requestStart":150.79999995231628,"responseEnd":387.7999999523163,"responseStart":387.7999999523163,"secureConnectionStart":150.79999995231628},{"duration":240.5,"initiatorType":"script","name":"https://jira.mariadb.org/s/94c15bff32baef80f4096a08aceae8bc-CDN/lu2bu7/820016/12ta74/c92c0caa9a024ae85b0ebdbed7fb4bd7/_/download/contextbatch/js/atl.global,-_super/batch.js?locale=en","startTime":150.89999985694885,"connectEnd":150.89999985694885,"connectStart":150.89999985694885,"domainLookupEnd":150.89999985694885,"domainLookupStart":150.89999985694885,"fetchStart":150.89999985694885,"redirectEnd":0,"redirectStart":0,"requestStart":150.89999985694885,"responseEnd":391.39999985694885,"responseStart":391.39999985694885,"secureConnectionStart":150.89999985694885},{"duration":241.40000009536743,"initiatorType":"script","name":"https://jira.mariadb.org/s/d41d8cd98f00b204e9800998ecf8427e-CDN/lu2bu7/820016/12ta74/1.0/_/download/batch/jira.webresources:calendar-en/jira.webresources:calendar-en.js","startTime":150.89999985694885,"connectEnd":150.89999985694885,"connectStart":150.89999985694885,"domainLookupEnd":150.89999985694885,"domainLookupStart":150.89999985694885,"fetchStart":150.89999985694885,"redirectEnd":0,"redirectStart":0,"requestStart":150.89999985694885,"responseEnd":392.2999999523163,"responseStart":392.2999999523163,"secureConnectionStart":150.89999985694885},{"duration":241.59999990463257,"initiatorType":"script","name":"https://jira.mariadb.org/s/d41d8cd98f00b204e9800998ecf8427e-CDN/lu2bu7/820016/12ta74/1.0/_/download/batch/jira.webresources:calendar-localisation-moment/jira.webresources:calendar-localisation-moment.js","startTime":151.09999990463257,"connectEnd":151.09999990463257,"connectStart":151.09999990463257,"domainLookupEnd":151.09999990463257,"domainLookupStart":151.09999990463257,"fetchStart":151.09999990463257,"redirectEnd":0,"redirectStart":0,"requestStart":151.09999990463257,"responseEnd":392.69999980926514,"responseStart":392.69999980926514,"secureConnectionStart":151.09999990463257},{"duration":242.20000004768372,"initiatorType":"link","name":"https://jira.mariadb.org/s/b04b06a02d1959df322d9cded3aeecc1-CDN/lu2bu7/820016/12ta74/a2ff6aa845ffc9a1d22fe23d9ee791fc/_/download/contextbatch/css/jira.global.look-and-feel,-_super/batch.css","startTime":151.19999980926514,"connectEnd":0,"connectStart":0,"domainLookupEnd":0,"domainLookupStart":0,"fetchStart":151.19999980926514,"redirectEnd":0,"redirectStart":0,"requestStart":0,"responseEnd":393.39999985694885,"responseStart":0,"secureConnectionStart":0},{"duration":242.09999990463257,"initiatorType":"script","name":"https://jira.mariadb.org/rest/api/1.0/shortcuts/820016/47140b6e0a9bc2e4913da06536125810/shortcuts.js?context=issuenavigation&context=issueaction","startTime":151.29999995231628,"connectEnd":151.29999995231628,"connectStart":151.29999995231628,"domainLookupEnd":151.29999995231628,"domainLookupStart":151.29999995231628,"fetchStart":151.29999995231628,"redirectEnd":0,"redirectStart":0,"requestStart":151.29999995231628,"responseEnd":393.39999985694885,"responseStart":393.39999985694885,"secureConnectionStart":151.29999995231628},{"duration":242.79999995231628,"initiatorType":"link","name":"https://jira.mariadb.org/s/3ac36323ba5e4eb0af2aa7ac7211b4bb-CDN/lu2bu7/820016/12ta74/d176f0986478cc64f24226b3d20c140d/_/download/contextbatch/css/com.atlassian.jira.projects.sidebar.init,-_super,-project.issue.navigator,-jira.view.issue/batch.css?jira.create.linked.issue=true","startTime":151.39999985694885,"connectEnd":0,"connectStart":0,"domainLookupEnd":0,"domainLookupStart":0,"fetchStart":151.39999985694885,"redirectEnd":0,"redirectStart":0,"requestStart":0,"responseEnd":394.19999980926514,"responseStart":0,"secureConnectionStart":0},{"duration":242.79999995231628,"initiatorType":"script","name":"https://jira.mariadb.org/s/3339d87fa2538a859872f2df449bf8d0-CDN/lu2bu7/820016/12ta74/d176f0986478cc64f24226b3d20c140d/_/download/contextbatch/js/com.atlassian.jira.projects.sidebar.init,-_super,-project.issue.navigator,-jira.view.issue/batch.js?jira.create.linked.issue=true&locale=en","startTime":151.5,"connectEnd":151.5,"connectStart":151.5,"domainLookupEnd":151.5,"domainLookupStart":151.5,"fetchStart":151.5,"redirectEnd":0,"redirectStart":0,"requestStart":151.5,"responseEnd":394.2999999523163,"responseStart":394.2999999523163,"secureConnectionStart":151.5},{"duration":307.10000014305115,"initiatorType":"script","name":"https://jira.mariadb.org/s/d41d8cd98f00b204e9800998ecf8427e-CDN/lu2bu7/820016/12ta74/1.0/_/download/batch/jira.webresources:bigpipe-js/jira.webresources:bigpipe-js.js","startTime":157.39999985694885,"connectEnd":157.39999985694885,"connectStart":157.39999985694885,"domainLookupEnd":157.39999985694885,"domainLookupStart":157.39999985694885,"fetchStart":157.39999985694885,"redirectEnd":0,"redirectStart":0,"requestStart":157.39999985694885,"responseEnd":464.5,"responseStart":464.5,"secureConnectionStart":157.39999985694885},{"duration":353.7999999523163,"initiatorType":"script","name":"https://jira.mariadb.org/s/d41d8cd98f00b204e9800998ecf8427e-CDN/lu2bu7/820016/12ta74/1.0/_/download/batch/jira.webresources:bigpipe-init/jira.webresources:bigpipe-init.js","startTime":157.5,"connectEnd":157.5,"connectStart":157.5,"domainLookupEnd":157.5,"domainLookupStart":157.5,"fetchStart":157.5,"redirectEnd":0,"redirectStart":0,"requestStart":157.5,"responseEnd":511.2999999523163,"responseStart":511.2999999523163,"secureConnectionStart":157.5},{"duration":385.89999985694885,"initiatorType":"xmlhttprequest","name":"https://jira.mariadb.org/rest/webResources/1.0/resources","startTime":542.2999999523163,"connectEnd":542.2999999523163,"connectStart":542.2999999523163,"domainLookupEnd":542.2999999523163,"domainLookupStart":542.2999999523163,"fetchStart":542.2999999523163,"redirectEnd":0,"redirectStart":0,"requestStart":542.2999999523163,"responseEnd":928.1999998092651,"responseStart":928.1999998092651,"secureConnectionStart":542.2999999523163}],"fetchStart":0,"domainLookupStart":0,"domainLookupEnd":0,"connectStart":0,"connectEnd":0,"requestStart":9,"responseStart":145,"responseEnd":156,"domLoading":148,"domInteractive":892,"domContentLoadedEventStart":892,"domContentLoadedEventEnd":934,"domComplete":1765,"loadEventStart":1765,"loadEventEnd":1767,"userAgent":"Mozilla/5.0 AppleWebKit/537.36 (KHTML, like Gecko; compatible; ClaudeBot/1.0; +claudebot@anthropic.com)","marks":[{"name":"bigPipe.sidebar-id.start","time":874},{"name":"bigPipe.sidebar-id.end","time":874.5999999046326},{"name":"bigPipe.activity-panel-pipe-id.start","time":874.7999999523163},{"name":"bigPipe.activity-panel-pipe-id.end","time":877.1999998092651},{"name":"activityTabFullyLoaded","time":944.2999999523163}],"measures":[],"correlationId":"9aa693c2ba2e18","effectiveType":"4g","downlink":9.2,"rtt":0,"serverDuration":78,"dbReadsTimeInMs":16,"dbConnsTimeInMs":24,"applicationHash":"9d11dbea5f4be3d4cc21f03a88dd11d8c8687422","experiments":[]}}
Bug
Major
MDEV-7069 Fix buildbot failures in main server trees