Double-open in root for TFile::Open for new xrootd file?

ROOT
1

Opening a new xrootd file in a root session requires TFile::Open() to be executed twice. Example with debug=1 below.

-bash-3.2$ root
Info in TROOT::InitSystem: running with gDebug = 1
Info in TPluginManager::LoadHandlerMacros: /afs/rhic.bnl.gov/x8664_sl5/opt/dayabay/offline-opt/external/ROOT/5.22.00a/x86_64-slc5-gcc43-opt/root/etc/plugins/TSystem

  •                                     *

  •    W E L C O M E  to  R O O T       *

  •                                     *
  • Version 5.22/00a 12 February 2009 *
  •                                     *
  • You are welcome to visit our Web site *
  •      [root.cern.ch](http://root.cern.ch)            *

  •                                     *

ROOT 5.22/00a (branches/v5-22-00-patches@27437, Nov 16 2009, 16:07:00 on linuxx8664gcc)

CINT/ROOT C/C++ Interpreter version 5.16.29, Jan 08, 2008
Type ? for help. Commands must be C++ statements.
Enclose multiple statements between { }.
root [0] e32=TFile::Open(“root://daya0001.rcf.bnl.gov//xrootd/testMDC09b/output/e32.root”,“NEW”,“test file e32”)
Info in TCint::AutoLoadCallback: loaded dependent library libRIO.so for class TFile
Info in TUnixSystem::Load: loaded library /afs/rhic.bnl.gov/x8664_sl5/opt/dayabay/offline-opt/external/ROOT/5.22.00a/x86_64-slc5-gcc43-opt/root/lib/libRIO.so, status 0
Info in TCint::AutoLoadCallback: loaded library libRIO.so for class TFile
Info in TPluginManager::LoadHandlerMacros: /afs/rhic.bnl.gov/x8664_sl5/opt/dayabay/offline-opt/external/ROOT/5.22.00a/x86_64-slc5-gcc43-opt/root/etc/plugins/TFile
Info in TPluginManager::FindHandler: found plugin for TXNetFile
Info in TUnixSystem::Load: loading dependent library libRIO.so for library libThread.so
Info in TUnixSystem::Load: loaded library /afs/rhic.bnl.gov/x8664_sl5/opt/dayabay/offline-opt/external/ROOT/5.22.00a/x86_64-slc5-gcc43-opt/root/lib/libThread.so, status 0
Info in TCint::AutoLoad: loaded dependent library libThread.so for class TXNetFile
Info in TCint::AutoLoad: loaded dependent library libRIO.so for class TXNetFile
Info in TUnixSystem::Load: loading dependent library libMathCore.so for library libNet.so
Info in TUnixSystem::Load: loading dependent library libRIO.so for library libNet.so
Info in TUnixSystem::Load: loaded library /afs/rhic.bnl.gov/x8664_sl5/opt/dayabay/offline-opt/external/ROOT/5.22.00a/x86_64-slc5-gcc43-opt/root/lib/libNet.so, status 0
Info in TCint::AutoLoad: loaded dependent library libNet.so for class TXNetFile
Info in TUnixSystem::Load: loading dependent library libThread.so for library libNetx.so
Info in TUnixSystem::Load: loading dependent library libRIO.so for library libNetx.so
Info in TUnixSystem::Load: loading dependent library libNet.so for library libNetx.so
Info in TUnixSystem::Load: loaded library /afs/rhic.bnl.gov/x8664_sl5/opt/dayabay/offline-opt/external/ROOT/5.22.00a/x86_64-slc5-gcc43-opt/root/lib/libNetx.so, status 0
Info in TCint::AutoLoad: loaded library libNetx.so for class TXNetFile
Info in TPluginManager::LoadHandlerMacros: /afs/rhic.bnl.gov/x8664_sl5/opt/dayabay/offline-opt/external/ROOT/5.22.00a/x86_64-slc5-gcc43-opt/root/etc/plugins/TArchiveFile
Info in TXNetFile::ParseCacheOptions: found: cachesz = -1, readaheadsz = -1, rmpolicy = -1, mxredir = -1
Error in TXNetFile::CreateXClient: open attempt failed on root://daya0001.rcf.bnl.gov//xrootd/tes … t/e32.root
Info in TFile::~TFile: dtor called for root://daya0001.rcf.bnl.gov//xrootd/tes … t/e32.root [306148416]
Info in TDirectoryFile::~TDirectoryFile: dtor called for root://daya0001.rcf.bnl.gov//xrootd/tes … t/e32.root
Info in TDirectory::~TDirectory: dtor called for root://daya0001.rcf.bnl.gov//xrootd/tes … t/e32.root
(class TFile*)0x0
root [1] e32=TFile::Open(“root://daya0001.rcf.bnl.gov//xrootd/testMDC09b/output/e32.root”,“NEW”,“test file e32”)
Info in TPluginManager::FindHandler: found plugin for TXNetFile
Info in TXNetFile::ParseCacheOptions: found: cachesz = -1, readaheadsz = -1, rmpolicy = -1, mxredir = -1
TKey Writing 250 bytes at address 100 for ID= root://daya0001.rcf.bnl.gov//xrootd/tes … t/e32.root Title= test file e32
Info in TFileCacheWrite::TFileCacheWrite: Creating a write cache with buffersize=512000 bytes
(class TFile*)0x123b6a50
root [2] .q
TKey Writing 117 bytes at address 350 for ID= root://daya0001.rcf.bnl.gov//xrootd/tes … t/e32.root Title= test file e32
TKey Writing 123 bytes at address 467 for ID= root://daya0001.rcf.bnl.gov//xrootd/tes … t/e32.root Title= test file e32
Info in TFile::~TFile: dtor called for root://daya0001.rcf.bnl.gov//xrootd/tes … t/e32.root [305883728]
Info in TDirectoryFile::~TDirectoryFile: dtor called for root://daya0001.rcf.bnl.gov//xrootd/tes … t/e32.root
Info in TDirectory::~TDirectory: dtor called for root://daya0001.rcf.bnl.gov//xrootd/tes … t/e32.root

2

Hi,

I am not able to reproduce your problem.

Can you post the output that you get when you set

          root[] gEnv->SetValue("XNet.Debug", 2)

(leaving gDebug = 0) ?

Thanks,

G. Ganis

3

Thanks for the suggestion. Results included below.

I note the apparent problem kXR_error 4003 was discussed in root.cern.ch/phpBB2/viewtopic.ph … highlight=
but reported to be resolved in root 5.18.

root [0] gEnv->SetValue(“XNet.Debug”, 2)
root [1] e33=TFile::Open(“root://daya0001.rcf.bnl.gov//xrootd/testMDC09b/output/e33.root”,“NEW”,“test file e33”)
100114 10:09:46 001 Xrd: Create: © 2004 SLAC INFN XrdClient $Revision: 1.128 $ - Xrootd version: 20081122-0000
100114 10:09:46 001 Xrd: TakeUrl: parsing url:
100114 10:09:46 001 Xrd: XrdClientUrlSet: parsing: root://daya0001.rcf.bnl.gov//xrootd/tes … t/e33.root
100114 10:09:46 001 Xrd: XrdClientUrlSet: protocol: root
100114 10:09:46 001 Xrd: XrdClientUrlSet: file: /xrootd/testMDC09b/output/e33.root
100114 10:09:46 001 Xrd: XrdClientUrlSet: list of [host:port] : daya0001.rcf.bnl.gov
100114 10:09:46 001 Xrd: XrdClientUrlSet: Remote file to open is '/xrootd/testMDC09b/output/e33.root’
100114 10:09:46 001 Xrd: TakeUrl: parsing url: daya0001.rcf.bnl.gov
100114 10:09:46 001 Xrd: TakeUrl: HostWPort: daya0001.rcf.bnl.gov
100114 10:09:46 001 Xrd: TakeUrl: File: /
100114 10:09:46 001 Xrd: TakeUrl: Host: daya0001.rcf.bnl.gov
100114 10:09:46 001 Xrd: TakeUrl: Port: 0
100114 10:09:46 001 Xrd: ConvertDNSAlias: resolving daya0001.rcf.bnl.gov
100114 10:09:46 001 Xrd: CheckPort: TCP port not specified: trying /etc/services …
100114 10:09:47 001 Xrd: CheckPort: found tcp port 1094.
100114 10:09:47 001 Xrd: ConvertDNSAlias: found host daya0001.rcf.bnl.gov with addr 130.199.205.51
100114 10:09:47 001 Xrd: ShowUrls: The converted URLs count is 1
100114 10:09:47 001 Xrd: ShowUrls: URL n.1: root://daya0001.rcf.bnl.gov:1094//xroot … t/e33.root.
100114 10:09:47 001 Xrd: TakeUrl: parsing url: root://daya0001.rcf.bnl.gov//xrootd/tes … t/e33.root
100114 10:09:47 001 Xrd: TakeUrl: Proto: root
100114 10:09:47 001 Xrd: TakeUrl: HostWPort: daya0001.rcf.bnl.gov
100114 10:09:47 001 Xrd: TakeUrl: File: /xrootd/testMDC09b/output/e33.root
100114 10:09:47 001 Xrd: TakeUrl: Host: daya0001.rcf.bnl.gov
100114 10:09:47 001 Xrd: TakeUrl: Port: 0
100114 10:09:47 001 Xrd: CheckHostDomain: Resolved [daya0001.rcf.bnl.gov]'s domain name into [rcf.bnl.gov]
100114 10:09:47 001 Xrd: DomainMatcher: search for ‘rcf.bnl.gov’ in ''
100114 10:09:47 001 Xrd: DomainMatcher: no domain matching ‘rcf.bnl.gov’ found in ''
100114 10:09:47 001 Xrd: DomainMatcher: search for ‘rcf.bnl.gov’ in 'rcf.bnl.gov|'
100114 10:09:47 001 Xrd: DomainMatcher: domain: rcf.bnl.gov matches ‘rcf.bnl.gov’ (matching chars: 11)
100114 10:09:47 001 Xrd: CheckHostDomain: Access granted to the domain of [daya0001.rcf.bnl.gov].
100114 10:09:47 001 Xrd: Open: Trying to connect to daya0001.rcf.bnl.gov:1094. Connect try 1
100114 10:09:47 001 Xrd: XrdClientConn: Trying to connect to 130.199.205.51:1094
100114 10:09:47 001 Xrd: Connect: Creating a logical connection…
100114 10:09:47 001 Xrd: Connect: Physical connection not found. Creating a new one…
100114 10:09:47 001 Xrd: Connect: Connecting to [daya0001.rcf.bnl.gov:1094]
100114 10:09:47 001 Xrd: ClientSock::TryConnect_low: Trying to connect to daya0001.rcf.bnl.gov(130.199.205.51):1094 Windowsize=262144 Timeout=120
100114 10:09:47 001 Xrd: Connect: Connected to [daya0001.rcf.bnl.gov:1094]
100114 10:09:47 001 Xrd: Connect: New physical connection to server daya0001.rcf.bnl.gov:1094 succesfully created.
100114 10:09:47 001 Xrd: Connect: LogConn: size:1 count: 1PhyConn: size:1
100114 10:09:47 001 Xrd: Connect: Connect(daya0001.rcf.bnl.gov, 1094) returned 0
100114 10:09:47 001 Xrd: Open: The logical connection id is 0.
100114 10:09:47 001 Xrd: Open: Working url is root://daya0001.rcf.bnl.gov:1094//xroot … t/e33.root
100114 10:09:47 001 Xrd: DoHandShake: HandShake step 1: Sending 20 bytes.
100114 10:09:47 001 Xrd: DoHandShake: HandShake step 2: Reading 4 bytes.
100114 10:09:47 001 Xrd: DoHandShake: HandShake step 3: Reading 12 bytes.
100114 10:09:47 001 Xrd: DoHandShake: Server protocol: 656 type: 0
100114 10:09:47 001 Xrd: DoHandShake: Setting Load Balancer Server Url = root://daya0001.rcf.bnl.gov:1094//xroot … t/e33.root
100114 10:09:47 001 Xrd: TakeUrl: parsing url: root://daya0001.rcf.bnl.gov:1094//xroot … t/e33.root
100114 10:09:47 001 Xrd: TakeUrl: Proto: root
100114 10:09:47 001 Xrd: TakeUrl: HostWPort: daya0001.rcf.bnl.gov:1094
100114 10:09:47 001 Xrd: TakeUrl: File: /xrootd/testMDC09b/output/e33.root
100114 10:09:47 001 Xrd: TakeUrl: Host: daya0001.rcf.bnl.gov
100114 10:09:47 001 Xrd: TakeUrl: Port: 1094
100114 10:09:47 001 Xrd: GetAccessToSrv: Ok: the server on [daya0001.rcf.bnl.gov:1094] is an xrootd redirector.
100114 10:09:47 001 Xrd: StartReader: Starting reader thread…
100114 10:09:47 5408 Xrd: SocketReaderThread: Reader Thread starting.
100114 10:09:47 001 Xrd: DoLogin: Logging into the server [daya0001.rcf.bnl.gov:1094]. pid=5408 uid=djaffed
100114 10:09:47 001 Xrd: SendGenCommand: Sending command XrdClientConn::DoLogin
100114 10:09:47 001 Xrd: ReadPartialAnswer: Reading a XrdClientMessage from the server [daya0001.rcf.bnl.gov:1094]…
100114 10:09:47 001 Xrd: DoLogin: No prev session info for 130.199.205.51:1094
100114 10:09:47 001 Xrd: Open: Access to server granted.
100114 10:09:47 001 Xrd: Open: Opening the remote file /xrootd/testMDC09b/output/e33.root
100114 10:09:47 001 Xrd: SendGenCommand: Sending command Open
100114 10:09:47 001 Xrd: ReadPartialAnswer: Reading a XrdClientMessage from the server [daya0001.rcf.bnl.gov:1094]…
100114 10:09:47 001 Xrd: ReadPartialAnswer: Server [daya0001.rcf.bnl.gov:1094] answered [kXR_wait] (4005)
100114 10:09:47 001 Xrd: CheckErrorStatus: Server [daya0001.rcf.bnl.gov:1094] requested 5 seconds of wait
100114 10:09:52 001 Xrd: SendGenCommand: Sending command Open
100114 10:09:52 001 Xrd: ReadPartialAnswer: Reading a XrdClientMessage from the server [daya0001.rcf.bnl.gov:1094]…
100114 10:09:52 001 Xrd: ReadPartialAnswer: Server [daya0001.rcf.bnl.gov:1094] answered [kXR_redirect] (4004)
100114 10:09:52 001 Xrd: Disconnect: LogConnID: 0 destroyed
100114 10:09:52 001 Xrd: HandleServerError: Redir count=1
100114 10:09:52 001 Xrd: TakeUrl: parsing url: root://daya0001.rcf.bnl.gov:1094//xroot … t/e33.root
100114 10:09:52 001 Xrd: TakeUrl: Proto: root
100114 10:09:52 001 Xrd: TakeUrl: HostWPort: daya0001.rcf.bnl.gov:1094
100114 10:09:52 001 Xrd: TakeUrl: File: /xrootd/testMDC09b/output/e33.root
100114 10:09:52 001 Xrd: TakeUrl: Host: daya0001.rcf.bnl.gov
100114 10:09:52 001 Xrd: TakeUrl: Port: 1094
100114 10:09:52 001 Xrd: HandleServerError: Received redirection to [daya0003.rcf.bnl.gov:1094]. Token=[]]. Opaque=[].
100114 10:09:52 001 Xrd: CheckHostDomain: Resolved [daya0003.rcf.bnl.gov]'s domain name into [rcf.bnl.gov]
100114 10:09:52 001 Xrd: DomainMatcher: search for ‘rcf.bnl.gov’ in ''
100114 10:09:52 001 Xrd: DomainMatcher: no domain matching ‘rcf.bnl.gov’ found in ''
100114 10:09:52 001 Xrd: DomainMatcher: search for ‘rcf.bnl.gov’ in 'rcf.bnl.gov|'
100114 10:09:52 001 Xrd: DomainMatcher: domain: rcf.bnl.gov matches ‘rcf.bnl.gov’ (matching chars: 11)
100114 10:09:52 001 Xrd: CheckHostDomain: Access granted to the domain of [daya0003.rcf.bnl.gov].
100114 10:09:52 001 Xrd: XrdClientConn: Trying to connect to 130.199.205.53:1094
100114 10:09:52 001 Xrd: Connect: Creating a logical connection…
100114 10:09:52 001 Xrd: DumpPhyConn: Phyconn entry, key=‘djaffed@daya0001.rcf.bnl.gov:1094’, LogCnt=0 Valid
100114 10:09:52 001 Xrd: Connect: Physical connection not found. Creating a new one…
100114 10:09:52 001 Xrd: DumpPhyConn: Phyconn entry, key=‘djaffed@daya0001.rcf.bnl.gov:1094’, LogCnt=0 Valid
100114 10:09:52 001 Xrd: Connect: Connecting to [daya0003.rcf.bnl.gov:1094]
100114 10:09:52 001 Xrd: ClientSock::TryConnect_low: Trying to connect to daya0003.rcf.bnl.gov(130.199.205.53):1094 Windowsize=262144 Timeout=120
100114 10:09:52 001 Xrd: Connect: Connected to [daya0003.rcf.bnl.gov:1094]
100114 10:09:52 001 Xrd: Connect: New physical connection to server daya0003.rcf.bnl.gov:1094 succesfully created.
100114 10:09:52 001 Xrd: Connect: LogConn: size:2 count: 1PhyConn: size:2
100114 10:09:52 001 Xrd: Connect: Destroying connection condvar for djaffed@daya0003.rcf.bnl.gov:1094
100114 10:09:52 001 Xrd: Connect: Connect(daya0003.rcf.bnl.gov, 1094) returned 1
100114 10:09:52 001 Xrd: DoHandShake: HandShake step 1: Sending 20 bytes.
100114 10:09:52 001 Xrd: DoHandShake: HandShake step 2: Reading 4 bytes.
100114 10:09:52 001 Xrd: DoHandShake: HandShake step 3: Reading 12 bytes.
100114 10:09:52 001 Xrd: DoHandShake: Server protocol: 656 type: 1
100114 10:09:52 001 Xrd: GetAccessToSrv: Ok, the server on [daya0003.rcf.bnl.gov:1094] is an xrootd data server.
100114 10:09:52 001 Xrd: StartReader: Starting reader thread…
100114 10:09:52 5408 Xrd: SocketReaderThread: Reader Thread starting.
100114 10:09:52 001 Xrd: DoLogin: Logging into the server [daya0003.rcf.bnl.gov:1094]. pid=5408 uid=djaffed
100114 10:09:52 001 Xrd: SendGenCommand: Sending command XrdClientConn::DoLogin
100114 10:09:52 001 Xrd: ReadPartialAnswer: Reading a XrdClientMessage from the server [daya0003.rcf.bnl.gov:1094]…
100114 10:09:52 001 Xrd: DoLogin: No prev session info for 130.199.205.53:1094
100114 10:09:52 001 Xrd: SendGenCommand: Got (and maybe recovered) an error from daya0003.rcf.bnl.gov:1094
100114 10:09:52 001 Xrd: SendGenCommand: Sending command Open
100114 10:09:52 001 Xrd: ReadPartialAnswer: Reading a XrdClientMessage from the server [daya0003.rcf.bnl.gov:1094]…
100114 10:09:52 001 Xrd: ReadPartialAnswer: Server [daya0003.rcf.bnl.gov:1094] answered [kXR_error] (4003)
100114 10:09:52 001 Xrd: CheckErrorStatus: Server declared: Unable to create /xrootd/testMDC09b/output/e33.root; No such file or directory(error code: 3011)
100114 10:09:52 001 Xrd: Open: Error opening the file /xrootd/testMDC09b/output/e33.root on host daya0001.rcf.bnl.gov:1094
Error in TXNetFile::CreateXClient: open attempt failed on root://daya0001.rcf.bnl.gov//xrootd/tes … t/e33.root
100114 10:09:52 001 Xrd: Disconnect: LogConnID: 1 destroyed
Caching info: MissRate=0 MissCount=0 ReadsCounter=0
Caching info: BytesUsefulness=0 BytesSubmitted=0 BytesHit=0
(class TFile*)0x0
root [2] e33=TFile::Open(“root://daya0001.rcf.bnl.gov//xrootd/testMDC09b/output/e33.root”,“NEW”,“test file e33”)
100114 10:10:06 001 Xrd: TakeUrl: parsing url:
100114 10:10:06 001 Xrd: XrdClientUrlSet: parsing: root://daya0001.rcf.bnl.gov//xrootd/tes … t/e33.root
100114 10:10:06 001 Xrd: XrdClientUrlSet: protocol: root
100114 10:10:06 001 Xrd: XrdClientUrlSet: file: /xrootd/testMDC09b/output/e33.root
100114 10:10:06 001 Xrd: XrdClientUrlSet: list of [host:port] : daya0001.rcf.bnl.gov
100114 10:10:06 001 Xrd: XrdClientUrlSet: Remote file to open is '/xrootd/testMDC09b/output/e33.root’
100114 10:10:06 001 Xrd: TakeUrl: parsing url: daya0001.rcf.bnl.gov
100114 10:10:06 001 Xrd: TakeUrl: HostWPort: daya0001.rcf.bnl.gov
100114 10:10:06 001 Xrd: TakeUrl: File: /
100114 10:10:06 001 Xrd: TakeUrl: Host: daya0001.rcf.bnl.gov
100114 10:10:06 001 Xrd: TakeUrl: Port: 0
100114 10:10:06 001 Xrd: ConvertDNSAlias: resolving daya0001.rcf.bnl.gov
100114 10:10:06 001 Xrd: CheckPort: TCP port not specified: trying /etc/services …
100114 10:10:06 001 Xrd: CheckPort: found tcp port 1094.
100114 10:10:06 001 Xrd: ConvertDNSAlias: found host daya0001.rcf.bnl.gov with addr 130.199.205.51
100114 10:10:06 001 Xrd: ShowUrls: The converted URLs count is 1
100114 10:10:06 001 Xrd: ShowUrls: URL n.1: root://daya0001.rcf.bnl.gov:1094//xroot … t/e33.root.
100114 10:10:06 001 Xrd: TakeUrl: parsing url: root://daya0001.rcf.bnl.gov//xrootd/tes … t/e33.root
100114 10:10:06 001 Xrd: TakeUrl: Proto: root
100114 10:10:06 001 Xrd: TakeUrl: HostWPort: daya0001.rcf.bnl.gov
100114 10:10:06 001 Xrd: TakeUrl: File: /xrootd/testMDC09b/output/e33.root
100114 10:10:06 001 Xrd: TakeUrl: Host: daya0001.rcf.bnl.gov
100114 10:10:06 001 Xrd: TakeUrl: Port: 0
100114 10:10:06 001 Xrd: Open: Trying to connect to daya0001.rcf.bnl.gov:1094. Connect try 1
100114 10:10:06 001 Xrd: XrdClientConn: Trying to connect to 130.199.205.51:1094
100114 10:10:06 001 Xrd: Connect: Creating a logical connection…
100114 10:10:06 001 Xrd: DumpPhyConn: Phyconn entry, key=‘djaffed@daya0003.rcf.bnl.gov:1094’, LogCnt=0 Valid
100114 10:10:06 001 Xrd: DumpPhyConn: Phyconn entry, key=‘djaffed@daya0001.rcf.bnl.gov:1094’, LogCnt=0 Valid
100114 10:10:06 001 Xrd: Connect: LogConn: size:3 count: 1PhyConn: size:2
100114 10:10:06 001 Xrd: Connect: Connect(daya0001.rcf.bnl.gov, 1094) returned 2
100114 10:10:06 001 Xrd: Open: The logical connection id is 2.
100114 10:10:06 001 Xrd: Open: Working url is root://daya0001.rcf.bnl.gov:1094//xroot … t/e33.root
100114 10:10:06 001 Xrd: DoHandShake: The physical channel is already bound to a load balancer server [daya0001.rcf.bnl.gov:1094]. No handshake is needed.
100114 10:10:06 001 Xrd: DoHandShake: Setting Load Balancer Server Url = root://daya0001.rcf.bnl.gov:1094//xroot … t/e33.root
100114 10:10:06 001 Xrd: TakeUrl: parsing url: root://daya0001.rcf.bnl.gov:1094//xroot … t/e33.root
100114 10:10:06 001 Xrd: TakeUrl: Proto: root
100114 10:10:06 001 Xrd: TakeUrl: HostWPort: daya0001.rcf.bnl.gov:1094
100114 10:10:06 001 Xrd: TakeUrl: File: /xrootd/testMDC09b/output/e33.root
100114 10:10:06 001 Xrd: TakeUrl: Host: daya0001.rcf.bnl.gov
100114 10:10:06 001 Xrd: TakeUrl: Port: 1094
100114 10:10:06 001 Xrd: GetAccessToSrv: Ok: the server on [daya0001.rcf.bnl.gov:1094] is an xrootd redirector.
100114 10:10:06 001 Xrd: GetAccessToSrv: Reusing physical connection to server [daya0001.rcf.bnl.gov:1094]).
100114 10:10:06 001 Xrd: Open: Access to server granted.
100114 10:10:06 001 Xrd: Open: Opening the remote file /xrootd/testMDC09b/output/e33.root
100114 10:10:06 001 Xrd: SendGenCommand: Sending command Open
100114 10:10:06 001 Xrd: ReadPartialAnswer: Reading a XrdClientMessage from the server [daya0001.rcf.bnl.gov:1094]…
100114 10:10:06 001 Xrd: ReadPartialAnswer: Server [daya0001.rcf.bnl.gov:1094] answered [kXR_redirect] (4004)
100114 10:10:06 001 Xrd: Disconnect: LogConnID: 2 destroyed
100114 10:10:06 001 Xrd: HandleServerError: Redir count=1
100114 10:10:06 001 Xrd: TakeUrl: parsing url: root://daya0001.rcf.bnl.gov:1094//xroot … t/e33.root
100114 10:10:06 001 Xrd: TakeUrl: Proto: root
100114 10:10:06 001 Xrd: TakeUrl: HostWPort: daya0001.rcf.bnl.gov:1094
100114 10:10:06 001 Xrd: TakeUrl: File: /xrootd/testMDC09b/output/e33.root
100114 10:10:06 001 Xrd: TakeUrl: Host: daya0001.rcf.bnl.gov
100114 10:10:06 001 Xrd: TakeUrl: Port: 1094
100114 10:10:06 001 Xrd: HandleServerError: Received redirection to [daya0002.rcf.bnl.gov:1094]. Token=[]]. Opaque=[].
100114 10:10:06 001 Xrd: CheckHostDomain: Resolved [daya0002.rcf.bnl.gov]'s domain name into [rcf.bnl.gov]
100114 10:10:06 001 Xrd: DomainMatcher: search for ‘rcf.bnl.gov’ in ''
100114 10:10:06 001 Xrd: DomainMatcher: no domain matching ‘rcf.bnl.gov’ found in ''
100114 10:10:06 001 Xrd: DomainMatcher: search for ‘rcf.bnl.gov’ in 'rcf.bnl.gov|'
100114 10:10:06 001 Xrd: DomainMatcher: domain: rcf.bnl.gov matches ‘rcf.bnl.gov’ (matching chars: 11)
100114 10:10:06 001 Xrd: CheckHostDomain: Access granted to the domain of [daya0002.rcf.bnl.gov].
100114 10:10:06 001 Xrd: XrdClientConn: Trying to connect to 130.199.205.52:1094
100114 10:10:06 001 Xrd: Connect: Creating a logical connection…
100114 10:10:06 001 Xrd: DumpPhyConn: Phyconn entry, key=‘djaffed@daya0003.rcf.bnl.gov:1094’, LogCnt=0 Valid
100114 10:10:06 001 Xrd: DumpPhyConn: Phyconn entry, key=‘djaffed@daya0001.rcf.bnl.gov:1094’, LogCnt=0 Valid
100114 10:10:06 001 Xrd: Connect: Physical connection not found. Creating a new one…
100114 10:10:06 001 Xrd: DumpPhyConn: Phyconn entry, key=‘djaffed@daya0003.rcf.bnl.gov:1094’, LogCnt=0 Valid
100114 10:10:06 001 Xrd: DumpPhyConn: Phyconn entry, key=‘djaffed@daya0001.rcf.bnl.gov:1094’, LogCnt=0 Valid
100114 10:10:06 001 Xrd: Connect: Connecting to [daya0002.rcf.bnl.gov:1094]
100114 10:10:06 001 Xrd: ClientSock::TryConnect_low: Trying to connect to daya0002.rcf.bnl.gov(130.199.205.52):1094 Windowsize=262144 Timeout=120
100114 10:10:06 001 Xrd: Connect: Connected to [daya0002.rcf.bnl.gov:1094]
100114 10:10:06 001 Xrd: Connect: New physical connection to server daya0002.rcf.bnl.gov:1094 succesfully created.
100114 10:10:06 001 Xrd: Connect: LogConn: size:4 count: 1PhyConn: size:3
100114 10:10:06 001 Xrd: Connect: Destroying connection condvar for djaffed@daya0002.rcf.bnl.gov:1094
100114 10:10:06 001 Xrd: Connect: Connect(daya0002.rcf.bnl.gov, 1094) returned 3
100114 10:10:06 001 Xrd: DoHandShake: HandShake step 1: Sending 20 bytes.
100114 10:10:06 001 Xrd: DoHandShake: HandShake step 2: Reading 4 bytes.
100114 10:10:06 001 Xrd: DoHandShake: HandShake step 3: Reading 12 bytes.
100114 10:10:06 001 Xrd: DoHandShake: Server protocol: 656 type: 1
100114 10:10:06 001 Xrd: GetAccessToSrv: Ok, the server on [daya0002.rcf.bnl.gov:1094] is an xrootd data server.
100114 10:10:06 001 Xrd: StartReader: Starting reader thread…
100114 10:10:06 5408 Xrd: SocketReaderThread: Reader Thread starting.
100114 10:10:06 001 Xrd: DoLogin: Logging into the server [daya0002.rcf.bnl.gov:1094]. pid=5408 uid=djaffed
100114 10:10:06 001 Xrd: SendGenCommand: Sending command XrdClientConn::DoLogin
100114 10:10:06 001 Xrd: ReadPartialAnswer: Reading a XrdClientMessage from the server [daya0002.rcf.bnl.gov:1094]…
100114 10:10:06 001 Xrd: DoLogin: No prev session info for 130.199.205.52:1094
100114 10:10:06 001 Xrd: SendGenCommand: Got (and maybe recovered) an error from daya0002.rcf.bnl.gov:1094
100114 10:10:06 001 Xrd: SendGenCommand: Sending command Open
100114 10:10:06 001 Xrd: ReadPartialAnswer: Reading a XrdClientMessage from the server [daya0002.rcf.bnl.gov:1094]…
100114 10:10:06 001 Xrd: Open: Returned stats=387731896383047713 0 48 1263481806
100114 10:10:06 001 Xrd: Open: File opened succesfully.
100114 10:10:06 001 Xrd: SendGenCommand: Sending command Write
100114 10:10:06 001 Xrd: ReadPartialAnswer: Reading a XrdClientMessage from the server [daya0002.rcf.bnl.gov:1094]…
100114 10:10:06 001 Xrd: SendGenCommand: Sending command Sync
100114 10:10:06 001 Xrd: ReadPartialAnswer: Reading a XrdClientMessage from the server [daya0002.rcf.bnl.gov:1094]…
100114 10:10:06 001 Xrd: SendGenCommand: Sending command Write
100114 10:10:06 001 Xrd: ReadPartialAnswer: Reading a XrdClientMessage from the server [daya0002.rcf.bnl.gov:1094]…
(class TFile)0x8b47f10

4

Hi,

this line is very suspect:

CheckErrorStatus: Server declared: Unable to create /xrootd/testMDC09b/output/e33.root; No such file or directory(error code: 3011)

it means that XrdClient did not get the options needed to write, so the first time it opened the file only for reading. Could you please try with CREATE or RECREATE instead of NEW ? I suspect an incorrect parsing of that option field.

Fabrizio

5

I get the same behavior with either CREATE or RECREATE instead of NEW.

It seems like the first Open() primes the connection in some way and allows a subsequent Open() to be successful, even if a different file is Open()ed.
Here’s an example

root [0] e41=TFile::Open(“root://daya0001.rcf.bnl.gov//xrootd/testMDC09b/output/e41.root”,“RECREATE”,“test file e41”)
Error in TXNetFile::CreateXClient: open attempt failed on root://daya0001.rcf.bnl.gov//xrootd/tes … t/e41.root
(class TFile*)0x0
root [1] e42=TFile::Open(“root://daya0001.rcf.bnl.gov//xrootd/testMDC09b/output/e42.root”,“RECREATE”,“test file e42”)
(class TFile*)0x76367f0

I can repeat with the debug level non-zero if you wish.

Thanks.

6

Hi,

our suspect is that the server 130.199.205.53 has problems. To sort it out you could
write directly to this server instead than asking to the redirector daya0001.rcf.bnl.gov. All the attempts should fail. Instead, writing to the other server (130.199.205.52) should always succeed.

Could you please try this out?

Fabrizio

7

Hi Fabrizio,

Your hypothesis is correct. 130.199.205.53 always fails and
130.199.205.52 succeeds. I will take this up with the administrator.

Thanks very much the help.

8

Here is a response from Gerardo Ganis gerardo.ganis@cern.ch to Ofer Rind that may help others to avoid the problem:

Hi Ofer,

By default the missing components of the path are not created (just for ‘fopen(…)’ or ‘open(…)’).
However, you can force their creation in the following way:

   1. At file level, by adding the option 'mkpath=1' in the URL (e.g. 'root://theserver//new/path/file.root?mkpath=1')
   2. Globally using the setting

             XNet.Mkpath: 1

       in the relevant .rootrc file ($HOME/.rootrc or $ROOTSYS/etc/system.rootrc or /etc/root/system.rootrc)

When this option is set, TXNetFile sets the ‘kXR_mkpath’ bit in the option field when opening the file.
Most likely xrdcp sets always this bit, which would explain the different behavior.

Hope it helps.

Gerri

On 10/06/2010 04:24 AM, Ofer Rind wrote:
Hi all,

Are there any known issues trying to create a new file using TFile::Open() within ROOT when the parent directory has not been created previously? We seem to be unable to do this on the small xrootd deployment we have here at BNL for the Daya Bay group. With xrdcp, the parent directories get created automatically. Also, there is no problem creating the new file from within ROOT if the parent directories have been created previously on the selected storage server. Is this a server configuration issue, or possibly something missing in ROOT?

We are using ROOT v5.26/00b and xrd version 20091028-1003_dbg. I have attached a ROOT log executing

TFile* file = TFile::Open(url,“RECREATE”);

when the url is pointing to a nonexisting directory. The error we get is

101005 17:53:36 001 Xrd: ReadPartialAnswer: Server [daya0002.rcf.bnl.gov:1094] answered [kXR_error] (4003)
101005 17:53:36 001 Xrd: CheckErrorStatus: Server [daya0001.rcf.bnl.gov:1094] declared: Unable to create /xrootd/bv/test/does-not-exist/file.root; No such file or directory(error code: 3011)
101005 17:53:36 001 Xrd: Open: Error opening the file /xrootd/bv/test/does-not-exist/file.root on host daya0001.rcf.bnl.gov:1094
Error in TXNetFile::CreateXClient: open attempt failed on root://daya0001//xrootd/bv/test/does-no … /file.root

I have also attached our xrootd.cf. Any advice would be much appreciated and sincere apologies if this has been discussed and answered before.

Thanks!
Ofer Rind

PS This is the same problem discussed in /viewtopic.php?p=41410 (the problem was not the server but rather the absence of the parent directories).