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/7c834c0e-51b8-11e0-a49e-00163e1e087d.cudf.dudf-real.log.runsolver ./packup2hy4tr-0.6 /home/misc2010/data/2011/dudf-real//7c834c0e-51b8-11e0-a49e-00163e1e087d.cudf /home/misc2010/tmp/201108281254/packup2hy4tr-0.6/7c834c0e-51b8-11e0-a49e-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.02 1.05 1.00 4/36 22847
/proc/meminfo: memFree=218620/1048576 swapFree=0/0
[pid=22847] ppid=22846 vsize=2532 CPUtime=0.01
/proc/22847/stat : 22847 (packup2hy4tr-0.) R 22846 22847 17551 34817 17551 4194304 168 0 0 0 0 1 0 0 25 0 1 0 36011260 2592768 91 1283457024 134512640 135304128 4288777232 18446744073709551615 4160030434 0 0 0 0 0 0 0 17 0 0 0 0
/proc/22847/statm: 633 91 73 194 0 16 0

[startup+0.134951 s]
/proc/loadavg: 1.02 1.05 1.00 4/36 22847
/proc/meminfo: memFree=218620/1048576 swapFree=0/0
[pid=22847] ppid=22846 vsize=2572 CPUtime=0.01
/proc/22847/stat : 22847 (packup2hy4tr-0.) S 22846 22847 17551 34817 17551 4202496 378 0 0 0 0 1 0 0 25 0 1 0 36011260 2633728 274 1283457024 134512640 135304128 4288777232 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/22847/statm: 643 274 233 194 0 30 0
Current children cumulated CPU time (s) 0.01
Current children cumulated vsize (KiB) 2572

[startup+0.2069 s]
/proc/loadavg: 1.02 1.05 1.00 4/36 22847
/proc/meminfo: memFree=218620/1048576 swapFree=0/0
[pid=22847] ppid=22846 vsize=2572 CPUtime=0.01
/proc/22847/stat : 22847 (packup2hy4tr-0.) S 22846 22847 17551 34817 17551 4202496 378 0 0 0 0 1 0 0 25 0 1 0 36011260 2633728 274 1283457024 134512640 135304128 4288777232 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/22847/statm: 643 274 233 194 0 30 0
Current children cumulated CPU time (s) 0.01
Current children cumulated vsize (KiB) 2572

[startup+0.306904 s]
/proc/loadavg: 1.02 1.05 1.00 4/36 22847
/proc/meminfo: memFree=218620/1048576 swapFree=0/0
[pid=22847] ppid=22846 vsize=2572 CPUtime=0.01
/proc/22847/stat : 22847 (packup2hy4tr-0.) S 22846 22847 17551 34817 17551 4202496 378 0 0 0 0 1 0 0 25 0 1 0 36011260 2633728 274 1283457024 134512640 135304128 4288777232 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/22847/statm: 643 274 233 194 0 30 0
Current children cumulated CPU time (s) 0.01
Current children cumulated vsize (KiB) 2572

[startup+0.706922 s]
/proc/loadavg: 1.02 1.05 1.00 4/36 22847
/proc/meminfo: memFree=218620/1048576 swapFree=0/0
[pid=22847] ppid=22846 vsize=2572 CPUtime=0.01
/proc/22847/stat : 22847 (packup2hy4tr-0.) S 22846 22847 17551 34817 17551 4202496 378 0 0 0 0 1 0 0 25 0 1 0 36011260 2633728 274 1283457024 134512640 135304128 4288777232 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/22847/statm: 643 274 233 194 0 30 0
Current children cumulated CPU time (s) 0.01
Current children cumulated vsize (KiB) 2572

[startup+1.50704 s]
/proc/loadavg: 1.02 1.05 1.00 2/38 22849
/proc/meminfo: memFree=185408/1048576 swapFree=0/0
[pid=22847] ppid=22846 vsize=2572 CPUtime=0.01
/proc/22847/stat : 22847 (packup2hy4tr-0.) S 22846 22847 17551 34817 17551 4202496 378 0 0 0 0 1 0 0 25 0 1 0 36011260 2633728 274 1283457024 134512640 135304128 4288777232 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/22847/statm: 643 274 233 194 0 30 0
[pid=22849] ppid=22847 vsize=35528 CPUtime=0.95
/proc/22849/stat : 22849 (packup) R 22847 22847 17551 34817 17551 4202496 8408 0 0 0 86 9 0 0 25 0 1 0 36011260 36380672 8218 1283457024 134512640 134752139 4287050304 18446744073709551615 4294960130 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/22849/statm: 8882 8218 321 59 0 8046 0
Current children cumulated CPU time (s) 0.96
Current children cumulated vsize (KiB) 38100

