B4J Question [Solved] Out of Memory Issue

[Harris]

My app has been functioning great for many years. July 14, 2021 it started misbehaving...

This is the batch file that starts my app, which is large (24 meg)..

'cd\root
'java -Xmx1024M -jar tripinspect.jar
'pause


This is the error file (log section)...

'main._appstart (java line: 279)
'java.lang.RuntimeException: java.lang.OutOfMemoryError: unable To create new native thread
'    at anywheresoftware.b4a.BA.raiseEvent2(BA.java:120)
'    at anywheresoftware.b4a.objects.Timer$TickTack$1.run(Timer.java:118)
'    at anywheresoftware.b4a.keywords.SimpleMessageLoop.runMessageLoop(SimpleMessageLoop.java:30)
'    at anywheresoftware.b4a.StandardBA.startMessageLoop(StandardBA.java:26)
'    at anywheresoftware.b4a.keywords.Common.StartMessageLoop(Common.java:153)
'    at abmtripinspect.ti.com.main._appstart(main.java:279)
'    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
'    at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
'    at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
'    at java.lang.reflect.Method.invoke(Unknown Source)
'    at anywheresoftware.b4a.BA.raiseEvent2(BA.java:91)
'    at anywheresoftware.b4a.BA.raiseEvent(BA.java:78)
'    at abmtripinspect.ti.com.main.main(main.java:28)
'Caused by: java.lang.OutOfMemoryError: unable To create new native thread
'    at java.lang.Thread.start0(Native Method)
'    at java.lang.Thread.start(Unknown Source)
'    at anywheresoftware.b4a.objects.Timer.startTicking(Timer.java:68)
'    at anywheresoftware.b4a.objects.Timer.setEnabled(Timer.java:77)
'    at abmtripinspect.ti.com.callsubutils._plusimpl(callsubutils.java:130)
'    at abmtripinspect.ti.com.callsubutils._callsubdelayedplus2(callsubutils.java:73)
'    at abmtripinspect.ti.com.main._prtim_tick(main.java:477)
'    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
'    at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
'    at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
'    at java.lang.reflect.Method.invoke(Unknown Source)
'    at anywheresoftware.b4a.BA.raiseEvent2(BA.java:91)
'    ... 12 more
'
'main.main (java line: 28)
'java.lang.RuntimeException: java.lang.RuntimeException: java.lang.OutOfMemoryError: unable To create new native thread
'    at anywheresoftware.b4a.BA.raiseEvent2(BA.java:120)
'    at anywheresoftware.b4a.BA.raiseEvent(BA.java:78)
'

If I remove the - -Xmx1024M from the startup bat, will it use as much memory as it needs to run any process?

Right now, dead in the water....
Thx

 

[Erel]

Is this a server app? Why are you using CallSubPlus?
It looks like you are creating more and more timers until the app crashes.

 

[Harris]

Is this a server app? Why are you using CallSubPlus?

Yes, server app using ABMaterial...
Using CallSubPlus from legacy - prior to any notion of Wait For...

Funny thing, works great in my dev environment in release - but throws error in remote production server...

Only one timer is ever created - just enabled and disabled when required... Has worked this way for years.... Java 8.

I shall upload a new copy of the jar file to remote server and see what happens then...
Strange Beans....

 

[alwaysbusy]

On our production server we have a similar issue with our main WebApp, also starting from somewhere this summer. I wrote some extra functions into the HikaryCP library from Kiffi (updated it to v5.0.0 too, see attachment) to track some stuff like memory consumption, left-open connections in the pool etc (we did had one fringe case that did not close an SQL, however it did not fix the overall memory problem).

I also added in the background worker some code that initiates (suggests actually) to Java to do some garbage collection. This does does the WebApp last longer. Our Server guru has for the moment also a CRON job set that does restart the WebApp every 2 weeks on Sunday night.

We are still in the phase of analysing the cause, but at least this (temporary) fixes the problem for our users.

GarbageCollectorWorker:

Sub Class_Globals
    Private tmrHook As Timer
    Private gcTime As Long
    Private freq_gc As Int = 1
    Private freq_info As Int = 10
    Private Counter As Int
End Sub

'Initializes the object. You can add parameters to this method if needed.
Public Sub Initialize
    '  3 seconds
    tmrHook.Initialize("tmrHook", 3000)
    tmrHook.Enabled = True
   
    #if debug
          freq_info = 1
    #End If
   
    '  set the initial GC time
    gcTime =DateTime.Now + (DateTime.TicksPerMinute * freq_gc)
   
    StartMessageLoop '<- don't forget!
End Sub

