OBIEE 12c: [nQSError: 13082] Status of read-only lock on the repository is already true

Arindam Saha

As an ongoing development process, we always modify the RPD in Offline mode and then upload the RPD to the server. This upload is ran by a Administrator user, which is shared across the developers for uploading purposes.

I'm frequently getting notified by the developers that they are seeing the below error while uploading the RPD. It doesn't happen always, just sometimes, very frequently for the last 1 week.

"Metadata lock already acquired by other process. Waiting for it to be release; Re-trying..."

From the logs, it appears that the BI System user is locking the session.

obis1-diagnostic.log says:

**********  Task: 1. Running for (mls):  **********

Description: Execute Query

Repository Name: ssi

Catalog:

Tenant:

Tenant ID: ssi

Service Name:

User: kbywer7fz04ljh8iognmtapsdcqvxu63

Session ID: 0xa0850000

Request ID: 0xa0850002

ProcedureID: 1000199

Logical SQL:

^M

]]^M

[2017-04-05T17:19:30.741+01:00] [OBIS] [TRACE:32] [] [] [ecid: 6f11d942-bb74-4899-9633-930957b45ec3-00007435,0:2:11] [sik: ssi] [tid: 952a9700] Environment variable BI_PRODUCT_HOME=/opt/obiee/obiee12212/bi [[^M

file: server/Utility/Generic/Portable/Src/SUPOS.cpp; line: 2307^M

]]^M

[2017-04-05T17:19:30.741+01:00] [OBIS] [TRACE:1] [] [] [ecid: 6f11d942-bb74-4899-9633-930957b45ec3-00007435,0:2:11] [sik: ssi] [tid: 952a9700]  [13060] Login with user='kbywer7fz04ljh8iognmtapsdcqvxu63', guid='(empty)', impersonated user='(empty)' and runas user='(empty)'. [[^M

Properties: sessionID:=1594884096; ^M

]]^M

[2017-04-05T17:19:30.822+01:00] [OBIS] [TRACE:1] [] [] [ecid: 6f11d942-bb74-4899-9633-930957b45ec3-00007435,0:2:11] [sik: ssi] [tid: 952a9700]  [13055] User 'kbywer7fz04ljh8iognmtapsdcqvxu63' spent 80.000000 milliseconds getting http response when 'getAuthenticatedUserWithLanguageAndProperties'.^M

[2017-04-05T17:19:30.822+01:00] [OBIS] [TRACE:1] [] [] [ecid: 6f11d942-bb74-4899-9633-930957b45ec3-00007435,0:2:11] [sik: ssi] [tid: 952a9700] The request from kbywer7fz04ljh8iognmtapsdcqvxu63:<?xml version="1.0"?><soap:Envelope xmlns:soap="http://www.w3.org/2003/05/soap-envelope"><soap:Header><wsse:Security xmlns:wsse="http://docs.oasis-open.org/wss/2004/01/oasis-200401-wss-wssecurity-secext-1.0.xsd"><wsse:UsernameToken><wsse:Username>kbywer7fz04ljh8iognmtapsdcqvxu63</wsse:Username><wsse:Password>xxxxxxxxxx</wsse:Password></wsse:UsernameToken></wsse:Security></soap:Header><soap:Body><sec:getAuthenticatedUserWithLanguageAndProperties xmlns:sec="http://oracle/bi/security/ws/"><language></language></sec:getAuthenticatedUserWithLanguageAndProperties></soap:Body></soap:Envelope>^M

[2017-04-05T17:19:30.822+01:00] [OBIS] [TRACE:1] [] [] [ecid: 6f11d942-bb74-4899-9633-930957b45ec3-00007435,0:2:11] [sik: ssi] [tid: 952a9700] The response:<env:Envelope xmlns:env="http://www.w3.org/2003/05/soap-envelope"><env:Header/><env:Body><ns1:getAuthenticatedUserWithLanguageAndPropertiesResponse xmlns:ns0="http://oracle/bi/security/" xmlns:ns1="http://oracle/bi/security/ws/"><result><GUID><value>kbywer7fz04ljh8iognmtapsdcqvxu63</value></GUID><name>kbywer7fz04ljh8iognmtapsdcqvxu63</name><description>The virtual BI system user.</description><displayName>kbywer7fz04ljh8iognmtapsdcqvxu63</displayName><language xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:nil="true"/><timezone xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:nil="true"/><tenantGUID xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:nil="true"/><tenantName>OBIEE_INTERNALTENANTGUID</tenantName><serviceName xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xsi:nil="true"/><roles><GUID><value>AuthenticatedUser</value></GUID><name>AuthenticatedUser</name><description>A role granted to every user.</description><displayName>Authenticated User Role</displayName></roles><roles><GUID><value>BIConsumer</value></GUID><name>BIConsumer</name><description>A role for consumers of BI content.</description><displayName>BI Consumer Role</displayName></roles><roles><GUID><value>BISystem</value></GUID><name>BISystem</name><description>A role granted to the system user.</description><displayName>BI System Role</displayName></roles><permissions><resourceName>oracle.bi.scheduler.manageJobs</resourceName><resourceType>oracle.bi.scheduler.permission</resourceType><actions>_all_</actions></permissions><permissions><resourceName>oracle.bi.server.manageRepositories</resourceName><resourceType>oracle.bi.server.permission</resourceType><actions>_all_</actions></permissions><permissions><resourceName>oracle.bi.server.queryUserPopulation</resourceName><resourceType>oracle.bi.server.permission</resourceType><actions>_all_</actions></permissions></result></ns1:getAuthenticatedUserWithLanguageAndPropertiesResponse></env:Body></env:Envelope>^M