[startup+3.10745 s]
/proc/loadavg: 1.02 1.05 1.00 2/41 22855
/proc/meminfo: memFree=156120/1048576 swapFree=0/0
[pid=22847] ppid=22846 vsize=2572 CPUtime=0.01
/proc/22847/stat : 22847 (packup2hy4tr-0.) S 22846 22847 17551 34817 17551 4202496 378 0 0 0 0 1 0 0 25 0 1 0 36011260 2633728 274 1283457024 134512640 135304128 4288777232 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/22847/statm: 643 274 233 194 0 30 0
[pid=22849] ppid=22847 vsize=35528 CPUtime=1.04
/proc/22849/stat : 22849 (packup) S 22847 22847 17551 34817 17551 4202496 8412 0 0 0 90 14 0 0 25 0 1 0 36011260 36380672 8221 1283457024 134512640 134752139 4287050304 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/22849/statm: 8882 8221 324 59 0 8046 0
[pid=22850] ppid=22849 vsize=1672 CPUtime=0
/proc/22850/stat : 22850 (sh) S 22849 22847 17551 34817 17551 4202496 147 0 0 0 0 0 0 0 25 0 1 0 36011419 1712128 124 1283457024 134512640 134593992 4292372544 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/22850/statm: 418 124 108 20 0 45 0
[pid=22851] ppid=22850 vsize=2568 CPUtime=0.01
/proc/22851/stat : 22851 (run_h) S 22850 22847 17551 34817 17551 4202496 365 611 0 0 0 1 0 0 25 0 1 0 36011420 2629632 272 1283457024 134512640 135304128 4291198768 18446744073709551615 4294960130 0 65536 18948 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/22851/statm: 642 272 232 194 0 29 0
[pid=22855] ppid=22851 vsize=54856 CPUtime=1.49
/proc/22855/stat : 22855 (minisatp_32) R 22851 22847 17551 34817 17551 4202496 17502 0 0 0 135 14 0 0 25 0 1 0 36011421 56172544 12112 1283457024 134512640 135413687 4289535376 18446744073709551615 134686235 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/22855/statm: 13714 12112 108 220 0 13492 0
Current children cumulated CPU time (s) 2.55
Current children cumulated vsize (KiB) 97196

[startup+6.30948 s]
/proc/loadavg: 1.10 1.06 1.01 2/41 22867
/proc/meminfo: memFree=161700/1048576 swapFree=0/0
[pid=22847] ppid=22846 vsize=2572 CPUtime=0.01
/proc/22847/stat : 22847 (packup2hy4tr-0.) S 22846 22847 17551 34817 17551 4202496 378 0 0 0 0 1 0 0 25 0 1 0 36011260 2633728 274 1283457024 134512640 135304128 4288777232 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/22847/statm: 643 274 233 194 0 30 0
[pid=22849] ppid=22847 vsize=35536 CPUtime=4.58
/proc/22849/stat : 22849 (packup) S 22847 22847 17551 34817 17551 4202496 8545 31970 0 0 107 33 292 26 18 0 1 0 36011260 36388864 8240 1283457024 134512640 134752139 4287050304 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/22849/statm: 8884 8240 332 59 0 8048 0
[pid=22862] ppid=22849 vsize=1676 CPUtime=0
/proc/22862/stat : 22862 (sh) S 22849 22847 17551 34817 17551 4202496 148 0 0 0 0 0 0 0 18 0 1 0 36011784 1716224 124 1283457024 134512640 134593992 4288414832 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/22862/statm: 419 124 108 20 0 46 0
[pid=22863] ppid=22862 vsize=2576 CPUtime=0
/proc/22863/stat : 22863 (run_h) S 22862 22847 17551 34817 17551 4202496 369 611 0 0 0 0 0 0 20 0 1 0 36011784 2637824 274 1283457024 134512640 135304128 4290684592 18446744073709551615 4294960130 0 65536 18948 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/22863/statm: 644 274 232 194 0 31 0
[pid=22867] ppid=22863 vsize=31988 CPUtime=1.06
/proc/22867/stat : 22867 (minisatp_32) R 22863 22847 17551 34817 17551 4202496 9816 0 0 0 94 12 0 0 25 0 1 0 36011784 32755712 7286 1283457024 134512640 135413687 4294494784 18446744073709551615 134980953 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/22867/statm: 7997 7286 94 220 0 7775 0
Current children cumulated CPU time (s) 5.65
Current children cumulated vsize (KiB) 74348

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

