# -*- coding: utf-8 -*-
# Part of Odoo. See LICENSE file for full copyright and licensing details.
import time

from odoo.exceptions import AccessError
from odoo.tests.common import BaseCase, TransactionCase, tagged, new_test_user
from odoo.tools import profiler
from odoo.tools.profiler import Profiler, ExecutionContext
from odoo.tools.speedscope import Speedscope


@tagged('post_install', '-at_install', 'profiling')
# post_install to ensure mail is already loaded if installed (new_test_user would fail otherwise because of notification_type)
class TestProfileAccess(TransactionCase):

    @classmethod
    def setUpClass(cls):
        super().setUpClass()
        cls.test_profile = cls.env['ir.profile'].create({})

    def test_admin_has_access(self):
        self.assertEqual(self.env['ir.profile'].search([('id', '=', self.test_profile.id)]), self.test_profile)
        self.test_profile.read(['name'])

    def test_user_no_access(self):
        user = new_test_user(self.env, login='noProfile', groups='base.group_user')
        with self.with_user('noProfile'), self.assertRaises(AccessError):
            self.env['ir.profile'].search([])
        with self.assertRaises(AccessError):
            self.test_profile.with_user(user).read(['name'])


@tagged('post_install', '-at_install', 'profiling')
class TestSpeedscope(BaseCase):
    def example_profile(self):
        return {
            'init_stack_trace': [['/path/to/file_1.py', 135, '__main__', 'main()']],
            'result': [{  # init frame
                'start': 2.0,
                'exec_context': (),
                'stack': [
                    ['/path/to/file_1.py', 10, 'main', 'do_stuff1(test=do_tests)'],
                    ['/path/to/file_1.py', 101, 'do_stuff1', 'cr.execute(query, params)'],
                ],
            }, {
                'start': 3.0,
                'exec_context': (),
                'stack': [
                    ['/path/to/file_1.py', 10, 'main', 'do_stuff1(test=do_tests)'],
                    ['/path/to/file_1.py', 101, 'do_stuff1', 'cr.execute(query, params)'],
                    ['/path/to/sql_db.py', 650, 'execute', 'res = self._obj.execute(query, params)'],
                ],
            }, {  # duplicate frame
                'start': 4.0,
                'exec_context': (),
                'stack': [
                    ['/path/to/file_1.py', 10, 'main', 'do_stuff1(test=do_tests)'],
                    ['/path/to/file_1.py', 101, 'do_stuff1', 'cr.execute(query, params)'],
                    ['/path/to/sql_db.py', 650, 'execute', 'res = self._obj.execute(query, params)'],
                ],
            }, {  # other frame
                'start': 6.0,
                'exec_context': (),
                'stack': [
                    ['/path/to/file_1.py', 10, 'main', 'do_stuff1(test=do_tests)'],
                    ['/path/to/file_1.py', 101, 'do_stuff1', 'check'],
                    ['/path/to/sql_db.py', 650, 'check', 'assert x = y'],
                ],
            }, {  # out of frame
                'start': 10.0,
                'exec_context': (),
                'stack': [
                    ['/path/to/file_1.py', 10, 'main', 'do_stuff1(test=do_tests)'],
                    ['/path/to/file_1.py', 101, 'do_stuff1', 'for i in range(10):'],
                ],
            }, {  # final frame
                'start': 10.35,
                'exec_context': (),
                'stack': None,
            }],
        }

    def test_convert_empty(self):
        Speedscope().make()

    def test_converts_profile_simple(self):
        profile = self.example_profile()

        sp = Speedscope(init_stack_trace=profile['init_stack_trace'])
        sp.add('profile', profile['result'])
        sp.add_output(['profile'], complete=False)
        res = sp.make()

        frames = res['shared']['frames']
        self.assertEqual(len(frames), 4)

        profile_combined = res['profiles'][0]
        events = [(e['type'], e['frame']) for e in profile_combined['events']]
        self.assertEqual(events, [
            ('O', 0),  # /main
            ('O', 1),  # /main/do_stuff1
            ('O', 2),  # /main/do_stuff1/execute
            ('C', 2),  # /main/do_stuff1
            ('O', 3),  # /main/do_stuff1/check
            ('C', 3),  # /main/do_stuff1
            ('C', 1),  # /main
            ('C', 0),  # /
        ])
        self.assertEqual(profile_combined['events'][0]['at'], 0.0)
        self.assertEqual(profile_combined['events'][-1]['at'], 8.35)

    def test_converts_profile_no_end(self):
        profile = self.example_profile()
        profile['result'].pop()

        sp = Speedscope(init_stack_trace=profile['init_stack_trace'])
        sp.add('profile', profile['result'])
        sp.add_output(['profile'], complete=False)
        res = sp.make()
        profile_combined = res['profiles'][0]
        events = [(e['type'], e['frame']) for e in profile_combined['events']]

        self.assertEqual(events, [
            ('O', 0),  # /main
            ('O', 1),  # /main/do_stuff1
            ('O', 2),  # /main/do_stuff1/execute
            ('C', 2),  # /main/do_stuff1
            ('O', 3),  # /main/do_stuff1/check
            ('C', 3),  # /main/do_stuff1
            ('C', 1),  # /main
            ('C', 0),  # /
        ])
        self.assertEqual(profile_combined['events'][-1]['at'], 8)

    def test_converts_init_stack_trace(self):
        profile = self.example_profile()

        sp = Speedscope(init_stack_trace=profile['init_stack_trace'])
        sp.add('profile', profile['result'])
        sp.add_output(['profile'], complete=True)
        res = sp.make()

        profile_combined = res['profiles'][0]
        events = [(e['type'], e['frame']) for e in profile_combined['events']]

        self.assertEqual(events, [
            ('O', 4),  # /__main__/
            ('O', 0),  # /__main__/main
            ('O', 1),  # /__main__/main/do_stuff1
            ('O', 2),  # /__main__/main/do_stuff1/execute
            ('C', 2),  # /__main__/main/do_stuff1
            ('O', 3),  # /__main__/main/do_stuff1/check
            ('C', 3),  # /__main__/main/do_stuff1
            ('C', 1),  # /__main__/main
            ('C', 0),  # /__main__/
            ('C', 4),  # /
        ])
        self.assertEqual(profile_combined['events'][-1]['at'], 8.35)

    def test_end_priority(self):
        """
        If a sample as a time (usually a query) we expect to keep the complete frame
        even if another concurent frame tics before the end of the current one:
        frame duration should always be more reliable.
        """

        async_profile = self.example_profile()['result']
        sql_profile = self.example_profile()['result']
        # make sql_profile a single frame from 2.5 to 5.5
        sql_profile = [sql_profile[1]]
        sql_profile[0]['start'] = 2.5
        sql_profile[0]['time'] = 3
        sql_profile[0]['query'] = 'SELECT 1'
        sql_profile[0]['full_query'] = 'SELECT 1'
        # some check to ensure the take makes sence
        self.assertEqual(async_profile[1]['start'], 3)
        self.assertEqual(async_profile[2]['start'], 4)

        self.assertNotIn('query', async_profile[1]['stack'])
        self.assertNotIn('time', async_profile[1]['stack'])
        self.assertEqual(async_profile[1]['stack'], async_profile[2]['stack'])
        # this last assertion is not really useful but ensures that the samples
        # are consistent with the sql one, just missing tue query

        sp = Speedscope(init_stack_trace=[])
        sp.add('sql', async_profile)
        sp.add('traces', sql_profile)
        sp.add_output(['sql', 'traces'], complete=False)
        res = sp.make()
        profile_combined = res['profiles'][0]
        events = [
            (e['at']+2, e['type'], res['shared']['frames'][e['frame']]['name'])
            for e in profile_combined['events']
        ]
        self.assertEqual(events, [
            # pylint: disable=bad-continuation
            (2.0, 'O', 'main'),
                (2.0, 'O', 'do_stuff1'),
                    (2.5, 'O', 'execute'),
                        (2.5, 'O', "sql('SELECT 1')"),
                        (5.5, 'C', "sql('SELECT 1')"),  # select ends at 5.5 as expected despite another concurent frame at 3 and 4
                    (5.5, 'C', 'execute'),
                    (6.0, 'O', 'check'),
                    (10.0, 'C', 'check'),
                (10.35, 'C', 'do_stuff1'),
            (10.35, 'C', 'main'),
        ])

    def test_converts_context(self):
        stack = [
            ['file.py', 10, 'level1', 'level1'],
            ['file.py', 11, 'level2', 'level2'],
        ]
        profile = {
            'init_stack_trace': [['file.py', 1, 'level0', 'level0)']],
            'result': [{  # init frame
                'start': 2.0,
                'exec_context': ((2, {'a': '1'}), (3, {'b': '1'})),
                'stack': list(stack),
            }, {
                'start': 3.0,
                'exec_context': ((2, {'a': '1'}), (3, {'b': '2'})),
                'stack': list(stack),
            }, {  # final frame
                'start': 10.35,
                'exec_context': (),
                'stack': None,
            }],
        }
        sp = Speedscope(init_stack_trace=profile['init_stack_trace'])
        sp.add('profile', profile['result'])
        sp.add_output(['profile'], complete=True)
        res = sp.make()
        events = [
            (e['type'], res['shared']['frames'][e['frame']]['name'])
            for e in res['profiles'][0]['events']
        ]
        self.assertEqual(events, [
            # pylint: disable=bad-continuation
            ('O', 'level0'),
                ('O', 'a=1'),
                    ('O', 'level1'),
                        ('O', 'b=1'),
                            ('O', 'level2'),
                            ('C', 'level2'),
                        ('C', 'b=1'),
                        ('O', 'b=2'),
                            ('O', 'level2'),
                            ('C', 'level2'),
                        ('C', 'b=2'),
                    ('C', 'level1'),
                ('C', 'a=1'),
            ('C', 'level0'),
        ])

    def test_converts_context_nested(self):
        stack = [
            ['file.py', 10, 'level1', 'level1'],
            ['file.py', 11, 'level2', 'level2'],
        ]
        profile = {
            'init_stack_trace': [['file.py', 1, 'level0', 'level0)']],
            'result': [{  # init frame
                'start': 2.0,
                'exec_context': ((3, {'a': '1'}), (3, {'b': '1'})),  # two contexts at the same level
                'stack': list(stack),
            }, {  # final frame
                'start': 10.35,
                'exec_context': (),
                'stack': None,
            }],
        }
        sp = Speedscope(init_stack_trace=profile['init_stack_trace'])
        sp.add('profile', profile['result'])
        sp.add_output(['profile'], complete=True)
        res = sp.make()
        events = [
            (e['type'], res['shared']['frames'][e['frame']]['name'])
            for e in res['profiles'][0]['events']
        ]
        self.assertEqual(events, [
            # pylint: disable=bad-continuation
            ('O', 'level0'),
                ('O', 'level1'),
                    ('O', 'a=1'),
                        ('O', 'b=1'),
                            ('O', 'level2'),
                            ('C', 'level2'),
                        ('C', 'b=1'),
                    ('C', 'a=1'),
                ('C', 'level1'),
            ('C', 'level0'),
        ])

    def test_converts_context_lower(self):
        stack = [
            ['file.py', 10, 'level4', 'level4'],
            ['file.py', 11, 'level5', 'level5'],
        ]
        profile = {
            'init_stack_trace': [
                ['file.py', 1, 'level0', 'level0'],
                ['file.py', 1, 'level1', 'level1'],
                ['file.py', 1, 'level2', 'level2'],
                ['file.py', 1, 'level3', 'level3'],
            ],
            'result': [{  # init frame
                'start': 2.0,
                'exec_context': ((2, {'a': '1'}), (6, {'b': '1'})),
                'stack': list(stack),
            }, {  # final frame
                'start': 10.35,
                'exec_context': (),
                'stack': None,
            }],
        }
        sp = Speedscope(init_stack_trace=profile['init_stack_trace'])
        sp.add('profile', profile['result'])
        sp.add_output(['profile'], complete=False)
        res = sp.make()
        events = [
            (e['type'], res['shared']['frames'][e['frame']]['name'])
            for e in res['profiles'][0]['events']
        ]
        self.assertEqual(events, [
            # pylint: disable=bad-continuation
            ('O', 'level4'),
                ('O', 'b=1'),
                    ('O', 'level5'),
                    ('C', 'level5'),
                ('C', 'b=1'),
            ('C', 'level4'),
        ])

    def test_converts_no_context(self):
        stack = [
            ['file.py', 10, 'level4', 'level4'],
            ['file.py', 11, 'level5', 'level5'],
        ]
        profile = {
            'init_stack_trace': [
                ['file.py', 1, 'level0', 'level0'],
                ['file.py', 1, 'level1', 'level1'],
                ['file.py', 1, 'level2', 'level2'],
                ['file.py', 1, 'level3', 'level3'],
            ],
            'result': [{  # init frame
                'start': 2.0,
                'exec_context': ((2, {'a': '1'}), (6, {'b': '1'})),
                'stack': list(stack),
            }, {  # final frame
                'start': 10.35,
                'exec_context': (),
                'stack': None,
            }],
        }
        sp = Speedscope(init_stack_trace=profile['init_stack_trace'])
        sp.add('profile', profile['result'])
        sp.add_output(['profile'], complete=False, use_context=False)
        res = sp.make()
        events = [
            (e['type'], res['shared']['frames'][e['frame']]['name'])
            for e in res['profiles'][0]['events']
        ]
        self.assertEqual(events, [
            # pylint: disable=bad-continuation
            ('O', 'level4'),
                ('O', 'level5'),
                ('C', 'level5'),
            ('C', 'level4'),
        ])


