802 Reggie Burnett 2009-11-20
refactored our logging output once again. We are going with a more detailed stream of data and will be developing a log viewer application that will provide the ability to search or filter log events. This log viewer app will likely appear in 6.3. We are also now exposing the log data using TraceSource and in a defined format so that custom trace listeners can be written.
modified:
MySql.Data/Provider/Properties/Resources.Designer.cs
MySql.Data/Provider/Properties/Resources.resx
MySql.Data/Provider/Source/Connection.cs
MySql.Data/Provider/Source/Driver.cs
MySql.Data/Provider/Source/MySqlConnectionStringBuilder.cs
MySql.Data/Provider/Source/MySqlPool.cs
MySql.Data/Provider/Source/MySqlTrace.cs
MySql.Data/Provider/Source/PerformanceMonitor.cs
MySql.Data/Provider/Source/ProcedureCache.cs
MySql.Data/Provider/Source/TracingDriver.cs
MySql.Data/Provider/Source/command.cs
MySql.Data/Tests/Source/Logging.cs
MySql.Data/Tests/Source/UsageAdvisor.cs
801 Vladislav Vaintroub 2009-11-12 [merge]
merge
modified:
MySql.Data/Provider/MySql.Data.csproj
MySql.Data/Tests/MySql.Data.Tests.csproj
MySql.VisualStudio/MySql.VisualStudio.csproj
MySql.Web/Providers/MySql.Web.csproj
=== modified file 'MySql.Data/Provider/Properties/Resources.Designer.cs'
=== modified file 'MySql.Data/Provider/Properties/Resources.Designer.cs'
--- a/MySql.Data/Provider/Properties/Resources.Designer.cs 2009-11-11 17:41:52 +0000
+++ b/MySql.Data/Provider/Properties/Resources.Designer.cs 2009-11-20 17:04:03 +0000
@@ -21,9 +21,7 @@
// with the /str option, or rebuild your VS project.
[global::System.CodeDom.Compiler.GeneratedCodeAttribute("System.Resources.Tools.StronglyTypedResourceBuilder", "4.0.0.0")]
[global::System.Diagnostics.DebuggerNonUserCodeAttribute()]
-#if !CF
[global::System.Runtime.CompilerServices.CompilerGeneratedAttribute()]
-#endif
public class Resources {
private static global::System.Resources.ResourceManager resourceMan;
@@ -783,6 +781,105 @@
}
/// <summary>
+ /// Looks up a localized string similar to {1}: Connection Closed.
+ /// </summary>
+ public static string TraceCloseConnection {
+ get {
+ return ResourceManager.GetString("TraceCloseConnection", resourceCulture);
+ }
+ }
+
+ /// <summary>
+ /// Looks up a localized string similar to {1}: Connection Opened: connection string = '{2}'.
+ /// </summary>
+ public static string TraceOpenConnection {
+ get {
+ return ResourceManager.GetString("TraceOpenConnection", resourceCulture);
+ }
+ }
+
+ /// <summary>
+ /// Looks up a localized string similar to {1}: Query Closed.
+ /// </summary>
+ public static string TraceQueryDone {
+ get {
+ return ResourceManager.GetString("TraceQueryDone", resourceCulture);
+ }
+ }
+
+ /// <summary>
+ /// Looks up a localized string similar to {1}: Query Opened: {2}.
+ /// </summary>
+ public static string TraceQueryText {
+ get {
+ return ResourceManager.GetString("TraceQueryText", resourceCulture);
+ }
+ }
+
+ /// <summary>
+ /// Looks up a localized string similar to {1}: Resultset Opened: field(s) = {2}, affected rows = {3}, inserted id = {4}.
+ /// </summary>
+ public static string TraceResult {
+ get {
+ return ResourceManager.GetString("TraceResult", resourceCulture);
+ }
+ }
+
+ /// <summary>
+ /// Looks up a localized string similar to {1}: Resultset Closed: {2} total rows, {3} skipped rows.
+ /// </summary>
+ public static string TraceResultClosed {
+ get {
+ return ResourceManager.GetString("TraceResultClosed", resourceCulture);
+ }
+ }
+
+ /// <summary>
+ /// Looks up a localized string similar to {1}: Set Database: {2}.
+ /// </summary>
+ public static string TraceSetDatabase {
+ get {
+ return ResourceManager.GetString("TraceSetDatabase", resourceCulture);
+ }
+ }
+
+ /// <summary>
+ /// Looks up a localized string similar to {1}: Usage Advisor Warning: Query is using a bad index.
+ /// </summary>
+ public static string TraceUAWarningBadIndex {
+ get {
+ return ResourceManager.GetString("TraceUAWarningBadIndex", resourceCulture);
+ }
+ }
+
+ /// <summary>
+ /// Looks up a localized string similar to {1}: Usage Advisor Warning: Query does not use an index.
+ /// </summary>
+ public static string TraceUAWarningNoIndex {
+ get {
+ return ResourceManager.GetString("TraceUAWarningNoIndex", resourceCulture);
+ }
+ }
+
+ /// <summary>
+ /// Looks up a localized string similar to {1}: Usage Advisor Warning: The following columns were not accessed: {3}.
+ /// </summary>
+ public static string TraceUAWarningSkippedColumns {
+ get {
+ return ResourceManager.GetString("TraceUAWarningSkippedColumns", resourceCulture);
+ }
+ }
+
+ /// <summary>
+ /// Looks up a localized string similar to {1}: Usage Advisor Warning: Skipped {3} rows. Consider a more focused query..
+ /// </summary>
+ public static string TraceUAWarningSkippedRows {
+ get {
+ return ResourceManager.GetString("TraceUAWarningSkippedRows", resourceCulture);
+ }
+ }
+
+ /// <summary>
/// Looks up a localized string similar to Unable to connect to any of the specified MySQL hosts..
/// </summary>
public static string UnableToConnectToHost {
=== modified file 'MySql.Data/Provider/Properties/Resources.resx'
--- a/MySql.Data/Provider/Properties/Resources.resx 2009-10-22 15:27:25 +0000
+++ b/MySql.Data/Provider/Properties/Resources.resx 2009-11-20 17:04:03 +0000
@@ -393,4 +393,37 @@
<data name="InvalidConnectionStringValue" xml:space="preserve">
<value>The requested value '{0}' is invalid for the given keyword '{1}'.</value>
</data>
+ <data name="TraceCloseConnection" xml:space="preserve">
+ <value>{1}: Connection Closed</value>
+ </data>
+ <data name="TraceOpenConnection" xml:space="preserve">
+ <value>{1}: Connection Opened: connection string = '{2}'</value>
+ </data>
+ <data name="TraceQueryText" xml:space="preserve">
+ <value>{1}: Query Opened: {2}</value>
+ </data>
+ <data name="TraceResult" xml:space="preserve">
+ <value>{1}: Resultset Opened: field(s) = {2}, affected rows = {3}, inserted id = {4}</value>
+ </data>
+ <data name="TraceQueryDone" xml:space="preserve">
+ <value>{1}: Query Closed</value>
+ </data>
+ <data name="TraceSetDatabase" xml:space="preserve">
+ <value>{1}: Set Database: {2}</value>
+ </data>
+ <data name="TraceUAWarningBadIndex" xml:space="preserve">
+ <value>{1}: Usage Advisor Warning: Query is using a bad index</value>
+ </data>
+ <data name="TraceUAWarningNoIndex" xml:space="preserve">
+ <value>{1}: Usage Advisor Warning: Query does not use an index</value>
+ </data>
+ <data name="TraceResultClosed" xml:space="preserve">
+ <value>{1}: Resultset Closed: {2} total rows, {3} skipped rows</value>
+ </data>
+ <data name="TraceUAWarningSkippedRows" xml:space="preserve">
+ <value>{1}: Usage Advisor Warning: Skipped {3} rows. Consider a more focused query.</value>
+ </data>
+ <data name="TraceUAWarningSkippedColumns" xml:space="preserve">
+ <value>{1}: Usage Advisor Warning: The following columns were not accessed: {3}</value>
+ </data>
</root>
\ No newline at end of file
=== modified file 'MySql.Data/Provider/Source/Connection.cs'
--- a/MySql.Data/Provider/Source/Connection.cs 2009-11-03 18:00:36 +0000
+++ b/MySql.Data/Provider/Source/Connection.cs 2009-11-20 17:04:03 +0000
@@ -458,7 +458,7 @@
// if the user is using old syntax, let them know
if (driver.Settings.UseOldSyntax)
- MySqlTrace.LogWarning(
+ MySqlTrace.LogWarning(ServerThread,
"You are using old syntax that will be removed in future versions");
SetState(ConnectionState.Open, false);
@@ -637,7 +637,7 @@
}
catch (Exception ex)
{
- MySqlTrace.LogWarning("Could not kill query in timeout handler, " +
+ MySqlTrace.LogWarning(ServerThread, "Could not kill query in timeout handler, " +
" aborting connection. Exception was " + ex.Message);
Abort();
isFatal = true;
=== modified file 'MySql.Data/Provider/Source/Driver.cs'
--- a/MySql.Data/Provider/Source/Driver.cs 2009-11-11 19:49:07 +0000
+++ b/MySql.Data/Provider/Source/Driver.cs 2009-11-20 17:04:03 +0000
@@ -241,7 +241,7 @@
}
catch (Exception ex)
{
- MySqlTrace.LogError(ex.Message);
+ MySqlTrace.LogError(ThreadID, ex.Message);
throw;
}
}
@@ -317,7 +317,7 @@
}
catch (Exception ex)
{
- MySqlTrace.LogError(ex.Message);
+ MySqlTrace.LogError(ThreadID, ex.Message);
throw;
}
}
@@ -360,7 +360,7 @@
firstResult = false;
int affectedRows = -1, insertedId = -1;
- int fieldCount = GetResult(ref affectedRows, ref insertedId);
+ int fieldCount = GetResult(statementId, ref affectedRows, ref insertedId);
if (fieldCount == -1)
return null;
if (fieldCount > 0)
@@ -369,7 +369,7 @@
return new ResultSet(affectedRows, insertedId);
}
- protected virtual int GetResult(ref int affectedRows, ref int insertedId)
+ protected virtual int GetResult(int statementId, ref int affectedRows, ref int insertedId)
{
return handler.GetResult(ref affectedRows, ref insertedId);
}
@@ -384,7 +384,7 @@
return FetchDataRow(-1, 0);
}
- public void ExecuteDirect(string sql)
+ public virtual void ExecuteDirect(string sql)
{
MySqlPacket p = new MySqlPacket(Encoding);
p.WriteString(sql);
@@ -402,7 +402,7 @@
return fields;
}
- public int PrepareStatement(string sql, ref MySqlField[] parameters)
+ public virtual int PrepareStatement(string sql, ref MySqlField[] parameters)
{
return handler.PrepareStatement(sql, ref parameters);
}
@@ -427,34 +427,27 @@
return handler.Ping();
}
- public void SetDatabase(string dbName)
+ public virtual void SetDatabase(string dbName)
{
handler.SetDatabase(dbName);
}
- public void ExecuteStatement(MySqlPacket packetToExecute)
+ public virtual void ExecuteStatement(MySqlPacket packetToExecute)
{
handler.ExecuteStatement(packetToExecute);
}
- public void CloseStatement(int id)
+ public virtual void CloseStatement(int id)
{
handler.CloseStatement(id);
}
- public void Reset()
+ public virtual void Reset()
{
handler.Reset();
}
- private void LogQuery()
- {
- //if (Settings.Logging)
- // Logger.LogCommand(DBCmd.QUERY, encoding.GetString(
- // queryPacket.Buffer, 5, queryPacket.Length - 5));
- }
-
#region IDisposable Members
protected virtual void Dispose(bool disposing)
=== modified file 'MySql.Data/Provider/Source/MySqlConnectionStringBuilder.cs'
--- a/MySql.Data/Provider/Source/MySqlConnectionStringBuilder.cs 2009-11-09 16:35:35 +0000
+++ b/MySql.Data/Provider/Source/MySqlConnectionStringBuilder.cs 2009-11-20 17:04:03 +0000
@@ -233,7 +233,7 @@
uint timeout = Math.Min(value, Int32.MaxValue / 1000);
if (timeout != value)
{
- MySqlTrace.LogWarning("Connection timeout value too large ("
+ MySqlTrace.LogWarning(-1, "Connection timeout value too large ("
+ value + " seconds). Changed to max. possible value" +
+ timeout + " seconds)");
}
@@ -849,9 +849,9 @@
if (!validKeywords.ContainsKey(key))
throw new ArgumentException(Resources.KeywordNotSupported, keyword);
if (validKeywords[key] == "Use Old Syntax")
- MySqlTrace.LogWarning("Use Old Syntax is now obsolete. Please see documentation");
+ MySqlTrace.LogWarning(-1, "Use Old Syntax is now obsolete. Please see documentation");
if (validKeywords[key] == "Encrypt")
- MySqlTrace.LogWarning("Encrypt is now obsolete. Use Ssl Mode instead");
+ MySqlTrace.LogWarning(-1, "Encrypt is now obsolete. Use Ssl Mode instead");
}
private static void Initialize()
=== modified file 'MySql.Data/Provider/Source/MySqlPool.cs'
--- a/MySql.Data/Provider/Source/MySqlPool.cs 2009-10-09 20:38:36 +0000
+++ b/MySql.Data/Provider/Source/MySqlPool.cs 2009-11-20 17:04:03 +0000
@@ -237,7 +237,7 @@
}
catch (Exception ex)
{
- MySqlTrace.LogError(ex.Message);
+ MySqlTrace.LogError(-1, ex.Message);
Interlocked.Increment(ref available);
throw;
}
=== modified file 'MySql.Data/Provider/Source/MySqlTrace.cs'
--- a/MySql.Data/Provider/Source/MySqlTrace.cs 2009-10-09 21:44:54 +0000
+++ b/MySql.Data/Provider/Source/MySqlTrace.cs 2009-11-20 17:04:03 +0000
@@ -25,114 +25,68 @@
namespace MySql.Data.MySqlClient
{
- internal class MySqlTrace
- {
- static MySqlTrace()
- {
- }
-
- public static void LogInformation(string msg)
- {
-#if !CF
- Trace.TraceInformation(
- String.Format("[{0}] - {1}", DateTime.Now, msg));
-#endif
- }
-
- public static void LogWarning(string msg)
- {
-#if !CF
- Trace.TraceWarning(
- String.Format("[{0}] - {1}", DateTime.Now, msg));
-#endif
- }
-
- public static void LogError(string msg)
- {
-#if !CF
- Trace.TraceError(
- String.Format("[{0}] - {1}", DateTime.Now, msg));
-#endif
- }
- }
-
- internal enum UsageAdvisorFlags
- {
- NoIndex = 1,
- BadIndex = 2,
- PartialRowSet = 4
- }
-
-#if !CF
- internal class MySqlTraceResultInfo
- {
- public int RowsRead;
- public int RowsChanged;
- public int RowsSkipped;
- public int InsertedId;
- public List<string> FieldsNotAccessed = new List<string>();
- public UsageAdvisorFlags UAFlags;
-
- public override string ToString()
- {
- StringBuilder msg = new StringBuilder();
- msg.AppendLine("-- Result --");
- if (RowsChanged > -1)
- msg.AppendLine(String.Format("Rows affected: {0}", RowsChanged));
- if (InsertedId > -1)
- msg.AppendLine(String.Format("Inserted Id (if any): {0}", InsertedId));
- if (RowsRead > 0)
- msg.AppendLine(String.Format("Rows returned: {0}", RowsRead));
- if (UAFlags != 0)
- {
- if (RowsSkipped > 0)
- msg.AppendLine(String.Format(
- "UA Warning: not all rows were read. Skipped {0} rows", RowsSkipped));
- if ((UAFlags & UsageAdvisorFlags.NoIndex) != 0)
- msg.AppendLine("UA Warning: query did not use an index");
- if ((UAFlags & UsageAdvisorFlags.BadIndex) != 0)
- msg.AppendLine("UA Warning: query used a bad index");
- if ((UAFlags & UsageAdvisorFlags.PartialRowSet) != 0)
- {
- msg.Append("UA Warning: some fields not accessed (");
- string delimiter = "";
- foreach (string colName in FieldsNotAccessed)
- {
- msg.AppendFormat("{0}{1}", delimiter, colName);
- delimiter = ", ";
- }
- msg.AppendLine(")");
- }
- }
- return msg.ToString();
- }
- }
-
- internal class MySqlTraceQueryInfo
- {
- public string CommandText;
- public string Server;
- public TimeSpan ExecutionTime;
- public DateTime TimeOfQuery;
- public List<MySqlTraceResultInfo> Results = new List<MySqlTraceResultInfo>();
-
- public override string ToString()
- {
- StringBuilder msg = new StringBuilder();
- msg.AppendLine();
- msg.AppendLine("====== Query logged ======");
- msg.AppendLine(String.Format("Time of query: {0}", TimeOfQuery));
- msg.AppendLine(String.Format("host: {0}", Server));
- msg.AppendLine(String.Format("time of execution: {0} seconds ({1} milliseconds",
- ExecutionTime.TotalSeconds, ExecutionTime.TotalMilliseconds));
-
- foreach (MySqlTraceResultInfo ri in Results)
- msg.Append(ri.ToString());
- msg.AppendLine("Command text:");
- msg.AppendLine(CommandText);
- msg.AppendLine("====== End of Query ======");
- return msg.ToString();
- }
- }
-#endif
+ public class MySqlTrace
+ {
+ private static TraceSource source = new TraceSource("mysql");
+
+ public static TraceListenerCollection Listeners
+ {
+ get { return source.Listeners; }
+ }
+
+ public static SourceSwitch Switch
+ {
+ get { return source.Switch; }
+ set { source.Switch = value; }
+ }
+
+ internal static TraceSource Source
+ {
+ get { return source; }
+ }
+
+ internal static void LogInformation(int id, string msg)
+ {
+#if !CF
+ Source.TraceEvent(TraceEventType.Information, id, msg, MySqlTraceEventType.NonQuery, -1);
+ Trace.TraceInformation(msg);
+#endif
+ }
+
+ internal static void LogWarning(int id, string msg)
+ {
+#if !CF
+ Source.TraceEvent(TraceEventType.Warning, id, msg, MySqlTraceEventType.NonQuery, -1);
+ Trace.TraceWarning(msg);
+#endif
+ }
+
+ internal static void LogError(int id, string msg)
+ {
+#if !CF
+ Source.TraceEvent(TraceEventType.Error, id, msg, MySqlTraceEventType.NonQuery, -1);
+ Trace.TraceError(msg);
+#endif
+ }
+ }
+
+ public enum MySqlTraceEventType
+ {
+ ConnectionOpened = 1,
+ ConnectionClosed,
+ QuerySent,
+ ResultOpened,
+ ResultClosed,
+ QueryDone,
+ NonQuery,
+ UsageAdvisorWarning
+ }
+
+ public enum UsageAdvisorWarningFlags
+ {
+ NoIndex,
+ BadIndex,
+ SkippedRows,
+ SkippedColumns
+ }
}
=== modified file 'MySql.Data/Provider/Source/PerformanceMonitor.cs'
--- a/MySql.Data/Provider/Source/PerformanceMonitor.cs 2009-10-09 21:44:54 +0000
+++ b/MySql.Data/Provider/Source/PerformanceMonitor.cs 2009-11-20 17:04:03 +0000
@@ -47,7 +47,7 @@
}
catch (Exception ex)
{
- MySqlTrace.LogError(ex.Message);
+ MySqlTrace.LogError(connection.ServerThread, ex.Message);
}
}
}
=== modified file 'MySql.Data/Provider/Source/ProcedureCache.cs'
--- a/MySql.Data/Provider/Source/ProcedureCache.cs 2009-10-09 21:44:54 +0000
+++ b/MySql.Data/Provider/Source/ProcedureCache.cs 2009-11-20 17:04:03 +0000
@@ -55,7 +55,7 @@
#if !CF
conn.PerfMonitor.AddHardProcedureQuery();
#endif
- MySqlTrace.LogInformation(
+ MySqlTrace.LogInformation(conn.ServerThread,
String.Format(Resources.HardProcQuery, spName));
}
else
@@ -63,7 +63,7 @@
#if !CF
conn.PerfMonitor.AddSoftProcedureQuery();
#endif
- MySqlTrace.LogInformation(
+ MySqlTrace.LogInformation(conn.ServerThread,
String.Format(Resources.SoftProcQuery, spName));
}
return ds;
=== modified file 'MySql.Data/Provider/Source/TracingDriver.cs'
--- a/MySql.Data/Provider/Source/TracingDriver.cs 2009-10-09 21:44:54 +0000
+++ b/MySql.Data/Provider/Source/TracingDriver.cs 2009-11-20 17:04:03 +0000
@@ -23,82 +23,121 @@
using MySql.Data.Types;
using System.Diagnostics;
using System.Collections.Generic;
+using MySql.Data.MySqlClient.Properties;
namespace MySql.Data.MySqlClient
{
internal class TracingDriver : Driver
{
- private Stopwatch timer = new Stopwatch();
- private bool firstResult;
- private MySqlTraceQueryInfo qi;
- private ResultSet lastResult;
+ private Dictionary<int, ResultSet> activeResults = new Dictionary<int, ResultSet>();
public TracingDriver(MySqlConnectionStringBuilder settings)
: base(settings)
{
}
+ private TraceSource Source
+ {
+ get { return MySqlTrace.Source; }
+ }
+
+ public override void Open()
+ {
+ base.Open();
+ Source.TraceEvent(TraceEventType.Information, ThreadID,
+ Resources.TraceOpenConnection, MySqlTraceEventType.ConnectionOpened, -1,
+ Settings.ConnectionString);
+ }
+
+ public override void Close()
+ {
+ base.Close();
+ Source.TraceEvent(TraceEventType.Information, ThreadID, Resources.TraceCloseConnection,
+ MySqlTraceEventType.ConnectionClosed, -1);
+ }
+
public override void SendQuery(MySqlPacket p)
{
- qi = new MySqlTraceQueryInfo();
- qi.Server = Settings.Server;
- //TODO see if output buffering removes this ickyness
string cmdText = Encoding.GetString(p.Buffer, 5, p.Length - 5);
if (cmdText.Length > 300)
cmdText = cmdText.Substring(0, 300);
- qi.CommandText = cmdText;
- qi.TimeOfQuery = DateTime.Now;
+
base.SendQuery(p);
- firstResult = true;
- timer.Reset();
- timer.Start();
+
+ Source.TraceEvent(TraceEventType.Information, ThreadID, Resources.TraceQueryText,
+ MySqlTraceEventType.QuerySent, 0, cmdText);
}
- protected override int GetResult(ref int affectedRows, ref int insertedId)
+ protected override int GetResult(int statementId, ref int affectedRows, ref int insertedId)
{
- int fieldCount = base.GetResult(ref affectedRows, ref insertedId);
- if (firstResult)
- {
- timer.Stop();
- qi.ExecutionTime = timer.Elapsed;
- }
+ int fieldCount = base.GetResult(statementId, ref affectedRows, ref insertedId);
+
+ Source.TraceEvent(TraceEventType.Information, ThreadID, Resources.TraceResult,
+ MySqlTraceEventType.ResultOpened, statementId, fieldCount, affectedRows, insertedId);
+
+ ReportUsageAdvisorWarnings(statementId, null);
+
return fieldCount;
}
public override ResultSet NextResult(int statementId)
{
- if (lastResult != null)
- {
- MySqlTraceResultInfo ri = new MySqlTraceResultInfo();
- ri.InsertedId = lastResult.InsertedId;
- ri.RowsRead = lastResult.TotalRows;
- ri.RowsSkipped = lastResult.SkippedRows;
- ri.RowsChanged = lastResult.AffectedRows;
- if (HasStatus(ServerStatusFlags.NoIndex))
- ri.UAFlags |= UsageAdvisorFlags.NoIndex;
- if (HasStatus(ServerStatusFlags.BadIndex))
- ri.UAFlags |= UsageAdvisorFlags.BadIndex;
- if (!AllFieldsAccessed(lastResult))
- {
- ri.UAFlags |= UsageAdvisorFlags.PartialRowSet;
- for (int i = 0; i < lastResult.Size; i++)
- if (!lastResult.FieldRead(i))
- ri.FieldsNotAccessed.Add(lastResult.Fields[i].ColumnName);
- }
- qi.Results.Add(ri);
- }
-
- lastResult = base.NextResult(statementId);
- firstResult = false;
- if (lastResult == null)
- {
- MySqlTrace.LogInformation(qi.ToString());
- }
- return lastResult;
+ // first let's see if we already have a resultset on this statementId
+ ResultSet oldRS = null;
+ if (activeResults.ContainsKey(statementId))
+ {
+ oldRS = activeResults[statementId];
+ if (Settings.UseUsageAdvisor)
+ ReportUsageAdvisorWarnings(statementId, oldRS);
+ Source.TraceEvent(TraceEventType.Information, ThreadID, Resources.TraceResultClosed,
+ MySqlTraceEventType.ResultClosed, statementId, oldRS.TotalRows, oldRS.SkippedRows);
+ activeResults.Remove(statementId);
+ }
+
+ ResultSet rs = base.NextResult(statementId);
+ if (rs != null)
+ {
+ activeResults[statementId] = rs;
+ return rs;
+ }
+ if (oldRS != null)
+ Source.TraceEvent(TraceEventType.Information, ThreadID, Resources.TraceQueryDone,
+ MySqlTraceEventType.QueryDone, statementId);
+ return null;
+ }
+
+ public override int PrepareStatement(string sql, ref MySqlField[] parameters)
+ {
+ int statementId = base.PrepareStatement(sql, ref parameters);
+ return statementId;
+ }
+
+ public override void CloseStatement(int id)
+ {
+ base.CloseStatement(id);
+ }
+
+ public override void SetDatabase(string dbName)
+ {
+ base.SetDatabase(dbName);
+ Source.TraceEvent(TraceEventType.Information, ThreadID, Resources.TraceSetDatabase,
+ MySqlTraceEventType.NonQuery, -1, dbName);
+ }
+
+ public override void ExecuteStatement(MySqlPacket packetToExecute)
+ {
+ base.ExecuteStatement(packetToExecute);
+ }
+
+ public override bool FetchDataRow(int statementId, int columns)
+ {
+ bool b = base.FetchDataRow(statementId, columns);
+ return b;
}
public void ReportTypeConversion(string fieldName, MySqlDbType originalType, Type newType)
{
+ if (!Settings.UseUsageAdvisor) return;
}
private bool AllFieldsAccessed(ResultSet rs)
@@ -109,5 +148,40 @@
if (!rs.FieldRead(i)) return false;
return true;
}
+
+ private void ReportUsageAdvisorWarnings(int statementId, ResultSet rs)
+ {
+ if (!Settings.UseUsageAdvisor) return;
+ if (rs == null)
+ {
+ if (HasStatus(ServerStatusFlags.NoIndex))
+ Source.TraceEvent(TraceEventType.Warning, ThreadID, Resources.TraceUAWarningNoIndex,
+ MySqlTraceEventType.UsageAdvisorWarning, statementId, UsageAdvisorWarningFlags.NoIndex);
+ else if (HasStatus(ServerStatusFlags.BadIndex))
+ Source.TraceEvent(TraceEventType.Warning, ThreadID, Resources.TraceUAWarningBadIndex,
+ MySqlTraceEventType.UsageAdvisorWarning, statementId, UsageAdvisorWarningFlags.BadIndex);
+ }
+ else
+ {
+ if (rs.SkippedRows > 0)
+ Source.TraceEvent(TraceEventType.Warning, ThreadID, Resources.TraceUAWarningSkippedRows,
+ MySqlTraceEventType.UsageAdvisorWarning, statementId, UsageAdvisorWarningFlags.SkippedRows, rs.SkippedRows);
+
+ if (!AllFieldsAccessed(rs))
+ {
+ StringBuilder notAccessed = new StringBuilder("");
+ string delimiter = "";
+ for (int i = 0; i < rs.Size; i++)
+ if (!rs.FieldRead(i))
+ {
+ notAccessed.AppendFormat("{0}{1}", delimiter, rs.Fields[i].ColumnName);
+ delimiter = ",";
+ }
+ Source.TraceEvent(TraceEventType.Warning, ThreadID, Resources.TraceUAWarningSkippedColumns,
+ MySqlTraceEventType.UsageAdvisorWarning, statementId, UsageAdvisorWarningFlags.SkippedColumns,
+ notAccessed.ToString());
+ }
+ }
+ }
}
}
=== modified file 'MySql.Data/Provider/Source/command.cs'
--- a/MySql.Data/Provider/Source/command.cs 2009-11-03 18:00:36 +0000
+++ b/MySql.Data/Provider/Source/command.cs 2009-11-20 17:04:03 +0000
@@ -146,7 +146,7 @@
int timeout = Math.Min(value, Int32.MaxValue / 1000);
if (timeout != value)
{
- MySqlTrace.LogWarning(
+ MySqlTrace.LogWarning(connection.ServerThread,
"Command timeout value too large ("
+ value + " seconds). Changed to max. possible value ("
+ timeout + " seconds)");
=== modified file 'MySql.Data/Tests/Source/Logging.cs'
--- a/MySql.Data/Tests/Source/Logging.cs 2009-10-19 17:16:18 +0000
+++ b/MySql.Data/Tests/Source/Logging.cs 2009-11-20 17:04:03 +0000
@@ -46,20 +46,20 @@
execSQL("INSERT INTO Test VALUES (3, 'Test3')");
execSQL("INSERT INTO Test VALUES (4, 'Test4')");
- Trace.Listeners.Clear();
+ MySqlTrace.Listeners.Clear();
+ MySqlTrace.Switch.Level = SourceLevels.All;
GenericListener listener = new GenericListener();
- Trace.Listeners.Add(listener);
+ MySqlTrace.Listeners.Add(listener);
MySqlCommand cmd = new MySqlCommand("SELECT * FROM Test", conn);
using (MySqlDataReader reader = cmd.ExecuteReader())
{
}
- Assert.AreEqual(1, listener.Strings.Count);
- string s = listener.Strings[0];
- Assert.IsTrue(s.Contains("Rows returned: 4"));
- Assert.IsTrue(s.Contains("SELECT * FROM Test"));
- Assert.IsTrue(s.Contains("UA Warning: some fields not accessed (id, name)"));
- Assert.IsTrue(s.Contains("UA Warning: not all rows were read. Skipped 4 rows"));
+ Assert.AreEqual(4, listener.Strings.Count);
+ Assert.IsTrue(listener.Strings[0].Contains("Query Opened: SELECT * FROM Test"));
+ Assert.IsTrue(listener.Strings[1].Contains("Resultset Opened: field(s) = 2, affected rows = -1, inserted id = -1"));
+ Assert.IsTrue(listener.Strings[2].Contains("Resultset Closed: 4 total rows, 4 skipped rows"));
+ Assert.IsTrue(listener.Strings[3].Contains("Query Closed"));
}
}
}
=== modified file 'MySql.Data/Tests/Source/UsageAdvisor.cs'
--- a/MySql.Data/Tests/Source/UsageAdvisor.cs 2009-10-09 21:44:54 +0000
+++ b/MySql.Data/Tests/Source/UsageAdvisor.cs 2009-11-20 17:04:03 +0000
@@ -46,9 +46,10 @@
execSQL("INSERT INTO Test VALUES (3, 'Test3')");
execSQL("INSERT INTO Test VALUES (4, 'Test4')");
- Trace.Listeners.Clear();
+ MySqlTrace.Listeners.Clear();
+ MySqlTrace.Switch.Level = SourceLevels.All;
GenericListener listener = new GenericListener();
- Trace.Listeners.Add(listener);
+ MySqlTrace.Listeners.Add(listener);
string sql = "SELECT * FROM Test; SELECT * FROM Test WHERE id > 2";
MySqlCommand cmd = new MySqlCommand(sql, conn);
@@ -62,14 +63,19 @@
Assert.AreEqual("Test3", reader.GetString(1));
Assert.IsFalse(reader.NextResult());
}
- string log = listener.Strings[0];
- Assert.IsTrue(log.Contains(sql));
- Assert.IsTrue(log.Contains("Rows returned: 4"));
- Assert.IsTrue(log.Contains("Rows returned: 2"));
- Assert.IsTrue(log.Contains("some fields not accessed (name)"));
- Assert.IsTrue(log.Contains("some fields not accessed (id)"));
- Assert.IsTrue(log.Contains("UA Warning: not all rows were read. Skipped 2 rows"));
- Assert.IsTrue(log.Contains("UA Warning: not all rows were read. Skipped 1 rows"));
+
+ Assert.AreEqual(11, listener.Strings.Count);
+ Assert.IsTrue(listener.Strings[0].Contains("Query Opened: SELECT * FROM Test; SELECT * FROM Test WHERE id > 2"));
+ Assert.IsTrue(listener.Strings[1].Contains("Resultset Opened: field(s) = 2, affected rows = -1, inserted id = -1"));
+ Assert.IsTrue(listener.Strings[2].Contains("Usage Advisor Warning: Skipped 2 rows. Consider a more focused query."));
+ Assert.IsTrue(listener.Strings[3].Contains("Usage Advisor Warning: The following columns were not accessed: name"));
+ Assert.IsTrue(listener.Strings[4].Contains("Resultset Closed: 4 total rows, 2 skipped rows"));
+ Assert.IsTrue(listener.Strings[5].Contains("Resultset Opened: field(s) = 2, affected rows = -1, inserted id = -1"));
+ Assert.IsTrue(listener.Strings[6].Contains("Usage Advisor Warning: Query does not use an index"));
+ Assert.IsTrue(listener.Strings[7].Contains("Usage Advisor Warning: Skipped 1 rows. Consider a more focused query."));
+ Assert.IsTrue(listener.Strings[8].Contains("Usage Advisor Warning: The following columns were not accessed: id"));
+ Assert.IsTrue(listener.Strings[9].Contains("Resultset Closed: 2 total rows, 1 skipped rows"));
+ Assert.IsTrue(listener.Strings[10].Contains("Query Closed"));
}
[Test]
@@ -80,9 +86,10 @@
execSQL("INSERT INTO Test VALUES (3, 'Test3')");
execSQL("INSERT INTO Test VALUES (4, 'Test4')");
- Trace.Listeners.Clear();
+ MySqlTrace.Listeners.Clear();
+ MySqlTrace.Switch.Level = SourceLevels.All;
GenericListener listener = new GenericListener();
- Trace.Listeners.Add(listener);
+ MySqlTrace.Listeners.Add(listener);
MySqlCommand cmd = new MySqlCommand("SELECT * FROM Test; SELECT * FROM Test WHERE id > 2", conn);
using (MySqlDataReader reader = cmd.ExecuteReader())
@@ -94,7 +101,17 @@
reader.Read();
Assert.IsFalse(reader.NextResult());
}
- Assert.IsTrue(listener.Find("UA Warning: not all rows were read") > 0);
+ Assert.AreEqual(10, listener.Strings.Count);
+ Assert.IsTrue(listener.Strings[0].Contains("Query Opened: SELECT * FROM Test; SELECT * FROM Test WHERE id > 2"));
+ Assert.IsTrue(listener.Strings[1].Contains("Resultset Opened: field(s) = 2, affected rows = -1, inserted id = -1"));
+ Assert.IsTrue(listener.Strings[2].Contains("Usage Advisor Warning: Skipped 2 rows. Consider a more focused query."));
+ Assert.IsTrue(listener.Strings[3].Contains("Usage Advisor Warning: The following columns were not accessed: id,name"));
+ Assert.IsTrue(listener.Strings[4].Contains("Resultset Closed: 4 total rows, 2 skipped rows"));
+ Assert.IsTrue(listener.Strings[5].Contains("Resultset Opened: field(s) = 2, affected rows = -1, inserted id = -1"));
+ Assert.IsTrue(listener.Strings[6].Contains("Usage Advisor Warning: Query does not use an index"));
+ Assert.IsTrue(listener.Strings[7].Contains("Usage Advisor Warning: The following columns were not accessed: id,name"));
+ Assert.IsTrue(listener.Strings[8].Contains("Resultset Closed: 2 total rows, 0 skipped rows"));
+ Assert.IsTrue(listener.Strings[9].Contains("Query Closed"));
}
}
Attachment: [text/bzr-bundle] bzr/reggie.burnett@sun.com-20091120170403-asmylm3261q85stv.bundle
| Thread |
|---|
| • bzr push into connector-net-trunk branch (reggie.burnett:801 to 802) | Reggie Burnett | 20 Nov |
