Question Re: Checkpoints in Technology Q&A

Checkpoints

former_SQLA_member1694891 — Mon, 17 Sep 2018 04:23:47 GMT

Hi,

We are running SQLAnywhere 17 (Version 17.0.8.4003), and some of our clients are complaining about a lack of performance. We notice a lot of checkpoints in a single minutes on their database.

Here an example of the database server messages :

I. 03/06 11:27:35. Starting checkpoint of "NEUTRIK" (NEUTRIK.db) at Tue Mar 06 2018 11:27
I. 03/06 11:27:35. Finished checkpoint of "NEUTRIK" (NEUTRIK.db) at Tue Mar 06 2018 11:27
I. 03/06 11:27:37. Starting checkpoint of "NEUTRIK" (NEUTRIK.db) at Tue Mar 06 2018 11:27
I. 03/06 11:27:37. Finished checkpoint of "NEUTRIK" (NEUTRIK.db) at Tue Mar 06 2018 11:27
I. 03/06 11:27:38. Starting checkpoint of "NEUTRIK" (NEUTRIK.db) at Tue Mar 06 2018 11:27
I. 03/06 11:27:38. Finished checkpoint of "NEUTRIK" (NEUTRIK.db) at Tue Mar 06 2018 11:27
I. 03/06 11:27:38. Starting checkpoint of "NEUTRIK" (NEUTRIK.db) at Tue Mar 06 2018 11:27
I. 03/06 11:27:38. Finished checkpoint of "NEUTRIK" (NEUTRIK.db) at Tue Mar 06 2018 11:27
I. 03/06 11:27:39. Starting checkpoint of "NEUTRIK" (NEUTRIK.db) at Tue Mar 06 2018 11:27
I. 03/06 11:27:39. Finished checkpoint of "NEUTRIK" (NEUTRIK.db) at Tue Mar 06 2018 11:27
I. 03/06 11:27:42. Starting checkpoint of "NEUTRIK" (NEUTRIK.db) at Tue Mar 06 2018 11:27
I. 03/06 11:27:42. Finished checkpoint of "NEUTRIK" (NEUTRIK.db) at Tue Mar 06 2018 11:27
I. 03/06 11:27:45. Starting checkpoint of "NEUTRIK" (NEUTRIK.db) at Tue Mar 06 2018 11:27
I. 03/06 11:27:45. Finished checkpoint of "NEUTRIK" (NEUTRIK.db) at Tue Mar 06 2018 11:27
I. 03/06 11:27:48. Starting checkpoint of "NEUTRIK" (NEUTRIK.db) at Tue Mar 06 2018 11:27
I. 03/06 11:27:48. Finished checkpoint of "NEUTRIK" (NEUTRIK.db) at Tue Mar 06 2018 11:27
I. 03/06 11:27:51. Starting checkpoint of "NEUTRIK" (NEUTRIK.db) at Tue Mar 06 2018 11:27
I. 03/06 11:27:51. Finished checkpoint of "NEUTRIK" (NEUTRIK.db) at Tue Mar 06 2018 11:27
I. 03/06 11:27:52. Starting checkpoint of "NEUTRIK" (NEUTRIK.db) at Tue Mar 06 2018 11:27
I. 03/06 11:27:52. Finished checkpoint of "NEUTRIK" (NEUTRIK.db) at Tue Mar 06 2018 11:27
I. 03/06 11:27:53. Starting checkpoint of "NEUTRIK" (NEUTRIK.db) at Tue Mar 06 2018 11:27
I. 03/06 11:27:53. Finished checkpoint of "NEUTRIK" (NEUTRIK.db) at Tue Mar 06 2018 11:27
I. 03/06 11:27:54. Starting checkpoint of "NEUTRIK" (NEUTRIK.db) at Tue Mar 06 2018 11:27
I. 03/06 11:27:54. Finished checkpoint of "NEUTRIK" (NEUTRIK.db) at Tue Mar 06 2018 11:27
I. 03/06 11:27:55. Starting checkpoint of "NEUTRIK" (NEUTRIK.db) at Tue Mar 06 2018 11:27
I. 03/06 11:27:55. Finished checkpoint of "NEUTRIK" (NEUTRIK.db) at Tue Mar 06 2018 11:27
I. 03/06 11:27:55. Starting checkpoint of "NEUTRIK" (NEUTRIK.db) at Tue Mar 06 2018 11:27
I. 03/06 11:27:55. Finished checkpoint of "NEUTRIK" (NEUTRIK.db) at Tue Mar 06 2018 11:27
I. 03/06 11:27:57. Starting checkpoint of "NEUTRIK" (NEUTRIK.db) at Tue Mar 06 2018 11:27
I. 03/06 11:27:57. Finished checkpoint of "NEUTRIK" (NEUTRIK.db) at Tue Mar 06 2018 11:27
I. 03/06 11:27:59. Starting checkpoint of "NEUTRIK" (NEUTRIK.db) at Tue Mar 06 2018 11:27
I. 03/06 11:27:59. Finished checkpoint of "NEUTRIK" (NEUTRIK.db) at Tue Mar 06 2018 11:27
I. 03/06 11:28:00. Starting checkpoint of "NEUTRIK" (NEUTRIK.db) at Tue Mar 06 2018 11:28
I. 03/06 11:28:00. Finished checkpoint of "NEUTRIK" (NEUTRIK.db) at Tue Mar 06 2018 11:28
I. 03/06 11:28:02. Starting checkpoint of "NEUTRIK" (NEUTRIK.db) at Tue Mar 06 2018 11:28
I. 03/06 11:28:02. Finished checkpoint of "NEUTRIK" (NEUTRIK.db) at Tue Mar 06 2018 11:28
I. 03/06 11:28:03. Starting checkpoint of "NEUTRIK" (NEUTRIK.db) at Tue Mar 06 2018 11:28
I. 03/06 11:28:03. Finished checkpoint of "NEUTRIK" (NEUTRIK.db) at Tue Mar 06 2018 11:28
I. 03/06 11:28:12. Starting checkpoint of "NEUTRIK" (NEUTRIK.db) at Tue Mar 06 2018 11:28
I. 03/06 11:28:12. Finished checkpoint of "NEUTRIK" (NEUTRIK.db) at Tue Mar 06 2018 11:28
I. 03/06 11:28:12. Starting checkpoint of "NEUTRIK" (NEUTRIK.db) at Tue Mar 06 2018 11:28
I. 03/06 11:28:12. Finished checkpoint of "NEUTRIK" (NEUTRIK.db) at Tue Mar 06 2018 11:28
I. 03/06 11:28:14. Starting checkpoint of "NEUTRIK" (NEUTRIK.db) at Tue Mar 06 2018 11:28
I. 03/06 11:28:14. Finished checkpoint of "NEUTRIK" (NEUTRIK.db) at Tue Mar 06 2018 11:28
I. 03/06 11:28:16. Starting checkpoint of "NEUTRIK" (NEUTRIK.db) at Tue Mar 06 2018 11:28
I. 03/06 11:28:16. Finished checkpoint of "NEUTRIK" (NEUTRIK.db) at Tue Mar 06 2018 11:28
I. 03/06 11:28:17. Starting checkpoint of "NEUTRIK" (NEUTRIK.db) at Tue Mar 06 2018 11:28
I. 03/06 11:28:17. Finished checkpoint of "NEUTRIK" (NEUTRIK.db) at Tue Mar 06 2018 11:28
I. 03/06 11:28:17. Starting checkpoint of "NEUTRIK" (NEUTRIK.db) at Tue Mar 06 2018 11:28
I. 03/06 11:28:17. Finished checkpoint of "NEUTRIK" (NEUTRIK.db) at Tue Mar 06 2018 11:28
I. 03/06 11:28:17. Starting checkpoint of "NEUTRIK" (NEUTRIK.db) at Tue Mar 06 2018 11:28
I. 03/06 11:28:17. Finished checkpoint of "NEUTRIK" (NEUTRIK.db) at Tue Mar 06 2018 11:28
I. 03/06 11:28:18. Starting checkpoint of "NEUTRIK" (NEUTRIK.db) at Tue Mar 06 2018 11:28
I. 03/06 11:28:18. Finished checkpoint of "NEUTRIK" (NEUTRIK.db) at Tue Mar 06 2018 11:28
I. 03/06 11:28:21. Starting checkpoint of "NEUTRIK" (NEUTRIK.db) at Tue Mar 06 2018 11:28
I. 03/06 11:28:21. Finished checkpoint of "NEUTRIK" (NEUTRIK.db) at Tue Mar 06 2018 11:28
I. 03/06 11:28:24. Starting checkpoint of "NEUTRIK" (NEUTRIK.db) at Tue Mar 06 2018 11:28
I. 03/06 11:28:24. Finished checkpoint of "NEUTRIK" (NEUTRIK.db) at Tue Mar 06 2018 11:28
I. 03/06 11:28:27. Starting checkpoint of "NEUTRIK" (NEUTRIK.db) at Tue Mar 06 2018 11:28
I. 03/06 11:28:27. Finished checkpoint of "NEUTRIK" (NEUTRIK.db) at Tue Mar 06 2018 11:28
I. 03/06 11:28:28. Starting checkpoint of "NEUTRIK" (NEUTRIK.db) at Tue Mar 06 2018 11:28
I. 03/06 11:28:28. Finished checkpoint of "NEUTRIK" (NEUTRIK.db) at Tue Mar 06 2018 11:28
I. 03/06 11:28:49. Starting checkpoint of "NEUTRIK" (NEUTRIK.db) at Tue Mar 06 2018 11:28
I. 03/06 11:28:49. Finished checkpoint of "NEUTRIK" (NEUTRIK.db) at Tue Mar 06 2018 11:28
I. 03/06 11:28:49. Starting checkpoint of "NEUTRIK" (NEUTRIK.db) at Tue Mar 06 2018 11:28
I. 03/06 11:28:49. Finished checkpoint of "NEUTRIK" (NEUTRIK.db) at Tue Mar 06 2018 11:28
I. 03/06 11:28:49. Starting checkpoint of "NEUTRIK" (NEUTRIK.db) at Tue Mar 06 2018 11:28
I. 03/06 11:28:49. Finished checkpoint of "NEUTRIK" (NEUTRIK.db) at Tue Mar 06 2018 11:28
I. 03/06 11:28:49. Starting checkpoint of "NEUTRIK" (NEUTRIK.db) at Tue Mar 06 2018 11:28
I. 03/06 11:28:49. Finished checkpoint of "NEUTRIK" (NEUTRIK.db) at Tue Mar 06 2018 11:28
I. 03/06 11:28:50. Starting checkpoint of "NEUTRIK" (NEUTRIK.db) at Tue Mar 06 2018 11:28
I. 03/06 11:28:51. Finished checkpoint of "NEUTRIK" (NEUTRIK.db) at Tue Mar 06 2018 11:28
I. 03/06 11:28:52. Starting checkpoint of "NEUTRIK" (NEUTRIK.db) at Tue Mar 06 2018 11:28
I. 03/06 11:28:52. Finished checkpoint of "NEUTRIK" (NEUTRIK.db) at Tue Mar 06 2018 11:28
I. 03/06 11:28:54. Starting checkpoint of "NEUTRIK" (NEUTRIK.db) at Tue Mar 06 2018 11:28
I. 03/06 11:28:54. Finished checkpoint of "NEUTRIK" (NEUTRIK.db) at Tue Mar 06 2018 11:28
I. 03/06 11:28:55. Starting checkpoint of "NEUTRIK" (NEUTRIK.db) at Tue Mar 06 2018 11:28
I. 03/06 11:28:55. Finished checkpoint of "NEUTRIK" (NEUTRIK.db) at Tue Mar 06 2018 11:28
I. 03/06 11:28:58. Starting checkpoint of "NEUTRIK" (NEUTRIK.db) at Tue Mar 06 2018 11:28
I. 03/06 11:28:58. Finished checkpoint of "NEUTRIK" (NEUTRIK.db) at Tue Mar 06 2018 11:28
I. 03/06 11:29:00. Starting checkpoint of "NEUTRIK" (NEUTRIK.db) at Tue Mar 06 2018 11:29
I. 03/06 11:29:00. Finished checkpoint of "NEUTRIK" (NEUTRIK.db) at Tue Mar 06 2018 11:29

