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/ab9005be-bacc-11e0-b0f6-00163e1e087d.cudf.dudf-real.log.runsolver ./packup2mp4tr-0.6 /home/misc2010/data/2011/dudf-real//ab9005be-bacc-11e0-b0f6-00163e1e087d.cudf /home/misc2010/tmp/201108241238/packup2mp4tr-0.6/ab9005be-bacc-11e0-b0f6-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.33 1.09 1.07 4/34 29670
/proc/meminfo: memFree=335604/1048576 swapFree=0/0
[pid=29669] ppid=29668 vsize=2572 CPUtime=0
/proc/29669/stat : 29669 (packup2mp4tr-0.) S 29668 29669 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 18 0 1 0 5014061 2633728 274 1283457024 134512640 135304128 4287961936 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/29669/statm: 643 274 233 194 0 30 0
[pid=29670] ppid=29669 vsize=3716 CPUtime=0.01
/proc/29670/stat : 29670 (packup) R 29669 29669 1511 34817 1511 4202496 423 0 0 0 1 0 0 0 25 0 1 0 5014061 3805184 352 1283457024 134512640 134752139 4288773088 18446744073709551615 134681839 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/29670/statm: 929 352 286 59 0 93 0

[startup+0.145047 s]
/proc/loadavg: 1.33 1.09 1.07 4/34 29670
/proc/meminfo: memFree=335604/1048576 swapFree=0/0
[pid=29669] ppid=29668 vsize=2572 CPUtime=0
/proc/29669/stat : 29669 (packup2mp4tr-0.) S 29668 29669 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 18 0 1 0 5014061 2633728 274 1283457024 134512640 135304128 4287961936 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/29669/statm: 643 274 233 194 0 30 0
[pid=29670] ppid=29669 vsize=9036 CPUtime=0.15
/proc/29670/stat : 29670 (packup) R 29669 29669 1511 34817 1511 4202496 1749 0 0 0 15 0 0 0 25 0 1 0 5014061 9252864 1678 1283457024 134512640 134752139 4288773088 18446744073709551615 134705950 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/29670/statm: 2259 1678 286 59 0 1423 0
Current children cumulated CPU time (s) 0.15
Current children cumulated vsize (KiB) 11608

[startup+0.205061 s]
/proc/loadavg: 1.33 1.09 1.07 4/34 29670
/proc/meminfo: memFree=335604/1048576 swapFree=0/0
[pid=29669] ppid=29668 vsize=2572 CPUtime=0
/proc/29669/stat : 29669 (packup2mp4tr-0.) S 29668 29669 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 18 0 1 0 5014061 2633728 274 1283457024 134512640 135304128 4287961936 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/29669/statm: 643 274 233 194 0 30 0
[pid=29670] ppid=29669 vsize=11148 CPUtime=0.21
/proc/29670/stat : 29670 (packup) R 29669 29669 1511 34817 1511 4202496 2261 0 0 0 21 0 0 0 25 0 1 0 5014061 11415552 2190 1283457024 134512640 134752139 4288773088 18446744073709551615 4159459641 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/29670/statm: 2787 2190 286 59 0 1951 0
Current children cumulated CPU time (s) 0.21
Current children cumulated vsize (KiB) 13720

[startup+0.30508 s]
/proc/loadavg: 1.33 1.09 1.07 4/34 29670
/proc/meminfo: memFree=335604/1048576 swapFree=0/0
[pid=29669] ppid=29668 vsize=2572 CPUtime=0
/proc/29669/stat : 29669 (packup2mp4tr-0.) S 29668 29669 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 18 0 1 0 5014061 2633728 274 1283457024 134512640 135304128 4287961936 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/29669/statm: 643 274 233 194 0 30 0
[pid=29670] ppid=29669 vsize=14172 CPUtime=0.31
/proc/29670/stat : 29670 (packup) R 29669 29669 1511 34817 1511 4202496 3039 0 0 0 31 0 0 0 25 0 1 0 5014061 14512128 2968 1283457024 134512640 134752139 4288773088 18446744073709551615 134705961 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/29670/statm: 3543 2968 286 59 0 2707 0
Current children cumulated CPU time (s) 0.31
Current children cumulated vsize (KiB) 16744

