Skip to content

Commit bb98aec

Browse files
laanwjlaanwj
committed
Merge #12567: util: Print timestamp strings in logs using ISO 8601 formatting
a7324bd Format timestamps using ISO 8601 formatting (e.g. "2018-02-28T12:34:56Z") (practicalswift) Pull request description: Print timestamp strings in logs using [ISO 8601](https://en.wikipedia.org/wiki/ISO_8601) formatting (e.g. `2018-02-28T12:34:56Z`): * `Z` is the zone designator for the zero [UTC](https://en.wikipedia.org/wiki/Coordinated_Universal_Time) offset. * `T` is the delimiter used to separate date and time. This makes it clear for the end-user that the date/time logged is specified in UTC and not in the local time zone. Before this patch: ``` 2018-02-28 12:34:56 New outbound peer connected: version: 70015, blocks=1286123, peer=0 ``` After this patch: ``` 2018-02-28T12:34:56Z New outbound peer connected: version: 70015, blocks=1286123, peer=0 ``` Tree-SHA512: 52b53c3d3d11ddf4af521a3b5f90a79f6e6539ee5955ec56a5aa2c6a5cf29cecf166d8cb43277c62553c3325a31bcea83691acbb4e86429c523f8aff8d7b210a
2 parents 29fad97 + a7324bd commit bb98aec

File tree

12 files changed

+61
-23
lines changed

12 files changed

+61
-23
lines changed

‎doc/release-notes.md

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -93,6 +93,10 @@ Low-level RPC changes
9393
with any `-wallet=<path>` options, there is no change in behavior, and the
9494
name of any wallet is just its `<path>` string.
9595

96+
### Logging
97+
98+
- The log timestamp format is now ISO 8601 (e.g. "2018-02-28T12:34:56Z").
99+
96100
Credits
97101
=======
98102

‎src/init.cpp

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -1224,7 +1224,7 @@ bool AppInitMain()
12241224
}
12251225

12261226
if (!fLogTimestamps)
1227-
LogPrintf("Startup time: %s\n", DateTimeStrFormat("%Y-%m-%d %H:%M:%S", GetTime()));
1227+
LogPrintf("Startup time: %s\n", FormatISO8601DateTime(GetTime()));
12281228
LogPrintf("Default data directory %s\n", GetDefaultDataDir().string());
12291229
LogPrintf("Using data directory %s\n", GetDataDir().string());
12301230
LogPrintf("Using config file %s\n", GetConfigFile(gArgs.GetArg("-conf", BITCOIN_CONF_FILENAME)).string());

‎src/net.cpp

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -2795,7 +2795,7 @@ void CNode::AskFor(const CInv& inv)
27952795
nRequestTime = it->second;
27962796
else
27972797
nRequestTime = 0;
2798-
LogPrint(BCLog::NET, "askfor %s %d (%s) peer=%d\n", inv.ToString(), nRequestTime, DateTimeStrFormat("%H:%M:%S", nRequestTime/1000000), id);
2798+
LogPrint(BCLog::NET, "askfor %s %d (%s) peer=%d\n", inv.ToString(), nRequestTime, FormatISO8601Time(nRequestTime/1000000), id);
27992799

28002800
// Make sure not to reuse time indexes to keep things in the same order
28012801
int64_t nNow = GetTimeMicros() - 1000000;

