Error in QlikView Server Reload - Qlik Community

Report Inappropriate Content · ‎2015-12-24

Hello,

Since the beginning of the week, we have a problem when loading taks. The execution of these tasks worked perfectly until this week.

The problem began to occur for the first time last Saturday. It didn't occur since this last night where it failed again. The log
error isn't explicit:

I join the DocumentLog.txt

24/12/2015 00:56:46.9632194 Information 24/12/2015 00:56:46: Execution started.

24/12/2015 00:56:46.9632194 Information 24/12/2015 00:56:46: QlikView Version:11.20.12577.0

24/12/2015 00:56:46.9632194 Information 24/12/2015 00:56:46: CPU Target x64

24/12/2015 00:56:46.9632194 Information 24/12/2015 00:56:46: Operating System Windows Server 2012 R2 Standard (64 bit edition)

24/12/2015 00:56:46.9632194 Information 24/12/2015 00:56:46: Wow64 mode Not using Wow64

24/12/2015 00:56:46.9632194 Information 24/12/2015 00:56:46: MDAC Version 6.3.9600.16384

24/12/2015 00:56:46.9632194 Information 24/12/2015 00:56:46: MDAC Full Install Version 6.3.9600.16384

24/12/2015 00:56:46.9632194 Information 24/12/2015 00:56:46: PreferredCompression 2

24/12/2015 00:56:46.9632194 Information 24/12/2015 00:56:46: EnableParallelReload 1

24/12/2015 00:56:46.9632194 Information 24/12/2015 00:56:46: ParallelizeQvdLoads 1

24/12/2015 00:56:46.9632194 Information 24/12/2015 00:56:46: AutoSaveAfterReload 0

24/12/2015 00:56:46.9632194 Information 24/12/2015 00:56:46: BackupBeforeReload 0

24/12/2015 00:56:46.9632194 Information 24/12/2015 00:56:46: EnableFlushLog 0

24/12/2015 00:56:46.9632194 Information 24/12/2015 00:56:46: SaveInfoWhenSavingFile 0

24/12/2015 00:56:46.9788475 Information 24/12/2015 00:56:46: UserLogfileCharset 1200

24/12/2015 00:56:46.9788475 Information 24/12/2015 00:56:46: OdbcLoginTimeout -1

24/12/2015 00:56:46.9788475 Information 24/12/2015 00:56:46: OdbcConnectionTimeout -1

24/12/2015 00:56:46.9788475 Information 24/12/2015 00:56:46: ScriptWantsDbWrite false

24/12/2015 00:56:46.9788475 Information 24/12/2015 00:56:46: ScriptWantsExe false

24/12/2015 00:56:46.9788475 Information 24/12/2015 00:56:46: LogFile CodePage Used: 1200

24/12/2015 00:56:46.9788475 Information 24/12/2015 00:56:46: Reload Executed By DOMBS1\capcir

24/12/2015 00:56:46.9944718 Information 24/12/2015 00:56:46: Process Executing: QVB

And the TaskLog.txt

24/12/2015 00:56:45.4476092 Information Starting task 'CORINFO RELOAD/2_Modeles/Transformation_donnees.qvw'. Id:9edd7bd1-2be6-4532-8fec-ce5522c95430. Triggered by 'TaskCompletedTrigger'. Id:28743846-5734-4340-90c2-2f0d2dfa5953

24/12/2015 00:56:45.4632275 Information Entering Task Execution.

24/12/2015 00:56:45.4632275 Information ClusterID=1

24/12/2015 00:56:45.4632275 Information QDSID=61453a03-80c7-5ed9-788d-fc257b361969

24/12/2015 00:56:45.4632275 Information TaskID=9edd7bd1-2be6-4532-8fec-ce5522c95430

24/12/2015 00:56:45.4632275 Information MaxRunTime=06:00:00

24/12/2015 00:56:45.4632275 Information MachineName=SRVCLIKVIEW

24/12/2015 00:56:45.4632275 Information Max attempts:1

24/12/2015 00:56:45.4632275 Information Current Attempt=0

24/12/2015 00:56:45.4632275 Information Task Dependencies are OK

