diff --git a/.github/workflows/CI.yml b/.github/workflows/CI.yml index b537058620b..c108b5b0584 100644 --- a/.github/workflows/CI.yml +++ b/.github/workflows/CI.yml @@ -72,7 +72,9 @@ jobs: zlib-dev - name: Clone repository - uses: actions/checkout@v1 + uses: actions/checkout@v4 + with: + fetch-depth: 0 - name: Setup GitHub runner user within container run: adduser -D --uid 1001 runner && chown -R runner:runner ${GITHUB_WORKSPACE} @@ -95,7 +97,7 @@ jobs: env: ACTIONS_ALLOW_USE_UNSECURE_NODE_VERSION: true - ACTIONS_RUNNER_FORCE_ACTIONS_NODE_VERSION: node16 + ACTIONS_RUNNER_FORCE_ACTIONS_NODE_VERSION: node18 CMAKE_ARGS: "-DCMAKE_INSTALL_PREFIX=/usr;-DCMAKE_INSTALL_RPATH='$ORIGIN/../$LIB'" steps: @@ -118,7 +120,7 @@ jobs: yum install -y epel-rpm-macros git rpmdevtools sudo yum-utils - name: Clone repository - uses: actions/checkout@v3 + uses: actions/checkout@v1 with: fetch-depth: 0 @@ -204,6 +206,42 @@ jobs: tests/post-install.sh tests/check-headers.sh + alma10beta: + name: Alma 10 (beta) + runs-on: ubuntu-latest + container: almalinux:10-kitten + + env: + CMAKE_ARGS: "-DCMAKE_INSTALL_PREFIX=/usr;-DCMAKE_INSTALL_RPATH='$ORIGIN/../$LIB'" + + steps: + - name: Install dependencies + run: | + dnf install -y dnf-plugins-core epel-release git rpmdevtools sudo + dnf config-manager --set-enabled crb + + - name: Clone repository + uses: actions/checkout@v4 + with: + fetch-depth: 0 + + - name: Setup GitHub runner user within container + run: adduser --uid 1001 runner && chown -R runner:runner ${GITHUB_WORKSPACE} + + - name: Install XRootD build dependencies + run: dnf builddep -y xrootd.spec + + - name: Build and Test with CTest + run: sudo -E -u runner ctest -VV -S test.cmake + + - name: Install with CMake + run: cmake --install build + + - name: Run post-install tests + run: | + tests/post-install.sh + tests/check-headers.sh + fedora: name: Fedora runs-on: ubuntu-latest diff --git a/.github/workflows/RPM.yml b/.github/workflows/RPM.yml index c0c06436ad4..d3626b71d2e 100644 --- a/.github/workflows/RPM.yml +++ b/.github/workflows/RPM.yml @@ -26,7 +26,7 @@ jobs: env: ACTIONS_ALLOW_USE_UNSECURE_NODE_VERSION: true - ACTIONS_RUNNER_FORCE_ACTIONS_NODE_VERSION: node16 + ACTIONS_RUNNER_FORCE_ACTIONS_NODE_VERSION: node18 steps: - name: Use CentOS 7 Vault Repository URLs @@ -69,16 +69,6 @@ jobs: - name: Run post-install tests run: tests/post-install.sh - - name: Move RPMs to Artifact Directory - run: mkdir RPMS && mv $(rpm -E '%{_rpmdir}')/*/*.rpm RPMS/ - - - name: Upload Artifacts - uses: actions/upload-artifact@v3 - with: - name: centos7 - path: RPMS - retention-days: 14 - alma8: name: Alma Linux 8 runs-on: ubuntu-latest @@ -169,10 +159,55 @@ jobs: path: RPMS retention-days: 14 + alma10beta: + name: Alma Linux 10 (beta) + runs-on: ubuntu-latest + container: almalinux:9 + + steps: + - name: Install git + run: yum install -y git + + - name: Clone repository + uses: actions/checkout@v4 + with: + fetch-depth: 0 + + - name: Install RPM development tools + run: | + dnf install -y epel-release rpmdevtools dnf-plugins-core + dnf config-manager --set-enabled crb + + - name: Install XRootD build dependencies + run: dnf builddep -y xrootd.spec + + - name: Build RPMs + run: | + rpmdev-setuptree + git config --global --add safe.directory "$GITHUB_WORKSPACE" + git archive --prefix xrootd/ -o $(rpm -E '%{_sourcedir}')/xrootd.tar.gz HEAD + rpmbuild -bb --with git xrootd.spec + + - name: Install RPMs + run: dnf install -y $(rpm -E '%{_rpmdir}')/*/*.rpm + + - name: Run post-install tests + run: tests/post-install.sh + + - name: Move RPMs to Artifact Directory + run: mkdir RPMS && mv $(rpm -E '%{_rpmdir}')/ RPMS$(rpm -E '%{dist}' | tr . /) + + - name: Upload Artifacts + uses: actions/upload-artifact@v4 + with: + name: alma10 + path: RPMS + retention-days: 14 + fedora: - name: Fedora 40 + name: Fedora 41 runs-on: ubuntu-latest - container: fedora:40 + container: fedora:41 steps: - name: Install git diff --git a/.gitlab-ci.yml b/.gitlab-ci.yml index 882c10a0388..bc7d0188635 100644 --- a/.gitlab-ci.yml +++ b/.gitlab-ci.yml @@ -104,10 +104,17 @@ AlmaLinux 9: - dnf config-manager --set-enabled crb <<: *rpm_build_dnf -Fedora 39: - image: fedora:39 +AlmaLinux 10 (beta): + image: almalinux:10-kitten + before_script: + - dnf install -y epel-release + - dnf config-manager --set-enabled crb <<: *rpm_build_dnf Fedora 40: image: fedora:40 <<: *rpm_build_dnf + +Fedora 41: + image: fedora:41 + <<: *rpm_build_dnf diff --git a/Doxyfile b/Doxyfile index a85babb7c04..f3bc4c5249e 100644 --- a/Doxyfile +++ b/Doxyfile @@ -492,7 +492,7 @@ LOOKUP_CACHE_SIZE = 2 # DOT_NUM_THREADS setting. # Minimum value: 0, maximum value: 32, default value: 1. -NUM_PROC_THREADS = 0 +NUM_PROC_THREADS = 1 # If the TIMESTAMP tag is set different from NO then each generated page will # contain the date or date and time when the page was generated. Setting this to diff --git a/bindings/python/libs/client/copyprocess.py b/bindings/python/libs/client/copyprocess.py index e934dc4ac90..6d4a1ff0f7f 100644 --- a/bindings/python/libs/client/copyprocess.py +++ b/bindings/python/libs/client/copyprocess.py @@ -26,6 +26,7 @@ from pyxrootd import client from XRootD.client.url import URL from XRootD.client.responses import XRootDStatus +from .env import EnvGetInt, EnvGetString class ProgressHandlerWrapper(object): """Internal progress handler wrapper to convert parameters to friendly @@ -83,17 +84,17 @@ def add_job(self, checksumtype = '', checksumpreset = '', dynamicsource = False, - chunksize = 8388608, - parallelchunks = 4, - inittimeout = 600, - tpctimeout = 1800, + chunksize = EnvGetInt('CPChunkSize'), + parallelchunks = EnvGetInt('CPParallelChunks'), + inittimeout = EnvGetInt('CPInitTimeout'), + tpctimeout = EnvGetInt('CPTPCTimeout'), rmBadCksum = False, - cptimeout = 0, - xrateThreshold = 0, + cptimeout = EnvGetInt('CPTimeout'), + xrateThreshold = EnvGetInt('XRateThreshold'), xrate = 0, - retry = 0, + retry = EnvGetInt('CpRetry'), cont = False, - rtrplc = "force" ): + rtrplc = EnvGetString('CpRetryPolicy') ): """Add a job to the copy process. :param source: original source URL diff --git a/bindings/python/setup.py b/bindings/python/setup.py index 737f2d6bd53..1486df4ffd5 100644 --- a/bindings/python/setup.py +++ b/bindings/python/setup.py @@ -118,7 +118,7 @@ def build_extensions(self): os.makedirs(self.build_temp) check_call([cmake, ext.src, '-B', self.build_temp] + cmake_args) - check_call([cmake, '--build', self.build_temp, '--parallel']) + check_call([cmake, '--build', self.build_temp]) version = get_version() diff --git a/cmake/XRootDOSDefs.cmake b/cmake/XRootDOSDefs.cmake index 342838ef737..e5f35fcf051 100644 --- a/cmake/XRootDOSDefs.cmake +++ b/cmake/XRootDOSDefs.cmake @@ -10,8 +10,6 @@ set( Hurd FALSE ) set( MacOSX FALSE ) set( Solaris FALSE ) -set( XrdClPipelines FALSE ) - add_definitions( -D_LARGEFILE_SOURCE -D_LARGEFILE64_SOURCE -D_FILE_OFFSET_BITS=64 ) define_default( LIBRARY_PATH_PREFIX "lib" ) @@ -29,14 +27,6 @@ if( ENABLE_TSAN ) set(CMAKE_CXX_FLAGS "${CMAKE_CXX_FLAGS} -fsanitize=thread") endif() -#------------------------------------------------------------------------------- -# Enable XrdCl::Pipelines for clang compiler -# Note: once we move to c++14 globaly we can remove this -#------------------------------------------------------------------------------- -if( CMAKE_CXX_COMPILER_ID STREQUAL "Clang" ) - set( XrdClPipelines TRUE ) -endif() - #------------------------------------------------------------------------------- # GCC #------------------------------------------------------------------------------- @@ -51,12 +41,12 @@ if( CMAKE_COMPILER_IS_GNUCXX ) set( CMAKE_CXX_FLAGS "${CMAKE_CXX_FLAGS} -Werror" ) endif() set( CMAKE_CXX_FLAGS "${CMAKE_CXX_FLAGS} -Wno-unused-parameter" ) +endif() - execute_process( COMMAND ${CMAKE_C_COMPILER} -dumpversion - OUTPUT_VARIABLE GCC_VERSION ) - if( GCC_VERSION VERSION_GREATER 4.8.0 ) - set( XrdClPipelines TRUE ) - endif() +# Disable warnings with nvc++ (for when we are built as ROOT built-in dependency) + +if(CMAKE_CXX_COMPILER_ID MATCHES "NVHPC") + add_compile_options(-w) endif() #------------------------------------------------------------------------------- @@ -106,11 +96,10 @@ endif() #------------------------------------------------------------------------------- if( APPLE ) set( MacOSX TRUE ) - set( XrdClPipelines TRUE ) set(CMAKE_MACOSX_RPATH TRUE) set(CMAKE_INSTALL_RPATH_USE_LINK_PATH TRUE) - set(CMAKE_INSTALL_RPATH "@loader_path/../lib") + set(CMAKE_INSTALL_RPATH "@loader_path/../lib" CACHE STRING "Install RPATH") # this is here because of Apple deprecating openssl and krb5 set( CMAKE_CXX_FLAGS "${CMAKE_CXX_FLAGS} -Wno-deprecated-declarations" ) diff --git a/docs/ReleaseNotes.txt b/docs/ReleaseNotes.txt index 5bb43c941d7..fb00f640979 100644 --- a/docs/ReleaseNotes.txt +++ b/docs/ReleaseNotes.txt @@ -5,6 +5,44 @@ XRootD Release Notes ============= +------------- +Version 5.7.2 +------------- + ++ **Performance Improvements** + **[XrdHttp]** Avoid calling `stat` on HTTP GET (#2299, #2300) + **[XrdPfc]** Fix behavior and improve performance of stat calls (#2349) + ++ **Major bug fixes** + **[XrdOuc]** Migrate away from `std::regex` to avoid stack overflow bug in C++ standard library + **[XrdHttp]** Client plugin returning XrdCl::errSocketTimeout triggers near-infinite loop in XrdHttp (#2357) + **[XrdHttp]** Invalid chunk framing for HTTP (#2351) + ++ **Minor bug fixes** + **[Misc]** Fix various issues reported by code scanning tool CodeQL + **[Python]** Do not build in parallel by default to avoid using too many threads (#2356) + **[Python]** Fix RPATH setting for Python bindings on macOS (#2350) + **[Python]** Make environment take precedence over default arguments of add_job (#1657) + **[XCache]** Add number of bytes prefetched and written to disk to the gstream record (#2366) + **[XCache]** Fix errors that happen under high load (#2360) + **[XCache]** Reduce verbosity of error messages (#2288, #2327, #2370) + **[XrdCl]** xrdfs ls on a directory on a server runs locate (#2120) + **[XrdHttpTPC]** Race condition during HTTP TPC request may cause file deletion (#2354) + **[XrdHttp]** Redact tokens from additional places to prevent them leaking into logs (#2343, #2371) + **[XrdSut]** Fix narrowing conversion on 32-bit systems (#2272) + **[XrdSys]** Protect against array index out of bounds (#2329) + ++ **Miscellaneous** + **[CI]** Update GitHub Actions and GitLab CI, add Alma 10 beta builds + **[CMake]** Support building with Nvidia HPC Toolkit compilers (#2361) + **[Doxygen]** Make documentation builds reproducible (#2337) + **[Tests]** Avoid test failures when $RANDOM returns a multiple of 1024 (#2344) + **[Tests]** Increase default timeouts in client/server tests + **[Tests]** More HTTP tests added to the test suite (#2375) + **[XrdCl]** Downgrade force disconnect error message to debug level (#2370) + **[XrdCl]** Handle kXR_attrCache attribute in protocol response + **[XrdCms]** Improve DFS error message to be less confusing (#2345) + ------------- Version 5.7.1 ------------- diff --git a/setup.py b/setup.py index c676e0854fb..fd5782679da 100644 --- a/setup.py +++ b/setup.py @@ -87,7 +87,7 @@ def build_extensions(self): os.makedirs(self.build_temp) check_call([cmake, ext.src, '-B', self.build_temp] + cmake_args) - check_call([cmake, '--build', self.build_temp, '--parallel']) + check_call([cmake, '--build', self.build_temp]) version = get_version() diff --git a/src/Xrd/XrdConfig.cc b/src/Xrd/XrdConfig.cc index 857ffcde1b3..65a8303a6f5 100644 --- a/src/Xrd/XrdConfig.cc +++ b/src/Xrd/XrdConfig.cc @@ -1427,7 +1427,7 @@ int XrdConfig::SetupAPath() // #ifndef WIN32 if (chmod(AdminPath, AdminMode & ~S_IWGRP)) - {Log.Emsg("Config", errno, "set permision for admin path", AdminPath); + {Log.Emsg("Config", errno, "set permission for admin path", AdminPath); return 1; } #endif diff --git a/src/XrdApps/Xrdadler32.cc b/src/XrdApps/Xrdadler32.cc index ab333656ec1..3c512551982 100644 --- a/src/XrdApps/Xrdadler32.cc +++ b/src/XrdApps/Xrdadler32.cc @@ -186,14 +186,14 @@ int main(int argc, char *argv[]) } if (argc == 1 || path[0] == '\0') { /* this is a local file */ - if (argc > 1) + if (argc > 1) { strcpy(path, argv[1]); - rc = stat(path, &stbuf); - if (rc != 0 || ! S_ISREG(stbuf.st_mode) || - (fd = open(path,O_RDONLY)) < 0) + if ((fd = open(path, O_RDONLY)) < 0 || fstat(fd, &stbuf) != 0 || !S_ISREG(stbuf.st_mode)) { - printf("Error_accessing %s\n", path); + if (fd != -1) + close(fd); + printf("Error opening %s: %s\n", path, strerror(errno)); return 1; } else /* see if the adler32 is saved in attribute already */ diff --git a/src/XrdCl/CMakeLists.txt b/src/XrdCl/CMakeLists.txt index a8fc5424271..11472a07b33 100644 --- a/src/XrdCl/CMakeLists.txt +++ b/src/XrdCl/CMakeLists.txt @@ -8,20 +8,17 @@ set( XRD_CL_SOVERSION 3 ) #------------------------------------------------------------------------------- # The XrdCl Pipelining API -# (we build this API only if the compiler has a good support for c++11) #------------------------------------------------------------------------------- -if( XrdClPipelines ) - set( XrdClPipelineSources - XrdClOperations.cc XrdClOperations.hh - XrdClOperationHandlers.hh - XrdClArg.hh - XrdClFwd.hh - XrdClParallelOperation.hh - XrdClFileOperations.hh - XrdClFileSystemOperations.hh - XrdClZipOperations.hh - ) -endif() +set( XrdClPipelineSources + XrdClOperations.cc XrdClOperations.hh + XrdClOperationHandlers.hh + XrdClArg.hh + XrdClFwd.hh + XrdClParallelOperation.hh + XrdClFileOperations.hh + XrdClFileSystemOperations.hh + XrdClZipOperations.hh +) #------------------------------------------------------------------------------- # XrdEc sources diff --git a/src/XrdCl/XrdClAsyncMsgReader.hh b/src/XrdCl/XrdClAsyncMsgReader.hh index cae92bfeab0..0f4587c39af 100644 --- a/src/XrdCl/XrdClAsyncMsgReader.hh +++ b/src/XrdCl/XrdClAsyncMsgReader.hh @@ -109,14 +109,14 @@ namespace XrdCl if( !st.IsOK() || st.code == suRetry ) return st; - log->Dump( AsyncSockMsg, "[%s] Received message header for 0x%x size: %d", + log->Dump( AsyncSockMsg, "[%s] Received message header for %p size: %d", strmname.c_str(), inmsg.get(), inmsg->GetCursor() ); ServerResponse *rsp = (ServerResponse*)inmsg->GetBuffer(); if( rsp->hdr.status == kXR_attn ) { log->Dump( AsyncSockMsg, "[%s] Will readout the attn action code " - "of message 0x%x", strmname.c_str(), inmsg.get() ); + "of message %p", strmname.c_str(), inmsg.get() ); inmsg->ReAllocate( 16 ); // header (bytes 8) + action code (8 bytes) readstage = ReadAttn; continue; @@ -128,7 +128,7 @@ namespace XrdCl if( inhandler ) { log->Dump( AsyncSockMsg, "[%s] Will use the raw handler to read body " - "of message 0x%x", strmname.c_str(), inmsg.get() ); + "of message %p", strmname.c_str(), inmsg.get() ); //-------------------------------------------------------------- // The next step is to read raw data //-------------------------------------------------------------- @@ -260,7 +260,7 @@ namespace XrdCl //---------------------------------------------------------------- // Report the incoming message //---------------------------------------------------------------- - log->Dump( AsyncSockMsg, "[%s] Received message 0x%x of %d bytes", + log->Dump( AsyncSockMsg, "[%s] Received message %p of %d bytes", strmname.c_str(), inmsg.get(), inmsgsize ); strm.OnIncoming( substrmnb, std::move( inmsg ), inmsgsize ); diff --git a/src/XrdCl/XrdClAsyncMsgWriter.hh b/src/XrdCl/XrdClAsyncMsgWriter.hh index 52458642eb8..edf6199e4c8 100644 --- a/src/XrdCl/XrdClAsyncMsgWriter.hh +++ b/src/XrdCl/XrdClAsyncMsgWriter.hh @@ -161,7 +161,7 @@ namespace XrdCl if( !st.IsOK() || st.code == suRetry ) return st; outmsgsize += wrtcnt; log->Dump( AsyncSockMsg, "[%s] Wrote %d bytes of raw data of message" - "(0x%x) body.", strmname.c_str(), wrtcnt, outmsg ); + "(%p) body.", strmname.c_str(), wrtcnt, outmsg ); } //---------------------------------------------------------------- // The next step is to finalize the write operation @@ -182,7 +182,7 @@ namespace XrdCl return st; } - log->Dump( AsyncSockMsg, "[%s] Successfully sent message: %s (0x%x).", + log->Dump( AsyncSockMsg, "[%s] Successfully sent message: %s (%p).", strmname.c_str(), outmsg->GetObfuscatedDescription().c_str(), outmsg ); strm.OnMessageSent( substrmnb, outmsg, outmsgsize ); diff --git a/src/XrdCl/XrdClCopy.cc b/src/XrdCl/XrdClCopy.cc index 53117e68a63..47b21570daf 100644 --- a/src/XrdCl/XrdClCopy.cc +++ b/src/XrdCl/XrdClCopy.cc @@ -838,7 +838,7 @@ int main( int argc, char **argv ) } log->Dump( AppMsg, "Processing source entry: %s, type %s, target file: %s, logLevel = %d", sourcePathObf.c_str(), FileType2String( sourceFile->Protocol ), - destPathObf.c_str() ); + destPathObf.c_str(), log->GetLevel() ); //-------------------------------------------------------------------------- // Set up the job diff --git a/src/XrdCl/XrdClCopyProcess.cc b/src/XrdCl/XrdClCopyProcess.cc index c067062b177..72ef3bb52dd 100644 --- a/src/XrdCl/XrdClCopyProcess.cc +++ b/src/XrdCl/XrdClCopyProcess.cc @@ -368,7 +368,7 @@ namespace XrdCl Log *log = DefaultEnv::GetLog(); std::vector::iterator it; - log->Debug( UtilityMsg, "CopyProcess: %d jobs to prepare", + log->Debug( UtilityMsg, "CopyProcess: %llu jobs to prepare", pImpl->pJobProperties.size() ); std::map targetFlags; diff --git a/src/XrdCl/XrdClFileStateHandler.cc b/src/XrdCl/XrdClFileStateHandler.cc index ca11c41d1fe..244fa9b9c19 100644 --- a/src/XrdCl/XrdClFileStateHandler.cc +++ b/src/XrdCl/XrdClFileStateHandler.cc @@ -166,7 +166,7 @@ namespace if( crcval != cksums[pgnb] ) { Log *log = DefaultEnv::GetLog(); - log->Info( FileMsg, "[0x%x@%s] Received corrupted page, will retry page #%d.", + log->Info( FileMsg, "[%p@%s] Received corrupted page, will retry page #%llu.", this, stateHandler->pFileUrl->GetObfuscatedURL().c_str(), pgnb ); XRootDStatus st = XrdCl::FileStateHandler::PgReadRetry( stateHandler, pgoff, pgsize, pgnb, buffer, this, 0 ); @@ -257,7 +257,7 @@ namespace if( !status->IsOK() ) { Log *log = DefaultEnv::GetLog(); - log->Info( FileMsg, "[0x%x@%s] Failed to recover page #%d.", + log->Info( FileMsg, "[%p@%s] Failed to recover page #%llu.", this, pgReadHandler->stateHandler->pFileUrl->GetObfuscatedURL().c_str(), pgnb ); pgReadHandler->HandleResponseWithHosts( status, response, hostList ); delete this; @@ -269,7 +269,7 @@ namespace if( pginf->GetLength() > (uint32_t)XrdSys::PageSize || pginf->GetCksums().size() != 1 ) { Log *log = DefaultEnv::GetLog(); - log->Info( FileMsg, "[0x%x@%s] Failed to recover page #%d.", + log->Info( FileMsg, "[%p@%s] Failed to recover page #%llu.", this, pgReadHandler->stateHandler->pFileUrl->GetObfuscatedURL().c_str(), pgnb ); // we retry a page at a time so the length cannot exceed 4KB DeleteArgs( status, response, hostList ); @@ -282,7 +282,7 @@ namespace if( crcval != pginf->GetCksums().front() ) { Log *log = DefaultEnv::GetLog(); - log->Info( FileMsg, "[0x%x@%s] Failed to recover page #%d.", + log->Info( FileMsg, "[%p@%s] Failed to recover page #%llu.", this, pgReadHandler->stateHandler->pFileUrl->GetObfuscatedURL().c_str(), pgnb ); DeleteArgs( status, response, hostList ); pgReadHandler->HandleResponseWithHosts( new XRootDStatus( stError, errDataError ), 0, 0 ); @@ -291,7 +291,7 @@ namespace } Log *log = DefaultEnv::GetLog(); - log->Info( FileMsg, "[0x%x@%s] Successfully recovered page #%d.", + log->Info( FileMsg, "[%p@%s] Successfully recovered page #%llu.", this, pgReadHandler->stateHandler->pFileUrl->GetObfuscatedURL().c_str(), pgnb ); DeleteArgs( 0, response, hostList ); @@ -800,7 +800,7 @@ namespace XrdCl if( !self->pFileUrl->IsValid() ) { - log->Error( FileMsg, "[0x%x@%s] Trying to open invalid url: %s", + log->Error( FileMsg, "[%p@%s] Trying to open invalid url: %s", self.get(), self->pFileUrl->GetPath().c_str(), url.c_str() ); self->pStatus = XRootDStatus( stError, errInvalidArgs ); self->pFileState = Closed; @@ -817,7 +817,7 @@ namespace XrdCl !self->pDoRecoverRead ) { self->pDoRecoverRead = false; - log->Debug( FileMsg, "[0x%x@%s] Read recovery procedures are disabled", + log->Debug( FileMsg, "[%p@%s] Read recovery procedures are disabled", self.get(), self->pFileUrl->GetObfuscatedURL().c_str() ); } @@ -826,14 +826,14 @@ namespace XrdCl !self->pDoRecoverWrite ) { self->pDoRecoverWrite = false; - log->Debug( FileMsg, "[0x%x@%s] Write recovery procedures are disabled", + log->Debug( FileMsg, "[%p@%s] Write recovery procedures are disabled", self.get(), self->pFileUrl->GetObfuscatedURL().c_str() ); } //-------------------------------------------------------------------------- // Open the file //-------------------------------------------------------------------------- - log->Debug( FileMsg, "[0x%x@%s] Sending an open command", self.get(), + log->Debug( FileMsg, "[%p@%s] Sending an open command", self.get(), self->pFileUrl->GetObfuscatedURL().c_str() ); self->pOpenMode = mode; @@ -898,8 +898,8 @@ namespace XrdCl self->pFileState = CloseInProgress; Log *log = DefaultEnv::GetLog(); - log->Debug( FileMsg, "[0x%x@%s] Sending a close command for handle 0x%x to " - "%s", self.get(), self->pFileUrl->GetObfuscatedURL().c_str(), + log->Debug( FileMsg, "[%p@%s] Sending a close command for handle %#x to %s", + self.get(), self->pFileUrl->GetObfuscatedURL().c_str(), *((uint32_t*)self->pFileHandle), self->pDataServer->GetHostId().c_str() ); //-------------------------------------------------------------------------- @@ -974,8 +974,8 @@ namespace XrdCl } Log *log = DefaultEnv::GetLog(); - log->Debug( FileMsg, "[0x%x@%s] Sending a stat command for handle 0x%x to " - "%s", self.get(), self->pFileUrl->GetObfuscatedURL().c_str(), + log->Debug( FileMsg, "[%p@%s] Sending a stat command for handle %#x to %s", + self.get(), self->pFileUrl->GetObfuscatedURL().c_str(), *((uint32_t*)self->pFileHandle), self->pDataServer->GetHostId().c_str() ); //-------------------------------------------------------------------------- @@ -1021,8 +1021,8 @@ namespace XrdCl return XRootDStatus( stError, errInvalidOp ); Log *log = DefaultEnv::GetLog(); - log->Debug( FileMsg, "[0x%x@%s] Sending a read command for handle 0x%x to " - "%s", self.get(), self->pFileUrl->GetObfuscatedURL().c_str(), + log->Debug( FileMsg, "[%p@%s] Sending a read command for handle %#x to %s", + self.get(), self->pFileUrl->GetObfuscatedURL().c_str(), *((uint32_t*)self->pFileHandle), self->pDataServer->GetHostId().c_str() ); Message *msg; @@ -1076,7 +1076,7 @@ namespace XrdCl if( !issupported ) { - DefaultEnv::GetLog()->Debug( FileMsg, "[0x%x@%s] PgRead not supported; substituting with Read.", + DefaultEnv::GetLog()->Debug( FileMsg, "[%p@%s] PgRead not supported; substituting with Read.", self.get(), self->pFileUrl->GetObfuscatedURL().c_str() ); ResponseHandler *substitHandler = new PgReadSubstitutionHandler( self, handler ); auto st = Read( self, offset, size, buffer, substitHandler, timeout ); @@ -1124,8 +1124,8 @@ namespace XrdCl return XRootDStatus( stError, errInvalidOp ); Log *log = DefaultEnv::GetLog(); - log->Debug( FileMsg, "[0x%x@%s] Sending a pgread command for handle 0x%x to " - "%s", self.get(), self->pFileUrl->GetObfuscatedURL().c_str(), + log->Debug( FileMsg, "[%p@%s] Sending a pgread command for handle %#x to %s", + self.get(), self->pFileUrl->GetObfuscatedURL().c_str(), *((uint32_t*)self->pFileHandle), self->pDataServer->GetHostId().c_str() ); Message *msg; @@ -1180,8 +1180,8 @@ namespace XrdCl return XRootDStatus( stError, errInvalidOp ); Log *log = DefaultEnv::GetLog(); - log->Debug( FileMsg, "[0x%x@%s] Sending a write command for handle 0x%x to " - "%s", self.get(), self->pFileUrl->GetObfuscatedURL().c_str(), + log->Debug( FileMsg, "[%p@%s] Sending a write command for handle %#x to %s", + self.get(), self->pFileUrl->GetObfuscatedURL().c_str(), *((uint32_t*)self->pFileHandle), self->pDataServer->GetHostId().c_str() ); Message *msg; @@ -1226,9 +1226,9 @@ namespace XrdCl if( !XrdSys::KernelBuffer::IsPageAligned( buffer.GetBuffer() ) || self->pIsChannelEncrypted ) { Log *log = DefaultEnv::GetLog(); - log->Info( FileMsg, "[0x%x@%s] Buffer is not page aligned (4KB), cannot " - "convert it to kernel space buffer.", self.get(), self->pFileUrl->GetObfuscatedURL().c_str(), - *((uint32_t*)self->pFileHandle) ); + log->Info( FileMsg, "[%p@%s] Buffer for handle %#x is not page aligned (4KB), " + "cannot convert it to kernel space buffer.", self.get(), + self->pFileUrl->GetObfuscatedURL().c_str(), *((uint32_t*)self->pFileHandle) ); void *buff = buffer.GetBuffer(); uint32_t size = buffer.GetSize(); @@ -1414,20 +1414,20 @@ namespace XrdCl r->Get( inf ); if( inf->NeedRetry() ) // so we failed in the end { - DefaultEnv::GetLog()->Warning( FileMsg, "[0x%x@%s] Failed retransmitting corrupted " + DefaultEnv::GetLog()->Warning( FileMsg, "[%p@%s] Failed retransmitting corrupted " "page: pgoff=%llu, pglen=%du, pgdigest=%du", self.get(), self->pFileUrl->GetObfuscatedURL().c_str(), pgoff, pglen, pgdigest ); pgwrt->SetStatus( new XRootDStatus( stError, errDataError, 0, "Failed to retransmit corrupted page" ) ); } else - DefaultEnv::GetLog()->Info( FileMsg, "[0x%x@%s] Succesfuly retransmitted corrupted " + DefaultEnv::GetLog()->Info( FileMsg, "[%p@%s] Succesfuly retransmitted corrupted " "page: pgoff=%llu, pglen=%du, pgdigest=%du", self.get(), self->pFileUrl->GetObfuscatedURL().c_str(), pgoff, pglen, pgdigest ); } ); auto st = PgWriteRetry( self, pgoff, pglen, pgbuf, pgdigest, h, timeout ); if( !st.IsOK() ) pgwrt->SetStatus( new XRootDStatus( st ) ); - DefaultEnv::GetLog()->Info( FileMsg, "[0x%x@%s] Retransmitting corrupted page: " + DefaultEnv::GetLog()->Info( FileMsg, "[%p@%s] Retransmitting corrupted page: " "pgoff=%llu, pglen=%du, pgdigest=%du", self.get(), self->pFileUrl->GetObfuscatedURL().c_str(), pgoff, pglen, pgdigest ); } @@ -1477,8 +1477,8 @@ namespace XrdCl return XRootDStatus( stError, errInvalidOp ); Log *log = DefaultEnv::GetLog(); - log->Debug( FileMsg, "[0x%x@%s] Sending a pgwrite command for handle 0x%x to " - "%s", self.get(), self->pFileUrl->GetObfuscatedURL().c_str(), + log->Debug( FileMsg, "[%p@%s] Sending a pgwrite command for handle %#x to %s", + self.get(), self->pFileUrl->GetObfuscatedURL().c_str(), *((uint32_t*)self->pFileHandle), self->pDataServer->GetHostId().c_str() ); //-------------------------------------------------------------------------- @@ -1527,8 +1527,8 @@ namespace XrdCl return XRootDStatus( stError, errInvalidOp ); Log *log = DefaultEnv::GetLog(); - log->Debug( FileMsg, "[0x%x@%s] Sending a sync command for handle 0x%x to " - "%s", self.get(), self->pFileUrl->GetObfuscatedURL().c_str(), + log->Debug( FileMsg, "[%p@%s] Sending a sync command for handle %#x to %s", + self.get(), self->pFileUrl->GetObfuscatedURL().c_str(), *((uint32_t*)self->pFileHandle), self->pDataServer->GetHostId().c_str() ); Message *msg; @@ -1566,8 +1566,8 @@ namespace XrdCl return XRootDStatus( stError, errInvalidOp ); Log *log = DefaultEnv::GetLog(); - log->Debug( FileMsg, "[0x%x@%s] Sending a truncate command for handle 0x%x to " - "%s", self.get(), self->pFileUrl->GetObfuscatedURL().c_str(), + log->Debug( FileMsg, "[%p@%s] Sending a truncate command for handle %#x to %s", + self.get(), self->pFileUrl->GetObfuscatedURL().c_str(), *((uint32_t*)self->pFileHandle), self->pDataServer->GetHostId().c_str() ); Message *msg; @@ -1610,8 +1610,8 @@ namespace XrdCl return XRootDStatus( stError, errInvalidOp ); Log *log = DefaultEnv::GetLog(); - log->Debug( FileMsg, "[0x%x@%s] Sending a vector read command for handle " - "0x%x to %s", self.get(), self->pFileUrl->GetObfuscatedURL().c_str(), + log->Debug( FileMsg, "[%p@%s] Sending a vector read command for handle %#x to %s", + self.get(), self->pFileUrl->GetObfuscatedURL().c_str(), *((uint32_t*)self->pFileHandle), self->pDataServer->GetHostId().c_str() ); //-------------------------------------------------------------------------- @@ -1686,8 +1686,8 @@ namespace XrdCl return XRootDStatus( stError, errInvalidOp ); Log *log = DefaultEnv::GetLog(); - log->Debug( FileMsg, "[0x%x@%s] Sending a vector write command for handle " - "0x%x to %s", self.get(), self->pFileUrl->GetObfuscatedURL().c_str(), + log->Debug( FileMsg, "[%p@%s] Sending a vector write command for handle %#x to %s", + self.get(), self->pFileUrl->GetObfuscatedURL().c_str(), *((uint32_t*)self->pFileHandle), self->pDataServer->GetHostId().c_str() ); //-------------------------------------------------------------------------- @@ -1762,8 +1762,8 @@ namespace XrdCl return XRootDStatus( stError, errInvalidOp ); Log *log = DefaultEnv::GetLog(); - log->Debug( FileMsg, "[0x%x@%s] Sending a write command for handle 0x%x to " - "%s", self.get(), self->pFileUrl->GetObfuscatedURL().c_str(), + log->Debug( FileMsg, "[%p@%s] Sending a write command for handle %#x to %s", + self.get(), self->pFileUrl->GetObfuscatedURL().c_str(), *((uint32_t*)self->pFileHandle), self->pDataServer->GetHostId().c_str() ); Message *msg; @@ -1818,8 +1818,8 @@ namespace XrdCl return XRootDStatus( stError, errInvalidOp ); Log *log = DefaultEnv::GetLog(); - log->Debug( FileMsg, "[0x%x@%s] Sending a read command for handle 0x%x to " - "%s", self.get(), self->pFileUrl->GetObfuscatedURL().c_str(), + log->Debug( FileMsg, "[%p@%s] Sending a read command for handle %#x to %s", + self.get(), self->pFileUrl->GetObfuscatedURL().c_str(), *((uint32_t*)self->pFileHandle), self->pDataServer->GetHostId().c_str() ); Message *msg; @@ -1875,8 +1875,8 @@ namespace XrdCl return XRootDStatus( stError, errInvalidOp ); Log *log = DefaultEnv::GetLog(); - log->Debug( FileMsg, "[0x%x@%s] Sending a fcntl command for handle 0x%x to " - "%s", self.get(), self->pFileUrl->GetObfuscatedURL().c_str(), + log->Debug( FileMsg, "[%p@%s] Sending a fcntl command for handle %#x to %s", + self.get(), self->pFileUrl->GetObfuscatedURL().c_str(), *((uint32_t*)self->pFileHandle), self->pDataServer->GetHostId().c_str() ); Message *msg; @@ -1916,8 +1916,8 @@ namespace XrdCl return XRootDStatus( stError, errInvalidOp ); Log *log = DefaultEnv::GetLog(); - log->Debug( FileMsg, "[0x%x@%s] Sending a visa command for handle 0x%x to " - "%s", self.get(), self->pFileUrl->GetObfuscatedURL().c_str(), + log->Debug( FileMsg, "[%p@%s] Sending a visa command for handle %#x to %s", + self.get(), self->pFileUrl->GetObfuscatedURL().c_str(), *((uint32_t*)self->pFileHandle), self->pDataServer->GetHostId().c_str() ); Message *msg; @@ -1956,8 +1956,8 @@ namespace XrdCl return XRootDStatus( stError, errInvalidOp ); Log *log = DefaultEnv::GetLog(); - log->Debug( FileMsg, "[0x%x@%s] Sending a fattr set command for handle 0x%x to " - "%s", self.get(), self->pFileUrl->GetObfuscatedURL().c_str(), + log->Debug( FileMsg, "[%p@%s] Sending a fattr set command for handle %#x to %s", + self.get(), self->pFileUrl->GetObfuscatedURL().c_str(), *((uint32_t*)self->pFileHandle), self->pDataServer->GetHostId().c_str() ); //-------------------------------------------------------------------------- @@ -1982,8 +1982,8 @@ namespace XrdCl return XRootDStatus( stError, errInvalidOp ); Log *log = DefaultEnv::GetLog(); - log->Debug( FileMsg, "[0x%x@%s] Sending a fattr get command for handle 0x%x to " - "%s", self.get(), self->pFileUrl->GetObfuscatedURL().c_str(), + log->Debug( FileMsg, "[%p@%s] Sending a fattr get command for handle %#x to %s", + self.get(), self->pFileUrl->GetObfuscatedURL().c_str(), *((uint32_t*)self->pFileHandle), self->pDataServer->GetHostId().c_str() ); //-------------------------------------------------------------------------- @@ -2008,8 +2008,8 @@ namespace XrdCl return XRootDStatus( stError, errInvalidOp ); Log *log = DefaultEnv::GetLog(); - log->Debug( FileMsg, "[0x%x@%s] Sending a fattr del command for handle 0x%x to " - "%s", self.get(), self->pFileUrl->GetObfuscatedURL().c_str(), + log->Debug( FileMsg, "[%p@%s] Sending a fattr del command for handle %#x to %s", + self.get(), self->pFileUrl->GetObfuscatedURL().c_str(), *((uint32_t*)self->pFileHandle), self->pDataServer->GetHostId().c_str() ); //-------------------------------------------------------------------------- @@ -2033,8 +2033,8 @@ namespace XrdCl return XRootDStatus( stError, errInvalidOp ); Log *log = DefaultEnv::GetLog(); - log->Debug( FileMsg, "[0x%x@%s] Sending a fattr list command for handle 0x%x to " - "%s", self.get(), self->pFileUrl->GetObfuscatedURL().c_str(), + log->Debug( FileMsg, "[%p@%s] Sending a fattr list command for handle %#x to %s", + self.get(), self->pFileUrl->GetObfuscatedURL().c_str(), *((uint32_t*)self->pFileHandle), self->pDataServer->GetHostId().c_str() ); //-------------------------------------------------------------------------- @@ -2069,8 +2069,8 @@ namespace XrdCl return XRootDStatus( stError, errInvalidOp ); Log *log = DefaultEnv::GetLog(); - log->Debug( FileMsg, "[0x%x@%s] Sending a checkpoint command for " - "handle 0x%x to %s", self.get(), self->pFileUrl->GetObfuscatedURL().c_str(), + log->Debug( FileMsg, "[%p@%s] Sending a checkpoint command for handle %#x to %s", + self.get(), self->pFileUrl->GetObfuscatedURL().c_str(), *((uint32_t*)self->pFileHandle), self->pDataServer->GetHostId().c_str() ); Message *msg; @@ -2120,8 +2120,8 @@ namespace XrdCl return XRootDStatus( stError, errInvalidOp ); Log *log = DefaultEnv::GetLog(); - log->Debug( FileMsg, "[0x%x@%s] Sending a write command for handle 0x%x to " - "%s", self.get(), self->pFileUrl->GetObfuscatedURL().c_str(), + log->Debug( FileMsg, "[%p@%s] Sending a write command for handle %#x to %s", + self.get(), self->pFileUrl->GetObfuscatedURL().c_str(), *((uint32_t*)self->pFileHandle), self->pDataServer->GetHostId().c_str() ); Message *msg; @@ -2182,8 +2182,8 @@ namespace XrdCl return XRootDStatus( stError, errInvalidOp ); Log *log = DefaultEnv::GetLog(); - log->Debug( FileMsg, "[0x%x@%s] Sending a write command for handle 0x%x to " - "%s", self.get(), self->pFileUrl->GetObfuscatedURL().c_str(), + log->Debug( FileMsg, "[%p@%s] Sending a write command for handle %#x to %s", + self.get(), self->pFileUrl->GetObfuscatedURL().c_str(), *((uint32_t*)self->pFileHandle), self->pDataServer->GetHostId().c_str() ); Message *msg; @@ -2358,7 +2358,7 @@ namespace XrdCl } } - log->Debug(FileMsg, "[0x%x@%s] Open has returned with status %s", + log->Debug(FileMsg, "[%p@%s] Open has returned with status %s", this, pFileUrl->GetObfuscatedURL().c_str(), status->ToStr().c_str() ); if( pDataServer && !pDataServer->IsLocalFile() ) @@ -2384,7 +2384,7 @@ namespace XrdCl pStatus = *status; if( !pStatus.IsOK() || !openInfo ) { - log->Debug(FileMsg, "[0x%x@%s] Error while opening at %s: %s", + log->Debug(FileMsg, "[%p@%s] Error while opening at %s: %s", this, pFileUrl->GetObfuscatedURL().c_str(), lastServer.c_str(), pStatus.ToStr().c_str() ); FailQueuedMessages( pStatus ); @@ -2419,7 +2419,7 @@ namespace XrdCl pStatInfo = new StatInfo( *openInfo->GetStatInfo() ); } - log->Debug( FileMsg, "[0x%x@%s] successfully opened at %s, handle: 0x%x, " + log->Debug( FileMsg, "[%p@%s] successfully opened at %s, handle: %#x, " "session id: %ld", this, pFileUrl->GetObfuscatedURL().c_str(), pDataServer->GetHostId().c_str(), *((uint32_t*)pFileHandle), pSessionId ); @@ -2455,13 +2455,12 @@ namespace XrdCl Log *log = DefaultEnv::GetLog(); XrdSysMutexHelper scopedLock( pMutex ); - log->Debug(FileMsg, "[0x%x@%s] Close returned from %s with: %s", this, + log->Debug(FileMsg, "[%p@%s] Close returned from %s with: %s", this, pFileUrl->GetObfuscatedURL().c_str(), pDataServer->GetHostId().c_str(), status->ToStr().c_str() ); - log->Dump(FileMsg, "[0x%x@%s] Items in the fly %d, queued for recovery %d", - this, pFileUrl->GetObfuscatedURL().c_str(), pInTheFly.size(), - pToBeRecovered.size() ); + log->Dump(FileMsg, "[%p@%s] Items in the fly %llu, queued for recovery %llu", + this, pFileUrl->GetObfuscatedURL().c_str(), pInTheFly.size(), pToBeRecovered.size() ); MonitorClose( status ); ResetMonitoringVars(); @@ -2505,7 +2504,7 @@ namespace XrdCl XrdSysMutexHelper scopedLock( self->pMutex ); self->pInTheFly.erase( message ); - log->Dump( FileMsg, "[0x%x@%s] File state error encountered. Message %s " + log->Dump( FileMsg, "[%p@%s] File state error encountered. Message %s " "returned with %s", self.get(), self->pFileUrl->GetObfuscatedURL().c_str(), message->GetObfuscatedDescription().c_str(), status->ToStr().c_str() ); @@ -2540,7 +2539,7 @@ namespace XrdCl //-------------------------------------------------------------------------- if( !self->IsRecoverable( *status ) || sendParams.kbuff ) { - log->Error( FileMsg, "[0x%x@%s] Fatal file state error. Message %s " + log->Error( FileMsg, "[%p@%s] Fatal file state error. Message %s " "returned with %s", self.get(), self->pFileUrl->GetObfuscatedURL().c_str(), message->GetObfuscatedDescription().c_str(), status->ToStr().c_str() ); @@ -2600,7 +2599,7 @@ namespace XrdCl Log *log = DefaultEnv::GetLog(); XrdSysMutexHelper scopedLock( self->pMutex ); - log->Dump( FileMsg, "[0x%x@%s] Got state response for message %s", + log->Dump( FileMsg, "[%p@%s] Got state response for message %s", self.get(), self->pFileUrl->GetObfuscatedURL().c_str(), message->GetObfuscatedDescription().c_str() ); @@ -2719,7 +2718,7 @@ namespace XrdCl if( !pToBeRecovered.empty() ) { Log *log = DefaultEnv::GetLog(); - log->Dump( FileMsg, "[0x%x@%s] Got a timer event", this, + log->Dump( FileMsg, "[%p@%s] Got a timer event", this, pFileUrl->GetObfuscatedURL().c_str() ); RequestList::iterator it; JobManager *jobMan = DefaultEnv::GetPostMaster()->GetJobManager(); @@ -2752,7 +2751,7 @@ namespace XrdCl if( (IsReadOnly() && pDoRecoverRead) || (!IsReadOnly() && pDoRecoverWrite) ) { - log->Debug( FileMsg, "[0x%x@%s] Putting the file in recovery state in " + log->Debug( FileMsg, "[%p@%s] Putting the file in recovery state in " "process %d", this, pFileUrl->GetObfuscatedURL().c_str(), getpid() ); pFileState = Recovering; pInTheFly.clear(); @@ -2775,7 +2774,7 @@ namespace XrdCl self->pFileState = Recovering; Log *log = DefaultEnv::GetLog(); - log->Debug( FileMsg, "[0x%x@%s] Reopen file at next data server.", + log->Debug( FileMsg, "[%p@%s] Reopen file at next data server.", self.get(), self->pFileUrl->GetObfuscatedURL().c_str() ); // merge CGI @@ -2919,7 +2918,7 @@ namespace XrdCl self->pFileState = Recovering; Log *log = DefaultEnv::GetLog(); - log->Dump( FileMsg, "[0x%x@%s] Putting message %s in the recovery list", + log->Dump( FileMsg, "[%p@%s] Putting message %s in the recovery list", self.get(), self->pFileUrl->GetObfuscatedURL().c_str(), rd.request->GetObfuscatedDescription().c_str() ); @@ -2948,7 +2947,7 @@ namespace XrdCl return Status(); Log *log = DefaultEnv::GetLog(); - log->Debug( FileMsg, "[0x%x@%s] Running the recovery procedure", self.get(), + log->Debug( FileMsg, "[%p@%s] Running the recovery procedure", self.get(), self->pFileUrl->GetObfuscatedURL().c_str() ); Status st; @@ -3008,7 +3007,7 @@ namespace XrdCl uint16_t timeout ) { Log *log = DefaultEnv::GetLog(); - log->Dump( FileMsg, "[0x%x@%s] Sending a recovery open command to %s", + log->Dump( FileMsg, "[%p@%s] Sending a recovery open command to %s", self.get(), self->pFileUrl->GetObfuscatedURL().c_str(), url.GetObfuscatedURL().c_str() ); //-------------------------------------------------------------------------- @@ -3069,7 +3068,7 @@ namespace XrdCl void FileStateHandler::FailMessage( RequestData rd, XRootDStatus status ) { Log *log = DefaultEnv::GetLog(); - log->Dump( FileMsg, "[0x%x@%s] Failing message %s with %s", + log->Dump( FileMsg, "[%p@%s] Failing message %s with %s", this, pFileUrl->GetObfuscatedURL().c_str(), rd.request->GetObfuscatedDescription().c_str(), status.ToStr().c_str() ); @@ -3078,7 +3077,7 @@ namespace XrdCl if( !sh ) { Log *log = DefaultEnv::GetLog(); - log->Error( FileMsg, "[0x%x@%s] Internal error while recovering %s", + log->Error( FileMsg, "[%p@%s] Internal error while recovering %s", this, pFileUrl->GetObfuscatedURL().c_str(), rd.request->GetObfuscatedDescription().c_str() ); return; @@ -3189,7 +3188,7 @@ namespace XrdCl } Log *log = DefaultEnv::GetLog(); - log->Dump( FileMsg, "[0x%x@%s] Rewritten file handle for %s to 0x%x", + log->Dump( FileMsg, "[%p@%s] Rewritten file handle for %s to %#x", this, pFileUrl->GetObfuscatedURL().c_str(), msg->GetObfuscatedDescription().c_str(), *((uint32_t*)pFileHandle) ); XRootDTransport::SetDescription( msg ); @@ -3258,8 +3257,8 @@ namespace XrdCl return XRootDStatus( stError, errInvalidOp ); Log *log = DefaultEnv::GetLog(); - log->Debug( FileMsg, "[0x%x@%s] Sending a write command for handle 0x%x to " - "%s", self.get(), self->pFileUrl->GetObfuscatedURL().c_str(), + log->Debug( FileMsg, "[%p@%s] Sending a write command for handle %#x to %s", + self.get(), self->pFileUrl->GetObfuscatedURL().c_str(), *((uint32_t*)self->pFileHandle), self->pDataServer->GetHostId().c_str() ); Message *msg; diff --git a/src/XrdCl/XrdClFileSystem.cc b/src/XrdCl/XrdClFileSystem.cc index 1bcfb9ce9d8..2e2e2bd691c 100644 --- a/src/XrdCl/XrdClFileSystem.cc +++ b/src/XrdCl/XrdClFileSystem.cc @@ -308,7 +308,7 @@ namespace //---------------------------------------------------------------------- if( !status->IsOK() ) { - log->Dump( FileSystemMsg, "[0x%x@DeepLocate(%s)] Got error " + log->Dump( FileSystemMsg, "[%p@DeepLocate(%s)] Got error " "response: %s", this, pPath.c_str(), status->ToStr().c_str() ); @@ -317,7 +317,7 @@ namespace //-------------------------------------------------------------------- if( pFirstTime ) { - log->Debug( FileSystemMsg, "[0x%x@DeepLocate(%s)] Failed to get " + log->Debug( FileSystemMsg, "[%p@DeepLocate(%s)] Failed to get " "the initial location list: %s", this, pPath.c_str(), status->ToStr().c_str() ); pHandler->HandleResponse( status, response ); @@ -334,7 +334,7 @@ namespace //-------------------------------------------------------------------- if( !pOutstanding ) { - log->Debug( FileSystemMsg, "[0x%x@DeepLocate(%s)] No outstanding " + log->Debug( FileSystemMsg, "[%p@DeepLocate(%s)] No outstanding " "requests, give out what we've got", this, pPath.c_str() ); scopedLock.UnLock(); @@ -352,7 +352,7 @@ namespace response->Get( info ); LocationInfo::Iterator it; - log->Dump( FileSystemMsg, "[0x%x@DeepLocate(%s)] Got %d locations", + log->Dump( FileSystemMsg, "[%p@DeepLocate(%s)] Got %d locations", this, pPath.c_str(), info->GetSize() ); for( it = info->Begin(); it != info->End(); ++it ) @@ -944,7 +944,7 @@ namespace XrdCl Log *log = DefaultEnv::GetLog(); XrdSysMutexHelper scopedLock( fs->pMutex ); - log->Dump( FileSystemMsg, "[0x%x@%s] Sending %s", fs.get(), + log->Dump( FileSystemMsg, "[%p@%s] Sending %s", fs.get(), fs->pUrl->GetHostId().c_str(), msg->GetObfuscatedDescription().c_str() ); AssignLastURLHandler *lastUrlHandler = new AssignLastURLHandler( fs, handler ); @@ -980,7 +980,7 @@ namespace XrdCl if( pLoadBalancerLookupDone ) return; - log->Dump( FileSystemMsg, "[0x%x@%s] Assigning %s as load balancer", this, + log->Dump( FileSystemMsg, "[%p@%s] Assigning %s as load balancer", this, pUrl->GetHostId().c_str(), url.GetHostId().c_str() ); pUrl.reset( new URL( url ) ); @@ -995,7 +995,7 @@ namespace XrdCl Log *log = DefaultEnv::GetLog(); XrdSysMutexHelper scopedLock( pMutex ); - log->Dump( FileSystemMsg, "[0x%x@%s] Assigning %s as last URL", this, + log->Dump( FileSystemMsg, "[%p@%s] Assigning %s as last URL", this, pUrl->GetHostId().c_str(), url.GetHostId().c_str() ); pLastUrl.reset( new URL( url ) ); @@ -1737,37 +1737,49 @@ namespace XrdCl //-------------------------------------------------------------------------- if( flags & DirListFlags::Locate ) { + bool isserver = false; //------------------------------------------------------------------------ - // Locate all the disk servers holding the directory + // Check if destination is a data server //------------------------------------------------------------------------ - LocationInfo *locations; - std::string locatePath = "*"; locatePath += path; - XRootDStatus st = DeepLocate( locatePath, - OpenFlags::PrefName | OpenFlags::Compress | OpenFlags::IntentDirList, locations ); - - if( !st.IsOK() ) - return st; - - if( locations->GetSize() == 0 ) { - delete locations; - return XRootDStatus( stError, errNotFound ); - } + AnyObject obj; + XRootDStatus st = DefaultEnv::GetPostMaster()->QueryTransport( + *pImpl->fsdata->pUrl, XRootDQuery::ServerFlags, obj); - // Check if destination is a data server - bool isserver = false; - AnyObject obj; - st = DefaultEnv::GetPostMaster()->QueryTransport( *pImpl->fsdata->pUrl, XRootDQuery::ServerFlags, obj ); - if( st.IsOK() ) - { - int *ptr = 0; - obj.Get( ptr ); - isserver = ( *ptr & kXR_isServer ); - delete ptr; + if( st.IsOK() ) + { + int *ptr = 0; + obj.Get( ptr ); + isserver = ( *ptr & kXR_isServer ); + delete ptr; + } } - if( !isserver ) - { + if (isserver) { + // Just disable the locate flag if we are talking to a single server + flags &= ~DirListFlags::Locate; + } else { + //------------------------------------------------------------------------ + // Locate all the disk servers holding the directory + //------------------------------------------------------------------------ + LocationInfo *locations; + std::string locatePath = "*"; locatePath += path; + + XRootDStatus st = DeepLocate(locatePath, + OpenFlags::PrefName | + OpenFlags::Compress | + OpenFlags::IntentDirList, + locations); + + if( !st.IsOK() ) + return st; + + if( locations->GetSize() == 0 ) + { + delete locations; + return XRootDStatus( stError, errNotFound ); + } + //------------------------------------------------------------------------ // Ask each server for a directory list //------------------------------------------------------------------------ @@ -1811,6 +1823,7 @@ namespace XrdCl fs = 0; currentResp = 0; } + delete locations; if( flags & DirListFlags::Merge ) @@ -1824,8 +1837,6 @@ namespace XrdCl } return XRootDStatus(); } - else - delete locations; } //-------------------------------------------------------------------------- diff --git a/src/XrdCl/XrdClInQueue.cc b/src/XrdCl/XrdClInQueue.cc index 6af97b29e79..46141dfce9d 100644 --- a/src/XrdCl/XrdClInQueue.cc +++ b/src/XrdCl/XrdClInQueue.cc @@ -86,14 +86,14 @@ namespace XrdCl handler = it->second.first; act = handler->Examine( msg ); exp = it->second.second; - log->Debug( ExDbgMsg, "[msg: 0x%x] Assigned MsgHandler: 0x%x.", + log->Debug( ExDbgMsg, "[msg: %p] Assigned MsgHandler: %p.", msg.get(), handler ); if( act & MsgHandler::RemoveHandler ) { pHandlers.erase( it ); - log->Debug( ExDbgMsg, "[handler: 0x%x] Removed MsgHandler: 0x%x from the in-queue.", + log->Debug( ExDbgMsg, "[handler: %p] Removed MsgHandler: %p from the in-queue.", handler, handler ); } } @@ -127,7 +127,7 @@ namespace XrdCl XrdSysMutexHelper scopedLock( pMutex ); pHandlers.erase(handlerSid); Log *log = DefaultEnv::GetLog(); - log->Debug( ExDbgMsg, "[handler: 0x%x] Removed MsgHandler: 0x%x from the in-queue.", + log->Debug( ExDbgMsg, "[handler: %p] Removed MsgHandler: %p from the in-queue.", handler, handler ); } diff --git a/src/XrdCl/XrdClJobManager.cc b/src/XrdCl/XrdClJobManager.cc index 63884912492..d3424606523 100644 --- a/src/XrdCl/XrdClJobManager.cc +++ b/src/XrdCl/XrdClJobManager.cc @@ -83,7 +83,7 @@ namespace XrdCl } } pRunning = true; - log->Debug( JobMgrMsg, "Job manager started, %d workers", pWorkers.size() ); + log->Debug( JobMgrMsg, "Job manager started, %llu workers", pWorkers.size() ); return true; } diff --git a/src/XrdCl/XrdClPollerBuiltIn.cc b/src/XrdCl/XrdClPollerBuiltIn.cc index 00c18968c35..a7c966554a1 100644 --- a/src/XrdCl/XrdClPollerBuiltIn.cc +++ b/src/XrdCl/XrdClPollerBuiltIn.cc @@ -269,7 +269,7 @@ namespace XrdCl return false; } - log->Debug( PollerMsg, "Adding socket 0x%x to the poller", socket ); + log->Debug( PollerMsg, "Adding socket %p to the poller", socket ); //-------------------------------------------------------------------------- // Check if the socket is already registered diff --git a/src/XrdCl/XrdClSocket.cc b/src/XrdCl/XrdClSocket.cc index 44917b5e3a6..09fd3ab7e78 100644 --- a/src/XrdCl/XrdClSocket.cc +++ b/src/XrdCl/XrdClSocket.cc @@ -529,7 +529,7 @@ namespace XrdCl // We have written the message successfully //---------------------------------------------------------------------- Log *log = DefaultEnv::GetLog(); - log->Dump( AsyncSockMsg, "[%s] Wrote a message: %s (0x%x), %d bytes", + log->Dump( AsyncSockMsg, "[%s] Wrote a message: %s (%p), %d bytes", strmname.c_str(), msg.GetObfuscatedDescription().c_str(), &msg, msg.GetSize() ); return XRootDStatus(); diff --git a/src/XrdCl/XrdClStream.cc b/src/XrdCl/XrdClStream.cc index da99819ee62..97f260099fd 100644 --- a/src/XrdCl/XrdClStream.cc +++ b/src/XrdCl/XrdClStream.cc @@ -322,7 +322,7 @@ namespace XrdCl path.up = 0; } - log->Dump( PostMasterMsg, "[%s] Sending message %s (0x%x) through " + log->Dump( PostMasterMsg, "[%s] Sending message %s (%p) through " "substream %d expecting answer at %d", pStreamName.c_str(), msg->GetObfuscatedDescription().c_str(), msg, path.up, path.down ); @@ -506,7 +506,7 @@ namespace XrdCl if( !handler ) { ServerResponse *rsp = (ServerResponse*)msg->GetBuffer(); - log->Warning( PostMasterMsg, "[%s] Discarding received message: 0x%x " + log->Warning( PostMasterMsg, "[%s] Discarding received message: %p " "(status=%d, SID=[%d,%d]), no MsgHandler found.", pStreamName.c_str(), msg.get(), rsp->hdr.status, rsp->hdr.streamid[0], rsp->hdr.streamid[1] ); @@ -516,12 +516,12 @@ namespace XrdCl //-------------------------------------------------------------------------- // We have a handler, so we call the callback //-------------------------------------------------------------------------- - log->Dump( PostMasterMsg, "[%s] Handling received message: 0x%x.", + log->Dump( PostMasterMsg, "[%s] Handling received message: %p.", pStreamName.c_str(), msg.get() ); if( action & (MsgHandler::NoProcess|MsgHandler::Ignore) ) { - log->Dump( PostMasterMsg, "[%s] Ignoring the processing handler for: 0x%x.", + log->Dump( PostMasterMsg, "[%s] Ignoring the processing handler for: %s.", pStreamName.c_str(), msg->GetObfuscatedDescription().c_str() ); // if we are handling partial response we have to take down the timeout fence @@ -647,8 +647,8 @@ namespace XrdCl //------------------------------------------------------------------------ if( pSubStreams.size() > 1 ) { - log->Debug( PostMasterMsg, "[%s] Attempting to connect %d additional " - "streams.", pStreamName.c_str(), pSubStreams.size()-1 ); + log->Debug( PostMasterMsg, "[%s] Attempting to connect %llu additional streams.", + pStreamName.c_str(), pSubStreams.size()-1 ); for( size_t i = 1; i < pSubStreams.size(); ++i ) { pSubStreams[i]->socket->SetAddress( pSubStreams[0]->socket->GetAddress() ); @@ -745,8 +745,8 @@ namespace XrdCl // Check if we still have time to try and do something in the current window //-------------------------------------------------------------------------- time_t elapsed = now-pConnectionInitTime; - log->Error( PostMasterMsg, "[%s] elapsed = %d, pConnectionWindow = %d " - "seconds.", pStreamName.c_str(), elapsed, pConnectionWindow ); + log->Error( PostMasterMsg, "[%s] elapsed = %ld, pConnectionWindow = %d seconds.", + pStreamName.c_str(), elapsed, pConnectionWindow ); //------------------------------------------------------------------------ // If we have some IP addresses left we try them @@ -775,8 +775,8 @@ namespace XrdCl else if( elapsed < pConnectionWindow && pConnectionCount < pConnectionRetry && !status.IsFatal() ) { - log->Info( PostMasterMsg, "[%s] Attempting reconnection in %d " - "seconds.", pStreamName.c_str(), pConnectionWindow-elapsed ); + log->Info( PostMasterMsg, "[%s] Attempting reconnection in %ld seconds.", + pStreamName.c_str(), pConnectionWindow-elapsed ); Task *task = new ::StreamConnectorTask( *pUrl, pStreamName ); pTaskManager->RegisterTask( task, pConnectionInitTime+pConnectionWindow ); @@ -921,7 +921,7 @@ namespace XrdCl pSubStreams[substream]->status = Socket::Disconnected; if( !hush ) - log->Error( PostMasterMsg, "[%s] Forcing error on disconnect: %s.", + log->Debug( PostMasterMsg, "[%s] Forcing error on disconnect: %s.", pStreamName.c_str(), status.ToString().c_str() ); //-------------------------------------------------------------------- diff --git a/src/XrdCl/XrdClUtils.cc b/src/XrdCl/XrdClUtils.cc index c5b3b4f826b..315eec4fd57 100644 --- a/src/XrdCl/XrdClUtils.cc +++ b/src/XrdCl/XrdClUtils.cc @@ -246,7 +246,7 @@ namespace XrdCl addrStr += ", "; } addrStr.erase( addrStr.length()-2, 2 ); - log->Debug( type, "[%s] Found %d address(es): %s", + log->Debug( type, "[%s] Found %llu address(es): %s", hostId.c_str(), addresses.size(), addrStr.c_str() ); } diff --git a/src/XrdCl/XrdClXCpSrc.cc b/src/XrdCl/XrdClXCpSrc.cc index c19332c7422..41eaa8db0c4 100644 --- a/src/XrdCl/XrdClXCpSrc.cc +++ b/src/XrdCl/XrdClXCpSrc.cc @@ -490,7 +490,7 @@ void XCpSrc::Steal( XCpSrc *src ) // need to notify pCtx->NotifyIdleSrc(); - log->Debug( UtilityMsg, "s%: Stealing everything from %s", myHost.c_str(), srcHost.c_str() ); + log->Debug( UtilityMsg, "%s: Stealing everything from %s", myHost.c_str(), srcHost.c_str() ); return; } @@ -515,7 +515,7 @@ void XCpSrc::Steal( XCpSrc *src ) pBlkEnd = src->pBlkEnd; src->pBlkEnd -= steal; - log->Debug( UtilityMsg, "s%: Stealing fraction (%f) of block from %s", myHost.c_str(), fraction, srcHost.c_str() ); + log->Debug( UtilityMsg, "%s: Stealing fraction (%f) of block from %s", myHost.c_str(), fraction, srcHost.c_str() ); return; } @@ -530,7 +530,7 @@ void XCpSrc::Steal( XCpSrc *src ) src->pRecovered.erase( itr ); } - log->Debug( UtilityMsg, "s%: Stealing fraction (%f) of recovered chunks from %s", myHost.c_str(), fraction, srcHost.c_str() ); + log->Debug( UtilityMsg, "%s: Stealing fraction (%f) of recovered chunks from %s", myHost.c_str(), fraction, srcHost.c_str() ); return; } @@ -551,7 +551,7 @@ void XCpSrc::Steal( XCpSrc *src ) src->pOngoing.erase( itr ); } - log->Debug( UtilityMsg, "s%: Stealing fraction (%f) of ongoing chunks from %s", myHost.c_str(), fraction, srcHost.c_str() ); + log->Debug( UtilityMsg, "%s: Stealing fraction (%f) of ongoing chunks from %s", myHost.c_str(), fraction, srcHost.c_str() ); } } @@ -567,7 +567,7 @@ XRootDStatus XCpSrc::GetWork() Log *log = DefaultEnv::GetLog(); std::string myHost = URL( pUrl ).GetHostName(); - log->Debug( UtilityMsg, "s% got next block", myHost.c_str() ); + log->Debug( UtilityMsg, "%s got next block", myHost.c_str() ); return XRootDStatus(); } diff --git a/src/XrdCl/XrdClXRootDMsgHandler.cc b/src/XrdCl/XrdClXRootDMsgHandler.cc index 371aca15e59..0e93e2cd5ef 100644 --- a/src/XrdCl/XrdClXRootDMsgHandler.cc +++ b/src/XrdCl/XrdClXRootDMsgHandler.cc @@ -123,7 +123,7 @@ namespace XrdCl { Log *log = DefaultEnv::GetLog(); log->Warning( ExDbgMsg, "[%s] MsgHandler is examining a response although " - "it already owns a response: 0x%x (message: %s ).", + "it already owns a response: %p (message: %s ).", pUrl.GetHostId().c_str(), this, pRequest->GetObfuscatedDescription().c_str() ); } @@ -795,7 +795,7 @@ namespace XrdCl if( resendTime < pExpiration ) { - log->Debug( ExDbgMsg, "[%s] Scheduling WaitTask for MsgHandler: 0x%x (message: %s ).", + log->Debug( ExDbgMsg, "[%s] Scheduling WaitTask for MsgHandler: %p (message: %s ).", pUrl.GetHostId().c_str(), this, pRequest->GetObfuscatedDescription().c_str() ); @@ -906,7 +906,7 @@ namespace XrdCl log->Dump( XRootDMsg, "[%s] Message %s has been successfully sent.", pUrl.GetHostId().c_str(), message->GetObfuscatedDescription().c_str() ); - log->Debug( ExDbgMsg, "[%s] Moving MsgHandler: 0x%x (message: %s ) from out-queue to in-queue.", + log->Debug( ExDbgMsg, "[%s] Moving MsgHandler: %p (message: %s ) from out-queue to in-queue.", pUrl.GetHostId().c_str(), this, pRequest->GetObfuscatedDescription().c_str() ); @@ -1121,7 +1121,7 @@ namespace XrdCl AnyObject *response = 0; Log *log = DefaultEnv::GetLog(); - log->Debug( ExDbgMsg, "[%s] Calling MsgHandler: 0x%x (message: %s ) " + log->Debug( ExDbgMsg, "[%s] Calling MsgHandler: %p (message: %s ) " "with status: %s.", pUrl.GetHostId().c_str(), this, pRequest->GetObfuscatedDescription().c_str(), @@ -1659,7 +1659,7 @@ namespace XrdCl //------------------------------------------------------------------------ case kXR_readv: { - log->Dump( XRootDMsg, "[%s] Parsing the response to 0x%x as " + log->Dump( XRootDMsg, "[%s] Parsing the response to %p as " "VectorReadInfo", pUrl.GetHostId().c_str(), pRequest->GetObfuscatedDescription().c_str() ); @@ -2132,7 +2132,7 @@ namespace XrdCl if( pUrl.IsMetalink() && pFollowMetalink ) { - log->Debug( ExDbgMsg, "[%s] Metaling redirection for MsgHandler: 0x%x (message: %s ).", + log->Debug( ExDbgMsg, "[%s] Metaling redirection for MsgHandler: %p (message: %s ).", pUrl.GetHostId().c_str(), this, pRequest->GetObfuscatedDescription().c_str() ); @@ -2145,7 +2145,7 @@ namespace XrdCl } else { - log->Debug( ExDbgMsg, "[%s] Retry at server MsgHandler: 0x%x (message: %s ).", + log->Debug( ExDbgMsg, "[%s] Retry at server MsgHandler: %p (message: %s ).", pUrl.GetHostId().c_str(), this, pRequest->GetObfuscatedDescription().c_str() ); return pPostMaster->Send( pUrl, pRequest, this, true, pExpiration ); @@ -2249,7 +2249,7 @@ namespace XrdCl else { Log *log = DefaultEnv::GetLog(); - log->Debug( ExDbgMsg, "[%s] Passing to the thread-pool MsgHandler: 0x%x (message: %s ).", + log->Debug( ExDbgMsg, "[%s] Passing to the thread-pool MsgHandler: %p (message: %s ).", pUrl.GetHostId().c_str(), this, pRequest->GetObfuscatedDescription().c_str() ); jobMgr->QueueJob( new HandleRspJob( this ), 0 ); @@ -2262,7 +2262,7 @@ namespace XrdCl void XRootDMsgHandler::HandleLocalRedirect( URL *url ) { Log *log = DefaultEnv::GetLog(); - log->Debug( ExDbgMsg, "[%s] Handling local redirect - MsgHandler: 0x%x (message: %s ).", + log->Debug( ExDbgMsg, "[%s] Handling local redirect - MsgHandler: %p (message: %s ).", pUrl.GetHostId().c_str(), this, pRequest->GetObfuscatedDescription().c_str() ); diff --git a/src/XrdCl/XrdClXRootDMsgHandler.hh b/src/XrdCl/XrdClXRootDMsgHandler.hh index 403e09c6663..ee137aebd93 100644 --- a/src/XrdCl/XrdClXRootDMsgHandler.hh +++ b/src/XrdCl/XrdClXRootDMsgHandler.hh @@ -183,7 +183,7 @@ namespace XrdCl pHasSessionId = true; Log *log = DefaultEnv::GetLog(); - log->Debug( ExDbgMsg, "[%s] MsgHandler created: 0x%x (message: %s ).", + log->Debug( ExDbgMsg, "[%s] MsgHandler created: %p (message: %s ).", pUrl.GetHostId().c_str(), this, pRequest->GetObfuscatedDescription().c_str() ); @@ -222,7 +222,7 @@ namespace XrdCl pEffectiveDataServerUrl = reinterpret_cast( 0xDEADBEEF ); Log *log = DefaultEnv::GetLog(); - log->Debug( ExDbgMsg, "[%s] Destroying MsgHandler: 0x%x.", + log->Debug( ExDbgMsg, "[%s] Destroying MsgHandler: %p.", pUrl.GetHostId().c_str(), this ); } diff --git a/src/XrdCl/XrdClXRootDResponses.hh b/src/XrdCl/XrdClXRootDResponses.hh index 11fa1ca166c..2ae19113957 100644 --- a/src/XrdCl/XrdClXRootDResponses.hh +++ b/src/XrdCl/XrdClXRootDResponses.hh @@ -348,6 +348,7 @@ namespace XrdCl { IsManager = kXR_isManager, //!< Manager IsServer = kXR_isServer, //!< Data server + AttrCache = kXR_attrCache, //!< Cache attribute AttrMeta = kXR_attrMeta, //!< Meta attribute AttrProxy = kXR_attrProxy, //!< Proxy attribute AttrSuper = kXR_attrSuper //!< Supervisor attribute diff --git a/src/XrdCl/XrdClXRootDTransport.cc b/src/XrdCl/XrdClXRootDTransport.cc index 0be81f902ba..b98e0695f13 100644 --- a/src/XrdCl/XrdClXRootDTransport.cc +++ b/src/XrdCl/XrdClXRootDTransport.cc @@ -333,7 +333,7 @@ namespace XrdCl uint32_t bodySize = *(uint32_t*)(message.GetBuffer(4)); Log *log = DefaultEnv::GetLog(); - log->Dump( XRootDTransportMsg, "[msg: 0x%x] Expecting %d bytes of message " + log->Dump( XRootDTransportMsg, "[msg: %p] Expecting %d bytes of message " "body", &message, bodySize ); return XRootDStatus( stOK, suDone ); @@ -418,14 +418,14 @@ namespace XrdCl XRootDStatus st = XRootDTransport::UnMarchalStatusMore( message ); if( !st.IsOK() && st.code == errDataError ) { - log->Error( XRootDTransportMsg, "[msg: 0x%x] %s", &message, + log->Error( XRootDTransportMsg, "[msg: %p] %s", &message, st.GetErrorMessage().c_str() ); return st; } if( !st.IsOK() ) { - log->Error( XRootDTransportMsg, "[msg: 0x%x] Failed to unmarshall status body.", + log->Error( XRootDTransportMsg, "[msg: %p] Failed to unmarshall status body.", &message ); return st; } @@ -764,7 +764,7 @@ namespace XrdCl //-------------------------------------------------------------------------- XrdSysMutexHelper scopedLock( info->mutex ); uint16_t allocatedSIDs = info->sidManager->GetNumberOfAllocatedSIDs(); - log->Dump( XRootDTransportMsg, "[%s] Stream inactive since %d seconds, " + log->Dump( XRootDTransportMsg, "[%s] Stream inactive since %ld seconds, " "TTL: %d, allocated SIDs: %d, open files: %d, bound file objects: %d", info->streamName.c_str(), inactiveTime, ttl, allocatedSIDs, info->openFiles, info->finstcnt.load( std::memory_order_relaxed ) ); @@ -799,7 +799,7 @@ namespace XrdCl const bool anySID = info->sidManager->IsAnySIDOldAs( now - streamTimeout ); - log->Dump( XRootDTransportMsg, "[%s] Stream inactive since %d seconds, " + log->Dump( XRootDTransportMsg, "[%s] Stream inactive since %ld seconds, " "stream timeout: %d, any SID: %d, wait barrier: %s", info->streamName.c_str(), inactiveTime, streamTimeout, anySID, Utils::TimeToString(info->waitBarrier).c_str() ); @@ -1584,7 +1584,7 @@ namespace XrdCl if( info->sidManager->IsTimedOut( rsp->hdr.streamid ) ) { - log->Error( XRootDTransportMsg, "Message 0x%x, stream [%d, %d] is a " + log->Error( XRootDTransportMsg, "Message %p, stream [%d, %d] is a " "response that we're no longer interested in (timed out)", &msg, rsp->hdr.streamid[0], rsp->hdr.streamid[1] ); //------------------------------------------------------------------------ @@ -1618,7 +1618,7 @@ namespace XrdCl { seconds = ntohl( rsp->body.waitresp.seconds ); - log->Dump( XRootDMsg, "[%s] Got kXR_waitresp response of %d seconds, " + log->Dump( XRootDMsg, "[%s] Got kXR_waitresp response of %u seconds, " "setting up wait barrier.", info->streamName.c_str(), seconds ); @@ -2857,6 +2857,9 @@ namespace XrdCl if( flags & kXR_attrMeta ) repr += "meta "; + else if( flags & kXR_attrCache ) + repr += "cache "; + else if( flags & kXR_attrProxy ) repr += "proxy "; diff --git a/src/XrdCl/XrdClZipArchive.cc b/src/XrdCl/XrdClZipArchive.cc index fb303d23668..7dbdbc65a48 100644 --- a/src/XrdCl/XrdClZipArchive.cc +++ b/src/XrdCl/XrdClZipArchive.cc @@ -93,7 +93,7 @@ namespace XrdCl // if it is a compressed file use ZIP cache to read from the file if( cdfh->compressionMethod == Z_DEFLATED ) { - log->Dump( ZipMsg, "[0x%x] Reading compressed data.", &me ); + log->Dump( ZipMsg, "[%p] Reading compressed data.", &me ); // check if respective ZIP cache exists bool empty = me.zipcache.find( fn ) == me.zipcache.end(); // if the entry does not exist, it will be created using @@ -156,7 +156,7 @@ namespace XrdCl [relativeOffset, rdbuff, &cache, &me]( XRootDStatus &st, RSP &rsp ) { Log *log = DefaultEnv::GetLog(); - log->Dump( ZipMsg, "[0x%x] Read %d bytes of remote data at offset %d.", + log->Dump( ZipMsg, "[%p] Read %d bytes of remote data at offset %llu.", &me, rsp.GetLength(), rsp.GetOffset() ); cache.QueueRsp( st, relativeOffset, std::move( *rdbuff ) ); }; @@ -172,7 +172,7 @@ namespace XrdCl if( size ) { memcpy( usrbuff, me.buffer.get() + offset, size ); - log->Dump( ZipMsg, "[0x%x] Serving read from local cache.", &me ); + log->Dump( ZipMsg, "[%p] Serving read from local cache.", &me ); } if( usrHandler ) @@ -187,8 +187,8 @@ namespace XrdCl Pipeline p = XrdCl::RdWithRsp( me.archive, offset, size, usrbuff ) >> [=, &me]( XRootDStatus &st, RSP &r ) { - log->Dump( ZipMsg, "[0x%x] Read %d bytes of remote data at " - "offset %d.", &me, r.GetLength(), r.GetOffset() ); + log->Dump( ZipMsg, "[%p] Read %d bytes of remote data at " + "offset %llu.", &me, r.GetLength(), r.GetOffset() ); if( usrHandler ) { XRootDStatus *status = ZipArchive::make_status( st ); @@ -243,12 +243,12 @@ namespace XrdCl { archsize = info.GetSize(); openstage = NotParsed; - log->Debug( ZipMsg, "[0x%x] Opened (only) a ZIP archive (%s).", + log->Debug( ZipMsg, "[%p] Opened (only) a ZIP archive (%s).", this, url.c_str() ); } else { - log->Error( ZipMsg, "[0x%x] Failed to open-only a ZIP archive (%s): %s", + log->Error( ZipMsg, "[%p] Failed to open-only a ZIP archive (%s): %s", this, url.c_str(), st.ToString().c_str() ); } @@ -288,7 +288,7 @@ namespace XrdCl { cdexists = false; openstage = Done; - log->Dump( ZipMsg, "[0x%x] Opened a ZIP archive (file empty).", this ); + log->Dump( ZipMsg, "[%p] Opened a ZIP archive (file empty).", this ); Pipeline::Stop(); } // prepare the arguments for the subsequent read @@ -297,8 +297,8 @@ namespace XrdCl buffer.reset( new char[*rdsize] ); rdbuff = buffer.get(); openstage = HaveEocdBlk; - log->Dump( ZipMsg, "[0x%x] Opened a ZIP archive, reading " - "Central Directory at offset: %d.", this, *rdoff ); + log->Dump( ZipMsg, "[%p] Opened a ZIP archive, reading " + "Central Directory at offset: %llu.", this, *rdoff ); } // read the Central Directory (in several stages if necessary) | XrdCl::Read( archive, rdoff, rdsize, rdbuff ) >> @@ -324,7 +324,7 @@ namespace XrdCl } try{ eocd.reset( new EOCD( eocdBlock, chunk.length - uint32_t(eocdBlock - buff) ) ); - log->Dump( ZipMsg, "[0x%x] EOCD record parsed: %s", this, + log->Dump( ZipMsg, "[%p] EOCD record parsed: %s", this, eocd->ToString().c_str() ); if(eocd->cdOffset > archsize || eocd->cdOffset + eocd->cdSize > archsize) throw bad_data(); @@ -371,7 +371,7 @@ namespace XrdCl buffer.reset( new char[*rdsize] ); rdbuff = buffer.get(); openstage = HaveCdRecords; - log->Dump( ZipMsg, "[0x%x] Reading additional data at offset: %d.", + log->Dump( ZipMsg, "[%p] Reading additional data at offset: %llu.", this, *rdoff ); Pipeline::Repeat(); break; // the break is really not needed ... } @@ -379,7 +379,7 @@ namespace XrdCl case HaveZip64EocdlBlk: { std::unique_ptr eocdl( new ZIP64_EOCDL( buff ) ); - log->Dump( ZipMsg, "[0x%x] EOCDL record parsed: %s", + log->Dump( ZipMsg, "[%p] EOCDL record parsed: %s", this, eocdl->ToString().c_str() ); if( chunk.offset > eocdl->zip64EocdOffset ) @@ -390,7 +390,7 @@ namespace XrdCl buffer.reset( new char[*rdsize] ); rdbuff = buffer.get(); openstage = HaveZip64EocdBlk; - log->Dump( ZipMsg, "[0x%x] Reading additional data at offset: %d.", + log->Dump( ZipMsg, "[%p] Reading additional data at offset: %llu.", this, *rdoff ); Pipeline::Repeat(); } @@ -410,7 +410,7 @@ namespace XrdCl Pipeline::Stop( error ); } zip64eocd.reset( new ZIP64_EOCD( buff ) ); - log->Dump( ZipMsg, "[0x%x] ZIP64EOCD record parsed: %s", + log->Dump( ZipMsg, "[%p] ZIP64EOCD record parsed: %s", this, zip64eocd->ToString().c_str() ); // now we can read the CD records, adjust the read arguments @@ -422,7 +422,7 @@ namespace XrdCl buffer.reset( new char[*rdsize] ); rdbuff = buffer.get(); openstage = HaveCdRecords; - log->Dump( ZipMsg, "[0x%x] Reading additional data at offset: %d.", + log->Dump( ZipMsg, "[%p] Reading additional data at offset: %llu.", this, *rdoff ); Pipeline::Repeat(); break; // the break is really not needed ... } @@ -438,7 +438,7 @@ namespace XrdCl std::tie( cdvec, cdmap ) = CDFH::Parse( buff, zip64eocd->cdSize, zip64eocd->nbCdRec ); else std::tie( cdvec, cdmap ) = CDFH::Parse( buff, eocd->cdSize, eocd->nbCdRec ); - log->Dump( ZipMsg, "[0x%x] CD records parsed.", this ); + log->Dump( ZipMsg, "[%p] CD records parsed.", this ); uint64_t sumCompSize = 0; for (auto it = cdvec.begin(); it != cdvec.end(); it++) { @@ -470,10 +470,10 @@ namespace XrdCl | XrdCl::Final( [=]( const XRootDStatus &status ) { // finalize the pipeline by calling the user callback if( status.IsOK() ) - log->Debug( ZipMsg, "[0x%x] Opened a ZIP archive (%s): %s", + log->Debug( ZipMsg, "[%p] Opened a ZIP archive (%s): %s", this, url.c_str(), status.ToString().c_str() ); else - log->Error( ZipMsg, "[0x%x] Failed to open a ZIP archive (%s): %s", + log->Error( ZipMsg, "[%p] Failed to open a ZIP archive (%s): %s", this, url.c_str(), status.ToString().c_str() ); if( handler ) handler->HandleResponse( make_status( status ), nullptr ); @@ -504,11 +504,11 @@ namespace XrdCl { openfn = fn; lfh.reset( new LFH( fn, crc32, size, time( 0 ) ) ); - log->Dump( ZipMsg, "[0x%x] File %s opened for append.", + log->Dump( ZipMsg, "[%p] File %s opened for append.", this, fn.c_str() ); return XRootDStatus(); } - log->Dump( ZipMsg, "[0x%x] Open failed: %s not in the ZIP archive.", + log->Dump( ZipMsg, "[%p] Open failed: %s not in the ZIP archive.", this, fn.c_str() ); return XRootDStatus( stError, errNotFound ); } @@ -517,14 +517,14 @@ namespace XrdCl // a file with the same name if( flags & OpenFlags::New ) { - log->Dump( ZipMsg, "[0x%x] Open failed: file exists %s, cannot append.", + log->Dump( ZipMsg, "[%p] Open failed: file exists %s, cannot append.", this, fn.c_str() ); return XRootDStatus( stError, errInvalidOp, EEXIST, "The file already exists in the ZIP archive." ); } openfn = fn; - log->Dump( ZipMsg, "[0x%x] File %s opened for reading.", + log->Dump( ZipMsg, "[%p] File %s opened for reading.", this, fn.c_str() ); return XRootDStatus(); } @@ -650,10 +650,10 @@ namespace XrdCl | XrdCl::Final( [=]( const XRootDStatus &st ) mutable { if( st.IsOK() ) - log->Dump( ZipMsg, "[0x%x] Successfully closed ZIP archive " + log->Dump( ZipMsg, "[%p] Successfully closed ZIP archive " "(CD written).", this ); else - log->Error( ZipMsg, "[0x%x] Failed to close ZIP archive: %s", + log->Error( ZipMsg, "[%p] Failed to close ZIP archive: %s", this, st.ToString().c_str() ); wrtbufs.clear(); if( handler ) handler->HandleResponse( make_status( st ), nullptr ); @@ -672,13 +672,13 @@ namespace XrdCl if( st.IsOK() ) { Clear(); - log->Dump( ZipMsg, "[0x%x] Successfully closed " + log->Dump( ZipMsg, "[%p] Successfully closed " "ZIP archive.", this ); } else { openstage = Error; - log->Error( ZipMsg, "[0x%x] Failed to close ZIP archive:" + log->Error( ZipMsg, "[%p] Failed to close ZIP archive:" " %s", this, st.ToString().c_str() ); } if( handler ) @@ -774,7 +774,7 @@ namespace XrdCl lfh->Serialize( *lfhbuf ); iov[0].iov_base = lfhbuf->data(); iov[0].iov_len = lfhlen; - log->Dump( ZipMsg, "[0x%x] Will write LFH.", this ); + log->Dump( ZipMsg, "[%p] Will write LFH.", this ); } //------------------------------------------------------------------------- // If there is no LFH just make the first chunk empty. @@ -886,12 +886,12 @@ namespace XrdCl // check if the file already exists in the archive if( itr != cdmap.end() ) { - log->Dump( ZipMsg, "[0x%x] Open failed: file exists %s, cannot append.", + log->Dump( ZipMsg, "[%p] Open failed: file exists %s, cannot append.", this, fn.c_str() ); return XRootDStatus( stError, errInvalidOp ); } - log->Dump( ZipMsg, "[0x%x] Appending file: %s.", this, fn.c_str() ); + log->Dump( ZipMsg, "[%p] Appending file: %s.", this, fn.c_str() ); //------------------------------------------------------------------------- // Create Local File Header record //------------------------------------------------------------------------- diff --git a/src/XrdClHttp/XrdClHttpFilePlugIn.cc b/src/XrdClHttp/XrdClHttpFilePlugIn.cc index c20326d182f..f28025a44e3 100644 --- a/src/XrdClHttp/XrdClHttpFilePlugIn.cc +++ b/src/XrdClHttp/XrdClHttpFilePlugIn.cc @@ -186,11 +186,11 @@ XRootDStatus HttpFilePlugIn::Close(ResponseHandler *handler, return XRootDStatus(stError, errInvalidOp); } - logger_->Debug(kLogXrdClHttp, "Closing davix fd: %ld", davix_fd_); + logger_->Debug(kLogXrdClHttp, "Closing davix fd: %p", davix_fd_); auto status = Posix::Close(*davix_client_, davix_fd_); if (status.IsError()) { - logger_->Error(kLogXrdClHttp, "Could not close davix fd: %ld, error: %s", + logger_->Error(kLogXrdClHttp, "Could not close davix fd: %p, error: %s", davix_fd_, status.ToStr().c_str()); return status; } @@ -272,7 +272,7 @@ XRootDStatus HttpFilePlugIn::Read(uint64_t offset, uint32_t size, void *buffer, curr_offset = offset + num_bytes_read; if (avoid_pread_) offset_locker.unlock(); - logger_->Debug(kLogXrdClHttp, "Read %d bytes, at offset %d, from URL: %s", + logger_->Debug(kLogXrdClHttp, "Read %d bytes, at offset %llu, from URL: %s", num_bytes_read, offset, url_.c_str()); auto status = new XRootDStatus(); @@ -369,7 +369,7 @@ XRootDStatus HttpFilePlugIn::Write(uint64_t offset, uint32_t size, else filesize += res.first; - logger_->Debug(kLogXrdClHttp, "Wrote %d bytes, at offset %d, to URL: %s", + logger_->Debug(kLogXrdClHttp, "Wrote %d bytes, at offset %llu, to URL: %s", res.first, offset, url_.c_str()); handler->HandleResponse(new XRootDStatus(), nullptr); diff --git a/src/XrdCrypto/XrdCryptosslX509.cc b/src/XrdCrypto/XrdCryptosslX509.cc index 01fbdb25389..428302d70af 100644 --- a/src/XrdCrypto/XrdCryptosslX509.cc +++ b/src/XrdCrypto/XrdCryptosslX509.cc @@ -31,12 +31,6 @@ /* OpenSSL implementation of XrdCryptoX509 */ /* */ /* ************************************************************************** */ -#include -#include -#include -#include -#include - #include "XrdCrypto/XrdCryptosslRSA.hh" #include "XrdCrypto/XrdCryptosslX509.hh" #include "XrdCrypto/XrdCryptosslAux.hh" @@ -44,6 +38,14 @@ #include +#include +#include + +#include +#include +#include +#include + #define BIO_PRINT(b,c) \ BUF_MEM *bptr; \ BIO_get_mem_ptr(b, &bptr); \ @@ -90,19 +92,28 @@ XrdCryptosslX509::XrdCryptosslX509(const char *cf, const char *kf) } // Make sure file exists; struct stat st; - if (stat(cf, &st) != 0) { + int fd = open(cf, O_RDONLY); + + if (fd == -1) { if (errno == ENOENT) { DEBUG("file "< -#include -#include -#include -#include - #include "XrdCrypto/XrdCryptosslRSA.hh" #include "XrdCrypto/XrdCryptosslX509Crl.hh" #include "XrdCrypto/XrdCryptosslAux.hh" @@ -45,6 +39,14 @@ #include #include +#include +#include + +#include +#include +#include +#include + #if OPENSSL_VERSION_NUMBER < 0x10100000L #define X509_REVOKED_get0_revocationDate(x) (x)->revocationDate #define X509_REVOKED_get0_serialNumber(x) (x)->serialNumber @@ -164,21 +166,25 @@ int XrdCryptosslX509Crl::Init(const char *cf) DEBUG("file name undefined"); return -1; } + // Make sure file exists; - struct stat st; - if (stat(cf, &st) != 0) { + int fd = open(cf, O_RDONLY); + + if (fd == -1) { if (errno == ENOENT) { DEBUG("file "<= bLeft) break; + ++n; + bLeft -= n; if ((var = index(bP, '\\'))) Squash(var); aEnt.eP->eChk[eCode-eVec] = bP; bP += n; aOK = true; diff --git a/src/XrdEc/XrdEcReader.cc b/src/XrdEc/XrdEcReader.cc index 9ac55b5387e..e8a6e9903a2 100644 --- a/src/XrdEc/XrdEcReader.cc +++ b/src/XrdEc/XrdEcReader.cc @@ -980,7 +980,7 @@ namespace XrdEc if(!st.IsOK()) { - log->Dump(XrdCl::XRootDMsg, "EC Vector Read of host %d failed entirely.", i); + log->Dump(XrdCl::XRootDMsg, "EC Vector Read of host %llu failed entirely.", i); MissingVectorRead(currentBlock, blkid, strpid, timeout); } else{ @@ -1002,7 +1002,7 @@ namespace XrdEc uint32_t cksum = objcfg.digest( 0, currentBlock->stripes[strpid].data(), currentBlock->stripes[strpid].size() ); if( orgcksum != cksum ) { - log->Dump(XrdCl::XRootDMsg, "EC Vector Read: Wrong checksum for block %d stripe %d.", blkid, strpid); + log->Dump(XrdCl::XRootDMsg, "EC Vector Read: Wrong checksum for block %llu stripe %llu.", blkid, strpid); MissingVectorRead(currentBlock, blkid, strpid, timeout); continue; } @@ -1010,7 +1010,7 @@ namespace XrdEc currentBlock->state[strpid] = block_t::Valid; bool recoverable = currentBlock->error_correction( currentBlock ); if(!recoverable) - log->Dump(XrdCl::XRootDMsg, "EC Vector Read: Couldn't recover block %d.", blkid); + log->Dump(XrdCl::XRootDMsg, "EC Vector Read: Couldn't recover block %llu.", blkid); } } } @@ -1045,12 +1045,12 @@ namespace XrdEc // put received data into given buffers if(blockMap.find(blkid) == blockMap.end() || blockMap[blkid] == nullptr){ - log->Dump(XrdCl::XRootDMsg, "EC Vector Read: Missing block %d.", blkid); + log->Dump(XrdCl::XRootDMsg, "EC Vector Read: Missing block %llu.", blkid); failed = true; break; } if(blockMap[blkid]->state[strpid] != block_t::Valid){ - log->Dump(XrdCl::XRootDMsg, "EC Vector Read: Invalid stripe in block %d stripe %d.", blkid, strpid); + log->Dump(XrdCl::XRootDMsg, "EC Vector Read: Invalid stripe in block %llu stripe %llu.", blkid, strpid); failed = true; break; } diff --git a/src/XrdEc/XrdEcRedundancyProvider.cc b/src/XrdEc/XrdEcRedundancyProvider.cc index c41232aee28..ad1e6467c96 100644 --- a/src/XrdEc/XrdEcRedundancyProvider.cc +++ b/src/XrdEc/XrdEcRedundancyProvider.cc @@ -87,10 +87,11 @@ static int gf_gen_decode_matrix( unsigned char* invert_matrix, * backup, * b, s; int incr = 0; - std::vector memory((size_t) (m * k * 3)); + size_t mk = (size_t)m * (size_t)k; + std::vector memory(3 * mk); b = &memory[0]; - backup = &memory[m * k]; - invert_matrix = &memory[2 * m * k]; + backup = &memory[mk]; + invert_matrix = &memory[2 * mk]; // Construct matrix b by removing error rows for (i = 0, r = 0; i < k; i++, r++) { @@ -109,7 +110,7 @@ static int gf_gen_decode_matrix( return -1; } incr++; - memcpy(b, backup, (size_t) (m * k)); + memcpy(b, backup, mk); for (i = nsrcerrs; i < nerrs - nsrcerrs; i++) { if (src_err_list[i] == (decode_index[k - 1] + incr)) { // skip the erased parity line @@ -177,7 +178,9 @@ RedundancyProvider::CodingTable& RedundancyProvider::getCodingTable( const std:: /* Expand pattern */ int nerrs = 0, nsrcerrs = 0; unsigned char err_indx_list[objcfg.nbparity]; - for (std::uint8_t i = 0; i < pattern.size(); i++) { + /* Avoid narrowing cast warning, size is always < 256 */ + uint8_t n = static_cast(pattern.size() & 0xff); + for (uint8_t i = 0; i < n; i++) { if (pattern[i]) { err_indx_list[nerrs++] = i; if (i < objcfg.nbdata) { nsrcerrs++; } diff --git a/src/XrdHttp/XrdHttpProtocol.cc b/src/XrdHttp/XrdHttpProtocol.cc index 4c9b4a733b8..ba8af7435f2 100644 --- a/src/XrdHttp/XrdHttpProtocol.cc +++ b/src/XrdHttp/XrdHttpProtocol.cc @@ -616,11 +616,11 @@ int XrdHttpProtocol::Process(XrdLink *lp) // We ignore the argument here // Read as many lines as possible into the buffer. An empty line breaks while ((rc = BuffgetLine(tmpline)) > 0) { + std::string traceLine = tmpline.c_str(); if (TRACING(TRACE_DEBUG)) { - std::string traceLine{tmpline.c_str()}; traceLine = obfuscateAuth(traceLine); - TRACE(DEBUG, " rc:" << rc << " got hdr line: " << traceLine); } + TRACE(DEBUG, " rc:" << rc << " got hdr line: " << traceLine); if ((rc == 2) && (tmpline.length() > 1) && (tmpline[rc - 1] == '\n')) { CurrentReq.headerok = true; TRACE(DEBUG, " rc:" << rc << " detected header end."); @@ -629,7 +629,7 @@ int XrdHttpProtocol::Process(XrdLink *lp) // We ignore the argument here if (CurrentReq.request == CurrentReq.rtUnset) { - TRACE(DEBUG, " Parsing first line: " << tmpline.c_str()); + TRACE(DEBUG, " Parsing first line: " << traceLine.c_str()); int result = CurrentReq.parseFirstLine((char *)tmpline.c_str(), rc); if (result < 0) { TRACE(DEBUG, " Parsing of first line failed with " << result); @@ -2235,20 +2235,31 @@ int XrdHttpProtocol::xsecretkey(XrdOucStream & Config) { if (val[0] == '/') { struct stat st; inFile = true; - if ( stat(val, &st) ) { - eDest.Emsg("Config", errno, "stat shared secret key file", val); + int fd = open(val, O_RDONLY); + + if ( fd == -1 ) { + eDest.Emsg("Config", errno, "open shared secret key file", val); + return 1; + } + + if ( fstat(fd, &st) != 0 ) { + eDest.Emsg("Config", errno, "fstat shared secret key file", val); + close(fd); return 1; } if ( st.st_mode & S_IWOTH & S_IWGRP & S_IROTH) { - eDest.Emsg("Config", "For your own security, the shared secret key file cannot be world readable or group writable'", val, "'"); + eDest.Emsg("Config", + "For your own security, the shared secret key file cannot be world readable or group writable '", val, "'"); + close(fd); return 1; } - FILE *fp = fopen(val,"r"); + FILE *fp = fdopen(fd, "r"); - if( fp == NULL ) { - eDest.Emsg("Config", errno, "open shared secret key file", val); + if ( fp == nullptr ) { + eDest.Emsg("Config", errno, "fdopen shared secret key file", val); + close(fd); return 1; } diff --git a/src/XrdHttp/XrdHttpReq.cc b/src/XrdHttp/XrdHttpReq.cc index f293f59485e..aaa90899eb8 100644 --- a/src/XrdHttp/XrdHttpReq.cc +++ b/src/XrdHttp/XrdHttpReq.cc @@ -521,8 +521,10 @@ bool XrdHttpReq::Error(XrdXrootd::Bridge::Context &info, //!< the result context if (PostProcessHTTPReq()) reset(); - // Second part of the ugly hack on stat() - if ((request == rtGET) && (xrdreq.header.requestid == ntohs(kXR_stat))) + // If we are servicing a GET on a directory, it'll generate an error for the default + // OSS (we don't assume this is always true). Catch and suppress the error so we can instead + // generate a directory listing (if configured). + if ((request == rtGET) && (xrdreq.header.requestid == ntohs(kXR_open)) && (xrderrcode == kXR_isDirectory)) return true; return false; @@ -611,7 +613,7 @@ bool XrdHttpReq::Redir(XrdXrootd::Bridge::Context &info, //!< the result context appendOpaque(redirdest, 0, 0, 0); - TRACE(REQ, " XrdHttpReq::Redir Redirecting to " << redirdest.c_str()); + TRACE(REQ, " XrdHttpReq::Redir Redirecting to " << obfuscateAuth(redirdest.c_str()).c_str()); if (request != rtGET) prot->SendSimpleResp(307, NULL, (char *) redirdest.c_str(), 0, 0, keepalive); @@ -1090,22 +1092,36 @@ int XrdHttpReq::ProcessHTTPReq() { } // The reqstate parameter basically moves us through a simple state machine. - // - 0: Perform a stat on the resource + // To optimize things, we start off by opening the file; if it turns out to be a directory, then + // we close the file handle and switch to doing a HTML-based rendering of the directory. This + // avoids needing to always to do "stat" first to determine the next step (since the file-open also + // does a "stat"). + // - 0: Perform an open on the resource // - 1: Perform a checksum request on the resource (only if requested in header; otherwise skipped) - // - 2: Perform an open request (dirlist as appropriate). - // - 3+: Reads from file; if at end, perform a close. + // - 2: Perform a close (for dirlist only) + // - 3: Perform a dirlist. + // - 4+: Reads from file; if at end, perform a close. switch (reqstate) { - case 0: // Stat() - - // Do a Stat - if (prot->doStat((char *) resourceplusopaque.c_str())) { - XrdOucString errmsg = "Error stating"; - errmsg += resource.c_str(); - prot->SendSimpleResp(404, NULL, NULL, (char *) errmsg.c_str(), 0, false); + case 0: // Open the path for reading. + { + memset(&xrdreq, 0, sizeof (ClientRequest)); + xrdreq.open.requestid = htons(kXR_open); + l = resourceplusopaque.length() + 1; + xrdreq.open.dlen = htonl(l); + xrdreq.open.mode = 0; + xrdreq.open.options = htons(kXR_retstat | kXR_open_read); + + if (!prot->Bridge->Run((char *) &xrdreq, (char *) resourceplusopaque.c_str(), l)) { + prot->SendSimpleResp(404, NULL, NULL, (char *) "Could not run request.", 0, false); return -1; } + // Prepare to chunk up the request + writtenbytes = 0; + + // We want to be invoked again after this request is finished return 0; + } case 1: // Checksum request if (!(fileflags & kXR_isDir) && !m_req_digest.empty()) { // In this case, the Want-Digest header was set. @@ -1135,16 +1151,24 @@ int XrdHttpReq::ProcessHTTPReq() { reqstate += 1; } // fallthrough - case 2: // Open() or dirlist - { + case 2: // Close file handle for directory + if ((fileflags & kXR_isDir) && fopened) { + memset(&xrdreq, 0, sizeof (ClientRequest)); + xrdreq.close.requestid = htons(kXR_close); + memcpy(xrdreq.close.fhandle, fhandle, 4); - if (!prot->Bridge) { - prot->SendSimpleResp(500, NULL, NULL, (char *) "prot->Bridge is NULL.", 0, false); + if (!prot->Bridge->Run((char *) &xrdreq, 0, 0)) { + mapXrdErrorToHttpStatus(); + sendFooterError("Could not run close request on the bridge"); return -1; } - + return 0; + } else { + reqstate += 1; + } + // fallthrough + case 3: // List directory if (fileflags & kXR_isDir) { - if (prot->listdeny) { prot->SendSimpleResp(503, NULL, NULL, (char *) "Listings are disabled.", 0, false); return -1; @@ -1164,10 +1188,8 @@ int XrdHttpReq::ProcessHTTPReq() { return -1; } - std::string res; res = resourceplusopaque.c_str(); - //res += "?xrd.dirstat=1"; // --------- DIRLIST memset(&xrdreq, 0, sizeof (ClientRequest)); @@ -1177,43 +1199,29 @@ int XrdHttpReq::ProcessHTTPReq() { xrdreq.dirlist.dlen = htonl(l); if (!prot->Bridge->Run((char *) &xrdreq, (char *) res.c_str(), l)) { - prot->SendSimpleResp(404, NULL, NULL, (char *) "Could not run request.", 0, false); + mapXrdErrorToHttpStatus(); + prot->SendSimpleResp(httpStatusCode, NULL, NULL, httpStatusText.c_str(), httpStatusText.length(), false); + sendFooterError("Could not run listing request on the bridge"); return -1; } // We don't want to be invoked again after this request is finished return 1; - } else { - - - // --------- OPEN - memset(&xrdreq, 0, sizeof (ClientRequest)); - xrdreq.open.requestid = htons(kXR_open); - l = resourceplusopaque.length() + 1; - xrdreq.open.dlen = htonl(l); - xrdreq.open.mode = 0; - xrdreq.open.options = htons(kXR_retstat | kXR_open_read); - - if (!prot->Bridge->Run((char *) &xrdreq, (char *) resourceplusopaque.c_str(), l)) { - prot->SendSimpleResp(404, NULL, NULL, (char *) "Could not run request.", 0, false); - return -1; - } - - // Prepare to chunk up the request - writtenbytes = 0; - - // We want to be invoked again after this request is finished - return 0; + reqstate += 1; + } + // fallthrough + case 4: + { + auto retval = ReturnGetHeaders(); + if (retval) { + return retval; } - - } // fallthrough - default: // Read() or Close(); reqstate is 3+ + default: // Read() or Close(); reqstate is 4+ { - const XrdHttpIOList &readChunkList = readRangeHandler.NextReadList(); // Close() if we have finished, otherwise read the next chunk @@ -1227,7 +1235,10 @@ int XrdHttpReq::ProcessHTTPReq() { memcpy(xrdreq.close.fhandle, fhandle, 4); if (!prot->Bridge->Run((char *) &xrdreq, 0, 0)) { - prot->SendSimpleResp(404, NULL, NULL, (char *) "Could not run close request.", 0, false); + TRACEI(REQ, " Failed to run close request on the bridge."); + // Note: we have already completed the request and sent the data to the client. + // Hence, there's no need to send an error. However, since the bridge is potentially + // in a bad state, we close the TCP socket to force the client to reconnect. return -1; } @@ -1282,14 +1293,17 @@ int XrdHttpReq::ProcessHTTPReq() { } if ((offs >= filesize) || (offs+l > filesize)) { - TRACE(ALL, " Requested range " << l << "@" << offs << - " is past the end of file (" << filesize << ")"); - //prot->SendSimpleResp(522, NULL, NULL, (char *) "Invalid range request", 0); + httpStatusCode = 416; + httpStatusText = "Range Not Satisfiable"; + std::stringstream ss; + ss << "Requested range " << l << "@" << offs << " is past the end of file (" << filesize << ")"; + sendFooterError(ss.str()); return -1; } if (!prot->Bridge->Run((char *) &xrdreq, 0, 0)) { - prot->SendSimpleResp(404, NULL, NULL, (char *) "Could not run read request.", 0, false); + mapXrdErrorToHttpStatus(); + sendFooterError("Could not run read request on the bridge"); return -1; } } else { @@ -1298,7 +1312,8 @@ int XrdHttpReq::ProcessHTTPReq() { length = ReqReadV(readChunkList); if (!prot->Bridge->Run((char *) &xrdreq, (char *) &ralist[0], length)) { - prot->SendSimpleResp(404, NULL, NULL, (char *) "Could not run read request.", 0, false); + mapXrdErrorToHttpStatus(); + sendFooterError("Could not run ReadV request on the bridge"); return -1; } @@ -1435,7 +1450,8 @@ int XrdHttpReq::ProcessHTTPReq() { TRACEI(REQ, "XrdHTTP PUT: Writing chunk of size " << bytes_to_write << " starting with '" << *(prot->myBuffStart) << "'" << " with " << chunk_bytes_remaining << " bytes remaining in the chunk"); if (!prot->Bridge->Run((char *) &xrdreq, prot->myBuffStart, bytes_to_write)) { - prot->SendSimpleResp(500, NULL, NULL, (char *) "Could not run write request.", 0, false); + mapXrdErrorToHttpStatus(); + sendFooterError("Could not run write request on the bridge"); return -1; } // If there are more bytes in the buffer, then immediately call us after the @@ -1458,7 +1474,8 @@ int XrdHttpReq::ProcessHTTPReq() { TRACEI(REQ, "Writing " << bytes_to_read); if (!prot->Bridge->Run((char *) &xrdreq, prot->myBuffStart, bytes_to_read)) { - prot->SendSimpleResp(404, NULL, NULL, (char *) "Could not run write request.", 0, false); + mapXrdErrorToHttpStatus(); + sendFooterError("Could not run write request on the bridge"); return -1; } @@ -1481,7 +1498,8 @@ int XrdHttpReq::ProcessHTTPReq() { if (!prot->Bridge->Run((char *) &xrdreq, 0, 0)) { - prot->SendSimpleResp(404, NULL, NULL, (char *) "Could not run close request.", 0, false); + mapXrdErrorToHttpStatus(); + sendFooterError("Could not run close request on the bridge"); return -1; } @@ -1785,6 +1803,287 @@ XrdHttpReq::PostProcessChecksum(std::string &digest_header) { } } +int +XrdHttpReq::PostProcessListing(bool final_) { + + if (xrdresp == kXR_error) { + prot->SendSimpleResp(httpStatusCode, NULL, NULL, + httpStatusText.c_str(), httpStatusText.length(), false); + return -1; + } + + if (stringresp.empty()) { + // Start building the HTML response + stringresp = "\n" + "\n" + "\n" + "\n" + "\n" + "\n"; + + stringresp += ""; + stringresp += resource.c_str(); + stringresp += "\n"; + + stringresp += "\n" + "\n"; + + char *estr = escapeXML(resource.c_str()); + + stringresp += "

