Web API：控制器中几乎相同操作的巨大 TTFB 时间差

【问题标题】：Web API: Huge TTFB time difference for almost identical actions in controllersWeb API：控制器中几乎相同操作的巨大 TTFB 时间差
【发布时间】：2020-04-20 16:06:24
【问题描述】：

我在 Azure 中的 Web API 存在一些 TTFB（待处理、等待）问题，我找不到原因，因为这两个操作使用相同的机制来返回分页列表的结果

Controller "Post" => Posts as PagedList => ~ 70-100ms (~80ms in local dev environment)

Controller "Page" => Pages as PagedList => ~ 1.100-1.200ms (~80ms in local dev environment)

我在使用分页列表的所有 3 个 API 中都有这些问题。有些分页列表操作可以正常工作，有些则不行。运行速度快的调用总是相同的，运行缓慢的调用总是相同的。

PagedList，基于微软推荐：

public class PagedList<T> : List<T>
{
    public int CurrentPage { get; set; }
    public int TotalPages { get; set; }
    public int PageSize { get; set; }
    public int TotalCount { get; set; }

    public PagedList(List<T> items, int count, int currentPage, int pageSize)
    {
        TotalCount = count;
        PageSize = pageSize;
        CurrentPage = currentPage;
        TotalPages = (int)Math.Ceiling(count / (double)pageSize);
        this.AddRange(items);
    }

    public bool HasPreviousPage
    {
        get { return (CurrentPage > 1); }
    }

    public bool HasNextPage
    {
        get { return (CurrentPage < TotalPages); }
    }

    public static async Task<PagedList<T>> CreateAsync(IQueryable<T> source, int pageIndex, int pageSize)
    {
        var count = await source.CountAsync();
        var items = await source.Skip((pageIndex - 1) * pageSize).Take(pageSize).ToListAsync();

        return new PagedList<T>(items, count, pageIndex, pageSize);
    }
}

分页类

public class Pagination
{
    private const int MaxPageSize = 50;
    public int PageNumber { get; set; } = 1;
    private int pageSize = 10;
    public int PageSize
    {
        get { return pageSize; }
        set { pageSize = (value > MaxPageSize) ? MaxPageSize : value; }
    }
}

public class BlogListPagination : Pagination
{
    public string SearchString { get; set; } = "";
    public int CategoryId { get; set; }
    public int TagId { get; set; }
}

public class PageListPagination : Pagination
{
    public string SearchString { get; set; } = "";        
}

后控制器

[HttpGet]
public async Task<ActionResult> PostsAsPagedList([FromQuery]BlogListPagination paginationParams)
{
    var posts = await _postService.GetPostsAsPagedList(paginationParams);

    var result = _mapper.Map<IEnumerable<PostShortListDto>>(posts);

    Response.AddPagination(posts.CurrentPage, posts.PageSize, posts.TotalCount, posts.TotalPages);

    if (posts == null)
        return BadRequest();
    else
        return Ok(result);
}

发布Dto

public class PostShortListDto
{
    public int Id { get; set; }
    public string Slug { get; set; }
    public string Title { get; set; }
    public string Abstract { get; set; }
    public string Author { get; set; }
    public DateTime Created { get; set; }
    public string Thumbnail { get; set; }
    public ICollection<CategoryDto> PostCategories { get; set; }
}

邮政服务

public async Task<PagedList<Post>> GetPostsAsPagedList(BlogListPagination paginationParams)
{
    IQueryable<Post> result;

    var posts = _context.Posts
        .Include(x => x.PostCategories)
            .ThenInclude(pc => pc.Category)
        .Include(x => x.PostTags)
            .ThenInclude(pt => pt.Tag)
        .AsQueryable();

    if (!string.IsNullOrEmpty(paginationParams.SearchString))
    {
        var cleanSearch = StripInput(paginationParams.SearchString);
        posts = posts.Where(x => x.Title.Contains(cleanSearch) || x.Content.Contains(cleanSearch));
    }

    if (paginationParams.CategoryId != 0)
    {
        posts = posts.Where(x => x.PostCategories.Any(y => y.CategoryId == paginationParams.CategoryId));
    }

    if (paginationParams.TagId != 0)
    {
        posts = posts.Where(x => x.PostTags.Any(y => y.TagId == paginationParams.TagId));
    }

    result = posts;

    result = result.OrderByDescending(x => x.Created);

    return await PagedList<Post>.CreateAsync(result, paginationParams.PageNumber, paginationParams.PageSize);
}

