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/rand348.cudf.s-e-l-s.log.runsolver ./packup2mp4tr-0.6 /home/misc2010/data/2011/incremental/s-e-l-s/rand348.cudf /home/misc2010/tmp/201108241238/packup2mp4tr-0.6/rand348.cudf.s-e-l-s.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.03 1.04 1.00 4/36 9870
/proc/meminfo: memFree=513488/1048576 swapFree=0/0
[pid=9869] ppid=9868 vsize=2572 CPUtime=0
/proc/9869/stat : 9869 (packup2mp4tr-0.) S 9868 9869 1511 34817 1511 4202496 380 0 0 0 0 0 0 0 18 0 1 0 2337610 2633728 275 1283457024 134512640 135304128 4289316032 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/9869/statm: 643 275 233 194 0 30 0
[pid=9870] ppid=9869 vsize=3556 CPUtime=0
/proc/9870/stat : 9870 (packup) R 9869 9869 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 25 0 1 0 2337610 3641344 306 1283457024 134512640 134752139 4293976320 18446744073709551615 4157743843 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/9870/statm: 889 306 264 59 0 53 0

[startup+0.163334 s]
/proc/loadavg: 1.03 1.04 1.00 4/36 9870
/proc/meminfo: memFree=513488/1048576 swapFree=0/0
[pid=9869] ppid=9868 vsize=2572 CPUtime=0
/proc/9869/stat : 9869 (packup2mp4tr-0.) S 9868 9869 1511 34817 1511 4202496 380 0 0 0 0 0 0 0 18 0 1 0 2337610 2633728 275 1283457024 134512640 135304128 4289316032 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/9869/statm: 643 275 233 194 0 30 0
[pid=9870] ppid=9869 vsize=10000 CPUtime=0.16
/proc/9870/stat : 9870 (packup) R 9869 9869 1511 34817 1511 4202496 1991 0 0 0 16 0 0 0 25 0 1 0 2337610 10240000 1919 1283457024 134512640 134752139 4293976320 18446744073709551615 4157770539 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/9870/statm: 2500 1919 286 59 0 1664 0
Current children cumulated CPU time (s) 0.16
Current children cumulated vsize (KiB) 12572

[startup+0.213341 s]
/proc/loadavg: 1.03 1.04 1.00 4/36 9870
/proc/meminfo: memFree=513488/1048576 swapFree=0/0
[pid=9869] ppid=9868 vsize=2572 CPUtime=0
/proc/9869/stat : 9869 (packup2mp4tr-0.) S 9868 9869 1511 34817 1511 4202496 380 0 0 0 0 0 0 0 18 0 1 0 2337610 2633728 275 1283457024 134512640 135304128 4289316032 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/9869/statm: 643 275 233 194 0 30 0
[pid=9870] ppid=9869 vsize=11848 CPUtime=0.21
/proc/9870/stat : 9870 (packup) R 9869 9869 1511 34817 1511 4202496 2455 0 0 0 21 0 0 0 25 0 1 0 2337610 12132352 2383 1283457024 134512640 134752139 4293976320 18446744073709551615 4157721500 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/9870/statm: 2962 2383 286 59 0 2126 0
Current children cumulated CPU time (s) 0.21
Current children cumulated vsize (KiB) 14420

[startup+0.30336 s]
/proc/loadavg: 1.03 1.04 1.00 4/36 9870
/proc/meminfo: memFree=513488/1048576 swapFree=0/0
[pid=9869] ppid=9868 vsize=2572 CPUtime=0
/proc/9869/stat : 9869 (packup2mp4tr-0.) S 9868 9869 1511 34817 1511 4202496 380 0 0 0 0 0 0 0 18 0 1 0 2337610 2633728 275 1283457024 134512640 135304128 4289316032 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/9869/statm: 643 275 233 194 0 30 0
[pid=9870] ppid=9869 vsize=14684 CPUtime=0.3
/proc/9870/stat : 9870 (packup) R 9869 9869 1511 34817 1511 4202496 3170 0 0 0 29 1 0 0 25 0 1 0 2337610 15036416 3098 1283457024 134512640 134752139 4293976320 18446744073709551615 134681805 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/9870/statm: 3671 3098 286 59 0 2835 0
Current children cumulated CPU time (s) 0.3
Current children cumulated vsize (KiB) 17256

