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/rand59.cudf.dudf-random.log.runsolver ./packup2mp4pa-0.6 /home/misc2010/data/2011/dudf-random//rand59.cudf /home/misc2010/tmp/201108251442/packup2mp4pa-0.6/rand59.cudf.dudf-random.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.38 1.33 1.15 5/36 19886 /proc/meminfo: memFree=290148/1048576 swapFree=0/0 [pid=19885] ppid=19884 vsize=2568 CPUtime=0 /proc/19885/stat : 19885 (packup2mp4pa-0.) R 19884 19885 4778 34817 4778 4202496 359 0 0 0 0 0 0 0 25 0 1 0 11119267 2629632 273 1283457024 134512640 135304128 4293538000 18446744073709551615 4294960130 0 65538 4 84480 0 0 0 17 0 0 0 0 /proc/19885/statm: 642 273 233 194 0 29 0 [pid=19886] ppid=19885 vsize=2568 CPUtime=0 /proc/19886/stat : 19886 (packup2mp4pa-0.) R 19885 19885 4778 34817 4778 4202560 0 0 0 0 0 0 0 0 25 0 1 0 11119267 2629632 40 1283457024 134512640 135304128 4293538000 18446744073709551615 4294960130 0 65538 4 84480 0 0 0 17 0 0 0 0 /proc/19886/statm: 642 40 0 194 0 29 0 [startup+0.115747 s] /proc/loadavg: 1.38 1.33 1.15 5/36 19886 /proc/meminfo: memFree=290148/1048576 swapFree=0/0 [pid=19885] ppid=19884 vsize=2568 CPUtime=0 /proc/19885/stat : 19885 (packup2mp4pa-0.) S 19884 19885 4778 34817 4778 4202496 377 0 0 0 0 0 0 0 25 0 1 0 11119267 2629632 273 1283457024 134512640 135304128 4293538000 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/19885/statm: 642 273 233 194 0 29 0 [pid=19886] ppid=19885 vsize=7452 CPUtime=0.12 /proc/19886/stat : 19886 (packup) R 19885 19885 4778 34817 4778 4202496 1353 0 0 0 12 0 0 0 25 0 1 0 11119267 7630848 1282 1283457024 134512640 134752139 4292648896 18446744073709551615 134681631 0 0 18944 8192 0 0 0 17 0 0 0 0 /proc/19886/statm: 1863 1282 286 59 0 1027 0 Current children cumulated CPU time (s) 0.12 Current children cumulated vsize (KiB) 10020 [startup+0.215762 s] /proc/loadavg: 1.38 1.33 1.15 5/36 19886 /proc/meminfo: memFree=290148/1048576 swapFree=0/0 [pid=19885] ppid=19884 vsize=2568 CPUtime=0 /proc/19885/stat : 19885 (packup2mp4pa-0.) S 19884 19885 4778 34817 4778 4202496 377 0 0 0 0 0 0 0 25 0 1 0 11119267 2629632 273 1283457024 134512640 135304128 4293538000 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/19885/statm: 642 273 233 194 0 29 0 [pid=19886] ppid=19885 vsize=10356 CPUtime=0.22 /proc/19886/stat : 19886 (packup) R 19885 19885 4778 34817 4778 4202496 2085 0 0 0 22 0 0 0 25 0 1 0 11119267 10604544 2014 1283457024 134512640 134752139 4292648896 18446744073709551615 134683169 0 0 18944 8192 0 0 0 17 0 0 0 0 /proc/19886/statm: 2589 2014 286 59 0 1753 0 Current children cumulated CPU time (s) 0.22 Current children cumulated vsize (KiB) 12924 [startup+0.315784 s] /proc/loadavg: 1.38 1.33 1.15 5/36 19886 /proc/meminfo: memFree=290148/1048576 swapFree=0/0 [pid=19885] ppid=19884 vsize=2568 CPUtime=0 /proc/19885/stat : 19885 (packup2mp4pa-0.) S 19884 19885 4778 34817 4778 4202496 377 0 0 0 0 0 0 0 25 0 1 0 11119267 2629632 273 1283457024 134512640 135304128 4293538000 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/19885/statm: 642 273 233 194 0 29 0 [pid=19886] ppid=19885 vsize=13236 CPUtime=0.31 /proc/19886/stat : 19886 (packup) R 19885 19885 4778 34817 4778 4202496 2787 0 0 0 31 0 0 0 25 0 1 0 11119267 13553664 2716 1283457024 134512640 134752139 4292648896 18446744073709551615 4157152379 0 0 18944 8192 0 0 0 17 0 0 0 0 /proc/19886/statm: 3309 2716 286 59 0 2473 0 Current children cumulated CPU time (s) 0.31 Current children cumulated vsize (KiB) 15804 [startup+0.715894 s] /proc/loadavg: 1.38 1.33 1.15 5/36 19886 /proc/meminfo: memFree=290148/1048576 swapFree=0/0 [pid=19885] ppid=19884 vsize=2568 CPUtime=0 /proc/19885/stat : 19885 (packup2mp4pa-0.) S 19884 19885 4778 34817 4778 4202496 377 0 0 0 0 0 0 0 25 0 1 0 11119267 2629632 273 1283457024 134512640 135304128 4293538000 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/19885/statm: 642 273 233 194 0 29 0 [pid=19886] ppid=19885 vsize=22804 CPUtime=0.71 /proc/19886/stat : 19886 (packup) R 19885 19885 4778 34817 4778 4202496 5220 0 0 0 69 2 0 0 25 0 1 0 11119267 23351296 5149 1283457024 134512640 134752139 4292648896 18446744073709551615 134638032 0 0 18944 8192 0 0 0 17 0 0 0 0 /proc/19886/statm: 5701 5149 306 59 0 4865 0 Current children cumulated CPU time (s) 0.71 Current children cumulated vsize (KiB) 25372 [startup+1.50607 s] /proc/loadavg: 1.38 1.33 1.15 2/39 19889 /proc/meminfo: memFree=250796/1048576 swapFree=0/0 [pid=19885] ppid=19884 vsize=2568 CPUtime=0 /proc/19885/stat : 19885 (packup2mp4pa-0.) S 19884 19885 4778 34817 4778 4202496 377 0 0 0 0 0 0 0 25 0 1 0 11119267 2629632 273 1283457024 134512640 135304128 4293538000 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/19885/statm: 642 273 233 194 0 29 0 [pid=19886] ppid=19885 vsize=25704 CPUtime=1.5 /proc/19886/stat : 19886 (packup) R 19885 19885 4778 34817 4778 4202496 5988 9787 0 0 74 10 61 5 19 0 1 0 11119267 26320896 5843 1283457024 134512640 134752139 4292648896 18446744073709551615 4158712254 0 0 18944 8192 0 0 0 17 0 0 0 0 /proc/19886/statm: 6426 5843 332 59 0 5590 0 Current children cumulated CPU time (s) 1.5 Current children cumulated vsize (KiB) 28272 Solver just ended. Dumping a history of the last processes samples [startup+1.60609 s] /proc/loadavg: 1.38 1.33 1.15 2/39 19889 /proc/meminfo: memFree=250796/1048576 swapFree=0/0 [pid=19885] ppid=19884 vsize=2568 CPUtime=0 /proc/19885/stat : 19885 (packup2mp4pa-0.) S 19884 19885 4778 34817 4778 4202496 377 0 0 0 0 0 0 0 25 0 1 0 11119267 2629632 273 1283457024 134512640 135304128 4293538000 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/19885/statm: 642 273 233 194 0 29 0 [pid=19886] ppid=19885 vsize=25704 CPUtime=1.52 /proc/19886/stat : 19886 (packup) S 19885 19885 4778 34817 4778 4202496 5989 9787 0 0 74 12 61 5 19 0 1 0 11119267 26320896 5843 1283457024 134512640 134752139 4292648896 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0 /proc/19886/statm: 6426 5843 332 59 0 5590 0 Current children cumulated CPU time (s) 1.52 Current children cumulated vsize (KiB) 28272 [startup+2.00621 s] /proc/loadavg: 1.38 1.33 1.15 2/39 19889 /proc/meminfo: memFree=250796/1048576 swapFree=0/0 [pid=19885] ppid=19884 vsize=2568 CPUtime=0 /proc/19885/stat : 19885 (packup2mp4pa-0.) S 19884 19885 4778 34817 4778 4202496 377 0 0 0 0 0 0 0 25 0 1 0 11119267 2629632 273 1283457024 134512640 135304128 4293538000 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/19885/statm: 642 273 233 194 0 29 0 [pid=19886] ppid=19885 vsize=25704 CPUtime=1.52 /proc/19886/stat : 19886 (packup) S 19885 19885 4778 34817 4778 4202496 5989 9787 0 0 74 12 61 5 19 0 1 0 11119267 26320896 5843 1283457024 134512640 134752139 4292648896 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0 /proc/19886/statm: 6426 5843 332 59 0 5590 0 Current children cumulated CPU time (s) 1.52 Current children cumulated vsize (KiB) 28272 [startup+2.20625 s] /proc/loadavg: 1.38 1.33 1.15 2/39 19891 /proc/meminfo: memFree=241124/1048576 swapFree=0/0 [pid=19885] ppid=19884 vsize=2568 CPUtime=0 /proc/19885/stat : 19885 (packup2mp4pa-0.) S 19884 19885 4778 34817 4778 4202496 377 0 0 0 0 0 0 0 25 0 1 0 11119267 2629632 273 1283457024 134512640 135304128 4293538000 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/19885/statm: 642 273 233 194 0 29 0 [pid=19886] ppid=19885 vsize=25704 CPUtime=1.52 /proc/19886/stat : 19886 (packup) S 19885 19885 4778 34817 4778 4202496 5989 9787 0 0 74 12 61 5 19 0 1 0 11119267 26320896 5843 1283457024 134512640 134752139 4292648896 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0 /proc/19886/statm: 6426 5843 332 59 0 5590 0 [pid=19890] ppid=19886 vsize=1672 CPUtime=0.01 /proc/19890/stat : 19890 (sh) S 19886 19885 4778 34817 4778 4202496 147 0 0 0 0 1 0 0 19 0 1 0 11119421 1712128 124 1283457024 134512640 134593992 4286944000 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0 /proc/19890/statm: 418 124 108 20 0 45 0 [pid=19891] ppid=19890 vsize=29448 CPUtime=0.66 /proc/19891/stat : 19891 (minisatp_32) R 19890 19885 4778 34817 4778 4202496 10294 0 0 0 61 5 0 0 25 0 1 0 11119421 30154752 6696 1283457024 134512640 135413687 4289154352 18446744073709551615 134667622 0 0 18944 0 0 0 0 17 0 0 0 0 /proc/19891/statm: 7362 6696 108 220 0 7140 0 Current children cumulated CPU time (s) 2.19 Current children cumulated vsize (KiB) 59392 [startup+2.31632 s] /proc/loadavg: 1.38 1.33 1.15 2/39 19891 /proc/meminfo: memFree=241124/1048576 swapFree=0/0 [pid=19885] ppid=19884 vsize=2568 CPUtime=0 /proc/19885/stat : 19885 (packup2mp4pa-0.) S 19884 19885 4778 34817 4778 4202496 377 0 0 0 0 0 0 0 25 0 1 0 11119267 2629632 273 1283457024 134512640 135304128 4293538000 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/19885/statm: 642 273 233 194 0 29 0 [pid=19886] ppid=19885 vsize=25708 CPUtime=2.31 /proc/19886/stat : 19886 (packup) R 19885 19885 4778 34817 4778 4202496 10462 20724 0 0 75 14 130 12 15 0 1 0 11119267 26324992 5857 1283457024 134512640 134752139 4292648896 18446744073709551615 4158935236 0 0 18944 8192 0 0 0 17 0 0 0 0 /proc/19886/statm: 6427 5857 345 59 0 5591 0 Current children cumulated CPU time (s) 2.31 Current children cumulated vsize (KiB) 28276 Child status: 0 Real time (s): 2.34854 CPU time (s): 2.34815 CPU user time (s): 2.07613 CPU system time (s): 0.272017 CPU usage (%): 99.9834 Max. virtual memory (cumulated for all children) (KiB): 59392 getrusage(RUSAGE_CHILDREN,...) data: user time used= 2.07613 system time used= 0.272017 maximum resident set size= 0 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 32519 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= 51 runsolver used 0 second user time and 0 second system time The end