@tagged('post_install', '-at_install', 'profiling')
class TestProfiling(TransactionCase):

    def test_default_values(self):
        p = Profiler()
        self.assertEqual(p.db, self.env.cr.dbname)

    def test_env_profiler_database(self):
        p = Profiler(collectors=[])
        self.assertEqual(p.db, self.env.cr.dbname)

    def test_env_profiler_description(self):
        with Profiler(collectors=[], db=None) as p:
            self.assertIn('test_env_profiler_description', p.description)

    def test_execution_context_save(self):
        with Profiler(db=None, collectors=['sql']) as p:
            for letter in ('a', 'b'):
                stack_level = profiler.stack_size()
                with ExecutionContext(letter=letter):
                    self.env.cr.execute('SELECT 1')
        entries = p.collectors[0].entries
        self.assertEqual(entries.pop(0)['exec_context'], ((stack_level, {'letter': 'a'}),))
        self.assertEqual(entries.pop(0)['exec_context'], ((stack_level, {'letter': 'b'}),))

    def test_execution_context_nested(self):
        """
        This test checks that an execution can be nested at the same level of the stack.
        """
        with Profiler(db=None, collectors=['sql']) as p:
            stack_level = profiler.stack_size()
            with ExecutionContext(letter='a'):
                self.env.cr.execute('SELECT 1')
                with ExecutionContext(letter='b'):
                    self.env.cr.execute('SELECT 1')
                with ExecutionContext(letter='c'):
                    self.env.cr.execute('SELECT 1')
                self.env.cr.execute('SELECT 1')
        entries = p.collectors[0].entries
        self.assertEqual(entries.pop(0)['exec_context'], ((stack_level, {'letter': 'a'}),))
        self.assertEqual(entries.pop(0)['exec_context'], ((stack_level, {'letter': 'a'}), (stack_level, {'letter': 'b'})))
        self.assertEqual(entries.pop(0)['exec_context'], ((stack_level, {'letter': 'a'}), (stack_level, {'letter': 'c'})))
        self.assertEqual(entries.pop(0)['exec_context'], ((stack_level, {'letter': 'a'}),))

    def test_sync_recorder(self):
        def a():
            b()
            c()

        def b():
            pass

        def c():
            d()
            d()

        def d():
            pass

        with Profiler(description='test', collectors=['traces_sync'], db=None) as p:
            a()

        stacks = [r['stack'] for r in p.collectors[0].entries]

        # map stack frames to their function name, and check
        stacks_methods = [[frame[2] for frame in stack] for stack in stacks]
        self.assertEqual(stacks_methods[:-2], [
            ['a'],
            ['a', 'b'],
            ['a'],
            ['a', 'c'],
            ['a', 'c', 'd'],
            ['a', 'c'],
            ['a', 'c', 'd'],
            ['a', 'c'],
            ['a'],
            [],
        ])

        # map stack frames to their line number, and check
        stacks_lines = [[frame[1] for frame in stack] for stack in stacks]
        self.assertEqual(stacks_lines[1][0] + 1, stacks_lines[3][0],
                         "Call of b() in a() should be one line before call of c()")

    def test_qweb_recorder(self):
        template = self.env['ir.ui.view'].create({
            'name': 'test',
            'type': 'qweb',
            'key': 'root',
            'arch_db': '''<t t-name="root">
                <t t-foreach="{'a': 3, 'b': 2, 'c': 1}" t-as="item">
                    [<t t-out="item_index"/>: <t t-set="record" t-value="item"/><t t-call="base.dummy"/> <t t-out="item_value"/>]
                    <b t-out="add_one_query()"/></t>
            </t>'''
        })
        child_template = self.env['ir.ui.view'].create({
            'name': 'test',
            'type': 'qweb',
            'key': 'dummy',
            'arch_db': '<t t-name="dummy"><span t-attf-class="myclass"><t t-out="record"/> <t t-out="add_one_query()"/></span></t>'
        })
        self.env.cr.execute("INSERT INTO ir_model_data(name, model, res_id, module)"
                            "VALUES ('dummy', 'ir.ui.view', %s, 'base')", [child_template.id])

        values = {'add_one_query': lambda: self.env.cr.execute('SELECT id FROM ir_ui_view LIMIT 1') or 'query'}
        result = u"""
                    [0: <span class="myclass">a query</span> 3]
                    <b>query</b>
                    [1: <span class="myclass">b query</span> 2]
                    <b>query</b>
                    [2: <span class="myclass">c query</span> 1]
                    <b>query</b>
        """

        # test rendering without profiling
        rendered = self.env['ir.qweb']._render(template.id, values)
        self.assertEqual(rendered.strip(), result.strip(), 'Without profiling')

        # This rendering is used to cache the compiled template method so as
        # not to have a number of requests that vary according to the modules
        # installed.
        with Profiler(description='test', collectors=['qweb'], db=None):
            self.env['ir.qweb']._render(template.id, values)

        with Profiler(description='test', collectors=['qweb'], db=None) as p:
            rendered = self.env['ir.qweb']._render(template.id, values)
            # check if qweb is ok
            self.assertEqual(rendered.strip(), result.strip())

        # check if the arch of all used templates is includes in the result
        self.assertEqual(p.collectors[0].entries[0]['results']['archs'], {
            template.id: template.arch_db,
            child_template.id: child_template.arch_db,
        })

        # check all directives without duration information
        for data in p.collectors[0].entries[0]['results']['data']:
            data.pop('delay')

        data = p.collectors[0].entries[0]['results']['data']
        expected = [
            # pylint: disable=bad-whitespace
            # first template and first directive
            {'view_id': template.id,       'xpath': '/t/t',         'directive': """t-foreach="{'a': 3, 'b': 2, 'c': 1}" t-as='item'""", 'query': 0},
            # first pass in the loop
            {'view_id': template.id,       'xpath': '/t/t/t[1]',    'directive': "t-out='item_index'", 'query': 0},
            {'view_id': template.id,       'xpath': '/t/t/t[2]',    'directive': "t-set='record' t-value='item'", 'query': 0},
            {'view_id': template.id,       'xpath': '/t/t/t[3]',    'directive': "t-call='base.dummy'", 'query': 0}, # 0 because the template is in ir.ui.view cache
            # first pass in the loop: content of the child template
            {'view_id': child_template.id, 'xpath': '/t/span',      'directive': "t-attf-class='myclass'", 'query': 0},
            {'view_id': child_template.id, 'xpath': '/t/span/t[1]', 'directive': "t-out='record'", 'query': 0},
            {'view_id': child_template.id, 'xpath': '/t/span/t[2]', 'directive': "t-out='add_one_query()'", 'query': 1},
            {'view_id': template.id,       'xpath': '/t/t/t[4]',    'directive': "t-out='item_value'", 'query': 0},
            {'view_id': template.id,       'xpath': '/t/t/b',       'directive': "t-out='add_one_query()'", 'query':1},
            # second pass in the loop
            {'view_id': template.id,       'xpath': '/t/t/t[1]',    'directive': "t-out='item_index'", 'query': 0},
            {'view_id': template.id,       'xpath': '/t/t/t[2]',    'directive': "t-set='record' t-value='item'", 'query': 0},
            {'view_id': template.id,       'xpath': '/t/t/t[3]',    'directive': "t-call='base.dummy'", 'query': 0},
            {'view_id': child_template.id, 'xpath': '/t/span',      'directive': "t-attf-class='myclass'", 'query': 0},
            {'view_id': child_template.id, 'xpath': '/t/span/t[1]', 'directive': "t-out='record'", 'query': 0},
            {'view_id': child_template.id, 'xpath': '/t/span/t[2]', 'directive': "t-out='add_one_query()'", 'query': 1},
            {'view_id': template.id,       'xpath': '/t/t/t[4]',    'directive': "t-out='item_value'", 'query': 0},
            {'view_id': template.id,       'xpath': '/t/t/b',       'directive': "t-out='add_one_query()'", 'query':1},
            # third pass in the loop
            {'view_id': template.id,       'xpath': '/t/t/t[1]',    'directive': "t-out='item_index'", 'query': 0},
            {'view_id': template.id,       'xpath': '/t/t/t[2]',    'directive': "t-set='record' t-value='item'", 'query': 0},
            {'view_id': template.id,       'xpath': '/t/t/t[3]',    'directive': "t-call='base.dummy'", 'query': 0},
            {'view_id': child_template.id, 'xpath': '/t/span',      'directive': "t-attf-class='myclass'", 'query': 0},
            {'view_id': child_template.id, 'xpath': '/t/span/t[1]', 'directive': "t-out='record'", 'query': 0},
            {'view_id': child_template.id, 'xpath': '/t/span/t[2]', 'directive': "t-out='add_one_query()'", 'query': 1},
            {'view_id': template.id,       'xpath': '/t/t/t[4]',    'directive': "t-out='item_value'", 'query': 0},
            {'view_id': template.id,       'xpath': '/t/t/b',       'directive': "t-out='add_one_query()'", 'query':1},
        ]
        self.assertEqual(data, expected)

    def test_default_recorders(self):
        with Profiler(db=None) as p:
            queries_start = self.env.cr.sql_log_count
            for i in range(10):
                self.env['res.partner'].create({'name': 'snail%s' % i})
            self.env.flush_all()
            total_queries = self.env.cr.sql_log_count - queries_start

        rq = next(r for r in p.collectors if r.name == "sql").entries
        self.assertEqual(p.init_stack_trace[-1][2], 'test_default_recorders')
        self.assertEqual(p.init_stack_trace[-1][0].split('/')[-1], 'test_profiler.py')

        self.assertEqual(len(rq), total_queries)
        first_query = rq[0]
        self.assertEqual(first_query['stack'][0][2], 'create')
        #self.assertIn("self.env['res.partner'].create({", first_query['stack'][0][3])

        self.assertGreater(first_query['time'], 0)
        self.assertEqual(first_query['stack'][-1][2], 'execute')
        self.assertEqual(first_query['stack'][-1][0].split('/')[-1], 'sql_db.py')