页面控制器

[HttpGet]
public async Task<ActionResult> PagesAsPagedList([FromQuery]PageListPagination paginationParams)
{
    var pages = await _pageService.GetPagesAsPagedList(paginationParams);

    var result = _mapper.Map<IEnumerable<PageShortDto>>(pages);

    Response.AddPagination(pages.CurrentPage, pages.PageSize, pages.TotalCount, pages.TotalPages);

    if (pages == null)
        return BadRequest();
    else
        return Ok(result);
}

页面Dto

public class PageShortDto
{
    public int Id { get; set; }
    public string Title { get; set; }
    public DateTime Created { get; set; }
}

页面服务

public async Task<PagedList<Page>> GetPagesAsPagedList(PageListPagination paginationParams)
{
    IQueryable<Page> result;

    var pages = _context.Pages.AsQueryable();

    if (!string.IsNullOrEmpty(paginationParams.SearchString))
    {
        var cleanSearch = StripInput(paginationParams.SearchString);
        pages = pages.Where(x => x.Title.Contains(cleanSearch) || x.Content.Contains(cleanSearch));
    }

    result = pages;

    result = result.OrderByDescending(x => x.Created);

    return await PagedList<Page>.CreateAsync(result, paginationParams.PageNumber, paginationParams.PageSize);
}

启动

services.AddTransient<IPostService, PostService>();
services.AddTransient<IPageService, PageService>();

虽然 Post 控制器中的调用更复杂，但它的执行速度快了 10 倍以上。

在 Azure 诊断中一切正常，没有显示错误。资源也不错。

您可以在浏览器中使用这 2 个 GET 请求或例如在此处检查行为。邮递员：

https://kombasapicontent.azurewebsites.net/api/post
https://kombasapicontent.azurewebsites.net/api/page

目前我不知道可能是什么原因，因为请求的行为总是相同的。

编辑（2 个请求的调试输出）：

帖子 => 数据库中的 33 个条目

Pages => 数据库中有 173 个条目

所以我们不谈论“海量”数据。

作为分页列表的帖子

info: Microsoft.AspNetCore.Hosting.Internal.WebHost[1]
      Request starting HTTP/1.1 GET https://localhost:5011/api/post
info: Microsoft.AspNetCore.Routing.EndpointMiddleware[0]
      Executing endpoint 'komBAS.API.Content.Controllers.PostController.PostsAsPagedList (komBAS.API.Content)'
info: Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker[1]
      Route matched with {action = "PostsAsPagedList", controller = "Post"}. Executing action komBAS.API.Content.Controllers.PostController.PostsAsPagedList (komBAS.API.Content)
info: Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker[1]
      Executing action method komBAS.API.Content.Controllers.PostController.PostsAsPagedList (komBAS.API.Content) with arguments (komBAS.API.Content.Models.Pagination.BlogListPagination) - Validation state: Valid
info: Microsoft.EntityFrameworkCore.Infrastructure[10403]
      Entity Framework Core 2.2.0-rtm-35687 initialized 'DataContext' using provider 'Microsoft.EntityFrameworkCore.SqlServer' with options: None
info: Microsoft.EntityFrameworkCore.Database.Command[20101]
      Executed DbCommand (2ms) [Parameters=[], CommandType='Text', CommandTimeout='30']
      SELECT COUNT(*)
      FROM [Posts] AS [x]
info: Microsoft.EntityFrameworkCore.Database.Command[20101]
      Executed DbCommand (3ms) [Parameters=[@__p_0='?' (DbType = Int32), @__p_1='?' (DbType = Int32)], CommandType='Text', CommandTimeout='30']
      SELECT [x].[Id], [x].[Abstract], [x].[Author], [x].[Content], [x].[Created], [x].[MetaDescription], [x].[MetaKeywords], [x].[PostType], [x].[ShowSocialSharing], [x].[Slug], [x].[Status], [x].[Thumbnail], [x].[Title]
      FROM [Posts] AS [x]
      ORDER BY [x].[Created] DESC, [x].[Id]
      OFFSET @__p_0 ROWS FETCH NEXT @__p_1 ROWS ONLY
