Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[GCU] Loading yang-models only once #1981

Merged
merged 3 commits into from
Dec 22, 2021

Conversation

ghooo
Copy link
Contributor

@ghooo ghooo commented Dec 21, 2021

What I did

Loading sonic-yang models only once, and re-using them. This makes the sorting a lot faster.

How to verify loadYangModel took a lot of time?

Add the following snippet to TestPatchSorter

from pstats import Stats
import cProfile
class TestPatchSorter(...):
    def setUp(self):
        """init each test"""
        self.pr = cProfile.Profile()
        self.pr.enable()
        print("\n<<<---")
    def tearDown(self):
        """finish any test"""
        p = Stats (self.pr)
        p.strip_dirs()
        p.sort_stats ('cumtime')
        p.print_stats ()
        print("\n--->>>")
    .
    .
    .
    # Also update verify(self, cc_ops=[], tc_ops=[]) by commenting out changes validation to avoid extra calls to loadYangModels 
    def verify(self, cc_ops=[], tc_ops=[]):
        # Arrange
        config_wrapper=ConfigWrapper()
        target_config=jsonpatch.JsonPatch(tc_ops).apply(Files.CROPPED_CONFIG_DB_AS_JSON)
        current_config=jsonpatch.JsonPatch(cc_ops).apply(Files.CROPPED_CONFIG_DB_AS_JSON)
        patch=jsonpatch.make_patch(current_config, target_config)

        # Act
        actual = self.create_patch_sorter(current_config).sort(patch)

        # Assert
        # simulated_config = current_config
        # for move in actual:
        #     simulated_config = move.apply(simulated_config)
        #     self.assertTrue(config_wrapper.validate_config_db_config(simulated_config))
        # self.assertEqual(target_config, simulated_config)

Run

> python3 -m unittest patch_sorter_test.TestPatchSorter.test_sort__dpb_1_to_4__success 
.
.
.
         48986582 function calls (48933431 primitive calls) in 104.530 seconds

   Ordered by: cumulative time

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        1    0.000    0.000  104.530  104.530 case.py:549(_callTestMethod)
        1    0.000    0.000  104.530  104.530 patch_sorter_test.py:1889(test_sort__dpb_1_to_4__success)
        1    0.000    0.000  104.529  104.529 patch_sorter_test.py:1933(verify)
        1    0.005    0.005  104.527  104.527 patch_sorter.py:1332(sort)
     32/1    0.006    0.000  104.077  104.077 patch_sorter.py:955(sort)
      334    0.012    0.000   99.498    0.298 patch_sorter.py:310(validate)
      492    2.140    0.004   95.810    0.195 sonic_yang_ext.py:30(loadYangModel)  <=========

From the above we can see profiling data about test_sort__dpb_1_to_4__success:

  • Took 104.53s to complete
  • loadYangModel was called 492 times
  • loadYangModel took 95.810s.

loadYangModel is the method that loads the yang models from memory into SonicYang object. The loading of the YANG models should only happen once.

How I did it

Moved all calls to create sonic_yang object to ConfigWrapper, and each call to create a new instance just fills in the data for the yang models.

How to verify it

unit-test

Running profiling after the update:

> python3 -m unittest patch_sorter_test.TestPatchSorter.test_sort__dpb_1_to_4__success 
.
.
.
         702096 function calls (648951 primitive calls) in 2.882 seconds

   Ordered by: cumulative time

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        1    0.000    0.000    2.882    2.882 case.py:549(_callTestMethod)
        1    0.000    0.000    2.882    2.882 patch_sorter_test.py:1890(test_sort__dpb_1_to_4__success)
        1    0.002    0.002    2.881    2.881 patch_sorter_test.py:1934(verify)
        1    0.000    0.000    2.874    2.874 patch_sorter.py:1332(sort)
     32/1    0.004    0.000    2.705    2.705 patch_sorter.py:955(sort)
      334    0.008    0.000    2.242    0.007 patch_sorter.py:310(validate)
      490    0.080    0.000    1.791    0.004 sonic_yang_ext.py:1043(loadData)
      332    0.043    0.000    1.655    0.005 patch_sorter.py:345(validate)
      332    0.018    0.000    1.509    0.005 gu_common.py:112(validate_config_db_config)
        .
        .
        .
        1    0.002    0.002    0.164    0.164 sonic_yang_ext.py:30(loadYangModel)

