Skip to content

tests: frequent failure of test 2600 on Windows #14177

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom
Closed
vszakats opened this issue Jul 13, 2024 · 4 comments
Closed

tests: frequent failure of test 2600 on Windows #14177

vszakats opened this issue Jul 13, 2024 · 4 comments
Labels
CI Continuous Integration tests Windows Windows-specific

Comments

@vszakats
Copy link
Member

vszakats commented Jul 13, 2024 •
edited
Loading

I did this

Started seeing lots unit2600 failures recently (in the last week or so). This
can be been related to disabling more test groups and thus giving way to
this one, so it's not necessarly a recent regression.

This is often the last reported test, before the jobs hanging and timing out.

It happened with various mingw and MSVC configurations and versions.

Example:

  test 2600...[connection filter connect/destroy unit tests]
  
  unit2600 returned 20, when expecting 0
   2600: exit FAILED
  == Contents of files in the log/3/ dir after test 2600
  === Start of file server.cmd
   Testnum 2600
  === End of file server.cmd
  === Start of file stderr2600
   URL: -
   * !!! WARNING !!
   * This is a debug build of libcurl, do not use in production.
   * Added test.com:123:192.0.2.1 to DNS cache
   * STATE: INIT => SETUP handle 0x2d15b7a1e28; line 1936
   * STATE: SETUP => CONNECT handle 0x2d15b7a1e28; line 1952
   * Added connection 0. The cache now contains 1 members
   * Hostname test.com was found in DNS cache
   * STATE: CONNECT => CONNECTING handle 0x2d15b7a1e28; line 1988
   * 0001ms: cf[v4-0] created
   * multi_done[CONNECTING]: status: 0 prem: 1 done: 0
   * multi_done, not reusing connection=0, forbid=0, close=0, premature=1, conn_multiplex=0
   * The cache now contains 0 members
   * Curl_disconnect(conn #0, aborted=1)
   * closing connection #0
   * [CCACHE] closing #0
   * 0001ms: cf[v4-0] destroyed
   * Expire cleared
   1: test case took 1ms
   D:\a\curl\curl\tests\unit\unit2600.c:256 test FAILED: '1: expected result 7 but got 27'
   D:\a\curl\curl\tests\unit\unit2600.c:273 test FAILED: '1: expected min duration of 200ms, but took 1ms'
   * RESOLVE test.com:123 - old addresses discarded
   * Added test.com:123:192.0.2.1,192.0.2.2 to DNS cache
   * STATE: INIT => SETUP handle 0x2d15b7a1e28; line 1936
   * STATE: SETUP => CONNECT handle 0x2d15b7a1e28; line 1952
   * Added connection 1. The cache now contains 1 members
   * Hostname test.com was found in DNS cache
   * STATE: CONNECT => CONNECTING handle 0x2d15b7a1e28; line 1988
   * 0000ms: cf[v4-0] created
   * multi_done[CONNECTING]: status: 0 prem: 1 done: 0
   * multi_done, not reusing connection=1, forbid=0, close=0, premature=1, conn_multiplex=0
   * The cache now contains 0 members
   * Curl_disconnect(conn #1, aborted=1)
   * closing connection #1
   * [CCACHE] closing #1
   * 0000ms: cf[v4-0] destroyed
   * Expire cleared
   2: test case took 0ms
   D:\a\curl\curl\tests\unit\unit2600.c:256 test FAILED: '2: expected result 7 but got 27'
   D:\a\curl\curl\tests\unit\unit2600.c:261 test FAILED: '2: expected 2 ipv4 creations, but got 1'
   D:\a\curl\curl\tests\unit\unit2600.c:273 test FAILED: '2: expected min duration of 400ms, but took 0ms'
   * RESOLVE test.com:123 - old addresses discarded
   * Added test.com:123:::1 to DNS cache
   * STATE: INIT => SETUP handle 0x2d15b7a1e28; line 1936
   * STATE: SETUP => CONNECT handle 0x2d15b7a1e28; line 1952
   * Added connection 2. The cache now contains 1 members
   * Hostname test.com was found in DNS cache
   * STATE: CONNECT => CONNECTING handle 0x2d15b7a1e28; line 1988
   * 0000ms: cf[v6-0] created
   * multi_done[CONNECTING]: status: 0 prem: 1 done: 0
   * multi_done, not reusing connection=2, forbid=0, close=0, premature=1, conn_multiplex=0
   * The cache now contains 0 members
   * Curl_disconnect(conn #2, aborted=1)
   * closing connection #2
   * [CCACHE] closing #2
   * 0000ms: cf[v6-0] destroyed
   * Expire cleared
   3: test case took 0ms
   D:\a\curl\curl\tests\unit\unit2600.c:256 test FAILED: '3: expected result 7 but got 27'
   D:\a\curl\curl\tests\unit\unit2600.c:273 test FAILED: '3: expected min duration of 200ms, but took 0ms'
   * RESOLVE test.com:123 - old addresses discarded
   * Added test.com:123:::1,::2 to DNS cache
   * STATE: INIT => SETUP handle 0x2d15b7a1e28; line 1936
   * STATE: SETUP => CONNECT handle 0x2d15b7a1e28; line 1952
   * Added connection 3. The cache now contains 1 members
   * Hostname test.com was found in DNS cache
   * STATE: CONNECT => CONNECTING handle 0x2d15b7a1e28; line 1988
   * 0002ms: cf[v6-0] created
   * multi_done[CONNECTING]: status: 0 prem: 1 done: 0
   * multi_done, not reusing connection=3, forbid=0, close=0, premature=1, conn_multiplex=0
   * The cache now contains 0 members
   * Curl_disconnect(conn #3, aborted=1)
   * closing connection #3
   * [CCACHE] closing #3
   * 0002ms: cf[v6-0] destroyed
   * Expire cleared
   4: test case took 2ms
   D:\a\curl\curl\tests\unit\unit2600.c:256 test FAILED: '4: expected result 7 but got 27'
   D:\a\curl\curl\tests\unit\unit2600.c:266 test FAILED: '4: expected 2 ipv6 creations, but got 1'
   D:\a\curl\curl\tests\unit\unit2600.c:273 test FAILED: '4: expected min duration of 400ms, but took 2ms'
   * RESOLVE test.com:123 - old addresses discarded
   * Added test.com:123:192.0.2.1,::1 to DNS cache
   * STATE: INIT => SETUP handle 0x2d15b7a1e28; line 1936
   * STATE: SETUP => CONNECT handle 0x2d15b7a1e28; line 1952
   * Added connection 4. The cache now contains 1 members
   * Hostname test.com was found in DNS cache
   * STATE: CONNECT => CONNECTING handle 0x2d15b7a1e28; line 1988
   * 0000ms: cf[v4-0] created
   * multi_done[CONNECTING]: status: 0 prem: 1 done: 0
   * multi_done, not reusing connection=4, forbid=0, close=0, premature=1, conn_multiplex=0
   * The cache now contains 0 members
   * Curl_disconnect(conn #4, aborted=1)
   * closing connection #4
   * [CCACHE] closing #4
   * 0000ms: cf[v4-0] destroyed
   * Expire cleared
   5: test case took 0ms
   D:\a\curl\curl\tests\unit\unit2600.c:256 test FAILED: '5: expected result 7 but got 27'
   D:\a\curl\curl\tests\unit\unit2600.c:266 test FAILED: '5: expected 1 ipv6 creations, but got 0'
   D:\a\curl\curl\tests\unit\unit2600.c:273 test FAILED: '5: expected min duration of 350ms, but took 0ms'
   * RESOLVE test.com:123 - old addresses discarded
   * Added test.com:123:::1,192.0.2.1 to DNS cache
   * STATE: INIT => SETUP handle 0x2d15b7a1e28; line 1936
   * STATE: SETUP => CONNECT handle 0x2d15b7a1e28; line 1952
   * Added connection 5. The cache now contains 1 members
   * Hostname test.com was found in DNS cache
   * STATE: CONNECT => CONNECTING handle 0x2d15b7a1e28; line 1988
   * 0000ms: cf[v6-0] created
   * multi_done[CONNECTING]: status: 0 prem: 1 done: 0
   * multi_done, not reusing connection=5, forbid=0, close=0, premature=1, conn_multiplex=0
   * The cache now contains 0 members
   * Curl_disconnect(conn #5, aborted=1)
   * closing connection #5
   * [CCACHE] closing #5
   * 0000ms: cf[v6-0] destroyed
   * Expire cleared
   6: test case took 2ms
   D:\a\curl\curl\tests\unit\unit2600.c:256 test FAILED: '6: expected result 7 but got 27'
   D:\a\curl\curl\tests\unit\unit2600.c:261 test FAILED: '6: expected 1 ipv4 creations, but got 0'
   D:\a\curl\curl\tests\unit\unit2600.c:273 test FAILED: '6: expected min duration of 350ms, but took 2ms'
   * RESOLVE test.com:123 - old addresses discarded
   * Added test.com:123:192.0.2.1,::1 to DNS cache
   * STATE: INIT => SETUP handle 0x2d15b7a1e28; line 1936
   * STATE: SETUP => CONNECT handle 0x2d15b7a1e28; line 1952
   * Added connection 6. The cache now contains 1 members
   * Hostname test.com was found in DNS cache
   * STATE: CONNECT => CONNECTING handle 0x2d15b7a1e28; line 1988
   * 0000ms: cf[v4-0] created
   * multi_done[CONNECTING]: status: 0 prem: 1 done: 0
   * multi_done, not reusing connection=6, forbid=0, close=0, premature=1, conn_multiplex=0
   * The cache now contains 0 members
   * Curl_disconnect(conn #6, aborted=1)
   * closing connection #6
   * [CCACHE] closing #6
   * 0000ms: cf[v4-0] destroyed
   * Expire cleared
   7: test case took 0ms
   D:\a\curl\curl\tests\unit\unit2600.c:256 test FAILED: '7: expected result 7 but got 27'
   D:\a\curl\curl\tests\unit\unit2600.c:273 test FAILED: '7: expected min duration of 400ms, but took 0ms'
   * RESOLVE test.com:123 - old addresses discarded
   * Added test.com:123:::1,192.0.2.1 to DNS cache
Error: The action 'cmake run tests' has timed out after 30 minutes.

Ref: https://github.com/curl/curl/actions/runs/9919874100/job/27406166474?pr=14175#step:13:5436

A collection of similar failures:

  1. https://github.com/curl/curl/actions/runs/9775422731/job/26985795679 (old-mingw-w64, 9.5.0) location unknown, last executed was test2600 with a failure
  2. https://github.com/curl/curl/actions/runs/9796121067/job/27049861121?pr=14096#step:14:2887 (msys2 cmake, mingw-w64, x86_64) last test in log: 2603
  3. https://github.com/curl/curl/actions/runs/9831904667/job/27139950536#step:9:5148 (msvc, libressl) last test: 2600
  4. https://github.com/curl/curl/actions/runs/9837611706/job/27155835549?pr=14117#step:9:5156 (msvc, boringssl) last test: 2600
  5. https://github.com/curl/curl/actions/runs/9841853460/job/27169458913?pr=14125#step:13:5265 (msvc, boringssl) last test: 2600
  6. https://github.com/curl/curl/actions/runs/9841771973/job/27169174607?pr=14124 (mingw, CM x86_64 schannel U) 'cmake run tests' step failed to start.
  7. https://github.com/curl/curl/actions/runs/9843527144/job/27174924074?pr=14129#step:23:3322 (mingw, CM x86_64 schannel U) last test: 2600
  8. https://github.com/curl/curl/actions/runs/9843961100/job/27176348727?pr=14097#step:23:3323 (mingw, CM x86_64 schannel U) last test: 2600
  9. https://github.com/curl/curl/actions/runs/9857526570/job/27216813548?pr=14137#step:13:5265 (msvc, boringssl) last test: 2600
  10. https://github.com/curl/curl/actions/runs/9918753161/attempts/1?pr=14174 (4 jobs) all test 2600

via #13599 (comment)

I expected the following

Test to finish, ideally with success.

curl/libcurl version

master (8.9.0-DEV)

operating system

Windows
@vszakats vszakats added tests Windows Windows-specific CI Continuous Integration labels Jul 13, 2024
@icing
Copy link
Contributor

icing commented Jul 15, 2024

27 is CURLE_OUT_OF_MEMORY? What is going on?

@vszakats
Copy link
Member Author

vszakats commented Jul 15, 2024 •
edited
Loading

One trend seems interesting: Cygwin and MSYS builds running on the same runner seem stable. Native Windows ones: odd hangs and flakiness. I have no clue why that is. Possibly Windows is just like that, but then why Cygwin and MSYS run fine?

Cygwin running with -j8 might explain its stability, but MSYS runs with the same -j14 as the unstable/hanging native Windows runs.

@icing
Copy link
Contributor

icing commented Jul 15, 2024

I think we should disable this test for Windows. It uses the file descriptor 1 as a valid, but uneventful socket. Which is not portable.

icing added a commit to icing/curl that referenced this issue Jul 15, 2024
@icing
test2600, disable on win32
f1ae130 
- disbable this test on WIN32 platforms. It uses the file describtor '1'
  as valid socket without events. Not portable.
- reduce trace output somewhat on other runs
- refs curl#14177
@icing icing mentioned this issue Jul 15, 2024
Closed
@icing
Copy link
Contributor

icing commented Jul 15, 2024

#14191 as proposed fix.

@bagder bagder closed this as completed in 6f0a8bd Jul 15, 2024
meslubi2021 pushed a commit to Unity-Curl/curl that referenced this issue Jul 19, 2024
@icing @meslubi2021
test2600: disable on win32
fed4e0c 
- disbable this test on WIN32 platforms. It uses the file describtor '1'
  as valid socket without events. Not portable.
- reduce trace output somewhat on other runs

Fixes curl#14177
Reported-by: Viktor Szakats
Closes curl#14191
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
CI Continuous Integration tests Windows Windows-specific
Milestone
No milestone
Development

No branches or pull requests
2 participants
@icing @vszakats