Uploaded image for project: 'Policy Framework'
  1. Policy Framework
  2. POLICY-777

PAP: frequent failing of provisioning transactions because of DB locking table errors

XMLWordPrintable

    • Icon: Bug Bug
    • Resolution: Done
    • Icon: Highest Highest
    • Beijing Release
    • Beijing Release
    • None
    • Heat and k8s

      See PAP log:

      ==> xacml-pap-rest/debug.log <==
      2018-05-06 22:24:11,199 [http-nio-9091-exec-3] INFO com.att.eelf.debug clientIpAddress=10.42.209.41 server=dev-pap-8587696769-ncpqm MetricEndTimestamp=2018-05-06T22:24:11.198+00:00 targetEntity=POLICY partnerName=USER serviceName=PAP.put requestId=cd1254e3-c298-4ed3-b265-71645ab85bb9 serverIpAddress=10.42.59.14 ClassName= targetServiceName=PE Process MetricElapsedTime=0 TransactionBeginTimestamp=2018-05-06T22:24:11.196+00:00 MetricBeginTimestamp=2018-05-06T22:24:11.198+00:00 statusCode=COMPLETEPOLICY-500I INFO: SavePolicyHandler: JSON request from API to create a policy: {"PAPPolicyType":"StdPAPPolicy","policyName":"BRMSParamvDNS","oldPolicyFileName":null,"policyDescription":"BRMS Param vDNS policy","onapName":"DROOLS","configName":"BRMS_PARAM_RULE","treatments":{},"dropDownMap":{},"dynamicSettingsMap":{},"dynamicRuleAlgorithmLabels":null,"dynamicRuleAlgorithmCombo":null,"dynamicRuleAlgorithmField1":null,"dynamicRuleAlgorithmField2":null,"dynamicVariableList":null,"dataTypeList":null,"configBodyData":null,"policyID":null,"ruleID":null,"brmsController":null,"brmsDependency":null,"configType":null,"editPolicy":false,"draft":false,"version":null,"configPolicyType":"BRMS_Param","jsonBody":null,"serviceType":null,"highestVersion":0,"location":null,"actionPerformer":null,"actionAttribute":null,"actionBody":null,"actionDictHeader":null,"actionDictType":null,"actionDictUrl":null,"actionDictMethod":null,"uuid":null,"msLocation":null,"priority":null,"drlRuleAndUIParams":{"templateName":"ClosedLoopControlName","closedLoopControlName":"ControlLoop-vDNS-6f37f56d-a87d-4b85-b6a9-cc953cf779b3","controlLoopYaml":"controlLoop%3A%0D%0A+version%3A+2.0.0%0D%0AcontrolLoopName%3A+ControlLoop-vDNS-6f37f56d-a87d-4b85-b6a9-cc953cf779b3%0D%0Atrigger_policy%3A+unique-policy-id-1-scale-up%0D%0Atimeout%3A+1200%0D%0Aabatement%3A+false%0D%0Apolicies%3A%0D%0A+-id%3A+unique-policy-id-1-scale-up%0D%0A++name%3A+Create+a+new+VF+Module%0D%0A++description%3A%0D%0A++actor%3A+SO%0D%0A++recipe%3A+VF+Module+Create%0D%0A++target%3A%0D%0A++++type%3A+VNF%0D%0A++retry%3A+0%0D%0A++timeout%3A+1200%0D%0A++success%3A+final_success%0D%0A++failure%3A+final_failure%0D%0A++failure_timeout%3A+final_failure_timeout%0D%0A++failure_retries%3A+final_failure_retries%0D%0A++failure_exception%3A+final_failure_exception%0D%0A+++failure_guard%3A+final_failure_guard"},"deleteCondition":null,"dictionaryType":null,"dictionary":null,"dictionaryFields":null,"providerComboBox":null,"riskType":"default","guard":"false","riskLevel":"5","ttldate":null,"domainDir":"com","dynamicFieldConfigAttributes":{"controller":"amsterdam"}}
      2018-05-06 22:24:11,219 [http-nio-9091-exec-3] INFO com.att.eelf.debug clientIpAddress=10.42.209.41 server=dev-pap-8587696769-ncpqm MetricEndTimestamp=2018-05-06T22:24:11.198+00:00 targetEntity=POLICY partnerName=USER serviceName=PAP.put requestId=cd1254e3-c298-4ed3-b265-71645ab85bb9 serverIpAddress=10.42.59.14 ClassName= targetServiceName=PE Process MetricElapsedTime=0 TransactionBeginTimestamp=2018-05-06T22:24:11.196+00:00 MetricBeginTimestamp=2018-05-06T22:24:11.198+00:00 statusCode=COMPLETEPOLICY-500I INFO: SavePolicyHandler: Setting parameter values to PolicyAdapter
      2018-05-06 22:24:11,322 [http-nio-9091-exec-3] INFO com.att.eelf.debug clientIpAddress=10.42.209.41 server=dev-pap-8587696769-ncpqm MetricEndTimestamp=2018-05-06T22:24:11.198+00:00 targetEntity=POLICY partnerName=USER serviceName=PAP.put requestId=cd1254e3-c298-4ed3-b265-71645ab85bb9 serverIpAddress=10.42.59.14 ClassName= targetServiceName=PE Process MetricElapsedTime=0 TransactionBeginTimestamp=2018-05-06T22:24:11.196+00:00 MetricBeginTimestamp=2018-05-06T22:24:11.198+00:00 statusCode=COMPLETEPOLICY-500I INFO: Template name from API is: ClosedLoopControlName
      2018-05-06 22:24:11,338 [http-nio-9091-exec-3] DEBUG com.att.eelf.debug clientIpAddress=10.42.209.41 server=dev-pap-8587696769-ncpqm MetricEndTimestamp=2018-05-06T22:24:11.198+00:00 targetEntity=POLICY partnerName=USER serviceName=PAP.put requestId=cd1254e3-c298-4ed3-b265-71645ab85bb9 serverIpAddress=10.42.59.14 ClassName=org.onap.policy.pap.xacml.rest.components.PolicyDBDao targetServiceName=PE Process MetricElapsedTime=0 TransactionBeginTimestamp=2018-05-06T22:24:11.196+00:00 MetricBeginTimestamp=2018-05-06T22:24:11.198+00:00 statusCode=COMPLETE -POLICY-500-I INFO: getPolicyDBDaoInstance(EntityManagerFactory emf) as getPolicyDBDaoInstance(org.eclipse.persistence.internal.jpa.EntityManagerFactoryImpl@33d41743) called
      2018-05-06 22:24:11,338 [http-nio-9091-exec-3] DEBUG com.att.eelf.debug clientIpAddress=10.42.209.41 server=dev-pap-8587696769-ncpqm MetricEndTimestamp=2018-05-06T22:24:11.198+00:00 targetEntity=POLICY partnerName=USER serviceName=PAP.put requestId=cd1254e3-c298-4ed3-b265-71645ab85bb9 serverIpAddress=10.42.59.14 ClassName=org.onap.policy.pap.xacml.rest.components.PolicyDBDao targetServiceName=PE Process MetricElapsedTime=0 TransactionBeginTimestamp=2018-05-06T22:24:11.196+00:00 MetricBeginTimestamp=2018-05-06T22:24:11.198+00:00 statusCode=COMPLETE -POLICY-500-I INFO: getNewTransaction() as getNewTransaction() called
      2018-05-06 22:24:11,338 [http-nio-9091-exec-3] DEBUG com.att.eelf.debug clientIpAddress=10.42.209.41 server=dev-pap-8587696769-ncpqm MetricEndTimestamp=2018-05-06T22:24:11.198+00:00 targetEntity=POLICY partnerName=USER serviceName=PAP.put requestId=cd1254e3-c298-4ed3-b265-71645ab85bb9 serverIpAddress=10.42.59.14 ClassName=org.onap.policy.pap.xacml.rest.components.PolicyDBDao targetServiceName=PE Process MetricElapsedTime=0 TransactionBeginTimestamp=2018-05-06T22:24:11.196+00:00 MetricBeginTimestamp=2018-05-06T22:24:11.198+00:00 statusCode=COMPLETE -POLICY-500-I INFO: \n\nPolicyDBDaoTransactionInstance() as PolicyDBDaoTransactionInstance() called:\n transactionTimeout = 5000\n transactionWaitTime = 500000\n\n
      2018-05-06 22:24:11,338 [http-nio-9091-exec-3] DEBUG com.att.eelf.debug clientIpAddress=10.42.209.41 server=dev-pap-8587696769-ncpqm MetricEndTimestamp=2018-05-06T22:24:11.198+00:00 targetEntity=POLICY partnerName=USER serviceName=PAP.put requestId=cd1254e3-c298-4ed3-b265-71645ab85bb9 serverIpAddress=10.42.59.14 ClassName=org.onap.policy.pap.xacml.rest.components.PolicyDBDao targetServiceName=PE Process MetricElapsedTime=0 TransactionBeginTimestamp=2018-05-06T22:24:11.196+00:00 MetricBeginTimestamp=2018-05-06T22:24:11.198+00:00 statusCode=COMPLETE -POLICY-500-I INFO: \n\nstartTransactionSynced(EntityManager entityMgr,int waitTime) as \n startTransactionSynced(org.eclipse.persistence.internal.jpa.EntityManagerImpl@1d2294ea,500000) called\n\n
      2018-05-06 22:24:11,338 [http-nio-9091-exec-3] DEBUG com.att.eelf.debug clientIpAddress=10.42.209.41 server=dev-pap-8587696769-ncpqm MetricEndTimestamp=2018-05-06T22:24:11.198+00:00 targetEntity=POLICY partnerName=USER serviceName=PAP.put requestId=cd1254e3-c298-4ed3-b265-71645ab85bb9 serverIpAddress=10.42.59.14 ClassName=org.onap.policy.pap.xacml.rest.components.PolicyDBDao targetServiceName=PE Process MetricElapsedTime=0 TransactionBeginTimestamp=2018-05-06T22:24:11.196+00:00 MetricBeginTimestamp=2018-05-06T22:24:11.198+00:00 statusCode=COMPLETE -POLICY-500-I INFO: \n\nstartTransactionSynced():\n entityManager.getProperties() = {xacml.rest.pap.workspace=workspace, xacml.rest.pdp.idfile=test.properties, ENVIRONMENT=TEST, xacml.PAP.papEngineFactory=org.onap.policy.xacml.std.pap.StdEngineFactory, xacml.policy.msPolicyName=, xacml.rest.pap.audit.timeoutms=300000, xacml.rest.pap.userid=testpap, xacml.rest.pap.transaction.waitms=500000, node_type=pap, deletePolicy.impl.className=org.onap.policy.pap.xacml.rest.handler.DeleteHandler, pushPolicy.impl.className=org.onap.policy.pap.xacml.rest.handler.PushPolicyHandler, fp_monitor_interval=30, javax.persistence.jdbc.user=policy_user, javax.persistence.jdbc.url=jdbc:mariadb://policydb:3306/onap_sdk?failOverReadOnly=false&autoReconnect=true, xacml.rest.pap.resource.name=pap_1, xacml.rest.pap.incomingnotification.tries=4, javax.persistence.query.timeout=500000, xacml.rest.pap.transaction.timeoutms=5000, xacml.rest.pap.password=alpha123, max_fpc_update_interval=60, xacm.xcor.required.pattern=1,1, xacml.rest.pap.repository=repository, integrity_audit_period_seconds=-1, xacml.rest.pap.url=http://pap:9091/pap/, xacml.pap.pdps=/opt/app/policy/servers/pap/bin/pdps, xacml.rest.pap.heartbeat.timeout=10000, xacml.rest.pap.run.audit.flag=true, test_trans_interval=20, xacml.rest.pap.domain=com, savePolicy.impl.className=org.onap.policy.pap.xacml.rest.handler.SavePolicyHandler, test_via_jmx=false, xacml.rest.config.webapps=/opt/app/policy/servers/pap/webapps, xacml.policy.msOnapName=, failed_counter_threshold=3, dictionary.impl.className=org.onap.policy.pap.xacml.rest.handler.DictionaryHandlerImpl, site_name=site_1, xacml.rest.pap.heartbeat.interval=10000, javax.persistence.jdbc.password=policy_user, javax.persistence.jdbc.driver=org.mariadb.jdbc.Driver, dependency_groups=paplp_1, xacml.rest.pap.initiate.pdp=true, write_fpc_interval=5, xacml.rest.pap.filesystem.audit=true}\n\n
      2018-05-06 22:24:11,338 [http-nio-9091-exec-3] DEBUG com.att.eelf.debug clientIpAddress=10.42.209.41 server=dev-pap-8587696769-ncpqm MetricEndTimestamp=2018-05-06T22:24:11.198+00:00 targetEntity=POLICY partnerName=USER serviceName=PAP.put requestId=cd1254e3-c298-4ed3-b265-71645ab85bb9 serverIpAddress=10.42.59.14 ClassName=org.onap.policy.pap.xacml.rest.components.PolicyDBDao targetServiceName=PE Process MetricElapsedTime=0 TransactionBeginTimestamp=2018-05-06T22:24:11.196+00:00 MetricBeginTimestamp=2018-05-06T22:24:11.198+00:00 statusCode=COMPLETE -POLICY-500-I INFO: \n\nstartTransactionSynced():\n ATTEMPT to get the DB lock\n\n

      ==> xacml-pap-rest/error.log <==
      2018-05-06 22:24:11,532 [http-nio-9091-exec-3] ERROR com.att.eelf.error clientIpAddress=10.42.209.41 ErrorDescription=This is a general error message during the process. Please check the error message for detail information server=dev-pap-8587696769-ncpqm MetricEndTimestamp=2018-05-06T22:24:11.198+00:00 targetEntity=POLICY partnerName=USER serviceName=PAP.put requestId=cd1254e3-c298-4ed3-b265-71645ab85bb9 serverIpAddress=10.42.59.14 ClassName=org.onap.policy.pap.xacml.rest.components.PolicyDBDao targetServiceName=PE Process ErrorCode=-POLICY-515-E MetricElapsedTime=0 TransactionBeginTimestamp=2018-05-06T22:24:11.196+00:00 MetricBeginTimestamp=2018-05-06T22:24:11.198+00:00 statusCode=COMPLETE -POLICY-515-E ERROR: Exception Occuredjavax.persistence.PessimisticLockException: Exception [EclipseLink-4002] (Eclipse Persistence Services - 2.6.0.v20150309-bf26070): org.eclipse.persistence.exceptions.DatabaseException\nInternal Exception: java.sql.SQLNonTransientConnectionException: (conn=67) Could not send query: Broken pipe (Write failed)\nError Code: 0\nQuery: ReadObjectQuery(name="readDatabaseLockEntity" referenceClass=DatabaseLockEntity sql="SELECT lock_key FROM DatabaseLockEntity WHERE (lock_key = ?) FOR UPDATE")

      ==> xacml-pap-rest/debug.log <==
      2018-05-06 22:24:11,532 [http-nio-9091-exec-3] DEBUG com.att.eelf.debug clientIpAddress=10.42.209.41 ErrorDescription=This is a general error message during the process. Please check the error message for detail information server=dev-pap-8587696769-ncpqm MetricEndTimestamp=2018-05-06T22:24:11.198+00:00 targetEntity=POLICY partnerName=USER serviceName=PAP.put requestId=cd1254e3-c298-4ed3-b265-71645ab85bb9 serverIpAddress=10.42.59.14 ClassName=org.onap.policy.pap.xacml.rest.components.PolicyDBDao targetServiceName=PE Process ErrorCode=-POLICY-515-E MetricElapsedTime=0 TransactionBeginTimestamp=2018-05-06T22:24:11.196+00:00 MetricBeginTimestamp=2018-05-06T22:24:11.198+00:00 statusCode=COMPLETE -POLICY-500-I INFO: java.lang.IllegalStateException: The lock row does not exist in the table. Please create a primary key with value = 1.

      ==> xacml-pap-rest/metrics.log <==
      2018-05-06 22:24:11,532 [http-nio-9091-exec-3] INFO com.att.eelf.metrics clientIpAddress=10.42.209.41 ErrorDescription=This is an Unknown Error. Please check the error message for detail information server=dev-pap-8587696769-ncpqm MetricEndTimestamp=2018-05-06T22:24:11.532+00:00 targetEntity=POLICY partnerName=USER serviceName=PAP.put ErrorCategory=ERROR requestId=cd1254e3-c298-4ed3-b265-71645ab85bb9 serverIpAddress=10.42.59.14 ClassName= targetServiceName=PE Process ErrorCode=-POLICY-519-E MetricElapsedTime=334 TransactionBeginTimestamp=2018-05-06T22:24:11.196+00:00 MetricBeginTimestamp=2018-05-06T22:24:11.198+00:00 statusCode=COMPLETE -POLICY-510-I Service Name: null:Executing method: XACMLPapServlet goPut apiRequestHandler doPut

      ==> xacml-pap-rest/error.log <==
      2018-05-06 22:24:11,532 [http-nio-9091-exec-3] ERROR com.att.eelf.error clientIpAddress=10.42.209.41 ErrorDescription=This is an Unknown Error. Please check the error message for detail information server=dev-pap-8587696769-ncpqm MetricEndTimestamp=2018-05-06T22:24:11.198+00:00 targetEntity=POLICY partnerName=USER serviceName=PAP.put ErrorCategory=ERROR requestId=cd1254e3-c298-4ed3-b265-71645ab85bb9 serverIpAddress=10.42.59.14 ClassName= targetServiceName=PE Process ErrorCode=-POLICY-519-E MetricElapsedTime=0 TransactionBeginTimestamp=2018-05-06T22:24:11.196+00:00 MetricBeginTimestamp=2018-05-06T22:24:11.198+00:00 statusCode=COMPLETEPOLICY-519E ERROR: Exception Occured : :javax.persistence.PersistenceException: Could not lock transaction within 500000 milliseconds - \tat org.onap.policy.pap.xacml.rest.components.PolicyDBDao$PolicyDBDaoTransactionInstance.<init>(PolicyDBDao.java:1414) - \tat org.onap.policy.pap.xacml.rest.components.PolicyDBDao$PolicyDBDaoTransactionInstance.<init>(PolicyDBDao.java:1393) - \tat org.onap.policy.pap.xacml.rest.components.PolicyDBDao$PolicyDBDaoTransactionInstance.<init>(PolicyDBDao.java:1381) - \tat org.onap.policy.pap.xacml.rest.components.PolicyDBDao.getNewTransaction(PolicyDBDao.java:260) - \tat org.onap.policy.pap.xacml.rest.policycontroller.PolicyCreation.savePolicy(PolicyCreation.java:469) - \tat org.onap.policy.pap.xacml.rest.handler.SavePolicyHandler.doPolicyAPIPut(SavePolicyHandler.java:81) - \tat org.onap.policy.pap.xacml.rest.handler.APIRequestHandler.doPut(APIRequestHandler.java:74) - \tat org.onap.policy.pap.xacml.rest.XACMLPapServlet.doPut(XACMLPapServlet.java:1186) - \tat javax.servlet.http.HttpServlet.service(HttpServlet.java:651) - \tat javax.servlet.http.HttpServlet.service(HttpServlet.java:729) - \tat org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:292) - \tat org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:207) - \tat org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52) - \tat org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:240) - \tat org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:207) - \tat org.apache.catalina.core.ApplicationDispatcher.invoke(ApplicationDispatcher.java:716) - \tat org.apache.catalina.core.ApplicationDispatcher.processRequest(ApplicationDispatcher.java:466) - \tat org.apache.catalina.core.ApplicationDispatcher.doForward(ApplicationDispatcher.java:391) - \tat org.apache.catalina.core.ApplicationDispatcher.forward(ApplicationDispatcher.java:318) - \tat org.onap.policy.pap.xacml.restAuth.PAPAuthenticationFilter.doFilter(PAPAuthenticationFilter.java:72) - \tat org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:240) - \tat org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:207) - \tat org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:212) - \tat org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:94) - \tat org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:141) - \tat org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:79) - \tat org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:620) - \tat org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:88) - \tat org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:502) - \tat org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1132) - \tat org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:684) - \tat org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1539) - \tat org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:1495) - \tat java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) - \tat java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) - \tat org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61) - \tat java.lang.Thread.run(Thread.java:748) -

      ==> xacml-pap-rest/audit.log <==
      2018-05-06 22:24:11,533 [http-nio-9091-exec-3] INFO com.att.eelf.audit clientIpAddress=10.42.209.41 ErrorDescription=This is an Unknown Error. Please check the error message for detail information server=dev-pap-8587696769-ncpqm MetricEndTimestamp=2018-05-06T22:24:11.532+00:00 targetEntity=POLICY partnerName=USER serviceName=PAP.put TransactionEndTimestamp=2018-05-06T22:24:11.532+00:00 StatusCode=COMPLETE ErrorCategory=ERROR TransactionElapsedTime=336 requestId=cd1254e3-c298-4ed3-b265-71645ab85bb9 serverIpAddress=10.42.59.14 ClassName= targetServiceName=PE Process ErrorCode=-POLICY-519-E MetricElapsedTime=334 TransactionBeginTimestamp=2018-05-06T22:24:11.196+00:00 MetricBeginTimestamp=2018-05-06T22:24:11.198+00:00 statusCode=COMPLETE Transaction Ended Successfully

      ==> xacml-pap-rest/error.log <==
      2018-05-06 22:24:14,668 [http-nio-9091-exec-9] ERROR com.att.eelf.error clientIpAddress=10.42.0.1 ErrorDescription=This is a general error message during the process. Please check the error message for detail information server=dev-pap-8587696769-ncpqm MetricEndTimestamp=2018-05-05T22:52:57.571+00:00 targetEntity=POLICY partnerName=USER serviceName=AC:PAP.getAllGroups TransactionEndTimestamp=2018-05-05T22:52:57.572+00:00 StatusCode=COMPLETE TransactionElapsedTime=39 requestId=e95bf633-8ccc-41e2-b3e7-3b061e453f35 serverIpAddress=10.42.59.14 ClassName=org.onap.policy.utils.CryptoUtils targetServiceName=PE Process ErrorCode=-POLICY-515-E MetricElapsedTime=29 TransactionBeginTimestamp=2018-05-05T22:52:57.533+00:00 MetricBeginTimestamp=2018-05-05T22:52:57.542+00:00 statusCode=COMPLETE -POLICY-515-E ERROR: decryptTxtNoEx: Exception while decryption : javax.crypto.IllegalBlockSizeException: Input length must be multiple of 16 when decrypting with padded cipher

      ==> xacml-pap-rest/debug.log <==
      2018-05-06 22:24:14,670 [http-nio-9091-exec-9] INFO com.att.eelf.debug clientIpAddress=10.42.212.99 server=dev-pap-8587696769-ncpqm targetEntity=POLICY partnerName=USER requestId=31cef66a-fc03-4646-a8eb-476f4c3f1661 serverIpAddress=10.42.59.14 ClassName= targetServiceName=PE Process serviceName=PAP.put TransactionBeginTimestamp=2018-05-06T22:24:14.670+00:00 statusCode=COMPLETEPOLICY-500I INFO: requestID was provided in call to XACMLPapSrvlet (doPut)
      2018-05-06 22:24:14,674 [http-nio-9091-exec-9] INFO com.att.eelf.debug clientIpAddress=10.42.212.99 server=dev-pap-8587696769-ncpqm MetricEndTimestamp=2018-05-06T22:24:14.673+00:00 targetEntity=POLICY partnerName=USER serviceName=PAP.put requestId=31cef66a-fc03-4646-a8eb-476f4c3f1661 serverIpAddress=10.42.59.14 ClassName= targetServiceName=PE Process MetricElapsedTime=0 TransactionBeginTimestamp=2018-05-06T22:24:14.670+00:00 MetricBeginTimestamp=2018-05-06T22:24:14.673+00:00 statusCode=COMPLETEPOLICY-500I INFO: SavePolicyHandler: JSON request from API to create a policy: {"PAPPolicyType":"StdPAPPolicy","policyName":"BRMSParamVOLTE","oldPolicyFileName":null,"policyDescription":"BRMS Param VOLTE policy","onapName":"DROOLS","configName":"BRMS_PARAM_RULE","treatments":{},"dropDownMap":{},"dynamicSettingsMap":{},"dynamicRuleAlgorithmLabels":null,"dynamicRuleAlgorithmCombo":null,"dynamicRuleAlgorithmField1":null,"dynamicRuleAlgorithmField2":null,"dynamicVariableList":null,"dataTypeList":null,"configBodyData":null,"policyID":null,"ruleID":null,"brmsController":null,"brmsDependency":null,"configType":null,"editPolicy":false,"draft":false,"version":null,"configPolicyType":"BRMS_Param","jsonBody":null,"serviceType":null,"highestVersion":0,"location":null,"actionPerformer":null,"actionAttribute":null,"actionBody":null,"actionDictHeader":null,"actionDictType":null,"actionDictUrl":null,"actionDictMethod":null,"uuid":null,"msLocation":null,"priority":null,"drlRuleAndUIParams":{"templateName":"ClosedLoopControlName","closedLoopControlName":"ControlLoop-VOLTE-2179b738-fd36-4843-a71a-a8c24c70c55b","controlLoopYaml":"controlLoop%3A%0D%0A+version%3A+2.0.0%0D%0AcontrolLoopName%3A+ControlLoop-VOLTE-2179b738-fd36-4843-a71a-a8c24c70c55b%0D%0Atrigger_policy%3A+unique-policy-id-1-restart%0D%0Atimeout%3A+3600%0D%0Aabatement%3A+false%0D%0A%0D%0Apolicies%3A%0D%0A++-id%3A+unique-policy-id-1-restart%0D%0A++name%3A+Restart+the+VM%0D%0A++description%3A%0D%0A++actor%3A+VFC%0D%0A++recipe%3A+Restart%0D%0A++target%3A%0D%0A++++type%3A+VM%0D%0A++retry%3A+3%0D%0A++timeout%3A+1200%0D%0A++success%3A+final_success%0D%0A++failure%3A+final_failure%0D%0A++failure_timeout%3A+final_failure_timeout%0D%0A++failure_retries%3A+final_failure_retries%0D%0A++failure_exception%3A+final_failure_exception%0D%0A+++failure_guard%3A+final_failure_guard"},"deleteCondition":null,"dictionaryType":null,"dictionary":null,"dictionaryFields":null,"providerComboBox":null,"riskType":"default","guard":"false","riskLevel":"5","ttldate":null,"domainDir":"com","dynamicFieldConfigAttributes":{"controller":"amsterdam"}}

      ==> xacml-pap-rest/metrics.log <==
      2018-05-06 22:24:14,673 [http-nio-9091-exec-9] INFO com.att.eelf.metrics clientIpAddress=10.42.212.99 server=dev-pap-8587696769-ncpqm MetricEndTimestamp=2018-05-06T22:24:14.673+00:00 targetEntity=POLICY partnerName=USER serviceName=PAP.put requestId=31cef66a-fc03-4646-a8eb-476f4c3f1661 serverIpAddress=10.42.59.14 ClassName= targetServiceName=PE Process MetricElapsedTime=3 TransactionBeginTimestamp=2018-05-06T22:24:14.670+00:00 MetricBeginTimestamp=2018-05-06T22:24:14.670+00:00 statusCode=COMPLETEPOLICY-510I Service Name: null:Executing method: XACMLPapServlet doPut im startTransaction
      2018-05-06 22:24:14,673 [http-nio-9091-exec-9] INFO com.att.eelf.metrics clientIpAddress=10.42.212.99 server=dev-pap-8587696769-ncpqm MetricEndTimestamp=2018-05-06T22:24:14.673+00:00 targetEntity=POLICY partnerName=USER serviceName=PAP.put requestId=31cef66a-fc03-4646-a8eb-476f4c3f1661 serverIpAddress=10.42.59.14 ClassName= targetServiceName=PE Process MetricElapsedTime=0 TransactionBeginTimestamp=2018-05-06T22:24:14.670+00:00 MetricBeginTimestamp=2018-05-06T22:24:14.673+00:00 statusCode=COMPLETEPOLICY-510I Service Name: null:Executing method: XACMLPapServlet doPut dumpRequest

       

      PDP log:

       

      => xacml-pdp-rest/debug.log <==
      2018-05-06 22:24:11,118 [http-nio-8081-exec-49] INFO com.att.eelf.debug clientIpAddress=10.42.59.14 server=dev-pdp-0.pdp.onap.svc.cluster.local MetricEndTimestamp=2018-05-06T22:22:45.172+00:00 targetEntity=POLICY partnerName=USER serviceName=POLICY TransactionEndTimestamp=2018-05-06T22:22:45.174+00:00 StatusCode=COMPLETE TransactionElapsedTime=3 requestId=538802c0-c8e0-4296-80c9-6dfe367effd0 serverIpAddress=10.42.209.41 ClassName=org.onap.policy.pdp.rest.config.PDPApiAuth targetServiceName=PE ProcessMetricElapsedTime=0 TransactionBeginTimestamp=2018-05-06T22:22:45.171+00:00 MetricBeginTimestamp=2018-05-06T22:22:45.172+00:00 statusCode=COMPLETE POLICY-500I INFO: User python is Accessing Policy Engine API.
      2018-05-06 22:24:11,120 [http-nio-8081-exec-49] INFO com.att.eelf.debug clientIpAddress=10.42.59.14 server=dev-pdp-0.pdp.onap.svc.cluster.local MetricEndTimestamp=2018-05-06T22:22:45.172+00:00 targetEntity=POLICY partnerName=USER serviceName=POLICY TransactionEndTimestamp=2018-05-06T22:22:45.174+00:00 StatusCode=COMPLETE TransactionElapsedTime=3 requestId=538802c0-c8e0-4296-80c9-6dfe367effd0 serverIpAddress=10.42.209.41 ClassName= targetServiceName=PE Process MetricElapsedTime=0 TransactionBeginTimestamp=2018-05-06T22:22:45.171+00:00 MetricBeginTimestamp=2018-05-06T22:22:45.172+00:00 statusCode=COMPLETE POLICY-500I INFO: Generated Random UUID: cd1254e3-c298-4ed3-b265-71645ab85bb9
      2018-05-06 22:24:11,120 [http-nio-8081-exec-49] INFO com.att.eelf.debug clientIpAddress=10.42.59.14 server=dev-pdp-0.pdp.onap.svc.cluster.local MetricEndTimestamp=2018-05-06T22:22:45.172+00:00 targetEntity=POLICY partnerName=USER serviceName=POLICY TransactionEndTimestamp=2018-05-06T22:22:45.174+00:00 StatusCode=COMPLETE TransactionElapsedTime=3 requestId=538802c0-c8e0-4296-80c9-6dfe367effd0 serverIpAddress=10.42.209.41 ClassName= targetServiceName=PE Process MetricElapsedTime=0 TransactionBeginTimestamp=2018-05-06T22:22:45.171+00:00 MetricBeginTimestamp=2018-05-06T22:22:45.172+00:00 statusCode=COMPLETE POLICY-500I INFO: Name is BRMSParamvDNS scope is com
      2018-05-06 22:24:11,147 [http-nio-8081-exec-49] DEBUG com.att.eelf.debug clientIpAddress=10.42.59.14 server=dev-pdp-0.pdp.onap.svc.cluster.local MetricEndTimestamp=2018-05-06T22:22:45.172+00:00 targetEntity=POLICY partnerName=USER serviceName=POLICY TransactionEndTimestamp=2018-05-06T22:22:45.174+00:00 StatusCode=COMPLETE TransactionElapsedTime=3 requestId=538802c0-c8e0-4296-80c9-6dfe367effd0 serverIpAddress=10.42.209.41 ClassName= targetServiceName=PE Process MetricElapsedTime=0 TransactionBeginTimestamp=2018-05-06T22:22:45.171+00:00 MetricBeginTimestamp=2018-05-06T22:22:45.172+00:00 statusCode=COMPLETE POLICY-500I INFO: — Sending Request to PAP : http://pap:9091/pap/?operation=create&apiflag=api&policyType=Config

      ==> xacml-pdp-rest/error.log <==
      2018-05-06 22:24:11,147 [http-nio-8081-exec-49] ERROR com.att.eelf.error clientIpAddress=10.42.59.14 ErrorDescription=This is a general error message during the process. Please check the error message for detail information server=dev-pdp-0.pdp.onap.svc.cluster.localMetricEndTimestamp=2018-05-06T22:22:45.172+00:00 targetEntity=POLICY partnerName=USER serviceName=POLICY TransactionEndTimestamp=2018-05-06T22:22:45.174+00:00 StatusCode=COMPLETE TransactionElapsedTime=3 requestId=538802c0-c8e0-4296-80c9-6dfe367effd0 serverIpAddress=10.42.209.41 ClassName=org.onap.policy.utils.CryptoUtils targetServiceName=PE Process ErrorCode=POLICY-515E MetricElapsedTime=0 TransactionBeginTimestamp=2018-05-06T22:22:45.171+00:00 MetricBeginTimestamp=2018-05-06T22:22:45.172+00:00 statusCode=COMPLETE POLICY-515E ERROR: decryptTxtNoEx: Exception while decryption : javax.crypto.IllegalBlockSizeException: Input length must be multiple of 16 when decrypting with padded cipher

      ==> xacml-pdp-rest/debug.log <==
      2018-05-06 22:24:11,147 [http-nio-8081-exec-49] INFO com.att.eelf.debug clientIpAddress=10.42.59.14 ErrorDescription=This is a general error message during the process. Please check the error message for detail information server=dev-pdp-0.pdp.onap.svc.cluster.localMetricEndTimestamp=2018-05-06T22:22:45.172+00:00 targetEntity=POLICY partnerName=USER serviceName=POLICY TransactionEndTimestamp=2018-05-06T22:22:45.174+00:00 StatusCode=COMPLETE TransactionElapsedTime=3 requestId=538802c0-c8e0-4296-80c9-6dfe367effd0 serverIpAddress=10.42.209.41 ClassName= targetServiceName=PE Process ErrorCode=POLICY-515E MetricElapsedTime=0 TransactionBeginTimestamp=2018-05-06T22:22:45.171+00:00 MetricBeginTimestamp=2018-05-06T22:22:45.172+00:00 statusCode=COMPLETE POLICY-500I INFO: Using provided request ID: cd1254e3-c298-4ed3-b265-71645ab85bb9
      2018-05-06 22:24:11,534 [http-nio-8081-exec-49] DEBUG com.att.eelf.debug clientIpAddress=10.42.59.14 ErrorDescription=This is a general error message during the process. Please check the error message for detail information server=dev-pdp-0.pdp.onap.svc.cluster.localMetricEndTimestamp=2018-05-06T22:22:45.172+00:00 targetEntity=POLICY partnerName=USER serviceName=POLICY TransactionEndTimestamp=2018-05-06T22:22:45.174+00:00 StatusCode=COMPLETE TransactionElapsedTime=3 requestId=538802c0-c8e0-4296-80c9-6dfe367effd0 serverIpAddress=10.42.209.41 ClassName= targetServiceName=PE Process ErrorCode=POLICY-515E MetricElapsedTime=0 TransactionBeginTimestamp=2018-05-06T22:22:45.171+00:00 MetricBeginTimestamp=2018-05-06T22:22:45.172+00:00 statusCode=COMPLETE POLICY-500I INFO: connected to the PAP : http://pap:9091/pap/
      2018-05-06 22:24:11,534 [http-nio-8081-exec-49] DEBUG com.att.eelf.debug clientIpAddress=10.42.59.14 ErrorDescription=This is a general error message during the process. Please check the error message for detail information server=dev-pdp-0.pdp.onap.svc.cluster.localMetricEndTimestamp=2018-05-06T22:22:45.172+00:00 targetEntity=POLICY partnerName=USER serviceName=POLICY TransactionEndTimestamp=2018-05-06T22:22:45.174+00:00 StatusCode=COMPLETE TransactionElapsedTime=3 requestId=538802c0-c8e0-4296-80c9-6dfe367effd0 serverIpAddress=10.42.209.41 ClassName= targetServiceName=PE Process ErrorCode=POLICY-515E MetricElapsedTime=0 TransactionBeginTimestamp=2018-05-06T22:22:45.171+00:00 MetricBeginTimestamp=2018-05-06T22:22:45.172+00:00 statusCode=COMPLETE POLICY-500I INFO: — Response: —
      2018-05-06 22:24:11,534 [http-nio-8081-exec-49] DEBUG com.att.eelf.debug clientIpAddress=10.42.59.14 ErrorDescription=This is a general error message during the process. Please check the error message for detail information server=dev-pdp-0.pdp.onap.svc.cluster.localMetricEndTimestamp=2018-05-06T22:22:45.172+00:00 targetEntity=POLICY partnerName=USER serviceName=POLICY TransactionEndTimestamp=2018-05-06T22:22:45.174+00:00 StatusCode=COMPLETE TransactionElapsedTime=3 requestId=538802c0-c8e0-4296-80c9-6dfe367effd0 serverIpAddress=10.42.209.41 ClassName= targetServiceName=PE Process ErrorCode=POLICY-515E MetricElapsedTime=0 TransactionBeginTimestamp=2018-05-06T22:22:45.171+00:00 MetricBeginTimestamp=2018-05-06T22:22:45.172+00:00 statusCode=COMPLETE POLICY-500I INFO: Header :null Value: [HTTP/1.1 200 OK]
      2018-05-06 22:24:11,534 [http-nio-8081-exec-49] DEBUG com.att.eelf.debug clientIpAddress=10.42.59.14 ErrorDescription=This is a general error message during the process. Please check the error message for detail information server=dev-pdp-0.pdp.onap.svc.cluster.localMetricEndTimestamp=2018-05-06T22:22:45.172+00:00 targetEntity=POLICY partnerName=USER serviceName=POLICY TransactionEndTimestamp=2018-05-06T22:22:45.174+00:00 StatusCode=COMPLETE TransactionElapsedTime=3 requestId=538802c0-c8e0-4296-80c9-6dfe367effd0 serverIpAddress=10.42.209.41 ClassName= targetServiceName=PE Process ErrorCode=POLICY-515E MetricElapsedTime=0 TransactionBeginTimestamp=2018-05-06T22:22:45.171+00:00 MetricBeginTimestamp=2018-05-06T22:22:45.172+00:00 statusCode=COMPLETE POLICY-500I INFO: Header :Server Value: [Apache-Coyote/1.1]

        1. ks8-pap.txt
          879 kB
        2. ks8-pdp-0.txt
          300 kB

            jhh jhh
            jhh jhh
            Votes:
            0 Vote for this issue
            Watchers:
            5 Start watching this issue

              Created:
              Updated:
              Resolved: