B4A Class Log to txt file class

SteveTerrell

Active Member
Licensed User
This is a simple logger class i use to help with debugging. It has the advantage of the entries being time stamped to see when they happen as well as creating a permanent record in a txt file. When debugging the entries are also written to the log window.

The log file uses the day date as part of its file name so the files can be viewed for up to a month after their creation. Log files can become quite long but at the same time can be used to record what the app is doing and help with debugging difficult to find faults.

Suggested use;
declare and create in the starter service

B4X:
Sub Process_Globals
    'These global variables will be declared once when the application starts.
    'These variables can be accessed from all modules.
   
    Public pLogger As TrsLogClass
B4X:
Sub Service_Create
    'This is the program entry point.
    'This is a good place to load resources that are not specific to a single activity.
   
    pLogger.Initialize(File.DirDefaultExternal , "TheLogFile" )
    pLogger.LogInformation("Logger Test","V0.01 11FEB17")
Initialize parameters:
File.DirDefaultExternal and "TheLogFile" determine where the file will be stored and its name.
The file name created will be "TheLogFile20.txt" if it is the 20th of the month - etc.


The log file (and log window) looks like
B4X:
12:21:16:194::I:TrsLogClass:Log file is TheLogFile20.txt
12:21:16:194::I:Logger Test:V0.01 11FEB17
12:21:16:272::I:Main:Activity resume
12:21:19:506::I:Main:Activity pause - user closed

Examples of use (here in Main but can be just about anywhere because Starter.pLogger is global)
B4X:
Sub Activity_Pause (UserClosed As Boolean)
    If UserClosed Then
        Starter.pLogger.LogInformation("Main", "Activity pause - user closed")
    Else
        Starter.pLogger.LogInformation("Main", "Activity pause - user closed = false")
    End If
    Starter.pLogger.Flush
End Sub
The main logging methods (LogInformation, LogWarning...) differ only in the letter placed after the time stamp (I=information in the example, W=warning, F=fault, T=Test result). All methods take a source and message string.

log entries created by the logging methods are initially put in a list when the method is called. Every 250ms this list is written to the log txt file and the list cleared. This is done to prevent the logging methods slowing the user code with txt file activities.

The pLogger.Flush call causes the list to be immediately written to the txt file.

I welcome any enhancements, optimizations etc.
 

Attachments

Arf

Active Member
Licensed User
I've been using this logger, it works well, however I am getting a crash that I am not sure is related to the logger or not.
It might be due to something completely different.

I added some code in my Start Service to dump the end LogCat to a text file:
B4X:
Sub Application_Error (Error As Exception, StackTrace As String) As Boolean
    'wait for 500ms to allow the logs to be updated.
    Dim jo As JavaObject
    Dim l As Long = 500
    jo.InitializeStatic("java.lang.Thread").RunMethod("sleep", Array(l))
    logcat.LogCatStop
    logs.Append(StackTrace)
    File.WriteString(DDB.AppFolder, "CrashReport.txt", logs)
    pLog.LogFault("Starter Service", Error.Message & " " & StackTrace)
    pLog.LogFault("Application Error", logs)
    Return True
