From 9c67dc50afb2eaa1c3966ee73fac3ce55935556c Mon Sep 17 00:00:00 2001 From: Pierre-Marc Fournier Date: Mon, 16 Feb 2009 14:54:28 -0500 Subject: [PATCH] ust: generate traces readable in lttv --- hello/Makefile | 5 +- hello/hello.c | 220 +++++++++++++++++++++--------------------- hello/serialize.c | 1 + libmarkers/Makefile | 2 +- libmarkers/marker.c | 83 ++++++++-------- libtracing/channels.c | 2 + libtracing/relay.c | 35 +------ libtracing/relay.h | 37 +++++++ libtracing/tracer.c | 4 +- libtracing/tracer.h | 9 +- share/kernelcompat.h | 8 +- 11 files changed, 213 insertions(+), 193 deletions(-) diff --git a/hello/Makefile b/hello/Makefile index 2eee1152..eeb43fdb 100644 --- a/hello/Makefile +++ b/hello/Makefile @@ -1,7 +1,10 @@ all: hello hello: hello.c - gcc -g -I../libmarkers -I../share -I../libtracing -L../libmarkers -lmarkers -L../libtracectl -ltracectl -L../libtracing -ltracing -o hello hello.c marker-control.c serialize.c +#dynamic version +# gcc -g -I../libmarkers -I../share -I../libtracing -L../libmarkers -lmarkers -L../libtracectl -ltracectl -L../libtracing -ltracing -o hello hello.c marker-control.c serialize.c -static +#static version + gcc -g -I../libmarkers -I../share -I../libtracing -L../libmarkers -o hello hello.c marker-control.c serialize.c ../libtracing/*.c ../libmarkers/*.c ../libtracectl/*.c ../share/*.c clean: rm -rf hello *.o diff --git a/hello/hello.c b/hello/hello.c index 1c97db93..2e74505c 100644 --- a/hello/hello.c +++ b/hello/hello.c @@ -1,11 +1,106 @@ #include #include #include +#include +#include +#include +#include #include "../libmarkers/marker.h" #include "usterr.h" #include "tracer.h" #include "marker-control.h" +#include "relay.h" + + +char consumer_stack[10000]; +char trace_name[] = "theusttrace"; +char trace_type[] = "ustrelay"; + +#define CPRINTF(fmt, args...) safe_printf(fmt "\n", ## args) + +int safe_printf(const char *fmt, ...) +{ + static char buf[500]; + va_list ap; + int n; + + va_start(ap, fmt); + + n = vsnprintf(buf, sizeof(buf), fmt, ap); + + write(STDOUT_FILENO, buf, n); + + va_end(ap); +} + +int consumer(void *arg) +{ + int result; + + int fd; + + char str[] = "Hello, this is the consumer.\n"; + + struct ltt_trace_struct *trace; + + ltt_lock_traces(); + trace = _ltt_trace_find(trace_name); + ltt_unlock_traces(); + + if(trace == NULL) { + CPRINTF("cannot find trace!"); + return 1; + } + + CPRINTF("consumer: got a trace: %s with %d channels\n", trace_name, trace->nr_channels); + + struct ltt_channel_struct *chan = &trace->channels[0]; + + CPRINTF("channel 1 (%s) active=%u", chan->channel_name, chan->active & 1); + + struct rchan *rchan = chan->trans_channel_data; + struct rchan_buf *rbuf = rchan->buf; + struct ltt_channel_buf_struct *lttbuf = chan->buf; + long consumed_old; + + result = fd = open("trace.out", O_WRONLY | O_CREAT | O_TRUNC, 00644); + if(result == -1) { + perror("open"); + return -1; + } + + for(;;) { + write(STDOUT_FILENO, str, sizeof(str)); + + result = ltt_do_get_subbuf(rbuf, lttbuf, &consumed_old); + if(result < 0) { + CPRINTF("ltt_do_get_subbuf: error: %s", strerror(-result)); + } + else { + CPRINTF("success!"); + + result = write(fd, rbuf->buf_data + (consumed_old & (2 * 4096-1)), 4096); + ltt_do_put_subbuf(rbuf, lttbuf, consumed_old); + } + + //CPRINTF("There seems to be %ld bytes available", SUBBUF_TRUNC(local_read(<tbuf->offset), rbuf->chan) - consumed_old); + CPRINTF("Commit count %ld", local_read(<tbuf->commit_count[0])); + + + sleep(1); + } +} + +void start_consumer(void) +{ + int result; + + result = clone(consumer, consumer_stack+sizeof(consumer_stack)-1, CLONE_FS | CLONE_FILES | CLONE_VM, NULL); + if(result == -1) { + perror("clone"); + } +} void probe(const struct marker *mdata, void *probe_private, void *call_private, @@ -14,23 +109,6 @@ void probe(const struct marker *mdata, printf("In probe\n"); } -//ust// void try_map() -//ust// { -//ust// char *m; -//ust// -//ust// /* maybe add MAP_LOCKED */ -//ust// m = mmap(NULL, 4096, PROT_WRITE, MAP_PRIVATE | MAP_ANONYMOUS | MAP_POPULATE , -1, 0); -//ust// if(m == (char*)-1) { -//ust// perror("mmap"); -//ust// return; -//ust// } -//ust// -//ust// printf("The mapping is at %p.\n", m); -//ust// strcpy(m, "Hello, Mapping!"); -//ust// } - -//sig_atomic_t must_quit; - void inthandler(int sig) { printf("in handler\n"); @@ -63,85 +141,6 @@ int init_int_handler(void) return 0; } -//ust// DEFINE_MUTEX(probes_mutex); -//ust// -//ust// static LIST_HEAD(probes_registered_list); -//ust// -//ust// int ltt_marker_connect(const char *channel, const char *mname, -//ust// const char *pname) -//ust// -//ust// { -//ust// int ret; -//ust// struct ltt_active_marker *pdata; -//ust// struct ltt_available_probe *probe; -//ust// -//ust// ltt_lock_traces(); -//ust// mutex_lock(&probes_mutex); -//ust// probe = get_probe_from_name(pname); -//ust// if (!probe) { -//ust// ret = -ENOENT; -//ust// goto end; -//ust// } -//ust// pdata = marker_get_private_data(channel, mname, probe->probe_func, 0); -//ust// if (pdata && !IS_ERR(pdata)) { -//ust// ret = -EEXIST; -//ust// goto end; -//ust// } -//ust// pdata = kmem_cache_zalloc(markers_loaded_cachep, GFP_KERNEL); -//ust// if (!pdata) { -//ust// ret = -ENOMEM; -//ust// goto end; -//ust// } -//ust// pdata->probe = probe; -//ust// /* -//ust// * ID has priority over channel in case of conflict. -//ust// */ -//ust// ret = marker_probe_register(channel, mname, NULL, -//ust// probe->probe_func, pdata); -//ust// if (ret) -//ust// kmem_cache_free(markers_loaded_cachep, pdata); -//ust// else -//ust// list_add(&pdata->node, &markers_loaded_list); -//ust// end: -//ust// mutex_unlock(&probes_mutex); -//ust// ltt_unlock_traces(); -//ust// return ret; -//ust// } -//ust// -//ust// -//ust// int ltt_probe_register(struct ltt_available_probe *pdata) -//ust// { -//ust// int ret = 0; -//ust// int comparison; -//ust// struct ltt_available_probe *iter; -//ust// -//ust// mutex_lock(&probes_mutex); -//ust// list_for_each_entry_reverse(iter, &probes_registered_list, node) { -//ust// comparison = strcmp(pdata->name, iter->name); -//ust// if (!comparison) { -//ust// ret = -EBUSY; -//ust// goto end; -//ust// } else if (comparison > 0) { -//ust// /* We belong to the location right after iter. */ -//ust// list_add(&pdata->node, &iter->node); -//ust// goto end; -//ust// } -//ust// } -//ust// /* Should be added at the head of the list */ -//ust// list_add(&pdata->node, &probes_registered_list); -//ust// end: -//ust// mutex_unlock(&probes_mutex); -//ust// return ret; -//ust// } -//ust// -//ust// -//ust// struct ltt_available_probe default_probe = { -//ust// .name = "default", -//ust// .format = NULL, -//ust// .probe_func = ltt_vtrace, -//ust// .callbacks[0] = ltt_serialize_data, -//ust// }; - int main() { int result; @@ -152,20 +151,17 @@ int main() printf("page size is %d\n", sysconf(_SC_PAGE_SIZE)); - char trace_name[] = "theusttrace"; - char trace_type[] = "ustrelay"; - marker_control_init(); - marker_probe_register("abc", "testmark", "", probe, NULL); - marker_probe_register("metadata", "core_marker_id", "channel %s name %s event_id %hu int #1u%zu long #1u%zu pointer #1u%zu size_t #1u%zu alignment #1u%u", probe, NULL); + //marker_probe_register("abc", "testmark", "", probe, NULL); +//ust// marker_probe_register("metadata", "core_marker_id", "channel %s name %s event_id %hu int #1u%zu long #1u%zu pointer #1u%zu size_t #1u%zu alignment #1u%u", probe, NULL); //ust// result = ltt_probe_register(&default_probe); //ust// if(result) //ust// ERR("ltt_probe_register"); - result = ltt_marker_connect("abc", "testmark2", "default"); - if(result) - ERR("ltt_marker_connect"); + //result = ltt_marker_connect("metadata", "testev", "default"); + //if(result) + // ERR("ltt_marker_connect"); result = ltt_trace_setup(trace_name); @@ -192,13 +188,21 @@ int main() return 1; } - + start_consumer(); printf("Hello, World!\n"); + sleep(1); for(;;) { - trace_mark(abc, testmark, "", MARK_NOARGS); - trace_mark(abc, testmark2, "", MARK_NOARGS); - sleep(1); + //trace_mark(abc, testmark, "", MARK_NOARGS); + //trace_mark(metadata, testev, "", MARK_NOARGS); + trace_mark(metadata, core_marker_id, + "channel %s name %s event_id %hu " + "int #1u%zu long #1u%zu pointer #1u%zu " + "size_t #1u%zu alignment #1u%u", + "abc", "def", (unsigned short)1000, + sizeof(int), sizeof(long), sizeof(void *), + sizeof(size_t), ltt_get_alignment()); + usleep(100000); } scanf("%*s"); diff --git a/hello/serialize.c b/hello/serialize.c index fd636822..26d4c478 100644 --- a/hello/serialize.c +++ b/hello/serialize.c @@ -672,6 +672,7 @@ notrace void ltt_vtrace(const struct marker *mdata, void *probe_data, /* Out-of-order commit */ ltt_commit_slot(channel, &transport_data, buf_offset, slot_size); + printf("just commited event at offset %d and size %d\n", buf_offset, slot_size); } //ust// __get_cpu_var(ltt_nesting)--; ltt_nesting--; diff --git a/libmarkers/Makefile b/libmarkers/Makefile index d4f8ecda..d3729f8f 100644 --- a/libmarkers/Makefile +++ b/libmarkers/Makefile @@ -1,6 +1,6 @@ all: libmarkers.so libmarkers.so: marker.c *.c *.h - gcc -g -fPIC -I../share -I../libtracing -shared -o libmarkers.so marker.c ../share/kref.c ../libtracing/channels.c + gcc -g -fPIC -I../share -I../libtracing -I. -shared -o libmarkers.so marker.c ../share/kref.c ../libtracing/channels.c .PHONY: libmarkers.so all diff --git a/libmarkers/marker.c b/libmarkers/marker.c index f9f82fb0..980cf392 100644 --- a/libmarkers/marker.c +++ b/libmarkers/marker.c @@ -35,6 +35,7 @@ #include "usterr.h" #include "channels.h" #include "tracercore.h" +#include "tracer.h" extern struct marker __start___markers[]; extern struct marker __stop___markers[]; @@ -1031,7 +1032,7 @@ void *marker_get_private_data(const char *channel, const char *name, //ust// } //ust// } -#ifdef CONFIG_MODULES +//ust//#ifdef CONFIG_MODULES /** * marker_get_iter_range - Get a next marker iterator given a range. @@ -1067,7 +1068,7 @@ static void marker_get_iter(struct marker_iter *iter) goto end; } /* Markers in modules. */ - found = module_get_iter_markers(iter); +//ust// found = module_get_iter_markers(iter); end: if (!found) marker_iter_reset(iter); @@ -1338,7 +1339,7 @@ int is_marker_enabled(const char *channel, const char *name) return entry && !!entry->refcount; } -#endif +//ust// #endif int marker_module_notify(struct notifier_block *self, unsigned long val, void *data) @@ -1372,42 +1373,42 @@ struct notifier_block marker_module_nb = { #endif /* CONFIG_MODULES */ -//ust// void ltt_dump_marker_state(struct ltt_trace_struct *trace) -//ust// { -//ust// struct marker_iter iter; -//ust// struct ltt_probe_private_data call_data; -//ust// const char *channel; -//ust// -//ust// call_data.trace = trace; -//ust// call_data.serializer = NULL; -//ust// -//ust// marker_iter_reset(&iter); -//ust// marker_iter_start(&iter); -//ust// for (; iter.marker != NULL; marker_iter_next(&iter)) { -//ust// if (!_imv_read(iter.marker->state)) -//ust// continue; -//ust// channel = ltt_channels_get_name_from_index( -//ust// iter.marker->channel_id); -//ust// __trace_mark(0, metadata, core_marker_id, -//ust// &call_data, -//ust// "channel %s name %s event_id %hu " -//ust// "int #1u%zu long #1u%zu pointer #1u%zu " -//ust// "size_t #1u%zu alignment #1u%u", -//ust// channel, -//ust// iter.marker->name, -//ust// iter.marker->event_id, -//ust// sizeof(int), sizeof(long), -//ust// sizeof(void *), sizeof(size_t), -//ust// ltt_get_alignment()); -//ust// if (iter.marker->format) -//ust// __trace_mark(0, metadata, -//ust// core_marker_format, -//ust// &call_data, -//ust// "channel %s name %s format %s", -//ust// channel, -//ust// iter.marker->name, -//ust// iter.marker->format); -//ust// } -//ust// marker_iter_stop(&iter); -//ust// } +void ltt_dump_marker_state(struct ltt_trace_struct *trace) +{ + struct marker_iter iter; + struct ltt_probe_private_data call_data; + const char *channel; + + call_data.trace = trace; + call_data.serializer = NULL; + + marker_iter_reset(&iter); + marker_iter_start(&iter); + for (; iter.marker != NULL; marker_iter_next(&iter)) { + if (!_imv_read(iter.marker->state)) + continue; + channel = ltt_channels_get_name_from_index( + iter.marker->channel_id); + __trace_mark(0, metadata, core_marker_id, + &call_data, + "channel %s name %s event_id %hu " + "int #1u%zu long #1u%zu pointer #1u%zu " + "size_t #1u%zu alignment #1u%u", + channel, + iter.marker->name, + iter.marker->event_id, + sizeof(int), sizeof(long), + sizeof(void *), sizeof(size_t), + ltt_get_alignment()); + if (iter.marker->format) + __trace_mark(0, metadata, + core_marker_format, + &call_data, + "channel %s name %s format %s", + channel, + iter.marker->name, + iter.marker->format); + } + marker_iter_stop(&iter); +} //ust// EXPORT_SYMBOL_GPL(ltt_dump_marker_state); diff --git a/libtracing/channels.c b/libtracing/channels.c index fc0db8ea..a8df3c48 100644 --- a/libtracing/channels.c +++ b/libtracing/channels.c @@ -311,6 +311,8 @@ int _ltt_channels_get_event_id(const char *channel, const char *name) ret = 0; else if (strcmp(name, "core_marker_format") == 0) ret = 1; + else if (strcmp(name, "testev") == 0) + ret = 2; else ret = -ENOENT; goto end; diff --git a/libtracing/relay.c b/libtracing/relay.c index d78fa72a..0f503a89 100644 --- a/libtracing/relay.c +++ b/libtracing/relay.c @@ -748,37 +748,6 @@ void *ltt_relay_offset_address(struct rchan_buf *buf, size_t offset) #define printk_dbg(fmt, args...) #endif -/* LTTng lockless logging buffer info */ -struct ltt_channel_buf_struct { - /* First 32 bytes cache-hot cacheline */ - local_t offset; /* Current offset in the buffer */ - local_t *commit_count; /* Commit count per sub-buffer */ - atomic_long_t consumed; /* - * Current offset in the buffer - * standard atomic access (shared) - */ - unsigned long last_tsc; /* - * Last timestamp written in the buffer. - */ - /* End of first 32 bytes cacheline */ - atomic_long_t active_readers; /* - * Active readers count - * standard atomic access (shared) - */ - local_t events_lost; - local_t corrupted_subbuffers; - spinlock_t full_lock; /* - * buffer full condition spinlock, only - * for userspace tracing blocking mode - * synchronization with reader. - */ -//ust// wait_queue_head_t write_wait; /* -//ust// * Wait queue for blocking user space -//ust// * writers -//ust// */ - atomic_t wakeup_readers; /* Boolean : wakeup readers waiting ? */ -} ____cacheline_aligned; - /* * Last TSC comparison functions. Check if the current TSC overflows * LTT_TSC_BITS bits from the last TSC read. Reads and writes last_tsc @@ -1041,7 +1010,7 @@ static notrace void ltt_buf_unfull(struct rchan_buf *buf, //ust// return mask; //ust// } -static int ltt_do_get_subbuf(struct rchan_buf *buf, struct ltt_channel_buf_struct *ltt_buf, long *pconsumed_old) +int ltt_do_get_subbuf(struct rchan_buf *buf, struct ltt_channel_buf_struct *ltt_buf, long *pconsumed_old) { struct ltt_channel_struct *ltt_channel = (struct ltt_channel_struct *)buf->chan->private_data; long consumed_old, consumed_idx, commit_count, write_offset; @@ -1081,7 +1050,7 @@ static int ltt_do_get_subbuf(struct rchan_buf *buf, struct ltt_channel_buf_struc return 0; } -static int ltt_do_put_subbuf(struct rchan_buf *buf, struct ltt_channel_buf_struct *ltt_buf, u32 uconsumed_old) +int ltt_do_put_subbuf(struct rchan_buf *buf, struct ltt_channel_buf_struct *ltt_buf, u32 uconsumed_old) { long consumed_new, consumed_old; diff --git a/libtracing/relay.h b/libtracing/relay.h index 47ebfd13..54bd2b9e 100644 --- a/libtracing/relay.h +++ b/libtracing/relay.h @@ -314,5 +314,42 @@ extern void ltt_relay_close(struct rchan *chan); */ extern const struct file_operations ltt_relay_file_operations; + +/* LTTng lockless logging buffer info */ +struct ltt_channel_buf_struct { + /* First 32 bytes cache-hot cacheline */ + local_t offset; /* Current offset in the buffer */ + local_t *commit_count; /* Commit count per sub-buffer */ + atomic_long_t consumed; /* + * Current offset in the buffer + * standard atomic access (shared) + */ + unsigned long last_tsc; /* + * Last timestamp written in the buffer. + */ + /* End of first 32 bytes cacheline */ + atomic_long_t active_readers; /* + * Active readers count + * standard atomic access (shared) + */ + local_t events_lost; + local_t corrupted_subbuffers; + spinlock_t full_lock; /* + * buffer full condition spinlock, only + * for userspace tracing blocking mode + * synchronization with reader. + */ +//ust// wait_queue_head_t write_wait; /* +//ust// * Wait queue for blocking user space +//ust// * writers +//ust// */ + atomic_t wakeup_readers; /* Boolean : wakeup readers waiting ? */ +} ____cacheline_aligned; + +int ltt_do_get_subbuf(struct rchan_buf *buf, struct ltt_channel_buf_struct *ltt_buf, long *pconsumed_old); + +int ltt_do_put_subbuf(struct rchan_buf *buf, struct ltt_channel_buf_struct *ltt_buf, u32 uconsumed_old); + + #endif /* _LINUX_LTT_RELAY_H */ diff --git a/libtracing/tracer.c b/libtracing/tracer.c index 8c7000d3..81c29251 100644 --- a/libtracing/tracer.c +++ b/libtracing/tracer.c @@ -324,7 +324,7 @@ static void trace_async_wakeup(struct ltt_trace_struct *trace) * * Returns a pointer to the trace structure, NULL if not found. */ -static struct ltt_trace_struct *_ltt_trace_find(const char *trace_name) +struct ltt_trace_struct *_ltt_trace_find(const char *trace_name) { struct ltt_trace_struct *trace; @@ -956,7 +956,7 @@ int ltt_trace_start(const char *trace_name) * directly using this trace handle inside the logging function. */ -//ust// ltt_dump_marker_state(trace); + ltt_dump_marker_state(trace); //ust// if (!try_module_get(ltt_statedump_owner)) { //ust// err = -ENODEV; diff --git a/libtracing/tracer.h b/libtracing/tracer.h index e9418c4c..e39947f0 100644 --- a/libtracing/tracer.h +++ b/libtracing/tracer.h @@ -547,11 +547,14 @@ static inline void ltt_commit_slot( #define LTT_FLIGHT_PREFIX "flight-" /* Tracer properties */ -#define LTT_DEFAULT_SUBBUF_SIZE_LOW 65536 +//#define LTT_DEFAULT_SUBBUF_SIZE_LOW 65536 +#define LTT_DEFAULT_SUBBUF_SIZE_LOW 4096 #define LTT_DEFAULT_N_SUBBUFS_LOW 2 -#define LTT_DEFAULT_SUBBUF_SIZE_MED 262144 +//#define LTT_DEFAULT_SUBBUF_SIZE_MED 262144 +#define LTT_DEFAULT_SUBBUF_SIZE_MED 4096 #define LTT_DEFAULT_N_SUBBUFS_MED 2 -#define LTT_DEFAULT_SUBBUF_SIZE_HIGH 1048576 +//#define LTT_DEFAULT_SUBBUF_SIZE_HIGH 1048576 +#define LTT_DEFAULT_SUBBUF_SIZE_HIGH 4096 #define LTT_DEFAULT_N_SUBBUFS_HIGH 2 #define LTT_TRACER_MAGIC_NUMBER 0x00D6B7ED #define LTT_TRACER_VERSION_MAJOR 2 diff --git a/share/kernelcompat.h b/share/kernelcompat.h index b442718e..ee676deb 100644 --- a/share/kernelcompat.h +++ b/share/kernelcompat.h @@ -159,25 +159,25 @@ static inline unsigned long __cmpxchg(volatile void *ptr, unsigned long old, unsigned long prev; switch (size) { case 1: - asm volatile("lock cmpxchgb %b1,%2" + asm volatile("lock; cmpxchgb %b1,%2" : "=a"(prev) : "q"(new), "m"(*__xg(ptr)), "0"(old) : "memory"); return prev; case 2: - asm volatile("lock cmpxchgw %w1,%2" + asm volatile("lock; cmpxchgw %w1,%2" : "=a"(prev) : "r"(new), "m"(*__xg(ptr)), "0"(old) : "memory"); return prev; case 4: - asm volatile("lock cmpxchgl %k1,%2" + asm volatile("lock; cmpxchgl %k1,%2" : "=a"(prev) : "r"(new), "m"(*__xg(ptr)), "0"(old) : "memory"); return prev; case 8: - asm volatile("lock cmpxchgq %1,%2" + asm volatile("lock; cmpxchgq %1,%2" : "=a"(prev) : "r"(new), "m"(*__xg(ptr)), "0"(old) : "memory"); -- 2.34.1