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/aspcud-paranoid-1.5/rand512.cudf.dudf-random.log.runsolver ./aspcud-paranoid-1.5 /home/misc2010/data/2011/dudf-random//rand512.cudf /home/misc2010/tmp/201108251442/aspcud-paranoid-1.5/rand512.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.42 1.31 1.13 3/34 19269 /proc/meminfo: memFree=305404/1048576 swapFree=0/0 [pid=19268] ppid=19267 vsize=2588 CPUtime=0 /proc/19268/stat : 19268 (aspcud-paranoid) R 19267 19268 4778 34817 4778 4202496 367 0 0 0 0 0 0 0 25 0 1 0 11112680 2650112 280 1283457024 134512640 135304128 4293677280 18446744073709551615 4294960130 0 65538 4 65536 0 0 0 17 0 0 0 0 /proc/19268/statm: 647 280 234 194 0 34 0 [pid=19269] ppid=19268 vsize=2588 CPUtime=0 /proc/19269/stat : 19269 (aspcud-paranoid) R 19268 19268 4778 34817 4778 4202560 0 0 0 0 0 0 0 0 25 0 1 0 11112680 2650112 46 1283457024 134512640 135304128 4293677280 18446744073709551615 4294960130 0 65538 4 65536 0 0 0 17 0 0 0 0 /proc/19269/statm: 647 46 0 194 0 34 0 [startup+0.10479 s] /proc/loadavg: 1.42 1.31 1.13 3/34 19269 /proc/meminfo: memFree=305404/1048576 swapFree=0/0 [pid=19268] ppid=19267 vsize=2596 CPUtime=0.01 /proc/19268/stat : 19268 (aspcud-paranoid) S 19267 19268 4778 34817 4778 4202496 651 2939 0 0 0 0 1 0 25 0 1 0 11112680 2658304 299 1283457024 134512640 135304128 4293677280 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/19268/statm: 649 299 251 194 0 36 0 Current children cumulated CPU time (s) 0.01 Current children cumulated vsize (KiB) 2596 [startup+0.204798 s] /proc/loadavg: 1.42 1.31 1.13 3/34 19269 /proc/meminfo: memFree=305404/1048576 swapFree=0/0 [pid=19268] ppid=19267 vsize=2596 CPUtime=0.01 /proc/19268/stat : 19268 (aspcud-paranoid) S 19267 19268 4778 34817 4778 4202496 651 2939 0 0 0 0 1 0 25 0 1 0 11112680 2658304 299 1283457024 134512640 135304128 4293677280 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/19268/statm: 649 299 251 194 0 36 0 Current children cumulated CPU time (s) 0.01 Current children cumulated vsize (KiB) 2596 [startup+0.304805 s] /proc/loadavg: 1.42 1.31 1.13 3/34 19269 /proc/meminfo: memFree=305404/1048576 swapFree=0/0 [pid=19268] ppid=19267 vsize=2596 CPUtime=0.01 /proc/19268/stat : 19268 (aspcud-paranoid) S 19267 19268 4778 34817 4778 4202496 651 2939 0 0 0 0 1 0 25 0 1 0 11112680 2658304 299 1283457024 134512640 135304128 4293677280 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/19268/statm: 649 299 251 194 0 36 0 Current children cumulated CPU time (s) 0.01 Current children cumulated vsize (KiB) 2596 [startup+0.704832 s] /proc/loadavg: 1.42 1.31 1.13 3/34 19269 /proc/meminfo: memFree=305404/1048576 swapFree=0/0 [pid=19268] ppid=19267 vsize=2596 CPUtime=0.01 /proc/19268/stat : 19268 (aspcud-paranoid) S 19267 19268 4778 34817 4778 4202496 651 2939 0 0 0 0 1 0 25 0 1 0 11112680 2658304 299 1283457024 134512640 135304128 4293677280 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/19268/statm: 649 299 251 194 0 36 0 Current children cumulated CPU time (s) 0.01 Current children cumulated vsize (KiB) 2596 [startup+1.50514 s] /proc/loadavg: 1.39 1.31 1.13 1/37 19285 /proc/meminfo: memFree=280956/1048576 swapFree=0/0 [pid=19268] ppid=19267 vsize=2596 CPUtime=0.01 /proc/19268/stat : 19268 (aspcud-paranoid) S 19267 19268 4778 34817 4778 4202496 651 2939 0 0 0 0 1 0 25 0 1 0 11112680 2658304 299 1283457024 134512640 135304128 4293677280 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/19268/statm: 649 299 251 194 0 36 0 [pid=19283] ppid=19268 vsize=1928 CPUtime=0 /proc/19283/stat : 19283 (clasp) S 19268 19268 4778 34817 4778 4202496 292 0 0 0 0 0 0 0 25 0 1 0 11112681 1974272 160 1283457024 134512640 136285277 4287361696 18446744073709551615 4294960130 0 0 6 18944 18446744071564457842 0 0 17 0 0 0 0 /proc/19283/statm: 482 160 144 433 0 47 0 [pid=19284] ppid=19268 vsize=2580 CPUtime=0 /proc/19284/stat : 19284 (gringo) S 19268 19268 4778 34817 4778 4202496 403 0 0 0 0 0 0 0 25 0 1 0 11112681 2641920 271 1283457024 134512640 136933539 4292444144 18446744073709551615 135633806 0 0 6 16384 18446744071564457842 0 0 17 0 0 0 0 /proc/19284/statm: 645 271 242 592 0 50 0 [pid=19285] ppid=19268 vsize=29872 CPUtime=1.05 /proc/19285/stat : 19285 (cudf2lp) R 19268 19268 4778 34817 4778 4202496 8079 0 0 0 104 1 0 0 25 0 1 0 11112681 30588928 6578 1283457024 134512640 135786343 4291743584 18446744073709551615 135219509 0 0 6 0 0 0 0 17 0 0 0 0 /proc/19285/statm: 7468 6578 133 311 0 7155 0 Current children cumulated CPU time (s) 1.06 Current children cumulated vsize (KiB) 36976 Solver just ended. Dumping a history of the last processes samples [startup+1.60515 s] /proc/loadavg: 1.39 1.31 1.13 1/37 19285 /proc/meminfo: memFree=280956/1048576 swapFree=0/0 [pid=19268] ppid=19267 vsize=2596 CPUtime=0.01 /proc/19268/stat : 19268 (aspcud-paranoid) S 19267 19268 4778 34817 4778 4202496 651 2939 0 0 0 0 1 0 25 0 1 0 11112680 2658304 299 1283457024 134512640 135304128 4293677280 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/19268/statm: 649 299 251 194 0 36 0 [pid=19283] ppid=19268 vsize=2868 CPUtime=0 /proc/19283/stat : 19283 (clasp) S 19268 19268 4778 34817 4778 4202496 574 0 0 0 0 0 0 0 18 0 1 0 11112681 2936832 442 1283457024 134512640 136285277 4287361696 18446744073709551615 4294960130 0 0 6 18944 18446744071564457842 0 0 17 0 0 0 0 /proc/19283/statm: 717 442 176 433 0 282 0 [pid=19284] ppid=19268 vsize=4372 CPUtime=0.04 /proc/19284/stat : 19284 (gringo) S 19268 19268 4778 34817 4778 4202496 847 0 0 0 4 0 0 0 18 0 1 0 11112681 4476928 617 1283457024 134512640 136933539 4292444144 18446744073709551615 135633806 0 0 6 16384 18446744071564457842 0 0 17 0 0 0 0 /proc/19284/statm: 1093 617 242 592 0 498 0 [pid=19285] ppid=19268 vsize=24900 CPUtime=1.11 /proc/19285/stat : 19285 (cudf2lp) R 19268 19268 4778 34817 4778 4202496 8224 0 0 0 110 1 0 0 25 0 1 0 11112681 25497600 5979 1283457024 134512640 135786343 4291743584 18446744073709551615 135199354 0 0 6 0 0 0 0 17 0 0 0 0 /proc/19285/statm: 6225 5979 137 311 0 5912 0 Current children cumulated CPU time (s) 1.16 Current children cumulated vsize (KiB) 34736 [startup+1.80519 s] /proc/loadavg: 1.39 1.31 1.13 1/37 19285 /proc/meminfo: memFree=280956/1048576 swapFree=0/0 [pid=19268] ppid=19267 vsize=2596 CPUtime=1.18 /proc/19268/stat : 19268 (aspcud-paranoid) S 19267 19268 4778 34817 4778 4202496 651 11167 0 0 0 0 116 2 18 0 1 0 11112680 2658304 299 1283457024 134512640 135304128 4293677280 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/19268/statm: 649 299 251 194 0 36 0 [pid=19283] ppid=19268 vsize=6304 CPUtime=0.02 /proc/19283/stat : 19283 (clasp) R 19268 19268 4778 34817 4778 4202496 1435 0 0 0 2 0 0 0 18 0 1 0 11112681 6455296 1262 1283457024 134512640 136285277 4287361696 18446744073709551615 134835582 0 0 6 18944 0 0 0 17 0 0 0 0 /proc/19283/statm: 1576 1262 177 433 0 1141 0 [pid=19284] ppid=19268 vsize=10288 CPUtime=0.18 /proc/19284/stat : 19284 (gringo) R 19268 19268 4778 34817 4778 4202496 2266 0 0 0 18 0 0 0 18 0 1 0 11112681 10534912 1907 1283457024 134512640 136933539 4292444144 18446744073709551615 135633710 0 0 6 16384 0 0 0 17 0 0 0 0 /proc/19284/statm: 2572 1907 253 592 0 1977 0 Current children cumulated CPU time (s) 1.38 Current children cumulated vsize (KiB) 19188 [startup+1.90523 s] /proc/loadavg: 1.39 1.31 1.13 1/37 19285 /proc/meminfo: memFree=280956/1048576 swapFree=0/0 [pid=19268] ppid=19267 vsize=2596 CPUtime=1.18 /proc/19268/stat : 19268 (aspcud-paranoid) R 19267 19268 4778 34817 4778 4202496 651 11167 0 0 0 0 116 2 18 0 1 0 11112680 2658304 299 1283457024 134512640 135304128 4293677280 18446744073709551615 4294960130 0 65536 4 1132560123 0 0 0 17 0 0 0 0 /proc/19268/statm: 649 299 251 194 0 36 0 [pid=19283] ppid=19268 vsize=8632 CPUtime=0.1 /proc/19283/stat : 19283 (clasp) R 19268 19268 4778 34817 4778 4202496 2231 0 0 0 9 1 0 0 18 0 1 0 11112681 8839168 1909 1283457024 134512640 136285277 4287361696 18446744073709551615 134902017 0 0 6 18944 0 0 0 17 0 0 0 0 /proc/19283/statm: 2158 1909 217 433 0 1723 0 [pid=19284] ppid=19268 vsize=0 CPUtime=0.19 /proc/19284/stat : 19284 (gringo) Z 19268 19268 4778 34817 4778 4202508 2732 0 0 0 19 0 0 0 18 0 1 0 11112681 0 0 1283457024 0 0 0 0 0 0 0 6 16384 18446744071564254338 0 0 17 0 0 0 0 /proc/19284/statm: 0 0 0 0 0 0 0 Current children cumulated CPU time (s) 1.47 Current children cumulated vsize (KiB) 11228 Child status: 0 Real time (s): 1.98366 CPU time (s): 1.5481 CPU user time (s): 1.51609 CPU system time (s): 0.032002 CPU usage (%): 78.0426 Max. virtual memory (cumulated for all children) (KiB): 36976 getrusage(RUSAGE_CHILDREN,...) data: user time used= 1.51609 system time used= 0.032002 maximum resident set size= 0 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 20532 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= 287 involuntary context switches= 276 runsolver used 0 second user time and 0 second system time The end