[startup+0.703431 s]
/proc/loadavg: 1.03 1.04 1.00 4/36 9870
/proc/meminfo: memFree=513488/1048576 swapFree=0/0
[pid=9869] ppid=9868 vsize=2572 CPUtime=0
/proc/9869/stat : 9869 (packup2mp4tr-0.) S 9868 9869 1511 34817 1511 4202496 380 0 0 0 0 0 0 0 18 0 1 0 2337610 2633728 275 1283457024 134512640 135304128 4289316032 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/9869/statm: 643 275 233 194 0 30 0
[pid=9870] ppid=9869 vsize=26116 CPUtime=0.7
/proc/9870/stat : 9870 (packup) R 9869 9869 1511 34817 1511 4202496 6010 0 0 0 66 4 0 0 25 0 1 0 2337610 26742784 5938 1283457024 134512640 134752139 4293976320 18446744073709551615 134623024 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/9870/statm: 6529 5938 286 59 0 5693 0
Current children cumulated CPU time (s) 0.7
Current children cumulated vsize (KiB) 28688

[startup+1.50361 s]
/proc/loadavg: 1.03 1.03 1.00 2/37 9871
/proc/meminfo: memFree=480864/1048576 swapFree=0/0
[pid=9869] ppid=9868 vsize=2572 CPUtime=0
/proc/9869/stat : 9869 (packup2mp4tr-0.) S 9868 9869 1511 34817 1511 4202496 380 0 0 0 0 0 0 0 18 0 1 0 2337610 2633728 275 1283457024 134512640 135304128 4289316032 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/9869/statm: 643 275 233 194 0 30 0
[pid=9870] ppid=9869 vsize=52840 CPUtime=1.5
/proc/9870/stat : 9870 (packup) R 9869 9869 1511 34817 1511 4202496 12977 0 0 0 144 6 0 0 25 0 1 0 2337610 54108160 12662 1283457024 134512640 134752139 4293976320 18446744073709551615 134668264 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/9870/statm: 13210 12662 306 59 0 12374 0
Current children cumulated CPU time (s) 1.5
Current children cumulated vsize (KiB) 55412

[startup+3.10393 s]
/proc/loadavg: 1.03 1.03 1.00 2/37 9871
/proc/meminfo: memFree=447012/1048576 swapFree=0/0
[pid=9869] ppid=9868 vsize=2572 CPUtime=0
/proc/9869/stat : 9869 (packup2mp4tr-0.) S 9868 9869 1511 34817 1511 4202496 380 0 0 0 0 0 0 0 18 0 1 0 2337610 2633728 275 1283457024 134512640 135304128 4289316032 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/9869/statm: 643 275 233 194 0 30 0
[pid=9870] ppid=9869 vsize=67792 CPUtime=2.24
/proc/9870/stat : 9870 (packup) S 9869 9869 1511 34817 1511 4202496 16814 0 0 0 184 40 0 0 25 0 1 0 2337610 69419008 16048 1283457024 134512640 134752139 4293976320 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/9870/statm: 16948 16048 325 59 0 16112 0
Current children cumulated CPU time (s) 2.24
Current children cumulated vsize (KiB) 70364
heavy processes:

[startup+6.30469 s]
/proc/loadavg: 1.18 1.07 1.01 2/39 9875
/proc/meminfo: memFree=440540/1048576 swapFree=0/0
[pid=9869] ppid=9868 vsize=2572 CPUtime=0
/proc/9869/stat : 9869 (packup2mp4tr-0.) S 9868 9869 1511 34817 1511 4202496 380 0 0 0 0 0 0 0 18 0 1 0 2337610 2633728 275 1283457024 134512640 135304128 4289316032 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/9869/statm: 643 275 233 194 0 30 0
[pid=9870] ppid=9869 vsize=67796 CPUtime=5.28
/proc/9870/stat : 9870 (packup) S 9869 9869 1511 34817 1511 4202496 16935 14883 0 0 202 72 226 28 19 0 1 0 2337610 69423104 16067 1283457024 134512640 134752139 4293976320 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/9870/statm: 16949 16067 333 59 0 16113 0
[pid=9874] ppid=9870 vsize=1672 CPUtime=0
/proc/9874/stat : 9874 (sh) S 9870 9869 1511 34817 1511 4202496 146 0 0 0 0 0 0 0 19 0 1 0 2338139 1712128 123 1283457024 134512640 134593992 4290420304 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/9874/statm: 418 123 108 20 0 45 0
[pid=9875] ppid=9874 vsize=27464 CPUtime=1
/proc/9875/stat : 9875 (minisatp_32) R 9874 9869 1511 34817 1511 4202496 6224 0 0 0 100 0 0 0 25 0 1 0 2338139 28123136 5521 1283457024 134512640 135413687 4292366400 18446744073709551615 134966924 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/9875/statm: 6866 5521 77 220 0 6644 0
Current children cumulated CPU time (s) 6.28
Current children cumulated vsize (KiB) 99504

