B4J Question Websocket Server - Client connections - JVM not releasing memory

Status
Not open for further replies.

Jmu5667

Well-Known Member
Licensed User
Longtime User
Hello All

We have a web-socket server that uses an SSL connection for the clients. We were contacted by one of our customers informing us that the server was not working any more.

We looked at the server and it was not accepting any connections, and the existing connections had died. We started to investigate and built a test app that makes a connection to a ping class on on the server, once it has a connection, it disconnects and make the connection again. It will repeat this process forever unless you stop it. I have attached the test_ping app.

The problem we now face is that we are not sure what is causing the memory to keep growing. I have used visual VM on the server and all the threads being created are being release. We stripped down the ping class to its bare bones, here it is.

B4X:
'WebSocket class
Sub Class_Globals
 
   Private ws                    As WebSocket
 
End Sub

Public Sub Initialize

End Sub

Private Sub WebSocket_Connected (WebSocket1 As WebSocket)


    ws = WebSocket1
    ws.Session.MaxInactiveInterval = 30

End Sub

Private Sub WebSocket_Disconnected
 
    log("WebSocket_Disconnected")

End Sub

This is the command to start the server:

java -Xms32M -Xmx64M -XX:+UseG1GC -XX:MaxGCPauseMillis=200 -XX:parallelGCThreads=20 -XX:ConcGCThreads=5 -XX:InitiatingHeapOccupancyPercent=30 -jar ies_svr_aspect_hello.jar

Java Version :
1.8 1.8.0_202 http://java.sun.com/products/autodl/j2se C:\Program Files\Java\jre1.8.0_202\bin\javaw.exe true x86_64

Machine:
View attachment 77242

Main in the server app is as follows:


B4X:
'Non-UI application (console / server application)
' Version 1.0.0.8
#Region  Project Attributes
   #CommandLineArgs:
   #AdditionalJar: mssql-jdbc-6.2.2.jre8.jar
   #AdditionalJar: conscrypt-openjdk-uber-1.1.2.jar
   #AdditionalJar: bcprov-jdk15on-159.jar
#End Region

Sub Process_Globals
 
   Public DB_SQL As ConnectionPool
   Public srvr As Server
   Public svrConsole As ServerSocket
 
   ' // Global Map holding the settings
   Public SettingsMap As Map
   ' // Define the settings file which is read by the global settings map
   Public SettingsFile As String = "ies_svr_aspect_hello.ini"
   Public appPath As String
   Public logPath As String
 
   Private logStream    As OutputStream

End Sub

Sub AppStart (Args() As String)
 
   Dim res As Int
  
   Try
       appPath = mod_settings.get_app_path
       logPath = mod_settings.get_log_path
  
       mod_settings.load_settings
 
       writelog("AppStart, Version 1.0.0.8")
  
       ' // setup the SQL server
       res = ConfigureSQL
       If res > 0 Then
           ExitApplication2(res)
       End If
  
  
       ' // configure websocket  
       srvr.Initialize("")
       srvr.AddWebSocket("/ping", "ping")
       res = ConfigureSSL(SettingsMap.Get("ssl_port"))
       If res > 0 Then
           ExitApplication2(res)
       End If
       srvr.Port = SettingsMap.Get("http_port")
       srvr.Http2Enabled = True
       srvr.Start
                
       ' // start the message loop
       StartMessageLoop
  
   Catch
       writelog("Error " & LastException.Message)
       ExitApplication2(999)
   End Try
 
 
 
End Sub

private Sub ConfigureSQL As Int
 
 
   Dim res As Int = 0

   Try
       DB_SQL.Initialize("com.microsoft.sqlserver.jdbc.SQLServerDriver","jdbc:sqlserver:" & _
                       SettingsMap.Get("sql_host"), _
                       mod_security.decrypt(SettingsMap.Get("sql_usr")), _
                       mod_security.decrypt(SettingsMap.Get("sql_pwd")))
      
       If Not(DB_SQL.IsInitialized) Then
           res = 1       
           writelog("ConfigureSQL() error - " & SettingsMap.Get("sql_host") & ", Not Initialized")
           writelog("ConfigureSQL() error -  " & LastException.Message)
       Else
           writelog("ConfigureSQL() SQL IsInitialized = " & DB_SQL.IsInitialized)
       End If
      
      
       ' // set the connection pool size
       Dim jo As JavaObject = DB_SQL
       Dim pool As Int  = SettingsMap.Get("sql_pool")
       writelog("AppStart pool   = " & pool)
       jo.RunMethod("setMaxPoolSize", Array(pool))
  
   Catch
       writelog("ConfigureSQL() error -  " & LastException.message)
       res = 1
   End Try
  
  
   Return res
 
