Re: [Linux-ia64] SAL error record logging/decoding

Bjorn Helgaas
2003-05-28T23:26:02Z

[-- Attachment #1: Type: text/plain, Size: 11561 bytes --]

On Wednesday 21 May 2003 12:06 pm, Luck, Tony wrote:
> Is there any easy way to get a notification that there is
> a record waiting in one of the /proc/sal/cpuX/* files ...

That's a good question that hadn't even occurred to me.
Here's another pass; see what you think:

- Added support for poll(2) on the cpuX/* files
- App keeps all the (4*NR_CPUS) files open
- poll(2) tells app which files have data to be read
- Added wakeup at the place we currently call
ia64_log_print

It got a little more involved than I hoped, because I didn't
want to call get_state_info() for all (4*NR_CPUS) files every
time the app called poll(2).

Oh, and I removed the MCA printks from the kernel. I'll
go back and pull all the other printks out too, but I'll
propose that as a separate patch to avoid cluttering this
one.

Later, Tony wrote:
> 4) Reading this way is also kind of weird in that every partial read
> results in the kernel going back to re-fetch the data from the SAL
> with another call to ia64_sal_get_state_info().

I thought about trying to avoid this by caching the records in
open(), but then the app has to close and reopen the file in
order to see new data. I really want to avoid managing buffers
of this stuff in the kernel, and I couldn't figure out a good
way to avoid the extra get_state_info() calls without maintaining
a lot more state. With the current patch, we do about 4 or 5
get_state_info() calls per event:

- ia64_os_mca_tlb_error_check() in mca_asm.S
- ia64_log_get() in mca.c ISR
- salinfo_log_read_cpu() when app reads record
- salinfo_log_read_cpu() (to get EOF indication
after a short read)
- salinfo_log_clear_cpu() when app clears record
(to see whether this makes another record available)

and I think we can get rid of the one in mca.c by just doing
the appropriate wakeup. If the kernel doesn't decode anything,
there's probably no need to even get the record.

That still seems like a lot, but at least it scales with the
number of events that occur, not the number of CPUs and event
types.

Bjorn

===== arch/ia64/kernel/mca.c 1.26 vs edited =====
--- 1.26/arch/ia64/kernel/mca.c Fri May 16 04:33:42 2003
+++ edited/arch/ia64/kernel/mca.c Wed May 28 09:48:33 2003
@@ -130,12 +130,14 @@
*/
static int cmc_polling_enabled = 1;

+extern void salinfo_log_wakeup(int);
+
/*
* ia64_mca_log_sal_error_record
*
- * This function retrieves a specified error record type from SAL, sends it to
- * the system log, and notifies SALs to clear the record from its non-volatile
- * memory.
+ * This function retrieves a specified error record type from SAL,
+ * wakes up any processes waiting for error records, and sends it to
+ * the system log.
*
* Inputs : sal_info_type (Type of error record MCA/CMC/CPE/INIT)
* Outputs : platform error status
@@ -155,11 +157,8 @@
* 3. set ia64_os_mca_recovery_successful flag, if applicable
*/

+ salinfo_log_wakeup(sal_info_type);
platform_err = ia64_log_print(sal_info_type, (prfunc_t)printk);
- /* temporary: only clear SAL logs on hardware-corrected errors
- or if we're logging an error after an MCA-initiated reboot */
- if ((sal_info_type > 1) || (called_from_init))
- ia64_sal_clear_state_info(sal_info_type);

return platform_err;
}
@@ -369,9 +368,7 @@
* ia64_mca_check_errors
*
* External entry to check for error records which may have been posted by SAL
- * for a prior failure which resulted in a machine shutdown before an the
- * error could be logged. This function must be called after the filesystem
- * is initialized.
+ * for a prior failure.
*
* Inputs : None
*
@@ -383,6 +380,7 @@
/*
* If there is an MCA error record pending, get it and log it.
*/
+ printk("CPU %d: checking for saved MCA error records\n", smp_processor_id());
ia64_mca_log_sal_error_record(SAL_INFO_TYPE_MCA, 1);

return 0;
@@ -1250,9 +1248,6 @@

ia64_process_min_state_save(&SAL_LPI_PSI_INFO(proc_ptr)->min_state_area);

- /* Clear the INIT SAL logs now that they have been saved in the OS buffer */
- ia64_sal_clear_state_info(SAL_INFO_TYPE_INIT);
-
init_handler_platform(proc_ptr, pt, sw); /* call platform specific routines */
}

@@ -2302,10 +2297,8 @@

switch(sal_info_type) {
case SAL_INFO_TYPE_MCA:
- prfunc("+BEGIN HARDWARE ERROR STATE AT MCA\n");
- platform_err = ia64_log_platform_info_print(IA64_LOG_CURR_BUFFER(sal_info_type),
- prfunc);
- prfunc("+END HARDWARE ERROR STATE AT MCA\n");
+ prfunc("+CPU %d: SAL log contains MCA error record\n", smp_processor_id());
+ ia64_log_rec_header_print(IA64_LOG_CURR_BUFFER(sal_info_type), prfunc);
break;
case SAL_INFO_TYPE_INIT:
prfunc("+MCA INIT ERROR LOG (UNIMPLEMENTED)\n");
===== arch/ia64/kernel/salinfo.c 1.1 vs edited =====
--- 1.1/arch/ia64/kernel/salinfo.c Thu Sep 12 10:43:47 2002
+++ edited/arch/ia64/kernel/salinfo.c Wed May 28 15:46:59 2003
@@ -4,16 +4,21 @@
* Creates entries in /proc/sal for various system features.
*
* Copyright (c) 2001 Silicon Graphics, Inc. All rights reserved.
+ * Copyright (c) 2003 Hewlett-Packard Co
+ * Bjorn Helgaas <bjorn.helgaas@hp.com>
*
* 10/30/2001 jbarnes@sgi.com copied much of Stephane's palinfo
* code to create this file
*/

#include <linux/types.h>
+#include <linux/poll.h>
#include <linux/proc_fs.h>
#include <linux/module.h>
+#include <linux/smp.h>

#include <asm/sal.h>
+#include <asm/uaccess.h>

MODULE_AUTHOR("Jesse Barnes <jbarnes@sgi.com>");
MODULE_DESCRIPTION("/proc interface to IA-64 SAL features");
@@ -40,25 +45,236 @@

#define NR_SALINFO_ENTRIES (sizeof(salinfo_entries)/sizeof(salinfo_entry_t))

-/*
- * One for each feature and one more for the directory entry...
- */
-static struct proc_dir_entry *salinfo_proc_entries[NR_SALINFO_ENTRIES + 1];
+static char *salinfo_log_name[] = {
+ "mca",
+ "init",
+ "cmc",
+ "cpe",
+};
+
+static struct proc_dir_entry *salinfo_proc_entries[
+ ARRAY_SIZE(salinfo_entries) + /* /proc/sal/bus_lock */
+ (NR_CPUS * ARRAY_SIZE(salinfo_log_name)) + /* /proc/sal/cpu0/mca */
+ NR_CPUS + /* /proc/sal/cpu0 */
+ 1]; /* /proc/sal */
+
+struct salinfo_log_data {
+ int type;
+ u8 *log_buffer;
+ u64 log_size;
+};
+
+struct salinfo_wait_queue {
+ int cpu;
+ int type;
+ int event_ready;
+ wait_queue_head_t queue;
+};
+
+static struct salinfo_wait_queue *salinfo_wait[NR_CPUS][ARRAY_SIZE(salinfo_log_name)];
+
+void
+salinfo_log_wakeup(int type)
+{
+ int cpu = smp_processor_id();
+
+ if (type < ARRAY_SIZE(salinfo_log_name)) {
+ struct salinfo_wait_queue *wait = salinfo_wait[cpu][type];
+
+ if (wait) {
+ wait->event_ready = 1;
+ wake_up_interruptible(&wait->queue);
+ }
+ }
+}
+
+static int
+salinfo_log_open(struct inode *inode, struct file *file)
+{
+ if (!suser())
+ return -EPERM;
+ return 0;
+}
+
+static void
+call_on_cpu(int cpu, void (*fn)(void *), void *arg)
+{
+#ifdef CONFIG_SMP
+ if (cpu == smp_processor_id())
+ (*fn)(arg);
+ else
+ smp_call_function_single(cpu, fn, arg, 0, 1);
+#else
+ (*fn)(arg);
+#endif
+}
+
+static void
+salinfo_log_read_cpu(void *context)
+{
+ struct salinfo_log_data *info = context;
+ struct salinfo_wait_queue *wait = salinfo_wait[smp_processor_id()][info->type];
+ u64 size;
+
+ size = ia64_sal_get_state_info_size(info->type);
+ info->log_buffer = kmalloc(size, GFP_ATOMIC);
+ if (!info->log_buffer)
+ return;
+
+ wait->event_ready = 0;
+ info->log_size = ia64_sal_get_state_info(info->type, (u64 *) info->log_buffer);
+ if (info->log_size)
+ salinfo_log_wakeup(info->type);
+}
+
+static ssize_t
+salinfo_log_read(struct file *file, char *buffer, size_t count, loff_t *ppos)
+{
+ struct inode *inode = file->f_dentry->d_inode;
+ struct proc_dir_entry *entry = (struct proc_dir_entry *) inode->u.generic_ip;
+ struct salinfo_wait_queue *wait = entry->data;
+ struct salinfo_log_data info;
+ int ret;
+ void *data;
+ size_t size;
+
+ info.type = wait->type;
+ call_on_cpu(wait->cpu, salinfo_log_read_cpu, &info);
+
+ if (!info.log_buffer || *ppos >= info.log_size) {
+ ret = 0;
+ goto out;
+ }
+
+ data = info.log_buffer + file->f_pos;
+ size = info.log_size - file->f_pos;
+ if (size > count)
+ size = count;
+
+ if (copy_to_user(buffer, data, size)) {
+ ret = -EFAULT;
+ goto out;
+ }
+
+ *ppos += size;
+ ret = size;
+
+out:
+ kfree(info.log_buffer);
+ return ret;
+}
+
+static void
+salinfo_log_clear_cpu(void *context)
+{
+ struct salinfo_wait_queue *wait = context;
+ struct salinfo_log_data info;
+
+ wait->event_ready = 0; /* avoid race with another wakeup */
+ ia64_sal_clear_state_info(wait->type);
+
+ info.type = wait->type;
+ salinfo_log_read_cpu(&info);
+ if (info.log_buffer && info.log_size)
+ salinfo_log_wakeup(wait->type);
+
+ kfree(info.log_buffer);
+}
+
+static ssize_t
+salinfo_log_write(struct file *file, const char *buffer, size_t count, loff_t *ppos)
+{
+ struct inode *inode = file->f_dentry->d_inode;
+ struct proc_dir_entry *entry = (struct proc_dir_entry *) inode->u.generic_ip;
+ struct salinfo_wait_queue *wait = entry->data;
+ char cmd[16];
+
+ if (ppos != &file->f_pos)
+ return -ESPIPE;
+
+ memset(cmd, 0, sizeof(cmd));
+ if (copy_from_user(cmd, buffer, sizeof(cmd)))
+ return -EFAULT;
+
+ if (strncmp(cmd, "clear", 5))
+ return count;
+
+ call_on_cpu(wait->cpu, salinfo_log_clear_cpu, wait);
+ return count;
+}
+
+static unsigned int
+salinfo_log_poll(struct file *file, poll_table *polltab)
+{
+ struct inode *inode = file->f_dentry->d_inode;
+ struct proc_dir_entry *entry = (struct proc_dir_entry *) inode->u.generic_ip;
+ struct salinfo_wait_queue *wait = entry->data;
+ unsigned int mask;
+
+ poll_wait(file, &wait->queue, polltab);
+ mask = POLLOUT | POLLWRNORM;
+ if (wait->event_ready)
+ mask |= POLLIN | POLLRDNORM;
+ return mask;
+}
+
+static struct file_operations salinfo_log_fops = {
+ .open = salinfo_log_open,
+ .read = salinfo_log_read,
+ .write = salinfo_log_write,
+ .poll = salinfo_log_poll,
+};

static int __init
salinfo_init(void)
{
struct proc_dir_entry *salinfo_dir; /* /proc/sal dir entry */
struct proc_dir_entry **sdir = salinfo_proc_entries; /* keeps track of every entry */
- int i;
+ struct proc_dir_entry *cpu_dir, *entry;
+ struct salinfo_wait_queue *wait;
+#define CPUSTR "cpu%d"
+ char name[sizeof(CPUSTR)];
+ int i, j;

salinfo_dir = proc_mkdir("sal", NULL);
+ if (!salinfo_dir)
+ return 0;

for (i=0; i < NR_SALINFO_ENTRIES; i++) {
/* pass the feature bit in question as misc data */
*sdir++ = create_proc_read_entry (salinfo_entries[i].name, 0, salinfo_dir,
salinfo_read, (void *)salinfo_entries[i].feature);
}
+
+ for (i = 0; i < NR_CPUS; i++) {
+ if (!cpu_online(i))
+ continue;
+
+ sprintf(name, CPUSTR, i);
+ cpu_dir = proc_mkdir(name, salinfo_dir);
+ if (!cpu_dir)
+ continue;
+
+ for (j = 0; j < ARRAY_SIZE(salinfo_log_name); j++) {
+ wait = kmalloc(sizeof(*wait), GFP_KERNEL);
+ if (!wait)
+ continue;
+
+ entry = create_proc_entry(salinfo_log_name[j], 0, cpu_dir);
+ if (entry) {
+ wait->cpu = i;
+ wait->type = j;
+ wait->event_ready = 1; /* assume we missed one */
+ init_waitqueue_head(&wait->queue);
+ salinfo_wait[i][j] = wait;
+ entry->data = wait;
+ entry->proc_fops = &salinfo_log_fops;
+ *sdir++ = entry;
+ }
+ }
+ *sdir++ = cpu_dir;
+ }
+
*sdir++ = salinfo_dir;

return 0;
@@ -69,7 +285,7 @@
{
int i = 0;

- for (i = 0; i < NR_SALINFO_ENTRIES ; i++) {
+ for (i = 0; i < ARRAY_SIZE(salinfo_proc_entries); i++) {
if (salinfo_proc_entries[i])
remove_proc_entry (salinfo_proc_entries[i]->name, NULL);
}

[-- Attachment #2: salinfo-0.1.tar.gz --]
[-- Type: application/x-tgz, Size: 33333 bytes --]