System.Diagnostics.Tracing.EventListener增加CPU使用率

真相03

新成员
已加入
2020年12月15日
留言内容
3
编程经验
10+
你好

我在运行在Linux Docker容器中的netcoreapp3.1应用程序中使用了EventListener。
奇怪的是,尽管该应用程序没有执行任何其他操作,但我的应用程序的CPU使用率却随时间增加。
如果我将EventListener注释掉,则不会增加CPU使用率。

这是我的代码:
EventListener:
public class EnvironmentInfoService: EventListener, IEnvironmentInfoService
{
    private readonly ILogger<EnvironmentInfoService> m_logger;
    private readonly IOptions<EnvironmentInfoOptions> m_options;

    private readonly IList<EventSource> m_missedEvents = new List<EventSource>();
    private static readonly Dictionary<string, object> m_eventCounters = new Dictionary<string, object>();
    private static readonly Stopwatch m_watch = Stopwatch.StartNew();
    private static int m_eventsReceived = 0;

    public EnvironmentInfoService(ILogger<EnvironmentInfoService> logger, IOptions<EnvironmentInfoOptions> options)
    {
        m_logger = logger;
        m_options = options;

        lock (m_missedEvents)
        {
            foreach (var source in m_missedEvents)
            {
                OnEventSourceCreated(source);
            }
        }
    }

    protected override void OnEventSourceCreated(EventSource source)
    {
        if (m_options == null)
        {
            lock (m_missedEvents)
            {
                m_missedEvents.Add(source);
            }
        }
        else
        {
            if (m_options.Value.EnableEventCounters)
            {
                m_logger.LogInformation("Enable Event Source: '" + source.Guid + "/" + source.Name + "' EventCounterIntervalSec: " + m_options.Value.EventCounterIntervalSec);
                EnableEvents(source, EventLevel.Verbose, EventKeywords.All, new Dictionary<string, string>()
                {
                    ["EventCounterIntervalSec"] = m_options.Value.EventCounterIntervalSec.ToString()
                });
            }
        }
    }

    protected override void OnEventWritten(EventWrittenEventArgs eventData)
    {
        lock (m_watch)
        {
            m_eventsReceived++;
            if (m_watch.ElapsedMilliseconds > 1000 * 60 * 10)
            {
                m_logger.LogInformation("OnEventWritten: " + m_eventsReceived + " in " + m_watch.Elapsed.ToString());
                m_watch.Restart();
                m_eventsReceived = 0;
            }
        }

        if (!eventData.EventName.Equals("EventCounters"))
        {
            return;
        }

        lock (m_eventCounters)
        {
            m_logger.LogInformation("Source: '" + eventData.EventSource.Guid + "/" + eventData.EventSource.Name + "/" + eventData.Level + "/" + eventData.Keywords + "' Event: '" + eventData.EventId + "/" + eventData.EventName + "' EventCounters received: " + eventData.Payload.Count);
            for (int i = 0; i < eventData.Payload.Count; ++i)
            {
                if (eventData.Payload[i] is IDictionary<string, object> eventPayload)
                {
                    var (counterName, counterValue) = GetRelevantMetric(eventPayload);
                    m_eventCounters[counterName] = counterValue;
                    m_logger.LogInformation(i + " Source: '" + eventData.EventSource.Guid + "/" + eventData.EventSource.Name + "' Event: '" + eventData.EventId + "/" + eventData.EventName + "' EventCounter '" + counterName + "' received with value: " + counterValue);
                }
            }
        }
    }

    private static (string counterName, string counterValue) GetRelevantMetric(
    IDictionary<string, object> eventPayload)
    {
        var counterName = "";
        var counterValue = "";

        if (eventPayload.TryGetValue("DisplayName", out object displayValue))
        {
            counterName = displayValue.ToString();
        }
        if (eventPayload.TryGetValue("Mean", out object value) ||
            eventPayload.TryGetValue("Increment", out value))
        {
            counterValue = value.ToString();
        }

        return (counterName, counterValue);
    }
}

我已经添加了一些日志来分析问题,但是没有发现CPU使用率不断增加的任何原因。
2天之内,CPU使用率从0.7%增加到1.1%。
这不是很多,但是我在此计算机上运行了30个带有此EventListener的应用程序,因此总CPU使用率在2天内从大约20%增加到35%,在一周后增加到大约70%。

EnableEvents 针对不同来源启动应用程序后,该方法将被调用约10次(无重复)。
OnEventWritten 每分钟大约调用1000-2000个方法
EventCounterIntervalSec 是5分钟,我真的每5分钟就会得到EventCounters

这个事件"来源:'9ded64a4-414c-5251-dcf7-1e4e20c15e70 / Microsoft.AspNetCore.Hosting / LogAlways / None'事件:'-1 / EventCounters'"我每5分钟会得到4次,其中包括以下计数器名称:
要求费率
要求总数
当前请求
请求失败

这个事件"来源:'49592c0f-5a05-516d-aa4b-a64e02026c89 / System.Runtime / LogAlways / None'事件:'-1 / EventCounters'"我每5分钟会得到19次,其中包括以下计数器名称:
监视锁争用计数
线程池队列长度
ThreadPool完成的工作项计数
自上次GC以来在GC中的时间百分比
Gen 0大小
第一代尺寸
Gen 2大小
大小
分配率
装配件数
活动计时器数
工作集
GC堆大小
Gen 0 GC计数
第1代GC计数
第2代GC计数
例外计数
ThreadPool线程数
CPU使用率


有什么办法可以避免CPU使用率增加吗?

谢谢托马斯
 

跳伞

工作人员
已加入
2019年4月6日
留言内容
2,497
地点
弗吉尼亚州切萨皮克
编程经验
10+
Also: Have you considered what the downstream effects of writing to your m_logger are? E.g. Does it append to a file? Is the OS doing extra work as that file gets longer and longer? Is there AV software that scans modified files and the bigger the file, the more data to scan? Is the logger keeping an in memory list instead of a circular buffer? Is that in memory list getting bigger and bigger?
 

真相03

新成员
已加入
2020年12月15日
留言内容
3
编程经验
10+
Also: Have you considered what the downstream effects of writing to your m_logger are? E.g. Does it append to a file? Is the OS doing extra work as that file gets longer and longer? Is there AV software that scans modified files and the bigger the file, the more data to scan? Is the logger keeping an in memory list instead of a circular buffer? Is that in memory list getting bigger and bigger?

记录器是Elasticsearch接收器,因此日志将被发送到另一个Docker容器,并在那里被写入数据库。
但是,如果没有所有这些日志记录问题,问题是相同的。我添加了所有的m_logger ....行来查找问题。在添加这些行之前,问题就在那里。
 
最佳 底部