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/rand230.cudf.s-e.log.runsolver ./packup2mp4pa-0.6 /home/misc2010/data/2011/incremental/s-e/rand230.cudf /home/misc2010/tmp/201108251442/packup2mp4pa-0.6/rand230.cudf.s-e.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.31 1.09 1.02 4/35 8698
/proc/meminfo: memFree=357544/1048576 swapFree=0/0
[pid=8697] ppid=8696 vsize=2564 CPUtime=0
/proc/8697/stat : 8697 (packup2mp4pa-0.) S 8696 8697 4778 34817 4778 4202496 376 0 0 0 0 0 0 0 18 0 1 0 10326446 2625536 273 1283457024 134512640 135304128 4286601776 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/8697/statm: 641 273 233 194 0 28 0
[pid=8698] ppid=8697 vsize=3716 CPUtime=0.01
/proc/8698/stat : 8698 (packup) R 8697 8697 4778 34817 4778 4202496 403 0 0 0 1 0 0 0 25 0 1 0 10326446 3805184 332 1283457024 134512640 134752139 4292339584 18446744073709551615 134694840 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/8698/statm: 929 332 286 59 0 93 0

[startup+0.153535 s]
/proc/loadavg: 1.31 1.09 1.02 4/35 8698
/proc/meminfo: memFree=357544/1048576 swapFree=0/0
[pid=8697] ppid=8696 vsize=2564 CPUtime=0
/proc/8697/stat : 8697 (packup2mp4pa-0.) S 8696 8697 4778 34817 4778 4202496 376 0 0 0 0 0 0 0 18 0 1 0 10326446 2625536 273 1283457024 134512640 135304128 4286601776 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/8697/statm: 641 273 233 194 0 28 0
[pid=8698] ppid=8697 vsize=9420 CPUtime=0.16
/proc/8698/stat : 8698 (packup) R 8697 8697 4778 34817 4778 4202496 1828 0 0 0 16 0 0 0 25 0 1 0 10326446 9646080 1757 1283457024 134512640 134752139 4292339584 18446744073709551615 134681788 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/8698/statm: 2355 1757 286 59 0 1519 0
Current children cumulated CPU time (s) 0.16
Current children cumulated vsize (KiB) 11984

[startup+0.203547 s]
/proc/loadavg: 1.31 1.09 1.02 4/35 8698
/proc/meminfo: memFree=357544/1048576 swapFree=0/0
[pid=8697] ppid=8696 vsize=2564 CPUtime=0
/proc/8697/stat : 8697 (packup2mp4pa-0.) S 8696 8697 4778 34817 4778 4202496 376 0 0 0 0 0 0 0 18 0 1 0 10326446 2625536 273 1283457024 134512640 135304128 4286601776 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/8697/statm: 641 273 233 194 0 28 0
[pid=8698] ppid=8697 vsize=11004 CPUtime=0.21
/proc/8698/stat : 8698 (packup) R 8697 8697 4778 34817 4778 4202496 2231 0 0 0 21 0 0 0 25 0 1 0 10326446 11268096 2160 1283457024 134512640 134752139 4292339584 18446744073709551615 134681536 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/8698/statm: 2751 2160 286 59 0 1915 0
Current children cumulated CPU time (s) 0.21
Current children cumulated vsize (KiB) 13568

[startup+0.313564 s]
/proc/loadavg: 1.31 1.09 1.02 4/35 8698
/proc/meminfo: memFree=357544/1048576 swapFree=0/0
[pid=8697] ppid=8696 vsize=2564 CPUtime=0
/proc/8697/stat : 8697 (packup2mp4pa-0.) S 8696 8697 4778 34817 4778 4202496 376 0 0 0 0 0 0 0 18 0 1 0 10326446 2625536 273 1283457024 134512640 135304128 4286601776 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/8697/statm: 641 273 233 194 0 28 0
[pid=8698] ppid=8697 vsize=14340 CPUtime=0.31
/proc/8698/stat : 8698 (packup) R 8697 8697 4778 34817 4778 4202496 3071 0 0 0 31 0 0 0 25 0 1 0 10326446 14684160 3000 1283457024 134512640 134752139 4292339584 18446744073709551615 134694907 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/8698/statm: 3585 3000 286 59 0 2749 0
Current children cumulated CPU time (s) 0.31
Current children cumulated vsize (KiB) 16904

[startup+0.713637 s]
/proc/loadavg: 1.31 1.09 1.02 4/35 8698
/proc/meminfo: memFree=357544/1048576 swapFree=0/0
[pid=8697] ppid=8696 vsize=2564 CPUtime=0
/proc/8697/stat : 8697 (packup2mp4pa-0.) S 8696 8697 4778 34817 4778 4202496 376 0 0 0 0 0 0 0 18 0 1 0 10326446 2625536 273 1283457024 134512640 135304128 4286601776 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/8697/statm: 641 273 233 194 0 28 0
[pid=8698] ppid=8697 vsize=25716 CPUtime=0.7
/proc/8698/stat : 8698 (packup) R 8697 8697 4778 34817 4778 4202496 5956 0 0 0 64 6 0 0 25 0 1 0 10326446 26333184 5800 1283457024 134512640 134752139 4292339584 18446744073709551615 4294960130 0 65536 18950 8192 0 0 0 17 0 0 0 0
/proc/8698/statm: 6429 5800 323 59 0 5593 0
Current children cumulated CPU time (s) 0.7
Current children cumulated vsize (KiB) 28280

