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.

Sign up for GitHub

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

Jump to bottom

[crash] SubscriptionCallback::OnReportEnd() #21142

Closed
aajain-com opened this issue Jul 23, 2022 · 1 comment
Closed

[crash] SubscriptionCallback::OnReportEnd() #21142

aajain-com opened this issue Jul 23, 2022 · 1 comment
Labels
crash darwin p1 priority 1 work

Comments

@aajain-com
Copy link
Contributor

Problem

Crash seen during stability testing with SHA 5d8599d195a93dfe5473f64e4f888c322e5df1d2

Exception Type:  EXC_BAD_ACCESS (SIGSEGV)
Exception Subtype: KERN_INVALID_ADDRESS at 0x0000000000000010
Exception Codes: 0x0000000000000001, 0x0000000000000010
VM Region Info: 0x10 is not in any region.  Bytes before following region: 68719476720
      REGION TYPE                 START - END      [ VSIZE] PRT/MAX SHRMOD  REGION DETAIL
      UNUSED SPACE AT START
--->  
      commpage (reserved)     1000000000-7000000000 [384.0G] ---/--- SM=NUL  ...(unallocated)
Termination Reason: SIGNAL 11 Segmentation fault: 11
Terminating Process: exc handler [16211]

0   CHIP                          	       0x188393dac invocation function for block in (anonymous namespace)::SubscriptionCallback::OnReportEnd() + 20 (connectedhomeip/src/darwin/Framework/CHIP/CHIPDevice.mm:1409)
1   libdispatch.dylib             	       0x1d12cb7ac _dispatch_call_block_and_release + 32 (Sources/libdispatch/src/init.c:1518)
2   libdispatch.dylib             	       0x1d12cd2d0 _dispatch_client_callout + 20 (Sources/libdispatch/src/object.m:560)
3   libdispatch.dylib             	       0x1d12d49d4 _dispatch_lane_serial_drain + 672 (Sources/libdispatch/src/inline_internal.h:2631)
4   libdispatch.dylib             	       0x1d12d5554 _dispatch_lane_invoke + 436 (Sources/libdispatch/src/queue.c:3939)
5   libdispatch.dylib             	       0x1d12e00a8 _dispatch_workloop_worker_thread + 652 (Sources/libdispatch/src/queue.c:6766)
6   libsystem_pthread.dylib       	       0x1d1532fe4 _pthread_wqthread + 288 (Sources/libpthread/src/pthread.c:2618)
7   libsystem_pthread.dylib       	       0x1d153a5c8 start_wqthread + 8

