Apple System Log (ASL) MARK Timestamps Mac OS X

To have a Mac OS X system produce a timestamp periodically and send it to the system log, add the following line to /etc/asl.conf:
  = mark_time sss
where sss is the number of seconds between timestamps. This will cause syslogd to produce a timestamp every sss seconds.

To have syslogd save the timestamps, add the following line to /etc/asl.conf:

  ? [= Level info] [= Facility syslog] store
  or if you wish to save them to a separate text log file:
  ? [= Level info] [= Facility syslog] file /var/log/timestamp.log
After the changes (above) have been made to /etc/asl.conf, send a HUP signal to syslogd as follows:
  % ps -axww | grep syslogd
  Get the PID from the command above then:
  % sudo kill -HUP <PID>
An example syslog entry for a timestamp is:
  [ASLMessageID 291061] [Time 1356637608] [TimeNanoSec 0] [Level 6]
    [PID 18] [UID 0] [GID 0] [ReadGID 80] [Host <hostname>]
    [Sender syslogd] [Facility syslog] [Message -- MARK --]
The timestamps can be found with the following command:
  % syslog -k Facility syslog -k Level Info -k Message eq "-- MARK --"

Note that syslogd can be started with the argument -m mm to produce periodic timestamps (where mm is the interval between timestamps in minutes). However, editing /etc/asl.conf and then sending a HUP signal to syslogd (as described above) is easier and retains more flexibility than editing:
  /System/Library/LaunchDaemons/com.apple.syslogd.plist
  to add:
  <string>-m</string>
  <string>10</string>
  and restarting syslogd or rebooting, though I believe that the results are identical.

Note that syslogd uses [Facility syslog] when producing the timestamps, not [Facility mark] as the documentation indicates (see the Apple System Log Documentation error, below). Also note that syslogd uses [Sender syslogd]when producing the timestamps, which should not be confused with [Facility syslog]. See the example timestamp entry in the syslog, above, which shows:
  [Sender syslogd] [Facility syslog]

Apple System Log Documentation error:

The documentation for syslogd and asl.conf both indicate that the timestamp messages will be produced with [Facility mark]. Typical documentation follows:
From the syslogd(8) man page:
 -mSet the number of minutes between "mark" messages. Mark messages are normally disabled. If -m is specified with no arguments, mark messages will be produced every 20 minutes. The "mark" facility is disabled if the setting is zero minutes.
From the asl.conf(5) man page:
 mark_time  Sets the time interval for the mark facility. The default is 0 seconds, which indicates that mark messages are not generated.
From <http://www.linuxjournal.com/article/5476>:
 Facilities are simply categories. Supported facilities in Linux are:
auth, authpriv, cron, daemon, kern, lpr, mail, mark, news, syslog, user, UUCP and local0 through local7.
Some of these are self-explanatory, but of special note are:
mark: messages generated by syslogd itself that contain only a timestamp and the string "-- MARK --".
To specify how many minutes should transpire between marks, invoke syslogd with the -m [minutes] flag.

However, an inspection of the syslogd source code (daemon.c) and observation of the action of syslogd both show that the timestamp messages are produced with [Facility syslog].

The relevant fragment of syslogd-148.8 daemon.c is:

  /* begin fragment of syslogd-148.8 daemon.c */
  void
  asl_mark(void)
  {
        char *str;

        str = NULL;
        asprintf(&str, "[%s syslogd] [%s %u] [%s %u] [%s -- MARK --] [%s 0] [%s 0] [Facility syslog]",
                         ASL_KEY_SENDER,
                         ASL_KEY_LEVEL, ASL_LEVEL_INFO,
                         ASL_KEY_PID, getpid(),
                         ASL_KEY_MSG, ASL_KEY_UID, ASL_KEY_GID);

        asl_log_string(str);
        if (str != NULL) free(str);
  }
  /* end fragment of syslogd-148.8 daemon.c */
The relevant fragment of syslogd-217.1.4 daemon.c is:
  /* begin fragment of syslogd-217.1.4 daemon.c */
  void
  asl_mark(void)
  {
        char *str = NULL;

        asprintf(&str, "[Sender syslogd] [Level 6] [PID %u] [Message -- MARK --] [UID 0] [UID 0] [Facility syslog]", global.pid);
        internal_log_message(str);
        free(str);
  }
  /* end fragment of syslogd-217.1.4 daemon.c */
I believe that the problem arises because the asprint string above should end with:
  [Facility mark]",
rather than:
  [Facility syslog]",
The documentation (and my reading of the source code) indicate that the timestamp will only be produced if some other message has not been logged in the previous mark_time sss seconds. However, it appears that with this setting, syslogd adds a timestamp every sss seconds regardless of whether another syslog entry has been produced in the previous sss seconds.

My current understanding of the source code is that timestamp messages with [Facility mark] will not be produced any more frequently than the mark_time sss frequency indicated in asl.conf (or the -m mm frequency used on the syslogd command line), however, because the timestamp messages are (incorrectly, I believe) set with [Facility syslog], perhaps this is why they escape the limit on how frequently they can & should be logged.

The relevant fragment of syslogd-148.8 syslogd.c is:

  /* begin code fragment of syslogd-148.8 syslogd.c */
        /* timer for MARK facility */
    if (global.mark_time > 0)
        {
                global.mark_timer = dispatch_source_create(DISPATCH_SOURCE_TYPE_TIMER, 0, 0, dispatch_get_main_queue());
                dispatch_source_set_event_handler(global.mark_timer, ^{ 
                        asl_mark();
                });
                dispatch_source_set_timer(global.mark_timer, dispatch_walltime(NULL, global.mark_time * NSEC_PER_SEC), global.mark_time * NSEC_PER_SEC, 0);
                dispatch_resume(global.mark_timer);
        }
  /* end code fragment of syslogd-148.8 syslogd.c */
The relevant fragment of syslogd-217.1.4 syslogd.c is:
  /* begin code fragment of syslogd-217.1.4 syslogd.c */
        /* timer for MARK facility */
        if (global.mark_time > 0)
        {
                global.mark_timer = dispatch_source_create(DISPATCH_SOURCE_TYPE_TIMER, 0, 0, dispatch_get_main_queue());
                dispatch_source_set_event_handler(global.mark_timer, ^{ 
                        asl_mark();
                });
                dispatch_source_set_timer(global.mark_timer, dispatch_time(DISPATCH_TIME_NOW, global.mark_time * NSEC_PER_SEC), global.mark_time * NSEC_PER_SEC, 0);
                dispatch_resume(global.mark_timer);
        }
  /* end code fragment of syslogd-217.1.4 syslogd.c */


Last Updated: 2014 September 3, Wednesday, 20:31:32 PDT (UTC-0700)