cancel
Showing results for 
Search instead for 
Did you mean: 
cancel
693
Views
15
Helpful
8
Replies
Highlighted

I'm trying to attach() to an existing Service transaction to use _ncs.maapi.load_config_cmds() to reduce template.apply() calls

The reason I would like to use _ncs.maapi.load_config_cmds() it to see how much time is saves us on the service we are developing. Currently, we want to allow ranges in for access switches. Such as range could be 1-2/1/1-200. I am currently using python to convert this range into the proper interfaces. That part works fine. The issue is when trying to apply the service template, we have to make a template.apply('template-name', vars) for every interface. This becomes costly quick.

 

For example:

1 interface on 1 device took .18 seconds.

interface GigabitEthernet 1/1/1
Command executed in 0.18 sec

 But 401 interfaces on 1 device took 35.33 seconds.

interface GigabitEthernet 1-2/1/1-200;
interface GigabitEthernet 1/1/1;

Command executed in 35.33 sec

 

This is a huge increase. My understanding is that this is due to context switching between python and ncs for each apply template that is called. Our idea is to build the template as a string in the python (inserting the variables where needed) and then call _ncs.maapi.load_config_cmds() and pass the string in for a one time load.

 

The issue I'm having is attaching the _ncs.maapi transaction to the existing service transaction so that it is all one commit and can be seen in the dry-run.

 

So first off, is this possible.

Second, is it a good idea (given the time it takes to prepare the config for a single switch - 35 seconds).

 

 