2022-07-22 14:03:21.7033 -0700 default 0x17dbf1 0x0 homed[16211] (CHIP): 🟢 [1658523801634] [16211:1563633] CHIP: [EM] Removed CHIP MessageCounter:174118038 from RetransTable on exchange 15319i
2022-07-22 14:03:21.7227 -0700 default 0x17dbf1 0x0 homed[16211] (CHIP): 🔵 [1658523801653] [16211:1563633] CHIP: [DMG] Refresh LivenessCheckTime for 25000 milliseconds with SubscriptionId = 0x4e4b0c04 Peer = 01:00000000FB384A57
2022-07-22 14:03:21.7228 -0700 default 0x17dbf1 0x0 homed[16211] (CHIP): 🟢 [1658523801654] [16211:1563633] CHIP: [EM] Piggybacking Ack for MessageCounter:87523897 on exchange: 15319i
2022-07-22 14:03:21.7229 -0700 default 0x17dbf1 0x0 homed[16211] (CHIP): 🔵 [1658523801654] [16211:1563633] CHIP: [IN] Prepared secure message 0x103029e68 to 0x00000000FB384A57 (1)  of type 0x1 and protocolId (0, 1) on exchange 15319i with MessageCounter:174118039.
2022-07-22 14:03:21.7230 -0700 default 0x17dbf1 0x0 homed[16211] (CHIP): 🔵 [1658523801654] [16211:1563633] CHIP: [IN] Sending encrypted msg 0x103029e68 with MessageCounter:174118039 to 0x00000000FB384A57 (1) at monotonic time: 00000000092A2900 msec
2022-07-22 14:03:21.9020 -0700 default 0x17dd00 0x0 homed[16211] (CHIP): 🔵 [1658523801833] [16211:1563904] CHIP: [EM] Received message of type 0x5 with protocolId (0, 1) and MessageCounter:87523898 on exchange 15319i
2022-07-22 14:03:21.9020 -0700 default 0x17dd00 0x0 homed[16211] (CHIP): 🟢 [1658523801833] [16211:1563904] CHIP: [EM] Found matching exchange: 15319i, Delegate: 0x105b57ac0
2022-07-22 14:03:21.9020 -0700 default 0x17dd00 0x0 homed[16211] (CHIP): 🟢 [1658523801833] [16211:1563904] CHIP: [EM] Rxd Ack; Removing MessageCounter:174118039 from Retrans Table on exchange 15319i
2022-07-22 14:03:21.9020 -0700 default 0x17dd00 0x0 homed[16211] (CHIP): 🟢 [1658523801833] [16211:1563904] CHIP: [EM] Removed CHIP MessageCounter:174118039 from RetransTable on exchange 15319i
2022-07-22 14:03:21.9091 -0700 default 0x17dd00 0x0 homed[16211] (CHIP): 🔵 [1658523801840] [16211:1563904] CHIP: [DMG] Refresh LivenessCheckTime for 25000 milliseconds with SubscriptionId = 0x4e4b0c04 Peer = 01:00000000FB384A57
2022-07-22 14:03:21.9092 -0700 default 0x17dd00 0x0 homed[16211] (CHIP): 🟢 [1658523801840] [16211:1563904] CHIP: [EM] Piggybacking Ack for MessageCounter:87523898 on exchange: 15319i
2022-07-22 14:03:21.9092 -0700 default 0x17dd00 0x0 homed[16211] (CHIP): 🔵 [1658523801840] [16211:1563904] CHIP: [IN] Prepared secure message 0x103029e68 to 0x00000000FB384A57 (1)  of type 0x1 and protocolId (0, 1) on exchange 15319i with MessageCounter:174118040.
2022-07-22 14:03:21.9093 -0700 default 0x17dd00 0x0 homed[16211] (CHIP): 🔵 [1658523801840] [16211:1563904] CHIP: [IN] Sending encrypted msg 0x103029e68 with MessageCounter:174118040 to 0x00000000FB384A57 (1) at monotonic time: 00000000092A29BA msec
2022-07-22 14:03:22.1309 -0700 default 0x17dd00 0x0 homed[16211] (CHIP): 🔵 [1658523802062] [16211:1563904] CHIP: [EM] Received message of type 0x5 with protocolId (0, 1) and MessageCounter:87523899 on exchange 15319i
2022-07-22 14:03:22.1309 -0700 default 0x17dd00 0x0 homed[16211] (CHIP): 🟢 [1658523802062] [16211:1563904] CHIP: [EM] Found matching exchange: 15319i, Delegate: 0x105b57ac0
2022-07-22 14:03:22.1311 -0700 default 0x17dd00 0x0 homed[16211] (CHIP): 🟢 [1658523802062] [16211:1563904] CHIP: [EM] Rxd Ack; Removing MessageCounter:174118040 from Retrans Table on exchange 15319i
2022-07-22 14:03:22.1311 -0700 default 0x17dd00 0x0 homed[16211] (CHIP): 🟢 [1658523802062] [16211:1563904] CHIP: [EM] Removed CHIP MessageCounter:174118040 from RetransTable on exchange 15319i
2022-07-22 14:03:22.1447 -0700 default 0x17dd00 0x0 homed[16211] (CHIP): 🔵 [1658523802076] [16211:1563904] CHIP: [DMG] Refresh LivenessCheckTime for 25000 milliseconds with SubscriptionId = 0x4e4b0c04 Peer = 01:00000000FB384A57
2022-07-22 14:03:22.1448 -0700 default 0x17dd00 0x0 homed[16211] (CHIP): 🟢 [1658523802076] [16211:1563904] CHIP: [EM] Piggybacking Ack for MessageCounter:87523899 on exchange: 15319i
2022-07-22 14:03:22.1449 -0700 default 0x17dd00 0x0 homed[16211] (CHIP): 🔵 [1658523802076] [16211:1563904] CHIP: [IN] Prepared secure message 0x103029e68 to 0x00000000FB384A57 (1)  of type 0x1 and protocolId (0, 1) on exchange 15319i with MessageCounter:174118041.
2022-07-22 14:03:22.1449 -0700 default 0x17dd00 0x0 homed[16211] (CHIP): 🔵 [1658523802076] [16211:1563904] CHIP: [IN] Sending encrypted msg 0x103029e68 with MessageCounter:174118041 to 0x00000000FB384A57 (1) at monotonic time: 00000000092A2AA6 msec
2022-07-22 14:03:22.2826 -0700 default 0x17dd00 0x0 homed[16211] (CHIP): 🔵 [1658523802213] [16211:1563904] CHIP: [EM] Received message of type 0x5 with protocolId (0, 1) and MessageCounter:87523900 on exchange 15319i
2022-07-22 14:03:22.2826 -0700 default 0x17dd00 0x0 homed[16211] (CHIP): 🟢 [1658523802213] [16211:1563904] CHIP: [EM] Found matching exchange: 15319i, Delegate: 0x105b57ac0
2022-07-22 14:03:22.2827 -0700 default 0x17dd00 0x0 homed[16211] (CHIP): 🟢 [1658523802213] [16211:1563904] CHIP: [EM] Rxd Ack; Removing MessageCounter:174118041 from Retrans Table on exchange 15319i
2022-07-22 14:03:22.2827 -0700 default 0x17dd00 0x0 homed[16211] (CHIP): 🟢 [1658523802213] [16211:1563904] CHIP: [EM] Removed CHIP MessageCounter:174118041 from RetransTable on exchange 15319i
2022-07-22 14:03:22.2992 -0700 default 0x17dd00 0x0 homed[16211] (CHIP): 🔵 [1658523802230] [16211:1563904] CHIP: [DMG] Refresh LivenessCheckTime for 25000 milliseconds with SubscriptionId = 0x4e4b0c04 Peer = 01:00000000FB384A57
2022-07-22 14:03:22.2993 -0700 default 0x17dd00 0x0 homed[16211] (CHIP): 🟢 [1658523802230] [16211:1563904] CHIP: [EM] Piggybacking Ack for MessageCounter:87523900 on exchange: 15319i
2022-07-22 14:03:22.2994 -0700 default 0x17dd00 0x0 homed[16211] (CHIP): 🔵 [1658523802230] [16211:1563904] CHIP: [IN] Prepared secure message 0x103029e68 to 0x00000000FB384A57 (1)  of type 0x1 and protocolId (0, 1) on exchange 15319i with MessageCounter:174118042.
2022-07-22 14:03:22.2994 -0700 default 0x17dd00 0x0 homed[16211] (CHIP): 🔵 [1658523802230] [16211:1563904] CHIP: [IN] Sending encrypted msg 0x103029e68 with MessageCounter:174118042 to 0x00000000FB384A57 (1) at monotonic time: 00000000092A2B41 msec
022-07-22 14:03:22.5343 -0700 default 0x17dd01 0x0 homed[16211] (CHIP): 🔵 [1658523802465] [16211:1563905] CHIP: [EM] Received message of type 0x4 with protocolId (0, 1) and MessageCounter:87523901 on exchange 15319i
2022-07-22 14:03:22.5343 -0700 default 0x17dd01 0x0 homed[16211] (CHIP): 🟢 [1658523802465] [16211:1563905] CHIP: [EM] Found matching exchange: 15319i, Delegate: 0x105b57ac0
2022-07-22 14:03:22.5344 -0700 default 0x17dd01 0x0 homed[16211] (CHIP): 🟢 [1658523802465] [16211:1563905] CHIP: [EM] Rxd Ack; Removing MessageCounter:174118042 from Retrans Table on exchange 15319i
2022-07-22 14:03:22.5344 -0700 default 0x17dd01 0x0 homed[16211] (CHIP): 🟢 [1658523802465] [16211:1563905] CHIP: [EM] Removed CHIP MessageCounter:174118042 from RetransTable on exchange 15319i
2022-07-22 14:03:22.5345 -0700 default 0x17dd01 0x0 homed[16211] (CHIP): 🟢 [1658523802465] [16211:1563905] CHIP: [DMG] mResubscribePolicy is null
2022-07-22 14:03:22.5345 -0700 default 0x17dd01 0x0 homed[16211] (CHIP): 🟢 [1658523802465] [16211:1563905] CHIP: [DMG] MoveToState ReadClient[0x105b57ac0]: Moving to [      Idle]
2022-07-22 14:03:22.5345 -0700 default 0x17dd01 0x0 homed[16211] (CHIP): 🟢 [1658523802465] [16211:1563905] CHIP: [EM] Sending Standalone Ack for MessageCounter:87523901 on exchange 15319i
2022-07-22 14:03:22.5346 -0700 default 0x17dd01 0x0 homed[16211] (CHIP): 🔵 [1658523802465] [16211:1563905] CHIP: [IN] Prepared secure message 0x16f6fd288 to 0x00000000FB384A57 (1)  of type 0x10 and protocolId (0, 0) on exchange 15319i with MessageCounter:174118043.
2022-07-22 14:03:22.5346 -0700 default 0x17dd01 0x0 homed[16211] (CHIP): 🔵 [1658523802465] [16211:1563905] CHIP: [IN] Sending encrypted msg 0x16f6fd288 with MessageCounter:174118043 to 0x00000000FB384A57 (1) at monotonic time: 00000000092A2C2C msec
2022-07-22 14:03:22.5347 -0700 default 0x17dd01 0x0 homed[16211] (CHIP): 🟢 [1658523802465] [16211:1563905] CHIP: [EM] Flushed pending ack for MessageCounter:87523901 on exchange 15319i

Apple reference: rdar://97467750
@aajain-com aajain-com added darwin crash p1 priority 1 work labels Jul 23, 2022
@aajain-com aajain-com mentioned this issue Aug 2, 2022
Closed
@bzbarsky-apple
Copy link
Contributor 

0   CHIP                          	       0x188393dac invocation function for block in (anonymous namespace)::SubscriptionCallback::OnReportEnd() + 20 (connectedhomeip/src/darwin/Framework/CHIP/CHIPDevice.mm:1409)

That line on 5d8599d looks like this:

    if (mEventReportCallback && eventReports.count) {
        dispatch_async(mQueue, ^{
1409 --> mEventReportCallback(eventReports);
        });
    }

the crash is a null-deref. This looks a lot like #21453 and should have been fixed by #21456

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
crash darwin p1 priority 1 work
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@aajain-com @bzbarsky-apple