feat(log): better parseable and configurable ssh-logs (#9056)

To audit access to our forgejo-instance we currently need to enable debug ssh-logs. It turns out a single log become multiple events in a k8s/container setup. To have our log-collectors properly join these events, we would like to indent them similar to what some stacktraces look like.

This PR would change
```
2025/09/08 07:18:53 ...eb/routing/logger.go:102:func1() [I] Serv Results:
IsWiki: %t
DeployKeyID: %d
KeyID: %d    KeyName: %s
UserName: %s
UserID: %d
OwnerName: %s
RepoName: %s
RepoID: %d
```
to
```
2025/09/08 07:18:53 ...eb/routing/logger.go:102:func1() [I] Serv Results:
    IsWiki: %t
    DeployKeyID: %d
    KeyID: %d    KeyName: %s
    UserName: %s
    UserID: %d
    OwnerName: %s
    RepoName: %s
    RepoID: %d
```

Furthermore to standardize user configuration of ssh-logs I have added `LOGGER_SSH_MODE` . It can be configured like router-logger. By doing so we can change the log-LEVEL to debug for ssh without changing other loggers. This would deprecate `ENABLE_SSH_LOG`.

## Checklist

The [contributor guide](https://forgejo.org/docs/next/contributor/) contains information that will be helpful to first time contributors. There also are a few [conditions for merging Pull Requests in Forgejo repositories](https://codeberg.org/forgejo/governance/src/branch/main/PullRequestsAgreement.md). You are also welcome to join the [Forgejo development chatroom](https://matrix.to/#/#forgejo-development:matrix.org).

### Documentation

- [ ] I created a pull request [to the documentation](https://codeberg.org/forgejo/docs) to explain to Forgejo users how to use this change.
- [x] I did not document these changes and I do not expect someone else to do it.

### Release notes

- [x] I do not want this change to show in the release notes.
- [ ] I want the title to show in the release notes with a link to this pull request.
- [ ] I want the content of the `release-notes/<pull request number>.md` to be be used for the release notes instead of the title.

<!--start release-notes-assistant-->

## Release notes
<!--URL:https://codeberg.org/forgejo/forgejo-->
- Features
  - [PR](https://codeberg.org/forgejo/forgejo/pulls/9056): <!--number 9056 --><!--line 0 --><!--description ZmVhdChsb2cpOiBiZXR0ZXIgcGFyc2VhYmxlIGFuZCBjb25maWd1cmFibGUgc3NoLWxvZ3M=-->feat(log): better parseable and configurable ssh-logs<!--description-->
<!--end release-notes-assistant-->

Reviewed-on: https://codeberg.org/forgejo/forgejo/pulls/9056
Reviewed-by: Lucas <sclu1034@noreply.codeberg.org>
Reviewed-by: Gusted <gusted@noreply.codeberg.org>
Reviewed-by: Earl Warren <earl-warren@noreply.codeberg.org>
Co-authored-by: zokki <zokki.softwareschmiede@gmail.com>
Co-committed-by: zokki <zokki.softwareschmiede@gmail.com>
This commit is contained in:
zokki 2025-09-11 18:59:24 +02:00 committed by Earl Warren
commit 8cb7c19bf4
15 changed files with 132 additions and 96 deletions

View file

@ -88,6 +88,14 @@ var (
alphaDashDotPattern = regexp.MustCompile(`[^\w-\.]`)
)
func sshLog(ctx context.Context, level log.Level, message string) error {
if testing.Testing() || setting.InternalToken == "" {
return nil
}
return private.SSHLog(ctx, level, message)
}
// fail prints message to stdout, it's mainly used for git serv and git hook commands.
// The output will be passed to git client and shown to user.
func fail(ctx context.Context, userMessage, logMsgFmt string, args ...any) error {
@ -112,10 +120,7 @@ func fail(ctx context.Context, userMessage, logMsgFmt string, args ...any) error
logMsg = userMessage + ". " + logMsg
}
}
// Don't send an log if this is done in a test and no InternalToken is set.
if !testing.Testing() || setting.InternalToken != "" {
_ = private.SSHLog(ctx, true, logMsg)
}
_ = sshLog(ctx, log.ERROR, logMsg)
}
return cli.Exit("", 1)
}

View file

@ -598,10 +598,7 @@ LEVEL = Info
;LOGGER_ACCESS_MODE=
;LOGGER_ROUTER_MODE=,
;LOGGER_XORM_MODE=,
;;
;; Collect SSH logs (Creates log from ssh git request)
;;
;ENABLE_SSH_LOG = false
;LOGGER_SSH_MODE= ;; SSH logs from ssh git request
;;
;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;;
;;

View file

@ -32,7 +32,7 @@ func Stack(skip int) string {
}
// Print equivalent of debug.Stack()
_, _ = fmt.Fprintf(buf, "%s:%d (0x%x)\n", filename, lineNumber, programCounter)
_, _ = fmt.Fprintf(buf, "\t%s:%d (0x%x)\n", filename, lineNumber, programCounter)
// Now try to print the offending line
if filename != lastFilename {
data, err := os.ReadFile(filename)
@ -44,7 +44,7 @@ func Stack(skip int) string {
lines = bytes.Split(data, []byte{'\n'})
lastFilename = filename
}
_, _ = fmt.Fprintf(buf, "\t%s: %s\n", functionName(programCounter), source(lines, lineNumber))
_, _ = fmt.Fprintf(buf, "\t\t%s: %s\n", functionName(programCounter), source(lines, lineNumber))
}
return buf.String()
}