[startup+6.40951 s]
/proc/loadavg: 1.10 1.06 1.01 2/41 22867
/proc/meminfo: memFree=161700/1048576 swapFree=0/0
[pid=22847] ppid=22846 vsize=2572 CPUtime=0.01
/proc/22847/stat : 22847 (packup2hy4tr-0.) S 22846 22847 17551 34817 17551 4202496 378 0 0 0 0 1 0 0 25 0 1 0 36011260 2633728 274 1283457024 134512640 135304128 4288777232 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/22847/statm: 643 274 233 194 0 30 0
[pid=22849] ppid=22847 vsize=35536 CPUtime=4.58
/proc/22849/stat : 22849 (packup) S 22847 22847 17551 34817 17551 4202496 8545 31970 0 0 107 33 292 26 18 0 1 0 36011260 36388864 8240 1283457024 134512640 134752139 4287050304 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/22849/statm: 8884 8240 332 59 0 8048 0
[pid=22862] ppid=22849 vsize=1676 CPUtime=0
/proc/22862/stat : 22862 (sh) S 22849 22847 17551 34817 17551 4202496 148 0 0 0 0 0 0 0 18 0 1 0 36011784 1716224 124 1283457024 134512640 134593992 4288414832 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/22862/statm: 419 124 108 20 0 46 0
[pid=22863] ppid=22862 vsize=2576 CPUtime=0
/proc/22863/stat : 22863 (run_h) S 22862 22847 17551 34817 17551 4202496 369 611 0 0 0 0 0 0 20 0 1 0 36011784 2637824 274 1283457024 134512640 135304128 4290684592 18446744073709551615 4294960130 0 65536 18948 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/22863/statm: 644 274 232 194 0 31 0
[pid=22867] ppid=22863 vsize=31420 CPUtime=1.16
/proc/22867/stat : 22867 (minisatp_32) R 22863 22847 17551 34817 17551 4202496 10532 0 0 0 104 12 0 0 25 0 1 0 36011784 32174080 7108 1283457024 134512640 135413687 4294494784 18446744073709551615 134698544 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/22867/statm: 7855 7108 94 220 0 7633 0
Current children cumulated CPU time (s) 5.75
Current children cumulated vsize (KiB) 73780

[startup+8.00993 s]
/proc/loadavg: 1.10 1.06 1.01 2/43 22878
/proc/meminfo: memFree=105620/1048576 swapFree=0/0
[pid=22847] ppid=22846 vsize=2572 CPUtime=0.01
/proc/22847/stat : 22847 (packup2hy4tr-0.) S 22846 22847 17551 34817 17551 4202496 378 0 0 0 0 1 0 0 25 0 1 0 36011260 2633728 274 1283457024 134512640 135304128 4288777232 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/22847/statm: 643 274 233 194 0 30 0
[pid=22849] ppid=22847 vsize=35540 CPUtime=6.04
/proc/22849/stat : 22849 (packup) S 22847 22847 17551 34817 17551 4202496 8605 43818 0 0 115 44 406 39 18 0 1 0 36011260 36392960 8241 1283457024 134512640 134752139 4287050304 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/22849/statm: 8885 8241 332 59 0 8049 0
[pid=22868] ppid=22849 vsize=1672 CPUtime=0
/proc/22868/stat : 22868 (sh) S 22849 22847 17551 34817 17551 4202496 147 0 0 0 0 0 0 0 18 0 1 0 36011930 1712128 124 1283457024 134512640 134593992 4293964224 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/22868/statm: 418 124 108 20 0 45 0
[pid=22869] ppid=22868 vsize=2568 CPUtime=0
/proc/22869/stat : 22869 (run_h) S 22868 22847 17551 34817 17551 4202496 367 613 0 0 0 0 0 0 20 0 1 0 36011930 2629632 273 1283457024 134512640 135304128 4292220976 18446744073709551615 4294960130 0 65536 18948 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/22869/statm: 642 273 232 194 0 29 0
[pid=22873] ppid=22869 vsize=2564 CPUtime=0
/proc/22873/stat : 22873 (run_scip) S 22869 22847 17551 34817 17551 4202496 390 756 0 0 0 0 0 0 22 0 1 0 36011931 2625536 268 1283457024 134512640 135304128 4289043744 18446744073709551615 4294960130 0 65536 18948 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/22873/statm: 641 268 228 194 0 28 0
[pid=22877] ppid=22873 vsize=71272 CPUtime=1.28
/proc/22877/stat : 22877 (scip-2.0.1.linu) R 22873 22847 17551 34817 17551 4202496 16875 0 0 0 110 18 0 0 25 0 1 0 36011931 72982528 15673 1283457024 134512640 143279753 4287927248 18446744073709551615 4294960130 0 0 18944 2 0 0 0 17 0 0 0 0
/proc/22877/statm: 17818 15673 608 2141 0 15674 0
[pid=22878] ppid=22873 vsize=7196 CPUtime=0
/proc/22878/stat : 22878 (scip2v) S 22873 22847 17551 34817 17551 4202496 1008 0 0 0 0 0 0 0 18 0 1 0 36011944 7368704 847 1283457024 134512640 136477024 4290442880 18446744073709551615 4294960130 0 0 16800256 2 18446744071564457842 0 0 17 0 0 0 0
/proc/22878/statm: 1799 847 474 480 0 384 0
Current children cumulated CPU time (s) 7.33
Current children cumulated vsize (KiB) 123384

