feat: implement -p flag for print statistics

README.md

@@ -154,6 +154,16 @@ switches are most important to you to have implemented next in the new sqlcmd.
 - `:Connect` now has an optional `-G` parameter to select one of the authentication methods for Azure SQL Database  - `SqlAuthentication`, `ActiveDirectoryDefault`, `ActiveDirectoryIntegrated`, `ActiveDirectoryServicePrincipal`, `ActiveDirectoryManagedIdentity`, `ActiveDirectoryPassword`. If `-G` is not provided, either Integrated security or SQL Authentication will be used, dependent on the presence of a `-U` username parameter.
 - The new `--driver-logging-level` command line parameter allows you to see traces from the `go-mssqldb` client driver. Use `64` to see all traces.
 - Sqlcmd can now print results using a vertical format. Use the new `--vertical` command line option to set it. It's also controlled by the `SQLCMDFORMAT` scripting variable.
+- `-p` prints performance statistics after each batch execution. Use `-p` for standard format or `-p1` for colon-separated format suitable for parsing.
+
+```
+1> select 1
+2> go
+
+Network packet size (bytes): 4096
+1 xact[s]:
+Clock Time (ms.): total         5  avg   5.00 (200.00 xacts per sec.)
+```
 
 ```
 1> select session_id, client_interface_name, program_name from sys.dm_exec_sessions where session_id=@@spid

cmd/sqlcmd/sqlcmd.go

@@ -82,6 +82,7 @@ type SQLCmdArguments struct {
 	ChangePassword              string
 	ChangePasswordAndExit       string
 	TraceFile                   string
+	PrintStatistics             *int
 	// Keep Help at the end of the list
 	Help bool
 }
@@ -126,6 +127,7 @@ const (
 	disableCmdAndWarn       = "disable-cmd-and-warn"
 	listServers             = "list-servers"
 	removeControlCharacters = "remove-control-characters"
+	printStatistics         = "print-statistics"
 )
 
 func encryptConnectionAllowsTLS(value string) bool {
@@ -330,6 +332,7 @@ func checkDefaultValue(args []string, i int) (val string) {
 		'k': "0",
 		'L': "|", // | is the sentinel for no value since users are unlikely to use it. It's "reserved" in most shells
 		'X': "0",
+		'p': "0",
 	}
 	if isFlag(args[i]) && len(args[i]) == 2 && (len(args) == i+1 || args[i+1][0] == '-') {
 		if v, ok := flags[rune(args[i][1])]; ok {
@@ -393,6 +396,7 @@ func SetScreenWidthFlags(args *SQLCmdArguments, rootCmd *cobra.Command) {
 	args.DisableCmd = getOptionalIntArgument(rootCmd, disableCmdAndWarn)
 	args.ErrorsToStderr = getOptionalIntArgument(rootCmd, errorsToStderr)
 	args.RemoveControlCharacters = getOptionalIntArgument(rootCmd, removeControlCharacters)
+	args.PrintStatistics = getOptionalIntArgument(rootCmd, printStatistics)
 }
 
 func setFlags(rootCmd *cobra.Command, args *SQLCmdArguments) {
@@ -475,6 +479,7 @@ func setFlags(rootCmd *cobra.Command, args *SQLCmdArguments) {
 	_ = rootCmd.Flags().BoolP("client-regional-setting", "R", false, localizer.Sprintf("Provided for backward compatibility. Client regional settings are not used"))
 	_ = rootCmd.Flags().IntP(removeControlCharacters, "k", 0, localizer.Sprintf("%s Remove control characters from output. Pass 1 to substitute a space per character, 2 for a space per consecutive characters", "-k [1|2]"))
 	rootCmd.Flags().BoolVarP(&args.EchoInput, "echo-input", "e", false, localizer.Sprintf("Echo input"))
+	_ = rootCmd.Flags().IntP(printStatistics, "p", 0, localizer.Sprintf("%s Print performance statistics after each batch. Pass 1 for colon-separated format", "-p[1]"))
 	rootCmd.Flags().IntVarP(&args.QueryTimeout, "query-timeout", "t", 0, "Query timeout")
 	rootCmd.Flags().BoolVarP(&args.EnableColumnEncryption, "enable-column-encryption", "g", false, localizer.Sprintf("Enable column encryption"))
 	rootCmd.Flags().StringVarP(&args.ChangePassword, "change-password", "z", "", localizer.Sprintf("New password"))
@@ -543,6 +548,14 @@ func normalizeFlags(cmd *cobra.Command) error {
 				err = invalidParameterError("-k", v, "1", "2")
 				return pflag.NormalizedName("")
 			}
+		case printStatistics:
+			switch v {
+			case "0", "1":
+				return pflag.NormalizedName(name)
+			default:
+				err = invalidParameterError("-p", v, "0", "1")
+				return pflag.NormalizedName("")
+			}
 		}
 
 		return pflag.NormalizedName(name)
@@ -812,6 +825,7 @@ func run(vars *sqlcmd.Variables, args *SQLCmdArguments) (int, error) {
 	s.SetupCloseHandler()
 	defer s.StopCloseHandler()
 	s.UnicodeOutputFile = args.UnicodeOutputFile
+	s.PrintStatistics = args.PrintStatistics
 
 	if args.DisableCmd != nil {
 		s.Cmd.DisableSysCommands(args.errorOnBlockedCmd())

cmd/sqlcmd/sqlcmd_test.go

@@ -99,6 +99,12 @@ func TestValidCommandLineToArgsConversion(t *testing.T) {
 		{[]string{"-k", "-X", "-r", "-z", "something"}, func(args SQLCmdArguments) bool {
 			return args.warnOnBlockedCmd() && !args.useEnvVars() && args.getControlCharacterBehavior() == sqlcmd.ControlRemove && *args.ErrorsToStderr == 0 && args.ChangePassword == "something"
 		}},
+		{[]string{"-p"}, func(args SQLCmdArguments) bool {
+			return args.PrintStatistics != nil && *args.PrintStatistics == 0
+		}},
+		{[]string{"-p", "1"}, func(args SQLCmdArguments) bool {
+			return args.PrintStatistics != nil && *args.PrintStatistics == 1
+		}},
 		{[]string{"-N"}, func(args SQLCmdArguments) bool {
 			return args.EncryptConnection == "true"
 		}},

pkg/sqlcmd/commands.go

@@ -249,7 +249,9 @@ func exitCommand(s *Sqlcmd, args []string, line uint) error {
 
 	if len(query1) > 0 || len(query2) > 0 {
 		query := query1 + SqlcmdEol + query2
-		s.Exitcode, _ = s.runQuery(query)
+		var elapsedMs int64
+		s.Exitcode, elapsedMs, _ = s.runQuery(query)
+		s.printStatistics(elapsedMs, 1, s.GetOutput())
 	}
 	return ErrExitRequested
 }
@@ -290,12 +292,16 @@ func goCommand(s *Sqlcmd, args []string, line uint) error {
 		return nil
 	}
 	query = s.getRunnableQuery(query)
+	var totalElapsedMs int64
 	for i := 0; i < n; i++ {
-		if retcode, err := s.runQuery(query); err != nil {
+		retcode, elapsedMs, err := s.runQuery(query)
+		totalElapsedMs += elapsedMs
+		if err != nil {
 			s.Exitcode = retcode
 			return err
 		}
 	}
+	s.printStatistics(totalElapsedMs, n, s.GetOutput())
 	s.batch.Reset(nil)
 	return nil
 }

pkg/sqlcmd/sqlcmd.go

@@ -86,8 +86,11 @@ type Sqlcmd struct {
 	UnicodeOutputFile bool
 	// EchoInput tells the GO command to print the batch text before running the query
 	EchoInput bool
-	colorizer color.Colorizer
-	termchan  chan os.Signal
+	// PrintStatistics controls printing of performance statistics after each batch
+	// nil means disabled, 0 means standard format, 1 means colon-separated format
+	PrintStatistics *int
+	colorizer       color.Colorizer
+	termchan        chan os.Signal
 }
 
 // New creates a new Sqlcmd instance.
@@ -413,14 +416,16 @@ func (s *Sqlcmd) getRunnableQuery(q string) string {
 	return b.String()
 }
 
-// runQuery runs the query and prints the results
-// The return value is based on the first cell of the last column of the last result set.
+// runQuery runs the query and prints the results.
+// Returns (exitcode, elapsedMs, error).
+// The exitcode is based on the first cell of the last column of the last result set.
 // If it's numeric, it will be converted to int
 // -100 : Error encountered prior to selecting return value
 // -101: No rows found
 // -102: Conversion error occurred when selecting return value
-func (s *Sqlcmd) runQuery(query string) (int, error) {
+func (s *Sqlcmd) runQuery(query string) (int, int64, error) {
 	retcode := -101
+	startTime := time.Now()
 	s.Format.BeginBatch(query, s.vars, s.GetOutput(), s.GetError())
 	ctx := context.Background()
 	timeout := s.vars.QueryTimeoutSeconds()
@@ -508,7 +513,8 @@ func (s *Sqlcmd) runQuery(query string) (int, error) {
 		}
 	}
 	s.Format.EndBatch()
-	return retcode, qe
+	elapsedMs := time.Since(startTime).Milliseconds()
+	return retcode, elapsedMs, qe
 }
 
 // returns ErrExitRequested if the error is a SQL error and satisfies the connection's error handling configuration
@@ -580,3 +586,38 @@ func (s *Sqlcmd) SetupCloseHandler() {
 func (s *Sqlcmd) StopCloseHandler() {
 	signal.Stop(s.termchan)
 }
+
+// printStatistics prints performance statistics after a batch execution
+// if PrintStatistics is enabled. The out parameter controls where the
+// statistics are written (typically s.GetOutput(), or s.GetStat() when
+// :perftrace redirection is active).
+func (s *Sqlcmd) printStatistics(elapsedMs int64, numBatches int, out io.Writer) {
+	if s.PrintStatistics == nil || numBatches <= 0 {
+		return
+	}
+
+	// Get packet size from connect settings or use default
+	packetSize := s.Connect.PacketSize
+	if packetSize <= 0 {
+		packetSize = 4096 // default packet size
+	}
+
+	// Ensure minimum 1ms for calculations
+	if elapsedMs < 1 {
+		elapsedMs = 1
+	}
+
+	avgTime := float64(elapsedMs) / float64(numBatches)
+	batchesPerSec := float64(numBatches) / (float64(elapsedMs) / 1000.0)
+
+	if *s.PrintStatistics == 1 {
+		// Colon-separated format: n:x:t1:t2:t3
+		// packetSize:numBatches:totalTime:avgTime:batchesPerSec
+		_, _ = fmt.Fprintf(out, "\n%d:%d:%d:%.2f:%.2f\n", packetSize, numBatches, elapsedMs, avgTime, batchesPerSec)
+	} else {
+		// Standard format
+		_, _ = fmt.Fprintf(out, "\nNetwork packet size (bytes): %d\n", packetSize)
+		_, _ = fmt.Fprintf(out, "%d xact[s]:\n", numBatches)
+		_, _ = fmt.Fprintf(out, "Clock Time (ms.): total   %7d  avg   %.2f (%.2f xacts per sec.)\n", elapsedMs, avgTime, batchesPerSec)
+	}
+}

pkg/sqlcmd/sqlcmd_test.go

@@ -289,27 +289,27 @@ func TestExitInitialQuery(t *testing.T) {
 func TestExitCodeSetOnError(t *testing.T) {
 	s, _ := setupSqlCmdWithMemoryOutput(t)
 	s.Connect.ErrorSeverityLevel = 12
-	retcode, err := s.runQuery("RAISERROR (N'Testing!' , 11, 1)")
+	retcode, _, err := s.runQuery("RAISERROR (N'Testing!' , 11, 1)")
 	assert.NoError(t, err, "!ExitOnError 11")
 	assert.Equal(t, -101, retcode, "Raiserror below ErrorSeverityLevel")
-	retcode, err = s.runQuery("RAISERROR (N'Testing!' , 14, 1)")
+	retcode, _, err = s.runQuery("RAISERROR (N'Testing!' , 14, 1)")
 	assert.NoError(t, err, "!ExitOnError 14")
 	assert.Equal(t, 14, retcode, "Raiserror above ErrorSeverityLevel")
 	s.Connect.ExitOnError = true
-	retcode, err = s.runQuery("RAISERROR (N'Testing!' , 11, 1)")
+	retcode, _, err = s.runQuery("RAISERROR (N'Testing!' , 11, 1)")
 	assert.NoError(t, err, "ExitOnError and Raiserror below ErrorSeverityLevel")
 	assert.Equal(t, -101, retcode, "Raiserror below ErrorSeverityLevel")
-	retcode, err = s.runQuery("RAISERROR (N'Testing!' , 14, 1)")
+	retcode, _, err = s.runQuery("RAISERROR (N'Testing!' , 14, 1)")
 	assert.ErrorIs(t, err, ErrExitRequested, "ExitOnError and Raiserror above ErrorSeverityLevel")
 	assert.Equal(t, 14, retcode, "ExitOnError and Raiserror above ErrorSeverityLevel")
 	s.Connect.ErrorSeverityLevel = 0
-	retcode, err = s.runQuery("RAISERROR (N'Testing!' , 11, 1)")
+	retcode, _, err = s.runQuery("RAISERROR (N'Testing!' , 11, 1)")
 	assert.ErrorIs(t, err, ErrExitRequested, "ExitOnError and ErrorSeverityLevel = 0, Raiserror above 10")
 	assert.Equal(t, 1, retcode, "ExitOnError and ErrorSeverityLevel = 0, Raiserror above 10")
-	retcode, err = s.runQuery("RAISERROR (N'Testing!' , 5, 1)")
+	retcode, _, err = s.runQuery("RAISERROR (N'Testing!' , 5, 1)")
 	assert.NoError(t, err, "ExitOnError and ErrorSeverityLevel = 0, Raiserror below 10")
 	assert.Equal(t, -101, retcode, "ExitOnError and ErrorSeverityLevel = 0, Raiserror below 10")
-	retcode, err = s.runQuery("RAISERROR (15002, 10, 127, 'param')")
+	retcode, _, err = s.runQuery("RAISERROR (15002, 10, 127, 'param')")
 	assert.ErrorIs(t, err, ErrExitRequested, "RAISERROR with state 127")
 	assert.Equal(t, 15002, retcode, "RAISERROR (15002, 10, 127, 'param')")
 }
@@ -441,7 +441,7 @@ func TestVerticalLayoutNoColumns(t *testing.T) {
 	s, buf := setupSqlCmdWithMemoryOutput(t)
 	defer buf.Close()
 	s.vars.Set(SQLCMDFORMAT, "vert")
-	_, err := s.runQuery("SELECT 100 as 'column1', 2000 as 'col2', 300")
+	_, _, err := s.runQuery("SELECT 100 as 'column1', 2000 as 'col2', 300")
 	assert.NoError(t, err, "runQuery failed")
 	assert.Equal(t,
 		"100"+SqlcmdEol+"2000"+SqlcmdEol+"300"+SqlcmdEol+SqlcmdEol+SqlcmdEol+oneRowAffected+SqlcmdEol,
@@ -451,15 +451,15 @@ func TestVerticalLayoutNoColumns(t *testing.T) {
 func TestSelectGuidColumn(t *testing.T) {
 	s, buf := setupSqlCmdWithMemoryOutput(t)
 	defer buf.Close()
-	_, err := s.runQuery("select convert(uniqueidentifier, N'3ddba21e-ff0f-4d24-90b4-f355864d7865')")
+	_, _, err := s.runQuery("select convert(uniqueidentifier, N'3ddba21e-ff0f-4d24-90b4-f355864d7865')")
 	assert.NoError(t, err, "runQuery failed")
 	assert.Equal(t, "3ddba21e-ff0f-4d24-90b4-f355864d7865"+SqlcmdEol+SqlcmdEol+oneRowAffected+SqlcmdEol, buf.buf.String(), "select a uniqueidentifier should work")
 }
 
 func TestSelectNullGuidColumn(t *testing.T) {
 	s, buf := setupSqlCmdWithMemoryOutput(t)
 	defer buf.Close()
-	_, err := s.runQuery("select convert(uniqueidentifier,null)")
+	_, _, err := s.runQuery("select convert(uniqueidentifier,null)")
 	assert.NoError(t, err, "runQuery failed")
 	assert.Equal(t, "NULL"+SqlcmdEol+SqlcmdEol+oneRowAffected+SqlcmdEol, buf.buf.String(), "select a null uniqueidentifier should work")
 }
@@ -469,7 +469,7 @@ func TestVerticalLayoutWithColumns(t *testing.T) {
 	defer buf.Close()
 	s.vars.Set(SQLCMDFORMAT, "vert")
 	s.vars.Set(SQLCMDMAXVARTYPEWIDTH, "256")
-	_, err := s.runQuery("SELECT 100 as 'column1', 2000 as 'col2', 300")
+	_, _, err := s.runQuery("SELECT 100 as 'column1', 2000 as 'col2', 300")
 	assert.NoError(t, err, "runQuery failed")
 	assert.Equal(t,
 		"column1 100"+SqlcmdEol+"col2    2000"+SqlcmdEol+"        300"+SqlcmdEol+SqlcmdEol+SqlcmdEol+oneRowAffected+SqlcmdEol,
@@ -591,7 +591,7 @@ func TestQueryTimeout(t *testing.T) {
 	s, buf := setupSqlCmdWithMemoryOutput(t)
 	defer buf.Close()
 	s.vars.Set(SQLCMDSTATTIMEOUT, "1")
-	i, err := s.runQuery("waitfor delay '00:00:10'")
+	i, _, err := s.runQuery("waitfor delay '00:00:10'")
 	if assert.NoError(t, err, "runQuery returned an error") {
 		assert.Equal(t, -100, i, "return from runQuery")
 		assert.Equal(t, "Timeout expired"+SqlcmdEol, buf.buf.String(), "Query should have timed out")
@@ -705,3 +705,47 @@ func TestSqlcmdPrefersSharedMemoryProtocol(t *testing.T) {
 	assert.EqualValuesf(t, "np", msdsn.ProtocolParsers[3].Protocol(), "np should be fourth protocol")
 
 }
+
+func TestPrintStatisticsStandardFormat(t *testing.T) {
+	s, buf := setupSqlCmdWithMemoryOutput(t)
+	defer func() { _ = buf.Close() }()
+	standardFormat := 0
+	s.PrintStatistics = &standardFormat
+	s.Connect.PacketSize = 4096
+	_, elapsedMs, err := s.runQuery("SELECT 1")
+	assert.NoError(t, err, "runQuery failed")
+	s.printStatistics(elapsedMs, 1, s.GetOutput())
+	output := buf.buf.String()
+	// Standard format should contain specific phrases
+	assert.Contains(t, output, "Network packet size (bytes): 4096", "Should contain packet size")
+	assert.Contains(t, output, "xact[s]:", "Should contain xacts label")
+	assert.Contains(t, output, "Clock Time (ms.):", "Should contain clock time label")
+	assert.Contains(t, output, "xacts per sec.", "Should contain xacts per sec")
+}
+
+func TestPrintStatisticsColonFormat(t *testing.T) {
+	s, buf := setupSqlCmdWithMemoryOutput(t)
+	defer func() { _ = buf.Close() }()
+	colonFormat := 1
+	s.PrintStatistics = &colonFormat
+	s.Connect.PacketSize = 8192
+	_, elapsedMs, err := s.runQuery("SELECT 1")
+	assert.NoError(t, err, "runQuery failed")
+	s.printStatistics(elapsedMs, 1, s.GetOutput())
+	output := buf.buf.String()
+	// Colon format: packetSize:numBatches:totalTime:avgTime:batchesPerSec
+	// Should start with 8192:1:
+	assert.Contains(t, output, "8192:1:", "Should contain packet size and batch count in colon format")
+}
+
+func TestPrintStatisticsDisabled(t *testing.T) {
+	s, buf := setupSqlCmdWithMemoryOutput(t)
+	defer func() { _ = buf.Close() }()
+	// PrintStatistics is nil by default (disabled)
+	_, _, err := s.runQuery("SELECT 1")
+	assert.NoError(t, err, "runQuery failed")
+	output := buf.buf.String()
+	// Should not contain statistics output
+	assert.NotContains(t, output, "Network packet size", "Should not contain packet size when disabled")
+	assert.NotContains(t, output, "xact[s]:", "Should not contain xacts label when disabled")
+}