Forums Active Threads
Print Thread
Page 2 of 2 1 2
Re: Cpu Utilisation at 100% on compile
misko #54185 11/13/16 01:31 PM
Joined: Feb 2013
Posts: 46
P
Pazus Offline
Member
Offline
Pazus
Member
P
Joined: Feb 2013
Posts: 46
Marco, if you remember this post the simptoms sounds familiar.
https://forums.allroundautomations....mp;Main=13799&Number=54118#Post54118

It seems like the content of the compiled object is "hiddenly" printed to somewhere, don't know how to say that. It's like you have ECHO enabled but directed not into the command window but somewhere else.

Pavel Kaplya
Re: Cpu Utilisation at 100% on compile
Pazus #54186 11/13/16 01:46 PM
Joined: Feb 2013
Posts: 46
P
Pazus Offline
Member
Offline
Pazus
Member
P
Joined: Feb 2013
Posts: 46
I have reproduced the problem with debugsql flag.

package: 1700:8900 lines spec:body.

Timing is enabled and reports 0.144 and 0.659 sec correspondingly
Real time spent is about 23 secs for spec+body.

The problem is that PL/SQL developer tries to interpret each line of the package:


00:02:56.325 InterpretLine starts: CREATE OR REPLACE PACKAGE BODY pkg_policy IS
00:02:56.326 InterpretLine ends
00:02:56.326 InterpretLine starts:
00:02:56.327 InterpretLine ends
00:02:56.327 InterpretLine starts: p_debug BOOLEAN := FALSE;
00:02:56.328 InterpretLine ends
00:02:56.329 InterpretLine starts:
00:02:56.329 InterpretLine ends
00:02:56.330 InterpretLine starts: /*
00:02:56.330 InterpretLine ends
00:02:56.331 InterpretLine starts: Байтин А.
00:02:56.331 InterpretLine ends
00:02:56.332 InterpretLine starts: Чтобы не было лишних commit'ов обернул процедуры
00:02:56.333 InterpretLine ends
00:02:56.333 InterpretLine starts: */
00:02:56.334 InterpretLine ends
00:02:56.334 InterpretLine starts:
00:02:56.335 InterpretLine ends
00:02:56.335 InterpretLine starts: PROCEDURE cover_log_autonomous
00:02:56.336 InterpretLine ends
00:02:56.336 InterpretLine starts: (
00:02:56.337 InterpretLine ends
00:02:56.337 InterpretLine starts: p_p_cover_id IN NUMBER
00:02:56.338 InterpretLine ends
00:02:56.339 InterpretLine starts: ,p_message IN VARCHAR2
00:02:56.339 InterpretLine ends
00:02:56.340 InterpretLine starts: ) IS
00:02:56.341 InterpretLine ends
00:02:56.342 InterpretLine starts: PRAGMA AUTONOMOUS_TRANSACTION;
00:02:56.343 InterpretLine ends
00:02:56.344 InterpretLine starts: BEGIN
00:02:56.344 InterpretLine ends
00:02:56.345 InterpretLine starts: INSERT INTO p_cover_debug
00:02:56.345 InterpretLine ends
00:02:56.346 InterpretLine starts: (p_cover_id, execution_date, operation_type, debug_message)
00:02:56.347 InterpretLine ends
00:02:56.347 InterpretLine starts: VALUES
00:02:56.348 InterpretLine ends
00:02:56.348 InterpretLine starts: (p_p_cover_id, SYSDATE, 'INS.PKG_POLICY', substr(p_message, 1, 4000));
00:02:56.349 InterpretLine ends
00:02:56.349 InterpretLine starts: COMMIT;
00:02:56.350 InterpretLine ends
.......
......
00:03:17.448 InterpretLine starts: AND pph.policy_id = pph.max_uncancelled_policy_id);
00:03:17.453 InterpretLine ends
00:03:17.453 InterpretLine starts: RETURN v_count = 1;
00:03:17.457 InterpretLine ends
00:03:17.457 InterpretLine starts: END is_active_and_last_version;
00:03:17.462 InterpretLine ends
00:03:17.462 InterpretLine starts:
00:03:17.466 InterpretLine ends
00:03:17.467 InterpretLine starts: END pkg_policy;
00:03:17.471 InterpretLine ends
00:03:17.471 InterpretLine starts: /
00:03:17.484 SetConnected starts
00:03:17.484 Already connected: check connection
00:03:17.485 TOracleQuery $0CA4C020 Start Query.Execute
SQL = select 'x' from dual
00:03:17.496 TOracleQuery $0CA4C020 End (1 record processed)
Duration = 0,016
00:03:17.496 Using existing connection
00:03:17.504 Lock
00:03:17.504 UnLock
00:03:17.505 NavigationBookmarks.EnableButtons(Rebuild)
00:03:17.505 NavigationBookmarks: Backward=2, Forward=0
00:03:17.505 WindowAllowed(3)
00:03:17.506 WindowAllowed done
00:03:17.506 WindowAllowed(1)
00:03:17.506 WindowAllowed done
00:03:17.506 WindowAllowed(2)
00:03:17.507 WindowAllowed done
00:03:17.507 WindowAllowed(6)
00:03:17.507 WindowAllowed done
00:03:17.507 WindowAllowed(5)
00:03:17.507 WindowAllowed done
00:03:17.509 Lock
00:03:17.509 UnLock
00:03:17.519 RSQLThread.Resume
00:03:17.520 TSQLThread SQLThread Suspend ended
00:03:17.520 TSQLThread SQLThread runs
00:03:17.520 TSQLThread SQLThread loop start
00:03:17.521 InterpretLine ends
00:03:17.521 TOracleQuery Query Start Query.Execute
SQL = begin :id := sys.dbms_transaction.local_transaction_id; end;
:ID = Null
00:03:17.526 TOracleQuery Query End
Duration = 0,015
00:03:17.529 TOracleQuery CommandForm.Query Start Query.Execute
SQL = CREATE OR REPLACE PACKAGE BODY pkg_policy IS