[startup+8.81013 s]
/proc/loadavg: 1.10 1.06 1.01 2/43 22878
/proc/meminfo: memFree=103388/1048576 swapFree=0/0
[pid=22847] ppid=22846 vsize=2572 CPUtime=0.01
/proc/22847/stat : 22847 (packup2hy4tr-0.) S 22846 22847 17551 34817 17551 4202496 378 0 0 0 0 1 0 0 25 0 1 0 36011260 2633728 274 1283457024 134512640 135304128 4288777232 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/22847/statm: 643 274 233 194 0 30 0
[pid=22849] ppid=22847 vsize=35540 CPUtime=6.04
/proc/22849/stat : 22849 (packup) S 22847 22847 17551 34817 17551 4202496 8605 43818 0 0 115 44 406 39 18 0 1 0 36011260 36392960 8241 1283457024 134512640 134752139 4287050304 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/22849/statm: 8885 8241 332 59 0 8049 0
[pid=22868] ppid=22849 vsize=1672 CPUtime=0
/proc/22868/stat : 22868 (sh) S 22849 22847 17551 34817 17551 4202496 147 0 0 0 0 0 0 0 18 0 1 0 36011930 1712128 124 1283457024 134512640 134593992 4293964224 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/22868/statm: 418 124 108 20 0 45 0
[pid=22869] ppid=22868 vsize=2568 CPUtime=0
/proc/22869/stat : 22869 (run_h) S 22868 22847 17551 34817 17551 4202496 367 613 0 0 0 0 0 0 20 0 1 0 36011930 2629632 273 1283457024 134512640 135304128 4292220976 18446744073709551615 4294960130 0 65536 18948 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/22869/statm: 642 273 232 194 0 29 0
[pid=22873] ppid=22869 vsize=2564 CPUtime=0
/proc/22873/stat : 22873 (run_scip) S 22869 22847 17551 34817 17551 4202496 390 756 0 0 0 0 0 0 22 0 1 0 36011931 2625536 268 1283457024 134512640 135304128 4289043744 18446744073709551615 4294960130 0 65536 18948 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/22873/statm: 641 268 228 194 0 28 0
[pid=22877] ppid=22873 vsize=73288 CPUtime=2.08
/proc/22877/stat : 22877 (scip-2.0.1.linu) R 22873 22847 17551 34817 17551 4202496 19464 0 0 0 186 22 0 0 25 0 1 0 36011931 75046912 16069 1283457024 134512640 143279753 4287927248 18446744073709551615 141858391 0 0 18944 2 0 0 0 17 0 0 0 0
/proc/22877/statm: 18322 16069 621 2141 0 16178 0
[pid=22878] ppid=22873 vsize=7196 CPUtime=0
/proc/22878/stat : 22878 (scip2v) S 22873 22847 17551 34817 17551 4202496 1008 0 0 0 0 0 0 0 18 0 1 0 36011944 7368704 847 1283457024 134512640 136477024 4290442880 18446744073709551615 4294960130 0 0 16800256 2 18446744071564457842 0 0 17 0 0 0 0
/proc/22878/statm: 1799 847 474 480 0 384 0
Current children cumulated CPU time (s) 8.13
Current children cumulated vsize (KiB) 125400