End Sub

Private Sub ConfigureSSL (SslPort As Int) As Int
 
   Dim res As Int = 0
 
   Try
       ' // SSL connector configuration
       Dim ssl As SslConfiguration
  
       ssl.Initialize
       ssl.SetKeyStorePath(File.GetFileParent(SettingsMap.Get("keystore")) , File.GetName(SettingsMap.Get("keystore")))
       ssl.KeyStorePassword = mod_security.decrypt(SettingsMap.Get("ssl_pwd"))
       ssl.KeyManagerPassword = mod_security.decrypt(SettingsMap.Get("ssl_pwd"))
       ssl.EnableConscryptProvider
       srvr.SetSslConfiguration(ssl, SslPort)
       writelog("ConfigureSSL() " & SslPort & ", Configured")
   Catch
       res = 2
       writelog("ConfigureSSL() " & SslPort & ", Error - " & LastException.Message)
   End Try
      
   Return res
      
End Sub


Sub writelog(pData As String)
 
   DateTime.DateFormat = "yyyy-MM-dd"
   DateTime.TimeFormat = "HH:mm:ss.SSS"
 
   RedirectOutput(logPath,"ies_svr_aspect_hello.log")
 
   If File.Size(logPath,"ies_svr_aspect_hello.log") > ((1024*1024)*10) Then
 
       logStream.Close
       ' // remove existing backup
       If File.Exists(logPath,"ies_svr_aspect_ptt_prev10mb.log") Then
           File.Delete(logPath,"ies_svr_aspect_ptt_prev10mb.log")
       End If
       ' // make new backup
       File.Copy(logPath,"ies_svr_aspect_hello.log",logPath,"ies_svr_aspect_hello_prev10mb.log")
       ' // delete current log
       File.Delete(logPath,"ies_svr_aspect_hello.log")
       RedirectOutput(logPath,"ies_svr_aspect_hello.log")
 
   End If

   Dim logString As String
   Dim Data() As Byte
   logString =  DateTime.date(DateTime.Now) & " " & DateTime.Time(DateTime.Now) & _
                   " " & pData & CRLF
   Data = logString.GetBytes("UTF8")

   logStream.WriteBytes(Data,0,Data.Length)
   logStream.Flush
   logStream.Close
 
   Log(logString)
 
End Sub


Sub RedirectOutput (Dir As String, FileName As String)
 
   logStream = File.OpenOutput(Dir,FileName,True)
 
End Sub

The server uses keystore so if anyone want to assist in helping you will need the same setup. As I said before we do not know why this is happening and I would like to hear from other who may have had this problem, or who have a production deployed solution similar to this but do not have this issue.

I will be back online Sunday 10th to work on this.

Regards

John.
 
Last edited:

OliverA

Expert
Licensed User
Longtime User
If i do not close the sql in the class it will cause a leak.
I need to quit posting before breakfast :). That only applies when not using a pool. Just consider that portion Off topic and ignore. On topic: keep pool size somewhere between 5-10
 
Upvote 0

Jmu5667

Well-Known Member
Licensed User
Longtime User
Here the log file of the crash, if you go to line 57309 you will see the start of the Out of Memory. The app is still running, should I go ti visual vm and get a heap dump ?
 

Attachments

  • ies_svr_aspect_hello.zip
    329.8 KB · Views: 344
Upvote 0

Jmu5667

Well-Known Member
Licensed User
Longtime User
Some info from Visual VM on a thread crash:

"qtp1915058446-28724" - Thread t@28724
java.lang.Thread.State: TIMED_WAITING
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <5e094947> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
at java.util.concurrent.locks.LockSupport.parkNanos(Unknown Source)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(Unknown Source)
at org.eclipse.jetty.util.BlockingArrayQueue.poll(BlockingArrayQueue.java:392)
at org.eclipse.jetty.util.thread.QueuedThreadPool.idleJobPoll(QueuedThreadPool.java:652)
at org.eclipse.jetty.util.thread.QueuedThreadPool.access$800(QueuedThreadPool.java:48)
at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:715)
at java.lang.Thread.run(Unknown Source)

