Added performances logs for long SQL queries (more than 1 second)

Cédric RICARD
1 parent 15bb49b1
Showing 2 changed files with 110 additions and 50 deletions Show diff stats
calexium_lib/database/db_utils.anubis
calexium_lib/net_services_protocols/logger_service.anubis
@@ -9,10 +9,30 @@
 read tools/basis.anubis
 read system/logger.anubis
+read system/string.anubis
 read data_base/sqlite.anubis
 read calexium_lib/net_services_protocols/logger_service.anubis
+define String
+  __utime_to_string
+  (
+    UTime t
+  ) =
+  to_decimal(t.seconds) + "." + zero_pad_n(6, t.microseconds ) + " s".
+
+define One 
+  __logLongQueries
+  (
+    UTime t0,
+    String sql_query
+  ) =
+  with t = unow - t0,
+  if t.seconds > 0 then
+      logTrace("SQL", logMask("sql_profiling"), "[SQL] " +  __utime_to_string(t) + " executing [" + sql_query + "]")
+  else
+    unique.
+
 public define Result(SQLite3Error, One)
   sql_transaction
   (
@@ -21,6 +41,7 @@ public define Result(SQLite3Error, One)
     String          message
   ) =
 //  logDebug(debug_log, "Entering into transaction [" + message + "].");
+  with t0 = unow,
   if db_do_transaction(
         db,
         (One _) |->
@@ -36,10 +57,11 @@ public define Result(SQLite3Error, One)
   {
     error(err_and_result) then 
 //      logDebug(debug_log, "Exiting from transaction [" + message + "] with error.");
-      if err_and_result is (err, mb_result) then
-        error(err),
+      __logLongQueries(t0, sql_command);
+      if err_and_result is (err, mb_result) then error(err),
     ok(_)                 then 
 //      logDebug(debug_log, "Exiting from transaction [" + message + "].");
+      __logLongQueries(t0, sql_command);
       ok(unique)
   }.
@@ -54,10 +76,15 @@ public define SQLite3QueryResult
     String            msg         //message to be shown if an error occure
   ) =
   //we try with 30 sec of timeout
+  with t0 = unow,
   if sql_query_timeout(db, sql_query, initial_bindings, 60, 100) is 
   {
-    error(sql_error)  then  logError("DB", db_error(sql_error,msg)); error(sql_error),
-    ok(headers, cursor, reset) then ok(headers, cursor, reset)
+    error(sql_error)  then  logError("DB", db_error(sql_error,msg)); 
+      __logLongQueries(t0, sql_query);
+      error(sql_error),
+    ok(headers, cursor, reset) then 
+      __logLongQueries(t0, sql_query);
+      ok(headers, cursor, reset)
   }.
 // deprecated. Use one of the previous ones.
@@ -69,10 +96,14 @@ public define Maybe(SQLite3HeadersOrRow -&gt; SQLite3Row)
     String          msg         //message to be shown if an error occure
   ) =
   //we try with 30 sec of timeout
