Print

Print

If it helps, this is a description of the problem from a dCache pool's perspective.

level=INFO ts=2020-12-08T18:57:10.177+0100 event=org.dcache.xrootd.connection.start session=pool:dcache-doma04-01@dcache-doma04-01Domain:xrootd:810e3848 socket.remote=[2001:1458:301:cd::100:c4]:37906 socket.local=[2001:638:700:10bf::1:43]:33185
level=INFO ts=2020-12-08T18:57:10.177+0100 event=org.dcache.xrootd.request session=pool:dcache-doma04-01@dcache-doma04-01Domain:xrootd:810e3848 request=protocol response=ok
level=INFO ts=2020-12-08T18:57:10.229+0100 event=org.dcache.xrootd.request session=pool:dcache-doma04-01@dcache-doma04-01Domain:xrootd:810e3848 request=login username=fts3 capver=5 pid=31464 token=?xrd.cc=ch&xrd.tz=1&xrd.appname=fts_url_copy&xrd.info=&xrd.hostname=fts-pilot-002.cern.ch&xrd.rn=v5.0.3 response=ok sessionId=4C832115EE857E067C233352972F0B6E
level=INFO ts=2020-12-08T18:57:10.260+0100 event=org.dcache.xrootd.request session=pool:dcache-doma04-01@dcache-doma04-01Domain:xrootd:810e3848 request=open path=//escape/wp2_rucio_testbed/desy_dcache/fts-testing/dest/fts.testfile.ca2efc4c-397e-11eb-8a4c-fa163e0a532b opaque=org.dcache.uuid=04121253-9f70-4458-9544-f63e52f62ee2&[log in to unmask]&oss.asize=1048576&tpc.dlg=eoseulake.cern.ch:1094&tpc.dlgon=1&tpc.key=2d26252d64117ae85fcfbe75&tpc.lfn=//eos/eulake/tests/rucio_test/eulake_1/fts-testing/src/fts.testfile.52ae7806-0df4-11eb-9b92-fa163ef9255e_1mb&tpc.scgi=cap.msg=WCsnX2zfIcjzTKauAk/8lol79gDZzvutgxkdGiMAec2m+07UzzC73sfLw6t8iV5oj29Pr3Wx5pZDbkdhfskhk6PimoTwDSNK5yI0lm1vYBjxlaIx5nBUOVEjgOz6ikYVYsYLPsjO41OgpHuG/rbSL+QEbiraX1mN6Oze+I7ynUeDYPhaWYGVmod9nKAHTQSHF5rZwnyZaeJ7Xm739lBAjfQz26vRU8necJ+iQxwxOFg6oB6leOpa8XZMtASLYy8CT3bn7eeNJq8VbUT68X49vp9ZPdPgyPWM2t/g55PH7ia07bMdcu3JE9iv016v+nl7sDyAZEnm+kUilYngax+Nehqpds+u39WKgB/GkqXSt/+IOlHATTqjpbdDzcv12zMemF4G+117KBrBwqycibbRW4rmhSD8WJT0VddXOVbqoFEg0+/8GunroXuXxHgJMz5IhR8nqqwdlbeQ1SnNf80GRGXmn9p9bNTnAdnVjIdGPYJeQeesAbUY1uhsaFi0W7GWqC967QHL1QhQVUvSowElSxB8FHt+Lq/Iyh0cYzr1Z+Uv03Z3Aebn0srCxec+Xs+o5BLacVvkhhE6aZa/ZW3Rk5Td6mM7RtI/y26uFRml0/E=      cap.sym=IXwTCS5luchuJsEVdO71eGA8pFc=    mgm.id=0357e543 mgm.logid=cae3eb16-397e-11eb-b697-0cc47a697326      mgm.mtime=1602662857    mgm.replicahead=0       mgm.replicaindex=0      tpc.stage=placement     xrd.gsiusrpxy=/tmp/x509up_h13309331254104230041XdcXchXdcXcernXouXorganicXunitsXouXusersXcnXewp2c01XcnX817926XcnXrobotXXescapeXwp2XcernX01&tpc.spr=root&tpc.src=p05151113691315.cern.ch:1095&tpc.stage=copy&tpc.str=1&tpc.tpr=root&xrd.gsiusrpxy=/tmp/x509up_h13309331254104230041XdcXchXdcXcernXouXorganicXunitsXouXusersXcnXewp2c01XcnX817926XcnXrobotXXescapeXwp2XcernX01 mode=0 options=0x468 response=ok handle=0 flags=0 modtime=1970-01-01T00:00:00Z size=0
level=INFO ts=2020-12-08T18:57:10.314+0100 event=org.dcache.xrootd.connection.start session=pool:dcache-doma04-01@dcache-doma04-01Domain:xrootd:326cc5ce socket.remote=[2001:1458:301:cd::100:c4]:37912 socket.local=[2001:638:700:10bf::1:43]:33185
level=INFO ts=2020-12-08T18:57:10.314+0100 event=org.dcache.xrootd.request session=pool:dcache-doma04-01@dcache-doma04-01Domain:xrootd:326cc5ce request=protocol response=ok
level=INFO ts=2020-12-08T18:57:10.366+0100 event=org.dcache.xrootd.request session=pool:dcache-doma04-01@dcache-doma04-01Domain:xrootd:326cc5ce request=login username=fts3 capver=5 pid=31464 token=?xrd.cc=ch&xrd.tz=1&xrd.appname=fts_url_copy&xrd.info=&xrd.hostname=fts-pilot-002.cern.ch&xrd.rn=v5.0.3 response=ok sessionId=6761F42E87D7719DAEEA92CA5BDDC05A
level=INFO ts=2020-12-08T18:57:10.393+0100 event=org.dcache.xrootd.request session=pool:dcache-doma04-01@dcache-doma04-01Domain:xrootd:326cc5ce request=query response=ok
level=INFO ts=2020-12-08T18:57:10.447+0100 event=org.dcache.xrootd.request session=pool:dcache-doma04-01@dcache-doma04-01Domain:xrootd:810e3848 request=sync handle=0 response=ok
level=INFO ts=2020-12-08T18:57:11.181+0100 event=org.dcache.xrootd.request session=pool:dcache-doma04-01@dcache-doma04-01Domain:xrootd:810e3848 request=sync handle=0 response=ok
level=INFO ts=2020-12-08T18:57:11.483+0100 event=org.dcache.xrootd.request session=pool:dcache-doma04-01@dcache-doma04-01Domain:xrootd:810e3848 request=stat handle=0 vfs=false response=ok flags=0 modtime=2020-12-08T17:57:10Z size=1048576
level=INFO ts=2020-12-08T18:57:11.542+0100 event=org.dcache.xrootd.request session=pool:dcache-doma04-01@dcache-doma04-01Domain:xrootd:810e3848 request=close handle=0 response=ok
level=ERROR ts=2020-12-08T18:57:11.678+0100 event=org.dcache.xrootd.request session=pool:dcache-doma04-01@dcache-doma04-01Domain:xrootd:326cc5ce request=query response=error error.code=Unsupported error.msg="Request 3001 not supported"
level=INFO ts=2020-12-08T18:57:11.773+0100 event=org.dcache.xrootd.connection.end session=pool:dcache-doma04-01@dcache-doma04-01Domain:xrootd:326cc5ce
level=INFO ts=2020-12-08T18:57:11.773+0100 event=org.dcache.xrootd.connection.end session=pool:dcache-doma04-01@dcache-doma04-01Domain:xrootd:810e3848