def deep_call(func, depth):
    """ Call the given function at the given call depth. """
    if depth > 0:
        deep_call(func, depth - 1)
    else:
        func()


@tagged('-standard', 'profiling_performance')
class TestPerformance(BaseCase):

    def test_collector_max_frequency(self):
        """
        Check the creation time of an entry
        """
        collector = profiler.Collector()
        p = Profiler(collectors=[collector], db=None)

        def collect():
            collector.add()

        # collect on changing stack
        with p:
            start = time.time()
            while start + 1 > time.time():
                deep_call(collect, 20)

        self.assertGreater(len(collector.entries), 20000)  # ~40000

        # collect on identical stack
        collector = profiler.Collector()
        p = Profiler(collectors=[collector], db=None)

        def collect_1_s():
            start = time.time()
            while start + 1 > time.time():
                collector.add()

        with p:
            deep_call(collect_1_s, 20)

        self.assertGreater(len(collector.entries), 50000)  # ~70000

    def test_frequencies_1ms_sleep(self):
        """
        Check the number of entries generated in 1s at 1kHz
        we need to artificially change the frame as often as possible to avoid
        triggering the memory optimisation skipping identical frames
        """
        def sleep_1():
            time.sleep(0.0001)

        def sleep_2():
            time.sleep(0.0001)

        with Profiler(collectors=['traces_async'], db=None) as res:
            start = time.time()
            while start + 1 > time.time():
                sleep_1()
                sleep_2()

        entry_count = len(res.collectors[0].entries)
        self.assertGreater(entry_count, 700)  # ~920

    def test_traces_async_memory_optimisation(self):
        """
        Identical frames should be saved only once.
        We should only have a few entries on a 1 second sleep.
        """
        with Profiler(collectors=['traces_async'], db=None) as res:
            time.sleep(1)
        entry_count = len(res.collectors[0].entries)
        self.assertLess(entry_count, 5)  # ~3