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/4f84e9c6-a79c-11e0-9eb7-00163e1e087d.cudf.dudf-real.log.runsolver ./packup2mp4pa-0.6 /home/misc2010/data/2011/dudf-real//4f84e9c6-a79c-11e0-9eb7-00163e1e087d.cudf /home/misc2010/tmp/201108251442/packup2mp4pa-0.6/4f84e9c6-a79c-11e0-9eb7-00163e1e087d.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.60 1.45 1.24 3/34 22236
/proc/meminfo: memFree=301516/1048576 swapFree=0/0
[pid=22235] ppid=22234 vsize=2572 CPUtime=0
/proc/22235/stat : 22235 (packup2mp4pa-0.) S 22234 22235 4778 34817 4778 4202496 379 0 0 0 0 0 0 0 18 0 1 0 11150660 2633728 275 1283457024 134512640 135304128 4288644080 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/22235/statm: 643 275 233 194 0 30 0
[pid=22236] ppid=22235 vsize=476 CPUtime=0
/proc/22236/stat : 22236 (packup) D 22235 22235 4778 34817 4778 4194304 99 0 0 0 0 0 0 0 18 0 1 0 11150660 487424 37 1283457024 134512640 134752139 4294551904 18446744073709551615 4160043860 0 0 0 0 18446744071564252162 0 0 17 0 0 0 0
/proc/22236/statm: 119 37 29 59 0 6 0

[startup+0.183788 s]
/proc/loadavg: 1.60 1.45 1.24 3/34 22236
/proc/meminfo: memFree=301516/1048576 swapFree=0/0
[pid=22235] ppid=22234 vsize=2572 CPUtime=0
/proc/22235/stat : 22235 (packup2mp4pa-0.) S 22234 22235 4778 34817 4778 4202496 379 0 0 0 0 0 0 0 18 0 1 0 11150660 2633728 275 1283457024 134512640 135304128 4288644080 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/22235/statm: 643 275 233 194 0 30 0
[pid=22236] ppid=22235 vsize=9924 CPUtime=0.16
/proc/22236/stat : 22236 (packup) R 22235 22235 4778 34817 4778 4202496 1976 0 0 0 16 0 0 0 25 0 1 0 11150660 10162176 1904 1283457024 134512640 134752139 4294551904 18446744073709551615 134681869 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/22236/statm: 2481 1904 286 59 0 1645 0
Current children cumulated CPU time (s) 0.16
Current children cumulated vsize (KiB) 12496

[startup+0.217373 s]
/proc/loadavg: 1.60 1.45 1.24 3/34 22236
/proc/meminfo: memFree=301516/1048576 swapFree=0/0
[pid=22235] ppid=22234 vsize=2572 CPUtime=0
/proc/22235/stat : 22235 (packup2mp4pa-0.) S 22234 22235 4778 34817 4778 4202496 379 0 0 0 0 0 0 0 18 0 1 0 11150660 2633728 275 1283457024 134512640 135304128 4288644080 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/22235/statm: 643 275 233 194 0 30 0
[pid=22236] ppid=22235 vsize=10980 CPUtime=0.19
/proc/22236/stat : 22236 (packup) R 22235 22235 4778 34817 4778 4202496 2246 0 0 0 19 0 0 0 25 0 1 0 11150660 11243520 2174 1283457024 134512640 134752139 4294551904 18446744073709551615 134682011 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/22236/statm: 2745 2174 286 59 0 1909 0
Current children cumulated CPU time (s) 0.19
Current children cumulated vsize (KiB) 13552

[startup+0.307396 s]
/proc/loadavg: 1.60 1.45 1.24 3/34 22236
/proc/meminfo: memFree=301516/1048576 swapFree=0/0
[pid=22235] ppid=22234 vsize=2572 CPUtime=0
/proc/22235/stat : 22235 (packup2mp4pa-0.) S 22234 22235 4778 34817 4778 4202496 379 0 0 0 0 0 0 0 18 0 1 0 11150660 2633728 275 1283457024 134512640 135304128 4288644080 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/22235/statm: 643 275 233 194 0 30 0
[pid=22236] ppid=22235 vsize=13824 CPUtime=0.28
/proc/22236/stat : 22236 (packup) R 22235 22235 4778 34817 4778 4202496 2934 0 0 0 28 0 0 0 25 0 1 0 11150660 14155776 2862 1283457024 134512640 134752139 4294551904 18446744073709551615 134706243 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/22236/statm: 3456 2862 286 59 0 2620 0
Current children cumulated CPU time (s) 0.28
Current children cumulated vsize (KiB) 16396

[startup+0.707485 s]
/proc/loadavg: 1.60 1.45 1.24 3/34 22236
/proc/meminfo: memFree=301516/1048576 swapFree=0/0
[pid=22235] ppid=22234 vsize=2572 CPUtime=0
/proc/22235/stat : 22235 (packup2mp4pa-0.) S 22234 22235 4778 34817 4778 4202496 379 0 0 0 0 0 0 0 18 0 1 0 11150660 2633728 275 1283457024 134512640 135304128 4288644080 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/22235/statm: 643 275 233 194 0 30 0
[pid=22236] ppid=22235 vsize=24712 CPUtime=0.68
/proc/22236/stat : 22236 (packup) R 22235 22235 4778 34817 4778 4202496 5670 0 0 0 66 2 0 0 25 0 1 0 11150660 25305088 5598 1283457024 134512640 134752139 4294551904 18446744073709551615 134694907 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/22236/statm: 6178 5598 286 59 0 5342 0
Current children cumulated CPU time (s) 0.68
Current children cumulated vsize (KiB) 27284

[startup+1.50769 s]
/proc/loadavg: 1.55 1.45 1.24 2/35 22237
/proc/meminfo: memFree=270132/1048576 swapFree=0/0
[pid=22235] ppid=22234 vsize=2572 CPUtime=0
/proc/22235/stat : 22235 (packup2mp4pa-0.) S 22234 22235 4778 34817 4778 4202496 379 0 0 0 0 0 0 0 18 0 1 0 11150660 2633728 275 1283457024 134512640 135304128 4288644080 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/22235/statm: 643 275 233 194 0 30 0
[pid=22236] ppid=22235 vsize=48712 CPUtime=1.48
/proc/22236/stat : 22236 (packup) R 22235 22235 4778 34817 4778 4202496 11800 0 0 0 131 17 0 0 25 0 1 0 11150660 49881088 11437 1283457024 134512640 134752139 4294551904 18446744073709551615 4294960130 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/22236/statm: 12178 11437 321 59 0 11342 0
Current children cumulated CPU time (s) 1.48
Current children cumulated vsize (KiB) 51284

Solver just ended. Dumping a history of the last processes samples

[startup+1.60771 s]
/proc/loadavg: 1.55 1.45 1.24 2/35 22237
/proc/meminfo: memFree=270132/1048576 swapFree=0/0
[pid=22235] ppid=22234 vsize=2572 CPUtime=0
/proc/22235/stat : 22235 (packup2mp4pa-0.) S 22234 22235 4778 34817 4778 4202496 379 0 0 0 0 0 0 0 18 0 1 0 11150660 2633728 275 1283457024 134512640 135304128 4288644080 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/22235/statm: 643 275 233 194 0 30 0
[pid=22236] ppid=22235 vsize=48712 CPUtime=1.58
/proc/22236/stat : 22236 (packup) R 22235 22235 4778 34817 4778 4202496 11800 0 0 0 136 22 0 0 25 0 1 0 11150660 49881088 11437 1283457024 134512640 134752139 4294551904 18446744073709551615 4294960130 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/22236/statm: 12178 11437 321 59 0 11342 0
Current children cumulated CPU time (s) 1.58
Current children cumulated vsize (KiB) 51284

