cap-js-community / event-queue

An event queue that enables secure multi-tenant enabled transactional processing of asynchronous events, featuring instant event processing with Redis Pub/Sub and load distribution across all application instances.
https://cap-js-community.github.io/event-queue/
Apache License 2.0
12 stars 1 forks source link

Processing event queue failed with unexpected error: Execution in new transaction failed: the user was already dropped before query execution #79

Closed js1972 closed 11 months ago

js1972 commented 11 months ago

Occasionally I have seen this error after my apps container starts up on cloud foundry. It triggers the container to get dumped and restarted then everything seems ok. I am creating a typical CAP app and using mbt build and cf deploy <mta>.

I am thinking this may actually be because an event fired during the update of services by cf deploy:

2023-12-05T10:22:14.99+0800 [APP/PROC/WEB/0] OUT [eventQueue/runner] - first event-queue run scheduled { firstRunScheduledFor: '2023-12-05T02:22:24.994Z' }
   2023-12-05T10:22:15.03+0800 [APP/PROC/WEB/0] ERR [eventQueue/processEventQueue] - Processing event queue failed with unexpected error. VError [ExecuteInNewTransactionError]: Execution in new transaction failed: the user was already dropped before query execution: B06246E7544E4A5392199C778C4BF2A3_4TMIDFQGRCZGMY1O749XXKHDW_RT
   2023-12-05T10:22:15.03+0800 [APP/PROC/WEB/0] ERR at Object.executeInNewTransaction (/home/vcap/app/node_modules/@cap-js-community/event-queue/src/shared/cdsHelper.js:69:15)
   2023-12-05T10:22:15.03+0800 [APP/PROC/WEB/0] ERR at process.processTicksAndRejections (node:internal/process/task_queues:95:5)
   2023-12-05T10:22:15.03+0800 [APP/PROC/WEB/0] ERR at async _acquireLockDB (/home/vcap/app/node_modules/@cap-js-community/event-queue/src/shared/distributedLock.js:91:3)
   2023-12-05T10:22:15.03+0800 [APP/PROC/WEB/0] ERR at async Object.acquireLock (/home/vcap/app/node_modules/@cap-js-community/event-queue/src/shared/distributedLock.js:14:12)
   2023-12-05T10:22:15.03+0800 [APP/PROC/WEB/0] ERR at async EventQueueDataSync.handleDistributedLock (/home/vcap/app/node_modules/@cap-js-community/event-queue/src/EventQueueProcessorBase.js:834:26)
   2023-12-05T10:22:15.03+0800 [APP/PROC/WEB/0] ERR at async processEventQueue (/home/vcap/app/node_modules/@cap-js-community/event-queue/src/processEventQueue.js:32:32)
   2023-12-05T10:22:15.03+0800 [APP/PROC/WEB/0] ERR at async runEventCombinationForTenant (/home/vcap/app/node_modules/@cap-js-community/event-queue/src/runner.js:238:14)
   2023-12-05T10:22:15.03+0800 [APP/PROC/WEB/0] ERR at async /home/vcap/app/node_modules/@cap-js-community/event-queue/src/runner.js:167:9 {
   2023-12-05T10:22:15.03+0800 [APP/PROC/WEB/0] ERR jse_shortmsg: 'Execution in new transaction failed',
   2023-12-05T10:22:15.03+0800 [APP/PROC/WEB/0] ERR jse_cause: [SqlError: the user was already dropped before query execution: B06246E7544E4A5392199C778C4BF2A3_4TMIDFQGRCZGMY1O749XXKHDW_RT] {
   2023-12-05T10:22:15.03+0800 [APP/PROC/WEB/0] ERR code: 402,
   2023-12-05T10:22:15.03+0800 [APP/PROC/WEB/0] ERR sqlState: 'HY000',
   2023-12-05T10:22:15.03+0800 [APP/PROC/WEB/0] ERR level: 1,
   2023-12-05T10:22:15.03+0800 [APP/PROC/WEB/0] ERR position: 0,
   2023-12-05T10:22:15.03+0800 [APP/PROC/WEB/0] ERR query: 'SELECT createdAt AS "createdAt", createdBy AS "createdBy", modifiedAt AS "modifiedAt", modifiedBy AS "modifiedBy", code AS "code", value AS "value" FROM sap_eventqueue_Lock ALIAS_1 WHERE code = ? LIMIT 1 FOR UPDATE WAIT 10',
   2023-12-05T10:22:15.03+0800 [APP/PROC/WEB/0] ERR values: [ '***' ]
   2023-12-05T10:22:15.03+0800 [APP/PROC/WEB/0] ERR },
   2023-12-05T10:22:15.03+0800 [APP/PROC/WEB/0] ERR jse_info: {},
   2023-12-05T10:22:15.03+0800 [APP/PROC/WEB/0] ERR cause: [Function: ve_cause]
   2023-12-05T10:22:15.03+0800 [APP/PROC/WEB/0] ERR } { eventType: 'DataSync_PERIODIC', eventSubType: 'DB' }

