Business Central Musings

For the things we have to learn before we can do them, we learn by doing them

Analysis of extension management using Telemetry

Share This Post

Business Central is a cloud-based, modular business management solution that can be customized and extended through the use of extensions. These extensions are packages of additional functionality that can be installed into the Business Central environment to provide additional features and capabilities. They can be developed by Microsoft, partners, or third-party developers, and can range from simple customizations to complex integrations with other systems.

On-Prem we run each needed PowerShell cmdlet one at a time, Publish-NAVApp, Sync-NAVApp, Start-NAVAppDataUpgrade or Install-NAVApp. When installing or upgrading an app in Business Central (cloud version) is a bit difficult to see what is actually performed in the environment. Hence the impressive importance of Telemetry logs in troubleshooting or auditing extensions issues.

With telemetry we get a better picture of what the system performs during an upgrade or update of an extension or even what is happening during an app un-installation. If you didn’t give telemetry a try you can start here.

Sneak peek on the blog content

I created 4 Hello World applications: App1, App2, App3 and App4. App1 is based on Microsoft set of applications (System, Base Application and Application) and App2 is based on App1 (dependency) and the set of Microsoft applications (System, Base Application and Application). App3 and App4 will be added later in the article.

The app.json for App1:

{
  "id": "99ce134e-1dac-4c4a-bfab-c2e207b01112",
  "name": "App 1",
  "publisher": "Silviu Virlan",
  "version": "1.0.0.6",
  "brief": "",
  "description": "",
  "privacyStatement": "",
  "EULA": "",
  "help": "",
  "url": "",
  "logo": "",
  "dependencies": [],
  "screenshots": [],
  "platform": "1.0.0.0",
  "application": "21.0.0.0",
  "idRanges": [
    {
      "from": 50300,
      "to": 50349
    }
  ],
  "resourceExposurePolicy": {
    "allowDebugging": true,
    "allowDownloadingSource": true,
    "includeSourceInSymbolFile": true
  },
  "runtime": "10.0",
  "features": [
    "NoImplicitWith"
  ]
}
The app.json for App2:
{
  "id": "7524c197-7156-4d16-b187-6ef443a1b3af",
  "name": "App 2",
  "publisher": "Silviu Virlan",
  "version": "1.0.0.4",
  "brief": "",
  "description": "",
  "privacyStatement": "",
  "EULA": "",
  "help": "",
  "url": "",
  "logo": "",
  "dependencies": [
    {
      "id": "99ce134e-1dac-4c4a-bfab-c2e207b01112",
      "name": "App 1",
      "publisher": "Silviu Virlan",
      "version": "1.0.0.1"
    }
  ],
  "screenshots": [],
  "platform": "1.0.0.0",
  "application": "21.0.0.0",
  "idRanges": [
    {
      "from": 50200,
      "to": 50249
    }
  ],
  "resourceExposurePolicy": {
    "allowDebugging": true,
    "allowDownloadingSource": true,
    "includeSourceInSymbolFile": true
  },
  "runtime": "10.0",
  "features": [
    "NoImplicitWith"
  ]
}
As described above, I drew a diagram of the topology of the first 2 extensions:

My environment is based on the latest Microsoft extensions:

I am going to cover straightaway a few operations with the 4 application and highlight the telemetry emitted in each case:

  1. Upgrade App1 via VS Code
  2. Upgrade App1 via Extension Management page
  3. Upgrade App2 via VS Code
  4. Upgrade App2 via Extension Management page
  5. Uninstall App1 via Extension Management page
  6. Uninstall App2 via Extension Management page
  7. Publish new App3 and add it as dependency to App2
  8. Publish new App4 who has App2 as dependency
  9. Un-install App3

Use Casses

1. Upgrade App1 via VS Code

Extension Old version New version Operation
App1 1.0.0.6 1.0.0.7 VS Code: Publish without debugging
    1. If you have an AppInsights service created in Azure Portal and if you enabled telemetry on your BC environment you should be able to run in Azure portal, under your AppInsights -> Logs the next KQL trace

 

    1. traces | where not (message has_any (“Authorization Succeeded”, “Web service”, “Task”)) and timestamp >= todatetime(‘2022-12-17T17:19:53.962227Z’)

 

