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/201108281254/packup2hy4tr-0.6/301cbe92-a79c-11e0-9181-00163e1e087d.cudf.dudf-real.log.runsolver ./packup2hy4tr-0.6 /home/misc2010/data/2011/dudf-real//301cbe92-a79c-11e0-9181-00163e1e087d.cudf /home/misc2010/tmp/201108281254/packup2hy4tr-0.6/301cbe92-a79c-11e0-9181-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.05 1.00 0.98 4/37 20667
/proc/meminfo: memFree=216832/1048576 swapFree=0/0
[pid=20666] ppid=20665 vsize=2572 CPUtime=0
/proc/20666/stat : 20666 (packup2hy4tr-0.) S 20665 20666 17551 34817 17551 4202496 379 0 0 0 0 0 0 0 18 0 1 0 35786032 2633728 275 1283457024 134512640 135304128 4290360720 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/20666/statm: 643 275 233 194 0 30 0
[pid=20667] ppid=20666 vsize=3424 CPUtime=0
/proc/20667/stat : 20667 (packup) R 20666 20666 17551 34817 17551 4194304 229 0 0 0 0 0 0 0 25 0 1 0 35786033 3506176 159 1283457024 134512640 134752139 4291667632 18446744073709551615 4157595472 0 0 0 0 0 0 0 17 0 0 0 0
/proc/20667/statm: 856 159 132 59 0 20 0

[startup+0.186962 s]
/proc/loadavg: 1.05 1.00 0.98 4/37 20667
/proc/meminfo: memFree=216832/1048576 swapFree=0/0
[pid=20666] ppid=20665 vsize=2572 CPUtime=0
/proc/20666/stat : 20666 (packup2hy4tr-0.) S 20665 20666 17551 34817 17551 4202496 379 0 0 0 0 0 0 0 18 0 1 0 35786032 2633728 275 1283457024 134512640 135304128 4290360720 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/20666/statm: 643 275 233 194 0 30 0
[pid=20667] ppid=20666 vsize=7548 CPUtime=0.08
/proc/20667/stat : 20667 (packup) R 20666 20666 17551 34817 17551 4202496 1365 0 0 0 8 0 0 0 25 0 1 0 35786033 7729152 1293 1283457024 134512640 134752139 4291667632 18446744073709551615 134681513 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/20667/statm: 1887 1293 286 59 0 1051 0
Current children cumulated CPU time (s) 0.08
Current children cumulated vsize (KiB) 10120

[startup+0.206989 s]
/proc/loadavg: 1.05 1.00 0.98 4/37 20667
/proc/meminfo: memFree=216832/1048576 swapFree=0/0
[pid=20666] ppid=20665 vsize=2572 CPUtime=0
/proc/20666/stat : 20666 (packup2hy4tr-0.) S 20665 20666 17551 34817 17551 4202496 379 0 0 0 0 0 0 0 18 0 1 0 35786032 2633728 275 1283457024 134512640 135304128 4290360720 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/20666/statm: 643 275 233 194 0 30 0
[pid=20667] ppid=20666 vsize=7944 CPUtime=0.08
/proc/20667/stat : 20667 (packup) D 20666 20666 17551 34817 17551 4202496 1469 0 0 0 8 0 0 0 25 0 1 0 35786033 8134656 1397 1283457024 134512640 134752139 4291667632 18446744073709551615 4294960130 0 0 18944 8192 18446744071564332000 0 0 17 0 0 0 0
/proc/20667/statm: 1986 1397 286 59 0 1150 0
Current children cumulated CPU time (s) 0.08
Current children cumulated vsize (KiB) 10516

[startup+0.306985 s]
/proc/loadavg: 1.05 1.00 0.98 4/37 20667
/proc/meminfo: memFree=216832/1048576 swapFree=0/0
[pid=20666] ppid=20665 vsize=2572 CPUtime=0
/proc/20666/stat : 20666 (packup2hy4tr-0.) S 20665 20666 17551 34817 17551 4202496 379 0 0 0 0 0 0 0 18 0 1 0 35786032 2633728 275 1283457024 134512640 135304128 4290360720 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/20666/statm: 643 275 233 194 0 30 0
[pid=20667] ppid=20666 vsize=9660 CPUtime=0.12
/proc/20667/stat : 20667 (packup) D 20666 20666 17551 34817 17551 4202496 1905 0 0 0 12 0 0 0 25 0 1 0 35786033 9891840 1833 1283457024 134512640 134752139 4291667632 18446744073709551615 4294960130 0 0 18944 8192 18446744071564332000 0 0 17 0 0 0 0
/proc/20667/statm: 2415 1833 286 59 0 1579 0
Current children cumulated CPU time (s) 0.12
Current children cumulated vsize (KiB) 12232

