`Error: TeamsfxCLI.RunCommandFailed: Task 'Run Command' failed.`

[yozachar]

Describe the bug

When running teamsfx preview --env local I get Error: TeamsfxCLI.RunCommandFailed: Task 'Run Command' failed.

To Reproduce Steps to reproduce the behavior:

1. teamsfx new

   $ teamsfx new
   ? Teams Toolkit: Create a New App: Create a new app
   ? Capabilities: Basic Bot
   ? Programming Language: TypeScript
   ? Workspace folder: /home/us-er/TeamsApp
   ? Application name: epitoma
   ████████████████████  100% | [1/1] Generating Template  (✖) Done.

2. cd epitoma

3. teamsfx account show

   $ teamsfx account show
   Your Microsoft 365 account is: example-user@XXvsms.onmicrosoft.com.
   Your Azure account is: example-user@XXvsms.onmicrosoft.com. Your subscriptions are: []

4. ngrok http 3988

   $ ngrok http 3988
   ngrok                                                                         (Ctrl+C to quit)
   
   🤯 Try the ngrok Kubernetes Ingress Controller: https://ngrok.com/s/k8s-ingress               
   
   Session Status                online                                                          
   Session Expires               1 hour, 59 minutes                                              
   Terms of Service              https://ngrok.com/tos                                           
   Version                       3.3.1                                                           
   Region                        India (in)                                                      
   Latency                       -                                                               
   Web Interface                 http://127.0.0.1:4040                                           
   Forwarding                    https://EXAMPLE-ID.ngrok.io -> http://localhost:3978    
   
   Connections                   ttl     opn     rt1     rt5     p50     p90                     
                                 0       0       0.00    0.00    0.00    0.00   

5. Edit env/.env.local to add the following lines:

   BOT_DOMAIN=EXAMPLE-ID.ngrok.io
   BOT_ENDPOINT=https://EXAMPLE-ID.ngrok.io

6. teamsfx validate --env local

   $ teamsfx validate --env local
   ? Select Teams manifest.json file: /home/us-er/TeamsApp/epitoma/appPackage/manifest.json
   Teams Toolkit has completed checking your app package against validation rules. All passed. Check [Output panel](command:fx-extension.showOutputChannel) for details.

7. teamsfx provision --env local

   $ teamsfx provision --env local
   (√)Done: Teams Package /home/us-er/TeamsApp/epitoma/appPackage/build/appPackage.local.zip built successfully! 
   Teams Toolkit has checked against all validation rules:
   
   Summary: 
   48 passed.
   (√) Done: Package of your add-in was parsed successfully.
   (√) Done: Your package matches the submission type.
   (√) Done: undefined
   (√) Done: Manifest version is not missing and follows the guideline.
   (√) Done: Schema URL is present.
   (√) Done: Manifest Version and Schema version are the same
   (√) Done: Checking the existence of "id".
   (√) Done: Field 'id' is a Guid in the manifest.
   (√) Done: App version should not start with '0'.
   (√) Done: App version should contain only numbers separated by dots.
   (√) Done: Short name is not missing in the manifest
   (√) Done: Short name has the correct length
   (√) Done: Short name doesn't contain "Microsoft" or any of the "Microsoft product" names
   (√) Done: Short name doesn't contain beta environment keywords
   (√) Done: Short name is not reserved name.
   (√) Done: Short description is not missing
   (√) Done: Short description has the corrected length
   (√) Done: Short description doesn't contain copyrighted brand names
   (√) Done: Full description has the corrected length
   (√) Done: Full description doesn't contain copyrighted brand
   (√) Done: Full description does not repeat the same lines in short description
   (√) Done: Required field 'developer name' is missing in the manifest.
   (√) Done: Developer name has the correct length.
   (√) Done: Developer name is valid.
   (√) Done: Website URL is not missing in the manifest.
   (√) Done: Website URL has the correct length.
   (√) Done: Website URL is secure
   (√) Done: Website URL is valid and follows the guideline
   (√) Done: Privacy URL is not missing in the manifest.
   (√) Done: Privacy URL has the correct length
   (√) Done: Privacy URL is secure
   (√) Done: Privacy URL must not be hosted in the different domain as compared with Company/Website URL
   (√) Done: Privacy URL does not point to Beta environment
   (√) Done: Terms of use URL is not missing
   (√) Done: Terms of use URL has the correct length
   (√) Done: Term of use URL is secure
   (√) Done: Term of use URL does not point to Beta environment
   (√) Done: Term of use URL must not be hosted in the different domain as compared with Company/Website URL
   (√) Done: MPNID length cannot be more than 10 symbols
   (√) Done: Valid domains don't contain tunneling site
   (√) Done: Valid domains don't contain hosting site with a wildcard
   (√) Done: Large icon should be 192x192 with no transparency. Image icons are as per guidelines
   (√) Done: Small icon has the correct size (32x32)
   (√) Done: If the manifest has group chat scope for bots, then the manifest version must be at least 1.3
   (√) Done: BotId should be a Guid value.
   (√) Done: CommandList not present if 'IsNotificationOnly' is true in bot.
   (√) Done: StaticTabs are in personal scope
   (√) Done: Acceptance test service has finished checking provided add-in.
    
   ████████████████████  100% | [7/7] Provision  (✖) Done.
   Successfully executed 7/7 actions in provision stage.

