From 23e08a88f3cd3ce2f154db506f006d27aa9d448f Mon Sep 17 00:00:00 2001 From: inga-lovinde <52715130+inga-lovinde@users.noreply.github.com> Date: Mon, 2 Jan 2012 01:08:27 +0000 Subject: [PATCH] Time profiling in XSLT transformations and DB requests --- Builder/IISMainHandler/build.txt | 2 +- FLocal.Common/Config.cs | 2 +- FLocal.IISHandler/WebContext.cs | 2 + MySQLConnector/CommandExecutionLogger.cs | 26 ++ MySQLConnector/Connection.cs | 363 ++++++++++++----------- MySQLConnector/MySQLConnector.csproj | 1 + 6 files changed, 225 insertions(+), 171 deletions(-) create mode 100644 MySQLConnector/CommandExecutionLogger.cs diff --git a/Builder/IISMainHandler/build.txt b/Builder/IISMainHandler/build.txt index bc4e1dc..14d9c90 100644 --- a/Builder/IISMainHandler/build.txt +++ b/Builder/IISMainHandler/build.txt @@ -1 +1 @@ -1968 \ No newline at end of file +1969 \ No newline at end of file diff --git a/FLocal.Common/Config.cs b/FLocal.Common/Config.cs index e7aa243..14b06d6 100644 --- a/FLocal.Common/Config.cs +++ b/FLocal.Common/Config.cs @@ -54,7 +54,6 @@ namespace FLocal.Common { protected Config(NameValueCollection data) : base(data) { this.InitTime = DateTime.Now.ToLongTimeString(); - this.mainConnection = new MySQLConnector.Connection(data["ConnectionString"], MySQLConnector.PostgresDBTraits.instance); this.dataDir = data["DataDir"]; this.DirSeparator = System.IO.Path.DirectorySeparatorChar.ToString(); this.SaltMigration = data["SaltMigration"]; @@ -75,6 +74,7 @@ namespace FLocal.Common { this.DefaultModernSkin = data["DefaultModernSkin"]; this.DefaultMachichara = data["DefaultMachichara"]; this.Logger = new SingleFileLogger(this); + this.mainConnection = new MySQLConnector.Connection(data["ConnectionString"], MySQLConnector.PostgresDBTraits.instance, this.Logger); } public static void Init(NameValueCollection data) { diff --git a/FLocal.IISHandler/WebContext.cs b/FLocal.IISHandler/WebContext.cs index dd018bd..22fee7e 100644 --- a/FLocal.IISHandler/WebContext.cs +++ b/FLocal.IISHandler/WebContext.cs @@ -164,7 +164,9 @@ namespace FLocal.IISHandler { public void WriteTransformResult(string templateName, System.Xml.Linq.XDocument data) { this.httpresponse.ContentType = this.design.ContentType; this.httpresponse.ContentEncoding = OutputEncoding; + DateTime start = DateTime.Now; TemplateEngine.WriteCompiled(this.design.GetFSName(templateName), data, this.httpresponse.Output); + Config.instance.Logger.Log(templateName + " transformation took " + (DateTime.Now-start).TotalSeconds + " seconds"); } public XElement exportSession() { diff --git a/MySQLConnector/CommandExecutionLogger.cs b/MySQLConnector/CommandExecutionLogger.cs new file mode 100644 index 0000000..8c2213c --- /dev/null +++ b/MySQLConnector/CommandExecutionLogger.cs @@ -0,0 +1,26 @@ +using System; +using System.Collections.Generic; +using System.Linq; +using System.Text; +using Web.Core; + +namespace MySQLConnector { + class CommandExecutionLogger : IDisposable { + + private readonly ILogger logger; + + private readonly DateTime start; + + public string commandText; + + public CommandExecutionLogger(ILogger logger) { + this.logger = logger; + this.start = DateTime.Now; + } + + void IDisposable.Dispose() { + this.logger.Log("Spent " + (DateTime.Now-start).TotalSeconds + " seconds while executing " + this.commandText); + } + + } +} diff --git a/MySQLConnector/Connection.cs b/MySQLConnector/Connection.cs index 46eaba0..1fd9814 100644 --- a/MySQLConnector/Connection.cs +++ b/MySQLConnector/Connection.cs @@ -12,13 +12,16 @@ namespace MySQLConnector { internal readonly IDBTraits traits; + internal readonly ILogger logger; + // private DbConnection connection; private string connectionString; private HashSet transactions; - public Connection(string connectionString, IDBTraits traits) { + public Connection(string connectionString, IDBTraits traits, ILogger logger) { this.traits = traits; + this.logger = logger; this.connectionString = connectionString; using(DbConnection connection = this.createConnection()) { //just testing we can open a connection @@ -26,6 +29,10 @@ namespace MySQLConnector { this.transactions = new HashSet(); } + private CommandExecutionLogger CreateCommandExecutionLogger() { + return new CommandExecutionLogger(this.logger); + } + internal DbConnection createConnection() { DbConnection connection = this.traits.createConnection(this.connectionString); connection.Open(); @@ -33,48 +40,51 @@ namespace MySQLConnector { } private List> _LoadByIds(DbCommand command, ITableSpec table, List ids, bool forUpdate) { - command.CommandType = System.Data.CommandType.Text; + using(var logger = this.CreateCommandExecutionLogger()) { - ParamsHolder paramsHolder = new ParamsHolder(); - List placeholder = new List(); - foreach(string id in ids) { - placeholder.Add(this.traits.markParam(paramsHolder.Add(id))); - } + command.CommandType = System.Data.CommandType.Text; - command.CommandText = "SELECT * FROM " + table.compile(this.traits) + " WHERE " + table.getIdSpec().compile(this.traits) + " IN (" + string.Join(", ", placeholder.ToArray()) + ")" + (forUpdate ? " FOR UPDATE" : ""); - //command.Prepare(); - foreach(KeyValuePair kvp in paramsHolder.data) { - command.AddParameter(kvp.Key, kvp.Value); - } + ParamsHolder paramsHolder = new ParamsHolder(); + List placeholder = new List(); + foreach(string id in ids) { + placeholder.Add(this.traits.markParam(paramsHolder.Add(id))); + } - Dictionary> rawResult = new Dictionary>(); - using(DbDataReader reader = command.ExecuteReader()) { - while(reader.Read()) { - Dictionary row = new Dictionary(); - for(int i=0; i kvp in paramsHolder.data) { + command.AddParameter(kvp.Key, kvp.Value); + } + + Dictionary> rawResult = new Dictionary>(); + using(DbDataReader reader = command.ExecuteReader()) { + while(reader.Read()) { + Dictionary row = new Dictionary(); + for(int i=0; i> result = new List>(); - foreach(string id in ids) { - if(rawResult.ContainsKey(id)) { - result.Add(rawResult[id]); + List> result = new List>(); + foreach(string id in ids) { + if(rawResult.ContainsKey(id)) { + result.Add(rawResult[id]); + } } + return result; } - return result; } public List> LoadByIds(ITableSpec table, List ids) { @@ -86,75 +96,78 @@ namespace MySQLConnector { } private List _LoadIdsByConditions(DbCommand command, ITableSpec table, Web.Core.DB.conditions.AbstractCondition conditions, Diapasone diapasone, JoinSpec[] joins, SortSpec[] sorts, bool allowHugeLists) { - command.CommandType = System.Data.CommandType.Text; - - var conditionsCompiled = ConditionCompiler.Compile(conditions, this.traits); - string queryConditions = ""; - if(conditionsCompiled.Key != "") queryConditions = "WHERE " + conditionsCompiled.Key; - ParamsHolder paramsHolder = conditionsCompiled.Value; - - StringBuilder queryJoins = new StringBuilder(); - { - foreach(var join in joins) { - queryJoins.Append(" JOIN "); - queryJoins.Append(join.additionalTableRaw.compile(this.traits)); - queryJoins.Append(" "); - queryJoins.Append(join.additionalTable.compile(this.traits)); - queryJoins.Append(" ON "); - queryJoins.Append(join.mainColumn.compile(this.traits)); - queryJoins.Append(" = "); - queryJoins.Append(join.additionalTable.getIdSpec().compile(this.traits)); + using(var logger = this.CreateCommandExecutionLogger()) { + + command.CommandType = System.Data.CommandType.Text; + + var conditionsCompiled = ConditionCompiler.Compile(conditions, this.traits); + string queryConditions = ""; + if(conditionsCompiled.Key != "") queryConditions = "WHERE " + conditionsCompiled.Key; + ParamsHolder paramsHolder = conditionsCompiled.Value; + + StringBuilder queryJoins = new StringBuilder(); + { + foreach(var join in joins) { + queryJoins.Append(" JOIN "); + queryJoins.Append(join.additionalTableRaw.compile(this.traits)); + queryJoins.Append(" "); + queryJoins.Append(join.additionalTable.compile(this.traits)); + queryJoins.Append(" ON "); + queryJoins.Append(join.mainColumn.compile(this.traits)); + queryJoins.Append(" = "); + queryJoins.Append(join.additionalTable.getIdSpec().compile(this.traits)); + } } - } - string querySorts = ""; - if(sorts.Length > 0) { - List sortParts = new List(); - foreach(SortSpec sortSpec in sorts) { - if(sortSpec.ascending) { - sortParts.Add(sortSpec.column.compile(this.traits) + " ASC"); - } else { - sortParts.Add(sortSpec.column.compile(this.traits) + " DESC"); + string querySorts = ""; + if(sorts.Length > 0) { + List sortParts = new List(); + foreach(SortSpec sortSpec in sorts) { + if(sortSpec.ascending) { + sortParts.Add(sortSpec.column.compile(this.traits) + " ASC"); + } else { + sortParts.Add(sortSpec.column.compile(this.traits) + " DESC"); + } } + querySorts = "ORDER BY " + string.Join(", ", sortParts.ToArray()); } - querySorts = "ORDER BY " + string.Join(", ", sortParts.ToArray()); - } - string queryMain = "FROM " + table.compile(this.traits) + " " + queryJoins + " " + queryConditions; + string queryMain = "FROM " + table.compile(this.traits) + " " + queryJoins + " " + queryConditions; - foreach(KeyValuePair kvp in paramsHolder.data) { - command.AddParameter(kvp.Key, kvp.Value); - } + foreach(KeyValuePair kvp in paramsHolder.data) { + command.AddParameter(kvp.Key, kvp.Value); + } - command.CommandText = "SELECT COUNT(*) " + queryMain; - object rawCount; - //try { + command.CommandText = logger.commandText = "SELECT COUNT(*) " + queryMain; + object rawCount; + //try { rawCount = command.ExecuteScalar(); - //} catch(Npgsql.NpgsqlException e) { + //} catch(Npgsql.NpgsqlException e) { //throw new FLocalException("Error while trying to execute " + command.CommandText + ": " + e.Message); - //} - long count = (long)rawCount; - if(count < 1) { - diapasone.total = 0; - return new List(); - } else { - diapasone.total = count; - if(diapasone.total > 1000 && diapasone.count < 0 && !allowHugeLists) { - throw new CriticalException("huge list"); - } - string queryLimits = ""; - if(diapasone.count >= 0) { - queryLimits = "LIMIT " + diapasone.count + " OFFSET " + diapasone.start; - } - command.CommandText = "SELECT " + table.getIdSpec().compile(this.traits) + " " + queryMain + " " + querySorts + " " + queryLimits; + //} + long count = (long)rawCount; + if(count < 1) { + diapasone.total = 0; + return new List(); + } else { + diapasone.total = count; + if(diapasone.total > 1000 && diapasone.count < 0 && !allowHugeLists) { + throw new CriticalException("huge list"); + } + string queryLimits = ""; + if(diapasone.count >= 0) { + queryLimits = "LIMIT " + diapasone.count + " OFFSET " + diapasone.start; + } + command.CommandText = "SELECT " + table.getIdSpec().compile(this.traits) + " " + queryMain + " " + querySorts + " " + queryLimits; - List result = new List(); - using(DbDataReader reader = command.ExecuteReader()) { - while(reader.Read()) { - result.Add(reader.GetValue(0).ToString()); + List result = new List(); + using(DbDataReader reader = command.ExecuteReader()) { + while(reader.Read()) { + result.Add(reader.GetValue(0).ToString()); + } } + return result; } - return result; } } @@ -167,31 +180,33 @@ namespace MySQLConnector { } public long GetCountByConditions(ITableSpec table, Web.Core.DB.conditions.AbstractCondition conditions, params JoinSpec[] joins) { - using(DbConnection connection = this.createConnection()) { - using(DbCommand command = connection.CreateCommand()) { - - command.CommandType = System.Data.CommandType.Text; - - var conditionsCompiled = ConditionCompiler.Compile(conditions, this.traits); - string queryConditions = ""; - if(conditionsCompiled.Key != "") queryConditions = "WHERE " + conditionsCompiled.Key; - ParamsHolder paramsHolder = conditionsCompiled.Value; - - string queryJoins = ""; - { - if(joins.Length > 0) { - throw new NotImplementedException(); + using(var logger = this.CreateCommandExecutionLogger()) { + using(DbConnection connection = this.createConnection()) { + using(DbCommand command = connection.CreateCommand()) { + + command.CommandType = System.Data.CommandType.Text; + + var conditionsCompiled = ConditionCompiler.Compile(conditions, this.traits); + string queryConditions = ""; + if(conditionsCompiled.Key != "") queryConditions = "WHERE " + conditionsCompiled.Key; + ParamsHolder paramsHolder = conditionsCompiled.Value; + + string queryJoins = ""; + { + if(joins.Length > 0) { + throw new NotImplementedException(); + } } - } - command.CommandText = "SELECT COUNT(*) " + "FROM " + table.compile(this.traits) + " " + queryJoins + " " + queryConditions; - foreach(KeyValuePair kvp in paramsHolder.data) { - command.AddParameter(kvp.Key, kvp.Value); + command.CommandText = logger.commandText = "SELECT COUNT(*) " + "FROM " + table.compile(this.traits) + " " + queryJoins + " " + queryConditions; + foreach(KeyValuePair kvp in paramsHolder.data) { + command.AddParameter(kvp.Key, kvp.Value); + } + object rawCount = command.ExecuteScalar(); + long count = (long)rawCount; + return count; } - object rawCount = command.ExecuteScalar(); - long count = (long)rawCount; - return count; } } } @@ -210,26 +225,30 @@ namespace MySQLConnector { } public void lockTable(Web.Core.DB.Transaction _transaction, ITableSpec table) { - Transaction transaction = (Transaction)_transaction; - lock(transaction) { - using(DbCommand command = transaction.sqlconnection.CreateCommand()) { - command.Transaction = transaction.sqltransaction; - command.CommandType = System.Data.CommandType.Text; - command.CommandText = "LOCK TABLE " + table.compile(this.traits); - command.ExecuteNonQuery(); + using(var logger = this.CreateCommandExecutionLogger()) { + Transaction transaction = (Transaction)_transaction; + lock(transaction) { + using(DbCommand command = transaction.sqlconnection.CreateCommand()) { + command.Transaction = transaction.sqltransaction; + command.CommandType = System.Data.CommandType.Text; + command.CommandText = logger.commandText = "LOCK TABLE " + table.compile(this.traits); + command.ExecuteNonQuery(); + } } } } public void lockRow(Web.Core.DB.Transaction _transaction, ITableSpec table, string id) { - Transaction transaction = (Transaction)_transaction; - lock(transaction) { - using(DbCommand command = transaction.sqlconnection.CreateCommand()) { - command.Transaction = transaction.sqltransaction; - command.CommandType = System.Data.CommandType.Text; - command.CommandText = "SELECT * FROM " + table.compile(this.traits) + " where " + table.getIdSpec().compile(this.traits) + " = " + this.traits.markParam("id") + " FOR UPDATE"; - command.AddParameter("id", id); - command.ExecuteNonQuery(); + using(var logger = this.CreateCommandExecutionLogger()) { + Transaction transaction = (Transaction)_transaction; + lock(transaction) { + using(DbCommand command = transaction.sqlconnection.CreateCommand()) { + command.Transaction = transaction.sqltransaction; + command.CommandType = System.Data.CommandType.Text; + command.CommandText = logger.commandText = "SELECT * FROM " + table.compile(this.traits) + " where " + table.getIdSpec().compile(this.traits) + " = " + this.traits.markParam("id") + " FOR UPDATE"; + command.AddParameter("id", id); + command.ExecuteNonQuery(); + } } } } @@ -255,62 +274,68 @@ namespace MySQLConnector { } public void update(Web.Core.DB.Transaction _transaction, ITableSpec table, string id, Dictionary data) { - Transaction transaction = (Transaction)_transaction; - lock(transaction) { - using(DbCommand command = transaction.sqlconnection.CreateCommand()) { - List updates = new List(); - ParamsHolder paramsholder = new ParamsHolder(); - foreach(KeyValuePair kvp in data) { - updates.Add(this.traits.escapeIdentifier(kvp.Key) + " = " + this.traits.markParam(paramsholder.Add(kvp.Value))); - } + using(var logger = this.CreateCommandExecutionLogger()) { + Transaction transaction = (Transaction)_transaction; + lock(transaction) { + using(DbCommand command = transaction.sqlconnection.CreateCommand()) { + List updates = new List(); + ParamsHolder paramsholder = new ParamsHolder(); + foreach(KeyValuePair kvp in data) { + updates.Add(this.traits.escapeIdentifier(kvp.Key) + " = " + this.traits.markParam(paramsholder.Add(kvp.Value))); + } - command.Transaction = transaction.sqltransaction; - command.CommandType = System.Data.CommandType.Text; - command.CommandText = "UPDATE " + table.compile(traits) + " set " + String.Join(", ", updates.ToArray()) + " where " + table.getIdSpec().compile(this.traits) + " = " + this.traits.markParam("id"); - command.AddParameter("id", id); - foreach(KeyValuePair kvp in paramsholder.data) { - command.AddParameter(kvp.Key, kvp.Value); + command.Transaction = transaction.sqltransaction; + command.CommandType = System.Data.CommandType.Text; + command.CommandText = logger.commandText = "UPDATE " + table.compile(traits) + " set " + String.Join(", ", updates.ToArray()) + " where " + table.getIdSpec().compile(this.traits) + " = " + this.traits.markParam("id"); + command.AddParameter("id", id); + foreach(KeyValuePair kvp in paramsholder.data) { + command.AddParameter(kvp.Key, kvp.Value); + } + // throw new CriticalException(command.CommandText + "; parameters: " + string.Join(", ", (from DbParameter parameter in command.Parameters select parameter.ParameterName + "='" + parameter.Value.ToString() + "'").ToArray())); + command.ExecuteNonQuery(); } -// throw new CriticalException(command.CommandText + "; parameters: " + string.Join(", ", (from DbParameter parameter in command.Parameters select parameter.ParameterName + "='" + parameter.Value.ToString() + "'").ToArray())); - command.ExecuteNonQuery(); } } } public string insert(Web.Core.DB.Transaction _transaction, ITableSpec table, Dictionary data) { - Transaction transaction = (Transaction)_transaction; - lock(transaction) { - using(DbCommand command = transaction.sqlconnection.CreateCommand()) { - List updates = new List(); - List updatesPlaceholders = new List(); - ParamsHolder paramsholder = new ParamsHolder(); - foreach(KeyValuePair kvp in data) { - updates.Add(this.traits.escapeIdentifier(kvp.Key)); - updatesPlaceholders.Add(this.traits.markParam(paramsholder.Add(kvp.Value))); - } + using(var logger = this.CreateCommandExecutionLogger()) { + Transaction transaction = (Transaction)_transaction; + lock(transaction) { + using(DbCommand command = transaction.sqlconnection.CreateCommand()) { + List updates = new List(); + List updatesPlaceholders = new List(); + ParamsHolder paramsholder = new ParamsHolder(); + foreach(KeyValuePair kvp in data) { + updates.Add(this.traits.escapeIdentifier(kvp.Key)); + updatesPlaceholders.Add(this.traits.markParam(paramsholder.Add(kvp.Value))); + } - command.Transaction = transaction.sqltransaction; - command.CommandType = System.Data.CommandType.Text; - command.CommandText = "INSERT INTO " + table.compile(this.traits) + " (" + String.Join(", ", updates.ToArray()) + ") VALUES (" + String.Join(", ", updatesPlaceholders.ToArray()) + ")"; - foreach(KeyValuePair kvp in paramsholder.data) { - command.AddParameter(kvp.Key, kvp.Value); + command.Transaction = transaction.sqltransaction; + command.CommandType = System.Data.CommandType.Text; + command.CommandText = logger.commandText = "INSERT INTO " + table.compile(this.traits) + " (" + String.Join(", ", updates.ToArray()) + ") VALUES (" + String.Join(", ", updatesPlaceholders.ToArray()) + ")"; + foreach(KeyValuePair kvp in paramsholder.data) { + command.AddParameter(kvp.Key, kvp.Value); + } + command.ExecuteNonQuery(); + if(data.ContainsKey(table.idName)) return data[table.idName]; + return this.traits.LastInsertId(command, table).ToString(); } - command.ExecuteNonQuery(); - if(data.ContainsKey(table.idName)) return data[table.idName]; - return this.traits.LastInsertId(command, table).ToString(); } } } public void delete(Web.Core.DB.Transaction _transaction, ITableSpec table, string id) { - Transaction transaction = (Transaction)_transaction; - lock(transaction) { - using(DbCommand command = transaction.sqlconnection.CreateCommand()) { - command.Transaction = transaction.sqltransaction; - command.CommandType = System.Data.CommandType.Text; - command.CommandText = "DELETE FROM " + table.compile(traits) + " where " + table.getIdSpec().compile(this.traits) + " = " + this.traits.markParam("id"); - command.AddParameter("id", id); - command.ExecuteNonQuery(); + using(var logger = this.CreateCommandExecutionLogger()) { + Transaction transaction = (Transaction)_transaction; + lock(transaction) { + using(DbCommand command = transaction.sqlconnection.CreateCommand()) { + command.Transaction = transaction.sqltransaction; + command.CommandType = System.Data.CommandType.Text; + command.CommandText = logger.commandText = "DELETE FROM " + table.compile(traits) + " where " + table.getIdSpec().compile(this.traits) + " = " + this.traits.markParam("id"); + command.AddParameter("id", id); + command.ExecuteNonQuery(); + } } } } diff --git a/MySQLConnector/MySQLConnector.csproj b/MySQLConnector/MySQLConnector.csproj index 643e7a2..fc753df 100644 --- a/MySQLConnector/MySQLConnector.csproj +++ b/MySQLConnector/MySQLConnector.csproj @@ -51,6 +51,7 @@ +