dCache / dcache

dCache - a system for storing and retrieving huge amounts of data, distributed among a large number of heterogenous server nodes, under a single virtual filesystem tree with a variety of standard access methods
https://dcache.org
284 stars 135 forks source link

NFS v4.1: fail to copy file from a host, works fine form other hosts #6487

Open DmitryLitvintsev opened 2 years ago

DmitryLitvintsev commented 2 years ago

In 7.2:

on one host:

[root@dunegpvm06 litvinse]# time cp  /pnfs/dune/persistent/users/hyliao/protodune/proton/v09_26_00/ana/PDSPProd4a_MC_1GeV_reco1_sce_datadriven_v1_nog4rw/mcproton_all.root /dev/null 
cp: overwrite ‘/dev/null’? y

real    1m22.006s
user    0m0.128s
sys 0m8.804s

saw mover on pool :+1:

[fndca3b] (p-dune-stkendca1909-8@p-dune-stkendca1909-8Domain) enstore > mover ls 
83891962 : RUNNING : 0000A4E295691AAA4773B8AD039AC40A9F4D IoMode=[READ] h={NFSv4.1/pNFS,OS=[61e827cd000200ad000085d2, seq: 0],cl=[131.225.67.158]} bytes=994836480 time/sec=2 LM=0 si={dune.persistent}

from two other hosts:

[root@dunegpvm09 litvinse]# time cp  /pnfs/dune/persistent/users/hyliao/protodune/proton/v09_26_00/ana/PDSPProd4a_MC_1GeV_reco1_sce_datadriven_v1_nog4rw/mcproton_all.root /dev/null 
cp: overwrite ‘/dev/null’? y

just stays there no data movement

No mover on pool. No transfers:

[litvinse@orbis ~]$ ssh -p 24223 enstore@fndca "\s NFS-enstore01 show transfers"  | grep -c 0000A4E295691AAA4773B8AD039AC40A9F4D 
0
DmitryLitvintsev commented 2 years ago

nfs.dump.gz

Result of

tcpdump host dunegpvm09 executed while copy was 'running' is attached. Not much there.

DmitryLitvintsev commented 2 years ago

tcp.dump.gz On a pool node I see connection to the client host:

tcp6       0    400 stkendca1909.fnal:29938 dunegpvm09.fnal.gov:768 ESTABLISHED 22610/java          

22610 is PID of the pool process. Pool has no movers associated.

On the client I see connection to the pool :

tcp        0    612 131.225.67.242:768      131.225.69.112:29938    ESTABLISHED -          

A lot of data is pumped on that connection:

dunegpvm09.fnal.gov                                                                   => stkendca1909.fnal.gov                                                                  28.2Mb  26.9Mb  26.9Mb

the tcpdump produced by this command on the client:

tcpdump -w tcp.dump host stkendca1909 

is attached.

DmitryLitvintsev commented 2 years ago

Restart of client (or pool) apparently kills that connection and file can be copied again!

This issue is affecting us badly.

kofemann commented 2 years ago

According the dump, pool returns BAD_STATEID which in in dCache language 'no such mover. Above, you have mentioned that no transfer or mover was started (that explains BAD_STATEID). The question is why client think that it can read the file without issuing LAYOUTGET :man_shrugging: . Please ensure that export files contain optionlt=flex_files`. At least this is will active kernel module that have better support.

DmitryLitvintsev commented 2 years ago
 dunegpvm09(rw,lt=nfsv4_1_files:flex_files)

is in /etc/exports

We do not know what is the cause and effect here.

An attempt to run cp on a file ends up with no interaction with pool (and the door it looks like).

This seems to be caused by this pre-existing connection :

tcp6       0    400 stkendca1909.fnal:29938 dunegpvm09.fnal.gov:768 ESTABLISHED 22610/java          

How this connection was created is unknown. Just one thing of note. The port 768 sounds familiar. Like , I have seen the same port used in the past in similar circumstances.

There is no transfer or mover associated with this connection. Yet it is there. Left behind from some previous interaction?

paulmillar commented 2 years ago

Does the NFS door's access log file provide any useful information on the client interaction?

This should contain (almost) all client interactions that led up to this problem.