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/rand946.cudf.s-e-l-s-s.log.runsolver ./packup2mp4pa-0.6 /home/misc2010/data/2011/incremental/s-e-l-s-s//rand946.cudf /home/misc2010/tmp/201108251442/packup2mp4pa-0.6/rand946.cudf.s-e-l-s-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.12 1.05 1.01 3/34 16870
/proc/meminfo: memFree=391040/1048576 swapFree=0/0
[pid=16869] ppid=16868 vsize=2568 CPUtime=0
/proc/16869/stat : 16869 (packup2mp4pa-0.) S 16868 16869 4778 34817 4778 4202496 378 0 0 0 0 0 0 0 25 0 1 0 11034123 2629632 274 1283457024 134512640 135304128 4293843216 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/16869/statm: 642 274 233 194 0 29 0
[pid=16870] ppid=16869 vsize=3716 CPUtime=0
/proc/16870/stat : 16870 (packup) R 16869 16869 4778 34817 4778 4202496 421 0 0 0 0 0 0 0 25 0 1 0 11034123 3805184 350 1283457024 134512640 134752139 4288592864 18446744073709551615 134694892 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/16870/statm: 929 350 286 59 0 93 0

[startup+0.134775 s]
/proc/loadavg: 1.12 1.05 1.01 3/34 16870
/proc/meminfo: memFree=391040/1048576 swapFree=0/0
[pid=16869] ppid=16868 vsize=2568 CPUtime=0
/proc/16869/stat : 16869 (packup2mp4pa-0.) S 16868 16869 4778 34817 4778 4202496 378 0 0 0 0 0 0 0 25 0 1 0 11034123 2629632 274 1283457024 134512640 135304128 4293843216 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/16869/statm: 642 274 233 194 0 29 0
[pid=16870] ppid=16869 vsize=9072 CPUtime=0.13
/proc/16870/stat : 16870 (packup) R 16869 16869 4778 34817 4778 4202496 1747 0 0 0 11 2 0 0 25 0 1 0 11034123 9289728 1676 1283457024 134512640 134752139 4288592864 18446744073709551615 4157145827 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/16870/statm: 2268 1676 286 59 0 1432 0
Current children cumulated CPU time (s) 0.13
Current children cumulated vsize (KiB) 11640

[startup+0.214795 s]
/proc/loadavg: 1.12 1.05 1.01 3/34 16870
/proc/meminfo: memFree=391040/1048576 swapFree=0/0
[pid=16869] ppid=16868 vsize=2568 CPUtime=0
/proc/16869/stat : 16869 (packup2mp4pa-0.) S 16868 16869 4778 34817 4778 4202496 378 0 0 0 0 0 0 0 25 0 1 0 11034123 2629632 274 1283457024 134512640 135304128 4293843216 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/16869/statm: 642 274 233 194 0 29 0
[pid=16870] ppid=16869 vsize=12132 CPUtime=0.21
/proc/16870/stat : 16870 (packup) R 16869 16869 4778 34817 4778 4202496 2506 0 0 0 17 4 0 0 25 0 1 0 11034123 12423168 2435 1283457024 134512640 134752139 4288592864 18446744073709551615 134643339 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/16870/statm: 3033 2435 286 59 0 2197 0
Current children cumulated CPU time (s) 0.21
Current children cumulated vsize (KiB) 14700

[startup+0.314818 s]
/proc/loadavg: 1.12 1.05 1.01 3/34 16870
/proc/meminfo: memFree=391040/1048576 swapFree=0/0
[pid=16869] ppid=16868 vsize=2568 CPUtime=0
/proc/16869/stat : 16869 (packup2mp4pa-0.) S 16868 16869 4778 34817 4778 4202496 378 0 0 0 0 0 0 0 25 0 1 0 11034123 2629632 274 1283457024 134512640 135304128 4293843216 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/16869/statm: 642 274 233 194 0 29 0
[pid=16870] ppid=16869 vsize=15232 CPUtime=0.31
/proc/16870/stat : 16870 (packup) R 16869 16869 4778 34817 4778 4202496 3292 0 0 0 26 5 0 0 25 0 1 0 11034123 15597568 3221 1283457024 134512640 134752139 4288592864 18446744073709551615 134694895 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/16870/statm: 3808 3221 286 59 0 2972 0
Current children cumulated CPU time (s) 0.31
Current children cumulated vsize (KiB) 17800

