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/56e31304-c17a-11df-b070-00163e3d3b7c.cudf.dudf-real.log.runsolver ./packup2mp4pa-0.6 /home/misc2010/data/2011/dudf-real//56e31304-c17a-11df-b070-00163e3d3b7c.cudf /home/misc2010/tmp/201108251442/packup2mp4pa-0.6/56e31304-c17a-11df-b070-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.51 1.42 1.28 5/37 23851
/proc/meminfo: memFree=297772/1048576 swapFree=0/0
[pid=23850] ppid=23849 vsize=2572 CPUtime=0
/proc/23850/stat : 23850 (packup2mp4pa-0.) S 23849 23850 4778 34817 4778 4202496 378 0 0 0 0 0 0 0 18 0 1 0 11176100 2633728 274 1283457024 134512640 135304128 4287982416 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/23850/statm: 643 274 233 194 0 30 0
[pid=23851] ppid=23850 vsize=4108 CPUtime=0.02
/proc/23851/stat : 23851 (packup) R 23850 23850 4778 34817 4778 4202496 517 0 0 0 2 0 0 0 25 0 1 0 11176100 4206592 446 1283457024 134512640 134752139 4290336096 18446744073709551615 134705919 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/23851/statm: 1027 446 286 59 0 191 0

[startup+0.173751 s]
/proc/loadavg: 1.51 1.42 1.28 5/37 23851
/proc/meminfo: memFree=297772/1048576 swapFree=0/0
[pid=23850] ppid=23849 vsize=2572 CPUtime=0
/proc/23850/stat : 23850 (packup2mp4pa-0.) S 23849 23850 4778 34817 4778 4202496 378 0 0 0 0 0 0 0 18 0 1 0 11176100 2633728 274 1283457024 134512640 135304128 4287982416 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/23850/statm: 643 274 233 194 0 30 0
[pid=23851] ppid=23850 vsize=9480 CPUtime=0.18
/proc/23851/stat : 23851 (packup) R 23850 23850 4778 34817 4778 4202496 1875 0 0 0 18 0 0 0 25 0 1 0 11176100 9707520 1804 1283457024 134512640 134752139 4290336096 18446744073709551615 134681798 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/23851/statm: 2370 1804 286 59 0 1534 0
Current children cumulated CPU time (s) 0.18
Current children cumulated vsize (KiB) 12052

[startup+0.203757 s]
/proc/loadavg: 1.51 1.42 1.28 5/37 23851
/proc/meminfo: memFree=297772/1048576 swapFree=0/0
[pid=23850] ppid=23849 vsize=2572 CPUtime=0
/proc/23850/stat : 23850 (packup2mp4pa-0.) S 23849 23850 4778 34817 4778 4202496 378 0 0 0 0 0 0 0 18 0 1 0 11176100 2633728 274 1283457024 134512640 135304128 4287982416 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/23850/statm: 643 274 233 194 0 30 0
[pid=23851] ppid=23850 vsize=10404 CPUtime=0.2
/proc/23851/stat : 23851 (packup) R 23850 23850 4778 34817 4778 4202496 2092 0 0 0 20 0 0 0 25 0 1 0 11176100 10653696 2021 1283457024 134512640 134752139 4290336096 18446744073709551615 134681895 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/23851/statm: 2601 2021 286 59 0 1765 0
Current children cumulated CPU time (s) 0.2
Current children cumulated vsize (KiB) 12976

[startup+0.313773 s]
/proc/loadavg: 1.51 1.42 1.28 5/37 23851
/proc/meminfo: memFree=297772/1048576 swapFree=0/0
[pid=23850] ppid=23849 vsize=2572 CPUtime=0
/proc/23850/stat : 23850 (packup2mp4pa-0.) S 23849 23850 4778 34817 4778 4202496 378 0 0 0 0 0 0 0 18 0 1 0 11176100 2633728 274 1283457024 134512640 135304128 4287982416 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/23850/statm: 643 274 233 194 0 30 0
[pid=23851] ppid=23850 vsize=13504 CPUtime=0.31
/proc/23851/stat : 23851 (packup) R 23850 23850 4778 34817 4778 4202496 2872 0 0 0 30 1 0 0 25 0 1 0 11176100 13828096 2801 1283457024 134512640 134752139 4290336096 18446744073709551615 134707874 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/23851/statm: 3376 2801 286 59 0 2540 0
Current children cumulated CPU time (s) 0.31
Current children cumulated vsize (KiB) 16076

