tests: reformat error messages to avoid tripping MSBuild

Change the format of error messages sent to stderr from tests and test
servers. As a workaround to avoid triggering Visual Studio's MSBuild
tool's built-in regexp matcher, and making it mark builds failed for
reasons we don't want them to hard fail.

Roughly, the pattern to avoid is the word "error" (case-insensitive)
in the same line with a colon `:`.

It affected GHA/windows MSVC CI jobs, causing flakiness:
```
CUSTOMBUILD : fopen() failed with error : 13 Permission denied [D:\a\curl\curl\bld\tests\test-ci.vcxproj]
  Error opening file: log/4/smtp_sockfilt.log
[...]
CUSTOMBUILD : fopen() failed with error : 13 Permission denied [D:\a\curl\curl\bld\tests\test-ci.vcxproj]
  Error opening file: log/8/imap_sockfilt.log
  Msg not logged: 00:18:10.656000 > 178 bytes data, server => client
[...]
  TESTDONE: 1629 tests out of 1634 reported OK: 99%
  Building Custom Rule D:/a/curl/curl/tests/CMakeLists.txt
C:\Program Files\Microsoft Visual Studio\2022\Enterprise\MSBuild\Microsoft\VC\v170\Microsoft.CppCommon.targets(254,5): error MSB8066: Custom build for 'D:\a\curl\curl\bld\CMakeFiles\621f80ddbb0fa48179f056ca77842ff0\test-ci.rule;D:\a\curl\curl\tests\CMakeLists.txt' exited with code -1. [D:\a\curl\curl\bld\tests\test-ci.vcxproj]
Error: Process completed with exit code 1.
```
Ref: https://github.com/curl/curl/actions/runs/13643149623/job/38137076210?pr=16490#step:14:3125
Ref: https://github.com/curl/curl/actions/runs/13688765792/job/38277961720?pr=16582#step:14:1717

The `IgnoreStandardErrorWarningFormat="true"` MSBuild Exec option
controls this behavior:
https://learn.microsoft.com/visualstudio/msbuild/exec-task#parameters
I couldn't figure out a way to apply it to CMake builds.

MSBuid pattern matching rules:
353c0f3d37/src/Shared/CanonicalError.cs
https://learn.microsoft.com/visualstudio/msbuild/msbuild-diagnostic-format-for-tasks

Note: There may be further error messages output from runtests scripts,
that use this format, which are not explicitly fatal. They may need
future fixes.

Thanks-to: Dion Williams
Ref: https://github.com/curl/curl/discussions/14854#discussioncomment-12382190
Ref: https://github.com/curl/curl/discussions/14854#discussioncomment-12395224

Closes #16583
This commit is contained in:
Viktor Szakats 2025-03-06 04:13:23 +01:00
parent 8537a5b0bc
commit 9463769f2e
No known key found for this signature in database
GPG key ID: B5ABD165E2AEF201
14 changed files with 130 additions and 130 deletions

View file