[startup+0.714928 s]
/proc/loadavg: 1.12 1.05 1.01 3/34 16870
/proc/meminfo: memFree=391040/1048576 swapFree=0/0
[pid=16869] ppid=16868 vsize=2568 CPUtime=0
/proc/16869/stat : 16869 (packup2mp4pa-0.) S 16868 16869 4778 34817 4778 4202496 378 0 0 0 0 0 0 0 25 0 1 0 11034123 2629632 274 1283457024 134512640 135304128 4293843216 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/16869/statm: 642 274 233 194 0 29 0
[pid=16870] ppid=16869 vsize=26528 CPUtime=0.71
/proc/16870/stat : 16870 (packup) R 16869 16869 4778 34817 4778 4202496 6119 0 0 0 66 5 0 0 25 0 1 0 11034123 27164672 6048 1283457024 134512640 134752139 4288592864 18446744073709551615 134683113 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/16870/statm: 6632 6048 286 59 0 5796 0
Current children cumulated CPU time (s) 0.71
Current children cumulated vsize (KiB) 29096

[startup+1.51505 s]
/proc/loadavg: 1.11 1.05 1.01 2/35 16871
/proc/meminfo: memFree=357948/1048576 swapFree=0/0
[pid=16869] ppid=16868 vsize=2568 CPUtime=0
/proc/16869/stat : 16869 (packup2mp4pa-0.) S 16868 16869 4778 34817 4778 4202496 378 0 0 0 0 0 0 0 25 0 1 0 11034123 2629632 274 1283457024 134512640 135304128 4293843216 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/16869/statm: 642 274 233 194 0 29 0
[pid=16870] ppid=16869 vsize=53848 CPUtime=1.51
/proc/16870/stat : 16870 (packup) R 16869 16869 4778 34817 4778 4202496 13022 0 0 0 144 7 0 0 25 0 1 0 11034123 55140352 12902 1283457024 134512640 134752139 4288592864 18446744073709551615 134657938 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/16870/statm: 13462 12902 316 59 0 12626 0
Current children cumulated CPU time (s) 1.51
Current children cumulated vsize (KiB) 56416

[startup+3.11561 s]
/proc/loadavg: 1.11 1.05 1.01 2/37 16873
/proc/meminfo: memFree=327660/1048576 swapFree=0/0
[pid=16869] ppid=16868 vsize=2568 CPUtime=0
/proc/16869/stat : 16869 (packup2mp4pa-0.) S 16868 16869 4778 34817 4778 4202496 378 0 0 0 0 0 0 0 25 0 1 0 11034123 2629632 274 1283457024 134512640 135304128 4293843216 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/16869/statm: 642 274 233 194 0 29 0
[pid=16870] ppid=16869 vsize=57552 CPUtime=1.87
/proc/16870/stat : 16870 (packup) S 16869 16869 4778 34817 4778 4202496 13959 0 0 0 163 24 0 0 25 0 1 0 11034123 58933248 13604 1283457024 134512640 134752139 4288592864 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/16870/statm: 14388 13604 324 59 0 13552 0
[pid=16872] ppid=16870 vsize=1668 CPUtime=0
/proc/16872/stat : 16872 (sh) S 16870 16869 4778 34817 4778 4202496 145 0 0 0 0 0 0 0 25 0 1 0 11034310 1708032 123 1283457024 134512640 134593992 4293974448 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/16872/statm: 417 123 108 20 0 44 0
[pid=16873] ppid=16872 vsize=29852 CPUtime=1.22
/proc/16873/stat : 16873 (minisatp_32) R 16872 16869 4778 34817 4778 4202496 7011 0 0 0 108 14 0 0 25 0 1 0 11034312 30568448 6291 1283457024 134512640 135413687 4286939936 18446744073709551615 134568315 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/16873/statm: 7463 6291 85 220 0 7241 0
Current children cumulated CPU time (s) 3.09
Current children cumulated vsize (KiB) 91640

