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/201103031013/aspcud-paranoid-1.4/3363.cudf.caixa.log.runsolver ./aspcud-paranoid-1.4 /home/misc2010/data/misc4/caixa//3363.cudf /home/misc2010/tmp/201103031013/aspcud-paranoid-1.4/3363.cudf.caixa.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.80 1.73 1.55 6/36 1569 /proc/meminfo: memFree=302616/1048576 swapFree=0/0 [pid=1553] ppid=1552 vsize=2600 CPUtime=0.02 /proc/1553/stat : 1553 (aspcud-paranoid) R 1552 1553 29493 34817 29493 4202496 634 2946 0 0 0 0 0 2 25 0 1 0 75910025 2662400 298 1283457024 134512640 135304128 4292663296 18446744073709551615 4294960130 0 65538 4 1132560123 0 0 0 17 0 0 0 0 /proc/1553/statm: 650 298 250 194 0 37 0 [pid=1567] ppid=1553 vsize=2600 CPUtime=0 /proc/1567/stat : 1567 (aspcud-paranoid) R 1553 1553 29493 34817 29493 4202560 111 0 0 0 0 0 0 0 25 0 1 0 75910026 2662400 132 1283457024 134512640 135304128 4292663296 18446744073709551615 4294960130 0 0 6 1132494585 0 0 0 17 0 0 0 0 /proc/1567/statm: 650 132 83 194 0 37 0 [pid=1568] ppid=1553 vsize=2600 CPUtime=0 /proc/1568/stat : 1568 (aspcud-paranoid) S 1553 1553 29493 34817 29493 4202560 110 0 0 0 0 0 0 0 25 0 1 0 75910026 2662400 132 1283457024 134512640 135304128 4292663296 18446744073709551615 4294960130 0 0 6 1132494585 18446744071564457842 0 0 17 0 0 0 0 /proc/1568/statm: 650 132 83 194 0 37 0 [pid=1569] ppid=1553 vsize=2600 CPUtime=0 /proc/1569/stat : 1569 (aspcud-paranoid) R 1553 1553 29493 34817 29493 4202560 0 0 0 0 0 0 0 0 25 0 1 0 75910026 2662400 48 1283457024 134512640 135304128 4292663296 18446744073709551615 4294960130 0 65538 4 1132560123 0 0 0 17 0 0 0 0 /proc/1569/statm: 650 48 0 194 0 37 0 [startup+0.163931 s] /proc/loadavg: 1.80 1.73 1.55 6/36 1569 /proc/meminfo: memFree=302616/1048576 swapFree=0/0 [pid=1553] ppid=1552 vsize=2600 CPUtime=0.02 /proc/1553/stat : 1553 (aspcud-paranoid) S 1552 1553 29493 34817 29493 4202496 660 2946 0 0 0 0 0 2 25 0 1 0 75910025 2662400 299 1283457024 134512640 135304128 4292663296 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/1553/statm: 650 299 251 194 0 37 0 [pid=1567] ppid=1553 vsize=1892 CPUtime=0 /proc/1567/stat : 1567 (clasp) S 1553 1553 29493 34817 29493 4202496 289 0 0 0 0 0 0 0 25 0 1 0 75910026 1937408 156 1283457024 134512640 136241547 4286722560 18446744073709551615 135683070 0 0 6 18944 18446744071564457842 0 0 17 0 0 0 0 /proc/1567/statm: 473 156 140 423 0 48 0 [pid=1568] ppid=1553 vsize=2608 CPUtime=0 /proc/1568/stat : 1568 (gringo) S 1553 1553 29493 34817 29493 4202496 409 0 0 0 0 0 0 0 25 0 1 0 75910026 2670592 277 1283457024 134512640 136959103 4292970608 18446744073709551615 135656590 0 0 6 16384 18446744071564457842 0 0 17 0 0 0 0 /proc/1568/statm: 652 277 247 598 0 51 0 [pid=1569] ppid=1553 vsize=8420 CPUtime=0.14 /proc/1569/stat : 1569 (cudf2lp) R 1553 1553 29493 34817 29493 4202496 2081 0 0 0 12 2 0 0 25 0 1 0 75910026 8622080 1851 1283457024 134512640 135749763 4289402144 18446744073709551615 135180807 0 0 6 0 0 0 0 17 0 0 0 0 /proc/1569/statm: 2105 1851 119 303 0 1800 0 Current children cumulated CPU time (s) 0.16 Current children cumulated vsize (KiB) 15520 [startup+0.213937 s] /proc/loadavg: 1.80 1.73 1.55 6/36 1569 /proc/meminfo: memFree=302616/1048576 swapFree=0/0 [pid=1553] ppid=1552 vsize=2600 CPUtime=0.02 /proc/1553/stat : 1553 (aspcud-paranoid) S 1552 1553 29493 34817 29493 4202496 660 2946 0 0 0 0 0 2 25 0 1 0 75910025 2662400 299 1283457024 134512640 135304128 4292663296 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/1553/statm: 650 299 251 194 0 37 0 [pid=1567] ppid=1553 vsize=1892 CPUtime=0 /proc/1567/stat : 1567 (clasp) S 1553 1553 29493 34817 29493 4202496 289 0 0 0 0 0 0 0 25 0 1 0 75910026 1937408 156 1283457024 134512640 136241547 4286722560 18446744073709551615 135683070 0 0 6 18944 18446744071564457842 0 0 17 0 0 0 0 /proc/1567/statm: 473 156 140 423 0 48 0 [pid=1568] ppid=1553 vsize=2608 CPUtime=0 /proc/1568/stat : 1568 (gringo) S 1553 1553 29493 34817 29493 4202496 409 0 0 0 0 0 0 0 25 0 1 0 75910026 2670592 277 1283457024 134512640 136959103 4292970608 18446744073709551615 135656590 0 0 6 16384 18446744071564457842 0 0 17 0 0 0 0 /proc/1568/statm: 652 277 247 598 0 51 0 [pid=1569] ppid=1553 vsize=12784 CPUtime=0.19 /proc/1569/stat : 1569 (cudf2lp) R 1553 1553 29493 34817 29493 4202496 3211 0 0 0 16 3 0 0 25 0 1 0 75910026 13090816 2852 1283457024 134512640 135749763 4289402144 18446744073709551615 135178409 0 0 6 0 0 0 0 17 0 0 0 0 /proc/1569/statm: 3196 2852 119 303 0 2891 0 Current children cumulated CPU time (s) 0.21 Current children cumulated vsize (KiB) 19884 [startup+0.303959 s] /proc/loadavg: 1.80 1.73 1.55 6/36 1569 /proc/meminfo: memFree=302616/1048576 swapFree=0/0 [pid=1553] ppid=1552 vsize=2600 CPUtime=0.02 /proc/1553/stat : 1553 (aspcud-paranoid) S 1552 1553 29493 34817 29493 4202496 660 2946 0 0 0 0 0 2 25 0 1 0 75910025 2662400 299 1283457024 134512640 135304128 4292663296 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/1553/statm: 650 299 251 194 0 37 0 [pid=1567] ppid=1553 vsize=1892 CPUtime=0 /proc/1567/stat : 1567 (clasp) S 1553 1553 29493 34817 29493 4202496 289 0 0 0 0 0 0 0 25 0 1 0 75910026 1937408 156 1283457024 134512640 136241547 4286722560 18446744073709551615 135683070 0 0 6 18944 18446744071564457842 0 0 17 0 0 0 0 /proc/1567/statm: 473 156 140 423 0 48 0 [pid=1568] ppid=1553 vsize=2608 CPUtime=0 /proc/1568/stat : 1568 (gringo) S 1553 1553 29493 34817 29493 4202496 409 0 0 0 0 0 0 0 25 0 1 0 75910026 2670592 277 1283457024 134512640 136959103 4292970608 18446744073709551615 135656590 0 0 6 16384 18446744071564457842 0 0 17 0 0 0 0 /proc/1568/statm: 652 277 247 598 0 51 0 [pid=1569] ppid=1553 vsize=14632 CPUtime=0.28 /proc/1569/stat : 1569 (cudf2lp) R 1553 1553 29493 34817 29493 4202496 3784 0 0 0 25 3 0 0 25 0 1 0 75910026 14983168 3425 1283457024 134512640 135749763 4289402144 18446744073709551615 135031905 0 0 6 0 0 0 0 17 0 0 0 0 /proc/1569/statm: 3658 3425 119 303 0 3353 0 Current children cumulated CPU time (s) 0.3 Current children cumulated vsize (KiB) 21732 [startup+0.704057 s] /proc/loadavg: 1.80 1.73 1.55 6/36 1569 /proc/meminfo: memFree=302616/1048576 swapFree=0/0 [pid=1553] ppid=1552 vsize=2600 CPUtime=0.02 /proc/1553/stat : 1553 (aspcud-paranoid) S 1552 1553 29493 34817 29493 4202496 660 2946 0 0 0 0 0 2 25 0 1 0 75910025 2662400 299 1283457024 134512640 135304128 4292663296 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/1553/statm: 650 299 251 194 0 37 0 [pid=1567] ppid=1553 vsize=3296 CPUtime=0 /proc/1567/stat : 1567 (clasp) S 1553 1553 29493 34817 29493 4202496 691 0 0 0 0 0 0 0 19 0 1 0 75910026 3375104 558 1283457024 134512640 136241547 4286722560 18446744073709551615 135683070 0 0 6 18944 18446744071564457842 0 0 17 0 0 0 0 /proc/1567/statm: 824 558 174 423 0 399 0 [pid=1568] ppid=1553 vsize=4732 CPUtime=0.11 /proc/1568/stat : 1568 (gringo) R 1553 1553 29493 34817 29493 4202496 1010 0 0 0 11 0 0 0 20 0 1 0 75910026 4845568 731 1283457024 134512640 136959103 4292970608 18446744073709551615 134598656 0 0 6 16384 0 0 0 17 0 0 0 0 /proc/1568/statm: 1183 731 247 598 0 582 0 [pid=1569] ppid=1553 vsize=33136 CPUtime=0.56 /proc/1569/stat : 1569 (cudf2lp) R 1553 1553 29493 34817 29493 4202496 8963 0 0 0 48 8 0 0 25 0 1 0 75910026 33931264 8046 1283457024 134512640 135749763 4289402144 18446744073709551615 135237662 0 0 6 0 0 0 0 17 0 0 0 0 /proc/1569/statm: 8284 8046 128 303 0 7979 0 Current children cumulated CPU time (s) 0.69 Current children cumulated vsize (KiB) 43764 Solver just ended. Dumping a history of the last processes samples [startup+0.804075 s] /proc/loadavg: 1.80 1.73 1.55 6/36 1569 /proc/meminfo: memFree=302616/1048576 swapFree=0/0 [pid=1553] ppid=1552 vsize=2600 CPUtime=0.02 /proc/1553/stat : 1553 (aspcud-paranoid) S 1552 1553 29493 34817 29493 4202496 660 2946 0 0 0 0 0 2 25 0 1 0 75910025 2662400 299 1283457024 134512640 135304128 4292663296 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/1553/statm: 650 299 251 194 0 37 0 [pid=1567] ppid=1553 vsize=4588 CPUtime=0 /proc/1567/stat : 1567 (clasp) S 1553 1553 29493 34817 29493 4202496 972 0 0 0 0 0 0 0 18 0 1 0 75910026 4698112 839 1283457024 134512640 136241547 4286722560 18446744073709551615 135683070 0 0 6 18944 18446744071564457842 0 0 17 0 0 0 0 /proc/1567/statm: 1147 839 175 423 0 722 0 [pid=1568] ppid=1553 vsize=6372 CPUtime=0.18 /proc/1568/stat : 1568 (gringo) S 1553 1553 29493 34817 29493 4202496 1519 0 0 0 18 0 0 0 20 0 1 0 75910026 6524928 1014 1283457024 134512640 136959103 4292970608 18446744073709551615 135656590 0 0 6 16384 18446744071564457842 0 0 17 0 0 0 0 /proc/1568/statm: 1593 1014 247 598 0 992 0 [pid=1569] ppid=1553 vsize=33136 CPUtime=0.58 /proc/1569/stat : 1569 (cudf2lp) R 1553 1553 29493 34817 29493 4202496 8963 0 0 0 50 8 0 0 25 0 1 0 75910026 33931264 8046 1283457024 134512640 135749763 4289402144 18446744073709551615 134852752 0 0 6 0 0 0 0 17 0 0 0 0 /proc/1569/statm: 8284 8046 128 303 0 7979 0 Current children cumulated CPU time (s) 0.78 Current children cumulated vsize (KiB) 46696 [startup+1.20418 s] /proc/loadavg: 1.80 1.73 1.55 2/36 1570 /proc/meminfo: memFree=284432/1048576 swapFree=0/0 [pid=1553] ppid=1552 vsize=2600 CPUtime=0.72 /proc/1553/stat : 1553 (aspcud-paranoid) S 1552 1553 29493 34817 29493 4202496 660 11913 0 0 0 0 61 11 18 0 1 0 75910025 2662400 299 1283457024 134512640 135304128 4292663296 18446744073709551615 4294960130 0 65536 4 1132560123 18446744071564329979 0 0 17 0 0 0 0 /proc/1553/statm: 650 299 251 194 0 37 0 [pid=1567] ppid=1553 vsize=10716 CPUtime=0.03 /proc/1567/stat : 1567 (clasp) S 1553 1553 29493 34817 29493 4202496 2713 0 0 0 3 0 0 0 18 0 1 0 75910026 10973184 2376 1283457024 134512640 136241547 4286722560 18446744073709551615 135683070 0 0 6 18944 18446744071564457842 0 0 17 0 0 0 0 /proc/1567/statm: 2679 2376 175 423 0 2254 0 [pid=1568] ppid=1553 vsize=16364 CPUtime=0.44 /proc/1568/stat : 1568 (gringo) R 1553 1553 29493 34817 29493 4202496 4068 0 0 0 42 2 0 0 19 0 1 0 75910026 16756736 3306 1283457024 134512640 136959103 4292970608 18446744073709551615 134620461 0 0 6 16384 0 0 0 17 0 0 0 0 /proc/1568/statm: 4091 3306 256 598 0 3490 0 Current children cumulated CPU time (s) 1.19 Current children cumulated vsize (KiB) 29680 [startup+1.40424 s] /proc/loadavg: 1.80 1.73 1.55 2/36 1570 /proc/meminfo: memFree=284432/1048576 swapFree=0/0 [pid=1553] ppid=1552 vsize=2600 CPUtime=1.39 /proc/1553/stat : 1553 (aspcud-paranoid) R 1552 1553 29493 34817 29493 4202496 1828 30908 0 0 0 0 121 18 16 0 1 0 75910025 2662400 304 1283457024 134512640 135304128 4292663296 18446744073709551615 4294960130 0 65538 16902 1132543225 0 0 0 17 0 0 0 0 /proc/1553/statm: 650 304 256 194 0 37 0 Current children cumulated CPU time (s) 1.39 Current children cumulated vsize (KiB) 2600 Child status: 0 Real time (s): 1.41021 CPU time (s): 1.40809 CPU user time (s): 1.21207 CPU system time (s): 0.196012 CPU usage (%): 99.8497 Max. virtual memory (cumulated for all children) (KiB): 46720 getrusage(RUSAGE_CHILDREN,...) data: user time used= 1.21208 system time used= 0.196012 maximum resident set size= 0 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 34208 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= 1017 involuntary context switches= 1007 runsolver used 0 second user time and 0 second system time The end