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/rand450.cudf.s-e-l-s.log.runsolver ./aspcud-paranoid-1.5 /home/misc2010/data/2011/incremental/s-e-l-s/rand450.cudf /home/misc2010/tmp/201108251442/aspcud-paranoid-1.5/rand450.cudf.s-e-l-s.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.00 1.16 1.13 5/36 13975 /proc/meminfo: memFree=358536/1048576 swapFree=0/0 [pid=13972] ppid=13971 vsize=2588 CPUtime=0 /proc/13972/stat : 13972 (aspcud-paranoid) S 13971 13972 4778 34817 4778 4202496 374 0 0 0 0 0 0 0 19 0 1 0 10632530 2650112 280 1283457024 134512640 135304128 4288205744 18446744073709551615 4294960130 0 0 4 65536 18446744071564457842 0 0 17 0 0 0 0 /proc/13972/statm: 647 280 234 194 0 34 0 [pid=13973] ppid=13972 vsize=2588 CPUtime=0 /proc/13973/stat : 13973 (aspcud-paranoid) S 13972 13972 4778 34817 4778 4202560 118 0 0 0 0 0 0 0 19 0 1 0 10632530 2650112 134 1283457024 134512640 135304128 4288205744 18446744073709551615 4294960130 0 0 0 65538 18446744071564457842 0 0 17 0 0 0 0 /proc/13973/statm: 647 134 87 194 0 34 0 [pid=13974] ppid=13973 vsize=2588 CPUtime=0 /proc/13974/stat : 13974 (aspcud-paranoid) R 13973 13972 4778 34817 4778 4202560 127 0 0 0 0 0 0 0 25 0 1 0 10632530 2650112 151 1283457024 134512640 135304128 4288205744 18446744073709551615 4294960130 0 65538 0 65538 0 0 0 17 0 0 0 0 /proc/13974/statm: 647 151 104 194 0 34 0 [pid=13975] ppid=13974 vsize=2588 CPUtime=0 /proc/13975/stat : 13975 (aspcud-paranoid) R 13974 13972 4778 34817 4778 4202560 0 0 0 0 0 0 0 0 25 0 1 0 10632530 2650112 47 1283457024 134512640 135304128 4288205744 18446744073709551615 4294960130 0 65538 0 65538 0 0 0 17 0 0 0 0 /proc/13975/statm: 647 47 0 194 0 34 0 [startup+0.119587 s] /proc/loadavg: 1.00 1.16 1.13 5/36 13975 /proc/meminfo: memFree=358536/1048576 swapFree=0/0 [pid=13972] ppid=13971 vsize=2596 CPUtime=0.01 /proc/13972/stat : 13972 (aspcud-paranoid) S 13971 13972 4778 34817 4778 4202496 655 2936 0 0 0 0 0 1 25 0 1 0 10632530 2658304 299 1283457024 134512640 135304128 4288205744 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/13972/statm: 649 299 251 194 0 36 0 Current children cumulated CPU time (s) 0.01 Current children cumulated vsize (KiB) 2596 [startup+0.207625 s] /proc/loadavg: 1.00 1.16 1.13 5/36 13975 /proc/meminfo: memFree=358536/1048576 swapFree=0/0 [pid=13972] ppid=13971 vsize=2596 CPUtime=0.01 /proc/13972/stat : 13972 (aspcud-paranoid) S 13971 13972 4778 34817 4778 4202496 655 2936 0 0 0 0 0 1 25 0 1 0 10632530 2658304 299 1283457024 134512640 135304128 4288205744 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/13972/statm: 649 299 251 194 0 36 0 Current children cumulated CPU time (s) 0.01 Current children cumulated vsize (KiB) 2596 [startup+0.315606 s] /proc/loadavg: 1.00 1.16 1.13 5/36 13975 /proc/meminfo: memFree=358536/1048576 swapFree=0/0 [pid=13972] ppid=13971 vsize=2596 CPUtime=0.01 /proc/13972/stat : 13972 (aspcud-paranoid) S 13971 13972 4778 34817 4778 4202496 655 2936 0 0 0 0 0 1 25 0 1 0 10632530 2658304 299 1283457024 134512640 135304128 4288205744 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/13972/statm: 649 299 251 194 0 36 0 Current children cumulated CPU time (s) 0.01 Current children cumulated vsize (KiB) 2596 [startup+0.70364 s] /proc/loadavg: 1.00 1.16 1.13 5/36 13975 /proc/meminfo: memFree=358536/1048576 swapFree=0/0 [pid=13972] ppid=13971 vsize=2596 CPUtime=0.01 /proc/13972/stat : 13972 (aspcud-paranoid) S 13971 13972 4778 34817 4778 4202496 655 2936 0 0 0 0 0 1 25 0 1 0 10632530 2658304 299 1283457024 134512640 135304128 4288205744 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/13972/statm: 649 299 251 194 0 36 0 Current children cumulated CPU time (s) 0.01 Current children cumulated vsize (KiB) 2596 [startup+1.50367 s] /proc/loadavg: 1.00 1.16 1.13 2/37 13989 /proc/meminfo: memFree=323256/1048576 swapFree=0/0 [pid=13972] ppid=13971 vsize=2596 CPUtime=0.01 /proc/13972/stat : 13972 (aspcud-paranoid) S 13971 13972 4778 34817 4778 4202496 655 2936 0 0 0 0 0 1 25 0 1 0 10632530 2658304 299 1283457024 134512640 135304128 4288205744 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/13972/statm: 649 299 251 194 0 36 0 [pid=13987] ppid=13972 vsize=1924 CPUtime=0 /proc/13987/stat : 13987 (clasp) S 13972 13972 4778 34817 4778 4202496 292 0 0 0 0 0 0 0 25 0 1 0 10632531 1970176 159 1283457024 134512640 136285277 4288383904 18446744073709551615 4294960130 0 0 6 18944 18446744071564457842 0 0 17 0 0 0 0 /proc/13987/statm: 481 159 144 433 0 46 0 [pid=13988] ppid=13972 vsize=2584 CPUtime=0 /proc/13988/stat : 13988 (gringo) S 13972 13972 4778 34817 4778 4202496 404 0 0 0 0 0 0 0 25 0 1 0 10632531 2646016 271 1283457024 134512640 136933539 4290661952 18446744073709551615 135633806 0 0 6 16384 18446744071564457842 0 0 17 0 0 0 0 /proc/13988/statm: 646 271 242 592 0 51 0 [pid=13989] ppid=13972 vsize=40448 CPUtime=1.3 /proc/13989/stat : 13989 (cudf2lp) R 13972 13972 4778 34817 4778 4202496 11566 0 0 0 124 6 0 0 25 0 1 0 10632531 41418752 8655 1283457024 134512640 135786343 4291274480 18446744073709551615 135196079 0 0 6 0 0 0 0 17 0 0 0 0 /proc/13989/statm: 10112 8655 126 311 0 9799 0 Current children cumulated CPU time (s) 1.31 Current children cumulated vsize (KiB) 47552 [startup+3.1098 s] /proc/loadavg: 1.00 1.15 1.13 3/37 13989 /proc/meminfo: memFree=285056/1048576 swapFree=0/0 [pid=13972] ppid=13971 vsize=2596 CPUtime=1.98 /proc/13972/stat : 13972 (aspcud-paranoid) S 13971 13972 4778 34817 4778 4202496 655 18634 0 0 0 0 186 12 18 0 1 0 10632530 2658304 299 1283457024 134512640 135304128 4288205744 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/13972/statm: 649 299 251 194 0 36 0 [pid=13987] ppid=13972 vsize=21212 CPUtime=0.1 /proc/13987/stat : 13987 (clasp) R 13972 13972 4778 34817 4778 4202496 5779 0 0 0 9 1 0 0 18 0 1 0 10632531 21721088 4988 1283457024 134512640 136285277 4288383904 18446744073709551615 4294960130 0 0 6 18944 0 0 0 17 0 0 0 0 /proc/13987/statm: 5303 4988 177 433 0 4868 0 [pid=13988] ppid=13972 vsize=35264 CPUtime=0.82 /proc/13988/stat : 13988 (gringo) R 13972 13972 4778 34817 4778 4202496 10007 0 0 0 77 5 0 0 18 0 1 0 10632531 36110336 7089 1283457024 134512640 136933539 4290661952 18446744073709551615 135827760 0 0 6 16384 0 0 0 17 0 0 0 0 /proc/13988/statm: 8816 7089 253 592 0 8221 0 Current children cumulated CPU time (s) 2.9 Current children cumulated vsize (KiB) 59072 [startup+6.31033 s] /proc/loadavg: 1.00 1.15 1.13 2/35 13989 /proc/meminfo: memFree=306044/1048576 swapFree=0/0 [pid=13972] ppid=13971 vsize=2596 CPUtime=3.1 /proc/13972/stat : 13972 (aspcud-paranoid) S 13971 13972 4778 34817 4778 4202496 655 30501 0 0 0 0 291 19 15 0 1 0 10632530 2658304 299 1283457024 134512640 135304128 4288205744 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/13972/statm: 649 299 251 194 0 36 0 [pid=13987] ppid=13972 vsize=33408 CPUtime=3 /proc/13987/stat : 13987 (clasp) R 13972 13972 4778 34817 4778 4202496 10012 0 0 0 298 2 0 0 24 0 1 0 10632531 34209792 8114 1283457024 134512640 136285277 4288383904 18446744073709551615 134931385 0 0 6 18944 0 0 0 17 0 0 0 0 /proc/13987/statm: 8352 8114 234 433 0 7917 0 Current children cumulated CPU time (s) 6.1 Current children cumulated vsize (KiB) 36004 Solver just ended. Dumping a history of the last processes samples [startup+6.41034 s] /proc/loadavg: 1.00 1.15 1.13 2/35 13989 /proc/meminfo: memFree=306044/1048576 swapFree=0/0 [pid=13972] ppid=13971 vsize=2596 CPUtime=3.1 /proc/13972/stat : 13972 (aspcud-paranoid) S 13971 13972 4778 34817 4778 4202496 655 30501 0 0 0 0 291 19 15 0 1 0 10632530 2658304 299 1283457024 134512640 135304128 4288205744 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/13972/statm: 649 299 251 194 0 36 0 [pid=13987] ppid=13972 vsize=33408 CPUtime=3.1 /proc/13987/stat : 13987 (clasp) R 13972 13972 4778 34817 4778 4202496 10012 0 0 0 308 2 0 0 24 0 1 0 10632531 34209792 8114 1283457024 134512640 136285277 4288383904 18446744073709551615 134930655 0 0 6 18944 0 0 0 17 0 0 0 0 /proc/13987/statm: 8352 8114 234 433 0 7917 0 Current children cumulated CPU time (s) 6.2 Current children cumulated vsize (KiB) 36004 [startup+7.21053 s] /proc/loadavg: 1.00 1.15 1.13 2/35 13989 /proc/meminfo: memFree=306052/1048576 swapFree=0/0 [pid=13972] ppid=13971 vsize=2596 CPUtime=3.1 /proc/13972/stat : 13972 (aspcud-paranoid) S 13971 13972 4778 34817 4778 4202496 655 30501 0 0 0 0 291 19 15 0 1 0 10632530 2658304 299 1283457024 134512640 135304128 4288205744 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/13972/statm: 649 299 251 194 0 36 0 [pid=13987] ppid=13972 vsize=33408 CPUtime=3.9 /proc/13987/stat : 13987 (clasp) R 13972 13972 4778 34817 4778 4202496 10012 0 0 0 388 2 0 0 25 0 1 0 10632531 34209792 8114 1283457024 134512640 136285277 4288383904 18446744073709551615 134930847 0 0 6 18944 0 0 0 17 0 0 0 0 /proc/13987/statm: 8352 8114 234 433 0 7917 0 Current children cumulated CPU time (s) 7 Current children cumulated vsize (KiB) 36004 [startup+7.61064 s] /proc/loadavg: 1.00 1.15 1.13 2/35 13989 /proc/meminfo: memFree=306052/1048576 swapFree=0/0 [pid=13972] ppid=13971 vsize=2596 CPUtime=3.1 /proc/13972/stat : 13972 (aspcud-paranoid) S 13971 13972 4778 34817 4778 4202496 655 30501 0 0 0 0 291 19 15 0 1 0 10632530 2658304 299 1283457024 134512640 135304128 4288205744 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/13972/statm: 649 299 251 194 0 36 0 [pid=13987] ppid=13972 vsize=33408 CPUtime=4.3 /proc/13987/stat : 13987 (clasp) R 13972 13972 4778 34817 4778 4202496 10012 0 0 0 428 2 0 0 25 0 1 0 10632531 34209792 8114 1283457024 134512640 136285277 4288383904 18446744073709551615 134966723 0 0 6 18944 0 0 0 17 0 0 0 0 /proc/13987/statm: 8352 8114 234 433 0 7917 0 Current children cumulated CPU time (s) 7.4 Current children cumulated vsize (KiB) 36004 [startup+7.81069 s] /proc/loadavg: 1.00 1.15 1.13 2/35 13989 /proc/meminfo: memFree=306052/1048576 swapFree=0/0 [pid=13972] ppid=13971 vsize=2696 CPUtime=7.6 /proc/13972/stat : 13972 (aspcud-paranoid) R 13971 13972 4778 34817 4778 4202496 877 42335 0 0 0 0 738 22 20 0 1 0 10632530 2760704 325 1283457024 134512640 135304128 4288205744 18446744073709551615 4294960130 0 65538 16902 1132543225 0 0 0 17 0 0 0 0 /proc/13972/statm: 674 325 256 194 0 61 0 Current children cumulated CPU time (s) 7.6 Current children cumulated vsize (KiB) 2696 Child status: 0 Real time (s): 7.82086 CPU time (s): 7.63648 CPU user time (s): 7.39646 CPU system time (s): 0.240015 CPU usage (%): 97.6424 Max. virtual memory (cumulated for all children) (KiB): 75152 getrusage(RUSAGE_CHILDREN,...) data: user time used= 7.39646 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= 44821 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= 1306 involuntary context switches= 1032 runsolver used 0 second user time and 0 second system time The end