Does this can explain the lack of performance ? If it is not the reason of the lack of performance why the server is doing all this Checkpoints ? on the database we are just doing select, updates, and some times a delete.

Re: Checkpoints

VolkerBarth — Mon, 17 Sep 2018 04:34:11 GMT

Do you use a transaction log? Otherwise, each COMMIT will force a checkpoint, leading to probably horrible performcance, c.f. that topic...

Or have you changed the default settings for checkpoint/recovery time? I.e. what does the following reveal:

select connection_property('checkpoint_time'), connection_property('recovery_time');

Re: Checkpoints

former_SQLA_member1694891 — Mon, 17 Sep 2018 09:05:08 GMT

Thanks for your quick reply :).

Yes we are using a transaction log.

We haven't change the setting of the properties checkpoint_time(value 60) and recovery_time (value 2).

Me migrate this client from SQLAnywhere12 to SQLAnywhere17 a short time ago. During this migration we unload the "sqla12 database" and reload it in a "sqla17 database" instead of upgrating it.

We are also truncating the log at each database backup, we were doing that with the SQLA12 to.

And we the option autocomit is on

Re: Checkpoints

Breck_Carter — Mon, 17 Sep 2018 15:24:51 GMT

The checkpoints may not be related to performance problems at all.

All the checkpoints are starting and ending within the same second, which probably means they are all taking much less than one second each (otherwise, at least one Starting Ending pair would span a second boundary, one thinks 🙂

This leads one to think that these checkpoints may be side-effects of some operation(s) that have a checkpoint as a side-effect, like ALTER TABLE, some DROP TABLE statements, some CREATE INDEX statements, ~~some~~ LOAD TABLE statements... and BACKUP, but it's unlikely you're running BACKUP that often :)

