Skip to content

Commit acdb9be

Browse files
bewithgauravCopilot
bewithgaurav
and
Copilot
authored
CHORE: Flaky Setup - Fail SQL Server setup loudly and dump container logs on every CI leg (#722)
### Work Item / Issue Reference > ADO Work Item: Fixed [AB#47310](https://sqlclientdrivers.visualstudio.com/c6d89619-62de-46a0-8b46-70b92a84d85e/_workitems/edit/47310) ------------------------------------------------------------------- ### Summary when SQL Server fails to come up in CI, the pipeline either does not fail at all or fails without saying why. this makes all eight readiness loops behave the same way. two of the eight never failed. the macOS one and the CodeCoverageReport one polled in a loop whose exit status is the final `sleep 2`, so the step reported success even when every probe failed. build 166760 hit this on macOS: the container died on startup, all 30 probes logged `container ... is not running`, the step went green, and pytest then ran 32.6 minutes against a database that did not exist, erroring on every db-backed test from the 1% mark while the non-db tests passed. #723 has since fixed the macOS half as part of the setup parallelization, so what is left here is CodeCoverageReport. the other six linux distro legs do fail, through `CREATE DATABASE TestDB` right after the loop, but you only get a sqlcmd connect error. nothing anywhere in the pipeline captures `docker logs`, so when the container exits on its own (SA password policy, EULA, OOM, port already bound) the reason is never recorded. that is why 166760's root cause is still unknown. every site now tracks readiness in a flag, probes once more after the loop, and on failure prints the attempt count followed by `docker logs --tail 200` before exiting non-zero. the extra probe matters because the loop sleeps after its final attempt, so SQL can become reachable in that window and would otherwise be called a hard failure. verified locally against real containers: a container that prints a startup error and exits now surfaces that error instead of only the connect failure, a healthy container is unaffected, and a container that becomes reachable only after the loop is rescued by the re-probe. healthy macOS runs use 3 to 6 of the 30 attempts, so the gate keeps roughly 5x headroom and no green run changes behaviour. --------- Co-authored-by: Gaurav Sharma <223556219+Copilot@users.noreply.github.com>
1 parent 8a9cdcb commit acdb9be

1 file changed

Lines changed: 144 additions & 2 deletions

File tree

‎eng/pipelines/pr-validation-pipeline.yml‎

Lines changed: 144 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -559,7 +559,23 @@ jobs:
559559
fi
560560
sleep 2
561561
done
562+
563+
# One last probe: the loop sleeps after its final attempt, so SQL can
564+
# become reachable in that window and would otherwise be missed.
565+
if docker exec sqlserver \
566+
/opt/mssql-tools18/bin/sqlcmd \
567+
-S localhost -U SA -P "$DB_PASSWORD" \
568+
-C -Q "SELECT 1"; then
569+
echo "[sql] SQL Server is ready."
570+
return 0
571+
fi
572+
573+
# sqlcmd only reports that the client could not connect. When the
574+
# container itself exited (bad password policy, EULA, OOM, port clash)
575+
# the reason is in the container's own log, so surface it here.
562576
echo "[sql] SQL Server did not become ready in time." >&2
577+
echo "[sql] ---- docker logs sqlserver (last 200 lines) ----" >&2
578+
docker logs --tail 200 sqlserver >&2 || true
563579
return 1
564580
}
565581
@@ -768,6 +784,7 @@ jobs:
768784
769785
# Wait for SQL Server to be ready
770786
echo "Waiting for SQL Server to start..."
787+
sql_ready=false
771788
for i in {1..60}; do
772789
if docker exec sqlserver-$(distroName) \
773790
/opt/mssql-tools18/bin/sqlcmd \
@@ -776,11 +793,28 @@ jobs:
776793
-P "$(DB_PASSWORD)" \
777794
-C -Q "SELECT 1" >/dev/null 2>&1; then
778795
echo "SQL Server is ready!"
796+
sql_ready=true
779797
break
780798
fi
781799
echo "Waiting... ($i/60)"
782800
sleep 2
783801
done
802+
if [ "$sql_ready" != true ]; then
803+
# the loop sleeps after its final attempt, so probe once more
804+
if docker exec sqlserver-$(distroName) \
805+
/opt/mssql-tools18/bin/sqlcmd \
806+
-S localhost \
807+
-U SA \
808+
-P "$(DB_PASSWORD)" \
809+
-C -Q "SELECT 1" >/dev/null 2>&1; then
810+
echo "SQL Server is ready!"
811+
else
812+
echo "SQL Server did not become ready after 60 attempts"
813+
echo "---- docker logs sqlserver-$(distroName) (last 200 lines) ----"
814+
docker logs --tail 200 sqlserver-$(distroName) || true
815+
exit 1
816+
fi
817+
fi
784818
785819
# Create test database
786820
docker exec sqlserver-$(distroName) \
@@ -1097,6 +1131,7 @@ jobs:
10971131
10981132
# Wait for SQL Server to be ready
10991133
echo "Waiting for SQL Server to start..."
1134+
sql_ready=false
11001135
for i in {1..60}; do
11011136
if docker exec sqlserver-$(distroName)-$(archName) \
11021137
/opt/mssql-tools18/bin/sqlcmd \
@@ -1105,11 +1140,28 @@ jobs:
11051140
-P "$(DB_PASSWORD)" \
11061141
-C -Q "SELECT 1" >/dev/null 2>&1; then
11071142
echo "SQL Server is ready!"
1143+
sql_ready=true
11081144
break
11091145
fi
11101146
echo "Waiting... ($i/60)"
11111147
sleep 2
11121148
done
1149+
if [ "$sql_ready" != true ]; then
1150+
# the loop sleeps after its final attempt, so probe once more
1151+
if docker exec sqlserver-$(distroName)-$(archName) \
1152+
/opt/mssql-tools18/bin/sqlcmd \
1153+
-S localhost \
1154+
-U SA \
1155+
-P "$(DB_PASSWORD)" \
1156+
-C -Q "SELECT 1" >/dev/null 2>&1; then
1157+
echo "SQL Server is ready!"
1158+
else
1159+
echo "SQL Server did not become ready after 60 attempts"
1160+
echo "---- docker logs sqlserver-$(distroName)-$(archName) (last 200 lines) ----"
1161+
docker logs --tail 200 sqlserver-$(distroName)-$(archName) || true
1162+
exit 1
1163+
fi
1164+
fi
11131165
11141166
# Create test database
11151167
docker exec sqlserver-$(distroName)-$(archName) \
@@ -1327,6 +1379,7 @@ jobs:
13271379
13281380
# Wait for SQL Server to be ready
13291381
echo "Waiting for SQL Server to start..."
1382+
sql_ready=false
13301383
for i in {1..60}; do
13311384
if docker exec sqlserver-rhel9 \
13321385
/opt/mssql-tools18/bin/sqlcmd \
@@ -1335,11 +1388,28 @@ jobs:
13351388
-P "$(DB_PASSWORD)" \
13361389
-C -Q "SELECT 1" >/dev/null 2>&1; then
13371390
echo "SQL Server is ready!"
1391+
sql_ready=true
13381392
break
13391393
fi
13401394
echo "Waiting... ($i/60)"
13411395
sleep 2
13421396
done
1397+
if [ "$sql_ready" != true ]; then
1398+
# the loop sleeps after its final attempt, so probe once more
1399+
if docker exec sqlserver-rhel9 \
1400+
/opt/mssql-tools18/bin/sqlcmd \
1401+
-S localhost \
1402+
-U SA \
1403+
-P "$(DB_PASSWORD)" \
1404+
-C -Q "SELECT 1" >/dev/null 2>&1; then
1405+
echo "SQL Server is ready!"
1406+
else
1407+
echo "SQL Server did not become ready after 60 attempts"
1408+
echo "---- docker logs sqlserver-rhel9 (last 200 lines) ----"
1409+
docker logs --tail 200 sqlserver-rhel9 || true
1410+
exit 1
1411+
fi
1412+
fi
13431413
13441414
# Create test database
13451415
docker exec sqlserver-rhel9 \
@@ -1554,6 +1624,7 @@ jobs:
15541624
15551625
# Wait for SQL Server to be ready
15561626
echo "Waiting for SQL Server to start..."
1627+
sql_ready=false
15571628
for i in {1..60}; do
15581629
if docker exec sqlserver-rhel9-arm64 \
15591630
/opt/mssql-tools18/bin/sqlcmd \
@@ -1562,11 +1633,28 @@ jobs:
15621633
-P "$(DB_PASSWORD)" \
15631634
-C -Q "SELECT 1" >/dev/null 2>&1; then
15641635
echo "SQL Server is ready!"
1636+
sql_ready=true
15651637
break
15661638
fi
15671639
echo "Waiting... ($i/60)"
15681640
sleep 2
15691641
done
1642+
if [ "$sql_ready" != true ]; then
1643+
# the loop sleeps after its final attempt, so probe once more
1644+
if docker exec sqlserver-rhel9-arm64 \
1645+
/opt/mssql-tools18/bin/sqlcmd \
1646+
-S localhost \
1647+
-U SA \
1648+
-P "$(DB_PASSWORD)" \
1649+
-C -Q "SELECT 1" >/dev/null 2>&1; then
1650+
echo "SQL Server is ready!"
1651+
else
1652+
echo "SQL Server did not become ready after 60 attempts"
1653+
echo "---- docker logs sqlserver-rhel9-arm64 (last 200 lines) ----"
1654+
docker logs --tail 200 sqlserver-rhel9-arm64 || true
1655+
exit 1
1656+
fi
1657+
fi
15701658
15711659
# Create test database
15721660
docker exec sqlserver-rhel9-arm64 \
@@ -1785,6 +1873,7 @@ jobs:
17851873
17861874
# Wait for SQL Server to be ready
17871875
echo "Waiting for SQL Server to start..."
1876+
sql_ready=false
17881877
for i in {1..60}; do
17891878
if docker exec sqlserver-alpine \
17901879
/opt/mssql-tools18/bin/sqlcmd \
@@ -1793,11 +1882,28 @@ jobs:
17931882
-P "$(DB_PASSWORD)" \
17941883
-C -Q "SELECT 1" >/dev/null 2>&1; then
17951884
echo "SQL Server is ready!"
1885+
sql_ready=true
17961886
break
17971887
fi
17981888
echo "Waiting... ($i/60)"
17991889
sleep 2
18001890
done
1891+
if [ "$sql_ready" != true ]; then
1892+
# the loop sleeps after its final attempt, so probe once more
1893+
if docker exec sqlserver-alpine \
1894+
/opt/mssql-tools18/bin/sqlcmd \
1895+
-S localhost \
1896+
-U SA \
1897+
-P "$(DB_PASSWORD)" \
1898+
-C -Q "SELECT 1" >/dev/null 2>&1; then
1899+
echo "SQL Server is ready!"
1900+
else
1901+
echo "SQL Server did not become ready after 60 attempts"
1902+
echo "---- docker logs sqlserver-alpine (last 200 lines) ----"
1903+
docker logs --tail 200 sqlserver-alpine || true
1904+
exit 1
1905+
fi
1906+
fi
18011907
18021908
# Create test database
18031909
docker exec sqlserver-alpine \
@@ -2041,6 +2147,7 @@ jobs:
20412147
20422148
# Wait for SQL Server to be ready
20432149
echo "Waiting for SQL Server to start..."
2150+
sql_ready=false
20442151
for i in {1..60}; do
20452152
if docker exec sqlserver-alpine-arm64 \
20462153
/opt/mssql-tools18/bin/sqlcmd \
@@ -2049,11 +2156,28 @@ jobs:
20492156
-P "$(DB_PASSWORD)" \
20502157
-C -Q "SELECT 1" >/dev/null 2>&1; then
20512158
echo "SQL Server is ready!"
2159+
sql_ready=true
20522160
break
20532161
fi
20542162
echo "Waiting... ($i/60)"
20552163
sleep 2
20562164
done
2165+
if [ "$sql_ready" != true ]; then
2166+
# the loop sleeps after its final attempt, so probe once more
2167+
if docker exec sqlserver-alpine-arm64 \
2168+
/opt/mssql-tools18/bin/sqlcmd \
2169+
-S localhost \
2170+
-U SA \
2171+
-P "$(DB_PASSWORD)" \
2172+
-C -Q "SELECT 1" >/dev/null 2>&1; then
2173+
echo "SQL Server is ready!"
2174+
else
2175+
echo "SQL Server did not become ready after 60 attempts"
2176+
echo "---- docker logs sqlserver-alpine-arm64 (last 200 lines) ----"
2177+
docker logs --tail 200 sqlserver-alpine-arm64 || true
2178+
exit 1
2179+
fi
2180+
fi
20572181
20582182
# Create test database
20592183
docker exec sqlserver-alpine-arm64 \
@@ -2510,15 +2634,33 @@ jobs:
25102634
-d mcr.microsoft.com/mssql/server:2022-latest
25112635
25122636
# Wait until SQL Server is ready
2637+
sql_ready=false
25132638
for i in {1..30}; do
2514-
docker exec sqlserver \
2639+
if docker exec sqlserver \
25152640
/opt/mssql-tools18/bin/sqlcmd \
25162641
-S localhost \
25172642
-U SA \
25182643
-P "$(DB_PASSWORD)" \
2519-
-C -Q "SELECT 1" && break
2644+
-C -Q "SELECT 1"; then
2645+
sql_ready=true
2646+
break
2647+
fi
25202648
sleep 2
25212649
done
2650+
if [ "$sql_ready" != true ]; then
2651+
# the loop sleeps after its final attempt, so probe once more
2652+
if ! docker exec sqlserver \
2653+
/opt/mssql-tools18/bin/sqlcmd \
2654+
-S localhost \
2655+
-U SA \
2656+
-P "$(DB_PASSWORD)" \
2657+
-C -Q "SELECT 1"; then
2658+
echo "SQL Server did not become ready after 30 attempts"
2659+
echo "---- docker logs sqlserver (last 200 lines) ----"
2660+
docker logs --tail 200 sqlserver || true
2661+
exit 1
2662+
fi
2663+
fi
25222664
displayName: 'Start SQL Server container'
25232665
env:
25242666
DB_PASSWORD: $(DB_PASSWORD)

0 commit comments

Comments
 (0)