[startup+6.30633 s]
/proc/loadavg: 1.11 1.05 1.01 2/37 16875
/proc/meminfo: memFree=322824/1048576 swapFree=0/0
[pid=16869] ppid=16868 vsize=2568 CPUtime=0
/proc/16869/stat : 16869 (packup2mp4pa-0.) S 16868 16869 4778 34817 4778 4202496 378 0 0 0 0 0 0 0 25 0 1 0 11034123 2629632 274 1283457024 134512640 135304128 4293843216 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/16869/statm: 642 274 233 194 0 29 0
[pid=16870] ppid=16869 vsize=57556 CPUtime=4.93
/proc/16870/stat : 16870 (packup) S 16869 16869 4778 34817 4778 4202496 14027 19907 0 0 175 44 244 30 18 0 1 0 11034123 58937344 13613 1283457024 134512640 134752139 4288592864 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/16870/statm: 14389 13613 332 59 0 13553 0
[pid=16874] ppid=16870 vsize=1676 CPUtime=0
/proc/16874/stat : 16874 (sh) S 16870 16869 4778 34817 4778 4202496 146 0 0 0 0 0 0 0 19 0 1 0 11034619 1716224 124 1283457024 134512640 134593992 4289910224 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/16874/statm: 419 124 108 20 0 46 0
[pid=16875] ppid=16874 vsize=31712 CPUtime=1.34
/proc/16875/stat : 16875 (minisatp_32) R 16874 16869 4778 34817 4778 4202496 7757 0 0 0 118 16 0 0 25 0 1 0 11034620 32473088 6916 1283457024 134512640 135413687 4288662720 18446744073709551615 134965174 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/16875/statm: 7928 6916 85 220 0 7706 0
Current children cumulated CPU time (s) 6.27
Current children cumulated vsize (KiB) 93512

[startup+12.7084 s]
/proc/loadavg: 1.10 1.05 1.01 2/37 16875
/proc/meminfo: memFree=187796/1048576 swapFree=0/0
[pid=16869] ppid=16868 vsize=2568 CPUtime=0
/proc/16869/stat : 16869 (packup2mp4pa-0.) S 16868 16869 4778 34817 4778 4202496 378 0 0 0 0 0 0 0 25 0 1 0 11034123 2629632 274 1283457024 134512640 135304128 4293843216 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/16869/statm: 642 274 233 194 0 29 0
[pid=16870] ppid=16869 vsize=57556 CPUtime=4.93
/proc/16870/stat : 16870 (packup) S 16869 16869 4778 34817 4778 4202496 14027 19907 0 0 175 44 244 30 18 0 1 0 11034123 58937344 13613 1283457024 134512640 134752139 4288592864 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/16870/statm: 14389 13613 332 59 0 13553 0
[pid=16874] ppid=16870 vsize=1676 CPUtime=0
/proc/16874/stat : 16874 (sh) S 16870 16869 4778 34817 4778 4202496 146 0 0 0 0 0 0 0 19 0 1 0 11034619 1716224 124 1283457024 134512640 134593992 4289910224 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/16874/statm: 419 124 108 20 0 46 0
[pid=16875] ppid=16874 vsize=193544 CPUtime=7.73
/proc/16875/stat : 16875 (minisatp_32) R 16874 16869 4778 34817 4778 4202496 58477 0 0 0 738 35 0 0 25 0 1 0 11034620 198189056 42879 1283457024 134512640 135413687 4288662720 18446744073709551615 134686212 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/16875/statm: 48386 42879 110 220 0 48164 0
Current children cumulated CPU time (s) 12.66
Current children cumulated vsize (KiB) 255344

