cancel
Showing results for 
Search instead for 
Did you mean: 

Incorrect LastReqTime

cigaras
Participant
768

While using SQL Anywhere 17.0.10.6175 and 17.0.11.6800 I encounter an error on a production server that connection property LastReqTime is earlier by 5 to 15 minutes. In some cases LastReqTime is even earlier than LoginTime.

select * from sa_performance_diagnostics() where LastReqTime < LoginTime

How can this be? I can not reproduce it on any of my dev environments, and have no idea where to start to search for a fix.

Update 1:

select @@version, current time, connection_property('LastReqTime')

alt text

jack_schueler
Product and Topic Expert
Product and Topic Expert
0 Kudos

I assume that RequestTiming is ON. Do you have some sample rows you could share? Perhaps a stare at them might help. Other thoughts... Are some clients coming from time zones different than the server? Did this happen over a switch from standard time to daylight saving time?

Breck_Carter
Participant
0 Kudos

> RequestTiming is ON

FWIW LastReqTime has been in SQL Anywhere since forever (V5 at least) and does not depend on RequestTiming like these new things (v10) do...

ReqTimeActive ReqTimeBlockContention ReqTimeBlockIO ReqTimeBlockLock ReqTimeUnscheduled

Breck_Carter
Participant
0 Kudos

My guess is the underlying statistic CONNECTION_PROPERTY ( 'LastReqTime" ) is not affected by this symptom, but sa_performance_diagnostics() is built upon a hidden intern(al) procedure that may have a bug.

cigaras
Participant
0 Kudos

If I execute select connection_property('LastReqTime') multiple times in rapid succession, I should get time close to current time, yet I get time 8 min. early on 17.0.11.6800 and 15 min. early on 17.0.10.6175, see attached picture in the question.

jack_schueler
Product and Topic Expert
Product and Topic Expert
0 Kudos

For how long has the server been up and running. The current time value should be the actual OS local time of day. The LastReqTime is based on an internal server clock. Is the current time value correct and the LastReqTime off? Perhaps you are seeing drift in the database server's internal clock? What operating system are you running the server on?

cigaras
Participant
0 Kudos

Yes, current time value is correct, LastReqTime is off. Server OS is Windows Server 2008 R2 and OS clock is showing the correct time.

DB that is off by 15 min is up since 2021-11-23, the one that is off by 8 min is up since 2022-01-19 (select property('StartTime')). Computers, running those DBs, have respective uptimes of 120 and 60 days (according to task manager).

VolkerBarth
Contributor
0 Kudos

Is the db server running in a virtualized environment?

FWIW, a similar issue has already been discussed with v12, see this (unanswered) question.

I could imagine that this problem might arise on our servers once again after DST has been applied and before they have been rebooted then...

regdomaratzki
Product and Topic Expert
Product and Topic Expert
0 Kudos

see attached picture in the question

It may just be me, but I just see a broken link in the question, not a picture.

regdomaratzki
Product and Topic Expert
Product and Topic Expert
0 Kudos

So it sounds like the database engine has been running for the same amount of time that the computer has been up and running.

I wonder if the issue is related to the time on the computer changing while the database engine is running? Are you able to run a test where you stop and start the database engine (no need to reboot the computer) to see if the problem resolves?

Thanks, Reg

cigaras
Participant
0 Kudos

Restarting the DB service did resolve the issue, however it would be great if it would not repeat itself 🙂

cigaras
Participant
0 Kudos

Yes, DB server is running in a virtualized environment.

Shouldn't DST change push clock by an hour, not by some arbitrary amount?

Restarting the DB service did resolve the issue, however it would be great if it would not repeat itself 🙂

VolkerBarth
Contributor
0 Kudos

I surely agree that the time sources for the current server time and for "request time" should stay consistent over time (pun intended), and of course even across a DST change. (Though for expected ever-increasing and non-unique values like a DEFAULT TIMESTAMP, a DST change to the previous hour is of course difficult to achieve...)

But according to that older question, the impression remains that both kind of times do have different time sources that can fall apart.

And now I hope SQL Anywhere engineers will clarify this issue. 🙂

chris_keating
Product and Topic Expert
Product and Topic Expert
0 Kudos

I recall Docker VMs having an issue where the clock would drift that would affect applications like SQLA that queried the system time. What virtualization environment are you running?

VolkerBarth
Contributor
0 Kudos

But even if the system time within a VM would loose precision over time compared to the host's system clock, that does not explain why SQL Anywhere would display different values for the current time and a "LastReqTime" of a currently started request, as in the OP's sample...

cigaras
Participant
0 Kudos

Environment is managed by our client, so I am not sure, but I doubt Docker is involved. According to msinfo32 system manufacturer is VMware, Inc, and after some Google I found a lot of info on VMware time drifting, including a huge document by VMware themselves https://www.vmware.com/content/dam/digitalmarketing/vmware/en/pdf/techpaper/Timekeeping-In-VirtualMa... Still, as already said by Volker Barth, SA should not count time differently.

cigaras
Participant
0 Kudos

Any advice on best way to contact SA engineers?

Breck_Carter
Participant
0 Kudos

JBSchueler said this in an earlier comment... "The current time value should be the actual OS local time of day. The LastReqTime is based on an internal server clock."

VolkerBarth
Contributor
0 Kudos

Well, they do already read and discuss here, namely Jack Schueler, Chris Keating and Reg Domaratzki... 🙂

chris_keating
Product and Topic Expert
Product and Topic Expert
0 Kudos

I have run a test that invokes the sa_performance_diagnostics() query cited at the start of the thread 500K times and cannot reproduce the behavior. And I often recommend using that procedure in an event to collect info to troubleshoot performance issues. To date, I have never seen a case where the values have drifted as shown here. You perhaps can open a support case and/or provide to this thread info about the virtualized environment (i.e., Hyper-V, VMWare), the virtualized OS and host (what OS is hosting the VM),has the VM ever been suspended and then reactivated - providing as much detail may help to recreate an environment that encounters the behavior.

Accepted Solutions (0)

Answers (0)