L'Oracle de Victor: 2018

jeudi 18 octobre 2018

TCPS - BLOB - Problème de communication

L'autre jour chez un de mes clients, on nous avait dit qu'on avait quelques problèmes avec des sessions gelées au moment de déposer un fichier BLOB sur la base de données en passant par une connexion sécurisée.

Base de données : 11.2.0.4
Système d'exploitation de la Bd : Solaris 10
Client Oracle : 11g (11.2.0.4) sur Windows Server 64 bits

Toutes les autres activités en TCPS se faisaient sans problème, mais c'était juste au moment d'essayer de déposer un fichier sur la base de données qu'on avait le problème.

En activant le trace sur le client 11g au niveau du "sqlnet.ora" (Voir les paramètres ci-dessous)

TRACE_UNIQUE_CLIENT=ON
TRACE_LEVEL_CLIENT=16
TRACE_DIRECTORY_CLIENT=C:\Temp
TRACE_FILE_CLIENT=TRC_CLT
TRACE_FILELEN_CLIENT=40960
TRACE_FILENO_CLIENT=2
TRACE_TIMESTAMP_CLIENT=ON
ADR_BASE=OFF
DIAG_ADR_ENABLED=OFF

J'ai demandé au responsable de lancer un autre test afin d'obtenir le fichier de trace.

Une fois obtenu, en feuillant dans le fichier de trace je me suis aperçu que la lecture du wallet se faisait sans problème et que l'établissement de la connexion sécurisée entre le serveur et client se faisait aussi, cependant j'ai remarqué aussi les lignes ci-dessous, en particulier de la ligne en surbrillance, qui montre un message d'erreur :

...

[000001 16-OCT. -2018 11:40:15:736] ntt2err: exit
[000001 16-OCT. -2018 11:40:15:736] nttrd: socket 712 had bytes read=0
[000001 16-OCT. -2018 11:40:15:736] nttrd: exit
[000001 16-OCT. -2018 11:40:15:736] [Raw read] length = 0
[000001 16-OCT. -2018 11:40:15:736] <read error -6993>
[000001 16-OCT. -2018 11:40:15:736] read 0 bytes. cicerr = -2130640891
[000001 16-OCT. -2018 11:40:15:736] read 0 bytes. error = 28861
[000001 16-OCT. -2018 11:40:15:736] nzos_Read: exit
[000001 16-OCT. -2018 11:40:15:736] ntznzosread: encountered "wouldblock" error
[000001 16-OCT. -2018 11:40:15:736] ntctst: size of NTTEST list is 1 - not calling poll
[000001 16-OCT. -2018 11:40:15:736] sntseltst: Testing for DATA on socket 712
[000001 16-OCT. -2018 11:40:16:018] sntseltst: FOUND: read request on socket 712
[000001 16-OCT. -2018 11:40:16:018] nzos_Read: entry
[000001 16-OCT. -2018 11:40:16:018] reading 8208 bytes
[000001 16-OCT. -2018 11:40:16:018] nttrd: entry
[000001 16-OCT. -2018 11:40:16:018] nttrd: socket 712 had bytes read=5
[000001 16-OCT. -2018 11:40:16:018] nttrd: exit
[000001 16-OCT. -2018 11:40:16:018] [Raw read] length = 5
...

Le détail sur le code d'erreur relié selon le lien ci-dessous dit :
https://docs.oracle.com/cd/E16764_01/core.1111/e10113/chapter_ssl_messages.htm

SSL-28861: SSL connection would block

Cause: This error is informational. It should never be communicated to the user.

Action: Enable tracing and retry the connection to determine the exact cause of the error. Contact Oracle customer support if needed.Level: 00001
Type: ERROR
Impact: Other

Dans ce cas, et avec l'information obtenue, je vais soir sur le site de support Oracle j'ai trouvé une note qui parle d'un problème similaire mais avec le client 10g, lequel supposément est corrigé avec le client 11g (Note : 1298611.1)

Pour essayer de voir si c'est le même cas, et afin de tester la recommandation d'Oracle malgré que ma version est 11g, je suis allé modifier le tnsnames du client en ajoutant le paramètre SEND_BUF_SIZE, afin d'avoir quelque chose comme ça:

