Connection Timeouts and DNS

On an Oracle 11.1.0.7.0 database running on AIX system, clients were complaining about connection timeouts. Tnsping was showing latency more than 1000 ms.

I opened a trace for tnsping using AIX truss:

$ truss -aefo tnsping.trc tnsping <tns_db>

30539848: 31654123: _getpid()                           = 30539848
30539848: 31654123: kopen("/etc/resolv.conf", O_RDONLY) = 5
30539848: 31654123: kioctl(5, 22528, 0x0000000000000000, 0x0000000000000000) Err#25 ENOTTY
30539848: 31654123: kioctl(5, 22528, 0x0000000000000000, 0x0000000000000000) Err#25 ENOTTY
30539848: 31654123: kread(5, " n a m e s e r v e r   1".., 4096) = 114
30539848: 31654123: kread(5, " n a m e s e r v e r   1".., 4096) = 0
30539848: 31654123: statx("/etc/resolv.conf", 0x0FFFFFFFFFFF9108, 176, 0) = 0
30539848: 31654123: close(5)                            = 0
30539848: 31654123: socket(1, 1, 0)                     = 5
30539848: 31654123: kfcntl(5, F_SETFD, 0x0000000000000001) = 0
30539848: 31654123: connext(5, 0x0FFFFFFFFFFF8BD8, 1025)        Err#2  ENOENT
30539848: 31654123: close(5)                            = 0
30539848: 31654123: kopen("/etc/netsvc.conf", O_RDONLY) = 5
30539848: 31654123: kioctl(5, 22528, 0x0000000000000000, 0x0000000000000000) Err#25 ENOTTY
30539848: 31654123: kioctl(5, 22528, 0x0000000000000000, 0x0000000000000000) Err#25 ENOTTY
30539848: 31654123: kread(5, " #   @ ( # ) 4 3        ".., 4096) = 4096
30539848: 31654123: kread(5, " o n   a n d   r e s o l".., 4096) = 638
30539848: 31654123: close(5)                            = 0
30539848: 31654123: _thread_self()                      = 31654123
30539848: 31654123: _thread_self()                      = 31654123
30539848: 31654123: kopen("/etc/hesiod.conf", O_RDONLY) Err#2  ENOENT
30539848: 31654123: __libc_sbrk(0x0000000000010020)     = 0x00000001106A4D40
30539848: 31654123: kopen("/etc/irs.conf", O_RDONLY)    Err#2  ENOENT
30539848: 31654123: _thread_self()                      = 31654123
30539848: 31654123: getdomainname(0x09001000A02273B0, 1024) = 0
30539848: 31654123: _thread_self()                      = 31654123
30539848: 31654123: _thread_self()                      = 31654123
30539848: 31654123: _thread_self()                      = 31654123
30539848: 31654123: getdomainname(0x09001000A02273B0, 1024) = 0
30539848: 31654123: _thread_self()                      = 31654123
30539848: 31654123: _thread_self()                      = 31654123
30539848: 31654123: _thread_self()                      = 31654123
30539848: 31654123: _thread_self()                      = 31654123
30539848: 31654123: _thread_self()                      = 31654123
30539848: 31654123: _thread_self()                      = 31654123
30539848: 31654123: _thread_self()                      = 31654123
30539848: 31654123: getdomainname(0x09001000A02273B0, 1024) = 0
30539848: 31654123: _thread_self()                      = 31654123
30539848: 31654123: _thread_self()                      = 31654123
30539848: 31654123: _thread_self()                      = 31654123
30539848: 31654123: getdomainname(0x09001000A02273B0, 1024) = 0
30539848: 31654123: _thread_self()                      = 31654123
30539848: 31654123: _thread_self()                      = 31654123
30539848: 31654123: kopen("/etc/hosts", O_RDONLY)               = 5
30539848: 31654123: kioctl(5, 22528, 0x0000000000000000, 0x0000000000000000) Err#25 ENOTTY
30539848: 31654123: kfcntl(5, F_SETFD, 0x0000000000000001) = 0
30539848: 31654123: kioctl(5, 22528, 0x0000000000000000, 0x0000000000000000) Err#25 ENOTTY
30539848: 31654123: kread(5, " #   @ ( # ) 4 7\t 1 . 2".., 4096) = 2018
30539848: 31654123: kread(5, " #   @ ( # ) 4 7\t 1 . 2".., 4096) = 0
30539848: 31654123: close(5)                            = 0
30539848: 31654123: kopen("/etc/hosts", O_RDONLY)               = 5
30539848: 31654123: kioctl(5, 22528, 0x0000000000000000, 0x0000000000000000) Err#25 ENOTTY
30539848: 31654123: kfcntl(5, F_SETFD, 0x0000000000000001) = 0
30539848: 31654123: kioctl(5, 22528, 0x0000000000000000, 0x0000000000000000) Err#25 ENOTTY
30539848: 31654123: kread(5, " #   @ ( # ) 4 7\t 1 . 2".., 4096) = 2018
30539848: 31654123: kread(5, " #   @ ( # ) 4 7\t 1 . 2".., 4096) = 0
30539848: 31654123: socket(2, 2, 0)                     = 6
30539848: 31654123: getsockopt(6, 65535, 4104, 0x0FFFFFFFFFFF7BE4, 0x0FFFFFFFFFFF7BE0) = 0
30539848: 31654123: connext(6, 0x09001000A0167878, 16)  = 0
30539848: 31654123: _esend(6, 0x0FFFFFFFFFFF8AF0, 35, 0, 0x0000000000000000) = 35
30539848: 31654123: _poll(0x0FFFFFFFFFFF7CB0, 1, 1000)  = 1
30539848: 31654123: _enrecvfrom(6, 0x0FFFFFFFFFFF9E20, 1024, 0, 0x0FFFFFFFFFFF8470, 0x0FFFFFFFFFFF7C98, 0x0000000000000000) = 104
30539848: 31654123: _esend(6, 0x0FFFFFFFFFFF8AF0, 47, 0, 0x0000000000000000) = 47
30539848: 31654123: _poll(0x0FFFFFFFFFFF7CB0, 1, 1000)  = 1
30539848: 31654123: _enrecvfrom(6, 0x0FFFFFFFFFFF9E20, 1024, 0, 0x0FFFFFFFFFFF8470, 0x0FFFFFFFFFFF7C98, 0x0000000000000000) = 122
30539848: 31654123: close(6)                            = 0
30539848: 31654123: close(5)                            = 0

