ESET ERA 6 Push Installation not working on some servers.

[Rinzler 0]

Hi!

So we have a test network for testing ERA 6. This network has 12 Windows server 2012 R2 servers they all have the same antivirus installed today (ESET File Server Security V4.5) and the same Windows firewall settings. On some servers the new antivirus package doesn't get installed, i get no errors just that they don't show up in the execution portion of the task. 

 

So my question is why is it working on some servers and not others? Are there some other requirements the servers need to run the AV package? All these servers have the agent installed.

 

Trace log shows the following:

 

CReplicationManager: Replication (network) connection to 'host: "ERA6SERVER(edited for confidentiality)" port: 2222' failed with: (0x274c), A connection attempt failed because the connected party did not properly respond after a period of time, or established connection failed because connected host has failed to respond

Edited January 9, 2016 by Rinzler

[MartinK 378]

Hi!

So we have a test network for testing ERA 6. This network has 12 Windows server 2012 R2 servers they all have the same antivirus installed today (ESET File Server Security V4.5) and the same Windows firewall settings. On some servers the new antivirus package doesn't get installed, i get no errors just that they don't show up in the execution portion of the task. 

 

So my question is why is it working on some servers and not others? Are there some other requirements the servers need to run the AV package? All these servers have the agent installed.

 

Trace log shows the following:

 

CReplicationManager: Replication (network) connection to 'host: "ERA6SERVER(edited for confidentiality)" port: 2222' failed with: (0x274c), A connection attempt failed because the connected party did not properly respond after a period of time, or established connection failed because connected host has failed to respond

 

Seems task are not being executed, because AGENTs installed on affected systems are not able to connect to ERA server. Could you please verify that ERA server is accessible from AGENT computers and there is no firewall blocking connection? I would try to open telnet/ssh connection from those system so ERA Server on port 2222 and check whether connection is opened or not (do not except any data in case it is opened).

Edited January 9, 2016 by MartinK

[Rinzler 0]

Hi there are no firewalls between active. This is more of the trace log:

 

2016-01-09 12:07:02 Information: SchedulerModule [Thread bd8]: Received message: RegisterTimeEvent

2016-01-09 12:07:02 Information: SchedulerModule [Thread bd8]: Received message: RegisterTimeEvent

2016-01-09 12:07:02 Information: Kernel [Thread a98]: Started module CDataMinersModule (used 784 KB)

2016-01-09 12:07:02 Information: Kernel [Thread a98]: Starting module CDynamicGroupsModule

2016-01-09 12:07:02 Information: Kernel [Thread a98]: Started module CDynamicGroupsModule (used 52 KB)

2016-01-09 12:07:02 Information: Kernel [Thread a98]: Starting module CReplicationModule

2016-01-09 12:07:02 Information: CReplicationModule [Thread a98]: CReplicationModuleBase: Starting module

2016-01-09 12:07:02 Information: CReplicationModule [Thread a98]: CStepProcessor: Starting

2016-01-09 12:07:02 Information: CReplicationModule [Thread a98]: CStepProcessor: Creating 1 worker threads

2016-01-09 12:07:02 Information: CReplicationModule [Thread a98]: CReplicationManager: Starting replication control messages processing

2016-01-09 12:07:02 Information: Kernel [Thread a98]: Started module CReplicationModule (used 28 KB)

2016-01-09 12:07:02 Information: Kernel [Thread a98]: Starting module AutomationModule

2016-01-09 12:07:02 Information: Kernel [Thread a98]: Started module AutomationModule (used 52 KB)

2016-01-09 12:07:02 Information: Kernel [Thread a98]: Starting module CPoliciesModule

2016-01-09 12:07:02 Information: SchedulerModule [Thread bd8]: Received message: RegisterTimeEvent

2016-01-09 12:07:02 Information: CDynamicGroupsModule [Thread 1628]: Refreshing dynamic groups after replication

2016-01-09 12:07:02 Information: CReplicationModule [Thread 364]: CStepProcessor: Starting worker thread 364

2016-01-09 12:07:02 Information: AutomationModule [Thread 1b14]: Facade: Loading all enabled triggers.

2016-01-09 12:07:02 Information: CDynamicGroupsModule [Thread 1628]: Refreshing dynamic groups templates after replication

2016-01-09 12:07:02 Information: AutomationModule [Thread 1b14]: Facade: Trigger has been created [uUID=00000000-0000-0000-7006-00000000000a, TYPE=DYNAMIC_GROUP_JOINED, CONFIG=triggerType: DYNAMIC_GROUP_JOINED].