[startup+25.5048 s]
/proc/loadavg: 1.08 1.05 1.01 2/37 16875
/proc/meminfo: memFree=36776/1048576 swapFree=0/0
[pid=16869] ppid=16868 vsize=2568 CPUtime=0
/proc/16869/stat : 16869 (packup2mp4pa-0.) S 16868 16869 4778 34817 4778 4202496 378 0 0 0 0 0 0 0 25 0 1 0 11034123 2629632 274 1283457024 134512640 135304128 4293843216 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/16869/statm: 642 274 233 194 0 29 0
[pid=16870] ppid=16869 vsize=57556 CPUtime=4.93
/proc/16870/stat : 16870 (packup) S 16869 16869 4778 34817 4778 4202496 14027 19907 0 0 175 44 244 30 18 0 1 0 11034123 58937344 13613 1283457024 134512640 134752139 4288592864 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/16870/statm: 14389 13613 332 59 0 13553 0
[pid=16874] ppid=16870 vsize=1676 CPUtime=0
/proc/16874/stat : 16874 (sh) S 16870 16869 4778 34817 4778 4202496 146 0 0 0 0 0 0 0 19 0 1 0 11034619 1716224 124 1283457024 134512640 134593992 4289910224 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/16874/statm: 419 124 108 20 0 46 0
[pid=16875] ppid=16874 vsize=325128 CPUtime=20.49
/proc/16875/stat : 16875 (minisatp_32) R 16874 16869 4778 34817 4778 4202496 119742 0 0 0 1994 55 0 0 25 0 1 0 11034620 332931072 74718 1283457024 134512640 135413687 4288662720 18446744073709551615 134649535 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/16875/statm: 81282 74718 110 220 0 81060 0
Current children cumulated CPU time (s) 25.42
Current children cumulated vsize (KiB) 386928

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

[startup+25.6048 s]
/proc/loadavg: 1.08 1.05 1.01 2/37 16875
/proc/meminfo: memFree=36776/1048576 swapFree=0/0
[pid=16869] ppid=16868 vsize=2568 CPUtime=0
/proc/16869/stat : 16869 (packup2mp4pa-0.) S 16868 16869 4778 34817 4778 4202496 378 0 0 0 0 0 0 0 25 0 1 0 11034123 2629632 274 1283457024 134512640 135304128 4293843216 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/16869/statm: 642 274 233 194 0 29 0
[pid=16870] ppid=16869 vsize=57556 CPUtime=4.93
/proc/16870/stat : 16870 (packup) S 16869 16869 4778 34817 4778 4202496 14027 19907 0 0 175 44 244 30 18 0 1 0 11034123 58937344 13613 1283457024 134512640 134752139 4288592864 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/16870/statm: 14389 13613 332 59 0 13553 0
[pid=16874] ppid=16870 vsize=1676 CPUtime=0
/proc/16874/stat : 16874 (sh) S 16870 16869 4778 34817 4778 4202496 146 0 0 0 0 0 0 0 19 0 1 0 11034619 1716224 124 1283457024 134512640 134593992 4289910224 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/16874/statm: 419 124 108 20 0 46 0
[pid=16875] ppid=16874 vsize=325128 CPUtime=20.59
/proc/16875/stat : 16875 (minisatp_32) R 16874 16869 4778 34817 4778 4202496 119743 0 0 0 2004 55 0 0 25 0 1 0 11034620 332931072 74719 1283457024 134512640 135413687 4288662720 18446744073709551615 134649574 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/16875/statm: 81282 74719 110 220 0 81060 0
Current children cumulated CPU time (s) 25.52
Current children cumulated vsize (KiB) 386928

