[logging] add lint-logs.sh to check for newline termination.

jnewbery commented at 2:19 pm on April 5, 2018: member

Check that all calls to LogPrintf() are terminated by a newline, except those that are explicitly marked as ‘continued’ logs.

jnewbery commented at 2:19 pm on April 5, 2018: member

Suggested by @MarcoFalke here: #12887 (comment)

linter hints suggested by @laanwj here: #12887 (comment)

in src/dbwrapper.cpp:66 in 28682f3354 outdated

62@@ -63,7 +63,7 @@ class CBitcoinLevelDBLogger : public leveldb::Logger {
63 
64                 assert(p <= limit);
65                 base[std::min(bufsize - 1, (int)(p - base))] = '\0';
66-                LogPrintf("leveldb: %s", base);
67+                LogPrintf("leveldb: %s", base);  /* Continued */

MarcoFalke commented at 2:28 pm on April 5, 2018:

Since you are changing those lines anyway, why not use LogPrintfContinuation or something?

jnewbery commented at 2:38 pm on April 5, 2018:

My suggestion here: #12887 (comment) has inverted semantics. This Continued here comment indicates that there is a continuation log to follow. LogPrintfContinuation() would indicate that the log continues a previous log.

I think LogPrintfContinuation() could be useful, but it’s a rebase-the-world PR since it removes the \n from every call to LogPrintf()

laanwj commented at 4:18 pm on April 5, 2018:

Yes, please don’t change every single log message. This solution is fine.

MarcoFalke commented at 2:36 pm on April 5, 2018: member

utACK 28682f3354a89f49a402735f94b7f79f34966aab

laanwj commented at 4:18 pm on April 5, 2018: member

utACK https://github.com/bitcoin/bitcoin/pull/12891/commits/28682f3354a89f49a402735f94b7f79f34966aab

practicalswift commented at 8:46 pm on April 5, 2018: contributor

Very strong concept ACK. Thanks for making this fix persistent by adding a lint script.

Please apply this patch to the lint script to make it work as expected:

 0--- lint-logs.sh	2018-04-05 22:43:14.119412169 +0200
 1+++ lint-logs.sh.fixed	2018-04-05 22:42:03.787354149 +0200
 2@@ -13,10 +13,10 @@
 3 # ignored
 4
 5
 6-UNTERMINATED_LOGS=$(git grep "LogPrintf(" -- *cpp | \
 7-	grep -v "\\\n\"" | \
 8-	grep -v "/\* Continued \*/" | \
 9-	grep -v "LogPrintf\(\)")
10+UNTERMINATED_LOGS=$(git grep "LogPrintf(" -- "*.cpp" | \
11+    grep -v '\\n"' | \
12+    grep -v "/\* Continued \*/" | \
13+    grep -v "LogPrintf()")
14 if [[ ${UNTERMINATED_LOGS} != "" ]]; then
15     echo "All calls to LogPrintf() should be terminated with \\n"
16     echo

The bugs:

The *cpp in git grep "LogPrintf(" -- *cpp will be expanded by the shell and match only cpp files in the current directory.
grep -v "LogPrintf\(\)" is equivalent to grep -v "LogPrintf" due to how basic regular expressions are handled by grep. From the documentation: “In basic regular expressions the meta-characters ?, +, {, |, (, and ) lose their special meaning; instead use the backslashed versions ?, +, {, |, (, and ).”

ACK modulo fixing the lint script bugs :-)

fanquake added the label Utils/log/libs on Apr 5, 2018

jnewbery force-pushed on Apr 6, 2018

jnewbery commented at 5:05 pm on April 6, 2018: member

Thanks for the review and bugfixes @practicalswift ! Your fixed version caught a non-conforming log, which I’ve fixed in a new commit.

MarcoFalke commented at 5:10 pm on April 6, 2018: member

utACK 621981530b57ac983b7bf35474c0796fbf5d5ed7

practicalswift commented at 5:12 pm on April 6, 2018: contributor

utACK 621981530b57ac983b7bf35474c0796fbf5d5ed7

in src/wallet/wallet.cpp:3079 in 621981530b outdated

3075@@ -3076,7 +3076,7 @@ bool CWallet::CommitTransaction(CTransactionRef tx, mapValue_t mapValue, std::ve
3076         wtxNew.fTimeReceivedIsTxTime = true;
3077         wtxNew.fFromMe = true;
3078 
3079-        LogPrintf("CommitTransaction:\n%s", wtxNew.tx->ToString());
3080+        LogPrintf("CommitTransaction:\n%s\n", wtxNew.tx->ToString());

laanwj commented at 2:15 pm on April 7, 2018:

Unfortunately this change is wrong, as tx->ToString() adds a final newline: https://github.com/bitcoin/bitcoin/blob/master/src/primitives/transaction.cpp#L99

jnewbery commented at 4:30 pm on April 7, 2018:

ah, well spotted. Now fixed.

Incidentally, I hate this log. As far as I’m aware it’s the only one with newlines embedded and it confuses my log parser!

[logging] Comment all continuing logs.

Most logs should terminated with a '\n'. Some logs
are built up over multiple calls to logPrintf(), so
do not need a newline terminater. Comment all of
these 'continued' logs as a linter hing.

5c21e6c6d3

[logging] add lint-logs.sh to check for newline termination.

Check that all calls to LogPrintf() are terminated by a newline,
except those that are explicitly marked as 'continued' logs.

d207207fd3

jnewbery force-pushed on Apr 7, 2018

practicalswift commented at 5:56 am on April 8, 2018: contributor

utACK d207207fd3ac1a0aaf3c34379f8f02b76dc69c69

laanwj commented at 9:05 am on April 8, 2018: member

utACK https://github.com/bitcoin/bitcoin/pull/12891/commits/d207207fd3ac1a0aaf3c34379f8f02b76dc69c69

laanwj merged this on Apr 8, 2018

laanwj closed this on Apr 8, 2018

laanwj referenced this in commit 3190785c11 on Apr 8, 2018

PastaPastaPasta referenced this in commit 1c9afbc878 on Jun 10, 2020

PastaPastaPasta referenced this in commit 3687335380 on Jun 10, 2020

PastaPastaPasta referenced this in commit 2a4f7f7103 on Jun 10, 2020

PastaPastaPasta referenced this in commit 53a27feb6e on Jun 11, 2020

PastaPastaPasta referenced this in commit b3fac065d8 on Jun 11, 2020

PastaPastaPasta referenced this in commit 24ee5b78f4 on Jun 11, 2020

PastaPastaPasta referenced this in commit 101f73bb6d on Jun 12, 2020

MarcoFalke locked this on Sep 8, 2021

[logging] add lint-logs.sh to check for newline termination. #12891