mtlynch / logpaste

A simple web service for storing text log files
https://logpaste.com/
MIT License
318 stars 28 forks source link

[Bug]: `PER_MINUTE_LIMIT` breaks uploads: Error retrieving user IP #177

Open Kangie opened 1 year ago

Kangie commented 1 year ago

Enabling PER_MINUTE_LIMIT seems to result in (some) failed uploads (HTTP 500s returned to clients) and associated Error retrieving user IP ... missing port in address entries in the logs.

paste_logpaste.1.rnrsxqsk6n34@hostname    | 2023/08/18 02:04:15 Error retrieving user IP: address 98.212.178.249: missing port in address
paste_logpaste.1.rnrsxqsk6n34@hostname    | 98.212.178.249 - - [18/Aug/2023:02:04:15 +0000] "PUT / HTTP/1.1" 500 22
paste_logpaste.1.rnrsxqsk6n34@hostname    | 98.212.178.249 - - [18/Aug/2023:02:04:16 +0000] "PUT / HTTP/1.1" 500 22
paste_logpaste.1.rnrsxqsk6n34@hostname    | 2023/08/18 02:04:16 Error retrieving user IP: address 98.212.178.249: missing port in address
paste_logpaste.1.rnrsxqsk6n34@hostname    | 2023/08/18 02:04:17 Error retrieving user IP: address 98.212.178.249: missing port in address
paste_logpaste.1.rnrsxqsk6n34@hostname    | 98.212.178.249 - - [18/Aug/2023:02:04:17 +0000] "PUT / HTTP/1.1" 500 22
paste_logpaste.1.rnrsxqsk6n34@hostname    | 98.212.178.249 - - [18/Aug/2023:02:04:17 +0000] "PUT / HTTP/1.1" 500 22
paste_logpaste.1.rnrsxqsk6n34@hostname    | 2023/08/18 02:04:17 Error retrieving user IP: address 98.212.178.249: missing port in address
paste_logpaste.1.rnrsxqsk6n34@hostname    | 119.18.36.251 - - [18/Aug/2023:02:09:02 +0000] "GET / HTTP/1.1" 200 2403

<snip>

paste_logpaste.1.rnrsxqsk6n34@hostname    | 97.139.114.161 - - [18/Aug/2023:02:21:56 +0000] "GET / HTTP/1.1" 200 2403
paste_logpaste.1.rnrsxqsk6n34@hostname    | 97.139.114.161 - - [18/Aug/2023:02:22:31 +0000] "GET / HTTP/1.1" 200 2403
paste_logpaste.1.rnrsxqsk6n34@hostname    | 97.139.114.161 - - [18/Aug/2023:02:22:31 +0000] "GET /third-party/prism/dark.css HTTP/1.1" 200 0
paste_logpaste.1.rnrsxqsk6n34@hostname    | 97.139.114.161 - - [18/Aug/2023:02:22:31 +0000] "GET /css/dark.css HTTP/1.1" 200 0
paste_logpaste.1.rnrsxqsk6n34@hostname    | 97.139.114.161 - - [18/Aug/2023:02:22:31 +0000] "GET /css/style.css HTTP/1.1" 200 0
paste_logpaste.1.rnrsxqsk6n34@hostname    | 97.139.114.161 - - [18/Aug/2023:02:22:31 +0000] "GET /third-party/prism/prism.js HTTP/1.1" 200 0
paste_logpaste.1.rnrsxqsk6n34@hostname    | 97.139.114.161 - - [18/Aug/2023:02:22:31 +0000] "GET /js/app.js HTTP/1.1" 200 0
paste_logpaste.1.rnrsxqsk6n34@hostname    | 97.139.114.161 - - [18/Aug/2023:02:22:31 +0000] "GET /js/logpaste.js HTTP/1.1" 200 0
paste_logpaste.1.rnrsxqsk6n34@hostname    | 97.139.114.161 - - [18/Aug/2023:02:22:32 +0000] "GET /favicon.ico HTTP/1.1" 404 19
paste_logpaste.1.rnrsxqsk6n34@hostname    | 97.139.114.161 - - [18/Aug/2023:02:22:44 +0000] "PUT / HTTP/1.1" 500 22
paste_logpaste.1.rnrsxqsk6n34@hostname    | 2023/08/18 02:22:44 Error retrieving user IP: address 97.139.114.161: missing port in address

<snip>

