SyncTrayzor launches twice at startup

[stuartpb]

I'm not sure what is triggering this, but for some reason, every time I start Windows, I see two instances of SyncTrayzor launch (the second one usually failing due to a resource lock with the first one).

Based on information from Process Explorer, both of these are using the same image (C:\Program Files\SyncTrayzor\SyncTrayzor.exe), and appear to be triggered by the same autostart location (HKCU\SOFTWARE\Microsoft\Windows\CurrentVersion\Run\SyncTrayzor).

The first process is recorded as having started at 3:11:43 PM, and the second as having started at 3:11:44 PM.

[stuartpb]

Relevant logs:

2016-03-21 15:14:07.2087 #332 [Debug] SyncTrayzor.Bootstrapper: SyncTrazor version 1.1.8.0 (Amd64) started at C:\Program Files\SyncTrayzor\SyncTrayzor.exe (.NET version: 4.6.1 on Windows 10 November Update systems (394254)) 
2016-03-21 15:14:08.6320 #332 [Info] SyncTrayzor.Services.SingleApplicationInstanceManager: Checking for other SyncTrayzor processes 
2016-03-21 15:14:08.6551 #332 [Info] SyncTrayzor.Services.SingleApplicationInstanceManager: Found process with ID 2648 and location C:\Program Files\SyncTrayzor\SyncTrayzor.exe. Asking it to show its main window... 
2016-03-21 15:14:07.2087 #2648 [Debug] SyncTrayzor.Bootstrapper: SyncTrazor version 1.1.8.0 (Amd64) started at C:\Program Files\SyncTrayzor\SyncTrayzor.exe (.NET version: 4.6.1 on Windows 10 November Update systems (394254)) 
2016-03-21 15:14:09.1898 #2648 [Info] SyncTrayzor.Services.SingleApplicationInstanceManager: Checking for other SyncTrayzor processes 
2016-03-21 15:14:09.1951 #2648 [Info] SyncTrayzor.Services.SingleApplicationInstanceManager: Found process with ID 332 and location C:\Program Files\SyncTrayzor\SyncTrayzor.exe. Asking it to show its main window... 
2016-03-21 15:14:09.6913 #2648 [Error] SyncTrayzor.Services.SingleApplicationInstanceManager: Process produced an error System.TimeoutException The operation has timed out. Void Connect(Int32)    at System.IO.Pipes.NamedPipeClientStream.Connect(Int32 timeout)
   at SyncTrayzor.Services.IpcCommsClient.SendCommand(Int32 pid, String command) in C:\projects\synctrayzor\src\SyncTrayzor\Services\IpcCommsClient.cs:line 33
   at SyncTrayzor.Services.SingleApplicationInstanceManager.ShouldExit() in C:\projects\synctrayzor\src\SyncTrayzor\Services\SingleApplicationInstanceManager.cs:line 47 System.TimeoutException: The operation has timed out.
   at System.IO.Pipes.NamedPipeClientStream.Connect(Int32 timeout)
   at SyncTrayzor.Services.IpcCommsClient.SendCommand(Int32 pid, String command) in C:\projects\synctrayzor\src\SyncTrayzor\Services\IpcCommsClient.cs:line 33
   at SyncTrayzor.Services.SingleApplicationInstanceManager.ShouldExit() in C:\projects\synctrayzor\src\SyncTrayzor\Services\SingleApplicationInstanceManager.cs:line 47
2016-03-21 15:14:10.8536 #2648 [Info] SyncTrayzor.Services.SingleApplicationInstanceManager: Did not find any other processes, or they all responded with an error. Indicating no close 
2016-03-21 15:14:10.8726 #2648 [Debug] SyncTrayzor.Services.Config.ApplicationPathsProvider: ExePath: C:\Program Files\SyncTrayzor 
2016-03-21 15:14:10.8726 #2648 [Debug] SyncTrayzor.Services.Config.ApplicationPathsProvider: LogFilePath: C:\Users\Stuart\AppData\Roaming\SyncTrayzor\logs 
2016-03-21 15:14:10.8791 #2648 [Debug] SyncTrayzor.Services.Config.ApplicationPathsProvider: SyncthingBackupPath: C:\Program Files\SyncTrayzor\syncthing.exe 
2016-03-21 15:14:10.8791 #2648 [Debug] SyncTrayzor.Services.Config.ApplicationPathsProvider: ConfigurationFilePath: C:\Users\Stuart\AppData\Roaming\SyncTrayzor\config.xml 
2016-03-21 15:14:10.8791 #2648 [Debug] SyncTrayzor.Services.Config.ApplicationPathsProvider: ConfigurationFileBackupPath: C:\Users\Stuart\AppData\Roaming\SyncTrayzor\config-backups 
2016-03-21 15:14:10.8791 #2648 [Debug] SyncTrayzor.Services.Config.ApplicationPathsProvider: CefCachePath: C:\Users\Stuart\AppData\Local\SyncTrayzor\cef\cache 
2016-03-21 15:14:09.3889 #332 [Error] SyncTrayzor.Services.SingleApplicationInstanceManager: Process produced an error System.TimeoutException The operation has timed out. Void Connect(Int32)    at System.IO.Pipes.NamedPipeClientStream.Connect(Int32 timeout)
   at SyncTrayzor.Services.IpcCommsClient.SendCommand(Int32 pid, String command) in C:\projects\synctrayzor\src\SyncTrayzor\Services\IpcCommsClient.cs:line 33
   at SyncTrayzor.Services.SingleApplicationInstanceManager.ShouldExit() in C:\projects\synctrayzor\src\SyncTrayzor\Services\SingleApplicationInstanceManager.cs:line 47 System.TimeoutException: The operation has timed out.
   at System.IO.Pipes.NamedPipeClientStream.Connect(Int32 timeout)
   at SyncTrayzor.Services.IpcCommsClient.SendCommand(Int32 pid, String command) in C:\projects\synctrayzor\src\SyncTrayzor\Services\IpcCommsClient.cs:line 33
   at SyncTrayzor.Services.SingleApplicationInstanceManager.ShouldExit() in C:\projects\synctrayzor\src\SyncTrayzor\Services\SingleApplicationInstanceManager.cs:line 47