[Please adjust your query to filter out other telemetry records to keep only data related to application extension update]

    The results of the query as operations get executed:
timestamp [Local Time] message
12/17/2022, 12:19:53.962 PM Extension un-installed successfully: App 2 version 1.0.0.4 by Silviu Virlan (7524c197-7156-4d16-b187-6ef443a1b3af)
12/17/2022, 12:19:54.055 PM Extension un-published successfully: App 2 version 1.0.0.4 by Silviu Virlan (7524c197-7156-4d16-b187-6ef443a1b3af)
12/17/2022, 12:20:00.415 PM Extension un-installed successfully: App 1 version 1.0.0.6 by Silviu Virlan (99ce134e-1dac-4c4a-bfab-c2e207b01112)
12/17/2022, 12:20:00.524 PM Extension un-published successfully: App 1 version 1.0.0.6 by Silviu Virlan (99ce134e-1dac-4c4a-bfab-c2e207b01112)
12/17/2022, 12:20:00.571 PM Extension compiled successfully: App 1 version 1.0.0.7 by Silviu Virlan (99ce134e-1dac-4c4a-bfab-c2e207b01112)
12/17/2022, 12:20:00.618 PM Extension published successfully: App 1 version 1.0.0.7 by Silviu Virlan (99ce134e-1dac-4c4a-bfab-c2e207b01112)
12/17/2022, 12:20:00.993 PM Extension synchronized successfully: App 1 version 1.0.0.7 by Silviu Virlan (99ce134e-1dac-4c4a-bfab-c2e207b01112)
12/17/2022, 12:20:08.025 PM Extension updated successfully: App 1 version 1.0.0.7 by Silviu Virlan (99ce134e-1dac-4c4a-bfab-c2e207b01112)
12/17/2022, 12:20:08.056 PM Extension compiled successfully: App 2 version 1.0.0.4 by Silviu Virlan (7524c197-7156-4d16-b187-6ef443a1b3af)
12/17/2022, 12:20:08.072 PM Extension published successfully: App 2 version 1.0.0.4 by Silviu Virlan (7524c197-7156-4d16-b187-6ef443a1b3af)
12/17/2022, 12:20:14.572 PM Dependent extension installed successfully: System Application version 21.2.49946.50677 by Microsoft (63ca2fa4-4f03-4f2b-a480-172fef340d3f)
12/17/2022, 12:20:14.572 PM Dependent extension installed successfully: Base Application version 21.2.49946.50677 by Microsoft (437dbf0e-84ff-417a-965d-ed2bb9650972)
12/17/2022, 12:20:14.572 PM Dependent extension installed successfully: Application version 21.2.49946.50300 by Microsoft (c1335042-3002-4257-bf8a-75c898ccb1b8)
12/17/2022, 12:20:14.572 PM Dependent extension installed successfully: App 1 version 1.0.0.7 by Silviu Virlan (99ce134e-1dac-4c4a-bfab-c2e207b01112)
12/17/2022, 12:20:14.619 PM Extension installed successfully: App 2 version 1.0.0.4 by Silviu Virlan (7524c197-7156-4d16-b187-6ef443a1b3af)
    And, if we were to distill all these into one picture:

2. Upgrade App1 via Extension Management page

As expected, traces logs look similar to Use Case 1. The only difference I noticed is that in Use Case 1, the user that published the extension from VS Code is recorded in traces table, whereas in Use Case 2 the user uploading the extension through page Extension Management is not recorded (yet):

3. Upgrade App2 via VS Code

Extension Old version New version Operation
App2 1.0.0.4 1.0.0.5 VS Code: Publish without debugging

For the same query as in Use Case 1 we get the following results:

timestamp [Local Time] message
12/17/2022, 1:27:30.345 PM Extension un-installed successfully: App 2 version 1.0.0.4 by Silviu Virlan (7524c197-7156-4d16-b187-6ef443a1b3af)
12/17/2022, 1:27:30.470 PM Extension un-published successfully: App 2 version 1.0.0.4 by Silviu Virlan (7524c197-7156-4d16-b187-6ef443a1b3af)
12/17/2022, 1:27:30.517 PM Extension compiled successfully: App 2 version 1.0.0.5 by Silviu Virlan (7524c197-7156-4d16-b187-6ef443a1b3af)
12/17/2022, 1:27:30.532 PM Extension published successfully: App 2 version 1.0.0.5 by Silviu Virlan (7524c197-7156-4d16-b187-6ef443a1b3af)
12/17/2022, 1:27:31.267 PM Extension synchronized successfully: App 2 version 1.0.0.5 by Silviu Virlan (7524c197-7156-4d16-b187-6ef443a1b3af)
12/17/2022, 1:27:46.517 PM Extension updated successfully: App 2 version 1.0.0.5 by Silviu Virlan (7524c197-7156-4d16-b187-6ef443a1b3af)

For a picture is worth lots of words, here it is:

4. Upgrade App2 via Extension Management page

Just like in Use Case 2, as expected, traces logs look similar to Use Case 1. Similarly, I noticed that in Use Case 3, the user that published the extension from VS Code is recorded in traces table, whereas in Use Case 4 the user uploading the extension through page Extension Management is not recorded (yet).

5. Uninstall App1 via Extension Management page

When we try un-installing App1, because we have App2 depending on App1, we get the following message:

Let’s go head and uninstall App1.

And by readjusting the timestamp to select only new logs we get:

timestamp [Local Time] message session_Id user_Id
12/17/2022, 1:58:56.276 PM Dependent extension un-installed successfully: App 2 version 1.0.0.5 by Silviu Virlan (7524c197-7156-4d16-b187-6ef443a1b3af) b726cf8d-7219-4493-89d7-95292978f17d N/A
12/17/2022, 1:58:56.276 PM Dependent extension un-installed successfully: App 2 version 1.0.0.2 by Silviu Virlan (7524c197-7156-4d16-b187-6ef443a1b3af) b726cf8d-7219-4493-89d7-95292978f17d N/A
12/17/2022, 1:58:56.276 PM Dependent extension un-installed successfully: App 2 version 1.0.0.3 by Silviu Virlan (7524c197-7156-4d16-b187-6ef443a1b3af) b726cf8d-7219-4493-89d7-95292978f17d N/A
12/17/2022, 1:58:56.276 PM Extension un-installed successfully: App 1 version 1.0.0.7 by Silviu Virlan (99ce134e-1dac-4c4a-bfab-c2e207b01112) b726cf8d-7219-4493-89d7-95292978f17d 332ddf79-565a-426a-b979-44701998949d

Notice how the user-initiated operation via Extension Management page is recorded in traces.user_id.

The user_id is the value of the field Telemetry ID on User record.

In effect, the diagram for this use case:

6. Uninstall App2 via Extension Management page

On the Extension Management page click on the App2 line that shows the latest version and it shows Is Installed = true.

We only get one trace log for this operation:

timestamp [Local Time] message user_Id
12/17/2022, 2:29:47.281 PM Extension un-installed successfully: App 2 version 1.0.0.5 by Silviu Virlan (7524c197-7156-4d16-b187-6ef443a1b3af) 332ddf79-565a-426a-b979-44701998949d

We can observe that User_Id is recorded.

Let’s go beyond current topology expanding horizontally the apps by adding a new extension App3 and add it as dependency to App2.

7. Publish new App3 and add it as dependency to App2

New app3 app.json source code:

{
  "id": "f16ffa35-0b2c-438d-9524-df7c67b7a6e9",
  "name": "App 3",
  "publisher": "Silviu Virlan",
  "version": "1.0.0.0",
  "brief": "",
  "description": "",
  "privacyStatement": "",
  "EULA": "",
  "help": "",
  "url": "",
  "logo": "",
  "dependencies": [],
  "screenshots": [],
  "platform": "1.0.0.0",
  "application": "21.0.0.0",
  "idRanges": [
    {
      "from": 50350,
      "to": 50359
    }
  ],
  "resourceExposurePolicy": {
    "allowDebugging": true,
    "allowDownloadingSource": true,
    "includeSourceInSymbolFile": true
  },
  "runtime": "10.0",
  "features": [
    "NoImplicitWith"
  ]
}

