link_shared does not seem to be automatically calling ack()

[achlee888]

Recently Slack API has been turning off events for our app. Following up with developer support, they indicated that link_shared is timing out. Additionally, looking at our error logs, we do see these errors:

[Slack] An incoming event was not acknowledged within 3 seconds. Ensure that the ack() argument is called in a listener.

According to the bolt-js documentation, Event API events should automatically be acknowledged. There's also no way to ack from within the event listener callback.

@slack/bolt version

3.7.0

Your App and Receiver Configuration

  const installerOptions: HTTPReceiverOptions['installerOptions'] = {
    redirectUriPath: `${ROUTE_PREFIX}${SlackPublicEndpoints.REDIRECT}`,
    stateVerification: true,
    directInstall: true,
    installPath: `${ROUTE_PREFIX}${SlackPublicEndpoints.INSTALL}`,
  };

  const receiver = new HTTPReceiver({
    clientId: config.slackClientId || EMPTY_STRING,
    clientSecret: config.slackClientSecret || EMPTY_STRING,
    endpoints: [`${ROUTE_PREFIX}${SlackPublicEndpoints.EVENTS}`],
    installerOptions,
    installationStore: slackInstallationStore,
    logger: {
      debug: (message) => logger.debug(message),
      error: (message) => {
        if (message instanceof Error) {
          Sentry.captureException(message);
        }
        logger.error(message);
      },
      info: (message) => logger.info(message),
      warn: (message) => logger.warn(message),
      setLevel: (level: LogLevel) => {
        logger.level = level;
      },
      getLevel: () => logger.level as LogLevel,
      setName: () => undefined,
    },
    scopes: Array.from(requiredBaseBotScopes),
    signingSecret: config.slackSigningSecret,
    stateSecret: config.slackStateSecret,
  });
  const slack = new App({ receiver });

Node.js runtime version

v18.19.1

Steps to reproduce:

(Share the commands to run, source code, and project settings)

1. slack.event('link_shared', async ({ body, event }) => {}
2. 3 seconds>

Expected result:

ack() should be handled automatically

Actual result:

Seeing ack timeout errors:

[Slack] An incoming event was not acknowledged within 3 seconds. Ensure that the ack() argument is called in a listener.

[zimeg]

Hey @achlee888 👋 Does your slack.event listener have logs when handling these events? Just want to check that link_shared is at least being received correctly by the app!

[achlee888]

Yes, we do see link_shared events being received in the logs

[zimeg]

Oh interesting... I remember finding something about link_shared domains potentially being removed from event subscriptions when failure conditions for the Events API are met.

Could you check that these unfurl domains match what you'd expect? Not sure if that's the cause, but this might've happened 😬

[achlee888]

Yes, failure conditions (not responding to ack within 3 seconds) is what is causing our events being turned off.

The unfurl domains are set up correctly (works when testing individually and our customers are using the feature).

I believe the issue here is that slack is sending us link_shared events, and we are using app.event. However, the interface doesn't allow us to ack() directly from within app.event. This us unlock app.view or app.action where the callback params have ack available.

[zimeg]

The unfurl domains are set up correctly (works when testing individually and our customers are using the feature).

Meaning app.event is handling the request alright and you can make API calls after? That's interesting since event listeners should ack immediately without needing to respond in the listener 🤔

I tested this on both the latest version 3.19.0 and version 3.7.0 and found both acknowledge the link_shared event with debug logs like this:

[DEBUG]  socket-mode:SocketModeClient:0 Received a message on the WebSocket: {"envelope_id":"662045ef-0c07-4b1f-9bdc-11bf88590d14","payload":{"token":"example","team_id":"T01234","api_app_id":"A01234","event":{"type":"link_shared","user":"U01234","channel":"C01234","message_ts":"1719027000.313859","links":[{"url":"https:\/\/example.com","domain":"example.com"}],"source":"conversations_history","unfurl_id":"C01234.1719027000.313859.0123456789","is_bot_user_member":true,"event_ts":"1719027000.729587"},"type":"event_callback","event_id":"Ev0799PVABCD","event_time":1719027000,"authorizations":[{"enterprise_id":null,"team_id":"T01234","user_id":"U01234","is_bot":true,"is_enterprise_install":false}],"is_ext_shared_channel":false,"event_context":"4-example"},"type":"events_api","accepts_response_payload":false,"retry_attempt":0,"retry_reason":""}
[DEBUG]  socket-mode:SocketModeClient:0 Calling ack() - type: events_api, envelope_id: 662045ef-0c07-4b1f-9bdc-11bf88590d14, data: undefined

Is it possible that just the first log is appearing in logs? Or do logs only show the message that an "incoming event was not acknowledged within 3 seconds"?

[achlee888]

Yes, as far as we can tell app.event is handling things fine and everything works until Slack API disables our events. When we had followed up they said link_shared is causing these. Not sure how these are happening since from our end in our service logs, everything looks ok.

How do we enable debug logging? That could be helpful.

All we know is that link_shared supposedly is having a high failure rate. But we can't find out where and the one area we can think of is ack's not happening automatically. The handler calls a service that generates an image that takes more than 3 seoncds...but that shouldn't matter if ack's are happening immediately.

[zimeg]

I'm not so sure what might be causing this either - the image generation doesn't sound like it'd be a problem 📸 🤕

Using debug logs for a few attempts with the event might reveal something helpful! I'd be interested if you find things that seem strange or odd things otherwise 👀

const { App, LogLevel } = require('@slack/bolt');

const app = new App({
  ...
  logLevel: LogLevel.DEBUG,
});

[bsoe003]

Curious. Is it normal for POST request body to the events endpoint to be undefined?

I'm getting when i set logLevel to LogLevel.DEBUG:

ack() call begins (body: undefined)

ack() response sent (body: undefined)

After the second one, then we see our logs on our link_shared event listener (with all expected event information).

[zimeg]

@bsoe003 an undefined body shouldn't be a problem! The 200 response is the required part when acknowledging requests though other details can be included for different requests.

After the second one, then we see our logs on our link_shared event listener (with all expected event information).

This sounds good to me! The ack response is sent before listeners are processed so additional logs should follow that response. Does it seem like your app might not be acknowledging these otherwise?

[bsoe003]

👋 @zimeg,

Does it seem like your app might not be acknowledging these otherwise?

I had to manually override unhandledRequestHandler to set the response code as a 200. I'm not sure if the later version fixed this issue, but here the version of @slack/bolt for the reference: 3.12.2

[github-actions[bot]]

👋 It looks like this issue has been open for 30 days with no activity. We'll mark this as stale for now, and wait 10 days for an update or for further comment before closing this issue out. If you think this issue needs to be prioritized, please comment to get the thread going again! Maintainers also review issues marked as stale on a regular basis and comment or adjust status if the issue needs to be reprioritized.

[github-actions[bot]]

As this issue has been inactive for more than one month, we will be closing it. Thank you to all the participants! If you would like to raise a related issue, please create a new issue which includes your specific details and references this issue number.