info: Microsoft.EntityFrameworkCore.Database.Command[20101]
      Executed DbCommand (2ms) [Parameters=[@__p_0='?' (DbType = Int32), @__p_1='?' (DbType = Int32)], CommandType='Text', CommandTimeout='30']
      SELECT [x.PostCategories].[PostId], [x.PostCategories].[CategoryId], [p.Category].[Id], [p.Category].[Description], [p.Category].[IsVisible], [p.Category].[Name]
      FROM [PostCategories] AS [x.PostCategories]
      INNER JOIN [Categories] AS [p.Category] ON [x.PostCategories].[CategoryId] = [p.Category].[Id]
      INNER JOIN (
          SELECT [x0].[Id], [x0].[Created]
          FROM [Posts] AS [x0]
          ORDER BY [x0].[Created] DESC, [x0].[Id]
          OFFSET @__p_0 ROWS FETCH NEXT @__p_1 ROWS ONLY
      ) AS [t] ON [x.PostCategories].[PostId] = [t].[Id]
      ORDER BY [t].[Created] DESC, [t].[Id]
info: Microsoft.EntityFrameworkCore.Database.Command[20101]
      Executed DbCommand (1ms) [Parameters=[@__p_0='?' (DbType = Int32), @__p_1='?' (DbType = Int32)], CommandType='Text', CommandTimeout='30']
      SELECT [x.PostTags].[PostId], [x.PostTags].[TagId], [p.Tag].[Id], [p.Tag].[Name]
      FROM [PostTags] AS [x.PostTags]
      INNER JOIN [Tags] AS [p.Tag] ON [x.PostTags].[TagId] = [p.Tag].[Id]
      INNER JOIN (
          SELECT [x1].[Id], [x1].[Created]
          FROM [Posts] AS [x1]
          ORDER BY [x1].[Created] DESC, [x1].[Id]
          OFFSET @__p_0 ROWS FETCH NEXT @__p_1 ROWS ONLY
      ) AS [t0] ON [x.PostTags].[PostId] = [t0].[Id]
      ORDER BY [t0].[Created] DESC, [t0].[Id]
info: Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker[2]
      Executed action method komBAS.API.Content.Controllers.PostController.PostsAsPagedList (komBAS.API.Content), returned result Microsoft.AspNetCore.Mvc.OkObjectResult in 58.0013ms.
info: Microsoft.AspNetCore.Mvc.Infrastructure.ObjectResultExecutor[1]
      Executing ObjectResult, writing value of type 'System.Collections.Generic.List`1[[komBAS.API.Content.Dtos.PostShortListDto, komBAS.API.Content, Version=1.0.0.0, Culture=neutral, PublicKeyToken=null]]'.
info: Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker[2]
      Executed action komBAS.API.Content.Controllers.PostController.PostsAsPagedList (komBAS.API.Content) in 72.2734ms
info: Microsoft.AspNetCore.Routing.EndpointMiddleware[1]
      Executed endpoint 'komBAS.API.Content.Controllers.PostController.PostsAsPagedList (komBAS.API.Content)'
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[2]
      Request finished in 89.6201ms 200 application/json; charset=utf-8

Pages as Pages List（这是 Azure 中速度较慢的一种）

info: Microsoft.AspNetCore.Hosting.Internal.WebHost[1]
      Request starting HTTP/1.1 GET https://localhost:5011/api/page
info: Microsoft.AspNetCore.Routing.EndpointMiddleware[0]
      Executing endpoint 'komBAS.API.Content.Controllers.PageController.PagesAsPagedList (komBAS.API.Content)'
info: Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker[1]
      Route matched with {action = "PagesAsPagedList", controller = "Page"}. Executing action komBAS.API.Content.Controllers.PageController.PagesAsPagedList (komBAS.API.Content)
info: Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker[1]
      Executing action method komBAS.API.Content.Controllers.PageController.PagesAsPagedList (komBAS.API.Content) with arguments (komBAS.API.Content.Models.Pagination.PageListPagination) - Validation state: Valid
info: Microsoft.EntityFrameworkCore.Infrastructure[10403]
      Entity Framework Core 2.2.0-rtm-35687 initialized 'DataContext' using provider 'Microsoft.EntityFrameworkCore.SqlServer' with options: None
