ice icon indicating copy to clipboard operation
ice copied to clipboard
verified publisher icon zeroc-ice

swift/Ice/hold failure

Open bernardnormier opened this issue 5 months ago • 5 comments

From https://github.com/zeroc-ice/ice/actions/runs/15855576926/job/44699905050

** [249/340] Running swift/Ice/hold tests ***
[ running client/server test - 06/24/25 16:24:44 ]
- Config: ssl,debug
(swift run -c debug --skip-build TestDriver Ice_hold Server --Ice.Default.Host=127.0.0.1 --Test.BasePort=14100 --Ice.Warn.Connections=1 --Ice.Default.Protocol=ssl --Ice.IPv6=0 --IceSSL.*** --IceSSL.DefaultDir=/Users/runner/work/ice/ice/certs/common/ca --IceSSL.CAs=ca_cert.pem --IceSSL.CertFile=server.p12 --IceSSL.KeychainPassword=password --IceSSL.Keychain=server.keychain --Ice.ThreadPool.Server.Size=1 --Ice.ThreadPool.Server.SizeMax=3 --Ice.ThreadPool.Server.SizeWarn=0 --Ice.PrintAdapterReady=1)
(swift run -c debug --skip-build TestDriver Ice_hold Client --Ice.Default.Host=127.0.0.1 --Test.BasePort=14100 --Ice.Warn.Connections=1 --Ice.Default.Protocol=ssl --Ice.IPv6=0 --IceSSL.*** --IceSSL.DefaultDir=/Users/runner/work/ice/ice/certs/common/ca --IceSSL.CAs=ca_cert.pem --IceSSL.CertFile=client.p12 --IceSSL.KeychainPassword=password --IceSSL.Keychain=client.keychain)
Another instance of SwiftPM is already running using '/Users/runner/work/ice/ice/swift/test/.build', waiting until that process has finished execution...testing stringToProxy... ok
testing checked cast... ok
changing state between active and hold rapidly... ok
testing waitForHold... ok
changing state to hold and shutting down server... ok
[ running client/server test - 06/24/25 16:24:47 ]
- Config: ws,compress,ipv6,serialize,mx,debug
(swift run -c debug --skip-build TestDriver Ice_hold Server --Ice.Default.Host=::1 --Test.BasePort=14100 --Ice.Warn.Connections=1 --Ice.Default.Protocol=ws --Ice.Override.Compress=1 --Ice.ThreadPool.Server.Serialize=1 --Ice.IPv6=1 --Ice.PreferIPv6Address=1 --Ice.Admin.Endpoints="tcp -h \"::1\"" --Ice.Admin.InstanceName=Server --IceMX.Metrics.Debug.GroupBy=id --IceMX.Metrics.Parent.GroupBy=parent --IceMX.Metrics.All.GroupBy=none --Ice.ThreadPool.Server.Size=1 --Ice.ThreadPool.Server.SizeMax=3 --Ice.ThreadPool.Server.SizeWarn=0 --Ice.PrintAdapterReady=1)
(swift run -c debug --skip-build TestDriver Ice_hold Client --Ice.Default.Host=::1 --Test.BasePort=14100 --Ice.Warn.Connections=1 --Ice.Default.Protocol=ws --Ice.Override.Compress=1 --Ice.ThreadPool.Server.Serialize=1 --Ice.IPv6=1 --Ice.PreferIPv6Address=1 --Ice.Admin.Endpoints="tcp -h \"::1\"" --Ice.Admin.InstanceName=Client --IceMX.Metrics.Debug.GroupBy=id --IceMX.Metrics.Parent.GroupBy=parent --IceMX.Metrics.All.GroupBy=none)
Another instance of SwiftPM is already running using '/Users/runner/work/ice/ice/swift/test/.build', waiting until that process has finished execution...testing stringToProxy... ok
testing checked cast... ok
changing state between active and hold rapidly... ok
testing waitForHold... -! 06/24/25 16:24:49.333 --Ice.Default.Host=::1: warning: connection exception:
   src/Ice/StreamSocket.cpp:213 Ice::ConnectionLostException connection lost: recv() returned zero
   stack trace:
     0 Ice::LocalException::LocalException(char const*, int, std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char>>) in TestDriver
     1 Ice::SyscallException::SyscallException(char const*, int, std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char>>, int, std::__1::function<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char>> (int)> const&) in TestDriver
     2 Ice::SocketException::SocketException(char const*, int, std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char>>, int, std::__1::function<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char>> (int)> const&) in TestDriver
     3 Ice::ConnectionLostException::ConnectionLostException(char const*, int, int) in TestDriver
     4 Ice::ConnectionLostException::ConnectionLostException(char const*, int, int) in TestDriver
     5 IceInternal::StreamSocket::read(char*, unsigned long) in TestDriver
     6 IceInternal::StreamSocket::read(IceInternal::Buffer&) in TestDriver
     7 IceInternal::TcpTransceiver::read(IceInternal::Buffer&) in TestDriver
     8 IceInternal::WSTransceiver::read(IceInternal::Buffer&) in TestDriver
     9 IceInternal::IdleTimeoutTransceiverDecorator::read(IceInternal::Buffer&) in TestDriver
    10 Ice::ConnectionI::read(IceInternal::Buffer&) in TestDriver
    11 Ice::ConnectionI::message(IceInternal::ThreadPoolCurrent&) in TestDriver
    12 IceInternal::ThreadPool::run(std::__1::shared_ptr<IceInternal::ThreadPool::EventHandlerThread> const&) in TestDriver
    13 IceInternal::ThreadPool::EventHandlerThread::run() in TestDriver
    14 decltype(*std::declval<IceInternal::ThreadPool::EventHandlerThread*>().*std::declval<void (IceInternal::ThreadPool::EventHandlerThread::*)()>()()) std::__1::__invoke[abi:ne190102]<void (IceInternal::ThreadPool::EventHandlerThread::*)(), IceInternal::ThreadPool::EventHandlerThread*, void>(void (IceInternal::ThreadPool::EventHandlerThread::*&&)(), IceInternal::ThreadPool::EventHandlerThread*&&) in TestDriver
    15 void std::__1::__thread_execute[abi:ne190102]<std::__1::unique_ptr<std::__1::__thread_struct, std::__1::default_delete<std::__1::__thread_struct>>, void (IceInternal::ThreadPool::EventHandlerThread::*)(), IceInternal::ThreadPool::EventHandlerThread*, 2ul>(std::__1::tuple<std::__1::unique_ptr<std::__1::__thread_struct, std::__1::default_delete<std::__1::__thread_struct>>, void (IceInternal::ThreadPool::EventHandlerThread::*)(), IceInternal::ThreadPool::EventHandlerThread*>&, std::__1::__tuple_indices<2ul>) in TestDriver
    16 void* std::__1::__thread_proxy[abi:ne190102]<std::__1::tuple<std::__1::unique_ptr<std::__1::__thread_struct, std::__1::default_delete<std::__1::__thread_struct>>, void (IceInternal::ThreadPool::EventHandlerThread::*)(), IceInternal::ThreadPool::EventHandlerThread*>>(void*) in TestDriver
    17 _pthread_start in libsystem_pthread.dylib
    18 thread_start in libsystem_pthread.dylib
   
   local address = ::1:50399
   remote address = ::1:14101