[startup+12.7062 s]
/proc/loadavg: 1.17 1.06 1.01 2/39 9878
/proc/meminfo: memFree=420700/1048576 swapFree=0/0
[pid=9869] ppid=9868 vsize=2572 CPUtime=0
/proc/9869/stat : 9869 (packup2mp4tr-0.) S 9868 9869 1511 34817 1511 4202496 380 0 0 0 0 0 0 0 18 0 1 0 2337610 2633728 275 1283457024 134512640 135304128 4289316032 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/9869/statm: 643 275 233 194 0 30 0
[pid=9870] ppid=9869 vsize=67800 CPUtime=10.9
/proc/9870/stat : 9870 (packup) S 9869 9869 1511 34817 1511 4202496 17064 49497 0 0 230 97 710 53 19 0 1 0 2337610 69427200 16079 1283457024 134512640 134752139 4293976320 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/9870/statm: 16950 16079 333 59 0 16114 0
[pid=9877] ppid=9870 vsize=1668 CPUtime=0
/proc/9877/stat : 9877 (sh) S 9870 9869 1511 34817 1511 4202496 146 0 0 0 0 0 0 0 19 0 1 0 2338701 1708032 123 1283457024 134512640 134593992 4292374576 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/9877/statm: 417 123 108 20 0 44 0
[pid=9878] ppid=9877 vsize=42040 CPUtime=1.78
/proc/9878/stat : 9878 (minisatp_32) R 9877 9869 1511 34817 1511 4202496 10053 0 0 0 173 5 0 0 25 0 1 0 2338702 43048960 9049 1283457024 134512640 135413687 4289123632 18446744073709551615 134971268 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/9878/statm: 10510 9049 77 220 0 10288 0
Current children cumulated CPU time (s) 12.68
Current children cumulated vsize (KiB) 114080

[startup+25.5024 s]
/proc/loadavg: 1.14 1.06 1.01 2/39 9881
/proc/meminfo: memFree=292732/1048576 swapFree=0/0
[pid=9869] ppid=9868 vsize=2572 CPUtime=0
/proc/9869/stat : 9869 (packup2mp4tr-0.) S 9868 9869 1511 34817 1511 4202496 380 0 0 0 0 0 0 0 18 0 1 0 2337610 2633728 275 1283457024 134512640 135304128 4289316032 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/9869/statm: 643 275 233 194 0 30 0
[pid=9870] ppid=9869 vsize=67804 CPUtime=20.41
/proc/9870/stat : 9870 (packup) S 9869 9869 1511 34817 1511 4202496 17173 107284 0 0 258 120 1566 97 18 0 1 0 2337610 69431296 16080 1283457024 134512640 134752139 4293976320 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/9870/statm: 16951 16080 333 59 0 16115 0
[pid=9880] ppid=9870 vsize=1672 CPUtime=0.01
/proc/9880/stat : 9880 (sh) S 9870 9869 1511 34817 1511 4202496 148 0 0 0 0 1 0 0 18 0 1 0 2339654 1712128 124 1283457024 134512640 134593992 4288320592 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/9880/statm: 418 124 108 20 0 45 0
[pid=9881] ppid=9880 vsize=180544 CPUtime=5.04
/proc/9881/stat : 9881 (minisatp_32) R 9880 9869 1511 34817 1511 4202496 51060 0 0 0 468 36 0 0 25 0 1 0 2339655 184877056 38721 1283457024 134512640 135413687 4289471872 18446744073709551615 134696821 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/9881/statm: 45136 38721 94 220 0 44914 0
Current children cumulated CPU time (s) 25.46
Current children cumulated vsize (KiB) 252592