MYBD.WORLD=(DESCRIPTION =(SEND_BUF_SIZE=2557500)(ADDRESS = (PROTOCOL = TCPS)(HOST = myserver.domain )(PORT = 1822))(ADDRESS = (PROTOCOL = TCP)(HOST = myserver.domain)(PORT = 1821))(CONNECT_DATA =(SERVER = DEDICATED)(SERVICE_NAME = mybd.domain)(SECURITY= (SSL_SERVER_CERT_DN="CN=XXXXXX,OU=YYYYYY,O=ZZZ,L=ZZZZ,ST=ZZZ,C=CA"))))

Sur le serveur de base de données j'ai ajouté aussi une modification additionnelle sur le listener sécurisé qui dessert ladite base de données, dans ce cas-là, j'ai ajouté le paramètre RECV_BUF_SIZE

L_MYBD_SSL =
(DESCRIPTION_LIST =
(DESCRIPTION =
(ADDRESS = (PROTOCOL=IPC)(KEY=EXTPROC1822))
(ADDRESS = (PROTOCOL=TCPS)(HOST=myserver.domain)(PORT=1822))
(RECV_BUF_SIZE=2557500))
)
)

C'est important de repartir le listener, pas juste un RELOAD, mais vraiment un STOP/START.

En faisant une autre fois les test, le problème semble corrigé. Le dépôt des BLOB's semble se faire sans problème cette fois à travers d'une connexion sécurisée.

Il faut remarquer que les valeurs utilisées dépendront bien sûr de vos configurations et comme vous savez, Oracle même ne donne pas une recommandation sur les valeurs. Donc, il faudrait calculer la bonne valeur afin de ne pas impacter le trafic sur le réseau non plus.

mercredi 10 octobre 2018

Drop database avec RMAN

Il y a quelques jours on m'avait demandé de supprimer une bd Oracle et j'ai bien profité pour créer un petit document que pourrait être utile à tous.

echo $ORACLE_SID
MYDB

srvctl remove database -d MYDB

rman target / catalog user/apssword@BDCATALOG ou rman target /
Recovery Manager: Release 12.1.0.2.0 - Production on Thu Aug 9 14:46:36 2018
Copyright (c) 1982, 2014, Oracle and/or its affiliates. All rights reserved.
connected to target database: MYDB (DBID=2774697611)
connected to recovery catalog database

RMAN> REPORT SCHEMA ;
Report of database schema for database with db_unique_name MMYDB

List of Permanent Datafiles
===========================
File Size(MB) Tablespace RB segs Datafile Name
---- -------- -------------------- ------- ------------------------
1 1530 SYSTEM YES +DATINXRWMYDB/MMYDB/datafile/system.265.870780837
2 1490 SYSAUX NO +DATINXRWMYDB/MMYDB/datafile/sysaux.266.870780837
3 695 UNDOTBS1 YES +DATINXRWMYDB/MMYDB/datafile/undotbs1.261.870780837
4 5 USERS NO +DATINXRWMYDB/MMYDB/datafile/users.259.870780839
5 5 TBS_RO_TEST01 NO +DATINXROMYDB/MMYDB/datafile/tbs_ro_test01.265.870780839
6 10 TBS_PDF_01 NO +DATINXROMYDB/MMYDB/datafile/tbs_pdf_01.dbf
7 200 GGS_DATA NO +DATINXRWMYDB/MMYDB/datafile/ggs_data.267.870780837

List of Temporary Files
=======================
File Size(MB) Tablespace Maxsize(MB) Tempfile Name
---- -------- -------------------- ----------- --------------------
1 100 TEMP 100 +TEMPMYDB/MMYDB/tempfile/temp.256.870780879
2 500 TEMP_NEW 32767 +TEMPMYDB/MMYDB/TEMPFILE/temp_new.257.881479571

RMAN> SHUTDOWN IMMEDIATE ;
database closed
database dismounted
Oracle instance shut down

RMAN> STARTUP MOUNT ;
connected to target database (not started)
Oracle instance started
database mounted

Total System Global Area 5368709120 bytes

Fixed Size 5284640 bytes
Variable Size 1895832800 bytes
Database Buffers 3456106496 bytes
Redo Buffers 11485184 bytes

RMAN> SQL 'ALTER SYSTEM ENABLE RESTRICTED SESSION';

