Skip to content

[advanced-reboot] Add timing data for finalizer, first lag, port init and ASIC views#3446

Merged
vaibhavhd merged 1 commit intosonic-net:masterfrom
vaibhavhd:advance-reboot-timings
May 6, 2021
Merged

[advanced-reboot] Add timing data for finalizer, first lag, port init and ASIC views#3446
vaibhavhd merged 1 commit intosonic-net:masterfrom
vaibhavhd:advance-reboot-timings

Conversation

@vaibhavhd
Copy link
Contributor

@vaibhavhd vaibhavhd commented May 5, 2021

Description of PR

Summary: Enhance the present timing collection in advanced_reboot test (warm/fast). New timing data that is added here:

  1. WARMBOOT_FINALIZER start/end
  2. ASIC INIT/APPLY VIEW start/end
  3. Port init start
  4. First LAG creation time

Some structuring changes are also added to keep the report structure consistent.
New timing calculation added to compare time taken since reboot.

Fixes # (issue)

Type of change

  • Bug fix
  • Testbed and Framework(new/improvement)
  • Test case(new/improvement)

Approach

What is the motivation for this PR?

How did you do it?

How did you verify/test it?

Tested on KVM and physical testbed. Sample reports for warm reboot:

KVM

{
    "Services": {
        "bgp": {
            "timestamp": {
                "Stopping": "May 05 22:13:44.956485", 
                "Starting": "May 05 22:15:07.329787", 
                "Stopped": "May 05 22:13:51.339968", 
                "Started": "May 05 22:15:09.011936"
            }, 
            "start_time": 1.682149, 
            "stop_time": 6.383483, 
            "reboot_time": 77.671968
        }, 
        "radv": {
            "timestamp": {
                "Stopping": "May 05 22:13:44.015692", 
                "Starting": "May 05 22:15:12.319497", 
                "Stopped": "May 05 22:13:44.917165", 
                "Started": "May 05 22:15:13.903904"
            }, 
            "start_time": 1.584407, 
            "Stopping count": 2, 
            "stop_time": 0.901473, 
            "reboot_time": 88.986739
        }, 
        "FINALIZER": {
            "timestamp": {
                "Start": "May 05 22:15:07.220814", 
                "End": "May 05 22:17:25.467302"
            }, 
            "start_time": null, 
            "stop_time": null, 
            "reboot_time": null
        }, 
        "teamd": {
            "timestamp": {
                "Stopping": "May 05 22:14:07.433174", 
                "Starting": "May 05 22:15:10.749340", 
                "Stopped": "May 05 22:14:15.209556", 
                "Started": "May 05 22:15:12.052432"
            }, 
            "start_time": 1.303092, 
            "stop_time": 7.776382, 
            "reboot_time": 56.842876
        }, 
        "gbsyncd": {
            "timestamp": {
                "Stopping": "May 05 22:14:30.059582", 
                "Starting": "May 05 22:15:10.752030", 
                "Stopped": "May 05 22:14:30.664766", 
                "Started": "May 05 22:15:12.237363"
            }, 
            "start_time": 1.485333, 
            "stop_time": 0.605184, 
            "reboot_time": 41.572597
        }, 
        "syncd": {
            "timestamp": {
                "Stopping": "May 05 22:14:15.258448", 
                "Starting": "May 05 22:15:10.757854", 
                "Stopped": "May 05 22:14:27.105090", 
                "Started": "May 05 22:15:12.251441"
            }, 
            "start_time": 1.493587, 
            "stop_time": 11.846642, 
            "reboot_time": 45.146351
        }, 
        "swss": {
            "timestamp": {
                "Stopping": "May 05 22:14:04.464976", 
                "Starting": "May 05 22:15:09.046936", 
                "Stopped": "May 05 22:14:05.464276", 
                "Started": "May 05 22:15:10.714430"
            }, 
            "start_time": 1.667494, 
            "stop_time": 0.9993, 
            "reboot_time": 65.250154
        }, 
        "APPLY_VIEW": {
            "timestamp": {
                "Start": "May 05 22:15:44.152578", 
                "End": "May 05 22:15:53.681743"
            }, 
            "start_time": null, 
            "stop_time": null, 
            "reboot_time": null
        }, 
        "INIT_VIEW": {
            "timestamp": {
                "Start": "May 05 22:15:19.461733", 
                "End": "May 05 22:15:22.265537"
            }, 
            "start_time": null, 
            "stop_time": null, 
            "reboot_time": null
        }
    }, 
    "first_occurence": {
        "default_route_set": {
            "timestamp": {
                "Start": "May 05 22:15:30.680705"
            }, 
            "time_since_reboot": 57.065211
        }, 
        "PORT_INIT": {
            "timestamp": {
                "Start": "May 05 22:15:21.698746"
            }, 
            "time_since_reboot": 48.083252
        }, 
        "LAG_READY": {
            "timestamp": {
                "Start": "May 05 22:16:28.851165"
            }, 
            "Start count": 4, 
            "time_since_reboot": 115.235671
        }, 
        "first_neighbor_entry": {
            "timestamp": {
                "Start": "May 05 22:15:25.417810"
            }, 
            "Start count": 509, 
            "time_since_reboot": 51.802316
        }
    }, 
    "reboot_start": "May 05 22:14:33.615494", 
    "sairedis_state": {
        "sai_switch_create": {
            "timestamp": {
                "Start": "May 05 22:15:22.278423", 
                "End": "May 05 22:15:22.279395"
            }
        }
    }, 
    "dataplane": {
        "total_downtime": "N/A", 
        "longest_downtime": 174.280219, 
        "reboot_time": 177.011082
    }
}

