View Issue Details

IDProjectCategoryView StatusLast Update
0001214bareos-core[All Projects] directorpublic2020-03-26 11:01
ReporterhostedpowerAssigned Toarogge 
PrioritynormalSeveritymajorReproducibilityalways
Status feedbackResolutionopen 
Product Version19.2.6 
Fixed in Version 
Summary0001214: Bareos hanging/failing (on heavy databases?)
DescriptionWe experience a lot of backups failing sooner or later with Could not reserve volume vol-cons-2368 on "customerx1-incr" (/home/customerx1/bareos)

There is not any reason this should fail since there is ample space on this volume. Moreover we see this happen really often with lotsa backups (but not all the time and not all backups).

We think it has to do with locks in MySQL. Probably the allocation for a new volume takes too long while it's waiting for an answer from MySQL, which makes it timeout internally and leads to this failure.

It's very very unfortunate issue and in fact really making the solution unreliable :(
Additional InformationYou can see the Creating sort index it blocks all other queries:

mysql> show full processlist;
+---------+--------+-----------+--------+---------+------+---------------------------------+----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+-----------+---------------+
| Id | User | Host | db | Command | Time | State | Info | Rows_sent | Rows_examined |
+---------+--------+-----------+--------+---------+------+---------------------------------+----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+-----------+---------------+
| 569514 | bareos | localhost | bareos | Sleep | 2 | | NULL | 0 | 0 |
| 1231194 | bareos | localhost | bareos | Sleep | 2321 | | NULL | 0 | 0 |
| 1231945 | bareos | localhost | bareos | Sleep | 588 | | NULL | 0 | 0 |
| 1232038 | bareos | localhost | bareos | Query | 87 | Waiting for table metadata lock | LOCK TABLES Path write, batch write, Path as p write | 0 | 0 |
| 1232110 | bareos | localhost | bareos | Query | 109 | Creating sort index | SELECT Path.Path, T1.Name, T1.FileIndex, T1.JobId, LStat, DeltaSeq , Fhinfo, Fhnode FROM ( SELECT FileId, Job.JobId AS JobId, FileIndex, File.PathId AS PathId, File.Name AS Name, LStat , DeltaSeq, Fhinfo, Fhnode, Job.JobTDate AS JobTDate FROM Job, File, (SELECT MAX(JobTDate) AS JobTDate, PathId, FileName FROM (SELECT JobTDate, PathId, File.Name AS FileName FROM File JOIN Job USING (JobId) WHERE File.JobId IN (7768,8346,3010,3176,3341,3506,3674,3976,4280,4584,4889,5194,5499,5805,6111,6418,6723,7030,7337,7647,7956,8227,8504) UNION ALL SELECT JobTDate, PathId, File.Name AS FileName FROM BaseFiles JOIN File USING (FileId) JOIN Job ON (BaseJobId = Job.JobId) WHERE BaseFiles.JobId IN (7768,8346,3010,3176,3341,3506,3674,3976,4280,4584,4889,5194,5499,5805,6111,6418,6723,7030,7337,7647,7956,8227,8504) ) AS tmp GROUP BY PathId, FileName) AS T1 WHERE (Job.JobId IN (SELECT DISTINCT BaseJobId FROM BaseFiles WHERE JobId IN (7768,8346,3010,3176,3341,3506,3674,3976,4280,4584,4889,5194,5499,5805,6111,6418,6723,7030,7337,7647,7956,8227,8504)) OR Job.JobId IN (7768,8346,3010,3176,3341,3506,3674,3976,4280,4584,4889,5194,5499,5805,6111,6418,6723,7030,7337,7647,7956,8227,8504)) AND T1.JobTDate = Job.JobTDate AND Job.JobId = File.JobId AND T1.PathId = File.PathId AND T1.FileName = File.Name ) AS T1 JOIN Path ON (Path.PathId = T1.PathId) WHERE FileIndex > 0 ORDER BY T1.JobTDate, FileIndex ASC | 148990 | 18940336 |
| 1232130 | bareos | localhost | bareos | Query | 2 | Waiting for table metadata lock | LOCK TABLES Path write, batch write, Path as p write | 0 | 0 |
| 1232133 | bareos | localhost | bareos | Query | 86 | Waiting for table metadata lock | SELECT Path.Path, T1.Name, T1.FileIndex, T1.JobId, LStat, DeltaSeq , Fhinfo, Fhnode FROM ( SELECT FileId, Job.JobId AS JobId, FileIndex, File.PathId AS PathId, File.Name AS Name, LStat , DeltaSeq, Fhinfo, Fhnode, Job.JobTDate AS JobTDate FROM Job, File, (SELECT MAX(JobTDate) AS JobTDate, PathId, FileName FROM (SELECT JobTDate, PathId, File.Name AS FileName FROM File JOIN Job USING (JobId) WHERE File.JobId IN (8412,3054,3220,3385,3550,3718,4020,4324,4628,4933,5238,5543,5849,6155,6462,6767,7074,7381,7691,8000,8271,8548) UNION ALL SELECT JobTDate, PathId, File.Name AS FileName FROM BaseFiles JOIN File USING (FileId) JOIN Job ON (BaseJobId = Job.JobId) WHERE BaseFiles.JobId IN (8412,3054,3220,3385,3550,3718,4020,4324,4628,4933,5238,5543,5849,6155,6462,6767,7074,7381,7691,8000,8271,8548) ) AS tmp GROUP BY PathId, FileName) AS T1 WHERE (Job.JobId IN (SELECT DISTINCT BaseJobId FROM BaseFiles WHERE JobId IN (8412,3054,3220,3385,3550,3718,4020,4324,4628,4933,5238,5543,5849,6155,6462,6767,7074,7381,7691,8000,8271,8548)) OR Job.JobId IN (8412,3054,3220,3385,3550,3718,4020,4324,4628,4933,5238,5543,5849,6155,6462,6767,7074,7381,7691,8000,8271,8548)) AND T1.JobTDate = Job.JobTDate AND Job.JobId = File.JobId AND T1.PathId = File.PathId AND T1.FileName = File.Name ) AS T1 JOIN Path ON (Path.PathId = T1.PathId) WHERE FileIndex > 0 ORDER BY T1.JobTDate, FileIndex ASC | 0 | 0 |
| 1232145 | bareos | localhost | bareos | Query | 56 | Waiting for table metadata lock | SELECT Path.Path, T1.Name, T1.FileIndex, T1.JobId, LStat, DeltaSeq , Fhinfo, Fhnode FROM ( SELECT FileId, Job.JobId AS JobId, FileIndex, File.PathId AS PathId, File.Name AS Name, LStat , DeltaSeq, Fhinfo, Fhnode, Job.JobTDate AS JobTDate FROM Job, File, (SELECT MAX(JobTDate) AS JobTDate, PathId, FileName FROM (SELECT JobTDate, PathId, File.Name AS FileName FROM File JOIN Job USING (JobId) WHERE File.JobId IN (105,8431,3070,3236,3401,3566,3734,4036,4340,4644,4949,5254,5559,5865,6171,6478,6783,7090,7397,7707,8016,8287,8564) UNION ALL SELECT JobTDate, PathId, File.Name AS FileName FROM BaseFiles JOIN File USING (FileId) JOIN Job ON (BaseJobId = Job.JobId) WHERE BaseFiles.JobId IN (105,8431,3070,3236,3401,3566,3734,4036,4340,4644,4949,5254,5559,5865,6171,6478,6783,7090,7397,7707,8016,8287,8564) ) AS tmp GROUP BY PathId, FileName) AS T1 WHERE (Job.JobId IN (SELECT DISTINCT BaseJobId FROM BaseFiles WHERE JobId IN (105,8431,3070,3236,3401,3566,3734,4036,4340,4644,4949,5254,5559,5865,6171,6478,6783,7090,7397,7707,8016,8287,8564)) OR Job.JobId IN (105,8431,3070,3236,3401,3566,3734,4036,4340,4644,4949,5254,5559,5865,6171,6478,6783,7090,7397,7707,8016,8287,8564)) AND T1.JobTDate = Job.JobTDate AND Job.JobId = File.JobId AND T1.PathId = File.PathId AND T1.FileName = File.Name ) AS T1 JOIN Path ON (Path.PathId = T1.PathId) WHERE FileIndex > 0 ORDER BY T1.JobTDate, FileIndex ASC | 0 | 0 |
| 1232147 | bareos | localhost | bareos | Query | 51 | Waiting for table metadata lock | SELECT Path.Path, T1.Name, T1.FileIndex, T1.JobId, LStat, DeltaSeq , Fhinfo, Fhnode FROM ( SELECT FileId, Job.JobId AS JobId, FileIndex, File.PathId AS PathId, File.Name AS Name, LStat , File.DeltaSeq AS DeltaSeq, File.Fhinfo AS Fhinfo, File.Fhnode AS Fhnode, Job.JobTDate AS JobTDate FROM Job, File, ( SELECT MAX(JobTDate) AS JobTDate, PathId, FileName, DeltaSeq, Fhinfo, Fhnode FROM ( SELECT JobTDate, PathId, File.Name AS FileName, DeltaSeq, Fhinfo, Fhnode FROM File JOIN Job USING (JobId) WHERE File.JobId IN (2880,3044,3210) UNION ALL SELECT JobTDate, PathId, File.Name AS FileName, DeltaSeq, Fhinfo, Fhnode FROM BaseFiles JOIN File USING (FileId) JOIN Job ON (BaseJobId = Job.JobId) WHERE BaseFiles.JobId IN (2880,3044,3210) ) AS tmp GROUP BY PathId, FileName, DeltaSeq, Fhinfo, Fhnode) AS T1 WHERE (Job.JobId IN (SELECT DISTINCT BaseJobId FROM BaseFiles WHERE JobId IN (2880,3044,3210)) OR Job.JobId IN (2880,3044,3210)) AND T1.JobTDate = Job.JobTDate AND Job.JobId = File.JobId AND T1.PathId = File.PathId AND T1.FileName = File.Name ) AS T1 JOIN Path ON (Path.PathId = T1.PathId) WHERE FileIndex > 0 ORDER BY T1.JobTDate, FileIndex ASC | 0 | 0 |
| 1232180 | root | localhost | NULL | Query | 0 | starting | show full processlist | 0 | 0 |
+---------+--------+-----------+--------+---------+------+---------------------------------+----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+-----------+---------------+
10 rows in set (0.00 sec)