And let’s add it as dependency to App2:

{
  "id": "7524c197-7156-4d16-b187-6ef443a1b3af",
  "name": "App 2",
  "publisher": "Silviu Virlan",
  "version": "1.0.0.6",
  "brief": "",
  "description": "",
  "privacyStatement": "",
  "EULA": "",
  "help": "",
  "url": "",
  "logo": "",
  "dependencies": [
    {
      "id": "99ce134e-1dac-4c4a-bfab-c2e207b01112",
      "name": "App 1",
      "publisher": "Silviu Virlan",
      "version": "1.0.0.1"
    },
    {
      "id": "f16ffa35-0b2c-438d-9524-df7c67b7a6e9",
      "name": "App 3",
      "publisher": "Silviu Virlan",
      "version": "1.0.0.0"
    }
  ],
  "screenshots": [],
  "platform": "1.0.0.0",
  "application": "21.0.0.0",
  "idRanges": [
    {
      "from": 50200,
      "to": 50249
    }
  ],
  "resourceExposurePolicy": {
    "allowDebugging": true,
    "allowDownloadingSource": true,
    "includeSourceInSymbolFile": true
  },
  "runtime": "10.0",
  "features": [
    "NoImplicitWith"
  ]
}

First publish App3 and then publish App2.

Traces logs

And the trace logs show the order of the operations:

timestamp [Local Time] message user_Id
Publish App 2 12/17/2022, 8:11:59.237 PM Extension un-installed successfully: App 2 version 1.0.0.5 by Silviu Virlan (7524c197-7156-4d16-b187-6ef443a1b3af) 332ddf79-565a-426a-b979-44701998949d
12/17/2022, 8:11:59.237 PM Extension un-installed successfully: App 2 version 1.0.0.5 by Silviu Virlan (7524c197-7156-4d16-b187-6ef443a1b3af) 332ddf79-565a-426a-b979-44701998949d
12/17/2022, 8:11:59.378 PM Extension un-published successfully: App 2 version 1.0.0.5 by Silviu Virlan (7524c197-7156-4d16-b187-6ef443a1b3af) 332ddf79-565a-426a-b979-44701998949d
12/17/2022, 8:11:59.425 PM Extension compiled successfully: App 2 version 1.0.0.6 by Silviu Virlan (7524c197-7156-4d16-b187-6ef443a1b3af) 332ddf79-565a-426a-b979-44701998949d
12/17/2022, 8:11:59.456 PM Extension published successfully: App 2 version 1.0.0.6 by Silviu Virlan (7524c197-7156-4d16-b187-6ef443a1b3af) 332ddf79-565a-426a-b979-44701998949d
12/17/2022, 8:11:59.722 PM Extension synchronized successfully: App 2 version 1.0.0.6 by Silviu Virlan (7524c197-7156-4d16-b187-6ef443a1b3af) 332ddf79-565a-426a-b979-44701998949d
12/17/2022, 8:12:11.910 PM Extension updated successfully: App 2 version 1.0.0.6 by Silviu Virlan (7524c197-7156-4d16-b187-6ef443a1b3af) 332ddf79-565a-426a-b979-44701998949d
Publish App 3 12/17/2022, 7:59:30.166 PM Extension published successfully: App 3 version 1.0.0.0 by Silviu Virlan (f16ffa35-0b2c-438d-9524-df7c67b7a6e9) 332ddf79-565a-426a-b979-44701998949d
12/17/2022, 7:59:30.385 PM Extension synchronized successfully: App 3 version 1.0.0.0 by Silviu Virlan (f16ffa35-0b2c-438d-9524-df7c67b7a6e9) 332ddf79-565a-426a-b979-44701998949d
12/17/2022, 7:59:36.979 PM Dependent extension installed successfully: System Application version 21.2.49946.50677 by Microsoft (63ca2fa4-4f03-4f2b-a480-172fef340d3f) 332ddf79-565a-426a-b979-44701998949d
12/17/2022, 7:59:36.979 PM Dependent extension installed successfully: System Application version 21.2.49946.50677 by Microsoft (63ca2fa4-4f03-4f2b-a480-172fef340d3f) 332ddf79-565a-426a-b979-44701998949d
12/17/2022, 7:59:36.979 PM Dependent extension installed successfully: Base Application version 21.2.49946.50677 by Microsoft (437dbf0e-84ff-417a-965d-ed2bb9650972) 332ddf79-565a-426a-b979-44701998949d
12/17/2022, 7:59:36.979 PM Dependent extension installed successfully: Application version 21.2.49946.50300 by Microsoft (c1335042-3002-4257-bf8a-75c898ccb1b8) 332ddf79-565a-426a-b979-44701998949d
12/17/2022, 7:59:36.979 PM Extension installed successfully: App 3 version 1.0.0.0 by Silviu Virlan (f16ffa35-0b2c-438d-9524-df7c67b7a6e9) 332ddf79-565a-426a-b979-44701998949d

