coreemu / core

Common Open Research Emulator
BSD 2-Clause "Simplified" License
671 stars 163 forks source link

Custom EMANE model insert errors #505

Closed szl0144 closed 4 years ago

szl0144 commented 4 years ago

Hi,

I am doing a multi-hop experiment with custom EMANE model. I chose a TDMA EMANE model and set traffic flow from n1 to N3 using mgen. In this scenario, I let n1 to be a transmitter, n2 is a relay to forward packets and n3 is a receiver. But I found I was faced some bugs, 1) There is no connection between the three nodes when I use custom EMANE TDMA model 2) I didn't find the mgen log file in /var/log/ folder.

My EMANE version is v 1.2.4 My ubuntu version is 16.04 My CORE version is 5.2 (is there any other good version which is compatible for EMANE V1.2.4? I am not sure whether this bug is caused by version problem)

I followed the installation process in readme as following: ./bootstrap.sh ./configure make sudo make install

And start the demo with the commands: sudo service core-daemon start sudo systemctl start core-daemon core-gui

I inserted the EMANE model by firstly downloading me revised code on Github, and build the deb file by ./autogen.sh && ./configure && make deb WITHOUT_PYTHON3=1 cd .debbuild sudo dpkg -i *.deb Then I set the core.conf file as following: emane_platform_port = 8101 emane_transform_port = 8201 emane_event_monitor = False emane_models_dir = /home/username/MyEmaneFolder emane_log_level = 2 emane_realtime = True

Is my process that combine custom EMANE mode with CORE correct? I also see the custom emane example in core/daemon/examples/myemane, need I run this file before I use my custom EMANE model in CORE? Can you please tell me what this file does? I think this file is to configure the MAC and PHY layer used in the CORE, but I see a configuration GUI in the CORE to configure MAC and PHY layer.

I also check the log file named core-daemon.log, I saw some errors in them.

DATA: # CORE MGEN script: flow 2 from n1 to n3 0.0 ON 2 UDP SRC 5000 DST 10.0.0.3/5000 TOS 0 DATA [0,1]

2020-08-05 19:02:02,059 - ERROR - corehandlers:handle_message - Thread-21: exception while handling message: CoreFileMessage <msgtype = FILE, flags = 0x1 > NODE: 1 NAME: flow2.mgn Traceback (most recent call last): File "/usr/local/lib/python2.7/dist-packages/core/corehandlers.py", line 490, in handle_message replies = message_handler(message) File "/usr/local/lib/python2.7/dist-packages/core/corehandlers.py", line 1378, in handle_file_message self.session.node_add_file(node_num, source_name, file_name, data) AttributeError: 'EmuSession' object has no attribute 'node_add_file' 2020-08-05 19:02:02,059 - ERROR - corehandlers:handle_message - Thread-21: exception while handling message: CoreFileMessage <msgtype = FILE, flags = 0x1 > DATA: # CORE MGEN script: flow 2 from n1 to n3 0.0 LISTEN UDP 5000

NODE: 3 NAME: flow2.mgn Traceback (most recent call last): File "/usr/local/lib/python2.7/dist-packages/core/corehandlers.py", line 490, in handle_message replies = message_handler(message) File "/usr/local/lib/python2.7/dist-packages/core/corehandlers.py", line 1378, in handle_file_message self.session.node_add_file(node_num, source_name, file_name, data) 2020-08-05 19:02:02,718 - ERROR - service:validate_service - node(n1) service(zebra) validate command failed Traceback (most recent call last): File "/usr/local/lib/python2.7/dist-packages/core/service.py", line 526, in validate_service node.check_cmd(cmd) File "/usr/local/lib/python2.7/dist-packages/core/netns/vnode.py", line 189, in check_cmd return self.client.check_cmd(args) File "/usr/local/lib/python2.7/dist-packages/core/netns/vnodeclient.py", line 111, in check_cmd raise CoreCommandError(status, args, output) CoreCommandError: Command(pidof zebra), Status(256):

2020-08-05 19:02:03,036 - ERROR - service:validate_service - node(n2) service(zebra) validate command failed Traceback (most recent call last): File "/usr/local/lib/python2.7/dist-packages/core/service.py", line 526, in validate_service node.check_cmd(cmd) File "/usr/local/lib/python2.7/dist-packages/core/netns/vnode.py", line 189, in check_cmd return self.client.check_cmd(args) File "/usr/local/lib/python2.7/dist-packages/core/netns/vnodeclient.py", line 111, in check_cmd raise CoreCommandError(status, args, output) CoreCommandError: Command(pidof zebra), Status(256):

