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

在一台服务器上并发执行同一个命令时,文件下载成功了,但是下载到本地的文件大小为0 #2427

Open
sssudada opened this issue Jun 2, 2023 · 9 comments
Assignees
Labels

Comments

@sssudada
Copy link

sssudada commented Jun 2, 2023

Bug report:

在一台服务器上并发执行同一个命令时,文件下载成功了,但是下载到本地的文件大小为0

Expected behavior:

How to reproduce it:

在一台服务器上,同一时间并行执行2次相同命令时:
dfget --tag xxx '--header=endpoint: https://oss-cn-hangzhou.aliyuncs.com' '--header=accessKeyID: id' '--header=accessKeySecret: secret' -u oss://bucket/path/to/object -O /path/to/output/object

dfget --tag xxx '--header=endpoint: https://oss-cn-hangzhou.aliyuncs.com' '--header=accessKeyID: id' '--header=accessKeySecret: secret' -u oss://bucket/path/to/object -O /path/to/output/object

Environment:

  • Dragonfly version: v2.0.8
  • OS: CentOS 7.9
  • Kernel (e.g. uname -a): Linux 6.1.1 support logger with fields #2 SMP PREEMPT_DYNAMIC Mon May 29 21:30:16 CST 2023 x86_64 x86_64 x86_64 GNU/Linux
  • Others:

core.log

{"level":"info","ts":"2023-06-02 17:23:31.255","caller":"cmd/root.go:219","msg":"Version:\nMajor: 2, Minor: 0, GitVersion: v2.0.8, GitCommit: 8a7d951, Platform: linux, BuildTime: 2022-12-02T08:07:43Z, GoVersion: go1.19.3 linux/amd64, Gotags: none, Gogcflags: none"}
{"level":"info","ts":"2023-06-02 17:23:31.256","caller":"cmd/root.go:219","msg":"Version:\nMajor: 2, Minor: 0, GitVersion: v2.0.8, GitCommit: 8a7d951, Platform: linux, BuildTime: 2022-12-02T08:07:43Z, GoVersion: go1.19.3 linux/amd64, Gotags: none, Gogcflags: none"}
{"level":"info","ts":"2023-06-02 17:23:31.257","caller":"cmd/root.go:223","msg":"client dfget configuration:\nconsole: false\nverbose: false\npprof-port: -1\njaeger: ""\nservice-name: dragonfly-dfget\nurl: oss://bucket/server_bin/master/output/gameserver/gameserver\noutput: /home/data/deploy_space/server_bin/master/output/gameserver/gameserver\ntag: 29e645679a61aa534cb90eb773d182af\nheader:\n - 'endpoint: oss-cn-shanghai-internal.aliyuncs.com'\n - 'accessKeyID: xxxxxxxx'\n - 'accessKeySecret: xxxxxx'\nrateLimit:\n limit: 1.073741824e+09\nrecursiveLevel: 5\n"}
{"level":"info","ts":"2023-06-02 17:23:31.257","caller":"cmd/root.go:234","msg":"start to check and spawn daemon"}
{"level":"info","ts":"2023-06-02 17:23:31.257","caller":"cmd/root.go:223","msg":"client dfget configuration:\nconsole: false\nverbose: false\npprof-port: -1\njaeger: ""\nservice-name: dragonfly-dfget\nurl: oss://bucket/server_bin/master/output/gameserver/gameserver\noutput: /home/data/deploy_space/server_bin/master/output/gameserver/gameserver\ntag: 29e645679a61aa534cb90eb773d182af\nheader:\n - 'endpoint: oss-cn-shanghai-internal.aliyuncs.com'\n - 'accessKeyID: xxxxxxxx'\n - 'accessKeySecret: xxxxxx'\nrateLimit:\n limit: 1.073741824e+09\nrecursiveLevel: 5\n"}
{"level":"info","ts":"2023-06-02 17:23:31.257","caller":"cmd/root.go:234","msg":"start to check and spawn daemon"}
{"level":"info","ts":"2023-06-02 17:23:33.275","caller":"cmd/root.go:281","msg":"do start daemon"}
{"level":"info","ts":"2023-06-02 17:23:34.375","caller":"cmd/root.go:238","msg":"check and spawn daemon success"}
{"level":"info","ts":"2023-06-02 17:23:34.376","caller":"dfget/dfget.go:55","msg":"init success and start to download","url":"oss://bucket/server_bin/master/output/gameserver/gameserver"}
{"level":"info","ts":"2023-06-02 17:23:34.378","caller":"cmd/root.go:238","msg":"check and spawn daemon success"}
{"level":"info","ts":"2023-06-02 17:23:34.378","caller":"dfget/dfget.go:55","msg":"init success and start to download","url":"oss://bucket/server_bin/master/output/gameserver/gameserver"}
{"level":"info","ts":"2023-06-02 17:23:42.645","caller":"dfget/dfget.go:121","msg":"download from daemon success, length: 1005517272 bytes cost: 8269 ms","url":"oss://bucket/server_bin/master/output/gameserver/gameserver"}
{"level":"info","ts":"2023-06-02 17:23:42.645","caller":"dependency/dependency.go:127","msg":"do 1 monitor finalizer"}
{"level":"info","ts":"2023-06-02 17:23:42.645","caller":"cmd/root.go:111","msg":"download success: true cost: 11393 ms","url":"oss://bucket/server_bin/master/output/gameserver/gameserver"}
{"level":"info","ts":"2023-06-02 17:23:42.732","caller":"dfget/dfget.go:121","msg":"download from daemon success, length: 1005517272 bytes cost: 8354 ms","url":"oss://bucket/server_bin/master/output/gameserver/gameserver"}
{"level":"info","ts":"2023-06-02 17:23:42.732","caller":"dependency/dependency.go:127","msg":"do 1 monitor finalizer"}
{"level":"info","ts":"2023-06-02 17:23:42.732","caller":"cmd/root.go:111","msg":"download success: true cost: 11478 ms","url":"oss://bucket/server_bin/master/output/gameserver/gameserver"}