Consequently, this is the diagram of the 2 operations performed:

Let’s continue the expansion vertically through a new extension App4 and add App2 as a dependency to App4.

8. Publish new App4 who has App2 as dependency

New app App4 app.json source code:

{
    “id”: “7c58282b-1619-45ad-a8cd-54814e41c415”,
    “name”: “App 4”,
    “publisher”: “Silviu Virlan”,
    “version”: “1.0.0.0”,
    “brief”: “”,
    “description”: “”,
    “privacyStatement”: “”,
    “EULA”: “”,
    “help”: “”,
    “url”: “”,
    “logo”: “”,
    “dependencies”: [
      {
         “id”: “7524c197-7156-4d16-b187-6ef443a1b3af”,
         “name”: “App 2”,
         “publisher”: “Silviu Virlan”,
         “version”: “1.0.0.0”
      }
    ],
    “screenshots”: [],
    “platform”: “1.0.0.0”,
    “application”: “21.0.0.0”,
    “idRanges”: [
      {
        “from”: 50400,
        “to”: 50409
      }
    ],
    “resourceExposurePolicy”: {
      “allowDebugging”: true,
      “allowDownloadingSource”: true,
      “includeSourceInSymbolFile”: true
    },
    “runtime”: “10.0”,
    “features”: [
      “NoImplicitWith”
    ]
  }

Traces Logs

Publishing App4 shows the following trace logs:
timestamp [Local Time] message user_Id
12/17/2022, 8:53:11.659 PM Extension compiled successfully: App 4 version 1.0.0.0 by Silviu Virlan (7c58282b-1619-45ad-a8cd-54814e41c415) 332ddf79-565a-426a-b979-44701998949d
12/17/2022, 8:53:11.690 PM Extension published successfully: App 4 version 1.0.0.0 by Silviu Virlan (7c58282b-1619-45ad-a8cd-54814e41c415) 332ddf79-565a-426a-b979-44701998949d
12/17/2022, 8:53:12.394 PM Extension synchronized successfully: App 4 version 1.0.0.0 by Silviu Virlan (7c58282b-1619-45ad-a8cd-54814e41c415) 332ddf79-565a-426a-b979-44701998949d
12/17/2022, 8:53:19.269 PM Dependent extension installed successfully: System Application version 21.2.49946.50677 by Microsoft (63ca2fa4-4f03-4f2b-a480-172fef340d3f) 332ddf79-565a-426a-b979-44701998949d
12/17/2022, 8:53:19.269 PM Dependent extension installed successfully: System Application version 21.2.49946.50677 by Microsoft (63ca2fa4-4f03-4f2b-a480-172fef340d3f) 332ddf79-565a-426a-b979-44701998949d
12/17/2022, 8:53:19.269 PM Dependent extension installed successfully: System Application version 21.2.49946.50677 by Microsoft (63ca2fa4-4f03-4f2b-a480-172fef340d3f) 332ddf79-565a-426a-b979-44701998949d
12/17/2022, 8:53:19.269 PM Dependent extension installed successfully: Base Application version 21.2.49946.50677 by Microsoft (437dbf0e-84ff-417a-965d-ed2bb9650972) 332ddf79-565a-426a-b979-44701998949d
12/17/2022, 8:53:19.269 PM Dependent extension installed successfully: Base Application version 21.2.49946.50677 by Microsoft (437dbf0e-84ff-417a-965d-ed2bb9650972) 332ddf79-565a-426a-b979-44701998949d
12/17/2022, 8:53:19.269 PM Dependent extension installed successfully: Application version 21.2.49946.50300 by Microsoft (c1335042-3002-4257-bf8a-75c898ccb1b8) 332ddf79-565a-426a-b979-44701998949d
12/17/2022, 8:53:19.269 PM Dependent extension installed successfully: Application version 21.2.49946.50300 by Microsoft (c1335042-3002-4257-bf8a-75c898ccb1b8) 332ddf79-565a-426a-b979-44701998949d
12/17/2022, 8:53:19.269 PM Dependent extension installed successfully: App 3 version 1.0.0.0 by Silviu Virlan (f16ffa35-0b2c-438d-9524-df7c67b7a6e9) 332ddf79-565a-426a-b979-44701998949d
12/17/2022, 8:53:19.269 PM Dependent extension installed successfully: App 1 version 1.0.0.7 by Silviu Virlan (99ce134e-1dac-4c4a-bfab-c2e207b01112) 332ddf79-565a-426a-b979-44701998949d
12/17/2022, 8:53:19.269 PM Dependent extension installed successfully: App 2 version 1.0.0.6 by Silviu Virlan (7524c197-7156-4d16-b187-6ef443a1b3af) 332ddf79-565a-426a-b979-44701998949d
12/17/2022, 8:53:19.284 PM Extension installed successfully: App 4 version 1.0.0.0 by Silviu Virlan (7c58282b-1619-45ad-a8cd-54814e41c415) 332ddf79-565a-426a-b979-44701998949d

