Skip to content
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.

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

feat(logs): improve android logging #5755

Merged
merged 2 commits into from
Sep 11, 2023
Merged

Conversation

ammarahm-ed
Copy link
Contributor

@ammarahm-ed ammarahm-ed commented Aug 17, 2023

PR Checklist

What is the current behavior?

Logging on android stops working if the app is restarted. This happens mainly due to logging directly linked with app PID when it was first launched. If the app restarts or crashes and is relauched, the PID changes which causes the logs to stop coming in. The only solution (very bad) is to kill the CLI and run the app again.

What is the new behavior?

I wanted to completely ditch PID for something else on android but I realized there are good reasons to keep using PID as it helps us filter logs precisely for the current app instance that is running.

In the new approach we restart adb logcat with the new PID if the app restarts. This way we always keep the CLI in sync with the current PID of the running NativeScript app. This requires running a separate instance of adb logcat -T 1 --regex=START.*com.myappid basically to watch for app START log from ActivityManager/ActivityTaskManager and then update the PID in the CLI and restart logcat. Yes we are running two instances of adb logcat but both are very lightweight and log precisely what we need by using native adb filters.

This PR also makes logging much more performant on android by using native android filters of TAGs of concern instead of filtering on the host device.

  • Removed JS: from logs
  • Logging works on app restart
  • Improved logging performance on android and reduced the filtering needed on host device. We only get logs from TAGs we care about. Everything else is excluded.

Closes #5739

@cla-bot cla-bot bot added the cla: yes label Aug 17, 2023
@mukaschultze
Copy link
Contributor

private logDataCore(data: string, deviceIdentifier: string): void {
// strip android JS: prefix
data = data.replace(/^JS:\s/, "");

I guess this can be removed now that the JS: tag is not forwarded to the provider?

@ammarahm-ed
Copy link
Contributor Author

private logDataCore(data: string, deviceIdentifier: string): void {
// strip android JS: prefix
data = data.replace(/^JS:\s/, "");

I guess this can be removed now that the JS: tag is not forwarded to the provider?

Probably yes, will have to see which one is better to keep.

@rigor789 rigor789 self-assigned this Aug 27, 2023
Copy link
Member

@rigor789 rigor789 left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Great additions! Added some notes about some cleanup changes I've done for future reference.

Comment on lines +48 to +49
lineText.match(AndroidLogFilter.API_LEVEL_23_LINE_REGEX) ||
lineText.match(AndroidLogFilter.LINE_REGEX);
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Note: I flipped this condition to speed up matching by optimizing for API23 first and then falling back to legacy regex.

!line.includes(options.pid)
) {
this.forceStop(deviceIdentifier);
options.onAppRestarted?.();
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Note: not break;-ing here, since it's possible (though unlikely) that two subsequent START lines come in the same lineBuffer. Though this doesn't really matter - this stream is not noisy at all because we're pre-filtering with the adb logcat regex.

Comment on lines +188 to +203
const acceptedTags = [
"chromium",
'"Web Console"',
"JS",
"System.err",
"TNS.Native",
"TNS.Java",
];

if (pid && isLogcatPidSupported) {
logcatCommand.push(`--pid=${pid}`);

acceptedTags.forEach((tag) => {
// -s <tag> - shows only logs with the specified tag
logcatCommand.push("-s", tag);
});
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@ammarahm-ed this is a great idea to move here - technically if isLogcatPidSupported is false - we'd log out all tags even if not accepted - since the filtering has been removed from android-log-filter, however I don't think this would ever be a problem.

I've extracted the isLogcatPidSupported to a function since it's used by both methods here - and I marked is @deprecated because I don't think we need to worry about that soon anymore (if I understood correctly, that's for API24 or below - android 7.0)...


// -b system - shows the system buffer/logs only
// -T 1 - shows only new logs after starting adb logcat
const logcatCommand = [`logcat`, `-b`, `system`, `-T`, `1`];
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Note: Added the -b system flag. Probably not a huge difference, but only showing the system buffer should theoretically be faster than showing the default (system, crash, main).

@rigor789 rigor789 merged commit 8c5ef04 into NativeScript:main Sep 11, 2023
@vallemar
Copy link
Contributor

@rigor789 Is there a version to test these changes?

@rigor789
Copy link
Member

The next tag should have it.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

Successfully merging this pull request may close these issues.

[Android] Log stop when app killed and relaunched
4 participants