Revision: 3635
Author: [email protected]
Date: Mon Jan 18 08:04:25 2010
Log: Fix issue 571: display descriptive names for code objects from
snapshot.
As this is only needed for internal profiling (not for DevTools),
the following approach had been chosen:
- during snapshot creation, positions of serialized objects inside
a snapshot are logged;
- then during V8 initialization, positions of deserealized objects
are logged;
- those positions are used for retrieving code objects names from
snapshot creation log, which needs to be supplied to tick processor
script.
Positions logging is controlled with the new flag: --log_snapshot_positions.
This flag is turned off by default, and this adds no startup penalty.
To plug this fix to Golem, the following actions are needed:
- logs created using 'mksnapshot' need to be stored along with VM images;
- tick processor script needs to be run with '--snapshot-log=...' cmdline
argument.
BUG=571
Review URL: http://codereview.chromium.org/551062
http://code.google.com/p/v8/source/detail?r=3635
Modified:
/branches/bleeding_edge/src/SConscript
/branches/bleeding_edge/src/flag-definitions.h
/branches/bleeding_edge/src/log.cc
/branches/bleeding_edge/src/log.h
/branches/bleeding_edge/src/mksnapshot.cc
/branches/bleeding_edge/src/serialize.cc
/branches/bleeding_edge/src/serialize.h
/branches/bleeding_edge/src/snapshot-common.cc
/branches/bleeding_edge/tools/profile.js
/branches/bleeding_edge/tools/tickprocessor-driver.js
/branches/bleeding_edge/tools/tickprocessor.js
=======================================
--- /branches/bleeding_edge/src/SConscript Wed Dec 9 04:56:42 2009
+++ /branches/bleeding_edge/src/SConscript Mon Jan 18 08:04:25 2010
@@ -235,7 +235,7 @@
env.Replace(**context.flags['v8'])
context.ApplyEnvOverrides(env)
env['BUILDERS']['JS2C'] = Builder(action=js2c.JS2C)
- env['BUILDERS']['Snapshot'] = Builder(action='$SOURCE $TARGET
--logfile "$LOGFILE"')
+ env['BUILDERS']['Snapshot'] = Builder(action='$SOURCE $TARGET
--logfile "$LOGFILE" --log-snapshot-positions')
# Build the standard platform-independent source files.
source_files = context.GetRelevantSources(SOURCES)
=======================================
--- /branches/bleeding_edge/src/flag-definitions.h Thu Jan 7 11:01:23 2010
+++ /branches/bleeding_edge/src/flag-definitions.h Mon Jan 18 08:04:25 2010
@@ -358,6 +358,8 @@
DEFINE_bool(log_gc, false,
"Log heap samples on garbage collection for the hp2ps tool.")
DEFINE_bool(log_handles, false, "Log global handle events.")
+DEFINE_bool(log_snapshot_positions, false,
+ "log positions of (de)serialized objects in the snapshot.")
DEFINE_bool(log_state_changes, false, "Log state changes.")
DEFINE_bool(log_suspect, false, "Log suspect operations.")
DEFINE_bool(log_producers, false, "Log stack traces of JS objects
allocations.")
=======================================
--- /branches/bleeding_edge/src/log.cc Wed Nov 25 08:39:18 2009
+++ /branches/bleeding_edge/src/log.cc Mon Jan 18 08:04:25 2010
@@ -869,6 +869,23 @@
msg.WriteToLogFile();
#endif
}
+
+
+void Logger::SnapshotPositionEvent(Address addr, int pos) {
+#ifdef ENABLE_LOGGING_AND_PROFILING
+ if (!Log::IsEnabled() || !FLAG_log_snapshot_positions) return;
+ LogMessageBuilder msg;
+ msg.Append("%s,", log_events_[SNAPSHOT_POSITION_EVENT]);
+ msg.AppendAddress(addr);
+ msg.Append(",%d", pos);
+ if (FLAG_compress_log) {
+ ASSERT(compression_helper_ != NULL);
+ if (!compression_helper_->HandleMessage(&msg)) return;
+ }
+ msg.Append('\n');
+ msg.WriteToLogFile();
+#endif
+}
void Logger::ResourceEvent(const char* name, const char* tag) {
=======================================
--- /branches/bleeding_edge/src/log.h Wed Nov 25 08:39:18 2009
+++ /branches/bleeding_edge/src/log.h Mon Jan 18 08:04:25 2010
@@ -116,6 +116,7 @@
V(CODE_CREATION_EVENT, "code-creation", "cc") \
V(CODE_MOVE_EVENT, "code-move", "cm") \
V(CODE_DELETE_EVENT, "code-delete", "cd") \
+ V(SNAPSHOT_POSITION_EVENT, "snapshot-pos", "sp") \
V(TICK_EVENT, "tick", "t") \
V(REPEAT_META_EVENT, "repeat", "r") \
V(BUILTIN_TAG, "Builtin", "bi") \
@@ -224,6 +225,8 @@
// Emits a code delete event.
static void CodeDeleteEvent(Address from);
+ static void SnapshotPositionEvent(Address addr, int pos);
+
// ==== Events logged by --log-gc. ====
// Heap sampling events: start, end, and individual types.
static void HeapSampleBeginEvent(const char* space, const char* kind);
=======================================
--- /branches/bleeding_edge/src/mksnapshot.cc Mon Jan 11 23:16:49 2010
+++ /branches/bleeding_edge/src/mksnapshot.cc Mon Jan 18 08:04:25 2010
@@ -129,6 +129,10 @@
fprintf(fp_, "\n");
}
}
+
+ virtual int Position() {
+ return bytes_written_;
+ }
private:
FILE* fp_;
=======================================
--- /branches/bleeding_edge/src/serialize.cc Mon Jan 18 01:49:50 2010
+++ /branches/bleeding_edge/src/serialize.cc Mon Jan 18 08:04:25 2010
@@ -697,6 +697,9 @@
*write_back = HeapObject::FromAddress(address);
Object** current = reinterpret_cast<Object**>(address);
Object** limit = current + (size >> kPointerSizeLog2);
+ if (FLAG_log_snapshot_positions) {
+ LOG(SnapshotPositionEvent(address, source_->position()));
+ }
ReadChunk(current, limit, space_number, address);
}
@@ -1089,6 +1092,8 @@
}
sink_->PutInt(size >> kObjectAlignmentBits, "Size in words");
+ LOG(SnapshotPositionEvent(object_->address(), sink_->Position()));
+
// Mark this object as already serialized.
bool start_new_page;
SerializationAddressMapper::Map(
=======================================
--- /branches/bleeding_edge/src/serialize.h Fri Jan 15 06:20:31 2010
+++ /branches/bleeding_edge/src/serialize.h Mon Jan 18 08:04:25 2010
@@ -146,6 +146,8 @@
bool AtEOF() {
return position_ == length_;
}
+
+ const int position() { return position_; }
private:
const byte* data_;
@@ -294,6 +296,7 @@
Put(byte, description);
}
void PutInt(uintptr_t integer, const char* description);
+ virtual int Position() = 0;
};
=======================================
--- /branches/bleeding_edge/src/snapshot-common.cc Mon Nov 16 04:08:40 2009
+++ /branches/bleeding_edge/src/snapshot-common.cc Mon Jan 18 08:04:25 2010
@@ -79,6 +79,9 @@
fputc(byte, fp_);
}
}
+ virtual int Position() {
+ return ftell(fp_);
+ }
private:
FILE* fp_;
=======================================
--- /branches/bleeding_edge/tools/profile.js Tue Jul 14 02:47:44 2009
+++ /branches/bleeding_edge/tools/profile.js Mon Jan 18 08:04:25 2010
@@ -162,6 +162,16 @@
};
+/**
+ * Retrieves a code entry by an address.
+ *
+ * @param {number} addr Entry address.
+ */
+devtools.profiler.Profile.prototype.findEntry = function(addr) {
+ return this.codeMap_.findEntry(addr);
+};
+
+
/**
* Records a tick event. Stack must contain a sequence of
* addresses starting with the program counter value.
@@ -344,6 +354,14 @@
};
+/**
+ * Returns raw node name (without type decoration).
+ */
+devtools.profiler.Profile.DynamicCodeEntry.prototype.getRawName =
function() {
+ return this.name;
+};
+
+
/**
* Constructs a call graph.
*
=======================================
--- /branches/bleeding_edge/tools/tickprocessor-driver.js Mon Jul 13
22:01:06 2009
+++ /branches/bleeding_edge/tools/tickprocessor-driver.js Mon Jan 18
08:04:25 2010
@@ -44,10 +44,16 @@
};
var params = processArguments(arguments);
+var snapshotLogProcessor;
+if (params.snapshotLogFileName) {
+ snapshotLogProcessor = new SnapshotLogProcessor();
+ snapshotLogProcessor.processLogFile(params.snapshotLogFileName);
+}
var tickProcessor = new TickProcessor(
new (entriesProviders[params.platform])(params.nm),
params.separateIc,
params.ignoreUnknown,
- params.stateFilter);
+ params.stateFilter,
+ snapshotLogProcessor);
tickProcessor.processLogFile(params.logFileName);
tickProcessor.printStatistics();
=======================================
--- /branches/bleeding_edge/tools/tickprocessor.js Thu Oct 15 00:50:23 2009
+++ /branches/bleeding_edge/tools/tickprocessor.js Mon Jan 18 08:04:25 2010
@@ -53,14 +53,79 @@
function inherits(childCtor, parentCtor) {
- function tempCtor() {};
- tempCtor.prototype = parentCtor.prototype;
- childCtor.prototype = new tempCtor();
+ childCtor.prototype.__proto__ = parentCtor.prototype;
};
+function SnapshotLogProcessor() {
+ devtools.profiler.LogReader.call(this, {
+ 'code-creation': {
+ parsers: [null, this.createAddressParser('code'), parseInt,
null],
+ processor: this.processCodeCreation, backrefs: true },
+ 'code-move': { parsers: [this.createAddressParser('code'),
+ this.createAddressParser('code-move-to')],
+ processor: this.processCodeMove, backrefs: true },
+ 'code-delete': { parsers: [this.createAddressParser('code')],
+ processor: this.processCodeDelete, backrefs: true },
+ 'snapshot-pos': { parsers: [this.createAddressParser('code'),
parseInt],
+ processor: this.processSnapshotPosition, backrefs: true }});
+
+ Profile.prototype.handleUnknownCode = function(operation, addr) {
+ var op = devtools.profiler.Profile.Operation;
+ switch (operation) {
+ case op.MOVE:
+ print('Snapshot: Code move event for unknown code: 0x' +
+ addr.toString(16));
+ break;
+ case op.DELETE:
+ print('Snapshot: Code delete event for unknown code: 0x' +
+ addr.toString(16));
+ break;
+ }
+ };
+
+ this.profile_ = new Profile();
+ this.serializedEntries_ = [];
+}
+inherits(SnapshotLogProcessor, devtools.profiler.LogReader);
+
+
+SnapshotLogProcessor.prototype.processCodeCreation = function(
+ type, start, size, name) {
+ var entry = this.profile_.addCode(
+ this.expandAlias(type), name, start, size);
+};
+
+
+SnapshotLogProcessor.prototype.processCodeMove = function(from, to) {
+ this.profile_.moveCode(from, to);
+};
+
+
+SnapshotLogProcessor.prototype.processCodeDelete = function(start) {
+ this.profile_.deleteCode(start);
+};
+
+
+SnapshotLogProcessor.prototype.processSnapshotPosition = function(addr,
pos) {
+ this.serializedEntries_[pos] = this.profile_.findEntry(addr);
+};
+
+
+SnapshotLogProcessor.prototype.processLogFile = function(fileName) {
+ var contents = readFile(fileName);
+ this.processLogChunk(contents);
+};
+
+
+SnapshotLogProcessor.prototype.getSerializedEntryName = function(pos) {
+ var entry = this.serializedEntries_[pos];
+ return entry ? entry.getRawName() : null;
+};
+
+
function TickProcessor(
- cppEntriesProvider, separateIc, ignoreUnknown, stateFilter) {
+ cppEntriesProvider, separateIc, ignoreUnknown, stateFilter,
snapshotLogProcessor) {
devtools.profiler.LogReader.call(this, {
'shared-library': { parsers: [null, parseInt, parseInt],
processor: this.processSharedLibrary },
@@ -72,6 +137,8 @@
processor: this.processCodeMove, backrefs: true },
'code-delete': { parsers: [this.createAddressParser('code')],
processor: this.processCodeDelete, backrefs: true },
+ 'snapshot-pos': { parsers: [this.createAddressParser('code'),
parseInt],
+ processor: this.processSnapshotPosition, backrefs: true },
'tick': { parsers: [this.createAddressParser('code'),
this.createAddressParser('stack'), parseInt, 'var-args'],
processor: this.processTick, backrefs: true },
@@ -95,6 +162,8 @@
this.cppEntriesProvider_ = cppEntriesProvider;
this.ignoreUnknown_ = ignoreUnknown;
this.stateFilter_ = stateFilter;
+ this.snapshotLogProcessor_ = snapshotLogProcessor;
+ this.deserializedEntriesNames_ = [];
var ticks = this.ticks_ =
{ total: 0, unaccounted: 0, excluded: 0, gc: 0 };
@@ -202,6 +271,7 @@
TickProcessor.prototype.processCodeCreation = function(
type, start, size, name) {
+ name = this.deserializedEntriesNames_[start] || name;
var entry = this.profile_.addCode(
this.expandAlias(type), name, start, size);
};
@@ -217,6 +287,14 @@
};
+TickProcessor.prototype.processSnapshotPosition = function(addr, pos) {
+ if (this.snapshotLogProcessor_) {
+ this.deserializedEntriesNames_[addr] =
+ this.snapshotLogProcessor_.getSerializedEntryName(pos);
+ }
+};
+
+
TickProcessor.prototype.includeTick = function(vmState) {
return this.stateFilter_ == null || this.stateFilter_ == vmState;
};
@@ -648,7 +726,9 @@
'--mac': ['platform', 'mac',
'Specify that we are running on Mac OS X platform'],
'--nm': ['nm', 'nm',
- 'Specify the \'nm\' executable to use (e.g. --nm=/my_dir/nm)']
+ 'Specify the \'nm\' executable to use (e.g. --nm=/my_dir/nm)'],
+ '--snapshot-log': ['snapshotLogFileName', 'snapshot.log',
+ 'Specify snapshot log file to use (e.g.
--snapshot-log=snapshot.log)']
};
this.argsDispatch_['--js'] = this.argsDispatch_['-j'];
this.argsDispatch_['--gc'] = this.argsDispatch_['-g'];
@@ -660,6 +740,7 @@
ArgumentsProcessor.DEFAULTS = {
logFileName: 'v8.log',
+ snapshotLogFileName: null,
platform: 'unix',
stateFilter: null,
ignoreUnknown: false,
--
v8-dev mailing list
[email protected]
http://groups.google.com/group/v8-dev
