#include #include #include #include #include #include "log.h" #include "events.h" #include "leds.h" #include "button.h" #include "hui_internal.h" /* set in connect/connect.c, can't include connect/connect.h because of conflicting variables */ extern unsigned int log_level; enum { ENTRY_FREE = 0, ENTRY_EVENT = 1, ENTRY_UNKNOWN_EVENT = 2, ENTRY_LED = 3, ENTRY_BUTTON = 4, ENTRY_BUTTON_EVENT = 5, }; struct log_entry_event { const struct event *event; int value; }; struct log_entry_unknown_event { int id; int value; }; struct log_entry_led { const struct led *led; struct blink_code code; } __attribute__((packed)); struct log_entry_button { const struct button *button; enum button_event event; }; struct log_entry_button_event { unsigned int id; unsigned int value; }; struct log_entry { unsigned long jiffies; union { struct log_entry_event event; struct log_entry_unknown_event unknown_event; struct log_entry_led led; struct log_entry_button button; struct log_entry_button_event button_event; } __attribute__((packed)); u8 type; } __attribute__((packed)); struct log { spinlock_t lock; /* * The sequence number intentionally does not wrap at num_entries. This makes * the use with the sysfs file a bit easier. The wrapping is only handled * in #hui_log_get_entry. * * This allows nice asynchronous iteration over the log, however if the log * wrapped while iterating, one may see newer entries at old places. Currently * we simply accept, that the may happens. */ loff_t next_seq; /* * Entries stored in entries. Must be power of 2 */ u16 num_entries; struct log_entry *entries; }; static struct log log; static struct log_entry *hui_log_get_entry(loff_t seq) { lockdep_assert_held(&log.lock); return &log.entries[seq & (log.num_entries - 1)]; } static struct log_entry *hui_log_create_entry(u8 type) { struct log_entry *entry = hui_log_get_entry(log.next_seq++); memset(entry, 0, sizeof(*entry)); entry->jiffies = jiffies; entry->type = type; return entry; } void hui_log_event(const struct event *event, int value) { struct log_entry *entry; spin_lock(&log.lock); entry = hui_log_create_entry(ENTRY_EVENT); entry->event.event = event; entry->event.value = value; spin_unlock(&log.lock); pr_debug("Log event entry=%p event=%p value=%d\n", entry, event, value); } void hui_log_unknown_event(int event_id, int value) { struct log_entry *entry; spin_lock(&log.lock); entry = hui_log_create_entry(ENTRY_UNKNOWN_EVENT); entry->unknown_event.id = event_id; entry->unknown_event.value = value; spin_unlock(&log.lock); pr_debug("Log unknown event entry=%p id=%d value=%d\n", entry, event_id, value); } void hui_log_led(const struct led *led) { struct log_entry *entry; spin_lock(&log.lock); entry = hui_log_create_entry(ENTRY_LED); entry->led.led = led; entry->led.code = led->current_code; spin_unlock(&log.lock); pr_debug("Log led entry entry=%p led=%p\n", entry, led); } void hui_log_button(const struct button *button, enum button_event event) { struct log_entry *entry; spin_lock(&log.lock); entry = hui_log_create_entry(ENTRY_BUTTON); entry->button.button = button; entry->button.event = event; spin_unlock(&log.lock); } void hui_log_button_event(unsigned int button_id, unsigned int value) { struct log_entry *entry; spin_lock(&log.lock); entry = hui_log_create_entry(ENTRY_BUTTON_EVENT); entry->button_event.id = button_id; entry->button_event.value = value; spin_unlock(&log.lock); } struct log_iter { struct log_entry entry; }; /* * We use the file pos as our index number, not as something mapping to bytes. * * We remember the first index number upon opening the file, and this will be * mapped to the 0 position. */ static void *log_seq_start(struct seq_file *seq, loff_t *pos) { struct log_iter *iter; loff_t base_seq = *(loff_t *)seq->private; loff_t start_seq = base_seq + *pos; iter = kzalloc(sizeof(struct log_iter), GFP_KERNEL); if (!iter) return NULL; spin_lock(&log.lock); /* * We've got a valid entry here, so retrieve it. Setting start_seq to next_seq, * means we need to search for the start of the log (which will happen * in #log_seq_next) */ if (start_seq != log.next_seq) // Store a copy of the entry here, to allow lock less access iter->entry = *hui_log_get_entry(start_seq); else { kfree(iter); iter = NULL; } spin_unlock(&log.lock); return iter; } static void *log_seq_next(struct seq_file *seq, void *ctx, loff_t *pos) { struct log_iter *iter = ctx; loff_t base_seq = *(loff_t *)seq->private; loff_t cur_seq = base_seq + *pos; /* * Find the next non free entry. We do not need to concern with * wrapping of seq, as this is much larger than our available entries * and #hui_log_get_entry will pick the right entry. */ spin_lock(&log.lock); for (cur_seq++; cur_seq != log.next_seq; cur_seq++) { struct log_entry *entry = hui_log_get_entry(cur_seq); if (entry->type != ENTRY_FREE) { iter->entry = *entry; spin_unlock(&log.lock); // Set the position for user space, relative to our starting point *pos = cur_seq - base_seq; return iter; } } spin_unlock(&log.lock); return NULL; } static void log_seq_stop(struct seq_file *seq, void *ctx) { kfree(ctx); } static int log_seq_show(struct seq_file *seq, void *ctx) { struct log_iter *iter = ctx; struct timespec64 ts, kernel_time; struct tm tm; if (iter->entry.type == ENTRY_FREE) return 0; /* * We only store the monotonic jiffies since boot. * But we want to output it in an human readable format * so that the lines can be better matched to actual * events happening. * * As there is no direct conversion from jiffies to * tm, we take the relative seconds to the current jiffies * and add those seconds to the current time. */ jiffies_to_timespec64(jiffies - iter->entry.jiffies, &ts); ktime_get_real_ts64(&kernel_time); ts = timespec64_sub(kernel_time, ts); #if LINUX_VERSION_CODE < KERNEL_VERSION(4, 8, 0) time_to_tm((time_t) ts.tv_sec, 0, &tm); #else time64_to_tm(ts.tv_sec, 0, &tm); #endif /* only print timestamp, if event will be printed */ if (iter->entry.type != ENTRY_UNKNOWN_EVENT || log_level > 1) { seq_printf(seq, "[%lu-%02d-%02d %02d:%02d:%02d] ", tm.tm_year + 1900, tm.tm_mon + 1, tm.tm_mday, tm.tm_hour, tm.tm_min, tm.tm_sec); } if (iter->entry.type == ENTRY_EVENT) { const struct event *event = iter->entry.event.event; if (event->def) { const struct event_member_def *def = &event->def[iter->entry.event.value]; seq_printf(seq, "set event state %s to %s\n", event->name, def->name); } else seq_printf(seq, "got event %s (value %d)\n", event->name, iter->entry.event.value); } else if (iter->entry.type == ENTRY_UNKNOWN_EVENT) { if (log_level > 1) { seq_printf(seq, "got event %d (value %d)\n", iter->entry.unknown_event.id, iter->entry.unknown_event.value); } } else if (iter->entry.type == ENTRY_LED) { const struct led *led = iter->entry.led.led; const struct blink_code *code = &iter->entry.led.code; seq_printf(seq, "set led %s to %d (%d, %d, #%02X%02X%02X)\n", led->name, code->type, code->params[0], code->params[1], code->color.c[0], code->color.c[1], code->color.c[2]); } else if (iter->entry.type == ENTRY_BUTTON) { const struct button *button = iter->entry.button.button; enum button_event event = iter->entry.button.event; if (event == button_event_down) seq_printf(seq, "button %s pressed\n", button_name(button)); else if (event == button_event_up) seq_printf(seq, "button %s released\n", button_name(button)); } else if (iter->entry.type == ENTRY_BUTTON_EVENT) { seq_printf(seq, "send button event %s (value %d)\n", hui_button_event_to_name(iter->entry.button_event.id), iter->entry.button_event.value); } else seq_puts(seq, "unknown entry\n"); return 0; } static const struct seq_operations log_seq_ops = { .start = log_seq_start, .next = log_seq_next, .stop = log_seq_stop, .show = log_seq_show, }; static int log_seq_open(struct inode *inode, struct file *file) { struct seq_file *seq; int error; loff_t base_seq; error = seq_open(file, &log_seq_ops); if (error) return error; seq = file->private_data; seq->private = kmalloc(sizeof(loff_t), GFP_KERNEL); if (!seq->private) { seq_release(inode, file); return -ENOMEM; } /* * To allow the use of tail we need to remember the seq we started at * * On F!OS the busybox tail implementation with follow will wait 1s * after the last read and then try reading again. * * As our sequence number is larger than the available entries, we * can simply increase it and will remember the first free sequence * when the files is opened. After this we use the file position * plus this base sequence to get the entry we want to read. */ spin_lock(&log.lock); // Move to the oldest possible entry base_seq = log.next_seq - log.num_entries + 1; // Find first non-free entry for (; hui_log_get_entry(base_seq)->type == ENTRY_FREE; base_seq++) ; spin_unlock(&log.lock); *(loff_t *)seq->private = base_seq; return error; } static int log_seq_release(struct inode *inode, struct file *file) { struct seq_file *seq = file->private_data; kfree(seq->private); return seq_release(inode, file); } #if LINUX_VERSION_CODE >= KERNEL_VERSION(5, 6, 0) static const struct proc_ops log_proc_ops = { .proc_open = log_seq_open, .proc_read = seq_read, .proc_lseek = seq_lseek, .proc_release = log_seq_release, }; #else static const struct file_operations log_proc_ops = { .open = log_seq_open, .read = seq_read, .llseek = seq_lseek, .release = log_seq_release, }; #endif int hui_log_init(void) { spin_lock_init(&log.lock); log.num_entries = 1024; log.entries = kzalloc(log.num_entries * sizeof(struct log_entry), GFP_KERNEL); proc_create("avm/hui/log", S_IRUGO, NULL, &log_proc_ops); return 0; }