Locked ownable synchronizers:
- None

log data from the server app:

2019-02-11 12:49:38.543:WARN:eek:ejut.QueuedThreadPool:qtp1915058446-28724:
java.lang.OutOfMemoryError: Direct buffer memory
at java.nio.Bits.reserveMemory(Unknown Source)
at java.nio.DirectByteBuffer.<init>(Unknown Source)
at java.nio.ByteBuffer.allocateDirect(Unknown Source)
at org.conscrypt.ConscryptEngine.getOrCreateLazyDirectBuffer(ConscryptEngine.java:1221)
at org.conscrypt.ConscryptEngine.readPlaintextDataHeap(ConscryptEngine.java:1125)
at org.conscrypt.ConscryptEngine.readPlaintextData(ConscryptEngine.java:1102)
at org.conscrypt.ConscryptEngine.unwrap(ConscryptEngine.java:852)
at org.conscrypt.ConscryptEngine.unwrap(ConscryptEngine.java:724)
at org.conscrypt.ConscryptEngine.unwrap(ConscryptEngine.java:689)
at org.conscrypt.Java8EngineWrapper.unwrap(Java8EngineWrapper.java:236)
at org.eclipse.jetty.io.ssl.SslConnection$DecryptedEndPoint.fill(SslConnection.java:681)
at org.eclipse.jetty.server.NegotiatingServerConnection.fill(NegotiatingServerConnection.java:153)
at org.eclipse.jetty.server.NegotiatingServerConnection.onFillable(NegotiatingServerConnection.java:98)
at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:281)
at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:102)
at org.eclipse.jetty.io.ssl.SslConnection.onFillable(SslConnection.java:291)
at org.eclipse.jetty.io.ssl.SslConnection$3.succeeded(SslConnection.java:151)
at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:102)
at org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:118)
at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:760)
at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:678)
at java.lang.Thread.run(Unknown Source)
2019-02-11 12:49:38.543:WARN:eek:ejut.QueuedThreadPool:qtp1915058446-28724: Unexpected thread death: org.eclipse.jetty.util.thread.QueuedThreadPool$2@1eedfa7b in QueuedThreadPool[qtp1915058446]@7225790e{STARTED,8<=8<=200,i=2,q=0}[ReservedThreadExecutor@6f15cc30{s=1/2,p=0}]
 
Upvote 0

OliverA

Expert
Licensed User
Longtime User
The default min/max settings for Jetty's thread pool seem to be 8/200 (https://support.sonatype.com/hc/en-...tanding-Eclipse-Jetty-9-4-8-Thread-Allocation). The settings can be configured via XML or when instantiating the Jetty server object, neither of which seem to be available under B4J (could be wrong, someone else can chime in on this) (https://stackoverflow.com/a/21841959). So you are just running out of memory (https://github.com/apache/incubator-druid/issues/2856) for the amount of traffic you are generating to your server.
 
Upvote 0

Jmu5667

Well-Known Member
Licensed User
Longtime User
The default min/max settings for Jetty's thread pool seem to be 8/200 (https://support.sonatype.com/hc/en-...tanding-Eclipse-Jetty-9-4-8-Thread-Allocation). The settings can be configured via XML or when instantiating the Jetty server object, neither of which seem to be available under B4J (could be wrong, someone else can chime in on this) (https://stackoverflow.com/a/21841959). So you are just running out of memory (https://github.com/apache/incubator-druid/issues/2856) for the amount of traffic you are generating to your server.

It would appear to be that, but I am still concerned that memory is not being released ? Am I wrong ? There must be something I am doing wrong, even when I use our B4A app for the server and load data, I see memory being used, but not being released.

I updated from conscrypt-openjdk-uber-1.1.2.jar to conscrypt-openjdk-uber-1.1.4.jar, made no difference.

There must be a solution to this.
 
Upvote 0

OliverA

Expert
Licensed User
Longtime User
Unless your server that provides the WebSocket service also host a regular site with lots of content on a page (text, pictures, javascript), turn HTTP/2 off. HTTP/2 does not really help with WebSocket communications. For a better overview/comparison, see: https://blog.sessionstack.com/how-j...h-sse-how-to-pick-the-right-path-584e6b8e3bf7

Now if after turning HTTP/2 off and letting Java handle the heap instead of constraining it via command line arguments you still get errors, we can tackle them at that time.

