FFS not waiting long enough for USB drive to wake up before sync

Posts: 14 · xenon2000 3 Jul 2013, 15:52

My USB 3 drive will always be sleeping by the time my scheduled job runs. But it always has a popup in the morning because it doesn't see the folders. I press retry, the drive spins up, and syncs. Annoying because none of the syncing happens overnight. It happens after I press retry and the drive spins up. Is there a way to have FFS either wait longer for the drive to spin up? Or to have it auto-retry X number of times before doing the set error action of Ignore or Popup?

Posts: 7211 · Zenju 3 Jul 2013, 15:54

Currently not, but FFS will get this feature in the future:
[404, Invalid URL: https://sourceforge.net/p/freefilesync/feature-requests/257/]

What error message are you seeing?

Posts: 14 · xenon2000 3 Jul 2013, 17:39

Currently not, but FFS will get this feature in the future:
[404, Invalid URL: https://sourceforge.net/p/freefilesync/feature-requests/257/]

What error message are you seeing?Zenju

I will make a screenshot tomorrow morning when I see it again. But it's something about a folder being empty. Which it is not. Of course it's morning when I see it and I click retry and everything goes fine. Including syncing files in the folder it just said was empty. But I will get the screenshot and exact message tomorrow.

Posts: 14 · xenon2000 4 Jul 2013, 19:05

Currently not, but FFS will get this feature in the future:
[404, Invalid URL: https://sourceforge.net/p/freefilesync/feature-requests/257/]

What error message are you seeing?Zenju

Hmm, odd. It didn't have an error last night. But Here is the log details from the night before when it did have the error. As well as last night when it did not have the error. Nothing changed between these. No reboots, logged in for both, same drives, same batch file, same scheduled job and time, etc. I also waited for this to happen 3 days in a row before posting here. The first 3 days of me using this program.

________________________________________________________________________________
|7/2/2013 - SyncSettings_Photos_and_www: Synchronization completed with errors!
|
| Items processed: 10 (2.84 MB)
| Total time: 07:04:12
|______________________________________________________________________________

[1:00:03 AM] Info: Start comparison
[1:00:13 AM] Error: Cannot find the following folders:
P:\usb drive\Chrome bookmarks\
P:\usb drive\IE Favorites\
You can ignore this error to consider each folder as empty. The folders then will be created automatically during synchronization.
[8:04:14 AM] Info: Synchronizing folder pair:
C:\Users\User\AppData\Local\Google\Chrome\User Data\Default\
P:\usb drive\Chrome bookmarks\
[8:04:14 AM] Info: Overwriting file 'P:\usb drive\Chrome bookmarks\Bookmarks'
[8:04:15 AM] Info: Synchronizing folder pair:
D:\Users\User\Favorites\
P:\usb drive\IE Favorites\
[8:04:15 AM] Info: Synchronizing folder pair:
D:\Users\User\Documents\
P:\usb drive\Documents\
[8:04:15 AM] Info: Synchronizing folder pair:
D:\Users\User\Pictures\
P:\usb drive\Photos\
[8:04:15 AM] Info: Synchronizing folder pair:
W:\
P:\WAMP\www\
[8:04:15 AM] Info: Moving file 'P:\WAMP\www\backups_DBs\k201305020100.zip' to recycle bin
[8:04:15 AM] Info: Moving file 'P:\WAMP\www\backups_DBs\s201305020100.zip' to recycle bin
[8:04:15 AM] Info: Creating file 'P:\WAMP\www\backups_DBs\a201307020100.zip'
[8:04:15 AM] Info: Creating file 'P:\WAMP\www\backups_DBs\k201307020100.zip'
[8:04:15 AM] Info: Creating file 'P:\WAMP\www\backups_DBs\t201307020100.zip'
[8:04:15 AM] Info: Creating file 'P:\WAMP\www\backups_DBs\p201307020100.zip'
[8:04:15 AM] Info: Creating file 'P:\WAMP\www\backups_DBs\s201307020101.zip'
[8:04:15 AM] Info: Creating file 'P:\WAMP\www\backups_DBs\h201307020101.zip'
[8:04:16 AM] Error: Synchronization completed with errors!

and here is today that didn't have any errors.
_______________________________________________________________________________
|7/4/2013 - SyncSettings_Photos_and_www: Synchronization completed successfully
|
| Items processed: 8 (1.05 MB)
| Total time: 00:01:37
|______________________________________________________________________________

[1:00:03 AM] Info: Starting comparison
[1:01:40 AM] Info: Synchronizing folder pair:
C:\Users\User\AppData\Local\Google\Chrome\User Data\Default\
P:\usb drive\Chrome bookmarks\
[1:01:40 AM] Info: Synchronizing folder pair:
D:\Users\User\Favorites\
P:\usb drive\IE Favorites\
[1:01:40 AM] Info: Synchronizing folder pair:
D:\Users\User\Documents\
P:\usb drive\Documents\
[1:01:40 AM] Info: Overwriting file 'P:\usb drive\Documents\659.docx'
[1:01:40 AM] Info: Overwriting file 'P:\usb drive\Documents\659.pdf'
[1:01:40 AM] Info: Creating file 'P:\usb drive\Documents\test.pdf'
[1:01:40 AM] Info: Creating file 'P:\usb drive\Documents\Week.docx'
[1:01:40 AM] Info: Creating file 'P:\usb drive\Documents\Week.pdf'
[1:01:41 AM] Info: Creating file 'P:\usb drive\Documents\Receipt.pdf'
[1:01:41 AM] Info: Creating file 'P:\usb drive\Documents\2.jpg'
[1:01:41 AM] Info: Synchronizing folder pair:
D:\Users\User\Pictures\
P:\usb drive\Photos\
[1:01:41 AM] Info: Synchronizing folder pair:
W:\
P:\WAMP\www\
[1:01:41 AM] Info: Creating file 'P:\WAMP\www\backups_DBs\a201307040100.zip'
[1:01:41 AM] Info: Synchronization completed successfully

Posts: 14 · xenon2000 4 Jul 2013, 19:28

While I don't see any logs or other proof, or even a real solid connection here. I do see 1 other task running at 1am. My SQL backup job. While it's not backup up those files when the FFS job runs and it backs up the DB zips just fine. I am going to shift my FFS job to 1:30am so there is nothing going on at all during the backups. Though I don't think that was the issue and it didn't have this last time.

Posts: 7211 · Zenju 4 Jul 2013, 19:31

>[1:00:13 AM] Error: Cannot find the following folders:
> P:\usb drive\Chrome bookmarks\
> P:\usb drive\IE Favorites\

The error message above does not reveal the Win32 error code. FFS is using GetFileAttributes to check file existence. Maybe the error code gives some clue about why Windows did not simply wake up the USB stick. Are you able to reproduce this problem, by somehow forcing the usb stick to sleep?

Posts: 14 · xenon2000 5 Jul 2013, 04:50

>[1:00:13 AM] Error: Cannot find the following folders:
> P:\usb drive\Chrome bookmarks\
> P:\usb drive\IE Favorites\

The error message above does not reveal the Win32 error code. FFS is using GetFileAttributes to check file existence. Maybe the error code gives some clue about why Windows did not simply wake up the USB stick. Are you able to reproduce this problem, by somehow forcing the usb stick to sleep?Zenju

It's a USB 3, 2TB, powered hard drive. I have reduced the sleep time to 1 minute from the previous 2 hour setting. Yet it wakes up quick enough for the job. Which is what made me look at the scheduled tasks for possible conflicts.

We will see if it happens again tomorrow morning. I haven't been able to get the same popup message manually. It has only been the previous 3 days in a row. Today is the first time it has synced without me having to press Retry.

I really wish I made a screenshot of the message. But, the log I shared does have the message that it was displaying in the popup. Which I just copy/pasted here for quick reference.

Error: Cannot find the following folders:
P:\usb drive\Chrome bookmarks\

P:\usb drive\IE Favorites\

You can ignore this error to consider each folder as empty. The folders then will be created automatically during synchronization.

Posts: 7211 · Zenju 5 Jul 2013, 10:15

I've created a modified version of FFS that will show the Windows error next time the directory is not found:
[404, Invalid URL: http://freefilesync.sourceforge.net/FreeFileSync_5.19_beta_Windows_Setup.exe]

Other reasons for not finding a particular folder could be missing permissions in which case the error code will be ERROR_ACCESS_DENIED.

Posts: 14 · xenon2000 5 Jul 2013, 16:57

I've created a modified version of FFS that will show the Windows error next time the directory is not found:
[404, Invalid URL: http://freefilesync.sourceforge.net/FreeFileSync_5.19_beta_Windows_Setup.exe]

Other reasons for not finding a particular folder could be missing permissions in which case the error code will be ERROR_ACCESS_DENIED.Zenju

Thanks, I will try this out. The message didn't happen this morning either. What is odd is that it works after clicking retry and it then moves on with syncing the folder and contents that it just got done saying was empty. Given that the P drive is the USB Hard drive. And the folder are there and working after clicking retry, that it must be because the drive is asleep when it happens.

But not sure why the error hasn't happened the last 2 nights after the first 3 nights it had the error.

Posts: 14 · xenon2000 10 Jul 2013, 03:20

Well, I guess there is nothing to do. If it happens again, I will come back and update. But the first 3 days are the only times it happened. And the only thing I can pinpoint as a difference between those 3 days and the days it has been successful, is a reboot that I manually did for the week. I like to reboot at least once a week. So maybe a pending windows update? No idea.

So it's still working with no errors and the drives still sleep like they did before. Not sure what the message was all about since it was syncing successfully after I clicked retry.

Posts: 14 · xenon2000 29 Aug 2013, 16:02

Error came back. The only thing that has changed since the last time, is that I have been updating as the updates come out. So a days ago, I updated to 5.20. There has been reboots since then.

Here is a screenshot of the error. And of course, if I hit retry, it works fine. It would be nice if there was a "auto retry after x seconds" option.

Posts: 14 · xenon2000 2 Sep 2013, 15:01

Well, 4 days in a row now... still getting the error each morning again. Of course I hit Retry and it works. I don't know why this issue has returned. Last time the issue only lasted 3 days. I am on day 4 now.

Posts: 7211 · Zenju 2 Sep 2013, 15:32

Do you still have the 5.19 beta version from above? I suggest you test with this one, since it has enhanced error reporting and should give an error code for why it did not find the folders.

Posts: 1 · brad_morgan 8 Sep 2013, 14:37

I'm running FFS (5.21) as a scheduled task on Windows 7 and 8. The NAS unit spins down the drives to conserve power. If the drives are spun down when the scheduled task runs, I get the following error(s) in the FFS log:

__________________________________________________________

|9/8/2013 - Virtual5: Synchronization completed with errors

|

|    Items processed: 0

|    Items remaining: 2,117 (248 GB)

|    Total time: 00:00:15

|__________________________________________________________



[6:30:00 AM] Info: Starting comparison

[6:30:10 AM] Error: Cannot find the following folders:

                    \\DLINK1\Volume_1\Virtual5\

                    You can ignore this error to consider each folder as empty. The folders then will be created automatically during synchronization.

[6:30:15 AM] Info: Synchronizing folder pair:

                       E:\Virtual Machines\

                       \\DLINK1\Volume_1\Virtual5\

[6:30:15 AM] Fatal Error: Target folder '\\DLINK1\Volume_1\Virtual5' already existing.

[6:30:15 AM] Error: Synchronization completed with errors

If I change the scheduled task to the following .cmd file, then it completes successfully.

dir \\Dlink1\Volume_1

"C:\Program Files\FreeFileSync\FreeFileSync.exe" Virtual5.ffs_batch

exit

The successful log:

____________________________________________

|9/8/2013 - Virtual5: Nothing to synchronize

|

|    Items processed: 0

|    Total time: 00:00:03

|___________________________________________



[7:38:26 AM] Info: Starting comparison

[7:38:29 AM] Info: Synchronizing folder pair:

                       E:\Virtual Machines\

                       \\DLINK1\Volume_1\Virtual5\

[7:38:29 AM] Info: Nothing to synchronize

I attempted to download the beta version of 5.19, but I got an error. If there's any additional information needed, let me know.

Brad

Posts: 7211 · Zenju 8 Sep 2013, 16:16

@Brad:
FFS 5.21 has a 20 sec timeout, in your log the directory checks fails at exactly 10 seconds, which is the old value. So either you are not using 5.21, or this is not a fault of FFS, but a Windows limit. Let's check this. I've created an updated FFS version which logs the reason for why it cannot find a folder:

[404, Invalid URL: http://freefilesync.sourceforge.net/FFS-5.22-enhanced-error.zip]

Posts: 14 · xenon2000 6 Oct 2013, 19:05

Sorry for the delay. I am now using 5.22 and set it to auto retry. I had been getting the error for weeks now, so it was pretty much constant. I updated to 5.22 and got the error the next day. But I had forgotten to change the setting and enable the retry feature. I did that and this morning I just saw the overview screen. Is there a way to see if the retry feature was actually used? Otherwise I don't know if it succeeded because it just worked, or because it did a retry and then worked. I didn't see mention of a retry in the log tab of the completed window.

Posts: 7211 · Zenju 6 Oct 2013, 19:11

Sorry for the delay. I am now using 5.22 and set it to auto retry. I had been getting the error for weeks now, so it was pretty much constant. I updated to 5.22 and got the error the next day. But I had forgotten to change the setting and enable the retry feature. I did that and this morning I just saw the overview screen. Is there a way to see if the retry feature was actually used? Otherwise I don't know if it succeeded because it just worked, or because it did a retry and then worked. I didn't see mention of a retry in the log tab of the completed window.xenon2000

Retries are logged as an info status message. The info text also distinguishes manual from automatic retries. If you don't see this info, then there haven't been any problems.

Posts: 14 · xenon2000 6 Oct 2013, 23:34

I see. So here is how it looks when it was a manual retry a few days back, using 5.21

>[1:30:03 AM] Info: Starting comparison
>[8:12:38 AM] Info: Retrying operation after error: Cannot find the following folders:

And here is the one from this morning that was successful, using 5.22:

>[1:30:03 AM] Info: Starting comparison
>[1:31:50 AM] Info: Synchronizing folder pair:

So I guess that means my last backup just worked normally, no manual or automatic retries. I will keep viewing the logs. I am curious to see the auto retry function working. Thanks for the addition of the retry function.

Posts: 7211 · Zenju 7 Oct 2013, 09:33

I see. So here is how it looks when it was a manual retry a few days back, using 5.21

>[1:30:03 AM] Info: Starting comparison
>[8:12:38 AM] Info: Retrying operation after error: Cannot find the following folders:

And here is the one from this morning that was successful, using 5.22:

>[1:30:03 AM] Info: Starting comparison
>[1:31:50 AM] Info: Synchronizing folder pair:

So I guess that means my last backup just worked normally, no manual or automatic retries. I will keep viewing the logs. I am curious to see the auto retry function working. Thanks for the addition of the retry function.xenon2000

It seems you're not running FFS 5.22, but an older version.

Posts: 14 · xenon2000 7 Oct 2013, 15:06

It seems you're not running FFS 5.22, but an older version.Zenju

What? The About screen says 5.22 Build Oct 1, 2013 Unicode x64. Why do you say it's not 5.22? And it has the retry function, set to 2 retries, 10 secs. And 5.22 is the only version with this function.

Remember, the first log I commented is from 5.21 without the retry function.

Posts: 7211 · Zenju 7 Oct 2013, 15:19

> the first log I commented is from 5.21 without the retry function.

Allright, then it's fine, I assumed both were supposed to be from 5.22.

Posts: 14 · xenon2000 7 Oct 2013, 17:13

> the first log I commented is from 5.21 without the retry function.

Allright, then it's fine, I assumed both were supposed to be from 5.22.Zenju

Sorry for the confusion. I just edited the log post to make that more clear. Thanks again for adding the retry function. I can't wait to see it actually used as I keep checking the logs. It ran fine again this morning. Then again, installing updates seems to always fix the issue and then it will eventually happen constantly. So we will see if that happens with this version as well. Thanks again.