Bareos Bug Tracker
Bareos Bug Tracker

View Issue Details Jump to Notes ] Related Changesets ] Issue History ] Print ]
IDProjectCategoryView StatusDate SubmittedLast Update
0000887bareos-core[All Projects] webuipublic2017-12-28 15:062018-01-15 06:56
Reportercrs9 
Assigned Tojoergs 
PrioritynormalSeverityminorReproducibilityalways
StatusfeedbackResolutionreopened 
PlatformLinuxOSCentOSOS Version7
Product Version17.2.4 
Target Version17.2.5Fixed in Version 
Summary0000887: Restore file list taking 20 minutes to populate
DescriptionWhen selecting a client with a large number of files, the file list will take over 20 minutes to come back. Clicking to other tabs will do nothing until the task is complete.
The bareos-audit.log shows:

20-Dec 11:29 : Console [admin] from [127.0.0.1] cmdline .bvfs_lsdirs jobid=778,804,829 path= limit=1000 offset=0
20-Dec 11:29 : Console [admin] from [127.0.0.1] cmdline .bvfs_update jobid=778,804,829
20-Dec 11:29 : Console [admin] from [127.0.0.1] cmdline .bvfs_lsdirs jobid=778,804,829 path= limit=1000 offset=1000

This appears over and over until it reaches:

20-Dec 11:50 : Console [admin] from [127.0.0.1] cmdline .bvfs_lsdirs jobid=778,804,829 path= limit=1000 offset=10349000
20-Dec 11:50 : Console [admin] from [127.0.0.1] cmdline status director