2016-01-09 12:07:02 Information: AutomationModule [Thread 1b14]: SimpleSchedulerTriggerBase: Trigger [uUID=00000000-0000-0000-7006-000000000001, TYPE=REPLICATION] registering scheduler event [startTime { year: 2016 month: 1 day: 9 hour: 12 minute: 7 second: 2 } TimeSpecification: "R * * * * ? *" UTCLocal: true].

2016-01-09 12:07:02 Information: SchedulerModule [Thread bd8]: Received message: RegisterTimeEvent

2016-01-09 12:07:02 Information: AutomationModule [Thread 1b14]: CSimpleSchedulerTriggerBase: Trigger [uUID=00000000-0000-0000-7006-000000000001, TYPE=REPLICATION] is going to generate a tick for a missed event [year: 2016 month: 1 day: 9 hour: 12 minute: 6 second: 57].

2016-01-09 12:07:02 Information: AutomationModule [Thread 1b14]: Trigger: Tick ALLOWED [uUID=00000000-0000-0000-7006-000000000001, TYPE=REPLICATION].

2016-01-09 12:07:02 Information: AutomationModule [Thread 1b14]: Task: Executing task [uUID=00000000-0000-0000-7005-000000000001, TYPE=Replication, CONFIG=scenarioType: REGULAR linkData { dataLimit: 1024 isDisabled: false connections { host: "APP2.secret.LOCAL" port: 2222 } }].

2016-01-09 12:07:02 Information: SchedulerModule [Thread bd8]: Received message: GetRemainingTimeByUserDataRequest

2016-01-09 12:07:02 Information: CDynamicGroupsModule [Thread 1628]: Refreshing static groups after replication

2016-01-09 12:07:02 Information: CReplicationModule [Thread 14f0]: CReplicationManager: Processing client replication task message

2016-01-09 12:07:02 Information: CReplicationModule [Thread 14f0]: CReplicationManager: Initiating replication connection to 'host: "APP2.secret.LOCAL" port: 2222' (scenario: Regular, data limit: 1024KB)

2016-01-09 12:07:02 Information: NetworkModule [Thread c44]: Received message: CreateConnectionRequest

2016-01-09 12:07:02 Information: CDynamicGroupsModule [Thread 1628]: Retrieving currently matching dynamic groups with static groups path to root

2016-01-09 12:07:02 Information: SchedulerModule [Thread bd8]: Received message: GetRemainingTimeByUserDataRequest

2016-01-09 12:07:02 Information: SchedulerModule [Thread bd8]: Received message: RegisterSleepEvent

2016-01-09 12:07:02 Information: AutomationModule [Thread 1b14]: Facade: Trigger has been created [uUID=00000000-0000-0000-7006-000000000001, TYPE=REPLICATION, CONFIG=StartTime { year: 2016 month: 1 day: 9 hour: 12 minute: 7 second: 2 } TimeSpecification: "R * * * * ? *" UTCLocal: true].

2016-01-09 12:07:02 Information: AutomationModule [Thread 1b14]: SimpleSchedulerTriggerBase: Trigger [uUID=00000000-0000-0000-7006-000000000002, TYPE=RESTART_AGENT] registering scheduler event [startTime { year: 2016 month: 1 day: 9 hour: 12 minute: 7 second: 2 } TimeSpecification: "0 0 * * * ? *" UTCLocal: true Delay: 30].

2016-01-09 12:07:02 Information: SchedulerModule [Thread bd8]: Received message: RegisterTimeEvent

2016-01-09 12:07:02 Information: AutomationModule [Thread 1b14]: Facade: Trigger has been created [uUID=00000000-0000-0000-7006-000000000002, TYPE=RESTART_AGENT, CONFIG=StartTime { year: 2016 month: 1 day: 9 hour: 12 minute: 7 second: 2 } TimeSpecification: "0 0 * * * ? *" UTCLocal: true Delay: 30].

2016-01-09 12:07:02 Information: AutomationModule [Thread 1b14]: Facade: Trigger has been created [uUID=00000000-0000-0000-7006-000000000005, TYPE=REPLICATION_OUT_OF_ORDER].

2016-01-09 12:07:02 Information: AutomationModule [Thread 1b14]: SimpleSchedulerTriggerBase: Trigger [uUID=00000000-0000-0000-7006-00000000000b, TYPE=UPDATE_MODULES] registering scheduler event [TimeSpecification: "R R R/6 * * ? *" UTCLocal: false Delay: 0].

2016-01-09 12:07:02 Information: SchedulerModule [Thread bd8]: Received message: RegisterTimeEvent

2016-01-09 12:07:02 Information: SchedulerModule [Thread bd8]: Received message: GetRemainingTimeByUserDataRequest

