Slow FILE_METADATA loading. Backups Never ends approaching 100%

UG0 · December 12, 2023, 1:55pm

I can’t reproduce this arror anymore but I fixed one client pc with:

no active jobs for the client
Stop urbackupclientbackend service
delete all files from C:\Program Files\UrBackup\urbackup\data
keep access_keys.properties and delete other files from C:\Program Files\UrBackup\urbackup
restart service and start backup.
First time I had error about config missing. I had to restart service again. It pulled new config from the server.

Andrea_Carotti · December 13, 2023, 7:36am

Hi there, no solution still. I’m investigating if next to the rebooting of the backupped client stuck at the metadata stage (100%) the issue is solved at the next automatic backup procedure. It seems to be like that…it’s like something is fixing. Thanks to @UG0 for the proposed procedure, I’m still waiting to apply that…
I would appreciate if @uroni or other Urbackup masters could give any hints.
Let’s see
A

penguinale · December 13, 2023, 8:00am

Same problem here, seems that if i restarted client computer before backup it works

thdamb · December 13, 2023, 9:50am

Hi there, i noticed same problems on several installations, from what i see and understand it has to be with VSS writers stayed in waiting for completion, differents solutions provided don’t resolved the problem all the times. Waiting for a real resolution.

Mike_Backup · December 18, 2023, 6:44pm

Same problem here. I opened another topic on it, as i could not find this one.
I did notice if i change my full file backup interval from 30 days to 14 days the problem does not happen as often.

uroni · December 18, 2023, 8:55pm

Looks like this a more common new issue. Could everyone please add the information mentioned at Having problems with UrBackup? Please read before posting ? E.g. complete (debug level) logs (mostly client logs are interesting), information about operating systems and uncommon software (such as the Bitdefender antivirus).
If you can make memory dumps (in the task manager) of hanging UrBackupClientBackend.exe processes, those would be interesting as well. As well as complete procmon traces, but those might be too large and need to capture not just a hanging process, but what caused it to hang.

Mike_Backup · January 11, 2024, 2:24am

Hi, i just wanted to follow up on this issue. @uroni was right ,Bitdefender. I run 2 identical urbackup servers. One at home and one at the office. Bitdefender was the only difference. I switched the office away from Bitdefender Gravityzone and my file backup works perfectly now.

antonis · January 11, 2024, 12:36pm

Hello, I can add that we also encounter the same issue and are using Bitdefender GravityZone. But this is an issue that appeared since the start of November, previously there was no conflict between the two and Backups were working as intended.
Removing GravityZone is not an option for us. What can be done to fix this?

m277392 · January 11, 2024, 12:58pm

Ciao,
I inform that I also I use Gravity Zone on all clients …

adamb · January 11, 2024, 2:40pm

I have also BitDefender Gravity Zone in my network, with the same problems.
It is strange, because from the begining I used BitDefender without problems, aprox from the last 3 months is the problem present.
Windows update???

Andrea_Carotti · January 11, 2024, 9:23pm

Unfortunately I can confirm that I’m using Bitdefender Gravity zone too and I cannot do anything about it.By the way it is up and running since at least a couple of years and it was living happily with urbackup…so I don’t know what is the problem and why now…

uroni · January 11, 2024, 10:06pm

Could (s)one of you please do the client debug logs/memory dump/procmon trace thing I requested? Maybe this can be fixed on the UrBackup side (If Bitdefender just hangs, it is probably not going to be fixed – a memory dump would tell if this is the case).

antonis · January 12, 2024, 9:33am

@uroni if you could give me some instructions on how to do what you requested, i would be happy to.

uroni · January 13, 2024, 5:59pm

For debug log (least likely to be useful) see Having problems with UrBackup? Please read before posting for instructions.

For procmon capture see e.g. Basic Steps for Making a Process Monitor (ProcMon) Capture - Microsoft Community Hub .

For memory dump see e.g. %kb_name - %short_descr - Knowledge Portal .

Andrea_Carotti · January 23, 2024, 9:16am

Hi guys
@antonis did you provided any file? Any news? I’ m trying to figure out if I can set some exclusion rules on gravity zone to make the urbackup process to finish safely…but without any luck until now.
Someone already tried this way?@uroni do you think it could work?
Thanks
Andrea

PointPubMedia · January 24, 2024, 12:56pm

We are having the same kind of issue on a couple of clients.

We did a test yesterday, as we are also using Bitdefender, we uninstall bitdefender on one client to test and get the same issue.

I also test to completely uninstall the client and reinstall, same issue again.

there’s no link between the client version as we are having both, working and non-working for the same version.

It’s not related to Windows version, as we are having again, working and non-working for the same Windows version.

Another interesting thing is, windows clients that are still “pending”, I got a lot, a lot of CLOSE_WAIT using netstat -an that are going to the IP of the server using port 55415

Windows’s client firewall is also disable

uroni · January 24, 2024, 7:52pm

Has this issue been reported to Bitdefender? It needs to be fixed on their side.

When I looked at the memory dump sent to be it was hanging while opening a file ( CreateFileW ).

PointPubMedia · January 24, 2024, 8:07pm