What you're seeing is the pool's access log file. Each line shows either an xroot requests (with the corresponding response from the pool), a TCP connection event, or a TCP disconnection event.

Here's a high level summary of what happened:

  1. The client (xrdcp) requests a xroot-TPC from the door and is redirected to the pool (this isn't shown),
  2. The client (xrdcp) connects to the pool (TCP-1). This is first line in access logfile.
  3. On TCP-1, the client does kXR_protocol, kXR_login and kXR_open (establishing parameters for the xroot-TPC)
  4. The client makes an additional TCP connection (TCP-2)
  5. On TCP-2 the client does kXR_protocol, kXR_login, and kXR_query requests.
  6. On TCP-1, the client does kXR_sync (starting the transfer) and another kXR_sync to be notified when the transfer is complete.
  7. Transfer completes successfully.
  8. On TCP-1, the client does kXR_stat
  9. On TCP-1 the client does kXR_close
  10. On TCP-2, the client does kXR_query to request the file's checksum --- This fails.
  11. Client closes both TCP-1 and TCP-2.

In xrootd v4.12 and earlier, the kXR_query that requests the file's checksum was made on the same TCP stream as the kXR_open request.

The checksum query fails because it was made over a different TCP connection from the one in which kXR_open was made. This is (in part) to do with how permissions are handled in dCache pools.

We can try to fix this in dCache but, to be honest, I don't understand the motivation for creating a second TCP connection ("TCP-2", above). It wasn't needed in earlier versions of xrootd (e.g. v4.12) -- it looks like a bug.

—
You are receiving this because you are subscribed to this thread.
Reply to this email directly, view it on GitHub, or unsubscribe.

[ { "@context": "http://schema.org", "@type": "EmailMessage", "potentialAction": { "@type": "ViewAction", "target": "https://github.com/xrootd/xrootd/issues/1359#issuecomment-741972627", "url": "https://github.com/xrootd/xrootd/issues/1359#issuecomment-741972627", "name": "View Issue" }, "description": "View this Issue on GitHub", "publisher": { "@type": "Organization", "name": "GitHub", "url": "https://github.com" } } ]

Use REPLY-ALL to reply to list

To unsubscribe from the XROOTD-DEV list, click the following link:
https://listserv.slac.stanford.edu/cgi-bin/wa?SUBED1=XROOTD-DEV&A=1