Client indexing


#1

I have added a client to our urbackup server. It has been indexing for a full week now so I think something is wrong with the way I have set it up. I have attached a bit of the debug log below. All of our other servers seem to back up fine.

2017-08-01 10:14:09: ClientService cmd: STATUS#pw=iMK2k8ftcbECp0JBJVGUKTDrEPapDt
2017-08-01 10:14:11: ClientService cmd: #IApzzbwma2yBSBqCSI7V1#2PING RUNNING pc_done=&status_id=69&speed_bpms=0&total_bytes=-1&done_bytes=0#token=UwWlUcLdvkPwbNfzWPyY
2017-08-01 10:14:21: ClientService cmd: #IApzzbwma2yBSBqCSI7V1#2PING RUNNING pc_done=&status_id=69&speed_bpms=0&total_bytes=-1&done_bytes=0#token=UwWlUcLdvkPwbNfzWPyY
2017-08-01 10:14:31: ClientService cmd: #IApzzbwma2yBSBqCSI7V1#2PING RUNNING pc_done=&status_id=69&speed_bpms=0&total_bytes=-1&done_bytes=0#token=UwWlUcLdvkPwbNfzWPyY
2017-08-01 10:14:41: ClientService cmd: #IApzzbwma2yBSBqCSI7V1#2PING RUNNING pc_done=&status_id=69&speed_bpms=0&total_bytes=-1&done_bytes=0#token=UwWlUcLdvkPwbNfzWPyY
2017-08-01 10:14:51: ClientService cmd: #IApzzbwma2yBSBqCSI7V1#2PING RUNNING pc_done=&status_id=69&speed_bpms=0&total_bytes=-1&done_bytes=0#token=UwWlUcLdvkPwbNfzWPyY
2017-08-01 10:15:01: ClientService cmd: #IApzzbwma2yBSBqCSI7V1#2PING RUNNING pc_done=&status_id=69&speed_bpms=0&total_bytes=-1&done_bytes=0#token=UwWlUcLdvkPwbNfzWPyY
2017-08-01 10:15:01: ClientService cmd: STATUS#pw=iMK2k8ftcbECp0JBJVGUKTDrEPapDt
2017-08-01 10:15:09: ClientService cmd: PONG

#2

I have the same issue with one remote Windows 10 surface pro… issue occurs with server 2.2.3 beta, client 2.2.2 beta… and server 2.1.19, client 2.1.16. All other machines seem to work fine. Client has been reinstalled multiple times.


#3

Sorry you are having issues. To solve the problem the client (debug) log would be useful.
If possible, could you post it or send it?

This post describes how to change the client to debug logging, where it is stored and where to send it to if posting is not possible: Having problems with UrBackup? Please read before posting

Thanks!


#4

this is the debug log on the client… it just continues to display the bottom portion while “indexing” forever

