Skip to content

Add logging output from the server #351

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

Merged
merged 3 commits into from
Jan 9, 2025
Merged

Conversation

schneems
Copy link
Contributor

@schneems schneems commented Dec 5, 2024

Currently nothing from the server logs when / is rendered, the only logs are from the router:

2024-12-05T22:12:31.218143+00:00 heroku[router]: at=info method=GET path="/" host=sheltered-eyrie-60144-d97e98d69373.herokuapp.com request_id=f2739cdb-62b2-464a-b2fe-2723ca64ff00 fwd="13.110.54.11" dyno=web.1 connect=0ms service=20ms status=304 bytes=152 protocol=https
2024-12-05T22:12:31.392858+00:00 heroku[router]: at=info method=GET path="/stylesheets/main.css" host=sheltered-eyrie-60144-d97e98d69373.herokuapp.com request_id=7c197cb2-09d7-43d0-ad43-59c8736291b1 fwd="13.110.54.11" dyno=web.1 connect=0ms service=8ms status=200 bytes=908 protocol=https
2024-12-05T22:12:31.506876+00:00 heroku[router]: at=info method=GET path="/lang-logo.png" host=sheltered-eyrie-60144-d97e98d69373.herokuapp.com request_id=1765623e-0a0a-48ce-9f4f-df7eff8bc381 fwd="13.110.54.11" dyno=web.1 connect=0ms service=11ms status=200 bytes=2567 protocol=https

This is what server logs look after this change:

2024-12-05T22:11:15.351801+00:00 heroku[router]: at=info method=GET path="/stylesheets/main.css" host=sheltered-eyrie-60144-d97e98d69373.herokuapp.com request_id=1bd60918-0c11-4c08-848a-d6bfb63ba7ae fwd="13.110.54.11" dyno=web.1 connect=0ms service=1ms status=304 bytes=237 protocol=https
2024-12-05T22:11:15.247601+00:00 heroku[router]: at=info method=GET path="/" host=sheltered-eyrie-60144-d97e98d69373.herokuapp.com request_id=e92141bc-eb31-4722-accb-5c9c243a4e00 fwd="13.110.54.11" dyno=web.1 connect=0ms service=2ms status=304 bytes=152 protocol=https
2024-12-05T22:11:15.246313+00:00 app[web.1]: Rendering `pages/index`
2024-12-05T22:11:15.246329+00:00 app[web.1]:
2024-12-05T22:11:15.246330+00:00 app[web.1]: Use `console.log()` on the server to send text to stdout.
2024-12-05T22:11:15.246349+00:00 app[web.1]: That log text is viewable via the `heroku logs` command or via a logging add-on.
2024-12-05T22:11:15.246349+00:00 app[web.1]: 
2024-12-05T22:11:15.353613+00:00 heroku[router]: at=info method=GET path="/lang-logo.png" host=sheltered-eyrie-60144-d97e98d69373.herokuapp.com request_id=4229139a-67a0-4dbe-b568-561e11768143 fwd="13.110.54.11" dyno=web.1 connect=0ms service=1ms status=304 bytes=237 protocol=https

This accomplishes:

  • Showing how router and web logs will differ.
  • Explaining via text in the logs how they can log (console.log()) as opposed to some people expecting to write to a log file on disk.
  • Explaining how to view those logs (the heroku logs command)
  • Hinting that a logging add-on might be a good idea

Currently nothing from the server logs when `/` is rendered, the only logs are from the router:

```
2024-12-05T22:12:31.218143+00:00 heroku[router]: at=info method=GET path="/" host=sheltered-eyrie-60144-d97e98d69373.herokuapp.com request_id=f2739cdb-62b2-464a-b2fe-2723ca64ff00 fwd="13.110.54.11" dyno=web.1 connect=0ms service=20ms status=304 bytes=152 protocol=https
2024-12-05T22:12:31.392858+00:00 heroku[router]: at=info method=GET path="/stylesheets/main.css" host=sheltered-eyrie-60144-d97e98d69373.herokuapp.com request_id=7c197cb2-09d7-43d0-ad43-59c8736291b1 fwd="13.110.54.11" dyno=web.1 connect=0ms service=8ms status=200 bytes=908 protocol=https
2024-12-05T22:12:31.506876+00:00 heroku[router]: at=info method=GET path="/lang-logo.png" host=sheltered-eyrie-60144-d97e98d69373.herokuapp.com request_id=1765623e-0a0a-48ce-9f4f-df7eff8bc381 fwd="13.110.54.11" dyno=web.1 connect=0ms service=11ms status=200 bytes=2567 protocol=https
```

This is what server logs look after this change:

```
2024-12-05T22:11:15.351801+00:00 heroku[router]: at=info method=GET path="/stylesheets/main.css" host=sheltered-eyrie-60144-d97e98d69373.herokuapp.com request_id=1bd60918-0c11-4c08-848a-d6bfb63ba7ae fwd="13.110.54.11" dyno=web.1 connect=0ms service=1ms status=304 bytes=237 protocol=https
2024-12-05T22:11:15.247601+00:00 heroku[router]: at=info method=GET path="/" host=sheltered-eyrie-60144-d97e98d69373.herokuapp.com request_id=e92141bc-eb31-4722-accb-5c9c243a4e00 fwd="13.110.54.11" dyno=web.1 connect=0ms service=2ms status=304 bytes=152 protocol=https
2024-12-05T22:11:15.246313+00:00 app[web.1]: Rendering `pages/index`
2024-12-05T22:11:15.246329+00:00 app[web.1]:
2024-12-05T22:11:15.246330+00:00 app[web.1]: Use `console.log()` on the server to send text to stdout.
2024-12-05T22:11:15.246349+00:00 app[web.1]: That log text is viewable via the `heroku logs` command or via a logging add-on.
2024-12-05T22:11:15.246349+00:00 app[web.1]: 
2024-12-05T22:11:15.353613+00:00 heroku[router]: at=info method=GET path="/lang-logo.png" host=sheltered-eyrie-60144-d97e98d69373.herokuapp.com request_id=4229139a-67a0-4dbe-b568-561e11768143 fwd="13.110.54.11" dyno=web.1 connect=0ms service=1ms status=304 bytes=237 protocol=https
```

This accomplishes:

- Showing how router and web logs will differ. 
- Explaining via text in the logs how they can log (`console.log()`) as opposed to some people expecting to write to a log file on disk.
- Explaining how to view those logs (the `heroku logs` command)
- Hinting that a logging add-on might be a good idea
@schneems schneems requested a review from a team as a code owner December 5, 2024 22:17
@edmorley edmorley requested review from colincasey and removed request for a team December 11, 2024 17:12
@edmorley
Copy link
Member

edmorley commented Jan 7, 2025

One concern I have with this, is that users tend to use our getting started guides as the basis for new projects, and often don't delete existing code fully. Adding multiple lines of logging here would mean some new apps will be spewing many bogus log lines per request.

I wonder if a compromise would be to instead enable single-line access logs for express iff in development (given the Heroku Router fulfils that role for production)? I think express doesn't support access logs directly, but there are middleware packages available that can add it.

@colincasey
Copy link
Contributor

I've changed this to a simpler one-line message. Our getting started guide already outlines how the logging works on Heroku so it feels redundant to go into detail within the log message and I'd prefer to not be prescriptive here by adding any logging framework or middleware. Usage of console on the route is also in line with the application startup and shutdown logging.

@colincasey colincasey enabled auto-merge (squash) January 9, 2025 16:02
@colincasey colincasey merged commit 1fd5088 into main Jan 9, 2025
1 check passed
@colincasey colincasey deleted the schneems/log-from-index branch January 9, 2025 16:02
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

3 participants