Physical

{
    "Services": {
        "bgp": {
            "timestamp": {
                "Stopping": "May 05 22:20:10.144137", 
                "Starting": "May 05 22:21:21.126050", 
                "Stopped": "May 05 22:20:15.249714", 
                "Started": "May 05 22:21:24.539145"
            }, 
            "start_time": 3.413095, 
            "stop_time": 5.105577, 
            "reboot_time": 69.289431
        }, 
        "radv": {
            "timestamp": {
                "Stopping": "May 05 22:20:09.429860", 
                "Starting": "May 05 22:21:30.166256", 
                "Stopped": "May 05 22:20:10.117482", 
                "Started": "May 05 22:21:33.680004"
            }, 
            "start_time": 3.513748, 
            "Stopping count": 2, 
            "stop_time": 0.687622, 
            "reboot_time": 83.562522
        }, 
        "FINALIZER": {
            "timestamp": {
                "Start": "May 05 22:21:20.922826", 
                "End": "May 05 22:23:48.070267"
            }, 
            "start_time": null, 
            "stop_time": null, 
            "reboot_time": null
        }, 
        "teamd": {
            "timestamp": {
                "Stopping": "May 05 22:20:28.982849", 
                "Starting": "May 05 22:21:27.312267", 
                "Stopped": "May 05 22:20:35.964843", 
                "Started": "May 05 22:21:30.092988"
            }, 
            "start_time": 2.780721, 
            "stop_time": 6.981994, 
            "reboot_time": 54.128145
        }, 
        "syncd": {
            "timestamp": {
                "Stopping": "May 05 22:20:35.997028", 
                "Starting": "May 05 22:21:27.314581", 
                "Stopped": "May 05 22:20:51.424264", 
                "Started": "May 05 22:21:30.101425"
            }, 
            "start_time": 2.786844, 
            "stop_time": 15.427236, 
            "reboot_time": 38.677161
        }, 
        "swss": {
            "timestamp": {
                "Stopping": "May 05 22:20:25.330404", 
                "Starting": "May 05 22:21:24.934529", 
                "Stopped": "May 05 22:20:26.158109", 
                "Started": "May 05 22:21:27.246435"
            }, 
            "start_time": 2.311906, 
            "stop_time": 0.827705, 
            "reboot_time": 61.088326
        }, 
        "APPLY_VIEW": {
            "timestamp": {
                "Start": "May 05 22:21:55.979105", 
                "End": "May 05 22:22:02.748900"
            }, 
            "start_time": null, 
            "stop_time": null, 
            "reboot_time": null
        }, 
        "INIT_VIEW": {
            "timestamp": {
                "Start": "May 05 22:21:37.915530", 
                "End": "May 05 22:21:48.287468"
            }, 
            "start_time": null, 
            "stop_time": null, 
            "reboot_time": null
        }
    }, 
    "first_occurence": {
        "default_route_set": {
            "timestamp": {
                "Start": "May 05 22:21:52.970898"
            }, 
            "time_since_reboot": 56.137849
        }, 
        "PORT_INIT": {
            "timestamp": {
                "Start": "May 05 22:21:46.541611"
            }, 
            "time_since_reboot": 49.708562
        }, 
        "LAG_READY": {
            "timestamp": {
                "Start": "May 05 22:22:47.007086"
            }, 
            "Start count": 4, 
            "time_since_reboot": 110.174037
        }, 
        "first_neighbor_entry": {
            "timestamp": {
                "Start": "May 05 22:21:51.041277"
            }, 
            "Start count": 513, 
            "time_since_reboot": 54.208228
        }
    }, 
    "reboot_start": "May 05 22:20:56.833049", 
    "sairedis_state": {
        "sai_switch_create": {
            "timestamp": {
                "Start": "May 05 22:21:48.291297", 
                "End": "May 05 22:21:48.293045"
            }
        }
    }, 
    "dataplane": {
        "total_downtime": 7.263669013977051, 
        "longest_downtime": 0.009153, 
        "reboot_time": 203.345876
    }
}

