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/201012061533/cudf2msu4paranoid-1.0/8ad21cec-4b22-11df-b280-00163e7a6f5e.cudf.debian-dudf.log.runsolver ./cudf2msu4paranoid-1.0 /home/misc2010/data/2010/debian-dudf//8ad21cec-4b22-11df-b280-00163e7a6f5e.cudf /home/misc2010/tmp/201012061533/cudf2msu4paranoid-1.0/8ad21cec-4b22-11df-b280-00163e7a6f5e.cudf.debian-dudf.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: 1.46 1.32 1.22 3/46 29664 /proc/meminfo: memFree=641968/1048576 swapFree=2078744/2097144 [pid=29663] ppid=29662 vsize=2568 CPUtime=0 /proc/29663/stat : 29663 (cudf2msu4parano) R 29662 29663 2059 34821 2220 4202496 356 0 0 0 0 0 0 0 25 0 1 0 876516811 2629632 270 1283457024 134512640 135304128 4289191008 18446744073709551615 4294960130 0 65538 4 65536 0 0 0 17 0 0 0 0 /proc/29663/statm: 642 270 230 194 0 28 0 [pid=29664] ppid=29663 vsize=2568 CPUtime=0 /proc/29664/stat : 29664 (cudf2msu4parano) R 29663 29663 2059 34821 2220 4202560 0 0 0 0 0 0 0 0 25 0 1 0 876516811 2629632 40 1283457024 134512640 135304128 4289191008 18446744073709551615 4294960130 0 65538 4 65536 0 0 0 17 0 0 0 0 /proc/29664/statm: 642 40 0 194 0 28 0 [startup+0.184868 s] /proc/loadavg: 1.46 1.32 1.22 3/46 29664 /proc/meminfo: memFree=641968/1048576 swapFree=2078744/2097144 [pid=29663] ppid=29662 vsize=2568 CPUtime=0 /proc/29663/stat : 29663 (cudf2msu4parano) S 29662 29663 2059 34821 2220 4202496 374 0 0 0 0 0 0 0 25 0 1 0 876516811 2629632 271 1283457024 134512640 135304128 4289191008 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0 /proc/29663/statm: 642 271 231 194 0 28 0 [pid=29664] ppid=29663 vsize=8976 CPUtime=0.18 /proc/29664/stat : 29664 (cudf_msu32) R 29663 29663 2059 34821 2220 4202496 2004 0 0 0 18 0 0 0 25 0 1 0 876516811 9191424 1944 1283457024 134512640 136120023 4287146624 18446744073709551615 134711923 0 0 0 16929 0 0 0 17 0 0 0 0 /proc/29664/statm: 2244 1944 137 393 0 1849 0 Current children cumulated CPU time (s) 0.18 Current children cumulated vsize (KiB) 11544 [startup+0.204865 s] /proc/loadavg: 1.46 1.32 1.22 3/46 29664 /proc/meminfo: memFree=641968/1048576 swapFree=2078744/2097144 [pid=29663] ppid=29662 vsize=2568 CPUtime=0 /proc/29663/stat : 29663 (cudf2msu4parano) S 29662 29663 2059 34821 2220 4202496 374 0 0 0 0 0 0 0 25 0 1 0 876516811 2629632 271 1283457024 134512640 135304128 4289191008 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0 /proc/29663/statm: 642 271 231 194 0 28 0 [pid=29664] ppid=29663 vsize=9636 CPUtime=0.2 /proc/29664/stat : 29664 (cudf_msu32) R 29663 29663 2059 34821 2220 4202496 2166 0 0 0 20 0 0 0 25 0 1 0 876516811 9867264 2106 1283457024 134512640 136120023 4287146624 18446744073709551615 134713585 0 0 0 16929 0 0 0 17 0 0 0 0 /proc/29664/statm: 2409 2106 137 393 0 2014 0 Current children cumulated CPU time (s) 0.2 Current children cumulated vsize (KiB) 12204 [startup+0.304882 s] /proc/loadavg: 1.46 1.32 1.22 3/46 29664 /proc/meminfo: memFree=641968/1048576 swapFree=2078744/2097144 [pid=29663] ppid=29662 vsize=2568 CPUtime=0 /proc/29663/stat : 29663 (cudf2msu4parano) S 29662 29663 2059 34821 2220 4202496 374 0 0 0 0 0 0 0 25 0 1 0 876516811 2629632 271 1283457024 134512640 135304128 4289191008 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0 /proc/29663/statm: 642 271 231 194 0 28 0 [pid=29664] ppid=29663 vsize=12824 CPUtime=0.3 /proc/29664/stat : 29664 (cudf_msu32) R 29663 29663 2059 34821 2220 4202496 2955 0 0 0 30 0 0 0 25 0 1 0 876516811 13131776 2895 1283457024 134512640 136120023 4287146624 18446744073709551615 134712307 0 0 0 16929 0 0 0 17 0 0 0 0 /proc/29664/statm: 3206 2895 138 393 0 2811 0 Current children cumulated CPU time (s) 0.3 Current children cumulated vsize (KiB) 15392 [startup+0.704931 s] /proc/loadavg: 1.46 1.32 1.22 3/46 29664 /proc/meminfo: memFree=641968/1048576 swapFree=2078744/2097144 [pid=29663] ppid=29662 vsize=2568 CPUtime=0 /proc/29663/stat : 29663 (cudf2msu4parano) S 29662 29663 2059 34821 2220 4202496 374 0 0 0 0 0 0 0 25 0 1 0 876516811 2629632 271 1283457024 134512640 135304128 4289191008 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0 /proc/29663/statm: 642 271 231 194 0 28 0 [pid=29664] ppid=29663 vsize=23844 CPUtime=0.69 /proc/29664/stat : 29664 (cudf_msu32) R 29663 29663 2059 34821 2220 4202496 5706 0 0 0 67 2 0 0 25 0 1 0 876516811 24416256 5646 1283457024 134512640 136120023 4287146624 18446744073709551615 135394523 0 0 0 16929 0 0 0 17 0 0 0 0 /proc/29664/statm: 5961 5646 138 393 0 5566 0 Current children cumulated CPU time (s) 0.69 Current children cumulated vsize (KiB) 26412 [startup+1.50508 s] /proc/loadavg: 1.46 1.32 1.22 2/47 29665 /proc/meminfo: memFree=610156/1048576 swapFree=2078744/2097144 [pid=29663] ppid=29662 vsize=2568 CPUtime=0 /proc/29663/stat : 29663 (cudf2msu4parano) S 29662 29663 2059 34821 2220 4202496 374 0 0 0 0 0 0 0 25 0 1 0 876516811 2629632 271 1283457024 134512640 135304128 4289191008 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0 /proc/29663/statm: 642 271 231 194 0 28 0 [pid=29664] ppid=29663 vsize=52420 CPUtime=1.5 /proc/29664/stat : 29664 (cudf_msu32) R 29663 29663 2059 34821 2220 4202496 13249 0 0 0 142 8 0 0 25 0 1 0 876516811 53678080 12800 1283457024 134512640 136120023 4287146624 18446744073709551615 134623490 0 0 0 16929 0 0 0 17 0 0 0 0 /proc/29664/statm: 13105 12800 150 393 0 12710 0 Current children cumulated CPU time (s) 1.5 Current children cumulated vsize (KiB) 54988 [startup+3.10587 s] /proc/loadavg: 1.46 1.32 1.22 2/47 29665 /proc/meminfo: memFree=545428/1048576 swapFree=2078744/2097144 [pid=29663] ppid=29662 vsize=2568 CPUtime=0 /proc/29663/stat : 29663 (cudf2msu4parano) S 29662 29663 2059 34821 2220 4202496 374 0 0 0 0 0 0 0 25 0 1 0 876516811 2629632 271 1283457024 134512640 135304128 4289191008 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0 /proc/29663/statm: 642 271 231 194 0 28 0 [pid=29664] ppid=29663 vsize=98340 CPUtime=3.09 /proc/29664/stat : 29664 (cudf_msu32) R 29663 29663 2059 34821 2220 4202496 24797 0 0 0 297 12 0 0 25 0 1 0 876516811 100700160 24333 1283457024 134512640 136120023 4287146624 18446744073709551615 134831643 0 0 0 16929 0 0 0 17 0 0 0 0 /proc/29664/statm: 24585 24333 182 393 0 24190 0 Current children cumulated CPU time (s) 3.09 Current children cumulated vsize (KiB) 100908 Solver just ended. Dumping a history of the last processes samples [startup+3.20592 s] /proc/loadavg: 1.46 1.32 1.22 2/47 29665 /proc/meminfo: memFree=545428/1048576 swapFree=2078744/2097144 [pid=29663] ppid=29662 vsize=2568 CPUtime=0 /proc/29663/stat : 29663 (cudf2msu4parano) S 29662 29663 2059 34821 2220 4202496 374 0 0 0 0 0 0 0 25 0 1 0 876516811 2629632 271 1283457024 134512640 135304128 4289191008 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0 /proc/29663/statm: 642 271 231 194 0 28 0 [pid=29664] ppid=29663 vsize=98340 CPUtime=3.19 /proc/29664/stat : 29664 (cudf_msu32) R 29663 29663 2059 34821 2220 4202496 24797 0 0 0 307 12 0 0 25 0 1 0 876516811 100700160 24333 1283457024 134512640 136120023 4287146624 18446744073709551615 134866586 0 0 0 16929 0 0 0 17 0 0 0 0 /proc/29664/statm: 24585 24333 182 393 0 24190 0 Current children cumulated CPU time (s) 3.19 Current children cumulated vsize (KiB) 100908 [startup+4.00631 s] /proc/loadavg: 1.46 1.32 1.22 2/47 29665 /proc/meminfo: memFree=545180/1048576 swapFree=2078744/2097144 [pid=29663] ppid=29662 vsize=2568 CPUtime=0 /proc/29663/stat : 29663 (cudf2msu4parano) S 29662 29663 2059 34821 2220 4202496 374 0 0 0 0 0 0 0 25 0 1 0 876516811 2629632 271 1283457024 134512640 135304128 4289191008 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0 /proc/29663/statm: 642 271 231 194 0 28 0 [pid=29664] ppid=29663 vsize=98340 CPUtime=3.99 /proc/29664/stat : 29664 (cudf_msu32) R 29663 29663 2059 34821 2220 4202496 24797 0 0 0 387 12 0 0 25 0 1 0 876516811 100700160 24333 1283457024 134512640 136120023 4287146624 18446744073709551615 134872772 0 0 0 16929 0 0 0 17 0 0 0 0 /proc/29664/statm: 24585 24333 182 393 0 24190 0 Current children cumulated CPU time (s) 3.99 Current children cumulated vsize (KiB) 100908 [startup+4.80654 s] /proc/loadavg: 1.46 1.32 1.22 2/47 29665 /proc/meminfo: memFree=545180/1048576 swapFree=2078744/2097144 [pid=29663] ppid=29662 vsize=2568 CPUtime=0 /proc/29663/stat : 29663 (cudf2msu4parano) S 29662 29663 2059 34821 2220 4202496 374 0 0 0 0 0 0 0 25 0 1 0 876516811 2629632 271 1283457024 134512640 135304128 4289191008 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0 /proc/29663/statm: 642 271 231 194 0 28 0 [pid=29664] ppid=29663 vsize=98340 CPUtime=4.79 /proc/29664/stat : 29664 (cudf_msu32) R 29663 29663 2059 34821 2220 4202496 24797 0 0 0 467 12 0 0 25 0 1 0 876516811 100700160 24333 1283457024 134512640 136120023 4287146624 18446744073709551615 134837910 0 0 0 16929 0 0 0 17 0 0 0 0 /proc/29664/statm: 24585 24333 182 393 0 24190 0 Current children cumulated CPU time (s) 4.79 Current children cumulated vsize (KiB) 100908 [startup+5.00661 s] /proc/loadavg: 1.46 1.32 1.22 2/47 29665 /proc/meminfo: memFree=545180/1048576 swapFree=2078744/2097144 [pid=29663] ppid=29662 vsize=2568 CPUtime=0 /proc/29663/stat : 29663 (cudf2msu4parano) S 29662 29663 2059 34821 2220 4202496 374 0 0 0 0 0 0 0 25 0 1 0 876516811 2629632 271 1283457024 134512640 135304128 4289191008 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0 /proc/29663/statm: 642 271 231 194 0 28 0 [pid=29664] ppid=29663 vsize=98340 CPUtime=4.99 /proc/29664/stat : 29664 (cudf_msu32) R 29663 29663 2059 34821 2220 4202496 24797 0 0 0 487 12 0 0 25 0 1 0 876516811 100700160 24333 1283457024 134512640 136120023 4287146624 18446744073709551615 134873006 0 0 0 16929 0 0 0 17 0 0 0 0 /proc/29664/statm: 24585 24333 182 393 0 24190 0 Current children cumulated CPU time (s) 4.99 Current children cumulated vsize (KiB) 100908 [startup+5.10665 s] /proc/loadavg: 1.46 1.32 1.22 2/47 29665 /proc/meminfo: memFree=545180/1048576 swapFree=2078744/2097144 [pid=29663] ppid=29662 vsize=2568 CPUtime=0 /proc/29663/stat : 29663 (cudf2msu4parano) S 29662 29663 2059 34821 2220 4202496 374 0 0 0 0 0 0 0 25 0 1 0 876516811 2629632 271 1283457024 134512640 135304128 4289191008 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0 /proc/29663/statm: 642 271 231 194 0 28 0 [pid=29664] ppid=29663 vsize=97948 CPUtime=5.09 /proc/29664/stat : 29664 (cudf_msu32) R 29663 29663 2059 34821 2220 4202496 24812 0 0 0 495 14 0 0 25 0 1 0 876516811 100298752 24250 1283457024 134512640 136120023 4287146624 18446744073709551615 135511795 0 0 0 16929 0 0 0 17 0 0 0 0 /proc/29664/statm: 24487 24250 197 393 0 24092 0 Current children cumulated CPU time (s) 5.09 Current children cumulated vsize (KiB) 100516 Child status: 0 Real time (s): 5.13369 CPU time (s): 5.12032 CPU user time (s): 4.96031 CPU system time (s): 0.16001 CPU usage (%): 99.7395 Max. virtual memory (cumulated for all children) (KiB): 100908 getrusage(RUSAGE_CHILDREN,...) data: user time used= 4.96031 system time used= 0.16001 maximum resident set size= 0 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 25198 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= 4 involuntary context switches= 104 runsolver used 0 second user time and 0 second system time The end