Chris, You can increase the level of logging in the gridftp door logs by increasing the number in the first line of the gridftpdoor.batch file set printout default 2 going to 3 or 4 should give you plenty of extra information. Greig On Tue, 24 Oct 2006, Brew, CAJ (Chris) wrote: > Hi Jon, > > I don't think so. The stuff from the kpwd file is the "/ / /" at the end > of the > > login <username> ... > > lines right? > > They're all set to the same and I haven't changed anything in srm.batch > - though I cannot see anything that looks like a user root in that file. > > The only log entry I can find for the initial error is int the > gridftpdoor log and only consists of: > > 10/24 13:25:26 Cell(GFTP-heplnx204-Unknown-115@gridftp-heplnx204Domain) > : PnfsHandler : CacheException (2) : Pnfs error : failed : File exists > > which isn't very informative and of course lcg-cr doesn't have a proper > --debug option so it's very hard to tell exactly what it's doing. > > The other very limited errors all seem to relate to the failed > srm-advisory delete. Can I turn the logging up any higher? > > Thanks, > Chris. > > > -----Original Message----- > > From: bakken [mailto:[log in to unmask]] > > Sent: 24 October 2006 12:25 > > To: [log in to unmask] > > Subject: Re: lcg-cr fails with "File Exists" > > > > My only guess is that the extra file components gridftp and > > srmcp can add to the filepath. For example, the dcache.kpwd > > file has a user root that is added, and srmcp has a different > > one in the srm batch file. Many people run with these both > > set to /, so they become degenerate. The gridftp component > > changes depending on the user, so your DN can make a difference. > > > > Complete filenames should be listed in the log, but it may be > > hard to find. > > > > Any chance that's it? > > > > <R4551|0n 7h3r3'5 n0 p|4c3 |1k3 127.0.0.1 > > Jon A. Bakken [log in to unmask] (630) 840-4790 > > > > On Tue, 24 Oct 2006, Brew, CAJ (Chris) wrote: > > > > > Hi All, > > > > > > I've got a problem with dcache that I've not seen before: > > > > > > lcg-cr fails with "File Exists" even though it doesn't. > > > > > > heplnx101 - ~ $ lcg-cr --vo babar -v -d > > > > > srm://heplnx204.pp.rl.ac.uk:8443/pnfs/pp.rl.ac.uk/data/babar/brew/test > > > -2 > > > 00610241145 file://home/hephp/brew/9936870.moose.01.root > > > Using grid catalog type: lfc > > > Using grid catalog : lfcserver.cnaf.infn.it Source URL: > > > file://home/hephp/brew/9936870.moose.01.root > > > File size: 13033805 > > > VO name: babar > > > Destination specified: > > > > > srm://heplnx204.pp.rl.ac.uk:8443/pnfs/pp.rl.ac.uk/data/babar/brew/test > > > -2 > > > 00610241145 > > > Destination URL for copy: > > > > > gsiftp://heplnx165.pp.rl.ac.uk:2811//pnfs/pp.rl.ac.uk/data/babar/brew/ > > > te > > > st-200610241145 > > > # streams: 1 > > > # set timeout to 0 seconds > > > Alias registered in Catalog: > > > > > lfn:/grid/babar/generated/2006-10-24/file-981c5a78-d7fd-4481-88d4-c8fa > > > 6a > > > a4998f > > > the server sent an error response: 553 553 Permission > > denied, reason: > > > CacheException(rc=2;msg=Pnfs error : failed : File exists) > > > > > > Copy Failed: Unregistering alias from catalog. > > > advisoryDelete(User [name=babar001, uid=37201, gid=24267, > > > root=/],pnfs/pp.rl.ac.uk/data/babar/brew/test-200610241145) > > Error file > > > does not exist, cannot delete > > > > > > I can however srmcp, or globus-url-copy the a file to the same path: > > > > > > heplnx101 - ~ $ srmcp -debug > > > file:////home/hephp/brew/9936870.moose.01.root > > > > > srm://heplnx204.pp.rl.ac.uk:8443/pnfs/pp.rl.ac.uk/data/dteam/brew/test > > > -2 > > > 00610241145 > > > Storage Resource Manager (SRM) CP Client version 1.21 Copyright (c) > > > 2002-2006 Fermi National Accelerator Laboratory > > > > > > SRM Configuration: > > > debug=true > > > gsissl=true > > > help=false > > > pushmode=false > > > userproxy=true > > > buffer_size=131072 > > > tcp_buffer_size=0 > > > streams_num=10 > > > config_file=/home/hephp/brew/.srmconfig/config.xml > > > glue_mapfile=/opt/d-cache/srm/conf/SRMServerV1.map > > > webservice_path=srm/managerv1.wsdl > > > webservice_protocol=https > > > gsiftpclinet=globus-url-copy > > > protocols_list=http,gsiftp > > > save_config_file=null > > > srmcphome=/opt/d-cache/srm > > > urlcopy=/opt/d-cache/srm/sbin/url-copy.sh > > > x509_user_cert=/home/hephp/brew/.globus/usercert.pem > > > x509_user_key=/home/hephp/brew/.globus/userkey.pem > > > x509_user_proxy=/tmp/x509up_u24431 > > > > > x509_user_trusted_certificates=/etc/grid-security/certificates > > > globus_tcp_port_range=null > > > gss_expected_name=null > > > storagetype=permanent > > > retry_num=20 > > > retry_timeout=10000 > > > wsdl_url=null > > > use_urlcopy_script=false > > > connect_to_wsdl=false > > > delegate=true > > > full_delegation=true > > > server_mode=passive > > > srm_protocol_version=1 > > > request_lifetime=86400 > > > from[0]=file:////home/hephp/brew/9936870.moose.01.root > > > > > > > > to=srm://heplnx204.pp.rl.ac.uk:8443/pnfs/pp.rl.ac.uk/data/dteam/brew/t > > > es > > > t-200610241145 > > > > > > Tue Oct 24 12:01:21 BST 2006: starting SRMPutClient Tue Oct 24 > > > 12:01:21 BST 2006: In SRMClient ExpectedName: host Tue Oct > > 24 12:01:21 > > > BST 2006: SRMClient(https,srm/managerv1,true) > > > SRMClientV1 : user credentials are: > > > /C=UK/O=eScience/OU=CLRC/L=RAL/CN=chris dteam brew > > > SRMClientV1 : SRMClientV1 calling > > > org.globus.axis.util.Util.registerTransport() > > > SRMClientV1 : connecting to srm at > > > httpg://heplnx204.pp.rl.ac.uk:8443/srm/managerv1 > > > Tue Oct 24 12:01:22 BST 2006: connected to server, > > obtaining proxy Tue > > > Oct 24 12:01:22 BST 2006: got proxy of type class > > > org.dcache.srm.client.SRMClientV1 > > > Tue Oct 24 12:01:22 BST 2006: source file#0 : > > > /home/hephp/brew/9936870.moose.01.root > > > SRMClientV1 : put, > > > > > sources[0]="srm://heplnx204.pp.rl.ac.uk:8443/pnfs/pp.rl.ac.uk/data/dte > > > am > > > /brew/test-200610241145" > > > SRMClientV1 : put, > > > > > dests[0]="srm://heplnx204.pp.rl.ac.uk:8443/pnfs/pp.rl.ac.uk/data/dteam > > > /b > > > rew/test-200610241145" > > > SRMClientV1 : put, protocols[0]="http" > > > SRMClientV1 : put, protocols[1]="dcap" > > > SRMClientV1 : put, protocols[2]="gsiftp" > > > SRMClientV1 : put, contacting service > > > httpg://heplnx204.pp.rl.ac.uk:8443/srm/managerv1 > > > copy_jobs is empty > > > Tue Oct 24 12:01:26 BST 2006: srm returned requestId = -2146176534 > > > Tue Oct 24 12:01:26 BST 2006: sleeping 1 seconds ... > > > Tue Oct 24 12:01:28 BST 2006: FileRequestStatus with > > > > > SURL=srm://heplnx204.pp.rl.ac.uk:8443/pnfs/pp.rl.ac.uk/data/dteam/brew > > > /t > > > est-200610241145 is Ready > > > Tue Oct 24 12:01:28 BST 2006: received > > > > > TURL=gsiftp://heplnx165.pp.rl.ac.uk:2811//pnfs/pp.rl.ac.uk/data/dteam/ > > > br > > > ew/test-200610241145 > > > copy_jobs is not empty > > > copying CopyJob, source = > > > file:////home/hephp/brew/9936870.moose.01.root > > > destination = > > > > > gsiftp://heplnx165.pp.rl.ac.uk:2811//pnfs/pp.rl.ac.uk/data/dteam/brew/ > > > te > > > st-200610241145 > > > GridftpClient: memory buffer size is set to 131072 > > > GridftpClient: connecting to heplnx165.pp.rl.ac.uk on port 2811 > > > GridftpClient: gridFTPClient tcp buffer size is set to 0 > > > GridftpClient: gridFTPWrite started, source file is > > > java.io.RandomAccessFile@12aea3e destination path is > > > /pnfs/pp.rl.ac.uk/data/dteam/brew/test-200610241145 > > > GridftpClient: gridFTPWrite started, destination path is > > > /pnfs/pp.rl.ac.uk/data/dteam/brew/test-200610241145 > > > GridftpClient: set local data channel authentication mode to None > > > GridftpClient: parallelism: 10 > > > GridftpClient: adler 32 for file java.io.RandomAccessFile@12aea3e is > > > 2932796037 > > > GridftpClient: waiting for completion of transfer > > > GridftpClient: gridFtpWrite: starting the transfer in emode to > > > /pnfs/pp.rl.ac.uk/data/dteam/brew/test-200610241145 > > > GridftpClient: DiskDataSink.close() called > > > GridftpClient: gridFTPWrite() wrote 13033805bytes > > > GridftpClient: closing client : > > > org.dcache.srm.util.GridftpClient$FnalGridFTPClient@141fab6 > > > GridftpClient: closed client > > > execution of CopyJob, source = > > > file:////home/hephp/brew/9936870.moose.01.root destination = > > > > > gsiftp://heplnx165.pp.rl.ac.uk:2811//pnfs/pp.rl.ac.uk/data/dteam/brew/ > > > te > > > st-200610241145 completed > > > setting file request -2146176533 status to Done copy_jobs is empty > > > stopping copier > > > > > > I can't find much in the logs and have restarted everything I can > > > think of without fixing the problem. > > > > > > This is with 1.6.6 > > > > > > Anyone got any ideas? > > > > > > Thanks, > > > Chris. > > > > > > -- ======================================================================= Dr Greig A Cowan http://www.ph.ed.ac.uk/~gcowan1 School of Physics, University of Edinburgh, James Clerk Maxwell Building TIER-2 STORAGE SUPPORT PAGES: http://wiki.gridpp.ac.uk/wiki/Grid_Storage =======================================================================