@ -242,7 +242,7 @@ static ssize_t fullread(int filedes, void *buffer, size_t nbytes)
return 0;
}
logmsg("reading from file descriptor: %d,", filedes);
logmsg("unrecoverable read() failure: (%d) %s",
logmsg("unrecoverable read() failure (%d) %s",
error, strerror(error));
return -1;
}
@ -288,7 +288,7 @@ static ssize_t fullwrite(int filedes, const void *buffer, size_t nbytes)
if((error == EINTR) || (error == EAGAIN))
continue;
logmsg("writing to file descriptor: %d,", filedes);
logmsg("unrecoverable write() failure: (%d) %s",
logmsg("unrecoverable write() failure (%d) %s",
error, strerror(error));
return -1;
}
@ -408,7 +408,7 @@ static bool read_data_block(unsigned char *buffer, ssize_t maxlen,
*buffer_len = (ssize_t)strtol((char *)buffer, NULL, 16);
if(*buffer_len > maxlen) {
logmsg("ERROR: Buffer size (%zd bytes) too small for data size "
logmsg("Buffer size (%zd bytes) too small for data size error "
"(%zd bytes)", maxlen, *buffer_len);
return FALSE;
}
@ -558,7 +558,7 @@ static unsigned int WINAPI select_ws_wait_thread(void *lpParameter)
/* if the pipe has NOT been closed, sleep and continue waiting */
ret = GetLastError();
if(ret != ERROR_BROKEN_PIPE) {
logmsg("[select_ws_wait_thread] PeekNamedPipe error: %lu", ret);
logmsg("[select_ws_wait_thread] PeekNamedPipe error (%lu)", ret);
SleepEx(0, FALSE);
continue;
}
@ -925,7 +925,7 @@ static bool disc_handshake(void)
return FALSE;
}
else {
logmsg("Error: unexpected message; aborting");
logmsg("Unexpected message error; aborting");
/*
* The only other messages that could occur here are PING and PORT,
* and both of them occur at the start of a test when nothing should be
@ -1084,7 +1084,7 @@ static bool juggle(curl_socket_t *sockfdp,
} while((rc == -1) && ((error = SOCKERRNO) == EINTR));
if(rc < 0) {
logmsg("select() failed with error: (%d) %s",
logmsg("select() failed with error (%d) %s",
error, sstrerror(error));
return FALSE;
}
@ -1187,7 +1187,7 @@ static bool juggle(curl_socket_t *sockfdp,
if(CURL_SOCKET_BAD == newfd) {
error = SOCKERRNO;
logmsg("accept(%" FMT_SOCKET_T ", NULL, NULL) "
"failed with error: (%d) %s", sockfd, error, sstrerror(error));
"failed with error (%d) %s", sockfd, error, sstrerror(error));
}
else {
logmsg("====> Client connect");
@ -1251,14 +1251,14 @@ static curl_socket_t sockdaemon(curl_socket_t sock,
(void *)&flag, sizeof(flag));
if(rc) {
error = SOCKERRNO;
logmsg("setsockopt(SO_REUSEADDR) failed with error: (%d) %s",
logmsg("setsockopt(SO_REUSEADDR) failed with error (%d) %s",
error, sstrerror(error));
if(maxretr) {
rc = wait_ms(delay);
if(rc) {
/* should not happen */
error = errno;
logmsg("wait_ms() failed with error: (%d) %s",
logmsg("wait_ms() failed with error (%d) %s",
error, strerror(error));
sclose(sock);
return CURL_SOCKET_BAD;
@ -1275,7 +1275,7 @@ static curl_socket_t sockdaemon(curl_socket_t sock,
} while(rc && maxretr--);
if(rc) {
logmsg("setsockopt(SO_REUSEADDR) failed %d times in %d ms. Error: (%d) %s",
logmsg("setsockopt(SO_REUSEADDR) failed %d times in %d ms. Error (%d) %s",
attempt, totdelay, error, strerror(error));
logmsg("Continuing anyway...");
}
@ -1303,7 +1303,7 @@ static curl_socket_t sockdaemon(curl_socket_t sock,
#endif /* USE_IPV6 */
if(rc) {
error = SOCKERRNO;
logmsg("Error binding socket on port %hu: (%d) %s",
logmsg("Error binding socket on port %hu (%d) %s",
*listenport, error, sstrerror(error));
sclose(sock);
return CURL_SOCKET_BAD;
@ -1325,7 +1325,7 @@ static curl_socket_t sockdaemon(curl_socket_t sock,
memset(&localaddr.sa, 0, (size_t)la_size);
if(getsockname(sock, &localaddr.sa, &la_size) < 0) {
error = SOCKERRNO;
logmsg("getsockname() failed with error: (%d) %s",
logmsg("getsockname() failed with error (%d) %s",
error, sstrerror(error));
sclose(sock);
return CURL_SOCKET_BAD;
@ -1363,7 +1363,7 @@ static curl_socket_t sockdaemon(curl_socket_t sock,
rc = listen(sock, 5);
if(0 != rc) {
error = SOCKERRNO;
logmsg("listen(%" FMT_SOCKET_T ", 5) failed with error: (%d) %s",
logmsg("listen(%" FMT_SOCKET_T ", 5) failed with error (%d) %s",
sock, error, sstrerror(error));
sclose(sock);
return CURL_SOCKET_BAD;
@ -1513,7 +1513,7 @@ int main(int argc, char *argv[])
if(CURL_SOCKET_BAD == sock) {
error = SOCKERRNO;
logmsg("Error creating socket: (%d) %s", error, sstrerror(error));
logmsg("Error creating socket (%d) %s", error, sstrerror(error));
write_stdout("FAIL\n", 5);
goto sockfilt_cleanup;
}
@ -1548,7 +1548,7 @@ int main(int argc, char *argv[])
#endif /* USE_IPV6 */
if(rc) {
error = SOCKERRNO;
logmsg("Error connecting to port %hu: (%d) %s",
logmsg("Error connecting to port %hu (%d) %s",
connectport, error, sstrerror(error));
write_stdout("FAIL\n", 5);
goto sockfilt_cleanup;