Author: Armin Rigo <[email protected]>
Branch: c7-full-profiling
Changeset: r1442:0014465e03aa
Date: 2014-10-03 16:53 +0200
http://bitbucket.org/pypy/stmgc/changeset/0014465e03aa/
Log: in-progress
diff --git a/c7/stm/core.c b/c7/stm/core.c
--- a/c7/stm/core.c
+++ b/c7/stm/core.c
@@ -343,7 +343,7 @@
assert(STM_PSEGMENT->safe_point == SP_NO_TRANSACTION);
assert(STM_PSEGMENT->transaction_state == TS_NONE);
- change_timing_state(STM_TIME_RUN_CURRENT);
+ timing_event(tl, STM_TRANSACTION_START, NULL, NULL);
STM_PSEGMENT->start_time = tl->_timing_cur_start;
STM_PSEGMENT->signalled_to_commit_soon = false;
STM_PSEGMENT->safe_point = SP_RUNNING;
@@ -783,7 +783,7 @@
list_clear(STM_PSEGMENT->modified_old_objects_markers);
}
-static void _finish_transaction(int attribute_to)
+static void _finish_transaction(enum stm_event_e final_event)
{
STM_PSEGMENT->safe_point = SP_NO_TRANSACTION;
STM_PSEGMENT->transaction_state = TS_NONE;
@@ -812,9 +812,6 @@
minor_collection(/*commit=*/ true);
- /* the call to minor_collection() above leaves us with
- STM_TIME_BOOKKEEPING */
-
/* synchronize overflow objects living in privatized pages */
push_overflow_objects_from_privatized_pages();
@@ -838,9 +835,9 @@
/* if a major collection is required, do it here */
if (is_major_collection_requested()) {
- int oldstate = change_timing_state(STM_TIME_MAJOR_GC);
+ timing_event(NULL, STM_GC_MAJOR_START, NULL, NULL);
major_collection_now_at_safe_point();
- change_timing_state(oldstate);
+ timing_event(NULL, STM_GC_MAJOR_STOP, NULL, NULL);
}
/* synchronize modified old objects to other threads */
@@ -867,7 +864,7 @@
}
/* done */
- _finish_transaction(STM_TIME_RUN_COMMITTED);
+ _finish_transaction(STM_TR_COMMIT);
/* cannot access STM_SEGMENT or STM_PSEGMENT from here ! */
s_mutex_unlock();
@@ -1052,16 +1049,16 @@
/* invoke the callbacks */
invoke_and_clear_user_callbacks(1); /* for abort */
- int attribute_to = STM_TIME_RUN_ABORTED_OTHER;
+ enum stm_event_e final_event = STM_TR_ABORT_OTHER;
if (is_abort(STM_SEGMENT->nursery_end)) {
/* done aborting */
- attribute_to = STM_SEGMENT->nursery_end;
+ final_event = STM_SEGMENT->nursery_end;
STM_SEGMENT->nursery_end = pause_signalled ? NSE_SIGPAUSE
: NURSERY_END;
}
- _finish_transaction(attribute_to);
+ _finish_transaction(final_event);
/* cannot access STM_SEGMENT or STM_PSEGMENT from here ! */
/* Broadcast C_ABORTED to wake up contention.c */
diff --git a/c7/stm/gcpage.c b/c7/stm/gcpage.c
--- a/c7/stm/gcpage.c
+++ b/c7/stm/gcpage.c
@@ -141,7 +141,7 @@
if (is_major_collection_requested()) { /* if still true */
- int oldstate = change_timing_state(STM_TIME_MAJOR_GC);
+ timing_event(NULL, STM_GC_MAJOR_START, NULL, NULL);
synchronize_all_threads(STOP_OTHERS_UNTIL_MUTEX_UNLOCK);
@@ -149,7 +149,7 @@
major_collection_now_at_safe_point();
}
- change_timing_state(oldstate);
+ timing_event(NULL, STM_GC_MAJOR_STOP, NULL, NULL);
}
s_mutex_unlock();
diff --git a/c7/stm/timing.c b/c7/stm/timing.c
deleted file mode 100644
--- a/c7/stm/timing.c
+++ /dev/null
@@ -1,91 +0,0 @@
-#ifndef _STM_CORE_H_
-# error "must be compiled via stmgc.c"
-#endif
-
-
-static inline void add_timing(stm_thread_local_t *tl, enum stm_time_e category,
- double elapsed)
-{
- tl->timing[category] += elapsed;
- tl->events[category] += 1;
-}
-
-#define TIMING_CHANGE(tl, newstate) \
- double curtime = get_stm_time(); \
- double elasped = curtime - tl->_timing_cur_start; \
- enum stm_time_e oldstate = tl->_timing_cur_state; \
- add_timing(tl, oldstate, elasped); \
- tl->_timing_cur_state = newstate; \
- tl->_timing_cur_start = curtime
-
-static enum stm_time_e change_timing_state(enum stm_time_e newstate)
-{
- stm_thread_local_t *tl = STM_SEGMENT->running_thread;
- TIMING_CHANGE(tl, newstate);
- return oldstate;
-}
-
-static double change_timing_state_tl(stm_thread_local_t *tl,
- enum stm_time_e newstate)
-{
- TIMING_CHANGE(tl, newstate);
- return elasped;
-}
-
-static void timing_end_transaction(enum stm_time_e attribute_to)
-{
- stm_thread_local_t *tl = STM_SEGMENT->running_thread;
- TIMING_CHANGE(tl, STM_TIME_OUTSIDE_TRANSACTION);
- double time_this_transaction = tl->timing[STM_TIME_RUN_CURRENT];
- add_timing(tl, attribute_to, time_this_transaction);
- tl->timing[STM_TIME_RUN_CURRENT] = 0.0f;
-
- if (attribute_to != STM_TIME_RUN_COMMITTED) {
- struct stm_priv_segment_info_s *pseg =
- get_priv_segment(STM_SEGMENT->segment_num);
- marker_copy(tl, pseg, attribute_to, time_this_transaction);
- }
-}
-
-static const char *timer_names[] = {
- "outside transaction",
- "run current",
- "run committed",
- "run aborted write write",
- "run aborted write read",
- "run aborted inevitable",
- "run aborted other",
- "wait free segment",
- "wait write read",
- "wait inevitable",
- "wait other",
- "sync commit soon",
- "bookkeeping",
- "minor gc",
- "major gc",
- "sync pause",
-};
-
-void stm_flush_timing(stm_thread_local_t *tl, int verbose)
-{
- enum stm_time_e category = tl->_timing_cur_state;
- uint64_t oldevents = tl->events[category];
- TIMING_CHANGE(tl, category);
- tl->events[category] = oldevents;
-
- assert((sizeof(timer_names) / sizeof(timer_names[0])) == _STM_TIME_N);
- if (verbose > 0) {
- int i;
- s_mutex_lock();
- fprintf(stderr, "thread %p:\n", tl);
- for (i = 0; i < _STM_TIME_N; i++) {
- fprintf(stderr, " %-24s %9u %8.3f s\n",
- timer_names[i], tl->events[i], (double)tl->timing[i]);
- }
- fprintf(stderr, " %-24s %6s %11.6f s\n",
- "longest recorded marker", "", tl->longest_marker_time);
- fprintf(stderr, " \"%.*s\"\n",
- (int)_STM_MARKER_LEN, tl->longest_marker_self);
- s_mutex_unlock();
- }
-}
diff --git a/c7/stm/timing.h b/c7/stm/timing.h
--- a/c7/stm/timing.h
+++ b/c7/stm/timing.h
@@ -1,14 +1,11 @@
-#include <time.h>
+void (*stmcb_timing_event)(stm_thread_local_t *, enum stm_event_e,
+ const char *, const char *);
-static inline double get_stm_time(void)
+static inline void timing_event(stm_thread_local_t *tl,
+ enum stm_event_e event,
+ const char *marker1,
+ const char *marker2)
{
- struct timespec tp;
- clock_gettime(CLOCK_MONOTONIC, &tp);
- return tp.tv_sec + tp.tv_nsec * 0.000000001;
+ if (stmcb_timing_event != NULL)
+ stmcb_timing_event(tl, event, marker1, marker2);
}
-
-static enum stm_time_e change_timing_state(enum stm_time_e newstate);
-static double change_timing_state_tl(stm_thread_local_t *tl,
- enum stm_time_e newstate);
-
-static void timing_end_transaction(enum stm_time_e attribute_to);
diff --git a/c7/stmgc.c b/c7/stmgc.c
--- a/c7/stmgc.c
+++ b/c7/stmgc.c
@@ -34,6 +34,5 @@
#include "stm/extra.c"
#include "stm/fprintcolor.c"
#include "stm/weakref.c"
-#include "stm/timing.c"
#include "stm/marker.c"
#include "stm/rewind_setjmp.c"
diff --git a/c7/stmgc.h b/c7/stmgc.h
--- a/c7/stmgc.h
+++ b/c7/stmgc.h
@@ -54,27 +54,32 @@
object_t *ss;
};
-enum stm_time_e {
- STM_TIME_OUTSIDE_TRANSACTION,
- STM_TIME_RUN_CURRENT,
- STM_TIME_RUN_COMMITTED,
- STM_TIME_RUN_ABORTED_WRITE_WRITE,
- STM_TIME_RUN_ABORTED_WRITE_READ,
- STM_TIME_RUN_ABORTED_INEVITABLE,
- STM_TIME_RUN_ABORTED_OTHER,
- STM_TIME_WAIT_FREE_SEGMENT,
- STM_TIME_WAIT_WRITE_READ,
- STM_TIME_WAIT_INEVITABLE,
- STM_TIME_WAIT_OTHER,
- STM_TIME_SYNC_COMMIT_SOON,
- STM_TIME_BOOKKEEPING,
- STM_TIME_MINOR_GC,
- STM_TIME_MAJOR_GC,
- STM_TIME_SYNC_PAUSE,
+/* Profiling events (in the comments: value for marker1, value for marker2) */
+enum stm_event_e {
+ /* always STM_TRANSACTION_START followed later by one of the STM_TR_xxx */
+ STM_TRANSACTION_START,
+ STM_TR_COMMIT,
+ STM_TR_ABORT_WRITE_WRITE, /* self write loc, other write loc */
+ STM_TR_ABORT_WRITE_READ, /* self write loc, other = null; or opposite
*/
+ STM_TR_ABORT_INEVITABLE, /* self cur loc, other turned-inev loc */
+ STM_TR_ABORT_OTHER, /* ?, ? */
+
+ /* always one STM_WT_xxx followed later by STM_WAIT_DONE */
+ STM_WT_FREE_SEGMENT,
+ STM_WT_SYNC_PAUSE,
+ STM_WT_WRITE_READ, /* self write loc, other = null; or opposite
*/
+ STM_WT_INEVITABLE, /* self cur loc, other turned-inev loc */
+ STM_WAIT_DONE,
+
+ /* start and end of GC cycles */
+ STM_GC_MINOR_START,
+ STM_GC_MINOR_STOP,
+ STM_GC_MAJOR_START,
+ STM_GC_MAJOR_STOP,
+
_STM_TIME_N
};
-
-#define _STM_MARKER_LEN 80
+#define _STM_MARKER_LEN 128
typedef struct stm_thread_local_s {
/* every thread should handle the shadow stack itself */
@@ -90,16 +95,6 @@
/* after an abort, some details about the abort are stored there.
(these fields are not modified on a successful commit) */
long last_abort__bytes_in_nursery;
- /* timing information, accumulated */
- uint32_t events[_STM_TIME_N];
- float timing[_STM_TIME_N];
- double _timing_cur_start;
- enum stm_time_e _timing_cur_state;
- /* the marker with the longest associated time so far */
- enum stm_time_e longest_marker_state;
- double longest_marker_time;
- char longest_marker_self[_STM_MARKER_LEN];
- char longest_marker_other[_STM_MARKER_LEN];
/* the next fields are handled internally by the library */
int associated_segment_num;
struct stm_thread_local_s *prev, *next;
@@ -448,8 +443,10 @@
extern void (*stmcb_expand_marker)(char *segment_base, uintptr_t odd_number,
object_t *following_object,
char *outputbuf, size_t outputbufsize);
-extern void (*stmcb_debug_print)(const char *cause, double time,
- const char *marker);
+extern void (*stmcb_timing_event)(stm_thread_local_t *tl,
+ enum stm_event_e event,
+ const char *marker1,
+ const char *marker2);
/* Conventience macros to push the markers into the shadowstack */
#define STM_PUSH_MARKER(tl, odd_num, p) do { \
diff --git a/c7/test/support.py b/c7/test/support.py
--- a/c7/test/support.py
+++ b/c7/test/support.py
@@ -24,12 +24,6 @@
size_t mem_bytes_to_clear_on_abort;
long last_abort__bytes_in_nursery;
int associated_segment_num;
- uint32_t events[];
- float timing[];
- int longest_marker_state;
- double longest_marker_time;
- char longest_marker_self[];
- char longest_marker_other[];
...;
} stm_thread_local_t;
@@ -113,29 +107,39 @@
long stm_call_on_abort(stm_thread_local_t *, void *key, void callback(void *));
long stm_call_on_commit(stm_thread_local_t *, void *key, void callback(void
*));
-#define STM_TIME_OUTSIDE_TRANSACTION ...
-#define STM_TIME_RUN_CURRENT ...
-#define STM_TIME_RUN_COMMITTED ...
-#define STM_TIME_RUN_ABORTED_WRITE_WRITE ...
-#define STM_TIME_RUN_ABORTED_WRITE_READ ...
-#define STM_TIME_RUN_ABORTED_INEVITABLE ...
-#define STM_TIME_RUN_ABORTED_OTHER ...
-#define STM_TIME_WAIT_FREE_SEGMENT ...
-#define STM_TIME_WAIT_WRITE_READ ...
-#define STM_TIME_WAIT_INEVITABLE ...
-#define STM_TIME_WAIT_OTHER ...
-#define STM_TIME_BOOKKEEPING ...
-#define STM_TIME_MINOR_GC ...
-#define STM_TIME_MAJOR_GC ...
-#define STM_TIME_SYNC_PAUSE ...
+enum stm_event_e {
+ /* always STM_TRANSACTION_START followed later by one of the STM_TR_xxx */
+ STM_TRANSACTION_START,
+ STM_TR_COMMIT,
+ STM_TR_ABORT_WRITE_WRITE, /* self write loc, other write loc */
+ STM_TR_ABORT_WRITE_READ, /* self write loc, other = null; or opposite
*/
+ STM_TR_ABORT_INEVITABLE, /* self cur loc, other turned-inev loc */
+ STM_TR_ABORT_OTHER, /* ?, ? */
+
+ /* always one STM_WT_xxx followed later by STM_WAIT_DONE */
+ STM_WT_FREE_SEGMENT,
+ STM_WT_SYNC_PAUSE,
+ STM_WT_WRITE_READ, /* self write loc, other = null; or opposite
*/
+ STM_WT_INEVITABLE, /* self cur loc, other turned-inev loc */
+ STM_WAIT_DONE,
+
+ /* start and end of GC cycles */
+ STM_GC_MINOR_START,
+ STM_GC_MINOR_STOP,
+ STM_GC_MAJOR_START,
+ STM_GC_MAJOR_STOP,
+ ...
+};
void stm_flush_timing(stm_thread_local_t *, int);
void (*stmcb_expand_marker)(char *segment_base, uintptr_t odd_number,
object_t *following_object,
char *outputbuf, size_t outputbufsize);
-void (*stmcb_debug_print)(const char *cause, double time,
- const char *marker);
+void (*stmcb_timing_event)(stm_thread_local_t *tl,
+ enum stm_event_e event,
+ const char *marker1,
+ const char *marker2);
void stm_push_marker(stm_thread_local_t *, uintptr_t, object_t *);
void stm_update_marker_num(stm_thread_local_t *, uintptr_t);
_______________________________________________
pypy-commit mailing list
[email protected]
https://mail.python.org/mailman/listinfo/pypy-commit
