arrange logging

Author: cleverfox

apps/tpnode/src/blockchain_reader.erl

@@ -561,11 +561,20 @@ mychain1() ->
   {MyChain, MyName, ChainNodes}.
 
 mychain(State) ->
-  {MyChain, MyName, ChainNodes}=mychain(),
-  ?LOG_INFO("My name ~p chain ~p ournodes ~p", [MyName, MyChain, maps:values(ChainNodes)]),
-  maps:merge(State,
-             #{myname=>MyName,
-               chainnodes=>ChainNodes,
-               mychain=>MyChain
-              }).
+  New={MyChain, MyName, ChainNodes}=mychain(),
+  Pre={
+    maps:get(mychain, State, undefined),
+    maps:get(myname, State, undefined),
+    maps:get(chainnodes, State, undefined)
+   },
+  if Pre =/= New ->
+       ?LOG_INFO("My name ~p chain ~p ournodes ~p", [MyName, MyChain, maps:values(ChainNodes)]),
+       maps:merge(State,
+                  #{myname=>MyName,
+                    chainnodes=>ChainNodes,
+                    mychain=>MyChain
+                   });
+     true ->
+       State
+  end.
 

apps/tpnode/src/blockchain_updater.erl

@@ -203,11 +203,9 @@ handle_call({new_block, #{hash:=BlockHash,
               is_tuple(PID) -> PID;
               true -> emulator
            end,
-  ?LOG_INFO("Arrived block from ~p Verify block with ~p",
-             [FromNode, maps:keys(Blk)]),
-
-  ?LOG_INFO("New block (~p/~p) hash ~s (~s/~s)",
+  ?LOG_INFO("New block from ~p (~p/~p) hash ~s (~s/~s)",
              [
+              FromNode,
               Hei,
               maps:get(height, maps:get(header, LastBlock)),
               blkid(BlockHash),
@@ -250,8 +248,8 @@ handle_call({new_block, #{hash:=BlockHash,
         Txs=maps:get(txs, Blk, []),
         Txsl=length(Txs),
         if LenSucc>0 ->
-             ?LOG_INFO("from ~p New block ~w arrived ~s, txs ~b, verify ~w sig (~.3f ms)",
-                        [FromNode, maps:get(height, maps:get(header, Blk)),
+             ?LOG_INFO("Block ~w verified ~s, txs ~b, verify ~w sig (~.3f ms)",
+                        [maps:get(height, maps:get(header, Blk)),
                          blkid(BlockHash), Txsl, length(Success), (T1-T0)/1000000]),
              ok;
            true ->
@@ -272,7 +270,6 @@ handle_call({new_block, #{hash:=BlockHash,
         SigLen=length(maps:get(sign, MBlk)),
         ?LOG_DEBUG("Signs ~p", [Success]),
         MinSig=getset(minsig,State),
-        ?LOG_INFO("Sig ~p ~p", [SigLen, MinSig]),
         if SigLen>=MinSig ->
              IsTemp=maps:get(temporary,Blk,false) =/= false,
              Header=maps:get(header, Blk),
@@ -554,6 +551,7 @@ handle_call({new_block, #{hash:=BlockHash,
              end;
            true ->
              %not enough
+             ?LOG_NOTICE("Block arrived to updater, but insufficient signature ~p, required ~p", [SigLen, MinSig]),
              {reply, {ok, no_enough_sig}, State#{
                                             candidates=>
                                             maps:put(BlockHash,

apps/tpnode/src/blockvote.erl

@@ -300,7 +300,7 @@ is_block_ready(BlockHash, #{extras:=Extras}=State) ->
         {true, {Success, _}}=block:verify(Blk1),
         T1=erlang:system_time(),
         Txs=maps:get(txs, Blk0, []),
-        ?LOG_INFO("TODO: Check keys ~p of ~p", [length(Success), MinSig]),
+        ?LOG_DEBUG("TODO: Check keys ~p of ~p", [length(Success), MinSig]),
         if length(Success)<MinSig ->
              ?LOG_INFO("BV New block ~w arrived ~s, txs ~b, verify ~w (~.3f ms)",
                   [maps:get(height, maps:get(header, Blk0)),
@@ -310,7 +310,7 @@ is_block_ready(BlockHash, #{extras:=Extras}=State) ->
                    (T1-T0)/1000000]),
              throw({notready, minsig});
            true ->
-             ?LOG_INFO("BV New block ~w arrived ~s, txs ~b, verify ~w (~.3f ms)",
+             ?LOG_DEBUG("BV New block ~w arrived ~s, txs ~b, verify ~w (~.3f ms)",
                   [maps:get(height, maps:get(header, Blk0)),
                    blkid(BlockHash),
                    length(Txs),
@@ -338,7 +338,10 @@ is_block_ready(BlockHash, #{extras:=Extras}=State) ->
 
         blockchain_updater:new_block(Blk),
         Extra=maps:get(BlockHash, Extras, #{}),
-        ?LOG_INFO("Extra for blk ~w ~s: ~p",[Height, blkid(BlockHash), Extra]),
+        if Extra =/= #{} andalso Extra =/= #{log=>[]} ->
+             ?LOG_INFO("Extra for blk ~w ~s: ~p",[Height, blkid(BlockHash), Extra]);
+           true -> ok
+        end,
         case maps:is_key(log, Extra) of
           false -> ok;
           true ->

apps/tpnode/src/generate_block.erl

@@ -131,13 +131,19 @@ generate_block(PreTXL, {Parent_Height, Parent_Hash}, GetSettings, GetAddr, Extra
     settings:=Settings,
     outbound:=Outbound,
     pick_block:=PickBlocks,
-    fee:=_FeeCollected,
-    tip:=_TipCollected,
+    fee:=FeeCollected,
+    tip:=TipCollected,
     emit:=EmitTXs0,
     log:=Logs0,
     new_settings := NewSettings
    }=finish_processing(generate_block_process:try_process(TXL, GBInit)),
-  ?LOG_INFO("MB Collected fee ~p tip ~p", [_FeeCollected, _TipCollected]),
+  if(FeeCollected == #{amount => #{},changes => []}
+     andalso
+     TipCollected == #{amount => #{},changes => []}) ->
+          ok;
+     true ->
+      ?LOG_INFO("MB Collected fee ~p tip ~p", [FeeCollected, TipCollected])
+  end,
   Logs=lists:reverse(Logs0),
 
   if length(Settings)>0 ->
@@ -485,7 +491,10 @@ txfind([_|Rest],TxID) ->
   txfind(Rest,TxID).
 
 cleanup_delayed(#{delayed:=DTX, new_settings:=NS, settings:=Sets} = Acc) ->
-  ?LOG_INFO("Delayed ~p",[DTX]),
+  if(DTX==[]) -> ok;
+    true ->
+      ?LOG_INFO("Delayed txs ~p",[DTX])
+  end,
   ToDel=lists:foldl(
           fun({TxID,DT},Acc1) ->
               case settings:get([<<"current">>, <<"delaytx">>, DT], NS) of

apps/tpnode/src/generate_block_process.erl

@@ -91,7 +91,7 @@ try_process([], #{
                     }
                 end, {SetState, Settings}, OutChains),
 
-  ?LOG_INFO("try_process finish"),
+  ?LOG_DEBUG("try_process finish"),
   Acc#{settings=>Set2, set_state=>SS2};
 
 %process inbound block
@@ -308,6 +308,7 @@ try_process([{TxID, #{
                            last => failed
                           });
         throw:X:S ->
+          io:format("~s Throw  ~p at ~p/~p~n",[TxID,X,hd(S),hd(tl(S))]),
           try_process(Rest,
                       Acc#{failed=>[{TxID, fmterr(X)}|Failed],
                            last => failed});

apps/tpnode/src/mkblock.erl

@@ -324,13 +324,13 @@ hei_and_has(B) ->
   PTmp=maps:get(temporary,B,false),
 
   case PTmp of false ->
-                 ?LOG_INFO("Prev block is permanent, make child"),
+                 ?LOG_DEBUG("Prev block is permanent, make child"),
                  #{header:=#{height:=Last_Height1}, hash:=Last_Hash1}=B,
                  {Last_Height1,
                   Last_Hash1,
                   <<(bnot Last_Height1):64/big,Last_Hash1/binary>>};
                X when is_integer(X) ->
-                 ?LOG_INFO("Prev block is temporary, make replacement"),
+                 ?LOG_DEBUG("Prev block is temporary, make replacement"),
                  #{header:=#{height:=Last_Height1, parent:=Last_Hash1}}=B,
                  {Last_Height1-1,
                   Last_Hash1,