Test 433 suddenly started randomly failing on Azure Ubuntu CI

[mback2k]

I did this

Checked recent master branch and PR Azure DevOps Ubuntu-based CI builds.

I expected the following

All tests to work on Linux / Ubuntu like before.

Examples

https://dev.azure.com/daniel0244/curl/_build/results?buildId=5042&view=logs&j=8165c288-ede3-54c0-ec36-33b42243957c&t=d264b5ad-e851-5f24-484d-d9cf1546c408&l=1638
https://dev.azure.com/daniel0244/curl/_build/results?buildId=5044&view=logs&j=9d58b9ac-e1e6-53b6-f83a-1f9f1d912522&t=51a4b246-0fa1-595b-3cc7-3e7aeb2b7380&l=1826
https://dev.azure.com/daniel0244/curl/_build/results?buildId=5044&view=logs&j=151da4b9-79a9-5fb7-f410-d59e17c3897b&t=ae9b0b05-05f4-558b-579c-a14022f0f07d&l=1655

Oldest CI run with this problem I could find:
https://dev.azure.com/daniel0244/curl/_build/results?buildId=5022&view=logs&j=151da4b9-79a9-5fb7-f410-d59e17c3897b&t=ae9b0b05-05f4-558b-579c-a14022f0f07d&l=1655

So it seems like it started between these commits:
7b2f067 (clean) and f073a42 (unclean)

[mback2k]

I just queued Azure DevOps Ubuntu Linux CI runs for all commits in the range mentioned above to bisect the root cause.

[bagder]

None of the commits in that range seems to have anything to do with such a failure... and I cannot reproduce on my Debian machine.

[mback2k]

I guessed so. Then probably something changed on the Ubuntu version that Azure uses. I will try to verify this by running previous commits on there later today.

[mback2k]

It seems the test started randomly failing since the 2021-03-11. I re-triggered this build from 2021-03-10 which failed due to a network connectivity issue in the first run, let's see how this turns out:
https://dev.azure.com/daniel0244/curl/_build/results?buildId=4996&view=results

[mback2k]

Okay, the one above worked on the first try. Let's try the last commit from 2021-03-10 again:
https://dev.azure.com/daniel0244/curl/_build/results?buildId=5057&view=results

[mback2k]

So the one above failed as well: https://dev.azure.com/daniel0244/curl/_build/results?buildId=5057&view=logs&j=9d58b9ac-e1e6-53b6-f83a-1f9f1d912522&t=51a4b246-0fa1-595b-3cc7-3e7aeb2b7380&l=1824

I guess something in the Azure CI environment has changed, probably the switch to Ubuntu 20.04 LTS which is causing this. @bagder do you happen to have such a VM around for re-production purposes? It would probably require running the test suite multiple times until it fails randomly.

[bagder]

I have a 18.04 VM here. Do we know if it requires 20.04 to fail? I could probably set one up, it might be useful in the future as well.

[mback2k]

Do we know if it requires 20.04 to fail?

That is the theory to investigate here. I have this theory since Azure DevOps recently changed ubuntu-latest to 20.04.

[bagder]

Took me a while but now I have a 20.04 VM with a fresh curl build and... test 433 works fine here! 😞

[mback2k]

I guess this is a behavioral issue that only appears if the whole test suite is run (multiple times).

[jay]

This is a weird one. It looks like the last line of the curlrc file is not read, but why. It could be a bug in curl. Try adding DEBUG_CONFIG to the preprocessor macros

curl/src/tool_parsecfg.c

Lines 187 to 189 in 2f33be8

	#ifdef DEBUG_CONFIG
	fprintf(stderr, "GOT: %s\n", option);
	#endif

curl/src/tool_parsecfg.c

Lines 240 to 242 in 2f33be8

	#ifdef DEBUG_CONFIG
	fprintf(stderr, "PARAM: \"%s\"\n",(param ? param : "(null)"));
	#endif

[bagder]

In the most recent commits on master I don't see any test 433 failures on azure.

[mback2k]

