listen and serve for metrics: listen tcp :9567: bind: address already in use

I added logger.Info("trying to serve metrics") here, to make sure:

https://github.com/juicedata/juicefs/blob/4f0efe36ab98c866374e9c760e977d3561e721af/cmd/mount.go#L221-L226

root@sana ~# ./juicefs -v mount -d localhost /mnt/
2021/03/06 12:57:50.969651 juicefs[69241] <INFO>: Meta address: redis://localhost
2021/03/06 12:57:50.971758 juicefs[69241] <DEBUG>: session is is 64
2021/03/06 12:57:50.972142 juicefs[69241] <DEBUG>: Creating scw storage at endpoint xxx
2021/03/06 12:57:50.972288 juicefs[69241] <INFO>: Data use scw://xxx/xxx/
2021/03/06 12:57:50.972360 juicefs[69241] <INFO>: Cache: /var/jfsCache/faa5166d-1994-4cda-b5c3-835065678353 capacity: 1024 MB
2021/03/06 12:57:50.972619 juicefs[69241] <DEBUG>: Scan /var/jfsCache/faa5166d-1994-4cda-b5c3-835065678353/raw to find cached blocks
2021/03/06 12:57:50.972624 juicefs[69241] <DEBUG>: Scan /var/jfsCache/faa5166d-1994-4cda-b5c3-835065678353/rawstaging to find staging blocks
2021/03/06 12:57:50.972886 juicefs[69241] <INFO>: Mounting volume seedbox at /mnt/ ...
2021/03/06 12:57:50.972963 juicefs[69241] <INFO>: trying to serve metrics
2021/03/06 12:57:50.978629 juicefs[69241] <DEBUG>: Found 686 cached blocks (1057331310 bytes) in 6.078094ms
2021/03/06 12:57:51.125141 juicefs[69241] <INFO>: OK, seedbox is ready at /mnt/

So far so good, but in syslog:

Mar 06 12:55:01 sana ./juicefs[68710]: juicefs[68710] <INFO>: trying to serve metrics
Mar 06 12:55:01 sana ./juicefs[68710]: juicefs[68710] <DEBUG>: Found 686 cached blocks (1057331310 bytes) in 5.608231ms
Mar 06 12:55:01 sana ./juicefs[68731]: juicefs[68731] <ERROR>: listen and serve for metrics: listen tcp :9567: bind: address already in use
Mar 06 12:55:01 sana ./juicefs[68751]: juicefs[68751] <INFO>: trying to serve metrics
Mar 06 12:55:01 sana ./juicefs[68751]: juicefs[68751] <ERROR>: listen and serve for metrics: listen tcp :9567: bind: address already in use
Mar 06 12:55:02 sana ./juicefs[68751]: juicefs[68751] <DEBUG>: Found 686 cached blocks (1057331310 bytes) in 6.154819ms
Mar 06 12:55:02 sana ./juicefs[68710]: juicefs[68710] <INFO>: OK, seedbox is ready at /mnt/

<ERROR>: listen and serve for metrics: listen tcp :9567: bind: address already in use.

Not sure why I get the error twice.

root@sana ~# curl 127.0.0.1:9567/metrics
curl: (7) Failed to connect to 127.0.0.1 port 9567: Connection refused

I can't find anything listening, so I don't know why it says so.

root@sana ~# netstat --tcp --udp --listening --program | grep 9567
root@sana ~# lsof -ti:9567
root@sana ~# netstat -tanl | grep 9567
root@sana ~# netstat -ano -p tcp | grep 9567
root@sana ~# netstat -tlnp | grep 9567

I can also run a little program with http.ListenAndServe(":9567", nil) and it will work.

But sometimes I will get the error once and it will still work:

Mar 06 13:02:37 sana ./juicefs[69941]: juicefs[69941] <INFO>: OK, seedbox is ready at /mnt/
Mar 06 13:02:37 sana ./juicefs[69957]: juicefs[69957] <ERROR>: listen and serve for metrics: listen tcp :9567: bind: address already in use
^C⏎
root@sana ~# netstat --tcp --udp --listening --program | grep 9567
tcp6       0      0 [::]:9567               [::]:*                  LISTEN      69981/./juicefs
root@sana ~# curl 127.0.0.1:9567/metrics
# HELP go_build_info Build information about the main Go module.
# TYPE go_build_info gauge
[...]

Sometimes it just works, but some metrics don't update. Not sure what is happening.

Environment:

JuiceFS version: juicefs version 0.11.0-13 (2021-03-05 4f0efe3)
OS: Debian 10
Kernel: 4.19.0-14-amd64
Redis info 5.0.3-4+deb10u2

juicedata / juicefs

listen and serve for metrics: listen tcp :9567: bind: address already in use #229