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/ca8f656c-db9e-11df-b9cf-00163e3d3b7c.cudf.dudf-real.log.runsolver ./packup2mp4pa-0.6 /home/misc2010/data/2011/dudf-real//ca8f656c-db9e-11df-b9cf-00163e3d3b7c.cudf /home/misc2010/tmp/201108251442/packup2mp4pa-0.6/ca8f656c-db9e-11df-b9cf-00163e3d3b7c.cudf.dudf-real.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.56 1.47 1.34 4/35 27744 /proc/meminfo: memFree=272900/1048576 swapFree=0/0 [pid=27743] ppid=27742 vsize=2568 CPUtime=0 /proc/27743/stat : 27743 (packup2mp4pa-0.) S 27742 27743 4778 34817 4778 4202496 377 0 0 0 0 0 0 0 18 0 1 0 11231445 2629632 273 1283457024 134512640 135304128 4293218384 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/27743/statm: 642 273 233 194 0 29 0 [pid=27744] ppid=27743 vsize=3716 CPUtime=0.01 /proc/27744/stat : 27744 (packup) R 27743 27743 4778 34817 4778 4202496 406 0 0 0 1 0 0 0 25 0 1 0 11231445 3805184 335 1283457024 134512640 134752139 4288336752 18446744073709551615 134681583 0 0 18944 8192 0 0 0 17 0 0 0 0 /proc/27744/statm: 929 335 286 59 0 93 0 [startup+0.193745 s] /proc/loadavg: 1.56 1.47 1.34 4/35 27744 /proc/meminfo: memFree=272900/1048576 swapFree=0/0 [pid=27743] ppid=27742 vsize=2568 CPUtime=0 /proc/27743/stat : 27743 (packup2mp4pa-0.) S 27742 27743 4778 34817 4778 4202496 377 0 0 0 0 0 0 0 18 0 1 0 11231445 2629632 273 1283457024 134512640 135304128 4293218384 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/27743/statm: 642 273 233 194 0 29 0 [pid=27744] ppid=27743 vsize=10200 CPUtime=0.2 /proc/27744/stat : 27744 (packup) R 27743 27743 4778 34817 4778 4202496 2025 0 0 0 20 0 0 0 25 0 1 0 11231445 10444800 1954 1283457024 134512640 134752139 4288336752 18446744073709551615 134681565 0 0 18944 8192 0 0 0 17 0 0 0 0 /proc/27744/statm: 2550 1954 286 59 0 1714 0 Current children cumulated CPU time (s) 0.2 Current children cumulated vsize (KiB) 12768 [startup+0.203739 s] /proc/loadavg: 1.56 1.47 1.34 4/35 27744 /proc/meminfo: memFree=272900/1048576 swapFree=0/0 [pid=27743] ppid=27742 vsize=2568 CPUtime=0 /proc/27743/stat : 27743 (packup2mp4pa-0.) S 27742 27743 4778 34817 4778 4202496 377 0 0 0 0 0 0 0 18 0 1 0 11231445 2629632 273 1283457024 134512640 135304128 4293218384 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/27743/statm: 642 273 233 194 0 29 0 [pid=27744] ppid=27743 vsize=10464 CPUtime=0.21 /proc/27744/stat : 27744 (packup) R 27743 27743 4778 34817 4778 4202496 2096 0 0 0 21 0 0 0 25 0 1 0 11231445 10715136 2025 1283457024 134512640 134752139 4288336752 18446744073709551615 134684278 0 0 18944 8192 0 0 0 17 0 0 0 0 /proc/27744/statm: 2616 2025 286 59 0 1780 0 Current children cumulated CPU time (s) 0.21 Current children cumulated vsize (KiB) 13032 [startup+0.313761 s] /proc/loadavg: 1.56 1.47 1.34 4/35 27744 /proc/meminfo: memFree=272900/1048576 swapFree=0/0 [pid=27743] ppid=27742 vsize=2568 CPUtime=0 /proc/27743/stat : 27743 (packup2mp4pa-0.) S 27742 27743 4778 34817 4778 4202496 377 0 0 0 0 0 0 0 18 0 1 0 11231445 2629632 273 1283457024 134512640 135304128 4293218384 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/27743/statm: 642 273 233 194 0 29 0 [pid=27744] ppid=27743 vsize=13696 CPUtime=0.31 /proc/27744/stat : 27744 (packup) R 27743 27743 4778 34817 4778 4202496 2910 0 0 0 31 0 0 0 25 0 1 0 11231445 14024704 2839 1283457024 134512640 134752139 4288336752 18446744073709551615 134681608 0 0 18944 8192 0 0 0 17 0 0 0 0 /proc/27744/statm: 3424 2839 286 59 0 2588 0 Current children cumulated CPU time (s) 0.31 Current children cumulated vsize (KiB) 16264 [startup+0.713869 s] /proc/loadavg: 1.56 1.47 1.34 4/35 27744 /proc/meminfo: memFree=272900/1048576 swapFree=0/0 [pid=27743] ppid=27742 vsize=2568 CPUtime=0 /proc/27743/stat : 27743 (packup2mp4pa-0.) S 27742 27743 4778 34817 4778 4202496 377 0 0 0 0 0 0 0 18 0 1 0 11231445 2629632 273 1283457024 134512640 135304128 4293218384 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/27743/statm: 642 273 233 194 0 29 0 [pid=27744] ppid=27743 vsize=25304 CPUtime=0.71 /proc/27744/stat : 27744 (packup) R 27743 27743 4778 34817 4778 4202496 5838 0 0 0 71 0 0 0 25 0 1 0 11231445 25911296 5767 1283457024 134512640 134752139 4288336752 18446744073709551615 134667516 0 0 18944 8192 0 0 0 17 0 0 0 0 /proc/27744/statm: 6326 5767 306 59 0 5490 0 Current children cumulated CPU time (s) 0.71 Current children cumulated vsize (KiB) 27872 [startup+1.50844 s] /proc/loadavg: 1.56 1.47 1.34 2/38 27747 /proc/meminfo: memFree=241856/1048576 swapFree=0/0 [pid=27743] ppid=27742 vsize=2568 CPUtime=0 /proc/27743/stat : 27743 (packup2mp4pa-0.) S 27742 27743 4778 34817 4778 4202496 377 0 0 0 0 0 0 0 18 0 1 0 11231445 2629632 273 1283457024 134512640 135304128 4293218384 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/27743/statm: 642 273 233 194 0 29 0 [pid=27744] ppid=27743 vsize=29772 CPUtime=0.94 /proc/27744/stat : 27744 (packup) S 27743 27743 4778 34817 4778 4202496 6965 0 0 0 85 9 0 0 25 0 1 0 11231445 30486528 6893 1283457024 134512640 134752139 4288336752 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0 /proc/27744/statm: 7443 6893 324 59 0 6607 0 [pid=27746] ppid=27744 vsize=1672 CPUtime=0 /proc/27746/stat : 27746 (sh) S 27744 27743 4778 34817 4778 4202496 145 0 0 0 0 0 0 0 25 0 1 0 11231539 1712128 123 1283457024 134512640 134593992 4294920864 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0 /proc/27746/statm: 418 123 108 20 0 45 0 [pid=27747] ppid=27746 vsize=11148 CPUtime=0.54 /proc/27747/stat : 27747 (minisatp_32) R 27746 27743 4778 34817 4778 4202496 3186 0 0 0 47 7 0 0 25 0 1 0 11231540 11415552 2602 1283457024 134512640 135413687 4293829040 18446744073709551615 134885996 0 0 18944 0 0 0 0 17 0 0 0 0 /proc/27747/statm: 2787 2602 101 220 0 2565 0 Current children cumulated CPU time (s) 1.48 Current children cumulated vsize (KiB) 45160 [startup+3.10892 s] /proc/loadavg: 1.56 1.47 1.34 2/38 27749 /proc/meminfo: memFree=234788/1048576 swapFree=0/0 [pid=27743] ppid=27742 vsize=2568 CPUtime=0 /proc/27743/stat : 27743 (packup2mp4pa-0.) S 27742 27743 4778 34817 4778 4202496 377 0 0 0 0 0 0 0 18 0 1 0 11231445 2629632 273 1283457024 134512640 135304128 4293218384 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/27743/statm: 642 273 233 194 0 29 0 [pid=27744] ppid=27743 vsize=29776 CPUtime=1.62 /proc/27744/stat : 27744 (packup) S 27743 27743 4778 34817 4778 4202496 7012 3345 0 0 89 19 47 7 20 0 1 0 11231445 30490624 6923 1283457024 134512640 134752139 4288336752 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0 /proc/27744/statm: 7444 6923 332 59 0 6608 0 [pid=27748] ppid=27744 vsize=1672 CPUtime=0 /proc/27748/stat : 27748 (sh) S 27744 27743 4778 34817 4778 4202496 146 0 0 0 0 0 0 0 20 0 1 0 11231610 1712128 124 1283457024 134512640 134593992 4290770592 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0 /proc/27748/statm: 418 124 108 20 0 45 0 [pid=27749] ppid=27748 vsize=58712 CPUtime=1.45 /proc/27749/stat : 27749 (minisatp_32) R 27748 27743 4778 34817 4778 4202496 18049 0 0 0 129 16 0 0 25 0 1 0 11231610 60121088 12619 1283457024 134512640 135413687 4287175504 18446744073709551615 134705674 0 0 18944 0 0 0 0 17 0 0 0 0 /proc/27749/statm: 14678 12619 108 220 0 14456 0 Current children cumulated CPU time (s) 3.07 Current children cumulated vsize (KiB) 92728 Solver just ended. Dumping a history of the last processes samples [startup+3.20896 s] /proc/loadavg: 1.56 1.47 1.34 2/38 27749 /proc/meminfo: memFree=234788/1048576 swapFree=0/0 [pid=27743] ppid=27742 vsize=2568 CPUtime=0 /proc/27743/stat : 27743 (packup2mp4pa-0.) S 27742 27743 4778 34817 4778 4202496 377 0 0 0 0 0 0 0 18 0 1 0 11231445 2629632 273 1283457024 134512640 135304128 4293218384 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/27743/statm: 642 273 233 194 0 29 0 [pid=27744] ppid=27743 vsize=29776 CPUtime=1.62 /proc/27744/stat : 27744 (packup) S 27743 27743 4778 34817 4778 4202496 7012 3345 0 0 89 19 47 7 20 0 1 0 11231445 30490624 6923 1283457024 134512640 134752139 4288336752 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0 /proc/27744/statm: 7444 6923 332 59 0 6608 0 [pid=27748] ppid=27744 vsize=1672 CPUtime=0 /proc/27748/stat : 27748 (sh) S 27744 27743 4778 34817 4778 4202496 146 0 0 0 0 0 0 0 20 0 1 0 11231610 1712128 124 1283457024 134512640 134593992 4290770592 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0 /proc/27748/statm: 418 124 108 20 0 45 0 [pid=27749] ppid=27748 vsize=58712 CPUtime=1.55 /proc/27749/stat : 27749 (minisatp_32) R 27748 27743 4778 34817 4778 4202496 18062 0 0 0 139 16 0 0 25 0 1 0 11231610 60121088 12632 1283457024 134512640 135413687 4287175504 18446744073709551615 134696961 0 0 18944 0 0 0 0 17 0 0 0 0 /proc/27749/statm: 14678 12632 108 220 0 14456 0 Current children cumulated CPU time (s) 3.17 Current children cumulated vsize (KiB) 92728 [startup+3.40902 s] /proc/loadavg: 1.51 1.47 1.34 2/38 27749 /proc/meminfo: memFree=195852/1048576 swapFree=0/0 [pid=27743] ppid=27742 vsize=2568 CPUtime=0 /proc/27743/stat : 27743 (packup2mp4pa-0.) S 27742 27743 4778 34817 4778 4202496 377 0 0 0 0 0 0 0 18 0 1 0 11231445 2629632 273 1283457024 134512640 135304128 4293218384 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/27743/statm: 642 273 233 194 0 29 0 [pid=27744] ppid=27743 vsize=30404 CPUtime=3.38 /proc/27744/stat : 27744 (packup) R 27743 27743 4778 34817 4778 4202496 13503 22488 0 0 94 21 198 25 18 0 1 0 11231445 31133696 6972 1283457024 134512640 134752139 4288336752 18446744073709551615 4158929460 0 0 18944 8192 0 0 0 17 0 0 0 0 /proc/27744/statm: 7601 6972 345 59 0 6765 0 Current children cumulated CPU time (s) 3.38 Current children cumulated vsize (KiB) 32972 Child status: 0 Real time (s): 3.44372 CPU time (s): 3.42821 CPU user time (s): 2.96419 CPU system time (s): 0.464029 CPU usage (%): 99.5498 Max. virtual memory (cumulated for all children) (KiB): 94956 getrusage(RUSAGE_CHILDREN,...) data: user time used= 2.96419 system time used= 0.464029 maximum resident set size= 0 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 36633 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= 12 involuntary context switches= 80 runsolver used 0 second user time and 0 second system time The end