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

postgres: Do not log timestamp #87219

Merged
merged 2 commits into from May 14, 2020

Conversation

kirelagin
Copy link
Member

By default, postgres prefixes each log line with a timestamp. On NixOS
logs are written to journal anyway, so they include an external
timestamp, so the timestamp ends up being printed twice, which clutters
the log.

  • Add a module option to change the log prefix.
  • Set it to upstream default sans timestamp.
  • Tested using sandboxing (nix.useSandbox on NixOS, or option sandbox in nix.conf on non-NixOS linux)
  • Built on platform(s)
    • NixOS
    • macOS
    • other Linux distributions
  • Tested via one or more NixOS test(s) if existing and applicable for the change (look inside nixos/tests)
  • Tested compilation of all pkgs that depend on this change using nix-shell -p nixpkgs-review --run "nixpkgs-review wip"
  • Tested execution of all binary files (usually in ./result/bin/)
  • Determined the impact on package closure size (by running nix path-info -S before and after)
  • Ensured that relevant documentation is up to date
  • Fits CONTRIBUTING.md.

By default, postgres prefixes each log line with a timestamp. On NixOS
logs are written to journal anyway, so they include an external
timestamp, so the timestamp ends up being printed twice, which clutters
the log.

* Add a module option to change the log prefix.
* Set it to upstream default sans timestamp.
@veprbl
Copy link
Member

veprbl commented May 8, 2020

@2chilled sorry, accidental ping
@GrahamcOfBorg test postgresql

@@ -192,6 +193,17 @@ in
'';
};

logLinePrefix = mkOption {
type = types.str;
default = "[%p] ";
Copy link
Member

Choose a reason for hiding this comment

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

Shouldn't we remove the %p as well then? The PID is also logged in journald.

Copy link
Member Author

Choose a reason for hiding this comment

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

Journal only shows (and records, IIUC) the PID of the main process, while postgres spawns and logs from a lot of subprocesses.

To be honest, I am not exactly sure if this is how it is supposed to work, i.e. why journalctl always shows the PID of the parent process – I would expect it to save the PID of the process that actually wrote the message. This might be something worth looking into later.

Copy link
Member

Choose a reason for hiding this comment

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

Uhm, AFAICS on my machine, journald doesn't show the parent's PID on each log-line, I'm using systemd 245 though.

Copy link
Member Author

@kirelagin kirelagin May 12, 2020

Choose a reason for hiding this comment

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

I don’t know about that. The code that prints it has been there since, at least, 2012. And if you google “journalctl” and go to images, you’ll see that they all contain the pid.

Copy link
Member

Choose a reason for hiding this comment

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

not sure if I'm misunderstanding you, but I meant that the PID of the process producing the line is shown in the line and not the PID of the main process of a unit.

Copy link
Member Author

Choose a reason for hiding this comment

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

Oh! Sorry, I misunderstood you.

I don’t see any release notes in the last couple versions that seem to be relevant. Can you try specifically with postgres please? My theory is that maybe this wrapping into bash scripts that we do breaks something. What I see in my journal is that the PID that journalctl prints is always the same for postgresql.service and the PIDs printed by postgres itself are different.

@lheckemann
Copy link
Member

This may break in fun ways if extraConfig contains log_line_prefix. Not sure if that warrants a release notes entry?

@kirelagin
Copy link
Member Author

I don’t think it can break, as options coming later in the file override the ones before them, so setting log_line_prefix in extraConfig will just override this. I think this is the standard behaviour for NixOS modules.

Co-authored-by: Mario Rodas <marsam@users.noreply.github.com>
@lheckemann lheckemann merged commit 85a0587 into NixOS:master May 14, 2020
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging this pull request may close these issues.

None yet

5 participants