Gitea is ignoring log settings (HTTP logs go to /var/log/syslog instead of http.log)

[denysobukh]

• Gitea version (or commit ref):
  Gitea version 1.4.2 built with: bindata, sqlite
• Git version:
  git version 2.17.1
• Operating system:
  Ubuntu 18.04 LTS
• Database (use [x]):
  • PostgreSQL
  • MySQL
  • MSSQL
  • [ x] SQLite
• Can you reproduce the bug at https://try.gitea.io:
  • Yes (provide example URL)
  • No
  • [x ] Not relevant
• Log gist:

Description:
Gitea is writing HTTP log messages to syslog instead of http.log
http.log is blank

app.ini

$ cat /etc/gitea/app.ini
APP_NAME = Gitea: Git with a cup of tea
RUN_USER = git
RUN_MODE = prod

[security]
INTERNAL_TOKEN = eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJuYmYiOjE1Mjk0OTc2ODl9.k11pRjleUo0NLOWW3mXgVUe0sKHxGo3xYBUQ9-9qLFk
INSTALL_LOCK   = true
SECRET_KEY     = PIMRFge1XY

[database]
DB_TYPE  = sqlite3
HOST     = 127.0.0.1:3306
NAME     = gitea
USER     = gitea
PASSWD   =
SSL_MODE = disable
PATH     = data/gitea.db

[repository]
ROOT = /home/git/gitea-repositories

[server]
SSH_DOMAIN       = nas.loc
DOMAIN           = nas.loc
HTTP_PORT        = 3000
ROOT_URL         = http://nas.loc:3000/
DISABLE_SSH      = false
SSH_PORT         = 22
LFS_START_SERVER = true
LFS_CONTENT_PATH = /var/lib/gitea/data/lfs
LFS_JWT_SECRET   = qSVvvSnASiyepyZ0IXrjTN8t9jFr-qMJnWjQKbBvElY
OFFLINE_MODE     = false

[mailer]
ENABLED = false

[service]
REGISTER_EMAIL_CONFIRM            = false
ENABLE_NOTIFY_MAIL                = false
DISABLE_REGISTRATION              = false
ENABLE_CAPTCHA                    = false
REQUIRE_SIGNIN_VIEW               = false
DEFAULT_KEEP_EMAIL_PRIVATE        = false
DEFAULT_ALLOW_CREATE_ORGANIZATION = true
DEFAULT_ENABLE_TIMETRACKING       = true
NO_REPLY_ADDRESS                  = noreply.example.org

[picture]
DISABLE_GRAVATAR        = true
ENABLE_FEDERATED_AVATAR = false

[openid]
ENABLE_OPENID_SIGNIN = true
ENABLE_OPENID_SIGNUP = true

[session]
PROVIDER = file

[log]
MODE      = file
LEVEL     = Warn
ROOT_PATH = /var/lib/gitea/log

gitea dir
$ ls -la /var/lib/gitea/

total 24
drwxr-xr-x  6 git  git  4096 Jun 20 15:33 .
drwxr-xr-x 56 root root 4096 Jun 20 15:27 ..
drwxr-xr-x  2 git  git  4096 Jun 20 15:27 custom
drwxr-x---  6 git  git  4096 Jun 21 14:50 data
drwxr-x---  2 git  git  4096 Jun 20 15:27 indexers
lrwxrwxrwx  1 git  git    14 Jun 20 15:33 log -> /var/log/gitea
drwxr-xr-x  2 git  git  4096 Jun 20 15:27 public

gitea log dir

$ ls -la /var/log/gitea/
total 408
drwxr-xr-x  3 git  git      4096 Jun 21 00:07 .
drwxrwxr-x 19 root syslog   4096 Jun 21 06:25 ..
-rw-r-----  1 git  git       973 Jun 21 14:47 gitea.log
drwxr-xr-x  2 git  git      4096 Jun 20 15:53 hooks
-rw-r-----  1 git  git         0 Jun 20 15:37 http.log
-rw-r-----  1 git  git    170105 Jun 21 14:53 xorm.log
-rw-r-----  1 git  git    222214 Jun 20 23:57 xorm.log.2018-06-21.001

gitea.log

