Switching from Data to Charts in Report Builder is slow

Ryan Kearbey shared this problem 2 months ago
Defect Logged

Hello,

We've noticed in Report Builder that switching from Data -> Charts is slow. It may have something to do with the Timestamp filter. If the Timestamp filter is set to a pre-defined "Last 1 hour" then the switching is pretty fast. However, if the Timestamp filter is set to "Last 24 hours" or "Last 7 days" then the switching increasingly becomes slower based on duration of Timestamp filter. We tried disabling Auto refresh in both the Data and Charts.

Is YF looking at the Time filter when switching to Charts?

Are there any config settings we need to adjust?

Attached is a .har file that may help your investigation. Open chrome browser. right click anywhere on a page > inspect elements > go to network tab > drag and drop the . har file You should see the logs.

Comments (11)

photo
1

Please note that I don't know for sure exactly it's the Timestamp filter causing the issue. It's just an assumption based on the behavior we're seeing.

photo
1

Hi Ryan, Thanks for reaching out.

Are you able to provide debug logs of the tab switching process as well? You can upload to our ftp https://ftp.yellowfin.bi using "send files" option, just reply here with a filename and timestamp (as exact as possible) of the switch action if you could please.

I can see a couple of actions in mine - with report preview disabled there are still some processes taking place on the "click" -

1. chart builder request -

YF:2022-05-12 09:22:13.552:DEBUG (i4RequestRegistry) - Registering Request /MIChartBuilder.i4;tab_token=5cae47b4-e906-4dcf-a017-18a98de3da71;m=1 Thread 557171074
YF:2022-05-12 09:22:13.552:DEBUG (SessionUtil) - [41] [Unknown] [Unknown] Finding Tab_Token for /MIChartBuilder.i4;tab_token=5cae47b4-e906-4dcf-a017-18a98de3da71;m=1


2. Filter output loaded - not sure if this is report data, or config db action

YF:2022-05-12 09:22:14.165:DEBUG (MIReportOutputAjaxAction) - [48] [52373755] [/MIReportOutputAjax.i4] ==> Requested action: loadFilterOutput


3. Report is updated with any changes -

YF:2022-05-12 09:47:27.117:DEBUG (ReportDataAjaxAction) - [49] [75E60F98] [/ReportDataAjax.i4] Requested action: saveReportDefinition


4. loads new page -

YF:2022-05-12 09:47:27.326:DEBUG (ReportDataAction) - [59] [75E60F98] [/ReportData.i4] ==> Requested action: navigateTo

Chart definitions loaded -


YF:2022-05-12 09:47:27.615:DEBUG (ResourceLoaderAjaxAction) - [61] [75E60F98] [/ResourceLoaderAjax.i4] ==> Requested action: loadChartDefinitions

So it could be part of the save process, or the definition load process... Do you see any gaps in the debug logs that could provide clues?

Thanks,

Eric

photo
1

Hi Eric,

When I click on "Charts" I noticed this is the log:

  • {"log":"YF:2022-05-13 21:36:58.935: INFO (ReportDataAction) - [738609] [E1C10606] [/ReportData.i4] ReportDataAction exiting with action: MIChartBuilder\n","stream":"stdout","time":"2022-05-13T21:36:58.935943524Z"}

If my Time filter set in the report is very long, let's say Last 7 Days for example, then the loading animation spins for upwards of 10 minutes or so. If it goes much beyond then an error thrown by our database.

  • {"log":"YF:2022-05-13 21:20:34.121:ERROR (DBAction) - [738610] [E1C10606] [/MIPreChartBuilder.i4] Error occured selecting data: java.sql.SQLTransientException: [Vertica][VJDBC](3322) ERROR: Execution canceled by operator\n","stream":"stdout","time":"2022-05-13T21:20:34.124629395Z"}
  • {"log":"java.sql.SQLTransientException: [Vertica][VJDBC](3322) ERROR: Execution canceled by operator\n","stream":"stdout","time":"2022-05-13T21:20:34.124710046Z"}

Sometimes, it works. At around 9 minutes during a test and I saw this in the log, and the Chart screen loaded.

  • {"log":"YF:2022-05-13 21:36:58.935: INFO (ReportDataAction) - [738609] [E1C10606] [/ReportData.i4] ReportDataAction exiting with action: MIChartBuilder\n","stream":"stdout","time":"2022-05-13T21:36:58.935943524Z"}
  • <9 minutes gap>
  • {"log":"YF:2022-05-13 21:45:24.960: INFO (ActivityAjaxAction) - [750399] [E1C10606] [/ActivityAjax.i4] ActivityAjaxAction entered\n","stream":"stdout","time":"2022-05-13T21:45:24.96024471Z"}
  • {"log":"YF:2022-05-13 21:45:24.969: INFO (ColourPickerAjaxAction) - [54] [E1C10606] [/ColourPickerAjax.i4] ColourPickerAjaxAction entered\n","stream":"stdout","time":"2022-05-13T21:45:24.969579717Z"}
  • {"log":"YF:2022-05-13 21:45:25.806: INFO (MIChartBuilderAjaxAction) - [37] [E1C10606] [/MIChartBuilderAjax.i4] Requested action: loadFunctionList\n","stream":"stdout","time":"2022-05-13T21:45:25.806931991Z"}