[startup+0.713905 s]
/proc/loadavg: 1.51 1.42 1.28 5/37 23851
/proc/meminfo: memFree=297772/1048576 swapFree=0/0
[pid=23850] ppid=23849 vsize=2572 CPUtime=0
/proc/23850/stat : 23850 (packup2mp4pa-0.) S 23849 23850 4778 34817 4778 4202496 378 0 0 0 0 0 0 0 18 0 1 0 11176100 2633728 274 1283457024 134512640 135304128 4287982416 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/23850/statm: 643 274 233 194 0 30 0
[pid=23851] ppid=23850 vsize=23468 CPUtime=0.71
/proc/23851/stat : 23851 (packup) R 23850 23850 4778 34817 4778 4202496 5348 0 0 0 70 1 0 0 25 0 1 0 11176100 24031232 5277 1283457024 134512640 134752139 4290336096 18446744073709551615 134640552 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/23851/statm: 5867 5277 286 59 0 5031 0
Current children cumulated CPU time (s) 0.71
Current children cumulated vsize (KiB) 26040

[startup+1.51393 s]
/proc/loadavg: 1.47 1.41 1.27 2/38 23852
/proc/meminfo: memFree=265076/1048576 swapFree=0/0
[pid=23850] ppid=23849 vsize=2572 CPUtime=0
/proc/23850/stat : 23850 (packup2mp4pa-0.) S 23849 23850 4778 34817 4778 4202496 378 0 0 0 0 0 0 0 18 0 1 0 11176100 2633728 274 1283457024 134512640 135304128 4287982416 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/23850/statm: 643 274 233 194 0 30 0
[pid=23851] ppid=23850 vsize=40228 CPUtime=1.36
/proc/23851/stat : 23851 (packup) S 23850 23850 4778 34817 4778 4202496 9674 0 0 0 120 16 0 0 25 0 1 0 11176100 41193472 9365 1283457024 134512640 134752139 4290336096 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/23851/statm: 10057 9365 324 59 0 9221 0
Current children cumulated CPU time (s) 1.36
Current children cumulated vsize (KiB) 42800

[startup+3.10416 s]
/proc/loadavg: 1.47 1.41 1.27 2/40 23854
/proc/meminfo: memFree=243468/1048576 swapFree=0/0
[pid=23850] ppid=23849 vsize=2572 CPUtime=0
/proc/23850/stat : 23850 (packup2mp4pa-0.) S 23849 23850 4778 34817 4778 4202496 378 0 0 0 0 0 0 0 18 0 1 0 11176100 2633728 274 1283457024 134512640 135304128 4287982416 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/23850/statm: 643 274 233 194 0 30 0
[pid=23851] ppid=23850 vsize=40232 CPUtime=3.08
/proc/23851/stat : 23851 (packup) R 23850 23850 4778 34817 4778 4202496 9734 13588 0 0 124 25 146 13 18 0 1 0 11176100 41197568 9374 1283457024 134512640 134752139 4290336096 18446744073709551615 4294960130 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/23851/statm: 10058 9374 332 59 0 9222 0
Current children cumulated CPU time (s) 3.08
Current children cumulated vsize (KiB) 42804

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

[startup+3.20418 s]
/proc/loadavg: 1.47 1.41 1.27 2/40 23854
/proc/meminfo: memFree=243468/1048576 swapFree=0/0
[pid=23850] ppid=23849 vsize=2572 CPUtime=0
/proc/23850/stat : 23850 (packup2mp4pa-0.) S 23849 23850 4778 34817 4778 4202496 378 0 0 0 0 0 0 0 18 0 1 0 11176100 2633728 274 1283457024 134512640 135304128 4287982416 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/23850/statm: 643 274 233 194 0 30 0
[pid=23851] ppid=23850 vsize=40232 CPUtime=3.16
/proc/23851/stat : 23851 (packup) R 23850 23850 4778 34817 4778 4202496 9734 13588 0 0 128 29 146 13 18 0 1 0 11176100 41197568 9374 1283457024 134512640 134752139 4290336096 18446744073709551615 4294960130 0 65536 18950 8192 0 0 0 17 0 0 0 0
/proc/23851/statm: 10058 9374 332 59 0 9222 0
Current children cumulated CPU time (s) 3.16
Current children cumulated vsize (KiB) 42804