The Dashboard state 9150221 files, 617 jobs. This specific client has 0000010:0000301,000 files.
If I browse away from this client and back, the count starts all over again.
Steps To ReproduceUpgrade from 17.1.3 to 17.2.4
Manually update db scheme
Log into webui
Select client with a large amount of files to restore from
Additional InformationJorg asked for the following:
}.bvfs_lsdirs jobid=778,804,829 path= limit=1000 offset=0
{
  "jsonrpc": "2.0",
  "id": null,
  "result": {
    "directories": [
      {
        "type": "D",
        "pathid": 45383,
        "fileid": 0,
        "jobid": 0,
        "lstat": "A A A A A A A A A A A A A A",
        "name": ".",
        "fullpath": ".",
        "stat": {
          "dev": 0,
          "ino": 0,
          "mode": 0,
          "nlink": 0,
          "user": "root",
          "group": "root",
          "rdev": 0,
          "size": 0,
          "atime": 0,
          "mtime": 0,
          "ctime": 0
        },
        "linkfileindex": 0
      }
    ]
  }

*.bvfs_lsdirs jobid=778,804,829 path= limit=1000 offset=1000
{
  "jsonrpc": "2.0",
  "id": null,
  "result": {
    "directories": [
      {
        "type": "D",
        "pathid": 45383,
        "fileid": 0,
        "jobid": 0,
        "lstat": "A A A A A A A A A A A A A A",
        "name": ".",
        "fullpath": ".",
        "stat": {
          "dev": 0,
          "ino": 0,
          "mode": 0,
          "nlink": 0,
          "user": "root",
          "group": "root",
          "rdev": 0,
          "size": 0,
          "atime": 0,
          "mtime": 0,
          "ctime": 0
        },
        "linkfileindex": 0
      }
    ]
  }

*.bvfs_lsdirs jobid=778,804,829 path= limit=1000 offset=10349000
{
  "jsonrpc": "2.0",
  "id": null,
  "result": {
    "directories": [
      {
        "type": "D",
        "pathid": 45383,
        "fileid": 0,
        "jobid": 0,
        "lstat": "A A A A A A A A A A A A A A",
        "name": ".",
        "fullpath": ".",
        "stat": {
          "dev": 0,
          "ino": 0,
          "mode": 0,
          "nlink": 0,
          "user": "root",
          "group": "root",
          "rdev": 0,
          "size": 0,
          "atime": 0,
          "mtime": 0,
          "ctime": 0
        },
        "linkfileindex": 0
      }
    ]
  }
TagsNo tags attached.
bareos-master: impactyes
bareos-master: actionwill care
bareos-17.2: impactyes
bareos-17.2: actionwill care
bareos-16.2: impact
bareos-16.2: actionnone
bareos-15.2: impact
bareos-15.2: actionnone
bareos-14.2: impact
bareos-14.2: actionnone
bareos-13.2: impact
bareos-13.2: actionnone
bareos-12.4: impact
bareos-12.4: actionnone
Attached Filespng file icon Снимок экрана от 2018-01-15 09-51-07.png [^] (184,466 bytes) 2018-01-15 06:56

- Relationships
related to 0000890confirmedjoergs .bvfs_update does not always create all cache enties. This results in a not working webui restore tree 

-  Notes
(0002854)
crs9 (reporter)
2018-01-02 21:35

As a note, from the 16.2.7 notes, I cannot create index

bareos=# CREATE INDEX file_jpfnidpart_idx ON File(PathId,_JobId, _FilenameId) WHERE FileIndex = 0;
ERROR: column "_jobid" does not exist

Not sure if this is required or not.
(0002855)
crs9 (reporter)
2018-01-02 21:55

I stand corrected, I see the expected indexes that were created during the 2171 migration
(0002857)
crs9 (reporter)
2018-01-03 15:49

I updated the cache manually.
backup01:~$ time echo ".bvfs_update" | sudo bconsole
Connecting to Director localhost:9101
1000 OK: backup01 Version: 17.2.4 (21 Sep 2017)
Enter a period to cancel a command.
.bvfs_update
Automatically selected Catalog: MyCatalog
Using Catalog "MyCatalog"
You have messages.

real 1m59.716s
user 0m0.053s
sys 0m0.020s

After only taking 2 minutes, the restore list is still taking 20 minutes to populate.
(0002859)
joergs (administrator)
2018-01-04 13:37

There are at least two problems here:

1. the result delivered by .bvfs_lsdirs is not correct. It misses an entry for "/".
2. the bareos-webui does not behave right. The newly introduced looping through the result set continues looping until it receives the full result. In your case this results in an endless loop. I assume, after 20 minutes some browser, ajax or php timeout triggers.

About 2: this will be fixed soon.

About 1: I'm not sure, what triggers the problem in the first place. A few questions to limit the scope:
  * does this happen for all restore jobs or just for a specific one?
  * what database backend do you use?
  * have you used bareos-dbcheck? If not, don't use it now. There is another bug in there, at least when using sqlite. This will also be resolved soon.
(0002860)
crs9 (reporter)
2018-01-04 14:44

1) I have 6 clients
backup01, centos7.2 - lists fine
catalog, centos 7.2 - lists fine
dc01, windows 2016 core - lists fine
dc02, windows 2016 core - lists fine
fmp01, windows 2016 - slow - 301975 files, 294GB size
fps01, windows 2016 - slow - 181855 files, 14.11GB size

Both slow servers took 20 minutes to list.

After 20min, the webui displays an error box "Oops, something went wrong, probably too many files"

2) Postgresql 9.6.6

3) I have not used that, should I try it since I'm using postgresql?
(0002861)
joergs (administrator)
2018-01-04 14:51

about 3:
not now. I'll first check what exactly the problem with dbcheck is.

about 1:
interesting. I've not assumed this.

What you could do is to recreate the full bvfs cache. Please be aware, that this will take quite a long time.

On bconsole type:
.bvfs_clear_cache yes
.bvfs_update

The first command will be quick, the second will take a lot of time and is normally not required (it will normally be called for specific jobids that you are interested in). However, you should give it a try.

For details about bvfs see http://doc.bareos.org/master/html/bareos-developer-guide.html#sec:bvfs [^]
(0002862)
crs9 (reporter)
2018-01-04 15:32

.bvfs_clear_cache yes
ran for 2 seconds

.bvfs_update
ran for 16 minutes

Same slowness and error after the update command.
(0002863)
joergs (administrator)
2018-01-04 15:44

Okay, that is the result of

list files jobid=<last full job of fmp01>
(0002864)
crs9 (reporter)
2018-01-04 15:49

It list all the files on C: and D:, which I would expect.
(0002865)
crs9 (reporter)
2018-01-04 15:55

fmp01 listing took 28 seconds.

fps01 last full lists all it's C: and D: files as expected also. this listing took 27 seconds, even though it has almost 2 times the number of files.
(0002866)
joergs (administrator)
2018-01-04 16:04

But how are they displayed?

/C:/...

or somehow else?
(0002867)
crs9 (reporter)
2018-01-04 16:08

C:/Users/
 D:/Users/

there is a block of whitespace before each letter. dc01 is displayed the same way.
One other way these two servers are different, they have a D:/, dc01 and 02 do not.
(0002868)
frank (manager)
2018-01-04 17:26

Note:

A fix regarding the endless loop in case of receiving rubish BVFS output has been pushed internal to the webui bareos-17.2 branch and is going public with the next push to GitHub as well.
(0002869)
joergs (administrator)
2018-01-05 16:56

In my Linux only test environment, I was able to create a similar problem by using dbcheck on my sqlite database.

Following steps did resolve this issue:

# clear cache
.bvfs_clear_cache yes

# restart the bareos-dir
systemctl restart bareos-dir

# update cache
.bvfs_update

The reason is some internal director cache.
(0002871)
frank (manager)
2018-01-09 12:31

Fix committed to bareos-webui bareos-17.2 branch with changesetid 7444.
(0002873)
protopopys (reporter)
2018-01-15 06:54

Hi, it's not working for me. I have a tousen folders in directory and if i want to restore some files i have the error.

- Related Changesets
bareos-webui: bareos-17.2 a562e5fe
Timestamp: 2018-01-04 17:13:06
Author: frank
Ported: N/A
Details ] Diff ]
Fix to bugreport 0000887

The newly introduced looping through the result set continues looping until it receives the full result.
There was a case that lead to an endless loop, if the BVFS API delivers a rubish result.

Fixes 0000887: Restore file list taking 20 minutes to populate
mod - CHANGELOG.md Diff ] File ]
mod - module/Restore/src/Restore/Model/RestoreModel.php Diff ] File ]

- Issue History
Date Modified Username Field Change
2017-12-28 15:06 crs9 New Issue
2018-01-02 21:35 crs9 Note Added: 0002854
2018-01-02 21:55 crs9 Note Added: 0002855
2018-01-03 15:49 crs9 Note Added: 0002857
2018-01-04 13:29 joergs Assigned To => frank
2018-01-04 13:29 joergs Status new => assigned
2018-01-04 13:37 joergs Note Added: 0002859
2018-01-04 14:44 crs9 Note Added: 0002860
2018-01-04 14:51 joergs Note Added: 0002861
2018-01-04 15:32 crs9 Note Added: 0002862
2018-01-04 15:44 joergs Note Added: 0002863
2018-01-04 15:49 crs9 Note Added: 0002864
2018-01-04 15:55 crs9 Note Added: 0002865
2018-01-04 16:04 joergs Note Added: 0002866
2018-01-04 16:08 crs9 Note Added: 0002867
2018-01-04 17:26 frank Note Added: 0002868
2018-01-05 16:52 joergs Assigned To frank => joergs
2018-01-05 16:53 joergs bareos-master: impact => yes
2018-01-05 16:53 joergs bareos-master: action => will care
2018-01-05 16:53 joergs bareos-17.2: impact => yes
2018-01-05 16:53 joergs bareos-17.2: action => will care
2018-01-05 16:53 joergs bareos-16.2: action => none
2018-01-05 16:53 joergs bareos-15.2: action => none
2018-01-05 16:53 joergs bareos-14.2: action => none
2018-01-05 16:53 joergs bareos-13.2: action => none
2018-01-05 16:53 joergs bareos-12.4: action => none
2018-01-05 16:53 joergs Target Version => 17.2.5
2018-01-05 16:56 joergs Note Added: 0002869
2018-01-05 16:56 joergs Status assigned => feedback
2018-01-08 21:56 joergs Relationship added related to 0000890
2018-01-09 12:31 frank Changeset attached => bareos-webui bareos-17.2 a562e5fe
2018-01-09 12:31 frank Note Added: 0002871
2018-01-09 12:31 frank Status feedback => resolved
2018-01-09 12:31 frank Resolution open => fixed
2018-01-09 12:31 frank Status resolved => feedback
2018-01-09 12:31 frank Resolution fixed => reopened
2018-01-15 06:54 protopopys Note Added: 0002873
2018-01-15 06:56 protopopys File Added: Снимок экрана от 2018-01-15 09-51-07.png


Copyright © 2000 - 2018 MantisBT Team
Powered by Mantis Bugtracker