How hard it is to implement a new event in TZSQLMonitor?

[aehimself]

I re-wrote one of my largest applications to use .Field properties instead of burned-in queries not that long ago. Before, I was doing logging like this...

Code: Select all

dataset.SQL.Text := insert_function_from_dll(parameter1, parameter2);
Log(dataset.SQL.Text);
dataset.ExecSQL;
Log(dataset.RowsAffected + ' row(s) affected in ' + timeelapsed + ' ms');

Now, it's a bit more easy to read, especially with my SQL table helper units:

Code: Select all

mytable.Insert;
mytable.FField1.Value := 'Hello';
mytable.FField2.Value := 42;
mytable.Save;

I created a TZSQLMonitor in the main application, which is catching all events nicely.... except the row(s) returned / affected. How complicated it would be to implement such an event in TZSQLMonitor?

[miab3]

What is this?:

mytable.Save;

Michal

[marsupilami]

What is this?:

mytable.Save;

I assume, aehimself has created some class helpers.

To get on topic - I don't know how easy it is to extend logging. I think that logging isn't a feature of the TZSqlMonitor directly. Logging happens on the dbc layer with code like this:

Code: Select all

    if DriverManager.HasLoggingListener then
      DriverManager.LogMessage(lcConnect, ConSettings^.Protocol, LogMsg);

So if one wants to do more logging, it is a matter of extending the driver in use, I think. For rows returned / affected, the statements would have to be extended.

[aehimself]

I assume, aehimself has created some class helpers.

I'm not a big fan of class helpers, I like to write custom classes. By a table wrapper I mean a completely separate TObject, containing a TZQuery object, publishing the table's field in SQL as custom properties:

Code: Select all

TMyTable = Class
strict private
 _sqltable: TZQuery;
public
 FCreated: TMyDateTimeField;
End;

These fields are assigned after setting the table active:

Code: Select all

 Self.FCreted.AssignField(_sqltable.FieldByName('Created));

The definitions are automatically generated by the database layout designer: if a table is created / deleted / modified, it's creating the delta scripts, full create scripts, the TMyTable definitions and some custom data formats required for the SQL query generator to be able to build a valid SQL query if the user wants to see "Created" and "IPAddress".

It's not ORM, but something like. The main purpose of it was to get rid of the continuous, expensive .FieldByName lookups as the application runs.
As TMyTable completely hides the ZQuery object it publishes some properties / methods, like .Eof, .RecNo, .RecordCount, etc.
.Save is simply calling _sqltable.Post after some internal data validation. I chose that name because it's easier to remember for me

Logging happens on the dbc layer with code like this:

Code: Select all

    if DriverManager.HasLoggingListener then
      DriverManager.LogMessage(lcConnect, ConSettings^.Protocol, LogMsg);

So if one wants to do more logging, it is a matter of extending the driver in use, I think. For rows returned / affected, the statements would have to be extended.

Well, the good news is that you answered my question as I have no idea what are you talking about I already saw statement and drivermanager references in the sources, but never actually worked with them... it's a good start though.

I'll see if I can get myself into it.

[Fr0sT]

The main purpose of it was to get rid of the continuous, expensive .FieldByName lookups as the application runs.

Regardless of an application it's a usual pattern of pre-caching a result of a slow function. Luckily TDataset easily allows it

Code: Select all

	f := DS.FieldByName('foo');
	for i := 0 to 100000 do
	begin
	  f.Value := i;
	  DS.Next;
	end;

[aehimself]

Effectively that's exactly what my wrapper is doing. After successfully opening the query, it calls it's own AssingFields method, which is assigning the fields to my own... field wrappers :D

Procedure MyTable.AssignFields;
Begin
Self.Field1.AssignField(_query.FieldByName('Field1));
Self.Field2.AssignField(_query.FieldByName('Field2));
[...]
End;

So from my code I simply can say...

MyTableInstance.Field1.Value := 'Hello, world';

This takes care of editing the query and posting the changes, if it's in browse mode. Value changes based on the definition... I have TMyBooleanFields, TMyIntegerFields, etc., the .Value propery always reads and writes the necessary type.

It's just instead of locally, I created a global wrapper to reduce code in routines.

[EgonHugeist]

@aehimself
any progress about tread toppic?

[aehimself]

any progress about tread toppic?

No, not yet. We had a release at work at the end of last week, so even my free time was a bit chaotic. I suppose I'll have time this week or next to dig myself into the topic.
Don't worry, I'll post a pull request once it's done :)

[EgonHugeist]

Not a problem, just wanted to know about grogress. It make no sence if i quickly add it, if you started already...

[aehimself]

Not a problem, just wanted to know about grogress. It make no sence if i quickly add it, if you started already...

I had time to start playing around, and I successfully expanded TZAbstractRODataSet with row(s) affected and record(s) returned logging messages. Then I quickly realized...

[2020.07.15 15:12:40.555] Prepare Statement 4 : show variables like 'lower_case_table_names'
[2020.07.15 15:12:40.555] Execute Statement 4 : show variables like 'lower_case_table_names'
[2020.07.15 15:12:40.566] Prepare Statement 5 : SHOW TABLES FROM database LIKE '%'
[2020.07.15 15:12:40.566] Execute Statement 5 : SHOW TABLES FROM database LIKE '%'
[2020.07.15 15:12:41.803] 11 record(s) returned

Notice that only SHOW TABLES returns a message. I guess the correct way would be to leave TZAbstractRODataSet alone and move the logging logic to IZStatement (or maybe to each IZStatement descendants...)? If yes, I'll still need to dig deeper as I don't know when .Execute, .ExecuteUpdate and .ExecuteQuery is called.
As an extra, what exactly we should do if .FetchRows is not zero and we are fetching additional record(s) during scrolling?

@Egonhugeist - you mentioned you could do it quickly? :)

[EgonHugeist]

Done in SVN on 7.3-testing
Implementing the "affected row(s)" was simple, implementing "retunred row(s)" was a bit more work.
Looking to your current log iv'e been trying to reduce the number of duplicate logs.
Note i don't use it. It's a performance loss logging the request (-> serialization -> CriticalSection.Enter..CriticalSection.Leave) but it's a nice tweak for everybody to find out issues sitting in front of a monitor.

Please test and give me a feedback.

[aehimself]

I saw the commit and oh, my god; this is definitely not what I started...
I can't wait for it to show up in Git, I'll give it a try immediately.

Thank you!

[aehimself]

Looking good, but still some statements return no lcFetchDone:

Execute Statement 1 : show variables like 'version' in 0 ms
Execute Statement 1 : show variables like 'version' in 11 ms
Execute Statement 2 : show variables like 'version_comment' in 0 ms
Execute Statement 2 : show variables like 'version_comment' in 9 ms
Execute Statement 3 : select database() as 'DATABASE' in 0 ms
Execute Statement 3 : select database() as 'DATABASE' in 2 ms

Execute Statement 4 : show variables like 'lower_case_table_names' in 0 ms
Execute Statement 4 : show variables like 'lower_case_table_names' in 9 ms
Execute Statement 5 : SHOW TABLES FROM mydatabase LIKE '%' in 0 ms
Execute Statement 5 : SHOW TABLES FROM mydatabase LIKE '%' in 5 ms
Fetch Statement 5, affected 11 row(s) in 6 ms

These are most probably executed directly via the SQLConnection.

Also, it seems that 7.3.0-31f20919 does not seem to log .ExecSQLs on MySQL anymore, while 7.3.0-33cc5d39 did.

Code: Select all

commit 31f209196e056aee0ad4c180cf5d356e1ccd0444
Author: egonhugeist <egonhugeist@localhost>
Date:   Tue Jul 21 16:34:55 2020 +0000

    resolve a dbgrid issue while changing successive fields of same row, reported by miab3

Code: Select all

commit 33cc5d39feccbfee040c078b6db0689854aa8ef8
Author: egonhugeist <egonhugeist@localhost>
Date:   Sun Jun 21 16:52:15 2020 +0000

    upgrade TZUpdateSQL for pending TXN support

On Oracle, it works just fine:

Prepare Statement 17 : UPDATE table SET field = NULL WHERE ID = -1
Execute prepared Statement 17, affected 0 row(s) in 24 ms

Looking to your current log iv'e been trying to reduce the number of duplicate logs.

On MySQL the only change I see is that instead of a prepare and an execute, two execute events are logged with the query.

[aehimself]

The issue is:

ZDbcMySQLStatement.pas : 804

Code: Select all

        if BindList.HasReturnParam then
      if DriverManager.HasLoggingListener then
        DriverManager.LogMessage(lcExecute,Self);

Logging only happens if BindList.HasReturnParam is true (whatever that is? :|). In a simple update, this seems to be false (UPDATE table SET field = value WHERE field = value).

My problem is that the code seems to be quite... strange. Before @Egonhugeis's commit, my git shows the method like this:

Code: Select all

        if BindList.HasReturnParam then
    end else begin

If condition Then end...?!

This way I simply can not understand what this method is supposed to do (TZAbstractMySQLPreparedStatement.ExecuteUpdatePrepared.ExecEmulated) and where should I touch to fix it :|

[EgonHugeist]

Fixed as proposed. Thx for pointing this out.
Btw. is the elapsed time available in the logs?