Cloning Grid Control agent binaries

Lastly we created a 2-node system in configuration active-standby. The environment for the second node was simply a copy of the first one. As all the paths were preserved then we successfully used the same Oracle Database binaries.
However when came to agents, when we run them on both nodes we get only one agent on the OMS. The other agent was seen as the same possibly - for example agents have a generated at the installation time agent seed, which is seen in several places - for example in emd.properties (as AgentSeed property) and in targets.xml (hashed/encrypted to AGENT_TOKEN). I have got an error about duplicating the agent. Possibly there are other such settings.

The solution is to clone the agent:
- copy binaries to the destination location
- run $ORACLE_HOME/oui/bin/runInstaller -clone -forceClone ORACLE_HOME= ORACLE_HOME_NAME= -noconfig -silent
- run $ORACLE_HOME/bin/agentca -f to run Agent Configuration Assistant
- run $ORACLE_HOME/root.sh as root (assuming this is not a first Oracle product on this machine, else run /oraInventory/orainstRoot.sh)

Location in Oracle docs here.

Error 1017 received logging on to the standby

I have got frequently the error "Error 1017 received logging on to the standby", while trying to enable the archivelog transfer between primary and standby.
The majority of tips on the net and the entry in the alert.log would tell You:
- check Your remote_login_passwordfile - should be SHARED or EXCLUSIVE
- check Your password file - it should exist and a password for SYS should be the same.
I have done as suggested, still no progress.

The solution was actually trivial - just copy the password file from the primary to the standby. Not sure why previously it did not work - I am sure the SYS password was the same and I checked connection in both directions (i.e. PRIMARY->STANDBY, STANDBY->PRIMARY) using the same entries in tnsnames.ora as specified in the archivelog transfer configuration.

It seems, there is a huge difference between versions 10g and 11g in this case - previously it was enough to create new password file with the same password. Now it must be the same file (ie. copy from the original on the primary).
And here is a very good article on the password files in Data Guard environment.

BIND_MISMATCH reason for not sharing cursor

BIND_MISMATCH reason is another one from the long list of possible reasons why not to share a cursor. General reason here is that bind variables between two executions differ too much for the database. The details are stored in the REASON column of the V$SQL_SHARED_CURSOR view. Here is how it looks like:


<childnode>
<childnumber>1</ChildNumber>
<id>40</ID>
<reason>Bind mismatch(22)</reason>
<size>4x4</size>
<bind_position>157</bind_position>
<original_oacflg>1</original_oacflg>
<original_oacmxl>32</original_oacmxl>
<upgradeable_new_oacmxl>128</upgradeable_new_oacmxl>
</ChildNode>




Whole thing is quite easy to decrypt. There is one node per an existing cursor child. The REASON tag provides one of reasons the database provides when it does not use an existing cursor child, but instead creates another one. The bind position indicates the position of the bind variable within a SQL text (every entry has a unique position per SQL even if we bind the same variable).
The ORIGINAL_OACFLG tag IMHO is the same entity as the OACFLG (or first FLG) in a bind section of a 10046 event raw trace and of course there is more equivalents.

The bind variables use some standard size buffers, which depend on data type. For varchar2 there are several sizes (due to varying nature of the type) and first size amounts to 32, so the minimum buffer length for bind variable of varchar2 is 32 bytes. The next values are 128 bytes, then 2000 bytes, and so on.

The change between different values of a bind variable may become a reason for not sharing a cursor . This happens when a buffer size of a variable changes - for example from smaller to larger.

Some details about bind section of the 10046 event trace

In general very good description of the 10046 event trace interpretation is contained on MOS as the article with 39817.1 id.
However with time there showed new entries not really mentioned in the article indicated above.
Let's see an example of the bind section:

Bind#2
oacdty=96 mxl=32(02) mxlc=00 mal=00 scl=00 pre=00
oacflg=01 fl2=1000000 frm=02 csi=2000 siz=0 off=56
kxsbbbfp=7fb04313fe80 bln=32 avl=02 flg=01
value=0 54

oac prefix I simply ignore and not sure what it stands for.

• dty is an id for data type
• mxl is a maximum length of bind variable (in parentheses there is provided a private maximum length - for me this is current bind variable length)
• mxlc is not sure for me, but I saw it always equal to 00
• mal is a maximum array length
• scl stands for scale
• pre stands for precision
• flg is a flag with bind options
• fl2 is a continuation of flag
• frm stays unknown
• csi is character set id, which can be decrypted with nls_charset_name function; the nls_charset_id function, working in an opposite way, is available as well
• siz is an amount of memory allocated for this chunk
• off is a memory offset of a buffer for this variable within the chunk
• kxsbbbfp is a bind addres
• bln is a bind buffer length and I suppose usually it is equal to mxl, unless data does not fit into one chunk
• avl is a current bind value length (or array length)
• flg is another flag (this time for bind status)
• value - finally current value

ROLL_INVALID_MISMATCH reason for not sharing cursor

