Kürzlich trat bei einem Kunden, der unseren SQL Server ODBC-Treiber verwendete, um Oracle mit SQL Server zu verbinden, ein Problem auf, dem man nur schwer auf den Grund gehen konnte.
Der Kunde erhielt jedes Mal, wenn DG4ODBC verwendet wurde, ein Protokoll des ODBC-Treibermanagers, was die Leistung beeinträchtigte – das Protokollieren von ODBC-Aufrufen hat Leistungseinbußen zur Folge. Der Kunde hatte die Datei odbcinst.ini auf Einträge überprüft, die die Protokollierung ermöglichen; diese Einträge waren nicht vorhanden.
Um dieses Problem zu lösen, haben wir das Strace-Tool verwendet, um herauszufinden, was "hinter den Kulissen" vor sich ging, als DG4ODBC verwendet wurde.
Da DG4ODBC eher eine Bibliothek als eine Anwendung ist, mussten wir strace an den Oracle-Listener-Prozess (die „Eltern“-Anwendung von DG4ODBC) anhängen, um die mit DG4ODBC verbundenen Operationen zu verfolgen.
Die Ablaufverfolgungsdatei zeigte, welche Kopie von odbcinst.ini die Protokollierung aktiviert hat.
Dies sind die Schritte, die wir unternommen haben, um strace an den Oracle-Listener anzuhängen:
$ ps -aef | grep tns* oracle 16242 1 0 15:02 ? 00:00:00 /u01/app/oracle/product/11.2.0/xe/bin/tnslsnr LISTENER -inherit $ sudo strace -p 16242 -f -o /tmp/mytracefile
(In einem separaten Terminalfenster):
$ ./sqlplus / as sysdba $ select * from mytable@mylink;
Was Oracle „unter der Haube“ getan hat, ist jetzt in /tmp/mytracefile erfasst. Wir haben dann Strg-C verwendet, um strace zu stoppen, und nach sql.log (der Protokolldatei des ODBC-Treiber-Managers) in /tmp/mytracefile gesucht. In unserem Fall zeigte dies:
16436 open("/etc/odbcinst.ini", O_RDONLY) = 7
16436 fstat(7, {st_mode=S_IFREG|0644, st_size=1365, ...}) = 0
16436 read(7, "[ODBC]\nTrace=Yes\nTraceFile=/tmp/"..., 4096) = 1365
16436 read(7, "", 4096) = 0
16436 close(7) = 0
16436 open("/u01/app/oracle/.odbcinst.ini", O_RDONLY) = -1 ENOENT (No such file or directory)
16436 open("/tmp/sql.log", O_WRONLY|O_CREAT|O_APPEND, 0666) = 7 