As you might notice, what tnsping and also any other Oracle Net service is doing is to check DNS server first then use local hosts file for name resolution. This is the cause of the latency because a public DNS server was set for this server and naturally there was no record for it on the DNS. Even you set hosts file as primary source in the netsvc.conf, Oracle does not care and uses DNS at first. 

After clearing DNS configuration on the server, connection times get into order. It's also a known bug that is fixed in 11.2.0.2. So, you need to upgrade for an appropriate solution.

Spatial Index Creation Fails with ORA-01031

While re-creating a spatial index it failed as follow:

DROP INDEX TEST.SIX_POLYGON;

CREATE INDEX TEST.SIX_POLYGON ON TEST.POLYGON (GEOLOC) INDEXTYPE IS MDSYS.SPATIAL_INDEX PARAMETERS('TABLESPACE=INDEX_TS') NOPARALLEL;

ORA-29855: error occurred in the execution of ODCIINDEXCREATE routine
ORA-13249: internal error in Spatial index: [mdidxrbd]
ORA-13249: Error in Spatial index: index build failed
ORA-13249: Error in R-tree: [mdrcrtscrt]
ORA-13231: failed to create index table [MDRS_1EEB04$] during R-tree creation
ORA-13249: Stmt-Execute Failure: CREATE SEQUENCE "TEST".MDRS_1EEB04$ ORDER START WITH 1 CACHE 100
ORA-29400: data cartridge error
ORA-01031: insufficient privileges
ORA-06512: at "MDSYS.SDO_INDEX_METHOD_10I", line 10

After some digging in, I found the missing privilege: create sequence. You can check if the user has required rights by:

select privilege
from DBA_SYS_PRIVS
where privilege in ('CREATE TABLE', 'CREATE SEQUENCE' )
and grantee = 'TEST';

All needed is to grant create sequence to the target user before creating index. Afterwards you can revoke the right:

GRANT CREATE SEQUENCE TO TEST;

CREATE INDEX TEST.SIX_POLYGON ON TEST.POLYGON (GEOLOC) INDEXTYPE IS MDSYS.SPATIAL_INDEX PARAMETERS('TABLESPACE=INDEX_TS') NOPARALLEL;


REVOKE CREATE SEQUENCE FROM TEST;

Upgrade Failed with PRKO-3226

It's been quite a while since my latest post. Let me get back on track with this short one.

During an upgrade of 10.2.0.5 two node RAC -CRS and ASM- to 11.2.0.4, rootupgrade.sh script failed with some errors on the second node. I corrected them and re-run the script a couple of times. At last rootupgrade.sh ended with the following:

PRKO-3226 : Upgrade from version 11.2.0.4.0 to version 11.2.0.4.0 using srvctl upgrade model command of version 11.2.0.4.0 is not supported

When it's queried, CRS's version seems upgraded:

$ crsctl query crs softwareversion
Oracle Clusterware version on node [node2] is [11.2.0.4.0]