Listing of: "; + stringresp += estr; + stringresp += "

\n"; + + free(estr); + + stringresp += "
"; + + stringresp += "\n" + "\n" + "" + "" + "" + "" + "" + "\n"; + } + + // Now parse the answer building the entries vector + if (iovN > 0) { + char *startp = (char *) iovP[0].iov_base, *endp = 0; + char entry[1024]; + DirListInfo e; + while ( (size_t)(startp - (char *) iovP[0].iov_base) < (size_t)( iovP[0].iov_len - 1) ) { + // Find the filename, it comes before the \n + if ((endp = (char *) strchr((const char*) startp, '\n'))) { + strncpy(entry, (char *) startp, endp - startp); + entry[endp - startp] = 0; + e.path = entry; + + endp++; + + // Now parse the stat info + TRACEI(REQ, "Dirlist " << resource.c_str() << " entry=" << entry + << " stat=" << endp); + + long dummyl; + sscanf(endp, "%ld %lld %ld %ld", + &dummyl, + &e.size, + &e.flags, + &e.modtime); + } else + strcpy(entry, (char *) startp); + + if (e.path.length() && (e.path != ".") && (e.path != "..")) { + // The entry is filled. + std::string p = "" + ""; + p += "" + "" + "" + ""; + + stringresp += p; + } + + if (endp) { + char *pp = (char *)strchr((const char *)endp, '\n'); + if (pp) startp = pp+1; + else break; + } else break; + + } + } + + // If this was the last bunch of entries, send the buffer and empty it immediately + if (final_) { + stringresp += "
ModeFlagsSizeModifiedName
file1.txt
"; + + if (e.flags & kXR_isDir) p += "d"; + else p += "-"; + + if (e.flags & kXR_other) p += "o"; + else p += "-"; + + if (e.flags & kXR_offline) p += "O"; + else p += "-"; + + if (e.flags & kXR_readable) p += "r"; + else p += "-"; + + if (e.flags & kXR_writable) p += "w"; + else p += "-"; + + if (e.flags & kXR_xset) p += "x"; + else p += "-"; + + p += "" + itos(e.flags) + "" + itos(e.size) + "" + ISOdatetime(e.modtime) + "" + ""; + p += e.path; + + free(estr); + + p += "


