when setting force tlsPolicy for dfdaemon, something still connect download unix sock with non-TLS

[karlhjm]

Bug report:

I haven't taken any download action at this time but something is accessing the download unix sock through non-TLS, whie I set tlsPolicy to 'force'

2024-08-15T04:04:01.926Z        INFO    grpclog/grpclog.go:37   [core][Channel #1 SubChannel #2] Subchannel Connectivity change to CONNECTING
2024-08-15T04:04:01.926Z        INFO    grpclog/grpclog.go:37   [core][Channel #1 SubChannel #2] Subchannel picks a new address "/var/run/dfdaemon.sock" to connect
2024-08-15T04:04:01.927Z        INFO    grpclog/grpclog.go:37   [core][Server #20] grpc: Server.Serve failed to create ServerTransport: connection error: desc = "ServerHandshake(\"@\") failed: tls: first record does not look like a TLS handshake"
2024-08-15T04:04:01.927Z        WARN    grpclog/grpclog.go:46   [core][Channel #1 SubChannel #2] grpc: addrConn.createTransport failed to connect to {Addr: "/var/run/dfdaemon.sock", ServerName: "localhost", Attributes: {"<%!p(networktype.keyType=grpc.internal.transport.networktype)>": "unix" }, }. Err: connection error: desc = "error reading server preface: EOF"
google.golang.org/grpc/internal/grpclog.WarningDepth
        /go/pkg/mod/google.golang.org/[email protected]/internal/grpclog/grpclog.go:46
google.golang.org/grpc/grpclog.(*componentData).WarningDepth
        /go/pkg/mod/google.golang.org/[email protected]/grpclog/component.go:41
google.golang.org/grpc/internal/channelz.AddTraceEvent
        /go/pkg/mod/google.golang.org/[email protected]/internal/channelz/funcs.go:313
google.golang.org/grpc/internal/channelz.Warningf
        /go/pkg/mod/google.golang.org/[email protected]/internal/channelz/logging.go:59
google.golang.org/grpc.(*addrConn).createTransport
        /go/pkg/mod/google.golang.org/[email protected]/clientconn.go:1400
google.golang.org/grpc.(*addrConn).tryAllAddrs
        /go/pkg/mod/google.golang.org/[email protected]/clientconn.go:1340
google.golang.org/grpc.(*addrConn).resetTransport
        /go/pkg/mod/google.golang.org/[email protected]/clientconn.go:1275
google.golang.org/grpc.(*addrConn).connect

Expected behavior:

when setting force tlsPolicy, every client access download unix sock with tls

How to reproduce it:

here is the main config of dfdaemon, use tlsPolicy: force and tlsVerify

download:
  calculateDigest: true
  syncPieceViaHTTPS: true
  downloadGRPC:
    security:
      insecure: false
      caCert: /etc/d7y-root-ca-key/ca.crt      
      cert: /etc/d7y-peer-server-cert/server.crt
      key: /etc/d7y-peer-server-cert/server.key
      tlsVerify: true    unixListen:
      socket: "/var/run/dfdaemon.sock"
  peerGRPC:
    security:
      insecure: false
      caCert: /etc/d7y-root-ca-key/ca.crt
      cert: /etc/d7y-peer-server-cert/server.crt
      key: /etc/d7y-peer-server-cert/server.key
      tlsVerify: true
    tcpListen:
      port: 65000
  perPeerRateLimit: 512Mi
  prefetch: false
  totalRateLimit: 1024Mi
upload:
  rateLimit: 1024Mi
  security:
    insecure: false
    caCert: /etc/d7y-root-ca-key/ca.crt
    cert: /etc/d7y-peer-server-cert/server.crt
    key: /etc/d7y-peer-server-cert/server.key
    tlsVerify: true
  tcpListen:
    port: 65002
objectStorage:
  enable: false
  filter: Expires&Signature&ns
  maxReplicas: 3
  security:
    insecure: true
    tlsVerify: true
  tcpListen:
    port: 65004
storage:
  diskGCThreshold: 50Gi
  multiplex: true
  strategy: io.d7y.storage.v2.simple
  taskExpireTime: 6h
proxy:
  defaultFilter: Expires&Signature&ns
  defaultTag: 
  tcpListen:    
    listen: 127.0.0.1
    port: 65001
  security:
    insecure: true
    tlsVerify: false
  registryMirror:
    dynamic: true
    insecure: false
    url: https://index.docker.io
  proxies:
    - regx: blobs/sha256.*
  hijackHTTPS:
    cert: /etc/dragonfly-ca/cacert.pem
    key: /etc/dragonfly-ca/cakey.pem
    hosts:
    - regx: .*
      insecure: true
security:
  autoIssueCert: true
  caCert: "/etc/d7y-root-ca-key/ca.crt"
  certSpec:
    ipAddresses: null
    validityPeriod: 4320h
  tlsPolicy: force
  tlsVerify: true

Environment:

• Dragonfly version: 2.1.0
• OS: ubuntu 16
• Kernel (e.g. uname -a):
• Others:

[gaius-qi]

@jim3ma

[karlhjm]

the command of dfdaemon is "/opt/dragonfly/bin/dfget daemon --v=10"

[jim3ma]

The dfget daemon does not write these log, you can find which process writes the logs file.

[karlhjm]

The dfget daemon does not write these log, you can find which process writes the logs file.

daemon writes it, error logs in /var/log/dragonfly/daemon/grpc.log

/ # lsof -n | grep /var/log/dragonfly/daemon/grpc.log
76307   /opt/dragonfly/bin/dfget        9       /var/log/dragonfly/daemon/grpc.log

/ # ps | grep 76307
28172 root      0:00 grep 76307
76307 root      0:15 /opt/dragonfly/bin/dfget daemon --v=10

/ # cat /var/log/dragonfly/daemon/grpc.log | grep -i err{"level":"warn","ts":"2024-08-15 07:27:35.147","caller":"grpclog/grpclog.go:46","msg":"[core][Channel #1 SubChannel #2] grpc: addrConn.createTransport failed to connect to {Addr: \"/var/run/dfdaemon.sock\", ServerName: \"localhost\", Attributes: {\"<%!p(networktype.keyType=grpc.internal.transport.networktype)>\": \"unix\" }, }. Err: connection error: desc = \"transport: Error while dialing: dial unix /var/run/dfdaemon.sock: connect: no such file or directory\"","stacktrace":"google.golang.org/grpc/internal/grpclog.WarningDepth\n\t/go/pkg/mod/google.golang.org/[email protected]/internal/grpclog/grpclog.go:46\ngoogle.golang.org/grpc/grpclog.(*componentData).WarningDepth\n\t/go/pkg/mod/google.golang.org/[email protected]/grpclog/component.go:41\ngoogle.golang.org/grpc/internal/channelz.AddTraceEvent\n\t/go/pkg/mod/google.golang.org/[email protected]/internal/channelz/funcs.go:313\ngoogle.golang.org/grpc/internal/channelz.Warningf\n\t/go/pkg/mod/google.golang.org/[email protected]/internal/channelz/logging.go:59\ngoogle.golang.org/grpc.(*addrConn).createTransport\n\t/go/pkg/mod/google.golang.org/[email protected]/clientconn.go:1400\ngoogle.golang.org/grpc.(*addrConn).tryAllAddrs\n\t/go/pkg/mod/google.golang.org/[email protected]/clientconn.go:1340\ngoogle.golang.org/grpc.(*addrConn
).resetTransport\n\t/go/pkg/mod/google.golang.org/[email protected]/clientconn.go:1275\ngoogle.golang.org/grpc.(*addrConn).connect\n\t/go/pkg/mod/google.golang.org/[email protected]/clientconn.go:930"}
{"level":"info","ts":"2024-08-15 07:27:35.147","caller":"grpclog/grpclog.go:37","msg":"[core][Channel #1 SubChannel #2] Subchannel Connectivity change to TRANSIENT_FAILURE, last error: connection error: desc = \"transport: Error while dialing: dial unix /var/run/dfdaemon.sock: connect: no such file or directory\""}
{"level":"info","ts":"2024-08-15 07:27:36.148","caller":"grpclog/grpclog.go:37","msg":"[core][Channel #1 SubChannel #2] Subchannel Connectivity change to IDLE, last error: connection error: desc = \"transport: Error while dialing: dial unix /var/run/dfdaemon.sock: connect: no such file or directory\""}
{"level":"info","ts":"2024-08-15 07:27:36.148","caller":"grpclog/grpclog.go:37","msg":"[core][Server #20] grpc: Server.Serve failed to create ServerTransport: connection error: desc = \"ServerHandshake(\\\"@\\\") failed: tls: first record does not look like a TLS handshake\""}{"level":"warn","ts":"2024-08-15 07:27:36.148","caller":"grpclog/grpclog.go:46","msg":"[core][Channel #1 SubChannel #2] grpc: addrConn.createTransport failed to connect to {Addr: \"/var/run/dfdaemon.sock\", ServerName: \"localhost\", Attributes: {\"<%!p(networktype.keyType=grpc.internal.transport.networktype)>\": \"unix\" }, }. Err: connection error: desc = \"error reading server preface: EOF\"","stacktrace":"google.golang.org/grpc/internal/grpclog.WarningDepth\n\t/go/pkg/mod/google.golang.org/[email protected]/internal/grpclog/grpclog.go:46\ngoogle.golang.org/grpc/grpclog.(*componentData).WarningDepth\n\t/go/pkg/mod/google.golang.org/[email protected]/grpclog/component.go:41\ngoogle.golang.org/grpc/internal/channelz.AddTraceEvent\n\t/go/pkg/mod/google.golang.org/[email protected]/internal/channelz/funcs.go:313\ngoogle.golang.org/grpc/internal/channelz.Warningf\n\t/go/pkg/mod/google.golang.org/[email protected]/internal/channelz/logging.go:59\ngoogle.golang.org/grpc.(*addrConn).createTransport\n\t/go/pkg/mod/google.golang.org/[email protected]/clientconn.go:1400\ngoogle.golang.org/grpc.(*addrConn).tryAllAddrs\n\t/go/pkg/mod/google.golang.org/[email protected]/clientconn.go:1340\ngoogle.golang.org/grpc.(*addrConn).resetTransport\n\t/go/pkg/mod/google.golang.org/[email protected]/clie
ntconn.go:1275\ngoogle.golang.org/grpc.(*addrConn).connect\n\t/go/pkg/mod/google.golang.org/[email protected]/clientconn.go:930"}
{"level":"info","ts":"2024-08-15 07:27:36.148","caller":"grpclog/grpclog.go:37","msg":"[core][Channel #1 SubChannel #2] Subchannel Connectivity change to TRANSIENT_FAILURE, last error: connection error: desc = \"error reading server preface: EOF\""}
{"level":"info","ts":"2024-08-15 07:27:37.772","caller":"grpclog/grpclog.go:37","msg":"[core][Channel #1 SubChannel #2] Subchannel Connectivity change to IDLE, last error: connection error: desc = \"error reading server preface: EOF\""}
{"level":"info","ts":"2024-08-15 07:27:37.772","caller":"grpclog/grpclog.go:37","msg":"[core][Server #20] grpc: Server.Serve failed to create ServerTransport: connection error: desc = \"ServerHandshake(\\\"@\\\") failed: tls: first record does not look like a TLS handshake\""}