search

dtn7 / dtn7-rs

Rust implementation of a DTN based on RFC 9171
Other
81 stars 20 forks source link

Automated Network Tests Python Error #38

Closed ghost closed 2 years ago

ghost commented 2 years ago 
This was a common error I encountered whenever I ran all of the example scenarios using the `run_scenario` command: https://github.com/dtn7/dtn7-rs/tree/master/tests/clab. The error has to do something with it not being able to retrieve a key called "mean' in a dictionary. 

Mon Aug  8 19:01:10 UTC 2022 | INFO | Result will be put into /shared/results-basic-1659985270
Mon Aug  8 19:01:10 UTC 2022 | INFO | Starting /shared/basic.xml
opened xml: True
Mon Aug  8 19:01:13 UTC 2022 | INFO | Found pre hook, executing it now...
pre hook
Mon Aug  8 19:01:13 UTC 2022 | INFO | Daemonizing "dtnd -C tcp -n $(hostname) -d" on all nodes
# HOST: n1

# HOST: n2

# HOST: n3

# HOST: n4

# HOST: n5

Mon Aug  8 19:01:13 UTC 2022 | INFO | Starting monitoring services
Mon Aug  8 19:01:13 UTC 2022 | INFO | Starting pidstat monitor.. dtnd
# HOST: n1

# HOST: n2

# HOST: n3

# HOST: n4

# HOST: n5

Mon Aug  8 19:01:14 UTC 2022 | INFO | Starting net monitor.. eth0
# HOST: n1

# HOST: n2

# HOST: n3

# HOST: n4

# HOST: n5

Mon Aug  8 19:01:14 UTC 2022 | INFO | Starting contacts monitor..
Mon Aug  8 19:01:14 UTC 2022 | INFO | Starting xy position monitor..
# HOST: n1

# HOST: n2

# HOST: n3

# HOST: n4

# HOST: n5

Mon Aug  8 19:01:15 UTC 2022 | INFO | Experiment started: 1659985274
Mon Aug  8 19:01:15 UTC 2022 | INFO | Experiment will run for 240 seconds
Mon Aug  8 19:05:15 UTC 2022 | INFO | Experiment finished: 1659985515
Mon Aug  8 19:05:15 UTC 2022 | INFO | Stopping user services: dtnd
dtnd: no process found
Mon Aug  8 19:05:15 UTC 2022 | INFO | Stopping monitoring services
Mon Aug  8 19:05:15 UTC 2022 | INFO | Collecting experiment.log from all nodes
Mon Aug  8 19:05:15 UTC 2022 | INFO | Found post hook, executing it now...
post hook - results in /shared/results-basic-1659985270
Mon Aug  8 19:05:15 UTC 2022 | INFO | Preprocessing pidstat logs
# HOST: n1

# HOST: n2

# HOST: n3

# HOST: n4

# HOST: n5