-! 06/24/25 16:24:49.346 --Ice.Default.Host=::1: warning: connection exception:
   src/Ice/StreamSocket.cpp:213 Ice::ConnectionLostException connection lost: recv() returned zero
   stack trace:
     0 Ice::LocalException::LocalException(char const*, int, std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char>>) in TestDriver
     1 Ice::SyscallException::SyscallException(char const*, int, std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char>>, int, std::__1::function<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char>> (int)> const&) in TestDriver
     2 Ice::SocketException::SocketException(char const*, int, std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char>>, int, std::__1::function<std::__1::basic_string<char, std::__1::char_traits<char>, std::__1::allocator<char>> (int)> const&) in TestDriver
     3 Ice::ConnectionLostException::ConnectionLostException(char const*, int, int) in TestDriver
     4 Ice::ConnectionLostException::ConnectionLostException(char const*, int, int) in TestDriver
     5 IceInternal::StreamSocket::read(char*, unsigned long) in TestDriver
     6 IceInternal::StreamSocket::read(IceInternal::Buffer&) in TestDriver
     7 IceInternal::TcpTransceiver::read(IceInternal::Buffer&) in TestDriver
     8 IceInternal::WSTransceiver::read(IceInternal::Buffer&) in TestDriver
     9 IceInternal::IdleTimeoutTransceiverDecorator::read(IceInternal::Buffer&) in TestDriver
    10 Ice::ConnectionI::read(IceInternal::Buffer&) in TestDriver
    11 Ice::ConnectionI::message(IceInternal::ThreadPoolCurrent&) in TestDriver
    12 IceInternal::ThreadPool::run(std::__1::shared_ptr<IceInternal::ThreadPool::EventHandlerThread> const&) in TestDriver
    13 IceInternal::ThreadPool::EventHandlerThread::run() in TestDriver
    14 decltype(*std::declval<IceInternal::ThreadPool::EventHandlerThread*>().*std::declval<void (IceInternal::ThreadPool::EventHandlerThread::*)()>()()) std::__1::__invoke[abi:ne190102]<void (IceInternal::ThreadPool::EventHandlerThread::*)(), IceInternal::ThreadPool::EventHandlerThread*, void>(void (IceInternal::ThreadPool::EventHandlerThread::*&&)(), IceInternal::ThreadPool::EventHandlerThread*&&) in TestDriver
    15 void std::__1::__thread_execute[abi:ne190102]<std::__1::unique_ptr<std::__1::__thread_struct, std::__1::default_delete<std::__1::__thread_struct>>, void (IceInternal::ThreadPool::EventHandlerThread::*)(), IceInternal::ThreadPool::EventHandlerThread*, 2ul>(std::__1::tuple<std::__1::unique_ptr<std::__1::__thread_struct, std::__1::default_delete<std::__1::__thread_struct>>, void (IceInternal::ThreadPool::EventHandlerThread::*)(), IceInternal::ThreadPool::EventHandlerThread*>&, std::__1::__tuple_indices<2ul>) in TestDriver
    16 void* std::__1::__thread_proxy[abi:ne190102]<std::__1::tuple<std::__1::unique_ptr<std::__1::__thread_struct, std::__1::default_delete<std::__1::__thread_struct>>, void (IceInternal::ThreadPool::EventHandlerThread::*)(), IceInternal::ThreadPool::EventHandlerThread*>>(void*) in TestDriver
    17 _pthread_start in libsystem_pthread.dylib
    18 thread_start in libsystem_pthread.dylib
   
   local address = ::1:50398
   remote address = ::1:14100