[startup+9.21023 s]
/proc/loadavg: 1.10 1.06 1.01 2/43 22878
/proc/meminfo: memFree=103388/1048576 swapFree=0/0
[pid=22847] ppid=22846 vsize=2572 CPUtime=0.01
/proc/22847/stat : 22847 (packup2hy4tr-0.) S 22846 22847 17551 34817 17551 4202496 378 0 0 0 0 1 0 0 25 0 1 0 36011260 2633728 274 1283457024 134512640 135304128 4288777232 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/22847/statm: 643 274 233 194 0 30 0
[pid=22849] ppid=22847 vsize=35540 CPUtime=6.04
/proc/22849/stat : 22849 (packup) S 22847 22847 17551 34817 17551 4202496 8605 43818 0 0 115 44 406 39 18 0 1 0 36011260 36392960 8241 1283457024 134512640 134752139 4287050304 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/22849/statm: 8885 8241 332 59 0 8049 0
[pid=22868] ppid=22849 vsize=1672 CPUtime=0
/proc/22868/stat : 22868 (sh) S 22849 22847 17551 34817 17551 4202496 147 0 0 0 0 0 0 0 18 0 1 0 36011930 1712128 124 1283457024 134512640 134593992 4293964224 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/22868/statm: 418 124 108 20 0 45 0
[pid=22869] ppid=22868 vsize=2568 CPUtime=0
/proc/22869/stat : 22869 (run_h) S 22868 22847 17551 34817 17551 4202496 367 613 0 0 0 0 0 0 20 0 1 0 36011930 2629632 273 1283457024 134512640 135304128 4292220976 18446744073709551615 4294960130 0 65536 18948 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/22869/statm: 642 273 232 194 0 29 0
[pid=22873] ppid=22869 vsize=2564 CPUtime=0
/proc/22873/stat : 22873 (run_scip) S 22869 22847 17551 34817 17551 4202496 390 756 0 0 0 0 0 0 22 0 1 0 36011931 2625536 268 1283457024 134512640 135304128 4289043744 18446744073709551615 4294960130 0 65536 18948 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/22873/statm: 641 268 228 194 0 28 0
[pid=22877] ppid=22873 vsize=73720 CPUtime=2.43
/proc/22877/stat : 22877 (scip-2.0.1.linu) R 22873 22847 17551 34817 17551 4202496 24628 0 0 0 214 29 0 0 25 0 1 0 36011931 75489280 16416 1283457024 134512640 143279753 4287927248 18446744073709551615 4294960130 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/22877/statm: 18430 16416 735 2141 0 16286 0
[pid=22878] ppid=22873 vsize=7196 CPUtime=0.05
/proc/22878/stat : 22878 (scip2v) S 22873 22847 17551 34817 17551 4202496 1028 0 0 0 0 5 0 0 18 0 1 0 36011944 7368704 867 1283457024 134512640 136477024 4290442880 18446744073709551615 4294960130 0 0 16800256 2 18446744071564457842 0 0 17 0 0 0 0
/proc/22878/statm: 1799 867 479 480 0 384 0
Current children cumulated CPU time (s) 8.53
Current children cumulated vsize (KiB) 125832

[startup+9.4103 s]
/proc/loadavg: 1.10 1.06 1.01 2/43 22878
/proc/meminfo: memFree=103388/1048576 swapFree=0/0
[pid=22847] ppid=22846 vsize=2572 CPUtime=0.01
/proc/22847/stat : 22847 (packup2hy4tr-0.) S 22846 22847 17551 34817 17551 4202496 378 0 0 0 0 1 0 0 25 0 1 0 36011260 2633728 274 1283457024 134512640 135304128 4288777232 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/22847/statm: 643 274 233 194 0 30 0
[pid=22849] ppid=22847 vsize=33808 CPUtime=8.75
/proc/22849/stat : 22849 (packup) R 22847 22847 17551 34817 17551 4202496 15902 71845 0 0 119 48 626 82 18 0 1 0 36011260 34619392 7928 1283457024 134512640 134752139 4287050304 18446744073709551615 4157548051 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/22849/statm: 8452 7928 345 59 0 7616 0
Current children cumulated CPU time (s) 8.76
Current children cumulated vsize (KiB) 36380

Child status: 0
Real time (s): 9.4466
CPU time (s): 8.80855
CPU user time (s): 7.49247
CPU system time (s): 1.31608
CPU usage (%): 93.2457
Max. virtual memory (cumulated for all children) (KiB): 126024

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 7.49247
system time used= 1.31608
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 88397
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= 13414
involuntary context switches= 13526

runsolver used 0 second user time and 0 second system time

The end