24/12/2015 00:56:45.6038715 Information Document is marked to be Reloaded with fresh data. Initializing Reload for Distribution.

24/12/2015 00:56:45.6195936 Information Opening "D:\QLIKVIEW\CORINFO APPLICATION\2_Modeles\Transformation_donnees.qvw"

24/12/2015 00:56:45.6195936 Information Allocating new QlikView Engine. Current usage count=0 of 2 (of type non-reader).

24/12/2015 00:56:45.6195936 Information Max retries:5

24/12/2015 00:56:45.6195936 Information Attempt:01

24/12/2015 00:56:46.7288612 Information Opened the QlikView Engine successfully. ProcessID=5372

24/12/2015 00:56:46.7288612 Information Allocated QlikView Engine successfully. Current usage count=1 of 2 (of type non-reader). Ticket number=42.

24/12/2015 00:56:46.7288612 Information Loading document "D:\QLIKVIEW\CORINFO APPLICATION\2_Modeles\Transformation_donnees.qvw" (0.21 Mb)

24/12/2015 00:56:46.8694747 Information Physical FileSize=0.21 Mb. Memory Allocation Delta for this file=3.13 Mb. Available Physical Memory Before Open=6155.48 Mb. Available Physical Memory After Open=6242.05 Mb. Total Physical Memory=16383.55 Mb.

24/12/2015 00:56:46.8694747 Information Attempted to load the document without data.

24/12/2015 00:56:46.8694747 Information The document was loaded successfully.

24/12/2015 00:56:46.8694747 Information Document was opened successfully

24/12/2015 00:56:46.8694747 Information Starting reload

24/12/2015 00:56:46.8850967 Information QlikView->Settings->Document Peferences->Generate Logfile in document is set. Enabling Log Copier.

24/12/2015 00:56:46.8850967 Information The Source Document is being reloaded. DocumentPath=D:\QLIKVIEW\CORINFO APPLICATION\2_Modeles\Transformation_donnees.qvw

24/12/2015 00:56:46.8850967 Information Waiting for the document log "D:\QLIKVIEW\CORINFO APPLICATION\2_Modeles\Transformation_donnees.qvw" to become available.. Check until 24/12/2015 00:57:16

24/12/2015 00:56:46.9632194 Information Found a document log. FileName=D:\QLIKVIEW\CORINFO APPLICATION\2_Modeles\Transformation_donnees.qvw.log

24/12/2015 00:56:46.9632194 Information Writing documentLog to C:\ProgramData\QlikTech\DistributionService\1\Log\20151224\005645 - CORINFO RELOAD_2_Modeles_Transformation_donnees.qvw\DocumentLog.txt

24/12/2015 00:56:47.8694826 Information Reloading.

24/12/2015 00:56:48.8850852 Information Reloading..

24/12/2015 00:56:49.8850841 Information Reloading...

24/12/2015 00:56:50.8850787 Information Reloading....

24/12/2015 00:56:51.8850752 Information Reloading.....

24/12/2015 00:56:52.8850697 Information Reloading......

24/12/2015 00:56:53.8850634 Information Reloading.......

24/12/2015 00:56:54.8850595 Information Reloading........

24/12/2015 00:56:55.8852162 Information Reloading.........

24/12/2015 00:56:56.9006756 Information Reloading..........

24/12/2015 00:56:57.9006858 Information Slow down logging. Log every <2> seconds.

24/12/2015 00:56:57.9006858 Information Reloading

24/12/2015 00:56:59.9168528 Information Reloading.

24/12/2015 00:57:01.9319237 Information Reloading..

24/12/2015 00:57:03.9475346 Information Reloading...

24/12/2015 00:57:05.9475301 Information Reloading....

24/12/2015 00:57:07.9475268 Information Reloading.....

24/12/2015 00:57:09.9631345 Information Reloading......

24/12/2015 00:57:11.9787429 Information Reloading.......

24/12/2015 00:57:13.9789071 Information Reloading........

24/12/2015 00:57:16.0099638 Information Reloading.........

24/12/2015 00:57:18.0099745 Information Reloading..........

24/12/2015 00:57:20.0099655 Information Slow down logging. Log every <10> seconds.

24/12/2015 00:57:20.0099655 Information Reloading