info: Microsoft.EntityFrameworkCore.Database.Command[20101]
      Executed DbCommand (11ms) [Parameters=[], CommandType='Text', CommandTimeout='30']
      SELECT COUNT(*)
      FROM [Pages] AS [x]
info: Microsoft.EntityFrameworkCore.Database.Command[20101]
      Executed DbCommand (2ms) [Parameters=[@__p_0='?' (DbType = Int32), @__p_1='?' (DbType = Int32)], CommandType='Text', CommandTimeout='30']
      SELECT [x].[Id], [x].[Content], [x].[ContentTag], [x].[Created], [x].[MetaDescription], [x].[MetaKeywords], [x].[NoIndex], [x].[PageType], [x].[Slug], [x].[Status], [x].[Title]
      FROM [Pages] AS [x]
      ORDER BY [x].[Created] DESC
      OFFSET @__p_0 ROWS FETCH NEXT @__p_1 ROWS ONLY
info: Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker[2]
      Executed action method komBAS.API.Content.Controllers.PageController.PagesAsPagedList (komBAS.API.Content), returned result Microsoft.AspNetCore.Mvc.OkObjectResult in 34.3177ms.
info: Microsoft.AspNetCore.Mvc.Infrastructure.ObjectResultExecutor[1]
      Executing ObjectResult, writing value of type 'System.Collections.Generic.List`1[[komBAS.API.Content.Dtos.PageShortDto, komBAS.API.Content, Version=1.0.0.0, Culture=neutral, PublicKeyToken=null]]'.
info: Microsoft.AspNetCore.Mvc.Internal.ControllerActionInvoker[2]
      Executed action komBAS.API.Content.Controllers.PageController.PagesAsPagedList (komBAS.API.Content) in 44.738ms
info: Microsoft.AspNetCore.Routing.EndpointMiddleware[1]
      Executed endpoint 'komBAS.API.Content.Controllers.PageController.PagesAsPagedList (komBAS.API.Content)'
info: Microsoft.AspNetCore.Hosting.Internal.WebHost[2]
      Request finished in 59.5634ms 200 application/json; charset=utf-8

更新：已解决

这个问题似乎和.NET Core 3.0中Nlog的使用有关。

虽然应用正在运行并且 Azure GUI 中未显示任何错误，但日志显示此错误：

2020-01-07 12:08:12.3741|11|FATAL|Microsoft.AspNetCore.Hosting.Diagnostics|Hosting startup assembly exception System.InvalidOperationException: Startup assembly Microsoft.AspNetCore.AzureAppServices.HostingStartup failed to execute. See the inner exception for more details.
 ---> System.IO.FileNotFoundException: Could not load file or assembly 'Microsoft.AspNetCore.AzureAppServices.HostingStartup, Culture=neutral, PublicKeyToken=null'. The system cannot find the file specified.

解决办法是添加

Microsoft.AspNetCore.AzureAppServices.HostingStartup

到您的项目，错误和延迟执行消失了。

我在所有 3 个 API 中都对此进行了测试，并且对所有这些 API 都有效。

【问题讨论】：

  • 向数据库发送什么查询？看起来可能很贵。
  • 我从本地环境中为 2 个调用添加了调试日志。第二个是 Azure 中的慢速。

标签： c# .net-core entity-framework-core asp.net-core-webapi


【解决方案1】：

问题与 Azure 中的 NLog 和 .NET Core 3.0 有关。

请参阅更新后的原始帖子以获取答案。

【讨论】：

    猜你喜欢
    • 1970-01-01
    • 2023-03-09
    • 2016-03-11
    • 1970-01-01
    • 1970-01-01
    • 2017-04-30
    • 1970-01-01
    • 1970-01-01
    • 1970-01-01
    相关资源
    最近更新 更多
    热门标签
    Java Python linux javascript Mysql C# Docker 算法 前端 SpringBoot Redis Vue spring 设计模式 .net core .net kubernetes c++ 数据库 数据结构 大数据 js 机器学习 微服务 Android Go 程序员 面试 JVM ASP.net core 云原生 人工智能 后端 PHP git CSS golang k8s Nginx Django mybatis 深度学习 多线程 React 架构 devops 爬虫 云计算 Spring Boot LeetCode