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/201012081719/cudf2pbo4paranoid-1.0/large2.cudf.cudf_set.log.runsolver ./cudf2pbo4paranoid-1.0 /home/misc2010/data/2010/cudf_set//large2.cudf /home/misc2010/tmp/201012081719/cudf2pbo4paranoid-1.0/large2.cudf.cudf_set.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: 0.99 0.96 0.91 3/39 10762 /proc/meminfo: memFree=45236/1048576 swapFree=2095372/2097144 [pid=10761] ppid=10760 vsize=2572 CPUtime=0 /proc/10761/stat : 10761 (cudf2pbo4parano) S 10760 10761 9023 34817 9081 4202496 383 0 0 0 0 0 0 0 19 0 1 0 893213869 2633728 279 1283457024 134512640 135304128 4289197216 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0 /proc/10761/statm: 643 279 238 194 0 29 0 [pid=10762] ppid=10761 vsize=1916 CPUtime=0 /proc/10762/stat : 10762 (cudf_msu32) D 10761 10761 9023 34817 9081 4202496 264 0 0 0 0 0 0 0 19 0 1 0 893213869 1961984 156 1283457024 134512640 136125367 4287454048 18446744073709551615 135594526 0 0 0 25121 18446744071564332000 0 0 17 0 0 0 0 /proc/10762/statm: 479 156 133 394 0 83 0 [startup+0.120226 s] /proc/loadavg: 0.99 0.96 0.91 3/39 10762 /proc/meminfo: memFree=45236/1048576 swapFree=2095372/2097144 [pid=10761] ppid=10760 vsize=2572 CPUtime=0.08 /proc/10761/stat : 10761 (cudf2pbo4parano) S 10760 10761 9023 34817 9081 4202496 403 535 0 0 0 0 6 2 25 0 1 0 893213869 2633728 282 1283457024 134512640 135304128 4289197216 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0 /proc/10761/statm: 643 282 241 194 0 29 0 Current children cumulated CPU time (s) 0.08 Current children cumulated vsize (KiB) 2572 [startup+0.204296 s] /proc/loadavg: 0.99 0.96 0.91 3/39 10762 /proc/meminfo: memFree=45236/1048576 swapFree=2095372/2097144 [pid=10761] ppid=10760 vsize=2572 CPUtime=0.08 /proc/10761/stat : 10761 (cudf2pbo4parano) S 10760 10761 9023 34817 9081 4202496 403 535 0 0 0 0 6 2 25 0 1 0 893213869 2633728 282 1283457024 134512640 135304128 4289197216 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0 /proc/10761/statm: 643 282 241 194 0 29 0 Current children cumulated CPU time (s) 0.08 Current children cumulated vsize (KiB) 2572 [startup+0.304323 s] /proc/loadavg: 0.99 0.96 0.91 3/39 10762 /proc/meminfo: memFree=45236/1048576 swapFree=2095372/2097144 [pid=10761] ppid=10760 vsize=2572 CPUtime=0.08 /proc/10761/stat : 10761 (cudf2pbo4parano) S 10760 10761 9023 34817 9081 4202496 403 535 0 0 0 0 6 2 25 0 1 0 893213869 2633728 282 1283457024 134512640 135304128 4289197216 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0 /proc/10761/statm: 643 282 241 194 0 29 0 Current children cumulated CPU time (s) 0.08 Current children cumulated vsize (KiB) 2572 [startup+0.704436 s] /proc/loadavg: 0.99 0.96 0.91 3/39 10762 /proc/meminfo: memFree=45236/1048576 swapFree=2095372/2097144 [pid=10761] ppid=10760 vsize=2572 CPUtime=0.08 /proc/10761/stat : 10761 (cudf2pbo4parano) S 10760 10761 9023 34817 9081 4202496 403 535 0 0 0 0 6 2 25 0 1 0 893213869 2633728 282 1283457024 134512640 135304128 4289197216 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0 /proc/10761/statm: 643 282 241 194 0 29 0 Current children cumulated CPU time (s) 0.08 Current children cumulated vsize (KiB) 2572 [startup+1.50467 s] /proc/loadavg: 0.99 0.96 0.91 2/40 10764 /proc/meminfo: memFree=42196/1048576 swapFree=2095372/2097144 [pid=10761] ppid=10760 vsize=2572 CPUtime=0.08 /proc/10761/stat : 10761 (cudf2pbo4parano) S 10760 10761 9023 34817 9081 4202496 403 535 0 0 0 0 6 2 25 0 1 0 893213869 2633728 282 1283457024 134512640 135304128 4289197216 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0 /proc/10761/statm: 643 282 241 194 0 29 0 [pid=10764] ppid=10761 vsize=5652 CPUtime=1.4 /proc/10764/stat : 10764 (bmo-pblex32) R 10761 10761 9023 34817 9081 4202496 1152 0 0 0 140 0 0 0 25 0 1 0 893213878 5787648 954 1283457024 134512640 135887319 4287619984 18446744073709551615 134615541 0 0 0 16899 0 0 0 17 0 0 0 0 /proc/10764/statm: 1413 954 137 336 0 1075 0 Current children cumulated CPU time (s) 1.48 Current children cumulated vsize (KiB) 8224 [startup+3.10517 s] /proc/loadavg: 0.99 0.96 0.91 2/40 10764 /proc/meminfo: memFree=41204/1048576 swapFree=2095372/2097144 [pid=10761] ppid=10760 vsize=2572 CPUtime=0.08 /proc/10761/stat : 10761 (cudf2pbo4parano) S 10760 10761 9023 34817 9081 4202496 403 535 0 0 0 0 6 2 25 0 1 0 893213869 2633728 282 1283457024 134512640 135304128 4289197216 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0 /proc/10761/statm: 643 282 241 194 0 29 0 [pid=10764] ppid=10761 vsize=6336 CPUtime=3 /proc/10764/stat : 10764 (bmo-pblex32) R 10761 10761 9023 34817 9081 4202496 1352 0 0 0 299 1 0 0 25 0 1 0 893213878 6488064 1124 1283457024 134512640 135887319 4287619984 18446744073709551615 134525473 0 0 0 16899 0 0 0 17 0 0 0 0 /proc/10764/statm: 1584 1124 137 336 0 1246 0 Current children cumulated CPU time (s) 3.08 Current children cumulated vsize (KiB) 8908 [startup+6.30617 s] /proc/loadavg: 0.99 0.96 0.91 2/40 10764 /proc/meminfo: memFree=40336/1048576 swapFree=2095372/2097144 [pid=10761] ppid=10760 vsize=2572 CPUtime=0.08 /proc/10761/stat : 10761 (cudf2pbo4parano) S 10760 10761 9023 34817 9081 4202496 403 535 0 0 0 0 6 2 25 0 1 0 893213869 2633728 282 1283457024 134512640 135304128 4289197216 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0 /proc/10761/statm: 643 282 241 194 0 29 0 [pid=10764] ppid=10761 vsize=7136 CPUtime=6.19 /proc/10764/stat : 10764 (bmo-pblex32) R 10761 10761 9023 34817 9081 4202496 1553 0 0 0 614 5 0 0 25 0 1 0 893213878 7307264 1300 1283457024 134512640 135887319 4287619984 18446744073709551615 134614964 0 0 0 16899 0 0 0 17 0 0 0 0 /proc/10764/statm: 1784 1300 137 336 0 1446 0 Current children cumulated CPU time (s) 6.27 Current children cumulated vsize (KiB) 9708 [startup+12.708 s] /proc/loadavg: 0.99 0.96 0.91 2/40 10764 /proc/meminfo: memFree=39096/1048576 swapFree=2095372/2097144 [pid=10761] ppid=10760 vsize=2572 CPUtime=0.08 /proc/10761/stat : 10761 (cudf2pbo4parano) S 10760 10761 9023 34817 9081 4202496 403 535 0 0 0 0 6 2 25 0 1 0 893213869 2633728 282 1283457024 134512640 135304128 4289197216 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0 /proc/10761/statm: 643 282 241 194 0 29 0 [pid=10764] ppid=10761 vsize=8268 CPUtime=12.59 /proc/10764/stat : 10764 (bmo-pblex32) R 10761 10761 9023 34817 9081 4202496 1879 0 0 0 1249 10 0 0 25 0 1 0 893213878 8466432 1583 1283457024 134512640 135887319 4287619984 18446744073709551615 134615314 0 0 0 16899 0 0 0 17 0 0 0 0 /proc/10764/statm: 2067 1583 137 336 0 1729 0 Current children cumulated CPU time (s) 12.67 Current children cumulated vsize (KiB) 10840 [startup+25.5105 s] /proc/loadavg: 0.99 0.96 0.91 2/40 10764 /proc/meminfo: memFree=38352/1048576 swapFree=2095372/2097144 [pid=10761] ppid=10760 vsize=2572 CPUtime=0.08 /proc/10761/stat : 10761 (cudf2pbo4parano) S 10760 10761 9023 34817 9081 4202496 403 535 0 0 0 0 6 2 25 0 1 0 893213869 2633728 282 1283457024 134512640 135304128 4289197216 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0 /proc/10761/statm: 643 282 241 194 0 29 0 [pid=10764] ppid=10761 vsize=8936 CPUtime=25.37 /proc/10764/stat : 10764 (bmo-pblex32) R 10761 10761 9023 34817 9081 4202496 2102 0 0 0 2518 19 0 0 25 0 1 0 893213878 9150464 1758 1283457024 134512640 135887319 4287619984 18446744073709551615 134614964 0 0 0 16899 0 0 0 17 0 0 0 0 /proc/10764/statm: 2234 1758 137 336 0 1896 0 Current children cumulated CPU time (s) 25.45 Current children cumulated vsize (KiB) 11508 [startup+51.1057 s] /proc/loadavg: 0.99 0.97 0.91 2/40 10764 /proc/meminfo: memFree=36616/1048576 swapFree=2095372/2097144 [pid=10761] ppid=10760 vsize=2572 CPUtime=0.08 /proc/10761/stat : 10761 (cudf2pbo4parano) S 10760 10761 9023 34817 9081 4202496 403 535 0 0 0 0 6 2 25 0 1 0 893213869 2633728 282 1283457024 134512640 135304128 4289197216 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0 /proc/10761/statm: 643 282 241 194 0 29 0 [pid=10764] ppid=10761 vsize=10560 CPUtime=50.95 /proc/10764/stat : 10764 (bmo-pblex32) R 10761 10761 9023 34817 9081 4202496 2575 0 0 0 5063 32 0 0 25 0 1 0 893213878 10813440 2164 1283457024 134512640 135887319 4287619984 18446744073709551615 134614864 0 0 0 16899 0 0 0 17 0 0 0 0 /proc/10764/statm: 2640 2164 137 336 0 2302 0 Current children cumulated CPU time (s) 51.03 Current children cumulated vsize (KiB) 13132 [startup+102.308 s] /proc/loadavg: 0.99 0.97 0.91 2/40 10764 /proc/meminfo: memFree=35128/1048576 swapFree=2095372/2097144 [pid=10761] ppid=10760 vsize=2572 CPUtime=0.08 /proc/10761/stat : 10761 (cudf2pbo4parano) S 10760 10761 9023 34817 9081 4202496 403 535 0 0 0 0 6 2 25 0 1 0 893213869 2633728 282 1283457024 134512640 135304128 4289197216 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0 /proc/10761/statm: 643 282 241 194 0 29 0 [pid=10764] ppid=10761 vsize=12076 CPUtime=102.03 /proc/10764/stat : 10764 (bmo-pblex32) R 10761 10761 9023 34817 9081 4202496 3053 0 0 0 10143 60 0 0 25 0 1 0 893213878 12365824 2524 1283457024 134512640 135887319 4287619984 18446744073709551615 134525040 0 0 0 16899 0 0 0 17 0 0 0 0 /proc/10764/statm: 3019 2524 137 336 0 2681 0 Current children cumulated CPU time (s) 102.11 Current children cumulated vsize (KiB) 14648 [startup+162.313 s] /proc/loadavg: 0.99 0.97 0.91 2/40 10764 /proc/meminfo: memFree=33764/1048576 swapFree=2095372/2097144 [pid=10761] ppid=10760 vsize=2572 CPUtime=0.08 /proc/10761/stat : 10761 (cudf2pbo4parano) S 10760 10761 9023 34817 9081 4202496 403 535 0 0 0 0 6 2 25 0 1 0 893213869 2633728 282 1283457024 134512640 135304128 4289197216 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0 /proc/10761/statm: 643 282 241 194 0 29 0 [pid=10764] ppid=10761 vsize=13328 CPUtime=161.93 /proc/10764/stat : 10764 (bmo-pblex32) R 10761 10761 9023 34817 9081 4202496 3450 0 0 0 16101 92 0 0 25 0 1 0 893213878 13647872 2824 1283457024 134512640 135887319 4287619984 18446744073709551615 134615145 0 0 0 16899 0 0 0 17 0 0 0 0 /proc/10764/statm: 3332 2824 137 336 0 2994 0 Current children cumulated CPU time (s) 162.01 Current children cumulated vsize (KiB) 15900 [startup+222.307 s] /proc/loadavg: 0.99 0.97 0.91 2/41 10768 /proc/meminfo: memFree=32392/1048576 swapFree=2095372/2097144 [pid=10761] ppid=10760 vsize=2572 CPUtime=0.08 /proc/10761/stat : 10761 (cudf2pbo4parano) S 10760 10761 9023 34817 9081 4202496 403 535 0 0 0 0 6 2 25 0 1 0 893213869 2633728 282 1283457024 134512640 135304128 4289197216 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0 /proc/10761/statm: 643 282 241 194 0 29 0 [pid=10764] ppid=10761 vsize=14716 CPUtime=221.81 /proc/10764/stat : 10764 (bmo-pblex32) R 10761 10761 9023 34817 9081 4202496 3879 0 0 0 22063 118 0 0 25 0 1 0 893213878 15069184 3158 1283457024 134512640 135887319 4287619984 18446744073709551615 134615026 0 0 0 16899 0 0 0 17 0 0 0 0 /proc/10764/statm: 3679 3158 137 336 0 3341 0 Current children cumulated CPU time (s) 221.89 Current children cumulated vsize (KiB) 17288 [startup+282.302 s] /proc/loadavg: 0.99 0.97 0.91 2/40 10768 /proc/meminfo: memFree=31904/1048576 swapFree=2095372/2097144 [pid=10761] ppid=10760 vsize=2572 CPUtime=0.08 /proc/10761/stat : 10761 (cudf2pbo4parano) S 10760 10761 9023 34817 9081 4202496 403 535 0 0 0 0 6 2 25 0 1 0 893213869 2633728 282 1283457024 134512640 135304128 4289197216 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0 /proc/10761/statm: 643 282 241 194 0 29 0 [pid=10764] ppid=10761 vsize=15580 CPUtime=281.73 /proc/10764/stat : 10764 (bmo-pblex32) R 10761 10761 9023 34817 9081 4202496 4125 0 0 0 28022 151 0 0 25 0 1 0 893213878 15953920 3357 1283457024 134512640 135887319 4287619984 18446744073709551615 134525088 0 0 0 16899 0 0 0 17 0 0 0 0 /proc/10764/statm: 3895 3357 137 336 0 3557 0 Current children cumulated CPU time (s) 281.81 Current children cumulated vsize (KiB) 18152 Maximum CPU time exceeded: sending signal-name then SIGKILL [startup+290.504 s] /proc/loadavg: 0.99 0.97 0.91 2/40 10768 /proc/meminfo: memFree=31036/1048576 swapFree=2095372/2097144 [pid=10761] ppid=10760 vsize=2572 CPUtime=0.08 /proc/10761/stat : 10761 (cudf2pbo4parano) S 10760 10761 9023 34817 9081 4202496 403 535 0 0 0 0 6 2 25 0 1 0 893213869 2633728 282 1283457024 134512640 135304128 4289197216 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0 /proc/10761/statm: 643 282 241 194 0 29 0 [pid=10764] ppid=10761 vsize=15976 CPUtime=289.92 /proc/10764/stat : 10764 (bmo-pblex32) R 10761 10761 9023 34817 9081 4202496 4250 0 0 0 28840 152 0 0 25 0 1 0 893213878 16359424 3466 1283457024 134512640 135887319 4287619984 18446744073709551615 134525424 0 0 0 16899 0 0 0 17 0 0 0 0 /proc/10764/statm: 3994 3466 137 336 0 3656 0 Current children cumulated CPU time (s) 290 Current children cumulated vsize (KiB) 18548 Sending User defined signal 1 to process tree (bottom up) Sleeping 10 seconds Solver just ended. Dumping a history of the last processes samples Child status: 0 Real time (s): 290.53 CPU time (s): 290.03 CPU user time (s): 288.486 CPU system time (s): 1.5441 CPU usage (%): 99.828 Max. virtual memory (cumulated for all children) (KiB): 18548 getrusage(RUSAGE_CHILDREN,...) data: user time used= 288.486 system time used= 1.5441 maximum resident set size= 0 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 6628 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= 10 involuntary context switches= 3710 runsolver used 0 second user time and 0.012 second system time The end