topcoder-platform / taas-apis

5 stars 33 forks source link

[$40] Error in ES-Processor during local setup #420

Closed maxceem closed 3 years ago

maxceem commented 3 years ago

During local testing I've noticed that there is an error happens in ES Processor which doesn't happen on DEV or PROD.

When I create a new Resource Booking the corresponding Work Periods are created automatically. It could happen that Kafka Event about created Work Period comes earlier than event about create Resource Booking. In such cases we retry creating Work Period in ES after some time as per https://github.com/topcoder-platform/taas-apis/issues/296#issuecomment-853352093

But it looks like when ES Processor tries to send retry Kafka Event there is an error happens UnhandledPromiseRejectionWarning: Error: "AUTH0_URL" is required

See error log below:

tc-taas-es-processor | [2021-07-21T11:01:10.513Z] app INFO : Handle Kafka event message; Topic: taas.workperiod.create; Partition: 5; Offset: 0; Message: {"topic":"taas.workperiod.create","originator":"taas-api","timestamp":"2021-07-21T11:01:10.126Z","mime-type":"application/json","payload":{"resourceBookingId":"c114b22d-380e-4c25-a77a-b40623597f6a","startDate":"2022-09-25","endDate":"2022-10-01","daysWorked":4,"paymentStatus":"pending","daysPaid":0,"paymentTotal":0,"projectId":17234,"userHandle":"pshah_manager","id":"325ddff6-d333-492b-9327-380f2e1aac52","createdBy":"00000000-0000-0000-0000-000000000000","updatedAt":"2021-07-21T11:01:10.118Z","createdAt":"2021-07-21T11:01:10.118Z","updatedBy":null},"key":"resourceBooking.id:c114b22d-380e-4c25-a77a-b40623597f6a"}.
tc-taas-es-processor | [2021-07-21T11:01:10.513Z] app INFO : Handle Kafka event message; Topic: taas.resourcebooking.create; Partition: 4; Offset: 0; Message: {"topic":"taas.resourcebooking.create","originator":"taas-api","timestamp":"2021-07-21T11:01:09.517Z","mime-type":"application/json","payload":{"projectId":17234,"userId":"a55fe1bc-1754-45fa-9adc-cf3d6d7c377a","jobId":"bf19e7ee-5329-4cc9-96be-a4fea4e0371c","startDate":"2022-09-27","endDate":"2022-10-27","memberRate":13.23,"customerRate":13,"rateType":"hourly","billingAccountId":80000071,"status":"placed","id":"c114b22d-380e-4c25-a77a-b40623597f6a","createdBy":"57646ff9-1cd3-4d3c-88ba-eb09a395366c","updatedAt":"2021-07-21T11:01:09.508Z","createdAt":"2021-07-21T11:01:09.508Z","updatedBy":null}}.
tc-taas-es-processor | [2021-07-21T11:01:10.513Z] app DEBUG : Current message count: 8
tc-taas-es-processor | [2021-07-21T11:01:10.513Z] WorkPeriodProcessorService processCreate DEBUG : input arguments: { message: { topic: 'taas.workperiod.create', originator: 'taas-api', timestamp: '2021-07-21T11:01:10.126Z', 'mime-type': 'application/json', payload: { resourceBookingId: 'c114b22d-380e-4c25-a77a-b40623597f6a', startDate: '2022-09-25', endDate: '2022-10-01', daysWorked: 4, paymentStatus: 'pending', daysPaid: 0, paymentTotal: 0, projectId: 17234, userHandle: 'pshah_manager', id: '325ddff6-d333-492b-9327-380f2e1aac52', createdBy: '00000000-0000-0000-0000-000000000000', updatedAt: '2021-07-21T11:01:10.118Z', createdAt: '2021-07-21T11:01:10.118Z', updatedBy: null }, key: 'resourceBooking.id:c114b22d-380e-4c25-a77a-b40623597f6a' }, transactionId: 'transaction_9' }
tc-taas-es-processor | [2021-07-21T11:01:10.515Z] app DEBUG : Current message count: 9
tc-taas-es-processor | [2021-07-21T11:01:10.515Z] ResourceBookingProcessorService processCreate DEBUG : input arguments: { message: { topic: 'taas.resourcebooking.create', originator: 'taas-api', timestamp: '2021-07-21T11:01:09.517Z', 'mime-type': 'application/json', payload: { projectId: 17234, userId: 'a55fe1bc-1754-45fa-9adc-cf3d6d7c377a', jobId: 'bf19e7ee-5329-4cc9-96be-a4fea4e0371c', startDate: '2022-09-27', endDate: '2022-10-27', memberRate: 13.23, customerRate: 13, rateType: 'hourly', billingAccountId: 80000071, status: 'placed', id: 'c114b22d-380e-4c25-a77a-b40623597f6a', createdBy: '57646ff9-1cd3-4d3c-88ba-eb09a395366c', updatedAt: '2021-07-21T11:01:09.508Z', createdAt: '2021-07-21T11:01:09.508Z', updatedBy: null } }, transactionId: 'transaction_10' }
tc-taas-es-processor | [2021-07-21T11:01:10.523Z] ActionProcessorService scheduleRetry DEBUG : retry: 1 for topic: taas.workperiod.create id: 325ddff6-d333-492b-9327-380f2e1aac52
tc-taas-es-processor | [2021-07-21T11:01:10.523Z] WorkPeriodProcessorService processCreate WARN : id: c114b22d-380e-4c25-a77a-b40623597f6a "resource_booking" not found
tc-taas-es-processor | [2021-07-21T11:01:10.523Z] WorkPeriodProcessorService processCreate DEBUG : output arguments: undefined
tc-taas-es-processor | [2021-07-21T11:01:10.523Z] app DEBUG : Successfully processed message with count 8
tc-taas-es-processor | [2021-07-21T11:01:10.523Z] app DEBUG : Commiting offset after processing message with count 8
tc-taas-es-processor | [2021-07-21T11:01:10.877Z] ResourceBookingProcessorService processCreate DEBUG : output arguments: undefined
tc-taas-es-processor | [2021-07-21T11:01:10.877Z] app DEBUG : Successfully processed message with count 9
tc-taas-es-processor | [2021-07-21T11:01:10.877Z] app DEBUG : Commiting offset after processing message with count 9
tc-taas-es-processor | [2021-07-21T11:01:11.524Z] helper postEvent DEBUG : Posting event to Kafka topic taas.action.retry, {"originalTopic":"taas.workperiod.create","originalPayload":{"resourceBookingId":"c114b22d-380e-4c25-a77a-b40623597f6a","startDate":"2022-09-25","endDate":"2022-10-01","daysWorked":4,"paymentStatus":"pending","daysPaid":0,"paymentTotal":0,"projectId":17234,"userHandle":"pshah_manager","id":"325ddff6-d333-492b-9327-380f2e1aac52","createdBy":"00000000-0000-0000-0000-000000000000","updatedAt":"2021-07-21T11:01:10.118Z","createdAt":"2021-07-21T11:01:10.118Z","updatedBy":null},"retry":1}
tc-taas-es-processor | (node:178) UnhandledPromiseRejectionWarning: Error: "AUTH0_URL" is required
tc-taas-es-processor |     at module.exports (/opt/app/node_modules/@topcoder-platform/topcoder-bus-api-wrapper/index.js:23:11)
tc-taas-es-processor |     at getBusApiClient (/opt/app/src/common/helper.js:194:18)
tc-taas-es-processor |     at Object.postEvent (/opt/app/src/common/helper.js:217:18)
tc-taas-es-processor |     at /opt/app/src/services/ActionProcessorService.js:71:12
tc-taas-es-processor | (node:178) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 6)

