Capture trace of error reporting thread and identify with boolean flag #355

fractalwrench · 2018-08-02T09:45:32Z

Goal

Captures the trace of Thread.currentThread(), which was previously omitted, and to identify it with a boolean flag in the serialised JSON.

Changeset

Alter ThreadState to stop removing the current thread from serialisation
Conditionally write errorReportingThread boolean flag by checking thread ID

Tests

Added unit tests for general ThreadState serialisation, and for checking that the current thread is now captured. Ran mazerunner locally, tested with dashboard.

Review

For the submitter, initial self-review:

Commented on code changes inline explain the reasoning behind the approach
Reviewed the test cases added for completeness and possible points for discussion
A changelog entry was added for the goal of this pull request
Check the scope of the changeset - is everything in the diff required for the pull request?
This pull request is ready for:
- Initial review of the intended approach, not yet feature complete
- Structural review of the classes, functions, and properties modified
- Final review

For the pull request reviewer(s), this changeset has been reviewed for:

Consistency across platforms for structures or concepts added or modified
Consistency between the changeset and the goal stated above
Internal consistency with the rest of the library - is there any overlap between existing interfaces and any which have been added?
Usage friction - is the proposed change in usage cumbersome or complicated?
Performance and complexity - are there any cases of unexpected O(n^3) when iterating, recursing, flat mapping, etc?
Concurrency concerns - if components are accessed asynchronously, what issues will arise
Thoroughness of added tests and any missing edge cases
Idiomatic use of the language

…olean flag in serialised json

coveralls · 2018-08-02T10:15:12Z

Coverage decreased (-0.02%) to 74.917% when pulling 60b5934 on thread-id into 0390356 on next.

coveralls · 2018-08-02T10:15:12Z

Coverage decreased (-0.02%) to 74.917% when pulling 60b5934 on thread-id into 0390356 on next.

coveralls · 2018-08-02T10:15:12Z

Coverage decreased (-0.2%) to 74.731% when pulling 2f83a7c on thread-id into 0390356 on next.

sdk/src/main/java/com/bugsnag/android/ThreadState.java

    private final Thread[] threads;
    private final Map<Thread, StackTraceElement[]> stackTraces;
+    private final long currentThreadId;


kattrali

I tested this with a few cases:

Spinning up background threads which periodically do work and then cause a handled or unhandled exception
Causing handled or unhandled exceptions from UI events
Causing handled or unhandled exceptions from the main thread immediately

In the case of unhandled exceptions, an incorrect thread is generally marked as the unhandledException thread is not the same as the error reporting thread. So a thread is marked but it has a different stacktrace from the Stacktrace tab.

For handled exceptions, I never see any thread marked as the reporting thread on the Threads tab.

sdk/src/main/java/com/bugsnag/android/ThreadState.java

    private final Thread[] threads;
    private final Map<Thread, StackTraceElement[]> stackTraces;
+    private final long currentThreadId;


sdk/src/main/java/com/bugsnag/android/ThreadState.java

     */
