If you were logged in you would be able to see more operations.
|
|
|
Product Version: |
Oracle 10g 10.2.0.4
|
Operating System: |
Windows
|
Operating System Version: |
2003
|
The customer encountered slow performance while navigating on their forms items. The problem occured sporadically. When it occurs it takes 3-4 seconds, which are not acceptable.
An excerpt from EVENT 10046 trace file:
*** [ Windows thread id: 5580 ]
*** 2008-11-24 21:27:20.390
RPC CALL:...(stament removed);
=====================
PARSING IN CURSOR #5 len=56 dep=1 uid=78 oct=3 lid=78 tim=1420397928
hv=3822139714 ad='57c1a3bc'
SELECT ...(stament removed)
END OF STMT
PARSE #5:c=0,e=32,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,tim=1420397924
EXEC #5:c=0,e=31,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,tim=1420398028
FETCH #5:c=0,e=14,p=0,cr=1,cu=0,mis=0,r=0,dep=1,og=1,tim=1420398156
RPC EXEC:c=0,e=0
WAIT #0: nam='SQL*Net message to client' ela= 4 driver id=1297371904
#bytes=1 p3=0 obj#=-1 tim=1420398646
*** 2008-11-24 21:27:20.765
WAIT #0: nam='SQL*Net message from client' ela= 3 driver id=1297371904
#bytes=1 p3=0 obj#=-1 tim=1420772565
RPC CALL:...(stament removed);
EXEC #5:c=0,e=38,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,tim=1420773632
FETCH #5:c=0,e=14,p=0,cr=1,cu=0,mis=0,r=0,dep=1,og=1,tim=1420773671
RPC EXEC:c=0,e=0
WAIT #0: nam='SQL*Net message to client' ela= 5 driver id=1297371904
#bytes=1 p3=0 obj#=-1 tim=1420774146
*** [ Windows thread id: 4416 ]
*** 2008-11-24 21:27:24.765
WAIT #0: nam='SQL*Net message from client' ela= 6 driver id=1297371904
#bytes=1 p3=0 obj#=-1 tim=1424766291
RPC CALL:...(stament removed);
=====================
PARSING IN CURSOR #7 len=70 dep=1 uid=78 oct=3 lid=78 tim=1424767161
hv=2516830579 ad='5af8ae9c'
SELECT ...(stament removed)
END OF STMT
PARSE #7:c=0,e=78,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,tim=1424767156
EXEC #7:c=0,e=59,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,tim=1424767987
FETCH #7:c=0,e=94,p=0,cr=3,cu=0,mis=0,r=1,dep=1,og=1,tim=1424768238
RPC EXEC:c=0,e=0
WAIT #0: nam='SQL*Net message to client' ela= 7 driver id=1297371904
#bytes=1 p3=0 obj#=-1 tim=1424768583
PUT: vc (659FD948), msg (5CF1D5B0), size (90), flgs (3)
*** [ Windows thread id: 5580 ]
*** 2008-11-24 21:27:24.765
WAIT #0: nam='SQL*Net message from client' ela= 4 driver id=1297371904
#bytes=1 p3=0 obj#=-1 tim=1424771121
RPC CALL:...(stament removed);
=====================
PARSING IN CURSOR #8 len=90 dep=1 uid=78 oct=3 lid=78 tim=1424772412
hv=1036237733 ad='5d1575f0'
SELECT ...(stament removed)
END OF STMT
PARSE #8:c=0,e=56,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,tim=1424772407
EXEC #8:c=0,e=55,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,tim=1424772567
FETCH #8:c=0,e=14,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,tim=1424772608
RPC EXEC:c=0,e=0
WAIT #0: nam='SQL*Net message to client' ela= 6 driver id=1297371904
#bytes=4 p3=0 obj#=-1 tim=1424773339
|
Description
|
The customer encountered slow performance while navigating on their forms items. The problem occured sporadically. When it occurs it takes 3-4 seconds, which are not acceptable.
An excerpt from EVENT 10046 trace file:
*** [ Windows thread id: 5580 ]
*** 2008-11-24 21:27:20.390
RPC CALL:...(stament removed);
=====================
PARSING IN CURSOR #5 len=56 dep=1 uid=78 oct=3 lid=78 tim=1420397928
hv=3822139714 ad='57c1a3bc'
SELECT ...(stament removed)
END OF STMT
PARSE #5:c=0,e=32,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,tim=1420397924
EXEC #5:c=0,e=31,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,tim=1420398028
FETCH #5:c=0,e=14,p=0,cr=1,cu=0,mis=0,r=0,dep=1,og=1,tim=1420398156
RPC EXEC:c=0,e=0
WAIT #0: nam='SQL*Net message to client' ela= 4 driver id=1297371904
#bytes=1 p3=0 obj#=-1 tim=1420398646
*** 2008-11-24 21:27:20.765
WAIT #0: nam='SQL*Net message from client' ela= 3 driver id=1297371904
#bytes=1 p3=0 obj#=-1 tim=1420772565
RPC CALL:...(stament removed);
EXEC #5:c=0,e=38,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,tim=1420773632
FETCH #5:c=0,e=14,p=0,cr=1,cu=0,mis=0,r=0,dep=1,og=1,tim=1420773671
RPC EXEC:c=0,e=0
WAIT #0: nam='SQL*Net message to client' ela= 5 driver id=1297371904
#bytes=1 p3=0 obj#=-1 tim=1420774146
*** [ Windows thread id: 4416 ]
*** 2008-11-24 21:27:24.765
WAIT #0: nam='SQL*Net message from client' ela= 6 driver id=1297371904
#bytes=1 p3=0 obj#=-1 tim=1424766291
RPC CALL:...(stament removed);
=====================
PARSING IN CURSOR #7 len=70 dep=1 uid=78 oct=3 lid=78 tim=1424767161
hv=2516830579 ad='5af8ae9c'
SELECT ...(stament removed)
END OF STMT
PARSE #7:c=0,e=78,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,tim=1424767156
EXEC #7:c=0,e=59,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,tim=1424767987
FETCH #7:c=0,e=94,p=0,cr=3,cu=0,mis=0,r=1,dep=1,og=1,tim=1424768238
RPC EXEC:c=0,e=0
WAIT #0: nam='SQL*Net message to client' ela= 7 driver id=1297371904
#bytes=1 p3=0 obj#=-1 tim=1424768583
PUT: vc (659FD948), msg (5CF1D5B0), size (90), flgs (3)
*** [ Windows thread id: 5580 ]
*** 2008-11-24 21:27:24.765
WAIT #0: nam='SQL*Net message from client' ela= 4 driver id=1297371904
#bytes=1 p3=0 obj#=-1 tim=1424771121
RPC CALL:...(stament removed);
=====================
PARSING IN CURSOR #8 len=90 dep=1 uid=78 oct=3 lid=78 tim=1424772412
hv=1036237733 ad='5d1575f0'
SELECT ...(stament removed)
END OF STMT
PARSE #8:c=0,e=56,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,tim=1424772407
EXEC #8:c=0,e=55,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,tim=1424772567
FETCH #8:c=0,e=14,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,tim=1424772608
RPC EXEC:c=0,e=0
WAIT #0: nam='SQL*Net message to client' ela= 6 driver id=1297371904
#bytes=4 p3=0 obj#=-1 tim=1424773339
|
Show » |
|
As seen from the excerpt above, the windows thread ID had switched to 4416.
elapsed time: (tim=1424766291) - (tim=1420774146) = 3992145 microseconds = 3.992145 seconds.
The customer has SHARED SERVER configuration. But, SHARED_SERVERS parameter was set to 1. Unfortunately, we had not got an opportunity to debug SHARED SERVER operations. But, increasing SHARED_SERVERS parameter has solved this thread switch problem since there are now pre-created SHARED SERVERS.