End Sub
That is nothing to do with the logger. However my colleague had a crash with our app (a few times), and this is what the above code dumped:
~e:clogger_logtimer_tick (java line: 249)
~e:java.io.FileNotFoundException: /storage/emulated/0/TrueConnect Mobile/TrueLog27.txt: open failed: EACCES (Permission denied)
~e: at libcore.io.IoBridge.open(IoBridge.java:409)
~e: at java.io.FileOutputStream.<init>(FileOutputStream.java:88)
~e: at anywheresoftware.b4a.objects.streams.File.OpenOutput(File.java:370)
~e: at com.realsolutions.trueconnectmobile.clogger._logtimer_tick(clogger.java:249)
~e: at java.lang.reflect.Method.invokeNative(Native Method)
~e: at java.lang.reflect.Method.invoke(Method.java:515)
~e: at anywheresoftware.b4a.BA.raiseEvent2(BA.java:186)
~e: at anywheresoftware.b4a.objects.Timer$TickTack.run(Timer.java:105)
~e: at android.os.Handler.handleCallback(Handler.java:733)
~e: at android.os.Handler.dispatchMessage(Handler.java:95)
~e: at android.os.Looper.loop(Looper.java:146)
~e: at android.app.ActivityThread.main(ActivityThread.java:5602)
~e: at java.lang.reflect.Method.invokeNative(Native Method)
~e: at java.lang.reflect.Method.invoke(Method.java:515)
~e: at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:1283)
~e: at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:1099)
~e: at dalvik.system.NativeStart.main(Native Method)
~e:Caused by: libcore.io.ErrnoException: open failed: EACCES (Permission denied)
~e: at libcore.io.Posix.open(Native Method)
~e: at libcore.io.BlockGuardOs.open(BlockGuardOs.java:110)
~e: at libcore.io.IoBridge.open(IoBridge.java:393)
~e: ... 16 more
java.io.FileNotFoundException: /storage/emulated/0/TrueConnect Mobile/TrueLog27.txt: open failed: EACCES (Permission denied)
at libcore.io.IoBridge.open(IoBridge.java:409)
at java.io.FileOutputStream.<init>(FileOutputStream.java:88)
at anywheresoftware.b4a.objects.streams.File.OpenOutput(File.java:370)
at com.realsolutions.trueconnectmobile.clogger._logtimer_tick(clogger.java:249)
at java.lang.reflect.Method.invokeNative(Native Method)
at java.lang.reflect.Method.invoke(Method.java:515)
at anywheresoftware.b4a.BA.raiseEvent2(BA.java:186)
at anywheresoftware.b4a.objects.Timer$TickTack.run(Timer.java:105)
at android.os.Handler.handleCallback(Handler.java:733)
at android.os.Handler.dispatchMessage(Handler.java:95)
at android.os.Looper.loop(Looper.java:146)
at android.app.ActivityThread.main(ActivityThread.java:5602)
at java.lang.reflect.Method.invokeNative(Native Method)
at java.lang.reflect.Method.invoke(Method.java:515)
at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:1283)
at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:1099)
at dalvik.system.NativeStart.main(Native Method)
Caused by: libcore.io.ErrnoException: open failed: EACCES (Permission denied)
at libcore.io.Posix.open(Native Method)
at libcore.io.BlockGuardOs.open(BlockGuardOs.java:110)
at libcore.io.IoBridge.open(IoBridge.java:393)
... 16 more
The crash is said to occur in logtimer_tick, which looks like this:
B4X:
Sub LogTimer_Tick()
    If faultReportingList.Size = 0 Then Return    ' nothing to do
    Dim TextWriter1 As TextWriter
    TextWriter1.Initialize(File.OpenOutput(fileRootIs, logFileToUse, True))
    Do While faultReportingList.Size > 0
        Dim entry  As logEntryStruct = faultReportingList.Get(0)
        faultReportingList.RemoveAt(0)
        Dim strToLog As String = DateTime.Time(entry.timeAndDate) &"::" & typeStrings(entry.logType)&":"&entry.source&":"&entry.message
        TextWriter1.WriteLine(strToLog)
        Log("*"&strToLog)
    Loop
    TextWriter1.Close
End Sub
Could it be that I have written too much to the logger, and it's not able to write it all within 250ms and is re-entering the timer Tick and unable to open the file as TextWriter is still writing to it?

Thanks
 

SteveTerrell

Active Member
Licensed User
Hi,
Sorry to hear of your problems. I is not something that I have ever seen - which of course does not help you.
I don't think the tick is re-entrant so while writing a lot will reduce the time for other processing it should not try and open the file again until after the first tick call closes it and exits.
Something you could try..
The LogTimer_Tick code should probably be in a Try ... Catch ... End Try block so at least a failure does not kill the app.

Try
TextWriter1.Initialise ... etc
.
TextWriter1.Close
Catch
Log("Catch in LogTimer_Tick")
End Try


Also in the logging method (such as LogFault) check the list size so if it reaches a limit put one more entry in such as "fill limit" then (as a temporary measure) throw away any more entries until the list is emptied by the tick.

If the crash only happens after the Application_Error sub is called i wonder if that is why TextWriter fails? You could try putting some of the TextWriter code from tick directly in the Error sub to see if that works.
 

SteveTerrell

Active Member
Licensed User
Just trying to clarify what is happening (in my mind).

When the EACCES occurs has there been some previous successful log entries written in that run of the app? As opposed to an earlier in the day run of the app.
If it is the first attempt to write that goes wrong it could point to a storage problem. There seems to be problems in this area relating to API 23+

If a number of writes succeed then one fails the problem must be elsewhere.

I see that the use of TextWriter is now depreciated.
You could experiment with using the File commands (as you have elsewhere) instead of TextWriter in the tick sub.
 

Arf

Active Member
Licensed User
Thanks Steve,
It seems a lot of writes work fine before this happens. I'll try change TextWriter to a different method .
Im sure it's probably something I am doing wrong, rather than your code.

I have just encountered some other oddd behaviour on another tablet, so hopefully investigating that today will throw up some clues.
 

SteveTerrell

Active Member
Licensed User
Good luck.

From a quick bit of research it looks like TextWriter is the best way here because we format the string before writing it to file so the File.WriteList does not help us.
Also remember Flush calls Tick but that can only be a problem if we called flush in the middle of tick (so it should not be).

It might also be worth considering calling flush after the two lines
pLog.LogFault("Starter Service", Error.Message & " " & StackTrace)
pLog.LogFault("Application Error", logs)

>> pLog.Flush

just in case the timer does not work properly after the application error
 
  • Like
Reactions: Arf
Top