Forum Discussion
October RS Refresh Failure
Hi, Is anyone getting a refresh failure from the new Oct PowerBI RS? I have a couple of small powerbi docs with odata and sql server connections and they refresh fine. However I have a more ...
Below are the errors I've seen in the RSPowerBI log file.
2017-11-06 02:00:02.8152|INFO|42|Handling event with data: TimeEntered: 06/11/2017 02:00:00, Type: Event, SessionId: bb1a37ba-bd74-492a-b202-86f6c99ec1a0, EventType: DataModelRefresh 2017-11-06 02:00:03.0142|INFO|42|Processing Data Model Refresh: SessionId: bb1a37ba-bd74-492a-b202-86f6c99ec1a0, Status: Starting Data Refresh. 2017-11-06 02:00:03.0142|INFO|42|Processing Data Model Refresh: SessionId: bb1a37ba-bd74-492a-b202-86f6c99ec1a0, Status: Starting Retrieving PBIX AsDatabaseInfo. 2017-11-06 02:00:03.9313|INFO|42|Processing Data Model Refresh: SessionId: bb1a37ba-bd74-492a-b202-86f6c99ec1a0, Status: Starting Verifying all the data sources are embedded. 2017-11-06 02:00:03.9833|INFO|42|Processing Data Model Refresh: SessionId: bb1a37ba-bd74-492a-b202-86f6c99ec1a0, Status: Starting Verifying connection strings are valid. 2017-11-06 02:00:04.0143|INFO|42|Processing Data Model Refresh: SessionId: bb1a37ba-bd74-492a-b202-86f6c99ec1a0, Status: Starting Streaming model to Analysis Server. 2017-11-06 02:00:06.5244|INFO|42|Processing Data Model Refresh: SessionId: bb1a37ba-bd74-492a-b202-86f6c99ec1a0, Status: Starting Refreshing the model. 2017-11-06 02:00:07.9175|ERROR|42|Error Processing Data Model Refresh: SessionId: bb1a37ba-bd74-492a-b202-86f6c99ec1a0, Status: Error Failed to refresh the model, Exception System.ArgumentException: An item with the same key has already been added. at System.Collections.Generic.Dictionary`2.Insert(TKey key, TValue value, Boolean add) at Microsoft.PowerBI.ReportServer.AsServer.Mashup.MashupProviderManager.GenerateDataSourceSettings(String mashupConnectionString, Dictionary`2 serverDataSourcesDictionary) at Microsoft.PowerBI.ReportServer.AsServer.Mashup.MashupProviderManager.UpdateConnectionStringWithCredentials(String connectionString, IEnumerable`1 dataSources) at Microsoft.PowerBI.ReportServer.AsServer.Mashup.MashupProviderManager.CreateCredentials(ProviderDataSource providerDataSource, IEnumerable`1 dataSources) at Microsoft.PowerBI.ReportServer.AsServer.AnalysisServicesServer.SetCredentials(TOMWrapper asWrapper, String databaseName, IEnumerable`1 dataSources) at Microsoft.PowerBI.ReportServer.AsServer.AnalysisServicesServer.RefreshDatabase(String databaseName, IEnumerable`1 dataSources, String clientSessionId) at Microsoft.PowerBI.ReportServer.WebHost.EventHandler.AnalysisServicesDataRefresh.RefreshDatabase(AsDatabaseInfo asDatabaseInfo) at Microsoft.PowerBI.ReportServer.WebHost.EventHandler.DataRefreshScope.<>c__DisplayClass9.<ExecuteActionWithLogging>b__7() at Microsoft.PowerBI.ReportServer.WebHost.EventHandler.DataRefreshScope.<ExecuteFuncWithLogging>d__3`1.MoveNext() 2017-11-06 02:00:07.9575|ERROR|42|Error Processing Data Model Refresh: SessionId: bb1a37ba-bd74-492a-b202-86f6c99ec1a0, Status: Error Failed Data Refresh, Exception System.ArgumentException: An item with the same key has already been added. at Microsoft.PowerBI.ReportServer.WebHost.EventHandler.DataRefreshScope.ExecuteActionWithLogging(Action methodToExecute, String description, String localizedDescription, String messageInFailure, RefreshInfo refreshInfo, DataAccessors dataAccessors, ReportEventType operation, Boolean isDataRetrieval, Boolean showInExecutionLog, Boolean sendToTelemetry) at Microsoft.PowerBI.ReportServer.WebHost.EventHandler.AnalysisServicesDataRefresh.RefreshData(RefreshInfo refreshInfo) at Microsoft.PowerBI.ReportServer.WebHost.EventHandler.DataRefreshScope.<>c__DisplayClass9.<ExecuteActionWithLogging>b__7() at Microsoft.PowerBI.ReportServer.WebHost.EventHandler.DataRefreshScope.<ExecuteFuncWithLogging>d__3`1.MoveNext() 2017-11-06 02:00:12.8209|INFO|42|Handling event with data: TimeEntered: 06/11/2017 02:00:00, Type: Event, SessionId: cee8aeeb-c15b-43f6-80c4-69ddfbcf8f23, EventType: DataModelRefresh 2017-11-06 02:00:12.8529|INFO|42|Processing Data Model Refresh: SessionId: cee8aeeb-c15b-43f6-80c4-69ddfbcf8f23, Status: Starting Data Refresh. 2017-11-06 02:00:12.8599|INFO|42|Processing Data Model Refresh: SessionId: cee8aeeb-c15b-43f6-80c4-69ddfbcf8f23, Status: Starting Retrieving PBIX AsDatabaseInfo. 2017-11-06 02:00:12.8709|INFO|42|Processing Data Model Refresh: SessionId: cee8aeeb-c15b-43f6-80c4-69ddfbcf8f23, Status: Starting Verifying all the data sources are embedded. 2017-11-06 02:00:12.8709|INFO|42|Processing Data Model Refresh: SessionId: cee8aeeb-c15b-43f6-80c4-69ddfbcf8f23, Status: Starting Verifying connection strings are valid. 2017-11-06 02:00:12.8969|INFO|42|Processing Data Model Refresh: SessionId: cee8aeeb-c15b-43f6-80c4-69ddfbcf8f23, Status: Starting Streaming model to Analysis Server. 2017-11-06 02:00:18.4523|INFO|42|Processing Data Model Refresh: SessionId: cee8aeeb-c15b-43f6-80c4-69ddfbcf8f23, Status: Starting Refreshing the model. 2017-11-06 02:00:22.8396|INFO|63|Handling event with data: TimeEntered: 06/11/2017 02:00:00, Type: Event, SessionId: 234ad4ca-0c2b-43e6-9fae-82a56f621fac, EventType: DataModelRefresh 2017-11-06 02:00:22.8856|INFO|63|Processing Data Model Refresh: SessionId: 234ad4ca-0c2b-43e6-9fae-82a56f621fac, Status: Starting Data Refresh. 2017-11-06 02:00:22.9056|INFO|63|Processing Data Model Refresh: SessionId: 234ad4ca-0c2b-43e6-9fae-82a56f621fac, Status: Starting Retrieving PBIX AsDatabaseInfo. 2017-11-06 02:00:22.9476|INFO|63|Processing Data Model Refresh: SessionId: 234ad4ca-0c2b-43e6-9fae-82a56f621fac, Status: Starting Verifying all the data sources are embedded. 2017-11-06 02:00:23.0286|INFO|63|Processing Data Model Refresh: SessionId: 234ad4ca-0c2b-43e6-9fae-82a56f621fac, Status: Starting Verifying connection strings are valid. 2017-11-06 02:00:25.4318|INFO|63|Processing Data Model Refresh: SessionId: 234ad4ca-0c2b-43e6-9fae-82a56f621fac, Status: Starting Streaming model to Analysis Server. 2017-11-06 02:00:27.9339|INFO|63|Processing Data Model Refresh: SessionId: 234ad4ca-0c2b-43e6-9fae-82a56f621fac, Status: Starting Refreshing the model. 2017-11-06 02:00:35.9465|INFO|63|Processing Data Model Refresh: SessionId: 234ad4ca-0c2b-43e6-9fae-82a56f621fac, Status: Starting Removing credentials from the model. 2017-11-06 02:00:35.9465|INFO|64|Handling event with data: TimeEntered: 06/11/2017 02:00:01, Type: Event, SessionId: 5d9d55bf-3680-4800-b9a0-f4e259fc4708, EventType: DataModelRefresh 2017-11-06 02:00:36.3635|INFO|64|Processing Data Model Refresh: SessionId: 5d9d55bf-3680-4800-b9a0-f4e259fc4708, Status: Starting Data Refresh. 2017-11-06 02:00:39.4357|INFO|63|Processing Data Model Refresh: SessionId: 234ad4ca-0c2b-43e6-9fae-82a56f621fac, Status: Starting Saving model to the catalog. 2017-11-06 02:00:39.4357|INFO|64|Processing Data Model Refresh: SessionId: 5d9d55bf-3680-4800-b9a0-f4e259fc4708, Status: Starting Retrieving PBIX AsDatabaseInfo. 2017-11-06 02:00:40.0118|INFO|64|Processing Data Model Refresh: SessionId: 5d9d55bf-3680-4800-b9a0-f4e259fc4708, Status: Starting Verifying all the data sources are embedded. 2017-11-06 02:00:40.1838|INFO|64|Processing Data Model Refresh: SessionId: 5d9d55bf-3680-4800-b9a0-f4e259fc4708, Status: Starting Verifying connection strings are valid. 2017-11-06 02:00:40.2048|INFO|64|Processing Data Model Refresh: SessionId: 5d9d55bf-3680-4800-b9a0-f4e259fc4708, Status: Starting Streaming model to Analysis Server. 2017-11-06 02:00:40.4808|INFO|42|Processing Data Model Refresh: SessionId: cee8aeeb-c15b-43f6-80c4-69ddfbcf8f23, Status: Starting Removing credentials from the model. 2017-11-06 02:00:41.4339|INFO|42|Processing Data Model Refresh: SessionId: cee8aeeb-c15b-43f6-80c4-69ddfbcf8f23, Status: Starting Saving model to the catalog. 2017-11-06 02:00:42.7540|INFO|64|Processing Data Model Refresh: SessionId: 5d9d55bf-3680-4800-b9a0-f4e259fc4708, Status: Starting Refreshing the model. 2017-11-06 02:01:24.5179|INFO|64|Processing Data Model Refresh: SessionId: 5d9d55bf-3680-4800-b9a0-f4e259fc4708, Status: Starting Removing credentials from the model. 2017-11-06 02:01:24.9689|INFO|64|Processing Data Model Refresh: SessionId: 5d9d55bf-3680-4800-b9a0-f4e259fc4708, Status: Starting Saving model to the catalog. 2017-11-06 02:05:21.9622|INFO|51|Started clean up of embedded models 2017-11-06 02:05:21.9622|INFO|51|Finished clean up of 0 embedded models 2017-11-06 02:20:22.1778|INFO|28|Started clean up of embedded models 2017-11-06 02:20:22.1778|INFO|28|Finished clean up of 0 embedded models 2017-11-06 02:35:22.2132|INFO|51|Started clean up of embedded models 2017-11-06 02:35:22.2132|INFO|51|Finished clean up of 0 embedded models 2017-11-06 02:50:22.2264|INFO|52|Started clean up of embedded models 2017-11-06 02:50:22.2264|INFO|52|Finished clean up of 0 embedded models
I've had some sucess remove some of the queries and getting it to refresh. I'm currently trying to identify which query or dax expression it doesn't like. I think it's something in the DAX as I've got all the M data sets importing, but my joins and dax have been removed after I disabled some parts.
I deployed a couple of other PBIX files and they worked fine however they are not as complex.
stretcharm thanks for the continued help with debugging the issue, I pulled down your templates from Github and have been working to get it setup on my end, still working on getting an SSIS DB up and running. Hopefully I'll get a repro on my end soon, thanks!
Cheers.
I've got a new version so I'll put that up. It runs much faster.
Still got lots of datasets, joins and Dax, so it should be a good test.
Updated a blank pbix doc for version 0.78 of the SSIS dashboard to the forum, I'll do git when I get time.
I've just rebuild the PBIX from the template and redeployed it the Report Server and it now refreshes fine without anything disabled.
Very odd.
I've tried with a load more historical data and it still worked. Ran pretty quick as well.
Let see if if works overnight, but it's looking good.
Phil