Sub tmrHook_Tick()
    '  do GC
    If gcTime < DateTime.Now Then
        '  set next time
        gcTime =DateTime.Now + (DateTime.TicksPerMinute * freq_gc)
        process_gc
    End If
End Sub

Sub process_gc()   
    Counter = Counter + 1
    If Counter = freq_info Then
        Log("Running Info Collector...")
        Counter = 0
       
        Dim variables As List
        variables.Initialize
        variables.Add(0)
        variables.Add(0)
        variables.Add(8)
        variables.Add("Info Collection " & Main.ClientID)
        variables.Add(FormatDateTimeNow3)
        variables.Add(0)
       
        Dim MB As Long = 1024 * 1024
       
        variables.Add(DBM.pool.MemoryUsed / MB)
        variables.Add(DBM.pool.MemoryAllocatedFree / MB)
        variables.Add(DBM.pool.activeConnections)
        variables.Add(DBM.pool.ThreadsAwaitingConnection)
        variables.Add(DBM.pool.totalConnections - DBM.pool.activeConnections)
      

        Dim SQL As SQL = DBM.GetSQL
        Dim SQL_str As String = $"INSERT INTO tsys_Trace(OTID, trcLoginID, trcTrcTypID, trcInfo, trcDateTime, trcLinkID, trcMemUsed, trcMemAllocFree, trcActiveConnections, trcThreadsAwaitingConnection, trcFreeConnections) VALUES (?,?,?,?,?,?,?,?,?,?,?)"$
        SQL.ExecNonQuery2(SQL_str, variables)
        DBM.CloseSQL(SQL)
    End If
   
    Log("Running Garbage Collector...")
   
    Dim jo As JavaObject = Me
    
    jo.RunMethod("do_garbage_collection",Null)
    
End Sub

Public Sub FormatDateTimeNow3() As String
    Dim orig As String = DateTime.DateFormat
    DateTime.dateformat = "yyyy-MM-dd'T'HH:mm:ss"
    Dim ret As String = DateTime.Date(DateTime.now)
    DateTime.dateformat = orig
    Return ret
End Sub

#if java
   import java.util.*;
 
   public void do_garbage_collection()   {        
       Runtime rs = Runtime.getRuntime();
       rs.gc();
   }  
#End If

For ABHikariCP, these settings are needed in Region Project Attributes (jars included in the .zip)

    #AdditionalJar: HikariCP-5.0.0.jar
    #AdditionalJar: slf4j-api-1.7.32       
    #AdditionalJar: slf4j-simple-1.7.32.jar
    #AdditionalJar: jsch-0.1.55.jar

Alwaysbusy

 

[tchart]

My app has been functioning great for many years. July 14, 2021 it started misbehaving...

Right now, dead in the water....
Thx

@Harris if you are running on WIndows why not run it as a service?

WinSW has a method that allows the app to restart itself - I use this to restart a long running app that would misbehave after a few weeks of running. See tutorial below.

Better Windows Services (for B4J)

There are many threads on the fourm regarding Windows Services e.g. https://www.b4x.com/android/forum/threads/java-as-windows-service.65741/#content For many years Ive used "JavaService" but this is old, hasnt been updated for years and while robust isn't that friendly to set up. To be fair to...

www.b4x.com

 

[Harris]

@Harris if you are running on WIndows why not run it as a service?

Way back when I was implementing my app, I searched for a way to run it as a service - to no avail...
So I purchased AlwaysUp, that essentially does the same thing - restarts stalled apps and starts them at boot (Windows).

On a fresh app start, it will throw the error the first time the condition is encountered....


Here is what I do...

In AppStart - I init a file watcher to look for new incoming files.
These are zip files sent from the Android tablets and contain CSV data (ecm and gps).
These files are received properly...

    myApp.StartServer(srvr, "srvr", 51049)   
    
    ' start server HTTP/2
    ' myApp.StartServerHTTP2(srvr, "srvr", yourport, yoursslport, "yourkeystorefile", "yourkeystorepassword", "yourkeymanagerpassword")

    fw.Initialize("fw").SetWatchList(Array As String(ecmFolder)).StartWatching

When a new file arrives, the proctimer (processzipfile) is enabled...

Sub fw_CreationDetected(FileName As String)
    Log("CreationDetected: " & FileName)    'Logs the creation of a new file or folder
    If inprocess = False Then
        inprocess = True
        proctimer.Enabled = True
    End If
    
End Sub

When the proc ticks, it gets a list of files in the "ecmfolder". If they are zip files, they will be processed.

