From 657d4fe978ebd16e05215b20d929b2c49a32cd1a Mon Sep 17 00:00:00 2001
From: Julian Noble <julian@precisium.com.au>
Date: Thu, 24 Jul 2025 00:52:47 +1000
Subject: [PATCH] punkcheck stderr msgs for performance testing on problematic
 machines

---
 src/bootsupport/modules/punkcheck-0.1.0.tm | 13 +++++++++++++
 src/modules/punkcheck-0.1.0.tm             | 13 +++++++++++++
 2 files changed, 26 insertions(+)

diff --git a/src/bootsupport/modules/punkcheck-0.1.0.tm b/src/bootsupport/modules/punkcheck-0.1.0.tm
index 2c07e246..8f830844 100644
--- a/src/bootsupport/modules/punkcheck-0.1.0.tm
+++ b/src/bootsupport/modules/punkcheck-0.1.0.tm
@@ -1665,7 +1665,13 @@ namespace eval punkcheck {
                 #Note this isn't a recordlist function - so it doesn't purely operate on the records
                 #this hits the filesystem for the sourcepath - gets checksums/timestamps depending on config.
                 #It doesn't save to .punkcheck (the only punkcheck::installfile_ method which doesn't)
+                set ts1 [clock milliseconds]
                 set filerec [punkcheck::installfile_add_source_and_fetch_metadata $punkcheck_folder $relative_source_path $filerec]
+                set ts2 [clock milliseconds]
+                set diff [expr {$ts2 - $ts1}]
+                if {$diff > 100} {
+                    puts stderr "punkcheck: performance warning: fetch_metdata for $m took $diff ms"
+                }
 
 
 
@@ -1689,6 +1695,7 @@ namespace eval punkcheck {
                     lappend files_copied $current_source_dir/$m
                 } else {
                     if {![file exists $current_target_dir/$m]} {
+                        puts stderr "punkcheck: first copy to $current_target_dir/$m "
                         file mkdir $current_target_dir
                         file copy $current_source_dir/$m $current_target_dir
                         set new_tgt_cksum_info [punk::mix::base::lib::cksum_path $current_target_dir/$m]
@@ -1699,9 +1706,15 @@ namespace eval punkcheck {
                             installedsourcechanged-targets {
                                 if {[llength $changed]} {
                                     #An unrecorded installation is considered a source change (from unknown/unrecorded source to recorded)
+                                    puts -nonewline stderr "punkcheck: about to: file copy -force $current_source_dir/$m $current_target_dir"
+                                    set ts1 [clock milliseconds]
                                     file mkdir $current_target_dir
                                     file copy -force $current_source_dir/$m $current_target_dir
+                                    set ts2 [clock milliseconds]
+                                    puts -nonewline stderr " (copy time [expr {$ts2 - $ts1}] ms)"
                                     set new_tgt_cksum_info [punk::mix::base::lib::cksum_path $current_target_dir/$m]
+                                    set ts3 [clock milliseconds]
+                                    puts stderr " (cksum time [expr {$ts2 - $ts1}] ms)"
                                     lappend files_copied $current_source_dir/$m
                                 } else {
                                     set is_skip 1
diff --git a/src/modules/punkcheck-0.1.0.tm b/src/modules/punkcheck-0.1.0.tm
index 2c07e246..8f830844 100644
--- a/src/modules/punkcheck-0.1.0.tm
+++ b/src/modules/punkcheck-0.1.0.tm
@@ -1665,7 +1665,13 @@ namespace eval punkcheck {
                 #Note this isn't a recordlist function - so it doesn't purely operate on the records
                 #this hits the filesystem for the sourcepath - gets checksums/timestamps depending on config.
                 #It doesn't save to .punkcheck (the only punkcheck::installfile_ method which doesn't)
+                set ts1 [clock milliseconds]
                 set filerec [punkcheck::installfile_add_source_and_fetch_metadata $punkcheck_folder $relative_source_path $filerec]
+                set ts2 [clock milliseconds]
+                set diff [expr {$ts2 - $ts1}]
+                if {$diff > 100} {
+                    puts stderr "punkcheck: performance warning: fetch_metdata for $m took $diff ms"
+                }
 
 
 
@@ -1689,6 +1695,7 @@ namespace eval punkcheck {
                     lappend files_copied $current_source_dir/$m
                 } else {
                     if {![file exists $current_target_dir/$m]} {
+                        puts stderr "punkcheck: first copy to $current_target_dir/$m "
                         file mkdir $current_target_dir
                         file copy $current_source_dir/$m $current_target_dir
                         set new_tgt_cksum_info [punk::mix::base::lib::cksum_path $current_target_dir/$m]
@@ -1699,9 +1706,15 @@ namespace eval punkcheck {
                             installedsourcechanged-targets {
                                 if {[llength $changed]} {
                                     #An unrecorded installation is considered a source change (from unknown/unrecorded source to recorded)
+                                    puts -nonewline stderr "punkcheck: about to: file copy -force $current_source_dir/$m $current_target_dir"
+                                    set ts1 [clock milliseconds]
                                     file mkdir $current_target_dir
                                     file copy -force $current_source_dir/$m $current_target_dir
+                                    set ts2 [clock milliseconds]
+                                    puts -nonewline stderr " (copy time [expr {$ts2 - $ts1}] ms)"
                                     set new_tgt_cksum_info [punk::mix::base::lib::cksum_path $current_target_dir/$m]
+                                    set ts3 [clock milliseconds]
+                                    puts stderr " (cksum time [expr {$ts2 - $ts1}] ms)"
                                     lappend files_copied $current_source_dir/$m
                                 } else {
                                     set is_skip 1