[startup+51.1106 s]
/proc/loadavg: 1.09 1.05 1.01 2/38 9883
/proc/meminfo: memFree=38508/1048576 swapFree=0/0
[pid=9869] ppid=9868 vsize=2572 CPUtime=0
/proc/9869/stat : 9869 (packup2mp4tr-0.) S 9868 9869 1511 34817 1511 4202496 380 0 0 0 0 0 0 0 18 0 1 0 2337610 2633728 275 1283457024 134512640 135304128 4289316032 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/9869/statm: 643 275 233 194 0 30 0
[pid=9870] ppid=9869 vsize=67804 CPUtime=20.41
/proc/9870/stat : 9870 (packup) S 9869 9869 1511 34817 1511 4202496 17173 107284 0 0 258 120 1566 97 18 0 1 0 2337610 69431296 16080 1283457024 134512640 134752139 4293976320 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/9870/statm: 16951 16080 333 59 0 16115 0
[pid=9880] ppid=9870 vsize=1672 CPUtime=0.01
/proc/9880/stat : 9880 (sh) S 9870 9869 1511 34817 1511 4202496 148 0 0 0 0 1 0 0 18 0 1 0 2339654 1712128 124 1283457024 134512640 134593992 4288320592 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/9880/statm: 418 124 108 20 0 45 0
[pid=9881] ppid=9880 vsize=456880 CPUtime=30.63
/proc/9881/stat : 9881 (minisatp_32) R 9880 9869 1511 34817 1511 4202496 166628 0 0 0 2975 88 0 0 25 0 1 0 2339655 467845120 105923 1283457024 134512640 135413687 4289471872 18446744073709551615 134649574 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/9881/statm: 114220 105923 110 220 0 113998 0
Current children cumulated CPU time (s) 51.05
Current children cumulated vsize (KiB) 528928

[startup+102.306 s]
/proc/loadavg: 1.04 1.04 1.00 2/38 9883
/proc/meminfo: memFree=7364/1048576 swapFree=0/0
[pid=9869] ppid=9868 vsize=2572 CPUtime=0
/proc/9869/stat : 9869 (packup2mp4tr-0.) S 9868 9869 1511 34817 1511 4202496 380 0 0 0 0 0 0 0 18 0 1 0 2337610 2633728 275 1283457024 134512640 135304128 4289316032 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/9869/statm: 643 275 233 194 0 30 0
[pid=9870] ppid=9869 vsize=67804 CPUtime=20.41
/proc/9870/stat : 9870 (packup) S 9869 9869 1511 34817 1511 4202496 17173 107284 0 0 258 120 1566 97 18 0 1 0 2337610 69431296 16080 1283457024 134512640 134752139 4293976320 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/9870/statm: 16951 16080 333 59 0 16115 0
[pid=9880] ppid=9870 vsize=1672 CPUtime=0.01
/proc/9880/stat : 9880 (sh) S 9870 9869 1511 34817 1511 4202496 148 0 0 0 0 1 0 0 18 0 1 0 2339654 1712128 124 1283457024 134512640 134593992 4288320592 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/9880/statm: 418 124 108 20 0 45 0
[pid=9881] ppid=9880 vsize=656108 CPUtime=81.78
/proc/9881/stat : 9881 (minisatp_32) R 9880 9869 1511 34817 1511 4202496 225002 0 0 0 8058 120 0 0 25 0 1 0 2339655 671854592 142228 1283457024 134512640 135413687 4289471872 18446744073709551615 134649574 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/9881/statm: 164027 142228 110 220 0 163805 0
Current children cumulated CPU time (s) 102.2
Current children cumulated vsize (KiB) 728156

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

[startup+102.406 s]
/proc/loadavg: 1.04 1.04 1.00 2/38 9883
/proc/meminfo: memFree=7364/1048576 swapFree=0/0
[pid=9869] ppid=9868 vsize=2572 CPUtime=0
/proc/9869/stat : 9869 (packup2mp4tr-0.) S 9868 9869 1511 34817 1511 4202496 380 0 0 0 0 0 0 0 18 0 1 0 2337610 2633728 275 1283457024 134512640 135304128 4289316032 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/9869/statm: 643 275 233 194 0 30 0
[pid=9870] ppid=9869 vsize=67804 CPUtime=20.41
/proc/9870/stat : 9870 (packup) S 9869 9869 1511 34817 1511 4202496 17173 107284 0 0 258 120 1566 97 18 0 1 0 2337610 69431296 16080 1283457024 134512640 134752139 4293976320 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/9870/statm: 16951 16080 333 59 0 16115 0
[pid=9880] ppid=9870 vsize=1672 CPUtime=0.01
/proc/9880/stat : 9880 (sh) S 9870 9869 1511 34817 1511 4202496 148 0 0 0 0 1 0 0 18 0 1 0 2339654 1712128 124 1283457024 134512640 134593992 4288320592 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/9880/statm: 418 124 108 20 0 45 0
[pid=9881] ppid=9880 vsize=656108 CPUtime=81.88
/proc/9881/stat : 9881 (minisatp_32) R 9880 9869 1511 34817 1511 4202496 225002 0 0 0 8068 120 0 0 25 0 1 0 2339655 671854592 142228 1283457024 134512640 135413687 4289471872 18446744073709551615 134649451 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/9881/statm: 164027 142228 110 220 0 163805 0
Current children cumulated CPU time (s) 102.3
Current children cumulated vsize (KiB) 728156