‎src/qt/paymentserver.cpp

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -770,7 +770,7 @@ bool PaymentServer::verifyExpired(const payments::PaymentDetails& requestDetails
770770
{
771771
bool fVerified = (requestDetails.has_expires() && (int64_t)requestDetails.expires() < GetTime());
772772
if (fVerified) {
773-
const QString requestExpires = QString::fromStdString(DateTimeStrFormat("%Y-%m-%d %H:%M:%S", (int64_t)requestDetails.expires()));
773+
const QString requestExpires = QString::fromStdString(FormatISO8601DateTime((int64_t)requestDetails.expires()));
774774
qWarning() << QString("PaymentServer::%1: Payment request expired \"%2\".")
775775
.arg(__func__)
776776
.arg(requestExpires);

‎src/test/util_tests.cpp

Lines changed: 17 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -164,10 +164,27 @@ BOOST_AUTO_TEST_CASE(util_DateTimeStrFormat)
164164
BOOST_CHECK_EQUAL(DateTimeStrFormat("%Y-%m-%d %H:%M:%S", 0), "1970-01-01 00:00:00");
165165
BOOST_CHECK_EQUAL(DateTimeStrFormat("%Y-%m-%d %H:%M:%S", 0x7FFFFFFF), "2038-01-19 03:14:07");
166166
BOOST_CHECK_EQUAL(DateTimeStrFormat("%Y-%m-%d %H:%M:%S", 1317425777), "2011-09-30 23:36:17");
167+
BOOST_CHECK_EQUAL(DateTimeStrFormat("%Y-%m-%dT%H:%M:%SZ", 1317425777), "2011-09-30T23:36:17Z");
168+
BOOST_CHECK_EQUAL(DateTimeStrFormat("%H:%M:%SZ", 1317425777), "23:36:17Z");
167169
BOOST_CHECK_EQUAL(DateTimeStrFormat("%Y-%m-%d %H:%M", 1317425777), "2011-09-30 23:36");
168170
BOOST_CHECK_EQUAL(DateTimeStrFormat("%a, %d %b %Y %H:%M:%S +0000", 1317425777), "Fri, 30 Sep 2011 23:36:17 +0000");
169171
}
170172

173+
BOOST_AUTO_TEST_CASE(util_FormatISO8601DateTime)
174+
{
175+
BOOST_CHECK_EQUAL(FormatISO8601DateTime(1317425777), "2011-09-30T23:36:17Z");
176+
}
177+
178+
BOOST_AUTO_TEST_CASE(util_FormatISO8601Date)
179+
{
180+
BOOST_CHECK_EQUAL(FormatISO8601Date(1317425777), "2011-09-30");
181+
}
182+
183+
BOOST_AUTO_TEST_CASE(util_FormatISO8601Time)
184+
{
185+
BOOST_CHECK_EQUAL(FormatISO8601Time(1317425777), "23:36:17Z");
186+
}
187+
171188
class TestArgsManager : public ArgsManager
172189
{
173190
public:

‎src/util.cpp

Lines changed: 6 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -315,12 +315,14 @@ static std::string LogTimestampStr(const std::string &str, std::atomic_bool *fSt
315315

316316
if (*fStartedNewLine) {
317317
int64_t nTimeMicros = GetTimeMicros();
318-
strStamped = DateTimeStrFormat("%Y-%m-%d %H:%M:%S", nTimeMicros/1000000);
319-
if (fLogTimeMicros)
320-
strStamped += strprintf(".%06d", nTimeMicros%1000000);
318+
strStamped = FormatISO8601DateTime(nTimeMicros/1000000);
319+
if (fLogTimeMicros) {
320+
strStamped.pop_back();
321+
strStamped += strprintf(".%06dZ", nTimeMicros%1000000);
322+
}
321323
int64_t mocktime = GetMockTime();
322324
if (mocktime) {
323-
strStamped += " (mocktime: " + DateTimeStrFormat("%Y-%m-%d %H:%M:%S", mocktime) + ")";
325+
strStamped += " (mocktime: " + FormatISO8601DateTime(mocktime) + ")";
324326
}
325327
strStamped += ' ' + str;
326328
} else

‎src/utiltime.cpp

Lines changed: 12 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -85,3 +85,15 @@ std::string DateTimeStrFormat(const char* pszFormat, int64_t nTime)
8585
ss << boost::posix_time::from_time_t(nTime);
8686
return ss.str();
8787
}
88+
89+
std::string FormatISO8601DateTime(int64_t nTime) {
90+
return DateTimeStrFormat("%Y-%m-%dT%H:%M:%SZ", nTime);
91+
}
92+
93+
std::string FormatISO8601Date(int64_t nTime) {
94+
return DateTimeStrFormat("%Y-%m-%d", nTime);
95+
}
96+
97+
std::string FormatISO8601Time(int64_t nTime) {
98+
return DateTimeStrFormat("%H:%M:%SZ", nTime);
99+
}

‎src/utiltime.h

Lines changed: 8 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -27,6 +27,14 @@ void SetMockTime(int64_t nMockTimeIn);
2727
int64_t GetMockTime();
2828
void MilliSleep(int64_t n);
2929

30+
/**
31+
* ISO 8601 formatting is preferred. Use the FormatISO8601{DateTime,Date,Time}
32+
* helper functions if possible.
33+
*/
3034
std::string DateTimeStrFormat(const char* pszFormat, int64_t nTime);
3135

36+
std::string FormatISO8601DateTime(int64_t nTime);
37+
std::string FormatISO8601Date(int64_t nTime);
38+
std::string FormatISO8601Time(int64_t nTime);
39+
3240
#endif // BITCOIN_UTILTIME_H

‎src/validation.cpp

Lines changed: 5 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -1267,13 +1267,12 @@ void static InvalidChainFound(CBlockIndex* pindexNew)
12671267

12681268
LogPrintf("%s: invalid block=%s height=%d log2_work=%.8g date=%s\n", __func__,
12691269
pindexNew->GetBlockHash().ToString(), pindexNew->nHeight,
1270-
log(pindexNew->nChainWork.getdouble())/log(2.0), DateTimeStrFormat("%Y-%m-%d %H:%M:%S",
1271-
pindexNew->GetBlockTime()));
1270+
log(pindexNew->nChainWork.getdouble())/log(2.0), FormatISO8601DateTime(pindexNew->GetBlockTime()));
12721271
CBlockIndex *tip = chainActive.Tip();
12731272
assert (tip);
12741273
LogPrintf("%s: current best=%s height=%d log2_work=%.8g date=%s\n", __func__,
12751274
tip->GetBlockHash().ToString(), chainActive.Height(), log(tip->nChainWork.getdouble())/log(2.0),
1276-
DateTimeStrFormat("%Y-%m-%d %H:%M:%S", tip->GetBlockTime()));
1275+
FormatISO8601DateTime(tip->GetBlockTime()));
12771276
CheckForkWarningConditions();
12781277
}
12791278