+  with t0 = unow,
   if sql_query_timeout(db, sql_query, [], 60, 100) is 
   {
-    error(sql_error)  then  logError("DB", db_error(sql_error,msg));failure,
+    error(sql_error)  then  logError("DB", db_error(sql_error,msg));
+      __logLongQueries(t0, sql_query);
+      failure,
     ok(headers, cursor, reset) then  
+      __logLongQueries(t0, sql_query);
       success((SQLite3HeadersOrRow h_or_r) |-> if h_or_r is
                                                {
                                                   headers then 
@@ -237,35 +237,6 @@ public define Maybe(UDP_Server)
  /****************** CLIENT PART *******************/
-/*
- define One
-  send_log_msg
-  (
-    MessageQueue  queue,
-    Message       log_msg
-  )=
-  with test_msg = message(_CXM_REQUEST_FOR_SERVICE),
-  forget(add_int32(test_msg, "service", _CXM_LOGGER_SERVICE_ID));
-  forget(add_int32(test_msg, "version", 1));
-  queue.add_Message_to_send(test_msg);
-  if queue.get_next_received_Message(30) is
-  {
-    timeout then println("send_log_msg receive timeout"),
-    closed  then println("send_log_msg socket closed"),
-    msg(msg)  then 
-      if find_int32(msg, "STATUS") is
-      {
-        failure     then println("status not found"),
-        success(v)  then 
-          if v = _CXM_OK then 
-            queue.add_Message_to_send(log_msg);
-            forget(wait_for_reply(queue, _CXM_LOGGER_LOG, 30))
-          else
-            println("requested service started won't start")        
-      }
-  }.
-*/  
-
 define One
   local_net_logger
   (
@@ -273,22 +244,7 @@ define One
     Message log_message
   )=
   forget(send_message_by_udp(log_message, ip_address((127,0,0,1)), logger_port)).
-  
-/*  if find_string(log_message, "LogString") is
-  {
-    failure         then println("process_log can't find LogString"),
-    success(log_string) then println(log_string)
-  }.
-  if connect( ip_address((127,0,0,1)), 33125) is
-  {
-    error(_)  then println("can't connect to logger server ["+logger_server+"]");
-    							 forget(process_log(fullLogger, log_message)),
-    ok(conn)  then 
-      with queue = create_MessageQueue("net logger sender"),
-      message_transceiver(conn, queue);
-      send_log_msg(queue, log_message);
-      queue.quit(unique)
-  }.*/
+
 define Message
   create_log_msg
@@ -306,6 +262,67 @@ define Message
   forget(add_int32(log_msg, "Thread", virtual_machine_id));
   log_msg
   .
+*/
+
+// HACK Begin of Hacked version
+  define String debug_log    = "Debug".
+  define String config_log   = "Config".
+  define String incoming_log = "Incoming".
+  define String outgoing_log = "Outgoing".
+  define String pop3_log     = "POP3".
+  define String mailing_log  = "Mailing".
+  define String errors_log   = "Errors".
+  define String security_log = "Security".
+  define String spams_log    = "Spams".
+  define String api_log      = "MF_API".
+  define String internal_log = "INTERNAL".
+  
+             
+  define String 
+    get_log_file
+    (
+      String log_name
+    ) =
+         if log_name = debug_log then "debug.log"
+  	else if log_name = "SendMail"     then "debug.log"
+    else if log_name = config_log     then "config.log"
+    else if log_name = incoming_log   then "incoming.log"
+  	else if log_name = outgoing_log   then "outgoing.log"
+  	else if log_name = pop3_log       then "pop3.log"
+  	else if log_name = mailing_log    then "mailing.log"
+  	else if log_name = errors_log     then "errors.log"
+  	else if log_name = "DB"           then "errors.log"
+  	else if log_name = "SQL"          then "sql_profiling.log"
+  	else if log_name = security_log   then "security.log"
+    else if log_name = spams_log      then "spams.log"
+    else if log_name = api_log        then "api.log"
+    else if log_name = internal_log   then "internal"
+    else "unknown.log".
+    
+             
+  define One
+    local_net_logger
+    (
+      String  logger_server,
+      One     _
+    )=
+    unique.
+  
+  define One
+    create_log_msg
+    (
+      String  logger_name,
+      String  log_string,
+      Int     level
+    )=
+    with log = createLogger(logger_name, 8, "/var/MailFountain/log/" + get_log_file(logger_name), logTrace, logTrace),
+         logLevel = get_LogLevel_from_value(level),
+    protect
+    doLog(log, log_string, logLevel, virtual_machine_id).
+
+// HACK End of Hacked version
+
+
 public define One 
   log( 
@@ -366,3 +383,15 @@ public define One
   with log_msg = create_log_msg(logger_name, log_string, 6),
   forget(add_string(log_msg, "LogMask", log_mask.mask));
   local_net_logger("127.0.0.1", log_msg).
+
+// HACK hacked version
+ public define One 
+  logTrace( 
+    String  logger_name,
+    LogMask log_mask,
+    String  log_string
+  )=
+  if log_mask is logMask(mask) then
+  if mask = "send_mail" | mask = "smtp" | mask = "sql_profiling"  then
+    local_net_logger("127.0.0.1", create_log_msg(logger_name, log_string, 6))
+  else unique.