blogs.conus.info

Oracle SPY
-- Dennis Yurichev <dennis(@)conus.info> http://blogs.conus.info

This is win32 utility which intercepts internal Oracle RDBMS function calls to rpisplu(), kprbprs(), opiprs() and OCIStmtPrepare() - all these 4 functions used in internal SQL processing. All they are actually "parse" command from different RDBMS layers.

Thereby, this utility allow us to see all (As I know) internal SQL executions.
It may be used for debugging, educational or any other purposes.

It was tested on Oracle 9.2.0.8, 10.1.0.5, 10.2.0.3 and 11.1.0.6.0, of course, for win32 platform.
Operation systems tested on: Windows Vista, Windows 2008 Server, Windows 2003 Server, Windows XP SP2 and SP3, Windows 2000 Server.

Before you run it, ORACLE_HOME environment variable should be set.
Also, ORACLE_HOME\bin path should be present in %PATH% environment variable.

After start, utility attaches to oracle.exe process and allow us to see these internal calls. Press Ctrl-C (once) to detach from Oracle process.
Please note: detaching is not working in Windows 2000, so all utility can do is to kill Oracle process.

If Oracle RDBMS version 11.1.0.6.0 is used, Oracle internal process name will be visible also at each SQL statement. Otherwise, only win32 thread ID will be visible. Windows thread ID can be converted to Oracle process name using this query:

"select spid, program from gv$process;"

Utility is not intended to use on production servers. But if someone consciously willing to use it, one should backup database. Utility cannot be stable yet, at this level of development.

Source code was initially compiled by MSVC 2008.

Examples, which were recorded on freshly installed 11g win32:

STARTUP_ospy.log: instance service startup
SCOTT_LOGON_ospy.log: user SCOTT logon.
VERSION_ospy.log: during "select * from v$version" query.
SHUTDOWN_ospy.log: instance shutdown.

Download

I'm not sure, which C compiler was used to compile Oracle 11.1.0.6.0 win32 (maybe Intel(R) C++ 9.1, which is used for 11.1.0.6.0 Linux), but it generate some strange things:

.text:0051FBF8 85 C0                             test    eax, eax
.text:0051FBFA 0F 84 8F 00 00 00                 jz      loc_51FC8F
.text:0051FC00 74 1D                             jz      short loc_51FC1F

(This code is from Oracle 11.1.0.6.0 Win32 CPUjul2008)

There're well-known parameters trace_level_server and trace_level_client in sqlnet.ora, which are defining debugging level of trace files.
A lot of network functions may call a special trace writer function which put passed information into trace file.
Usually, software developer with common sense makes trace writer function checking current debug level and let this tracer writer decide if to write any information to file. In this case his code is relatively clean and clear.
Oracle RDBMS developers make decision about this before trace writer function called, so code may looks like:

if (trace_is_enabled) write_to_trace (current_function_name, trace_level, message);

Most likely, this code is actually written using #define macros.
At least, Oracle 8.1.5 win32 installation contain C:\Oracle\Ora81\NETWORK\TNSAPI\SRC\ folder where TNSAPI.C file may be found: it contain some trace writer calls using macros, although, I cannot found there a macros definition.
So, in this case, code is not so clear, but here we can see time economy at the place of trace writer function prolog and epilog.
Not a bad idea at al.

It is clever idea used in Oracle RDBMS, where, in complex memory control environment, there are a presence of different malloc()-like functions.
Major portion of these malloc()-like functions also have comment-parameter, where caller pass short human-readable parameter, describing, for what this memory will be used.
After that, at any point of program execution, it is possible to see statistics, what are major memory consumers.
Also, in case of memory leakage, it is possible to see, what memory were not freed.
In Oracle RDBMS, if memory is allocated in SGA area, statistics can be seen using V$SGASTAT view.
For example:

SQL> select * from v$sgastat order by bytes desc;

POOL         NAME                            BYTES
------------ -------------------------- ----------
shared pool  free memory                  78190408
             buffer_cache                 20971520
shared pool  sql area                      4756932
java pool    free memory                   4194304
large pool   free memory                   3988096
shared pool  KCB Table Scan Buffer         3981204
shared pool  KSFD SGA I/O b                3977140
shared pool  row cache                     3755444
shared pool  library cache                 3266232
             log_buffer                    2904064
shared pool  kglsim hash table bkts        2097152

POOL         NAME                            BYTES
------------ -------------------------- ----------
shared pool  ASH buffers                   2097152
shared pool  PL/SQL MPCODE                 2046600
shared pool  KGLS heap                     1654696
shared pool  event statistics per sess     1566720
shared pool  CCursor                       1438520
             fixed_sga                     1289508
shared pool  PL/SQL DIANA                  1282072
shared pool  KTI-UNDO                      1235304
shared pool  private strands               1198080
shared pool  KSXR receive buffers          1034000
shared pool  KQR M PO                       979968