2016-03-21 15:14:10.9011 #332 [Info] SyncTrayzor.Services.SingleApplicationInstanceManager: Did not find any other processes, or they all responded with an error. Indicating no close 
2016-03-21 15:14:10.9011 #332 [Debug] SyncTrayzor.Services.Config.ApplicationPathsProvider: ExePath: C:\Program Files\SyncTrayzor 
2016-03-21 15:14:10.9121 #332 [Debug] SyncTrayzor.Services.Config.ApplicationPathsProvider: LogFilePath: C:\Users\Stuart\AppData\Roaming\SyncTrayzor\logs 
2016-03-21 15:14:10.9121 #332 [Debug] SyncTrayzor.Services.Config.ApplicationPathsProvider: SyncthingBackupPath: C:\Program Files\SyncTrayzor\syncthing.exe 
2016-03-21 15:14:10.9121 #332 [Debug] SyncTrayzor.Services.Config.ApplicationPathsProvider: ConfigurationFilePath: C:\Users\Stuart\AppData\Roaming\SyncTrayzor\config.xml 
2016-03-21 15:14:10.9121 #332 [Debug] SyncTrayzor.Services.Config.ApplicationPathsProvider: ConfigurationFileBackupPath: C:\Users\Stuart\AppData\Roaming\SyncTrayzor\config-backups 
2016-03-21 15:14:10.9121 #332 [Debug] SyncTrayzor.Services.Config.ApplicationPathsProvider: CefCachePath: C:\Users\Stuart\AppData\Local\SyncTrayzor\cef\cache 
2016-03-21 15:14:12.1196 #2648 [Debug] SyncTrayzor.Services.Config.ConfigurationProvider: Loaded default configuration: <Configuration ShowTrayIconOnlyOnClose=False MinimizeToTray=False CloseToTray=True ShowDeviceConnectivityBalloons=True ShowDeviceOrFolderRejectedBalloons=True SyncthingAddress=localhost:8384 StartSyncthingAutomatically=True SyncthingCommandLineFlags=[]SyncthingApiKey= SyncthingEnvironmentalVariables=[] SyncthingUseCustomHome=False SyncthingDenyUpgrade=False SyncthingPriorityLevel=Normal Folders=[] NotifyOfNewVersions=True LatestNotifiedVersion= ObfuscateDeviceIDs=True UseComputerCulture=True SyncthingConsoleHeight=100 WindowPlacement= SyncthingWebBrowserZoomLevel=0 LastSeenInstallCount=0 SyncthingPath=%APPDATA%\SyncTrayzor\syncthing.exe SyncthingCustomHomePath=%LOCALAPPDATA%\SyncTrayzor\syncthing ShowSynchronizedBalloonEvenIfNothingDownloaded=False DisableHardwareRendering=False EnableFailedTransferAlerts=True EnableConflictFileMonitoring=True SyncthingDebugFacilities=[] ConflictResolverDeletesToRecycleBin=True PauseDevicesOnMeteredNetworks=True HaveDonated=False> 
2016-03-21 15:14:12.1196 #332 [Debug] SyncTrayzor.Services.Config.ConfigurationProvider: Loaded default configuration: <Configuration ShowTrayIconOnlyOnClose=False MinimizeToTray=False CloseToTray=True ShowDeviceConnectivityBalloons=True ShowDeviceOrFolderRejectedBalloons=True SyncthingAddress=localhost:8384 StartSyncthingAutomatically=True SyncthingCommandLineFlags=[]SyncthingApiKey= SyncthingEnvironmentalVariables=[] SyncthingUseCustomHome=False SyncthingDenyUpgrade=False SyncthingPriorityLevel=Normal Folders=[] NotifyOfNewVersions=True LatestNotifiedVersion= ObfuscateDeviceIDs=True UseComputerCulture=True SyncthingConsoleHeight=100 WindowPlacement= SyncthingWebBrowserZoomLevel=0 LastSeenInstallCount=0 SyncthingPath=%APPDATA%\SyncTrayzor\syncthing.exe SyncthingCustomHomePath=%LOCALAPPDATA%\SyncTrayzor\syncthing ShowSynchronizedBalloonEvenIfNothingDownloaded=False DisableHardwareRendering=False EnableFailedTransferAlerts=True EnableConflictFileMonitoring=True SyncthingDebugFacilities=[] ConflictResolverDeletesToRecycleBin=True PauseDevicesOnMeteredNetworks=True HaveDonated=False> 
2016-03-21 15:14:12.3191 #2648 [Debug] SyncTrayzor.Services.Config.ConfigurationProvider: Found existing configuration at C:\Users\Stuart\AppData\Roaming\SyncTrayzor\config.xml 
2016-03-21 15:14:12.3191 #332 [Debug] SyncTrayzor.Services.Config.ConfigurationProvider: Found existing configuration at C:\Users\Stuart\AppData\Roaming\SyncTrayzor\config.xml 
2016-03-21 15:14:14.8988 #2648 [Info] SyncTrayzor.Services.AutostartProvider: Have read/write access to the registry 
2016-03-21 15:14:14.9118 #332 [Info] SyncTrayzor.Services.AutostartProvider: Have read/write access to the registry 
2016-03-21 15:14:32.3007 #2648 [Info] SyncTrayzor.Services.Conflicts.ConflictFileWatcher: Refreshing conflicted files. Found 0 from 0 options 
2016-03-21 15:14:32.3007 #332 [Info] SyncTrayzor.Services.Conflicts.ConflictFileWatcher: Refreshing conflicted files. Found 0 from 0 options 
2016-03-21 15:14:34.3867 #2648 [Debug] SyncTrayzor.Syncthing.SyncthingProcessRunner: SyncthingProcessRunner.Start called 
2016-03-21 15:14:34.3867 #332 [Debug] SyncTrayzor.Syncthing.SyncthingProcessRunner: SyncthingProcessRunner.Start called 
2016-03-21 15:14:34.7116 #2648 [Debug] SyncTrayzor.Syncthing.FreePortFinder: Found free port: 8384 
2016-03-21 15:14:34.7342 #2648 [Debug] SyncTrayzor.Syncthing.SyncthingManager: Request to set state: Stopped -> Starting 
2016-03-21 15:14:34.7362 #332 [Debug] SyncTrayzor.Syncthing.FreePortFinder: Found free port: 8385 
2016-03-21 15:14:34.7432 #2648 [Debug] SyncTrayzor.Syncthing.SyncthingManager: Setting state: Stopped -> Starting 
2016-03-21 15:14:34.7532 #332 [Debug] SyncTrayzor.Syncthing.SyncthingManager: Request to set state: Stopped -> Starting 
2016-03-21 15:14:34.7552 #2648 [Info] SyncTrayzor.Syncthing.SyncthingProcessRunner: Starting syncthing: C:\Users\Stuart\AppData\Roaming\SyncTrayzor\syncthing.exe 
2016-03-21 15:14:34.7572 #332 [Debug] SyncTrayzor.Syncthing.SyncthingManager: Setting state: Stopped -> Starting 
2016-03-21 15:14:34.7572 #332 [Info] SyncTrayzor.Syncthing.SyncthingProcessRunner: Starting syncthing: C:\Users\Stuart\AppData\Roaming\SyncTrayzor\syncthing.exe 
2016-03-21 15:14:36.7168 #2648 [Debug] SyncTrayzor.Syncthing.SyncthingManager: Starting API clients 
2016-03-21 15:14:36.7178 #332 [Debug] SyncTrayzor.Syncthing.SyncthingManager: Starting API clients 
2016-03-21 15:14:37.8799 #332 [Debug] SyncTrayzor.Syncthing.ApiClient.SyncthingApiClientFactory: Attempting to request API 
2016-03-21 15:14:37.8799 #2648 [Debug] SyncTrayzor.Syncthing.ApiClient.SyncthingApiClientFactory: Attempting to request API 
2016-03-21 15:14:37.9489 #2648 [Debug] SyncTrayzor.Syncthing.SyncthingProcessRunner: [MQW4Y] 15:14:37 INFO: syncthing v0.12.20 "Beryllium Bedbug" (go1.6 windows-amd64) WIN-P6RP886TVDJ\Administrator@WIN-P6RP886TVDJ 2016-03-06 10:59:03 UTC 
2016-03-21 15:14:37.9489 #332 [Debug] SyncTrayzor.Syncthing.SyncthingProcessRunner: [MQW4Y] 15:14:37 INFO: syncthing v0.12.20 "Beryllium Bedbug" (go1.6 windows-amd64) WIN-P6RP886TVDJ\Administrator@WIN-P6RP886TVDJ 2016-03-06 10:59:03 UTC 
2016-03-21 15:14:38.0509 #2648 [Debug] SyncTrayzor.Syncthing.SyncthingProcessRunner: [MQW4Y] 15:14:37 INFO: My ID: MQW4Y3H 
2016-03-21 15:14:38.1910 #2648 [Debug] SyncTrayzor.Syncthing.SyncthingProcessRunner: [MQW4Y] 15:14:38 INFO: Single thread hash performance is ~184 MB/s 
2016-03-21 15:14:38.0539 #332 [Debug] SyncTrayzor.Syncthing.SyncthingProcessRunner: [MQW4Y] 15:14:37 INFO: My ID: MQW4Y3H 
2016-03-21 15:14:38.2415 #332 [Debug] SyncTrayzor.Syncthing.SyncthingProcessRunner: [MQW4Y] 15:14:38 INFO: Single thread hash performance is ~187 MB/s 
2016-03-21 15:14:38.7362 #2648 [Debug] SyncTrayzor.Syncthing.SyncthingProcessRunner: [MQW4Y] 15:14:38 FATAL: Cannot open database: The process cannot access the file because it is being used by another process. - Is another copy of Syncthing already running? 
2016-03-21 15:14:38.8353 #2648 [Info] SyncTrayzor.Syncthing.SyncthingProcessRunner: Syncthing process stopped with exit status Error 
2016-03-21 15:14:38.8353 #2648 [Debug] SyncTrayzor.Syncthing.SyncthingManager: Request to set state: Starting -> Stopped 
2016-03-21 15:14:38.8503 #2648 [Debug] SyncTrayzor.Syncthing.SyncthingManager: Setting state: Starting -> Stopped 
2016-03-21 15:14:38.8503 #2648 [Debug] SyncTrayzor.Syncthing.SyncthingManager: Aborting API clients 
2016-03-21 15:14:39.7776 #332 [Debug] SyncTrayzor.Syncthing.SyncthingProcessRunner: [MQW4Y] 15:14:39 OK: Ready to synchronize MinecraftWorlds (read-write) 
2016-03-21 15:14:39.7845 #332 [Debug] SyncTrayzor.Syncthing.SyncthingProcessRunner: [MQW4Y] 15:14:39 INFO: Using discovery server https://discovery-v4-1.syncthing.net/?id=SR7AARM 
2016-03-21 15:14:39.7845 #332 [Debug] SyncTrayzor.Syncthing.SyncthingProcessRunner: [MQW4Y] 15:14:39 INFO: Using discovery server https://discovery-v4-2.syncthing.net/?id=DVU36WY 
2016-03-21 15:14:39.7845 #332 [Debug] SyncTrayzor.Syncthing.SyncthingProcessRunner: [MQW4Y] 15:14:39 INFO: Using discovery server https://discovery-v4-3.syncthing.net/?id=VK6HNJ3 
2016-03-21 15:14:39.7845 #332 [Debug] SyncTrayzor.Syncthing.SyncthingProcessRunner: [MQW4Y] 15:14:39 INFO: Using discovery server https://discovery-v6-1.syncthing.net/?id=SR7AARM 
2016-03-21 15:14:39.8021 #332 [Debug] SyncTrayzor.Syncthing.SyncthingProcessRunner: [MQW4Y] 15:14:39 INFO: Using discovery server https://discovery-v6-2.syncthing.net/?id=DVU36WY 
2016-03-21 15:14:39.8021 #332 [Debug] SyncTrayzor.Syncthing.SyncthingProcessRunner: [MQW4Y] 15:14:39 INFO: Using discovery server https://discovery-v6-3.syncthing.net/?id=VK6HNJ3 
2016-03-21 15:14:40.0467 #332 [Debug] SyncTrayzor.Syncthing.SyncthingProcessRunner: [MQW4Y] 15:14:40 INFO: Completed initial scan (rw) of folder MinecraftWorlds 
2016-03-21 15:14:40.1325 #332 [Debug] SyncTrayzor.Syncthing.SyncthingProcessRunner: [MQW4Y] 15:14:40 INFO: Device MQW4Y3H is "Stutendo" at [dynamic] 
2016-03-21 15:14:40.1325 #332 [Debug] SyncTrayzor.Syncthing.SyncthingProcessRunner: [MQW4Y] 15:14:40 INFO: Device 7S246U2 is "Stubatty" at [dynamic] 
2016-03-21 15:14:40.3303 #332 [Debug] SyncTrayzor.Syncthing.SyncthingProcessRunner: [MQW4Y] 15:14:40 INFO: API listening on 127.0.0.1:8385 
2016-03-21 15:14:40.3333 #332 [Debug] SyncTrayzor.Syncthing.SyncthingProcessRunner: [MQW4Y] 15:14:40 INFO: GUI URL is http://localhost:8385/ 
2016-03-21 15:14:44.2494 #2648 [Debug] SyncTrayzor.Bootstrapper: Cleaning up config folder path 
2016-03-21 15:14:44.2504 #332 [Debug] SyncTrayzor.Bootstrapper: Cleaning up config folder path 
2016-03-21 15:14:44.2624 #2648 [Info] SyncTrayzor.Services.Conflicts.ConflictFileWatcher: Refreshing conflicted files. Found 0 from 0 options 
2016-03-21 15:14:44.3671 #2648 [Info] SyncTrayzor.Services.Conflicts.ConflictFileWatcher: Refreshing conflicted files. Found 0 from 0 options 
2016-03-21 15:14:44.4792 #332 [Info] SyncTrayzor.Services.Conflicts.ConflictFileWatcher: Refreshing conflicted files. Found 0 from 0 options 
2016-03-21 15:14:46.7979 #2648 [Debug] SyncTrayzor.Syncthing.ApiClient.SyncthingApiClientFactory: Failed to connect on attempt 0 
2016-03-21 15:14:46.8014 #2648 [Info] SyncTrayzor.Syncthing.SyncthingManager: StartClientAsync aborted 
2016-03-21 15:14:48.7252 #332 [Debug] SyncTrayzor.Syncthing.ApiClient.SyncthingApiClient: Fetched version: <Version arch=amd64 longVersion=syncthing v0.12.20 "Beryllium Bedbug" (go1.6 windows-amd64) WIN-P6RP886TVDJ\Administrator@WIN-P6RP886TVDJ 2016-03-06 10:59:03 UTC os=windows version=v0.12.20> 
2016-03-21 15:14:48.7252 #332 [Debug] SyncTrayzor.Syncthing.ApiClient.SyncthingApiClientFactory: Success! 
2016-03-21 15:14:48.7252 #332 [Debug] SyncTrayzor.Syncthing.SyncthingManager: Have the API client! It's SyncthingApiClient 
2016-03-21 15:14:48.7252 #332 [Debug] SyncTrayzor.Syncthing.SyncthingManager: Request to set state: Starting -> Running 
2016-03-21 15:14:48.7252 #332 [Debug] SyncTrayzor.Syncthing.SyncthingManager: Setting state: Starting -> Running 
2016-03-21 15:14:48.8857 #332 [Debug] SyncTrayzor.Syncthing.SyncthingManager: Startup Complete! Loading startup data 
2016-03-21 15:14:49.1498 #332 [Debug] SyncTrayzor.Syncthing.ApiClient.SyncthingApiClient: Fetched version: <Version arch=amd64 longVersion=syncthing v0.12.20 "Beryllium Bedbug" (go1.6 windows-amd64) WIN-P6RP886TVDJ\Administrator@WIN-P6RP886TVDJ 2016-03-06 10:59:03 UTC os=windows version=v0.12.20> 
2016-03-21 15:14:49.2499 #332 [Debug] SyncTrayzor.Syncthing.ApiClient.SyncthingApiClient: Fetched system info: <SystemInfo alloc=7414816 cpuPercent=0.644446 goroutines=72 myId=MQW4Y3H-3E5KYXG-ZA3RGLA-NYISMVM-3P5BZYE-6P27TZ2-DBN3Q2O-FC7G2A6 pathSeparator=\ sys=21182712 tilde=C:\Users\Stuart> 
2016-03-21 15:14:49.3830 #332 [Debug] SyncTrayzor.Syncthing.ApiClient.SyncthingApiClient: Got debug facilities: <DebugFacilities Enabled= Facilities=beacon=Multicast and broadcast discovery,config=Configuration loading and saving,connections=Connection handling,db=The database layer,dialer=Dialing connections,discover=Remote device discovery,events=Event generation and logging,http=REST API,main=Main package,model=The root hub,protocol=The BEP protocol,relay=Relay connection handling,scanner=File change detection and hashing,stats=Persistent device and folder statistics,sync=Mutexes,upgrade=Binary upgrades,upnp=UPnP discovery and port mapping,versioner=File versioning> 
2016-03-21 15:14:49.5349 #332 [Debug] SyncTrayzor.Syncthing.ApiClient.SyncthingApiClient: Fetched configuration: <Config version=12 folders=[<Folder id=MinecraftWorlds path=C:\Users\Stuart\Sync\MinecraftWorlds devices=[<Device deviceId=MQW4Y3H-3E5KYXG-ZA3RGLA-NYISMVM-3P5BZYE-6P27TZ2-DBN3Q2O-FC7G2A6>, <Device deviceId=7S246U2-CC2OXLF-W3IUW6Y-FR7G4TL-NGSIGSP-EAQLPLO-WRO5IVI-7VIMWQW>] readonly=False rescalinterval=00:01:00 invalid=>] devices=[Device id=MQW4Y3H-3E5KYXG-ZA3RGLA-NYISMVM-3P5BZYE-6P27TZ2-DBN3Q2O-FC7G2A6 name=Stutendo addresses=[dynamic] compression=N/A certname= isintroducer=False>, Device id=7S246U2-CC2OXLF-W3IUW6Y-FR7G4TL-NGSIGSP-EAQLPLO-WRO5IVI-7VIMWQW name=Stubatty addresses=[dynamic] compression=N/A certname= isintroducer=False>]> 
2016-03-21 15:14:50.0201 #332 [Debug] SyncTrayzor.Syncthing.SyncthingProcessRunner: [MQW4Y] 15:14:50 WARNING: Failed to set UPnP port mapping: external port 0 on device 'DIR-808L' (192.168.0.1). 
2016-03-21 15:14:53.4042 #332 [Debug] SyncTrayzor.Syncthing.ApiClient.SyncthingApiClient: Fetched folder status for folder MinecraftWorlds: <FolderStatus GlobalBytes=6606095 GlobalDeleted=0 GlobalFiles=13 LocalBytes=6606095 LocalDeleted=0 LocalFiles=13 InSyncBytes=6606095 InSyncFiles=13 NeedBytes=0 NeedFiles=0 IgnorePattners=False, Invalid= State=idle StateChanged=3/21/2016 3:14:40 PM Version=16> 
2016-03-21 15:14:53.4379 #332 [Debug] SyncTrayzor.Syncthing.ApiClient.SyncthingApiClient: Fetched ignores for folderid MinecraftWorlds: <Ignores ignore=[] patterns=[]> 
2016-03-21 15:14:53.6022 #332 [Debug] SyncTrayzor.Services.Conflicts.ConflictFileWatcher: Starting watcher for folder: MinecraftWorlds 
2016-03-21 15:14:53.6257 #332 [Debug] SyncTrayzor.Services.Conflicts.ConflictFileWatcher: Scanning folder MinecraftWorlds (C:\Users\Stuart\Sync\MinecraftWorlds) for conflict files 
2016-03-21 15:14:54.1148 #332 [Debug] SyncTrayzor.Services.Conflicts.ConflictFileManager: Looking for conflicts in C:\Users\Stuart\Sync\MinecraftWorlds 
2016-03-21 15:14:54.8306 #332 [Debug] SyncTrayzor.Services.Config.ConfigurationProvider: Saving configuration atomically: <Configuration ShowTrayIconOnlyOnClose=False MinimizeToTray=False CloseToTray=True ShowDeviceConnectivityBalloons=True ShowDeviceOrFolderRejectedBalloons=True SyncthingAddress=localhost:8384 StartSyncthingAutomatically=True SyncthingCommandLineFlags=[]SyncthingApiKey= SyncthingEnvironmentalVariables=[] SyncthingUseCustomHome=False SyncthingDenyUpgrade=False SyncthingPriorityLevel=Normal Folders=[<Folder ID=MinecraftWorlds IsWatched=True NotificationsEnabled=True>] NotifyOfNewVersions=True LatestNotifiedVersion= ObfuscateDeviceIDs=True UseComputerCulture=True SyncthingConsoleHeight=100 WindowPlacement= SyncthingWebBrowserZoomLevel=0 LastSeenInstallCount=13 SyncthingPath=%APPDATA%\SyncTrayzor\syncthing.exe SyncthingCustomHomePath=%LOCALAPPDATA%\SyncTrayzor\syncthing ShowSynchronizedBalloonEvenIfNothingDownloaded=False DisableHardwareRendering=False EnableFailedTransferAlerts=True EnableConflictFileMonitoring=True SyncthingDebugFacilities=[] ConflictResolverDeletesToRecycleBin=True PauseDevicesOnMeteredNetworks=True HaveDonated=False> 
2016-03-21 15:14:55.0485 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: Received 1 events 
2016-03-21 15:14:55.0765 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: <GenericEvent ID=6 Type=RelayStateChanged Time=3/21/2016 3:14:49 PM Data={"new":["relay://104.236.166.46:22222/?id=A3IUKMJ-BTA5WGI-C6K46AD-XRPKCMF-IWFN2CS-XTXQ7MQ-5MZSFEZ-NJQHQQL&pingInterval=20s&networkTimeout=2m0s&sessionLimitBps=1048576&globalLimitBps=104857600&statusAddr=:22070&providedBy=https://sowingseasons.com - Blake VandeMerwe - San Francisco CA USA"],"old":null}> 
2016-03-21 15:15:32.6252 #332 [Debug] SyncTrayzor.Services.UpdateManagement.UpdateNotificationClient: Fetched updates response: <UpdateNotificationResponse data= error=> 
2016-03-21 15:15:32.6352 #332 [Info] SyncTrayzor.Services.UpdateManagement.UpdateChecker: No updates available 
2016-03-21 15:15:32.7943 #2648 [Debug] SyncTrayzor.Services.UpdateManagement.UpdateNotificationClient: Fetched updates response: <UpdateNotificationResponse data= error=> 
2016-03-21 15:15:32.8103 #2648 [Info] SyncTrayzor.Services.UpdateManagement.UpdateChecker: No updates available 
2016-03-21 15:15:40.1361 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: Received 1 events 
2016-03-21 15:15:40.1361 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: <GenericEvent ID=7 Type=Ping Time=3/21/2016 3:15:40 PM Data=null> 
2016-03-21 15:15:43.7568 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: Received 1 events 
2016-03-21 15:15:43.7568 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: <StateChangedEvent ID=8 Time=3/21/2016 3:15:43 PM Folder=MinecraftWorlds From=idle To=scanning Duration=00:01:03.6980000> 
2016-03-21 15:15:43.7568 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: Received 1 events 
2016-03-21 15:15:43.7728 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: <StateChangedEvent ID=9 Time=3/21/2016 3:15:43 PM Folder=MinecraftWorlds From=scanning To=idle Duration=00:00:00.0030000> 
2016-03-21 15:16:29.6375 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: Received 1 events 
2016-03-21 15:16:29.6375 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: <StateChangedEvent ID=10 Time=3/21/2016 3:16:29 PM Folder=MinecraftWorlds From=idle To=scanning Duration=00:00:45.8810000> 
2016-03-21 15:16:29.6721 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: Received 1 events 
2016-03-21 15:16:29.6755 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: <StateChangedEvent ID=11 Time=3/21/2016 3:16:29 PM Folder=MinecraftWorlds From=scanning To=idle Duration=00:00:00.0030000> 
2016-03-21 15:16:40.1367 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: Received 1 events 
2016-03-21 15:16:40.1367 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: <GenericEvent ID=12 Type=Ping Time=3/21/2016 3:16:40 PM Data=null> 
2016-03-21 15:17:23.2080 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: Received 1 events 
2016-03-21 15:17:23.2271 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: <StateChangedEvent ID=13 Time=3/21/2016 3:17:23 PM Folder=MinecraftWorlds From=idle To=scanning Duration=00:00:53.5750000> 
2016-03-21 15:17:23.2271 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: Received 1 events 
2016-03-21 15:17:23.2271 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: <StateChangedEvent ID=14 Time=3/21/2016 3:17:23 PM Folder=MinecraftWorlds From=scanning To=idle Duration=00:00:00.0200000> 
2016-03-21 15:17:40.1371 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: Received 1 events 
2016-03-21 15:17:40.1371 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: <GenericEvent ID=15 Type=Ping Time=3/21/2016 3:17:40 PM Data=null> 
2016-03-21 15:18:24.3178 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: Received 1 events 
2016-03-21 15:18:24.3178 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: <StateChangedEvent ID=16 Time=3/21/2016 3:18:24 PM Folder=MinecraftWorlds From=idle To=scanning Duration=00:01:01.0890000> 
2016-03-21 15:18:24.3178 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: Received 1 events 
2016-03-21 15:18:24.3178 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: <StateChangedEvent ID=17 Time=3/21/2016 3:18:24 PM Folder=MinecraftWorlds From=scanning To=idle Duration=00:00:00.0030000> 
2016-03-21 15:18:40.1384 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: Received 1 events 
2016-03-21 15:18:40.1384 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: <GenericEvent ID=18 Type=Ping Time=3/21/2016 3:18:40 PM Data=null> 
2016-03-21 15:19:15.9971 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: Received 1 events 
2016-03-21 15:19:15.9971 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: <StateChangedEvent ID=19 Time=3/21/2016 3:19:15 PM Folder=MinecraftWorlds From=idle To=scanning Duration=00:00:51.6790000> 
2016-03-21 15:19:15.9971 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: Received 1 events 
2016-03-21 15:19:16.0111 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: <StateChangedEvent ID=20 Time=3/21/2016 3:19:15 PM Folder=MinecraftWorlds From=scanning To=idle Duration=00:00:00.0030000> 
2016-03-21 15:19:32.4100 #2648 [Debug] SyncTrayzor.Services.MemoryUsageLogger: Working Set: 91MiB. Private Memory Size: 68MiB. GC Total Memory: 5MiB 
2016-03-21 15:19:32.4200 #332 [Debug] SyncTrayzor.Services.MemoryUsageLogger: Working Set: 96MiB. Private Memory Size: 72MiB. GC Total Memory: 6MiB 
2016-03-21 15:19:40.1384 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: Received 1 events 
2016-03-21 15:19:40.1384 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: <GenericEvent ID=21 Type=Ping Time=3/21/2016 3:19:40 PM Data=null> 
2016-03-21 15:20:17.4209 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: Received 1 events 
2016-03-21 15:20:17.4289 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: <StateChangedEvent ID=22 Time=3/21/2016 3:20:17 PM Folder=MinecraftWorlds From=idle To=scanning Duration=00:01:01.4210000> 
2016-03-21 15:20:17.4289 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: Received 1 events 
2016-03-21 15:20:17.4549 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: <StateChangedEvent ID=23 Time=3/21/2016 3:20:17 PM Folder=MinecraftWorlds From=scanning To=idle Duration=00:00:00.0070000> 
2016-03-21 15:20:40.1392 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: Received 1 events 
2016-03-21 15:20:40.1482 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: <GenericEvent ID=24 Type=Ping Time=3/21/2016 3:20:40 PM Data=null> 
2016-03-21 15:21:11.9560 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: Received 1 events 
2016-03-21 15:21:11.9590 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: <StateChangedEvent ID=25 Time=3/21/2016 3:21:11 PM Folder=MinecraftWorlds From=idle To=scanning Duration=00:00:54.5290000> 
2016-03-21 15:21:11.9590 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: Received 1 events 
2016-03-21 15:21:11.9590 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: <StateChangedEvent ID=26 Time=3/21/2016 3:21:11 PM Folder=MinecraftWorlds From=scanning To=idle Duration=00:00:00.0020000> 
2016-03-21 15:21:40.1402 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: Received 1 events 
2016-03-21 15:21:40.1492 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: <GenericEvent ID=27 Type=Ping Time=3/21/2016 3:21:40 PM Data=null> 
2016-03-21 15:22:07.5034 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: Received 1 events 
2016-03-21 15:22:07.5034 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: <StateChangedEvent ID=28 Time=3/21/2016 3:22:07 PM Folder=MinecraftWorlds From=idle To=scanning Duration=00:00:55.5450000> 
2016-03-21 15:22:07.5034 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: Received 1 events 
2016-03-21 15:22:07.5265 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: <StateChangedEvent ID=29 Time=3/21/2016 3:22:07 PM Folder=MinecraftWorlds From=scanning To=idle Duration=00:00:00.0060000> 
2016-03-21 15:22:40.1402 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: Received 1 events 
2016-03-21 15:22:40.1507 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: <GenericEvent ID=30 Type=Ping Time=3/21/2016 3:22:40 PM Data=null> 
2016-03-21 15:23:11.1021 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: Received 1 events 
2016-03-21 15:23:11.1021 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: <StateChangedEvent ID=31 Time=3/21/2016 3:23:11 PM Folder=MinecraftWorlds From=idle To=scanning Duration=00:01:03.5940000> 
2016-03-21 15:23:11.1021 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: Received 1 events 
2016-03-21 15:23:11.1021 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: <StateChangedEvent ID=32 Time=3/21/2016 3:23:11 PM Folder=MinecraftWorlds From=scanning To=idle Duration=00:00:00.0030000> 
2016-03-21 15:23:40.1419 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: Received 1 events 
2016-03-21 15:23:40.1499 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: <GenericEvent ID=33 Type=Ping Time=3/21/2016 3:23:40 PM Data=null> 
2016-03-21 15:24:08.9582 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: Received 1 events 
2016-03-21 15:24:08.9582 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: <StateChangedEvent ID=34 Time=3/21/2016 3:24:08 PM Folder=MinecraftWorlds From=idle To=scanning Duration=00:00:57.8530000> 
2016-03-21 15:24:09.0118 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: Received 1 events 
2016-03-21 15:24:09.0218 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: <StateChangedEvent ID=35 Time=3/21/2016 3:24:08 PM Folder=MinecraftWorlds From=scanning To=idle Duration=00:00:00.0070000> 
2016-03-21 15:24:32.4024 #2648 [Debug] SyncTrayzor.Services.MemoryUsageLogger: Working Set: 91MiB. Private Memory Size: 68MiB. GC Total Memory: 5MiB 
2016-03-21 15:24:32.4245 #332 [Debug] SyncTrayzor.Services.MemoryUsageLogger: Working Set: 96MiB. Private Memory Size: 72MiB. GC Total Memory: 6MiB 
2016-03-21 15:24:40.1420 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: Received 1 events 
2016-03-21 15:24:40.1505 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: <GenericEvent ID=36 Type=Ping Time=3/21/2016 3:24:40 PM Data=null> 
2016-03-21 15:25:07.3062 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: Received 1 events 
2016-03-21 15:25:07.3062 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: <StateChangedEvent ID=37 Time=3/21/2016 3:25:07 PM Folder=MinecraftWorlds From=idle To=scanning Duration=00:00:58.3410000> 
2016-03-21 15:25:07.3166 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: Received 1 events 
2016-03-21 15:25:07.3166 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: <StateChangedEvent ID=38 Time=3/21/2016 3:25:07 PM Folder=MinecraftWorlds From=scanning To=idle Duration=00:00:00.0060000> 
2016-03-21 15:25:40.1427 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: Received 1 events 
2016-03-21 15:25:40.1507 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: <GenericEvent ID=39 Type=Ping Time=3/21/2016 3:25:40 PM Data=null> 
2016-03-21 15:26:01.7946 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: Received 1 events 
2016-03-21 15:26:01.7946 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: <StateChangedEvent ID=40 Time=3/21/2016 3:26:01 PM Folder=MinecraftWorlds From=idle To=scanning Duration=00:00:54.4830000> 
2016-03-21 15:26:01.8001 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: Received 1 events 
2016-03-21 15:26:01.8001 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: <StateChangedEvent ID=41 Time=3/21/2016 3:26:01 PM Folder=MinecraftWorlds From=scanning To=idle Duration=00:00:00.0020000> 
2016-03-21 15:26:40.1431 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: Received 1 events 
2016-03-21 15:26:40.1476 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: <GenericEvent ID=42 Type=Ping Time=3/21/2016 3:26:40 PM Data=null> 
2016-03-21 15:26:56.6870 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: Received 1 events 
2016-03-21 15:26:56.7000 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: <StateChangedEvent ID=43 Time=3/21/2016 3:26:56 PM Folder=MinecraftWorlds From=idle To=scanning Duration=00:00:54.8880000> 
2016-03-21 15:26:56.7000 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: Received 1 events 
2016-03-21 15:26:56.7100 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: <StateChangedEvent ID=44 Time=3/21/2016 3:26:56 PM Folder=MinecraftWorlds From=scanning To=idle Duration=00:00:00.0120000> 
2016-03-21 15:27:40.1447 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: Received 1 events 
2016-03-21 15:27:40.1447 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: <GenericEvent ID=45 Type=Ping Time=3/21/2016 3:27:40 PM Data=null> 
2016-03-21 15:28:08.1551 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: Received 1 events 
2016-03-21 15:28:08.1551 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: <StateChangedEvent ID=46 Time=3/21/2016 3:28:08 PM Folder=MinecraftWorlds From=idle To=scanning Duration=00:01:11.4580000> 
2016-03-21 15:28:08.1602 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: Received 1 events 
2016-03-21 15:28:08.1602 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: <StateChangedEvent ID=47 Time=3/21/2016 3:28:08 PM Folder=MinecraftWorlds From=scanning To=idle Duration=00:00:00.0020000> 
2016-03-21 15:28:40.1456 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: Received 1 events 
2016-03-21 15:28:40.1456 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: <GenericEvent ID=48 Type=Ping Time=3/21/2016 3:28:40 PM Data=null> 
2016-03-21 15:28:58.1510 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: Received 1 events 
2016-03-21 15:28:58.1510 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: <StateChangedEvent ID=49 Time=3/21/2016 3:28:58 PM Folder=MinecraftWorlds From=idle To=scanning Duration=00:00:49.9940000> 
2016-03-21 15:28:58.1510 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: Received 1 events 
2016-03-21 15:28:58.1685 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: <StateChangedEvent ID=50 Time=3/21/2016 3:28:58 PM Folder=MinecraftWorlds From=scanning To=idle Duration=00:00:00.0020000> 
2016-03-21 15:29:32.4057 #2648 [Debug] SyncTrayzor.Services.MemoryUsageLogger: Working Set: 91MiB. Private Memory Size: 68MiB. GC Total Memory: 5MiB 
2016-03-21 15:29:32.4438 #332 [Debug] SyncTrayzor.Services.MemoryUsageLogger: Working Set: 96MiB. Private Memory Size: 72MiB. GC Total Memory: 6MiB 
2016-03-21 15:29:40.1456 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: Received 1 events 
2016-03-21 15:29:40.1456 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: <GenericEvent ID=51 Type=Ping Time=3/21/2016 3:29:40 PM Data=null> 
2016-03-21 15:30:06.8626 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: Received 1 events 
2016-03-21 15:30:06.8671 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: <StateChangedEvent ID=52 Time=3/21/2016 3:30:06 PM Folder=MinecraftWorlds From=idle To=scanning Duration=00:01:08.7090000> 
2016-03-21 15:30:06.8671 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: Received 1 events 
2016-03-21 15:30:06.8801 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: <StateChangedEvent ID=53 Time=3/21/2016 3:30:06 PM Folder=MinecraftWorlds From=scanning To=idle Duration=00:00:00.0030000> 
2016-03-21 15:30:40.1471 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: Received 1 events 
2016-03-21 15:30:40.1471 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: <GenericEvent ID=54 Type=Ping Time=3/21/2016 3:30:40 PM Data=null> 
2016-03-21 15:31:13.0816 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: Received 1 events 
2016-03-21 15:31:13.0816 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: <StateChangedEvent ID=55 Time=3/21/2016 3:31:13 PM Folder=MinecraftWorlds From=idle To=scanning Duration=00:01:06.2140000> 
2016-03-21 15:31:13.0816 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: Received 1 events 
2016-03-21 15:31:13.1047 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: <StateChangedEvent ID=56 Time=3/21/2016 3:31:13 PM Folder=MinecraftWorlds From=scanning To=idle Duration=00:00:00.0060000> 
2016-03-21 15:31:40.1477 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: Received 1 events 
2016-03-21 15:31:40.1477 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: <GenericEvent ID=57 Type=Ping Time=3/21/2016 3:31:40 PM Data=null> 
2016-03-21 15:32:02.3312 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: Received 1 events 
2016-03-21 15:32:02.3342 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: <StateChangedEvent ID=58 Time=3/21/2016 3:32:02 PM Folder=MinecraftWorlds From=idle To=scanning Duration=00:00:49.2450000> 
2016-03-21 15:32:02.3342 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: Received 1 events 
2016-03-21 15:32:02.3342 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: <StateChangedEvent ID=59 Time=3/21/2016 3:32:02 PM Folder=MinecraftWorlds From=scanning To=idle Duration=00:00:00.0020000> 
2016-03-21 15:32:40.1492 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: Received 1 events 
2016-03-21 15:32:40.1492 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: <GenericEvent ID=60 Type=Ping Time=3/21/2016 3:32:40 PM Data=null> 
2016-03-21 15:33:13.3723 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: Received 1 events 
2016-03-21 15:33:13.3803 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: <StateChangedEvent ID=61 Time=3/21/2016 3:33:13 PM Folder=MinecraftWorlds From=idle To=scanning Duration=00:01:11.0380000> 
2016-03-21 15:33:13.3803 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: Received 1 events 
2016-03-21 15:33:13.3964 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: <StateChangedEvent ID=62 Time=3/21/2016 3:33:13 PM Folder=MinecraftWorlds From=scanning To=idle Duration=00:00:00.0070000> 
2016-03-21 15:33:40.1475 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: Received 1 events 
2016-03-21 15:33:40.1475 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: <GenericEvent ID=63 Type=Ping Time=3/21/2016 3:33:40 PM Data=null> 
2016-03-21 15:34:09.6273 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: Received 1 events 
2016-03-21 15:34:09.6318 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: <StateChangedEvent ID=64 Time=3/21/2016 3:34:09 PM Folder=MinecraftWorlds From=idle To=scanning Duration=00:00:56.2500000> 
2016-03-21 15:34:09.6318 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: Received 1 events 
2016-03-21 15:34:09.6318 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: <StateChangedEvent ID=65 Time=3/21/2016 3:34:09 PM Folder=MinecraftWorlds From=scanning To=idle Duration=00:00:00.0030000> 
2016-03-21 15:34:32.4185 #2648 [Debug] SyncTrayzor.Services.MemoryUsageLogger: Working Set: 91MiB. Private Memory Size: 68MiB. GC Total Memory: 5MiB 
2016-03-21 15:34:32.4526 #332 [Debug] SyncTrayzor.Services.MemoryUsageLogger: Working Set: 96MiB. Private Memory Size: 72MiB. GC Total Memory: 6MiB 
2016-03-21 15:34:40.1497 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: Received 1 events 
2016-03-21 15:34:40.1732 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: <GenericEvent ID=66 Type=Ping Time=3/21/2016 3:34:40 PM Data=null> 
2016-03-21 15:35:06.1526 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: Received 1 events 
2016-03-21 15:35:06.1601 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: <StateChangedEvent ID=67 Time=3/21/2016 3:35:06 PM Folder=MinecraftWorlds From=idle To=scanning Duration=00:00:56.5220000> 
2016-03-21 15:35:06.1601 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: Received 1 events 
2016-03-21 15:35:06.1756 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: <StateChangedEvent ID=68 Time=3/21/2016 3:35:06 PM Folder=MinecraftWorlds From=scanning To=idle Duration=00:00:00.0050000> 
2016-03-21 15:35:40.1491 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: Received 1 events 
2016-03-21 15:35:40.1491 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: <GenericEvent ID=69 Type=Ping Time=3/21/2016 3:35:40 PM Data=null> 
2016-03-21 15:36:14.6453 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: Received 1 events 
2016-03-21 15:36:14.6453 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: <StateChangedEvent ID=70 Time=3/21/2016 3:36:14 PM Folder=MinecraftWorlds From=idle To=scanning Duration=00:01:08.4870000> 
2016-03-21 15:36:14.6453 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: Received 1 events 
2016-03-21 15:36:14.6696 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: <StateChangedEvent ID=71 Time=3/21/2016 3:36:14 PM Folder=MinecraftWorlds From=scanning To=idle Duration=00:00:00.0070000> 
2016-03-21 15:36:40.1491 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: Received 1 events 
2016-03-21 15:36:40.1491 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: <GenericEvent ID=72 Type=Ping Time=3/21/2016 3:36:40 PM Data=null> 
2016-03-21 15:37:17.3278 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: Received 1 events 
2016-03-21 15:37:17.3278 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: <StateChangedEvent ID=73 Time=3/21/2016 3:37:17 PM Folder=MinecraftWorlds From=idle To=scanning Duration=00:01:02.6770000> 
2016-03-21 15:37:17.3333 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: Received 1 events 
2016-03-21 15:37:17.3333 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: <StateChangedEvent ID=74 Time=3/21/2016 3:37:17 PM Folder=MinecraftWorlds From=scanning To=idle Duration=00:00:00.0020000> 
2016-03-21 15:37:40.1492 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: Received 1 events 
2016-03-21 15:37:40.1492 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: <GenericEvent ID=75 Type=Ping Time=3/21/2016 3:37:40 PM Data=null> 
2016-03-21 15:38:23.6961 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: Received 1 events 
2016-03-21 15:38:23.6961 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: <StateChangedEvent ID=76 Time=3/21/2016 3:38:23 PM Folder=MinecraftWorlds From=idle To=scanning Duration=00:01:06.3650000> 
2016-03-21 15:38:23.6961 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: Received 1 events 
2016-03-21 15:38:23.6961 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: <StateChangedEvent ID=77 Time=3/21/2016 3:38:23 PM Folder=MinecraftWorlds From=scanning To=idle Duration=00:00:00.0020000> 
2016-03-21 15:38:40.1503 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: Received 1 events 
2016-03-21 15:38:40.1503 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: <GenericEvent ID=78 Type=Ping Time=3/21/2016 3:38:40 PM Data=null> 
2016-03-21 15:38:55.7656 #332 [Info] SyncTrayzor.Services.AutostartProvider: GetCurrentSetup determined that the current configuration is: <AutostartConfiguration AutoStart=True StartMinimized=True> 
2016-03-21 15:39:09.1630 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: Received 1 events 
2016-03-21 15:39:09.1630 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: <StateChangedEvent ID=79 Time=3/21/2016 3:39:09 PM Folder=MinecraftWorlds From=idle To=scanning Duration=00:00:45.4650000> 
2016-03-21 15:39:09.1630 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: Received 1 events 
2016-03-21 15:39:09.1630 #332 [Debug] SyncTrayzor.Syncthing.EventWatcher.SyncthingEventWatcher: <StateChangedEvent ID=80 Time=3/21/2016 3:39:09 PM Folder=MinecraftWorlds From=scanning To=idle Duration=00:00:00.0020000> 
2016-03-21 15:39:24.5055 #332 [Info] SyncTrayzor.Services.ProcessStartProvider: Starting C:\Program Files\SyncTrayzor\ProcessRunner.exe --shell  -- "explorer.exe" /select, "C:\Users\Stuart\AppData\Roaming\SyncTrayzor\logs\SyncTrayzor.log" 

