Thread: Problem with Use Declare/Fetch
Hi,
Some time ago, We start to update our ODBC version.
We are using Post 9.0.4(UTF) and ODBC Unicode (psqlodbc_09_01_0100-1)
with use declare/fetch enable.
One of my customeres have a routine thats reads from some tables and
inserts in anoter. Bellow, some statements:
{snip}
<192.168.1.160# 2012-03-15 16:09:09 BRT 3117>LOG: statement:
BEGIN;declare "P01303" cursor for SELECT PC33Codigo, PC33Emp08,
PC33FatArr, PC33QtdPte, PC33CodInd FROM PC33T WHERE PC33Emp08 = '17' and
PC33Codigo = E'DECLARE F ' ORDER BY PC33Emp08, PC33Codigo ;fetch 100 in
"P01303"
<192.168.1.160# 2012-03-15 16:09:09 BRT 3118>LOG: statement: close "P01303"
<192.168.1.160# 2012-03-15 16:09:09 BRT 3119>LOG: statement: declare
"P01304" cursor for SELECT PC01CodEmp, PC01UsaCom, PC01TabRel FROM PC01T
WHERE PC01CodEmp = '17' ORDER BY PC01CodEmp ;fetch 100 in "P01304"
<192.168.1.160# 2012-03-15 16:09:09 BRT 3120>LOG: statement: close "P01304"
---- PROBLEM HERE ---
<192.168.1.160# 2012-03-15 16:09:09 BRT 3121>LOG: statement: declare
"P01305" cursor for SELECT Pc13Item, PC13CodPed, PC13AnoPed, PC13Emp08P,
PC13VlrEst, PC13VrUnit, PC13Cor, PC13Codigo, PC13Emp08, PC13Produ,
PC13Linha FROM PC13T WHERE (PC13Emp08 = '17' and PC13Codigo >= E'
') AND (PC13Linha >= '0' and PC13Linha <= '99999') AND
(PC13CodPed = '0') AND (PC13AnoPed = 0) AND (PC13Produ = E'S') AND
(PC13Codigo <= E'zzzzz ') ORDER BY PC13Emp08, PC13Codigo,
PC13Cor, PC13AnoPed ;fetch 100 in "P01305"
---- PROBLEM HERE ---
<192.168.1.160# 2012-03-15 16:09:09 BRT 3122>LOG: statement: declare
"P36492" cursor with hold for SELECT cf25item, cf25objeto, cf02login,
cf25conteu FROM CF25T WHERE cf02login = E'ADMINISTRADOR ' and
cf25objeto = E'PC0295PC0208 ' and cf25item = '1' ORDER BY cf02login,
cf25objeto, cf25item ;fetch 100 in "P36492"
<192.168.1.160# 2012-03-15 16:09:09 BRT 3123>LOG: statement: close "P36492"
{snip}
The problem is in table PC13T, that have more than 100 tuples. The
cursor "P01305" was executed once, instead of loop until the end of
resultset.
The strange is that this cursor is not CLOSED anymore:
postgres@vm002:~/data_90$ grep P01305 fetch_problem.log
<192.168.1.160# 2012-03-15 16:09:09 BRT 3121>LOG: statement: declare
"P01305" cursor for SELECT Pc13Item, PC13CodPed, PC13AnoPed, PC13Emp08P,
PC13VlrEst, PC13VrUnit, PC13Cor, PC13Codigo, PC13Emp08, PC13Produ,
PC13Linha FROM PC13T WHERE (PC13Emp08 = '17' and PC13Codigo >= E'
') AND (PC13Linha >= '0' and PC13Linha <= '99999') AND
(PC13CodPed = '0') AND (PC13AnoPed = 0) AND (PC13Produ = E'S') AND
(PC13Codigo <= E'zzzzz ') ORDER BY PC13Emp08, PC13Codigo,
PC13Cor, PC13AnoPed ;fetch 100 in "P01305"
postgres@vm002:~/data_90$
Best regards,
Alexandre
Hi Alexandre,
(2012/03/16 5:09), Alexandre - Aldeia Digital wrote:
> Hi,
>
> Some time ago, We start to update our ODBC version.
> We are using Post 9.0.4(UTF) and ODBC Unicode (psqlodbc_09_01_0100-1)
> with use declare/fetch enable.
>
> One of my customeres have a routine thats reads from some tables and
> inserts in anoter. Bellow, some statements:
>
> {snip}
>
> <192.168.1.160# 2012-03-15 16:09:09 BRT 3117>LOG: statement:
> BEGIN;declare "P01303" cursor for SELECT PC33Codigo, PC33Emp08,
> PC33FatArr, PC33QtdPte, PC33CodInd FROM PC33T WHERE PC33Emp08 = '17' and
> PC33Codigo = E'DECLARE F ' ORDER BY PC33Emp08, PC33Codigo ;fetch 100 in
> "P01303"
> <192.168.1.160# 2012-03-15 16:09:09 BRT 3118>LOG: statement: close "P01303"
>
> <192.168.1.160# 2012-03-15 16:09:09 BRT 3119>LOG: statement: declare
> "P01304" cursor for SELECT PC01CodEmp, PC01UsaCom, PC01TabRel FROM PC01T
> WHERE PC01CodEmp = '17' ORDER BY PC01CodEmp ;fetch 100 in "P01304"
> <192.168.1.160# 2012-03-15 16:09:09 BRT 3120>LOG: statement: close "P01304"
>
> ---- PROBLEM HERE ---
>
> <192.168.1.160# 2012-03-15 16:09:09 BRT 3121>LOG: statement: declare
> "P01305" cursor for SELECT Pc13Item, PC13CodPed, PC13AnoPed, PC13Emp08P,
> PC13VlrEst, PC13VrUnit, PC13Cor, PC13Codigo, PC13Emp08, PC13Produ,
> PC13Linha FROM PC13T WHERE (PC13Emp08 = '17' and PC13Codigo >= E' ') AND
> (PC13Linha >= '0' and PC13Linha <= '99999') AND (PC13CodPed = '0') AND
> (PC13AnoPed = 0) AND (PC13Produ = E'S') AND (PC13Codigo <= E'zzzzz ')
> ORDER BY PC13Emp08, PC13Codigo, PC13Cor, PC13AnoPed ;fetch 100 in "P01305"
>
> ---- PROBLEM HERE ---
>
> <192.168.1.160# 2012-03-15 16:09:09 BRT 3122>LOG: statement: declare
> "P36492" cursor with hold for SELECT cf25item, cf25objeto, cf02login,
> cf25conteu FROM CF25T WHERE cf02login = E'ADMINISTRADOR ' and cf25objeto
> = E'PC0295PC0208 ' and cf25item = '1' ORDER BY cf02login, cf25objeto,
> cf25item ;fetch 100 in "P36492"
> <192.168.1.160# 2012-03-15 16:09:09 BRT 3123>LOG: statement: close "P36492"
>
> {snip}
Could you send me directly the Mylog output?
regards,
Hiroshi Inoue
>
> The problem is in table PC13T, that have more than 100 tuples. The
> cursor "P01305" was executed once, instead of loop until the end of
> resultset.
> The strange is that this cursor is not CLOSED anymore:
>
> postgres@vm002:~/data_90$ grep P01305 fetch_problem.log
>
> <192.168.1.160# 2012-03-15 16:09:09 BRT 3121>LOG: statement: declare
> "P01305" cursor for SELECT Pc13Item, PC13CodPed, PC13AnoPed, PC13Emp08P,
> PC13VlrEst, PC13VrUnit, PC13Cor, PC13Codigo, PC13Emp08, PC13Produ,
> PC13Linha FROM PC13T WHERE (PC13Emp08 = '17' and PC13Codigo >= E' ') AND
> (PC13Linha >= '0' and PC13Linha <= '99999') AND (PC13CodPed = '0') AND
> (PC13AnoPed = 0) AND (PC13Produ = E'S') AND (PC13Codigo <= E'zzzzz ')
> ORDER BY PC13Emp08, PC13Codigo, PC13Cor, PC13AnoPed ;fetch 100 in "P01305"
>
> postgres@vm002:~/data_90$
>
>
> Best regards,
>
>
> Alexandre
Hi Hiroshi,
Sorry for delay!
I sent the links to download the logs directly in your e-mail.
I analyzed the logs and I believe that the error was in this cursor:
[1168-47.972] stmt_with_params = 'declare "P00954" cursor for SELECT
T1.Fn04CodEmp(...)
This query must return about 14k rows. But with use/declare fectch (in
this case, cache size = 10), returns only 10 rows.
I don't search in other areas, but if you need I can do this.
Another doubt: My Rollback on erros is set to Transaction. But I can see
some SAVEPOINT/RELEASE statements. It's normal ?
Best regards,
Alexandre
Em 15-03-2012 20:33, Hiroshi Inoue escreveu:
> Hi Alexandre,
>
> (2012/03/16 5:09), Alexandre - Aldeia Digital wrote:
>> Hi,
>>
>> Some time ago, We start to update our ODBC version.
>> We are using Post 9.0.4(UTF) and ODBC Unicode (psqlodbc_09_01_0100-1)
>> with use declare/fetch enable.
>>
>> One of my customeres have a routine thats reads from some tables and
>> inserts in anoter. Bellow, some statements:
>>
>> {snip}
>>
>> <192.168.1.160# 2012-03-15 16:09:09 BRT 3117>LOG: statement:
>> BEGIN;declare "P01303" cursor for SELECT PC33Codigo, PC33Emp08,
>> PC33FatArr, PC33QtdPte, PC33CodInd FROM PC33T WHERE PC33Emp08 = '17' and
>> PC33Codigo = E'DECLARE F ' ORDER BY PC33Emp08, PC33Codigo ;fetch 100 in
>> "P01303"
>> <192.168.1.160# 2012-03-15 16:09:09 BRT 3118>LOG: statement: close
>> "P01303"
>>
>> <192.168.1.160# 2012-03-15 16:09:09 BRT 3119>LOG: statement: declare
>> "P01304" cursor for SELECT PC01CodEmp, PC01UsaCom, PC01TabRel FROM PC01T
>> WHERE PC01CodEmp = '17' ORDER BY PC01CodEmp ;fetch 100 in "P01304"
>> <192.168.1.160# 2012-03-15 16:09:09 BRT 3120>LOG: statement: close
>> "P01304"
>>
>> ---- PROBLEM HERE ---
>>
>> <192.168.1.160# 2012-03-15 16:09:09 BRT 3121>LOG: statement: declare
>> "P01305" cursor for SELECT Pc13Item, PC13CodPed, PC13AnoPed, PC13Emp08P,
>> PC13VlrEst, PC13VrUnit, PC13Cor, PC13Codigo, PC13Emp08, PC13Produ,
>> PC13Linha FROM PC13T WHERE (PC13Emp08 = '17' and PC13Codigo >= E' ') AND
>> (PC13Linha >= '0' and PC13Linha <= '99999') AND (PC13CodPed = '0') AND
>> (PC13AnoPed = 0) AND (PC13Produ = E'S') AND (PC13Codigo <= E'zzzzz ')
>> ORDER BY PC13Emp08, PC13Codigo, PC13Cor, PC13AnoPed ;fetch 100 in
>> "P01305"
>>
>> ---- PROBLEM HERE ---
>>
>> <192.168.1.160# 2012-03-15 16:09:09 BRT 3122>LOG: statement: declare
>> "P36492" cursor with hold for SELECT cf25item, cf25objeto, cf02login,
>> cf25conteu FROM CF25T WHERE cf02login = E'ADMINISTRADOR ' and cf25objeto
>> = E'PC0295PC0208 ' and cf25item = '1' ORDER BY cf02login, cf25objeto,
>> cf25item ;fetch 100 in "P36492"
>> <192.168.1.160# 2012-03-15 16:09:09 BRT 3123>LOG: statement: close
>> "P36492"
>>
>> {snip}
>
> Could you send me directly the Mylog output?
>
> regards,
> Hiroshi Inoue
>
>
>>
>> The problem is in table PC13T, that have more than 100 tuples. The
>> cursor "P01305" was executed once, instead of loop until the end of
>> resultset.
>> The strange is that this cursor is not CLOSED anymore:
>>
>> postgres@vm002:~/data_90$ grep P01305 fetch_problem.log
>>
>> <192.168.1.160# 2012-03-15 16:09:09 BRT 3121>LOG: statement: declare
>> "P01305" cursor for SELECT Pc13Item, PC13CodPed, PC13AnoPed, PC13Emp08P,
>> PC13VlrEst, PC13VrUnit, PC13Cor, PC13Codigo, PC13Emp08, PC13Produ,
>> PC13Linha FROM PC13T WHERE (PC13Emp08 = '17' and PC13Codigo >= E' ') AND
>> (PC13Linha >= '0' and PC13Linha <= '99999') AND (PC13CodPed = '0') AND
>> (PC13AnoPed = 0) AND (PC13Produ = E'S') AND (PC13Codigo <= E'zzzzz ')
>> ORDER BY PC13Emp08, PC13Codigo, PC13Cor, PC13AnoPed ;fetch 100 in
>> "P01305"
>>
>> postgres@vm002:~/data_90$
>>
>>
>> Best regards,
>>
>>
>> Alexandre
>
>
Hi Alexandre,
(2012/04/10 8:25), Alexandre - Aldeia Digital wrote:
> Hi Hiroshi,
>
> Sorry for delay!
>
> I sent the links to download the logs directly in your e-mail.
> I analyzed the logs and I believe that the error was in this cursor:
>
> [1168-47.972] stmt_with_params = 'declare "P00954" cursor for SELECT
> T1.Fn04CodEmp(...)
>
> This query must return about 14k rows. But with use/declare fectch (in
> this case, cache size = 10), returns only 10 rows.
It seems OK to me. Psqlodbc driver fetches tuples using extended query
other than the 1st fetch. You can see the following lines in many
places
SendExecuteRequest: plan_name=P00954 count=10
and the query returns 14725 tuples as a result.
[1168-332.835]end of tuple list -- setting inUse to false: this =
083A0810 SELECT 5
ELECT 5
[1168-332.835]_QR_next_tuple: 'C' fetch_total = 14725 & this_fetch = 5
> I don't search in other areas, but if you need I can do this.
>
> Another doubt: My Rollback on erros is set to Transaction. But I can see
> some SAVEPOINT/RELEASE statements. It's normal ?
Yes the driver uses savepoint/rollback in some internal queries.
regards,
Hiroshi Inoue
Hi Hiroshi, Em 11-04-2012 10:38, Hiroshi Inoue escreveu: > Hi Alexandre, > > (2012/04/10 8:25), Alexandre - Aldeia Digital wrote: >> Hi Hiroshi, >> >> Sorry for delay! >> >> I sent the links to download the logs directly in your e-mail. >> I analyzed the logs and I believe that the error was in this cursor: >> >> [1168-47.972] stmt_with_params = 'declare "P00954" cursor for SELECT >> T1.Fn04CodEmp(...) >> >> This query must return about 14k rows. But with use/declare fectch (in >> this case, cache size = 10), returns only 10 rows. > > It seems OK to me. Psqlodbc driver fetches tuples using extended query > other than the 1st fetch. You can see the following lines in many > places > > SendExecuteRequest: plan_name=P00954 count=10 > > and the query returns 14725 tuples as a result. > > [1168-332.835]end of tuple list -- setting inUse to false: this = > 083A0810 SELECT 5 > ELECT 5 > [1168-332.835]_QR_next_tuple: 'C' fetch_total = 14725 & this_fetch = 5 > Very strange. I will try again and send you the results. >> I don't search in other areas, but if you need I can do this. >> >> Another doubt: My Rollback on erros is set to Transaction. But I can see >> some SAVEPOINT/RELEASE statements. It's normal ? > > Yes the driver uses savepoint/rollback in some internal queries. Ok. > regards, > Hiroshi Inoue Best regards, Alexandre