From c3b73181ea63b89bdaa4d10a4510b1cd299ec8d5 Mon Sep 17 00:00:00 2001 From: rosen-vladimirov Date: Fri, 1 Feb 2019 15:32:26 +0200 Subject: [PATCH] fix: incorrect filtering of Android logs by tag CLI filters Android logs by PID and by tags. However, in case the PID matches, but we do not find the tag, we may still output the line as we check if it contains the tag anywhere in the content. So, when searching for `JS` tag, we may output the line: ``` 02-01 13:29:23.990 8141 8141 I art : at java.lang.Object com.tns.Runtime.callJSMethod(java.lang.Object, java.lang.String, java.lang.Class, boolean, long, java.lang.Object[]) (Runtime.java:987) ``` Remove this incorrect behavior and rely on the tag filtering. --- .../mobile/android/android-log-filter.ts | 5 - .../test/unit-tests/android-log-filter.ts | 94 ++++++++++++++++++- 2 files changed, 90 insertions(+), 9 deletions(-) diff --git a/lib/common/mobile/android/android-log-filter.ts b/lib/common/mobile/android/android-log-filter.ts index 2681f17dd6..4097a15432 100644 --- a/lib/common/mobile/android/android-log-filter.ts +++ b/lib/common/mobile/android/android-log-filter.ts @@ -45,11 +45,6 @@ export class AndroidLogFilter implements Mobile.IPlatformLogFilter { consoleLogMessage = { tag: match[1].trim(), message: match[2] }; } - if (!consoleLogMessage) { - const matchingTag = _.some(acceptedTags, (tag: string) => { return lineText.indexOf(tag) !== -1; }); - consoleLogMessage = matchingTag ? { message: lineText } : null; - } - return consoleLogMessage; } } diff --git a/lib/common/test/unit-tests/android-log-filter.ts b/lib/common/test/unit-tests/android-log-filter.ts index 1d77b4141f..90f9f63f91 100644 --- a/lib/common/test/unit-tests/android-log-filter.ts +++ b/lib/common/test/unit-tests/android-log-filter.ts @@ -17,7 +17,7 @@ const androidApiLevel23TestData = [ }, { input: '12-28 10:14:31.460 3593 3593 I BrowserStartupController: Initializing chromium process, singleProcess=true', - output: '12-28 10:14:31.460 3593 3593 I BrowserStartupController: Initializing chromium process, singleProcess=true' + output: null }, { input: '12-28 10:14:31.486 3593 3613 W AudioManagerAndroid: Requires BLUETOOTH permission', output: null }, { input: '12-28 10:14:31.544 3593 3593 D libEGL : loaded /system/lib/egl/libEGL_emulation.so', output: null }, @@ -59,7 +59,7 @@ const androidApiLevel22TestData = [ }, { input: 'I/BrowserStartupController( 2971): Initializing chromium process, singleProcess=true', - output: 'I/BrowserStartupController( 2971): Initializing chromium process, singleProcess=true' + output: null }, { input: 'W/art ( 2971): Attempt to remove local handle scope entry from IRT, ignoring', output: null }, { input: 'W/AudioManagerAndroid( 2971): Requires BLUETOOTH permission', output: null }, @@ -89,11 +89,33 @@ 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: "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", output: null }, + { input: "I/art ( 4502): Rejecting re-init on previously-failed class java.lang.Class", output: null }, + { input: "D/OpenGLRenderer( 4502): Use EGL_SWAP_BEHAVIOR_PRESERVED: true", output: null }, + { input: "D/ ( 4502): HostConnection::get() New Host Connection established 0xa31f1060, tid 4502", output: null }, + { input: "D/Atlas ( 4502): Validating map...", output: null }, + { input: "V/WindowManager( 1542): Adding window Window{22cb1746 u0 org.nativescript.logsss/com.tns.NativeScriptActivity} at 2 of 6 (before Window{3f5d3e9 u0 Starting org.nativescript.logsss})", output: null }, + { input: "D/ ( 4502): HostConnection::get() New Host Connection established 0xa3230f60, tid 4532", output: null }, + { input: "I/OpenGLRenderer( 4502): Initialized EGL, version 1.4", output: null }, + { input: "W/OpenGLRenderer( 4502): Failed to choose config with EGL_SWAP_BEHAVIOR_PRESERVED, retrying without...", output: null }, + { input: "D/EGL_emulation( 4502): eglCreateContext: 0xa31f2340: maj 2 min 0 rcv 2", output: null }, + { input: "D/EGL_emulation( 4502): eglMakeCurrent: 0xa31f2340: ver 2 0", output: null }, + { input: "D/OpenGLRenderer( 4502): Enabling debug mode 0", output: null }, + { input: "D/ ( 1142): HostConnection::get() New Host Connection established 0xb6038380, tid 4442", output: null }, + { input: "D/EGL_emulation( 4502): eglMakeCurrent: 0xa31f2340: ver 2 0", output: null }, + { input: "I/art ( 4502): Background sticky concurrent mark sweep GC freed 22621(1698KB) AllocSpace objects, 10(183KB) LOS objects, 33% free, 3MB/5MB, paused 5.847ms total 36.229ms", output: null }, ]; const androidApiLevel23MapForPid8141 = [ - { input: "--------- beginning of main", output: null }, + { 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:23.065 739 760 I Choreographer: Skipped 54 frames! The application may be doing too much work on its main thread.", output: null }, @@ -203,6 +225,70 @@ const androidApiLevel23MapForPid8141 = [ { 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: "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.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 }, + { input: "02-01 13:29:23.988 8141 8141 I art : Rejecting re-init on previously-failed class java.lang.Class: java.lang.NoClassDefFoundError: Failed resolution of: Landroid/view/View$OnUnhandledKeyEventListener;", output: null }, + { input: "02-01 13:29:23.988 8141 8141 I art : at void android.support.v4.view.ViewCompat.setOnApplyWindowInsetsListener(android.view.View, android.support.v4.view.OnApplyWindowInsetsListener) (ViewCompat.java:2203)", output: null }, + { input: "02-01 13:29:23.988 8141 8141 I art : at android.view.ViewGroup android.support.v7.app.AppCompatDelegateImpl.createSubDecor() (AppCompatDelegateImpl.java:637)", output: null }, + { input: "02-01 13:29:23.988 8141 8141 I art : at void android.support.v7.app.AppCompatDelegateImpl.ensureSubDecor() (AppCompatDelegateImpl.java:518)", output: null }, + { input: "02-01 13:29:23.988 8141 8141 I art : at void android.support.v7.app.AppCompatDelegateImpl.setContentView(android.view.View, android.view.ViewGroup$LayoutParams) (AppCompatDelegateImpl.java:475)", output: null }, + { input: "02-01 13:29:23.988 8141 8141 I art : at void android.support.v7.app.AppCompatActivity.setContentView(android.view.View, android.view.ViewGroup$LayoutParams) (AppCompatActivity.java:150)", output: null }, + { input: "02-01 13:29:23.988 8141 8141 I art : at java.lang.Object com.tns.Runtime.callJSMethodNative(int, int, java.lang.String, int, boolean, java.lang.Object[]) (Runtime.java:-2)", output: null }, + { input: "02-01 13:29:23.989 8141 8141 I art : at java.lang.Object com.tns.Runtime.dispatchCallJSMethodNative(int, java.lang.String, boolean, long, java.lang.Class, java.lang.Object[]) (Runtime.java:1120)", output: null }, + { input: "02-01 13:29:23.989 8141 8141 I art : at java.lang.Object com.tns.Runtime.callJSMethodImpl(java.lang.Object, java.lang.String, java.lang.Class, boolean, long, java.lang.Object[]) (Runtime.java:1000)", output: null }, + { input: "02-01 13:29:23.990 8141 8141 I art : at java.lang.Object com.tns.Runtime.callJSMethod(java.lang.Object, java.lang.String, java.lang.Class, boolean, long, java.lang.Object[]) (Runtime.java:987)", output: null }, + { input: "02-01 13:29:23.990 8141 8141 I art : at java.lang.Object com.tns.Runtime.callJSMethod(java.lang.Object, java.lang.String, java.lang.Class, boolean, java.lang.Object[]) (Runtime.java:967)", output: null }, + { input: "02-01 13:29:23.990 8141 8141 I art : at java.lang.Object com.tns.Runtime.callJSMethod(java.lang.Object, java.lang.String, java.lang.Class, java.lang.Object[]) (Runtime.java:959)", output: null }, + { input: "02-01 13:29:23.990 8141 8141 I art : at void com.tns.NativeScriptActivity.onCreate(android.os.Bundle) (NativeScriptActivity.java:18)", output: null }, + { input: "02-01 13:29:23.990 8141 8141 I art : at void android.app.Activity.performCreate(android.os.Bundle) (Activity.java:6662)", output: null }, + { input: "02-01 13:29:23.990 8141 8141 I art : at void android.app.Instrumentation.callActivityOnCreate(android.app.Activity, android.os.Bundle) (Instrumentation.java:1118)", output: null }, + { input: "02-01 13:29:23.990 8141 8141 I art : at android.app.Activity android.app.ActivityThread.performLaunchActivity(android.app.ActivityThread$ActivityClientRecord, android.content.Intent) (ActivityThread.java:2599)", output: null }, + { input: "02-01 13:29:23.990 8141 8141 I art : at void android.app.ActivityThread.handleLaunchActivity(android.app.ActivityThread$ActivityClientRecord, android.content.Intent, java.lang.String) (ActivityThread.java:2707)", output: null }, + { input: "02-01 13:29:23.990 8141 8141 I art : at void android.app.ActivityThread.-wrap12(android.app.ActivityThread, android.app.ActivityThread$ActivityClientRecord, android.content.Intent, java.lang.String) (ActivityThread.java:-1)", output: null }, + { input: "02-01 13:29:23.990 8141 8141 I art : at void android.app.ActivityThread$H.handleMessage(android.os.Message) (ActivityThread.java:1460)", output: null }, + { input: "02-01 13:29:23.990 8141 8141 I art : at void android.os.Handler.dispatchMessage(android.os.Message) (Handler.java:102)", output: null }, + { input: "02-01 13:29:23.990 8141 8141 I art : at void android.os.Looper.loop() (Looper.java:154)", output: null }, + { input: "02-01 13:29:23.990 8141 8141 I art : at void android.app.ActivityThread.main(java.lang.String[]) (ActivityThread.java:6077)", output: null }, + { input: "02-01 13:29:23.990 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.990 8141 8141 I art : at void com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run() (ZygoteInit.java:866)", output: null }, + { input: "02-01 13:29:23.991 8141 8141 I art : at void com.android.internal.os.ZygoteInit.main(java.lang.String[]) (ZygoteInit.java:756)", output: null }, + { input: "02-01 13:29:23.991 8141 8141 I art : Caused by: java.lang.ClassNotFoundException: Didn't find class \"android.view.View$OnUnhandledKeyEventListener\" on path: DexPathList[[zip file \"/data/app / org.nativescript.app1 - 1 / base.apk\"],nativeLibraryDirectories=[/data/app/org.nativescript.app1-1/lib/x86, /data/app/org.nativescript.app1-1/base.apk!/lib/x86, /system/lib, /vendor/lib]]", output: null }, + { input: "02-01 13:29:23.992 8141 8141 I art : at java.lang.Class dalvik.system.BaseDexClassLoader.findClass(java.lang.String) (BaseDexClassLoader.java:56)", output: null }, + { input: "02-01 13:29:23.992 8141 8141 I art : at java.lang.Class java.lang.ClassLoader.loadClass(java.lang.String, boolean) (ClassLoader.java:380)", output: null }, + { input: "02-01 13:29:23.992 8141 8141 I art : at java.lang.Class java.lang.ClassLoader.loadClass(java.lang.String) (ClassLoader.java:312)", output: null }, + { input: "02-01 13:29:23.992 8141 8141 I art : at void android.support.v4.view.ViewCompat.setOnApplyWindowInsetsListener(android.view.View, android.support.v4.view.OnApplyWindowInsetsListener) (ViewCompat.java:2203)", output: null }, + { input: "02-01 13:29:23.992 8141 8141 I art : at android.view.ViewGroup android.support.v7.app.AppCompatDelegateImpl.createSubDecor() (AppCompatDelegateImpl.java:637)", output: null }, + { input: "02-01 13:29:23.992 8141 8141 I art : at void android.support.v7.app.AppCompatDelegateImpl.ensureSubDecor() (AppCompatDelegateImpl.java:518)", output: null }, + { input: "02-01 13:29:23.992 8141 8141 I art : at void android.support.v7.app.AppCompatDelegateImpl.setContentView(android.view.View, android.view.ViewGroup$LayoutParams) (AppCompatDelegateImpl.java:475)", output: null }, + { input: "02-01 13:29:23.992 8141 8141 I art : at void android.support.v7.app.AppCompatActivity.setContentView(android.view.View, android.view.ViewGroup$LayoutParams) (AppCompatActivity.java:150)", output: null }, + { input: "02-01 13:29:23.992 8141 8141 I art : at java.lang.Object com.tns.Runtime.callJSMethodNative(int, int, java.lang.String, int, boolean, java.lang.Object[]) (Runtime.java:-2)", output: null }, + { input: "02-01 13:29:23.992 8141 8141 I art : at java.lang.Object com.tns.Runtime.dispatchCallJSMethodNative(int, java.lang.String, boolean, long, java.lang.Class, java.lang.Object[]) (Runtime.java:1120)", output: null }, + { input: "02-01 13:29:23.992 8141 8141 I art : at java.lang.Object com.tns.Runtime.callJSMethodImpl(java.lang.Object, java.lang.String, java.lang.Class, boolean, long, java.lang.Object[]) (Runtime.java:1000)", output: null }, + { input: "02-01 13:29:23.992 8141 8141 I art : at java.lang.Object com.tns.Runtime.callJSMethod(java.lang.Object, java.lang.String, java.lang.Class, boolean, long, java.lang.Object[]) (Runtime.java:987)", output: null }, + { input: "02-01 13:29:23.992 8141 8141 I art : at java.lang.Object com.tns.Runtime.callJSMethod(java.lang.Object, java.lang.String, java.lang.Class, boolean, java.lang.Object[]) (Runtime.java:967)", output: null }, + { input: "02-01 13:29:23.993 8141 8141 I art : at java.lang.Object com.tns.Runtime.callJSMethod(java.lang.Object, java.lang.String, java.lang.Class, java.lang.Object[]) (Runtime.java:959)", output: null }, + { input: "02-01 13:29:23.993 8141 8141 I art : at void com.tns.NativeScriptActivity.onCreate(android.os.Bundle) (NativeScriptActivity.java:18)", output: null }, + { input: "02-01 13:29:23.994 8141 8141 I art : at void android.app.Activity.performCreate(android.os.Bundle) (Activity.java:6662)", output: null }, + { input: "02-01 13:29:23.994 8141 8141 I art : at void android.app.Instrumentation.callActivityOnCreate(android.app.Activity, android.os.Bundle) (Instrumentation.java:1118)", output: null }, + { input: "02-01 13:29:23.994 8141 8141 I art : at android.app.Activity android.app.ActivityThread.performLaunchActivity(android.app.ActivityThread$ActivityClientRecord, android.content.Intent) (ActivityThread.java:2599)", output: null }, + { input: "02-01 13:29:23.994 8141 8141 I art : at void android.app.ActivityThread.handleLaunchActivity(android.app.ActivityThread$ActivityClientRecord, android.content.Intent, java.lang.String) (ActivityThread.java:2707)", output: null }, + { input: "02-01 13:29:23.994 8141 8141 I art : at void android.app.ActivityThread.-wrap12(android.app.ActivityThread, android.app.ActivityThread$ActivityClientRecord, android.content.Intent, java.lang.String) (ActivityThread.java:-1)", output: null }, + { input: "02-01 13:29:23.994 8141 8141 I art : at void android.app.ActivityThread$H.handleMessage(android.os.Message) (ActivityThread.java:1460)", output: null }, + { input: "02-01 13:29:23.994 8141 8141 I art : at void android.os.Handler.dispatchMessage(android.os.Message) (Handler.java:102)", output: null }, + { input: "02-01 13:29:23.994 8141 8141 I art : at void android.os.Looper.loop() (Looper.java:154)", output: null }, + { input: "02-01 13:29:23.994 8141 8141 I art : at void android.app.ActivityThread.main(java.lang.String[]) (ActivityThread.java:6077)", output: null }, + { 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 }, ]; describe("androidLogFilter", () => {