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/rand83.cudf.dudf-random.log.runsolver ./aspcud-paranoid-1.5 /home/misc2010/data/2011/dudf-random//rand83.cudf /home/misc2010/tmp/201108251442/aspcud-paranoid-1.5/rand83.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.55 1.46 1.25 5/34 22499 /proc/meminfo: memFree=304808/1048576 swapFree=0/0 [pid=22498] ppid=22497 vsize=2588 CPUtime=0 /proc/22498/stat : 22498 (aspcud-paranoid) R 22497 22498 4778 34817 4778 4202496 366 0 0 0 0 0 0 0 25 0 1 0 11154407 2650112 280 1283457024 134512640 135304128 4287886176 18446744073709551615 4294960130 0 65538 4 65536 0 0 0 17 0 0 0 0 /proc/22498/statm: 647 280 234 194 0 34 0 [pid=22499] ppid=22498 vsize=2588 CPUtime=0 /proc/22499/stat : 22499 (aspcud-paranoid) R 22498 22498 4778 34817 4778 4202560 0 0 0 0 0 0 0 0 25 0 1 0 11154407 2650112 46 1283457024 134512640 135304128 4287886176 18446744073709551615 4294960130 0 65538 4 65536 0 0 0 17 0 0 0 0 /proc/22499/statm: 647 46 0 194 0 34 0 [startup+0.124036 s] /proc/loadavg: 1.55 1.46 1.25 5/34 22499 /proc/meminfo: memFree=304808/1048576 swapFree=0/0 [pid=22498] ppid=22497 vsize=2596 CPUtime=0.02 /proc/22498/stat : 22498 (aspcud-paranoid) S 22497 22498 4778 34817 4778 4202496 656 2938 0 0 0 0 0 2 25 0 1 0 11154407 2658304 299 1283457024 134512640 135304128 4287886176 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/22498/statm: 649 299 251 194 0 36 0 Current children cumulated CPU time (s) 0.02 Current children cumulated vsize (KiB) 2596 [startup+0.200737 s] /proc/loadavg: 1.55 1.46 1.25 5/34 22499 /proc/meminfo: memFree=304808/1048576 swapFree=0/0 [pid=22498] ppid=22497 vsize=2596 CPUtime=0.02 /proc/22498/stat : 22498 (aspcud-paranoid) S 22497 22498 4778 34817 4778 4202496 656 2938 0 0 0 0 0 2 25 0 1 0 11154407 2658304 299 1283457024 134512640 135304128 4287886176 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/22498/statm: 649 299 251 194 0 36 0 Current children cumulated CPU time (s) 0.02 Current children cumulated vsize (KiB) 2596 [startup+0.304734 s] /proc/loadavg: 1.55 1.46 1.25 5/34 22499 /proc/meminfo: memFree=304808/1048576 swapFree=0/0 [pid=22498] ppid=22497 vsize=2596 CPUtime=0.02 /proc/22498/stat : 22498 (aspcud-paranoid) S 22497 22498 4778 34817 4778 4202496 656 2938 0 0 0 0 0 2 25 0 1 0 11154407 2658304 299 1283457024 134512640 135304128 4287886176 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/22498/statm: 649 299 251 194 0 36 0 Current children cumulated CPU time (s) 0.02 Current children cumulated vsize (KiB) 2596 [startup+0.704753 s] /proc/loadavg: 1.55 1.46 1.25 5/34 22499 /proc/meminfo: memFree=304808/1048576 swapFree=0/0 [pid=22498] ppid=22497 vsize=2596 CPUtime=0.02 /proc/22498/stat : 22498 (aspcud-paranoid) S 22497 22498 4778 34817 4778 4202496 656 2938 0 0 0 0 0 2 25 0 1 0 11154407 2658304 299 1283457024 134512640 135304128 4287886176 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/22498/statm: 649 299 251 194 0 36 0 Current children cumulated CPU time (s) 0.02 Current children cumulated vsize (KiB) 2596 [startup+1.50486 s] /proc/loadavg: 1.55 1.46 1.25 2/37 22515 /proc/meminfo: memFree=267392/1048576 swapFree=0/0 [pid=22498] ppid=22497 vsize=2596 CPUtime=0.02 /proc/22498/stat : 22498 (aspcud-paranoid) S 22497 22498 4778 34817 4778 4202496 656 2938 0 0 0 0 0 2 25 0 1 0 11154407 2658304 299 1283457024 134512640 135304128 4287886176 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/22498/statm: 649 299 251 194 0 36 0 [pid=22513] ppid=22498 vsize=1932 CPUtime=0 /proc/22513/stat : 22513 (clasp) S 22498 22498 4778 34817 4778 4202496 293 0 0 0 0 0 0 0 25 0 1 0 11154408 1978368 160 1283457024 134512640 136285277 4292384624 18446744073709551615 4294960130 0 0 6 18944 18446744071564457842 0 0 17 0 0 0 0 /proc/22513/statm: 483 160 144 433 0 48 0 [pid=22514] ppid=22498 vsize=2580 CPUtime=0 /proc/22514/stat : 22514 (gringo) S 22498 22498 4778 34817 4778 4202496 404 0 0 0 0 0 0 0 25 0 1 0 11154408 2641920 271 1283457024 134512640 136933539 4293267648 18446744073709551615 135633806 0 0 6 16384 18446744071564457842 0 0 17 0 0 0 0 /proc/22514/statm: 645 271 242 592 0 50 0 [pid=22515] ppid=22498 vsize=25000 CPUtime=1.31 /proc/22515/stat : 22515 (cudf2lp) R 22498 22498 4778 34817 4778 4202496 7195 0 0 0 128 3 0 0 25 0 1 0 11154408 25600000 5596 1283457024 134512640 135786343 4290993840 18446744073709551615 134796470 0 0 6 0 0 0 0 17 0 0 0 0 /proc/22515/statm: 6250 5596 126 311 0 5937 0 Current children cumulated CPU time (s) 1.33 Current children cumulated vsize (KiB) 32108 [startup+3.1076 s] /proc/loadavg: 1.55 1.46 1.25 2/37 22515 /proc/meminfo: memFree=236976/1048576 swapFree=0/0 [pid=22498] ppid=22497 vsize=2596 CPUtime=2.21 /proc/22498/stat : 22498 (aspcud-paranoid) S 22497 22498 4778 34817 4778 4202496 656 15844 0 0 0 0 209 12 18 0 1 0 11154407 2658304 299 1283457024 134512640 135304128 4287886176 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/22498/statm: 649 299 251 194 0 36 0 [pid=22513] ppid=22498 vsize=15868 CPUtime=0.04 /proc/22513/stat : 22513 (clasp) R 22498 22498 4778 34817 4778 4202496 4385 0 0 0 3 1 0 0 18 0 1 0 11154408 16248832 3594 1283457024 134512640 136285277 4292384624 18446744073709551615 4294960130 0 0 6 18944 0 0 0 17 0 0 0 0 /proc/22513/statm: 3967 3594 177 433 0 3532 0 [pid=22514] ppid=22498 vsize=24512 CPUtime=0.6 /proc/22514/stat : 22514 (gringo) R 22498 22498 4778 34817 4778 4202496 6866 0 0 0 60 0 0 0 18 0 1 0 11154408 25100288 4818 1283457024 134512640 136933539 4293267648 18446744073709551615 134690218 0 0 6 16384 0 0 0 17 0 0 0 0 /proc/22514/statm: 6128 4818 253 592 0 5533 0 Current children cumulated CPU time (s) 2.85 Current children cumulated vsize (KiB) 42976 Solver just ended. Dumping a history of the last processes samples [startup+3.20763 s] /proc/loadavg: 1.55 1.46 1.25 2/37 22515 /proc/meminfo: memFree=236976/1048576 swapFree=0/0 [pid=22498] ppid=22497 vsize=2596 CPUtime=2.21 /proc/22498/stat : 22498 (aspcud-paranoid) S 22497 22498 4778 34817 4778 4202496 656 15844 0 0 0 0 209 12 18 0 1 0 11154407 2658304 299 1283457024 134512640 135304128 4287886176 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/22498/statm: 649 299 251 194 0 36 0 [pid=22513] ppid=22498 vsize=18780 CPUtime=0.06 /proc/22513/stat : 22513 (clasp) R 22498 22498 4778 34817 4778 4202496 5133 0 0 0 5 1 0 0 18 0 1 0 11154408 19230720 4342 1283457024 134512640 136285277 4292384624 18446744073709551615 4294960130 0 0 6 18944 0 0 0 17 0 0 0 0 /proc/22513/statm: 4695 4342 177 433 0 4260 0 [pid=22514] ppid=22498 vsize=27900 CPUtime=0.68 /proc/22514/stat : 22514 (gringo) R 22498 22498 4778 34817 4778 4202496 7760 0 0 0 68 0 0 0 18 0 1 0 11154408 28569600 5712 1283457024 134512640 136933539 4293267648 18446744073709551615 134596388 0 0 6 16384 0 0 0 17 0 0 0 0 /proc/22514/statm: 6975 5712 253 592 0 6380 0 Current children cumulated CPU time (s) 2.95 Current children cumulated vsize (KiB) 49276 [startup+4.00786 s] /proc/loadavg: 1.58 1.47 1.26 3/36 22515 /proc/meminfo: memFree=234884/1048576 swapFree=0/0 [pid=22498] ppid=22497 vsize=2596 CPUtime=3.25 /proc/22498/stat : 22498 (aspcud-paranoid) S 22497 22498 4778 34817 4778 4202496 656 26633 0 0 0 0 311 14 15 0 1 0 11154407 2658304 299 1283457024 134512640 135304128 4287886176 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/22498/statm: 649 299 251 194 0 36 0 [pid=22513] ppid=22498 vsize=32192 CPUtime=0.52 /proc/22513/stat : 22513 (clasp) R 22498 22498 4778 34817 4778 4202496 9422 0 0 0 50 2 0 0 18 0 1 0 11154408 32964608 7752 1283457024 134512640 136285277 4292384624 18446744073709551615 134894720 0 0 6 18944 0 0 0 17 0 0 0 0 /proc/22513/statm: 8048 7752 218 433 0 7613 0 Current children cumulated CPU time (s) 3.77 Current children cumulated vsize (KiB) 34788 [startup+4.20791 s] /proc/loadavg: 1.58 1.47 1.26 3/36 22515 /proc/meminfo: memFree=234884/1048576 swapFree=0/0 [pid=22498] ppid=22497 vsize=2596 CPUtime=3.96 /proc/22498/stat : 22498 (aspcud-paranoid) R 22497 22498 4778 34817 4778 4202496 706 36294 0 0 0 0 379 17 18 0 1 0 11154407 2658304 303 1283457024 134512640 135304128 4287886176 18446744073709551615 4294960130 0 65538 16902 1132543225 0 0 0 17 0 0 0 0 /proc/22498/statm: 649 303 255 194 0 36 0 Current children cumulated CPU time (s) 3.96 Current children cumulated vsize (KiB) 2596 Child status: 0 Real time (s): 4.23093 CPU time (s): 4.00025 CPU user time (s): 3.80824 CPU system time (s): 0.192012 CPU usage (%): 94.5477 Max. virtual memory (cumulated for all children) (KiB): 65400 getrusage(RUSAGE_CHILDREN,...) data: user time used= 3.80824 system time used= 0.192012 maximum resident set size= 0 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 40660 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= 1289 involuntary context switches= 1020 runsolver used 0 second user time and 0 second system time The end