So I've been trying a couple of different things, but I'm not certain if I know how to attach to the existing service transaction, or if it will even work. I was trying to follow  vleijon example (https://community.cisco.com/t5/nso-developer-hub-discussions/call-partial-sync-from-function-in-cb-create/m-p/3898446/highlight/true#M4079):

@Action.action
def cb_action(self, uinfo, name, kp, input, output):
m = maapi.Maapi()
m.start_user_session(uinfo.username, 'test_context')
t = m.attach(uinfo.actx_thandle, 0, uinfo.usid)

But it uses ncs.maapi(), and the ncs.maapi.attach() is different than the _ncs.maapi.attach() from what I was seeing in the pydocs.

 

So below is what we were trying to setup the _ncs maapi.

class Mmaapi:
  def __init__(self, tctx, name='MMaapi'):
    self.s = socket.socket()
    ncs.maapi.connect(self.s, '127.0.0.1', _ncs.NCS_PORT)
    # ncs.maapi.start_user_session(self.s, tctx.uinfo.username, name, [], '127.0.0.1', _ncs.PROTO_TCP)
    # self.th = _ncs.maapi.start_trans(self.s, _ncs.RUNNING, _ncs.READ_WRITE)
    ncs.maapi.attach(self.s, 0, tctx)
    # Do I need to start a transaction if I'm attaching to the existing service transaction?
    # If I do, do I attach first and then start a transaction, or start the transaction and then attach?

class ServiceCallbacks(Service):
    @Service.create
    def cb_create(self, tctx, root, service, proplist):
        self.log.info('Service create(service=', service._path, ')')
        # Parsing interfaces is left out for brevity
        # Building xml string is left out for brevity
        m = Mmaapi(tctx)
        _ncs.maapi.load_config_cmds(m.s,
                                    # m.th,
                                    tctx.th,
                                    _ncs.maapi.CONFIG_MERGE | _ncs.maapi.CONFIG_XML,
                                    xml, '')
        # Commented out iteration for applying template per interface
        '''
        for interface_key in full.keys():
            for interface in full[interface_key]:
                vars = ncs.template.Variables()
                vars.add('INT_NUM', interface)
                vars.add('INT_NAME', interface_key.split(' ')[0])
                template = ncs.template.Template(service)
                template.apply('rbac-interface-template', vars)
         '''
        # Apply global templates
        template = ncs.template.Template(service)
        template.apply('rbac-template')

 

This is really my first time getting into interact with existing transactions and I'm not certain exactly how to do it, or what the implications may be (is this an okay/good idea).

1 ACCEPTED SOLUTION

Accepted Solutions
Highlighted
Cisco Employee

There is a lot to unpack here, and a few different questions - your analysis is definitely reasonable, the context switch is expensive.

 

I'll start with the top-level issue around performance: There are a few different ways of doing this, one would be to try and move the for-loop into the template, if that is not too complicated that is probably the best option. Another option is to calculate it in python, put it in a temporary structure for consumption in the template.

 

I also want to take this opportunity to share a best practice that one of my colleagues have been working on: https://developer.cisco.com/docs/nso/#!performance-scaling that may have some interesting material for you around performance.

 

The second question is around using load_config_cmds, that is certainly possible (though I'd explore this after the previous options have been considered). However, you do not need to attach to a transaction, rather, in your cb_create method you already have access to that transaction through the root and service objects (they are ncs.maagic objects). So, you could do something like (untested):

trans = maagic.get_trans(service)
trans.load_config_cmds(ncs.maapi.CONFIG_MERGE | _ncs.maapi.CONFIG_XML, xml, ''))

to use the call directly.

 

Hopefully this is helpful.

 

View solution in original post

8 REPLIES 8
Highlighted
Cisco Employee

There is a lot to unpack here, and a few different questions - your analysis is definitely reasonable, the context switch is expensive.

 

I'll start with the top-level issue around performance: There are a few different ways of doing this, one would be to try and move the for-loop into the template, if that is not too complicated that is probably the best option. Another option is to calculate it in python, put it in a temporary structure for consumption in the template.

 

I also want to take this opportunity to share a best practice that one of my colleagues have been working on: https://developer.cisco.com/docs/nso/#!performance-scaling that may have some interesting material for you around performance.

 

The second question is around using load_config_cmds, that is certainly possible (though I'd explore this after the previous options have been considered). However, you do not need to attach to a transaction, rather, in your cb_create method you already have access to that transaction through the root and service objects (they are ncs.maagic objects). So, you could do something like (untested):

trans = maagic.get_trans(service)
trans.load_config_cmds(ncs.maapi.CONFIG_MERGE | _ncs.maapi.CONFIG_XML, xml, ''))

to use the call directly.

 

Hopefully this is helpful.

 

View solution in original post

Highlighted

Hi Viktor,

 

Thanks for your responses, they are very helpful.

 

In response to "move the for-loop into the template": We either can't do this, or don't know how to. This is because we'd like to maintain the range formatting (e.g., GigabitEthernet 1-2/1/1-200) which I don't believe is supported by YANG and therefore requires python logic.

 

In response to "calculate it in python, put it in a temporary structure for consumption in the template": I was considering this. The first attempt we tried, was to pass in a list generated from python and do a foreach over it. This doesn't work, as the XML treats the python list as a single value, and not like a leaf-list to iterate over (not certain how it works under the hood, but that is a close description to what I have experienced). I think we could maybe pass in the min and max of the list and do a for loop over that to reduce template.apply() calls, however the ranges we allow may make it a bit more complicated.

 

I tested the example code you shared an it worked as expected and desired!

trans = ncs.maagic.get_trans(service)
trans.load_config_cmds(ncs.maapi.CONFIG_MERGE | _ncs.maapi.CONFIG_XML, xml, ''))

 

So we now have a working solution, however I'm curious if see a misunderstanding in my response to: "calculate it in python, put it in a temporary structure for consumption in the template".

Highlighted

Interesting, after having trans.load_config_cmds() work, I had some time to play around with it and it takes just as long as the for loop for doing the template.apply().

 

interface GigabitEthernet 1-2/1/1-200

Command executed in 35.64 sec

I may need to consider a different approach.

 

Any idea why calling load_config_cmds once on a large string that has the 400 interfaces in xml format would take just as long as calling template.apply() 400 times?

Highlighted

So, every api call is a context switch, because the call has to go over the RPC socket. To get a big gain, you want to build the entire string at once and do a single call.
Highlighted

That is exactly what I'm doing. I for loop through and build the string. After the string is completely built, I make one call

