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/201108241238/packup2mp4tr-0.6/0207e19a-9b1c-11df-af69-00163e46d37a.cudf.dudf-real.log.runsolver ./packup2mp4tr-0.6 /home/misc2010/data/2011/dudf-real//0207e19a-9b1c-11df-af69-00163e46d37a.cudf /home/misc2010/tmp/201108241238/packup2mp4tr-0.6/0207e19a-9b1c-11df-af69-00163e46d37a.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.18 0.45 0.16 3/39 1923
/proc/meminfo: memFree=788988/1048576 swapFree=0/0
[pid=1922] ppid=1921 vsize=2576 CPUtime=0
/proc/1922/stat : 1922 (packup2mp4tr-0.) S 1921 1922 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 25 0 1 0 571853 2637824 275 1283457024 134512640 135304128 4291327616 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/1922/statm: 644 275 233 194 0 31 0
[pid=1923] ppid=1922 vsize=3848 CPUtime=0
/proc/1923/stat : 1923 (packup) R 1922 1922 1511 34817 1511 4202496 435 0 0 0 0 0 0 0 25 0 1 0 571853 3940352 364 1283457024 134512640 134752139 4292974560 18446744073709551615 4157037694 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/1923/statm: 962 364 286 59 0 126 0

[startup+0.136145 s]
/proc/loadavg: 1.18 0.45 0.16 3/39 1923
/proc/meminfo: memFree=788988/1048576 swapFree=0/0
[pid=1922] ppid=1921 vsize=2576 CPUtime=0
/proc/1922/stat : 1922 (packup2mp4tr-0.) S 1921 1922 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 25 0 1 0 571853 2637824 275 1283457024 134512640 135304128 4291327616 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/1922/statm: 644 275 233 194 0 31 0
[pid=1923] ppid=1922 vsize=8384 CPUtime=0.14
/proc/1923/stat : 1923 (packup) R 1922 1922 1511 34817 1511 4202496 1588 0 0 0 14 0 0 0 25 0 1 0 571853 8585216 1517 1283457024 134512640 134752139 4292974560 18446744073709551615 134681833 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/1923/statm: 2096 1517 286 59 0 1260 0
Current children cumulated CPU time (s) 0.14
Current children cumulated vsize (KiB) 10960

[startup+0.206158 s]
/proc/loadavg: 1.18 0.45 0.16 3/39 1923
/proc/meminfo: memFree=788988/1048576 swapFree=0/0
[pid=1922] ppid=1921 vsize=2576 CPUtime=0
/proc/1922/stat : 1922 (packup2mp4tr-0.) S 1921 1922 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 25 0 1 0 571853 2637824 275 1283457024 134512640 135304128 4291327616 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/1922/statm: 644 275 233 194 0 31 0
[pid=1923] ppid=1922 vsize=10496 CPUtime=0.2
/proc/1923/stat : 1923 (packup) R 1922 1922 1511 34817 1511 4202496 2117 0 0 0 20 0 0 0 25 0 1 0 571853 10747904 2046 1283457024 134512640 134752139 4292974560 18446744073709551615 134682011 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/1923/statm: 2624 2046 286 59 0 1788 0
Current children cumulated CPU time (s) 0.2
Current children cumulated vsize (KiB) 13072

[startup+0.306175 s]
/proc/loadavg: 1.18 0.45 0.16 3/39 1923
/proc/meminfo: memFree=788988/1048576 swapFree=0/0
[pid=1922] ppid=1921 vsize=2576 CPUtime=0
/proc/1922/stat : 1922 (packup2mp4tr-0.) S 1921 1922 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 25 0 1 0 571853 2637824 275 1283457024 134512640 135304128 4291327616 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/1922/statm: 644 275 233 194 0 31 0
[pid=1923] ppid=1922 vsize=13396 CPUtime=0.3
/proc/1923/stat : 1923 (packup) R 1922 1922 1511 34817 1511 4202496 2829 0 0 0 30 0 0 0 25 0 1 0 571853 13717504 2758 1283457024 134512640 134752139 4292974560 18446744073709551615 134681447 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/1923/statm: 3349 2758 286 59 0 2513 0
Current children cumulated CPU time (s) 0.3
Current children cumulated vsize (KiB) 15972

