Error RSPortal: obtaining a connection from the pool

[mrpellepelle]

Hi,

we use Oct. 2020 release  (product version 1.9.7627.11028)  and have the following Internal Server Error:

2021-02-01 10:54:28.3246|ERROR|190|OData exception occurred: 
System.Exception: ReportServerDatabaseUnavailableException --->System.InvalidOperationException: Timeout expired. 
The timeout period elapsed prior to obtaining a connection from the pool.  
This may have occurred because all pooled connections were in use and max pool size was reached.

 I can reproduce this error when i open one of our Power BI Reports ( Live Connection to Tabular) and navigate through the tabs and  filter values. After each click i can see increasing connections on SQL Server DB ReportSever DB  via sys.sysprocesses.
When it reaches 100 connections , the error occurs and the Report Service is unavailable( empty root folder) for some minutes. 

100 fits to the following Log entry in RSPortal after restarting PBIRS:

2021-02-01 12:05:10.4767|INFO|1|Catalog max connection pool size: 100

What is RsPortal used for? Older Power BI report do not show this behaviour.

Is it a bug and how can i resolve or work around the problem?

Is it fixed in Januar 2021 release?

[Petebro]

Thanks for the detail. Are you seeing the number of connections grow with Power BI Reports using direct query or are you seeing it with other types of models as well?

[jbarta_mlchc]

I did a test on a report with direct query to a SQL Server database and I did not have the issue. The report does not have as many slicers and visuals as the tabular model direct query report that has issues, so it might not be a good comparison. But those reports that I have SQL Server direct query are very limited, so it is all I had. 

I did do another test to see if I can get the blank Home screen to show and unfortunately it did this time. I have to reboot PBIRS from the RS Configuration Manager for the Home screen to show our folders again. Additionally, it causes all other reports that connect to the same SSAS instance to throw a something went wrong error.

[jbarta_mlchc]

Forgot to mention that to test the data source (SSAS Tabular model) for performance issues, I recreated the report/dashboard as a paginated report and the report did not experience the same issue. So i do not believe it is a problem with my tabular model.

[jbarta_mlchc]

Sorry, don't post frequently so I think I responded to the wrong message. My apologies. The majority of my reports are direct query to SSAS tabular model. I do have a few that are direct query to a SQL Server database, but I am hesitant to update any of those or edit them due to this issue. I can make a copy and see if the issue occurs. But I am only seeing this issue with direct query with a new report I created with the October 2020 release. I opened it in January 2021 and saved it again in hopes it fixed it, but as I stated it did not fix the issue. I have actually put a pause on all editing and new reports since the October 2020 release because of this issue. I will test a direct query to a SQL Database and let you know.

[jbarta_mlchc]

I have been getting this error as well ever since the October 2020 update. I was hoping the January 2021 update would fix it, but it does not. In the October 2020 release, the issue appeared to cause the Home screen to be blank once the error occurred and I would have to reboot PBIRS to get it to appear again. The blank Home screen appears to not happen with the January 2021 release. This is the full error I am seeing in the RSPortal log file:

