Hi Folks

I am using PSD 9.0.0.1600. I have noticed that every time I run a SQL query in a SQL Window, there is a long delay (about 8 seconds) before the query starts to run during which time "Initializing..." appears on the status line. This time is not included in the execution time.

Below is a small extract from a Debug.txt file I generated that illustrates the problem, and may hold the answer. You will notice that there is nothing between these 2 lines:

19-Jul-2011 18:04:01 InitStatistics ends
19-Jul-2011 18:04:09 NavigationBookmarks.EnableButtons(Rebuild)

So for those 8 seconds nothing is happening.

Any ideas?

Best regards

Billy


19-Jul-2011 18:04:01 SQLForm Initializing...
19-Jul-2011 18:04:01 SetConnected starts
19-Jul-2011 18:04:01 Already connected: check connection
19-Jul-2011 18:04:01 TOracleQuery $03711650 Start Query.Execute
SQL = select 'x' from dual
19-Jul-2011 18:04:01 TOracleQuery $03711650 End (1 record processed)
Duration = 0.015
19-Jul-2011 18:04:01 Using existing connection
19-Jul-2011 18:04:01 EnableOutput starts
19-Jul-2011 18:04:01 TOracleQuery PLSQLDevForm.EnableOutputQuery Start Query.Execute
SQL = begin
if :enable = 0 then
sys.dbms_output.disable;
else
sys.dbms_output.enable(:size);
end if;
end;
:ENABLE = 1
:SIZE = 100000
19-Jul-2011 18:04:01 TOracleQuery PLSQLDevForm.EnableOutputQuery End
Duration = 0
19-Jul-2011 18:04:01 EnableOutput done
19-Jul-2011 18:04:01 InitStatistics starts
19-Jul-2011 18:04:01 TOracleQuery $03711650 Start Query.Execute
SQL = select 'x' from dual
19-Jul-2011 18:04:01 TOracleQuery $03711650 End (1 record processed)
Duration = 0.015
19-Jul-2011 18:04:01 StartValues: StatQuery.ReadBuffer = 381
19-Jul-2011 18:04:01 StartValues: StatQuery.ReadBuffer set to 381
19-Jul-2011 18:04:01 TOracleQuery $03712410 Start Query.Execute
SQL = select value from v$sesstat where sid = :sid order by statistic#
:SID = 1034
19-Jul-2011 18:04:01 TOracleQuery $03712410 End (0 records processed)
Duration = 0.016
19-Jul-2011 18:04:01 InitStatistics ends
19-Jul-2011 18:04:09 NavigationBookmarks.EnableButtons(Rebuild)
19-Jul-2011 18:04:09 NavigationBookmarks: Backward=0, Forward=0
19-Jul-2011 18:04:09 Lock
19-Jul-2011 18:04:09 UnLock
19-Jul-2011 18:04:09 SQLForm Executing...
19-Jul-2011 18:04:09 Lock
19-Jul-2011 18:04:09 UnLock
19-Jul-2011 18:04:09 SQLForm Executing...
19-Jul-2011 18:04:09 TSQLThread SQLThread Suspend ended
19-Jul-2011 18:04:09 TOracleQuery Query Start Query.Execute
SQL = begin :id := sys.dbms_transaction.local_transaction_id; end;
:ID = Null
19-Jul-2011 18:04:09 TOracleQuery Query End
Duration = 0
19-Jul-2011 18:04:09 TOracleQuery $03711BD0 Start Query.Execute
SQL = SELECT * FROM tdif_file_stages WHERE fstg_fle_id=90539 ORDER BY fstg_id
19-Jul-2011 18:04:09 TOracleQuery $03711BD0 End (8 records processed)
Duration = 0.016
19-Jul-2011 18:04:09 TOracleQuery SQLForm_2.TestQuery Start Query.Describe
SQL = SELECT * FROM tdif_file_stages
19-Jul-2011 18:04:09 TOracleQuery SQLForm_2.TestQuery End
Duration = 0.016
19-Jul-2011 18:04:09 TOracleQuery Query Start Query.Execute
SQL = begin :id := sys.dbms_transaction.local_transaction_id; end;
:ID = Null
19-Jul-2011 18:04:09 TOracleQuery Query End
Duration = 0.016
19-Jul-2011 18:04:09 TSQLThread SQLThread Postmessage
19-Jul-2011 18:04:09 TSQLThread SQLThread Suspend
19-Jul-2011 18:04:09 TSQLForm.ThreadFinished
19-Jul-2011 18:04:09 TSQLForm.ThreadFinished: SQLThread.Suspended
19-Jul-2011 18:04:09 SQLForm 8 rows selected in 0.078 seconds
19-Jul-2011 18:04:09 Lock
19-Jul-2011 18:04:09 UnLock
19-Jul-2011 18:04:09 EndValues: StatQuery.ReadBuffer = 381
19-Jul-2011 18:04:09 EndValues: StatQuery.ReadBuffer set to 381
19-Jul-2011 18:04:09 TOracleQuery $03712410 Start Query.Execute
SQL = select value from v$sesstat where sid = :sid order by statistic#
:SID = 1034
19-Jul-2011 18:04:09 TOracleQuery $03712410 End (0 records processed)
Duration = 0.015
19-Jul-2011 18:04:09 NavigationBookmarks.EnableButtons(Rebuild)
19-Jul-2011 18:04:09 NavigationBookmarks: Backward=0, Forward=0
19-Jul-2011 18:04:09 TOracleQuery $037110D0 Start Query.Execute
SQL = begin
sys.dbms_output.get_line(line => :line, status => :status);
end;
:LINE = Null
:STATUS = Null
19-Jul-2011 18:04:09 TOracleQuery $037110D0 End
Duration = 0
19-Jul-2011 18:04:09 SQLForm 8 rows selected in 0.078 seconds