2020-08-05 19:02:03,324 - ERROR - service:validate_service - node(n3) service(zebra) validate command failed Traceback (most recent call last): File "/usr/local/lib/python2.7/dist-packages/core/service.py", line 526, in validate_service node.check_cmd(cmd) File "/usr/local/lib/python2.7/dist-packages/core/netns/vnode.py", line 189, in check_cmd return self.client.check_cmd(args) File "/usr/local/lib/python2.7/dist-packages/core/netns/vnodeclient.py", line 111, in check_cmd raise CoreCommandError(status, args, output) CoreCommandError: Command(pidof zebra), Status(256):

2020-08-05 19:02:03,450 - INFO - service:validate_service - validating node(n3) service(IPForward) 2020-08-05 19:02:03,590 - ERROR - corehandlers:handle_message - Thread-21: exception while handling message: CoreEventMessage <msgtype = EVENT, flags = 0x0 <>> TYPE: 3 Traceback (most recent call last): File "/usr/local/lib/python2.7/dist-packages/core/corehandlers.py", line 490, in handle_message replies = message_handler(message) File "/usr/local/lib/python2.7/dist-packages/core/corehandlers.py", line 1440, in handle_event_message self.session.instantiate() File "/usr/local/lib/python2.7/dist-packages/core/session.py", line 611, in instantiate self.boot_nodes() File "/usr/local/lib/python2.7/dist-packages/core/session.py", line 738, in boot_nodes result.get() File "/usr/lib/python2.7/multiprocessing/pool.py", line 567, in get raise self._value ServiceBootError: node(n1) service(zebra) failed validation 2020-08-05 19:02:10,061 - INFO - corehandlers:handle_execute_message - execute message with cmd=mgen instance n3flow2.mgn input flow2.mgn output /var/log/mgen2.log 2020-08-05 19:02:10,062 - INFO - corehandlers:handle_execute_message - execute message with cmd=mgen instance n1flow2.mgn input flow2.mgn

image

These are some parts of the log file, could you please tell me what causes the error happen?

Best, Shaoyi

bharnden commented 4 years ago

A few things:

szl0144 commented 4 years ago

Hi,

Thank you for your swift reply and helps, you advices help me so much.

Thank you for your explanation.

Best, Shaoyi

bharnden commented 4 years ago
szl0144 commented 4 years ago

Thank you very much, I got it. I got all of your first three points. For the last one, I installed the OSPF MDR from https://github.com/USNavalResearchLaboratory/ospf-mdr and I come into OSPF-MDR folder and install this package by the following commands ./bootstrap.sh ./configure make sudo make install After installing the package, I start my core again, I found the error shows up again about zebra . When I ping node 2 from node 1, the terminal shows Network is unreachable. When I uninstall OSPF-MDR, the error disappear. Can you please tell me where the problem is? I think it is not the problem of my EMANE source code, because I either can't ping n2 when I use the None EMANE model. image image Following is the errors in my log file when I install OSPF-MDR file. 2020-08-06 16:43:22,158 - ERROR - coreservices:_start_boot_paths - exception booting service: zebra Traceback (most recent call last): File "/usr/local/lib/python2.7/dist-packages/core/services/coreservices.py", line 493, in _start_boot_paths self.boot_service(node, service) File "/usr/local/lib/python2.7/dist-packages/core/services/coreservices.py", line 559, in boot_service "node(%s) service(%s) failed validation" % (node.name, service.name)

TYPE: 3 Traceback (most recent call last): File "/usr/local/lib/python2.7/dist-packages/core/api/tlv/corehandlers.py", line 552, in handle_message replies = message_handler(message) File "/usr/local/lib/python2.7/dist-packages/core/api/tlv/corehandlers.py", line 1627, in handle_event_message self.session.instantiate() File "/usr/local/lib/python2.7/dist-packages/core/emulator/session.py", line 1470, in instantiate self.boot_nodes() File "/usr/local/lib/python2.7/dist-packages/core/emulator/session.py", line 1612, in boot_nodes result.get() File "/usr/lib/python2.7/multiprocessing/pool.py", line 567, in get raise self._value ServiceBootError: node(n1) service(zebra) failed validation

