Logging Server Messages

SQL Anywhere engines display startup, progress and diagnostic text messages in the server window. Historically, the server window was called the "database console" so the messages are sometimes called the "console log".



The server messages may also include custom debugging and other output written by MESSAGE TO CONSOLE statements, and the command line option -o filespec.txt can be specified on the server command line to save all the messages to a text file:

"%SQLANY16%\bin64\dbsrv16.exe"^
  -o dbsrv16_log_ddd16.txt^
  ddd16.db 

MESSAGE 'Hello, world!' TO CONSOLE;

I. 04/08 09:07:11. SQL Anywhere Network Server Version 16.0.0.1324 I. 04/08 09:07:11. Developer edition, not licensed for deployment.
I. 04/08 09:07:11.  I. 04/08 09:07:11. Copyright © 2013 SAP AG or an SAP affiliate company.
...
I. 04/08 09:07:11. Automatic tuning of multiprogramming level is enabled
I. 04/08 09:07:11. Starting database "ddd16" (C:\temp\ddd16.db) at Mon Apr 08 2013 09:07
I. 04/08 09:07:11. Performance warning: Database file "C:\temp\ddd16.db" consists of 15 disk fragments
I. 04/08 09:07:11. Transaction log: ddd16.log
I. 04/08 09:07:11. Starting checkpoint of "ddd16" (ddd16.db) at Mon Apr 08 2013 09:07
I. 04/08 09:07:12. Finished checkpoint of "ddd16" (ddd16.db) at Mon Apr 08 2013 09:07
I. 04/08 09:07:12. Database "ddd16" (ddd16.db) started at Mon Apr 08 2013 09:07
I. 04/08 09:07:12. Database server started at Mon Apr 08 2013 09:07
I. 04/08 09:07:12. Trying to start SharedMemory link ...
I. 04/08 09:07:12.     SharedMemory link started successfully
I. 04/08 09:07:12. Trying to start TCPIP link ...
I. 04/08 09:07:12. Starting on port 2638
I. 04/08 09:07:17.     TCPIP link started successfully
I. 04/08 09:07:17. Now accepting requests
I. 04/08 09:08:30. Hello, world!

If you want to preserve a permanent record of these server messages, it is possible to gather them up at runtime and save them in the database. Unlike external files which can get lost and confused over time, data in the database is protected from inconsistencies by the ACID rules for database transactions, as well as being protected from loss by the regular database backup process (you do have a regular database backup process, right? ...riiight? :)

The sa_server_messages() system procedure makes the "gather them up at runtime" process possible, and some custom SQL takes care of the "save them in the database" part.

Here's a table designed to save all the msg_* columns returned by calls to sa_server_messages():

CREATE TABLE server_messages (
   primary_key    BIGINT NOT NULL DEFAULT AUTOINCREMENT PRIMARY KEY,
   msg_id         UNSIGNED BIGINT NOT NULL,
   msg_text       LONG VARCHAR NOT NULL,
   msg_time       TIMESTAMP NOT NULL,
   msg_severity   VARCHAR ( 255 ) NOT NULL,
   msg_category   VARCHAR ( 255 ) NOT NULL,
   msg_database   VARCHAR ( 255 ) NOT NULL,
   UNIQUE ( msg_id, msg_time ) );

The primary_key column has been added to guarantee ordering in the face of these facts:

• msg_id starts over at zero every time the server is restarted,
  

• it is conceivable that msg_time may repeat for rapid-fire messages, and
  

• msg_time values may fall back by one hour (and thus overlap if not repeat) when the autumn Daylight Saving Time change occurs.
  

At this point a bigger question arises: "If sa_server_messages() has access to all the server messages, why bother to save them separately? Why not just call sa_server_messages() whenever you want to query the messages?"

The answer is, only recent server messages are available to sa_server_messages(), so they must be repeatedly retrieved and saved in a separate table if you want to keep them longer. It is possible to define what "recent" means by setting the MessageCategoryLimit option but no matter what value you pick it may be possible for a flood of message output to cause data loss before you get around to calling sa_server_messages().

