Mikhail, It looks as if strtoll is not available on Windows. For now strtol should work.
/Søren On Wed, May 20, 2009 at 11:04, <[email protected]> wrote: > > Author: [email protected] > Date: Wed May 20 02:04:13 2009 > New Revision: 2009 > > Modified: > branches/bleeding_edge/src/compiler.cc > branches/bleeding_edge/src/log.cc > branches/bleeding_edge/src/log.h > branches/bleeding_edge/test/cctest/test-log.cc > > Log: > Introduce Logger::LogCompiledFunctions that logs current map of compiled > code. > > The goal is to make possible having --prof flag always enabled in > Chromium. Currently we can't do this because --prof causes compiler and gc > to log code creations / moves / deletes which aren't needed until we start > profiling. With LogCompiledFunctions it will be possible not to log > anything until we start profiling. When started, the current map of > compiled functions will be logged and compiler / gc logging will be enabled > to update current state. When profling is stopped, logging will be turned > off again. > > Funny that testing code is actually much longer and complex than function > code. > > Review URL: http://codereview.chromium.org/112036 > > Modified: branches/bleeding_edge/src/compiler.cc > > ============================================================================== > --- branches/bleeding_edge/src/compiler.cc (original) > +++ branches/bleeding_edge/src/compiler.cc Wed May 20 02:04:13 2009 > @@ -357,8 +357,8 @@ > // name and line number. Check explicit whether logging is enabled as > finding > // the line number is not for free. > if (Logger::is_enabled() || OProfileAgent::is_enabled()) { > - Handle<String> func_name(lit->name()->length() > 0 ? > - *lit->name() : shared->inferred_name()); > + Handle<String> func_name(name->length() > 0 ? > + *name : shared->inferred_name()); > if (script->name()->IsString()) { > int line_num = GetScriptLineNumber(script, start_position); > if (line_num > 0) { > > Modified: branches/bleeding_edge/src/log.cc > > ============================================================================== > --- branches/bleeding_edge/src/log.cc (original) > +++ branches/bleeding_edge/src/log.cc Wed May 20 02:04:13 2009 > @@ -1108,6 +1108,69 @@ > return Log::GetLogLines(from_pos, dest_buf, max_size); > } > > + > +void Logger::LogCompiledFunctions() { > + HandleScope scope; > + Handle<SharedFunctionInfo>* sfis = NULL; > + int compiled_funcs_count = 0; > + > + { > + AssertNoAllocation no_alloc; > + > + HeapIterator iterator; > + while (iterator.has_next()) { > + HeapObject* obj = iterator.next(); > + ASSERT(obj != NULL); > + if (obj->IsSharedFunctionInfo() > + && SharedFunctionInfo::cast(obj)->is_compiled()) { > + ++compiled_funcs_count; > + } > + } > + > + sfis = NewArray< Handle<SharedFunctionInfo> >(compiled_funcs_count); > + iterator.reset(); > + > + int i = 0; > + while (iterator.has_next()) { > + HeapObject* obj = iterator.next(); > + ASSERT(obj != NULL); > + if (obj->IsSharedFunctionInfo() > + && SharedFunctionInfo::cast(obj)->is_compiled()) { > + sfis[i++] = > Handle<SharedFunctionInfo>(SharedFunctionInfo::cast(obj)); > + } > + } > + } > + > + // During iteration, there can be heap allocation due to > + // GetScriptLineNumber call. > + for (int i = 0; i < compiled_funcs_count; ++i) { > + Handle<SharedFunctionInfo> shared = sfis[i]; > + Handle<String> name(String::cast(shared->name())); > + Handle<String> func_name(name->length() > 0 ? > + *name : shared->inferred_name()); > + if (shared->script()->IsScript()) { > + Handle<Script> script(Script::cast(shared->script())); > + if (script->name()->IsString()) { > + Handle<String> script_name(String::cast(script->name())); > + int line_num = GetScriptLineNumber(script, > shared->start_position()); > + if (line_num > 0) { > + line_num += script->line_offset()->value() + 1; > + LOG(CodeCreateEvent("LazyCompile", shared->code(), *func_name, > + *script_name, line_num)); > + } else { > + // Can't distinguish enum and script here, so always use Script. > + LOG(CodeCreateEvent("Script", shared->code(), *script_name)); > + } > + continue; > + } > + } > + // If no script or script has no name. > + LOG(CodeCreateEvent("LazyCompile", shared->code(), *func_name)); > + } > + > + DeleteArray(sfis); > +} > + > #endif > > > > Modified: branches/bleeding_edge/src/log.h > > ============================================================================== > --- branches/bleeding_edge/src/log.h (original) > +++ branches/bleeding_edge/src/log.h Wed May 20 02:04:13 2009 > @@ -214,6 +214,9 @@ > // retrieve previously written messages. See v8.h. > static int GetLogLines(int from_pos, char* dest_buf, int max_size); > > + // Logs all compiled functions found in the heap. > + static void LogCompiledFunctions(); > + > private: > > // Emits the source code of a regexp. Used by regexp events. > > Modified: branches/bleeding_edge/test/cctest/test-log.cc > > ============================================================================== > --- branches/bleeding_edge/test/cctest/test-log.cc (original) > +++ branches/bleeding_edge/test/cctest/test-log.cc Wed May 20 02:04:13 > 2009 > @@ -7,15 +7,17 @@ > #include "v8.h" > > #include "log.h" > - > #include "cctest.h" > > +using v8::internal::Address; > using v8::internal::Logger; > > +namespace i = v8::internal; > + > static void SetUp() { > // Log to memory buffer. > - v8::internal::FLAG_logfile = "*"; > - v8::internal::FLAG_log = true; > + i::FLAG_logfile = "*"; > + i::FLAG_log = true; > Logger::Setup(); > } > > @@ -103,14 +105,383 @@ > > TEST(MemoryLoggingTurnedOff) { > // Log to stdout > - v8::internal::FLAG_logfile = "-"; > - v8::internal::FLAG_log = true; > + i::FLAG_logfile = "-"; > + i::FLAG_log = true; > Logger::Setup(); > CHECK_EQ(0, Logger::GetLogLines(0, NULL, 0)); > CHECK_EQ(0, Logger::GetLogLines(100, NULL, 0)); > CHECK_EQ(0, Logger::GetLogLines(0, NULL, 100)); > CHECK_EQ(0, Logger::GetLogLines(100, NULL, 100)); > Logger::TearDown(); > +} > + > + > +static inline bool IsStringEqualTo(const char* r, const char* s) { > + return strncmp(r, s, strlen(r)) == 0; > +} > + > + > +static bool Consume(const char* str, char** buf) { > + if (IsStringEqualTo(str, *buf)) { > + *buf += strlen(str); > + return true; > + } > + return false; > +} > + > + > +static void ParseAddress(char* start, Address* min_addr, Address* > max_addr) { > + Address addr = reinterpret_cast<Address>(strtoll(start, NULL, 16)); > + if (addr < *min_addr) *min_addr = addr; > + if (addr > *max_addr) *max_addr = addr; > +} > + > + > +static Address ConsumeAddress( > + char** start, Address min_addr, Address max_addr) { > + char* end_ptr; > + Address addr = reinterpret_cast<Address>(strtoll(*start, &end_ptr, 16)); > + CHECK_GE(addr, min_addr); > + CHECK_GE(max_addr, addr); > + *start = end_ptr; > + return addr; > +} > + > + > +namespace { > + > +// A code entity is a pointer to a position of code-creation event in > buffer log > +// offset to a point where entity size begins, i.e.: '255,"func"\n'. This > makes > +// comparing code entities pretty easy. > +typedef char* CodeEntityInfo; > + > +// A structure used to return log parsing results. > +class ParseLogResult { > + public: > + ParseLogResult() > + : min_addr(reinterpret_cast<Address>(-1)), > + max_addr(reinterpret_cast<Address>(0)), > + entities_map(NULL), entities(NULL), > + max_entities(0) {}; > + > + ~ParseLogResult() { > + // See allocation code below. > + if (entities_map != NULL) { > + i::DeleteArray(entities_map - 1); > + } > + i::DeleteArray(entities); > + } > + > + void AllocateEntities() { > + // Make sure that the test doesn't operate on a bogus log. > + CHECK_GT(max_entities, 0); > + CHECK_GT(min_addr, 0); > + CHECK_GT(max_addr, min_addr); > + > + entities = i::NewArray<CodeEntityInfo>(max_entities); > + for (int i = 0; i < max_entities; ++i) { > + entities[i] = NULL; > + } > + // We're adding fake items at [-1] and [size + 1] to simplify > + // comparison code. > + const int map_length = max_addr - min_addr + 1 + 2; // 2 fakes. > + entities_map = i::NewArray<int>(map_length); > + for (int i = 0; i < map_length; ++i) { > + entities_map[i] = -1; > + } > + entities_map += 1; // Hide the -1 item, this is compensated on delete. > + } > + > + // Minimal code entity address. > + Address min_addr; > + // Maximal code entity address. > + Address max_addr; > + // Memory map of entities start addresses. Biased by min_addr. > + int* entities_map; > + // An array of code entities. > + CodeEntityInfo* entities; > + // Maximal entities count. Actual entities count can be lower, > + // empty entity slots are pointing to NULL. > + int max_entities; > +}; > + > +} // namespace > + > + > +typedef void (*ParserBlock)(char* start, char* end, ParseLogResult* > result); > + > +static void ParserCycle( > + char* start, char* end, ParseLogResult* result, > + ParserBlock block_creation, ParserBlock block_delete, > + ParserBlock block_move) { > + > + const char* code_creation = "code-creation,"; > + const char* code_delete = "code-delete,"; > + const char* code_move = "code-move,"; > + > + const char* lazy_compile = "LazyCompile,"; > + const char* script = "Script,"; > + const char* function = "Function,"; > + > + while (start < end) { > + if (Consume(code_creation, &start)) { > + if (Consume(lazy_compile, &start) > + || Consume(script, &start) > + || Consume(function, &start)) { > + block_creation(start, end, result); > + } > + } else if (Consume(code_delete, &start)) { > + block_delete(start, end, result); > + } else if (Consume(code_move, &start)) { > + block_move(start, end, result); > + } > + while (start < end && *start != '\n') ++start; > + ++start; > + } > +} > + > + > +static void Pass1CodeCreation(char* start, char* end, ParseLogResult* > result) { > + ParseAddress(start, &result->min_addr, &result->max_addr); > + ++result->max_entities; > +} > + > + > +static void Pass1CodeDelete(char* start, char* end, ParseLogResult* > result) { > + ParseAddress(start, &result->min_addr, &result->max_addr); > +} > + > + > +static void Pass1CodeMove(char* start, char* end, ParseLogResult* result) > { > + // Skip old address. > + while (start < end && *start != ',') ++start; > + CHECK_GT(end, start); > + ++start; // Skip ','. > + ParseAddress(start, &result->min_addr, &result->max_addr); > +} > + > + > +static void Pass2CodeCreation(char* start, char* end, ParseLogResult* > result) { > + Address addr = ConsumeAddress(&start, result->min_addr, > result->max_addr); > + CHECK_GT(end, start); > + ++start; // Skip ','. > + > + int idx = addr - result->min_addr; > + result->entities_map[idx] = -1; > + for (int i = 0; i < result->max_entities; ++i) { > + // Find an empty slot and fill it. > + if (result->entities[i] == NULL) { > + result->entities[i] = start; > + result->entities_map[idx] = i; > + break; > + } > + } > + // Make sure that a slot was found. > + CHECK_GE(result->entities_map[idx], 0); > +} > + > + > +static void Pass2CodeDelete(char* start, char* end, ParseLogResult* > result) { > + Address addr = ConsumeAddress(&start, result->min_addr, > result->max_addr); > + int idx = addr - result->min_addr; > + // There can be code deletes that are not related to JS code. > + if (result->entities_map[idx] >= 0) { > + result->entities[result->entities_map[idx]] = NULL; > + result->entities_map[idx] = -1; > + } > +} > + > + > +static void Pass2CodeMove(char* start, char* end, ParseLogResult* result) > { > + Address from_addr = ConsumeAddress( > + &start, result->min_addr, result->max_addr); > + CHECK_GT(end, start); > + ++start; // Skip ','. > + Address to_addr = ConsumeAddress(&start, result->min_addr, > result->max_addr); > + CHECK_GT(end, start); > + > + int from_idx = from_addr - result->min_addr; > + int to_idx = to_addr - result->min_addr; > + // There can be code moves that are not related to JS code. > + if (from_idx != to_idx && result->entities_map[from_idx] >= 0) { > + CHECK_EQ(-1, result->entities_map[to_idx]); > + result->entities_map[to_idx] = result->entities_map[from_idx]; > + result->entities_map[from_idx] = -1; > + }; > +} > + > + > +static void ParseLog(char* start, char* end, ParseLogResult* result) { > + // Pass 1: Calculate boundaries of addresses and entities count. > + ParserCycle(start, end, result, > + Pass1CodeCreation, Pass1CodeDelete, Pass1CodeMove); > + > + printf("min_addr: %p, max_addr: %p, entities: %d\n", > + result->min_addr, result->max_addr, result->max_entities); > + > + result->AllocateEntities(); > + > + // Pass 2: Fill in code entries data. > + ParserCycle(start, end, result, > + Pass2CodeCreation, Pass2CodeDelete, Pass2CodeMove); > +} > + > + > +static inline void PrintCodeEntityInfo(CodeEntityInfo entity) { > + const int max_len = 50; > + if (entity != NULL) { > + char* eol = strchr(entity, '\n'); > + int len = eol - entity; > + len = len <= max_len ? len : max_len; > + printf("%-*.*s ", max_len, len, entity); > + } else { > + printf("%*s", max_len + 1, ""); > + } > +} > + > + > +static void PrintCodeEntitiesInfo( > + bool is_equal, Address addr, > + CodeEntityInfo l_entity, CodeEntityInfo r_entity) { > + printf("%c %p ", is_equal ? ' ' : '*', addr); > + PrintCodeEntityInfo(l_entity); > + PrintCodeEntityInfo(r_entity); > + printf("\n"); > +} > + > + > +static inline int StrChrLen(const char* s, char c) { > + return strchr(s, c) - s; > +} > + > + > +static bool AreFuncSizesEqual(CodeEntityInfo ref_s, CodeEntityInfo new_s) > { > + int ref_len = StrChrLen(ref_s, ','); > + int new_len = StrChrLen(new_s, ','); > + return ref_len == new_len && strncmp(ref_s, new_s, ref_len) == 0; > +} > + > + > +static bool AreFuncNamesEqual(CodeEntityInfo ref_s, CodeEntityInfo new_s) > { > + // Skip size. > + ref_s = strchr(ref_s, ',') + 1; > + new_s = strchr(new_s, ',') + 1; > + int ref_len = StrChrLen(ref_s, '\n'); > + int new_len = StrChrLen(new_s, '\n'); > + // If reference is anonymous (""), it's OK to have anything in new. > + if (ref_len == 2) return true; > + // A special case for ErrorPrototype. Haven't yet figured out why they > + // are different. > + const char* error_prototype = "\"ErrorPrototype"; > + if (IsStringEqualTo(error_prototype, ref_s) > + && IsStringEqualTo(error_prototype, new_s)) { > + return true; > + } > + return ref_len == new_len && strncmp(ref_s, new_s, ref_len) == 0; > +} > + > + > +static bool AreEntitiesEqual(CodeEntityInfo ref_e, CodeEntityInfo new_e) { > + if (ref_e == NULL && new_e != NULL) return true; > + if (ref_e != NULL && new_e != NULL) { > + return AreFuncSizesEqual(ref_e, new_e) && AreFuncNamesEqual(ref_e, > new_e); > + } > + if (ref_e != NULL && new_e == NULL) { > + // args_count entities (argument adapters) are not found by heap > traversal, > + // but they are not needed because they doesn't contain any code. > + ref_e = strchr(ref_e, ',') + 1; > + const char* args_count = "\"args_count:"; > + return IsStringEqualTo(args_count, ref_e); > + } > + return false; > +} > + > + > +// Test that logging of code create / move / delete events > +// is equivalent to traversal of a resulting heap. > +TEST(EquivalenceOfLoggingAndTraversal) { > + i::FLAG_logfile = "*"; > + i::FLAG_log = true; > + i::FLAG_log_code = true; > + > + // Make sure objects move. > + bool saved_always_compact = i::FLAG_always_compact; > + if (!i::FLAG_never_compact) { > + i::FLAG_always_compact = true; > + } > + > + v8::Persistent<v8::Context> env = v8::Context::New(); > + v8::HandleScope scope; > + env->Enter(); > + > + // Compile and run a function that creates other functions. > + v8::Script::Compile(v8::String::New( > + "(function f() {\n" > + " var rets = [];\n" > + " for (var i = 0; i < 100; ++i) {\n" > + " rets.push((function inc(n) { return n + 1; })(i));\n" > + " }\n" > + "})();"))->Run(); > + i::Heap::CollectAllGarbage(); > + > + i::EmbeddedVector<char,204800> buffer; > + int log_size; > + ParseLogResult ref_result; > + > + // Retrieve the log. > + { > + // Make sure that no GCs occur prior to LogCompiledFunctions call. > + i::AssertNoAllocation no_alloc; > + > + log_size = Logger::GetLogLines(0, buffer.start(), buffer.length()); > + CHECK_GT(log_size, 0); > + CHECK_GT(buffer.length(), log_size); > + > + // Fill a map of compiled code objects. > + ParseLog(buffer.start(), buffer.start() + log_size, &ref_result); > + } > + > + // Iterate heap to find compiled functions, will write to log. > + i::Logger::LogCompiledFunctions(); > + char* new_log_start = buffer.start() + log_size; > + const int new_log_size = Logger::GetLogLines( > + log_size, new_log_start, buffer.length() - log_size); > + CHECK_GT(new_log_size, 0); > + CHECK_GT(buffer.length(), log_size + new_log_size); > + > + // Fill an equivalent map of compiled code objects. > + ParseLogResult new_result; > + ParseLog(new_log_start, new_log_start + new_log_size, &new_result); > + > + // Test their actual equivalence. > + bool results_equal = true; > + int ref_idx = -1, new_idx = -1, ref_inc = 1, new_inc = 1; > + while (ref_inc > 0 || new_inc > 0) { > + const Address ref_addr = ref_result.min_addr + ref_idx; > + const Address new_addr = new_result.min_addr + new_idx; > + ref_inc = ref_addr <= ref_result.max_addr && ref_addr <= new_addr ? > 1 : 0; > + new_inc = new_addr <= new_result.max_addr && new_addr <= ref_addr ? > 1 : 0; > + const int ref_item = ref_result.entities_map[ref_idx]; > + const int new_item = new_result.entities_map[new_idx]; > + if (ref_item != -1 || new_item != -1) { > + CodeEntityInfo ref_entity = > + ref_item != -1 ? ref_result.entities[ref_item] : NULL; > + CodeEntityInfo new_entity = > + new_item != -1 ? new_result.entities[new_item] : NULL; > + const bool equal = AreEntitiesEqual(ref_entity, new_entity); > + if (!equal) results_equal = false; > + PrintCodeEntitiesInfo( > + equal, ref_inc != 0 ? ref_addr : new_addr, > + ref_entity, new_entity); > + } > + ref_idx += ref_inc; > + new_idx += new_inc; > + } > + CHECK(results_equal); > + > + env->Exit(); > + v8::V8::Dispose(); > + i::FLAG_always_compact = saved_always_compact; > } > > > > > > --~--~---------~--~----~------------~-------~--~----~ v8-dev mailing list [email protected] http://groups.google.com/group/v8-dev -~----------~----~----~----~------~----~------~--~---
