Hi guys, I am trying to get a quicker alert to myself when a connection is being blocked. To figure out how long it has been blocked for I was using the connection property WaitStartTime. However I have a minor issue, it seems like the time is in the future.

I put a lock on a table then ran my query.

The WaitStartTime gave the following timestamp: 2012-03-28 10:39:57.675
The current timestamp gave the following timestamp: 2012-03-28 10:32:58.714

Do note that the connection property LastReqTime matched the WaitStartTime and the connection property TransactionStartTime was an empty string.

Can someone please tell me why my WaitStartTime is in the future? FWIW I am running on a ASA12 engine. Thanks!

asked 28 Mar '12, 12:18

numone's gravatar image

numone
31115
accept rate: 0%

edited 28 Mar '12, 12:21

1

IMO BlockedOn would be the property of choice to test... the description of WaitStartTime does not mention blocking, and there are other reasons for a connection to wait (like no available thread).

FWIW Foxhound can send you an Alert when a connection is blocked, and the next release will allow you to AutoDrop either blocker or blockee.

(28 Mar '12, 15:00) Breck Carter
Replies hidden

BlockedOn gives me the connection of what is blocking it (and is working good), but I only need to be concerned if the connection has been blocked for more then a minute or so, which is why I need to know how long it has been blocked for.

I will look into Foxhound, thanks for the tip.

(28 Mar '12, 16:16) numone

"how long it has been blocked"... that would be LastReqTime, since by definition the victim became blocked at the point the last request was made, at least from the client-request point of view. That's the property Foxhound uses to calculate the blocked connection Waiting Time value.

(29 Mar '12, 08:38) Breck Carter

The LastReqTime always matches (at least on all of my tests) the WaitStartTime, which is, again, in the future. And the most annoying part is it is always a different amount of time in the future, sometimes over 350 seconds, sometimes under 60 seconds. I'm wondering what clock it is going based on, and why it's using a different clock then current timestamp to record the time.

(29 Mar '12, 08:55) numone

Sounds like a bug... what build of V12 are you using? Can you try a more recent EBF?

(29 Mar '12, 09:05) Breck Carter

Looks like I am using 12.0.1.3298 - I will grab the newest EBF and see when I can install it. Thanks.

(29 Mar '12, 09:19) numone

In my current tests, the time values for "current timestamp" and the "LastReqTime" seem very different: Current timestamp fits the client's and server's time (both are synchronized regularly), whereas the "LastReqTime" is about 50 minutes behind... (15:34 vs. 14:43). This may be due to the lately switch to CEST here - the server has not booted since then.

So I would suggest that you compare the "LastReqTime" of the blocked and the current (diagnosing) connection to calculate the timespan.

I'm using 12.0.1.3324...

FWIW, the 12.0.1.3554 readme doesn't list any such fix.

(29 Mar '12, 09:36) Volker Barth
Replies hidden

He is reporting that LastReqTime > CURRENT TIMESTAMP which is "impossible"

(29 Mar '12, 09:43) Breck Carter

Yep, I'm aware of that. However, I'm reporting that on my servers (another one on 12.0.1.3298 shows the same behaviour but with a different time lag), LastReqTime << CURRENT TIMESTAMP even for freshly done queries, so I would suspect that these timings have different time sources - and if that is true (and not a bug), then why shouldn't be LastReqTime be "in front"...?


In other words: In case they do have different time sources (which I cannot know, for obvious reasons), then it would seem reasonable to compare just values from the same source, therefore my suggestion to compare LastRegTime from different connections (where one is known to be "current") with each other...

(29 Mar '12, 09:47) Volker Barth

Ok testing this on my local test bed, I found that restarting the database engine seems to pull the two timestamps back in sync. I guess my next question is, is there a way I can run a command that will re-sync them or is restarting the database engine really the only way?

(29 Mar '12, 10:25) numone

CURRENT TIMESTAMP and LastReqTime both come from the server.

(29 Mar '12, 10:29) Breck Carter

The LastReqTime value doesn't change for either connection (the one blocking or the one being blocked) so the only thing that would give me is the amount of time the blocking query has ran before the query being blocked started, which isn't what I need. I need how long the query being blocked has been blocked for.

(29 Mar '12, 10:29) numone

It might be possible that the system clock is very unstable, and CURRENT TIMESTAMP may have drifted into the future at the point LastReqTime was recorded, then it was pulled back into reality by the regular time synchronization process.

I have seen such instability before, and investigated it with a scheduled EVENT that inserted rows with DEFAULT AUTOINCREMENT and DEFAULT CURRENT TIMESTAMP columns into a table every second or so, then did queries to look for (and find!) regular trips into the future and back.

(29 Mar '12, 10:35) Breck Carter

Yes, I remember - one of the OLAP quiz questions I recently re-read...

Still, I do think that

  1. these timers seem able to divergent over time, and
  2. that would make me use "LastReqTime" of the diagnosing connection as the compare value against that of the blocked connection - in my tests, both are bound to the same time source.

And now SQL Anywhere Engineering might give insights into REAL CODE:)

(29 Mar '12, 10:47) Volker Barth

Compare these values with the connection that is about to report the problem. That connection will by design run "currently" - even if its "LastReqTime" is inaccurate as well. So the time difference ought to be the real blocking time.

(29 Mar '12, 10:49) Volker Barth

"LastReqTime" of the diagnosing connection

That's a Catch 22 isn't it? :)... "diagnosing connection" implies running a request on that connection, which would... change the LastReqTime... :)

(29 Mar '12, 10:57) Breck Carter

No, I had expected that there is some diagnosing connection (possibly an scheduled event) that has the task to detect and alert when any other connection is blocked - how would you otherwise take notice of that blocking?

And that "diagnosing" connection surely has a current "LastReqTime" - if it would not run "currently" (ro be blocked) - how would it be able to send an alert?


It would be a Catch 22 if the blocked connection would be asked to self-document - but that's not my level of engineering, I leave that to the SQL Anywhere "Zero Administration experts", and for a reason, apparently:)

(29 Mar '12, 11:31) Volker Barth

And it won't take long until there's a "Comment 22" here, I fear...

(29 Mar '12, 11:34) Volker Barth
showing 2 of 18 show all flat view
Be the first one to answer this question!
toggle preview

Follow this question

By Email:

Once you sign in you will be able to subscribe for any updates here

By RSS:

Answers

Answers and Comments

Markdown Basics

  • *italic* or _italic_
  • **bold** or __bold__
  • link:[text](http://url.com/ "title")
  • image?![alt text](/path/img.jpg "title")
  • numbered list: 1. Foo 2. Bar
  • to add a line break simply add two spaces to where you would like the new line to be.
  • basic HTML tags are also supported

Question tags:

×130
×20

question asked: 28 Mar '12, 12:18

question was seen: 871 times

last updated: 29 Mar '12, 11:34