Sub prtim_tick
    
        Dim lof As List
        lof.Initialize
        lof = File.ListFiles(ecmFolder)
        For i  = 0 To lof.Size -1
            Dim str As String
            str = lof.Get(i)
            If str.Contains(".zip") Then
               csu.CallSubDelayedPlus2(Me,  "ProcessEcmZips",  2000,  Array(str))
            End If
        Next
        proctimer.Enabled = False   
        inprocess = False
        
End Sub

Now, the text files contained in the zip will be placed (unzipped) into the specific Truck folder to which they belong.
The zip file will be copied to a History folder (in case I ever need it) and then deleted from the current folder. Done...

Note: This all works perfectly on my dev system, but fails first time on remote server... It all started July 14 on remote server for some spooky reason...
I am currently peppering the subs with logs to see at what point it goes so very sideways... and hope this exposes the root of the problem...

Sub ProcessEcmZips(fn() As Object)
    Log(" will process this: "&fn(0))
    csu.CallSubDelayedPlus2(Me,  "PlaceinDir",  1000, Array(fn(0)))
End Sub

Sub PlaceinDir(fn() As Object)
    
    Dim str, str1 As String
    Dim id, id1 As Int
    str = fn(0)
    If str.Contains(".zip") Then
        If File.Exists(ecmFolder,str) Then
            Dim arc As Archiver
            
            id = str.IndexOf("_")
            id1 = str.IndexOf(".")
            str1 = str.SubString2(id+1,id1)
            Log(" Folder to create: "&str1)
            Dim newfld As String = "TR_"&str1
            File.MakeDir(ecmFolder,newfld)
            File.MakeDir(base_ecm, "hist")
            
            arc.AsyncUnZip( ecmFolder,str,ecmFolder&"/"&newfld, "unzip")
            
            File.Copy( ecmFolder,str,base_ecm&"/hist",str)
            csu.CallSubDelayedPlus2(Me,  "delzip",  2000, Array(str))
                
            
        End If
    End If
End Sub

Sub delzip(fn() As Object)
    
    Dim str As String = fn(0)
    File.Delete(ecmFolder, str) ',base_ecm&"/hist",str)
    Log(" File to delete: "&str)

End Sub

Sub unzip_UnZipDone(err As Boolean, no As Int)
    ' handle file if needed
    Log(" Unzipdone - completed without error? "&err& "num files:"&no     )

End Sub

 

[Harris]

Looking at the error log closely, it seems that the csu.callsub timer may be an issue...
As Erel stated: "Why am I using this?" Short answer - legacy... I try avoiding "Fixing what ain't Broken" - until it breaks - like now!

'    at abmtripinspect.ti.com.callsubutils._plusimpl(callsubutils.java:130)
'    at abmtripinspect.ti.com.callsubutils._callsubdelayedplus2(callsubutils.java:73)
'    at abmtripinspect.ti.com.main._prtim_tick(main.java:477)

EDIT

read comments in following...

        Dim lof As List
        lof.Initialize
        lof = File.ListFiles(ecmFolder) '   Houston - we have a problem....   There are over 2000 zip files in this folder (since July 14 - more files are added everyday).
        For i  = 0 To lof.Size -1
            Dim str As String
            str = lof.Get(i)
            If str.Contains(".zip") Then
' lets try and create over 2000 timers in the CallSubDelayedPlus2.  Think that will raise an OOM error?
               csu.CallSubDelayedPlus2(Me,  "ProcessEcmZips",  2000,  Array(str))
            End If
        Next
        proctimer.Enabled = False   
        inprocess = False

 

[Harris]

' lets try and create over 2000 timers in the CallSubDelayedPlus2. Think that will raise an OOM error?

I couldn't see the Forest because I thought I was looking at a Single Tree!!!!

Well, I moved all 2500 zip files out of the watched folder - and then gave it just One to chew on....
Worked as expected - unzipped files to correct folder, copied file to history folder and deleted processed zip file...

Obviously I must re-think how this process is handled to prevent creating so many timers when faced with so many files... A simple EXIT in the loop should do and eventually all files will get processed in due time. Or, more appropriately - use a simple Wait For to do the same thing!

The question is: how did the watched folder get so many files on the day of starting the error?
Answer: 50 trucks (tablets) deliver these files to the server each day via WiFi. If any one truck cannot make a connection to the server, then these files remain on the device until they can be delivered. Lets say, if the connection could not be made for a week or so (which has happened), this could amount to 150 or more zip files hitting the watched folder at the same time....

Thanks Erel for pointing me to a timer.... Took me awhile to determine WHICH timer you were referring to...
I must get better at reading the error logs...

As we live, we learn....

Thanks all....

 

[tchart]

@Harris I know its a legacy project but it sounds like you need to queue the processing rather than spinning up separate timers.

In one of my projects I have a timer to do background processing. It pauses the timer and processes a batch (500 at a time) before re-enabling the timer.

 

[Harris]

I hear ya tchart...

I now see how I can make it so much simpler and remove all csu.CallSubDelayed (which makes additional timers), and also remove the file watcher...
My current handling of this is way too complicated - needlessly...

Using one enabled timer, every 10 seconds get a list of files in the folder...
If one item is a zip file, process it and exit the loop. This will process 6 zip files every minute - which is more than adequate for my needs.
For the most part, the timer tick will do nothing because it will not find any files to process...

I do this for similar processes and it works just fine - never an issue...
Thanks

 

[Harris]

This works.... simple and effective...
Timer looks at new file folder containing incoming zips.
Fires every 10 seconds... Processes each until folder is empty...

Corrections are welcome. Love to learn from you experts...

Sub prtim_tick
    
        Dim lof As List
        lof.Initialize
        lof = File.ListFiles( ecmFolder1)
        Log(" how many new ecmfiles to process: "&lof.Size)
        For i  = 0 To lof.Size -1
            Dim str As String
            str = lof.Get(i)
            If str.Contains(".zip") Then
                PlaceinDir(str)
                Exit  ' process one file and wait for timer to tick again , one file less in folder - 5 to 10 seconds later, whatever I set it to...
            End If
        Next
        
End Sub


Sub PlaceinDir(fn As String)
    
    Dim str, str1 As String
    Dim id, id1 As Int
    str = fn
    If str.Contains(".zip") Then
        If File.Exists(ecmFolder1,str) Then
            Dim arc As Archiver
            
            id = str.IndexOf("_")
            id1 = str.IndexOf(".")
            str1 = str.SubString2(id+1,id1)
            Log(" Folder to create: "&str1&"  file got from: "&ecmFolder1)
            Dim newfld As String = "TR_"&str1
            File.MakeDir(ecmFolder,newfld)
            File.MakeDir(base_ecm, "hist")
            
            arc.AsyncUnZip( ecmFolder1, str, ecmFolder&"/"&newfld, "unzip")
            Sleep(2000) ' wait a short bit for AsyncUnZip to do its stuff....
            
            Wait For (File.CopyAsync(ecmFolder1,str,base_ecm&"/hist",str)) Complete (Success As Boolean)
            Log("file copy to hist Success: " & Success)
            If Success Then
               Log("Did copy file to hist: " & str)
               delzip(str)
               Sleep(500)   ' wait for file to get deleted....
              
            Else
                Log("Did not delete file due to copy failure: " & str)
            End If
            
        End If
    End If
End Sub

Sub delzip(str As String)
    
    Log(" File to delete: "&ecmFolder1&"/"&str&" -  ")

    Wait For (File.Delete( ecmFolder1, str)) Complete (Success As Boolean)

' below did not work... no log entry so commented out...  File WAS deleted however....

'    If Not (File.Exists(ecmFolder1,str))  Then
'        Log(" File WAS deleted: "&ecmFolder1&"/"&str&" -  ")
'    Else
'        Log(" File WAS NOT Deleted: "&ecmFolder1&"/"&str&" -  ")
'    End If       

End Sub

 

[Jmu5667]

Sub prtim_tick

Dim lof As List
lof.Initialize
lof = File.ListFiles( ecmFolder1)
Log(" how many new ecmfiles to process: "&lof.Size)
prtim.enabled = false
For i = 0 To lof.Size -1
Dim str As String
str = lof.Get(i)
If str.Contains(".zip") Then
PlaceinDir(str)
Exit ' <- REMOVE
End If
Next
prtim.enabled = true
End Sub

In your prtim_tick code, disable the timer before the for loop, and enable if after the for loop is finished.

 

[EnriqueGonzalez]

Dim lof As List
lof.Initialize
lof = File.ListFiles( ecmFolder1)

Dont initialize and later apply a value, you are just setting the memory twice.

Dim str As String
str = lof.Get(i)
If str.Contains(".zip") Then

if lof.get(i).as(string).contains(".zip") then

" File to delete: "&ecmFolder1&"/"&str&" - "

You can use smartstrings

[B4X] Smart String Literal

The "smart string" literal is a more powerful version of the standard string literal. It has three advantages: Supports multi-line strings. No need to escape quotes. Supports string interpolation. The smart string literal starts with $" and ends with "$. Examples: Dim s As String = $"Hello...

www.b4x.com

