URL: <http://savannah.cern.ch/bugs/?79847> Summary: Authentication problem copying a file from CERN to SLAC Project: XROOTD Submitted by: gnegri Submitted on: 2011-03-22 16:08 Severity: 3 - Normal Priority: 5 - Normal Status: None Privacy: Public Assigned to: None Originator Email: Open/Closed: Open Discussion Lock: Any Fixed by commit(s): _______________________________________________________ Details: A user is trying to copy a file from CASTOR (stager castorcernt3, serviceclass atlascerngroupdisk) to a machine at SLAC (atlint01.slac.stanford.edu). The xrdcp command is issued on the SLAC machine. Apparently, the problem is authentication (on bottom, the "-d 3" output). How does authentication work for xrdcp? Has kerberos to be properly setup on the remote machine? Can access with GSI authentication work on CASTOR also for certificates not issued by CERN? castorcernt3 shuold not be gsi-enabled, but the xrootd redirector castoratlas should be. Thanks a lot --------------------------------------------------- [atlint01] ~/atlasdata/TestBeam2011/IBL-DESY-Feb2011 $ xrdcp -d 3 root://castoratlas.cern.ch///castor/cern.ch/atlas/atlascerngroupdisk/det-ibl/TestBeam/Feb2011_DESY/Output/tbtrack30377.root . Set debug level 3 110322 08:32:22 001 Xrd: main: (C) 2004-2010 by the Xrootd group. $Revision$ - Xrootd version: v3.0.2_dbg 110322 08:32:22 001 Xrd: Create: (C) 2004-2010 by the Xrootd group. XrdClient $Revision$ - Xrootd version: v3.0.2_dbg 110322 08:32:22 001 Xrd: TakeUrl: parsing url: 110322 08:32:22 001 Xrd: GetDomainToMatch: GetHostName(atlint01) returned name=atlint01.slac.stanford.edu 110322 08:32:22 001 Xrd: GetDomainToMatch: GetDomain(atlint01) --> slac.stanford.edu 110322 08:32:22 001 Xrd: XrdClientUrlSet: parsing: root://castoratlas.cern.ch///castor/cern.ch/atlas/atlascerngroupdisk/det-ibl/TestBeam/Feb2011_DESY/Output/tbtrack30377.root 110322 08:32:22 001 Xrd: XrdClientUrlSet: protocol: root 110322 08:32:22 001 Xrd: XrdClientUrlSet: file: //castor/cern.ch/atlas/atlascerngroupdisk/det-ibl/TestBeam/Feb2011_DESY/Output/tbtrack30377.root 110322 08:32:22 001 Xrd: XrdClientUrlSet: list of [host:port] : castoratlas.cern.ch 110322 08:32:22 001 Xrd: XrdClientUrlSet: Remote file to open is '//castor/cern.ch/atlas/atlascerngroupdisk/det-ibl/TestBeam/Feb2011_DESY/Output/tbtrack30377.root' 110322 08:32:22 001 Xrd: XrdClientUrlSet: parsing entity: castoratlas.cern.ch 110322 08:32:22 001 Xrd: TakeUrl: parsing url: castoratlas.cern.ch 110322 08:32:22 001 Xrd: TakeUrl: HostWPort: castoratlas.cern.ch 110322 08:32:22 001 Xrd: TakeUrl: File: / 110322 08:32:22 001 Xrd: TakeUrl: Host: castoratlas.cern.ch 110322 08:32:22 001 Xrd: TakeUrl: Port: 0 110322 08:32:22 001 Xrd: ConvertDNSAlias: resolving castoratlas.cern.ch 110322 08:32:22 001 Xrd: CheckPort: TCP port not specified: trying /etc/services ... 110322 08:32:22 001 Xrd: CheckPort: found tcp port 1094. 110322 08:32:22 001 Xrd: ConvertDNSAlias: found host c2atlassrv102.cern.ch with addr 128.142.178.143 110322 08:32:22 001 Xrd: ShowUrls: The converted URLs count is 1 110322 08:32:22 001 Xrd: ShowUrls: URL n.1: root://c2atlassrv102.cern.ch:1094///castor/cern.ch/atlas/atlascerngroupdisk/det-ibl/TestBeam/Feb2011_DESY/Output/tbtrack30377.root. 110322 08:32:22 001 Xrd: TakeUrl: parsing url: root://castoratlas.cern.ch///castor/cern.ch/atlas/atlascerngroupdisk/det-ibl/TestBeam/Feb2011_DESY/Output/tbtrack30377.root 110322 08:32:22 001 Xrd: TakeUrl: Proto: root 110322 08:32:22 001 Xrd: TakeUrl: HostWPort: castoratlas.cern.ch 110322 08:32:22 001 Xrd: TakeUrl: File: //castor/cern.ch/atlas/atlascerngroupdisk/det-ibl/TestBeam/Feb2011_DESY/Output/tbtrack30377.root 110322 08:32:22 001 Xrd: TakeUrl: Host: castoratlas.cern.ch 110322 08:32:22 001 Xrd: TakeUrl: Port: 0 110322 08:32:22 001 Xrd: CheckHostDomain: Resolved [c2atlassrv102.cern.ch]'s domain name into [cern.ch] 110322 08:32:22 001 Xrd: DomainMatcher: search for 'cern.ch' in '' 110322 08:32:22 001 Xrd: DomainMatcher: no domain matching 'cern.ch' found in '' 110322 08:32:22 001 Xrd: DomainMatcher: search for 'cern.ch' in '*' 110322 08:32:22 001 Xrd: DomainMatcher: checking domain: * 110322 08:32:22 001 Xrd: DomainMatcher: domain: * matches 'cern.ch' (matching chars: 1) 110322 08:32:22 001 Xrd: CheckHostDomain: Access granted to the domain of [c2atlassrv102.cern.ch]. 110322 08:32:22 001 Xrd: Open: Trying to connect to c2atlassrv102.cern.ch:1094. Connect try 1 110322 08:32:22 001 Xrd: XrdClientConn: Trying to connect to 128.142.178.143:1094 110322 08:32:22 001 Xrd: Connect: Creating a logical connection... 110322 08:32:22 001 Xrd: Connect: Physical connection not found. Creating a new one... 110322 08:32:22 001 Xrd: Connect: Connecting to [c2atlassrv102.cern.ch:1094] 110322 08:32:22 001 Xrd: ClientSock::TryConnect_low: Trying to connect to c2atlassrv102.cern.ch(128.142.178.143):1094 Windowsize=0 Timeout=120 110322 08:32:22 001 Xrd: Connect: Connected to [c2atlassrv102.cern.ch:1094] 110322 08:32:22 001 Xrd: Connect: New physical connection to server c2atlassrv102.cern.ch:1094 succesfully created. 110322 08:32:22 001 Xrd: Connect: LogConn: size:1 count: 1PhyConn: size:1 110322 08:32:22 001 Xrd: Connect: Connect(c2atlassrv102.cern.ch, 1094) returned 0 110322 08:32:22 001 Xrd: Open: The logical connection id is 0. 110322 08:32:22 001 Xrd: Open: Working url is root://c2atlassrv102.cern.ch:1094///castor/cern.ch/atlas/atlascerngroupdisk/det-ibl/TestBeam/Feb2011_DESY/Output/tbtrack30377.root 110322 08:32:22 001 Xrd: DoHandShake: HandShake step 1: Sending 20 bytes. 110322 08:32:22 001 Xrd: WriteRaw: Writing to substreamid 0 110322 08:32:22 001 Xrd: DoHandShake: HandShake step 2: Reading 4 bytes. 110322 08:32:22 001 Xrd: ReadRaw: Reading from c2atlassrv102.cern.ch:1094 110322 08:32:22 001 Xrd: DoHandShake: HandShake step 3: Reading 12 bytes. 110322 08:32:22 001 Xrd: ReadRaw: Reading from c2atlassrv102.cern.ch:1094 110322 08:32:22 001 Xrd: DoHandShake: Server protocol: 656 type: 0 110322 08:32:22 001 Xrd: DoHandShake: Setting Load Balancer Server Url = root://c2atlassrv102.cern.ch:1094///castor/cern.ch/atlas/atlascerngroupdisk/det-ibl/TestBeam/Feb2011_DESY/Output/tbtrack30377.root 110322 08:32:22 001 Xrd: TakeUrl: parsing url: root://c2atlassrv102.cern.ch:1094///castor/cern.ch/atlas/atlascerngroupdisk/det-ibl/TestBeam/Feb2011_DESY/Output/tbtrack30377.root 110322 08:32:22 001 Xrd: TakeUrl: Proto: root 110322 08:32:22 001 Xrd: TakeUrl: HostWPort: c2atlassrv102.cern.ch:1094 110322 08:32:22 001 Xrd: TakeUrl: File: //castor/cern.ch/atlas/atlascerngroupdisk/det-ibl/TestBeam/Feb2011_DESY/Output/tbtrack30377.root 110322 08:32:22 001 Xrd: TakeUrl: Host: c2atlassrv102.cern.ch 110322 08:32:22 001 Xrd: TakeUrl: Port: 1094 110322 08:32:22 001 Xrd: GetAccessToSrv: Ok: the server on [c2atlassrv102.cern.ch:1094] is an xrootd redirector. 110322 08:32:22 001 Xrd: StartReader: Starting reader thread... 110322 08:32:22 11296 Xrd: SocketReaderThread: Reader Thread starting. 110322 08:32:22 11296 Xrd: XrdClientMessage::ReadRaw: Reading header (8 bytes). 110322 08:32:22 001 Xrd: DoLogin: Logging into the server [c2atlassrv102.cern.ch:1094]. pid=11296 uid=grenier 110322 08:32:22 11296 Xrd: ReadRaw: Reading from c2atlassrv102.cern.ch:1094 110322 08:32:22 001 Xrd: SendGenCommand: Sending command XrdClientConn::DoLogin ================= DUMPING CLIENT REQUEST HEADER ================= ClientHeader.streamid = 0x01 0x00 ClientHeader.requestid = kXR_login (3007) ClientHeader.login.pid = 11296 ClientHeader.login_body.username = grenier ClientHeader.login.reserved = 0 repeated 2 times ClientHeader.login.capver = 130 ClientHeader.login.role = 0 ClientHeader.header.dlen = 0 =================== END CLIENT HEADER DUMPING =================== 110322 08:32:22 001 Xrd: WriteRaw: Writing 24 bytes to physical connection 110322 08:32:22 001 Xrd: WriteRaw: Writing to substreamid 0 110322 08:32:22 001 Xrd: ReadPartialAnswer: Reading a XrdClientMessage from the server [c2atlassrv102.cern.ch:1094]... 110322 08:32:23 11296 Xrd: XrdClientMessage::ReadRaw: sid: 1, IsAttn: 0, substreamid: 0 110322 08:32:23 11296 Xrd: XrdClientMessage::ReadRaw: Reading data (58 bytes) from substream 0 110322 08:32:23 11296 Xrd: ReadRaw: Reading from c2atlassrv102.cern.ch:1094 110322 08:32:23 11296 Xrd: BuildMessage: posting id 1 ======== DUMPING SERVER RESPONSE HEADER ======== ServerHeader.streamid = 0x01 0x00 ServerHeader.status = kXR_ok (0) ServerHeader.dlen = 58 ========== END DUMPING SERVER HEADER =========== 110322 08:32:23 11296 Xrd: XrdClientMessage::ReadRaw: Reading header (8 bytes). 110322 08:32:23 001 Xrd: DoLogin: Got session ID: 68ffffff9a0800ffffff9f360000ffffffc1000000ffffffadffffff9a0800 110322 08:32:23 001 Xrd: DoLogin: server requires authentication 110322 08:32:23 001 Xrd: DoAuthentication: host c2atlassrv102.cern.ch sent a list of 43 bytes 110322 08:32:23 11296 Xrd: ReadRaw: Reading from c2atlassrv102.cern.ch:1094 sec_Client: protocol request for host c2atlassrv102.cern.ch token='&P=krb5,[log in to unmask] sec_PM: Loading krb5 protocol object from libXrdSeckrb5.so sec_PM: Using krb5 protocol, [log in to unmask] Seckrb5: getCredentials Seckrb5: FILE:/tmp/krb5cc_7283_P0kor2 Seckrb5: init context Seckrb5: cc cache default Seckrb5: context lock Seckrb5: context locked Seckrb5: get_krbCreds: unable to get creds; Server not found in Kerberos database 110322 08:32:23 001 Xrd: DoAuthentication: cannot obtain credentials (protocol: krb5) sec_Client: protocol request for host c2atlassrv102.cern.ch token='' XrdSec: No authentication protocols are available. 110322 08:32:23 001 Xrd: DoAuthentication: unable to get protocol object. 110322 08:32:23 001 Xrd: DoLogin: No prev session info for 128.142.178.143:1094 110322 08:32:23 001 Xrd: Cache: Cache Status -------------------------- 110322 08:32:23 001 Xrd: Cache: -------------------------------------- fTotalByteCount = 0 110322 08:32:23 001 Xrd: PhyConnection: Disconnecting socket... 110322 08:32:23 001 Xrd: DumpPhyConn: Phyconn entry, [log in to unmask]:1094', LogCnt=1 NotValid 110322 08:32:23 001 Xrd: PhyConnection: Disconnecting socket... 110322 08:32:23 001 Xrd: DumpPhyConn: Phyconn entry, key='Trashed connection', LogCnt=1 NotValid 110322 08:32:23 001 Xrd: Disconnect: LogConnID: 0 destroyed 110322 08:32:23 001 Xrd: Cache: Cache Status -------------------------- 110322 08:32:23 001 Xrd: Cache: -------------------------------------- fTotalByteCount = 0 110322 08:32:23 001 Xrd: Open: Authentication failure: unable to get protocol object 110322 08:32:23 001 Xrd: Open: Disconnecting. 110322 08:32:23 001 Xrd: Cache: Cache Status -------------------------- 110322 08:32:23 001 Xrd: Cache: -------------------------------------- fTotalByteCount = 0 Last server error 3010 ('unable to get protocol object.') Error accessing path/file for root://castoratlas.cern.ch///castor/cern.ch/atlas/atlascerngroupdisk/det-ibl/TestBeam/Feb2011_DESY/Output/tbtrack30377.root _______________________________________________________ Reply to this item at: <http://savannah.cern.ch/bugs/?79847> _______________________________________________ Message sent via/by LCG Savannah http://savannah.cern.ch/