Skip to content

fix: missing logs when __enableVerboseLogging is called #4334

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

Merged
merged 1 commit into from
Feb 4, 2019
+52 −24
Merged

fix: missing logs when __enableVerboseLogging is called #4334

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
3 changes: 2 additions & 1 deletion lib/common/mobile/android/android-log-filter.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -35,7 +35,8 @@ export class AndroidLogFilter implements Mobile.IPlatformLogFilter {
return null;
}

const acceptedTags = ["chromium", "Web Console", "JS", "ActivityManager", "System.err"];
// Messages with category TNS.Native and TNS.Java will be printed by runtime to Logcat only when `__enableVerboseLogging()` is called in the application.
const acceptedTags = ["chromium", "Web Console", "JS", "ActivityManager", "System.err", "TNS.Native", "TNS.Java"];

let consoleLogMessage: { tag?: string, message: string };

Expand Down
73 changes: 50 additions & 23 deletions lib/common/test/unit-tests/android-log-filter.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -28,7 +28,7 @@ const androidApiLevel23TestData = [
output: 'chromium: [INFO:CONSOLE(1)] "Uncaught ReferenceError: start is not defined", source: file:///data/user/0/com.telerik.app1/files/12590FAA-5EDD-4B12-856D-F52A0A1599F2/index.html (1)'
},
{ input: '12-28 10:16:49.267 779 1172 I ActivityManager: Start proc 3714:org.nativescript.appDebug1/u0a60 for activity org.nativescript.appDebug1/com.tns.NativeScriptActivity', output: 'ActivityManager: Start proc 3714:org.nativescript.appDebug1/u0a60 for activity org.nativescript.appDebug1/com.tns.NativeScriptActivity' },
{ input: '12-28 10:16:49.316 3714 3714 I TNS.Native: NativeScript Runtime Version 1.5.1, commit c27e977f059e37b3f8230722a4687e16acf43a7f', output: null },
{ input: '12-28 10:16:49.316 3714 3714 I TNS.Runtime: NativeScript Runtime Version 1.5.1, commit c27e977f059e37b3f8230722a4687e16acf43a7f', output: null },
{ input: '12-28 10:16:49.710 3714 3714 V JS : TAPPED: 42', output: 'JS: TAPPED: 42' },
{ input: '12-28 10:16:49.775 3714 3714 D NativeScriptActivity: NativeScriptActivity.onCreate called', output: null },
{
Expand Down Expand Up @@ -90,12 +90,12 @@ const androidApiLevel22TestData = [
input: 'I/Web Console( 4438): Received Event: deviceready at file:///storage/emulated/0/Icenium/com.telerik.TestApp/js/index.js:48',
output: 'Web Console: Received Event: deviceready at file:///storage/emulated/0/Icenium/com.telerik.TestApp/js/index.js:48'
},
{ input: "I/TNS.Native( 4502): NativeScript Runtime Version 5.1.0, commit 4497f43b69cb57ce65ece2aac5b98b2010f85857", output: null },
{ input: "D/TNS.Native( 4502): JNI_ONLoad", output: null },
{ input: "D/TNS.Native( 4502): JNI_ONLoad END", output: null },
{ input: "D/TNS.Native( 4502): V8 version 6.9.427.23", output: null },
{ input: "D/TNS.Native( 4502): lenNodes=79716, lenNames=901566, lenValues=1062800", output: null },
{ input: "D/TNS.Native( 4502): time=1", output: null },
{ input: "I/TNS.Runtime( 4502): NativeScript Runtime Version 5.1.0, commit 4497f43b69cb57ce65ece2aac5b98b2010f85857", output: null },
{ input: "D/TNS.Runtime( 4502): JNI_ONLoad", output: null },
{ input: "D/TNS.Runtime( 4502): JNI_ONLoad END", output: null },
{ input: "D/TNS.Runtime( 4502): V8 version 6.9.427.23", output: null },
{ input: "D/TNS.Native( 4502): lenNodes=79716, lenNames=901566, lenValues=1062800", output: "TNS.Native: lenNodes=79716, lenNames=901566, lenValues=1062800" },
{ input: "D/TNS.Native( 4502): time=1", output: "TNS.Native: time=1" },
{ input: "W/art ( 4502): Before Android 4.1, method android.graphics.PorterDuffColorFilter android.support.graphics.drawable.VectorDrawableCompat.updateTintFilter(android.graphics.PorterDuffColorFilter, android.content.res.ColorStateList, android.graphics.PorterDuff$Mode) would have incorrectly overridden the package-private method in android.graphics.drawable.Drawable", output: null },
{ input: "I/art ( 4502): Rejecting re-init on previously-failed class java.lang.Class<android.support.v4.view.ViewCompat$OnUnhandledKeyEventListenerWrapper>", output: null },
{ input: "I/art ( 4502): Rejecting re-init on previously-failed class java.lang.Class<android.support.v4.view.ViewCompat$OnUnhandledKeyEventListenerWrapper>", output: null },
Expand All @@ -116,8 +116,8 @@ const androidApiLevel22TestData = [

const androidApiLevel23MapForPid8141 = [
{ input: "--------- of main", output: null },
{ input: "07-25 06:36:22.590 8141 8141 D TNS.Native: lenNodes=71568, lenNames=824195, lenValues=963214", output: null },
{ input: "07-25 06:36:22.590 8141 8141 D TNS.Native: time=1", output: null },
{ input: "07-25 06:36:22.590 8141 8141 D TNS.Native: lenNodes=71568, lenNames=824195, lenValues=963214", output: "TNS.Native: lenNodes=71568, lenNames=824195, lenValues=963214" },
{ input: "07-25 06:36:22.590 8141 8141 D TNS.Native: time=1", output: "TNS.Native: time=1" },
{ input: "07-25 06:36:23.065 739 760 I Choreographer: Skipped 54 frames! The application may be doing too much work on its main thread.", output: null },
{ input: "07-25 06:36:23.149 8141 8141 W art : Before Android 4.1, method android.graphics.PorterDuffColorFilter android.support.graphics.drawable.VectorDrawableCompat.updateTintFilter(android.graphics.PorterDuffColorFilter, android.content.res.ColorStateList, android.graphics.PorterDuff$Mode) would have incorrectly overridden the package-private method in android.graphics.drawable.Drawable", output: null },
{ input: "07-25 06:36:23.298 8141 8141 D : HostConnection::get() New Host Connection established 0xd3916970, tid 8141", output: null },
Expand All @@ -143,11 +143,11 @@ const androidApiLevel23MapForPid8141 = [
{ input: "07-25 06:36:38.327 8183 8183 I art : Late-enabling -Xcheck:jni", output: null },
{ input: "07-25 06:36:38.327 8183 8183 W art : Unexpected CPU variant for X86 using defaults: x86", output: null },
{ input: "07-25 06:36:38.335 739 1212 I ActivityManager: Start proc 8183:org.nativescript.a2test/u0a122 for activity org.nativescript.a2test/com.tns.NativeScriptActivity", output: null },
{ input: "07-25 06:36:38.406 8183 8183 I TNS.Native: NativeScript Runtime Version 3.0.1, commit 733bfa5fab5d4c156eab156eaf01946eb36dab1e", output: null },
{ input: "07-25 06:36:38.406 8183 8183 D TNS.Native: JNI_ONLoad", output: null },
{ input: "07-25 06:36:38.406 8183 8183 D TNS.Native: JNI_ONLoad END", output: null },
{ input: "07-25 06:36:38.424 8183 8183 D TNS.Native: Failed to load snapshot: dlopen failed: library \"libsnapshot.so\" not found", output: null },
{ input: "07-25 06:36:38.534 8183 8183 D TNS.Native: V8 version 5.5.372.32", output: null },
{ input: "07-25 06:36:38.406 8183 8183 I TNS.Runtime: NativeScript Runtime Version 3.0.1, commit 733bfa5fab5d4c156eab156eaf01946eb36dab1e", output: null },
{ input: "07-25 06:36:38.406 8183 8183 D TNS.Runtime: JNI_ONLoad", output: null },
{ input: "07-25 06:36:38.406 8183 8183 D TNS.Runtime: JNI_ONLoad END", output: null },
{ input: "07-25 06:36:38.424 8183 8183 D TNS.Runtime: Failed to load snapshot: dlopen failed: library \"libsnapshot.so\" not found", output: null },
{ input: "07-25 06:36:38.534 8183 8183 D TNS.Runtime: V8 version 5.5.372.32", output: null },
{ input: "07-25 06:36:38.675 8183 8183 D TNS.Native: lenNodes=66492, lenNames=775380, lenValues=899324", output: null },
{ input: "07-25 06:36:38.675 8183 8183 D TNS.Native: time=24", output: null },
{ input: "07-25 06:36:39.376 739 760 I Choreographer: Skipped 55 frames! The application may be doing too much work on its main thread.", output: null },
Expand Down Expand Up @@ -222,17 +222,17 @@ const androidApiLevel23MapForPid8141 = [
{ input: "07-25 06:37:05.084 739 751 I ActivityManager: Start proc 8244:org.nativescript.personalalarm/u0a64 for activity org.nativescript.personalalarm/com.tns.ErrorReportActivity", output: null },
{ input: "07-25 06:37:05.084 8244 8244 I art : Late-enabling -Xcheck:jni", output: null },
{ input: "07-25 06:37:05.085 8244 8244 W art : Unexpected CPU variant for X86 using defaults: x86", output: null },
{ input: "07-25 06:37:05.212 8244 8244 I TNS.Native: NativeScript Runtime Version 3.1.1, commit 253c76f850b88b0119fda04e413626872f223de5", output: null },
{ input: "07-25 06:37:05.213 8244 8244 D TNS.Native: JNI_ONLoad", output: null },
{ input: "07-25 06:37:05.213 8244 8244 D TNS.Native: JNI_ONLoad END", output: null },
{ input: "02-01 13:29:22.990 8141 8141 I TNS.Native: NativeScript Runtime Version 5.1.0, commit 4497f43b69cb57ce65ece2aac5b98b2010f85857", output: null },
{ input: "02-01 13:29:22.991 8141 8141 D TNS.Native: JNI_ONLoad", output: null },
{ input: "02-01 13:29:22.991 8141 8141 D TNS.Native: JNI_ONLoad END", output: null },
{ input: "07-25 06:37:05.212 8244 8244 I TNS.Runtime: NativeScript Runtime Version 3.1.1, commit 253c76f850b88b0119fda04e413626872f223de5", output: null },
{ input: "07-25 06:37:05.213 8244 8244 D TNS.Runtime: JNI_ONLoad", output: null },
{ input: "07-25 06:37:05.213 8244 8244 D TNS.Runtime: JNI_ONLoad END", output: null },
{ input: "02-01 13:29:22.990 8141 8141 I TNS.Runtime: NativeScript Runtime Version 5.1.0, commit 4497f43b69cb57ce65ece2aac5b98b2010f85857", output: null },
{ input: "02-01 13:29:22.991 8141 8141 D TNS.Runtime: JNI_ONLoad", output: null },
{ input: "02-01 13:29:22.991 8141 8141 D TNS.Runtime: JNI_ONLoad END", output: null },
{ input: "02-01 13:29:23.027 1344 1351 D gralloc_ranchu: gralloc_alloc: Creating ashmem region of size 8294400", output: null },
{ input: "02-01 13:29:23.043 1652 1661 I art : Background partial concurrent mark sweep GC freed 975(53KB) AllocSpace objects, 0(0B) LOS objects, 17% free, 18MB/22MB, paused 4.347ms total 122.768ms", output: null },
{ input: "02-01 13:29:23.061 8141 8141 D TNS.Native: V8 version 6.9.427.23", output: null },
{ input: "02-01 13:29:23.067 8141 8141 D TNS.Native: lenNodes=79716, lenNames=901564, lenValues=1062800", output: null },
{ input: "02-01 13:29:23.067 8141 8141 D TNS.Native: time=2", output: null },
{ input: "02-01 13:29:23.061 8141 8141 D TNS.Runtime: V8 version 6.9.427.23", output: null },
{ input: "02-01 13:29:23.067 8141 8141 D TNS.Native: lenNodes=79716, lenNames=901564, lenValues=1062800", output: "TNS.Native: lenNodes=79716, lenNames=901564, lenValues=1062800" },
{ input: "02-01 13:29:23.067 8141 8141 D TNS.Native: time=2", output: "TNS.Native: time=2" },
{ input: "02-01 13:29:23.155 2288 2390 D EGL_emulation: eglMakeCurrent: 0xa037ba00: ver 2 0 (tinfo 0x92b47100)", output: null },
{ input: "02-01 13:29:23.450 8141 8141 W art : Before Android 4.1, method android.graphics.PorterDuffColorFilter android.support.graphics.drawable.VectorDrawableCompat.updateTintFilter(android.graphics.PorterDuffColorFilter, android.content.res.ColorStateList, android.graphics.PorterDuff$Mode) would have incorrectly overridden the package-private method in android.graphics.drawable.Drawable", output: null },
{ input: "02-01 13:29:23.576 8141 4663 I art : Background sticky concurrent mark sweep GC freed 20657(1509KB) AllocSpace objects, 7(140KB) LOS objects, 0% free, 11MB/11MB, paused 12.708ms total 102.843ms", output: null },
Expand Down Expand Up @@ -289,6 +289,33 @@ const androidApiLevel23MapForPid8141 = [
{ input: "02-01 13:29:23.994 8141 8141 I art : at java.lang.Object java.lang.reflect.Method.invoke!(java.lang.Object, java.lang.Object[]) (Method.java:-2)", output: null },
{ input: "02-01 13:29:23.994 8141 8141 I art : at void com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run() (ZygoteInit.java:866)", output: null },
{ input: "02-01 13:29:23.994 8141 8141 I art : at void com.android.internal.os.ZygoteInit.main(java.lang.String[]) (ZygoteInit.java:756)", output: null },
{ input: "02-04 15:54:54.440 8141 8141 D TNS.Native: createJSInstanceNative called", output: "TNS.Native: createJSInstanceNative called" },
{ input: "02-04 15:54:54.440 8141 8141 D TNS.Native: createJSInstanceNative class com/tns/NativeScriptActivity", output: "TNS.Native: createJSInstanceNative class com/tns/NativeScriptActivity" },
{ input: "02-04 15:54:54.440 8141 8141 D TNS.Native: createJSInstanceNative: implementationObject :82225", output: "TNS.Native: createJSInstanceNative: implementationObject :82225" },
{ input: "02-04 15:54:54.440 8141 8141 D TNS.Java: JSInstance for class com.tns.NativeScriptActivity created with overrides", output: "TNS.Java: JSInstance for class com.tns.NativeScriptActivity created with overrides" },
{ input: "02-04 15:54:54.448 8141 8141 D TNS.Java: Platform.CallJSMethod: calling js method onCreate with javaObjectID 3 type=com.tns.NativeScriptActivity", output: "TNS.Java: Platform.CallJSMethod: calling js method onCreate with javaObjectID 3 type=com.tns.NativeScriptActivity" },
{ input: "02-04 15:54:54.449 8141 8141 D TNS.Native: CallJSMethodNative called javaObjectID=3", output: "TNS.Native: CallJSMethodNative called javaObjectID=3" },
{ input: "02-04 15:54:54.449 8141 8141 D TNS.Native: CallJSMethodNative called jsObject=335940", output: "TNS.Native: CallJSMethodNative called jsObject=335940" },
{ input: "02-04 15:54:54.516 8141 8141 D TNS.Java: Platform.CallJSMethod: calling js method onActivityCreated with javaObjectID 1 type=com.tns.gen.android.app.Application_ActivityLifecycleCallbacks", output: "TNS.Java: Platform.CallJSMethod: calling js method onActivityCreated with javaObjectID 1 type=com.tns.gen.android.app.Application_ActivityLifecycleCallbacks" },
{ input: "02-04 15:54:54.516 8141 8141 D TNS.Native: CallJSMethodNative called javaObjectID=1", output: "TNS.Native: CallJSMethodNative called javaObjectID=1" },
{ input: "02-04 15:54:54.516 8141 8141 D TNS.Native: CallJSMethodNative called jsObject=572643", output: "TNS.Native: CallJSMethodNative called jsObject=572643" },
{ input: "02-04 15:54:54.630 8141 8141 D TNS.Native: com.tns.Runtime.callJSMethodNative(Native Method)", output: "TNS.Native: com.tns.Runtime.callJSMethodNative(Native Method)" },
{ input: "02-04 15:54:54.630 8141 8141 D TNS.Native: com.tns.Runtime.dispatchCallJSMethodNative(Runtime.java:1120)", output: "TNS.Native: com.tns.Runtime.dispatchCallJSMethodNative(Runtime.java:1120)" },
{ input: "02-04 15:54:54.630 8141 8141 D TNS.Native: com.tns.Runtime.callJSMethodImpl(Runtime.java:1000)", output: "TNS.Native: com.tns.Runtime.callJSMethodImpl(Runtime.java:1000)" },
{ input: "02-04 15:54:54.630 8141 8141 D TNS.Native: com.tns.Runtime.callJSMethod(Runtime.java:987)", output: "TNS.Native: com.tns.Runtime.callJSMethod(Runtime.java:987)" },
{ input: "02-04 15:54:54.630 8141 8141 D TNS.Native: com.tns.Runtime.callJSMethod(Runtime.java:967)", output: "TNS.Native: com.tns.Runtime.callJSMethod(Runtime.java:967)" },
{ input: "02-04 15:54:54.630 8141 8141 D TNS.Native: com.tns.Runtime.callJSMethod(Runtime.java:959)", output: "TNS.Native: com.tns.Runtime.callJSMethod(Runtime.java:959)" },
{ input: "02-04 15:54:55.100 8141 8141 D TNS.Java: Platform.CallJSMethod: calling js method onStart with javaObjectID 3 type=com.tns.NativeScriptActivity", output: "TNS.Java: Platform.CallJSMethod: calling js method onStart with javaObjectID 3 type=com.tns.NativeScriptActivity" },
{ input: "02-04 15:54:55.100 8141 8141 D TNS.Native: CallJSMethodNative called javaObjectID=3", output: "TNS.Native: CallJSMethodNative called javaObjectID=3" },
{ input: "02-04 15:54:55.100 8141 8141 D TNS.Native: CallJSMethodNative called jsObject=335940", output: "TNS.Native: CallJSMethodNative called jsObject=335940" },
{ input: "02-04 15:54:55.101 8141 8141 D TNS.Java: Platform.CallJSMethod: calling js method onActivityStarted with javaObjectID 1 type=com.tns.gen.android.app.Application_ActivityLifecycleCallbacks", output: "TNS.Java: Platform.CallJSMethod: calling js method onActivityStarted with javaObjectID 1 type=com.tns.gen.android.app.Application_ActivityLifecycleCallbacks" },
{ input: "02-04 15:54:55.101 8141 8141 D TNS.Native: CallJSMethodNative called javaObjectID=1", output: "TNS.Native: CallJSMethodNative called javaObjectID=1" },
{ input: "02-04 15:54:55.101 8141 8141 D TNS.Native: CallJSMethodNative called jsObject=572643", output: "TNS.Native: CallJSMethodNative called jsObject=572643" },
{ input: "02-04 15:54:55.180 8141 8141 D TNS.Java: Platform.CallJSMethod: calling js method onActivityResumed with javaObjectID 1 type=com.tns.gen.android.app.Application_ActivityLifecycleCallbacks", output: "TNS.Java: Platform.CallJSMethod: calling js method onActivityResumed with javaObjectID 1 type=com.tns.gen.android.app.Application_ActivityLifecycleCallbacks" },
{ input: "02-04 15:54:55.180 8141 8141 D TNS.Native: CallJSMethodNative called javaObjectID=1", output: "TNS.Native: CallJSMethodNative called javaObjectID=1" },
{ input: "02-04 15:54:55.180 8141 8141 D TNS.Native: CallJSMethodNative called jsObject=572643", output: "TNS.Native: CallJSMethodNative called jsObject=572643" },
{ input: "02-04 15:54:55.216 8141 8141 D TNS.Java: Platform.CallJSMethod: calling js method onViewAttachedToWindow with javaObjectID 75 type=com.tns.gen.java.lang.Object_frame_29_36_AttachListener", output: "TNS.Java: Platform.CallJSMethod: calling js method onViewAttachedToWindow with javaObjectID 75 type=com.tns.gen.java.lang.Object_frame_29_36_AttachListener" },
{ input: "02-04 15:54:55.216 8141 8141 D TNS.Native: CallJSMethodNative called javaObjectID=75", output: "TNS.Native: CallJSMethodNative called javaObjectID=75" },
];

describe("androidLogFilter", () => {
Expand Down