View file

@ -11,6 +11,7 @@ import (
"forgejo.org/modules/git"
"forgejo.org/modules/git/pushoptions"
"forgejo.org/modules/log"
"forgejo.org/modules/repository"
"forgejo.org/modules/setting"
)
@ -46,7 +47,7 @@ func (o *HookOptions) GetGitPushOptions() pushoptions.Interface {
// SSHLogOption ssh log options
type SSHLogOption struct {
IsError bool
Level log.Level
Message string
}
@ -121,9 +122,9 @@ func SetDefaultBranch(ctx context.Context, ownerName, repoName, branch string) R
}
// SSHLog sends ssh error log response
func SSHLog(ctx context.Context, isErr bool, msg string) error {
func SSHLog(ctx context.Context, level log.Level, msg string) error {
reqURL := setting.LocalURL + "api/internal/ssh/log"
req := newInternalRequest(ctx, reqURL, "POST", &SSHLogOption{IsError: isErr, Message: msg})
req := newInternalRequest(ctx, reqURL, "POST", &SSHLogOption{Level: level, Message: msg})
_, extra := requestJSONResp(req, &ResponseText{})
return extra.Error
}

View file

@ -23,8 +23,6 @@ type LogGlobalConfig struct {
StacktraceLogLevel log.Level
BufferLen int
EnableSSHLog bool
AccessLogTemplate string
RequestIDHeaders []string
}
@ -47,8 +45,6 @@ func loadLogGlobalFrom(rootCfg ConfigProvider) {
}
Log.RootPath = util.FilePathJoinAbs(Log.RootPath)
Log.EnableSSHLog = sec.Key("ENABLE_SSH_LOG").MustBool(false)
Log.AccessLogTemplate = sec.Key("ACCESS_LOG_TEMPLATE").MustString(accessLogTemplateDefault)
Log.RequestIDHeaders = sec.Key("REQUEST_ID_HEADERS").Strings(",")
}
@ -124,6 +120,16 @@ func prepareLoggerConfig(rootCfg ConfigProvider) {
if hasNoValue {
sec.Key("LOGGER_XORM_MODE").SetValue(",") // use default logger
}
// Priority: `LOGGER_SSH_MODE` -> `ENABLE_SSH_LOG`
deprecatedSettingWarning(rootCfg, "log", "ENABLE_SSH_LOG", "log", "LOGGER_SSH_MODE")
if !sec.HasKey("LOGGER_SSH_MODE") && sec.HasKey("ENABLE_SSH_LOG") {
if sec.Key("ENABLE_SSH_LOG").MustBool() {
sec.Key("LOGGER_SSH_MODE").SetValue(",") // use default logger
} else {
sec.Key("LOGGER_SSH_MODE").SetValue("") // disable ssh logger
}
}
}
func LogPrepareFilenameForWriter(fileName, defaultFileName string) string {
@ -245,6 +251,7 @@ func initManagedLoggers(manager *log.LoggerManager, cfg ConfigProvider) {
initLoggerByName(manager, cfg, "access")
initLoggerByName(manager, cfg, "router")
initLoggerByName(manager, cfg, "xorm")
initLoggerByName(manager, cfg, "ssh")
}
func initLoggerByName(manager *log.LoggerManager, rootCfg ConfigProvider, loggerName string) {

View file

@ -585,6 +585,31 @@ logger.xorm.MODE = console
`[log]
LOGGER_XORM_MODE = file
logger.xorm.MODE = console
`,
"file",
},
})
})
t.Run("ssh", func(t *testing.T) {
runCases(t, "LOGGER_SSH_MODE", Cases{
{
"uses default value for ssh logger",
"",
"",
},
{
"deprecated config can enable logger",
`[log]
ENABLE_SSH_LOG = true
`,
",",
},
{
"check priority",
`[log]
LOGGER_SSH_MODE = file
ENABLE_SSH_LOG = true
`,
"file",
},

View file

@ -15,6 +15,8 @@ import (
"forgejo.org/modules/setting"
)
var logger = log.GetManager().GetLogger("ssh")
func Init() error {
if setting.SSH.Disabled {
builtinUnused()

View file

@ -61,10 +61,10 @@ func sessionHandler(session ssh.Session) {
command := session.RawCommand()
log.Trace("SSH: Payload: %v", command)
logger.Trace("SSH: Payload: %v", command)
args := []string{"--config=" + setting.CustomConf, "serv", "key-" + keyID}
log.Trace("SSH: Arguments: %v", args)
logger.Trace("SSH: Arguments: %v", args)
ctx, cancel := context.WithCancel(session.Context())
defer cancel()
@ -87,21 +87,21 @@ func sessionHandler(session ssh.Session) {
stdout, err := cmd.StdoutPipe()
if err != nil {
log.Error("SSH: StdoutPipe: %v", err)
logger.Error("SSH: StdoutPipe: %v", err)
return
}
defer stdout.Close()
stderr, err := cmd.StderrPipe()
if err != nil {
log.Error("SSH: StderrPipe: %v", err)
logger.Error("SSH: StderrPipe: %v", err)
return
}
defer stderr.Close()
stdin, err := cmd.StdinPipe()
if err != nil {
log.Error("SSH: StdinPipe: %v", err)
logger.Error("SSH: StdinPipe: %v", err)
return
}
defer stdin.Close()
@ -112,14 +112,14 @@ func sessionHandler(session ssh.Session) {
wg.Add(2)
if err = cmd.Start(); err != nil {
log.Error("SSH: Start: %v", err)
logger.Error("SSH: Start: %v", err)
return
}
go func() {
defer stdin.Close()
if _, err := io.Copy(stdin, session); err != nil {
log.Error("Failed to write session to stdin. %s", err)
logger.Error("Failed to write session to stdin. %s", err)
}
}()
@ -127,7 +127,7 @@ func sessionHandler(session ssh.Session) {
defer wg.Done()
defer stdout.Close()
if _, err := io.Copy(session, stdout); err != nil {
log.Error("Failed to write stdout to session. %s", err)
logger.Error("Failed to write stdout to session. %s", err)
}
}()
@ -135,7 +135,7 @@ func sessionHandler(session ssh.Session) {
defer wg.Done()
defer stderr.Close()
if _, err := io.Copy(session.Stderr(), stderr); err != nil {
log.Error("Failed to write stderr to session. %s", err)
logger.Error("Failed to write stderr to session. %s", err)
}
}()
@ -149,41 +149,41 @@ func sessionHandler(session ssh.Session) {
// Cannot use errors.Is here because ExitError doesn't implement Is
// Thus errors.Is will do equality test NOT type comparison
if _, ok := err.(*exec.ExitError); !ok {
log.Error("SSH: Wait: %v", err)
logger.Error("SSH: Wait: %v", err)
}
}
if err := session.Exit(getExitStatusFromError(err)); err != nil && !errors.Is(err, io.EOF) {
log.Error("Session failed to exit. %s", err)
logger.Error("Session failed to exit. %s", err)
}
}
func publicKeyHandler(ctx ssh.Context, key ssh.PublicKey) bool {
if log.IsDebug() { // <- FingerprintSHA256 is kinda expensive so only calculate it if necessary
log.Debug("Handle Public Key: Fingerprint: %s from %s", gossh.FingerprintSHA256(key), ctx.RemoteAddr())
if logger.LevelEnabled(log.DEBUG) { // <- FingerprintSHA256 is kinda expensive so only calculate it if necessary
logger.Debug("Handle Public Key: Fingerprint: %s from %s", gossh.FingerprintSHA256(key), ctx.RemoteAddr())
}
if ctx.User() != setting.SSH.BuiltinServerUser {
log.Warn("Invalid SSH username %s - must use %s for all git operations via ssh", ctx.User(), setting.SSH.BuiltinServerUser)
log.Warn("Failed authentication attempt from %s", ctx.RemoteAddr())
logger.Warn("Invalid SSH username %s - must use %s for all git operations via ssh", ctx.User(), setting.SSH.BuiltinServerUser)
logger.Warn("Failed authentication attempt from %s", ctx.RemoteAddr())
return false
}
// check if we have a certificate
if cert, ok := key.(*gossh.Certificate); ok {
if log.IsDebug() { // <- FingerprintSHA256 is kinda expensive so only calculate it if necessary
log.Debug("Handle Certificate: %s Fingerprint: %s is a certificate", ctx.RemoteAddr(), gossh.FingerprintSHA256(key))
if logger.LevelEnabled(log.DEBUG) { // <- FingerprintSHA256 is kinda expensive so only calculate it if necessary
logger.Debug("Handle Certificate: %s Fingerprint: %s is a certificate", ctx.RemoteAddr(), gossh.FingerprintSHA256(key))
}
if len(setting.SSH.TrustedUserCAKeys) == 0 {
log.Warn("Certificate Rejected: No trusted certificate authorities for this server")
log.Warn("Failed authentication attempt from %s", ctx.RemoteAddr())
logger.Warn("Certificate Rejected: No trusted certificate authorities for this server")
logger.Warn("Failed authentication attempt from %s", ctx.RemoteAddr())
return false
}
if cert.CertType != gossh.UserCert {
log.Warn("Certificate Rejected: Not a user certificate")
log.Warn("Failed authentication attempt from %s", ctx.RemoteAddr())
logger.Warn("Certificate Rejected: Not a user certificate")
logger.Warn("Failed authentication attempt from %s", ctx.RemoteAddr())
return false
}
@ -193,10 +193,10 @@ func publicKeyHandler(ctx ssh.Context, key ssh.PublicKey) bool {
pkey, err := asymkey_model.SearchPublicKeyByContentExact(ctx, principal)
if err != nil {
if asymkey_model.IsErrKeyNotExist(err) {
log.Debug("Principal Rejected: %s Unknown Principal: %s", ctx.RemoteAddr(), principal)
logger.Debug("Principal Rejected: %s Unknown Principal: %s", ctx.RemoteAddr(), principal)
continue principalLoop
}
log.Error("SearchPublicKeyByContentExact: %v", err)
logger.Error("SearchPublicKeyByContentExact: %v", err)
return false
}
@ -215,8 +215,8 @@ func publicKeyHandler(ctx ssh.Context, key ssh.PublicKey) bool {
// check the CA of the cert
if !c.IsUserAuthority(cert.SignatureKey) {
if log.IsDebug() {
log.Debug("Principal Rejected: %s Untrusted Authority Signature Fingerprint %s for Principal: %s", ctx.RemoteAddr(), gossh.FingerprintSHA256(cert.SignatureKey), principal)
if logger.LevelEnabled(log.DEBUG) {
logger.Debug("Principal Rejected: %s Untrusted Authority Signature Fingerprint %s for Principal: %s", ctx.RemoteAddr(), gossh.FingerprintSHA256(cert.SignatureKey), principal)
}
continue principalLoop
}
@ -224,14 +224,14 @@ func publicKeyHandler(ctx ssh.Context, key ssh.PublicKey) bool {
// validate the cert for this principal
if err := c.CheckCert(principal, cert); err != nil {
// User is presenting an invalid certificate - STOP any further processing
log.Error("Invalid Certificate KeyID %s with Signature Fingerprint %s presented for Principal: %s from %s", cert.KeyId, gossh.FingerprintSHA256(cert.SignatureKey), principal, ctx.RemoteAddr())
log.Warn("Failed authentication attempt from %s", ctx.RemoteAddr())
logger.Error("Invalid Certificate KeyID %s with Signature Fingerprint %s presented for Principal: %s from %s", cert.KeyId, gossh.FingerprintSHA256(cert.SignatureKey), principal, ctx.RemoteAddr())
logger.Warn("Failed authentication attempt from %s", ctx.RemoteAddr())
return false
}
if log.IsDebug() { // <- FingerprintSHA256 is kinda expensive so only calculate it if necessary
log.Debug("Successfully authenticated: %s Certificate Fingerprint: %s Principal: %s", ctx.RemoteAddr(), gossh.FingerprintSHA256(key), principal)
if logger.LevelEnabled(log.DEBUG) { // <- FingerprintSHA256 is kinda expensive so only calculate it if necessary
logger.Debug("Successfully authenticated: %s Certificate Fingerprint: %s Principal: %s", ctx.RemoteAddr(), gossh.FingerprintSHA256(key), principal)
}
if ctx.Permissions().Extensions == nil {
ctx.Permissions().Extensions = map[string]string{}
@ -241,28 +241,28 @@ func publicKeyHandler(ctx ssh.Context, key ssh.PublicKey) bool {
return true
}
log.Warn("From %s Fingerprint: %s is a certificate, but no valid principals found", ctx.RemoteAddr(), gossh.FingerprintSHA256(key))
log.Warn("Failed authentication attempt from %s", ctx.RemoteAddr())
logger.Warn("From %s Fingerprint: %s is a certificate, but no valid principals found", ctx.RemoteAddr(), gossh.FingerprintSHA256(key))
logger.Warn("Failed authentication attempt from %s", ctx.RemoteAddr())
return false
}
if log.IsDebug() { // <- FingerprintSHA256 is kinda expensive so only calculate it if necessary
log.Debug("Handle Public Key: %s Fingerprint: %s is not a certificate", ctx.RemoteAddr(), gossh.FingerprintSHA256(key))
if logger.LevelEnabled(log.DEBUG) { // <- FingerprintSHA256 is kinda expensive so only calculate it if necessary
logger.Debug("Handle Public Key: %s Fingerprint: %s is not a certificate", ctx.RemoteAddr(), gossh.FingerprintSHA256(key))
}
pkey, err := asymkey_model.SearchPublicKeyByContent(ctx, strings.TrimSpace(string(gossh.MarshalAuthorizedKey(key))))
if err != nil {
if asymkey_model.IsErrKeyNotExist(err) {
log.Warn("Unknown public key: %s from %s", gossh.FingerprintSHA256(key), ctx.RemoteAddr())
log.Warn("Failed authentication attempt from %s", ctx.RemoteAddr())
logger.Warn("Unknown public key: %s from %s", gossh.FingerprintSHA256(key), ctx.RemoteAddr())
logger.Warn("Failed authentication attempt from %s", ctx.RemoteAddr())
return false
}
log.Error("SearchPublicKeyByContent: %v", err)
logger.Error("SearchPublicKeyByContent: %v", err)
return false
}
if log.IsDebug() { // <- FingerprintSHA256 is kinda expensive so only calculate it if necessary
log.Debug("Successfully authenticated: %s Public Key Fingerprint: %s", ctx.RemoteAddr(), gossh.FingerprintSHA256(key))
if logger.LevelEnabled(log.DEBUG) { // <- FingerprintSHA256 is kinda expensive so only calculate it if necessary
logger.Debug("Successfully authenticated: %s Public Key Fingerprint: %s", ctx.RemoteAddr(), gossh.FingerprintSHA256(key))
}
if ctx.Permissions().Extensions == nil {
ctx.Permissions().Extensions = map[string]string{}
@ -276,9 +276,9 @@ func publicKeyHandler(ctx ssh.Context, key ssh.PublicKey) bool {
// - this mainly exists to give a nice function name in logging
func sshConnectionFailed(conn net.Conn, err error) {
// Log the underlying error with a specific message
log.Warn("Failed connection from %s with error: %v", conn.RemoteAddr(), err)
logger.Warn("Failed connection from %s with error: %v", conn.RemoteAddr(), err)
// Log with the standard failed authentication from message for simpler fail2ban configuration
log.Warn("Failed authentication attempt from %s", conn.RemoteAddr())
logger.Warn("Failed authentication attempt from %s", conn.RemoteAddr())
}
// Listen starts a SSH server listens on given port.
@ -317,22 +317,22 @@ func Listen(host string, port int, ciphers, keyExchanges, macs []string) {
filePath := filepath.Dir(setting.SSH.ServerHostKeys[0])
if err := os.MkdirAll(filePath, os.ModePerm); err != nil {
log.Error("Failed to create dir %s: %v", filePath, err)
logger.Error("Failed to create dir %s: %v", filePath, err)
}
err := GenKeyPair(setting.SSH.ServerHostKeys[0])
if err != nil {
log.Fatal("Failed to generate private key: %v", err)
}
log.Trace("New private key is generated: %s", setting.SSH.ServerHostKeys[0])
logger.Trace("New private key is generated: %s", setting.SSH.ServerHostKeys[0])
keys = append(keys, setting.SSH.ServerHostKeys[0])
}
for _, key := range keys {
log.Info("Adding SSH host key: %s", key)
logger.Info("Adding SSH host key: %s", key)
err := srv.SetOption(ssh.HostKeyFile(key))
if err != nil {
log.Error("Failed to set Host Key. %s", err)
logger.Error("Failed to set Host Key. %s", err)
}
}
@ -359,7 +359,7 @@ func GenKeyPair(keyPath string) error {
}
defer func() {
if err = f.Close(); err != nil {
log.Error("Close: %v", err)
logger.Error("Close: %v", err)
}
}()
@ -380,7 +380,7 @@ func GenKeyPair(keyPath string) error {
}
defer func() {
if err = p.Close(); err != nil {
log.Error("Close: %v", err)
logger.Error("Close: %v", err)
}
}()
_, err = p.Write(public)

View file

@ -20,12 +20,12 @@ func listen(server *ssh.Server) {
if err != nil {
select {
case <-graceful.GetManager().IsShutdown():
log.Critical("Failed to start SSH server: %v", err)
logger.Critical("Failed to start SSH server: %v", err)
default:
log.Fatal("Failed to start SSH server: %v", err)
}
}
log.Info("SSH Listener: %s Closed", server.Addr)
logger.Info("SSH Listener: %s Closed", server.Addr)
}
// builtinUnused informs our cleanup routine that we will not be using a ssh port

View file

@ -23,6 +23,8 @@ import (
wiki_service "forgejo.org/services/wiki"
)
var sshLogger = log.GetManager().GetLogger("ssh")
func checkTwoFactor(ctx *context.PrivateContext, user *user_model.User) {
if !user.MustHaveTwoFactor() {
return
@ -30,7 +32,7 @@ func checkTwoFactor(ctx *context.PrivateContext, user *user_model.User) {
hasTwoFactor, err := auth.HasTwoFactorByUID(ctx, user.ID)
if err != nil {
log.Error("Error getting 2fa: %s", err)
sshLogger.Error("Error getting 2fa: %s", err)
ctx.JSON(http.StatusInternalServerError, private.Response{
Err: fmt.Sprintf("Error getting 2fa: %s", err),
})
@ -62,7 +64,7 @@ func ServNoCommand(ctx *context.PrivateContext) {
})
return
}
log.Error("Unable to get public key: %d Error: %v", keyID, err)
sshLogger.Error("Unable to get public key: %d Error: %v", keyID, err)
ctx.JSON(http.StatusInternalServerError, private.Response{
Err: err.Error(),
})
@ -79,7 +81,7 @@ func ServNoCommand(ctx *context.PrivateContext) {
})
return
}
log.Error("Unable to get owner with id: %d for public key: %d Error: %v", key.OwnerID, keyID, err)
sshLogger.Error("Unable to get owner with id: %d for public key: %d Error: %v", key.OwnerID, keyID, err)
ctx.JSON(http.StatusInternalServerError, private.Response{
Err: err.Error(),
})
@ -138,13 +140,13 @@ func ServCommand(ctx *context.PrivateContext) {
if err != nil {
if user_model.IsErrUserNotExist(err) {
// User is fetching/cloning a non-existent repository
log.Warn("Failed authentication attempt (cannot find repository: %s/%s) from %s", results.OwnerName, results.RepoName, ctx.RemoteAddr())
sshLogger.Warn("Failed authentication attempt (cannot find repository: %s/%s) from %s", results.OwnerName, results.RepoName, ctx.RemoteAddr())
ctx.JSON(http.StatusNotFound, private.Response{
UserMsg: fmt.Sprintf("Cannot find repository: %s/%s", results.OwnerName, results.RepoName),
})
return
}
log.Error("Unable to get repository owner: %s/%s Error: %v", results.OwnerName, results.RepoName, err)
sshLogger.Error("Unable to get repository owner: %s/%s Error: %v", results.OwnerName, results.RepoName, err)
ctx.JSON(http.StatusForbidden, private.Response{
UserMsg: fmt.Sprintf("Unable to get repository owner: %s/%s %v", results.OwnerName, results.RepoName, err),
})
@ -166,7 +168,7 @@ func ServCommand(ctx *context.PrivateContext) {
for _, verb := range ctx.FormStrings("verb") {
if verb == "git-upload-pack" {
// User is fetching/cloning a non-existent repository
log.Warn("Failed authentication attempt (cannot find repository: %s/%s) from %s", results.OwnerName, results.RepoName, ctx.RemoteAddr())
sshLogger.Warn("Failed authentication attempt (cannot find repository: %s/%s) from %s", results.OwnerName, results.RepoName, ctx.RemoteAddr())
ctx.JSON(http.StatusNotFound, private.Response{
UserMsg: fmt.Sprintf("Cannot find repository: %s/%s", results.OwnerName, results.RepoName),
})
@ -174,7 +176,7 @@ func ServCommand(ctx *context.PrivateContext) {
}
}
} else {
log.Error("Unable to get repository: %s/%s Error: %v", results.OwnerName, results.RepoName, err)
sshLogger.Error("Unable to get repository: %s/%s Error: %v", results.OwnerName, results.RepoName, err)
ctx.JSON(http.StatusInternalServerError, private.Response{
Err: fmt.Sprintf("Unable to get repository: %s/%s %v", results.OwnerName, results.RepoName, err),
})
@ -219,7 +221,7 @@ func ServCommand(ctx *context.PrivateContext) {
})
return
}
log.Error("Unable to get public key: %d Error: %v", keyID, err)
sshLogger.Error("Unable to get public key: %d Error: %v", keyID, err)
ctx.JSON(http.StatusInternalServerError, private.Response{
Err: fmt.Sprintf("Unable to get key: %d Error: %v", keyID, err),
})
@ -252,7 +254,7 @@ func ServCommand(ctx *context.PrivateContext) {
})
return
}
log.Error("Unable to get deploy for public (deploy) key: %d in %-v Error: %v", key.ID, repo, err)
sshLogger.Error("Unable to get deploy for public (deploy) key: %d in %-v Error: %v", key.ID, repo, err)
ctx.JSON(http.StatusInternalServerError, private.Response{
Err: fmt.Sprintf("Unable to get Deploy Key for Public Key: %d:%s in %s/%s.", key.ID, key.Name, results.OwnerName, results.RepoName),
})
@ -280,7 +282,7 @@ func ServCommand(ctx *context.PrivateContext) {
})
return
}
log.Error("Unable to get owner: %d for public key: %d:%s Error: %v", key.OwnerID, key.ID, key.Name, err)
sshLogger.Error("Unable to get owner: %d for public key: %d:%s Error: %v", key.OwnerID, key.ID, key.Name, err)
ctx.JSON(http.StatusInternalServerError, private.Response{
Err: fmt.Sprintf("Unable to get Owner: %d for Deploy Key: %d:%s in %s/%s.", key.OwnerID, key.ID, key.Name, ownerName, repoName),
})
@ -341,7 +343,7 @@ func ServCommand(ctx *context.PrivateContext) {
perm, err := access_model.GetUserRepoPermission(ctx, repo, user)
if err != nil {
log.Error("Unable to get permissions for %-v with key %d in %-v Error: %v", user, key.ID, repo, err)
sshLogger.Error("Unable to get permissions for %-v with key %d in %-v Error: %v", user, key.ID, repo, err)
ctx.JSON(http.StatusInternalServerError, private.Response{
Err: fmt.Sprintf("Unable to get permissions for user %d:%s with key %d in %s/%s Error: %v", user.ID, user.Name, key.ID, results.OwnerName, results.RepoName, err),
})
@ -351,7 +353,7 @@ func ServCommand(ctx *context.PrivateContext) {
userMode := perm.UnitAccessMode(unitType)
if userMode < mode {
log.Warn("Failed authentication attempt for %s with key %s (not authorized to %s %s/%s) from %s", user.Name, key.Name, modeString, ownerName, repoName, ctx.RemoteAddr())
sshLogger.Warn("Failed authentication attempt for %s with key %s (not authorized to %s %s/%s) from %s", user.Name, key.Name, modeString, ownerName, repoName, ctx.RemoteAddr())
ctx.JSON(http.StatusUnauthorized, private.Response{
UserMsg: fmt.Sprintf("User: %d:%s with Key: %d:%s is not authorized to %s %s/%s.", user.ID, user.Name, key.ID, key.Name, modeString, ownerName, repoName),
})
@ -385,7 +387,7 @@ func ServCommand(ctx *context.PrivateContext) {
repo, err = repo_service.PushCreateRepo(ctx, user, owner, results.RepoName)
if err != nil {
log.Error("pushCreateRepo: %v", err)
sshLogger.Error("pushCreateRepo: %v", err)
ctx.JSON(http.StatusNotFound, private.Response{
UserMsg: fmt.Sprintf("Cannot find repository: %s/%s", results.OwnerName, results.RepoName),
})
@ -403,7 +405,7 @@ func ServCommand(ctx *context.PrivateContext) {
})
return
}
log.Error("Failed to get the wiki unit in %-v Error: %v", repo, err)
sshLogger.Error("Failed to get the wiki unit in %-v Error: %v", repo, err)
ctx.JSON(http.StatusInternalServerError, private.Response{
Err: fmt.Sprintf("Failed to get the wiki unit in %s/%s Error: %v", ownerName, repoName, err),
})
@ -412,14 +414,14 @@ func ServCommand(ctx *context.PrivateContext) {
// Finally if we're trying to touch the wiki we should init it
if err = wiki_service.InitWiki(ctx, repo); err != nil {
log.Error("Failed to initialize the wiki in %-v Error: %v", repo, err)
sshLogger.Error("Failed to initialize the wiki in %-v Error: %v", repo, err)
ctx.JSON(http.StatusInternalServerError, private.Response{
Err: fmt.Sprintf("Failed to initialize the wiki in %s/%s Error: %v", ownerName, repoName, err),
})
return
}
}
log.Debug("Serv Results:\nIsWiki: %t\nDeployKeyID: %d\nKeyID: %d\tKeyName: %s\nUserName: %s\nUserID: %d\nOwnerName: %s\nRepoName: %s\nRepoID: %d",
sshLogger.Info("Serv Results:\n\tIsWiki: %t\n\tDeployKeyID: %d\n\tKeyID: %d\tKeyName: %s\n\tUserName: %s\n\tUserID: %d\n\tOwnerName: %s\n\tRepoName: %s\n\tRepoID: %d",
results.IsWiki,
results.DeployKeyID,
results.KeyID,

View file

@ -8,26 +8,19 @@ import (
"forgejo.org/modules/log"
"forgejo.org/modules/private"
"forgejo.org/modules/setting"
"forgejo.org/modules/web"
"forgejo.org/services/context"
)
// SSHLog hook to response ssh log
func SSHLog(ctx *context.PrivateContext) {
if !setting.Log.EnableSSHLog {
logger := log.GetManager().GetLogger("ssh")
if !logger.IsEnabled() {
ctx.Status(http.StatusOK)
return
}
opts := web.GetForm(ctx).(*private.SSHLogOption)
if opts.IsError {
log.Error("ssh: %v", opts.Message)
ctx.Status(http.StatusOK)
return
}
log.Debug("ssh: %v", opts.Message)
logger.Log(0, opts.Level, "ssh: %v", opts.Message)
ctx.Status(http.StatusOK)
}

View file

@ -275,7 +275,10 @@ func testOptionsGitPush(t *testing.T, u *url.URL) {
t.Run("Collaborator with write access fails to change private & template via push options", func(t *testing.T) {
logChecker, cleanup := test.NewLogChecker(log.DEFAULT, log.TRACE)
logChecker.Filter("permission denied for changing repo settings").StopMark("Git push options validation")
logChecker.StopMark("Git push options validation")
defer cleanup()
sshLogChecker, cleanup := test.NewLogChecker("ssh", log.ERROR)
sshLogChecker.Filter("permission denied for changing repo settings")
defer cleanup()
branchName := "branch4"
doGitCreateBranch(gitPath, branchName)(t)
@ -284,7 +287,8 @@ func testOptionsGitPush(t *testing.T, u *url.URL) {
require.NoError(t, err)
require.False(t, repo.IsPrivate)
require.False(t, repo.IsTemplate)
logFiltered, logStopped := logChecker.Check(5 * time.Second)
_, logStopped := logChecker.Check(5 * time.Second)
logFiltered, _ := sshLogChecker.Check(5 * time.Second)
assert.True(t, logStopped)
assert.True(t, logFiltered[0])
})

View file

@ -76,8 +76,8 @@ PROVIDER_CONFIG = tests/{{TEST_TYPE}}/gitea-{{TEST_TYPE}}-mysql/data/sessions
[log]
MODE = {{TEST_LOGGER}}
ROOT_PATH = {{REPO_TEST_DIR}}mysql-log
ENABLE_SSH_LOG = true
LOGGER_XORM_MODE = file
LOGGER_SSH_MODE = ,
[log.test]
LEVEL = Info

View file

@ -81,8 +81,8 @@ PROVIDER_CONFIG = tests/{{TEST_TYPE}}/gitea-{{TEST_TYPE}}-pgsql/data/sessions
[log]
MODE = {{TEST_LOGGER}}
ROOT_PATH = {{REPO_TEST_DIR}}pgsql-log
ENABLE_SSH_LOG = true
LOGGER_XORM_MODE = file
LOGGER_SSH_MODE = ,
[log.test]
LEVEL = Info

View file

@ -78,8 +78,8 @@ PROVIDER_CONFIG = tests/{{TEST_TYPE}}/gitea-{{TEST_TYPE}}-sqlite/data/sessions
[log]
MODE = {{TEST_LOGGER}}
ROOT_PATH = {{REPO_TEST_DIR}}sqlite-log
ENABLE_SSH_LOG = true
LOGGER_XORM_MODE = file
LOGGER_SSH_MODE = ,
[log.test]
LEVEL = Info