There are other advantages to using a permanent table:

• It's easier to replicate server messages to the consolidated database using SQL Remote or MobiLink if an ordinary table is involved, and
  

• different rules can be used for purging old data; e.g., delete by msg_time, delete by msg_category, delete uninteresting messages, and so on.
  

But the big reason is this: If the server's restarted, sa_server_messages() starts over from scratch... all the old messages are gone, gone, gone.

The following code uses a SQL Anywhere EVENT triggered once a minute to capture fresh messages. The code ignores the problem of inter-call message loss by assuming you can either increase the MessageCategoryLimit option and/or change the EVERY 1 MINUTES clause to something more frequent.

CREATE EVENT save_server_messages 
SCHEDULE START TIME '00:00' EVERY 1 MINUTES
HANDLER BEGIN

DECLARE @most_recent_msg_time   TIMESTAMP DEFAULT '1900-01-01';

-- Determine the approximate starting point for fresh messages.

SELECT TOP 1 msg_time 
  INTO @most_recent_msg_time
  FROM server_messages
 ORDER BY primary_key DESC;

-- Copy fresh messages.

INSERT server_messages (
       msg_id,
       msg_text,
       msg_time,
       msg_severity,
       msg_category,
       msg_database )
SELECT msg_id, 
       COALESCE ( msg_text, '' ),
       msg_time,
       msg_severity,
       msg_category,
       COALESCE ( msg_database, '' )
  FROM sa_server_messages()
 WHERE msg_time >= DATEADD ( hour, - 1, @most_recent_msg_time )
   AND NOT EXISTS  
          ( SELECT *
              FROM server_messages
             WHERE server_messages.msg_id   = sa_server_messages.msg_id
               AND server_messages.msg_time = sa_server_messages.msg_time ) 
 ORDER BY msg_id;

COMMIT;

END;

• The SELECT starting on line 9 determines an approximate starting point for copying fresh messages. It's an approximate value because Daylight Saving Time causes the clock-on-the-wall time to be set earlier by one hour each autumn, and messages recorded during that hour must be treated as fresh messages even though they may have msg_time values earlier than @most_recent_msg_time.
  

• The INSERT SELECT starting on line 16 copies and saves all the fresh messages returned by sa_server_messages().
  

• The COALESCE calls make life easier later on: no worries about NULL values when writing queries.
  

• The WHERE msg_time >= DATEADD predicate eliminates messages older than 1 hour.
  

• The NOT EXISTS predicate eliminates more recent messages that have already been copied. ON EXISTING SKIP is often a good alternative to this kind of NOT EXISTS, but not this time: ON EXISTING SKIP allows new DEFAULT AUTOINCREMENT values to be calculated and then discarded when the primary key value collides; it also requires a different primary key for the server_messages table... something other than a DEFAULT AUTOINCREMENT column (yes, this has been tested, and yes, ON EXISTING SKIP does work as long as you're OK with big gaps in the DEFAULT AUTOINCREMENT values).
  

• The ORDER BY msg_id clause makes sure that new DEFAULT AUTOINCREMENT values of the server_message.primary_key column are calculated in the same order as the messages were created. By definition, all rows returned by a single call to sa_server_messages() have monotonically increasing values of msg_id even though msg_id starts over again when the server is restarted. Put another way, sa_server_messages.msg_id works as a primary key for all the messages produced by a single execution of the SQL Anywhere server, which is all that sa_server_messages() returns.
  

Flaw: It is conceivable that the SQL Anywhere server could be shut down and restarted around the time the clock is set backward for Daylight Saving Time, causing the same values of msg_id and msg_time to be used for two different messages, and that the WHERE clause could cause one of those messages to be incorrectly discarded. The solution is left as an exercise for the person who cares reader :)

Here's what the table looks like...

---