[startup+0.706256 s]
/proc/loadavg: 1.18 0.45 0.16 3/39 1923
/proc/meminfo: memFree=788988/1048576 swapFree=0/0
[pid=1922] ppid=1921 vsize=2576 CPUtime=0
/proc/1922/stat : 1922 (packup2mp4tr-0.) S 1921 1922 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 25 0 1 0 571853 2637824 275 1283457024 134512640 135304128 4291327616 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/1922/statm: 644 275 233 194 0 31 0
[pid=1923] ppid=1922 vsize=23360 CPUtime=0.7
/proc/1923/stat : 1923 (packup) R 1922 1922 1511 34817 1511 4202496 5317 0 0 0 70 0 0 0 25 0 1 0 571853 23920640 5246 1283457024 134512640 134752139 4292974560 18446744073709551615 134681595 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/1923/statm: 5840 5246 286 59 0 5004 0
Current children cumulated CPU time (s) 0.7
Current children cumulated vsize (KiB) 25936

[startup+1.5064 s]
/proc/loadavg: 1.18 0.45 0.16 2/40 1924
/proc/meminfo: memFree=756392/1048576 swapFree=0/0
[pid=1922] ppid=1921 vsize=2576 CPUtime=0
/proc/1922/stat : 1922 (packup2mp4tr-0.) S 1921 1922 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 25 0 1 0 571853 2637824 275 1283457024 134512640 135304128 4291327616 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/1922/statm: 644 275 233 194 0 31 0
[pid=1923] ppid=1922 vsize=35792 CPUtime=1.22
/proc/1923/stat : 1923 (packup) S 1922 1922 1511 34817 1511 4202496 8466 0 0 0 108 14 0 0 25 0 1 0 571853 36651008 8394 1283457024 134512640 134752139 4292974560 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/1923/statm: 8948 8394 324 59 0 8112 0
Current children cumulated CPU time (s) 1.22
Current children cumulated vsize (KiB) 38368

[startup+3.10673 s]
/proc/loadavg: 1.17 0.46 0.17 2/42 1928
/proc/meminfo: memFree=752020/1048576 swapFree=0/0
[pid=1922] ppid=1921 vsize=2576 CPUtime=0
/proc/1922/stat : 1922 (packup2mp4tr-0.) S 1921 1922 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 25 0 1 0 571853 2637824 275 1283457024 134512640 135304128 4291327616 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/1922/statm: 644 275 233 194 0 31 0
[pid=1923] ppid=1922 vsize=37216 CPUtime=2.11
/proc/1923/stat : 1923 (packup) S 1922 1922 1511 34817 1511 4202496 9092 4574 0 0 118 22 60 11 19 0 1 0 571853 38109184 8630 1283457024 134512640 134752139 4292974560 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/1923/statm: 9304 8630 332 59 0 8468 0
[pid=1927] ppid=1923 vsize=1676 CPUtime=0
/proc/1927/stat : 1927 (sh) S 1923 1922 1511 34817 1511 4202496 146 0 0 0 0 0 0 0 19 0 1 0 572065 1716224 124 1283457024 134512640 134593992 4290385472 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/1927/statm: 419 124 108 20 0 46 0
[pid=1928] ppid=1927 vsize=37200 CPUtime=0.98
/proc/1928/stat : 1928 (minisatp_32) R 1927 1922 1511 34817 1511 4202496 10711 0 0 0 85 13 0 0 25 0 1 0 572065 38092800 8118 1283457024 134512640 135413687 4292227104 18446744073709551615 134689792 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/1928/statm: 9300 8118 108 220 0 9078 0
Current children cumulated CPU time (s) 3.09
Current children cumulated vsize (KiB) 78668

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