We'll check out what's happening between these 2 log entries.

Hi Marco

I should point out that this "initializing..." delay did not just appear in Release 9, it has been there for a few months in Release 8 although I could not tell you exactly when it appeared.

I also have tried using the free Oracle SQL Developer IDE against the same database and there is no delay in running SQL queries, so the problem appears to be with PL/SQL Developer.

Best regards

Billy

Okay, thanks for the info.

Hi Marco

Another update on this, because it is becoming more and more frustrating. I noticed that if I select the SQL to be executed and click the Execute button, there is no delay, so the 8 second delay seems to be related to the AutoSelect Statement functionality where PSD is trying to determine what SQL statement to execute.

Following on this train of thought, I noticed that if I open a new SQL window and put a single SELECT statement in it and execute, there is no delay. Thus the delay I have been noticing seems to be caused by the size of the SQL script file in which I am executing individual SQL commands - in my case this file is currently 14,722 lines long, as it is a project SQL file that I keep adding to as the project develops.

Is it possible to stop the AutoSelect functionality from caring about the size of the file in which it is being asked to autoselect a SQL statement?

Best regards

Billy

We have not yet been able to reproduce this, nor have we had any similar problem reports. We'll add some diagnostics and will send you a test version shortly.

Thanks Marco

Hi!

I have similar issue, not the same, but maybe related. I'm using the latest version 9.0.0.1601.

I have really annoying delay of approx 10 seconds when doing any query which has many columns. When I select a query and press execute it kind of executes the query, in the result list I can see how many rows will be selected (it seems plsqldev is reserving the place and shows only first column of grid with select button where I can select whole row), it shows executing and after 10 secs result appears on the screen, while it tries to show the results IDE is completely frozen. When I execute the same query again it shows results immediately, even if I change where clause it selects that instantly. I observed increased network traffic when this happens. That particular table has 244 columns.
It seems that there is a problem getting description for result set, I tried to switch off the "Display dictionary info in result set" and this doesn't help.
This is extremely annoying

There is a test case, I ran 2 queries:
1. select sysdate from dual;
2. SELECT * FROM ap_invoice_distributions_all t WHERE invoice_distribution_id IN (-1,-2)

I remember there was similar issue with betas as well. Please fix this fast as there is no workaround this time

regards
Kirurgs

Hi!

