rts: add activity logging to give context for resource usage reports by marksvc · Pull Request #4061 · sillsdev/web-xforge

marksvc · 2026-08-19T22:44:14Z

This change is

marksvc · 2026-08-19T22:49:12Z

This branch has task/rts-connect as the merge target, as it is built no that branch. That branch will need to be merged before this PR can be.

codecov · 2026-08-19T22:52:26Z

Codecov Report

❌ Patch coverage is 91.72414% with 12 lines in your changes missing coverage. Please review.
✅ Project coverage is 81.12%. Comparing base (9ea2662) to head (4c14b30).
✅ All tests successful. No failed tests found.

Files with missing lines	Patch %	Lines
src/RealtimeServer/common/realtime-server.ts	83.72%	7 Missing ⚠️
src/RealtimeServer/common/activity-logger.ts	92.42%	5 Missing ⚠️

Additional details and impacted files

@@            Coverage Diff             @@
##           master    #4061      +/-   ##
==========================================
+ Coverage   81.09%   81.12%   +0.02%     
==========================================
  Files         666      669       +3     
  Lines       43263    43388     +125     
  Branches     7061     7115      +54     
==========================================
+ Hits        35085    35199     +114     
+ Misses       7013     7009       -4     
- Partials     1165     1180      +15

☔ View full report in Codecov by Harness.
📢 Have feedback on the report? Share it here.

github-actions · 2026-08-19T22:52:54Z

📸 Screenshot diff deployed! (1 change)

View the visual diff at: https://pr-4061--sf-screenshot-diffs.netlify.app

marksvc · 2026-08-19T23:27:36Z

src/RealtimeServer/common/index.ts line 343 at r1 (raw file):

    }
    const conn = connections.get(handle);
    conn?.fetchSnapshotByTimestamp(collection, id, timestamp, (err, snapshot) => {

Devin posted a concern about this. The main problem is pre-existing, and I am drafting a fix for it to go into a separate PR. (null conn never calls callback)

marksvc · 2026-08-20T15:48:55Z

src/RealtimeServer/common/realtime-server.ts line 428 at r1 (raw file):

        opsCount = 0;
      }
      ActivityLogger.instance.log('opSubmitted', {

Devin has expressed some concern about incompleteness of the logging, such as if an op submission is later rejected for permission reasons. In practice, the activity logger needs to show where the heavy or frequent activity is happening, rather than infrequent or special situations.

There may be some logging that is missing that would be relevant for identifying heavy activity. So that's something to keep an eye out for.

marksvc · 2026-08-20T16:05:30Z

src/RealtimeServer/common/activity-logger.ts line 19 at r1 (raw file):

}

const DEFAULT_LOG_LEVEL: RtsLogLevel = 'none';

Devin mentions that there is no log bound or rotation. I had a look at this and it looks like it shouldn't be too challenging to set up if we need it. We can do it at the system level; it looks like the application doesn't need additional changes to make that possible.

marksvc · 2026-08-20T16:07:11Z

src/RealtimeServer/common/activity-logger.ts line 112 at r1 (raw file):

          .map(batchEntry => JSON.stringify(batchEntry) + '\n')
          .join('');
        await appendFile(this.logPath, lines, { flag: 'a' });

Devin is concerned about multiple processes writing to the log at the same time. We only run one RealtimeServer at a time.

pmachapman

@pmachapman reviewed 12 files and all commit messages, made 6 comments, and resolved 3 discussions.
Reviewable status: all files reviewed, 6 unresolved discussions (waiting on marksvc).

src/RealtimeServer/common/activity-logger.ts line 19 at r1 (raw file):

Previously, marksvc wrote…

Devin mentions that there is no log bound or rotation. I had a look at this and it looks like it shouldn't be too challenging to set up if we need it. We can do it at the system level; it looks like the application doesn't need additional changes to make that possible.

Possibly the main problem will be a log filling up a server or workstation hard disk, because it was accidentally left running?

We could mitigate that by having rotation across X number of Y MB logs, and/or having different log levels, like DEBUG, INFO, WARNING, ERROR, etc.

src/RealtimeServer/common/interop-activity-logging.ts line 2 at r2 (raw file):

import { ActivityLogger } from './activity-logger';

Activity logging is really only half of this file. Do you think we should rename it to just interop.ts (or similar) given the generic interop nature of most of the exports in the top half of this file?

src/RealtimeServer/common/realtime-server.ts line 214 at r2 (raw file):

      });
      callback();
    });

I ran the backend with SF_RTS_LOG_LEVEL=all, but couldn't get more than one log entry (connectionEstablished) in the log when syncing a project and performing other regular actions. Was there something else I needed to do to get entries like this logged?

Code quote:

    this.use('afterWrite', (context, callback) => {
      ActivityLogger.instance.log('opCommitted', {
        collection: context.collection,
        docId: context.id,
        clientId: (context.agent as unknown as AgentInternal).clientId,
        srcClientId: context.op.src,
        opSeq: context.op.seq,
        version: context.snapshot?.v,
        saveMilestoneSnapshot: context.saveMilestoneSnapshot,
        source: this.resolvePersistedSource(context.collection, context.extra)
      });
      callback();
    });

src/RealtimeServer/common/realtime-server.ts line 658 at r2 (raw file):

   * opCommitted log's source field reflects what was actually persisted, not just what the client requested.
   */
  private resolvePersistedSource(collection: string, extra: any): string | undefined {

I think this method might get out of sync with the logic in this.use('commit', ...

Could you please add a comment in that block referring to this function so a future update won't forget about this?

Code quote:

private resolvePersistedSource(collection: string, extra: any): string | undefined {

src/RealtimeServer/common/utils/xdg-data-path.ts line 12 at r2 (raw file):

 * @param fallbackName Directory or file name joined onto the XDG_DATA_HOME/HOME/cwd fallback locations.
 */
export function resolveXdgDataPath(overrideEnvVarName: string, fallbackName: string): string {

Could we name this function something else like resolveLogDataPath or something?

For a Windows user like me, XDG wasn't so clear (and the XDG directory is only one of the cases this function returns).

Code quote:

resolveXdgDataPath

src/RealtimeServer/common/utils/xdg-data-path.ts line 22 at r2 (raw file):

  if (isStringPopulated(home)) return path.join(home, '.local', 'share', fallbackName);

  return path.join(process.cwd(), fallbackName);

On Windows this is the path that will be used, and so the log ends up in src/SIL.XForge.Scripture/sf-rts-activity-log/realtimeserver-log.jsonl.

Do you think sf-rts-activity-log should be added to .gitignore?

Or maybe we should fallback to os.tmpdir()? (Usually it is not a good idea to write to the program directory during execution. Windows applications are normally blocked from doing this by permissions).

Code quote:

return path.join(process.cwd(), fallbackName);

marksvc

@marksvc made 6 comments.
Reviewable status: all files reviewed, 6 unresolved discussions (waiting on pmachapman).

src/RealtimeServer/common/activity-logger.ts line 19 at r1 (raw file):

Possibly the main problem will be a log filling up a ... hard disk

Yeah.

My tentative plan is to have a server process that does something like the following daily:

move logfile to logfile-YYYY-MM-DD
xz logfile-YYYY-MM-DD

And that should significantly cut down on the storage usage. If we see it start to become a problem, we can turn off logging and restart SF.

We could mitigate that by having rotation across X number of Y MB logs

Yeah; I'm hoping to be able to capture everything over a period of time without needing to discard old logs. But we can see how it starts to look when put into practice.

src/RealtimeServer/common/interop-activity-logging.ts line 2 at r2 (raw file):