|
Hi! Our sybase 12 database Engine running as a service doesn't close down as we expect. When we order a shutdown of the service, we can see that all connections immediatly are closed, but "Services" gives us error 1053. If we watch dbsrv12.exe in the taskmanager we can se that it loads the cpu with approx 25%, and keeps approx 2600 MB in ram. After about 5 minutes we can see the that the ram consumption starts to fall and the then the Engine really close. Any tips on how to debug/fix this is appreciated. Regards Janne |
|
What does the console log (dbsrv12 -o MyConsole.log) reveal? You may add the -z option to log debugging information to your server's command line. In case that is too expensive, you can also turn on debugging just before you try to shutdown the server, via call sa_server_option('DebuggingInformation', 'YES'); (Don't forget to unset that option afterwards...) Ok, will try this next week since this is a system used 24/7 so I'm not allowed to do ANYTHING on a friday! (good rule by the way). Will this generate a log file or write to the eventlog or what?
(24 Jan '14, 09:34)
Janne
Replies hidden
1
These messages will not appear in the OS eventlog but in the console log file - if you have specified one with dbsrv12 -o. If not, and you cannot re-start the server, you can also add that at runtime via call sa_server_option('ConsoleLogFile', 'C:\\MyConsole.log');
(24 Jan '14, 11:01)
Volker Barth
OK, here is the output on my logfile: I. 01/27 10:04:54. Database server shutdown requested via server console I. 01/27 10:04:54. Disallowing new connections W. 01/27 10:04:54. TCPIP listener on IP address (::):2638 is exiting W. 01/27 10:04:54. TCPIP listener on IP address 0.0.0.0:2638 is exiting E. 01/27 10:04:54. TCP/IP link, function WSARecvFrom, error code 995 E. 01/27 10:04:54. TCP/IP link, function WSARecvFrom, error code 995 E. 01/27 10:04:54. TCP/IP link, function WSARecvFrom, error code 995 I. 01/27 10:04:54. Shutting down databases I. 01/27 10:04:54. Connection ID 117359: Client disconnected I. 01/27 10:04:54. Connection ID 4: Client disconnected I. 01/27 10:04:54. Connection ID 117359: "ABC" disconnected from database "depot_2321" I. 01/27 10:04:54. Connection ID 4: "PLC" disconnected from database "depot_2321" I. 01/27 10:04:54. Connection ID 14526: Client disconnected I. 01/27 10:04:54. Connection ID 14526: "ABC" disconnected from database "depot_2321" I. 01/27 10:04:54. Connection ID 149412: Client disconnected I. 01/27 10:04:54. Connection ID 149412: "ABC" disconnected from database "depot_2321" I. 01/27 10:04:54. Connection ID 1447: "EXTENV_MAIN" disconnected from database "depot_2321" I. 01/27 10:04:54. Connection ID 161032: "ABCD" disconnected from database "depot_2321" I. 01/27 10:04:54. Starting checkpoint of "depot_XXXX" (depot_XXXX.db) at Mon Jan 27 2014 10:04 I. 01/27 10:04:59. Finished checkpoint of "depot_XXXX" (depot_XXXX.db) at Mon Jan 27 2014 10:04 I. 01/27 10:15:23. Completing server shutdown I. 01/27 10:15:31. Database server stopped at Mon Jan 27 2014 10:15
(27 Jan '14, 04:18)
Janne
Replies hidden
Is that a console log containing debugging information (i.e. produced with -z or sa_server_option('DebuggingInformation', 'YES'))? Note, the lines starting with "E. " contain error messages, so there seems to be something unusual with the TCP/IP (I can't tell whether that has any influence on the slow shutdown)...
(27 Jan '14, 05:59)
Volker Barth
Yes it is, The error has something to do with IPV6 as far as I understand, Found this in Another thread: If SA 9.0 works, then perhaps it's an IPv6 issue. Try adding this to your server start command: -x tcpip(IPv6=NO) This is an undocumented TCP option so don't tell anyone about it. :-) Trying that now. Datbase is always fast to shutdown if we do it 0-15 minutes after it's started so I'll have to wait....
(27 Jan '14, 06:50)
Janne
Replies hidden
In case you can leave a DBA connection open after the general shutdown request has been sent (and other connections have been closes) - say, after 10:05 in your above log: Could you then query (say, with sa_conn_info) if there are still (internal) connections active? (If your DBA connection is immediately closed with the others, well, then it's more difficult, apparently: You may then add a "DISCONNECT event" to log on-going actions, say by writing the contents of sa_conn_info or other system state information like db_property('RollbackLogPages') to the console log (via MESSAGE statements) in a loop until that event connection is closed, too...)
(27 Jan '14, 07:28)
Volker Barth
1
FYI: When the TCP listener shuts down, seeing a '995' in the detailed console log is typical - see 'WSA_OPERATION_ABORTED' in the details of WSARecvFrom.
This just means that the outstanding operations on the socket didn't complete before the socket closed. Which is understandable if the socket is being forcefully closed.
(27 Jan '14, 12:08)
Jeff Albion
-x tcpip(IPv6=NO) did not help.... Last 4 lines of the following text: I. 01/28 08:58:44. Starting checkpoint of "depot_2321" (depot_2321.db) at Tue Jan 28 2014 08:58 I. 01/28 08:58:47. Finished checkpoint of "depot_2321" (depot_2321.db) at Tue Jan 28 2014 08:58 I. 01/28 09:06:07. Completing server shutdown I. 01/28 09:06:11. Database server stopped at Tue Jan 28 2014 09:06 What does it do between 08:58:47 and 09:06:07, 8 minutes??????? I. 01/28 08:58:44. Connection ID 11169: Client disconnected I. 01/28 08:58:44. Connection ID 3: Client disconnected I. 01/28 08:58:44. Connection ID 3: "PLC" disconnected from atabase "depot_2321" I. 01/28 08:58:44. Connection ID 11169: "PLC" disconnected from database "depot_2321" W. 01/28 08:58:44. TCPIP listener on IP address 0.0.0.0:2638 is exiting I. 01/28 08:58:44. Connection ID 71: "okq8" disconnected from database "depot_2321" I. 01/28 08:58:44. P,71,[S]DUMMY<seq> I. 01/28 08:58:44. Connection ID 4: "okq8" disconnected from database "depot_2321" I. 01/28 08:58:44. P,4,[S]DUMMY<seq> I. 01/28 08:58:44. P,4,[S]DUMMY<seq> I. 01/28 08:58:44. E,2040,-299,Statement interrupted by user I. 01/28 08:58:44. >,2040,EXEC I. 01/28 08:58:44. Connection ID 2040: "EXTENV_MAIN" disconnected from database "depot_2321" I. 01/28 08:58:44. Starting checkpoint of "depot_2321" (depot_2321.db) at Tue Jan 28 2014 08:58 I. 01/28 08:58:47. Finished checkpoint of "depot_2321" (depot_2321.db) at Tue Jan 28 2014 08:58 I. 01/28 09:06:07. Completing server shutdown I. 01/28 09:06:11. Database server stopped at Tue Jan 28 2014 09:06
(28 Jan '14, 09:21)
Janne
|
Please provide the exact version of your dbsrv12
SQL Anywhere Network Server Version 12.0.1.3994
Workgroup Edition
Copyright © 2001-2013, iAnywhere Solutions, Inc. Portions copyright © 1988-2013, Sybase, Inc. All rights reserved. Use of this software is governed by the Sybase License Agreement. Refer to http://www.sybase.com/softwarelicenses.
When you shutdown the server, do the active connections have uncommitted transactions? Stopping the server will force to rollback all uncommitted transactions, and that may require some work on the server.
Does the same happen if there are no (or just a few) active connections when you stop the service?
FWIW: net helpmsg 1053: