Checkpoints

[former_SQLA_member1694891]

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.

[Breck_Carter]

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.

[VolkerBarth]

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

[Breck_Carter]

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.

[VolkerBarth]

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.

[VolkerBarth]

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

[Breck_Carter]

...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.

[former_SQLA_member1694891]

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.

[VolkerBarth]

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');

[former_SQLA_member1694891]

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

[former_SQLA_member1694891]

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.

[Breck_Carter]

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.

[former_SQLA_member1694891]

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 :).

[Breck_Carter]

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;

[Breck_Carter]

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 🙂

[Breck_Carter]

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.