Hello gurus.
We have a workbook containing 2 small reports (30 rows, like 20 columns, all base members, no localmemebers, no formulas... a pretty simple report) which are taking forever to refresh. In that same workbook there are other 5 reports which refresh pretty fast even if they are heavier. All of them are dynamic reports, without formatting.
This will happen in DEV, QUAL and PROD environments.
After checking log and traces, everything is OK at server side. They are fine RSDRI queries which take less than a second to retrieve the data, and the rest of steps at server side run pretty fast too.
The problem comes when EPM writes the report in Excel.
Having a look at the trace for one of the reports, which you can find below, one of the methods called WriteSmart is taking almost 300 seconds (in bigger ones takes 1-15 secs). It is executed as part of the WriteReport process.
2017-03-15 17:06:38,559|TRACE|Performance|FPMXLClient.Office.ExcelReportWriter.WriteSmart|MYUSER|||||1|Method [Write Smart] end, duration = 264.820 s#
(I have marked it with XXXXXXXXXXXXX in the code at the end of this message to make it easier to find it, but here's the line in question:)
I have serached everywhere for that, but the information about it is scarce.
There is another message in SAP Archive where a fellow BPC guy had a similar problem, but with a big report. We have tried the solution provided there (refreshing from VBA button instead of standard button) but it didn't work in our case.
https://archive.sap.com/discussions/thread/3766795
He says something about clearing data in VBA before refreshing. We did that as well by clearing a cell range with standard Excel methods, but didn't work either. I dind't find any EPM related methods to do so.
We have run through the "Performance Analysis and Optimization for BPC 10" as well.
https://blogs.sap.com/2013/07/09/performance-analysis-and-optimization-for-bpc-10/
So this is what we have tried so far, without success:
- Running it without the Antivirus, as proposed in countless other BPC messages.
- Optimization with zero supression.
- Remaking the report from scratch.
- Copying a very similar working report and modifying it.
- Including a parent member in the report so it runs MDX instead of RSDRI, just in case.
- Tracing it with all the availavle tools until we were sure it is not a server side problem but a Client Side problem (TRACE log in EPM logs, FIDDLER, SLG1, ST01, UJSTAT...)
- Refreshing from VBA macro instead of the standard EPM button.
- The same as last point, but clearing data before that, using standard Excel methods.
- Set paralell execution for the report = active. That one was just in case.
- Force symmetric Refresh for Large Asymmetric Axis in Sheet options.
- Remove zero and empty rows in Sheet options, because who knows...
- We have tried all this using a combination of Win 7, Win 10, Excel 2010, Excel 2013, EPMs SP19 and SP24 from different laptops and different networks, without success.
We are pretty much running out of ideas now.
This is the TRACE log of one of the reports. The other one is pretty much the same As I told you before, "XXXXXX" marks the place:
dynamicReport = BUDGET_GW
forceEliminateEmpty = BG_BUDGET#
2017-03-15 17:02:06,855|DEBUG|Performance|?.?|MYUSER|||||1|Remote call [http://sapbiprod.MYCLIENT.com:8003/sap/bpc/query/BUDGET_GW/BG_BUDGET?method=axis] start#
2017-03-15 17:02:13,450|DEBUG|Performance|?.?|MYUSER|||||1|Remote call [http://sapbiprod.MYCLIENT.com:8003/sap/bpc/query/BUDGET_GW/BG_BUDGET?method=axis] end, duration = 6.595 s#
2017-03-15 17:02:13,455|TRACE|Performance|FPMXLClient.BPCProxy.MetaData_Data.DataServiceHelper.AxisQueryStreamEx|MYUSER|||||1|Method [AxisQueryStreamEx] end, duration = 6.599 s#
2017-03-15 17:02:13,458|TRACE|Performance|FPMXLClient.BPCProxy.MetaData_Data.DataServiceHelper.ExecuteReportAsGzipStream|MYUSER|||||1|Measure [Building report from json stream] start#
2017-03-15 17:02:13,461|TRACE|Performance|FPMXLClient.BPCProxy.MetaData_Data.JsonReportBuilder.BuildReportFromJsonStream|MYUSER|||||1|Measure [Reading Axes and Cells from Json Stream] start#
2017-03-15 17:02:13,639|TRACE|Performance|FPMXLClient.BPCProxy.MetaData_Data.JsonReportBuilder.BuildReportFromJsonStream|MYUSER|||||1|Measure [Reading Axes and Cells from Json Stream] end, duration = 0.174 s#
2017-03-15 17:02:13,640|TRACE|Performance|FPMXLClient.ReportManagement.ReportResult.BuildReportFromRealAxis|MYUSER|||||1|Measure [Building Report from Axes and Cells] start#
2017-03-15 17:02:13,649|TRACE|Performance|FPMXLClient.ReportManagement.ReportResult.BuildReportFromRealAxis|MYUSER|||||1|Measure [Building Report from Axes and Cells] end, duration = 0.007 s#
2017-03-15 17:02:13,650|TRACE|Performance|FPMXLClient.BPCProxy.MetaData_Data.DataServiceHelper.ExecuteReportAsGzipStream|MYUSER|||||1|Measure [Building report from json stream] end, duration = 0.189 s#
2017-03-15 17:02:13,651|TRACE|Performance|FPMXLClient.BPCProxy.MetaData_Data.DataServiceHelper.ExecuteReportAsGzipStream|MYUSER|||||1|Method [ExecuteReportAsStream] end, duration = 6.839 s#
2017-03-15 17:02:13,652|TRACE|Performance|FPMXLClient.Connection.RESTConnection.ExecuteReport|MYUSER|||||1|Method [ExecuteReport] end, duration = 6.841 s#
2017-03-15 17:02:13,653|TRACE|Performance|FPMXLClient.Office.EPMReportManager.ExecuteReportThreadStarter|MYUSER|||||1|Method [ExecuteReportThreadStarter] end, duration = 6.844 s#
2017-03-15 17:02:13,653|TRACE|Performance|FPMXLClient.Office.EPMExcelReportManager.ExecuteReport|MYUSER|||||1|Measure [Execute Report000] end, duration = 6.847 s#
2017-03-15 17:02:13,654|TRACE|Performance|FPMXLClient.Office.EPMExcelReportManager.ExecuteParallelizedReportsFramework4|MYUSER|||||1|Measure [Parallelized Execution] end, duration = 6.852 s#
2017-03-15 17:02:13,656|TRACE|Performance|FPMXLClient.Office.EPMExcelReportManager.RefreshReports|MYUSER|||||1|Measure [Insert Local Members] start#
2017-03-15 17:02:13,657|TRACE|Performance|FPMXLClient.Office.EPMExcelReportManager.RefreshReports|MYUSER|||||1|Measure [Insert Local Members] end, duration = 0.001 s#
2017-03-15 17:02:13,717|TRACE|Performance|FPMXLClient.Office.EPMExcelReportManager.RefreshReports|MYUSER|||||1|Measure [Clear report] start#
2017-03-15 17:02:13,727|TRACE|Performance|FPMXLClient.Office.ExcelReportCleaner.ClearOnData|MYUSER|||||1|Method [ClearOnData] start#
2017-03-15 17:02:13,730|TRACE|Performance|FPMXLClient.Office.ExcelReportCleaner.ClearOnData|MYUSER|||||1|Method [ClearOnData] end, duration = 0.002 s#
2017-03-15 17:02:13,731|TRACE|Performance|FPMXLClient.Office.EPMExcelReportManager.RefreshReports|MYUSER|||||1|Measure [Clear report] end, duration = 0.013 s#
2017-03-15 17:02:13,733|TRACE|Performance|FPMXLClient.Office.EPMExcelReportManager.WriteReport|MYUSER|||||1|Method [Write Report] start#
2017-03-15 17:02:13,737|TRACE|Performance|FPMXLClient.Office.ExcelReportWriter.WriteSmart|MYUSER|||||1|Method [Write Smart] start#
2017-03-15 17:04:10,407|TRACE|Performance|FPMXLClient.Office.ExcelReportWriter.SmartLineSwitch|MYUSER|||||1|Method [Switching Excel Rows] start#
2017-03-15 17:04:35,536|TRACE|Performance|FPMXLClient.Office.ExcelReportWriter.SmartLineSwitch|MYUSER|||||1|Method [Switching Excel Rows] end, duration = 25.127 s#
2017-03-15 17:06:31,962|TRACE|Performance|FPMXLClient.Office.ExcelReportWriter.SmartColSwitch|MYUSER|||||1|Method [Switching Columns] start#
2017-03-15 17:06:31,964|TRACE|Performance|FPMXLClient.Office.ExcelReportWriter.SmartColSwitch|MYUSER|||||1|Method [Switching Columns] end, duration = 0.000 s#
2017-03-15 17:06:31,968|TRACE|Performance|FPMXLClient.Office.ExcelReportWriter.WriteData|MYUSER|||||1|Method [WriteData] start#
2017-03-15 17:06:31,999|TRACE|Performance|FPMXLClient.Office.ExcelReportWriter.WriteData|MYUSER|||||1|Method [WriteData] end, duration = 0.030 s#
2017-03-15 17:06:32,002|TRACE|Performance|FPMXLClient.Office.ExcelReportWriter.WriteRows|MYUSER|||||1|Method [WriteRows] start#
2017-03-15 17:06:32,071|TRACE|Performance|FPMXLClient.Office.EPMExcelMultiRangeManager.SetSmartFormula|MYUSER|||||1|Measure [SetSmartFormula] start#
2017-03-15 17:06:38,535|TRACE|Performance|FPMXLClient.Office.EPMExcelMultiRangeManager.SetSmartFormula|MYUSER|||||1|Measure [SetSmartFormula] end, duration = 6.463 s#
2017-03-15 17:06:38,536|TRACE|Performance|FPMXLClient.Office.ExcelReportWriter.WriteRows|MYUSER|||||1|Method [WriteRows] end, duration = 6.533 s#
2017-03-15 17:06:38,538|TRACE|Performance|FPMXLClient.Office.ExcelReportWriter.WriteColumns|MYUSER|||||1|Method [WriteColumns] start#
2017-03-15 17:06:38,540|TRACE|Performance|FPMXLClient.Office.EPMExcelMultiRangeManager.SetSmartFormula|MYUSER|||||1|Measure [SetSmartFormula] start#
2017-03-15 17:06:38,541|TRACE|Performance|FPMXLClient.Office.EPMExcelMultiRangeManager.SetSmartFormula|MYUSER|||||1|Measure [SetSmartFormula] end, duration = 0.000 s#
2017-03-15 17:06:38,543|TRACE|Performance|FPMXLClient.Office.ExcelReportWriter.WriteColumns|MYUSER|||||1|Method [WriteColumns] end, duration = 0.003 s#
2017-03-15 17:06:38,545|TRACE|Performance|FPMXLClient.Office.ExcelReportWriter.PushUp|MYUSER|||||1|Method [PushUp] start#
2017-03-15 17:06:38,558|TRACE|Performance|FPMXLClient.Office.ExcelReportWriter.PushUp|MYUSER|||||1|Method [PushUp] end, duration = 0.000 s#
XXXXXXXXXXXXXXXXTHISXXXXXXXXXXXXXXXXXXXX
XXXXXXXXXXXXXXXXTHISXXXXXXXXXXXXXXXXXXXX
2017-03-15 17:06:38,559|TRACE|Performance|FPMXLClient.Office.ExcelReportWriter.WriteSmart|MYUSER|||||1|Method [Write Smart] end, duration = 264.820 s#
XXXXXXXXXXXXXXXENDTHISXXXXXXXXXXXXXXXXXXXX
XXXXXXXXXXXXXXXENDTHISXXXXXXXXXXXXXXXXXX
2017-03-15 17:06:38,562|TRACE|Performance|FPMXLClient.Office.ExcelReportFormatter.FormattingReport|MYUSER|||||1|Method [FormattingReport] start#
2017-03-15 17:06:38,569|TRACE|Performance|FPMXLClient.Office.ExcelReportFormatter.FormattingReport|MYUSER|||||1|Method [FormattingReport] end, duration = 0.001 s#
2017-03-15 17:06:38,570|TRACE|Performance|FPMXLClient.Office.ExcelReportWriterHelper.CopyPasteInsertedZone|MYUSER|||||1|Measure [InsertAfterRange 000] start#
2017-03-15 17:06:38,585|TRACE|Performance|FPMXLClient.Office.ExcelReportWriterHelper.CopyPasteInsertedZone|MYUSER|||||1|Measure [InsertAfterRange 000] end, duration = 0.000 s#
2017-03-15 17:06:38,586|TRACE|Performance|FPMXLClient.Office.ExcelReportWriterHelper.CopyPasteInsertedZone|MYUSER|||||1|Measure [InsertAfterRange 000] start#
2017-03-15 17:06:38,587|TRACE|Performance|FPMXLClient.Office.ExcelReportWriterHelper.CopyPasteInsertedZone|MYUSER|||||1|Measure [InsertAfterRange 000] end, duration = 0.000 s#
2017-03-15 17:06:38,588|TRACE|Performance|FPMXLClient.ReportManagement.DynamicReport.Save|MYUSER|||||1|Measure [Save report] start#
2017-03-15 17:06:38,612|TRACE|Performance|FPMXLClient.ReportManagement.DynamicReport.Save|MYUSER|||||1|Measure [Save report] end, duration = 0.023 s#
2017-03-15 17:06:38,614|TRACE|Performance|FPMXLClient.Office.EPMExcelReportManager.WriteReport|MYUSER|||||1|Method [Write Report] end, duration = 264.879 s#
2017-03-15 17:06:38,617|TRACE|Performance|FPMXLClient.Office.EPMExcelReportManager.LoadReports|MYUSER|||||1|Method [Load Reports] start#
2017-03-15 17:06:38,618|TRACE|Performance|FPMXLClient.Office.EPMExcelReportManager.LoadReports|MYUSER|||||1|Method [Load Reports] end, duration = 0.000 s#
This is our SAP system, although it is not a server side problem:
SAP BW 7.30 SP015
CPMBPC800 SP022
Please, if you have any ideas or different approaches to this problem, let us know.
Thanks a lot.
Edit: We also tried disabling ScreenUpdating, EnableEvents and AutomaticCalculation in VBA before refreshing. No luck.
Application.ScreenUpdating = False
Application.EnableEvents = False
Application.Calculation = xlCalculationManual
You must be a registered user to add a comment. If you've already registered, sign in. Otherwise, register and sign in.