It looks like ES Processor doesn't get AUTH0_URL environment variable even though I have .env file that have it:

AUTH0_URL=https://topcoder-dev.auth0.com/oauth/token
AUTH0_AUDIENCE=https://m2m.topcoder-dev.com/
AUTH0_AUDIENCE_UBAHN=https://u-bahn.topcoder.com
AUTH0_CLIENT_ID=...
AUTH0_CLIENT_SECRET=...

# necessary if you'll utilize email functionality of interviews
INTERVIEW_INVITATION_SENDGRID_TEMPLATE_ID=
INTERVIEW_INVITATION_SENDER_EMAIL=
# Locally deployed services (via docker-compose)
ES_HOST=http://dockerhost:9200
DATABASE_URL=postgres://postgres:postgres@dockerhost:5432/postgres
BUSAPI_URL=http://dockerhost:8002/v5

I've tried to fix it by changing the docker-compose.yaml (added AUTH0_* variables) but it didn't help

  taas-es-processor:
    container_name: tc-taas-es-processor
    build:
      context: ./generic-tc-service
      args:
        NODE_VERSION: 12.16.3
        GIT_URL: https://github.com/topcoder-platform/taas-es-processor
        GIT_BRANCH: dev
    command: start kafka-client
    ports:
      - 5001:5001
    depends_on:
      - kafka-client
      - elasticsearch
    environment:
      - KAFKA_URL=kafka:9093
      - ES_HOST=http://elasticsearch:9200
      - AUTH0_URL
      - AUTH0_AUDIENCE
      - AUTH0_CLIENT_ID
      - AUTH0_CLIENT_SECRET
      - AUTH0_PROXY_SERVER_URL

