Hi all,
Are there asynchronous-read cache issues I should know about in 3.1?
The output (debug level = 1) below shows where I issue a ReadV with 71 chunks, sleep for a second (to make sure the server responds), and prints out the contents of the cache.
After printing out the contents of the cache, I immediately read the exact contents of the first few entries of the cache. The client log indicates that it went back out to the server.
The code looks like this:
// Prefetch into the cache (if any).
if (m_client->ReadV(0, &offsets[0], &lengths[0], n) < 0) {
edm::Exception ex(edm::errors::FileReadError);
throw ex;
}
sleep(1);
m_client->GetClientConn()->PrintCache();
// Issue actual reads.
IOSize total = 0;
for (IOSize i = 0; i < n; ++i)
{
int s = m_client->Read(into[i].data(), offsets[i], lengths[i]);
…
The cache/read-ahead settings I used are:
m_client->SetReadAheadStrategy(0);
m_client->SetBlockReadTrimming(0);
m_client->SetCacheParameters(-1, 0, 0);
Anyone see anything "obvious" I'm doing wrong? If no, I'll dig more.
Brian
120222 18:24:01 001 Xrd: ReqReadV: Requesting to read 71 chunks.
120222 18:24:01 001 Xrd: ReqReadV: Returning: total_len 10739731
120222 18:24:01 001 Xrd: ReadV: Excessive async readv size 13424663. Fixing cache size.
120222 18:24:01 16848 Xrd: ProcessUnsolicitedMsg: Incoming unsolicited response from streamid 4
120222 18:24:01 16848 Xrd: ProcessUnsolicitedMsg: Processing async response from streamid 4 father=1
120222 18:24:01 16848 Xrd: ProcessUnsolicitedMsg: Putting kXR_readV data into cache. len 1966240
120222 18:24:01 16848 Xrd: Cache: Submitting 360->196967 to cache.
120222 18:24:01 16848 Xrd: Cache: Submitting 196968->393575 to cache.
120222 18:24:01 16848 Xrd: Cache: Submitting 393576->590183 to cache.
120222 18:24:01 16848 Xrd: Cache: Submitting 590184->786791 to cache.
120222 18:24:01 16848 Xrd: Cache: Submitting 786792->983399 to cache.
120222 18:24:01 16848 Xrd: Cache: Submitting 983400->1180007 to cache.
120222 18:24:01 16848 Xrd: Cache: Submitting 1180008->1376615 to cache.
120222 18:24:01 16848 Xrd: Cache: Submitting 1376616->1573223 to cache.
120222 18:24:01 16848 Xrd: Cache: Submitting 1573224->1769831 to cache.
120222 18:24:01 16848 Xrd: Cache: Submitting 1769832->1966439 to cache.
120222 18:24:01 16848 Xrd: ProcessUnsolicitedMsg: Incoming unsolicited response from streamid 4
120222 18:24:01 16848 Xrd: ProcessUnsolicitedMsg: Processing async response from streamid 4 father=1
120222 18:24:01 16848 Xrd: ProcessUnsolicitedMsg: Putting kXR_readV data into cache. len 1966240
120222 18:24:01 16848 Xrd: Cache: Submitting 1966440->2163047 to cache.
120222 18:24:01 16848 Xrd: Cache: Submitting 2163048->2359655 to cache.
120222 18:24:01 16848 Xrd: Cache: Submitting 2359656->2556263 to cache.
120222 18:24:01 16848 Xrd: Cache: Submitting 2556264->2752871 to cache.
120222 18:24:01 16848 Xrd: Cache: Submitting 2752872->2949479 to cache.
120222 18:24:01 16848 Xrd: Cache: Submitting 2949480->3146087 to cache.
120222 18:24:01 16848 Xrd: Cache: Submitting 3146088->3342695 to cache.
120222 18:24:01 16848 Xrd: Cache: Submitting 3342696->3539303 to cache.
120222 18:24:01 16848 Xrd: Cache: Submitting 3539304->3735911 to cache.
120222 18:24:01 16848 Xrd: Cache: Submitting 3735912->3932519 to cache.
120222 18:24:01 16848 Xrd: ProcessUnsolicitedMsg: Incoming unsolicited response from streamid 4
120222 18:24:01 16848 Xrd: ProcessUnsolicitedMsg: Processing async response from streamid 4 father=1
120222 18:24:01 16848 Xrd: ProcessUnsolicitedMsg: Putting kXR_readV data into cache. len 1997858
120222 18:24:01 16848 Xrd: Cache: Submitting 3932520->4129127 to cache.
120222 18:24:01 16848 Xrd: Cache: Submitting 4129128->4325735 to cache.
120222 18:24:01 16848 Xrd: Cache: Submitting 4325736->4522343 to cache.
120222 18:24:01 16848 Xrd: Cache: Submitting 4522344->4718951 to cache.
120222 18:24:01 16848 Xrd: Cache: Submitting 4718952->4915559 to cache.
120222 18:24:01 16848 Xrd: Cache: Submitting 4915560->5112167 to cache.
120222 18:24:01 16848 Xrd: Cache: Submitting 5112168->5308775 to cache.
120222 18:24:01 16848 Xrd: Cache: Submitting 5308776->5505383 to cache.
120222 18:24:01 16848 Xrd: Cache: Submitting 5505384->5536985 to cache.
120222 18:24:01 16848 Xrd: Cache: Submitting 5537764->5734371 to cache.
120222 18:24:01 16848 Xrd: Cache: Submitting 5734372->5930979 to cache.
120222 18:24:01 16848 Xrd: ProcessUnsolicitedMsg: Incoming unsolicited response from streamid 4
120222 18:24:01 16848 Xrd: ProcessUnsolicitedMsg: Processing async response from streamid 4 father=1
120222 18:24:01 16848 Xrd: ProcessUnsolicitedMsg: Putting kXR_readV data into cache. len 2073502
120222 18:24:01 16848 Xrd: Cache: Submitting 5930980->6127587 to cache.
120222 18:24:01 16848 Xrd: Cache: Submitting 6127588->6324195 to cache.
120222 18:24:01 16848 Xrd: Cache: Submitting 6324196->6520803 to cache.
120222 18:24:01 16848 Xrd: Cache: Submitting 6520804->6717411 to cache.
120222 18:24:01 16848 Xrd: Cache: Submitting 6717412->6914019 to cache.
120222 18:24:01 16848 Xrd: Cache: Submitting 6914020->7085720 to cache.
120222 18:24:01 16848 Xrd: Cache: Submitting 7216971->7217663 to cache.
120222 18:24:01 16848 Xrd: Cache: Submitting 7360659->7467076 to cache.
120222 18:24:01 16848 Xrd: Cache: Submitting 7519223->7519932 to cache.
120222 18:24:01 16848 Xrd: Cache: Submitting 7600901->7797508 to cache.
120222 18:24:01 16848 Xrd: Cache: Submitting 7797509->7977539 to cache.
120222 18:24:01 16848 Xrd: Cache: Submitting 8262674->8265352 to cache.
120222 18:24:01 16848 Xrd: Cache: Submitting 8446084->8446711 to cache.
120222 18:24:01 16848 Xrd: Cache: Submitting 8481421->8482683 to cache.
120222 18:24:01 16848 Xrd: Cache: Submitting 8893583->8907505 to cache.
120222 18:24:01 16848 Xrd: Cache: Submitting 9007528->9204135 to cache.
120222 18:24:01 16848 Xrd: Cache: Submitting 9204136->9400743 to cache.
120222 18:24:01 16848 Xrd: Cache: Submitting 9400744->9423047 to cache.
120222 18:24:01 16848 Xrd: ProcessUnsolicitedMsg: Incoming unsolicited response from streamid 4
120222 18:24:01 16848 Xrd: ProcessUnsolicitedMsg: Processing async response from streamid 4 father=1
120222 18:24:01 16848 Xrd: ProcessUnsolicitedMsg: Putting kXR_readV data into cache. len 1954115
120222 18:24:01 16848 Xrd: Cache: Submitting 9695526->9888175 to cache.
120222 18:24:01 16848 Xrd: Cache: Submitting 9956070->10024962 to cache.
120222 18:24:01 16848 Xrd: Cache: Submitting 10659786->10856393 to cache.
120222 18:24:01 16848 Xrd: Cache: Submitting 10856394->10944615 to cache.
120222 18:24:01 16848 Xrd: Cache: Submitting 10944945->11141552 to cache.
120222 18:24:01 16848 Xrd: Cache: Submitting 11141553->11338160 to cache.
120222 18:24:01 16848 Xrd: Cache: Submitting 11338161->11389968 to cache.
120222 18:24:01 16848 Xrd: Cache: Submitting 11547044->11547186 to cache.
120222 18:24:01 16848 Xrd: Cache: Submitting 11592419->11624884 to cache.
120222 18:24:01 16848 Xrd: Cache: Submitting 11671050->11867657 to cache.
120222 18:24:01 16848 Xrd: Cache: Submitting 11867658->12064265 to cache.
120222 18:24:01 16848 Xrd: Cache: Submitting 12064266->12071205 to cache.
120222 18:24:01 16848 Xrd: Cache: Submitting 12208733->12208882 to cache.
120222 18:24:01 16848 Xrd: Cache: Submitting 12260125->12456732 to cache.
120222 18:24:01 16848 Xrd: Cache: Submitting 12456733->12653340 to cache.
120222 18:24:01 16848 Xrd: Cache: Submitting 12653341->12789671 to cache.
120222 18:24:01 16848 Xrd: ProcessUnsolicitedMsg: Incoming unsolicited response from streamid 4
120222 18:24:01 16848 Xrd: ProcessUnsolicitedMsg: Processing async response from streamid 4 father=1
120222 18:24:01 16848 Xrd: ProcessUnsolicitedMsg: Putting kXR_readV data into cache. len 782912
120222 18:24:01 16848 Xrd: Cache: Submitting 12835083->13013821 to cache.
120222 18:24:01 16848 Xrd: Cache: Submitting 13082309->13278916 to cache.
120222 18:24:01 16848 Xrd: Cache: Submitting 13278917->13475524 to cache.
120222 18:24:01 16848 Xrd: Cache: Submitting 13475525->13538864 to cache.
120222 18:24:01 16848 Xrd: Cache: Submitting 13562322->13583340 to cache.
120222 18:24:01 16848 Xrd: Cache: Submitting 13583511->13710012 to cache.
120222 18:24:02 001 Xrd: Cache: Cache Status --------------------------
120222 18:24:02 001 Xrd: Cache blk: 0Data block 360->196967
120222 18:24:02 001 Xrd: Cache blk: 1Data block 196968->393575
120222 18:24:02 001 Xrd: Cache blk: 2Data block 393576->590183
120222 18:24:02 001 Xrd: Cache blk: 3Data block 590184->786791
120222 18:24:02 001 Xrd: Cache blk: 4Data block 786792->983399
120222 18:24:02 001 Xrd: Cache blk: 5Data block 983400->1180007
120222 18:24:02 001 Xrd: Cache blk: 6Data block 1180008->1376615
120222 18:24:02 001 Xrd: Cache blk: 7Data block 1376616->1573223
120222 18:24:02 001 Xrd: Cache blk: 8Data block 1573224->1769831
120222 18:24:02 001 Xrd: Cache blk: 9Data block 1769832->1966439
120222 18:24:02 001 Xrd: Cache blk: 10Data block 1966440->2163047
120222 18:24:02 001 Xrd: Cache blk: 11Data block 2163048->2359655
120222 18:24:02 001 Xrd: Cache blk: 12Data block 2359656->2556263
120222 18:24:02 001 Xrd: Cache blk: 13Data block 2556264->2752871
120222 18:24:02 001 Xrd: Cache blk: 14Data block 2752872->2949479
120222 18:24:02 001 Xrd: Cache blk: 15Data block 2949480->3146087
120222 18:24:02 001 Xrd: Cache blk: 16Data block 3146088->3342695
120222 18:24:02 001 Xrd: Cache blk: 17Data block 3342696->3539303
120222 18:24:02 001 Xrd: Cache blk: 18Data block 3539304->3735911
120222 18:24:02 001 Xrd: Cache blk: 19Data block 3735912->3932519
120222 18:24:02 001 Xrd: Cache blk: 20Data block 3932520->4129127
120222 18:24:02 001 Xrd: Cache blk: 21Data block 4129128->4325735
120222 18:24:02 001 Xrd: Cache blk: 22Data block 4325736->4522343
120222 18:24:02 001 Xrd: Cache blk: 23Data block 4522344->4718951
120222 18:24:02 001 Xrd: Cache blk: 24Data block 4718952->4915559
120222 18:24:02 001 Xrd: Cache blk: 25Data block 4915560->5112167
120222 18:24:02 001 Xrd: Cache blk: 26Data block 5112168->5308775
120222 18:24:02 001 Xrd: Cache blk: 27Data block 5308776->5505383
120222 18:24:02 001 Xrd: Cache blk: 28Data block 5505384->5536985
120222 18:24:02 001 Xrd: Cache blk: 29Data block 5537764->5734371
120222 18:24:02 001 Xrd: Cache blk: 30Data block 5734372->5930979
120222 18:24:02 001 Xrd: Cache blk: 31Data block 5930980->6127587
120222 18:24:02 001 Xrd: Cache blk: 32Data block 6127588->6324195
120222 18:24:02 001 Xrd: Cache blk: 33Data block 6324196->6520803
120222 18:24:02 001 Xrd: Cache blk: 34Data block 6520804->6717411
120222 18:24:02 001 Xrd: Cache blk: 35Data block 6717412->6914019
120222 18:24:02 001 Xrd: Cache blk: 36Data block 6914020->7085720
120222 18:24:02 001 Xrd: Cache blk: 37Data block 7216971->7217663
120222 18:24:02 001 Xrd: Cache blk: 38Data block 7360659->7467076
120222 18:24:02 001 Xrd: Cache blk: 39Data block 7519223->7519932
120222 18:24:02 001 Xrd: Cache blk: 40Data block 7600901->7797508
120222 18:24:02 001 Xrd: Cache blk: 41Data block 7797509->7977539
120222 18:24:02 001 Xrd: Cache blk: 42Data block 8262674->8265352
120222 18:24:02 001 Xrd: Cache blk: 43Data block 8446084->8446711
120222 18:24:02 001 Xrd: Cache blk: 44Data block 8481421->8482683
120222 18:24:02 001 Xrd: Cache blk: 45Data block 8893583->8907505
120222 18:24:02 001 Xrd: Cache blk: 46Data block 9007528->9204135
120222 18:24:02 001 Xrd: Cache blk: 47Data block 9204136->9400743
120222 18:24:02 001 Xrd: Cache blk: 48Data block 9400744->9423047
120222 18:24:02 001 Xrd: Cache blk: 49Data block 9695526->9888175
120222 18:24:02 001 Xrd: Cache blk: 50Data block 9956070->10024962
120222 18:24:02 001 Xrd: Cache blk: 51Data block 10659786->10856393
120222 18:24:02 001 Xrd: Cache blk: 52Data block 10856394->10944615
120222 18:24:02 001 Xrd: Cache blk: 53Data block 10944945->11141552
120222 18:24:02 001 Xrd: Cache blk: 54Data block 11141553->11338160
120222 18:24:02 001 Xrd: Cache blk: 55Data block 11338161->11389968
120222 18:24:02 001 Xrd: Cache blk: 56Data block 11547044->11547186
120222 18:24:02 001 Xrd: Cache blk: 57Data block 11592419->11624884
120222 18:24:02 001 Xrd: Cache blk: 58Data block 11671050->11867657
120222 18:24:02 001 Xrd: Cache blk: 59Data block 11867658->12064265
120222 18:24:02 001 Xrd: Cache blk: 60Data block 12064266->12071205
120222 18:24:02 001 Xrd: Cache blk: 61Data block 12208733->12208882
120222 18:24:02 001 Xrd: Cache blk: 62Data block 12260125->12456732
120222 18:24:02 001 Xrd: Cache blk: 63Data block 12456733->12653340
120222 18:24:02 001 Xrd: Cache blk: 64Data block 12653341->12789671
120222 18:24:02 001 Xrd: Cache blk: 65Data block 12835083->13013821
120222 18:24:02 001 Xrd: Cache blk: 66Data block 13082309->13278916
120222 18:24:02 001 Xrd: Cache blk: 67Data block 13278917->13475524
120222 18:24:02 001 Xrd: Cache blk: 68Data block 13475525->13538864
120222 18:24:02 001 Xrd: Cache blk: 69Data block 13562322->13583340
120222 18:24:02 001 Xrd: Cache blk: 70Data block 13583511->13710012
120222 18:24:02 001 Xrd: Cache: -------------------------------------- fTotalByteCount = 10739731
120222 18:24:02 001 Xrd: Read: Read(offs=360, len=5536626)
120222 18:24:02 001 Xrd: SendGenCommand: Sending command ReadBuffer
120222 18:24:02 001 Xrd: ReadPartialAnswer: Reading a XrdClientMessage from the server [cmsstor168.fnal.gov:1093]...
120222 18:24:02 001 Xrd: Cache: Submitting 360->2097511 to cache.
########################################################################
Use REPLY-ALL to reply to list
To unsubscribe from the XROOTD-DEV list, click the following link:
https://listserv.slac.stanford.edu/cgi-bin/wa?SUBED1=XROOTD-DEV&A=1