[canton7]

I've seen this before (which is why the pid is in the logs) but we never got to the bottom of it.

Maybe some more googling is in order. I'll have a look around tomorrow.

[canton7]

Can you just check in HKCU\SOFTWARE\Microsoft\Windows\CurrentVersion\Run\, make sure there aren't two keys pointing to SyncTrayzor somehow?

[canton7]

Any response?

[stuartpb]

Yeah, I checked the registry - there's only one entry for SyncTrayzor. As I said, they're both triggered by the same autostart location.

[canton7]

I have no idea what Windows is doing then...

Try things like disabling autostart (in the SyncTrayzor settings), restarting (does it autostart SyncTrayzor for some reason), re-enable autostart?

[canton7]

Closing as no response.

[stuartpb]

Pretty sure I disabled auto-start (got no instances at startup) and re-enabled it (got two instances again). I can try this again now and, if I do, I'll post if that's the case now.

[canton7]

Just check the registry key HKEY_CURRENT_USER\SOFTWARE\Microsoft\Windows\CurrentVersion\Run. If there's only one SyncTrayzor entry in there, yet Windows is starting SyncTrayzor twice, then that's between you and Windows I'm afraid.

[stuartpb]

There very much is only one entry at that location, as I stated when I originally opened the issue, and reiterated shortly after. Are you saying this problem, which I have only ever seen manifest with SyncTrayzor and am not the only user to have encountered, is a core Windows system bug? Because, then, as a dev, I believe that would make it an issue between you and Windows, not me.

