openthread / openthread

OpenThread released by Google is an open-source implementation of the Thread networking protocol
https://openthread.io
BSD 3-Clause "New" or "Revised" License
3.47k stars 1.07k forks source link

Assert in Thread::Mle::MleRouter::HandleChildIdRequest #1280

Closed nibanks closed 7 years ago

nibanks commented 7 years ago

I just hit the following in my testing on Windows:

00 ffffc681`efc8aa30 fffff808`64989823 nt!RtlAssert+0xeb [minkernel\ntos\rtl\assert.c @ 132]
01 ffffc681`efc8af90 fffff808`649800f8 otlwf!Thread::Mle::MleRouter::HandleChildIdRequest+0x963 [c:\users\nibanks\source\repos\openthread-win\src\core\thread\mle_router.cpp @ 2215]
02 ffffc681`efc8b0e0 fffff808`64980297 otlwf!Thread::Mle::Mle::HandleUdpReceive+0xb08 [c:\users\nibanks\source\repos\openthread-win\src\core\thread\mle.cpp @ 2050]
03 ffffc681`efc8b370 fffff808`6497103e otlwf!Thread::Mle::Mle::HandleUdpReceive+0x27 [c:\users\nibanks\source\repos\openthread-win\src\core\thread\mle.cpp @ 1845]
04 ffffc681`efc8b3a0 fffff808`64970ffa otlwf!Thread::Ip6::UdpSocket::HandleUdpReceive+0x2e [c:\users\nibanks\source\repos\openthread-win\src\core\net\udp6.hpp @ 147]
05 ffffc681`efc8b3d0 fffff808`64972ca4 otlwf!Thread::Ip6::Udp::HandleMessage+0x33a [c:\users\nibanks\source\repos\openthread-win\src\core\net\udp6.cpp @ 248]
06 ffffc681`efc8b450 fffff808`64972547 otlwf!Thread::Ip6::Ip6::HandlePayload+0x54 [c:\users\nibanks\source\repos\openthread-win\src\core\net\ip6.cpp @ 588]
07 ffffc681`efc8b490 fffff808`649a489a otlwf!Thread::Ip6::Ip6::HandleDatagram+0x4b7 [c:\users\nibanks\source\repos\openthread-win\src\core\net\ip6.cpp @ 761]
08 ffffc681`efc8b560 fffff808`649a558a otlwf!Thread::MeshForwarder::HandleDatagram+0x6a [c:\users\nibanks\source\repos\openthread-win\src\core\thread\mesh_forwarder.cpp @ 2019]
09 ffffc681`efc8b5b0 fffff808`649a6065 otlwf!Thread::MeshForwarder::HandleLowpanHC+0x1fa [c:\users\nibanks\source\repos\openthread-win\src\core\thread\mesh_forwarder.cpp @ 2005]
0a ffffc681`efc8b620 fffff808`649a616d otlwf!Thread::MeshForwarder::HandleReceivedFrame+0x2e5 [c:\users\nibanks\source\repos\openthread-win\src\core\thread\mesh_forwarder.cpp @ 1722]
0b ffffc681`efc8b6c0 fffff808`64966063 otlwf!Thread::MeshForwarder::HandleReceivedFrame+0x1d [c:\users\nibanks\source\repos\openthread-win\src\core\thread\mesh_forwarder.cpp @ 1658]
0c ffffc681`efc8b6f0 fffff808`649676ab otlwf!Thread::Mac::Receiver::HandleReceivedFrame+0x23 [c:\users\nibanks\source\repos\openthread-win\src\core\mac\mac.hpp @ 119]
0d ffffc681`efc8b720 fffff808`6496967a otlwf!Thread::Mac::Mac::ReceiveDoneTask+0x92b [c:\users\nibanks\source\repos\openthread-win\src\core\mac\mac.cpp @ 1398]
0e ffffc681`efc8b7f0 fffff808`6495db2a otlwf!otPlatRadioReceiveDone+0xca [c:\users\nibanks\source\repos\openthread-win\src\core\mac\mac.cpp @ 1216]
0f ffffc681`efc8b830 fffff808`6494b920 otlwf!otLwfRadioReceiveFrame+0x14a [c:\users\nibanks\source\repos\openthread-win\examples\drivers\windows\otlwf\radio.c @ 472]
10 ffffc681`efc8b880 fffff801`6856b528 otlwf!otLwfEventWorkerThread+0x1010 [c:\users\nibanks\source\repos\openthread-win\examples\drivers\windows\otlwf\eventprocessing.c @ 1021]
11 ffffc681`efc8bc10 fffff801`685fec86 nt!PspSystemThreadStartup+0x48 [minkernel\ntos\ps\psexec.c @ 7675]
12 ffffc681`efc8bc60 00000000`00000000 nt!KxStartSystemThread+0x16 [d:\rs2\minkernel\ntos\ke\amd64\threadbg.asm @ 81]

