Case #02253144
We are having the issue, that on some of our VPS, the Veeam Agent service is hanging on startup and blocking a lot of actions on the virtual machine.
As long as this issue occurs, the vm stays in a partially unresponsive state. For example: files cannot be opened, programs are not starting. As soon as the issue resolves itself, all is working as expected.
There is a simple workaround for the case: If you set the "Veeam Agent for Microsoft Windows" service to "Automatic (Delayed Start)", the issue will not appear.
The agent is installed on dozens of Windows virtual machines, but only two of them are having this particular issue. It might be related to the installed MS SQL Server, but I wasn't able to find any connections in the Windows event logs so far.
Since the open support case is not getting anywhere, I thought it might be reasonable to post this to the forum.
This is the Svc.VeeamEndpointBackup.log, where you can clearly see the problem.
Code: Select all
[15.08.2017 09:42:52] <04> Info Starting EndpointService as service
[15.08.2017 09:42:53] <04> Info Session parameters: OTBmNjlkICA2ZGZjYjQ0ZCAzMS4xMi45OTk5IDIzOjU5OjU5IGUzYmJlIGI0MzUxYzg5LTBlMzItMzU0OC05ZmQ3LTBkNzE1Y2RmYzE0YyBkMTIz
[15.08.2017 09:42:53] <06> Info Created mutex [EndPointServiceStartMutex]
[15.08.2017 09:42:53] <06> Info Acquired mutex [EndPointServiceStartMutex]
[15.08.2017 09:42:53] <04> Info Remoting options: [AuthenticationMode: [IdentifyCallers], UseIpAddress: [], MachineName: [127.0.0.1]]
[15.08.2017 09:42:53] <04> Info Database options: [Server: [(local)], ServerInstanceName: [VeeamEndPoint], ServerInstancePipeName: [np:\\.\pipe\LOCALDB#B6EF92CB\tsql\query], ServerInstancePort: [-1], InitialCatalog: [VeeamBackup], SqlAuthentication: [True], User: [VeeamLogin], Password: [*****], ImpersonateUser: [False], UserName: [], ConnectionRetryCount: [11], ConnectionRetryTimeout: [20], ConnectionTimeout: [120], StatementTimeout: [180], EnableLog: [True], EnableExtendedLog: [False], ]
[15.08.2017 09:42:53] <04> Info Service options: [Dispatch loop wait on error: [5 sec], Stop service: [20 sec], Stop all running jobs: True, Stop all running jobs: [00:05:00 sec], Stop service: [20 sec], SqlExec data process: [180 sec], Log jobs info: [60 min], JobStartedCheckTimeout: [5 sec], JobFinishedCheckTimeout: [30 sec], JobStartedMaxTime: [360 sec], PeriodicallyGarbageCollect: [False].VolumesDiscoverThreadsNumber: [5].VolumesDiscoverPeriodicallyHours: [4].SanRescanPeriodicallyDays: [1].PeriodicallyHvCtpScanner: [1] day.CatCatalogPeriodicallyHours: [24].LicenseCheckTimeout: [60 min].RpcTransportPort: [6183 min].RpcDeployerPort: [6183 min].]
[15.08.2017 09:42:53] <04> Info [EndPointEnvironment] Trying to open tcp channel on port = 9395.
[15.08.2017 09:42:53] <04> Info Registering TCP server channel [bstcp]. Port: [9395]
[15.08.2017 09:42:53] <04> Info Skip down nic [Ethernet OpenVPN]
[15.08.2017 09:42:53] <04> Info Skip down nic [Tunnel isatap.{4E413ED1-9210-4528-94D0-743BD84669F6}]
[15.08.2017 09:42:53] <04> Info Skip down nic [Tunnel isatap.{B8CC0A50-F6C5-48B6-9D5F-E42203DAFF6D}]
[15.08.2017 09:42:53] <04> Info Channel URIs:
[15.08.2017 09:42:53] <04> Info [tcp://127.0.0.1:9395]
[15.08.2017 09:42:53] <04> Info [EndPointEnvironment] Tcp channel is opened.
[15.08.2017 09:42:53] <04> Info [EndPointEnvironment] Updating registry value for BackupServerPort.
[15.08.2017 09:42:53] <04> Info Starting service...
[15.08.2017 09:42:53] <05> Info [Schedule Events] Catched PowerSettingsEvent: Guid: 02731015-4510-4526-99e6-e5a17ebd1aea, Value: 1
[15.08.2017 09:43:23] <10> Info [Schedule Events] Received notification about session state change: ConsoleConnect, session id: '1'
[15.08.2017 09:44:42] <11> Info [Schedule Events] Received notification about session state change: SessionLogon, session id: '1'
[15.08.2017 10:02:10] <12> Info [Schedule Events] Catched PowerSettingsEvent: Guid: 02731015-4510-4526-99e6-e5a17ebd1aea, Value: 0
[15.08.2017 10:02:11] <13> Info [Schedule Events] Received notification about session state change: SessionLock, session id: '1'
[15.08.2017 10:10:37] <14> Info [Schedule Events] Catched PowerSettingsEvent: Guid: 02731015-4510-4526-99e6-e5a17ebd1aea, Value: 1
[15.08.2017 10:10:58] <15> Info [Schedule Events] Received notification about session state change: SessionUnlock, session id: '1'
[15.08.2017 10:13:22] <09> Error Failed to track service status.
[15.08.2017 10:13:22] <09> Error Unable to start service. Time: [00:30:00] (System.TimeoutException)
[15.08.2017 10:13:22] <09> Error bei Veeam.Backup.Common.CScmNotifier.WaitStatusCallback()
[15.08.2017 10:15:37] <04> Info Checking access rights for 'C:\Windows\system32\config\systemprofile'
[15.08.2017 10:15:37] <04> Info ACL contains full control access right for current user
[15.08.2017 10:15:38] <04> Info Searching for local database instance 'VeeamEndPoint'
[15.08.2017 10:15:38] <04> Info Local database instance 'VeeamEndPoint' founded
[15.08.2017 10:15:38] <04> Info [SqlLocalDb] Starting instance 'VeeamEndPoint'
[15.08.2017 10:15:41] <04> Info [SqlLocalDB] Instance 'VeeamEndPoint' has been started