[startup+32.0067 s]
/proc/loadavg: 1.07 1.05 1.01 2/37 16875
/proc/meminfo: memFree=37500/1048576 swapFree=0/0
[pid=16869] ppid=16868 vsize=2568 CPUtime=0
/proc/16869/stat : 16869 (packup2mp4pa-0.) S 16868 16869 4778 34817 4778 4202496 378 0 0 0 0 0 0 0 25 0 1 0 11034123 2629632 274 1283457024 134512640 135304128 4293843216 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/16869/statm: 642 274 233 194 0 29 0
[pid=16870] ppid=16869 vsize=57556 CPUtime=4.93
/proc/16870/stat : 16870 (packup) S 16869 16869 4778 34817 4778 4202496 14027 19907 0 0 175 44 244 30 18 0 1 0 11034123 58937344 13613 1283457024 134512640 134752139 4288592864 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/16870/statm: 14389 13613 332 59 0 13553 0
[pid=16874] ppid=16870 vsize=1676 CPUtime=0
/proc/16874/stat : 16874 (sh) S 16870 16869 4778 34817 4778 4202496 146 0 0 0 0 0 0 0 19 0 1 0 11034619 1716224 124 1283457024 134512640 134593992 4289910224 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/16874/statm: 419 124 108 20 0 46 0
[pid=16875] ppid=16874 vsize=367828 CPUtime=26.98
/proc/16875/stat : 16875 (minisatp_32) R 16874 16869 4778 34817 4778 4202496 137415 0 0 0 2634 64 0 0 25 0 1 0 11034620 376655872 82104 1283457024 134512640 135413687 4288662720 18446744073709551615 134649535 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/16875/statm: 91957 82104 110 220 0 91735 0
Current children cumulated CPU time (s) 31.91
Current children cumulated vsize (KiB) 429628

[startup+38.4088 s]
/proc/loadavg: 1.06 1.05 1.01 2/37 16875
/proc/meminfo: memFree=36880/1048576 swapFree=0/0
[pid=16869] ppid=16868 vsize=2568 CPUtime=0
/proc/16869/stat : 16869 (packup2mp4pa-0.) S 16868 16869 4778 34817 4778 4202496 378 0 0 0 0 0 0 0 25 0 1 0 11034123 2629632 274 1283457024 134512640 135304128 4293843216 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/16869/statm: 642 274 233 194 0 29 0
[pid=16870] ppid=16869 vsize=57556 CPUtime=4.93
/proc/16870/stat : 16870 (packup) S 16869 16869 4778 34817 4778 4202496 14027 19907 0 0 175 44 244 30 18 0 1 0 11034123 58937344 13613 1283457024 134512640 134752139 4288592864 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/16870/statm: 14389 13613 332 59 0 13553 0
[pid=16874] ppid=16870 vsize=1676 CPUtime=0
/proc/16874/stat : 16874 (sh) S 16870 16869 4778 34817 4778 4202496 146 0 0 0 0 0 0 0 19 0 1 0 11034619 1716224 124 1283457024 134512640 134593992 4289910224 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/16874/statm: 419 124 108 20 0 46 0
[pid=16875] ppid=16874 vsize=368180 CPUtime=33.37
/proc/16875/stat : 16875 (minisatp_32) R 16874 16869 4778 34817 4778 4202496 140094 0 0 0 3271 66 0 0 25 0 1 0 11034620 377016320 82271 1283457024 134512640 135413687 4288662720 18446744073709551615 134653643 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/16875/statm: 92045 82271 110 220 0 91823 0
Current children cumulated CPU time (s) 38.3
Current children cumulated vsize (KiB) 429980

