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/8b0e7c16-bab4-11e0-a883-00163e1e087d.cudf.dudf-real.log.runsolver ./aspcud-paranoid-1.5 /home/misc2010/data/2011/dudf-real//8b0e7c16-bab4-11e0-a883-00163e1e087d.cudf /home/misc2010/tmp/201108251442/aspcud-paranoid-1.5/8b0e7c16-bab4-11e0-a883-00163e1e087d.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.53 1.45 1.32 5/36 26246 /proc/meminfo: memFree=265648/1048576 swapFree=0/0 [pid=26244] ppid=26243 vsize=2588 CPUtime=0 /proc/26244/stat : 26244 (aspcud-paranoid) S 26243 26244 4778 34817 4778 4202496 373 0 0 0 0 0 0 0 18 0 1 0 11210851 2650112 280 1283457024 134512640 135304128 4286734864 18446744073709551615 4294960130 0 0 4 65536 18446744071564457842 0 0 17 0 0 0 0 /proc/26244/statm: 647 280 234 194 0 34 0 [pid=26245] ppid=26244 vsize=2588 CPUtime=0 /proc/26245/stat : 26245 (aspcud-paranoid) R 26244 26244 4778 34817 4778 4202560 110 0 0 0 0 0 0 0 25 0 1 0 11210851 2650112 133 1283457024 134512640 135304128 4286734864 18446744073709551615 4294960130 0 65538 0 65538 0 0 0 17 0 0 0 0 /proc/26245/statm: 647 133 86 194 0 34 0 [pid=26246] ppid=26245 vsize=2588 CPUtime=0 /proc/26246/stat : 26246 (aspcud-paranoid) R 26245 26244 4778 34817 4778 4202560 0 0 0 0 0 0 0 0 25 0 1 0 11210851 2650112 47 1283457024 134512640 135304128 4286734864 18446744073709551615 4294960130 0 65538 0 65538 0 0 0 17 0 0 0 0 /proc/26246/statm: 647 47 0 194 0 34 0 [startup+0.184667 s] /proc/loadavg: 1.53 1.45 1.32 5/36 26246 /proc/meminfo: memFree=265648/1048576 swapFree=0/0 [pid=26244] ppid=26243 vsize=2596 CPUtime=0 /proc/26244/stat : 26244 (aspcud-paranoid) S 26243 26244 4778 34817 4778 4202496 655 2935 0 0 0 0 0 0 25 0 1 0 11210851 2658304 299 1283457024 134512640 135304128 4286734864 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/26244/statm: 649 299 251 194 0 36 0 Current children cumulated CPU time (s) 0 Current children cumulated vsize (KiB) 2596 [startup+0.206746 s] /proc/loadavg: 1.53 1.45 1.32 5/36 26246 /proc/meminfo: memFree=265648/1048576 swapFree=0/0 [pid=26244] ppid=26243 vsize=2596 CPUtime=0 /proc/26244/stat : 26244 (aspcud-paranoid) S 26243 26244 4778 34817 4778 4202496 655 2935 0 0 0 0 0 0 25 0 1 0 11210851 2658304 299 1283457024 134512640 135304128 4286734864 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/26244/statm: 649 299 251 194 0 36 0 Current children cumulated CPU time (s) 0 Current children cumulated vsize (KiB) 2596 [startup+0.304677 s] /proc/loadavg: 1.53 1.45 1.32 5/36 26246 /proc/meminfo: memFree=265648/1048576 swapFree=0/0 [pid=26244] ppid=26243 vsize=2596 CPUtime=0 /proc/26244/stat : 26244 (aspcud-paranoid) S 26243 26244 4778 34817 4778 4202496 655 2935 0 0 0 0 0 0 25 0 1 0 11210851 2658304 299 1283457024 134512640 135304128 4286734864 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/26244/statm: 649 299 251 194 0 36 0 Current children cumulated CPU time (s) 0 Current children cumulated vsize (KiB) 2596 [startup+0.709103 s] /proc/loadavg: 1.53 1.45 1.32 5/36 26246 /proc/meminfo: memFree=265648/1048576 swapFree=0/0 [pid=26244] ppid=26243 vsize=2596 CPUtime=0 /proc/26244/stat : 26244 (aspcud-paranoid) S 26243 26244 4778 34817 4778 4202496 655 2935 0 0 0 0 0 0 25 0 1 0 11210851 2658304 299 1283457024 134512640 135304128 4286734864 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/26244/statm: 649 299 251 194 0 36 0 Current children cumulated CPU time (s) 0 Current children cumulated vsize (KiB) 2596 [startup+1.50664 s] /proc/loadavg: 1.53 1.45 1.32 2/38 26261 /proc/meminfo: memFree=229100/1048576 swapFree=0/0 [pid=26244] ppid=26243 vsize=2596 CPUtime=0 /proc/26244/stat : 26244 (aspcud-paranoid) S 26243 26244 4778 34817 4778 4202496 655 2935 0 0 0 0 0 0 25 0 1 0 11210851 2658304 299 1283457024 134512640 135304128 4286734864 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/26244/statm: 649 299 251 194 0 36 0 [pid=26259] ppid=26244 vsize=1928 CPUtime=0.01 /proc/26259/stat : 26259 (clasp) S 26244 26244 4778 34817 4778 4202496 291 0 0 0 0 1 0 0 25 0 1 0 11210853 1974272 159 1283457024 134512640 136285277 4293216304 18446744073709551615 4294960130 0 0 6 18944 18446744071564457842 0 0 17 0 0 0 0 /proc/26259/statm: 482 159 144 433 0 47 0 [pid=26260] ppid=26244 vsize=2584 CPUtime=0 /proc/26260/stat : 26260 (gringo) S 26244 26244 4778 34817 4778 4202496 404 0 0 0 0 0 0 0 25 0 1 0 11210853 2646016 272 1283457024 134512640 136933539 4289791344 18446744073709551615 135633806 0 0 6 16384 18446744071564457842 0 0 17 0 0 0 0 /proc/26260/statm: 646 272 242 592 0 51 0 [pid=26261] ppid=26244 vsize=26512 CPUtime=1.3 /proc/26261/stat : 26261 (cudf2lp) D 26244 26244 4778 34817 4778 4202496 7833 0 0 0 126 4 0 0 25 0 1 0 11210853 27148288 6235 1283457024 134512640 135786343 4292224976 18446744073709551615 135258478 0 0 6 0 0 0 0 17 0 0 0 0 /proc/26261/statm: 6628 6235 126 311 0 6315 0 Current children cumulated CPU time (s) 1.31 Current children cumulated vsize (KiB) 33620 [startup+3.10779 s] /proc/loadavg: 1.53 1.45 1.32 2/38 26261 /proc/meminfo: memFree=192376/1048576 swapFree=0/0 [pid=26244] ppid=26243 vsize=2596 CPUtime=1.86 /proc/26244/stat : 26244 (aspcud-paranoid) S 26243 26244 4778 34817 4778 4202496 655 15801 0 0 0 0 180 6 18 0 1 0 11210851 2658304 299 1283457024 134512640 135304128 4286734864 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/26244/statm: 649 299 251 194 0 36 0 [pid=26259] ppid=26244 vsize=21460 CPUtime=0.18 /proc/26259/stat : 26259 (clasp) R 26244 26244 4778 34817 4778 4202496 5819 0 0 0 17 1 0 0 18 0 1 0 11210853 21975040 5029 1283457024 134512640 136285277 4293216304 18446744073709551615 4294960130 0 0 6 18944 0 0 0 17 0 0 0 0 /proc/26259/statm: 5365 5029 177 433 0 4930 0 [pid=26260] ppid=26244 vsize=35324 CPUtime=0.85 /proc/26260/stat : 26260 (gringo) R 26244 26244 4778 34817 4778 4202496 9782 0 0 0 82 3 0 0 18 0 1 0 11210853 36171776 7187 1283457024 134512640 136933539 4289791344 18446744073709551615 136204783 0 0 6 16384 0 0 0 17 0 0 0 0 /proc/26260/statm: 8831 7187 253 592 0 8236 0 Current children cumulated CPU time (s) 2.89 Current children cumulated vsize (KiB) 59380 Solver just ended. Dumping a history of the last processes samples [startup+3.20783 s] /proc/loadavg: 1.53 1.45 1.32 2/38 26261 /proc/meminfo: memFree=192376/1048576 swapFree=0/0 [pid=26244] ppid=26243 vsize=2596 CPUtime=1.86 /proc/26244/stat : 26244 (aspcud-paranoid) S 26243 26244 4778 34817 4778 4202496 655 15801 0 0 0 0 180 6 18 0 1 0 11210851 2658304 299 1283457024 134512640 135304128 4286734864 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/26244/statm: 649 299 251 194 0 36 0 [pid=26259] ppid=26244 vsize=24804 CPUtime=0.21 /proc/26259/stat : 26259 (clasp) R 26244 26244 4778 34817 4778 4202496 6781 0 0 0 18 3 0 0 18 0 1 0 11210853 25399296 5788 1283457024 134512640 136285277 4293216304 18446744073709551615 4294960130 0 0 6 18944 0 0 0 17 0 0 0 0 /proc/26259/statm: 6201 5788 177 433 0 5766 0 [pid=26260] ppid=26244 vsize=39112 CPUtime=0.92 /proc/26260/stat : 26260 (gringo) R 26244 26244 4778 34817 4778 4202496 10672 0 0 0 89 3 0 0 18 0 1 0 11210853 40050688 8077 1283457024 134512640 136933539 4289791344 18446744073709551615 134733099 0 0 6 16384 0 0 0 17 0 0 0 0 /proc/26260/statm: 9778 8077 253 592 0 9183 0 Current children cumulated CPU time (s) 2.99 Current children cumulated vsize (KiB) 66512 [startup+4.00807 s] /proc/loadavg: 1.53 1.45 1.32 2/36 26261 /proc/meminfo: memFree=218944/1048576 swapFree=0/0 [pid=26244] ppid=26243 vsize=2596 CPUtime=2.84 /proc/26244/stat : 26244 (aspcud-paranoid) S 26243 26244 4778 34817 4778 4202496 655 26729 0 0 0 0 274 10 15 0 1 0 11210851 2658304 299 1283457024 134512640 135304128 4286734864 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/26244/statm: 649 299 251 194 0 36 0 [pid=26259] ppid=26244 vsize=31824 CPUtime=0.96 /proc/26259/stat : 26259 (clasp) R 26244 26244 4778 34817 4778 4202496 9510 0 0 0 92 4 0 0 18 0 1 0 11210853 32587776 7731 1283457024 134512640 136285277 4293216304 18446744073709551615 134893169 0 0 6 18944 0 0 0 17 0 0 0 0 /proc/26259/statm: 7956 7731 234 433 0 7521 0 Current children cumulated CPU time (s) 3.8 Current children cumulated vsize (KiB) 34420 [startup+4.40823 s] /proc/loadavg: 1.49 1.45 1.31 2/35 26272 /proc/meminfo: memFree=242796/1048576 swapFree=0/0 [pid=26244] ppid=26243 vsize=2856 CPUtime=4.21 /proc/26244/stat : 26244 (aspcud-paranoid) R 26243 26244 4778 34817 4778 4202496 963 38814 0 0 2 0 404 15 25 0 1 0 11210851 2924544 356 1283457024 134512640 135304128 4286734864 18446744073709551615 4159854710 0 0 16902 1132543225 0 0 0 17 0 0 0 0 /proc/26244/statm: 714 356 256 194 0 101 0 Current children cumulated CPU time (s) 4.21 Current children cumulated vsize (KiB) 2856 Child status: 0 Real time (s): 4.41584 CPU time (s): 4.22426 CPU user time (s): 4.06825 CPU system time (s): 0.156009 CPU usage (%): 95.6616 Max. virtual memory (cumulated for all children) (KiB): 66512 getrusage(RUSAGE_CHILDREN,...) data: user time used= 4.06825 system time used= 0.156009 maximum resident set size= 0 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 40817 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= 1282 involuntary context switches= 986 runsolver used 0 second user time and 0 second system time The end