Mon Aug  8 19:05:15 UTC 2022 | INFO | Collecting data
Mon Aug  8 19:05:15 UTC 2022 | INFO | Copying /tmp/pycore.1/n1.conf/net-n1.log to /shared/results-basic-1659985270/n1
Mon Aug  8 19:05:15 UTC 2022 | INFO | Copying /tmp/pycore.1/n1.conf/nohup.dtnd.iqC9.log to /shared/results-basic-1659985270/n1
Mon Aug  8 19:05:15 UTC 2022 | INFO | Copying /tmp/pycore.1/n1.conf/nohup.monitor-net.TNuP.log to /shared/results-basic-1659985270/n1
Mon Aug  8 19:05:15 UTC 2022 | INFO | Copying /tmp/pycore.1/n1.conf/nohup.monitor-pidstat.cIsi.log to /shared/results-basic-1659985270/n1
Mon Aug  8 19:05:15 UTC 2022 | INFO | Copying /tmp/pycore.1/n1.conf/pidstat-n1.csv.log to /shared/results-basic-1659985270/n1
Mon Aug  8 19:05:15 UTC 2022 | INFO | Copying /tmp/pycore.1/n1.conf/pidstat-n1.log to /shared/results-basic-1659985270/n1
Mon Aug  8 19:05:15 UTC 2022 | INFO | Copying /tmp/pycore.1/n1.conf/var.log to /shared/results-basic-1659985270/n1
cp: -r not specified; omitting directory '/tmp/pycore.1/n1.conf/var.log'
Mon Aug  8 19:05:15 UTC 2022 | INFO | Copying /tmp/pycore.1/n2.conf/net-n2.log to /shared/results-basic-1659985270/n2
Mon Aug  8 19:05:15 UTC 2022 | INFO | Copying /tmp/pycore.1/n2.conf/nohup.dtnd.JYIn.log to /shared/results-basic-1659985270/n2
Mon Aug  8 19:05:15 UTC 2022 | INFO | Copying /tmp/pycore.1/n2.conf/nohup.monitor-net.GUCe.log to /shared/results-basic-1659985270/n2
Mon Aug  8 19:05:15 UTC 2022 | INFO | Copying /tmp/pycore.1/n2.conf/nohup.monitor-pidstat.G6fe.log to /shared/results-basic-1659985270/n2
Mon Aug  8 19:05:16 UTC 2022 | INFO | Copying /tmp/pycore.1/n2.conf/pidstat-n2.csv.log to /shared/results-basic-1659985270/n2
Mon Aug  8 19:05:16 UTC 2022 | INFO | Copying /tmp/pycore.1/n2.conf/pidstat-n2.log to /shared/results-basic-1659985270/n2
Mon Aug  8 19:05:16 UTC 2022 | INFO | Copying /tmp/pycore.1/n2.conf/var.log to /shared/results-basic-1659985270/n2
cp: -r not specified; omitting directory '/tmp/pycore.1/n2.conf/var.log'
Mon Aug  8 19:05:16 UTC 2022 | INFO | Copying /tmp/pycore.1/n3.conf/net-n3.log to /shared/results-basic-1659985270/n3
Mon Aug  8 19:05:16 UTC 2022 | INFO | Copying /tmp/pycore.1/n3.conf/nohup.dtnd.3cvd.log to /shared/results-basic-1659985270/n3
Mon Aug  8 19:05:16 UTC 2022 | INFO | Copying /tmp/pycore.1/n3.conf/nohup.monitor-net.hwYv.log to /shared/results-basic-1659985270/n3
Mon Aug  8 19:05:16 UTC 2022 | INFO | Copying /tmp/pycore.1/n3.conf/nohup.monitor-pidstat.zneA.log to /shared/results-basic-1659985270/n3
Mon Aug  8 19:05:16 UTC 2022 | INFO | Copying /tmp/pycore.1/n3.conf/pidstat-n3.csv.log to /shared/results-basic-1659985270/n3
Mon Aug  8 19:05:16 UTC 2022 | INFO | Copying /tmp/pycore.1/n3.conf/pidstat-n3.log to /shared/results-basic-1659985270/n3
Mon Aug  8 19:05:16 UTC 2022 | INFO | Copying /tmp/pycore.1/n3.conf/var.log to /shared/results-basic-1659985270/n3
cp: -r not specified; omitting directory '/tmp/pycore.1/n3.conf/var.log'
Mon Aug  8 19:05:16 UTC 2022 | INFO | Copying /tmp/pycore.1/n4.conf/net-n4.log to /shared/results-basic-1659985270/n4
Mon Aug  8 19:05:16 UTC 2022 | INFO | Copying /tmp/pycore.1/n4.conf/nohup.dtnd.fkex.log to /shared/results-basic-1659985270/n4
Mon Aug  8 19:05:16 UTC 2022 | INFO | Copying /tmp/pycore.1/n4.conf/nohup.monitor-net.B5VL.log to /shared/results-basic-1659985270/n4
Mon Aug  8 19:05:16 UTC 2022 | INFO | Copying /tmp/pycore.1/n4.conf/nohup.monitor-pidstat.sOjA.log to /shared/results-basic-1659985270/n4
Mon Aug  8 19:05:16 UTC 2022 | INFO | Copying /tmp/pycore.1/n4.conf/pidstat-n4.csv.log to /shared/results-basic-1659985270/n4
Mon Aug  8 19:05:16 UTC 2022 | INFO | Copying /tmp/pycore.1/n4.conf/pidstat-n4.log to /shared/results-basic-1659985270/n4
Mon Aug  8 19:05:16 UTC 2022 | INFO | Copying /tmp/pycore.1/n4.conf/var.log to /shared/results-basic-1659985270/n4
cp: -r not specified; omitting directory '/tmp/pycore.1/n4.conf/var.log'
Mon Aug  8 19:05:16 UTC 2022 | INFO | Copying /tmp/pycore.1/n5.conf/net-n5.log to /shared/results-basic-1659985270/n5
Mon Aug  8 19:05:16 UTC 2022 | INFO | Copying /tmp/pycore.1/n5.conf/nohup.dtnd.lqBw.log to /shared/results-basic-1659985270/n5
Mon Aug  8 19:05:16 UTC 2022 | INFO | Copying /tmp/pycore.1/n5.conf/nohup.monitor-net.rKvU.log to /shared/results-basic-1659985270/n5
Mon Aug  8 19:05:16 UTC 2022 | INFO | Copying /tmp/pycore.1/n5.conf/nohup.monitor-pidstat.gptU.log to /shared/results-basic-1659985270/n5
Mon Aug  8 19:05:16 UTC 2022 | INFO | Copying /tmp/pycore.1/n5.conf/pidstat-n5.csv.log to /shared/results-basic-1659985270/n5
Mon Aug  8 19:05:16 UTC 2022 | INFO | Copying /tmp/pycore.1/n5.conf/pidstat-n5.log to /shared/results-basic-1659985270/n5
Mon Aug  8 19:05:16 UTC 2022 | INFO | Copying /tmp/pycore.1/n5.conf/var.log to /shared/results-basic-1659985270/n5
cp: -r not specified; omitting directory '/tmp/pycore.1/n5.conf/var.log'
Mon Aug  8 19:05:16 UTC 2022 | INFO | Gathering file stats for node n1
Mon Aug  8 19:05:16 UTC 2022 | INFO | Gathering file stats for node n2
Mon Aug  8 19:05:16 UTC 2022 | INFO | Gathering file stats for node n3
Mon Aug  8 19:05:16 UTC 2022 | INFO | Gathering file stats for node n4
Mon Aug  8 19:05:16 UTC 2022 | INFO | Gathering file stats for node n5
Mon Aug  8 19:05:16 UTC 2022 | INFO | Found analyze hook, executing it now...
analyze hook - results in /shared/results-basic-1659985270
Mon Aug  8 19:05:16 UTC 2022 | INFO | Analyzing data
Mon Aug  8 19:05:16 UTC 2022 | INFO | Plotting pidstat logs
Traceback (most recent call last):
  File "/usr/lib/python3/dist-packages/pandas/core/indexes/base.py", line 2897, in get_loc
    return self._engine.get_loc(key)
  File "pandas/_libs/index.pyx", line 107, in pandas._libs.index.IndexEngine.get_loc
  File "pandas/_libs/index.pyx", line 131, in pandas._libs.index.IndexEngine.get_loc
  File "pandas/_libs/hashtable_class_helper.pxi", line 1607, in pandas._libs.hashtable.PyObjectHashTable.get_item
  File "pandas/_libs/hashtable_class_helper.pxi", line 1614, in pandas._libs.hashtable.PyObjectHashTable.get_item