Since 10g there was introduced a change in the way the cursors are invalidated. Now they are invalidated in a rolling fashion (i.e. not all at once), hence the reason ROLL_INVALID_MISMATCH.
The excellent article on this theme at The Dutch Prutser's Blog

Cursors with high VERSION_COUNT

Symptoms
Since upgrade to 11gR2 from time to time we experience problems with excessive number of cursor children per some cursors. Symptoms are common - many active sessions with waits on mutex X, mutex S, library cache latch, and few others, high VERSION_COUNT for those cursors.
What happens?
It seems those all waits are due to very slow work of shared pool for those cursors. My understanding of this issue is all the children of such cursor are sharing the same sql_id and hash_value, so eventually they end up in the same bucket of library cache and the more of them, the longer sessions need to hold the latch to library cache or mutexes in order to check all the children to choose the possibly matched for sharing.

Root causes
The root causes for multiplying the cursor children are various. Some reasons are provided by the V$SQL_SHARED_CURSOR, there is a plenty of bugs (search term high VERSION_COUNT on Metalink).
In our case the reasons are few and not sure the concretes, as few explanations are possible. The bug is one of them, however as probable is wrong use of bind variables. From V$SQL_SHARED_CURSOR we get as a reason mainly BIND_MISMATCH, with possible addition of BIND_LENGTH_UPGRADEABLE. Partially this is due to the change of a bind variable length (the buffer for bind value is allocated up to 32 bytes or up to 128 bytes or up to 2000 bytes - at least those were revealed by observing trace 10046, so I would not say how it is beyond 2000 bytes - are there other thresholds or the bind possible maximum is the limit).

Workarounds
Whatever the reasons workarounds are similar and I dare to say "officially" used. What is important this behavior is not seen on 10g (or I would rather say it is hidden). This is due to the obsoleting cursors with more than 1024 children, what is not a case with 11g. So the clue of a workaround is mimic this by:

1. workaround in the form of purging excessive children with use of dbms_shared_pool.purge
   
2. hidden parameter _cursor_obsolete_threshold and the MOS article 10187168.8
   

True solutions They depend on the root causes. This varies from applying patch to changing the SQL to changing bind variables (size or type) to impossible or better say independent of our doings - great example/article is the entry by Martin Klier. Update 2013.08.08 Few weeks ago we have another attack of mutexes' waits. It was another bug (11930680), where the workaround was to disable optimizer_secure_view_merging. The diagnosis method for such problems may be called generic - when one see a huge bunch of session waiting on "mutex X" or "mutex S" or "cursor pin S wait on X" and all of them try to perform the same query then:

• count the number of children for the query
• if high (few hundreds to thousands) look at V$SQL_SHARED_CURSOR in order to figure out why there are so many of them
• google Google (or any other favourite search engine) and MOS with the reasons found in V$SQL_SHARED_CURSOR
• as a symptom softening measure one may run the cursor purge as a job in short interval

On the grounds of short experience I may say that usually the very high cursor children count is brought by some bug. With poorly written code we hit ~200 children per cursor, with bugs it was up to 5.000 or more. But as I said the experience is short...
Here one may find that similar contention may arise from different than bug reasons.

NFS and Oracle UTL_FILE

Today we faced a challenge in the shape of slow dump by UTL_FILE of rows to a file located on a NFS mounted storage. The dump runs quite fast on a test environment, but there the storage in use is a FC based storage array.
After initial code review we found that the UTL_FILE.PUT_LINE is followed immediately by a call to UTL_FILE.FFLUSH, so it become apparent, that every single row dump is immediately flushed to the NFS file. An educated guess (or intuition) pointed out that the code sends data in inefficient manner.

The NFS storage was mounted with the following options: rw,bg,vers=2,proto=tcp,sec=sys. Those settings mean the write window size to be 8K for version 2 of NFS. I have found among many articles by Glen Fawcett a tip to the 359515.1 article on the Metalink (anyway this is a blog worth of looking at). In our case the recommended settings were rw,bg,hard,rsize=32768,wsize=32768,vers=3,cio,intr,timeo=600,proto=tcp, so we went with those new settings. The test showed that with those new ones was even worse.

And now all become clear: in case of NFS the write buffer is sent through network as is, so one can write as much as want to, but the data will be divided into buffers of set size and pushed to a network. In our case we flushed 231-bytes worth portion of data through first 8K, then 32K write windows.
After that all went smoothly. As we could not have been able to change the code at once, we managed to decrease the write window size - first 512B, then even 256B. The test showed that 512B window is better - evidently the protocol overhead + our 231 bytes was more then 256B, so finally we stayed at wsize=512 with a goal to do something about this FFLUSH call in the future and return to 32K window.

Long story short do not call FFLUSH after every PUT_LINE (unless You know what You do in order for example to allow for reading by others as quick as You are able to write), or even better do not call it at all (as it is called implicitly after buffer become full).
And second thought: set Your rsize and wsize according to the data amounts You will read or write in a single call to Your NFS storage.