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/201108251442/packup2mp4pa-0.6/1aabfc32-d491-11df-9a24-00163e3d3b7c.cudf.dudf-real.log.runsolver ./packup2mp4pa-0.6 /home/misc2010/data/2011/dudf-real//1aabfc32-d491-11df-9a24-00163e3d3b7c.cudf /home/misc2010/tmp/201108251442/packup2mp4pa-0.6/1aabfc32-d491-11df-9a24-00163e3d3b7c.cudf.dudf-real.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.50 1.19 1.06 4/34 9402 /proc/meminfo: memFree=311640/1048576 swapFree=0/0 [pid=9401] ppid=9400 vsize=2576 CPUtime=0 /proc/9401/stat : 9401 (packup2mp4pa-0.) S 9400 9401 4778 34817 4778 4202496 379 0 0 0 0 0 0 0 18 0 1 0 10335946 2637824 274 1283457024 134512640 135304128 4286915152 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/9401/statm: 644 274 233 194 0 31 0 [pid=9402] ppid=9401 vsize=3712 CPUtime=0 /proc/9402/stat : 9402 (packup) R 9401 9401 4778 34817 4778 4202496 410 0 0 0 0 0 0 0 25 0 1 0 10335946 3801088 339 1283457024 134512640 134752139 4293804208 18446744073709551615 134682058 0 0 18944 8192 0 0 0 17 0 0 0 0 /proc/9402/statm: 928 339 286 59 0 92 0 [startup+0.164233 s] /proc/loadavg: 1.50 1.19 1.06 4/34 9402 /proc/meminfo: memFree=311640/1048576 swapFree=0/0 [pid=9401] ppid=9400 vsize=2576 CPUtime=0 /proc/9401/stat : 9401 (packup2mp4pa-0.) S 9400 9401 4778 34817 4778 4202496 379 0 0 0 0 0 0 0 18 0 1 0 10335946 2637824 274 1283457024 134512640 135304128 4286915152 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/9401/statm: 644 274 233 194 0 31 0 [pid=9402] ppid=9401 vsize=9336 CPUtime=0.16 /proc/9402/stat : 9402 (packup) R 9401 9401 4778 34817 4778 4202496 1821 0 0 0 16 0 0 0 25 0 1 0 10335946 9560064 1750 1283457024 134512640 134752139 4293804208 18446744073709551615 4157373911 0 0 18944 8192 0 0 0 17 0 0 0 0 /proc/9402/statm: 2334 1750 286 59 0 1498 0 Current children cumulated CPU time (s) 0.16 Current children cumulated vsize (KiB) 11912 [startup+0.204239 s] /proc/loadavg: 1.50 1.19 1.06 4/34 9402 /proc/meminfo: memFree=311640/1048576 swapFree=0/0 [pid=9401] ppid=9400 vsize=2576 CPUtime=0 /proc/9401/stat : 9401 (packup2mp4pa-0.) S 9400 9401 4778 34817 4778 4202496 379 0 0 0 0 0 0 0 18 0 1 0 10335946 2637824 274 1283457024 134512640 135304128 4286915152 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/9401/statm: 644 274 233 194 0 31 0 [pid=9402] ppid=9401 vsize=10524 CPUtime=0.2 /proc/9402/stat : 9402 (packup) R 9401 9401 4778 34817 4778 4202496 2116 0 0 0 20 0 0 0 25 0 1 0 10335946 10776576 2045 1283457024 134512640 134752139 4293804208 18446744073709551615 134681765 0 0 18944 8192 0 0 0 17 0 0 0 0 /proc/9402/statm: 2631 2045 286 59 0 1795 0 Current children cumulated CPU time (s) 0.2 Current children cumulated vsize (KiB) 13100 [startup+0.304261 s] /proc/loadavg: 1.50 1.19 1.06 4/34 9402 /proc/meminfo: memFree=311640/1048576 swapFree=0/0 [pid=9401] ppid=9400 vsize=2576 CPUtime=0 /proc/9401/stat : 9401 (packup2mp4pa-0.) S 9400 9401 4778 34817 4778 4202496 379 0 0 0 0 0 0 0 18 0 1 0 10335946 2637824 274 1283457024 134512640 135304128 4286915152 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/9401/statm: 644 274 233 194 0 31 0 [pid=9402] ppid=9401 vsize=13228 CPUtime=0.3 /proc/9402/stat : 9402 (packup) R 9401 9401 4778 34817 4778 4202496 2803 0 0 0 30 0 0 0 25 0 1 0 10335946 13545472 2732 1283457024 134512640 134752139 4293804208 18446744073709551615 134681895 0 0 18944 8192 0 0 0 17 0 0 0 0 /proc/9402/statm: 3307 2732 286 59 0 2471 0 Current children cumulated CPU time (s) 0.3 Current children cumulated vsize (KiB) 15804 [startup+0.70434 s] /proc/loadavg: 1.50 1.19 1.06 4/34 9402 /proc/meminfo: memFree=311640/1048576 swapFree=0/0 [pid=9401] ppid=9400 vsize=2576 CPUtime=0 /proc/9401/stat : 9401 (packup2mp4pa-0.) S 9400 9401 4778 34817 4778 4202496 379 0 0 0 0 0 0 0 18 0 1 0 10335946 2637824 274 1283457024 134512640 135304128 4286915152 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/9401/statm: 644 274 233 194 0 31 0 [pid=9402] ppid=9401 vsize=23208 CPUtime=0.7 /proc/9402/stat : 9402 (packup) R 9401 9401 4778 34817 4778 4202496 5302 0 0 0 67 3 0 0 25 0 1 0 10335946 23764992 5231 1283457024 134512640 134752139 4293804208 18446744073709551615 134681659 0 0 18944 8192 0 0 0 17 0 0 0 0 /proc/9402/statm: 5802 5231 286 59 0 4966 0 Current children cumulated CPU time (s) 0.7 Current children cumulated vsize (KiB) 25784 [startup+1.50867 s] /proc/loadavg: 1.50 1.19 1.06 2/35 9403 /proc/meminfo: memFree=280876/1048576 swapFree=0/0 [pid=9401] ppid=9400 vsize=2576 CPUtime=0 /proc/9401/stat : 9401 (packup2mp4pa-0.) S 9400 9401 4778 34817 4778 4202496 379 0 0 0 0 0 0 0 18 0 1 0 10335946 2637824 274 1283457024 134512640 135304128 4286915152 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/9401/statm: 644 274 233 194 0 31 0 [pid=9402] ppid=9401 vsize=44900 CPUtime=1.49 /proc/9402/stat : 9402 (packup) R 9401 9401 4778 34817 4778 4202496 10841 0 0 0 133 16 0 0 25 0 1 0 10335946 45977600 10489 1283457024 134512640 134752139 4293804208 18446744073709551615 4159129231 0 0 18944 8192 0 0 0 17 0 0 0 0 /proc/9402/statm: 11225 10489 321 59 0 10389 0 Current children cumulated CPU time (s) 1.49 Current children cumulated vsize (KiB) 47476 [startup+3.1095 s] /proc/loadavg: 1.46 1.19 1.06 2/37 9405 /proc/meminfo: memFree=254804/1048576 swapFree=0/0 [pid=9401] ppid=9400 vsize=2576 CPUtime=0 /proc/9401/stat : 9401 (packup2mp4pa-0.) S 9400 9401 4778 34817 4778 4202496 379 0 0 0 0 0 0 0 18 0 1 0 10335946 2637824 274 1283457024 134512640 135304128 4286915152 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/9401/statm: 644 274 233 194 0 31 0 [pid=9402] ppid=9401 vsize=44900 CPUtime=1.54 /proc/9402/stat : 9402 (packup) S 9401 9401 4778 34817 4778 4202496 10846 0 0 0 137 17 0 0 25 0 1 0 10335946 45977600 10492 1283457024 134512640 134752139 4293804208 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0 /proc/9402/statm: 11225 10492 324 59 0 10389 0 [pid=9404] ppid=9402 vsize=1672 CPUtime=0 /proc/9404/stat : 9404 (sh) S 9402 9401 4778 34817 4778 4202496 148 0 0 0 0 0 0 0 25 0 1 0 10336101 1712128 124 1283457024 134512640 134593992 4286866160 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0 /proc/9404/statm: 418 124 108 20 0 45 0 [pid=9405] ppid=9404 vsize=53896 CPUtime=1.54 /proc/9405/stat : 9405 (minisatp_32) R 9404 9401 4778 34817 4778 4202496 16140 0 0 0 130 24 0 0 25 0 1 0 10336102 55189504 12040 1283457024 134512640 135413687 4292663440 18446744073709551615 134690435 0 0 18944 0 0 0 0 17 0 0 0 0 /proc/9405/statm: 13474 12040 107 220 0 13252 0 Current children cumulated CPU time (s) 3.08 Current children cumulated vsize (KiB) 103044 [startup+6.31088 s] /proc/loadavg: 1.46 1.19 1.06 2/37 9407 /proc/meminfo: memFree=251704/1048576 swapFree=0/0 [pid=9401] ppid=9400 vsize=2576 CPUtime=0 /proc/9401/stat : 9401 (packup2mp4pa-0.) S 9400 9401 4778 34817 4778 4202496 379 0 0 0 0 0 0 0 18 0 1 0 10335946 2637824 274 1283457024 134512640 135304128 4286915152 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/9401/statm: 644 274 233 194 0 31 0 [pid=9402] ppid=9401 vsize=44904 CPUtime=4.67 /proc/9402/stat : 9402 (packup) S 9401 9401 4778 34817 4778 4202496 10924 27056 0 0 148 32 256 31 18 0 1 0 10335946 45981696 10501 1283457024 134512640 134752139 4293804208 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0 /proc/9402/statm: 11226 10501 332 59 0 10390 0 [pid=9406] ppid=9402 vsize=1676 CPUtime=0 /proc/9406/stat : 9406 (sh) S 9402 9401 4778 34817 4778 4202496 147 0 0 0 0 0 0 0 18 0 1 0 10336417 1716224 124 1283457024 134512640 134593992 4292565088 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0 /proc/9406/statm: 419 124 108 20 0 46 0 [pid=9407] ppid=9406 vsize=73596 CPUtime=1.6 /proc/9407/stat : 9407 (minisatp_32) R 9406 9401 4778 34817 4778 4202496 19776 0 0 0 144 16 0 0 25 0 1 0 10336418 75362304 15670 1283457024 134512640 135413687 4294234640 18446744073709551615 134656621 0 0 18944 0 0 0 0 17 0 0 0 0 /proc/9407/statm: 18399 15670 108 220 0 18177 0 Current children cumulated CPU time (s) 6.27 Current children cumulated vsize (KiB) 122752 Solver just ended. Dumping a history of the last processes samples [startup+6.41091 s] /proc/loadavg: 1.46 1.19 1.06 2/37 9407 /proc/meminfo: memFree=251704/1048576 swapFree=0/0 [pid=9401] ppid=9400 vsize=2576 CPUtime=0 /proc/9401/stat : 9401 (packup2mp4pa-0.) S 9400 9401 4778 34817 4778 4202496 379 0 0 0 0 0 0 0 18 0 1 0 10335946 2637824 274 1283457024 134512640 135304128 4286915152 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/9401/statm: 644 274 233 194 0 31 0 [pid=9402] ppid=9401 vsize=44904 CPUtime=4.67 /proc/9402/stat : 9402 (packup) S 9401 9401 4778 34817 4778 4202496 10924 27056 0 0 148 32 256 31 18 0 1 0 10335946 45981696 10501 1283457024 134512640 134752139 4293804208 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0 /proc/9402/statm: 11226 10501 332 59 0 10390 0 [pid=9406] ppid=9402 vsize=1676 CPUtime=0 /proc/9406/stat : 9406 (sh) S 9402 9401 4778 34817 4778 4202496 147 0 0 0 0 0 0 0 18 0 1 0 10336417 1716224 124 1283457024 134512640 134593992 4292565088 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0 /proc/9406/statm: 419 124 108 20 0 46 0 [pid=9407] ppid=9406 vsize=82500 CPUtime=1.7 /proc/9407/stat : 9407 (minisatp_32) R 9406 9401 4778 34817 4778 4202496 23189 0 0 0 154 16 0 0 25 0 1 0 10336418 84480000 18682 1283457024 134512640 135413687 4294234640 18446744073709551615 134648935 0 0 18944 0 0 0 0 17 0 0 0 0 /proc/9407/statm: 20625 18682 108 220 0 20403 0 Current children cumulated CPU time (s) 6.37 Current children cumulated vsize (KiB) 131656 [startup+7.21116 s] /proc/loadavg: 1.46 1.19 1.06 3/37 9407 /proc/meminfo: memFree=186356/1048576 swapFree=0/0 [pid=9401] ppid=9400 vsize=2576 CPUtime=0 /proc/9401/stat : 9401 (packup2mp4pa-0.) S 9400 9401 4778 34817 4778 4202496 379 0 0 0 0 0 0 0 18 0 1 0 10335946 2637824 274 1283457024 134512640 135304128 4286915152 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/9401/statm: 644 274 233 194 0 31 0 [pid=9402] ppid=9401 vsize=44904 CPUtime=4.67 /proc/9402/stat : 9402 (packup) S 9401 9401 4778 34817 4778 4202496 10924 27056 0 0 148 32 256 31 18 0 1 0 10335946 45981696 10501 1283457024 134512640 134752139 4293804208 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0 /proc/9402/statm: 11226 10501 332 59 0 10390 0 [pid=9406] ppid=9402 vsize=1676 CPUtime=0 /proc/9406/stat : 9406 (sh) S 9402 9401 4778 34817 4778 4202496 147 0 0 0 0 0 0 0 18 0 1 0 10336417 1716224 124 1283457024 134512640 134593992 4292565088 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0 /proc/9406/statm: 419 124 108 20 0 46 0 [pid=9407] ppid=9406 vsize=119824 CPUtime=2.49 /proc/9407/stat : 9407 (minisatp_32) R 9406 9401 4778 34817 4778 4202496 31541 0 0 0 230 19 0 0 25 0 1 0 10336418 122699776 26311 1283457024 134512640 135413687 4294234640 18446744073709551615 134683779 0 0 18944 0 0 0 0 17 0 0 0 0 /proc/9407/statm: 29956 26311 108 220 0 29734 0 Current children cumulated CPU time (s) 7.16 Current children cumulated vsize (KiB) 168980 [startup+8.0114 s] /proc/loadavg: 1.43 1.19 1.06 2/37 9407 /proc/meminfo: memFree=169500/1048576 swapFree=0/0 [pid=9401] ppid=9400 vsize=2576 CPUtime=0 /proc/9401/stat : 9401 (packup2mp4pa-0.) S 9400 9401 4778 34817 4778 4202496 379 0 0 0 0 0 0 0 18 0 1 0 10335946 2637824 274 1283457024 134512640 135304128 4286915152 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/9401/statm: 644 274 233 194 0 31 0 [pid=9402] ppid=9401 vsize=44904 CPUtime=4.67 /proc/9402/stat : 9402 (packup) S 9401 9401 4778 34817 4778 4202496 10924 27056 0 0 148 32 256 31 18 0 1 0 10335946 45981696 10501 1283457024 134512640 134752139 4293804208 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0 /proc/9402/statm: 11226 10501 332 59 0 10390 0 [pid=9406] ppid=9402 vsize=1676 CPUtime=0 /proc/9406/stat : 9406 (sh) S 9402 9401 4778 34817 4778 4202496 147 0 0 0 0 0 0 0 18 0 1 0 10336417 1716224 124 1283457024 134512640 134593992 4292565088 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0 /proc/9406/statm: 419 124 108 20 0 46 0 [pid=9407] ppid=9406 vsize=110296 CPUtime=3.29 /proc/9407/stat : 9407 (minisatp_32) R 9406 9401 4778 34817 4778 4202496 33570 0 0 0 308 21 0 0 25 0 1 0 10336418 112943104 25145 1283457024 134512640 135413687 4294234640 18446744073709551615 134705683 0 0 18944 0 0 0 0 17 0 0 0 0 /proc/9407/statm: 27574 25145 108 220 0 27352 0 Current children cumulated CPU time (s) 7.96 Current children cumulated vsize (KiB) 159452 [startup+8.41153 s] /proc/loadavg: 1.43 1.19 1.06 2/37 9407 /proc/meminfo: memFree=169500/1048576 swapFree=0/0 [pid=9401] ppid=9400 vsize=2576 CPUtime=0 /proc/9401/stat : 9401 (packup2mp4pa-0.) S 9400 9401 4778 34817 4778 4202496 379 0 0 0 0 0 0 0 18 0 1 0 10335946 2637824 274 1283457024 134512640 135304128 4286915152 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/9401/statm: 644 274 233 194 0 31 0 [pid=9402] ppid=9401 vsize=44904 CPUtime=4.67 /proc/9402/stat : 9402 (packup) S 9401 9401 4778 34817 4778 4202496 10924 27056 0 0 148 32 256 31 18 0 1 0 10335946 45981696 10501 1283457024 134512640 134752139 4293804208 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0 /proc/9402/statm: 11226 10501 332 59 0 10390 0 [pid=9406] ppid=9402 vsize=1676 CPUtime=0 /proc/9406/stat : 9406 (sh) S 9402 9401 4778 34817 4778 4202496 147 0 0 0 0 0 0 0 18 0 1 0 10336417 1716224 124 1283457024 134512640 134593992 4292565088 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0 /proc/9406/statm: 419 124 108 20 0 46 0 [pid=9407] ppid=9406 vsize=101888 CPUtime=3.69 /proc/9407/stat : 9407 (minisatp_32) R 9406 9401 4778 34817 4778 4202496 35476 0 0 0 347 22 0 0 25 0 1 0 10336418 104333312 23660 1283457024 134512640 135413687 4294234640 18446744073709551615 134597339 0 0 18944 0 0 0 0 17 0 0 0 0 /proc/9407/statm: 25472 23660 117 220 0 25250 0 Current children cumulated CPU time (s) 8.36 Current children cumulated vsize (KiB) 151044 [startup+8.51155 s] /proc/loadavg: 1.43 1.19 1.06 2/37 9407 /proc/meminfo: memFree=169500/1048576 swapFree=0/0 [pid=9401] ppid=9400 vsize=2576 CPUtime=0 /proc/9401/stat : 9401 (packup2mp4pa-0.) S 9400 9401 4778 34817 4778 4202496 379 0 0 0 0 0 0 0 18 0 1 0 10335946 2637824 274 1283457024 134512640 135304128 4286915152 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0 /proc/9401/statm: 644 274 233 194 0 31 0 [pid=9402] ppid=9401 vsize=43936 CPUtime=8.49 /proc/9402/stat : 9402 (packup) R 9401 9401 4778 34817 4778 4202496 19754 62682 0 0 156 34 604 55 18 0 1 0 10335946 44990464 10271 1283457024 134512640 134752139 4293804208 18446744073709551615 134536379 0 0 18944 8192 0 0 0 17 0 0 0 0 /proc/9402/statm: 10984 10271 344 59 0 10148 0 Current children cumulated CPU time (s) 8.49 Current children cumulated vsize (KiB) 46512 Child status: 0 Real time (s): 8.56284 CPU time (s): 8.54853 CPU user time (s): 7.64048 CPU system time (s): 0.908056 CPU usage (%): 99.8329 Max. virtual memory (cumulated for all children) (KiB): 168980 getrusage(RUSAGE_CHILDREN,...) data: user time used= 7.64048 system time used= 0.908056 maximum resident set size= 0 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 83627 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= 12 involuntary context switches= 147 runsolver used 0 second user time and 0 second system time The end