I've also tried to recreate containers by

npm run services:down

npm run services:up -- --force-recreate --build

We have to find a way on how to fix this issue, or how to correctly recreate containers so that this issue is fixed.

eisbilir commented 3 years ago

Recreation of containers is not needed after this fix, just run npm run services:up

maxceem commented 3 years ago

Hi @eisbilir

so far I've merged you PR and it works, but I'm still thinking on how to avoid creating the second config file.

There is a couple of ideas.

1. We can supply .env file to the docker-compose like this "services:up": "docker-compose -f ./local/docker-compose.yml --env-file .env up -d" see documentation https://docs.docker.com/compose/environment-variables/#the-env-file.

It looks like we can use these variables inside the docker-compose file like this ${AUTH_URL} and then pass to container like this:

  taas-es-processor:
    environment:
      - KAFKA_URL=kafka:9093
      - ES_HOST=http://elasticsearch:9200
      - AUTH0_URL="${AUTH0_URL}"
      - AUTH0_AUDIENCE="${AUTH0_AUDIENCE}"
      - AUTH0_CLIENT_ID="${AUTH0_CLIENT_ID}"
      - AUTH0_CLIENT_SECRET="${AUTH0_CLIENT_SECRET}"
      - AUTH0_PROXY_SERVER_URL="${AUTH0_PROXY_SERVER_URL}"

2. Another idea. Add to the NPM command services:up additional command which would populate env values from file to the system, but only during this command run. For example using https://www.npmjs.com/package/env-cmd or something similar, like this:

"services:up": "env-cmd docker-compose -f ./local/docker-compose.yml up -d",

which suppose to populate env variable during docker-compose run, and then in the docker-compose file do like:

  taas-es-processor:
    environment:
      - KAFKA_URL=kafka:9093
      - ES_HOST=http://elasticsearch:9200
      - AUTH0_URL
      - AUTH0_AUDIENCE
      - AUTH0_CLIENT_ID
      - AUTH0_CLIENT_SECRET
      - AUTH0_PROXY_SERVER_URL

Do you think something like this could work?

The main aim:

eisbilir commented 3 years ago

Good solutions, let me try both

eisbilir commented 3 years ago

@maxceem

425 followed solution 1.

maxceem commented 3 years ago

Challenge https://www.topcoder.com/challenges/a769e0af-9944-4e8d-ba6f-4ed7c26e00db has been created for this ticket.

This is an automated message for maxceem via Topcoder X

maxceem commented 3 years ago

Challenge https://www.topcoder.com/challenges/a769e0af-9944-4e8d-ba6f-4ed7c26e00db has been assigned to eisbilir.

This is an automated message for maxceem via Topcoder X

maxceem commented 3 years ago

This issue only to improves the local setup process. It cannot be QAed, so I'm closing it.

maxceem commented 3 years ago

Payment task has been updated: https://www.topcoder.com/challenges/a769e0af-9944-4e8d-ba6f-4ed7c26e00db Payments Complete Winner: eisbilir Copilot: maxceem Challenge a769e0af-9944-4e8d-ba6f-4ed7c26e00db has been paid and closed.

This is an automated message for maxceem via Topcoder X