Additional info.
I enabled DebugSQL as well and I see where the problem is. In debug.txt there is this kind of text repeated for 489 times after I run second query:

I think that's the cause. Please investigate and thank You in advance.

P.S. I can send You debug.txt as well, please post an address or site where to upload.

regards
Kirurgs

You can send it to support@allroundautomations.com. It may help if you mention this topic in your message.

Regards,
Gustavo

Hi!

Thank You for info, file sent, hope Marco will look at it soon.

regards
Kirurgs

Hi Marco

I ran some experiments here and am easily able to recreate the problem.

Open a new SQL Window, and enter this 10 line SELECT:

SELECT owner
,NAME
,TYPE
,line
,text
FROM user_source
ORDER BY owner
,NAME
,TYPE
,line;

Copy this and paste 100 times to make 1000 lines of code. Then make a new line and type another command, say

SELECT SYSDATE FROM DUAL;

Select the first 1000 lines, copy and paste 9 times to make 10000 lines before the SYSDATE command above. Then position the cursor in the SYSDATE command above (ensure you have auto select turned on) and hit the execute - you should notice a delay with "Initialising..." displayed on the status line, during which the application is locked.

Note that I tried with just 10000 blank lines, and with 10000 non-SQL lines, and the delay does not happen. So it is related to the application trying to parse the SQL command to be run from other SQL in the Window. Also, the more SQL command lines I add before the SYSDATE command, the longer the delay.

It must be said here that I am running the software on an old Dell Optiplex GS620 under Windows 2000 Professional, and perhaps with a more modern PC with faster processor/OS/more memory etc. there may not be much of a delay, or you may have to add a lot more SQL commands before the SYSDATE command until you see the delay.

If you need any more details, let me know.

Best regards

Billy

There is indeed a 1 second delay on my PC for this 10,000 line script. Do others also experience this delay for large scripts?

Hi!

I tried with 1000 lines, virtually no delay, with 10K it was about one sec as Marco said.
I have 2.5GHz laptop usually running on 800MHz, when I select that and press execute it will speed up to 2.5.

Marco have You had a chance looking into my issue?

regards
Kirurgs

Hi!

Marco have You had a chance looking into issue I'm facing?

Yes, but we have not yet been able to find a cause for the issue. We are still looking into this.

Hi!

Is there anything I can help, like providing any additional debug info to you?

We'll probably have a test version shortly with some additional diagnostic information to pinpoint the cause of the problem. If you could run this test for us that would be great.

Hi!

Very good, please send me the link/file, I'll gladly provide any debug info.

regards
Kirurgs

Ditto for me.

Best regards

Billy

Can you guys try this version with the DebugSQL option as before? It contains some extra diagnostics. Please send me a new debug.txt for any query performance related issues.

The issue with the excessive number of v$nls_parameter queries is already fixed in this version, so that should already help in some cases.

Hi Marco

I just emailed the Debug.txt file to support@allroundautomations.com.

The 8 second delay is still there, and I believe it is between lines 1695 and 1696 i.e.:

23-Aug-2011 12:56:07 CreateQueryTabs Finding SQL
23-Aug-2011 12:56:15 CreateQueryTabs SQL Found

So it looks like the delay is when it is trying to figure out which SQL to execute.

If you need anything else, let me know.

Best regards

Billy

Thanks. We have all we need to fix this.

Hi!

I ran queries and they are still slow. Now there are no excessive nls thing. I have run the same in ver 8 and 9, in 8 result is instant, but in 9 it takes 5 secs now.
Now it seems that it's executing dictionary info SQL, I have set that off in preferences. Maybe this is the cause.
I sent debug to support mailbox.
Please check.

thanks in advance
Kirurgs

Thanks, we have received it. We'll try to reproduce and optimize this.

This version should fix the query performance issue and AutoSelect SQL performance issue for large scripts.

Hi!

I have tested it and now it seems that result is instant, if dictionary info is checked it's still slow, but I think that's expected. So in short - problem fixed.
BUT for some strange reason now plsqldev.exe process eats whole cpu all the time after connection is made, cpu usage varies from 65% to 99%.

