search

go-gitea / gitea

Git with a cup of tea! Painless self-hosted all-in-one software development service, including Git hosting, code review, team collaboration, package registry and CI/CD
https://gitea.com
MIT License
44.59k stars 5.45k forks source link

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

Closed denysobukh closed 5 years ago

denysobukh commented 6 years ago

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 commented 6 years ago

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

denysobukh commented 6 years ago

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 commented 6 years ago

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 commented 6 years ago

Upon further investigation it seems the go-macaron package is outputting these messages, and the fix needs to go at https://github.com/go-gitea/gitea/blob/95f0f62ea40b7b0419607e9e918f329981bcafb7/routers/routes/routes.go#L49 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 https://github.com/go-gitea/gitea/blob/5a62eb30df3a04e76e465824f525b4ffd920b562/routers/init.go#L77

denysobukh commented 6 years ago

Any updates on which version this fix will include?

stale[bot] commented 5 years ago

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 commented 5 years ago

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

denysobukh commented 5 years ago

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 commented 5 years ago

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 commented 5 years ago

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 commented 4 years ago

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 commented 4 years ago

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

If after having read the above you still need help:

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.