$ tail /var/log/gitea/gitea.log  -n 100
2018/06/20 15:37:14 [I] Log Mode: File(Info)
2018/06/20 15:37:14 [I] XORM Log Mode: File(Info)
2018/06/20 15:37:14 [I] Cache Service Enabled
2018/06/20 15:37:14 [I] Session Service Enabled
2018/06/20 15:37:14 [I] Git Version: 2.17.1
2018/06/20 15:37:14 [I] Git config user.name set to Gitea
2018/06/20 15:37:14 [I] Git config user.email set to gitea@fake.local
2018/06/20 15:37:14 [I] SQLite3 Supported
2018/06/20 15:37:14 [I] Run Mode: Production
2018/06/20 15:37:14 [I] First-time run install finished!
2018/06/20 15:37:14 [I] New random avatar created: 1
2018/06/21 13:41:07 [I] Log Mode: File(Info)
2018/06/21 13:41:07 [I] XORM Log Mode: File(Info)
2018/06/21 13:41:07 [I] Cache Service Enabled
2018/06/21 13:41:07 [I] Session Service Enabled
2018/06/21 13:41:07 [I] Git Version: 2.17.1
2018/06/21 13:41:07 [I] SQLite3 Supported
2018/06/21 13:41:07 [I] Run Mode: Production
2018/06/21 13:41:07 [I] Listen: http://0.0.0.0:3000
2018/06/21 13:41:07 [I] LFS server enabled

syslog

$ tail /var/log/syslog
Jun 21 14:53:08 nas systemd[1]: Started Gitea (Git with a cup of tea).
Jun 21 14:53:08 nas gitea[17243]: 2018/06/21 14:53:08 #033[1;36m[T] AppPath: /usr/local/bin/gitea#033[0m
Jun 21 14:53:08 nas gitea[17243]: 2018/06/21 14:53:08 #033[1;36m[T] AppWorkPath: /var/lib/gitea#033[0m
Jun 21 14:53:08 nas gitea[17243]: 2018/06/21 14:53:08 #033[1;36m[T] Custom path: /var/lib/gitea/custom#033[0m
Jun 21 14:53:08 nas gitea[17243]: 2018/06/21 14:53:08 #033[1;36m[T] Log path: /var/lib/gitea/log#033[0m
Jun 21 14:53:08 nas gitea[17243]: 2018/06/21 14:53:08 #033[1;32m[I] Gitea v1.4.2 built with: bindata, sqlite#033[0m
Jun 21 14:53:08 nas gitea[17243]: 2018/06/21 14:53:08 Serving [::]:3000 with pid 17243
Jun 21 14:54:23 nas gitea[17243]: [Macaron] 2018-06-21 14:54:23: Started GET / for 192.168.88.252
Jun 21 14:54:23 nas gitea[17243]: [Macaron] 2018-06-21 14:54:23: Completed GET / 200 OK in 31.275567ms
Jun 21 14:54:23 nas gitea[17243]: [Macaron] 2018-06-21 14:54:23: Started GET /vendor/assets/octicons/octicons.min.css for 192.168.88.252
Jun 21 14:54:23 nas gitea[17243]: [Macaron] [Static] Serving /vendor/assets/octicons/octicons.min.css
Jun 21 14:54:23 nas gitea[17243]: [Macaron] 2018-06-21 14:54:23: Completed GET /vendor/assets/octicons/octicons.min.css 200 OK in 15.213746ms
Jun 21 14:54:23 nas gitea[17243]: [Macaron] 2018-06-21 14:54:23: Started GET /vendor/assets/font-awesome/css/font-awesome.min.css for 192.168.88.252
Jun 21 14:54:23 nas gitea[17243]: [Macaron] [Static] Serving /vendor/assets/font-awesome/css/font-awesome.min.css
Jun 21 14:54:23 nas gitea[17243]: [Macaron] 2018-06-21 14:54:23: Completed GET /vendor/assets/font-awesome/css/font-awesome.min.css 200 OK in 4.31435ms
Jun 21 14:54:23 nas gitea[17243]: [Macaron] 2018-06-21 14:54:23: Started GET /api/v1/repos/search?uid=1&q=&limit=15&mode= for 192.168.88.252
Jun 21 14:54:23 nas gitea[17243]: [Macaron] 2018-06-21 14:54:23: Completed GET /api/v1/repos/search?uid=1&q=&limit=15&mode= 200 OK in 8.651964ms

[techknowlogick]

@denysobukh are you using systemd, or another similar service, to manage how gitea runs?

[denysobukh]

Yes, I'm using systemd to run gitea:
here is the service file:

$ cat /etc/systemd/system/gitea.service
[Unit]
Description=Gitea (Git with a cup of tea)
After=syslog.target
After=network.target
#After=mysqld.service
#After=postgresql.service
#After=memcached.service
#After=redis.service

