Skip to content

Commit 889a6d3

Browse files
rosen-vladimirovrosen-vladimirov
authored
Merge pull request #4334 from NativeScript/vladimirov/fix-enable-verbose-logging
fix: missing logs when `__enableVerboseLogging` is called
2 parents 1a08b52 + e4d8d9e commit 889a6d3

File tree

2 files changed

+52
-24
lines changed

2 files changed

+52
-24
lines changed

‎lib/common/mobile/android/android-log-filter.ts

+2-1
Original file line numberDiff line numberDiff line change
@@ -35,7 +35,8 @@ export class AndroidLogFilter implements Mobile.IPlatformLogFilter {
3535
return null;
3636
}
3737

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

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

‎lib/common/test/unit-tests/android-log-filter.ts

+50-23
Original file line numberDiff line numberDiff line change
@@ -28,7 +28,7 @@ const androidApiLevel23TestData = [
2828
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)'
2929
},
3030
{ 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' },
31-
{ input: '12-28 10:16:49.316 3714 3714 I TNS.Native: NativeScript Runtime Version 1.5.1, commit c27e977f059e37b3f8230722a4687e16acf43a7f', output: null },
31+
{ input: '12-28 10:16:49.316 3714 3714 I TNS.Runtime: NativeScript Runtime Version 1.5.1, commit c27e977f059e37b3f8230722a4687e16acf43a7f', output: null },
3232
{ input: '12-28 10:16:49.710 3714 3714 V JS : TAPPED: 42', output: 'JS: TAPPED: 42' },
3333
{ input: '12-28 10:16:49.775 3714 3714 D NativeScriptActivity: NativeScriptActivity.onCreate called', output: null },
3434
{
@@ -90,12 +90,12 @@ const androidApiLevel22TestData = [
9090
input: 'I/Web Console( 4438): Received Event: deviceready at file:///storage/emulated/0/Icenium/com.telerik.TestApp/js/index.js:48',
9191
output: 'Web Console: Received Event: deviceready at file:///storage/emulated/0/Icenium/com.telerik.TestApp/js/index.js:48'
9292
},
93-
{ input: "I/TNS.Native( 4502): NativeScript Runtime Version 5.1.0, commit 4497f43b69cb57ce65ece2aac5b98b2010f85857", output: null },
94-
{ input: "D/TNS.Native( 4502): JNI_ONLoad", output: null },
95-
{ input: "D/TNS.Native( 4502): JNI_ONLoad END", output: null },
96-
{ input: "D/TNS.Native( 4502): V8 version 6.9.427.23", output: null },
97-
{ input: "D/TNS.Native( 4502): lenNodes=79716, lenNames=901566, lenValues=1062800", output: null },
98-
{ input: "D/TNS.Native( 4502): time=1", output: null },
93+
{ input: "I/TNS.Runtime( 4502): NativeScript Runtime Version 5.1.0, commit 4497f43b69cb57ce65ece2aac5b98b2010f85857", output: null },
94+
{ input: "D/TNS.Runtime( 4502): JNI_ONLoad", output: null },
95+
{ input: "D/TNS.Runtime( 4502): JNI_ONLoad END", output: null },
96+
{ input: "D/TNS.Runtime( 4502): V8 version 6.9.427.23", output: null },
97+
{ input: "D/TNS.Native( 4502): lenNodes=79716, lenNames=901566, lenValues=1062800", output: "TNS.Native: lenNodes=79716, lenNames=901566, lenValues=1062800" },
98+
{ input: "D/TNS.Native( 4502): time=1", output: "TNS.Native: time=1" },
9999
{ 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 },
100100
{ input: "I/art ( 4502): Rejecting re-init on previously-failed class java.lang.Class<android.support.v4.view.ViewCompat$OnUnhandledKeyEventListenerWrapper>", output: null },
101101
{ input: "I/art ( 4502): Rejecting re-init on previously-failed class java.lang.Class<android.support.v4.view.ViewCompat$OnUnhandledKeyEventListenerWrapper>", output: null },
@@ -116,8 +116,8 @@ const androidApiLevel22TestData = [
116116

117117
const androidApiLevel23MapForPid8141 = [
118118
{ input: "--------- of main", output: null },
119-
{ input: "07-25 06:36:22.590 8141 8141 D TNS.Native: lenNodes=71568, lenNames=824195, lenValues=963214", output: null },
120-
{ input: "07-25 06:36:22.590 8141 8141 D TNS.Native: time=1", output: null },
119+
{ 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" },
120+
{ input: "07-25 06:36:22.590 8141 8141 D TNS.Native: time=1", output: "TNS.Native: time=1" },
121121
{ 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 },
122122
{ 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 },
123123
{ input: "07-25 06:36:23.298 8141 8141 D : HostConnection::get() New Host Connection established 0xd3916970, tid 8141", output: null },
@@ -143,11 +143,11 @@ const androidApiLevel23MapForPid8141 = [
143143
{ input: "07-25 06:36:38.327 8183 8183 I art : Late-enabling -Xcheck:jni", output: null },
144144
{ input: "07-25 06:36:38.327 8183 8183 W art : Unexpected CPU variant for X86 using defaults: x86", output: null },
145145
{ 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 },
146-
{ input: "07-25 06:36:38.406 8183 8183 I TNS.Native: NativeScript Runtime Version 3.0.1, commit 733bfa5fab5d4c156eab156eaf01946eb36dab1e", output: null },
147-
{ input: "07-25 06:36:38.406 8183 8183 D TNS.Native: JNI_ONLoad", output: null },
148-
{ input: "07-25 06:36:38.406 8183 8183 D TNS.Native: JNI_ONLoad END", output: null },
149-
{ 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 },
150-
{ input: "07-25 06:36:38.534 8183 8183 D TNS.Native: V8 version 5.5.372.32", output: null },
146+
{ input: "07-25 06:36:38.406 8183 8183 I TNS.Runtime: NativeScript Runtime Version 3.0.1, commit 733bfa5fab5d4c156eab156eaf01946eb36dab1e", output: null },
147+
{ input: "07-25 06:36:38.406 8183 8183 D TNS.Runtime: JNI_ONLoad", output: null },
148+
{ input: "07-25 06:36:38.406 8183 8183 D TNS.Runtime: JNI_ONLoad END", output: null },
149+
{ 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 },
150+
{ input: "07-25 06:36:38.534 8183 8183 D TNS.Runtime: V8 version 5.5.372.32", output: null },
151151
{ input: "07-25 06:36:38.675 8183 8183 D TNS.Native: lenNodes=66492, lenNames=775380, lenValues=899324", output: null },
152152
{ input: "07-25 06:36:38.675 8183 8183 D TNS.Native: time=24", output: null },
153153
{ 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 },
@@ -222,17 +222,17 @@ const androidApiLevel23MapForPid8141 = [
222222
{ 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 },
223223
{ input: "07-25 06:37:05.084 8244 8244 I art : Late-enabling -Xcheck:jni", output: null },
224224
{ input: "07-25 06:37:05.085 8244 8244 W art : Unexpected CPU variant for X86 using defaults: x86", output: null },
225-
{ input: "07-25 06:37:05.212 8244 8244 I TNS.Native: NativeScript Runtime Version 3.1.1, commit 253c76f850b88b0119fda04e413626872f223de5", output: null },
226-
{ input: "07-25 06:37:05.213 8244 8244 D TNS.Native: JNI_ONLoad", output: null },
227-
{ input: "07-25 06:37:05.213 8244 8244 D TNS.Native: JNI_ONLoad END", output: null },
228-
{ input: "02-01 13:29:22.990 8141 8141 I TNS.Native: NativeScript Runtime Version 5.1.0, commit 4497f43b69cb57ce65ece2aac5b98b2010f85857", output: null },
229-
{ input: "02-01 13:29:22.991 8141 8141 D TNS.Native: JNI_ONLoad", output: null },
230-
{ input: "02-01 13:29:22.991 8141 8141 D TNS.Native: JNI_ONLoad END", output: null },
225+
{ input: "07-25 06:37:05.212 8244 8244 I TNS.Runtime: NativeScript Runtime Version 3.1.1, commit 253c76f850b88b0119fda04e413626872f223de5", output: null },
226+
{ input: "07-25 06:37:05.213 8244 8244 D TNS.Runtime: JNI_ONLoad", output: null },
227+
{ input: "07-25 06:37:05.213 8244 8244 D TNS.Runtime: JNI_ONLoad END", output: null },
228+
{ input: "02-01 13:29:22.990 8141 8141 I TNS.Runtime: NativeScript Runtime Version 5.1.0, commit 4497f43b69cb57ce65ece2aac5b98b2010f85857", output: null },
229+
{ input: "02-01 13:29:22.991 8141 8141 D TNS.Runtime: JNI_ONLoad", output: null },
230+
{ input: "02-01 13:29:22.991 8141 8141 D TNS.Runtime: JNI_ONLoad END", output: null },
231231
{ input: "02-01 13:29:23.027 1344 1351 D gralloc_ranchu: gralloc_alloc: Creating ashmem region of size 8294400", output: null },
232232
{ 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 },
233-
{ input: "02-01 13:29:23.061 8141 8141 D TNS.Native: V8 version 6.9.427.23", output: null },
234-
{ input: "02-01 13:29:23.067 8141 8141 D TNS.Native: lenNodes=79716, lenNames=901564, lenValues=1062800", output: null },
235-
{ input: "02-01 13:29:23.067 8141 8141 D TNS.Native: time=2", output: null },
233+
{ input: "02-01 13:29:23.061 8141 8141 D TNS.Runtime: V8 version 6.9.427.23", output: null },
234+
{ 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" },
235+
{ input: "02-01 13:29:23.067 8141 8141 D TNS.Native: time=2", output: "TNS.Native: time=2" },
236236
{ input: "02-01 13:29:23.155 2288 2390 D EGL_emulation: eglMakeCurrent: 0xa037ba00: ver 2 0 (tinfo 0x92b47100)", output: null },
237237
{ 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 },
238238
{ 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 },
@@ -289,6 +289,33 @@ const androidApiLevel23MapForPid8141 = [
289289
{ 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 },
290290
{ 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 },
291291
{ 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 },
292+
{ input: "02-04 15:54:54.440 8141 8141 D TNS.Native: createJSInstanceNative called", output: "TNS.Native: createJSInstanceNative called" },
293+
{ 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" },
294+
{ input: "02-04 15:54:54.440 8141 8141 D TNS.Native: createJSInstanceNative: implementationObject :82225", output: "TNS.Native: createJSInstanceNative: implementationObject :82225" },
295+
{ 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" },
296+
{ 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" },
297+
{ input: "02-04 15:54:54.449 8141 8141 D TNS.Native: CallJSMethodNative called javaObjectID=3", output: "TNS.Native: CallJSMethodNative called javaObjectID=3" },
298+
{ input: "02-04 15:54:54.449 8141 8141 D TNS.Native: CallJSMethodNative called jsObject=335940", output: "TNS.Native: CallJSMethodNative called jsObject=335940" },
299+
{ 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" },
300+
{ input: "02-04 15:54:54.516 8141 8141 D TNS.Native: CallJSMethodNative called javaObjectID=1", output: "TNS.Native: CallJSMethodNative called javaObjectID=1" },
301+
{ input: "02-04 15:54:54.516 8141 8141 D TNS.Native: CallJSMethodNative called jsObject=572643", output: "TNS.Native: CallJSMethodNative called jsObject=572643" },
302+
{ 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)" },
303+
{ 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)" },
304+
{ 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)" },
305+
{ 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)" },
306+
{ 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)" },
307+
{ 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)" },
308+
{ 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" },
309+
{ input: "02-04 15:54:55.100 8141 8141 D TNS.Native: CallJSMethodNative called javaObjectID=3", output: "TNS.Native: CallJSMethodNative called javaObjectID=3" },
310+
{ input: "02-04 15:54:55.100 8141 8141 D TNS.Native: CallJSMethodNative called jsObject=335940", output: "TNS.Native: CallJSMethodNative called jsObject=335940" },
311+
{ 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" },
312+
{ input: "02-04 15:54:55.101 8141 8141 D TNS.Native: CallJSMethodNative called javaObjectID=1", output: "TNS.Native: CallJSMethodNative called javaObjectID=1" },
313+
{ input: "02-04 15:54:55.101 8141 8141 D TNS.Native: CallJSMethodNative called jsObject=572643", output: "TNS.Native: CallJSMethodNative called jsObject=572643" },
314+
{ 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" },
315+
{ input: "02-04 15:54:55.180 8141 8141 D TNS.Native: CallJSMethodNative called javaObjectID=1", output: "TNS.Native: CallJSMethodNative called javaObjectID=1" },
316+
{ input: "02-04 15:54:55.180 8141 8141 D TNS.Native: CallJSMethodNative called jsObject=572643", output: "TNS.Native: CallJSMethodNative called jsObject=572643" },
317+
{ 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" },
318+
{ input: "02-04 15:54:55.216 8141 8141 D TNS.Native: CallJSMethodNative called javaObjectID=75", output: "TNS.Native: CallJSMethodNative called javaObjectID=75" },
292319
];
293320

294321
describe("androidLogFilter", () => {

0 commit comments

Comments
 (0)