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

xrootd: xrdcp "Could not load authentication handler", libXrdSec-5.so isn't found #169677

Closed
ShamrockLee opened this issue Apr 22, 2022 · 1 comment · Fixed by #289140
Closed
Labels
0.kind: bug 2.status: stale https://github.com/NixOS/nixpkgs/blob/master/.github/STALE-BOT.md

Comments

@ShamrockLee
Copy link
Contributor

Describe the bug

XRootD failed to access the files following the root:// URL, complaining that libXrdSec.so isn't found and the authentication handler couldn't be loaded.

However, libXrdSec.so does present in the output directory.

$ nix shell .#xrootd --command xrdcp -v -d 3 root://eospublic.cern.ch//eos/opendata/cms/MonteCarloCASTOR/MinBias_TuneZ2_7TeV_pythia6_cff_py_GEN_SIM_START311_V2_Dec11_v2/MinBias_TuneZ2_7TeV_pythia6_cff_py_Step3_START42_V11_Dec11_v2/86bcdbe9c73956c342e477ba771c41c7/STEP2_RAW2DIGI_L1Reco_RECO_7TeV_10_1_s8p.root /dev/shm/
...
[2022-04-22 09:42:38.329696 +0800][Error  ][XRootDTransport   ] Unable to get the security framework: Plugin No such file or directory loading seclib libXrdSec-5.so
...
Run: [FATAL] Auth failed: Could not load authentication handler. (source)
...

Steps To Reproduce

Steps to reproduce the behavior:

  1. Enter the top directory of Nixpkgs
  2. nix shell .#xrootd --command xrdcp root://eospublic.cern.ch//eos/opendata/cms/MonteCarloCASTOR
  3. See
    [0B/0B][100%][==================================================][0B/s]
    Run: [FATAL] Auth failed: Could not load authentication handler. (source)
    
  4. Run nix shell .#xrootd --command xrdcp -v -d 3 root://eospublic.cern.ch//eos/opendata/cms/MonteCarloCASTOR
  5. See the detailed output

Expected behavior

A clear and concise description of what you expected to happen.

Screenshots

If applicable, add screenshots to help explain your problem.

Additional context

Terminal output during execution:
Short:

$ nix shell .#xrootd --command xrdcp root://eospublic.cern.ch//eos/opendata/cms/MonteCarloCASTOR/MinBias_TuneZ2_7TeV_pythia6_cff_py_GEN_SIM_START311_V2_Dec11_v2/MinBias_TuneZ2_7TeV_pythia6_cff_py_Step3_START42_V11_Dec11_v2/86bcdbe9c73956c342e477ba771c41c7/STEP2_RAW2DIGI_L1Reco_RECO_7TeV_10_1_s8p.root /dev/shm/
[0B/0B][100%][==================================================][0B/s]
Run: [FATAL] Auth failed: Could not load authentication handler. (source)

Long:

$ nix shell .#xrootd --command xrdcp -v -d 3 root://eospublic.cern.ch//eos/opendata/cms/MonteCarloCASTOR/MinBias_TuneZ2_7TeV_pythia6_cff_py_GEN_SIM_START311_V2_Dec11_v2/MinBias_TuneZ2_7TeV_pythia6_cff_py_Step3_START42_V11_Dec11_v2/86bcdbe9c73956c342e477ba771c41c7/STEP2_RAW2DIGI_L1Reco_RECO_7TeV_10_1_s8p.root /dev/shm/
[2022-04-22 09:42:36.282010 +0800][Dump   ][App               ] Chunk size: 8388608, parallel chunks 4, streams: 1
[2022-04-22 09:42:36.282048 +0800][Dump   ][App               ] Processing source entry: root://eospublic.cern.ch//eos/opendata/cms/MonteCarloCASTOR/MinBias_TuneZ2_7TeV_pythia6_cff_py_GEN_SIM_START311_V2_Dec11_v2/MinBias_TuneZ2_7TeV_pythia6_cff_py_Step3_START42_V11_Dec11_v2/86bcdbe9c73956c342e477ba771c41c7/STEP2_RAW2DIGI_L1Reco_RECO_7TeV_10_1_s8p.root, type xroot, target file: file:///dev/shm/
[2022-04-22 09:42:36.282083 +0800][Dump   ][Utility           ] Adding job with properties: 'checkSumMode' = 'none', 'checkSumPreset' = '', 'checkSumType' = '', 'chunkSize' = '8388608', 'coerce' = '0', 'continue' = '0', 'cpTimeout' = '0', 'delegate' = '0', 'dynamicSource' = '0', 'force' = '0', 'initTimeout' = '600', 'makeDir' = '0', 'parallelChunks' = '4', 'posc' = '0', 'preserveXAttr' = '0', 'rmOnBadCksum' = '0', 'source' = 'root://eospublic.cern.ch//eos/opendata/cms/MonteCarloCASTOR/MinBias_TuneZ2_7TeV_pythia6_cff_py_GEN_SIM_START311_V2_Dec11_v2/MinBias_TuneZ2_7TeV_pythia6_cff_py_Step3_START42_V11_Dec11_v2/86bcdbe9c73956c342e477ba771c41c7/STEP2_RAW2DIGI_L1Reco_RECO_7TeV_10_1_s8p.root', 'target' = 'file:///dev/shm/', 'targetIsDir' = '1', 'thirdParty' = 'none', 'tpcTimeout' = '1800', 'xcp' = '0', 'xcpBlockSize' = '134217728', 'xrate' = '0', 'xrateThreashold' = '0', 'zipAppend' = '0', 'zipArchive' = '0'
[2022-04-22 09:42:36.282094 +0800][Debug  ][Utility           ] CopyProcess: 2 jobs to prepare
[2022-04-22 09:42:36.282104 +0800][Dump   ][Utility           ] URL: root://eospublic.cern.ch//eos/opendata/cms/MonteCarloCASTOR/MinBias_TuneZ2_7TeV_pythia6_cff_py_GEN_SIM_START311_V2_Dec11_v2/MinBias_TuneZ2_7TeV_pythia6_cff_py_Step3_START42_V11_Dec11_v2/86bcdbe9c73956c342e477ba771c41c7/STEP2_RAW2DIGI_L1Reco_RECO_7TeV_10_1_s8p.root
[2022-04-22 09:42:36.282104 +0800][Dump   ][Utility           ] Protocol:  root
[2022-04-22 09:42:36.282104 +0800][Dump   ][Utility           ] User Name:
[2022-04-22 09:42:36.282104 +0800][Dump   ][Utility           ] Password:
[2022-04-22 09:42:36.282104 +0800][Dump   ][Utility           ] Host Name: eospublic.cern.ch
[2022-04-22 09:42:36.282104 +0800][Dump   ][Utility           ] Port:      1094
[2022-04-22 09:42:36.282104 +0800][Dump   ][Utility           ] Path:      /eos/opendata/cms/MonteCarloCASTOR/MinBias_TuneZ2_7TeV_pythia6_cff_py_GEN_SIM_START311_V2_Dec11_v2/MinBias_TuneZ2_7TeV_pythia6_cff_py_Step3_START42_V11_Dec11_v2/86bcdbe9c73956c342e477ba771c41c7/STEP2_RAW2DIGI_L1Reco_RECO_7TeV_10_1_s8p.root
[2022-04-22 09:42:36.282118 +0800][Dump   ][Utility           ] URL: file:///dev/shm/
[2022-04-22 09:42:36.282118 +0800][Dump   ][Utility           ] Protocol:  file
[2022-04-22 09:42:36.282118 +0800][Dump   ][Utility           ] User Name:
[2022-04-22 09:42:36.282118 +0800][Dump   ][Utility           ] Password:
[2022-04-22 09:42:36.282118 +0800][Dump   ][Utility           ] Host Name: localhost
[2022-04-22 09:42:36.282118 +0800][Dump   ][Utility           ] Port:      1094
[2022-04-22 09:42:36.282118 +0800][Dump   ][Utility           ] Path:      /dev/shm
[2022-04-22 09:42:36.282135 +0800][Dump   ][Utility           ] URL: root://eospublic.cern.ch//eos/opendata/cms/MonteCarloCASTOR/MinBias_TuneZ2_7TeV_pythia6_cff_py_GEN_SIM_START311_V2_Dec11_v2/MinBias_TuneZ2_7TeV_pythia6_cff_py_Step3_START42_V11_Dec11_v2/86bcdbe9c73956c342e477ba771c41c7/STEP2_RAW2DIGI_L1Reco_RECO_7TeV_10_1_s8p.root
[2022-04-22 09:42:36.282135 +0800][Dump   ][Utility           ] Protocol:  root
[2022-04-22 09:42:36.282135 +0800][Dump   ][Utility           ] User Name:
[2022-04-22 09:42:36.282135 +0800][Dump   ][Utility           ] Password:
[2022-04-22 09:42:36.282135 +0800][Dump   ][Utility           ] Host Name: eospublic.cern.ch
[2022-04-22 09:42:36.282135 +0800][Dump   ][Utility           ] Port:      1094
[2022-04-22 09:42:36.282135 +0800][Dump   ][Utility           ] Path:      /eos/opendata/cms/MonteCarloCASTOR/MinBias_TuneZ2_7TeV_pythia6_cff_py_GEN_SIM_START311_V2_Dec11_v2/MinBias_TuneZ2_7TeV_pythia6_cff_py_Step3_START42_V11_Dec11_v2/86bcdbe9c73956c342e477ba771c41c7/STEP2_RAW2DIGI_L1Reco_RECO_7TeV_10_1_s8p.root
[2022-04-22 09:42:36.282146 +0800][Dump   ][Utility           ] URL: file://localhost/dev/shm/STEP2_RAW2DIGI_L1Reco_RECO_7TeV_10_1_s8p.root
[2022-04-22 09:42:36.282146 +0800][Dump   ][Utility           ] Protocol:  file
[2022-04-22 09:42:36.282146 +0800][Dump   ][Utility           ] User Name:
[2022-04-22 09:42:36.282146 +0800][Dump   ][Utility           ] Password:
[2022-04-22 09:42:36.282146 +0800][Dump   ][Utility           ] Host Name: localhost
[2022-04-22 09:42:36.282146 +0800][Dump   ][Utility           ] Port:      1094
[2022-04-22 09:42:36.282146 +0800][Dump   ][Utility           ] Path:      /dev/shm/STEP2_RAW2DIGI_L1Reco_RECO_7TeV_10_1_s8p.root
[2022-04-22 09:42:36.282152 +0800][Debug  ][Utility           ] Creating a classic copy job, from root://eospublic.cern.ch:1094//eos/opendata/cms/MonteCarloCASTOR/MinBias_TuneZ2_7TeV_pythia6_cff_py_GEN_SIM_START311_V2_Dec11_v2/MinBias_TuneZ2_7TeV_pythia6_cff_py_Step3_START42_V11_Dec11_v2/86bcdbe9c73956c342e477ba771c41c7/STEP2_RAW2DIGI_L1Reco_RECO_7TeV_10_1_s8p.root to file://localhost/dev/shm/STEP2_RAW2DIGI_L1Reco_RECO_7TeV_10_1_s8p.root
[2022-04-22 09:42:36.282159 +0800][Debug  ][Utility           ] Monitor library name not set. No monitoring
[2022-04-22 09:42:36.282179 +0800][Debug  ][Utility           ] Env: trying to get a non-existent string entry: pollerpreference
[2022-04-22 09:42:36.282184 +0800][Debug  ][Poller            ] Available pollers: built-in
[2022-04-22 09:42:36.282186 +0800][Debug  ][Poller            ] Attempting to create a poller according to preference: built-in
[2022-04-22 09:42:36.282188 +0800][Debug  ][Poller            ] Creating poller: built-in
[2022-04-22 09:42:36.282191 +0800][Debug  ][Poller            ] Creating and starting the built-in poller...
[2022-04-22 09:42:36.282312 +0800][Debug  ][Poller            ] Using 1 poller threads
[2022-04-22 09:42:36.282323 +0800][Debug  ][TaskMgr           ] Starting the task manager...
[2022-04-22 09:42:36.282356 +0800][Debug  ][TaskMgr           ] Task manager started
[2022-04-22 09:42:36.282362 +0800][Debug  ][JobMgr            ] Starting the job manager...
[2022-04-22 09:42:36.282400 +0800][Debug  ][JobMgr            ] Job manager started, 3 workers
[2022-04-22 09:42:36.282405 +0800][Debug  ][TaskMgr           ] Registering task: "FileTimer task" to be run at: [2022-04-22 09:42:36 +0800]
[2022-04-22 09:42:36.282409 +0800][Debug  ][Utility           ] Opening root://eospublic.cern.ch:1094//eos/opendata/cms/MonteCarloCASTOR/MinBias_TuneZ2_7TeV_pythia6_cff_py_GEN_SIM_START311_V2_Dec11_v2/MinBias_TuneZ2_7TeV_pythia6_cff_py_Step3_START42_V11_Dec11_v2/86bcdbe9c73956c342e477ba771c41c7/STEP2_RAW2DIGI_L1Reco_RECO_7TeV_10_1_s8p.root for reading
[2022-04-22 09:42:36.282421 +0800][Dump   ][Utility           ] URL: root://eospublic.cern.ch:1094//eos/opendata/cms/MonteCarloCASTOR/MinBias_TuneZ2_7TeV_pythia6_cff_py_GEN_SIM_START311_V2_Dec11_v2/MinBias_TuneZ2_7TeV_pythia6_cff_py_Step3_START42_V11_Dec11_v2/86bcdbe9c73956c342e477ba771c41c7/STEP2_RAW2DIGI_L1Reco_RECO_7TeV_10_1_s8p.root
[2022-04-22 09:42:36.282421 +0800][Dump   ][Utility           ] Protocol:  root
[2022-04-22 09:42:36.282421 +0800][Dump   ][Utility           ] User Name:
[2022-04-22 09:42:36.282421 +0800][Dump   ][Utility           ] Password:
[2022-04-22 09:42:36.282421 +0800][Dump   ][Utility           ] Host Name: eospublic.cern.ch
[2022-04-22 09:42:36.282421 +0800][Dump   ][Utility           ] Port:      1094
[2022-04-22 09:42:36.282421 +0800][Dump   ][Utility           ] Path:      /eos/opendata/cms/MonteCarloCASTOR/MinBias_TuneZ2_7TeV_pythia6_cff_py_GEN_SIM_START311_V2_Dec11_v2/MinBias_TuneZ2_7TeV_pythia6_cff_py_Step3_START42_V11_Dec11_v2/86bcdbe9c73956c342e477ba771c41c7/STEP2_RAW2DIGI_L1Reco_RECO_7TeV_10_1_s8p.root
[2022-04-22 09:42:36.282435 +0800][Dump   ][Utility           ] URL: root://eospublic.cern.ch:1094//eos/opendata/cms/MonteCarloCASTOR/MinBias_TuneZ2_7TeV_pythia6_cff_py_GEN_SIM_START311_V2_Dec11_v2/MinBias_TuneZ2_7TeV_pythia6_cff_py_Step3_START42_V11_Dec11_v2/86bcdbe9c73956c342e477ba771c41c7/STEP2_RAW2DIGI_L1Reco_RECO_7TeV_10_1_s8p.root
[2022-04-22 09:42:36.282435 +0800][Dump   ][Utility           ] Protocol:  root
[2022-04-22 09:42:36.282435 +0800][Dump   ][Utility           ] User Name:
[2022-04-22 09:42:36.282435 +0800][Dump   ][Utility           ] Password:
[2022-04-22 09:42:36.282435 +0800][Dump   ][Utility           ] Host Name: eospublic.cern.ch
[2022-04-22 09:42:36.282435 +0800][Dump   ][Utility           ] Port:      1094
[2022-04-22 09:42:36.282435 +0800][Dump   ][Utility           ] Path:      /eos/opendata/cms/MonteCarloCASTOR/MinBias_TuneZ2_7TeV_pythia6_cff_py_GEN_SIM_START311_V2_Dec11_v2/MinBias_TuneZ2_7TeV_pythia6_cff_py_Step3_START42_V11_Dec11_v2/86bcdbe9c73956c342e477ba771c41c7/STEP2_RAW2DIGI_L1Reco_RECO_7TeV_10_1_s8p.root
[2022-04-22 09:42:36.282445 +0800][Dump   ][Utility           ] URL: root://eospublic.cern.ch:1094//eos/opendata/cms/MonteCarloCASTOR/MinBias_TuneZ2_7TeV_pythia6_cff_py_GEN_SIM_START311_V2_Dec11_v2/MinBias_TuneZ2_7TeV_pythia6_cff_py_Step3_START42_V11_Dec11_v2/86bcdbe9c73956c342e477ba771c41c7/STEP2_RAW2DIGI_L1Reco_RECO_7TeV_10_1_s8p.root
[2022-04-22 09:42:36.282445 +0800][Dump   ][Utility           ] Protocol:  root
[2022-04-22 09:42:36.282445 +0800][Dump   ][Utility           ] User Name:
[2022-04-22 09:42:36.282445 +0800][Dump   ][Utility           ] Password:
[2022-04-22 09:42:36.282445 +0800][Dump   ][Utility           ] Host Name: eospublic.cern.ch
[2022-04-22 09:42:36.282445 +0800][Dump   ][Utility           ] Port:      1094
[2022-04-22 09:42:36.282445 +0800][Dump   ][Utility           ] Path:      /eos/opendata/cms/MonteCarloCASTOR/MinBias_TuneZ2_7TeV_pythia6_cff_py_GEN_SIM_START311_V2_Dec11_v2/MinBias_TuneZ2_7TeV_pythia6_cff_py_Step3_START42_V11_Dec11_v2/86bcdbe9c73956c342e477ba771c41c7/STEP2_RAW2DIGI_L1Reco_RECO_7TeV_10_1_s8p.root
[2022-04-22 09:42:36.282461 +0800][Debug  ][File              ] [0xd3cf10@root://eospublic.cern.ch:1094//eos/opendata/cms/MonteCarloCASTOR/MinBias_TuneZ2_7TeV_pythia6_cff_py_GEN_SIM_START311_V2_Dec11_v2/MinBias_TuneZ2_7TeV_pythia6_cff_py_Step3_START42_V11_Dec11_v2/86bcdbe9c73956c342e477ba771c41c7/STEP2_RAW2DIGI_L1Reco_RECO_7TeV_10_1_s8p.root?xrdcl.requuid=486fcf91-14cc-4617-85cb-cf284e63621f] Sending an open command
[2022-04-22 09:42:36.282470 +0800][Dump   ][XRootD            ] [eospublic.cern.ch:1094] Sending message kXR_open (file: /eos/opendata/cms/MonteCarloCASTOR/MinBias_TuneZ2_7TeV_pythia6_cff_py_GEN_SIM_START311_V2_Dec11_v2/MinBias_TuneZ2_7TeV_pythia6_cff_py_Step3_START42_V11_Dec11_v2/86bcdbe9c73956c342e477ba771c41c7/STEP2_RAW2DIGI_L1Reco_RECO_7TeV_10_1_s8p.root, mode: 00, flags: kXR_open_read kXR_async kXR_retstat )
[2022-04-22 09:42:36.282480 +0800][Debug  ][ExDbgMsg          ] [eospublic.cern.ch:1094] MsgHandler created: 0xd424f0 (message: kXR_open (file: /eos/opendata/cms/MonteCarloCASTOR/MinBias_TuneZ2_7TeV_pythia6_cff_py_GEN_SIM_START311_V2_Dec11_v2/MinBias_TuneZ2_7TeV_pythia6_cff_py_Step3_START42_V11_Dec11_v2/86bcdbe9c73956c342e477ba771c41c7/STEP2_RAW2DIGI_L1Reco_RECO_7TeV_10_1_s8p.root, mode: 00, flags: kXR_open_read kXR_async kXR_retstat ) ).
[2022-04-22 09:42:36.282494 +0800][Dump   ][Utility           ] URL: eospublic.cern.ch:1094
[2022-04-22 09:42:36.282494 +0800][Dump   ][Utility           ] Protocol:  root
[2022-04-22 09:42:36.282494 +0800][Dump   ][Utility           ] User Name:
[2022-04-22 09:42:36.282494 +0800][Dump   ][Utility           ] Password:
[2022-04-22 09:42:36.282494 +0800][Dump   ][Utility           ] Host Name: eospublic.cern.ch
[2022-04-22 09:42:36.282494 +0800][Dump   ][Utility           ] Port:      1094
[2022-04-22 09:42:36.282494 +0800][Dump   ][Utility           ] Path:
[2022-04-22 09:42:36.282503 +0800][Dump   ][Utility           ] URL: root://eospublic.cern.ch:1094
[2022-04-22 09:42:36.282503 +0800][Dump   ][Utility           ] Protocol:  root
[2022-04-22 09:42:36.282503 +0800][Dump   ][Utility           ] User Name:
[2022-04-22 09:42:36.282503 +0800][Dump   ][Utility           ] Password:
[2022-04-22 09:42:36.282503 +0800][Dump   ][Utility           ] Host Name: eospublic.cern.ch
[2022-04-22 09:42:36.282503 +0800][Dump   ][Utility           ] Port:      1094
[2022-04-22 09:42:36.282503 +0800][Dump   ][Utility           ] Path:
[2022-04-22 09:42:36.282511 +0800][Debug  ][PostMaster        ] Creating new channel to: root://eospublic.cern.ch:1094
[2022-04-22 09:42:36.282520 +0800][Debug  ][PostMaster        ] [eospublic.cern.ch:1094] Stream parameters: Network Stack: IPAuto, Connection Window: 120, ConnectionRetry: 5, Stream Error Window: 1800
[2022-04-22 09:42:36.282527 +0800][Debug  ][TaskMgr           ] Registering task: "TickGeneratorTask for: root://eospublic.cern.ch:1094" to be run at: [2022-04-22 09:42:51 +0800]
[2022-04-22 09:42:36.282534 +0800][Dump   ][PostMaster        ] [eospublic.cern.ch:1094] Sending message kXR_open (file: /eos/opendata/cms/MonteCarloCASTOR/MinBias_TuneZ2_7TeV_pythia6_cff_py_GEN_SIM_START311_V2_Dec11_v2/MinBias_TuneZ2_7TeV_pythia6_cff_py_Step3_START42_V11_Dec11_v2/86bcdbe9c73956c342e477ba771c41c7/STEP2_RAW2DIGI_L1Reco_RECO_7TeV_10_1_s8p.root, mode: 00, flags: kXR_open_read kXR_async kXR_retstat ) (0xd3d600) through substream 0 expecting answer at 0
[2022-04-22 09:42:37.282505 +0800][Dump   ][TaskMgr           ] Running task: "FileTimer task"
[2022-04-22 09:42:37.282539 +0800][Dump   ][TaskMgr           ] Will rerun task "FileTimer task" at [2022-04-22 09:42:52 +0800]
[2022-04-22 09:42:37.305170 +0800][Debug  ][PostMaster        ] [eospublic.cern.ch:1094] Found 2 address(es): [::ffff:128.142.160.145]:1094, [2001:1458:301:17::100:e]:1094
[2022-04-22 09:42:37.305205 +0800][Debug  ][AsyncSock         ] [eospublic.cern.ch:1094.0] Attempting connection to [2001:1458:301:17::100:e]:1094
[2022-04-22 09:42:37.305237 +0800][Debug  ][Poller            ] Adding socket 0xd3dbd0 to the poller
[2022-04-22 09:42:37.614083 +0800][Debug  ][AsyncSock         ] [eospublic.cern.ch:1094.0] Async connection call returned
[2022-04-22 09:42:37.614196 +0800][Debug  ][XRootDTransport   ] [eospublic.cern.ch:1094.0] Sending out the initial hand shake + kXR_protocol
[2022-04-22 09:42:37.614263 +0800][Dump   ][AsyncSock         ] [eospublic.cern.ch:1094.0] Wrote a message:  (0xec001430), 44 bytes
[2022-04-22 09:42:37.919823 +0800][Dump   ][XRootDTransport   ] [msg: 0xec001690] Expecting 8 bytes of message body
[2022-04-22 09:42:37.919898 +0800][Dump   ][AsyncSock         ] [eospublic.cern.ch:1094.0] Received message header, size: 8
[2022-04-22 09:42:37.919916 +0800][Dump   ][AsyncSock         ] [eospublic.cern.ch:1094.0] Received a message of 16 bytes
[2022-04-22 09:42:37.919933 +0800][Debug  ][XRootDTransport   ] [eospublic.cern.ch:1094.0] Got the server hand shake response (type: manager [], protocol version 400)
[2022-04-22 09:42:37.919962 +0800][Dump   ][XRootDTransport   ] [msg: 0xec001690] Expecting 8 bytes of message body
[2022-04-22 09:42:37.919978 +0800][Dump   ][AsyncSock         ] [eospublic.cern.ch:1094.0] Received message header, size: 8
[2022-04-22 09:42:37.919993 +0800][Dump   ][AsyncSock         ] [eospublic.cern.ch:1094.0] Received a message of 16 bytes
[2022-04-22 09:42:37.920015 +0800][Debug  ][XRootDTransport   ] [eospublic.cern.ch:1094.0] kXR_protocol successful (type: manager [], protocol version 400)
[2022-04-22 09:42:37.920386 +0800][Debug  ][XRootDTransport   ] [eospublic.cern.ch:1094.0] Sending out kXR_login request, username: shamrock, cgi: ?xrd.cc=us&xrd.tz=8&xrd.appname=xrdcp&xrd.info=&xrd.hostname=nixos-202104&xrd.rn=unknown, dual-stack: true, private IPv4: true, private IPv6: true
[2022-04-22 09:42:37.920454 +0800][Dump   ][AsyncSock         ] [eospublic.cern.ch:1094.0] Wrote a message:  (0xec001840), 112 bytes
[2022-04-22 09:42:38.329306 +0800][Dump   ][XRootDTransport   ] [msg: 0xec001430] Expecting 135 bytes of message body
[2022-04-22 09:42:38.329376 +0800][Dump   ][AsyncSock         ] [eospublic.cern.ch:1094.0] Received message header, size: 8
[2022-04-22 09:42:38.329398 +0800][Dump   ][AsyncSock         ] [eospublic.cern.ch:1094.0] Received a message of 143 bytes
[2022-04-22 09:42:38.329420 +0800][Debug  ][XRootDTransport   ] [eospublic.cern.ch:1094.0] Logged in, session: 58bd960721730000220f000064759707
[2022-04-22 09:42:38.329435 +0800][Debug  ][XRootDTransport   ] [eospublic.cern.ch:1094.0] Authentication is required: &P=krb5,xrootd/eospublic.cern.ch@CERN.CH&P=gsi,v:10400,c:ssl,ca:5168735f.0|4339b4bc.0&P=sss,0.13:/etc/eos.keytab&P=unix
[2022-04-22 09:42:38.329452 +0800][Debug  ][XRootDTransport   ] [eospublic.cern.ch:1094.0] Sending authentication data
[2022-04-22 09:42:38.329696 +0800][Error  ][XRootDTransport   ] Unable to get the security framework: Plugin No such file or directory loading seclib libXrdSec-5.so
[2022-04-22 09:42:38.332027 +0800][Error  ][AsyncSock         ] [eospublic.cern.ch:1094.0] Socket error while handshaking: [FATAL] Auth failed
[2022-04-22 09:42:38.332054 +0800][Debug  ][AsyncSock         ] [eospublic.cern.ch:1094.0] Closing the socket
[2022-04-22 09:42:38.332069 +0800][Debug  ][Poller            ] <[2401:e180:8861:273:d771:cbef:4aba:163e]:49708><--><[2001:1458:301:17::100:e]:1094> Removing socket from the poller
[2022-04-22 09:42:38.332158 +0800][Error  ][PostMaster        ] [eospublic.cern.ch:1094] elapsed = 1, pConnectionWindow = 120 seconds.
[2022-04-22 09:42:38.332223 +0800][Debug  ][AsyncSock         ] [eospublic.cern.ch:1094.0] Attempting connection to [::ffff:128.142.160.145]:1094
[2022-04-22 09:42:38.332309 +0800][Debug  ][Poller            ] Adding socket 0xd3dbd0 to the poller
[2022-04-22 09:42:38.665893 +0800][Debug  ][AsyncSock         ] [eospublic.cern.ch:1094.0] Async connection call returned
[2022-04-22 09:42:38.665998 +0800][Debug  ][XRootDTransport   ] [eospublic.cern.ch:1094.0] Sending out the initial hand shake + kXR_protocol
[2022-04-22 09:42:38.666094 +0800][Dump   ][AsyncSock         ] [eospublic.cern.ch:1094.0] Wrote a message:  (0xd44180), 44 bytes
[2022-04-22 09:42:39.046270 +0800][Dump   ][XRootDTransport   ] [msg: 0xec001430] Expecting 8 bytes of message body
[2022-04-22 09:42:39.046344 +0800][Dump   ][AsyncSock         ] [eospublic.cern.ch:1094.0] Received message header, size: 8
[2022-04-22 09:42:39.046361 +0800][Dump   ][AsyncSock         ] [eospublic.cern.ch:1094.0] Received a message of 16 bytes
[2022-04-22 09:42:39.046377 +0800][Debug  ][XRootDTransport   ] [eospublic.cern.ch:1094.0] Got the server hand shake response (type: manager [], protocol version 400)
[2022-04-22 09:42:39.046405 +0800][Dump   ][XRootDTransport   ] [msg: 0xec001430] Expecting 8 bytes of message body
[2022-04-22 09:42:39.046419 +0800][Dump   ][AsyncSock         ] [eospublic.cern.ch:1094.0] Received message header, size: 8
[2022-04-22 09:42:39.046432 +0800][Dump   ][AsyncSock         ] [eospublic.cern.ch:1094.0] Received a message of 16 bytes
[2022-04-22 09:42:39.046452 +0800][Debug  ][XRootDTransport   ] [eospublic.cern.ch:1094.0] kXR_protocol successful (type: manager [], protocol version 400)
[2022-04-22 09:42:39.046852 +0800][Debug  ][XRootDTransport   ] [eospublic.cern.ch:1094.0] Sending out kXR_login request, username: shamrock, cgi: ?xrd.cc=us&xrd.tz=8&xrd.appname=xrdcp&xrd.info=&xrd.hostname=nixos-202104&xrd.rn=unknown, dual-stack: true, private IPv4: true, private IPv6: true
[2022-04-22 09:42:39.046931 +0800][Dump   ][AsyncSock         ] [eospublic.cern.ch:1094.0] Wrote a message:  (0xec001690), 112 bytes
[2022-04-22 09:42:39.455691 +0800][Dump   ][XRootDTransport   ] [msg: 0xd44180] Expecting 135 bytes of message body
[2022-04-22 09:42:39.455785 +0800][Dump   ][AsyncSock         ] [eospublic.cern.ch:1094.0] Received message header, size: 8
[2022-04-22 09:42:39.455811 +0800][Dump   ][AsyncSock         ] [eospublic.cern.ch:1094.0] Received a message of 143 bytes
[2022-04-22 09:42:39.455842 +0800][Debug  ][XRootDTransport   ] [eospublic.cern.ch:1094.0] Logged in, session: 72bd9607217300007a0d000080759707
[2022-04-22 09:42:39.455858 +0800][Debug  ][XRootDTransport   ] [eospublic.cern.ch:1094.0] Authentication is required: &P=krb5,xrootd/eospublic.cern.ch@CERN.CH&P=gsi,v:10400,c:ssl,ca:5168735f.0|4339b4bc.0&P=sss,0.13:/etc/eos.keytab&P=unix
[2022-04-22 09:42:39.455872 +0800][Debug  ][XRootDTransport   ] [eospublic.cern.ch:1094.0] Sending authentication data
[2022-04-22 09:42:39.455998 +0800][Error  ][XRootDTransport   ] Unable to get the security framework: Plugin No such file or directory loading seclib libXrdSec-5.so
[2022-04-22 09:42:39.456046 +0800][Error  ][AsyncSock         ] [eospublic.cern.ch:1094.0] Socket error while handshaking: [FATAL] Auth failed
[2022-04-22 09:42:39.456067 +0800][Debug  ][AsyncSock         ] [eospublic.cern.ch:1094.0] Closing the socket
[2022-04-22 09:42:39.456092 +0800][Debug  ][Poller            ] <[::ffff:192.168.190.108]:51900><--><[::ffff:128.142.160.145]:1094> Removing socket from the poller
[2022-04-22 09:42:39.456204 +0800][Error  ][PostMaster        ] [eospublic.cern.ch:1094] elapsed = 1, pConnectionWindow = 120 seconds.
[2022-04-22 09:42:39.456242 +0800][Error  ][PostMaster        ] [eospublic.cern.ch:1094] Unable to recover: [FATAL] Auth failed.
[2022-04-22 09:42:39.456288 +0800][Error  ][XRootD            ] [eospublic.cern.ch:1094] Impossible to send message kXR_open (file: /eos/opendata/cms/MonteCarloCASTOR/MinBias_TuneZ2_7TeV_pythia6_cff_py_GEN_SIM_START311_V2_Dec11_v2/MinBias_TuneZ2_7TeV_pythia6_cff_py_Step3_START42_V11_Dec11_v2/86bcdbe9c73956c342e477ba771c41c7/STEP2_RAW2DIGI_L1Reco_RECO_7TeV_10_1_s8p.root, mode: 00, flags: kXR_open_read kXR_async kXR_retstat ). Trying to recover.
[2022-04-22 09:42:39.456323 +0800][Debug  ][XRootD            ] [eospublic.cern.ch:1094] Handling error while processing kXR_open (file: /eos/opendata/cms/MonteCarloCASTOR/MinBias_TuneZ2_7TeV_pythia6_cff_py_GEN_SIM_START311_V2_Dec11_v2/MinBias_TuneZ2_7TeV_pythia6_cff_py_Step3_START42_V11_Dec11_v2/86bcdbe9c73956c342e477ba771c41c7/STEP2_RAW2DIGI_L1Reco_RECO_7TeV_10_1_s8p.root, mode: 00, flags: kXR_open_read kXR_async kXR_retstat ): [FATAL] Auth failed.
[2022-04-22 09:42:39.456353 +0800][Debug  ][ExDbgMsg          ] [eospublic.cern.ch:1094] Passing to the thread-pool MsgHandler: 0xd424f0 (message: kXR_open (file: /eos/opendata/cms/MonteCarloCASTOR/MinBias_TuneZ2_7TeV_pythia6_cff_py_GEN_SIM_START311_V2_Dec11_v2/MinBias_TuneZ2_7TeV_pythia6_cff_py_Step3_START42_V11_Dec11_v2/86bcdbe9c73956c342e477ba771c41c7/STEP2_RAW2DIGI_L1Reco_RECO_7TeV_10_1_s8p.root, mode: 00, flags: kXR_open_read kXR_async kXR_retstat ) ).
[2022-04-22 09:42:39.456521 +0800][Debug  ][ExDbgMsg          ] [eospublic.cern.ch:1094] Calling MsgHandler: 0xd424f0 (message: kXR_open (file: /eos/opendata/cms/MonteCarloCASTOR/MinBias_TuneZ2_7TeV_pythia6_cff_py_GEN_SIM_START311_V2_Dec11_v2/MinBias_TuneZ2_7TeV_pythia6_cff_py_Step3_START42_V11_Dec11_v2/86bcdbe9c73956c342e477ba771c41c7/STEP2_RAW2DIGI_L1Reco_RECO_7TeV_10_1_s8p.root, mode: 00, flags: kXR_open_read kXR_async kXR_retstat ) ) with status: [FATAL] Auth failed.
[2022-04-22 09:42:39.456638 +0800][Debug  ][File              ] [0xd3cf10@root://eospublic.cern.ch:1094//eos/opendata/cms/MonteCarloCASTOR/MinBias_TuneZ2_7TeV_pythia6_cff_py_GEN_SIM_START311_V2_Dec11_v2/MinBias_TuneZ2_7TeV_pythia6_cff_py_Step3_START42_V11_Dec11_v2/86bcdbe9c73956c342e477ba771c41c7/STEP2_RAW2DIGI_L1Reco_RECO_7TeV_10_1_s8p.root?xrdcl.requuid=486fcf91-14cc-4617-85cb-cf284e63621f] Open has returned with status [FATAL] Auth failed: Could not load authentication handler.
[2022-04-22 09:42:39.456677 +0800][Debug  ][File              ] [0xd3cf10@root://eospublic.cern.ch:1094//eos/opendata/cms/MonteCarloCASTOR/MinBias_TuneZ2_7TeV_pythia6_cff_py_GEN_SIM_START311_V2_Dec11_v2/MinBias_TuneZ2_7TeV_pythia6_cff_py_Step3_START42_V11_Dec11_v2/86bcdbe9c73956c342e477ba771c41c7/STEP2_RAW2DIGI_L1Reco_RECO_7TeV_10_1_s8p.root?xrdcl.requuid=486fcf91-14cc-4617-85cb-cf284e63621f] Error while opening at eospublic.cern.ch:1094: [FATAL] Auth failed: Could not load authentication handler.
[2022-04-22 09:42:39.456711 +0800][Debug  ][ExDbgMsg          ] [eospublic.cern.ch:1094] Destroying MsgHandler: 0xd424f0.
[0B/0B][100%][==================================================][0B/s]
Run: [FATAL] Auth failed: Could not load authentication handler. (source)
[2022-04-22 09:42:39.457436 +0800][Debug  ][JobMgr            ] Stopping the job manager...
[2022-04-22 09:42:39.457472 +0800][Dump   ][JobMgr            ] Stopping worker #0...
[2022-04-22 09:42:39.457763 +0800][Dump   ][JobMgr            ] Worker #0 stopped
[2022-04-22 09:42:39.457817 +0800][Dump   ][JobMgr            ] Stopping worker #1...
[2022-04-22 09:42:39.458029 +0800][Dump   ][JobMgr            ] Worker #1 stopped
[2022-04-22 09:42:39.458084 +0800][Dump   ][JobMgr            ] Stopping worker #2...
[2022-04-22 09:42:39.458276 +0800][Dump   ][JobMgr            ] Worker #2 stopped
[2022-04-22 09:42:39.458329 +0800][Debug  ][JobMgr            ] Job manager stopped
[2022-04-22 09:42:39.458344 +0800][Debug  ][TaskMgr           ] Stopping the task manager...
[2022-04-22 09:42:39.458679 +0800][Debug  ][TaskMgr           ] Task manager stopped
[2022-04-22 09:42:39.458753 +0800][Debug  ][Poller            ] Stopping the poller...
[2022-04-22 09:42:39.458936 +0800][Debug  ][TaskMgr           ] Requesting unregistration of: "TickGeneratorTask for: root://eospublic.cern.ch:1094"
[2022-04-22 09:42:39.459006 +0800][Debug  ][AsyncSock         ] [eospublic.cern.ch:1094.0] Closing the socket
[2022-04-22 09:42:39.459024 +0800][Debug  ][PostMaster        ] [eospublic.cern.ch:1094] Destroying stream
[2022-04-22 09:42:39.459036 +0800][Debug  ][AsyncSock         ] [eospublic.cern.ch:1094.0] Closing the socket

Notify maintainers

xrootd is packaged by myself, but I haven't found the solution. Suggestions and helps are more than welcom.

Metadata

Please run nix-shell -p nix-info --run "nix-info -m" and paste the result.

[user@system:~]$ nix-shell -p nix-info --run "nix-info -m"
 - system: `"x86_64-linux"`
 - host os: `Linux 5.10.98, NixOS, 21.11 (Porcupine)`
 - multi-user?: `yes`
 - sandbox: `yes`
 - version: `nix-env (Nix) 2.5.0pre20211206_d1aaa7e`
 - nixpkgs: `/nix/store/9dmig1pv9njj5kswvs8yvw3qp6b81zkd-source`

@ajs124
Copy link
Member

ajs124 commented Jul 10, 2022

This is probably because lib/libXrdUtils.so.3.0.0 has the wrong RUNPATH. How to fix that though? No idea.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
0.kind: bug 2.status: stale https://github.com/NixOS/nixpkgs/blob/master/.github/STALE-BOT.md
Projects
None yet
2 participants