Skip to content

Commit

Permalink
More instrumentation (memory allocation, also fixes #7259)
Browse files Browse the repository at this point in the history
  • Loading branch information
@timholy
timholy committed Jul 9, 2014
1 parent b43b391 commit 196dfbc
Show file tree
Hide file tree
Showing 8 changed files with 176 additions and 23 deletions.
1 change: 1 addition & 0 deletions base/exports.jl
View file
Original file line number Diff line number Diff line change
Expand Up @@ -1072,6 +1072,7 @@ export
gc_disable,
gc_enable,
precompile,
clear_malloc_data,

# misc
atexit,
Expand Down
3 changes: 3 additions & 0 deletions base/util.jl
View file
Original file line number Diff line number Diff line change
Expand Up @@ -12,6 +12,9 @@ gc_time_ns() = ccall(:jl_gc_total_hrtime, Uint64, ())
# total number of bytes allocated so far
gc_bytes() = ccall(:jl_gc_total_bytes, Int64, ())

# reset the malloc log. Used to avoid counting memory allocated during compilation.
clear_malloc_data() = ccall(:jl_clear_malloc_data, Void, ())

function tic()
t0 = time_ns()
task_local_storage(:TIMERS, (t0, get(task_local_storage(), :TIMERS, ())))
Expand Down
37 changes: 33 additions & 4 deletions src/codegen.cpp
View file
Original file line number Diff line number Diff line change
Expand Up @@ -322,6 +322,8 @@ static Function *jlgetnthfieldchecked_func;
#ifdef _OS_WINDOWS_
static Function *resetstkoflw_func;
#endif
static Function *diff_gc_total_bytes_func;
static Function *show_execution_point_func;

// --- code generation ---

Expand Down Expand Up @@ -3367,8 +3369,9 @@ static Function *emit_function(jl_lambda_info_t *lam, bool cstyle)
ctx.f = f;

// step 5. set up debug info context and create first basic block
bool do_coverage =
jl_compileropts.code_coverage && lam->module != jl_base_module && lam->module != jl_core_module;
bool in_user_code = lam->module != jl_base_module && lam->module != jl_core_module;
bool do_coverage = jl_compileropts.code_coverage == JL_LOG_ALL || (jl_compileropts.code_coverage == JL_LOG_USER && in_user_code);
bool do_malloc_log = jl_compileropts.malloc_log == JL_LOG_ALL || (jl_compileropts.malloc_log == JL_LOG_USER && in_user_code);
jl_value_t *stmt = jl_cellref(stmts,0);
std::string filename = "no file";
char *dbgFuncName = lam->name->name;
Expand Down Expand Up @@ -3414,6 +3417,7 @@ static Function *emit_function(jl_lambda_info_t *lam, bool cstyle)
builder.SetCurrentDebugLocation(noDbg);
debug_enabled = false;
do_coverage = false;
do_malloc_log = false;
}
else {
// TODO: Fix when moving to new LLVM version
Expand Down Expand Up @@ -3716,18 +3720,20 @@ static Function *emit_function(jl_lambda_info_t *lam, bool cstyle)

// step 15. compile body statements
bool prevlabel = false;
lno = -1;
int prevlno = -1;
for(i=0; i < stmtslen; i++) {
jl_value_t *stmt = jl_cellref(stmts,i);
if (jl_is_linenode(stmt)) {
int lno = jl_linenode_line(stmt);
lno = jl_linenode_line(stmt);
if (debug_enabled)
builder.SetCurrentDebugLocation(DebugLoc::get(lno, 1, (MDNode*)SP, NULL));
if (do_coverage)
coverageVisitLine(filename, lno);
ctx.lineno = lno;
}
else if (jl_is_expr(stmt) && ((jl_expr_t*)stmt)->head == line_sym) {
int lno = jl_unbox_long(jl_exprarg(stmt, 0));
lno = jl_unbox_long(jl_exprarg(stmt, 0));
if (debug_enabled)
builder.SetCurrentDebugLocation(DebugLoc::get(lno, 1, (MDNode*)SP, NULL));
if (do_coverage)
Expand All @@ -3741,6 +3747,12 @@ static Function *emit_function(jl_lambda_info_t *lam, bool cstyle)
else {
prevlabel = false;
}
if (do_malloc_log && lno != prevlno) {
// Check memory allocation only after finishing a line
if (prevlno != -1)
mallocVisitLine(filename, prevlno);
prevlno = lno;
}
if (jl_is_expr(stmt) && ((jl_expr_t*)stmt)->head == return_sym) {
jl_expr_t *ex = (jl_expr_t*)stmt;
Value *retval;
Expand All @@ -3761,6 +3773,8 @@ static Function *emit_function(jl_lambda_info_t *lam, bool cstyle)
builder.CreateStore(builder.CreateBitCast(builder.CreateLoad(gcpop, false), jl_ppvalue_llvmt),
prepare_global(jlpgcstack_var));
#endif
if (do_malloc_log && lno != -1)
mallocVisitLine(filename, lno);
if (builder.GetInsertBlock()->getTerminator() == NULL) {
if (retty == T_void)
builder.CreateRetVoid();
Expand Down Expand Up @@ -4254,6 +4268,21 @@ static void init_julia_llvm_env(Module *m)
"jl_get_nth_field_checked", m);
add_named_global(jlgetnthfieldchecked_func, (void*)*jl_get_nth_field_checked);

diff_gc_total_bytes_func =
Function::Create(FunctionType::get(T_int64, false),
Function::ExternalLinkage,
"diff_gc_total_bytes", m);
add_named_global(diff_gc_total_bytes_func, (void*)*diff_gc_total_bytes);

std::vector<Type *> execpoint_args(0);
execpoint_args.push_back(T_pint8);
execpoint_args.push_back(T_int32);
show_execution_point_func =
Function::Create(FunctionType::get(T_void, execpoint_args, false),
Function::ExternalLinkage,
"show_execution_point", m);
add_named_global(show_execution_point_func, (void*)*show_execution_point);

// set up optimization passes
FPM = new FunctionPassManager(m);

Expand Down
96 changes: 80 additions & 16 deletions src/debuginfo.cpp
View file
Original file line number Diff line number Diff line change
Expand Up @@ -541,14 +541,14 @@ void* CALLBACK jl_getUnwindInfo(HANDLE hProcess, ULONG64 AddrBase, ULONG64 UserC

// Code coverage

typedef std::map<std::string,std::vector<GlobalVariable*> > coveragedata_t;
static coveragedata_t coverageData;
typedef std::map<std::string,std::vector<GlobalVariable*> > logdata_t;
static logdata_t coverageData;

static void coverageVisitLine(std::string filename, int line)
{
if (filename == "" || filename == "none" || filename == "no file")
return;
coveragedata_t::iterator it = coverageData.find(filename);
logdata_t::iterator it = coverageData.find(filename);
if (it == coverageData.end()) {
coverageData[filename] = std::vector<GlobalVariable*>(0);
}
Expand All @@ -564,39 +564,43 @@ static void coverageVisitLine(std::string filename, int line)
v);
}

extern "C" void jl_write_coverage_data(void)
void write_log_data(logdata_t logData, const char* extension)
{
coveragedata_t::iterator it = coverageData.begin();
for (; it != coverageData.end(); it++) {
std::string base = std::string(julia_home);
base = base + "/../share/julia/base/";
logdata_t::iterator it = logData.begin();
for (; it != logData.end(); it++) {
std::string filename = (*it).first;
std::string outfile = filename + ".cov";
std::vector<GlobalVariable*> &counts = (*it).second;
if (counts.size() > 1) {
std::vector<GlobalVariable*> &values = (*it).second;
if (values.size() > 1) {
if (filename[0] != '/')
filename = base + filename;
std::ifstream inf(filename.c_str());
if (inf.is_open()) {
std::string outfile = filename + extension;
std::ofstream outf(outfile.c_str(), std::ofstream::trunc | std::ofstream::out);
char line[1024];
int l = 1;
while (!inf.eof()) {
inf.getline(line, sizeof(line));
if (inf.fail() && !inf.bad()) {
// Read through lines longer than 1024
// Read through lines longer than sizeof(line)
inf.clear();
inf.ignore(std::numeric_limits<std::streamsize>::max(), '\n');
}
int count = -1;
if ((size_t)l < counts.size()) {
GlobalVariable *gv = counts[l];
int value = -1;
if ((size_t)l < values.size()) {
GlobalVariable *gv = values[l];
if (gv) {
int *p = (int*)jl_ExecutionEngine->getPointerToGlobal(gv);
count = *p;
value = *p;
}
}
outf.width(9);
if (count == -1)
if (value == -1)
outf<<'-';
else
outf<<count;
outf<<value;
outf.width(0);
outf<<" "<<line<<std::endl;
l++;
Expand All @@ -607,3 +611,63 @@ extern "C" void jl_write_coverage_data(void)
}
}
}

extern "C" void jl_write_coverage_data(void)
{
write_log_data(coverageData, ".cov");
}

// Memory allocation log (malloc_log)

static logdata_t mallocData;

static void mallocVisitLine(std::string filename, int line)
{
if (filename == "" || filename == "none" || filename == "no file") {
sync_gc_total_bytes();
return;
}
logdata_t::iterator it = mallocData.find(filename);
if (it == mallocData.end()) {
mallocData[filename] = std::vector<GlobalVariable*>(0);
}
std::vector<GlobalVariable*> &vec = mallocData[filename];
if (vec.size() <= (size_t)line)
vec.resize(line+1, NULL);
if (vec[line] == NULL)
vec[line] = new GlobalVariable(*jl_Module, T_int64, false,
GlobalVariable::InternalLinkage,
ConstantInt::get(T_int64,0), "bytecnt");
GlobalVariable *v = vec[line];
builder.CreateStore(builder.CreateAdd(builder.CreateLoad(v, true),
builder.CreateCall(prepare_call(diff_gc_total_bytes_func))),
v, true);
}

// Resets the malloc counts. Needed to avoid including memory usage
// from JITting.
extern "C" DLLEXPORT void jl_clear_malloc_data(void)
{
logdata_t::iterator it = mallocData.begin();
for (; it != mallocData.end(); it++) {
std::vector<GlobalVariable*> &bytes = (*it).second;
std::vector<GlobalVariable*>::iterator itb;
for (itb = bytes.begin(); itb != bytes.end(); itb++) {
if (*itb) {
int64_t *p = (int64_t*) jl_ExecutionEngine->getPointerToGlobal(*itb);
*p = 0;
}
}
}
sync_gc_total_bytes();
}

extern "C" void jl_write_malloc_log(void)
{
write_log_data(mallocData, ".mlc");
}

void show_execution_point(char *filename, int lno)
{
jl_printf(JL_STDOUT, "executing file %s, line %d\n", filename, lno);
}
10 changes: 10 additions & 0 deletions src/gc.c
View file
Original file line number Diff line number Diff line change
Expand Up @@ -80,6 +80,7 @@ typedef struct _bigval_t {
// GC knobs and self-measurement variables
static size_t allocd_bytes = 0;
static int64_t total_allocd_bytes = 0;
static int64_t last_gc_total_bytes = 0;
static size_t freed_bytes = 0;
static uint64_t total_gc_time=0;
#ifdef _P64
Expand Down Expand Up @@ -917,6 +918,15 @@ DLLEXPORT int jl_gc_is_enabled(void) { return is_gc_enabled; }
DLLEXPORT int64_t jl_gc_total_bytes(void) { return total_allocd_bytes + allocd_bytes; }
DLLEXPORT uint64_t jl_gc_total_hrtime(void) { return total_gc_time; }

int64_t diff_gc_total_bytes(void)
{
int64_t oldtb = last_gc_total_bytes;
int64_t newtb = jl_gc_total_bytes();
last_gc_total_bytes = newtb;
return newtb - oldtb;
}
void sync_gc_total_bytes(void) {last_gc_total_bytes = jl_gc_total_bytes();}

void jl_gc_ephemeral_on(void) { pools = &ephe_pools[0]; }
void jl_gc_ephemeral_off(void) { pools = &norm_pools[0]; }

Expand Down
4 changes: 4 additions & 0 deletions src/init.c
View file
Original file line number Diff line number Diff line change
Expand Up @@ -67,6 +67,7 @@ extern BOOL (WINAPI *hSymRefreshModuleList)(HANDLE);
char *julia_home = NULL;
jl_compileropts_t jl_compileropts = { NULL, // build_path
0, // code_coverage
0, // malloc_log
JL_COMPILEROPT_CHECK_BOUNDS_DEFAULT,
0 // int32_literals
};
Expand Down Expand Up @@ -378,6 +379,7 @@ static void jl_uv_exitcleanup_walk(uv_handle_t* handle, void *arg)
}

void jl_write_coverage_data(void);
void jl_write_malloc_log(void);

DLLEXPORT void uv_atexit_hook()
{
Expand All @@ -386,6 +388,8 @@ DLLEXPORT void uv_atexit_hook()
#endif
if (jl_compileropts.code_coverage)
jl_write_coverage_data();
if (jl_compileropts.malloc_log)
jl_write_malloc_log();
if (jl_base_module) {
jl_value_t *f = jl_get_global(jl_base_module, jl_symbol("_atexit"));
if (f!=NULL && jl_is_function(f)) {
Expand Down
13 changes: 13 additions & 0 deletions src/julia.h
View file
Original file line number Diff line number Diff line change
Expand Up @@ -1054,6 +1054,8 @@ DLLEXPORT void jl_gc_disable(void);
DLLEXPORT int jl_gc_is_enabled(void);
DLLEXPORT int64_t jl_gc_total_bytes(void);
DLLEXPORT uint64_t jl_gc_total_hrtime(void);
int64_t diff_gc_total_bytes(void);
void sync_gc_total_bytes(void);
void jl_gc_ephemeral_on(void);
void jl_gc_ephemeral_off(void);
DLLEXPORT void jl_gc_collect(void);
Expand All @@ -1073,6 +1075,8 @@ DLLEXPORT void *alloc_4w(void);
void *allocb(size_t sz);
DLLEXPORT void *allocobj(size_t sz);

DLLEXPORT void jl_clear_malloc_data(void);

#else

#define JL_GC_PUSH(...) ;
Expand Down Expand Up @@ -1308,17 +1312,26 @@ DLLEXPORT size_t jl_static_show(JL_STREAM *out, jl_value_t *v);
void jl_print_gc_stats(JL_STREAM *s);
#endif

// debugging
void show_execution_point(char *filename, int lno);

// compiler options -----------------------------------------------------------

typedef struct {
char *build_path;
int8_t code_coverage;
int8_t malloc_log;
int8_t check_bounds;
int int_literals;
} jl_compileropts_t;

extern DLLEXPORT jl_compileropts_t jl_compileropts;

// Settings for code_coverage and mallog_log
#define JL_LOG_NONE 0
#define JL_LOG_USER 1
#define JL_LOG_ALL 2

#define JL_COMPILEROPT_CHECK_BOUNDS_DEFAULT 0
#define JL_COMPILEROPT_CHECK_BOUNDS_ON 1
#define JL_COMPILEROPT_CHECK_BOUNDS_OFF 2
Expand Down
Loading

2 comments on commit 196dfbc

@vtjnash
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

i think you may also want to disable the loading of cached code when profiling the system library

@timholy
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yep. How?

Please sign in to comment.