[startup+0.705156 s]
/proc/loadavg: 1.33 1.09 1.07 4/34 29670
/proc/meminfo: memFree=335604/1048576 swapFree=0/0
[pid=29669] ppid=29668 vsize=2572 CPUtime=0
/proc/29669/stat : 29669 (packup2mp4tr-0.) S 29668 29669 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 18 0 1 0 5014061 2633728 274 1283457024 134512640 135304128 4287961936 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/29669/statm: 643 274 233 194 0 30 0
[pid=29670] ppid=29669 vsize=25324 CPUtime=0.7
/proc/29670/stat : 29670 (packup) R 29669 29669 1511 34817 1511 4202496 5818 0 0 0 70 0 0 0 25 0 1 0 5014061 25931776 5747 1283457024 134512640 134752139 4288773088 18446744073709551615 134681639 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/29670/statm: 6331 5747 286 59 0 5495 0
Current children cumulated CPU time (s) 0.7
Current children cumulated vsize (KiB) 27896

[startup+1.50532 s]
/proc/loadavg: 1.33 1.09 1.07 2/35 29671
/proc/meminfo: memFree=304452/1048576 swapFree=0/0
[pid=29669] ppid=29668 vsize=2572 CPUtime=0
/proc/29669/stat : 29669 (packup2mp4tr-0.) S 29668 29669 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 18 0 1 0 5014061 2633728 274 1283457024 134512640 135304128 4287961936 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/29669/statm: 643 274 233 194 0 30 0
[pid=29670] ppid=29669 vsize=53276 CPUtime=1.5
/proc/29670/stat : 29670 (packup) R 29669 29669 1511 34817 1511 4202496 12914 0 0 0 140 10 0 0 25 0 1 0 5014061 54554624 12570 1283457024 134512640 134752139 4288773088 18446744073709551615 4294960130 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/29670/statm: 13319 12570 322 59 0 12483 0
Current children cumulated CPU time (s) 1.5
Current children cumulated vsize (KiB) 55848

[startup+3.10561 s]
/proc/loadavg: 1.33 1.09 1.07 2/37 29673
/proc/meminfo: memFree=274040/1048576 swapFree=0/0
[pid=29669] ppid=29668 vsize=2572 CPUtime=0
/proc/29669/stat : 29669 (packup2mp4tr-0.) S 29668 29669 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 18 0 1 0 5014061 2633728 274 1283457024 134512640 135304128 4287961936 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/29669/statm: 643 274 233 194 0 30 0
[pid=29670] ppid=29669 vsize=53276 CPUtime=1.75
/proc/29670/stat : 29670 (packup) S 29669 29669 1511 34817 1511 4202496 12918 0 0 0 153 22 0 0 25 0 1 0 5014061 54554624 12573 1283457024 134512640 134752139 4288773088 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/29670/statm: 13319 12573 325 59 0 12483 0
[pid=29672] ppid=29670 vsize=1676 CPUtime=0.01
/proc/29672/stat : 29672 (sh) S 29670 29669 1511 34817 1511 4202496 147 0 0 0 0 1 0 0 25 0 1 0 5014236 1716224 124 1283457024 134512640 134593992 4287853536 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/29672/statm: 419 124 108 20 0 46 0
[pid=29673] ppid=29672 vsize=32688 CPUtime=1.34
/proc/29673/stat : 29673 (minisatp_32) R 29672 29669 1511 34817 1511 4202496 7818 0 0 0 122 12 0 0 25 0 1 0 5014237 33472512 6983 1283457024 134512640 135413687 4289197376 18446744073709551615 134988446 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/29673/statm: 8172 6983 85 220 0 7950 0
Current children cumulated CPU time (s) 3.1
Current children cumulated vsize (KiB) 90212

[startup+6.30691 s]
/proc/loadavg: 1.31 1.09 1.07 2/37 29675
/proc/meminfo: memFree=278016/1048576 swapFree=0/0
[pid=29669] ppid=29668 vsize=2572 CPUtime=0
/proc/29669/stat : 29669 (packup2mp4tr-0.) S 29668 29669 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 18 0 1 0 5014061 2633728 274 1283457024 134512640 135304128 4287961936 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/29669/statm: 643 274 233 194 0 30 0
[pid=29670] ppid=29669 vsize=53280 CPUtime=5.28
/proc/29670/stat : 29670 (packup) S 29669 29669 1511 34817 1511 4202496 13025 27138 0 0 169 40 288 31 18 0 1 0 5014061 54558720 12591 1283457024 134512640 134752139 4288773088 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/29670/statm: 13320 12591 333 59 0 12484 0
[pid=29674] ppid=29670 vsize=1668 CPUtime=0
/proc/29674/stat : 29674 (sh) S 29670 29669 1511 34817 1511 4202496 145 0 0 0 0 0 0 0 18 0 1 0 5014589 1708032 123 1283457024 134512640 134593992 4291522400 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/29674/statm: 417 123 108 20 0 44 0
[pid=29675] ppid=29674 vsize=27204 CPUtime=1.01
/proc/29675/stat : 29675 (minisatp_32) R 29674 29669 1511 34817 1511 4202496 6127 0 0 0 99 2 0 0 23 0 1 0 5014590 27856896 5466 1283457024 134512640 135413687 4287302512 18446744073709551615 134971360 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/29675/statm: 6801 5466 77 220 0 6579 0
Current children cumulated CPU time (s) 6.29
Current children cumulated vsize (KiB) 84724