KeyError: 'mean'

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/bin/plot-pidstat.py", line 51, in <module>
    per_node[node_name] = [the_row["mean"][0],
  File "/usr/lib/python3/dist-packages/pandas/core/frame.py", line 2995, in __getitem__
    indexer = self.columns.get_loc(key)
  File "/usr/lib/python3/dist-packages/pandas/core/indexes/base.py", line 2899, in get_loc
    return self._engine.get_loc(self._maybe_cast_indexer(key))
  File "pandas/_libs/index.pyx", line 107, in pandas._libs.index.IndexEngine.get_loc
  File "pandas/_libs/index.pyx", line 131, in pandas._libs.index.IndexEngine.get_loc
  File "pandas/_libs/hashtable_class_helper.pxi", line 1607, in pandas._libs.hashtable.PyObjectHashTable.get_item
  File "pandas/_libs/hashtable_class_helper.pxi", line 1614, in pandas._libs.hashtable.PyObjectHashTable.get_item
KeyError: 'mean'
Traceback (most recent call last):
  File "/usr/lib/python3/dist-packages/pandas/core/indexes/base.py", line 2897, in get_loc
    return self._engine.get_loc(key)
  File "pandas/_libs/index.pyx", line 107, in pandas._libs.index.IndexEngine.get_loc
  File "pandas/_libs/index.pyx", line 131, in pandas._libs.index.IndexEngine.get_loc
  File "pandas/_libs/hashtable_class_helper.pxi", line 1607, in pandas._libs.hashtable.PyObjectHashTable.get_item
  File "pandas/_libs/hashtable_class_helper.pxi", line 1614, in pandas._libs.hashtable.PyObjectHashTable.get_item
KeyError: 'mean'

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/bin/plot-pidstat.py", line 51, in <module>
    per_node[node_name] = [the_row["mean"][0],
  File "/usr/lib/python3/dist-packages/pandas/core/frame.py", line 2995, in __getitem__
    indexer = self.columns.get_loc(key)
  File "/usr/lib/python3/dist-packages/pandas/core/indexes/base.py", line 2899, in get_loc
    return self._engine.get_loc(self._maybe_cast_indexer(key))
  File "pandas/_libs/index.pyx", line 107, in pandas._libs.index.IndexEngine.get_loc
  File "pandas/_libs/index.pyx", line 131, in pandas._libs.index.IndexEngine.get_loc
  File "pandas/_libs/hashtable_class_helper.pxi", line 1607, in pandas._libs.hashtable.PyObjectHashTable.get_item
  File "pandas/_libs/hashtable_class_helper.pxi", line 1614, in pandas._libs.hashtable.PyObjectHashTable.get_item
KeyError: 'mean'
Traceback (most recent call last):
  File "/usr/lib/python3/dist-packages/pandas/core/indexes/base.py", line 2897, in get_loc
    return self._engine.get_loc(key)
  File "pandas/_libs/index.pyx", line 107, in pandas._libs.index.IndexEngine.get_loc
  File "pandas/_libs/index.pyx", line 131, in pandas._libs.index.IndexEngine.get_loc
  File "pandas/_libs/hashtable_class_helper.pxi", line 1607, in pandas._libs.hashtable.PyObjectHashTable.get_item
  File "pandas/_libs/hashtable_class_helper.pxi", line 1614, in pandas._libs.hashtable.PyObjectHashTable.get_item
KeyError: 'mean'

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/bin/plot-pidstat.py", line 51, in <module>
    per_node[node_name] = [the_row["mean"][0],
  File "/usr/lib/python3/dist-packages/pandas/core/frame.py", line 2995, in __getitem__
    indexer = self.columns.get_loc(key)
  File "/usr/lib/python3/dist-packages/pandas/core/indexes/base.py", line 2899, in get_loc
    return self._engine.get_loc(self._maybe_cast_indexer(key))
  File "pandas/_libs/index.pyx", line 107, in pandas._libs.index.IndexEngine.get_loc
  File "pandas/_libs/index.pyx", line 131, in pandas._libs.index.IndexEngine.get_loc
  File "pandas/_libs/hashtable_class_helper.pxi", line 1607, in pandas._libs.hashtable.PyObjectHashTable.get_item
  File "pandas/_libs/hashtable_class_helper.pxi", line 1614, in pandas._libs.hashtable.PyObjectHashTable.get_item
KeyError: 'mean'
Mon Aug  8 19:05:18 UTC 2022 | INFO | Plotting net logs
Mon Aug  8 19:05:21 UTC 2022 | INFO | Plotting xy position log
Mon Aug  8 19:05:21 UTC 2022 | INFO | Analyzing file stats
Mon Aug  8 19:05:21 UTC 2022 | INFO | Plotting contact data
Mon Aug  8 19:05:23 UTC 2022 | INFO | Deleting session
delete session(1): True
gh0st42 commented 2 years ago

this is only affecting the generation of plots from the pidstat statistics. you should still find all logs in the results folder.

Also, if you have console output you should put it in a code block here, makes it easier to read :D

I just ran it on one of our servers and everything seems to work fine. Did you change anything in one of the experiment.conf files? Maybe configured a different process to be monitored by pidstat?

Here, my output:

Mon Aug  8 19:49:51 UTC 2022 | INFO | Result will be put into /shared/results-basic-1659988191
Mon Aug  8 19:49:51 UTC 2022 | INFO | Starting /shared/basic.xml
opened xml: True
Mon Aug  8 19:49:54 UTC 2022 | INFO | Found pre hook, executing it now...
pre hook
Mon Aug  8 19:49:54 UTC 2022 | INFO | Daemonizing "dtnd -C tcp -n $(hostname) -d" on all nodes
# HOST: n1

# HOST: n2

# HOST: n3

# HOST: n4

# HOST: n5

Mon Aug  8 19:49:55 UTC 2022 | INFO | Starting monitoring services
Mon Aug  8 19:49:55 UTC 2022 | INFO | Starting pidstat monitor.. dtnd
# HOST: n1

# HOST: n2

# HOST: n3

# HOST: n4

# HOST: n5

Mon Aug  8 19:49:55 UTC 2022 | INFO | Starting net monitor.. eth0
# HOST: n1

# HOST: n2

# HOST: n3

# HOST: n4

# HOST: n5

Mon Aug  8 19:49:56 UTC 2022 | INFO | Starting contacts monitor..
Mon Aug  8 19:49:56 UTC 2022 | INFO | Starting xy position monitor..
# HOST: n1

# HOST: n2

# HOST: n3

# HOST: n4

# HOST: n5

Mon Aug  8 19:49:56 UTC 2022 | INFO | Experiment started: 1659988196
Mon Aug  8 19:49:56 UTC 2022 | INFO | Experiment will run for 240 seconds
Mon Aug  8 19:53:56 UTC 2022 | INFO | Experiment finished: 1659988436
Mon Aug  8 19:53:56 UTC 2022 | INFO | Stopping user services: dtnd
Mon Aug  8 19:53:56 UTC 2022 | INFO | Stopping monitoring services
Mon Aug  8 19:53:56 UTC 2022 | INFO | Collecting experiment.log from all nodes
Mon Aug  8 19:53:56 UTC 2022 | INFO | Found post hook, executing it now...
post hook - results in /shared/results-basic-1659988191
Mon Aug  8 19:53:56 UTC 2022 | INFO | Preprocessing pidstat logs
# HOST: n1

# HOST: n2

# HOST: n3

# HOST: n4

# HOST: n5

Mon Aug  8 19:53:56 UTC 2022 | INFO | Collecting data
Mon Aug  8 19:53:56 UTC 2022 | INFO | Copying /tmp/pycore.1/n1.conf/net-n1.log to /shared/results-basic-1659988191/n1
Mon Aug  8 19:53:56 UTC 2022 | INFO | Copying /tmp/pycore.1/n1.conf/nohup.dtnd.KsIY.log to /shared/results-basic-1659988191/n1
Mon Aug  8 19:53:56 UTC 2022 | INFO | Copying /tmp/pycore.1/n1.conf/nohup.monitor-net.fQV5.log to /shared/results-basic-1659988191/n1
Mon Aug  8 19:53:56 UTC 2022 | INFO | Copying /tmp/pycore.1/n1.conf/nohup.monitor-pidstat.nAAa.log to /shared/results-basic-1659988191/n1
Mon Aug  8 19:53:56 UTC 2022 | INFO | Copying /tmp/pycore.1/n1.conf/pidstat-n1.csv.log to /shared/results-basic-1659988191/n1
Mon Aug  8 19:53:56 UTC 2022 | INFO | Copying /tmp/pycore.1/n1.conf/pidstat-n1.log to /shared/results-basic-1659988191/n1
Mon Aug  8 19:53:56 UTC 2022 | INFO | Copying /tmp/pycore.1/n1.conf/var.log to /shared/results-basic-1659988191/n1
cp: -r not specified; omitting directory '/tmp/pycore.1/n1.conf/var.log'
Mon Aug  8 19:53:56 UTC 2022 | INFO | Copying /tmp/pycore.1/n2.conf/net-n2.log to /shared/results-basic-1659988191/n2
Mon Aug  8 19:53:56 UTC 2022 | INFO | Copying /tmp/pycore.1/n2.conf/nohup.dtnd.DSuo.log to /shared/results-basic-1659988191/n2
Mon Aug  8 19:53:56 UTC 2022 | INFO | Copying /tmp/pycore.1/n2.conf/nohup.monitor-net.Zicx.log to /shared/results-basic-1659988191/n2
Mon Aug  8 19:53:56 UTC 2022 | INFO | Copying /tmp/pycore.1/n2.conf/nohup.monitor-pidstat.v2eq.log to /shared/results-basic-1659988191/n2
Mon Aug  8 19:53:56 UTC 2022 | INFO | Copying /tmp/pycore.1/n2.conf/pidstat-n2.csv.log to /shared/results-basic-1659988191/n2
Mon Aug  8 19:53:56 UTC 2022 | INFO | Copying /tmp/pycore.1/n2.conf/pidstat-n2.log to /shared/results-basic-1659988191/n2
Mon Aug  8 19:53:56 UTC 2022 | INFO | Copying /tmp/pycore.1/n2.conf/var.log to /shared/results-basic-1659988191/n2
cp: -r not specified; omitting directory '/tmp/pycore.1/n2.conf/var.log'
Mon Aug  8 19:53:56 UTC 2022 | INFO | Copying /tmp/pycore.1/n3.conf/net-n3.log to /shared/results-basic-1659988191/n3
Mon Aug  8 19:53:56 UTC 2022 | INFO | Copying /tmp/pycore.1/n3.conf/nohup.dtnd.PnuH.log to /shared/results-basic-1659988191/n3
Mon Aug  8 19:53:56 UTC 2022 | INFO | Copying /tmp/pycore.1/n3.conf/nohup.monitor-net.B6Lw.log to /shared/results-basic-1659988191/n3
Mon Aug  8 19:53:56 UTC 2022 | INFO | Copying /tmp/pycore.1/n3.conf/nohup.monitor-pidstat.YWbL.log to /shared/results-basic-1659988191/n3
Mon Aug  8 19:53:56 UTC 2022 | INFO | Copying /tmp/pycore.1/n3.conf/pidstat-n3.csv.log to /shared/results-basic-1659988191/n3
Mon Aug  8 19:53:56 UTC 2022 | INFO | Copying /tmp/pycore.1/n3.conf/pidstat-n3.log to /shared/results-basic-1659988191/n3
Mon Aug  8 19:53:56 UTC 2022 | INFO | Copying /tmp/pycore.1/n3.conf/var.log to /shared/results-basic-1659988191/n3
cp: -r not specified; omitting directory '/tmp/pycore.1/n3.conf/var.log'
Mon Aug  8 19:53:56 UTC 2022 | INFO | Copying /tmp/pycore.1/n4.conf/net-n4.log to /shared/results-basic-1659988191/n4
Mon Aug  8 19:53:56 UTC 2022 | INFO | Copying /tmp/pycore.1/n4.conf/nohup.dtnd.8Hbt.log to /shared/results-basic-1659988191/n4
Mon Aug  8 19:53:56 UTC 2022 | INFO | Copying /tmp/pycore.1/n4.conf/nohup.monitor-net.XFMx.log to /shared/results-basic-1659988191/n4
Mon Aug  8 19:53:56 UTC 2022 | INFO | Copying /tmp/pycore.1/n4.conf/nohup.monitor-pidstat.RV74.log to /shared/results-basic-1659988191/n4
Mon Aug  8 19:53:56 UTC 2022 | INFO | Copying /tmp/pycore.1/n4.conf/pidstat-n4.csv.log to /shared/results-basic-1659988191/n4
Mon Aug  8 19:53:56 UTC 2022 | INFO | Copying /tmp/pycore.1/n4.conf/pidstat-n4.log to /shared/results-basic-1659988191/n4
Mon Aug  8 19:53:56 UTC 2022 | INFO | Copying /tmp/pycore.1/n4.conf/var.log to /shared/results-basic-1659988191/n4
cp: -r not specified; omitting directory '/tmp/pycore.1/n4.conf/var.log'
Mon Aug  8 19:53:56 UTC 2022 | INFO | Copying /tmp/pycore.1/n5.conf/net-n5.log to /shared/results-basic-1659988191/n5
Mon Aug  8 19:53:56 UTC 2022 | INFO | Copying /tmp/pycore.1/n5.conf/nohup.dtnd.LL43.log to /shared/results-basic-1659988191/n5
Mon Aug  8 19:53:56 UTC 2022 | INFO | Copying /tmp/pycore.1/n5.conf/nohup.monitor-net.l5eD.log to /shared/results-basic-1659988191/n5
Mon Aug  8 19:53:56 UTC 2022 | INFO | Copying /tmp/pycore.1/n5.conf/nohup.monitor-pidstat.Vafi.log to /shared/results-basic-1659988191/n5
Mon Aug  8 19:53:56 UTC 2022 | INFO | Copying /tmp/pycore.1/n5.conf/pidstat-n5.csv.log to /shared/results-basic-1659988191/n5
Mon Aug  8 19:53:56 UTC 2022 | INFO | Copying /tmp/pycore.1/n5.conf/pidstat-n5.log to /shared/results-basic-1659988191/n5
Mon Aug  8 19:53:56 UTC 2022 | INFO | Copying /tmp/pycore.1/n5.conf/var.log to /shared/results-basic-1659988191/n5
cp: -r not specified; omitting directory '/tmp/pycore.1/n5.conf/var.log'
Mon Aug  8 19:53:56 UTC 2022 | INFO | Gathering file stats for node n1
Mon Aug  8 19:53:56 UTC 2022 | INFO | Gathering file stats for node n2
Mon Aug  8 19:53:56 UTC 2022 | INFO | Gathering file stats for node n3
Mon Aug  8 19:53:56 UTC 2022 | INFO | Gathering file stats for node n4
Mon Aug  8 19:53:57 UTC 2022 | INFO | Gathering file stats for node n5
Mon Aug  8 19:53:57 UTC 2022 | INFO | Found analyze hook, executing it now...
analyze hook - results in /shared/results-basic-1659988191
Mon Aug  8 19:53:57 UTC 2022 | INFO | Analyzing data
Mon Aug  8 19:53:57 UTC 2022 | INFO | Plotting pidstat logs
Mon Aug  8 19:53:59 UTC 2022 | INFO | Plotting net logs
Mon Aug  8 19:54:01 UTC 2022 | INFO | Plotting xy position log
Mon Aug  8 19:54:01 UTC 2022 | INFO | Analyzing file stats
Mon Aug  8 19:54:01 UTC 2022 | INFO | Plotting contact data
Mon Aug  8 19:54:03 UTC 2022 | INFO | Deleting session
delete session(1): True

real    4m11.782s
user    1m40.044s
sys     0m13.210s
ghost commented 2 years ago

this is only affecting the generation of plots from the pidstat statistics. you should still find all logs in the results folder.

Also, if you have console output you should put it in a code block here, makes it easier to read :D

I just ran it on one of our servers and everything seems to work fine. Did you change anything in one of the experiment.conf files? Maybe configured a different process to be monitored by pidstat?

Here, my output:

Mon Aug  8 19:49:51 UTC 2022 | INFO | Result will be put into /shared/results-basic-1659988191
Mon Aug  8 19:49:51 UTC 2022 | INFO | Starting /shared/basic.xml
opened xml: True
Mon Aug  8 19:49:54 UTC 2022 | INFO | Found pre hook, executing it now...
pre hook
Mon Aug  8 19:49:54 UTC 2022 | INFO | Daemonizing "dtnd -C tcp -n $(hostname) -d" on all nodes
# HOST: n1

# HOST: n2

# HOST: n3

# HOST: n4

# HOST: n5

Mon Aug  8 19:49:55 UTC 2022 | INFO | Starting monitoring services
Mon Aug  8 19:49:55 UTC 2022 | INFO | Starting pidstat monitor.. dtnd
# HOST: n1

# HOST: n2

# HOST: n3

# HOST: n4

# HOST: n5

Mon Aug  8 19:49:55 UTC 2022 | INFO | Starting net monitor.. eth0
# HOST: n1

# HOST: n2

# HOST: n3

# HOST: n4

# HOST: n5

Mon Aug  8 19:49:56 UTC 2022 | INFO | Starting contacts monitor..
Mon Aug  8 19:49:56 UTC 2022 | INFO | Starting xy position monitor..
# HOST: n1

# HOST: n2

# HOST: n3

# HOST: n4

# HOST: n5

Mon Aug  8 19:49:56 UTC 2022 | INFO | Experiment started: 1659988196
Mon Aug  8 19:49:56 UTC 2022 | INFO | Experiment will run for 240 seconds
Mon Aug  8 19:53:56 UTC 2022 | INFO | Experiment finished: 1659988436
Mon Aug  8 19:53:56 UTC 2022 | INFO | Stopping user services: dtnd
Mon Aug  8 19:53:56 UTC 2022 | INFO | Stopping monitoring services
Mon Aug  8 19:53:56 UTC 2022 | INFO | Collecting experiment.log from all nodes
Mon Aug  8 19:53:56 UTC 2022 | INFO | Found post hook, executing it now...
post hook - results in /shared/results-basic-1659988191
Mon Aug  8 19:53:56 UTC 2022 | INFO | Preprocessing pidstat logs
# HOST: n1

# HOST: n2

# HOST: n3

# HOST: n4

# HOST: n5

Mon Aug  8 19:53:56 UTC 2022 | INFO | Collecting data
Mon Aug  8 19:53:56 UTC 2022 | INFO | Copying /tmp/pycore.1/n1.conf/net-n1.log to /shared/results-basic-1659988191/n1
Mon Aug  8 19:53:56 UTC 2022 | INFO | Copying /tmp/pycore.1/n1.conf/nohup.dtnd.KsIY.log to /shared/results-basic-1659988191/n1
Mon Aug  8 19:53:56 UTC 2022 | INFO | Copying /tmp/pycore.1/n1.conf/nohup.monitor-net.fQV5.log to /shared/results-basic-1659988191/n1
Mon Aug  8 19:53:56 UTC 2022 | INFO | Copying /tmp/pycore.1/n1.conf/nohup.monitor-pidstat.nAAa.log to /shared/results-basic-1659988191/n1
Mon Aug  8 19:53:56 UTC 2022 | INFO | Copying /tmp/pycore.1/n1.conf/pidstat-n1.csv.log to /shared/results-basic-1659988191/n1
Mon Aug  8 19:53:56 UTC 2022 | INFO | Copying /tmp/pycore.1/n1.conf/pidstat-n1.log to /shared/results-basic-1659988191/n1
Mon Aug  8 19:53:56 UTC 2022 | INFO | Copying /tmp/pycore.1/n1.conf/var.log to /shared/results-basic-1659988191/n1
cp: -r not specified; omitting directory '/tmp/pycore.1/n1.conf/var.log'
Mon Aug  8 19:53:56 UTC 2022 | INFO | Copying /tmp/pycore.1/n2.conf/net-n2.log to /shared/results-basic-1659988191/n2
Mon Aug  8 19:53:56 UTC 2022 | INFO | Copying /tmp/pycore.1/n2.conf/nohup.dtnd.DSuo.log to /shared/results-basic-1659988191/n2
Mon Aug  8 19:53:56 UTC 2022 | INFO | Copying /tmp/pycore.1/n2.conf/nohup.monitor-net.Zicx.log to /shared/results-basic-1659988191/n2
Mon Aug  8 19:53:56 UTC 2022 | INFO | Copying /tmp/pycore.1/n2.conf/nohup.monitor-pidstat.v2eq.log to /shared/results-basic-1659988191/n2
Mon Aug  8 19:53:56 UTC 2022 | INFO | Copying /tmp/pycore.1/n2.conf/pidstat-n2.csv.log to /shared/results-basic-1659988191/n2
Mon Aug  8 19:53:56 UTC 2022 | INFO | Copying /tmp/pycore.1/n2.conf/pidstat-n2.log to /shared/results-basic-1659988191/n2
Mon Aug  8 19:53:56 UTC 2022 | INFO | Copying /tmp/pycore.1/n2.conf/var.log to /shared/results-basic-1659988191/n2
cp: -r not specified; omitting directory '/tmp/pycore.1/n2.conf/var.log'
Mon Aug  8 19:53:56 UTC 2022 | INFO | Copying /tmp/pycore.1/n3.conf/net-n3.log to /shared/results-basic-1659988191/n3
Mon Aug  8 19:53:56 UTC 2022 | INFO | Copying /tmp/pycore.1/n3.conf/nohup.dtnd.PnuH.log to /shared/results-basic-1659988191/n3
Mon Aug  8 19:53:56 UTC 2022 | INFO | Copying /tmp/pycore.1/n3.conf/nohup.monitor-net.B6Lw.log to /shared/results-basic-1659988191/n3
Mon Aug  8 19:53:56 UTC 2022 | INFO | Copying /tmp/pycore.1/n3.conf/nohup.monitor-pidstat.YWbL.log to /shared/results-basic-1659988191/n3
Mon Aug  8 19:53:56 UTC 2022 | INFO | Copying /tmp/pycore.1/n3.conf/pidstat-n3.csv.log to /shared/results-basic-1659988191/n3
Mon Aug  8 19:53:56 UTC 2022 | INFO | Copying /tmp/pycore.1/n3.conf/pidstat-n3.log to /shared/results-basic-1659988191/n3
Mon Aug  8 19:53:56 UTC 2022 | INFO | Copying /tmp/pycore.1/n3.conf/var.log to /shared/results-basic-1659988191/n3
cp: -r not specified; omitting directory '/tmp/pycore.1/n3.conf/var.log'
Mon Aug  8 19:53:56 UTC 2022 | INFO | Copying /tmp/pycore.1/n4.conf/net-n4.log to /shared/results-basic-1659988191/n4
Mon Aug  8 19:53:56 UTC 2022 | INFO | Copying /tmp/pycore.1/n4.conf/nohup.dtnd.8Hbt.log to /shared/results-basic-1659988191/n4
Mon Aug  8 19:53:56 UTC 2022 | INFO | Copying /tmp/pycore.1/n4.conf/nohup.monitor-net.XFMx.log to /shared/results-basic-1659988191/n4
Mon Aug  8 19:53:56 UTC 2022 | INFO | Copying /tmp/pycore.1/n4.conf/nohup.monitor-pidstat.RV74.log to /shared/results-basic-1659988191/n4
Mon Aug  8 19:53:56 UTC 2022 | INFO | Copying /tmp/pycore.1/n4.conf/pidstat-n4.csv.log to /shared/results-basic-1659988191/n4
Mon Aug  8 19:53:56 UTC 2022 | INFO | Copying /tmp/pycore.1/n4.conf/pidstat-n4.log to /shared/results-basic-1659988191/n4
Mon Aug  8 19:53:56 UTC 2022 | INFO | Copying /tmp/pycore.1/n4.conf/var.log to /shared/results-basic-1659988191/n4
cp: -r not specified; omitting directory '/tmp/pycore.1/n4.conf/var.log'
Mon Aug  8 19:53:56 UTC 2022 | INFO | Copying /tmp/pycore.1/n5.conf/net-n5.log to /shared/results-basic-1659988191/n5
Mon Aug  8 19:53:56 UTC 2022 | INFO | Copying /tmp/pycore.1/n5.conf/nohup.dtnd.LL43.log to /shared/results-basic-1659988191/n5
Mon Aug  8 19:53:56 UTC 2022 | INFO | Copying /tmp/pycore.1/n5.conf/nohup.monitor-net.l5eD.log to /shared/results-basic-1659988191/n5
Mon Aug  8 19:53:56 UTC 2022 | INFO | Copying /tmp/pycore.1/n5.conf/nohup.monitor-pidstat.Vafi.log to /shared/results-basic-1659988191/n5
Mon Aug  8 19:53:56 UTC 2022 | INFO | Copying /tmp/pycore.1/n5.conf/pidstat-n5.csv.log to /shared/results-basic-1659988191/n5
Mon Aug  8 19:53:56 UTC 2022 | INFO | Copying /tmp/pycore.1/n5.conf/pidstat-n5.log to /shared/results-basic-1659988191/n5
Mon Aug  8 19:53:56 UTC 2022 | INFO | Copying /tmp/pycore.1/n5.conf/var.log to /shared/results-basic-1659988191/n5
cp: -r not specified; omitting directory '/tmp/pycore.1/n5.conf/var.log'
Mon Aug  8 19:53:56 UTC 2022 | INFO | Gathering file stats for node n1
Mon Aug  8 19:53:56 UTC 2022 | INFO | Gathering file stats for node n2
Mon Aug  8 19:53:56 UTC 2022 | INFO | Gathering file stats for node n3
Mon Aug  8 19:53:56 UTC 2022 | INFO | Gathering file stats for node n4
Mon Aug  8 19:53:57 UTC 2022 | INFO | Gathering file stats for node n5
Mon Aug  8 19:53:57 UTC 2022 | INFO | Found analyze hook, executing it now...
analyze hook - results in /shared/results-basic-1659988191
Mon Aug  8 19:53:57 UTC 2022 | INFO | Analyzing data
Mon Aug  8 19:53:57 UTC 2022 | INFO | Plotting pidstat logs
Mon Aug  8 19:53:59 UTC 2022 | INFO | Plotting net logs
Mon Aug  8 19:54:01 UTC 2022 | INFO | Plotting xy position log
Mon Aug  8 19:54:01 UTC 2022 | INFO | Analyzing file stats
Mon Aug  8 19:54:01 UTC 2022 | INFO | Plotting contact data
Mon Aug  8 19:54:03 UTC 2022 | INFO | Deleting session
delete session(1): True

real    4m11.782s
user    1m40.044s
sys     0m13.210s

I did not change any of the experiment.conf files, nor did I configure a different process to be monitored by pidstat.

gh0st42 commented 2 years ago

I tried it on 3 other machines (ranging from x64 to arm64 with different linux distributions), two with preexisting dtn7-rs installations or other projects using coreemu-lab (did pull via git and docker) and one machine which did not have anything installed besides pure docker, here I installed the rust toolchain and checked out the latest dtn7-rs from the master branch.

All machines ran scenario_basic just fine and plotted figures afterwards. If you cannot give steps to reproduce the issue on a different machine, I unfortunately cannot help you. The problem seems to be related to your setup.