trojanXX.lock : Empty lockfile (EOF) , Lock for 'trojan/XX' is stale

[cattyhouse]

caddy 2.6.4 with caddy-trojan main, lots of log like this , every 3~10 minutes:

caddy[pid]: {"level":"info","ts":hide_TIMESTAMP,"msg":"[INFO][FileStorage:/home/caddy/.local/share/caddy] /home/caddy/.local/share/caddy/locks/trojanxxxxxxxxxxx.lock: Empty lockfile (EOF) - likely previous process crashed or storage medium failure; treating as stale"}

caddy[pid]: {"level":"info","ts":hide_TIMESTAMP,"msg":"[INFO][FileStorage:/home/caddy/.local/share/caddy] Lock for 'trojan/xxxxxxxxxxx' is stale (created: 0001-01-01 00:00:00 +0000 UTC, last update: 0001-01-01 00:00:00 +0000 UTC); removing then retrying: /home/caddy/.local/share/caddy/locks/trojanxxxxxxxxxxx.lock"}

the user/group is caddy:caddy, home is /home/caddy, permissions/ownership are all fine as i've checked. , i already set global log level to PANIC. btw, trojan is working fine, it's just the logs are annoying.

what could be the causes?

Caddyfile (with sensitive info replaced)

{
    servers :443 {
        listener_wrappers {
            trojan
        }
        protocols h1 h2
    }
    trojan {
        caddy
        no_proxy
        users $pw
    }
    log {
        level PANIC
    }
    admin off
    order trojan before file_server
}

:443, $name {
    tls $mail
    header {
        Strict-Transport-Security max-age=31536000
        X-Content-Type-Options nosniff
        X-Robots-Tag "noindex, nofollow, nosnippet, noarchive"
        X-Frame-Options DENY
        Permissions-Policy interest-cohort=()
        Referrer-Policy no-referrer-when-downgrade
    }
    trojan {
        #connect_method
        #websocket
    }
    file_server browse {
        root /var/www/html
    }
}

[cattyhouse]

sudo journalctl -g 'empty|stale' -u caddy

[imgk]

Hi, caddy-trojan uses the FileStorage module to store data. So this might be an issue with caddy not caddy-trojan.

[cattyhouse]

Hi, caddy-trojan uses the FileStorage module to store data. So this might be an issue with caddy not caddy-trojan.

Thanks for your reply. Do you see these logs on your side if you are using caddy 2.6.4?

[cattyhouse]

there is a file in /home/caddy/.local/share/caddy/trojan/xxxxxxxxxxx, that is used to store up/down traffics, maybe related to that file?

[cattyhouse]

looks like it is due to this commit : https://github.com/caddyserver/certmagic/commit/79babffe28c5e593b19b5268bf26447f1f5f0b26

[cattyhouse]

looks like this kind of log can't be disabled because it does not have a logger ( namespace field), thus not possible to exclude

temporary solution:

edit caddy.service, add one of below options

[Service]

# newer systemd, e.g. on Archlinux
# ~ means discard, the following keyword is in extended regex (ERE) form 
LogFilterPatterns=~FileStorage.*trojan

# older systemd, e.g. on debian 12
# this version of system does not have above option, we have to redirect logs to /dev/null
# WARNING: this will discard all logs except for caddy environ output
StandardError=null

why does it bother?

journalctl -g 'empty|stale' -u caddy | wc -l:

32285

[cattyhouse]

@imgk would you mind reading this comment? it basically says, .lock should not be created empty.

when created , it stores timestamps info as json format.

https://github.com/caddyserver/certmagic/issues/232#issuecomment-1550788904

[cattyhouse]

i made a patch to disable traffic updating, thus disables creating lock files

do you think it is worthy making this as an option?

diff --git a/listener/listener.go b/listener/listener.go
index b8116c2..88efe02 100644
--- a/listener/listener.go
+++ b/listener/listener.go
@@ -192,11 +192,11 @@ func (l *Listener) loop() {
                lg.Info(fmt.Sprintf("handle trojan net.Conn from %v", c.RemoteAddr()))
            }

-           nr, nw, err := l.Proxy.Handle(io.Reader(c), io.Writer(c))
+           _, _, err := l.Proxy.Handle(io.Reader(c), io.Writer(c))
            if err != nil {
                lg.Error(fmt.Sprintf("handle net.Conn error: %v", err))
            }
-           up.Consume(utils.ByteSliceToString(b[:trojan.HeaderLen]), nr, nw)
+           // up.Consume(utils.ByteSliceToString(b[:trojan.HeaderLen]), nr, nw)
        }(conn, l.Logger, l.Upstream)
    }
 }

[imgk]

Hi, sorry for the late reply. If you want to stop storing traffic on disk, you can try to setup trojan like this.

{
  "apps": {
    "http": {
      "servers": {
        "srv0": {
          "listen": [":443"],
          "listener_wrappers": [{
            "wrapper": "trojan"
          }],
          "routes": [{
            "handle": [{
              "handler": "trojan",
              "connect_method": true,
              "websocket": true
            },
            {
              "handler": "file_server",
              "root": "/var/www/html"
            }]
          }]
        }
      }
    },
    "trojan": {
      "upstream": {
        "upstream": "memory"
      },
      "proxy": {
        "proxy": "no_proxy"
      },
      "users": ["pass1234","word5678"]
    },
    "tls": {
      "certificates": {
        "automate": ["example.com"]
      },
      "automation": {
        "policies": [{
          "issuers": [{
            "module": "acme",
            "email": "your@email.com" //optional,recommended
          },
          {
            "module": "zerossl",
            "email": "your@email.com" //optional,recommended
          }]
        }]
      }
    }
  }
}

[cattyhouse]

thanks. that's basically replace caddy with memory?

[imgk]

Yes. When setting the value of upstream to memory, caddy-trojan wouldn't store traffic data to caddy FileStorage. Just store that data in computer memory.

[cattyhouse]

will that store users added via API in memory as well?

and even in memory, lock file is still generated on each connection?

[cattyhouse]

would you mind to tell all the differences between caddy and memory

[imgk]

caddy: save to caddy FileStorage

memory: save to computer memory

[cattyhouse]

thanks! i'll close now. it is caddy upstream issue (race condition).

[cattyhouse]

@imgk the issue is solved upstream by Caddy author Matt Holt by introducing a wait and retry mechanism. And he suggests using sync.Mutex method for the lock file (quote "For in-process locking, definitely just use sync.Mutex.")

could you take a look at it? thanks.