[startup+3.20676 s]
/proc/loadavg: 1.17 0.46 0.17 2/42 1928
/proc/meminfo: memFree=752020/1048576 swapFree=0/0
[pid=1922] ppid=1921 vsize=2576 CPUtime=0
/proc/1922/stat : 1922 (packup2mp4tr-0.) S 1921 1922 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 25 0 1 0 571853 2637824 275 1283457024 134512640 135304128 4291327616 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/1922/statm: 644 275 233 194 0 31 0
[pid=1923] ppid=1922 vsize=37216 CPUtime=2.11
/proc/1923/stat : 1923 (packup) S 1922 1922 1511 34817 1511 4202496 9092 4574 0 0 118 22 60 11 19 0 1 0 571853 38109184 8630 1283457024 134512640 134752139 4292974560 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/1923/statm: 9304 8630 332 59 0 8468 0
[pid=1927] ppid=1923 vsize=1676 CPUtime=0
/proc/1927/stat : 1927 (sh) S 1923 1922 1511 34817 1511 4202496 146 0 0 0 0 0 0 0 19 0 1 0 572065 1716224 124 1283457024 134512640 134593992 4290385472 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/1927/statm: 419 124 108 20 0 46 0
[pid=1928] ppid=1927 vsize=41948 CPUtime=1.08
/proc/1928/stat : 1928 (minisatp_32) R 1927 1922 1511 34817 1511 4202496 12106 0 0 0 94 14 0 0 25 0 1 0 572065 42954752 9280 1283457024 134512640 135413687 4292227104 18446744073709551615 134657039 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/1928/statm: 10487 9280 108 220 0 10265 0
Current children cumulated CPU time (s) 3.19
Current children cumulated vsize (KiB) 83416

[startup+4.80705 s]
/proc/loadavg: 1.17 0.46 0.17 2/42 1931
/proc/meminfo: memFree=739496/1048576 swapFree=0/0
[pid=1922] ppid=1921 vsize=2576 CPUtime=0
/proc/1922/stat : 1922 (packup2mp4tr-0.) S 1921 1922 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 25 0 1 0 571853 2637824 275 1283457024 134512640 135304128 4291327616 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/1922/statm: 644 275 233 194 0 31 0
[pid=1923] ppid=1922 vsize=37224 CPUtime=4.61
/proc/1923/stat : 1923 (packup) S 1922 1922 1511 34817 1511 4202496 9211 22450 0 0 134 43 250 34 16 0 1 0 571853 38117376 8637 1283457024 134512640 134752139 4292974560 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/1923/statm: 9306 8637 332 59 0 8470 0
Current children cumulated CPU time (s) 4.61
Current children cumulated vsize (KiB) 39800

[startup+5.60724 s]
/proc/loadavg: 1.17 0.46 0.17 2/42 1933
/proc/meminfo: memFree=729204/1048576 swapFree=0/0
[pid=1922] ppid=1921 vsize=2576 CPUtime=0
/proc/1922/stat : 1922 (packup2mp4tr-0.) S 1921 1922 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 25 0 1 0 571853 2637824 275 1283457024 134512640 135304128 4291327616 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/1922/statm: 644 275 233 194 0 31 0
[pid=1923] ppid=1922 vsize=37224 CPUtime=4.61
/proc/1923/stat : 1923 (packup) S 1922 1922 1511 34817 1511 4202496 9211 22450 0 0 134 43 250 34 16 0 1 0 571853 38117376 8637 1283457024 134512640 134752139 4292974560 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/1923/statm: 9306 8637 332 59 0 8470 0
[pid=1932] ppid=1923 vsize=1672 CPUtime=0
/proc/1932/stat : 1932 (sh) S 1923 1922 1511 34817 1511 4202496 146 0 0 0 0 0 0 0 16 0 1 0 572315 1712128 124 1283457024 134512640 134593992 4293077200 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/1932/statm: 418 124 108 20 0 45 0
[pid=1933] ppid=1932 vsize=34024 CPUtime=0.98
/proc/1933/stat : 1933 (minisatp_32) R 1932 1922 1511 34817 1511 4202496 9681 0 0 0 89 9 0 0 20 0 1 0 572315 34840576 7626 1283457024 134512640 135413687 4289514896 18446744073709551615 134960907 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/1933/statm: 8506 7626 108 220 0 8284 0
Current children cumulated CPU time (s) 5.59
Current children cumulated vsize (KiB) 75496

