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/201109011757/aspcud-1.5/2c3aece6-c8b2-11df-a040-00163e3d3b7c.cudf.dudf-real.log.runsolver ./aspcud-1.5 /home/misc2010/data/2011/dudf-real//2c3aece6-c8b2-11df-a040-00163e3d3b7c.cudf /home/misc2010/tmp/201109011757/aspcud-1.5/2c3aece6-c8b2-11df-a040-00163e3d3b7c.cudf.dudf-real.result -sum(pin-priority-1),-sum(pin-priority-500),-sum(pin-priority-700),-notuptodate,-removed,-changed 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.00 1.04 1.00 5/38 26021 /proc/meminfo: memFree=597920/1048576 swapFree=0/0 [pid=26019] ppid=26018 vsize=2584 CPUtime=0 /proc/26019/stat : 26019 (aspcud-1.5) S 26018 26019 22717 34817 22717 4202496 373 0 0 0 0 0 0 0 20 0 1 0 72088076 2646016 279 1283457024 134512640 135304128 4290612592 18446744073709551615 4294960130 0 0 4 65536 18446744071564457842 0 0 17 0 0 0 0 /proc/26019/statm: 646 279 234 194 0 33 0 [pid=26020] ppid=26019 vsize=2584 CPUtime=0 /proc/26020/stat : 26020 (aspcud-1.5) R 26019 26019 22717 34817 22717 4202560 110 0 0 0 0 0 0 0 25 0 1 0 72088076 2646016 132 1283457024 134512640 135304128 4290612592 18446744073709551615 4294960130 0 65538 0 65538 0 0 0 17 0 0 0 0 /proc/26020/statm: 646 132 86 194 0 33 0 [pid=26021] ppid=26020 vsize=2584 CPUtime=0 /proc/26021/stat : 26021 (aspcud-1.5) R 26020 26019 22717 34817 22717 4202560 0 0 0 0 0 0 0 0 25 0 1 0 72088076 2646016 46 1283457024 134512640 135304128 4290612592 18446744073709551615 4294960130 0 65538 0 65538 0 0 0 17 0 0 0 0 /proc/26021/statm: 646 46 0 194 0 33 0 [startup+0.195814 s] /proc/loadavg: 1.00 1.04 1.00 5/38 26021 /proc/meminfo: memFree=597920/1048576 swapFree=0/0 [pid=26019] ppid=26018 vsize=2592 CPUtime=0 /proc/26019/stat : 26019 (aspcud-1.5) S 26018 26019 22717 34817 22717 4202496 576 1524 0 0 0 0 0 0 25 0 1 0 72088076 2654208 298 1283457024 134512640 135304128 4290612592 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/26019/statm: 648 298 251 194 0 35 0 Current children cumulated CPU time (s) 0 Current children cumulated vsize (KiB) 2592 [startup+0.207823 s] /proc/loadavg: 1.00 1.04 1.00 5/38 26021 /proc/meminfo: memFree=597920/1048576 swapFree=0/0 [pid=26019] ppid=26018 vsize=2592 CPUtime=0 /proc/26019/stat : 26019 (aspcud-1.5) S 26018 26019 22717 34817 22717 4202496 576 1524 0 0 0 0 0 0 25 0 1 0 72088076 2654208 298 1283457024 134512640 135304128 4290612592 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/26019/statm: 648 298 251 194 0 35 0 Current children cumulated CPU time (s) 0 Current children cumulated vsize (KiB) 2592 [startup+0.30783 s] /proc/loadavg: 1.00 1.04 1.00 5/38 26021 /proc/meminfo: memFree=597920/1048576 swapFree=0/0 [pid=26019] ppid=26018 vsize=2592 CPUtime=0 /proc/26019/stat : 26019 (aspcud-1.5) S 26018 26019 22717 34817 22717 4202496 576 1524 0 0 0 0 0 0 25 0 1 0 72088076 2654208 298 1283457024 134512640 135304128 4290612592 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/26019/statm: 648 298 251 194 0 35 0 Current children cumulated CPU time (s) 0 Current children cumulated vsize (KiB) 2592 [startup+0.70784 s] /proc/loadavg: 1.00 1.04 1.00 5/38 26021 /proc/meminfo: memFree=597920/1048576 swapFree=0/0 [pid=26019] ppid=26018 vsize=2592 CPUtime=0 /proc/26019/stat : 26019 (aspcud-1.5) S 26018 26019 22717 34817 22717 4202496 576 1524 0 0 0 0 0 0 25 0 1 0 72088076 2654208 298 1283457024 134512640 135304128 4290612592 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/26019/statm: 648 298 251 194 0 35 0 Current children cumulated CPU time (s) 0 Current children cumulated vsize (KiB) 2592 [startup+1.50789 s] /proc/loadavg: 1.00 1.04 1.00 2/40 26030 /proc/meminfo: memFree=560460/1048576 swapFree=0/0 [pid=26019] ppid=26018 vsize=2592 CPUtime=0 /proc/26019/stat : 26019 (aspcud-1.5) S 26018 26019 22717 34817 22717 4202496 576 1524 0 0 0 0 0 0 25 0 1 0 72088076 2654208 298 1283457024 134512640 135304128 4290612592 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/26019/statm: 648 298 251 194 0 35 0 [pid=26028] ppid=26019 vsize=1924 CPUtime=0 /proc/26028/stat : 26028 (clasp) S 26019 26019 22717 34817 22717 4202496 291 0 0 0 0 0 0 0 25 0 1 0 72088077 1970176 159 1283457024 134512640 136285277 4293273696 18446744073709551615 4294960130 0 0 6 18944 18446744071564457842 0 0 17 0 0 0 0 /proc/26028/statm: 481 159 144 433 0 46 0 [pid=26029] ppid=26019 vsize=2584 CPUtime=0 /proc/26029/stat : 26029 (gringo) S 26019 26019 22717 34817 22717 4202496 404 0 0 0 0 0 0 0 25 0 1 0 72088077 2646016 272 1283457024 134512640 136933539 4294830672 18446744073709551615 135633806 0 0 6 16384 18446744071564457842 0 0 17 0 0 0 0 /proc/26029/statm: 646 272 242 592 0 51 0 [pid=26030] ppid=26019 vsize=28276 CPUtime=1.19 /proc/26030/stat : 26030 (cudf2lp) R 26019 26019 22717 34817 22717 4202496 8112 0 0 0 118 1 0 0 25 0 1 0 72088077 28954624 6465 1283457024 134512640 135786343 4291333824 18446744073709551615 134614683 0 0 6 0 0 0 0 17 0 0 0 0 /proc/26030/statm: 7069 6465 128 311 0 6756 0 Current children cumulated CPU time (s) 1.19 Current children cumulated vsize (KiB) 35376 [startup+3.10926 s] /proc/loadavg: 1.00 1.04 1.00 3/40 26030 /proc/meminfo: memFree=528084/1048576 swapFree=0/0 [pid=26019] ppid=26018 vsize=2592 CPUtime=2.59 /proc/26019/stat : 26019 (aspcud-1.5) S 26018 26019 22717 34817 22717 4202496 576 23047 0 0 0 0 251 8 15 0 1 0 72088076 2654208 298 1283457024 134512640 135304128 4290612592 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/26019/statm: 648 298 251 194 0 35 0 [pid=26028] ppid=26019 vsize=25056 CPUtime=0.18 /proc/26028/stat : 26028 (clasp) R 26019 26019 22717 34817 22717 4202496 6655 0 0 0 16 2 0 0 18 0 1 0 72088077 25657344 5865 1283457024 134512640 136285277 4293273696 18446744073709551615 135066291 0 0 6 18944 0 0 0 17 0 0 0 0 /proc/26028/statm: 6264 5865 187 433 0 5829 0 Current children cumulated CPU time (s) 2.77 Current children cumulated vsize (KiB) 27648 Solver just ended. Dumping a history of the last processes samples [startup+3.20928 s] /proc/loadavg: 1.00 1.04 1.00 3/40 26030 /proc/meminfo: memFree=528084/1048576 swapFree=0/0 [pid=26019] ppid=26018 vsize=2592 CPUtime=2.59 /proc/26019/stat : 26019 (aspcud-1.5) S 26018 26019 22717 34817 22717 4202496 576 23047 0 0 0 0 251 8 15 0 1 0 72088076 2654208 298 1283457024 134512640 135304128 4290612592 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/26019/statm: 648 298 251 194 0 35 0 [pid=26028] ppid=26019 vsize=27416 CPUtime=0.28 /proc/26028/stat : 26028 (clasp) R 26019 26019 22717 34817 22717 4202496 7009 0 0 0 25 3 0 0 18 0 1 0 72088077 28073984 6034 1283457024 134512640 136285277 4293273696 18446744073709551615 134933763 0 0 6 18944 0 0 0 17 0 0 0 0 /proc/26028/statm: 6854 6034 190 433 0 6419 0 Current children cumulated CPU time (s) 2.87 Current children cumulated vsize (KiB) 30008 [startup+3.40932 s] /proc/loadavg: 1.00 1.04 1.00 2/38 26030 /proc/meminfo: memFree=551304/1048576 swapFree=0/0 [pid=26019] ppid=26018 vsize=2592 CPUtime=2.59 /proc/26019/stat : 26019 (aspcud-1.5) S 26018 26019 22717 34817 22717 4202496 576 23047 0 0 0 0 251 8 15 0 1 0 72088076 2654208 298 1283457024 134512640 135304128 4290612592 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/26019/statm: 648 298 251 194 0 35 0 [pid=26028] ppid=26019 vsize=27700 CPUtime=0.48 /proc/26028/stat : 26028 (clasp) R 26019 26019 22717 34817 22717 4202496 7949 0 0 0 45 3 0 0 18 0 1 0 72088077 28364800 6640 1283457024 134512640 136285277 4293273696 18446744073709551615 134893169 0 0 6 18944 0 0 0 17 0 0 0 0 /proc/26028/statm: 6925 6640 233 433 0 6490 0 Current children cumulated CPU time (s) 3.07 Current children cumulated vsize (KiB) 30292 [startup+3.50934 s] /proc/loadavg: 1.00 1.04 1.00 2/38 26030 /proc/meminfo: memFree=551304/1048576 swapFree=0/0 [pid=26019] ppid=26018 vsize=2592 CPUtime=2.59 /proc/26019/stat : 26019 (aspcud-1.5) S 26018 26019 22717 34817 22717 4202496 576 23047 0 0 0 0 251 8 15 0 1 0 72088076 2654208 298 1283457024 134512640 135304128 4290612592 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/26019/statm: 648 298 251 194 0 35 0 [pid=26028] ppid=26019 vsize=27700 CPUtime=0.58 /proc/26028/stat : 26028 (clasp) R 26019 26019 22717 34817 22717 4202496 7949 0 0 0 55 3 0 0 18 0 1 0 72088077 28364800 6640 1283457024 134512640 136285277 4293273696 18446744073709551615 134931382 0 0 6 18944 0 0 0 17 0 0 0 0 /proc/26028/statm: 6925 6640 233 433 0 6490 0 Current children cumulated CPU time (s) 3.17 Current children cumulated vsize (KiB) 30292 Child status: 0 Real time (s): 3.55622 CPU time (s): 3.2362 CPU user time (s): 3.09219 CPU system time (s): 0.144009 CPU usage (%): 91.0011 Max. virtual memory (cumulated for all children) (KiB): 61128 getrusage(RUSAGE_CHILDREN,...) data: user time used= 3.09219 system time used= 0.144009 maximum resident set size= 0 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 35507 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= 1137 involuntary context switches= 875 runsolver used 0 second user time and 0.012 second system time The end