24/12/2015 00:57:30.0567858 Information Reloading.

24/12/2015 00:57:40.1348684 Information Reloading..

24/12/2015 00:57:50.1973454 Information Reloading...

24/12/2015 00:58:00.2597880 Information Reloading....

24/12/2015 00:58:10.3378648 Information Reloading.....

24/12/2015 00:58:20.4159457 Information Reloading......

24/12/2015 00:58:30.4783884 Information Reloading.......

24/12/2015 00:58:40.5564694 Information Reloading........

24/12/2015 00:58:50.6345703 Information Reloading.........

24/12/2015 00:59:00.7282562 Information Reloading..........

24/12/2015 00:59:10.7907289 Information Slow down logging. Log every <60> seconds.

24/12/2015 00:59:10.7907289 Information Reloading

24/12/2015 01:00:11.2435719 Information Reloading.

24/12/2015 01:01:11.6653439 Information Reloading..

24/12/2015 01:02:12.1180410 Information Reloading...

24/12/2015 01:03:12.5552792 Information Reloading....

24/12/2015 01:04:12.9613372 Information Reloading.....

24/12/2015 01:05:13.3672806 Information Reloading......

24/12/2015 01:06:13.8044879 Information Reloading.......

24/12/2015 01:07:14.2729977 Information Reloading........

24/12/2015 01:08:14.7258237 Information Reloading.........

24/12/2015 01:09:15.1161934 Information Reloading..........

24/12/2015 01:10:15.5065418 Information Slow down logging. Log every <300> seconds.

24/12/2015 01:10:15.5065418 Information Reloading

24/12/2015 01:15:17.6302666 Information Reloading.

24/12/2015 01:20:19.7226453 Information Reloading..

24/12/2015 01:25:22.0963035 Information Reloading...

24/12/2015 01:28:13.9705426 Information The Source Document reload complete. DocumentPath=D:\QLIKVIEW\CORINFO APPLICATION\2_Modeles\Transformation_donnees.qvw

24/12/2015 01:30:32.8449778 Information Reloading....

24/12/2015 01:35:34.6873528 Information Reloading.....

24/12/2015 01:40:40.4828811 Information Reloading......

24/12/2015 01:45:46.0284100 Information Reloading.......

24/12/2015 01:50:47.6677104 Information Reloading........

24/12/2015 01:55:53.5569872 Information Reloading.........

24/12/2015 02:00:58.2900209 Information Reloading..........

24/12/2015 02:06:04.0386814 Information Slow down logging. Log every <600> seconds.

24/12/2015 02:06:04.0386814 Information Reloading

24/12/2015 02:16:11.3485047 Information Reloading.

24/12/2015 02:26:17.2677310 Information Reloading..

24/12/2015 02:36:23.0619332 Information Reloading...

24/12/2015 02:46:29.1061324 Information Reloading....

24/12/2015 02:56:33.0253480 Information Reloading.....

24/12/2015 03:06:39.1008141 Information Reloading......

24/12/2015 03:16:44.2388402 Information Reloading.......

24/12/2015 03:26:50.0798520 Information Reloading........

24/12/2015 03:36:55.2490713 Information Reloading.........

24/12/2015 03:47:02.1838971 Information Reloading..........

24/12/2015 03:57:06.5581990 Information Slow down logging. Log every <900> seconds.

24/12/2015 03:57:06.5581990 Information Reloading

24/12/2015 04:12:14.4306393 Information Reloading.

24/12/2015 04:27:22.8171362 Information Reloading..

24/12/2015 04:42:30.8443821 Information Reloading...

24/12/2015 04:57:38.6372582 Information Reloading....

24/12/2015 05:12:43.8051463 Information Reloading.....

24/12/2015 05:44:21.8124224 Information Reloading.......

24/12/2015 05:59:30.6990448 Information Reloading........

24/12/2015 06:14:38.9294371 Information Reloading.........

24/12/2015 06:29:47.8785564 Information Reloading..........

24/12/2015 06:44:54.0933135 Information Slow down logging. Log every <1200> seconds.

24/12/2015 06:44:54.0933135 Information Reloading

24/12/2015 06:56:57.3266552 Information Closing the document.