8. teamsfx deploy --env local

   $ teamsfx deploy --env local
   Successfully executed 2/2 actions in deploy stage.
   ████████████████████  100% | [2/2] Deploy  (✖) Done.

9. Finally teamsfx preview --env local

   $ teamsfx preview --env local
   ████████████████████  100% | [1/1] Microsoft 365 Account  (✖) Done.
   Microsoft 365 Account (example-user@XXvsms.onmicrosoft.com) is logged in and sideloading enabled
   Option 'run-command' is not provided, set to: npm run dev:teamsfx 
   Run Command: Working folder - /home/us-er/TeamsApp/epitoma 
   Run Command: Executing command - npm run dev:teamsfx 
   Run Command: Running pattern - /started|successfully|finished|crashed|failed/i 
   Run Command: The log of this task can be found in: /home/us-er/.fx/cli-log/local-preview/2023-07-17T05_44_23_568Z/Run-Command.log 
   (x) Error: TeamsfxCLI.RunCommandFailed: Task 'Run Command' failed.
   ▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒  0% | [1/1] Run Command: npm run dev:teamsfx (✖) Failed.
   (x) Error: TeamsfxCLI.RunCommandFailed: Task 'Run Command' failed.

Expected behavior Application preview happens without any hiccups.

CLI Information (please complete the following information):

$ node --version
v18.16.1
$ teamsfx --version          
2.0.1
$ microsoft-edge-beta --version
Microsoft Edge 115.0.1901.175 beta
$ cat /etc/os-release                                                               
NAME="Arch Linux"
PRETTY_NAME="Arch Linux"
ID=arch
BUILD_ID=rolling
ANSI_COLOR="38;2;23;147;209"
HOME_URL="https://archlinux.org/"
DOCUMENTATION_URL="https://wiki.archlinux.org/"
SUPPORT_URL="https://bbs.archlinux.org/"
BUG_REPORT_URL="https://bugs.archlinux.org/"
PRIVACY_POLICY_URL="https://terms.archlinux.org/docs/privacy-policy/"
LOGO=archlinux-logo

Additional context

$ cat /home/us-er/.fx/cli-log/local-preview/2023-07-17T05_44_23_568Z/Run-Command.log
npm run dev:teamsfx
$ cat package.json
{
    "name": "epitoma",
    "version": "1.0.0",
    "description": "Microsoft Teams Toolkit hello world Bot sample",
    "engines": {
        "node": "16 || 18"
    },
    "author": "Microsoft",
    "license": "MIT",
    "main": "./lib/index.js",
    "scripts": {
        "dev:teamsfx": "env-cmd --silent -f .localConfigs npm run dev",
        "dev": "nodemon --exec node --inspect=9239 --signal SIGINT -r ts-node/register ./index.ts",
        "build": "tsc --build && shx cp -r ./adaptiveCards ./lib/",
        "start": "node ./lib/index.js",
        "watch": "nodemon --exec \"npm run start\"",
        "test": "echo \"Error: no test specified\" && exit 1"
    },
    "repository": {
        "type": "git",
        "url": "https://github.com"
    },
    "dependencies": {
        "@microsoft/adaptivecards-tools": "^1.0.0",
        "botbuilder": "^4.17.0",
        "restify": "^10.0.0"
    },
    "devDependencies": {
        "@types/restify": "^8.5.5",
        "@types/node": "^14.0.0",
        "env-cmd": "^10.1.0",
        "ts-node": "^10.4.0",
        "typescript": "^4.4.4",
        "nodemon": "^2.0.7",
        "shx": "^0.3.3"
    }
}