[Service]
# Modify these two values and uncomment them if you have
# repos with lots of files and get an HTTP error 500 because
# of that
###
#LimitMEMLOCK=infinity
#LimitNOFILE=65535
RestartSec=2s
Type=simple
User=git
Group=git
WorkingDirectory=/var/lib/gitea/
ExecStart=/usr/local/bin/gitea web -c /etc/gitea/app.ini
Restart=always
Environment=USER=git HOME=/home/git GITEA_WORK_DIR=/var/lib/gitea
# If you want to bind Gitea to a port below 1024 uncomment
# the two values below
###
#CapabilityBoundingSet=CAP_NET_BIND_SERVICE
#AmbientCapabilities=CAP_NET_BIND_SERVICE

[Install]
WantedBy=multi-user.target

[jrkoenig]

I have the same issue; http.log is blank. This is probably because gitea just spits out http logs to stdout, which systemd then redirects to the syslog: https://unix.stackexchange.com/a/57243

If you run git from the command line you'll get this output. Workarounds include changing the ExecStart in the service file to redirect (via an ugly bash hack) to a log file in the gitea directory: https://stackoverflow.com/a/37595720
You could also disable stdout in the service file via StandardOutput=null which would silence the syslog entries but not populate http.log.

[jrkoenig]

Upon further investigation it seems the go-macaron package is outputting these messages, and the fix needs to go at

gitea/routers/routes/routes.go

Line 49 in 95f0f62

m := macaron.New()

Instead of macaron.New, it should be .NewWithLogger with an io.Writer bound to the open file http.log

It looks like the only place http.log is used in this whole project is

gitea/routers/init.go

Line 77 in 5a62eb3

log.NewGitLogger(path.Join(setting.LogRootPath, "http.log"))

[denysobukh]

Any updates on which version this fix will include?

[stale]

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs during the next 2 weeks. Thank you for your contributions.

[zeripath]

Hi @denysobukh @jrkoenig is logging the macaron requests to the gitea.log as my PR above a reasonable solution?

[denysobukh]

Hi @denysobukh @jrkoenig is logging the macaron requests to the gitea.log as my PR above a reasonable solution?

Hi @zeripath
Unfortunately, I can't test this until it's in a release candidate at least.
(1.7.0-rc2 haven't got it)

[zeripath]

Ok so the gist is that the pr will redirect the Macaron log including its router logging to what is by default the gitea.log.

(The issue with sending it to http.log is that I worry that there may be concurrency problems there.)

Would that fix your issue?

[denysobukh]

Hi All
As to 1.7.4 release:
Routing logs still have been going to /var/log/syslog before 'DISABLE_ROUTER_LOG = true' is set

Mar 17 16:59:33 nas gitea[27124]: [Macaron] 2019-03-17 16:59:33: Started GET /admin/config for 192.168.88.200
Mar 17 16:59:33 nas gitea[27124]: [Macaron] 2019-03-17 16:59:33: Completed GET /admin/config 200 OK in 14.692245ms
Mar 17 16:59:35 nas gitea[27124]: [Macaron] 2019-03-17 16:59:35: Started GET /admin/config for 192.168.88.200
Mar 17 16:59:35 nas gitea[27124]: [Macaron] 2019-03-17 16:59:35: Completed GET /admin/config 200 OK in 11.651224ms

[agaskins]

I'm on 1.11.5, should I have this patch? Could someone explain the setting one should change to use the new method? I can't seem to stop getting the macaron logs in my systemd journal.

[zeripath]

@agaskins yes this has been part of Gitea since #5667 and was merged in to 1.8.0!

• Have you read https://docs.gitea.io/en-us/logging-configuration/ ?
• Have you discovered any of my previous comments regarding logging, e.g.:
  • Log file splitting is not working #11269 (comment)
  • Allow log.xxx.default to set logging settings for the default logger only #11292 (comment)

If after having read the above you still need help:

• I need to know what your current log configuration is? (Include the setting of [database] LOG_SQL)
• Tell me clearly what you want.

From the little your comment says, I think adding:

[log]
...
REDIRECT_MACARON_LOG = true
MACARON = file
ROUTER = file

Would work - however, you may want to consider dropping the router log with DISABLE_ROUTER_LOG=true and instead use ENABLE_ACCESS_LOG=true & ACCESS=file as that gives a access.log that conforms to the NCSA standard like apache/nginx.