[bug_fixed] Race happens?

In this forum all bug reports concerning the 6.x branch will be gahtered. You have the possibility to track the bug fix process.

Moderators: EgonHugeist, mdaems

Post Reply
cnliou
Zeos Dev Team
Zeos Dev Team
Posts: 31
Joined: 11.11.2005, 12:18

[bug_fixed] Race happens?

Post by cnliou »

I am afraid this issue affects all drivers.

Revision 188 "testing".

Code: Select all

CREATE TABLE z1 (c1 VARCHAR(20),c2 VARCHAR(20),c3 SMALLINT,c4 NUMERIC,PRIMARY KEY (c1,c2,c3));

CREATE TABLE z2 (c1 VARCHAR(20),c2 VARCHAR(20),c3 SMALLINT,c4 SMALLINT,c5 VARCHAR(20), PRIMARY KEY (c1,c2,c3,c4));

CREATE TABLE z3 (c1 VARCHAR(20),c2 VARCHAR(20),c3 TIMESTAMPTZ,PRIMARY KEY (c1,c2));

INSERT INTO z1 VALUES ('A','ID1',1,287463.371);
INSERT INTO z1 VALUES ('A','ID1',2,46152.2361);

INSERT INTO z2 VALUES ('A','ID1',1,100,'XX');
INSERT INTO z2 VALUES ('A','ID1',2,200,'YY');

INSERT INTO z3 VALUES ('A','XX','2005-12-31 12:30');
INSERT INTO z3 VALUES ('A','YY','2005-10-31 14:30');
Set the following text in SQL.Text:

Code: Select all

SELECT SUM(z1.c4) AS amount
  ,z3.c3 AS DueDate
  ,AGE(z3.c3) AS age
FROM z1  LEFT JOIN z2 ON (z2.c1=z1.c1 AND z2.c2=z1.c2 AND z2.c3=z1.c3)
  LEFT JOIN z2 s2 ON (s2.c1=z1.c1 AND s2.c2=z1.c2 AND s2.c3=z1.c3)
  LEFT JOIN z3 ON (z3.c1=s2.c1 AND z3.c2=s2.c5)
WHERE z1.c1='A' AND z2.c4=200
GROUP BY DueDate,age
Problem: You will get "0" for "DueDate"! :x

To see what happens, enable logging:
Modify file ZAbstractRODataset.pas to enable the logging facility:

Code: Select all

use ZDbcLogging;

procedure TZAbstractRODataset.InternalInitFieldDefs;
var
  I, J, Size: Integer;
  AutoInit: Boolean;
  FieldType: TFieldType;
  ResultSet: IZResultSet;
  FieldName: string;
  FName: string;
begin
  FieldDefs.Clear;
  ResultSet := Self.ResultSet;
  AutoInit := ResultSet = nil;

  try
    { Opens an internal result set if query is closed. }
    if AutoInit then
    begin
      CheckSQLQuery;
      CheckConnected;
      ResultSet := CreateResultSet(FSQL.Statements[0].SQL, 0);
    end;
    if not Assigned(ResultSet) then
      raise Exception.Create(SCanNotOpenResultSet);

    { Reads metadata from resultset. }
//log
with ResultSet.GetMetadata do begin
 for I := 1 to GetColumnCount do
DriverManager.LogError(lcOther,'I='+IntToStr(I)+'--->'+GetColumnLabel(I)
        ,'TZSQLType='+IntToStr(Integer(GetColumnType(I)))
        ,Integer(ConvertDbcToDatasetType(GetColumnType(I)))
        ,'AAAAAAAAAA');
end;

    with ResultSet.GetMetadata do
    begin
      for I := 1 to GetColumnCount do
      begin
//log
DriverManager.LogError(lcOther,'I='+IntToStr(I)+'--->'+GetColumnLabel(I)
        ,'TZSQLType='+IntToStr(Integer(GetColumnType(I)))
        ,Integer(ConvertDbcToDatasetType(GetColumnType(I)))
        ,'BBBBBBBBBB');
        FieldType := ConvertDbcToDatasetType(GetColumnType(I));
The log follows:

Code: Select all

2006-12-13 20:40:19 cat: Execute, proto: postgresql-8, msg: SELECT SUM(z1.c4) AS amount
  ,z3.c3 AS DueDate
  ,AGE(z3.c3) AS age
FROM z1  LEFT JOIN z2 ON (z2.c1=z1.c1 AND z2.c2=z1.c2 AND z2.c3=z1.c3)
  LEFT JOIN z2 s2 ON (s2.c1=z1.c1 AND s2.c2=z1.c2 AND s2.c3=z1.c3)
  LEFT JOIN z3 ON (z3.c1=s2.c1 AND z3.c2=s2.c5)