@@ -2229,7 +2228,7 @@ void static UpdateTip(const CBlockIndex *pindexNew, const CChainParams& chainPar
22292228
LogPrintf("%s: new best=%s height=%d version=0x%08x log2_work=%.8g tx=%lu date='%s' progress=%f cache=%.1fMiB(%utxo)", __func__,
22302229
pindexNew->GetBlockHash().ToString(), pindexNew->nHeight, pindexNew->nVersion,
22312230
log(pindexNew->nChainWork.getdouble())/log(2.0), (unsigned long)pindexNew->nChainTx,
2232-
DateTimeStrFormat("%Y-%m-%d %H:%M:%S", pindexNew->GetBlockTime()),
2231+
FormatISO8601DateTime(pindexNew->GetBlockTime()),
22332232
GuessVerificationProgress(chainParams.TxData(), pindexNew), pcoinsTip->DynamicMemoryUsage() * (1.0 / (1<<20)), pcoinsTip->GetCacheSize());
22342233
if (!warningMessages.empty())
22352234
LogPrintf(" warning='%s'", boost::algorithm::join(warningMessages, ", "));
@@ -3856,7 +3855,7 @@ bool LoadChainTip(const CChainParams& chainparams)
38563855

38573856
LogPrintf("Loaded best chain: hashBestChain=%s height=%d date=%s progress=%f\n",
38583857
chainActive.Tip()->GetBlockHash().ToString(), chainActive.Height(),
3859-
DateTimeStrFormat("%Y-%m-%d %H:%M:%S", chainActive.Tip()->GetBlockTime()),
3858+
FormatISO8601DateTime(chainActive.Tip()->GetBlockTime()),
38603859
GuessVerificationProgress(chainparams.TxData(), chainActive.Tip()));
38613860
return true;
38623861
}
@@ -4554,7 +4553,7 @@ void CChainState::CheckBlockIndex(const Consensus::Params& consensusParams)
45544553