0   TestDriver                          0x0000000102d7144c async_MainTY2_ + 164
1   TestDriver                          0x0000000102d717e1 $sIetH_yts5Error_pIegHrzo_TRTQ0_ + 1
2   TestDriver                          0x0000000102d71909 $sIetH_yts5Error_pIegHrzo_TRTATQ0_ + 1
3   libswift_Concurrency.dylib          0x00000002721e883d _ZL23completeTaskWithClosurePN5swift12AsyncContextEPNS_10SwiftErrorE + 1
Error src/Ice/StreamSocket.cpp:213 Ice::ConnectionLostException connection lost: recv() returned zero

test in Ice/hold failed:

bernardnormier avatar Jun 24 '25 18:06 bernardnormier

The attached crash log shows this:

Thread 16 Crashed:
0   TestDriver                    	       0x10052f628 std::__1::__hash_table<std::__1::__hash_value_type<void*, ICELocalObject* __weak>, std::__1::__unordered_map_hasher<void*, std::__1::__hash_value_type<void*, ICELocalObject* __weak>, std::__1::hash<void*>, std::__1::equal_to<void*>, true>, std::__1::__unordered_map_equal<void*, std::__1::__hash_value_type<void*, ICELocalObject* __weak>, std::__1::equal_to<void*>, std::__1::hash<void*>, true>, std::__1::allocator<std::__1::__hash_value_type<void*, ICELocalObject* __weak>>>::remove(std::__1::__hash_const_iterator<std::__1::__hash_node<std::__1::__hash_value_type<void*, ICELocalObject* __weak>, void*>*>) + 104 (__hash_table:1883)
1   TestDriver                    	       0x10052f554 std::__1::__hash_table<std::__1::__hash_value_type<void*, ICELocalObject* __weak>, std::__1::__unordered_map_hasher<void*, std::__1::__hash_value_type<void*, ICELocalObject* __weak>, std::__1::hash<void*>, std::__1::equal_to<void*>, true>, std::__1::__unordered_map_equal<void*, std::__1::__hash_value_type<void*, ICELocalObject* __weak>, std::__1::equal_to<void*>, std::__1::hash<void*>, true>, std::__1::allocator<std::__1::__hash_value_type<void*, ICELocalObject* __weak>>>::erase(std::__1::__hash_const_iterator<std::__1::__hash_node<std::__1::__hash_value_type<void*, ICELocalObject* __weak>, void*>*>) + 88 (__hash_table:1832)
2   TestDriver                    	       0x10052b89c std::__1::unordered_map<void*, ICELocalObject* __weak, std::__1::hash<void*>, std::__1::equal_to<void*>, std::__1::allocator<std::__1::pair<void* const, ICELocalObject* __weak>>>::erase[abi:ne190102](std::__1::__hash_map_iterator<std::__1::__hash_iterator<std::__1::__hash_node<std::__1::__hash_value_type<void*, ICELocalObject* __weak>, void*>*>>) + 56 (unordered_map:1323)
3   TestDriver                    	       0x10052bb6c -[ICELocalObject dealloc] + 636 (LocalObject.mm:80)
4   TestDriver                    	       0x1003bc168 LocalObject.deinit + 56
5   TestDriver                    	       0x10037f404 ConnectionI.deinit + 28
6   TestDriver                    	       0x10037f42c ConnectionI.__deallocating_deinit + 28
7   libswiftCore.dylib            	       0x19af137b4 _swift_release_dealloc + 56
8   libswiftCore.dylib            	       0x19af1468c bool swift::RefCounts<swift::RefCountBitsT<(swift::RefCountInlinedness)1>>::doDecrementSlow<(swift::PerformDeinit)1>(swift::RefCountBitsT<(swift::RefCountInlinedness)1>, unsigned int) + 152
9   TestDriver                    	       0x1003e6590 0x10033c000 + 697744
10  libswiftCore.dylib            	       0x19af137b4 _swift_release_dealloc + 56
11  libswiftCore.dylib            	       0x19af1468c bool swift::RefCounts<swift::RefCountBitsT<(swift::RefCountInlinedness)1>>::doDecrementSlow<(swift::PerformDeinit)1>(swift::RefCountBitsT<(swift::RefCountInlinedness)1>, unsigned int) + 152
12  TestDriver                    	       0x10036ff9c 0x10033c000 + 212892
13  libswiftCore.dylib            	       0x19af137b4 _swift_release_dealloc + 56
14  libswiftCore.dylib            	       0x19af1468c bool swift::RefCounts<swift::RefCountBitsT<(swift::RefCountInlinedness)1>>::doDecrementSlow<(swift::PerformDeinit)1>(swift::RefCountBitsT<(swift::RefCountInlinedness)1>, unsigned int) + 152
15  libswift_Concurrency.dylib    	       0x2721e886c completeTaskWithClosure(swift::AsyncContext*, swift::SwiftError*) + 48
16  libswift_Concurrency.dylib    	       0x2721e883d completeTaskWithClosure(swift::AsyncContext*, swift::SwiftError*) + 1

