coreemu / core

Common Open Research Emulator
BSD 2-Clause "Simplified" License
683 stars 165 forks source link

Using custom services under python API results in not working core-daemon #193

Closed emirljuca closed 6 years ago

emirljuca commented 6 years ago

I am using CORE 5.2 with Ubuntu 18.04.

I have a custom service that I include in myservices that I would normally add to the core.conf file for the core-gui to find. However, when I want to use those services under the python API I can add the services fine but when I boot the nodes, I get some errors.

To add the services with the python API, I use the following lines...

SERVICES = /path/to/services
from core.service import ServiceManager
ServiceManager.add_services(SERVICES)

To run the emulation of a specific xml file with nodes running the custom service, I run the following lines...

emu = CoreEmu()
session = emu.create_session()

a = session.open_xml("/path/to/xml.xml", start=True)

However I get the following error when running under pycharm (my IDE of choice)...

Traceback (most recent call last):
  File "/home/dev/pycharm-community-2018.1.4/helpers/pydev/pydevd.py", line 1664, in <module>
    main()
  File "/home/dev/pycharm-community-2018.1.4/helpers/pydev/pydevd.py", line 1658, in main
    globals = debugger.run(setup['file'], None, None, is_module)
  File "/home/dev/pycharm-community-2018.1.4/helpers/pydev/pydevd.py", line 1068, in run
    pydev_imports.execfile(file, globals, locals)  # execute the script
  File "/home/dev/.PyCharmCE2018.1/config/scratches/scratch.py", line 9, in <module>
    a = session.open_xml("/path/to/xml.xml", start=True)
  File "/usr/local/lib/python2.7/dist-packages/core/emulator/coreemu.py", line 670, in open_xml
    self.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 572, in get
    raise self._value
AttributeError: 'NoneType' object has no attribute 'endswith'

where it would normally work within the GUI. After this error, when I try to run the core-gui with the specific xml file, the nodes never start up. I tried stopping the core-daemon with no success.

Am I using the xmlsession incorrectly? Is there a better way I am supposed to use it.

bharnden commented 6 years ago

I assume you will find the usage of "endswith" within your custom service. Something is going wrong when it is trying to start.

Looks like the expectation of something being a string and actually None.

I need to update the exception handling during bootup to catch and log these types of errors, which would give much better context, than what gets returned from the multiprocessing module.

siliconja commented 6 years ago

I think that I ran into that same problem when migrating some of my scripts from 4.8 to 5.2, due to missing session metadata...

Does this patch fix it?:

--- a/daemon/core/corehandlers.py
+++ b/daemon/core/corehandlers.py
@@ -1759,8 +1759,12 @@ class CoreHandler(SocketServer.BaseRequestHandler):
         self.session.broadcast_config(config_data)

         # send session metadata
