Performance issues when server is full

Hi Uroni,

my Server is full and UrBackup is stating “Es is momentan nicht genügend Speicherplatz für Backups vorhanden. UrBackup löscht gerade alte Datei- und Image-Backups, innerhalb der Grenzen die in den Einstellungen festgelegt sind. Wärend dieses Vorgangs ist die Performanz des Backupservers eventuell eingeschränkt; Lauftende Backups sind eventuell pausiert.” (by the way: there are some mistakes in writing in this text)
The server´s main page still opens but if I click anything else it get the “loading” on top right and that´s it, nothing happens anymore. UrBackup runs on it´s own PC, nothing else installed. Installpath is C:\Program files (enough free), TMP path is D:\ (500GB), backup path is E:\ (3TB, 0 (!) Bytes free), actual server version.

What could that be?

PS: I also deleted some Client and it does not get removed from database

Does it do something (e.g. delete old backups, use the database)? Log messages would be helpful. If you are able to set it into debug mode, even more so.
( http://www.urbackup.org/Administration_Manual.php#x1-440008.2 )

I see a lot of activity on database it seems (at first \Program files\UrBackupServer\urbackup\backup_server.db-wal, then \Program files\UrBackupServer\urbackup\backup_server.db). Processes System (i guess AntiVirus) and UrBackupService.exe, which also consumes around 50% cpu.

If I restart Service, I have to wait for a long LOOONG time until I can open logon page, the after logon I see summary page but if I click anything else on the Website nothing comes up. Also a restart of browser does not help, I then get nothing back from website (also not logon or summary page).

the debug log:

2013-03-12 01:41:16: Loaded -url- plugin
2013-03-12 01:41:16: Loaded -fsimageplugin- plugin
2013-03-12 01:41:16: Loaded -download- plugin
2013-03-12 01:41:16: Loaded -pychart- plugin
2013-03-12 01:41:16: Starting HTTP-Server on port 55414
2013-03-12 01:41:16: HTTP: Server started up sucessfully!
2013-03-12 01:41:16: Loaded -cryptoplugin- plugin
2013-03-12 01:41:17: Destroying all databases…
2013-03-12 01:41:17: Destroying all databases…
2013-03-12 01:45:38: HTTP: New Connection incomming 635351121 s: 2244
2013-03-12 01:45:38: HTTP: No available slots… starting new Worker
2013-03-12 01:45:38: HTTP: New Connection incomming 635351137 s: 2264
2013-03-12 01:45:38: Parsing done… starting handling request_num: 0 635351231
2013-03-12 01:45:38: Sending file “urbackup\www”
2013-03-12 01:45:38: Sending file: urbackup\www/index.htm
2013-03-12 01:45:38: Sending file: urbackup\www/index.htm done
2013-03-12 01:45:40: Parsing done… starting handling request_num: 0 635353820
2013-03-12 01:45:40: Sending file “urbackup\www/layout.css”
2013-03-12 01:45:40: Sending file: urbackup\www/layout.css
2013-03-12 01:45:40: Sending file: urbackup\www/layout.css done
2013-03-12 01:45:41: HTTP: New Connection incomming 635353914 s: 2324
2013-03-12 01:45:41: HTTP: New Connection incomming 635353914 s: 2264
2013-03-12 01:45:41: Parsing done… starting handling request_num: 0 635353914
2013-03-12 01:45:41: Sending file “urbackup\www/prototype.js”
2013-03-12 01:45:41: Sending file: urbackup\www/prototype.js
2013-03-12 01:45:41: Sending file: urbackup\www/prototype.js done
2013-03-12 01:45:41: Parsing done… starting handling request_num: 0 635354132
2013-03-12 01:45:41: Sending file “urbackup\www/templates.js”
2013-03-12 01:45:41: Sending file: urbackup\www/templates.js
2013-03-12 01:45:41: Sending file: urbackup\www/templates.js done
2013-03-12 01:45:41: HTTP: New Connection incomming 635354460 s: 2328
2013-03-12 01:45:41: HTTP: New Connection incomming 635354460 s: 2264
2013-03-12 01:45:41: Parsing done… starting handling request_num: 0 635354460
2013-03-12 01:45:41: Sending file “urbackup\www/urbackup_functions.js”
2013-03-12 01:45:41: Sending file: urbackup\www/urbackup_functions.js
2013-03-12 01:45:41: Parsing done… starting handling request_num: 0 635354491
2013-03-12 01:45:41: Sending file “urbackup\www/urbackup.js”
2013-03-12 01:45:41: Sending file: urbackup\www/urbackup.js
2013-03-12 01:45:41: Sending file: urbackup\www/urbackup_functions.js done
2013-03-12 01:45:41: Sending file: urbackup\www/urbackup.js done
2013-03-12 01:45:41: HTTP: New Connection incomming 635354600 s: 2344
2013-03-12 01:45:41: HTTP: New Connection incomming 635354600 s: 2264
2013-03-12 01:45:41: Parsing done… starting handling request_num: 0 635354600
2013-03-12 01:45:41: Sending file “urbackup\www/md5.js”
2013-03-12 01:45:41: Sending file: urbackup\www/md5.js
2013-03-12 01:45:41: Sending file: urbackup\www/md5.js done
2013-03-12 01:45:41: Parsing done… starting handling request_num: 0 635354694
2013-03-12 01:45:41: Sending file “urbackup\www/translation.js”
2013-03-12 01:45:41: Sending file: urbackup\www/translation.js
2013-03-12 01:45:41: Sending file: urbackup\www/translation.js done
2013-03-12 01:45:41: HTTP: New Connection incomming 635354787 s: 2352
2013-03-12 01:45:41: HTTP: New Connection incomming 635354787 s: 2264
2013-03-12 01:45:41: Parsing done… starting handling request_num: 0 635354787
2013-03-12 01:45:42: Parsing done… starting handling request_num: 0 635354959
2013-03-12 01:45:42: Sending file “urbackup\www/tabber-minimized.js”
2013-03-12 01:45:42: Sending file: urbackup\www/tabber-minimized.js
2013-03-12 01:45:42: Sending file: urbackup\www/tabber-minimized.js done
2013-03-12 01:45:42: HTTP: New Connection incomming 635355443 s: 2340
2013-03-12 01:45:42: Parsing done… starting handling request_num: 0 635355458
2013-03-12 01:45:42: Sending file “urbackup\www/indicator.gif”
2013-03-12 01:45:42: Sending file: urbackup\www/indicator.gif
2013-03-12 01:45:42: Sending file: urbackup\www/indicator.gif done
2013-03-12 01:48:25: HTTP: New Connection incomming 635518885 s: 3028
2013-03-12 01:48:25: HTTP: New Connection incomming 635518885 s: 3032
2013-03-12 01:49:43: HTTP: New Connection incomming 635595965 s: 3400
2013-03-12 01:49:43: HTTP: New Connection incomming 635595965 s: 3404
2013-03-12 01:54:04: Loaded -url- plugin
2013-03-12 01:54:04: Loaded -fsimageplugin- plugin
2013-03-12 01:54:04: Loaded -download- plugin
2013-03-12 01:54:04: Loaded -pychart- plugin
2013-03-12 01:54:04: Starting HTTP-Server on port 55414
2013-03-12 01:54:04: HTTP: Server started up sucessfully!
2013-03-12 01:54:04: Loaded -cryptoplugin- plugin
2013-03-12 01:54:04: Destroying all databases…
2013-03-12 01:54:04: Destroying all databases…
2013-03-12 02:07:33: HTTP: New Connection incomming 636666912 s: 5080
2013-03-12 02:07:33: HTTP: No available slots… starting new Worker
2013-03-12 02:07:33: HTTP: New Connection incomming 636666912 s: 5100
2013-03-12 02:07:34: Parsing done… starting handling request_num: 0 636666990
2013-03-12 02:11:47: Created new database connection for urbackup/backup_server.db
2013-03-12 02:11:47: Started UrBackup…
2013-03-12 02:11:47: Created new database connection for urbackup/backup_server.db
2013-03-12 02:11:47: Removing temporary files…
2013-03-12 02:11:47: HTTP: New Connection incomming 636920460 s: 6704
2013-03-12 02:11:47: HTTP: New Connection incomming 636920460 s: 6696
2013-03-12 02:11:47: Parsing done… starting handling request_num: 0 636920460
2013-03-12 02:11:47: Sending file “urbackup\www/header.png”
2013-03-12 02:11:47: Sending file: urbackup\www/header.png
2013-03-12 02:11:47: Sending file: urbackup\www/header.png done
2013-03-12 02:11:47: Parsing done… starting handling request_num: 0 636920694
2013-03-12 02:11:47: Sending file “urbackup\www/favicon.ico”
2013-03-12 02:11:47: HTTP: New Connection incomming 636920726 s: 6712
2013-03-12 02:11:47: HTTP: New Connection incomming 636920726 s: 6696
2013-03-12 02:11:47: Parsing done… starting handling request_num: 0 636920726
2013-03-12 02:11:47: Created new database connection for urbackup/backup_server.db
2013-03-12 02:11:47: UrBackup Server start up complete.
2013-03-12 02:11:47: Looking for old Sessions… 0 sessions
2013-03-12 02:11:47: Created new database connection for urbackup/backup_server.db
2013-03-12 02:11:47: Created new database connection for urbackup/backup_server.db
2013-03-12 02:11:48: Recreating temporary folder…
2013-03-12 02:11:48: Testing if backup destination can handle subvolumes and snapshots…
2013-03-12 02:11:48: Backup destination cannot handle subvolumes and snapshots. Snapshots disabled.
2013-03-12 02:11:49: Hostname: BA-BACKUP01
2013-03-12 02:11:50: New Backupclient: BA-PM-014
2013-03-12 02:11:50: New Backupclient: BA-PM-008
2013-03-12 02:11:50: New Backupclient: BA-PM-009
2013-03-12 02:11:50: New Backupclient: BA-SCN-02
2013-03-12 02:11:50: Created new database connection for urbackup/backup_server.db
2013-03-12 02:11:50: Created new database connection for urbackup/backup_server.db
2013-03-12 02:11:50: Created new database connection for urbackup/backup_server.db
2013-03-12 02:11:50: Getting client settings…
2013-03-12 02:11:50: Sending backup incr intervall…
2013-03-12 02:11:50: Getting client settings…
2013-03-12 02:11:50: Sending backup incr intervall…
2013-03-12 02:11:51: Getting client settings…
2013-03-12 02:11:51: Sending backup incr intervall…
2013-03-12 02:11:51: Created new database connection for urbackup/backup_server.db
2013-03-12 02:11:51: Created new database connection for urbackup/backup_server.db
2013-03-12 02:11:51: Created new database connection for urbackup/backup_server.db
2013-03-12 02:11:51: Created new database connection for urbackup/backup_server.db
2013-03-12 02:11:51: Created new database connection for urbackup/backup_server.db
2013-03-12 02:11:51: Created new database connection for urbackup/backup_server.db
2013-03-12 02:12:40: Hostname: BA-BACKUP01
2013-03-12 02:12:47: Downloading version file…
2013-03-12 02:13:31: Hostname: BA-BACKUP01
2013-03-12 02:13:47: ERROR: Download err: ERROR (1, 2) url=http://update1.urbackup.org/version.txt
2013-03-12 02:14:23: Hostname: BA-BACKUP01
2013-03-12 02:14:36: HTTP: New Connection incomming 637089987 s: 96
2013-03-12 02:14:36: HTTP: New Connection incomming 637089987 s: 6696
2013-03-12 02:14:36: Parsing done… starting handling request_num: 0 637089987
2013-03-12 02:14:37: Created new database connection for urbackup/backup_server.db
2013-03-12 02:14:37: Parsing done… starting handling request_num: 0 637090143
2013-03-12 02:14:37: HTTP: New Connection incomming 637090221 s: 7516
2013-03-12 02:14:37: HTTP: New Connection incomming 637090221 s: 6696
2013-03-12 02:14:37: Parsing done… starting handling request_num: 0 637090221
2013-03-12 02:15:14: Hostname: BA-BACKUP01
2013-03-12 02:15:44: HTTP: New Connection incomming 637157005 s: 7452
2013-03-12 02:15:44: HTTP: New Connection incomming 637157005 s: 6696
2013-03-12 02:15:44: Parsing done… starting handling request_num: 0 637157005
2013-03-12 02:15:53: Parsing done… starting handling request_num: 0 637166989
2013-03-12 02:16:03: HTTP: New Connection incomming 637176973 s: 7464
2013-03-12 02:16:03: Parsing done… starting handling request_num: 0 637176988
2013-03-12 02:16:05: Hostname: BA-BACKUP01
2013-03-12 02:16:13: HTTP: New Connection incomming 637186972 s: 6876
2013-03-12 02:16:13: Parsing done… starting handling request_num: 0 637186988
2013-03-12 02:16:23: HTTP: New Connection incomming 637196972 s: 7536
2013-03-12 02:16:23: Parsing done… starting handling request_num: 0 637196988
2013-03-12 02:16:33: HTTP: New Connection incomming 637206972 s: 7548
2013-03-12 02:16:33: Parsing done… starting handling request_num: 0 637206987
2013-03-12 02:16:56: Hostname: BA-BACKUP01
2013-03-12 02:17:48: Hostname: BA-BACKUP01
2013-03-12 02:18:39: Hostname: BA-BACKUP01
2013-03-12 02:19:30: Hostname: BA-BACKUP01
2013-03-12 02:20:22: Hostname: BA-BACKUP01
2013-03-12 02:21:13: Hostname: BA-BACKUP01
2013-03-12 02:22:04: Hostname: BA-BACKUP01
2013-03-12 02:22:55: Hostname: BA-BACKUP01
2013-03-12 02:23:47: Hostname: BA-BACKUP01
2013-03-12 02:24:38: Hostname: BA-BACKUP01
2013-03-12 02:25:29: Hostname: BA-BACKUP01
2013-03-12 02:26:20: Hostname: BA-BACKUP01
2013-03-12 02:26:56: msg=
2013-03-12 02:26:56: msg=
2013-03-12 02:26:56: msg=
2013-03-12 02:27:12: Hostname: BA-BACKUP01
2013-03-12 02:28:03: Hostname: BA-BACKUP01
2013-03-12 02:28:54: Hostname: BA-BACKUP01
2013-03-12 02:29:45: Hostname: BA-BACKUP01
2013-03-12 02:30:37: Hostname: BA-BACKUP01
2013-03-12 02:31:28: Hostname: BA-BACKUP01
2013-03-12 02:31:57: msg=
2013-03-12 02:31:57: msg=
2013-03-12 02:31:58: msg=
2013-03-12 02:32:20: Hostname: BA-BACKUP01
2013-03-12 02:32:52: Created new database connection for urbackup/backup_server.db
2013-03-12 02:32:52: Created new database connection for urbackup/backup_server.db
2013-03-12 02:32:52: Getting client settings…
2013-03-12 02:32:52: Sending backup incr intervall…
2013-03-12 02:33:11: Hostname: BA-BACKUP01
2013-03-12 02:33:56: HTTP: New Connection incomming 638249277 s: 7304
2013-03-12 02:33:56: HTTP: New Connection incomming 638249277 s: 7688
2013-03-12 02:34:02: Hostname: BA-BACKUP01
2013-03-12 02:34:53: Hostname: BA-BACKUP01
2013-03-12 02:35:44: Hostname: BA-BACKUP01
2013-03-12 02:36:35: Hostname: BA-BACKUP01
2013-03-12 02:36:57: msg=
2013-03-12 02:36:57: msg=
2013-03-12 02:36:57: msg=
2013-03-12 02:37:27: Hostname: BA-BACKUP01
2013-03-12 02:38:18: Hostname: BA-BACKUP01

[quote=“fossy777”]I see a lot of activity on database it seems (at first \Program files\UrBackupServer\urbackup\backup_server.db-wal, then \Program files\UrBackupServer\urbackup\backup_server.db). Processes System (i guess AntiVirus) and UrBackupService.exe, which also consumes around 50% cpu.

If I restart Service, I have to wait for a long LOOONG time until I can open logon page, the after logon I see summary page but if I click anything else on the Website nothing comes up. Also a restart of browser does not help, I then get nothing back from website (also not logon or summary page).
[/quote]

Seems like there is a problem with the database then. How big is the -wal file?

You could open the database with a SQLite Database Management tool (e.g. https://addons.mozilla.org/en-US/firefox/addon/sqlite-manager/ ) and do an integrity check/compress.

UrBackup should, if you did not disable it, create backups of its database at backupfolder\urbackup. You could shut down the server move all the backup_server* files away, move the backups databases there and continue with the backups.

It got, most likely, stuck while deleting a file backup with many files from the database. Do you, by chance, know how many files the file backups have approx. ?

I restored it and now it works again.

I noticed, that UrBackup uses really all available space on backup disk (Windows states “0 Bytes free”). Is that a good idea? I think this way problems are conceivable. Shouldn´t UrBackup break before the drive is completely full (for example 100 or 200MB free) and delete old backups?

Yes, performance likely goes to hell if you use 100% of a spinning platter. You could set a disk quota to avoid that, but I don’t think this is UrBackup’s job.

Something that could have happend is that it started cleaning up, because it had no space anymore and after a little bit of cleaning up started another backup concurrently. I’ll try to implement something to avoid that.

Well this is not as easy in Windows, since Urbackup service runs with “Local System” (and I don´t want to change too much to get off from Standards and Defaults).

I don´t agree with you that UrBackup shouldn´t do that since UrBackup is the cause and because of this issue UrBackup doesn´t work properly.

Your guess that it is cleaning up and then a backup starts is not the case I think. Most likely it is cleaning up BECAUSE backups are running and there is not enough space any more.

PS: why does this silly Forum correct my written words to capital letters? Except of the first letter in this posting I typed everything in small letters :evil:

Now the disk space is gone again and all the same Problems come up again. Performance is really bad, Server is stating “Es is momentan nicht genügend Speicherplatz für Backups vorhanden. UrBackup löscht gerade alte Datei- und Image-Backups, innerhalb der Grenzen die in den Einstellungen festgelegt sind. Wärend dieses Vorgangs ist die Performanz des Backupservers eventuell eingeschränkt; Lauftende Backups sind eventuell pausiert.” and after logon to the main page everything I click does not open.

By the way: what would a quota on disk Change? If I use a hard quota isn´t that the same as getting a disk full?

I’m sorry to hear that. It would probably be a little bit faster with the hard quota. If you are able you could put the server into debug log mode (See http://www.urbackup.org/Administration_Manual.php#x1-440008.2 ) and send the debug log file (compressed) to me martin@urbackup.org (From a period where it displays the warning on the status page).

I thought you meant a hard quota. A soft quota is planned. Both user level and server wide. Seeing the problems here I’ll probably get to it faster.

You could probably let the server delete the backups at night by lowering the maximal number of backups for some clients.

on Windows Systems, defining a hard quota would be not as easy: Administrators are per Default not affected by hard quotas and i fear it is impossible to change and if not one should not Change that. UrBackup per default runs as “local System” which is Administrator. So one would have to Change the Service to run as different user and grant that user Access to all Locations it has to Access to work. So much to configure only to use quotas.

I cannot let the Server delete any backups because I cannot Access the web Interface. As I already wrote: after logon the main page appears and then all other sites are dead. I cannot Change to Settings page.

I will send you the debug log soon…

PS: I had to set the process priority of urbackup Service to low to have any Performance left to do anything on the Server. UrBackup consumed so much Disk-IO that the Performance was very low. Now as I wanted to start Debugging I first tried again to Access the Website and now nothing was coming up, the process consumed 100% CPU.

I’ve implemented a cleanup procedure in the backup server here: https://sourceforge.net/projects/urbackup/files/Server/1.2RC/
Install that latest Windows server. Go to C:\Program Files\UrBackupServer and run the cleanup.bat as Administrator. Per default it will free 10% of the drive the backup folder is on.

This probably happens because some backups are not in the database anymore and thus UrBackup does not know about them. This was probably caused by using the database backups, i.e., older versions that didn’t have recent backups. I updated the version here ( http://sourceforge.net/projects/urbackup/files/Server/1.2RC/UrBackup%20Server%201.2-1.exe/download ) to include a script that removes files/directories that UrBackup does not know about (remove_unknown.bat). I would be interested in the output.

you are right - the script deleted almost one TB!

I will send you the log file…