I noticed while using the streaming infrastructure in trace-cmd that I was
seemingly missing events. Using other tracing methods I got these events and
record->missed_events was never being set. This is because the streaming
infrastructure uses blocking reads on the per cpu trace pipe's, which means
we'll wait for an entire pages worth of data to be ready before passing it along
to the recorder. This makes it impossible to do long term tracing that requires
coupling two different events that could occur on different CPU's, and I imagine
it has been what is screwing up my trace-cmd profile runs on our giant 40 cpu
boxes. Fix trace-cmd instead to use a nonblocking read with select to wait for
data on the pipe so we don't burn CPU unnecessarily. With this patch I'm no
longer seeing missed events in my app. Thanks,
Signed-off-by: Josef Bacik <[email protected]>
---
trace-cmd.h | 1 +
trace-record.c | 9 +++++++--
trace-recorder.c | 30 ++++++++++++++++++++++++++++++
3 files changed, 38 insertions(+), 2 deletions(-)
diff --git a/trace-cmd.h b/trace-cmd.h
index 3a230b4..c94f784 100644
--- a/trace-cmd.h
+++ b/trace-cmd.h
@@ -282,6 +282,7 @@ struct tracecmd_recorder *tracecmd_create_buffer_recorder(const char *file, int
struct tracecmd_recorder *tracecmd_create_buffer_recorder_maxkb(const char *file, int cpu, unsigned flags, const char *buffer, int maxkb);
int tracecmd_start_recording(struct tracecmd_recorder *recorder, unsigned long sleep);
+long tracecmd_stream_recording(struct tracecmd_recorder *recorder, unsigned long sleep);
void tracecmd_stop_recording(struct tracecmd_recorder *recorder);
void tracecmd_stat_cpu(struct trace_seq *s, int cpu);
long tracecmd_flush_recording(struct tracecmd_recorder *recorder);
diff --git a/trace-record.c b/trace-record.c
index 49a8280..7981932 100644
--- a/trace-record.c
+++ b/trace-record.c
@@ -2450,8 +2450,13 @@ static int create_recorder(struct buffer_instance *instance, int cpu,
}
while (!finished) {
- if (tracecmd_start_recording(recorder, sleep_time) < 0)
- break;
+ if (type == TRACE_TYPE_STREAM) {
+ if (tracecmd_stream_recording(recorder, sleep_time) < 0)
+ break;
+ } else {
+ if (tracecmd_start_recording(recorder, sleep_time) < 0)
+ break;
+ }
}
tracecmd_free_recorder(recorder);
diff --git a/trace-recorder.c b/trace-recorder.c
index 16d1be0..13e2e9f 100644
--- a/trace-recorder.c
+++ b/trace-recorder.c
@@ -440,6 +440,36 @@ long tracecmd_flush_recording(struct tracecmd_recorder *recorder)
return total;
}
+#define USECS_IN_SEC 1000000UL
+long tracecmd_stream_recording(struct tracecmd_recorder *recorder, unsigned long sleep)
+{
+ static int nonblock = 0;
+ fd_set rfds;
+ struct timeval tv;
+ long total = 0;
+ long ret;
+
+ if (!nonblock)
+ set_nonblock(recorder);
+
+ FD_ZERO(&rfds);
+ FD_SET(recorder->trace_fd, &rfds);
+ tv.tv_sec = sleep / USECS_IN_SEC;
+ tv.tv_usec = sleep % USECS_IN_SEC;
+ ret = select(FD_SETSIZE, &rfds, NULL, NULL, &tv);
+ if (ret <= 0)
+ return 0;
+
+ do {
+ ret = read_data(recorder);
+ if (ret < 0)
+ return ret;
+ total += ret;
+ } while (ret);
+
+ return total;
+}
+
int tracecmd_start_recording(struct tracecmd_recorder *recorder, unsigned long sleep)
{
struct timespec req;
--
2.5.0