[startup+4.80447 s]
/proc/loadavg: 1.47 1.41 1.27 2/40 23858
/proc/meminfo: memFree=212468/1048576 swapFree=0/0
[pid=23850] ppid=23849 vsize=2572 CPUtime=0
/proc/23850/stat : 23850 (packup2mp4pa-0.) S 23849 23850 4778 34817 4778 4202496 378 0 0 0 0 0 0 0 18 0 1 0 11176100 2633728 274 1283457024 134512640 135304128 4287982416 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/23850/statm: 643 274 233 194 0 30 0
[pid=23851] ppid=23850 vsize=40232 CPUtime=3.16
/proc/23851/stat : 23851 (packup) S 23850 23850 4778 34817 4778 4202496 9735 13588 0 0 128 29 146 13 18 0 1 0 11176100 41197568 9374 1283457024 134512640 134752139 4290336096 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/23851/statm: 10058 9374 332 59 0 9222 0
[pid=23857] ppid=23851 vsize=1672 CPUtime=0
/proc/23857/stat : 23857 (sh) S 23851 23850 4778 34817 4778 4202496 146 0 0 0 0 0 0 0 18 0 1 0 11176418 1712128 124 1283457024 134512640 134593992 4290045424 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/23857/statm: 418 124 108 20 0 45 0
[pid=23858] ppid=23857 vsize=62976 CPUtime=1.61
/proc/23858/stat : 23858 (minisatp_32) R 23857 23850 4778 34817 4778 4202496 19836 0 0 0 145 16 0 0 25 0 1 0 11176418 64487424 13826 1283457024 134512640 135413687 4293829040 18446744073709551615 134696716 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/23858/statm: 15744 13826 108 220 0 15522 0
Current children cumulated CPU time (s) 4.77
Current children cumulated vsize (KiB) 107452

[startup+5.2046 s]
/proc/loadavg: 1.47 1.41 1.27 2/40 23858
/proc/meminfo: memFree=212468/1048576 swapFree=0/0
[pid=23850] ppid=23849 vsize=2572 CPUtime=0
/proc/23850/stat : 23850 (packup2mp4pa-0.) S 23849 23850 4778 34817 4778 4202496 378 0 0 0 0 0 0 0 18 0 1 0 11176100 2633728 274 1283457024 134512640 135304128 4287982416 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/23850/statm: 643 274 233 194 0 30 0
[pid=23851] ppid=23850 vsize=40232 CPUtime=3.16
/proc/23851/stat : 23851 (packup) S 23850 23850 4778 34817 4778 4202496 9735 13588 0 0 128 29 146 13 18 0 1 0 11176100 41197568 9374 1283457024 134512640 134752139 4290336096 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/23851/statm: 10058 9374 332 59 0 9222 0
[pid=23857] ppid=23851 vsize=1672 CPUtime=0
/proc/23857/stat : 23857 (sh) S 23851 23850 4778 34817 4778 4202496 146 0 0 0 0 0 0 0 18 0 1 0 11176418 1712128 124 1283457024 134512640 134593992 4290045424 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/23857/statm: 418 124 108 20 0 45 0
[pid=23858] ppid=23857 vsize=71372 CPUtime=2.01
/proc/23858/stat : 23858 (minisatp_32) R 23857 23850 4778 34817 4778 4202496 21312 0 0 0 185 16 0 0 25 0 1 0 11176418 73084928 15267 1283457024 134512640 135413687 4293829040 18446744073709551615 134683810 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/23858/statm: 17843 15267 108 220 0 17621 0
Current children cumulated CPU time (s) 5.17
Current children cumulated vsize (KiB) 115848

[startup+5.40465 s]
/proc/loadavg: 1.47 1.41 1.27 2/40 23858
/proc/meminfo: memFree=212468/1048576 swapFree=0/0
[pid=23850] ppid=23849 vsize=2572 CPUtime=0
/proc/23850/stat : 23850 (packup2mp4pa-0.) S 23849 23850 4778 34817 4778 4202496 378 0 0 0 0 0 0 0 18 0 1 0 11176100 2633728 274 1283457024 134512640 135304128 4287982416 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/23850/statm: 643 274 233 194 0 30 0
[pid=23851] ppid=23850 vsize=37960 CPUtime=5.38
/proc/23851/stat : 23851 (packup) R 23850 23850 4778 34817 4778 4202496 18031 35503 0 0 132 33 343 30 18 0 1 0 11176100 38871040 8954 1283457024 134512640 134752139 4290336096 18446744073709551615 4157302173 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/23851/statm: 9490 8954 345 59 0 8654 0
Current children cumulated CPU time (s) 5.38
Current children cumulated vsize (KiB) 40532

Child status: 0
Real time (s): 5.42794
CPU time (s): 5.42034
CPU user time (s): 4.7603
CPU system time (s): 0.660041
CPU usage (%): 99.8599
Max. virtual memory (cumulated for all children) (KiB): 115848

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 4.7603
system time used= 0.660041
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 54260
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= 124

runsolver used 0 second user time and 0 second system time

The end