ERROR: Cannot create Directory for backup (Server error)

general discussion
1

Hello! I have urbackup server running on Linux Mint Debian Edition (LMDE) box, and two clients running on Windows 7 64-bit. When I attempt to initiate a backup, either image or file, from the server-side or from the client-side, it would not proceed and I would get this error in the log:

ERROR: Cannot create Directory for backup (Server error)

First of all a disclaimer: I started a forum topic on December 3, 2013 concerning a problem with changing backup paths. That was on another server I was running and since then I believe I have figured out what was wrong with it. This LMDE server has a fresh install of urbackup server; this problem should be unrelated to the first. :)

We have an external USB hard drive (NTFS partitioned) on the router that we’d like to use to store urbackup data. To mount this, we used an automounter called “autofs” (version 5.0.7-3).

The drive is mounted to /urbackup/office_backup by this mounting argument:

office_backup  -fstype=cifs,username=****,password=****,uid=116,gid=125,iocharset=utf8,sec=ntlm    ://192.168.0.1/Office_Backup

(username and password masked for security reasons; 116 and 125 are the user and group ID for “urbackup”)

Accordingly, in urbackup settings, the backup storage path is set to: /urbackup/office_backup

This seems to work fine. The output of “ls -l /urbackup/office_backup” shows:

ben@mint-server /urbackup/office_backup $ ls -l
total 0
drwxr-xr-x 1 urbackup urbackup 0 Jan  7 11:17 clients
drwxr-xr-x 1 urbackup urbackup 0 Jan  6 11:56 MARLENE-HP
drwxr-xr-x 1 urbackup urbackup 0 Jan  7 11:47 STAFF-HP
drwxr-xr-x 1 urbackup urbackup 0 Jan  8 03:55 urbackup
drwxr-xr-x 1 urbackup urbackup 0 Jan  7 15:53 urbackup_tmp_files

where MARLENE-HP and STAFF-HP are the two clients.

When a backup command is given, the Status page of the urbackup webpage will show:

Queued backup

but when the page is refreshed after a few seconds, it’s gone.

The log on the urbackup webpage shows:

Info	23.01.14 12:57	Starting full file backup...
Errors	23.01.14 12:57	Cannot create Directory for backup (Server error)
Info	23.01.14 12:57	Time taken for backing up client STAFF-HP:
Errors	23.01.14 12:57	Backup failed

The client-side log also shows exactly the same messages.

In /tmp/urbackup, something funny is going on too. Files were created, but they are all size zero:

ben@mint-server /tmp/urbackup_tmp $ ls -l
total 0
-rw------- 1 urbackup urbackup 0 Jan 23 12:58 cps.gZUhX4
-rw------- 1 urbackup urbackup 0 Jan 23 12:56 cps.KDWWX9
-rw------- 1 urbackup urbackup 0 Jan 23 12:57 cps.uhcvxz

I am at a loss and greatly appreciate any offer to help. And thanks to uroni for creating this project!

And BTW, the urbackup server version is 1.3.2.463-1; the urbackup client software is version 1.3.

Lastly, here is a relevant (I hope) portion of the debug log from /var/log/urbackup.log:

2014-01-23 12:52:42: Starting incremental file backup...
2014-01-23 12:52:42: ERROR: Cannot create Directory for backup (Server error)
2014-01-23 12:52:43: Time taken for backing up client STAFF-HP:
2014-01-23 12:52:43: ERROR: Backup failed
2014-01-23 12:52:43: Updating statistics...
2014-01-23 12:52:43: Copying files from files_new table...
2014-01-23 12:52:43: Deleting contents of files_new table...
2014-01-23 12:52:43: Updating image stats...
2014-01-23 12:52:43: Repairing image failed
2014-01-23 12:52:43: ERROR: Error opening file '/urbackup/office_backup/STAFF-HP/Image_SYSVOL_140107-1559.vhd'
2014-01-23 12:52:43: Updating deleted files...
2014-01-23 12:52:43: Updating file stats...
2014-01-23 12:52:43: Done updating statistics.
2014-01-23 12:53:51: Changing user...
2014-01-23 12:53:51: done.
2014-01-23 12:53:51: Loaded -pychart- plugin
2014-01-23 12:53:51: Loaded -url- plugin
2014-01-23 12:53:51: Loaded -cryptoplugin- plugin
2014-01-23 12:53:51: Loaded -download- plugin
2014-01-23 12:53:51: Loaded -fsimageplugin- plugin
2014-01-23 12:53:51: Starting HTTP-Server on port 55414
2014-01-23 12:53:51: HTTP: Server started up sucessfully!
2014-01-23 12:53:51: Created new database connection for urbackup/backup_server.db
2014-01-23 12:53:51: Destroying all databases...
2014-01-23 12:53:51: Destroying all databases...
2014-01-23 12:53:51: Created new database connection for urbackup/backup_server.db
2014-01-23 12:53:52: Creating files Indices...
2014-01-23 12:53:52: Started UrBackup...
2014-01-23 12:53:52: Created new database connection for urbackup/backup_server.db
2014-01-23 12:53:52: Testing if backup destination can handle subvolumes and snapshots...
2014-01-23 12:53:52: Backup destination cannot handle subvolumes and snapshots. Snapshots disabled.
2014-01-23 12:53:52: Binding to interface eth0 for broadcasting...
2014-01-23 12:53:52: UrBackup Server start up complete.
2014-01-23 12:53:52: Creating SOCKET...
2014-01-23 12:53:52: done.
2014-01-23 12:53:52: Server started up sucessfully!
2014-01-23 12:53:52: Looking for old Sessions... 0 sessions
2014-01-23 12:53:52: Created new database connection for urbackup/backup_server.db
2014-01-23 12:53:52: Created new database connection for urbackup/backup_server.db
2014-01-23 12:54:23: New Backupclient: STAFF-HP
2014-01-23 12:54:23: Created new database connection for urbackup/backup_server.db
2014-01-23 12:54:23: Created new database connection for urbackup/backup_server.db
2014-01-23 12:54:23: Getting client settings...
2014-01-23 12:54:23: Sending backup incr intervall...
2014-01-23 12:54:23: Starting incremental file backup...
2014-01-23 12:54:23: ERROR: Cannot create Directory for backup (Server error)
2014-01-23 12:54:24: Time taken for backing up client STAFF-HP: 1s
2014-01-23 12:54:24: ERROR: Backup failed
2014-01-23 12:54:24: Downloading version file...
2014-01-23 12:54:25: Downloaded file successfully
2014-01-23 12:54:25: Updating statistics...
2014-01-23 12:54:25: Copying files from files_new table...
2014-01-23 12:54:25: Deleting contents of files_new table...
2014-01-23 12:54:25: Updating image stats...
2014-01-23 12:54:25: Repairing image failed
2014-01-23 12:54:25: ERROR: Error opening file '/urbackup/office_backup/STAFF-HP/Image_SYSVOL_140107-1559.vhd'
2014-01-23 12:54:25: Updating deleted files...
2014-01-23 12:54:25: Updating file stats...
2014-01-23 12:54:25: Done updating statistics.
2014-01-23 12:56:21: HTTP: No available slots... starting new Worker
2014-01-23 12:56:21: Created new database connection for urbackup/backup_server.db
2014-01-23 12:56:22: Created new database connection for urbackup/backup_server.db
2014-01-23 12:57:08: msg=START BACKUP FULL
2014-01-23 12:57:08: Starting full file backup...
2014-01-23 12:57:08: ERROR: Cannot create Directory for backup (Server error)
2014-01-23 12:57:09: Time taken for backing up client STAFF-HP:
2014-01-23 12:57:09: ERROR: Backup failed
2014-01-23 12:57:09: Updating statistics...
2014-01-23 12:57:09: Copying files from files_new table...
2014-01-23 12:57:09: Deleting contents of files_new table...
2014-01-23 12:57:09: Updating image stats...
2014-01-23 12:57:09: Repairing image failed
2014-01-23 12:57:09: ERROR: Error opening file '/urbackup/office_backup/STAFF-HP/Image_SYSVOL_140107-1559.vhd'
2014-01-23 12:57:09: Updating deleted files...
2014-01-23 12:57:09: Updating file stats...
2014-01-23 12:57:09: Done updating statistics.
2014-01-23 12:58:08: Sending file "/var/urbackup/www"
2014-01-23 12:58:08: Sending file: /var/urbackup/www/index.htm
2014-01-23 12:58:08: Sending file: /var/urbackup/www/index.htm done
2014-01-23 12:58:08: HTTP: No available slots... starting new Worker
2014-01-23 12:58:08: HTTP: No available slots... starting new Worker
2014-01-23 12:58:08: Sending file "/var/urbackup/www/layout.css"
2014-01-23 12:58:08: Sending file: /var/urbackup/www/layout.css
2014-01-23 12:58:08: Sending file "/var/urbackup/www/prototype.js"
2014-01-23 12:58:08: Sending file: /var/urbackup/www/layout.css done
2014-01-23 12:58:08: Sending file: /var/urbackup/www/prototype.js
2014-01-23 12:58:08: Sending file "/var/urbackup/www/templates.js"
2014-01-23 12:58:08: Sending file: /var/urbackup/www/templates.js
2014-01-23 12:58:08: HTTP: No available slots... starting new Worker
2014-01-23 12:58:08: HTTP: No available slots... starting new Worker
2014-01-23 12:58:08: Sending file "/var/urbackup/www/default_user_rights.js"
2014-01-23 12:58:08: Sending file: /var/urbackup/www/default_user_rights.js
2014-01-23 12:58:08: Sending file "/var/urbackup/www/md5.js"
2014-01-23 12:58:08: Sending file: /var/urbackup/www/default_user_rights.js done
2014-01-23 12:58:08: Sending file: /var/urbackup/www/md5.js
2014-01-23 12:58:08: Sending file: /var/urbackup/www/md5.js done
2014-01-23 12:58:08: HTTP: No available slots... starting new Worker
2014-01-23 12:58:08: Sending file "/var/urbackup/www/translation.js"
2014-01-23 12:58:08: Sending file: /var/urbackup/www/translation.js
2014-01-23 12:58:08: Sending file: /var/urbackup/www/templates.js done
2014-01-23 12:58:08: Sending file "/var/urbackup/www/urbackup.js"
2014-01-23 12:58:08: Sending file: /var/urbackup/www/urbackup.js
2014-01-23 12:58:08: Sending file "/var/urbackup/www/urbackup_functions.js"
2014-01-23 12:58:08: Sending file: /var/urbackup/www/urbackup_functions.js
2014-01-23 12:58:08: Sending file "/var/urbackup/www/tabber-minimized.js"
2014-01-23 12:58:08: Sending file: /var/urbackup/www/tabber-minimized.js
2014-01-23 12:58:08: Sending file: /var/urbackup/www/tabber-minimized.js done
2014-01-23 12:58:08: Sending file: /var/urbackup/www/prototype.js done
2014-01-23 12:58:08: Sending file: /var/urbackup/www/urbackup_functions.js done
2014-01-23 12:58:08: Sending file: /var/urbackup/www/translation.js done
2014-01-23 12:58:08: Sending file: /var/urbackup/www/urbackup.js done
2014-01-23 12:58:09: Sending file "/var/urbackup/www/indicator.gif"
2014-01-23 12:58:09: Sending file "/var/urbackup/www/header.png"
2014-01-23 12:58:09: Sending file: /var/urbackup/www/indicator.gif
2014-01-23 12:58:09: Sending file: /var/urbackup/www/header.png
2014-01-23 12:58:09: Sending file: /var/urbackup/www/indicator.gif done
2014-01-23 12:58:09: Sending file: /var/urbackup/www/header.png done
2014-01-23 12:58:10: Created new database connection for urbackup/backup_server.db
2014-01-23 12:58:10: Created new database connection for urbackup/backup_server.db
2014-01-23 12:58:28: Created new database connection for urbackup/backup_server.db
2014-01-23 12:58:29: Sending file "/var/urbackup/www/arr.png"
2014-01-23 12:58:29: Sending file: /var/urbackup/www/arr.png
2014-01-23 12:58:29: Sending file: /var/urbackup/www/arr.png done
2