2020-08-06 16:46:18,623 - ERROR - coreservices:stop_service - error running stop command killall zebra Traceback (most recent call last): File "/usr/local/lib/python2.7/dist-packages/core/services/coreservices.py", line 634, in stop_service node.check_cmd(args) File "/usr/local/lib/python2.7/dist-packages/core/nodes/base.py", line 626, in check_cmd return self.client.check_cmd(args) File "/usr/local/lib/python2.7/dist-packages/core/nodes/client.py", line 111, in check_cmd raise CoreCommandError(status, args, output) CoreCommandError: Command(killall zebra), Status(1): zebra: no process found 2020-08-06 16:46:18,641 - ERROR - coreservices:stop_service - error running stop command killall ospf6d Traceback (most recent call last): File "/usr/local/lib/python2.7/dist-packages/core/services/coreservices.py", line 634, in stop_service node.check_cmd(args) File "/usr/local/lib/python2.7/dist-packages/core/nodes/base.py", line 626, in check_cmd return self.client.check_cmd(args) File "/usr/local/lib/python2.7/dist-packages/core/nodes/client.py", line 111, in check_cmd raise CoreCommandError(status, args, output) CoreCommandError: Command(killall ospf6d), Status(1): ospf6d: no process found 2020-08-06 16:46:18,658 - ERROR - coreservices:stop_service - error running stop command killall zebra Traceback (most recent call last): File "/usr/local/lib/python2.7/dist-packages/core/services/coreservices.py", line 634, in stop_service node.check_cmd(args) File "/usr/local/lib/python2.7/dist-packages/core/nodes/base.py", line 626, in check_cmd return self.client.check_cmd(args) File "/usr/local/lib/python2.7/dist-packages/core/nodes/client.py", line 111, in check_cmd raise CoreCommandError(status, args, output) CoreCommandError: Command(killall zebra), Status(1): zebra: no process found 2020-08-06 16:46:18,672 - ERROR - coreservices:stop_service - error running stop command killall ospf6d Traceback (most recent call last): File "/usr/local/lib/python2.7/dist-packages/core/services/coreservices.py", line 634, in stop_service node.check_cmd(args) File "/usr/local/lib/python2.7/dist-packages/core/nodes/base.py", line 626, in check_cmd return self.client.check_cmd(args) File "/usr/local/lib/python2.7/dist-packages/core/nodes/client.py", line 111, in check_cmd raise CoreCommandError(status, args, output) CoreCommandError: Command(killall ospf6d), Status(1): ospf6d: no process found 2020-08-06 16:46:18,687 - ERROR - coreservices:stop_service - error running stop command killall zebra Traceback (most recent call last): File "/usr/local/lib/python2.7/dist-packages/core/services/coreservices.py", line 634, in stop_service node.check_cmd(args) File "/usr/local/lib/python2.7/dist-packages/core/nodes/base.py", line 626, in check_cmd return self.client.check_cmd(args) File "/usr/local/lib/python2.7/dist-packages/core/nodes/client.py", line 111, in check_cmd raise CoreCommandError(status, args, output) CoreCommandError: Command(killall zebra), Status(1): zebra: no process found 2020-08-06 16:46:18,700 - ERROR - coreservices:stop_service - error running stop command killall ospf6d Traceback (most recent call last): File "/usr/local/lib/python2.7/dist-packages/core/services/coreservices.py", line 634, in stop_service node.check_cmd(args) File "/usr/local/lib/python2.7/dist-packages/core/nodes/base.py", line 626, in check_cmd return self.client.check_cmd(args) File "/usr/local/lib/python2.7/dist-packages/core/nodes/client.py", line 111, in check_cmd raise CoreCommandError(status, args, output) CoreCommandError: Command(killall ospf6d), Status(1): ospf6d: no process found

Best, Shaoyi

bharnden commented 4 years ago

It's hard to say exactly what your issue is, since you are on such an old version of CORE. I am not sure exactly what parts of EMANE you have modified, but if its an existing model, I am not sure the python2 part really matters.

The only errors I see are that services are failing, but why is hard to say.