I tried to use FPGA in quick search of original Oracle RDBMS account passwords extracting their hash values from database.
Relatively simple hashing algorithm used there, involving DES crypto algorithm.
I used three FPGA developer kits for this.
Cyclone III FPGA Starter Kit, where EP3C25F324 chip is used. I achieved roughly ~12.5 millions passwords per second, that is about 2 hours for all 7-symbol passwords.
Nios II Development Kit, Stratix II Edition, where EP2S60F672C3 chip is used. I achieved roughly ~76 millions passwords per second, that is about 20 minutes for all 7-symbol passwords.
PCI Express Development Kit, Stratix II GX Edition, where EP2SGX90F1508C3 chip is used. I achieved roughyl ~109 millions passwords per second, that is about 14 minutes for all 7-symbol passwords or 9 hours for all 8-symbol passwords.
There also relative speed of software Oracle password crackers.
It was showed that using mid-range FPGA chips like Altera Cyclone is cheaper in terms cost/speed. Probably, Xilinx Spartans may show the same results.
Also, the interesting thing is that, although FPGA hardware is expensive, practically any board from ebay.com may be taken for this task, if it, of course, contain some useful FPGA chips + power supply + some memory for booting, etc.
I tend to sell source files, e.g., FPGA "firmware", then ready-to-use hardware.
Feel free ask me any questions.

It seems, Oracle written in C with rich use of global variables.

Evolution of oracle.exe executable for win32:

8.0.5: ~16k functions and ~600 global variables.
8.1.5: ~18k functions and ~4k global variables.
8.1.7.4: ~22k functions and ~4.5k global variables.
9.0.1.1.1: ~31k functions and ~6k global variables.
9.2.0.4: ~45k functions and ~8k global variables.
10.1.0.5: ~60k functions and ~11k global variables.
10.2.0.3: ~72k functions and ~11k gloval variables.
11.1.0.6.0: ~113k functions and ~17k global variables.

About _disable_txn_alert undocumented parameter - at least as for Oracle 11g win32.

This parameter is connected with ktsmgd_ global variable.

This variable is actually bitmap.
Default value is 0.
Bits which are checked within Oracle 11g processes: 1, 2, 4, 8, 0x10, 0x20, 0x40, 0x80, 0x100, 0x200.

0x1: if it is set, ktuilqa() function will not execute.
0x2: if it is set, ktrsiosa() function will not execute.
0x4: if set: write some debug info to trace file using ksdwrf() function.
0x8: if set: write some debug info to trace file using ksdwrf() function.
0x10: if set, ktsmguuf() function will not execute.
0x20: if set: write some debug info to trace file using ksdwrf() function.
0x40: if set: write some debug info to trace file using ksdwrf() function.
0x80: affect code flow in ktsmgfru() function.
0x100: affect code flow in ktsmgru(), ktsmgruarr(), ktsmghlth(), ktsmgadv() functions.
0x200: affect code flow in ktsmgmql(), ktsmgaex(), ktsmgmsz(), ktsmgbpr(), ktsmgru(), ktsmgruarr(), ktsmghlth(), ktsmgadv() functions.

Thus, turn on trace flags will be: 0x4 + 0x8 + 0x20 + 0x40 = 0x6C or 108 decimal.
Or turn on all flags: 0x1 + 0x2 + 0x4 + 0x8 + 0x10 + 0x20 + 0x40 + 0x80 + 0x100 + 0x200 = 0x3FF or 1023 decimal.

Note: ksdwrf() function write trace information to files usually named <SID>_<process_name>_<thread_id>.trc, at the folder which is usually defined by background_dump_dest parameter.

Update: this command is also can be used for viewing state of ktsmgd_ variable: oradebug dumpvar SGA ktsmgd_

Regarding question on Oracle X$KSMLRU fixed table.

The x$ksmlru table keeps track of the current shared pool objects and the corresponding number of objects flushed out of the shared pool to allocate space for the load. These objects are stored and flushed out based on the Least Recently Used (LRU) algorithm.
....
Note: This is a fixed table: once you query the table, the database will automatically reset the table. Make sure that you spool the output to a file so you can capture it for analysis.

I cannot yet answer why this table reset after each SELECT, but at least, I know at which point.
Information in this table is constructed using function ksmlrs() (at least for 10.2), which also calls ksmsplu(). The last function allocate memory chunks for the table, marking them as "x$ksmsp lrstat" and "x$ksmsp lru", then copy the table, then calls memset() C function to zero it.
If to bypass this last call to memset(), by debugger for example, it is possible to have such Oracle instance which will not reset this table after each SELECT. However, if you want to do this, I hope you'll backup your database first.

On different OS, Oracle V$TIMER system value shows different values.
On Microsoft Windows (we tested Oracle 8.0.5, 8.1.5, 9.0.1.1.1, 9.2.0.1, 10.1.0.2, 10.2.0.1, 10.2.0.1 x64, 11.1.0.6.0 and 11.1.0.6.0 x64) this value is exactly what system call GetTickCount() returning divided by 10.
On GNU/Linux (we tested 10.1.0.3, 10.2.0.1, 11.1.0.6.0 and 11.1.0.6.0 x64) this is exactly what times() system call returning.
On Solaris 10 (we tested 10.2.0.1 x64) this is value returned by gethrtime() divided by 10000000.

So, while we reading official Oracle manual of 11g Release 1 (11.1):

V$TIMER displays the elapsed time in hundredths of a second. Time is measured since the beginning of the epoch, which is operating system specific, and wraps around to 0 again whenever the value overflows four bytes (roughly 497 days).

... they probably not covering all OS-es.