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/cudf2pbo4trendy-1.0/rand180.sarge.cudf.sarge.log.runsolver ./cudf2pbo4trendy-1.0 /home/misc2010/data/icse/sarge/rand180.sarge.cudf /home/misc2010/tmp/201012081719/cudf2pbo4trendy-1.0/rand180.sarge.cudf.sarge.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.84 0.94 0.90 6/39 10343 /proc/meminfo: memFree=59928/1048576 swapFree=2095372/2097144 [pid=10342] ppid=10341 vsize=2568 CPUtime=0 /proc/10342/stat : 10342 (cudf2pbo4trendy) R 10341 10342 9023 34817 9081 4202496 364 0 0 0 0 0 0 0 25 0 1 0 892915734 2629632 278 1283457024 134512640 135304128 4287093408 18446744073709551615 4294960130 0 65538 4 82432 0 0 0 17 0 0 0 0 /proc/10342/statm: 642 278 238 194 0 28 0 [pid=10343] ppid=10342 vsize=2568 CPUtime=0 /proc/10343/stat : 10343 (cudf2pbo4trendy) R 10342 10342 9023 34817 9081 4202560 0 0 0 0 0 0 0 0 25 0 1 0 892915734 2629632 40 1283457024 134512640 135304128 4287093408 18446744073709551615 4294960130 0 65538 4 82432 0 0 0 17 0 0 0 0 /proc/10343/statm: 642 40 0 194 0 28 0 [startup+0.160584 s] /proc/loadavg: 0.84 0.94 0.90 6/39 10343 /proc/meminfo: memFree=59928/1048576 swapFree=2095372/2097144 [pid=10342] ppid=10341 vsize=2568 CPUtime=0 /proc/10342/stat : 10342 (cudf2pbo4trendy) S 10341 10342 9023 34817 9081 4202496 381 0 0 0 0 0 0 0 25 0 1 0 892915734 2629632 278 1283457024 134512640 135304128 4287093408 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0 /proc/10342/statm: 642 278 238 194 0 28 0 [pid=10343] ppid=10342 vsize=8156 CPUtime=0.15 /proc/10343/stat : 10343 (cudf_msu32) R 10342 10342 9023 34817 9081 4202496 1858 0 0 0 14 1 0 0 25 0 1 0 892915734 8351744 1751 1283457024 134512640 136125367 4293177552 18446744073709551615 134740087 0 0 0 25121 0 0 0 17 0 0 0 0 /proc/10343/statm: 2039 1751 142 394 0 1643 0 Current children cumulated CPU time (s) 0.15 Current children cumulated vsize (KiB) 10724 [startup+0.21059 s] /proc/loadavg: 0.84 0.94 0.90 6/39 10343 /proc/meminfo: memFree=59928/1048576 swapFree=2095372/2097144 [pid=10342] ppid=10341 vsize=2568 CPUtime=0 /proc/10342/stat : 10342 (cudf2pbo4trendy) S 10341 10342 9023 34817 9081 4202496 381 0 0 0 0 0 0 0 25 0 1 0 892915734 2629632 278 1283457024 134512640 135304128 4287093408 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0 /proc/10342/statm: 642 278 238 194 0 28 0 [pid=10343] ppid=10342 vsize=9688 CPUtime=0.21 /proc/10343/stat : 10343 (cudf_msu32) R 10342 10342 9023 34817 9081 4202496 2245 0 0 0 19 2 0 0 25 0 1 0 892915734 9920512 2138 1283457024 134512640 136125367 4293177552 18446744073709551615 134674976 0 0 0 25121 0 0 0 17 0 0 0 0 /proc/10343/statm: 2422 2138 152 394 0 2026 0 Current children cumulated CPU time (s) 0.21 Current children cumulated vsize (KiB) 12256 [startup+0.310597 s] /proc/loadavg: 0.84 0.94 0.90 6/39 10343 /proc/meminfo: memFree=59928/1048576 swapFree=2095372/2097144 [pid=10342] ppid=10341 vsize=2568 CPUtime=0 /proc/10342/stat : 10342 (cudf2pbo4trendy) S 10341 10342 9023 34817 9081 4202496 381 0 0 0 0 0 0 0 25 0 1 0 892915734 2629632 278 1283457024 134512640 135304128 4287093408 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0 /proc/10342/statm: 642 278 238 194 0 28 0 [pid=10343] ppid=10342 vsize=12296 CPUtime=0.3 /proc/10343/stat : 10343 (cudf_msu32) R 10342 10342 9023 34817 9081 4202496 2921 0 0 0 24 6 0 0 25 0 1 0 892915734 12591104 2814 1283457024 134512640 136125367 4293177552 18446744073709551615 135594622 0 0 0 25121 0 0 0 17 0 0 0 0 /proc/10343/statm: 3074 2814 164 394 0 2678 0 Current children cumulated CPU time (s) 0.3 Current children cumulated vsize (KiB) 14864 [startup+0.710666 s] /proc/loadavg: 0.84 0.94 0.90 6/39 10343 /proc/meminfo: memFree=59928/1048576 swapFree=2095372/2097144 [pid=10342] ppid=10341 vsize=2568 CPUtime=0.35 /proc/10342/stat : 10342 (cudf2pbo4trendy) S 10341 10342 9023 34817 9081 4202496 401 2923 0 0 0 0 27 8 22 0 1 0 892915734 2629632 281 1283457024 134512640 135304128 4287093408 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0 /proc/10342/statm: 642 281 241 194 0 28 0 Current children cumulated CPU time (s) 0.35 Current children cumulated vsize (KiB) 2568 [startup+1.51075 s] /proc/loadavg: 0.85 0.94 0.90 2/40 10345 /proc/meminfo: memFree=53980/1048576 swapFree=2095372/2097144 [pid=10342] ppid=10341 vsize=2568 CPUtime=0.35 /proc/10342/stat : 10342 (cudf2pbo4trendy) S 10341 10342 9023 34817 9081 4202496 401 2923 0 0 0 0 27 8 22 0 1 0 892915734 2629632 281 1283457024 134512640 135304128 4287093408 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0 /proc/10342/statm: 642 281 241 194 0 28 0 [pid=10345] ppid=10342 vsize=7848 CPUtime=1.14 /proc/10345/stat : 10345 (bmo-pblex32) R 10342 10342 9023 34817 9081 4202496 2269 0 0 0 110 4 0 0 25 0 1 0 892915769 8036352 1594 1283457024 134512640 135887319 4291516240 18446744073709551615 134617801 0 0 0 16899 0 0 0 17 0 0 0 0 /proc/10345/statm: 1962 1594 144 336 0 1624 0 Current children cumulated CPU time (s) 1.49 Current children cumulated vsize (KiB) 10416 [startup+3.11113 s] /proc/loadavg: 0.85 0.94 0.90 2/40 10345 /proc/meminfo: memFree=53980/1048576 swapFree=2095372/2097144 [pid=10342] ppid=10341 vsize=2568 CPUtime=0.35 /proc/10342/stat : 10342 (cudf2pbo4trendy) S 10341 10342 9023 34817 9081 4202496 401 2923 0 0 0 0 27 8 22 0 1 0 892915734 2629632 281 1283457024 134512640 135304128 4287093408 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0 /proc/10342/statm: 642 281 241 194 0 28 0 [pid=10345] ppid=10342 vsize=7980 CPUtime=2.74 /proc/10345/stat : 10345 (bmo-pblex32) R 10342 10342 9023 34817 9081 4202496 2308 0 0 0 270 4 0 0 25 0 1 0 892915769 8171520 1631 1283457024 134512640 135887319 4291516240 18446744073709551615 134525478 0 0 0 16899 0 0 0 17 0 0 0 0 /proc/10345/statm: 1995 1631 144 336 0 1657 0 Current children cumulated CPU time (s) 3.09 Current children cumulated vsize (KiB) 10548 [startup+6.31213 s] /proc/loadavg: 0.85 0.94 0.90 2/40 10345 /proc/meminfo: memFree=53484/1048576 swapFree=2095372/2097144 [pid=10342] ppid=10341 vsize=2568 CPUtime=0.35 /proc/10342/stat : 10342 (cudf2pbo4trendy) S 10341 10342 9023 34817 9081 4202496 401 2923 0 0 0 0 27 8 22 0 1 0 892915734 2629632 281 1283457024 134512640 135304128 4287093408 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0 /proc/10342/statm: 642 281 241 194 0 28 0 [pid=10345] ppid=10342 vsize=8392 CPUtime=5.94 /proc/10345/stat : 10345 (bmo-pblex32) R 10342 10342 9023 34817 9081 4202496 2427 0 0 0 590 4 0 0 25 0 1 0 892915769 8593408 1734 1283457024 134512640 135887319 4291516240 18446744073709551615 134603626 0 0 0 16899 0 0 0 17 0 0 0 0 /proc/10345/statm: 2098 1734 144 336 0 1760 0 Current children cumulated CPU time (s) 6.29 Current children cumulated vsize (KiB) 10960 [startup+12.7133 s] /proc/loadavg: 0.88 0.94 0.90 2/40 10345 /proc/meminfo: memFree=52492/1048576 swapFree=2095372/2097144 [pid=10342] ppid=10341 vsize=2568 CPUtime=0.35 /proc/10342/stat : 10342 (cudf2pbo4trendy) S 10341 10342 9023 34817 9081 4202496 401 2923 0 0 0 0 27 8 22 0 1 0 892915734 2629632 281 1283457024 134512640 135304128 4287093408 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0 /proc/10342/statm: 642 281 241 194 0 28 0 [pid=10345] ppid=10342 vsize=9364 CPUtime=12.34 /proc/10345/stat : 10345 (bmo-pblex32) R 10342 10342 9023 34817 9081 4202496 2724 0 0 0 1226 8 0 0 25 0 1 0 892915769 9588736 1981 1283457024 134512640 135887319 4291516240 18446744073709551615 134526944 0 0 0 16899 0 0 0 17 0 0 0 0 /proc/10345/statm: 2341 1981 144 336 0 2003 0 Current children cumulated CPU time (s) 12.69 Current children cumulated vsize (KiB) 11932 [startup+25.5154 s] /proc/loadavg: 0.89 0.94 0.90 2/40 10345 /proc/meminfo: memFree=51624/1048576 swapFree=2095372/2097144 [pid=10342] ppid=10341 vsize=2568 CPUtime=0.35 /proc/10342/stat : 10342 (cudf2pbo4trendy) S 10341 10342 9023 34817 9081 4202496 401 2923 0 0 0 0 27 8 22 0 1 0 892915734 2629632 281 1283457024 134512640 135304128 4287093408 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0 /proc/10342/statm: 642 281 241 194 0 28 0 [pid=10345] ppid=10342 vsize=10244 CPUtime=25.13 /proc/10345/stat : 10345 (bmo-pblex32) R 10342 10342 9023 34817 9081 4202496 2967 0 0 0 2500 13 0 0 25 0 1 0 892915769 10489856 2176 1283457024 134512640 135887319 4291516240 18446744073709551615 134526950 0 0 0 16899 0 0 0 17 0 0 0 0 /proc/10345/statm: 2561 2176 144 336 0 2223 0 Current children cumulated CPU time (s) 25.48 Current children cumulated vsize (KiB) 12812 [startup+51.1101 s] /proc/loadavg: 0.93 0.94 0.90 2/40 10345 /proc/meminfo: memFree=50632/1048576 swapFree=2095372/2097144 [pid=10342] ppid=10341 vsize=2568 CPUtime=0.35 /proc/10342/stat : 10342 (cudf2pbo4trendy) S 10341 10342 9023 34817 9081 4202496 401 2923 0 0 0 0 27 8 22 0 1 0 892915734 2629632 281 1283457024 134512640 135304128 4287093408 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0 /proc/10342/statm: 642 281 241 194 0 28 0 [pid=10345] ppid=10342 vsize=11172 CPUtime=50.72 /proc/10345/stat : 10345 (bmo-pblex32) R 10342 10342 9023 34817 9081 4202496 3225 0 0 0 5047 25 0 0 25 0 1 0 892915769 11440128 2400 1283457024 134512640 135887319 4291516240 18446744073709551615 134603416 0 0 0 16899 0 0 0 17 0 0 0 0 /proc/10345/statm: 2793 2400 144 336 0 2455 0 Current children cumulated CPU time (s) 51.07 Current children cumulated vsize (KiB) 13740 [startup+102.313 s] /proc/loadavg: 0.97 0.95 0.91 2/40 10345 /proc/meminfo: memFree=49888/1048576 swapFree=2095372/2097144 [pid=10342] ppid=10341 vsize=2568 CPUtime=0.35 /proc/10342/stat : 10342 (cudf2pbo4trendy) S 10341 10342 9023 34817 9081 4202496 401 2923 0 0 0 0 27 8 22 0 1 0 892915734 2629632 281 1283457024 134512640 135304128 4287093408 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0 /proc/10342/statm: 642 281 241 194 0 28 0 [pid=10345] ppid=10342 vsize=11832 CPUtime=101.86 /proc/10345/stat : 10345 (bmo-pblex32) R 10342 10342 9023 34817 9081 4202496 3404 0 0 0 10141 45 0 0 25 0 1 0 892915769 12115968 2572 1283457024 134512640 135887319 4291516240 18446744073709551615 134526496 0 0 0 16899 0 0 0 17 0 0 0 0 /proc/10345/statm: 2958 2572 144 336 0 2620 0 Current children cumulated CPU time (s) 102.21 Current children cumulated vsize (KiB) 14400 [startup+162.305 s] /proc/loadavg: 0.99 0.96 0.91 2/40 10345 /proc/meminfo: memFree=49392/1048576 swapFree=2095372/2097144 [pid=10342] ppid=10341 vsize=2568 CPUtime=0.35 /proc/10342/stat : 10342 (cudf2pbo4trendy) S 10341 10342 9023 34817 9081 4202496 401 2923 0 0 0 0 27 8 22 0 1 0 892915734 2629632 281 1283457024 134512640 135304128 4287093408 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0 /proc/10342/statm: 642 281 241 194 0 28 0 [pid=10345] ppid=10342 vsize=12164 CPUtime=161.85 /proc/10345/stat : 10345 (bmo-pblex32) R 10342 10342 9023 34817 9081 4202496 3551 0 0 0 16115 70 0 0 25 0 1 0 892915769 12455936 2662 1283457024 134512640 135887319 4291516240 18446744073709551615 134614896 0 0 0 16899 0 0 0 17 0 0 0 0 /proc/10345/statm: 3041 2662 144 336 0 2703 0 Current children cumulated CPU time (s) 162.2 Current children cumulated vsize (KiB) 14732 [startup+222.308 s] /proc/loadavg: 0.99 0.96 0.91 2/40 10345 /proc/meminfo: memFree=48524/1048576 swapFree=2095372/2097144 [pid=10342] ppid=10341 vsize=2568 CPUtime=0.35 /proc/10342/stat : 10342 (cudf2pbo4trendy) S 10341 10342 9023 34817 9081 4202496 401 2923 0 0 0 0 27 8 22 0 1 0 892915734 2629632 281 1283457024 134512640 135304128 4287093408 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0 /proc/10342/statm: 642 281 241 194 0 28 0 [pid=10345] ppid=10342 vsize=12976 CPUtime=221.83 /proc/10345/stat : 10345 (bmo-pblex32) R 10342 10342 9023 34817 9081 4202496 3769 0 0 0 22090 93 0 0 25 0 1 0 892915769 13287424 2861 1283457024 134512640 135887319 4291516240 18446744073709551615 134603619 0 0 0 16899 0 0 0 17 0 0 0 0 /proc/10345/statm: 3244 2861 144 336 0 2906 0 Current children cumulated CPU time (s) 222.18 Current children cumulated vsize (KiB) 15544 [startup+282.309 s] /proc/loadavg: 0.99 0.97 0.91 2/40 10345 /proc/meminfo: memFree=48152/1048576 swapFree=2095372/2097144 [pid=10342] ppid=10341 vsize=2568 CPUtime=0.35 /proc/10342/stat : 10342 (cudf2pbo4trendy) S 10341 10342 9023 34817 9081 4202496 401 2923 0 0 0 0 27 8 22 0 1 0 892915734 2629632 281 1283457024 134512640 135304128 4287093408 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0 /proc/10342/statm: 642 281 241 194 0 28 0 [pid=10345] ppid=10342 vsize=13372 CPUtime=281.79 /proc/10345/stat : 10345 (bmo-pblex32) R 10342 10342 9023 34817 9081 4202496 3854 0 0 0 28063 116 0 0 25 0 1 0 892915769 13692928 2946 1283457024 134512640 135887319 4291516240 18446744073709551615 134603587 0 0 0 16899 0 0 0 17 0 0 0 0 /proc/10345/statm: 3343 2946 144 336 0 3005 0 Current children cumulated CPU time (s) 282.14 Current children cumulated vsize (KiB) 15940 Maximum CPU time exceeded: sending signal-name then SIGKILL [startup+290.211 s] /proc/loadavg: 0.99 0.97 0.91 2/40 10345 /proc/meminfo: memFree=48152/1048576 swapFree=2095372/2097144 [pid=10342] ppid=10341 vsize=2568 CPUtime=0.35 /proc/10342/stat : 10342 (cudf2pbo4trendy) S 10341 10342 9023 34817 9081 4202496 401 2923 0 0 0 0 27 8 22 0 1 0 892915734 2629632 281 1283457024 134512640 135304128 4287093408 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0 /proc/10342/statm: 642 281 241 194 0 28 0 [pid=10345] ppid=10342 vsize=13372 CPUtime=289.69 /proc/10345/stat : 10345 (bmo-pblex32) R 10342 10342 9023 34817 9081 4202496 3855 0 0 0 28851 118 0 0 25 0 1 0 892915769 13692928 2947 1283457024 134512640 135887319 4291516240 18446744073709551615 134526950 0 0 0 16899 0 0 0 17 0 0 0 0 /proc/10345/statm: 3343 2947 144 336 0 3005 0 Current children cumulated CPU time (s) 290.04 Current children cumulated vsize (KiB) 15940 Sending User defined signal 1 to process tree (bottom up) Sleeping 10 seconds Solver just ended. Dumping a history of the last processes samples [startup+290.211 s] /proc/loadavg: 0.99 0.97 0.91 2/40 10345 /proc/meminfo: memFree=48152/1048576 swapFree=2095372/2097144 [pid=10342] ppid=10341 vsize=2568 CPUtime=0.35 /proc/10342/stat : 10342 (cudf2pbo4trendy) S 10341 10342 9023 34817 9081 4202496 401 2923 0 0 0 0 27 8 22 0 1 0 892915734 2629632 281 1283457024 134512640 135304128 4287093408 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0 /proc/10342/statm: 642 281 241 194 0 28 0 [pid=10345] ppid=10342 vsize=13372 CPUtime=289.69 /proc/10345/stat : 10345 (bmo-pblex32) R 10342 10342 9023 34817 9081 4202496 3855 0 0 0 28851 118 0 0 25 0 1 0 892915769 13692928 2947 1283457024 134512640 135887319 4291516240 18446744073709551615 134526950 0 0 0 16899 0 0 0 17 0 0 0 0 /proc/10345/statm: 3343 2947 144 336 0 3005 0 Current children cumulated CPU time (s) 290.04 Current children cumulated vsize (KiB) 15940 Child status: 0 Real time (s): 290.245 CPU time (s): 290.09 CPU user time (s): 288.814 CPU system time (s): 1.27608 CPU usage (%): 99.9465 Max. virtual memory (cumulated for all children) (KiB): 15940 getrusage(RUSAGE_CHILDREN,...) data: user time used= 288.814 system time used= 1.27608 maximum resident set size= 0 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 8684 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= 8 involuntary context switches= 4099 runsolver used 0 second user time and 0 second system time The end