2017-08-09 12:58:19: Successfully connected.
2017-08-09 12:58:27: Started connection to SERVICE_COMMANDS
2017-08-09 12:58:27: ClientService cmd: #I0yz7MLujGbEBy8rUIHck#1CHANNEL capa=9489&token=VLtGKJKos8JvlqDazgBE&restore_version=1&virtual_client=
2017-08-09 12:58:27: New channel: Number of Channels: 1
2017-08-09 12:58:43: ClientService cmd: STATUS#pw=IamC74f9RcRYQeeUDlfpTor9tsWyiR
2017-08-09 12:59:27: ClientService cmd: PONG
2017-08-09 12:59:35: ClientService cmd: STATUS#pw=IamC74f9RcRYQeeUDlfpTor9tsWyiR
2017-08-09 13:00:27: ClientService cmd: PONG
2017-08-09 13:00:27: ClientService cmd: STATUS#pw=IamC74f9RcRYQeeUDlfpTor9tsWyiR
2017-08-09 13:01:19: ClientService cmd: STATUS#pw=IamC74f9RcRYQeeUDlfpTor9tsWyiR
2017-08-09 13:01:27: ClientService cmd: PONG
2017-08-09 13:02:11: ClientService cmd: STATUS#pw=IamC74f9RcRYQeeUDlfpTor9tsWyiR
2017-08-09 13:02:27: ClientService cmd: PONG
2017-08-09 13:03:03: ClientService cmd: STATUS#pw=IamC74f9RcRYQeeUDlfpTor9tsWyiR
2017-08-09 13:03:27: ClientService cmd: PONG
2017-08-09 13:03:55: ClientService cmd: STATUS#pw=IamC74f9RcRYQeeUDlfpTor9tsWyiR
2017-08-09 13:04:27: ClientService cmd: PONG
2017-08-09 13:04:47: ClientService cmd: STATUS#pw=IamC74f9RcRYQeeUDlfpTor9tsWyiR
2017-08-09 13:05:27: ClientService cmd: PONG
2017-08-09 13:05:38: ClientService cmd: STATUS#pw=IamC74f9RcRYQeeUDlfpTor9tsWyiR
2017-08-09 13:06:27: ClientService cmd: PONG
2017-08-09 13:06:29: ClientService cmd: STATUS#pw=IamC74f9RcRYQeeUDlfpTor9tsWyiR
2017-08-09 13:07:21: ClientService cmd: STATUS#pw=IamC74f9RcRYQeeUDlfpTor9tsWyiR
2017-08-09 13:07:27: ClientService cmd: PONG
2017-08-09 13:08:13: ClientService cmd: STATUS#pw=IamC74f9RcRYQeeUDlfpTor9tsWyiR
2017-08-09 13:08:27: ClientService cmd: PONG
2017-08-09 13:09:05: ClientService cmd: STATUS#pw=IamC74f9RcRYQeeUDlfpTor9tsWyiR
2017-08-09 13:09:27: ClientService cmd: PONG
2017-08-09 13:09:56: ClientService cmd: STATUS#pw=IamC74f9RcRYQeeUDlfpTor9tsWyiR
2017-08-09 13:10:27: ClientService cmd: PONG
2017-08-09 13:10:48: ClientService cmd: STATUS#pw=IamC74f9RcRYQeeUDlfpTor9tsWyiR
2017-08-09 13:11:27: ClientService cmd: PONG
2017-08-09 13:11:40: ClientService cmd: STATUS#pw=IamC74f9RcRYQeeUDlfpTor9tsWyiR
2017-08-09 13:12:27: ClientService cmd: PONG
2017-08-09 13:12:32: ClientService cmd: STATUS#pw=IamC74f9RcRYQeeUDlfpTor9tsWyiR
2017-08-09 13:13:24: ClientService cmd: STATUS#pw=IamC74f9RcRYQeeUDlfpTor9tsWyiR
2017-08-09 13:13:27: ClientService cmd: PONG
2017-08-09 13:14:16: ClientService cmd: STATUS#pw=IamC74f9RcRYQeeUDlfpTor9tsWyiR
2017-08-09 13:14:22: Started connection to SERVICE_COMMANDS
2017-08-09 13:14:22: ClientService cmd: #I0yz7MLujGbEBy8rUIHck#2PING RUNNING pc_done=&status_id=102&speed_bpms=0&total_bytes=-1&done_bytes=0&paused_fb=1#token=VLtGKJKos8JvlqDazgBE
2017-08-09 13:14:22: Started connection to SERVICE_COMMANDS
2017-08-09 13:14:22: ClientService cmd: #I0yz7MLujGbEBy8rUIHck#3START FULL BACKUP group=0&running_jobs=1&sha=528&with_permissions=1&with_scripts=1&with_orig_path=1&with_sequence=1&with_proper_symlinks=1&status_id=102&phash=1&async=1#token=VLtGKJKos8JvlqDazgBE
2017-08-09 13:14:22: Async index ce37d54ea26f9deae2742630448a2ed9
2017-08-09 13:14:22: Removing VSS log data...
2017-08-09 13:14:22: rc=0 hasError=true state=0
2017-08-09 13:14:22: SERVICE_COMMANDS finished
2017-08-09 13:14:22: Final path: C:\Users
2017-08-09 13:14:22: Script list at "C:\Program Files\UrBackup\backup_scripts\list.bat" does not exist. Skipping.
2017-08-09 13:14:22: Deleting files... doing full index...
2017-08-09 13:14:22: Started connection to SERVICE_COMMANDS
2017-08-09 13:14:22: ClientService cmd: #I0yz7MLujGbEBy8rUIHck#WAIT FOR INDEX async_id=ce37d54ea26f9deae2742630448a2ed9#token=VLtGKJKos8JvlqDazgBE
2017-08-09 13:14:22: Wait for async index ce37d54ea26f9deae2742630448a2ed9
2017-08-09 13:14:22: Final path: C:\Users
2017-08-09 13:14:22: Started connection to SERVICE_FILESRV
2017-08-09 13:14:22: FileSrv: Received data...
2017-08-09 13:14:22: FileSrv: Received a Packet.
2017-08-09 13:14:22: FileSrv: Sending script output (normal) phash_{9c28ff72-5a74-487b-b5e1-8f1c96cd0cf4}/phash_ce37d54ea26f9deae2742630448a2ed9|0|3290779557|VLtGKJKos8JvlqDazgBE metadata_id=0
2017-08-09 13:14:22: FileSrv: Mapped name: C:\Program Files\UrBackup\urbackup\phash\phash_ce37d54ea26f9deae2742630448a2ed9|0|3290779557|VLtGKJKos8JvlqDazgBE
2017-08-09 13:14:22: Removing deleted directories from index...
2017-08-09 13:14:22: Creating shadowcopy of "Users" in indexDirs()
2017-08-09 13:14:23: ClientService cmd: STATUS#pw=IamC74f9RcRYQeeUDlfpTor9tsWyiR
2017-08-09 13:14:27: ClientService cmd: PONG
2017-08-09 13:14:32: ClientService cmd: #I0yz7MLujGbEBy8rUIHck#2PING RUNNING pc_done=&status_id=102&speed_bpms=0&total_bytes=-1&done_bytes=0&paused_fb=1#token=VLtGKJKos8JvlqDazgBE
2017-08-09 13:14:42: ClientService cmd: #I0yz7MLujGbEBy8rUIHck#2PING RUNNING pc_done=&status_id=102&speed_bpms=0&total_bytes=-1&done_bytes=0&paused_fb=1#token=VLtGKJKos8JvlqDazgBE
2017-08-09 13:14:52: ClientService cmd: #I0yz7MLujGbEBy8rUIHck#2PING RUNNING pc_done=&status_id=102&speed_bpms=0&total_bytes=-1&done_bytes=0&paused_fb=1#token=VLtGKJKos8JvlqDazgBE
2017-08-09 13:15:02: ClientService cmd: #I0yz7MLujGbEBy8rUIHck#2PING RUNNING pc_done=&status_id=102&speed_bpms=0&total_bytes=-1&done_bytes=0&paused_fb=1#token=VLtGKJKos8JvlqDazgBE
2017-08-09 13:15:13: ClientService cmd: #I0yz7MLujGbEBy8rUIHck#2PING RUNNING pc_done=&status_id=102&speed_bpms=0&total_bytes=-1&done_bytes=0&paused_fb=1#token=VLtGKJKos8JvlqDazgBE
2017-08-09 13:15:14: ClientService cmd: STATUS#pw=IamC74f9RcRYQeeUDlfpTor9tsWyiR
2017-08-09 13:15:23: ClientService cmd: #I0yz7MLujGbEBy8rUIHck#2PING RUNNING pc_done=&status_id=102&speed_bpms=0&total_bytes=-1&done_bytes=0&paused_fb=1#token=VLtGKJKos8JvlqDazgBE
2017-08-09 13:15:27: ClientService cmd: PONG
2017-08-09 13:15:33: ClientService cmd: #I0yz7MLujGbEBy8rUIHck#2PING RUNNING pc_done=&status_id=102&speed_bpms=0&total_bytes=-1&done_bytes=0&paused_fb=1#token=VLtGKJKos8JvlqDazgBE
2017-08-09 13:15:43: ClientService cmd: #I0yz7MLujGbEBy8rUIHck#2PING RUNNING pc_done=&status_id=102&speed_bpms=0&total_bytes=-1&done_bytes=0&paused_fb=1#token=VLtGKJKos8JvlqDazgBE
2017-08-09 13:15:53: ClientService cmd: #I0yz7MLujGbEBy8rUIHck#2PING RUNNING pc_done=&status_id=102&speed_bpms=0&total_bytes=-1&done_bytes=0&paused_fb=1#token=VLtGKJKos8JvlqDazgBE
2017-08-09 13:16:03: ClientService cmd: #I0yz7MLujGbEBy8rUIHck#2PING RUNNING pc_done=&status_id=102&speed_bpms=0&total_bytes=-1&done_bytes=0&paused_fb=1#token=VLtGKJKos8JvlqDazgBE
2017-08-09 13:16:06: ClientService cmd: STATUS#pw=IamC74f9RcRYQeeUDlfpTor9tsWyiR
2017-08-09 13:16:13: ClientService cmd: #I0yz7MLujGbEBy8rUIHck#2PING RUNNING pc_done=&status_id=102&speed_bpms=0&total_bytes=-1&done_bytes=0&paused_fb=1#token=VLtGKJKos8JvlqDazgBE
2017-08-09 13:16:23: ClientService cmd: #I0yz7MLujGbEBy8rUIHck#2PING RUNNING pc_done=&status_id=102&speed_bpms=0&total_bytes=-1&done_bytes=0&paused_fb=1#token=VLtGKJKos8JvlqDazgBE
2017-08-09 13:16:27: ClientService cmd: PONG

#5

Looks like it hangs in shadow copy creation. I’d:

  1. Check the Windows event log for issues
  2. Check for unusual vss providers (vssadmin list providers) and writers (vssadmin list writers) and uninstall them if present
  3. Create a memory dump of UrBackupBackend.exe and send that to me (e.g. via task manager https://blogs.msdn.microsoft.com/debugger/2009/12/30/what-is-a-dump-and-how-do-i-create-one/ )

#6

After removing the client on the server, waiting for removal period, and than manually deleting a couple lingering backups on the server and reinstalling the client, the issue is resolved.