[2017-04-05T17:19:30.823+01:00] [OBIS] [NOTIFICATION:1] [] [] [ecid: 6f11d942-bb74-4899-9633-930957b45ec3-00007435,0:2:11] [sik: ssi] [tid: 952a9700] LCMAPIsUtil.GetSDD-> /opt/obiee/obiee12c/user_projects/domains/bi/bidata^M

[2017-04-05T17:19:30.825+01:00] [OBIS] [ERROR:1] [] [] [ecid: 6f11d942-bb74-4899-9633-930957b45ec3-00007435,0:2:21] [sik: ssi] [tid: 952a9700]  [nQSError: 13082] Status of read-only lock on the repository is already true.

from bi-lcm-rest.log.0 log, it says:

Apr 05,2017 17:19:30 oracle.bi.lcm.rest.app.LCMApplication INFO - 86 * Server has received a request on thread [ACTIVE] ExecuteThread: '1' for queue: 'weblogic.kernel.Default (self-tuning)'

86 > POST https://dev-bi12c.iggroup.local:9503/bi-lcm/v1/si/ssi/rpd/lockmetadataupdates

86 > Accept: text/html, image/gif, image/jpeg, *; q=.2, */*; q=.2

86 > Authorization: Basic YmlfZGVwbG95OldlbGNvbWUx

86 > Connection: keep-alive

86 > Content-Length: 6

86 > Content-Type: application/x-www-form-urlencoded

86 > Host: dev-bi12c.iggroup.local:9503

86 > User-Agent: Jersey/2.22.1 (HttpUrlConnection 1.8.0_77)

lock=1

Apr 05,2017 17:19:30 oracle.bi.lcm.rest.si.rpd.RpdEndpointV1 INFO - lockMetadataUpdate called for: ssi

Apr 05,2017 17:19:30 oracle.bi.lcm.rest.si.rpd.RpdEndpointV1 SEVERE - Exception while locking metadata updates: oracle.bi.server.customization.utils.ServerException: java.sql.SQLException: PreparedStatement execute failed java.io.IOException: execute query failed[nQSError: 43113] Message returned from OBIS.

[nQSError: 13082] Status of read-only lock on the repository is already true.

        at oracle.bi.server.customization.utils.BiProcedureExecutor.getMetadataUpdateLock(BiProcedureExecutor.java:300)

        at oracle.bi.server.customization.utils.LockMetadataUpdateTask.execute(LockMetadataUpdateTask.java:24)

        at oracle.bi.server.customization.utils.CallableProgress.call(CallableProgress.java:37)

        at oracle.bi.server.customization.utils.OnlineTask.call(OnlineTask.java:16)

        at oracle.bi.server.customization.utils.CallableProgress.call(CallableProgress.java:12)

        at java.util.concurrent.FutureTask.run(FutureTask.java:266)

        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)

        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)

        at java.lang.Thread.run(Thread.java:745)

Caused by: java.sql.SQLException: PreparedStatement execute failed java.io.IOException: execute query failed[nQSError: 43113] Message returned from OBIS.

[nQSError: 13082] Status of read-only lock on the repository is already true.

        at oracle.bi.jdbc.AnaJdbcPreparedStatementImpl.execute(AnaJdbcPreparedStatementImpl.java:542)

        at oracle.bi.server.customization.utils.BiProcedureExecutor.getMetadataUpdateLock(BiProcedureExecutor.java:298)

        ... 8 more

Apr 05,2017 17:19:30 oracle.bi.lcm.rest.app.LCMApplication INFO - 86 * Server responded with a response on thread [ACTIVE] ExecuteThread: '1' for queue: 'weblogic.kernel.Default (self-tuning)'

86 < 200

86 < Content-Type: application/vnd.siren+json

{"clazz":["rpd-response"],"links":[{"href":"https://dev-bi12c.iggroup.local:9503/bi-lcm/v1/si/ssi/rpd/lockmetadataupdates","rel":["self"]}],"properties":{"entry":[{"key":"si","value":{"type":"string","value":"ssi"}},{"key":"description","value":{"type":"string","value":"Lock on the repository is already acquired. Release the lock or wait for it to be released by other process."}},{"key":"desc_code","value":{"type":"string","value":"DESC_CODE_LOCK_ALREADY_ACQUIRED_ERROR"}},{"key":"status","value":{"type":"string","value":"ERROR"}}]},"title":"RPD-LCM response, SI=ssi, action=Lock Metadata Update"}

Restarting "obis1"  fixes the problem, but after sometime the issue appears again. Any idea why this NQSError happen? How to avoid this issue ?