I'm having a random issue with the auto-reloading of my QlikView document using QlikView Server 10 and I'm hoping someone can give me some pointers.
I'm running QlikView Server 10 on a machine with 8 GB RAM. My server only hosts 1 QlikView document (other that the out of the box demo documents which are not set to reload).
The SQL database my document is reading from is fairly large, about 20 GB but is running on a very powerful dedicated SQL Server with 24 GB RAM and 8 CPU Cores. However this database is accessed 24 hours a day, with heavy usage between 8 am and 7 pm (approx 70 users) and lighter usage during off peak hours (about 10 users).
My QlikView document does have section access and I have defined this in the Reload information tab for the document.
The reload seems to work fine on some days, and seems to fail on others. Its very random. Ironically I have found that scheduling it at 10:55 am (peak hours) seems to result in fewer failures than scheduling it at 3:30 am (off-peak hours).
When the reload works properly, it reloads the document in under 15 mins.
When it fails, here's what the logs show: (there are several lines that are repeated which I have omitted below to keep this post short). I've also posted the entire reload log as an attachment.
(2011-09-18 10:55:05) Information: Executing ClusterID=1, QDSID=7a6f619a-390f-3161-f352-ed66dc3e21b9 QDSMain.DistributeTask
(2011-09-18 10:55:05) Information: Starting task "QSI Visual Analyzer.qvw" (Attempt 1 of 1)
(2011-09-18 10:55:05) Information: Max run time: 02:51:00
(2011-09-18 10:55:06) Information: Document is marked for refresh; Initializing Reload.
(2011-09-18 10:55:07) Information: Opening "C:\ProgramData\QlikTech\Documents\QSI Visual Analyzer.qvw"
(2011-09-18 10:55:07) Information: Allocating QlikView Engine
(2011-09-18 10:55:07) Information: Allocating new QlikView Engine. Current usagecount=1 of 2
(2011-09-18 10:55:07) Information: An instance of the QlikView Engine is being created
(2011-09-18 10:55:07) Information: Starting QlikView Engine
(2011-09-18 10:55:10) Information: Allocated QlikView Engine successfully. Current usagecount=1 of 2, Ticket=5
(2011-09-18 10:55:11) Information: Loading document "C:\ProgramData\QlikTech\Documents\QSI Visual Analyzer.qvw" (209.05 Mb)
(2011-09-18 10:55:11) Information: Loading. LoadTime=00:00:01
(2011-09-18 10:55:13) Information: Loading. LoadTime=00:00:03
(it keeps repeating the line above every minute until 2011-09-18 11:54)
(2011-09-18 11:54:16) Information: Loading. LoadTime=00:59:05.2500000
(2011-09-18 11:54:18) Information: Physical FileSize=209.05 Mb. Memory Allocation Delta for this file=866.64 Mb. Available Physical Memory Before Open=3854.39 Mb. Available Physical Memory After Open=2970.10 Mb. Total Physical Memory=8190.60 Mb.
(2011-09-18 11:54:30) Information: The document was loaded successfully.
(2011-09-18 11:54:30) Information: Initializing Checkout (0), Loading document (3719), Initializing load (3719), Checking read (3719), Creating QlikView Engine (3922), Checking Size (9203), Load (S&A) (9203), Load Completed (3249266), Tables read (3544078), Opened successfully (3563078)
(2011-09-18 11:54:30) Information: Document was opened successfully
(2011-09-18 11:54:30) Information: Opened successfully (0)
(2011-09-18 11:54:30) Information: Starting reload
(2011-09-18 11:54:31) Information: Reloading.
(2011-09-18 11:54:32) Information: Reloading..
(2011-09-18 11:54:33) Information: Reloading...
(2011-09-18 11:54:36) Information: QlikView->Settings->Document Peferences->Generate Logfile in document is not set.
(2011-09-18 11:54:36) Information: The Source Document is being reloaded. DocumentPath=C:\ProgramData\QlikTech\Documents\QSI Visual Analyzer.qvw
(2011-09-18 11:54:37) Information: Reloading.......
(it continues with the Reloading message above until 2011-09-18 13:46)
(2011-09-18 13:43:35) Information: Reloading....
(2011-09-18 13:46:01) Error: Aborting Reload. Error=QDSMain.TaskResult
(2011-09-18 13:46:16) Warning: The QlikView Engine is Reloading, it will be killed (Please ignore logged warnings/errors about the kill).
(2011-09-18 13:46:16) Information: Killing the QlikView Engine. ProcessID=3688
(2011-09-18 13:46:18) Error: Reload was aborted.
(2011-09-18 13:46:18) Information: Initializing Reload (0), Initializing (6705406), Finished (6706922)
(2011-09-18 13:46:18) Information: Closed the QlikView Engine successfully. ProcessID=3688
(2011-09-18 13:46:18) Information: Finished (0)
(2011-09-18 13:46:18) Error: Task aborted.
(2011-09-18 13:46:18) Error: The task "QSI Visual Analyzer.qvw" failed. ErrorCount=3
(2011-09-18 13:46:18) Information: Sending Alert Mail to 2 recipients.
Note that I have had successful reloads, at the very same time (10:55 am) as well...my success rate is about 50%. Would appreciate any insight the experts can offer.
Are there any maintenance tasks running on the SQL Server that are perhaps slowing down the reload, disonnecting the model during reload or even preventing access altogether?
Thanks for your responses.
Not sure what you mean by Document log. I assume you mean the log file that I attached with my original post? That doesn't seem to indicate what the issue is.
The task execution timeout is set to 10260. I reduced it from the default since the server would constantly keep retrying and causing performance issues on the database.
I believe the issue with the reload failing at 3 am was due to a backup task running which is why I've changed it to 10:55 am which seems to work better somehow.
I suspect my issue has to do with deadlocks on the database, especially since its an inconsistent issue. However since this is a large database that's used 24/7 its hard to figure out when the best time to reload it would be. I wish the QlikView server logs would indicate what the error was.
What you posted was the TaskLog. The Document Log will be named QSI Visual Analyzer.qvw.log and will be in the same directory as QSI Visual Analyzer.qvw. -- If you have "Generate Logfile" checked on in the Document Properties, General. If it's not on, check it on so you a have a log for the next failure. If you are getting an error from the DBMS, like a deadlock, there should be a message in the Document Log.
10260 is a funny sounding exec timeout. Is this the "Timeout in Minutes" value on the QEMC Task Triggers page? Or something set in the SQL server as seconds? Because it's just about the length of your execution...
Thanks for the follow up. I have updated the document so that logging is enabled, hopefully that will provide more insight.
The 10260 timeout value is the value set on the Reload tab of the document (in QlikView Enterprise Mgmt Console) under the "Timeout seconds" field.
My execution was probably terminated because the timeout was reached.
I have the same situation as yours. Do you have any hints to check?
I doubt that my DB server cannot have enough thread. And I have too many connection running at the same time.
Just want to find some evidence to prove that is the problem of DB instead of Qlikview.
Unfortunately I wasn't able to find a definitive answer to this. In my case I had to "experiment" with running the reload at different times during the day and found that ironically, running the reload during production hours seemed to be more successful than at non-production hours like 5 am.
However I do suspect the issue had to do with some database locks/processes. The database in question had a lot of after-hours processing and changes being done to it during non-production hours so its quite likely that these were causing locks and making the document reload fail.
Unfortunately in my case the document log doesn't indicate an issue any more since changing the timing of the reload resolved the issue for me and now it seemingly works fine, the log has no errors.
The issue I was having was over 2 years ago so I don't have logs for that time.