LISTSERV mailing list manager LISTSERV 16.5

Help for XROOTD-L Archives


XROOTD-L Archives

XROOTD-L Archives


XROOTD-L@LISTSERV.SLAC.STANFORD.EDU


View:

Message:

[

First

|

Previous

|

Next

|

Last

]

By Topic:

[

First

|

Previous

|

Next

|

Last

]

By Author:

[

First

|

Previous

|

Next

|

Last

]

Font:

Proportional Font

LISTSERV Archives

LISTSERV Archives

XROOTD-L Home

XROOTD-L Home

XROOTD-L  September 2019

XROOTD-L September 2019

Subject:

Re: Uploaded file 128TB on filesystem

From:

Mario Lassnig <[log in to unmask]>

Reply-To:

[log in to unmask]

Date:

Thu, 5 Sep 2019 08:38:17 +0200

Content-Type:

text/plain

Parts/Attachments:

Parts/Attachments

text/plain (540 lines)

Hi Petr, Andy,

once extra piece of information here: Rucio uses the python bindings to
the gfal library to upload these files, and de-facto always uses the
current stable gfal version that is published on ALRB. Rucio doesn't
implement any other upload by itself.

Cheers,
Mario

On 05/09/2019 04:21, Andrew Hanushevsky wrote:
> Hi Petr,
>  
> So, look at this line:
>  
> 190904 17:02:16 22915 atlasprd.2817:152@[2001:718:401:6e03::1:82]
> ofs_write: 1784104010@6506989258351653185
> fn=/dpm/farm.particle.cz/home/atlas/atlasdatadisk/rucio/mc15_5TeV/90/9f/EVNT.18960107._035789.pool.root.1.rucio.upload
> Why did the application doing the write specify an offset of
> 5506989258351653185? So, that is the problem and, as you noted, it
> doesn’t matter whether POSC is on or not. Indeed, it’s the first write
> to the file and only the first write that suffers from this problem. So,
> there are two possibilities here: a) there is a bug in the uploader, or
> b) there was a network data corruption that managed to hit the offset
> (somewhat unlikely).
>  
> Andy
>  
> *From:* Petr Vokac <mailto:[log in to unmask]>
> *Sent:* Wednesday, September 04, 2019 12:19 PM
> *To:* Andrew Hanushevsky <mailto:[log in to unmask]>
> *Cc:* dpm-devel <mailto:[log in to unmask]> ; [log in to unmask]
> <mailto:[log in to unmask]>
> *Subject:* Re: Uploaded file 128TB on filesystem
>  
> I configured our diskservers with "ofs.trace write" (I did not yet add
> in xrootd configuraton "ofs.persist hold 0") and today new file appeared
> on one of our storage servers:
> 
> *[root@dpmpool1 ~]# grep atlasprd.2817:152
> /var/log/xrootd/dpmdisk/xrootd.log*
> 190904 17:02:08 1894 XrootdXeq: atlasprd.2817:152@[2001:718:401:6e03::1:82] pub IP64 login as /DC=ch/DC=cern/OU=Organic Units/OU=Users/CN=atlpilo1/CN=614260/CN=Robot: ATLAS Pilot1
> 190904 17:02:16 22915 atlasprd.2817:152@[2001:718:401:6e03::1:82] ofs_write: 1784104010@6506989258351653185 fn=/dpm/farm.particle.cz/home/atlas/atlasdatadisk/rucio/mc15_5TeV/90/9f/EVNT.18960107._035789.pool.root.1.rucio.upload
> 190904 17:02:16 22915 atlasprd.2817:152@[2001:718:401:6e03::1:82] ofs_write: 262144@262144 fn=/dpm/farm.particle.cz/home/atlas/atlasdatadisk/rucio/mc15_5TeV/90/9f/EVNT.18960107._035789.pool.root.1.rucio.upload
> 190904 17:02:17 22915 atlasprd.2817:152@[2001:718:401:6e03::1:82] ofs_write: 262144@524288 fn=/dpm/farm.particle.cz/home/atlas/atlasdatadisk/rucio/mc15_5TeV/90/9f/EVNT.18960107._035789.pool.root.1.rucio.upload
> 190904 17:02:17 22915 atlasprd.2817:152@[2001:718:401:6e03::1:82] ofs_write: 262144@786432 fn=/dpm/farm.particle.cz/home/atlas/atlasdatadisk/rucio/mc15_5TeV/90/9f/EVNT.18960107._035789.pool.root.1.rucio.upload
> 190904 17:02:17 22915 atlasprd.2817:152@[2001:718:401:6e03::1:82] ofs_write: 262144@1048576 fn=/dpm/farm.particle.cz/home/atlas/atlasdatadisk/rucio/mc15_5TeV/90/9f/EVNT.18960107._035789.pool.root.1.rucio.upload
> 190904 17:02:17 22915 atlasprd.2817:152@[2001:718:401:6e03::1:82] ofs_write: 262144@1310720 fn=/dpm/farm.particle.cz/home/atlas/atlasdatadisk/rucio/mc15_5TeV/90/9f/EVNT.18960107._035789.pool.root.1.rucio.upload
> 190904 17:02:17 22915 atlasprd.2817:152@[2001:718:401:6e03::1:82] ofs_write: 262144@1572864 fn=/dpm/farm.particle.cz/home/atlas/atlasdatadisk/rucio/mc15_5TeV/90/9f/EVNT.18960107._035789.pool.root.1.rucio.upload
> 190904 17:02:17 22915 atlasprd.2817:152@[2001:718:401:6e03::1:82] ofs_write: 262144@1835008 fn=/dpm/farm.particle.cz/home/atlas/atlasdatadisk/rucio/mc15_5TeV/90/9f/EVNT.18960107._035789.pool.root.1.rucio.upload
> 190904 17:02:17 22915 atlasprd.2817:152@[2001:718:401:6e03::1:82] ofs_write: 135000@2097152 fn=/dpm/farm.particle.cz/home/atlas/atlasdatadisk/rucio/mc15_5TeV/90/9f/EVNT.18960107._035789.pool.root.1.rucio.upload
> 190904 17:07:32 2163 XrootdXeq: atlasprd.2817:152@[2001:718:401:6e03::1:82] disc 0:05:24
> 
> *[root@dpmpool1 ~]# ls -la
> /mnt/fs2/atlas/2019-09-04/EVNT.18960107._035789.pool.root.1.rucio.upload.309650.1567609328*
> -rw-rw---- 1 dpmmgr dpmmgr 6506989258351919104 Sep  4 17:02 /mnt/fs2/atlas/2019-09-04/EVNT.18960107._035789.pool.root.1.rucio.upload.309650.1567609328
> 
> *[root@dpmpool1 ~]# du --block-size=1
> /mnt/fs2/atlas/2019-09-04/EVNT.18960107._035789.pool.root.1.rucio.upload.309650.1567609328*
> 2236416	/mnt/fs2/atlas/2019-09-04/EVNT.18960107._035789.pool.root.1.rucio.upload.309650.1567609328
> 
> This file has first 256kb filled with 0x00 (adler32 up to original size
> 2232152 doesn't match) and this time there is no ofs_Posc in the
> xrootd.log file.
> 
> Petr Vokac
> 
> On 8/19/19 3:24 AM, Andrew Hanushevsky wrote:
>> Hi Petr,
>>
>> The issue here is that the python script (I believe it's python) is
>> disconnecting without closing the file and then reconnecting and
>> writing at a high offset. The log is pretty clear on that. You can
>> verify by adding "ofs.trace write" to see the write offsets (hough it
>> will produce a lot of output). You can also prohibit reconnection by
>> adding this to the persist directive.
>>
>> ofs.persist hold 0
>>
>> which would delete the file the moment the client disconnects without
>> closing the file.
>>
>> Andy
>>
>> On Sat, 17 Aug 2019, Petr Vokac wrote:
>>
>>> Today new "65PB" file appeared on our storage and it was again
>>> transferred with xrootd protocol. I can see again same error in the log
>>> file:
>>>
>>> **[root@dpmpool21 ~]# ls -la
>>> /mnt/fs4/atlas/2019-08-17/EVNT.18893579._003197.pool.root.1.rucio.upload.234855.1566031522*
>>>
>>> *-rw-rw---- 1 dpmmgr dpmmgr 72340172838077281 Aug 17 10:48
>>> /mnt/fs4/atlas/2019-08-17/EVNT.18893579._003197.pool.root.1.rucio.upload.234855.1566031522
>>> ***[root@dpmpool21 ~]# grep atlasprd.2757
>>> /var/log/xrootd/dpmdisk/xrootd.log*
>>> ...
>>> 190817 10:47:55 57803 XrootdXeq:
>>> atlasprd.2757:65@[2001:718:401:6e03::1:43] pub IP64 login as
>>> /DC=ch/DC=cern/OU=Organic
>>> Units/OU=Users/CN=atlpilo1/CN=614260/CN=Robot: ATLAS Pilot1
>>> 190817 10:47:55 61859 XrootdXeq:
>>> atlasprd.2757:66@[2001:718:401:6e03::1:83] pub IP64 login as
>>> /DC=ch/DC=cern/OU=Organic
>>> Units/OU=Users/CN=atlpilo1/CN=614260/CN=Robot: ATLAS Pilot1
>>> 190817 10:48:52 62233 XrootdXeq:
>>> atlasprd.2757:46@[2001:718:401:6e03::1:72] disc 0:00:58
>>> 190817 10:48:52 62954 XrootdXeq:
>>> atlasprd.2757:25@[2001:718:401:6e03::1:72] disc 0:03:30
>>> 190817 10:48:52 57804 XrootdXeq:
>>> atlasprd.2757:28@[2001:718:401:6e03::1:72] pub IP64 login as
>>> /DC=ch/DC=cern/OU=Organic
>>> Units/OU=Users/CN=atlpilo1/CN=614260/CN=Robot: ATLAS Pilot1
>>> 190817 10:48:52 57804 ofs_Posc: Creator changed from
>>> atlasprd.2757:25@[2001:718:401:6e03::1:72] to
>>> atlasprd.2757:28@[2001:718:401:6e03::1:72] for
>>> /dpm/farm.particle.cz/home/atlas/atlasdatadisk/rucio/mc15_13TeV/8b/f3/EVNT.18893579._003197.pool.root.1.rucio.upload
>>> 190817 10:48:53 57803 XrootdXeq:
>>> atlasprd.2757:46@[2001:718:401:6017:20:0:14:44] pub IP64 login as
>>> /DC=ch/DC=cern/OU=Organic
>>> Units/OU=Users/CN=atlpilo1/CN=614260/CN=Robot: ATLAS Pilot1
>>> 190817 10:49:01 57818 XrootdXeq:
>>> atlasprd.2757:70@[2001:718:401:6017:20:0:11:11] pub IP64 login as
>>> /DC=ch/DC=cern/OU=Organic
>>> Units/OU=Users/CN=atlpilo1/CN=614260/CN=Robot: ATLAS Pilot1
>>> 190817 10:49:07 62954 XrootdXeq:
>>> atlasprd.2757:55@[2001:718:401:6e03::1:81] disc 0:10:17
>>> ...
>>>
>>> Any suggestion how to trace what is causing this behavior?
>>>
>>> Petr
>>>
>>>
>>> On 7/20/19 7:48 AM, Petr Vokac wrote:
>>>> Hi,
>>>>
>>>> I ran the command you sent me
>>>>
>>>> grep "atlasprd.2757:" <logfile> | egrep 
>>>> '2001:718:401:6e03::1:21|2001:718:401:6e03::1:32' > <excerpt>
>>>>
>>>> and because the output was not just few lines long I uploaded it to the
>>>>
>>>> https://vokac.web.cern.ch/vokac/tmp/dpmpool22.xrootd.log
>>>> https://vokac.web.cern.ch/vokac/tmp/dpmpool24.xrootd.log
>>>>
>>>> These machines on 2001:718:401:6e03::/64 subnet are in remote location
>>>> (but relatively close with RTT ~ 0.7ms). I can see several ofs_Posc
>>>> occurrences in the logs of our disknodes during "190717 17:xx:xx" time
>>>> period:
>>>>
>>>> http://vokac.web.cern.ch/vokac/tmp/POSC.txt
>>>>
>>>> Petr
>>>>
>>>> On 7/19/19 8:51 PM, Andrew Hanushevsky wrote:
>>>>> Hi Petr,
>>>>>
>>>>> Well, POSC says that the client reconnected for writing so not all
>>>>> went well. Can I get the log output for that occurrence as I
>>>>> previously described?
>>>>>
>>>>> Andy
>>>>>
>>>>> On Fri, 19 Jul 2019, Petr Vokac wrote:
>>>>>
>>>>>> We are using Rucio download client to transfer job outputs (it is
>>>>>> build
>>>>>> on top of gfal2 python interface).
>>>>>>
>>>>>> https://vokac.web.cern.ch/vokac/tmp/dpmpool22.xrootd.log
>>>>>> https://vokac.web.cern.ch/vokac/tmp/dpmpool24.xrootd.log
>>>>>>
>>>>>> this is the full job output unfortunately with minimal gfal2 logging
>>>>>> output.
>>>>>>
>>>>>> https://vokac.web.cern.ch/vokac/tmp/grid.2258136.4.out-from-2001:718:401:6e03::1:21-to-dpmpool22.txt
>>>>>>
>>>>>>
>>>>>> https://vokac.web.cern.ch/vokac/tmp/grid.2255921.7.out-from-2001:718:401:6e03::1:32-to-dpmpool24.txt
>>>>>>
>>>>>>
>>>>>>
>>>>>> It looks like according gfal2 transfer was OK
>>>>>>
>>>>>> 2019-07-17 15:09:17,782 | INFO     | copytool_out        |
>>>>>> gfal2                            | connect                   |
>>>>>> [gfal_module_load] plugin
>>>>>> /usr/lib64/gfal2-plugins//libgfal_plugin_xrootd.so loaded with
>>>>>> success
>>>>>> 2019-07-17 15:09:17,782 | INFO     | copytool_out        |
>>>>>> gfal2                            | connect                   |
>>>>>> [gfal_module_load] plugin
>>>>>> /usr/lib64/gfal2-plugins//libgfal_plugin_rfio.so loaded with success
>>>>>> 2019-07-17 15:09:17,783 | INFO     | copytool_out        |
>>>>>> gfal2                            | connect                   |
>>>>>> [gfal_module_load] plugin
>>>>>> /usr/lib64/gfal2-plugins//libgfal_plugin_gridftp.so loaded with
>>>>>> success
>>>>>> 2019-07-17 15:09:17,783 | INFO     | copytool_out        |
>>>>>> gfal2                            | connect                   |
>>>>>> [gfal_module_load] plugin
>>>>>> /usr/lib64/gfal2-plugins//libgfal_plugin_http.so loaded with success
>>>>>> 2019-07-17 15:09:17,783 | INFO     | copytool_out        |
>>>>>> gfal2                            | connect                   |
>>>>>> [gfal_module_load] plugin
>>>>>> /usr/lib64/gfal2-plugins//libgfal_plugin_lfc.so loaded with success
>>>>>> 2019-07-17 15:09:17,783 | INFO     | copytool_out        |
>>>>>> gfal2                            | connect                   |
>>>>>> [gfal_module_load] plugin
>>>>>> /usr/lib64/gfal2-plugins//libgfal_plugin_file.so loaded with success
>>>>>> 2019-07-17 15:09:17,784 | INFO     | copytool_out        |
>>>>>> gfal2                            | connect                   |
>>>>>> [gfal_module_load] plugin
>>>>>> /usr/lib64/gfal2-plugins//libgfal_plugin_sftp.so loaded with success
>>>>>> 2019-07-17 15:09:17,784 | INFO     | copytool_out        |
>>>>>> gfal2                            | connect                   |
>>>>>> [gfal_module_load] plugin
>>>>>> /usr/lib64/gfal2-plugins//libgfal_plugin_dcap.so loaded with success
>>>>>> 2019-07-17 15:09:17,784 | INFO     | copytool_out        |
>>>>>> gfal2                            | connect                   |
>>>>>> [gfal_module_load] plugin
>>>>>> /usr/lib64/gfal2-plugins//libgfal_plugin_srm.so loaded with success
>>>>>> 2019-07-17 15:09:17,793 | INFO     | copytool_out        |
>>>>>> gfal2                            | connect                   |
>>>>>> [gfal_module_load] plugin
>>>>>> /usr/lib64/gfal2-plugins//libgfal_plugin_xrootd.so loaded with
>>>>>> success
>>>>>> 2019-07-17 15:09:17,793 | INFO     | copytool_out        |
>>>>>> gfal2                            | connect                   |
>>>>>> [gfal_module_load] plugin
>>>>>> /usr/lib64/gfal2-plugins//libgfal_plugin_rfio.so loaded with success
>>>>>> 2019-07-17 15:09:17,793 | INFO     | copytool_out        |
>>>>>> gfal2                            | connect                   |
>>>>>> [gfal_module_load] plugin
>>>>>> /usr/lib64/gfal2-plugins//libgfal_plugin_gridftp.so loaded with
>>>>>> success
>>>>>> 2019-07-17 15:09:17,794 | INFO     | copytool_out        |
>>>>>> gfal2                            | connect                   |
>>>>>> [gfal_module_load] plugin
>>>>>> /usr/lib64/gfal2-plugins//libgfal_plugin_http.so loaded with success
>>>>>> 2019-07-17 15:09:17,794 | INFO     | copytool_out        |
>>>>>> gfal2                            | connect                   |
>>>>>> [gfal_module_load] plugin
>>>>>> /usr/lib64/gfal2-plugins//libgfal_plugin_lfc.so loaded with success
>>>>>> 2019-07-17 15:09:17,794 | INFO     | copytool_out        |
>>>>>> gfal2                            | connect                   |
>>>>>> [gfal_module_load] plugin
>>>>>> /usr/lib64/gfal2-plugins//libgfal_plugin_file.so loaded with success
>>>>>> 2019-07-17 15:09:17,794 | INFO     | copytool_out        |
>>>>>> gfal2                            | connect                   |
>>>>>> [gfal_module_load] plugin
>>>>>> /usr/lib64/gfal2-plugins//libgfal_plugin_sftp.so loaded with success
>>>>>> 2019-07-17 15:09:17,794 | INFO     | copytool_out        |
>>>>>> gfal2                            | connect                   |
>>>>>> [gfal_module_load] plugin
>>>>>> /usr/lib64/gfal2-plugins//libgfal_plugin_dcap.so loaded with success
>>>>>> 2019-07-17 15:09:17,794 | INFO     | copytool_out        |
>>>>>> gfal2                            | connect                   |
>>>>>> [gfal_module_load] plugin
>>>>>> /usr/lib64/gfal2-plugins//libgfal_plugin_srm.so loaded with success
>>>>>> 2019-07-17 15:09:17,795 | INFO     | copytool_out        |
>>>>>> gfal2                            | connect                   |
>>>>>> [gfal_module_load] plugin
>>>>>> /usr/lib64/gfal2-plugins//libgfal_plugin_xrootd.so loaded with
>>>>>> success
>>>>>> 2019-07-17 15:09:17,795 | INFO     | copytool_out        |
>>>>>> gfal2                            | connect                   |
>>>>>> [gfal_module_load] plugin
>>>>>> /usr/lib64/gfal2-plugins//libgfal_plugin_rfio.so loaded with success
>>>>>> 2019-07-17 15:09:17,795 | INFO     | copytool_out        |
>>>>>> gfal2                            | connect                   |
>>>>>> [gfal_module_load] plugin
>>>>>> /usr/lib64/gfal2-plugins//libgfal_plugin_gridftp.so loaded with
>>>>>> success
>>>>>> 2019-07-17 15:09:17,795 | INFO     | copytool_out        |
>>>>>> gfal2                            | connect                   |
>>>>>> [gfal_module_load] plugin
>>>>>> /usr/lib64/gfal2-plugins//libgfal_plugin_http.so loaded with success
>>>>>> 2019-07-17 15:09:17,796 | INFO     | copytool_out        |
>>>>>> gfal2                            | connect                   |
>>>>>> [gfal_module_load] plugin
>>>>>> /usr/lib64/gfal2-plugins//libgfal_plugin_lfc.so loaded with success
>>>>>> 2019-07-17 15:09:17,796 | INFO     | copytool_out        |
>>>>>> gfal2                            | connect                   |
>>>>>> [gfal_module_load] plugin
>>>>>> /usr/lib64/gfal2-plugins//libgfal_plugin_file.so loaded with success
>>>>>> 2019-07-17 15:09:17,796 | INFO     | copytool_out        |
>>>>>> gfal2                            | connect                   |
>>>>>> [gfal_module_load] plugin
>>>>>> /usr/lib64/gfal2-plugins//libgfal_plugin_sftp.so loaded with success
>>>>>> 2019-07-17 15:09:17,796 | INFO     | copytool_out        |
>>>>>> gfal2                            | connect                   |
>>>>>> [gfal_module_load] plugin
>>>>>> /usr/lib64/gfal2-plugins//libgfal_plugin_dcap.so loaded with success
>>>>>> 2019-07-17 15:09:17,796 | INFO     | copytool_out        |
>>>>>> gfal2                            | connect                   |
>>>>>> [gfal_module_load] plugin
>>>>>> /usr/lib64/gfal2-plugins//libgfal_plugin_srm.so loaded with success
>>>>>> 2019-07-17 15:09:17,810 | INFO     | copytool_out        |
>>>>>> gfal2                            | __gfal2_copy              | Event
>>>>>> triggered: BOTH GFAL2:CORE:COPY LIST:ENTER
>>>>>> 2019-07-17 15:09:17,810 | INFO     | copytool_out        |
>>>>>> gfal2                            | __gfal2_copy              | Event
>>>>>> triggered: BOTH GFAL2:CORE:COPY LIST:ITEM
>>>>>> file:///scratch/condor/dir_24031/atlas_HudmF2he/PanDA_Pilot-4419868006/log.18636890._001059.job.log.tgz.1
>>>>>>
>>>>>> =>
>>>>>> root://golias100.farm.particle.cz:1094//dpm/farm.particle.cz/home/atlas/atlasdatadisk/rucio/mc15_13TeV/26/98/log.18636890._001059.job.log.tgz.1.rucio.upload
>>>>>>
>>>>>> 2019-07-17 15:09:17,810 | INFO     | copytool_out        |
>>>>>> gfal2                            | __gfal2_copy              | Event
>>>>>> triggered: BOTH GFAL2:CORE:COPY LIST:EXIT
>>>>>> 2019-07-17 15:09:17,811 | INFO     | Dummy-2             |
>>>>>> gfal2                            | (unknown function)        | Event
>>>>>> triggered: BOTH xroot TRANSFER:ENTER
>>>>>> file://localhost///scratch/condor/dir_24031/atlas_HudmF2he/PanDA_Pilot-4419868006/log.18636890._001059.job.log.tgz.1?xrd.gsiusrpxy=/scratch/condor/dir_24031/job.9XONDm6yx7unnoBGSqYX2MjnABFKDmABFKDmSyhTDmEBFKDmqAGN3n.proxy&xrd.wantprot=gsi,unix
>>>>>>
>>>>>> =>
>>>>>> root://golias100.farm.particle.cz:1094///dpm/farm.particle.cz/home/atlas/atlasdatadisk/rucio/mc15_13TeV/26/98/log.18636890._001059.job.log.tgz.1.rucio.upload?xrd.gsiusrpxy=/scratch/condor/dir_24031/job.9XONDm6yx7unnoBGSqYX2MjnABFKDmABFKDmSyhTDmEBFKDmqAGN3n.proxy&x
>>>>>>
>>>>>> 2019-07-17 15:09:17,811 | INFO     | Dummy-2             |
>>>>>> gfal2                            | (unknown function)        | Event
>>>>>> triggered: BOTH xroot TRANSFER:TYPE streamed
>>>>>> 2019-07-17 15:11:23,914 | INFO     | Dummy-2             |
>>>>>> gfal2                            | (unknown function)        | Event
>>>>>> triggered: BOTH xroot TRANSFER:EXIT Job finished, [SUCCESS]
>>>>>>
>>>>>> but probably rucio tries to verify checksum (gfal-sum via python
>>>>>> bindings) and it fails
>>>>>>
>>>>>> 2019-07-17 15:15:23,774 | INFO     | copytool_out        |
>>>>>> pilot.copytool.rucio             | copy_out                  |
>>>>>> stderr = An unknown exception occurred.
>>>>>> Details: Checksum not validated
>>>>>>
>>>>>> because DPM is unable to calculate checksum for 128TB file within
>>>>>> timeout.
>>>>>>
>>>>>> Petr
>>>>>>
>>>>>> On 7/19/19 5:07 AM, Andrew Hanushevsky wrote:
>>>>>>> Hi Petr,
>>>>>>>
>>>>>>> Indeed, it looks like what was used to upload the files (xrdcp?)
>>>>>>> created a very large sparse file by writing with a very large
>>>>>>> offset.
>>>>>>> The clue here is that an anomaly occurred during the write and these
>>>>>>> two messages (lkely each corresponding to each file) tell us
>>>>>>> something....
>>>>>>>
>>>>>>>> 190717 17:10:39 332092 ofs_Posc: Creator changed from
>>>>>>>   atlasprd.2757:90@[2001:718:401:6e03::1:21] to
>>>>>>>   atlasprd.2757:39@[2001:718:401:6e03::1:21] for
>>>>>>>  
>>>>>>> /dpm/farm.particle.cz/home/atlas/atlasdatadisk/rucio/mc15_13TeV/26/98/
>>>>>>>
>>>>>>>   log.18636890._001059.job.log.tgz.1.rucio.upload
>>>>>>>
>>>>>>>> 190717 17:29:26 14204 ofs_Posc: Creator changed from
>>>>>>>   atlasprd.2757:33@[2001:718:401:6e03::1:32] to
>>>>>>>   atlasprd.2757:95@[2001:718:401:6e03::1:32] for
>>>>>>>  
>>>>>>> /dpm/farm.particle.cz/home/atlas/atlasdatadisk/rucio/mc16_5TeV/09/bc/
>>>>>>>
>>>>>>>   AOD.18595963._000786.pool.root.1.rucio.upload
>>>>>>>
>>>>>>> What the POSC system is saying is that in each case the original
>>>>>>> creator of the file lost contact with the server. It then
>>>>>>> reconnected
>>>>>>> and resumed writing with a successful close. POSC allows this to
>>>>>>> avoid
>>>>>>> network glitches from deleting a file because a network glitch will
>>>>>>> cause the client to reconnect and resume where it left off. This is
>>>>>>> only allowed when the resuming client comes from the same IP
>>>>>>> address,
>>>>>>> has the same process ID, and the same logical name. In this case it
>>>>>>> was "atlasprd.2757". I find that rather odd because it's next to
>>>>>>> impossible for two processes on two different machines to have the
>>>>>>> same process number (i.e. 2757). So, this is why I am wondering if
>>>>>>> this was really an xrdcp or some other program.
>>>>>>>
>>>>>>> We should look to see what these client were actually doing during
>>>>>>> this period as they clearly did not do the right thing when they
>>>>>>> reconnected. So, could you grep out all interactions of these two
>>>>>>> client from the log. Something like:
>>>>>>>
>>>>>>> grep "atlasprd.2757:" <logfile> | egrep
>>>>>>> '2001:718:401:6e03::1:21|2001:718:401:6e03::1:32' > <excerpt>
>>>>>>>
>>>>>>> and send the excerpt to me?
>>>>>>>
>>>>>>> Andy
>>>>>>>
>>>>>>>
>>>>>>> On Thu, 18 Jul 2019, Petr Vokac wrote:
>>>>>>>
>>>>>>>> Hi,
>>>>>>>>
>>>>>>>> our DPM which is using native xrootd 4.9.1 yesterday created two
>>>>>>>> different 128TB files on two different diskservers that were
>>>>>>>> received as
>>>>>>>> a job output from two different worker nodes. The size of original
>>>>>>>> file
>>>>>>>> was few megabytes and when I check beginning of stored files up to
>>>>>>>> original size & checksum everything seems to be OK - except
>>>>>>>> these are
>>>>>>>> sparse files with size 128TB. Original transferred files from WN
>>>>>>>> looked
>>>>>>>> like:
>>>>>>>>
>>>>>>>> mc15_13TeV:log.18636890._001059.job.log.tgz.1 - original size
>>>>>>>> 3101899, adler32 742e1336
>>>>>>>> mc16_5TeV:AOD.18595963._000786.pool.root.1 - original size
>>>>>>>> 737474514,
>>>>>>>> adler32 dc68cb21
>>>>>>>>
>>>>>>>> but on our diskservers they were stored as
>>>>>>>>
>>>>>>>> [root@dpmpool22 ~]# ls -l
>>>>>>>> /mnt/fs1/atlas/2019-07-17/log.18636890._001059.job.log.tgz.1.rucio.upload.209928.1563376157
>>>>>>>>
>>>>>>>>
>>>>>>>> -rw-rw---- 1 dpmmgr dpmmgr 140560257079236 Jul 17 17:11
>>>>>>>> /mnt/fs1/atlas/2019-07-17/log.18636890._001059.job.log.tgz.1.rucio.upload.209928.1563376157
>>>>>>>>
>>>>>>>>
>>>>>>>> [root@dpmpool22 ~]# du --block-size=1
>>>>>>>> /mnt/fs1/atlas/2019-07-17/log.18636890._001059.job.log.tgz.1.rucio.upload.209928.1563376157
>>>>>>>>
>>>>>>>>
>>>>>>>> 3108864   
>>>>>>>> /mnt/fs1/atlas/2019-07-17/log.18636890._001059.job.log.tgz.1.rucio.upload.209928.1563376157
>>>>>>>>
>>>>>>>>
>>>>>>>>
>>>>>>>> [root@dpmpool24 ~]# ls -l
>>>>>>>> /mnt/fs2/atlas/2019-07-17/AOD.18595963._000786.pool.root.1.rucio.upload.210480.1563377083
>>>>>>>>
>>>>>>>>
>>>>>>>> -rw-rw---- 1 dpmmgr dpmmgr 139734345056408 Jul 17 17:31
>>>>>>>> /mnt/fs2/atlas/2019-07-17/AOD.18595963._000786.pool.root.1.rucio.upload.210480.1563377083
>>>>>>>>
>>>>>>>>
>>>>>>>> [root@dpmpool24 tmp]# du --block-size=1
>>>>>>>> /mnt/fs2/atlas/2019-07-17/AOD.18595963._000786.pool.root.1.rucio.upload.210480.1563377083
>>>>>>>>
>>>>>>>>
>>>>>>>> 737480704   
>>>>>>>> /mnt/fs2/atlas/2019-07-17/AOD.18595963._000786.pool.root.1.rucio.upload.210480.1563377083
>>>>>>>>
>>>>>>>>
>>>>>>>>
>>>>>>>> I was told that DPM is not really involved in transfering / storing
>>>>>>>> files with xrootd protocol, so I guess something bad must happened
>>>>>>>> inside XRootD libraries. Do you have any idea why these two
>>>>>>>> transfers
>>>>>>>> generated such extreme files? Unfortunately our xrootd logging is
>>>>>>>> pretty
>>>>>>>> low and I was able to find only info about file creation
>>>>>>>>
>>>>>>>> [root@dpmpool22 ~]# grep log.18636890._001059.job.log.tgz
>>>>>>>> /var/log/xrootd/dpmdisk/xrootd.log
>>>>>>>> 190717 17:10:39 332092 ofs_Posc: Creator changed from
>>>>>>>   atlasprd.2757:90@[2001:718:401:6e03::1:21] to
>>>>>>>   atlasprd.2757:39@[2001:718:401:6e03::1:21] for
>>>>>>>  
>>>>>>> /dpm/farm.particle.cz/home/atlas/atlasdatadisk/rucio/mc15_13TeV/26/98/
>>>>>>>
>>>>>>>   log.18636890._001059.job.log.tgz.1.rucio.upload
>>>>>>>>
>>>>>>>> [root@dpmpool24 tmp]# grep AOD.18595963._000786.pool.root
>>>>>>>> /var/log/xrootd/dpmdisk/xrootd.log
>>>>>>>> 190717 17:29:26 14204 ofs_Posc: Creator changed from
>>>>>>>   atlasprd.2757:33@[2001:718:401:6e03::1:32] to
>>>>>>>   atlasprd.2757:95@[2001:718:401:6e03::1:32] for
>>>>>>>  
>>>>>>> /dpm/farm.particle.cz/home/atlas/atlasdatadisk/rucio/mc16_5TeV/09/bc/AOD.18595963.
>>>>>>>
>>>>>>>
>>>>>>>   _000786.pool.root.1.rucio.upload
>>>>>>>>
>>>>>>>>
>>>>>>>> Petr
>>>>>>>>
>>>>>>>> ########################################################################
>>>>>>>>
>>>>>>>>
>>>>>>>> Use REPLY-ALL to reply to list
>>>>>>>>
>>>>>>>> To unsubscribe from the XROOTD-L list, click the following link:
>>>>>>>> https://listserv.slac.stanford.edu/cgi-bin/wa?SUBED1=XROOTD-L&A=1
>>>>>>>>
>>>>>>>
>>>>>>> ########################################################################
>>>>>>>
>>>>>>>
>>>>>>> Use REPLY-ALL to reply to list
>>>>>>>
>>>>>>> To unsubscribe from the XROOTD-L list, click the following link:
>>>>>>> https://listserv.slac.stanford.edu/cgi-bin/wa?SUBED1=XROOTD-L&A=1
>>>>>>
>>>>>>
>>>>>
>>>>> ########################################################################
>>>>>
>>>>> Use REPLY-ALL to reply to list
>>>>>
>>>>> To unsubscribe from the XROOTD-L list, click the following link:
>>>>> https://listserv.slac.stanford.edu/cgi-bin/wa?SUBED1=XROOTD-L&A=1
>>>>
>>>>
>>>> ------------------------------------------------------------------------
>>>>
>>>>
>>>> Use REPLY-ALL to reply to list
>>>>
>>>> To unsubscribe from the XROOTD-L list, click the following link:
>>>> https://listserv.slac.stanford.edu/cgi-bin/wa?SUBED1=XROOTD-L&A=1
>>>>
>>>
>>>
> 
> 
> ------------------------------------------------------------------------
> 
> Use REPLY-ALL to reply to list
> 
> To unsubscribe from the XROOTD-L list, click the following link:
> https://listserv.slac.stanford.edu/cgi-bin/wa?SUBED1=XROOTD-L&A=1
> 

########################################################################
Use REPLY-ALL to reply to list

To unsubscribe from the XROOTD-L list, click the following link:
https://listserv.slac.stanford.edu/cgi-bin/wa?SUBED1=XROOTD-L&A=1

Top of Message | Previous Page | Permalink

Advanced Options


Options

Log In

Log In

Get Password

Get Password


Search Archives

Search Archives


Subscribe or Unsubscribe

Subscribe or Unsubscribe


Archives

February 2024
January 2024
December 2023
November 2023
October 2023
September 2023
August 2023
July 2023
June 2023
May 2023
April 2023
March 2023
February 2023
January 2023
December 2022
October 2022
September 2022
August 2022
July 2022
June 2022
May 2022
April 2022
March 2022
February 2022
January 2022
December 2021
November 2021
October 2021
September 2021
August 2021
July 2021
June 2021
May 2021
April 2021
March 2021
February 2021
January 2021
December 2020
November 2020
October 2020
September 2020
August 2020
July 2020
June 2020
May 2020
April 2020
March 2020
February 2020
January 2020
December 2019
November 2019
October 2019
September 2019
August 2019
July 2019
June 2019
May 2019
April 2019
March 2019
February 2019
January 2019
December 2018
November 2018
October 2018
September 2018
August 2018
July 2018
June 2018
May 2018
April 2018
March 2018
February 2018
January 2018
December 2017
November 2017
October 2017
September 2017
August 2017
July 2017
June 2017
May 2017
April 2017
March 2017
February 2017
January 2017
December 2016
November 2016
October 2016
September 2016
August 2016
July 2016
May 2016
April 2016
March 2016
February 2016
January 2016
December 2015
November 2015
October 2015
September 2015
August 2015
July 2015
June 2015
May 2015
April 2015
March 2015
February 2015
January 2015
December 2014
November 2014
October 2014
September 2014
August 2014
July 2014
June 2014
May 2014
April 2014
March 2014
February 2014
January 2014
December 2013
November 2013
October 2013
September 2013
August 2013
July 2013
June 2013
May 2013
April 2013
March 2013
February 2013
January 2013
December 2012
November 2012
October 2012
September 2012
August 2012
July 2012
June 2012
May 2012
April 2012
March 2012
February 2012
January 2012
December 2011
November 2011
October 2011
September 2011
August 2011
July 2011
June 2011
May 2011
April 2011
March 2011
February 2011
January 2011
December 2010
October 2010
September 2010
August 2010
July 2010
June 2010
May 2010
April 2010
March 2010
February 2010
January 2010
December 2009
November 2009
October 2009
September 2009
July 2009
June 2009
May 2009
April 2009
March 2009
January 2009
December 2008
September 2008
August 2008
July 2008
June 2008
May 2008
April 2008
March 2008
February 2008
January 2008
December 2007
November 2007
October 2007
September 2007
August 2007
July 2007
June 2007
May 2007
April 2007
March 2007
February 2007
January 2007
December 2006
November 2006
October 2006
September 2006
August 2006
July 2006
June 2006
May 2006
April 2006
March 2006
February 2006
January 2006
December 2005
November 2005
October 2005
September 2005
August 2005
July 2005
June 2005
May 2005
April 2005
March 2005
February 2005
January 2005
December 2004
November 2004
October 2004
September 2004
August 2004

ATOM RSS1 RSS2



LISTSERV.SLAC.STANFORD.EDU

Secured by F-Secure Anti-Virus CataList Email List Search Powered by the LISTSERV Email List Manager

Privacy Notice, Security Notice and Terms of Use