// Called when: // - we are exiting an epwrapper // - the return value is successful // - symbolic kernel retvals are enabled static void verify_symretval(const char *fn, int line, unsigned long retval) { if (bad_path) { // This path was set up artificially // The kernel did something other than what the driver // thinks it did. uprintk ("At %s:%d exit point with retval %ld: this is a bad path\n", fn, line, s2e_get_example_uint (retval)); s2e_kill_state(1, 0, "Bad path returning to kernel"); return; } // This path is genuine in the sense that the kernel actually did // what the driver thinks it did. if (driver_call_stack >= 1) { // Path is genuine and there are more driver functions on call stack uprintk ("At %s:%d exit point with retval %ld: successful path but more to go ...\n", fn, line, s2e_get_example_uint (retval)); } else { // Path is genuine and there are no more driver functions on call stack uprintk ("At %s:%d exit point with retval %ld: successful path\n", fn, line, s2e_get_example_uint (retval)); //tfassert_detail (0, "Good path returning to kernel - reducing state explosion"); if (g_sym_retval == 1) { s2e_kill_state(1, 0, "Good path returning to kernel - reducing state explosion"); } else if (g_sym_retval == 2) { uprintk ("Good path completed -- deprioritizing..."); s2e_deprioritize(line); } else { tfassert_detail(0, "Expected g_sym_retval not to be %d\n", g_sym_retval); } } }
static void verify_retval (const char *fn, int line, enum symdrive_WRAPPER_TYPE wrapper_type, enum symdrive_DIRECTION dir, int retval_valid, unsigned long retval) { tfassert (wrapper_type == STUBWRAPPER || wrapper_type == PREPOSTFN); tfassert (dir == ENTRANCE || dir == EXIT); // Precondition. We're either entering or leaving the driver. tfassert (driver_call_stack == 0); if (wrapper_type == PREPOSTFN && dir == EXIT) { if (retval_valid) { if (g_symdrive_annotations == 0) { // Proceed normally } else { // Convert retval to success uprintk ("At %s:%d exit point with retval %ld: allowing our path per annotation\n", fn, line, s2e_get_example_uint (retval)); g_symdrive_annotations = 0; retval = 0; } if (IS_ERR_VALUE(retval)) { uprintk ("At %s:%d exit point with retval %ld: terminating our path\n", fn, line, s2e_get_example_uint (retval)); s2e_kill_state(0, 0, "Test complete: failure detected on this path."); } if (!IS_ERR_VALUE(retval)) { // Driver entry point completed successfully if (g_sym_retval == 0) { uprintk ("At %s:%d exit point with retval %ld: calling s2e_concretize_kill\n", fn, line, s2e_get_example_uint (retval)); s2e_concretize_kill (line); } else if (g_sym_retval == 1 || g_sym_retval == 2) { verify_symretval(fn, line, retval); } else { tfassert_detail(0, "g_sym_retval should not be %d\n", g_sym_retval); } } } else { uprintk ("At %s:%d exit point with no retval: calling s2e_concretize_kill\n", fn, line); s2e_concretize_kill (line); uprintk ("At %s:%d exit point with no retval: Killed everything\n", fn, line); } } if (wrapper_type == STUBWRAPPER && dir == ENTRANCE) { // In this case, we're entering back into the driver // from a kernel function call. // Does not matter -- kernel function was successful, or not. //s2e_prioritize(line); } }
static void handle_max_coverage (const char *fn, int line, int retval_valid, unsigned long retval, enum symdrive_WRAPPER_TYPE wrapper_type, enum symdrive_DIRECTION direction) { if (strcmp (fn, g_sym_starting_fn)) { return; } // We have a match if (direction == ENTRANCE) { uprintk ("Max coverage mode detected: %s:%d\n", fn, line); g_sym_retval = 1; s2e_kill_all_others(line); } else if (direction == EXIT) { if (retval_valid && IS_ERR_VALUE(retval)) { char temp[128]; sprintf (temp, "Terminating failed thorough coverage fn path (%s:%d)...", fn, line); s2e_kill_state(0, 0, temp); } else { // Disable favor successful and start exploring all other paths // through this function. char temp[128]; s2e_favor_successful(line, 0); sprintf (temp, "Terminating successful thorough coverage fn path (line %s/%d)...", fn, line); s2e_kill_state(0, 0, temp); } } else { tfassert_detail (0, "Failed %s: %s:%d\n", __func__, fn, line); } }
static int pci_platform_probe (struct pci_dev *pdev, const struct pci_device_id *ent) { int rc = 0; int i; struct pci_private *private; uprintk ("%s\n", __func__); // PCI platform private private = kzalloc (sizeof (struct pci_private), GFP_KERNEL);
// Return true (!= 0) if any referenced bits are set. static int ref_bits_set (int exclude_irqhandler) { void *cur_addr; pte_t *pte; int i; int ret_val = 0; for (i = 0; i < cr_num_drivers; i++) { if (exclude_irqhandler) uprintk ("i %d: ", i); for (cur_addr = cr_base_address[i]; cur_addr < cr_base_address[i] + cr_module_size[i]; cur_addr += PAGE_SIZE) { pte = virt_to_pte (cur_addr); if (pte != NULL) { // See if we're excluding the interrupt handler // from this check. if (exclude_irqhandler && addr_contains_irq_handler (cur_addr)) { pte_unmap(pte); if (exclude_irqhandler) uprintk ("X"); continue; } // See if the page was referenced lately. if (pte_young(*pte) != 0) { // kunmap_atomic (page, KM_IRQ1); pte_unmap(pte); if (exclude_irqhandler) uprintk ("1"); ret_val = 1; continue; } if (exclude_irqhandler) uprintk ("0"); // kunmap_atomic (page, KM_IRQ1); pte_unmap(pte); } } if (exclude_irqhandler) uprintk ("\n"); } return ret_val; }
int gen_make_symbolic_ptr (const char *fn, int line, void **ptr_retval) { void *orig_retval = *ptr_retval; if (g_sym_retval == 0) { return g_sym_retval; } acquire_global_lock(); s2e_make_symbolic (ptr_retval, sizeof (void *), "symbolic_retval_ptr"); if (*ptr_retval == orig_retval) { uprintk ("%s/%s: original retval: %p\n", fn, __func__, *ptr_retval); s2e_success_path(line, fn, 1); } else if (*ptr_retval == NULL && *ptr_retval != orig_retval) { uprintk ("%s/%s: NULL retval\n", fn, __func__); s2e_success_path(line, fn, -1); bad_path = 1; } else { s2e_kill_state(1, 0, "gen_make_symbolic_ptr: extra path\n"); } release_global_lock(); return g_sym_retval; }
static void manage_call_stack(const char *fn, int line, int add, enum symdrive_WRAPPER_TYPE wrapper_type) { const char *buffer1; const char *buffer2; if (add == -1 && wrapper_type == STUBWRAPPER) { buffer1 = "Exiting driver, entering kernel function: "; } else if (add == 1 && wrapper_type == STUBWRAPPER) { buffer1 = "Entering driver, exiting kernel function: "; } else if (add == -1 && wrapper_type == PREPOSTFN) { buffer1 = "Exiting driver function: "; } else if (add == 1 && wrapper_type == PREPOSTFN) { buffer1 = "Entering driver function: "; } else { buffer1 = ""; tfassert_detail (0, "Inconsistent add/wrapper_type: %d %d\n", add, wrapper_type); } tfassert_detail(driver_call_stack >= 0 && driver_call_stack < driver_call_stack_max, "driver_call_stack = %d\n", driver_call_stack); if (wrapper_type == STUBWRAPPER) { // kernel function if (add < 0) { push_driver_call_stack(fn); } driver_call_stack -= add; if (add > 0) { pop_driver_call_stack(fn); } } else if (wrapper_type == PREPOSTFN) { // driver function if (add > 0) { push_driver_call_stack(fn); } driver_call_stack += add; if (add < 0) { pop_driver_call_stack(fn); } } else { tfassert_detail (0, "Failed in test_framework verify because wrapper_type = %d\n", wrapper_type); } tfassert_detail(driver_call_stack >= 0 && driver_call_stack < driver_call_stack_max, "driver_call_stack = %d\n", driver_call_stack); buffer2 = driver_dump_stack(0); uprintk ("%s %s. %s\n", buffer1, fn, buffer2); }
const char *driver_dump_stack(int print) { int i; assert_global_lock(); memset(call_stack_buffer1, 0, call_stack_buffer_size); memset(call_stack_buffer2, 0, call_stack_buffer_size); call_stack_buffer1[0] = 0; for (i = 0; i < driver_call_stack_max; i++) { if (driver_call_stack_str[i] != NULL) { call_stack_buffer2[0] = 0; sprintf (call_stack_buffer2, "%s:%d -> ", driver_call_stack_str[i], i); strlcat (call_stack_buffer1, call_stack_buffer2, call_stack_buffer_size); } } if (print) { uprintk ("%s", call_stack_buffer1); } return call_stack_buffer1; }
// // This function is called in the postfn_ generated function // int gen_exit_driver (const char *fn, int line, enum symdrive_WRAPPER_TYPE wrapper_type, int retval_valid, unsigned long retval, const char *interesting_fn, void (*gen_register_all_param)(void)) { //static int alternate_sym = 0; acquire_global_lock(); // Exiting driver/kernel function: s2e_exit_function(line, fn, wrapper_type); // Track performance / basic blocks // Do this before calling verify_retval // Do this before max coverage. //if (strcmp (fn, g_sym_trackperf_fn) == 0) { // s2e_disable_trackperf(__LINE__, SYMDRIVE_STOP_AUTO); //} // Starting the full-coverage mode handle_max_coverage(fn, line, retval_valid, retval, wrapper_type, EXIT); handle_interesting_function(fn, line, wrapper_type, retval_valid, retval, interesting_fn, EXIT); // If the retval is valid and not symbolic then prioritize or deprioritize. // If it is symbolic, then do nothing on the assumption that it's a hardware // value -- we should not be prioritizing hardware values. if (retval_valid) { if (s2e_is_symbolic_symdrive(line, retval) == 0) { s2e_prioritize(line); if (g_symdrive_annotations == 0) { // Proceed normally } else { // Convert retval to success uprintk ("Prioritization: allowing our path per annotation\n", fn, line, s2e_get_example_uint (retval)); g_symdrive_annotations = 0; retval = 0; } if (!IS_ERR_VALUE(retval)) { s2e_success_path(line, fn, 1); uprintk ("Prioritizing line %d, example val %lu\n", line, s2e_get_example_uint(retval)); } else { uprintk ("Deprioritizing line %d, example val %lu\n", line, s2e_get_example_uint(retval)); s2e_success_path(line, fn, -1); s2e_deprioritize(line); } } else { uprintk ("Line %d: symbolic retval, example %lu.\n", line, s2e_get_example_uint(retval)); } } // Exiting driver: verify_invariants(fn, line, -1, wrapper_type); if (driver_call_stack == 0) { verify_retval(fn, line, wrapper_type, EXIT, retval_valid, retval); reset_new_objects (fn); //if (cleanup_path == 0) { // s2e_enable_all_apic_interrupts(); //} } release_global_lock(); // Moved from generated code. // Call interrupt handlers if we're returning to the kernel. if (wrapper_type == PREPOSTFN && driver_call_stack == 0) { //s2e_disable_trackperf(__LINE__, SYMDRIVE_PAUSE_IRQ); // Pause accumulation call_interrupt_handlers(fn, line); execute_completions(fn, line); //s2e_enable_trackperf(__LINE__, SYMDRIVE_CONTINUE_IRQ); // Resume accumulation } // Not used as far as I know: return driver_call_stack; }
static void handle_interesting_function(const char *fn, int line, enum symdrive_WRAPPER_TYPE wrapper_type, int retval_valid, unsigned long retval, const char *interesting_fn, enum symdrive_DIRECTION direction) { #if 0 if (interesting_fn[0] == 0) { return; } tfassert_detail(line >= 0 && line < MAX_INTERESTING_LINES, "File too large -- interesting function at line %d\n", line); interesting_function_lines[line]++; if (interesting_function_lines[line] > MAX_INTERESTING_PER_LINE && interesting_function_started == 0) { //uprintk ("Interesting function: %s:%d. Skipping, count too high: %d\n", // fn, line, interesting_function_lines[line]); return; } if (direction == ENTRANCE) { if (wrapper_type == PREPOSTFN) { // Precondition for interesting driver fn if (interesting_function_started == 0) { interesting_function_started++; tfassert_detail (interesting_function_success >= 0, "Failed %s: %s:%d\n", __func__, fn, line); } else if (interesting_function_started >= 1) { uprintk ("Interesting function: unconditional prioritize %s:%d\n", fn, line); s2e_prioritize (0); interesting_function_started++; } else { tfassert_detail (0, "Failed %s: %s:%d\n", __func__, fn, line); } } else if (wrapper_type == STUBWRAPPER) { // Precondition for kernel function if (interesting_function_started == 0) { // // This should never happen because if it does, it means that we're calling // an interesting kernel function but we've not already started the // corresponding interesting driver function. All interesting // kernel functions that are called must have a corresponding driver // function. // tfassert_detail (0, "Bug in test framework or static analysis\n"); } else if (interesting_function_started >= 1) { if (strcmp (fn, interesting_fn) == 0) { uprintk ("Interesting function: Unconditional prioritize -- kernel fn called %s:%d\n", fn, line); interesting_function_success++; s2e_prioritize (0); } else { uprintk ("Interesting function: Not prioritizing -- kernel fn called %s:%d expecting %s\n", fn, line, interesting_fn); } } else { tfassert_detail (0, "Failed %s: %s:%d\n", __func__, fn, line); } } else { tfassert_detail (0, "Failed %s: %s:%d\n", __func__, fn, line); } } else if (direction == EXIT) { if (wrapper_type == PREPOSTFN) { // Postcondition for interesting driver fn if (interesting_function_started == 0) { tfassert_detail (0, "Failed %s: %s:%d\n", __func__, fn, line); } else if (interesting_function_started >= 1) { if (interesting_function_success == 0) { char temp[128]; sprintf (temp, "Interesting function: %s:%d failed to complete successfully.", fn, line); s2e_kill_state(1, 0, temp); } else if (interesting_function_success >= 1) { s2e_prioritize(0); interesting_function_started--; if (interesting_function_started == 0) { uprintk ("Interesting function: Complete success, success at %d. %s:%d. Prioritized\n", interesting_function_success, fn, line); interesting_function_success--; } else if (interesting_function_started >= 1) { uprintk ("Interesting function: Success. %s:%d. Prioritize\n", fn, line); } else { tfassert_detail (0, "Failed %s: %s:%d\n", __func__, fn, line); } } else { tfassert_detail (0, "Failed %s: %s:%d\n", __func__, fn, line); } } else { tfassert_detail (0, "Failed %s: %s:%d\n", __func__, fn, line); } } else if (wrapper_type == STUBWRAPPER) { // Postcondition for interesting kernel fn. // No need to do anything here -- all logic is in the precondition, above } else { tfassert_detail (0, "Failed %s: %s:%d\n", __func__, fn, line); } } else { tfassert_detail (0, "Failed %s: %s:%d\n", __func__, fn, line); } #endif }
/* http://lxr.linux.no/linux+v2.6.18.1/include/linux/page-flags.h 31 * Note that the referenced bit, the page->lru list_head and the active, 32 * inactive_dirty and inactive_clean lists are protected by the 33 * zone->lru_lock, and *NOT* by the usual PG_locked bit! */ static void crmod_check_function (void) { int irq; // Disable the device's IRQ temporarily. // We'll be calling the interrupt handler ourselves potentially. // This avoids some race conditions for (irq = 0; irq < CR_MAP_SIZE; irq++) { if (cr_irq_handlers[irq] != NULL) { // disable_irq (irq); } } down (&timer_semaphore); if (problem_pending != 0) { problem_pending--; if (atomic_read (&interrupt_handler_called) == 0) { // In this case we may have a problem. // A request was made of the driver, but the interrupt // handler has not been called. This could be one of // two things: // // - The device is malfunctioning, and not generating // interrupts. // - The driver simply did not need to invoke the device // to service the request--e.g. E1000 ethtool functions // are requests to the driver that do not result in // interrupts being generated. // // Call ALL IRQ handlers! And hope for the best. // Remember, this may take a long time! // More requests may come in while this executes. :( irqreturn_t retval; uprintk ("Problem detected...\n"); retval = call_all_interrupt_handlers (); if (retval != 0) { // Productive uprintk ("Productive interrupt resolved.\n"); if (unproductive_interrupts == 0) { crmod_timer_length /= 2; if (crmod_timer_length < 1) { crmod_timer_length = 1; } } else { unproductive_interrupts--; } } else { // Reset unproductive_interrupts++; if (unproductive_interrupts > max_unproductive_interrupts) { clear_ref_bits (); atomic_set (&interrupt_handler_called, 0); unproductive_interrupts = 0; } crmod_timer_length *= 2; if (crmod_timer_length > HZ) { crmod_timer_length = HZ; } uprintk ("Unproductive interrupt resolved\n"); } } else { // No problem since the interrupt handler is working // still. uprintk ("Situation #2\n"); // Reset clear_ref_bits (); atomic_set(&interrupt_handler_called, 0); } } else { // In this case, there is no problem pending at the moment. // Let's see if that's still the case. if (atomic_read (&interrupt_handler_called) != 0) { // Interrupt handler was called recently. if (ref_bits_set (0)) { // This happens all the time // Interrupt handler was called, no big deal. uprintk ("Situation #3\n"); } else { dump_stack(); uprintk ("interrupt_handler_called: %d\n", atomic_read (&interrupt_handler_called)); //panic ("%s how is this possible?", __FUNCTION__); } // Reset atomic_set(&interrupt_handler_called, 0); clear_ref_bits (); unproductive_interrupts = 0; crmod_timer_length = default_timer_length; } else { // Interrupt handler not called if (ref_bits_set (0)) { // We start the count down. // The interrupt handler was not called, but // referenced bits are set. problem_pending += problem_pending_inc; uprintk ("Situation #4\n"); } else { // Nothing, the driver is simply inactive. //uprintk ("#5\n"); } // Don't reset the reference bits since there'd be // a small race condition. If we reset here, // then some request might come in before this // function finishes executing, and we'd miss it. } } up (&timer_semaphore); // Reset everything. for (irq = 0; irq < CR_MAP_SIZE; irq++) { if (cr_irq_handlers[irq] != NULL) { //enable_irq (irq); } } }