Dear Asp.Net Zero Team We deploy our project into azure app services and from begging we struggled with request performance. Each request have very long execution in our opinion. We focus to optimize sql query and have some success on this field, but right now when we measure our execution we get 200ms for query but full request take 530ms for example. Where we can look for a problem. From logs its looks like that legacy code for example JwtBearer.JwtBearerHandler take 100ms and this issue only occur on app service when we running our project locally it take couple of ms. Right now we run on S1 plan. Is it to low to run asp.net zero? Some snippets from logs sorry for some doubled logs it is issue with our NLog configuration but we already check it has no impact on this problem:
Line 13543: INFO [2020-05-12 06:34:17.7041] Microsoft.AspNetCore.Hosting.Diagnostics |1b6abeee-454c029f4f6920ae. GET https://OurDomain.com/api/services/app/Course/GetAll Request starting HTTP/1.1 GET https://OurDomain.com/api/services/app/Course/GetAll?Sorting=&SkipCount=0&MaxResultCount=100&Keyword=&Filters= application/json
Line 13544: INFO [2020-05-12 06:34:17.7160] Microsoft.AspNetCore.Hosting.Diagnostics |1b6abeee-454c029f4f6920ae. GET https://OurDomain.com/api/services/app/Course/GetAll Request starting HTTP/1.1 GET https://OurDomain.com/api/services/app/Course/GetAll?Sorting=&SkipCount=0&MaxResultCount=100&Keyword=&Filters= application/json
Line 13545: INFO [2020-05-12 06:34:17.7234] Microsoft.AspNetCore.Cors.Infrastructure.CorsService |1b6abeee-454c029f4f6920ae. GET https://OurDomain.com/api/services/app/Course/GetAll CORS policy execution successful.
Line 13546: INFO [2020-05-12 06:34:17.7234] Microsoft.AspNetCore.Cors.Infrastructure.CorsService |1b6abeee-454c029f4f6920ae. GET https://OurDomain.com/api/services/app/Course/GetAll CORS policy execution successful.
Line 13547: INFO [2020-05-12 06:34:17.7657] Microsoft.AspNetCore.Authentication.JwtBearer.JwtBearerHandler |1b6abeee-454c029f4f6920ae. GET https://OurDomain.com/api/services/app/Course/GetAll Successfully validated the token.
Line 13548: INFO [2020-05-12 06:34:17.7691] Microsoft.AspNetCore.Authentication.JwtBearer.JwtBearerHandler |1b6abeee-454c029f4f6920ae. GET https://OurDomain.com/api/services/app/Course/GetAll Successfully validated the token.
Line 13549: INFO [2020-05-12 06:34:17.8594] Microsoft.AspNetCore.Routing.EndpointMiddleware |1b6abeee-454c029f4f6920ae. GET https://OurDomain.com/api/services/app/Course/GetAll Executing endpoint 'OurProject.ReservationsSystem.Courses.CourseAppService.GetAll (OurProject.Application)'
Line 13550: INFO [2020-05-12 06:34:17.8654] Microsoft.AspNetCore.Routing.EndpointMiddleware |1b6abeee-454c029f4f6920ae. GET https://OurDomain.com/api/services/app/Course/GetAll Executing endpoint 'OurProject.ReservationsSystem.Courses.CourseAppService.GetAll (OurProject.Application)'
Line 13551: INFO [2020-05-12 06:34:17.8654] Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker |1b6abeee-454c029f4f6920ae. GET https://OurDomain.com/api/services/app/Course/GetAll Route matched with {area = "app", action = "GetAll", controller = "Course"}. Executing controller action with signature System.Threading.Tasks.Task`1[Abp.Application.Services.Dto.PagedResultDto`1[OurProject.ReservationsSystem.Courses.Dto.CourseDto]] GetAll(OurProject.Generics.PagedAndSortedWithKeywordAndFiltersResultRequestDto) on controller OurProject.ReservationsSystem.Courses.CourseAppService (OurProject.Application).
Line 13552: INFO [2020-05-12 06:34:17.8805] Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker |1b6abeee-454c029f4f6920ae. GET https://OurDomain.com/api/services/app/Course/GetAll Route matched with {area = "app", action = "GetAll", controller = "Course"}. Executing controller action with signature System.Threading.Tasks.Task`1[Abp.Application.Services.Dto.PagedResultDto`1[OurProject.ReservationsSystem.Courses.Dto.CourseDto]] GetAll(OurProject.Generics.PagedAndSortedWithKeywordAndFiltersResultRequestDto) on controller OurProject.ReservationsSystem.Courses.CourseAppService (OurProject.Application).
Line 13553: DEBUG [2020-05-12 06:34:17.9276] OurProject.ReservationsSystem.Courses.CourseAppService |1b6abeee-454c029f4f6920ae. GET https://OurDomain.com/api/services/app/Course/GetAll START GetAll for CourseDto
Line 13554: DEBUG [2020-05-12 06:34:17.9276] OurProject.ReservationsSystem.Courses.CourseAppService |1b6abeee-454c029f4f6920ae. GET https://OurDomain.com/api/services/app/Course/GetAll START CheckGetAllPermission
Line 13555: DEBUG [2020-05-12 06:34:17.9454] OurProject.ReservationsSystem.Courses.CourseAppService |1b6abeee-454c029f4f6920ae. GET https://OurDomain.com/api/services/app/Course/GetAll END CheckGetAllPermission and START _queryService.GetAll()
Line 13556: DEBUG [2020-05-12 06:34:17.9568] OurProject.ReservationsSystem.Courses.CourseAppService |1b6abeee-454c029f4f6920ae. GET https://OurDomain.com/api/services/app/Course/GetAll END _queryService.GetAll() and START ApplySorting(query, input)
Line 13557: DEBUG [2020-05-12 06:34:17.9568] OurProject.ReservationsSystem.Courses.CourseAppService |1b6abeee-454c029f4f6920ae. GET https://OurDomain.com/api/services/app/Course/GetAll END ApplySorting(query, input) and START ApplyKeywordSearch(query, input)
Line 13558: DEBUG [2020-05-12 06:34:17.9568] OurProject.ReservationsSystem.Courses.CourseAppService |1b6abeee-454c029f4f6920ae. GET https://OurDomain.com/api/services/app/Course/GetAll END ApplyKeywordSearch(query, input) and START ApplyFiltering(query, input)
Line 13559: DEBUG [2020-05-12 06:34:17.9846] OurProject.ReservationsSystem.Courses.CourseAppService |1b6abeee-454c029f4f6920ae. GET https://OurDomain.com/api/services/app/Course/GetAll END ApplyFiltering(query, input) and START query.CountAsync();
Line 13560: DEBUG [2020-05-12 06:34:18.0116] OurProject.ReservationsSystem.Courses.CourseAppService |1b6abeee-454c029f4f6920ae. GET https://OurDomain.com/api/services/app/Course/GetAll END query.CountAsync() and START ApplyPaging(query, input)
Line 13561: DEBUG [2020-05-12 06:34:18.0116] OurProject.ReservationsSystem.Courses.CourseAppService |1b6abeee-454c029f4f6920ae. GET https://OurDomain.com/api/services/app/Course/GetAll END ApplyPaging(query, input) and START page.ToListAsync()
Line 13562: DEBUG [2020-05-12 06:34:18.1466] OurProject.ReservationsSystem.Courses.CourseAppService |1b6abeee-454c029f4f6920ae. GET https://OurDomain.com/api/services/app/Course/GetAll END page.ToListAsync()
Line 13563: DEBUG [2020-05-12 06:34:18.1466] OurProject.ReservationsSystem.Courses.CourseAppService |1b6abeee-454c029f4f6920ae. GET https://OurDomain.com/api/services/app/Course/GetAll END GetAll for CourseDto Execution Time: 00:00:00.2157793
Line 13564: INFO [2020-05-12 06:34:18.1587] Microsoft.AspNetCore.Mvc.Infrastructure.ObjectResultExecutor |1b6abeee-454c029f4f6920ae. GET https://OurDomain.com/api/services/app/Course/GetAll Executing ObjectResult, writing value of type 'Abp.Web.Models.AjaxResponse'.
Line 13565: INFO [2020-05-12 06:34:18.1587] Microsoft.AspNetCore.Mvc.Infrastructure.ObjectResultExecutor |1b6abeee-454c029f4f6920ae. GET https://OurDomain.com/api/services/app/Course/GetAll Executing ObjectResult, writing value of type 'Abp.Web.Models.AjaxResponse'.
Line 13566: INFO [2020-05-12 06:34:18.2144] Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker |1b6abeee-454c029f4f6920ae. GET https://OurDomain.com/api/services/app/Course/GetAll Executed action OurProject.ReservationsSystem.Courses.CourseAppService.GetAll (OurProject.Application) in 330.1808ms
Line 13567: INFO [2020-05-12 06:34:18.2221] Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker |1b6abeee-454c029f4f6920ae. GET https://OurDomain.com/api/services/app/Course/GetAll Executed action OurProject.ReservationsSystem.Courses.CourseAppService.GetAll (OurProject.Application) in 330.1808ms
Line 13568: INFO [2020-05-12 06:34:18.2221] Microsoft.AspNetCore.Routing.EndpointMiddleware |1b6abeee-454c029f4f6920ae. GET https://OurDomain.com/api/services/app/Course/GetAll Executed endpoint 'OurProject.ReservationsSystem.Courses.CourseAppService.GetAll (OurProject.Application)'
Line 13569: INFO [2020-05-12 06:34:18.2221] Microsoft.AspNetCore.Routing.EndpointMiddleware |1b6abeee-454c029f4f6920ae. GET https://OurDomain.com/api/services/app/Course/GetAll Executed endpoint 'OurProject.ReservationsSystem.Courses.CourseAppService.GetAll (OurProject.Application)'
Line 13570: INFO [2020-05-12 06:34:18.2221] Microsoft.AspNetCore.Hosting.Diagnostics |1b6abeee-454c029f4f6920ae. GET https://OurDomain.com/api/services/app/Course/GetAll Request finished in 530.7161ms 200 application/json; charset=utf-8
Line 13571: INFO [2020-05-12 06:34:18.2381] Microsoft.AspNetCore.Hosting.Diagnostics |1b6abeee-454c029f4f6920ae. GET https://OurDomain.com/api/services/app/Course/GetAll Request finished in 530.7161ms 200 application/json; charset=utf-8
If some additional checks needed we can provide it. We need solution for this issue.