Group application insight logs by custom property

Today we found excessive number of logs in Application Insight instance, an application that usually cost few bucks each month, started to use more resources. Looking at a summary of last 30 days we see excessive number of custom events.

Figure 1: Application insight summary for a specific application

Now the problem is: how can I quickly spot out why we have an excessive number of CustomEvents? Logs shows me clearly that the vast majority of logs are indeed Custom Events. To have a better insight to detail of events, we need to use custom queries, first of all I grouped by name.

1
2
3
4
5

customEvents
| extend itemType = iif(itemType == 'customEvent',itemType,"")
| where (itemType == 'customEvent' and (timestamp >= datetime(2020-03-28T08:50:00.000Z) and timestamp <= datetime(2020-04-27T08:50:00.000Z))) 
| summarize Count = count() by name
| top 101 by Count desc

Thanks to powerful query language in Application Insight , we can simply summarize all custom events by name, to verify if some of the events are responsible for this increase of cost.

Figure 2. Summarize immediately found the events that is gone wrong

From Figure 2 it is really clear that almost all of the events are of type “CommandExecuted”. We are not using custom event extensively, one of the few custom event that we use is CommandExecuted, sent each time the server executes a command. Now my problem is: which command is responsible of most of the log?

Application Insight contains a really powerful language that allows me to group by and filter using both predefined properties or custom properties.

Lets look at a single instance of CommandExecuted events, to verify if we have some interesting custom property to further group by.

Figure 3. Each event has some interesting custom properties, one is the CommandType

From Figure 3 it is evident that CommandType Custom property is a good candidate for another group by. What I want is to be able to have a count for each distinct CommandType, but that property is indeed a custom property stored inside a dictionary. Thanks to AI we have a simple syntax for extending the resultset using a custom property or other dictionary data in the log.

1
2
3
4
5
6

customEvents
| extend itemType = iif(itemType == 'customEvent',itemType,"")
| extend CommandType = tostring( customDimensions.CommandType)
| where (itemType == 'customEvent' and (timestamp >= datetime(2020-03-28T08:50:00.000Z) and timestamp <= datetime(2020-04-27T08:50:00.000Z))) 
| summarize Count = count() by CommandType
| top 101 by Count desc

Thanks to the extend functionality, I’m able to ask to AI to create another column, called CommandType that is a conversion to string of customDinensions.CommandType. Once you extended the resultset and created a new CommandType column, I can summarize using that column obtaining the data I need.

Figure 4. Group by custom property result

Bingo, we have lots of commands related to user synchronization from active directory. This happens because the frequency of user active directory sync was increased and also some customers have really big Active Directory, with a lot of users. Each time the system scan active directory, thousands of commands are launched, and if the sync happens once an hour, or more frequently, you got some million of commands in an entire month.

Application Insight has a powerful query language that is able to filter and crunch an enormous amount of data, letting you group and filter even on your custom properties.

Thanks to Application Insight, I was able to spot out which events generated excessive amount of log, then I immediately remove those two specific commands from tracing. The team decided that we do not need to track CommandExecuted events generated by User Sync job.

If you are using Application Insight, I strongly suggest you to start exploring query capability, it is a really powerful tool to immediately find the information you need.

Gian Maria.