@@ -2,8 +2,11 @@ from Standard.Base import all
22import Standard.Base.Errors.Illegal_Argument.Illegal_Argument
33import Standard.Base.Errors.Illegal_State.Illegal_State
44import Standard.Base.Errors.Unimplemented.Unimplemented
5+ import Standard.Base.Logging.Log_Level
6+ import Standard.Base.Logging.Profile
57import Standard.Base.Runtime.Context
68import Standard.Base.Runtime.Managed_Resource.Managed_Resource
9+ import Standard.Base.Runtime.State
710from Standard.Base.Enso_Cloud.Enso_Secret import as_hideable_value
811
912from Standard.Table import Table, Value_Type
@@ -256,27 +259,26 @@ private _set_statement_values stmt:PreparedStatement statement_setter:Statement_
256259 A helper that logs performed SQL queries/statements run-time to a profiling
257260 file, if an environment variable is set.
258261private _profile_sql_if_enabled (jdbc_connection : JDBC_Connection) (~query_text : Text) ~action (skip_log:Boolean=False) =
259- path = if skip_log then "" else
260- Environment.get "ENSO_SQL_PROFILING_PATH" . if_nothing Environment.get "ENSO_SQL_LOG_PATH" . if_nothing ""
261- if path.is_empty then action else
262- duration_and_result = Duration.time_execution action
263- result = duration_and_result.second
264- ## If the action returns a dataflow error, `time_execution` returns the error, no duration.
265- We could work around this. But we don't want to - the failing queries likely did not run anyway,
266- so their time info would most likely be an outlier. For current purposes it makes sense to ignore such cases.
267- Error.return_if_error result
268-
269- padded_query = query_text.to_display_text.pad length=80
270- millis = duration_and_result.first.total_milliseconds
271- millis_text = (millis.to_text.pad length=5 with_pad=' ' at=..Left) + ' ms'
272-
273- # E.g. [SQLite] SELECT * FROM "test" ... --> 12 ms
262+ make_label =
274263 db_id = jdbc_connection.with_metadata .getDatabaseProductName
275- log_line = "[" + db_id + "] " + padded_query + " --> " + millis_text + '\n'
276- Context.Output.with_enabled <|
277- log_line.write path on_existing_file=Existing_File_Behavior.Append
264+ "[" + db_id + "] " + query_text.to_display_text
278265
279- result
266+ Profile.time_execution _profile_level label=make_label module=JDBC_Connection <|
267+ path = if skip_log then "" else Environment.get "ENSO_SQL_LOG_PATH" . if_nothing ""
268+ if path.is_empty then @Tail_Call action else
269+ result = action
270+ ## If the action returns a dataflow error, `time_execution` returns the error, no duration.
271+ We could work around this. But we don't want to - the failing queries likely did not run anyway,
272+ so their time info would most likely be an outlier. For current purposes it makes sense to ignore such cases.
273+ Error.return_if_error result
274+
275+ # E.g. [SQLite] SELECT * FROM "test"
276+ padded_query = make_label.pad 100
277+ log_line = "[" + Date_Time.now.to_text + "] [" + db_id + "] " + padded_query '\n'
278+ Context.Output.with_enabled <|
279+ log_line.write path on_existing_file=Existing_File_Behavior.Append
280+
281+ result
280282
281283## ---
282284 private: true
@@ -285,3 +287,11 @@ private _profile_sql_if_enabled (jdbc_connection : JDBC_Connection) (~query_text
285287 this Connection concurrently.
286288private _synchronized (jdbc_connection : JDBC_Connection) ~action =
287289 jdbc_connection.operation_synchronizer.runSynchronizedAction _->action
290+
291+ private _profile_level = State.get Table if_missing=_profile_level_from_env
292+
293+ private _profile_level_from_env =
294+ env_val = Environment.get "ENSO_PROFILE_SQL"
295+ if env_val == Nothing then Nothing else
296+ level = Log_Level.from env_val
297+ if level.is_error then Nothing else level
0 commit comments