Re: get time end of a process can capture(Stored Procedure)
Date: Tue, 19 Aug 2008 11:44:18 -0700 (PDT)
Message-ID: <b7827c01-51b3-4743-a1a5-fe8559c26c95@2g2000hsn.googlegroups.com>
On Aug 19, 11:18 am, EliasFigueroa <Eliasf..._at_gmail.com> wrote:
> As I get time end of a process
> can capture? cpu time consumed (%)
> find time elapsed (Oracle 8i)
> I have this SP ,I catch the same time
> Thank you
>
> CREATE OR REPLACE PROCEDURE SPG_EXAMPLE
> ( p_fecha IN VARCHAR2,
> p_descripcion OUT VARCHAR2,
> p_estado OUT NUMBER,
> P_registros OUT NUMBER,
> p_message OUT VARCHAR2,
> p_inicio OUT DATE
> p_fin OUT DATE
>
> )
> IS
> TYPE T_numero IS TABLE OF AGENCIAS.NUMERO%type;
> TYPE T_indicador IS TABLE OF AGENCIAS.INDICADOR%type;
> v_numero T_numero;
> v_indicador T_indicador;
> ld_inicio DATE;
> ld_fin DATE;
> ld_diff DATE;
> lv_SQL2 VARCHAR2(2000);
> lv_Count NUMBER;
> v_errornumber CHAR(10);
> v_errortext CHAR(100);
> v_descripción VARCHAR2(2000) :='CARGA AGENCIAS';
> BEGIN
> ld_inicio := sysdate;===> STARTTIME
> p_inicio := ld_inicio;
> p_estado:= 0;
> p_message:='';
> p_descripcion:=v_descripción;
> lv_SQL2:='select count(ROWID) from agencias2 ' ;
>
> select numero,indicador
>
> BULK COLLECT INTO v_numero ,v_indicador
> FROM agencias;
>
> FORALL i IN v_numero.FIRST..v_numero.LAST
> INSERT INTO agencias2
> (numero, indicador,
> usuariocreacion, fechacreacion,
> usuarioactualizacion, fechaactualizacion)
>
> VALUES( v_numero(i) ,v_indicador(i),'PRUEBA',SYSDATE,'PRUEBA',SYSDATE);
> COMMIT;
> p_estado := 1;
>
> EXECUTE IMMEDIATE lv_SQL2 INTO lv_Count;
> P_registros:=lv_Count;
> p_message:=('Se Insertaron un Total de :'|| lv_Count||'
> Registros');
> ld_fin := sysdate; --- end time
>
> EXCEPTION
> WHEN others THEN
> ROLLBACK;
> v_errornumber := SQLCODE;
> v_errortext := substr(SQLERRM,1,100);
> Raise_application_error(-20002, 'Error al insertar:' ||
> v_errornumber || v_errortext);
> END SPGT147_CARGAAGENCIAS;
You're collecting elapsed time, not CPU time, for this procedure, and
they can be, and most likely will be, different. Out of 100 seconds
of elapsed time you may have spent 2 seconds actually using the CPU
to do work. If you're licensed to use the Automatic Workload
Repository you can query the AWR tables/views and possibly return the
actual (or estimated) CPU time for a given session; taking 'readings'
at the start and at the end of your procedure thenn computing the
difference would give you a rough estimate of the actual CPU time
consumed, which will probably be much less than the total elapsed time
you're computing now.
You could query V$SESSTAT for 'CPU used by this session' at the start and end of your processing, compute the difference and divide by 100 to get seconds of CPU time consumed, but this will only give you a rough estimate as the value is updated for each interval of 10 milliseconds. An example is shown below:
SQL> declare
2 usid number; 3 cpu_elapsed number; 4 cpu_start number; 5 cpu_end number; 6 start_time date; 7 end_time date; 8 x number; 9 begin 10 start_time := sysdate; 11 select value*10 12 into cpu_start 13 from v$sesstat s, v$statname n 14 where s.statistic# = n.statistic# 15 and n.name = 'CPU used by this session' 16 and sid = (select sid from v$session wheresys_context('USERENV','SESSIONID') = audsid); 17
18 for i in 0..255 loop
19 dbms_output.put_line('Code '||i||' = '||chr(i));
20 for j in 1..50 loop
21 x:=i*j*i*j;
22 end loop;
23 dbms_lock.sleep(1);
24 end loop;
25
26 end_time := sysdate;
27 select value*10
28 into cpu_end
29 from v$sesstat s, v$statname n
30 where s.statistic# = n.statistic#
31 and n.name = 'CPU used by this session'
32 and sid = (select sid from v$session where
sys_context('USERENV','SESSIONID') = audsid);
33
34 cpu_elapsed := (cpu_end - cpu_start)/1000.0000000; 35
36 dbms_output.put_line('Start CPU for this block: '|| cpu_start||' milliseconds');
37 dbms_output.put_line('End CPU for this block: '|| cpu_end||' milliseconds');
38 dbms_output.put_line('Elapsed CPU for this block: '|| cpu_elapsed||' seconds');
39 dbms_output.put_line('Elapsed time for this block: '||
(end_time-start_time)*86400||' seconds');
40 dbms_output.put_line('CPU percent for this block: '||
(cpu_elapsed/((end_time-start_time)*86400))*100);
41
42 end;
43 /
Code 0 = Code 1 = Code 2 = Code 3 = Code 4 = Code 5 = Code 6 = Code 7 = Code 8 = Code 9 =
Code 10 =
Code 11 = Code 12 = Code 13 = Code 14 = Code 15 = Code 16 = Code 17 = Code 18 = Code 19 = Code 20 = Code 21 = Code 22 = Code 23 = Code 24 = Code 25 = Code 26 = Code 27 = Code 28 = Code 29 = Code 30 = Code 31 = Code 32 = Code 33 = ! Code 34 = " Code 35 = # Code 36 = $ Code 37 = % Code 38 = & Code 39 = ' Code 40 = ( Code 41 = ) Code 42 = * Code 43 = + Code 44 = , Code 45 = - Code 46 = . Code 47 = / Code 48 = 0 Code 49 = 1 Code 50 = 2 Code 51 = 3 Code 52 = 4 Code 53 = 5 Code 54 = 6 Code 55 = 7 Code 56 = 8 Code 57 = 9 Code 58 = : Code 59 = ; Code 60 = < Code 61 = = Code 62 = > Code 63 = ? Code 64 = @ Code 65 = A Code 66 = B Code 67 = C Code 68 = D Code 69 = E Code 70 = F Code 71 = G Code 72 = H Code 73 = I Code 74 = J Code 75 = K Code 76 = L Code 77 = M Code 78 = N Code 79 = O Code 80 = P Code 81 = Q Code 82 = R Code 83 = S Code 84 = T Code 85 = U Code 86 = V Code 87 = W Code 88 = X Code 89 = Y Code 90 = Z Code 91 = [ Code 92 = \ Code 93 = ] Code 94 = ^ Code 95 = _ Code 96 = ` Code 97 = a
Code 98 = b
Code 99 = c
Code 100 = d
Code 101 = e
Code 102 = f
Code 103 = g
Code 104 = h
Code 105 = i
Code 106 = j
Code 107 = k
Code 108 = l
Code 109 = m
Code 110 = n
Code 111 = o
Code 112 = p
Code 113 = q
Code 114 = r
Code 115 = s
Code 116 = t
Code 117 = u
Code 118 = v
Code 119 = w
Code 120 = x
Code 121 = y
Code 122 = z
Code 123 = {
Code 124 = |
Code 125 = }
Code 126 = ~
Code 127 =
Code 128 = ¿
Code 129 =
Code 130 = ¿
Code 131 = ¿
Code 132 = ¿
Code 133 = ¿
Code 134 = ¿
Code 135 = ¿
Code 136 = ¿
Code 137 = ¿
Code 138 = ¿
Code 139 = ¿
Code 140 = ¿
Code 141 =
Code 142 = ¿
Code 143 =
Code 144 =
Code 145 = ¿
Code 146 = ¿
Code 147 = ¿
Code 148 = ¿
Code 149 = ¿
Code 150 = ¿
Code 151 = ¿
Code 152 = ¿
Code 153 = ¿
Code 154 = ¿
Code 155 = ¿
Code 156 = ¿
Code 157 =
Code 158 = ¿
Code 159 = ¿
Code 160 =
Code 161 = ¡
Code 162 = ¢
Code 163 = £
Code 164 = ¤
Code 165 = ¥
Code 166 = ¦
Code 167 = §
Code 168 = ¨
Code 169 = ©
Code 170 = ª
Code 171 = «
Code 172 = ¬
Code 173 =
Code 174 = ®
Code 175 = ¯
Code 176 = °
Code 177 = ±
Code 178 = ²
Code 179 = ³
Code 180 = ´
Code 181 = µ
Code 182 = ¶
Code 183 = ·
Code 184 = ¸
Code 185 = ¹
Code 186 = º
Code 187 = »
Code 188 = ¼
Code 189 = ½
Code 190 = ¾
Code 191 = ¿
Code 192 = À
Code 193 = Á
Code 194 = Â
Code 195 = Ã
Code 196 = Ä
Code 197 = Å
Code 198 = Æ
Code 199 = Ç
Code 200 = È
Code 201 = É
Code 202 = Ê
Code 203 = Ë
Code 204 = Ì
Code 205 = Í
Code 206 = Î
Code 207 = Ï
Code 208 = Ð
Code 209 = Ñ
Code 210 = Ò
Code 211 = Ó
Code 212 = Ô
Code 213 = Õ
Code 214 = Ö
Code 215 = ×
Code 216 = Ø
Code 217 = Ù
Code 218 = Ú
Code 219 = Û
Code 220 = Ü
Code 221 = Ý
Code 222 = Þ
Code 223 = ß
Code 224 = à
Code 225 = á
Code 226 = â
Code 227 = ã
Code 228 = ä
Code 229 = å
Code 230 = æ
Code 231 = ç
Code 232 = è
Code 233 = é
Code 234 = ê
Code 235 = ë
Code 236 = ì
Code 237 = í
Code 238 = î
Code 239 = ï
Code 240 = ð
Code 241 = ñ
Code 242 = ò
Code 243 = ó
Code 244 = ô
Code 245 = õ
Code 246 = ö
Code 247 = ÷
Code 248 = ø
Code 249 = ù
Code 250 = ú
Code 251 = û
Code 252 = ü
Code 253 = ý
Code 254 = þ
Code 255 = ÿ
Start CPU for this block: 90 milliseconds End CPU for this block: 130 milliseconds Elapsed CPU for this block: .04 seconds
Elapsed time for this block: 256 seconds CPU percent for this block: .015625
PL/SQL procedure successfully completed.
SQL> David Fitzjarrell Received on Tue Aug 19 2008 - 13:44:18 CDT