[startup+0.707016 s]
/proc/loadavg: 1.05 1.00 0.98 4/37 20667
/proc/meminfo: memFree=216832/1048576 swapFree=0/0
[pid=20666] ppid=20665 vsize=2572 CPUtime=0
/proc/20666/stat : 20666 (packup2hy4tr-0.) S 20665 20666 17551 34817 17551 4202496 379 0 0 0 0 0 0 0 18 0 1 0 35786032 2633728 275 1283457024 134512640 135304128 4290360720 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/20666/statm: 643 275 233 194 0 30 0
[pid=20667] ppid=20666 vsize=15144 CPUtime=0.24
/proc/20667/stat : 20667 (packup) R 20666 20666 17551 34817 17551 4202496 3277 0 0 0 23 1 0 0 25 0 1 0 35786033 15507456 3205 1283457024 134512640 134752139 4291667632 18446744073709551615 134681659 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/20667/statm: 3786 3205 286 59 0 2950 0
Current children cumulated CPU time (s) 0.24
Current children cumulated vsize (KiB) 17716

[startup+1.50705 s]
/proc/loadavg: 1.05 1.00 0.98 2/38 20668
/proc/meminfo: memFree=189708/1048576 swapFree=0/0
[pid=20666] ppid=20665 vsize=2572 CPUtime=0
/proc/20666/stat : 20666 (packup2hy4tr-0.) S 20665 20666 17551 34817 17551 4202496 379 0 0 0 0 0 0 0 18 0 1 0 35786032 2633728 275 1283457024 134512640 135304128 4290360720 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/20666/statm: 643 275 233 194 0 30 0
[pid=20667] ppid=20666 vsize=25240 CPUtime=0.51
/proc/20667/stat : 20667 (packup) R 20666 20666 17551 34817 17551 4202496 5813 0 0 0 50 1 0 0 25 0 1 0 35786033 25845760 5741 1283457024 134512640 134752139 4291667632 18446744073709551615 134681639 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/20667/statm: 6310 5741 286 59 0 5474 0
Current children cumulated CPU time (s) 0.51
Current children cumulated vsize (KiB) 27812

[startup+3.10644 s]
/proc/loadavg: 1.05 1.00 0.98 1/38 20668
/proc/meminfo: memFree=167720/1048576 swapFree=0/0
[pid=20666] ppid=20665 vsize=2572 CPUtime=0
/proc/20666/stat : 20666 (packup2hy4tr-0.) S 20665 20666 17551 34817 17551 4202496 379 0 0 0 0 0 0 0 18 0 1 0 35786032 2633728 275 1283457024 134512640 135304128 4290360720 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/20666/statm: 643 275 233 194 0 30 0
[pid=20667] ppid=20666 vsize=50852 CPUtime=1.4
/proc/20667/stat : 20667 (packup) S 20666 20666 17551 34817 17551 4202496 12360 0 0 0 116 24 0 0 25 0 1 0 35786033 52072448 11975 1283457024 134512640 134752139 4291667632 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/20667/statm: 12713 11975 325 59 0 11877 0
Current children cumulated CPU time (s) 1.4
Current children cumulated vsize (KiB) 53424
heavy processes:

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

[startup+3.20646 s]
/proc/loadavg: 1.05 1.00 0.98 2/41 20674
/proc/meminfo: memFree=142440/1048576 swapFree=0/0
[pid=20666] ppid=20665 vsize=2572 CPUtime=0
/proc/20666/stat : 20666 (packup2hy4tr-0.) S 20665 20666 17551 34817 17551 4202496 379 0 0 0 0 0 0 0 18 0 1 0 35786032 2633728 275 1283457024 134512640 135304128 4290360720 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/20666/statm: 643 275 233 194 0 30 0
[pid=20667] ppid=20666 vsize=50852 CPUtime=1.4
/proc/20667/stat : 20667 (packup) S 20666 20666 17551 34817 17551 4202496 12360 0 0 0 116 24 0 0 25 0 1 0 35786033 52072448 11975 1283457024 134512640 134752139 4291667632 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/20667/statm: 12713 11975 325 59 0 11877 0
[pid=20669] ppid=20667 vsize=1668 CPUtime=0
/proc/20669/stat : 20669 (sh) S 20667 20666 17551 34817 17551 4202496 146 0 0 0 0 0 0 0 25 0 1 0 35786325 1708032 123 1283457024 134512640 134593992 4294947504 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/20669/statm: 417 123 108 20 0 44 0
[pid=20670] ppid=20669 vsize=2572 CPUtime=0.01
/proc/20670/stat : 20670 (run_h) S 20669 20666 17551 34817 17551 4202496 366 611 0 0 1 0 0 0 25 0 1 0 35786326 2633728 272 1283457024 134512640 135304128 4290805456 18446744073709551615 4294960130 0 65536 18948 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/20670/statm: 643 272 232 194 0 30 0
[pid=20674] ppid=20670 vsize=11824 CPUtime=0.26
/proc/20674/stat : 20674 (minisatp_32) R 20670 20666 17551 34817 17551 4202496 2058 0 0 0 25 1 0 0 25 0 1 0 35786326 12107776 1657 1283457024 134512640 135413687 4287806432 18446744073709551615 134661766 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/20674/statm: 2956 1657 77 220 0 2734 0
Current children cumulated CPU time (s) 1.67
Current children cumulated vsize (KiB) 69488