If you had qugga installed before, you would have had to uninstall before installing OSPF MDR.

The only things that seem to make sense is that there is a bad setup of the environment in this case.

szl0144 commented 4 years ago

Hi,

Thank you for your patient reply.

I follow your advice to change my system to ubuntu 18.04 and download the newest version of CORE, I didn't face any problem in the automatic installation. After I check the ping function with wlan connected with several MDRs, everything goes on well this time. I think I didn't install the OSPF-MDR package correctly, the wrong OSPF-MDR installation causes a problem in wireless routing.

One problem I faced is I didn't see any operations about saving packet information into mgen log file in core-daemon log file after I configured and started a traffic using mgen. I saw the flow.mgn file which defines mgen command in transmitter. And there was no mgen1.log file in the receiver and my ubuntu system. I just run two script commands which are sudo core-daemon and core-gui, can you tell me how can I see the mgen1.log file in the receiver node?

I haven't downloaded my EMANE source code and tested CORE with it, I will download my EMANE source code tomorrow and update whether there is any question.

Best, Shaoyi

bharnden commented 4 years ago
szl0144 commented 4 years ago

Hi,

Thank you for your valuable tips. After I installed mgen in ubuntu, I can run the traffic and get the mgen.log file, everything goes on well.

I also download my EMANE source code from Github, I follow the installation instruction on Ubuntu 18.04, I install the deb file successfully and build it well. One problem is when I choose EMANE TDMA model in CORE, the core-daemon log file shows "EMANE python bindings are not installed". I check my python version is Python 3.6.9 and import emane package, the terminal shows No module named 'emane'. I guess it is because I previously run my EMANE source code on python2, can you please tell me how can I figure out it?

Thank you very much!

bharnden commented 4 years ago

The EMANE binding part requires manually building EMANE and installing the python bindings into CORE's virtual environment.

https://coreemu.github.io/core/install.html#manually-install-emane

cd <CORE_REPO>/daemon
poetry run pip install <EMANE_REPO>/src/python
szl0144 commented 4 years ago

Hi,

Thank you, I have bound the package into CORE. When I run core-daemon, the terminal shows.

File "/home/core/.cache/pypoetry/virtualenvs/core-mpDUWUHI-py3.6/lib/python3.6/site-packages/google/protobuf/descriptor.py", line 941, in new return _message.default_pool.AddSerializedFile(serialized_pb) TypeError: expected bytes, str found

I search some material about this error, I think it is caused by a old version protobuf-compiler in my system, I am still working on upgrading the portobuf-compiler, I think the upgrade is a little bit complex. Could you give some suggestions about it?

bharnden commented 4 years ago

It looks more like a python2/3 issue, but not one I have run into. Potentially you somehow installed the EMANE python2 bindings?

Or possibly related to how you built your custom EMANE part.

szl0144 commented 4 years ago

Yes, I think so. I am afraid I have some parts wrong in building EMANE. Because I also downloaded original EMANE source code to do a comparison, when I manually install the EMANE python bindings using "poetry run pip install /home/core/emane/src/python", terminal shows Directory '/home/core/emane/src/python' is not installable. File 'setup.py' not found. I think I either fail to get the new setup.py file when I built my own EMANE source code, so CORE installed my old python 2 bindings and there is a problem about python2/3 issue.

The way I installed EMANE is as instructions on EMANE Build.

Install EMANE build dependencies on Ubuntu 18.04: sudo apt-get install gcc g++ autoconf automake libtool libxml2-dev libprotobuf-dev \ python-protobuf libpcap-dev libpcre3-dev uuid-dev debhelper pkg-config \ python-setuptools protobuf-compiler git dh-python python3-protobuf python3-setuptools

Clone the EMANE repo: git clone https://github.com/adjacentlink/emane.git

Build debs: cd emane ./autogen.sh && ./configure && make deb

Install debs: cd .debbuild sudo dpkg -i *.deb sudo apt-get install -f

I didn't meet any problem in the official package building process, what do you think are the potential issues? .

szl0144 commented 4 years ago

Hi,

Sorry to trouble you on weekends, there is an update of my installation. 1) I notice a file named setup.py.in in the folder /emane/src/python.py.in. And I see some make files, so I run the command make in the folder. After the make command, I get the setup.py file.

