formal-model/urcu-controldataflow-alpha-ipi-progress-minimal/urcu_progress_writer.log

   1 make[1]: Entering directory `/home/compudj/doc/userspace-rcu/formal-model/urcu-controldataflow-min-progress'
   2 rm -f pan* trail.out .input.spin* *.spin.trail .input.define
   3 touch .input.define
   4 cat .input.define > pan.ltl
   5 cat DEFINES >> pan.ltl
   6 spin -f "!(`cat urcu_progress.ltl | grep -v ^//`)" >> pan.ltl
   7 cp urcu_progress_writer.define .input.define
   8 cat .input.define > .input.spin
   9 cat DEFINES >> .input.spin
  10 cat urcu.spin >> .input.spin
  11 rm -f .input.spin.trail
  12 spin -a -X -N pan.ltl .input.spin
  13 Exit-Status 0
  14 gcc -O2 -w -DHASH64 -DCOLLAPSE -o pan pan.c
  15 ./pan -a -f -v -c1 -X -m10000000 -w20
  16 warning: for p.o. reduction to be valid the never claim must be stutter-invariant
  17 (never claims generated from LTL formulae are stutter-invariant)
  18 depth 0: Claim reached state 5 (line 1179)
  19 depth 7: Claim reached state 9 (line 1184)
  20 depth 46: Claim reached state 9 (line 1183)
  21 Depth=    3817 States=    1e+06 Transitions= 2.94e+08 Memory=   492.912 t=    480 R=   2e+03
  22 Depth=    3900 States=    2e+06 Transitions= 6.63e+08 Memory=   519.572 t= 1.09e+03 R=   2e+03
  23 Depth=    3900 States=    3e+06 Transitions= 1.33e+09 Memory=   543.986 t= 2.23e+03 R=   1e+03
  24 pan: resizing hashtable to -w22..  done
  25 Depth=    3900 States=    4e+06 Transitions= 1.71e+09 Memory=   601.279 t= 2.86e+03 R=   1e+03
  26 Depth=    3900 States=    5e+06 Transitions= 2.06e+09 Memory=   627.647 t= 3.45e+03 R=   1e+03
  27 Depth=    3900 States=    6e+06 Transitions= 2.49e+09 Memory=   653.818 t= 4.18e+03 R=   1e+03
  28 Depth=    3900 States=    7e+06 Transitions= 3.14e+09 Memory=   678.135 t= 5.28e+03 R=   1e+03
  29 Depth=    3900 States=    8e+06 Transitions= 3.52e+09 Memory=   704.404 t= 5.93e+03 R=   1e+03
  30 Depth=    3900 States=    9e+06 Transitions= 3.88e+09 Memory=   730.869 t= 6.53e+03 R=   1e+03
  31 pan: resizing hashtable to -w24..  done
  32 Depth=    3900 States=    1e+07 Transitions= 4.34e+09 Memory=   880.451 t= 7.29e+03 R=   1e+03
  33
  34 (Spin Version 5.1.7 -- 23 December 2008)
  35         + Partial Order Reduction
  36         + Compression
  37
  38 Full statespace search for:
  39         never claim             +
  40         assertion violations    + (if within scope of claim)
  41         acceptance   cycles     + (fairness enabled)
  42         invalid end states      - (disabled by never claim)
  43
  44 State-vector 80 byte, depth reached 3900, errors: 0
  45   5638524 states, stored (1.00251e+07 visited)
  46 4.3347674e+09 states, matched
  47 4.3447924e+09 transitions (= visited+matched)
  48 2.5387604e+10 atomic steps
  49 hash conflicts: 1.1627355e+09 (resolved)
  50
  51 Stats on memory usage (in Megabytes):
  52   623.769       equivalent memory usage for states (stored*(State-vector + overhead))
  53   295.411       actual memory usage for states (compression: 47.36%)
  54                 state-vector as stored = 19 byte + 36 byte overhead
  55   128.000       memory used for hash table (-w24)
  56   457.764       memory used for DFS stack (-m10000000)
  57   881.037       total actual memory usage
  58
  59 nr of templates: [ globals chans procs ]
  60 collapse counts: [ 26786 2128 1995 2 2 ]
  61 unreached in proctype urcu_reader
  62         line 268, "pan.___", state 55, "cache_dirty_urcu_gp_ctr = 0"
  63         line 276, "pan.___", state 77, "cache_dirty_rcu_ptr = 0"
  64         line 280, "pan.___", state 86, "cache_dirty_rcu_data[i] = 0"
  65         line 245, "pan.___", state 102, "(1)"
  66         line 249, "pan.___", state 110, "(1)"
  67         line 253, "pan.___", state 122, "(1)"
  68         line 257, "pan.___", state 130, "(1)"
  69         line 404, "pan.___", state 156, "cache_dirty_urcu_gp_ctr = 0"
  70         line 413, "pan.___", state 188, "cache_dirty_rcu_ptr = 0"
  71         line 417, "pan.___", state 202, "cache_dirty_rcu_data[i] = 0"
  72         line 422, "pan.___", state 221, "(1)"
  73         line 431, "pan.___", state 251, "(1)"
  74         line 435, "pan.___", state 264, "(1)"
  75         line 614, "pan.___", state 285, "_proc_urcu_reader = (_proc_urcu_reader|((1<<2)<<1))"
  76         line 404, "pan.___", state 292, "cache_dirty_urcu_gp_ctr = 0"
  77         line 413, "pan.___", state 324, "cache_dirty_rcu_ptr = 0"
  78         line 417, "pan.___", state 338, "cache_dirty_rcu_data[i] = 0"
  79         line 422, "pan.___", state 357, "(1)"
  80         line 431, "pan.___", state 387, "(1)"
  81         line 435, "pan.___", state 400, "(1)"
  82         line 404, "pan.___", state 421, "cache_dirty_urcu_gp_ctr = 0"
  83         line 413, "pan.___", state 453, "cache_dirty_rcu_ptr = 0"
  84         line 417, "pan.___", state 467, "cache_dirty_rcu_data[i] = 0"
  85         line 422, "pan.___", state 486, "(1)"
  86         line 431, "pan.___", state 516, "(1)"
  87         line 435, "pan.___", state 529, "(1)"
  88         line 404, "pan.___", state 552, "cache_dirty_urcu_gp_ctr = 0"
  89         line 404, "pan.___", state 554, "(1)"
  90         line 404, "pan.___", state 555, "(cache_dirty_urcu_gp_ctr)"
  91         line 404, "pan.___", state 555, "else"
  92         line 404, "pan.___", state 558, "(1)"
  93         line 408, "pan.___", state 566, "cache_dirty_urcu_active_readers = 0"
  94         line 408, "pan.___", state 568, "(1)"
  95         line 408, "pan.___", state 569, "(cache_dirty_urcu_active_readers)"
  96         line 408, "pan.___", state 569, "else"
  97         line 408, "pan.___", state 572, "(1)"
  98         line 408, "pan.___", state 573, "(1)"
  99         line 408, "pan.___", state 573, "(1)"
 100         line 406, "pan.___", state 578, "((i<1))"
 101         line 406, "pan.___", state 578, "((i>=1))"
 102         line 413, "pan.___", state 584, "cache_dirty_rcu_ptr = 0"
 103         line 413, "pan.___", state 586, "(1)"
 104         line 413, "pan.___", state 587, "(cache_dirty_rcu_ptr)"
 105         line 413, "pan.___", state 587, "else"
 106         line 413, "pan.___", state 590, "(1)"
 107         line 413, "pan.___", state 591, "(1)"
 108         line 413, "pan.___", state 591, "(1)"
 109         line 417, "pan.___", state 598, "cache_dirty_rcu_data[i] = 0"
 110         line 417, "pan.___", state 600, "(1)"
 111         line 417, "pan.___", state 601, "(cache_dirty_rcu_data[i])"
 112         line 417, "pan.___", state 601, "else"
 113         line 417, "pan.___", state 604, "(1)"
 114         line 417, "pan.___", state 605, "(1)"
 115         line 417, "pan.___", state 605, "(1)"
 116         line 415, "pan.___", state 610, "((i<2))"
 117         line 415, "pan.___", state 610, "((i>=2))"
 118         line 422, "pan.___", state 617, "(1)"
 119         line 422, "pan.___", state 618, "(!(cache_dirty_urcu_gp_ctr))"
 120         line 422, "pan.___", state 618, "else"
 121         line 422, "pan.___", state 621, "(1)"
 122         line 422, "pan.___", state 622, "(1)"
 123         line 422, "pan.___", state 622, "(1)"
 124         line 426, "pan.___", state 630, "(1)"
 125         line 426, "pan.___", state 631, "(!(cache_dirty_urcu_active_readers))"
 126         line 426, "pan.___", state 631, "else"
 127         line 426, "pan.___", state 634, "(1)"
 128         line 426, "pan.___", state 635, "(1)"
 129         line 426, "pan.___", state 635, "(1)"
 130         line 424, "pan.___", state 640, "((i<1))"
 131         line 424, "pan.___", state 640, "((i>=1))"
 132         line 431, "pan.___", state 647, "(1)"
 133         line 431, "pan.___", state 648, "(!(cache_dirty_rcu_ptr))"
 134         line 431, "pan.___", state 648, "else"
 135         line 431, "pan.___", state 651, "(1)"
 136         line 431, "pan.___", state 652, "(1)"
 137         line 431, "pan.___", state 652, "(1)"
 138         line 435, "pan.___", state 660, "(1)"
 139         line 435, "pan.___", state 661, "(!(cache_dirty_rcu_data[i]))"
 140         line 435, "pan.___", state 661, "else"
 141         line 435, "pan.___", state 664, "(1)"
 142         line 435, "pan.___", state 665, "(1)"
 143         line 435, "pan.___", state 665, "(1)"
 144         line 433, "pan.___", state 670, "((i<2))"
 145         line 433, "pan.___", state 670, "((i>=2))"
 146         line 443, "pan.___", state 674, "(1)"
 147         line 443, "pan.___", state 674, "(1)"
 148         line 614, "pan.___", state 677, "cached_urcu_active_readers = (tmp+1)"
 149         line 614, "pan.___", state 678, "_proc_urcu_reader = (_proc_urcu_reader|(1<<5))"
 150         line 614, "pan.___", state 679, "(1)"
 151         line 404, "pan.___", state 686, "cache_dirty_urcu_gp_ctr = 0"
 152         line 413, "pan.___", state 718, "cache_dirty_rcu_ptr = 0"
 153         line 417, "pan.___", state 732, "cache_dirty_rcu_data[i] = 0"
 154         line 422, "pan.___", state 751, "(1)"
 155         line 431, "pan.___", state 781, "(1)"
 156         line 435, "pan.___", state 794, "(1)"
 157         line 404, "pan.___", state 821, "cache_dirty_urcu_gp_ctr = 0"
 158         line 413, "pan.___", state 853, "cache_dirty_rcu_ptr = 0"
 159         line 417, "pan.___", state 867, "cache_dirty_rcu_data[i] = 0"
 160         line 422, "pan.___", state 886, "(1)"
 161         line 431, "pan.___", state 916, "(1)"
 162         line 435, "pan.___", state 929, "(1)"
 163         line 404, "pan.___", state 950, "cache_dirty_urcu_gp_ctr = 0"
 164         line 413, "pan.___", state 982, "cache_dirty_rcu_ptr = 0"
 165         line 417, "pan.___", state 996, "cache_dirty_rcu_data[i] = 0"
 166         line 422, "pan.___", state 1015, "(1)"
 167         line 431, "pan.___", state 1045, "(1)"
 168         line 435, "pan.___", state 1058, "(1)"
 169         line 245, "pan.___", state 1091, "(1)"
 170         line 253, "pan.___", state 1111, "(1)"
 171         line 257, "pan.___", state 1119, "(1)"
 172         line 748, "pan.___", state 1136, "-end-"
 173         (91 of 1136 states)
 174 unreached in proctype urcu_writer
 175         line 404, "pan.___", state 45, "cache_dirty_urcu_gp_ctr = 0"
 176         line 408, "pan.___", state 59, "cache_dirty_urcu_active_readers = 0"
 177         line 413, "pan.___", state 77, "cache_dirty_rcu_ptr = 0"
 178         line 422, "pan.___", state 110, "(1)"
 179         line 426, "pan.___", state 123, "(1)"
 180         line 431, "pan.___", state 140, "(1)"
 181         line 268, "pan.___", state 176, "cache_dirty_urcu_gp_ctr = 0"
 182         line 272, "pan.___", state 185, "cache_dirty_urcu_active_readers = 0"
 183         line 276, "pan.___", state 198, "cache_dirty_rcu_ptr = 0"
 184         line 404, "pan.___", state 238, "cache_dirty_urcu_gp_ctr = 0"
 185         line 408, "pan.___", state 252, "cache_dirty_urcu_active_readers = 0"
 186         line 413, "pan.___", state 270, "cache_dirty_rcu_ptr = 0"
 187         line 417, "pan.___", state 284, "cache_dirty_rcu_data[i] = 0"
 188         line 422, "pan.___", state 303, "(1)"
 189         line 426, "pan.___", state 316, "(1)"
 190         line 431, "pan.___", state 333, "(1)"
 191         line 435, "pan.___", state 346, "(1)"
 192         line 408, "pan.___", state 383, "cache_dirty_urcu_active_readers = 0"
 193         line 413, "pan.___", state 401, "cache_dirty_rcu_ptr = 0"
 194         line 417, "pan.___", state 415, "cache_dirty_rcu_data[i] = 0"
 195         line 426, "pan.___", state 447, "(1)"
 196         line 431, "pan.___", state 464, "(1)"
 197         line 435, "pan.___", state 477, "(1)"
 198         line 408, "pan.___", state 522, "cache_dirty_urcu_active_readers = 0"
 199         line 413, "pan.___", state 540, "cache_dirty_rcu_ptr = 0"
 200         line 417, "pan.___", state 554, "cache_dirty_rcu_data[i] = 0"
 201         line 426, "pan.___", state 586, "(1)"
 202         line 431, "pan.___", state 603, "(1)"
 203         line 435, "pan.___", state 616, "(1)"
 204         line 408, "pan.___", state 651, "cache_dirty_urcu_active_readers = 0"
 205         line 413, "pan.___", state 669, "cache_dirty_rcu_ptr = 0"
 206         line 417, "pan.___", state 683, "cache_dirty_rcu_data[i] = 0"
 207         line 426, "pan.___", state 715, "(1)"
 208         line 431, "pan.___", state 732, "(1)"
 209         line 435, "pan.___", state 745, "(1)"
 210         line 408, "pan.___", state 782, "cache_dirty_urcu_active_readers = 0"
 211         line 413, "pan.___", state 800, "cache_dirty_rcu_ptr = 0"
 212         line 417, "pan.___", state 814, "cache_dirty_rcu_data[i] = 0"
 213         line 426, "pan.___", state 846, "(1)"
 214         line 431, "pan.___", state 863, "(1)"
 215         line 435, "pan.___", state 876, "(1)"
 216         line 268, "pan.___", state 931, "cache_dirty_urcu_gp_ctr = 0"
 217         line 272, "pan.___", state 940, "cache_dirty_urcu_active_readers = 0"
 218         line 276, "pan.___", state 955, "(1)"
 219         line 280, "pan.___", state 962, "cache_dirty_rcu_data[i] = 0"
 220         line 245, "pan.___", state 978, "(1)"
 221         line 249, "pan.___", state 986, "(1)"
 222         line 253, "pan.___", state 998, "(1)"
 223         line 257, "pan.___", state 1006, "(1)"
 224         line 268, "pan.___", state 1037, "cache_dirty_urcu_gp_ctr = 0"
 225         line 272, "pan.___", state 1046, "cache_dirty_urcu_active_readers = 0"
 226         line 276, "pan.___", state 1059, "cache_dirty_rcu_ptr = 0"
 227         line 280, "pan.___", state 1068, "cache_dirty_rcu_data[i] = 0"
 228         line 245, "pan.___", state 1084, "(1)"
 229         line 249, "pan.___", state 1092, "(1)"
 230         line 253, "pan.___", state 1104, "(1)"
 231         line 257, "pan.___", state 1112, "(1)"
 232         line 272, "pan.___", state 1138, "cache_dirty_urcu_active_readers = 0"
 233         line 276, "pan.___", state 1151, "cache_dirty_rcu_ptr = 0"
 234         line 280, "pan.___", state 1160, "cache_dirty_rcu_data[i] = 0"
 235         line 245, "pan.___", state 1176, "(1)"
 236         line 249, "pan.___", state 1184, "(1)"
 237         line 253, "pan.___", state 1196, "(1)"
 238         line 257, "pan.___", state 1204, "(1)"
 239         line 268, "pan.___", state 1235, "cache_dirty_urcu_gp_ctr = 0"
 240         line 272, "pan.___", state 1244, "cache_dirty_urcu_active_readers = 0"
 241         line 276, "pan.___", state 1257, "cache_dirty_rcu_ptr = 0"
 242         line 280, "pan.___", state 1266, "cache_dirty_rcu_data[i] = 0"
 243         line 245, "pan.___", state 1282, "(1)"
 244         line 249, "pan.___", state 1290, "(1)"
 245         line 253, "pan.___", state 1302, "(1)"
 246         line 257, "pan.___", state 1310, "(1)"
 247         line 272, "pan.___", state 1336, "cache_dirty_urcu_active_readers = 0"
 248         line 276, "pan.___", state 1349, "cache_dirty_rcu_ptr = 0"
 249         line 280, "pan.___", state 1358, "cache_dirty_rcu_data[i] = 0"
 250         line 245, "pan.___", state 1374, "(1)"
 251         line 249, "pan.___", state 1382, "(1)"
 252         line 253, "pan.___", state 1394, "(1)"
 253         line 257, "pan.___", state 1402, "(1)"
 254         line 268, "pan.___", state 1433, "cache_dirty_urcu_gp_ctr = 0"
 255         line 272, "pan.___", state 1442, "cache_dirty_urcu_active_readers = 0"
 256         line 276, "pan.___", state 1455, "cache_dirty_rcu_ptr = 0"
 257         line 280, "pan.___", state 1464, "cache_dirty_rcu_data[i] = 0"
 258         line 245, "pan.___", state 1480, "(1)"
 259         line 249, "pan.___", state 1488, "(1)"
 260         line 253, "pan.___", state 1500, "(1)"
 261         line 257, "pan.___", state 1508, "(1)"
 262         line 272, "pan.___", state 1534, "cache_dirty_urcu_active_readers = 0"
 263         line 276, "pan.___", state 1547, "cache_dirty_rcu_ptr = 0"
 264         line 280, "pan.___", state 1556, "cache_dirty_rcu_data[i] = 0"
 265         line 245, "pan.___", state 1572, "(1)"
 266         line 249, "pan.___", state 1580, "(1)"
 267         line 253, "pan.___", state 1592, "(1)"
 268         line 257, "pan.___", state 1600, "(1)"
 269         line 268, "pan.___", state 1631, "cache_dirty_urcu_gp_ctr = 0"
 270         line 272, "pan.___", state 1640, "cache_dirty_urcu_active_readers = 0"
 271         line 276, "pan.___", state 1653, "cache_dirty_rcu_ptr = 0"
 272         line 280, "pan.___", state 1662, "cache_dirty_rcu_data[i] = 0"
 273         line 245, "pan.___", state 1678, "(1)"
 274         line 249, "pan.___", state 1686, "(1)"
 275         line 253, "pan.___", state 1698, "(1)"
 276         line 257, "pan.___", state 1706, "(1)"
 277         line 1123, "pan.___", state 1722, "-end-"
 278         (103 of 1722 states)
 279 unreached in proctype :init:
 280         (0 of 26 states)
 281 unreached in proctype :never:
 282         line 1186, "pan.___", state 11, "-end-"
 283         (1 of 11 states)
 284
 285 pan: elapsed time 7.3e+03 seconds
 286 pan: rate 1373.8126 states/second
 287 pan: avg transition delay 1.6795e-06 usec
 288 cp .input.spin urcu_progress_writer.spin.input
 289 cp .input.spin.trail urcu_progress_writer.spin.input.trail
 290 make[1]: Leaving directory `/home/compudj/doc/userspace-rcu/formal-model/urcu-controldataflow-min-progress'