Verified Commit f353afe8 authored by Tommaso Tocci's avatar Tommaso Tocci
Browse files

performance: make syscalls loggin logging optional 

Syscall logging allows to log all syscalls but this will slow down the
execution.

Syscalls logging needs now to be explicitely enabled through the
definition of LOG_SYSCALLS at compile time.
parent 1ce85f25

ifs/CMakeLists.txt

+5 −0
Original line number Diff line number Diff line
@@ -64,6 +64,11 @@ find_package(Boost 1.53 REQUIRED 


find_package(Threads REQUIRED)



option(LOG_SYSCALLS "Enable logging for syscall interception. Trace log level must be set at rountine" OFF)

if(LOG_SYSCALLS)

    add_definitions(-DLOG_SYSCALLS)

endif()



option(USE_OFI_VERBS "Use libfabric plugin with verbs." OFF)

if (USE_OFI_VERBS)

    find_package(LibFabric REQUIRED)

ifs/src/preload/hooks.cpp

+51 −39
Original line number Diff line number Diff line
@@ -10,6 +10,18 @@ 
#include <fcntl.h>

#include <memory>





#ifdef LOG_SYSCALLS

    #define LOG_HOOK_TRACE(...) \

        do { \

            CTX->log()->strace(__VA_ARGS__); \

        } while(0);

#else

    #define LOG_HOOK_TRACE(...) \

        do {} while(0);

#endif





static inline int with_errno(int ret) {

    return (ret < 0)? -errno : ret;

}
@@ -17,7 +29,7 @@ static inline int with_errno(int ret) { 


int hook_openat(int dirfd, const char *cpath, int flags, mode_t mode) {



    CTX->log()->trace("{}() called with fd: {}, path: {}, flags: {}, mode: {}",

    LOG_HOOK_TRACE("{}() called with fd: {}, path: {}, flags: {}, mode: {}",

                       __func__, dirfd, cpath, flags, mode);



    std::string resolved;
@@ -42,7 +54,7 @@ int hook_openat(int dirfd, const char *cpath, int flags, mode_t mode) { 
}



int hook_close(int fd) {

    CTX->log()->trace("{}() called with fd {}", __func__, fd);

    LOG_HOOK_TRACE("{}() called with fd {}", __func__, fd);

    if(CTX->file_map()->exist(fd)) {

        // No call to the daemon is required

        CTX->file_map()->remove(fd);
@@ -52,7 +64,7 @@ int hook_close(int fd) { 
}



int hook_stat(const char* path, struct stat* buf) {

    CTX->log()->trace("{}() called with path '{}'", __func__, path);

    LOG_HOOK_TRACE("{}() called with path '{}'", __func__, path);

    std::string rel_path;

    if (CTX->relativize_path(path, rel_path)) {

            return with_errno(adafs_stat(rel_path, buf));
@@ -61,7 +73,7 @@ int hook_stat(const char* path, struct stat* buf) { 
}



int hook_lstat(const char* path, struct stat* buf) {

    CTX->log()->trace("{}() called with path '{}'", __func__, path);

    LOG_HOOK_TRACE("{}() called with path '{}'", __func__, path);

    std::string rel_path;

    if (CTX->relativize_path(path, rel_path, false)) {

        return with_errno(adafs_stat(rel_path, buf));
@@ -70,7 +82,7 @@ int hook_lstat(const char* path, struct stat* buf) { 
}



int hook_fstat(unsigned int fd, struct stat* buf) {

    CTX->log()->trace("{}() called with fd '{}'", __func__, fd);

    LOG_HOOK_TRACE("{}() called with fd '{}'", __func__, fd);

    if (CTX->file_map()->exist(fd)) {

        auto path = CTX->file_map()->get(fd)->path();

        return with_errno(adafs_stat(path, buf));
@@ -79,7 +91,7 @@ int hook_fstat(unsigned int fd, struct stat* buf) { 
}



int hook_fstatat(int dirfd, const char * cpath, struct stat * buf, int flags) {

    CTX->log()->trace("{}() called with path '{}' and fd {}", __func__, cpath, dirfd);

    LOG_HOOK_TRACE("{}() called with path '{}' and fd {}", __func__, cpath, dirfd);



    if(flags & AT_EMPTY_PATH) {

        CTX->log()->error("{}() AT_EMPTY_PATH flag not supported", __func__);
@@ -108,7 +120,7 @@ int hook_fstatat(int dirfd, const char * cpath, struct stat * buf, int flags) { 
}



int hook_read(unsigned int fd, void* buf, size_t count) {

    CTX->log()->trace("{}() called with fd {}, count {}", __func__, fd, count);

    LOG_HOOK_TRACE("{}() called with fd {}, count {}", __func__, fd, count);

    if (CTX->file_map()->exist(fd)) {

        return  with_errno(adafs_read(fd, buf, count));

    }
@@ -116,7 +128,7 @@ int hook_read(unsigned int fd, void* buf, size_t count) { 
}



int hook_pread(unsigned int fd, char * buf, size_t count, loff_t pos) {

    CTX->log()->trace("{}() called with fd {}, count {}, pos {}",

    LOG_HOOK_TRACE("{}() called with fd {}, count {}, pos {}",

                      __func__, fd, count, pos);

    if (CTX->file_map()->exist(fd)) {

        return with_errno(adafs_pread_ws(fd, buf, count, pos));
@@ -126,7 +138,7 @@ int hook_pread(unsigned int fd, char * buf, size_t count, loff_t pos) { 
}



int hook_write(unsigned int fd, const char * buf, size_t count) {

    CTX->log()->trace("{}() called with fd {}, count {}", __func__, fd, count);

    LOG_HOOK_TRACE("{}() called with fd {}, count {}", __func__, fd, count);

    if (CTX->file_map()->exist(fd)) {

        return with_errno(adafs_write(fd, buf, count));

    }
@@ -134,7 +146,7 @@ int hook_write(unsigned int fd, const char * buf, size_t count) { 
}



int hook_pwrite(unsigned int fd, const char * buf, size_t count, loff_t pos) {

    CTX->log()->trace("{}() called with fd {}, count {}, pos {}",

    LOG_HOOK_TRACE("{}() called with fd {}, count {}, pos {}",

                      __func__, fd, count, pos);

    if (CTX->file_map()->exist(fd)) {

        return with_errno(adafs_pwrite_ws(fd, buf, count, pos));
@@ -144,7 +156,7 @@ int hook_pwrite(unsigned int fd, const char * buf, size_t count, loff_t pos) { 
}



int hook_writev(unsigned long fd, const struct iovec * iov, unsigned long iovcnt) {

    CTX->log()->trace("{}() called with fd {}, ops_num {}", __func__, fd, iovcnt);

    LOG_HOOK_TRACE("{}() called with fd {}, ops_num {}", __func__, fd, iovcnt);

    if (CTX->file_map()->exist(fd)) {

        return with_errno(adafs_writev(fd, iov, iovcnt));

    }
@@ -153,7 +165,7 @@ int hook_writev(unsigned long fd, const struct iovec * iov, unsigned long iovcnt 


int hook_pwritev(unsigned long fd, const struct iovec * iov, unsigned long iovcnt,

                 unsigned long pos_l, unsigned long pos_h) {

    CTX->log()->trace("{}() called with fd {}, ops_num {}, low position {},"

    LOG_HOOK_TRACE("{}() called with fd {}, ops_num {}, low position {},"

                      "high postion {}", __func__, fd, iovcnt, pos_l, pos_h);

    if (CTX->file_map()->exist(fd)) {

        CTX->log()->warn("{}() Not supported", __func__);
@@ -163,7 +175,7 @@ int hook_pwritev(unsigned long fd, const struct iovec * iov, unsigned long iovcn 
}



int hook_unlinkat(int dirfd, const char * cpath, int flags) {

    CTX->log()->trace("{}() called with path '{}' dirfd {}, flags {}",

    LOG_HOOK_TRACE("{}() called with path '{}' dirfd {}, flags {}",

                      __func__, cpath, dirfd, flags);



    if ((flags & ~AT_REMOVEDIR) != 0) {
@@ -197,7 +209,7 @@ int hook_unlinkat(int dirfd, const char * cpath, int flags) { 
}



int hook_symlinkat(const char * oldname, int newdfd, const char * newname) {

    CTX->log()->trace("{}() called with oldname '{}', new fd {}, new name '{}'",

    LOG_HOOK_TRACE("{}() called with oldname '{}', new fd {}, new name '{}'",

                      __func__, oldname, newdfd, newname);



    std::string oldname_resolved;
@@ -230,7 +242,7 @@ int hook_symlinkat(const char * oldname, int newdfd, const char * newname) { 




int hook_access(const char* path, int mask) {

    CTX->log()->trace("{}() called path '{}', mask {}", __func__, path, mask);

    LOG_HOOK_TRACE("{}() called path '{}', mask {}", __func__, path, mask);

    std::string rel_path;

    if (CTX->relativize_path(path, rel_path)) {

        auto ret = adafs_access(rel_path, mask);
@@ -243,7 +255,7 @@ int hook_access(const char* path, int mask) { 
}



int hook_faccessat(int dirfd, const char * cpath, int mode) {

    CTX->log()->trace("{}() called with path '{}' dirfd {}, mode {}",

    LOG_HOOK_TRACE("{}() called with path '{}' dirfd {}, mode {}",

                      __func__, cpath, dirfd, mode);



    std::string resolved;
@@ -268,7 +280,7 @@ int hook_faccessat(int dirfd, const char * cpath, int mode) { 
}



int hook_lseek(unsigned int fd, off_t offset, unsigned int whence) {

    CTX->log()->trace("{}() called with fd {}, offset {}, whence {}", __func__, fd, offset, whence);

    LOG_HOOK_TRACE("{}() called with fd {}, offset {}, whence {}", __func__, fd, offset, whence);

    if (CTX->file_map()->exist(fd)) {

        auto off_ret = adafs_lseek(fd, static_cast<off64_t>(offset), whence);

        if (off_ret > std::numeric_limits<off_t>::max()) {
@@ -276,14 +288,14 @@ int hook_lseek(unsigned int fd, off_t offset, unsigned int whence) { 
        } else if(off_ret < 0) {

            return -errno;

        }

        CTX->log()->trace("{}() returning {}", __func__, off_ret);

        LOG_HOOK_TRACE("{}() returning {}", __func__, off_ret);

        return off_ret;

    }

   return syscall_no_intercept(SYS_lseek, fd, offset, whence);

}



int hook_truncate(const char* path, long length) {

    CTX->log()->trace("{}() called with path: {}, offset: {}", __func__, path, length);

    LOG_HOOK_TRACE("{}() called with path: {}, offset: {}", __func__, path, length);

    std::string rel_path;

    if (CTX->relativize_path(path, rel_path)) {

        return with_errno(adafs_truncate(rel_path, length));
@@ -292,7 +304,7 @@ int hook_truncate(const char* path, long length) { 
}



int hook_ftruncate(unsigned int fd, unsigned long length) {

    CTX->log()->trace("{}() called  [fd: {}, offset: {}]", __func__, fd, length);

    LOG_HOOK_TRACE("{}() called  [fd: {}, offset: {}]", __func__, fd, length);

    if (CTX->file_map()->exist(fd)) {

        auto path = CTX->file_map()->get(fd)->path();

        return with_errno(adafs_truncate(path, length));
@@ -301,7 +313,7 @@ int hook_ftruncate(unsigned int fd, unsigned long length) { 
}



int hook_dup(unsigned int fd) {

    CTX->log()->trace("{}() called with oldfd {}", __func__, fd);

    LOG_HOOK_TRACE("{}() called with oldfd {}", __func__, fd);

    if (CTX->file_map()->exist(fd)) {

        return with_errno(adafs_dup(fd));

    }
@@ -309,7 +321,7 @@ int hook_dup(unsigned int fd) { 
}



int hook_dup2(unsigned int oldfd, unsigned int newfd) {

    CTX->log()->trace("{}() called with fd {} newfd {}", __func__, oldfd, newfd);

    LOG_HOOK_TRACE("{}() called with fd {} newfd {}", __func__, oldfd, newfd);

    if (CTX->file_map()->exist(oldfd)) {

        return with_errno(adafs_dup2(oldfd, newfd));

    }
@@ -327,7 +339,7 @@ int hook_dup3(unsigned int oldfd, unsigned int newfd, int flags) { 
}



int hook_getdents(unsigned int fd, struct linux_dirent *dirp, unsigned int count) {

    CTX->log()->trace("{}() called with fd {}, count {}", __func__, fd, count);

    LOG_HOOK_TRACE("{}() called with fd {}, count {}", __func__, fd, count);

    if (CTX->file_map()->exist(fd)) {

        return with_errno(getdents(fd, dirp, count));

    }
@@ -335,7 +347,7 @@ int hook_getdents(unsigned int fd, struct linux_dirent *dirp, unsigned int count 
}



int hook_mkdirat(int dirfd, const char * cpath, mode_t mode) {

    CTX->log()->trace("{}() called with fd: {}, path: {}, mode: {}",

    LOG_HOOK_TRACE("{}() called with fd: {}, path: {}, mode: {}",

                      __func__, dirfd, cpath, mode);



    std::string resolved;
@@ -360,7 +372,7 @@ int hook_mkdirat(int dirfd, const char * cpath, mode_t mode) { 
}



int hook_fchmodat(int dirfd, const char * cpath, mode_t mode) {

    CTX->log()->trace("{}() called dirfd {}, path '{}', mode {}", __func__, dirfd, cpath, mode);

    LOG_HOOK_TRACE("{}() called dirfd {}, path '{}', mode {}", __func__, dirfd, cpath, mode);



    std::string resolved;

    auto rstatus = CTX->relativize_fd_path(dirfd, cpath, resolved);
@@ -385,7 +397,7 @@ int hook_fchmodat(int dirfd, const char * cpath, mode_t mode) { 
}



int hook_fchmod(unsigned int fd, mode_t mode) {

    CTX->log()->trace("{}() called with fd {}, mode {}", __func__, fd, mode);

    LOG_HOOK_TRACE("{}() called with fd {}, mode {}", __func__, fd, mode);

    if (CTX->file_map()->exist(fd)) {

        CTX->log()->warn("{}() operation not supported", __func__);

        return -ENOTSUP;
@@ -394,7 +406,7 @@ int hook_fchmod(unsigned int fd, mode_t mode) { 
}



int hook_chdir(const char * path) {

    CTX->log()->trace("{}() called with path '{}'", __func__, path);

    LOG_HOOK_TRACE("{}() called with path '{}'", __func__, path);

    std::string rel_path;

    bool internal = CTX->relativize_path(path, rel_path);

    if (internal) {
@@ -425,7 +437,7 @@ int hook_chdir(const char * path) { 
}



int hook_fchdir(unsigned int fd) {

    CTX->log()->trace("{}() called with fd {}", __func__, fd);

    LOG_HOOK_TRACE("{}() called with fd {}", __func__, fd);

    if (CTX->file_map()->exist(fd)) {

        auto open_file = CTX->file_map()->get(fd);

        auto open_dir = std::static_pointer_cast<OpenDir>(open_file);
@@ -460,7 +472,7 @@ int hook_fchdir(unsigned int fd) { 
}



int hook_getcwd(char * buf, unsigned long size) {

    CTX->log()->trace("{}() called with size {}", __func__, size);

    LOG_HOOK_TRACE("{}() called with size {}", __func__, size);

    if(CTX->cwd().size() + 1 > size) {

        CTX->log()->error("{}() buffer too small to host current working dir", __func__);

        return -ERANGE;
@@ -471,7 +483,7 @@ int hook_getcwd(char * buf, unsigned long size) { 
}



int hook_readlinkat(int dirfd, const char * cpath, char * buf, int bufsiz) {

    CTX->log()->trace("{}() called with path '{}' dirfd {}, bufsize {}",

    LOG_HOOK_TRACE("{}() called with path '{}' dirfd {}, bufsize {}",

                      __func__, cpath, dirfd, bufsiz);



    std::string resolved;
@@ -497,7 +509,7 @@ int hook_readlinkat(int dirfd, const char * cpath, char * buf, int bufsiz) { 
}



int hook_fcntl(unsigned int fd, unsigned int cmd, unsigned long arg) {

    CTX->log()->trace("{}() called with fd {}, cmd {}, arg {}", __func__, fd, cmd, arg);

    LOG_HOOK_TRACE("{}() called with fd {}, cmd {}, arg {}", __func__, fd, cmd, arg);

    if (!CTX->file_map()->exist(fd)) {

        return syscall_no_intercept(SYS_fcntl, fd, cmd, arg);

    }
@@ -505,11 +517,11 @@ int hook_fcntl(unsigned int fd, unsigned int cmd, unsigned long arg) { 
    switch (cmd) {



        case F_DUPFD:

            CTX->log()->trace("{}() F_DUPFD on fd {}", __func__, fd);

            LOG_HOOK_TRACE("{}() F_DUPFD on fd {}", __func__, fd);

            return with_errno(adafs_dup(fd));



        case F_DUPFD_CLOEXEC:

            CTX->log()->trace("{}() F_DUPFD_CLOEXEC on fd {}", __func__, fd);

            LOG_HOOK_TRACE("{}() F_DUPFD_CLOEXEC on fd {}", __func__, fd);

            ret = adafs_dup(fd);

            if(ret == -1) {

                return -errno;
@@ -518,7 +530,7 @@ int hook_fcntl(unsigned int fd, unsigned int cmd, unsigned long arg) { 
            return ret;



        case F_GETFD:

            CTX->log()->trace("{}() F_GETFD on fd {}", __func__, fd);

            LOG_HOOK_TRACE("{}() F_GETFD on fd {}", __func__, fd);

            if(CTX->file_map()->get(fd)

                    ->get_flag(OpenFile_flags::cloexec)) {

                return FD_CLOEXEC;
@@ -526,7 +538,7 @@ int hook_fcntl(unsigned int fd, unsigned int cmd, unsigned long arg) { 
            return 0;



        case F_GETFL:

            CTX->log()->trace("{}() F_GETFL on fd {}", __func__, fd);

            LOG_HOOK_TRACE("{}() F_GETFL on fd {}", __func__, fd);

            ret = 0;

            if(CTX->file_map()->get(fd)

                    ->get_flag(OpenFile_flags::rdonly)) {
@@ -543,7 +555,7 @@ int hook_fcntl(unsigned int fd, unsigned int cmd, unsigned long arg) { 
            return ret;



        case F_SETFD:

            CTX->log()->trace("{}() [fd: {}, cmd: F_SETFD, FD_CLOEXEC: {}]",

            LOG_HOOK_TRACE("{}() [fd: {}, cmd: F_SETFD, FD_CLOEXEC: {}]",

                __func__, fd, (arg & FD_CLOEXEC));

            CTX->file_map()->get(fd)

                ->set_flag(OpenFile_flags::cloexec, (arg & FD_CLOEXEC));
@@ -561,7 +573,7 @@ int hook_renameat(int olddfd, const char * oldname, 
                  int newdfd, const char * newname,

                  unsigned int flags) {



    CTX->log()->trace("{}() called with olddfd {}, oldname: '{}', newfd {}, newname '{}', flags {}",

    LOG_HOOK_TRACE("{}() called with olddfd {}, oldname: '{}', newfd {}, newname '{}', flags {}",

                      __func__, olddfd, oldname, newdfd, newname, flags);



    const char * oldpath_pass;
@@ -616,7 +628,7 @@ int hook_renameat(int olddfd, const char * oldname, 
}



int hook_statfs(const char * path, struct statfs * buf) {

    CTX->log()->trace("{}() called with path: {}", __func__, path);

    LOG_HOOK_TRACE("{}() called with path: {}", __func__, path);

    std::string rel_path;

    if (CTX->relativize_path(path, rel_path)) {

        return with_errno(adafs_statfs(buf));
@@ -625,7 +637,7 @@ int hook_statfs(const char * path, struct statfs * buf) { 
}



int hook_fstatfs(unsigned int fd, struct statfs * buf) {

    CTX->log()->trace("{}() called with fs: {}", __func__, fd);

    LOG_HOOK_TRACE("{}() called with fs: {}", __func__, fd);

    if (CTX->file_map()->exist(fd)) {

        return with_errno(adafs_statfs(buf));

    }

ifs/src/preload/intercept.cpp

+79 −28
Original line number Diff line number Diff line
@@ -15,7 +15,7 @@ 
#define HOOKED 0





static inline int hook(long syscall_number,

static inline void hook(long syscall_number,

         long arg0, long arg1, long arg2,

         long arg3, long arg4, long arg5,

         long *result)
@@ -284,22 +284,13 @@ static inline int hook(long syscall_number, 
        break;



    default:

        /*

         * Ignore any other syscalls

         * i.e.: pass them on to the kernel

         * as would normally happen.

         */



        #ifndef NDEBUG

        CTX->log()->trace("Syscall [{}, {}]  Passthrough", syscall_names[syscall_number], syscall_number);

        #endif

        return NOT_HOOKED;

        // Syscall have been already filtered in the wrapper

        // At this point there shuldn't be any unexpected syscalls

        // If you reach this point you miss some syscall litesed in the wrapper func

        assert(false);

        break;

    }



    #ifndef NDEBUG

    CTX->log()->trace("Syscall [{}, {}]  Intercepted", syscall_names[syscall_number], syscall_number);

    #endif

    return HOOKED;

}
@@ -310,6 +301,53 @@ hook_guard_wrapper(long syscall_number, 
                   long arg0, long arg1, long arg2,

                   long arg3, long arg4, long arg5,

                   long *syscall_return_value)

{

    switch (syscall_number) {



    case SYS_open:

    case SYS_creat:

    case SYS_openat:

    case SYS_close:

    case SYS_stat:

    case SYS_lstat:

    case SYS_fstat:

    case SYS_newfstatat:

    case SYS_read:

    case SYS_pread64:

    case SYS_pwrite64:

    case SYS_write:

    case SYS_writev:

    case SYS_pwritev:

    case SYS_unlink:

    case SYS_unlinkat:

    case SYS_rmdir:

    case SYS_symlink:

    case SYS_symlinkat:

    case SYS_access:

    case SYS_faccessat:

    case SYS_lseek:

    case SYS_truncate:

    case SYS_ftruncate:

    case SYS_dup:

    case SYS_dup2:

    case SYS_dup3:

    case SYS_getdents:

    case SYS_mkdirat:

    case SYS_mkdir:

    case SYS_chmod:

    case SYS_fchmod:

    case SYS_fchmodat:

    case SYS_chdir:

    case SYS_fchdir:

    case SYS_getcwd:

    case SYS_readlink:

    case SYS_readlinkat:

    case SYS_fcntl:

    case SYS_rename:

    case SYS_renameat:

    case SYS_renameat2:

    case SYS_fstatfs:

    case SYS_statfs:

    {

        assert(CTX->initialized());
@@ -317,17 +355,30 @@ hook_guard_wrapper(long syscall_number, 
            return NOT_HOOKED;

        }



    int is_hooked;

#ifdef LOG_SYSCALL

        CTX->log()->trace("Syscall [{}, {}]  Intercepted", syscall_names[syscall_number], syscall_number);

#endif



        guard_flag = true;

        int oerrno = errno;

    is_hooked = hook(syscall_number,

        hook(syscall_number,

                arg0, arg1, arg2, arg3, arg4, arg5,

                syscall_return_value);

        errno = oerrno;

        guard_flag = false;



    return is_hooked;

        return HOOKED;

    } break;



    default:

    {

        #ifdef LOG_SYSCALL

        CTX->log()->trace("Syscall [{}, {}]  Passthrough", syscall_names[syscall_number], syscall_number);

        #endif

        return NOT_HOOKED;

    } break;



    } // end switch case

}