[ghost]

Thank you for contacting us! Any issue or feedback from you is quite important to us. We will do our best to fully respond to your issue as soon as possible. Sometimes additional investigations may be needed, we will usually get back to you within 2 days by adding comments to this issue. Please stay tuned.

[yozachar]

I've tried using devtunnel:

$ devtunnel host -p 8080
Hosting port: 8080
Connect via browser: https://EXAMPLE-ID.asse.devtunnels.ms:8080, https://EXAMPLE-ID-8080.asse.devtunnels.ms
Inspect network activity: https://EXAMPLE-ID-8080-inspect.asse.devtunnels.ms

Ready to accept connections for tunnel: rxt2jbxd

env/.env.local

BOT_DOMAIN=EXAMPLE-ID-8080.asse.devtunnels.ms
BOT_ENDPOINT=https://EXAMPLE-ID-8080.asse.devtunnels.ms

Then teamsfx provison, deploy and preview but preview fails with the same error.

[swatDong]

@joe733 , from your error log there's something like Run Command: The log of this task can be found in: \<some-path>, e.g.,

$ teamsfx preview --env local ... Run Command: The log of this task can be found in: /home/us-er/.fx/cli-log/local-preview/2023-07-17T05_44_23_568Z/Run-Command.log ...

Could you please check that log file and see if there's any detailed error message?

[yozachar]

Well yes, that's what I put in the additional context section. Here's today's

$ teamsfx preview --env local --verbose
████████████████████  100% | [1/1] Microsoft 365 Account  (✖) Done.
Microsoft 365 Account (example-user@XXvsms.onmicrosoft.com) is logged in and sideloading enabled
Option 'run-command' is not provided, set to: npm run dev:teamsfx 
Run Command: Working folder - /home/us-er/TeamsApp/epitoma 
Run Command: Executing command - npm run dev:teamsfx 
Run Command: Running pattern - /started|successfully|finished|crashed|failed/i 
Run Command: The log of this task can be found in: /home/us-er/.fx/cli-log/local-preview/2023-07-18T07_27_38_928Z/Run-Command.log 
(x) Error: TeamsfxCLI.RunCommandFailed: Task 'Run Command' failed.
▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒  0% | [1/1] Run Command: npm run dev:teamsfx (✖) Failed.
(x) Error: TeamsfxCLI.RunCommandFailed: Task 'Run Command' failed.

$ cat /home/us-er/.fx/cli-log/local-preview/2023-07-18T07_27_38_928Z/Run-Command.log
npm run dev:teamsfx

[swatDong]

Well yes, that's what I put in the additional context section. Here's today's

$ teamsfx preview --env local --verbose
████████████████████  100% | [1/1] Microsoft 365 Account  (✖) Done.
Microsoft 365 Account (example-user@XXvsms.onmicrosoft.com) is logged in and sideloading enabled
Option 'run-command' is not provided, set to: npm run dev:teamsfx 
Run Command: Working folder - /home/us-er/TeamsApp/epitoma 
Run Command: Executing command - npm run dev:teamsfx 
Run Command: Running pattern - /started|successfully|finished|crashed|failed/i 
Run Command: The log of this task can be found in: /home/us-er/.fx/cli-log/local-preview/2023-07-18T07_27_38_928Z/Run-Command.log 
(x) Error: TeamsfxCLI.RunCommandFailed: Task 'Run Command' failed.
▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒  0% | [1/1] Run Command: npm run dev:teamsfx (✖) Failed.
(x) Error: TeamsfxCLI.RunCommandFailed: Task 'Run Command' failed.

$ cat /home/us-er/.fx/cli-log/local-preview/2023-07-18T07_27_38_928Z/Run-Command.log
npm run dev:teamsfx

So there's only one line in Run-Command.log... It's weird. What if you directly run npm run dev:teamsfx?

[yozachar]

The program launches local instance, normally.

$ npm run dev:teamsfx

 > epitoma@1.0.0 dev:teamsfx
 > env-cmd --silent -f .localConfigs npm run dev

 > epitoma@1.0.0 dev
 > nodemon --exec node --inspect=9239 --signal SIGINT -r ts-node/register ./src/index.ts

 [nodemon] 2.0.22
 [nodemon] to restart at any time, enter `rs`
 [nodemon] watching path(s): *.*
 [nodemon] watching extensions: ts,json
 [nodemon] starting `node --inspect=9239 -r ts-node/register ./src/index.ts`
 Debugger listening on ws://127.0.0.1:9239/7a9d704f-9dae-4132-b353-13fafa937c4f
 For help, see: https://nodejs.org/en/docs/inspector
 (node:30338) [DEP0111] DeprecationWarning: Access to process.binding('http_parser') is deprecated.
 (Use `node --trace-deprecation ...` to show where the warning was created)

 Bot Started, restify listening to http://[::]:3978

[swatDong]

As workaround, please:

• npm run dev:teamsfx first to ensure local instance is running
• teamsfx preview --env local --run-command "" - passing empty value as run-command to skip running by teamsfx

For the original error, just a guess - npm log (stdout?, stderr?) is not correctly detected by teamsfx so the run command part times out. Need more investigation and repro.

[yozachar]

The workaround well.. works. Thanks!

Here's my repo https://gitea.com/joe733/epitoma

For the original error, just a guess - npm log (stdout?, stderr?) is not correctly detected by teamsfx so the run command part times out.

Or not properly reading from package.json?

[swatDong]

It works well on my Windows machine. I'll try your repo on a Linux machine. BTW, since the working folder and run command look correct, it should already read package.json.

[yozachar]

The workaround well.. works.

Not quite the way I figured.

In terminal 1:

$ devtunnel host -p 3978
Hosting port: 3978
Connect via browser: https://rjb9td35-3978.asse.devtunnels.ms
Inspect network activity: https://rjb9td35-3978-inspect.asse.devtunnels.ms

Ready to accept connections for tunnel: rjb9td35

Edited the env/.env.local to include:

BOT_DOMAIN=rjb9td35-3978.asse.devtunnels.ms
BOT_ENDPOINT=https://rjb9td35-3978.asse.devtunnels.ms

In terminal 2:

$ npm run dev:teamsfx

 > epitoma@1.0.0 dev:teamsfx
 > env-cmd --silent -f .localConfigs npm run dev

 > epitoma@1.0.0 dev
 > nodemon --exec node --inspect=9239 --signal SIGINT -r ts-node/register ./src/index.ts

 [nodemon] 2.0.22
 [nodemon] to restart at any time, enter `rs`
 [nodemon] watching path(s): *.*
 [nodemon] watching extensions: ts,json
 [nodemon] starting `node --inspect=9239 -r ts-node/register ./src/index.ts`
 Debugger listening on ws://127.0.0.1:9239/7a9d704f-9dae-4132-b353-13fafa937c4f
 For help, see: https://nodejs.org/en/docs/inspector
 (node:30338) [DEP0111] DeprecationWarning: Access to process.binding('http_parser') is deprecated.
 (Use `node --trace-deprecation ...` to show where the warning was created)

 Bot Started, restify listening to http://[::]:3978

In terminal 3:

$ teamsfx preview --env local --run-command ""
████████████████████  100% | [1/1] Microsoft 365 Account  (✖) Done.
Microsoft 365 Account (example-user@XXvsms.onmicrosoft.com) is logged in and sideloading enabled
Teams web client is being launched for you to preview the app: https://teams.microsoft.com/l/app/BOT_ID?installAppPackage=true&webjoin=true&appTenantId=TENANT_ID&login_hint=example-user%40XXvsms.onmicrosoft.com 
████████████████████  100% | [1/1] preview  (✖) Done.
(!) Warning: If you changed the manifest file, please run 'teamsfx provision --env local' to install app again.
$ 

The last command in terminal 3, does launch the bot in the browser, but then there's is no activity in the HTTPS tunnel. The bot is supposed to console.log stuff, but I cannot see that on terminal 2.

[swatDong]

After setting BOT_DOMAIN and BOT_ENDPOINT in env/.env.local, could you please run teamsfx provision --env local again?

To verify, you can view your bot registration on dev.botframework.com/bots?id= and there should be such Configuration on Settings page.

[yozachar]

So after teamsfx provision --env local I can see my app on dev.teams.microsoft.com/app

but not on portal.azure.com/#view/Microsoft_AAD_RegisteredApps/ApplicationsListBlade

Is that expected?

[swatDong]

There should be an AAD app on App registration. Since you are able to see your teams app on dev.teams.microsoft.com/app, can you also check if you can see the bot on dev.teams.microsoft.com/bots ?