And accordingly, the diagram:

Finally, we are going to uninstall an app in the middle of the chain, for example App3, and we’ll record and diagram the telemetry logs:

9. Un-install App3

Attempting to un-install App3 we get notified that App4 and App2 are dependent on App3:

Go ahead and confirm un-installation.

Traces Logs

Let’s look at the telemetry traces logs:

timestamp [Local Time] message user_Id
12/17/2022, 9:12:07.443 PM Dependent extension un-installed successfully: App 4 version 1.0.0.0 by Silviu Virlan (7c58282b-1619-45ad-a8cd-54814e41c415) N/A
12/17/2022, 9:12:07.443 PM Dependent extension un-installed successfully: App 2 version 1.0.0.6 by Silviu Virlan (7524c197-7156-4d16-b187-6ef443a1b3af) N/A
12/17/2022, 9:12:07.443 PM Extension un-installed successfully: App 3 version 1.0.0.0 by Silviu Virlan (f16ffa35-0b2c-438d-9524-df7c67b7a6e9) 332ddf79-565a-426a-b979-44701998949d
12/17/2022, 9:12:07.443 PM Extension un-installed successfully: App 3 version 1.0.0.0 by Silviu Virlan (f16ffa35-0b2c-438d-9524-df7c67b7a6e9) 332ddf79-565a-426a-b979-44701998949d

Hence the diagram:

Conclusions

To sum up, I performed various operations with 4 basic extensions. Some were upgraded, some were uninstalled, and in some use cases I had first-time installs.

Therefore, if we deal with a (first time) installation, the app is verified if it compiles successfully, then is published and then is installed. The system also verifies all dependent apps (“lower apps”) are installed, including Microsoft apps. Use case 8.

Then, if we deal with an app upgrade, the older version of the app is un-installed and un-published. The new version is compiled and published, data-sync’d. If all these steps perform successfully the app is concluded updated successfully. See use cases 1, 2, 3, 4 and 7.

And lastly, if we deal with an app un-install, all “higher apps” (apps that have the un-installed app as dependency) will be un-installed at the same time with the app un-installed. See use case 5, 6 and 9.

Overall, extension management can be sometimes harder to understand when the hierarchy of extensions is complex, but telemetry has proved to be the right tool to employ when analyzing what the system is performing in any extension operation, including when these operations fail.

Share This Post

Related Articles

2 Responses

Leave a Reply

Recent Posts

Get Notified About New Posts

Categories
Verified by MonsterInsights