From the above we can see profiling data about test_sort__dpb_1_to_4__success:

  • Took 2.882s to complete
  • loadYangModel was called 1time
  • loadYangModel took 0.164s.

profiling-after.txt

Previous command output (if the output of a command-line utility has changed)

New command output (if the output of a command-line utility has changed)

@@ -43,6 +43,7 @@ def __eq__(self, other):
class ConfigWrapper:
def __init__(self, yang_dir = YANG_DIR):
self.yang_dir = YANG_DIR
self.sonic_yang_with_loaded_models = None
Copy link
Contributor

@qiluo-msft qiluo-msft Dec 21, 2021

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

sonic_yang_with_loaded_models

Is sonic_yang_model good enough? #Closed

Copy link
Contributor Author

@ghooo ghooo Dec 21, 2021

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I don't think so. sonic_yang_model refers to the model but here we are referring to SonicYang object check code

This variable will hold an instance of SonicYang but with the models loaded hence the name

if self.sonic_yang_with_loaded_models is None:
loaded_models_sy = sonic_yang.SonicYang(self.yang_dir)
loaded_models_sy.loadYangModel()
self.sonic_yang_with_loaded_models = loaded_models_sy
Copy link
Contributor

@qiluo-msft qiluo-msft Dec 21, 2021

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Could you add comment which line spends most of the time? #Closed

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

ok

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

updated

@@ -258,6 +258,35 @@ def test_remove_empty_tables__multiple_empty_tables__returns_config_without_empt
# Assert
self.assertDictEqual({"any_table": {"key": "value"}}, actual)

def test_create_sonic_yang_with_loaded_models__creates_new_sonic_yang_every_call(self):
Copy link
Contributor

@qiluo-msft qiluo-msft Dec 21, 2021

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

test_create_sonic_yang_with_loaded_models__creates_new_sonic_yang_every_call

You mentioned

TestPatchSorter took ... Before: 800s

The performance comparison is interesting. Could you explain what happens in 800s? How can we repro your result by unit test? #Closed

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

updated pr description with profiling data for a specific case instead of all cases in TestPatchSorter

loaded_models_sy.loadYangModel()
self.sonic_yang_with_loaded_models = loaded_models_sy

# create a copy of sonic_yang_with_loaded_models, only copy the loaded yang models related properties
Copy link
Contributor

@qiluo-msft qiluo-msft Dec 21, 2021

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

create

This is similar to shallow copy. Did you consider https://docs.python.org/3/library/copy.html#copy.copy? #Closed

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Good idea

@ghooo ghooo merged commit 3b642c9 into sonic-net:master Dec 22, 2021
judyjoseph pushed a commit that referenced this pull request Jan 9, 2022
#### What I did
Loading sonic-yang models only once, and re-using them. This makes the sorting a lot faster.

How to verify `loadYangModel` took a lot of time?