Any platform specific information?

Supported testbed topology if it's a new test case?

Documentation

@vaibhavhd vaibhavhd requested a review from shi-su May 5, 2021 22:32
@vaibhavhd vaibhavhd requested a review from jleveque as a code owner May 5, 2021 22:32
@vaibhavhd vaibhavhd requested a review from a team May 6, 2021 00:03
shi-su
shi-su reviewed May 6, 2021
View reviewed changes
@vaibhavhd
Copy link
Contributor Author

vaibhavhd commented May 6, 2021

/Azp run

@azure-pipelines
Copy link

azure-pipelines bot commented May 6, 2021

Azure Pipelines successfully started running 1 pipeline(s).

@vaibhavhd vaibhavhd merged commit 03744ce into sonic-net:master May 6, 2021
@vaibhavhd vaibhavhd deleted the advance-reboot-timings branch May 6, 2021 19:52
bingwang-ms pushed a commit to bingwang-ms/sonic-mgmt that referenced this pull request Aug 18, 2021
@wangxin
Merged PR 4525167: Add azure pipeline yaml files for nightly test
d240c77 
We are migrating from Jenkins to azure pipeline. This PR added azure pipeline yaml files and dependent template files for nightly tests. Pipeline yaml files only added for 3 testbeds yet. The pipelines were originally added to branch azp-test of repo https://dev.azure.com/mssonic/internal/_git/sonic-mgmt-int. They have been tested on Azure DevOps.

Now we formally add these pipelines to the Networking-acs-sonic-mgmt repo. Currently the internal branch of Networking-acs-sonic-mgmt is synched to same internal branch of the sonic-mgmt-int repo. After this PR is merged, we need to update configuration of the created pipelines to formally use these files from the internal branch.

If the pipelines work fine with yaml files from internal branch, we will create more pipeline files based on current templates for rest of the nightly testbeds.

Related work items: sonic-net#3021, sonic-net#3073, sonic-net#3135, sonic-net#3153, sonic-net#3162, sonic-net#3176, sonic-net#3238, sonic-net#3241, sonic-net#3346, sonic-net#3352, sonic-net#3378, sonic-net#3389, sonic-net#3395, sonic-net#3397, sonic-net#3398, sonic-net#3407, sonic-net#3410, sonic-net#3411, sonic-net#3412, sonic-net#3413, sonic-net#3414, sonic-net#3415, sonic-net#3434, sonic-net#3437, sonic-net#3445, sonic-net#3446, sonic-net#3447, #9740131, #9821349
vmittal-msft pushed a commit to vmittal-msft/sonic-mgmt that referenced this pull request Sep 28, 2021
@vaibhavhd @vmittal-msft
Enhance advanced reboot timing collection (sonic-net#3446)
a6ae762 
Enhanced the present timing collection in advanced_reboot test (warm/fast). New timing data that is added here:

WARMBOOT_FINALIZER start/end
ASIC INIT/APPLY VIEW start/end
Port init start
First LAG creation time
Some structuring changes are also added to keep the report structure consistent.
New timing calculation added to compare time taken since reboot.

Tested on KVM and physical testbeds.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Reviewers

@jleveque jleveque Awaiting requested review from jleveque

1 more reviewer

@shi-su shi-su shi-su approved these changes

Reviewers whose approvals may not affect merge requirements

Assignees

No one assigned

Labels

Enhancement Pytest 🐍

Projects

None yet

Milestone

No milestone

Development

Successfully merging this pull request may close these issues.

2 participants

@vaibhavhd @shi-su