DISCLAIMER: App related source code shown here are for testing purposes only, and don't reflect best practices or recommended implementation.

File name: `nested-requests_0.0.1.zip`

An app that simulates a "nested request" scenario. It listens for `IPostMessageSent` events, and provides a slashcommand that sends a message. Executing the slashcommand will create a scenario where the event handler for `IPostMessageSent` will be triggered by the slashcommand executor handler.

This situation used to cause logs for the originating handler (the slashcommand executor, in this case) to disappear, and only the logs for the nested request (`IPostMessageSent` handler, in this case) would be persisted to the database.

<details>

<summary>App source code</summary>

export class NestedRequestsApp extends App implements IPostMessageSent {

public async executePostMessageSent(message: IMessage, _read: IRead, _http: IHttp, _persistence: IPersistence, _modify: IModify): Promise<void> {

this.getLogger().debug('executed_post_message_sent', message.id);

}

protected async extendConfiguration(configuration: IConfigurationExtend, _environmentRead: IEnvironmentRead): Promise<void> {

configuration.slashCommands.provideSlashCommand(new class implements ISlashCommand {

public command= 'nest';

public i18nParamsExample = 'nest';

public i18nDescription = 'nest';

public providesPreview = false;

constructor(private readonly app: IApp) { }

public async executor(context: SlashCommandContext, _read: IRead, modify: IModify, _http: IHttp, _persis: IPersistence): Promise<void> {

const [execId] = context.getArguments();

this.app.getLogger().debug('slashcommand_triggered', execId);

const mb = modify.getCreator().startMessage()

.setText(`nested_test_message ${execId}`)

.setRoom(context.getRoom());

const id = await modify.getCreator().finish(mb);

this.app.getLogger().debug('slashcommand_message_sent', id);

}

}(this));

}

}

</details>

export const appCausingNestedRequests = path.resolve(__dirname, './nested-requests_0.0.1.zip');

import { credentials, methodCall, request } from './api-data';

export const executeAppSlashCommand = (cmd: string, rid: string, params = '', triggerId = 'triggerId') =>

request

.post(methodCall('slashCommand'))

.set(credentials)

.send({

message: JSON.stringify({

id: 'id',

msg: 'method',

method: 'slashCommand',

params: [

{

cmd,

params,

triggerId,

msg: {

rid,

_id: 'message_id',

msg: `/${cmd} ${params}`.trim(),

},

},

],

}),

});

import type { ILoggerStorageEntry } from '@rocket.chat/apps-engine/server/logging';

import { expect } from 'chai';

import { after, before, describe, it } from 'mocha';

import { getCredentials, request, credentials } from '../../data/api-data';

import { appCausingNestedRequests } from '../../data/apps/app-packages';

import { apps } from '../../data/apps/apps-data';

import { cleanupApps, installLocalTestPackage } from '../../data/apps/helper';

import { loadHistory } from '../../data/rooms.helper';

import { executeAppSlashCommand } from '../../data/slashcommands.helpers';

import { IS_EE } from '../../e2e/config/constants';

(IS_EE ? describe : describe.skip)('Apps - Logs Nested Requests', () => {

before((done) => getCredentials(done));

after(() => cleanupApps());

it('should log nested requests without errors', async () => {

const app = await installLocalTestPackage(appCausingNestedRequests);

const roomId = 'GENERAL';

const execId = Math.random().toString(36).substring(2, 15);

const slashcommandRes = await executeAppSlashCommand('nest', roomId, execId);

expect(slashcommandRes.status, 'Slashcommand execution failed').to.equal(200);

const { messages } = await loadHistory(roomId);

const targetMessage = messages.find((msg) => msg.msg === `nested_test_message ${execId}`);

expect(targetMessage, 'Target message from nested request not found').to.exist;

// eslint-disable-next-line @typescript-eslint/no-non-null-assertion -- we're checking existence above

const { _id: messageId } = targetMessage!;

const logsRes = await request.get(apps(`/${app.id}/logs`)).set(credentials);

expect(logsRes.status, 'Fetching app logs failed').to.equal(200);

expect(logsRes.body, 'Apps logs response success is not true').to.have.a.property('success', true);

expect(logsRes.body, 'Apps logs response logs property is empty or missing')

.to.have.a.property('logs')

.that.is.an('array')

.with.lengthOf.greaterThan(0);

let slashcommandExecutionLog: ILoggerStorageEntry | undefined;

let postMessageExecutionLog: ILoggerStorageEntry | undefined;

logsRes.body.logs.forEach((log: ILoggerStorageEntry) => {

if ((log.method as string) === 'slashcommand:nest:executor' && log.entries.find((entry) => entry.args.includes(messageId))) {

slashcommandExecutionLog = log;

return;

}

if ((log.method as string) === 'app:executePostMessageSent' && log.entries.find((entry) => entry.args.includes(messageId))) {

postMessageExecutionLog = log;

}

});

expect(postMessageExecutionLog, 'IPostMessageSent execution log not found').to.exist;

expect(slashcommandExecutionLog, 'Slashcommand execution log not found').to.exist;

expect(

slashcommandExecutionLog?.entries.filter((entry) => entry.args.includes(execId)),

`Slashcommand execution log does not contain a matching execId "${execId}"`,

).to.have.lengthOf(1);

});

import { wrapComposedApp } from '../lib/wrapAppForRequest.ts';

const { logger } = request.context;

logger.debug(`${path}'s ${call} is being executed...`, requestData);

const result = await (method as Function).apply(wrapComposedApp(endpoint, request), [

logger.debug(`${path}'s ${call} was successfully executed.`);

logger.debug(`${path}'s ${call} was unsuccessful.`);

const app = new appClass(appPackage.info, request.context.logger, AppAccessorsInstance.getDefaultAppAccessors());

import { wrapAppForRequest } from '../../lib/wrapAppForRequest.ts';

export default async function handleInitialize(request: RequestContext): Promise<boolean> {

await app.initialize.call(

wrapAppForRequest(app, request),

AppAccessorsInstance.getConfigurationExtend(),

AppAccessorsInstance.getEnvironmentRead()

);

import { wrapAppForRequest } from '../../lib/wrapAppForRequest.ts';

export default async function handleOnDisable(request: RequestContext): Promise<boolean> {

await app.onDisable.call(wrapAppForRequest(app, request), AppAccessorsInstance.getConfigurationModify());