public void ExecuteNextCommand() { ReplayCommand cmd = GetNextCommand(); if (cmd != null) { ExecuteCommand(cmd); commandCount++; } }
private void RaiseErrorEvent(ReplayCommand Command, string ErrorMessage, SqlConnection conn) { string msg = ""; msg += "DATABASE:" + Environment.NewLine; msg += Command.Database + Environment.NewLine; msg += "MESSAGE:" + Environment.NewLine; msg += ErrorMessage + Environment.NewLine; msg += "--------------------" + Environment.NewLine; msg += Command.CommandText; RaiseErrorEvent("WorkloadTools.Replay", msg, UserErrorType.Error, conn); }
public ReplayCommand GetNextCommand() { ReplayCommand result = null; while (!Commands.TryDequeue(out result)) { if (stopped) { return(null); } _spinWait.SpinOnce(); } return(result); }
public ReplayCommand GetNextCommand() { ReplayCommand result = null; while (!Commands.TryDequeue(out result)) { if (stopped) { return(null); } Thread.Sleep(10); } return(result); }
private void RaiseErrorEvent(ReplayCommand Command, string ErrorMessage, SqlConnection conn) { // Raise a custom event. Both SqlTrace and Extended Events can capture this event. string sql = "EXEC sp_trace_generateevent @eventid = 83, @userinfo = @userinfo, @userdata = @userdata;"; using (SqlCommand cmd = new SqlCommand(sql)) { cmd.Connection = conn; cmd.Parameters.AddWithValue("@userinfo", "WorkloadTools.Replay"); string msg = ""; msg += "DATABASE:" + Environment.NewLine; msg += Command.Database + Environment.NewLine; msg += "MESSAGE:" + Environment.NewLine; msg += ErrorMessage + Environment.NewLine; msg += "--------------------" + Environment.NewLine; msg += Command.CommandText; cmd.Parameters.AddWithValue("@userdata", Encoding.Unicode.GetBytes(msg.Substring(0, msg.Length > 8000 ? 8000 : msg.Length))); cmd.ExecuteNonQuery(); } }
public void AppendCommand(ReplayCommand cmd) { Commands.Enqueue(cmd); }
public void ExecuteCommand(ReplayCommand command) { LastCommandTime = DateTime.Now; if (conn == null) { try { ConnectionInfo.ApplicationName = "WorkloadTools-ReplayWorker"; if (MimicApplicationName) { ConnectionInfo.ApplicationName = command.ApplicationName; if (String.IsNullOrEmpty(ConnectionInfo.ApplicationName)) { ConnectionInfo.ApplicationName = "WorkloadTools-ReplayWorker"; } } InitializeConnection(); } catch (SqlException se) { logger.Error(se.Message); logger.Error($"Worker [{Name}] - Unable to acquire the connection. Quitting the ReplayWorker"); return; } } if (conn != null) { while (conn.State == System.Data.ConnectionState.Connecting) { if (stopped) { break; } Thread.Sleep(5); } } if (conn == null || (conn.State == System.Data.ConnectionState.Closed) || (conn.State == System.Data.ConnectionState.Broken)) { InitializeConnection(); } // Extract the handle from the prepared statement NormalizedSqlText nst = transformer.Normalize(command.CommandText); if (nst.CommandType == NormalizedSqlText.CommandTypeEnum.SP_RESET_CONNECTION) { //Stop(false); return; } else if (nst.CommandType == NormalizedSqlText.CommandTypeEnum.SP_PREPARE) { command.CommandText = nst.NormalizedText; } else if (nst.CommandType == NormalizedSqlText.CommandTypeEnum.SP_UNPREPARE || nst.CommandType == NormalizedSqlText.CommandTypeEnum.SP_EXECUTE) { // look up the statement to unprepare in the dictionary if (preparedStatements.ContainsKey(nst.Handle)) { command.CommandText = nst.NormalizedText + " " + preparedStatements[nst.Handle]; if (nst.CommandType == NormalizedSqlText.CommandTypeEnum.SP_UNPREPARE) { preparedStatements.Remove(nst.Handle); } } else { return; // statement not found: better return } } try { if (conn.Database != command.Database) { logger.Trace($"Worker [{Name}] - Changing database to {command.Database} "); conn.ChangeDatabase(command.Database); } // if the command comes with a replay sleep, do it now // the amount of milliseconds to sleep is set in // FileWorkloadListener // The other listeners do not set this value, as they // already come with the original timing // // Don't remove the IF test: even Sleep(0) can end up // sleeping for 10ms or more. Sleep guarantees that // the current thread sleeps for AT LEAST the amount // of milliseconds set. if (command.BeforeSleepMilliseconds > 2) { Thread.Sleep(command.BeforeSleepMilliseconds); } using (SqlCommand cmd = new SqlCommand(command.CommandText)) { cmd.Connection = conn; cmd.CommandTimeout = QueryTimeoutSeconds; if (nst.CommandType == NormalizedSqlText.CommandTypeEnum.SP_PREPARE) { if (cmd.CommandText == null) { return; } int handle = -1; try { object res = cmd.ExecuteScalar(); if (res != null) { handle = (int)res; if (!preparedStatements.ContainsKey(nst.Handle)) { preparedStatements.Add(nst.Handle, handle); } } } catch (NullReferenceException) { throw; } } else if (ConsumeResults) { using (SqlDataReader reader = cmd.ExecuteReader()) using (ResultSetConsumer consumer = new ResultSetConsumer(reader)) { consumer.Consume(); } } else { cmd.ExecuteNonQuery(); } } logger.Trace($"Worker [{Name}] - SUCCES - \n{command.CommandText}"); if (commandCount > 0 && commandCount % WorkerStatsCommandCount == 0) { var seconds = (DateTime.Now - previousCPSComputeTime).TotalSeconds; var cps = (commandCount - previousCommandCount) / ((seconds == 0) ? 1 : seconds); previousCPSComputeTime = DateTime.Now; previousCommandCount = commandCount; if (DisplayWorkerStats) { commandsPerSecond.Add((int)cps); cps = commandsPerSecond.Average(); logger.Info($"Worker [{Name}] - {commandCount} commands executed."); logger.Info($"Worker [{Name}] - {Commands.Count} commands pending."); logger.Info($"Worker [{Name}] - {(int)cps} commands per second."); } } } catch (SqlException e) { // handle timeouts if (e.Number == -2) { RaiseTimeoutEvent(command.CommandText, conn); } else { RaiseErrorEvent(command, e.Message, conn); } if (StopOnError) { logger.Error($"Worker[{Name}] - Error: \n{command.CommandText}"); throw; } else { logger.Trace($"Worker [{Name}] - Error: {command.CommandText}"); logger.Warn($"Worker [{Name}] - Error: {e.Message}"); logger.Trace(e.StackTrace); } } catch (Exception e) { if (StopOnError) { logger.Error($"Worker[{Name}] - Error: \n{command.CommandText}"); throw; } else { logger.Error($"Worker [{Name}] - Error: {e.Message}"); logger.Error(e.StackTrace); } } }
public override void ConsumeBuffered(WorkloadEvent evnt) { if (evnt is MessageWorkloadEvent) { MessageWorkloadEvent msgEvent = evnt as MessageWorkloadEvent; if (msgEvent.MsgType == MessageWorkloadEvent.MessageType.TotalEvents) { try { totalEventCount = (long)msgEvent.Value; } catch (Exception e) { logger.Error($"Unable to set the total number of events: {e.Message}"); } } } if (!(evnt is ExecutionWorkloadEvent)) { return; } if (evnt.Type != WorkloadEvent.EventType.RPCCompleted && evnt.Type != WorkloadEvent.EventType.BatchCompleted) { return; } eventCount++; if ((eventCount > 0) && (eventCount % WorkerStatsCommandCount == 0)) { string percentInfo = (totalEventCount > 0) ? "( " + ((eventCount * 100) / totalEventCount).ToString() + "% )" : ""; logger.Info($"{eventCount} events queued for replay {percentInfo}"); } if (startTime == DateTime.MinValue) { startTime = DateTime.Now; } ExecutionWorkloadEvent evt = (ExecutionWorkloadEvent)evnt; ReplayCommand command = new ReplayCommand() { CommandText = evt.Text, Database = evt.DatabaseName, ApplicationName = evt.ApplicationName, ReplayOffset = evt.ReplayOffset, EventSequence = evt.EventSequence }; int session_id = -1; session_id = (int)evt.SPID; ReplayWorker rw = null; if (ReplayWorkers.TryGetValue(session_id, out rw)) { // Ensure that the buffer does not get too big while (rw.QueueLength >= (BufferSize * .9)) { spin.SpinOnce(); } rw.AppendCommand(command); } else { rw = new ReplayWorker() { ConnectionInfo = this.ConnectionInfo, ReplayIntervalSeconds = 0, StopOnError = false, Name = session_id.ToString(), DisplayWorkerStats = this.DisplayWorkerStats, ConsumeResults = this.ConsumeResults, QueryTimeoutSeconds = this.QueryTimeoutSeconds, WorkerStatsCommandCount = this.WorkerStatsCommandCount, MimicApplicationName = this.MimicApplicationName, DatabaseMap = this.DatabaseMap, StartTime = startTime, FailRetryCount = this.FailRetryCount, TimeoutRetryCount = this.TimeoutRetryCount }; ReplayWorkers.TryAdd(session_id, rw); rw.AppendCommand(command); logger.Info($"Worker [{session_id}] - Starting"); } if (runner == null) { runner = new Thread(new ThreadStart( delegate { try { RunWorkers(); } catch (Exception e) { try { logger.Error(e, "Unhandled exception in ReplayConsumer.RunWorkers"); } catch { Console.WriteLine(e.Message); } } } )); runner.IsBackground = true; runner.Start(); } if (sweeper == null) { sweeper = new Thread(new ThreadStart( delegate { try { RunSweeper(); } catch (Exception e) { try { logger.Error(e, "Unhandled exception in TraceManager.RunSweeper"); } catch { Console.WriteLine(e.Message); } } } )); sweeper.IsBackground = true; sweeper.Start(); } }
public void ExecuteCommand(ReplayCommand command) { LastCommandTime = DateTime.Now; if (conn == null) { try { ConnectionInfo.ApplicationName = "WorkloadTools-ReplayWorker"; if (MIMIC_APPLICATION_NAME) { ConnectionInfo.ApplicationName = command.ApplicationName; if (String.IsNullOrEmpty(ConnectionInfo.ApplicationName)) { ConnectionInfo.ApplicationName = "WorkloadTools-ReplayWorker"; } } InitializeConnection(); } catch (SqlException se) { logger.Error(se.Message); logger.Error(String.Format("Worker [{0}] - Unable to acquire the connection. Quitting the ReplayWorker", Name)); return; } } if (conn != null) { while (conn.State == System.Data.ConnectionState.Connecting) { if (stopped) { break; } Thread.Sleep(5); } } if (conn == null || (conn.State == System.Data.ConnectionState.Closed) || (conn.State == System.Data.ConnectionState.Broken)) { conn.ConnectionString += ";MultipleActiveResultSets=true;"; conn.Open(); } // Extract the handle from the prepared statement NormalizedSqlText nst = transformer.Normalize(command.CommandText); if (nst.CommandType == NormalizedSqlText.CommandTypeEnum.SP_RESET_CONNECTION) { //Stop(false); return; } else if (nst.CommandType == NormalizedSqlText.CommandTypeEnum.SP_PREPARE) { command.CommandText = nst.NormalizedText; } else if (nst.CommandType == NormalizedSqlText.CommandTypeEnum.SP_UNPREPARE || nst.CommandType == NormalizedSqlText.CommandTypeEnum.SP_EXECUTE) { // look up the statement to unprepare in the dictionary if (preparedStatements.ContainsKey(nst.Handle)) { command.CommandText = nst.NormalizedText + " " + preparedStatements[nst.Handle]; if (nst.CommandType == NormalizedSqlText.CommandTypeEnum.SP_UNPREPARE) { preparedStatements.Remove(nst.Handle); } } else { return; // statement not found: better return } } try { if (conn.Database != command.Database) { logger.Trace(String.Format("Worker [{0}] - Changing database to {1} ", Name, command.Database)); conn.ChangeDatabase(command.Database); } using (SqlCommand cmd = new SqlCommand(command.CommandText)) { cmd.Connection = conn; cmd.CommandTimeout = DEFAULT_QUERY_TIMEOUT_SECONDS; if (nst.CommandType == NormalizedSqlText.CommandTypeEnum.SP_PREPARE) { if (cmd.CommandText == null) { return; } int handle = -1; try { handle = (int)cmd.ExecuteScalar(); if (!preparedStatements.ContainsKey(nst.Handle)) { preparedStatements.Add(nst.Handle, handle); } } catch (NullReferenceException) { throw; } } else if (CONSUME_RESULTS) { using (SqlDataReader reader = cmd.ExecuteReader()) using (ResultSetConsumer consumer = new ResultSetConsumer(reader)) { consumer.Consume(); } } else { cmd.ExecuteNonQuery(); } } logger.Trace(String.Format("Worker [{0}] - SUCCES - \n{1}", Name, command.CommandText)); if (commandCount > 0 && commandCount % WORKLOAD_INFO_COMMAND_COUNT == 0) { var seconds = (DateTime.Now - previousCPSComputeTime).TotalSeconds; var cps = (commandCount - previousCommandCount) / ((seconds == 0) ? 1 : seconds); previousCPSComputeTime = DateTime.Now; previousCommandCount = commandCount; if (COMPUTE_AVERAGE_STATS) { commandsPerSecond.Add((int)cps); cps = commandsPerSecond.Average(); } logger.Info(String.Format("Worker [{0}] - {1} commands executed.", Name, commandCount)); logger.Info(String.Format("Worker [{0}] - {1} commands pending.", Name, Commands.Count)); logger.Info(String.Format("Worker [{0}] - {1} commands per second.", Name, (int)cps)); } } catch (SqlException e) { // handle timeouts if (e.Number == -2) { RaiseTimeoutEvent(command.CommandText, conn); } if (StopOnError) { logger.Error(String.Format("Worker[{0}] - Error: \n{1}", Name, command.CommandText)); throw; } else { logger.Trace(String.Format("Worker [{0}] - Error: {1}", Name, command.CommandText)); logger.Warn(String.Format("Worker [{0}] - Error: {1}", Name, e.Message)); logger.Trace(e.StackTrace); } } catch (Exception e) { if (StopOnError) { logger.Error(String.Format("Worker[{0}] - Error: \n{1}", Name, command.CommandText)); throw; } else { logger.Error(String.Format("Worker [{0}] - Error: {1}", Name, e.Message)); logger.Error(e.StackTrace); } } }
public override void ConsumeBuffered(WorkloadEvent evnt) { if (!(evnt is ExecutionWorkloadEvent)) { return; } if (evnt.Type != WorkloadEvent.EventType.RPCCompleted && evnt.Type != WorkloadEvent.EventType.BatchCompleted) { return; } ExecutionWorkloadEvent evt = (ExecutionWorkloadEvent)evnt; ReplayCommand command = new ReplayCommand() { CommandText = evt.Text, Database = evt.DatabaseName, ApplicationName = evt.ApplicationName }; int session_id = -1; session_id = (int)evt.SPID; ReplayWorker rw = null; if (ReplayWorkers.TryGetValue(session_id, out rw)) { rw.AppendCommand(command); } else { rw = new ReplayWorker() { ConnectionInfo = this.ConnectionInfo, ReplayIntervalSeconds = 0, StopOnError = false, Name = session_id.ToString() }; ReplayWorkers.TryAdd(session_id, rw); rw.AppendCommand(command); logger.Info(String.Format("Worker [{0}] - Starting", session_id)); } if (runner == null) { runner = new Thread(new ThreadStart( delegate { try { RunWorkers(); } catch (Exception e) { try { logger.Error(e, "Unhandled exception in TraceManager.RunWorkers"); } catch { Console.WriteLine(e.Message); } } } )); runner.IsBackground = true; runner.Start(); } if (sweeper == null) { sweeper = new Thread(new ThreadStart( delegate { try { RunSweeper(); } catch (Exception e) { try { logger.Error(e, "Unhandled exception in TraceManager.RunSweeper"); } catch { Console.WriteLine(e.Message); } } } )); sweeper.IsBackground = true; sweeper.Start(); } }
public void ExecuteCommand(ReplayCommand command) { LastCommandTime = DateTime.Now; if (conn == null) { try { ConnectionInfo.ApplicationName = "WorkloadTools-ReplayWorker"; if (MimicApplicationName) { ConnectionInfo.ApplicationName = command.ApplicationName; if (String.IsNullOrEmpty(ConnectionInfo.ApplicationName)) { ConnectionInfo.ApplicationName = "WorkloadTools-ReplayWorker"; } } InitializeConnection(); } catch (SqlException se) { logger.Error(se.Message); logger.Error($"Worker [{Name}] - Unable to acquire the connection. Quitting the ReplayWorker"); return; } } if (conn != null) { while (conn.State == System.Data.ConnectionState.Connecting) { if (stopped) { break; } Thread.Sleep(5); } } if (conn == null || (conn.State == System.Data.ConnectionState.Closed) || (conn.State == System.Data.ConnectionState.Broken)) { InitializeConnection(); } // Extract the handle from the prepared statement NormalizedSqlText nst = transformer.Normalize(command.CommandText); if (nst.CommandType == NormalizedSqlText.CommandTypeEnum.SP_RESET_CONNECTION) { //Stop(false); return; } else if (nst.CommandType == NormalizedSqlText.CommandTypeEnum.SP_PREPARE) { command.CommandText = nst.NormalizedText; } else if (nst.CommandType == NormalizedSqlText.CommandTypeEnum.SP_UNPREPARE || nst.CommandType == NormalizedSqlText.CommandTypeEnum.SP_EXECUTE) { // look up the statement to unprepare in the dictionary if (preparedStatements.ContainsKey(nst.Handle)) { command.CommandText = nst.NormalizedText + " " + preparedStatements[nst.Handle]; if (nst.CommandType == NormalizedSqlText.CommandTypeEnum.SP_UNPREPARE) { preparedStatements.Remove(nst.Handle); } } else { return; // statement not found: better return } } try { // Try to remap the database according to the database map if (DatabaseMap.ContainsKey(command.Database)) { command.Database = DatabaseMap[command.Database]; } if (conn.Database != command.Database) { logger.Trace($"Worker [{Name}] - Changing database to {command.Database} "); conn.ChangeDatabase(command.Database); } // if the command comes with a replay offset, do it now // the offset in milliseconds is set in // FileWorkloadListener // The other listeners do not set this value, as they // already come with the original timing if (command.ReplayOffset > 0) { // I am using 7 here as an average compensation for sleep // fluctuations due to Windows preemptive scheduling while ((DateTime.Now - StartTime).TotalMilliseconds < command.ReplayOffset - 7) { // Thread.Sleep will not sleep exactly 1 millisecond. // It will yield the current thread and put it back // in the runnable queue once the sleep delay has expired. // This means that the actual sleep time before the // current thread gains back control can be much higher // (15 milliseconds or more) // However we do not need to be super precise here: // each command has a requested offset from the beginning // of the workload and this class does its best to respect it. // If the previous commands take longer in the target environment // the offset cannot be respected and the command will execute // without further waits, but there is no way to recover // the delay that has built up to that point. Thread.Sleep(1); } } using (SqlCommand cmd = new SqlCommand(command.CommandText)) { cmd.Connection = conn; cmd.CommandTimeout = QueryTimeoutSeconds; if (nst.CommandType == NormalizedSqlText.CommandTypeEnum.SP_PREPARE) { if (cmd.CommandText == null) { return; } int handle = -1; try { object res = cmd.ExecuteScalar(); if (res != null) { handle = (int)res; if (!preparedStatements.ContainsKey(nst.Handle)) { preparedStatements.Add(nst.Handle, handle); } } } catch (NullReferenceException) { throw; } } else if (ConsumeResults) { using (SqlDataReader reader = cmd.ExecuteReader()) using (ResultSetConsumer consumer = new ResultSetConsumer(reader)) { consumer.Consume(); } } else { cmd.ExecuteNonQuery(); } } logger.Trace($"Worker [{Name}] - SUCCES - \n{command.CommandText}"); if (commandCount > 0 && commandCount % WorkerStatsCommandCount == 0) { var seconds = (DateTime.Now - previousCPSComputeTime).TotalSeconds; var cps = (commandCount - previousCommandCount) / ((seconds == 0) ? 1 : seconds); previousCPSComputeTime = DateTime.Now; previousCommandCount = commandCount; if (DisplayWorkerStats) { commandsPerSecond.Add((int)cps); cps = commandsPerSecond.Average(); logger.Info($"Worker [{Name}] - {commandCount} commands executed."); logger.Info($"Worker [{Name}] - {Commands.Count} commands pending."); logger.Info($"Worker [{Name}] - Last Event Sequence: {command.EventSequence}"); logger.Info($"Worker [{Name}] - {(int)cps} commands per second."); } } } catch (SqlException e) { // handle timeouts if (e.Number == -2) { RaiseTimeoutEvent(command.CommandText, conn); } else { RaiseErrorEvent(command, e.Message, conn); } if (StopOnError) { logger.Error($"Worker[{Name}] - Sequence[{command.EventSequence}] - Error: \n{command.CommandText}"); throw; } else { logger.Trace($"Worker [{Name}] - Sequence[{command.EventSequence}] - Error: {command.CommandText}"); logger.Warn($"Worker [{Name}] - Sequence[{command.EventSequence}] - Error: {e.Message}"); logger.Trace(e.StackTrace); } } catch (Exception e) { if (StopOnError) { logger.Error($"Worker[{Name}] - Sequence[{command.EventSequence}] - Error: \n{command.CommandText}"); throw; } else { logger.Error($"Worker [{Name}] - Sequence[{command.EventSequence}] - Error: {e.Message}"); logger.Error(e.StackTrace); } } }
public override void ConsumeBuffered(WorkloadEvent evnt) { if (!(evnt is ExecutionWorkloadEvent)) { return; } if (evnt.Type != WorkloadEvent.EventType.RPCCompleted && evnt.Type != WorkloadEvent.EventType.BatchCompleted) { return; } eventCount++; if ((eventCount > 0) && (eventCount % WorkerStatsCommandCount == 0)) { logger.Info($"{eventCount} events queued for replay"); } ExecutionWorkloadEvent evt = (ExecutionWorkloadEvent)evnt; ReplayCommand command = new ReplayCommand() { CommandText = evt.Text, Database = evt.DatabaseName, ApplicationName = evt.ApplicationName, BeforeSleepMilliseconds = evt.ReplaySleepMilliseconds }; int session_id = -1; session_id = (int)evt.SPID; ReplayWorker rw = null; if (ReplayWorkers.TryGetValue(session_id, out rw)) { // Ensure that the buffer does not get too big while (rw.QueueLength >= (BufferSize * .9)) { spin.SpinOnce(); } rw.AppendCommand(command); } else { rw = new ReplayWorker() { ConnectionInfo = this.ConnectionInfo, ReplayIntervalSeconds = 0, StopOnError = false, Name = session_id.ToString(), DisplayWorkerStats = this.DisplayWorkerStats, ConsumeResults = this.ConsumeResults, QueryTimeoutSeconds = this.QueryTimeoutSeconds, WorkerStatsCommandCount = this.WorkerStatsCommandCount, MimicApplicationName = this.MimicApplicationName }; ReplayWorkers.TryAdd(session_id, rw); rw.AppendCommand(command); logger.Info($"Worker [{session_id}] - Starting"); } if (runner == null) { runner = new Thread(new ThreadStart( delegate { try { RunWorkers(); } catch (Exception e) { try { logger.Error(e, "Unhandled exception in TraceManager.RunWorkers"); } catch { Console.WriteLine(e.Message); } } } )); runner.IsBackground = true; runner.Start(); } if (sweeper == null) { sweeper = new Thread(new ThreadStart( delegate { try { RunSweeper(); } catch (Exception e) { try { logger.Error(e, "Unhandled exception in TraceManager.RunSweeper"); } catch { Console.WriteLine(e.Message); } } } )); sweeper.IsBackground = true; sweeper.Start(); } }