drivers/staging/nanohub/chub_log.c

   1 /*
   2  * Copyright (c) 2017 Samsung Electronics Co., Ltd.
   3  *
   4  * This program is free software; you can redistribute it and/or modify
   5  * it under the terms of the GNU General Public License as published by
   6  * the Free Software Foundation; either version 2 of the License, or
   7  * (at your option) any later version.
   8  */
   9
  10 #include <linux/debugfs.h>
  11 #include <linux/mutex.h>
  12 #include <linux/vmalloc.h>
  13 #include <linux/io.h>
  14 #include <linux/device.h>
  15 #include <linux/module.h>
  16 #include <linux/iommu.h>
  17 #include <linux/poll.h>
  18 #include <linux/uaccess.h>
  19 #include <linux/delay.h>
  20
  21 #include "chub_log.h"
  22 #include "chub_dbg.h"
  23 #include "chub_ipc.h"
  24
  25 #ifdef CONFIG_CONTEXTHUB_DEBUG
  26 #define SIZE_OF_BUFFER (SZ_512K + SZ_128K)
  27 #else
  28 #define SIZE_OF_BUFFER (SZ_128K)
  29 #endif
  30
  31 #define S_IRWUG (0660)
  32 #define DEFAULT_FLUSH_MS (1000)
  33
  34 static u32 log_auto_save;
  35 static struct dentry *dbg_root_dir __read_mostly;
  36 static LIST_HEAD(log_list_head);
  37 static struct log_buffer_info *print_info;
  38 u32 auto_log_flush_ms;
  39
  40 static void log_memcpy(struct log_buffer_info *info,
  41                        struct log_kernel_buffer *kernel_buffer,
  42                        const char *src, size_t size)
  43 {
  44         mm_segment_t old_fs;
  45
  46         size_t left_size = SIZE_OF_BUFFER - kernel_buffer->index;
  47
  48         dev_dbg(info->dev, "%s(%zu)\n", __func__, size);
  49         if (size > SIZE_OF_BUFFER) {
  50                 dev_warn(info->dev,
  51                          "flush size (%zu, %zu) is bigger than kernel buffer size (%d)",
  52                          size, left_size, SIZE_OF_BUFFER);
  53                 size = SIZE_OF_BUFFER;
  54         }
  55
  56         old_fs = get_fs();
  57         set_fs(KERNEL_DS);
  58
  59         if(log_auto_save) {
  60                 if (likely(info->file_created)) {
  61                         info->filp = filp_open(info->save_file_name, O_RDWR | O_APPEND | O_CREAT, S_IRWUG);
  62                         dev_info(info->dev, "appended to %s\n", info->save_file_name);
  63                 } else {
  64                         info->filp = filp_open(info->save_file_name, O_RDWR | O_TRUNC | O_CREAT, S_IRWUG);
  65                         info->file_created = true;
  66                         dev_info(info->dev, "created %s\n", info->save_file_name);
  67                 }
  68
  69                 if (IS_ERR(info->filp)) {
  70                         dev_warn(info->dev, "%s: saving log fail\n", __func__);
  71                         goto out;
  72                 }
  73         }
  74
  75         if (left_size < size) {
  76                 if (info->sram_log_buffer)
  77                         memcpy_fromio(kernel_buffer->buffer + kernel_buffer->index, src, left_size);
  78                 else
  79                         memcpy(kernel_buffer->buffer + kernel_buffer->index, src, left_size);
  80
  81                 if (log_auto_save) {
  82                         vfs_write(info->filp, kernel_buffer->buffer + kernel_buffer->index, left_size, &info->filp->f_pos);
  83                         vfs_fsync(info->filp, 0);
  84                 }
  85                 src += left_size;
  86                 size -= left_size;
  87
  88                 kernel_buffer->index = 0;
  89                 kernel_buffer->wrap = true;
  90         }
  91
  92         if (info->sram_log_buffer)
  93                 memcpy_fromio(kernel_buffer->buffer + kernel_buffer->index, src, size);
  94         else
  95                 memcpy(kernel_buffer->buffer + kernel_buffer->index, src, size);
  96
  97         if (log_auto_save) {
  98                 vfs_write(info->filp,
  99                           kernel_buffer->buffer + kernel_buffer->index, size, &info->filp->f_pos);
 100                 vfs_fsync(info->filp, 0);
 101                 filp_close(info->filp, NULL);
 102         }
 103
 104         kernel_buffer->index += size;
 105
 106 out:
 107         set_fs(old_fs);
 108 }
 109
 110 void log_flush(struct log_buffer_info *info)
 111 {
 112         struct LOG_BUFFER *buffer = info->log_buffer;
 113         struct log_kernel_buffer *kernel_buffer = &info->kernel_buffer;
 114         unsigned int index_writer = buffer->index_writer;
 115
 116         /* check logbuf index dueto sram corruption */
 117         if ((buffer->index_reader >= ipc_get_offset(IPC_REG_LOG))
 118                 || (buffer->index_writer >= ipc_get_offset(IPC_REG_LOG))) {
 119                 dev_err(info->dev, "%s(%d): offset is corrupted. index_writer=%u, index_reader=%u, size=%u-%u\n",
 120                         __func__, info->id, buffer->index_writer, buffer->index_reader, buffer->size,
 121                         ipc_get_offset(IPC_REG_LOG));
 122
 123                 return;
 124         }
 125
 126         if (buffer->index_reader == index_writer)
 127                 return;
 128
 129         dev_dbg(info->dev,
 130                 "%s(%d): index_writer=%u, index_reader=%u, size=%u\n", __func__,
 131                 info->id, index_writer, buffer->index_reader, buffer->size);
 132
 133         mutex_lock(&info->lock);
 134
 135         if (buffer->index_reader > index_writer) {
 136                 log_memcpy(info, kernel_buffer,
 137                            buffer->buffer + buffer->index_reader,
 138                            buffer->size - buffer->index_reader);
 139                 buffer->index_reader = 0;
 140         }
 141         log_memcpy(info, kernel_buffer,
 142                    buffer->buffer + buffer->index_reader,
 143                    index_writer - buffer->index_reader);
 144         buffer->index_reader = index_writer;
 145
 146         wmb();
 147         mutex_unlock(&info->lock);
 148
 149         kernel_buffer->updated = true;
 150         wake_up_interruptible(&kernel_buffer->wq);
 151 }
 152
 153 static void log_flush_all_work_func(struct work_struct *work);
 154 static DECLARE_DEFERRABLE_WORK(log_flush_all_work, log_flush_all_work_func);
 155
 156 static void log_flush_all(void)
 157 {
 158         struct log_buffer_info *info;
 159
 160         list_for_each_entry(info, &log_list_head, list) {
 161                 if (!info) {
 162                         pr_warn("%s: fails get info\n", __func__);
 163                         return;
 164                 }
 165                 log_flush(info);
 166         }
 167 }
 168
 169 static void log_flush_all_work_func(struct work_struct *work)
 170 {
 171         log_flush_all();
 172
 173         if (auto_log_flush_ms)
 174                 schedule_delayed_work(&log_flush_all_work,
 175                                       msecs_to_jiffies(auto_log_flush_ms));
 176 }
 177
 178 void log_schedule_flush_all(void)
 179 {
 180         schedule_delayed_work(&log_flush_all_work, msecs_to_jiffies(3000));
 181 }
 182
 183 static int log_file_open(struct inode *inode, struct file *file)
 184 {
 185         struct log_buffer_info *info = inode->i_private;
 186
 187         dev_dbg(info->dev, "%s\n", __func__);
 188
 189         file->private_data = inode->i_private;
 190         info->log_file_index = -1;
 191
 192         return 0;
 193 }
 194
 195 static ssize_t log_file_read(struct file *file, char __user *buf, size_t count,
 196                              loff_t *ppos)
 197 {
 198         struct log_buffer_info *info = file->private_data;
 199         struct log_kernel_buffer *kernel_buffer = &info->kernel_buffer;
 200         size_t end, size;
 201         bool first = (info->log_file_index < 0);
 202         int result;
 203
 204         dev_dbg(info->dev, "%s(%zu, %lld)\n", __func__, count, *ppos);
 205
 206         mutex_lock(&info->lock);
 207
 208         if (info->log_file_index < 0) {
 209                 info->log_file_index =
 210                     likely(kernel_buffer->wrap) ? kernel_buffer->index : 0;
 211         }
 212
 213         do {
 214                 end = ((info->log_file_index < kernel_buffer->index) ||
 215                        ((info->log_file_index == kernel_buffer->index) &&
 216                         !first)) ? kernel_buffer->index : SIZE_OF_BUFFER;
 217                 size = min(end - info->log_file_index, count);
 218                 if (size == 0) {
 219                         mutex_unlock(&info->lock);
 220                         if (file->f_flags & O_NONBLOCK) {
 221                                 dev_dbg(info->dev, "non block\n");
 222                                 return -EAGAIN;
 223                         }
 224                         kernel_buffer->updated = false;
 225
 226                         result = wait_event_interruptible(kernel_buffer->wq,
 227                                 kernel_buffer->updated);
 228                         if (result != 0) {
 229                                 dev_dbg(info->dev, "interrupted\n");
 230                                 return result;
 231                         }
 232                         mutex_lock(&info->lock);
 233                 }
 234         } while (size == 0);
 235
 236         dev_dbg(info->dev, "start=%zd, end=%zd size=%zd\n",
 237                 info->log_file_index, end, size);
 238         if (copy_to_user
 239             (buf, kernel_buffer->buffer + info->log_file_index, size)) {
 240                 mutex_unlock(&info->lock);
 241                 return -EFAULT;
 242         }
 243
 244         info->log_file_index += size;
 245         if (info->log_file_index >= SIZE_OF_BUFFER)
 246                 info->log_file_index = 0;
 247
 248         mutex_unlock(&info->lock);
 249
 250         dev_dbg(info->dev, "%s: size = %zd\n", __func__, size);
 251
 252         return size;
 253 }
 254
 255 static unsigned int log_file_poll(struct file *file, poll_table *wait)
 256 {
 257         struct log_buffer_info *info = file->private_data;
 258         struct log_kernel_buffer *kernel_buffer = &info->kernel_buffer;
 259
 260         dev_dbg(info->dev, "%s\n", __func__);
 261
 262         poll_wait(file, &kernel_buffer->wq, wait);
 263         return POLLIN | POLLRDNORM;
 264 }
 265
 266 static const struct file_operations log_fops = {
 267         .open = log_file_open,
 268         .read = log_file_read,
 269         .poll = log_file_poll,
 270         .llseek = generic_file_llseek,
 271         .owner = THIS_MODULE,
 272 };
 273
 274 static struct dentry *chub_dbg_get_root_dir(void)
 275 {
 276         if (!dbg_root_dir)
 277                 dbg_root_dir = debugfs_create_dir("nanohub", NULL);
 278
 279         return dbg_root_dir;
 280 }
 281
 282 static void chub_log_auto_save_open(struct log_buffer_info *info)
 283 {
 284         mm_segment_t old_fs = get_fs();
 285
 286         set_fs(KERNEL_DS);
 287
 288         /* close previous */
 289         if (info->filp && !IS_ERR(info->filp)) {
 290                 dev_info(info->dev, "%s closing previous file %p\n", __func__, info->filp);
 291                 filp_close(info->filp, current->files);
 292                 }
 293
 294         info->filp =
 295             filp_open(info->save_file_name, O_RDWR | O_TRUNC | O_CREAT,
 296                       S_IRWUG);
 297
 298         dev_info(info->dev, "%s created\n", info->save_file_name);
 299
 300         if (IS_ERR(info->filp))
 301                 dev_warn(info->dev, "%s: saving log fail\n", __func__);
 302
 303         set_fs(old_fs);
 304 }
 305
 306 static void chub_log_auto_save_ctrl(struct log_buffer_info *info, u32 event)
 307 {
 308         if (event) {
 309                 /* set file name */
 310                 snprintf(info->save_file_name, sizeof(info->save_file_name),
 311                          "%s/nano-%02d-00-%06u.log", CHUB_DBG_DIR, info->id,
 312                          (u32)(sched_clock() / NSEC_PER_SEC));
 313                 chub_log_auto_save_open(info);
 314                 log_auto_save = 1;
 315         } else {
 316                 log_auto_save = 0;
 317                 info->filp = NULL;
 318         }
 319
 320         pr_info("%s: %s, %d, %p\n", __func__, info->save_file_name,
 321                 log_auto_save, info->filp);
 322 }
 323
 324 static ssize_t chub_log_save_show(struct device *kobj,
 325                                   struct device_attribute *attr, char *buf)
 326 {
 327         return sprintf(buf, "%d\n", log_auto_save);
 328 }
 329
 330 static ssize_t chub_log_save_save(struct device *dev,
 331                                   struct device_attribute *attr,
 332                                   const char *buf, size_t count)
 333 {
 334         long event;
 335         int err;
 336
 337         /* auto log_save */
 338         err = kstrtol(&buf[0], 10, &event);
 339
 340         if (!err) {
 341                 struct log_buffer_info *info;
 342
 343                 list_for_each_entry(info, &log_list_head, list)
 344                         if (info->support_log_save) /* sram can support it */
 345                                 chub_log_auto_save_ctrl(info, event);
 346
 347                 /* set log_flush to save log */
 348                 if (!auto_log_flush_ms) {
 349                         log_schedule_flush_all();
 350                         auto_log_flush_ms = DEFAULT_FLUSH_MS;
 351                         dev_dbg(dev, "%s: set log_flush time(% dms) for log_save\n",
 352                                 auto_log_flush_ms);
 353                 }
 354                 return count;
 355         } else {
 356                 return 0;
 357         }
 358 }
 359
 360 #define TMP_BUFFER_SIZE (1000)
 361
 362 #if defined(CONFIG_CONTEXTHUB_DEBUG)
 363 static void log_dump(struct log_buffer_info *info, int err)
 364 {
 365         struct file *filp;
 366         mm_segment_t old_fs;
 367         char save_file_name[64];
 368         struct LOG_BUFFER *buffer = info->log_buffer;
 369         u32 wrap_index = buffer->index_writer;
 370
 371         /* check logbuf index dueto sram corruption */
 372         if ((buffer->index_reader >= ipc_get_offset(IPC_REG_LOG))
 373                 || (buffer->index_writer >= ipc_get_offset(IPC_REG_LOG))) {
 374                 dev_err(info->dev, "%s(%d): offset is corrupted. index_writer=%u, index_reader=%u, size=%u-%u\n",
 375                         __func__, info->id, buffer->index_writer, buffer->index_reader, buffer->size,
 376                         ipc_get_offset(IPC_REG_LOG));
 377                 return;
 378         }
 379
 380         snprintf(save_file_name, sizeof(save_file_name),
 381                  "%s/nano-%02d-%02d-%06u.log", CHUB_DBG_DIR,
 382                  info->id, err, (u32)(sched_clock() / NSEC_PER_SEC));
 383
 384         old_fs = get_fs();
 385         set_fs(KERNEL_DS);
 386
 387         filp = filp_open(save_file_name, O_RDWR | O_TRUNC | O_CREAT, S_IRWUG);
 388         if (IS_ERR(filp)) {
 389                 dev_warn(info->dev, "%s: fails filp:%p\n", __func__, filp);
 390                 goto out;
 391         }
 392
 393         if (info->sram_log_buffer) {
 394                 int i;
 395                 int size;
 396                 bool wrap = false;
 397                 char tmp_buffer[TMP_BUFFER_SIZE];
 398                 u32 start_index = wrap_index;
 399                 int bottom = 0;
 400
 401                 /* dump sram-log buffer to fs (eq ~ eq + logbuf_size) */
 402                 dev_dbg(info->dev, "%s: logbuf:%p, eq:%d, dq:%d, size:%d, loop:%d\n", __func__,
 403                         (void *)buffer, wrap_index,     buffer->index_reader, buffer->size,
 404                         (buffer->size / TMP_BUFFER_SIZE) + 1);
 405                 for (i = 0; i < (buffer->size / TMP_BUFFER_SIZE) + 1;
 406                      i++, start_index += TMP_BUFFER_SIZE) {
 407                         if (start_index + TMP_BUFFER_SIZE > buffer->size) {
 408                                 size = buffer->size - start_index;
 409                                 wrap = true;
 410                                 bottom = 1;
 411                         } else if (bottom && (wrap_index - start_index < TMP_BUFFER_SIZE))      {
 412                                 size = wrap_index - start_index;
 413                         } else {
 414                                 size = TMP_BUFFER_SIZE;
 415                         }
 416                         memcpy_fromio(tmp_buffer, buffer->buffer + start_index, size);
 417                         vfs_write(filp, tmp_buffer, size, &filp->f_pos);
 418                         if (wrap) {
 419                                 wrap = false;
 420                                 start_index = 0;
 421                         }
 422                 }
 423         } else {
 424                 vfs_write(filp, buffer->buffer + wrap_index, buffer->size - wrap_index,
 425                           &filp->f_pos);
 426                 vfs_write(filp, buffer->buffer, wrap_index, &filp->f_pos);
 427         }
 428         dev_dbg(info->dev, "%s is created\n", save_file_name);
 429
 430         vfs_fsync(filp, 0);
 431         filp_close(filp, NULL);
 432
 433 out:
 434         set_fs(old_fs);
 435 }
 436
 437 void log_dump_all(int err)
 438 {
 439         struct log_buffer_info *info;
 440
 441         list_for_each_entry(info, &log_list_head, list)
 442                 log_dump(info, err);
 443 }
 444 #endif
 445
 446 static ssize_t chub_log_flush_show(struct device *kobj,
 447                                    struct device_attribute *attr, char *buf)
 448 {
 449         return sprintf(buf, "%d\n", auto_log_flush_ms);
 450 }
 451
 452 static ssize_t chub_log_flush_save(struct device *dev,
 453                                    struct device_attribute *attr,
 454                                    const char *buf, size_t count)
 455 {
 456         long event;
 457         int err;
 458
 459         err = kstrtol(&buf[0], 10, &event);
 460         if (!err) {
 461                 if (!auto_log_flush_ms) {
 462                         if (!err) {
 463                                 log_flush_all();
 464                         } else {
 465                                 pr_err("%s: fails to flush log\n", __func__);
 466                         }
 467                 }
 468                 /* update log_flush time */
 469                 auto_log_flush_ms = event * 1000;
 470
 471                 return count;
 472         } else {
 473                 return 0;
 474         }
 475
 476         return count;
 477 }
 478
 479 static ssize_t chub_dump_log_save(struct device *dev,
 480                                   struct device_attribute *attr,
 481                                   const char *buf, size_t count)
 482 {
 483         log_dump_all(0);
 484         return count;
 485 }
 486
 487 static struct device_attribute attributes[] = {
 488         /* enable auto-save with flush_log */
 489         __ATTR(save_log, 0664, chub_log_save_show, chub_log_save_save),
 490         /* flush sram-logbuf to dram */
 491         __ATTR(flush_log, 0664, chub_log_flush_show, chub_log_flush_save),
 492         /* dump sram-logbuf to file */
 493         __ATTR(dump_log, 0220, NULL, chub_dump_log_save)
 494 };
 495
 496 struct log_buffer_info *log_register_buffer(struct device *dev, int id,
 497                                             struct LOG_BUFFER *buffer,
 498                                             char *name, bool sram)
 499 {
 500         struct log_buffer_info *info = vmalloc(sizeof(*info));
 501         int i;
 502         int ret;
 503
 504         if (!info)
 505                 return NULL;
 506
 507         mutex_init(&info->lock);
 508         info->id = id;
 509         info->file_created = false;
 510         info->kernel_buffer.buffer = vzalloc(SIZE_OF_BUFFER);
 511         info->kernel_buffer.index = 0;
 512         info->kernel_buffer.index_reader = 0;
 513         info->kernel_buffer.index_writer = 0;
 514         info->kernel_buffer.wrap = false;
 515         init_waitqueue_head(&info->kernel_buffer.wq);
 516         info->dev = dev;
 517         info->log_buffer = buffer;
 518
 519         /* HACK: clang make error
 520         buffer->index_reader = 0;
 521         buffer->index_writer = 0;
 522         */
 523         info->save_file_name[0] = '\0';
 524         info->filp = NULL;
 525
 526         dev_info(dev, "%s with %p buffer size %d. %p kernel buffer size %d\n",
 527                  __func__, buffer->buffer, buffer->size,
 528                  info->kernel_buffer.buffer, SIZE_OF_BUFFER);
 529
 530         debugfs_create_file(name, S_IRWUG, chub_dbg_get_root_dir(), info,
 531                             &log_fops);
 532
 533         list_add_tail(&info->list, &log_list_head);
 534
 535         if (sram) {
 536                 info->sram_log_buffer = true;
 537                 info->support_log_save = true;
 538
 539                 /* add device files */
 540                 for (i = 0, ret = 0; i < ARRAY_SIZE(attributes); i++) {
 541                         ret = device_create_file(dev, &attributes[i]);
 542                         if (ret)
 543                                 dev_warn(dev, "Failed to create file: %s\n",
 544                                          attributes[i].attr.name);
 545                 }
 546         } else {
 547                 print_info = info;
 548                 info->sram_log_buffer = false;
 549                 info->support_log_save = false;
 550         }
 551
 552         return info;
 553 }
 554
 555 void log_printf(const char *format, ...)
 556 {
 557         struct LOG_BUFFER *buffer;
 558         int size;
 559         va_list args;
 560
 561         if (print_info) {
 562                 char tmp_buf[512];
 563                 char *buffer_index = tmp_buf;
 564
 565                 buffer = print_info->log_buffer;
 566
 567                 va_start(args, format);
 568                 size = vsprintf(tmp_buf, format, args);
 569                 va_end(args);
 570
 571                 size++;
 572                 if (buffer->index_writer + size > buffer->size) {
 573                         int left_size = buffer->size - buffer->index_writer;
 574
 575                         memcpy(&buffer->buffer[buffer->index_writer],
 576                                buffer_index, left_size);
 577                         buffer->index_writer = 0;
 578                         buffer_index += left_size;
 579                 }
 580                 memcpy(&buffer->buffer[buffer->index_writer], buffer_index,
 581                        size - (buffer_index - tmp_buf));
 582                 buffer->index_writer += size - (buffer_index - tmp_buf);
 583
 584         }
 585 }
 586
 587 static int __init log_late_initcall(void)
 588 {
 589         debugfs_create_u32("log_auto_save", S_IRWUG, chub_dbg_get_root_dir(),
 590                            &log_auto_save);
 591         return 0;
 592 }
 593
 594 late_initcall(log_late_initcall);