(EDIT: Yes, even when it's due to a factor outside of the dev's control, it's still primarily an issue between the dev and the upstream, not the user and upstream. Why? Because the dev's in a better position to perform root-cause analysis across multiple instances of the failure case. If it's only one user who's encountering the bug, then yeah, it may do better to say that the burden of investigation lies on them, but it was established here that this wasn't the case.)

[canton7]

Yes, I'm saying that if you have one entry in there, and no entries anywhere else (as confirmed by disabling autostart and seeing if anything gets launched), yet Windows starts the process twice, that's Windows at work, not me. My control begins when SyncTrayzor is launched. If it's launched twice, there's nothing I can do: that's out of my control.

Also, this seems to be an issue with a couple of specific machines. If it was a simple issue with SyncTrayzor, everyone would be reporting it.

Maybe you can check and see what the parent process is, if any?

[canton7]

I could potentially be smarter about protecting against multiple processes started at the same instant.

Currently they both notice that the other exists, try and talk to the other, give up, then start listening for messages from the other. The logic isn't really supposed to handle two processes start at exactly the same instant... We'd need to avoid both telling the other to show itself, then both shutting down together, however, as that's even worse.

Not sure of the best way to do this. We can't use a named mutex, as we're only exclusive within one user session and for one specific SyncTrayzor.exe. Maybe after the first failure to contact the other, start the server and delay a random amount? We'd still need to spot if the other talked to us within that delay, and it starts to get involved. Maybe just delay a random amount before trying to talk to the other? But that impacts everyone.

[canton7]

(Re-opening as the OP is communicating again).

[stuartpb]

The parent process is explorer.exe, just like any other autorun-at-startup task. I don't know what there is to inspect beyond that.

[canton7]

The parent process for both launched instances is explorer? (Just want to make sure).

[canton7]

The only other thing I can think of is to fire up autoruns and check that SyncTrayzor is only listed in there once.

[stuartpb]

Yes, the same top-level instance of Explorer that auto-starts all of Windows' other auto-runs.

And, yes, I verified that SyncTrayzor is only listed once by autoruns.

[canton7]

Do you have any other programs listed in HKCU\SOFTWARE\Microsoft\Windows\CurrentVersion\Run? Is it only SyncTrayzor that's started this way?

[stuartpb]

Windows Registry Editor Version 5.00

[HKEY_CURRENT_USER\SOFTWARE\Microsoft\Windows\CurrentVersion\Run]
"Google Update"="C:\\Users\\Stuart\\AppData\\Local\\Google\\Update\\1.3.32.7\\GoogleUpdateCore.exe"
"Steam"="\"C:\\Program Files (x86)\\Steam\\steam.exe\" -silent"
"SyncTrayzor"="\"C:\\Program Files\\SyncTrayzor\\SyncTrayzor.exe\" -minimized"
"Zoom"=""
"OneDrive"="\"C:\\Users\\Stuart\\AppData\\Local\\Microsoft\\OneDrive\\OneDrive.exe\" /background"
"CorsairLink4"="C:\\Program Files (x86)\\CorsairLink4\\CorsairLink4.exe -startup"
"GoogleDriveSync"="\"C:\\Program Files (x86)\\Google\\Drive\\googledrivesync.exe\" /autostart"
"GoogleChromeAutoLaunch_C547D43CD725728C8B60ADB062C7B06A"="\"C:\\Program Files (x86)\\Google\\Chrome\\Application\\chrome.exe\" --no-startup-window /prefetch:5"

[stuartpb]

Hmm... I wonder if that empty Zoom entry is causing it to re-interpret the entry above.

[stuartpb]

I'm going to try removing the blank entry for Zoom and see if that fixes the problem after restarting.

[canton7]

That's an idea. If that is the issue, with SyncTrayzor autostart disabled that would have started Steam twice... But Steam probably copes with that better than I do, so you'd never have known.

(Anyway, I'm going to bed. Back on this tomorrow).

[stuartpb]

Hah - it would appear that this blank HKCU\SOFTWARE\Microsoft\Windows\CurrentVersion\Run entry for "Zoom" (which is, if I'm not mistaken, inserted by Windows) is, in fact, what causes this issue.

I've reported the bug via the Microsoft "Feedback Hub" app that is, for inscrutable NIH reasons, not web-accessible: https://aka.ms/Gfq0tb

(I also installed two updates when rebooting - this and this - but neither described this issue as one of the things they solved, and I'm guessing that re-adding the broken Autorun entry would re-introduce the problem, though I don't care to spend another half-hour rebooting to test that hypothesis myself.)

Until this issue is solved by Microsoft: maybe add a runtime check at startup for a blank entry on HKCU\SOFTWARE\Microsoft\Windows\CurrentVersion\Run, and if launch fails for the kinds of reasons that are exhibited by this bug and such a key is present, link the user to this issue suggesting that they nag Microsoft about the bug and get rid of the blank entry as a workaround?

[stuartpb]

Not sure of the best way to do this. We can't use a named mutex, as we're only exclusive within one user session and for one specific SyncTrayzor.exe. Maybe after the first failure to contact the other, start the server and delay a random amount? We'd still need to spot if the other talked to us within that delay, and it starts to get involved. Maybe just delay a random amount before trying to talk to the other? But that impacts everyone.

I think a lockfile would make sense, especially since that's effectively what's already happening anyway (the second instance fails with denied access to the config file opened by the first instance).

[canton7]

Hah, nice find. Told you it was between you and Microsoft 😉

if launch fails for the kinds of reasons that are exhibited by this bug and such a key is present

Launching doesn't fail though - as you saw, it launches two instances just fine. A better single-instance locking strategy would mitigate the issue, but then it wouldn't be visible to the user, so there's no need to warn them about anything.

A lockfile would change the single-instance model a bit: previously two installed versions in different directories but the same configuration folder could run at the same time, but that would be prevented with the lockfile approach. That's probably for the best, though. I need the PID of the existing process, but I can put that in the lockfile. There are races around one process locking the lockfile and writing its PID, while the other reads a partially-written PID, but I think those are solvable.