[startup+128.004 s]
/proc/loadavg: 1.02 1.04 1.00 2/37 9883
/proc/meminfo: memFree=7392/1048576 swapFree=0/0
[pid=9869] ppid=9868 vsize=2572 CPUtime=0
/proc/9869/stat : 9869 (packup2mp4tr-0.) S 9868 9869 1511 34817 1511 4202496 380 0 0 0 0 0 0 0 18 0 1 0 2337610 2633728 275 1283457024 134512640 135304128 4289316032 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/9869/statm: 643 275 233 194 0 30 0
[pid=9870] ppid=9869 vsize=67804 CPUtime=20.41
/proc/9870/stat : 9870 (packup) S 9869 9869 1511 34817 1511 4202496 17173 107284 0 0 258 120 1566 97 18 0 1 0 2337610 69431296 16080 1283457024 134512640 134752139 4293976320 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/9870/statm: 16951 16080 333 59 0 16115 0
[pid=9880] ppid=9870 vsize=1672 CPUtime=0.01
/proc/9880/stat : 9880 (sh) S 9870 9869 1511 34817 1511 4202496 148 0 0 0 0 1 0 0 18 0 1 0 2339654 1712128 124 1283457024 134512640 134593992 4288320592 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/9880/statm: 418 124 108 20 0 45 0
[pid=9881] ppid=9880 vsize=656108 CPUtime=107.45
/proc/9881/stat : 9881 (minisatp_32) R 9880 9869 1511 34817 1511 4202496 226847 0 0 0 10623 122 0 0 25 0 1 0 2339655 671854592 142562 1283457024 134512640 135413687 4289471872 18446744073709551615 134649574 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/9881/statm: 164027 142562 110 220 0 163805 0
Current children cumulated CPU time (s) 127.87
Current children cumulated vsize (KiB) 728156

[startup+140.807 s]
/proc/loadavg: 1.02 1.04 1.00 2/37 9883
/proc/meminfo: memFree=7908/1048576 swapFree=0/0
[pid=9869] ppid=9868 vsize=2572 CPUtime=0
/proc/9869/stat : 9869 (packup2mp4tr-0.) S 9868 9869 1511 34817 1511 4202496 380 0 0 0 0 0 0 0 18 0 1 0 2337610 2633728 275 1283457024 134512640 135304128 4289316032 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/9869/statm: 643 275 233 194 0 30 0
[pid=9870] ppid=9869 vsize=67804 CPUtime=20.41
/proc/9870/stat : 9870 (packup) S 9869 9869 1511 34817 1511 4202496 17173 107284 0 0 258 120 1566 97 18 0 1 0 2337610 69431296 16080 1283457024 134512640 134752139 4293976320 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/9870/statm: 16951 16080 333 59 0 16115 0
[pid=9880] ppid=9870 vsize=1672 CPUtime=0.01
/proc/9880/stat : 9880 (sh) S 9870 9869 1511 34817 1511 4202496 148 0 0 0 0 1 0 0 18 0 1 0 2339654 1712128 124 1283457024 134512640 134593992 4288320592 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/9880/statm: 418 124 108 20 0 45 0
[pid=9881] ppid=9880 vsize=656444 CPUtime=120.24
/proc/9881/stat : 9881 (minisatp_32) R 9880 9869 1511 34817 1511 4202496 227856 0 0 0 11902 122 0 0 25 0 1 0 2339655 672198656 142772 1283457024 134512640 135413687 4289471872 18446744073709551615 134649456 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/9881/statm: 164111 142772 110 220 0 163889 0
Current children cumulated CPU time (s) 140.66
Current children cumulated vsize (KiB) 728492