Today’s Update: one client (MARLENE-HP) suddenly started working. I really didn’t do anything, other than turning on that computer! But this client can do file and image backups now.

There is still an error for the other client (STAFF-HP) whenever backup is initiated:

ERROR: Error opening file '/urbackup/office_backup/STAFF-HP/Image_SYSVOL_140107-1559.vhd'

I don’t understand why urbackup is looking for that vhd. It is absolutely empty in the /urbackup/office_backup/STAFF-HP path…

Ben.

3

This error normaly only occurs if it really cannot create the directory for the new file backup.

You can fix the “vhd” error by running “start_urbackup_server --remove_unknown” while the server is shut down. It tries to repair the image paths it has in its database from time to time (or you can just leave it be as it does not hurt).

4

Hi, uroni. Thank you for the response. I have tried “start_urbackup_server --remove_unknown” as you suggested.

The output showed that it removed some files for the “MARLENE-HP” client (the client that is working), but none for “STAFF-HP” (the client that’s not working). In any case, even prior to executing the command, the path “/urbackup/office_backup/STAFF-HP” is already empty.

After the clean-up, the situation has not changed much: MARLENE-HP can still perform backups, STAFF-HP still cannot, with the following error message from the log:

2014-01-27 10:28:18: ERROR: Cannot create Directory for backup (Server error)
2014-01-27 10:28:19: ERROR: Backup failed

