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/201108241238/aspcud-trendy-1.5/rand282.cudf.dudf-random.log.runsolver ./aspcud-trendy-1.5 /home/misc2010/data/2011/dudf-random//rand282.cudf /home/misc2010/tmp/201108241238/aspcud-trendy-1.5/rand282.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.10 1.05 1.01 5/36 7211 /proc/meminfo: memFree=625420/1048576 swapFree=0/0 [pid=7208] ppid=7207 vsize=2588 CPUtime=0 /proc/7208/stat : 7208 (aspcud-trendy-1) S 7207 7208 1511 34817 1511 4202496 373 0 0 0 0 0 0 0 18 0 1 0 1753120 2650112 280 1283457024 134512640 135304128 4287255248 18446744073709551615 4294960130 0 0 4 65536 18446744071564457842 0 0 17 0 0 0 0 /proc/7208/statm: 647 280 234 194 0 34 0 [pid=7209] ppid=7208 vsize=2588 CPUtime=0 /proc/7209/stat : 7209 (aspcud-trendy-1) S 7208 7208 1511 34817 1511 4202560 118 0 0 0 0 0 0 0 18 0 1 0 1753120 2650112 134 1283457024 134512640 135304128 4287255248 18446744073709551615 4294960130 0 0 0 65538 18446744071564457842 0 0 17 0 0 0 0 /proc/7209/statm: 647 134 87 194 0 34 0 [pid=7210] ppid=7209 vsize=2588 CPUtime=0 /proc/7210/stat : 7210 (aspcud-trendy-1) R 7209 7208 1511 34817 1511 4202560 127 0 0 0 0 0 0 0 25 0 1 0 1753120 2650112 151 1283457024 134512640 135304128 4287255248 18446744073709551615 4294960130 0 65538 0 65538 0 0 0 17 0 0 0 0 /proc/7210/statm: 647 151 104 194 0 34 0 [pid=7211] ppid=7210 vsize=2588 CPUtime=0 /proc/7211/stat : 7211 (aspcud-trendy-1) R 7210 7208 1511 34817 1511 4202560 0 0 0 0 0 0 0 0 25 0 1 0 1753120 2650112 47 1283457024 134512640 135304128 4287255248 18446744073709551615 4294960130 0 65538 0 65538 0 0 0 17 0 0 0 0 /proc/7211/statm: 647 47 0 194 0 34 0 [startup+0.105386 s] /proc/loadavg: 1.10 1.05 1.01 5/36 7211 /proc/meminfo: memFree=625420/1048576 swapFree=0/0 [pid=7208] ppid=7207 vsize=2596 CPUtime=0.01 /proc/7208/stat : 7208 (aspcud-trendy-1) S 7207 7208 1511 34817 1511 4202496 622 2227 0 0 0 0 0 1 25 0 1 0 1753120 2658304 299 1283457024 134512640 135304128 4287255248 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/7208/statm: 649 299 251 194 0 36 0 Current children cumulated CPU time (s) 0.01 Current children cumulated vsize (KiB) 2596 [startup+0.205406 s] /proc/loadavg: 1.10 1.05 1.01 5/36 7211 /proc/meminfo: memFree=625420/1048576 swapFree=0/0 [pid=7208] ppid=7207 vsize=2596 CPUtime=0.01 /proc/7208/stat : 7208 (aspcud-trendy-1) S 7207 7208 1511 34817 1511 4202496 622 2227 0 0 0 0 0 1 25 0 1 0 1753120 2658304 299 1283457024 134512640 135304128 4287255248 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/7208/statm: 649 299 251 194 0 36 0 Current children cumulated CPU time (s) 0.01 Current children cumulated vsize (KiB) 2596 [startup+0.30542 s] /proc/loadavg: 1.10 1.05 1.01 5/36 7211 /proc/meminfo: memFree=625420/1048576 swapFree=0/0 [pid=7208] ppid=7207 vsize=2596 CPUtime=0.01 /proc/7208/stat : 7208 (aspcud-trendy-1) S 7207 7208 1511 34817 1511 4202496 622 2227 0 0 0 0 0 1 25 0 1 0 1753120 2658304 299 1283457024 134512640 135304128 4287255248 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/7208/statm: 649 299 251 194 0 36 0 Current children cumulated CPU time (s) 0.01 Current children cumulated vsize (KiB) 2596 [startup+0.705472 s] /proc/loadavg: 1.10 1.05 1.01 5/36 7211 /proc/meminfo: memFree=625420/1048576 swapFree=0/0 [pid=7208] ppid=7207 vsize=2596 CPUtime=0.01 /proc/7208/stat : 7208 (aspcud-trendy-1) S 7207 7208 1511 34817 1511 4202496 622 2227 0 0 0 0 0 1 25 0 1 0 1753120 2658304 299 1283457024 134512640 135304128 4287255248 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/7208/statm: 649 299 251 194 0 36 0 Current children cumulated CPU time (s) 0.01 Current children cumulated vsize (KiB) 2596 [startup+1.50559 s] /proc/loadavg: 1.10 1.05 1.01 2/37 7222 /proc/meminfo: memFree=603576/1048576 swapFree=0/0 [pid=7208] ppid=7207 vsize=2596 CPUtime=0.01 /proc/7208/stat : 7208 (aspcud-trendy-1) S 7207 7208 1511 34817 1511 4202496 622 2227 0 0 0 0 0 1 25 0 1 0 1753120 2658304 299 1283457024 134512640 135304128 4287255248 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/7208/statm: 649 299 251 194 0 36 0 [pid=7220] ppid=7208 vsize=1924 CPUtime=0 /proc/7220/stat : 7220 (clasp) S 7208 7208 1511 34817 1511 4202496 292 0 0 0 0 0 0 0 25 0 1 0 1753121 1970176 159 1283457024 134512640 136285277 4291481232 18446744073709551615 4294960130 0 0 6 18944 18446744071564457842 0 0 17 0 0 0 0 /proc/7220/statm: 481 159 144 433 0 46 0 [pid=7221] ppid=7208 vsize=2580 CPUtime=0 /proc/7221/stat : 7221 (gringo) S 7208 7208 1511 34817 1511 4202496 404 0 0 0 0 0 0 0 25 0 1 0 1753121 2641920 271 1283457024 134512640 136933539 4292394992 18446744073709551615 135633806 0 0 6 16384 18446744071564457842 0 0 17 0 0 0 0 /proc/7221/statm: 645 271 242 592 0 50 0 [pid=7222] ppid=7208 vsize=25008 CPUtime=1.49 /proc/7222/stat : 7222 (cudf2lp) R 7208 7208 1511 34817 1511 4202496 7237 0 0 0 146 3 0 0 25 0 1 0 1753121 25608192 5638 1283457024 134512640 135786343 4291421984 18446744073709551615 134585014 0 0 6 0 0 0 0 17 0 0 0 0 /proc/7222/statm: 6252 5638 126 311 0 5939 0 Current children cumulated CPU time (s) 1.5 Current children cumulated vsize (KiB) 32108 [startup+3.10578 s] /proc/loadavg: 1.10 1.05 1.01 3/37 7222 /proc/meminfo: memFree=584108/1048576 swapFree=0/0 [pid=7208] ppid=7207 vsize=2596 CPUtime=2.4 /proc/7208/stat : 7208 (aspcud-trendy-1) S 7207 7208 1511 34817 1511 4202496 623 15134 0 0 0 0 232 8 18 0 1 0 1753120 2658304 299 1283457024 134512640 135304128 4287255248 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/7208/statm: 649 299 251 194 0 36 0 [pid=7220] ppid=7208 vsize=16124 CPUtime=0.07 /proc/7220/stat : 7220 (clasp) R 7208 7208 1511 34817 1511 4202496 4437 0 0 0 6 1 0 0 18 0 1 0 1753121 16510976 3646 1283457024 134512640 136285277 4291481232 18446744073709551615 4294960130 0 0 6 18944 0 0 0 17 0 0 0 0 /proc/7220/statm: 4031 3646 177 433 0 3596 0 [pid=7221] ppid=7208 vsize=25908 CPUtime=0.61 /proc/7221/stat : 7221 (gringo) R 7208 7208 1511 34817 1511 4202496 7217 0 0 0 59 2 0 0 18 0 1 0 1753121 26529792 5040 1283457024 134512640 136933539 4292394992 18446744073709551615 134729494 0 0 6 16384 0 0 0 17 0 0 0 0 /proc/7221/statm: 6477 5040 253 592 0 5882 0 Current children cumulated CPU time (s) 3.08 Current children cumulated vsize (KiB) 44628 [startup+6.30702 s] /proc/loadavg: 1.10 1.05 1.01 2/35 7222 /proc/meminfo: memFree=588116/1048576 swapFree=0/0 [pid=7208] ppid=7207 vsize=2596 CPUtime=3.65 /proc/7208/stat : 7208 (aspcud-trendy-1) S 7207 7208 1511 34817 1511 4202496 623 29190 0 0 0 0 350 15 18 0 1 0 1753120 2658304 299 1283457024 134512640 135304128 4287255248 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/7208/statm: 649 299 251 194 0 36 0 [pid=7220] ppid=7208 vsize=38800 CPUtime=2.64 /proc/7220/stat : 7220 (clasp) R 7208 7208 1511 34817 1511 4202496 11592 0 0 0 260 4 0 0 22 0 1 0 1753121 39731200 9442 1283457024 134512640 136285277 4291481232 18446744073709551615 134930672 0 0 6 18944 0 0 0 17 0 0 0 0 /proc/7220/statm: 9700 9442 234 433 0 9265 0 Current children cumulated CPU time (s) 6.29 Current children cumulated vsize (KiB) 41396 Solver just ended. Dumping a history of the last processes samples [startup+6.40707 s] /proc/loadavg: 1.10 1.05 1.01 2/35 7222 /proc/meminfo: memFree=588116/1048576 swapFree=0/0 [pid=7208] ppid=7207 vsize=2596 CPUtime=3.65 /proc/7208/stat : 7208 (aspcud-trendy-1) S 7207 7208 1511 34817 1511 4202496 623 29190 0 0 0 0 350 15 18 0 1 0 1753120 2658304 299 1283457024 134512640 135304128 4287255248 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/7208/statm: 649 299 251 194 0 36 0 [pid=7220] ppid=7208 vsize=38800 CPUtime=2.74 /proc/7220/stat : 7220 (clasp) R 7208 7208 1511 34817 1511 4202496 11592 0 0 0 270 4 0 0 22 0 1 0 1753121 39731200 9442 1283457024 134512640 136285277 4291481232 18446744073709551615 134893284 0 0 6 18944 0 0 0 17 0 0 0 0 /proc/7220/statm: 9700 9442 234 433 0 9265 0 Current children cumulated CPU time (s) 6.39 Current children cumulated vsize (KiB) 41396 [startup+6.80728 s] /proc/loadavg: 1.10 1.05 1.01 2/35 7222 /proc/meminfo: memFree=588116/1048576 swapFree=0/0 [pid=7208] ppid=7207 vsize=2596 CPUtime=3.65 /proc/7208/stat : 7208 (aspcud-trendy-1) S 7207 7208 1511 34817 1511 4202496 623 29190 0 0 0 0 350 15 18 0 1 0 1753120 2658304 299 1283457024 134512640 135304128 4287255248 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/7208/statm: 649 299 251 194 0 36 0 [pid=7220] ppid=7208 vsize=38800 CPUtime=3.15 /proc/7220/stat : 7220 (clasp) R 7208 7208 1511 34817 1511 4202496 11592 0 0 0 310 5 0 0 25 0 1 0 1753121 39731200 9442 1283457024 134512640 136285277 4291481232 18446744073709551615 134893169 0 0 6 18944 0 0 0 17 0 0 0 0 /proc/7220/statm: 9700 9442 234 433 0 9265 0 Current children cumulated CPU time (s) 6.8 Current children cumulated vsize (KiB) 41396 [startup+7.2074 s] /proc/loadavg: 1.10 1.05 1.01 2/35 7222 /proc/meminfo: memFree=588116/1048576 swapFree=0/0 [pid=7208] ppid=7207 vsize=2596 CPUtime=3.65 /proc/7208/stat : 7208 (aspcud-trendy-1) S 7207 7208 1511 34817 1511 4202496 623 29190 0 0 0 0 350 15 18 0 1 0 1753120 2658304 299 1283457024 134512640 135304128 4287255248 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/7208/statm: 649 299 251 194 0 36 0 [pid=7220] ppid=7208 vsize=38800 CPUtime=3.54 /proc/7220/stat : 7220 (clasp) R 7208 7208 1511 34817 1511 4202496 11592 0 0 0 349 5 0 0 25 0 1 0 1753121 39731200 9442 1283457024 134512640 136285277 4291481232 18446744073709551615 134893063 0 0 6 18944 0 0 0 17 0 0 0 0 /proc/7220/statm: 9700 9442 234 433 0 9265 0 Current children cumulated CPU time (s) 7.19 Current children cumulated vsize (KiB) 41396 [startup+7.30744 s] /proc/loadavg: 1.10 1.05 1.01 2/35 7222 /proc/meminfo: memFree=588116/1048576 swapFree=0/0 [pid=7208] ppid=7207 vsize=2596 CPUtime=3.65 /proc/7208/stat : 7208 (aspcud-trendy-1) S 7207 7208 1511 34817 1511 4202496 623 29190 0 0 0 0 350 15 18 0 1 0 1753120 2658304 299 1283457024 134512640 135304128 4287255248 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/7208/statm: 649 299 251 194 0 36 0 [pid=7220] ppid=7208 vsize=38800 CPUtime=3.64 /proc/7220/stat : 7220 (clasp) R 7208 7208 1511 34817 1511 4202496 11592 0 0 0 359 5 0 0 25 0 1 0 1753121 39731200 9442 1283457024 134512640 136285277 4291481232 18446744073709551615 134893169 0 0 6 18944 0 0 0 17 0 0 0 0 /proc/7220/statm: 9700 9442 234 433 0 9265 0 Current children cumulated CPU time (s) 7.29 Current children cumulated vsize (KiB) 41396 Child status: 0 Real time (s): 7.3886 CPU time (s): 7.38846 CPU user time (s): 7.14845 CPU system time (s): 0.240015 CPU usage (%): 99.9982 Max. virtual memory (cumulated for all children) (KiB): 87852 getrusage(RUSAGE_CHILDREN,...) data: user time used= 7.14845 system time used= 0.240015 maximum resident set size= 0 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 45380 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= 1584 involuntary context switches= 1216 runsolver used 0 second user time and 0 second system time The end