[startup+3.60657 s]
/proc/loadavg: 1.05 1.00 0.98 2/41 20674
/proc/meminfo: memFree=138100/1048576 swapFree=0/0
[pid=20666] ppid=20665 vsize=2572 CPUtime=0
/proc/20666/stat : 20666 (packup2hy4tr-0.) S 20665 20666 17551 34817 17551 4202496 379 0 0 0 0 0 0 0 18 0 1 0 35786032 2633728 275 1283457024 134512640 135304128 4290360720 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/20666/statm: 643 275 233 194 0 30 0
[pid=20667] ppid=20666 vsize=50852 CPUtime=1.4
/proc/20667/stat : 20667 (packup) S 20666 20666 17551 34817 17551 4202496 12360 0 0 0 116 24 0 0 25 0 1 0 35786033 52072448 11975 1283457024 134512640 134752139 4291667632 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/20667/statm: 12713 11975 325 59 0 11877 0
[pid=20669] ppid=20667 vsize=1668 CPUtime=0
/proc/20669/stat : 20669 (sh) S 20667 20666 17551 34817 17551 4202496 146 0 0 0 0 0 0 0 25 0 1 0 35786325 1708032 123 1283457024 134512640 134593992 4294947504 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/20669/statm: 417 123 108 20 0 44 0
[pid=20670] ppid=20669 vsize=2572 CPUtime=0.01
/proc/20670/stat : 20670 (run_h) S 20669 20666 17551 34817 17551 4202496 366 611 0 0 1 0 0 0 25 0 1 0 35786326 2633728 272 1283457024 134512640 135304128 4290805456 18446744073709551615 4294960130 0 65536 18948 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/20670/statm: 643 272 232 194 0 30 0
[pid=20674] ppid=20670 vsize=19976 CPUtime=0.66
/proc/20674/stat : 20674 (minisatp_32) R 20670 20666 17551 34817 17551 4202496 4238 0 0 0 62 4 0 0 25 0 1 0 35786326 20455424 3662 1283457024 134512640 135413687 4287806432 18446744073709551615 134961377 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/20674/statm: 4994 3662 77 220 0 4772 0
Current children cumulated CPU time (s) 2.07
Current children cumulated vsize (KiB) 77640

[startup+4.00666 s]
/proc/loadavg: 1.05 1.00 0.98 2/41 20674
/proc/meminfo: memFree=138100/1048576 swapFree=0/0
[pid=20666] ppid=20665 vsize=2572 CPUtime=0
/proc/20666/stat : 20666 (packup2hy4tr-0.) S 20665 20666 17551 34817 17551 4202496 379 0 0 0 0 0 0 0 18 0 1 0 35786032 2633728 275 1283457024 134512640 135304128 4290360720 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/20666/statm: 643 275 233 194 0 30 0
[pid=20667] ppid=20666 vsize=50080 CPUtime=2.48
/proc/20667/stat : 20667 (packup) R 20666 20666 17551 34817 17551 4202496 21424 6951 0 0 120 28 93 7 18 0 1 0 35786033 51281920 11802 1283457024 134512640 134752139 4291667632 18446744073709551615 4157532398 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/20667/statm: 12520 11802 346 59 0 11684 0
Current children cumulated CPU time (s) 2.48
Current children cumulated vsize (KiB) 52652

Child status: 0
Real time (s): 4.04611
CPU time (s): 2.51616
CPU user time (s): 2.16414
CPU system time (s): 0.352022
CPU usage (%): 62.187
Max. virtual memory (cumulated for all children) (KiB): 83132

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 2.16413
system time used= 0.352022
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 30647
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= 111
involuntary context switches= 114

runsolver used 0 second user time and 0.004 second system time

The end