grpc.log

{"level":"info","ts":"2023-06-02 17:23:31.257","caller":"grpclog/grpclog.go:37","msg":"[core][Channel #1] Channel created"}
{"level":"info","ts":"2023-06-02 17:23:31.257","caller":"grpclog/grpclog.go:37","msg":"[core][Channel #1] original dial target is: "unix:///var/run/dfdaemon.sock""}
{"level":"info","ts":"2023-06-02 17:23:31.257","caller":"grpclog/grpclog.go:37","msg":"[core][Channel #1] parsed dial target is: {Scheme:unix Authority: Endpoint:var/run/dfdaemon.sock URL:{Scheme:unix Opaque: User: Host: Path:/var/run/dfdaemon.sock RawPath: OmitHost:false ForceQuery:false RawQuery: Fragment: RawFragment:}}"}
{"level":"info","ts":"2023-06-02 17:23:31.257","caller":"grpclog/grpclog.go:37","msg":"[core][Channel #1] Channel authority set to "localhost""}
{"level":"info","ts":"2023-06-02 17:23:31.257","caller":"grpclog/grpclog.go:37","msg":"[core][Channel #1] Channel created"}
{"level":"info","ts":"2023-06-02 17:23:31.257","caller":"grpclog/grpclog.go:37","msg":"[core][Channel #1] original dial target is: "unix:///var/run/dfdaemon.sock""}
{"level":"info","ts":"2023-06-02 17:23:31.257","caller":"grpclog/grpclog.go:37","msg":"[core][Channel #1] parsed dial target is: {Scheme:unix Authority: Endpoint:var/run/dfdaemon.sock URL:{Scheme:unix Opaque: User: Host: Path:/var/run/dfdaemon.sock RawPath: OmitHost:false ForceQuery:false RawQuery: Fragment: RawFragment:}}"}
{"level":"info","ts":"2023-06-02 17:23:31.257","caller":"grpclog/grpclog.go:37","msg":"[core][Channel #1] Channel authority set to "localhost""}
{"level":"info","ts":"2023-06-02 17:23:31.257","caller":"grpclog/grpclog.go:37","msg":"[core][Channel #1] Resolver state updated: {\n "Addresses": [\n {\n "Addr": "/var/run/dfdaemon.sock",\n "ServerName": "",\n "Attributes": {},\n "BalancerAttributes": null,\n "Type": 0,\n "Metadata": null\n }\n ],\n "ServiceConfig": null,\n "Attributes": null\n} (resolver returned new addresses)"}
{"level":"info","ts":"2023-06-02 17:23:31.257","caller":"grpclog/grpclog.go:37","msg":"[core][Channel #1] Channel switches to new LB policy "pick_first""}
{"level":"info","ts":"2023-06-02 17:23:31.258","caller":"grpclog/grpclog.go:37","msg":"[core][Channel #1 SubChannel #2] Subchannel created"}
{"level":"info","ts":"2023-06-02 17:23:31.258","caller":"grpclog/grpclog.go:37","msg":"[core]blockingPicker: the picked transport is not ready, loop back to repick"}
{"level":"info","ts":"2023-06-02 17:23:31.258","caller":"grpclog/grpclog.go:37","msg":"[core][Channel #1 SubChannel #2] Subchannel Connectivity change to CONNECTING"}
{"level":"info","ts":"2023-06-02 17:23:31.258","caller":"grpclog/grpclog.go:37","msg":"[core][Channel #1 SubChannel #2] Subchannel picks a new address "/var/run/dfdaemon.sock" to connect"}
{"level":"warn","ts":"2023-06-02 17:23:31.258","caller":"grpclog/grpclog.go:46","msg":"[core][Channel #1 SubChannel #2] grpc: addrConn.createTransport failed to connect to {\n "Addr": "/var/run/dfdaemon.sock",\n "ServerName": "localhost",\n "Attributes": {},\n "BalancerAttributes": null,\n "Type": 0,\n "Metadata": null\n}. Err: connection error: desc = "transport: Error while dialing dial unix /var/run/dfdaemon.sock: connect: connection refused"","stacktrace":"google.golang.org/grpc/internal/grpclog.WarningDepth\n\t/home/runner/go/pkg/mod/google.golang.org/[email protected]/internal/grpclog/grpclog.go:46\ngoogle.golang.org/grpc/grpclog.(*componentData).WarningDepth\n\t/home/runner/go/pkg/mod/google.golang.org/[email protected]/grpclog/component.go:41\ngoogle.golang.org/grpc/internal/channelz.AddTraceEvent\n\t/home/runner/go/pkg/mod/google.golang.org/[email protected]/internal/channelz/funcs.go:342\ngoogle.golang.org/grpc/internal/channelz.Warningf\n\t/home/runner/go/pkg/mod/google.golang.org/[email protected]/internal/channelz/logging.go:59\ngoogle.golang.org/grpc.(*addrConn).createTransport\n\t/home/runner/go/pkg/mod/google.golang.org/[email protected]/clientconn.go:1273\ngoogle.golang.org/grpc.(*addrConn).tryAllAddrs\n\t/home/runner/go/pkg/mod/google.golang.org/[email protected]/clientconn.go:1213\ngoogle.golang.org/grpc.(*addrConn).resetTransport\n\t/home/runner/go/pkg/mod/google.golang.org/[email protected]/clientconn.go:1148\ngoogle.golang.org/grpc.(*addrConn).connect\n\t/home/runner/go/pkg/mod/google.golang.org/[email protected]/clientconn.go:803"}
{"level":"info","ts":"2023-06-02 17:23:31.258","caller":"grpclog/grpclog.go:37","msg":"[core][Channel #1 SubChannel #2] Subchannel Connectivity change to TRANSIENT_FAILURE"}
{"level":"info","ts":"2023-06-02 17:23:31.258","caller":"grpclog/grpclog.go:37","msg":"[core][Channel #1] Channel Connectivity change to CONNECTING"}
{"level":"info","ts":"2023-06-02 17:23:31.258","caller":"grpclog/grpclog.go:37","msg":"[core][Channel #1] Channel Connectivity change to TRANSIENT_FAILURE"}
{"level":"info","ts":"2023-06-02 17:23:31.258","caller":"grpclog/grpclog.go:37","msg":"[core][Channel #1] Resolver state updated: {\n "Addresses": [\n {\n "Addr": "/var/run/dfdaemon.sock",\n "ServerName": "",\n "Attributes": {},\n "BalancerAttributes": null,\n "Type": 0,\n "Metadata": null\n }\n ],\n "ServiceConfig": null,\n "Attributes": null\n} (resolver returned new addresses)"}
{"level":"info","ts":"2023-06-02 17:23:31.258","caller":"grpclog/grpclog.go:37","msg":"[core][Channel #1] Channel switches to new LB policy "pick_first""}
{"level":"info","ts":"2023-06-02 17:23:31.258","caller":"grpclog/grpclog.go:37","msg":"[core][Channel #1 SubChannel #2] Subchannel created"}
{"level":"info","ts":"2023-06-02 17:23:31.258","caller":"grpclog/grpclog.go:37","msg":"[core]blockingPicker: the picked transport is not ready, loop back to repick"}
{"level":"info","ts":"2023-06-02 17:23:31.258","caller":"grpclog/grpclog.go:37","msg":"[core][Channel #1 SubChannel #2] Subchannel Connectivity change to CONNECTING"}
{"level":"info","ts":"2023-06-02 17:23:31.259","caller":"grpclog/grpclog.go:37","msg":"[core][Channel #1 SubChannel #2] Subchannel picks a new address "/var/run/dfdaemon.sock" to connect"}
{"level":"warn","ts":"2023-06-02 17:23:31.259","caller":"grpclog/grpclog.go:46","msg":"[core][Channel #1 SubChannel #2] grpc: addrConn.createTransport failed to connect to {\n "Addr": "/var/run/dfdaemon.sock",\n "ServerName": "localhost",\n "Attributes": {},\n "BalancerAttributes": null,\n "Type": 0,\n "Metadata": null\n}. Err: connection error: desc = "transport: Error while dialing dial unix /var/run/dfdaemon.sock: connect: connection refused"","stacktrace":"google.golang.org/grpc/internal/grpclog.WarningDepth\n\t/home/runner/go/pkg/mod/google.golang.org/[email protected]/internal/grpclog/grpclog.go:46\ngoogle.golang.org/grpc/grpclog.(*componentData).WarningDepth\n\t/home/runner/go/pkg/mod/google.golang.org/[email protected]/grpclog/component.go:41\ngoogle.golang.org/grpc/internal/channelz.AddTraceEvent\n\t/home/runner/go/pkg/mod/google.golang.org/[email protected]/internal/channelz/funcs.go:342\ngoogle.golang.org/grpc/internal/channelz.Warningf\n\t/home/runner/go/pkg/mod/google.golang.org/[email protected]/internal/channelz/logging.go:59\ngoogle.golang.org/grpc.(*addrConn).createTransport\n\t/home/runner/go/pkg/mod/google.golang.org/[email protected]/clientconn.go:1273\ngoogle.golang.org/grpc.(*addrConn).tryAllAddrs\n\t/home/runner/go/pkg/mod/google.golang.org/[email protected]/clientconn.go:1213\ngoogle.golang.org/grpc.(*addrConn).resetTransport\n\t/home/runner/go/pkg/mod/google.golang.org/[email protected]/clientconn.go:1148\ngoogle.golang.org/grpc.(*addrConn).connect\n\t/home/runner/go/pkg/mod/google.golang.org/[email protected]/clientconn.go:803"}
{"level":"info","ts":"2023-06-02 17:23:31.259","caller":"grpclog/grpclog.go:37","msg":"[core][Channel #1 SubChannel #2] Subchannel Connectivity change to TRANSIENT_FAILURE"}
{"level":"info","ts":"2023-06-02 17:23:31.259","caller":"grpclog/grpclog.go:37","msg":"[core][Channel #1] Channel Connectivity change to CONNECTING"}
{"level":"info","ts":"2023-06-02 17:23:31.259","caller":"grpclog/grpclog.go:37","msg":"[core][Channel #1] Channel Connectivity change to TRANSIENT_FAILURE"}
{"level":"info","ts":"2023-06-02 17:23:32.259","caller":"grpclog/grpclog.go:37","msg":"[core][Channel #1 SubChannel #2] Subchannel Connectivity change to IDLE"}
{"level":"info","ts":"2023-06-02 17:23:32.259","caller":"grpclog/grpclog.go:37","msg":"[core][Channel #1] Channel Connectivity change to IDLE"}
{"level":"info","ts":"2023-06-02 17:23:32.260","caller":"grpclog/grpclog.go:37","msg":"[core][Channel #1 SubChannel #2] Subchannel Connectivity change to IDLE"}
{"level":"info","ts":"2023-06-02 17:23:32.260","caller":"grpclog/grpclog.go:37","msg":"[core][Channel #1] Channel Connectivity change to IDLE"}
{"level":"info","ts":"2023-06-02 17:23:32.261","caller":"grpclog/grpclog.go:37","msg":"[core][Channel #1 SubChannel #2] Subchannel Connectivity change to CONNECTING"}
{"level":"info","ts":"2023-06-02 17:23:32.261","caller":"grpclog/grpclog.go:37","msg":"[core][Channel #1 SubChannel #2] Subchannel picks a new address "/var/run/dfdaemon.sock" to connect"}
{"level":"warn","ts":"2023-06-02 17:23:32.261","caller":"grpclog/grpclog.go:46","msg":"[core][Channel #1 SubChannel #2] grpc: addrConn.createTransport failed to connect to {\n "Addr": "/var/run/dfdaemon.sock",\n "ServerName": "localhost",\n "Attributes": {},\n "BalancerAttributes": null,\n "Type": 0,\n "Metadata": null\n}. Err: connection error: desc = "transport: Error while dialing dial unix /var/run/dfdaemon.sock: connect: connection refused"","stacktrace":"google.golang.org/grpc/internal/grpclog.WarningDepth\n\t/home/runner/go/pkg/mod/google.golang.org/[email protected]/internal/grpclog/grpclog.go:46\ngoogle.golang.org/grpc/grpclog.(*componentData).WarningDepth\n\t/home/runner/go/pkg/mod/google.golang.org/[email protected]/grpclog/component.go:41\ngoogle.golang.org/grpc/internal/channelz.AddTraceEvent\n\t/home/runner/go/pkg/mod/google.golang.org/[email protected]/internal/channelz/funcs.go:342\ngoogle.golang.org/grpc/internal/channelz.Warningf\n\t/home/runner/go/pkg/mod/google.golang.org/[email protected]/internal/channelz/logging.go:59\ngoogle.golang.org/grpc.(*addrConn).createTransport\n\t/home/runner/go/pkg/mod/google.golang.org/[email protected]/clientconn.go:1273\ngoogle.golang.org/grpc.(*addrConn).tryAllAddrs\n\t/home/runner/go/pkg/mod/google.golang.org/[email protected]/clientconn.go:1213\ngoogle.golang.org/grpc.(*addrConn).resetTransport\n\t/home/runner/go/pkg/mod/google.golang.org/[email protected]/clientconn.go:1148\ngoogle.golang.org/grpc.(*addrConn).connect\n\t/home/runner/go/pkg/mod/google.golang.org/[email protected]/clientconn.go:803"}
{"level":"info","ts":"2023-06-02 17:23:32.261","caller":"grpclog/grpclog.go:37","msg":"[core][Channel #1 SubChannel #2] Subchannel Connectivity change to TRANSIENT_FAILURE"}
{"level":"info","ts":"2023-06-02 17:23:32.261","caller":"grpclog/grpclog.go:37","msg":"[core][Channel #1] Channel Connectivity change to CONNECTING"}
{"level":"info","ts":"2023-06-02 17:23:32.261","caller":"grpclog/grpclog.go:37","msg":"[core][Channel #1] Channel Connectivity change to TRANSIENT_FAILURE"}
{"level":"warn","ts":"2023-06-02 17:23:32.261","caller":"zap/client_interceptors.go:52","msg":"finished client unary call","system":"grpc","span.kind":"client","grpc.service":"dfdaemon.Daemon","grpc.method":"CheckHealth","error":"rpc error: code = Unavailable desc = connection error: desc = "transport: Error while dialing dial unix /var/run/dfdaemon.sock: connect: connection refused"","grpc.code":"Unavailable","grpc.time_ms":1003.593,"stacktrace":"github.com/grpc-ecosystem/go-grpc-middleware/logging/zap.logFinalClientLine\n\t/home/runner/go/pkg/mod/github.com/grpc-ecosystem/[email protected]/logging/zap/client_interceptors.go:52\ngithub.com/grpc-ecosystem/go-grpc-middleware/logging/zap.UnaryClientInterceptor.func1\n\t/home/runner/go/pkg/mod/github.com/grpc-ecosystem/[email protected]/logging/zap/client_interceptors.go:30\ngithub.com/grpc-ecosystem/go-grpc-middleware.ChainUnaryClient.func1.1.1\n\t/home/runner/go/pkg/mod/github.com/grpc-ecosystem/[email protected]/chain.go:72\ngithub.com/grpc-ecosystem/go-grpc-prometheus.(*ClientMetrics).UnaryClientInterceptor.func1\n\t/home/runner/go/pkg/mod/github.com/grpc-ecosystem/[email protected]/client_metrics.go:112\ngithub.com/grpc-ecosystem/go-grpc-middleware.ChainUnaryClient.func1.1.1\n\t/home/runner/go/pkg/mod/github.com/grpc-ecosystem/[email protected]/chain.go:72\ngo.opentelemetry.io/contrib/instrumentation/google.golang.org/grpc/otelgrpc.UnaryClientInterceptor.func1\n\t/home/runner/go/pkg/mod/go.opentelemetry.io/contrib/instrumentation/google.golang.org/grpc/[email protected]/interceptor.go:105\ngithub.com/grpc-ecosystem/go-grpc-middleware.ChainUnaryClient.func1.1.1\n\t/home/runner/go/pkg/mod/github.com/grpc-ecosystem/[email protected]/chain.go:72\nd7y.io/dragonfly/v2/pkg/rpc.ConvertErrorUnaryClientInterceptor\n\t/home/runner/work/Dragonfly2/Dragonfly2/pkg/rpc/interceptor.go:128\ngithub.com/grpc-ecosystem/go-grpc-middleware.ChainUnaryClient.func1.1.1\n\t/home/runner/go/pkg/mod/github.com/grpc-ecosystem/[email protected]/chain.go:72\ngithub.com/grpc-ecosystem/go-grpc-middleware.ChainUnaryClient.func1\n\t/home/runner/go/pkg/mod/github.com/grpc-ecosystem/[email protected]/chain.go:81\ngoogle.golang.org/grpc.(*ClientConn).Invoke\n\t/home/runner/go/pkg/mod/google.golang.org/[email protected]/call.go:35\nd7y.io/api/pkg/apis/dfdaemon/v1.(*daemonClient).CheckHealth\n\t/home/runner/go/pkg/mod/d7y.io/[email protected]/pkg/apis/dfdaemon/v1/dfdaemon.pb.go:973\nd7y.io/dragonfly/v2/pkg/rpc/dfdaemon/client.(*client).CheckHealth\n\t/home/runner/work/Dragonfly2/Dragonfly2/pkg/rpc/dfdaemon/client/client.go:193\nd7y.io/dragonfly/v2/cmd/dfget/cmd.checkAndSpawnDaemon\n\t/home/runner/work/Dragonfly2/Dragonfly2/cmd/dfget/cmd/root.go:254\nd7y.io/dragonfly/v2/cmd/dfget/cmd.runDfget\n\t/home/runner/work/Dragonfly2/Dragonfly2/cmd/dfget/cmd/root.go:235\nd7y.io/dragonfly/v2/cmd/dfget/cmd.glob..func2\n\t/home/runner/work/Dragonfly2/Dragonfly2/cmd/dfget/cmd/root.go:102\ngithub.com/spf13/cobra.(*Command).execute\n\t/home/runner/go/pkg/mod/github.com/spf13/[email protected]/command.go:916\ngithub.com/spf13/cobra.(*Command).ExecuteC\n\t/home/runner/go/pkg/mod/github.com/spf13/[email protected]/command.go:1044\ngithub.com/spf13/cobra.(*Command).Execute\n\t/home/runner/go/pkg/mod/github.com/spf13/[email protected]/command.go:968\nd7y.io/dragonfly/v2/cmd/dfget/cmd.Execute\n\t/home/runner/work/Dragonfly2/Dragonfly2/cmd/dfget/cmd/root.go:120\nmain.main\n\t/home/runner/work/Dragonfly2/Dragonfly2/cmd/dfget/main.go:26\nruntime.main\n\t/opt/hostedtoolcache/go/1.19.3/x64/src/runtime/proc.go:250"}
{"level":"warn","ts":"2023-06-02 17:23:32.260","caller":"zap/client_interceptors.go:52","msg":"finished client unary call","system":"grpc","span.kind":"client","grpc.service":"dfdaemon.Daemon","grpc.method":"CheckHealth","error":"rpc error: code = Unavailable desc = connection error: desc = "transport: Error while dialing dial unix /var/run/dfdaemon.sock: connect: connection refused"","grpc.code":"Unavailable","grpc.time_ms":1001.495,"stacktrace":"github.com/grpc-ecosystem/go-grpc-middleware/logging/zap.logFinalClientLine\n\t/home/runner/go/pkg/mod/github.com/grpc-ecosystem/[email protected]/logging/zap/client_interceptors.go:52\ngithub.com/grpc-ecosystem/go-grpc-middleware/logging/zap.UnaryClientInterceptor.func1\n\t/home/runner/go/pkg/mod/github.com/grpc-ecosystem/[email protected]/logging/zap/client_interceptors.go:30\ngithub.com/grpc-ecosystem/go-grpc-middleware.ChainUnaryClient.func1.1.1\n\t/home/runner/go/pkg/mod/github.com/grpc-ecosystem/[email protected]/chain.go:72\ngithub.com/grpc-ecosystem/go-grpc-prometheus.(*ClientMetrics).UnaryClientInterceptor.func1\n\t/home/runner/go/pkg/mod/github.com/grpc-ecosystem/[email protected]/client_metrics.go:112\ngithub.com/grpc-ecosystem/go-grpc-middleware.ChainUnaryClient.func1.1.1\n\t/home/runner/go/pkg/mod/github.com/grpc-ecosystem/[email protected]/chain.go:72\ngo.opentelemetry.io/contrib/instrumentation/google.golang.org/grpc/otelgrpc.UnaryClientInterceptor.func1\n\t/home/runner/go/pkg/mod/go.opentelemetry.io/contrib/instrumentation/google.golang.org/grpc/[email protected]/interceptor.go:105\ngithub.com/grpc-ecosystem/go-grpc-middleware.ChainUnaryClient.func1.1.1\n\t/home/runner/go/pkg/mod/github.com/grpc-ecosystem/[email protected]/chain.go:72\nd7y.io/dragonfly/v2/pkg/rpc.ConvertErrorUnaryClientInterceptor\n\t/home/runner/work/Dragonfly2/Dragonfly2/pkg/rpc/interceptor.go:128\ngithub.com/grpc-ecosystem/go-grpc-middleware.ChainUnaryClient.func1.1.1\n\t/home/runner/go/pkg/mod/github.com/grpc-ecosystem/[email protected]/chain.go:72\ngithub.com/grpc-ecosystem/go-grpc-middleware.ChainUnaryClient.func1\n\t/home/runner/go/pkg/mod/github.com/grpc-ecosystem/[email protected]/chain.go:81\ngoogle.golang.org/grpc.(*ClientConn).Invoke\n\t/home/runner/go/pkg/mod/google.golang.org/[email protected]/call.go:35\nd7y.io/api/pkg/apis/dfdaemon/v1.(*daemonClient).CheckHealth\n\t/home/runner/go/pkg/mod/d7y.io/[email protected]/pkg/apis/dfdaemon/v1/dfdaemon.pb.go:973\nd7y.io/dragonfly/v2/pkg/rpc/dfdaemon/client.(*client).CheckHealth\n\t/home/runner/work/Dragonfly2/Dragonfly2/pkg/rpc/dfdaemon/client/client.go:193\nd7y.io/dragonfly/v2/cmd/dfget/cmd.checkAndSpawnDaemon\n\t/home/runner/work/Dragonfly2/Dragonfly2/cmd/dfget/cmd/root.go:254\nd7y.io/dragonfly/v2/cmd/dfget/cmd.runDfget\n\t/home/runner/work/Dragonfly2/Dragonfly2/cmd/dfget/cmd/root.go:235\nd7y.io/dragonfly/v2/cmd/dfget/cmd.glob..func2\n\t/home/runner/work/Dragonfly2/Dragonfly2/cmd/dfget/cmd/root.go:102\ngithub.com/spf13/cobra.(*Command).execute\n\t/home/runner/go/pkg/mod/github.com/spf13/[email protected]/command.go:916\ngithub.com/spf13/cobra.(*Command).ExecuteC\n\t/home/runner/go/pkg/mod/github.com/spf13/[email protected]/command.go:1044\ngithub.com/spf13/cobra.(*Command).Execute\n\t/home/runner/go/pkg/mod/github.com/spf13/[email protected]/command.go:968\nd7y.io/dragonfly/v2/cmd/dfget/cmd.Execute\n\t/home/runner/work/Dragonfly2/Dragonfly2/cmd/dfget/cmd/root.go:120\nmain.main\n\t/home/runner/work/Dragonfly2/Dragonfly2/cmd/dfget/main.go:26\nruntime.main\n\t/opt/hostedtoolcache/go/1.19.3/x64/src/runtime/proc.go:250"}
{"level":"warn","ts":"2023-06-02 17:23:33.270","caller":"zap/client_interceptors.go:52","msg":"finished client unary call","system":"grpc","span.kind":"client","grpc.service":"dfdaemon.Daemon","grpc.method":"CheckHealth","error":"rpc error: code = Unavailable desc = connection error: desc = "transport: Error while dialing dial unix /var/run/dfdaemon.sock: connect: connection refused"","grpc.code":"Unavailable","grpc.time_ms":1000.879,"stacktrace":"github.com/grpc-ecosystem/go-grpc-middleware/logging/zap.logFinalClientLine\n\t/home/runner/go/pkg/mod/github.com/grpc-ecosystem/[email protected]/logging/zap/client_interceptors.go:52\ngithub.com/grpc-ecosystem/go-grpc-middleware/logging/zap.UnaryClientInterceptor.func1\n\t/home/runner/go/pkg/mod/github.com/grpc-ecosystem/[email protected]/logging/zap/client_interceptors.go:30\ngithub.com/grpc-ecosystem/go-grpc-middleware.ChainUnaryClient.func1.1.1\n\t/home/runner/go/pkg/mod/github.com/grpc-ecosystem/[email protected]/chain.go:72\ngithub.com/grpc-ecosystem/go-grpc-prometheus.(*ClientMetrics).UnaryClientInterceptor.func1\n\t/home/runner/go/pkg/mod/github.com/grpc-ecosystem/[email protected]/client_metrics.go:112\ngithub.com/grpc-ecosystem/go-grpc-middleware.ChainUnaryClient.func1.1.1\n\t/home/runner/go/pkg/mod/github.com/grpc-ecosystem/[email protected]/chain.go:72\ngo.opentelemetry.io/contrib/instrumentation/google.golang.org/grpc/otelgrpc.UnaryClientInterceptor.func1\n\t/home/runner/go/pkg/mod/go.opentelemetry.io/contrib/instrumentation/google.golang.org/grpc/[email protected]/interceptor.go:105\ngithub.com/grpc-ecosystem/go-grpc-middleware.ChainUnaryClient.func1.1.1\n\t/home/runner/go/pkg/mod/github.com/grpc-ecosystem/[email protected]/chain.go:72\nd7y.io/dragonfly/v2/pkg/rpc.ConvertErrorUnaryClientInterceptor\n\t/home/runner/work/Dragonfly2/Dragonfly2/pkg/rpc/interceptor.go:128\ngithub.com/grpc-ecosystem/go-grpc-middleware.ChainUnaryClient.func1.1.1\n\t/home/runner/go/pkg/mod/github.com/grpc-ecosystem/[email protected]/chain.go:72\ngithub.com/grpc-ecosystem/go-grpc-middleware.ChainUnaryClient.func1\n\t/home/runner/go/pkg/mod/github.com/grpc-ecosystem/[email protected]/chain.go:81\ngoogle.golang.org/grpc.(*ClientConn).Invoke\n\t/home/runner/go/pkg/mod/google.golang.org/[email protected]/call.go:35\nd7y.io/api/pkg/apis/dfdaemon/v1.(*daemonClient).CheckHealth\n\t/home/runner/go/pkg/mod/d7y.io/[email protected]/pkg/apis/dfdaemon/v1/dfdaemon.pb.go:973\nd7y.io/dragonfly/v2/pkg/rpc/dfdaemon/client.(*client).CheckHealth\n\t/home/runner/work/Dragonfly2/Dragonfly2/pkg/rpc/dfdaemon/client/client.go:193\nd7y.io/dragonfly/v2/cmd/dfget/cmd.checkAndSpawnDaemon\n\t/home/runner/work/Dragonfly2/Dragonfly2/cmd/dfget/cmd/root.go:271\nd7y.io/dragonfly/v2/cmd/dfget/cmd.runDfget\n\t/home/runner/work/Dragonfly2/Dragonfly2/cmd/dfget/cmd/root.go:235\nd7y.io/dragonfly/v2/cmd/dfget/cmd.glob..func2\n\t/home/runner/work/Dragonfly2/Dragonfly2/cmd/dfget/cmd/root.go:102\ngithub.com/spf13/cobra.(*Command).execute\n\t/home/runner/go/pkg/mod/github.com/spf13/[email protected]/command.go:916\ngithub.com/spf13/cobra.(*Command).ExecuteC\n\t/home/runner/go/pkg/mod/github.com/spf13/[email protected]/command.go:1044\ngithub.com/spf13/cobra.(*Command).Execute\n\t/home/runner/go/pkg/mod/github.com/spf13/[email protected]/command.go:968\nd7y.io/dragonfly/v2/cmd/dfget/cmd.Execute\n\t/home/runner/work/Dragonfly2/Dragonfly2/cmd/dfget/cmd/root.go:120\nmain.main\n\t/home/runner/work/Dragonfly2/Dragonfly2/cmd/dfget/main.go:26\nruntime.main\n\t/opt/hostedtoolcache/go/1.19.3/x64/src/runtime/proc.go:250"}
{"level":"info","ts":"2023-06-02 17:23:34.007","caller":"grpclog/grpclog.go:37","msg":"[core][Channel #1 SubChannel #2] Subchannel Connectivity change to IDLE"}
{"level":"info","ts":"2023-06-02 17:23:34.007","caller":"grpclog/grpclog.go:37","msg":"[core][Channel #1] Channel Connectivity change to IDLE"}
{"level":"info","ts":"2023-06-02 17:23:34.374","caller":"grpclog/grpclog.go:37","msg":"[core][Channel #1 SubChannel #2] Subchannel Connectivity change to CONNECTING"}
{"level":"info","ts":"2023-06-02 17:23:34.374","caller":"grpclog/grpclog.go:37","msg":"[core][Channel #1 SubChannel #2] Subchannel picks a new address "/var/run/dfdaemon.sock" to connect"}
{"level":"info","ts":"2023-06-02 17:23:34.374","caller":"grpclog/grpclog.go:37","msg":"[core][Channel #1] Channel Connectivity change to CONNECTING"}
{"level":"info","ts":"2023-06-02 17:23:34.374","caller":"grpclog/grpclog.go:37","msg":"[core][Channel #1 SubChannel #2] Subchannel Connectivity change to READY"}
{"level":"info","ts":"2023-06-02 17:23:34.374","caller":"grpclog/grpclog.go:37","msg":"[core][Channel #1] Channel Connectivity change to READY"}
{"level":"info","ts":"2023-06-02 17:23:34.376","caller":"grpclog/grpclog.go:37","msg":"[core][Channel #1 SubChannel #2] Subchannel Connectivity change to CONNECTING"}
{"level":"info","ts":"2023-06-02 17:23:34.376","caller":"grpclog/grpclog.go:37","msg":"[core][Channel #1 SubChannel #2] Subchannel picks a new address "/var/run/dfdaemon.sock" to connect"}
{"level":"info","ts":"2023-06-02 17:23:34.376","caller":"grpclog/grpclog.go:37","msg":"[core][Channel #1] Channel Connectivity change to CONNECTING"}
{"level":"info","ts":"2023-06-02 17:23:34.377","caller":"grpclog/grpclog.go:37","msg":"[core][Channel #1 SubChannel #2] Subchannel Connectivity change to READY"}
{"level":"info","ts":"2023-06-02 17:23:34.377","caller":"grpclog/grpclog.go:37","msg":"[core][Channel #1] Channel Connectivity change to READY"}

@sssudada
Copy link
Author

@jim3ma 请问下这个BUG有进展吗?

@jim3ma
Copy link
Member

jim3ma commented Jun 15, 2023

@jim3ma 请问下这个BUG有进展吗?

调研中,还请麻烦等待一下,这周可能没时间看具体问题,下周会同步进展。

@jim3ma
Copy link
Member

jim3ma commented Jun 15, 2023

目前无法复现这个问题,不过并发下载的确是可能出现读写顺序的问题,考虑加个锁同步一下

@sssudada
Copy link
Author

目前无法复现这个问题,不过并发下载的确是可能出现读写顺序的问题,考虑加个锁同步一下

我这边必现的方式:先清空本地缓存,然后关闭dfget服务,然后下载一个1G以上的大文件(相同的命令在一台机器开2个窗口各执行一次,等待执行完毕后,下载到本地的文件大小为0)。

@jim3ma
Copy link
Member

jim3ma commented Jun 15, 2023

麻烦复现后,看一下 /var/lib/dragonfly 目录下蜻蜓的数据文件大小,进入目录最里层,应该有 metdata 和 data 两个文件,看看这个两个文件的大小

@jim3ma
Copy link
Member

jim3ma commented Jun 15, 2023

#2465
这个 PR 在写文件的时候加排它锁,解决可能的潜在冲突,理论上能解决这个问题。
你可以 pull 一下这个分支的代码,然后构建 dfget 测试一下,构建命令是 make build-dfget

@YangZhigang177
Copy link

是因为这个原因吗
while dialing dial unix /var/run/dfdaemon.sock: connect: connection

@jim3ma
Copy link
Member

jim3ma commented Oct 19, 2023

是因为这个原因吗 while dialing dial unix /var/run/dfdaemon.sock: connect: connection

有更多的日志么?

@YangZhigang177
Copy link

是因为这个原因吗 while dialing dial unix /var/run/dfdaemon.sock: connect: connection

有更多的日志么?

我这边解决了,估计不是同一个问题

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

No branches or pull requests

3 participants