[startup+41.6098 s]
/proc/loadavg: 1.06 1.04 1.00 2/37 16875
/proc/meminfo: memFree=36632/1048576 swapFree=0/0
[pid=16869] ppid=16868 vsize=2568 CPUtime=0
/proc/16869/stat : 16869 (packup2mp4pa-0.) S 16868 16869 4778 34817 4778 4202496 378 0 0 0 0 0 0 0 25 0 1 0 11034123 2629632 274 1283457024 134512640 135304128 4293843216 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/16869/statm: 642 274 233 194 0 29 0
[pid=16870] ppid=16869 vsize=57556 CPUtime=4.93
/proc/16870/stat : 16870 (packup) S 16869 16869 4778 34817 4778 4202496 14027 19907 0 0 175 44 244 30 18 0 1 0 11034123 58937344 13613 1283457024 134512640 134752139 4288592864 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/16870/statm: 14389 13613 332 59 0 13553 0
[pid=16874] ppid=16870 vsize=1676 CPUtime=0
/proc/16874/stat : 16874 (sh) S 16870 16869 4778 34817 4778 4202496 146 0 0 0 0 0 0 0 19 0 1 0 11034619 1716224 124 1283457024 134512640 134593992 4289910224 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/16874/statm: 419 124 108 20 0 46 0
[pid=16875] ppid=16874 vsize=368180 CPUtime=36.57
/proc/16875/stat : 16875 (minisatp_32) R 16874 16869 4778 34817 4778 4202496 140690 0 0 0 3591 66 0 0 25 0 1 0 11034620 377016320 82341 1283457024 134512640 135413687 4288662720 18446744073709551615 134649535 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/16875/statm: 92045 82341 110 220 0 91823 0
Current children cumulated CPU time (s) 41.5
Current children cumulated vsize (KiB) 429980

[startup+42.41 s]
/proc/loadavg: 1.06 1.04 1.00 2/39 16877
/proc/meminfo: memFree=36608/1048576 swapFree=0/0
[pid=16869] ppid=16868 vsize=2568 CPUtime=0
/proc/16869/stat : 16869 (packup2mp4pa-0.) S 16868 16869 4778 34817 4778 4202496 378 0 0 0 0 0 0 0 25 0 1 0 11034123 2629632 274 1283457024 134512640 135304128 4293843216 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/16869/statm: 642 274 233 194 0 29 0
[pid=16870] ppid=16869 vsize=57556 CPUtime=4.93
/proc/16870/stat : 16870 (packup) S 16869 16869 4778 34817 4778 4202496 14027 19907 0 0 175 44 244 30 18 0 1 0 11034123 58937344 13613 1283457024 134512640 134752139 4288592864 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/16870/statm: 14389 13613 332 59 0 13553 0
[pid=16874] ppid=16870 vsize=1676 CPUtime=0
/proc/16874/stat : 16874 (sh) S 16870 16869 4778 34817 4778 4202496 146 0 0 0 0 0 0 0 19 0 1 0 11034619 1716224 124 1283457024 134512640 134593992 4289910224 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/16874/statm: 419 124 108 20 0 46 0
[pid=16875] ppid=16874 vsize=368180 CPUtime=37.37
/proc/16875/stat : 16875 (minisatp_32) R 16874 16869 4778 34817 4778 4202496 140700 0 0 0 3671 66 0 0 25 0 1 0 11034620 377016320 82351 1283457024 134512640 135413687 4288662720 18446744073709551615 134649574 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/16875/statm: 92045 82351 110 220 0 91823 0
Current children cumulated CPU time (s) 42.3
Current children cumulated vsize (KiB) 429980

[startup+42.8101 s]
/proc/loadavg: 1.06 1.04 1.00 2/39 16877
/proc/meminfo: memFree=36608/1048576 swapFree=0/0
[pid=16869] ppid=16868 vsize=2568 CPUtime=0
/proc/16869/stat : 16869 (packup2mp4pa-0.) S 16868 16869 4778 34817 4778 4202496 378 0 0 0 0 0 0 0 25 0 1 0 11034123 2629632 274 1283457024 134512640 135304128 4293843216 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/16869/statm: 642 274 233 194 0 29 0
[pid=16870] ppid=16869 vsize=57556 CPUtime=4.93
/proc/16870/stat : 16870 (packup) S 16869 16869 4778 34817 4778 4202496 14027 19907 0 0 175 44 244 30 18 0 1 0 11034123 58937344 13613 1283457024 134512640 134752139 4288592864 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/16870/statm: 14389 13613 332 59 0 13553 0
[pid=16874] ppid=16870 vsize=1676 CPUtime=0
/proc/16874/stat : 16874 (sh) S 16870 16869 4778 34817 4778 4202496 146 0 0 0 0 0 0 0 19 0 1 0 11034619 1716224 124 1283457024 134512640 134593992 4289910224 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/16874/statm: 419 124 108 20 0 46 0
[pid=16875] ppid=16874 vsize=368180 CPUtime=37.77
/proc/16875/stat : 16875 (minisatp_32) R 16874 16869 4778 34817 4778 4202496 140706 0 0 0 3711 66 0 0 25 0 1 0 11034620 377016320 82357 1283457024 134512640 135413687 4288662720 18446744073709551615 134649535 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/16875/statm: 92045 82357 110 220 0 91823 0
Current children cumulated CPU time (s) 42.7
Current children cumulated vsize (KiB) 429980

