Author: Armin Rigo <[email protected]>
Branch: c7-full-profiling
Changeset: r1450:8f88cdb1d916
Date: 2014-10-04 17:24 +0200
http://bitbucket.org/pypy/stmgc/changeset/8f88cdb1d916/
Log: Write the full to-disk profiling support here too
diff --git a/c7/stm/forksupport.c b/c7/stm/forksupport.c
--- a/c7/stm/forksupport.c
+++ b/c7/stm/forksupport.c
@@ -55,14 +55,12 @@
s_mutex_unlock();
bool was_in_transaction = _stm_in_transaction(this_tl);
- if (was_in_transaction) {
- stm_become_inevitable(this_tl, "fork");
- /* Note that the line above can still fail and abort, which should
- be fine */
- }
- else {
- stm_start_inevitable_transaction(this_tl);
- }
+ if (!was_in_transaction)
+ stm_start_transaction(this_tl);
+
+ stm_become_inevitable(this_tl, "fork");
+ /* Note that the line above can still fail and abort, which should
+ be fine */
s_mutex_lock();
synchronize_all_threads(STOP_OTHERS_UNTIL_MUTEX_UNLOCK);
@@ -203,6 +201,9 @@
just release these locks early */
s_mutex_unlock();
+ /* Open a new profiling file, if any */
+ forksupport_open_new_profiling_file();
+
/* Move the copy of the mmap over the old one, overwriting it
and thus freeing the old mapping in this process
*/
diff --git a/c7/stm/prof.c b/c7/stm/prof.c
new file mode 100644
--- /dev/null
+++ b/c7/stm/prof.c
@@ -0,0 +1,102 @@
+#include <time.h>
+
+
+static FILE *profiling_file;
+static char *profiling_basefn = NULL;
+static int (*profiling_expand_marker)(stm_loc_marker_t *, char *, int);
+
+
+static void _stm_profiling_event(stm_thread_local_t *tl,
+ enum stm_event_e event,
+ stm_loc_marker_t *markers)
+{
+ struct buf_s {
+ uint32_t tv_sec;
+ uint32_t tv_nsec;
+ uint32_t thread_num;
+ uint8_t event;
+ uint8_t marker_length[2];
+ char extra[256];
+ } __attribute__((packed));
+
+ struct buf_s buf;
+ struct timespec t;
+ clock_gettime(CLOCK_MONOTONIC, &t);
+ buf.tv_sec = t.tv_sec;
+ buf.tv_nsec = t.tv_nsec;
+ buf.thread_num = tl->thread_local_counter;
+ buf.event = event;
+
+ int len0 = 0;
+ int len1 = 0;
+ if (markers != NULL) {
+ if (markers[0].odd_number != 0)
+ len0 = profiling_expand_marker(&markers[0], buf.extra, 128);
+ if (markers[1].odd_number != 0)
+ len1 = profiling_expand_marker(&markers[1], buf.extra + len0, 128);
+ }
+ buf.marker_length[0] = len0;
+ buf.marker_length[1] = len1;
+
+ fwrite(&buf, offsetof(struct buf_s, extra) + len0 + len1,
+ 1, profiling_file);
+}
+
+static int default_expand_marker(stm_loc_marker_t *m, char *p, int s)
+{
+ *(uintptr_t *)p = m->odd_number;
+ return sizeof(uintptr_t);
+}
+
+static bool open_timing_log(const char *filename)
+{
+ profiling_file = fopen(filename, "w");
+ if (profiling_file == NULL)
+ return false;
+
+ fwrite("STMGC-C7-PROF01\n", 16, 1, profiling_file);
+ stmcb_timing_event = _stm_profiling_event;
+ return true;
+}
+
+static bool close_timing_log(void)
+{
+ if (stmcb_timing_event == &_stm_profiling_event) {
+ stmcb_timing_event = NULL;
+ fclose(profiling_file);
+ profiling_file = NULL;
+ return true;
+ }
+ return false;
+}
+
+static void forksupport_open_new_profiling_file(void)
+{
+ if (close_timing_log() && profiling_basefn != NULL) {
+ char filename[1024];
+ snprintf(filename, sizeof(filename),
+ "%s.fork%ld", profiling_basefn, (long)getpid());
+ open_timing_log(filename);
+ }
+}
+
+int stm_set_timing_log(const char *profiling_file_name,
+ int expand_marker(stm_loc_marker_t *, char *, int))
+{
+ close_timing_log();
+ free(profiling_basefn);
+ profiling_basefn = NULL;
+
+ if (profiling_file_name == NULL)
+ return 0;
+
+ if (!expand_marker)
+ expand_marker = default_expand_marker;
+ profiling_expand_marker = expand_marker;
+
+ if (!open_timing_log(profiling_file_name))
+ return -1;
+
+ profiling_basefn = strdup(profiling_file_name);
+ return 0;
+}
diff --git a/c7/stm/prof.h b/c7/stm/prof.h
new file mode 100644
--- /dev/null
+++ b/c7/stm/prof.h
@@ -0,0 +1,2 @@
+
+static void forksupport_open_new_profiling_file(void);
diff --git a/c7/stm/setup.c b/c7/stm/setup.c
--- a/c7/stm/setup.c
+++ b/c7/stm/setup.c
@@ -225,6 +225,8 @@
return (pthread_t *)(tl->creating_pthread);
}
+static int thread_local_counters = 0;
+
void stm_register_thread_local(stm_thread_local_t *tl)
{
int num;
@@ -247,6 +249,7 @@
numbers automatically. */
num = (num % NB_SEGMENTS) + 1;
tl->associated_segment_num = num;
+ tl->thread_local_counter = ++thread_local_counters;
*_get_cpth(tl) = pthread_self();
_init_shadow_stack(tl);
set_gs_register(get_segment_base(num));
diff --git a/c7/stmgc.c b/c7/stmgc.c
--- a/c7/stmgc.c
+++ b/c7/stmgc.c
@@ -15,6 +15,7 @@
#include "stm/fprintcolor.h"
#include "stm/weakref.h"
#include "stm/marker.h"
+#include "stm/prof.h"
#include "stm/misc.c"
#include "stm/list.c"
@@ -34,4 +35,5 @@
#include "stm/fprintcolor.c"
#include "stm/weakref.c"
#include "stm/marker.c"
+#include "stm/prof.c"
#include "stm/rewind_setjmp.c"
diff --git a/c7/stmgc.h b/c7/stmgc.h
--- a/c7/stmgc.h
+++ b/c7/stmgc.h
@@ -66,10 +66,11 @@
char *mem_clear_on_abort;
size_t mem_bytes_to_clear_on_abort;
/* after an abort, some details about the abort are stored there.
- (these fields are not modified on a successful commit) */
+ (this field is not modified on a successful commit) */
long last_abort__bytes_in_nursery;
/* the next fields are handled internally by the library */
int associated_segment_num;
+ int thread_local_counter;
struct stm_thread_local_s *prev, *next;
void *creating_pthread[2];
} stm_thread_local_t;
@@ -467,6 +468,17 @@
enum stm_event_e event,
stm_loc_marker_t *markers);
+/* Calling this sets up a stmcb_timing_event callback that will produce
+ a binary file calling 'profiling_file_name'. After a fork(), it is
+ written to 'profiling_file_name.fork<PID>'. Call it with NULL to
+ stop profiling. Returns -1 in case of error (see errno then).
+ The optional 'expand_marker' function pointer is called to expand
+ the marker's odd_number and object into data, starting at the given
+ position and with the given maximum length. */
+int stm_set_timing_log(const char *profiling_file_name,
+ int expand_marker(stm_loc_marker_t *, char *, int));
+
+
/* Convenience macros to push the markers into the shadowstack */
#define STM_PUSH_MARKER(tl, odd_num, p) do { \
uintptr_t _odd_num = (odd_num); \
@@ -492,8 +504,6 @@
_ss->ss = (object_t *)_odd_num; \
} while (0)
-char *_stm_expand_marker(void);
-
/* ==================== END ==================== */
diff --git a/c7/test/support.py b/c7/test/support.py
--- a/c7/test/support.py
+++ b/c7/test/support.py
@@ -152,6 +152,9 @@
stm_loc_marker_t *markers);
stmcb_timing_event_fn stmcb_timing_event;
+int stm_set_timing_log(const char *profiling_file_name,
+ int expand_marker(stm_loc_marker_t *, char *, int));
+
void stm_push_marker(stm_thread_local_t *, uintptr_t, object_t *);
void stm_update_marker_num(stm_thread_local_t *, uintptr_t);
void stm_pop_marker(stm_thread_local_t *);
diff --git a/c7/test/test_prof.py b/c7/test/test_prof.py
new file mode 100644
--- /dev/null
+++ b/c7/test/test_prof.py
@@ -0,0 +1,77 @@
+from support import *
+import py, os, struct
+
+udir = py.path.local.make_numbered_dir(prefix = 'stmgc-')
+
+
+def read_log(filename):
+ f = open(filename, 'rb')
+ header = f.read(16)
+ assert header == "STMGC-C7-PROF01\n"
+ result = []
+ while True:
+ packet = f.read(15)
+ if not packet: break
+ sec, nsec, threadnum, event, len0, len1 = \
+ struct.unpack("IIIBBB", packet)
+ result.append((sec + 0.000000001 * nsec,
+ threadnum,
+ event,
+ f.read(len0),
+ f.read(len1)))
+ f.close()
+ return result
+
+
+class TestProf(BaseTest):
+
+ def test_simple(self):
+ filename = os.path.join(str(udir), 'simple.prof')
+ r = lib.stm_set_timing_log(filename, ffi.NULL)
+ assert r == 0
+ try:
+ self.start_transaction()
+ self.commit_transaction()
+ finally:
+ lib.stm_set_timing_log(ffi.NULL, ffi.NULL)
+
+ result = read_log(filename)
+ assert result[0][2] == lib.STM_TRANSACTION_START
+ assert result[1][2] == lib.STM_GC_MINOR_START
+ assert result[2][2] == lib.STM_GC_MINOR_DONE
+ assert result[3][2] == lib.STM_TRANSACTION_COMMIT
+ assert len(result) == 4
+
+ def test_contention(self):
+ @ffi.callback("int(stm_loc_marker_t *, char *, int)")
+ def expand_marker(marker, p, s):
+ p[0] = chr(100 + marker.odd_number)
+ return 1
+ filename = os.path.join(str(udir), 'contention.prof')
+ r = lib.stm_set_timing_log(filename, expand_marker)
+ assert r == 0
+ try:
+ p = stm_allocate_old(16)
+ self.start_transaction()
+ assert stm_get_char(p) == '\x00' # read
+ #
+ self.switch(1)
+ self.start_transaction()
+ self.push_root(ffi.cast("object_t *", 19))
+ self.push_root(ffi.cast("object_t *", ffi.NULL))
+ stm_set_char(p, 'B') # write
+ py.test.raises(Conflict, self.commit_transaction)
+ finally:
+ lib.stm_set_timing_log(ffi.NULL, ffi.NULL)
+
+ result = read_log(filename)
+ id0 = result[0][1]
+ id1 = result[1][1]
+ assert result[0][1:5] == (id0, lib.STM_TRANSACTION_START, '', '')
+ assert result[1][1:5] == (id1, lib.STM_TRANSACTION_START, '', '')
+ assert result[2][1:5] == (id1, lib.STM_GC_MINOR_START, '', '')
+ assert result[3][1:5] == (id1, lib.STM_GC_MINOR_DONE, '', '')
+ assert result[4][1:5] == (id1, lib.STM_CONTENTION_WRITE_READ,
+ chr(119), '')
+ assert result[5][1:5] == (id1, lib.STM_TRANSACTION_ABORT, '', '')
+ assert len(result) == 6
_______________________________________________
pypy-commit mailing list
[email protected]
https://mail.python.org/mailman/listinfo/pypy-commit
