Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Added transform info to Tracer Log #43528

Merged
merged 2 commits into from
Dec 12, 2023
Merged

Added transform info to Tracer Log #43528

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
2 commits
Select commit Hold shift + click to select a range
071049e
Added transform info to Tracer Log
Dr15Jones Dec 8, 2023
caf0c49
Added zoom buttons to tracer log viewer
Dr15Jones Dec 8, 2023
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
2 changes: 1 addition & 1 deletion FWCore/Framework/src/ProductResolvers.cc
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -567,7 +567,7 @@ namespace edm {
//This gives a lifetime greater than this call
ParentContext parent(mcc);
mcc_ = ModuleCallingContext(
worker_->description(), index_, ModuleCallingContext::State::kPrefetching, parent, nullptr);
worker_->description(), index_ + 1, ModuleCallingContext::State::kPrefetching, parent, nullptr);

EventTransitionInfo const& info = aux_->eventTransitionInfo();
worker_->doTransformAsync(WaitingTaskHolder(*waitTask.group(), t),
Expand Down
2 changes: 1 addition & 1 deletion FWCore/Framework/src/WorkerT.cc
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -252,7 +252,7 @@ namespace edm {
ServiceRegistry::Operate guard(weakToken.lock());

ModuleCallingContext mcc(
&module_->moduleDescription(), iTransformIndex, ModuleCallingContext::State::kRunning, iParent, nullptr);
&module_->moduleDescription(), iTransformIndex + 1, ModuleCallingContext::State::kRunning, iParent, nullptr);
module_->doTransformAsync(iTask, iTransformIndex, iEvent, activityRegistry(), mcc, weakToken);
} catch (...) {
iTask.doneWaiting(std::current_exception());
Expand Down
4 changes: 4 additions & 0 deletions FWCore/Services/plugins/monitor_file_utilities.h
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -19,6 +19,10 @@ namespace edm::service::monitor_file_utilities {

inline auto module_id(edm::ESModuleCallingContext const& mcc) { return mcc.componentDescription()->id_; }

inline auto module_callid(edm::ModuleCallingContext const& mcc) { return mcc.callID(); }

inline auto module_callid(edm::ESModuleCallingContext const& mcc) { return mcc.callID(); }

template <typename T>
std::enable_if_t<std::is_integral<T>::value> concatenate(std::ostream& os, T const t) {
os << ' ' << t;
Expand Down
230 changes: 135 additions & 95 deletions FWCore/Services/plugins/tracer_setupFile.cc
View file
Open in desktop

Large diffs are not rendered by default.

103 changes: 54 additions & 49 deletions FWCore/Services/scripts/edmTracerCompactLogViewer.py
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -54,14 +54,14 @@ def printHelp():

#these values must match the enum class Phase in tracer_setupFile.cc
class Phase (object):
destruction = -15
destruction = -16
endJob = -12
endStream = -11
writeProcessBlock = -10
endProcessBlock = -9
globalWriteRun = -7
globalEndRun = -6
streamEndRun = -4
streamEndRun = -5
globalWriteLumi = -4
globalEndLumi = -3
streamEndLumi = -2
Expand Down Expand Up @@ -457,28 +457,34 @@ def __init__(self, payload, moduleNames):
self.index = int(payload[1])
self.moduleID = int(payload[2])
self.moduleName = moduleNames[self.moduleID]
self.requestingModuleID = int(payload[3])
self.callID = int(payload[3])
self.requestingModuleID = int(payload[4])
self.requestingCallID = int(payload[5])
self.requestingModuleName = None
if self.requestingModuleID != 0:
self.requestingModuleName = moduleNames[self.requestingModuleID]
self.time = int(payload[4])
self.time = int(payload[6])
def baseIndentLevel(self):
return transitionIndentLevel(self.transition)
def textPrefix(self, context):
indent = 0
if self.requestingModuleID != 0:
indent = context[(self.transition, self.index, self.requestingModuleID)]
context[(self.transition, self.index, self.moduleID)] = indent+1
indent = context[(self.transition, self.index, self.requestingModuleID, self.requestingCallID)]
context[(self.transition, self.index, self.moduleID, self.callID)] = indent+1
return textPrefix_(self.time, indent+1+self.baseIndentLevel())
def textPostfix(self):
return f'{self.moduleName} during {transitionName(self.transition)} : id={self.index}'
def textIfTransform(self):
if self.callID:
return f' transform {self.callID-1}'
return ''
def text(self, context):
return f'{self.textPrefix(context)} {self.textSpecial()}: {self.textPostfix()}'
return f'{self.textPrefix(context)} {self.textSpecial()}{self.textIfTransform()}: {self.textPostfix()}'
def _preJson(self, activity, counter, data, mayUseTemp = False):
index = self.index
found = False
if mayUseTemp:
compare = lambda x: x['type'] == self.transition and x['id'] == self.index and x['mod'] == self.moduleID and (x['act'] == Activity.temporary or x['act'] == Activity.externalWork)
compare = lambda x: x['type'] == self.transition and x['id'] == self.index and x['mod'] == self.moduleID and x['call'] == self.callID and (x['act'] == Activity.temporary or x['act'] == Activity.externalWork)
if transitionIsGlobal(self.transition):
item,slot = data.findLastInModGlobals(index, self.moduleID, compare)
else:
Expand All @@ -494,10 +500,10 @@ def _preJson(self, activity, counter, data, mayUseTemp = False):
slot = data.findOpenSlotInModGlobals(index, self.moduleID)
else:
slot = data.findOpenSlotInModStreams(index, self.moduleID)
slot.append(jsonModuleTransition(type=self.transition, id=self.index, modID=self.moduleID, activity=activity, start=self.time))
slot.append(jsonModuleTransition(type=self.transition, id=self.index, modID=self.moduleID, callID=self.callID, activity=activity, start=self.time))
return slot[-1]
def _postJson(self, counter, data, injectAfter = None):
compare = lambda x: x['id'] == self.index and x['mod'] == self.moduleID and x['type'] == self.transition
compare = lambda x: x['id'] == self.index and x['mod'] == self.moduleID and x['call'] == self.callID and x['type'] == self.transition
index = self.index
if transitionIsGlobal(self.transition):
item,slot = data.findLastInModGlobals(index, self.moduleID, compare)
Expand Down Expand Up @@ -552,7 +558,7 @@ def textSpecial(self):
def jsonInfo(self, counter, data):
if self._moduleCentric:
#inject a dummy at end of the same slot to guarantee module run is in that slot
return self._postJson(counter, data, jsonModuleTransition(type=self.transition, id=self.index, modID=self.moduleID, activity=Activity.temporary, start=self.time))
return self._postJson(counter, data, jsonModuleTransition(type=self.transition, id=self.index, modID=self.moduleID, callID=self.callID, activity=Activity.temporary, start=self.time))
pass

class PreEDModuleAcquireParser(EDModuleTransitionParser):
Expand All @@ -573,7 +579,7 @@ def textSpecial(self):
def jsonInfo(self, counter, data):
if self._moduleCentric:
#inject an external work at end of the same slot to guarantee module run is in that slot
return self._postJson(counter, data, jsonModuleTransition(type=self.transition, id=self.index, modID=self.moduleID, activity=Activity.externalWork, start=self.time))
return self._postJson(counter, data, jsonModuleTransition(type=self.transition, id=self.index, modID=self.moduleID, callID=self.callID, activity=Activity.externalWork, start=self.time))
return self._postJson(counter,data)

class PreEDModuleEventDelayedGetParser(EDModuleTransitionParser):
Expand Down Expand Up @@ -620,18 +626,19 @@ def __init__(self, payload, moduleNames, esModuleNames, recordNames):
self.recordName = recordNames[self.recordID]
self.callID = int(payload[4])
self.requestingModuleID = int(payload[5])
self.requestingCallID = int(payload[6])
self.requestingModuleName = None
if self.requestingModuleID < 0 :
self.requestingModuleName = esModuleNames[-1*self.requestingModuleID]
else:
self.requestingModuleName = moduleNames[self.requestingModuleID]
self.time = int(payload[6])
self.time = int(payload[7])
def baseIndentLevel(self):
return transitionIndentLevel(self.transition)
def textPrefix(self, context):
indent = 0
indent = context[(self.transition, self.index, self.requestingModuleID)]
context[(self.transition, self.index, -1*self.moduleID)] = indent+1
indent = context[(self.transition, self.index, self.requestingModuleID, self.requestingCallID)]
context[(self.transition, self.index, -1*self.moduleID, self.callID)] = indent+1
return textPrefix_(self.time, indent+1+self.baseIndentLevel())
def textPostfix(self):
return f'esmodule {self.moduleName} in record {self.recordName} during {transitionName(self.transition)} : id={self.index}'
Expand All @@ -643,11 +650,10 @@ def _preJson(self, activity, counter, data):
slot = data.findOpenSlotInModGlobals(index, -1*self.moduleID)
else:
slot = data.findOpenSlotInModStreams(index, -1*self.moduleID)
slot.append(jsonModuleTransition(type=self.transition, id=self.index, modID=-1*self.moduleID, activity=activity, start=self.time))
slot[-1]['callID']=self.callID
slot.append(jsonModuleTransition(type=self.transition, id=self.index, modID=-1*self.moduleID, callID=self.callID, activity=activity, start=self.time))
return slot[-1]
def _postJson(self, counter, data):
compare = lambda x: x['id'] == self.index and x['mod'] == -1*self.moduleID and x.get('callID',0) == self.callID
compare = lambda x: x['id'] == self.index and x['mod'] == -1*self.moduleID and x['call'] == self.callID
index = self.index
if transitionIsGlobal(self.transition):
item,s = data.findLastInModGlobals(index, -1*self.moduleID, compare)
Expand All @@ -657,7 +663,6 @@ def _postJson(self, counter, data):
print(f"failed to find {-1*self.moduleID} for {self.transition} in {self.index}")
return
item["finish"]=self.time*kMicroToSec
del item['callID']


class PreESModuleTransitionParser(ESModuleTransitionParser):
Expand Down Expand Up @@ -978,8 +983,8 @@ def findLastInModStreams(self, index, modID, comparer):
def jsonTransition(type, id, sync, start, finish, isSrc=False):
return {"type": type, "id": id, "sync": sync, "start": start*kMicroToSec, "finish": finish*kMicroToSec, "isSrc":isSrc}

def jsonModuleTransition(type, id, modID, activity, start, finish=0):
return {"type": type, "id": id, "mod": modID, "act": activity, "start": start*kMicroToSec, "finish": finish*kMicroToSec}
def jsonModuleTransition(type, id, modID, callID, activity, start, finish=0):
return {"type": type, "id": id, "mod": modID, "call": callID, "act": activity, "start": start*kMicroToSec, "finish": finish*kMicroToSec}

def startTime(x):
return x["start"]
Expand Down Expand Up @@ -1085,11 +1090,11 @@ def incr(t):
f'F {Phase.startTracing} 0 0 0 0 {incr(t)}',
f'S {Phase.construction} 0 {incr(t)}',
f's {Phase.construction} 0 {incr(t)}3',
f'M {Phase.construction} 0 1 0 {incr(t)}',
f'm {Phase.construction} 0 1 0 {incr(t)}',
f'M {Phase.construction} 0 1 0 0 0 {incr(t)}',
f'm {Phase.construction} 0 1 0 0 0 {incr(t)}',
f'F {Phase.beginJob} 0 0 0 0 {incr(t)}',
f'M {Phase.beginJob} 0 1 0 {incr(t)}',
f'm {Phase.beginJob} 0 1 0 {incr(t)}',
f'M {Phase.beginJob} 0 1 0 0 0 {incr(t)}',
f'm {Phase.beginJob} 0 1 0 0 0 {incr(t)}',
f'f {Phase.beginJob} 0 0 0 0 {incr(t)}',
f'F {Phase.beginProcessBlock} 0 0 0 0 {incr(t)}',
f'f {Phase.beginProcessBlock} 0 0 0 0 {incr(t)}',
Expand All @@ -1103,33 +1108,33 @@ def incr(t):
f'S {Phase.getNextTransition} {incr(t)}',
f's {Phase.getNextTransition} {incr(t)}',
f'F {Phase.globalBeginRun} 0 1 0 0 {incr(t)}',
f'P {Phase.globalBeginRun} 0 1 0 {incr(t)}',
f'p {Phase.globalBeginRun} 0 1 0 {incr(t)}',
f'M {Phase.globalBeginRun} 0 1 0 {incr(t)}',
f'm {Phase.globalBeginRun} 0 1 0 {incr(t)}',
f'P {Phase.globalBeginRun} 0 1 0 0 0 {incr(t)}',
f'p {Phase.globalBeginRun} 0 1 0 0 0 {incr(t)}',
f'M {Phase.globalBeginRun} 0 1 0 0 0 {incr(t)}',
f'm {Phase.globalBeginRun} 0 1 0 0 0 {incr(t)}',
f'f {Phase.globalBeginRun} 0 1 0 0 {incr(t)}',
f'F {Phase.esSyncEnqueue} -1 1 1 0 {incr(t)}',
f'F {Phase.esSync} -1 1 1 0 {incr(t)}',
f'f {Phase.esSync} -1 1 1 0 {incr(t)}',
f'S {Phase.getNextTransition} {incr(t)}',
f's {Phase.getNextTransition} {incr(t)}',
f'F {Phase.streamBeginRun} 0 1 0 0 {incr(t)}',
f'M {Phase.streamBeginRun} 0 1 0 {incr(t)}',
f'm {Phase.streamBeginRun} 0 1 0 {incr(t)}',
f'M {Phase.streamBeginRun} 0 1 0 0 0 {incr(t)}',
f'm {Phase.streamBeginRun} 0 1 0 0 0 {incr(t)}',
f'f {Phase.streamBeginRun} 0 1 0 0 {incr(t)}',
f'F {Phase.streamBeginRun} 1 1 0 0 {incr(t)}',
f'M {Phase.streamBeginRun} 1 1 0 {incr(t)}',
f'm {Phase.streamBeginRun} 1 1 0 {incr(t)}',
f'M {Phase.streamBeginRun} 1 1 0 0 0 {incr(t)}',
f'm {Phase.streamBeginRun} 1 1 0 0 0 {incr(t)}',
f'f {Phase.streamBeginRun} 1 1 0 0 {incr(t)}',
f'S {Phase.globalBeginLumi} 0 {incr(t)}',
f's {Phase.globalBeginLumi} 0 {incr(t)}',
f'S {Phase.getNextTransition} {incr(t)}',
f's {Phase.getNextTransition} {incr(t)}',
f'F {Phase.globalBeginLumi} 0 1 1 0 {incr(t)}',
f'P {Phase.globalBeginLumi} 0 1 0 {incr(t)}',
f'p {Phase.globalBeginLumi} 0 1 0 {incr(t)}',
f'M {Phase.globalBeginLumi} 0 1 0 {incr(t)}',
f'm {Phase.globalBeginLumi} 0 1 0 {incr(t)}',
f'P {Phase.globalBeginLumi} 0 1 0 0 0 {incr(t)}',
f'p {Phase.globalBeginLumi} 0 1 0 0 0 {incr(t)}',
f'M {Phase.globalBeginLumi} 0 1 0 0 0 {incr(t)}',
f'm {Phase.globalBeginLumi} 0 1 0 0 0 {incr(t)}',
f'f {Phase.globalBeginLumi} 0 1 1 0 {incr(t)}',
f'F {Phase.streamBeginLumi} 0 1 1 0 {incr(t)}',
f'f {Phase.streamBeginLumi} 0 1 1 0 {incr(t)}',
Expand All @@ -1143,18 +1148,18 @@ def incr(t):
f'S {Phase.Event} 1 {incr(t)}',
f's {Phase.Event} 1 {incr(t)}',
f'F {Phase.Event} 1 1 1 2 {incr(t)}',
f'P {Phase.Event} 0 1 0 {incr(t)}',
f'p {Phase.Event} 0 1 0 {incr(t)}',
f'Q {Phase.Event} 0 1 1 0 1 {incr(t)}',
f'q {Phase.Event} 0 1 1 0 1 {incr(t)}',
f'N {Phase.Event} 0 1 1 0 1 {incr(t)}',
f'n {Phase.Event} 0 1 1 0 1 {incr(t)}',
f'P {Phase.Event} 1 1 0 {incr(t)}',
f'p {Phase.Event} 1 1 0 {incr(t)}',
f'M {Phase.Event} 0 1 0 {incr(t)}',
f'M {Phase.Event} 1 1 0 {incr(t)}',
f'm {Phase.Event} 1 1 0 {incr(t)}',
f'm {Phase.Event} 0 1 0 {incr(t)}',
f'P {Phase.Event} 0 1 0 0 0 {incr(t)}',
f'p {Phase.Event} 0 1 0 0 0 {incr(t)}',
f'Q {Phase.Event} 0 1 1 0 1 0 {incr(t)}',
f'q {Phase.Event} 0 1 1 0 1 0 {incr(t)}',
f'N {Phase.Event} 0 1 1 0 1 0 {incr(t)}',
f'n {Phase.Event} 0 1 1 0 1 0 {incr(t)}',
f'P {Phase.Event} 1 1 0 0 0 {incr(t)}',
f'p {Phase.Event} 1 1 0 0 0 {incr(t)}',
f'M {Phase.Event} 0 1 0 0 0 {incr(t)}',
f'M {Phase.Event} 1 1 0 0 0 {incr(t)}',
f'm {Phase.Event} 1 1 0 0 0 {incr(t)}',
f'm {Phase.Event} 0 1 0 0 0 {incr(t)}',
f'f {Phase.Event} 0 1 1 1 {incr(t)}',
f'f {Phase.Event} 1 1 1 2 {incr(t)}'])

Expand Down
5 changes: 5 additions & 0 deletions FWCore/Services/web/index.html
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -21,6 +21,11 @@
<div class="selected">
<p id="selected_paragraph">Selected:</p>
</div>
<div class="controls">
<button id="zoom_out">--&gt; &lt;--</button>
<button id="zoom_in">&lt;-- --&gt;</button>
<p>&lt;CTRL&gt;+scroll to zoom</p>
</div>
</div>
</body>
</html>
5 changes: 5 additions & 0 deletions FWCore/Services/web/transitions.css
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -77,4 +77,9 @@ body {
grid-column: 1/11;
grid-row: 10;
height: 50px;
}

.controls {
grid-column: 1/1;
grid-row: 9;
}
31 changes: 29 additions & 2 deletions FWCore/Services/web/transitions.js
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -104,6 +104,8 @@ window.onload = () => {
const time_view = document.getElementById('time_view');
const time_context = time_view.getContext('2d');
const selected_view = document.getElementById('selected_paragraph');
const zoom_in_button = document.getElementById('zoom_in');
const zoom_out_button = document.getElementById('zoom_out');
let selected_item = null;
selected_view.innerHTML = "Selected: [click on box in graph]";
let mouse_is_down = false;
Expand Down Expand Up @@ -300,7 +302,7 @@ window.onload = () => {
//console.log(xDiff, original, minVisibleTime);
const timeEnd = (max_graph_width)/kInitPixelsPerSecond/timeZoomFactor+minVisibleTime;
if (timeEnd > kEndTime) {
minVisibleTime = kEndTime - max_graph_width*kInitPixelsPerSecond*timeZoomFactor;
minVisibleTime = kEndTime - max_graph_width/kInitPixelsPerSecond/timeZoomFactor;
}
if (minVisibleTime < 0) {
minVisibleTime = 0;
Expand Down Expand Up @@ -387,7 +389,11 @@ window.onload = () => {
+" lumi: "+item.sync[1]+ " event: "+item.sync[2]+" start: "+item.start.toFixed(6)+"s finish:"+item.finish.toFixed(6)+"s duration: "+duration(item.finish-item.start);
}
} else {
selected_view.innerHTML ="Selected: module : "+item.mod+" "+moduleIdToName(item.mod)+ " while "+activityToName[item.act]+" "+typeToName[item.type+kTypeOffset] +" start: "+item.start.toFixed(6)+"s finish: "+item.finish.toFixed(6)+"s duration: "+duration(item.finish-item.start);
let transform = '';
if (item.call != 0 && item.mod > 0) {
transform = ' transform '
}
selected_view.innerHTML ="Selected: module : "+item.mod+" "+moduleIdToName(item.mod)+ " while "+activityToName[item.act]+transform+" "+typeToName[item.type+kTypeOffset] +" start: "+item.start.toFixed(6)+"s finish: "+item.finish.toFixed(6)+"s duration: "+duration(item.finish-item.start);
}
}
function doSelection(items, x) {
Expand Down Expand Up @@ -530,6 +536,27 @@ window.onload = () => {
time_view.addEventListener('mouseout', time_onMouseOut)
time_view.addEventListener('wheel', time_onWheel);

function zoom_in_click(event) {
const zoom = 1.1;
const originalScale = 1. / timeZoomFactor / kInitPixelsPerSecond;
timeZoomFactor *= zoom;
const newScale = 1. / timeZoomFactor / kInitPixelsPerSecond;
//Keep the center of the view at the same time and change zoom around that point
minVisibleTime = minVisibleTime + max_graph_width/2*(originalScale-newScale);
drawGraph();
}
function zoom_out_click(event) {
const zoom = 0.909;
const originalScale = 1. / timeZoomFactor / kInitPixelsPerSecond;
timeZoomFactor *= zoom;
const newScale = 1. / timeZoomFactor / kInitPixelsPerSecond;
//Keep the center of the view at the same time and change zoom around that point
minVisibleTime = minVisibleTime + max_graph_width/2*(originalScale-newScale);
drawGraph();
}
zoom_in_button.addEventListener("click", zoom_in_click);
zoom_out_button.addEventListener("click", zoom_out_click);

function name_onWheel(event) {
let offset = 0;
graph_translate(0, -1*event.deltaY);
Expand Down