[startup+12.7084 s]
/proc/loadavg: 1.28 1.09 1.07 2/37 29677
/proc/meminfo: memFree=218000/1048576 swapFree=0/0
[pid=29669] ppid=29668 vsize=2572 CPUtime=0
/proc/29669/stat : 29669 (packup2mp4tr-0.) S 29668 29669 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 18 0 1 0 5014061 2633728 274 1283457024 134512640 135304128 4287961936 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/29669/statm: 643 274 233 194 0 30 0
[pid=29670] ppid=29669 vsize=53284 CPUtime=10.01
/proc/29670/stat : 29670 (packup) S 29669 29669 1511 34817 1511 4202496 13117 67294 0 0 184 61 697 59 18 0 1 0 5014061 54562816 12601 1283457024 134512640 134752139 4288773088 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/29670/statm: 13321 12601 333 59 0 12485 0
[pid=29676] ppid=29670 vsize=1672 CPUtime=0
/proc/29676/stat : 29676 (sh) S 29670 29669 1511 34817 1511 4202496 145 0 0 0 0 0 0 0 18 0 1 0 5015063 1712128 123 1283457024 134512640 134593992 4286868208 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/29676/statm: 418 123 108 20 0 45 0
[pid=29677] ppid=29676 vsize=71152 CPUtime=2.67
/proc/29677/stat : 29677 (minisatp_32) R 29676 29669 1511 34817 1511 4202496 24109 0 0 0 243 24 0 0 25 0 1 0 5015064 72859648 16376 1283457024 134512640 135413687 4287437712 18446744073709551615 134686229 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/29677/statm: 17788 16376 94 220 0 17566 0
Current children cumulated CPU time (s) 12.68
Current children cumulated vsize (KiB) 128680

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

[startup+12.8084 s]
/proc/loadavg: 1.28 1.09 1.07 2/37 29677
/proc/meminfo: memFree=218000/1048576 swapFree=0/0
[pid=29669] ppid=29668 vsize=2572 CPUtime=0
/proc/29669/stat : 29669 (packup2mp4tr-0.) S 29668 29669 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 18 0 1 0 5014061 2633728 274 1283457024 134512640 135304128 4287961936 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/29669/statm: 643 274 233 194 0 30 0
[pid=29670] ppid=29669 vsize=53284 CPUtime=10.01
/proc/29670/stat : 29670 (packup) S 29669 29669 1511 34817 1511 4202496 13117 67294 0 0 184 61 697 59 18 0 1 0 5014061 54562816 12601 1283457024 134512640 134752139 4288773088 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/29670/statm: 13321 12601 333 59 0 12485 0
[pid=29676] ppid=29670 vsize=1672 CPUtime=0
/proc/29676/stat : 29676 (sh) S 29670 29669 1511 34817 1511 4202496 145 0 0 0 0 0 0 0 18 0 1 0 5015063 1712128 123 1283457024 134512640 134593992 4286868208 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/29676/statm: 418 123 108 20 0 45 0
[pid=29677] ppid=29676 vsize=72368 CPUtime=2.77
/proc/29677/stat : 29677 (minisatp_32) R 29676 29669 1511 34817 1511 4202496 24325 0 0 0 253 24 0 0 25 0 1 0 5015064 74104832 16584 1283457024 134512640 135413687 4287437712 18446744073709551615 134705601 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/29677/statm: 18092 16584 94 220 0 17870 0
Current children cumulated CPU time (s) 12.78
Current children cumulated vsize (KiB) 129896

