-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1
Hi Emmanuel,
I send all information you requested. Resuming, at iSQL and Postgres SQL
command line everything works fine.
Postgres SQL command line, postgres log:
32173 2008-12-22 09:55:43 CETLOG: duration: 4.199 ms statement: SELECT
* FROM table2 LIMIT 1;
iSQL, postgres log:
406 2008-12-22 10:22:52 CETLOG: duration: 2.466 ms parse <unnamed>:
SELECT * FROM table2 LIMIT 1
406 2008-12-22 10:22:52 CETLOG: duration: 0.230 ms bind <unnamed>:
SELECT * FROM table2 LIMIT 1
406 2008-12-22 10:22:52 CETLOG: duration: 0.271 ms execute <unnamed>:
SELECT * FROM table2 LIMIT 1
406 2008-12-22 10:22:52 CETLOG: duration: 1.094 ms parse <unnamed>:
SELECT typname FROM pg_catalog.pg_type WHERE oid = $1
406 2008-12-22 10:22:52 CETLOG: duration: 0.240 ms bind <unnamed>:
SELECT typname FROM pg_catalog.pg_type WHERE oid = $1
406 2008-12-22 10:22:52 CETDETAIL: parameters: $1 = '1007'
406 2008-12-22 10:22:52 CETLOG: duration: 0.021 ms execute <unnamed>:
SELECT typname FROM pg_catalog.pg_type WHERE oid = $1
406 2008-12-22 10:22:52 CETDETAIL: parameters: $1 = '1007'
406 2008-12-22 10:22:52 CETLOG: duration: 0.149 ms parse <unnamed>:
SELECT typname FROM pg_catalog.pg_type WHERE oid = $1
406 2008-12-22 10:22:52 CETLOG: duration: 0.105 ms bind <unnamed>:
SELECT typname FROM pg_catalog.pg_type WHERE oid = $1
406 2008-12-22 10:22:52 CETDETAIL: parameters: $1 = '1005'queries to
406 2008-12-22 10:22:52 CETLOG: duration: 0.023 ms execute <unnamed>:
SELECT typname FROM pg_catalog.pg_type WHERE oid = $1
406 2008-12-22 10:22:52 CETDETAIL: parameters: $1 = '1005'
(Note that next times I execute this SELECT, select from
"pg_catalog.pg_type" are not executed again. When you load iSQL viewer,
the is also some SQL queries to scan object on database, bug iSQL uses
bigs sql sentences to do this (Sequioa seems to execute small SQL
sentences in a loop when scanning database))
iSQL log:
6857 [isql-swing-events] INFO org.isqlviewer.util.QueryExecutor -
Executiong SQL Statement:
SELECT * FROM table2 LIMIT 1
6868 [isql-swing-events] INFO org.isqlviewer.util.QueryExecutor - Total
query execution time: .
6871 [isql-swing-events] INFO org.isqlviewer.util.QueryExecutor -
Change in memory after query has been executed: -35.789KB.
6890 [isql-swing-events] INFO org.isqlviewer.util.QueryExecutor - Total
rows processed from query: 1.
6929 [isql-swing-events] INFO org.isqlviewer.util.QueryExecutor - Total
time to render query results: 20 millisecond(s).
6935 [isql-swing-events] INFO org.isqlviewer.util.QueryExecutor -
Change in memory after results have been rendered: -160.961KB.
7436 [isql-swing-events] INFO org.isqlviewer.util.QueryExecutor - Query
execution/rendering process has finished.
Some database details:
Tables: 228
Views: 75
The "table2" table is one of the biggest in our database
Number of columns: 118
Emmanuel Cecchet escribió:
> Hi Ruben,
>
>
> It looks like the requests you are seeing are generated by the Postgres
> JDBC driver. It can come either from the ResultSetMetaData fetching or
> from the database schema fetching.
> How many tables do you have?
> How many columns per table?
> What happens if you use a console like iSQL and try to browse the
> database schema (eventually going directly to PostgreSQL and not through
> Sequoia)?
>
> Thanks for the feedback,
> Emmanuel
>
>> Both problems must to be related: at this point all test are all done
>> with sequioa sql client. There is not application involved.
>>
>> I think I have more useful information related to this problem. I have
>> set up postgres to log every SQL command and the timestamp.
>>
>> When I load controller, it seems to check every object in database.
>> There are too many SQLs at database, but If this is once this is ok.
>>
>> The problem is when I try to execute the SQL "SELECT * FROM table2 LIMIT
>> 1": Then is where there is a really big number of SQL's against the
>> database.
>>
>> I have attached a little more than one second postgres log since I
>> execute "SELECT * FROM table2". I have waited more than a minute and It
>> dind't finish. It also generated almost 100Mb log.
>>
>> I guess cache is not working?
>>
>>
>>
>> Emmanuel Cecchet escribió:
>>
>>> Hi Ruben,
>>>
>>>
>>>> Always when I try to get some data from one especified table (it is
>>>> always the same table) top command shows postgres at 70%-80%
>>>>
>>>> If you try to know witch SQLs is being executed in postgres, executing:
>>>>
>>>> echo 'SELECT current_query FROM pg_stat_activity;' |
>>>> /usr/local/pgsql/bin/psql vacadb -p 5432
>>>>
>>>> It shows:
>>>> - ------
>>>> SELECT def.adsrc FROM pg_catalog.pg_class c 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) WHERE c.oid = $1 and a.attnum = $2 AND def.adsrc LIKE
>>>> '%nextval(%'
>>>> SELECT current_query FROM pg_stat_activity;
>>>> - -------
>>>>
>>> If I am not mistaken this is a query issued by the Postgres JDBC driver
>>> to retrieve the ResultSetMetaData. When you execute a query, Sequoia
>>> fetches the ResultSet from the database but also the ResultSetMetaData
>>> to get column names and other information in case you access the result
>>> using rs.getString("column_name"). It turns out that ResultSetMetaData
>>> fetching is very slow in Postgres. This is why we have implemented a
>>> MetadataCache in Sequoia. The first query execution should fetch the
>>> ResultSetMetadata but subsequent queries should get it from the cache.
>>>
>>>> If you get the controller log, you have a message that is repeating all
>>>> the time:
>>>>
>>>> [...]
>>>> 16:06:03,221 WARN virtualdatabase.VirtualDatabaseWorkerThread.vvacadb
>>>> Client (login:vaca,host:192.168.12.8 closed connection with server)
>>>> 16:06:04,365 WARN virtualdatabase.VirtualDatabaseWorkerThread.vvacadb
>>>> Client (login:vaca,host:192.168.12.8 closed connection with server)
>>>> 16:06:04,856 WARN virtualdatabase.VirtualDatabaseWorkerThread.vvacadb
>>>> Client (login:vaca,host:192.168.12.8 closed connection with server)
>>>> 16:06:05,683 WARN virtualdatabase.VirtualDatabaseWorkerThread.vvacadb
>>>> Client (login:vaca,host:192.168.12.8 closed connection with server)
>>>> 16:06:06,989 WARN virtualdatabase.VirtualDatabaseWorkerThread.vvacadb
>>>> Client (login:vaca,host:192.168.12.8 closed connection with server)
>>>> 16:06:07,642 WARN virtualdatabase.VirtualDatabaseWorkerThread.vvacadb
>>>> Client (login:vaca,host:192.168.12.8 closed connection with server)
>>>> 16:06:08,300 WARN virtualdatabase.VirtualDatabaseWorkerThread.vvacadb
>>>> Client (login:vaca,host:192.168.12.8 closed connection with server)
>>>> 16:06:08,789 WARN virtualdatabase.VirtualDatabaseWorkerThread.vvacadb
>>>> Client (login:vaca,host:192.168.12.8 closed connection with server)
>>>> 16:06:09,277 WARN virtualdatabase.VirtualDatabaseWorkerThread.vvacadb
>>>> Client (login:vaca,host:192.168.12.8 closed connection with server)
>>>> [...]
>>>>
>>>> ... and go on, until I disable backend.
>>>>
>>> This looks like this is a separate issue. A client is dropping
>>> connections without calling Connection.close(). I cannot tell why this
>>> is happening but at least this is the diagnosis! This usually happens
>>> when you kill a client application or threads that had a private
>>> connection are terminated and garbage collected.
>>>
>>>> I have no idea what's going on. Any advise would be really appreciated.
>>>>
>>> Let me know if that helps,
>>> Emmanuel
>>>
>>>
>>>> -----BEGIN PGP SIGNATURE-----
>>>> Version: GnuPG v1.4.6 (GNU/Linux)
>>>> Comment: Using GnuPG with Mozilla - http://enigmail.mozdev.org
>>>>
>>>> iD8DBQFJSmg9Io1XmbAXRboRAonmAJ9JJq18cNcrgAZk1RyBArGiBCC3kgCdEeSQ
>>>> hKAcWU+6Y+p0SVNcEu+RbSc=
>>>> =0k8/
>>>> -----END PGP SIGNATURE-----
>>>> _______________________________________________
>>>> Sequoia mailing list
>>>> [email protected]
>>>> https://forge.continuent.org/mailman/listinfo/sequoia
>>>>
>>>
>> -----BEGIN PGP SIGNATURE-----
>> Version: GnuPG v1.4.6 (GNU/Linux)
>> Comment: Using GnuPG with Mozilla - http://enigmail.mozdev.org
>>
>> iD8DBQFJS1h4Io1XmbAXRboRAkTEAKCK03qjfsuJ1vWQQJDiX7T4fKLlJwCfSsLm
>> sogklqRpUZIDW96kuMhQhOM=
>> =G0zE
>> -----END PGP SIGNATURE-----
>> _______________________________________________
>> Sequoia mailing list
>> [email protected]
>> https://forge.continuent.org/mailman/listinfo/sequoia
>
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.6 (GNU/Linux)
Comment: Using GnuPG with Mozilla - http://enigmail.mozdev.org
iD8DBQFJT1+gIo1XmbAXRboRAoD4AKCEhjqEEQl9oGgXeo0BV7+DyZ1MJACgtuJo
d8lNsJALov9vzutIpFl6Oo0=
=QP7g
-----END PGP SIGNATURE-----
begin:vcard
fn:Ruben Rubio
n:Rubio;Ruben
org:Rentalia Holidays S.L
adr;quoted-printable:;;Gran v=C3=ADa 31, 9=C2=BA-1=C2=BA;Madrid;;;Spain
email;internet:[email protected]
tel;work:+34915233104
url:http://www.rentalia.com
version:2.1
end:vcard
_______________________________________________
Sequoia mailing list
[email protected]
https://forge.continuent.org/mailman/listinfo/sequoia