Add the following snippet to `TestPatchSorter`
```python
from pstats import Stats
import cProfile
class TestPatchSorter(...):
    def setUp(self):
        """init each test"""
        self.pr = cProfile.Profile()
        self.pr.enable()
        print("\n<<<---")
    def tearDown(self):
        """finish any test"""
        p = Stats (self.pr)
        p.strip_dirs()
        p.sort_stats ('cumtime')
        p.print_stats ()
        print("\n--->>>")
    .
    .
    .
    # Also update verify(self, cc_ops=[], tc_ops=[]) by commenting out changes validation to avoid extra calls to loadYangModels 
    def verify(self, cc_ops=[], tc_ops=[]):
        # Arrange
        config_wrapper=ConfigWrapper()
        target_config=jsonpatch.JsonPatch(tc_ops).apply(Files.CROPPED_CONFIG_DB_AS_JSON)
        current_config=jsonpatch.JsonPatch(cc_ops).apply(Files.CROPPED_CONFIG_DB_AS_JSON)
        patch=jsonpatch.make_patch(current_config, target_config)

        # Act
        actual = self.create_patch_sorter(current_config).sort(patch)

        # Assert
        # simulated_config = current_config
        # for move in actual:
        #     simulated_config = move.apply(simulated_config)
        #     self.assertTrue(config_wrapper.validate_config_db_config(simulated_config))
        # self.assertEqual(target_config, simulated_config)

```
Run
```
> python3 -m unittest patch_sorter_test.TestPatchSorter.test_sort__dpb_1_to_4__success 
.
.
.
         48986582 function calls (48933431 primitive calls) in 104.530 seconds

   Ordered by: cumulative time

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        1    0.000    0.000  104.530  104.530 case.py:549(_callTestMethod)
        1    0.000    0.000  104.530  104.530 patch_sorter_test.py:1889(test_sort__dpb_1_to_4__success)
        1    0.000    0.000  104.529  104.529 patch_sorter_test.py:1933(verify)
        1    0.005    0.005  104.527  104.527 patch_sorter.py:1332(sort)
     32/1    0.006    0.000  104.077  104.077 patch_sorter.py:955(sort)
      334    0.012    0.000   99.498    0.298 patch_sorter.py:310(validate)
      492    2.140    0.004   95.810    0.195 sonic_yang_ext.py:30(loadYangModel)  <=========
```

From the above we can see profiling data about test_sort__dpb_1_to_4__success:
- Took 104.53s to complete
- loadYangModel was called 492 times
- loadYangModel took 95.810s.

loadYangModel is the method that loads the yang models from memory into SonicYang object. The loading of the YANG models should only happen once.

#### How I did it
Moved all calls to create sonic_yang object to ConfigWrapper, and each call to create a new instance just fills in the data for the yang models.

#### How to verify it
unit-test

Running profiling after the update:
```
> python3 -m unittest patch_sorter_test.TestPatchSorter.test_sort__dpb_1_to_4__success 
.
.
.
         702096 function calls (648951 primitive calls) in 2.882 seconds

   Ordered by: cumulative time

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        1    0.000    0.000    2.882    2.882 case.py:549(_callTestMethod)
        1    0.000    0.000    2.882    2.882 patch_sorter_test.py:1890(test_sort__dpb_1_to_4__success)
        1    0.002    0.002    2.881    2.881 patch_sorter_test.py:1934(verify)
        1    0.000    0.000    2.874    2.874 patch_sorter.py:1332(sort)
     32/1    0.004    0.000    2.705    2.705 patch_sorter.py:955(sort)
      334    0.008    0.000    2.242    0.007 patch_sorter.py:310(validate)
      490    0.080    0.000    1.791    0.004 sonic_yang_ext.py:1043(loadData)
      332    0.043    0.000    1.655    0.005 patch_sorter.py:345(validate)
      332    0.018    0.000    1.509    0.005 gu_common.py:112(validate_config_db_config)
        .
        .
        .
        1    0.002    0.002    0.164    0.164 sonic_yang_ext.py:30(loadYangModel)
```
From the above we can see profiling data about test_sort__dpb_1_to_4__success:
- Took 2.882s to complete
- loadYangModel was called 1time
- loadYangModel took 0.164s.

[profiling-after.txt](https://github.com/Azure/sonic-utilities/files/7757252/profiling-after.txt)

#### Previous command output (if the output of a command-line utility has changed)

#### New command output (if the output of a command-line utility has changed)
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging this pull request may close these issues.

3 participants