Merge pull request #623 from LF-Decentralized-Trust-labs/timeline-logging

Timeline logging

Author: Chengxuan

config/pkg/pldconf/publictxmgr.go

@@ -172,4 +172,5 @@ type PublicTxManagerOrchestratorConfig struct {
 	PersistenceRetryTime      *string            `json:"persistenceRetryTime"`
 	UnavailableBalanceHandler *string            `json:"unavailableBalanceHandler"`
 	SubmissionRetry           RetryConfigWithMax `json:"submissionRetry"`
+	TimeLineLoggingEnabled    bool               `json:"timelineLoggingEnabled"`
 }

core/go/internal/publictxmgr/in_flight_transaction_stage_controller.go

@@ -32,7 +32,6 @@ import (
 	"github.com/kaleido-io/paladin/core/pkg/ethclient"
 	"github.com/kaleido-io/paladin/sdk/go/pkg/pldapi"
 	"github.com/kaleido-io/paladin/sdk/go/pkg/pldtypes"
-	"github.com/sirupsen/logrus"
 )
 
 type InFlightStatus int
@@ -133,7 +132,7 @@ func NewInFlightTransactionStageController(
 				timestamp: ptx.Created.Time(),
 			},
 		},
-		timeLineLoggingEnabled: logrus.IsLevelEnabled(logrus.DebugLevel),
+		timeLineLoggingEnabled: oc.timeLineLoggingEnabled,
 	}
 
 	ift.MarkTime("wait_in_inflight_queue")

core/go/internal/publictxmgr/transaction_manager_test.go

@@ -98,6 +98,7 @@ func newTestPublicTxManager(t *testing.T, realDBAndSigner bool, extraSetup ...fu
 			SubmissionRetry: pldconf.RetryConfigWithMax{
 				MaxAttempts: confutil.P(1),
 			},
+			TimeLineLoggingEnabled: true,
 		},
 		GasPrice: pldconf.GasPriceConfig{
 			FixedGasPrice: 0,

core/go/internal/publictxmgr/transaction_orchestrator.go

@@ -147,6 +147,8 @@ type orchestrator struct {
 	// updates
 	updates   []*transactionUpdate
 	updateMux sync.Mutex
+
+	timeLineLoggingEnabled bool
 }
 
 const veryShortMinimum = 50 * time.Millisecond
@@ -182,6 +184,7 @@ func NewOrchestrator(
 		stopProcess:                make(chan bool, 1),
 		ethClient:                  ptm.ethClient,
 		bIndexer:                   ptm.bIndexer,
+		timeLineLoggingEnabled:     conf.Orchestrator.TimeLineLoggingEnabled,
 	}
 
 	log.L(ctx).Debugf("NewOrchestrator for signing address %s created: %+v", newOrchestrator.signingAddress, newOrchestrator)
@@ -376,6 +379,7 @@ func (oc *orchestrator) pollAndProcess(ctx context.Context) (polled int, total i
 			oc.totalCompleted = oc.totalCompleted + 1
 			queueUpdated = true
 			log.L(ctx).Debugf("Orchestrator poll and process, marking %s as complete after: %s", p.stateManager.GetSignerNonce(), time.Since(p.stateManager.GetCreatedTime().Time()))
+			p.PrintTimeline()
 		} else {
 			log.L(ctx).Debugf("Orchestrator poll and process, continuing tx %s after: %s", p.stateManager.GetSignerNonce(), time.Since(p.stateManager.GetCreatedTime().Time()))
 			oc.inFlightTxs = append(oc.inFlightTxs, p)

core/go/pkg/ethclient/client.go

@@ -459,7 +459,8 @@ func (ec *ethClient) SendRawTransaction(ctx context.Context, rawTX pldtypes.HexB
 		if err != nil {
 			log.L(ctx).Errorf("Invalid transaction build during signing: %s", err)
 		} else {
-			log.L(ctx).Errorf("Rejected TX (from=%s): %+v", addr, logJSON(decodedTX.Transaction))
+			log.L(ctx).Errorf("Rejected TX (from=%s, nonce=%+v)", addr, decodedTX.Nonce)
+			log.L(ctx).Tracef("Rejected TX (from=%s): %+v", addr, logJSON(decodedTX.Transaction))
 		}
 		return nil, fmt.Errorf("eth_sendRawTransaction failed: %+v", rpcErr)
 	}