moqdateserver crash - connecting to relay onAnnounceOk

[gmarzot]

gmarzot@typhoon:~/Projects/moq/upstream/moxygen$ ./moxygen/samples/date/moqdateserver --logging DBG -v 6 --cert certs/certificate.pem --key certs/certificate.key -relay_url https://relay.vivohcast.net:4433/moq
V0208 12:45:57.441511 3097917 MoQClient.cpp:53] connectH3WithWebtransport
V0208 12:45:57.441525 3097917 HQConnector.cpp:32] HQConnector
V0208 12:45:57.441584 3097917 HQConnector.cpp:79] connect, timeout=1000ms
V0208 12:45:57.444498 3097917 MoQClient.cpp:38] connectSuccess
V0208 12:45:57.444527 3097917 HQConnector.cpp:36] ~HQConnector
V0208 12:45:57.444531 3097917 HQConnector.cpp:48] reset
V0208 12:45:57.444534 3097917 MoQClient.cpp:55] exit connectH3WithWebtransport
V0208 12:45:57.445359 3097917 MoQSession.cpp:1040] start sess=0x55ea3ce2d870
V0208 12:45:57.445390 3097917 MoQSession.cpp:1141] setup sess=0x55ea3ce2d870
V0208 12:45:57.445457 3097917 MoQSession.cpp:1105] controlWriteLoop sess=0x55ea3ce2d870
V0208 12:45:57.445479 3097917 MoQSession.cpp:1225] controlReadLoop sess=0x55ea3ce2d870
V0208 12:45:57.445687 3097917 MoQCodec.cpp:292] parsing frame type=65
V0208 12:45:57.445694 3097917 MoQSession.cpp:1177] onServerSetup sess=0x55ea3ce2d870
V0208 12:45:57.445732 3097917 MoQSession.cpp:2225] announce ns=moq-date sess=0x55ea3ce2d870
V0208 12:45:57.446035 3097917 MoQCodec.cpp:292] parsing frame type=7
V0208 12:45:57.446042 3097917 MoQSession.cpp:1992] onAnnounceOk ns=moq-date sess=0x55ea3ce2d870
*** Aborted at 1739036757 (Unix time, try 'date -d @1739036757') ***
*** Signal 11 (SIGSEGV) (0x55ef62411388) received by PID 3097917 (pthread TID 0x7ff2f8a7f280) (linux TID 3097917) (code: address not mapped to object), stack trace: ***
./moxygen/samples/date/moqdateserver(+0x21ef82)[0x55ea2bb8df82]
./moxygen/samples/date/moqdateserver(+0x1d6bdd)[0x55ea2bb45bdd]
./moxygen/samples/date/moqdateserver(+0x1d4c72)[0x55ea2bb43c72]
/lib/x86_64-linux-gnu/libc.so.6(+0x4251f)[0x7ff2f8aca51f]
/lib/x86_64-linux-gnu/libc.so.6(free+0x1e)[0x7ff2f8b2d3fe]
./moxygen/samples/date/moqdateserver(_ZNSt6vectorINSt7__cxx1112basic_stringIcSt11char_traitsIcESaIcEEESaIS5_EED1Ev+0x39)[0x55ea2ba955b9]
./moxygen/samples/date/moqdateserver(+0x132f6e)[0x55ea2baa1f6e]
./moxygen/samples/date/moqdateserver(+0x1ac971)[0x55ea2bb1b971]
./moxygen/samples/date/moqdateserver(+0x127ae4)[0x55ea2ba96ae4]
./moxygen/samples/date/moqdateserver(+0x16a7de)[0x55ea2bad97de]
./moxygen/samples/date/moqdateserver(+0x163d19)[0x55ea2bad2d19]
./moxygen/samples/date/moqdateserver(+0x163ead)[0x55ea2bad2ead]
./moxygen/samples/date/moqdateserver(+0x166c8f)[0x55ea2bad5c8f]
./moxygen/samples/date/moqdateserver(+0x1676a4)[0x55ea2bad66a4]
./moxygen/samples/date/moqdateserver(+0x16773f)[0x55ea2bad673f]
./moxygen/samples/date/moqdateserver(+0x1698cc)[0x55ea2bad88cc]
./moxygen/samples/date/moqdateserver(+0x1153d7)[0x55ea2ba843d7]
/lib/x86_64-linux-gnu/libc.so.6(+0x29d8f)[0x7ff2f8ab1d8f]
/lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0x7f)[0x7ff2f8ab1e3f]
./moxygen/samples/date/moqdateserver(+0x11c564)[0x55ea2ba8b564]
./moxygen/samples/date/moqdateserver(+0x1d6c8c)[0x55ea2bb45c8c]
./moxygen/samples/date/moqdateserver(+0x1ac972)[0x55ea2bb1b972]
./moxygen/samples/date/moqdateserver(+0x115248)[0x55ea2ba84248]
./moxygen/samples/date/moqdateserver(+0x115ff9)[0x55ea2ba84ff9]
(safe mode, symbolizer not available)
*** Check failure async stack trace: ***
*** First async stack root: 0x7ffe3ff733d0, normal stack frame pointer holding async stack root: 0x7ffe3ff73410, return address: 0x55ea2ba96ae5 ***
*** First async stack frame pointer: 0x55ea3ce00348, return address: 0x55ea2bb1b972, async stack trace: ***
(safe mode, symbolizer not available)
Segmentation fault (core dumped)

