Can't get client connection

[sdnian 6]

I've ERA server v6.4 that be running in Ubuntu 16.04 x64. It keeps stop working in sometime every day. It is about one time per day.

 

When the issue happened. I can logon web console and everything seems fine. But I found all clients can't connect to ERA server. The last connect field stop update. I've make sure there are a lot of clients are online in that time. Every time it happened, I ran 'systemctl restart mysql.service'. Then this issue was gone. All clients start to connect ERA server again. It seems MySQL problem. But in that time, I try to access MySQL, it's fine. Even I try to query data of 'era_db' database via odbc from this server. I could get datas.

 

This problem happened about one week. 

 

I checked the trace.log of ERA server.. There are many error logs. Like:

 

2016-11-23 23:11:47 Error: CReplicationModule [Thread 7f1965ffb700]: CStepProcessor: Replication master rejected, slave is busy

 

and some these error logs:

 

2016-11-23 23:41:06 Error: NetworkModule [Thread 7f19c1ffb700]: Verify user failed for all computers: 127.0.0.1: NodVerifyCertificateChain failed: NodVerifyTrustResult: 6, NVT_NotTrustedRoot, X509ChainStatus: 0x4, X509CSF_Revoked,127.0.0.1: NodVerifyCertificateChain failed: NodVerifyTrustResult: 6, NVT_NotTrustedRoot, X509ChainStatus: 0x4, X509CSF_Revoked

2016-11-23 23:41:06 Error: NetworkModule [Thread 7f19c1ffb700]: Receive: NodSslWriteEncryptedData: Internal error in the underlying implementations., ResolvedIpAddress:127.0.0.1, ResolvedHostname:127.0.0.1, ResolvedPort:33558

2016-11-23 23:41:06 Error: NetworkModule [Thread 7f19c1ffb700]: Protocol failure for session id 108048, error:Receive: NodSslWriteEncryptedData: Internal error in the underlying implementations.

 

I've only single ERA server. No any ERA proxy.

 

Ubuntu 16.04.1 LTS x64

ERA Server 6.4.304.0

ERA Web Console 6.4.266.0

MySQL 5.7.16

ERA Agent 6.4.283.0

[MartinK 378]

2016-11-23 23:11:47 Error: CReplicationModule [Thread 7f1965ffb700]: CStepProcessor: Replication master rejected, slave is busy

 

This means SERVER is in state in which incoming connection are rejected. There are multiple possibilities what could be reason, for example:

• SERVER lost connection to database
• SERVER has connection to database, but it is accepting data faster than it is able to write into database (i.e. there are many pending logs). This
• SERVER is out of memory (RAM)

In case it happens once a day, it may be caused by so called DB cleanups, which are performed at 00:00:00 of local time on SERVER - does it correlate with your findings?. Also please check status.html on SERVER from time it is not working properly, there may be more relevant information of reason why SERVER is in overloaded or busy state. Could you also verify that your MySQL driver and unixODBC are configured so that multi-threading is enabled (parameter Threading=0 or new unixODBC)?

 

 

Remaining errors are unrelated to this issue: SERVER seems to be rejecting connections from client because it's certificate was revoked. And it seems is it actually AGENT installed on the same computer...

[sdnian 6]

 

2016-11-23 23:11:47 Error: CReplicationModule [Thread 7f1965ffb700]: CStepProcessor: Replication master rejected, slave is busy

 

This means SERVER is in state in which incoming connection are rejected. There are multiple possibilities what could be reason, for example:

• SERVER lost connection to database
• SERVER has connection to database, but it is accepting data faster than it is able to write into database (i.e. there are many pending logs). This
• SERVER is out of memory (RAM)

In case it happens once a day, it may be caused by so called DB cleanups, which are performed at 00:00:00 of local time on SERVER - does it correlate with your findings?. Also please check status.html on SERVER from time it is not working properly, there may be more relevant information of reason why SERVER is in overloaded or busy state. Could you also verify that your MySQL driver and unixODBC are configured so that multi-threading is enabled (parameter Threading=0 or new unixODBC)?

 

 

Remaining errors are unrelated to this issue: SERVER seems to be rejecting connections from client because it's certificate was revoked. And it seems is it actually AGENT installed on the same computer...

 

 

I found it happned about 08:00AM in local time. But my timezone is UTC+8. So is it possible that server run DB cleanups it that time? Any log could confirm when DB cleanups be performed?

 

According you mention.. 

 

Point 1. I don't think so. Because I could logon web console and there are datas in there. If ERA server has no connection to database. Why do I saw data in console?

Point 3. Server is out of memory. I check the memory, it seems okay.

 

# free

              total        used        free      shared  buff/cache   available

Mem:       16355332     2492188     1112308      169488    12750836    13388260

Swap:      16776188           0    16776188

 

Point 2.. how could I make sure if it is the reason? 

 

You also mention unixODBC. I wonder maybe it is the reason. Long time ago.. I've asked another issue https://forum.eset.com/topic/9520-no-progress-count/, but no one give me the answer.

Maybe it's relative. In fact, I don't use unixODBC. Because I use Ubuntu 16.04.1 LTS and MySQL 5.7. The unixODBC doesn't support MySQL 5.7. The unixODBC package has been removed from

