Author: tschoening Date: Tue Feb 18 21:46:35 2014 New Revision: 1569535 URL: http://svn.apache.org/r1569535 Log: LOGCXX-425: Changed the calculation of millis in a formatted string again and added another tests for LOGCXX-420. There's some debug output in there which need to get removed later, but for now I need some help in defining the correct behavior and want others to be able to test themselves.
Modified: incubator/log4cxx/trunk/src/main/cpp/cacheddateformat.cpp incubator/log4cxx/trunk/src/test/cpp/helpers/cacheddateformattestcase.cpp Modified: incubator/log4cxx/trunk/src/main/cpp/cacheddateformat.cpp URL: http://svn.apache.org/viewvc/incubator/log4cxx/trunk/src/main/cpp/cacheddateformat.cpp?rev=1569535&r1=1569534&r2=1569535&view=diff ============================================================================== --- incubator/log4cxx/trunk/src/main/cpp/cacheddateformat.cpp (original) +++ incubator/log4cxx/trunk/src/main/cpp/cacheddateformat.cpp Tue Feb 18 21:46:35 2014 @@ -132,24 +132,38 @@ int CachedDateFormat::findMillisecondSta LogString plusZero; formatter->format(plusZero, slotBegin, pool); - // If the next 1..3 characters match the magic string, depending on if the currently - // used millis overlap with the magic string, and the remaining fragments are identical. - // Because magic string and currently used millis can overlap, i is not always the index - // of the first millis char. - // - // LOG4CXX-420: - // pattern: %d{yyyy-MM-dd HH:mm:ss,SSS} - // formatted: 2010-08-12 11:04:50,609 - // plusMagic: 2010-08-12 11:04:50,654 - // plusZero: 2010-08-12 11:04:50,000 - int possibleRetVal = i - (3 - (formatted.length() - i)); + // Test if the next 1..3 characters match the magic string, main problem is that magic + // available millis in formatted can overlap. Therefore the current i is not always the + // index of the first millis char, but may be already within the millis. Besides that + // the millis can occur everywhere in formatted. See LOGCXX-420 and following. + size_t magicLength = magicString.length(); + size_t overlapping = magicString.find(plusMagic[i]); + int possibleRetVal = i - overlapping; + +wprintf(L"formatted: %s\n", formatted.c_str()); +wprintf(L"formattedMillis: %s\n", formattedMillis.c_str()); +wprintf(L"magicString: %s\n", magicString.c_str()); +wprintf(L"plusMagic: %s\n", plusMagic.c_str()); +wprintf(L"plusZero: %s\n", plusZero.c_str()); + +printf("i: %i\n", i); +printf("formatted.length(): %i\n", formatted.length()); +printf("overlapping: %i\n", overlapping); +printf("possibleRetVal: %i\n", possibleRetVal); + +printf("1: %i\n", regionMatches(magicString, 0, plusMagic, possibleRetVal, magicLength)); +printf("2: %i\n", regionMatches(formattedMillis, 0, formatted, possibleRetVal, magicLength)); +printf("3: %i\n", regionMatches(zeroString, 0, plusZero, possibleRetVal, magicLength)); +printf("4: %i\n", formatted.length() == possibleRetVal + magicLength); +printf("5: %i\n", plusZero.compare(possibleRetVal + magicLength, LogString::npos, plusMagic, possibleRetVal + magicLength, LogString::npos) == 0); + if (plusZero.length() == formatted.length() - && regionMatches(magicString, 0, plusMagic, possibleRetVal, plusMagic.length() - possibleRetVal) - && regionMatches(formattedMillis, 0, formatted, possibleRetVal, formatted.length() - possibleRetVal) - && regionMatches(zeroString, 0, plusZero, possibleRetVal, plusZero.length() - possibleRetVal) - && (formatted.length() == possibleRetVal + (formatted.length() - possibleRetVal) - || plusZero.compare(possibleRetVal + (plusZero.length() - possibleRetVal), - LogString::npos, plusMagic, possibleRetVal + (plusMagic.length() - possibleRetVal), LogString::npos) == 0)) { + && regionMatches(magicString, 0, plusMagic, possibleRetVal, magicLength) + && regionMatches(formattedMillis, 0, formatted, possibleRetVal, magicLength) + && regionMatches(zeroString, 0, plusZero, possibleRetVal, magicLength) + /*&& (formatted.length() == possibleRetVal + magicLength + || plusZero.compare(possibleRetVal + magicLength, + LogString::npos, plusMagic, possibleRetVal + magicLength, LogString::npos) == 0)*/) { return possibleRetVal; } else { return UNRECOGNIZED_MILLISECONDS; @@ -183,18 +197,16 @@ int CachedDateFormat::findMillisecondSta // (that is if it was found or milliseconds did not appear) // if (millisecondStart != UNRECOGNIZED_MILLISECONDS) { - // Check if the cache is still valid. // If the requested time is within the same integral second // as the last request and a shorter expiration was not requested. if (now < slotBegin + expiration && now >= slotBegin && now < slotBegin + 1000000L) { - // // if there was a millisecond field then update it // - if (millisecondStart >= 0 ) { + if (millisecondStart >= 0) { millisecondFormat((int) ((now - slotBegin)/1000), cache, millisecondStart); } // @@ -202,11 +214,11 @@ int CachedDateFormat::findMillisecondSta // (the slot begin should be unchanged) previousTime = now; buf.append(cache); + return; } } - // // could not use previous value. // Call underlying formatter to format date. @@ -219,7 +231,6 @@ int CachedDateFormat::findMillisecondSta slotBegin -= 1000000; } - // // if the milliseconds field was previous found // then reevaluate in case it moved. @@ -229,7 +240,6 @@ int CachedDateFormat::findMillisecondSta } } - /** * Formats a count of milliseconds (0-999) into a numeric representation. * @param millis Millisecond count between 0 and 999. Modified: incubator/log4cxx/trunk/src/test/cpp/helpers/cacheddateformattestcase.cpp URL: http://svn.apache.org/viewvc/incubator/log4cxx/trunk/src/test/cpp/helpers/cacheddateformattestcase.cpp?rev=1569535&r1=1569534&r2=1569535&view=diff ============================================================================== --- incubator/log4cxx/trunk/src/test/cpp/helpers/cacheddateformattestcase.cpp (original) +++ incubator/log4cxx/trunk/src/test/cpp/helpers/cacheddateformattestcase.cpp Tue Feb 18 21:46:35 2014 @@ -48,38 +48,36 @@ using namespace log4cxx::pattern; /** - Unit test {@link CachedDateFormat}. - - */ + * Unit test {@link CachedDateFormat}. + */ LOGUNIT_CLASS(CachedDateFormatTestCase) { LOGUNIT_TEST_SUITE( CachedDateFormatTestCase ); - LOGUNIT_TEST( test1 ); - LOGUNIT_TEST( test2 ); - LOGUNIT_TEST( test3 ); - LOGUNIT_TEST( test4 ); + LOGUNIT_TEST(test1); + LOGUNIT_TEST(test2); + LOGUNIT_TEST(test3); + LOGUNIT_TEST(test4); #if LOG4CXX_HAS_STD_LOCALE - LOGUNIT_TEST( test5 ); + LOGUNIT_TEST(test5); #endif - LOGUNIT_TEST( test6 ); - LOGUNIT_TEST( test8 ); + LOGUNIT_TEST(test6); + LOGUNIT_TEST(test8); // Gump doesn't like this test -// LOGUNIT_TEST( test9 ); - LOGUNIT_TEST( test10 ); - LOGUNIT_TEST( test11); - LOGUNIT_TEST( test12 ); - LOGUNIT_TEST( test13 ); - LOGUNIT_TEST( test14 ); - LOGUNIT_TEST( test15 ); - LOGUNIT_TEST( test16 ); - LOGUNIT_TEST( test17); - LOGUNIT_TEST( test18); - LOGUNIT_TEST( test19); - LOGUNIT_TEST( test20); - LOGUNIT_TEST( test21); +// LOGUNIT_TEST(test9); + LOGUNIT_TEST(test10); + LOGUNIT_TEST(test11); + LOGUNIT_TEST(test12); + LOGUNIT_TEST(test13); + LOGUNIT_TEST(test14); + LOGUNIT_TEST(test15); + LOGUNIT_TEST(test16); + LOGUNIT_TEST(test17); + LOGUNIT_TEST(test18); + LOGUNIT_TEST(test19); + LOGUNIT_TEST(test20); + LOGUNIT_TEST(test21); LOGUNIT_TEST_SUITE_END(); - #define MICROSECONDS_PER_DAY APR_INT64_C(86400000000) public: @@ -474,16 +472,16 @@ void test12() { formatted.clear(); df->format(formatted, ticks, p); - int msStartLogcxx420_406 = CachedDateFormat::findMillisecondStart(ticks, formatted, df, p); - LOGUNIT_ASSERT_EQUAL(20, msStartLogcxx420_406); + msStart = CachedDateFormat::findMillisecondStart(ticks, formatted, df, p); + LOGUNIT_ASSERT_EQUAL(20, msStart); c.tm_usec = 609000; LOGUNIT_ASSERT_EQUAL(0, apr_time_exp_gmt_get(&ticks, &c)); formatted.clear(); df->format(formatted, ticks, p); - int msStartLogcxx420_609 = CachedDateFormat::findMillisecondStart(ticks, formatted, df, p); - LOGUNIT_ASSERT_EQUAL(20, msStartLogcxx420_609); + msStart = CachedDateFormat::findMillisecondStart(ticks, formatted, df, p); + LOGUNIT_ASSERT_EQUAL(20, msStart); } /** @@ -551,7 +549,6 @@ void test16() { LOGUNIT_ASSERT_EQUAL((int) CachedDateFormat::UNRECOGNIZED_MILLISECONDS, millisecondStart); } - /** * Check caching when multiple SSS appear in pattern */ @@ -574,12 +571,30 @@ void test17() { LOGUNIT_ASSERT_EQUAL((LogString) LOG4CXX_STR("00:00:00,120 00:00:00,120"), s); s.erase(s.begin(), s.end()); +printf("test17 1\n"); cachedFormat->format(s, jul2, p); - LOGUNIT_ASSERT_EQUAL((LogString) LOG4CXX_STR("00:00:00,120 00:00:00,120"), s) ; +printf("test17 2\n"); int maxValid = CachedDateFormat::getMaximumCacheValidity(badPattern); LOGUNIT_ASSERT_EQUAL(1000, maxValid); + + // Test overlapping millis with a magic string from CachedDateFormat for LOGCXX-420. + s.clear(); + jul2 += 286000; +printf("test17 3\n"); + cachedFormat->format(s, jul2, p); + int msStart = CachedDateFormat::findMillisecondStart(jul2, s, simpleFormat, p); + LOGUNIT_ASSERT_EQUAL(9, msStart); +printf("test17 4\n"); + + s.clear(); + jul2 += 203000; +printf("test17 5\n"); + cachedFormat->format(s, jul2, p); + msStart = CachedDateFormat::findMillisecondStart(jul2, s, simpleFormat, p); + LOGUNIT_ASSERT_EQUAL(9, msStart); +printf("test17 6\n"); } /** @@ -632,5 +647,4 @@ void test21() { }; - LOGUNIT_TEST_SUITE_REGISTRATION(CachedDateFormatTestCase);