Skip to content
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

feat: make syslog logging useable #411

Open
wants to merge 3 commits into
base: main
Choose a base branch
from

Conversation

maxmoehl
Copy link
Member

@maxmoehl maxmoehl commented Apr 19, 2024

Summary

This PR corrects and improves the direct-to-syslog logging of access logs for Gorouter.

  • does not log an empty new line when writing to syslog
  • allows the operator to configure truncation on syslog, as syslog servers usually have a message limit
  • significant performance improvement to the syslog implementation

The syslog implementation in Go has not been maintained by the Go authors since around 2015. While there are forks of the syslog code, all of them are also dormant. This PR inlines and significantly rewrites the syslog implementation, focusing on the following performance improvements:

  • No use of the expensive fmt.Sprintf
  • Determine all "static" fields (e.g. the PID) on initialization, not per message
  • Correct handling of UTF-8 BOM according to RFC5424

Limitations:

  • Only TCP and UDP are supported, as described in the routing-release property for the syslog network. All other means (unix sockets, etc.) are not supported.

Backward Compatibility

Breaking Change? Yes

  • This PR moves the syslog implementation from the BSD-style syslog format, which is not standardised, to the RFC5424 format.

* do not log an empty new line when writing to syslog
* allow operator to configure truncation on syslog
@maxmoehl maxmoehl marked this pull request as ready for review November 20, 2024 14:53
@maxmoehl maxmoehl requested a review from a team as a code owner November 20, 2024 14:53
@maxmoehl
Copy link
Member Author

I forgot to update the breaking change indicator after pushing my latest change. This is technically breaking because we move from the BSD-style syslog format which is not standardised to the RFC5424 format. I'm not sure how man people actually use the syslog implementation today, over UDP each log line also inserts an empty log line due to the (previously dedicated) call to Write. Over TCP it did probably work, however, it caused gorouter to perform worse as the old implementation did unnecessary syscalls for each log line written and the formatting was done using fmt.

The go standard library implementation of log/syslog has been abandoned
and is no longer maintained. In our tests with syslog logging in
gorouter we noticed a significant performance penalty over file based
logging. However, with file based logging we frequently observe broken
logs because logrotate interferes with log reading / writing.

This commit inlines the relevant file from log/syslog and refactors the
implementation to be on-par with the file based logging.

Co-authored-by: Alexander Lais <[email protected]>
@ameowlia
Copy link
Member

@maxmoehl
Copy link
Member Author

The old format looks something like this:

<34>Oct 11 22:14:15 mymachine MESSAGE

and the new format is something like this:

<34>1 2003-10-11T22:14:15.003Z mymachine.example.com su - ID47 - \ufeffMESSAGE

@maxmoehl
Copy link
Member Author

maxmoehl commented Nov 25, 2024

For testing use this config:

logging.syslog_addr: 127.0.0.1:514
logging.syslog_network: udp
enable_access_log_streaming: true
write_access_logs_locally: false

@maxmoehl
Copy link
Member Author

I've also opened cloudfoundry/routing-release#446

Copy link
Member

@ameowlia ameowlia left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Before example wihtout deploying any code from when I ran cf apps (note the extra line):

2024-12-03T17:21:35Z 7c816b03-30fe-48fc-8112-024f1b7c875d vcap.gorouter[7]: api.z85e8a830.shepherd.lease - [2024-12-03T17:21:35.246128238Z] "GET /v3/apps?order_by=name&per_page=5000&space_guids=f091f24f-9f20-495c-93c0-171b2d5c405a HTTP/1.1" 200 0 424 "-" "cf/8.8.3+3cd802e.2024-10-29 (go1.23.1; amd64 linux)" "34.121.99.84:35278" "10.244.0.133:9024" x_forwarded_for:"34.121.99.84" x_forwarded_proto:"https" vcap_request_id:"41376a16-828e-47b5-6c49-4e9adf5d96aa" response_time:0.032040 gorouter_time:0.000163 app_id:"-" app_index:"-" instance_id:"5a0886b8-5a06-4fda-66ec-db02512ba331" x_cf_routererror:"-" x_b3_traceid:"41376a16828e47b56c494e9adf5d96aa" x_b3_spanid:"6c494e9adf5d96aa" x_b3_parentspanid:"-" b3:"41376a16828e47b56c494e9adf5d96aa-6c494e9adf5d96aa"
2024-12-03T17:21:35Z 7c816b03-30fe-48fc-8112-024f1b7c875d vcap.gorouter[7]:

After example (note no extra line)

2024-12-03T18:24:08Z 7c816b03-30fe-48fc-8112-024f1b7c875d vcap.gorouter[7] api.z85e8a830.shepherd.lease - [2024-12-03T18:24:08.892876502Z] "GET /v3/apps?order_by=name&per_page=5000&space_guids=f091f24f-9f20-495c-93c0-171b2d5c405a HTTP/1.1" 200 0 424 "-" "cf/8.8.3+3cd802e.2024-10-29 (go1.23.1; amd64 linux)" "34.121.99.84:52634" "10.244.0.133:9024" x_forwarded_for:"34.121.99.84" x_forwarded_proto:"https" vcap_request_id:"83e5beb2-4e2f-430d-7412-b01fa140c0a1" response_time:0.032635 gorouter_time:0.000214 app_id:"-" app_index:"-" instance_id:"8bd9eb77-02e5-4cac-5e12-aa8dea25e775" x_cf_routererror:"-" x_b3_traceid:"83e5beb24e2f430d7412b01fa140c0a1" x_b3_spanid:"7412b01fa140c0a1" x_b3_parentspanid:"-" b3:"83e5beb24e2f430d7412b01fa140c0a1-7412b01fa140c0a1"

✅ 1. No more blank lines

Great!

❓ 2. No difference in format

I don't see any difference between the before and after logs. Do you know why this is?

⛔ 3. Static Check Failure

When I run ./scripts/test-in-docker.bash I get the following failure...

accesslog/file_and_loggregator_access_logger.go:77:22: io.Writer.Write must not modify the provided buffer, not even temporarily (SA1023)

✏️ 4. Integration test

Is it possible to add an integration test to test this? That way if breaks we will find out in less than 6 years unlike last time.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
Development

Successfully merging this pull request may close these issues.

3 participants