+---------+--------+-----------+--------+---------+------+---------------------------------+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+-----------+---------------+
| 569514 | bareos | localhost | bareos | Sleep | 5 | | NULL | 0 | 1 |
| 1231194 | bareos | localhost | bareos | Sleep | 3165 | | NULL | 0 | 0 |
| 1231945 | bareos | localhost | bareos | Sleep | 531 | | NULL | 0 | 0 |
| 1232133 | bareos | localhost | bareos | Query | 192 | Waiting for table metadata lock | LOCK TABLES Path write, batch write, Path as p write | 0 | 0 |
| 1232202 | bareos | localhost | bareos | Query | 542 | Waiting for table metadata lock | LOCK TABLES Path write, batch write, Path as p write | 0 | 0 |
| 1232276 | bareos | localhost | bareos | Sleep | 2 | | NULL | 0 | 0 |
| 1232305 | bareos | localhost | bareos | Query | 567 | Creating sort index | SELECT Path.Path, T1.Name, T1.FileIndex, T1.JobId, LStat, DeltaSeq , Fhinfo, Fhnode FROM ( SELECT FileId, Job.JobId AS JobId, FileIndex, File.PathId AS PathId, File.Name AS Name, LStat , File.DeltaSeq AS DeltaSeq, File.Fhinfo AS Fhinfo, File.Fhnode AS Fhnode, Job.JobTDate AS JobTDate FROM Job, File, ( SELECT MAX(JobTDate) AS JobTDate, PathId, FileName, DeltaSeq, Fhinfo, Fhnode FROM ( SELECT JobTDate, PathId, File.Name AS FileName, DeltaSeq, Fhinfo, Fhnode FROM File JOIN Job USING (JobId) WHERE File.JobId IN (54,8436,3020,3186) UNION ALL SELECT JobTDate, PathId, File.Name AS FileName, DeltaSeq, Fhinfo, Fhnode FROM BaseFiles JOIN File USING (FileId) JOIN Job ON (BaseJobId = Job.JobId) WHERE BaseFiles.JobId IN (54,8436,3020,3186) ) AS tmp GROUP BY PathId, FileName, DeltaSeq, Fhinfo, Fhnode) AS T1 WHERE (Job.JobId IN (SELECT DISTINCT BaseJobId FROM BaseFiles WHERE JobId IN (54,8436,3020,3186)) OR Job.JobId IN (54,8436,3020,3186)) AND T1.JobTDate = Job.JobTDate AND Job.JobId = File.JobId AND T1.PathId = File.PathId AND T1.FileName = File.Name ) AS T1 JOIN Path ON (Path.PathId = T1.PathId) WHERE FileIndex > 0 ORDER BY T1.JobTDate, FileIndex ASC | 0 | 17339328 |
| 1232308 | bareos | localhost | bareos | Sleep | 422 | | NULL | 0 | 0 |
| 1232313 | bareos | localhost | bareos | Query | 156 | Waiting for table metadata lock | LOCK TABLES Path write, batch write, Path as p write | 0 | 0 |
| 1232460 | root | localhost | NULL | Query | 0 | starting | show full processlist | 0 | 0 |
+---------+--------+-----------+--------+---------+------+---------------------------------+---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+-----------+---------------+