[startup+16.0091 s]
/proc/loadavg: 1.26 1.08 1.07 2/37 29677
/proc/meminfo: memFree=177204/1048576 swapFree=0/0
[pid=29669] ppid=29668 vsize=2572 CPUtime=0
/proc/29669/stat : 29669 (packup2mp4tr-0.) S 29668 29669 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 18 0 1 0 5014061 2633728 274 1283457024 134512640 135304128 4287961936 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/29669/statm: 643 274 233 194 0 30 0
[pid=29670] ppid=29669 vsize=53288 CPUtime=15.78
/proc/29670/stat : 29670 (packup) S 29669 29669 1511 34817 1511 4202496 13206 111761 0 0 204 78 1192 104 18 0 1 0 5014061 54566912 12602 1283457024 134512640 134752139 4288773088 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/29670/statm: 13322 12602 333 59 0 12486 0
Current children cumulated CPU time (s) 15.78
Current children cumulated vsize (KiB) 55860

[startup+19.2098 s]
/proc/loadavg: 1.24 1.08 1.07 2/37 29679
/proc/meminfo: memFree=178444/1048576 swapFree=0/0
[pid=29669] ppid=29668 vsize=2572 CPUtime=0
/proc/29669/stat : 29669 (packup2mp4tr-0.) S 29668 29669 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 18 0 1 0 5014061 2633728 274 1283457024 134512640 135304128 4287961936 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/29669/statm: 643 274 233 194 0 30 0
[pid=29670] ppid=29669 vsize=53288 CPUtime=15.78
/proc/29670/stat : 29670 (packup) S 29669 29669 1511 34817 1511 4202496 13206 111761 0 0 204 78 1192 104 18 0 1 0 5014061 54566912 12602 1283457024 134512640 134752139 4288773088 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/29670/statm: 13322 12602 333 59 0 12486 0
[pid=29678] ppid=29670 vsize=1668 CPUtime=0
/proc/29678/stat : 29678 (sh) S 29670 29669 1511 34817 1511 4202496 145 0 0 0 0 0 0 0 18 0 1 0 5015640 1708032 123 1283457024 134512640 134593992 4286913264 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/29678/statm: 417 123 108 20 0 44 0
[pid=29679] ppid=29678 vsize=124136 CPUtime=3.41
/proc/29679/stat : 29679 (minisatp_32) R 29678 29669 1511 34817 1511 4202496 38237 0 0 0 307 34 0 0 25 0 1 0 5015640 127115264 26768 1283457024 134512640 135413687 4288001056 18446744073709551615 134689069 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/29679/statm: 31034 26768 94 220 0 30812 0
Current children cumulated CPU time (s) 19.19
Current children cumulated vsize (KiB) 181664

[startup+20.8102 s]
/proc/loadavg: 1.24 1.08 1.07 2/37 29679
/proc/meminfo: memFree=176832/1048576 swapFree=0/0
[pid=29669] ppid=29668 vsize=2572 CPUtime=0
/proc/29669/stat : 29669 (packup2mp4tr-0.) S 29668 29669 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 18 0 1 0 5014061 2633728 274 1283457024 134512640 135304128 4287961936 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/29669/statm: 643 274 233 194 0 30 0
[pid=29670] ppid=29669 vsize=53288 CPUtime=15.78
/proc/29670/stat : 29670 (packup) S 29669 29669 1511 34817 1511 4202496 13206 111761 0 0 204 78 1192 104 18 0 1 0 5014061 54566912 12602 1283457024 134512640 134752139 4288773088 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/29670/statm: 13322 12602 333 59 0 12486 0
[pid=29678] ppid=29670 vsize=1668 CPUtime=0
/proc/29678/stat : 29678 (sh) S 29670 29669 1511 34817 1511 4202496 145 0 0 0 0 0 0 0 18 0 1 0 5015640 1708032 123 1283457024 134512640 134593992 4286913264 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/29678/statm: 417 123 108 20 0 44 0
[pid=29679] ppid=29678 vsize=130152 CPUtime=5.01
/proc/29679/stat : 29679 (minisatp_32) R 29678 29669 1511 34817 1511 4202496 46049 0 0 0 464 37 0 0 25 0 1 0 5015640 133275648 29748 1283457024 134512640 135413687 4288001056 18446744073709551615 134686484 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/29679/statm: 32538 29748 107 220 0 32316 0
Current children cumulated CPU time (s) 20.79
Current children cumulated vsize (KiB) 187680