sql statement: ALTER SYSTEM ENABLE RESTRICTED SESSION

Si on veut tout supprimer et ne pas laisser de traces des sauvegardes prises pour cette base de données on doit ajouter le INCLUDING BACKUPS.

RMAN> DROP DATABASE INCLUDING BACKUPS;

database name is "MYDB" and DBID is 2774697611

Do you really want to drop all backups and the database (enter YES or NO)? YES

allocated channel: ORA_DISK_1
channel ORA_DISK_1: SID=69 device type=DISK

List of Backup Pieces
BP Key BS Key Pc# Cp# Status Device Type Piece Name
------- ------- --- --- ----------- ----------- ----------
1371427 1371426 1 1 AVAILABLE DISK /bkpdskrman/MYDB/01pue54s_1_1
1371445 1371439 1 1 AVAILABLE DISK /bkpdskrman/MYDB/02pue54v_1_1
1371446 1371440 1 1 AVAILABLE DISK /bkpdskrman/MYDB/03pue55o_1_1
1371464 1371461 1 1 AVAILABLE DISK /bkpdskrman/MYDB/04pue55s_1_1
1371474 1371472 1 1 AVAILABLE DISK /bkpdskrman/MYDB/05pue55v_1_1
deleted backup piece
backup piece handle=/bkpdskrman/MYDB/01pue54s_1_1 RECID=1 STAMP=870782108
deleted backup piece
backup piece handle=/bkpdskrman/MYDB/02pue54v_1_1 RECID=2 STAMP=870782111
deleted backup piece
backup piece handle=/bkpdskrman/MYDB/03pue55o_1_1 RECID=3 STAMP=870782137
deleted backup piece
backup piece handle=/bkpdskrman/MYDB/04pue55s_1_1 RECID=4 STAMP=870782140
deleted backup piece
backup piece handle=/bkpdskrman/MYDB/05pue55v_1_1 RECID=5 STAMP=870782144
Deleted 5 objects

released channel: ORA_DISK_1
allocated channel: ORA_DISK_1
channel ORA_DISK_1: SID=69 device type=DISK
specification does not match any datafile copy in the repository
specification does not match any control file copy in the repository
specification does not match any control file copy in the repository
List of Archived Log Copies for database with db_unique_name MMYDB
=====================================================================

Key Thrd Seq S Low Time
------- ---- ------- - ---------
1371361 1 1 A 04-FEB-15
Name: +ARCHMYDB/MMYDB/archivelog/2015_02_04/thread_1_seq_1.312.870781535

1371362 1 2 A 04-FEB-15
Name: +ARCHMYDB/MMYDB/archivelog/2015_02_04/thread_1_seq_2.311.870781733

1371416 1 3 A 04-FEB-15
Name: +ARCHMYDB/MMYDB/archivelog/2015_02_04/thread_1_seq_3.310.870782095

1371421 1 4 A 04-FEB-15
Name: +ARCHMYDB/MMYDB/archivelog/2015_02_04/thread_1_seq_4.309.870782107

1371559 1 5 A 04-FEB-15
Name: +ARCHMYDB/MMYDB/archivelog/2015_02_04/thread_1_seq_5.321.870793853

1371438 1 5 A 04-FEB-15
Name: +ARCHMYDB/MMYDB/archivelog/2015_02_04/thread_1_seq_5.308.870782139

1371602 1 67 A 04-FEB-15
Name: +ARCHMYDB/MMYDB/archivelog/2015_02_04/thread_1_seq_67.320.870793939

1371603 1 68 A 04-FEB-15
Name: +ARCHMYDB/MMYDB/archivelog/2015_02_04/thread_1_seq_68.319.870793941

1371604 1 69 A 04-FEB-15
Name: +ARCHMYDB/MMYDB/archivelog/2015_02_04/thread_1_seq_69.318.870793941

