xnu-4903.231.4.tar.gz

[apple/xnu.git] / bsd / vfs / vfs_fslog.c

diff --git a/bsd/vfs/vfs_fslog.c b/bsd/vfs/vfs_fslog.c
index dfc64b7a2ca2e61552b6e29391844dd3c18cbf24..87db6067f5470105291a4f7c0dc84e26a2936029 100644 (file)
--- a/bsd/vfs/vfs_fslog.c
+++ b/bsd/vfs/vfs_fslog.c
@@ -1,5 +1,5 @@
 /*
 /*

- * Copyright (c) 2006 Apple Computer, Inc. All rights reserved.
+ * Copyright (c) 2006-2017 Apple Inc. All rights reserved.

  *
  * @APPLE_OSREFERENCE_LICENSE_HEADER_START@
  * 
  *
  * @APPLE_OSREFERENCE_LICENSE_HEADER_START@
  * 


@@ -40,7 +40,8 @@
 #include <sys/mount_internal.h>
 #include <sys/kasl.h>
 
 #include <sys/mount_internal.h>
 #include <sys/kasl.h>
 

-#include <dev/random/randomdev.h>
+#include <sys/queue.h>
+#include <kern/kalloc.h>

 
 #include <uuid/uuid.h>
 
 
 #include <uuid/uuid.h>
 


@@ -74,7 +75,7 @@ fslog_extmod_msgtracer(proc_t caller, proc_t target)
                strlcat(c_name, "(", sizeof(c_name));
                strlcat(c_name, uuidstr, sizeof(c_name));
                strlcat(c_name, ")", sizeof(c_name));
                strlcat(c_name, "(", sizeof(c_name));
                strlcat(c_name, uuidstr, sizeof(c_name));
                strlcat(c_name, ")", sizeof(c_name));

-               if (0 != escape_str(c_name, strlen(c_name), sizeof(c_name))) {
+               if (0 != escape_str(c_name, strlen(c_name) + 1, sizeof(c_name))) {

                        return;
                }
 
                        return;
                }
 


@@ -83,7 +84,7 @@ fslog_extmod_msgtracer(proc_t caller, proc_t target)
                strlcat(t_name, "(", sizeof(t_name));
                strlcat(t_name, uuidstr, sizeof(t_name));
                strlcat(t_name, ")", sizeof(t_name));
                strlcat(t_name, "(", sizeof(t_name));
                strlcat(t_name, uuidstr, sizeof(t_name));
                strlcat(t_name, ")", sizeof(t_name));

-               if (0 != escape_str(t_name, strlen(t_name), sizeof(t_name))) {
+               if (0 != escape_str(t_name, strlen(t_name) + 1, sizeof(t_name))) {

                        return;
                }
 #if DEBUG
                        return;
                }
 #if DEBUG


@@ -105,231 +106,170 @@ fslog_extmod_msgtracer(proc_t caller, proc_t target)
        }
 }
 
        }
 }
 

-/* Log file system related error in key-value format identified by Apple 
- * system log (ASL) facility.  The key-value pairs are string pointers 
- * (char *) and are provided as variable arguments list.  A NULL value 
- * indicates end of the list.
- *
- * Keys can not contain '[', ']', space, and newline.  Values can not 
- * contain '[', ']', and newline.  If any key-value contains any of the 
- * reserved characters, the behavior is undefined.  The caller of the 
- * function should escape any occurrences of '[' and ']' by prefixing
- * it with '\'.
- * 
- * The function takes a message ID which can be used to logically group
- * different ASL messages.  Messages in same logical group have same message
- * ID and have information to describe order of the message --- first, 
- * middle, or last.
- *
- * The following message IDs have special meaning - 
- * FSLOG_MSG_FIRST - This message is the first message in its logical
- *     group.  This generates a unique message ID, creates two key-value 
- *     pairs with message ID and order of the message as "First".
- * FSLOG_MSG_LAST - This is really a MASK which should be logically OR'ed 
- *     with message ID to indicate the last message for a logical group.  
- *     This also creates two key-value pairs with message ID and order of 
- *     message as "Last".
- * FSLOG_MSG_SINGLE - This signifies that the message is the only message
- *     in its logical group.  Therefore no extra key-values are generated 
- *     for this option.
- * For all other values of message IDs, it regards them as intermediate 
- * message and generates two key-value pairs with message ID and order of
- * message as "Middle".
- * 
- * Returns - 
- *     Message ID of the ASL message printed.  The caller should use
- *     this value to print intermediate messages or end the logical message
- *     group.
- *     For FSLOG_MSG_SINGLE option, it returns FSLOG_MSG_SINGLE. 
+#if defined(__x86_64__)
+
+/*
+ * Log information about floating point exception handling

  */
  */

