lmkd: Add meminfo logging after each kill for easy troubleshooting

While troubleshooting memory pressure related issues it's hard to get a
good view of the memory state when lmkd kill happens. Logging relevant
information from /proc/meminfo file that was used to make a kill decision
is very helpful for further analysis. To do this efficiently we are using
Android Logger event library functions and log the data used for kill
decision after the kill signal was issued.

Test: Run lmkd_unit_test and logcat -b events -v descriptive
Change-Id: Id5de41b9d91a04dd5d3eb9b85d4e1babe9755628
Signed-off-by: Suren Baghdasaryan <surenb@google.com>

lmkd/Android.bp

@@ -20,6 +20,7 @@ cc_binary {
             ],
         },
     },
+    logtags: ["event.logtags"],
 }
 
 cc_library_static {

lmkd/event.logtags

@@ -0,0 +1,38 @@
+# The entries in this file map a sparse set of log tag numbers to tag names.
+# This is installed on the device, in /system/etc, and parsed by logcat.
+#
+# Tag numbers are decimal integers, from 0 to 2^31.  (Let's leave the
+# negative values alone for now.)
+#
+# Tag names are one or more ASCII letters and numbers or underscores, i.e.
+# "[A-Z][a-z][0-9]_".  Do not include spaces or punctuation (the former
+# impacts log readability, the latter makes regex searches more annoying).
+#
+# Tag numbers and names are separated by whitespace.  Blank lines and lines
+# starting with '#' are ignored.
+#
+# Optionally, after the tag names can be put a description for the value(s)
+# of the tag. Description are in the format
+#    (<name>|data type[|data unit])
+# Multiple values are separated by commas.
+#
+# The data type is a number from the following values:
+# 1: int
+# 2: long
+# 3: string
+# 4: list
+#
+# The data unit is a number taken from the following list:
+# 1: Number of objects
+# 2: Number of bytes
+# 3: Number of milliseconds
+# 4: Number of allocations
+# 5: Id
+# 6: Percent
+# s: Number of seconds (monotonic time)
+# Default value for data of type int/long is 2 (bytes).
+#
+# TODO: generate ".java" and ".h" files with integer constants from this file.
+
+# for meminfo logs
+10195355 meminfo (MemFree|1),(Cached|1),(SwapCached|1),(Buffers|1),(Shmem|1),(Unevictable|1),(SwapFree|1),(ActiveAnon|1),(InactiveAnon|1),(ActiveFile|1),(InactiveFile|1),(SReclaimable|1),(SUnreclaim|1),(KernelStack|1),(PageTables|1),(ION_heap|1),(ION_heap_pool|1),(CmaFree|1)

lmkd/lmkd.c

@@ -37,6 +37,7 @@
 #include <cutils/sockets.h>
 #include <lmkd.h>
 #include <log/log.h>
+#include <log/log_event_list.h>
 
 #ifdef LMKD_LOG_STATS
 #include "statslog.h"
@@ -72,6 +73,9 @@
 #define MEMINFO_PATH "/proc/meminfo"
 #define LINE_MAX 128
 
+/* Android Logger event logtags (see event.logtags) */
+#define MEMINFO_LOG_TAG 10195355
+
 /* gid containing AID_SYSTEM required */
 #define INKERNEL_MINFREE_PATH "/sys/module/lowmemorykiller/parameters/minfree"
 #define INKERNEL_ADJ_PATH "/sys/module/lowmemorykiller/parameters/adj"
@@ -85,6 +89,8 @@
 #define STRINGIFY(x) STRINGIFY_INTERNAL(x)
 #define STRINGIFY_INTERNAL(x) #x
 
+#define min(a, b) (((a) < (b)) ? (a) : (b))
+
 /* default to old in-kernel interface if no memory pressure events */
 static bool use_inkernel_interface = true;
 static bool has_inkernel_module;
@@ -120,6 +126,8 @@ static unsigned long kill_timeout_ms;
 static bool use_minfree_levels;
 static bool per_app_memcg;
 
+static android_log_context ctx;
+
 /* data required to handle events */
 struct event_handler_info {
     int data;
@@ -198,7 +206,17 @@ enum meminfo_field {
     MI_SHMEM,
     MI_UNEVICTABLE,
     MI_FREE_SWAP,
-    MI_DIRTY,
+    MI_ACTIVE_ANON,
+    MI_INACTIVE_ANON,
+    MI_ACTIVE_FILE,
+    MI_INACTIVE_FILE,
+    MI_SRECLAIMABLE,
+    MI_SUNRECLAIM,
+    MI_KERNEL_STACK,
+    MI_PAGE_TABLES,
+    MI_ION_HELP,
+    MI_ION_HELP_POOL,
+    MI_CMA_FREE,
     MI_FIELD_COUNT
 };
 
@@ -210,7 +228,17 @@ static const char* const meminfo_field_names[MI_FIELD_COUNT] = {
     "Shmem:",
     "Unevictable:",
     "SwapFree:",
-    "Dirty:",
+    "Active(anon):",
+    "Inactive(anon):",
+    "Active(file):",
+    "Inactive(file):",
+    "SReclaimable:",
+    "SUnreclaim:",
+    "KernelStack:",
+    "PageTables:",
+    "ION_heap:",
+    "ION_heap_pool:",
+    "CmaFree:",
 };
 
 union meminfo {
@@ -222,7 +250,17 @@ union meminfo {
         int64_t shmem;
         int64_t unevictable;
         int64_t free_swap;
-        int64_t dirty;
+        int64_t active_anon;
+        int64_t inactive_anon;
+        int64_t active_file;
+        int64_t inactive_file;
+        int64_t sreclaimable;
+        int64_t sunreclaimable;
+        int64_t kernel_stack;
+        int64_t page_tables;
+        int64_t ion_heap;
+        int64_t ion_heap_pool;
+        int64_t cma_free;
         /* fields below are calculated rather than read from the file */
         int64_t nr_file_pages;
     } field;
@@ -922,6 +960,15 @@ static int meminfo_parse(union meminfo *mi) {
     return 0;
 }
 
+static void meminfo_log(union meminfo *mi) {
+    for (int field_idx = 0; field_idx < MI_FIELD_COUNT; field_idx++) {
+        android_log_write_int32(ctx, (int32_t)min(mi->arr[field_idx] * page_k, INT32_MAX));
+    }
+
+    android_log_write_list(ctx, LOG_ID_EVENTS);
+    android_log_reset(ctx);
+}
+
 static int proc_get_size(int pid) {
     char path[PATH_MAX];
     char line[LINE_MAX];
@@ -1329,6 +1376,8 @@ do_kill:
             if (debug_process_killing) {
                 ALOGI("Nothing to kill");
             }
+        } else {
+            meminfo_log(&mi);
         }
     } else {
         int pages_freed;
@@ -1377,6 +1426,9 @@ do_kill:
                   pages_to_free, pages_freed);
             gettimeofday(&last_report_tm, NULL);
         }
+        if (pages_freed > 0) {
+            meminfo_log(&mi);
+        }
     }
 }
 
@@ -1591,6 +1643,8 @@ int main(int argc __unused, char **argv __unused) {
     per_app_memcg =
         property_get_bool("ro.config.per_app_memcg", low_ram_device);
 
+    ctx = create_android_logger(MEMINFO_LOG_TAG);
+
 #ifdef LMKD_LOG_STATS
     statslog_init(&log_ctx, &enable_stats_log);
 #endif
@@ -1626,6 +1680,8 @@ int main(int argc __unused, char **argv __unused) {
     statslog_destroy(&log_ctx);
 #endif
 
+    android_log_destroy(&ctx);
+
     ALOGI("exiting");
     return 0;
 }