Scheduled PowerPivot Data Refresh Not Running (PowerPivot 2012)
-
Wednesday, May 30, 2012 10:33 PM
Scheduled PowerPivot data refreshes never run.
I have SharePoint 2010, with PowerPivot 2012 installed on two SP servers, without anything else running on those servers. When I access a PowerPivot workbook, it works fine, pulls back data without any errors.
When I go into the workbook and schedule the data refresh nothing happens. No error, nothing. I've checked the PowerPivot Data Refresh timer jobs for both servers and they are running every minute, successfully.
I try scheduling the refresh for a certain time, but nothing happens. If I check the "Refresh immediately" checkbox, still nothing happens.
Again, everything seems to be working properly otherwise, I just can't get the scheduled refreshes to happen.
Thanks for any input.
All Replies
-
Wednesday, May 30, 2012 10:37 PM
I should add that I do see this error in the ULS logs on the server.
05/30/2012 13:36:21.39 w3wp.exe (0x115C) 0x1604 PowerPivot Service Data Refresh 99 High EXCEPTION: System.Data.SqlClient.SqlException: The SELECT permission was denied on the object 'Connections', database 'PowerPivot', schema 'Usage'. at System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection) at System.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj) at System.Data.SqlClient.TdsParser.Run(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj) at System.Data.SqlClient.SqlCommand.FinishExecuteReader(SqlDataReader ds, RunBehavior runBehavior, String resetOptionsString) at System.Data.SqlClient.SqlCommand.RunExecuteReaderTds(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, Bo... f9468844-8c6e-4e73-a877-f46eeca03a91 05/30/2012 13:36:21.39* w3wp.exe (0x115C) 0x1604 PowerPivot Service Data Refresh 99 High ...olean async) at System.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method, DbAsyncResult result) at System.Data.SqlClient.SqlCommand.InternalExecuteNonQuery(DbAsyncResult result, String methodName, Boolean sendToPipe) at System.Data.SqlClient.SqlCommand.ExecuteNonQuery() at Microsoft.AnalysisServices.SharePoint.Integration.MTSAccessorBase.ExecuteNonQuery(String commandText, CommandType commandType, SqlParameter[] paramArray) f9468844-8c6e-4e73-a877-f46eeca03a91 05/30/2012 13:36:21.39 w3wp.exe (0x115C) 0x1604 PowerPivot Service Data Refresh 99 High EXCEPTION: Microsoft.AnalysisServices.SharePoint.Integration.Redirector.RedirectorException: This request could not be redirected to a PowerPivot for SharePoint server. An internal error occurred. Please look in the SharePoint logs for more information or contact the administrator of this farm. ---> System.Data.SqlClient.SqlException: The SELECT permission was denied on the object 'Connections', database 'PowerPivot', schema 'Usage'. at System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection) at System.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj) at System.Data.SqlClient.TdsParser.Run(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParser... f9468844-8c6e-4e73-a877-f46eeca03a91 05/30/2012 13:36:21.39* w3wp.exe (0x115C) 0x1604 PowerPivot Service Data Refresh 99 High ...StateObject stateObj) at System.Data.SqlClient.SqlCommand.FinishExecuteReader(SqlDataReader ds, RunBehavior runBehavior, String resetOptionsString) at System.Data.SqlClient.SqlCommand.RunExecuteReaderTds(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, Boolean async) at System.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method, DbAsyncResult result) at System.Data.SqlClient.SqlCommand.InternalExecuteNonQuery(DbAsyncResult result, String methodName, Boolean sendToPipe) at System.Data.SqlClient.SqlCommand.ExecuteNonQuery() at Microsoft.AnalysisServices.SharePoint.Integration.MTSAccessorBase.ExecuteNonQuery(String commandText, CommandType commandType, SqlParamet... f9468844-8c6e-4e73-a877-f46eeca03a91 05/30/2012 13:36:21.39* w3wp.exe (0x115C) 0x1604 PowerPivot Service Data Refresh 99 High ...er[] paramArray) --- End of inner exception stack trace --- at Microsoft.AnalysisServices.SharePoint.Integration.MTSAccessorBase.ExecuteNonQuery(String commandText, CommandType commandType, SqlParameter[] paramArray) at Microsoft.AnalysisServices.SharePoint.Integration.DataRefreshAccessor.PersistRunStatusAndComments(DataRefreshRun drr, Boolean processed, DateTime timeLastModifiedBeforeRefresh, Int32 disableAfterFailures, Int32 disableAfterInactivity, Boolean connectionEventsEnabled, Int32& failureCount, Int32& inactivityCount) at Microsoft.AnalysisServices.SharePoint.Integration.DataRefreshService.ProcessRunCompletion(DataRefreshRun dataRefreshRun, Boolean p, DateTime dateTime) at Microsoft.AnalysisServices.SharePoint.Integration.DataRefreshService.CleanupAbortedRun(Dat... f9468844-8c6e-4e73-a877-f46eeca03a91 05/30/2012 13:36:21.39* w3wp.exe (0x115C) 0x1604 PowerPivot Service Data Refresh 99 High ...aRefreshRun drr, Semaphore processingSemaphore, Boolean isSemaphoreCreatedNew, ServiceEntryLockStatus lockObtained) at Microsoft.AnalysisServices.SharePoint.Integration.DataRefreshService.Execute() f9468844-8c6e-4e73-a877-f46eeca03a91
Thanks!
-
Thursday, May 31, 2012 10:03 PM
So I deleted the PowerPivot Service Application and repaired the PowerPivot installation on the servers. I then ran the PowerPivot Configuration wizard to provision the service application again (just on one server this time; I'll do the second server after this one works). Just as last time the PPVT Config Wizard went through without an error.
Using SQL Management Studio I connected to the Analysis Services instance on this computer and it opens up just fine.
I then went to the PowerPivot gallery and opened up one of the workbooks. It opened without an error and I was able to refresh the data and slice without any issues.
Next, was to try to see if the scheduled data refresh would work. So I went to the "Manage Data Refresh" screen for the workbook and scheduled a data refresh to happen right away. When I return to the Manage Data Refresh screen to see the status, this is what I see:
As you can see, it actually looks like it connected, and the workbook has a last modified by of the PowerPivot Data Refresh account. So it appears that it made it through much of this process. However, after refreshing over and over, it never leaves the Running status.
So let's look through the logs to see what's happening:
It looks like everything started out just fine. The Timer Job sees that there is a refresh that needs to be run and it picks it up:
05/31/2012 12:04:28.66 OWSTIMER.EXE (0x0920) 0x0974 PowerPivot Service Data Refresh 97 Verbose Attempting to retrieve EngineService f845dcb7-35db-4c3d-b035-ee56dbd3d2f1 05/31/2012 12:04:28.66 OWSTIMER.EXE (0x0920) 0x0974 PowerPivot Service Data Refresh 97 Verbose Attempting to retrieve EngineService f845dcb7-35db-4c3d-b035-ee56dbd3d2f1 05/31/2012 12:04:28.66 OWSTIMER.EXE (0x0920) 0x0974 PowerPivot Service Administration 97 Verbose Service instance 'POWERPIVOT' is enabled. f845dcb7-35db-4c3d-b035-ee56dbd3d2f1 05/31/2012 12:04:28.76 w3wp.exe (0x0EAC) 0x0B0C PowerPivot Service Data Refresh 42 Verbose Found a datarefresh job to run and acquired all the required locks. Examining data sources.. 81ad35eb-ab95-499f-b212-135df04e4302 05/31/2012 12:04:28.76 w3wp.exe (0x0EAC) 0x0B0C PowerPivot Service Data Refresh 42 Verbose Job Description: Run Id - 0, Item - SDPerformance.xlsx, User Identity - 81ad35eb-ab95-499f-b212-135df04e4302 05/31/2012 12:04:28.81 w3wp.exe (0x0EAC) 0x0B0C PowerPivot Service Data Refresh 42 Verbose Begin to refresh data source 81ad35eb-ab95-499f-b212-135df04e4302
Ok, this next section looks like it ran everything fine. Look at the last line. I think that indicates that it copied the workbook back into the site, which is why I see the PowerPivotDataRefresh account as the last modified user. Isn't that what you see also, "Successfully uploaded the file"?
05/31/2012 12:04:31.97 w3wp.exe (0x0EAC) 0x0B0C PowerPivot Service Data Refresh 42 Verbose Attempting image load for the item Self Service/SDPerformance.xlsx 81ad35eb-ab95-499f-b212-135df04e4302 05/31/2012 12:04:33.34 w3wp.exe (0x0EAC) 0x0B0C SharePoint Foundation Monitoring b4ly High Leaving Monitored Scope (PowerPivot:CacheManager:ImageLoad:DownloadFileFromSharePoint). Execution Time=1298.17420929196 81ad35eb-ab95-499f-b212-135df04e4302 05/31/2012 12:04:33.34 w3wp.exe (0x0EAC) 0x0B0C PowerPivot Service Data Refresh 37 Verbose Begin to load database: SDPerformance Process 265da003-615f-4284-a10d-2361b6ba420a 81ad35eb-ab95-499f-b212-135df04e4302 05/31/2012 12:04:35.58 w3wp.exe (0x0EAC) 0x0B0C SharePoint Foundation Monitoring b4ly High Leaving Monitored Scope (PowerPivot:CacheManager:ImageLoad:ServerLoad). Execution Time=2232.3208675963 81ad35eb-ab95-499f-b212-135df04e4302 05/31/2012 12:04:35.58 w3wp.exe (0x0EAC) 0x0B0C PowerPivot Service Data Refresh 37 Verbose Finish loading database: SDPerformance Process 265da003-615f-4284-a10d-2361b6ba420a 81ad35eb-ab95-499f-b212-135df04e4302 05/31/2012 12:04:35.72 w3wp.exe (0x0EAC) 0x0B0C SharePoint Foundation Monitoring b4ly High Leaving Monitored Scope (PowerPivot:CacheManager:ImageLoad). Execution Time=3710.33050289911 81ad35eb-ab95-499f-b212-135df04e4302 05/31/2012 12:04:35.72 w3wp.exe (0x0EAC) 0x0B0C SharePoint Foundation Monitoring b4ly High Leaving Monitored Scope (PowerPivot:CacheManager:ImageLoad2). Execution Time=3743.48946583993 81ad35eb-ab95-499f-b212-135df04e4302 05/31/2012 12:04:35.72 w3wp.exe (0x0EAC) 0x0B0C PowerPivot Service Data Refresh 42 Verbose The sandbox to refresh has been loaded 81ad35eb-ab95-499f-b212-135df04e4302 05/31/2012 12:04:35.73 w3wp.exe (0x0EAC) 0x0B0C PowerPivot Service Data Refresh 42 Verbose The update of the sandbox has been launched 81ad35eb-ab95-499f-b212-135df04e4302 05/31/2012 12:04:35.73 w3wp.exe (0x0EAC) 0x0B0C PowerPivot Service Data Refresh 42 Verbose Data source processing launched 81ad35eb-ab95-499f-b212-135df04e4302 05/31/2012 12:04:35.75 w3wp.exe (0x0EAC) 0x0688 PowerPivot Service Data Refresh 97 Verbose Creating admin role for database '265da003-615f-4284-a10d-2361b6ba420a' 05/31/2012 12:04:36.08 w3wp.exe (0x0EAC) 0x0688 PowerPivot Service Data Refresh 97 Verbose Successfuuly created admin role for database '265da003-615f-4284-a10d-2361b6ba420a' 05/31/2012 12:04:36.16 w3wp.exe (0x0EAC) 0x0688 PowerPivot Service Data Refresh 97 Verbose Attempting to retrieve MidTierService 05/31/2012 12:04:36.22 w3wp.exe (0x0EAC) 0x0688 PowerPivot Service Data Refresh 41 Verbose Begin to process database: SDPerformance Process 265da003-615f-4284-a10d-2361b6ba420a 05/31/2012 12:04:40.73 w3wp.exe (0x0EAC) 0x0B0C PowerPivot Service Data Refresh 42 Medium The service is running 'MAXCONCURRENTJOBS' and will not look for any more at this point. 81ad35eb-ab95-499f-b212-135df04e4302 05/31/2012 12:04:56.33 w3wp.exe (0x0EAC) 0x046C PowerPivot Service Background Jobs 97 Verbose Attempting to retrieve EngineService 05/31/2012 12:04:56.33 w3wp.exe (0x0EAC) 0x046C PowerPivot Service Background Jobs 40 Verbose Calculation of aggregated CPU Utilization on this server was launched by the background thread 05/31/2012 12:04:59.33 w3wp.exe (0x0EAC) 0x046C PowerPivot Service Background Jobs 40 Verbose The aggregated CPU utilization is: 10.91667 05/31/2012 12:05:03.48 w3wp.exe (0x0EAC) 0x0688 PowerPivot Service Data Refresh 41 Verbose Finish processing database: SDPerformance Process 265da003-615f-4284-a10d-2361b6ba420a 05/31/2012 12:05:03.50 w3wp.exe (0x0EAC) 0x0688 PowerPivot Service Data Refresh 41 Verbose Begin to process database: SDPerformance Process 265da003-615f-4284-a10d-2361b6ba420a 05/31/2012 12:05:05.33 w3wp.exe (0x0EAC) 0x0688 PowerPivot Service Data Refresh 41 Verbose Finish processing database: SDPerformance Process 265da003-615f-4284-a10d-2361b6ba420a 05/31/2012 12:05:05.33 w3wp.exe (0x0EAC) 0x0688 PowerPivot Service Data Refresh 97 Verbose Removing admin role for database '265da003-615f-4284-a10d-2361b6ba420a' 05/31/2012 12:05:05.78 w3wp.exe (0x0EAC) 0x0688 PowerPivot Service Data Refresh 97 Verbose Successfully removed admin role for database '265da003-615f-4284-a10d-2361b6ba420a' 05/31/2012 12:05:06.59 w3wp.exe (0x0EAC) 0x0688 SharePoint Foundation Monitoring b4ly High Leaving Monitored Scope (PowerPivot:CacheManager:ImageSave:ServerSave). Execution Time=770.619450237391 05/31/2012 12:05:06.59 w3wp.exe (0x0EAC) 0x0688 PowerPivot Service Data Refresh 37 Verbose Updating the refreshOnload flag for file 'e:\Program Files\Microsoft SQL Server\MSAS11.POWERPIVOT\OLAP\Backup\Sandboxes\PowerPivot Service\ReadWriteMode-265da003-615f-4284-a10d-2361b6ba420a-SDPerformance.xlsx' 05/31/2012 12:05:07.08 w3wp.exe (0x0EAC) 0x0688 SharePoint Foundation Monitoring b4ly High Leaving Monitored Scope (PowerPivot:CacheManager:ImageSave:UpdateRefreshOnLoad). Execution Time=484.316582135439 05/31/2012 12:05:07.44 w3wp.exe (0x0EAC) 0x0688 PowerPivot Service Data Refresh 37 Verbose Successfully uploaded file to http://SHAREPOINTSITE/SITE/Enterprise-Data-Warehouse/Self Service/SDPerformance.xlsx
I think this next section is where it gets ugly and we start seeing errors:
05/31/2012 12:05:07.44 w3wp.exe (0x0EAC) 0x0688 SharePoint Foundation Monitoring b4ly High Leaving Monitored Scope (PowerPivot:CacheManager:ImageSavc:UploadFileToSharePoint). Execution Time=355.949429326912 05/31/2012 12:05:07.44 w3wp.exe (0x0EAC) 0x0688 SharePoint Foundation Monitoring b4ly High Leaving Monitored Scope (PowerPivot:CacheManager:ImageSave). Execution Time=1651.64818433628 05/31/2012 12:05:07.45 w3wp.exe (0x0EAC) 0x046C SharePoint Foundation Monitoring b4ly High Leaving Monitored Scope (EnsureListItemsData). Execution Time=8.58181696277041 05/31/2012 12:05:07.47 w3wp.exe (0x0EAC) 0x0688 PowerPivot Service Data Refresh 99 High EXCEPTION: System.Data.SqlClient.SqlException: The SELECT permission was denied on the object 'Connections', database 'PowerPivotService', schema 'Usage'. at System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection) at System.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj) at System.Data.SqlClient.TdsParser.Run(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj) at System.Data.SqlClient.SqlCommand.FinishExecuteReader(SqlDataReader ds, RunBehavior runBehavior, String resetOptionsString) at System.Data.SqlClient.SqlCommand.RunExecuteReaderTds(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStr... 05/31/2012 12:05:07.47* w3wp.exe (0x0EAC) 0x0688 PowerPivot Service Data Refresh 99 High ...eam, Boolean async) at System.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method, DbAsyncResult result) at System.Data.SqlClient.SqlCommand.InternalExecuteNonQuery(DbAsyncResult result, String methodName, Boolean sendToPipe) at System.Data.SqlClient.SqlCommand.ExecuteNonQuery() at Microsoft.AnalysisServices.SharePoint.Integration.MTSAccessorBase.ExecuteNonQuery(String commandText, CommandType commandType, SqlParameter[] paramArray) 05/31/2012 12:05:07.47 w3wp.exe (0x0EAC) 0x0688 PowerPivot Service Data Refresh 99 High EXCEPTION: Microsoft.AnalysisServices.SharePoint.Integration.Redirector.RedirectorException: This request could not be redirected to a PowerPivot for SharePoint server. An internal error occurred. Please look in the SharePoint logs for more information or contact the administrator of this farm. ---> System.Data.SqlClient.SqlException: The SELECT permission was denied on the object 'Connections', database 'PowerPivotService', schema 'Usage'. at System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection) at System.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj) at System.Data.SqlClient.TdsParser.Run(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, Td... 05/31/2012 12:05:07.47* w3wp.exe (0x0EAC) 0x0688 PowerPivot Service Data Refresh 99 High ...sParserStateObject stateObj) at System.Data.SqlClient.SqlCommand.FinishExecuteReader(SqlDataReader ds, RunBehavior runBehavior, String resetOptionsString) at System.Data.SqlClient.SqlCommand.RunExecuteReaderTds(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, Boolean async) at System.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method, DbAsyncResult result) at System.Data.SqlClient.SqlCommand.InternalExecuteNonQuery(DbAsyncResult result, String methodName, Boolean sendToPipe) at System.Data.SqlClient.SqlCommand.ExecuteNonQuery() at Microsoft.AnalysisServices.SharePoint.Integration.MTSAccessorBase.ExecuteNonQuery(String commandText, CommandType commandType, Sql... 05/31/2012 12:05:07.47* w3wp.exe (0x0EAC) 0x0688 PowerPivot Service Data Refresh 99 High ...Parameter[] paramArray) --- End of inner exception stack trace --- at Microsoft.AnalysisServices.SharePoint.Integration.MTSAccessorBase.ExecuteNonQuery(String commandText, CommandType commandType, SqlParameter[] paramArray) at Microsoft.AnalysisServices.SharePoint.Integration.DataRefreshAccessor.PersistRunStatusAndComments(DataRefreshRun drr, Boolean processed, DateTime timeLastModifiedBeforeRefresh, Int32 disableAfterFailures, Int32 disableAfterInactivity, Boolean connectionEventsEnabled, Int32& failureCount, Int32& inactivityCount) at Microsoft.AnalysisServices.SharePoint.Integration.DataRefreshService.ProcessRunCompletion(DataRefreshRun dataRefreshRun, Boolean p, DateTime dateTime) at Microsoft.AnalysisServices.SharePoint.Integration.DataRefreshService.ProcessingJob(... 05/31/2012 12:05:07.47* w3wp.exe (0x0EAC) 0x0688 PowerPivot Service Data Refresh 99 High ...Object parameters) 05/31/2012 12:05:07.49 w3wp.exe (0x0EAC) 0x0688 PowerPivot Service Data Refresh 99 High EXCEPTION: System.Data.SqlClient.SqlException: The SELECT permission was denied on the object 'Connections', database 'PowerPivotService', schema 'Usage'. at System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection) at System.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj) at System.Data.SqlClient.TdsParser.Run(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj) at System.Data.SqlClient.SqlCommand.FinishExecuteReader(SqlDataReader ds, RunBehavior runBehavior, String resetOptionsString) at System.Data.SqlClient.SqlCommand.RunExecuteReaderTds(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStr... 05/31/2012 12:05:07.49* w3wp.exe (0x0EAC) 0x0688 PowerPivot Service Data Refresh 99 High ...eam, Boolean async) at System.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method, DbAsyncResult result) at System.Data.SqlClient.SqlCommand.InternalExecuteNonQuery(DbAsyncResult result, String methodName, Boolean sendToPipe) at System.Data.SqlClient.SqlCommand.ExecuteNonQuery() at Microsoft.AnalysisServices.SharePoint.Integration.MTSAccessorBase.ExecuteNonQuery(String commandText, CommandType commandType, SqlParameter[] paramArray) 05/31/2012 12:05:07.59 w3wp.exe (0x0EAC) 0x046C PowerPivot Service Report Gallery 98 Verbose SDPerformance.xlsx - is Updated in Self Service located at http://SHAREPOINTSITE/SITE/Enterprise-Data-Warehouse by COMPANYDOMAIN\bisedw . . 05/31/2012 12:05:08.02 w3wp.exe (0x0EAC) 0x0688 PowerPivot Service Data Refresh 97 Verbose Removing admin role for database '265da003-615f-4284-a10d-2361b6ba420a' 05/31/2012 12:05:08.06 w3wp.exe (0x0EAC) 0x0688 PowerPivot Service Data Refresh 97 Verbose Successfully removed admin role for database '265da003-615f-4284-a10d-2361b6ba420a' 05/31/2012 12:05:08.13 w3wp.exe (0x0EAC) 0x0688 PowerPivot Service Data Refresh 37 Verbose Trying to delete folder c:\Program Files\Microsoft SQL Server\MSAS11.POWERPIVOT\OLAP\Backup\Sandboxes\PowerPivot Service\265da003-615f-4284-a10d-2361b6ba420a.2.db 05/31/2012 12:05:08.13 w3wp.exe (0x0EAC) 0x0688 PowerPivot Service Data Refresh 37 Verbose Trying to delete files under \\?\c:\Program Files\Microsoft SQL Server\MSAS11.POWERPIVOT\OLAP\Backup\Sandboxes\PowerPivot Service\265da003-615f-4284-a10d-2361b6ba420a.2.db 05/31/2012 12:05:08.13 w3wp.exe (0x0EAC) 0x0688 PowerPivot Service Data Refresh 37 Verbose Trying to delete files under \\?\c:\Program Files\Microsoft SQL Server\MSAS11.POWERPIVOT\OLAP\Backup\Sandboxes\PowerPivot Service\265da003-615f-4284-a10d-2361b6ba420a.2.db\5c5823bb-bbb5-44b9-ab34-9ee051fd2b04.0.ds 05/31/2012 12:05:08.14 w3wp.exe (0x0EAC) 0x0688 PowerPivot Service Data Refresh 37 Verbose Trying to delete files under \\?\c:\Program Files\Microsoft SQL Server\MSAS11.POWERPIVOT\OLAP\Backup\Sandboxes\PowerPivot Service\265da003-615f-4284-a10d-2361b6ba420a.2.db\db4664f2-fbc4-444e-9cfe-63f68beb1d34.0.ds 05/31/2012 12:05:08.14 w3wp.exe (0x0EAC) 0x0688 PowerPivot Service Data Refresh 37 Verbose Trying to delete files under \\?\c:\Program Files\Microsoft SQL Server\MSAS11.POWERPIVOT\OLAP\Backup\Sandboxes\PowerPivot Service\265da003-615f-4284-a10d-2361b6ba420a.2.db\Model.52.cub 05/31/2012 12:05:08.14 w3wp.exe (0x0EAC) 0x0688 PowerPivot Service Data Refresh 37 Verbose Trying to delete files under \\?\c:\Program Files\Microsoft SQL Server\MSAS11.POWERPIVOT\OLAP\Backup\Sandboxes\PowerPivot Service\265da003-615f-4284-a10d-2361b6ba420a.2.db\Model.52.cub\Service Desk Performance_a9d48e1c-f0ff-47c1-b467-f5ab007cbb02.31.det 05/31/2012 12:05:08.14 w3wp.exe (0x0EAC) 0x0688 PowerPivot Service Data Refresh 37 Verbose Trying to delete files under \\?\c:\Program Files\Microsoft SQL Server\MSAS11.POWERPIVOT\OLAP\Backup\Sandboxes\PowerPivot Service\265da003-615f-4284-a10d-2361b6ba420a.2.db\Model.52.cub\Service Desk Performance_a9d48e1c-f0ff-47c1-b467-f5ab007cbb02.31.det\Service Desk Performance_a9d48e1c-f0ff-47c1-b467-f5ab007cbb02.5.prt 05/31/2012 12:05:08.14 w3wp.exe (0x0EAC) 0x0688 PowerPivot Service Data Refresh 37 Verbose Trying to delete files under \\?\c:\Program Files\Microsoft SQL Server\MSAS11.POWERPIVOT\OLAP\Backup\Sandboxes\PowerPivot Service\265da003-615f-4284-a10d-2361b6ba420a.2.db\Model.52.cub\Service Desk Service Level Agreement KPI_cab0c02f-9934-4b59-a07a-1a687232be26.49.det 05/31/2012 12:05:08.14 w3wp.exe (0x0EAC) 0x0688 PowerPivot Service Data Refresh 37 Verbose Trying to delete files under \\?\c:\Program Files\Microsoft SQL Server\MSAS11.POWERPIVOT\OLAP\Backup\Sandboxes\PowerPivot Service\265da003-615f-4284-a10d-2361b6ba420a.2.db\Model.52.cub\Service Desk Service Level Agreement KPI_cab0c02f-9934-4b59-a07a-1a687232be26.49.det\Service Desk Service Level Agreement KPI_cab0c02f-9934-4b59-a07a-1a687232be26.10.prt 05/31/2012 12:05:08.14 w3wp.exe (0x0EAC) 0x0688 PowerPivot Service Data Refresh 37 Verbose Trying to delete files under \\?\c:\Program Files\Microsoft SQL Server\MSAS11.POWERPIVOT\OLAP\Backup\Sandboxes\PowerPivot Service\265da003-615f-4284-a10d-2361b6ba420a.2.db\Service Desk Performance_a9d48e1c-f0ff-47c1-b467-f5ab007cbb02.0.dim 05/31/2012 12:05:08.16 w3wp.exe (0x0EAC) 0x0688 PowerPivot Service Data Refresh 37 Verbose Trying to delete files under \\?\c:\Program Files\Microsoft SQL Server\MSAS11.POWERPIVOT\OLAP\Backup\Sandboxes\PowerPivot Service\265da003-615f-4284-a10d-2361b6ba420a.2.db\Service Desk Service Level Agreement KPI_cab0c02f-9934-4b59-a07a-1a687232be26.0.dim 05/31/2012 12:05:08.19 w3wp.exe (0x0EAC) 0x0688 PowerPivot Service Data Refresh 42 Verbose The processing job has ended. The sharepoint file http://SHAREPOINTSITE/SITE/Enterprise-Data-Warehouse/Self Service/SDPerformance.xlsx will be deleted from c:\Program Files\Microsoft SQL Server\MSAS11.POWERPIVOT\OLAP\Backup\Sandboxes\PowerPivot Service\ReadWriteMode-265da003-615f-4284-a10d-2361b6ba420a-SDPerformance.xlsx 05/31/2012 12:05:28.10 OWSTIMER.EXE (0x0920) 0x16C4 PowerPivot Service Data Refresh 97 Verbose Attempting to retrieve EngineService 17663ec5-bb81-4637-9e0b-248949e1ac84 05/31/2012 12:05:28.10 OWSTIMER.EXE (0x0920) 0x16C4 PowerPivot Service Data Refresh 97 Verbose Attempting to retrieve EngineService 17663ec5-bb81-4637-9e0b-248949e1ac84
It looks like there are permissions missing on the PowerPivotService database. The Farm Account has "GeminiServiceAdmin" on the database and the Admin and Service accounts have DB Owner, but that's it. It seems like maybe there should be more, but I've checked those permissions against my Test and QA environments and those environments don't even have the Service account as DB Owner. So permissions should be sufficient based on two other environments. Maybe something else is missing? Is it that "Illegal character"?
Just to finish it off, here are the last of the logs for that data refresh attempt, with the same "Illegal Character" and SQL errors again:
05/31/2012 12:05:28.10 OWSTIMER.EXE (0x0920) 0x16C4 PowerPivot Service Administration 97 Verbose Service instance 'POWERPIVOT' is enabled. 17663ec5-bb81-4637-9e0b-248949e1ac84 05/31/2012 12:05:29.66 w3wp.exe (0x0A78) 0x1260 SharePoint Foundation Unified Logging Service b8fx High ULS Init Completed (w3wp.exe, onetnative.dll) 05/31/2012 12:05:31.13 w3wp.exe (0x0A78) 0x1260 SharePoint Foundation Database 8u1d High Flushing connection pool 'Data Source=SQLSERVER987;Failover Partner=SQLPSHP21\PS1;Initial Catalog=SharePoint_Config;Integrated Security=True;Enlist=False;Connect Timeout=15' 05/31/2012 12:05:31.13 w3wp.exe (0x0A78) 0x1260 SharePoint Foundation General avew High An application domain named /LM/W3SVC/2/ROOT/b69b422637934b8986e147f4e44a46b1-1-129829647282253212 has just been loaded. 05/31/2012 12:05:31.13 w3wp.exe (0x0A78) 0x1260 SharePoint Foundation Topology 2myc High Creating a new filesystem watcher for the configuration cache. 05/31/2012 12:05:31.14 w3wp.exe (0x0A78) 0x1260 SharePoint Foundation Monitoring b4ly High Leaving Monitored Scope (Initializing Admin OM). Execution Time=1466.53108146426 05/31/2012 12:05:31.17 w3wp.exe (0x0A78) 0x1260 PowerPivot Service Unknown 97 Verbose Attempting to retrieve EngineService 05/31/2012 12:05:31.19 w3wp.exe (0x0A78) 0x1260 PowerPivot Service Unknown 97 Verbose Running function GetSolutionProductVersion(). 05/31/2012 12:05:31.19 w3wp.exe (0x0A78) 0x1260 PowerPivot Service Unknown 97 Verbose File name is Microsoft.AnalysisServices.SharePoint.Integration.DLL 05/31/2012 12:05:31.19 w3wp.exe (0x0A78) 0x1260 PowerPivot Service Unknown 97 Verbose Found solution location in registry setting 05/31/2012 12:05:31.19 w3wp.exe (0x0A78) 0x1260 PowerPivot Service Unknown 97 Verbose The location is C:\Program Files\Microsoft SQL Server\110\SDK\Assemblies\Microsoft.AnalysisServices.SharePoint.Integration.DLL. 05/31/2012 12:05:31.19 w3wp.exe (0x0A78) 0x1260 PowerPivot Service Unknown 97 Verbose Microsoft.AnalysisServices.SharePoint.Integration.DLL not present in SDK 05/31/2012 12:05:31.20 w3wp.exe (0x0A78) 0x1260 PowerPivot Service Unknown 97 Verbose The product version of executing assembly is 11.0.2100.60. 05/31/2012 12:05:31.20 w3wp.exe (0x0A78) 0x1260 PowerPivot Service Unknown 97 Verbose Comparing two versions: ver1 is 11.0.2100.60. Ver2 is 11.0.2100.60 05/31/2012 12:05:31.36 w3wp.exe (0x0A78) 0x1190 SharePoint Foundation Object Cache 9j6t High SPXmlDocCache cache parameters arc: high water mark 10485760 bytes, low water mark 5242880 bytes, interval 180000 ms 05/31/2012 12:05:33.13 w3wp.exe (0x0A78) 0x1260 SharePoint Foundation Monitoring b4ly High Leaving Monitored Scope (SPTrustedIssuerNameRegistry.GetIssuerName). Execution Time=1690.70761786763 05/31/2012 12:05:33.19 OWSTIMER.EXE (0x0920) 0x16C4 SharePoint Foundation Monitoring b4ly High Leaving Monitored Scope (ExecuteWcfOperation:http://tempuri.org/IGeminiServiceApplication/ExecuteDataRefreshService). Execution Time=5096.69608846934 17663ec5-bb81-4637-9e0b-248949e1ac84 05/31/2012 12:05:33.20 w3wp.exe (0x0A78) 0x1260 PowerPivot Service Data Refresh 42 Verbose Data Refresh purge history is executed. d6865de7-3e87-4189-a047-784f376aafe4 05/31/2012 12:05:33.33 w3wp.exe (0x0A78) 0x1260 PowerPivot Service Data Refresh 42 Verbose Detected abnormal exit of the process. Cleanup has been triggered d6865de7-3e87-4189-a047-784f376aafe4 05/31/2012 12:05:36.46 w3wp.exe (0x0A78) 0x1260 PowerPivot Service Data Refresh 42 High An error occured while cleaning the sandboxes of the aborted run 5eb3e955-3994-4f07-bb50-c068f93b6987. The sandbox could not be removed. d6865de7-3e87-4189-a047-784f376aafe4 05/31/2012 12:05:36.47 w3wp.exe (0x0A78) 0x1260 PowerPivot Service Data Refresh 99 High EXCEPTION: System.ArgumentException: Illegal characters in path. at System.Security.Permissions.FileIOPermission.HasIllegalCharacters(String[] str) at System.Security.Permissions.FileIOPermission.AddPathList(FileIOPermissionAccess access, AccessControlActions control, String[] pathListOrig, Boolean checkForDuplicates, Boolean needFullPath, Boolean copyPathList) at System.Security.Permissions.FileIOPermission..ctor(FileIOPermissionAccess access, String[] pathList, Boolean checkForDuplicates, Boolean needFullPath) at System.IO.FileInfo..ctor(String fileName) at Microsoft.AnalysisServices.SharePoint.Integration.DataRefreshService.CleanupAbortedRun(DataRefreshRun drr, Semaphore processingSemaphore, Boolean isSemaphoreCreatedNew, ServiceEntryLockStatus lockObtained) d6865de7-3e87-4189-a047-784f376aafe4 05/31/2012 12:05:36.50 w3wp.exe (0x0A78) 0x1260 PowerPivot Service Data Refresh 99 High EXCEPTION: System.Data.SqlClient.SqlException: The SELECT permission was denied on the object 'Connections', database 'PowerPivotService', schema 'Usage'. at System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection) at System.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj) at System.Data.SqlClient.TdsParser.Run(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, TdsParserStateObject stateObj) at System.Data.SqlClient.SqlCommand.FinishExecuteReader(SqlDataReader ds, RunBehavior runBehavior, String resetOptionsString) at System.Data.SqlClient.SqlCommand.RunExecuteReaderTds(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStr... d6865de7-3e87-4189-a047-784f376aafe4 05/31/2012 12:05:36.50* w3wp.exe (0x0A78) 0x1260 PowerPivot Service Data Refresh 99 High ...eam, Boolean async) at System.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method, DbAsyncResult result) at System.Data.SqlClient.SqlCommand.InternalExecuteNonQuery(DbAsyncResult result, String methodName, Boolean sendToPipe) at System.Data.SqlClient.SqlCommand.ExecuteNonQuery() at Microsoft.AnalysisServices.SharePoint.Integration.MTSAccessorBase.ExecuteNonQuery(String commandText, CommandType commandType, SqlParameter[] paramArray) d6865de7-3e87-4189-a047-784f376aafe4 05/31/2012 12:05:36.50 w3wp.exe (0x0A78) 0x1260 PowerPivot Service Data Refresh 99 High EXCEPTION: Microsoft.AnalysisServices.SharePoint.Integration.Redirector.RedirectorException: This request could not be redirected to a PowerPivot for SharePoint server. An internal error occurred. Please look in the SharePoint logs for more information or contact the administrator of this farm. ---> System.Data.SqlClient.SqlException: The SELECT permission was denied on the object 'Connections', database 'PowerPivotService', schema 'Usage'. at System.Data.SqlClient.SqlConnection.OnError(SqlException exception, Boolean breakConnection) at System.Data.SqlClient.TdsParser.ThrowExceptionAndWarning(TdsParserStateObject stateObj) at System.Data.SqlClient.TdsParser.Run(RunBehavior runBehavior, SqlCommand cmdHandler, SqlDataReader dataStream, BulkCopySimpleResultSet bulkCopyHandler, Td... d6865de7-3e87-4189-a047-784f376aafe4 05/31/2012 12:05:36.50* w3wp.exe (0x0A78) 0x1260 PowerPivot Service Data Refresh 99 High ...sParserStateObject stateObj) at System.Data.SqlClient.SqlCommand.FinishExecuteReader(SqlDataReader ds, RunBehavior runBehavior, String resetOptionsString) at System.Data.SqlClient.SqlCommand.RunExecuteReaderTds(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, Boolean async) at System.Data.SqlClient.SqlCommand.RunExecuteReader(CommandBehavior cmdBehavior, RunBehavior runBehavior, Boolean returnStream, String method, DbAsyncResult result) at System.Data.SqlClient.SqlCommand.InternalExecuteNonQuery(DbAsyncResult result, String methodName, Boolean sendToPipe) at System.Data.SqlClient.SqlCommand.ExecuteNonQuery() at Microsoft.AnalysisServices.SharePoint.Integration.MTSAccessorBase.ExecuteNonQuery(String commandText, CommandType commandType, Sql... d6865de7-3e87-4189-a047-784f376aafe4 05/31/2012 12:05:36.50* w3wp.exe (0x0A78) 0x1260 PowerPivot Service Data Refresh 99 High ...Parameter[] paramArray) --- End of inner exception stack trace --- at Microsoft.AnalysisServices.SharePoint.Integration.MTSAccessorBase.ExecuteNonQuery(String commandText, CommandType commandType, SqlParameter[] paramArray) at Microsoft.AnalysisServices.SharePoint.Integration.DataRefreshAccessor.PersistRunStatusAndComments(DataRefreshRun drr, Boolean processed, DateTime timeLastModifiedBeforeRefresh, Int32 disableAfterFailures, Int32 disableAfterInactivity, Boolean connectionEventsEnabled, Int32& failureCount, Int32& inactivityCount) at Microsoft.AnalysisServices.SharePoint.Integration.DataRefreshService.ProcessRunCompletion(DataRefreshRun dataRefreshRun, Boolean p, DateTime dateTime) at Microsoft.AnalysisServices.SharePoint.Integration.DataRefreshService.CleanupAborted... d6865de7-3e87-4189-a047-784f376aafe4 05/31/2012 12:05:36.50* w3wp.exe (0x0A78) 0x1260 PowerPivot Service Data Refresh 99 High ...Run(DataRefreshRun drr, Semaphore processingSemaphore, Boolean isSemaphoreCreatedNew, ServiceEntryLockStatus lockObtained) at Microsoft.AnalysisServices.SharePoint.Integration.DataRefreshService.Execute() d6865de7-3e87-4189-a047-784f376aafe4
Hopefully someone has seen this or has some insight into what is happening. Thanks in advance. -
Tuesday, June 05, 2012 9:42 PM
I think we resolved the problem. I was just about to pull the trigger on a MS Premier ticket and asked my coworker to take a final look as I reviewed what was happening. We decided to grant the Farm account (which is the only account in the GeminiServiceAdmin role) DB_Owner on the PowerPivot database since the error was pointing to not having permissions on that DB. The datarefresh began working perfectly.
Obviously I didn’t want to just leave it that way in Production, when that wasn’t required in Test or QA. So I asked our SQL team to look at the DBs and see if they could find any differences between Test, QA and Prod PowerPivot DBs. On their first pass, they didn’t find any differences. I then mentioned that the GeminiServiceAdmin is the main role for PowerPivot. They then found that the GeminiServiceAdmin role did not have permission to run any of the DataRefresh and RedirectService stored procs, only the Usage and HealthRule stored procs.
I’m not sure why that happened in production (twice! since I had re-provisioned the entire service app with a new DB) and not Test or QA. However, once the GeminiServiceAdmin role was granted Execute permissions for those stored procs it appears to be running properly now.
Here is a screenshot of the required stored procs.
This may be completely isolated to my environment, but if anyone else has this I hope they find this post.
- Marked As Answer by mcwoods Tuesday, June 05, 2012 9:42 PM
-
Sunday, August 05, 2012 12:04 PM
Interesting thread. Same issue with my install (single machine), I've now installed twice (first manually, second with scripted AutoSPInstaller) and same issue both times.
Something to do with SP_Farm account on the DefaultPowerPivotServiceApplicationDB permissions, it needs db_owner to be set before it runs any refreshes!
Any ideas as to whats going on? Did you get to the bottom of this issue:
a) Confirm if the stored procs were at fault?
b) Find out why this is going wrong in the first place?
How can I raise this with Microsoft without having to pay to support this as I am sure its not a problem from my side?
Regards,
Chris
-
Monday, August 06, 2012 5:47 PM
I never figured out the "why" behind the stored procs not getting the right permissions, but once I changed the permissions the data refresh runs.
I don't know that you can open a ticket with MS without paying. If it's a bug they won't end up charging you for it, but that's a risk you take. We usually don't open one unless we're sure it's a bug or we REALLY need help fixing a critical issue.
-
Wednesday, August 08, 2012 7:06 PM
Good points and well diagnosed. At least I know its not just me who had the same issue.
Just suprising I could not find others complaining of the same problem as I could repeat the problem on seperate boxes it each time i tried!
Regards,
Chris