[startup+2.40785 s]
/proc/loadavg: 1.55 1.45 1.24 2/37 22239
/proc/meminfo: memFree=241952/1048576 swapFree=0/0
[pid=22235] ppid=22234 vsize=2572 CPUtime=0
/proc/22235/stat : 22235 (packup2mp4pa-0.) S 22234 22235 4778 34817 4778 4202496 379 0 0 0 0 0 0 0 18 0 1 0 11150660 2633728 275 1283457024 134512640 135304128 4288644080 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/22235/statm: 643 275 233 194 0 30 0
[pid=22236] ppid=22235 vsize=48712 CPUtime=1.59
/proc/22236/stat : 22236 (packup) S 22235 22235 4778 34817 4778 4202496 11804 0 0 0 136 23 0 0 25 0 1 0 11150660 49881088 11440 1283457024 134512640 134752139 4294551904 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/22236/statm: 12178 11440 324 59 0 11342 0
[pid=22238] ppid=22236 vsize=1672 CPUtime=0
/proc/22238/stat : 22238 (sh) S 22236 22235 4778 34817 4778 4202496 146 0 0 0 0 0 0 0 25 0 1 0 11150821 1712128 124 1283457024 134512640 134593992 4294681184 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/22238/statm: 418 124 108 20 0 45 0
[pid=22239] ppid=22238 vsize=22332 CPUtime=0.79
/proc/22239/stat : 22239 (minisatp_32) R 22238 22235 4778 34817 4778 4202496 4777 0 0 0 77 2 0 0 25 0 1 0 11150822 22867968 4244 1283457024 134512640 135413687 4288386176 18446744073709551615 134961229 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/22239/statm: 5583 4244 77 220 0 5361 0
Current children cumulated CPU time (s) 2.38
Current children cumulated vsize (KiB) 75288

[startup+2.80793 s]
/proc/loadavg: 1.55 1.45 1.24 2/37 22239
/proc/meminfo: memFree=241952/1048576 swapFree=0/0
[pid=22235] ppid=22234 vsize=2572 CPUtime=0
/proc/22235/stat : 22235 (packup2mp4pa-0.) S 22234 22235 4778 34817 4778 4202496 379 0 0 0 0 0 0 0 18 0 1 0 11150660 2633728 275 1283457024 134512640 135304128 4288644080 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/22235/statm: 643 275 233 194 0 30 0
[pid=22236] ppid=22235 vsize=48712 CPUtime=1.59
/proc/22236/stat : 22236 (packup) S 22235 22235 4778 34817 4778 4202496 11804 0 0 0 136 23 0 0 25 0 1 0 11150660 49881088 11440 1283457024 134512640 134752139 4294551904 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/22236/statm: 12178 11440 324 59 0 11342 0
[pid=22238] ppid=22236 vsize=1672 CPUtime=0
/proc/22238/stat : 22238 (sh) S 22236 22235 4778 34817 4778 4202496 146 0 0 0 0 0 0 0 25 0 1 0 11150821 1712128 124 1283457024 134512640 134593992 4294681184 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/22238/statm: 418 124 108 20 0 45 0
[pid=22239] ppid=22238 vsize=28460 CPUtime=1.18
/proc/22239/stat : 22239 (minisatp_32) R 22238 22235 4778 34817 4778 4202496 6359 0 0 0 103 15 0 0 25 0 1 0 11150822 29143040 5800 1283457024 134512640 135413687 4288386176 18446744073709551615 134988446 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/22239/statm: 7115 5800 85 220 0 6893 0
Current children cumulated CPU time (s) 2.77
Current children cumulated vsize (KiB) 81416

[startup+2.90797 s]
/proc/loadavg: 1.55 1.45 1.24 2/37 22239
/proc/meminfo: memFree=241952/1048576 swapFree=0/0
[pid=22235] ppid=22234 vsize=2572 CPUtime=0
/proc/22235/stat : 22235 (packup2mp4pa-0.) S 22234 22235 4778 34817 4778 4202496 379 0 0 0 0 0 0 0 18 0 1 0 11150660 2633728 275 1283457024 134512640 135304128 4288644080 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/22235/statm: 643 275 233 194 0 30 0
[pid=22236] ppid=22235 vsize=45616 CPUtime=2.87
/proc/22236/stat : 22236 (packup) R 22235 22235 4778 34817 4778 4202496 22210 6540 0 0 144 24 103 16 18 0 1 0 11150660 46710784 10874 1283457024 134512640 134752139 4294551904 18446744073709551615 134555028 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/22236/statm: 11404 10874 344 59 0 10568 0
Current children cumulated CPU time (s) 2.87
Current children cumulated vsize (KiB) 48188

Child status: 0
Real time (s): 2.9218
CPU time (s): 2.89618
CPU user time (s): 2.47615
CPU system time (s): 0.420026
CPU usage (%): 99.1232
Max. virtual memory (cumulated for all children) (KiB): 81416

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 2.47615
system time used= 0.420026
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 29228
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= 8
involuntary context switches= 71

runsolver used 0.012 second user time and 0 second system time

The end