@uroni I did some test yesterday using one Windows server that we uninstall Bitdefender and got the same issue!

For our problems, we are having 3 scenarios

1- If it can start the backup, it will hang at 100% and I got a lot of “Loading FILE_METADATA” in the logs, if I restart urbackupclient, it will “end” the backup but with a couple of error about some missing METADATA

2- OR worst, it never start the backup and in the log we have “Connecting for filelist (async)…”

3- everything works as normal

But I can confirm that it’s not related to Gravity zone at all and not even related to Windows Firewall.

As our testing, I also create a complete NEW urbackup server just to make sure it’s not related to our actual config and/or our actual urbackup database and I got the same issue as #1 on this machine too.

PointPubMedia · January 24, 2024, 8:12pm

Another thing related to our scenario #1

In the server log I got some

Established internet connection. Service=1
and
Established internet connection. Service=0

sounds like the client is trying to reconnect and it can’t. and at this stage, the logs on the backup job will loop about loading METADATA. If I restart the client it will end and the backup will be good except some error about metadata missing

as you can see in the log:

|01/24/24 14:47 |DEBUG |Loading urbackup/FILE_METADATA|HpBjz1Icoeir6xVuXGTC|4. Loaded 6.20312 MB at 67.528 KBit/s|
|—|—|—|
|01/24/24 14:49 |DEBUG |Loading urbackup/FILE_METADATA|HpBjz1Icoeir6xVuXGTC|4. Loaded 6 MB at 48 Bit/s|
|01/24/24 14:50 |DEBUG |Loading urbackup/FILE_METADATA|HpBjz1Icoeir6xVuXGTC|4. Loaded 6.03125 MB at 3.8 KBit/s|
|01/24/24 14:52 |DEBUG |Loading urbackup/FILE_METADATA|HpBjz1Icoeir6xVuXGTC|4. Loaded 6 MB at 48 Bit/s|
|01/24/24 14:53 |DEBUG |Loading urbackup/FILE_METADATA|HpBjz1Icoeir6xVuXGTC|4. Loaded 6.03125 MB at 3.8 KBit/s|
|01/24/24 14:55 |DEBUG |Loading urbackup/FILE_METADATA|HpBjz1Icoeir6xVuXGTC|4. Loaded 6 MB at 48 Bit/s|
|01/24/24 14:56 |DEBUG |Loading urbackup/FILE_METADATA|HpBjz1Icoeir6xVuXGTC|4. Loaded 6.03125 MB at 3.8 KBit/s|
|01/24/24 14:58 |DEBUG |Loading urbackup/FILE_METADATA|HpBjz1Icoeir6xVuXGTC|4. Loaded 6 MB at 48 Bit/s|
|01/24/24 14:59 |DEBUG |Loading urbackup/FILE_METADATA|HpBjz1Icoeir6xVuXGTC|4. Loaded 6.03125 MB at 3.8 KBit/s|
|01/24/24 15:01 |DEBUG |Loading urbackup/FILE_METADATA|HpBjz1Icoeir6xVuXGTC|4. Loaded 6 MB at 48 Bit/s|
|01/24/24 15:02 |DEBUG |Loading urbackup/FILE_METADATA|HpBjz1Icoeir6xVuXGTC|4. Loaded 6.03125 MB at 3.8 KBit/s|
|01/24/24 15:04 |DEBUG |Loading urbackup/FILE_METADATA|HpBjz1Icoeir6xVuXGTC|4. Loaded 6 MB at 48 Bit/s|
|01/24/24 15:07 |DEBUG |Loading urbackup/FILE_METADATA|HpBjz1Icoeir6xVuXGTC|4. Loaded 6 MB at 1.296 KBit/s|
|01/24/24 15:10 |DEBUG |Loading urbackup/FILE_METADATA|HpBjz1Icoeir6xVuXGTC|4. Loaded 6 MB at 1.296 KBit/s|
|01/24/24 15:10 |ERROR |Error getting file metadata. Errorcode: CANNOT_OPEN_FILE (3)|
|01/24/24 15:11 |ERROR |Error informing client about metadata stream end. Errorcode: TIMEOUT (2)|
|01/24/24 15:11 |INFO |Waiting for file hashing and copying threads…|
|01/24/24 15:11 |INFO |Writing new file list…|
|01/24/24 15:11 |DEBUG |Symbolic links created.|
|01/24/24 15:11 |INFO |Transferred 7.20487 MB - Average speed: 40.312 KBit/s|
|01/24/24 15:11 |INFO |(Before compression: 22.2105 MB ratio: 3.08271)|
|01/24/24 15:11 |INFO |58.0523 GB of files were already present on the server and did not need to be transferred|
|01/24/24 15:11 |DEBUG |Script does not exist urbackup/post_incr_filebackup|
|01/24/24 15:11 |INFO |Time taken for backing up client vDCVAULTFS.10ruptiv.local: 25m 20s|
|01/24/24 15:11 |INFO |Backup completed with issues|

At 15:11 I restart the client and the job continue and end correctly.

uroni · January 24, 2024, 8:12pm

Have you followed John McAffee’s instructions on how to uninstall your virus scanner?