diff --git a/include/znc/User.h b/include/znc/User.h index d9bcca6e..63dea4bc 100644 --- a/include/znc/User.h +++ b/include/znc/User.h @@ -110,6 +110,7 @@ class CUser { CString AddTimestamp(const CString& sStr) const; CString AddTimestamp(time_t tm, const CString& sStr) const; + CString AddTimestamp(timeval tv, const CString& sStr) const; void CloneNetworks(const CUser& User); bool Clone(const CUser& User, CString& sErrorRet, diff --git a/include/znc/Utils.h b/include/znc/Utils.h index 5cc74d84..8029f249 100644 --- a/include/znc/Utils.h +++ b/include/znc/Utils.h @@ -79,6 +79,21 @@ class CUtils { static CString CTime(time_t t, const CString& sTZ); static CString FormatTime(time_t t, const CString& sFormat, const CString& sTZ); + /** Supports an additional format specifier for formatting sub-second values: + * + * - %f - sub-second fraction + * - %3f - millisecond (default, if no width is specified) + * - %6f - microsecond + * + * However, note that timeval only supports microsecond precision + * (thus, formatting with higher-than-microsecond precision will + * always result in trailing zeroes), and IRC server-time is specified + * in millisecond precision (thus formatting received timestamps with + * higher-than-millisecond precision will always result in trailing + * zeroes). + */ + static CString FormatTime(const timeval& tv, const CString& sFormat, + const CString& sTZ); static CString FormatServerTime(const timeval& tv); static timeval ParseServerTime(const CString& sTime); static SCString GetTimezones(); diff --git a/modules/awaystore.cpp b/modules/awaystore.cpp index dc128551..b2a76b02 100644 --- a/modules/awaystore.cpp +++ b/modules/awaystore.cpp @@ -58,8 +58,8 @@ class CAwayJob : public CTimer { class CAway : public CModule { void AwayCommand(const CString& sCommand) { CString sReason; - time_t curtime; - time(&curtime); + timeval curtime; + gettimeofday(&curtime, nullptr); if (sCommand.Token(1) != "-quiet") { sReason = CUtils::FormatTime(curtime, sCommand.Token(1, true), diff --git a/modules/listsockets.cpp b/modules/listsockets.cpp index 55c67571..d3ec7170 100644 --- a/modules/listsockets.cpp +++ b/modules/listsockets.cpp @@ -154,8 +154,10 @@ class CListSockets : public CModule { CString GetCreatedTime(Csock* pSocket) { unsigned long long iStartTime = pSocket->GetStartTime(); - time_t iTime = iStartTime / 1000; - return CUtils::FormatTime(iTime, "%Y-%m-%d %H:%M:%S", + timeval tv; + tv.tv_sec = iStartTime / 1000; + tv.tv_usec = iStartTime % 1000 * 1000; + return CUtils::FormatTime(tv, "%Y-%m-%d %H:%M:%S.%f", GetUser()->GetTimezone()); } diff --git a/modules/log.cpp b/modules/log.cpp index 05685593..f1ac9fd8 100644 --- a/modules/log.cpp +++ b/modules/log.cpp @@ -271,9 +271,9 @@ void CLogMod::PutLog(const CString& sLine, } CString sPath; - time_t curtime; + timeval curtime; - time(&curtime); + gettimeofday(&curtime, nullptr); // Generate file name sPath = CUtils::FormatTime(curtime, m_sLogPath, GetUser()->GetTimezone()); if (sPath.empty()) { diff --git a/src/Buffer.cpp b/src/Buffer.cpp index a95d5e0d..14ef8ffa 100644 --- a/src/Buffer.cpp +++ b/src/Buffer.cpp @@ -52,7 +52,7 @@ CMessage CBufLine::ToMessage(const CClient& Client, mssThisParams["text"] = m_sText; } else { mssThisParams["text"] = - Client.GetUser()->AddTimestamp(Line.GetTime().tv_sec, m_sText); + Client.GetUser()->AddTimestamp(Line.GetTime(), m_sText); } // make a copy of params, because the following loop modifies the original diff --git a/src/User.cpp b/src/User.cpp index c853968b..718ba84a 100644 --- a/src/User.cpp +++ b/src/User.cpp @@ -603,17 +603,25 @@ CString& CUser::ExpandString(const CString& sStr, CString& sRet) const { } CString CUser::AddTimestamp(const CString& sStr) const { - time_t tm; - return AddTimestamp(time(&tm), sStr); + timeval tv; + gettimeofday(&tv, nullptr); + return AddTimestamp(tv, sStr); } CString CUser::AddTimestamp(time_t tm, const CString& sStr) const { + timeval tv; + tv.tv_sec = tm; + tv.tv_usec = 0; + return AddTimestamp(tv, sStr); +} + +CString CUser::AddTimestamp(timeval tv, const CString& sStr) const { CString sRet = sStr; if (!GetTimestampFormat().empty() && (m_bAppendTimestamp || m_bPrependTimestamp)) { CString sTimestamp = - CUtils::FormatTime(tm, GetTimestampFormat(), m_sTimezone); + CUtils::FormatTime(tv, GetTimestampFormat(), m_sTimezone); if (sTimestamp.empty()) { return sRet; } diff --git a/src/Utils.cpp b/src/Utils.cpp index e72f05bb..aedc6a76 100644 --- a/src/Utils.cpp +++ b/src/Utils.cpp @@ -498,6 +498,64 @@ CString CUtils::FormatTime(time_t t, const CString& sFormat, return s; } +CString CUtils::FormatTime(const timeval& tv, const CString& sFormat, + const CString& sTimezone) { + // Parse additional format specifiers before passing them to + // strftime, since the way strftime treats unknown format + // specifiers is undefined. + CString sFormat2; + + // Make sure %% is parsed correctly, i.e. %%f is passed through to + // strftime to become %f, and not 123. + bool bInFormat = false; + int iDigits; + CString::size_type uLastCopied = 0, uFormatStart; + + for (CString::size_type i = 0; i < sFormat.length(); i++) { + if (!bInFormat) { + if (sFormat[i] == '%') { + uFormatStart = i; + bInFormat = true; + iDigits = 3; + } + } else { + switch (sFormat[i]) { + case '0': case '1': case '2': case '3': case '4': + case '5': case '6': case '7': case '8': case '9': + iDigits = sFormat[i] - '0'; + break; + case 'f': { + int iVal = tv.tv_usec; + int iDigitDelta = iDigits - 6; // tv_user is in 10^-6 seconds + for (; iDigitDelta > 0; iDigitDelta--) + iVal *= 10; + for (; iDigitDelta < 0; iDigitDelta++) + iVal /= 10; + sFormat2 += sFormat.substr(uLastCopied, + uFormatStart - uLastCopied); + CString sVal = CString(iVal); + sFormat2 += CString(iDigits - sVal.length(), '0'); + sFormat2 += sVal; + uLastCopied = i + 1; + bInFormat = false; + break; + } + default: + bInFormat = false; + } + } + } + + if (uLastCopied) { + sFormat2 += sFormat.substr(uLastCopied); + return FormatTime(tv.tv_sec, sFormat2, sTimezone); + } else { + // If there are no extended format specifiers, avoid doing any + // memory allocations entirely. + return FormatTime(tv.tv_sec, sFormat, sTimezone); + } +} + CString CUtils::FormatServerTime(const timeval& tv) { CString s_msec(tv.tv_usec / 1000); while (s_msec.length() < 3) { diff --git a/test/UtilsTest.cpp b/test/UtilsTest.cpp index 9560d5c0..aed89deb 100644 --- a/test/UtilsTest.cpp +++ b/test/UtilsTest.cpp @@ -117,3 +117,43 @@ TEST(UtilsTest, ServerTime) { } tzset(); } + +class TimeTest : public testing::TestWithParam< + std::tuple> {}; + +TEST_P(TimeTest, FormatTime) { + timeval tv = std::get<0>(GetParam()); + EXPECT_EQ(std::get<1>(GetParam()), CUtils::FormatTime(tv, "%s.%f", "UTC")); + EXPECT_EQ(std::get<2>(GetParam()), CUtils::FormatTime(tv, "%s.%6f", "UTC")); + EXPECT_EQ(std::get<3>(GetParam()), CUtils::FormatTime(tv, "%s.%9f", "UTC")); +} + +INSTANTIATE_TEST_CASE_P( + TimeTest, TimeTest, + testing::Values( + // leading zeroes + std::make_tuple(timeval{42, 12345}, "42.012", "42.012345", "42.012345000"), + // (no) rounding + std::make_tuple(timeval{42, 999999}, "42.999", "42.999999", "42.999999000"), + // no tv_usec part + std::make_tuple(timeval{42, 0}, "42.000", "42.000000", "42.000000000"))); + +TEST(UtilsTest, FormatTime) { + // Test passthrough + timeval tv1; + tv1.tv_sec = 42; + tv1.tv_usec = 123456; + CString str1 = CUtils::FormatTime(tv1, "%s", "UTC"); + EXPECT_EQ("42", str1); + + // Test escapes + timeval tv2; + tv2.tv_sec = 42; + tv2.tv_usec = 123456; + CString str2 = CUtils::FormatTime(tv2, "%%f", "UTC"); + EXPECT_EQ("%f", str2); + + // Test suffix + CString str3 = CUtils::FormatTime(tv2, "a%fb", "UTC"); + EXPECT_EQ("a123b", str3); +}