Mysterious 60 second delay in logfile

bnc1 · Post by **bnc1** » Thu Aug 14, 2008 12:40 am

I have a macro that automates an application continuously 24x7. Recently while observing the application I noticed an unexplained delay. While examining the MS log file I uncovered a mysterious 60 second delay that I can not explain. I then added some VBEval>Timer commands to further diagnose the problem. I have found 4 occurences of the problem. Each time there is a delay of exactly 60 seconds between MS commands. My first thought was something occurring outside of MS, like a virus scan. I can find nothing like that. I examined the Windows event log and found no clues there either, and even if I did find something, what could possibly explain a repeated delay of exactly 60 seconds ?? I am using MS 10.1.7 on a Vista Ultimate x64 system.

Two examples from the logfile :

8/13/2008 04:25:38:222 - START: ReadLn>I:\Bmp\White_save\save_White_7.txt,1,old_line
8/13/2008 04:25:38:222 - END: ReadLn>I:\Bmp\White_save\save_White_7.txt,1,old_line
8/13/2008 04:25:38:222 - START: If>text_dup=old_line
8/13/2008 04:25:38:222 - END: endif
8/13/2008 04:25:38:237 - START: Until>k=1
8/13/2008 04:26:38:734 - END: Repeat>k
8/13/2008 04:26:38:734 - START: Repeat>k
8/13/2008 04:26:38:750 - END: Repeat>k
8/13/2008 04:26:38:750 - START: let>k=k-1
8/13/2008 04:26:38:750 - END: let>k=k-1

8/12/2008 22:48:16:201 - START: let>starttime1=starttime1+10
8/12/2008 22:48:16:201 - END: let>starttime1=starttime1+10
8/12/2008 22:48:16:201 - START: GetTextAtPoint>681,144,strText,nChar
8/12/2008 22:48:16:310 - END: GetTextAtPoint>681,144,strText,nChar
8/12/2008 22:48:16:310 - START: If>nChar>-1
8/12/2008 22:49:16:370 - END: else
8/12/2008 22:49:16:386 - START: let>text_dup=strText
8/12/2008 22:49:16:386 - END: let>text_dup=strText
8/12/2008 22:49:16:386 - START: Endif
8/12/2008 22:49:16:386 - END: Endif

Post by **Marcus Tettmar** » Fri Aug 22, 2008 7:57 pm

Looks like you have two macros running at the same time. The START and END entries don't match up in those instances. Do you have another macro running on a schedule which uses the same log file?

bnc1 · Post by **bnc1** » Fri Aug 22, 2008 8:57 pm

As I stated in the original post, I actually observed the application's mysterious 60 second delay. Without that direct observation, I would have never known there was a problem. In my view , it is not an issue of mismatched log entries.

I do not use scheduling of any kind. All macros are initiated manually.
Here is another example :

8/21/2008 23:05:19:501 - START: IfWindowopen>Watching:*
8/21/2008 23:05:19:501 - END: IfWindowopen>Watching:*
8/21/2008 23:05:19:501 - START: setfocus>Watching:*
8/21/2008 23:05:19:501 - END: setfocus>Watching:*
8/21/2008 23:05:19:501 - START: wait>1
8/21/2008 23:05:20:515 - END: wait>1
8/21/2008 23:06:19:904 - START: getactivewindow>win_title_diag,xpos,ypos
8/21/2008 23:06:19:904 - END: getactivewindow>win_title_diag,xpos,ypos
8/21/2008 23:06:19:904 - START: GetWindowText>Watching: DR3 Esquire-Knilch,wintext
8/21/2008 23:06:19:951 - END: GetWindowText>Watching: DR3 Esquire-Knilch,wintext

bnc1 · Post by **bnc1** » Sun Mar 29, 2009 11:44 am

Beware of solid state disks !

They have their problems .. a good writeup on this at http://www.anandtech.com/storage/showdo ... i=3531&p=1

After updating my Intel Storage Matrix Manager software a while back, I was able to correlate the 60 sec timeouts to my Samsung 64gb SSD drive. A firmware update was just released that might help. The problem is very intermittent however.