-    private Thread[] sanitiseThreads(long currentThreadId,
-                                     Map<Thread, StackTraceElement[]> liveThreads) {
+    private Thread[] sanitiseThreads(Map<Thread, StackTraceElement[]> liveThreads) {


…n relying on Thread.currentThre

fractalwrench · 2018-08-07T09:36:29Z

Thanks for the review @kattrali - I've updated ThreadState so that it now requires a Thread parameter in its constructor, which is populated via the thread value from uncaughtException, and Thread.currentThread for notify calls. This should address the wrong thread being selected for unhandled exceptions.

For handled exceptions, I never see any thread marked as the reporting thread on the Threads tab.

I was not able to reproduce this behaviour, did you have a code example that will trigger this?

out of date

fractalwrench · 2018-08-07T10:38:30Z

I've updated the thread serialisation to capture the threads at the point of report generation, rather than serialisation. I've also made sure that we pass in the current Thread to ThreadState rather than assuming Thread.currentThread, as this value will often be wrong.

kattrali · 2018-08-08T01:17:21Z

I was not able to reproduce this behaviour, did you have a code example that will trigger this?

Nothing special, just fired up the example app with the handled exception buttons. It still happens sometimes.

kattrali

Tested this further, made some suggestions for how to get a consistent result for both handled and unhandled exceptions. The error reporting thread for handled errors looks as I would expect (though sometimes no thread is marked?), though unhandled errors may end up with an unexpected stack if they are from a pool and should be set to the exception stack.

sdk/src/main/java/com/bugsnag/android/ExceptionHandler.java

@@ -77,12 +77,12 @@ public void uncaughtException(@NonNull Thread thread, @NonNull Throwable throwab
                StrictMode.setThreadPolicy(StrictMode.ThreadPolicy.LAX);

                client.cacheAndNotify(throwable, Severity.ERROR,
-                    metaData, severityReason, violationDesc);
+                    metaData, severityReason, violationDesc, thread);


fractalwrench · 2018-08-08T10:03:35Z

Nothing special, just fired up the example app with the handled exception buttons. It still happens sometimes.

I've tried pressing each button in the example app 10x on an API 27 emulator. For all of the 70 received events "Error reported from this thread" is present on one entry in the threads tab. Do I need to increase the frequency to reproduce this issue, or is there some sort of code change required?

One potential cause I can think of would be that Thread.getAllStackTraces() only returns alive threads, and that the thread parameter passed into uncaughtException might be terminated, and therefore not in the map.

If this is the case then we might be able to record the thread ID, name, and a zero-element array stacktrace by adding the terminated thread into the set of live threads. However, I'm still not sure how this could explain why this behaviour was observed for a blocking notify call - I suspect there's something subtly different in our environments and it would be good to get to the bottom of this.

However, all of the required elements are here to construct the expected result. For unhandled reports, the errorReportingThread should have: exception.getStackTrace()

I discussed this with Duncan at project kick-off and believe the requested behaviour was to capture the thread trace for both handled/unhandled errors, rather than the exception stacktrace. I'll run this past the necessary Slack channel before making the change

fractalwrench · 2018-08-08T15:43:28Z

This behaviour is reproducible on API 25 not API 27, investigating further

… already a key An issue exists in api 24/25 where not all threads are reported correctly from Thread.getAllStacktraces(). Adding it in manually and calling Thread.getStacktrace() appears to negate this behaviour. https://issuetracker.google.com/issues/64122757

…or, rather than thread trace, f

…ace for unhandled errors

fractalwrench · 2018-08-09T14:34:48Z

sdk/src/androidTest/java/com/bugsnag/android/ThreadStateTest.kt

+
+    private fun verifyCurrentThreadStructure(json: JSONArray,
+                                             currentThreadId: Long,
+                                             action: ((thread: JSONObject) -> Unit)? = null) {


Allows passing a function that will be invoked when the errorReportingThread json is found. This means assertions can be run with less boilerplate finding the necessary thread

fractalwrench · 2018-08-09T14:35:55Z

sdk/src/main/java/com/bugsnag/android/Error.java

+                @NonNull Thread thread,
+                boolean unhandled) {
+            Throwable exc = unhandled ? exception : null;
+            this.threadState = new ThreadState(config, thread, Thread.getAllStackTraces(), exc);


If an exception is passed in (default for unhandled errors), the exception stacktrace will be serialised rather than the thread stacktrace

comments addressed

fractalwrench · 2018-08-09T15:06:08Z

There appears to be a bug in API levels 24/25 where Thread.getAllStacktraces() does not actually capture all threads, which meant the errorReportingThread would not be serialised at all on those levels. This led to the observed behaviour with handled exceptions not showing the expected information in the dashboard.

I have applied a workaround for this by capturing the stacktrace of the errorReportingThread directly, via Thread.getStackTrace(). However, it's worth noting that the rest of the affected threads will not be serialised on Android 7 devices. I'm not aware of a suitable workaround for this at the present time.

I have also altered the thread serialisation so that the exception stacktrace is used for the errorReportingThread, for unhandled errors only.

Testing included:

Full Mazerunner suite on API 21
Addition of new unit tests and running on API 16, 19, 21, 25, 27
Manual tests on API 25/27 (inspected thread tab on dashboard):
- Handled + unhandled exception button in app
- Wrapping handled + unhandled exception button code with Thread {}.start() and confirming errorReportingThread differed
Self-review of changeset

…yntax

Add mazerunner scenario for thread id

fractalwrench · 2018-08-20T15:43:04Z

Added an additional mazerunner scenario, which has passed locally (CI build is blocked again but I believe this should be ready for review.)

simonbowring · 2018-09-04T13:11:38Z

features/error_reporting_thread.feature

+Feature: Error Reporting Thread
+
+Scenario: Only 1 thread is flagged as the error reporting thread
+    When I run "HandledExceptionScenario" with the defaults


Is it worth adding a scenario for unhandled as well?

yes, good point.

simonbowring · 2018-09-05T10:23:09Z

The current thread stacktrace for handled events looks like this:

VMStack.java:-2dalvik.system.VMStack.getThreadStackTrace	
Thread.java:580java.lang.Thread.getStackTrace	
Thread.java:522java.lang.Thread.getAllStackTraces	
Error.java:408com.bugsnag.android.Error$Builder.<init>	
Client.java:665com.bugsnag.android.Client.notify	
Bugsnag.java:380com.bugsnag.android.Bugsnag.notify	
ExampleActivity.java:83com.bugsnag.android.example.ExampleActivity.crashHandled
...

Should we trim off everything from Bugsnag.java upwards as it's potentially not relevant (our code), or is it important that we present the entire thread state?

fractalwrench · 2018-09-05T10:36:24Z

@simonbowring this is the requested behaviour for handled events - unhandled events will show the exception stacktrace rather than the thread trace.

adds a scenario for an unhandled exception, that ensures the error reporting thread is serialised. For handled exceptions, the thread trace should be reported. For unhandled exceptions, the exception stacktrace should be used instead.

simonbowring

LGTM

Add react native maven repo earlier in plugin lifecycle

Bump bugsnag-android to v5.11.0

$fractalwrench$

fractalwrench added 2 commits August 2, 2018 10:32

$@fractalwrench$

feat: capture trace of error reporting thread and identify it with bo…

f7961fb

…olean flag in serialised json

$@fractalwrench$

add changelog entry

60b5934

snmaynard reviewed Aug 2, 2018

View reviewed changes

$@fractalwrench$ fractalwrench requested a review from a team August 3, 2018 08:11

kattrali previously requested changes Aug 6, 2018

View reviewed changes

fractalwrench added 3 commits August 7, 2018 10:26

$@fractalwrench$

feat: pass current thread into threadstate when notifying, rather tha…

9461b25

…n relying on Thread.currentThre

$@fractalwrench$

docs: update javadoc for threadstate

37f4de2

$@fractalwrench$

rename thread -> currentThread

d75f08c

$@fractalwrench$

test: verify that the current thread is not always used in thread state

932397f

kattrali previously requested changes Aug 8, 2018

View reviewed changes

fractalwrench added 4 commits August 9, 2018 13:43

$@fractalwrench$

refactor: factor current thread test logic into separate function

dc34285

$@fractalwrench$

feat: use exception stacktrace when passed into threadstate construct…

3949a23

…or, rather than thread trace, f

$@fractalwrench$

feat: update exceptionHandler threadstate to record exception stacktr…

2f83a7c

…ace for unhandled errors

$fractalwrench$

fractalwrench commented Aug 9, 2018

View reviewed changes

$@fractalwrench$ fractalwrench requested a review from a team August 17, 2018 14:21

fractalwrench added 2 commits August 20, 2018 14:36

$@fractalwrench$

test: add mazerunner scenario for thread id

a544429

$@fractalwrench$

build: update gemfile lock

3d3a5c4

fractalwrench added 3 commits August 20, 2018 15:49

$@fractalwrench$

test: update mazerunner scenario to use latest error reporting step s…

8f5d352

…yntax

$@fractalwrench$

Merge pull request #362 from bugsnag/thread-id-mazerunner

ddffdef

Add mazerunner scenario for thread id

$@fractalwrench$

Merge branch 'next' into thread-id

36884de

$@fractalwrench$

Merge branch 'next' into thread-id

4ad4542

simonbowring reviewed Sep 4, 2018

View reviewed changes

simonbowring approved these changes Sep 25, 2018

View reviewed changes

$@fractalwrench$ fractalwrench merged commit d91643e into next Sep 25, 2018

$@fractalwrench$ fractalwrench deleted the thread-id branch September 25, 2018 13:45

lemnik pushed a commit that referenced this pull request Jun 2, 2021

$@fractalwrench$

Merge pull request #355 from bugsnag/fix-rn-maven-repo

489eb21

Add react native maven repo earlier in plugin lifecycle

rich-bugsnag added a commit that referenced this pull request Sep 3, 2021

Merge pull request #355 from bugsnag/android-5110

4fb60c5

Bump bugsnag-android to v5.11.0

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Capture trace of error reporting thread and identify with boolean flag #355

Capture trace of error reporting thread and identify with boolean flag #355

$@fractalwrench$ fractalwrench commented Aug 2, 2018 •

edited by simonbowring

Loading

coveralls commented Aug 2, 2018

coveralls commented Aug 2, 2018

coveralls commented Aug 2, 2018 •

edited

Loading

This comment was marked as resolved.

This comment was marked as resolved.

This comment was marked as resolved.

This comment was marked as resolved.

This comment was marked as resolved.

kattrali left a comment

This comment was marked as resolved.

This comment was marked as resolved.

fractalwrench commented Aug 7, 2018

fractalwrench commented Aug 7, 2018

kattrali commented Aug 8, 2018

kattrali left a comment

This comment was marked as resolved.

fractalwrench commented Aug 8, 2018

fractalwrench commented Aug 8, 2018

$@fractalwrench$ fractalwrench Aug 9, 2018

$@fractalwrench$ fractalwrench Aug 9, 2018

fractalwrench commented Aug 9, 2018

fractalwrench commented Aug 20, 2018

simonbowring Sep 4, 2018

$@fractalwrench$ fractalwrench Sep 5, 2018

simonbowring commented Sep 5, 2018

fractalwrench commented Sep 5, 2018

simonbowring left a comment

Capture trace of error reporting thread and identify with boolean flag #355

Capture trace of error reporting thread and identify with boolean flag #355

Conversation

fractalwrench commented Aug 2, 2018 • edited by simonbowring Loading

Goal

Changeset

Tests

Review

coveralls commented Aug 2, 2018

coveralls commented Aug 2, 2018

coveralls commented Aug 2, 2018 • edited Loading

This comment was marked as resolved.

This comment was marked as resolved.

This comment was marked as resolved.

This comment was marked as resolved.

This comment was marked as resolved.

kattrali left a comment

Choose a reason for hiding this comment

This comment was marked as resolved.

This comment was marked as resolved.

fractalwrench commented Aug 7, 2018

fractalwrench commented Aug 7, 2018

kattrali commented Aug 8, 2018

kattrali left a comment

Choose a reason for hiding this comment

This comment was marked as resolved.

fractalwrench commented Aug 8, 2018

fractalwrench commented Aug 8, 2018

fractalwrench Aug 9, 2018

Choose a reason for hiding this comment

fractalwrench Aug 9, 2018

Choose a reason for hiding this comment

fractalwrench commented Aug 9, 2018

fractalwrench commented Aug 20, 2018

simonbowring Sep 4, 2018

Choose a reason for hiding this comment

fractalwrench Sep 5, 2018

Choose a reason for hiding this comment

simonbowring commented Sep 5, 2018

fractalwrench commented Sep 5, 2018

simonbowring left a comment

Choose a reason for hiding this comment

$@fractalwrench$ fractalwrench commented Aug 2, 2018 •

edited by simonbowring

Loading

coveralls commented Aug 2, 2018 •

edited

Loading

$@fractalwrench$ fractalwrench Aug 9, 2018

$@fractalwrench$ fractalwrench Aug 9, 2018

$@fractalwrench$ fractalwrench Sep 5, 2018