L3-agent periodic task is skipped often

[Itsuro Oda]

You can observe this phenomenon from any jenkins log easily.

For example:
http://logs.openstack.org/32/147032/2/check/check-tempest-dsvm-neutron-full/d5c65a2/logs/screen-q-vpn.txt.gz#_2015-01-15_00_43_37_878
---
2015-01-15 00:43:37.878 2818 DEBUG neutron.openstack.common.periodic_task [-] Running periodic task VPNAgent.periodic_sync_routers_task run_periodic_tasks /opt/stack/new/neutron/neutron/openstack/common/periodic_task.py:199
2015-01-15 00:43:37.878 2818 DEBUG neutron.agent.l3.agent [-] Starting periodic_sync_routers_task - fullsync:False periodic_sync_routers_task /opt/stack/new/neutron/neutron/agent/l3/agent.py:1094
2015-01-15 00:43:57.778 2818 DEBUG neutron.agent.l3.agent [-] Report state task started _report_state /opt/stack/new/neutron/neutron/agent/l3/agent.py:1211
2015-01-15 00:43:57.782 2818 DEBUG neutron.agent.l3.agent [-] Report state task successfully completed _report_state /opt/stack/new/neutron/neutron/agent/l3/agent.py:1235
2015-01-15 00:44:27.778 2818 DEBUG neutron.agent.l3.agent [-] Report state task started _report_state /opt/stack/new/neutron/neutron/agent/l3/agent.py:1211
2015-01-15 00:44:27.785 2818 DEBUG neutron.agent.l3.agent [-] Report state task successfully completed _report_state /opt/stack/new/neutron/neutron/agent/l3/agent.py:1235
2015-01-15 00:44:57.778 2818 DEBUG neutron.agent.l3.agent [-] Report state task started _report_state /opt/stack/new/neutron/neutron/agent/l3/agent.py:1211
2015-01-15 00:44:57.783 2818 DEBUG neutron.agent.l3.agent [-] Report state task successfully completed _report_state /opt/stack/new/neutron/neutron/agent/l3/agent.py:1235
2015-01-15 00:44:57.878 2818 DEBUG neutron.openstack.common.periodic_task [-] Running periodic task VPNAgent.periodic_sync_routers_task run_periodic_tasks /opt/stack/new/neutron/neutron/openstack/common/periodic_task.py:199
2015-01-15 00:44:57.878 2818 DEBUG neutron.agent.l3.agent [-] Starting periodic_sync_routers_task - fullsync:False periodic_sync_routers_task /opt/stack/new/neutron/neutron/agent/l3/agent.py:1094
---

periodic_interval is 40 here.
periodic task is expected to run at 00:43:37, 00:44:17 and 00:44:57. But execution at 00:44:17 is skipped.

[Kevin Benton (kevinbenton)]

I don't think a full sync is guaranteed on every run. Certain events have to happen to trigger it.

[Itsuro Oda (oda-g)]

periodic_sync_routers_task is task to check the necessity of full sync.
"periodic_interval = 40' means if full sync triggered, full sync will start at least within 40sec after trigger.
This is not true by this bug. Full sync will start after 80sec from trigger with the worst case. This is not intention of periodic task, isn't it ?

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: master
Review: https://review.openstack.org/147710

[OpenStack Infra (hudson-openstack)]

Reviewed: https://review.openstack.org/147710
Committed: https://git.openstack.org/cgit/openstack/neutron/commit/?id=8c989e67b99745f55d462e21be0eaa00f6a0e9b8
Submitter: Jenkins
Branch: master

commit 8c989e67b99745f55d462e21be0eaa00f6a0e9b8
Author: Kevin Benton <email address hidden>
Date: Thu Jan 15 08:11:49 2015 -0800

    Make L3 agent honor periodic_interval setting

    The periodic_task decorator for the sync routers task was resulting
    in a default spacing of 60 seconds. This meant that any values less
    than that for the periodic_interval setting would not work correctly.
    The fixed interval looping call would run at the periodic_interval
    but this task would not execute every time as expected.

    For example, if the periodic_interval was 40 seconds, the task would
    only end up running every other interval (80 seconds in this case)
    because every other attempt would be blocked by the default 60 second
    barrier of periodic_task.

    This sets the periodic_taks spacing variable to 1 second so the
    interval is controlled only by the loopingcall as expected.

    Ultimately periodic_task should probably be completely removed since
    it's not compatible with the fixed interval loopingcall in this manner.

    Closes-Bug: #1411085
    Change-Id: I23818c3fab2640b241692f00f9b5a2f923e3cf31

[OpenStack Infra (hudson-openstack)]

Fix proposed to branch: neutron-pecan
Review: https://review.openstack.org/185072