View Issue Details

Jump to NotesJump to History
IDProjectCategoryView StatusDate SubmittedLast Update
0001214bareos-coredirectorpublic2020-03-23 09:072024-03-20 14:50
Reporterhostedpower Assigned Toarogge  
PrioritynormalSeveritymajorReproducibilityalways
Status resolvedResolutionfixed 
Product Version19.2.6 
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.

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

manager   ~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.
hostedpower

hostedpower

2020-04-06 14:26

reporter   ~0003926

ok we started with MySQL since that was supported back then. I don't believe this is something unsolvable with MySQL, but I think indeed priorities always have been with postgres. Any way to migrate all data to postgres? We have 120 GB of database data atm I believe.


Because at the moment we see this problem more and more lately :(

When we retry the job afterwards it does succeed!! So it looks like something temporary is causing this.
hostedpower

hostedpower

2020-04-06 15:42

reporter   ~0003927

Found it here about migration: https://docs.bareos.org/Appendix/Howtos.html
hostedpower

hostedpower

2020-04-07 12:13

reporter   ~0003928

PS: We're looking into postgresql, do you support postgresql 12? :)

On the other hand it's strange we have these reported errors intermittently, I really hope if we go over all the trouble to convert to postgresql we don't run into the same or other issues :)
hostedpower

hostedpower

2020-04-22 21:22

reporter   ~0003955

ok we switched to postgresql now, certain things seems slower than it was with MySQL at first sight, I hope it helps for our other problems :|
hostedpower

hostedpower

2020-04-22 21:44

reporter   ~0003957

ok I retried some jobs, but I see the same error messages as initially reported unfortunately :(

Messages like: 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)
hostedpower

hostedpower

2020-04-23 09:38

reporter   ~0003958

We ran consolidates today and so far so good, I think my previous conclusions were taken too soon and it seems the consolidate at least is more performant with PostgreSQL than it was with MySQL!

Not sure yet about the bug reported here... :)
hostedpower

hostedpower

2020-04-30 10:50

reporter   ~0003978

Unfortunately we had the initially reported error now with posgresql
hostedpower

hostedpower

2020-04-30 10:57

reporter   ~0003979

We also noticed that we we retry this failed job with posgres, ALL jobs are consolidated, just keeping a single job!! So we LOST ALL BACKUPS (except 1 full)


I don't think this ever happened with MySQL. Example from cancelled job:

our-dir JobId 20011: Consolidating JobIds 19691,14190

Now we cancelled that job and used retry:

our-dir JobId 20080: Consolidating JobIds 12652,19691,14190,14486,14659,14927,15229,15533,15835,16137,16438,16691,16966,17235,17500,17781,18051,18338,18630,18942,19256,19571,19892

How can this happen?
kszmigielski

kszmigielski

2020-05-04 15:06

reporter   ~0003981

I have exactly the same problem. The problem also occurs in version 19.2.7
hostedpower

hostedpower

2020-05-07 10:47

reporter   ~0003985

this problems seems to get worse atm, anything that can be done about it?
hostedpower

hostedpower

2020-08-05 13:14

reporter   ~0004030

Also there is big bug when re-trying a hung consolidate job. IT DELETES ALL BACKUPS AND KEEPS ONLY ONE.

See my previous message (2 nd previous)



We still have the initially reported issue as well :(
bruno-at-bareos

bruno-at-bareos

2024-03-20 14:50

manager   ~0005857

first problem is fixed, last problem is a duplicate due to rerun usage of consolidated jobs without any jobids.
this will be fixed soon.

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
2020-04-06 14:26 hostedpower Note Added: 0003926
2020-04-06 14:26 hostedpower Status feedback => assigned
2020-04-06 15:42 hostedpower Note Added: 0003927
2020-04-07 12:13 hostedpower Note Added: 0003928
2020-04-22 21:22 hostedpower Note Added: 0003955
2020-04-22 21:44 hostedpower Note Added: 0003957
2020-04-23 09:38 hostedpower Note Added: 0003958
2020-04-30 10:50 hostedpower Note Added: 0003978
2020-04-30 10:57 hostedpower Note Added: 0003979
2020-05-04 15:06 kszmigielski Note Added: 0003981
2020-05-07 10:47 hostedpower Note Added: 0003985
2020-08-05 13:14 hostedpower Note Added: 0004030
2024-03-20 14:50 bruno-at-bareos Status assigned => resolved
2024-03-20 14:50 bruno-at-bareos Resolution open => fixed
2024-03-20 14:50 bruno-at-bareos Note Added: 0005857