Reduce overhead of multiplayer logging

The current logging operations use `writeText` and `appendText` helpers, which create a `FileOutputStream` underneath for every log.

This replaces the helpers with a `BufferedWriter` and continuous background flushing.

Author: Rian8337

src/com/osudroid/multiplayer/Multiplayer.kt

@@ -1,7 +1,6 @@
 package com.osudroid.multiplayer
 
 import android.net.*
-import android.text.format.DateFormat
 import android.util.Log
 import com.osudroid.multiplayer.api.RoomAPI
 import com.osudroid.multiplayer.api.data.Room
@@ -14,14 +13,12 @@ import kotlinx.coroutines.CoroutineScope
 import kotlinx.coroutines.Dispatchers
 import kotlinx.coroutines.launch
 import org.json.JSONArray
-import ru.nsu.ccfit.zuev.osu.Config
 import ru.nsu.ccfit.zuev.osu.GlobalManager
 import ru.nsu.ccfit.zuev.osu.MainActivity
 import ru.nsu.ccfit.zuev.osu.ToastLogger
 import ru.nsu.ccfit.zuev.osu.menu.*
 import ru.nsu.ccfit.zuev.osu.online.OnlineManager
 import ru.nsu.ccfit.zuev.osu.scoring.StatisticV2
-import java.io.File
 
 object Multiplayer {
 
@@ -79,15 +76,7 @@ object Multiplayer {
     val isConnected
         get() = room != null
 
-
-    private val LOG_FILE = File("${Config.getDefaultCorePath()}/Log", "multi_log.txt").apply {
-
-        parentFile?.mkdirs()
-
-        if (!exists()) {
-            createNewFile()
-        }
-    }
+    private val logger = MultiplayerLogger()
 
     private val reconnectionScope by lazy { CoroutineScope(Dispatchers.Default) }
 
@@ -102,7 +91,7 @@ object Multiplayer {
 
 
     init {
-        LOG_FILE.writeText("[${"yyyy/MM/dd hh:mm:ss".fromDate()}] Client ${MainActivity.versionName} started.")
+        logger.log("[${"yyyy/MM/dd hh:mm:ss".fromDate()}] Client ${MainActivity.versionName} started.")
     }
 
 
@@ -295,19 +284,16 @@ object Multiplayer {
 
     @JvmStatic
     fun log(text: String) {
-        val timestamp = DateFormat.format("hh:mm:ss", System.currentTimeMillis())
-
-        LOG_FILE.appendText("\n[$timestamp] $text")
-        Log.i("Multiplayer", text)
+        logger.log(text)
     }
 
     @JvmStatic
     fun log(e: Throwable) {
-        val time = "hh:mm:ss".formatTimeMilliseconds(System.currentTimeMillis())
-        val stacktrace = Log.getStackTraceString(e)
-
-        LOG_FILE.appendText("\n[$time] EXCEPTION: ${e.javaClass.simpleName}\n$stacktrace")
+        logger.log(e)
+    }
 
-        Log.e("Multiplayer", "An exception has been thrown.", e)
+    @JvmStatic
+    fun flushLog() {
+        logger.flush()
     }
 }

src/com/osudroid/multiplayer/MultiplayerLogger.kt

@@ -0,0 +1,110 @@
+package com.osudroid.multiplayer
+
+import android.util.Log
+import com.reco1l.toolkt.kotlin.formatTimeMilliseconds
+import java.io.File
+import kotlinx.coroutines.CoroutineScope
+import kotlinx.coroutines.Dispatchers
+import kotlinx.coroutines.SupervisorJob
+import kotlinx.coroutines.launch
+import ru.nsu.ccfit.zuev.osu.Config
+
+/**
+ * Logger for multiplayer events.
+ */
+class MultiplayerLogger : AutoCloseable {
+    private val dispatcher = Dispatchers.IO.limitedParallelism(1)
+    private val scope = CoroutineScope(dispatcher + SupervisorJob())
+
+    @Volatile
+    private var isClosed = false
+
+    private val writer = File("${Config.getDefaultCorePath()}/Log", "multi_log.txt").apply {
+        parentFile?.mkdirs()
+
+        if (!exists()) {
+            createNewFile()
+        }
+    }.bufferedWriter()
+
+    /**
+     * Logs a message to the log file.
+     *
+     * @param text The message to log.
+     */
+    fun log(text: String) {
+        if (isClosed) {
+            return
+        }
+
+        val timestamp = "hh:mm:ss".formatTimeMilliseconds(System.currentTimeMillis())
+
+        Log.i("Multiplayer", text)
+        write("\n[$timestamp] $text")
+    }
+
+    /**
+     * Logs a [Throwable] to the log file.
+     *
+     * @param e The [Throwable] to log.
+     */
+    fun log(e: Throwable) {
+        if (isClosed) {
+            return
+        }
+
+        val time = "hh:mm:ss".formatTimeMilliseconds(System.currentTimeMillis())
+        val stacktrace = Log.getStackTraceString(e)
+
+        Log.e("Multiplayer", "An exception has been thrown.", e)
+        write("\n[$time] EXCEPTION: ${e.javaClass.simpleName}\n$stacktrace")
+    }
+
+    /**
+     * Flushes the underlying buffer.
+     */
+    fun flush() {
+        if (isClosed) {
+            return
+        }
+
+        scope.launch {
+            try {
+                writer.flush()
+            } catch (e: Exception) {
+                e.printStackTrace()
+            }
+        }
+    }
+
+    private fun write(str: String) {
+        if (isClosed) {
+            return
+        }
+
+        scope.launch {
+            try {
+                writer.write(str)
+            } catch (ex: Exception) {
+                ex.printStackTrace()
+            }
+        }
+    }
+
+    override fun close() {
+        if (isClosed) {
+            return
+        }
+
+        isClosed = true
+
+        scope.launch {
+            try {
+                writer.flush()
+                writer.close()
+            } catch (e: Exception) {
+                e.printStackTrace()
+            }
+        }
+    }
+}

src/ru/nsu/ccfit/zuev/osu/MainActivity.java

@@ -78,6 +78,7 @@
 import java.util.HashSet;
 import java.util.concurrent.Executors;
 import java.util.concurrent.ScheduledExecutorService;
+import java.util.concurrent.ScheduledFuture;
 import java.util.concurrent.TimeUnit;
 
 import ru.nsu.ccfit.zuev.audio.serviceAudio.SaveServiceObject;
@@ -103,6 +104,7 @@ public class MainActivity extends BaseGameActivity implements
     private boolean willReplay = false;
     private static boolean activityVisible = true;
     private static final ScheduledExecutorService scheduledExecutor = Executors.newSingleThreadScheduledExecutor();
+    private ScheduledFuture<?> logFlushFuture;
     private Display display;
     private DisplayManager.DisplayListener displayListener;
     private float currentRefreshRate = 60;
@@ -345,6 +347,8 @@ public void onLoadComplete() {
                     AccessibilityDetector.check(MainActivity.this);
                 }, 0, 100, TimeUnit.MILLISECONDS);
 
+                logFlushFuture = scheduledExecutor.scheduleAtFixedRate(Multiplayer::flushLog, 0, 5, TimeUnit.SECONDS);
+
                 if (roomInviteLink != null) {
                     Multiplayer.connectFromLink(roomInviteLink);
                 } else if (willReplay) {
@@ -625,6 +629,8 @@ public void onResume() {
         super.onResume();
         activityVisible = true;
 
+        logFlushFuture = scheduledExecutor.scheduleAtFixedRate(Multiplayer::flushLog, 0, 5, TimeUnit.SECONDS);
+
         if (mEngine == null) {
             return;
         }
@@ -641,6 +647,12 @@ public void onPause() {
         super.onPause();
         activityVisible = false;
 
+        if (logFlushFuture != null && !logFlushFuture.isCancelled()) {
+            logFlushFuture.cancel(false);
+        }
+
+        Multiplayer.flushLog();
+
         if (mEngine == null) {
             return;
         }
@@ -665,12 +677,21 @@ public void onPause() {
     @Override
     public void onStop() {
         super.onStop();
+
+        if (logFlushFuture != null && !logFlushFuture.isCancelled()) {
+            logFlushFuture.cancel(false);
+        }
+
+        Multiplayer.flushLog();
+
         activityVisible = false;
     }
 
     @Override
     protected void onDestroy() {
         super.onDestroy();
+
+        Multiplayer.flushLog();
         ((DisplayManager) getSystemService(DISPLAY_SERVICE)).unregisterDisplayListener(displayListener);
     }