Skip to Content

If you find your ASE server unexpectedly not running, the errorlog can provide some useful clues as to how it shutdown.

Obligatory anecdote:

Many years ago, I once worked a support case with a customer who had ended up with hard corruption in their database.  Their errorlog showed that ASE had repeatedly rebooted, roughly 20 times over the course of the previous night.  Their host was setup to automatically boot ASE when the OS started up.  Each time there was no indication of why ASE had shutdown.  I expressed the opinion that the lack of shutdown messages made me think the most likely cause was power being repeatedly shut off. A check of the OS logs confirmed that the host had also been rebooted many times with no indication of a polite shutdown.  The problem was soon tracked down to new cleaning staff turning the power on and off in the computer lab.  We didn’t investigate the corruption further, the assumption being that a hard drive abruptly losing power while writing was a reasonable cause (and the corrupt data was clearly gibberish that didn’t resemble formatted data).

Behavior for TSQL “shutdown” command (commonly called a ‘polite shutdown’):

00:0006:00000:00012:2013/07/22 09:33:58.10 server  Shutdown started by user ‘sa’. SQL text: shutdown
00:0006:00000:00012:2013/07/22 09:34:00.10 server  ASE shutdown by request.
00:0006:00000:00012:2013/07/22 09:34:00.10 kernel  ueshutdown: exiting
00:0000:00000:00000:2013/07/22 09:34:00.10 kernel  Main thread performing final shutdown.
00:0000:00000:00000:2013/07/22 09:34:00.19 kernel  Blocking call queue shutdown.
00:0000:00000:00000:2013/07/22 09:34:00.20 kernel  SySAM: Checked in license for 1 ASE_CORE

Behavior for TSQL “shutdown with nowait” command (commonly called an ‘abrupt shutdown’):

00:0002:00000:00014:2013/07/22 09:30:11.14 server  Shutdown started by user ‘sa’. SQL text: shutdown with nowait
00:0002:00000:00014:2013/07/22 09:30:11.14 server  Shutdown with nowait detected – ASE process level execution bindings will be cleared on startup.
00:0002:00000:00014:2013/07/22 09:30:11.16 server  ASE shutdown by request.
00:0002:00000:00014:2013/07/22 09:30:11.17 kernel  ueshutdown: exiting
00:0000:00000:00000:2013/07/22 09:30:11.18 kernel  Main thread performing final shutdown.
00:0000:00000:00000:2013/07/22 09:30:11.28 kernel  Blocking call queue shutdown.
00:0000:00000:00000:2013/07/22 09:30:11.80 kernel  SySAM: Checked in license for 1 ASE_CORE

Behavior for OS “kill <pid>” command:

00:0006:00000:00000:2013/07/22 09:36:07.02 kernel  ueshutdown: exiting
00:0000:00000:00000:2013/07/22 09:36:07.02 kernel  Main thread performing final shutdown.
00:0000:00000:00000:2013/07/22 09:36:07.23 kernel  Blocking call queue shutdown.
00:0000:00000:00000:2013/07/22 09:36:07.23 kernel  SySAM: Checked in license for 1 ASE_CORE

Behavior for spid-fatal error while holding a spinlock:

00:0014:00000:02998:2014/01/20 03:10:23.62 kernel Spinlocks held by kpid <kpid#>
[…fatal error, typically with a stack trace…]
00:0014:00000:02998:2014/01/20 03:10:23.62 kernel Spinlock Resource-><spinlock name> at address <address> owned by <kpid#>
00:0014:00000:02998:2014/01/20 03:10:23.62 kernel End of spinlock display.
[… typically another stack trace …]
00:0014:00000:02998:2014/01/20 03:10:23.62 kernel end of stack trace, spid <spid>, kpid <kpid>, suid <suid>
00:0014:00000:02998:2014/01/20 03:10:23.62 kernel ueshutdown: exiting
[On a server running in threaded mode rather than process mode, the following additional line is also output:]
00:0000:00000:00000:2014/01/20 03:10:23.62 kernel Main thread performing final shutdown.

Behavior for an OS Panic:

00:0006:00000:00000:2013/07/22 09:36:07.02 kernel Engine 0 (os pid <pid> has died, server is performing emergency shutdown
[…]
stacktrace containing the function keipanic+0x8c (offset may vary by platform)
[…]
00:0006:00000:00000:2013/07/22 09:36:07.02 kernel ueshutdown: exiting
00:0006:00000:00000:2013/07/22 09:36:07.02kernel end of stack trace, kernel
service process: kpid 1114129

Behavior for OS “kill -9 <pid>” command:

[no output added to log].

Behavior for UNIX OS shutdown and reboot:

[no output added to log]

Behavior for abrupt power shutoff:

[no output added to log]

Other possible causes (not exhaustive) of no shutdown-related information in the errorlog:

a) Errorlog’s file system filled before the shutdown
b) Errorlog file disconnected from file descriptor used by ASE.
   For example, errorlog copied to another file, original file deleted, copy renamed.
   A possible hint for this is an unusual lack of entries preceeding the shutdown.
c) Errorlog could have been edited to remove information.

To report this post you need to login first.

2 Comments

You must be Logged on to comment or reply to a post.

  1. Jens Gleichmann

    Hi Bret,

    thanks for sharing this. I think this helps all DBA’s to interpret the error logs.

    I had a simular issue. The customer noticed a regurlar shutdown at about 03:30AM every 2 weeks. The system logs displayed this:

    00:0000:00000:00000:2014/05/18 03:29:15.59 kernel  kisignal: SQL Server terminated by system shutdown.

    00:0000:00000:00000:2014/05/18 03:29:15.60 kernel  ueshutdown: exiting

    00:0011:00000:00000:2014/05/18 03:29:15.60 kernel  Sybperf helper thread is quitting

    00:0000:00000:00000:2014/05/18 03:29:15.60 kernel  Main thread performing final shutdown.

    00:0000:00000:00000:2014/05/18 03:29:15.65 kernel  Blocking call queue shutdown.

    This logs entries are displayed if it is a normal system shutdown (OS Windows) which includes a stop of the sybase services. The reason was that the customer activated the automatic windows updates. The WSUS (Windows Server Update Services) will restart the server after 3 days (policy default).

    This should never be activated. You should test the updates in your test environment and implement the patches after successful test phase in QAS/PRD systems.

    Regards,

    Jens

    (0) 
  2. Bart Van Kuijk

    To add to Jens’s reply, on Windows ASE there is another shutdown sequence that can be seen when ASE is shutdown through the Services utility and is identified by the ‘shutdownproc’ prefix :

    00:0002:00000:00003:2014/06/02 14:41:28.63 kernel  shutdownproc: shutting down SQL Server!

    00:0002:00000:00003:2014/06/02 14:41:28.71 server  ASE shutdown by request.

    00:0002:00000:00003:2014/06/02 14:41:28.71 kernel  ueshutdown: exiting

    Rgds

    Bart van Kuijk

    (0) 

Leave a Reply