To be sure, I opened an SR on the issue. Oracle Support replied by stating that it's totally a misleading error since the node  already has been upgraded and it's safe to continue. So I ignored the error and didn't re-run rootupgrade.sh, continued through UI and completed the process successfully.

Exadata and iPhone

I never thought one day I will find a similarity between Oracle Exadata and iPhone. But it was before Oracle announced X4-2C, the colorful Exadata:)

X4 2C


However, I don't think that X4-2C is cheaper as iPhone 5C is, since it's a limited edition...

Data Redaction in Oracle 12c and 11gR2

Data Redaction is one of the new features of 12c actually, and also it's become available in 11gR2 with 11.2.0.4. Data Redaction is in Advanced Security option of enterprise edition.

What Data Redaction does is basically masking the data on the fly based on the type and expression given. Let's do a demonstration:

First thing to do is to create a policy. Policies are created on tables and a table can have only one policy. If you try to add a policy to table with a policy, you get ORA-28069. Policy can be defined for only a single column at a time but you can add columns to the policy by altering it.

begin
    dbms_redact.add_policy (
        object_schema       => 'DEMO',
        object_name         => 'CUSTOMERS',
        column_name         => 'CNAME',        
        policy_name         => 'customers_pol',
        function_type       => DBMS_REDACT.REGEXP,
        regexp_pattern      => '(\S{3})(\S+)',
        regexp_replace_string   => '\1***',  
        expression          => 'SYS_CONTEXT(''USERENV'',''SESSION_USER'') != ''SYS'''
    );
end;
/

Above command creates a policy on table CUSTOMERS in schema DEMO and it masks column CNAME by using regular expressions. Masked values will contain first 3 letters of the name (each name if customer has a middle name) and 3 "*"s.

There are 6 types of redaction; full, partial, regexp, random and none. You can find detail information in Oracle documentation. Please not the expression parameter. What we're saying here is apply this policy to users who are not sys. By default polices applied against users except sys and object owner. So if you also want table owner gets masked values or you want to redact data based on application, such an expression must be used. Expression is a mandatory parameter, you can set it as '1=1' if you have no rule to apply.

begin
    dbms_redact.alter_policy (
        object_schema       => 'DEMO',
        object_name         => 'CUSTOMERS',        
        policy_name         => 'customers_pol',
        action              => DBMS_REDACT.ADD_COLUMN,
        column_name         => 'DOB',
        function_type       => DBMS_REDACT.PARTIAL,
        function_parameters => DBMS_REDACT.REDACT_DATE_EPOCH,
        expression          => 'SYS_CONTEXT(''USERENV'',''SESSION_USER'') != ''SYS'''        
    );
end;
/

By altering the policy we've created, we added another column of the table to be masked. Here we used built-in redaction function. This function set all date values to 01-Jan-1970. There are couple of more pre-defined functions such for SSN, e-mail zip code.

begin
    dbms_redact.alter_policy (
        object_schema       => 'DEMO',
        object_name         => 'CUSTOMERS',        
        policy_name         => 'customers_pol',
        action              => DBMS_REDACT.ADD_COLUMN,
        column_name         => 'CID',
        function_type       => DBMS_REDACT.FULL, 
        expression          => 'SYS_CONTEXT(''USERENV'',''SESSION_USER'') != ''SYS'''        
    );
end;
/

This time we add CID column to the policy and redacted it fully. So masked values will be displayed as 0. To change a columns redaction type, alter policy again by setting altering action to MODIFY_COLUMN:

begin
    dbms_redact.alter_policy (
        object_schema       => 'DEMO',
        object_name         => 'CUSTOMERS',        
        policy_name         => 'customers_pol',
        action              => DBMS_REDACT.MODIFY_COLUMN,
        column_name         => 'CID',
        function_type       => DBMS_REDACT.RANDOM, 
        expression          => 'SYS_CONTEXT(''USERENV'',''SESSION_USER'') != ''SYS'''        
    );
end;
/

Now, we set it to use random masking, random values will be generated for the column. Redacted query output is as below at the end:

SQL> select cid, cname, dob from demo.customers;

CID         CNAME DOB
-----------------------------------------
1311680984   ABD*** AYD***   01-JAN-70
102691765    AHM*** YIL*** 01-JAN-70
819107024  ARI*** DEM***   01-JAN-70
7285271581  AYD*** TUR***   01-JAN-70
22688323660  AZM*** SEV***   01-JAN-70
7508336149  HAC*** ELM***   01-JAN-70
46158355970  HAL*** HAT***   01-JAN-70

Finally, if you need to drop a policy:

begin
    dbms_redact.drop_policy(
        object_schema     => 'DEMO',
        object_name       => 'CUSTOMERS',
        policy_name       => 'customers_pol'
    );        