trans.load_config_cmds(_ncs.maapi.CONFIG_MERGE | _ncs.maapi.CONFIG_XML, xml, '')

 

The thing that I found weird, is that the single call of trans.load_config_cmds() was taking just as long as when I made 400 context switches with template.apply() (one template.apply() for each interface).

 

Perhaps this is from NSO performing the diff on the 400 interfaces? If so, I don't actually see any performance hit from context switching (yet).

Highlighted

That is surprising. I mean, you would expect four hundred to take more time than one, but not that bad exactly. Try using commit dry-run | details to see where the time is spent!
Highlighted

 
Highlighted

So I ran it a couple of times, and the results were pretty consistent with similar values.

 

It looks like it takes 7 seconds for service create, 7 seconds for saving FASTMAP reverse diff-set and then 23 seconds on the prepare.

template.apply('rbac-interface-template', vars)

-------

sam@ncs(config-rbac-test)# commit dry-run | details very-verbose
entering validate phase for running (tid=886, session-id=47)...
 2020-03-13T11:43:04.371 validate: run pre-trans-lock service callbacks...
 2020-03-13T11:43:04.371 validate: run transforms and transaction hooks...
 2020-03-13T11:43:04.373 validate: run transforms and transaction hooks done [0.001 sec]
 2020-03-13T11:43:04.373 validate: pre-trans-lock service callbacks done [0.001 sec]
 2020-03-13T11:43:04.373 validate: grabbing transaction lock... ok [0.001 sec]
 2020-03-13T11:43:04.375 validate: run transforms and transaction hooks...
 2020-03-13T11:43:04.376 ncs: service /services/rbac:rbac[name='test']: pre-modification: service pre-modification...
 2020-03-13T11:43:04.376 ncs: service /services/rbac:rbac[name='test']: pre-modification: service pre-modification ok [0.000 sec]
 2020-03-13T11:43:04.376 ncs: service /services/rbac:rbac[name='test']: applying FASTMAP reverse diff-set...
 2020-03-13T11:43:04.380 ncs: service /services/rbac:rbac[name='test']: applying FASTMAP reverse diff-set ok [0.003 sec]
 2020-03-13T11:43:04.380 ncs: service /services/rbac:rbac[name='test']: create: service create...
 2020-03-13T11:43:11.562 ncs: service /services/rbac:rbac[name='test']: create: service create ok [7.181 sec]
 2020-03-13T11:43:11.562 ncs: service /services/rbac:rbac[name='test']: saving FASTMAP reverse diff-set and applying changes...
 2020-03-13T11:43:17.306 ncs: service /services/rbac:rbac[name='test']: saving FASTMAP reverse diff-set and applying changes ok [5.744 sec]
 2020-03-13T11:43:17.320 ncs: service /services/rbac:rbac[name='test']: post-modification: service post-modification...
 2020-03-13T11:43:17.320 ncs: service /services/rbac:rbac[name='test']: post-modification: service post-modification ok [0.000 sec]
 2020-03-13T11:43:17.579 validate: run transforms and transaction hooks done [13.204 sec]
 2020-03-13T11:43:17.579 validate: mark inactive... ok [0.339 sec]
 2020-03-13T11:43:17.918 validate: pre validate... ok [0.395 sec]
 2020-03-13T11:43:18.315 validate: run validation over the change set...
 2020-03-13T11:43:18.937 validate: validation over the change set done [0.622 sec]
 2020-03-13T11:43:18.937 validate: run dependency-triggered validation...
 2020-03-13T11:43:18.939 validate: dependency-triggered validation done [0.001 sec]
 2020-03-13T11:43:18.939 validate: check configuration policies...
 2020-03-13T11:43:18.939 validate: configuration policies done [0.000 sec]
entering write-start phase for running (tid=886, session-id=47)...
 2020-03-13T11:43:18.939 cdb: write-start
entering prepare phase for running (tid=886, session-id=47)...
 2020-03-13T11:43:19.522 cdb: prepare
 2020-03-13T11:43:19.522 ncs-internal-device-mgr: prepare
