Arch Linux

icouto

Member

Registered: 2020-11-12

Posts: 6

[SOLVED] Is Nginx double-logging errors to journald?

I have configured nginx's error_log to stderr, and it seems be logging just fine - but it logs errors TWICE... Is this normal? Or have I got some configuration screwed up somewhere?...

Example: I have setup basic http-auth on a test server with nginx newly installed. When I try to access the server, and purposely fail the login, I get 2 'error' lines in the log - which seem identical:

journalctl -r -p 3 -n 2 -u nginx

-- Logs begin at Fri 2020-11-06 09:54:26 AEDT, end at Thu 2020-11-12 17:27:52 AEDT. --
Nov 12 16:42:54 archie-test nginx[6356]: 2020/11/12 16:42:54 [error] 6356#6356: *99 user "onceagain" was not found in "/etc/nginx/.htpasswd", client: 192.168.0.2, server: localhost, request: "GET / HTTP/1.1", host: "192.168.0.1"
Nov 12 16:42:54 archie-test nginx[6356]: 2020/11/12 16:42:54 [error] 6356#6356: *99 user "onceagain" was not found in "/etc/nginx/.htpasswd", client: 192.168.0.2, server: localhost, request: "GET / HTTP/1.1", host: "192.168.0.1"

I tried getting the 'verbose' output from journalctl, to see if there were any fields that were being omitted from the short output, that could show a reason for double entry:

journalctl -r -p 3 -n 2 -u nginx -o verbose

-- Logs begin at Fri 2020-11-06 09:54:26 AEDT, end at Thu 2020-11-12 17:35:12 AEDT. --                                                                        
Thu 2020-11-12 16:42:54.362025 AEDT [s=92efa25d9a2f4a528bcc2e69b67efacf;i=a856;b=641775777ab54bb1960a0a2799b02c80;m=19d442253e;t=5b3e2622899a9;x=5b4fda58a487e2fb]                                 
    _MACHINE_ID=7df9ee238d024462bb2a4a3d2a4885bc                                
    SYSLOG_FACILITY=3                                                           
    _SYSTEMD_SLICE=system.slice                                                 
    _TRANSPORT=stdout                                                           
    PRIORITY=3                                                                  
    _HOSTNAME=archie-test                                                       
    _CAP_EFFECTIVE=0                                                            
    SYSLOG_IDENTIFIER=nginx                                                     
    _COMM=nginx                                                                 
    _EXE=/usr/bin/nginx                                                         
    _SYSTEMD_CGROUP=/system.slice/nginx.service                                 
    _SYSTEMD_UNIT=nginx.service                                                 
    _CMDLINE=nginx: worker process                                              
    _UID=33                                                                     
    _GID=33  
    _BOOT_ID=641775777ab54bb1960a0a2799b02c80                                   
    _SYSTEMD_INVOCATION_ID=8d07d5a257804cd481761f5954716c18                     
    _STREAM_ID=7839610889164de4a60281cc6d0f70fd                                 
    _PID=6356                                                                   
    MESSAGE=2020/11/12 16:42:54 [error] 6356#6356: *99 user "onceagain" was not found in "/etc/nginx/.htpasswd", client: 192.168.0.2, server: localhost, request: "GET / HTTP/1.1", host: "192.168.0.1"                   
Thu 2020-11-12 16:42:54.362025 AEDT [s=92efa25d9a2f4a528bcc2e69b67efacf;i=a855;b=641775777ab54bb1960a0a2799b02c80;m=19d442253e;t=5b3e2622899a9;x=5b4fda58a487e2fb]                                 
    _MACHINE_ID=7df9ee238d024462bb2a4a3d2a4885bc                                
    SYSLOG_FACILITY=3                                                           
    _SYSTEMD_SLICE=system.slice                                                 
    _TRANSPORT=stdout                                                           
    PRIORITY=3
    _HOSTNAME=archie-test
    _CAP_EFFECTIVE=0
    SYSLOG_IDENTIFIER=nginx
    _COMM=nginx
    _EXE=/usr/bin/nginx                                                         
    _SYSTEMD_CGROUP=/system.slice/nginx.service                                 
    _SYSTEMD_UNIT=nginx.service                                                 
    _CMDLINE=nginx: worker process                                              
    _UID=33                                                                     
    _GID=33                                                                     
    _BOOT_ID=641775777ab54bb1960a0a2799b02c80                                   
    _SYSTEMD_INVOCATION_ID=8d07d5a257804cd481761f5954716c18                     
    _STREAM_ID=7839610889164de4a60281cc6d0f70fd                                 
    _PID=6356                                                                   
    MESSAGE=2020/11/12 16:42:54 [error] 6356#6356: *99 user "onceagain" was not found in "/etc/nginx/.htpasswd", client: 192.168.0.2, server: localhost, request: "GET / HTTP/1.1", host: "192.168.0.1"                   

The only difference I can spot between the 2 records is in the first line of each, right where the timestamp is:

- one says: "Thu 2020-11-12 16:42:54.362025 AEDT [...;i=a856;...]         
- the other: "Thu 2020-11-12 16:42:54.362025 AEDT [...;i=a855;...]

...which I suspect is just the different record IDs...

I don't understand why the error event is being logged twice. I've tried going over the nginx configuration files, to see if there is anything there that could be triggering double-logging. The `error_log` directive is only used ONCE, at the very beginning of `nginx.conf`, and nowhere else.

Any suggestions to help me try and work out where the double entries are coming from - and how to stop them - would be most welcome!

Last edited by icouto (2020-11-12 23:05:09)

progandy

Member

Registered: 2012-05-17

Posts: 5,190

Re: [SOLVED] Is Nginx double-logging errors to journald?

The systemd unit file defines error_log as well. You could try to remove your definition.

systemctl cat nginx.service

Last edited by progandy (2020-11-12 07:51:25)

---

| alias CUTF='LANG=en_XX.UTF-8@POSIX ' |

icouto

Member

Registered: 2020-11-12

Posts: 6

Re: [SOLVED] Is Nginx double-logging errors to journald?

The systemd unit file defines error_log as well.

Thank you so much! That was exactly it: systemd was starting nginx already with its own 'error_log' directive - and that is why it wasn't showing up on any of my configuration directives, even when I did

nginx -T | grep "error_log"

That was driving me crazy! I simply removed the 'error_log' directive from my own 'nginx.conf' file, so now it's using just the directive from systemd. The error logging now 'just works', and we don't need to explicitly add an 'error_log' directive at all - and no more double entries!

Once again, thank you so much :-)