-unsigned long fslog_err(unsigned long msg_id, ... )
+
+static lck_mtx_t fpxlock;
+
+void
+fpxlog_init(void)

 {
 {

-       va_list ap;
-       int num_pairs;
-       char msg_id_str[21]; /* To convert 64-bit number to string with NULL char */
-       char *arg;
-       const char *msg_order_ptr;
-
-       /* Count number of arguments and key-value pairs provided by user */
-       num_pairs = 0;
-       va_start(ap, msg_id);
-       arg = va_arg(ap, char *);
-       while (arg) {
-               num_pairs++;
-               arg = va_arg(ap, char *);
-       }
-       num_pairs /= 2;
-       va_end(ap);
-
-       va_start(ap, msg_id);
-       if (msg_id == FSLOG_MSG_SINGLE) {
-               /* Single message, do not print message ID and message order */
-               (void) kern_asl_msg_va(FSLOG_VAL_LEVEL, FSLOG_VAL_FACILITY, 
-                   num_pairs, ap,
-                   FSLOG_KEY_READ_UID, FSLOG_VAL_READ_UID,
-                   NULL);
-       } else {
-               if (msg_id == FSLOG_MSG_FIRST) {
-                       /* First message, generate random message ID */
-                       while ((msg_id == FSLOG_MSG_FIRST) ||
-                              (msg_id == FSLOG_MSG_LAST) ||
-                              (msg_id == FSLOG_MSG_SINGLE)) {
-                               msg_id = RandomULong();
-                               /* MSB is reserved for indicating last message 
-                                * in sequence.  Clear the MSB while generating
-                                * new message ID.
-                                */
-                               msg_id = msg_id >> 1;
-                       }
-                       msg_order_ptr = FSLOG_VAL_ORDER_FIRST;
-               } else if (msg_id & FSLOG_MSG_LAST) { 
-                       /* MSB set to indicate last message for this ID */
-                       msg_order_ptr = FSLOG_VAL_ORDER_LAST;
-                       /* MSB of message ID is set to indicate last message
-                        * in sequence.  Clear the bit to get real message ID.
-                        */
-                       msg_id = msg_id & ~FSLOG_MSG_LAST;
-               } else {
-                       /* Intermediate message for this ID */
-                       msg_order_ptr = FSLOG_VAL_ORDER_MIDDLE;
-               }
+       lck_grp_attr_t *lck_grp_attr = lck_grp_attr_alloc_init();
+       lck_grp_t *lck_grp = lck_grp_alloc_init("fpx", lck_grp_attr);
+       lck_mtx_init(&fpxlock, lck_grp, LCK_ATTR_NULL);
+}

 
 

-               snprintf(msg_id_str, sizeof(msg_id_str), "%lu", msg_id);
-               (void) kern_asl_msg_va(FSLOG_VAL_LEVEL, FSLOG_VAL_FACILITY, 
-                   num_pairs, ap,
-                   FSLOG_KEY_READ_UID, FSLOG_VAL_READ_UID,
-                   FSLOG_KEY_MSG_ID, msg_id_str, 
-                   FSLOG_KEY_MSG_ORDER, msg_order_ptr, NULL);
-       }
-       va_end(ap);
-       return msg_id;
+struct fpx_event {
+       uuid_t fe_uuid;
+       uint32_t fe_code;
+       uint32_t fe_xcpt;
+       TAILQ_ENTRY(fpx_event) fe_link;
+};
+
+static bool
+match_fpx_event(const struct fpx_event *fe,
+    const uuid_t uuid, const uint32_t code, const uint32_t xcpt)
+{
+       return (code == fe->fe_code && xcpt == fe->fe_xcpt &&
+           0 == memcmp(uuid, fe->fe_uuid, sizeof (uuid_t)));

 }
 
 }
 

-/* Log information about runtime file system corruption detected by
- * the file system.  It takes the VFS mount structure as 
- * parameter which is used to access the mount point of the 
- * corrupt volume.  If no mount structure or mount point string 
- * string exists, nothing is logged to ASL database.
- * 
- * Currently prints following information - 
- *     1. Mount Point
- */
-void fslog_fs_corrupt(struct mount *mnt)
+#if FPX_EVENT_DBG
+static __attribute__((noinline)) void
+print_fpx_event(const char *pfx, const struct fpx_event *fe)

 {
 {

-       if (mnt != NULL) {
-               fslog_err(FSLOG_MSG_SINGLE,
-                         FSLOG_KEY_ERR_TYPE, FSLOG_VAL_ERR_TYPE_FS,
-                         FSLOG_KEY_MNTPT, mnt->mnt_vfsstat.f_mntonname,
-                         NULL);
-       }
-               
-       return;
-} 
+       uuid_string_t uustr;
+       uuid_unparse_upper(fe->fe_uuid, uustr);
+       printf("%s: code 0x%x xcpt 0x%x uuid '%s'\n",
+           pfx, fe->fe_code, fe->fe_xcpt, uustr);
+}
+#define DPRINTF_FPX_EVENT(pfx, fe)     print_fpx_event(pfx, fe)
+#else
+#define DPRINTF_FPX_EVENT(pfx, fe)     /* nothing */
+#endif

 
 