[startup+6.00737 s]
/proc/loadavg: 1.17 0.46 0.17 2/42 1933
/proc/meminfo: memFree=729204/1048576 swapFree=0/0
[pid=1922] ppid=1921 vsize=2576 CPUtime=0
/proc/1922/stat : 1922 (packup2mp4tr-0.) S 1921 1922 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 25 0 1 0 571853 2637824 275 1283457024 134512640 135304128 4291327616 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/1922/statm: 644 275 233 194 0 31 0
[pid=1923] ppid=1922 vsize=37224 CPUtime=4.61
/proc/1923/stat : 1923 (packup) S 1922 1922 1511 34817 1511 4202496 9211 22450 0 0 134 43 250 34 16 0 1 0 571853 38117376 8637 1283457024 134512640 134752139 4292974560 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/1923/statm: 9306 8637 332 59 0 8470 0
[pid=1932] ppid=1923 vsize=1672 CPUtime=0
/proc/1932/stat : 1932 (sh) S 1923 1922 1511 34817 1511 4202496 146 0 0 0 0 0 0 0 16 0 1 0 572315 1712128 124 1283457024 134512640 134593992 4293077200 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/1932/statm: 418 124 108 20 0 45 0
[pid=1933] ppid=1932 vsize=38284 CPUtime=1.38
/proc/1933/stat : 1933 (minisatp_32) R 1932 1922 1511 34817 1511 4202496 12386 0 0 0 128 10 0 0 21 0 1 0 572315 39202816 8482 1283457024 134512640 135413687 4289514896 18446744073709551615 134957778 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/1933/statm: 9571 8482 108 220 0 9349 0
Current children cumulated CPU time (s) 5.99
Current children cumulated vsize (KiB) 79756

[startup+6.21745 s]
/proc/loadavg: 1.17 0.46 0.17 2/42 1933
/proc/meminfo: memFree=729204/1048576 swapFree=0/0
[pid=1922] ppid=1921 vsize=2576 CPUtime=0
/proc/1922/stat : 1922 (packup2mp4tr-0.) S 1921 1922 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 25 0 1 0 571853 2637824 275 1283457024 134512640 135304128 4291327616 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/1922/statm: 644 275 233 194 0 31 0
[pid=1923] ppid=1922 vsize=36640 CPUtime=6.2
/proc/1923/stat : 1923 (packup) R 1922 1922 1511 34817 1511 4202496 16612 35201 0 0 140 43 393 44 15 0 1 0 571853 37519360 8504 1283457024 134512640 134752139 4292974560 18446744073709551615 4158820545 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/1923/statm: 9160 8504 345 59 0 8324 0
Current children cumulated CPU time (s) 6.2
Current children cumulated vsize (KiB) 39216

Child status: 0
Real time (s): 6.26187
CPU time (s): 6.26039
CPU user time (s): 5.38034
CPU system time (s): 0.880055
CPU usage (%): 99.9764
Max. virtual memory (cumulated for all children) (KiB): 83416

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 5.38034
system time used= 0.880055
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 52754
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= 19
involuntary context switches= 115

runsolver used 0 second user time and 0 second system time

The end