Skip to content
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.

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

mqtt: enable by default #5858

Closed
wants to merge 1 commit into from
Closed

Conversation

bagder
Copy link
Member

@bagder bagder commented Aug 26, 2020

No longer considered experimental.

Proposal taken to the mailing list: https://curl.haxx.se/mail/lib-2020-08/0033.html

@bagder bagder added the MQTT label Aug 26, 2020
@jay
Copy link
Member

jay commented Aug 27, 2020

The CI shows some tests failing for msys1_mingw_debug_openssl and what it's dumping during the failed tests appears to be MQTT tests of different test numbers which passed so I don't know what's going on.

2020-08-26T10:39:56.4260425Z test 1190...[MQTT SUBSCRIBE]
2020-08-26T10:39:56.6790397Z --p----e--- OK (912 out of 1362, remaining: 10:34, took 2.034s, duration: 21:25)
2020-08-26T10:47:26.0914174Z test 1449...[FTP download range with integer overflow]
2020-08-26T10:47:26.6192371Z --p----e--- OK (1156 out of 1362, remaining: 05:09, took 0.833s, duration: 28:55)
2020-08-26T10:47:27.5096138Z /usr/bin/env: python: No such file or directory
2020-08-26T10:47:32.4308539Z == Contents of files in the log/ dir after test 1450
2020-08-26T10:47:32.4309150Z === Start of file ftp_server.log
2020-08-26T10:47:32.4309670Z  10:47:28.159879 DATA sockfilt for passive data channel killed now
2020-08-26T10:47:32.4310193Z  10:47:28.168508 Awaiting input
2020-08-26T10:47:32.4310605Z === End of file ftp_server.log
2020-08-26T10:47:32.4311231Z === Start of file test1190
2020-08-26T10:47:32.4311590Z  <testcase>
2020-08-26T10:47:32.4311855Z  <info>
2020-08-26T10:47:32.4312206Z  <keywords>
2020-08-26T10:47:32.4312464Z  MQTT
...

and a whole lot of that.

/cc @mback2k

@bagder
Copy link
Member Author

bagder commented Aug 28, 2020

It looks like the directory isn't cleaned properly so there are leftovers from several previous tests in there, tests that ran fine.

@mback2k
Copy link
Member

mback2k commented Aug 28, 2020

It looks like the directory isn't cleaned properly so there are leftovers from several previous tests in there, tests that ran fine.

Could this be related to the tests being flaky in general? I am currently thinking about creating a C-only version of my group-job utility to include in the curl test suite in order to have process chains shutdown completely. It seems like lingering processes are still the root cause of trouble with the Window CI. Since there is no exec/fork-like process spawning on Windows, the Shell and Perl scripts in the test suite result in huge process hierarchies and the lt-script-wrapper binaries add up to that as well. So my current guess is that the PID and process shutdown/reaping does not work in all cases, which seems to be confirmed by this:

2020-08-26T10:55:09.4000167Z Warning: tftp server unexpectedly alive
2020-08-26T10:55:42.6709322Z Warning: http server unexpectedly alive
2020-08-26T10:56:14.8158368Z Warning: gopher-ipv6 server unexpectedly alive
2020-08-26T10:56:47.1319945Z Warning: rtsp server unexpectedly alive
2020-08-26T10:57:18.9065927Z Warning: gopher server unexpectedly alive
2020-08-26T10:57:47.9195004Z Warning: http2 server unexpectedly alive
2020-08-26T10:58:20.5639129Z Warning: http-ipv6 server unexpectedly alive

https://dev.azure.com/daniel0244/curl/_build/results?buildId=2874&view=logs&j=615b66df-eaf6-5866-5430-1c294f968047&t=a13db5bd-aeb3-5dc4-dfab-dd6cee9aedd4&l=8981

@jay
Copy link
Member

jay commented Aug 29, 2020

If you want to try that I have no problem with it, but to me it seems like a shot in the dark. I think I've seen too much random CI weirdness over time and I'm prone to ignore it unless it keeps happening.

/azp run windows

No longer considered experimental.

Closes #5858
@bagder bagder force-pushed the bagder/mqtt-unmark-experimental branch from aae0d72 to bfceca9 Compare August 29, 2020 22:21
@bagder bagder marked this pull request as ready for review August 31, 2020 07:44
@bagder bagder closed this in e37e446 Aug 31, 2020
@bagder bagder deleted the bagder/mqtt-unmark-experimental branch August 31, 2020 07:45
mback2k added a commit to mback2k/curl that referenced this pull request Sep 1, 2020
@emilengler
Copy link
Contributor

emilengler commented Sep 1, 2020

This introduced another data race:

WARNING: ThreadSanitizer: data race (pid=22832)
  Read of size 1 at 0x7b740000061f by thread T1 (mutexes: write M9):
    #0 ConnectionExists /home/eengler/dev/curl/lib/url.c:1119:10 (libcurl.so.4+0x37e9b)
    #1 create_conn /home/eengler/dev/curl/lib/url.c:3699:13 (libcurl.so.4+0x40d11)
    #2 Curl_connect /home/eengler/dev/curl/lib/url.c:3958:12 (libcurl.so.4+0x418a8)
    #3 multi_runsingle /home/eengler/dev/curl/lib/multi.c:1822:16 (libcurl.so.4+0x7e311)
    #4 curl_multi_perform /home/eengler/dev/curl/lib/multi.c:2560:14 (libcurl.so.4+0x80842)
    #5 easy_transfer /home/eengler/dev/curl/lib/easy.c:603:15 (libcurl.so.4+0x21232)
    #6 easy_perform /home/eengler/dev/curl/lib/easy.c:693:42 (libcurl.so.4+0x214f4)
    #7 curl_easy_perform /home/eengler/dev/curl/lib/easy.c:712:10 (libcurl.so.4+0x21545)
    #8 do_transfer <null> (a.out+0x4aee55)
    #9 thread_func <null> (a.out+0x4aedd8)

  Previous write of size 1 at 0x7b740000061f by main thread:
    #0 Curl_init_do /home/eengler/dev/curl/lib/url.c:4006:24 (libcurl.so.4+0x41a23)
    #1 create_conn /home/eengler/dev/curl/lib/url.c:3830:3 (libcurl.so.4+0x412be)
    #2 Curl_connect /home/eengler/dev/curl/lib/url.c:3958:12 (libcurl.so.4+0x418a8)
    #3 multi_runsingle /home/eengler/dev/curl/lib/multi.c:1822:16 (libcurl.so.4+0x7e311)
    #4 curl_multi_perform /home/eengler/dev/curl/lib/multi.c:2560:14 (libcurl.so.4+0x80842)
    #5 easy_transfer /home/eengler/dev/curl/lib/easy.c:603:15 (libcurl.so.4+0x21232)
    #6 easy_perform /home/eengler/dev/curl/lib/easy.c:693:42 (libcurl.so.4+0x214f4)
    #7 curl_easy_perform /home/eengler/dev/curl/lib/easy.c:712:10 (libcurl.so.4+0x21545)
    #8 do_transfer <null> (a.out+0x4aee55)
    #9 main <null> (a.out+0x4aec96)

  Location is heap block of size 2104 at 0x7b7400000000 allocated by main thread:
    #0 calloc <null> (a.out+0x42551a)
    #1 curl_dbg_calloc /home/eengler/dev/curl/lib/memdebug.c:205:9 (libcurl.so.4+0x6d855)
    #2 allocate_conn /home/eengler/dev/curl/lib/url.c:1582:30 (libcurl.so.4+0x39560)
    #3 create_conn /home/eengler/dev/curl/lib/url.c:3416:10 (libcurl.so.4+0x3f9ad)
    #4 Curl_connect /home/eengler/dev/curl/lib/url.c:3958:12 (libcurl.so.4+0x418a8)
    #5 multi_runsingle /home/eengler/dev/curl/lib/multi.c:1822:16 (libcurl.so.4+0x7e311)
    #6 curl_multi_perform /home/eengler/dev/curl/lib/multi.c:2560:14 (libcurl.so.4+0x80842)
    #7 easy_transfer /home/eengler/dev/curl/lib/easy.c:603:15 (libcurl.so.4+0x21232)
    #8 easy_perform /home/eengler/dev/curl/lib/easy.c:693:42 (libcurl.so.4+0x214f4)
    #9 curl_easy_perform /home/eengler/dev/curl/lib/easy.c:712:10 (libcurl.so.4+0x21545)
    #10 do_transfer <null> (a.out+0x4aee55)
    #11 main <null> (a.out+0x4aec96)

  Mutex M9 (0x000000f0c2c8) created at:
    #0 pthread_mutex_lock <null> (a.out+0x4422ee)
    #1 lock_func <null> (a.out+0x4aed2d)
    #2 Curl_share_lock /home/eengler/dev/curl/lib/share.c:238:7 (libcurl.so.4+0xad92f)
    #3 curl_multi_add_handle /home/eengler/dev/curl/lib/multi.c:517:3 (libcurl.so.4+0x7a545)
    #4 easy_perform /home/eengler/dev/curl/lib/easy.c:681:11 (libcurl.so.4+0x2148a)
    #5 curl_easy_perform /home/eengler/dev/curl/lib/easy.c:712:10 (libcurl.so.4+0x21545)
    #6 do_transfer <null> (a.out+0x4aee55)
    #7 main <null> (a.out+0x4aec96)

  Thread T1 (tid=22834, running) created by main thread at:
    #0 pthread_create <null> (a.out+0x4267e5)
    #1 main <null> (a.out+0x4aec8a)

