From 27353fef2007eccf484dca6075eb1a30bc4d6ba3 Mon Sep 17 00:00:00 2001 From: Dominic Saadi Date: Sun, 28 Jan 2024 17:24:30 +0000 Subject: [PATCH] fix(serve): fix server listening logs (#9894) Right now logs from `yarn rw serve` are a bit deceiving. `yarn rw serve` sets `NODE_ENV` to `'production'` if it's not already set. This changes the host the server ends up listening on: https://github.com/redwoodjs/redwood/blob/97296d4c57e6dffb4eee2489397a3486d11e24fd/packages/cli/src/commands/serve.js#L195-L198 https://github.com/redwoodjs/redwood/blob/97296d4c57e6dffb4eee2489397a3486d11e24fd/packages/cli/src/commands/serveBothHandler.js#L125-L128 Basically, if a user doesn't set `NODE_ENV`, `yarn rw serve` serves everything at `'0.0.0.0'`. But we've hardcoded `'localhost'` in our logs: https://github.com/redwoodjs/redwood/blob/97296d4c57e6dffb4eee2489397a3486d11e24fd/packages/cli/src/commands/serveBothHandler.js#L136-L141 At first it doesn't appear wrong if you go to http://localhost:8910. It's there. But that's only because `'0.0.0.0'` means listen on all ipv4 addresses. This may seem like a small change but it's a bug if your server is listening on localhost in Docker and on deploy providers. When you look at the serve logs in a container, this is giving the impression that something is misconfigured when everything is actually fine. Instead let's just use the return from `fastify.listen` or `fastify.listeningOrigin` which tell us where it's listening. #### Before image #### After image --------- Co-authored-by: Tobbe Lundberg --- .../src/__tests__/createServer.test.ts | 4 +- packages/api-server/src/cliHandlers.ts | 71 ++++++++++--------- packages/api-server/src/createServer.ts | 14 +--- packages/api-server/src/fastify.ts | 2 +- .../api-server/src/plugins/lambdaLoader.ts | 6 +- packages/api-server/src/server.ts | 18 ++++- packages/api-server/src/watch.ts | 4 +- packages/cli/src/commands/serveApiHandler.js | 15 ++-- packages/cli/src/commands/serveBothHandler.js | 24 +++---- packages/fastify/src/config.ts | 2 +- packages/web-server/src/webServer.ts | 4 +- 11 files changed, 86 insertions(+), 78 deletions(-) diff --git a/packages/api-server/src/__tests__/createServer.test.ts b/packages/api-server/src/__tests__/createServer.test.ts index 5026218767..5b60161b6a 100644 --- a/packages/api-server/src/__tests__/createServer.test.ts +++ b/packages/api-server/src/__tests__/createServer.test.ts @@ -119,7 +119,9 @@ describe('createServer', () => { const lastCallIndex = consoleLogSpy.mock.calls.length - 1 - expect(consoleLogSpy.mock.calls[lastCallIndex][0]).toMatch(/Listening on/) + expect(consoleLogSpy.mock.calls[lastCallIndex][0]).toMatch( + /Server listening at/ + ) // `console.warn` will be used if there's a `server.config.js` file. expect(consoleWarnSpy.mock.calls[0][0]).toMatchInlineSnapshot(` diff --git a/packages/api-server/src/cliHandlers.ts b/packages/api-server/src/cliHandlers.ts index 219a9a694f..3ef2117e8e 100644 --- a/packages/api-server/src/cliHandlers.ts +++ b/packages/api-server/src/cliHandlers.ts @@ -43,37 +43,47 @@ export const apiCliOptions = { export const apiServerHandler = async (options: ApiServerArgs) => { const { port, socket, apiRootPath } = options const tsApiServer = Date.now() - process.stdout.write(c.dim(c.italic('Starting API Server...\n'))) + console.log(c.dim.italic('Starting API Server...')) let fastify = createFastifyInstance() // Import Server Functions. fastify = await withFunctions(fastify, options) - const http = startFastifyServer({ - port, - socket, - fastify, - }).ready(() => { - console.log(c.italic(c.dim('Took ' + (Date.now() - tsApiServer) + ' ms'))) - - const on = socket - ? socket - : c.magenta(`http://localhost:${port}${apiRootPath}`) - console.log(`API listening on ${on}`) - const graphqlEnd = c.magenta(`${apiRootPath}graphql`) - console.log(`GraphQL endpoint at ${graphqlEnd}`) + fastify = await startFastifyServer({ port, socket, fastify }) + + fastify.ready(() => { + console.log(c.dim.italic('Took ' + (Date.now() - tsApiServer) + ' ms')) + + // In the past, in development, we've prioritized showing a friendlier + // host than the listen-on-all-ipv6-addresses '[::]'. Here we replace it + // with 'localhost' only if 1) we're not in production and 2) it's there. + // In production it's important to be transparent. + // + // We have this logic for `apiServerHandler` because this is the only + // handler called by the watch bin (which is called by `yarn rw dev`). + let address = fastify.listeningOrigin + if (process.env.NODE_ENV !== 'production') { + address = address.replace(/http:\/\/\[::\]/, 'http://localhost') + } + + const apiServer = c.magenta(`${address}${apiRootPath}`) + const graphqlEndpoint = c.magenta(`${apiServer}graphql`) + + console.log(`API server listening at ${apiServer}`) + console.log(`GraphQL endpoint at ${graphqlEndpoint}`) + sendProcessReady() }) process.on('exit', () => { - http?.close() + fastify?.close() }) } export const bothServerHandler = async (options: BothServerArgs) => { const { port, socket } = options const tsServer = Date.now() - process.stdout.write(c.dim(c.italic('Starting API and Web Servers...\n'))) + console.log(c.dim.italic('Starting API and Web Servers...')) const apiRootPath = coerceRootPath(getConfig().web.apiUrl) let fastify = createFastifyInstance() @@ -81,22 +91,19 @@ export const bothServerHandler = async (options: BothServerArgs) => { await fastify.register(redwoodFastifyWeb) fastify = await withFunctions(fastify, { ...options, apiRootPath }) - startFastifyServer({ - port, - socket, - fastify, - }).ready(() => { - console.log(c.italic(c.dim('Took ' + (Date.now() - tsServer) + ' ms'))) - const on = socket - ? socket - : c.magenta(`http://localhost:${port}${apiRootPath}`) - const webServer = c.green(`http://localhost:${port}`) - const apiServer = c.magenta(`http://localhost:${port}`) - console.log(`Web server started on ${webServer}`) - console.log(`API serving from ${apiServer}`) - console.log(`API listening on ${on}`) - const graphqlEnd = c.magenta(`${apiRootPath}graphql`) - console.log(`GraphQL endpoint at ${graphqlEnd}`) + fastify = await startFastifyServer({ port, socket, fastify }) + + fastify.ready(() => { + console.log(c.dim.italic('Took ' + (Date.now() - tsServer) + ' ms')) + + const webServer = c.green(fastify.listeningOrigin) + const apiServer = c.magenta(`${fastify.listeningOrigin}${apiRootPath}`) + const graphqlEndpoint = c.magenta(`${apiServer}graphql`) + + console.log(`Web server listening at ${webServer}`) + console.log(`API server listening at ${apiServer}`) + console.log(`GraphQL endpoint at ${graphqlEndpoint}`) + sendProcessReady() }) } diff --git a/packages/api-server/src/createServer.ts b/packages/api-server/src/createServer.ts index 771bd079e9..768f810058 100644 --- a/packages/api-server/src/createServer.ts +++ b/packages/api-server/src/createServer.ts @@ -161,20 +161,10 @@ export async function createServer(options: CreateServerOptions = {}) { done() }) - // Just logging. The conditional here is to appease TS. - // `server.server.address()` can return a string, an AddressInfo object, or null. - // Note that the logging here ("Listening on...") seems to be duplicated, probably by `@redwoodjs/graphql-server` server.addHook('onListen', (done) => { - const addressInfo = server.server.address() - - if (!addressInfo || typeof addressInfo === 'string') { - done() - return - } - console.log( - `Listening on ${c.magenta( - `http://${addressInfo.address}:${addressInfo.port}${apiRootPath}` + `Server listening at ${c.magenta( + `${server.listeningOrigin}${apiRootPath}` )}` ) done() diff --git a/packages/api-server/src/fastify.ts b/packages/api-server/src/fastify.ts index f6d419176c..0a474edf67 100644 --- a/packages/api-server/src/fastify.ts +++ b/packages/api-server/src/fastify.ts @@ -47,7 +47,7 @@ export function loadFastifyConfig() { } if (!isServerConfigLoaded) { - console.log(`Loading server config from ${serverConfigPath} \n`) + console.log(`Loading server config from ${serverConfigPath}`) serverConfigFile = { ...require(serverConfigPath) } isServerConfigLoaded = true } diff --git a/packages/api-server/src/plugins/lambdaLoader.ts b/packages/api-server/src/plugins/lambdaLoader.ts index ebcdce6fb1..c002ee601e 100644 --- a/packages/api-server/src/plugins/lambdaLoader.ts +++ b/packages/api-server/src/plugins/lambdaLoader.ts @@ -22,7 +22,7 @@ export const LAMBDA_FUNCTIONS: Lambdas = {} export const setLambdaFunctions = async (foundFunctions: string[]) => { const tsImport = Date.now() - console.log(c.italic(c.dim('Importing Server Functions... '))) + console.log(c.dim.italic('Importing Server Functions... ')) const imports = foundFunctions.map((fnPath) => { return new Promise((resolve) => { @@ -42,7 +42,7 @@ export const setLambdaFunctions = async (foundFunctions: string[]) => { // TODO: Use terminal link. console.log( c.magenta('/' + routeName), - c.italic(c.dim(Date.now() - ts + ' ms')) + c.dim.italic(Date.now() - ts + ' ms') ) return resolve(true) }) @@ -50,7 +50,7 @@ export const setLambdaFunctions = async (foundFunctions: string[]) => { Promise.all(imports).then((_results) => { console.log( - c.italic(c.dim('...Done importing in ' + (Date.now() - tsImport) + ' ms')) + c.dim.italic('...Done importing in ' + (Date.now() - tsImport) + ' ms') ) }) } diff --git a/packages/api-server/src/server.ts b/packages/api-server/src/server.ts index eda581d3d3..1d6a3b5405 100644 --- a/packages/api-server/src/server.ts +++ b/packages/api-server/src/server.ts @@ -6,7 +6,7 @@ export interface HttpServerParams { fastify: FastifyInstance } -export const startServer = ({ +export const startServer = async ({ port = 8911, socket, fastify, @@ -14,7 +14,21 @@ export const startServer = ({ const host = process.env.NODE_ENV === 'production' ? '0.0.0.0' : '::' const serverPort = socket ? parseInt(socket) : port - fastify.listen({ port: serverPort, host }) + await fastify.listen({ + port: serverPort, + host, + listenTextResolver: (address) => { + // In the past, in development, we've prioritized showing a friendlier + // host than the listen-on-all-ipv6-addresses '[::]'. Here we replace it + // with 'localhost' only if 1) we're not in production and 2) it's there. + // In production it's important to be transparent. + if (process.env.NODE_ENV !== 'production') { + address = address.replace(/http:\/\/\[::\]/, 'http://localhost') + } + + return `Server listening at ${address}` + }, + }) fastify.ready(() => { fastify.log.trace( diff --git a/packages/api-server/src/watch.ts b/packages/api-server/src/watch.ts index 6af09d7a2c..aee598579d 100644 --- a/packages/api-server/src/watch.ts +++ b/packages/api-server/src/watch.ts @@ -85,7 +85,7 @@ const buildAndRestart = async ({ killApiServer() const buildTs = Date.now() - process.stdout.write(c.dim(c.italic('Building... '))) + console.log(c.dim.italic('Building...')) if (clean) { await cleanApiBuild() @@ -96,7 +96,7 @@ const buildAndRestart = async ({ } else { await buildApi() } - console.log(c.dim(c.italic('Took ' + (Date.now() - buildTs) + ' ms'))) + console.log(c.dim.italic('Took ' + (Date.now() - buildTs) + ' ms')) const forkOpts = { execArgv: process.execArgv, diff --git a/packages/cli/src/commands/serveApiHandler.js b/packages/cli/src/commands/serveApiHandler.js index 1b1195ab0e..5d3fe3a90c 100644 --- a/packages/cli/src/commands/serveApiHandler.js +++ b/packages/cli/src/commands/serveApiHandler.js @@ -53,7 +53,7 @@ export const apiServerHandler = async (options) => { } } - fastify.listen(listenOptions) + const address = await fastify.listen(listenOptions) fastify.ready(() => { fastify.log.trace( @@ -61,15 +61,14 @@ export const apiServerHandler = async (options) => { 'Fastify server configuration' ) fastify.log.trace(`Registered plugins \n${fastify.printPlugins()}`) - console.log(chalk.italic.dim('Took ' + (Date.now() - tsApiServer) + ' ms')) - const on = socket - ? socket - : chalk.magenta(`http://localhost:${port}${apiRootPath}`) + console.log(chalk.dim.italic('Took ' + (Date.now() - tsApiServer) + ' ms')) - console.log(`API listening on ${on}`) - const graphqlEnd = chalk.magenta(`${apiRootPath}graphql`) - console.log(`GraphQL endpoint at ${graphqlEnd}`) + const apiServer = chalk.magenta(`${address}${apiRootPath}`) + const graphqlEndpoint = chalk.magenta(`${apiServer}graphql`) + + console.log(`API server listening at ${apiServer}`) + console.log(`GraphQL endpoint at ${graphqlEndpoint}`) sendProcessReady() }) diff --git a/packages/cli/src/commands/serveBothHandler.js b/packages/cli/src/commands/serveBothHandler.js index 55d23c2dba..cfd9e1775a 100644 --- a/packages/cli/src/commands/serveBothHandler.js +++ b/packages/cli/src/commands/serveBothHandler.js @@ -124,22 +124,18 @@ export const bothServerHandler = async (options) => { } } - fastify.listen(listenOptions) + const address = await fastify.listen(listenOptions) fastify.ready(() => { - console.log(chalk.italic.dim('Took ' + (Date.now() - tsServer) + ' ms')) - - const on = socket - ? socket - : chalk.magenta(`http://localhost:${port}${apiRootPath}`) - - const webServer = chalk.green(`http://localhost:${port}`) - const apiServer = chalk.magenta(`http://localhost:${port}`) - console.log(`Web server started on ${webServer}`) - console.log(`API serving from ${apiServer}`) - console.log(`API listening on ${on}`) - const graphqlEnd = chalk.magenta(`${apiRootPath}graphql`) - console.log(`GraphQL endpoint at ${graphqlEnd}`) + console.log(chalk.dim.italic('Took ' + (Date.now() - tsServer) + ' ms')) + + const webServer = chalk.green(address) + const apiServer = chalk.magenta(`${address}${apiRootPath}`) + const graphqlEndpoint = chalk.magenta(`${apiServer}graphql`) + + console.log(`Web server listening at ${webServer}`) + console.log(`API server listening at ${apiServer}`) + console.log(`GraphQL endpoint at ${graphqlEndpoint}`) sendProcessReady() }) diff --git a/packages/fastify/src/config.ts b/packages/fastify/src/config.ts index 8daadb0f4c..f9c6e59796 100644 --- a/packages/fastify/src/config.ts +++ b/packages/fastify/src/config.ts @@ -68,7 +68,7 @@ export function loadFastifyConfig() { } if (!isServerConfigLoaded) { - console.log(`Loading server config from ${serverConfigPath} \n`) + console.log(`Loading server config from ${serverConfigPath}`) serverConfigFile = { ...require(serverConfigPath) } isServerConfigLoaded = true } diff --git a/packages/web-server/src/webServer.ts b/packages/web-server/src/webServer.ts index bd8af09409..7698fcd13a 100644 --- a/packages/web-server/src/webServer.ts +++ b/packages/web-server/src/webServer.ts @@ -11,7 +11,7 @@ import type { ParsedOptions } from './types' export async function serveWeb(options: ParsedOptions = {}) { const start = Date.now() - console.log(chalk.italic.dim('Starting Web Server...')) + console.log(chalk.dim.italic('Starting Web Server...')) const distIndexExists = await fs.pathExists( path.join(getPaths().web.dist, 'index.html') @@ -49,5 +49,5 @@ export async function serveWeb(options: ParsedOptions = {}) { }) console.log(chalk.italic.dim('Took ' + (Date.now() - start) + ' ms')) - console.log(`Server listening at ${chalk.green(address)}`) + console.log(`Web server listening at ${chalk.green(address)}`) }