Ubuntu 16.04. So I use MySQL connector/ODBC for Linux - https://dev.mysql.com/downloads/connector/odbc/ . Maybe ERA server 6.4 does not fully compatible MySQL connector/ODBC?

[MartinK 378]

I found it happned about 08:00AM in local time. But my timezone is UTC+8. So is it possible that server run DB cleanups it that time? Any log could confirm when DB cleanups be performed?

Could you please check whether UTC date is correctly set on this machine? Commands:

date
date -u
date +%z

should print local time, UTC time and timezone offset.

 

During execution of cleanups, you should see this in trace log, but only in case highest verbosity is enabled:

2016-11-24 15:43:59 Information: CCleanupModule [Thread 7ff7a47f3700]: Initiating abandoned logs cleanup
2016-11-24 15:43:59 Information: CCleanupModule [Thread 7ff7a47f3700]: Finished abandoned logs cleanup
2016-11-24 15:43:59 Information: CCleanupModule [Thread 7ff7a47f3700]: Initiating old logs cleanup (older than: 2016-May-28 15:43:59)
2016-11-24 15:43:59 Information: CCleanupModule [Thread 7ff7a47f3700]: Finished old logs cleanup
2016-11-24 15:43:59 Information: CCleanupModule [Thread 7ff7a47f3700]: Initiating event logs cleanup
2016-11-24 15:43:59 Information: CCleanupModule [Thread 7ff7a47f3700]: Finished event logs cleanup
2016-11-24 15:43:59 Information: CCleanupModule [Thread 7ff7a47f3700]: Initiating ignored logs cleanup
2016-11-24 15:44:00 Information: CCleanupModule [Thread 7ff7a47f3700]: Finished ignored logs cleanup
2016-11-24 15:44:00 Information: CCleanupModule [Thread 7ff7a47f3700]: Initiating obsolete delta logs cleanup
2016-11-24 15:44:01 Information: CCleanupModule [Thread 7ff7a47f3700]: Finished obsolete delta logs cleanup
2016-11-24 15:44:01 Information: CCleanupModule [Thread 7ff7a47f3700]: Initiating indexes cleanup
2016-11-24 15:44:01 Information: CCleanupModule [Thread 7ff7a47f3700]: Finished indexes cleanup
2016-11-24 15:44:01 Information: CCleanupModule [Thread 7ff7a47f3700]: Initiating storage cleanup
2016-11-24 15:44:01 Information: CCleanupModule [Thread 7ff7a47f3700]: Finished storage cleanup
2016-11-24 15:44:01 Information: CCleanupModule [Thread 7ff7a47f3700]: Initiating cleaning computer enrollement tombstone
2016-11-24 15:44:01 Information: CCleanupModule [Thread 7ff7a47f3700]: Finished cleaning computer enrollement tombstone
2016-11-24 15:44:01 Information: CCleanupModule [Thread 7ff7a47f3700]: Initiating static objects cleanup
2016-11-24 15:44:01 Information: CCleanupModule [Thread 7ff7a47f3700]: Finished static objects cleanup

Each cleanup phase should have start and end entry in trace log.

 

 

You also mention unixODBC. I wonder maybe it is the reason. Long time ago.. I've asked another issue https://forum.eset.com/topic/9520-no-progress-count/, but no one give me the answer.

Maybe it's relative. In fact, I don't use unixODBC. Because I use Ubuntu 16.04.1 LTS and MySQL 5.7. The unixODBC doesn't support MySQL 5.7. The unixODBC package has been removed from

Ubuntu 16.04. So I use MySQL connector/ODBC for Linux - https://dev.mysql.com/downloads/connector/odbc/ . Maybe ERA server 6.4 does not fully compatible MySQL connector/ODBC?

 

Using this combination of driver and MySQL should be fine in case your database is at leas of version 5.7.13. Previous versions had bug that caused ERA to not work correctly.

 

Just out of curiosity, how many endpoints is this installation managing? Does this problem happens for longer time? Has there been any outbreak in your environment that could flood ERA server with many logs? Could you also check database size in terms of size on disk?

[sdnian 6]

date

date -u

date +%z

 

# date

一 11月 28 09:33:55 CST 2016

# date -u

一 11月 28 01:33:58 UTC 2016

# date +%z

+0800

 

Each cleanup phase should have start and end entry in trace log.

 

I have not found same log. And I found a lot of below logs. It appear frequency every minue. No others 'CCleanupModule' log in trace.log file.

2016-11-27 23:37:46 Information: CCleanupModule [Thread 7f19d27fc700]: Initiating calculation of status snapshots
2016-11-27 23:37:46 Information: CCleanupModule [Thread 7f19d27fc700]: Finished calculation of status snapshots

Just out of curiosity, how many endpoints is this installation managing? Does this problem happens for longer time? Has there been any outbreak in your environment that could flood ERA server with many logs? Could you also check database size in terms of size on disk?

 

This ERA server has 600 clients. The 'era_db' database size is about 650MB.

 

And I resolve this problem. It didn't happen again last three days.

Edited November 28, 2016 by sdnian