deleted archived log
archived log file name=+ARCHMYDB/MMYDB/archivelog/2015_02_04/thread_1_seq_1.312.870781535 RECID=1 STAMP=870781535
deleted archived log
archived log file name=+ARCHMYDB/MMYDB/archivelog/2015_02_04/thread_1_seq_2.311.870781733 RECID=2 STAMP=870781733
deleted archived log
archived log file name=+ARCHMYDB/MMYDB/archivelog/2015_02_04/thread_1_seq_3.310.870782095 RECID=3 STAMP=870782094
deleted archived log
archived log file name=+ARCHMYDB/MMYDB/archivelog/2015_02_04/thread_1_seq_4.309.870782107 RECID=4 STAMP=870782106
deleted archived log
archived log file name=+ARCHMYDB/MMYDB/archivelog/2015_02_04/thread_1_seq_5.321.870793853 RECID=9 STAMP=870793852
deleted archived log
archived log file name=+ARCHMYDB/MMYDB/archivelog/2015_02_04/thread_1_seq_5.308.870782139 RECID=5 STAMP=870782139
deleted archived log
archived log file name=+ARCHMYDB/MMYDB/archivelog/2015_02_04/thread_1_seq_67.320.870793939 RECID=9 STAMP=870793940
deleted archived log
archived log file name=+ARCHMYDB/MMYDB/archivelog/2015_02_04/thread_1_seq_68.319.870793941 RECID=10 STAMP=870793940
deleted archived log
archived log file name=+ARCHMYDB/MMYDB/archivelog/2015_02_04/thread_1_seq_69.318.870793941 RECID=11 STAMP=870793941
Deleted 9 objects

database name is "MYDB" and DBID is 2774697611
database dropped

database name is "MYDB" and DBID is 2774697611
database unregistered from the recovery catalog

Bien sûr, il reste à faire le ménage dans les fichiers *.ora et selon le cas les policies de backup qu'auraient pu être reliés à cette base de données.

jeudi 19 juillet 2018

OracleText - Solaris - HAS (BUG)

Chez un de mes clients on avait un problème avec l'indexation de documents en français, apparemment on n'avait aucun erreur mais l'indexation ne se faisait pas correctement.

Oracle database : 12.1.0.2.0
Solaris Sparc 64bits : 5.11
HAS

Tout a commencé avec des tokens générés incorrectement pour la plupart de documents, sauf pour les document Word 2003. pour tester je me suis crée une table et j'ai chargé quelques documents dans une colonne BLOB.

Comme la vraie table allait contenir plutôt de documents en français, j'ai fait mes test avec un PDF rédigé à 99% en français.

Le résultat des tokens une fois l'index créé pour ce fichier PDF donnait un résultat comme celui ci-dessous; pour valider si le mot ÉVOLUTION était indexé :

SELECT DISTINCT TOKEN_TEXT FROM DR$EVTABLOBIDX$I A
WHERE A.TOKEN_TEXT LIKE '%VOLUTION'
ORDER BY A.TOKEN_TEXT ;

...
VOLUTION
...

Ce qui était évident pour moi que mon document n'était pas correctement indexé.

Par contre si je faisais le même test avec un document word 2003 avec le même contenu, j'avais cet autre résultat:

SELECT DISTINCT TOKEN_TEXT FROM DR$EVTABLOBIDX$I A
WHERE A.TOKEN_TEXT LIKE '%VOLUTION'
ORDER BY A.TOKEN_TEXT ;

...
EVOLUTION
...

En essayant de trouver la cause je me suis rendu compte que ce problématique affectait surtout les mot accentués, d'autres mots sans accents étaient correctement reconnus dans la presque totalité.

Mes préférences avaient considéré la restriction de la langue, mais malgré tout, l'indexation n'était pas correcte.

