runsolver Copyright (C) 2010 Olivier ROUSSEL This is runsolver version 3.2.9a (svn: 651) This program is distributed in the hope that it will be useful, but WITHOUT ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU General Public License for more details. command line: /home/misc2010/bin/runsolver -s SIGUSR1 -M 1124 -C 290 -d 10 -w /home/misc2010/tmp/201108251442/packup2mp4pa-0.6/rand797.cudf.s-e-l.log.runsolver ./packup2mp4pa-0.6 /home/misc2010/data/2011/incremental/s-e-l/rand797.cudf /home/misc2010/tmp/201108251442/packup2mp4pa-0.6/rand797.cudf.s-e-l.result Enforcing CPUTime limit (soft limit, will send signal-name then SIGKILL): 290 seconds Enforcing CPUTime limit (hard limit, will send SIGXCPU): 320 seconds Enforcing VSIZE limit (soft limit, will send signal-name then SIGKILL): 1150976 KiB Enforcing VSIZE limit (hard limit, stack expansion will fail with SIGSEGV, brk() and mmap() will return ENOMEM): 1202176 KiB Current StackSize limit: 8192 KiB [startup+0 s] /proc/loadavg: 1.37 1.28 1.11 5/34 18652 /proc/meminfo: memFree=328904/1048576 swapFree=0/0 [pid=18651] ppid=18650 vsize=2576 CPUtime=0 /proc/18651/stat : 18651 (packup2mp4pa-0.) S 18650 18651 4778 34817 4778 4202496 380 0 0 0 0 0 0 0 18 0 1 0 11104393 2637824 275 1283457024 134512640 135304128 4290135440 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/18651/statm: 644 275 233 194 0 31 0 [pid=18652] ppid=18651 vsize=4108 CPUtime=0.01 /proc/18652/stat : 18652 (packup) R 18651 18651 4778 34817 4778 4202496 525 0 0 0 0 1 0 0 25 0 1 0 11104393 4206592 453 1283457024 134512640 134752139 4286818864 18446744073709551615 4157214458 0 0 18944 8192 0 0 0 17 0 0 0 0 /proc/18652/statm: 1027 453 286 59 0 191 0 [startup+0.20334 s] /proc/loadavg: 1.37 1.28 1.11 5/34 18652 /proc/meminfo: memFree=328904/1048576 swapFree=0/0 [pid=18651] ppid=18650 vsize=2576 CPUtime=0 /proc/18651/stat : 18651 (packup2mp4pa-0.) S 18650 18651 4778 34817 4778 4202496 380 0 0 0 0 0 0 0 18 0 1 0 11104393 2637824 275 1283457024 134512640 135304128 4290135440 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/18651/statm: 644 275 233 194 0 31 0 [pid=18652] ppid=18651 vsize=11104 CPUtime=0.2 /proc/18652/stat : 18652 (packup) R 18651 18651 4778 34817 4778 4202496 2280 0 0 0 18 2 0 0 25 0 1 0 11104393 11370496 2208 1283457024 134512640 134752139 4286818864 18446744073709551615 4157371107 0 0 18944 8192 0 0 0 17 0 0 0 0 /proc/18652/statm: 2776 2208 286 59 0 1940 0 Current children cumulated CPU time (s) 0.2 Current children cumulated vsize (KiB) 13680 [startup+0.313357 s] /proc/loadavg: 1.37 1.28 1.11 5/34 18652 /proc/meminfo: memFree=328904/1048576 swapFree=0/0 [pid=18651] ppid=18650 vsize=2576 CPUtime=0 /proc/18651/stat : 18651 (packup2mp4pa-0.) S 18650 18651 4778 34817 4778 4202496 380 0 0 0 0 0 0 0 18 0 1 0 11104393 2637824 275 1283457024 134512640 135304128 4290135440 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/18651/statm: 644 275 233 194 0 31 0 [pid=18652] ppid=18651 vsize=14668 CPUtime=0.31 /proc/18652/stat : 18652 (packup) R 18651 18651 4778 34817 4778 4202496 3147 0 0 0 29 2 0 0 25 0 1 0 11104393 15020032 3075 1283457024 134512640 134752139 4286818864 18446744073709551615 4157377469 0 0 18944 8192 0 0 0 17 0 0 0 0 /proc/18652/statm: 3667 3075 286 59 0 2831 0 Current children cumulated CPU time (s) 0.31 Current children cumulated vsize (KiB) 17244 [startup+0.403383 s] /proc/loadavg: 1.37 1.28 1.11 5/34 18652 /proc/meminfo: memFree=328904/1048576 swapFree=0/0 [pid=18651] ppid=18650 vsize=2576 CPUtime=0 /proc/18651/stat : 18651 (packup2mp4pa-0.) S 18650 18651 4778 34817 4778 4202496 380 0 0 0 0 0 0 0 18 0 1 0 11104393 2637824 275 1283457024 134512640 135304128 4290135440 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/18651/statm: 644 275 233 194 0 31 0 [pid=18652] ppid=18651 vsize=17176 CPUtime=0.4 /proc/18652/stat : 18652 (packup) R 18651 18651 4778 34817 4778 4202496 3790 0 0 0 38 2 0 0 25 0 1 0 11104393 17588224 3718 1283457024 134512640 134752139 4286818864 18446744073709551615 134681682 0 0 18944 8192 0 0 0 17 0 0 0 0 /proc/18652/statm: 4294 3718 286 59 0 3458 0 Current children cumulated CPU time (s) 0.4 Current children cumulated vsize (KiB) 19752 [startup+0.713475 s] /proc/loadavg: 1.37 1.28 1.11 5/34 18652 /proc/meminfo: memFree=328904/1048576 swapFree=0/0 [pid=18651] ppid=18650 vsize=2576 CPUtime=0 /proc/18651/stat : 18651 (packup2mp4pa-0.) S 18650 18651 4778 34817 4778 4202496 380 0 0 0 0 0 0 0 18 0 1 0 11104393 2637824 275 1283457024 134512640 135304128 4290135440 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/18651/statm: 644 275 233 194 0 31 0 [pid=18652] ppid=18651 vsize=25424 CPUtime=0.71 /proc/18652/stat : 18652 (packup) R 18651 18651 4778 34817 4778 4202496 5851 0 0 0 68 3 0 0 25 0 1 0 11104393 26034176 5779 1283457024 134512640 134752139 4286818864 18446744073709551615 4157396370 0 0 18944 8192 0 0 0 17 0 0 0 0 /proc/18652/statm: 6356 5779 286 59 0 5520 0 Current children cumulated CPU time (s) 0.71 Current children cumulated vsize (KiB) 28000 [startup+1.51373 s] /proc/loadavg: 1.37 1.28 1.11 2/35 18654 /proc/meminfo: memFree=292596/1048576 swapFree=0/0 [pid=18651] ppid=18650 vsize=2576 CPUtime=0 /proc/18651/stat : 18651 (packup2mp4pa-0.) S 18650 18651 4778 34817 4778 4202496 380 0 0 0 0 0 0 0 18 0 1 0 11104393 2637824 275 1283457024 134512640 135304128 4290135440 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/18651/statm: 644 275 233 194 0 31 0 [pid=18652] ppid=18651 vsize=39304 CPUtime=1.21 /proc/18652/stat : 18652 (packup) S 18651 18651 4778 34817 4778 4202496 9442 0 0 0 101 20 0 0 25 0 1 0 11104393 40247296 9126 1283457024 134512640 134752139 4286818864 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0 /proc/18652/statm: 9826 9126 324 59 0 8990 0 Current children cumulated CPU time (s) 1.21 Current children cumulated vsize (KiB) 41880 [startup+3.10413 s] /proc/loadavg: 1.37 1.28 1.11 2/37 18655 /proc/meminfo: memFree=270632/1048576 swapFree=0/0 [pid=18651] ppid=18650 vsize=2576 CPUtime=0 /proc/18651/stat : 18651 (packup2mp4pa-0.) S 18650 18651 4778 34817 4778 4202496 380 0 0 0 0 0 0 0 18 0 1 0 11104393 2637824 275 1283457024 134512640 135304128 4290135440 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/18651/statm: 644 275 233 194 0 31 0 [pid=18652] ppid=18651 vsize=39308 CPUtime=2.57 /proc/18652/stat : 18652 (packup) S 18651 18651 4778 34817 4778 4202496 9498 7588 0 0 110 32 104 11 18 0 1 0 11104393 40251392 9135 1283457024 134512640 134752139 4286818864 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0 /proc/18652/statm: 9827 9135 332 59 0 8991 0 Current children cumulated CPU time (s) 2.57 Current children cumulated vsize (KiB) 41884 [startup+6.30533 s] /proc/loadavg: 1.34 1.27 1.11 2/37 18657 /proc/meminfo: memFree=220172/1048576 swapFree=0/0 [pid=18651] ppid=18650 vsize=2576 CPUtime=0 /proc/18651/stat : 18651 (packup2mp4pa-0.) S 18650 18651 4778 34817 4778 4202496 380 0 0 0 0 0 0 0 18 0 1 0 11104393 2637824 275 1283457024 134512640 135304128 4290135440 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/18651/statm: 644 275 233 194 0 31 0 [pid=18652] ppid=18651 vsize=39308 CPUtime=2.57 /proc/18652/stat : 18652 (packup) S 18651 18651 4778 34817 4778 4202496 9498 7588 0 0 110 32 104 11 18 0 1 0 11104393 40251392 9135 1283457024 134512640 134752139 4286818864 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0 /proc/18652/statm: 9827 9135 332 59 0 8991 0 [pid=18656] ppid=18652 vsize=1668 CPUtime=0 /proc/18656/stat : 18656 (sh) S 18652 18651 4778 34817 4778 4202496 145 0 0 0 0 0 0 0 18 0 1 0 11104651 1708032 123 1283457024 134512640 134593992 4289760688 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0 /proc/18656/statm: 417 123 108 20 0 44 0 [pid=18657] ppid=18656 vsize=112896 CPUtime=3.72 /proc/18657/stat : 18657 (minisatp_32) R 18656 18651 4778 34817 4778 4202496 35643 0 0 0 348 24 0 0 25 0 1 0 11104652 115605504 24267 1283457024 134512640 135413687 4286984992 18446744073709551615 134686212 0 0 18944 0 0 0 0 17 0 0 0 0 /proc/18657/statm: 28224 24267 109 220 0 28002 0 Current children cumulated CPU time (s) 6.29 Current children cumulated vsize (KiB) 156448 Solver just ended. Dumping a history of the last processes samples [startup+6.50537 s] /proc/loadavg: 1.34 1.27 1.11 2/37 18657 /proc/meminfo: memFree=220172/1048576 swapFree=0/0 [pid=18651] ppid=18650 vsize=2576 CPUtime=0 /proc/18651/stat : 18651 (packup2mp4pa-0.) S 18650 18651 4778 34817 4778 4202496 380 0 0 0 0 0 0 0 18 0 1 0 11104393 2637824 275 1283457024 134512640 135304128 4290135440 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/18651/statm: 644 275 233 194 0 31 0 [pid=18652] ppid=18651 vsize=39308 CPUtime=2.57 /proc/18652/stat : 18652 (packup) S 18651 18651 4778 34817 4778 4202496 9498 7588 0 0 110 32 104 11 18 0 1 0 11104393 40251392 9135 1283457024 134512640 134752139 4286818864 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0 /proc/18652/statm: 9827 9135 332 59 0 8991 0 [pid=18656] ppid=18652 vsize=1668 CPUtime=0 /proc/18656/stat : 18656 (sh) S 18652 18651 4778 34817 4778 4202496 145 0 0 0 0 0 0 0 18 0 1 0 11104651 1708032 123 1283457024 134512640 134593992 4289760688 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0 /proc/18656/statm: 417 123 108 20 0 44 0 [pid=18657] ppid=18656 vsize=115552 CPUtime=3.91 /proc/18657/stat : 18657 (minisatp_32) R 18656 18651 4778 34817 4778 4202496 36730 0 0 0 367 24 0 0 25 0 1 0 11104652 118325248 25304 1283457024 134512640 135413687 4286984992 18446744073709551615 134706362 0 0 18944 0 0 0 0 17 0 0 0 0 /proc/18657/statm: 28888 25304 109 220 0 28666 0 Current children cumulated CPU time (s) 6.48 Current children cumulated vsize (KiB) 159104 [startup+7.30562 s] /proc/loadavg: 1.34 1.27 1.11 2/37 18657 /proc/meminfo: memFree=190412/1048576 swapFree=0/0 [pid=18651] ppid=18650 vsize=2576 CPUtime=0 /proc/18651/stat : 18651 (packup2mp4pa-0.) S 18650 18651 4778 34817 4778 4202496 380 0 0 0 0 0 0 0 18 0 1 0 11104393 2637824 275 1283457024 134512640 135304128 4290135440 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/18651/statm: 644 275 233 194 0 31 0 [pid=18652] ppid=18651 vsize=39308 CPUtime=2.57 /proc/18652/stat : 18652 (packup) S 18651 18651 4778 34817 4778 4202496 9498 7588 0 0 110 32 104 11 18 0 1 0 11104393 40251392 9135 1283457024 134512640 134752139 4286818864 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0 /proc/18652/statm: 9827 9135 332 59 0 8991 0 [pid=18656] ppid=18652 vsize=1668 CPUtime=0 /proc/18656/stat : 18656 (sh) S 18652 18651 4778 34817 4778 4202496 145 0 0 0 0 0 0 0 18 0 1 0 11104651 1708032 123 1283457024 134512640 134593992 4289760688 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0 /proc/18656/statm: 417 123 108 20 0 44 0 [pid=18657] ppid=18656 vsize=112328 CPUtime=4.71 /proc/18657/stat : 18657 (minisatp_32) R 18656 18651 4778 34817 4778 4202496 38630 0 0 0 445 26 0 0 25 0 1 0 11104652 115023872 24684 1283457024 134512640 135413687 4286984992 18446744073709551615 134649456 0 0 18944 0 0 0 0 17 0 0 0 0 /proc/18657/statm: 28082 24684 110 220 0 27860 0 Current children cumulated CPU time (s) 7.28 Current children cumulated vsize (KiB) 155880 [startup+7.70577 s] /proc/loadavg: 1.34 1.27 1.11 2/37 18657 /proc/meminfo: memFree=190412/1048576 swapFree=0/0 [pid=18651] ppid=18650 vsize=2576 CPUtime=0 /proc/18651/stat : 18651 (packup2mp4pa-0.) S 18650 18651 4778 34817 4778 4202496 380 0 0 0 0 0 0 0 18 0 1 0 11104393 2637824 275 1283457024 134512640 135304128 4290135440 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/18651/statm: 644 275 233 194 0 31 0 [pid=18652] ppid=18651 vsize=39308 CPUtime=2.57 /proc/18652/stat : 18652 (packup) S 18651 18651 4778 34817 4778 4202496 9498 7588 0 0 110 32 104 11 18 0 1 0 11104393 40251392 9135 1283457024 134512640 134752139 4286818864 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0 /proc/18652/statm: 9827 9135 332 59 0 8991 0 [pid=18656] ppid=18652 vsize=1668 CPUtime=0 /proc/18656/stat : 18656 (sh) S 18652 18651 4778 34817 4778 4202496 145 0 0 0 0 0 0 0 18 0 1 0 11104651 1708032 123 1283457024 134512640 134593992 4289760688 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0 /proc/18656/statm: 417 123 108 20 0 44 0 [pid=18657] ppid=18656 vsize=112328 CPUtime=5.11 /proc/18657/stat : 18657 (minisatp_32) R 18656 18651 4778 34817 4778 4202496 38638 0 0 0 484 27 0 0 25 0 1 0 11104652 115023872 24692 1283457024 134512640 135413687 4286984992 18446744073709551615 134649535 0 0 18944 0 0 0 0 17 0 0 0 0 /proc/18657/statm: 28082 24692 110 220 0 27860 0 Current children cumulated CPU time (s) 7.68 Current children cumulated vsize (KiB) 155880 [startup+7.90584 s] /proc/loadavg: 1.34 1.27 1.11 2/37 18657 /proc/meminfo: memFree=193512/1048576 swapFree=0/0 [pid=18651] ppid=18650 vsize=2576 CPUtime=0 /proc/18651/stat : 18651 (packup2mp4pa-0.) S 18650 18651 4778 34817 4778 4202496 380 0 0 0 0 0 0 0 18 0 1 0 11104393 2637824 275 1283457024 134512640 135304128 4290135440 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/18651/statm: 644 275 233 194 0 31 0 [pid=18652] ppid=18651 vsize=38536 CPUtime=7.9 /proc/18652/stat : 18652 (packup) R 18651 18651 4778 34817 4778 4202496 15975 46386 0 0 112 35 603 40 18 0 1 0 11104393 39460864 8955 1283457024 134512640 134752139 4286818864 18446744073709551615 4159160516 0 0 18944 8192 0 0 0 17 0 0 0 0 /proc/18652/statm: 9634 8955 345 59 0 8798 0 Current children cumulated CPU time (s) 7.9 Current children cumulated vsize (KiB) 41112 Child status: 0 Real time (s): 7.95698 CPU time (s): 7.9605 CPU user time (s): 7.19245 CPU system time (s): 0.768048 CPU usage (%): 100.044 Max. virtual memory (cumulated for all children) (KiB): 159728 getrusage(RUSAGE_CHILDREN,...) data: user time used= 7.19245 system time used= 0.768048 maximum resident set size= 0 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 64599 page faults= 0 swaps= 0 block input operations= 0 block output operations= 0 messages sent= 0 messages received= 0 signals received= 0 voluntary context switches= 11 involuntary context switches= 140 runsolver used 0 second user time and 0 second system time The end