2021-02-02 10:04:50.1524|ERROR|235|OData exception occurred: System.Exception: ReportServerDatabaseUnavailableException ---> System.InvalidOperationException: Timeout expired. The timeout period elapsed prior to obtaining a connection from the pool. This may have occurred because all pooled connections were in use and max pool size was reached.
at System.Data.ProviderBase.DbConnectionFactory.TryGetConnection(DbConnection owningConnection, TaskCompletionSource`1 retry, DbConnectionOptions userOptions, DbConnectionInternal oldConnection, DbConnectionInternal& connection)
at System.Data.ProviderBase.DbConnectionInternal.TryOpenConnectionInternal(DbConnection outerConnection, DbConnectionFactory connectionFactory, TaskCompletionSource`1 retry, DbConnectionOptions userOptions)
at System.Data.SqlClient.SqlConnection.TryOpenInner(TaskCompletionSource`1 retry)
at System.Data.SqlClient.SqlConnection.TryOpen(TaskCompletionSource`1 retry)
at System.Data.SqlClient.SqlConnection.Open()
at Microsoft.BIServer.HostingEnvironment.Storage.MeteredSqlConnection..ctor(String connectionString)
--- End of inner exception stack trace ---
at Microsoft.BIServer.HostingEnvironment.Storage.MeteredSqlConnection..ctor(String connectionString)
at Microsoft.BIServer.Configuration.Catalog.CatalogAccessFactory.NewConnection()
at Microsoft.ReportingServices.CatalogAccess.Streams.VarbinaryReadableStream..ctor(String getContentStoredProcedure, Dictionary`2 parameters)
at Microsoft.ReportingServices.CatalogAccess.Streams.VarbinaryReadableStreamFactory.CreateExtendedContentReadableStream(Guid catalogItemId, ExtendedContentType contentType)
at Microsoft.ReportingServices.Portal.Repositories.CatalogItemRepository.GetCatalogItemWithContentInternal(IPrincipal userPrincipal, RSService rsService, String path, Boolean internalUse)
at Microsoft.ReportingServices.Portal.Repositories.CatalogItemRepository.GetCatalogItemWithContentTrusted(IPrincipal userPrincipal, Guid key)
at Microsoft.ReportingServices.Portal.ODataWebApi.Common.CatalogItemControllerHelper`1.GetItem(String key)
at Microsoft.ReportingServices.Portal.ODataWebApi.V2.Controllers.CatalogItemsController.GetEntity(String key, String castName)
at Microsoft.ReportingServices.Portal.ODataWebApi.Controllers.Reflection.EntitySetReflectionODataController`1.GetRoot(ODataPath oDataPath, Int32& index)
at Microsoft.ReportingServices.Portal.ODataWebApi.Controllers.Reflection.ReflectionODataController`1.Get(ODataPath oDataPath)
at lambda_method(Closure , Object , Object[] )
at System.Web.Http.Controllers.ReflectedHttpActionDescriptor.ActionExecutor.<>c__DisplayClass6_2.<GetExecutor>b__2(Object instance, Object[] methodParameters)
at System.Web.Http.Controllers.ReflectedHttpActionDescriptor.ExecuteAsync(HttpControllerContext controllerContext, IDictionary`2 arguments, CancellationToken cancellationToken)
--- End of stack trace from previous location where exception was thrown ---
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
at System.Web.Http.Controllers.ApiControllerActionInvoker.<InvokeActionAsyncCore>d__1.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
at System.Web.Http.Filters.ActionFilterAttribute.<CallOnActionExecutedAsync>d__6.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
at System.Web.Http.Filters.ActionFilterAttribute.<CallOnActionExecutedAsync>d__6.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
at System.Web.Http.Filters.ActionFilterAttribute.<ExecuteActionFilterAsyncCore>d__5.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
at System.Web.Http.Controllers.ActionFilterResult.<ExecuteAsync>d__5.MoveNext()
--- End of stack trace from previous location where exception was thrown ---
at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
at System.Web.Http.Controllers.ExceptionFilterResult.<ExecuteAsync>d__6.MoveNext().| RequestID = 4f5e7c00-4014-2159-000a-2aacfe265f20 ClientSessionID = fc2378e1-3ab0-f57e-4a80-34c19e60aa6d

[mrpellepelle]

Hi again,

I was able to narrow down the problem:

Some of our older Live Connection Power BI reports don't even open one connection via RSPortal to SQL Server, while others keep increasing the number of connections with each new click (filter, drill down).

I opened one of the old Power BI reports (build with  a 2019 desktop version)  in my up to date Desktop Version (Oct. 2020) and saved it again to PBIRS.

Now, with each click in this new Version the number of connections increase and i am able to reproduce the error mentioned  above. 

Looks like a bug in the Desktop Version.

Please advise.

[jbarta_mlchc]

What browser are you using? I just did some further testing and it does not seem to happen with the new Edge browser. I was wondering if you are using IE 11.

[mrpellepelle]

I see increasing connections with every browser I use: Firefox (78), Edge (87), Chrome (88).
I don't think this has anything to do with the browser, but with the desktop version that provides the Power-Bi report on the server.

[jbarta_mlchc]

Thanks for your reply. After understanding where to watch the connections I am now seeing the issue with the new Edge browser as well. I noticed that there were less connection per filter/slicer change with the new Edge browser when compared to IE 11. I was seeing ~24 connections in IE 11 and ~4 with the new Edge. So it took longer for the portal to become unresponsive using the new Edge giving me the false impression that it was resolved using the new Edge browser.

[Petebro]

Ah let me engage with someone from the desktop team that is more familar with that area I will be back with investigation outcomes.

Though would it be possible to setup an enviroment using the January release of PBI RS And PBI RS Desktop to ensure this wasn't already fixed since October?

[mrpellepelle]

Hello,

No changes to the SQL instance. There isn't a large number of connections by RSPportal in sys.sysprocesses, just up to 100. What do you mean by "catalog"? DB or SQL Server instance?

[Petebro]

Catalog refers to the ReportServer database that stores state for the Power BI Report Server instance. Usually named "ReportServer" but you can view this from the RSConfig.exe tool when you connect to your PBIRS instance.

[Petebro]

RSPortal is the process that hosts the UI for browsing your reports. AKA http://{ServerName}/Reports runs in RSPortal process and talks to the catalog to fetch various information. I am unaware of any issue where we suddenly require extra connections to reach some sort of upper limit of connections available. It is not something we specifically changed in October or fixed in January.

Have there been any changes to the SQL instance hosting the catalog? Is it possible to run the profilers on the catalog to see if there are a huge number of connections coming in from somewhere?