]> git.proxmox.com Git - mirror_ubuntu-zesty-kernel.git/blobdiff - kernel/trace/trace.c
tracing: protect ring_buffer_expanded with trace_types_lock
[mirror_ubuntu-zesty-kernel.git] / kernel / trace / trace.c
index c0e9c126339329d3a165cd23bf107f2709cbd4e9..04ab8243a13d1d6ebcb3fb2a6a610b6281e200f9 100644 (file)
 unsigned long __read_mostly    tracing_max_latency;
 unsigned long __read_mostly    tracing_thresh;
 
+/*
+ * On boot up, the ring buffer is set to the minimum size, so that
+ * we do not waste memory on systems that are not using tracing.
+ */
+static int ring_buffer_expanded;
+
 /*
  * We need to change this state when a selftest is running.
  * A selftest will lurk into the ring-buffer to count the
@@ -128,6 +134,8 @@ static int __init set_ftrace(char *str)
 {
        strncpy(bootup_tracer_buf, str, BOOTUP_TRACER_SIZE);
        default_bootup_tracer = bootup_tracer_buf;
+       /* We are using ftrace early, expand it */
+       ring_buffer_expanded = 1;
        return 1;
 }
 __setup("ftrace=", set_ftrace);
@@ -799,7 +807,7 @@ tracing_generic_entry_update(struct trace_entry *entry, unsigned long flags,
 
        entry->preempt_count            = pc & 0xff;
        entry->pid                      = (tsk) ? tsk->pid : 0;
-       entry->tgid                     = (tsk) ? tsk->tgid : 0;
+       entry->tgid                     = (tsk) ? tsk->tgid : 0;
        entry->flags =
 #ifdef CONFIG_TRACE_IRQFLAGS_SUPPORT
                (irqs_disabled_flags(flags) ? TRACE_FLAG_IRQS_OFF : 0) |
@@ -1169,6 +1177,71 @@ void trace_graph_return(struct ftrace_graph_ret *trace)
 }
 #endif /* CONFIG_FUNCTION_GRAPH_TRACER */
 