24/12/2015 06:56:57.9808303 Information Closed the QlikView Engine successfully. ProcessID=5372

24/12/2015 06:56:58.0745119 Error Exception=System.ObjectDisposedException: Le handle sécurisé a été fermé

à System.Threading.WaitHandle.WaitOneNative(SafeHandle waitableSafeHandle, UInt32 millisecondsTimeout, Boolean hasThreadAffinity, Boolean exitContext)

à System.Threading.WaitHandle.InternalWaitOne(SafeHandle waitableSafeHandle, Int64 millisecondsTimeout, Boolean hasThreadAffinity, Boolean exitContext)

à QVBWrapper.Document.ReadDocumentLogThread(ILogBucket i_LogBucket, DateTime i_ReloadStartTime)

24/12/2015 06:56:58.1526541 Error The task "CORINFO RELOAD/2_Modeles/Transformation_donnees.qvw" failed. Exception:

QDSMain.Exceptions.DistributionFailedException: Distribute failed with errors to follow. ---> QDSMain.Exceptions.ReloadFailedException: Reload failed ---> System.Threading.ThreadAbortException: Le thread a été abandonné.

à System.Threading.WaitHandle.WaitOneNative(SafeHandle waitableSafeHandle, UInt32 millisecondsTimeout, Boolean hasThreadAffinity, Boolean exitContext)

à System.Threading.WaitHandle.InternalWaitOne(SafeHandle waitableSafeHandle, Int64 millisecondsTimeout, Boolean hasThreadAffinity, Boolean exitContext)

à SolutionGlobal.ThreadPool.ThreadPoolJob.SafeWaitEvent(WaitHandle eventWaitHandle)

à QDSMain.ReloadTask.Reload(String fileName, TaskResult taskResult, String sectionAccessUserName, String sectionAccessPassword, eReloadOptions reloadOption, String variableName, String variableValue, Boolean moniterCpuUsage)

--- Fin de la trace de la pile d'exception interne ---

à QDSMain.ReloadTask.Reload(String fileName, TaskResult taskResult, String sectionAccessUserName, String sectionAccessPassword, eReloadOptions reloadOption, String variableName, String variableValue, Boolean moniterCpuUsage)

à QDSMain.DistributeTask.Execute(TaskResult currentTaskResult)

--- Fin de la trace de la pile d'exception interne ---

à QDSMain.DistributeTask.Execute(TaskResult currentTaskResult)

à QDSMain.Task.AbstractTask.TaskExecution(ILogBucket logBucket, TaskResult taskResult)

24/12/2015 06:56:58.1995527 Error Task failed with exception

24/12/2015 06:56:58.1995527 Error Exception=The currently executing operation was aborted.

24/12/2015 06:56:58.2463891 Information Sending Alert mail

24/12/2015 06:56:58.5120308 Information TaskResult.status=Finished

24/12/2015 06:56:58.5589721 Information Notifying all triggers of new state:FinishedWithErrors

24/12/2015 06:56:58.5589721 Information Notifying all triggers of new state:FinishedWithErrors - completed

24/12/2015 06:56:58.5745316 Information Saving Task Result

We think about about a memory problem. The server has 16Go.

Can someone tell me why this error comes ?

I wish to thank you in advance for helping us,

Best regards,

guillaume

swuehl · ‎2015-12-24

Your reload ran into the timeout set on the server (6 hours, as far as I see).

If you posted the complete document log, it seems it hasn't done much in that time. Are you trying to connect to a DBMS? Could this lead to a hung system?

If you are assuming a memory issue (I don't see any evidence for that in the log files), you could try to monitor the memory consumption (e.g. enable PerfMon)

Peter_Cammaert · ‎2015-12-24

If it runs successfully in an on/off-fashion, check the average reload duration in QMC->Status->Tasks->Expand Task Details->Task History. How long does it take to reload with success this particular document?

Report Inappropriate Content · ‎2015-12-24

Thanks for your answer,

Indeed, It seems to be a connection problem to database. We don't know why it keeps reloading. Normally, the script runs for around 40 minutes. We checked and connection seems to be good.

We had set a Windows task to restart the QV server before lanching the QV task. We will see whats happening next time.