Major Problem with Qlikview QVDistributionService.exe

[#1]

I am new to Qlikview and don't know much about memory leaks, but that is what I appear to have going on.

Our Management Console has been running the same jobs for over a year now with no problems.  In the last few days, it takes jobs that run in one hour over three hours to run.  Every jobs run-time is magnified (increased) by at least three to four times.

The only thing I really knew to do was look at the Windows Task Manager to see what all was running in Processes.  I appears as though the QVDistributionService.exe just continues to increase the memory even when NOTHING is running.  I think this runs until it maxes out and then my Qlikview jobs won't run anymore.

Does anyone know why console jobs would take 4X longer to run than before?

Thanks,

Joel

PS:  I am very green at this.

[marcus_sommer]

At first I would do a restart of the qlikview services and if it's not worked of the whole machine - just to exclude strange an most often not traceable issues.

After that I would check if there was any changes within the qlikview settings or within the OS. Further I would take a look on the loadings itself because small changes here could have a huge impact, for example by loading tables with:

select * from source

there could be more fields included or fields are now missing which could effects join-statements or the table-associations within the datamodels.

- Marcus

[Colin-Albert]

In addition to the service / server restart suggested by marcus_sommer‌ , can you identify which version, release & build number of QlikView your server is running, as you may have an issue that a later release has resolved.

You can find this on the Management Console (QMC) under System, About and let us know your Client Build Number

[stabben23]

Hi,

what Version on .NET? there is some issues With .NET4.

[Peter_Cammaert]

The TaskLog of a job that suddenly takes three times as long to complete may contain some useful information about what the scheduler (or the reload engine) is doing during that time.

Logs are kept a default minimum of 30 days.

[#6]

Thanks everyone for replying so far. I am going to have our admin restart the server that Qlikview is residing on.  Turns out he didn't do this when asked before, so I thought bouncing the server didn't work and posted my question here.  I will update you all afterwards, and go from there.  If I am still having a problem, I might try and dig into the logs like Peter suggested. 

Peter, can you direct me to a step by step guide to follow to find appropriate logs for analysis?

Thanks,

Joel

[Peter_Cammaert]

The Qlikview Distribution Serviece is the process that manages reload processes for QlikView Server. Detailed logs can be found in C:\ProgramData\QlikTech\DistributionService\1\Log\ (folder may be different if you operate a cluster)

In that folder, you'll find subdirectories with date stamps (usually30 days back). Open the day folder for your erroneous reload. In a day folder; you'll find subdirectories with the task name and a timestampt (in case tasks are executed multiple times in the same day). Open the one you need.

Every folder contains a DocumentLog and a TaskLog. If the reloaded document is distributed in additiion, you'll have a Distibution report in XML format as well.

Indeed, time and date information of the erroneous reload task is good to have...

[Colin-Albert]

Hi Joel,

The document log is only recorded if you enable Generate Logfile on the document properties tab.

By default this option is off.

[#9]

Thanks so far, guys. 

IT rebooted the server and I still have the same slowness issue.

So I went in there and have the log open and don't see anything strange, but maybe you guys would be able to identify something that would cause a job to run way too long. 

Like I said before, This job normally took 1 hour and 5 minutes and now it is taking bout 2.5 hours on a consistent basis.  It usually doesn't error out, but completes successfully. This is taking way too long to complete when you consider that nothing has changed with regard to Qlikview settings or code in the actual Qlikview jobs.  However, I cannot speak for the actual server Qlikview/Management Console sits on, since IT deals with that.  It literally went from these jobs running okay last Thursday/Friday to running this way the following Monday of this week.

Our IT server guy is trying to get out of it by saying to contact the vendor (they always do that), but my gut tells me that something is wrong with the way the OS is allowing things to run, but I am not a server guy.

I should also add that these jobs all ran at normal speeds and now are all running consistently 2.5 to 3 times more slowly, just like the job I am posting here about.  So this is a universal problem.

FYI, I can also attach the server cpu graphs our IT guy sent me, if this would help.  Just let me know if you are interested.

I didn't see any way to attach a file to this thread, so here is a copy/paste of the TaskLog.txt for the job in question:

-------------------------------------------------------------------------------------------------------------------------------------

8/22/2017 07:28:39.6088311 Information Starting task 'Step1_BIT_Build'. Id:1f7dceef-e176-40c1-ac8d-e5bee1069156. Triggered by 'TaskCompletedTrigger'. Id:b861430a-8ace-40d6-a737-d817cdca1c8d

8/22/2017 07:28:39.6088311 Information Entering Task Execution.

8/22/2017 07:28:39.6088311 Information ClusterID=1

8/22/2017 07:28:39.6088311 Information QDSID=90e316dd-12a8-634d-d41e-12e0f9f86f85

8/22/2017 07:28:39.6088311 Information TaskID=1f7dceef-e176-40c1-ac8d-e5bee1069156

8/22/2017 07:28:39.6088311 Information MaxRunTime=1.00:00:00

8/22/2017 07:28:39.6088311 Information MachineName=W2K8BIT03

8/22/2017 07:28:39.6088311 Information Max attempts:1

8/22/2017 07:28:39.6088311 Information Current Attempt=0

8/22/2017 07:28:39.6088311 Information Task Dependencies are OK

8/22/2017 07:28:39.6244314 Information Document is marked to be Reloaded with fresh data. Initializing Reload for Distribution.

8/22/2017 07:28:39.6712323 Information Opening "\\W2K8BIT01\D\QlikView_Server\SourceDocuments\New BIT Build QVWs\Step_1_VCHG_PFT_PHY.qvw"

8/22/2017 07:28:39.6712323 Information Allocating new QlikView Engine. Current usage count=1 of 4 (of type non-reader).

8/22/2017 07:28:39.6712323 Information Max retries:5

8/22/2017 07:28:39.6712323 Information Attempt:01

8/22/2017 07:28:40.2952443 Information Opened the QlikView Engine successfully. ProcessID=26484

8/22/2017 07:28:40.2952443 Information Allocated QlikView Engine successfully. Current usage count=2 of 4 (of type non-reader). Ticket number=11.

8/22/2017 07:28:40.3108446 Information Loading document "\\W2K8BIT01\D\QlikView_Server\SourceDocuments\New BIT Build QVWs\Step_1_VCHG_PFT_PHY.qvw" (2271.17 Mb)

8/22/2017 07:28:41.3092638 Information Loading. LoadTime=00:00:01.0140195

8/22/2017 07:28:43.3342030 Information Loading. LoadTime=00:00:03.0389587

8/22/2017 07:28:47.3865815 Information Loading. LoadTime=00:00:07.0913372

8/22/2017 07:28:55.4956377 Information Loading. LoadTime=00:00:15.2003934

8/22/2017 07:29:11.6844499 Information Loading. LoadTime=00:00:31.3892056

8/22/2017 07:29:39.4069853 Information Physical FileSize=2271.17 Mb. Memory Allocation Delta for this file=3.57 Mb. Available Physical Memory Before Open=91321.20 Mb. Available Physical Memory After Open=91312.57 Mb. Total Physical Memory=122879.49 Mb.

8/22/2017 07:29:39.4069853 Information Attempted to load the document without data.

8/22/2017 07:29:39.4069853 Information The document was loaded successfully.

8/22/2017 07:29:39.4069853 Information Document was opened successfully

8/22/2017 07:29:39.4069853 Information Starting reload

8/22/2017 07:29:39.4225856 Information QlikView->Settings->Document Peferences->Generate Logfile in document is not set.

8/22/2017 07:29:39.4225856 Information The Source Document is being reloaded. DocumentPath=\\W2K8BIT01\D\QlikView_Server\SourceDocuments\New BIT Build QVWs\Step_1_VCHG_PFT_PHY.qvw

8/22/2017 07:29:40.4098050 Information Reloading.

8/22/2017 07:29:41.4238245 Information Reloading..

8/22/2017 07:29:42.4378440 Information Reloading...

8/22/2017 07:29:43.4674638 Information Reloading....

8/22/2017 07:29:44.4814833 Information Reloading.....

8/22/2017 07:29:45.4968035 Information Reloading......

8/22/2017 07:29:46.5108230 Information Reloading.......

8/22/2017 07:29:47.5248425 Information Reloading........

8/22/2017 07:29:48.5388620 Information Reloading.........

8/22/2017 07:29:49.5528815 Information Reloading..........

8/22/2017 07:29:50.5657016 Information Slow down logging. Log every <2> seconds.

8/22/2017 07:29:50.5657016 Information Reloading

8/22/2017 07:29:52.5937406 Information Reloading.

8/22/2017 07:29:54.6217796 Information Reloading..

8/22/2017 07:29:56.6436190 Information Reloading...

8/22/2017 07:29:58.6872583 Information Reloading....

8/22/2017 07:30:00.6759967 Information Reloading.....

8/22/2017 07:30:02.7246362 Information Reloading......

8/22/2017 07:30:04.7526752 Information Reloading.......

8/22/2017 07:30:06.7776144 Information Reloading........

8/22/2017 07:30:08.8056534 Information Reloading.........

8/22/2017 07:30:10.8336924 Information Reloading..........

8/22/2017 07:30:12.8630321 Information Slow down logging. Log every <10> seconds.

8/22/2017 07:30:12.8630321 Information Reloading

8/22/2017 07:30:22.9933280 Information Reloading.

8/22/2017 07:30:33.1211238 Information Reloading..

8/22/2017 07:30:43.2414193 Information Reloading...

8/22/2017 07:30:53.3667150 Information Reloading....

8/22/2017 07:31:03.4995110 Information Reloading.....

8/22/2017 07:31:13.6223066 Information Reloading......

8/22/2017 07:31:23.7451022 Information Reloading.......

8/22/2017 07:31:33.8834981 Information Reloading........

8/22/2017 07:31:44.0137940 Information Reloading.........

8/22/2017 07:31:54.1621903 Information Reloading..........

8/22/2017 07:32:04.2918865 Information Slow down logging. Log every <60> seconds.

8/22/2017 07:32:04.2918865 Information Reloading

8/22/2017 07:33:05.0505613 Information Reloading.

8/22/2017 07:34:05.7837367 Information Reloading..

8/22/2017 07:35:06.5199106 Information Reloading...

8/22/2017 07:36:07.2492852 Information Reloading....

8/22/2017 07:37:07.9942601 Information Reloading.....

8/22/2017 07:38:08.7029329 Information Reloading......

8/22/2017 07:39:09.4584066 Information Reloading.......

8/22/2017 07:40:10.2108818 Information Reloading........

8/22/2017 07:41:10.9632557 Information Reloading.........

8/22/2017 07:42:11.7344310 Information Reloading..........

8/22/2017 07:43:12.5367056 Information Slow down logging. Log every <300> seconds.

8/22/2017 07:43:12.5367056 Information Reloading

8/22/2017 07:48:16.2943772 Information Reloading.

8/22/2017 07:53:20.0273436 Information Reloading..

8/22/2017 07:58:23.6700106 Information Reloading...

8/22/2017 08:03:27.4091766 Information Reloading....

8/22/2017 08:08:31.0834413 Information Reloading.....

8/22/2017 08:13:34.8495087 Information Reloading......

8/22/2017 08:18:38.5655741 Information Reloading.......

8/22/2017 08:23:42.3395389 Information Reloading........

8/22/2017 08:28:46.0436022 Information Reloading.........

8/22/2017 08:33:49.7264701 Information Reloading..........

8/22/2017 08:38:55.5370439 Information Slow down logging. Log every <600> seconds.

8/22/2017 08:38:55.5370439 Information Reloading

8/22/2017 08:49:03.0816508 Information Reloading.

8/22/2017 08:59:09.7938095 Information Reloading..

8/22/2017 09:09:16.2711857 Information Reloading...

8/22/2017 09:19:22.7558596 Information Reloading....

8/22/2017 09:29:29.4043326 Information Reloading.....

8/22/2017 09:39:35.7564313 Information Reloading......

8/22/2017 09:49:42.1201992 Information Reloading.......

8/22/2017 09:50:51.1060346 Information The Source Document reload complete. DocumentPath=\\W2K8BIT01\D\QlikView_Server\SourceDocuments\New BIT Build QVWs\Step_1_VCHG_PFT_PHY.qvw

8/22/2017 09:50:51.1060346 Information Memory Allocation Delta for this file=9273.16 Mb. Available Physical Memory Before Reload=91312.57 Mb. Available Physical Memory After Reload=67673.93 Mb. Total Physical Memory=67673.93 Mb.

8/22/2017 09:50:51.4804418 Information The Source Document was reloaded successfully.

8/22/2017 09:50:51.4804418 Information Reload finished successfully

8/22/2017 09:50:51.4804418 Information Start saving document

8/22/2017 09:55:12.9236976 Information Check in document: \\W2K8BIT01\D\QlikView_Server\SourceDocuments\New BIT Build QVWs\Step_1_VCHG_PFT_PHY.qvw

8/22/2017 09:55:12.9392979 Information Closing the document.

8/22/2017 09:55:14.2653234 Information Closed the QlikView Engine successfully. ProcessID=26484

8/22/2017 09:55:14.2653234 Information No distribution required.

8/22/2017 09:55:14.2653234 Information Task Execute Duration=02:26:34.6564923

8/22/2017 09:55:14.2653234 Information The task "Step1_BIT_Build" finished successfully

8/22/2017 09:55:14.2653234 Information TaskResult.status=Finished

8/22/2017 09:55:14.2653234 Information Notifying all triggers of new state:Finished

8/22/2017 09:55:14.2653234 Information Notifying all triggers of new state:Finished - completed

8/22/2017 09:55:14.2653234 Information Saving Task Result

-------------------------------------------------------------------------------------------------------------------------------------

Thanks,

Joel

[#10]

Colin,

To answer your question, here is my Qlikview information you asked about:

Client Build Number:  11.20.12235.0

Thanks,

Joel