diff --git a/.circleci/config.yml b/.circleci/config.yml index 4b142b59..0132f2f5 100644 --- a/.circleci/config.yml +++ b/.circleci/config.yml @@ -20,9 +20,8 @@ executors: - image: circleci/ruby:2.4 jobs: - build-test: + build-test-22: executor: python-executor - parallelism: 1 steps: - checkout - setup_remote_docker @@ -39,8 +38,104 @@ jobs: /usr/local/bin/cpplint --filter=-whitespace/line_length src/* true - run: - name: Build the image - command: bash scripts/docker-outer.sh + name: Build the packages + command: BUILD_VERSIONS=22 bash scripts/docker-outer.sh + - *persist_to_workspace + + build-test-28: + executor: python-executor + steps: + - checkout + - setup_remote_docker + - run: + name: Install cpplint + command: sudo pip install cpplint + - run: + name: Set up version + command: bash scripts/version.sh + - run: + name: Call cpplint; expected to fail, so set things up to pass + command: | + set +eo pipefail + /usr/local/bin/cpplint --filter=-whitespace/line_length src/* + true + - run: + name: Build the packages + command: BUILD_VERSIONS=28 bash scripts/docker-outer.sh + - *persist_to_workspace + + build-test-22-devel: + executor: python-executor + steps: + - checkout + - setup_remote_docker + - add_ssh_keys: + fingerprints: + - "17:da:1d:21:58:46:74:fc:38:4a:62:2a:32:79:1d:ab" + - run: + name: Install cpplint + command: sudo pip install cpplint + - run: + name: Set up version + command: bash scripts/version.sh + - run: + name: Call cpplint; expected to fail, so set things up to pass + command: | + set +eo pipefail + /usr/local/bin/cpplint --filter=-whitespace/line_length src/* + true + - run: + name: Build the packages + command: BUILD_VERSIONS=22 DEVEL=-devel bash scripts/docker-outer.sh + - run: + name: git config + command: | + git config --global user.email "$CIRCLE_USERNAME@users.noreply.github.com" + git config --global user.name "$CIRCLE_USERNAME" + - run: + name: trigger integration + command: | + git clone git@github.com:pantheon-systems/fusedav-kube + cd fusedav-kube + git tag f22-${CIRCLE_BUILD_NUM}-devel + git push origin f22-${CIRCLE_BUILD_NUM}-devel + - *persist_to_workspace + + build-test-28-devel: + executor: python-executor + steps: + - checkout + - setup_remote_docker + - add_ssh_keys: + fingerprints: + - "17:da:1d:21:58:46:74:fc:38:4a:62:2a:32:79:1d:ab" + - run: + name: Install cpplint + command: sudo pip install cpplint + - run: + name: Set up version + command: bash scripts/version.sh + - run: + name: Call cpplint; expected to fail, so set things up to pass + command: | + set +eo pipefail + /usr/local/bin/cpplint --filter=-whitespace/line_length src/* + true + - run: + name: Build the packages + command: BUILD_VERSIONS=28 DEVEL=-devel bash scripts/docker-outer.sh + - run: + name: git config + command: | + git config --global user.email "$CIRCLE_USERNAME@users.noreply.github.com" + git config --global user.name "$CIRCLE_USERNAME" + - run: + name: trigger integration + command: | + git clone git@github.com:pantheon-systems/fusedav-kube + cd fusedav-kube + git tag f28-${CIRCLE_BUILD_NUM}-devel-${CIRCLE_PULL_REQUEST##*/} + git push origin f28-${CIRCLE_BUILD_NUM}-devel-${CIRCLE_PULL_REQUEST##*/} - *persist_to_workspace deploy-dev: @@ -71,10 +166,28 @@ workflows: version: 2 build-test-deploy: jobs: - - build-test + - build-test-22 + - build-test-28 + - build-test-22-devel: + filters: + branches: + ignore: + - dev + - yolo + - stage + - master + - build-test-28-devel: + filters: + branches: + ignore: + - dev + - yolo + - stage + - master - deploy-dev: requires: - - build-test + - build-test-22 + - build-test-28 filters: branches: only: @@ -83,7 +196,8 @@ workflows: - stage - deploy-prod: requires: - - build-test + - build-test-22 + - build-test-28 filters: branches: only: diff --git a/Dockerfile b/Dockerfile new file mode 100644 index 00000000..aced9af1 --- /dev/null +++ b/Dockerfile @@ -0,0 +1,8 @@ +ARG VERSION + +FROM quay.io/getpantheon/fedora:${VERSION} + +COPY pkg/fusedav /opt/fusedav +RUN dnf install -y /opt/fusedav/*.rpm make perf valgrind gdb \ + && rm -r /opt/fusedav \ + && dnf clean all diff --git a/scripts/docker-inner.sh b/scripts/docker-inner.sh index 3a9d147c..90044013 100755 --- a/scripts/docker-inner.sh +++ b/scripts/docker-inner.sh @@ -1,4 +1,4 @@ -#!/bin/sh +#!/bin/bash # # set -ex @@ -14,6 +14,11 @@ rpm_dir=$2 build=$3 epoch=$4 +devel= +if [[ "$fusedav_channel" == *-devel ]]; then + devel=true +fi + fedora_release=$(rpm -q --queryformat '%{VERSION}\n' fedora-release) GITSHA=$(git log -1 --format="%h") name="fusedav-$fusedav_channel" @@ -44,6 +49,13 @@ if [[ -d "/curl-7.46.0" ]]; then fi ./autogen.sh +SANITIZER_FLAGS= +if [[ -n $devel ]] && [[ $fusedav_channel == *f28* ]]; then + SANITIZER_FLAGS="-fsanitize=address -fsanitize=undefined -fno-omit-frame-pointer -g" + yum install -y libasan libubsan + export 'LSAN_OPTIONS=verbosity=1:log_threads=1' +fi +export SANITIZER_FLAGS CURL_LIBS="-lcurl" ./configure make @@ -64,10 +76,31 @@ if [ "1" != "$?" ] ; then fi set -e +# pack in sources and tests into the rpm +if [[ -n $devel ]]; then + cp -r -t $install_prefix src tests + + iozone_version=iozone3_487 + curl http://www.iozone.org/src/current/${iozone_version}.tar > ${iozone_version}.tar + sha256sum -c sha256sum + + tar xf ${iozone_version}.tar + + pushd 2>&1 ${iozone_version}/src/current > /dev/null + make linux-AMD64 + mv iozone $install_prefix/iozone + popd 2>&1 > /dev/null +fi + mv /usr/local/bin/fusedav $install_prefix/$name cp $bin/exec_wrapper/mount.fusedav_chan /usr/sbin/mount.$name chmod 755 /usr/sbin/mount.$name +DEP_DEVEL= +if [[ -n $devel ]]; then + DEP_DEVEL="--depends gcc --depends libasan --depends libubsan" +fi + fpm -s dir -t rpm \ --name "${name}" \ --version "${version}" \ @@ -76,9 +109,11 @@ fpm -s dir -t rpm \ --url "${url}" \ --vendor "${vendor}" \ --description "${description}" \ - --depends uriparser \ + --depends uriparser \ --depends fuse-libs \ --depends leveldb \ + --depends jemalloc \ + ${DEP_DEVEL} \ --log=debug \ $install_prefix \ /usr/sbin/mount.$name diff --git a/scripts/docker-outer.sh b/scripts/docker-outer.sh index 80342b7f..56823f16 100755 --- a/scripts/docker-outer.sh +++ b/scripts/docker-outer.sh @@ -1,4 +1,4 @@ -#!/bin/sh +#!/bin/bash set -e bin="$(cd -P -- "$(dirname -- "$0")" && pwd -P)" docker=$(which docker) @@ -13,6 +13,8 @@ RUN_ARGS="--rm" # set a default build -> 0 for when it doesn't exist CIRCLE_BUILD_NUM=${CIRCLE_BUILD_NUM:-0} +DEVEL=${DEVEL:-} + # location to mount the source in the container inner_mount="/fusedav" @@ -21,6 +23,8 @@ $docker volume create fusedav_vol $docker run --name cp-vol -v fusedav_vol:/fusedav busybox true $docker cp $bin/../. cp-vol:/fusedav/ +docker login -p "$QUAY_PASSWD" -u "$QUAY_USER" quay.io + # epoch to use for -revision epoch=$(date +%s) @@ -31,7 +35,7 @@ for ver in $BUILD_VERSIONS; do $docker pull $build_image channel=$(tr -d "\n\r" < $bin/../CHANNEL) - exec_cmd="$inner_mount/scripts/docker-inner.sh $channel $inner_mount/pkg $CIRCLE_BUILD_NUM $epoch" + exec_cmd="$inner_mount/scripts/docker-inner.sh $channel$DEVEL $inner_mount/pkg $CIRCLE_BUILD_NUM $epoch" if [ -n "$BUILD_DEBUG" ] ; then RUN_ARGS="$RUN_ARGS -ti " exec_cmd="/bin/bash" @@ -48,8 +52,21 @@ EOL echo "Running: $docker_cmd" $docker_cmd + echo "copying the rpm from the container..." + mkdir -p "$bin/../pkg" + $docker cp "cp-vol:/fusedav/pkg/${ver}/fusedav" "$bin/../pkg/fusedav" + docker_tag="quay.io/getpantheon/fusedav:f${ver}-${CIRCLE_BUILD_NUM}${DEVEL}" + docker_build="$docker build -t $docker_tag --build-arg VERSION=${ver} ." + + echo "Running: $docker_build" + $docker_build + + docker_push="$docker push $docker_tag" + + echo "Running: $docker_push" + $docker_push + done -$docker cp cp-vol:/fusedav/pkg $bin/../pkg/ $docker rm cp-vol $docker volume rm fusedav_vol diff --git a/sha256sum b/sha256sum new file mode 100644 index 00000000..95e4583e --- /dev/null +++ b/sha256sum @@ -0,0 +1 @@ +2c488a7ccddd624fd557af16e71442c367b131d6178e1b4023bbd532bacdda59 iozone3_487.tar diff --git a/src/Makefile.am b/src/Makefile.am index 74761abd..70e185ce 100644 --- a/src/Makefile.am +++ b/src/Makefile.am @@ -30,5 +30,5 @@ fusedav_SOURCES=fusedav.c fusedav.h \ stats.c stats.h \ fusedav-statsd.c fusedav-statsd.h -fusedav_CFLAGS = $(AM_CFLAGS) $(CURL_CFLAGS) $(URIPARSER_CFLAGS) $(FUSE_CFLAGS) $(YAML_CFLAGS) $(LEVELDB_CFLAGS) $(SYSTEMD_CFLAGS) $(ZLIB_CFLAGS) $(GLIB_CFLAGS) -DFUSE_USE_VERSION=26 -DINJECT_ERRORS=${INJECT_ERRORS} +fusedav_CFLAGS = $(AM_CFLAGS) $(CURL_CFLAGS) $(URIPARSER_CFLAGS) $(FUSE_CFLAGS) $(YAML_CFLAGS) $(LEVELDB_CFLAGS) $(SYSTEMD_CFLAGS) $(ZLIB_CFLAGS) $(GLIB_CFLAGS) -DFUSE_USE_VERSION=26 -DINJECT_ERRORS=${INJECT_ERRORS} $(SANITIZER_FLAGS) fusedav_LDADD = -lpthread -ljemalloc -lrt -lresolv -lexpat $(CURL_LIBS) $(URIPARSER_LIBS) $(FUSE_LIBS) $(YAML_LIBS) $(LEVELDB_LIBS) $(SYSTEMD_LIBS) $(ZLIB_LIBS) $(GLIB_LIBS) diff --git a/src/filecache.c b/src/filecache.c index 2dd1bd1e..032ab907 100644 --- a/src/filecache.c +++ b/src/filecache.c @@ -42,6 +42,9 @@ #include "fusedav-statsd.h" #define CACHE_FILE_ENTROPY 20 +#define FILECACHE_INVALIDATED 1 +#define FILECACHE_ENTRY_TTL 2 +#define FILECACHE_PARENT_UPDATE_GRACE 2 // Keeping track of file sizes processed #define XLG 100 * 1024 * 1024 @@ -50,32 +53,42 @@ #define SM 100 * 1024 #define XSM 10 * 1024 +// @TODO Where to find ETAG_MAX? +#define ETAG_MAX 256 + // Entries for stat and file cache are in the ldb cache; fc: designates filecache entries static const char * filecache_prefix = "fc:"; // Name of forensic haven directory static const char * forensic_haven_dir = "forensic-haven"; +// Persistent data stored in leveldb +typedef struct filecache_http_get_response { + long status_code; + char etag[ETAG_MAX + 1]; + CURLcode res; + int fd; + char filename[PATH_MAX]; +} fc_http_get_response; + +// Persistent data stored in leveldb +typedef struct filecache_pdata { + char filename[PATH_MAX]; + char etag[ETAG_MAX + 1]; + time_t last_server_update; +} fc_pdata; typedef int fd_t; // Session data -struct filecache_sdata { +typedef struct filecache_sdata { fd_t fd; // LOCK_SH for write/truncation; LOCK_EX during PUT bool readable; bool writable; bool modified; int error_code; -}; - -// @TODO Where to find ETAG_MAX? -#define ETAG_MAX 256 - -// Persistent data stored in leveldb -struct filecache_pdata { - char filename[PATH_MAX]; - char etag[ETAG_MAX + 1]; - time_t last_server_update; -}; + filecache_t *cache; + char *cache_path; +} fc_sdata; // GError mechanisms static G_DEFINE_QUARK(FC, filecache) @@ -185,7 +198,7 @@ static void new_cache_file(const char *cache_path, char *cache_file_path, fd_t * // adds an entry to the ldb cache static void filecache_pdata_set(filecache_t *cache, const char *path, - const struct filecache_pdata *pdata, GError **gerr) { + const fc_pdata *pdata, GError **gerr) { leveldb_writeoptions_t *options; char *ldberr = NULL; char *key; @@ -202,7 +215,7 @@ static void filecache_pdata_set(filecache_t *cache, const char *path, key = path2key(path); options = leveldb_writeoptions_create(); - leveldb_put(cache, options, key, strlen(key) + 1, (const char *) pdata, sizeof(struct filecache_pdata), &ldberr); + leveldb_put(cache, options, key, strlen(key) + 1, (const char *) pdata, sizeof(fc_pdata), &ldberr); leveldb_writeoptions_destroy(options); free(key); @@ -218,19 +231,20 @@ static void filecache_pdata_set(filecache_t *cache, const char *path, } // Create a new file to write into and set values -static void create_file(struct filecache_sdata *sdata, const char *cache_path, +static void create_file(fc_sdata *sdata, const char *cache_path, filecache_t *cache, const char *path, GError **gerr) { - struct filecache_pdata *pdata; + fc_pdata *pdata; GError *tmpgerr = NULL; + const char *funcname = "create_file"; BUMP(filecache_create_file); - log_print(LOG_INFO, SECTION_FILECACHE_OPEN, "create_file: on %s", path); + log_print(LOG_INFO, SECTION_FILECACHE_OPEN, "%s: on %s", funcname, path); - pdata = calloc(1, sizeof(struct filecache_pdata)); + pdata = calloc(1, sizeof(fc_pdata)); if (pdata == NULL || inject_error(filecache_error_createcalloc)) { - g_set_error(gerr, system_quark(), errno, "create_file: calloc returns NULL for pdata"); + g_set_error(gerr, system_quark(), errno, "%s: calloc returns NULL for pdata", funcname); free(pdata); // If we get here via inject_error, pdata might in fact have been allocated return; } @@ -239,17 +253,17 @@ static void create_file(struct filecache_sdata *sdata, const char *cache_path, sdata->writable = true; new_cache_file(cache_path, pdata->filename, &sdata->fd, &tmpgerr); if (tmpgerr) { - g_propagate_prefixed_error(gerr, tmpgerr, "create_file: "); + g_propagate_prefixed_error(gerr, tmpgerr, "%s: ", funcname); goto finish; } // The local copy currently trumps the server one, no matter how old. pdata->last_server_update = 0; - log_print(LOG_DEBUG, SECTION_FILECACHE_OPEN, "create_file: Updating file cache for %d : %s : %s : timestamp %lu.", sdata->fd, path, pdata->filename, pdata->last_server_update); + log_print(LOG_DEBUG, SECTION_FILECACHE_OPEN, "%s: Updating file cache for %d : %s : %s : timestamp %lu.", funcname, sdata->fd, path, pdata->filename, pdata->last_server_update); filecache_pdata_set(cache, path, pdata, &tmpgerr); if (tmpgerr) { - g_propagate_prefixed_error(gerr, tmpgerr, "create_file: "); + g_propagate_prefixed_error(gerr, tmpgerr, "%s: ", funcname); goto finish; } @@ -261,8 +275,8 @@ static void create_file(struct filecache_sdata *sdata, const char *cache_path, } // get an entry from the ldb cache -static struct filecache_pdata *filecache_pdata_get(filecache_t *cache, const char *path, GError **gerr) { - struct filecache_pdata *pdata = NULL; +static fc_pdata *filecache_pdata_get(filecache_t *cache, const char *path, GError **gerr) { + fc_pdata *pdata = NULL; char *key; leveldb_readoptions_t *options; size_t vallen; @@ -276,7 +290,7 @@ static struct filecache_pdata *filecache_pdata_get(filecache_t *cache, const cha options = leveldb_readoptions_create(); leveldb_readoptions_set_fill_cache(options, false); - pdata = (struct filecache_pdata *) leveldb_get(cache, options, key, strlen(key) + 1, &vallen, &ldberr); + pdata = (fc_pdata *) leveldb_get(cache, options, key, strlen(key) + 1, &vallen, &ldberr); leveldb_readoptions_destroy(options); free(key); @@ -292,8 +306,8 @@ static struct filecache_pdata *filecache_pdata_get(filecache_t *cache, const cha return NULL; } - if (vallen != sizeof(struct filecache_pdata) || inject_error(filecache_error_getvallen)) { - g_set_error(gerr, leveldb_quark(), E_FC_LDBERR, "Length %lu is not expected length %lu.", vallen, sizeof(struct filecache_pdata)); + if (vallen != sizeof(fc_pdata) || inject_error(filecache_error_getvallen)) { + g_set_error(gerr, leveldb_quark(), E_FC_LDBERR, "Length %lu is not expected length %lu.", vallen, sizeof(fc_pdata)); free(pdata); return NULL; } @@ -309,30 +323,28 @@ static size_t capture_etag(void *ptr, size_t size, size_t nmemb, void *userdata) char *header = (char *) ptr; char *etag = (char *) userdata; // Allocated to ETAG_MAX length. char *value; + size_t value_len = 0; + strcpy(etag, ""); + if (strncasecmp(header, "ETag", 4) != 0) { + return real_size; + } value = strstr(header, ":"); - - if (value == NULL) - goto finish; - + if (value == NULL) { + return real_size; + } // Skip the colon and whitespace. ++value; - while(isspace(value[0])) + while(isspace(value[0])) { ++value; - - // Is it an ETag? If so, store it. - if (strncasecmp(header, "ETag", 4) == 0) { - size_t value_len = strlen(value); - - // If the ETag is too long, bail. - if (value_len > ETAG_MAX) - goto finish; - - strncpy(etag, value, value_len); - etag[value_len - 1] = '\0'; } - -finish: + value_len = strlen(value); + // If the ETag is too long, bail. + if (value_len > ETAG_MAX) { + return real_size; + } + strncpy(etag, value, value_len); + etag[value_len - 1] = '\0'; return real_size; } @@ -347,487 +359,439 @@ static size_t write_response_to_fd(void *ptr, size_t size, size_t nmemb, void *u return real_size; } -// Get a file descriptor pointing to the latest full copy of the file. -static void get_fresh_fd(filecache_t *cache, - const char *cache_path, const char *path, struct filecache_sdata *sdata, - struct filecache_pdata **pdatap, int flags, bool use_local_copy, bool rw, GError **gerr) { - static const char *funcname = "get_fresh_fd"; +static time_t get_parent_updated_children_time(filecache_t *cache, const char *path, GError **gerr) { + const char* funcname = "get_parent_updated_children_time"; + time_t parent_children_update_ts; + char *parent_path; GError *tmpgerr = NULL; - struct filecache_pdata *pdata; - char etag[ETAG_MAX]; - char response_filename[PATH_MAX] = "\0"; - int response_fd = -1; - bool close_response_fd = true; - struct timespec start_time; - long response_code = 500; // seed it as bad so we can enter the loop - CURLcode res = CURLE_OK; - // Not to exceed time for operation, else it's an error. Allow large files a longer time - // Somewhat arbitrary - static const unsigned small_time_allotment = 2000; // 2 seconds - static const unsigned large_time_allotment = 8000; // 8 seconds - - BUMP(filecache_fresh_fd); - - clock_gettime(CLOCK_MONOTONIC, &start_time); - assert(pdatap); - pdata = *pdatap; - - if (pdata != NULL) { - log_print(LOG_DEBUG, SECTION_FILECACHE_OPEN, "%s: file found in cache: %s::%s", funcname, path, pdata->filename); + parent_path = path_parent(path); + if (parent_path == NULL) { + g_set_error(&tmpgerr, filecache_quark(), EEXIST, "could not get parent path"); + g_propagate_prefixed_error(gerr, tmpgerr, "%s: ", funcname); + return parent_children_update_ts; } - // Do we need to go out to the server, or just serve from the file cache - // We should have guaranteed that if O_TRUNC is specified and pdata is NULL we don't get here. - // For O_TRUNC, we just want to open a truncated cache file and not bother getting a copy from - // the server. - // If not O_TRUNC, but the cache file is fresh, just reuse it without going to the server. - // If the file is in-use (last_server_update = 0) we use the local file and don't go to the server. - // If we're in saint mode, don't go to the server - if (pdata != NULL && - ((flags & O_TRUNC) || use_local_copy || - (pdata->last_server_update == 0) || (time(NULL) - pdata->last_server_update) <= STAT_CACHE_NEGATIVE_TTL)) { - const float samplerate = 1.0; // always sample stat - log_print(LOG_DEBUG, SECTION_FILECACHE_OPEN, "%s: file is fresh or being truncated: %s::%s", - funcname, path, pdata->filename); - - // Open first with O_TRUNC off to avoid modifying the file without holding the right lock. - sdata->fd = open(pdata->filename, flags & ~O_TRUNC); - if (sdata->fd < 0 || inject_error(filecache_error_freshopen1)) { - log_print(LOG_DYNAMIC, SECTION_FILECACHE_OPEN, "%s: < 0, %s with flags %x returns < 0: errno: %d, %s : ENOENT=%d", - funcname, path, flags, errno, strerror(errno), ENOENT); - // If the cachefile named in pdata->filename does not exist, or any other error occurs... - g_set_error(gerr, system_quark(), errno, "%s: open failed: %s", funcname, strerror(errno)); - // use_local_copy means we're in saint mode - // otherwise we failed on something we expected based on last_server_update - // I believe we can get here on a PUT, and succeed in getting a previous copy from the cache - // This will eventually fail if we are already in saint mode, but should succeed for now - if (use_local_copy) { - if (rw ) stats_counter("put_saint_mode_failure", 1, samplerate); - else stats_counter("get_saint_mode_failure", 1, samplerate); - log_print(LOG_WARNING, SECTION_FILECACHE_OPEN, "%s: get_saint_mode_failure on file: %s::%s", funcname, path, pdata->filename); - } else { - if (rw) stats_counter("put_cache_failure", 1, samplerate); - else stats_counter("get_cache_failure", 1, samplerate); - log_print(LOG_WARNING, SECTION_FILECACHE_OPEN, "%s: get_cache_failure on file in cache: %s::%s", funcname, path, pdata->filename); - } - goto finish; - } else { - if (use_local_copy) { - if (rw) stats_counter("put_saint_mode_success", 1, samplerate); - else stats_counter("get_saint_mode_success", 1, samplerate); - log_print(LOG_NOTICE, SECTION_FILECACHE_OPEN, "%s: get_saint_mode_success on file: %s::%s", funcname, path, pdata->filename); - } else { - if (rw) stats_counter("put_cache_success", 1, samplerate); - else stats_counter("get_cache_success", 1, samplerate); - log_print(LOG_INFO, SECTION_FILECACHE_OPEN, "%s: get_cache_success on file in cache: %s::%s", funcname, path, pdata->filename); - } - } - - if (flags & O_TRUNC) { - log_print(LOG_DEBUG, SECTION_FILECACHE_OPEN, "%s: truncating fd %d:%s::%s", - funcname, sdata->fd, path, pdata->filename); - - log_print(LOG_DEBUG, SECTION_FILECACHE_FLOCK, "%s: acquiring shared file lock on fd %d", - funcname, sdata->fd); - if (flock(sdata->fd, LOCK_SH) || inject_error(filecache_error_freshflock1)) { - g_set_error(gerr, system_quark(), errno, "%s: error acquiring shared file lock", funcname); - goto finish; - } - log_print(LOG_DEBUG, SECTION_FILECACHE_FLOCK, "%s: acquired shared file lock on fd %d", funcname, sdata->fd); - - if (ftruncate(sdata->fd, 0) || inject_error(filecache_error_freshftrunc)) { - g_set_error(gerr, system_quark(), errno, "%s: ftruncate failed", funcname); - log_print(LOG_INFO, SECTION_FILECACHE_OPEN, "%s: ftruncate failed; %d:%s:%s :: %s", - funcname, sdata->fd, path, pdata->filename, g_strerror(errno)); - // Fall through to release the lock - } + log_print(LOG_DEBUG, SECTION_FILECACHE_OPEN, "%s: Getting parent path entry: %s", funcname, parent_path); + parent_children_update_ts = stat_cache_read_updated_children(cache, parent_path, &tmpgerr); + if (tmpgerr) { + g_propagate_prefixed_error(gerr, tmpgerr, "%s: ", funcname); + } - log_print(LOG_DEBUG, SECTION_FILECACHE_FLOCK, "%s: releasing shared file lock on fd %d", - funcname, sdata->fd); - if (flock(sdata->fd, LOCK_UN) || inject_error(filecache_error_freshflock2)) { - // If we didn't get an error from ftruncate, then set gerr here from flock on error; - // If ftruncate did get an error, it will take precedence and we will ignore this error - if (!gerr) { - g_set_error(gerr, system_quark(), errno, "%s: error releasing shared file lock", funcname); - } - else { - // If we got an error from ftruncate so don't set one for flock, still report - // that releasing the lock failed. - log_print(LOG_CRIT, SECTION_FILECACHE_OPEN, "%s: error releasing shared file lock :: %s", - funcname, strerror(errno)); - } - goto finish; - } + free(parent_path); + return parent_children_update_ts; +} - // We've fallen through to flock from ftruncate; if ftruncate returns an error, return here - if (gerr) goto finish; +static bool filecache_is_fresh(filecache_t *cache, const char *path, fc_pdata *pdata, GError **gerr) { + time_t parent_children_update_ts; + time_t check_now = time(NULL); + GError *tmpgerr = NULL; + static const char *funcname = "filecache_is_fresh"; + const float samplerate = 1.0; // always sample stat - log_print(LOG_DEBUG, SECTION_FILECACHE_FLOCK, "%s: released shared file lock on fd %d", funcname, sdata->fd); + parent_children_update_ts = get_parent_updated_children_time(cache, path, &tmpgerr); + if (tmpgerr) { + g_propagate_prefixed_error(gerr, tmpgerr, "%s: ", funcname); + return false; + } + if (((check_now - parent_children_update_ts) <= FILECACHE_PARENT_UPDATE_GRACE) + && (pdata->last_server_update > FILECACHE_INVALIDATED)) { + return true; + } + stats_counter("parent_propfind_miss", 1, samplerate); + return ((check_now - pdata->last_server_update) <= FILECACHE_ENTRY_TTL); +} - sdata->modified = true; - } - else { - log_print(LOG_DEBUG, SECTION_FILECACHE_OPEN, "%s: O_TRUNC not specified on fd %d:%s::%s", - funcname, sdata->fd, path, pdata->filename); - } +static bool filecache_conditional_http_get(const char *path, const char *etag, fc_http_get_response *resp, int idx, rwp_t rwp, GError **gerr) { + long elapsed_time = 0; + CURL *session; + struct curl_slist *slist = NULL; + + resp->res = CURLE_OK; + resp->status_code = 500; + session = session_request_init(path, NULL, false, rwp); + if (!session || inject_error(filecache_error_freshsession)) { + g_set_error(gerr, curl_quark(), E_FC_CURLERR, "Failed session_request_init on GET"); + try_release_request_outstanding(); + return false; + } + // Give cURL the fd and callback for handling the response body. + curl_easy_setopt(session, CURLOPT_WRITEDATA, &(resp->fd)); + curl_easy_setopt(session, CURLOPT_WRITEFUNCTION, write_response_to_fd); + // let cURL capture the etag + curl_easy_setopt(session, CURLOPT_HEADERFUNCTION, capture_etag); + curl_easy_setopt(session, CURLOPT_WRITEHEADER, resp->etag); + // Set headers + if (etag[0] != '\0') { + char *etag_header = NULL; + asprintf(&etag_header, "If-None-Match: %s", etag); + slist = curl_slist_append(slist, etag_header); + free(etag_header); + } + slist = enhanced_logging(slist, LOG_INFO, SECTION_FILECACHE_OPEN, "get_fresh_id: %s", path); + if (slist) { + curl_easy_setopt(session, CURLOPT_HTTPHEADER, slist); + } + // Finally do it + timed_curl_easy_perform(session, &(resp->res), &(resp->status_code), &elapsed_time); + if (slist) { + curl_slist_free_all(slist); + } + return process_status("get", session, resp->res, resp->status_code, elapsed_time, idx, path, false); +} - // We're done; no need to access the server... - goto finish; +static void filecache_count_get_timing(off_t st_size, const char *path, long response_code, long elapsed_time) { + // Not to exceed time for operation, else it's an error. Allow large files a longer time + // Somewhat arbitrary + static const unsigned small_time_allotment = 2000; // 2 seconds + static const unsigned large_time_allotment = 8000; // 8 seconds + char *stats_name = NULL; + if (st_size > XLG) { + TIMING(filecache_get_xlg_timing, elapsed_time); + BUMP(filecache_get_xlg_count); + asprintf(&stats_name, "large-get-latency.%ld", response_code); + } + else if (st_size > LG) { + TIMING(filecache_get_lg_timing, elapsed_time); + BUMP(filecache_get_lg_count); + asprintf(&stats_name, "large-get-latency.%ld", response_code); + } + else if (st_size > MED) { + TIMING(filecache_get_med_timing, elapsed_time); + BUMP(filecache_get_med_count); + asprintf(&stats_name, "large-get-latency.%ld", response_code); + } + else if (st_size > SM) { + TIMING(filecache_get_sm_timing, elapsed_time); + BUMP(filecache_get_sm_count); + asprintf(&stats_name, "small-get-latency.%ld", response_code); + } + else if (st_size > XSM) { + TIMING(filecache_get_xsm_timing, elapsed_time); + BUMP(filecache_get_xsm_count); + asprintf(&stats_name, "small-get-latency.%ld", response_code); + } + else { + TIMING(filecache_get_xxsm_timing, elapsed_time); + BUMP(filecache_get_xxsm_count); + asprintf(&stats_name, "small-get-latency.%ld", response_code); } - for (int idx = 0; idx < num_filesystem_server_nodes && (res != CURLE_OK || response_code >= 500); idx++) { - long elapsed_time = 0; - CURL *session; - struct curl_slist *slist = NULL; - rwp_t rwp; + stats_timer(stats_name, elapsed_time); + free(stats_name); + stats_name = NULL; + if (elapsed_time <= large_time_allotment) { + return; + } - if (rw) rwp = WRITE; - else rwp = READ; + if (st_size >= LG) { + log_print(LOG_WARNING, SECTION_FILECACHE_OPEN, "large (%lu) GET for %s exceeded time allotment %lu with %lu", + st_size, path, large_time_allotment, elapsed_time); + asprintf(&stats_name, "exceeded-time-large-GET-latency.%ld", response_code); + stats_timer(stats_name, elapsed_time); + } + else { + log_print(LOG_WARNING, SECTION_FILECACHE_OPEN, "small (%lu) GET for %s exceeded time allotment %lu with %lu", + st_size, path, small_time_allotment, elapsed_time); + asprintf(&stats_name, "exceeded-time-small-GET-latency.%ld", response_code); + stats_timer(stats_name, elapsed_time); + } + free(stats_name); + return; +} - // These will be -1 and [0] = '\0' on idx 0; but subsequent iterations we need to clean up from previous time - if (response_fd >= 0) close(response_fd); - if (response_filename[0] != '\0') unlink(response_filename); +static void filecache_get_handle_200(const char *path, fc_sdata *sdata, fc_pdata *pdata, fc_http_get_response *resp, GError **gerr) { + char old_filename[PATH_MAX] = {'\0'}; - session = session_request_init(path, NULL, false, rwp); - if (!session || inject_error(filecache_error_freshsession)) { - g_set_error(gerr, curl_quark(), E_FC_CURLERR, "%s: Failed session_request_init on GET", funcname); - // TODO(kibra): Manually cleaning up this lock sucks. We should make sure this happens in a better way. - try_release_request_outstanding(); - goto finish; + if (pdata == NULL) { + pdata = calloc(1, sizeof(fc_pdata)); + if (pdata == NULL || inject_error(filecache_error_freshpdata)) { + g_set_error(gerr, system_quark(), errno, "could not allocate pdata"); + return; } + pdata->filename[0] = '\0'; + } + strncpy(old_filename, pdata->filename, PATH_MAX); - if (pdata) { - char *header = NULL; - - // In case we have stale cache data, set a header to aim for a 304. - asprintf(&header, "If-None-Match: %s", pdata->etag); - slist = curl_slist_append(slist, header); - free(header); - } - slist = enhanced_logging(slist, LOG_INFO, SECTION_FILECACHE_OPEN, "get_fresh_id: %s", path); - if (slist) curl_easy_setopt(session, CURLOPT_HTTPHEADER, slist); + log_print(LOG_DEBUG, SECTION_FILECACHE_OPEN, "Saving ETag: %s", resp->etag); + strncpy(pdata->etag, resp->etag, ETAG_MAX); + pdata->last_server_update = time(NULL); + strncpy(pdata->filename, resp->filename, PATH_MAX); + sdata->fd = resp->fd; - // Set an ETag header capture path. - etag[0] = '\0'; - curl_easy_setopt(session, CURLOPT_HEADERFUNCTION, capture_etag); - curl_easy_setopt(session, CURLOPT_WRITEHEADER, etag); + filecache_pdata_set(sdata->cache, path, pdata, gerr); + if (*gerr) { + memset(sdata, 0, sizeof(fc_sdata)); + return; + } + log_print(LOG_INFO, SECTION_FILECACHE_OPEN, "Updated file cache for %s : %s : timestamp: %lu.", + path, pdata->filename, pdata->last_server_update); + if (old_filename[0] != '\0') { + unlink(old_filename); + } + return; +} - // Create a new temp file in case cURL needs to write to one. - new_cache_file(cache_path, response_filename, &response_fd, &tmpgerr); - if (tmpgerr) { - g_propagate_prefixed_error(gerr, tmpgerr, "%s: ", funcname); - // @TODO: Should we delete path from cache and/or null-out pdata? - // @TODO: Punt. Revisit when we add curl retry to open - if (slist) curl_slist_free_all(slist); - goto finish; - } +static void filecache_get_handle_304(const char *path, fc_sdata *sdata, fc_pdata *pdata, GError **gerr) { + // This should never happen with a well-behaved server. + if (pdata == NULL || inject_error(filecache_error_freshcurl2)) { + g_set_error(gerr, system_quark(), E_FC_PDATANULL, + "Should not get HTTP 304 from server when pdata is NULL because etag is empty."); + return; + } + // Mark the cache item as revalidated at the current time. + pdata->last_server_update = time(NULL); + filecache_pdata_set(sdata->cache, path, pdata, gerr); + return; +} - // Give cURL the fd and callback for handling the response body. - curl_easy_setopt(session, CURLOPT_WRITEDATA, &response_fd); - curl_easy_setopt(session, CURLOPT_WRITEFUNCTION, write_response_to_fd); +static void filecache_get_handle_404(fc_sdata *sdata, const char *path, GError **gerr) { + // A previous propfind showed this file would exist, but between then and now, the path was deleted on the server + // We clear the cache entries for this path to prevent the case where the path is forever poisoned + // We are subject to a TOCTOU issue where the cache has been updated since we used it, and we clear a valid entry + struct stat_cache_value *value; + g_set_error(gerr, filecache_quark(), ENOENT, "File %s expected to exist.", path); + value = stat_cache_value_get(sdata->cache, path, true, NULL); + if (value) { + stat_cache_delete(sdata->cache, path, NULL); + } + free(value); + // Delete it from the filecache too + filecache_delete(sdata->cache, path, true, NULL); + return; +} - timed_curl_easy_perform(session, &res, &response_code, &elapsed_time); +static void filecache_handle_http_get_response(const char *path, fc_sdata *sdata, fc_pdata *pdata, fc_http_get_response *resp, + const struct timespec *start_time, GError **gerr) { + struct timespec now; + struct stat st; + long elapsed_time; + trigger_saint_event(CLUSTER_SUCCESS, "get"); - if (slist) curl_slist_free_all(slist); + if (inject_error(filecache_error_fresh400)) resp->status_code = 400; - bool non_retriable_error = process_status("get", session, res, response_code, elapsed_time, idx, path, false); - // Some errors should not be retried. (Non-errors will fail the - // for loop test and fall through naturally) - if (non_retriable_error) break; + if (resp->status_code == 304) { + filecache_get_handle_304(path, sdata, pdata, gerr); + goto finish; } - - if ((res != CURLE_OK || response_code >= 500) || inject_error(filecache_error_freshcurl1)) { - trigger_saint_event(CLUSTER_FAILURE, "get"); - set_dynamic_logging(); - g_set_error(gerr, curl_quark(), E_FC_CURLERR, "%s: curl_easy_perform is not CURLE_OK or 500: %s", - funcname, curl_easy_strerror(res)); + if (resp->status_code == 200) { + filecache_get_handle_200(path, sdata, pdata, resp, gerr); goto finish; - } else { - trigger_saint_event(CLUSTER_SUCCESS, "get"); - } - - // If we get a 304, the cache file has the same contents as the file on the server, so - // just open the cache file without bothering to re-GET the contents from the server. - // If we get a 200, the cache file is stale and we need to update its contents from - // the server. - // We should not get a 404 here; either the open included O_CREAT and we create a new - // file, or the getattr/get_stat calls in fusedav.c should have detected the file was - // missing and handled it there. - // Update on unexpected 404: one theoretical path is that a file gets opened and written to, - // but on the close (dav_flush/release), the PUT fails and the file never makes it to the server. - // On opening again, the server will deliver this unexpected 404. Changes for forensic-haven - // should prevent these errors in the future (2013-08-29) - - if (inject_error(filecache_error_fresh400)) response_code = 400; - - if (response_code == 304) { - // This should never happen with a well-behaved server. - if (pdata == NULL || inject_error(filecache_error_freshcurl2)) { - g_set_error(gerr, system_quark(), E_FC_PDATANULL, - "%s: Should not get HTTP 304 from server when pdata is NULL because etag is empty.", funcname); - goto finish; - } - - // Mark the cache item as revalidated at the current time. - pdata->last_server_update = time(NULL); - - log_print(LOG_INFO, SECTION_FILECACHE_OPEN, - "%s: Updating file cache on 304 for %s : %s : timestamp: %lu : etag %s.", - funcname, path, pdata->filename, pdata->last_server_update, pdata->etag); - filecache_pdata_set(cache, path, pdata, &tmpgerr); - if (tmpgerr) { - g_propagate_prefixed_error(gerr, tmpgerr, "%s on 304: ", funcname); - goto finish; - } + } + if (resp->status_code == 404 || resp->status_code == 410) { + filecache_get_handle_404(sdata, path, gerr); + goto finish; + } + g_set_error(gerr, filecache_quark(), E_FC_CURLERR, "unexpected response code for path %s", path); + goto finish; +finish: + // Subtract seconds since start_time and multiply by 1000 to get ms. + // Subtract nanoseconds since start_time and divide by a million to get ms. + clock_gettime(CLOCK_MONOTONIC, &now); + elapsed_time = ((now.tv_sec - start_time->tv_sec) * 1000) + ((now.tv_nsec - start_time->tv_nsec) / (1000 * 1000)); + if (fstat(sdata->fd, &st)) { + log_print(LOG_WARNING, SECTION_FILECACHE_OPEN, "put_return_etag: fstat failed on %s", path); + return; + } + filecache_count_get_timing(st.st_size, path, resp->status_code, elapsed_time); +} - sdata->fd = open(pdata->filename, flags); +static void _filecache_truncate(fc_sdata *sdata, off_t s, GError **gerr) { + static const char* funcname = "_filecache_truncate"; - if (sdata->fd < 0 || inject_error(filecache_error_freshopen2)) { - // If the cachefile named in pdata->filename does not exist ... - if (errno == ENOENT) { - // delete pdata from cache, we can't trust its values. - // We see one site continually failing on the same non-existent cache file. - filecache_delete(cache, path, true, NULL); - } - g_set_error(gerr, system_quark(), errno, "%s: open for 304 failed: %s", funcname, strerror(errno)); - log_print(LOG_DYNAMIC, SECTION_FILECACHE_OPEN, - "%s: open for 304 on %s with flags %x and etag %s returns < 0: errno: %d, %s", - funcname, pdata->filename, flags, pdata->etag, errno, strerror(errno)); - goto finish; - } - else { - log_print(LOG_DEBUG, SECTION_FILECACHE_OPEN, "%s: open for 304 on %s with flags %x succeeded; fd %d", - funcname, pdata->filename, flags, sdata->fd); - BUMP(filecache_get_304_count); - } + if (sdata == NULL || inject_error(filecache_error_truncsdata)) { + g_set_error(gerr, filecache_quark(), E_FC_SDATANULL, "%s: sdata is NULL", funcname); + return; } - else if (response_code == 200) { - struct stat st; - long elapsed_time; - struct timespec now; - unsigned long latency; - unsigned long count; - // Archive the old temp file path for unlinking after replacement. - char old_filename[PATH_MAX]; - const char *sz; - bool unlink_old = false; - const float samplerate = 1.0; // always sample stat + log_print(LOG_INFO, SECTION_FILECACHE_FILE, "%s(%d)", funcname, sdata->fd); - if (pdata == NULL) { - *pdatap = calloc(1, sizeof(struct filecache_pdata)); - pdata = *pdatap; - if (pdata == NULL || inject_error(filecache_error_freshpdata)) { - g_set_error(gerr, system_quark(), errno, "%s: ", funcname); - goto finish; - } - } - else { - strncpy(old_filename, pdata->filename, PATH_MAX); - unlink_old = true; - } - - // Fill in ETag. - log_print(LOG_DEBUG, SECTION_FILECACHE_OPEN, "Saving ETag: %s", etag); - strncpy(pdata->etag, etag, ETAG_MAX); - pdata->etag[ETAG_MAX] = '\0'; // length of etag is ETAG_MAX + 1 to accomodate this null terminator + log_print(LOG_DEBUG, SECTION_FILECACHE_FLOCK, "%s: acquiring shared file lock on fd %d", funcname, sdata->fd); + if (flock(sdata->fd, LOCK_SH) || inject_error(filecache_error_truncflock1)) { + g_set_error(gerr, system_quark(), errno, "%s: error acquiring shared file lock", funcname); + return; + } + log_print(LOG_DEBUG, SECTION_FILECACHE_FLOCK, "%s: acquired shared file lock on fd %d", funcname, sdata->fd); - // Point the persistent cache to the new file content. - pdata->last_server_update = time(NULL); - strncpy(pdata->filename, response_filename, PATH_MAX); + if ((ftruncate(sdata->fd, s) < 0) || inject_error(filecache_error_truncftrunc)) { + // falling through to release lock ... + g_set_error(gerr, system_quark(), errno, "%s: ftruncate failed", funcname); + } + if (*gerr == NULL) { + sdata->modified = true; + } - sdata->fd = response_fd; + log_print(LOG_DEBUG, SECTION_FILECACHE_FLOCK, "%s: releasing shared file lock on fd %d", funcname, sdata->fd); + if (flock(sdata->fd, LOCK_UN) || inject_error(filecache_error_truncflock2)) { + log_print(LOG_CRIT, SECTION_FILECACHE_OPEN, "%s: error releasing shared file lock :: %s", + funcname, strerror(errno)); + // If ftruncate got an error, it will take precedence and we will ignore this error + g_set_error(gerr, system_quark(), errno, "%s: error releasing shared file lock", funcname); + } + return; +} - log_print(LOG_INFO, SECTION_FILECACHE_OPEN, "%s: Updating file cache on 200 for %s : %s : timestamp: %lu.", - funcname, path, pdata->filename, pdata->last_server_update); - filecache_pdata_set(cache, path, pdata, &tmpgerr); +static void filecache_fill(fc_pdata *pdata, fc_sdata *sdata, int flags, GError** gerr) { + static const char *funcname = "filecache_fill"; + GError *tmpgerr = NULL; + // Open first with O_TRUNC off to avoid modifying the file without holding the right lock. + sdata->fd = open(pdata->filename, flags & ~O_TRUNC); + // If the cachefile named in pdata->filename does not exist, or any other error occurs... + if (sdata->fd < 0 || inject_error(filecache_error_freshopen1)) { + g_set_error(&tmpgerr, system_quark(), errno, "open with flags %x failed: %s", flags, strerror(errno)); + g_propagate_prefixed_error(gerr, tmpgerr, "%s: ", funcname); + return; + } + if (flags & O_TRUNC) { + _filecache_truncate(sdata, 0, &tmpgerr); if (tmpgerr) { - memset(sdata, 0, sizeof(struct filecache_sdata)); - g_propagate_prefixed_error(gerr, tmpgerr, "%s on 200: ", funcname); - goto finish; - } - - close_response_fd = false; - - // Unlink the old cache file, which the persistent cache - // no longer references. This will cause the file to be - // deleted once no more file descriptors reference it. - if (unlink_old) { - unlink(old_filename); - log_print(LOG_NOTICE, SECTION_FILECACHE_OPEN, "%s: 200: unlink old filename %s", funcname, old_filename); - } - - if (fstat(sdata->fd, &st)) { - log_print(LOG_WARNING, SECTION_FILECACHE_OPEN, "put_return_etag: fstat failed on %s", path); - goto finish; + g_propagate_prefixed_error(gerr, tmpgerr, "%s: ", funcname); } + } + return; +} - /* Get the time into now. - * Subtract seconds since start_time and multiply by 1000 to get ms. - * Subtract nanoseconds since start_time and divide by a million to get ms. - * ns count might be negative (now is 3s and 100 million ns, start was 1 sec and 800 million ns. - * Seconds is now 2 (*1000); - * ns is now -700 (800 million ns - 100 million ns divided by a million. - * 2000 - 700 = 1300 ms, or 1s 300ms, which is correct for 3.1 - 1.8) - */ - clock_gettime(CLOCK_MONOTONIC, &now); - elapsed_time = ((now.tv_sec - start_time.tv_sec) * 1000) + ((now.tv_nsec - start_time.tv_nsec) / (1000 * 1000)); +static void get_fresh_cache_file(const char *path, fc_sdata *sdata, fc_pdata *pdata, rwp_t rwp, GError **gerr) { + char etag[ETAG_MAX] = {'\0'}; + fc_http_get_response *resp = NULL; + GError *tmpgerr = NULL; + const char *funcname = "get_fresh_cache_file"; + struct timespec start_time; + clock_gettime(CLOCK_MONOTONIC, &start_time); - if (st.st_size > XLG) { - TIMING(filecache_get_xlg_timing, elapsed_time); - BUMP(filecache_get_xlg_count); - latency = FETCH(filecache_get_xlg_timing); - count = FETCH(filecache_get_xlg_count); - sz = "XLG"; - stats_counter("large-gets", 1, samplerate); - stats_timer("large-get-latency", elapsed_time); - } - else if (st.st_size > LG) { - TIMING(filecache_get_lg_timing, elapsed_time); - BUMP(filecache_get_lg_count); - latency = FETCH(filecache_get_lg_timing); - count = FETCH(filecache_get_lg_count); - sz = "LG"; - stats_counter("large-gets", 1, samplerate); - stats_timer("large-get-latency", elapsed_time); - } - else if (st.st_size > MED) { - TIMING(filecache_get_med_timing, elapsed_time); - BUMP(filecache_get_med_count); - latency = FETCH(filecache_get_med_timing); - count = FETCH(filecache_get_med_count); - sz = "MED"; - stats_counter("large-gets", 1, samplerate); - stats_timer("large-get-latency", elapsed_time); - } - else if (st.st_size > SM) { - TIMING(filecache_get_sm_timing, elapsed_time); - BUMP(filecache_get_sm_count); - latency = FETCH(filecache_get_sm_timing); - count = FETCH(filecache_get_sm_count); - sz = "SM"; - stats_counter("small-gets", 1, samplerate); - stats_timer("small-get-latency", elapsed_time); - } - else if (st.st_size > XSM) { - TIMING(filecache_get_xsm_timing, elapsed_time); - BUMP(filecache_get_xsm_count); - latency = FETCH(filecache_get_xsm_timing); - count = FETCH(filecache_get_xsm_count); - sz = "XSM"; - stats_counter("small-gets", 1, samplerate); - stats_timer("small-get-latency", elapsed_time); - } - else { - TIMING(filecache_get_xxsm_timing, elapsed_time); - BUMP(filecache_get_xxsm_count); - latency = FETCH(filecache_get_xxsm_timing); - count = FETCH(filecache_get_xxsm_count); - sz = "XXSM"; - stats_counter("small-gets", 1, samplerate); - stats_timer("small-get-latency", elapsed_time); - } - log_print(LOG_DEBUG, SECTION_FILECACHE_OPEN, "put_fresh_fd: GET on size %s (%lu) for %s -- Current:Average latency %lu :: %lu", - sz, st.st_size, path, elapsed_time, (latency / count)); + resp = calloc(1, sizeof(fc_http_get_response)); + if (resp == NULL) { + g_set_error(gerr, system_quark(), errno, "Failed to calloc fc_http_get_response"); + return; + } + resp->etag[0] = '\0'; + resp->filename[0] = '\0'; + resp->fd = -1; - if (st.st_size >= LG && elapsed_time > large_time_allotment) { - log_print(LOG_WARNING, SECTION_FILECACHE_OPEN, "put_fresh_fd: large (%lu) GET for %s exceeded time allotment %lu with %lu", - st.st_size, path, large_time_allotment, elapsed_time); - stats_counter("exceeded-time-large-GET-count", 1, samplerate); - stats_timer("exceeded-time-large-GET-latency", elapsed_time); + if (pdata) { + strncpy(&etag, pdata->etag, ETAG_MAX); + } + new_cache_file(sdata->cache_path, resp->filename, &(resp->fd), &tmpgerr); + if (tmpgerr) { + g_propagate_prefixed_error(gerr, tmpgerr, "%s: ", funcname); + goto finish; + } + for (int idx = 0; idx < num_filesystem_server_nodes; idx++) { + // clean up from previous iteration + if ((lseek(resp->fd, 0, SEEK_SET) == (off_t)-1)) { + g_set_error(gerr, system_quark(), errno, "%s: failed lseek on %s", funcname, path); + break; } - else if (st.st_size < LG && elapsed_time > small_time_allotment) { - log_print(LOG_WARNING, SECTION_FILECACHE_OPEN, "put_fresh_fd: small (%lu) GET for %s exceeded time allotment %lu with %lu", - st.st_size, path, small_time_allotment, elapsed_time); - stats_counter("exceeded-time-small-GET-count", 1, samplerate); - stats_timer("exceeded-time-small-GET-latency", elapsed_time); + bool non_retriable_error = filecache_conditional_http_get(path, etag, resp, idx, rwp, gerr); + if (non_retriable_error || *gerr) { + break; } } - else if (response_code == 404 || response_code == 410) { - - /* If two bindings are in a race condition on the same file, this - * can occur. Binding A does a propfind; Binding B does a propfind - * and the file is shown to exist. Binding A deletes the file - * then Binding B tries to access it and the server returns 404. - * Not sure how to remediate without doing way more work and - * introducing way more problems than the fix will fix. - */ - struct stat_cache_value *value; - g_set_error(gerr, filecache_quark(), ENOENT, "%s: File %s expected to exist returns %ld.", - funcname, path, response_code); - /* we get a 404 because the stat_cache returned that the file existed, but it - * was not on the server. Deleting it from the stat_cache makes the stat_cache - * consistent, so the next access to the file will be handled correctly. - */ - - value = stat_cache_value_get(cache, path, true, NULL); - if (value) { - // Collect some additional information to give some hints about the file - // which might help uncover why this error is happening. - time_t lsu = 0; - time_t atime = value->st.st_atime; - off_t sz = value->st.st_size; - unsigned long lg = value->local_generation; + if (resp->status_code != 200) { + close(resp->fd); + unlink(resp->filename); + } + if (*gerr) { + goto finish; + } + if ((resp->res != CURLE_OK || resp->status_code >= 500) || inject_error(filecache_error_freshcurl1)) { + trigger_saint_event(CLUSTER_FAILURE, "get"); + set_dynamic_logging(); + g_set_error(gerr, curl_quark(), E_FC_CURLERR, "%s: curl_easy_perform is not CURLE_OK or is 500: %s", + funcname, curl_easy_strerror(resp->res)); + goto finish; + } + filecache_handle_http_get_response(path, sdata, pdata, resp, &start_time, &tmpgerr); + if (tmpgerr) { + g_propagate_prefixed_error(gerr, tmpgerr, "%s on %ld: ", funcname, resp->status_code); + goto finish; + } +finish: + free(resp); + return; +} - // If we have a pdata, it is out of date, since the server doesn't have the file, - // meaning it must have been deleted. - if (pdata) lsu = pdata->last_server_update; +// Get a file descriptor pointing to the latest full copy of the file. +static void get_fresh_fd(const char *path, fc_sdata *sdata, fc_pdata **pdatap, int flags, bool use_local_copy, GError **gerr) { + static const char *funcname = "get_fresh_fd"; + GError *tmpgerr = NULL; + fc_pdata *pdata; + const float samplerate = 1.0; // always sample stat + char *stats_name_base, *stats_name; + BUMP(filecache_fresh_fd); + bool rw = write_flag(flags); + rwp_t rwp = READ; + if (rw) { + rwp = WRITE; + } - log_print(LOG_ERR, SECTION_FILECACHE_OPEN, "%s: 404 on file in cache %s, (lg sz tm lsu %lu %lu %lu %lu); deleting...", - funcname, path, lg, sz, atime, lsu); + assert(pdatap); + pdata = *pdatap; - stat_cache_delete(cache, path, NULL); + // If O_TRUNC, the caller will ignore any data we would get from the server, so don't call, just open the file and truncate. + // If the file is in-use (last_server_update = 0) or fresh, we use the local file and don't go to the server. + // If we're in saint mode, don't go to the server + if (pdata != NULL && (use_local_copy || flags & O_TRUNC || (pdata->last_server_update == 0) + || filecache_is_fresh(sdata->cache, path, pdata, &tmpgerr))) { + // set the prefix of the stat name to something like put_saint_mode or get_cache + asprintf(&stats_name_base, "%s_%s", (rw) ? "put" : "get", use_local_copy ? "saint_mode" : "cache"); - free(value); + asprintf(&stats_name, "%s_%s", stats_name_base, "success"); + filecache_fill(pdata, sdata, flags, &tmpgerr); + if (tmpgerr) { + g_propagate_prefixed_error(gerr, tmpgerr, "%s: on path %s: ", funcname, path); + asprintf(&stats_name, "%s_%s", stats_name_base, "failure"); } - // Delete it from the filecache too - filecache_delete(cache, path, true, NULL); - goto finish; - } - else { - // Not sure what to do here; goto finish, or try the loop another time? - log_print(LOG_WARNING, SECTION_FILECACHE_OPEN, "%s: returns %d; expected 304 or 200; err: %s", funcname, response_code, curl_errorbuffer(response_code)); + stats_counter(stats_name, 1, samplerate); + log_print(LOG_INFO, SECTION_FILECACHE_OPEN, "%s: %s on file: %s::%s", funcname, stats_name, path, pdata->filename); + free(stats_name); + free(stats_name_base); + return; } - // No check for O_TRUNC here because we skip server access and just - // truncate. - assert(!(flags & O_TRUNC)); - -finish: - if (close_response_fd) { - if (response_fd >= 0) close(response_fd); - if (response_filename[0] != '\0') unlink(response_filename); + get_fresh_cache_file(path, sdata, pdata, rwp, gerr); + if (!*gerr) { + sdata->fd = open(pdata->filename, flags); + // delete the entry if it's fd is inoperable + if (sdata->fd < 0 || inject_error(filecache_error_freshopen2)) { + if (errno == ENOENT) { + filecache_delete(sdata->cache, path, true, NULL); + } + g_set_error(gerr, system_quark(), errno, "open for 304 failed: %s", strerror(errno)); + } } + return; } // top-level open call -void filecache_open(char *cache_path, filecache_t *cache, const char *path, struct fuse_file_info *info, - bool grace, bool rw, GError **gerr) { - struct filecache_pdata *pdata = NULL; - struct filecache_sdata *sdata = NULL; +void filecache_open(char *cache_path, filecache_t *cache, const char *path, struct fuse_file_info *info, bool grace, GError **gerr) { + fc_pdata *pdata = NULL; + fc_sdata *sdata = NULL; GError *tmpgerr = NULL; int max_retries = 2; int flags = info->flags; bool use_local_copy = false; + const char *funcname = "filecache_open"; BUMP(filecache_open); - log_print(LOG_INFO, SECTION_FILECACHE_OPEN, "filecache_open: %s", path); + log_print(LOG_INFO, SECTION_FILECACHE_OPEN, "%s: %s", funcname, path); // Don't bother going to server if already in cluster saint mode if (use_saint_mode()) { use_local_copy = true; max_retries = 1; // Only try once if already in saint mode log_print(LOG_INFO, SECTION_FILECACHE_OPEN, - "filecache_open: already in saint mode, using local copy: %s", path); + "%s: already in saint mode, using local copy: %s", funcname, path); } // Allocate and zero-out a session data structure. - sdata = calloc(1, sizeof(struct filecache_sdata)); + sdata = calloc(1, sizeof(fc_sdata)); if (sdata == NULL || inject_error(filecache_error_opencalloc)) { - g_set_error(gerr, system_quark(), errno, "filecache_open: Failed to calloc sdata"); + g_set_error(gerr, system_quark(), errno, "%s: Failed to calloc sdata", funcname); goto fail; } + sdata->cache = cache; + sdata->cache_path = cache_path; // NB. We call get_fresh_fd; it tries each of the servers. If they all fail // we try again but force it to use the local copy. This should make saint mode @@ -853,33 +817,32 @@ void filecache_open(char *cache_path, filecache_t *cache, const char *path, stru // of the same name, this outdated entry will still be in the // filecache. Since it's out of date, it's ok to overwrite it. log_print(LOG_INFO, SECTION_FILECACHE_OPEN, - "filecache_open: creating a file that already has a cache entry: %s", path); + "%s: creating a file that already has a cache entry: %s", funcname, path); } - log_print(LOG_DEBUG, SECTION_FILECACHE_OPEN, "filecache_open: calling create_file on %s", path); create_file(sdata, cache_path, cache, path, &tmpgerr); if (tmpgerr) { - g_propagate_prefixed_error(gerr, tmpgerr, "filecache_open: "); + g_propagate_prefixed_error(gerr, tmpgerr, "%s: ", funcname); goto fail; } break; } // Get a file descriptor pointing to a guaranteed-fresh file. - log_print(LOG_DEBUG, SECTION_FILECACHE_OPEN, "filecache_open: calling get_fresh_fd on %s", path); - get_fresh_fd(cache, cache_path, path, sdata, &pdata, flags, use_local_copy, rw, &tmpgerr); + log_print(LOG_DEBUG, SECTION_FILECACHE_OPEN, "%s: calling get_fresh_fd on %s", funcname, path); + get_fresh_fd(path, sdata, &pdata, flags, use_local_copy, &tmpgerr); if (tmpgerr) { - // If we got a network error (curl_quark is a marker) and we + // If we got a network error (curl_quark is a marker) and we // are using grace, try again but use the local copy // If we are already in saint mode (use_local_copy already true) // don't retry if (tmpgerr->domain == curl_quark() && grace && !use_local_copy) { log_print(LOG_WARNING, SECTION_FILECACHE_OPEN, - "filecache_open: Retry in saint mode for path %s. Error: %s", path, tmpgerr->message); + "%s: Retry in saint mode for path %s. Error: %s", funcname, path, tmpgerr->message); g_clear_error(&tmpgerr); use_local_copy = true; continue; } - g_propagate_prefixed_error(gerr, tmpgerr, "filecache_open: Failed on get_fresh_fd: "); + g_propagate_prefixed_error(gerr, tmpgerr, "%s: Failed on get_fresh_fd: ", funcname); goto fail; } @@ -887,7 +850,7 @@ void filecache_open(char *cache_path, filecache_t *cache, const char *path, stru break; } - log_print(LOG_INFO, SECTION_FILECACHE_OPEN, "filecache_open: success on %s", path); + log_print(LOG_INFO, SECTION_FILECACHE_OPEN, "%s: success on %s", funcname, path); if (flags & O_RDONLY || flags & O_RDWR) sdata->readable = 1; if (flags & O_WRONLY || flags & O_RDWR) sdata->writable = 1; @@ -895,19 +858,19 @@ void filecache_open(char *cache_path, filecache_t *cache, const char *path, stru if (sdata->fd >= 0) { if (pdata) { log_print(LOG_DEBUG, SECTION_FILECACHE_OPEN, - "filecache_open: Setting fd to session data structure with fd %d for %s :: %s:%lu.", + "%s: Setting fd to session data structure with fd %d for %s :: %s:%lu.", funcname, sdata->fd, path, pdata->filename, pdata->last_server_update); } else { log_print(LOG_DEBUG, SECTION_FILECACHE_OPEN, - "filecache_open: Setting fd to session data structure with fd %d for %s :: (no pdata).", sdata->fd, path); + "%s: Setting fd to session data structure with fd %d for %s :: (no pdata).", funcname, sdata->fd, path); } info->fh = (uint64_t) sdata; goto finish; } fail: - log_print(LOG_DEBUG, SECTION_FILECACHE_OPEN, "filecache_open: No valid fd set for path %s. Setting fh structure to NULL.", path); + log_print(LOG_DEBUG, SECTION_FILECACHE_OPEN, "%s: No valid fd set for path %s. Setting fh structure to NULL.", funcname, path); info->fh = (uint64_t) NULL; free(sdata); @@ -918,7 +881,7 @@ void filecache_open(char *cache_path, filecache_t *cache, const char *path, stru // top-level read call ssize_t filecache_read(struct fuse_file_info *info, char *buf, size_t size, off_t offset, GError **gerr) { - struct filecache_sdata *sdata = (struct filecache_sdata *)info->fh; + fc_sdata *sdata = (fc_sdata *)info->fh; ssize_t bytes_read; BUMP(filecache_read); @@ -942,7 +905,7 @@ ssize_t filecache_read(struct fuse_file_info *info, char *buf, size_t size, off_ return bytes_read; } -static void set_error(struct filecache_sdata *sdata, int error_code) { +static void set_error(fc_sdata *sdata, int error_code) { if (sdata->error_code == 0) { sdata->error_code = error_code; log_print(LOG_DEBUG, SECTION_FILECACHE_IO, "set_error: %d.", error_code); @@ -954,7 +917,7 @@ static void set_error(struct filecache_sdata *sdata, int error_code) { // top-level write call ssize_t filecache_write(struct fuse_file_info *info, const char *buf, size_t size, off_t offset, GError **gerr) { - struct filecache_sdata *sdata = (struct filecache_sdata *)info->fh; + fc_sdata *sdata = (fc_sdata *)info->fh; ssize_t bytes_written; BUMP(filecache_write); @@ -1003,7 +966,7 @@ ssize_t filecache_write(struct fuse_file_info *info, const char *buf, size_t siz // close the file void filecache_close(struct fuse_file_info *info, GError **gerr) { - struct filecache_sdata *sdata = (struct filecache_sdata *)info->fh; + fc_sdata *sdata = (fc_sdata *)info->fh; BUMP(filecache_close); @@ -1089,7 +1052,7 @@ static void put_return_etag(const char *path, int fd, char *etag, GError **gerr) goto finish; } - // REVIEW: We didn't use to check for sesssion == NULL, so now we + // REVIEW: We didn't use to check for sesssion == NULL, so now we // also call try_release_request_outstanding. Is this OK? session = session_request_init(path, NULL, false, rwp); if (!session || inject_error(filecache_error_freshsession)) { @@ -1122,12 +1085,12 @@ static void put_return_etag(const char *path, int fd, char *etag, GError **gerr) // Some errors should not be retried. (Non-errors will fail the // for loop test and fall through naturally) if (non_retriable_error) break; - } + } // end for loop if ((res != CURLE_OK || response_code >= 500) || inject_error(filecache_error_etagcurl1)) { trigger_saint_event(CLUSTER_FAILURE, "put"); set_dynamic_logging(); - g_set_error(gerr, curl_quark(), E_FC_CURLERR, "%s: retry_curl_easy_perform is not CURLE_OK: %s", + g_set_error(gerr, curl_quark(), E_FC_CURLERR, "%s: retry_curl_easy_perform is not CURLE_OK: %s", funcname, curl_easy_strerror(res)); goto finish; } @@ -1254,192 +1217,93 @@ static void put_return_etag(const char *path, int fd, char *etag, GError **gerr) // top-level sync call bool filecache_sync(filecache_t *cache, const char *path, struct fuse_file_info *info, bool do_put, GError **gerr) { - struct filecache_sdata *sdata = (struct filecache_sdata *)info->fh; - struct filecache_pdata *pdata = NULL; + fc_sdata *sdata = (fc_sdata *)info->fh; + fc_pdata *pdata = NULL; GError *tmpgerr = NULL; bool wrote_data = false; - + const char *funcname = "filecache_sync"; BUMP(filecache_sync); - // We only do the sync if we have a path - // If we are accessing a bare file descriptor (open/unlink/read|write), - // path will be NULL, so just return without doing anything + // early return for accessing a bare file descriptor (open/unlink/read|write) if (path == NULL) { - log_print(LOG_DEBUG, SECTION_FILECACHE_COMM, "filecache_sync(NULL path, returning, fd=%d)", sdata? sdata->fd : -1); - goto finish; - } - else { - log_print(LOG_DEBUG, SECTION_FILECACHE_COMM, "filecache_sync(%s, fd=%d)", path, sdata? sdata->fd : -1); + log_print(LOG_DEBUG, SECTION_FILECACHE_COMM, "%s(NULL path, returning, fd=%d)", funcname, sdata? sdata->fd : -1); + return wrote_data; } - + log_print(LOG_DEBUG, SECTION_FILECACHE_COMM, "%s(%s, fd=%d)", funcname, path, sdata? sdata->fd : -1); if (sdata == NULL || inject_error(filecache_error_syncsdata)) { - log_print(LOG_NOTICE, SECTION_FILECACHE_COMM, "filecache_sync: error on NULL sdata on %s", path); - g_set_error(gerr, filecache_quark(), E_FC_SDATANULL, "filecache_sync: sdata is NULL"); - goto finish; + g_set_error(gerr, filecache_quark(), E_FC_SDATANULL, "%s: sdata is NULL on %s", funcname, path); } - - // If we already have an error: - // If we are about to try a PUT, just stop and return. This will cause dav_release to - // cleanup, sending file to forensic haven. - // So no need to go ahead and try to process this. - // However, if we aren't yet doing the PUT, let the sync continue. Eventually, the file - // will make it to forensic haven if (sdata->error_code && do_put) { - log_print(LOG_NOTICE, SECTION_FILECACHE_COMM, "filecache_sync: already have previous error on %s", path); - g_set_error(gerr, filecache_quark(), sdata->error_code, "filecache_sync: sdata indicates previous error"); - goto finish; + g_set_error(gerr, filecache_quark(), sdata->error_code, "%s: sdata indicates previous error on %s", funcname, path); } - - log_print(LOG_INFO, SECTION_FILECACHE_COMM, "filecache_sync: Checking if file (%s) was writable.", path); - if (!sdata->writable) { - log_print(LOG_DEBUG, SECTION_FILECACHE_COMM, "filecache_sync: not writable on %s", path); - goto finish; + if (*gerr || !sdata->modified) { + return wrote_data; } - - // Write this data to the persistent cache - // Update the file cache + // locate the file cache data, which must exist from a prior call to open pdata = filecache_pdata_get(cache, path, &tmpgerr); if (tmpgerr) { - log_print(LOG_NOTICE, SECTION_FILECACHE_COMM, "filecache_sync: error on filecache_pdata_get on %s", path); - g_propagate_prefixed_error(gerr, tmpgerr, "filecache_sync: "); + g_propagate_prefixed_error(gerr, tmpgerr, "%s: error on %s", funcname, path); goto finish; } if (pdata == NULL || inject_error(filecache_error_syncpdata)) { - log_print(LOG_NOTICE, SECTION_FILECACHE_COMM, "filecache_sync: error on pdata NULL on %s", path); - g_set_error(gerr, filecache_quark(), E_FC_PDATANULL, "filecache_sync: pdata is NULL"); + g_set_error(gerr, filecache_quark(), E_FC_PDATANULL, "%s: pdata is NULL on %s", funcname, path); goto finish; } - log_print(LOG_DEBUG, SECTION_FILECACHE_COMM, "filecache_sync(%s, fd=%d): cachefile=%s", path, sdata->fd, pdata->filename); - - if (sdata->modified) { - if (do_put) { - log_print(LOG_DEBUG, SECTION_FILECACHE_COMM, "filecache_sync: Seeking fd=%d", sdata->fd); - // If this lseek fails, file eventually goes to forensic haven. - if ((lseek(sdata->fd, 0, SEEK_SET) == (off_t)-1) || inject_error(filecache_error_synclseek)) { - set_error(sdata, errno); - log_print(LOG_NOTICE, SECTION_FILECACHE_COMM, "filecache_sync: error on lseek on %s", path); - g_set_error(gerr, system_quark(), errno, "filecache_sync: failed lseek"); - goto finish; - } - - log_print(LOG_INFO, SECTION_FILECACHE_COMM, "About to PUT file (%s, fd=%d).", path, sdata->fd); - - put_return_etag(path, sdata->fd, pdata->etag, &tmpgerr); - - // if we fail PUT for any reason, file will eventually go to forensic haven. - // We err in put_return_etag on: - // -- failure to get flock - // -- failure on fstat of fd - // -- retry_curl_easy_perform not CURL_OK - // -- curl response code not between 200 and 300 - // -- failure to release flock - if (tmpgerr) { - /* Outside of calls to fsync itself, we call filecache_sync and PUT the file twice, - * once on dav_flush, then closely after on dav_release. If we call set_error on the - * first one, we won't attempt the PUT on the second one. In case of cURL error, - * don't set_error, so if it fails on the dav_flush, it might still succeed on the - * dav_release. - * (We call filecache_sync on writes and other times, but with the arg do_put - * set to false, so it doesn't do the PUT anyway.) - * This is a separate issue from whether or not the file goes to forensic haven. - * set_error really means, "If we see an error on write before we ever even attempt - * to do the PUT, don't do the PUT." This is different from, "If we fail PUT on dav_flush, - * do/don't try the PUT on dav_release." - */ - // Don't set error on cURL error; if dav_flush fails, we can still try again on dav_release - if (tmpgerr->code != E_FC_CURLERR) set_error(sdata, tmpgerr->code); - log_print(LOG_NOTICE, SECTION_FILECACHE_COMM, "filecache_sync: put_return_etag PUT failed on %s", path); - g_propagate_prefixed_error(gerr, tmpgerr, "filecache_sync: put_return_etag PUT failed: "); - goto finish; - } + log_print(LOG_DEBUG, SECTION_FILECACHE_COMM, "%s(%s, fd=%d): cachefile=%s", funcname, path, sdata->fd, pdata->filename); - log_print(LOG_INFO, SECTION_FILECACHE_COMM, "filecache_sync: PUT successful: %s : %s : old-timestamp: %lu: etag = %s", path, pdata->filename, pdata->last_server_update, pdata->etag); - - // If the PUT succeeded, the file isn't locally modified. - sdata->modified = false; - pdata->last_server_update = time(NULL); - } - else { - // If we don't PUT the file, we don't have an etag, so zero it out - strncpy(pdata->etag, "", 1); - - // The local copy currently trumps the server one, no matter how old. - pdata->last_server_update = 0; - } + if (!do_put) { + // If we don't PUT the file, we don't have an etag, so zero it out + strncpy(pdata->etag, "", 1); + // Mark in use + pdata->last_server_update = 0; wrote_data = true; + goto finish; + } + log_print(LOG_DEBUG, SECTION_FILECACHE_COMM, "%s: Seeking fd=%d", funcname, sdata->fd); + if ((lseek(sdata->fd, 0, SEEK_SET) == (off_t)-1) || inject_error(filecache_error_synclseek)) { + set_error(sdata, errno); + g_set_error(gerr, system_quark(), errno, "%s: failed lseek on %s", funcname, path); + goto finish; + } + put_return_etag(path, sdata->fd, pdata->etag, &tmpgerr); + if (tmpgerr) { + // Don't set error on cURL error; if dav_flush fails, we can still try again on dav_release + if (tmpgerr->code != E_FC_CURLERR) { + set_error(sdata, tmpgerr->code); + } + g_propagate_prefixed_error(gerr, tmpgerr, "%s: put_return_etag PUT failed on %s: ", funcname, path); + goto finish; + } + sdata->modified = false; + pdata->last_server_update = time(NULL); + wrote_data = true; - - // @REVIEW: If sdata->modified is false, we didn't change pdata, and if - // we didn't change pdata, why call filecache_pdata_set? Or am I wrong? - // Point the persistent cache to the new file content. +finish: + if (tmpgerr) { + free(pdata); + return wrote_data; + } + if (wrote_data) { filecache_pdata_set(cache, path, pdata, &tmpgerr); if (tmpgerr) { set_error(sdata, tmpgerr->code); - log_print(LOG_NOTICE, SECTION_FILECACHE_COMM, "filecache_sync: filecache_pdata_set failed on %s", path); - g_propagate_prefixed_error(gerr, tmpgerr, "filecache_sync: "); - goto finish; + g_propagate_prefixed_error(gerr, tmpgerr, "%s: ", funcname); } } - log_print(LOG_INFO, SECTION_FILECACHE_COMM, "filecache_sync: Updated stat cache %d:%s:%s:%lu", sdata->fd, path, pdata->filename, pdata->last_server_update); - -finish: - free(pdata); - - log_print(LOG_DEBUG, SECTION_FILECACHE_COMM, "filecache_sync: Done syncing file (%s, fd=%d).", path, sdata ? sdata->fd : -1); - return wrote_data; } // top-level truncate call void filecache_truncate(struct fuse_file_info *info, off_t s, GError **gerr) { - struct filecache_sdata *sdata = (struct filecache_sdata *)info->fh; - + fc_sdata *sdata = (fc_sdata *)info->fh; BUMP(filecache_truncate); - - if (sdata == NULL || inject_error(filecache_error_truncsdata)) { - g_set_error(gerr, filecache_quark(), E_FC_SDATANULL, "filecache_truncate: sdata is NULL"); - return; - } - - log_print(LOG_INFO, SECTION_FILECACHE_FILE, "filecache_truncate(%d)", sdata->fd); - - log_print(LOG_DEBUG, SECTION_FILECACHE_FLOCK, "filecache_truncate: acquiring shared file lock on fd %d", sdata->fd); - if (flock(sdata->fd, LOCK_SH) || inject_error(filecache_error_truncflock1)) { - g_set_error(gerr, system_quark(), errno, "filecache_truncate: error acquiring shared file lock"); - return; - } - log_print(LOG_DEBUG, SECTION_FILECACHE_FLOCK, "filecache_truncate: acquired shared file lock on fd %d", sdata->fd); - - if ((ftruncate(sdata->fd, s) < 0) || inject_error(filecache_error_truncftrunc)) { - g_set_error(gerr, system_quark(), errno, "filecache_truncate: ftruncate failed"); - // fall through to release lock ... - } - - log_print(LOG_DEBUG, SECTION_FILECACHE_FLOCK, "filecache_truncate: releasing shared file lock on fd %d", sdata->fd); - if (flock(sdata->fd, LOCK_UN) || inject_error(filecache_error_truncflock2)) { - if (!gerr) { - g_set_error(gerr, system_quark(), errno, "filecache_truncate: error releasing shared file lock"); - } - else { - log_print(LOG_CRIT, SECTION_FILECACHE_FILE, "filecache_truncate: error releasing shared file lock :: %s", g_strerror(errno)); - } - return; - } - - // If we got an error on ftruncate, we fell through to flock. If we didn't get an error there, we need - // to return before setting sdata modified. - if (gerr) return; - - log_print(LOG_DEBUG, SECTION_FILECACHE_FILE, "filecache_truncate: released shared file lock on fd %d", sdata->fd); - - sdata->modified = true; - + _filecache_truncate(sdata, s, gerr); return; } int filecache_fd(struct fuse_file_info *info) { - struct filecache_sdata *sdata = (struct filecache_sdata *)info->fh; + fc_sdata *sdata = (fc_sdata *)info->fh; BUMP(filecache_get_fd); @@ -1448,7 +1312,7 @@ int filecache_fd(struct fuse_file_info *info) { } void filecache_set_error(struct fuse_file_info *info, int error_code) { - struct filecache_sdata *sdata = (struct filecache_sdata *)info->fh; + fc_sdata *sdata = (fc_sdata *)info->fh; BUMP(filecache_set_error); set_error(sdata, error_code); @@ -1456,7 +1320,7 @@ void filecache_set_error(struct fuse_file_info *info, int error_code) { // deletes entry from ldb cache void filecache_delete(filecache_t *cache, const char *path, bool unlink_cachefile, GError **gerr) { - struct filecache_pdata *pdata; + fc_pdata *pdata; leveldb_writeoptions_t *options; GError *tmpgerr = NULL; char *key; @@ -1522,7 +1386,7 @@ static int clear_files(const char *filecache_path, time_t stamped_time, GError * snprintf(cachefile_path, PATH_MAX , "%s/%s", filecache_path, diriter->d_name) ; if (stat(cachefile_path, &stbuf) == -1) { - log_print(LOG_NOTICE, SECTION_FILECACHE_CLEAN, "%s: Unable to stat file: %s: %d %s", + log_print(LOG_NOTICE, SECTION_FILECACHE_CLEAN, "%s: Unable to stat file: %s: %d %s", fname, cachefile_path, errno, strerror(errno)); --ret; continue; @@ -1546,7 +1410,7 @@ static int clear_files(const char *filecache_path, time_t stamped_time, GError * ++visited; if (stbuf.st_mtime < stamped_time) { if (unlink(cachefile_path)) { - log_print(LOG_NOTICE, SECTION_FILECACHE_CLEAN, "%s: failed to unlink %s: %d %s", + log_print(LOG_NOTICE, SECTION_FILECACHE_CLEAN, "%s: failed to unlink %s: %d %s", fname, cachefile_path, errno, strerror(errno)); --ret; } @@ -1554,13 +1418,13 @@ static int clear_files(const char *filecache_path, time_t stamped_time, GError * ++unlinked; } else { - log_print(LOG_INFO, SECTION_FILECACHE_CLEAN, "%s: didn't unlink %s: %d %d", + log_print(LOG_INFO, SECTION_FILECACHE_CLEAN, "%s: didn't unlink %s: %d %d", fname, cachefile_path, stamped_time, stbuf.st_mtime); } } } closedir(dir); - log_print(LOG_INFO, SECTION_FILECACHE_CLEAN, "%s: visited %d files, unlinked %d, and had %d issues", + log_print(LOG_INFO, SECTION_FILECACHE_CLEAN, "%s: visited %d files, unlinked %d, and had %d issues", fname, visited, unlinked, ret); // return the number of files still left @@ -1569,7 +1433,7 @@ static int clear_files(const char *filecache_path, time_t stamped_time, GError * void filecache_forensic_haven(const char *cache_path, filecache_t *cache, const char *path, off_t fsize, GError **gerr) { const char *fname = "filecache_forensic_haven"; - struct filecache_pdata *pdata = NULL; + fc_pdata *pdata = NULL; char *bpath = NULL; char *bname; char *newpath = NULL; @@ -1652,14 +1516,14 @@ void filecache_forensic_haven(const char *cache_path, filecache_t *cache, const while (files_left >= files_kept && hours > 0) { files_left = clear_files(newpath, time(NULL) - (hours * 60 * 60), &subgerr); if (subgerr) { - log_print(LOG_ERR, SECTION_FILECACHE_FILE, - "%s: error on clear_files: %s -- %d: %s", + log_print(LOG_ERR, SECTION_FILECACHE_FILE, + "%s: error on clear_files: %s -- %d: %s", fname, subgerr->message, subgerr->code, g_strerror(subgerr->code)); break; } hours /= 4; - log_print(LOG_NOTICE, SECTION_FILECACHE_FILE, - "%s: files_left: %d; files_kept: %d; hours: %d", + log_print(LOG_NOTICE, SECTION_FILECACHE_FILE, + "%s: files_left: %d; files_kept: %d; hours: %d", fname, files_left, files_kept, hours); } free(newpath); @@ -1668,7 +1532,7 @@ void filecache_forensic_haven(const char *cache_path, filecache_t *cache, const } void filecache_pdata_move(filecache_t *cache, const char *old_path, const char *new_path, GError **gerr) { - struct filecache_pdata *pdata = NULL; + fc_pdata *pdata = NULL; GError *tmpgerr = NULL; BUMP(filecache_pdata_move); @@ -1708,6 +1572,32 @@ void filecache_pdata_move(filecache_t *cache, const char *old_path, const char * return; } +// mark filecache stale for path +void filecache_invalidate(filecache_t* cache, const char* path, GError** gerr) { + fc_pdata *pdata = NULL; + GError *subgerr = NULL; + const char* funcname = "filecache_invalidate"; + + pdata = filecache_pdata_get(cache, path, &subgerr); + if (subgerr) { + g_propagate_prefixed_error(gerr, subgerr, "%s: ", funcname); + return; + } + if (pdata == NULL) { + g_set_error(gerr, filecache_quark(), E_FC_PDATANULL, "%s: path %s does not exist.", funcname, path); + return; + } + // We mark the data invalidated by setting the last update very far in the past. + // This preserves the etag so we can still try it and get lucky, eg if the file + // content was updated, and then updated back to its previous value. + pdata->last_server_update = FILECACHE_INVALIDATED; + filecache_pdata_set(cache, path, pdata, &subgerr); + if (subgerr) { + g_propagate_prefixed_error(gerr, subgerr, "%s: ", funcname); + return; + } +} + // Does *not* allocate a new string. static const char *key2path(const char *key) { char *prefix; @@ -1780,7 +1670,7 @@ bool filecache_cleanup(filecache_t *cache, const char *cache_path, bool first, G // New round while (leveldb_iter_valid(iter)) { - const struct filecache_pdata *pdata; + const fc_pdata *pdata; const char *iterkey; const char *path; struct stat stbuf; @@ -1790,8 +1680,8 @@ bool filecache_cleanup(filecache_t *cache, const char *cache_path, bool first, G path = key2path(iterkey); // if path is null, we've gone past the filecache entries if (path == NULL) break; - pdata = (const struct filecache_pdata *)leveldb_iter_value(iter, &klen); - log_print(LOG_DEBUG, SECTION_FILECACHE_CLEAN, + pdata = (const fc_pdata *)leveldb_iter_value(iter, &klen); + log_print(LOG_DEBUG, SECTION_FILECACHE_CLEAN, "filecache_cleanup: Visiting %s :: %s", path, pdata ? pdata->filename : "no pdata"); if (pdata) { ++cached_files; @@ -1825,11 +1715,11 @@ bool filecache_cleanup(filecache_t *cache, const char *cache_path, bool first, G // total_size will be less the max cache size if (round > 1 && deleted_size > max_delete) { // Avoid the delete - log_print(LOG_INFO, SECTION_FILECACHE_CLEAN, + log_print(LOG_INFO, SECTION_FILECACHE_CLEAN, "filecache_cleanup: Too many deletions this round; not deleting %s", fname); // Print once per round that we've hit the limit if (pmsg) { - log_print(LOG_NOTICE, SECTION_FILECACHE_CLEAN, + log_print(LOG_NOTICE, SECTION_FILECACHE_CLEAN, "filecache_cleanup: Too many deletions this round; not deleting %s", fname); pmsg = false; } @@ -1853,19 +1743,19 @@ bool filecache_cleanup(filecache_t *cache, const char *cache_path, bool first, G // put a timestamp on the file ret = utime(fname, NULL); if (ret) { - log_print(LOG_NOTICE, SECTION_FILECACHE_CLEAN, - "filecache_cleanup: failed to update timestamp on \"%s\" for \"%s\" from ldb cache: %d - %s", + log_print(LOG_NOTICE, SECTION_FILECACHE_CLEAN, + "filecache_cleanup: failed to update timestamp on \"%s\" for \"%s\" from ldb cache: %d - %s", fname, path, errno, strerror(errno)); } } } else { - log_print(LOG_NOTICE, SECTION_FILECACHE_CLEAN, + log_print(LOG_NOTICE, SECTION_FILECACHE_CLEAN, "filecache_cleanup: pulled NULL pdata out of cache for %s", path); } leveldb_iter_next(iter); } - if (round == 1 && total_size <= max_cache_size) { + if (round == 1 && total_size <= max_cache_size) { // If the size of files when we started the first round was already less than max ... done = true; } else { @@ -1874,14 +1764,14 @@ bool filecache_cleanup(filecache_t *cache, const char *cache_path, bool first, G if (new_total_size <= max_cache_size) { // If the file size is now less than max cache size, exit - log_print(LOG_NOTICE, SECTION_FILECACHE_CLEAN, - "filecache_cleanup: Stopping, new total size is less than max: %lu", + log_print(LOG_NOTICE, SECTION_FILECACHE_CLEAN, + "filecache_cleanup: Stopping, new total size is less than max: %lu", new_total_size); done = true; } else if (age_out <= two_hours) { // Avoid being too aggressive. Leave two hours worth of files in the cache. // If the age out is less than two hours, exit even if file size is greater than max - log_print(LOG_NOTICE, SECTION_FILECACHE_CLEAN, + log_print(LOG_NOTICE, SECTION_FILECACHE_CLEAN, "filecache_cleanup: Stopping, age_out less than 2 hours: %lu", age_out); done = true; } else { @@ -1889,7 +1779,7 @@ bool filecache_cleanup(filecache_t *cache, const char *cache_path, bool first, G age_out /= 2; // But always leave max_cache_size in the cache max_delete = new_total_size - max_cache_size; - log_print(LOG_NOTICE, SECTION_FILECACHE_CLEAN, + log_print(LOG_NOTICE, SECTION_FILECACHE_CLEAN, "filecache_cleanup: new age_out: %lu and max_delete: %lu;", age_out, max_delete); } // If when we started there was more file content than max cache size, inform the caller so it can @@ -1897,14 +1787,14 @@ bool filecache_cleanup(filecache_t *cache, const char *cache_path, bool first, G reduce_interval = true; // In order to allow log searching to find sites which required a second or later round, log at NOTICE if (round > 1) { - log_print(LOG_NOTICE, SECTION_FILECACHE_CLEAN, + log_print(LOG_NOTICE, SECTION_FILECACHE_CLEAN, "filecache_cleanup: Completed round %d; new total_size: %lu, max: %lu, ageout: %lu, " - "new max_delete: %lu, done: %d", + "new max_delete: %lu, done: %d", round, new_total_size, max_cache_size, age_out, max_delete, done); } else { - log_print(LOG_NOTICE, SECTION_FILECACHE_CLEAN, + log_print(LOG_NOTICE, SECTION_FILECACHE_CLEAN, "filecache_cleanup: Completed first round; new total_size: %lu, max: %lu, ageout: %lu, " - "new max_delete: %lu, done: %d", + "new max_delete: %lu, done: %d", new_total_size, max_cache_size, age_out, max_delete, done); } } diff --git a/src/filecache.h b/src/filecache.h index b8425070..e364b72d 100644 --- a/src/filecache.h +++ b/src/filecache.h @@ -43,8 +43,8 @@ typedef leveldb_t filecache_t; void filecache_print_stats(void); void filecache_init(char *cache_path, GError **gerr); void filecache_delete(filecache_t *cache, const char *path, bool unlink, GError **gerr); -void filecache_open(char *cache_path, filecache_t *cache, const char *path, struct fuse_file_info *info, - bool grace, bool rw, GError **gerr); +void filecache_open(char *cache_path, filecache_t *cache, const char *path, struct fuse_file_info *info, + bool grace, GError **gerr); ssize_t filecache_read(struct fuse_file_info *info, char *buf, size_t size, off_t offset, GError **gerr); ssize_t filecache_write(struct fuse_file_info *info, const char *buf, size_t size, off_t offset, GError **gerr); void filecache_close(struct fuse_file_info *info, GError **gerr); @@ -54,6 +54,7 @@ int filecache_fd(struct fuse_file_info *info); void filecache_set_error(struct fuse_file_info *info, int error_code); void filecache_forensic_haven(const char *cache_path, filecache_t *cache, const char *path, off_t fsize, GError **gerr); void filecache_pdata_move(filecache_t *cache, const char *old_path, const char *new_path, GError **gerr); +void filecache_invalidate(filecache_t* cache, const char* path, GError** gerr); bool filecache_cleanup(filecache_t *cache, const char *cache_path, bool first, GError **gerr); struct curl_slist* enhanced_logging(struct curl_slist *slist, int log_level, int section, const char *format, ...); diff --git a/src/fusedav.c b/src/fusedav.c index 340a6345..6c4665ea 100644 --- a/src/fusedav.c +++ b/src/fusedav.c @@ -178,7 +178,7 @@ static void getdir_propfind_callback(__unused void *userdata, const char *path, struct stat_cache_value *existing = NULL; struct stat_cache_value value; rwp_t rwp = PROPFIND; - GError *subgerr1 = NULL ; + GError *subgerr1 = NULL; log_print(LOG_INFO, SECTION_FUSEDAV_PROP, "%s: %s (%lu)", funcname, path, status_code); @@ -420,6 +420,10 @@ static void getdir_propfind_callback(__unused void *userdata, const char *path, if (subgerr1) { g_propagate_prefixed_error(gerr, subgerr1, "%s: ", funcname); } + filecache_invalidate(config->cache, path, &subgerr1); + if (subgerr1) { + g_propagate_prefixed_error(gerr, subgerr1, "%s: ", funcname); + } } } @@ -1842,24 +1846,13 @@ static int dav_mknod(const char *path, mode_t mode, __unused dev_t rdev) { return 0; } -static bool write_flag(int flags) { - // O_RDWR technically belongs in the list, but since it might be used for files - // which are only read, I leave it out. - // O_CREAT on a file which already exists is a noop unless O_EXCL is also included. - // So, only respond if both are present. - if ((flags & O_WRONLY) || ((flags & O_CREAT) && (flags & O_EXCL)) || (flags & O_TRUNC) || (flags & O_APPEND)) { - return true; - } - return false; -} - static void do_open(const char *path, struct fuse_file_info *info, GError **gerr) { struct fusedav_config *config = fuse_get_context()->private_data; GError *tmpgerr = NULL; assert(info); - filecache_open(config->cache_path, config->cache, path, info, config->grace, write_flag(info->flags), &tmpgerr); + filecache_open(config->cache_path, config->cache, path, info, config->grace, &tmpgerr); if (tmpgerr) { g_propagate_prefixed_error(gerr, tmpgerr, "do_open: "); return; diff --git a/src/fusedav_config.c b/src/fusedav_config.c index 2b925547..5e8ea1f5 100644 --- a/src/fusedav_config.c +++ b/src/fusedav_config.c @@ -78,7 +78,7 @@ static int fusedav_opt_proc(void *data, const char *arg, int key, struct fuse_ar break; case KEY_IGNORE: - return 0; + return 0; case KEY_HELP: fprintf(stderr, @@ -130,6 +130,7 @@ static void print_config(struct fusedav_config *config) { log_print(LOG_DEBUG, SECTION_CONFIG_DEFAULT, "log_level %d", config->log_level); log_print(LOG_DEBUG, SECTION_CONFIG_DEFAULT, "log_level_by_section %s", config->log_level_by_section); log_print(LOG_DEBUG, SECTION_CONFIG_DEFAULT, "log_prefix %s", config->log_prefix); + log_print(LOG_DEBUG, SECTION_CONFIG_DEFAULT, "log_destination %s", config->log_destination); log_print(LOG_DEBUG, SECTION_CONFIG_DEFAULT, "max_file_size %d", config->max_file_size); log_print(LOG_DEBUG, SECTION_CONFIG_DEFAULT, "statsd_host %s", config->statsd_host); log_print(LOG_DEBUG, SECTION_CONFIG_DEFAULT, "statsd_port %s", config->statsd_port); @@ -156,6 +157,7 @@ run_as_gid=6f7a106722f74cc7bd96d4d06785ed78 log_level=5 log_level_by_section=0 log_prefix=6f7a106722f74cc7bd96d4d06785ed78 +log_destination=journal max_file_size=256 statsd_host=127.0.0.1 statsd_port=8126 @@ -198,6 +200,7 @@ static void parse_configs(struct fusedav_config *config, GError **gerr) { keytuple(fusedav, log_level, INT), keytuple(fusedav, log_level_by_section, STRING), keytuple(fusedav, log_prefix, STRING), + keytuple(fusedav, log_destination, STRING), keytuple(fusedav, max_file_size, INT), keytuple(fusedav, statsd_host, STRING), keytuple(fusedav, statsd_port, STRING), @@ -290,6 +293,7 @@ void configure_fusedav(struct fusedav_config *config, struct fuse_args *args, ch config->nodaemon = false; config->max_file_size = 256; // 256M config->log_level = 5; // default log_level: LOG_NOTICE + config->log_destination = JOURNAL; asprintf(&config->statsd_host, "%s", "127.0.0.1"); asprintf(&config->statsd_port, "%s", "8126"); @@ -312,7 +316,7 @@ void configure_fusedav(struct fusedav_config *config, struct fuse_args *args, ch asprintf(&user_agent, "FuseDAV/%s %s", PACKAGE_VERSION, config->log_prefix); - log_init(config->log_level, config->log_level_by_section, config->log_prefix); + log_init(config->log_level, config->log_level_by_section, config->log_prefix, config->log_destination); log_print(LOG_DEBUG, SECTION_CONFIG_DEFAULT, "log_level: %d.", config->log_level); if (stats_init(config->statsd_host, config->statsd_port) < 0) { diff --git a/src/fusedav_config.h b/src/fusedav_config.h index d32b3908..fc66d25c 100644 --- a/src/fusedav_config.h +++ b/src/fusedav_config.h @@ -52,6 +52,7 @@ struct fusedav_config { int log_level; char *log_level_by_section; char *log_prefix; + char *log_destination; int max_file_size; char *statsd_host; char *statsd_port; diff --git a/src/log.c b/src/log.c index 6dd6d3b4..c1c7efbf 100644 --- a/src/log.c +++ b/src/log.c @@ -26,6 +26,7 @@ #include #include #include +#include #include "log.h" #include "log_sections.h" @@ -53,10 +54,19 @@ __thread unsigned int LOG_DYNAMIC = LOG_INFO; // max size for strings in log_key_value array #define KVITEM_SIZE 64 +static const char *log_template = "{\"MESSAGE\": \"%s%s\", " + "\"PRIORITY\": %d, " + "\"USER_AGENT\": \"%s\", " + "\"SITE\": \"%s\", " + "\"ENVIRONMENT\": \"%s\", " + "\"HOST_ADDRESS\": \"%s\", " + "\"TID\": \"%lu\", " + "\"PACKAGE_VERSION\": \"%s\"}\n"; + static unsigned int global_log_level = 5; static unsigned int section_log_levels[SECTIONS] = {0}; static const char *log_key_value[KVITEMS]; - +static enum log_destination log_destination = JOURNAL; static const char *errlevel[] = {"EMERG: ", "ALERT: ", "CRIT: ", "ERR: ", "WARN: ", "NOTICE: ", "INFO: ", "DEBUG: "}; // From the base url get the site id and site env @@ -85,7 +95,7 @@ static void initialize_site(void) { } /* The log_prefix comes from fusedav.conf; the base_url from curl and fuse. */ -void log_init(unsigned int log_level, const char *log_level_by_section, const char *user_agent_abbrev) { +void log_init(unsigned int log_level, const char *log_level_by_section, const char *user_agent_abbrev, const char *destination) { unsigned int vlen; @@ -100,6 +110,10 @@ void log_init(unsigned int log_level, const char *log_level_by_section, const ch log_key_value[USER_AGENT_ABBREV] = "(null)"; } + if ((destination != NULL) && strncmp(destination, "stdout", sizeof("stdout")) == 0) { + log_destination = STDOUT; + } + initialize_site(); if (log_level_by_section == NULL) return; @@ -168,9 +182,22 @@ int logging(unsigned int log_level, unsigned int section) { } static int print_it(const char const *formatwithtid, const char const *msg, int log_level) { - int ret; - // fusedav-server standardizing on names BINDING, SITE, and ENVIRONMENT - ret = sd_journal_send("MESSAGE=%s%s", formatwithtid, msg, + if (log_destination == STDOUT) { + char * escaped = g_strescape(msg, NULL); + printf(log_template, + formatwithtid, escaped, + log_level, + get_user_agent(), + log_key_value[SITE], + log_key_value[ENVIRONMENT], + log_key_value[HOST_ADDRESS], + syscall(SYS_gettid), + PACKAGE_VERSION, + NULL); + free(escaped); + return 0; + } + return sd_journal_send("MESSAGE=%s%s", formatwithtid, msg, "PRIORITY=%d", log_level, "USER_AGENT=%s", get_user_agent(), "SITE=%s", log_key_value[SITE], @@ -179,7 +206,6 @@ static int print_it(const char const *formatwithtid, const char const *msg, int "TID=%lu", syscall(SYS_gettid), "PACKAGE_VERSION=%s", PACKAGE_VERSION, NULL); - return ret; } #define max_msg_sz 2048 @@ -196,7 +222,7 @@ int log_print(unsigned int log_level, unsigned int section, const char *format, assert(formatwithlevel); // print the intended message - ret = print_it(formatwithlevel, msg, log_level); + print_it(formatwithlevel, msg, log_level); // Check and see if we're no longer doing dynamic logging. If so, it will take effect after this call. Then print a message if (turning_off_dynamic_logging()) { diff --git a/src/log.h b/src/log.h index 971436fe..8c533867 100644 --- a/src/log.h +++ b/src/log.h @@ -22,7 +22,13 @@ extern __thread unsigned int LOG_DYNAMIC; -void log_init(unsigned int log_level, const char *log_level_by_section, const char *user_agent); +enum log_destination { + JOURNAL, + STDOUT +}; + + +void log_init(unsigned int log_level, const char *log_level_by_section, const char *user_agent, const char *destination); int log_print(unsigned int log_level, unsigned int section, const char *format, ...); int logging(unsigned int log_level, unsigned int section); void set_dynamic_logging(void); diff --git a/src/props.c b/src/props.c index 4470cf6c..e6db007e 100644 --- a/src/props.c +++ b/src/props.c @@ -68,7 +68,7 @@ struct propfind_state { static char *get_relative_path(UriUriA *base_uri, UriUriA *source_uri) { char *path = NULL; - char *segment; + char *segment = NULL; size_t segment_len = 0; UriPathSegmentA *cur_base = base_uri->pathHead; UriPathSegmentA *cur = source_uri->pathHead; @@ -89,12 +89,15 @@ static char *get_relative_path(UriUriA *base_uri, UriUriA *source_uri) { // Verify that we're done with the base path // and still have parts left of the main path. if (cur == NULL || cur_base != NULL) { - return NULL; + path = strdup(""); + return path; } // Iterate through the unique parts. while (cur != NULL) { segment_len = cur->text.afterLast - cur->text.first; + // we init segment to NULL so that this will always work + free(segment); segment = malloc(segment_len + 1); strncpy(segment, cur->text.first, segment_len); segment[segment_len] = '\0'; @@ -105,7 +108,6 @@ static char *get_relative_path(UriUriA *base_uri, UriUriA *source_uri) { else { char *oldpath = path; asprintf(&path, "%s/%s", oldpath, segment); - free(segment); free(oldpath); } cur = cur->next; @@ -146,14 +148,13 @@ static char *get_path_beyond_base(const char *source_url) { // Compute the relative path and store it to a string. path = get_relative_path(&base_uri, &source_uri); - // If we've got a NULL, it's just the base path. - if (path == NULL) { - path = strdup(""); + path_len = strlen(path); + + // it's just the base path. + if (path_len == 0 ) { goto finish; } - path_len = strlen(path); - // Drop any trailing slash. if (path[path_len - 1] == '/') { path[path_len - 1] = '\0'; diff --git a/src/session.c b/src/session.c index fe5fb9b8..8ec54df2 100644 --- a/src/session.c +++ b/src/session.c @@ -1298,6 +1298,8 @@ CURL *session_request_init(const char *path, const char *query_string, bool tmp_ curl_errbuf[0] = '\0'; curl_easy_setopt(session, CURLOPT_ERRORBUFFER, curl_errbuf); curl_easy_setopt(session, CURLOPT_VERBOSE, 1L); + // accept and decode all encodings with compiled support: let the server decide + curl_easy_setopt(session, CURLOPT_ACCEPT_ENCODING, ""); escaped_path = escape_except_slashes(session, path); if (escaped_path == NULL) { diff --git a/src/util.c b/src/util.c index f5307500..c7bae788 100644 --- a/src/util.c +++ b/src/util.c @@ -24,12 +24,24 @@ #include #include #include +#include #include #include "util.h" #include "log.h" #include "log_sections.h" +bool write_flag(int flags) { + // O_RDWR technically belongs in the list, but since it might be used for files + // which are only read, I leave it out. + // O_CREAT on a file which already exists is a noop unless O_EXCL is also included. + // So, only respond if both are present. + if ((flags & O_WRONLY) || ((flags & O_CREAT) && (flags & O_EXCL)) || (flags & O_TRUNC) || (flags & O_APPEND)) { + return true; + } + return false; +} + // Return value is allocated and must be freed. char *path_parent(const char *uri) { size_t len = strlen(uri); diff --git a/src/util.h b/src/util.h index ade7c570..6cbff44d 100644 --- a/src/util.h +++ b/src/util.h @@ -28,6 +28,7 @@ #include #include +bool write_flag(int flags); char *path_parent(const char *uri); // For GError