[startup+43.0139 s]
/proc/loadavg: 1.06 1.04 1.00 2/39 16877
/proc/meminfo: memFree=51240/1048576 swapFree=0/0
[pid=16869] ppid=16868 vsize=2568 CPUtime=0
/proc/16869/stat : 16869 (packup2mp4pa-0.) S 16868 16869 4778 34817 4778 4202496 378 0 0 0 0 0 0 0 25 0 1 0 11034123 2629632 274 1283457024 134512640 135304128 4293843216 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/16869/statm: 642 274 233 194 0 29 0
[pid=16870] ppid=16869 vsize=57556 CPUtime=4.93
/proc/16870/stat : 16870 (packup) S 16869 16869 4778 34817 4778 4202496 14027 19907 0 0 175 44 244 30 18 0 1 0 11034123 58937344 13613 1283457024 134512640 134752139 4288592864 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/16870/statm: 14389 13613 332 59 0 13553 0
[pid=16874] ppid=16870 vsize=1676 CPUtime=0
/proc/16874/stat : 16874 (sh) S 16870 16869 4778 34817 4778 4202496 146 0 0 0 0 0 0 0 19 0 1 0 11034619 1716224 124 1283457024 134512640 134593992 4289910224 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/16874/statm: 419 124 108 20 0 46 0
[pid=16875] ppid=16874 vsize=0 CPUtime=37.97
/proc/16875/stat : 16875 (minisatp_32) R 16874 16869 4778 34817 4778 4202500 141196 0 0 0 3728 69 0 0 25 0 1 0 11034620 0 0 1283457024 0 0 0 0 0 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/16875/statm: 0 0 0 0 0 0 0
Current children cumulated CPU time (s) 42.9
Current children cumulated vsize (KiB) 61800

[startup+43.1138 s]
/proc/loadavg: 1.06 1.04 1.00 2/39 16877
/proc/meminfo: memFree=51240/1048576 swapFree=0/0
[pid=16869] ppid=16868 vsize=2568 CPUtime=0
/proc/16869/stat : 16869 (packup2mp4pa-0.) S 16868 16869 4778 34817 4778 4202496 378 0 0 0 0 0 0 0 25 0 1 0 11034123 2629632 274 1283457024 134512640 135304128 4293843216 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/16869/statm: 642 274 233 194 0 29 0
[pid=16870] ppid=16869 vsize=54332 CPUtime=43.02
/proc/16870/stat : 16870 (packup) R 16869 16869 4778 34817 4778 4202496 26035 161251 0 0 183 46 3973 100 18 0 1 0 11034123 55635968 13052 1283457024 134512640 134752139 4288592864 18446744073709551615 4157134237 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/16870/statm: 13583 13052 345 59 0 12747 0
Current children cumulated CPU time (s) 43.02
Current children cumulated vsize (KiB) 56900

Child status: 0
Real time (s): 43.1596
CPU time (s): 43.0707
CPU user time (s): 41.5986
CPU system time (s): 1.47209
CPU usage (%): 99.7941
Max. virtual memory (cumulated for all children) (KiB): 478496

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

runsolver used 0 second user time and 0.004 second system time

The end