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/aspuncud-paranoid-1.3/7bf50d1c-9b1b-11df-8b50-00163e46d37a.cudf.dudf-real.log.runsolver ./aspuncud-paranoid-1.3 /home/misc2010/data/2011/dudf-real//7bf50d1c-9b1b-11df-8b50-00163e46d37a.cudf /home/misc2010/tmp/201108251442/aspuncud-paranoid-1.3/7bf50d1c-9b1b-11df-8b50-00163e46d37a.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.40 1.39 1.28 5/35 24785 /proc/meminfo: memFree=285440/1048576 swapFree=0/0 [pid=24783] ppid=24782 vsize=2588 CPUtime=0 /proc/24783/stat : 24783 (aspuncud-parano) S 24782 24783 4778 34817 4778 4202496 373 0 0 0 0 0 0 0 18 0 1 0 11193666 2650112 280 1283457024 134512640 135304128 4293148704 18446744073709551615 4294960130 0 0 4 65536 18446744071564457842 0 0 17 0 0 0 0 /proc/24783/statm: 647 280 234 194 0 34 0 [pid=24784] ppid=24783 vsize=2588 CPUtime=0 /proc/24784/stat : 24784 (aspuncud-parano) R 24783 24783 4778 34817 4778 4202560 110 0 0 0 0 0 0 0 25 0 1 0 11193666 2650112 133 1283457024 134512640 135304128 4293148704 18446744073709551615 4294960130 0 65538 0 65538 0 0 0 17 0 0 0 0 /proc/24784/statm: 647 133 86 194 0 34 0 [pid=24785] ppid=24784 vsize=2588 CPUtime=0 /proc/24785/stat : 24785 (aspuncud-parano) R 24784 24783 4778 34817 4778 4202560 0 0 0 0 0 0 0 0 25 0 1 0 11193667 2650112 47 1283457024 134512640 135304128 4293148704 18446744073709551615 4294960130 0 65538 0 65538 0 0 0 17 0 0 0 0 /proc/24785/statm: 647 47 0 194 0 34 0 [startup+0.193484 s] /proc/loadavg: 1.40 1.39 1.28 5/35 24785 /proc/meminfo: memFree=285440/1048576 swapFree=0/0 [pid=24783] ppid=24782 vsize=2592 CPUtime=0.01 /proc/24783/stat : 24783 (aspuncud-parano) S 24782 24783 4778 34817 4778 4202496 655 2940 0 0 0 0 1 0 25 0 1 0 11193666 2654208 298 1283457024 134512640 135304128 4293148704 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/24783/statm: 648 298 251 194 0 35 0 Current children cumulated CPU time (s) 0.01 Current children cumulated vsize (KiB) 2592 [startup+0.203477 s] /proc/loadavg: 1.40 1.39 1.28 5/35 24785 /proc/meminfo: memFree=285440/1048576 swapFree=0/0 [pid=24783] ppid=24782 vsize=2592 CPUtime=0.01 /proc/24783/stat : 24783 (aspuncud-parano) S 24782 24783 4778 34817 4778 4202496 655 2940 0 0 0 0 1 0 25 0 1 0 11193666 2654208 298 1283457024 134512640 135304128 4293148704 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/24783/statm: 648 298 251 194 0 35 0 Current children cumulated CPU time (s) 0.01 Current children cumulated vsize (KiB) 2592 [startup+0.313506 s] /proc/loadavg: 1.40 1.39 1.28 5/35 24785 /proc/meminfo: memFree=285440/1048576 swapFree=0/0 [pid=24783] ppid=24782 vsize=2592 CPUtime=0.01 /proc/24783/stat : 24783 (aspuncud-parano) S 24782 24783 4778 34817 4778 4202496 655 2940 0 0 0 0 1 0 25 0 1 0 11193666 2654208 298 1283457024 134512640 135304128 4293148704 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/24783/statm: 648 298 251 194 0 35 0 Current children cumulated CPU time (s) 0.01 Current children cumulated vsize (KiB) 2592 [startup+0.713683 s] /proc/loadavg: 1.40 1.39 1.28 5/35 24785 /proc/meminfo: memFree=285440/1048576 swapFree=0/0 [pid=24783] ppid=24782 vsize=2592 CPUtime=0.01 /proc/24783/stat : 24783 (aspuncud-parano) S 24782 24783 4778 34817 4778 4202496 655 2940 0 0 0 0 1 0 25 0 1 0 11193666 2654208 298 1283457024 134512640 135304128 4293148704 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/24783/statm: 648 298 251 194 0 35 0 Current children cumulated CPU time (s) 0.01 Current children cumulated vsize (KiB) 2592 [startup+1.51388 s] /proc/loadavg: 1.37 1.38 1.28 2/37 24800 /proc/meminfo: memFree=263960/1048576 swapFree=0/0 [pid=24783] ppid=24782 vsize=2592 CPUtime=0.01 /proc/24783/stat : 24783 (aspuncud-parano) S 24782 24783 4778 34817 4778 4202496 655 2940 0 0 0 0 1 0 25 0 1 0 11193666 2654208 298 1283457024 134512640 135304128 4293148704 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/24783/statm: 648 298 251 194 0 35 0 [pid=24798] ppid=24783 vsize=3984 CPUtime=0.01 /proc/24798/stat : 24798 (unclasp) R 24783 24783 4778 34817 4778 4202496 576 0 0 0 1 0 0 0 18 0 1 0 11193668 4079616 441 1283457024 134512640 135121179 4292161472 18446744073709551615 134782728 0 0 6 16384 0 0 0 17 0 0 0 0 /proc/24798/statm: 996 441 275 149 0 187 0 [pid=24799] ppid=24783 vsize=3684 CPUtime=0.02 /proc/24799/stat : 24799 (gringo) S 24783 24783 4778 34817 4778 4202496 621 0 0 0 2 0 0 0 18 0 1 0 11193668 3772416 493 1283457024 134512640 137056543 4288070496 18446744073709551615 4294960130 0 0 6 16384 18446744071564457842 0 0 17 0 0 0 0 /proc/24799/statm: 921 493 253 622 0 296 0 [pid=24800] ppid=24783 vsize=33328 CPUtime=1.45 /proc/24800/stat : 24800 (cudf2lp) R 24783 24783 4778 34817 4778 4202496 10789 0 0 0 141 4 0 0 25 0 1 0 11193668 34127872 8131 1283457024 134512640 135786343 4290121168 18446744073709551615 135258574 0 0 6 0 0 0 0 17 0 0 0 0 /proc/24800/statm: 8332 8131 137 311 0 8019 0 Current children cumulated CPU time (s) 1.49 Current children cumulated vsize (KiB) 43588 Solver just ended. Dumping a history of the last processes samples [startup+1.6039 s] /proc/loadavg: 1.37 1.38 1.28 2/37 24800 /proc/meminfo: memFree=263960/1048576 swapFree=0/0 [pid=24783] ppid=24782 vsize=2592 CPUtime=0.01 /proc/24783/stat : 24783 (aspuncud-parano) S 24782 24783 4778 34817 4778 4202496 655 2940 0 0 0 0 1 0 25 0 1 0 11193666 2654208 298 1283457024 134512640 135304128 4293148704 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/24783/statm: 648 298 251 194 0 35 0 [pid=24798] ppid=24783 vsize=5408 CPUtime=0.02 /proc/24798/stat : 24798 (unclasp) S 24783 24783 4778 34817 4778 4202496 929 0 0 0 2 0 0 0 18 0 1 0 11193668 5537792 794 1283457024 134512640 135121179 4292161472 18446744073709551615 4294960130 0 0 6 16384 18446744071564457842 0 0 17 0 0 0 0 /proc/24798/statm: 1352 794 275 149 0 543 0 [pid=24799] ppid=24783 vsize=5888 CPUtime=0.06 /proc/24799/stat : 24799 (gringo) R 24783 24783 4778 34817 4778 4202496 1274 0 0 0 6 0 0 0 18 0 1 0 11193668 6029312 903 1283457024 134512640 137056543 4288070496 18446744073709551615 134890469 0 0 6 16384 0 0 0 17 0 0 0 0 /proc/24799/statm: 1472 903 253 622 0 847 0 [pid=24800] ppid=24783 vsize=33328 CPUtime=1.48 /proc/24800/stat : 24800 (cudf2lp) R 24783 24783 4778 34817 4778 4202496 10789 0 0 0 144 4 0 0 25 0 1 0 11193668 34127872 8131 1283457024 134512640 135786343 4290121168 18446744073709551615 135258574 0 0 6 0 0 0 0 17 0 0 0 0 /proc/24800/statm: 8332 8131 137 311 0 8019 0 Current children cumulated CPU time (s) 1.57 Current children cumulated vsize (KiB) 47216 [startup+1.80395 s] /proc/loadavg: 1.37 1.38 1.28 2/37 24800 /proc/meminfo: memFree=263960/1048576 swapFree=0/0 [pid=24783] ppid=24782 vsize=2592 CPUtime=1.6 /proc/24783/stat : 24783 (aspuncud-parano) S 24782 24783 4778 34817 4778 4202496 655 13733 0 0 0 0 154 6 18 0 1 0 11193666 2654208 298 1283457024 134512640 135304128 4293148704 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/24783/statm: 648 298 251 194 0 35 0 [pid=24798] ppid=24783 vsize=7456 CPUtime=0.03 /proc/24798/stat : 24798 (unclasp) R 24783 24783 4778 34817 4778 4202496 1441 0 0 0 3 0 0 0 18 0 1 0 11193668 7634944 1306 1283457024 134512640 135121179 4292161472 18446744073709551615 4294960130 0 0 6 16384 0 0 0 17 0 0 0 0 /proc/24798/statm: 1864 1306 277 149 0 1055 0 [pid=24799] ppid=24783 vsize=8940 CPUtime=0.15 /proc/24799/stat : 24799 (gringo) R 24783 24783 4778 34817 4778 4202496 2053 0 0 0 15 0 0 0 18 0 1 0 11193668 9154560 1585 1283457024 134512640 137056543 4288070496 18446744073709551615 134513020 0 0 6 16384 0 0 0 17 0 0 0 0 /proc/24799/statm: 2235 1585 268 622 0 1610 0 Current children cumulated CPU time (s) 1.78 Current children cumulated vsize (KiB) 18988 [startup+1.91399 s] /proc/loadavg: 1.37 1.38 1.28 2/37 24800 /proc/meminfo: memFree=263960/1048576 swapFree=0/0 [pid=24783] ppid=24782 vsize=2592 CPUtime=1.6 /proc/24783/stat : 24783 (aspuncud-parano) R 24782 24783 4778 34817 4778 4202496 655 13733 0 0 0 0 154 6 18 0 1 0 11193666 2654208 298 1283457024 134512640 135304128 4293148704 18446744073709551615 4294960130 0 65536 4 1132560123 0 0 0 17 0 0 0 0 /proc/24783/statm: 648 298 251 194 0 35 0 [pid=24798] ppid=24783 vsize=11060 CPUtime=0.09 /proc/24798/stat : 24798 (unclasp) R 24783 24783 4778 34817 4778 4202496 2452 0 0 0 9 0 0 0 18 0 1 0 11193668 11325440 2227 1283457024 134512640 135121179 4292161472 18446744073709551615 4157896550 0 0 6 16384 0 0 0 17 0 0 0 0 /proc/24798/statm: 2765 2227 299 149 0 1956 0 [pid=24799] ppid=24783 vsize=0 CPUtime=0.21 /proc/24799/stat : 24799 (gringo) Z 24783 24783 4778 34817 4778 4202508 2663 0 0 0 19 2 0 0 18 0 1 0 11193668 0 0 1283457024 0 0 0 0 0 0 0 6 16384 18446744071564254338 0 0 17 0 0 0 0 /proc/24799/statm: 0 0 0 0 0 0 0 Current children cumulated CPU time (s) 1.9 Current children cumulated vsize (KiB) 13652 Child status: 0 Real time (s): 1.98423 CPU time (s): 1.98012 CPU user time (s): 1.89212 CPU system time (s): 0.088005 CPU usage (%): 99.7928 Max. virtual memory (cumulated for all children) (KiB): 47216 getrusage(RUSAGE_CHILDREN,...) data: user time used= 1.89212 system time used= 0.088005 maximum resident set size= 0 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 22158 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= 434 involuntary context switches= 336 runsolver used 0 second user time and 0.008 second system time The end