Home | History | Annotate | Download | only in tests 
      1 /*
      2  * Copyright (C) 2018 The Android Open Source Project
      3  *
      4  * Licensed under the Apache License, Version 2.0 (the "License");
      5  * you may not use this file except in compliance with the License.
      6  * You may obtain a copy of the License at
      7  *
      8  *      http://www.apache.org/licenses/LICENSE-2.0
      9  *
     10  * Unless required by applicable law or agreed to in writing, software
     11  * distributed under the License is distributed on an "AS IS" BASIS,
     12  * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
     13  * See the License for the specific language governing permissions and
     14  * limitations under the License.
     15  */
     16 
     17 #include <sstream>
     18 #include <stdio.h>
     19 #include <string.h>
     20 #include <string>
     21 #include <sys/mman.h>
     22 #include <sys/types.h>
     23 #include <unistd.h>
     24 
     25 #include <android-base/file.h>
     26 #include <android-base/logging.h>
     27 #include <android-base/properties.h>
     28 #include <android-base/stringprintf.h>
     29 #include <android-base/strings.h>
     30 #include <gtest/gtest.h>
     31 #include <lmkd.h>
     32 #include <liblmkd_utils.h>
     33 #include <log/log_properties.h>
     34 #include <private/android_filesystem_config.h>
     35 
     36 using namespace android::base;
     37 
     38 #define INKERNEL_MINFREE_PATH "/sys/module/lowmemorykiller/parameters/minfree"
     39 #define LMKDTEST_RESPAWN_FLAG "LMKDTEST_RESPAWN"
     40 
     41 #define LMKD_LOGCAT_MARKER "lowmemorykiller"
     42 #define LMKD_KILL_MARKER_TEMPLATE LMKD_LOGCAT_MARKER ": Killing '%s'"
     43 #define OOM_MARKER "Out of memory"
     44 #define OOM_KILL_MARKER "Killed process"
     45 #define MIN_LOG_SIZE 100
     46 
     47 #define ONE_MB (1 << 20)
     48 
     49 /* Test constant parameters */
     50 #define OOM_ADJ_MAX 1000
     51 #define OOM_ADJ_MIN 0
     52 #define OOM_ADJ_STEP 100
     53 #define STEP_COUNT ((OOM_ADJ_MAX - OOM_ADJ_MIN) / OOM_ADJ_STEP + 1)
     54 
     55 #define ALLOC_STEP (ONE_MB)
     56 #define ALLOC_DELAY 1000
     57 
     58 /* Utility functions */
     59 std::string readCommand(const std::string& command) {
     60     FILE* fp = popen(command.c_str(), "r");
     61     std::string content;
     62     ReadFdToString(fileno(fp), &content);
     63     pclose(fp);
     64     return content;
     65 }
     66 
     67 std::string readLogcat(const std::string& marker) {
     68     std::string content = readCommand("logcat -d -b all");
     69     size_t pos = content.find(marker);
     70     if (pos == std::string::npos) return "";
     71     content.erase(0, pos);
     72     return content;
     73 }
     74 
     75 bool writeFile(const std::string& file, const std::string& string) {
     76     if (getuid() == static_cast<unsigned>(AID_ROOT)) {
     77         return WriteStringToFile(string, file);
     78     }
     79     return string == readCommand(
     80         "echo -n '" + string + "' | su root tee " + file + " 2>&1");
     81 }
     82 
     83 bool writeKmsg(const std::string& marker) {
     84     return writeFile("/dev/kmsg", marker);
     85 }
     86 
     87 std::string getTextAround(const std::string& text, size_t pos,
     88                           size_t lines_before, size_t lines_after) {
     89     size_t start_pos = pos;
     90 
     91     // find start position
     92     // move up lines_before number of lines
     93     while (lines_before > 0 &&
     94            (start_pos = text.rfind('\n', start_pos)) != std::string::npos) {
     95         lines_before--;
     96     }
     97     // move to the beginning of the line
     98     start_pos = text.rfind('\n', start_pos);
     99     start_pos = (start_pos == std::string::npos) ? 0 : start_pos + 1;
    100 
    101     // find end position
    102     // move down lines_after number of lines
    103     while (lines_after > 0 &&
    104            (pos = text.find('\n', pos)) != std::string::npos) {
    105         pos++;
    106         lines_after--;
    107     }
    108     return text.substr(start_pos, (pos == std::string::npos) ?
    109                        std::string::npos : pos - start_pos);
    110 }
    111 
    112 bool getExecPath(std::string &path) {
    113     char buf[PATH_MAX + 1];
    114     int ret = readlink("/proc/self/exe", buf, sizeof(buf) - 1);
    115     if (ret < 0) {
    116         return false;
    117     }
    118     buf[ret] = '\0';
    119     path = buf;
    120     return true;
    121 }
    122 
    123 /* Child synchronization primitives */
    124 #define STATE_INIT 0
    125 #define STATE_CHILD_READY 1
    126 #define STATE_PARENT_READY 2
    127 
    128 struct state_sync {
    129     pthread_mutex_t mutex;
    130     pthread_cond_t condition;
    131     int state;
    132 };
    133 
    134 struct state_sync * init_state_sync_obj() {
    135     struct state_sync *ssync;
    136 
    137     ssync = (struct state_sync*)mmap(NULL, sizeof(struct state_sync),
    138                 PROT_READ | PROT_WRITE, MAP_ANONYMOUS | MAP_SHARED, -1, 0);
    139     if (ssync == MAP_FAILED) {
    140         return NULL;
    141     }
    142 
    143     pthread_mutexattr_t mattr;
    144     pthread_mutexattr_init(&mattr);
    145     pthread_mutexattr_setpshared(&mattr, PTHREAD_PROCESS_SHARED);
    146     pthread_mutex_init(&ssync->mutex, &mattr);
    147 
    148     pthread_condattr_t cattr;
    149     pthread_condattr_init(&cattr);
    150     pthread_condattr_setpshared(&cattr, PTHREAD_PROCESS_SHARED);
    151     pthread_cond_init(&ssync->condition, &cattr);
    152 
    153     ssync->state = STATE_INIT;
    154     return ssync;
    155 }
    156 
    157 void destroy_state_sync_obj(struct state_sync *ssync) {
    158     pthread_cond_destroy(&ssync->condition);
    159     pthread_mutex_destroy(&ssync->mutex);
    160     munmap(ssync, sizeof(struct state_sync));
    161 }
    162 
    163 void signal_state(struct state_sync *ssync, int state) {
    164     pthread_mutex_lock(&ssync->mutex);
    165     ssync->state = state;
    166     pthread_cond_signal(&ssync->condition);
    167     pthread_mutex_unlock(&ssync->mutex);
    168 }
    169 
    170 void wait_for_state(struct state_sync *ssync, int state) {
    171     pthread_mutex_lock(&ssync->mutex);
    172     while (ssync->state != state) {
    173         pthread_cond_wait(&ssync->condition, &ssync->mutex);
    174     }
    175     pthread_mutex_unlock(&ssync->mutex);
    176 }
    177 
    178 /* Memory allocation and data sharing */
    179 struct shared_data {
    180     size_t allocated;
    181     bool finished;
    182     size_t total_size;
    183     size_t step_size;
    184     size_t step_delay;
    185     int oomadj;
    186 };
    187 
    188 volatile void *gptr;
    189 void add_pressure(struct shared_data *data) {
    190     volatile void *ptr;
    191     size_t allocated_size = 0;
    192 
    193     data->finished = false;
    194     while (allocated_size < data->total_size) {
    195         ptr = mmap(NULL, data->step_size, PROT_READ | PROT_WRITE,
    196                 MAP_ANONYMOUS | MAP_PRIVATE, 0, 0);
    197         if (ptr != MAP_FAILED) {
    198             /* create ptr aliasing to prevent compiler optimizing the access */
    199             gptr = ptr;
    200             /* make data non-zero */
    201             memset((void*)ptr, (int)(allocated_size + 1), data->step_size);
    202             allocated_size += data->step_size;
    203             data->allocated = allocated_size;
    204         }
    205         usleep(data->step_delay);
    206     }
    207     data->finished = (allocated_size >= data->total_size);
    208 }
    209 
    210 /* Memory stress test main body */
    211 void runMemStressTest() {
    212     struct shared_data *data;
    213     struct state_sync *ssync;
    214     int sock;
    215     pid_t pid;
    216     uid_t uid = getuid();
    217 
    218     ASSERT_FALSE((sock = lmkd_connect()) < 0)
    219         << "Failed to connect to lmkd process, err=" << strerror(errno);
    220 
    221     /* allocate shared memory to communicate params with a child */
    222     data = (struct shared_data*)mmap(NULL, sizeof(struct shared_data),
    223                 PROT_READ | PROT_WRITE, MAP_ANONYMOUS | MAP_SHARED, -1, 0);
    224     ASSERT_FALSE(data == MAP_FAILED) << "Memory allocation failure";
    225     data->total_size = (size_t)-1; /* allocate until killed */
    226     data->step_size = ALLOC_STEP;
    227     data->step_delay = ALLOC_DELAY;
    228 
    229     /* allocate state sync object */
    230     ASSERT_FALSE((ssync = init_state_sync_obj()) == NULL)
    231         << "Memory allocation failure";
    232 
    233     /* run the test gradually decreasing oomadj */
    234     data->oomadj = OOM_ADJ_MAX;
    235     while (data->oomadj >= OOM_ADJ_MIN) {
    236         ASSERT_FALSE((pid = fork()) < 0)
    237             << "Failed to spawn a child process, err=" << strerror(errno);
    238         if (pid != 0) {
    239             /* Parent */
    240             struct lmk_procprio params;
    241             /* wait for child to start and get ready */
    242             wait_for_state(ssync, STATE_CHILD_READY);
    243             params.pid = pid;
    244             params.uid = uid;
    245             params.oomadj = data->oomadj;
    246             ASSERT_FALSE(lmkd_register_proc(sock, &params) < 0)
    247                 << "Failed to communicate with lmkd, err=" << strerror(errno);
    248             // signal the child it can proceed
    249             signal_state(ssync, STATE_PARENT_READY);
    250             waitpid(pid, NULL, 0);
    251             if (data->finished) {
    252                 GTEST_LOG_(INFO) << "Child [pid=" << pid << "] allocated "
    253                                  << data->allocated / ONE_MB << "MB";
    254             } else {
    255                 GTEST_LOG_(INFO) << "Child [pid=" << pid << "] allocated "
    256                                  << data->allocated / ONE_MB
    257                                  << "MB before being killed";
    258             }
    259             data->oomadj -= OOM_ADJ_STEP;
    260         } else {
    261             /* Child */
    262             pid = getpid();
    263             GTEST_LOG_(INFO) << "Child [pid=" << pid
    264                              << "] is running at oomadj="
    265                              << data->oomadj;
    266             data->allocated = 0;
    267             data->finished = false;
    268             ASSERT_FALSE(create_memcg(uid, pid) != 0)
    269                 << "Child [pid=" << pid << "] failed to create a cgroup";
    270             signal_state(ssync, STATE_CHILD_READY);
    271             wait_for_state(ssync, STATE_PARENT_READY);
    272             add_pressure(data);
    273             /* should not reach here, child should be killed by OOM/LMK */
    274             FAIL() << "Child [pid=" << pid << "] was not killed";
    275             break;
    276         }
    277     }
    278     destroy_state_sync_obj(ssync);
    279     munmap(data, sizeof(struct shared_data));
    280     close(sock);
    281 }
    282 
    283 TEST(lmkd, check_for_oom) {
    284     // test requirements
    285     //   userdebug build
    286     if (!__android_log_is_debuggable()) {
    287         GTEST_LOG_(INFO) << "Must be userdebug build, terminating test";
    288         return;
    289     }
    290     // check if in-kernel LMK driver is present
    291     if (!access(INKERNEL_MINFREE_PATH, W_OK)) {
    292         GTEST_LOG_(INFO) << "Must not have kernel lowmemorykiller driver,"
    293                          << " terminating test";
    294         return;
    295     }
    296 
    297     // if respawned test process then run the test and exit (no analysis)
    298     if (getenv(LMKDTEST_RESPAWN_FLAG) != NULL) {
    299         runMemStressTest();
    300         return;
    301     }
    302 
    303     // Main test process
    304     // mark the beginning of the test
    305     std::string marker = StringPrintf(
    306         "LMKD test start %lu\n", static_cast<unsigned long>(time(nullptr)));
    307     ASSERT_TRUE(writeKmsg(marker));
    308 
    309     // get executable complete path
    310     std::string test_path;
    311     ASSERT_TRUE(getExecPath(test_path));
    312 
    313     std::string test_output;
    314     if (getuid() != static_cast<unsigned>(AID_ROOT)) {
    315         // if not root respawn itself as root and capture output
    316         std::string command = StringPrintf(
    317             "%s=true su root %s 2>&1", LMKDTEST_RESPAWN_FLAG,
    318             test_path.c_str());
    319         std::string test_output = readCommand(command);
    320         GTEST_LOG_(INFO) << test_output;
    321     } else {
    322         // main test process is root, run the test
    323         runMemStressTest();
    324     }
    325 
    326     // Analyze results
    327     // capture logcat containind kernel logs
    328     std::string logcat_out = readLogcat(marker);
    329 
    330     // 1. extract LMKD kills from logcat output, count kills
    331     std::stringstream kill_logs;
    332     int hit_count = 0;
    333     size_t pos = 0;
    334     marker = StringPrintf(LMKD_KILL_MARKER_TEMPLATE, test_path.c_str());
    335 
    336     while (true) {
    337         if ((pos = logcat_out.find(marker, pos)) != std::string::npos) {
    338             kill_logs << getTextAround(logcat_out, pos, 0, 1);
    339             pos += marker.length();
    340             hit_count++;
    341         } else {
    342             break;
    343         }
    344     }
    345     GTEST_LOG_(INFO) << "====Logged kills====" << std::endl
    346                      << kill_logs.str();
    347     EXPECT_TRUE(hit_count == STEP_COUNT) << "Number of kills " << hit_count
    348                                          << " is less than expected "
    349                                          << STEP_COUNT;
    350 
    351     // 2. check kernel logs for OOM kills
    352     pos = logcat_out.find(OOM_MARKER);
    353     bool oom_detected = (pos != std::string::npos);
    354     bool oom_kill_detected = (oom_detected &&
    355         logcat_out.find(OOM_KILL_MARKER, pos) != std::string::npos);
    356 
    357     EXPECT_FALSE(oom_kill_detected) << "OOM kill is detected!";
    358     if (oom_detected || oom_kill_detected) {
    359         // capture logcat with logs around all OOMs
    360         pos = 0;
    361         while ((pos = logcat_out.find(OOM_MARKER, pos)) != std::string::npos) {
    362             GTEST_LOG_(INFO) << "====Logs around OOM====" << std::endl
    363                              << getTextAround(logcat_out, pos,
    364                                     MIN_LOG_SIZE / 2, MIN_LOG_SIZE / 2);
    365             pos += strlen(OOM_MARKER);
    366         }
    367     }
    368 
    369     // output complete logcat with kernel (might get truncated)
    370     GTEST_LOG_(INFO) << "====Complete logcat output====" << std::endl
    371                      << logcat_out;
    372 }
    373 
    374