From b9620a7dc3f9c1e4141a5effaa9cea8f9176f7f9 Mon Sep 17 00:00:00 2001 From: ziggie Date: Tue, 22 Apr 2025 00:01:16 +0200 Subject: [PATCH] mulit: increase logprogress time Switched the batchsize to 30 seconds instead of number of payments and invoices. --- channeldb/invoices.go | 35 +++++++++++++++++++----------- channeldb/payment_control.go | 18 ++++++++++------ channeldb/payments.go | 6 +++--- invoices/sql_store.go | 41 ++++++++++++++++++++++++------------ 4 files changed, 66 insertions(+), 34 deletions(-) diff --git a/channeldb/invoices.go b/channeldb/invoices.go index 1b13c3336..161fa4a2e 100644 --- a/channeldb/invoices.go +++ b/channeldb/invoices.go @@ -143,9 +143,9 @@ const ( ampStateCircuitKeysType tlv.Type = 4 ampStateAmtPaidType tlv.Type = 5 - // invoiceScanBatchSize is the number we use limiting the logging output - // of invoice processing. - invoiceScanBatchSize = 1000 + // invoiceProgressLogInterval is the interval we use limiting the + // logging output of invoice processing. + invoiceProgressLogInterval = 30 * time.Second ) // AddInvoice inserts the targeted invoice into the database. If the invoice has @@ -248,6 +248,7 @@ func (d *DB) InvoicesAddedSince(_ context.Context, sinceAddIndex uint64) ( var ( newInvoices []invpkg.Invoice start = time.Now() + lastLogTime = time.Now() processedCount int ) @@ -294,10 +295,14 @@ func (d *DB) InvoicesAddedSince(_ context.Context, sinceAddIndex uint64) ( newInvoices = append(newInvoices, invoice) processedCount++ - if processedCount%invoiceScanBatchSize == 0 { - log.Debugf("Processed %d invoices since "+ - "invoice with add index %v", + if time.Since(lastLogTime) >= + invoiceProgressLogInterval { + + log.Debugf("Processed %d invoices which "+ + "were added since add index %v", processedCount, sinceAddIndex) + + lastLogTime = time.Now() } } @@ -310,7 +315,7 @@ func (d *DB) InvoicesAddedSince(_ context.Context, sinceAddIndex uint64) ( } elapsed := time.Since(start) - log.Debugf("Completed scanning invoices added since index %v: "+ + log.Debugf("Completed scanning for invoices added since index %v: "+ "total_processed=%d, found_invoices=%d, elapsed=%v", sinceAddIndex, processedCount, len(newInvoices), elapsed.Round(time.Millisecond)) @@ -1068,6 +1073,7 @@ func (d *DB) InvoicesSettledSince(_ context.Context, sinceSettleIndex uint64) ( var ( settledInvoices []invpkg.Invoice start = time.Now() + lastLogTime = time.Now() processedCount int ) @@ -1130,10 +1136,15 @@ func (d *DB) InvoicesSettledSince(_ context.Context, sinceSettleIndex uint64) ( settledInvoices = append(settledInvoices, invoice) processedCount++ - if processedCount%invoiceScanBatchSize == 0 { + if time.Since(lastLogTime) >= + invoiceProgressLogInterval { + log.Debugf("Processed %d settled invoices "+ - "since invoice with settle index %v", - processedCount, sinceSettleIndex) + "which have a settle index greater "+ + "than %v", processedCount, + sinceSettleIndex) + + lastLogTime = time.Now() } } @@ -1146,8 +1157,8 @@ func (d *DB) InvoicesSettledSince(_ context.Context, sinceSettleIndex uint64) ( } elapsed := time.Since(start) - log.Debugf("Completed scanning invoices settled since index %v: "+ - "total_processed=%d, found_invoices=%d, elapsed=%v", + log.Debugf("Completed scanning for settled invoices starting at "+ + "index %v: total_processed=%d, found_invoices=%d, elapsed=%v", sinceSettleIndex, processedCount, len(settledInvoices), elapsed.Round(time.Millisecond)) diff --git a/channeldb/payment_control.go b/channeldb/payment_control.go index c369782d1..61739e92d 100644 --- a/channeldb/payment_control.go +++ b/channeldb/payment_control.go @@ -18,9 +18,9 @@ const ( // payment sequences for future payments. paymentSeqBlockSize = 1000 - // paymentBatchSize is the number we use limiting the logging output - // of payment processing. - paymentBatchSize = 1000 + // paymentProgressLogInterval is the interval we use limiting the + // logging output of payment processing. + paymentProgressLogInterval = 30 * time.Second ) var ( @@ -778,6 +778,7 @@ func (p *PaymentControl) FetchInFlightPayments() ([]*MPPayment, error) { var ( inFlights []*MPPayment start = time.Now() + lastLogTime = time.Now() processedCount int ) @@ -799,11 +800,15 @@ func (p *PaymentControl) FetchInFlightPayments() ([]*MPPayment, error) { } processedCount++ - if processedCount%paymentBatchSize == 0 { + if time.Since(lastLogTime) >= + paymentProgressLogInterval { + log.Debugf("Scanning inflight payments "+ "(in progress), processed %d, last "+ "processed payment: %v", processedCount, p.Info) + + lastLogTime = time.Now() } // Skip the payment if it's terminated. @@ -822,8 +827,9 @@ func (p *PaymentControl) FetchInFlightPayments() ([]*MPPayment, error) { } elapsed := time.Since(start) - log.Debugf("Completed scanning inflight payments: total_processed=%d, "+ - "found_inflight=%d, elapsed=%v", processedCount, len(inFlights), + log.Debugf("Completed scanning for inflight payments: "+ + "total_processed=%d, found_inflight=%d, elapsed=%v", + processedCount, len(inFlights), elapsed.Round(time.Millisecond)) return inFlights, nil diff --git a/channeldb/payments.go b/channeldb/payments.go index 947ec1ea3..51457671a 100644 --- a/channeldb/payments.go +++ b/channeldb/payments.go @@ -202,10 +202,10 @@ type PaymentCreationInfo struct { FirstHopCustomRecords lnwire.CustomRecords } +// String returns a human-readable description of the payment creation info. func (p *PaymentCreationInfo) String() string { - return fmt.Sprintf("payment_id=%v, amount=%v, created_at=%v, "+ - "payment_request=%v", p.PaymentIdentifier, p.Value, - p.CreationTime, p.PaymentRequest) + return fmt.Sprintf("payment_id=%v, amount=%v, created_at=%v", + p.PaymentIdentifier, p.Value, p.CreationTime) } // htlcBucketKey creates a composite key from prefix and id where the result is diff --git a/invoices/sql_store.go b/invoices/sql_store.go index 94149c36a..1372a3131 100644 --- a/invoices/sql_store.go +++ b/invoices/sql_store.go @@ -25,9 +25,9 @@ const ( // queries to limit the number of rows returned. defaultQueryPaginationLimit = 100 - // invoiceScanBatchSize is the number we use limiting the logging output - // when scanning invoices. - invoiceScanBatchSize = 1000 + // invoiceProgressLogInterval is the interval we use limiting the + // logging output of invoice processing. + invoiceProgressLogInterval = 30 * time.Second ) // SQLInvoiceQueries is an interface that defines the set of operations that can @@ -792,6 +792,7 @@ func (i *SQLStore) InvoicesSettledSince(ctx context.Context, idx uint64) ( var ( invoices []Invoice start = time.Now() + lastLogTime = time.Now() processedCount int ) @@ -829,11 +830,15 @@ func (i *SQLStore) InvoicesSettledSince(ctx context.Context, idx uint64) ( invoices = append(invoices, *invoice) processedCount++ - if processedCount%invoiceScanBatchSize == 0 { + if time.Since(lastLogTime) >= + invoiceProgressLogInterval { + log.Debugf("Processed %d settled "+ - "invoices since invoice with "+ - "settle index %v", + "invoices which have a settle "+ + "index greater than %v", processedCount, idx) + + lastLogTime = time.Now() } } @@ -891,10 +896,15 @@ func (i *SQLStore) InvoicesSettledSince(ctx context.Context, idx uint64) ( invoices = append(invoices, *invoice) processedCount++ - if processedCount%invoiceScanBatchSize == 0 { + if time.Since(lastLogTime) >= + invoiceProgressLogInterval { + log.Debugf("Processed %d settled invoices "+ - "since invoice with settle index %v", + "including AMP sub invoices which "+ + "have a settle index greater than %v", processedCount, idx) + + lastLogTime = time.Now() } } @@ -908,8 +918,8 @@ func (i *SQLStore) InvoicesSettledSince(ctx context.Context, idx uint64) ( } elapsed := time.Since(start) - log.Debugf("Completed scanning invoices settled since index %v: "+ - "total_processed=%d, found_invoices=%d, elapsed=%v", + log.Debugf("Completed scanning for settled invoices starting at "+ + "index %v: total_processed=%d, found_invoices=%d, elapsed=%v", idx, processedCount, len(invoices), elapsed.Round(time.Millisecond)) @@ -928,6 +938,7 @@ func (i *SQLStore) InvoicesAddedSince(ctx context.Context, idx uint64) ( var ( result []Invoice start = time.Now() + lastLogTime = time.Now() processedCount int ) @@ -963,10 +974,14 @@ func (i *SQLStore) InvoicesAddedSince(ctx context.Context, idx uint64) ( result = append(result, *invoice) processedCount++ - if processedCount%invoiceScanBatchSize == 0 { + if time.Since(lastLogTime) >= + invoiceProgressLogInterval { + log.Debugf("Processed %d invoices "+ - "added since invoice with add "+ + "which were added since add "+ "index %v", processedCount, idx) + + lastLogTime = time.Now() } } @@ -982,7 +997,7 @@ func (i *SQLStore) InvoicesAddedSince(ctx context.Context, idx uint64) ( } elapsed := time.Since(start) - log.Debugf("Completed scanning invoices added since index %v: "+ + log.Debugf("Completed scanning for invoices added since index %v: "+ "total_processed=%d, found_invoices=%d, elapsed=%v", idx, processedCount, len(result), elapsed.Round(time.Millisecond))