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/201012091434/cudf2pbo4user-1.0/rand8cc693.cudf.impossible.log.runsolver ./cudf2pbo4user-1.0 /home/misc2010/data/2010/impossible//rand8cc693.cudf /home/misc2010/tmp/201012091434/cudf2pbo4user-1.0/rand8cc693.cudf.impossible.result -changed,-removed,-unmet_recommends,-new 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 1.00 1.01 3/39 30749 /proc/meminfo: memFree=429552/1048576 swapFree=2095372/2097144 [pid=30748] ppid=30747 vsize=2576 CPUtime=0 /proc/30748/stat : 30748 (cudf2pbo4user-1) S 30747 30748 25521 34816 25544 4202496 386 0 0 0 0 0 0 0 18 0 1 0 900362338 2637824 281 1283457024 134512640 135304128 4288795664 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0 /proc/30748/statm: 644 281 240 194 0 30 0 [pid=30749] ppid=30748 vsize=2576 CPUtime=0 /proc/30749/stat : 30749 (cudf2pbo4user-1) D 30748 30748 25521 34816 25544 4202560 80 0 0 0 0 0 0 0 18 0 1 0 900362338 2637824 104 1283457024 134512640 135304128 4288795664 18446744073709551615 4294960130 0 0 0 0 18446744071564252162 0 0 17 0 0 0 0 /proc/30749/statm: 644 104 62 194 0 30 0 [startup+0.118221 s] /proc/loadavg: 0.99 1.00 1.01 3/39 30749 /proc/meminfo: memFree=429552/1048576 swapFree=2095372/2097144 [pid=30748] ppid=30747 vsize=2576 CPUtime=0 /proc/30748/stat : 30748 (cudf2pbo4user-1) S 30747 30748 25521 34816 25544 4202496 386 0 0 0 0 0 0 0 18 0 1 0 900362338 2637824 281 1283457024 134512640 135304128 4288795664 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0 /proc/30748/statm: 644 281 240 194 0 30 0 [pid=30749] ppid=30748 vsize=6464 CPUtime=0.1 /proc/30749/stat : 30749 (cudf_msu32) R 30748 30748 25521 34816 25544 4202496 1414 0 0 0 9 1 0 0 25 0 1 0 900362338 6619136 1306 1283457024 134512640 136125367 4294621712 18446744073709551615 135532117 0 0 0 25121 0 0 0 17 0 0 0 0 /proc/30749/statm: 1616 1306 146 394 0 1220 0 Current children cumulated CPU time (s) 0.1 Current children cumulated vsize (KiB) 9040 [startup+0.208242 s] /proc/loadavg: 0.99 1.00 1.01 3/39 30749 /proc/meminfo: memFree=429552/1048576 swapFree=2095372/2097144 [pid=30748] ppid=30747 vsize=2576 CPUtime=0 /proc/30748/stat : 30748 (cudf2pbo4user-1) S 30747 30748 25521 34816 25544 4202496 386 0 0 0 0 0 0 0 18 0 1 0 900362338 2637824 281 1283457024 134512640 135304128 4288795664 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0 /proc/30748/statm: 644 281 240 194 0 30 0 [pid=30749] ppid=30748 vsize=9632 CPUtime=0.18 /proc/30749/stat : 30749 (cudf_msu32) R 30748 30748 25521 34816 25544 4202496 2238 0 0 0 16 2 0 0 25 0 1 0 900362338 9863168 2130 1283457024 134512640 136125367 4294621712 18446744073709551615 134727103 0 0 0 25121 0 0 0 17 0 0 0 0 /proc/30749/statm: 2408 2130 146 394 0 2012 0 Current children cumulated CPU time (s) 0.18 Current children cumulated vsize (KiB) 12208 [startup+0.308263 s] /proc/loadavg: 0.99 1.00 1.01 3/39 30749 /proc/meminfo: memFree=429552/1048576 swapFree=2095372/2097144 [pid=30748] ppid=30747 vsize=2576 CPUtime=0 /proc/30748/stat : 30748 (cudf2pbo4user-1) S 30747 30748 25521 34816 25544 4202496 386 0 0 0 0 0 0 0 18 0 1 0 900362338 2637824 281 1283457024 134512640 135304128 4288795664 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0 /proc/30748/statm: 644 281 240 194 0 30 0 [pid=30749] ppid=30748 vsize=13220 CPUtime=0.29 /proc/30749/stat : 30749 (cudf_msu32) R 30748 30748 25521 34816 25544 4202496 3127 0 0 0 26 3 0 0 25 0 1 0 900362338 13537280 3019 1283457024 134512640 136125367 4294621712 18446744073709551615 135528873 0 0 0 25121 0 0 0 17 0 0 0 0 /proc/30749/statm: 3305 3019 147 394 0 2909 0 Current children cumulated CPU time (s) 0.29 Current children cumulated vsize (KiB) 15796 [startup+0.708359 s] /proc/loadavg: 0.99 1.00 1.01 3/39 30749 /proc/meminfo: memFree=429552/1048576 swapFree=2095372/2097144 [pid=30748] ppid=30747 vsize=2576 CPUtime=0 /proc/30748/stat : 30748 (cudf2pbo4user-1) S 30747 30748 25521 34816 25544 4202496 386 0 0 0 0 0 0 0 18 0 1 0 900362338 2637824 281 1283457024 134512640 135304128 4288795664 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0 /proc/30748/statm: 644 281 240 194 0 30 0 [pid=30749] ppid=30748 vsize=25296 CPUtime=0.69 /proc/30749/stat : 30749 (cudf_msu32) R 30748 30748 25521 34816 25544 4202496 6139 0 0 0 66 3 0 0 25 0 1 0 900362338 25903104 6031 1283457024 134512640 136125367 4294621712 18446744073709551615 134717925 0 0 0 25121 0 0 0 17 0 0 0 0 /proc/30749/statm: 6324 6031 147 394 0 5928 0 Current children cumulated CPU time (s) 0.69 Current children cumulated vsize (KiB) 27872 [startup+1.50855 s] /proc/loadavg: 0.99 1.00 1.01 2/40 30750 /proc/meminfo: memFree=395308/1048576 swapFree=2095372/2097144 [pid=30748] ppid=30747 vsize=2576 CPUtime=0 /proc/30748/stat : 30748 (cudf2pbo4user-1) S 30747 30748 25521 34816 25544 4202496 386 0 0 0 0 0 0 0 18 0 1 0 900362338 2637824 281 1283457024 134512640 135304128 4288795664 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0 /proc/30748/statm: 644 281 240 194 0 30 0 [pid=30749] ppid=30748 vsize=46104 CPUtime=1.49 /proc/30749/stat : 30749 (cudf_msu32) R 30748 30748 25521 34816 25544 4202496 11386 0 0 0 144 5 0 0 25 0 1 0 900362338 47210496 11229 1283457024 134512640 136125367 4294621712 18446744073709551615 134698030 0 0 0 25121 0 0 0 17 0 0 0 0 /proc/30749/statm: 11526 11229 157 394 0 11130 0 Current children cumulated CPU time (s) 1.49 Current children cumulated vsize (KiB) 48680 [startup+3.109 s] /proc/loadavg: 0.99 1.00 1.01 2/40 30750 /proc/meminfo: memFree=358976/1048576 swapFree=2095372/2097144 [pid=30748] ppid=30747 vsize=2576 CPUtime=0 /proc/30748/stat : 30748 (cudf2pbo4user-1) S 30747 30748 25521 34816 25544 4202496 386 0 0 0 0 0 0 0 18 0 1 0 900362338 2637824 281 1283457024 134512640 135304128 4288795664 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0 /proc/30748/statm: 644 281 240 194 0 30 0 [pid=30749] ppid=30748 vsize=74952 CPUtime=3.08 /proc/30749/stat : 30749 (cudf_msu32) R 30748 30748 25521 34816 25544 4202496 18910 0 0 0 248 60 0 0 25 0 1 0 900362338 76750848 18459 1283457024 134512640 136125367 4294621712 18446744073709551615 135594622 0 0 0 25121 0 0 0 17 0 0 0 0 /proc/30749/statm: 18738 18459 169 394 0 18342 0 Current children cumulated CPU time (s) 3.08 Current children cumulated vsize (KiB) 77528 [startup+6.31005 s] /proc/loadavg: 0.99 1.00 1.01 2/40 30751 /proc/meminfo: memFree=385884/1048576 swapFree=2095372/2097144 [pid=30748] ppid=30747 vsize=2576 CPUtime=3.25 /proc/30748/stat : 30748 (cudf2pbo4user-1) S 30747 30748 25521 34816 25544 4202496 404 18912 0 0 0 0 262 63 20 0 1 0 900362338 2637824 282 1283457024 134512640 135304128 4288795664 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0 /proc/30748/statm: 644 282 241 194 0 30 0 [pid=30751] ppid=30748 vsize=39608 CPUtime=3.01 /proc/30751/stat : 30751 (bmo-pblex32) R 30748 30748 25521 34816 25544 4202496 10161 0 0 0 244 57 0 0 25 0 1 0 900362666 40558592 9207 1283457024 134512640 135887319 4293351680 18446744073709551615 135381649 0 0 0 16899 0 0 0 17 0 0 0 0 /proc/30751/statm: 9902 9207 138 336 0 9564 0 Current children cumulated CPU time (s) 6.26 Current children cumulated vsize (KiB) 42184 [startup+12.7119 s] /proc/loadavg: 0.99 1.00 1.01 2/40 30751 /proc/meminfo: memFree=383652/1048576 swapFree=2095372/2097144 [pid=30748] ppid=30747 vsize=2576 CPUtime=3.25 /proc/30748/stat : 30748 (cudf2pbo4user-1) S 30747 30748 25521 34816 25544 4202496 404 18912 0 0 0 0 262 63 20 0 1 0 900362338 2637824 282 1283457024 134512640 135304128 4288795664 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0 /proc/30748/statm: 644 282 241 194 0 30 0 [pid=30751] ppid=30748 vsize=42004 CPUtime=9.36 /proc/30751/stat : 30751 (bmo-pblex32) R 30748 30748 25521 34816 25544 4202496 10800 0 0 0 748 188 0 0 25 0 1 0 900362666 43012096 9803 1283457024 134512640 135887319 4293351680 18446744073709551615 134614964 0 0 0 16899 0 0 0 17 0 0 0 0 /proc/30751/statm: 10501 9803 138 336 0 10163 0 Current children cumulated CPU time (s) 12.61 Current children cumulated vsize (KiB) 44580 [startup+25.5052 s] /proc/loadavg: 0.99 1.00 1.01 2/40 30751 /proc/meminfo: memFree=378444/1048576 swapFree=2095372/2097144 [pid=30748] ppid=30747 vsize=2576 CPUtime=3.25 /proc/30748/stat : 30748 (cudf2pbo4user-1) S 30747 30748 25521 34816 25544 4202496 404 18912 0 0 0 0 262 63 20 0 1 0 900362338 2637824 282 1283457024 134512640 135304128 4288795664 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0 /proc/30748/statm: 644 282 241 194 0 30 0 [pid=30751] ppid=30748 vsize=47204 CPUtime=22.1 /proc/30751/stat : 30751 (bmo-pblex32) R 30748 30748 25521 34816 25544 4202496 12107 0 0 0 1741 469 0 0 25 0 1 0 900362666 48336896 11088 1283457024 134512640 135887319 4293351680 18446744073709551615 135381649 0 0 0 16899 0 0 0 17 0 0 0 0 /proc/30751/statm: 11801 11088 138 336 0 11463 0 Current children cumulated CPU time (s) 25.35 Current children cumulated vsize (KiB) 49780 [startup+51.1129 s] /proc/loadavg: 0.99 1.00 1.00 2/40 30751 /proc/meminfo: memFree=370260/1048576 swapFree=2095372/2097144 [pid=30748] ppid=30747 vsize=2576 CPUtime=3.25 /proc/30748/stat : 30748 (cudf2pbo4user-1) S 30747 30748 25521 34816 25544 4202496 404 18912 0 0 0 0 262 63 20 0 1 0 900362338 2637824 282 1283457024 134512640 135304128 4288795664 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0 /proc/30748/statm: 644 282 241 194 0 30 0 [pid=30751] ppid=30748 vsize=55268 CPUtime=47.68 /proc/30751/stat : 30751 (bmo-pblex32) R 30748 30748 25521 34816 25544 4202496 14237 0 0 0 4233 535 0 0 25 0 1 0 900362666 56594432 13110 1283457024 134512640 135887319 4293351680 18446744073709551615 134604723 0 0 0 16899 0 0 0 17 0 0 0 0 /proc/30751/statm: 13817 13110 138 336 0 13479 0 Current children cumulated CPU time (s) 50.93 Current children cumulated vsize (KiB) 57844 [startup+102.308 s] /proc/loadavg: 0.99 1.00 1.00 2/40 30751 /proc/meminfo: memFree=352776/1048576 swapFree=2095372/2097144 [pid=30748] ppid=30747 vsize=2576 CPUtime=3.25 /proc/30748/stat : 30748 (cudf2pbo4user-1) S 30747 30748 25521 34816 25544 4202496 404 18912 0 0 0 0 262 63 20 0 1 0 900362338 2637824 282 1283457024 134512640 135304128 4288795664 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0 /proc/30748/statm: 644 282 241 194 0 30 0 [pid=30751] ppid=30748 vsize=72716 CPUtime=98.84 /proc/30751/stat : 30751 (bmo-pblex32) R 30748 30748 25521 34816 25544 4202496 18839 0 0 0 9328 556 0 0 25 0 1 0 900362666 74461184 17442 1283457024 134512640 135887319 4293351680 18446744073709551615 134617710 0 0 0 16899 0 0 0 17 0 0 0 0 /proc/30751/statm: 18179 17442 138 336 0 17841 0 Current children cumulated CPU time (s) 102.09 Current children cumulated vsize (KiB) 75292 [startup+162.305 s] /proc/loadavg: 0.99 1.00 1.00 2/40 30751 /proc/meminfo: memFree=342236/1048576 swapFree=2095372/2097144 [pid=30748] ppid=30747 vsize=2576 CPUtime=3.25 /proc/30748/stat : 30748 (cudf2pbo4user-1) S 30747 30748 25521 34816 25544 4202496 404 18912 0 0 0 0 262 63 20 0 1 0 900362338 2637824 282 1283457024 134512640 135304128 4288795664 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0 /proc/30748/statm: 644 282 241 194 0 30 0 [pid=30751] ppid=30748 vsize=83124 CPUtime=158.78 /proc/30751/stat : 30751 (bmo-pblex32) R 30748 30748 25521 34816 25544 4202496 21648 0 0 0 15297 581 0 0 25 0 1 0 900362666 85118976 20019 1283457024 134512640 135887319 4293351680 18446744073709551615 134624367 0 0 0 16899 0 0 0 17 0 0 0 0 /proc/30751/statm: 20781 20019 138 336 0 20443 0 Current children cumulated CPU time (s) 162.03 Current children cumulated vsize (KiB) 85700 [startup+222.304 s] /proc/loadavg: 0.99 1.00 1.00 2/40 30751 /proc/meminfo: memFree=341244/1048576 swapFree=2095372/2097144 [pid=30748] ppid=30747 vsize=2576 CPUtime=3.25 /proc/30748/stat : 30748 (cudf2pbo4user-1) S 30747 30748 25521 34816 25544 4202496 404 18912 0 0 0 0 262 63 20 0 1 0 900362338 2637824 282 1283457024 134512640 135304128 4288795664 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0 /proc/30748/statm: 644 282 241 194 0 30 0 [pid=30751] ppid=30748 vsize=84064 CPUtime=218.72 /proc/30751/stat : 30751 (bmo-pblex32) R 30748 30748 25521 34816 25544 4202496 21914 0 0 0 21273 599 0 0 25 0 1 0 900362666 86081536 20262 1283457024 134512640 135887319 4293351680 18446744073709551615 134624311 0 0 0 16899 0 0 0 17 0 0 0 0 /proc/30751/statm: 21016 20262 138 336 0 20678 0 Current children cumulated CPU time (s) 221.97 Current children cumulated vsize (KiB) 86640 [startup+282.312 s] /proc/loadavg: 0.99 1.00 1.00 2/40 30751 /proc/meminfo: memFree=324380/1048576 swapFree=2095372/2097144 [pid=30748] ppid=30747 vsize=2576 CPUtime=3.25 /proc/30748/stat : 30748 (cudf2pbo4user-1) S 30747 30748 25521 34816 25544 4202496 404 18912 0 0 0 0 262 63 20 0 1 0 900362338 2637824 282 1283457024 134512640 135304128 4288795664 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0 /proc/30748/statm: 644 282 241 194 0 30 0 [pid=30751] ppid=30748 vsize=101188 CPUtime=278.66 /proc/30751/stat : 30751 (bmo-pblex32) R 30748 30748 25521 34816 25544 4202496 26396 0 0 0 27244 622 0 0 25 0 1 0 900362666 103616512 24512 1283457024 134512640 135887319 4293351680 18446744073709551615 134605901 0 0 0 16899 0 0 0 17 0 0 0 0 /proc/30751/statm: 25297 24512 138 336 0 24959 0 Current children cumulated CPU time (s) 281.91 Current children cumulated vsize (KiB) 103764 Maximum CPU time exceeded: sending signal-name then SIGKILL [startup+290.414 s] /proc/loadavg: 0.99 1.00 1.00 2/40 30751 /proc/meminfo: memFree=321900/1048576 swapFree=2095372/2097144 [pid=30748] ppid=30747 vsize=2576 CPUtime=3.25 /proc/30748/stat : 30748 (cudf2pbo4user-1) S 30747 30748 25521 34816 25544 4202496 404 18912 0 0 0 0 262 63 20 0 1 0 900362338 2637824 282 1283457024 134512640 135304128 4288795664 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0 /proc/30748/statm: 644 282 241 194 0 30 0 [pid=30751] ppid=30748 vsize=103364 CPUtime=286.76 /proc/30751/stat : 30751 (bmo-pblex32) R 30748 30748 25521 34816 25544 4202496 26987 0 0 0 28050 626 0 0 25 0 1 0 900362666 105844736 25078 1283457024 134512640 135887319 4293351680 18446744073709551615 134624311 0 0 0 16899 0 0 0 17 0 0 0 0 /proc/30751/statm: 25841 25078 138 336 0 25503 0 Current children cumulated CPU time (s) 290.01 Current children cumulated vsize (KiB) 105940 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.524 s] /proc/loadavg: 0.99 1.00 1.00 2/40 30751 /proc/meminfo: memFree=321900/1048576 swapFree=2095372/2097144 [pid=30748] ppid=30747 vsize=2584 CPUtime=290.04 /proc/30748/stat : 30748 (cudf2pbo4user-1) S 30747 30748 25521 34816 25544 4202496 447 45903 0 0 0 0 28314 690 17 0 1 0 900362338 2646016 288 1283457024 134512640 135304128 4288795664 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0 /proc/30748/statm: 646 288 245 194 0 32 0 Current children cumulated CPU time (s) 290.04 Current children cumulated vsize (KiB) 2584 Child status: 0 Real time (s): 290.563 CPU time (s): 290.17 CPU user time (s): 283.254 CPU system time (s): 6.91643 CPU usage (%): 99.8649 Max. virtual memory (cumulated for all children) (KiB): 105940 getrusage(RUSAGE_CHILDREN,...) data: user time used= 283.254 system time used= 6.91643 maximum resident set size= 0 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 48772 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= 30 involuntary context switches= 7843 runsolver used 0 second user time and 0 second system time The end