Here is my event-queue config:

periodicEvents:
  - type: DataSync
    subType: DB
    impl: ./srv/EventQueueSyncAdoptionTrackerData
    load: 100
    interval: 30

This is my event handler as its always a possibility that I'm doing something incredibly stupid:

"use strict";

const eventQueue = require("@cap-js-community/event-queue");
const cds = require("@sap/cds");
const axios = require('axios');

const LOG = cds.log("event-queue-periodic-handler");

class EventQueueDataSync extends eventQueue.EventQueueProcessorBase {
  constructor(context, eventType, eventSubType, config) {
    super(context, eventType, eventSubType, config);
  }

  // eslint-disable-next-line no-unused-vars
  async processPeriodicEvent(processContext, key, queueEntry) {
    LOG.info("Doing data sync with adoptiontracker");

    const customersService = await cds.connect.to("AdoptionTrackerCustomersService");
    const { Customers } = customersService.entities;

    let token = null;
    if (cds.env.production) {
      token = await this._fetchTokenFromXsuaaService();
    }

    let headers = {
      //Authorization: req.headers.authorization, // this only works when in a user request
      Authorization: 'Bearer ' + token
    };

    let result = await customersService.send({
        query: SELECT.from(Customers).limit(5),
        headers: headers,
    });

    LOG.info(`Found ${result.length} customers`);

    //const customerData = await fetchCustomerData();
    //await INSERT.into("Customer").entries(customerData);
  }

  async _fetchTokenFromXsuaaService() {  
    return new Promise (async (resolve, reject) => {
      let options1 = {
        method: 'POST',
        url: cds.env.requires.auth.credentials.url + '/oauth/token?grant_type=client_credentials',
        headers: {
            Authorization: 'Basic ' + Buffer.from(cds.env.requires.auth.credentials.clientid + ':' + cds.env.requires.auth.credentials.clientsecret).toString('base64')
        }
      };
      let res1 = await axios(options1);
      resolve(res1.data.access_token);

      // const XSUAA_CONFIG = xsenv.getServices({
      //   xsuaa: {tag: 'xsuaa'}
      // }).xsuaa;

      // LOG.info(`myXsuaa: ${JSON.stringify(XSUAA_CONFIG)}`);

      // xssec.requests.requestClientCredentialsToken(null, XSUAA_CONFIG, null, null, (error, token) => {
      //     if (error) {
      //         LOG.error('[_fetchTokenFromXsuaaService] ERROR: ' + error);
      //     }
      //     resolve(token);
      // });
    });
  }
}

module.exports = EventQueueDataSync;
soccermax commented 11 months ago

I could imagine that this issue occurs during the deployment process when replacing one container with another. The error messages suggest that the DB-User in the binding to your HANA HDI container is no longer valid. Therefore, I assume that the credentials for your "old" container have been revoked, but it is still running, while the new container is being spun up. Can you confirm this?