-/* Log information about IO error detected in buf_biodone()
- * Currently prints following information - 
- *     1. Physical block number
- *     2. Logical block number
- *     3. Device node 
- *     4. Mount point
- *     5. Path for file, if any
- *     6. Error number
- *     7. Type of IO (read/write)
+#define MAX_DISTINCT_FPX_EVENTS        101     /* (approx one page of heap) */
+
+/*
+ * Filter to detect "new" <uuid, code, xcpt> tuples.
+ * Uses limited amount of state, managed LRU.
+ * Optimized to ignore repeated invocation with the same tuple.
+ *
+ * Note that there are 6 exception types, two types of FP, and
+ * many binaries, so don't make the list bound too small.
+ * It's also a linear search, so don't make it too large either.
+ * Next level filtering provided by syslogd, and summarization.

  */
  */

-void fslog_io_error(const buf_t bp)
+static bool
+novel_fpx_event(const uuid_t uuid, uint32_t code, uint32_t xcpt)

 {
 {

-       int err;
-       unsigned long msg_id;
-       char blknum_str[21];
-       char lblknum_str[21];
-       char errno_str[6];
-       const char *iotype;
-       unsigned char print_last = 0;
-       vnode_t vp;
-
-       if (buf_error(bp) == 0) {
-               return;
-       }
+       static TAILQ_HEAD(fpx_event_head, fpx_event) fehead =
+               TAILQ_HEAD_INITIALIZER(fehead);
+       struct fpx_event *fe;

 
 

-       /* Convert error number to string */
-       snprintf (errno_str, sizeof(errno_str), "%d", buf_error(bp));
+       lck_mtx_lock(&fpxlock);

 
 

-       /* Determine type of IO operation */
-       if (buf_flags(bp) & B_READ) {
-               iotype = FSLOG_VAL_IOTYPE_READ;
-       } else {
-               iotype = FSLOG_VAL_IOTYPE_WRITE;
+       fe = TAILQ_FIRST(&fehead);
+       if (NULL != fe &&
+           match_fpx_event(fe, uuid, code, xcpt)) {
+               /* seen before and element already at head */
+               lck_mtx_unlock(&fpxlock);
+               DPRINTF_FPX_EVENT("seen, head", fe);
+               return (false);

        }
 
        }
 

-       /* Convert physical block number to string */
-       snprintf (blknum_str, sizeof(blknum_str), "%lld", buf_blkno(bp));
-
-       /* Convert logical block number to string */
-       snprintf (lblknum_str, sizeof(lblknum_str), "%lld", buf_lblkno(bp));
-
-       msg_id = fslog_err(FSLOG_MSG_FIRST,
-                               FSLOG_KEY_ERR_TYPE, FSLOG_VAL_ERR_TYPE_IO,
-                               FSLOG_KEY_ERRNO, errno_str,
-                               FSLOG_KEY_IOTYPE, iotype,
-                               FSLOG_KEY_PHYS_BLKNUM, blknum_str,
-                               FSLOG_KEY_LOG_BLKNUM, lblknum_str,
-                               NULL);
-       
-       /* Access the vnode for this buffer */
-       vp = buf_vnode(bp);
-       if (vp) {
-               struct vfsstatfs *sp;
-               mount_t mp;
-               char *path;
-               int len;
-               struct vfs_context context;
-
-               mp = vnode_mount(vp);
-               /* mp should be NULL only for bdevvp during boot */
-               if (mp == NULL) {
-                       goto out;
+       unsigned int count = 0;
+
+       TAILQ_FOREACH(fe, &fehead, fe_link) {
+               if (match_fpx_event(fe, uuid, code, xcpt)) {
+                       /* seen before, now move element to head */
+                       TAILQ_REMOVE(&fehead, fe, fe_link);
+                       TAILQ_INSERT_HEAD(&fehead, fe, fe_link);
+                       lck_mtx_unlock(&fpxlock);
+                       DPRINTF_FPX_EVENT("seen, moved to head", fe);
+                       return (false);

                }
                }

-               sp = vfs_statfs(mp);
-
-               /* Access the file path */
-               MALLOC(path, char *, MAXPATHLEN, M_TEMP, M_WAITOK);
-               if (path) {
-                       len = MAXPATHLEN;
-                       context.vc_thread = current_thread();
-                       context.vc_ucred = kauth_cred_get();
-                       /* Find path without entering file system */
-                       err = build_path(vp, path, len, &len, BUILDPATH_NO_FS_ENTER,
-                                        &context);     
-                       if (!err) {
-                               err = escape_str(path, len, MAXPATHLEN);
-                               if (!err) {
-                                       /* Print device node, mount point, path */
-                                       msg_id = fslog_err(msg_id | FSLOG_MSG_LAST, 
-                                               FSLOG_KEY_DEVNODE, sp->f_mntfromname,
-                                               FSLOG_KEY_MNTPT, sp->f_mntonname, 
-                                               FSLOG_KEY_PATH, path, 
-                                               NULL);
-                                       print_last = 1;
-                               }
-                       }
-                       FREE(path, M_TEMP);
-               } 
-
-               if (print_last == 0) {
-                       /* Print device node and mount point */
-                       msg_id = fslog_err(msg_id | FSLOG_MSG_LAST, 
-                                       FSLOG_KEY_DEVNODE, sp->f_mntfromname,
-                                       FSLOG_KEY_MNTPT, sp->f_mntonname, 
-                                       NULL);
-                       print_last = 1;
-               } 
+               count++;

        }
 
        }
 

-out:
-       if (print_last == 0) {
-               msg_id = fslog_err(msg_id | FSLOG_MSG_LAST, NULL);
+       /* not recorded here => novel */
+
+       if (count >= MAX_DISTINCT_FPX_EVENTS) {
+               /* reuse LRU element */
+               fe = TAILQ_LAST(&fehead, fpx_event_head);
+               TAILQ_REMOVE(&fehead, fe, fe_link);
+               DPRINTF_FPX_EVENT("reusing", fe);
+       } else {
+               /* add a new element to the list */
+               fe = kalloc(sizeof (*fe));

        }
        }

+       memcpy(fe->fe_uuid, uuid, sizeof (uuid_t));
+       fe->fe_code = code;
+       fe->fe_xcpt = xcpt;
+       TAILQ_INSERT_HEAD(&fehead, fe, fe_link);
+       lck_mtx_unlock(&fpxlock);
+
+       DPRINTF_FPX_EVENT("novel", fe);
+
+       return (true);
+}
+
+void
+fpxlog(
+       int code,       /* Mach exception code: e.g. 5 or 8 */
+       uint32_t stat,  /* Full FP status register bits */
+       uint32_t ctrl,  /* Full FP control register bits */
+       uint32_t xcpt)  /* Exception bits from FP status */
+{
+       proc_t p = current_proc();
+       if (PROC_NULL == p)
+               return;
+
+       uuid_t uuid;
+       proc_getexecutableuuid(p, uuid, sizeof (uuid));
+
+       /*
+        * Check to see if an exception with this <uuid, code, xcpt>
+        * has been seen before.  If "novel" then log a message.
+        */
+       if (!novel_fpx_event(uuid, code, xcpt))
+               return;
+
+       const size_t nmlen = 2 * MAXCOMLEN + 1;
+       char nm[nmlen] = {};
+       proc_selfname(nm, nmlen);
+       if (escape_str(nm, strlen(nm) + 1, nmlen))
+               snprintf(nm, nmlen, "(a.out)");

 
 

-       return;
+       const size_t slen = 8 + 1 + 8 + 1;
+       char xcptstr[slen], csrstr[slen];
+
+       snprintf(xcptstr, slen, "%x.%x", code, xcpt);
+       if (ctrl == stat)
+               snprintf(csrstr, slen, "%x", ctrl);
+       else
+               snprintf(csrstr, slen, "%x.%x", ctrl, stat);
+
+#if DEVELOPMENT || DEBUG
+       printf("%s[%d]: com.apple.kernel.fpx: %s, %s\n",
+               nm, proc_pid(p), xcptstr, csrstr);
+#endif
+       kern_asl_msg(LOG_DEBUG, "messagetracer", 5,
+       /* 0 */ "com.apple.message.domain", "com.apple.kernel.fpx",
+       /* 1 */ "com.apple.message.signature", nm,
+       /* 2 */ "com.apple.message.signature2", xcptstr,
+       /* 3 */ "com.apple.message.value", csrstr,
+       /* 4 */ "com.apple.message.summarize", "YES",
+               NULL);

 }
 
 }
 

+#else
+
+void
+fpxlog_init(void)
+{}
+
+#endif /* __x86_64__ */