paste_logpaste.1.27ukohbhfvwm@hostname    | 119.18.36.251 - - [22/Aug/2023:07:43:10 +0000] "GET / HTTP/1.1" 200 2403
paste_logpaste.1.27ukohbhfvwm@hostname    | 119.18.36.251 - - [22/Aug/2023:07:43:16 +0000] "GET / HTTP/1.1" 200 2403
paste_logpaste.1.27ukohbhfvwm@hostname    | 119.18.36.251 - - [22/Aug/2023:07:43:19 +0000] "GET / HTTP/1.1" 200 2403
paste_logpaste.1.27ukohbhfvwm@hostname    | 119.18.36.251 - - [22/Aug/2023:07:43:19 +0000] "GET /css/style.css HTTP/1.1" 200 0
paste_logpaste.1.27ukohbhfvwm@hostname    | 119.18.36.251 - - [22/Aug/2023:07:43:19 +0000] "GET /third-party/prism/dark.css HTTP/1.1" 200 0
paste_logpaste.1.27ukohbhfvwm@hostname    | 119.18.36.251 - - [22/Aug/2023:07:43:19 +0000] "GET /css/dark.css HTTP/1.1" 200 0
paste_logpaste.1.27ukohbhfvwm@hostname    | 119.18.36.251 - - [22/Aug/2023:07:43:19 +0000] "GET /third-party/prism/prism.js HTTP/1.1" 200 0
paste_logpaste.1.27ukohbhfvwm@hostname    | 119.18.36.251 - - [22/Aug/2023:07:43:19 +0000] "GET /js/logpaste.js HTTP/1.1" 200 0
paste_logpaste.1.27ukohbhfvwm@hostname    | 119.18.36.251 - - [22/Aug/2023:07:43:19 +0000] "GET /js/app.js HTTP/1.1" 200 0
paste_logpaste.1.27ukohbhfvwm@hostname    | 119.18.36.251 - - [22/Aug/2023:07:43:19 +0000] "GET /favicon.ico HTTP/1.1" 404 19
paste_logpaste.1.27ukohbhfvwm@hostname    | 2023/08/22 07:43:37 Error retrieving user IP: address 119.18.36.251: missing port in address
paste_logpaste.1.27ukohbhfvwm@hostname    | 119.18.36.251 - - [22/Aug/2023:07:43:37 +0000] "POST / HTTP/1.1" 500 22
paste_logpaste.1.27ukohbhfvwm@hostname    | 2023/08/22 07:43:45 Error retrieving user IP: address 119.18.36.251: missing port in address
paste_logpaste.1.27ukohbhfvwm@hostname    | 119.18.36.251 - - [22/Aug/2023:07:43:45 +0000] "POST / HTTP/1.1" 500 22

I can't confirm that this envvar/option is the cause of the issue, but it seems to have stopped happening when not trying to rate limit.

Deployment details:

Docker container behind traefik, configured as follows:

version: '3.9'

services:
  logpaste:
    image: mtlynch/logpaste
    environment:
      - LITESTREAM_ACCESS_KEY_ID=<snip>
      - LITESTREAM_SECRET_ACCESS_KEY=<snip>
      - LITESTREAM_REGION=<snip>
      - DB_REPLICA_URL=<snip>
      - PORT=3001
      - PS_BEHIND_PROXY=y
      - SITE_TITLE=(Un)official Gentoo Pastebin
      - SITE_SUBTITLE=A place for Gentoo-related pastes. No abuse
      - SITE_FOOTER=For cool people only.
      - SITE_DARK_MODE=true
        #- PER_MINUTE_LIMIT=5
    networks:
      - traefik-network
    deploy:
      labels:
        # Enable Traefik for this docker service
        - "traefik.enable=true"
        # Redirect HTTP -> HTTPS with a middleware
        - "traefik.http.routers.paste-http.rule=Host(`paste.gentoo.zip`)"
        - "traefik.http.routers.paste-http.entrypoints=web"
        - "traefik.http.routers.paste-http.middlewares=redirect-https@file"
        - "traefik.http.routers.paste-http.service=paste"
        # Define our HTTPS configuration
        - "traefik.http.routers.paste-https.rule=Host(`paste.gentoo.zip`)"
        - "traefik.http.routers.paste-https.service=paste"
        - "traefik.http.routers.paste-https.entrypoints=websecure"
        - "traefik.http.routers.paste-https.tls=true"
        - "traefik.http.routers.paste-https.tls.certresolver=letsencrypt"
        - "traefik.http.routers.paste-https.tls.domains[0].main=gentoo.zip"
        - "traefik.http.routers.paste-https.tls.domains[0].sans=*.gentoo.zip"
        # Define the Traefik service for this docker container
        - "traefik.http.services.paste.loadbalancer.server.port=3001"

networks:
  traefik-network:
    external: true
Kangie commented 1 year ago

Confirmed to be a bug gated by ratelimiting envvar

Seems like we're assuming that we'll always get a port and sometimes we get an IP with no port and splitting the port fails.

https://github.com/mtlynch/logpaste/blob/27275996629d6792a729542d3d956c27371aba39/limit/limit.go#L46-L56

mtlynch commented 1 year ago

Thanks for chasing this down, @Kangie!

Isn't that a bug on traefik's side? How can the client not have a TCP port number?

Kangie commented 1 year ago

Isn't that a bug on traefik's side? How can the client not have a TCP port number?

Not sure tbh, but even if it is a bug on the traefik side this information is also not something that logpaste needs to function work outside of this single line in the ratelimiting code.

It'd probably be worth raising upstream but if we don't actually need the information, working around it here will be by far the fastest way to get the code working as intended!

I'm not a golang person, and I'm still recovering from RSI so I can't dig into the code yet, but I'm hoping that maybe next month I have time for 'fun' computing, not just essential :)