[startup+1.51378 s]
/proc/loadavg: 1.31 1.09 1.02 2/38 8701
/proc/meminfo: memFree=326252/1048576 swapFree=0/0
[pid=8697] ppid=8696 vsize=2564 CPUtime=0
/proc/8697/stat : 8697 (packup2mp4pa-0.) S 8696 8697 4778 34817 4778 4202496 376 0 0 0 0 0 0 0 18 0 1 0 10326446 2625536 273 1283457024 134512640 135304128 4286601776 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/8697/statm: 641 273 233 194 0 28 0
[pid=8698] ppid=8697 vsize=25720 CPUtime=1.5
/proc/8698/stat : 8698 (packup) R 8697 8697 4778 34817 4778 4202496 6005 6044 0 0 70 12 61 7 19 0 1 0 10326446 26337280 5810 1283457024 134512640 134752139 4292339584 18446744073709551615 4294960130 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/8698/statm: 6430 5810 332 59 0 5594 0
Current children cumulated CPU time (s) 1.5
Current children cumulated vsize (KiB) 28284

[startup+3.10427 s]
/proc/loadavg: 1.29 1.08 1.02 2/38 8703
/proc/meminfo: memFree=318812/1048576 swapFree=0/0
[pid=8697] ppid=8696 vsize=2564 CPUtime=0
/proc/8697/stat : 8697 (packup2mp4pa-0.) S 8696 8697 4778 34817 4778 4202496 376 0 0 0 0 0 0 0 18 0 1 0 10326446 2625536 273 1283457024 134512640 135304128 4286601776 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/8697/statm: 641 273 233 194 0 28 0
[pid=8698] ppid=8697 vsize=25720 CPUtime=1.5
/proc/8698/stat : 8698 (packup) S 8697 8697 4778 34817 4778 4202496 6006 6044 0 0 70 12 61 7 19 0 1 0 10326446 26337280 5810 1283457024 134512640 134752139 4292339584 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/8698/statm: 6430 5810 332 59 0 5594 0
[pid=8702] ppid=8698 vsize=1672 CPUtime=0
/proc/8702/stat : 8702 (sh) S 8698 8697 4778 34817 4778 4202496 146 0 0 0 0 0 0 0 19 0 1 0 10326597 1712128 124 1283457024 134512640 134593992 4289230128 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/8702/statm: 418 124 108 20 0 45 0
[pid=8703] ppid=8702 vsize=44620 CPUtime=1.58
/proc/8703/stat : 8703 (minisatp_32) R 8702 8697 4778 34817 4778 4202496 14548 0 0 0 151 7 0 0 25 0 1 0 10326598 45690880 9579 1283457024 134512640 135413687 4288826592 18446744073709551615 134649535 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/8703/statm: 11155 9579 111 220 0 10933 0
Current children cumulated CPU time (s) 3.08
Current children cumulated vsize (KiB) 74576

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

[startup+3.2043 s]
/proc/loadavg: 1.29 1.08 1.02 2/38 8703
/proc/meminfo: memFree=318812/1048576 swapFree=0/0
[pid=8697] ppid=8696 vsize=2564 CPUtime=0
/proc/8697/stat : 8697 (packup2mp4pa-0.) S 8696 8697 4778 34817 4778 4202496 376 0 0 0 0 0 0 0 18 0 1 0 10326446 2625536 273 1283457024 134512640 135304128 4286601776 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/8697/statm: 641 273 233 194 0 28 0
[pid=8698] ppid=8697 vsize=25720 CPUtime=1.5
/proc/8698/stat : 8698 (packup) S 8697 8697 4778 34817 4778 4202496 6006 6044 0 0 70 12 61 7 19 0 1 0 10326446 26337280 5810 1283457024 134512640 134752139 4292339584 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/8698/statm: 6430 5810 332 59 0 5594 0
[pid=8702] ppid=8698 vsize=1672 CPUtime=0
/proc/8702/stat : 8702 (sh) S 8698 8697 4778 34817 4778 4202496 146 0 0 0 0 0 0 0 19 0 1 0 10326597 1712128 124 1283457024 134512640 134593992 4289230128 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/8702/statm: 418 124 108 20 0 45 0
[pid=8703] ppid=8702 vsize=42712 CPUtime=1.68
/proc/8703/stat : 8703 (minisatp_32) R 8702 8697 4778 34817 4778 4202496 14561 0 0 0 161 7 0 0 25 0 1 0 10326598 43737088 9217 1283457024 134512640 135413687 4288826592 18446744073709551615 134597339 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/8703/statm: 10678 9217 121 220 0 10456 0
Current children cumulated CPU time (s) 3.18
Current children cumulated vsize (KiB) 72668

Child status: 0
Real time (s): 3.27294
CPU time (s): 3.2682
CPU user time (s): 2.97219
CPU system time (s): 0.296018
CPU usage (%): 99.8554
Max. virtual memory (cumulated for all children) (KiB): 75732

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 2.97219
system time used= 0.296018
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 32384
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= 11
involuntary context switches= 75

runsolver used 0 second user time and 0 second system time

The end