Examples with ServiceSemaphore org.apache.ofbiz.service.semaphore.ServiceSemaphore used on opensource projects

Example 1 with ServiceSemaphore

use of org.apache.ofbiz.service.semaphore.ServiceSemaphore in project ofbiz-framework by apache.

the class ServiceDispatcher method runSync.

/**
 * Run the service synchronously and return the result.
 * @param localName Name of the context to use.
 * @param modelService Service model object.
 * @param params Map of name, value pairs composing the parameters.
 * @param validateOut Validate OUT parameters
 * @return Map of name, value pairs composing the result.
 * @throws ServiceAuthException
 * @throws ServiceValidationException
 * @throws GenericServiceException
 */
public Map<String, Object> runSync(String localName, ModelService modelService, Map<String, ? extends Object> params, boolean validateOut) throws ServiceAuthException, ServiceValidationException, GenericServiceException {
    long serviceStartTime = System.currentTimeMillis();
    Map<String, Object> result = new HashMap<>();
    ServiceSemaphore lock = null;
    Map<String, List<ServiceEcaRule>> eventMap = null;
    Map<String, Object> ecaContext = null;
    RunningService rs = null;
    DispatchContext ctx = localContext.get(localName);
    GenericEngine engine = null;
    Transaction parentTransaction = null;
    boolean isFailure = false;
    boolean isError = false;
    boolean beganTrans = false;
    try {
        // check for semaphore and acquire a lock
        if ("wait".equals(modelService.semaphore) || "fail".equals(modelService.semaphore)) {
            lock = new ServiceSemaphore(delegator, modelService);
            lock.acquire();
        }
        if (Debug.verboseOn() || modelService.debug) {
            if (Debug.verboseOn())
                Debug.logVerbose("[ServiceDispatcher.runSync] : invoking service " + modelService.name + " [" + modelService.location + "/" + modelService.invoke + "] (" + modelService.engineName + ")", module);
        }
        Map<String, Object> context = new HashMap<>();
        if (params != null) {
            context.putAll(params);
        }
        // check the locale
        Locale locale = this.checkLocale(context);
        // set up the running service log
        rs = this.logService(localName, modelService, GenericEngine.SYNC_MODE);
        // get eventMap once for all calls for speed, don't do event calls if it is null
        eventMap = ServiceEcaUtil.getServiceEventMap(modelService.name);
        engine = this.getGenericEngine(modelService.engineName);
        modelService.informIfDeprecated();
        // set IN attributes with default-value as applicable
        modelService.updateDefaultValues(context, ModelService.IN_PARAM);
        if (modelService.useTransaction) {
            if (TransactionUtil.isTransactionInPlace()) {
                // if a new transaction is needed, do it here; if not do nothing, just use current tx
                if (modelService.requireNewTransaction) {
                    parentTransaction = TransactionUtil.suspend();
                    if (TransactionUtil.isTransactionInPlace()) {
                        throw new GenericTransactionException("In service " + modelService.name + " transaction is still in place after suspend, status is " + TransactionUtil.getStatusString());
                    }
                    // now start a new transaction
                    beganTrans = TransactionUtil.begin(modelService.transactionTimeout);
                }
            } else {
                beganTrans = TransactionUtil.begin(modelService.transactionTimeout);
            }
            // enlist for XAResource debugging
            if (beganTrans && TransactionUtil.debugResources()) {
                DebugXaResource dxa = new DebugXaResource(modelService.name);
                try {
                    dxa.enlist();
                } catch (Exception e) {
                    Debug.logError(e, module);
                }
            }
        }
        try {
            int lockRetriesRemaining = LOCK_RETRIES;
            boolean needsLockRetry = false;
            do {
                // Ensure this is reset to false on each pass
                needsLockRetry = false;
                lockRetriesRemaining--;
                // setup global transaction ECA listeners to execute later
                if (eventMap != null) {
                    ServiceEcaUtil.evalRules(modelService.name, eventMap, "global-rollback", ctx, context, result, isError, isFailure);
                }
                if (eventMap != null) {
                    ServiceEcaUtil.evalRules(modelService.name, eventMap, "global-commit", ctx, context, result, isError, isFailure);
                }
                // pre-auth ECA
                if (eventMap != null) {
                    ServiceEcaUtil.evalRules(modelService.name, eventMap, "auth", ctx, context, result, isError, isFailure);
                }
                // check for pre-auth failure/errors
                isFailure = ServiceUtil.isFailure(result);
                isError = ServiceUtil.isError(result);
                context = checkAuth(localName, context, modelService);
                GenericValue userLogin = (GenericValue) context.get("userLogin");
                if (modelService.auth && userLogin == null) {
                    throw new ServiceAuthException("User authorization is required for this service: " + modelService.name + modelService.debugInfo());
                }
                // now that we have authed, if there is a userLogin, set the EE userIdentifier
                if (userLogin != null && userLogin.getString("userLoginId") != null) {
                    GenericDelegator.pushUserIdentifier(userLogin.getString("userLoginId"));
                }
                // pre-validate ECA
                if (eventMap != null) {
                    ServiceEcaUtil.evalRules(modelService.name, eventMap, "in-validate", ctx, context, result, isError, isFailure);
                }
                // check for pre-validate failure/errors
                isFailure = ServiceUtil.isFailure(result);
                isError = ServiceUtil.isError(result);
                // validate the context
                if (modelService.validate && !isError && !isFailure) {
                    try {
                        modelService.validate(context, ModelService.IN_PARAM, locale);
                    } catch (ServiceValidationException e) {
                        Debug.logError(e, "Incoming context (in runSync : " + modelService.name + ") does not match expected requirements", module);
                        throw e;
                    }
                }
                // pre-invoke ECA
                if (eventMap != null) {
                    ServiceEcaUtil.evalRules(modelService.name, eventMap, "invoke", ctx, context, result, isError, isFailure);
                }
                // check for pre-invoke failure/errors
                isFailure = ServiceUtil.isFailure(result);
                isError = ServiceUtil.isError(result);
                // ===== invoke the service =====
                if (!isError && !isFailure) {
                    Map<String, Object> invokeResult = null;
                    invokeResult = engine.runSync(localName, modelService, context);
                    engine.sendCallbacks(modelService, context, invokeResult, GenericEngine.SYNC_MODE);
                    if (invokeResult != null) {
                        result.putAll(invokeResult);
                    } else {
                        Debug.logWarning("Service (in runSync : " + modelService.name + ") returns null result", module);
                    }
                }
                // re-check the errors/failures
                isFailure = ServiceUtil.isFailure(result);
                isError = ServiceUtil.isError(result);
                if (beganTrans) {
                    // crazy stuff here: see if there was a deadlock or other such error and if so retry... which we can ONLY do if we own the transaction!
                    String errMsg = ServiceUtil.getErrorMessage(result);
                    // service is written to not ignore it of course!
                    if (errMsg != null && errMsg.toUpperCase(Locale.getDefault()).indexOf("DEADLOCK") >= 0) {
                        // it's a deadlock! retry...
                        String retryMsg = "RETRYING SERVICE [" + modelService.name + "]: Deadlock error found in message [" + errMsg + "]; retry [" + (LOCK_RETRIES - lockRetriesRemaining) + "] of [" + LOCK_RETRIES + "]";
                        // make sure the old transaction is rolled back, and then start a new one
                        // if there is an exception in these things, let the big overall thing handle it
                        TransactionUtil.rollback(beganTrans, retryMsg, null);
                        beganTrans = TransactionUtil.begin(modelService.transactionTimeout);
                        // enlist for XAResource debugging
                        if (beganTrans && TransactionUtil.debugResources()) {
                            DebugXaResource dxa = new DebugXaResource(modelService.name);
                            try {
                                dxa.enlist();
                            } catch (Exception e) {
                                Debug.logError(e, module);
                            }
                        }
                        if (!beganTrans) {
                            // just log and let things roll through, will be considered an error and ECAs, etc will run according to that
                            Debug.logError("After rollback attempt for lock retry did not begin a new transaction!", module);
                        } else {
                            // deadlocks can be resolved by retring immediately as conflicting operations in the other thread will have cleared
                            needsLockRetry = true;
                            // reset state variables
                            result = new HashMap<>();
                            isFailure = false;
                            isError = false;
                            Debug.logWarning(retryMsg, module);
                        }
                        // - MySQL ? lock wait timeout string: "Lock wait timeout exceeded; try restarting transaction"
                        if (errMsg.indexOf("A lock could not be obtained within the time requested") >= 0 || errMsg.indexOf("Lock wait timeout exceeded") >= 0) {
                        // TODO: add to run after parent tx
                        }
                    }
                }
            } while (needsLockRetry && lockRetriesRemaining > 0);
            // create a new context with the results to pass to ECA services; necessary because caller may reuse this context
            ecaContext = new HashMap<>();
            ecaContext.putAll(context);
            // copy all results: don't worry parameters that aren't allowed won't be passed to the ECA services
            ecaContext.putAll(result);
            // setup default OUT values
            modelService.updateDefaultValues(context, ModelService.OUT_PARAM);
            // validate the result
            if (modelService.validate && validateOut) {
                // pre-out-validate ECA
                if (eventMap != null) {
                    ServiceEcaUtil.evalRules(modelService.name, eventMap, "out-validate", ctx, ecaContext, result, isError, isFailure);
                }
                try {
                    modelService.validate(result, ModelService.OUT_PARAM, locale);
                } catch (ServiceValidationException e) {
                    throw new GenericServiceException("Outgoing result (in runSync : " + modelService.name + ") does not match expected requirements", e);
                }
            }
            // pre-commit ECA
            if (eventMap != null) {
                ServiceEcaUtil.evalRules(modelService.name, eventMap, "commit", ctx, ecaContext, result, isError, isFailure);
            }
            // check for pre-commit failure/errors
            isFailure = ServiceUtil.isFailure(result);
            isError = ServiceUtil.isError(result);
            // global-commit-post-run ECA, like global-commit but gets the context after the service is run
            if (eventMap != null) {
                ServiceEcaUtil.evalRules(modelService.name, eventMap, "global-commit-post-run", ctx, ecaContext, result, isError, isFailure);
            }
            // check for failure and log on info level; this is used for debugging
            if (isFailure) {
                Debug.logWarning("Service Failure [" + modelService.name + "]: " + ServiceUtil.getErrorMessage(result), module);
            }
        } catch (Throwable t) {
            if (Debug.timingOn()) {
                UtilTimer.closeTimer(localName + " / " + modelService.name, "Sync service failed...", module);
            }
            String errMsg = "Service [" + modelService.name + "] threw an unexpected exception/error";
            engine.sendCallbacks(modelService, context, t, GenericEngine.SYNC_MODE);
            try {
                TransactionUtil.rollback(beganTrans, errMsg, t);
            } catch (GenericTransactionException te) {
                Debug.logError(te, "Cannot rollback transaction", module);
            }
            rs.setEndStamp();
            if (t instanceof ServiceAuthException) {
                throw (ServiceAuthException) t;
            } else if (t instanceof ServiceValidationException) {
                throw (ServiceValidationException) t;
            } else if (t instanceof GenericServiceException) {
                throw (GenericServiceException) t;
            } else {
                throw new GenericServiceException("Service [" + modelService.name + "] Failed" + modelService.debugInfo(), t);
            }
        } finally {
            // if there was an error, rollback transaction, otherwise commit
            if (isError) {
                String errMsg = "Error in Service [" + modelService.name + "]: " + ServiceUtil.getErrorMessage(result);
                Debug.logError(errMsg, module);
                // rollback the transaction
                try {
                    TransactionUtil.rollback(beganTrans, errMsg, null);
                } catch (GenericTransactionException e) {
                    Debug.logError(e, "Could not rollback transaction: " + e.toString(), module);
                }
            } else {
                // commit the transaction
                try {
                    TransactionUtil.commit(beganTrans);
                } catch (GenericTransactionException e) {
                    GenericDelegator.popUserIdentifier();
                    String errMsg = "Could not commit transaction for service [" + modelService.name + "] call";
                    Debug.logError(e, errMsg, module);
                    if (e.getMessage() != null) {
                        errMsg = errMsg + ": " + e.getMessage();
                    }
                    throw new GenericServiceException(errMsg);
                }
            }
            // call notifications -- event is determined from the result (success, error, fail)
            modelService.evalNotifications(this.getLocalContext(localName), context, result);
            // clear out the EE userIdentifier
            GenericDelegator.popUserIdentifier();
        }
    } catch (GenericTransactionException te) {
        Debug.logError(te, "Problems with the transaction", module);
        throw new GenericServiceException("Problems with the transaction.", te.getNested());
    } finally {
        if (lock != null) {
            // release the semaphore lock
            try {
                lock.release();
            } catch (GenericServiceException e) {
                Debug.logWarning(e, "Exception thrown while unlocking semaphore: ", module);
            }
        }
        // resume the parent transaction
        if (parentTransaction != null) {
            try {
                TransactionUtil.resume(parentTransaction);
            } catch (GenericTransactionException ite) {
                Debug.logWarning(ite, "Transaction error, not resumed", module);
                throw new GenericServiceException("Resume transaction exception, see logs");
            }
        }
    }
    // pre-return ECA
    if (eventMap != null) {
        ServiceEcaUtil.evalRules(modelService.name, eventMap, "return", ctx, ecaContext, result, isError, isFailure);
    }
    rs.setEndStamp();
    long timeToRun = System.currentTimeMillis() - serviceStartTime;
    long showServiceDurationThreshold = UtilProperties.getPropertyAsLong("service", "showServiceDurationThreshold", 0);
    long showSlowServiceThreshold = UtilProperties.getPropertyAsLong("service", "showSlowServiceThreshold", 1000);
    if (Debug.timingOn() && timeToRun > showServiceDurationThreshold) {
        Debug.logTiming("Sync service [" + localName + "/" + modelService.name + "] finished in [" + timeToRun + "] milliseconds", module);
    } else if (Debug.infoOn() && timeToRun > showSlowServiceThreshold) {
        Debug.logTiming("Slow sync service execution detected: service [" + localName + "/" + modelService.name + "] finished in [" + timeToRun + "] milliseconds", module);
    }
    if ((Debug.verboseOn() || modelService.debug) && timeToRun > 50 && !modelService.hideResultInLog) {
        // Sanity check - some service results can be multiple MB in size. Limit message size to 10K.
        String resultStr = result.toString();
        if (resultStr.length() > 10240) {
            resultStr = resultStr.substring(0, 10226) + "...[truncated]";
        }
        if (Debug.verboseOn())
            Debug.logVerbose("Sync service [" + localName + "/" + modelService.name + "] finished with response [" + resultStr + "]", module);
    }
    if (modelService.metrics != null) {
        modelService.metrics.recordServiceRate(1, timeToRun);
    }
    return result;
}