Thingworx Application is down frequently?

[sarathi]

Thingworx Application is down frequently , It is taking very long time to respond.

This my Thingworx Application Log File

2019-07-08 14:47:00.161+0530 [L: WARN] [O: c.m.v.c.i.NewPooledConnection] [I: ] [U: ] [S: ] [T: pool-24-thread-1] [c3p0] A PooledConnection that has already signalled a Connection error is still in use!
2019-07-08 14:47:00.161+0530 [L: WARN] [O: c.m.v.c.i.NewPooledConnection] [I: ] [U: ] [S: ] [T: pool-24-thread-1] [c3p0] Another error has occurred [ org.postgresql.util.PSQLException: This connection has been closed. ] which will not be reported to listeners!
2019-07-08 14:47:00.161+0530 [L: ERROR] [O: c.t.p.p.PostgresModelExceptionTranslator] [I: ] [U: ] [S: ] [T: pool-24-thread-1] [message: [2,002] No connection. Contact the administrator.]
2019-07-08 14:47:00.161+0530 [L: WARN] [O: c.t.s.s.f.e.ReservationReclaimer] [I: ] [U: ] [S: ] [T: pool-24-thread-1] Failed to get any reservations
2019-07-08 14:52:09.654+0530 [L: ERROR] [O: E.c.t.w.Things] [I: ] [U: Orissa_HT_API] [S: ] [T: http-nio-8080-exec-20] [message: java.io.IOException: An existing connection was forcibly closed by the remote host]
2019-07-08 14:52:09.654+0530 [L: ERROR] [O: c.t.w.BaseService] [I: ] [U: Orissa_HT_API] [S: ] [T: http-nio-8080-exec-20] Internal error: org.apache.catalina.connector.ClientAbortException: java.io.IOException: An existing connection was forcibly closed by the remote host
2019-07-08 14:52:09.654+0530 [L: ERROR] [O: c.t.w.BaseService] [I: ] [U: Orissa_HT_API] [S: ] [T: http-nio-8080-exec-20] [context: com.thingworx.webservices.context.HttpExecutionContext@14720111][message: java.io.IOException: An existing connection was forcibly closed by the remote host]
2019-07-08 14:57:18.295+0530 [L: WARN] [O: c.m.v.c.i.NewPooledConnection] [I: ] [U: ] [S: ] [T: pool-24-thread-1] [c3p0] A PooledConnection that has already signalled a Connection error is still in use!
2019-07-08 14:57:18.311+0530 [L: WARN] [O: c.m.v.c.i.NewPooledConnection] [I: ] [U: ] [S: ] [T: pool-24-thread-1] [c3p0] Another error has occurred [ org.postgresql.util.PSQLException: This connection has been closed. ] which will not be reported to listeners!
2019-07-08 14:57:18.311+0530 [L: ERROR] [O: c.t.p.p.PostgresModelExceptionTranslator] [I: ] [U: ] [S: ] [T: pool-24-thread-1] [message: [2,002] No connection. Contact the administrator.]
2019-07-08 14:57:18.311+0530 [L: WARN] [O: c.t.s.s.f.e.ReservationReclaimer] [I: ] [U: ] [S: ] [T: pool-24-thread-1] Failed to get any reservations

Can any give suggestion how to find root cause of server down issue and what are all possible issues are there?

[slangley]

Hi @sarathi.

It sounds like you're losing database connectivity.  Here are some things you can check:

• Space issues
• Network issues or possibly a problem with the NIC (assuming the database and ThingWorx are on separate machines

You should also check the database logs for more information on what may be occurring.

Regards.

--Sharon

[sarathi]

Hi @slangley 

Thanks for your information still am facing the same issue

Herewith I have attached my Postgres log file

2019-07-12 19:20:09 IST LOG: could not receive data from client: An existing connection was forcibly closed by the remote host.

2019-07-12 19:20:09 IST LOG: could not receive data from client: An existing connection was forcibly closed by the remote host.

2019-07-12 19:20:09 IST LOG: could not receive data from client: An existing connection was forcibly closed by the remote host.

2019-07-12 19:20:09 IST LOG: could not receive data from client: An existing connection was forcibly closed by the remote host.

2019-07-12 19:20:09 IST LOG: unexpected EOF on client connection with an open transaction
2019-07-12 19:20:09 IST LOG: could not receive data from client: An existing connection was forcibly closed by the remote host.

2019-07-12 19:20:09 IST LOG: could not receive data from client: An existing connection was forcibly closed by the remote host.

2019-07-12 19:20:09 IST LOG: could not receive data from client: An existing connection was forcibly closed by the remote host.

2019-07-12 19:20:09 IST LOG: unexpected EOF on client connection with an open transaction
2019-07-12 19:20:09 IST LOG: could not receive data from client: An existing connection was forcibly closed by the remote host.

2019-07-12 19:20:09 IST LOG: could not receive data from client: An existing connection was forcibly closed by the remote host.

2019-07-12 19:20:09 IST LOG: could not receive data from client: An existing connection was forcibly closed by the remote host.

2019-07-12 19:20:09 IST LOG: could not receive data from client: An existing connection was forcibly closed by the remote host.

2019-07-12 19:20:09 IST LOG: could not receive data from client: An existing connection was forcibly closed by the remote host.

2019-07-12 19:20:09 IST LOG: could not receive data from client: An existing connection was forcibly closed by the remote host.

2019-07-12 19:20:09 IST LOG: could not receive data from client: An existing connection was forcibly closed by the remote host.

2019-07-12 19:20:09 IST LOG: could not receive data from client: An existing connection was forcibly closed by the remote host.

2019-07-12 19:20:09 IST LOG: could not send data to client: An existing connection was forcibly closed by the remote host.

2019-07-12 19:20:09 IST FATAL: connection to client lost
2019-07-12 20:57:20 IST ERROR: canceling autovacuum task
2019-07-12 20:57:20 IST CONTEXT: automatic vacuum of table "thingworx_29052019.public.property_vtq"

I could see that error frequently

unexpected EOF on client connection with an open transaction

[slangley]

Hi @sarathi.

Please advise the version of ThingWorx and PostgreSQL you're running.  Also, it would be helpful for you to restart Tomcat, then attach all log files located in \ThingworxStorage\logs as well as the PostgreSQL log (not just the snippets).

How are you configured?  Are you running ThingWorx on Linux or Windows?  Is PostgreSQL running on the same machine as ThingWorx?  Please provide as much information as possible regarding your configuration.

Regards.

--Sharon

[sarathi]

Hi @slangley 

First of all thank you for your reply

My details are following

Thingworx Setup: Version-8.3, Installed on Windows VM Server

PostgresSql:Version 9.4 , Installed on separate Windows VM Server

Both server are using SAN as a Strorage device 

Tomcat Max Heap size :20GB

Issue: Frequently tomcat was hanged and loaded with maximum memory , i cant able to figure out which service are  consume JVM memory

How to figure out which thingworx service are consumes maximum memory

i enable garbage collection herewith i have attached Thingworx Log file , GC Log file, and Postgres DB log file

[sarathi]

Hi @slangley 

Herewith i updated further log file

[slangley · Accepted solution]

Hi @sarathi.

The logs you provided contain many significant errors which point to coding as an issue.  Here are just a few:

2019-07-15 13:31:50.920+0530 [L: WARN] [O: c.t.w.c.ThreadLocalContext] [I: ] [U: AmalanT] [S: ] [T: pool-21-thread-1] ----> Security context stack is growing large : current size = [depth: 31]
2019-07-15 13:32:52.868+0530 [L: WARN] [O: c.t.w.c.ThreadLocalContext] [I: ] [U: sarathi] [S: ] [T: pool-21-thread-1] ----> Security context stack is growing large : current size = [depth: 32]
2019-07-15 13:34:58.337+0530 [L: WARN] [O: c.t.w.c.ThreadLocalContext] [I: ] [U: bhavya.redeem] [S: ] [T: pool-21-thread-1] ----> Security context stack is growing large : current size = [depth: 33]
2019-07-15 13:38:39.056+0530 [L: WARN] [O: c.t.w.c.ThreadLocalContext] [I: ] [U: Kshitij] [S: ] [T: pool-21-thread-1] ----> Security context stack is growing large : current size = [depth: 34]
2019-07-15 13:50:40.385+0530 [L: WARN] [O: c.m.v.a.ThreadPoolAsynchronousRunner] [I: ] [U: ] [S: ] [T: C3P0PooledConnectionPoolManager[identityToken->1hge4xna31vmo9iejfbjxp|232a9884]-AdminTaskTimer] com.mchange.v2.async.ThreadPoolAsynchronousRunner$DeadlockDetector@6dc5c687 -- APPARENT DEADLOCK!!! Creating emergency threads for unassigned pending tasks!
2019-07-15 13:50:59.807+0530 [L: WARN] [O: c.m.v.a.ThreadPoolAsynchronousRunner] [I: ] [U: ] [S: ] [T: C3P0PooledConnectionPoolManager[identityToken->1hge4xna31vmo9iejfbjxp|232a9884]-AdminTaskTimer] com.mchange.v2.async.ThreadPoolAsynchronousRunner$DeadlockDetector@6dc5c687 -- APPARENT DEADLOCK!!! Complete Status: __    Managed Threads: 8__    Active Threads: 0__    Active Tasks: __    Pending Tasks: __        com.mchange.v2.resourcepool.BasicResourcePool$ScatteredAcquireTask@3888b34c__        com.mchange.v2.resourcepool.BasicResourcePool$ScatteredAcquireTask@239021f9__        com.mchange.v2.resourcepool.BasicResourcePool$ScatteredAcquireTask@3833ddd0__        com.mchange.v2.resourcepool.BasicResourcePool$ScatteredAcquireTask@5f032ce3__        com.mchange.v2.resourcepool.BasicResourcePool$ScatteredAcquireTask@22ecf69c__Pool thread stack traces:__   

In regard to the "Security context growing large" error, here is an article to explain what is occurring.

For identifying the cause of the deadlocks, you would need to look at the running processes in the database at the time of the occurrence.  I recommend installing the Support Tools for assistance.

Regards.

--Sharon