lmkd: reroute atoms logging to AMS am: a92b76b54d

Original change: https://android-review.googlesource.com/c/platform/system/memory/lmkd/+/1702386

Change-Id: Ibfac12827098eac2ab2789c876a688da73d0cd87
This commit is contained in:
Vova Sharaienko 2021-05-11 17:42:46 +00:00 committed by Automerger Merge Worker
commit ea85216d08
5 changed files with 223 additions and 146 deletions

View File

@ -18,11 +18,9 @@ cc_binary {
"liblog", "liblog",
"libprocessgroup", "libprocessgroup",
"libpsi", "libpsi",
"libstatssocket",
], ],
static_libs: [ static_libs: [
"libstatslogc", "libstatslogc",
"libstatslog_lmkd",
"liblmkd_utils", "liblmkd_utils",
], ],
local_include_dirs: ["include"], local_include_dirs: ["include"],
@ -40,6 +38,7 @@ cc_binary {
cc_library_static { cc_library_static {
name: "libstatslogc", name: "libstatslogc",
srcs: ["statslog.cpp"], srcs: ["statslog.cpp"],
local_include_dirs: ["include"],
cflags: [ cflags: [
"-Wall", "-Wall",
"-Werror", "-Werror",
@ -49,37 +48,6 @@ cc_library_static {
shared_libs: [ shared_libs: [
"liblog", "liblog",
], ],
static_libs: [
"libstatslog_lmkd",
],
}
genrule {
name: "statslog_lmkd.h",
tools: ["stats-log-api-gen"],
cmd: "$(location stats-log-api-gen) --header $(genDir)/statslog_lmkd.h --module lmkd --namespace android,lmkd,stats",
out: [
"statslog_lmkd.h",
],
}
genrule {
name: "statslog_lmkd.cpp",
tools: ["stats-log-api-gen"],
cmd: "$(location stats-log-api-gen) --cpp $(genDir)/statslog_lmkd.cpp --module lmkd --namespace android,lmkd,stats --importHeader statslog_lmkd.h",
out: [
"statslog_lmkd.cpp",
],
}
cc_library_static {
name: "libstatslog_lmkd",
generated_sources: ["statslog_lmkd.cpp"],
generated_headers: ["statslog_lmkd.h"],
export_generated_headers: ["statslog_lmkd.h"],
shared_libs: [
"libstatssocket",
],
} }
cc_library_static { cc_library_static {

View File

@ -35,6 +35,8 @@ enum lmk_cmd {
LMK_SUBSCRIBE, /* Subscribe for asynchronous events */ LMK_SUBSCRIBE, /* Subscribe for asynchronous events */
LMK_PROCKILL, /* Unsolicited msg to subscribed clients on proc kills */ LMK_PROCKILL, /* Unsolicited msg to subscribed clients on proc kills */
LMK_UPDATE_PROPS, /* Reinit properties */ LMK_UPDATE_PROPS, /* Reinit properties */
LMK_STAT_KILL_OCCURRED, /* Unsolicited msg to subscribed clients on proc kills for statsd log */
LMK_STAT_STATE_CHANGED, /* Unsolicited msg to subscribed clients on state changed */
}; };
/* /*
@ -204,10 +206,11 @@ static inline size_t lmkd_pack_set_getkillcnt_repl(LMKD_CTRL_PACKET packet, int
return 2 * sizeof(int); return 2 * sizeof(int);
} }
/* Types of asyncronous events sent from lmkd to its clients */ /* Types of asynchronous events sent from lmkd to its clients */
enum async_event_type { enum async_event_type {
LMK_ASYNC_EVENT_FIRST, LMK_ASYNC_EVENT_FIRST,
LMK_ASYNC_EVENT_KILL = LMK_ASYNC_EVENT_FIRST, LMK_ASYNC_EVENT_KILL = LMK_ASYNC_EVENT_FIRST,
LMK_ASYNC_EVENT_STAT,
LMK_ASYNC_EVENT_COUNT, LMK_ASYNC_EVENT_COUNT,
}; };

View File

@ -22,7 +22,6 @@
#include <pwd.h> #include <pwd.h>
#include <sched.h> #include <sched.h>
#include <signal.h> #include <signal.h>
#include <statslog_lmkd.h>
#include <stdbool.h> #include <stdbool.h>
#include <stdlib.h> #include <stdlib.h>
#include <string.h> #include <string.h>
@ -758,6 +757,49 @@ static void ctrl_data_write_lmk_kill_occurred(pid_t pid, uid_t uid) {
} }
} }
/*
* Write the kill_stat/memory_stat over the data socket to be propagated via AMS to statsd
*/
static void stats_write_lmk_kill_occurred(struct kill_stat *kill_st,
struct memory_stat *mem_st) {
LMK_KILL_OCCURRED_PACKET packet;
const size_t len = lmkd_pack_set_kill_occurred(packet, kill_st, mem_st);
if (len == 0) {
return;
}
for (int i = 0; i < MAX_DATA_CONN; i++) {
if (data_sock[i].sock >= 0 && data_sock[i].async_event_mask & 1 << LMK_ASYNC_EVENT_STAT) {
ctrl_data_write(i, packet, len);
}
}
}
static void stats_write_lmk_kill_occurred_pid(int pid, struct kill_stat *kill_st,
struct memory_stat *mem_st) {
kill_st->taskname = stats_get_task_name(pid);
if (kill_st->taskname != NULL) {
stats_write_lmk_kill_occurred(kill_st, mem_st);
}
}
/*
* Write the state_changed over the data socket to be propagated via AMS to statsd
*/
static void stats_write_lmk_state_changed(enum lmk_state state) {
LMKD_CTRL_PACKET packet_state_changed;
const size_t len = lmkd_pack_set_state_changed(packet_state_changed, state);
if (len == 0) {
return;
}
for (int i = 0; i < MAX_DATA_CONN; i++) {
if (data_sock[i].sock >= 0 && data_sock[i].async_event_mask & 1 << LMK_ASYNC_EVENT_STAT) {
ctrl_data_write(i, (char*)packet_state_changed, len);
}
}
}
static void poll_kernel(int poll_fd) { static void poll_kernel(int poll_fd) {
if (poll_fd == -1) { if (poll_fd == -1) {
// not waiting // not waiting
@ -2183,8 +2225,7 @@ static int find_and_kill_process(int min_score_adj, enum kill_reasons kill_reaso
if (killed_size >= 0) { if (killed_size >= 0) {
if (!lmk_state_change_start) { if (!lmk_state_change_start) {
lmk_state_change_start = true; lmk_state_change_start = true;
stats_write_lmk_state_changed( stats_write_lmk_state_changed(STATE_START);
android::lmkd::stats::LMK_STATE_CHANGED__STATE__START);
} }
break; break;
} }
@ -2195,7 +2236,7 @@ static int find_and_kill_process(int min_score_adj, enum kill_reasons kill_reaso
} }
if (lmk_state_change_start) { if (lmk_state_change_start) {
stats_write_lmk_state_changed(android::lmkd::stats::LMK_STATE_CHANGED__STATE__STOP); stats_write_lmk_state_changed(STATE_STOP);
} }
return killed_size; return killed_size;

View File

@ -24,21 +24,27 @@
#include <string.h> #include <string.h>
#include <stdlib.h> #include <stdlib.h>
#include <string.h> #include <string.h>
#include <sys/endian.h>
#include <sys/param.h>
#include <sys/uio.h> #include <sys/uio.h>
#include <time.h> #include <time.h>
#include <unistd.h> #include <unistd.h>
#ifdef LMKD_LOG_STATS #ifdef LMKD_LOG_STATS
#define LINE_MAX 128
#define STRINGIFY(x) STRINGIFY_INTERNAL(x) #define STRINGIFY(x) STRINGIFY_INTERNAL(x)
#define STRINGIFY_INTERNAL(x) #x #define STRINGIFY_INTERNAL(x) #x
/**
* Used to make sure that the payload is always smaller than LMKD_REPLY_MAX_SIZE
*/
#define BUILD_BUG_ON(cond) ((void)sizeof(char[1 - 2 * !!(cond)]))
static bool enable_stats_log = property_get_bool("ro.lmk.log_stats", true); static bool enable_stats_log = property_get_bool("ro.lmk.log_stats", true);
struct proc { struct proc {
int pid; int pid;
char taskname[LINE_MAX]; char taskname[MAX_TASKNAME_LEN];
struct proc* pidhash_next; struct proc* pidhash_next;
}; };
@ -46,20 +52,6 @@ struct proc {
static struct proc** pidhash = NULL; static struct proc** pidhash = NULL;
#define pid_hashfn(x) ((((x) >> 8) ^ (x)) & (PIDHASH_SZ - 1)) #define pid_hashfn(x) ((((x) >> 8) ^ (x)) & (PIDHASH_SZ - 1))
/**
* Logs the change in LMKD state which is used as start/stop boundaries for logging
* LMK_KILL_OCCURRED event.
* Code: LMK_STATE_CHANGED = 54
*/
int
stats_write_lmk_state_changed(int32_t state) {
if (enable_stats_log) {
return android::lmkd::stats::stats_write(android::lmkd::stats::LMK_STATE_CHANGED, state);
} else {
return -EINVAL;
}
}
static struct proc* pid_lookup(int pid) { static struct proc* pid_lookup(int pid) {
struct proc* procp; struct proc* procp;
@ -71,68 +63,11 @@ static struct proc* pid_lookup(int pid) {
return procp; return procp;
} }
inline int32_t map_kill_reason(enum kill_reasons reason) {
switch (reason) {
case PRESSURE_AFTER_KILL:
return android::lmkd::stats::LMK_KILL_OCCURRED__REASON__PRESSURE_AFTER_KILL;
case NOT_RESPONDING:
return android::lmkd::stats::LMK_KILL_OCCURRED__REASON__NOT_RESPONDING;
case LOW_SWAP_AND_THRASHING:
return android::lmkd::stats::LMK_KILL_OCCURRED__REASON__LOW_SWAP_AND_THRASHING;
case LOW_MEM_AND_SWAP:
return android::lmkd::stats::LMK_KILL_OCCURRED__REASON__LOW_MEM_AND_SWAP;
case LOW_MEM_AND_THRASHING:
return android::lmkd::stats::LMK_KILL_OCCURRED__REASON__LOW_MEM_AND_THRASHING;
case DIRECT_RECL_AND_THRASHING:
return android::lmkd::stats::LMK_KILL_OCCURRED__REASON__DIRECT_RECL_AND_THRASHING;
case LOW_MEM_AND_SWAP_UTIL:
return android::lmkd::stats::LMK_KILL_OCCURRED__REASON__LOW_MEM_AND_SWAP_UTIL;
default:
return android::lmkd::stats::LMK_KILL_OCCURRED__REASON__UNKNOWN;
}
}
/**
* Logs the event when LMKD kills a process to reduce memory pressure.
* Code: LMK_KILL_OCCURRED = 51
*/
int stats_write_lmk_kill_occurred(struct kill_stat *kill_st, struct memory_stat *mem_st) {
if (enable_stats_log) {
return android::lmkd::stats::stats_write(
android::lmkd::stats::LMK_KILL_OCCURRED,
kill_st->uid,
kill_st->taskname,
kill_st->oom_score,
mem_st ? mem_st->pgfault : -1,
mem_st ? mem_st->pgmajfault : -1,
mem_st ? mem_st->rss_in_bytes : -1,
mem_st ? mem_st->cache_in_bytes : -1,
mem_st ? mem_st->swap_in_bytes : -1,
mem_st ? mem_st->process_start_time_ns : -1,
kill_st->min_oom_score,
kill_st->free_mem_kb,
kill_st->free_swap_kb,
map_kill_reason(kill_st->kill_reason)
);
} else {
return -EINVAL;
}
}
int stats_write_lmk_kill_occurred_pid(int pid, struct kill_stat *kill_st,
struct memory_stat* mem_st) {
struct proc* proc = pid_lookup(pid);
if (!proc) return -EINVAL;
kill_st->taskname = proc->taskname;
return stats_write_lmk_kill_occurred(kill_st, mem_st);
}
static void memory_stat_parse_line(char* line, struct memory_stat* mem_st) { static void memory_stat_parse_line(char* line, struct memory_stat* mem_st) {
char key[LINE_MAX + 1]; char key[MAX_TASKNAME_LEN + 1];
int64_t value; int64_t value;
sscanf(line, "%" STRINGIFY(LINE_MAX) "s %" SCNd64 "", key, &value); sscanf(line, "%" STRINGIFY(MAX_TASKNAME_LEN) "s %" SCNd64 "", key, &value);
if (strcmp(key, "total_") < 0) { if (strcmp(key, "total_") < 0) {
return; return;
@ -275,8 +210,8 @@ void stats_store_taskname(int pid, const char* taskname) {
} }
procp = static_cast<struct proc*>(malloc(sizeof(struct proc))); procp = static_cast<struct proc*>(malloc(sizeof(struct proc)));
procp->pid = pid; procp->pid = pid;
strncpy(procp->taskname, taskname, LINE_MAX - 1); strncpy(procp->taskname, taskname, MAX_TASKNAME_LEN - 1);
procp->taskname[LINE_MAX - 1] = '\0'; procp->taskname[MAX_TASKNAME_LEN - 1] = '\0';
proc_insert(procp); proc_insert(procp);
} }
@ -299,4 +234,110 @@ void stats_purge_tasknames() {
memset(pidhash, 0, PIDHASH_SZ * sizeof(*pidhash)); memset(pidhash, 0, PIDHASH_SZ * sizeof(*pidhash));
} }
const char* stats_get_task_name(int pid) {
struct proc* proc = pid_lookup(pid);
return proc ? proc->taskname : NULL;
}
/**
* Writes int32 in a machine independent way
* https://docs.oracle.com/javase/7/docs/api/java/io/DataOutput.html#writeInt(int)
*/
static inline size_t pack_int32(LMK_KILL_OCCURRED_PACKET packet,
size_t index,
int32_t value) {
int32_t* int_buffer = (int32_t*)(packet + index);
*int_buffer = htonl(value);
return index + sizeof(int32_t);
}
/**
* Writes int64 in a machine independent way
* https://docs.oracle.com/javase/7/docs/api/java/io/DataOutput.html#writeLong(long)
*/
static inline size_t pack_int64(LMK_KILL_OCCURRED_PACKET packet,
size_t index,
int64_t value) {
int64_t* int64_buffer = (int64_t*)(packet + index);
*int64_buffer = htonq(value);
return index + sizeof(int64_t);
}
/**
* Writes ANSI string in a machine independent way
* https://docs.oracle.com/javase/7/docs/api/java/io/DataOutput.html#writeShort(int)
* 2 bytes str len following n chars
* to be read on the Java side with
* https://docs.oracle.com/javase/7/docs/api/java/io/DataInput.html#readUTF()
* Truncates the value string & packs up to MAX_TASKNAME_LEN - 1 chars
*/
static inline size_t pack_string(LMK_KILL_OCCURRED_PACKET packet,
size_t index,
const char* value) {
const size_t len_proc_name = MIN(strlen(value), MAX_TASKNAME_LEN - 1);
int16_t* short_buffer = (int16_t*)(packet + index);
*short_buffer = htons((int16_t)len_proc_name);
char* byte_buffer = (char*)(short_buffer + 1);
strncpy(byte_buffer, value, MAX_TASKNAME_LEN - 1);
byte_buffer[MAX_TASKNAME_LEN - 1] = '\0';
return index + sizeof(int16_t) + len_proc_name + 1;
}
size_t lmkd_pack_set_kill_occurred(LMK_KILL_OCCURRED_PACKET packet,
struct kill_stat *kill_stat,
struct memory_stat *mem_stat) {
BUILD_BUG_ON(sizeof(LMK_KILL_OCCURRED_PACKET) > LMKD_REPLY_MAX_SIZE);
if (!enable_stats_log) {
return 0;
}
int32_t index = 0;
index = pack_int32(packet, index, LMK_STAT_KILL_OCCURRED);
if (mem_stat) {
index = pack_int64(packet, index, mem_stat->pgfault);
index = pack_int64(packet, index, mem_stat->pgmajfault);
index = pack_int64(packet, index, mem_stat->rss_in_bytes);
index = pack_int64(packet, index, mem_stat->cache_in_bytes);
index = pack_int64(packet, index, mem_stat->swap_in_bytes);
index = pack_int64(packet, index, mem_stat->process_start_time_ns);
} else {
index = pack_int64(packet, index, -1);
index = pack_int64(packet, index, -1);
index = pack_int64(packet, index, -1);
index = pack_int64(packet, index, -1);
index = pack_int64(packet, index, -1);
index = pack_int64(packet, index, -1);
}
index = pack_int32(packet, index, kill_stat->uid);
index = pack_int32(packet, index, kill_stat->oom_score);
index = pack_int32(packet, index, kill_stat->min_oom_score);
index = pack_int32(packet, index, (int)kill_stat->free_mem_kb);
index = pack_int32(packet, index, (int)kill_stat->free_swap_kb);
index = pack_int32(packet, index, (int)kill_stat->kill_reason);
index = pack_string(packet, index, kill_stat->taskname);
return index;
}
size_t lmkd_pack_set_state_changed(LMKD_CTRL_PACKET packet,
enum lmk_state state) {
if (!enable_stats_log) {
return 0;
}
packet[0] = htonl(LMK_STAT_STATE_CHANGED);
packet[1] = htonl(state);
return 2 * sizeof(int);
}
#endif /* LMKD_LOG_STATS */ #endif /* LMKD_LOG_STATS */

View File

@ -17,9 +17,10 @@
#ifndef _STATSLOG_H_ #ifndef _STATSLOG_H_
#define _STATSLOG_H_ #define _STATSLOG_H_
#include <lmkd.h>
#include <assert.h> #include <assert.h>
#include <inttypes.h> #include <inttypes.h>
#include <statslog_lmkd.h>
#include <stdbool.h> #include <stdbool.h>
#include <sys/cdefs.h> #include <sys/cdefs.h>
#include <sys/types.h> #include <sys/types.h>
@ -28,6 +29,21 @@
__BEGIN_DECLS __BEGIN_DECLS
#define MAX_TASKNAME_LEN 128
/*
* Max LMKD reply packet length in bytes
* Notes about size calculation:
* 4 bytes for packet type
* 80 bytes for the LmkKillOccurred fields: memory_stat + kill_stat
* 2 bytes for process name string size
* MAX_TASKNAME_LEN bytes for the process name string
*
* Must be in sync with LmkdConnection.java
*/
#define LMKD_REPLY_MAX_SIZE 214
/* LMK_MEMORY_STATS packet payload */
struct memory_stat { struct memory_stat {
int64_t pgfault; int64_t pgfault;
int64_t pgmajfault; int64_t pgmajfault;
@ -37,7 +53,7 @@ struct memory_stat {
int64_t process_start_time_ns; int64_t process_start_time_ns;
}; };
// If you update this, also update the corresponding stats enum mapping. // If you update this, also update the corresponding stats enum mapping and LmkdStatsReporter.java
enum kill_reasons { enum kill_reasons {
NONE = -1, /* To denote no kill condition */ NONE = -1, /* To denote no kill condition */
PRESSURE_AFTER_KILL = 0, PRESSURE_AFTER_KILL = 0,
@ -50,9 +66,10 @@ enum kill_reasons {
KILL_REASON_COUNT KILL_REASON_COUNT
}; };
/* LMK_KILL_STAT packet payload */
struct kill_stat { struct kill_stat {
int32_t uid; int32_t uid;
char *taskname; const char *taskname;
enum kill_reasons kill_reason; enum kill_reasons kill_reason;
int32_t oom_score; int32_t oom_score;
int32_t min_oom_score; int32_t min_oom_score;
@ -60,6 +77,16 @@ struct kill_stat {
int64_t free_swap_kb; int64_t free_swap_kb;
}; };
/* LMKD reply packet to hold data for the LmkKillOccurred statsd atom */
typedef char LMK_KILL_OCCURRED_PACKET[LMKD_REPLY_MAX_SIZE];
// If you update this, also update the corresponding stats enum mapping.
enum lmk_state {
STATE_UNKNOWN = 0,
STATE_START,
STATE_STOP,
};
#ifdef LMKD_LOG_STATS #ifdef LMKD_LOG_STATS
#define MEMCG_PROCESS_MEMORY_STAT_PATH "/dev/memcg/apps/uid_%u/pid_%d/memory.stat" #define MEMCG_PROCESS_MEMORY_STAT_PATH "/dev/memcg/apps/uid_%u/pid_%d/memory.stat"
@ -68,24 +95,19 @@ struct kill_stat {
#define BYTES_IN_KILOBYTE 1024 #define BYTES_IN_KILOBYTE 1024
/** /**
* Logs the change in LMKD state which is used as start/stop boundaries for logging * Produces packet with the change in LMKD state which is used as start/stop boundaries for logging
* LMK_KILL_OCCURRED event. * LMK_KILL_OCCURRED event.
* Code: LMK_STATE_CHANGED = 54 * Code: LMK_STATE_CHANGED = 54
*/ */
int size_t lmkd_pack_set_state_changed(LMKD_CTRL_PACKET packet,
stats_write_lmk_state_changed(int32_t state); enum lmk_state state);
/** /**
* Logs the event when LMKD kills a process to reduce memory pressure. * Produces packet with the event when LMKD kills a process to reduce memory pressure.
* Code: LMK_KILL_OCCURRED = 51 * Code: LMK_KILL_OCCURRED = 51
*/ */
int stats_write_lmk_kill_occurred(struct kill_stat *kill_st, struct memory_stat *mem_st); size_t lmkd_pack_set_kill_occurred(LMK_KILL_OCCURRED_PACKET packet,
struct kill_stat *kill_st,
/**
* Logs the event when LMKD kills a process to reduce memory pressure.
* Code: LMK_KILL_OCCURRED = 51
*/
int stats_write_lmk_kill_occurred_pid(int pid, struct kill_stat *kill_st,
struct memory_stat *mem_st); struct memory_stat *mem_st);
/** /**
@ -109,18 +131,18 @@ void stats_purge_tasknames();
*/ */
void stats_remove_taskname(int pid); void stats_remove_taskname(int pid);
const char* stats_get_task_name(int pid);
#else /* LMKD_LOG_STATS */ #else /* LMKD_LOG_STATS */
static inline int static inline size_t
stats_write_lmk_state_changed(int32_t state __unused) { return -EINVAL; } lmkd_pack_set_state_changed(LMKD_CTRL_PACKET packet __unused, enum lmk_state state __unused) {
static inline int
stats_write_lmk_kill_occurred(struct kill_stat *kill_st __unused,
struct memory_stat *mem_st __unused) {
return -EINVAL; return -EINVAL;
} }
int stats_write_lmk_kill_occurred_pid(int pid __unused, struct kill_stat *kill_st __unused, static inline size_t
lmkd_pack_set_kill_occurred(LMK_KILL_OCCURRED_PACKET packet __unused,
struct kill_stat *kill_st __unused,
struct memory_stat *mem_st __unused) { struct memory_stat *mem_st __unused) {
return -EINVAL; return -EINVAL;
} }
@ -137,6 +159,8 @@ static inline void stats_purge_tasknames() {}
static inline void stats_remove_taskname(int pid __unused) {} static inline void stats_remove_taskname(int pid __unused) {}
static inline const char* stats_get_task_name(int pid __unused) { return NULL; }
#endif /* LMKD_LOG_STATS */ #endif /* LMKD_LOG_STATS */
__END_DECLS __END_DECLS