From the “start_urbackup_server --remove_unknown” output, I found the following message to be of interest:

2014-01-27 10:18:19: Testing if backup destination can handle subvolumes and snapshots...
Create subvolume '/urbackup/office_backup/testA54hj5luZtlorr494/A'
ERROR: cannot create subvolume - Inappropriate ioctl for device
chown: cannot access `/urbackup/office_backup/testA54hj5luZtlorr494/A': No such file or directory
Creating test subvolume failed
2014-01-27 10:18:19: Backup destination cannot handle subvolumes and snapshots. Snapshots disabled.

Does it provide a hint to the puzzle of a problem that is with STAFF-HP? Any insight or tip is much appreciated!

Here is the full output from “start_urbackup_server --remove_unknown”:

ben@mint-server /etc/init.d $ sudo start_urbackup_server --remove_unknown
2014-01-27 10:17:58: Changing user...
2014-01-27 10:17:58: done.
2014-01-27 10:17:58: Loaded -pychart- plugin
2014-01-27 10:17:58: Loaded -url- plugin
2014-01-27 10:17:58: Loaded -cryptoplugin- plugin
2014-01-27 10:17:58: Loaded -download- plugin
2014-01-27 10:17:58: Loaded -fsimageplugin- plugin
2014-01-27 10:17:58: Starting HTTP-Server on port 55414
2014-01-27 10:17:58: HTTP: Server started up sucessfully!
2014-01-27 10:17:58: Going to remove all unknown files and directories in the urbackup storage directory. Waiting 20 seconds...
2014-01-27 10:18:18: Shutting down all database instances...
2014-01-27 10:18:18: Destroying all databases...
2014-01-27 10:18:18: Opening urbackup server database...
2014-01-27 10:18:18: Created new database connection for urbackup/backup_server.db
2014-01-27 10:18:19: Created new database connection for urbackup/backup_server.db
2014-01-27 10:18:19: Testing if backup destination can handle subvolumes and snapshots...
Create subvolume '/urbackup/office_backup/testA54hj5luZtlorr494/A'
ERROR: cannot create subvolume - Inappropriate ioctl for device
chown: cannot access `/urbackup/office_backup/testA54hj5luZtlorr494/A': No such file or directory
Creating test subvolume failed
2014-01-27 10:18:19: Backup destination cannot handle subvolumes and snapshots. Snapshots disabled.
2014-01-27 10:18:19: Transitioning urbackup server database to different journaling mode...
2014-01-27 10:18:19: Cleaning up 0 percent
2014-01-27 10:18:19: Cleaning up 0 bytes on backup storage
2014-01-27 10:18:19: Database cache size is 400 MB
2014-01-27 10:18:19: Starting cleanup...
2014-01-27 10:18:19: Freeing database connections...
2014-01-27 10:18:19: Destroying all databases...
2014-01-27 10:18:19: Created new database connection for urbackup/backup_server.db
2014-01-27 10:18:19: Enough free space now.
2014-01-27 10:18:19: Enough free space now.
2014-01-27 10:18:19: Updating statistics...
2014-01-27 10:18:19: Copying files from files_new table...
2014-01-27 10:18:19: Deleting contents of files_new table...
2014-01-27 10:18:19: Updating image stats...
2014-01-27 10:18:19: Updating deleted files...
2014-01-27 10:18:19: Updating file stats...
2014-01-27 10:18:19: Done updating statistics.
2014-01-27 10:18:19: Enough free space now.
2014-01-27 10:18:19: Cleanup successfull.
2014-01-27 10:18:19: Created new database connection for urbackup/backup_server.db
2014-01-27 10:18:19: WARNING: File backup "140117-1603" of client "MARLENE-HP" not found in database. Deleting it.
2014-01-27 10:18:20: WARNING: File backup "140117-1606" of client "MARLENE-HP" not found in database. Deleting it.
2014-01-27 10:18:20: WARNING: File backup "140117-1607" of client "MARLENE-HP" not found in database. Deleting it.
2014-01-27 10:18:20: WARNING: File backup "140117-1614" of client "MARLENE-HP" not found in database. Deleting it.
2014-01-27 10:18:20: WARNING: File backup "140117-1622" of client "MARLENE-HP" not found in database. Deleting it.
2014-01-27 10:18:20: WARNING: File backup "140117-1626" of client "MARLENE-HP" not found in database. Deleting it.
2014-01-27 10:18:20: WARNING: File backup "140117-1633" of client "MARLENE-HP" not found in database. Deleting it.
2014-01-27 10:18:20: WARNING: File backup "140117-1639" of client "MARLENE-HP" not found in database. Deleting it.
2014-01-27 10:18:20: WARNING: File backup "140117-1646" of client "MARLENE-HP" not found in database. Deleting it.
2014-01-27 10:18:20: WARNING: File backup "140117-1652" of client "MARLENE-HP" not found in database. Deleting it.
2014-01-27 10:18:20: WARNING: File backup "140117-1659" of client "MARLENE-HP" not found in database. Deleting it.
2014-01-27 10:18:20: WARNING: File backup "140117-1705" of client "MARLENE-HP" not found in database. Deleting it.
2014-01-27 10:18:20: WARNING: File backup "Image_SYSVOL_140113-1413.vhd" of client "MARLENE-HP" not found in database. Deleting it.
2014-01-27 10:18:20: WARNING: File backup "Image_SYSVOL_140113-1413.vhd.hash" of client "MARLENE-HP" not found in database. Deleting it.
2014-01-27 10:18:20: WARNING: File backup "Image_SYSVOL_140117-1413.vhd" of client "MARLENE-HP" not found in database. Deleting it.
2014-01-27 10:18:20: Removing dangling file entries...
2014-01-27 10:18:20: Successfully removed all unknown files in backup directory.