From f24a73b9bd28d7472003bfed8e349fe58eb7afe3 Mon Sep 17 00:00:00 2001
From: xumia <59720581+xumia@users.noreply.github.com>
Date: Tue, 30 Aug 2022 09:19:58 +0800
Subject: [PATCH] Fix vs check install login timeout issue (#11727)

Why I did it
Fix a build not stable issue: #11620
The vs vm has started successfully, but failed to wait for the message "sonic login:".

There were 55 builds failed caused by the issue in the last 30 days.

AzurePipelineBuildLogs
| where startTime > ago(30d)
| where type =~ "task"
| where result =~ "failed"
| where name =~ "Build sonic image"
| where content contains "Timeout exceeded"
| where content contains "re.compile('sonic login:')"
| project-away content
| extend branchName=case(reason=~"pullRequest", tostring(todynamic(parameters)['system.pullRequest.targetBranch']),
              replace("refs/heads/", "", sourceBranch))
| summarize FailedCount=dcount(buildId) by branchName

branchName	FailedCount
master	37
202012	9
202106	4
202111	2
202205	1
201911	1
It is caused by the login message mixed with the output message of the /etc/rc.local, one of the examples as below: (see the message rc.local[307]: sonic+ onie_disco_subnet=255.255.255.0 login: )
The check_install.py was waiting for the message "sonic login:", and Linux console was waiting for the username input (the login message has already printed in the console).
https://dev.azure.com/mssonic/build/_build/results?buildId=123294&view=logs&j=cef3d8a9-152e-5193-620b-567dc18af272&t=359769c4-8b5e-5976-a793-85da132e0a6f

2022-07-17T15:00:58.9198877Z [   25.493855] rc.local[307]: + onie_disco_opt53=05
2022-07-17T15:00:58.9199330Z [   25.595054] rc.local[307]: + onie_disco_router=10.0.2.2
2022-07-17T15:00:58.9199781Z [   25.699409] rc.local[307]: + onie_disco_serverid=10.0.2.2
2022-07-17T15:00:58.9200252Z [   25.789891] rc.local[307]: + onie_disco_siaddr=10.0.2.2
2022-07-17T15:00:58.9200622Z [   25.880920]
2022-07-17T15:00:58.9200745Z
2022-07-17T15:00:58.9201019Z Debian GNU/Linux 10 sonic ttyS0
2022-07-17T15:00:58.9201201Z
2022-07-17T15:00:58.9201542Z rc.local[307]: sonic+ onie_disco_subnet=255.255.255.0 login:
2022-07-17T15:00:58.9202309Z [   26.079767] rc.local[307]: + onie_exec_url=file://dev/vdb/onie-installer.bin

How I did it
Input a newline when finished to run the script /etc/rc.local.
If entering a newline, the message "sonic login:" will prompt again.
---
 check_install.py | 7 ++++++-
 1 file changed, 6 insertions(+), 1 deletion(-)

diff --git a/check_install.py b/check_install.py
index ecd3a8ee9a..b8fc3936f7 100755
--- a/check_install.py
+++ b/check_install.py
@@ -19,6 +19,7 @@ def main():
     passwd_prompt = 'Password:'
     cmd_prompt = "{}@sonic:~\$ $".format(args.u)
     grub_selection = "The highlighted entry will be executed"
+    firsttime_prompt = 'firsttime_exit'
 
     i = 0
     while True:
@@ -38,13 +39,17 @@ def main():
 
     # bootup sonic image
     while True:
-        i = p.expect([login_prompt, passwd_prompt, cmd_prompt])
+        i = p.expect([login_prompt, passwd_prompt, firsttime_prompt, cmd_prompt])
         if i == 0:
             # send user name
             p.sendline(args.u)
         elif i == 1:
             # send password
             p.sendline(args.P)
+        elif i == 2:
+            # fix a login timeout issue, caused by the login_prompt message mixed with the output message of the rc.local
+            time.sleep(1)
+            p.sendline()
         else:
             break