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/rand815.sarge-etch-lenny-squeeze-sid.cudf.sarge-etch-lenny-squeeze-sid.log.runsolver ./cudf2pbo4trendy-1.0 /home/misc2010/data/icse/sarge-etch-lenny-squeeze-sid/rand815.sarge-etch-lenny-squeeze-sid.cudf /home/misc2010/tmp/201012081719/cudf2pbo4trendy-1.0/rand815.sarge-etch-lenny-squeeze-sid.cudf.sarge-etch-lenny-squeeze-sid.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.98 0.95 0.91 5/35 12202 /proc/meminfo: memFree=74136/1048576 swapFree=2095372/2097144 [pid=12201] ppid=12200 vsize=2572 CPUtime=0 /proc/12201/stat : 12201 (cudf2pbo4trendy) S 12200 12201 9023 34817 9081 4202496 382 0 0 0 0 0 0 0 18 0 1 0 893905146 2633728 278 1283457024 134512640 135304128 4287156816 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0 /proc/12201/statm: 643 278 238 194 0 29 0 [pid=12202] ppid=12201 vsize=2444 CPUtime=0.02 /proc/12202/stat : 12202 (cudf_msu32) R 12201 12201 9023 34817 9081 4202496 414 0 0 0 2 0 0 0 25 0 1 0 893905146 2502656 307 1283457024 134512640 136125367 4289707360 18446744073709551615 134717783 0 0 0 25121 0 0 0 17 0 0 0 0 /proc/12202/statm: 611 307 141 394 0 215 0 [startup+0.183674 s] /proc/loadavg: 0.98 0.95 0.91 5/35 12202 /proc/meminfo: memFree=74136/1048576 swapFree=2095372/2097144 [pid=12201] ppid=12200 vsize=2572 CPUtime=0 /proc/12201/stat : 12201 (cudf2pbo4trendy) S 12200 12201 9023 34817 9081 4202496 382 0 0 0 0 0 0 0 18 0 1 0 893905146 2633728 278 1283457024 134512640 135304128 4287156816 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0 /proc/12201/statm: 643 278 238 194 0 29 0 [pid=12202] ppid=12201 vsize=9632 CPUtime=0.18 /proc/12202/stat : 12202 (cudf_msu32) R 12201 12201 9023 34817 9081 4202496 2211 0 0 0 18 0 0 0 25 0 1 0 893905146 9863168 2104 1283457024 134512640 136125367 4289707360 18446744073709551615 134717747 0 0 0 25121 0 0 0 17 0 0 0 0 /proc/12202/statm: 2408 2104 142 394 0 2012 0 Current children cumulated CPU time (s) 0.18 Current children cumulated vsize (KiB) 12204 [startup+0.213689 s] /proc/loadavg: 0.98 0.95 0.91 5/35 12202 /proc/meminfo: memFree=74136/1048576 swapFree=2095372/2097144 [pid=12201] ppid=12200 vsize=2572 CPUtime=0 /proc/12201/stat : 12201 (cudf2pbo4trendy) S 12200 12201 9023 34817 9081 4202496 382 0 0 0 0 0 0 0 18 0 1 0 893905146 2633728 278 1283457024 134512640 135304128 4287156816 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0 /proc/12201/statm: 643 278 238 194 0 29 0 [pid=12202] ppid=12201 vsize=10620 CPUtime=0.22 /proc/12202/stat : 12202 (cudf_msu32) R 12201 12201 9023 34817 9081 4202496 2470 0 0 0 22 0 0 0 25 0 1 0 893905146 10874880 2363 1283457024 134512640 136125367 4289707360 18446744073709551615 135543652 0 0 0 25121 0 0 0 17 0 0 0 0 /proc/12202/statm: 2655 2363 143 394 0 2259 0 Current children cumulated CPU time (s) 0.22 Current children cumulated vsize (KiB) 13192 [startup+0.303695 s] /proc/loadavg: 0.98 0.95 0.91 5/35 12202 /proc/meminfo: memFree=74136/1048576 swapFree=2095372/2097144 [pid=12201] ppid=12200 vsize=2572 CPUtime=0 /proc/12201/stat : 12201 (cudf2pbo4trendy) S 12200 12201 9023 34817 9081 4202496 382 0 0 0 0 0 0 0 18 0 1 0 893905146 2633728 278 1283457024 134512640 135304128 4287156816 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0 /proc/12201/statm: 643 278 238 194 0 29 0 [pid=12202] ppid=12201 vsize=13788 CPUtime=0.3 /proc/12202/stat : 12202 (cudf_msu32) R 12201 12201 9023 34817 9081 4202496 3267 0 0 0 30 0 0 0 25 0 1 0 893905146 14118912 3160 1283457024 134512640 136125367 4289707360 18446744073709551615 134717719 0 0 0 25121 0 0 0 17 0 0 0 0 /proc/12202/statm: 3447 3160 143 394 0 3051 0 Current children cumulated CPU time (s) 0.3 Current children cumulated vsize (KiB) 16360 [startup+0.703761 s] /proc/loadavg: 0.98 0.95 0.91 5/35 12202 /proc/meminfo: memFree=74136/1048576 swapFree=2095372/2097144 [pid=12201] ppid=12200 vsize=2572 CPUtime=0 /proc/12201/stat : 12201 (cudf2pbo4trendy) S 12200 12201 9023 34817 9081 4202496 382 0 0 0 0 0 0 0 18 0 1 0 893905146 2633728 278 1283457024 134512640 135304128 4287156816 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0 /proc/12201/statm: 643 278 238 194 0 29 0 [pid=12202] ppid=12201 vsize=25996 CPUtime=0.7 /proc/12202/stat : 12202 (cudf_msu32) R 12201 12201 9023 34817 9081 4202496 6318 0 0 0 70 0 0 0 25 0 1 0 893905146 26619904 6211 1283457024 134512640 136125367 4289707360 18446744073709551615 134717932 0 0 0 25121 0 0 0 17 0 0 0 0 /proc/12202/statm: 6499 6211 143 394 0 6103 0 Current children cumulated CPU time (s) 0.7 Current children cumulated vsize (KiB) 28568 [startup+1.50388 s] /proc/loadavg: 0.98 0.95 0.91 2/36 12203 /proc/meminfo: memFree=39620/1048576 swapFree=2095372/2097144 [pid=12201] ppid=12200 vsize=2572 CPUtime=0 /proc/12201/stat : 12201 (cudf2pbo4trendy) S 12200 12201 9023 34817 9081 4202496 382 0 0 0 0 0 0 0 18 0 1 0 893905146 2633728 278 1283457024 134512640 135304128 4287156816 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0 /proc/12201/statm: 643 278 238 194 0 29 0 [pid=12202] ppid=12201 vsize=52512 CPUtime=1.5 /proc/12202/stat : 12202 (cudf_msu32) R 12201 12201 9023 34817 9081 4202496 12867 0 0 0 144 6 0 0 25 0 1 0 893905146 53772288 12710 1283457024 134512640 136125367 4289707360 18446744073709551615 134610324 0 0 0 25121 0 0 0 17 0 0 0 0 /proc/12202/statm: 13128 12710 160 394 0 12732 0 Current children cumulated CPU time (s) 1.5 Current children cumulated vsize (KiB) 55084 [startup+3.10796 s] /proc/loadavg: 0.98 0.95 0.91 2/36 12203 /proc/meminfo: memFree=13332/1048576 swapFree=2095372/2097144 [pid=12201] ppid=12200 vsize=2572 CPUtime=2.42 /proc/12201/stat : 12201 (cudf2pbo4trendy) S 12200 12201 9023 34817 9081 4202496 402 14908 0 0 0 0 200 42 20 0 1 0 893905146 2633728 281 1283457024 134512640 135304128 4287156816 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0 /proc/12201/statm: 643 281 241 194 0 29 0 Current children cumulated CPU time (s) 2.42 Current children cumulated vsize (KiB) 2572 heavy processes: [startup+6.30861 s] /proc/loadavg: 0.98 0.95 0.91 2/36 12204 /proc/meminfo: memFree=41976/1048576 swapFree=2095372/2097144 [pid=12201] ppid=12200 vsize=2572 CPUtime=2.42 /proc/12201/stat : 12201 (cudf2pbo4trendy) S 12200 12201 9023 34817 9081 4202496 402 14908 0 0 0 0 200 42 20 0 1 0 893905146 2633728 281 1283457024 134512640 135304128 4287156816 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0 /proc/12201/statm: 643 281 241 194 0 29 0 [pid=12204] ppid=12201 vsize=29932 CPUtime=3.85 /proc/12204/stat : 12204 (bmo-pblex32) R 12201 12201 9023 34817 9081 4202496 7875 0 0 0 287 98 0 0 25 0 1 0 893905389 30650368 7016 1283457024 134512640 135887319 4291659584 18446744073709551615 134614964 0 0 0 16899 0 0 0 17 0 0 0 0 /proc/12204/statm: 7483 7016 138 336 0 7145 0 Current children cumulated CPU time (s) 6.27 Current children cumulated vsize (KiB) 32504 [startup+12.7101 s] /proc/loadavg: 0.98 0.95 0.91 2/36 12204 /proc/meminfo: memFree=23384/1048576 swapFree=2095372/2097144 [pid=12201] ppid=12200 vsize=2572 CPUtime=2.42 /proc/12201/stat : 12201 (cudf2pbo4trendy) S 12200 12201 9023 34817 9081 4202496 402 14908 0 0 0 0 200 42 20 0 1 0 893905146 2633728 281 1283457024 134512640 135304128 4287156816 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0 /proc/12201/statm: 643 281 241 194 0 29 0 [pid=12204] ppid=12201 vsize=56660 CPUtime=10.25 /proc/12204/stat : 12204 (bmo-pblex32) R 12201 12201 9023 34817 9081 4202496 19270 0 0 0 796 229 0 0 25 0 1 0 893905389 58019840 13717 1283457024 134512640 135887319 4291659584 18446744073709551615 134598515 0 0 0 16899 0 0 0 17 0 0 0 0 /proc/12204/statm: 14165 13717 144 336 0 13827 0 Current children cumulated CPU time (s) 12.67 Current children cumulated vsize (KiB) 59232 [startup+25.5138 s] /proc/loadavg: 1.07 0.97 0.91 2/36 12204 /proc/meminfo: memFree=9124/1048576 swapFree=2095372/2097144 [pid=12201] ppid=12200 vsize=2572 CPUtime=2.42 /proc/12201/stat : 12201 (cudf2pbo4trendy) S 12200 12201 9023 34817 9081 4202496 402 14908 0 0 0 0 200 42 20 0 1 0 893905146 2633728 281 1283457024 134512640 135304128 4287156816 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0 /proc/12201/statm: 643 281 241 194 0 29 0 [pid=12204] ppid=12201 vsize=62592 CPUtime=23.03 /proc/12204/stat : 12204 (bmo-pblex32) R 12201 12201 9023 34817 9081 4202496 20839 0 0 0 1998 305 0 0 25 0 1 0 893905389 64094208 15210 1283457024 134512640 135887319 4291659584 18446744073709551615 134603584 0 0 0 16899 0 0 0 17 0 0 0 0 /proc/12204/statm: 15648 15210 144 336 0 15310 0 Current children cumulated CPU time (s) 25.45 Current children cumulated vsize (KiB) 65164 [startup+51.1097 s] /proc/loadavg: 1.04 0.97 0.91 2/36 12204 /proc/meminfo: memFree=7264/1048576 swapFree=2095372/2097144 [pid=12201] ppid=12200 vsize=2572 CPUtime=2.42 /proc/12201/stat : 12201 (cudf2pbo4trendy) S 12200 12201 9023 34817 9081 4202496 402 14908 0 0 0 0 200 42 20 0 1 0 893905146 2633728 281 1283457024 134512640 135304128 4287156816 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0 /proc/12201/statm: 643 281 241 194 0 29 0 [pid=12204] ppid=12201 vsize=64592 CPUtime=48.61 /proc/12204/stat : 12204 (bmo-pblex32) R 12201 12201 9023 34817 9081 4202496 21358 0 0 0 4552 309 0 0 25 0 1 0 893905389 66142208 15703 1283457024 134512640 135887319 4291659584 18446744073709551615 134614964 0 0 0 16899 0 0 0 17 0 0 0 0 /proc/12204/statm: 16148 15703 144 336 0 15810 0 Current children cumulated CPU time (s) 51.03 Current children cumulated vsize (KiB) 67164 [startup+102.314 s] /proc/loadavg: 1.02 0.97 0.91 2/36 12204 /proc/meminfo: memFree=5608/1048576 swapFree=2095372/2097144 [pid=12201] ppid=12200 vsize=2572 CPUtime=2.42 /proc/12201/stat : 12201 (cudf2pbo4trendy) S 12200 12201 9023 34817 9081 4202496 402 14908 0 0 0 0 200 42 20 0 1 0 893905146 2633728 281 1283457024 134512640 135304128 4287156816 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0 /proc/12201/statm: 643 281 241 194 0 29 0 [pid=12204] ppid=12201 vsize=67544 CPUtime=99.77 /proc/12204/stat : 12204 (bmo-pblex32) R 12201 12201 9023 34817 9081 4202496 22129 0 0 0 9666 311 0 0 25 0 1 0 893905389 69165056 16457 1283457024 134512640 135887319 4291659584 18446744073709551615 134603626 0 0 0 16899 0 0 0 17 0 0 0 0 /proc/12204/statm: 16886 16457 144 336 0 16548 0 Current children cumulated CPU time (s) 102.19 Current children cumulated vsize (KiB) 70116 [startup+162.307 s] /proc/loadavg: 1.00 0.97 0.91 2/36 12204 /proc/meminfo: memFree=5468/1048576 swapFree=2095372/2097144 [pid=12201] ppid=12200 vsize=2572 CPUtime=2.42 /proc/12201/stat : 12201 (cudf2pbo4trendy) S 12200 12201 9023 34817 9081 4202496 402 14908 0 0 0 0 200 42 20 0 1 0 893905146 2633728 281 1283457024 134512640 135304128 4287156816 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0 /proc/12201/statm: 643 281 241 194 0 29 0 [pid=12204] ppid=12201 vsize=70052 CPUtime=159.74 /proc/12204/stat : 12204 (bmo-pblex32) R 12201 12201 9023 34817 9081 4202496 22743 0 0 0 15657 317 0 0 25 0 1 0 893905389 71733248 17066 1283457024 134512640 135887319 4291659584 18446744073709551615 134525296 0 0 0 16899 0 0 0 17 0 0 0 0 /proc/12204/statm: 17513 17066 144 336 0 17175 0 Current children cumulated CPU time (s) 162.16 Current children cumulated vsize (KiB) 72624 [startup+222.312 s] /proc/loadavg: 1.00 0.97 0.91 2/36 12204 /proc/meminfo: memFree=5736/1048576 swapFree=2095372/2097144 [pid=12201] ppid=12200 vsize=2572 CPUtime=2.42 /proc/12201/stat : 12201 (cudf2pbo4trendy) S 12200 12201 9023 34817 9081 4202496 402 14908 0 0 0 0 200 42 20 0 1 0 893905146 2633728 281 1283457024 134512640 135304128 4287156816 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0 /proc/12201/statm: 643 281 241 194 0 29 0 [pid=12204] ppid=12201 vsize=74540 CPUtime=219.69 /proc/12204/stat : 12204 (bmo-pblex32) R 12201 12201 9023 34817 9081 4202496 23905 0 0 0 21647 322 0 0 25 0 1 0 893905389 76328960 18217 1283457024 134512640 135887319 4291659584 18446744073709551615 134603584 0 0 0 16899 0 0 0 17 0 0 0 0 /proc/12204/statm: 18635 18217 144 336 0 18297 0 Current children cumulated CPU time (s) 222.11 Current children cumulated vsize (KiB) 77112 [startup+282.309 s] /proc/loadavg: 1.00 0.97 0.91 2/36 12204 /proc/meminfo: memFree=5828/1048576 swapFree=2095372/2097144 [pid=12201] ppid=12200 vsize=2572 CPUtime=2.42 /proc/12201/stat : 12201 (cudf2pbo4trendy) S 12200 12201 9023 34817 9081 4202496 402 14908 0 0 0 0 200 42 20 0 1 0 893905146 2633728 281 1283457024 134512640 135304128 4287156816 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0 /proc/12201/statm: 643 281 241 194 0 29 0 [pid=12204] ppid=12201 vsize=81164 CPUtime=279.62 /proc/12204/stat : 12204 (bmo-pblex32) R 12201 12201 9023 34817 9081 4202496 25590 0 0 0 27634 328 0 0 25 0 1 0 893905389 83111936 19865 1283457024 134512640 135887319 4291659584 18446744073709551615 134603626 0 0 0 16899 0 0 0 17 0 0 0 0 /proc/12204/statm: 20291 19865 144 336 0 19953 0 Current children cumulated CPU time (s) 282.04 Current children cumulated vsize (KiB) 83736 Maximum CPU time exceeded: sending signal-name then SIGKILL [startup+290.311 s] /proc/loadavg: 1.00 0.97 0.91 2/36 12204 /proc/meminfo: memFree=5208/1048576 swapFree=2095372/2097144 [pid=12201] ppid=12200 vsize=2572 CPUtime=2.42 /proc/12201/stat : 12201 (cudf2pbo4trendy) S 12200 12201 9023 34817 9081 4202496 402 14908 0 0 0 0 200 42 20 0 1 0 893905146 2633728 281 1283457024 134512640 135304128 4287156816 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0 /proc/12201/statm: 643 281 241 194 0 29 0 [pid=12204] ppid=12201 vsize=81692 CPUtime=287.62 /proc/12204/stat : 12204 (bmo-pblex32) R 12201 12201 9023 34817 9081 4202496 25723 0 0 0 28433 329 0 0 25 0 1 0 893905389 83652608 19998 1283457024 134512640 135887319 4291659584 18446744073709551615 134526502 0 0 0 16899 0 0 0 17 0 0 0 0 /proc/12204/statm: 20423 19998 144 336 0 20085 0 Current children cumulated CPU time (s) 290.04 Current children cumulated vsize (KiB) 84264 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.422 CPU time (s): 290.158 CPU user time (s): 286.422 CPU system time (s): 3.73623 CPU usage (%): 99.9093 Max. virtual memory (cumulated for all children) (KiB): 84264 getrusage(RUSAGE_CHILDREN,...) data: user time used= 286.422 system time used= 3.73623 maximum resident set size= 0 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 43247 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= 20 involuntary context switches= 7342 runsolver used 0 second user time and 0 second system time The end