-        data_values = "|".join(["%s=%s" % item for item in self.session.metadata.get_configs().iteritems()])
-        data_types = tuple(ConfigDataTypes.STRING.value for _ in self.session.metadata.get_configs())
+        if self.session.metadata.get_configs() is None:
+            data_values = "canvas c1={name {Canvas1}}"
+            data_types = (ConfigDataTypes.STRING.value,)
+        else:
+            data_values = "|".join(["%s=%s" % item for item in self.session.metadata.get_configs().iteritems()])
+            data_types = tuple(ConfigDataTypes.STRING.value for _ in self.session.metadata.get_configs())
         config_data = ConfigData(
             message_type=0,
             object=self.session.metadata.name,
emirljuca commented 6 years ago

@siliconja After doing a uninstall, patch, and install of the core files I tried running my custom services under the gui with the following error. Is this something you have seen before?

2018-09-25 10:57:24,333 - INFO - service:add - loading service: class(CustomService) name(ServiceStartup)
2018-09-25 10:57:24,334 - ERROR - core-daemon:cored - error starting main server on:  localhost:4038
Traceback (most recent call last):
  File "/usr/local/bin/core-daemon", line 44, in cored
    server = CoreServer((host, port), CoreHandler, cfg)
  File "/usr/local/lib/python2.7/dist-packages/core/coreserver.py", line 30, in __init__
    SocketServer.TCPServer.__init__(self, server_address, handler_class)
  File "/usr/lib/python2.7/SocketServer.py", line 417, in __init__
    self.server_bind()
  File "/usr/lib/python2.7/SocketServer.py", line 431, in server_bind
    self.socket.bind(self.server_address)
  File "/usr/lib/python2.7/socket.py", line 228, in meth
    return getattr(self._sock,name)(*args)
error: [Errno 98] Address already in use
2018-09-25 10:57:24,334 - INFO - coreemu:shutdown - shutting down all sessions
siliconja commented 6 years ago

well in this 2nd case, it appears you have two core-daemons running (?); you can shut them all down using sudo core-cleanup -d

(unless somehow your custom service is trying to start a 2nd daemon...)

bharnden commented 6 years ago

I replied with what you error is related to, in your case, it is not related to the patch above.

emirljuca commented 6 years ago

@bharnden Thanks for your reply, but I had the service running under the core-gui without this type of error. When I ran it with the python API however, I was getting these errors.

@siliconja After restarting I get the following issues with zebra...

2018-09-25 13:01:08,770 - ERROR - corehandlers:handle_message - Thread-2: 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 572, in get
    raise self._value
ServiceBootError: node(n2) service(zebra) failed validation

Should I maybe do another clean install of CORE without the patch to see if there is problems?

bharnden commented 6 years ago

Service start validation is more strict now and there are times when the validation check for zebra occurs before being up.

It uses:

pidof zebra

There needs to be a tweak on our end to retry validation for "validation_time" as it is hard to guarantee a timing between systems and different loads.

You can retry running it a couple times for success or would need to modify how that service is getting validated.

bharnden commented 6 years ago

I pushed some updates in relation to custom services that may help and/or provide better information about what went wrong.

Validation will now be repeated for NON_BLOCKING service up until "validation_timer" every "validation_period" delay.

defaults:

validation_timer = 5
validation_period = 0.5

This should hopefully catch timing issues with some default services, like Zebra above and can be tweaked for custom services as well, as need be.

There is also now exception logging at a closer level for service boot failures, that should provide a better stack trace for any issues happening there.

emirljuca commented 6 years ago

To start, I haven't changed the defaults that you mentioned which may be the problem here. Regardless I will go over what I did to get to the failures I see now.

After a make uninstall, git pull, ./bootstrap, ./configure, make clean, make, sudo make install, I was able to get the core-gui in a working order again where I wasn't seeing the same problems as my last comment. After this I changed the core.conf to include my custom service and I started a node with my custom service. Everything was working as expected. I had my script launch a python script that failed and it didn't crash the daemon and logged the crash in the tmp file which is as expected.

I then ran the xml file with an instantiated emulator through the following code...

SERVICES = "/home/user/.core/myservices"
from core.emulator.coreemu import CoreEmu
from core.service import ServiceManager
ServiceManager.add_services(SERVICES)

emu = CoreEmu()
session = emu.create_session()

a = session.open_xml("/home/user/.core/configs/test.xml", start=True)

emu.shutdown()

and received the following log output... My service name is Startup with class name StartService

2018-09-27 10:29:37,055 - INFO - service:add - loading service: class(StartService) name(Startup)
2018-09-27 10:29:37,055 - INFO - service:add - loading service: class(MyService) name(MyService)
2018-09-27 10:29:37,056 - INFO - nodeutils:_log_map - node type (TAP_BRIDGE) - class (GreTapBridge)
2018-09-27 10:29:37,056 - INFO - nodeutils:_log_map - node type (DEFAULT) - class (CoreNode)
2018-09-27 10:29:37,056 - INFO - nodeutils:_log_map - node type (WIRELESS_LAN) - class (WlanNode)
2018-09-27 10:29:37,056 - INFO - nodeutils:_log_map - node type (EMANE_NET) - class (EmaneNet)
2018-09-27 10:29:37,056 - INFO - nodeutils:_log_map - node type (EMANE) - class (EmaneNode)
2018-09-27 10:29:37,056 - INFO - nodeutils:_log_map - node type (PHYSICAL) - class (PhysicalNode)
2018-09-27 10:29:37,056 - INFO - nodeutils:_log_map - node type (CONTROL_NET) - class (CtrlNet)
2018-09-27 10:29:37,056 - INFO - nodeutils:_log_map - node type (HUB) - class (HubNode)
2018-09-27 10:29:37,056 - INFO - nodeutils:_log_map - node type (TUNNEL) - class (TunnelNode)
2018-09-27 10:29:37,057 - INFO - nodeutils:_log_map - node type (PEER_TO_PEER) - class (PtpNet)
2018-09-27 10:29:37,057 - INFO - nodeutils:_log_map - node type (RJ45) - class (RJ45Node)
2018-09-27 10:29:37,057 - INFO - nodeutils:_log_map - node type (SWITCH) - class (SwitchNode)
2018-09-27 10:29:37,057 - INFO - nodeutils:_log_map - node type (KTUNNEL) - class (None)
2018-09-27 10:29:37,057 - INFO - nodeutils:_log_map - node type (TBD) - class (None)
2018-09-27 10:29:37,220 - WARNING - dockersvc:<module> - missing python docker bindings
2018-09-27 10:29:37,222 - INFO - service:add - loading service: class(Bird) name(bird)
2018-09-27 10:29:37,223 - INFO - service:add - loading service: class(BirdBgp) name(BIRD_BGP)
2018-09-27 10:29:37,223 - INFO - service:add - loading service: class(BirdOspf) name(BIRD_OSPFv2)
2018-09-27 10:29:37,223 - INFO - service:add - loading service: class(BirdRadv) name(BIRD_RADV)
2018-09-27 10:29:37,223 - INFO - service:add - loading service: class(BirdRip) name(BIRD_RIP)
2018-09-27 10:29:37,223 - INFO - service:add - loading service: class(BirdStatic) name(BIRD_static)
2018-09-27 10:29:37,224 - INFO - service:add - loading service: class(EmaneTransportService) name(transportd)
2018-09-27 10:29:37,224 - INFO - service:add - loading service: class(AtdService) name(atd)
2018-09-27 10:29:37,224 - INFO - service:add - loading service: class(DefaultMulticastRouteService) name(DefaultMulticastRoute)
2018-09-27 10:29:37,224 - INFO - service:add - loading service: class(DefaultRouteService) name(DefaultRoute)
2018-09-27 10:29:37,225 - INFO - service:add - loading service: class(DhcpClientService) name(DHCPClient)
2018-09-27 10:29:37,225 - INFO - service:add - loading service: class(DhcpService) name(DHCP)
2018-09-27 10:29:37,225 - INFO - service:add - loading service: class(FtpService) name(FTP)
2018-09-27 10:29:37,225 - INFO - service:add - loading service: class(HttpService) name(HTTP)
2018-09-27 10:29:37,225 - INFO - service:add - loading service: class(IPForwardService) name(IPForward)
2018-09-27 10:29:37,225 - INFO - service:add - loading service: class(PcapService) name(pcap)
2018-09-27 10:29:37,225 - INFO - service:add - loading service: class(RadvdService) name(radvd)
2018-09-27 10:29:37,226 - INFO - service:add - loading service: class(SshService) name(SSH)
2018-09-27 10:29:37,226 - INFO - service:add - loading service: class(StaticRouteService) name(StaticRoute)
2018-09-27 10:29:37,226 - INFO - service:add - loading service: class(UserDefinedService) name(UserDefined)
2018-09-27 10:29:37,226 - INFO - service:add - loading service: class(Firewall) name(Firewall)
2018-09-27 10:29:37,226 - INFO - service:add - loading service: class(IPsec) name(IPsec)
2018-09-27 10:29:37,226 - INFO - service:add - loading service: class(VPNClient) name(VPNClient)
2018-09-27 10:29:37,226 - INFO - service:add - loading service: class(VPNServer) name(VPNServer)
2018-09-27 10:29:37,226 - INFO - service:add - loading service: class(Ucarp) name(ucarp)
2018-09-27 10:29:37,226 - INFO - service:add - loading service: class(DockerService) name(Docker)
2018-09-27 10:29:37,227 - WARNING - service:add - service(Docker) missing executable: docker
2018-09-27 10:29:37,227 - WARNING - service:add_services - not loading service: service(Docker) missing executable: docker
2018-09-27 10:29:37,227 - INFO - service:add - loading service: class(Babel) name(Babel)
2018-09-27 10:29:37,227 - INFO - service:add - loading service: class(Bgp) name(BGP)
2018-09-27 10:29:37,227 - INFO - service:add - loading service: class(Ospfv2) name(OSPFv2)
2018-09-27 10:29:37,227 - INFO - service:add - loading service: class(Ospfv3) name(OSPFv3)
2018-09-27 10:29:37,228 - INFO - service:add - loading service: class(Ospfv3mdr) name(OSPFv3MDR)
2018-09-27 10:29:37,228 - INFO - service:add - loading service: class(Rip) name(RIP)
2018-09-27 10:29:37,228 - INFO - service:add - loading service: class(Ripng) name(RIPNG)
2018-09-27 10:29:37,228 - INFO - service:add - loading service: class(Xpimd) name(Xpimd)
2018-09-27 10:29:37,228 - INFO - service:add - loading service: class(Zebra) name(zebra)
2018-09-27 10:29:37,228 - INFO - service:add - loading service: class(OvsService) name(OvsService)
2018-09-27 10:29:37,228 - INFO - service:add - loading service: class(RyuService) name(ryuService)
2018-09-27 10:29:37,229 - WARNING - service:add - service(ryuService) missing executable: ryu-manager
2018-09-27 10:29:37,229 - WARNING - service:add_services - not loading service: service(ryuService) missing executable: ryu-manager
2018-09-27 10:29:37,229 - INFO - service:add - loading service: class(XorpBgp) name(XORP_BGP)
2018-09-27 10:29:37,229 - INFO - service:add - loading service: class(XorpOlsr) name(XORP_OLSR)
2018-09-27 10:29:37,229 - INFO - service:add - loading service: class(XorpOspfv2) name(XORP_OSPFv2)
2018-09-27 10:29:37,229 - INFO - service:add - loading service: class(XorpOspfv3) name(XORP_OSPFv3)
2018-09-27 10:29:37,229 - INFO - service:add - loading service: class(XorpPimSm4) name(XORP_PIMSM4)
2018-09-27 10:29:37,230 - INFO - service:add - loading service: class(XorpPimSm6) name(XORP_PIMSM6)
2018-09-27 10:29:37,230 - INFO - service:add - loading service: class(XorpRip) name(XORP_RIP)
2018-09-27 10:29:37,230 - INFO - service:add - loading service: class(XorpRipng) name(XORP_RIPNG)
2018-09-27 10:29:37,230 - INFO - service:add - loading service: class(XorpRtrmgr) name(xorp_rtrmgr)
2018-09-27 10:29:37,230 - INFO - service:add - loading service: class(Arouted) name(arouted)
2018-09-27 10:29:37,230 - WARNING - service:add - service(arouted) missing executable: arouted
2018-09-27 10:29:37,231 - WARNING - service:add_services - not loading service: service(arouted) missing executable: arouted
2018-09-27 10:29:37,231 - INFO - service:add - loading service: class(MgenActor) name(MgenActor)
2018-09-27 10:29:37,231 - INFO - service:add - loading service: class(MgenSinkService) name(MGEN_Sink)
2018-09-27 10:29:37,231 - INFO - service:add - loading service: class(NrlNhdp) name(NHDP)
2018-09-27 10:29:37,231 - WARNING - service:add - service(NHDP) missing executable: nrlnhdp
2018-09-27 10:29:37,231 - WARNING - service:add_services - not loading service: service(NHDP) missing executable: nrlnhdp
2018-09-27 10:29:37,231 - INFO - service:add - loading service: class(NrlOlsr) name(OLSR)
2018-09-27 10:29:37,232 - WARNING - service:add - service(OLSR) missing executable: nrlolsrd
2018-09-27 10:29:37,232 - WARNING - service:add_services - not loading service: service(OLSR) missing executable: nrlolsrd
2018-09-27 10:29:37,232 - INFO - service:add - loading service: class(NrlOlsrv2) name(OLSRv2)
2018-09-27 10:29:37,232 - WARNING - service:add - service(OLSRv2) missing executable: nrlolsrv2
2018-09-27 10:29:37,232 - WARNING - service:add_services - not loading service: service(OLSRv2) missing executable: nrlolsrv2
2018-09-27 10:29:37,232 - INFO - service:add - loading service: class(NrlSmf) name(SMF)
2018-09-27 10:29:37,232 - WARNING - service:add - service(SMF) missing executable: nrlsmf
2018-09-27 10:29:37,232 - WARNING - service:add_services - not loading service: service(SMF) missing executable: nrlsmf
2018-09-27 10:29:37,232 - INFO - service:add - loading service: class(OlsrOrg) name(OLSRORG)
2018-09-27 10:29:37,234 - INFO - broker:addserver - adding broker server(localhost): None:None
2018-09-27 10:29:37,750 - INFO - emanemanager:emane_check - using EMANE: 1.2.2
2018-09-27 10:29:37,751 - INFO - emanemanager:load_models - loading emane model: EmaneRfPipeModel
2018-09-27 10:29:37,751 - INFO - emanemanager:load_models - loading emane model: EmaneIeee80211abgModel
2018-09-27 10:29:37,751 - INFO - emanemanager:load_models - loading emane model: EmaneCommEffectModel
2018-09-27 10:29:37,751 - INFO - emanemanager:load_models - loading emane model: EmaneBypassModel
2018-09-27 10:29:37,751 - INFO - emanemanager:load_models - loading emane model: EmaneTdmaModel
2018-09-27 10:29:37,752 - INFO - coreemu:create_session - created session: 60000
2018-09-27 10:29:39,779 - INFO - broker:reset - clearing state
2018-09-27 10:29:39,780 - INFO - corexml:read_default_services - reading default services for nodes(ncp): ['Startup', 'OSPFv2', 'OSPFv3', 'zebra', 'IPForward']
2018-09-27 10:29:39,780 - INFO - corexml:read_default_services - reading default services for nodes(PC): ['DefaultRoute']
2018-09-27 10:29:39,781 - INFO - corexml:read_default_services - reading default services for nodes(host): ['DefaultRoute', 'SSH']
2018-09-27 10:29:39,781 - INFO - corexml:read_default_services - reading default services for nodes(prouter): ['zebra', 'OSPFv2', 'OSPFv3', 'IPForward']
2018-09-27 10:29:39,781 - INFO - corexml:read_default_services - reading default services for nodes(mdr): ['zebra', 'OSPFv3MDR', 'IPForward']
2018-09-27 10:29:39,781 - INFO - corexml:read_default_services - reading default services for nodes(router): ['zebra', 'OSPFv2', 'OSPFv3', 'IPForward']
2018-09-27 10:29:39,782 - INFO - corexml:read_session_metadata - reading session metadata: {'global_options': 'interface_names=no ip_addresses=yes ipv6_addresses=yes node_labels=yes link_labels=yes show_api=no background_images=no annotations=yes grid=yes traffic_start=0', 'canvas c1': '{name {Canvas1}}'}
2018-09-27 10:29:39,782 - INFO - corexml:read_session_origin - reading session reference geo: 47.5791667, -122.132322, 2.0
2018-09-27 10:29:39,782 - INFO - corexml:read_session_origin - reading session reference scale: 150.0
2018-09-27 10:29:39,783 - INFO - corexml:read_device - reading node id(1) model(ncp) name(n1)
2018-09-27 10:29:39,783 - INFO - coreemu:add_node - creating node(CoreNode) id(1) name(n1) start(False)
2018-09-27 10:29:39,784 - INFO - service:add_services - setting services for node(n1): ['Startup', 'OSPFv2', 'OSPFv3', 'zebra', 'IPForward']
2018-09-27 10:29:39,784 - INFO - service:add_services - adding service to node(n1): Startup
2018-09-27 10:29:39,784 - INFO - service:add_services - adding service to node(n1): OSPFv2
2018-09-27 10:29:39,785 - INFO - service:add_services - adding service to node(n1): OSPFv3
2018-09-27 10:29:39,785 - INFO - service:add_services - adding service to node(n1): zebra
2018-09-27 10:29:39,785 - INFO - service:add_services - adding service to node(n1): IPForward
2018-09-27 10:29:39,785 - INFO - corexml:read_device - reading node id(2) model(ncp) name(n2)
2018-09-27 10:29:39,786 - INFO - coreemu:add_node - creating node(CoreNode) id(2) name(n2) start(False)
2018-09-27 10:29:39,786 - INFO - service:add_services - setting services for node(n2): ['Startup', 'OSPFv2', 'OSPFv3', 'zebra', 'IPForward']
2018-09-27 10:29:39,786 - INFO - service:add_services - adding service to node(n2): Startup
2018-09-27 10:29:39,787 - INFO - service:add_services - adding service to node(n2): OSPFv2
2018-09-27 10:29:39,787 - INFO - service:add_services - adding service to node(n2): OSPFv3
2018-09-27 10:29:39,787 - INFO - service:add_services - adding service to node(n2): zebra
2018-09-27 10:29:39,787 - INFO - service:add_services - adding service to node(n2): IPForward
2018-09-27 10:29:39,788 - INFO - corexml:read_device - reading node id(3) model(ncp) name(n3)
2018-09-27 10:29:39,788 - INFO - coreemu:add_node - creating node(CoreNode) id(3) name(n3) start(False)
2018-09-27 10:29:39,788 - INFO - service:add_services - setting services for node(n3): ['Startup', 'OSPFv2', 'OSPFv3', 'zebra', 'IPForward']
2018-09-27 10:29:39,788 - INFO - service:add_services - adding service to node(n3): Startup
2018-09-27 10:29:39,789 - INFO - service:add_services - adding service to node(n3): OSPFv2
2018-09-27 10:29:39,789 - INFO - service:add_services - adding service to node(n3): OSPFv3
2018-09-27 10:29:39,789 - INFO - service:add_services - adding service to node(n3): zebra
2018-09-27 10:29:39,789 - INFO - service:add_services - adding service to node(n3): IPForward
2018-09-27 10:29:39,790 - INFO - corexml:read_links - reading link node_one(1) node_two(2)
2018-09-27 10:29:39,790 - INFO - coreemu:add_link - adding link for peer to peer nodes: n1 - n2
2018-09-27 10:29:39,790 - INFO - coreemu:add_link - adding link from node to network: n1 - 5743
2018-09-27 10:29:39,791 - INFO - coreemu:add_link - adding link from network to node: n2 - 5743
2018-09-27 10:29:39,792 - INFO - corexml:read_links - reading link node_one(2) node_two(3)
2018-09-27 10:29:39,792 - INFO - coreemu:add_link - adding link for peer to peer nodes: n2 - n3
2018-09-27 10:29:39,792 - INFO - coreemu:add_link - adding link from node to network: n2 - 33723
2018-09-27 10:29:39,793 - INFO - coreemu:add_link - adding link from network to node: n3 - 33723
2018-09-27 10:29:39,798 - INFO - session:boot_nodes - booting node: n1
2018-09-27 10:29:39,799 - INFO - session:boot_nodes - booting node: n2
2018-09-27 10:29:39,806 - INFO - session:boot_nodes - booting node: n3
2018-09-27 10:29:39,812 - INFO - service:_start_boot_paths - booting node services: zebra -> OSPFv2 -> OSPFv3
2018-09-27 10:29:39,813 - INFO - service:boot_service - starting node(n1) service(zebra) validation(NON_BLOCKING)
2018-09-27 10:29:39,813 - INFO - service:_start_boot_paths - booting node services: Startup
2018-09-27 10:29:39,814 - INFO - service:_start_boot_paths - booting node services: IPForward
2018-09-27 10:29:39,815 - INFO - service:boot_service - starting node(n1) service(Startup) validation(NON_BLOCKING)
2018-09-27 10:29:39,815 - ERROR - service:_start_boot_paths - exception booting service: zebra
Traceback (most recent call last):
  File "/usr/local/lib/python2.7/dist-packages/core/service.py", line 451, in _start_boot_paths
    self.boot_service(node, service)
  File "/usr/local/lib/python2.7/dist-packages/core/service.py", line 470, in boot_service
    node.privatedir(directory)
  File "/usr/local/lib/python2.7/dist-packages/core/netns/vnode.py", line 543, in privatedir
    hostpath = os.path.join(self.nodedir, os.path.normpath(path).strip("/").replace("/", "."))
  File "/usr/lib/python2.7/posixpath.py", line 70, in join
    elif path == '' or path.endswith('/'):
AttributeError: 'NoneType' object has no attribute 'endswith'
2018-09-27 10:29:39,816 - INFO - service:boot_service - starting node(n1) service(IPForward) validation(NON_BLOCKING)
2018-09-27 10:29:39,817 - INFO - service:create_service_files - node(n1) service(Startup) creating config files
2018-09-27 10:29:39,823 - INFO - service:create_service_files - node(n1) service(IPForward) creating config files
2018-09-27 10:29:39,824 - INFO - startservice:generate_config - - n1 - THE FOLLOWING WON'T WORK ON FREEBSD OR MAC
2018-09-27 10:29:39,825 - ERROR - service:_start_boot_paths - exception booting service: IPForward
Traceback (most recent call last):
  File "/usr/local/lib/python2.7/dist-packages/core/service.py", line 451, in _start_boot_paths
    self.boot_service(node, service)
  File "/usr/local/lib/python2.7/dist-packages/core/service.py", line 473, in boot_service
    self.create_service_files(node, service)
  File "/usr/local/lib/python2.7/dist-packages/core/service.py", line 708, in create_service_files
    node.nodefile(file_name, cfg)
  File "/usr/local/lib/python2.7/dist-packages/core/netns/vnode.py", line 587, in nodefile
    with self.opennodefile(filename, "w") as open_file:
  File "/usr/local/lib/python2.7/dist-packages/core/netns/vnode.py", line 572, in opennodefile
    hostfilename = self.hostfilename(filename)
  File "/usr/local/lib/python2.7/dist-packages/core/netns/vnode.py", line 560, in hostfilename
    dirname = os.path.join(self.nodedir, dirname)
  File "/usr/lib/python2.7/posixpath.py", line 70, in join
    elif path == '' or path.endswith('/'):
AttributeError: 'NoneType' object has no attribute 'endswith'
2018-09-27 10:29:39,827 - INFO - service:_start_boot_paths - booting node services: zebra -> OSPFv2 -> OSPFv3
2018-09-27 10:29:39,827 - ERROR - service:_start_boot_paths - exception booting service: Startup
Traceback (most recent call last):
  File "/usr/local/lib/python2.7/dist-packages/core/service.py", line 451, in _start_boot_paths
    self.boot_service(node, service)
  File "/usr/local/lib/python2.7/dist-packages/core/service.py", line 473, in boot_service
    self.create_service_files(node, service)
  File "/usr/local/lib/python2.7/dist-packages/core/service.py", line 708, in create_service_files
    node.nodefile(file_name, cfg)
  File "/usr/local/lib/python2.7/dist-packages/core/netns/vnode.py", line 587, in nodefile
    with self.opennodefile(filename, "w") as open_file:
  File "/usr/local/lib/python2.7/dist-packages/core/netns/vnode.py", line 572, in opennodefile
    hostfilename = self.hostfilename(filename)
  File "/usr/local/lib/python2.7/dist-packages/core/netns/vnode.py", line 560, in hostfilename
    dirname = os.path.join(self.nodedir, dirname)
  File "/usr/lib/python2.7/posixpath.py", line 70, in join
    elif path == '' or path.endswith('/'):
AttributeError: 'NoneType' object has no attribute 'endswith'
2018-09-27 10:29:39,827 - INFO - service:_start_boot_paths - booting node services: IPForward
2018-09-27 10:29:39,828 - INFO - service:_start_boot_paths - booting node services: Startup
2018-09-27 10:29:39,830 - INFO - service:boot_service - starting node(n2) service(zebra) validation(NON_BLOCKING)
2018-09-27 10:29:39,832 - INFO - service:boot_service - starting node(n2) service(IPForward) validation(NON_BLOCKING)
2018-09-27 10:29:39,833 - ERROR - service:_start_boot_paths - exception booting service: zebra
Traceback (most recent call last):
  File "/usr/local/lib/python2.7/dist-packages/core/service.py", line 451, in _start_boot_paths
    self.boot_service(node, service)
  File "/usr/local/lib/python2.7/dist-packages/core/service.py", line 470, in boot_service
    node.privatedir(directory)
  File "/usr/local/lib/python2.7/dist-packages/core/netns/vnode.py", line 543, in privatedir
    hostpath = os.path.join(self.nodedir, os.path.normpath(path).strip("/").replace("/", "."))
  File "/usr/lib/python2.7/posixpath.py", line 70, in join
    elif path == '' or path.endswith('/'):
AttributeError: 'NoneType' object has no attribute 'endswith'
2018-09-27 10:29:39,834 - INFO - service:boot_service - starting node(n2) service(Startup) validation(NON_BLOCKING)
2018-09-27 10:29:39,835 - INFO - service:create_service_files - node(n2) service(IPForward) creating config files
2018-09-27 10:29:39,836 - INFO - service:create_service_files - node(n2) service(Startup) creating config files
2018-09-27 10:29:39,837 - ERROR - service:_start_boot_paths - exception booting service: IPForward
Traceback (most recent call last):
  File "/usr/local/lib/python2.7/dist-packages/core/service.py", line 451, in _start_boot_paths
    self.boot_service(node, service)
  File "/usr/local/lib/python2.7/dist-packages/core/service.py", line 473, in boot_service
    self.create_service_files(node, service)
  File "/usr/local/lib/python2.7/dist-packages/core/service.py", line 708, in create_service_files
    node.nodefile(file_name, cfg)
  File "/usr/local/lib/python2.7/dist-packages/core/netns/vnode.py", line 587, in nodefile
    with self.opennodefile(filename, "w") as open_file:
  File "/usr/local/lib/python2.7/dist-packages/core/netns/vnode.py", line 572, in opennodefile
    hostfilename = self.hostfilename(filename)
  File "/usr/local/lib/python2.7/dist-packages/core/netns/vnode.py", line 560, in hostfilename
    dirname = os.path.join(self.nodedir, dirname)
  File "/usr/lib/python2.7/posixpath.py", line 70, in join
    elif path == '' or path.endswith('/'):
AttributeError: 'NoneType' object has no attribute 'endswith'
2018-09-27 10:29:39,837 - INFO - startservice:generate_config - - n2 - THE FOLLOWING WON'T WORK ON FREEBSD OR MAC
2018-09-27 10:29:39,838 - INFO - service:_start_boot_paths - booting node services: zebra -> OSPFv2 -> OSPFv3
2018-09-27 10:29:39,840 - INFO - service:_start_boot_paths - booting node services: Startup
2018-09-27 10:29:39,841 - INFO - service:boot_service - starting node(n3) service(zebra) validation(NON_BLOCKING)
2018-09-27 10:29:39,841 - INFO - service:boot_service - starting node(n3) service(Startup) validation(NON_BLOCKING)
2018-09-27 10:29:39,840 - INFO - service:_start_boot_paths - booting node services: IPForward
2018-09-27 10:29:39,841 - ERROR - service:_start_boot_paths - exception booting service: Startup
Traceback (most recent call last):
  File "/usr/local/lib/python2.7/dist-packages/core/service.py", line 451, in _start_boot_paths
    self.boot_service(node, service)
  File "/usr/local/lib/python2.7/dist-packages/core/service.py", line 473, in boot_service
    self.create_service_files(node, service)
  File "/usr/local/lib/python2.7/dist-packages/core/service.py", line 708, in create_service_files
    node.nodefile(file_name, cfg)
  File "/usr/local/lib/python2.7/dist-packages/core/netns/vnode.py", line 587, in nodefile
    with self.opennodefile(filename, "w") as open_file:
  File "/usr/local/lib/python2.7/dist-packages/core/netns/vnode.py", line 572, in opennodefile
    hostfilename = self.hostfilename(filename)
  File "/usr/local/lib/python2.7/dist-packages/core/netns/vnode.py", line 560, in hostfilename
    dirname = os.path.join(self.nodedir, dirname)
  File "/usr/lib/python2.7/posixpath.py", line 70, in join
    elif path == '' or path.endswith('/'):
AttributeError: 'NoneType' object has no attribute 'endswith'
2018-09-27 10:29:39,842 - ERROR - service:_start_boot_paths - exception booting service: zebra
Traceback (most recent call last):
  File "/usr/local/lib/python2.7/dist-packages/core/service.py", line 451, in _start_boot_paths
    self.boot_service(node, service)
  File "/usr/local/lib/python2.7/dist-packages/core/service.py", line 470, in boot_service
    node.privatedir(directory)
  File "/usr/local/lib/python2.7/dist-packages/core/netns/vnode.py", line 543, in privatedir
    hostpath = os.path.join(self.nodedir, os.path.normpath(path).strip("/").replace("/", "."))
  File "/usr/lib/python2.7/posixpath.py", line 70, in join
    elif path == '' or path.endswith('/'):
AttributeError: 'NoneType' object has no attribute 'endswith'
2018-09-27 10:29:39,842 - INFO - service:create_service_files - node(n3) service(Startup) creating config files
2018-09-27 10:29:39,843 - INFO - service:boot_service - starting node(n3) service(IPForward) validation(NON_BLOCKING)
2018-09-27 10:29:39,844 - INFO - startservice:generate_config - - n3 - THE FOLLOWING WON'T WORK ON FREEBSD OR MAC
2018-09-27 10:29:39,845 - INFO - service:create_service_files - node(n3) service(IPForward) creating config files
2018-09-27 10:29:39,845 - ERROR - service:_start_boot_paths - exception booting service: Startup
Traceback (most recent call last):
  File "/usr/local/lib/python2.7/dist-packages/core/service.py", line 451, in _start_boot_paths
    self.boot_service(node, service)
  File "/usr/local/lib/python2.7/dist-packages/core/service.py", line 473, in boot_service
    self.create_service_files(node, service)
  File "/usr/local/lib/python2.7/dist-packages/core/service.py", line 708, in create_service_files
    node.nodefile(file_name, cfg)
  File "/usr/local/lib/python2.7/dist-packages/core/netns/vnode.py", line 587, in nodefile
    with self.opennodefile(filename, "w") as open_file:
  File "/usr/local/lib/python2.7/dist-packages/core/netns/vnode.py", line 572, in opennodefile
    hostfilename = self.hostfilename(filename)
  File "/usr/local/lib/python2.7/dist-packages/core/netns/vnode.py", line 560, in hostfilename
    dirname = os.path.join(self.nodedir, dirname)
  File "/usr/lib/python2.7/posixpath.py", line 70, in join
    elif path == '' or path.endswith('/'):
AttributeError: 'NoneType' object has no attribute 'endswith'
2018-09-27 10:29:39,845 - ERROR - service:_start_boot_paths - exception booting service: IPForward
Traceback (most recent call last):
  File "/usr/local/lib/python2.7/dist-packages/core/service.py", line 451, in _start_boot_paths
    self.boot_service(node, service)
  File "/usr/local/lib/python2.7/dist-packages/core/service.py", line 473, in boot_service
    self.create_service_files(node, service)
  File "/usr/local/lib/python2.7/dist-packages/core/service.py", line 708, in create_service_files
    node.nodefile(file_name, cfg)
  File "/usr/local/lib/python2.7/dist-packages/core/netns/vnode.py", line 587, in nodefile
    with self.opennodefile(filename, "w") as open_file:
  File "/usr/local/lib/python2.7/dist-packages/core/netns/vnode.py", line 572, in opennodefile
    hostfilename = self.hostfilename(filename)
  File "/usr/local/lib/python2.7/dist-packages/core/netns/vnode.py", line 560, in hostfilename
    dirname = os.path.join(self.nodedir, dirname)
  File "/usr/lib/python2.7/posixpath.py", line 70, in join
    elif path == '' or path.endswith('/'):
AttributeError: 'NoneType' object has no attribute 'endswith'
Traceback (most recent call last):
  File "/home/dev/pycharm-community-2018.1.4/helpers/pydev/pydevd.py", line 1664, in <module>
    main()
  File "/home/dev/pycharm-community-2018.1.4/helpers/pydev/pydevd.py", line 1658, in main
    globals = debugger.run(setup['file'], None, None, is_module)
  File "/home/dev/pycharm-community-2018.1.4/helpers/pydev/pydevd.py", line 1068, in run
    pydev_imports.execfile(file, globals, locals)  # execute the script
  File "/home/dev/.PyCharmCE2018.1/config/scratches/scratch.py", line 9, in <module>
    a = session.open_xml("/home/dev/.core/configs/test.xml", start=True)
  File "/usr/local/lib/python2.7/dist-packages/core/emulator/coreemu.py", line 670, in open_xml
    self.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 572, in get
    raise self._value
AttributeError: 'NoneType' object has no attribute 'endswith'

Thanks for your time on this, I sincerely appreciate it!

bharnden commented 6 years ago

This should fix your problem after locally testing your example.

SERVICES = "/home/user/.core/myservices"
from core.emulator.coreemu import CoreEmu
from core.service import ServiceManager
from core.enumerations import EventTypes

ServiceManager.add_services(SERVICES)

emu = CoreEmu()
session = emu.create_session()
session.set_state(EventTypes.CONFIGURATION_STATE)
a = session.open_xml("/home/user/.core/configs/test.xml", start=True)

emu.shutdown()
emirljuca commented 6 years ago

Okay, awesome, it seems to have worked fine this time without an exception. I have a few lines where I get errors for zebra as follows...

2018-09-27 11:25:32,728 - ERROR - service:validate_service - node(n3) service(zebra) validate failed
2018-09-27 11:25:32,728 - ERROR - service:validate_service - cmd(pidof zebra): 

however this does not crash the API, which is great. Thanks again for your help, however could I get a bit of an explanation on this?

bharnden commented 6 years ago

The errors listed are for now initial failures to validate the service the first time around, after trying again later it succeeded. These can be changed to warnings, might be more appropriate.

The EventTypes values in this case help define some constant values, that are really integers, to use for various interactions. Along with other values within the "core.enumerations" module.

This section of documentation talks about scripting, but can definitely be improved. Most usage is based around using the GUI, scripting isn't documented as much and has its own quirks due to the code base being based more so on the GUI. The configuration state is needed for nodes to start up appropriately. Otherwise their node directories do not get created, which caused the errors you had before.

I am not sure what you are trying to do with your service to advise on debugging it, but any exceptions that may occur will at least be logged better.

emirljuca commented 6 years ago

Okay, thanks for all the information and help. I will be looking at the document you provided for python API scripting related functions.