entering abort phase for running (tid=886, session-id=47)...
 2020-03-13T11:43:42.900 cdb: abort
cli {
...

-------

sam@ncs(config-rbac-test)# timecmd commit dry-run
Command executed in 38.85 sec
It looks like it takes 5 seconds for service create, 4 seconds for saving FASTMAP reverse diff-set and then 23 seconds on the prepare.

trans.load_config_cmds()

-------

sam@ncs(config-rbac-test)# commit dry-run | details very-verbose
entering validate phase for running (tid=928, session-id=47)...
 2020-03-13T11:47:07.622 validate: run pre-trans-lock service callbacks...
 2020-03-13T11:47:07.622 validate: run transforms and transaction hooks...
 2020-03-13T11:47:07.624 validate: run transforms and transaction hooks done [0.001 sec]
 2020-03-13T11:47:07.624 validate: pre-trans-lock service callbacks done [0.001 sec]
 2020-03-13T11:47:07.624 validate: grabbing transaction lock... ok [0.001 sec]
 2020-03-13T11:47:07.625 validate: run transforms and transaction hooks...
 2020-03-13T11:47:07.626 ncs: service /services/rbac:rbac[name='test']: pre-modification: service pre-modification...
 2020-03-13T11:47:07.627 ncs: service /services/rbac:rbac[name='test']: pre-modification: service pre-modification ok [0.000 sec]
 2020-03-13T11:47:07.627 ncs: service /services/rbac:rbac[name='test']: applying FASTMAP reverse diff-set...
 2020-03-13T11:47:07.631 ncs: service /services/rbac:rbac[name='test']: applying FASTMAP reverse diff-set ok [0.004 sec]
 2020-03-13T11:47:07.632 ncs: service /services/rbac:rbac[name='test']: create: service create...
 2020-03-13T11:47:12.189 ncs: service /services/rbac:rbac[name='test']: create: service create ok [4.557 sec]
 2020-03-13T11:47:12.189 ncs: service /services/rbac:rbac[name='test']: saving FASTMAP reverse diff-set and applying changes...
 2020-03-13T11:47:16.428 ncs: service /services/rbac:rbac[name='test']: saving FASTMAP reverse diff-set and applying changes ok [4.238 sec]
 2020-03-13T11:47:16.440 ncs: service /services/rbac:rbac[name='test']: post-modification: service post-modification...
 2020-03-13T11:47:16.441 ncs: service /services/rbac:rbac[name='test']: post-modification: service post-modification ok [0.000 sec]
 2020-03-13T11:47:16.712 validate: run transforms and transaction hooks done [9.087 sec]
 2020-03-13T11:47:16.712 validate: mark inactive... ok [0.334 sec]
 2020-03-13T11:47:17.047 validate: pre validate... ok [0.405 sec]
 2020-03-13T11:47:17.453 validate: run validation over the change set...
 2020-03-13T11:47:18.078 validate: validation over the change set done [0.624 sec]
 2020-03-13T11:47:18.078 validate: run dependency-triggered validation...
 2020-03-13T11:47:18.079 validate: dependency-triggered validation done [0.001 sec]
 2020-03-13T11:47:18.079 validate: check configuration policies...
 2020-03-13T11:47:18.080 validate: configuration policies done [0.000 sec]
entering write-start phase for running (tid=928, session-id=47)...
 2020-03-13T11:47:18.080 cdb: write-start
entering prepare phase for running (tid=928, session-id=47)...
 2020-03-13T11:47:18.604 cdb: prepare
 2020-03-13T11:47:18.604 ncs-internal-device-mgr: prepare
entering abort phase for running (tid=928, session-id=47)...
 2020-03-13T11:47:41.948 cdb: abort
cli {
...

-------

sam@ncs(config-rbac-test)# timecmd commit dry-run
Command executed in 34.95 sec

I used logs in the ncs-python-vm-rbac.log to ensure it was using the expected method of deployment/configuring (just incase I forgot package reload), these are the results. They are very similar. I ran it a couple of times to confirm, the majority followed this time split.