cancel
Showing results for 
Search instead for 
Did you mean: 

What would cause long delay after final checkpoint?

Breck_Carter
Participant
1,118

17.0.9.4882

What would cause a 10 minute delay between the last "Finished checkpoint" message and the subsequent "Database server stopped"?

I. 12/05 13:49:32. Finished checkpoint of "f" (foxhound5.db) at Sat Dec 05 2020 13:49
I. 12/05 13:59:13. Database server stopped at Sat Dec 05 2020 13:59

As far as I can tell, dbsrv17.exe was pounding the *.db file for the whole time... is it possible the last "Finished checkpoint" message is sent long before the disk I/O is complete?

Here's more of the log...

I. 11/26 11:14:26. SQL Anywhere Network Server Version 17.0.9.4882
...
I. 11/26 11:14:26. Running Windows 10 Build 18362  on X86_64
I. 11/26 11:14:26. Server built for X86_64 processor architecture
I. 11/26 11:14:26. 4192032K of memory used for caching
I. 11/26 11:14:26. Minimum cache size: 4187960K, maximum cache size: 8363632K
I. 11/26 11:14:26. Using a maximum page size of 8192 bytes
I. 11/26 11:14:26. Multiprogramming level: minimum:8, current:220, maximum:880
I. 11/26 11:14:26. Automatic tuning of multiprogramming level is disabled
I. 11/26 11:14:26. Starting database "f" (C:\\ProgramData\\RisingRoad\\Foxhound5\\foxhound5.db) 
   at Thu Nov 26 2020 11:14
I. 11/26 11:14:27. Performance warning: Database file 
   "C:\\ProgramData\\RisingRoad\\Foxhound5\\foxhound5.db" consists of 148 disk fragments
I. 11/26 11:14:27. Transaction log: foxhound5.log
I. 11/26 11:14:28. Starting checkpoint of "f" (foxhound5.db) at Thu Nov 26 2020 11:14
I. 11/26 11:14:28. Finished checkpoint of "f" (foxhound5.db) at Thu Nov 26 2020 11:14
I. 11/26 11:14:28. Database "f" (foxhound5.db) started at Thu Nov 26 2020 11:14
I. 11/26 11:14:28. Database server started at Thu Nov 26 2020 11:14
I. 11/26 11:14:28. Trying to start SharedMemory link ...
I. 11/26 11:14:28.     SharedMemory link started successfully
I. 11/26 11:14:28. Trying to start TCPIP link ...
I. 11/26 11:14:28. Starting on port 49152
I. 11/26 11:14:33.     TCPIP link started successfully
I. 11/26 11:14:33. HTTP listener starting on port 80
I. 11/26 11:14:33. Now accepting requests
I. 11/26 11:14:35. ---------------------------------------
I. 11/26 11:14:35. Foxhound Version 5.0 by RisingRoad - Extended Edition 5.0.5500a 
   built at 2020 11 07 14:32 
   in a SQL Anywhere 17.0.9.4882 database created at 2020 11 07 14:32
I. 11/26 11:14:35. ---------------------------------------
I. 11/26 11:14:37. No patches were processed.
I. 11/26 11:14:49. Foxhound folder: C:\\ProgramData\\RisingRoad\\Foxhound5
I. 11/26 11:14:49. Foxhound command line: "C:\\Program Files\\SQL Anywhere 17\\Bin64\\dbsrv17.exe" 
   -c 25p -ch 50p -cr- -gk all -gl all -gn 220 -gna 0 -m -n foxhound5 -o foxhound5_debug.txt 
   -oe foxhound5_debug_startup.txt -on 1M -sb 0 -ufd restart -x tcpip -xd 
   -xs http(port=80;maxsize=0;to=600;kto=600) foxhound5.db -n f "-hn0,60368:512"
