server/src/muse_server_log.c

   1 /*
   2  * muse-server
   3  *
   4  * Copyright (c) 2017 Samsung Electronics Co., Ltd. All rights reserved.
   5  *
   6  * Contact: YoungHun Kim <yh8004.kim@samsung.com>
   7  *
   8  * Licensed under the Apache License, Version 2.0 (the "License");
   9  * you may not use this file except in compliance with the License.
  10  * You may obtain a copy of the License at
  11  *
  12  * http://www.apache.org/licenses/LICENSE-2.0
  13  *
  14  * Unless required by applicable law or agreed to in writing, software
  15  * distributed under the License is distributed on an "AS IS" BASIS,
  16  * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
  17  * See the License for the specific language governing permissions and
  18  * limitations under the License.
  19  *
  20  */
  21
  22 #include "muse_server_private.h"
  23
  24 #define U32BITS                         0xffffffff
  25 #define MAX_FILE_NUM            3
  26 #define MAX_SIZE                        33554432
  27 #define WRITE_FAIL                      -1
  28 #define BUILD_ID                        "BUILD_ID"
  29 #define delimiter                       "="
  30
  31 static gboolean _ms_log_pid_is_valid(pid_t pid);
  32 static void _ms_log_latest_msgs(ms_log_t *log);
  33 static void _ms_log_pid_time(ms_log_t* log, int pid);
  34 static void _ms_log_cmdline(ms_log_t* log, int pid);
  35 static void _ms_log_process_info(ms_log_t* log, int pid);
  36 static void _ms_log_api_info(ms_log_t *log);
  37 static void _ms_log_binary_info(ms_log_t *log);
  38 static int _ms_fd_set_block(int fd);
  39 static int _ms_log_open_work(const char *path);
  40 static void _ms_log_create_fd(ms_log_t *log);
  41 static void _ms_log_set_fd(ms_log_t *log);
  42 static void _ms_log_cache_latest_msg(ms_log_t *log, int pid, char *msg);
  43
  44 static gboolean _ms_log_pid_is_valid(pid_t pid)
  45 {
  46         char log_buf[MUSE_MSG_LEN_MAX];
  47
  48         muse_return_val_if_fail(ms_is_log_enabled(), FALSE);
  49
  50         snprintf(log_buf, sizeof(log_buf), "/proc/%d", (int)pid);
  51
  52         if (access(log_buf, F_OK) != 0) {
  53                 LOGD("%d process doesn't exist", (int)pid);
  54                 return FALSE;
  55         }
  56
  57         return TRUE;
  58 }
  59
  60 static void _ms_log_latest_msgs(ms_log_t *log)
  61 {
  62         int idx = 0;
  63
  64         muse_return_if_fail(ms_is_log_enabled());
  65         muse_return_if_fail(log);
  66
  67         g_mutex_lock(&log->lock);
  68
  69         if (muse_core_fd_is_valid(log->fd)) {
  70                 for (idx = log->cur_idx; idx < MUSE_LOG_MSG_NUM; idx++)
  71                         ms_log_write(log->latest_msgs[idx]);
  72
  73                 for (idx = 0; idx < log->cur_idx; idx++)
  74                         ms_log_write(log->latest_msgs[idx]);
  75         }
  76
  77         g_mutex_unlock(&log->lock);
  78 }
  79
  80 static void _ms_log_pid_time(ms_log_t *log, int pid)
  81 {
  82         char log_buf[MUSE_MSG_LEN_MAX];
  83         char time_buf[MUSE_MSG_TIME_LEN];
  84
  85         muse_return_if_fail(ms_is_log_enabled());
  86         muse_return_if_fail(log);
  87         muse_return_if_fail(muse_core_fd_is_valid(log->fd));
  88         muse_return_if_fail(_ms_log_pid_is_valid(pid));
  89
  90         muse_core_get_cur_time(NULL, time_buf);
  91         snprintf(log_buf, MUSE_MSG_LEN_MAX, "[PID] %d %s", pid, time_buf);
  92
  93         ms_log_write(log_buf);
  94 }
  95
  96 static void _ms_log_cmdline(ms_log_t *log, int pid)
  97 {
  98         char log_buf[MUSE_MSG_LEN_MAX];
  99         FILE *fp;
 100
 101         muse_return_if_fail(ms_is_log_enabled());
 102         muse_return_if_fail(log);
 103         muse_return_if_fail(muse_core_fd_is_valid(log->fd));
 104         muse_return_if_fail(_ms_log_pid_is_valid(pid));
 105
 106         snprintf(log_buf, sizeof(log_buf), "/proc/%d/cmdline", pid);
 107         fp = fopen(log_buf, "r");
 108         if (fp) {
 109                 size_t size = fread(log_buf, sizeof(char), MUSE_MSG_LEN_MAX, fp);
 110                 log_buf[size] = '\0';
 111
 112                 ms_log_write(log_buf);
 113                 fclose(fp);
 114         }
 115 }
 116
 117 static void _ms_log_process_info(ms_log_t *log, int pid)
 118 {
 119         char log_buf[MUSE_MSG_LEN_MAX];
 120         FILE *fp;
 121
 122         muse_return_if_fail(ms_is_log_enabled());
 123         muse_return_if_fail(log);
 124         muse_return_if_fail(muse_core_fd_is_valid(log->fd));
 125         muse_return_if_fail(_ms_log_pid_is_valid(pid));
 126
 127         snprintf(log_buf, sizeof(log_buf), "/bin/ps -Lo pcpu,pmem,tid,comm -p %d", pid);
 128         fp = popen(log_buf, "r");
 129         if (fp) {
 130                 ms_log_write(log_buf);
 131
 132                 while (fgets(log_buf, MUSE_MSG_LEN_MAX, fp)) {
 133                         if (write(log->fd, log_buf, strlen(log_buf)) == WRITE_FAIL)
 134                                 LOGE("fail to write command info to logfile");
 135                 }
 136
 137                 if (pclose(fp) == -1)
 138                         LOGE("fail to pclose");
 139         }
 140 }
 141
 142 static void _ms_log_api_info(ms_log_t *log)
 143 {
 144         Dl_info info;
 145         char log_buf[MUSE_MSG_LEN_MAX];
 146         gpointer ptr;
 147         int idx;
 148
 149         muse_return_if_fail(ms_is_log_enabled());
 150         muse_return_if_fail(log);
 151         muse_return_if_fail(muse_core_fd_is_valid(log->fd));
 152
 153         for (idx = 0; idx < ms_config_get_host_cnt(); idx++) {
 154                 ms_module_get_dllsym_value(idx, DISPATCHER_PTR, &ptr);
 155                 memset(&info, 0, sizeof(info));
 156                 if (dladdr((const void *) ptr, &info) && info.dli_sname) {
 157                         snprintf(log_buf, sizeof(log_buf), "[The latest called api name] %s", info.dli_sname);
 158                         ms_log_write(log_buf);
 159                 }
 160         }
 161 }
 162
 163 static void _ms_log_binary_info(ms_log_t *log)
 164 {
 165         char log_buf[MUSE_MSG_LEN_MAX];
 166         FILE *fp;
 167         char *label;
 168         char *value;
 169         char *ptr = NULL;
 170
 171         muse_return_if_fail(ms_is_log_enabled());
 172         muse_return_if_fail(log);
 173         muse_return_if_fail(muse_core_fd_is_valid(log->fd));
 174
 175         fp = fopen("/etc/tizen-release", "r");
 176         muse_return_if_fail(fp);
 177
 178         while (fgets(log_buf, MUSE_MSG_LEN_MAX, fp)) {
 179                 label = strtok_r(log_buf, delimiter, &ptr);
 180                 if (label) {
 181                         if (strncmp(label, BUILD_ID, strlen(BUILD_ID) + 1) == 0) {
 182                                 value = strtok_r(NULL, delimiter, &ptr);
 183                                 if (value)
 184                                         ms_log_write(value);
 185                                 else
 186                                         LOGE("strtok_r (value) returns null");
 187                         }
 188                 } else {
 189                         LOGE("strtok_r (label) returns null");
 190                 }
 191         }
 192
 193         fclose(fp);
 194 }
 195
 196 static int _ms_fd_set_block(int fd)
 197 {
 198         int flags;
 199         int ret;
 200
 201         muse_return_val_if_fail(ms_is_log_enabled(), MM_ERROR_NOT_SUPPORT_API);
 202
 203         flags = fcntl(fd, F_GETFL);
 204         ret = fcntl(fd, F_SETFL, flags & (U32BITS ^ O_NONBLOCK));
 205
 206         muse_core_update_fd_state(fd);
 207
 208         return ret;
 209 }
 210
 211 static int _ms_log_open_work(const char *path)
 212 {
 213         muse_return_val_if_fail(path, MM_ERROR_INVALID_ARGUMENT);
 214         muse_core_remove_symlink(path);
 215         return open(path, O_CREAT | O_APPEND | O_WRONLY | O_NONBLOCK, 0644);
 216 }
 217
 218 static void _ms_log_create_fd(ms_log_t *log)
 219 {
 220         int selected_idx = 0;
 221         int idx;
 222         struct stat st;
 223         char file[MAX_FILE_NUM][MUSE_MSG_LEN];
 224
 225         muse_return_if_fail(ms_is_log_enabled());
 226         muse_return_if_fail(log);
 227
 228         for (idx = 0; idx < MAX_FILE_NUM; idx++)
 229                 snprintf(file[idx], strlen(MUSE_LOG_FILE) + 3, "%s.%d", MUSE_LOG_FILE, idx);
 230
 231         for (idx = 0; idx < MAX_FILE_NUM; idx++) {
 232                 if (access(file[idx], F_OK) == 0) { /* if 0, then there is file */
 233                         if (stat(file[idx], &st) == MUSE_ERR) {
 234                                 LOGE("stat %s fail", file[idx]);
 235                                 continue;
 236                         }
 237                         log->size = st.st_size;
 238                         if (log->size > MAX_SIZE) {
 239                                 selected_idx = (idx + 1) % MAX_FILE_NUM;
 240                         } else {
 241                                 selected_idx = idx;
 242                                 break;
 243                         }
 244                 } else {
 245                         selected_idx = idx;
 246                         break;
 247                 }
 248         }
 249
 250         LOGD("filename: %s", file[selected_idx]);
 251         /* open log file again */
 252         log->fd = _ms_log_open_work(file[selected_idx]);
 253         if (!muse_core_fd_is_valid(log->fd))
 254                 LOGE("couldn't open log file %d", log->fd);
 255         else
 256                 LOGD("log fd : %d", log->fd);
 257 }
 258
 259 static void _ms_log_set_fd(ms_log_t *log)
 260 {
 261         char err_msg[MUSE_MSG_LEN_MAX] = {'\0',};
 262
 263         if (!ms_is_log_enabled())
 264                 return;
 265
 266         muse_return_if_fail(log);
 267
 268         _ms_log_create_fd(log);
 269
 270         muse_return_if_fail(muse_core_fd_is_valid(log->fd));
 271
 272         if (fcntl(log->fd, F_SETFD, FD_CLOEXEC) < 0) {
 273                 strerror_r(errno, err_msg, MUSE_MSG_LEN_MAX);
 274                 LOGE("unable to set CLO_EXEC on log fd %d: %s", log->fd, err_msg);
 275         }
 276
 277         (void) _ms_fd_set_block(log->fd);
 278 }
 279
 280 static void _ms_log_cache_latest_msg(ms_log_t *log, int pid, char *msg)
 281 {
 282         char time_buf[MUSE_MSG_TIME_LEN];
 283         muse_return_if_fail(msg);
 284         muse_return_if_fail(log);
 285
 286         g_mutex_lock(&log->lock);
 287
 288         muse_core_get_cur_time(NULL, time_buf);
 289         snprintf(log->latest_msgs[log->cur_idx], MUSE_MSG_LEN_MAX, "[P%5d] %s %s", pid, time_buf, msg);
 290
 291         log->cur_idx = (log->cur_idx + 1) % MUSE_LOG_MSG_NUM;
 292
 293         g_mutex_unlock(&log->lock);
 294 }
 295
 296 void ms_log_init(ms_log_t *log)
 297 {
 298         muse_return_if_fail(log);
 299
 300         g_mutex_init(&log->lock);
 301         _ms_log_set_fd(log);
 302 }
 303
 304 void ms_log_deinit(ms_log_t *log)
 305 {
 306         LOGD("Enter");
 307
 308         muse_return_if_fail(log);
 309
 310         muse_return_if_fail(ms_is_log_enabled());
 311         g_mutex_clear(&log->lock);
 312
 313         MUSE_G_FREE(log);
 314
 315         LOGD("Leave");
 316 }
 317
 318 void ms_log_save_addr_name(int pid, gpointer addr)
 319 {
 320         Dl_info info;
 321
 322         muse_return_if_fail(ms_get_instance());
 323         muse_return_if_fail(ms_is_log_enabled());
 324         muse_return_if_fail(addr);
 325
 326         memset(&info, 0, sizeof(info));
 327
 328         if (dladdr((const void *) addr, &info) && info.dli_sname)
 329                 _ms_log_cache_latest_msg(ms_get_instance()->log, pid, (char *)info.dli_sname);
 330         else
 331                 LOGE("fail to log api name");
 332 }
 333
 334 void ms_log_debug_pid_info(int pid)
 335 {
 336         ms_log_t *log = NULL;
 337
 338         muse_return_if_fail(ms_get_instance());
 339         muse_return_if_fail(ms_is_log_enabled());
 340
 341         log = ms_get_instance()->log;
 342         muse_return_if_fail(log);
 343
 344         /* pid */
 345         _ms_log_pid_time(log, pid);
 346
 347         /* cmdline */
 348         _ms_log_cmdline(log, pid);
 349
 350         /* process info */
 351         _ms_log_process_info(log, pid);
 352
 353         /* api info */
 354         _ms_log_api_info(log);
 355
 356         /* binary version */
 357         _ms_log_binary_info(log);
 358
 359         /* latest api */
 360         _ms_log_latest_msgs(log);
 361 }
 362
 363 void ms_log_write(char *buf)
 364 {
 365         ms_log_t *log = NULL;
 366
 367         muse_return_if_fail(ms_get_instance());
 368
 369         log = ms_get_instance()->log;
 370
 371         muse_return_if_fail(ms_is_log_enabled());
 372         muse_return_if_fail(log);
 373         muse_return_if_fail(muse_core_fd_is_valid(log->fd));
 374         muse_return_if_fail(buf);
 375
 376         if (write(log->fd, buf, strlen(buf)) == WRITE_FAIL)
 377                 LOGE("There was an error writing module pid to logfile");
 378         else if (write(log->fd, "\n", 1) == WRITE_FAIL)
 379                 LOGE("fail to write new line character");
 380 }
 381