" + "

Request by "; + + if (prot->SecEntity.name) + stringresp += prot->SecEntity.name; + else + stringresp += prot->Link->ID; + + if (prot->SecEntity.vorg || + prot->SecEntity.name || + prot->SecEntity.moninfo || + prot->SecEntity.role) + stringresp += " ("; + + if (prot->SecEntity.vorg) { + stringresp += " VO: "; + stringresp += prot->SecEntity.vorg; + } + + if (prot->SecEntity.moninfo) { + stringresp += " DN: "; + stringresp += prot->SecEntity.moninfo; + } else + if (prot->SecEntity.name) { + stringresp += " DN: "; + stringresp += prot->SecEntity.name; + } + + if (prot->SecEntity.role) { + stringresp += " Role: "; + stringresp += prot->SecEntity.role; + if (prot->SecEntity.endorsements) { + stringresp += " ("; + stringresp += prot->SecEntity.endorsements; + stringresp += ") "; + } + } + + if (prot->SecEntity.vorg || + prot->SecEntity.moninfo || + prot->SecEntity.role) + stringresp += " )"; + + if (prot->SecEntity.host) { + stringresp += " ( "; + stringresp += prot->SecEntity.host; + stringresp += " )"; + } + + stringresp += "

\n"; + stringresp += "

Powered by XrdHTTP "; + stringresp += XrdVSTRING; + stringresp += " (CERN IT-SDC)

\n"; + + prot->SendSimpleResp(200, NULL, NULL, (char *) stringresp.c_str(), 0, keepalive); + stringresp.clear(); + return keepalive ? 1 : -1; + } + + return 0; +} + +int +XrdHttpReq::ReturnGetHeaders() { + std::string responseHeader; + if (!m_digest_header.empty()) { + responseHeader = m_digest_header; + } + long one; + if (filemodtime && XrdOucEnv::Import("XRDPFC", one)) { + if (!responseHeader.empty()) { + responseHeader += "\r\n"; + } + long object_age = time(NULL) - filemodtime; + responseHeader += std::string("Age: ") + std::to_string(object_age < 0 ? 0 : object_age); + } + + const XrdHttpReadRangeHandler::UserRangeList &uranges = readRangeHandler.ListResolvedRanges(); + if (uranges.empty() && readRangeHandler.getError()) { + prot->SendSimpleResp(readRangeHandler.getError().httpRetCode, NULL, NULL, readRangeHandler.getError().errMsg.c_str(),0,false); + return -1; + } + + if (readRangeHandler.isFullFile()) { + // Full file. + TRACEI(REQ, "Sending full file: " << filesize); + if (m_transfer_encoding_chunked && m_trailer_headers) { + prot->StartChunkedResp(200, NULL, responseHeader.empty() ? NULL : responseHeader.c_str(), -1, keepalive); + } else { + prot->SendSimpleResp(200, NULL, responseHeader.empty() ? NULL : responseHeader.c_str(), NULL, filesize, keepalive); + } + return 0; + } + + if (readRangeHandler.isSingleRange()) { + // Possibly with zero sized file but should have been included + // in the FullFile case above + if (uranges.size() != 1) + return -1; + + // Only one range to return to the user + char buf[64]; + const off_t cnt = uranges[0].end - uranges[0].start + 1; + + XrdOucString s = "Content-Range: bytes "; + sprintf(buf, "%lld-%lld/%lld", (long long int)uranges[0].start, (long long int)uranges[0].end, filesize); + s += buf; + if (!responseHeader.empty()) { + s += "\r\n"; + s += responseHeader.c_str(); + } + + if (m_transfer_encoding_chunked && m_trailer_headers) { + prot->StartChunkedResp(206, NULL, (char *)s.c_str(), -1, keepalive); + } else { + prot->SendSimpleResp(206, NULL, (char *)s.c_str(), NULL, cnt, keepalive); + } + return 0; + } + + // Multiple reads to perform, compose and send the header + off_t cnt = 0; + for (auto &ur : uranges) { + cnt += ur.end - ur.start + 1; + + cnt += buildPartialHdr(ur.start, + ur.end, + filesize, + (char *) "123456").size(); + + } + cnt += buildPartialHdrEnd((char *) "123456").size(); + std::string header = "Content-Type: multipart/byteranges; boundary=123456"; + if (!m_digest_header.empty()) { + header += "\n"; + header += m_digest_header; + } + + if (m_transfer_encoding_chunked && m_trailer_headers) { + prot->StartChunkedResp(206, NULL, header.c_str(), -1, keepalive); + } else { + prot->SendSimpleResp(206, NULL, header.c_str(), NULL, cnt, keepalive); + } + return 0; +} // This is invoked by the callbacks, after something has happened in the bridge @@ -1864,488 +2163,144 @@ int XrdHttpReq::PostProcessHTTPReq(bool final_) { } case XrdHttpReq::rtGET: { + // To duplicate the state diagram from the rtGET request state + // - 0: Perform an open request + // - 1: Perform a checksum request on the resource (only if requested in header; otherwise skipped) + // - 2: Perform a close (for directory listings only) + // - 3: Perform a dirlist + // - 4+: Reads from file; if at end, perform a close. + switch (reqstate) { + case 0: // open + { + if (xrdresp == kXR_ok) { + fopened = true; + getfhandle(); - if (xrdreq.header.requestid == ntohs(kXR_dirlist)) { - - - if (xrdresp == kXR_error) { - prot->SendSimpleResp(httpStatusCode, NULL, NULL, - httpStatusText.c_str(), httpStatusText.length(), false); - return -1; - } - - - if (stringresp.empty()) { - - // Start building the HTML response - stringresp = "\n" - "\n" - "\n" - "\n" - "\n" - "\n"; - - stringresp += ""; - stringresp += resource.c_str(); - stringresp += "\n"; - - stringresp += "\n" - "\n"; - - char *estr = escapeXML(resource.c_str()); - - stringresp += "