I. 11/26 11:14:49. Foxhound server name: foxhound5
I. 11/26 11:14:49. Foxhound database name: f
I. 11/26 11:14:49. Foxhound Windows API support DLL: rroad5_sa17_bin64.dll
I. 11/26 11:14:49. SQL Anywhere startup time: 6.7s
I. 11/26 11:14:49. Foxhound startup time: 16.3s
I. 11/26 11:14:49. Total startup time: 23s
I. 11/26 11:14:49. Foxhound now accepting requests.
I. 11/26 11:41:33. Starting checkpoint of "f" (foxhound5.db) at Thu Nov 26 2020 11:41
I. 11/26 11:41:35. Finished checkpoint of "f" (foxhound5.db) at Thu Nov 26 2020 11:41
...
I. 12/05 13:28:04. Starting checkpoint of "f" (foxhound5.db) at Sat Dec 05 2020 13:28
I. 12/05 13:28:06. Finished checkpoint of "f" (foxhound5.db) at Sat Dec 05 2020 13:28
I. 12/05 13:49:20. Database server shutdown requested by DBSTOP
W. 12/05 13:49:22. TCPIP listener on IP address 0.0.0.0:49152 is exiting
W. 12/05 13:49:22. HTTP listener on IP address (::):80 is exiting
W. 12/05 13:49:22. HTTP listener on IP address 0.0.0.0:80 is exiting
W. 12/05 13:49:22. TCPIP listener on IP address (::):49152 is exiting
E. 12/05 13:49:27. Handler for event 'rroad_monitor_sample_loop' caused SQLSTATE '57014'
E. 12/05 13:49:27. Handler for event 'rroad_monitor_sample_loop' caused SQLSTATE '57014'
E. 12/05 13:49:27. Handler for event 'rroad_monitor_sample_loop' caused SQLSTATE '57014'
E. 12/05 13:49:27. Handler for event 'rroad_monitor_sample_loop' caused SQLSTATE '57014'
E. 12/05 13:49:27. Handler for event 'rroad_monitor_sample_loop' caused SQLSTATE '57014'
E. 12/05 13:49:27. Handler for event 'rroad_monitor_main_loop' caused SQLSTATE '57014'
E. 12/05 13:49:27. Handler for event 'rroad_monitor_sample_loop' caused SQLSTATE '57014'
E. 12/05 13:49:27. Handler for event 'rroad_monitor_sample_loop' caused SQLSTATE '57014'
E. 12/05 13:49:27. Handler for event 'rroad_monitor_sample_loop' caused SQLSTATE '57014'
E. 12/05 13:49:27. Handler for event 'rroad_monitor_sample_loop' caused SQLSTATE '57014'
E. 12/05 13:49:27. Statement interrupted by user
E. 12/05 13:49:27. Statement interrupted by user
E. 12/05 13:49:27. Statement interrupted by user
E. 12/05 13:49:27. Statement interrupted by user
E. 12/05 13:49:27. Statement interrupted by user
E. 12/05 13:49:27. Statement interrupted by user
E. 12/05 13:49:27. Statement interrupted by user
E. 12/05 13:49:28. Statement interrupted by user
E. 12/05 13:49:28. Statement interrupted by user
E. 12/05 13:49:28. Statement interrupted by user
I. 12/05 13:49:30. Starting checkpoint of "f" (foxhound5.db) at Sat Dec 05 2020 13:49
I. 12/05 13:49:32. Finished checkpoint of "f" (foxhound5.db) at Sat Dec 05 2020 13:49
I. 12/05 13:59:13. Database server stopped at Sat Dec 05 2020 13:59

Accepted Solutions (1)

Accepted Solutions (1)

jack_schueler
Product and Topic Expert
Product and Topic Expert

In recent versions of the database server (17.0.9.4937 or later), the -z option causes a lot more shutdown messages to appear in the server log. I realize the horse has already left the barn, but for the future, this may be a useful thing to enable. This enhancement should appear under the title "database server subsystem shutdown logging" in the release notes.

Breck_Carter
Participant

Thank you!

> 17.0.9.4937

That supports my personal motto "Nothing is easy"... I waited a very long time before freezing the requirements for Foxhound 5 at "SQL Anywhere 17.0.9.4882 or better"... so of course I was outlasted by SAP 🙂

Answers (0)