BEGIN
CTX_DDL.CREATE_PREFERENCE('UCM_EVTA_LEXER', 'BASIC_LEXER');
CTX_DDL.SET_ATTRIBUTE('UCM_EVTA_LEXER', 'BASE_LETTER', 'YES' );
CTX_DDL.SET_ATTRIBUTE('UCM_EVTA_LEXER','PRINTJOINS','@&_|/\''#().');
END ;
/

J'ai même vérifié que les librairies étaient correctement initialisées et même configurées pour la bd et le(s) listeners.

LD_LIBRARY_PATH=$ORACLE_HOME/ctx/lib:$ORACLE_HOME/lib

mais toujours rien, une fois le support d"Oracle contacté, on m'a confirmé qu'avec Solaris cette variable semble ignorées (des fois, pas toujours) et que la variable à utiliser serait plutôt LD_LIBRARY_PATH_64

Donc, modification faite, je constate qu'on a toujours le même problème.

Voici mon script de création de l'index :

CREATE INDEX EVTABLOBIDX ON EVTABLOB(OTSCONTENT) INDEXTYPE IS CTXSYS.CONTEXT
PARAMETERS('LEXER UCM_EVTA_LEXER FILTER UCM_EVTA_FILTER WORDLIST UCM_EVTA_WLIST MEMORY 350M SYNC(MANUAL)') ;

J'ai essayé donc de tracer au niveau du système d'exploitation le moment juste de la création d'index, afin de voir si je pouvais collecter plus d'information, et voici ce que j'ai découvert avec cette trace.

...
2068/1: memcntl(0xFFFFFFFF75600000, 10960, MC_ADVISE, MADV_WILLNEED, 0, 0) = 0
2068/1: stat("/usr/ccs/lib/sparcv9/librt.so.1", 0xFFFFFFFF7FFFE080) Err#2 ENOENT
2068/1: mmap(0x00000000, 65536, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANON, -1, 0) = 0xFFFFFFFF7CB00000
2068/1: stat("/lib/64/libclntshcore.so.12.1", 0xFFFFFFFF7FFFE080) Err#2 ENOENT
2068/1: stat("/usr/lib/64/libclntshcore.so.12.1", 0xFFFFFFFF7FFFE080) Err#2 ENOENT
2068/1: open("/usr/lib/locale/en_US.UTF-8/LC_MESSAGES/SUNW_OST_SGS.mo", O_RDONLY) Err#2 ENOENT
2068/1: open("/usr/lib/locale/en_US.UTF-8/LC_MESSAGES/SUNW_OST_OSLIB.mo", O_RDONLY) Err#2 ENOENT
2068/1: write(2, 0xFFFFFFFF7DD48A60, 85) = 85
2068/1: l d . s o . 1 : c t x h x : f a t a l : l i b c l n t s h
2068/1: c o r e . s o . 1 2 . 1 : o p e n f a i l e d : N o s u
2068/1: c h f i l e o r d i r e c t o r y\n
2068/1: lwp_self() = 1
1778/1: waitid(P_PID, 2068, 0xFFFFFFFF7FFE8D40, WEXITED|WTRAPPED) = 0
1778/1: siginfo: SIGCLD CLD_KILLED pid=2068 status=0x0009
...

Ceci me montre qu'une de librairies n'est pas retrouvée, cependant ce qui est le plus étrange c'est l'endroit où Oracle la cherche malgré le contenu des variables.

Pour tester que c'était la cause, je me suis permis de créer un lien symbolique là, où il la cherchait le fichier; cette fois mon index a bien reconnu les mots.
Avec cette information Oracle a reconnu la présence d'une bogue et le contournement passerait par modifier les références contenues dans le fichier libnnz12.so qui se trouve dans le $ORACLE_HOME/lib

Avant de la modification le fichier libnnz12.so affiche :

$ elfdump -d libnnz12.so

Dynamic Section: .dynamic

index tag value

[0] NEEDED 0x36e4 libclntshcore.so.12.1

[1] INIT 0x27e8d0

[2] FINI 0x27e8e0

[3] SONAME 0x36d8 libnnz12.so

[4] HASH 0x380

[5] STRTAB 0x7068

[6] STRSZ 0x38fa

[7] SYMTAB 0x1ed8

[8] SYMENT 0x18

[9] CHECKSUM 0x8f21

[10] VERDEF 0xa968

[11] VERDEFNUM 0x1

[12] RELACOUNT 0x348f

[13] PLTRELSZ 0xea0

[14] PLTREL 0x7

[15] JMPREL 0x59e50

[16] RELA 0xb058

[17] RELASZ 0x4fc98

[18] RELAENT 0x18

[19] REGISTER 0x194

[20] REGISTER 0x1a0

[21] SYMBOLIC 0

[22] FLAGS 0x2 [ SYMBOLIC ]

[23] FLAGS_1 0 0

[24] SUNW_STRPAD 0x200

[25] SUNW_LDMACH 0x2b EM_SPARCV9

[26] PLTGOT 0x578f00

[27-37] NULL 0

Une fois modifié avec cette commande (Un arrêt/départ est nécessaire):

elfedit -e 'dyn:runpath /mon/oraclehome/lib' libnnz12.so

elfdump -d libnnz12.so