2) Then I try to use the TDMA model in wlan, the core-daemon log file shows core.errors.CoreCommandError: Command(['emaneevent-tdmaschedule', '-i', 'b.9001.79', '/usr/local/share/core/examples/tdma/schedule.xml']), Status(1): stdout: stderr: unable to open: /usr/local/share/core/examples/tdma/schedule.xml Then I downloaded schedule.xml file from emane-tutorial/8 and change the TDMA configuration path to emane-tutorial/8. Then everything goes well now besides one small warning, but the warning seems not influence the demo. 2020-08-10 03:53:14,906 - WARNING - linkmonitor:setup - unknown emane link model: tdmaeventschedulerradiomodel 2020-08-10 03:53:14,907 - WARNING - linkmonitor:setup - unknown emane link model: tdmaeventschedulerradiomodel 2020-08-10 03:53:14,907 - WARNING - linkmonitor:setup - unknown emane link model: tdmaeventschedulerradiomodel 2020-08-10 03:53:14,908 - INFO - linkmonitor:start - no valid emane models to monitor links

3) I repeated the steps to install my 1.2.4 EMANE source code, but the python2/python3 error still happens. Then I migrated my code to EMANE 1.2.6. I install the new EMANE package into CORE, and there is no errors happen. When I checked the mgen.log file after I combined my EMANE with CORE, I found the result is different from EMANE with the same parameters. Because I changed the priority of packets in MAC layer queue in my EMANE code, I changed the queue discipline from FIFO to others, packets are saved in my new queue according to some key features such as creation time and packet length. The mgen log file in CORE shows there is no priority changes, the priority is still FIFO. But I see a clear priority change in EMANE mgen log file with same parameters. Can you please tell me whether CORE can read user custom revised EMANE source code? I will test my demo with several different parameters tomorrow in CORE to locate how the bug happens.

Thank you very much! Best, Shaoyi

szl0144 commented 4 years ago

Hi,

After installing several different version of my modified EMANE source code, the bug (CORE's simulation results of Queue discipline Performance are different from EMANE's) still happens. Then I use network tools to debug, I thought I find where the potential bug is. When I checked the packet using wireshark from EMANE's interface emanenode0 and transmitter node2's interface veth2.99.9 in CORE, I found their length of mgen header in bytes are totally different, CORE's length is about 96 bytes shorter than EMANE's. Because I use some information in packet mgen header, CORE read the wrong field from packet due to the length differences. I need to update my EMANE source code to comply with CORE. Can you please tell me is there any file to check the event information or print out variable from EMAME in CORE, such as emane.log? I think that will help me check if I read the correct filed from packet in CORE environment, I didn't find emane.log file in CORE. Thank you very much!

Best, Shaoyi

bharnden commented 4 years ago

EMANE handles processing packets and transporting them in their own unique way for emulating RF (https://github.com/adjacentlink/emane/wiki/Introduction). This is a separate process than anything CORE does.

CORE does also not handle any packets directly, it just connects linux namespaces using veths and bridges, so everything is handled by the linux networking stack.

In the latest release there is an EMANE log file for the emane daemon being ran on a node in the root directory of a node, prior releases had this file in the session directory. But these are EMANE specific log files and not COREs.

# session directory
/tmp/pycore.<session>

# node directory
/tmp/pycore.<session>/<node>.conf
szl0144 commented 4 years ago

Thank you for your information, I got it, the different lengths of packet header may be caused by different configuration in mgen. I think I set everything well in CORE. I have changed the EMANE code to read the field which represents packet creation time according to the packet capture result in wireshark. The packet priority sorting appear in the mgen log file in CORE. Although it seems I read the wrong field in packet header, I know where the previous bug happens. I will continue to find the correct field in packet header.

I went to the node folder /tmp/pycore./.conf and see a emane log file named eth0-emane.log, but it is always blank when I start the session, I can't see any event information in it, need I do any configuration to let the event information show up?

szl0144 commented 4 years ago

Hi,

I got where the problem is, I didn't set the emane log level to debug level in core.conf, so there is nothing shown in emane log file. I have find the correct field in mgen header after comparing packet data in wireshark and emane log file in CORE, the packet is sorted as I want in the queue module, I think everything about the configuration is done right now. I will start some simulations to see whether there are any other problems. Thank you for your patient reply!

Best, Shaoyi