Listing of: "; - stringresp += estr; - stringresp += "

\n"; - - free(estr); - - stringresp += "
"; - - - stringresp += "\n" - "\n" - "" - "" - "" - "" - "" - "\n"; - - } - - // Now parse the answer building the entries vector - if (iovN > 0) { - char *startp = (char *) iovP[0].iov_base, *endp = 0; - char entry[1024]; - DirListInfo e; - while ( (size_t)(startp - (char *) iovP[0].iov_base) < (size_t)( iovP[0].iov_len - 1) ) { - // Find the filename, it comes before the \n - if ((endp = (char *) strchr((const char*) startp, '\n'))) { - strncpy(entry, (char *) startp, endp - startp); - entry[endp - startp] = 0; - e.path = entry; - - endp++; - - // Now parse the stat info - TRACEI(REQ, "Dirlist " << resource.c_str() << " entry=" << entry - << " stat=" << endp); + // Always try to parse response. In the case of a caching proxy, the open + // will have created the file in cache + if (iovP[1].iov_len > 1) { + TRACEI(REQ, "Stat for GET " << resource.c_str() + << " stat=" << (char *) iovP[1].iov_base); long dummyl; - sscanf(endp, "%ld %lld %ld %ld", - &dummyl, - &e.size, - &e.flags, - &e.modtime); - } else - strcpy(entry, (char *) startp); - - - if (e.path.length() && (e.path != ".") && (e.path != "..")) { - // The entry is filled. - std::string p = "" - ""; - p += "" - "" - "" - ""; - - stringresp += p; - - - } - - if (endp) { - char *pp = (char *)strchr((const char *)endp, '\n'); - if (pp) startp = pp+1; - else break; - } else break; + readRangeHandler.SetFilesize(filesize); - } - } - - // If this was the last bunch of entries, send the buffer and empty it immediately - if (final_) { - stringresp += "
ModeFlagsSizeModifiedName
file1.txt
"; - - if (e.flags & kXR_isDir) p += "d"; - else p += "-"; - - if (e.flags & kXR_other) p += "o"; - else p += "-"; - - if (e.flags & kXR_offline) p += "O"; - else p += "-"; - - if (e.flags & kXR_readable) p += "r"; - else p += "-"; - - if (e.flags & kXR_writable) p += "w"; - else p += "-"; - - if (e.flags & kXR_xset) p += "x"; - else p += "-"; - - p += "" + itos(e.flags) + "" + itos(e.size) + "" + ISOdatetime(e.modtime) + "" - ""; - p += e.path; - - free(estr); - - p += "


" - "

Request by "; - - if (prot->SecEntity.name) - stringresp += prot->SecEntity.name; - else - stringresp += prot->Link->ID; - - if (prot->SecEntity.vorg || - prot->SecEntity.name || - prot->SecEntity.moninfo || - prot->SecEntity.role) - stringresp += " ("; - - if (prot->SecEntity.vorg) { - stringresp += " VO: "; - stringresp += prot->SecEntity.vorg; - } - - if (prot->SecEntity.moninfo) { - stringresp += " DN: "; - stringresp += prot->SecEntity.moninfo; - } else - if (prot->SecEntity.name) { - stringresp += " DN: "; - stringresp += prot->SecEntity.name; - } - - - if (prot->SecEntity.role) { - stringresp += " Role: "; - stringresp += prot->SecEntity.role; - if (prot->SecEntity.endorsements) { - stringresp += " ("; - stringresp += prot->SecEntity.endorsements; - stringresp += ") "; - } - } - - - - if (prot->SecEntity.vorg || - prot->SecEntity.moninfo || - prot->SecEntity.role) - stringresp += " )"; - - if (prot->SecEntity.host) { - stringresp += " ( "; - stringresp += prot->SecEntity.host; - stringresp += " )"; - } - - stringresp += "

\n"; - stringresp += "

Powered by XrdHTTP "; - stringresp += XrdVSTRING; - stringresp += " (CERN IT-SDC)

\n"; - - prot->SendSimpleResp(200, NULL, NULL, (char *) stringresp.c_str(), 0, keepalive); - stringresp.clear(); - return keepalive ? 1 : -1; - } - - - } // end handling of dirlist - else - { // begin handling of open-read-close - - // To duplicate the state diagram from the rtGET request state - // - 0: Perform a stat on the resource - // - 1: Perform a checksum request on the resource (only if requested in header; otherwise skipped) - // - 2: Perform an open request (dirlist as appropriate). - // - 3+: Reads from file; if at end, perform a close. - switch (reqstate) { - case 0: //stat - { - // Ugly hack. Be careful with EOS! Test with vanilla XrdHTTP and EOS, separately - // A 404 on the preliminary stat() is fatal only - // in a manager. A non-manager will ignore the result and try anyway to open the file - // - if (xrdresp == kXR_ok) { - - if (iovN > 0) { - - // Now parse the stat info - TRACEI(REQ, "Stat for GET " << resource.c_str() - << " stat=" << (char *) iovP[0].iov_base); - - long dummyl; - sscanf((const char *) iovP[0].iov_base, "%ld %lld %ld %ld", - &dummyl, - &filesize, - &fileflags, - &filemodtime); - - readRangeHandler.SetFilesize(filesize); - - // We will default the response size specified by the headers; if that - // wasn't given, use the file size. - if (!length) { - length = filesize; - } - } - else { - TRACEI(REQ, "Can't find the stat information for '" - << resource.c_str() << "' Internal error?"); + // As above: if the client specified a response size, we use that. + // Otherwise, utilize the filesize + if (!length) { + length = filesize; } } - - // We are here if the request failed - - if (prot->myRole == kXR_isManager) { - prot->SendSimpleResp(httpStatusCode, NULL, NULL, - httpStatusText.c_str(), httpStatusText.length(), false); + else { + TRACEI(ALL, "GET returned no STAT information. Internal error?"); + prot->SendSimpleResp(500, NULL, NULL, "Storage system did not return stat info.", 0, false); return -1; } - - // We are here in the case of a negative response in a non-manager - return 0; - } // end stat - case 1: // checksum was requested and now we have its response. - { - return PostProcessChecksum(m_digest_header); - } - case 2: // open - { - if (xrdresp == kXR_ok) { - - getfhandle(); - - // Always try to parse response. In the case of a caching proxy, the open - // will have created the file in cache - if (iovP[1].iov_len > 1) { - TRACEI(REQ, "Stat for GET " << resource.c_str() - << " stat=" << (char *) iovP[1].iov_base); - - long dummyl; - sscanf((const char *) iovP[1].iov_base, "%ld %lld %ld %ld", - &dummyl, - &filesize, - &fileflags, - &filemodtime); - - readRangeHandler.SetFilesize(filesize); - - // As above: if the client specified a response size, we use that. - // Otherwise, utilize the filesize - if (!length) { - length = filesize; - } - } - else { - TRACEI(ALL, "GET returned no STAT information. Internal error?"); - } - - std::string responseHeader; - if (!m_digest_header.empty()) { - responseHeader = m_digest_header; - } - long one; - if (filemodtime && XrdOucEnv::Import("XRDPFC", one)) { - if (!responseHeader.empty()) { - responseHeader += "\r\n"; - } - long object_age = time(NULL) - filemodtime; - responseHeader += std::string("Age: ") + std::to_string(object_age < 0 ? 0 : object_age); - } - - const XrdHttpReadRangeHandler::UserRangeList &uranges = readRangeHandler.ListResolvedRanges(); - if (uranges.empty() && readRangeHandler.getError()) { - prot->SendSimpleResp(readRangeHandler.getError().httpRetCode, NULL, NULL, readRangeHandler.getError().errMsg.c_str(),0,false); - return -1; - } - - if (readRangeHandler.isFullFile()) { - // Full file. - - if (m_transfer_encoding_chunked && m_trailer_headers) { - prot->StartChunkedResp(200, NULL, responseHeader.empty() ? NULL : responseHeader.c_str(), -1, keepalive); - } else { - prot->SendSimpleResp(200, NULL, responseHeader.empty() ? NULL : responseHeader.c_str(), NULL, filesize, keepalive); - } - return 0; - } - - if (readRangeHandler.isSingleRange()) { - // Possibly with zero sized file but should have been included - // in the FullFile case above - if (uranges.size() != 1) - return -1; - - // Only one range to return to the user - char buf[64]; - const off_t cnt = uranges[0].end - uranges[0].start + 1; - - XrdOucString s = "Content-Range: bytes "; - sprintf(buf, "%lld-%lld/%lld", (long long int)uranges[0].start, (long long int)uranges[0].end, filesize); - s += buf; - if (!responseHeader.empty()) { - s += "\r\n"; - s += responseHeader.c_str(); - } - - if (m_transfer_encoding_chunked && m_trailer_headers) { - prot->StartChunkedResp(206, NULL, (char *)s.c_str(), -1, keepalive); - } else { - prot->SendSimpleResp(206, NULL, (char *)s.c_str(), NULL, cnt, keepalive); - } - return 0; - } - - // Multiple reads to perform, compose and send the header - off_t cnt = 0; - for (auto &ur : uranges) { - cnt += ur.end - ur.start + 1; - - cnt += buildPartialHdr(ur.start, - ur.end, - filesize, - (char *) "123456").size(); - - } - cnt += buildPartialHdrEnd((char *) "123456").size(); - std::string header = "Content-Type: multipart/byteranges; boundary=123456"; - if (!m_digest_header.empty()) { - header += "\n"; - header += m_digest_header; - } - - if (m_transfer_encoding_chunked && m_trailer_headers) { - prot->StartChunkedResp(206, NULL, header.c_str(), -1, keepalive); - } else { - prot->SendSimpleResp(206, NULL, header.c_str(), NULL, cnt, keepalive); - } - return 0; - - - } else { // xrdresp indicates an error occurred - - prot->SendSimpleResp(httpStatusCode, NULL, NULL, - httpStatusText.c_str(), httpStatusText.length(), false); - return -1; - } + } else if (xrderrcode == kXR_isDirectory) { // This is a directory; trigger directory-handling topic. + fileflags = kXR_isDir; + return 0; + } else { // xrdresp indicates an error occurred - // Case should not be reachable + prot->SendSimpleResp(httpStatusCode, NULL, NULL, + httpStatusText.c_str(), httpStatusText.length(), false); + return -1; + } + // Case should not be reachable + return -1; + } // end open + case 1: // checksum was requested and now we have its response. + { + return PostProcessChecksum(m_digest_header); + } + case 2: // close file handle in case of the directory + { + if (xrdresp != kXR_ok) { + prot->SendSimpleResp(httpStatusCode, NULL, NULL, + httpStatusText.c_str(), httpStatusText.length(), false); return -1; } - default: //read or readv + return 0; + } + case 3: // handle the directory listing response + { + return PostProcessListing(final_); + } + default: //read or readv, followed by a close. + { + // If we are postprocessing a close, potentially send out informational trailers + if ((ntohs(xrdreq.header.requestid) == kXR_close) || readClosing) { - // If we are postprocessing a close, potentially send out informational trailers - if ((ntohs(xrdreq.header.requestid) == kXR_close) || readClosing) - { - const XrdHttpReadRangeHandler::Error &rrerror = readRangeHandler.getError(); - if (rrerror) { - httpStatusCode = rrerror.httpRetCode; - httpStatusText = rrerror.errMsg; - } - - if (m_transfer_encoding_chunked && m_trailer_headers) { - if (prot->ChunkRespHeader(0)) - return -1; - - const std::string crlf = "\r\n"; - std::stringstream ss; - ss << "X-Transfer-Status: " << httpStatusCode << ": " << httpStatusText << crlf; - - const auto header = ss.str(); - if (prot->SendData(header.c_str(), header.size())) - return -1; - - if (prot->ChunkRespFooter()) - return -1; - } - - if (rrerror) return -1; - return keepalive ? 1 : -1; + const XrdHttpReadRangeHandler::Error &rrerror = readRangeHandler.getError(); + if (rrerror) { + httpStatusCode = rrerror.httpRetCode; + httpStatusText = rrerror.errMsg; } + + if (m_transfer_encoding_chunked && m_trailer_headers) { + if (prot->ChunkRespHeader(0)) + return -1; - // On error, we can only send out a message if trailers are enabled and the - // status response in trailer behavior is requested. - if (xrdresp == kXR_error) { - if (m_transfer_encoding_chunked && m_trailer_headers && m_status_trailer) { - // A trailer header is appropriate in this case; this is signified by - // a chunk with size zero, then the trailer, then a crlf. - // - // We only send the status trailer when explicitly requested; otherwise a - // "normal" HTTP client might simply see a short response and think it's a - // success - if (prot->ChunkRespHeader(0)) - return -1; - - const std::string crlf = "\r\n"; - std::stringstream ss; - ss << "X-Transfer-Status: " << httpStatusCode << ": " << httpStatusText << crlf; - - const auto header = ss.str(); - if (prot->SendData(header.c_str(), header.size())) - return -1; - - if (prot->ChunkRespFooter()) - return -1; + const std::string crlf = "\r\n"; + std::stringstream ss; + ss << "X-Transfer-Status: " << httpStatusCode << ": " << httpStatusText << crlf; + const auto header = ss.str(); + if (prot->SendData(header.c_str(), header.size())) return -1; - } else { + + if (prot->ChunkRespFooter()) return -1; - } } + if (rrerror) return -1; + return keepalive ? 1 : -1; + } - TRACEI(REQ, "Got data vectors to send:" << iovN); - - XrdHttpIOList received; - getReadResponse(received); + // On error, we can only send out a message if trailers are enabled and the + // status response in trailer behavior is requested. + if (xrdresp == kXR_error) { + sendFooterError(""); + return -1; + } - int rc; - if (readRangeHandler.isSingleRange()) { - rc = sendReadResponseSingleRange(received); - } else { - rc = sendReadResponsesMultiRanges(received); - } - if (rc) { - // make sure readRangeHandler will trigger close - // of file after next NextReadList(). - readRangeHandler.NotifyError(); - } - return 0; - } // end read or readv + TRACEI(REQ, "Got data vectors to send:" << iovN); - } // switch reqstate + XrdHttpIOList received; + getReadResponse(received); - } // End handling of the open-read-close case + int rc; + if (readRangeHandler.isSingleRange()) { + rc = sendReadResponseSingleRange(received); + } else { + rc = sendReadResponsesMultiRanges(received); + } + if (rc) { + // make sure readRangeHandler will trigger close + // of file after next NextReadList(). + readRangeHandler.NotifyError(); + } + return 0; + } // end read or readv + } // switch reqstate break; } // case GET - case XrdHttpReq::rtPUT: { if (!fopened) { @@ -2747,6 +2702,36 @@ int XrdHttpReq::PostProcessHTTPReq(bool final_) { return 0; } +void +XrdHttpReq::sendFooterError(const std::string &extra_text) { + if (m_transfer_encoding_chunked && m_trailer_headers && m_status_trailer) { + // A trailer header is appropriate in this case; this is signified by + // a chunk with size zero, then the trailer, then a crlf. + // + // We only send the status trailer when explicitly requested; otherwise a + // "normal" HTTP client might simply see a short response and think it's a + // success + + if (prot->ChunkRespHeader(0)) + return; + + std::stringstream ss; + ss << httpStatusCode << ": " << httpStatusText; + if (!extra_text.empty()) + ss << ": " << extra_text; + TRACEI(REQ, ss.str()); + ss << "\r\n"; + + const auto header = "X-Transfer-Status: " + ss.str(); + if (prot->SendData(header.c_str(), header.size())) + return; + + prot->ChunkRespFooter(); + } else { + TRACEI(REQ, httpStatusCode << ": " << httpStatusText << (extra_text.empty() ? "" : (": " + extra_text))); + } +} + void XrdHttpReq::reset() { TRACE(REQ, " XrdHttpReq request ended."); diff --git a/src/XrdHttp/XrdHttpReq.hh b/src/XrdHttp/XrdHttpReq.hh index ed56ede2066..1eee5cb45e3 100644 --- a/src/XrdHttp/XrdHttpReq.hh +++ b/src/XrdHttp/XrdHttpReq.hh @@ -107,6 +107,14 @@ private: // be included in the response. int PostProcessChecksum(std::string &digest_header); + // Process the listing request of a GET request against a directory + // - final_: True if this is the last entry in the listing. + int PostProcessListing(bool final_); + + // Send the response for a GET request for a file read (i.e., not a directory) + // Invoked after the open is successful but before the first read is issued. + int ReturnGetHeaders(); + /// Cook and send the response after the bridge did something /// Return values: /// 0->everything OK, additionsl steps may be required @@ -135,6 +143,10 @@ private: // the data and necessary headers, assuming multipart/byteranges content type. int sendReadResponsesMultiRanges(const XrdHttpIOList &received); + // If requested by the client, sends any I/O errors that occur during the transfer + // into a footer. + void sendFooterError(const std::string &); + /** * Extract a comma separated list of checksums+metadata into a vector * @param checksumList the list like "0:sha1, 1:adler32, 2:md5" diff --git a/src/XrdNet/XrdNetIF.cc b/src/XrdNet/XrdNetIF.cc index 5e06b79da12..6d774c781a4 100644 --- a/src/XrdNet/XrdNetIF.cc +++ b/src/XrdNet/XrdNetIF.cc @@ -729,7 +729,6 @@ bool XrdNetIF::SetIF(XrdNetAddrInfo *src, const char *ifList, int port, // Process the iflist (up to four interfaces) // - if (ifList && *ifList) do {while (*ifBeg && *ifBeg == ' ') ifBeg++; if ( !(*ifBeg)) break; if (!(ifEnd = index(ifBeg, ' '))) {ifAdr = ifBeg; ifBeg = "";} diff --git a/src/XrdOfs/XrdOfs.cc b/src/XrdOfs/XrdOfs.cc index cb8d89cdaf0..e91d728b487 100644 --- a/src/XrdOfs/XrdOfs.cc +++ b/src/XrdOfs/XrdOfs.cc @@ -2549,12 +2549,19 @@ int XrdOfs::Emsg(const char *pfx, // Message prefix value // If the error is EBUSY then we just need to stall the client. This is // a hack in order to provide for proxy support // +// The hack unfotunately is now beinng triggered for reads and writes when +// it was never so before (presumably due to client changes). So do not +// apply the hack for these operations. This gets a better fix in R 6.0 +// +if (strcmp("read", op) && strcmp("readv", op) && strcmp("pgRead", op) && + strcmp("write",op) && strcmp("pgwrite",op)) { if (ecode < 0) ecode = -ecode; if (ecode == EBUSY) return 5; // A hack for proxy support // Check for timeout conditions that require a client delay // if (ecode == ETIMEDOUT) return OSSDelay; + } // Format the error message // diff --git a/src/XrdOss/XrdOssStage.cc b/src/XrdOss/XrdOssStage.cc index 4fad9b7dde3..539030489a7 100644 --- a/src/XrdOss/XrdOssStage.cc +++ b/src/XrdOss/XrdOssStage.cc @@ -393,8 +393,9 @@ int XrdOssSys::CalcTime() int XrdOssSys::CalcTime(XrdOssStage_Req *req) // StageMutex lock held! { + unsigned long long numq = 1; unsigned long long tbytes = req->size + stgbytes/2; - int xfrtime, numq = 1; + int xfrtime; time_t now; XrdOssStage_Req *rqp = req; diff --git a/src/XrdOuc/XrdOucTPC.cc b/src/XrdOuc/XrdOucTPC.cc index 4920e281c3f..b3a46ce751f 100644 --- a/src/XrdOuc/XrdOucTPC.cc +++ b/src/XrdOuc/XrdOucTPC.cc @@ -237,13 +237,15 @@ int XrdOucTPC::copyCGI(const char *cgi, char *Buff, int Blen) int xlen; bool eqs; + if (!cgi) {*Buff = 0; return 0;} + // Skip over initial ampersands // while(*cgi == '&' && *cgi) cgi++; // Check if there is anything here // - if (!cgi || *cgi == 0) {*Buff = 0; return 0;} + if (!*cgi) {*Buff = 0; return 0;} Blen--; // Copy all keys except system oriented ones. diff --git a/src/XrdOuc/XrdOucUtils.cc b/src/XrdOuc/XrdOucUtils.cc index b5af090b6b1..40d4e811f28 100644 --- a/src/XrdOuc/XrdOucUtils.cc +++ b/src/XrdOuc/XrdOucUtils.cc @@ -36,6 +36,8 @@ #include #include +#include + #ifdef WIN32 #include #include "XrdSys/XrdWin32.hh" @@ -115,19 +117,6 @@ int LookUp(idMap_t &idMap, unsigned int id, char *buff, int blen) } } -static const std::string OBFUSCATION_STR = "REDACTED"; - -// As the compilation of the regexes when the std::regex object is constructed is expensive, -// we initialize the auth obfuscation regexes only once in the XRootD process lifetime - -static const std::vector authObfuscationRegexes = { - //authz=xxx&... We deal with cases like "(message: kXR_stat (path: /tmp/xrootd/public/foo?pelican.timeout=3s&authz=foo1234, flags: none)" where we do not want to obfuscate - // ", flags: none)" + we deal with cases where the 'authz=Bearer token' when an admin could set 'http.header2cgi Authorization authz' in the server config - std::regex(R"((authz=)(Bearer\s)?([^ &\",<>#%{}|\^~\[\]`]*))",std::regex_constants::optimize), - // HTTP Authorization, TransferHeaderAuthorization headers that with the key that can be prefixed with spaces and value prefixed by spaces - std::regex(R"((\s*\w*Authorization\s*:\s*)[^$]*)", std::regex_constants::icase | std::regex_constants::optimize) -}; - /******************************************************************************/ /* a r g L i s t */ /******************************************************************************/ @@ -1429,26 +1418,62 @@ void XrdOucUtils::trim(std::string &str) { } /** - * Use this function to obfuscate any string containing key-values with OBFUSCATION_STR + * Returns a boolean indicating whether 'c' is a valid token character or not. + * See https://datatracker.ietf.org/doc/html/rfc6750#section-2.1 for details. + */ + +static bool is_token_character(int c) +{ + if (isalnum(c)) + return true; + + static constexpr char token_chars[] = "-._~+/=:"; + + for (char ch : token_chars) + if (c == ch) + return true; + + return false; +} + +/** + * This function obfuscates away authz= cgi elements and/or HTTP authorization + * headers from URL or other log line strings which might contain them. + * * @param input the string to obfuscate - * @param regexes the obfuscation regexes to apply to replace the value with OBFUSCATION_STR. - * The key should be a regex group e.g: "(authz=)" - * Have a look at obfuscateAuth for more examples - * @return the string with values obfuscated + * @return the string with token values obfuscated */ -std::string obfuscate(const std::string &input, const std::vector ®exes) { - std::string result = input; - for(const auto & regex: regexes) { - //Loop over the regexes and replace the values with OBFUSCATION_STR - //$1 matches the first regex subgroup (e.g: "(authz=)") - result = std::regex_replace(result, regex, std::string("$1" + OBFUSCATION_STR)); + +std::string obfuscateAuth(const std::string& input) +{ + static const regex_t auth_regex = []() { + constexpr char re[] = + "(authz=|(transferheader)?(www-|proxy-)?auth(orization|enticate)[[:space:]]*:[[:space:]]*)" + "(Bearer([[:space:]]|%20)?(token([[:space:]]|%20)?)?)?"; + + regex_t regex; + + if (regcomp(®ex, re, REG_EXTENDED | REG_ICASE) != 0) + throw std::runtime_error("Failed to compile regular expression"); + + return regex; + }(); + + regmatch_t match; + size_t offset = 0; + std::string redacted; + const char *const text = input.c_str(); + + while (regexec(&auth_regex, text + offset, 1, &match, 0) == 0) { + redacted.append(text + offset, match.rm_eo).append("REDACTED"); + + offset += match.rm_eo; + + while (offset < input.size() && is_token_character(input[offset])) + ++offset; } - return result; -} -std::string obfuscateAuth(const std::string & input) { - return obfuscate(input, authObfuscationRegexes); + return redacted.append(text + offset); } #endif - diff --git a/src/XrdOuc/XrdOucUtils.hh b/src/XrdOuc/XrdOucUtils.hh index 8b612614599..265ddde26aa 100644 --- a/src/XrdOuc/XrdOucUtils.hh +++ b/src/XrdOuc/XrdOucUtils.hh @@ -35,7 +35,6 @@ #include #include #include -#include class XrdSysError; class XrdOucString; diff --git a/src/XrdPfc/XrdPfc.cc b/src/XrdPfc/XrdPfc.cc index 9d411ced2c6..567bda0d9a2 100644 --- a/src/XrdPfc/XrdPfc.cc +++ b/src/XrdPfc/XrdPfc.cc @@ -31,6 +31,7 @@ #include "XrdSys/XrdSysPthread.hh" #include "XrdSys/XrdSysTimer.hh" #include "XrdSys/XrdSysTrace.hh" +#include "XrdSys/XrdSysXAttr.hh" #include "XrdXrootd/XrdXrootdGStream.hh" @@ -43,6 +44,8 @@ #include "XrdPfcIOFile.hh" #include "XrdPfcIOFileBlock.hh" +extern XrdSysXAttr *XrdSysXAttrActive; + using namespace XrdPfc; Cache * Cache::m_instance = 0; @@ -411,7 +414,7 @@ void Cache::ReleaseRAM(char* buf, long long size) File* Cache::GetFile(const std::string& path, IO* io, long long off, long long filesize) { - // Called from virtual IO::Attach + // Called from virtual IOFile constructor. TRACE(Debug, "GetFile " << path << ", io " << io); @@ -447,6 +450,7 @@ File* Cache::GetFile(const std::string& path, IO* io, long long off, long long f } } + // This is always true, now that IOFileBlock is unsupported. if (filesize == 0) { struct stat st; @@ -504,7 +508,7 @@ void Cache::ReleaseFile(File* f, IO* io) dec_ref_cnt(f, true); } - + namespace { @@ -581,7 +585,8 @@ void Cache::inc_ref_cnt(File* f, bool lock, bool high_debug) void Cache::dec_ref_cnt(File* f, bool high_debug) { - // Called from ReleaseFile() or DiskSync callback. + // NOT under active lock. + // Called from ReleaseFile(), DiskSync callback and stat-like functions. int tlvl = high_debug ? TRACE_Debug : TRACE_Dump; int cnt; @@ -590,6 +595,7 @@ void Cache::dec_ref_cnt(File* f, bool high_debug) XrdSysCondVarHelper lock(&m_active_cond); cnt = f->get_ref_cnt(); + TRACE_INT(tlvl, "dec_ref_cnt " << f->GetLocalPath() << ", cnt at entry = " << cnt); if (f->is_in_emergency_shutdown()) { @@ -607,13 +613,15 @@ void Cache::dec_ref_cnt(File* f, bool high_debug) TRACE_INT(tlvl, "dec_ref_cnt " << f->GetLocalPath() << " is in shutdown, ref_cnt = " << cnt << " -- waiting"); } - + return; + } + if (cnt > 1) + { + f->dec_ref_cnt(); return; } } - TRACE_INT(tlvl, "dec_ref_cnt " << f->GetLocalPath() << ", cnt at entry = " << cnt); - if (cnt == 1) { if (f->FinalizeSyncBeforeExit()) @@ -648,12 +656,14 @@ void Cache::dec_ref_cnt(File* f, bool high_debug) int len = snprintf(buf, 4096, "{\"event\":\"file_close\"," "\"lfn\":\"%s\",\"size\":%lld,\"blk_size\":%d,\"n_blks\":%d,\"n_blks_done\":%d," "\"access_cnt\":%lu,\"attach_t\":%lld,\"detach_t\":%lld,\"remotes\":%s," - "\"b_hit\":%lld,\"b_miss\":%lld,\"b_bypass\":%lld,\"n_cks_errs\":%d}", + "\"b_hit\":%lld,\"b_miss\":%lld,\"b_bypass\":%lld," + "\"b_todisk\":%lld,\"b_prefetch\":%lld,\"n_cks_errs\":%d}", f->GetLocalPath().c_str(), f->GetFileSize(), f->GetBlockSize(), f->GetNBlocks(), f->GetNDownloadedBlocks(), (unsigned long) f->GetAccessCnt(), (long long) as->AttachTime, (long long) as->DetachTime, f->GetRemoteLocations().c_str(), - as->BytesHit, as->BytesMissed, as->BytesBypassed, st.m_NCksumErrors + as->BytesHit, as->BytesMissed, as->BytesBypassed, + st.m_BytesWritten, f->GetPrefetchedBytes(), st.m_NCksumErrors ); bool suc = false; if (len < 4096) @@ -897,6 +907,78 @@ int Cache::LocalFilePath(const char *curl, char *buff, int blen, return -ENOENT; } +//______________________________________________________________________________ +// If supported, write file_size as xattr to cinfo file. +//------------------------------------------------------------------------------ +void Cache::WriteFileSizeXAttr(int cinfo_fd, long long file_size) +{ + if (m_metaXattr) { + int res = XrdSysXAttrActive->Set("pfc.fsize", &file_size, sizeof(long long), 0, cinfo_fd, 0); + if (res != 0) { + TRACE(Debug, "WriteFileSizeXAttr error setting xattr " << res); + } + } +} + +//______________________________________________________________________________ +// Determine full size of the data file from the corresponding cinfo-file name. +// Attempts to read xattr first and falls back to reading of the cinfo file. +// Returns -error on failure. +//------------------------------------------------------------------------------ +long long Cache::DetermineFullFileSize(const std::string &cinfo_fname) +{ + if (m_metaXattr) { + char pfn[4096]; + m_oss->Lfn2Pfn(cinfo_fname.c_str(), pfn, 4096); + long long fsize = -1ll; + int res = XrdSysXAttrActive->Get("pfc.fsize", &fsize, sizeof(long long), pfn); + if (res == sizeof(long long)) + { + return fsize; + } + else + { + TRACE(Debug, "DetermineFullFileSize error getting xattr " << res); + } + } + + XrdOssDF *infoFile = m_oss->newFile(m_configuration.m_username.c_str()); + XrdOucEnv env; + int res = infoFile->Open(cinfo_fname.c_str(), O_RDONLY, 0600, env); + if (res < 0) + return res; + Info info(m_trace, 0); + if ( ! info.Read(infoFile, cinfo_fname.c_str())) + return -EBADF; + return info.GetFileSize(); +} + +//______________________________________________________________________________ +// Calculate if the file is to be considered cached for the purposes of +// only-if-cached and setting of atime of the Stat() calls. +// Returns true if the file is to be conidered cached. +//------------------------------------------------------------------------------ +bool Cache::DecideIfConsideredCached(long long file_size, long long bytes_on_disk) +{ + if (file_size == 0 || bytes_on_disk >= file_size) + return true; + + double frac_on_disk = (double) bytes_on_disk / file_size; + + if (file_size <= m_configuration.m_onlyIfCachedMinSize) + { + if (frac_on_disk >= m_configuration.m_onlyIfCachedMinFrac) + return true; + } + else + { + if (bytes_on_disk >= m_configuration.m_onlyIfCachedMinSize && + frac_on_disk >= m_configuration.m_onlyIfCachedMinFrac) + return true; + } + return false; +} + //______________________________________________________________________________ // Check if the file is cached including m_onlyIfCachedMinSize and m_onlyIfCachedMinFrac // pfc configuration parameters. The logic of accessing the Info file is the same @@ -905,108 +987,58 @@ int Cache::LocalFilePath(const char *curl, char *buff, int blen, //! the buffer, if it has been supllied. //! //! @return <0 - the request could not be fulfilled. The return value is -//! -errno describing why. If a buffer was supplied and a -//! path could be generated it is returned only if "why" is -//! ForCheck or ForInfo. Otherwise, a null path is returned. +//! -errno describing why. //! //! @return >0 - Reserved for future use. //------------------------------------------------------------------------------ int Cache::ConsiderCached(const char *curl) { - TRACE(Debug, "ConsiderFileCached '" << curl << "'" ); + static const char* tpfx = "ConsiderCached "; + + TRACE(Debug, tpfx << curl); XrdCl::URL url(curl); std::string f_name = url.GetPath(); - std::string i_name = f_name + Info::s_infoExtension; + File *file = nullptr; { XrdSysCondVarHelper lock(&m_active_cond); - m_purge_delay_set.insert(f_name); + auto it = m_active.find(f_name); + if (it != m_active.end()) { + file = it->second; + inc_ref_cnt(file, false, false); + } + } + if (file) { + struct stat sbuff; + int res = file->Fstat(sbuff); + dec_ref_cnt(file, false); + if (res) + return res; + // DecideIfConsideredCached() already called in File::Fstat(). + return sbuff.st_atime > 0 ? 0 : -EREMOTE; } - struct stat sbuff, sbuff2; - if (m_oss->Stat(f_name.c_str(), &sbuff) == XrdOssOK && - m_oss->Stat(i_name.c_str(), &sbuff2) == XrdOssOK) + struct stat sbuff; + int res = m_oss->Stat(f_name.c_str(), &sbuff); + if (res != XrdOssOK) { + TRACE(Debug, tpfx << curl << " -> " << res); + return res; + } + if (S_ISDIR(sbuff.st_mode)) { - if (S_ISDIR(sbuff.st_mode)) - { - TRACE(Info, "ConsiderCached '" << curl << ", why=ForInfo" << " -> EISDIR"); - return -EISDIR; - } - else - { - bool read_ok = false; - bool is_cached = false; - - // Lock and check if the file is active. If NOT, keep the lock - // and add dummy access after successful reading of info file. - // If it IS active, just release the lock, this ongoing access will - // assure the file continues to exist. - - // XXXX How can I just loop over the cinfo file when active? - // Can I not get is_complete from the existing file? - // Do I still want to inject access record? - // Oh, it writes only if not active .... still let's try to use existing File. - - m_active_cond.Lock(); - - bool is_active = m_active.find(f_name) != m_active.end(); - - if (is_active) - m_active_cond.UnLock(); - - XrdOssDF *infoFile = m_oss->newFile(m_configuration.m_username.c_str()); - XrdOucEnv myEnv; - int res = infoFile->Open(i_name.c_str(), O_RDWR, 0600, myEnv); - if (res >= 0) - { - Info info(m_trace, 0); - if (info.Read(infoFile, i_name.c_str())) - { - read_ok = true; - - if (info.IsComplete()) - { - is_cached = true; - } - else if (info.GetFileSize() == 0) - { - is_cached = true; - } - else - { - long long fileSize = info.GetFileSize(); - long long bytesRead = info.GetNDownloadedBytes(); - - if (fileSize < m_configuration.m_onlyIfCachedMinSize) - { - if ((float)bytesRead / fileSize > m_configuration.m_onlyIfCachedMinFrac) - is_cached = true; - } - else - { - if (bytesRead > m_configuration.m_onlyIfCachedMinSize && - (float)bytesRead / fileSize > m_configuration.m_onlyIfCachedMinFrac) - is_cached = true; - } - } - } - infoFile->Close(); - } - delete infoFile; - - if (!is_active) m_active_cond.UnLock(); + TRACE(Debug, tpfx << curl << " -> EISDIR"); + return -EISDIR; + } - if (read_ok) - { - TRACE(Info, "ConsiderCached '" << curl << "', why=ForInfo" << (is_cached ? " -> FILE_COMPLETE_IN_CACHE" : " -> EREMOTE")); - return is_cached ? 0 : -EREMOTE; - } - } + long long file_size = DetermineFullFileSize(f_name + Info::s_infoExtension); + if (file_size < 0) { + TRACE(Debug, tpfx << curl << " -> " << file_size); + return (int) file_size; } + bool is_cached = DecideIfConsideredCached(file_size, sbuff.st_blocks * 512ll); - TRACE(Info, "ConsiderCached '" << curl << "', why=ForInfo" << " -> ENOENT"); - return -ENOENT; + return is_cached ? 0 : -EREMOTE; } //______________________________________________________________________________ @@ -1051,8 +1083,7 @@ int Cache::Prepare(const char *curl, int oflags, mode_t mode) } struct stat sbuff; - int res = m_oss->Stat(i_name.c_str(), &sbuff); - if (res == 0) + if (m_oss->Stat(i_name.c_str(), &sbuff) == XrdOssOK) { TRACE(Dump, "Prepare defer open " << f_name); return 1; @@ -1073,44 +1104,51 @@ int Cache::Prepare(const char *curl, int oflags, mode_t mode) int Cache::Stat(const char *curl, struct stat &sbuff) { + const char *tpfx = "Stat "; + XrdCl::URL url(curl); std::string f_name = url.GetPath(); + File *file = nullptr; { XrdSysCondVarHelper lock(&m_active_cond); - m_purge_delay_set.insert(f_name); + auto it = m_active.find(f_name); + if (it != m_active.end()) { + file = it->second; + inc_ref_cnt(file, false, false); + } + } + if (file) { + int res = file->Fstat(sbuff); + dec_ref_cnt(file, false); + TRACE(Debug, tpfx << "from active file " << curl << " -> " << res); + return res; } - if (m_oss->Stat(f_name.c_str(), &sbuff) == XrdOssOK) + int res = m_oss->Stat(f_name.c_str(), &sbuff); + if (res != XrdOssOK) { + TRACE(Debug, tpfx << curl << " -> " << res); + return 1; // res; -- for only-if-cached + } + if (S_ISDIR(sbuff.st_mode)) { - if (S_ISDIR(sbuff.st_mode)) - { - return 0; - } - else - { - bool success = false; - XrdOssDF* infoFile = m_oss->newFile(m_configuration.m_username.c_str()); - XrdOucEnv myEnv; + TRACE(Debug, tpfx << curl << " -> EISDIR"); + return -EISDIR; + } - f_name += Info::s_infoExtension; - int res = infoFile->Open(f_name.c_str(), O_RDONLY, 0600, myEnv); - if (res >= 0) - { - Info info(m_trace, 0); - if (info.Read(infoFile, f_name.c_str())) - { - sbuff.st_size = info.GetFileSize(); - success = true; - } - } - infoFile->Close(); - delete infoFile; - return success ? 0 : 1; - } + long long file_size = DetermineFullFileSize(f_name + Info::s_infoExtension); + if (file_size < 0) { + TRACE(Debug, tpfx << curl << " -> " << file_size); + return 1; // (int) file_size; -- for only-if-cached } + sbuff.st_size = file_size; + bool is_cached = DecideIfConsideredCached(file_size, sbuff.st_blocks * 512ll); + if ( ! is_cached) + sbuff.st_atime = 0; + + TRACE(Debug, tpfx << "from disk " << curl << " -> " << res); - return 1; + return 0; } //______________________________________________________________________________ diff --git a/src/XrdPfc/XrdPfc.hh b/src/XrdPfc/XrdPfc.hh index fdc4093dd70..f22591eb115 100644 --- a/src/XrdPfc/XrdPfc.hh +++ b/src/XrdPfc/XrdPfc.hh @@ -300,6 +300,10 @@ public: //--------------------------------------------------------------------- virtual int ConsiderCached(const char *url); + bool DecideIfConsideredCached(long long file_size, long long bytes_on_disk); + void WriteFileSizeXAttr(int cinfo_fd, long long file_size); + long long DetermineFullFileSize(const std::string &cinfo_fname); + //-------------------------------------------------------------------- //! \brief Makes decision if the original XrdOucCacheIO should be cached. //! @@ -409,6 +413,7 @@ private: bool xcschk(XrdOucStream &); bool xdlib(XrdOucStream &); bool xtrace(XrdOucStream &); + bool test_oss_basics_and_features(); bool cfg2bytes(const std::string &str, long long &store, long long totalSpace, const char *name); @@ -437,6 +442,8 @@ private: int m_RAM_std_size; bool m_isClient; //!< True if running as client + bool m_dataXattr = false; //!< True if xattrs are available on the data space + bool m_metaXattr = false; //!< True if xattrs are available on the meta space struct WriteQ { diff --git a/src/XrdPfc/XrdPfcConfiguration.cc b/src/XrdPfc/XrdPfcConfiguration.cc index 2cdb5869394..74e4a098626 100644 --- a/src/XrdPfc/XrdPfcConfiguration.cc +++ b/src/XrdPfc/XrdPfcConfiguration.cc @@ -10,11 +10,19 @@ #include "XrdOuc/XrdOucPinLoader.hh" #include "XrdOuc/XrdOuca2x.hh" -#include "XrdOfs/XrdOfsConfigPI.hh" #include "XrdVersion.hh" +#include "XrdOfs/XrdOfsConfigPI.hh" +#include "XrdSys/XrdSysXAttr.hh" #include +extern XrdSysXAttr *XrdSysXAttrActive; + +namespace XrdPfc +{ + const char *trace_what_strings[] = {"","error ","warning ","info ","debug ","dump "}; +} + using namespace XrdPfc; XrdVERSIONINFO(XrdOucGetCache, XrdPfc); @@ -263,6 +271,76 @@ bool Cache::xtrace(XrdOucStream &Config) return false; } +// Determine if oss spaces are operational and if they support xattrs. +bool Cache::test_oss_basics_and_features() +{ + static const char *epfx = "test_oss_basics_and_features()"; + + const auto &conf = m_configuration; + const char *user = conf.m_username.c_str(); + XrdOucEnv env; + + auto check_space = [&](const char *space, bool &has_xattr) + { + std::string fname("__prerun_test_pfc_"); + fname += space; + fname += "_space__"; + env.Put("oss.cgroup", space); + + int res = m_oss->Create(user, fname.c_str(), 0600, env, XRDOSS_mkpath); + if (res != XrdOssOK) { + m_log.Emsg(epfx, "Can not create a file on space", space); + return false; + } + XrdOssDF *oss_file = m_oss->newFile(user); + res = oss_file->Open(fname.c_str(), O_RDWR, 0600, env); + if (res != XrdOssOK) { + m_log.Emsg(epfx, "Can not open a file on space", space); + return false; + } + res = oss_file->Write(fname.data(), 0, fname.length()); + if (res != (int) fname.length()) { + m_log.Emsg(epfx, "Can not write into a file on space", space); + return false; + } + + has_xattr = true; + long long fsize = fname.length(); + res = XrdSysXAttrActive->Set("pfc.fsize", &fsize, sizeof(long long), 0, oss_file->getFD(), 0); + if (res != 0) { + m_log.Emsg(epfx, "Can not write xattr to a file on space", space); + has_xattr = false; + } + + oss_file->Close(); + + if (has_xattr) { + char pfn[4096]; + m_oss->Lfn2Pfn(fname.c_str(), pfn, 4096); + fsize = -1ll; + res = XrdSysXAttrActive->Get("pfc.fsize", &fsize, sizeof(long long), pfn); + if (res != sizeof(long long) || fsize != (long long) fname.length()) + { + m_log.Emsg(epfx, "Can not read xattr from a file on space", space); + has_xattr = false; + } + } + + res = m_oss->Unlink(fname.c_str()); + if (res != XrdOssOK) { + m_log.Emsg(epfx, "Can not unlink a file on space", space); + return false; + } + + return true; + }; + + bool aOK = true; + aOK &= check_space(conf.m_data_space.c_str(), m_dataXattr); + aOK &= check_space(conf.m_meta_space.c_str(), m_metaXattr); + + return aOK; +} //______________________________________________________________________________ /* Function: Config @@ -379,6 +457,9 @@ bool Cache::Config(const char *config_filename, const char *parameters) return false; } + // Test if OSS is operational, determine optional features. + aOK &= test_oss_basics_and_features(); + // sets default value for disk usage XrdOssVSInfo sP; { @@ -423,6 +504,7 @@ bool Cache::Config(const char *config_filename, const char *parameters) else aOK = false; } } + // sets flush frequency if ( ! tmpc.m_flushRaw.empty()) { @@ -456,7 +538,6 @@ bool Cache::Config(const char *config_filename, const char *parameters) } // Setup number of standard-size blocks not released back to the system to 5% of total RAM. m_configuration.m_RamKeepStdBlocks = (m_configuration.m_RamAbsAvailable / m_configuration.m_bufferSize + 1) * 5 / 100; - // Set tracing to debug if this is set in environment char* cenv = getenv("XRDDEBUG"); diff --git a/src/XrdPfc/XrdPfcFile.cc b/src/XrdPfc/XrdPfcFile.cc index 178d1205c5b..f96eae37592 100644 --- a/src/XrdPfc/XrdPfcFile.cc +++ b/src/XrdPfc/XrdPfcFile.cc @@ -68,6 +68,7 @@ File::File(const std::string& path, long long iOffset, long long iFileSize) : m_block_size(0), m_num_blocks(0), m_prefetch_state(kOff), + m_prefetch_bytes(0), m_prefetch_read_cnt(0), m_prefetch_hit_cnt(0), m_prefetch_score(0) @@ -473,6 +474,7 @@ bool File::Open() m_cfi.ResetNoCkSumTime(); m_cfi.Write(m_info_file, ifn.c_str()); m_info_file->Fsync(); + cache()->WriteFileSizeXAttr(m_info_file->getFD(), m_file_size); TRACEF(Debug, tpfx << "Creating new file info, data size = " << m_file_size << " num blocks = " << m_cfi.GetNBlocks()); } @@ -486,6 +488,27 @@ bool File::Open() return true; } +int File::Fstat(struct stat &sbuff) +{ + // Stat on an open file. + // Corrects size to actual full size of the file. + // Sets atime to 0 if the file is only partially downloaded, in accordance + // with pfc.onlyifcached settings. + // Called from IO::Fstat() and Cache::Stat() when the file is active. + // Returns 0 on success, -errno on error. + + int res; + + if ((res = m_data_file->Fstat(&sbuff))) return res; + + sbuff.st_size = m_file_size; + + bool is_cached = cache()->DecideIfConsideredCached(m_file_size, sbuff.st_blocks * 512ll); + if ( ! is_cached) + sbuff.st_atime = 0; + + return 0; +} //============================================================================== // Read and helpers @@ -923,7 +946,8 @@ int File::ReadOpusCoalescere(IO *io, const XrdOucIOVec *readV, int readVnum, if (read_req) { read_req->m_bytes_read += bytes_read; - read_req->update_error_cond(error_cond); + if (error_cond) + read_req->update_error_cond(error_cond); read_req->m_stats.m_BytesHit += bytes_read; read_req->m_sync_done = true; @@ -1217,7 +1241,7 @@ void File::ProcessBlockError(Block *b, ReadRequest *rreq) // Does not manage m_read_req. // Will not complete the request. - TRACEF(Error, "ProcessBlockError() io " << b->m_io << ", block "<< b->m_offset/m_block_size << + TRACEF(Debug, "ProcessBlockError() io " << b->m_io << ", block "<< b->m_offset/m_block_size << " finished with error " << -b->get_error() << " " << XrdSysE2T(-b->get_error())); rreq->update_error_cond(b->get_error()); @@ -1320,6 +1344,7 @@ void File::ProcessBlockResponse(Block *b, int res) m_state_cond.UnLock(); return; } + m_prefetch_bytes += b->get_size(); } else { @@ -1353,9 +1378,15 @@ void File::ProcessBlockResponse(Block *b, int res) else { if (res < 0) { - TRACEF(Error, tpfx << "block " << b << ", idx=" << b->m_offset/m_block_size << ", off=" << b->m_offset << " error=" << res); + bool new_error = b->get_io()->register_block_error(res); + int tlvl = new_error ? TRACE_Error : TRACE_Debug; + TRACEF_INT(tlvl, tpfx << "block " << b << ", idx=" << b->m_offset/m_block_size << ", off=" << b->m_offset + << ", io=" << b->get_io() << ", error=" << res); } else { - TRACEF(Error, tpfx << "block " << b << ", idx=" << b->m_offset/m_block_size << ", off=" << b->m_offset << " incomplete, got " << res << " expected " << b->get_size()); + bool first_p = b->get_io()->register_incomplete_read(); + int tlvl = first_p ? TRACE_Error : TRACE_Debug; + TRACEF_INT(tlvl, tpfx << "block " << b << ", idx=" << b->m_offset/m_block_size << ", off=" << b->m_offset + << ", io=" << b->get_io() << " incomplete, got " << res << " expected " << b->get_size()); #if defined(__APPLE__) || defined(__GNU__) || (defined(__FreeBSD_kernel__) && defined(__GLIBC__)) || defined(__FreeBSD__) res = -EIO; #else @@ -1393,7 +1424,7 @@ void File::ProcessBlockResponse(Block *b, int res) { ReadRequest *rreq = creqs_to_keep.front().m_read_req; - TRACEF(Info, "ProcessBlockResponse() requested block " << (void*)b << " failed with another io " << + TRACEF(Debug, "ProcessBlockResponse() requested block " << (void*)b << " failed with another io " << b->get_io() << " - reissuing request with my io " << rreq->m_io); b->reset_error_and_set_io(rreq->m_io, rreq); diff --git a/src/XrdPfc/XrdPfcFile.hh b/src/XrdPfc/XrdPfcFile.hh index 608e5dd73e3..58d10d987cf 100644 --- a/src/XrdPfc/XrdPfcFile.hh +++ b/src/XrdPfc/XrdPfcFile.hh @@ -78,6 +78,7 @@ struct ReadRequest long long m_bytes_read = 0; int m_error_cond = 0; // to be set to -errno + int m_error_count = 0; Stats m_stats; int m_n_chunk_reqs = 0; @@ -88,7 +89,7 @@ struct ReadRequest m_io(io), m_rh(rh) {} - void update_error_cond(int ec) { if (m_error_cond == 0 ) m_error_cond = ec; } + void update_error_cond(int ec) { ++m_error_count; if (m_error_cond == 0 ) m_error_cond = ec; } bool is_complete() const { return m_n_chunk_reqs == 0 && m_sync_done && m_direct_done; } int return_value() const { return m_error_cond ? m_error_cond : m_bytes_read; } @@ -291,8 +292,11 @@ public: int GetBlockSize() const { return m_cfi.GetBufferSize(); } int GetNBlocks() const { return m_cfi.GetNBlocks(); } int GetNDownloadedBlocks() const { return m_cfi.GetNDownloadedBlocks(); } + long long GetPrefetchedBytes() const { return m_prefetch_bytes; } const Stats& RefStats() const { return m_stats; } + int Fstat(struct stat &sbuff); + // These three methods are called under Cache's m_active lock int get_ref_cnt() { return m_ref_cnt; } int inc_ref_cnt() { return ++m_ref_cnt; } @@ -311,7 +315,7 @@ private: static const char *m_traceID; int m_ref_cnt; //!< number of references from IO or sync - + XrdOssDF *m_data_file; //!< file handle for data file on disk XrdOssDF *m_info_file; //!< file handle for data-info file on disk Info m_cfi; //!< download status of file blocks and access statistics @@ -364,6 +368,7 @@ private: PrefetchState_e m_prefetch_state; + long long m_prefetch_bytes; int m_prefetch_read_cnt; int m_prefetch_hit_cnt; float m_prefetch_score; // cached diff --git a/src/XrdPfc/XrdPfcIO.hh b/src/XrdPfc/XrdPfcIO.hh index 1e5f5885b71..a8298927c2a 100644 --- a/src/XrdPfc/XrdPfcIO.hh +++ b/src/XrdPfc/XrdPfcIO.hh @@ -85,6 +85,16 @@ private: int m_active_prefetches {0}; bool m_allow_prefetching {true}; bool m_in_detach {false}; + +protected: + int m_incomplete_count {0}; + std::map m_error_counts; + bool register_incomplete_read() { + return m_incomplete_count++ == 0; + } + bool register_block_error(int res) { + return m_error_counts[res]++ == 0; + } }; } diff --git a/src/XrdPfc/XrdPfcIOFile.cc b/src/XrdPfc/XrdPfcIOFile.cc index d0b3ebef169..3c39966d72d 100644 --- a/src/XrdPfc/XrdPfcIOFile.cc +++ b/src/XrdPfc/XrdPfcIOFile.cc @@ -35,8 +35,7 @@ using namespace XrdPfc; //______________________________________________________________________________ IOFile::IOFile(XrdOucCacheIO *io, Cache & cache) : IO(io, cache), - m_file(0), - m_localStat(0) + m_file(0) { m_file = Cache::GetInstance().GetFile(GetFilename(), this); } @@ -47,22 +46,20 @@ IOFile::~IOFile() // called from Detach() if no sync is needed or // from Cache's sync thread TRACEIO(Debug, "~IOFile() " << this); - - delete m_localStat; } //______________________________________________________________________________ int IOFile::Fstat(struct stat &sbuff) { - int res = 0; - if( ! m_localStat) - { - res = initCachedStat(); - if (res) return res; + // This is only called during Cache::Attach / Cache::GetFile() for file creation. + // Should really be separate name but one needs to change virtual interface + // so initialStat() becomes virtual in the base-class. + // Also, IOFileBlock should be ditched. + if ( ! m_file) { + return initialStat(sbuff); } - memcpy(&sbuff, m_localStat, sizeof(struct stat)); - return 0; + return m_file->Fstat(sbuff); } //______________________________________________________________________________ @@ -72,65 +69,30 @@ long long IOFile::FSize() } //______________________________________________________________________________ -int IOFile::initCachedStat() +int IOFile::initialStat(struct stat &sbuff) { - // Called indirectly from the constructor. + // Get stat to determine file-size. + // Called indirectly from the constructor, via Cache::GetFile(). + // Either read it from cinfo file or obtain it from the remote IO. - static const char* trace_pfx = "initCachedStat "; - - int res = -1; - struct stat tmpStat; + static const char* trace_pfx = "initialStat "; std::string fname = GetFilename(); - std::string iname = fname + Info::s_infoExtension; - if (m_cache.GetOss()->Stat(fname.c_str(), &tmpStat) == XrdOssOK) + if (m_cache.GetOss()->Stat(fname.c_str(), &sbuff) == XrdOssOK) { - XrdOssDF* infoFile = m_cache.GetOss()->newFile(Cache::GetInstance().RefConfiguration().m_username.c_str()); - XrdOucEnv myEnv; - int res_open; - if ((res_open = infoFile->Open(iname.c_str(), O_RDONLY, 0600, myEnv)) == XrdOssOK) - { - Info info(m_cache.GetTrace()); - if (info.Read(infoFile, iname.c_str())) - { - // The filesize from the file itself may be misleading if its download is incomplete; take it from the cinfo. - tmpStat.st_size = info.GetFileSize(); - // We are arguably abusing the mtime to be the creation time of the file; then ctime becomes the - // last time additional data was cached. - tmpStat.st_mtime = info.GetCreationTime(); - TRACEIO(Info, trace_pfx << "successfully read size " << tmpStat.st_size << " and creation time " << tmpStat.st_mtime << " from info file"); - res = 0; - } - else - { - // file exist but can't read it - TRACEIO(Info, trace_pfx << "info file is incomplete or corrupt"); - } - } - else + long long file_size = m_cache.DetermineFullFileSize(fname + Info::s_infoExtension); + if (file_size >= 0) { - TRACEIO(Error, trace_pfx << "can't open info file " << XrdSysE2T(-res_open)); + sbuff.st_size = file_size; + TRACEIO(Info, trace_pfx << "successfully read size " << sbuff.st_size << " from info file"); + return 0; } - infoFile->Close(); - delete infoFile; + TRACEIO(Error, trace_pfx << "failed reading from info file " << XrdSysE2T(-file_size)); } - if (res) - { - res = GetInput()->Fstat(tmpStat); - TRACEIO(Debug, trace_pfx << "got stat from client res = " << res << ", size = " << tmpStat.st_size); - // The mtime / atime / ctime for cached responses come from the file on disk in the cache hit case. - // To avoid weirdness when two subsequent stat queries can give wildly divergent times (one from the - // origin, one from the cache), set the times to "now" so we effectively only report the *time as the - // cache service sees it. - tmpStat.st_ctime = tmpStat.st_mtime = tmpStat.st_atime = time(NULL); - } + int res = GetInput()->Fstat(sbuff); + TRACEIO(Debug, trace_pfx << "stat from client res = " << res << ", size = " << sbuff.st_size); - if (res == 0) - { - m_localStat = new struct stat; - memcpy(m_localStat, &tmpStat, sizeof(struct stat)); - } return res; } @@ -153,11 +115,28 @@ void IOFile::DetachFinalize() { // Effectively a destructor. - TRACE(Info, "DetachFinalize() " << this); + TRACE(Debug, "DetachFinalize() " << this); m_file->RequestSyncOfDetachStats(); Cache::GetInstance().ReleaseFile(m_file, this); + if (( ! m_error_counts.empty() || m_incomplete_count > 0) && XRD_TRACE What >= TRACE_Error) { + char info[1024]; + int pos = 0, cap = 1024; + bool truncated = false; + for (auto [err, cnt] : m_error_counts) { + int len = snprintf(&info[pos], cap, " ( %d : %d)", err, cnt); + if (len >= cap) { + truncated = true; + break; + } + pos += len; + cap -= len; + } + TRACE(Error, "DetachFinalize() " << this << " n_incomplete_reads=" << m_incomplete_count + << ", block (error : count) report:" << info << (truncated ? " - truncated" : "")); + } + delete this; } @@ -273,9 +252,9 @@ int IOFile::ReadEnd(int retval, ReadReqRH *rh) TRACEIO(Dump, "ReadEnd() " << (rh->m_iocb ? "a" : "") << "sync " << this << " sid: " << Xrd::hex1 << rh->m_seq_id << " retval: " << retval << " expected_size: " << rh->m_expected_size); if (retval < 0) { - TRACEIO(Warning, "ReadEnd() error in File::Read(), exit status=" << retval << ", error=" << XrdSysE2T(-retval) << " sid: " << Xrd::hex1 << rh->m_seq_id); + TRACEIO(Debug, "ReadEnd() error in File::Read(), exit status=" << retval << ", error=" << XrdSysE2T(-retval) << " sid: " << Xrd::hex1 << rh->m_seq_id); } else if (retval < rh->m_expected_size) { - TRACEIO(Warning, "ReadEnd() bytes missed " << rh->m_expected_size - retval << " sid: " << Xrd::hex1 << rh->m_seq_id); + TRACEIO(Debug, "ReadEnd() bytes missed " << rh->m_expected_size - retval << " sid: " << Xrd::hex1 << rh->m_seq_id); } if (rh->m_iocb) rh->m_iocb->Done(retval); @@ -362,9 +341,9 @@ int IOFile::ReadVEnd(int retval, ReadReqRH *rh) " retval: " << retval << " n_chunks: " << rh->m_n_chunks << " expected_size: " << rh->m_expected_size); if (retval < 0) { - TRACEIO(Warning, "ReadVEnd() error in File::ReadV(), exit status=" << retval << ", error=" << XrdSysE2T(-retval)); + TRACEIO(Debug, "ReadVEnd() error in File::ReadV(), exit status=" << retval << ", error=" << XrdSysE2T(-retval)); } else if (retval < rh->m_expected_size) { - TRACEIO(Warning, "ReadVEnd() bytes missed " << rh->m_expected_size - retval); + TRACEIO(Debug, "ReadVEnd() bytes missed " << rh->m_expected_size - retval); } if (rh->m_iocb) rh->m_iocb->Done(retval); diff --git a/src/XrdPfc/XrdPfcIOFile.hh b/src/XrdPfc/XrdPfcIOFile.hh index 7e771dbbfb2..f1dc0e036f1 100644 --- a/src/XrdPfc/XrdPfcIOFile.hh +++ b/src/XrdPfc/XrdPfcIOFile.hh @@ -86,10 +86,7 @@ private: int ReadVBegin(const XrdOucIOVec *readV, int n, ReadReqRH *rh); int ReadVEnd(int retval, ReadReqRH *rh); - struct stat *m_localStat; - int initCachedStat(); - - + int initialStat(struct stat &sbuff); }; } diff --git a/src/XrdPfc/XrdPfcTrace.hh b/src/XrdPfc/XrdPfcTrace.hh index 4f69bfeca7a..38f2719bd7a 100644 --- a/src/XrdPfc/XrdPfcTrace.hh +++ b/src/XrdPfc/XrdPfcTrace.hh @@ -38,6 +38,11 @@ #define XRD_TRACE GetTrace()-> #endif +namespace XrdPfc +{ + extern const char *trace_what_strings[]; +} + #define ERRNO_AND_ERRSTR(err_code) ", err_code=" << err_code << ", err_str=" << XrdSysE2T(err_code) #define TRACE(act, x) \ @@ -46,8 +51,7 @@ #define TRACE_INT(act, x) \ if (XRD_TRACE What >= act) \ - {static const char* t_what[]={"","error ","warning ","info ","debug ","dump "};\ - SYSTRACE(XRD_TRACE, 0, m_traceID, 0, t_what[act] << x)} + SYSTRACE(XRD_TRACE, 0, m_traceID, 0, trace_what_strings[act] << x) #define TRACE_TEST(act, x) \ SYSTRACE(XRD_TRACE, 0, m_traceID, 0, TRACE_STR_ ## act << x) @@ -64,6 +68,10 @@ if (XRD_TRACE What >= TRACE_ ## act) SYSTRACE(XRD_TRACE, 0, m_traceID, 0, \ TRACE_STR_ ## act << x << " " << GetLocalPath()) +#define TRACEF_INT(act, x) \ + if (XRD_TRACE What >= act) \ + SYSTRACE(XRD_TRACE, 0, m_traceID, 0, trace_what_strings[act] << x << " " << GetLocalPath()) + #else #define ERRNO_AND_ERRSTR(err_code) @@ -71,6 +79,7 @@ #define TRACE_PC(act, pre_code, x) #define TRACEIO(act, x) #define TRACEF(act, x) +#define TRACEF_INT(act, x) #endif diff --git a/src/XrdPosix.cmake b/src/XrdPosix.cmake index e8db4bc2f99..b67be9f769a 100644 --- a/src/XrdPosix.cmake +++ b/src/XrdPosix.cmake @@ -74,7 +74,13 @@ set_target_properties( # It is meant to replace symbols from the system and as such # must not be compiled with link-time optimizations. -target_compile_options(XrdPosixPreload PRIVATE -fno-lto) +include(CheckCXXCompilerFlag) + +check_cxx_compiler_flag(-fno-lto HAS_NOLTO) + +if(HAS_NOLTO) + target_compile_options(XrdPosixPreload PRIVATE -fno-lto) +endif() #------------------------------------------------------------------------------- # Install diff --git a/src/XrdPosix/XrdPosixFile.cc b/src/XrdPosix/XrdPosixFile.cc index 09c55f971e3..a6c5b651902 100644 --- a/src/XrdPosix/XrdPosixFile.cc +++ b/src/XrdPosix/XrdPosixFile.cc @@ -38,6 +38,7 @@ #include #include "XrdOuc/XrdOucName2Name.hh" +#include "XrdOuc/XrdOucPrivateUtils.hh" #include "XrdPosix/XrdPosixCallBack.hh" #include "XrdPosix/XrdPosixConfig.hh" #include "XrdPosix/XrdPosixFile.hh" @@ -236,9 +237,9 @@ do{if (doWait) } if (Say) {snprintf(buff, sizeof(buff), "%s timeout closing", eTxt); - Say->Emsg("DDestroy", buff, fCurr->Origin()); + Say->Emsg("DDestroy", buff, obfuscateAuth(fCurr->Origin()).c_str()); } else { - DMSG("DDestroy", eTxt <<" timeout closing " <Origin() + DMSG("DDestroy", eTxt <<" timeout closing " << obfuscateAuth(fCurr->Origin()) <<' ' <nextFile = ddLost; @@ -295,9 +296,10 @@ void XrdPosixFile::DelayedDestroy(XrdPosixFile *fp) fp->numTries = 0; ddMutex.UnLock(); - DEBUG("DLY destroy "<<(doPost ? "post " : "has ")<Origin()); - + if(DEBUGON) { + DEBUG("DLY destroy " << (doPost ? "post " : "has ") << ddCount + << " objects; added " << obfuscateAuth(fp->Origin())); + } if (doPost) ddSem.Post(); } diff --git a/src/XrdPosix/XrdPosixPrepIO.cc b/src/XrdPosix/XrdPosixPrepIO.cc index 47c80ed4b25..6ef7020012e 100644 --- a/src/XrdPosix/XrdPosixPrepIO.cc +++ b/src/XrdPosix/XrdPosixPrepIO.cc @@ -28,6 +28,7 @@ /* specific prior written permission of the institution or contributor. */ /******************************************************************************/ +#include "XrdOuc/XrdOucPrivateUtils.hh" #include "XrdPosix/XrdPosixObjGuard.hh" #include "XrdPosix/XrdPosixPrepIO.hh" #include "XrdPosix/XrdPosixStats.hh" @@ -52,7 +53,9 @@ void XrdPosixPrepIO::Disable() EPNAME("PrepIODisable"); XrdPosixObjGuard objGuard(fileP); - DEBUG("Disabling deferred open "<Origin()); + if(DEBUGON) { + DEBUG("Disabling deferred open " << obfuscateAuth(fileP->Origin())); + } openRC = -ESHUTDOWN; } @@ -102,7 +105,7 @@ bool XrdPosixPrepIO::Init(XrdOucCacheIOCB *iocbP) else {openRC = XrdPosixMap::Result(Status, fileP->ecMsg, false); if (DEBUGON && errno != ENOENT && errno != ELOOP) {std::string eTxt = Status.ToString(); - DEBUG(eTxt<<" deferred open "<Origin()); + DEBUG(eTxt<<" deferred open "<< obfuscateAuth(fileP->Origin())); } XrdPosixGlobals::Stats.Count(XrdPosixGlobals::Stats.X.OpenErrs); return false; diff --git a/src/XrdPosix/XrdPosixXrootd.cc b/src/XrdPosix/XrdPosixXrootd.cc index d86acc97cc7..9efac0736b3 100644 --- a/src/XrdPosix/XrdPosixXrootd.cc +++ b/src/XrdPosix/XrdPosixXrootd.cc @@ -55,6 +55,7 @@ #include "XrdOuc/XrdOucEnv.hh" #include "XrdOuc/XrdOucName2Name.hh" #include "XrdOuc/XrdOucPsx.hh" +#include "XrdOuc/XrdOucPrivateUtils.hh" #include "XrdPosix/XrdPosixAdmin.hh" #include "XrdPosix/XrdPosixCallBack.hh" @@ -287,7 +288,7 @@ int XrdPosixXrootd::Close(int fildes) {if ((ret = fP->Close(Status))) {delete fP; fP = 0;} else if (DEBUGON) {std::string eTxt = Status.ToString(); - DEBUG(eTxt <<" closing " <Origin()); + DEBUG(eTxt <<" closing " << obfuscateAuth(fP->Origin())); } } else { ret = true; @@ -634,7 +635,7 @@ int XrdPosixXrootd::Open(const char *path, int oflags, mode_t mode, {XrdPosixGlobals::Stats.Count(XrdPosixGlobals::Stats.X.OpenErrs); int rc = XrdPosixMap::Result(Status,XrdPosixGlobals::ecMsg,false); if (DEBUGON && rc != -ENOENT && rc != -ELOOP) - {DEBUG(XrdPosixGlobals::ecMsg.Msg() <<" open " <Origin());} + {DEBUG(XrdPosixGlobals::ecMsg.Msg() <<" open " << obfuscateAuth(fp->Origin()));} delete fp; errno = -rc; // Saved errno across the delete return -1; diff --git a/src/XrdPss/XrdPss.cc b/src/XrdPss/XrdPss.cc index b140bbac863..bd5d84a7a78 100644 --- a/src/XrdPss/XrdPss.cc +++ b/src/XrdPss/XrdPss.cc @@ -64,6 +64,7 @@ #include "XrdOuc/XrdOucEnv.hh" #include "XrdOuc/XrdOucExport.hh" #include "XrdOuc/XrdOucPgrwUtils.hh" +#include "XrdOuc/XrdOucPrivateUtils.hh" #include "XrdSec/XrdSecEntity.hh" #include "XrdSecsss/XrdSecsssID.hh" #include "XrdSfs/XrdSfsInterface.hh" @@ -363,7 +364,10 @@ int XrdPssSys::Mkdir(const char *path, mode_t mode, int mkpath, XrdOucEnv *eP) // Some tracing // - DEBUG(uInfo.Tident(),"url="<Delete();} /******************************************************************************/ /* Private: F i n d */ diff --git a/src/XrdSecztn/XrdSecztn.cc b/src/XrdSecztn/XrdSecztn.cc index 036baed646e..2054d6abbb3 100644 --- a/src/XrdSecztn/XrdSecztn.cc +++ b/src/XrdSecztn/XrdSecztn.cc @@ -28,6 +28,7 @@ #include #include #include +#include #ifndef __FreeBSD__ #include @@ -81,7 +82,10 @@ namespace int DecodeUrl(const char *decode, size_t num_decode, char *out, size_t &num_out) { // No integer overflows please. - if ((decode + num_decode) < decode || (out + num_out) < out) + if (num_decode > std::numeric_limits::max() - (size_t)decode) + return 1; + + if (num_out > std::numeric_limits::max() - (size_t)out) return 1; if (num_out < DecodeBytesNeeded(num_decode)) diff --git a/src/XrdSut/XrdSutCache.hh b/src/XrdSut/XrdSutCache.hh index b9635d4e12c..6c39f87e8db 100644 --- a/src/XrdSut/XrdSutCache.hh +++ b/src/XrdSut/XrdSutCache.hh @@ -40,10 +40,10 @@ typedef bool (*XrdSutCacheGet_t)(XrdSutCacheEntry *, void *); typedef struct { - long arg1; - long arg2; - long arg3; - long arg4; + long long arg1; + long long arg2; + long long arg3; + long long arg4; } XrdSutCacheArg_t; class XrdSutCache { diff --git a/src/XrdSys/XrdSysE2T.cc b/src/XrdSys/XrdSysE2T.cc index 83b62e317f8..64daa982749 100644 --- a/src/XrdSys/XrdSysE2T.cc +++ b/src/XrdSys/XrdSysE2T.cc @@ -67,11 +67,16 @@ int initErrTable() // EAUTH is remapped to EBADE ('invalid exchange'). Given there's no current XRootD use of a // syscall that can return EBADE, we assume EBADE really means authentication denied. #if defined(EBADE) - if (Errno2String[EBADE]) { - free((char*)Errno2String[EBADE]); + if (EBADE - ERRNOBASE > 0 && EBADE - ERRNOBASE < errSlots) { + if (Errno2String[EBADE - ERRNOBASE]) + free((char*)Errno2String[EBADE - ERRNOBASE]); + Errno2String[EBADE - ERRNOBASE] = "authentication failed - possible invalid exchange"; + if (EBADE - ERRNOBASE > lastGood) + lastGood = EBADE - ERRNOBASE; + } + else { + e2sMap[EBADE] = "authentication failed - possible invalid exchange"; } - - Errno2String[EBADE] = "authentication failed - possible invalid exchange"; #endif // Supply generic message for missing ones diff --git a/src/XrdTpc.cmake b/src/XrdTpc.cmake index 695d41dd3e8..2dcf5e23dd4 100644 --- a/src/XrdTpc.cmake +++ b/src/XrdTpc.cmake @@ -25,7 +25,7 @@ if( BUILD_TPC ) } " CURL_PIPELINING ) - set(XRD_COMPILE_DEFS "XRD_CHUNK_RESP") + if ( CURL_PIPELINING ) set(XRD_COMPILE_DEFS ${XRD_COMPILE_DEFS} "USE_PIPELINING") endif () diff --git a/src/XrdTpc/XrdTpcMultistream.cc b/src/XrdTpc/XrdTpcMultistream.cc index 290688f84a3..ae13f1757a1 100644 --- a/src/XrdTpc/XrdTpcMultistream.cc +++ b/src/XrdTpc/XrdTpcMultistream.cc @@ -2,8 +2,6 @@ * Implementation of multi-stream HTTP transfers for the TPCHandler */ -#ifdef XRD_CHUNK_RESP - #include "XrdTpcTPC.hh" #include "XrdTpcState.hh" #include "XrdTpcCurlMulti.hh" @@ -260,17 +258,11 @@ int TPCHandler::RunCurlWithStreamsImpl(XrdHttpExtReq &req, State &state, size_t streams, std::vector &handles, std::vector &curl_handles, TPCLogRecord &rec) { - int result; bool success; - CURL *curl = state.GetHandle(); - if ((result = DetermineXferSize(curl, req, state, success, rec)) || !success) { - return result; - } + // The content-length was set thanks to the call to GetContentLengthTPCPull() before calling this function off_t content_size = state.GetContentLength(); off_t current_offset = 0; - state.ResetAfterRequest(); - size_t concurrency = streams * m_pipelining_multiplier; handles.reserve(concurrency); @@ -553,6 +545,4 @@ int TPCHandler::RunCurlWithStreams(XrdHttpExtReq &req, State &state, } return req.ChunkResp(NULL, 0); } -} - -#endif // XRD_CHUNK_RESP +} \ No newline at end of file diff --git a/src/XrdTpc/XrdTpcState.hh b/src/XrdTpc/XrdTpcState.hh index c4052c4816d..7ac178ea14e 100644 --- a/src/XrdTpc/XrdTpcState.hh +++ b/src/XrdTpc/XrdTpcState.hh @@ -87,6 +87,8 @@ public: off_t BytesTransferred() const {return m_offset;} + void SetContentLength(const off_t content_length) { m_content_length = content_length; } + off_t GetContentLength() const {return m_content_length;} int GetErrorCode() const {return m_error_code;} diff --git a/src/XrdTpc/XrdTpcTPC.cc b/src/XrdTpc/XrdTpcTPC.cc index bb25a4643ee..eca9b9d4be2 100644 --- a/src/XrdTpc/XrdTpcTPC.cc +++ b/src/XrdTpc/XrdTpcTPC.cc @@ -427,11 +427,8 @@ int TPCHandler::OpenWaitStall(XrdSfsFile &fh, const std::string &resource, } /******************************************************************************/ -/* XRD_CHUNK_RESP: */ /* T P C H a n d l e r : : D e t e r m i n e X f e r S i z e */ /******************************************************************************/ - -#ifdef XRD_CHUNK_RESP @@ -442,14 +439,18 @@ int TPCHandler::DetermineXferSize(CURL *curl, XrdHttpExtReq &req, State &state, bool &success, TPCLogRecord &rec, bool shouldReturnErrorToClient) { success = false; curl_easy_setopt(curl, CURLOPT_NOBODY, 1); + // Set a custom timeout of 60 seconds (= CONNECT_TIMEOUT for convenience) for the HEAD request + curl_easy_setopt(curl, CURLOPT_TIMEOUT, CONNECT_TIMEOUT); CURLcode res; res = curl_easy_perform(curl); //Immediately set the CURLOPT_NOBODY flag to 0 as we anyway //don't want the next curl call to do be a HEAD request curl_easy_setopt(curl, CURLOPT_NOBODY, 0); + // Reset the CURLOPT_TIMEOUT to no timeout (default) + curl_easy_setopt(curl, CURLOPT_TIMEOUT, 0L); if (res == CURLE_HTTP_RETURNED_ERROR) { std::stringstream ss; - ss << "Remote server failed request"; + ss << "Remote server failed request while fetching remote size"; std::stringstream ss2; ss2 << ss.str() << ": " << curl_easy_strerror(res); rec.status = 500; @@ -457,13 +458,13 @@ int TPCHandler::DetermineXferSize(CURL *curl, XrdHttpExtReq &req, State &state, return shouldReturnErrorToClient ? req.SendSimpleResp(rec.status, NULL, NULL, generateClientErr(ss, rec, res).c_str(), 0) : -1; } else if (state.GetStatusCode() >= 400) { std::stringstream ss; - ss << "Remote side " << req.clienthost << " failed with status code " << state.GetStatusCode(); + ss << "Remote side " << req.clienthost << " failed with status code " << state.GetStatusCode() << " while fetching remote size"; rec.status = 500; logTransferEvent(LogMask::Error, rec, "SIZE_FAIL", ss.str()); return shouldReturnErrorToClient ? req.SendSimpleResp(rec.status, NULL, NULL, generateClientErr(ss, rec).c_str(), 0) : -1; } else if (res) { std::stringstream ss; - ss << "Internal transfer failure"; + ss << "Internal transfer failure while fetching remote size"; std::stringstream ss2; ss2 << ss.str() << " - HTTP library failed: " << curl_easy_strerror(res); rec.status = 500; @@ -484,8 +485,8 @@ int TPCHandler::GetContentLengthTPCPull(CURL *curl, XrdHttpExtReq &req, uint64_t //it will fail state.CopyHeaders(req); int result; - //In case we cannot get the content length, we don't return anything to the client - if ((result = DetermineXferSize(curl, req, state, success, rec, false)) || !success) { + //In case we cannot get the content length, we return the error to the client + if ((result = DetermineXferSize(curl, req, state, success, rec)) || !success) { return result; } contentLength = state.GetContentLength(); @@ -493,7 +494,6 @@ int TPCHandler::GetContentLengthTPCPull(CURL *curl, XrdHttpExtReq &req, uint64_t } /******************************************************************************/ -/* XRD_CHUNK_RESP: */ /* T P C H a n d l e r : : S e n d P e r f M a r k e r */ /******************************************************************************/ @@ -518,7 +518,6 @@ int TPCHandler::SendPerfMarker(XrdHttpExtReq &req, TPCLogRecord &rec, TPC::State } /******************************************************************************/ -/* XRD_CHUNK_RESP: */ /* T P C H a n d l e r : : S e n d P e r f M a r k e r */ /******************************************************************************/ @@ -567,7 +566,6 @@ int TPCHandler::SendPerfMarker(XrdHttpExtReq &req, TPCLogRecord &rec, std::vecto } /******************************************************************************/ -/* XRD_CHUNK_RESP: */ /* T P C H a n d l e r : : R u n C u r l W i t h U p d a t e s */ /******************************************************************************/ @@ -794,49 +792,6 @@ int TPCHandler::RunCurlWithUpdates(CURL *curl, XrdHttpExtReq &req, State &state, return req.ChunkResp(NULL, 0); } -/******************************************************************************/ -/* !XRD_CHUNK_RESP: */ -/* T P C H a n d l e r : : R u n C u r l B a s i c */ -/******************************************************************************/ - -#else -int TPCHandler::RunCurlBasic(CURL *curl, XrdHttpExtReq &req, State &state, - TPCLogRecord &rec) { - const char *log_prefix = rec.log_prefix.c_str(); - CURLcode res; - res = curl_easy_perform(curl); - state.Flush(); - state.Finalize(); - if (state.GetErrorCode()) { - std::string err = state.GetErrorMessage(); - if (err.empty()) {err = "(no error message provided)";} - else {std::replace(err.begin(), err.end(), '\n', ' ');} - std::stringstream ss2; - ss2 << "Error when interacting with local filesystem: " << err; - logTransferEvent(LogMask::Error, rec, "TRANSFER_FAIL", ss2.str()); - ss << "failure: " << ss2.str(); - } else if (res == CURLE_HTTP_RETURNED_ERROR) { - m_log.Emsg(log_prefix, "Remote server failed request", curl_easy_strerror(res)); - return req.SendSimpleResp(500, NULL, NULL, - const_cast(curl_easy_strerror(res)), 0); - } else if (state.GetStatusCode() >= 400) { - std::stringstream ss; - ss << "Remote side failed with status code " << state.GetStatusCode(); - m_log.Emsg(log_prefix, "Remote server failed request", ss.str().c_str()); - return req.SendSimpleResp(500, NULL, NULL, - const_cast(ss.str().c_str()), 0); - } else if (res) { - m_log.Emsg(log_prefix, "Curl failed", curl_easy_strerror(res)); - char msg[] = "Unknown internal transfer failure"; - return req.SendSimpleResp(500, NULL, NULL, msg, 0); - } else { - char msg[] = "Created"; - rec.status = 0; - return req.SendSimpleResp(201, NULL, NULL, msg, 0); - } -} -#endif - /******************************************************************************/ /* T P C H a n d l e r : : P r o c e s s P u s h R e q */ /******************************************************************************/ @@ -919,11 +874,7 @@ int TPCHandler::ProcessPushReq(const std::string & resource, XrdHttpExtReq &req) State state(0, stream, curl, true, req.tpcForwardCreds); state.CopyHeaders(req); -#ifdef XRD_CHUNK_RESP return RunCurlWithUpdates(curl, req, state, rec); -#else - return RunCurlBasic(curl, req, state, rec); -#endif } /******************************************************************************/ @@ -1035,11 +986,10 @@ int TPCHandler::ProcessPullReq(const std::string &resource, XrdHttpExtReq &req) std::string authz = GetAuthz(req); curl_easy_setopt(curl, CURLOPT_URL, resource.c_str()); ConfigureCurlCA(curl); -#ifdef XRD_CHUNK_RESP + uint64_t sourceFileContentLength = 0; { //Get the content-length of the source file and pass it to the OSS layer //during the open - uint64_t sourceFileContentLength = 0; bool success; GetContentLengthTPCPull(curl, req, sourceFileContentLength, success, rec); if(success) { @@ -1047,9 +997,12 @@ int TPCHandler::ProcessPullReq(const std::string &resource, XrdHttpExtReq &req) //we just don't add the size information to the opaque of the local file to open full_url += hasSetOpaque ? "&" : "?"; full_url += "oss.asize=" + std::to_string(sourceFileContentLength); + } else { + // In the case the GetContentLength is not successful, an error will be returned to the client + // just exit here so we don't open the file! + return 0; } } -#endif int open_result = OpenWaitStall(*fh, full_url, mode|SFS_O_WRONLY, 0644 | SFS_O_MKPTH, req.GetSecEntity(), authz); @@ -1074,16 +1027,13 @@ int TPCHandler::ProcessPullReq(const std::string &resource, XrdHttpExtReq &req) Stream stream(std::move(fh), streams * m_pipelining_multiplier, streams > 1 ? m_block_size : m_small_block_size, m_log); State state(0, stream, curl, false, req.tpcForwardCreds); state.CopyHeaders(req); + state.SetContentLength(sourceFileContentLength); -#ifdef XRD_CHUNK_RESP if (streams > 1) { return RunCurlWithStreams(req, state, streams, rec); } else { return RunCurlWithUpdates(curl, req, state, rec); } -#else - return RunCurlBasic(curl, req, state, rec); -#endif } /******************************************************************************/ diff --git a/src/XrdTpc/XrdTpcTPC.hh b/src/XrdTpc/XrdTpcTPC.hh index 80da2c5975f..d230d633838 100644 --- a/src/XrdTpc/XrdTpcTPC.hh +++ b/src/XrdTpc/XrdTpcTPC.hh @@ -100,7 +100,6 @@ private: int openMode, const XrdSecEntity &sec, const std::string &authz); -#ifdef XRD_CHUNK_RESP int DetermineXferSize(CURL *curl, XrdHttpExtReq &req, TPC::State &state, bool &success, TPCLogRecord &, bool shouldReturnErrorToClient = true); @@ -125,10 +124,6 @@ private: size_t streams, std::vector &streams_handles, std::vector &curl_handles, TPCLogRecord &rec); -#else - int RunCurlBasic(CURL *curl, XrdHttpExtReq &req, TPC::State &state, - TPCLogRecord &rec); -#endif int ProcessPushReq(const std::string & resource, XrdHttpExtReq &req); int ProcessPullReq(const std::string &resource, XrdHttpExtReq &req); diff --git a/src/XrdXrootd/XrdXrootdJob.cc b/src/XrdXrootd/XrdXrootdJob.cc index 467323de5ae..f208366c545 100644 --- a/src/XrdXrootd/XrdXrootdJob.cc +++ b/src/XrdXrootd/XrdXrootdJob.cc @@ -612,7 +612,7 @@ int XrdXrootdJob::Schedule(const char *jkey, // First find if this is a duplicate or create a new one // myMutex.Lock(); - if (!(Opts & JOB_Unique) && jkey && (jp = JobTable.Find(jkey))) + if (!(Opts & JOB_Unique) && (jp = JobTable.Find(jkey))) {if (jp->Status == XrdXrootdJob2Do::Job_Done) {rc = sendResult(resp, args[0], jp); myMutex.UnLock(); diff --git a/src/XrdXrootd/XrdXrootdPrepare.cc b/src/XrdXrootd/XrdXrootdPrepare.cc index 94700936228..581c72d676c 100644 --- a/src/XrdXrootd/XrdXrootdPrepare.cc +++ b/src/XrdXrootd/XrdXrootdPrepare.cc @@ -258,14 +258,19 @@ int XrdXrootdPrepare::Open(const char *reqid, int &fsz) strcpy(path, (const char *)LogDir); strcpy(path+LogDirLen, reqid); +// Open the file and return the file descriptor +// + if ((fd = open((const char *)path, O_RDONLY)) < 0) return -errno; + // Get the file size // - if (stat((const char *)path, &buf)) return -errno; + if (fstat(fd, &buf) != 0) { + close(fd); + return -errno; + } + fsz = buf.st_size; -// Open the file and return the file descriptor -// - if ((fd = open((const char *)path, O_RDONLY)) < 0) return -errno; return fd; } diff --git a/src/XrdXrootd/XrdXrootdTpcMon.cc b/src/XrdXrootd/XrdXrootdTpcMon.cc index e95ec709795..05737dc272a 100644 --- a/src/XrdXrootd/XrdXrootdTpcMon.cc +++ b/src/XrdXrootd/XrdXrootdTpcMon.cc @@ -46,7 +46,7 @@ const char *json_fmt = "{\"TPC\":\"%s\",\"Client\":\"%s\"," "\"IPv\":%c}," "\"Src\":\"%s\",\"Dst\":\"%s\",\"Size\":%zu}"; -const char *urlFMT = ""; +const char *hostport = ""; XrdSysError eDest(0, "Ouc"); } @@ -72,8 +72,8 @@ XrdXrootdTpcMon::XrdXrootdTpcMon(const char *proto, const char *host = getenv("XRDHOST"); if (!host) host = "localhost"; const char *port = getenv("XRDPORT"); if (!port) {colon = ""; port = "";} - snprintf(buff, sizeof(buff), "%%s://%s%s%s/%%s", host, colon, port); - urlFMT = strdup(buff); + snprintf(buff, sizeof(buff), "%s%s%s", host, colon, port); + hostport = strdup(buff); } /******************************************************************************/ @@ -86,7 +86,7 @@ const char *XrdXrootdTpcMon::getURL(const char *spec, const char *prot, // Handle the spec // if (*spec == '/') - {snprintf(buff, bsz, urlFMT, prot, spec); + {snprintf(buff, bsz, "%s://%s/%s", prot, hostport, spec); spec = buff; } return spec; diff --git a/src/XrdXrootd/XrdXrootdTransit.cc b/src/XrdXrootd/XrdXrootdTransit.cc index 52d454de7c6..57720b78ac0 100644 --- a/src/XrdXrootd/XrdXrootdTransit.cc +++ b/src/XrdXrootd/XrdXrootdTransit.cc @@ -463,6 +463,11 @@ void XrdXrootdTransit::Redrive() if (rc == 0) { rc = realProt->Process(NULL); } + if (runStatus) + {AtomicBeg(runMutex); + AtomicZAP(runStatus); + AtomicEnd(runMutex); + } } while((rc == 0) && !runError && !runWait); } else rc = Send(kXR_error, ioV, 2, 0); @@ -567,7 +572,10 @@ bool XrdXrootdTransit::Run(const char *xreqP, char *xdataP, int xdataL) AtomicBeg(runMutex); rc = AtomicInc(runStatus); AtomicEnd(runMutex); - if (rc) return false; + if (rc) + {TRACEP(REQ, "Bridge request failed due to re-entry"); + return false; + } // Copy the request header // @@ -579,13 +587,17 @@ bool XrdXrootdTransit::Run(const char *xreqP, char *xdataP, int xdataL) if (Request.header.requestid & 0x8000 || Request.header.requestid > static_cast(kXR_truncate) || !reqTab[Request.header.requestid - kXR_auth]) - return Fail(kXR_Unsupported, "Unsupported bridge request"); + {TRACEP(REQ, "Unsupported bridge request"); + return Fail(kXR_Unsupported, "Unsupported bridge request"); + } // Validate the data length // Request.header.dlen = ntohl(Request.header.dlen); if (Request.header.dlen < 0) - return Fail(kXR_ArgInvalid, "Invalid request data length"); + {TRACEP(REQ, "Invalid request data length"); + return Fail(kXR_ArgInvalid, "Invalid request data length"); + } // Copy the stream id and trace this request // @@ -607,7 +619,9 @@ bool XrdXrootdTransit::Run(const char *xreqP, char *xdataP, int xdataL) if (!runArgs || movLen > runABsz) {if (runArgs) free(runArgs); if (!(runArgs = (char *)malloc(movLen))) - return Fail(kXR_NoMemory, "Insufficient memory"); + {TRACEP(REQ, "Failed to allocate memory"); + return Fail(kXR_NoMemory, "Insufficient memory"); + } runABsz = movLen; } memcpy(runArgs, xdataP, movLen); runALen = movLen; diff --git a/src/XrdXrootd/XrdXrootdXeq.cc b/src/XrdXrootd/XrdXrootdXeq.cc index ff1a4f855ac..78292614ce5 100644 --- a/src/XrdXrootd/XrdXrootdXeq.cc +++ b/src/XrdXrootd/XrdXrootdXeq.cc @@ -2504,7 +2504,7 @@ int XrdXrootdProtocol::do_ReadNone(int &retc, int &pathID) XrdXrootdFHandle fh; int ralsz = Request.header.dlen; struct read_args *rargs=(struct read_args *)(argp->buff); - struct readahead_list *ralsp = (readahead_list *)(rargs+sizeof(read_args)); + struct readahead_list *ralsp = (readahead_list *)(rargs+1); // Return the pathid // diff --git a/tests/XRootD/common.cfg b/tests/XRootD/common.cfg index b560ac0aed6..80ae82ce10c 100644 --- a/tests/XRootD/common.cfg +++ b/tests/XRootD/common.cfg @@ -21,7 +21,11 @@ ofs.trace all oss.trace all pss.trace all sec.trace all -xrd.trace all -xrootd.trace all macaroons.trace all scitokens.trace all + +# very verbose, enable only if needed +# +# xrd.trace all +# xrootd.trace all +# diff --git a/tests/XRootD/fuse.sh b/tests/XRootD/fuse.sh index 3bd33a726f4..1a6d011e099 100755 --- a/tests/XRootD/fuse.sh +++ b/tests/XRootD/fuse.sh @@ -43,7 +43,7 @@ function test_fuse() { FILES=$(seq -w 1 "${NFILES:-10}") for i in ${FILES}; do - assert openssl rand -base64 -out "${i}.ref" $((1024 * (RANDOM % 1024))) + assert openssl rand -base64 -out "${i}.ref" $((1024 * ((RANDOM % 1024) + 1))) # TODO: Fix "Resource deadlock avoided" if this sleep is removed sleep 0.1 diff --git a/tests/XRootD/http.sh b/tests/XRootD/http.sh index c3e7618d8e2..2b0ace4efb8 100755 --- a/tests/XRootD/http.sh +++ b/tests/XRootD/http.sh @@ -1,7 +1,7 @@ #!/usr/bin/env bash function setup_http() { - require_commands davix-{get,put,mkdir,rm} openssl + require_commands davix-{get,put,mkdir,rm} openssl curl openssl rand -base64 -out macaroons-secret 64 } @@ -75,5 +75,64 @@ function test_http() { assert davix-rm "${HOST}/${TMPDIR}/${i}.ref" done + # GET range-request + ## Upload a file with a fixed content string + alphabetFile="alphabet.txt" + alphabetFilePath="${TMPDIR}/$alphabetFile" + echo -n "abcdefghijklmnopqrstuvw987" > "$alphabetFilePath" + assert curl -v -L -H 'Transfer-Encoding: chunked' "${HOST}/$alphabetFilePath" --upload-file "$alphabetFilePath" + outputFilePath=${TMPDIR}/output.txt + ## Download the file to a file and sanitize the output (remove '\r') + curl -v -L --silent -H 'range: bytes=0-3,24-26' "${HOST}/$alphabetFilePath" --output - | tr -d '\r' > "$outputFilePath" + ## Check the first content range header received + contentRange=$(grep -i 'Content-range' "$outputFilePath" | awk 'NR==1') + expectedContentRange='Content-range: bytes 0-3/26' + assert_eq "$expectedContentRange" "$contentRange" "GET range-request test failed (first Content-range)" + ## Check the first body received + expectedBody='abcd' + receivedBody=$(grep -E 'abcd$' "$outputFilePath") + assert_eq "$expectedBody" "$receivedBody" "GET range-request test failed (first body)" + ## Check the second content range header received + contentRange=$(grep -i 'Content-range' "$outputFilePath"| awk 'NR==2') + expectedContentRange='Content-range: bytes 24-25/26' + assert_eq "$expectedContentRange" "$contentRange" "GET range-request test failed (second Content-range)" + ## Check the second body received + expectedBody='87' + receivedBody=$(grep -E '87' "$outputFilePath") + assert_eq "$expectedBody" "$receivedBody" "GET range-request test failed (second body)" + ## Check the amount of boundary delimiters there is in the body + expectedDelimiters=3 + receivedDelimiters=$(grep -c '\-\-123456' "$outputFilePath") + assert_eq "$expectedDelimiters" "$receivedDelimiters" "GET range-request test failed (boundary delimiters)" + ## GET with trailers + curl -v -L --raw -H "X-Transfer-Status: true" -H "TE: trailers" "${HOST}/$alphabetFilePath" --output - | tr -d '\r' > "$outputFilePath" + cat "$outputFilePath" + expectedTransferStatus='X-Transfer-Status: 200: OK' + receivedTransferStatus=$(grep -i 'X-Transfer-Status' "$outputFilePath") + assert_eq "$expectedTransferStatus" "$receivedTransferStatus" "GET request with trailers test failed (transfer status)" + # HEAD request + curl -v -I -H 'Want-Digest: adler32' "${HOST}/$alphabetFilePath" | tr -d '\r' > "$outputFilePath" + cat "$outputFilePath" + grep '200 OK' "$outputFilePath" || error "HEAD request test failed: Failed to perform HEAD request on ${HOST}/$alphabetFilePath" + expectedDigest="Digest: adler32="$(xrdadler32 "$alphabetFilePath" | cut -d' ' -f1) + receivedDigest=$(grep -i "Digest" "$outputFilePath") + assert_eq "$expectedDigest" "$receivedDigest" "HEAD request test failed (adler32)" + expectedContentLength="Content-Length: $(wc -c < "$alphabetFilePath" | sed 's/^ *//')" + # Explanation of the above line: Use wc -c for getting the size in bytes of a file, MacOS does not support stat --printf. + # In addition, remove all spaces coming from `wc -c` as MacOS adds extra spaces in front of the number returned by wc -c... + receivedContentLength=$(grep -i 'Content-Length' "$outputFilePath") + assert_eq "$expectedContentLength" "$receivedContentLength" "HEAD request test failed (Content-Length)" + + xrdcrc32c -s "$alphabetFilePath" + curl -v -I -H 'Want-Digest: crc32c' "${HOST}/$alphabetFilePath" | tr -d '\r' > "$outputFilePath" + cat "$outputFilePath" + expectedDigest="Digest: crc32c=7iTyng==" + receivedDigest=$(grep "Digest" "$outputFilePath") + assert_eq "$expectedDigest" "$receivedDigest" "HEAD request test failed (crc32c)" + curl -v -I -H 'Want-Digest: NotSupported, adler32, crc32c' "${HOST}/$alphabetFilePath" | tr -d '\r' > "$outputFilePath" + cat "$outputFilePath" + expectedDigest="Digest: adler32="$(xrdadler32 "$alphabetFilePath" | cut -d' ' -f1) + receivedDigest=$(grep -i "Digest" "$outputFilePath") + assert_eq "$expectedDigest" "$receivedDigest" "HEAD request test failed (digest not supported)" wait } diff --git a/tests/XRootD/test.sh b/tests/XRootD/test.sh index 60a402920b3..f8f6a81ad51 100755 --- a/tests/XRootD/test.sh +++ b/tests/XRootD/test.sh @@ -10,6 +10,11 @@ function assert() { echo "$@"; "$@" || error "command \"$*\" failed"; } +# $1 is expected_value $2 is received value $3 is the error message +function assert_eq() { + [[ "$1" == "$2" ]] || error "$3: expected $1 but received $2" +} + function assert_failure() { echo "$@"; "$@" && error "command \"$*\" did not fail"; } @@ -47,8 +52,8 @@ export XRD_LOGLEVEL XRD_LOGFILE # Reduce default timeouts to catch errors quickly and prevent the test # suite from getting stuck waiting for timeouts while running. -: "${XRD_REQUESTTIMEOUT:=2}" -: "${XRD_STREAMTIMEOUT:=2}" +: "${XRD_REQUESTTIMEOUT:=10}" +: "${XRD_STREAMTIMEOUT:=5}" : "${XRD_TIMEOUTRESOLUTION:=1}" export XRD_REQUESTTIMEOUT XRD_STREAMTIMEOUT XRD_TIMEOUTRESOLUTION diff --git a/tests/XrdOucTests/XrdOucUtilsTests.cc b/tests/XrdOucTests/XrdOucUtilsTests.cc index cdce9ac2303..3deafc95e58 100644 --- a/tests/XrdOucTests/XrdOucUtilsTests.cc +++ b/tests/XrdOucTests/XrdOucUtilsTests.cc @@ -1,46 +1,247 @@ #undef NDEBUG -#include -#include -#include - #include "XrdOuc/XrdOucUtils.hh" - #include "XrdOuc/XrdOucTUtils.hh" #include "XrdOuc/XrdOucPrivateUtils.hh" +#include +#include + +#include + +class XrdOucUtilsTests : public ::testing::Test {}; + +/* String we replace token values with */ +static const std::string redacted = "REDACTED"; + +/* + * These checks are meant to ensure tokens as described in sections below are + * not leaked into the output of either the server or the client in log lines. + * + * Access Token Types: https://datatracker.ietf.org/doc/html/rfc6749#section-7.1 + * Authorization Header: https://datatracker.ietf.org/doc/html/rfc6750#section-2.1 + * + */ + +static const std::string token_prefixes[] = { + "", + "Bearer", + "Bearer ", + "Bearer%20", + "Bearertoken", + "Bearertoken ", + "Bearer token", + "Bearer token ", + "Bearer%20token", + "Bearer%20token%20", +}; + +static const std::string tokens[] = { + /* short tokens */ + "my_secret_token", + "my.secret.token/with~special+chars==", + + /* macaroon */ + "MDAxY2xvY2F0aW9uIE9wdGlvbmFsLmVtcHR5CjAwMThpZGVudGlmaWVyIGh" + "sQ0kremlRCjAwMTVjaWQgaWlkOnBGTTA1MnJTCjAwMjFjaWQgaWQ6MjAwMj" + "sxMDAxLDIwMDIsMDtwzXVsCjAwMjhjaWQgYmVmb3JlOjIwMTktMDQtMTdUM" + "Dk6NTE6MjIuODQwWgowMDE5Y2lkIGhvbWU6L1VzZXJzL3BhdWwKMDAyZnNp" + "Z25hdHVyZSCT6Lea6oBIEpiF2KOsZ1FQvLeoXve_a3q38TZTBWhM1Qo", + + /* eos token */ + "zteos64:MDAwMDAyMGN4nON6z8jFXFReIbBj16edbBqMRmL6qfnF-snJiWlplfoZJSUF8SWpxSX6F" + "oxeKqlmhiapqWZGuonGpkm6hoapaboW5iaWummJhmbGqaamKZaJqUHzGaPdijIV_PLLFAxNgcjK0M" + "TK0EzByMDIJFahNDPFyiC6KD-_JFYhHYldkpmSmldiBeLoGRuYmBobW1iZGJs65OQnJ-Zk5BeXKOQ" + "l5qaC5RVS8qwUCoryS6xK8zIrFBILCqwUQCqsEGpT8nMTM_MgAhC2QnpqvpVCcWlKvpWhkIKUmL3V" + "4wPOwTNXqXcybNGTYjp9eOrjQr", + + /* demo scitoken */ + "eyJhbGciOiJSUzI1NiIsImtpZCI6ImtleS1yczI1NiIsInR5cCI6IkpXVCJ9.eyJ2ZXIiOiJzY2l0" + "b2tlbjoyLjAiLCJhdWQiOiJodHRwczovL2RlbW8uc2NpdG9rZW5zLm9yZyIsImlzcyI6Imh0dHBzO" + "i8vZGVtby5zY2l0b2tlbnMub3JnIiwiZXhwIjoxNzMwODk3NTU1LCJpYXQiOjE3MzA4OTY5NTUsIm" + "5iZiI6MTczMDg5Njk1NSwianRpIjoiYzUxOTM0OWEtMzRlMi00MTg2LTljMTMtNDU3Njk1ZjQwNTk" + "3In0.q0aLuqK8BpI7FqPw7VJYym2B3SLyYiU_7xH_y_dD-jmdOUuH8pySgvsCzlrKcqgVY6-E8ggq" + "fM09HqAMJCe5MRiOpZj34D8zSU3kgTC8bh9fjy6sYgTwnmzkCGXO5xdf_H7Xw1VO2eVOPJUHtsmc7" + "pa6_geLmHiJvSthKgd9XceRyQ5R8q9T5E03LsAmks4rhTC1dJaCGB2EUguKxXhos2dBk09MhPQOB7" + "jvQKFPXu9tdJb7eWNMPETxnWTJF7kn5zKIs1by2bcHtpdEpOIQ3qfGZhThzUeZ9NZC0FXsyKhoKoJ" + "EAkevGtNbs72NqZr3scxVUj_zHK6QIWe2UI7dKg", + + /* malicious "tokens" */ + std::string(65536, 'X'), + std::string(65536, '.'), +}; + +static const std::string plain_urls[] = { + /* empty URL */ + "", + + /* some realistic URLs */ + "root://eos.cern.ch//eos/", + "https://my.cdash.org/index.php?project=XRootD", + "https://gcc.gnu.org/bugzilla/show_bug.cgi?id=86164", + "https://zoom.us/j/6215903872?pwd=MzErQXJNXXXXX.RsS2VLSVgzVmtrdz09&omn=62242940660#success", + "https://p0@F4HP7QL65F.local:61631//first/namespace/token_gen/test1171569942?&timeout=9.5s", + "root://localhost:10940//data/cb4aacf1-6f28-42f2-b68a-90a73460f424.dat?xrdcl.requuid=26dab270-6d8a-43b1-8ebc-befb372c0d60", + + /* malicious "URLs" */ + std::string(65536, 'A'), + std::string(65536, '.'), + std::string(65536, '&'), + std::string(65536, ' '), +}; + +static const std::string authz_strings[] = { + "authz=REDACTED", + " authz=REDACTED ", + " 'authz=REDACTED' ", + " \"authz=REDACTED\" ", + "authz=REDACTED&scitag.flow=144&test=abcd", + "scitag.flow=144&authz=REDACTED&test=abcd", + "scitag.flow=144&test=abcd&authz=REDACTED", + "authz=REDACTED&test=test2&authz=REDACTED", + "authz=REDACTED&test=test2&authz=REDACTED&authz=REDACTED&test=test2&authz=REDACTED", + "/path/test.txt?scitag.flow=44&authz=REDACTED done close.", + "/path/test.txt?authz=REDACTED&scitag.flow=44 done close.", + "(message: kXR_stat (path: /tmp/xrootd/public/foo?authz=REDACTED&pelican.timeout=3s, flags: none) ).", + "(message: kXR_stat (path: /tmp/xrootd/public/foo?pelican.timeout=3s&authz=REDACTED, flags: none) ).", + "Appended header field to opaque info: 'authz=REDACTED'", + "Processing source entry: /etc/passwd, target file: root://localhost:1094//tmp/passwd?authz=REDACTED", + "240919 08:11:07 20995 unknown.3:33@[::1] Pss_Stat: url=pelican://p0@F4HP7QL65F.local:" /* no comma! */ + "61631//first/namespace/token_gen/test1171569942?&authz=REDACTED&pelican.timeout=9.5s" +}; + +static const std::string authz_headers[] = { + "authorization:REDACTED", + "authorization :REDACTED", + "authorization : REDACTED", + "Authorization:REDACTED", + "Authorization: REDACTED", + "Authorization :REDACTED", + "Authorization : REDACTED", + "transferHeaderauthorization: REDACTED", + "transferHeaderauthorization :REDACTED", + "transferHeaderauthorization : REDACTED", + "TransferHeaderAuthorization: REDACTED", + "TransferHeaderAuthorization :REDACTED", + "TransferHeaderAuthorization : REDACTED", + "WWW-Authenticate: REDACTED", + "Proxy-Authenticate: REDACTED", + "WWW-Authenticate : REDACTED", + "Proxy-Authenticate : REDACTED", +}; + +/* Check that plain URLs not containing a token remain intact */ + +TEST(XrdOucUtilsTests, RedactToken_PlainURLs) +{ + for (std::string str : plain_urls) + ASSERT_EQ(str, obfuscateAuth(str)); +} + +/* Check URLs with an empty token as a special case. This is needed + * because in the case an empty token is provided with prefix "Bearer ", + * that is, containing a space at the end, a word from the actual output + * will be redacted as if it were the value of the token. + * + * Example: + * "/test.txt?scitag.flow=44&authz=Bearer done close." + * Becomes: + * "/test.txt?scitag.flow=44&authz=REDACTED close." + * + * In this special case, whenever the prefix ends with a space, we check + * only that the word "REDACTED" appears in the output. + */ + +TEST(XrdOucUtilsTests, RedactToken_AuthzCGI_EmptyToken) +{ + for (std::string authz : authz_strings) { + for (std::string prefix : token_prefixes) { + std::string str = authz; + + size_t pos = 0; + while ((pos = str.find(redacted, pos)) != std::string::npos) + str = str.replace(pos, redacted.size(), prefix); + + std::string obfuscated_str = obfuscateAuth(str); + + /* Assert that we do find the word "REDACTED" in the output */ + ASSERT_TRUE(obfuscated_str.find(redacted) != std::string::npos); + + /* Skip input/output equality check since when prefix ends with a + * space, or input contains "REDACTED " with a space, an extra word + * will be consumed as if it were the token value. */ + } + } +} + +TEST(XrdOucUtilsTests, RedactToken_AuthzCGI_ValidToken) +{ + size_t pos = 0; + for (std::string authz : authz_strings) { + for (std::string prefix : token_prefixes) { + for (std::string token : tokens) { + std::string str = authz; + + pos = 0; + /* Replace all "REDACTED" strings with a token value in the test string */ + while ((pos = str.find(redacted, pos)) != std::string::npos) + str = str.replace(pos, redacted.size(), prefix + token); + + /* Call obfuscateAuth(str) to redact token values */ + std::string obfuscated_str = obfuscateAuth(str); + + pos = 0; + /* Replace all token values back with "REDACTED" in the test string */ + while ((pos = str.find(token, pos)) != std::string::npos) + str = str.replace(pos, token.size(), redacted); -using namespace testing; - -// duplicated here to avoid becoming a public symbol of XrdUtils -static const std::string OBFUSCATION_STR = "REDACTED"; - -class XrdOucUtilsTests : public Test {}; - -TEST(XrdOucUtilsTests, obfuscateAuth) { - // General cases - ASSERT_EQ(std::string("scitag.flow=144&authz=") + OBFUSCATION_STR + std::string("&test=abcd"), obfuscateAuth("scitag.flow=144&authz=token&test=abcd")); - ASSERT_EQ(std::string("authz=") + OBFUSCATION_STR + std::string("&scitag.flow=144&test=abcd"), obfuscateAuth("authz=token&scitag.flow=144&test=abcd")); - ASSERT_EQ(std::string("scitag.flow=144&test=abcd&authz=") + OBFUSCATION_STR, obfuscateAuth("scitag.flow=144&test=abcd&authz=token")); - // Nothing to obfuscate - ASSERT_EQ("test=abcd&test2=abcde",obfuscateAuth("test=abcd&test2=abcde")); - ASSERT_EQ("nothingtoobfuscate",obfuscateAuth("nothingtoobfuscate")); - //Empty string obfuscation - ASSERT_EQ("",obfuscateAuth("")); - //2 authz to obfuscate - ASSERT_EQ(std::string("authz=") + OBFUSCATION_STR + std::string("&test=test2&authz=") + OBFUSCATION_STR,obfuscateAuth("authz=abcd&test=test2&authz=abcdef")); - // Trimmed key obfuscation - ASSERT_EQ(std::string("Authorization: ") + OBFUSCATION_STR, obfuscateAuth("Authorization: Bearer token")); - ASSERT_EQ(std::string("Authorization :") + OBFUSCATION_STR, obfuscateAuth("Authorization :Bearer token")); - ASSERT_EQ(std::string("authorization :") + OBFUSCATION_STR, obfuscateAuth("authorization :Bearer token")); - ASSERT_EQ(std::string("transferHeaderauthorization :") + OBFUSCATION_STR, obfuscateAuth("transferHeaderauthorization :Bearer token")); - // Different obfuscation - ASSERT_EQ(std::string("(message: kXR_stat (path: /tmp/xrootd/public/foo?authz=") + OBFUSCATION_STR + std::string("&pelican.timeout=3s, flags: none) )."), obfuscateAuth("(message: kXR_stat (path: /tmp/xrootd/public/foo?authz=foo1234&pelican.timeout=3s, flags: none) ).")); - ASSERT_EQ(std::string("(message: kXR_stat (path: /tmp/xrootd/public/foo?pelican.timeout=3s&authz=") + OBFUSCATION_STR + std::string(", flags: none) )."), obfuscateAuth("(message: kXR_stat (path: /tmp/xrootd/public/foo?pelican.timeout=3s&authz=foo1234, flags: none) ).")); - ASSERT_EQ(std::string("/path/test.txt?scitag.flow=44&authz=") + OBFUSCATION_STR + std::string(" done close."),obfuscateAuth("/path/test.txt?scitag.flow=44&authz=abcdef done close.")); - ASSERT_EQ(std::string("Appended header field to opaque info: 'authz=") + OBFUSCATION_STR, obfuscateAuth("Appended header field to opaque info: 'authz=Bearer abcdef'")); - ASSERT_EQ(std::string("Appended header fields to opaque info: 'authz=") + OBFUSCATION_STR + std::string("&scitag.flow=65'"), obfuscateAuth("Appended header fields to opaque info: 'authz=Bearer token&scitag.flow=65'")); - ASSERT_EQ(std::string("Processing source entry: /etc/passwd, type local file, target file: root://localhost:1094//tmp/passwd?authz=") + OBFUSCATION_STR, obfuscateAuth("Processing source entry: /etc/passwd, type local file, target file: root://localhost:1094//tmp/passwd?authz=testabcd")); + /* Assert that we do not find the token value in the output */ + ASSERT_TRUE(obfuscated_str.find(token) == std::string::npos) + << "\ntoken = '" << token << "'\n str = '" << obfuscated_str << "'" << std::endl; + + /* Assert that we do find the word "REDACTED" in the output */ + ASSERT_TRUE(obfuscated_str.find(redacted) != std::string::npos); + + /* Assert that we get back the original string after redaction */ + ASSERT_EQ(str, obfuscated_str); + } + } + } +} + +TEST(XrdOucUtilsTests, RedactToken_AuthHeader) +{ + size_t pos = 0; + for (std::string header : authz_headers) { + for (std::string prefix : token_prefixes) { + for (std::string token : tokens) { + std::string str = header; + + pos = 0; + /* replace all "REDACTED" strings with a token value in the test string */ + while ((pos = str.find(redacted, pos)) != std::string::npos) + str = str.replace(pos, redacted.size(), prefix + token); + + /* Call obfuscateAuth(str) to redact token values */ + std::string obfuscated_str = obfuscateAuth(str); + + pos = 0; + /* Replace all token values back with "REDACTED" in the test string */ + while ((pos = str.find(token, pos)) != std::string::npos) + str = str.replace(pos, token.size(), redacted); + + /* Assert that we do not find the token value in the output */ + ASSERT_TRUE(obfuscated_str.find(token) == std::string::npos) + << "\ntoken = '" << token << "'\n str = '" << obfuscated_str << "'" << std::endl; + + /* Assert that we do find the word "REDACTED" in the output */ + ASSERT_TRUE(obfuscated_str.find(redacted) != std::string::npos); + + /* Assert that we get back the original string after redaction */ + ASSERT_EQ(str, obfuscated_str); + } + } + } } TEST(XrdOucUtilsTests, caseInsensitiveFind) { diff --git a/xrootd.spec b/xrootd.spec index 74563b5e508..5530ffba8b4 100644 --- a/xrootd.spec +++ b/xrootd.spec @@ -25,7 +25,7 @@ License: LGPL-3.0-or-later AND BSD-2-Clause AND BSD-3-Clause AND curl AND MIT AN URL: https://xrootd.slac.stanford.edu %if !%{with git} -Version: 5.7.1 +Version: 5.7.2 Source0: https://xrootd.web.cern.ch/download/v%{version}/%{name}-%{version}.tar.gz %else %define git_version %(tar xzf %{_sourcedir}/%{name}.tar.gz -O xrootd/VERSION) @@ -948,6 +948,9 @@ fi %changelog +* Wed Nov 27 2024 Guilherme Amadio - 1:5.7.2-1 +- XRootD 5.7.2 + * Mon Sep 02 2024 Guilherme Amadio - 1:5.7.1-1 - XRootD 5.7.1