At that moment new volume creation seems to timeout (probably underlying) :


2020-03-23 07:58:55 backupsrvxxx JobId 8836: stored/acquire.cc:271 Job 8836 canceled.
 
2020-03-23 07:58:55 backupsrvxxx JobId 8836: Fatal error: stored/mount.cc:972 Cannot open Dev="customerx1-incr" (/home/customerx1/bareos), Vol=vol-cons-2368
 
2020-03-23 07:58:55 backupsrvxxx JobId 8836: End of all volumes.
 
2020-03-23 07:58:55 backupsrvxxx JobId 8836: Fatal error: stored/mac.cc:752 Fatal append error on device "customerx1-cons" (/home/customerx1/bareos): ERR=stored/dev.cc:747 Could not open: /home/customerx1/bareos/vol-cons-2368, ERR=No such file or directory

 
2020-03-23 07:58:55 backupsrvxxx JobId 8836: Elapsed time=02:16:21, Transfer rate=304.1 K Bytes/second
 
2020-03-23 07:58:55 backupsrvxxx JobId 8836: Releasing device "customerx1-cons" (/home/customerx1/bareos).
 
2020-03-23 07:58:55 backupsrvxxx JobId 8836: Releasing device "customerx1-incr" (/home/customerx1/bareos).
 