@bagder I still see it here on master for d4a9327:
https://dev.azure.com/daniel0244/curl/_build/results?buildId=5063&view=logs&j=151da4b9-79a9-5fb7-f410-d59e17c3897b&t=ae9b0b05-05f4-558b-579c-a14022f0f07d&l=1655
https://dev.azure.com/daniel0244/curl/_build/results?buildId=5063&view=logs&j=c9424829-8b1f-5fe2-e093-1cfd17bcdeea&t=4a1d5523-7d7b-5de5-63aa-8396a316d312&l=1407

and for cc615f4:
https://dev.azure.com/daniel0244/curl/_build/results?buildId=5070&view=logs&j=9d58b9ac-e1e6-53b6-f83a-1f9f1d912522&t=51a4b246-0fa1-595b-3cc7-3e7aeb2b7380&l=1826
https://dev.azure.com/daniel0244/curl/_build/results?buildId=5070&view=logs&j=8165c288-ede3-54c0-ec36-33b42243957c&t=d264b5ad-e851-5f24-484d-d9cf1546c408&l=1638
https://dev.azure.com/daniel0244/curl/_build/results?buildId=5070&view=logs&j=151da4b9-79a9-5fb7-f410-d59e17c3897b&t=ae9b0b05-05f4-558b-579c-a14022f0f07d&l=1655
https://dev.azure.com/daniel0244/curl/_build/results?buildId=5070&view=logs&j=c9424829-8b1f-5fe2-e093-1cfd17bcdeea&t=4a1d5523-7d7b-5de5-63aa-8396a316d312&l=1407

[bagder]

@jay: it also lacks the header in the request so I think it rather looks like it doesn't read the .curlrc file at all, which then make it looks like the XDG_CONFIG_HOME=%PWD/log environment variable setting doesn't work...

[jay]

Use #6756 to run experiments

[jay]

XDG_CONFIG_HOME is set by perl to /home/vsts/work/1/s/tests/log but when curl retrieves via getenv it's /.config so curl tries to open /.config/.curlrc which is wrong of course

full output

[jay]

What puzzles me is that it looks like curl finds CURL_HOME set and uses that, even though the test is supposed to clear that... ?

curl tool is called several times and there's debug output each time it's called. what I am looking at is the debug output in stderr logfile which should be the right one,

2021-03-17T07:13:06.0977860Z === Start of file stderr433
2021-03-17T07:13:06.0978102Z  DEBUG: parseconfig "(null)"
2021-03-17T07:13:06.0978329Z  DEBUG: homedir(".curlrc")
2021-03-17T07:13:06.0978574Z  DEBUG: CURL_HOME: (null)
2021-03-17T07:13:06.0978834Z  DEBUG: XDG_CONFIG_HOME: /.config
2021-03-17T07:13:06.0979092Z  DEBUG: c: /.config/.curlrc
2021-03-17T07:13:06.0979412Z  DEBUG: fd: -1
2021-03-17T07:13:06.0979641Z  DEBUG: errno: 2
2021-03-17T07:13:06.0979890Z  DEBUG: pathalloc: /home/vsts/.curlrc
2021-03-17T07:13:06.0980127Z  DEBUG: file: (nil)

I've modified the debug output to dump command line arguments as well, to be sure. My guess is the shell sets XDG_CONFIG_HOME

[bagder]

My guess is the shell sets XDG_CONFIG_HOME

Yes clearly something is setting it anyway after runtests.pl has set it. The question is then what we should do about it. I figure we have a few different alternatives. In order of my preference I can think of:

1. research if we can stop this practice in these CI machines (perhaps by removing/editing some files in the CI setup)
2. try to detect that it can't be set (<precheck> ?) and skip it if so
3. make the test debug-only and for such builds actually use a different environment varaible

[bagder]

BTW, in my Ubuntu 20.04 VM I don't get XDG_CONFIG_HOME at all in my standard shell after a very standard install:

$ env | grep XDG
XDG_CONFIG_DIRS=/etc/xdg/xdg-ubuntu:/etc/xdg
XDG_MENU_PREFIX=gnome-
XDG_SESSION_DESKTOP=ubuntu
XDG_SESSION_TYPE=x11
XDG_CURRENT_DESKTOP=ubuntu:GNOME
XDG_SESSION_CLASS=user
XDG_RUNTIME_DIR=/run/user/1000
XDG_DATA_DIRS=/usr/share/ubuntu:/usr/local/share/:/usr/share/:/var/lib/snapd/desktop