Skip to content

Bug: SIGSEGV in ProxyStub::UnknownStub::Handle when deactivating RDK services caused by a race condition between Release RPC message and Administrator::DeleteChannel #6436

@npoltorapavlo

Description

@npoltorapavlo

Problem/Opportunity

SIGSEGV in "ProxyStub::UnknownStub::Handle" at IUnknown.cpp:70 ("implementation->Release()"). Seg fault address isn't mapped:

Program terminated with signal SIGSEGV, Segmentation fault.
#0  0xaa600a30 in ?? ()
[Current thread is 1 (LWP 10977)]
warning: File "/home/npoltorapavlo/Downloads/gdb/usr/lib/libstdc++.so.6.0.29-gdb.py" auto-loading has been declined by your `auto-load safe-path' set to "$debugdir:$datadir/auto-load".
(gdb) bt
#0  0xaa600a30 in ?? ()
#1  0xb3e2e05c in WPEFramework::ProxyStub::UnknownStub::Handle (this=0x156c630, index=<optimized out>, channel=..., message=...)
    at /usr/src/debug/wpeframework/4.4-r0/git/Source/com/IUnknown.cpp:70
#2  0x00063cf2 in WPEFramework::RPC::Job::Invoke (channel=..., data=...) at /usr/src/debug/wpeframework/4.4-r0/git/Source/core/../com/Administrator.h:379
#3  0x00065c08 in WPEFramework::Core::ThreadPool::Minion::Process (this=this@entry=0x1568dd8)
    at /usr/src/debug/wpeframework/4.4-r0/git/Source/core/../core/ThreadPool.h:452
#4  0x00065d66 in WPEFramework::Core::ThreadPool::Executor::Worker (this=0x1568ce8) at /usr/src/debug/wpeframework/4.4-r0/git/Source/core/../core/ThreadPool.h:540
#5  0xb3d8937c in WPEFramework::Core::Thread::StartThread (cClassPointer=0x1568ce8) at /usr/src/debug/wpeframework/4.4-r0/git/Source/core/Thread.cpp:194
#6  0xb3b3cc86 in start_thread (arg=0xa3d51c28) at pthread_create.c:442
#7  0xb3b8d3c0 in ?? () at ../sysdeps/unix/sysv/linux/arm/clone.S:74 from /home/npoltorapavlo/Downloads/gdb/lib/libc.so.6

ProxyStub relates to IDeviceOptimizeStateActivator:

(gdb) f 1
Downloading source file /usr/src/debug/wpeframework/4.4-r0/git/Source/com/IUnknown.cpp
#1  0xb3e2e05c in WPEFramework::ProxyStub::UnknownStub::Handle (this=0x156c630, index=<optimized out>, channel=..., message=...)                                      
    at /usr/src/debug/wpeframework/4.4-r0/git/Source/com/IUnknown.cpp:70
warning: 70    /usr/src/debug/wpeframework/4.4-r0/git/Source/com/IUnknown.cpp: No such file or directory
(gdb) p *this
$1 = {
  _vptr.UnknownStub = 0xac8cc5a4 <vtable for WPEFramework::ProxyStub::UnknownStubType<WPEFramework::Exchange::IDeviceOptimizeStateActivator, &WPEFramework::ProxyStubs::ExchangeDeviceOptimizeStateActivatorStubMethods>+8>}

Log prints "Unregistering an interface 0x1050 from a non-existing channel!!!". This message means when in Release RPC message, channel isn't in RPC::Administrator's _channelReferenceMap. Apparently, Administrator::DeleteChannel removed it from _channelReferenceMap (and released the interface):

2025-11-14T16:09:36.136Z WPEFramework[10811]:  ====> Unregistering an interface [0x1050, 10811] from a non-existing channel!!!
2025-11-14T16:09:36.136Z /usr/bin/WPEFramework[10811]:  Signal received 11. in process [10811]

interface id 0x1050 corresponds to IDeviceOptimizeStateActivator (0x1010 + ID_EXTERNAL_INTERFACE_OFFSET, 0x0040):

../meta-rdk-comcast-video/recipes-extended/wpe-framework/files/r4.4/0002-Ids_comcast_interfaces.patch:+        ID_DEVICE_OPTIMIZE_STATE_ACTIVATOR           = RPC::IDS::ID_EXTERNAL_INTERFACE_OFFSET + 0x1010,

Channel in RPC::Job::Invoke arg is closed:

(gdb) p *(WPEFramework::Core::IPCChannelClientType<WPEFramework::RPC::Communicator::ChannelLink, false, false> *)channel._realObject
m_hostName = {... "/tmp/communicator"
m_Socket = -1,
m_State = {... _M_i = 0

Log analysis. Provider of the IDeviceOptimizeStateActivator interface (DisplaySettings service) and consumer (SystemMode service) deactivated in parallel. Both services are in-process. ClientDeactivated routine timed out (20s). JSONRPC::LinkType::Unsubscribe timed out (1s x10):

2025-11-14T15:47:55.800Z WPEFramework[10811]:  [10977] INFO [DisplaySettings.cpp:590] Deinitialize: Enetering DisplaySettings::Deinitialize
2025-11-14T15:48:15.803Z WPEFramework[10811]:  [10977] INFO [UtilsString.h:282] updateSystemModeFile: Updated file /tmp/SystemMode.txt successfully.
2025-11-14T15:48:15.803Z WPEFramework[10811]:  [12171] INFO [DisplaySettings.cpp:4859] sendMsgThread:  sendCecMessageThread Exiting
2025-11-14T15:48:15.804Z WPEFramework[10811]:  [10977] INFO [DisplaySettings.cpp:5480] stopCecTimeAndUnsubscribeEvent: de-init cec timer and subscribbed event
2025-11-14T15:48:16.805Z WPEFramework[10811]:  [10977] INFO [DisplaySettings.cpp:5503] stopCecTimeAndUnsubscribeEvent: Unsubscribing event arcInitiationEvent
2025-11-14T15:48:17.808Z WPEFramework[10811]:  [10977] INFO [DisplaySettings.cpp:5503] stopCecTimeAndUnsubscribeEvent: Unsubscribing event arcTerminationEvent
2025-11-14T15:48:18.805Z WPEFramework[10811]:  [10977] INFO [DisplaySettings.cpp:5503] stopCecTimeAndUnsubscribeEvent: Unsubscribing event shortAudiodesciptorEvent
2025-11-14T15:48:19.807Z WPEFramework[10811]:  [10977] INFO [DisplaySettings.cpp:5503] stopCecTimeAndUnsubscribeEvent: Unsubscribing event setSystemAudioModeEvent
2025-11-14T15:48:20.808Z WPEFramework[10811]:  [10977] INFO [DisplaySettings.cpp:5503] stopCecTimeAndUnsubscribeEvent: Unsubscribing event reportAudioDeviceConnectedStatus
2025-11-14T15:48:21.807Z WPEFramework[10811]:  [10977] INFO [DisplaySettings.cpp:5503] stopCecTimeAndUnsubscribeEvent: Unsubscribing event reportCecEnabledEvent
2025-11-14T15:48:22.808Z WPEFramework[10811]:  [10977] INFO [DisplaySettings.cpp:5503] stopCecTimeAndUnsubscribeEvent: Unsubscribing event reportAudioDevicePowerStatus
2025-11-14T15:48:23.808Z WPEFramework[10811]:  [10977] INFO [DisplaySettings.cpp:5503] stopCecTimeAndUnsubscribeEvent: Unsubscribing event reportAudioStatusEvent
2025-11-14T15:48:23.808Z WPEFramework[10811]:  [10977] INFO [DisplaySettings.cpp:5507] stopCecTimeAndUnsubscribeEvent: deleting m_client
2025-11-14T15:48:23.811Z WPEFramework[10811]:  [10977] INFO [DisplaySettings.cpp:732] DeinitializeIARM: device::Manager::DeInitialize success
2025-11-14T15:48:23.813Z WPEFramework[10811]:  [SysLog]:[Shutdown]: Deactivated plugin [DisplaySettings]:[org.rdk.DisplaySettings]
2025-11-14T15:48:35.820Z WPEFramework[10811]:  [SysLog]:[Shutdown]: SystemMode::Deinitialize
2025-11-14T15:48:35.821Z WPEFramework[10811]:  [10982] INFO [SystemModeImplementation.cpp:137] ~SystemModeImplementation: Disconnect from the COM-RPC socket
2025-11-14T15:48:55.210Z WPEFramework[10811]:  [SysLog]:[Shutdown]: SystemMode de-initialised
2025-11-14T15:48:55.210Z WPEFramework[10811]:  [SysLog]:[Shutdown]: Deactivated plugin [SystemMode]:[org.rdk.SystemMode]
2025-11-14T15:48:55.223Z WPEFramework[10811]:  [10977] INFO [DisplaySettings.cpp:371] ~DisplaySettings: dtor
2025-11-14T16:09:36.136Z WPEFramework[10811]:  ====> Unregistering an interface [0x1050, 10811] from a non-existing channel!!!
2025-11-14T16:09:36.136Z /usr/bin/WPEFramework[10811]:  Signal received 11. in process [10811]
2025-11-14T16:09:36.155Z WPEFramework[10811]:  [SysLog]:[Shutdown]: SystemMode Destructor

Another log example:

2025-11-20T14:59:47.558Z WPEFramework[11501]:  [11501] INFO [DisplaySettings.cpp:590] Deinitialize: Enetering DisplaySettings::Deinitialize
2025-11-20T15:00:07.560Z WPEFramework[11501]:  [11501] INFO [UtilsString.h:282] updateSystemModeFile: Updated file /tmp/SystemMode.txt successfully.
2025-11-20T15:00:07.560Z WPEFramework[11501]:  [12884] INFO [DisplaySettings.cpp:4859] sendMsgThread:  sendCecMessageThread Exiting
2025-11-20T15:00:07.560Z WPEFramework[11501]:  [11501] INFO [DisplaySettings.cpp:5480] stopCecTimeAndUnsubscribeEvent: de-init cec timer and subscribbed event
2025-11-20T15:00:08.561Z WPEFramework[11501]:  [11501] INFO [DisplaySettings.cpp:5503] stopCecTimeAndUnsubscribeEvent: Unsubscribing event arcInitiationEvent
2025-11-20T15:00:09.561Z WPEFramework[11501]:  [11501] INFO [DisplaySettings.cpp:5503] stopCecTimeAndUnsubscribeEvent: Unsubscribing event arcTerminationEvent
2025-11-20T15:00:10.560Z WPEFramework[11501]:  [11501] INFO [DisplaySettings.cpp:5503] stopCecTimeAndUnsubscribeEvent: Unsubscribing event shortAudiodesciptorEvent
2025-11-20T15:00:11.561Z WPEFramework[11501]:  [11501] INFO [DisplaySettings.cpp:5503] stopCecTimeAndUnsubscribeEvent: Unsubscribing event setSystemAudioModeEvent
2025-11-20T15:00:12.563Z WPEFramework[11501]:  [11501] INFO [DisplaySettings.cpp:5503] stopCecTimeAndUnsubscribeEvent: Unsubscribing event reportAudioDeviceConnectedStatus
2025-11-20T15:00:13.564Z WPEFramework[11501]:  [11501] INFO [DisplaySettings.cpp:5503] stopCecTimeAndUnsubscribeEvent: Unsubscribing event reportCecEnabledEvent
2025-11-20T15:00:14.564Z WPEFramework[11501]:  [11501] INFO [DisplaySettings.cpp:5503] stopCecTimeAndUnsubscribeEvent: Unsubscribing event reportAudioDevicePowerStatus
2025-11-20T15:00:15.563Z WPEFramework[11501]:  [11501] INFO [DisplaySettings.cpp:5503] stopCecTimeAndUnsubscribeEvent: Unsubscribing event reportAudioStatusEvent
2025-11-20T15:00:15.563Z WPEFramework[11501]:  [11501] INFO [DisplaySettings.cpp:5507] stopCecTimeAndUnsubscribeEvent: deleting m_client
2025-11-20T15:00:15.568Z WPEFramework[11501]:  [11501] INFO [DisplaySettings.cpp:732] DeinitializeIARM: device::Manager::DeInitialize success
2025-11-20T15:00:15.570Z WPEFramework[11501]:  [SysLog]:[Shutdown]: Deactivated plugin [DisplaySettings]:[org.rdk.DisplaySettings]
2025-11-20T15:00:27.746Z WPEFramework[11501]:  [SysLog]:[Shutdown]: SystemMode::Deinitialize
2025-11-20T15:00:27.746Z WPEFramework[11501]:  [11585] INFO [SystemModeImplementation.cpp:137] ~SystemModeImplementation: Disconnect from the COM-RPC socket
2025-11-20T15:00:27.862Z WPEFramework[11501]:  [SysLog]:[Shutdown]: SystemMode de-initialised
2025-11-20T15:00:27.862Z WPEFramework[11501]:  [SysLog]:[Shutdown]: Deactivated plugin [SystemMode]:[org.rdk.SystemMode]
2025-11-20T15:00:27.897Z WPEFramework[11501]:  [11501] INFO [DisplaySettings.cpp:371] ~DisplaySettings: dtor
2025-11-20T15:00:27.943Z WPEFramework[11501]:  [SysLog]:[Shutdown]: SystemMode Destructor
2025-11-20T15:19:16.348Z /usr/bin/WPEFramework[11501]:  Signal received 11. in process [11501]
2025-11-20T15:19:16.351Z WPEFramework[11501]:  ====> Unregistering an interface [0x1050, 11501] from a non-existing channel!!!

In code, DisplaySettings::Deinitialize queries ISystemMode (over IShell) to call ClientDeactivated. ClientDeactivated calls Release() on IDeviceOptimizeStateActivator (over RPC::CommunicatorClient). ~SystemModeImplementation() closes _communicatorClient before interface, which is incorrect order, however should not be a problem:

void DisplaySettings::Deinitialize(PluginHost::IShell* service)
{
...
    if(_remotStoreObject1 == nullptr)
    {
        _remotStoreObject1 = service->QueryInterfaceByCallsign<Exchange::ISystemMode>("org.rdk.SystemMode");
    }
...
        _remotStoreObject1->ClientDeactivated(...);
        _remotStoreObject1->Release();
uint32_t SystemModeImplementation::ClientDeactivated(const string& callsign ,const string& systemMode)
{
...
    if (index != _clients.end()) { // Remove from the list, if it is already there
        Exchange::IDeviceOptimizeStateActivator *temp = index->second;	
        temp->Release();				
        _clients.erase(index);
SystemModeImplementation::~SystemModeImplementation()
{ 
    if (_controller)
    {
        _controller->Release();
	 _controller = nullptr;
    }

    LOGINFO("Disconnect from the COM-RPC socket\n");
    // Disconnect from the COM-RPC socket
    _communicatorClient->Close(RPC::CommunicationTimeOut);
    if (_communicatorClient.IsValid())
    {
        _communicatorClient.Release();
    }

    if(_engine.IsValid())
    {
        _engine.Release();
    }

    for (auto& entry : _clients) {
	    if (entry.second) {  // Check if the pointer is not null
		    entry.second->Release();
	    }
    }

}

ThreadPool queue size by the time of crash is high (e.g 43, or 25). This means Thunder can be out-of-threads and process tasks with a delay.

Looks like what happens is, DisplaySettings::Deinitialize calls ClientDeactivated, other side receives it immediately as in-process, other side calls Release() on DisplaySettings, which times out because requires a new thread, Thunder is out-of-threads, though RPC::Job is submitted in queue. DisplaySettings::Deinitialize ends, service isn't destroyed yet because still referenced. Then SystemMode service deinitializes, ~SystemModeImplementation() closes RPC channel, this causes ResourceMonitor thread to wake up, remove channel and release DisplaySettings on behalf of the other side. At this point "~DisplaySettings: dtor" is logged. Finally RPC::Job gets a thread when implementation is already destroyed and channel is closed, hence a crash on "implementation->Release()".

Steps to reproduce

for item in "org.rdk.Bluetooth" "org.rdk.SecManager" "JSPP" "org.rdk.UsbMassStorage" \
  "org.rdk.Wifi" "org.rdk.MediaSettings" "PlayerInfo" "org.rdk.FrontPanel" \
  "org.rdk.AVInput" "DisplayInfo" "org.rdk.Privacy" "org.rdk.FirmwareUpdate" \
  "DeviceInfo" "Monitor" "org.rdk.SystemMode" "OCDM" \
  "org.rdk.SharedStorage" "org.rdk.OCIContainer" "org.rdk.RemoteControl" "org.rdk.MaintenanceManager" \
  "org.rdk.HdmiCecSource" "org.rdk.Analytics" "org.rdk.SystemAudioPlayer" "org.rdk.Xcast" \
  "org.rdk.LinchPinClient" "org.rdk.Cryptography" "org.rdk.IPControl" "org.rdk.TextTrack" \
  "org.rdk.CloudStore" "com.comcast.DeviceProvisioning" "org.rdk.UsbDevice" "org.rdk.VoiceControl" \
  "org.rdk.Telemetry" "org.rdk.AuthService" "org.rdk.System" "org.rdk.TextToSpeech" \
  "org.rdk.HdcpProfile" "org.rdk.UserSettings" "org.rdk.DisplaySettings" "org.rdk.Network"; do
  curl -X PUT http://127.0.0.1:9998/Service/Controller/Deactivate/$item &
done

Expected Behavior

No crash

Actual Behavior

Crash

Notes (Optional)

No response

Metadata

Metadata

Assignees

No one assigned

    Labels

    bugSomething isn't working

    Type

    No fields configured for Bug.

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions