Ok, thanks for the info.

   Lukasz

On Tue, Oct 19, 2010 at 11:07 AM, Brian Bockelman <[log in to unmask]> wrote:
> Hi Lukasz,
>
> I don't think we were able to determine anything solid (besides it was broken...) - the CMSSW client is old, and it's not clear whether this bug exists in current versions.
>
> Brian
>
> On Oct 19, 2010, at 5:05 PM, Lukasz Janyst wrote:
>
>> Hi Brian, Andy,
>>
>>   I am back from holidays now. Is this issue closed?
>>
>> Cheers,
>>   Lukasz
>>
>> On Sat, Oct 9, 2010 at 12:11 AM, Brian Bockelman <[log in to unmask]> wrote:
>>>
>>> On Oct 8, 2010, at 4:54 PM, Andrew Hanushevsky wrote:
>>>
>>>> Hi Brian,
>>>>
>>>> One more thing, could you answer the following:
>>>> a) Client release being used,
>>>
>>> 20090727.1318
>>>
>>> This is the default for CMSSW.
>>>
>>>> b) Read cache size being used,
>>>
>>> Default for the release.
>>>
>>>> c) Read-ahead size being used.
>>>
>>> Default for the release.
>>>
>>> brian
>>>
>>>>
>>>> Andy
>>>>
>>>> On Fri, 8 Oct 2010, Brian Bockelman wrote:
>>>>
>>>>> Hi Andy,
>>>>>
>>>>> Is there a way to do that via ~/.rootrc?  I've only got a few limited hooks into the workload software itself - just ~/.rootrc and environment variables are at my disposal.
>>>>>
>>>>> Brian
>>>>>
>>>>> On Oct 8, 2010, at 3:23 PM, Andrew Hanushevsky wrote:
>>>>>
>>>>>> Hi Brian,
>>>>>>
>>>>>> I can look at this while Lukasz is taking some vacation. Your immediate bypass is to increase the connection timeout to something relatively large so this problem is not encountered to begin with (the assumption is that the closing of an idle connection and later reopening it triggers the problem). The variable name is "DataServerConn_ttl" (the current default is 5 minutes).
>>>>>>
>>>>>> Andy
>>>>>>
>>>>>> On Fri, 8 Oct 2010, Brian Bockelman wrote:
>>>>>>
>>>>>>> Hi Andy,
>>>>>>>
>>>>>>> Nope, this is a user analysis job running on EC2.  The job is ntuple-like and runs at about 1KHz.  So, each file takes about 2 minutes to process and the connection is trashed by the client in the "normal" manner after a few minutes.
>>>>>>>
>>>>>>> The sequence, as far as I can tell is:
>>>>>>>
>>>>>>> 1) Client reads file from red-gridftp9.
>>>>>>> 2) About 5 minutes after the file is closed and the connection idles, the client disconnects
>>>>>>> 3) Later on, the client hits another file at red-gridftp9.
>>>>>>> 4) Client instructs red-gridftp9 to close the session.  red-gridftp9 says "no such session".
>>>>>>> 5) Client continues to puke error messages once a second, regardless if there are any outstanding requests.
>>>>>>>
>>>>>>> Note that the first two dumps below have the following error message:
>>>>>>>
>>>>>>>>> Xrd: Read: Timeout or error waiting outstanding blocks. Retrying sync! List of outstanding reqs follows
>>>>>>>
>>>>>>> but the list of requests are empty!
>>>>>>>
>>>>>>> Brian
>>>>>>>
>>>>>>> On Oct 8, 2010, at 3:06 PM, Andrew Hanushevsky wrote:
>>>>>>>
>>>>>>>> Hi Brian,
>>>>>>>>
>>>>>>>> Looks like the client starts to hiccup every 7 minutes on the dot. The endsess is a normal part of the reconnect process and a recommendation in the protocol. The reason that the previous session wasn't found is that the client actually disconnected ending the previous session. I assume the reason is that the client thinks the server is not responding and so it tries to simply reconnect. It would seem that the client lost several blocks that it wanted to transfer. I assume this is related to xtreme copy.
>>>>>>>>
>>>>>>>> Andy
>>>>>>>>
>>>>>>>> On Fri, 8 Oct 2010, Brian Bockelman wrote:
>>>>>>>>
>>>>>>>>> Hi all,
>>>>>>>>>
>>>>>>>>> I'm seeing some issues with xrootd in CMSSW jobs that are causing severe performance issues.  See below for a snippet from the client and relevant server.
>>>>>>>>>
>>>>>>>>> It seems that the client is trying to end a previously terminated security session and, after this happens the first time, I always get these "Timeout or error waiting on outstanding blocks".  This happens about every second of a multi-hour job, making the log file a touch verbose.
>>>>>>>>>
>>>>>>>>> In this case, the client was talking to red-gridftp9.  I tried a few test transfers, and the server is otherwise responsive (although by no means idle, xrootd is exporting about 4Gbps today).
>>>>>>>>>
>>>>>>>>> Any ideas?  I've only seen these timeout issues when there's the server error.  My search has not been exhaustive, so it could just be a coincidence.
>>>>>>>>>
>>>>>>>>> Brian
>>>>>>>>>
>>>>>>>>> 101008 11:32:41 001 Xrd: CheckErrorStatus: Server declared: session not found(error code: 3011)
>>>>>>>>> 101008 11:32:41 001 Xrd: Open: File opened succesfully.
>>>>>>>>> 08-Oct-2010 11:32:42 CDT  Successfully opened file root://xrootd.unl.edu//store/data/Run2010A/JetMETTau/RECO/Sep17ReReco_v2/0051/BC729A70-BEC6-DF11-AFF4-0018F3D096EE.root
>>>>>>>>> 101008 11:32:48 001 Xrd: Read: Timeout or error waiting outstanding blocks. Retrying sync! List of outstanding reqs follows.
>>>>>>>>> -------------------------------------------------- start outstanding reqs dump. freesids: 65533
>>>>>>>>> ++++++++++++++++++++++++++++++++++++++++++++++++++++ end  outstanding reqs dump.
>>>>>>>>> 101008 11:32:48 001 Xrd: Read: Timeout or error waiting outstanding blocks. Retrying sync! List of outstanding reqs follows.
>>>>>>>>> -------------------------------------------------- start outstanding reqs dump. freesids: 65533
>>>>>>>>> ++++++++++++++++++++++++++++++++++++++++++++++++++++ end  outstanding reqs dump.
>>>>>>>>> 101008 11:32:48 001 Xrd: Read: Timeout or error waiting outstanding blocks. Retrying sync! List of outstanding reqs follows.
>>>>>>>>> -------------------------------------------------- start outstanding reqs dump. freesids: 65532
>>>>>>>>>
>>>>>>>>>
>>>>>>>>> ================= DUMPING CLIENT REQUEST HEADER =================
>>>>>>>>>             ClientHeader.streamid = 0x75 0x0d
>>>>>>>>>            ClientHeader.requestid = kXR_read (3013)
>>>>>>>>>         ClientHeader.read.fhandle = 0x00 0x00 0x00 0x00
>>>>>>>>>          ClientHeader.read.offset = 11937606541
>>>>>>>>>            ClientHeader.read.rlen = 562291
>>>>>>>>>          ClientHeader.header.dlen = 0
>>>>>>>>> =================== END CLIENT HEADER DUMPING ===================
>>>>>>>>>
>>>>>>>>> ++++++++++++++++++++++++++++++++++++++++++++++++++++ end  outstanding reqs dump.
>>>>>>>>>
>>>>>>>>> [root@red-gridftp9 ~]# grep glidein_.10759 /var/log/xrootd/xrootd.log
>>>>>>>>> 101008 11:33:20 8224 glidein_.10759:[log in to unmask] XrootdProtocol: more auth requested; sz=2082
>>>>>>>>> 101008 11:33:20 8224 XrootdXeq: glidein_.10759:[log in to unmask] login as 92a2e9e2.0
>>>>>>>>> 101008 11:33:20 8224 acc_Audit: glidein_.10759:[log in to unmask] grant gsi [log in to unmask] read /store/data/Run2010A/JetMETTau/RECO/Sep17ReReco_v2/0050/D6E7ADBB-B7C6-DF11-AFC6-002618943975.root
>>>>>>>>> 101008 11:40:24 8224 XrootdXeq: glidein_.10759:[log in to unmask] disc 0:07:04
>>>>>>>>> 101008 12:26:57 8224 glidein_.10759:[log in to unmask] XrootdProtocol: more auth requested; sz=2082
>>>>>>>>> 101008 12:26:58 8224 XrootdXeq: glidein_.10759:[log in to unmask] login as 92a2e9e2.0
>>>>>>>>> 101008 12:26:58 8224 glidein_.10759:[log in to unmask] XrootdProtocol: endsess 8222:371.14718
>>>>>>>>> 101008 12:26:58 8224 glidein_.10759:[log in to unmask] XrootdProtocol: endsess 8222:371.14718 rc=-3 (No such process)
>>>>>>>>> 101008 12:26:58 8224 glidein_.10759:[log in to unmask] XrootdResponse: sending err 3011: session not found
>>>>>>>>> 101008 12:26:58 8224 acc_Audit: glidein_.10759:[log in to unmask] grant gsi [log in to unmask] read /store/data/Run2010A/JetMETTau/RECO/Sep17ReReco_v2/0050/E62D2728-B8C6-DF11-8E71-0018F3D0962C.root
>>>>>>>>> 101008 12:33:59 8224 XrootdXeq: glidein_.10759:[log in to unmask] disc 0:07:02
>>>>>>>>> 101008 12:56:01 8224 glidein_.10759:[log in to unmask] XrootdProtocol: more auth requested; sz=2082
>>>>>>>>> 101008 12:56:01 8224 XrootdXeq: glidein_.10759:[log in to unmask] login as 92a2e9e2.0
>>>>>>>>> 101008 12:56:01 8224 glidein_.10759:[log in to unmask] XrootdProtocol: endsess 8222:451.14760
>>>>>>>>> 101008 12:56:01 8224 glidein_.10759:[log in to unmask] XrootdProtocol: endsess 8222:451.14760 rc=-3 (No such process)
>>>>>>>>> 101008 12:56:01 8224 glidein_.10759:[log in to unmask] XrootdResponse: sending err 3011: session not found
>>>>>>>>> 101008 12:56:01 8224 acc_Audit: glidein_.10759:[log in to unmask] grant gsi [log in to unmask] read /store/data/Run2010A/JetMETTau/RECO/Sep17ReReco_v2/0047/884E3212-6AC6-DF11-B1C9-0026189438AF.root
>>>>>>>>>
>>>>>>>>>
>>>>>>>
>>>>>>>
>>>>>
>>>>>
>>>
>>>
>>>
>
>