The assert is here:

    switch (GetDeviceState())
    {
    case kDeviceStateDisabled:
    case kDeviceStateDetached:
        assert(false);              <============== HERE
        break;

My guess is that there may be an issue with detaching and still having pending packets to indicate to OpenThread. Here is a dump of the various objects on the stack:

class Thread::Mle::MleRouter * 0xffffe786`bc3494d8
   +0x000 mNetif           : 0xffffe786`bc348248 Thread::ThreadNetif
   +0x008 mLeaderData      : Thread::Mle::LeaderDataTlv
   +0x012 mRetrieveNewNetworkData : 
   +0x014 mDeviceState     :  ( kDeviceStateDetached )
   +0x018 mParent          : Thread::Router
   +0x044 mDeviceMode      : 0xf ''
   +0x045 isAssignLinkQuality : 
   +0x046 mAssignLinkQuality : 0 ''
   +0x047 mAssignLinkMargin : 0 ''
   +0x048 mAddr64          : Thread::Mac::ExtAddress
   +0x050 mParentRequestState :  ( kParentRequestRouter )
   +0x054 mReattachState   :  ( kReattachStop )
   +0x058 mParentRequestTimer : Thread::Timer
   +0x080 mRouterSelectionJitter : 0x1 ''
   +0x081 mRouterSelectionJitterTimeout : 0 ''
   +0x082 mLastPartitionRouterIdSequence : 0x59 'Y'
   +0x084 mLastPartitionId : 0x29f9af35
   +0x088 mChildIdRequest  : Thread::Mle::Mle::<unnamed-type-mChildIdRequest>
   +0x091 mParentRequest   : Thread::Mle::Mle::<unnamed-type-mParentRequest>
   +0x09c mParentRequestMode :  ( kMleAttachAnyPartition )
   +0x0a0 mParentLinkQuality : 0x3 ''
   +0x0a1 mParentPriority  : 0 ''
   +0x0a2 mParentLinkQuality3 : 0x1 ''
   +0x0a3 mParentLinkQuality2 : 0 ''
   +0x0a4 mParentLinkQuality1 : 0 ''
   +0x0a5 mParentLeaderData : Thread::Mle::LeaderDataTlv
   +0x0af mParentIsSingleton : 
   +0x0b0 mParentCandidate : Thread::Router
   +0x0e0 mSocket          : Thread::Ip6::UdpSocket
   +0x128 mTimeout         : 0x64
   +0x130 mSendChildUpdateRequest : Thread::Tasklet
   +0x150 mDiscoverHandler : (null) 
   +0x158 mDiscoverContext : (null) 
   +0x160 mIsDiscoverInProgress : 
   +0x161 mAnnounceChannel : 0xb ''
   +0x162 mPreviousChannel : 0 ''
   +0x164 mPreviousPanId   : 0xffff
   +0x168 mLeaderAloc      : Thread::Ip6::NetifUnicastAddress
   +0x190 mLinkLocal64     : Thread::Ip6::NetifUnicastAddress
   +0x1b8 mMeshLocal64     : Thread::Ip6::NetifUnicastAddress
   +0x1e0 mMeshLocal16     : Thread::Ip6::NetifUnicastAddress
   +0x208 mLinkLocalAllThreadNodes : Thread::Ip6::NetifMulticastAddress
   +0x220 mRealmLocalAllThreadNodes : Thread::Ip6::NetifMulticastAddress
   +0x238 mNetifCallback   : Thread::Ip6::NetifCallback
   +0x250 mDelayedResponses : Thread::MessageQueue
   +0x258 mAdvertiseTimer  : Thread::TrickleTimer
   +0x2b0 mStateUpdateTimer : Thread::Timer
   +0x2d8 mDelayedResponseTimer : Thread::Timer
   +0x300 mChildUpdateRequestTimer : Thread::Timer
   +0x328 mAddressSolicit  : Thread::Coap::Resource
   +0x348 mAddressRelease  : Thread::Coap::Resource
   +0x368 mRouterIdSequence : 0x59 'Y'
   +0x36c mRouterIdSequenceLastUpdated : 0x134810
   +0x370 mRouters         : [63] Thread::Router
   +0xe44 mMaxChildrenAllowed : 0x20 ' '
   +0xe48 mChildren        : [32] Thread::Child
   +0x21c8 mChallengeTimeout : 0 ''
   +0x21c9 mChallenge       : [8]  "???"
   +0x21d2 mNextChildId     : 1
   +0x21d4 mNetworkIdTimeout : 0x78 'x'
   +0x21d5 mRouterUpgradeThreshold : 0x10 ''
   +0x21d6 mRouterDowngradeThreshold : 0x17 ''
   +0x21d7 mLeaderWeight    : 0x40 '@'
   +0x21d8 mFixedLeaderPartitionId : 0
   +0x21dc mRouterRoleEnabled : 
   +0x21dd mRouterId        : 0x30 '0'
   +0x21de mPreviousRouterId : 0x30 '0'
   +0x21e0 mPreviousPartitionId : 0x29f9af35
class Thread::Mac::Mac * 0xffffe786`bc348f60
   +0x000 mMacTimer        : Thread::Timer
   +0x028 mBackoffTimer    : Thread::Timer
   +0x050 mReceiveTimer    : Thread::Timer
   +0x078 mNetif           : 0xffffe786`bc348248 Thread::ThreadNetif
   +0x080 mExtAddress      : Thread::Mac::ExtAddress
   +0x088 mShortAddress    : 0xfffe
   +0x08a mPanId           : 0xface
   +0x08c mChannel         : 0xb ''
   +0x08d mMaxTransmitPower : 0 ''
   +0x08e mNetworkName     : otNetworkName
   +0x09f mExtendedPanId   : otExtendedPanId
   +0x0a8 mSendHead        : (null) 
   +0x0b0 mSendTail        : (null) 
   +0x0b8 mReceiveHead     : 0xffffe786`bc349380 Thread::Mac::Receiver
   +0x0c0 mReceiveTail     : 0xffffe786`bc349380 Thread::Mac::Receiver
   +0x0c8 mState           : 0 ''
   +0x0c9 mBeaconSequence  : 0x2d '-'
   +0x0ca mDataSequence    : 0xef ''
   +0x0cb mRxOnWhenIdle    : 
   +0x0cc mCsmaAttempts    : 0 ''
   +0x0cd mTransmitAttempts : 0 ''
   +0x0ce mTransmitBeacon  : 
   +0x0d0 mPendingScanRequest :  ( kScanTypeNone )
   +0x0d4 mScanChannel     : 0xb ''
   +0x0d8 mScanChannels    : 0xff
   +0x0dc mScanDuration    : 0
   +0x0e0 mScanContext     : (null) 
   +0x0e8 mActiveScanHandler : (null) 
   +0x0e8 mEnergyScanHandler : (null) 
   +0x0f0 mEnergyScanCurrentMaxRssi : 127 ''
   +0x0f8 mEnergyScanSampleRssiTask : Thread::Tasklet
   +0x118 mNoiseFloor      : Thread::LinkQualityInfo
   +0x120 mPcapCallback    : (null) 
   +0x128 mPcapCallbackContext : (null) 
   +0x130 mWhitelist       : Thread::Mac::Whitelist
   +0x271 mBlacklist       : Thread::Mac::Blacklist
   +0x398 mTxFrame         : 0xffff9a05`99994e28 Thread::Mac::Frame
   +0x3a0 mCounters        : otMacCounters
   +0x41c mKeyIdMode2FrameCounter : 0
struct _MS_FILTER * 0xffff9a05`99994870
   +0x000 FilterModuleLink : _LIST_ENTRY [ 0xffff9a05`96ce2870 - 0xffff9a05`98c3c870 ]
   +0x010 FilterHandle     : 0xffff9a05`99ca2c60 Void
   +0x018 State            :  ( FilterRunning )
   +0x020 AddressChangeHandle : 0xffffe786`bac1f9b0 Void
   +0x028 InterfaceGuid    : _GUID {4c7d2d41-5df1-4788-a8c8-2fe402f1aa1a}
   +0x038 InterfaceIndex   : 0x44e
   +0x040 InterfaceLuid    : _NET_LUID_LH
   +0x048 InterfaceCompartmentID : 0xec (No matching name)
   +0x050 InterfaceFriendlyName : _UNICODE_STRING "Microsoft Virtual Thread Adapter #235"
   +0x060 InterfaceRegKey  : 0xffffffff`80002b58 Void
   +0x068 MiniportLinkState : _NDIS_LINK_STATE
   +0x090 ExternalRefs     : _EX_RUNDOWN_REF
   +0x098 cmdRundown       : _EX_RUNDOWN_REF
   +0x0a0 cmdLock          : _NDIS_SPIN_LOCK
   +0x0b0 cmdHandlers      : _LIST_ENTRY [ 0xffff9a05`99994920 - 0xffff9a05`99994920 ]
   +0x0c0 cmdTIDsInUse     : 0
   +0x0c2 cmdNextTID       : 0xa ''
   +0x0c8 cmdNblPool       : 0xffff9a05`9ad6ca80 Void
   +0x0d0 cmdInitTryCount  : 1
   +0x0d4 DeviceCapabilities : 0xb (No matching name)
   +0x0d8 DeviceStatus     :  ( OTLWF_DEVICE_STATUS_RADIO_MODE )
   +0x0dc otCachedAddr     : [16] in6_addr
   +0x1dc otCachedAddrCount : 4
   +0x1e0 otLinkLocalAddr  : in6_addr
   +0x1f0 otAutoAddresses  : [4] otNetifAddress
   +0x290 otDhcpAddresses  : [4] otDhcpAddress
   +0x350 EventWorkerThread : 0xffffe786`b1402040 Void
   +0x358 EventWorkerThreadStopEvent : _KEVENT
   +0x370 EventWorkerThreadProcessAddressChanges : _KEVENT
   +0x388 EventWorkerThreadProcessNBLs : _KEVENT
   +0x3a0 EventWorkerThreadProcessMacFrames : _KEVENT
   +0x3b8 EventsLock       : _NDIS_SPIN_LOCK
   +0x3c8 AddressChangesHead : _LIST_ENTRY [ 0xffff9a05`99994c38 - 0xffff9a05`99994c38 ]
   +0x3d8 NBLsHead         : _LIST_ENTRY [ 0xffff9a05`99994c48 - 0xffff9a05`99994c48 ]
   +0x3e8 MacFramesHead    : _LIST_ENTRY [ 0xffff9a05`99994c58 - 0xffff9a05`99994c58 ]
   +0x3f8 NextAlarmTickCount : _LARGE_INTEGER 0x11401
   +0x400 EventWorkerThreadWaitTimeUpdated : _KEVENT
   +0x418 EventWorkerThreadProcessTasklets : _KEVENT
   +0x430 EventHighPrecisionTimer : 0xffffe786`bc422a40 _EX_TIMER
   +0x438 EventTimerState  : 0 ''
   +0x440 EventIrpListHead : _LIST_ENTRY [ 0xffff9a05`99994cb0 - 0xffff9a05`99994cb0 ]
   +0x450 EventWorkerThreadProcessIrp : _KEVENT
   +0x468 EventWorkerThreadEnergyScanComplete : _KEVENT
   +0x480 otCachedRole     :  ( kDeviceRoleDetached )
   +0x484 SendPending      : 0 ''
   +0x488 SendNetBufferListComplete : _KEVENT
   +0x4a0 otRadioCapabilities : 3 (No matching name)
   +0x4a4 otPhyState       :  ( kStateReceive )
   +0x4a8 otCurrentListenChannel : 0xb ''
   +0x4a9 otReceiveMessage : [127]  "a???"
   +0x528 otTransmitMessage : [127]  "A???"
   +0x5a8 otReceiveFrame   : RadioPacket
   +0x5b8 otTransmitFrame  : RadioPacket
   +0x5c8 otLastTransmitError :  ( kThreadError_None )
   +0x5cc otLastTransmitFramePending : 0 ''
   +0x5cd otLastEnergyScanMaxRssi : 0 ''
   +0x5ce otPromiscuous    : 0 ''
   +0x5d0 otPanID          : 0xface
   +0x5d8 otFactoryAddress : 0x0a113f59`4ef01e3c
   +0x5e0 otExtendedAddress : 0xeee6c14c`6eb81267
   +0x5e8 otShortAddress   : 0xfffe
   +0x5ea otPendingMacOffloadEnabled : 0x1 ''
   +0x5eb otPendingShortAddressCount : 0 ''
   +0x5ec otPendingShortAddresses : [32] 0xc001
   +0x62c otPendingExtendedAddressCount : 0 ''
   +0x630 otPendingExtendedAddresses : [32] 0x4292265e`673c0ebc
   +0x730 otCtx            : 0xffffe786`bc308008 otInstance
   +0x738 otInstanceBuffer : 0xffffe786`bc308000  "pH???"
   +0x350 TunWorkerThread  : 0xffffe786`b1402040 Void
   +0x358 TunWorkerThreadStopEvent : _KEVENT
   +0x370 TunWorkerThreadAddressChangedEvent : _KEVENT
abtink commented 7 years ago

Thanks for reporting this. I wonder if we may be keeping the child table when we detach... Otherwise this should have caused an early exit: VerifyOrExit((child = FindChild(macAddr)) != NULL, ;);

jwhui commented 7 years ago

Thanks for reporting this issue! Will propose a fix soon.