search

NativeScript / android

NativeScript for Android using v8
https://docs.nativescript.org/guide/android-marshalling
Apache License 2.0
529 stars 135 forks source link

NS app crashes regularly in several different ways #986

Closed gsmedley closed 6 years ago

gsmedley commented 6 years ago

Getting a few different crashes running "adb monkey" tests on my NS application

Did you verify this is a real problem by searching the [NativeScript Forum]

Yes.

Tell us about the problem

After an hour or so of running the tests I get a one of the following crashes:

System.err: com.tns.NativeScriptException: Attempt to use cleared object reference id=116786
System.err:     at com.tns.Runtime.getJavaObjectByID(Runtime.java:897)
System.err:     at com.tns.Runtime.callJSMethodNative(Native Method)
System.err:     at com.tns.Runtime.dispatchCallJSMethodNative(Runtime.java:1088)
System.err:     at com.tns.Runtime.callJSMethodImpl(Runtime.java:970)
System.err:     at com.tns.Runtime.callJSMethod(Runtime.java:957)
System.err:     at com.tns.Runtime.callJSMethod(Runtime.java:941)
System.err:     at com.tns.Runtime.callJSMethod(Runtime.java:933)
System.err:     at com.tns.FragmentClass.onCreateView(FragmentClass.java:40)
System.err:     at android.app.Fragment.performCreateView(Fragment.java:2281)
System.err:     at android.app.FragmentManagerImpl.moveToState(FragmentManager.java:983)
System.err:     at android.app.FragmentManagerImpl.moveToState(FragmentManager.java:1163)
System.err:     at android.app.BackStackRecord.run(BackStackRecord.java:793)
System.err:     at android.app.FragmentManagerImpl.execPendingActions(FragmentManager.java:1552)
System.err:     at android.app.FragmentManagerImpl$1.run(FragmentManager.java:487)
System.err:     at android.os.Handler.handleCallback(Handler.java:739)
System.err:     at android.os.Handler.dispatchMessage(Handler.java:95)
System.err:     at android.os.Looper.loop(Looper.java:158)
System.err:     at android.app.ActivityThread.main(ActivityThread.java:7224)
System.err:     at java.lang.reflect.Method.invoke(Native Method)
System.err:     at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:1230)
System.err:     at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:1120)
System.err: com.tns.NativeScriptException: No weak reference found. Attempt to use cleared object reference id=22033
System.err:     at com.tns.Runtime.getJavaObjectByID(Runtime.java:892)
System.err:     at com.tns.Runtime.callJSMethodNative(Native Method)
System.err:     at com.tns.Runtime.dispatchCallJSMethodNative(Runtime.java:1088)
System.err:     at com.tns.Runtime.callJSMethodImpl(Runtime.java:970)
System.err:     at com.tns.Runtime.callJSMethod(Runtime.java:957)
System.err:     at com.tns.Runtime.callJSMethod(Runtime.java:941)
System.err:     at com.tns.Runtime.callJSMethod(Runtime.java:933)
System.err:     at com.tns.FragmentClass.onCreateView(FragmentClass.java:40)
System.err:     at android.app.Fragment.performCreateView(Fragment.java:2281)
System.err:     at android.app.FragmentManagerImpl.moveToState(FragmentManager.java:983)
System.err:     at android.app.FragmentManagerImpl.moveToState(FragmentManager.java:1163)
System.err:     at android.app.BackStackRecord.run(BackStackRecord.java:793)
System.err:     at android.app.FragmentManagerImpl.execPendingActions(FragmentManager.java:1552)
System.err:     at android.app.FragmentManagerImpl$1.run(FragmentManager.java:487)
System.err:     at android.os.Handler.handleCallback(Handler.java:739)
System.err:     at android.os.Handler.dispatchMessage(Handler.java:95)
System.err:     at android.os.Looper.loop(Looper.java:158)
System.err:     at android.app.ActivityThread.main(ActivityThread.java:7224)
System.err:     at java.lang.reflect.Method.invoke(Native Method)
System.err:     at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:1230)
System.err:     at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:1120)
ActivityManager: Process com.kanayo.mymobilenative (pid 8808)(adj 0) has died(221,529)
System.err: TypeError: Cannot read property 'delete' of undefined
System.err: File: "file:///data/data/com.kanayo.mymobilenative/files/app/tns_modules/tns-core-modules/ui/frame/fragment.transitions.js, line: 553, column: 11
System.err: StackTrace:
System.err:     Frame: function:'transitionOrAnimationCompleted', file:'file:///data/data/com.kanayo.mymobilenative/files/app/tns_modules/tns-core-modules/ui/frame/fragment.transitions.js', line: 553, column: 12
System.err:     Frame: function:'TransitionListenerImpl.onTransitionEnd', file:'file:///data/data/com.kanayo.mymobilenative/files/app/tns_modules/tns-core-modules/ui/frame/fragment.transitions.js', line: 220, column: 17
System.err:     at com.tns.Runtime.callJSMethodNative(Native Method)
System.err:     at com.tns.Runtime.dispatchCallJSMethodNative(Runtime.java:1088)
System.err:     at com.tns.Runtime.callJSMethodImpl(Runtime.java:970)
System.err:     at com.tns.Runtime.callJSMethod(Runtime.java:957)
System.err:     at com.tns.Runtime.callJSMethod(Runtime.java:941)
System.err:     at com.tns.Runtime.callJSMethod(Runtime.java:933)
System.err:     at com.tns.gen.java.lang.Object_frnal_ts_helpers_l58_c38__TransitionListenerImpl.onTransitionEnd(Object_frnal_ts_helpers_l58_c38__TransitionListenerImpl.java:18)
System.err:     at android.transition.Transition.end(Transition.java:1924)
System.err:     at android.transition.Transition$3.onAnimationEnd(Transition.java:1875)
System.err:     at android.animation.ValueAnimator.endAnimation(ValueAnimator.java:1239)
System.err:     at android.animation.ValueAnimator$AnimationHandler.doAnimationFrame(ValueAnimator.java:766)
System.err:     at android.animation.ValueAnimator$AnimationHandler$1.run(ValueAnimator.java:801)
System.err:     at android.view.Choreographer$CallbackRecord.run(Choreographer.java:920)
System.err:     at android.view.Choreographer.doCallbacks(Choreographer.java:695)
System.err:     at android.view.Choreographer.doFrame(Choreographer.java:628)
System.err:     at android.view.Choreographer$FrameDisplayEventReceiver.run(Choreographer.java:906)
System.err:     at android.os.Handler.handleCallback(Handler.java:739)
System.err:     at android.os.Handler.dispatchMessage(Handler.java:95)
System.err:     at android.os.Looper.loop(Looper.java:158)
System.err:     at android.app.ActivityThread.main(ActivityThread.java:7224)
System.err:     at java.lang.reflect.Method.invoke(Native Method)
System.err:     at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:1230)
System.err:     at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:1120)
// java.lang.RuntimeException: Unable to instantiate activity java.lang.NullPointerException: Attempt to read from field 'int com.tns.Runtime.currentObjectId' on a null object reference
//  at android.app.ActivityThread.performLaunchActivity(ActivityThread.java:3093)
//  at android.app.ActivityThread.handleLaunchActivity(ActivityThread.java:3349)
//  at android.app.ActivityThread.access$1100(ActivityThread.java:221)
//  at android.app.ActivityThread$H.handleMessage(ActivityThread.java:1794)
//  at android.os.Handler.dispatchMessage(Handler.java:102)
//  at android.os.Looper.loop(Looper.java:158)
//  at android.app.ActivityThread.main(ActivityThread.java:7224)
//  at java.lang.reflect.Method.invoke(Native Method)
//  at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:1230)
//  at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:1120)
// Caused by: java.lang.NullPointerException: Attempt to read from field 'int com.tns.Runtime.currentObjectId' on a null object reference
//  at com.tns.Runtime.initInstance(Runtime.java:601)
//  at com.tns.NativeScriptActivity.<init>(NativeScriptActivity.java:7)
//  at java.lang.Class.newInstance(Native Method)
//  at android.app.Instrumentation.newActivity(Instrumentation.java:1095)
//  at android.app.ActivityThread.performLaunchActivity(ActivityThread.java:3083)
System.err: java.lang.IllegalStateException: The specified child already has a parent. You must call removeView() on the child's parent first.
System.err:     at android.view.ViewGroup.addViewInner(ViewGroup.java:4656)
System.err:     at android.view.ViewGroup.addView(ViewGroup.java:4492)
System.err:     at android.view.ViewGroup.addView(ViewGroup.java:4433)
System.err:     at android.view.ViewGroup.addView(ViewGroup.java:4406)
System.err:     at android.app.FragmentManagerImpl.moveToState(FragmentManager.java:995)
System.err:     at android.app.FragmentManagerImpl.moveToState(FragmentManager.java:1163)
System.err:     at android.app.BackStackRecord.run(BackStackRecord.java:793)
System.err:     at android.app.FragmentManagerImpl.execPendingActions(FragmentManager.java:1552)
System.err:     at android.app.FragmentManagerImpl$1.run(FragmentManager.java:487)
System.err:     at android.os.Handler.handleCallback(Handler.java:739)
System.err:     at android.os.Handler.dispatchMessage(Handler.java:95)
System.err:     at android.os.Looper.loop(Looper.java:158)
System.err:     at android.app.ActivityThread.main(ActivityThread.java:7224)
System.err:     at java.lang.reflect.Method.invoke(Native Method)
System.err:     at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:1230)
System.err:     at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:1120)
TypeError: Cannot read property 'key' of undefined
     at NSRouteReuseStrategy.shouldAttach (file:///data/data/[appname]/files/app/tns_modules/nativescript-angular/router/ns-route-reuse-strategy.js:64:55)
     at ActivateRoutes.activateRoutes (file:///data/data/[appname]/files/app/tns_modules/@angular/router/bundles/router.umd.js:4743:45)
     at file:///data/data/[appname]/files/app/tns_modules/@angular/router/bundles/router.umd.js:4715:58
     at Array.forEach (native)
     at ActivateRoutes.activateChildRoutes (file:///data/data/[appname]/files/app/tns_modules/@angular/router/bundles/router.umd.js:4715:29)
     at ActivateRoutes.activateRoutes (file:///data/data/[appname]/files/app/tns_modules/@angular/router/bundles/router.umd.js:4736:22)
     at file:///data/data/[appname]/files/app/tns_modules/@angular/router/bundles/router.umd.js:4715:58
     at Array.forEach (native)
     at ActivateRoutes.activateChildRoutes (file:///data/data/[appname]/files/app/tns_modules/@angular/router/bundles/router.umd.js:4715:29)
     at ActivateRoutes.activate (file:///data/data/[appname]/files/app/tns_modules/@angular/router/bundles/router.umd.js:4608:14)
     at file:///data/data/[appname]/files/app/tns_modules/@angular/router/bundles/router.umd.js:4185:22
     at SafeSubscriber._next (file:///data/data/[appname]/files/app/tns_modules/rxjs/Observable.js:224:21)
     at SafeSubscriber.__tryOrSetError (file:///data/data/[appname]/files/app/tns_modules/rxjs/Subscriber.js:247:16)
     at SafeSubscriber.next (file:///data/data/[appname]/files/app/tns_modules/rxjs/Subscriber.js:187:27)
     at Subscriber._next (file:///data/data/[appname]/files/app/tns_modules/rxjs/Subscriber.js:125:26)

Please provide the following version numbers that your issue occurs with:

tns 3.4.2

 "dependencies": {
    "@angular/common": "^4.4.5",
    "@angular/compiler": "^4.4.5",
    "@angular/core": "^4.4.5",
    "@angular/forms": "^4.4.5",
    "@angular/http": "^4.4.5",
    "@angular/platform-browser": "^4.4.5",
    "@angular/router": "^4.4.5",
    "@types/i18next": "^8.4.2",
    "angular": "^1.6.6",
    "bigdecimal": "^0.6.1",
    "i18next": "^9.1.0",
    "jsrsasign": "^8.0.4",
    "moment": "2.19.1",
    "nativescript-angular": "^4.4.0",
    "nativescript-bcryptjs": "^1.0.1",
    "nativescript-cardview": "^2.0.5",
    "nativescript-checkbox": "https://github.com/gsmedley/nativescript-checkbox-dist/tarball/master",
    "nativescript-floatingactionbutton": "^4.1.3",
    "nativescript-local-notifications": "https://github.com/kanayo/nativescript-local-notifications/tarball/master",
    "nativescript-ng2-fonticon": "^1.3.4",
    "nativescript-numeric-keyboard": "^3.0.3",
    "nativescript-permissions": "^1.2.3",
    "nativescript-secure-storage": "2.2.1",
    "nativescript-textinputlayout": "^2.0.2",
    "nativescript-texttospeech": "^2.0.1",
    "nativescript-theme-core": "~1.0.4",
    "nativescript-toast": "1.4.6",
    "nativescript-ui-chart": "^3.5.0",
    "nativescript-ui-listview": "^3.5.0",
    "nativescript-ui-sidedrawer": "^3.5.0",
    "nativescript-unit-test-runner": "^0.3.4",
    "nativescript-urlhandler": "^1.2.1",
    "nativescript-uuid": "0.0.1",
    "npm": "^5.7.1",
    "object-assign-deep": "^0.3.1",
    "reflect-metadata": "~0.1.8",
    "rxjs": "~5.4.2",
    "semver": "^5.5.0",
    "tns-core-modules": "^3.4.0",
    "tns-platform-declarations": "^3.3.0",
    "zone.js": "^0.8.18"

Did the error happen while the app was executing? (runtime error)

Yes

Please tell us how to recreate the issue in as much detail as possible.

Here is the adb command I am using:

adb shell monkey -p com.kanayo.mymobilenative -c android.intent.category.LAUNCHER -v --ignore-security-exceptions --pct-touch 99 --pct-motion 0 --pct-trackball 0 --pct-syskeys 0 --pct-nav 0 --pct-majornav 0 --pct-appswitch 0 --pct-flip 0 --pct-anyevent 1 --pct-pinchzoom 0 --pct-permission 0 --throttle 2000 5000000

petekanev commented 6 years ago

@gsmedley logs are all good, but a reproduction repository would be better, as we'd be able to test locally. Otherwise we can mostly just guess what happens and where. Also, you could reduce the monkey arguments to only those which may be causing the crash.

gsmedley commented 6 years ago

@Pip3r4o - Thanks for the quick reply!

Unfortunately I can't share the app as it relies on a private server to run.

The test parameters just:

I am going to add some logging to see if I can isolate which pages the crashes happen on.

Is there any other internal logging I could enable?

gsmedley commented 6 years ago

And another one:

I see there is a fix in the works for this one and a workaround:

#5130 

System.err: java.lang.NullPointerException: Attempt to invoke virtual method 'boolean java.lang.Boolean.booleanValue()' on a null object reference
System.err:     at com.tns.gen.java.lang.Object_frnal_ts_helpers_l58_c38__EditTextListenersImpl.onEditorAction(Object_frnal_ts_helpers_l58_c38__EditTextListenersImpl.java:45)
System.err:     at android.widget.TextView.onEditorAction(TextView.java:5491)
System.err:     at com.android.internal.widget.EditableInputConnection.performEditorAction(EditableInputConnection.java:139)
System.err:     at com.android.internal.view.IInputConnectionWrapper.executeMessage(IInputConnectionWrapper.java:304)
System.err:     at com.android.internal.view.IInputConnectionWrapper$MyHandler.handleMessage(IInputConnectionWrapper.java:78)
System.err:     at android.os.Handler.dispatchMessage(Handler.java:102)
System.err:     at android.os.Looper.loop(Looper.java:158)
System.err:     at android.app.ActivityThread.main(ActivityThread.java:7224)
System.err:     at java.lang.reflect.Method.invoke(Native Method)
System.err:     at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:1230)
System.err:     at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:1120)
gsmedley commented 6 years ago

And yet another one:

See #974 

System.err: android.content.res.Resources$NotFoundException: Resource ID #0xffffffec
System.err:     at android.content.res.Resources.getValue(Resources.java:2558)
System.err:     at android.content.res.Resources.loadXmlResourceParser(Resources.java:4360)
System.err:     at android.content.res.Resources.getAnimation(Resources.java:2396)
System.err:     at android.animation.AnimatorInflater.loadAnimator(AnimatorInflater.java:122)
System.err:     at android.animation.AnimatorInflater.loadAnimator(AnimatorInflater.java:103)
System.err:     at android.animation.AnimatorInflater.loadAnimator(AnimatorInflater.java:88)
System.err:     at android.app.FragmentManagerImpl.loadAnimator(FragmentManager.java:831)
System.err:     at android.app.FragmentManagerImpl.moveToState(FragmentManager.java:1057)
System.err:     at android.app.FragmentManagerImpl.removeFragment(FragmentManager.java:1270)
System.err:     at android.app.BackStackRecord.run(BackStackRecord.java:744)
System.err:     at android.app.FragmentManagerImpl.execPendingActions(FragmentManager.java:1552)
System.err:     at android.app.FragmentManagerImpl$1.run(FragmentManager.java:487)
System.err:     at android.os.Handler.handleCallback(Handler.java:739)
System.err:     at android.os.Handler.dispatchMessage(Handler.java:95)
System.err:     at android.os.Looper.loop(Looper.java:158)
System.err:     at android.app.ActivityThread.main(ActivityThread.java:7224)
System.err:     at java.lang.reflect.Method.invoke(Native Method)
System.err:     at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:1230)
System.err:     at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:1120)
Plamen5kov commented 6 years ago

Hi @gsmedley On your question: "Is there any other internal logging I could enable?" You can add __enableVerboseLogging() early in your javascript. If you do, you'll see the android-runtime's debug log.

Plamen5kov commented 6 years ago 
declare function __enableVerboseLogging()
__enableVerboseLogging()

That's the way you do it in typescript.

gsmedley commented 6 years ago

Thanks - that worked - seeing some TNS.Java & TNS.Native output.

gsmedley commented 6 years ago

For completeness, I'm going to add the different stack traces I find

An uncaught Exception occurred on "main" thread.
com.tns.NativeScriptException: Attempt to use cleared object reference id=129237
    at com.tns.Runtime.getJavaObjectByID(Runtime.java:897)
    at com.tns.Runtime.callJSMethodNative(Native Method)
    at com.tns.Runtime.dispatchCallJSMethodNative(Runtime.java:1088)
    at com.tns.Runtime.callJSMethodImpl(Runtime.java:970)
    at com.tns.Runtime.callJSMethod(Runtime.java:957)
    at com.tns.Runtime.callJSMethod(Runtime.java:941)
    at com.tns.Runtime.callJSMethod(Runtime.java:933)
    at com.tns.gen.java.lang.Runnable.run(Runnable.java:10)
    at android.os.Handler.handleCallback(Handler.java:739)
    at android.os.Handler.dispatchMessage(Handler.java:95)
    at android.os.Looper.loop(Looper.java:158)
    at android.app.ActivityThread.main(ActivityThread.java:7224)
    at java.lang.reflect.Method.invoke(Native Method)
    at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:1230)
    at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:1120)
pana-cc commented 6 years ago

This is somewhat related: https://github.com/NativeScript/android-runtime/issues/887

pana-cc commented 6 years ago

@gsmedley Any chance the "Attempt to use cleared object reference" errors to have a JavaScript call stack in the log?

gsmedley commented 6 years ago

@pana-cc I did get a JS stack trace in my most recent test, after setting __enableVerboseLogging(), perhaps? It pointed toward a page update in a JS setInterval() after the View was gone. I'm clearing the interval in ngOnDestroy(), but maybe that's too late? It happens pretty infrequently so maybe related to memory management having happened at an inopportune time. A lot of conjecture there.

I've added more logging and started another test but It sometimes takes a day or so of robo-testing to make any error happen. I'll keep posting updates to this issue.

By the way, I want express my appreciation to all of the NS folks who've been helping me out with this.

Here is the stack trace with JS:

04-05 16:08:41.614  8007  8007 D TNS.Native: StackTrace: 
04-05 16:08:41.614  8007  8007 D TNS.Native:    Frame: function:'ViewBase._setupUI', file:'file:///data/data/com.kanayo.mymobilenative/files/app/tns_modules/tns-core-modules/ui/core/view-base/view-base.js', line: 424, column: 49
04-05 16:08:41.614  8007  8007 D TNS.Native:    Frame: function:'', file:'file:///data/data/com.kanayo.mymobilenative/files/app/tns_modules/tns-core-modules/ui/core/view-base/view-base.js', line: 456, column: 19
04-05 16:08:41.614  8007  8007 D TNS.Native:    Frame: function:'LayoutBaseCommon.eachChildView', file:'file:///data/data/com.kanayo.mymobilenative/files/app/tns_modules/tns-core-modules/ui/layouts/layout-base-common.js', line: 125, column: 26
04-05 16:08:41.614  8007  8007 D TNS.Native:    Frame: function:'ViewCommon.eachChild', file:'file:///data/data/com.kanayo.mymobilenative/files/app/tns_modules/tns-core-modules/ui/core/view/view-common.js', line: 699, column: 14
04-05 16:08:41.614  8007  8007 D TNS.Native:    Frame: function:'ViewBase._setupUI', file:'file:///data/data/com.kanayo.mymobilenative/files/app/tns_modules/tns-core-modules/ui/core/view-base/view-base.js', line: 455, column: 14
04-05 16:08:41.614  8007  8007 D TNS.Native:    Frame: function:'', file:'file:///data/data/com.kanayo.mymobilenative/files/app/tns_modules/tns-core-modules/ui/core/view-base/view-base.js', line: 456, column: 19
04-05 16:08:41.614  8007  8007 D TNS.Native:    Frame: function:'LayoutBaseCommon.eachChildView', file:'file:///data/data/com.kanayo.mymobilenative/files/app/tns_modules/tns-core-modules/ui/layouts/layout-base-common.js', line: 125, column: 26
04-05 16:08:41.614  8007  8007 D TNS.Native:    Frame: function:'ViewCommon.eachChild', file:'file:///data/data/com.kanayo.mymobilenative/files/app/tns_modules/tns-core-modules/ui/core/view/view-common.js', line: 699, column: 14
04-05 16:08:41.614  8007  8007 D TNS.Native:    Frame: function:'ViewBase._setupUI', file:'file:///data/data/com.kanayo.mymobilenative/files/app/tns_modules/tns-core-modules/ui/core/view-base/view-base.js', line: 455, column: 14
04-05 16:08:41.614  8007  8007 D TNS.Native:    Frame: function:'', file:'file:///data/data/com.kanayo.mymobilenative/files/app/tns_modules/tns-core-modules/ui/core/view-base/view-base.js', line: 456, column: 19
04-05 16:08:41.614  8007  8007 D TNS.Native:    Frame: function:'LayoutBaseCommon.eachChildView', file:'file:///data/data/com.kanayo.mymobilenative/files/app/tns_modules/tns-core-modules/ui/layouts/layout-base-common.js', line: 125, column: 26
04-05 16:08:41.614  8007  8007 D TNS.Native:    Frame: function:'ViewCommon.eachChild', file:'file:///data/data/com.kanayo.mymobilenative/files/app/tns_modules/tns-core-modules/ui/core/view/view-common.js', line: 699, column: 14
04-05 16:08:41.614  8007  8007 D TNS.Native:    Frame: function:'ViewBase._setupUI', file:'file:///data/data/com.kanayo.mymobilenative/files/app/tns_modules/tns-core-modules/ui/core/view-base/view-base.js', line: 455, column: 14
04-05 16:08:41.614  8007  8007 D TNS.Native:    Frame: function:'', file:'file:///data/data/com.kanayo.mymobilenative/files/app/tns_modules/tns-core-modules/ui/core/view-base/view-base.js', line: 456, column: 19
04-05 16:08:41.614  8007  8007 D TNS.Native:    Frame: function:'LayoutBaseCommon.eachChildView', file:'file:///data/data/com.kanayo.mymobilenative/files/app/tns_modules/tns-core-modules/ui/layouts/layout-base-common.js', line: 125, column: 26
04-05 16:08:41.614  8007  8007 D TNS.Native:    Frame: function:'ViewCommon.eachChild', file:'file:///data/data/com.kanayo.mymobilenative/files/app/tns_modules/tns-core-modules/ui/core/view/view-common.js', line: 699, column: 14
04-05 16:08:41.614  8007  8007 D TNS.Native:    Frame: function:'ViewBase._setupUI', file:'file:///data/data/com.kanayo.mymobilenative/files/app/tns_modules/tns-core-modules/ui/core/view-base/view-base.js', line: 455, column: 14
04-05 16:08:41.614  8007  8007 D TNS.Native:    Frame: function:'', file:'file:///data/data/com.kanayo.mymobilenative/files/app/tns_modules/tns-core-modules/ui/core/view-base/view-base.js', line: 456, column: 19
04-05 16:08:41.614  8007  8007 D TNS.Native:    Frame: function:'ContentView.eachChildView', file:'file:///data/data/com.kanayo.mymobilenative/files/app/tns_modules/tns-core-modules/ui/content-view/content-view.js', line: 70, column: 13
04-05 16:08:41.614  8007  8007 D TNS.Native:    Frame: function:'ViewCommon.eachChild', file:'file:///data/data/com.kanayo.mymobilenative/files/app/tns_modules/tns-core-modules/ui/core/view/view-common.js', line: 699, column: 14
04-05 16:08:41.614  8007  8007 D TNS.Native:    Frame: function:'ViewBase._setupUI', file:'file:///data/data/com.kanayo.mymobilenative/files/app/tns_modules/tns-core-modules/ui/core/view-base/view-base.js', line: 455, column: 14
04-05 16:08:41.614  8007  8007 D TNS.Native:    Frame: function:'ViewBase._addViewCore', file:'file:///data/data/com.kanayo.mymobilenative/files/app/tns_modules/tns-core-modules/ui/core/view-base/view-base.js', line: 357, column: 18
04-05 16:08:41.614  8007  8007 D TNS.Native:    Frame: function:'ViewBase._addView', file:'file:///data/data/com.kanayo.mymobilenative/files/app/tns_modules/tns-core-modules/ui/core/view-base/view-base.js', line: 346, column: 14
04-05 16:08:41.614  8007  8007 D TNS.Native:    Frame: function:'LayoutBaseCommon.addChild', file:'file:///data/data/com.kanayo.mymobilenative/files/app/tns_modules/tns-core-modules/ui/layouts/layout-base-common.js', line: 44, column: 14
04-05 16:08:41.614  8007  8007 D TNS.Native:    Frame: function:'ViewUtil.insertToLayout', file:'file:///data/data/com.kanayo.mymobilenative/files/app/tns_modules/nativescript-angular/view-util.js', line: 92, column: 20
04-05 16:08:41.614  8007  8007 D TNS.Native:    Frame: function:'ViewUtil.addToVisualTree', file:'file:///data/data/com.kanayo.mymobilenative/files/app/tns_modules/nativescript-angular/view-util.js', line: 73, column: 18
04-05 16:08:41.614  8007  8007 D TNS.Native:    Frame: function:'ViewUtil.insertChild', file:'file:///data/data/com.kanayo.mymobilenative/files/app/tns_modules/nativescript-angular/view-util.js', line: 41, column: 18
04-05 16:08:41.614  8007  8007 D TNS.Native:    Frame: function:'NativeScriptRenderer.insertBefore', file:'file:///data/data/com.kanayo.mymobilenative/files/app/tns_modules/nativescript-angular/renderer.js', line: 79, column: 23
04-05 16:08:41.614  8007  8007 D TNS.Native:    Frame: function:'DebugRenderer2.insertBefore', file:'file:///data/data/com.kanayo.mymobilenative/files/app/tns_modules/@angular/core/bundles/core.umd.js', line: 13654, column: 23
04-05 16:08:41.614  8007  8007 D TNS.Native:    Frame: function:'execRenderNodeAction', file:'file:///data/data/com.kanayo.mymobilenative/files/app/tns_modules/@angular/core/bundles/core.umd.js', line: 8930, column: 22
04-05 16:08:41.614  8007  8007 D TNS.Native:    Frame: function:'visitRenderNode', file:'file:///data/data/com.kanayo.mymobilenative/files/app/tns_modules/@angular/core/bundles/core.umd.js', line: 8901, column: 13
04-05 16:08:41.614  8007  8007 D TNS.Native:    Frame: function:'visitSiblingRenderNodes', file:'file:///data/data/com.kanayo.mymobilenative/files/app/tns_modules/@angular/core/bundles/core.umd.js', line: 8832, column: 13
04-05 16:08:41.614  8007  8007 D TNS.Native:    Frame: function:'visitRootRenderNodes', file:'file:///data/data/com.kanayo.mymobilenative/files/app/tns_modules/@angular/core/bundles/core.umd.js', line: 8816, column: 5
04-05 16:08:41.614  8007  8007 D TNS.Native:    Frame: function:'renderAttachEmbeddedView', file:'file:///data/data/com.kanayo.mymobilenative/files/app/tns_modules/@angular/core/bundles/core.umd.js', line: 9760, column: 5
04-05 16:08:41.614  8007  8007 D TNS.Native:    Frame: function:'attachEmbeddedView', file:'file:///data/data/com.kanayo.mymobilenative/files/app/tns_modules/@angular/core/bundles/core.umd.js', line: 9640, column: 5
04-05 16:08:41.614  8007  8007 D TNS.Native:    Frame: function:'ViewContainerRef_.insert', file:'file:///data/data/com.kanayo.mymobilenative/files/app/tns_modules/@angular/core/bundles/core.umd.js', line: 10106, column: 9
04-05 16:08:41.614  8007  8007 D TNS.Native:    Frame: function:'ViewContainerRef_.createEmbeddedView', file:'file:///data/data/com.kanayo.mymobilenative/files/app/tns_modules/@angular/core/bundles/core.umd.js', line: 10074, column: 14
04-05 16:08:41.614  8007  8007 D TNS.Native:    Frame: function:'', file:'file:///data/data/com.kanayo.mymobilenative/files/app/tns_modules/@angular/common/bundles/common.umd.js', line: 1740, column: 66
04-05 16:08:41.614  8007  8007 D TNS.Native:    Frame: function:'DefaultIterableDiffer.forEachOperation', file:'file:///data/data/com.kanayo.mymobilenative/files/app/tns_modules/@angular/core/bundles/core.umd.js', line: 6813, column: 17
04-05 16:08:41.614  8007  8007 D TNS.Native:    Frame: function:'NgForOf._applyChanges', file:'file:///data/data/com.kanayo.mymobilenative/files/app/tns_modules/@angular/common/bundles/common.umd.js', line: 1738, column: 17
04-05 16:08:41.614  8007  8007 D TNS.Native:    Frame: function:'NgForOf.ngDoCheck', file:'file:///data/data/com.kanayo.mymobilenative/files/app/tns_modules/@angular/common/bundles/common.umd.js', line: 1728, column: 22
04-05 16:08:41.614  8007  8007 D TNS.Native:    Frame: function:'checkAndUpdateDirectiveInline', file:'file:///data/data/com.kanayo.mymobilenative/files/app/tns_modules/@angular/core/bundles/core.umd.js', line: 10878, column: 19
04-05 16:08:41.614  8007  8007 D TNS.Native:    Frame: function:'checkAndUpdateNodeInline', file:'file:///data/data/com.kanayo.mymobilenative/files/app/tns_modules/@angular/core/bundles/core.umd.js', line: 12373, column: 20
04-05 16:08:41.614  8007  8007 D TNS.Native:    Frame: function:'checkAndUpdateNode', file:'file:///data/data/com.kanayo.mymobilenative/files/app/tns_modules/@angular/core/bundles/core.umd.js', line: 12316, column: 16
04-05 16:08:41.614  8007  8007 D TNS.Native:    Frame: function:'debugCheckAndUpdateNode', file:'file:///data/data/com.kanayo.mymobilenative/files/app/tns_modules/@angular/core/bundles/core.umd.js', line: 13173, column: 59
04-05 16:08:41.614  8007  8007 D TNS.Native:    Frame: function:'debugCheckDirectivesFn', file:'file:///data/data/com.kanayo.mymobilenative/files/app/tns_modules/@angular/core/bundles/core.umd.js', line: 13114, column: 13
04-05 16:08:41.614  8007  8007 D TNS.Native:    Frame: function:'View_ScheduleGroupPartial_0._co', file:'', line: 29, column: 5
04-05 16:08:41.614  8007  8007 D TNS.Native:    Frame: function:'debugUpdateDirectives', file:'file:///data/data/com.kanayo.mymobilenative/files/app/tns_modules/@angular/core/bundles/core.umd.js', line: 13099, column: 21
04-05 16:08:41.614  8007  8007 D TNS.Native:    Frame: function:'checkAndUpdateView', file:'file:///data/data/com.kanayo.mymobilenative/files/app/tns_modules/@angular/core/bundles/core.umd.js', line: 12283, column: 14
04-05 16:08:41.614  8007  8007 D TNS.Native:    Frame: function:'callViewAction', file:'file:///data/data/com.kanayo.mymobilenative/files/app/tns_modules/@angular/core/bundles/core.umd.js', line: 12631, column: 21
04-05 16:08:41.614  8007  8007 D TNS.Native:    Frame: function:'execComponentViewsAction', file:'file:///data/data/com.kanayo.mymobilenative/files/app/tns_modules/@angular/core/bundles/core.umd.js', line: 12563, column: 13
04-05 16:08:41.614  8007  8007 D TNS.Native:    Frame: function:'checkAndUpdateView', file:'file:///data/data/com.kanayo.mymobilenative/files/app/tns_modules/@angular/core/bundles/core.umd.js', line: 12289, column: 5
04-05 16:08:41.614  8007  8007 D TNS.Native:    Frame: function:'callWithDebugContext', file:'file:///data/data/com.kanayo.mymobilenative/files/app/tns_modules/@angular/core/bundles/core.umd.js', line: 13499, column: 42
04-05 16:08:41.614  8007  8007 D TNS.Native:    Frame: function:'debugCheckAndUpdateView', file:'file:///data/data/com.kanayo.mymobilenative/files/app/tns_modules/@angular/core/bundles/core.umd.js', line: 13039, column: 12
04-05 16:08:41.614  8007  8007 D TNS.Native:    Frame: function:'ViewRef_.detectChanges', file:'file:///data/data/com.kanayo.mymobilenative/files/app/tns_modules/@angular/core/bundles/core.umd.js', line: 10206, column: 18
04-05 16:08:41.614  8007  8007 D TNS.Native:    Frame: function:'PlanComponent.refreshSchedule', file:'file:///data/data/com.kanayo.mymobilenative/files/app/pages/plan/plan.component.js', line: 74, column: 24
04-05 16:08:41.614  8007  8007 D TNS.Native:    Frame: function:'', file:'file:///data/data/com.kanayo.mymobilenative/files/app/pages/plan/plan.component.js', line: 64, column: 19
04-05 16:08:41.614  8007  8007 D TNS.Native:    Frame: function:'ZoneDelegate.invokeTask', file:'file:///data/data/com.kanayo.mymobilenative/files/app/tns_modules/nativescript-angular/zone-js/dist/zone-nativescript.js', line: 398, column: 31
04-05 16:08:41.614  8007  8007 D TNS.Native:    Frame: function:'Zone.runTask', file:'file:///data/data/com.kanayo.mymobilenative/files/app/tns_modules/nativescript-angular/zone-js/dist/zone-nativescript.js', line: 165, column: 47
04-05 16:08:41.614  8007  8007 D TNS.Native:    Frame: function:'ZoneTask.invoke', file:'file:///data/data/com.kanayo.mymobilenative/files/app/tns_modules/nativescript-angular/zone-js/dist/zone-nativescript.js', line: 460, column: 38
04-05 16:08:41.614  8007  8007 D TNS.Native:    Frame: function:'timer', file:'file:///data/data/com.kanayo.mymobilenative/files/app/tns_modules/nativescript-angular/zone-js/dist/zone-nativescript.js', line: 1634, column: 29
04-05 16:08:41.614  8007  8007 D TNS.Native:    Frame: function:'invoke', file:'file:///data/data/com.kanayo.mymobilenative/files/app/tns_modules/tns-core-modules/timer/timer.js', line: 52, column: 48
04-05 16:08:41.614  8007  8007 D TNS.Native:    Frame: function:'ZoneDelegate.invoke', file:'file:///data/data/com.kanayo.mymobilenative/files/app/tns_modules/nativescript-angular/zone-js/dist/zone-nativescript.js', line: 365, column: 26
04-05 16:08:41.614  8007  8007 D TNS.Native:    Frame: function:'Zone.runGuarded', file:'file:///data/data/com.kanayo.mymobilenative/files/app/tns_modules/nativescript-angular/zone-js/dist/zone-nativescript.js', line: 138, column: 47
04-05 16:08:41.614  8007  8007 D TNS.Native:    Frame: function:'', file:'file:///data/data/com.kanayo.mymobilenative/files/app/tns_modules/nativescript-angular/zone-js/dist/zone-nativescript.js', line: 116, column: 29
04-05 16:08:41.614  8007  8007 D TNS.Native:    Frame: function:'run', file:'file:///data/data/com.kanayo.mymobilenative/files/app/tns_modules/tns-core-modules/timer/timer.js', line: 56, column: 13
04-05 16:08:41.614  8007  8007 D TNS.Java: Platform.getJavaObjectByID:40995
04-05 16:08:41.614  8007  8007 D AndroidRuntime: Shutting down VM
04-05 16:08:41.624  8007  8007 W System.err: com.tns.NativeScriptException: Attempt to use cleared object reference id=38608
04-05 16:08:41.624  8007  8007 W System.err:    at com.tns.Runtime.getJavaObjectByID(Runtime.java:897)
04-05 16:08:41.624  8007  8007 W System.err:    at com.tns.Runtime.callJSMethodNative(Native Method)
04-05 16:08:41.624  8007  8007 W System.err:    at com.tns.Runtime.dispatchCallJSMethodNative(Runtime.java:1088)
04-05 16:08:41.624  8007  8007 W System.err:    at com.tns.Runtime.callJSMethodImpl(Runtime.java:970)
04-05 16:08:41.624  8007  8007 W System.err:    at com.tns.Runtime.callJSMethod(Runtime.java:957)
04-05 16:08:41.624  8007  8007 W System.err:    at com.tns.Runtime.callJSMethod(Runtime.java:941)
04-05 16:08:41.624  8007  8007 W System.err:    at com.tns.Runtime.callJSMethod(Runtime.java:933)
04-05 16:08:41.624  8007  8007 W System.err:    at com.tns.gen.java.lang.Runnable.run(Runnable.java:10)
04-05 16:08:41.624  8007  8007 W System.err:    at android.os.Handler.handleCallback(Handler.java:739)
04-05 16:08:41.624  8007  8007 W System.err:    at android.os.Handler.dispatchMessage(Handler.java:95)
04-05 16:08:41.624  8007  8007 W System.err:    at android.os.Looper.loop(Looper.java:158)
04-05 16:08:41.624  8007  8007 W System.err:    at android.app.ActivityThread.main(ActivityThread.java:7224)
04-05 16:08:41.624  8007  8007 W System.err:    at java.lang.reflect.Method.invoke(Native Method)
04-05 16:08:41.624  8007  8007 W System.err:    at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:1230)
04-05 16:08:41.624  8007  8007 W System.err:    at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:1120)
04-05 16:08:41.624  8007  8007 D TNS.Java: Uncaught Exception Message=An uncaught Exception occurred on "main" thread.
04-05 16:08:41.624  8007  8007 D TNS.Java: com.tns.NativeScriptException: Attempt to use cleared object reference id=38608
04-05 16:08:41.624  8007  8007 D TNS.Java:  at com.tns.Runtime.getJavaObjectByID(Runtime.java:897)
04-05 16:08:41.624  8007  8007 D TNS.Java:  at com.tns.Runtime.callJSMethodNative(Native Method)
04-05 16:08:41.624  8007  8007 D TNS.Java:  at com.tns.Runtime.dispatchCallJSMethodNative(Runtime.java:1088)
04-05 16:08:41.624  8007  8007 D TNS.Java:  at com.tns.Runtime.callJSMethodImpl(Runtime.java:970)
04-05 16:08:41.624  8007  8007 D TNS.Java:  at com.tns.Runtime.callJSMethod(Runtime.java:957)
04-05 16:08:41.624  8007  8007 D TNS.Java:  at com.tns.Runtime.callJSMethod(Runtime.java:941)
04-05 16:08:41.624  8007  8007 D TNS.Java:  at com.tns.Runtime.callJSMethod(Runtime.java:933)
04-05 16:08:41.624  8007  8007 D TNS.Java:  at com.tns.gen.java.lang.Runnable.run(Runnable.java:10)
04-05 16:08:41.624  8007  8007 D TNS.Java:  at android.os.Handler.handleCallback(Handler.java:739)
04-05 16:08:41.624  8007  8007 D TNS.Java:  at android.os.Handler.dispatchMessage(Handler.java:95)
04-05 16:08:41.624  8007  8007 D TNS.Java:  at android.os.Looper.loop(Looper.java:158)
04-05 16:08:41.624  8007  8007 D TNS.Java:  at android.app.ActivityThread.main(ActivityThread.java:7224)
04-05 16:08:41.624  8007  8007 D TNS.Java:  at java.lang.reflect.Method.invoke(Native Method)
04-05 16:08:41.624  8007  8007 D TNS.Java:  at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:1230)
04-05 16:08:41.624  8007  8007 D TNS.Java:  at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:1120)
pana-cc commented 6 years ago

The intervals create java.lang.Runnable objects, that are stored in the timer module in the timeoutCallbacks, they are kept there until intervals are cleared or until timeouts tick: https://github.com/NativeScript/NativeScript/blob/a316e53d547b1de797e6b7cd36fb07d1f37d2482/tns-core-modules/timer/timer.android.ts#L65 I am not sure how exactly the timer may glitch. Also you said the view is removed, and perhaps later added by the timer? When is the view removed? What events or triggers cause it to be removed? I wonder if it is possible to have the view removed from the visual tree and kept in another handler's closure, one that is not strongly referenced and later from its callback the view to be handed over to the timer but has its Java instance already collected, so when the timer adds it to a visual tree it is already in incorrect state?

It would be very helpful for us to collect as much as possible JavaScript stacks with these "Attempt to use cleared object reference". Also what is the severity of these crashes? You mentioned the last one may run for a day before it crashes? Are there other crashes that are not caused by the "Attempt to use cleared object reference"? Have you tried to run the app without "markingMode: none" and check if it will produce other errors?

gsmedley commented 6 years ago

From the timer I'm forcing a page to redraw like this. 

  doDetectChanges(cdRef: ChangeDetectorRef){
    if (!cdRef['destroyed']) {
        cdRef.detectChanges();
    }
}

So there is no manipulation of the view objects from code. The timer is cleared when a page is unloaded, but maybe there is a race condition, or I'm using detectChanges(); incorrectly.

Sometimes it's a day before a crash, sometimes it's an hour. The unpredictability makes it severe.

We do get other crashes, in the Graphing code and the Drawer code, that are also hard to reproduce. We've drawn/redrawn graphs thousands of times without a problem, then during one test, there will be a crash. We're following up on those in separate issues.

Good idea about running with "markingMode: none" off. That could help isolate the problems. I'll set up a test for that and let you know what happens.

gsmedley commented 6 years ago

Just wanted to post an update on our robo-testing efforts. We have now been running without a crash for 3 days, which is a record.

We currently have one blocker, graphs will crash after drawing about 3000 of them. This has been reported before, see issue 618 We're currently leaving graphs out of the testing so we can make sure the rest of the app is working.

We also see this one very rarely, System.err: TypeError: Cannot read property 'delete' of undefined. Seems to be related to Drawer control animations.

Here is how we solved the issues we were seeing:

  1. TypeError: Cannot read property 'key' of undefined This happens sometimes when you go back after using clearHistory. We added a canGoBack() check before calling back(), and that seems to have solved it.

  2. com.tns.NativeScriptException: Attempt to use cleared object reference id= This happened when calling cdRef.detectChanges(); from a timer. Put a try/catch around it so we could continue after this.

  3. com.tns.NativeScriptException: Attempt to use cleared object reference id= This also happened when using our own plugins, which we have made markingMode: none safe. See the discussion in the comments of https://panayotcankov.github.io/nativescript-3.2.0-memory-management/

  4. System.err: java.lang.NullPointerException: Attempt to invoke virtual method 'boolean java.lang.Boolean.booleanValue()' on a null object reference This was related to text fields, used the fix posted in #5130

pana-cc commented 6 years ago

The solution 2 is weak. You can not simply try/catch these errors, perhaps the execution of the program continued, but the native views setup is done recursively and once it throws there would be a big chunk of the visual tree in a wrong state (texts not updated, missing views, white screen etc.) This error is either due to the timer not preserving properly the native callback object (although we've gone a few times through it and it seems fine) or due to the views are handled in other callback that are eligible for collection, it is also possible that after the fix 3 the problem in 2 may be less severe. Did you apply 2 before 3 and if so, could you run the tests without the try/catch in 2 while waiting for the charts issue?

gsmedley commented 6 years ago

I wasn't happy with that try/catch either, but I think we've found what caused #2. The timeouts are used to update pages that show a schedule and need to be regularly updated. setInterval is called on a navigatedToEvent and cleared on a navigatedFromEvent or in ngOnDestroy, whichever comes first. There was a mistake in the clear code so some of the the timeouts kept running after the page was gone.

Since making this fix we are down to 618 as our only blocker.

vtrifonov commented 6 years ago

@gsmedley the issues with

System.err: TypeError: Cannot read property 'delete' of undefined.

Seems to be fixed with the following commit: https://github.com/NativeScript/NativeScript/commit/cf950e1ebbf4fd388cd44ff4527c77c11c024525

vtrifonov commented 6 years ago

@gsmedley do you still have problems with your project or it is OK to close the issue?

gsmedley commented 6 years ago

@vtrifonov -

I think you can close it. The remaining problems are with the graphs and there are separate issues for those. Excluding those we've been able to run continuous monkey tests for over 10 days without a crash. Thanks again for all the help with this!