Update: LOAD TABLE is the most likely culprit... at least it is in my code 🙂

Another possibility is that explicit CHECKPOINT statements appear in your application code or stored procedures somewhere... CHECKPOINT has sometimes been confused with COMMIT.

Another possibility is your database is very busy... but that's hard to reconcile with 4 checkpoints in one second (11:28:49).

Also, consider Foxhound.

Re: Checkpoints

VolkerBarth — Tue, 18 Sep 2018 03:32:29 GMT

Glenn's answer from that older question has a quite exhaustive list of the statements that have an implicit checkpoint as side effect.

Re: Checkpoints

Breck_Carter — Tue, 18 Sep 2018 11:07:04 GMT

Thanks for finding that list... I dunno where I got "some LOAD TABLE statements", probably misread some other Help topic.

CHECKPOINT storms are quite common because repeated LOAD TABLE statements are quite common... so common I've come to ignore them... which explains why I didn't think of the likely answer... or old age 🙂

...now if you'll excuse me, I have to go and copy Glenn's list into the Foxhound Help.

Re: Checkpoints

VolkerBarth — Tue, 18 Sep 2018 11:31:00 GMT

Rather easy to find: It's the answer to Glenn's single question:) - although it was actually mine:)

~~For LOAD TABLE, the WITH CHECKPOINT clause might do the trick...~~