p_debug BOOLEAN := FALSE;

/*
Байтин А.
Чтобы не было лишних commit'ов обернул процедуры
*/

PROCEDURE cover_log_autonomous
(
p_p_cover_id IN NUMBER
,p_message IN VARCHAR2
) IS
PRAGMA AUTONOMOUS_TRANSACTION;
BEGIN
INSERT INTO p_cover_debug
(p_cover_id, execution_date, operation_type, debug_message)
VALUES
(p_p_cover_id, SYSDATE, 'INS.PKG_POLICY', substr(p_message, 1, 4000));
COMMIT;
...........
...........
FUNCTION is_active_and_last_version(par_policy_id p_policy.policy_id%TYPE) RETURN BOOLEAN IS
v_count NUMBER;
BEGIN
SELECT COUNT(*)
INTO v_count
FROM dual
WHERE EXISTS (SELECT NULL
FROM p_pol_header pph
WHERE pph.policy_id = par_policy_id
AND pph.policy_id = pph.max_uncancelled_policy_id);
RETURN v_count = 1;
END is_active_and_last_version;

END pkg_policy;
00:03:18.145 TOracleQuery CommandForm.Query End
Duration = 0,594
00:03:18.146 TSQLThread SQLThread loop end
00:03:18.146 TSQLThread SQLThread loop done
00:03:18.146 TSQLThread SQLThread transaction management done
00:03:18.146 TSQLThread SQLThread Postmessage
00:03:18.147 TSQLThread SQLThread Suspend
00:03:18.147 Waiting for Suspension
00:03:18.147 Done waiting for Suspension
00:03:18.156 Lock
00:03:18.158 UnLock
00:03:18.158 NavigationBookmarks.EnableButtons(Rebuild)
00:03:18.158 NavigationBookmarks: Backward=2, Forward=0
00:03:18.159 WindowAllowed(3)
00:03:18.159 WindowAllowed done
00:03:18.159 WindowAllowed(1)
00:03:18.159 WindowAllowed done
00:03:18.160 WindowAllowed(2)
00:03:18.160 WindowAllowed done
00:03:18.160 WindowAllowed(6)
00:03:18.160 WindowAllowed done
00:03:18.161 WindowAllowed(5)
00:03:18.161 WindowAllowed done
00:03:18.163 InterpretLine starts:
00:03:18.164 InterpretLine starts:
00:03:18.168 Lock
00:03:18.168 UnLock
00:03:18.169 Lock
00:03:18.170 UnLock
00:03:18.170 TOracleQuery Query Start Query.Execute
SQL = begin :id := sys.dbms_transaction.local_transaction_id; end;
:ID = Null
00:03:18.176 TOracleQuery Query End
Duration = 0
00:03:18.176 Lock
00:03:18.177 UnLock
00:03:18.177 UpdateConnectionsChildList start
00:03:18.178 UpdateConnectionsChildList ConnectionFolders.Count = 6
00:03:18.178 UpdateConnectionsChildList CheckList.Count = 6
00:03:18.179 UpdateConnectionsChildList RemoveList.Count = 0
00:03:18.179 UpdateConnectionsChildList EndUpdate
00:03:18.180 UpdateConnectionsChildList end
00:03:18.180 NavigationBookmarks.EnableButtons(Rebuild)
00:03:18.180 NavigationBookmarks: Backward=2, Forward=0
00:03:18.181 WindowAllowed(3)
00:03:18.181 WindowAllowed done
00:03:18.181 WindowAllowed(1)
00:03:18.182 WindowAllowed done
00:03:18.182 WindowAllowed(2)
00:03:18.182 WindowAllowed done
00:03:18.182 WindowAllowed(6)
00:03:18.182 WindowAllowed done
00:03:18.183 WindowAllowed(5)
00:03:18.183 WindowAllowed done

Notice the time difference.


Pavel Kaplya
Re: Cpu Utilisation at 100% on compile
Pazus #55307 01/09/17 05:06 PM
Joined: Feb 2013
Posts: 46
P
Pazus Offline
Member
Offline
Pazus
Member
P
Joined: Feb 2013
Posts: 46
Marco?

Pavel Kaplya
Re: Cpu Utilisation at 100% on compile
Pazus #55308 01/09/17 05:09 PM
Joined: Feb 2013
Posts: 46
P
Pazus Offline
Member
Offline
Pazus
Member
P
Joined: Feb 2013
Posts: 46
I'm working on a framework evailable on github here: https://github.com/utPLSQL/utPLSQL/tree/version3

If you install it and run tests/RunAll.sql script using command windows in takes more then 2 minutes, but with sqlplus about 6 second.

The source of the problem is the same - line by line parsing performance.

Pavel Kaplya
Page 2 of 2 1 2

Moderated by  support 

Link Copied to Clipboard
Privacy Policy · Forum Rules · Mark All Read Contact Us · Forum Help ·
Powered by UBB.threads™ PHP Forum Software 7.7.4
(Release build 20200307)
Responsive Width:

PHP: 7.1.33 Page Time: 0.035s Queries: 15 (0.011s) Memory: 2.5532 MB (Peak: 3.0394 MB) Data Comp: Off Server Time: 2024-06-17 05:15:10 UTC
Valid HTML 5 and Valid CSS