[yozachar]

Yes, I see the bot and the endpoint.

[yozachar]

But tunnel still unresponsive (and portal.azure.com/#view/Microsoft_AAD_RegisteredApps/ApplicationsListBlade is still empty).

I've not made any change to the code yet:

$ git remote -v
origin  https://gitea.com/joe733/epitoma.git (fetch)
origin  https://gitea.com/joe733/epitoma.git (push)
$ git status
On branch main
Your branch is up to date with 'origin/main'.

nothing to commit, working tree clean

[swatDong]

I tried your repo from a clean state, and the app finally worked.

1. Still cannot repro the "Run Command" issue, but workaround works.

2. Since you are using devtunnel, please use parameter --allow-anonymous, e.g., devtunnel host -p 3978 --protocol http --allow-anonymous. Teams connects to your bot code via it's own Bot Authentication, so tunnel auth may break the bot auth.

3. For AAD App, please find it under "All applications" with BOT_ID.

   

[blackchoey]

So after teamsfx provision --env local I can see my app on dev.teams.microsoft.com/app

but not on portal.azure.com/#view/Microsoft_AAD_RegisteredApps/ApplicationsListBlade

Is that expected?

@joe733 For the problem that the AAD app does not show in your Owned applications tab, this should be an issue in Microsoft Graph API. We will report this for a fix. As you already have the client id and client secret, this issue won't impact your application. Please use the All applications tab to find related applications when needed.

[yozachar]

Thanks @swatDong & @blackchoey.

So just to wrap up, I was able to get the bot working with the following steps.

$ # Console 1: Create Project `AwesomeTeamsApp`
$ teamsfx new
$ cd AwesomeTeamsApp
$ teamsfx account login

$ # Console 2: Start tunnel
$ devtunnel host -p 3978 --protocol http --allow-anonymous
...

$ # Console 1: Edit environment variables
$ nano env/.env.local

BOT_DOMAIN=EXAMPLE-ID-PORT.asse.devtunnels.ms
BOT_ENDPOINT=https://EXAMPLE-ID-PORT.asse.devtunnels.ms

$ # Console 3: Run npm script
$ npm run dev:teamsfx
...

$ # Console 1: Launch AwesomeTeamsApp
$ teamsfx provision --env local
$ teamsfx deploy --env local
$ teamsfx preview --env local --run-command ""

---

Activity can bee seen in the tunnel.

Hosting port: 3978
Connect via browser: https://EXAMPLE-ID-3978.asse.devtunnels.ms
Inspect network activity: https://EXAMPLE-ID-3978-inspect.asse.devtunnels.ms

Ready to accept connections for tunnel: EXAMPLE-ID
ClientSSH: Channel forwarder closed connection.
ClientSSH: Channel forwarder closed connection.

and the bot is responding via console logs:

Bot Started, restify listening to http://[::]:3978

Received user input
No of attachments: 2
Asynchronous processing
        Handling attachment of class: 'application/vnd.microsoft.teams.file.download.info' & of type: 'txt'
        Handling attachment of class: 'text/html' & of type: 'txt'
        Attachment class: 'text/html' & of type: 'txt' isn't supported

        ==> Attempting to download: sample.txt of class: 'application/vnd.microsoft.teams.file.download.info' & of type: 'txt'
        ==> Download Source: https://XXvsms-my.sharepoint.com/personal/example-user_XXvsms_onmicrosoft_com/Documents/Microsoft Teams Chat Files/sample.txt
        ==> Download Error: 401 Unauthorized
        ==> Skipping unsupported attachment
Awaiting next user input

Also yes, I'm able to see bot under All applications tabs on Azure portal.

---

The Run Command failed error persists.

(x) Error: TeamsfxCLI.RunCommandFailed: Task 'Run Command' failed.
▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒▒  0% | [1/1] Run Command: npm run dev:teamsfx (✖) Failed.
(x) Error: TeamsfxCLI.RunCommandFailed: Task 'Run Command' failed.

And weirdly log file at /home/us-er/.fx/cli-log/local-preview/YYY-MM-DDT0HH_MM_SS_468Z/Run-Command.log contain a single line:

npm run dev:teamsfx

---

Edit:

I've made minor changes to the code, you may have to force pull.

[swatDong]

Good to know workaround works. For the Run Command failed issue, probably due to only listening on stdout (related source code). Created internal item to track the fix.