45554554
std::string CBlockFileInfo::ToString() const
45564555
{
4557-
return strprintf("CBlockFileInfo(blocks=%u, size=%u, heights=%u...%u, time=%s...%s)", nBlocks, nSize, nHeightFirst, nHeightLast, DateTimeStrFormat("%Y-%m-%d", nTimeFirst), DateTimeStrFormat("%Y-%m-%d", nTimeLast));
4556+
return strprintf("CBlockFileInfo(blocks=%u, size=%u, heights=%u...%u, time=%s...%s)", nBlocks, nSize, nHeightFirst, nHeightLast, FormatISO8601Date(nTimeFirst), FormatISO8601Date(nTimeLast));
45584557
}
45594558

45604559
CBlockFileInfo* GetBlockFileInfo(size_t n)

‎src/wallet/rpcdump.cpp

Lines changed: 4 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -28,10 +28,6 @@
2828
#include <univalue.h>
2929

3030

31-
std::string static EncodeDumpTime(int64_t nTime) {
32-
return DateTimeStrFormat("%Y-%m-%dT%H:%M:%SZ", nTime);
33-
}
34-
3531
int64_t static DecodeDumpTime(const std::string &str) {
3632
static const boost::posix_time::ptime epoch = boost::posix_time::from_time_t(0);
3733
static const std::locale loc(std::locale::classic(),
@@ -722,9 +718,9 @@ UniValue dumpwallet(const JSONRPCRequest& request)
722718

723719
// produce output
724720
file << strprintf("# Wallet dump created by Bitcoin %s\n", CLIENT_BUILD);
725-
file << strprintf("# * Created on %s\n", EncodeDumpTime(GetTime()));
721+
file << strprintf("# * Created on %s\n", FormatISO8601DateTime(GetTime()));
726722
file << strprintf("# * Best block at time of backup was %i (%s),\n", chainActive.Height(), chainActive.Tip()->GetBlockHash().ToString());
727-
file << strprintf("# mined on %s\n", EncodeDumpTime(chainActive.Tip()->GetBlockTime()));
723+
file << strprintf("# mined on %s\n", FormatISO8601DateTime(chainActive.Tip()->GetBlockTime()));
728724
file << "\n";
729725

730726
// add the base58check encoded extended master if the wallet uses HD
@@ -741,7 +737,7 @@ UniValue dumpwallet(const JSONRPCRequest& request)
741737
}
742738
for (std::vector<std::pair<int64_t, CKeyID> >::const_iterator it = vKeyBirth.begin(); it != vKeyBirth.end(); it++) {
743739
const CKeyID &keyid = it->second;
744-
std::string strTime = EncodeDumpTime(it->first);
740+
std::string strTime = FormatISO8601DateTime(it->first);
745741
std::string strAddr;
746742
std::string strLabel;
747743
CKey key;
@@ -769,7 +765,7 @@ UniValue dumpwallet(const JSONRPCRequest& request)
769765
// get birth times for scripts with metadata
770766
auto it = pwallet->m_script_metadata.find(scriptid);
771767
if (it != pwallet->m_script_metadata.end()) {
772-
create_time = EncodeDumpTime(it->second.nCreateTime);
768+
create_time = FormatISO8601DateTime(it->second.nCreateTime);
773769
}
774770
if(pwallet->GetCScript(scriptid, script)) {
775771
file << strprintf("%s %s script=1", HexStr(script.begin(), script.end()), create_time);

0 commit comments

Comments
 (0)