+
+/**
+ * trace_vprintk - write binary msg to tracing buffer
+ *
+ */
+int trace_vprintk(unsigned long ip, int depth, const char *fmt, va_list args)
+{
+       static raw_spinlock_t trace_buf_lock =
+               (raw_spinlock_t)__RAW_SPIN_LOCK_UNLOCKED;
+       static u32 trace_buf[TRACE_BUF_SIZE];
+
+       struct ring_buffer_event *event;
+       struct trace_array *tr = &global_trace;
+       struct trace_array_cpu *data;
+       struct print_entry *entry;
+       unsigned long flags;
+       int resched;
+       int cpu, len = 0, size, pc;
+
+       if (unlikely(tracing_selftest_running || tracing_disabled))
+               return 0;
+
+       /* Don't pollute graph traces with trace_vprintk internals */
+       pause_graph_tracing();
+
+       pc = preempt_count();
+       resched = ftrace_preempt_disable();
+       cpu = raw_smp_processor_id();
+       data = tr->data[cpu];
+
+       if (unlikely(atomic_read(&data->disabled)))
+               goto out;
+
+       /* Lockdep uses trace_printk for lock tracing */
+       local_irq_save(flags);
+       __raw_spin_lock(&trace_buf_lock);
+       len = vbin_printf(trace_buf, TRACE_BUF_SIZE, fmt, args);
+
+       if (len > TRACE_BUF_SIZE || len < 0)
+               goto out_unlock;
+
+       size = sizeof(*entry) + sizeof(u32) * len;
+       event = trace_buffer_lock_reserve(tr, TRACE_PRINT, size, flags, pc);
+       if (!event)
+               goto out_unlock;
+       entry = ring_buffer_event_data(event);
+       entry->ip                       = ip;
+       entry->depth                    = depth;
+       entry->fmt                      = fmt;
+
+       memcpy(entry->buf, trace_buf, sizeof(u32) * len);
+       ring_buffer_unlock_commit(tr->buffer, event);
+
+out_unlock:
+       __raw_spin_unlock(&trace_buf_lock);
+       local_irq_restore(flags);
+
+out:
+       ftrace_preempt_enable(resched);
+       unpause_graph_tracing();
+
+       return len;
+}
+EXPORT_SYMBOL_GPL(trace_vprintk);
+
 enum trace_file_type {
        TRACE_FILE_LAT_FMT      = 1,
        TRACE_FILE_ANNOTATE     = 2,
@@ -1405,11 +1478,11 @@ print_trace_header(struct seq_file *m, struct trace_iterator *iter)
        total = entries +
                ring_buffer_overruns(iter->tr->buffer);
 
-       seq_printf(m, "%s latency trace v1.1.5 on %s\n",
+       seq_printf(m, "%s latency trace v1.1.5 on %s\n",
                   name, UTS_RELEASE);
-       seq_puts(m, "-----------------------------------"
+       seq_puts(m, "-----------------------------------"
                 "---------------------------------\n");
-       seq_printf(m, " latency: %lu us, #%lu/%lu, CPU#%d |"
+       seq_printf(m, "# latency: %lu us, #%lu/%lu, CPU#%d |"
                   " (M:%s VP:%d, KP:%d, SP:%d HP:%d",
                   nsecs_to_usecs(data->saved_latency),
                   entries,
@@ -1431,24 +1504,24 @@ print_trace_header(struct seq_file *m, struct trace_iterator *iter)
 #else
        seq_puts(m, ")\n");
 #endif
-       seq_puts(m, "    -----------------\n");
-       seq_printf(m, "    | task: %.16s-%d "
+       seq_puts(m, "#    -----------------\n");
+       seq_printf(m, "#    | task: %.16s-%d "
                   "(uid:%d nice:%ld policy:%ld rt_prio:%ld)\n",
                   data->comm, data->pid, data->uid, data->nice,
                   data->policy, data->rt_priority);
-       seq_puts(m, "    -----------------\n");
+       seq_puts(m, "#    -----------------\n");
 
        if (data->critical_start) {
-               seq_puts(m, " => started at: ");
+               seq_puts(m, " => started at: ");
                seq_print_ip_sym(&iter->seq, data->critical_start, sym_flags);
                trace_print_seq(m, &iter->seq);
-               seq_puts(m, "\n => ended at:   ");
+               seq_puts(m, "\n => ended at:   ");
                seq_print_ip_sym(&iter->seq, data->critical_end, sym_flags);
                trace_print_seq(m, &iter->seq);
-               seq_puts(m, "\n");
+               seq_puts(m, "#\n");
        }
 
-       seq_puts(m, "\n");
+       seq_puts(m, "#\n");
 }
 
 static void test_cpu_buff_start(struct trace_iterator *iter)
@@ -1564,7 +1637,7 @@ static enum print_line_t print_printk_msg_only(struct trace_iterator *iter)
 
        trace_assign_type(field, entry);
 
-       ret = trace_seq_printf(s, "%s", field->buf);
+       ret = trace_seq_bprintf(s, field->fmt, field->buf);
        if (!ret)
                return TRACE_TYPE_PARTIAL_LINE;
 
@@ -1593,6 +1666,19 @@ static int trace_empty(struct trace_iterator *iter)
 {
        int cpu;
 
+       /* If we are looking at one CPU buffer, only check that one */
+       if (iter->cpu_file != TRACE_PIPE_ALL_CPU) {
+               cpu = iter->cpu_file;
+               if (iter->buffer_iter[cpu]) {
+                       if (!ring_buffer_iter_empty(iter->buffer_iter[cpu]))
+                               return 0;
+               } else {
+                       if (!ring_buffer_empty_cpu(iter->tr->buffer, cpu))
+                               return 0;
+               }
+               return 1;
+       }
+
        for_each_tracing_cpu(cpu) {
                if (iter->buffer_iter[cpu]) {
                        if (!ring_buffer_iter_empty(iter->buffer_iter[cpu]))
@@ -1719,17 +1805,11 @@ __tracing_open(struct inode *inode, struct file *file)
 
                        iter->buffer_iter[cpu] =
                                ring_buffer_read_start(iter->tr->buffer, cpu);
-
-                       if (!iter->buffer_iter[cpu])
-                               goto fail_buffer;
                }
        } else {
                cpu = iter->cpu_file;
                iter->buffer_iter[cpu] =
                                ring_buffer_read_start(iter->tr->buffer, cpu);
-
-               if (!iter->buffer_iter[cpu])
-                       goto fail;
        }
 
        /* TODO stop tracer */
@@ -1882,14 +1962,14 @@ static int show_traces_open(struct inode *inode, struct file *file)
        return ret;
 }
 
-static struct file_operations tracing_fops = {
+static const struct file_operations tracing_fops = {
        .open           = tracing_open,
        .read           = seq_read,
        .llseek         = seq_lseek,
        .release        = tracing_release,
 };
 
-static struct file_operations show_traces_fops = {
+static const struct file_operations show_traces_fops = {
        .open           = show_traces_open,
        .read           = seq_read,
        .release        = seq_release,
@@ -1982,7 +2062,7 @@ err_unlock:
        return err;
 }
 
-static struct file_operations tracing_cpumask_fops = {
+static const struct file_operations tracing_cpumask_fops = {
        .open           = tracing_open_generic,
        .read           = tracing_cpumask_read,
        .write          = tracing_cpumask_write,
@@ -2134,7 +2214,7 @@ tracing_trace_options_write(struct file *filp, const char __user *ubuf,
        return cnt;
 }
 
-static struct file_operations tracing_iter_fops = {
+static const struct file_operations tracing_iter_fops = {
        .open           = tracing_open_generic,
        .read           = tracing_trace_options_read,
        .write          = tracing_trace_options_write,
@@ -2167,7 +2247,7 @@ tracing_readme_read(struct file *filp, char __user *ubuf,
                                        readme_msg, strlen(readme_msg));
 }
 
-static struct file_operations tracing_readme_fops = {
+static const struct file_operations tracing_readme_fops = {
        .open           = tracing_open_generic,
        .read           = tracing_readme_read,
 };
@@ -2250,6 +2330,75 @@ int tracer_init(struct tracer *t, struct trace_array *tr)
        return t->init(tr);
 }
 
+static int tracing_resize_ring_buffer(unsigned long size)
+{
+       int ret;
+
+       /*
+        * If kernel or user changes the size of the ring buffer
+        * we use the size that was given, and we can forget about
+        * expanding it later.
+        */
+       ring_buffer_expanded = 1;
+
+       ret = ring_buffer_resize(global_trace.buffer, size);
+       if (ret < 0)
+               return ret;
+
+       ret = ring_buffer_resize(max_tr.buffer, size);
+       if (ret < 0) {
+               int r;
+
+               r = ring_buffer_resize(global_trace.buffer,
+                                      global_trace.entries);
+               if (r < 0) {
+                       /*
+                        * AARGH! We are left with different
+                        * size max buffer!!!!
+                        * The max buffer is our "snapshot" buffer.
+                        * When a tracer needs a snapshot (one of the
+                        * latency tracers), it swaps the max buffer
+                        * with the saved snap shot. We succeeded to
+                        * update the size of the main buffer, but failed to
+                        * update the size of the max buffer. But when we tried
+                        * to reset the main buffer to the original size, we
+                        * failed there too. This is very unlikely to
+                        * happen, but if it does, warn and kill all
+                        * tracing.
+                        */
+                       WARN_ON(1);
+                       tracing_disabled = 1;
+               }
+               return ret;
+       }
+
+       global_trace.entries = size;
+
+       return ret;
+}
+
+/**
+ * tracing_update_buffers - used by tracing facility to expand ring buffers
+ *
+ * To save on memory when the tracing is never used on a system with it
+ * configured in. The ring buffers are set to a minimum size. But once
+ * a user starts to use the tracing facility, then they need to grow
+ * to their default size.
+ *
+ * This function is to be called when a tracer is about to be used.
+ */
+int tracing_update_buffers(void)
+{
+       int ret = 0;
+
+       mutex_lock(&trace_types_lock);
+       if (!ring_buffer_expanded)
+               ret = tracing_resize_ring_buffer(trace_buf_size);
+       mutex_unlock(&trace_types_lock);
+
+       return ret;
+}
+
 struct trace_option_dentry;
 
 static struct trace_option_dentry *
@@ -2266,6 +2415,14 @@ static int tracing_set_tracer(const char *buf)
        int ret = 0;
 
        mutex_lock(&trace_types_lock);
+
+       if (!ring_buffer_expanded) {
+               ret = tracing_resize_ring_buffer(trace_buf_size);
+               if (ret < 0)
+                       return ret;
+               ret = 0;
+       }
+
        for (t = trace_types; t; t = t->next) {
                if (strcmp(t->name, buf) == 0)
                        break;
@@ -2838,28 +2995,11 @@ tracing_entries_write(struct file *filp, const char __user *ubuf,
        val <<= 10;
 
        if (val != global_trace.entries) {
-               ret = ring_buffer_resize(global_trace.buffer, val);
+               ret = tracing_resize_ring_buffer(val);
                if (ret < 0) {
                        cnt = ret;
                        goto out;
                }
-
-               ret = ring_buffer_resize(max_tr.buffer, val);
-               if (ret < 0) {
-                       int r;
-                       cnt = ret;
-                       r = ring_buffer_resize(global_trace.buffer,
-                                              global_trace.entries);
-                       if (r < 0) {
-                               /* AARGH! We are left with different
-                                * size max buffer!!!! */
-                               WARN_ON(1);
-                               tracing_disabled = 1;
-                       }
-                       goto out;
-               }
-
-               global_trace.entries = val;
        }
 
        filp->f_pos += cnt;
@@ -2927,25 +3067,25 @@ tracing_mark_write(struct file *filp, const char __user *ubuf,
        return cnt;
 }
 
-static struct file_operations tracing_max_lat_fops = {
+static const struct file_operations tracing_max_lat_fops = {
        .open           = tracing_open_generic,
        .read           = tracing_max_lat_read,
        .write          = tracing_max_lat_write,
 };
 
-static struct file_operations tracing_ctrl_fops = {
+static const struct file_operations tracing_ctrl_fops = {
        .open           = tracing_open_generic,
        .read           = tracing_ctrl_read,
        .write          = tracing_ctrl_write,
 };
 
-static struct file_operations set_tracer_fops = {
+static const struct file_operations set_tracer_fops = {
        .open           = tracing_open_generic,
        .read           = tracing_set_trace_read,
        .write          = tracing_set_trace_write,
 };
 
-static struct file_operations tracing_pipe_fops = {
+static const struct file_operations tracing_pipe_fops = {
        .open           = tracing_open_pipe,
        .poll           = tracing_poll_pipe,
        .read           = tracing_read_pipe,
@@ -2953,13 +3093,13 @@ static struct file_operations tracing_pipe_fops = {
        .release        = tracing_release_pipe,
 };
 
-static struct file_operations tracing_entries_fops = {
+static const struct file_operations tracing_entries_fops = {
        .open           = tracing_open_generic,
        .read           = tracing_entries_read,
        .write          = tracing_entries_write,
 };
 
-static struct file_operations tracing_mark_fops = {
+static const struct file_operations tracing_mark_fops = {
        .open           = tracing_open_generic,
        .write          = tracing_mark_write,
 };
@@ -3240,7 +3380,7 @@ tracing_read_dyn_info(struct file *filp, char __user *ubuf,
        return r;
 }
 
-static struct file_operations tracing_dyn_info_fops = {
+static const struct file_operations tracing_dyn_info_fops = {
        .open           = tracing_open_generic,
        .read           = tracing_read_dyn_info,
 };
@@ -3714,84 +3854,6 @@ static __init int tracer_init_debugfs(void)
        return 0;
 }
 
-int trace_vprintk(unsigned long ip, int depth, const char *fmt, va_list args)
-{
-       static raw_spinlock_t trace_buf_lock = __RAW_SPIN_LOCK_UNLOCKED;
-       static char trace_buf[TRACE_BUF_SIZE];
-
-       struct ring_buffer_event *event;
-       struct trace_array *tr = &global_trace;
-       struct trace_array_cpu *data;
-       int cpu, len = 0, size, pc;
-       struct print_entry *entry;
-       unsigned long irq_flags;
-
-       if (tracing_disabled || tracing_selftest_running)
-               return 0;
-
-       pc = preempt_count();
-       preempt_disable_notrace();
-       cpu = raw_smp_processor_id();
-       data = tr->data[cpu];
-
-       if (unlikely(atomic_read(&data->disabled)))
-               goto out;
-
-       pause_graph_tracing();
-       raw_local_irq_save(irq_flags);
-       __raw_spin_lock(&trace_buf_lock);
-       len = vsnprintf(trace_buf, TRACE_BUF_SIZE, fmt, args);
-
-       len = min(len, TRACE_BUF_SIZE-1);
-       trace_buf[len] = 0;
-
-       size = sizeof(*entry) + len + 1;
-       event = trace_buffer_lock_reserve(tr, TRACE_PRINT, size, irq_flags, pc);
-       if (!event)
-               goto out_unlock;
-       entry = ring_buffer_event_data(event);
-       entry->ip                       = ip;
-       entry->depth                    = depth;
-
-       memcpy(&entry->buf, trace_buf, len);
-       entry->buf[len] = 0;
-       ring_buffer_unlock_commit(tr->buffer, event);
-
- out_unlock:
-       __raw_spin_unlock(&trace_buf_lock);
-       raw_local_irq_restore(irq_flags);
-       unpause_graph_tracing();
- out:
-       preempt_enable_notrace();
-
-       return len;
-}
-EXPORT_SYMBOL_GPL(trace_vprintk);
-
-int __trace_printk(unsigned long ip, const char *fmt, ...)
-{
-       int ret;
-       va_list ap;
-
-       if (!(trace_flags & TRACE_ITER_PRINTK))
-               return 0;
-
-       va_start(ap, fmt);
-       ret = trace_vprintk(ip, task_curr_ret_stack(current), fmt, ap);
-       va_end(ap);
-       return ret;
-}
-EXPORT_SYMBOL_GPL(__trace_printk);
-
-int __ftrace_vprintk(unsigned long ip, const char *fmt, va_list ap)
-{
-       if (!(trace_flags & TRACE_ITER_PRINTK))
-               return 0;
-
-       return trace_vprintk(ip, task_curr_ret_stack(current), fmt, ap);
-}
-EXPORT_SYMBOL_GPL(__ftrace_vprintk);
-
 static int trace_panic_handler(struct notifier_block *this,
                               unsigned long event, void *unused)
 {
@@ -3929,6 +3991,7 @@ void ftrace_dump(void)
 __init static int tracer_alloc_buffers(void)
 {
        struct trace_array_cpu *data;
+       int ring_buf_size;
        int i;
        int ret = -ENOMEM;
 
@@ -3941,12 +4004,18 @@ __init static int tracer_alloc_buffers(void)
        if (!alloc_cpumask_var(&tracing_reader_cpumask, GFP_KERNEL))
                goto out_free_tracing_cpumask;
 
+       /* To save memory, keep the ring buffer size to its minimum */
+       if (ring_buffer_expanded)
+               ring_buf_size = trace_buf_size;
+       else
+               ring_buf_size = 1;
+
        cpumask_copy(tracing_buffer_mask, cpu_possible_mask);
        cpumask_copy(tracing_cpumask, cpu_all_mask);
        cpumask_clear(tracing_reader_cpumask);
 
        /* TODO: make the number of buffers hot pluggable with CPUS */
-       global_trace.buffer = ring_buffer_alloc(trace_buf_size,
+       global_trace.buffer = ring_buffer_alloc(ring_buf_size,
                                                   TRACE_BUFFER_FLAGS);
        if (!global_trace.buffer) {
                printk(KERN_ERR "tracer: failed to allocate ring buffer!\n");
@@ -3957,7 +4026,7 @@ __init static int tracer_alloc_buffers(void)
 
 
 #ifdef CONFIG_TRACER_MAX_TRACE
-       max_tr.buffer = ring_buffer_alloc(trace_buf_size,
+       max_tr.buffer = ring_buffer_alloc(ring_buf_size,
                                             TRACE_BUFFER_FLAGS);
        if (!max_tr.buffer) {
                printk(KERN_ERR "tracer: failed to allocate max ring buffer!\n");