[startup+147.209 s]
/proc/loadavg: 1.02 1.04 1.00 2/37 9883
/proc/meminfo: memFree=7908/1048576 swapFree=0/0
[pid=9869] ppid=9868 vsize=2572 CPUtime=0
/proc/9869/stat : 9869 (packup2mp4tr-0.) S 9868 9869 1511 34817 1511 4202496 380 0 0 0 0 0 0 0 18 0 1 0 2337610 2633728 275 1283457024 134512640 135304128 4289316032 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/9869/statm: 643 275 233 194 0 30 0
[pid=9870] ppid=9869 vsize=67804 CPUtime=20.41
/proc/9870/stat : 9870 (packup) S 9869 9869 1511 34817 1511 4202496 17173 107284 0 0 258 120 1566 97 18 0 1 0 2337610 69431296 16080 1283457024 134512640 134752139 4293976320 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/9870/statm: 16951 16080 333 59 0 16115 0
[pid=9880] ppid=9870 vsize=1672 CPUtime=0.01
/proc/9880/stat : 9880 (sh) S 9870 9869 1511 34817 1511 4202496 148 0 0 0 0 1 0 0 18 0 1 0 2339654 1712128 124 1283457024 134512640 134593992 4288320592 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/9880/statm: 418 124 108 20 0 45 0
[pid=9881] ppid=9880 vsize=656444 CPUtime=126.64
/proc/9881/stat : 9881 (minisatp_32) R 9880 9869 1511 34817 1511 4202496 227916 0 0 0 12542 122 0 0 25 0 1 0 2339655 672198656 142829 1283457024 134512640 135413687 4289471872 18446744073709551615 134649535 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/9881/statm: 164111 142829 110 220 0 163889 0
Current children cumulated CPU time (s) 147.06
Current children cumulated vsize (KiB) 728492

[startup+150.41 s]
/proc/loadavg: 1.02 1.04 1.00 2/37 9883
/proc/meminfo: memFree=7784/1048576 swapFree=0/0
[pid=9869] ppid=9868 vsize=2572 CPUtime=0
/proc/9869/stat : 9869 (packup2mp4tr-0.) S 9868 9869 1511 34817 1511 4202496 380 0 0 0 0 0 0 0 18 0 1 0 2337610 2633728 275 1283457024 134512640 135304128 4289316032 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/9869/statm: 643 275 233 194 0 30 0
[pid=9870] ppid=9869 vsize=67804 CPUtime=20.41
/proc/9870/stat : 9870 (packup) S 9869 9869 1511 34817 1511 4202496 17173 107284 0 0 258 120 1566 97 18 0 1 0 2337610 69431296 16080 1283457024 134512640 134752139 4293976320 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/9870/statm: 16951 16080 333 59 0 16115 0
[pid=9880] ppid=9870 vsize=1672 CPUtime=0.01
/proc/9880/stat : 9880 (sh) S 9870 9869 1511 34817 1511 4202496 148 0 0 0 0 1 0 0 18 0 1 0 2339654 1712128 124 1283457024 134512640 134593992 4288320592 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/9880/statm: 418 124 108 20 0 45 0
[pid=9881] ppid=9880 vsize=656444 CPUtime=129.84
/proc/9881/stat : 9881 (minisatp_32) R 9880 9869 1511 34817 1511 4202496 227937 0 0 0 12862 122 0 0 25 0 1 0 2339655 672198656 142850 1283457024 134512640 135413687 4289471872 18446744073709551615 134649574 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/9881/statm: 164111 142850 110 220 0 163889 0
Current children cumulated CPU time (s) 150.26
Current children cumulated vsize (KiB) 728492

