model: debug print - pending release sequences
[model-checker.git] / model.cc
index 62e75205e4ee9681bcef321856c744978c9cc5c1..4d6d7634bf26c58eb83e2070b99df902c05b41ba 100644 (file)
--- a/model.cc
+++ b/model.cc
@@ -25,6 +25,7 @@ ModelChecker::ModelChecker(struct model_params params) :
        num_executions(0),
        num_feasible_executions(0),
        diverge(NULL),
+       earliest_diverge(NULL),
        action_trace(new action_list_t()),
        thread_map(new HashTable<int, Thread *, int>()),
        obj_map(new HashTable<const void *, action_list_t, uintptr_t, 4>()),
@@ -138,6 +139,9 @@ Thread * ModelChecker::get_next_thread(ModelAction *curr)
        ModelAction *next = node_stack->get_next()->get_action();
 
        if (next == diverge) {
+               if (earliest_diverge == NULL || *diverge < *earliest_diverge)
+                       earliest_diverge=diverge;
+
                Node *nextnode = next->get_node();
                /* Reached divergence point */
                if (nextnode->increment_promise()) {
@@ -157,8 +161,12 @@ Thread * ModelChecker::get_next_thread(ModelAction *curr)
                        Node *node = nextnode->get_parent();
                        tid = node->get_next_backtrack();
                        node_stack->pop_restofstack(1);
+                       if (diverge==earliest_diverge) {
+                               earliest_diverge=node->get_action();
+                       }
                }
                DEBUG("*** Divergence point ***\n");
+
                diverge = NULL;
        } else {
                tid = next->get_tid();
@@ -180,8 +188,20 @@ bool ModelChecker::next_execution()
        DBG();
 
        num_executions++;
-       if (isfinalfeasible())
+
+       if (isfinalfeasible()) {
+               printf("Earliest divergence point since last feasible execution:\n");
+               if (earliest_diverge)
+                       earliest_diverge->print(false);
+               else
+                       printf("(Not set)\n");
+
+               earliest_diverge = NULL;
                num_feasible_executions++;
+       }
+
+       DEBUG("Number of acquires waiting on pending release sequences: %lu\n",
+                       pending_acq_rel_seq->size());
 
        if (isfinalfeasible() || DBG_ENABLED())
                print_summary();
@@ -414,7 +434,7 @@ bool ModelChecker::process_mutex(ModelAction *curr) {
                action_list_t *waiters = lock_waiters_map->get_safe_ptr(curr->get_location());
                //activate all the waiting threads
                for (action_list_t::iterator rit = waiters->begin(); rit != waiters->end(); rit++) {
-                       scheduler->add_thread(get_thread((*rit)->get_tid()));
+                       scheduler->wake(get_thread(*rit));
                }
                waiters->clear();
                break;
@@ -459,11 +479,11 @@ bool ModelChecker::process_write(ModelAction *curr)
  * (e.g., ATOMIC_{READ,WRITE,RMW,LOCK}, etc.)
  *
  * @param curr The current action
- * @return True if synchronization was updated
+ * @return True if synchronization was updated or a thread completed
  */
 bool ModelChecker::process_thread_action(ModelAction *curr)
 {
-       bool synchronized = false;
+       bool updated = false;
 
        switch (curr->get_type()) {
        case THREAD_CREATE: {
@@ -480,7 +500,7 @@ bool ModelChecker::process_thread_action(ModelAction *curr)
                        scheduler->sleep(waiting);
                } else {
                        do_complete_join(curr);
-                       synchronized = true;
+                       updated = true; /* trigger rel-seq checks */
                }
                break;
        }
@@ -491,9 +511,10 @@ bool ModelChecker::process_thread_action(ModelAction *curr)
                        Thread *wake = get_thread(act);
                        scheduler->wake(wake);
                        do_complete_join(act);
-                       synchronized = true;
+                       updated = true; /* trigger rel-seq checks */
                }
                th->complete();
+               updated = true; /* trigger rel-seq checks */
                break;
        }
        case THREAD_START: {
@@ -504,7 +525,7 @@ bool ModelChecker::process_thread_action(ModelAction *curr)
                break;
        }
 
-       return synchronized;
+       return updated;
 }
 
 /**
@@ -531,6 +552,8 @@ ModelAction * ModelChecker::initialize_curr_action(ModelAction *curr)
                return newcurr;
        }
 
+       curr->set_seq_number(get_next_seq_num());
+
        newcurr = node_stack->explore_action(curr, scheduler->get_enabled());
        if (newcurr) {
                /* First restore type and order in case of RMW operation */
@@ -543,19 +566,19 @@ ModelAction * ModelChecker::initialize_curr_action(ModelAction *curr)
                /* Discard duplicate ModelAction; use action from NodeStack */
                delete curr;
 
-               /* If we have diverged, we need to reset the clock vector. */
-               if (diverge == NULL) {
-                       newcurr->create_cv(get_parent_action(newcurr->get_tid()));
-               }
+               /* Always compute new clock vector */
+               newcurr->create_cv(get_parent_action(newcurr->get_tid()));
        } else {
                newcurr = curr;
+
+               /* Always compute new clock vector */
+               newcurr->create_cv(get_parent_action(newcurr->get_tid()));
                /*
                 * Perform one-time actions when pushing new ModelAction onto
                 * NodeStack
                 */
-               curr->create_cv(get_parent_action(curr->get_tid()));
-               if (curr->is_write())
-                       compute_promises(curr);
+               if (newcurr->is_write())
+                       compute_promises(newcurr);
        }
        return newcurr;
 }
