def _task_name_id_mapping(self, trace):
"""
@brief Parses the provided logging message in order to get the mapping
between the task IDs and names.
@param logging_msg: logging message containing task ID to name mapping
"""
msg = trace.data.split('|')
if msg[0].endswith("PRE"):
self._tm_expected_cnt = int(msg[-1])
self._tm_current_cnt = 0
return
if trace.data[7] == ' ':
msg[0] = msg[0].split(' ')[-1]
else:
msg = msg[1:]
for i in xrange(1, len(msg), 2):
self._tm_current_cnt += 1
callback.invoke(
'task_id_name_callback_fun', {
'host': self._name,
'task_name': msg[i],
'task_id': int(msg[i - 1]),
'msg_counter': self._tm_current_cnt,
'msg_expected': self._tm_expected_cnt
})
def _sequence_error(self, gap, current_time):
self.reset()
callback.invoke('sequence_error_callback_fun', {
'host': self._name,
'missing': gap,
'zgt': current_time
})
def _add_to_zgt_reorder_buffer(self, trace_event):
"""
@brief Adds the trace event to a buffer in which entries are ordered
according to their time stamp from new to old.
The reorder buffer is used to guarantee that the events are processed
in monotonically increasing order w.r.p to their time stamps.
@param trace_event: Trace event to be added to the reorder buffer
@return: If the buffer is full and a new element is added the last
element is removed from the buffer and returned. Otherwise
None is returned.
"""
try:
idx = (i for i, v in enumerate(self._zgt_buffer)
if not v or trace_event.time >= v.time).next()
except StopIteration:
idx = 1
self._init_zgt_reorder_buffer()
callback.invoke(
'zgt_error_callback_fun', {
'host': self._name,
'zgt': trace_event.time,
'info': 'big time gap'
})
for c in self._cores:
c.reset()
logger.debug("for {} tried to add non increasing time stamp "
"to zgt reorder buffer {}".format(
self._name, trace_event.time))
self._zgt_buffer.insert(idx, trace_event)
return self._zgt_buffer.pop()
def checkpoint(self, trace, time, **args):
callback.invoke(
'checkpoint_callback_fun', {
'host': self._host._name,
'id': trace.checkpt_id,
'zgt': time,
'data': trace.checkpt_data
})
def pause(self, time_stamp, next_task_id):
active_task = self._core._active_task
if active_task and active_task is not self:
info = 'pause_task_unexpected_task'
self._core.state_error \
(time_stamp, self.__class__.__name__, self._state, info)
logger.debug(
"pause task unexpected task: expected {}, found {}".format(
active_task._id, self._id))
return
if self._state in [STATE_PREEMPTED, STATE_DELAYED]:
# invalid state transitions
info = 'pause_task'
self._core.state_error \
(time_stamp, self.__class__.__name__, self._state, info)
elif self._state == STATE_INIT:
pass # self transition after reset
elif self._state == STATE_RUNNING:
if self._active_entities:
self._active_entities[-1].pause(time_stamp)
if self._last_overhead_sync_event:
# check if overhead has to be updated
entity, old_ts = self._last_overhead_sync_event
if entity != self:
# the entity corresponds to runnable
if entity._overhead:
entity._overhead.append(time_stamp - old_ts)
overhead = math.ceil(sum(entity._overhead))
callback.invoke(
'rnbl_overhead_callback_fun', {
'host': entity._core._host._name,
'id': entity._id,
'swc': entity._swc_id,
'zgt': time_stamp,
'overhead': overhead,
'task': self._id,
'core': entity._core._id
})
else:
# there is no pre-runnable overhead stored. This
# can only happen after an error or at the start of
# a measurement session
pass
entity._overhead = []
self._core._active_task = None
self._state = STATE_PREEMPTED
callback.invoke(
'task_switch_callback_fun', {
'host': self._core._host._name,
'id': self._id,
'swc': self._swc_id,
'zgt': time_stamp,
'rt': time_stamp - self._time_resumed,
'core': self._core._id,
'next_task': next_task_id
})
def pm_stack_peak(self, trace, time, **args):
callback.invoke(
'pm_stack_peak_callback_fun', {
'host': self._host._name,
'id': trace.task_id,
'zgt': time,
'peak': trace.stackval,
'core': self._id
})
def pm_r_nettime(self, trace, time, **args):
callback.invoke(
'rnbl_netto_rt_callback_fun', {
'host': self._host._name,
'id': trace.rnbl_id,
'swc': trace.swc_id,
'zgt': time,
'netto_rt': trace.total,
'core': self._id
})
def state_error(self, time, _type, old_state, event):
callback.invoke(
'state_error_callback_fun', {
'host': self._host._name,
'zgt': time,
'type': _type,
'state': old_state,
'event': event
})
self._host.reset()
def pm_runtime(self, trace, time, **args):
callback.invoke(
'pm_runtime_callback_fun', {
'host': self._host._name,
'id': trace.rnbl_id,
'cnt': trace.cnt,
'zgt': time,
'total_rt': trace.total,
'max_rt': trace.max,
'core': self._id
})
def trigger_callback(self):
callback.invoke(
'event_received_callback_fun', {
'swc': self.swc_id,
'host': self.host,
'zgt': self.time,
'count': self.seq,
'type': self.type,
'core': self.core,
'data': self.data,
'rid': self.__dict__.get('rnbl_id', '')
})
def start(self, time_stamp):
active_task = self._core._active_task
if self._task is None and active_task is not None:
self._task = active_task
if active_task is not None and self._task != active_task:
# drivers always have to run in the context of the same task
info = 'driver_task_context_start_event'
self._core.state_error \
(time_stamp, self.__class__.__name__, self._state, info)
if active_task is None:
# netto runtime can't be computed since it is not known to
# which task this driver belongs
self._no_task_at_start = True
if self._state in [STATE_INIT, STATE_DELAYED]:
if self._task:
if self._task._active_entities:
self._task._active_entities[-1].pause(time_stamp)
self._task._active_entities.append(self)
if self._last_start is not None:
period = time_stamp - self._last_start
callback.invoke(
'driver_activation_callback_fun', {
'host': self._core._host._name,
'id': self._id,
'swc': self._swc_id,
'zgt': time_stamp,
'periodic_activation': period,
'core': self._core._id
})
self._last_start = time_stamp
self._resumed.append(time_stamp)
self._state = STATE_RUNNING
elif self._state in [STATE_RUNNING, STATE_PREEMPTED]:
# invalid state transition
info = 'start_driver'
self._core.state_error \
(time_stamp, self.__class__.__name__, self._state, info)
def stop(self, time_stamp):
"""
@brief Receives a driver-stop event and updates the state machine
accordingly.
@param time_stamp: Time at which the driver-stop event is received.
"""
if self._state == STATE_INIT:
pass # self transition: can happen after reset() is called
elif self._state == STATE_RUNNING:
active_task = self._core._active_task
if (self._task is not None) and (not self._no_task_at_start
and self._task != active_task):
# runnable always has to run in the context of the same task
info = 'driver_task_context_stop_events'
self._core.state_error \
(time_stamp, self.__class__.__name__, self._state, info)
return
# valid state transition
if self._task:
if self._task._active_entities.pop() is not self:
# unexpected runnable detected
info = 'unexpected_driver_stop_event'
self._core.state_error \
(time_stamp, self.__class__.__name__, self._state, info)
return
elif self._task._active_entities:
self._task._active_entities[-1].resume(time_stamp)
self._preempted.append(time_stamp)
net_rt = [a - b for (a, b) in zip(self._preempted, self._resumed)]
callback.invoke(
'driver_gross_rt_callback_fun', {
'host': self._core._host._name,
'id': self._id,
'swc': self._swc_id,
'zgt': time_stamp,
'gross_rt': time_stamp - self._last_start,
'core': self._core._id
})
if False == self._no_task_at_start:
callback.invoke(
'driver_netto_rt_callback_fun', {
'host': self._core._host._name,
'id': self._id,
'swc': self._swc_id,
'zgt': time_stamp,
'netto_rt': sum(net_rt),
'core': self._core._id
})
self._preempted = []
self._resumed = []
self._no_task_at_start = False
self._state = STATE_DELAYED
elif self._state in [STATE_DELAYED, STATE_PREEMPTED]:
info = 'stop_driver'
self._core.state_error \
(time_stamp, self.__class__.__name__, self._state, info)
def start(self, time_stamp):
"""
@brief Receives a runnable-start event and updates the state machine
accordingly.
@param time_stamp: Time at which the runnable-start event is received.
"""
active_task = self._core._active_task
if self._task is None and active_task is not None:
self._task = active_task
if active_task is not None and self._task != active_task:
# runnables always have to run in the context of the same task
info = 'runnable_task_context'
self._core.state_error \
(time_stamp, self.__class__.__name__, self._state, info)
if active_task is None:
# netto runtime can't be computed since it is not known to
# which task this driver belongs
self._no_task_at_start = False
if self._state in [STATE_INIT, STATE_DELAYED]:
if self._task:
if self._task._active_entities:
self._task._active_entities[-1].pause(time_stamp)
self._task._active_entities.append(self)
if self._last_start is not None:
if self._task and self._task._last_overhead_sync_event:
# compute pre-runnbale overhead
entity, old_ts = self._task._last_overhead_sync_event
dt = time_stamp - old_ts
if entity != self._task and entity._overhead:
# no task switch event between stop event of last
# runnable and start event of this runnable. Over-
# head has to be split.
dt = dt / 2.0
entity._overhead.append(dt)
overhead = math.ceil(sum(entity._overhead))
callback.invoke(
'rnbl_overhead_callback_fun', {
'host': entity._core._host._name,
'id': entity._id,
'swc': entity._swc_id,
'zgt': time_stamp,
'overhead': overhead,
'task': entity._task._id,
'core': entity._core._id
})
entity._overhead = []
self._overhead.append(dt)
period = time_stamp - self._last_start
callback.invoke(
'rnbl_activation_callback_fun', {
'host': self._core._host._name,
'id': self._id,
'swc': self._swc_id,
'zgt': time_stamp,
'periodic_activation': period,
'core': self._core._id
})
self._last_start = time_stamp
self._resumed.append(time_stamp)
self._state = STATE_RUNNING
elif self._state in [STATE_RUNNING, STATE_PREEMPTED]:
# invalid state transition
info = 'start_runnable'
self._core.state_error \
(time_stamp, self.__class__.__name__, self._state, info)
def process(self, trace_event_in):
if trace_event_in.is_log:
try:
if 'task_id_name' == EVENT_MAP[trace_event_in.type]:
self._task_name_id_mapping(trace_event_in)
trace_event_in.trigger_callback()
except AttributeError:
pass
# don't further process log messages since they have a different
# sequence counter
return
trace_event = self._add_to_sequence_buffer(trace_event_in)
if trace_event is None:
# buffer is not full yet
return
if trace_event.time == 0xFFFFFFFFFFFF:
# invalid time stamp detected
callback.invoke(
'zgt_error_callback_fun', {
'host': self._name,
'zgt': trace_event.time,
'info': 'invalid ZGT received'
})
logger.warning("invalid ZGT received")
for c in self._cores:
c.reset()
return
if EVENT_MAP[trace_event.type] == 'zgt_correction':
# ZGT correction event is not added to ZGT reorder buffer
self._zgt_correction = trace_event.zgt_corr_val
logger.debug("ZGT correction on {}: {}".format(
self._name, self._zgt_correction))
return
trace_event.time -= self._zgt_correction
trace_event = self._add_to_zgt_reorder_buffer(trace_event)
if trace_event is None: return
if self._max_zgt > 0:
# check event stream for ZGT jumps
td = abs(trace_event.time - self._max_zgt)
if td > 1000000:
callback.invoke(
'zgt_error_callback_fun', {
'host': self._name,
'zgt': trace_event.time,
'info': 'ZGT jump'
})
for c in self._cores:
c.reset()
trace_event.trigger_callback()
self._max_zgt = max(self._max_zgt, trace_event.time)
if trace_event.sequence_gap > 0:
self._sequence_error(trace_event.sequence_gap, trace_event.time)
return
core = self._cores[trace_event.core]
fun = getattr(core, EVENT_MAP[trace_event.type])
fun(**{'trace': trace_event, 'time': trace_event.time})
def zgt_correction(self, trace, time, **args):
callback.invoke('zgt_correction_callback_fun', {
'zgt': time,
'correction_value': trace.zgt_corr_val
})