WHERE z1.c1='A' AND z2.c4=200
GROUP BY DueDate,age

2006-12-13 20:40:19 cat: Other, proto: I=1--->amount, msg: TZSQLType=7, errcode: 6, error: AAAAAAAAAA
2006-12-13 20:40:19 cat: Other, proto: I=2--->duedate, msg: TZSQLType=14, errcode: 11, error: AAAAAAAAAA
2006-12-13 20:40:19 cat: Other, proto: I=3--->age, msg: TZSQLType=9, errcode: 1, error: AAAAAAAAAA
2006-12-13 20:40:19 cat: Other, proto: I=1--->amount, msg: TZSQLType=7, errcode: 6, error: BBBBBBBBBB
2006-12-13 20:40:19 cat: Execute, proto: postgresql-8, msg: SELECT version()
2006-12-13 20:40:19 cat: Execute, proto: postgresql-8, msg: SELECT n.nspname,c.relname,a.attname,a.atttypid,a.attnotnull,a.atttypmod,a.attlen,a.attnum,def.adsrc,dsc.description  FROM pg_catalog.pg_namespace n  JOIN pg_catalog.pg_class c ON (c.relnamespace = n.oid)  JOIN pg_catalog.pg_attribute a ON (a.attrelid=c.oid)  LEFT JOIN pg_catalog.pg_attrdef def ON (a.attrelid=def.adrelid AND a.attnum = def.adnum) LEFT JOIN pg_catalog.pg_description dsc ON (c.oid=dsc.objoid AND a.attnum = dsc.objsubid)  LEFT JOIN pg_catalog.pg_class dc ON (dc.oid=dsc.classoid AND dc.relname='pg_class') LEFT JOIN pg_catalog.pg_namespace dn ON (dc.relnamespace=dn.oid AND dn.nspname='pg_catalog')  WHERE a.attnum > 0 AND NOT a.attisdropped AND c.relname LIKE 'z1' AND a.attname LIKE '%' ORDER BY nspname,relname,attnum 
2006-12-13 20:40:19 cat: Execute, proto: postgresql-8, msg: SELECT n.nspname,c.relname,a.attname,a.atttypid,a.attnotnull,a.atttypmod,a.attlen,a.attnum,def.adsrc,dsc.description  FROM pg_catalog.pg_namespace n  JOIN pg_catalog.pg_class c ON (c.relnamespace = n.oid)  JOIN pg_catalog.pg_attribute a ON (a.attrelid=c.oid)  LEFT JOIN pg_catalog.pg_attrdef def ON (a.attrelid=def.adrelid AND a.attnum = def.adnum) LEFT JOIN pg_catalog.pg_description dsc ON (c.oid=dsc.objoid AND a.attnum = dsc.objsubid)  LEFT JOIN pg_catalog.pg_class dc ON (dc.oid=dsc.classoid AND dc.relname='pg_class') LEFT JOIN pg_catalog.pg_namespace dn ON (dc.relnamespace=dn.oid AND dn.nspname='pg_catalog')  WHERE a.attnum > 0 AND NOT a.attisdropped AND c.relname LIKE 'z2' AND a.attname LIKE '%' ORDER BY nspname,relname,attnum 
2006-12-13 20:40:19 cat: Execute, proto: postgresql-8, msg: SELECT n.nspname,c.relname,a.attname,a.atttypid,a.attnotnull,a.atttypmod,a.attlen,a.attnum,def.adsrc,dsc.description  FROM pg_catalog.pg_namespace n  JOIN pg_catalog.pg_class c ON (c.relnamespace = n.oid)  JOIN pg_catalog.pg_attribute a ON (a.attrelid=c.oid)  LEFT JOIN pg_catalog.pg_attrdef def ON (a.attrelid=def.adrelid AND a.attnum = def.adnum) LEFT JOIN pg_catalog.pg_description dsc ON (c.oid=dsc.objoid AND a.attnum = dsc.objsubid)  LEFT JOIN pg_catalog.pg_class dc ON (dc.oid=dsc.classoid AND dc.relname='pg_class') LEFT JOIN pg_catalog.pg_namespace dn ON (dc.relnamespace=dn.oid AND dn.nspname='pg_catalog')  WHERE a.attnum > 0 AND NOT a.attisdropped AND c.relname LIKE 'z3' AND a.attname LIKE '%' ORDER BY nspname,relname,attnum 
2006-12-13 20:40:19 cat: Other, proto: I=2--->duedate, msg: TZSQLType=3, errcode: 2, error: BBBBBBBBBB
2006-12-13 20:40:19 cat: Other, proto: I=3--->age, msg: TZSQLType=9, errcode: 1, error: BBBBBBBBBB
The three big "SELECT" SQL's are fired by this function:

Code: Select all

function TZPostgreSQLDatabaseMetadata.GetColumns(const Catalog: string;
  const SchemaPattern: string; const TableNamePattern: string;
  const ColumnNamePattern: string): IZResultSet;
The log shows that TZSQLType of "ResultSet" associated with field "DueDate" gets overwritten from "14" to "9" (by function GetColumnType() :?: ). I presume this is the cause of problem.:?:
You do not have the required permissions to view the files attached to this post.
User avatar
mdaems
Zeos Project Manager
Zeos Project Manager
Posts: 2766
Joined: 20.09.2005, 15:28
Location: Brussels, Belgium
Contact:

Post by mdaems »

Hi cnliou,

Thanks for the report. I would have been better if you'd logged it to the new Mantis Bug tracker.(We have to get used to it, isn't it?)

Anyway...
I think it's a PostgreSQL issue as the three big queries are PG-specific. Not sure, however. Maybe I could try it for mysql as well.

Mark
User avatar
cipto_kh
Senior Boarder
Senior Boarder
Posts: 83
Joined: 28.09.2005, 11:22
Location: Indonesia
Contact:

Post by cipto_kh »

I try it on FB 2.0 (without using the "age" function of course) and it also has the same error, the error in Delphi is
"Convertion is not possible for column 2 from Short to TimeStamp"

If I make persistant field from the query, the column 2 (DUEDATE) is generated as TSmallIntField instead of TDateTimeField :((

I think this error effect all DB too :(
cnliou
Zeos Dev Team
Zeos Dev Team
Posts: 31
Joined: 11.11.2005, 12:18

Post by cnliou »

Thank you for the testing :idea:

A minor correction to my original comment as:
The log shows that TZSQLType of "ResultSet" associated with field "DueDate" gets overwritten from "14" to "3" (by function GetColumnType() ).
I don't think this is a PostgreSQL specific problem. In fact I reported this problem to sourceforge years ago and thought this was PostgreSQL specific until now.

This problem happens only when the SELECTs are complex enough. It doesn't happen to simple SELECTs.

In some cases, re-ordering the selected columns appears to "solve" the problem like this:

Revise

Code: Select all

SELECT
(SELECT m FROM n) AS a
,MAX(i,j) AS c
,COALESCE(x,y) AS b
FROM...
to

Code: Select all

SELECT
COALESCE(x,y) AS b
,(SELECT m FROM n) AS a
,MAX(i,j) AS c
FROM...
This is of course a dirty workaround and sometimes doesn't work.

Watch the two logging statements:
They are as close as nearly consecutive. There is no call to SELECT in between. Weird is the log shows 3 ghost SELECTs in the middle of the logging outputs. This makes me think that this is a multi-threaded system with race problem because, I think, some heavily loaded threads fail to finish their jobs in time and thus result in race problems.
User avatar
mdaems
Zeos Project Manager
Zeos Project Manager
Posts: 2766
Joined: 20.09.2005, 15:28
Location: Brussels, Belgium
Contact:

Post by mdaems »

0 result for duedate also confirmed for mysql.

I'll try to give it a detailed look later.

Mark
User avatar
mdaems
Zeos Project Manager
Zeos Project Manager
Posts: 2766
Joined: 20.09.2005, 15:28
Location: Brussels, Belgium
Contact:

Post by mdaems »

I did the full debugging hell of a job.

During analysis of the query 1 token (table part of z3.c3) was skipped. This caused confusion when resolving 'c3' as this is also a field of Z1. This made zeos treat Z3.C3 as a smallint field (Z1.C3).

For me it works now...
I committed this fix to SVN testing in revision 191.

Code: Select all

Index: ZGenericSqlAnalyser.pas
===================================================================
--- ZGenericSqlAnalyser.pas	(revision 190)
+++ ZGenericSqlAnalyser.pas	(revision 191)
@@ -545,6 +545,7 @@
         SelectSchema.AddField(TZFieldRef.Create(False, '', '', '', '',
           Alias, nil));
         ClearElements;
+        Dec(TokenIndex); // go back 1 token(Because of Inc in next lines)
       end;
     end;
     Inc(TokenIndex);
For mysql the example did not show the gost sql.

Please confirm if the problem is fixed.

Mark
User avatar
mdaems
Zeos Project Manager
Zeos Project Manager
Posts: 2766
Joined: 20.09.2005, 15:28
Location: Brussels, Belgium
Contact:

Post by mdaems »

Had to do a second commit (rev192) : it was only fixed when an alias was provided for the preceding field.

Confirmed by CN on Jan 10. 2007.

Mark
Post Reply