Skip to content

Commit e9bf8a7

Browse files
author
Deyan Ginev
committed
update(cli): Improve filtering of iOS logs
1 parent bab1251 commit e9bf8a7

File tree

2 files changed

+109
-74
lines changed

2 files changed

+109
-74
lines changed

‎lib/services/ios-log-filter.ts

+58-40
Original file line numberDiff line numberDiff line change
@@ -4,62 +4,80 @@ import { cache } from "../common/decorators";
44
import * as iOSLogFilterBase from "../common/mobile/ios/ios-log-filter";
55

66
export class IOSLogFilter extends iOSLogFilterBase.IOSLogFilter implements Mobile.IPlatformLogFilter {
7-
protected infoFilterRegex = /^.*?((?:<Notice>:)?.*?(((?:CONSOLE|JS) (?:LOG|ERROR)).*?))$/im;
7+
// Used to trim the passed messages to a simpler output
8+
// Example:
9+
// This: "May 24 15:54:52 Dragons-iPhone NativeScript250(NativeScript)[356] <Notice>: CONSOLE ERROR file:///app/tns_modules/@angular/core/bundles/core.umd.js:3477:36: ORIGINAL STACKTRACE:"
10+
// Becomes: CONSOLE ERROR file:///app/tns_modules/@angular/core/bundles/core.umd.js:3477:36: ORIGINAL STACKTRACE:
11+
protected infoFilterRegex = /^.*(?:<Notice>:|<Warning>:|\(NativeScript\)|(?:[a-zA-Z0-9]+)(?:\([a-zA-Z0-9]+\))?\[[0-9]+\]:){1}/;
12+
// Used to recognize output related to the current project
13+
// This looks for artifacts like: AppName[22432] or AppName(SomeTextHere)[23123]
14+
private appOutputRegex: RegExp = /([a-zA-Z0-9]+)(?:\([a-zA-Z0-9]+\))?\[[0-9]+\]/;
15+
private filterActive: boolean = true;
16+
private projectName: string;
817

918
private partialLine: string = null;
19+
private loggingLevels: Mobile.ILoggingLevels;
1020

1121
constructor($loggingLevels: Mobile.ILoggingLevels,
1222
private $fs: IFileSystem,
1323
private $projectData: IProjectData) {
1424
super($loggingLevels);
25+
this.projectName = this.$projectData.projectName;
26+
this.loggingLevels = $loggingLevels;
1527
}
1628

1729
public filterData(data: string, logLevel: string, pid?: string): string {
18-
data = super.filterData(data, logLevel, pid);
19-
if (pid && data && data.indexOf(`[${pid}]`) === -1) {
20-
return null;
30+
const specifiedLogLevel = (logLevel || '').toUpperCase();
31+
32+
if (specifiedLogLevel !== this.loggingLevels.info || !data) {
33+
return data;
2134
}
2235

23-
if (data) {
24-
const skipLastLine = data[data.length - 1] !== "\n";
25-
const lines = data.split("\n");
26-
let result = "";
27-
for (let i = 0; i < lines.length; i++) {
28-
let line = lines[i];
29-
if (i === 0 && this.partialLine) {
30-
line = this.partialLine + line;
31-
this.partialLine = null;
32-
}
33-
if (line.length < 1 ||
34-
line.indexOf("SecTaskCopyDebugDescription") !== -1 ||
35-
line.indexOf("NativeScript loaded bundle") !== -1 ||
36-
(line.indexOf("assertion failed:") !== -1 && data.indexOf("libxpc.dylib") !== -1)) {
37-
continue;
38-
}
39-
// CONSOLE LOG messages comme in the following form:
40-
// <date> <domain> <app>[pid] CONSOLE LOG file:///location:row:column: <actual message goes here>
41-
// This code removes unnecessary information from log messages. The output looks like:
42-
// CONSOLE LOG file:///location:row:column: <actual message goes here>
43-
if (pid) {
44-
if (line.indexOf(`[${pid}]: `) !== -1) {
45-
const pidRegex = new RegExp(`^.*\\[${pid}\\]:\\s(?:\\(NativeScript\\)\\s)?`);
46-
line = line.replace(pidRegex, "").trim();
47-
this.getOriginalFileLocation(line);
48-
result += this.getOriginalFileLocation(line) + "\n";
49-
}
36+
const chunkLines = data.split('\n');
37+
const skipLastLine = chunkLines.length > 1 ? data[data.length - 1] !== "\n" : false;
38+
let output = "";
39+
for (let i = 0; i < chunkLines.length; i++) {
40+
let currentLine = chunkLines[i];
5041

51-
continue;
52-
}
53-
if (skipLastLine && i === lines.length - 1 && lines.length > 1) {
54-
this.partialLine = line;
55-
} else {
56-
result += this.getOriginalFileLocation(line) + "\n";
57-
}
42+
// Legacy filter
43+
if (currentLine.length < 1 ||
44+
currentLine.indexOf("SecTaskCopyDebugDescription") !== -1 ||
45+
currentLine.indexOf("NativeScript loaded bundle") !== -1 ||
46+
(currentLine.indexOf("assertion failed:") !== -1 && data.indexOf("libxpc.dylib") !== -1)) {
47+
continue;
48+
}
49+
50+
const matchResult = this.appOutputRegex.exec(currentLine);
51+
52+
if (matchResult && matchResult.length > 1) {
53+
// Check if the name of the app equals the name of the CLI project and turn on the filter if not.
54+
this.filterActive = matchResult[1] !== this.projectName;
5855
}
59-
return result;
56+
57+
if (this.filterActive) {
58+
continue;
59+
}
60+
61+
if (this.partialLine) {
62+
currentLine = this.partialLine + currentLine;
63+
this.partialLine = undefined;
64+
}
65+
66+
if (i === chunkLines.length - 1 && skipLastLine) {
67+
this.partialLine = currentLine;
68+
break;
69+
}
70+
71+
const filteredLineInfo = currentLine.match(this.infoFilterRegex);
72+
if (filteredLineInfo && filteredLineInfo.length > 0) {
73+
currentLine = currentLine.replace(filteredLineInfo[0], "");
74+
}
75+
76+
currentLine = currentLine.trim();
77+
output += this.getOriginalFileLocation(currentLine) + '\n';
6078
}
6179

62-
return data;
80+
return output.length === 0 ? null : output;
6381
}
6482

6583
private getOriginalFileLocation(data: string): string {

‎test/services/ios-log-filter.ts

+51-34
Original file line numberDiff line numberDiff line change
@@ -3,15 +3,16 @@ import { Yok } from "../../lib/common/yok";
33
import { LoggingLevels } from "../../lib/common/mobile/logging-levels";
44
import * as assert from "assert";
55

6-
function createTestInjector(): IInjector {
6+
function createTestInjector(projectName: string): IInjector {
77
const testInjector = new Yok();
88
testInjector.register("loggingLevels", LoggingLevels);
99
testInjector.register("fs", {
1010
exists: () => false
1111
});
1212
testInjector.register("projectData", {
1313
initializeProjectData: () => { /* empty */ },
14-
projectDir: "test"
14+
projectDir: "test",
15+
projectName: projectName
1516
});
1617

1718
return testInjector;
@@ -24,6 +25,7 @@ describe("iOSLogFilter", () => {
2425
const testData = [
2526
{
2627
version: 9,
28+
projectName: "NativeScript250",
2729
originalDataArr: [
2830
"May 24 15:54:38 Dragons-iPhone backboardd(BaseBoard)[62] <Error>: Unable to bootstrap_look_up port with name .gsEvents: unknown error code (1102)",
2931
"May 24 15:54:51 Dragons-iPhone locationd[67] <Notice>: Client com.apple.springboard disconnected",
@@ -45,9 +47,10 @@ describe("iOSLogFilter", () => {
4547
null,
4648
null,
4749
"CONSOLE ERROR file:///app/tns_modules/@angular/core/bundles/core.umd.js:3472:32: EXCEPTION: Uncaught (in promise): Error: CUSTOM EXCEPTION",
48-
"CONSOLE LOG file:///app/home/home-view-model.js:6:20: CUSTOM CONSOLE LOG",
50+
null,
4951
""
5052
],
53+
simProjectName: "TestApp",
5154
simulator: [
5255
"Aug 22 10:59:20 MCSOFAPPBLD TestApp[52946]: CONSOLE LOG file:///app/home/home-view-model.js:6:20: CUSTOM CONSOLE LOG",
5356
"Aug 22 10:59:20 MCSOFAPPBLD TestApp[52946]: CONSOLE DEBUG file:///app/home/home-view-model.js:6:20: CUSTOM CONSOLE LOG",
@@ -60,6 +63,7 @@ describe("iOSLogFilter", () => {
6063
]
6164
}, {
6265
version: 10,
66+
projectName: "NativeScript250",
6367
originalDataArr: [
6468
"May 24 15:54:52 Dragons-iPhone apsd(PersistentConnection)[90] <Notice>: 2017-05-24 15:54:52 +0300 apsd[90]: <PCDispatchTimer: 0x156ad240> performing call back",
6569
"May 24 15:54:52 Dragons-iPhone NativeScript250(NativeScript)[356] <Notice>: CONSOLE LOG file:///app/modules/homeView/homeView.component.js:13:24: CUSTOM CONSOLE LOG",
@@ -86,20 +90,21 @@ describe("iOSLogFilter", () => {
8690
"CONSOLE ERROR file:///app/tns_modules/@angular/core/bundles/core.umd.js:3472:32: EXCEPTION: Uncaught (in promise): Error: CUSTOM EXCEPTION",
8791
"CONSOLE ERROR file:///app/tns_modules/@angular/core/bundles/core.umd.js:3477:36: ORIGINAL STACKTRACE:",
8892
"CONSOLE ERROR file:///app/tns_modules/@angular/core/bundles/core.umd.js:3478:36: resolvePromise@file:///app/tns_modules/nativescript-angular/zone-js/dist/zone-nativescript.js:416:40",
93+
"resolvePromise@file:///app/tns_modules/nativescript-angular/zone-js/dist/zone-nativescript.js:401:31",
94+
"file:///app/tns_modules/nativescript-angular/zone-js/dist/zone-nativescript.js:449:31",
95+
"invokeTask@file:///app/tns_modules/nativescript-angular/zone-js/dist/zone-nativescript.js:223:42",
96+
"onInvokeTask@file:///app/tns_modules/@angular/core/bundles/core.umd.js:4382:51",
97+
"invokeTask@file:///app/tns_modules/nativescript-angular/zone-js/dist/zone-nativescript.js:222:54",
98+
"runTask@file:///app/tns_modules/nativescript-angular/zone-js/dist/zone-nativescript.js:123:57",
99+
"drainMicroTaskQueue@file:///app/tns_modules/nativescript-angular/zone-js/dist/zone-nativescript.js:355:42",
100+
"promiseReactionJob@[native code]",
101+
"UIApplicationMain@[native code]",
102+
"start@file:///app/tns_modules/tns-core-modules/application/application.js:251:26",
103+
"bootstrapApp@file:///app/tns_module",
89104
null,
90-
null,
91-
null,
92-
null,
93-
null,
94-
null,
95-
null,
96-
null,
97-
null,
98-
null,
99-
null,
100-
"CONSOLE LOG file:///app/home/home-view-model.js:6:20: CUSTOM CONSOLE LOG",
101105
""
102106
],
107+
simProjectName: "TestApp",
103108
simulator: [
104109
"Aug 22 10:59:20 MCSOFAPPBLD TestApp[52946]: CONSOLE LOG file:///app/home/home-view-model.js:6:20: CUSTOM CONSOLE LOG",
105110
"Aug 22 10:59:20 MCSOFAPPBLD TestApp[52946]: CONSOLE DEBUG file:///app/home/home-view-model.js:6:20: CUSTOM CONSOLE LOG",
@@ -113,6 +118,7 @@ describe("iOSLogFilter", () => {
113118
},
114119
{
115120
version: 11,
121+
projectName: "NativeScript250",
116122
originalDataArr: [
117123
"May 24 15:54:52 Dragons-iPhone apsd(PersistentConnection)[90] <Notice>: 2017-05-24 15:54:52 +0300 apsd[90]: <PCDispatchTimer: 0x156ad240> performing call back",
118124
"May 24 15:54:52 Dragons-iPhone NativeScript250(NativeScript)[356] <Notice>: CONSOLE LOG file:///app/modules/homeView/homeView.component.js:13:24: CUSTOM CONSOLE LOG",
@@ -139,20 +145,21 @@ describe("iOSLogFilter", () => {
139145
"CONSOLE ERROR file:///app/tns_modules/@angular/core/bundles/core.umd.js:3472:32: EXCEPTION: Uncaught (in promise): Error: CUSTOM EXCEPTION",
140146
"CONSOLE ERROR file:///app/tns_modules/@angular/core/bundles/core.umd.js:3477:36: ORIGINAL STACKTRACE:",
141147
"CONSOLE ERROR file:///app/tns_modules/@angular/core/bundles/core.umd.js:3478:36: resolvePromise@file:///app/tns_modules/nativescript-angular/zone-js/dist/zone-nativescript.js:416:40",
148+
"resolvePromise@file:///app/tns_modules/nativescript-angular/zone-js/dist/zone-nativescript.js:401:31",
149+
"file:///app/tns_modules/nativescript-angular/zone-js/dist/zone-nativescript.js:449:31",
150+
"invokeTask@file:///app/tns_modules/nativescript-angular/zone-js/dist/zone-nativescript.js:223:42",
151+
"onInvokeTask@file:///app/tns_modules/@angular/core/bundles/core.umd.js:4382:51",
152+
"invokeTask@file:///app/tns_modules/nativescript-angular/zone-js/dist/zone-nativescript.js:222:54",
153+
"runTask@file:///app/tns_modules/nativescript-angular/zone-js/dist/zone-nativescript.js:123:57",
154+
"drainMicroTaskQueue@file:///app/tns_modules/nativescript-angular/zone-js/dist/zone-nativescript.js:355:42",
155+
"promiseReactionJob@[native code]",
156+
"UIApplicationMain@[native code]",
157+
"start@file:///app/tns_modules/tns-core-modules/application/application.js:251:26",
158+
"bootstrapApp@file:///app/tns_module",
142159
null,
143-
null,
144-
null,
145-
null,
146-
null,
147-
null,
148-
null,
149-
null,
150-
null,
151-
null,
152-
null,
153-
"CONSOLE LOG file:///app/home/home-view-model.js:6:20: CUSTOM CONSOLE LOG",
154160
""
155161
],
162+
simProjectName: "cliapp",
156163
simulator: [
157164
"2017-10-09 13:34:38.527844+0300 localhost cliapp[52946]: (NativeScript) CONSOLE LOG file:///app/main-view-model.js:18:20: Test Console",
158165
"2017-10-09 13:34:38.527844+0300 localhost cliapp[52946]: (NativeScript) CONSOLE DEBUG file:///app/main-view-model.js:18:20: Test Console",
@@ -168,45 +175,55 @@ describe("iOSLogFilter", () => {
168175
const infoLogLevel = "INFO";
169176
const fullLogLevel = "FULL";
170177

171-
beforeEach(() => {
172-
testInjector = createTestInjector();
173-
logFilter = testInjector.resolve(IOSLogFilter);
174-
});
178+
// beforeEach(() => {
179+
// // testInjector = createTestInjector();
180+
// // logFilter = testInjector.resolve(IOSLogFilter);
181+
// });
175182

176-
describe("filterData", () => {
183+
describe.only("filterData", () => {
177184
testData.forEach(data => {
178185
it(`returns correct data when logLevel is ${fullLogLevel} on iOS ${data.version} and all data is passed at once`, () => {
186+
testInjector = createTestInjector(data.projectName);
187+
logFilter = testInjector.resolve(IOSLogFilter);
179188
const actualData = logFilter.filterData(data.originalDataArr.join("\n"), fullLogLevel, null);
180189
const actualArr = actualData.split("\n").map(line => line.trim());
181-
const expectedArr = data.originalDataArr.map(line => line.trim());
190+
const expectedArr = data.originalDataArr.map(line => line.trim()).filter(item => item !== null);
182191
assert.deepEqual(actualArr, expectedArr);
183192
});
184193

185194
it(`returns correct data when logLevel is ${fullLogLevel} on iOS ${data.version} and data is passed one line at a time`, () => {
186195
data.originalDataArr.forEach(line => {
196+
testInjector = createTestInjector(data.projectName);
197+
logFilter = testInjector.resolve(IOSLogFilter);
187198
const actualData = logFilter.filterData(line, fullLogLevel, null);
188199
assert.deepEqual(actualData.trim(), line.trim());
189200
});
190201
});
191202

192203
it(`parses data incorrectly when logLevel is ${infoLogLevel} on iOS ${data.version} and all data is passed at once with pid(simulator)`, () => {
204+
testInjector = createTestInjector(data.simProjectName);
205+
logFilter = testInjector.resolve(IOSLogFilter);
193206
const actualData = logFilter.filterData(data.simulator.join("\n"), infoLogLevel, pid);
194207
const actualArr = actualData.split("\n").map(line => line.trim());
195-
assert.deepEqual(actualArr, data.simulatorExpectedArr);
208+
assert.deepEqual(actualArr, data.simulatorExpectedArr.filter(item => item !== null));
196209
});
197210

198211
it(`parses data incorrectly when logLevel is ${infoLogLevel} on iOS ${data.version} and all data is passed at once and pid is available`, () => {
212+
testInjector = createTestInjector(data.projectName);
213+
logFilter = testInjector.resolve(IOSLogFilter);
199214
const actualData = logFilter.filterData(data.originalDataArr.join("\n"), infoLogLevel, null);
200215
const actualArr = actualData.split("\n").map(line => line.trim());
201-
const expectedArr = ["CONSOLE LOG file:///app/modules/homeView/homeView.component.js:13:24: CUSTOM CONSOLE LOG", ""];
216+
const expectedArr = data.infoExpectedArr.filter(item => item !== null);
202217
assert.deepEqual(actualArr, expectedArr);
203218
});
204219

205220
it(`returns correct data when logLevel is ${infoLogLevel} on iOS ${data.version} and data is passed one line at a time`, () => {
221+
testInjector = createTestInjector(data.projectName);
222+
logFilter = testInjector.resolve(IOSLogFilter);
206223
data.originalDataArr.forEach((line, index) => {
207224
const actualData = logFilter.filterData(line, infoLogLevel, null);
208225
const expectedData = data.infoExpectedArr[index];
209-
assert.deepEqual(actualData && actualData.trim(), expectedData && expectedData);
226+
assert.equal(actualData && actualData.trim(), expectedData && expectedData);
210227
});
211228
});
212229
});

0 commit comments

Comments
 (0)