[startup+21.2103 s]
/proc/loadavg: 1.24 1.08 1.07 2/37 29679
/proc/meminfo: memFree=160464/1048576 swapFree=0/0
[pid=29669] ppid=29668 vsize=2572 CPUtime=0
/proc/29669/stat : 29669 (packup2mp4tr-0.) S 29668 29669 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 18 0 1 0 5014061 2633728 274 1283457024 134512640 135304128 4287961936 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/29669/statm: 643 274 233 194 0 30 0
[pid=29670] ppid=29669 vsize=53288 CPUtime=15.78
/proc/29670/stat : 29670 (packup) S 29669 29669 1511 34817 1511 4202496 13206 111761 0 0 204 78 1192 104 18 0 1 0 5014061 54566912 12602 1283457024 134512640 134752139 4288773088 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/29670/statm: 13322 12602 333 59 0 12486 0
[pid=29678] ppid=29670 vsize=1668 CPUtime=0
/proc/29678/stat : 29678 (sh) S 29670 29669 1511 34817 1511 4202496 145 0 0 0 0 0 0 0 18 0 1 0 5015640 1708032 123 1283457024 134512640 134593992 4286913264 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/29678/statm: 417 123 108 20 0 44 0
[pid=29679] ppid=29678 vsize=133716 CPUtime=5.4
/proc/29679/stat : 29679 (minisatp_32) R 29678 29669 1511 34817 1511 4202496 48380 0 0 0 502 38 0 0 25 0 1 0 5015640 136925184 30621 1283457024 134512640 135413687 4288001056 18446744073709551615 134692010 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/29679/statm: 33429 30621 107 220 0 33207 0
Current children cumulated CPU time (s) 21.18
Current children cumulated vsize (KiB) 191244

[startup+21.4104 s]
/proc/loadavg: 1.24 1.08 1.07 2/37 29679
/proc/meminfo: memFree=160464/1048576 swapFree=0/0
[pid=29669] ppid=29668 vsize=2572 CPUtime=0
/proc/29669/stat : 29669 (packup2mp4tr-0.) S 29668 29669 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 18 0 1 0 5014061 2633728 274 1283457024 134512640 135304128 4287961936 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/29669/statm: 643 274 233 194 0 30 0
[pid=29670] ppid=29669 vsize=53288 CPUtime=15.78
/proc/29670/stat : 29670 (packup) S 29669 29669 1511 34817 1511 4202496 13206 111761 0 0 204 78 1192 104 18 0 1 0 5014061 54566912 12602 1283457024 134512640 134752139 4288773088 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/29670/statm: 13322 12602 333 59 0 12486 0
[pid=29678] ppid=29670 vsize=1668 CPUtime=0
/proc/29678/stat : 29678 (sh) S 29670 29669 1511 34817 1511 4202496 145 0 0 0 0 0 0 0 18 0 1 0 5015640 1708032 123 1283457024 134512640 134593992 4286913264 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/29678/statm: 417 123 108 20 0 44 0
[pid=29679] ppid=29678 vsize=127736 CPUtime=5.61
/proc/29679/stat : 29679 (minisatp_32) R 29678 29669 1511 34817 1511 4202496 48634 0 0 0 522 39 0 0 25 0 1 0 5015640 130801664 29310 1283457024 134512640 135413687 4288001056 18446744073709551615 134597339 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/29679/statm: 31934 29310 117 220 0 31712 0
Current children cumulated CPU time (s) 21.39
Current children cumulated vsize (KiB) 185264

[startup+21.5104 s]
/proc/loadavg: 1.24 1.08 1.07 2/37 29679
/proc/meminfo: memFree=160464/1048576 swapFree=0/0
[pid=29669] ppid=29668 vsize=2572 CPUtime=0
/proc/29669/stat : 29669 (packup2mp4tr-0.) S 29668 29669 1511 34817 1511 4202496 378 0 0 0 0 0 0 0 18 0 1 0 5014061 2633728 274 1283457024 134512640 135304128 4287961936 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/29669/statm: 643 274 233 194 0 30 0
[pid=29670] ppid=29669 vsize=52516 CPUtime=21.49
/proc/29670/stat : 29670 (packup) R 29669 29669 1511 34817 1511 4202496 17692 160543 0 0 208 82 1715 144 18 0 1 0 5014061 53776384 12422 1283457024 134512640 134752139 4288773088 18446744073709551615 4157663470 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/29670/statm: 13129 12422 346 59 0 12293 0
Current children cumulated CPU time (s) 21.49
Current children cumulated vsize (KiB) 55088

Child status: 0
Real time (s): 21.6055
CPU time (s): 21.5933
CPU user time (s): 19.3172
CPU system time (s): 2.27614
CPU usage (%): 99.9436
Max. virtual memory (cumulated for all children) (KiB): 202436

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

runsolver used 0 second user time and 0 second system time

The end