[gmarzot]

Log from relay

V0208 12:45:57.445198 3093074 MoQSession.cpp:1040] start sess=0x7fbd74021cb0
V0208 12:45:57.445523 3093074 MoQSession.cpp:2742] onNewBidiStream sess=0x7fbd74021cb0
V0208 12:45:57.445544 3093074 MoQSession.cpp:1225] controlReadLoop sess=0x7fbd74021cb0
V0208 12:45:57.445552 3093074 MoQSession.cpp:1105] controlWriteLoop sess=0x7fbd74021cb0
V0208 12:45:57.445563 3093074 MoQCodec.cpp:292] parsing frame type=64
V0208 12:45:57.445567 3093074 MoQSession.cpp:1191] onClientSetup sess=0x7fbd74021cb0
I0208 12:45:57.445570 3093074 MoQServer.cpp:60] ClientSetup
V0208 12:45:57.445887 3093074 MoQCodec.cpp:292] parsing frame type=6
V0208 12:45:57.445895 3093074 MoQSession.cpp:1949] onAnnounce ns=moq-date sess=0x7fbd74021cb0
V0208 12:45:57.445913 3093074 MoQRelay.cpp:43] announce ns=moq-date
V0208 12:45:57.445919 3093074 MoQSession.cpp:2249] announceOk ns=moq-date sess=0x7fbd74021cb0
E0208 12:45:58.505657 3093074 MoQServer.h:63] proxygen::HTTPException: Got error=LocalError: Connection abandoned, Exceeded max PTO
V0208 12:45:58.505668 3093074 MoQSession.h:187] onSessionEnderr=4294967295 sess=0x7fbd74021cb0
V0208 12:45:58.505687 3093074 MoQSession.cpp:1087] close sess=0x7fbd74021cb0
V0208 12:45:58.505690 3093074 MoQRelay.cpp:80] unannounce ns=moq-date
V0208 12:45:58.505694 3093074 MoQSession.cpp:1029] requestCancellation from cleanup sess=0x7fbd74021cb0
V0208 12:45:58.505698 3093074 MoQSession.cpp:1098] requestCancellation from close sess=0x7fbd74021cb0
E0208 12:45:58.505817 3093074 MoQSession.cpp:1240] proxygen::WebTransport::Exception: quic error with error=4294967295 id=4 sess=0x7fbd74021cb0
V0208 12:45:58.505822 3093074 MoQSession.cpp:1227] exit controlReadLoop sess=0x7fbd74021cb0
V0208 12:45:58.505901 3093074 MoQSession.cpp:1107] exit controlWriteLoop sess=0x7fbd74021cb0
V0208 12:45:58.505908 3093074 MoQSession.cpp:978] ~MoQSession sess=0x7fbd74021cb0

[afrind]

Hm, I couldn't reproduce on localhost:

W0209 17:58:50.130141 1541181 QuicServerWorker.cpp:1231] HostId is already set to 0
V0209 17:58:50.131195 1541181 MoQClient.cpp:53] connectH3WithWebtransport
V0209 17:58:50.158595 1541181 MoQClient.cpp:38] connectSuccess
V0209 17:58:50.158868 1541181 MoQClient.cpp:55] exit connectH3WithWebtransport
V0209 17:58:50.167749 1541181 MoQSession.cpp:1040] start sess=0x516000004b90
V0209 17:58:50.168207 1541181 MoQSession.cpp:1141] setup sess=0x516000004b90
V0209 17:58:50.168797 1541181 MoQSession.cpp:1105] controlWriteLoop sess=0x516000004b90
V0209 17:58:50.169014 1541181 MoQSession.cpp:1225] controlReadLoop sess=0x516000004b90
V0209 17:58:50.171679 1541181 MoQCodec.cpp:292] parsing frame type=65
V0209 17:58:50.171779 1541181 MoQSession.cpp:1177] onServerSetup sess=0x516000004b90
V0209 17:58:50.172167 1541181 MoQSession.cpp:2225] announce ns=moq-date sess=0x516000004b90
V0209 17:58:50.175191 1541181 MoQCodec.cpp:292] parsing frame type=7
V0209 17:58:50.175300 1541181 MoQSession.cpp:1992] onAnnounceOk ns=moq-date sess=0x516000004b90
V0209 17:58:50.175510 1541181 MoQSession.cpp:2270] unannounce ns=moq-date sess=0x516000004b90

However, the unannounce shouldn't be there and I see why it is -- MoQRelayClient::run lets the returned AnnounceHandle go out of scope. It needs to be held or passed back or something.

I wonder if it's a related timing issue?

[gmarzot]

crach reproducible every time here

Core was generated by `./_build/bin/moqdateserver --logging DBG -v 10 --cert certs/certificate.pem --k'.
Program terminated with signal SIGSEGV, Segmentation fault.
#0 0x00007f82cdf0b3fe in __GI___libc_free (mem=0x56158ac170c1) at ./malloc/malloc.c:3368
3368 ./malloc/malloc.c: No such file or directory.
[Current thread is 1 (Thread 0x7f82cde5d280 (LWP 1049661))]
(gdb) bt
#0 0x00007f82cdf0b3fe in __GI___libc_free (mem=0x56158ac170c1) at ./malloc/malloc.c:3368
#1 0x00005610be9a16da in __gnu_cxx::new_allocator::deallocate (this=0x5610ebc71890, __t=,
__p=) at /usr/include/c++/11/ext/new_allocator.h:145
#2 std::allocator::deallocate (__n=, __p=, this=0x5610ebc71890)
at /usr/include/c++/11/bits/allocator.h:199
#3 std::allocator_traits<std::allocator >::deallocate (__n=, __p=, __a=...)
at /usr/include/c++/11/bits/alloc_traits.h:496
#4 std::__cxx11::basic_string<char, std::char_traits, std::allocator >::_M_destroy (
__size=, this=0x5610ebc71890) at /usr/include/c++/11/bits/basic_string.h:245
#5 std::__cxx11::basic_string<char, std::char_traits, std::allocator >::_M_dispose (
this=0x5610ebc71890) at /usr/include/c++/11/bits/basic_string.h:240
#6 std::__cxx11::basic_string<char, std::char_traits, std::allocator >::~basic_string (
this=0x5610ebc71890, __in_chrg=) at /usr/include/c++/11/bits/basic_string.h:672
#7 std::destroy_at<std::__cxx11::basic_string<char, std::char_traits, std::allocator > > (
__location=0x5610ebc71890) at /usr/include/c++/11/bits/stl_construct.h:88
#8 std::_Destroy<std::__cxx11::basic_string<char, std::char_traits, std::allocator > > (
__pointer=0x5610ebc71890) at /usr/include/c++/11/bits/stl_construct.h:149
#9 std::_Destroy_aux::__destroy<std::__cxx11::basic_string<char, std::char_traits, std::allocator >> (__last=, __first=0x5610ebc71890) at /usr/include/c++/11/bits/stl_construct.h:163
#10 std::_Destroy<std::__cxx11::basic_string<char, std::char_traits, std::allocator >> (
__last=, __first=) at /usr/include/c++/11/bits/stl_construct.h:196
#11 std::_Destroy<std::__cxx11::basic_string<char, std::char_traits, std::allocator >*, std::__cxx11::basic_string<char, std::char_traits, std::allocator > > (__last=0x5610ebc718b0,
__first=) at /usr/include/c++/11/bits/alloc_traits.h:848
#12 std::vector<std::__cxx11::basic_string<char, std::char_traits, std::allocator >, std::allocator<std::__cxx11::basic_string<char, std::char_traits, std::allocator > > >::~vector (
this=0x5610ebbefb90, __in_chrg=) at /usr/include/c++/11/bits/stl_vector.h:680
#13 0x00005610be9acb6e in moxygen::TrackNamespace::~TrackNamespace (this=0x5610ebbefb90,
__in_chrg=) at /home/gmarzot/Projects/moq/moxygen/moxygen/MoQFramer.h:328
#14 moxygen::MoQRelayClient::run(ZN7moxygen14MoQRelayClient3runENS_4RoleESt6vectorINS_14TrackNamespaceESaIS3_EENSt6chrono8durationIlSt5ratioILl1ELl1000EEEESA.Frame *) (frame_ptr=0x5610ebbef9e0)
at /home/gmarzot/Projects/moq/moxygen/moxygen/relay/MoQRelayClient.h:56
#15 0x00005610bea27952 in std::__n4861::coroutine_handle::resume (this=)
--Type for more, q to quit, c to continue without paging--
at /usr/include/c++/11/coroutine:126
#16 folly::resumeCoroutineWithNewAsyncStackRoot (h=..., frame=...)
at /home/gmarzot/Projects/moq/moxygen/_build/deps/folly/folly/tracing/AsyncStack.cpp:201
#17 0x00005610be9a2865 in folly::coro::detail::ViaCoroutinePromiseBase::executeContinuation (
this=0x5610ebcf5c60) at /home/gmarzot/Projects/moq/moxygen/_build/deps/include/folly/coro/Coroutine.h:340
#18 folly::coro::detail::ViaCoroutinePromiseBase::scheduleContinuation()::{lambda()#1}::operator()() const (
__closure=)
at /home/gmarzot/Projects/moq/moxygen/build/deps/include/folly/coro/ViaIfAsync.h:85
#19 folly::detail::function::call<folly::coro::detail::ViaCoroutinePromiseBase::scheduleContinuation()::{lambda()#1}, true, false, void>(, folly::detail::function::Data&) (p=...)
at /home/gmarzot/Projects/moq/moxygen/_build/deps/include/folly/Function.h:341
#20 0x00005610be9e57cf in folly::detail::function::FunctionTraits<void ()>::operator()() (this=0x5610ebcf5d00)
at /home/gmarzot/Projects/moq/moxygen/_build/deps/folly/folly/Function.h:370
#21 folly::EventBase::FunctionLoopCallback::runLoopCallback (this=0x5610ebcf5cd0)
at /home/gmarzot/Projects/moq/moxygen/_build/deps/folly/folly/io/async/EventBase.h:189
#22 0x00005610be9ded0a in folly::EventBase::runLoopCallbackList (this=0x7ffce732c660, currentCallbacks=...,
deadline=...) at /home/gmarzot/Projects/moq/moxygen/_build/deps/folly/folly/io/async/EventBase.cpp:984
#23 0x00005610be9dee9e in folly::EventBase::runLoopCallbacks (this=0x7ffce732c660)
at /home/gmarzot/Projects/moq/moxygen/_build/deps/folly/folly/io/async/EventBase.cpp:1005
#24 0x00005610be9e1c80 in folly::EventBase::loopMain (this=0x7ffce732c660, flags=, options=...)
at /home/gmarzot/Projects/moq/moxygen/_build/deps/folly/folly/io/async/EventBase.cpp:631
#25 0x00005610be9e2695 in folly::EventBase::loopBody (this=0x7ffce732c660, flags=0, options=...)
at /home/gmarzot/Projects/moq/moxygen/_build/deps/folly/folly/io/async/EventBase.cpp:516
#26 0x00005610be9e2730 in folly::EventBase::loop (this=0x7ffce732c660)
at /home/gmarzot/Projects/moq/moxygen/_build/deps/folly/folly/io/async/EventBase.cpp:477
#27 0x00005610be9e48bd in folly::EventBase::loopForever (this=this@entry=0x7ffce732c660)
at /home/gmarzot/Projects/moq/moxygen/_build/deps/folly/folly/io/async/EventBase.cpp:784
#28 0x00005610be990e35 in main (argc=, argv=)
at /home/gmarzot/Projects/moq/moxygen/moxygen/samples/date/MoQDateServer.cpp:356

[gmarzot]

PR #21