Corrections are welcome. Love to learn from you experts...

not an expert, but this corrections will ease your life.

 

[Harris]

Geeezzzz.
When it comes to proper event coding, one often forgets more than they learn - the hard way.... (comes back and bites you in the arse)

1) When dealing with Async methods (fired in another thread - on their own good time), do other important stuff in the Done event/method raised... (I used to know this some time ago...)
Such as in my case, - unzip a file. When done event raised, copy it to backup folder (new code below). Then delete it if required (required in my case).

2) A virtual machine (all in RAM) is much faster than your local dev machine if it has to spin a hard disk to operate.... I refactored my code to respect this.

However, I now think a corrupt zip file was actually at fault - not allowing my "fool proof" process to continue... (lol)

3) Deal with errors effectively. Here I have an issue. In this situation, a corrupt zip file is presented. After AsyncUnZip() tried to unzip it, it seems I can't delete it...
Therefore, it remains in the list and tries to get processed, over and over again.... never moving on with all other files in the list.....

Brain is stuck trying to resolve. Added new issue thread with same problem - unzip . https://www.b4x.com/android/forum/threads/detect-corrupt-zip-file.135581/
Until the light bulb turns on, time to make a scalloped potato entre from my massive crop this year.
Just finished hauling the rest of the crop to my root cellar since it will dip to -4 C tonight...

Keep on gardening folks....Your local store does not generally grow your produce... Its up to you...

Sub unzip_UnZipDone(err As Boolean, no As Int)
    ' handle file if needed
    Log(ABMShared.CurrDT& " Unzipdone - completed without error? "&err& "   num files:"&no     )
    
    Wait For (File.CopyAsync(ecmFolder1,currdel,base_ecm&"/hist",currdel)) Complete (Success As Boolean)
    'Log("file copy to hist Success: " & Success)
    If Success Then
        Log("  --- Did copy file to hist: " & currdel)
    Else
        Log("  --- Did not copy file due to copy failure: " & currdel)
    End If
    
    delzip(currdel)
    
End Sub


Sub delzip(str As String)
    
Log(" File to delete: "&ecmFolder1&"/"&str)

    File.Delete( ecmFolder1,  str)

    If (File.Exists(ecmFolder1,str))  Then
        Log(ABMShared.CurrDT&" File WAS NOT deleted: "&ecmFolder1&"/"&str)
    Else
        Log(ABMShared.CurrDT&" File WAS Deleted!!!: "&ecmFolder1&"/"&str)
    End If       

End Sub

The log file counting down every zip it processes...

2021/10/29 - 17:34:16 Unzipdone - completed without error? true   num files:14
  ---  Did copy file to hist: 1632670239668_72205.zip
 File to delete: C:\root/www/tripinspect/inecm/1632670239668_72205.zip
2021/10/29 - 17:34:16 File [B]WAS [/B]Deleted!!!: C:\root/www/tripinspect/inecm/1632670239668_72205.zip
2021/10/29 - 17:34:25 how many new ecmfiles to process: 449
 Folder to create: 72205  file got from: C:\root/www/tripinspect/inecm
2021/10/29 - 17:34:26 Unzipdone - completed without error? true   num files:14
  ---  Did copy file to hist: 1632670239814_72205.zip
 File to delete: C:\root/www/tripinspect/inecm/1632670239814_72205.zip
2021/10/29 - 17:34:26 File [B]WAS [/B]Deleted!!!: C:\root/www/tripinspect/inecm/1632670239814_72205.zip
2021/10/29 - 17:34:36 how many new ecmfiles to process: 448
 Folder to create: 72204  file got from: C:\root/www/tripinspect/inecm
2021/10/29 - 17:34:36 Unzipdone - completed without error? true   num files:14
  ---  Did copy file to hist: 1632679773783_72204.zip
 File to delete: C:\root/www/tripinspect/inecm/1632679773783_72204.zip
2021/10/29 - 17:34:36 File [B]WAS [/B]Deleted!!!: C:\root/www/tripinspect/inecm/1632679773783_72204.zip

 

[Harris]

All is good now. Learned so much on this issue....
What started out as a total mystery turned out to be so satisfying fix (proper evaluation and recode) - 10 feet tall and bullet proof! (famous last words...)

[ Solved] Detect Corrupt .zip File

Using the Archive lib for zip files, AsyncUnZip attempts to unzip but when corrupt, it seems to keep a handle on it, so I cant delete it (programmatically). This stalls my process to unzip many files - since this corrupt one from the folder in which it is located still exists.... How can one...

www.b4x.com

The above link explains final result.


Thanks again - case closed....