There must be something I am doing wrong, even when I use our B4A app for the server and load data, I see memory being used, but not being released.
What memory release are you talking about? The memory allocated as shown in Window's Task Manager? Who cares? As long as the application starts leveling out, why does it matter if it gives the memory back? My test app uses about 100MB+-4MB and stays there. It does the job. Or are you talking about what VisualVM shows you? In my case, I posted a picture of VisualVM's heap monitor and it nicely shows how the used heap space grows and shrinks. Please note that this growing and shrinking is not at all reflected what Task Manager shows and it should not! Constantly grabbing and releasing memory from the operating system is very resource expensive/intensive!
 
Upvote 0

Jmu5667

Well-Known Member
Licensed User
Longtime User
Why are you using conscrypt?

See the first line in the tutorial: https://www.b4x.com/android/forum/threads/server-conscrypt-and-http-2.93040/

BTW, you haven't written that you are using http/2. This is not the same as writing that you are using SSL...

Sorry, I though conscript was a replacement for -Xbootclasspath/p:alpn-boot-8.1.11.v20170118.jar as it was no longer supported, that is why I switched to conscript, I obviously did not read the edit update correctly.

So, do I need to use Xbootclasspath/p:alpn-boot-8.1.11.v20170118.jar with the latest build of B4j ?
 
Upvote 0

OliverA

Expert
Licensed User
Longtime User
You can use Conscrypt with Java 8, just don't enable HTTP/2.
You just need java 9+ and enabling Http/2, no more need for the alpn-boot stuff.
In his case he may not even need HTTP/2 if he only uses WebSockets/simple HTTPS communications.

Off topic: 2/1/2019 if you want to use Java 8 and above for business purposes, you either pay Oracle, use OpenJDK or use someone else's implementation of their JDK/JRE (IBM, RedHat, etc) that are available for commercial use without having to pay license fees.
 
Upvote 0

Jmu5667

Well-Known Member
Licensed User
Longtime User
You can use Conscrypt with Java 8, just don't enable HTTP/2.

In his case he may not even need HTTP/2 if he only uses WebSockets/simple HTTPS communications.

Off topic: 2/1/2019 if you want to use Java 8 and above for business purposes, you either pay Oracle, use OpenJDK or use someone else's implementation of their JDK/JRE (IBM, RedHat, etc) that are available for commercial use without having to pay license fees.

Are the issues with conscrypt only with http/2 ?
 
Upvote 0

OliverA

Expert
Licensed User
Longtime User
Upvote 0

Jmu5667

Well-Known Member
Licensed User
Longtime User
What memory release are you talking about? The memory allocated as shown in Window's Task Manager? Who cares? As long as the application starts leveling out, why does it matter if it gives the memory back? My test app uses about 100MB+-4MB and stays there. It does the job. Or are you talking about what VisualVM shows you? In my case, I posted a picture of VisualVM's heap monitor and it nicely shows how the used heap space grows and shrinks. Please note that this growing and shrinking is not at all reflected what Task Manager shows and it should not! Constantly grabbing and releasing memory from the operating system is very resource expensive/intensive!

I saw the picture and it is what I would expect, but in relation to windows task manager, is it showing a cumulative value .ie. paging etc and not just actual RAM ?
 
Upvote 0

OliverA

Expert
Licensed User
Longtime User
Under Process (Task Manager), it should show actual RAM. If you want to check out cache/paged/non-paged pool usage, check out the Performance tab. I don't think anywhere it will show you which applications are using paged/non-paged pooling, it's just a general overview. Please note, that just because VisualVM shows you a 200MB heap does not mean that Java will allocate all at once. As per my example, the app was at most using ~50MB of the 200MB heap and the total RAM usage under Task Manager was ~100MB.
 
Upvote 0

Jmu5667

Well-Known Member
Licensed User
Longtime User
Under Process (Task Manager), it should show actual RAM. If you want to check out cache/paged/non-paged pool usage, check out the Performance tab. I don't think anywhere it will show you which applications are using paged/non-paged pooling, it's just a general overview. Please note, that just because VisualVM shows you a 200MB heap does not mean that Java will allocate all at once. As per my example, the app was at most using ~50MB of the 200MB heap and the total RAM usage under Task Manager was ~100MB.
Cool, I will leave it run over night :)
 
Upvote 0
Status
Not open for further replies.
Top