Sigh, I'm wrong, the docs state:

A checkpoint is carried out at the beginning of the operation. A second checkpoint is performed at the end if WITH CHECKPOINT ON is specified.

Re: Checkpoints

VolkerBarth — Tue, 18 Sep 2018 11:34:56 GMT

Here's the current list from the v17 docs, I guess it was built from Glenn's summary.

Re: Checkpoints

Breck_Carter — Tue, 18 Sep 2018 11:48:04 GMT

...and for the record, here's the future Foxhound Help topic for the "Checkpoints" column...

Checkpoints is the number of checkpoint operations that have been executed in the previous interval.

Performance Tip: Checkpoint operations can be expensive. More than one checkpoint every once in a while may indicate that undesirable behavior is causing a performance bottleneck.

Generally speaking, explicit CHECKPOINT statements are not required in application programs because the server does a good job of scheduling checkpoints to minimize their impact on performance. An explicit CHECKPOINT should never be used without careful consideration, especially in a busy multi-user environment. Checkpoints are different from commits; a commit ensures that the transaction log file is up to date whereas a checkpoint ensures that the database file is up to date. As long as commits are performed frequently, performance can be greatly improved by delaying checkpoint operations... which is what SQL Anywhere does by default.

Performance Tip: Think twice before running a database without a transaction log. Even if you don't need the log for recovery purposes, SQL Anywhere will perform a checkpoint after every commit if there's no transaction log... and that can be very bad for performance.