regards
Kirurgs

I am having the exact problem. When using version 9 and connecting, it runs this query even though I have selected to use DBA_views where available. This sorted the same issue in version 8, but does not seem to work in version 9.
The query is this:
select s.synonym_name as object_name, o.object_type
from all_synonyms s, sys.all_objects o
where s.owner in ('PUBLIC', :schema)
and o.owner = s.table_owner
and o.object_name = s.table_name
and o.object_type in ('TABLE', 'VIEW', 'PACKAGE','TYPE', 'PROCEDURE', 'FUNCTION', 'SEQUENCE');

We are on 11gR1. Due to this we are not installing version 9 since the CPU is so high and will bring our environments down due to the amount of users we have.

[quote=Kirurgs]BUT for some strange reason now plsqldev.exe process eats whole cpu all the time after connection is made, cpu usage varies from 65% to 99%.[/quote]

Does the CPU usage go down eventually?

Can you test what happens if you go to Tools > Preferences > Code Assistant and disable the "Describe Context" option? Does this clear the CPU usage after a restart?

[quote=lparker]I am having the exact problem. When using version 9 and connecting, it runs this query even though I have selected to use DBA_views where available. This sorted the same issue in version 8, but does not seem to work in version 9.
The query is this:
select s.synonym_name as object_name, o.object_type
from all_synonyms s, sys.all_objects o
where s.owner in ('PUBLIC', :schema)
and o.owner = s.table_owner
and o.object_name = s.table_name
and o.object_type in ('TABLE', 'VIEW', 'PACKAGE','TYPE', 'PROCEDURE', 'FUNCTION', 'SEQUENCE');

We are on 11gR1. Due to this we are not installing version 9 since the CPU is so high and will bring our environments down due to the amount of users we have. [/quote]
You can change or remove these queries by editing the CANames.sql file in the PL/SQL Developer installation directory. The file includes a description.

[quote=Marco Kalter][quote=Kirurgs]BUT for some strange reason now plsqldev.exe process eats whole cpu all the time after connection is made, cpu usage varies from 65% to 99%.[/quote]

Does the CPU usage go down eventually?

Can you test what happens if you go to Tools > Preferences > Code Assistant and disable the "Describe Context" option? Does this clear the CPU usage after a restart? [/quote]

Hi!

I'm on vacation so I check this very rare.
CPU won't go down, it starts even when there are no windows opened at all, just plain PLSQLDev. I went to check sessions and no query is running.
That check box didn't help either.

Hi!

v9.0.1 (1613) have the same CPU usage bug. I still see no queries being performed while CPU usage is high.
DB ver. is 11gR2.

Edit: In 9.0.1 CPU went down after under 5 mins (approx 3-4). Do You have clue why is that?

I'm not sure why this would happen and we cannot reproduce this.

Does the CPU usage go up again when you connect to a different database after the CPU usage goes down?

Hi!

I think I understood where the problem is
See, we are working with Oracle eBusiness Suite which is really large product of Oracle, I took statements from CANames and executed them with the schema I logged in (APPS), results are: objects (1st stmnt) ~ 80000, synonyms (2nd stmnt) ~ 50000, links (3rd stmnt) = 7.
It seems that PLSQLDev tries cache them all and do smth with them and uses a lot of CPU then. I added 1=2 to the statements and no excessive CPU usage anymore but code assistant didn't work.
It seems that in v8 code assistant was querying stuff on-demand but now it tries to cache it...
Is there a setting which reverts to old behavior or setting which prevents caching all of the stuff at once?

regards
Kirurgs

We'll check it out. Maybe there is something we can do to improve this.

Can you try this version and let me know if the CPU usage is reduced?

Hi!

I have tried it and it is a lot better now.
However, when I'm trying to use code assistant on tables which are used via synonyms they don't appear to be visible for some time, after couple of mins after logging in they are, but not right away as those who are in the current schema.

Personally me, I can live with that, but if You can improve this, it would be nice.

My guess would be that querying the synonyms is slow. You can verify this be running or modifying the CANames.sql file in the PL/SQL Developer directory.