def _overwrite_sim_log_log(log_notification_filter):
if log_notification_filter == 'all':
_filter = 'all'
elif isinstance(log_notification_filter, str):
_filter = DEFAULT_LOG_NOTIFICATION_FILTER
_filter.append(log_notification_filter)
elif isinstance(log_notification_filter, list):
_filter = DEFAULT_LOG_NOTIFICATION_FILTER + log_notification_filter
else:
raise RuntimeError('unsupported type for log_notification_filter')
sim_log = SimLog.SimLog()
sim_log.original_log = sim_log.log
def _new_log(self, simlog, content):
self.original_log(simlog, content)
# content is expected to be updated adding _asn, _type
assert '_asn' in content
assert '_type' in content
if ((_filter == 'all') or (content['_type'] in _filter)):
eel.notifyLogEvent(content)
else:
pass
sim_log.log = types.MethodType(_new_log, sim_log)
def test_log(log_notification_filter, log_events):
config = backend.sim.get_default_config()
settings = config['settings']['regular']
for key in config['settings']['combination']:
settings[key] = config['settings']['combination'][key][0]
# use a short exec_numSlotframesPerRun so that this test ends in a
# short time
settings['exec_numSlotframesPerRun'] = 100
# invoke start()
sim_greenlet = gevent.spawn(backend.sim.start, settings,
log_notification_filter)
gevent.sleep(backend.sim.GEVENT_SLEEP_SECONDS_IN_SIM_ENGINE)
assert backend.sim._sim_engine is not None
# find the log file for the simulation
log_file_path = SimLog.SimLog().log_output_file.name
assert log_file_path is not None
# run the simulation until it ends
gevent.joinall([sim_greenlet])
# _sim_engine should have gone
assert backend.sim._sim_engine is None
if log_notification_filter == 'all':
# we should have all the log items notified which have been
# generated during the simulation. to make the test simple, we
# compare only the number of log events with the number of
# lines of the log file
num_log_events = len([
event for event in log_events
if event['_type'].startswith('_backend') is False
])
# subtract by one because the very first line of the log file
# is the 'config' type, that is not recorded through
# SimLog.log() method.
num_log_lines = sum(1 for line in open(log_file_path, 'r')) - 1
assert num_log_events == num_log_lines
else:
# only log types specified in the filter can be notified in
# addition to the default log types which are defined in
# sim.py
_filter = (
log_notification_filter +
backend.sim.DEFAULT_LOG_NOTIFICATION_FILTER +
['_backend.tick.minute'] # special log event for GUI
)
_log_types = []
for event in log_events:
assert event['_type'] in _filter
if event['_type'] not in _log_types:
_log_types.append(event['_type'])
# we should always have logs of the types specifined by
# DEFAULT_LOG_NOTIFICATION_FILTER
for default_log_type in backend.sim.DEFAULT_LOG_NOTIFICATION_FILTER:
assert default_log_type in _log_types
def _destroy_sim():
global _sim_engine
global _elapsed_minutes
sim_log = SimLog.SimLog()
connectivity = _sim_engine.connectivity
sim_settings = _sim_engine.settings
_sim_engine.destroy()
sim_log.destroy()
connectivity.destroy()
sim_settings.destroy()
_sim_engine = None
_elapsed_minutes = 0
def test_tsch_clock(sim_engine, with_keep_alive):
diff_config = {
'exec_numMotes': 3,
'app_pkPeriod': 0,
'app_pkPeriodVar': 0,
'tsch_probBcast_ebProb': 0,
'roupe_daoPeriod': 0,
'exec_numSlotframesPerRun': 100,
'conn_class': 'Linear'
}
if with_keep_alive is True:
diff_config['tsch_keep_alive_interval'] = 10
else:
diff_config['tsch_keep_alive_interval'] = 0
diff_config['exec_randomSeed'] = 7263092949079992026
sim_engine = sim_engine(diff_config=diff_config,
force_initial_routing_and_scheduling_state=True)
log_type_clock_diff = 'clock_diff'
sim_log = SimLog.SimLog()
# static values
macTsRxWait = 0.00222 # 2,220 usec defined for 2.4 GHz by IEEE 802.15.4-2015
# shorthands
root = sim_engine.motes[0]
hop_1 = sim_engine.motes[1]
hop_2 = sim_engine.motes[2]
slot_duration = sim_engine.settings.tsch_slotDuration
slotframe_length = sim_engine.settings.tsch_slotframeLength
max_drift = sim_engine.settings.tsch_clock_max_drift_ppm
clock_interval = 1.0 / sim_engine.settings.tsch_clock_frequency
guard_time = (old_div(macTsRxWait, 2)) - (2 * clock_interval)
def _check_and_log_clock_drift():
# without keep-alive, difference between the two clocks is
# getting bigger and bigger. but, it should be within
# -max_drift*2 and +max_drift*2 with offset in the range
# between 0 and clock_interval
diff_1 = hop_1.tsch.clock.get_drift() - root.tsch.clock.get_drift()
diff_2 = hop_2.tsch.clock.get_drift() - hop_1.tsch.clock.get_drift()
elapsed_time = sim_engine.getAsn() * slot_duration
lower_bound_drift = (elapsed_time * (-1 * max_drift * 2) + 0)
upper_bound_drift = (elapsed_time * (+1 * max_drift * 2) +
clock_interval)
assert lower_bound_drift < diff_1
assert diff_1 < upper_bound_drift
assert lower_bound_drift < diff_2
assert diff_2 < upper_bound_drift
if with_keep_alive:
assert abs(diff_1) < guard_time
assert abs(diff_2) < guard_time
# custom log
for mote_id, diff in zip([hop_1.id, hop_2.id], [diff_1, diff_2]):
sim_log.log(
{
'type': log_type_clock_diff,
'keys': ['_mote_id', 'value']
}, {
'_mote_id': mote_id,
'value': diff
})
_schedule_clock_drift_checking_and_logging()
def _schedule_clock_drift_checking_and_logging():
sim_engine.scheduleAtAsn(asn=sim_engine.getAsn() +
(1.0 / slot_duration),
cb=_check_and_log_clock_drift,
uniqueTag='check_and_log_clock_drift',
intraSlotOrder=d.INTRASLOTORDER_ADMINTASKS)
_schedule_clock_drift_checking_and_logging()
u.run_until_end(sim_engine)
keep_alive_logs = [
log for log in u.read_log_file([SimLog.LOG_TSCH_TXDONE['type']])
if (log['packet']['type'] == d.PKT_TYPE_KEEP_ALIVE)
]
if with_keep_alive is True:
assert len(keep_alive_logs) > 0
else:
assert len(keep_alive_logs) == 0
def destroy_all_singletons(engine):
engine.destroy()
engine.connectivity.destroy()
engine.settings.destroy()
SimLog.SimLog().destroy()
def runSimCombinations(params):
"""
Runs simulations for all combinations of simulation settings.
This function may run independently on different CPUs.
"""
cpuID = params['cpuID']
pid = params['pid']
numRuns = params['numRuns']
first_run = params['first_run']
verbose = params['verbose']
config_data = params['config_data']
simconfig = SimConfig.SimConfig(configdata=config_data)
# record simulation start time
simStartTime = time.time()
# compute all the simulation parameter combinations
combinationKeys = simconfig.settings.combination.keys()
simParams = []
for p in itertools.product(
*[simconfig.settings.combination[k] for k in combinationKeys]):
simParam = {}
for (k, v) in zip(combinationKeys, p):
simParam[k] = v
for (k, v) in simconfig.settings.regular.items():
if k not in simParam:
simParam[k] = v
simParams += [simParam]
# run a simulation for each set of simParams
for (simParamNum, simParam) in enumerate(simParams):
# run the simulation runs
for run_id in range(first_run, first_run + numRuns):
# printOrLog
output = 'parameters {0}/{1}, run {2}/{3}'.format(
simParamNum + 1, len(simParams), run_id + 1 - first_run,
numRuns)
printOrLog(cpuID, pid, output, verbose)
# create singletons
settings = SimSettings.SimSettings(cpuID=cpuID,
run_id=run_id,
**simParam)
settings.setLogDirectory(simconfig.get_log_directory_name())
settings.setCombinationKeys(combinationKeys)
simlog = SimLog.SimLog()
simlog.set_log_filters(simconfig.logging)
parentlog = ParentLogs.ParentLogs()
parentlog.set_log_filters(simconfig.logging)
simengine = SimEngine.SimEngine(run_id=run_id, verbose=verbose)
# start simulation run
simengine.start()
# wait for simulation run to end
simengine.join()
# destroy singletons
simlog.destroy()
#parentlog.destroy()
simengine.destroy()
Connectivity.Connectivity().destroy()
settings.destroy() # destroy last, Connectivity needs it
# printOrLog
output = 'simulation ended after {0:.0f}s ({1} runs).'.format(
time.time() - simStartTime, numRuns * len(simParams))
printOrLog(cpuID, pid, output, verbose)
def test_random_seed(sim_engine, fixture_random_seed):
diff_config = {
'exec_randomSeed': fixture_random_seed,
'exec_numSlotframesPerRun': 100
}
log_file_hashes = []
# compare logs out of 10 runs
results = []
for i in range(10):
sha2 = hashlib.sha256()
if fixture_random_seed == 'range':
# ues i for 'exec_randomSeed':
diff_config['exec_randomSeed'] = i
engine = sim_engine(diff_config=diff_config)
log = SimLog.SimLog()
settings = SimSettings.SimSettings()
# run the simulator
u.run_until_end(engine)
# save the log file name and a random seed for later use
log_file_name = settings.getOutputFile()
logs = u.read_log_file(
filter=[SimLog.LOG_SIMULATOR_RANDOM_SEED['type']])
assert len(logs) == 1
random_seed = logs[0]['value']
# destroy singletons for the next run
engine.connectivity.destroy()
engine.destroy()
log.destroy()
settings.destroy()
# this is for test purpose only; reset SimConfig._startTime
SimConfig.SimConfig._startTime = None
# compute the file hash
with open(log_file_name, 'r') as f:
# skip the very first line in the log file, which has
# 'logDirectory' etnry and it should have a unique value even if a
# certain integer is specified for 'exec_randSeed'
f.readline()
sha2.update(f.read().encode('utf-8'))
results.append({
'log_file_name': log_file_name,
'sha256': sha2.hexdigest(),
'random_seed': random_seed
})
# collect hash values and print debug messages
seed_list = []
hash_list = []
for entry in results:
seed_list.append(entry['random_seed'])
hash_list.append(entry['sha256'])
# print hash values, which will be printed out when this test fails
print('{0} {1}'.format(entry['sha256'], entry['log_file_name']))
# compare hash values and random seeds
if fixture_random_seed in ['random', 'range', 'context']:
# different seed values should have been used
assert (sum([i == j
for i, j in zip(seed_list[:-1], seed_list[1:])]) == 0)
# hash values shouldn't be the same
assert (sum([i == j
for i, j in zip(hash_list[:-1], hash_list[1:])]) == 0)
else:
# the random seed values are found in the log files should be identical
assert (sum([i != j
for i, j in zip(seed_list[:-1], seed_list[1:])]) == 0)
# hash values should be identical as well
assert (sum([i != j
for i, j in zip(hash_list[:-1], hash_list[1:])]) == 0)
def test_retransmission_backoff_algorithm(sim_engine, cell_type):
sim_engine = sim_engine(
diff_config={
'exec_numSlotframesPerRun': 10000,
'exec_numMotes': 2,
'app_pkPeriod': 0,
'secjoin_enabled': False,
'tsch_keep_alive_interval': 0
})
sim_log = SimLog.SimLog()
# filter logs to make this test faster; we need only SimLog.LOG_TSCH_TXDONE
sim_log.set_log_filters([SimLog.LOG_TSCH_TXDONE['type']])
# for quick access
root = sim_engine.motes[0]
hop_1 = sim_engine.motes[1]
slotframe_length = sim_engine.settings.tsch_slotframeLength
# increase TSCH_MAXTXRETRIES so that we can have enough retransmission
# samples to validate
d.TSCH_MAXTXRETRIES = 100
#== test setup ==
u.run_until_everyone_joined(sim_engine)
# make hop_1 ready to send an application packet
assert hop_1.rpl.dodagId is None
dio = root.rpl._create_DIO()
dio['mac'] = {'srcMac': root.get_mac_addr()}
hop_1.rpl.action_receiveDIO(dio)
assert hop_1.rpl.dodagId is not None
# make root ignore all the incoming frame for this test
def ignoreRx(self, packet, channel):
self.waitingFor = None
isACKed = False
return isACKed
root.tsch.rxDone = types.MethodType(ignoreRx, root.tsch)
if cell_type == 'dedicated-cell':
# allocate one TX=1/RX=1/SHARED=1 cell to the motes as their dedicate cell.
cellOptions = [d.CELLOPTION_TX, d.CELLOPTION_RX, d.CELLOPTION_SHARED]
assert len(root.tsch.get_cells(hop_1.get_mac_addr())) == 0
root.tsch.addCell(1, 1, hop_1.get_mac_addr(), cellOptions)
assert len(root.tsch.get_cells(hop_1.get_mac_addr())) == 1
assert len(hop_1.tsch.get_cells(root.get_mac_addr())) == 0
hop_1.tsch.addCell(1, 1, root.get_mac_addr(), cellOptions)
assert len(hop_1.tsch.get_cells(root.get_mac_addr())) == 1
# make sure hop_1 send a application packet when the simulator starts
hop_1.tsch.txQueue = []
hop_1.app._send_a_single_packet()
assert len(hop_1.tsch.txQueue) == 1
#== start test ==
asn_starting_test = sim_engine.getAsn()
# run the simulator until hop_1 drops the packet or the simulation ends
def drop_packet(self, packet, reason):
if packet['type'] == d.PKT_TYPE_DATA:
# pause the simulator
sim_engine.pauseAtAsn(sim_engine.getAsn() + 1)
hop_1.drop_packet = types.MethodType(drop_packet, hop_1)
u.run_until_end(sim_engine)
# confirm
# - hop_1 sent the application packet to the root
# - retransmission backoff worked
logs = u.read_log_file(filter=[SimLog.LOG_TSCH_TXDONE['type']],
after_asn=asn_starting_test)
app_data_tx_logs = []
for log in logs:
if ((log['_mote_id'] == hop_1.id)
and (root.is_my_mac_addr(log['packet']['mac']['dstMac']))
and (log['packet']['type'] == d.PKT_TYPE_DATA)):
app_data_tx_logs.append(log)
assert len(app_data_tx_logs) == 1 + d.TSCH_MAXTXRETRIES
# all transmission should have happened only on the dedicated cell if it's
# available (it shouldn't transmit a unicast frame to the root on the
# minimal (shared) cell.
if cell_type == 'dedicated-cell':
_cell = hop_1.tsch.get_cells(root.get_mac_addr())[0]
expected_cell_offset = _cell.slot_offset
elif cell_type == 'shared-cell':
expected_cell_offset = 0 # the minimal (shared) cell
else:
raise NotImplementedError()
for log in app_data_tx_logs:
slot_offset = log['_asn'] % slotframe_length
assert slot_offset == expected_cell_offset
# retransmission should be performed after backoff wait; we should see gaps
# between consecutive retransmissions. If all the gaps are 101 slots, that
# is, one slotframe, this means there was no backoff wait between
# transmissions.
timestamps = [log['_asn'] for log in app_data_tx_logs]
diffs = map(lambda x: x[1] - x[0], zip(timestamps[:-1], timestamps[1:]))
assert len([diff for diff in diffs if diff != slotframe_length]) > 0
def start(settings, log_notification_filter='all', stderr_redirect=True):
global _sim_engine
global _elapsed_minutes
sim_settings = None
sim_log = None
ret_val = {}
if _sim_engine is not None:
return {
'status': RETURN_STATUS_FAILURE,
'message': 'SimEngine has been started already',
'trace': None
}
try:
sim_settings = SimSettings.SimSettings(
cpuID=0, run_id=0, log_root_dir=backend.SIM_DATA_PATH, **settings)
start_time = time.time()
sim_settings.setLogDirectory('{0}-{1:03d}'.format(
time.strftime("%Y%m%d-%H%M%S", time.localtime(start_time)),
int(round(start_time * 1000)) % 1000))
sim_settings.setCombinationKeys(DUMMY_COMBINATION_KEYS)
sim_log = SimLog.SimLog()
sim_log.set_log_filters(SIM_LOG_FILTERS)
_overwrite_sim_log_log(log_notification_filter)
_save_config_json(sim_settings,
saving_settings={
'combination': {},
'regular': settings.copy()
})
crash_report_path = os.path.join(sim_settings.logRootDirectoryPath,
sim_settings.logDirectory,
'crash_report.log')
if stderr_redirect is True:
_redirect_stderr(redirect_to=open(crash_report_path, 'w'))
_sim_engine = SimEngine.SimEngine()
_elapsed_minutes = 0
_overwrite_sim_engine_actionEndSlotframe()
# start and wait until the simulation ends
_sim_engine.start()
_sim_engine.join()
except Exception as e:
ret_val['status'] = RETURN_STATUS_FAILURE
ret_val['message'] = str(e)
ret_val['trace'] = traceback.format_exc()
else:
if _sim_engine.getAsn() == (sim_settings.exec_numSlotframesPerRun *
sim_settings.tsch_slotframeLength):
ret_val['status'] = RETURN_STATUS_SUCCESS
# rename .dat file and remove the subdir
dat_file_path = sim_settings.getOutputFile()
subdir_path = os.path.dirname(dat_file_path)
new_file_name = subdir_path + '.dat'
os.rename(dat_file_path, new_file_name)
os.rmdir(subdir_path)
else:
# simulation is aborted
ret_val['status'] = RETURN_STATUS_ABORTED
finally:
# housekeeping for crash_report and stderr
if stderr_redirect is True:
crash_report = _restore_stderr()
crash_report.close()
if os.stat(crash_report.name).st_size == 0:
os.remove(crash_report.name)
else:
ret_val['crash_report_path'] = crash_report.name
# cleanup
if _sim_engine is None:
if sim_settings is not None:
sim_settings.destroy()
if sim_log is not None:
sim_log.destroy()
else:
_destroy_sim()
return ret_val