Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

XrdCl-Http client transfer to EOS storage finishing with Segmentation fault and incomplete file transferred. #1891

Closed
gumond opened this issue Feb 2, 2023 · 5 comments
Assignees
Labels
Pending Info Waiting on additional information from issue reporter

Comments

@gumond
Copy link

gumond commented Feb 2, 2023

Reproduction of the problem transferring over http to EOS storage.
Preparation checks:

[root@jaro-dev2 ~]# ll /var/tmp/4G.file
-rw-r--r--. 1 root root 4294967296 Jan 25 16:53 /var/tmp/4G.file


[root@jaro-dev2 ~]# rpm -ql xrdcl-http
/etc/xrootd/client.plugins.d/xrdcl-http-plugin.conf
/usr/lib64/libXrdClHttp-5.so
[root@jaro-dev2 ~]# rpm -qa xrdcl-http
xrdcl-http-5.5.1-1.el7.x86_64

[root@jaro-dev2 ~]# which xrdcp
/usr/bin/xrdcp
[root@jaro-dev2 ~]# xrdcp --version
v5.5.1

[root@jaro-dev2 ~]# ll /tmp/x509up_u12354
-rw-------. 1 root root 6325 Feb  2 14:12 /tmp/x509up_u12354

[root@jaro-dev2 ~]# export X509_USER_PROXY=/tmp/x509up_u12354

[root@eosams02-ip563 (mgm:master mq:slave) ~]$ eos ls -l /eos/ams02/opstest/guenther/4G.file
Unable to stat /eos/ams02/opstest/guenther/4G.file; No such file or directory (errc=2) (No such file or directory)

The execution of the transfer command:

[root@jaro-dev2 ~]# time XrdSecPROTOCOL=gsi,unix xrdcp -f --debug 2 --allow-http /var/tmp/4G.file "https://eosams.cern.ch:443//eos/ams02/opstest/guenther/4G.file?eos.ruid=12354&eos.rgid=2763"
[2023-02-02 14:13:03.709247 +0100][Debug  ][Utility           ] Env: overriding entry: tlsnodata=0 with 1
[2023-02-02 14:13:03.709485 +0100][Debug  ][Utility           ] CopyProcess: 2 jobs to prepare
[2023-02-02 14:13:03.709556 +0100][Debug  ][Utility           ] Creating a classic copy job, from file://localhost/var/tmp/4G.file to https://eosams.cern.ch:443//eos/ams02/opstest/guenther/4G.file?eos.rgid=2763&eos.ruid=12354
[2023-02-02 14:13:03.709579 +0100][Debug  ][Utility           ] Monitor library name not set. No monitoring
[2023-02-02 14:13:03.709652 +0100][Debug  ][Utility           ] Opening file://localhost/var/tmp/4G.file for reading
[2023-02-02 14:13:03.709741 +0100][Debug  ][File              ] [0x11e5720@file://localhost/var/tmp/4G.file?xrdcl.requuid=8f7a6bcb-e1bf-4700-ba40-c281f63f5648] Sending an open command
[2023-02-02 14:13:03.709839 +0100][Debug  ][Utility           ] Env: trying to get a non-existent string entry: pollerpreference
[2023-02-02 14:13:03.709849 +0100][Debug  ][Poller            ] Available pollers: built-in
[2023-02-02 14:13:03.709854 +0100][Debug  ][Poller            ] Attempting to create a poller according to preference: built-in
[2023-02-02 14:13:03.709859 +0100][Debug  ][Poller            ] Creating poller: built-in
[2023-02-02 14:13:03.709870 +0100][Debug  ][Poller            ] Creating and starting the built-in poller...
[2023-02-02 14:13:03.710119 +0100][Debug  ][Poller            ] Using 1 poller threads
[2023-02-02 14:13:03.710136 +0100][Debug  ][TaskMgr           ] Starting the task manager...
[2023-02-02 14:13:03.710175 +0100][Debug  ][TaskMgr           ] Task manager started
[2023-02-02 14:13:03.710181 +0100][Debug  ][JobMgr            ] Starting the job manager...
[2023-02-02 14:13:03.710255 +0100][Debug  ][JobMgr            ] Job manager started, 3 workers
[2023-02-02 14:13:03.710264 +0100][Debug  ][TaskMgr           ] Registering task: "FileTimer task" to be run at: [2023-02-02 14:13:03 +0100]
[2023-02-02 14:13:03.710375 +0100][Debug  ][File              ] [0x11e5720@file://localhost/var/tmp/4G.file?xrdcl.requuid=8f7a6bcb-e1bf-4700-ba40-c281f63f5648] Open has returned with status [SUCCESS]
[2023-02-02 14:13:03.710400 +0100][Debug  ][File              ] [0x11e5720@file://localhost/var/tmp/4G.file?xrdcl.requuid=8f7a6bcb-e1bf-4700-ba40-c281f63f5648] successfully opened at localhost, handle: 0x7, session id: 1
[2023-02-02 14:13:03.710483 +0100][Debug  ][Utility           ] Opening https://eosams.cern.ch:443//eos/ams02/opstest/guenther/4G.file?eos.rgid=2763&eos.ruid=12354&oss.asize=4294967296 for writing
[2023-02-02 14:13:03.710536 +0100][Debug  ][XrdClHttp         ] HttpFilePlugin constructed.
[2023-02-02 14:13:03.747783 +0100][Debug  ][XrdClHttp         ] Open: URL: https://eosams.cern.ch:443//eos/ams02/opstest/guenther/4G.file?eos.rgid=2763&eos.ruid=12354&oss.asize=4294967296, XRootD flags: 34, POSIX flags: 578
[2023-02-02 14:13:03.766476 +0100][Debug  ][XrdClHttp         ] Opened: https://eosams.cern.ch:443//eos/ams02/opstest/guenther/4G.file?eos.rgid=2763&eos.ruid=12354&oss.asize=4294967296
[2023-02-02 14:13:03.766583 +0100][Error  ][Utility           ] The given URL is empty
[2023-02-02 14:13:03.766661 +0100][Error  ][PostMaster        ] Unable to get transport handler for  protocol
[2023-02-02 14:13:03.784673 +0100][Debug  ][XrdClHttp         ] Stat-ed URL: https://eosams.cern.ch:443//eos/ams02/opstest/guenther/4G.file?eos.rgid=2763&eos.ruid=12354&oss.asize=4294967296
[2023-02-02 14:13:03.784786 +0100][Debug  ][File              ] [0x11e5720@file://localhost/var/tmp/4G.file?xrdcl.requuid=8f7a6bcb-e1bf-4700-ba40-c281f63f5648] Sending a read command for handle 0x7 to localhost
[2023-02-02 14:13:03.784917 +0100][Debug  ][File              ] [0x11e5720@file://localhost/var/tmp/4G.file?xrdcl.requuid=8f7a6bcb-e1bf-4700-ba40-c281f63f5648] Sending a read command for handle 0x7 to localhost
[2023-02-02 14:13:03.784994 +0100][Debug  ][File              ] [0x11e5720@file://localhost/var/tmp/4G.file?xrdcl.requuid=8f7a6bcb-e1bf-4700-ba40-c281f63f5648] Sending a read command for handle 0x7 to localhost
[2023-02-02 14:13:03.785017 +0100][Debug  ][File              ] [0x11e5720@file://localhost/var/tmp/4G.file?xrdcl.requuid=8f7a6bcb-e1bf-4700-ba40-c281f63f5648] Sending a read command for handle 0x7 to localhost
[2023-02-02 14:13:03.811201 +0100][Debug  ][XrdClHttp         ] Wrote 8388608 bytes, at offset 0, to URL: https://eosams.cern.ch:443//eos/ams02/opstest/guenther/4G.file?eos.rgid=2763&eos.ruid=12354&oss.asize=4294967296
[8MB/4GB][  0%][>                                                 ][8MB/s]  [2023-02-02 14:13:03.811375 +0100][Debug  ][File              ] [0x11e5720@file://localhost/var/tmp/4G.file?xrdcl.requuid=8f7a6bcb-e1bf-4700-ba40-c281f63f5648] Sending a read command for handle 0x7 to localhost
[2023-02-02 14:13:03.836593 +0100][Error  ][XrdClHttp         ] Could not write URL: https://eosams.cern.ch:443//eos/ams02/opstest/guenther/4G.file?eos.rgid=2763&eos.ruid=12354&oss.asize=4294967296, error: [ERROR] Internal error: not a directory: Impossible to write to fdNo space left on device
[2023-02-02 14:13:03.838100 +0100][Debug  ][XrdClHttp         ] Closing davix fd: 20923904
Segmentation fault

real	0m0.317s
user	0m0.078s
sys	0m0.139s

Result is an incomplete file present on the storage:

[root@eosams02-ip563 (mgm:master mq:slave) ~]$ eos ls -l /eos/ams02/opstest/guenther/4G.file
-rw-r--r--   2 guenther it            8454144 Feb  2 14:17 4G.file
``

I do have space in that path on EOS:

[root@eosams02-ip563 (mgm:master mq:slave) ~]$ eos quota ls /eos/ams02/opstest/guenther/

┏━> Quota Node: /eos/ams02/opstest/guenther/
┌──────────┬──────────┬──────────┬──────────┬──────────┬──────────┬──────────┬──────────┬──────────┬──────────┐
│user │used bytes│logi bytes│used files│aval bytes│aval logib│aval files│ filled[%]│vol-status│ino-status│
└──────────┴──────────┴──────────┴──────────┴──────────┴──────────┴──────────┴──────────┴──────────┴──────────┘
guenther 33.82 MB 16.91 MB 4 2.00 TB 1.00 TB 0 0.00 % ok ignored

@gumond
Copy link
Author

gumond commented Feb 2, 2023

For small files the transfer seems to work fine:

[root@jaro-dev2 ~]# ll testtextfile
-rw-r--r--. 1 root root 15 Jan 25 16:58 testtextfile
[root@jaro-dev2 ~]# cat testtextfile
test text file

[root@jaro-dev2 ~]# time XrdSecPROTOCOL=gsi,unix xrdcp -f --debug 2 --allow-http /root/testtextfile "https://eosams.cern.ch:443//eos/ams02/opstest/guenther/testtextfile?eos.ruid=12354&eos.rgid=2763"
[2023-02-02 14:24:33.923860 +0100][Debug  ][Utility           ] Env: overriding entry: tlsnodata=0 with 1
[2023-02-02 14:24:33.924142 +0100][Debug  ][Utility           ] CopyProcess: 2 jobs to prepare
[2023-02-02 14:24:33.924206 +0100][Debug  ][Utility           ] Creating a classic copy job, from file://localhost/root/testtextfile to https://eosams.cern.ch:443//eos/ams02/opstest/guenther/testtextfile?eos.rgid=2763&eos.ruid=12354
[2023-02-02 14:24:33.924229 +0100][Debug  ][Utility           ] Monitor library name not set. No monitoring
[2023-02-02 14:24:33.924303 +0100][Debug  ][Utility           ] Opening file://localhost/root/testtextfile for reading
[2023-02-02 14:24:33.924402 +0100][Debug  ][File              ] [0x26147f0@file://localhost/root/testtextfile?xrdcl.requuid=f3189112-299e-49ed-b126-f0d7204df326] Sending an open command
[2023-02-02 14:24:33.924509 +0100][Debug  ][Utility           ] Env: trying to get a non-existent string entry: pollerpreference
[2023-02-02 14:24:33.924519 +0100][Debug  ][Poller            ] Available pollers: built-in
[2023-02-02 14:24:33.924524 +0100][Debug  ][Poller            ] Attempting to create a poller according to preference: built-in
[2023-02-02 14:24:33.924530 +0100][Debug  ][Poller            ] Creating poller: built-in
[2023-02-02 14:24:33.924540 +0100][Debug  ][Poller            ] Creating and starting the built-in poller...
[2023-02-02 14:24:33.924752 +0100][Debug  ][Poller            ] Using 1 poller threads
[2023-02-02 14:24:33.924768 +0100][Debug  ][TaskMgr           ] Starting the task manager...
[2023-02-02 14:24:33.924816 +0100][Debug  ][TaskMgr           ] Task manager started
[2023-02-02 14:24:33.924823 +0100][Debug  ][JobMgr            ] Starting the job manager...
[2023-02-02 14:24:33.924970 +0100][Debug  ][JobMgr            ] Job manager started, 3 workers
[2023-02-02 14:24:33.924985 +0100][Debug  ][TaskMgr           ] Registering task: "FileTimer task" to be run at: [2023-02-02 14:24:33 +0100]
[2023-02-02 14:24:33.925122 +0100][Debug  ][File              ] [0x26147f0@file://localhost/root/testtextfile?xrdcl.requuid=f3189112-299e-49ed-b126-f0d7204df326] Open has returned with status [SUCCESS]
[2023-02-02 14:24:33.925146 +0100][Debug  ][File              ] [0x26147f0@file://localhost/root/testtextfile?xrdcl.requuid=f3189112-299e-49ed-b126-f0d7204df326] successfully opened at localhost, handle: 0x7, session id: 1
[2023-02-02 14:24:33.925278 +0100][Debug  ][Utility           ] Opening https://eosams.cern.ch:443//eos/ams02/opstest/guenther/testtextfile?eos.rgid=2763&eos.ruid=12354&oss.asize=15 for writing
[2023-02-02 14:24:33.925326 +0100][Debug  ][XrdClHttp         ] HttpFilePlugin constructed.
[2023-02-02 14:24:33.970095 +0100][Debug  ][XrdClHttp         ] Open: URL: https://eosams.cern.ch:443//eos/ams02/opstest/guenther/testtextfile?eos.rgid=2763&eos.ruid=12354&oss.asize=15, XRootD flags: 34, POSIX flags: 578
[2023-02-02 14:24:33.988435 +0100][Debug  ][XrdClHttp         ] Opened: https://eosams.cern.ch:443//eos/ams02/opstest/guenther/testtextfile?eos.rgid=2763&eos.ruid=12354&oss.asize=15
[2023-02-02 14:24:33.988482 +0100][Error  ][Utility           ] The given URL is empty
[2023-02-02 14:24:33.988528 +0100][Error  ][PostMaster        ] Unable to get transport handler for  protocol
[2023-02-02 14:24:34.006215 +0100][Debug  ][XrdClHttp         ] Stat-ed URL: https://eosams.cern.ch:443//eos/ams02/opstest/guenther/testtextfile?eos.rgid=2763&eos.ruid=12354&oss.asize=15
[2023-02-02 14:24:34.006272 +0100][Debug  ][File              ] [0x26147f0@file://localhost/root/testtextfile?xrdcl.requuid=f3189112-299e-49ed-b126-f0d7204df326] Sending a read command for handle 0x7 to localhost
[2023-02-02 14:24:34.006700 +0100][Debug  ][XrdClHttp         ] Wrote 15 bytes, at offset 0, to URL: https://eosams.cern.ch:443//eos/ams02/opstest/guenther/testtextfile?eos.rgid=2763&eos.ruid=12354&oss.asize=15
[15B/15B][100%][==================================================][15B/s]  [2023-02-02 14:24:34.006793 +0100][Debug  ][XrdClHttp         ] Closing davix fd: 42046832
[2023-02-02 14:24:34.065831 +0100][Debug  ][File              ] [0x26147f0@file://localhost/root/testtextfile?xrdcl.requuid=f3189112-299e-49ed-b126-f0d7204df326] Sending a close command for handle 0x7 to localhost
[2023-02-02 14:24:34.065997 +0100][Debug  ][File              ] [0x26147f0@file://localhost/root/testtextfile?xrdcl.requuid=f3189112-299e-49ed-b126-f0d7204df326] Close returned from localhost with: [SUCCESS]
[15B/15B][100%][==================================================][15B/s]
[2023-02-02 14:24:34.066577 +0100][Debug  ][JobMgr            ] Stopping the job manager...
[2023-02-02 14:24:34.066829 +0100][Debug  ][JobMgr            ] Job manager stopped
[2023-02-02 14:24:34.066843 +0100][Debug  ][TaskMgr           ] Stopping the task manager...
[2023-02-02 14:24:34.066990 +0100][Debug  ][TaskMgr           ] Task manager stopped
[2023-02-02 14:24:34.067005 +0100][Debug  ][Poller            ] Stopping the poller...

real	0m0.160s
user	0m0.076s
sys	0m0.015s
[root@jaro-dev2 ~]#

[root@eosams02-ip563 (mgm:master mq:slave) ~]$ eos ls -l /eos/ams02/opstest/guenther/testtextfile
-rw-r--r--   2 guenther it                 15 Feb  2 14:28 testtextfile

@gumond
Copy link
Author

gumond commented Feb 2, 2023

root@eosams02-ip563 (mgm:master mq:slave) ~]$ eos ls -l /eos/ams02/opstest/guenther/
-rw-r--r--   2 guenther it            8454144 Feb  2 14:17 4G.file
-rw-r--r--   2 guenther it            8454144 Jan 25 16:58 file.txt
-rw-r--r--   2 guenther it                 14 Jan 25 16:27 testfile
-rw-r--r--   2 guenther it                 15 Feb  2 14:28 testtextfile

@abh3
Copy link
Member

abh3 commented Feb 2, 2023 via email

@abh3 abh3 added the Pending Info Waiting on additional information from issue reporter label Feb 6, 2023
@abh3
Copy link
Member

abh3 commented Feb 15, 2023

Have you solved this issue and can I close this ticket?

@abh3
Copy link
Member

abh3 commented Oct 12, 2023

Given no response then we assume this problem has at least a bypass. So, I am closing this ticket.

@abh3 abh3 closed this as completed Oct 12, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Pending Info Waiting on additional information from issue reporter
Projects
None yet
Development

No branches or pull requests

3 participants