1 /*
2 * Copyright (C) 2018-2022 Intel Corporation.
3 * SPDX-License-Identifier: BSD-3-Clause
4 */
5
6 #include <stdio.h>
7 #include <unistd.h>
8 #include <string.h>
9 #include <malloc.h>
10 #include <openssl/sha.h>
11 #include <signal.h>
12 #include <limits.h>
13 #include <stdlib.h>
14 #include "android_events.h"
15 #include "strutils.h"
16 #include "cmdutils.h"
17 #include "log_sys.h"
18 #include "fsutils.h"
19 #include "history.h"
20 #include "loop.h"
21 #include "vmrecord.h"
22
23 #define VM_WARNING_LINES 2000
24
25 #define ANDROID_DATA_PAR_NAME "data"
26 #define ANDROID_EVT_KEY_LEN 20
27
28 /* TODO: hardcoding the img path here means that only one Android Guest OS
29 * is supoorted at this moment. To support multiple Android Guest OS, this
30 * path should be moved to structure vm_t and configurable.
31 */
32 static const char *android_img = "/data/android/android.img";
33 static const char *android_histpath = "logs/history_event";
34 char *loop_dev;
35
36 /* Find the next event that needs to be synced.
37 * There is a history_event file in User VM side, it records User VM's events in
38 * real-time. Generally, the cursor point to the first unsynchronized line.
39 */
next_vm_event(const char * cursor,const char * data,size_t dlen,const struct vm_t * vm)40 static char *next_vm_event(const char *cursor, const char *data,
41 size_t dlen, const struct vm_t *vm)
42 {
43 char *line_to_sync = (char *)~(0);
44 const char *syncevent;
45 int id;
46
47 if (!cursor || !vm)
48 return NULL;
49
50 /* find all syncing types start from cursor,
51 * focus the event with smaller address.
52 */
53 for_each_syncevent_vm(id, syncevent, vm) {
54 char *p;
55 char *new;
56 char *type;
57 int tlen;
58 size_t len;
59
60 if (!syncevent)
61 continue;
62
63 tlen = asprintf(&type, "\n%s ", syncevent);
64 if (tlen == -1) {
65 LOGE("out of memory\n");
66 return NULL;
67 }
68 /* a sync event may be configured as type/subtype */
69 p = strchr(type, '/');
70 if (p) {
71 char *subtype;
72 int stlen;
73
74 tlen = p - type;
75 stlen = asprintf(&subtype, " %s", p + 1);
76 if (stlen == -1) {
77 free(type);
78 LOGE("out of memory\n");
79 return NULL;
80 }
81 new = get_line(subtype, (size_t)stlen, data, dlen,
82 cursor, &len);
83 free(subtype);
84 /*
85 * ignore the result if 'line' does not start with
86 * 'type'.
87 */
88 if (!new || memcmp(new, type + 1, tlen - 1) ||
89 *(new + tlen - 1) != ' ') {
90 free(type);
91 continue;
92 }
93 } else {
94 new = get_line(type, (size_t)tlen, data, dlen,
95 cursor, &len);
96 }
97
98 if (new)
99 line_to_sync = MIN(line_to_sync, new);
100
101 free(type);
102 }
103
104 if (line_to_sync == (char *)~(0))
105 return NULL;
106
107 return line_to_sync;
108 }
109
get_vms_history(const struct sender_t * sender)110 static int get_vms_history(const struct sender_t *sender)
111 {
112 struct vm_t *vm;
113 unsigned long size;
114 int ret;
115 int id;
116
117 for_each_vm(id, vm, conf) {
118 if (!vm)
119 continue;
120
121 if (e2fs_open(loop_dev, &vm->datafs) == -1)
122 continue;
123
124 if (e2fs_read_file_by_fpath(vm->datafs, android_histpath,
125 (void **)&vm->history_data,
126 &size) == -1) {
127 LOGE("failed to get vm_history from (%s).\n", vm->name);
128 vm->history_data = NULL;
129 e2fs_close(vm->datafs);
130 vm->datafs = NULL;
131 continue;
132 }
133
134 e2fs_close(vm->datafs);
135 vm->datafs = NULL;
136
137 if (!size) {
138 LOGE("empty vm_history from (%s).\n", vm->name);
139 vm->history_data = NULL;
140 continue;
141 }
142
143 /* warning large history file once */
144 if (size == vm->history_size[sender->id])
145 continue;
146
147 ret = strcnt(vm->history_data, '\n');
148 if (ret > VM_WARNING_LINES)
149 LOGW("File too large, (%d) lines in (%s) of (%s)\n",
150 ret, android_histpath, vm->name);
151
152 vm->history_size[sender->id] = size;
153 }
154
155 return 0;
156 }
157
158 /**
159 * There are 2 stages in vm events sync.
160 * Stage1: detect new vm events and record them into log_vmrecordid file.
161 * Stage2: push the recorded events to event_queue, the senders will do
162 * the corresponding process.
163 *
164 * The design reason is giving User VM some time to get log stored.
165 */
detect_new_events(struct sender_t * sender)166 static void detect_new_events(struct sender_t *sender)
167 {
168 int id;
169 struct vm_t *vm;
170
171 for_each_vm(id, vm, conf) {
172 char *data;
173 size_t data_size;
174 char *start;
175 char *last_key;
176 char *line_to_sync;
177
178 if (!vm || !vm->history_data)
179 continue;
180
181 data = vm->history_data;
182 data_size = vm->history_size[sender->id];
183 last_key = &vm->last_evt_detected[sender->id][0];
184 if (*last_key) {
185 start = strstr(data, last_key);
186 if (start == NULL) {
187 LOGW("no synced id (%s), sync from head\n",
188 last_key);
189 start = data;
190 } else {
191 start = strchr(start, '\n');
192 }
193 } else {
194 start = data;
195 }
196
197 while ((line_to_sync = next_vm_event(start, data, data_size,
198 vm))) {
199 /* It's possible that log's content isn't ready
200 * at this moment, so we postpone the fn until
201 * the next loop
202 */
203 //fn(line_to_sync, vm);
204 char vmkey[ANDROID_WORD_LEN];
205 ssize_t len;
206 const char * const vm_format =
207 IGN_ONEWORD ANDROID_KEY_FMT IGN_RESTS;
208
209 len = strlinelen(line_to_sync,
210 data + data_size - line_to_sync);
211 if (len == -1)
212 break;
213
214 start = strchr(line_to_sync, '\n');
215 if (str_split_ere(line_to_sync, len + 1, vm_format,
216 strlen(vm_format), vmkey,
217 sizeof(vmkey)) != 1) {
218 LOGE("get an invalid line from (%s), skip\n",
219 vm->name);
220 continue;
221 }
222
223 if ((strnlen(vmkey, sizeof(vmkey)) !=
224 ANDROID_EVT_KEY_LEN) ||
225 !strcmp(vmkey, "00000000000000000000")) {
226 LOGE("invalid key (%s) from (%s)\n",
227 vmkey, vm->name);
228 continue;
229 }
230
231 LOGD("stage1 %s\n", vmkey);
232 *(char *)(mempcpy(vm->last_evt_detected[sender->id],
233 vmkey, ANDROID_EVT_KEY_LEN)) = '\0';
234 if (vmrecord_new(&sender->vmrecord, vm->name,
235 vmkey) == -1)
236 LOGE("failed to new vm record\n");
237 }
238 }
239
240 }
241
next_record(const struct mm_file_t * file,const char * fstart,size_t * len)242 static char *next_record(const struct mm_file_t *file, const char *fstart,
243 size_t *len)
244 {
245 const char *tag = " " VMRECORD_TAG_WAITING_SYNC;
246 size_t tlen = strlen(tag);
247
248 return get_line(tag, tlen, file->begin, file->size, fstart, len);
249 }
250
fire_detected_events(struct sender_t * sender,int (* fn)(const char *,size_t,const struct vm_t *))251 static void fire_detected_events(struct sender_t *sender,
252 int (*fn)(const char*, size_t, const struct vm_t *))
253 {
254 struct mm_file_t *recos;
255 char *record;
256 size_t recolen;
257
258 pthread_mutex_lock(&sender->vmrecord.mtx);
259 recos = mmap_file(sender->vmrecord.path);
260 if (!recos) {
261 LOGE("failed to mmap %s, %s\n", sender->vmrecord.path,
262 strerror(errno));
263 pthread_mutex_unlock(&sender->vmrecord.mtx);
264 return;
265 }
266 if (!recos->size ||
267 mm_count_lines(recos) < VMRECORD_HEAD_LINES) {
268 LOGE("(%s) invalid\n", sender->vmrecord.path);
269 goto out;
270 }
271
272 sender->vmrecord.recos = recos;
273 for (record = next_record(recos, recos->begin, &recolen); record;
274 record = next_record(recos, record + recolen, &recolen)) {
275 const char * const record_fmt =
276 VM_NAME_FMT ANDROID_KEY_FMT IGN_RESTS;
277 char *hist_line;
278 size_t len;
279 char vm_name[32];
280 char vmkey[ANDROID_WORD_LEN];
281 struct vm_t *vm;
282 int res;
283
284 /* VMNAME xxxxxxxxxxxxxxxxxxxx <== */
285 if (str_split_ere(record, recolen,
286 record_fmt, strlen(record_fmt),
287 vm_name, sizeof(vm_name),
288 vmkey, sizeof(vmkey)) != 2) {
289 LOGE("failed to parse vm record\n");
290 continue;
291 }
292
293 vm = get_vm_by_name((const char *)vm_name);
294 if (!vm || !vm->history_data)
295 continue;
296
297 hist_line = get_line(vmkey, strnlen(vmkey, sizeof(vmkey)),
298 vm->history_data,
299 vm->history_size[sender->id],
300 vm->history_data, &len);
301 if (!hist_line) {
302 vmrecord_mark(&sender->vmrecord, vmkey,
303 strnlen(vmkey, sizeof(vmkey)), NOT_FOUND);
304 continue;
305 }
306
307 res = fn(hist_line, len + 1, vm);
308 if (res == VMEVT_HANDLED)
309 vmrecord_mark(&sender->vmrecord, vmkey,
310 strnlen(vmkey, sizeof(vmkey)), ON_GOING);
311 }
312
313 out:
314 unmap_file(recos);
315 pthread_mutex_unlock(&sender->vmrecord.mtx);
316 }
317
318 /* This function only for initialization */
get_last_evt_detected(struct sender_t * sender)319 static void get_last_evt_detected(struct sender_t *sender)
320 {
321 int id;
322 struct vm_t *vm;
323
324 for_each_vm(id, vm, conf) {
325 char vmkey[ANDROID_WORD_LEN];
326
327 if (!vm)
328 continue;
329
330 /* generally only exec for each vm once */
331 if (vm->last_evt_detected[sender->id][0])
332 continue;
333
334 if (vmrecord_last(&sender->vmrecord, vm->name, vm->name_len,
335 vmkey, sizeof(vmkey)) == -1)
336 continue;
337
338 if (strnlen(vmkey, sizeof(vmkey)) != ANDROID_EVT_KEY_LEN) {
339 LOGE("get an invalid vm event (%s) in (%s)\n",
340 vmkey, sender->vmrecord.path);
341 continue;
342 }
343
344 *(char *)(mempcpy(vm->last_evt_detected[sender->id], vmkey,
345 ANDROID_EVT_KEY_LEN)) = '\0';
346
347 }
348 }
349
setup_loop_dev(void)350 static char *setup_loop_dev(void)
351 {
352
353 /* Currently User VM image(/data/android/android.img) mounted by
354 * launch_UOS.sh, we need mount its data partition to loop device
355 */
356 char loop_dev_tmp[32];
357 int i;
358 int res;
359 int devnr;
360
361 if (!file_exists(android_img)) {
362 LOGW("img(%s) is not available\n", android_img);
363 return NULL;
364 }
365
366 devnr = loopdev_num_get_free();
367 if (devnr < 0) {
368 LOGE("failed to get free loop device\n");
369 return NULL;
370 }
371
372 for (i = 0; i < devnr; i++) {
373 res = snprintf(loop_dev_tmp, ARRAY_SIZE(loop_dev_tmp),
374 "/dev/loop%d", i);
375 if (s_not_expect(res, ARRAY_SIZE(loop_dev_tmp)))
376 return NULL;
377
378 if (loopdev_check_parname(loop_dev_tmp,
379 ANDROID_DATA_PAR_NAME)) {
380 loop_dev = strdup(loop_dev_tmp);
381 if (!loop_dev) {
382 LOGE("out of memory\n");
383 return NULL;
384 }
385 return loop_dev;
386 }
387 }
388
389 res = asprintf(&loop_dev, "/dev/loop%d", devnr);
390 if (res == -1) {
391 LOGE("out of memory\n");
392 return NULL;
393 }
394
395 res = loopdev_set_img_par(loop_dev, android_img, ANDROID_DATA_PAR_NAME);
396 if (res == -1) {
397 LOGE("failed to setup loopdev.\n");
398 free(loop_dev);
399 loop_dev = NULL;
400 return NULL;
401 }
402
403 return loop_dev;
404 }
405
406 /* This function searches all android vms' new events and call the fn for
407 * each event.
408 *
409 * Note that: fn should return VMEVT_HANDLED to indicate event has been handled.
410 * fn will be called in a time loop if it returns VMEVT_DEFER.
411 */
refresh_vm_history(struct sender_t * sender,int (* fn)(const char *,size_t,const struct vm_t *))412 void refresh_vm_history(struct sender_t *sender,
413 int (*fn)(const char*, size_t, const struct vm_t *))
414 {
415 struct vm_t *vm;
416 int id;
417
418 if (!sender)
419 return;
420
421 if (!loop_dev) {
422 loop_dev = setup_loop_dev();
423 if (!loop_dev)
424 return;
425 LOGI("setup loop dev successful\n");
426 }
427
428 if (vmrecord_gen_ifnot_exists(&sender->vmrecord) == -1) {
429 LOGE("failed to create vmrecord\n");
430 return;
431 }
432
433 get_last_evt_detected(sender);
434 get_vms_history(sender);
435
436 /* read events from vmrecords and mark them as ongoing */
437 fire_detected_events(sender, fn);
438
439 /* add events to vmrecords */
440 detect_new_events(sender);
441
442 for_each_vm(id, vm, conf) {
443 if (!vm)
444 continue;
445 if (vm->history_data) {
446 free(vm->history_data);
447 vm->history_data = NULL;
448 }
449 }
450 }
451
android_event_analyze(const char * msg,size_t len,char ** result,size_t * rsize)452 int android_event_analyze(const char *msg, size_t len, char **result,
453 size_t *rsize)
454 {
455 char *data;
456 char *tail;
457 size_t data_len;
458 char event[ANDROID_WORD_LEN];
459 char longtime[ANDROID_WORD_LEN];
460 char type[ANDROID_WORD_LEN];
461 char rest[PATH_MAX];
462 char vmkey[ANDROID_WORD_LEN];
463 const char * const format =
464 ANDROID_ENEVT_FMT ANDROID_KEY_FMT ANDROID_LONGTIME_FMT
465 ANDROID_TYPE_FMT ANDROID_LINE_REST_FMT;
466
467 if (str_split_ere(msg, len, format, strlen(format), event,
468 sizeof(event), vmkey, sizeof(vmkey), longtime,
469 sizeof(longtime), type, sizeof(type), rest,
470 sizeof(rest)) != 5) {
471 LOGE("try to analyze an invalid line (%s), skip\n", msg);
472 return -1;
473 }
474
475 data_len = strnlen(vmkey, sizeof(vmkey)) + 1;
476 data_len += strnlen(event, sizeof(event)) + 1;
477 data_len += strnlen(type, sizeof(type)) + 1;
478 data_len += strnlen(rest, sizeof(rest)) + 1;
479
480 data = malloc(data_len);
481 if (!data)
482 return -1;
483 tail = (char *)mempcpy(data, vmkey, strnlen(vmkey, sizeof(vmkey)));
484 *(tail++) = '\0';
485 tail = (char *)mempcpy(tail, event, strnlen(event, sizeof(event)));
486 *(tail++) = '\0';
487 tail = (char *)mempcpy(tail, type, strnlen(type, sizeof(type)));
488 *(tail++) = '\0';
489 *(char *)mempcpy(tail, rest, strnlen(rest, sizeof(rest))) = '\0';
490
491 *result = data;
492 *rsize = data_len;
493 return 0;
494 }
495