SUMMARY: ThreadSanitizer: data race /home/eengler/dev/curl/lib/url.c:1119:10 in ConnectionExists
==================
==================
WARNING: ThreadSanitizer: data race (pid=22832)
  Read of size 1 at 0x7b740000061c by thread T1 (mutexes: write M9):
    #0 ConnectionExists /home/eengler/dev/curl/lib/url.c:1119:35 (libcurl.so.4+0x37ec3)
    #1 create_conn /home/eengler/dev/curl/lib/url.c:3699:13 (libcurl.so.4+0x40d11)
    #2 Curl_connect /home/eengler/dev/curl/lib/url.c:3958:12 (libcurl.so.4+0x418a8)
    #3 multi_runsingle /home/eengler/dev/curl/lib/multi.c:1822:16 (libcurl.so.4+0x7e311)
    #4 curl_multi_perform /home/eengler/dev/curl/lib/multi.c:2560:14 (libcurl.so.4+0x80842)
    #5 easy_transfer /home/eengler/dev/curl/lib/easy.c:603:15 (libcurl.so.4+0x21232)
    #6 easy_perform /home/eengler/dev/curl/lib/easy.c:693:42 (libcurl.so.4+0x214f4)
    #7 curl_easy_perform /home/eengler/dev/curl/lib/easy.c:712:10 (libcurl.so.4+0x21545)
    #8 do_transfer <null> (a.out+0x4aee55)
    #9 thread_func <null> (a.out+0x4aedd8)

  Previous write of size 1 at 0x7b740000061c by main thread:
    #0 Curl_init_do /home/eengler/dev/curl/lib/url.c:4006:24 (libcurl.so.4+0x41a23)
    #1 create_conn /home/eengler/dev/curl/lib/url.c:3830:3 (libcurl.so.4+0x412be)
    #2 Curl_connect /home/eengler/dev/curl/lib/url.c:3958:12 (libcurl.so.4+0x418a8)
    #3 multi_runsingle /home/eengler/dev/curl/lib/multi.c:1822:16 (libcurl.so.4+0x7e311)
    #4 curl_multi_perform /home/eengler/dev/curl/lib/multi.c:2560:14 (libcurl.so.4+0x80842)
    #5 easy_transfer /home/eengler/dev/curl/lib/easy.c:603:15 (libcurl.so.4+0x21232)
    #6 easy_perform /home/eengler/dev/curl/lib/easy.c:693:42 (libcurl.so.4+0x214f4)
    #7 curl_easy_perform /home/eengler/dev/curl/lib/easy.c:712:10 (libcurl.so.4+0x21545)
    #8 do_transfer <null> (a.out+0x4aee55)
    #9 main <null> (a.out+0x4aec96)

  Location is heap block of size 2104 at 0x7b7400000000 allocated by main thread:
    #0 calloc <null> (a.out+0x42551a)
    #1 curl_dbg_calloc /home/eengler/dev/curl/lib/memdebug.c:205:9 (libcurl.so.4+0x6d855)
    #2 allocate_conn /home/eengler/dev/curl/lib/url.c:1582:30 (libcurl.so.4+0x39560)
    #3 create_conn /home/eengler/dev/curl/lib/url.c:3416:10 (libcurl.so.4+0x3f9ad)
    #4 Curl_connect /home/eengler/dev/curl/lib/url.c:3958:12 (libcurl.so.4+0x418a8)
    #5 multi_runsingle /home/eengler/dev/curl/lib/multi.c:1822:16 (libcurl.so.4+0x7e311)
    #6 curl_multi_perform /home/eengler/dev/curl/lib/multi.c:2560:14 (libcurl.so.4+0x80842)
    #7 easy_transfer /home/eengler/dev/curl/lib/easy.c:603:15 (libcurl.so.4+0x21232)
    #8 easy_perform /home/eengler/dev/curl/lib/easy.c:693:42 (libcurl.so.4+0x214f4)
    #9 curl_easy_perform /home/eengler/dev/curl/lib/easy.c:712:10 (libcurl.so.4+0x21545)
    #10 do_transfer <null> (a.out+0x4aee55)
    #11 main <null> (a.out+0x4aec96)

  Mutex M9 (0x000000f0c2c8) created at:
    #0 pthread_mutex_lock <null> (a.out+0x4422ee)
    #1 lock_func <null> (a.out+0x4aed2d)
    #2 Curl_share_lock /home/eengler/dev/curl/lib/share.c:238:7 (libcurl.so.4+0xad92f)
    #3 curl_multi_add_handle /home/eengler/dev/curl/lib/multi.c:517:3 (libcurl.so.4+0x7a545)
    #4 easy_perform /home/eengler/dev/curl/lib/easy.c:681:11 (libcurl.so.4+0x2148a)
    #5 curl_easy_perform /home/eengler/dev/curl/lib/easy.c:712:10 (libcurl.so.4+0x21545)
    #6 do_transfer <null> (a.out+0x4aee55)
    #7 main <null> (a.out+0x4aec96)

  Thread T1 (tid=22834, running) created by main thread at:
    #0 pthread_create <null> (a.out+0x4267e5)
    #1 main <null> (a.out+0x4aec8a)

Was working on #4915 and this new race appeared. After reveting this commit in lib/url.c everything was "fine" again

@emilengler
Copy link
Contributor

Turns out this is the fault of our implementation of MQTT, not this commit. Sorry for the false warning

mback2k added a commit that referenced this pull request Sep 2, 2020
Reviewed-by: Daniel Stenberg

Follow up to #5858
Closes #5903
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Development

Successfully merging this pull request may close these issues.

None yet

4 participants