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/rand6b4d6e.cudf.impossible.log.runsolver ./cudf2pbo4trendy-1.0 /home/misc2010/data/2010/impossible//rand6b4d6e.cudf /home/misc2010/tmp/201012081719/cudf2pbo4trendy-1.0/rand6b4d6e.cudf.impossible.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/39 10943 /proc/meminfo: memFree=64744/1048576 swapFree=2095372/2097144 [pid=10942] ppid=10941 vsize=2572 CPUtime=0 /proc/10942/stat : 10942 (cudf2pbo4trendy) S 10941 10942 9023 34817 9081 4202496 383 0 0 0 0 0 0 0 18 0 1 0 893286964 2633728 279 1283457024 134512640 135304128 4287837008 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0 /proc/10942/statm: 643 279 238 194 0 29 0 [pid=10943] ppid=10942 vsize=2572 CPUtime=0.02 /proc/10943/stat : 10943 (cudf_msu32) R 10942 10942 9023 34817 9081 4202496 438 0 0 0 2 0 0 0 25 0 1 0 893286964 2633728 330 1283457024 134512640 136125367 4294513184 18446744073709551615 134718286 0 0 0 25121 0 0 0 17 0 0 0 0 /proc/10943/statm: 643 330 141 394 0 247 0 [startup+0.165359 s] /proc/loadavg: 0.98 0.95 0.91 5/39 10943 /proc/meminfo: memFree=64744/1048576 swapFree=2095372/2097144 [pid=10942] ppid=10941 vsize=2572 CPUtime=0 /proc/10942/stat : 10942 (cudf2pbo4trendy) S 10941 10942 9023 34817 9081 4202496 383 0 0 0 0 0 0 0 18 0 1 0 893286964 2633728 279 1283457024 134512640 135304128 4287837008 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0 /proc/10942/statm: 643 279 238 194 0 29 0 [pid=10943] ppid=10942 vsize=8704 CPUtime=0.16 /proc/10943/stat : 10943 (cudf_msu32) R 10942 10942 9023 34817 9081 4202496 1971 0 0 0 15 1 0 0 25 0 1 0 893286964 8912896 1863 1283457024 134512640 136125367 4294513184 18446744073709551615 135549888 0 0 0 25121 0 0 0 17 0 0 0 0 /proc/10943/statm: 2176 1863 142 394 0 1780 0 Current children cumulated CPU time (s) 0.16 Current children cumulated vsize (KiB) 11276 [startup+0.205367 s] /proc/loadavg: 0.98 0.95 0.91 5/39 10943 /proc/meminfo: memFree=64744/1048576 swapFree=2095372/2097144 [pid=10942] ppid=10941 vsize=2572 CPUtime=0 /proc/10942/stat : 10942 (cudf2pbo4trendy) S 10941 10942 9023 34817 9081 4202496 383 0 0 0 0 0 0 0 18 0 1 0 893286964 2633728 279 1283457024 134512640 135304128 4287837008 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0 /proc/10942/statm: 643 279 238 194 0 29 0 [pid=10943] ppid=10942 vsize=10024 CPUtime=0.2 /proc/10943/stat : 10943 (cudf_msu32) R 10942 10942 9023 34817 9081 4202496 2324 0 0 0 19 1 0 0 25 0 1 0 893286964 10264576 2216 1283457024 134512640 136125367 4294513184 18446744073709551615 134717743 0 0 0 25121 0 0 0 17 0 0 0 0 /proc/10943/statm: 2506 2216 142 394 0 2110 0 Current children cumulated CPU time (s) 0.2 Current children cumulated vsize (KiB) 12596 [startup+0.305385 s] /proc/loadavg: 0.98 0.95 0.91 5/39 10943 /proc/meminfo: memFree=64744/1048576 swapFree=2095372/2097144 [pid=10942] ppid=10941 vsize=2572 CPUtime=0 /proc/10942/stat : 10942 (cudf2pbo4trendy) S 10941 10942 9023 34817 9081 4202496 383 0 0 0 0 0 0 0 18 0 1 0 893286964 2633728 279 1283457024 134512640 135304128 4287837008 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0 /proc/10942/statm: 643 279 238 194 0 29 0 [pid=10943] ppid=10942 vsize=13612 CPUtime=0.3 /proc/10943/stat : 10943 (cudf_msu32) R 10942 10942 9023 34817 9081 4202496 3216 0 0 0 29 1 0 0 25 0 1 0 893286964 13938688 3108 1283457024 134512640 136125367 4294513184 18446744073709551615 135543652 0 0 0 25121 0 0 0 17 0 0 0 0 /proc/10943/statm: 3403 3108 143 394 0 3007 0 Current children cumulated CPU time (s) 0.3 Current children cumulated vsize (KiB) 16184 [startup+0.705462 s] /proc/loadavg: 0.98 0.95 0.91 5/39 10943 /proc/meminfo: memFree=64744/1048576 swapFree=2095372/2097144 [pid=10942] ppid=10941 vsize=2572 CPUtime=0 /proc/10942/stat : 10942 (cudf2pbo4trendy) S 10941 10942 9023 34817 9081 4202496 383 0 0 0 0 0 0 0 18 0 1 0 893286964 2633728 279 1283457024 134512640 135304128 4287837008 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0 /proc/10942/statm: 643 279 238 194 0 29 0 [pid=10943] ppid=10942 vsize=25688 CPUtime=0.7 /proc/10943/stat : 10943 (cudf_msu32) R 10942 10942 9023 34817 9081 4202496 6233 0 0 0 68 2 0 0 25 0 1 0 893286964 26304512 6125 1283457024 134512640 136125367 4294513184 18446744073709551615 134738054 0 0 0 25121 0 0 0 17 0 0 0 0 /proc/10943/statm: 6422 6125 143 394 0 6026 0 Current children cumulated CPU time (s) 0.7 Current children cumulated vsize (KiB) 28260 [startup+1.50564 s] /proc/loadavg: 0.98 0.95 0.91 2/40 10944 /proc/meminfo: memFree=30800/1048576 swapFree=2095372/2097144 [pid=10942] ppid=10941 vsize=2572 CPUtime=0 /proc/10942/stat : 10942 (cudf2pbo4trendy) S 10941 10942 9023 34817 9081 4202496 383 0 0 0 0 0 0 0 18 0 1 0 893286964 2633728 279 1283457024 134512640 135304128 4287837008 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0 /proc/10942/statm: 643 279 238 194 0 29 0 [pid=10943] ppid=10942 vsize=46108 CPUtime=1.5 /proc/10943/stat : 10943 (cudf_msu32) R 10942 10942 9023 34817 9081 4202496 11406 0 0 0 142 8 0 0 25 0 1 0 893286964 47214592 11249 1283457024 134512640 136125367 4294513184 18446744073709551615 135594622 0 0 0 25121 0 0 0 17 0 0 0 0 /proc/10943/statm: 11527 11249 153 394 0 11131 0 Current children cumulated CPU time (s) 1.5 Current children cumulated vsize (KiB) 48680 [startup+3.10592 s] /proc/loadavg: 0.98 0.95 0.91 2/40 10944 /proc/meminfo: memFree=5976/1048576 swapFree=2095372/2097144 [pid=10942] ppid=10941 vsize=2572 CPUtime=0 /proc/10942/stat : 10942 (cudf2pbo4trendy) S 10941 10942 9023 34817 9081 4202496 383 0 0 0 0 0 0 0 18 0 1 0 893286964 2633728 279 1283457024 134512640 135304128 4287837008 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0 /proc/10942/statm: 643 279 238 194 0 29 0 [pid=10943] ppid=10942 vsize=73904 CPUtime=3.09 /proc/10943/stat : 10943 (cudf_msu32) R 10942 10942 9023 34817 9081 4202496 18667 0 0 0 244 65 0 0 25 0 1 0 893286964 75677696 18215 1283457024 134512640 136125367 4294513184 18446744073709551615 135594622 0 0 0 25121 0 0 0 17 0 0 0 0 /proc/10943/statm: 18476 18215 165 394 0 18080 0 Current children cumulated CPU time (s) 3.09 Current children cumulated vsize (KiB) 76476 [startup+6.30677 s] /proc/loadavg: 0.98 0.95 0.91 2/40 10945 /proc/meminfo: memFree=42560/1048576 swapFree=2095372/2097144 [pid=10942] ppid=10941 vsize=2572 CPUtime=3.17 /proc/10942/stat : 10942 (cudf2pbo4trendy) S 10941 10942 9023 34817 9081 4202496 403 18669 0 0 0 0 251 66 20 0 1 0 893286964 2633728 282 1283457024 134512640 135304128 4287837008 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0 /proc/10942/statm: 643 282 241 194 0 29 0 [pid=10945] ppid=10942 vsize=37276 CPUtime=3.11 /proc/10945/stat : 10945 (bmo-pblex32) R 10942 10942 9023 34817 9081 4202496 9846 0 0 0 237 74 0 0 25 0 1 0 893287282 38170624 8923 1283457024 134512640 135887319 4290022880 18446744073709551615 134614896 0 0 0 16899 0 0 0 17 0 0 0 0 /proc/10945/statm: 9319 8923 138 336 0 8981 0 Current children cumulated CPU time (s) 6.28 Current children cumulated vsize (KiB) 39848 [startup+12.7041 s] /proc/loadavg: 0.98 0.95 0.91 2/40 10945 /proc/meminfo: memFree=28920/1048576 swapFree=2095372/2097144 [pid=10942] ppid=10941 vsize=2572 CPUtime=3.17 /proc/10942/stat : 10942 (cudf2pbo4trendy) S 10941 10942 9023 34817 9081 4202496 403 18669 0 0 0 0 251 66 20 0 1 0 893286964 2633728 282 1283457024 134512640 135304128 4287837008 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0 /proc/10942/statm: 643 282 241 194 0 29 0 [pid=10945] ppid=10942 vsize=50896 CPUtime=9.4 /proc/10945/stat : 10945 (bmo-pblex32) R 10942 10942 9023 34817 9081 4202496 15124 0 0 0 706 234 0 0 25 0 1 0 893287282 52117504 12336 1283457024 134512640 135887319 4290022880 18446744073709551615 134614964 0 0 0 16899 0 0 0 17 0 0 0 0 /proc/10945/statm: 12724 12336 144 336 0 12386 0 Current children cumulated CPU time (s) 12.57 Current children cumulated vsize (KiB) 53468 [startup+25.5071 s] /proc/loadavg: 0.98 0.95 0.91 2/40 10945 /proc/meminfo: memFree=6248/1048576 swapFree=2095372/2097144 [pid=10942] ppid=10941 vsize=2572 CPUtime=3.17 /proc/10942/stat : 10942 (cudf2pbo4trendy) S 10941 10942 9023 34817 9081 4202496 403 18669 0 0 0 0 251 66 20 0 1 0 893286964 2633728 282 1283457024 134512640 135304128 4287837008 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0 /proc/10942/statm: 643 282 241 194 0 29 0 [pid=10945] ppid=10942 vsize=78196 CPUtime=22.17 /proc/10945/stat : 10945 (bmo-pblex32) R 10942 10942 9023 34817 9081 4202496 26938 0 0 0 1776 441 0 0 25 0 1 0 893287282 80072704 19227 1283457024 134512640 135887319 4290022880 18446744073709551615 134598528 0 0 0 16899 0 0 0 17 0 0 0 0 /proc/10945/statm: 19549 19227 144 336 0 19211 0 Current children cumulated CPU time (s) 25.34 Current children cumulated vsize (KiB) 80768 [startup+51.1115 s] /proc/loadavg: 0.99 0.96 0.91 2/40 10945 /proc/meminfo: memFree=6136/1048576 swapFree=2095372/2097144 [pid=10942] ppid=10941 vsize=2572 CPUtime=3.17 /proc/10942/stat : 10942 (cudf2pbo4trendy) S 10941 10942 9023 34817 9081 4202496 403 18669 0 0 0 0 251 66 20 0 1 0 893286964 2633728 282 1283457024 134512640 135304128 4287837008 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0 /proc/10942/statm: 643 282 241 194 0 29 0 [pid=10945] ppid=10942 vsize=90956 CPUtime=47.67 /proc/10945/stat : 10945 (bmo-pblex32) R 10942 10942 9023 34817 9081 4202496 30155 0 0 0 4058 709 0 0 25 0 1 0 893287282 93138944 22417 1283457024 134512640 135887319 4290022880 18446744073709551615 134603607 0 0 0 16899 0 0 0 17 0 0 0 0 /proc/10945/statm: 22739 22417 144 336 0 22401 0 Current children cumulated CPU time (s) 50.84 Current children cumulated vsize (KiB) 93528 [startup+102.307 s] /proc/loadavg: 0.99 0.96 0.91 2/40 10945 /proc/meminfo: memFree=6328/1048576 swapFree=2095372/2097144 [pid=10942] ppid=10941 vsize=2572 CPUtime=3.17 /proc/10942/stat : 10942 (cudf2pbo4trendy) S 10941 10942 9023 34817 9081 4202496 403 18669 0 0 0 0 251 66 20 0 1 0 893286964 2633728 282 1283457024 134512640 135304128 4287837008 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0 /proc/10942/statm: 643 282 241 194 0 29 0 [pid=10945] ppid=10942 vsize=96116 CPUtime=98.85 /proc/10945/stat : 10945 (bmo-pblex32) R 10942 10942 9023 34817 9081 4202496 31521 0 0 0 9164 721 0 0 25 0 1 0 893287282 98422784 23715 1283457024 134512640 135887319 4290022880 18446744073709551615 134614964 0 0 0 16899 0 0 0 17 0 0 0 0 /proc/10945/statm: 24029 23715 144 336 0 23691 0 Current children cumulated CPU time (s) 102.02 Current children cumulated vsize (KiB) 98688 Solver just ended. Dumping a history of the last processes samples [startup+102.407 s] /proc/loadavg: 0.99 0.96 0.91 2/40 10945 /proc/meminfo: memFree=6328/1048576 swapFree=2095372/2097144 [pid=10942] ppid=10941 vsize=2572 CPUtime=3.17 /proc/10942/stat : 10942 (cudf2pbo4trendy) S 10941 10942 9023 34817 9081 4202496 403 18669 0 0 0 0 251 66 20 0 1 0 893286964 2633728 282 1283457024 134512640 135304128 4287837008 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0 /proc/10942/statm: 643 282 241 194 0 29 0 [pid=10945] ppid=10942 vsize=96116 CPUtime=98.95 /proc/10945/stat : 10945 (bmo-pblex32) R 10942 10942 9023 34817 9081 4202496 31523 0 0 0 9174 721 0 0 25 0 1 0 893287282 98422784 23717 1283457024 134512640 135887319 4290022880 18446744073709551615 134614964 0 0 0 16899 0 0 0 17 0 0 0 0 /proc/10945/statm: 24029 23717 144 336 0 23691 0 Current children cumulated CPU time (s) 102.12 Current children cumulated vsize (KiB) 98688 [startup+115.211 s] /proc/loadavg: 0.99 0.96 0.91 2/40 10945 /proc/meminfo: memFree=6228/1048576 swapFree=2095372/2097144 [pid=10942] ppid=10941 vsize=2572 CPUtime=3.17 /proc/10942/stat : 10942 (cudf2pbo4trendy) S 10941 10942 9023 34817 9081 4202496 403 18669 0 0 0 0 251 66 20 0 1 0 893286964 2633728 282 1283457024 134512640 135304128 4287837008 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0 /proc/10942/statm: 643 282 241 194 0 29 0 [pid=10945] ppid=10942 vsize=97304 CPUtime=111.74 /proc/10945/stat : 10945 (bmo-pblex32) R 10942 10942 9023 34817 9081 4202496 31834 0 0 0 10451 723 0 0 25 0 1 0 893287282 99639296 24025 1283457024 134512640 135887319 4290022880 18446744073709551615 134614964 0 0 0 16899 0 0 0 17 0 0 0 0 /proc/10945/statm: 24326 24025 144 336 0 23988 0 Current children cumulated CPU time (s) 114.91 Current children cumulated vsize (KiB) 99876 [startup+121.612 s] /proc/loadavg: 0.99 0.96 0.91 2/40 10945 /proc/meminfo: memFree=5608/1048576 swapFree=2095372/2097144 [pid=10942] ppid=10941 vsize=2572 CPUtime=3.17 /proc/10942/stat : 10942 (cudf2pbo4trendy) S 10941 10942 9023 34817 9081 4202496 403 18669 0 0 0 0 251 66 20 0 1 0 893286964 2633728 282 1283457024 134512640 135304128 4287837008 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0 /proc/10942/statm: 643 282 241 194 0 29 0 [pid=10945] ppid=10942 vsize=97964 CPUtime=118.14 /proc/10945/stat : 10945 (bmo-pblex32) R 10942 10942 9023 34817 9081 4202496 31999 0 0 0 11088 726 0 0 25 0 1 0 893287282 100315136 24188 1283457024 134512640 135887319 4290022880 18446744073709551615 134614964 0 0 0 16899 0 0 0 17 0 0 0 0 /proc/10945/statm: 24491 24188 144 336 0 24153 0 Current children cumulated CPU time (s) 121.31 Current children cumulated vsize (KiB) 100536 [startup+124.813 s] /proc/loadavg: 0.99 0.96 0.91 2/40 10945 /proc/meminfo: memFree=5236/1048576 swapFree=2095372/2097144 [pid=10942] ppid=10941 vsize=2572 CPUtime=3.17 /proc/10942/stat : 10942 (cudf2pbo4trendy) S 10941 10942 9023 34817 9081 4202496 403 18669 0 0 0 0 251 66 20 0 1 0 893286964 2633728 282 1283457024 134512640 135304128 4287837008 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0 /proc/10942/statm: 643 282 241 194 0 29 0 [pid=10945] ppid=10942 vsize=98360 CPUtime=121.34 /proc/10945/stat : 10945 (bmo-pblex32) R 10942 10942 9023 34817 9081 4202496 32106 0 0 0 11408 726 0 0 25 0 1 0 893287282 100720640 24281 1283457024 134512640 135887319 4290022880 18446744073709551615 134614964 0 0 0 16899 0 0 0 17 0 0 0 0 /proc/10945/statm: 24590 24281 144 336 0 24252 0 Current children cumulated CPU time (s) 124.51 Current children cumulated vsize (KiB) 100932 [startup+125.613 s] /proc/loadavg: 0.99 0.96 0.91 2/40 10945 /proc/meminfo: memFree=6252/1048576 swapFree=2095372/2097144 [pid=10942] ppid=10941 vsize=2572 CPUtime=3.17 /proc/10942/stat : 10942 (cudf2pbo4trendy) S 10941 10942 9023 34817 9081 4202496 403 18669 0 0 0 0 251 66 20 0 1 0 893286964 2633728 282 1283457024 134512640 135304128 4287837008 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0 /proc/10942/statm: 643 282 241 194 0 29 0 [pid=10945] ppid=10942 vsize=98492 CPUtime=122.13 /proc/10945/stat : 10945 (bmo-pblex32) R 10942 10942 9023 34817 9081 4202496 32137 0 0 0 11487 726 0 0 25 0 1 0 893287282 100855808 24312 1283457024 134512640 135887319 4290022880 18446744073709551615 134614896 0 0 0 16899 0 0 0 17 0 0 0 0 /proc/10945/statm: 24623 24312 144 336 0 24285 0 Current children cumulated CPU time (s) 125.3 Current children cumulated vsize (KiB) 101064 [startup+126.014 s] /proc/loadavg: 0.99 0.96 0.91 2/40 10945 /proc/meminfo: memFree=6252/1048576 swapFree=2095372/2097144 [pid=10942] ppid=10941 vsize=2572 CPUtime=3.17 /proc/10942/stat : 10942 (cudf2pbo4trendy) S 10941 10942 9023 34817 9081 4202496 403 18669 0 0 0 0 251 66 20 0 1 0 893286964 2633728 282 1283457024 134512640 135304128 4287837008 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0 /proc/10942/statm: 643 282 241 194 0 29 0 [pid=10945] ppid=10942 vsize=98624 CPUtime=122.53 /proc/10945/stat : 10945 (bmo-pblex32) R 10942 10942 9023 34817 9081 4202496 32154 0 0 0 11527 726 0 0 25 0 1 0 893287282 100990976 24329 1283457024 134512640 135887319 4290022880 18446744073709551615 134614962 0 0 0 16899 0 0 0 17 0 0 0 0 /proc/10945/statm: 24656 24329 144 336 0 24318 0 Current children cumulated CPU time (s) 125.7 Current children cumulated vsize (KiB) 101196 [startup+126.214 s] /proc/loadavg: 0.99 0.96 0.91 2/40 10945 /proc/meminfo: memFree=6252/1048576 swapFree=2095372/2097144 [pid=10942] ppid=10941 vsize=2572 CPUtime=125.79 /proc/10942/stat : 10942 (cudf2pbo4trendy) S 10941 10942 9023 34817 9081 4202496 434 51269 0 0 0 0 11786 793 21 0 1 0 893286964 2633728 282 1283457024 134512640 135304128 4287837008 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0 /proc/10942/statm: 643 282 241 194 0 29 0 Current children cumulated CPU time (s) 125.79 Current children cumulated vsize (KiB) 2572 Child status: 0 Real time (s): 126.228 CPU time (s): 125.92 CPU user time (s): 117.979 CPU system time (s): 7.9405 CPU usage (%): 99.7555 Max. virtual memory (cumulated for all children) (KiB): 101196 getrusage(RUSAGE_CHILDREN,...) data: user time used= 117.979 system time used= 7.9405 maximum resident set size= 0 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 53660 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= 27 involuntary context switches= 10290 runsolver used 0 second user time and 0 second system time The end