Loading include/client/logging.hpp +135 −13 Original line number Diff line number Diff line Loading @@ -179,6 +179,138 @@ log_buffer(int fd, const void* buffer, std::size_t length) { ::syscall_no_intercept(SYS_write, fd, buffer, length); } /** * @brief convert a time_t to a tm * It is not POSIX compliant, but it dows not uses any syscall or timezone * Converts a Unix timestamp (number of seconds since the beginning of 1970 * CE) to a Gregorian civil date-time tuple in GMT (UTC) time zone. * * This conforms to C89 (and C99...) and POSIX. * * This implementation works, and doesn't overflow for any sizeof(time_t). * It doesn't check for overflow/underflow in tm->tm_year output. Other than * that, it never overflows or underflows. It assumes that that time_t is * signed. * * This implements the inverse of the POSIX formula * (http://pubs.opengroup.org/onlinepubs/9699919799/basedefs/V1_chap04.html#tag_04_15) * for all time_t values, no matter the size, as long as tm->tm_year doesn't * overflow or underflow. The formula is: tm_sec + tm_min*60 + tm_hour*3600 * + tm_yday*86400 + (tm_year-70)*31536000 + ((tm_year-69)/4)*86400 - * ((tm_year-1)/100)*86400 + ((tm_year+299)/400)*86400. * * License : GNU General Public License v2.0 from * https://github.com/pts/minilibc686/ * @param time_t * @return tm */ static inline struct tm* mini_gmtime_r(const time_t* timep, struct tm* tm) { const time_t ts = *timep; time_t t = ts / 86400; unsigned hms = ts % 86400; /* -86399 <= hms <= 86399. This needs sizeof(int) >= 4. */ time_t c, f; unsigned yday; /* 0 <= yday <= 426. Also fits to an `unsigned short', but `int' is faster. */ unsigned a; /* 0 <= a <= 2133. Also fits to an `unsigned short', but `int' is faster. */ if((int) hms < 0) { --t; hms += 86400; } /* Fix quotient and negative remainder if ts was negative (i.e. before year 1970 CE). */ /* Now: -24856 <= t <= 24855. */ tm->tm_sec = hms % 60; hms /= 60; tm->tm_min = hms % 60; tm->tm_hour = hms / 60; if(sizeof(time_t) > 4) { /* Optimization. For int32_t, this would keep t intact, so we won't have to do it. This produces unreachable code. */ f = (t + 4) % 7; if(f < 0) f += 7; /* Fix negative remainder if (t + 4) was negative. */ /* Now 0 <= f <= 6. */ tm->tm_wday = f; c = (t << 2) + 102032; f = c / 146097; if(c % 146097 < 0) --f; /* Fix negative remainder if c was negative. */ --f; t += f; f >>= 2; t -= f; f = (t << 2) + 102035; c = f / 1461; if(f % 1461 < 0) --c; /* Fix negative remainder if f was negative. */ } else { tm->tm_wday = (t + 24861) % 7; /* t + 24861 >= 0. */ /* Now: -24856 <= t <= 24855. */ c = ((t << 2) + 102035) / 1461; } yday = t - 365 * c - (c >> 2) + 25568; /* Now: 0 <= yday <= 425. */ a = yday * 5 + 8; /* Now: 8 <= a <= 2133. */ tm->tm_mon = a / 153; a %= 153; /* No need to fix if a < 0, because a cannot be negative here. */ /* Now: 2 <= tm->tm_mon <= 13. */ /* Now: 0 <= a <= 152. */ tm->tm_mday = 1 + a / 5; /* No need to fix if a < 0, because a cannot be negative here. */ /* Now: 1 <= tm->tm_mday <= 31. */ if(tm->tm_mon >= 12) { tm->tm_mon -= 12; /* Now: 0 <= tm->tm_mon <= 1. */ ++c; yday -= 366; } else { /* Check for leap year (in c). */ /* Now: 2 <= tm->tm_mon <= 11. */ /* 1903: not leap; 1904: leap, 1900: not leap; 2000: leap */ /* With sizeof(time_t) == 4, we have 1901 <= year <= 2038; of these * years only 2000 is divisble by 100, and that's a leap year, no we * optimize the check to `(c & 3) == 0' only. */ if(!((c & 3) == 0 && (sizeof(time_t) <= 4 || c % 100 != 0 || (c + 300) % 400 == 0))) --yday; /* These `== 0' comparisons work even if c < 0. */ } tm->tm_year = c; /* This assignment may overflow or underflow, we don't check it. Example: time_t is a huge int64_t, tm->tm_year is int32_t. */ /* Now: 0 <= tm->tm_mon <= 11. */ /* Now: 0 <= yday <= 365. */ tm->tm_yday = yday; tm->tm_isdst = 0; return tm; } static inline struct tm* mini_gmtime(const time_t* timep) { static struct tm tm; return mini_gmtime_r(timep, &tm); } static inline ssize_t format_timeval(struct timeval* tv, char* buf, size_t sz) { ssize_t written = -1; struct tm* gm = mini_gmtime(&tv->tv_sec); written = (ssize_t) strftime(buf, sz, "%Y-%m-%d %H:%M:%S", gm); if((written > 0) && ((size_t) written < sz)) { int w = snprintf(buf + written, sz - (size_t) written, ".%06ld", tv->tv_usec); written = (w > 0) ? written + w : -1; } return written; } /** * format_timestamp_to - safely format a timestamp for logging messages * Loading Loading @@ -212,21 +344,11 @@ format_timestamp_to(Buffer&& buffer, return; } date::sys_time<std::chrono::microseconds> now{ std::chrono::seconds{tv.tv_sec} + std::chrono::microseconds{tv.tv_usec}}; char buf[28]; if(!timezone) { fmt::format_to(std::back_inserter(buffer), "[{}] ", now.time_since_epoch().count()); return; if(format_timeval(&tv, buf, sizeof(buf)) > 0) { fmt::format_to(std::back_inserter(buffer), "[{}] ", buf); } auto str = format("%F %T", date::zoned_time<std::chrono::microseconds>{timezone, now}); fmt::format_to(std::back_inserter(buffer), "[{}] ", str); } template <typename Buffer> Loading src/client/CMakeLists.txt +0 −2 Original line number Diff line number Diff line Loading @@ -86,7 +86,6 @@ target_link_libraries( hermes fmt::fmt Threads::Threads Date::TZ Syscall_intercept::Syscall_intercept ) Loading @@ -98,7 +97,6 @@ target_link_libraries( hermes fmt::fmt Threads::Threads Date::TZ ) install( Loading src/client/logging.cpp +1 −41 Original line number Diff line number Diff line Loading @@ -32,11 +32,7 @@ #include <client/make_array.hpp> #include <regex> #include <filesystem> extern "C" { #include <date/tz.h> #include <fmt/ostream.h> } #include <ctime> #ifdef GKFS_ENABLE_LOGGING Loading @@ -46,9 +42,6 @@ extern "C" { namespace fs = std::filesystem; namespace { [[maybe_unused]] thread_local bool avoid_logging; } namespace { enum class split_str_mode { is_any_of, Loading Loading @@ -338,34 +331,6 @@ logger::logger(const std::string& opts, const std::string& path, log_fd_ = fd; } // Finding the current timezone implies accessing OS files (i.e. syscalls), // but current_zone() doesn't actually retrieve the time zone but rather // provides a descriptor to it that is **atomically initialized** upon its // first use. Thus, if we don't force the initialization here, logging the // first intercepted syscall will produce a call to date::time_zone::init() // (under std::call_once) which internally ends up calling fopen(). Since // fopen() ends up calling sys_open(), we will need to generate another // timestamp for a system call log entry, which will attempt to call // date::time_zone::init() since the prior initialization (under the same // std::call_once) has not yet completed. // // Unfortunately, date::time_zone doesn't provide a function to prevent // this lazy initialization, therefore we force it by requesting // information from an arbitrary timepoint (January 1st 1970) which forces // the initialization. This doesn't do any actual work and could safely be // removed if the date API ends up providing this functionality. try { timezone_ = date::current_zone(); #ifdef GKFS_DEBUG_BUILD using namespace date; timezone_->get_info(date::sys_days{January / 1 / 1970}); #endif // GKFS_DEBUG_BUILD } catch(const std::exception& ex) { // if timezone initialization fails, setting timezone_ to nullptr // makes format_timestamp_to() default to producing epoch timestamps timezone_ = nullptr; } #ifdef GKFS_ENABLE_LOGGING const auto log_hermes_message = [](const std::string& msg, hermes::log::level l, int severity, Loading Loading @@ -493,10 +458,6 @@ logger::log_syscall(syscall::info info, const long syscall_number, print_syscall: if(::avoid_logging) { return; } ::avoid_logging = true; fmt::basic_memory_buffer<char, max_buffer_size> buffer; detail::format_timestamp_to(buffer, timezone_); Loading @@ -511,7 +472,6 @@ print_syscall: fmt::format_to(std::back_inserter(buffer), "\n"); ::syscall_no_intercept(SYS_write, log_fd_, buffer.data(), buffer.size()); ::avoid_logging = false; } } // namespace gkfs::log Loading
include/client/logging.hpp +135 −13 Original line number Diff line number Diff line Loading @@ -179,6 +179,138 @@ log_buffer(int fd, const void* buffer, std::size_t length) { ::syscall_no_intercept(SYS_write, fd, buffer, length); } /** * @brief convert a time_t to a tm * It is not POSIX compliant, but it dows not uses any syscall or timezone * Converts a Unix timestamp (number of seconds since the beginning of 1970 * CE) to a Gregorian civil date-time tuple in GMT (UTC) time zone. * * This conforms to C89 (and C99...) and POSIX. * * This implementation works, and doesn't overflow for any sizeof(time_t). * It doesn't check for overflow/underflow in tm->tm_year output. Other than * that, it never overflows or underflows. It assumes that that time_t is * signed. * * This implements the inverse of the POSIX formula * (http://pubs.opengroup.org/onlinepubs/9699919799/basedefs/V1_chap04.html#tag_04_15) * for all time_t values, no matter the size, as long as tm->tm_year doesn't * overflow or underflow. The formula is: tm_sec + tm_min*60 + tm_hour*3600 * + tm_yday*86400 + (tm_year-70)*31536000 + ((tm_year-69)/4)*86400 - * ((tm_year-1)/100)*86400 + ((tm_year+299)/400)*86400. * * License : GNU General Public License v2.0 from * https://github.com/pts/minilibc686/ * @param time_t * @return tm */ static inline struct tm* mini_gmtime_r(const time_t* timep, struct tm* tm) { const time_t ts = *timep; time_t t = ts / 86400; unsigned hms = ts % 86400; /* -86399 <= hms <= 86399. This needs sizeof(int) >= 4. */ time_t c, f; unsigned yday; /* 0 <= yday <= 426. Also fits to an `unsigned short', but `int' is faster. */ unsigned a; /* 0 <= a <= 2133. Also fits to an `unsigned short', but `int' is faster. */ if((int) hms < 0) { --t; hms += 86400; } /* Fix quotient and negative remainder if ts was negative (i.e. before year 1970 CE). */ /* Now: -24856 <= t <= 24855. */ tm->tm_sec = hms % 60; hms /= 60; tm->tm_min = hms % 60; tm->tm_hour = hms / 60; if(sizeof(time_t) > 4) { /* Optimization. For int32_t, this would keep t intact, so we won't have to do it. This produces unreachable code. */ f = (t + 4) % 7; if(f < 0) f += 7; /* Fix negative remainder if (t + 4) was negative. */ /* Now 0 <= f <= 6. */ tm->tm_wday = f; c = (t << 2) + 102032; f = c / 146097; if(c % 146097 < 0) --f; /* Fix negative remainder if c was negative. */ --f; t += f; f >>= 2; t -= f; f = (t << 2) + 102035; c = f / 1461; if(f % 1461 < 0) --c; /* Fix negative remainder if f was negative. */ } else { tm->tm_wday = (t + 24861) % 7; /* t + 24861 >= 0. */ /* Now: -24856 <= t <= 24855. */ c = ((t << 2) + 102035) / 1461; } yday = t - 365 * c - (c >> 2) + 25568; /* Now: 0 <= yday <= 425. */ a = yday * 5 + 8; /* Now: 8 <= a <= 2133. */ tm->tm_mon = a / 153; a %= 153; /* No need to fix if a < 0, because a cannot be negative here. */ /* Now: 2 <= tm->tm_mon <= 13. */ /* Now: 0 <= a <= 152. */ tm->tm_mday = 1 + a / 5; /* No need to fix if a < 0, because a cannot be negative here. */ /* Now: 1 <= tm->tm_mday <= 31. */ if(tm->tm_mon >= 12) { tm->tm_mon -= 12; /* Now: 0 <= tm->tm_mon <= 1. */ ++c; yday -= 366; } else { /* Check for leap year (in c). */ /* Now: 2 <= tm->tm_mon <= 11. */ /* 1903: not leap; 1904: leap, 1900: not leap; 2000: leap */ /* With sizeof(time_t) == 4, we have 1901 <= year <= 2038; of these * years only 2000 is divisble by 100, and that's a leap year, no we * optimize the check to `(c & 3) == 0' only. */ if(!((c & 3) == 0 && (sizeof(time_t) <= 4 || c % 100 != 0 || (c + 300) % 400 == 0))) --yday; /* These `== 0' comparisons work even if c < 0. */ } tm->tm_year = c; /* This assignment may overflow or underflow, we don't check it. Example: time_t is a huge int64_t, tm->tm_year is int32_t. */ /* Now: 0 <= tm->tm_mon <= 11. */ /* Now: 0 <= yday <= 365. */ tm->tm_yday = yday; tm->tm_isdst = 0; return tm; } static inline struct tm* mini_gmtime(const time_t* timep) { static struct tm tm; return mini_gmtime_r(timep, &tm); } static inline ssize_t format_timeval(struct timeval* tv, char* buf, size_t sz) { ssize_t written = -1; struct tm* gm = mini_gmtime(&tv->tv_sec); written = (ssize_t) strftime(buf, sz, "%Y-%m-%d %H:%M:%S", gm); if((written > 0) && ((size_t) written < sz)) { int w = snprintf(buf + written, sz - (size_t) written, ".%06ld", tv->tv_usec); written = (w > 0) ? written + w : -1; } return written; } /** * format_timestamp_to - safely format a timestamp for logging messages * Loading Loading @@ -212,21 +344,11 @@ format_timestamp_to(Buffer&& buffer, return; } date::sys_time<std::chrono::microseconds> now{ std::chrono::seconds{tv.tv_sec} + std::chrono::microseconds{tv.tv_usec}}; char buf[28]; if(!timezone) { fmt::format_to(std::back_inserter(buffer), "[{}] ", now.time_since_epoch().count()); return; if(format_timeval(&tv, buf, sizeof(buf)) > 0) { fmt::format_to(std::back_inserter(buffer), "[{}] ", buf); } auto str = format("%F %T", date::zoned_time<std::chrono::microseconds>{timezone, now}); fmt::format_to(std::back_inserter(buffer), "[{}] ", str); } template <typename Buffer> Loading
src/client/CMakeLists.txt +0 −2 Original line number Diff line number Diff line Loading @@ -86,7 +86,6 @@ target_link_libraries( hermes fmt::fmt Threads::Threads Date::TZ Syscall_intercept::Syscall_intercept ) Loading @@ -98,7 +97,6 @@ target_link_libraries( hermes fmt::fmt Threads::Threads Date::TZ ) install( Loading
src/client/logging.cpp +1 −41 Original line number Diff line number Diff line Loading @@ -32,11 +32,7 @@ #include <client/make_array.hpp> #include <regex> #include <filesystem> extern "C" { #include <date/tz.h> #include <fmt/ostream.h> } #include <ctime> #ifdef GKFS_ENABLE_LOGGING Loading @@ -46,9 +42,6 @@ extern "C" { namespace fs = std::filesystem; namespace { [[maybe_unused]] thread_local bool avoid_logging; } namespace { enum class split_str_mode { is_any_of, Loading Loading @@ -338,34 +331,6 @@ logger::logger(const std::string& opts, const std::string& path, log_fd_ = fd; } // Finding the current timezone implies accessing OS files (i.e. syscalls), // but current_zone() doesn't actually retrieve the time zone but rather // provides a descriptor to it that is **atomically initialized** upon its // first use. Thus, if we don't force the initialization here, logging the // first intercepted syscall will produce a call to date::time_zone::init() // (under std::call_once) which internally ends up calling fopen(). Since // fopen() ends up calling sys_open(), we will need to generate another // timestamp for a system call log entry, which will attempt to call // date::time_zone::init() since the prior initialization (under the same // std::call_once) has not yet completed. // // Unfortunately, date::time_zone doesn't provide a function to prevent // this lazy initialization, therefore we force it by requesting // information from an arbitrary timepoint (January 1st 1970) which forces // the initialization. This doesn't do any actual work and could safely be // removed if the date API ends up providing this functionality. try { timezone_ = date::current_zone(); #ifdef GKFS_DEBUG_BUILD using namespace date; timezone_->get_info(date::sys_days{January / 1 / 1970}); #endif // GKFS_DEBUG_BUILD } catch(const std::exception& ex) { // if timezone initialization fails, setting timezone_ to nullptr // makes format_timestamp_to() default to producing epoch timestamps timezone_ = nullptr; } #ifdef GKFS_ENABLE_LOGGING const auto log_hermes_message = [](const std::string& msg, hermes::log::level l, int severity, Loading Loading @@ -493,10 +458,6 @@ logger::log_syscall(syscall::info info, const long syscall_number, print_syscall: if(::avoid_logging) { return; } ::avoid_logging = true; fmt::basic_memory_buffer<char, max_buffer_size> buffer; detail::format_timestamp_to(buffer, timezone_); Loading @@ -511,7 +472,6 @@ print_syscall: fmt::format_to(std::back_inserter(buffer), "\n"); ::syscall_no_intercept(SYS_write, log_fd_, buffer.data(), buffer.size()); ::avoid_logging = false; } } // namespace gkfs::log