@@ -603,7 +626,7 @@ Thread * ModelChecker::check_current_action(ModelAction *curr)
                /* Make the execution look like we chose to run this action
                 * much later, when a lock is actually available to release */
                get_current_thread()->set_pending(curr);
-               remove_thread(get_current_thread());
+               scheduler->sleep(get_current_thread());
                return get_next_thread(NULL);
        }
 
@@ -658,7 +681,8 @@ Thread * ModelChecker::check_current_action(ModelAction *curr)
                        bool updated = false;
 
                        if (act->is_read()) {
-                               if (r_modification_order(act, act->get_reads_from()))
+                               const ModelAction *rf = act->get_reads_from();
+                               if (rf != NULL && r_modification_order(act, rf))
                                        updated = true;
                        }
                        if (act->is_write()) {
@@ -951,10 +975,10 @@ void ModelChecker::post_r_modification_order(ModelAction *curr, const ModelActio
                action_list_t::reverse_iterator rit;
                ModelAction *lastact = NULL;
 
-               /* Find last action that happens after curr */
+               /* Find last action that happens after curr that is either not curr or a rmw */
                for (rit = list->rbegin(); rit != list->rend(); rit++) {
                        ModelAction *act = *rit;
-                       if (curr->happens_before(act)) {
+                       if (curr->happens_before(act) && (curr != act || curr->is_rmw())) {
                                lastact = act;
                        } else
                                break;
@@ -962,12 +986,25 @@ void ModelChecker::post_r_modification_order(ModelAction *curr, const ModelActio
 
                        /* Include at most one act per-thread that "happens before" curr */
                if (lastact != NULL) {
-                       if (lastact->is_read()) {
+                       if (lastact==curr) {
+                               //Case 1: The resolved read is a RMW, and we need to make sure
+                               //that the write portion of the RMW mod order after rf
+
+                               mo_graph->addEdge(rf, lastact);
+                       } else if (lastact->is_read()) {
+                               //Case 2: The resolved read is a normal read and the next
+                               //operation is a read, and we need to make sure the value read
+                               //is mod ordered after rf
+
                                const ModelAction *postreadfrom = lastact->get_reads_from();
                                if (postreadfrom != NULL&&rf != postreadfrom)
                                        mo_graph->addEdge(rf, postreadfrom);
-                       } else if (rf != lastact) {
-                               mo_graph->addEdge(rf, lastact);
+                       } else {
+                               //Case 3: The resolved read is a normal read and the next
+                               //operation is a write, and we need to make sure that the
+                               //write is mod ordered after rf
+                               if (lastact!=rf)
+                                       mo_graph->addEdge(rf, lastact);
                        }
                        break;
                }
@@ -1291,6 +1328,8 @@ bool ModelChecker::resolve_release_sequences(void *location, work_queue_t *work_
                }
 
                if (updated) {
+                       /* Re-check all pending release sequences */
+                       work_queue->push_back(CheckRelSeqWorkEntry(NULL));
                        /* Re-check act for mo_graph edges */
                        work_queue->push_back(MOEdgeWorkEntry(act));
 
@@ -1575,6 +1614,33 @@ static void print_list(action_list_t *list)
        printf("---------------------------------------------------------------------\n");
 }
 
+#if SUPPORT_MOD_ORDER_DUMP
+void ModelChecker::dumpGraph(char *filename) {
+       char buffer[200];
+  sprintf(buffer, "%s.dot",filename);
+  FILE *file=fopen(buffer, "w");
+  fprintf(file, "digraph %s {\n",filename);
+       mo_graph->dumpNodes(file);
+       ModelAction ** thread_array=(ModelAction **)model_calloc(1, sizeof(ModelAction *)*get_num_threads());
+       
+       for (action_list_t::iterator it = action_trace->begin(); it != action_trace->end(); it++) {
+               ModelAction *action=*it;
+               if (action->is_read()) {
+                       fprintf(file, "N%u [label=\"%u, T%u\"];\n", action->get_seq_number(),action->get_seq_number(), action->get_tid());
+                       fprintf(file, "N%u -> N%u[label=\"rf\", color=red];\n", action->get_seq_number(), action->get_reads_from()->get_seq_number());
+               }
+               if (thread_array[action->get_tid()] != NULL) {
+                       fprintf(file, "N%u -> N%u[label=\"sb\", color=blue];\n", thread_array[action->get_tid()]->get_seq_number(), action->get_seq_number());
+               }
+               
+               thread_array[action->get_tid()]=action;
+       }
+  fprintf(file,"}\n");
+       model_free(thread_array);
+  fclose(file);        
+}
+#endif
+
 void ModelChecker::print_summary()
 {
        printf("\n");
@@ -1587,6 +1653,8 @@ void ModelChecker::print_summary()
        char buffername[100];
        sprintf(buffername, "exec%04u", num_executions);
        mo_graph->dumpGraphToFile(buffername);
+       sprintf(buffername, "graph%04u", num_executions);
+  dumpGraph(buffername);
 #endif
 
        if (!isfinalfeasible())