Buffer server logs before first connected client
MODIFY
packages/@romefrontend/cli-reporter/Reporter.ts
packages/@romefrontend/cli-reporter/Reporter.ts
@@ -40,6 +40,7 @@ import {onKeypress} from "./util";
import {
markupToHtml,
markupToPlainTextString,
+ normalizeMarkup,
} from "@romefrontend/string-markup/format";
import {
Stdout,
@@ -743,14 +744,14 @@ export default class Reporter {
writeAll(msg: string, opts: LogOptions = {}) {
for (const stream of this.getStreams(opts.stderr)) {
- this.writeSpecific(stream, msg);
+ this.writeSpecific(stream, msg, opts);
}
}
- writeSpecific(stream: ReporterStream, msg: string) {
+ writeSpecific(stream: ReporterStream, msg: string, opts: LogOptions) {
this.hasClearScreen = false;
- if (this.activeElements.size > 0) {
+ if (this.activeElements.size > 0 && opts.newline) {
// A progress bar is active and has probably drawn to the screen
this.clearLineSpecific(stream);
}
@@ -907,7 +908,7 @@ export default class Reporter {
}
case "markup": {
- return [built];
+ return [normalizeMarkup(built, this.markupOptions).text];
}
}
@@ -935,8 +936,15 @@ export default class Reporter {
logOne(stream: ReporterStream, msg: string, opts: LogOptions = {}) {
const lines = this.format(stream, msg);
- for (const line of lines) {
- this.logOneRaw(stream, line, opts);
+ for (let i = 0; i < lines.length; i++) {
+ this.logOneRaw(
+ stream,
+ lines[i],
+ {
+ ...opts,
+ newline: i === lines.length - 1 ? opts.newline : true,
+ },
+ );
}
}
@@ -958,7 +966,7 @@ export default class Reporter {
this.streamsWithNewlineEnd.delete(stream);
}
- this.writeSpecific(stream, msg);
+ this.writeSpecific(stream, msg, opts);
}
logAllWithCategory(
@@ -1004,10 +1012,7 @@ export default class Reporter {
markupTag(opts.markupTag, prefixInner),
);
const prefixedInner = `${prefix}<view>${inner}</view>`;
- const lines = this.format(stream, prefixedInner);
- for (const line of lines) {
- this.logOneRaw(stream, line, opts);
- }
+ this.logOne(stream, prefixedInner);
}
}

MODIFY
packages/@romefrontend/cli/cli.ts
packages/@romefrontend/cli/cli.ts
@@ -28,7 +28,7 @@ import {
import {commandCategories} from "@romefrontend/core/common/commands";
import {writeFile} from "@romefrontend/fs";
import fs = require("fs");
-import {markup} from "@romefrontend/string-markup";
+import {markup, markupToPlainTextString} from "@romefrontend/string-markup";
import {JSONObject, stringifyJSON} from "@romefrontend/codec-json";
import {getEnvVar} from "@romefrontend/environment";
@@ -458,13 +458,13 @@ export default async function cli() {
});
}
- await client.subscribeLogs(
+ client.subscribeLogs(
cliFlags.logWorkers === true,
(chunk) => {
if (fileout === undefined) {
- client.reporter.writeAll(chunk);
+ client.reporter.logAll(chunk, {newline: false});
} else {
- fileout.write(chunk);
+ fileout.write(markupToPlainTextString(chunk));
}
},
);

MODIFY
packages/@romefrontend/core/client/Client.ts
packages/@romefrontend/core/client/Client.ts
@@ -23,6 +23,7 @@ import fork from "../common/utils/fork";
import {
BridgeError,
Event,
+ EventSubscription,
createBridgeFromLocal,
createBridgeFromSocket,
} from "@romefrontend/events";
@@ -41,6 +42,7 @@ import zlib = require("zlib");
import fs = require("fs");
import child = require("child_process");
import {mergeObjects} from "@romefrontend/typescript-helpers";
+import {markupToPlainTextString} from "@romefrontend/string-markup";
export function getFilenameTimestamp(): string {
return new Date().toISOString().replace(/[^0-9a-zA-Z]/g, "");
@@ -133,7 +135,7 @@ export default class Client {
reporter: Reporter;
derivedReporterStreams: ReporterDerivedStreams;
bridgeStatus: undefined | BridgeStatus;
- bridgeAttachedEvent: Event<void, void>;
+ bridgeAttachedEvent: Event<BridgeStatus, void>;
requestResponseEvent: Event<ClientRequestResponseResult, void>;
endEvent: Event<void, void>;
@@ -275,17 +277,20 @@ export default class Client {
});
}
- async subscribeLogs(
+ subscribeLogs(
includeWorkerLogs: boolean,
callback: (chunk: string) => void,
- ): Promise<void> {
- const bridge = await this.findOrStartServer();
+ ): EventSubscription {
+ let logEvent: undefined | EventSubscription;
+ const bridgeAttachedEvent = this.bridgeAttachedEvent.subscribe(async (
+ {bridge},
+ ) => {
if (includeWorkerLogs) {
await bridge.enableWorkerLogs.call();
}
- bridge.log.subscribe(({origin, chunk}) => {
+ logEvent = bridge.log.subscribe(({origin, chunk}) => {
if (origin === "worker" && !includeWorkerLogs) {
// We allow multiple calls to bridge.enableWorkerLogs
// Filter the event if necessary if it wasn't requested by this log subscription
@@ -294,6 +299,16 @@ export default class Client {
callback(chunk);
});
+ });
+
+ return {
+ async unsubscribe() {
+ await bridgeAttachedEvent.unsubscribe();
+ if (logEvent !== undefined) {
+ await logEvent.unsubscribe();
+ }
+ },
+ };
}
async rage(ragePath: string, profileOpts: ClientProfileOptions) {
@@ -304,10 +319,10 @@ export default class Client {
}
let logs = "";
- await this.subscribeLogs(
+ this.subscribeLogs(
true,
(chunk) => {
- logs += chunk;
+ logs += markupToPlainTextString(chunk);
},
);
@@ -522,7 +537,7 @@ export default class Client {
bridge.handshake(),
]);
- await this.bridgeAttachedEvent.callOptional();
+ await this.bridgeAttachedEvent.callOptional(status);
}
async findOrStartServer(): Promise<ServerBridge> {

MODIFY
packages/@romefrontend/core/common/utils/Logger.ts
packages/@romefrontend/core/common/utils/Logger.ts
@@ -10,20 +10,11 @@ import {
ReporterConditionalStream,
ReporterOptions,
} from "@romefrontend/cli-reporter";
-import {AbsoluteFilePath} from "@romefrontend/path";
import {TERMINAL_FEATURES_DEFAULT} from "@romefrontend/environment";
-export type LoggerOptions = {
- cwd?: AbsoluteFilePath;
- excludePid?: boolean;
- type: string;
-};
-
-export type PartialLoggerOptions = Partial<LoggerOptions>;
-
export default class Logger extends Reporter {
constructor(
- loggerOptions: LoggerOptions,
+ loggerType: string,
opts: ReporterOptions,
{write, check}: {
check: () => boolean;
@@ -33,17 +24,13 @@ export default class Logger extends Reporter {
super({
verbose: true,
...opts,
- markupOptions: {
- cwd: loggerOptions.cwd,
- ...opts.markupOptions,
- },
});
- this.loggerOptions = loggerOptions;
+ this.loggerType = loggerType;
this.conditionalStream = this.attachConditionalStream(
{
type: "all",
- format: "none",
+ format: "markup",
features: {
...TERMINAL_FEATURES_DEFAULT,
columns: Infinity,
@@ -55,17 +42,15 @@ export default class Logger extends Reporter {
}
conditionalStream: ReporterConditionalStream;
- loggerOptions: LoggerOptions;
+ loggerType: string;
updateStream() {
this.conditionalStream.update();
}
- _getMessagePrefix() {
- let inner = this.loggerOptions.type;
- if (!this.loggerOptions.excludePid) {
- inner += ` ${process.pid}`;
- }
- return `<dim>[${inner}]</dim> `;
+ getMessagePrefix() {
+ const inner = `${this.loggerType} ${process.pid}`;
+ const timestamp = new Date().toISOString();
+ return `<dim>[${timestamp}] [${inner}]</dim> `;
}
}

MODIFY
packages/@romefrontend/core/integrationTestHelpers.ts
packages/@romefrontend/core/integrationTestHelpers.ts
@@ -162,11 +162,6 @@ export function createIntegrationTest(
// Force cache to be enabled (which will be at our generated folder specified above)
// This will ignore any ROME_CACHE env variable specified by scripts/dev-rome
forceCacheEnabled: true,
- // Custom loggerOptions so that logs don't vary between runs. ie. relative paths and no PIDs
- loggerOptions: {
- cwd: temp,
- excludePid: true,
- },
userConfig,
});

MODIFY
packages/@romefrontend/core/server/Server.ts
packages/@romefrontend/core/server/Server.ts
@@ -37,7 +37,7 @@ import ProjectManager from "./project/ProjectManager";
import WorkerManager from "./WorkerManager";
import Resolver from "./fs/Resolver";
import FileAllocator from "./fs/FileAllocator";
-import Logger, {PartialLoggerOptions} from "../common/utils/Logger";
+import Logger from "../common/utils/Logger";
import MemoryFileSystem from "./fs/MemoryFileSystem";
import Cache from "./Cache";
import {Reporter, ReporterStream} from "@romefrontend/cli-reporter";
@@ -84,7 +84,6 @@ export type ServerClient = {
export type ServerOptions = {
inbandOnly?: boolean;
- loggerOptions?: PartialLoggerOptions;
forceCacheEnabled?: boolean;
userConfig?: UserConfig;
dedicated: boolean;
@@ -189,6 +188,12 @@ export default class Server {
this.connectedLSPServers = new Set();
this.connectedClients = new Set();
+ this.clientIdCounter = 0;
+
+ this.logInitBuffer = "";
+ this.requestRunningCounter = 0;
+ this.terminateWhenIdle = false;
+
this.clientStartEvent = new Event({
name: "Server.clientStart",
onError: this.onFatalErrorBound,
@@ -211,10 +216,7 @@ export default class Server {
});
this.logger = new Logger(
- {
- ...opts.loggerOptions,
- type: "server",
- },
+ "server",
{
markupOptions: {
userConfig: this.userConfig,
@@ -245,10 +247,14 @@ export default class Server {
this.emitServerLog(chunk);
},
check: () => {
- return this.connectedClientsListeningForLogs.size > 0;
+ return (
+ this.clientIdCounter === 0 ||
+ this.connectedClientsListeningForLogs.size > 0
+ );
},
},
);
+ this.logger.updateStream();
this.virtualModules = new VirtualModules(this);
this.memoryFs = new MemoryFileSystem(this);
@@ -258,10 +264,7 @@ export default class Server {
this.resolver = new Resolver(this);
this.cache = new Cache(this);
- this.clientIdCounter = 0;
-
- this.requestRunningCounter = 0;
- this.terminateWhenIdle = false;
+ this.logger.info("[Server] Created Server with options", opts);
}
userConfig: UserConfig;
@@ -297,11 +300,20 @@ export default class Server {
connectedReporters: ServerReporter;
logger: Logger;
requestFileLocker: FilePathLocker;
+
+ // Before we receive our first connected client we will buffer our server init logs
+ // These should be relatively cheap to process since we don't do a lot
+ logInitBuffer: string;
+
connectedClients: Set<ServerClient>;
connectedLSPServers: Set<LSPServer>;
connectedClientsListeningForLogs: Set<ServerClient>;
emitServerLog(chunk: string) {
+ if (this.clientIdCounter === 0) {
+ this.logInitBuffer += chunk;
+ }
+
for (const {bridge} of this.connectedClientsListeningForLogs) {
// Sometimes the bridge hasn't completely been teardown and we still consider it connected
if (bridge.alive) {
@@ -707,7 +719,16 @@ export default class Server {
bridge.updatedListenersEvent.subscribe((listeners) => {
if (listeners.has("log")) {
+ if (!this.connectedClientsListeningForLogs.has(client)) {
this.connectedClientsListeningForLogs.add(client);
+ let buffer = this.logInitBuffer;
+ buffer += ".".repeat(20);
+ buffer += "\n";
+ bridge.log.send({
+ chunk: buffer,
+ origin: "server",
+ });
+ }
} else {
this.connectedClientsListeningForLogs.delete(client);
}
@@ -1067,7 +1088,6 @@ export default class Server {
printer.print();
// We could probably return printer.getDiagnostics() but we just want to print to the console
-
// We will still want to send the `error` property
return undefined;
}

MODIFY
packages/@romefrontend/core/server/ServerReporter.ts
packages/@romefrontend/core/server/ServerReporter.ts
@@ -23,9 +23,16 @@ export default class ServerReporter extends Reporter {
server: Server;
- // This is so all progress bars are also shown on an LSP client, alongside connected CLIs
+ // This is so all progress bars are renderer on each client. If we just use this.progressLocal then
+ // while it would work, we would be doing all the rendering work on the server
+ // The CLI also needs to know all the activeElements so it can properly draw and clear lines
+ // We also create a progress bar for all connected LSP clients
progress(opts?: ReporterProgressOptions): ReporterProgress {
- const progresses: Array<ReporterProgress> = [this.progressLocal(opts)];
+ const progresses: Array<ReporterProgress> = [];
+
+ for (const client of this.server.connectedClients) {
+ progresses.push(client.reporter.progress(opts));
+ }
for (const server of this.server.connectedLSPServers) {
progresses.push(server.createProgress(opts));

MODIFY
packages/@romefrontend/core/server/ServerRequest.ts
packages/@romefrontend/core/server/ServerRequest.ts
@@ -819,7 +819,9 @@ export default class ServerRequest {
startMarker(
opts: Omit<ServerUnfinishedMarker, "start">,
): ServerUnfinishedMarker {
- this.server.logger.info("[ServerRequest] Started marker", opts.label);
+ this.server.logger.info(
+ markup`[ServerRequest] Started marker: ${opts.label}`,
+ );
return {
...opts,
start: Date.now(),
@@ -832,8 +834,7 @@ export default class ServerRequest {
end: Date.now(),
};
this.server.logger.info(
- "[ServerRequest] Finished marker",
- startMarker.label,
+ markup`[ServerRequest] Started marker: ${startMarker.label}`,
);
this.markerEvent.send(endMarker);
return endMarker;

MODIFY
packages/@romefrontend/core/server/WorkerManager.ts
packages/@romefrontend/core/server/WorkerManager.ts
@@ -131,14 +131,12 @@ export default class WorkerManager {
// Create the worker
const bridge = createBridgeFromLocal(WorkerBridge, {});
const worker = new Worker({
- loggerOptions: this.server.logger.loggerOptions,
userConfig: this.server.userConfig,
bridge,
globalErrorHandlers: false,
});
// We make an assumption elsewhere in the code that this is always the first worker
-
// Let's use an invariant here for completeness
const id = this.getNextWorkerId();
if (id !== 0) {

MODIFY
packages/@romefrontend/core/server/fs/FileAllocator.ts
packages/@romefrontend/core/server/fs/FileAllocator.ts
@@ -156,7 +156,7 @@ export default class FileAllocator {
}
async assignOwner(path: AbsoluteFilePath): Promise<WorkerContainer> {
- const {workerManager, logger} = this.server;
+ const {workerManager, logger, memoryFs} = this.server;
const lock = await this.locker.getLock(path);
@@ -165,14 +165,15 @@ export default class FileAllocator {
lock.release();
return this.getOwnerAssert(path);
}
+
try {
const worker = await workerManager.getNextWorker(path);
// Add ourselves to the file map
logger.info(
- "[FileAllocator] File %s assigned to worker %s",
- path.toMarkup(),
- worker.id,
+ `[FileAllocator] File <emphasis>${path.toMarkup()}</emphasis> (file size <filesize>${memoryFs.getFileStats(
+ path,
+ )?.size}</filesize>) assigned to worker <number>${worker.id}</number>`,
);
this.fileToWorker.set(path, worker.id);

MODIFY
packages/@romefrontend/core/server/fs/MemoryFileSystem.ts
packages/@romefrontend/core/server/fs/MemoryFileSystem.ts
@@ -28,7 +28,6 @@ import {
} from "@romefrontend/diagnostics";
import {Event} from "@romefrontend/events";
import {consumeJSON} from "@romefrontend/codec-json";
-import {humanizeNumber} from "@romefrontend/string-utils";
import {WorkerPartialManifest} from "../../common/bridges/WorkerBridge";
import {
AbsoluteFilePath,
@@ -43,7 +42,6 @@ import {
watch,
} from "@romefrontend/fs";
import {getFileHandler} from "../../common/file-handlers/index";
-import {markup} from "@romefrontend/string-markup";
import crypto = require("crypto");
import fs = require("fs");
import {FileNotFound} from "@romefrontend/core/common/FileNotFound";
@@ -145,11 +143,12 @@ async function createWatcher(
projectFolder: AbsoluteFilePath,
): Promise<WatcherClose> {
const {logger} = memoryFs.server;
+ const projectFolderMarkup = "<emphasis>projectFolder.toMarkup()</emphasis>";
// Create activity spinners for all connected reporters
const activity = memoryFs.server.connectedReporters.progress({
initDelay: 1_000,
- title: `Adding project ${projectFolder.toMarkup()}`,
+ title: `Adding project ${projectFolderMarkup}`,
});
const watchers: AbsoluteFilePathMap<fs.FSWatcher> = new AbsoluteFilePathMap();
@@ -175,7 +174,7 @@ async function createWatcher(
{recursive, persistent: false},
(eventType, filename) => {
memoryFs.server.logger.info(
- `[MemoryFileSystem] Raw fs.watch event in ${folderPath.toMarkup()} type ${eventType} for ${filename}`,
+ `[MemoryFileSystem] Raw fs.watch event in <emphasis>${folderPath.toMarkup()}</emphasis> type ${eventType} for ${filename}`,
);
if (filename === null) {
@@ -207,9 +206,9 @@ async function createWatcher(
},
);
logger.info(
- `[MemoryFileSystem] Finished initial crawl for ${projectFolder.toMarkup()} - added ${humanizeNumber(
- memoryFs.countFiles(projectFolder),
- )} files`,
+ `[MemoryFileSystem] Finished initial crawl for <emphasis>${projectFolder.toMarkup()}</emphasis> - added <number>${memoryFs.countFiles(
+ projectFolder,
+ )}</number> files`,
);
} finally {
activity.end();
@@ -456,8 +455,7 @@ export default class MemoryFileSystem {
async watch(projectFolder: AbsoluteFilePath): Promise<void> {
const {logger} = this.server;
- const projectFolderJoined = projectFolder.join();
- const folderLink = markup`<filelink target="${projectFolderJoined}" />`;
+ const folderLink = `<emphasis>${projectFolder.toMarkup()}</emphasis>`;
// Defer if we're already currently initializing this project
const cached = this.watchPromises.get(projectFolder);
@@ -962,8 +960,7 @@ export default class MemoryFileSystem {
const oldStats = this.getFileStats(path);
if (oldStats !== undefined && opts.reason === "watch") {
this.server.logger.info(
- "[MemoryFileSystem] File change:",
- path.toMarkup(),
+ `[MemoryFileSystem] File change: <emphasis>${path.toMarkup()}</emphasis>`,
);
this.server.refreshFileEvent.send(path);
this.changedFileEvent.send({path, oldStats, newStats: stats});

MODIFY
packages/@romefrontend/core/worker/Worker.ts
packages/@romefrontend/core/worker/Worker.ts
@@ -15,9 +15,8 @@ import WorkerBridge, {
WorkerProjects,
} from "../common/bridges/WorkerBridge";
import {AnyRoot, ConstJSSourceType, JSRoot} from "@romefrontend/ast";
-import Logger, {PartialLoggerOptions} from "../common/utils/Logger";
+import Logger from "../common/utils/Logger";
import {Profiler} from "@romefrontend/v8";
-
import setupGlobalErrorHandlers from "../common/utils/setupGlobalErrorHandlers";
import {UserConfig, loadUserConfig} from "../common/userConfig";
import {hydrateJSONProjectConfig} from "@romefrontend/project";
@@ -50,7 +49,6 @@ export type ParseResult = {
};
type WorkerOptions = {
- loggerOptions?: PartialLoggerOptions;
userConfig?: UserConfig;
globalErrorHandlers: boolean;
bridge: WorkerBridge;
@@ -69,10 +67,7 @@ export default class Worker {
this.buffers = new AbsoluteFilePathMap();
this.logger = new Logger(
- {
- ...opts.loggerOptions,
- type: "worker",
- },
+ "worker",
{},
{
check: () => opts.bridge.log.hasSubscribers(),

MODIFY
packages/@romefrontend/string-markup/format.ts
packages/@romefrontend/string-markup/format.ts
@@ -135,7 +135,7 @@ function renderGrid(
...opts,
sourceText: input,
});
- grid.drawRoot(parseMarkup(input));
+ grid.drawChildren(grid.parse(input, undefined), []);
return {
width: ob1Get1(grid.getWidth()),
lines: grid.getLines(format),

MODIFY
packages/@romefrontend/string-markup/grid/Grid.ts
packages/@romefrontend/string-markup/grid/Grid.ts
@@ -47,7 +47,6 @@ import {
TERMINAL_FEATURES_DEFAULT,
TerminalFeatures,
} from "@romefrontend/environment";
-
import {parseMarkup} from "../parse";
import {Position} from "@romefrontend/parser-core";
import {lineWrapValidator} from "../tags";
@@ -329,6 +328,11 @@ export default class Grid {
}
moveCursor(cursor: Cursor) {
+ if (cursor.line !== this.cursor.line) {
+ this.lineStartMeta.indentationCount = 0;
+ this.lineStartMeta.sourceColumn = this.sourceCursor.currentColumn;
+ }
+
this.cursor = cursor;
}
@@ -346,7 +350,7 @@ export default class Grid {
if (this.doesOverflowViewport(newColumns)) {
const currentLine = this.lines[ob1Get1(this.cursor.line) - 1];
- this.newline();
+ this.moveCursorBottomStart();
// Inherit the previous lines indentation
if (currentLine !== undefined) {
@@ -374,9 +378,8 @@ export default class Grid {
}
newline() {
- this.lineStartMeta.indentationCount = 0;
- this.lineStartMeta.sourceColumn = this.sourceCursor.currentColumn;
this.moveCursorBottomStart();
+ this.fillCursor(this.cursor);
}
moveCursorStart() {
@@ -477,7 +480,7 @@ export default class Grid {
(this.doesOverflowViewport(ob1Add(this.cursor.column, word.length - 1)) &&
!this.doesOverflowViewport(ob1Coerce1(word.length))));
if (willOverflow) {
- this.newline();
+ this.moveCursorBottomStart();
}
forceNextWordOverflow = false;
@@ -730,8 +733,9 @@ export default class Grid {
drawView({children, attributes}: TagNode, ancestry: Ancestry) {
// We allow markup in the linePrefix tag... Not sure how else we can support it.
// NB: This assumes that the line prefix is only 1 height, maybe we could have some validation
- const linePrefix = this.normalizeChildren(
- parseMarkup(attributes.get("linePrefix").asString("")),
+ const linePrefix = this.parse(
+ attributes.get("linePrefix").asString(""),
+ attributes.get("linePrefix").getDiagnosticLocation("inner-value").start,
);
const linePrefixStart = this.getCursor();
@@ -964,10 +968,6 @@ export default class Grid {
}
}
- drawRoot(children: Children) {
- this.drawChildren(this.normalizeChildren(children), []);
- }
-
normalizeChildren(children: Children): Children {
let newChildren: Children = [];
@@ -1170,16 +1170,24 @@ export default class Grid {
switch (tag.name) {
case "filesize":
return [
+ {
+ ...tag,
+ children: [
{
type: "Text",
source: false,
sourceValue: singleInnerText,
value: humanizeFileSize(Number(singleInnerText)),
},
+ ],
+ },
];
case "duration":
return [
+ {
+ ...tag,
+ children: [
{
type: "Text",
source: false,
@@ -1189,26 +1197,38 @@ export default class Grid {
humanizeTime(Number(singleInnerText), true),
),
},
+ ],
+ },
];
case "number":
return [
+ {
+ ...tag,
+ children: [
{
type: "Text",
source: false,
sourceValue: singleInnerText,
value: formatNumber(attributes, singleInnerText),
},
+ ],
+ },
];
case "grammarNumber":
return [
+ {
+ ...tag,
+ children: [
{
type: "Text",
source: false,
sourceValue: singleInnerText,
value: formatGrammarNumber(attributes, singleInnerText),
},
+ ],
+ },
];
}
}

Buffer server logs before first connected client (#784)