pepone avatar Aug 12 '25 15:08 pepone

Seems like a duplicate of https://github.com/zeroc-ice/ice/issues/3229

pepone avatar Aug 13 '25 07:08 pepone

https://github.com/zeroc-ice/ice/blob/614281c5621d7b43cf882b1e3f6110853e488592/swift/src/IceImpl/LocalObject.mm#L8-L9

I don't understand this comment, if the map only holds weak references why would it trigger object destruction?

pepone avatar Nov 05 '25 11:11 pepone

ice/swift/src/IceImpl/LocalObject.mm

Lines 8 to 9 in 614281c

// We "leak" this map to avoid the destructor being called when the application is terminated. auto* cachedObjects = new std::unordered_map<void*, __weak ICELocalObject*>(); I don't understand this comment, if the map only holds weak references why would it trigger object destruction?

The issue is ordering. When the application terminates it's possible that this map is deleted before some ICELocalObjects. When one of their destructors runs they'll try to access the map, which causes a crash.

Overall I think we should consider getting rid of this setup entirely and not worry about returning the same Swift object every time.

externl avatar Nov 05 '25 14:11 externl

it's possible that this map is deleted

The map is never deleted - it's leaked on purpose. As a result, I don't see the potential ordering issue.

bernardnormier avatar Dec 03 '25 23:12 bernardnormier

Moved to 3.8.1, we should consider update the code as @externl suggested above in https://github.com/zeroc-ice/ice/issues/4143#issuecomment-3491461443

pepone avatar Dec 11 '25 21:12 pepone

For many objects like Communicator and Connection, it's critical to return the same Swift wrapper all the time.

bernardnormier avatar Dec 11 '25 22:12 bernardnormier