Performance Tip: If you see an "storm" of checkpoint operations, they may be caused by certain SQL statements (such as LOAD TABLE) that have "checkpoint" as a side-effect; here's the full list:

ALTER INDEX REBUILD
ALTER TABLE unless it adds a nullable column or a referential integrity constraint and does not need modify the table pages in any way
BACKUP
CHECKPOINT
COMMIT when the database doesn't have a transaction log file
CREATE DBSPACE
CREATE INDEX that specifies a computed column
DROP DBSPACE
DROP MATERIALIZED VIEW if the view contains one or more rows
DROP TABLE if the table contains one or more rows
REFRESH MATERIALIZED VIEW
REORGANIZE TABLE
LOAD TABLE

Checkpoints is based on the server-level Chkpt property for target databases running on SQL Anywhere versions 5 and 6, and on the database-level Chkpt property for versions 7 and later.

Re: Checkpoints

former_SQLA_member1694891 — Tue, 18 Sep 2018 12:15:26 GMT

Thank for your reply.

But in a normal use of our application we don't do all of this stuff (load table, ALTER TABLE, etc).

We only do (a lot) Select, update, some insert and a few delete.

Re: Checkpoints

former_SQLA_member1694891 — Tue, 18 Sep 2018 12:15:36 GMT

Thank for your reply.

But in a normal use of our application we don't do all of this stuff (load table, ALTER TABLE, etc).

We only do (a lot) Select, update, some insert and a few delete.

Re: Checkpoints

Breck_Carter — Tue, 18 Sep 2018 15:55:32 GMT

Do you have any stored procedures or scheduled events inside your database?

Regardless of the answer, it is unlikely the checkpoints are the originating cause of any performance problems since they are not taking very long.

Re: Checkpoints

former_SQLA_member1694891 — Wed, 19 Sep 2018 04:25:14 GMT

Yes we have some stored procedures and functions and scheduled events in our database.

I don't think either that the checkpoints are the cause of performance problems, but I want to know why we have some checkpoints storms with no reason :).

Re: Checkpoints

Breck_Carter — Wed, 19 Sep 2018 08:37:47 GMT

Oh, there will be a reason 🙂

Try running this query to look for possible "LOAD ..." statements (yes, I know there won't be any inside the views, but this came from a general-purpose template 🙂

BEGIN
SELECT * FROM SYSTABLE     WHERE view_def     LIKE '%LOAD %';
SELECT * FROM SYSPROCEDURE WHERE proc_defn    LIKE '%LOAD %';
SELECT * FROM SYSTRIGGER   WHERE trigger_defn LIKE '%LOAD %';
SELECT * FROM SYSEVENT     WHERE source       LIKE '%LOAD %';
END;

Re: Checkpoints

Breck_Carter — Wed, 19 Sep 2018 08:43:23 GMT

Request level logging can be used to determine what kind of SQL statements are actually coming from the client side.

--------------------------------------------------------------------- 
-- To log incoming SQL requests.

-- On
CALL sa_server_option ( 'Request_level_log_file', 'c:/temp/rlog.txt' );
CALL sa_server_option ( 'Request_level_logging', 'SQL+hostvars' );

-- Off
CALL sa_server_option ( 'Request_level_logging', 'NONE' );

Note: Yes, this old-style syntax works fine in SQL Anywhere 17.

Note: Notepad can be used to view the output file while it is still being written to... Notepad is magic 🙂

Re: Checkpoints

Breck_Carter — Wed, 19 Sep 2018 08:56:06 GMT

FWIW all this effort might not help at all with the performance problems. Try one of the products listed in Table 1 on this page.