If I set the Time filter to something like Last 5 minutes, it moves from Data into Chart screen very fast.

Also, I checked the both Show Duplicates in the report (so it won't do a select distinct), and disabled Auto Refresh in the chart builder.

I guess the question is does MIChartBuilder do a SQL query based on Time filter every time a user goes from Data -> Charts? If so, why does it do this even with chart auto refresh disabled?

photo
1

Hi Eric, some additional info.

I ran some tests and Yellowfin does appear to execute a query every time we switch from Data into Charts. (Well, we observed once when it didn't run a query for some odd reason, but most of the time it will query the db). We even tried it with deleting the existing chart, leaving only the default Auto Chart, and it still ran a query.

Tried it with setting the Time filter format default to Last 1 hour and when clicking from Data to Charts it kicked off this query:

2022-05-16 14:26:22.797 Init Session:0x7f0eb0fce700-15000000954e10d [Txn] <INFO> Rollback Txn: 15000000954e10d 'SELECT (SUM("cemup_hrly"."dn_byte") + SUM("cemup_hrly"."up_byte")) / 1000 / 1000 / 1000 / 1000 FROM "s_cemup"."cemup_hrly" WHERE ( "cemup_hrly"."timestamp" BETWEEN '2022-05-16 10:26:22.571' AND '2022-05-16 11:26:22.571' AND "cemup_hrly"."state" IN ('MG') AND "cemup_hrly"."city" IN ('BELO HORIZONTE') AND "cemup_hrly"."service_category" IS NOT NULL ) GROUP BY 1000 / 1000 / 1000 / 1000 LIMIT 10000'

Auto Refresh has been disabled in both the Report Builder (Data) and Charts.

/4f46199df9864dfdb74f770a84a46467

Charts:

/41102e3824de51505fbfc97ff810f629


So the question remains why it kicks off a query with Auto refresh disabled? If I set this to Last 7 days then the query takes too long and we get the error per my previous post in this thread. Is there a way to completely disable the Report Builder from querying the db until I manually click "Refresh"?

photo
1

Hi Ryan,

Thanks for the reply. So you are seeing this query as received in the SQL server logs? Interesting! Does the timing line up with any notable debug log actions? More succinctly, does it look associated with that same loadfilter output action I noted in my YF logs, prior to the savereportdefinition?

I think this sounds like a bug, would you agree? That select with filter call shouldn't be running at all with preview disabled, in my opinion... but maybe there's a reason...?

Unfortunately I don't have that answer, yet, but I have all I need to send off to devs for analysis, if you agree this is a good way forward.

Thanks,

Eric

photo
1

Hi Eric,

Yes, we see this query hit our db logs when we switch from Data into Charts. It lines up with the MIChartBuilder action in the YF logs.

We believe it's also a bug as auto refresh is disabled.

Can you please open a ticket with the devs, and share that ticket number with us? Would appreciate making this high priority since it's affecting the productivity of the users building the reports/charts.


Thank you again for your support,

Ryan

photo
1

Hi Ryan,

Thanks for the reply. I did some monitoring myself and think I can see this in action - can you take a look at the video below and confirm this is the "rogue query" you're seeing? I can get this to devs with a High priority marked right away then.

https://youtu.be/UGL4okpChFo

Thanks,

Eric

photo
1

Hi Eric, I think you got it! If a Timestamp filter was also used, then it would add it into the query. In our case, the longer apart the start/end times in the Timestamp filter, the longer it takes to go from Data into Charts.


Thanks,

Ryan

photo
2

Hi Ryan,


Thanks for confirming for me. I've gone ahead and created a developer task to look into this behavior. I've added your organization as an affected client, and attached this ticket to the task for tracking purposes. Updates to this task will be provided here as they are available. I'll in turn mark this ticket as Defect Logged for now; feel welcome to reply here with any related inquiries.

Thanks,

Eric

photo
1

Thanks Eric. Will you please share the ticket # with me? I need it to track with our internal team.

Ryan

photo
2

Hi Ryan,

Ticket ID on this is YFN-24514.

Thanks,

Er