[startup+152.011 s]
/proc/loadavg: 1.01 1.04 1.00 2/37 9883
/proc/meminfo: memFree=57468/1048576 swapFree=0/0
[pid=9869] ppid=9868 vsize=2572 CPUtime=0
/proc/9869/stat : 9869 (packup2mp4tr-0.) S 9868 9869 1511 34817 1511 4202496 380 0 0 0 0 0 0 0 18 0 1 0 2337610 2633728 275 1283457024 134512640 135304128 4289316032 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/9869/statm: 643 275 233 194 0 30 0
[pid=9870] ppid=9869 vsize=67804 CPUtime=20.41
/proc/9870/stat : 9870 (packup) S 9869 9869 1511 34817 1511 4202496 17173 107284 0 0 258 120 1566 97 18 0 1 0 2337610 69431296 16080 1283457024 134512640 134752139 4293976320 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/9870/statm: 16951 16080 333 59 0 16115 0
[pid=9880] ppid=9870 vsize=1672 CPUtime=0.01
/proc/9880/stat : 9880 (sh) S 9870 9869 1511 34817 1511 4202496 148 0 0 0 0 1 0 0 18 0 1 0 2339654 1712128 124 1283457024 134512640 134593992 4288320592 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/9880/statm: 418 124 108 20 0 45 0
[pid=9881] ppid=9880 vsize=626024 CPUtime=131.42
/proc/9881/stat : 9881 (minisatp_32) R 9880 9869 1511 34817 1511 4202496 238888 0 0 0 13018 124 0 0 25 0 1 0 2339655 641048576 139879 1283457024 134512640 135413687 4289471872 18446744073709551615 134649535 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/9881/statm: 156506 139879 110 220 0 156284 0
Current children cumulated CPU time (s) 151.84
Current children cumulated vsize (KiB) 698072

[startup+152.411 s]
/proc/loadavg: 1.01 1.04 1.00 2/37 9883
/proc/meminfo: memFree=57468/1048576 swapFree=0/0
[pid=9869] ppid=9868 vsize=2572 CPUtime=0
/proc/9869/stat : 9869 (packup2mp4tr-0.) S 9868 9869 1511 34817 1511 4202496 380 0 0 0 0 0 0 0 18 0 1 0 2337610 2633728 275 1283457024 134512640 135304128 4289316032 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/9869/statm: 643 275 233 194 0 30 0
[pid=9870] ppid=9869 vsize=67804 CPUtime=20.41
/proc/9870/stat : 9870 (packup) S 9869 9869 1511 34817 1511 4202496 17173 107284 0 0 258 120 1566 97 18 0 1 0 2337610 69431296 16080 1283457024 134512640 134752139 4293976320 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/9870/statm: 16951 16080 333 59 0 16115 0
[pid=9880] ppid=9870 vsize=1672 CPUtime=0.01
/proc/9880/stat : 9880 (sh) S 9870 9869 1511 34817 1511 4202496 148 0 0 0 0 1 0 0 18 0 1 0 2339654 1712128 124 1283457024 134512640 134593992 4288320592 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/9880/statm: 418 124 108 20 0 45 0
[pid=9881] ppid=9880 vsize=591752 CPUtime=131.82
/proc/9881/stat : 9881 (minisatp_32) R 9880 9869 1511 34817 1511 4202496 238897 0 0 0 13058 124 0 0 25 0 1 0 2339655 605954048 132988 1283457024 134512640 135413687 4289471872 18446744073709551615 134597339 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/9881/statm: 147938 132988 118 220 0 147716 0
Current children cumulated CPU time (s) 152.24
Current children cumulated vsize (KiB) 663800

[startup+152.61 s]
/proc/loadavg: 1.01 1.04 1.00 2/37 9883
/proc/meminfo: memFree=57468/1048576 swapFree=0/0
[pid=9869] ppid=9868 vsize=2572 CPUtime=0
/proc/9869/stat : 9869 (packup2mp4tr-0.) S 9868 9869 1511 34817 1511 4202496 380 0 0 0 0 0 0 0 18 0 1 0 2337610 2633728 275 1283457024 134512640 135304128 4289316032 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/9869/statm: 643 275 233 194 0 30 0
[pid=9870] ppid=9869 vsize=66068 CPUtime=152.45
/proc/9870/stat : 9870 (packup) R 9869 9869 1511 34817 1511 4202496 30252 346332 0 0 266 123 14628 228 18 0 1 0 2337610 67653632 15658 1283457024 134512640 134752139 4293976320 18446744073709551615 4157732253 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/9870/statm: 16517 15658 345 59 0 15681 0
Current children cumulated CPU time (s) 152.45
Current children cumulated vsize (KiB) 68640

Child status: 0
Real time (s): 152.689
CPU time (s): 152.53
CPU user time (s): 149.005
CPU system time (s): 3.52422
CPU usage (%): 99.8954
Max. virtual memory (cumulated for all children) (KiB): 777812

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

runsolver used 0 second user time and 0 second system time

The end