Improve app log to provide better user support

[laurent22]

Currently it is difficult to help with this kind of support request:

https://discourse.joplinapp.org/t/new-notes-disappeared/34162?u=laurent

Because we don't know when and how that particular note got deleted - it could be via sync, it could be a user action, and maybe the note is in the conflict folder. For deletion, we need the log to be as precise as possible: was it deleted by selecting and pressing the delete button, or by right-clicking and deleting, or by press "delete" on the keyboard, or via an API action, etc. It means including some context when we call Note.delete()

We should have maybe a separate "note log" that records everything that happened to notes, with the actual note title + ID. This log can't be shared easily for privacy reasons but at least we can potentially ask the user to send it via PM.

Or we can explain the user how to open this log, and search for the note title, then tell us what was found.

We should only record Creation and Deletion of notes. Recording all updates would be useful but would probably generate too much data. Unless we only record one change every x minutes.

Basically anything that allows us to answer the question "Where's my note??"

Implementation

(To be completed)

Perhaps we should just use the existing log for this, but use a specific prefix such as "notelog" (or something better), so that we can filter easily to just the note log. It may mean that in addition to this task we should implement a way to filter the log (in mobile in particular). Perhaps in desktop too? For example a way to generate a second file from the main log that includes only the note log.

Note updates

We probably shouldn't keep a log entry for each note body update as there will be too many of them. But maybe we could keep one when a note property is changed - in particular it would be useful to know when the parent ID, to-do status, or title is changed as all this can affect the visibility of the note.

[personalizedrefrigerator]

Possible solution: Add a Sensitive log level

Currently, Logger.ts supports different log levels. To address this, I propose adding a Sensitive log level:

export enum LogLevel {
	None = 0,
	Error = 10,
	Warn = 20,
	Info = 30,
	Debug = 40,

+   // Information logged during production, but should not
+   // be made public for privacy reasons. (E.g. note titles).
+   // Should NOT include passwords or keys.
+   Sensitive = 50,
}

Code could then log sensitive information with a method similar to logger.sensitive('sensitive information here').

Desktop UI & storage

Currently, the desktop app stores log data in files. To allow users to share log.txt without sensitive information, logger.sensitive could log to log.sensitive.txt (or similar).

Mobile UI

As the mobile app already supports filtering by error/non-error logs, we could include an off-by-default "include potentially sensitive information" checkbox:

If Sensitive information is enabled, we may also want to display a confirmation dialog when sharing:

Benefits

• Makes it clear in code and UI what information is sensitive.
• Users can share all log data privately (via direct message) and not need to worry about including a normal log and an app actions log.
• (Hopefully) more difficult to have a bug that exports sensitive log data.

Drawbacks

• Possibly harder to debug. A solution that provides just note actions may be easier to inspect (no need to filter out things that aren't note actions).

To-do

• Add new log level & logging function (~3 min)
• Logger::lastEntries: Don't return Sensitive logs by default (applies to mobile/database logging only) (~30 min)
• File logging: Send Sensitive logs to a different file (~30 min)
• Update RotatingLogs.ts to also rotate .sensitive logs (~1 hour)
• Mobile: New UI (~1 hour)
• Tests (~1-2 hours)

[laurent22]

Hmm, at this point, I'd prefer we don't focus on whether it's sensitive data or not - we can deal with this in a separate pull request and look into ways for users to share log without sharing private data. Also I don't feel it should be a log level? A debug or info log statement can also have sensitive information, so it's more a separate property of the statement.

However that's not what we need to focus on for now. We can always ask the user to search by themselves and tell us for example how a particular was deleted or created, without having to tell us the note title.

And I prefer if everything goes in the same log. I thought too about having a separate log but the problem is that we lose context and what other actions were performed before and after the note action happened. Once it's in the log we can always filter to get out only what's needed.

So to be clear, we should see something like this in the log:

- DATE_TIME: Note "Meeting report" (ID) was created: By clicking on the "New note" button
- DATE_TIME: Note "Holiday plan" (ID) was deleted: From the note context menu
- DATE_TIME: Note "Draft" (ID) was deleted: From the synchronizer

etc.

And to find back these log statements, we should prefix them with something. For example, "NoteAction: ......"

I think in your plan is missing how you're going to get the context information("From the synchronizer", etc.), which I feel is where most of the work is :)

[personalizedrefrigerator]

Possible solution: Include a context option in BaseResource methods

Synchronizer.ts already logs some amount of context:

...
	if (!local) {
		if (remote.isDeleted !== true) {
			action = 'createLocal';
			reason = 'remote exists but local does not';
			content = await loadContent();
			ItemClass = content ? BaseItem.itemClass(content) : null;
		}
	} else {
		ItemClass = BaseItem.itemClass(local);
		local = ItemClass.filter(local);
		if (remote.isDeleted) {
			action = 'deleteLocal';
			reason = 'remote has been deleted';
		} else {
			...
		}
	}
...

this.logSyncOperation(action, local, remote, reason);

Issues with the current logging method:

• It's specific to the synchronizer — items deleted elsewhere may lack a corresponding log and context.
• It's difficult to find the ID for a specific item that has been deleted

If we keep the existing logSyncOperation calls, we don't need to include the reason notes were deleted (as that should already be present), just the title, the ID, and what deleted the note.

One option is to make calls to methods like Folder.delete or BaseItem.batchDelete take a context: ActionContext parameter (or similar).

ActionContext could either be a string or an object.

If an object, it might have this form:

class ActionContext {
	// E.g. "the Synchronizer" or "the long-press menu"
	setActionSource(description: string): void;

	// E.g. "delta"
	setStep(stepDescription: string): void;

	// Maybe?? Probably this should go in the logger:
	//logMessage(...message: string[]): void;
}

Note::save currently has the following method signature:

public static async save(o: NoteEntity, options: SaveOptions = null): Promise<NoteEntity> {

Context can also be passed through the options parameter to Note::save and similar methods.

BaseItem and its subclasses can then use ActionContext to create a log message that includes context.

[laurent22]

If we keep the existing logSyncOperation calls, we don't need to include the reason notes were deleted (as that should already be present), just the title, the ID, and what deleted the note.

Yes we'll keep the sync log, even if it means slightly redundant information.

Note::save currently has the following method signature:

All save and delete calls have options I believe, so indeed anything we add should go in that option object.

If an object, it might have this form:

Ok, but that should be an object with plain properties, not a class instance, right? And I'm not sure the "step" parameter is necessary, since there won't be that many variations for a given source. And if there are some variations, you can make different sources. For example { source: ActionContext.SynchronizerDeletionStep }, { source: ActionContext.SynchronizerDeltaStep }, but just { source: ActionContext.LongPressMenu }