2016-01-09 12:07:02 Information: AutomationModule [Thread 1b14]: Facade: Trigger has been created [uUID=00000000-0000-0000-7006-00000000000b, TYPE=UPDATE_MODULES, CONFIG=TimeSpecification: "R R R/6 * * ? *" UTCLocal: false Delay: 0].

2016-01-09 12:07:02 Information: AutomationModule [Thread 1b14]: SimpleSchedulerTriggerBase: Trigger [uUID=00000000-0000-0000-7006-00000000000c, TYPE=CLEANUP_LOGS] registering scheduler event [TimeSpecification: "0 0 */2 * * ? *" UTCLocal: false Delay: 0].

2016-01-09 12:07:02 Information: SchedulerModule [Thread bd8]: Received message: RegisterTimeEvent

2016-01-09 12:07:02 Information: SchedulerModule [Thread bd8]: Received message: GetRemainingTimeByUserDataRequest

2016-01-09 12:07:02 Information: AutomationModule [Thread 1b14]: Facade: Trigger has been created [uUID=00000000-0000-0000-7006-00000000000c, TYPE=CLEANUP_LOGS, CONFIG=TimeSpecification: "0 0 */2 * * ? *" UTCLocal: false Delay: 0].

2016-01-09 12:07:02 Information: AutomationModule [Thread 1b14]: SimpleSchedulerTriggerBase: Trigger [uUID=00000000-0000-0000-7006-00000000000e, TYPE=DATAMINER_CREATE_SNAPHOT] registering scheduler event [TimeSpecification: "18 58 20 * * ? *" UTCLocal: true Delay: 0].

2016-01-09 12:07:02 Information: SchedulerModule [Thread bd8]: Received message: RegisterTimeEvent

2016-01-09 12:07:02 Information: SchedulerModule [Thread bd8]: Received message: GetRemainingTimeByUserDataRequest

2016-01-09 12:07:02 Information: AutomationModule [Thread 1b14]: Facade: Trigger has been created [uUID=00000000-0000-0000-7006-00000000000e, TYPE=DATAMINER_CREATE_SNAPHOT, CONFIG=TimeSpecification: "18 58 20 * * ? *" UTCLocal: true Delay: 0].

2016-01-09 12:07:02 Information: AutomationModule [Thread 1b14]: Facade: All enabled triggers have been loaded.

2016-01-09 12:07:02 Information: AutomationModule [Thread 1b14]: Trigger: Tick ALLOWED [uUID=00000000-0000-0000-7006-000000000005, TYPE=REPLICATION_OUT_OF_ORDER] by throttle [TFQ=1].

2016-01-09 12:07:02 Information: AutomationModule [Thread 1b14]: Task: Executing task [uUID=00000000-0000-0000-7005-000000000014, TYPE=ReplicationOutOfOrder, CONFIG=scenarioType: OUT_OF_ORDER linkData { dataLimit: 1024 isDisabled: false connections { host: "APP2.secret.LOCAL" port: 2222 } }].

2016-01-09 12:07:02 Information: CReplicationModule [Thread 14f0]: CReplicationManager: Processing client replication task message

2016-01-09 12:07:02 Information: CReplicationModule [Thread 14f0]: CReplicationManager: Failed to start replication, replication link '00000000-0000-0000-7007-000000000001' (Automatic replication (OUT_OF_ORDER)) is already in use

2016-01-09 12:07:02 Information: CReplicationModule [Thread 14f0]: CReplicationManager: Queuing replication task to be executed after current replication is finished

[MartinK 378]

It is very short part of trace.log to make any conclusions, but from what I can see everything is as it should be except that connection to you SERVER was not opened in time (there is 5 minutes timeout). There are many possibilities for this:

• network configuration problem (I have seen similar behavior in case port forwarding configuration for virtual network was not configured properly, and also in cases target machines was not listening at requested port)
• DNS name resolution problem (DNS response for hostname of your server takes too much time): if possible, try to repair affected AGENT and use IP address instead of hostname when specifying ERA server. Also please verify resolved IP address is correct.
• ERA server may not be accepting new connections for some reason: please verify that other AGENTs are still connecting (last connection time seen in Webconsole). There may also be related errors in ERA SERVER trace.log.
• firewall or other security tools may be blocking connection: please disable software that could be interfering with AGENT connections (even ESET Antivirus if installed also).

You may also use tools like Wireshark to analyze whether connection request is received to ERA SERVER or it is lost somewhere between.

[Rinzler 0]

Okay so i've tried all these recommendations and it still isn't working. DNS is working fine, agents are connecting, firewalls are off, the servers are even running as vm's on the same server.