RPCManager-DSRequests, non-RPCManager-DSRequests and connection pooling

[Blama]

Hi Isomorphic,

in order to better understand connection pooling I tried to run our current 12.0p application with sql.pool.maxActive: 1 in server.properties.
This only works under special circumstances. When the client sends the 1st DSRequest, there is a problem on the server side
This is the relevant part of our MyIDACall-handleDSRequest() method:

                    // store dsHandleLog in database
                    // Long handlerequestID = LogIncomingRequest.addDSRequestLog(rpc, dsRequest, "IDA"); [B]// does not work with [I]maxActive: 1, [/I]dsRequest not executed then[/B]

                    // Execute the request
                    DSResponse handleDSResponse = super.handleDSRequest(dsRequest, rpc, context);

                    // update end date and status after the ds handle request
                    // LogIncomingRequest.updateDSRequestStatus(handlerequestID, handleDSResponse);[B]// does not work with [I]maxActive: 1, [/I]dsRequest not executed then[/B]

                    return handleDSResponse;

This way it works with maxActive: 1, but if I comment in again my logging calls, which are not part of the rpcManager transaction for obvious reasons (log entries should never be rolled-back), the data request is not executed after the SELECT is logged to the console. With logging it does work only with maxActive: 2 or more.

This is the (static) logging method:

    /**
     * Logs incoming DSRequest. Not part of a transaction, so also unsuccessful requests can be logged.
     *
     * [USER="45788"]param[/USER] rpc
     *          {@link RPCManager}
     * [USER="45788"]param[/USER] dsRequest
     *          {@link DSRequest}
     * [USER="45788"]param[/USER] type
     *          process type, "IDA" or "REST"
     * @return ID of the saved record in T_LOG_DSREQUEST, used to later update the end time and status of the request.
     * @throws Exception
     */
    public static Long addDSRequestLog(RPCManager rpc, DSRequest dsRequest, String type) throws Exception {
        Long userID = Long.valueOf(rpc.getUserId());
        Long sessionID = User.getUserSessionId(dsRequest.getHttpServletRequest());

        DSRequest addHandleRequest = new DSRequest(ServerDatasourceEnum.T_LOG_DSREQUEST.getValue(), DataSource.OP_ADD);

        // For requests after relogin this might happen.
        if (userID != -1)
            addHandleRequest.setUserId(userID.toString());

        Map<String, Object> valueMap = new HashMap<>();
        valueMap.put(ServerDatasourceFieldEnum.T_LOG_DSREQUEST__DATASOURCE.getValue(), StringUtils.left(dsRequest.getDataSourceName(), 50));
        valueMap.put(ServerDatasourceFieldEnum.T_LOG_DSREQUEST__OPERATIONTYPE.getValue(), StringUtils.left(dsRequest.getOperationType(), 20));
        valueMap.put(ServerDatasourceFieldEnum.T_LOG_DSREQUEST__OPERATIONID.getValue(), StringUtils.left(dsRequest.getOperationId(), 50));
        valueMap.put(ServerDatasourceFieldEnum.T_LOG_DSREQUEST__CRITERIA.getValue(),
                dsRequest.getCriteria() == null || dsRequest.getCriteria().size() == 0 ? null
                        : StringUtils.left(dsRequest.getCriteria().toString(), 2000));
        {
            Map<String, Object> dataMap = new HashMap<>();
            dataMap.putAll(valueMap);
            valueMap.put(ServerDatasourceFieldEnum.T_LOG_DSREQUEST__DATA.getValue(), StringUtils.left(dataMap.toString(), 2000));
        }
        valueMap.put(ServerDatasourceFieldEnum.T_LOG_DSREQUEST__STARTDATE.getValue(), new Timestamp(System.currentTimeMillis()));
        valueMap.put(ServerDatasourceFieldEnum.T_LOG_DSREQUEST__TYPE.getValue(), type);
        valueMap.put(ServerDatasourceFieldEnum.T_LOG_DSREQUEST__REMOTE_IP.getValue(),
                StringUtils.left(dsRequest.getHttpServletRequest().getRemoteAddr(), 40));

        // For requests that do not require a login, like ones through RestHandler, the sessionID will be -1
        if (sessionID == null || sessionID == -1)
            valueMap.put(ServerDatasourceFieldEnum.T_LOG_DSREQUEST__USER_SESSION_ID.getValue(), null);
        else
            valueMap.put(ServerDatasourceFieldEnum.T_LOG_DSREQUEST__USER_SESSION_ID.getValue(), sessionID);

        addHandleRequest.setValues(valueMap);
        DSResponse addHandleResponse = addHandleRequest.execute();
        if (addHandleResponse.statusIsError())
            return null;
        return Long.parseLong(addHandleResponse.getRecord().get(ServerDatasourceFieldEnum.T_LOG_DSREQUEST__ID.getValue()).toString());
    }

I wonder why the connection is not released for use after addHandleRequest.execute(). I don't see a reason why it is not.
I can see though in Eclipse that there is an undocumented method DSResponse.requestConnectionClose(). Is it somehow related to this?

Thank you & Best regards
Blama

[Isomorphic]

Releasing is done lazily, at the end of the HTTP request lifecycle.

[Blama]

Hi Isomorphic,

in general, this is OK for me, as I only have this special case (which will be replaced with network based logging instead of logging to the db eventually) and use sql.Oracle.autoJoinTransactions: true in server.properties, which is the equivalent of transactionPolicy: all. Default in an unmodified project is autoJoinTransactions: ANY_CHANGE in isomorphic_core_rpc.jar/framework.properties.

For me, this way, basically all client requests use a single connection, because they happen in the same transaction (+1 for the logging).

Now my colleague forgot this setting yesterday when configuring another database, so we were back to default.
And here the application did not work. The client starts with a queue of 12 easy requests with settings we need synchronously on the client and therefore cache there (perhaps a common pattern).
As the DBCP pool was configured sql.pool.maxActive: 10, sql.pool.whenExhaustedAction: block, the 11th request failed, as it could not get a new connection.

Is there some reason that every request needs its own connection? The requests are worked one after another. To me it seems like a waste of connections with no benefit.

Best regards
Blama

[Isomorphic]

While this is an odd edge case, we’ve gone ahead and made a change, just for 12.1, that would cause connections to be re-pooled sooner in a situation like this. Please try it out and let us know if it avoids your problem.