end;
/

Data redaction is not a complicated way of defining security policies however what I see as a downside is one-to-one relationship between columns and policies: It is not allowed to add another policy/expression for a column, you get ORA-28060 error. So what you need is to create a rule base which has different masking types for different roles on the very same table, you need another tool. Otherwise you have practical data masking tool.

SQL Developer Hints to Format Output

SQL Developer may not be the perfect IDE, but it doesn't mean that it has not got any tricks at all. One of those features I'd like mention about can ease data transfer. SQL Developer excepts hints to format output. Here are the outputs for some of those hints; csv, loader, fixed and insert. As names implie; CSV gives rows with columns separated by commas, loader gives data formatted for SQL Loader, fixed returns columns separated by fixed spaces and insert creates insert commands.

select /*csv*/ * from scott.dept;
"DEPTNO","DNAME","LOC"
10,"ACCOUNTING","NEW YORK"
20,"RESEARCH","DALLAS"
30,"SALES","CHICAGO"
40,"OPERATIONS","BOSTON"

select /*loader*/ * from scott.dept;
10|"ACCOUNTING"|"NEW YORK"|
20|"RESEARCH"|"DALLAS"|
30|"SALES"|"CHICAGO"|
40|"OPERATIONS"|"BOSTON"|

select /*fixed*/ * from scott.dept;
"DEPTNO"    "DNAME"           "LOC"                        
"10"        "ACCOUNTING"      "NEW YORK"                   
"20"        "RESEARCH"        "DALLAS"                     
"30"        "SALES"           "CHICAGO"                    
"40"        "OPERATIONS"      "BOSTON"                      

select /*insert*/ * from scott.dept;
REM INSERTING into scott.dept
SET DEFINE OFF;
Insert into scott.dept (DEPTNO,DNAME,LOC) values (10,'ACCOUNTING','NEW YORK');
Insert into scott.dept (DEPTNO,DNAME,LOC) values (20,'RESEARCH','DALLAS');
Insert into scott.dept (DEPTNO,DNAME,LOC) values (30,'SALES','CHICAGO');
Insert into scott.dept (DEPTNO,DNAME,LOC) values (40,'OPERATIONS','BOSTON');

It's also possible to get output in html or xml format which can really be handy for a quick report. As you can see below, html format includes even a search box to make searches in content.


Please note that hints are used in lower case and no space left between the hint and *s.

BEA-337 Incidents on OMS 12c

Lately I noticed that free disk space on my 12c Cloud Control server was reducing for some amount. When I investigated, I've figured it out that there were daily incidents of BEA-337 errors with around 40 MB of log  files in /u01/app/Oracle/Middleware/oms12c/gc_inst/user_projects/domains/GCDomain/servers/EMGC_OMS1/adr/diag /ofm/GCDomain/EMGC_OMS1/incident directory.

Problem Key: BEA-337 [WebLogicServer]
Error Message Id: BEA-337

Description
-----------
Incident detected using watch rule "StuckThread":
Watch ServerName:       EMGC_OMS1
Watch RuleType:         Log
Watch Rule:             (SEVERITY = 'Error') AND ((MSGID = 'WL-000337') OR (MSGID = 'BEA-000337'))
Watch DomainName:       GCDomain
Watch Data:
   SERVER : EMGC_OMS1
   MESSAGE : [STUCK] ExecuteThread: '7' for queue: 'weblogic.kernel.Default (self-tuning)' has been busy for "611" seconds working on the request "weblogic.servlet.internal.ServletRequestImpl@70733a9e[
POST /em/websvcs/emws/ConsoleJobStepExecutorService HTTP/1.1

As you can see, incidents was caused due to a stuck thread watch rule. It was triggered because of "Refresh From My Oracle Support" job which is running more than 600 seconds. First thing I tried was rescheduling the job. From OEM, I navigated to jobs and found the job through advanced search by selecting ”Refresh From My Oracle Support” from the job type drop down and rescheduling it to some less busy time.

However it didn't work out the problem. So I decided to increase the parameter controlling stuck thread watch rule which is StuckThreadMaxTime. It's default value is 600 (seconds) and my job takes 13.5 minutes to complete. 

To alter the parameter:

1. Log on to WebLogic administration console through EMGC_OMS1 target on OMS or directly navigating to https://<host>:7200/console 

2. Click on EMGC_OMS1 under GCDomain->Environment -> Servers. Find "Stuck Thread Max Time" setting on Configuration/Tuning tab. I've increased it to 1200 seconds to cover job duration.


3. Save the configuration and then restart EMGC_OMS1 server from WebLogic administration console or from server console.

This workaround did the job.