URL:
  <http://savannah.cern.ch/support/?119913>

                 Summary: Authentication problem copying a file from CERN to
SLAC
                 Project: XROOTD
            Submitted by: gnegri
            Submitted on: 2011-03-22 17:23
                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/support/?119913>

_______________________________________________
  Message sent via/by LCG Savannah
  http://savannah.cern.ch/