2020-03-23 07:58:55 hostedpower-dir JobId 8836: Bareos hostedpower-dir 19.2.6 (11Feb20):
 Build OS: Linux-5.4.7-100.fc30.x86_64 debian Debian GNU/Linux 9.9 (stretch)
 JobId: 8836
 Job: backup-customerx1.xxx.com.2020-03-23_02.28.47_24
 Backup Level: Virtual Full
 Client: "customerx1.xxx.com" 18.2.7 (12Dec19) Linux-5.3.14-200.fc30.x86_64,debian,Debian GNU/Linux 9.9 (stretch),Debian_9.0,x86_64
 FileSet: "linux-all-mysql" 2020-02-12 22:15:00
 Pool: "customerx1-cons" (From Job Pool's NextPool resource)
 Catalog: "MyCatalog" (From Client resource)
 Storage: "customerx1-cons" (From Storage from Pool's NextPool resource)
 Scheduled time: 23-Mar-2020 02:28:47
 Start time: 03-Mar-2020 01:08:21
 End time: 03-Mar-2020 01:13:43
 Elapsed time: 5 mins 22 secs
 Priority: 10
 SD Files Written: 234,942
 SD Bytes Written: 2,488,124,067 (2.488 GB)
 Rate: 7727.1 KB/s
 Volume name(s): vol-cons-2368
 Volume Session Id: 4826
 Volume Session Time: 1581609872
 Last Volume Bytes: 6,660,046,477 (6.660 GB)
 SD Errors: 1
 SD termination status: Canceled
 Accurate: yes
 Bareos binary info: official Bareos subscription
 Termination: Backup Canceled

 
2020-03-23 07:55:33 backupsrvxxx JobId 8836: Warning: stored/vol_mgr.cc:544 Need volume from other drive, but swap not possible. Status: read=0 num_writers=1 num_reserve=0 swap=0 vol=vol-cons-2368 from dev="customerx1-cons" (/home/customerx1/bareos) to "customerx1-incr" (/home/customerx1/bareos)
 
2020-03-23 07:50:33 backupsrvxxx JobId 8836: Warning: stored/vol_mgr.cc:544 Need volume from other drive, but swap not possible. Status: read=0 num_writers=1 num_reserve=0 swap=0 vol=vol-cons-2368 from dev="customerx1-cons" (/home/customerx1/bareos) to "customerx1-incr" (/home/customerx1/bareos)
 
2020-03-23 07:45:33 backupsrvxxx JobId 8836: Warning: stored/vol_mgr.cc:544 Need volume from other drive, but swap not possible. Status: read=0 num_writers=1 num_reserve=0 swap=0 vol=vol-cons-2368 from dev="customerx1-cons" (/home/customerx1/bareos) to "customerx1-incr" (/home/customerx1/bareos)
 
2020-03-23 07:40:33 backupsrvxxx JobId 8836: Warning: stored/vol_mgr.cc:544 Need volume from other drive, but swap not possible. Status: read=0 num_writers=1 num_reserve=0 swap=0 vol=vol-cons-2368 from dev="customerx1-cons" (/home/customerx1/bareos) to "customerx1-incr" (/home/customerx1/bareos)
 
2020-03-23 07:35:33 backupsrvxxx JobId 8836: Warning: stored/vol_mgr.cc:544 Need volume from other drive, but swap not possible. Status: read=0 num_writers=1 num_reserve=0 swap=0 vol=vol-cons-2368 from dev="customerx1-cons" (/home/customerx1/bareos) to "customerx1-incr" (/home/customerx1/bareos)
 
2020-03-23 07:30:33 backupsrvxxx JobId 8836: Warning: stored/vol_mgr.cc:544 Need volume from other drive, but swap not possible. Status: read=0 num_writers=1 num_reserve=0 swap=0 vol=vol-cons-2368 from dev="customerx1-cons" (/home/customerx1/bareos) to "customerx1-incr" (/home/customerx1/bareos)
 
2020-03-23 07:25:33 backupsrvxxx JobId 8836: Warning: stored/vol_mgr.cc:544 Need volume from other drive, but swap not possible. Status: read=0 num_writers=1 num_reserve=0 swap=0 vol=vol-cons-2368 from dev="customerx1-cons" (/home/customerx1/bareos) to "customerx1-incr" (/home/customerx1/bareos)
 
2020-03-23 07:20:33 backupsrvxxx JobId 8836: Warning: stored/vol_mgr.cc:544 Need volume from other drive, but swap not possible. Status: read=0 num_writers=1 num_reserve=0 swap=0 vol=vol-cons-2368 from dev="customerx1-cons" (/home/customerx1/bareos) to "customerx1-incr" (/home/customerx1/bareos)
 
2020-03-23 07:15:33 backupsrvxxx JobId 8836: Warning: stored/vol_mgr.cc:544 Need volume from other drive, but swap not possible. Status: read=0 num_writers=1 num_reserve=0 swap=0 vol=vol-cons-2368 from dev="customerx1-cons" (/home/customerx1/bareos) to "customerx1-incr" (/home/customerx1/bareos)
 
2020-03-23 07:10:33 backupsrvxxx JobId 8836: Warning: stored/vol_mgr.cc:544 Need volume from other drive, but swap not possible. Status: read=0 num_writers=1 num_reserve=0 swap=0 vol=vol-cons-2368 from dev="customerx1-cons" (/home/customerx1/bareos) to "customerx1-incr" (/home/customerx1/bareos)
 
2020-03-23 07:05:33 backupsrvxxx JobId 8836: Warning: stored/vol_mgr.cc:544 Need volume from other drive, but swap not possible. Status: read=0 num_writers=1 num_reserve=0 swap=0 vol=vol-cons-2368 from dev="customerx1-cons" (/home/customerx1/bareos) to "customerx1-incr" (/home/customerx1/bareos)
 
2020-03-23 07:00:33 backupsrvxxx JobId 8836: Warning: stored/vol_mgr.cc:544 Need volume from other drive, but swap not possible. Status: read=0 num_writers=1 num_reserve=0 swap=0 vol=vol-cons-2368 from dev="customerx1-cons" (/home/customerx1/bareos) to "customerx1-incr" (/home/customerx1/bareos)
 
2020-03-23 06:55:33 backupsrvxxx JobId 8836: Warning: stored/vol_mgr.cc:544 Need volume from other drive, but swap not possible. Status: read=0 num_writers=1 num_reserve=0 swap=0 vol=vol-cons-2368 from dev="customerx1-cons" (/home/customerx1/bareos) to "customerx1-incr" (/home/customerx1/bareos)
 
2020-03-23 06:50:33 backupsrvxxx JobId 8836: Warning: stored/vol_mgr.cc:544 Need volume from other drive, but swap not possible. Status: read=0 num_writers=1 num_reserve=0 swap=0 vol=vol-cons-2368 from dev="customerx1-cons" (/home/customerx1/bareos) to "customerx1-incr" (/home/customerx1/bareos)
 
2020-03-23 06:45:33 backupsrvxxx JobId 8836: Please mount read Volume "vol-cons-2368" for:
 Job: backup-customerx1.xxx.com.2020-03-23_02.28.47_24
 Storage: "customerx1-incr" (/home/customerx1/bareos)
 Pool: customerx1-incr
 Media type: customerx1
 
2020-03-23 06:40:33 backupsrvxxx JobId 8836: Warning: stored/vol_mgr.cc:544 Need volume from other drive, but swap not possible. Status: read=0 num_writers=1 num_reserve=0 swap=0 vol=vol-cons-2368 from dev="customerx1-cons" (/home/customerx1/bareos) to "customerx1-incr" (/home/customerx1/bareos)
 
2020-03-23 06:35:33 backupsrvxxx JobId 8836: Warning: stored/vol_mgr.cc:544 Need volume from other drive, but swap not possible. Status: read=0 num_writers=1 num_reserve=0 swap=0 vol=vol-cons-2368 from dev="customerx1-cons" (/home/customerx1/bareos) to "customerx1-incr" (/home/customerx1/bareos)
 
2020-03-23 06:30:33 backupsrvxxx JobId 8836: Warning: stored/vol_mgr.cc:544 Need volume from other drive, but swap not possible. Status: read=0 num_writers=1 num_reserve=0 swap=0 vol=vol-cons-2368 from dev="customerx1-cons" (/home/customerx1/bareos) to "customerx1-incr" (/home/customerx1/bareos)
 
2020-03-23 06:25:33 backupsrvxxx JobId 8836: Warning: stored/vol_mgr.cc:544 Need volume from other drive, but swap not possible. Status: read=0 num_writers=1 num_reserve=0 swap=0 vol=vol-cons-2368 from dev="customerx1-cons" (/home/customerx1/bareos) to "customerx1-incr" (/home/customerx1/bareos)
 
2020-03-23 06:20:33 backupsrvxxx JobId 8836: Warning: stored/vol_mgr.cc:544 Need volume from other drive, but swap not possible. Status: read=0 num_writers=1 num_reserve=0 swap=0 vol=vol-cons-2368 from dev="customerx1-cons" (/home/customerx1/bareos) to "customerx1-incr" (/home/customerx1/bareos)
 
2020-03-23 06:15:33 backupsrvxxx JobId 8836: Warning: stored/vol_mgr.cc:544 Need volume from other drive, but swap not possible. Status: read=0 num_writers=1 num_reserve=0 swap=0 vol=vol-cons-2368 from dev="customerx1-cons" (/home/customerx1/bareos) to "customerx1-incr" (/home/customerx1/bareos)
 
2020-03-23 06:10:33 backupsrvxxx JobId 8836: Warning: stored/vol_mgr.cc:544 Need volume from other drive, but swap not possible. Status: read=0 num_writers=1 num_reserve=0 swap=0 vol=vol-cons-2368 from dev="customerx1-cons" (/home/customerx1/bareos) to "customerx1-incr" (/home/customerx1/bareos)
 
2020-03-23 06:05:33 backupsrvxxx JobId 8836: Warning: stored/vol_mgr.cc:544 Need volume from other drive, but swap not possible. Status: read=0 num_writers=1 num_reserve=0 swap=0 vol=vol-cons-2368 from dev="customerx1-cons" (/home/customerx1/bareos) to "customerx1-incr" (/home/customerx1/bareos)
 
2020-03-23 06:00:33 backupsrvxxx JobId 8836: Warning: stored/vol_mgr.cc:544 Need volume from other drive, but swap not possible. Status: read=0 num_writers=1 num_reserve=0 swap=0 vol=vol-cons-2368 from dev="customerx1-cons" (/home/customerx1/bareos) to "customerx1-incr" (/home/customerx1/bareos)
 
2020-03-23 05:55:33 backupsrvxxx JobId 8836: Warning: stored/vol_mgr.cc:544 Need volume from other drive, but swap not possible. Status: read=0 num_writers=1 num_reserve=0 swap=0 vol=vol-cons-2368 from dev="customerx1-cons" (/home/customerx1/bareos) to "customerx1-incr" (/home/customerx1/bareos)
 
2020-03-23 05:50:32 backupsrvxxx JobId 8836: Warning: stored/vol_mgr.cc:544 Need volume from other drive, but swap not possible. Status: read=0 num_writers=1 num_reserve=0 swap=0 vol=vol-cons-2368 from dev="customerx1-cons" (/home/customerx1/bareos) to "customerx1-incr" (/home/customerx1/bareos)
 
2020-03-23 05:45:32 backupsrvxxx JobId 8836: End of Volume at file 1 on device "customerx1-incr" (/home/customerx1/bareos), Volume "vol-cons-0042"
 
2020-03-23 05:45:32 backupsrvxxx JobId 8836: Warning: stored/vol_mgr.cc:544 Need volume from other drive, but swap not possible. Status: read=0 num_writers=1 num_reserve=0 swap=0 vol=vol-cons-2368 from dev="customerx1-cons" (/home/customerx1/bareos) to "customerx1-incr" (/home/customerx1/bareos)
 
2020-03-23 05:45:32 backupsrvxxx JobId 8836: Warning: stored/acquire.cc:343 Read acquire: stored/label.cc:268 Could not reserve volume vol-cons-2368 on "customerx1-incr" (/home/customerx1/bareos)
 
2020-03-23 05:45:32 backupsrvxxx JobId 8836: Please mount read Volume "vol-cons-2368" for:
 Job: backup-customerx1.xxx.com.2020-03-23_02.28.47_24
 Storage: "customerx1-incr" (/home/customerx1/bareos)
 Pool: customerx1-incr
 Media type: customerx1
 
2020-03-23 05:42:34 backupsrvxxx JobId 8836: Volume "vol-cons-2368" previously written, moving to end of data.
 
2020-03-23 05:42:34 backupsrvxxx JobId 8836: Ready to append to end of Volume "vol-cons-2368" size=4161368485
 
2020-03-23 05:42:34 backupsrvxxx JobId 8836: Forward spacing Volume "vol-cons-0042" to file:block 0:275.
 
2020-03-23 05:42:33 hostedpower-dir JobId 8836: Bootstrap records written to /var/lib/bareos/hostedpower-dir.restore.2224.bsr
 
2020-03-23 05:42:33 hostedpower-dir JobId 8836: Connected Storage daemon at backupsrvxxx:9103, encryption: ECDHE-PSK-CHACHA20-POLY1305
 
2020-03-23 05:42:33 hostedpower-dir JobId 8836: Using Device "customerx1-incr" to read.
 
2020-03-23 05:42:33 hostedpower-dir JobId 8836: Using Device "customerx1-cons" to write.
 
2020-03-23 05:42:33 backupsrvxxx JobId 8836: Ready to read from volume "vol-cons-0042" on device "customerx1-incr" (/home/customerx1/bareos).
 
2020-03-23 05:42:25 hostedpower-dir JobId 8836: Start Virtual Backup JobId 8836, Job=backup-customerx1.xxx.com.2020-03-23_02.28.47_24
 
2020-03-23 05:42:25 hostedpower-dir JobId 8836: Consolidating JobIds 58,8418,3024,3190



As soon this part happens:

2020-03-23 05:45:32 backupsrvxxx JobId 8836: Warning: stored/acquire.cc:343 Read acquire: stored/label.cc:268 Could not reserve volume vol-cons-2368 on "customerx1-incr" (/home/customerx1/bareos)
 
2020-03-23 05:45:32 backupsrvxxx JobId 8836: Please mount read Volume "vol-cons-2368" for:
 Job: backup-customerx1.xxx.com.2020-03-23_02.28.47_24
 Storage: "customerx1-incr" (/home/customerx1/bareos)
 Pool: customerx1-incr
 Media type: customerx1


Is never recovers from it as it looks like.

We have to cancel the job and most of the times it happens again sooner or later :(
TagsNo tags attached.
bareos-master: impact
bareos-master: action
bareos-19.2: impact
bareos-19.2: action
bareos-18.2: impact
bareos-18.2: action
bareos-17.2: impact
bareos-17.2: action
bareos-16.2: impact
bareos-16.2: action
bareos-15.2: impact
bareos-15.2: action
bareos-14.2: impact
bareos-14.2: action
bareos-13.2: impact
bareos-13.2: action
bareos-12.4: impact
bareos-12.4: action

Activities

hostedpower

hostedpower

2020-03-23 21:44

reporter   ~0003913

This query takes ages and ages :)

explain SELECT Path.Path, T1.Name, T1.FileIndex, T1.JobId, LStat, DeltaSeq , Fhinfo, Fhnode FROM ( SELECT FileId, Job.JobId AS JobId, FileIndex, File.PathId AS PathId, File.Name AS Name, LStat , File.DeltaSeq AS DeltaSeq, File.Fhinfo AS Fhinfo, File.Fhnode AS Fhnode, Job.JobTDate AS JobTDate FROM Job, File, ( SELECT MAX(JobTDate) AS JobTDate, PathId, FileName, DeltaSeq, Fhinfo, Fhnode FROM ( SELECT JobTDate, PathId, File.Name AS FileName, DeltaSeq, Fhinfo, Fhnode FROM File JOIN Job USING (JobId) WHERE File.JobId IN (8854,3351,3516,3684,3986,4290,4594,4899,5204,5509,5815,6121,6428,6733,7040,7347,7657,7966,8237,8514,8682) UNION ALL SELECT JobTDate, PathId, File.Name AS FileName, DeltaSeq, Fhinfo, Fhnode FROM BaseFiles JOIN File USING (FileId) JOIN Job ON (BaseJobId = Job.JobId) WHERE BaseFiles.JobId IN (8854,3351,3516,3684,3986,4290,4594,4899,5204,5509,5815,6121,6428,6733,7040,7347,7657,7966,8237,8514,8682) ) AS tmp GROUP BY PathId, FileName, DeltaSeq, Fhinfo, Fhnode) AS T1 WHERE (Job.JobId IN (SELECT DISTINCT BaseJobId FROM BaseFiles WHERE JobId IN (8854,3351,3516,3684,3986,4290,4594,4899,5204,5509,5815,6121,6428,6733,7040,7347,7657,7966,8237,8514,8682)) OR Job.JobId IN (8854,3351,3516,3684,3986,4290,4594,4899,5204,5509,5815,6121,6428,6733,7040,7347,7657,7966,8237,8514,8682)) AND T1.JobTDate = Job.JobTDate AND Job.JobId = File.JobId AND T1.PathId = File.PathId AND T1.FileName = File.Name ) AS T1 JOIN Path ON (Path.PathId = T1.PathId) WHERE FileIndex > 0 ORDER BY T1.JobTDate, FileIndex ASC;
+----+-------------+------------+------------+--------+---------------------+-------------+---------+----------------------------------------+-----------+----------+-----------------------------------------------------------+
| id | select_type | table | partitions | type | possible_keys | key | key_len | ref | rows | filtered | Extra |
+----+-------------+------------+------------+--------+---------------------+-------------+---------+----------------------------------------+-----------+----------+-----------------------------------------------------------+
| 1 | PRIMARY | Job | NULL | index | PRIMARY,JobTDate | JobTDate | 9 | NULL | 4558 | 100.00 | Using where; Using index; Using temporary; Using filesort |
| 1 | PRIMARY | <derived3> | NULL | ref | <auto_key1> | <auto_key1> | 9 | bareos.Job.JobTDate | 23494 | 100.00 | NULL |
| 1 | PRIMARY | File | NULL | ref | JobId,PathId | JobId | 265 | bareos.Job.JobId,T1.PathId,T1.FileName | 1 | 33.33 | Using where |
| 1 | PRIMARY | Path | NULL | eq_ref | PRIMARY | PRIMARY | 4 | T1.PathId | 1 | 100.00 | NULL |
| 6 | SUBQUERY | BaseFiles | NULL | ALL | basefiles_jobid_idx | NULL | NULL | NULL | 1 | 100.00 | Using where |
| 3 | DERIVED | <derived4> | NULL | ALL | NULL | NULL | NULL | NULL | 81892097 | 100.00 | Using temporary; Using filesort |
| 4 | DERIVED | File | NULL | ALL | JobId | NULL | NULL | NULL | 303320202 | 27.00 | Using where |
| 4 | DERIVED | Job | NULL | eq_ref | PRIMARY | PRIMARY | 4 | bareos.File.JobId | 1 | 100.00 | NULL |
| 5 | UNION | BaseFiles | NULL | ALL | basefiles_jobid_idx | NULL | NULL | NULL | 1 | 100.00 | Using where |
| 5 | UNION | Job | NULL | eq_ref | PRIMARY | PRIMARY | 4 | bareos.BaseFiles.BaseJobId | 1 | 100.00 | NULL |
| 5 | UNION | File | NULL | eq_ref | PRIMARY | PRIMARY | 8 | bareos.BaseFiles.FileId | 1 | 100.00 | NULL |
+----+-------------+------------+------------+--------+---------------------+-------------+---------+----------------------------------------+-----------+----------+-----------------------------------------------------------+
11 rows in set, 1 warning (0.00 sec)
arogge

arogge

2020-03-26 11:01

developer   ~0003917

That's one of the reasons why PostgreSQL has always been the preferred backend and MySQL has been deprecated in 19.2.
If you can find a way to make that query run faster (schema-change or database-tuning, not a query-change), we may consider adding it. However, don't expect any in-depth changes for MySQL anymore.

Issue History

Date Modified Username Field Change
2020-03-23 09:07 hostedpower New Issue
2020-03-23 21:44 hostedpower Note Added: 0003913
2020-03-26 11:01 arogge Assigned To => arogge
2020-03-26 11:01 arogge Status new => feedback
2020-03-26 11:01 arogge Note Added: 0003917