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: runsolver -s SIGUSR1 -M 1124 -C 300 -d 10 -w /tmp/misc2012/2012-09-02-22:42/full/aspuncud-full-1.7/trendy-size/install/rand83.cudf.log.runsolver /home/competition/aspuncud-full-1.7/aspuncud-full /home/competition/data/install/rand83.cudf /tmp/misc2012/2012-09-02-22:42/full/aspuncud-full-1.7/trendy-size/install/rand83.cudf.result -count(removed),-sum(solution,installedsize),-notuptodate(solution),-unsat_recommends(solution),-count(new) 

Enforcing CPUTime limit (soft limit, will send signal-name then SIGKILL): 300 seconds
Enforcing CPUTime limit (hard limit, will send SIGXCPU): 330 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.02 0.93 2/64 17337
/proc/meminfo: memFree=701552/1022884 swapFree=0/0
[pid=17337] ppid=17336 vsize=1068 CPUtime=0
/proc/17337/stat : 17337 (aspuncud-full) D 17336 17337 1745 0 -1 4194304 75 0 0 0 0 0 0 0 20 0 1 0 119661511 1093632 1 18446744073709551615 0 0 140735744084915 4288503984 4151673904 0 0 16781316 0 0 0 0 17 0 0 0 0 0 0
/proc/17337/statm: 267 1 0 0 0 28 0

[startup+0.166404 s]
/proc/loadavg: 1.12 1.02 0.93 2/64 17337
/proc/meminfo: memFree=701552/1022884 swapFree=0/0
[pid=17337] ppid=17336 vsize=9212 CPUtime=0.05
/proc/17337/stat : 17337 (aspuncud-full) S 17336 17337 1745 0 -1 4202496 700 2800 2 7 1 0 2 2 20 0 1 0 119661511 9433088 365 18446744073709551615 4194304 5129932 140735744079264 140735744077920 140459698943070 0 65536 16781316 1115778811 0 0 0 17 0 0 0 2 0 0
/proc/17337/statm: 2303 365 303 229 0 63 0
Current children cumulated CPU time (s) 0.05
Current children cumulated vsize (KiB) 9212

[startup+0.200335 s]
/proc/loadavg: 1.12 1.02 0.93 2/64 17337
/proc/meminfo: memFree=701552/1022884 swapFree=0/0
[pid=17337] ppid=17336 vsize=9212 CPUtime=0.05
/proc/17337/stat : 17337 (aspuncud-full) S 17336 17337 1745 0 -1 4202496 700 2800 2 7 1 0 2 2 20 0 1 0 119661511 9433088 365 18446744073709551615 4194304 5129932 140735744079264 140735744077920 140459698943070 0 65536 16781316 1115778811 0 0 0 17 0 0 0 2 0 0
/proc/17337/statm: 2303 365 303 229 0 63 0
Current children cumulated CPU time (s) 0.05
Current children cumulated vsize (KiB) 9212

[startup+0.300402 s]
/proc/loadavg: 1.12 1.02 0.93 2/64 17337
/proc/meminfo: memFree=701552/1022884 swapFree=0/0
[pid=17337] ppid=17336 vsize=9212 CPUtime=0.05
/proc/17337/stat : 17337 (aspuncud-full) S 17336 17337 1745 0 -1 4202496 700 2800 2 7 1 0 2 2 20 0 1 0 119661511 9433088 365 18446744073709551615 4194304 5129932 140735744079264 140735744077920 140459698943070 0 65536 16781316 1115778811 0 0 0 17 0 0 0 2 0 0
/proc/17337/statm: 2303 365 303 229 0 63 0
Current children cumulated CPU time (s) 0.05
Current children cumulated vsize (KiB) 9212

[startup+0.700198 s]
/proc/loadavg: 1.12 1.02 0.93 2/64 17337
/proc/meminfo: memFree=701552/1022884 swapFree=0/0
[pid=17337] ppid=17336 vsize=9212 CPUtime=0.05
/proc/17337/stat : 17337 (aspuncud-full) S 17336 17337 1745 0 -1 4202496 700 2800 2 7 1 0 2 2 20 0 1 0 119661511 9433088 365 18446744073709551615 4194304 5129932 140735744079264 140735744077920 140459698943070 0 65536 16781316 1115778811 0 0 0 17 0 0 0 2 0 0
/proc/17337/statm: 2303 365 303 229 0 63 0
Current children cumulated CPU time (s) 0.05
Current children cumulated vsize (KiB) 9212

[startup+1.50033 s]
/proc/loadavg: 1.12 1.02 0.93 2/66 17350
/proc/meminfo: memFree=668048/1022884 swapFree=0/0
[pid=17337] ppid=17336 vsize=9212 CPUtime=0.05
/proc/17337/stat : 17337 (aspuncud-full) S 17336 17337 1745 0 -1 4202496 700 2800 2 7 1 0 2 2 20 0 1 0 119661511 9433088 365 18446744073709551615 4194304 5129932 140735744079264 140735744077920 140459698943070 0 65536 16781316 1115778811 0 0 0 17 0 0 0 2 0 0
/proc/17337/statm: 2303 365 303 229 0 63 0
[pid=17350] ppid=17337 vsize=30408 CPUtime=1.35
/proc/17350/stat : 17350 (cudf2lp) R 17337 17337 1745 0 -1 4202496 9006 0 1 0 129 6 0 0 20 0 1 0 119661523 31137792 7273 18446744073709551615 4194304 5690517 140736878326400 140736878324040 4247165 0 0 16781316 0 0 0 0 17 0 0 0 2 0 0
/proc/17350/statm: 7602 7273 160 366 0 7233 0
Current children cumulated CPU time (s) 1.4
Current children cumulated vsize (KiB) 39620

[startup+3.10031 s]
/proc/loadavg: 1.11 1.01 0.93 2/66 17350
/proc/meminfo: memFree=636552/1022884 swapFree=0/0
[pid=17337] ppid=17336 vsize=9212 CPUtime=0.05
/proc/17337/stat : 17337 (aspuncud-full) S 17336 17337 1745 0 -1 4202496 700 2800 2 7 1 0 2 2 20 0 1 0 119661511 9433088 365 18446744073709551615 4194304 5129932 140735744079264 140735744077920 140459698943070 0 65536 16781316 1115778811 0 0 0 17 0 0 0 2 0 0
/proc/17337/statm: 2303 365 303 229 0 63 0
[pid=17350] ppid=17337 vsize=106344 CPUtime=2.94
/proc/17350/stat : 17350 (cudf2lp) R 17337 17337 1745 0 -1 4202496 26391 0 1 0 280 14 0 0 20 0 1 0 119661523 108896256 22993 18446744073709551615 4194304 5690517 140736878326400 140736878322600 4376724 0 0 16781316 0 0 0 0 17 0 0 0 2 0 0
/proc/17350/statm: 26586 22993 160 366 0 26217 0
Current children cumulated CPU time (s) 2.99
Current children cumulated vsize (KiB) 115556

[startup+6.3003 s]
/proc/loadavg: 1.11 1.01 0.93 2/66 17350
/proc/meminfo: memFree=610140/1022884 swapFree=0/0
[pid=17337] ppid=17336 vsize=9212 CPUtime=5.41
/proc/17337/stat : 17337 (aspuncud-full) S 17336 17337 1745 0 -1 4202496 728 42120 2 8 1 0 510 30 20 0 1 0 119661511 9433088 365 18446744073709551615 4194304 5129932 140735744079264 140735744077920 140459698943070 0 65536 16781316 1115778811 0 0 0 17 0 0 0 2 0 0
/proc/17337/statm: 2303 365 303 229 0 63 0
Current children cumulated CPU time (s) 5.41
Current children cumulated vsize (KiB) 9212

[startup+12.7003 s]
/proc/loadavg: 1.09 1.01 0.93 2/66 17351
/proc/meminfo: memFree=378136/1022884 swapFree=0/0
[pid=17337] ppid=17336 vsize=9212 CPUtime=5.41
/proc/17337/stat : 17337 (aspuncud-full) S 17336 17337 1745 0 -1 4202496 728 42120 2 8 1 0 510 30 20 0 1 0 119661511 9433088 365 18446744073709551615 4194304 5129932 140735744079264 140735744077920 140459698943070 0 65536 16781316 1115778811 0 0 0 17 0 0 0 2 0 0
/proc/17337/statm: 2303 365 303 229 0 63 0
[pid=17351] ppid=17337 vsize=382664 CPUtime=7.05
/proc/17351/stat : 17351 (gringo) R 17337 17337 1745 0 -1 4202496 92300 0 1 0 659 46 0 0 20 0 1 0 119662066 391847936 75825 18446744073709551615 4194304 6531320 140734721954176 140734721950600 4595520 0 0 16781316 16386 0 0 0 17 0 0 0 1 0 0
/proc/17351/statm: 95666 75825 282 571 0 95087 0
Current children cumulated CPU time (s) 12.46
Current children cumulated vsize (KiB) 391876

[startup+25.5003 s]
/proc/loadavg: 1.08 1.01 0.93 2/67 17353
/proc/meminfo: memFree=431712/1022884 swapFree=0/0
[pid=17337] ppid=17336 vsize=9212 CPUtime=18.77
/proc/17337/stat : 17337 (aspuncud-full) S 17336 17337 1745 0 -1 4202496 770 221715 2 9 1 0 1755 121 20 0 1 0 119661511 9433088 365 18446744073709551615 4194304 5129932 140735744079264 140735744077328 140459698943070 0 65536 16781316 1115778811 0 0 0 17 0 0 0 2 0 0
/proc/17337/statm: 2303 365 303 229 0 63 0
[pid=17352] ppid=17337 vsize=229728 CPUtime=6.24
/proc/17352/stat : 17352 (unclasp) R 17337 17337 1745 0 -1 4202496 69594 0 1 0 606 18 0 0 20 0 1 0 119663428 235241472 56978 18446744073709551615 4194304 6012874 140736141560128 140736141559448 4548906 0 0 16781316 16386 0 0 0 17 0 0 0 2 0 0
/proc/17352/statm: 57432 56978 230 444 0 56980 0
[pid=17353] ppid=17337 vsize=22356 CPUtime=0.01
/proc/17353/stat : 17353 (parse.py) S 17337 17337 1745 0 -1 4202496 1379 0 13 0 1 0 0 0 20 0 1 0 119663428 22892544 1201 18446744073709551615 4194304 6642060 140733569683328 140733569681288 140715137214240 0 0 16777220 20994 0 0 0 17 0 0 0 9 0 0
/proc/17353/statm: 5589 1201 508 598 0 675 0
Current children cumulated CPU time (s) 25.02
Current children cumulated vsize (KiB) 261296

[startup+51.1004 s]
/proc/loadavg: 1.05 1.01 0.93 2/67 17353
/proc/meminfo: memFree=431588/1022884 swapFree=0/0
[pid=17337] ppid=17336 vsize=9212 CPUtime=18.77
/proc/17337/stat : 17337 (aspuncud-full) S 17336 17337 1745 0 -1 4202496 770 221715 2 9 1 0 1755 121 20 0 1 0 119661511 9433088 365 18446744073709551615 4194304 5129932 140735744079264 140735744077328 140459698943070 0 65536 16781316 1115778811 0 0 0 17 0 0 0 2 0 0
/proc/17337/statm: 2303 365 303 229 0 63 0
[pid=17352] ppid=17337 vsize=229728 CPUtime=31.57
/proc/17352/stat : 17352 (unclasp) R 17337 17337 1745 0 -1 4202496 69594 0 1 0 3137 20 0 0 20 0 1 0 119663428 235241472 56978 18446744073709551615 4194304 6012874 140736141560128 140736141559448 4548913 0 0 16781316 16386 0 0 0 17 0 0 0 2 0 0
/proc/17352/statm: 57432 56978 230 444 0 56980 0
[pid=17353] ppid=17337 vsize=22540 CPUtime=0.01
/proc/17353/stat : 17353 (parse.py) S 17337 17337 1745 0 -1 4202496 1402 0 13 0 1 0 0 0 20 0 1 0 119663428 23080960 1224 18446744073709551615 4194304 6642060 140733569683328 140733569681528 140715137214240 0 0 16777220 20994 0 0 0 17 0 0 0 9 0 0
/proc/17353/statm: 5635 1224 508 598 0 721 0
Current children cumulated CPU time (s) 50.35
Current children cumulated vsize (KiB) 261480

[startup+102.3 s]
/proc/loadavg: 1.02 1.00 0.93 2/67 17353
/proc/meminfo: memFree=431340/1022884 swapFree=0/0
[pid=17337] ppid=17336 vsize=9212 CPUtime=18.77
/proc/17337/stat : 17337 (aspuncud-full) S 17336 17337 1745 0 -1 4202496 770 221715 2 9 1 0 1755 121 20 0 1 0 119661511 9433088 365 18446744073709551615 4194304 5129932 140735744079264 140735744077328 140459698943070 0 65536 16781316 1115778811 0 0 0 17 0 0 0 2 0 0
/proc/17337/statm: 2303 365 303 229 0 63 0
[pid=17352] ppid=17337 vsize=229728 CPUtime=82.32
/proc/17352/stat : 17352 (unclasp) R 17337 17337 1745 0 -1 4202496 69616 0 1 0 8210 22 0 0 20 0 1 0 119663428 235241472 57000 18446744073709551615 4194304 6012874 140736141560128 140736141559192 4495022 0 0 16781316 16386 0 0 0 17 0 0 0 2 0 0
/proc/17352/statm: 57432 57000 230 444 0 56980 0
[pid=17353] ppid=17337 vsize=22540 CPUtime=0.01
/proc/17353/stat : 17353 (parse.py) S 17337 17337 1745 0 -1 4202496 1402 0 13 0 1 0 0 0 20 0 1 0 119663428 23080960 1224 18446744073709551615 4194304 6642060 140733569683328 140733569681528 140715137214240 0 0 16777220 20994 0 0 0 17 0 0 0 9 0 0
/proc/17353/statm: 5635 1224 508 598 0 721 0
Current children cumulated CPU time (s) 101.1
Current children cumulated vsize (KiB) 261480

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

[startup+102.404 s]
/proc/loadavg: 1.02 1.00 0.93 2/67 17353
/proc/meminfo: memFree=431340/1022884 swapFree=0/0
[pid=17337] ppid=17336 vsize=9212 CPUtime=18.77
/proc/17337/stat : 17337 (aspuncud-full) S 17336 17337 1745 0 -1 4202496 770 221715 2 9 1 0 1755 121 20 0 1 0 119661511 9433088 365 18446744073709551615 4194304 5129932 140735744079264 140735744077328 140459698943070 0 65536 16781316 1115778811 0 0 0 17 0 0 0 2 0 0
/proc/17337/statm: 2303 365 303 229 0 63 0
[pid=17352] ppid=17337 vsize=229728 CPUtime=82.42
/proc/17352/stat : 17352 (unclasp) R 17337 17337 1745 0 -1 4202496 69616 0 1 0 8220 22 0 0 20 0 1 0 119663428 235241472 57000 18446744073709551615 4194304 6012874 140736141560128 140736141559448 4548906 0 0 16781316 16386 0 0 0 17 0 0 0 2 0 0
/proc/17352/statm: 57432 57000 230 444 0 56980 0
[pid=17353] ppid=17337 vsize=22540 CPUtime=0.01
/proc/17353/stat : 17353 (parse.py) S 17337 17337 1745 0 -1 4202496 1402 0 13 0 1 0 0 0 20 0 1 0 119663428 23080960 1224 18446744073709551615 4194304 6642060 140733569683328 140733569681528 140715137214240 0 0 16777220 20994 0 0 0 17 0 0 0 9 0 0
/proc/17353/statm: 5635 1224 508 598 0 721 0
Current children cumulated CPU time (s) 101.2
Current children cumulated vsize (KiB) 261480

[startup+115.2 s]
/proc/loadavg: 1.02 1.00 0.93 2/67 17353
/proc/meminfo: memFree=431340/1022884 swapFree=0/0
[pid=17337] ppid=17336 vsize=9212 CPUtime=18.77
/proc/17337/stat : 17337 (aspuncud-full) S 17336 17337 1745 0 -1 4202496 770 221715 2 9 1 0 1755 121 20 0 1 0 119661511 9433088 365 18446744073709551615 4194304 5129932 140735744079264 140735744077328 140459698943070 0 65536 16781316 1115778811 0 0 0 17 0 0 0 2 0 0
/proc/17337/statm: 2303 365 303 229 0 63 0
[pid=17352] ppid=17337 vsize=229728 CPUtime=95.09
/proc/17352/stat : 17352 (unclasp) R 17337 17337 1745 0 -1 4202496 69616 0 2 0 9487 22 0 0 20 0 1 0 119663428 235241472 57001 18446744073709551615 4194304 6012874 140736141560128 140736141559448 4548913 0 0 16781316 16386 0 0 0 17 0 0 0 3 0 0
/proc/17352/statm: 57432 57001 231 444 0 56980 0
[pid=17353] ppid=17337 vsize=22540 CPUtime=0.01
/proc/17353/stat : 17353 (parse.py) S 17337 17337 1745 0 -1 4202496 1402 0 13 0 1 0 0 0 20 0 1 0 119663428 23080960 1224 18446744073709551615 4194304 6642060 140733569683328 140733569681528 140715137214240 0 0 16777220 20994 0 0 0 17 0 0 0 9 0 0
/proc/17353/statm: 5635 1224 508 598 0 721 0
Current children cumulated CPU time (s) 113.87
Current children cumulated vsize (KiB) 261480

[startup+128 s]
/proc/loadavg: 1.09 1.02 0.94 2/67 17353
/proc/meminfo: memFree=431340/1022884 swapFree=0/0
[pid=17337] ppid=17336 vsize=9212 CPUtime=18.77
/proc/17337/stat : 17337 (aspuncud-full) S 17336 17337 1745 0 -1 4202496 770 221715 2 9 1 0 1755 121 20 0 1 0 119661511 9433088 365 18446744073709551615 4194304 5129932 140735744079264 140735744077328 140459698943070 0 65536 16781316 1115778811 0 0 0 17 0 0 0 2 0 0
/proc/17337/statm: 2303 365 303 229 0 63 0
[pid=17352] ppid=17337 vsize=229728 CPUtime=107.75
/proc/17352/stat : 17352 (unclasp) R 17337 17337 1745 0 -1 4202496 69616 0 2 0 10753 22 0 0 20 0 1 0 119663428 235241472 57001 18446744073709551615 4194304 6012874 140736141560128 140736141559448 4548102 0 0 16781316 16386 0 0 0 17 0 0 0 3 0 0
/proc/17352/statm: 57432 57001 231 444 0 56980 0
[pid=17353] ppid=17337 vsize=22540 CPUtime=0.01
/proc/17353/stat : 17353 (parse.py) S 17337 17337 1745 0 -1 4202496 1402 0 13 0 1 0 0 0 20 0 1 0 119663428 23080960 1224 18446744073709551615 4194304 6642060 140733569683328 140733569681528 140715137214240 0 0 16777220 20994 0 0 0 17 0 0 0 9 0 0
/proc/17353/statm: 5635 1224 508 598 0 721 0
Current children cumulated CPU time (s) 126.53
Current children cumulated vsize (KiB) 261480

[startup+131.2 s]
/proc/loadavg: 1.09 1.02 0.94 2/67 17353
/proc/meminfo: memFree=431340/1022884 swapFree=0/0
[pid=17337] ppid=17336 vsize=9212 CPUtime=18.77
/proc/17337/stat : 17337 (aspuncud-full) S 17336 17337 1745 0 -1 4202496 770 221715 2 9 1 0 1755 121 20 0 1 0 119661511 9433088 365 18446744073709551615 4194304 5129932 140735744079264 140735744077328 140459698943070 0 65536 16781316 1115778811 0 0 0 17 0 0 0 2 0 0
/proc/17337/statm: 2303 365 303 229 0 63 0
[pid=17352] ppid=17337 vsize=229728 CPUtime=110.92
/proc/17352/stat : 17352 (unclasp) R 17337 17337 1745 0 -1 4202496 69616 0 2 0 11070 22 0 0 20 0 1 0 119663428 235241472 57001 18446744073709551615 4194304 6012874 140736141560128 140736141559448 4548913 0 0 16781316 16386 0 0 0 17 0 0 0 3 0 0
/proc/17352/statm: 57432 57001 231 444 0 56980 0
[pid=17353] ppid=17337 vsize=22540 CPUtime=0.01
/proc/17353/stat : 17353 (parse.py) S 17337 17337 1745 0 -1 4202496 1402 0 13 0 1 0 0 0 20 0 1 0 119663428 23080960 1224 18446744073709551615 4194304 6642060 140733569683328 140733569681528 140715137214240 0 0 16777220 20994 0 0 0 17 0 0 0 9 0 0
/proc/17353/statm: 5635 1224 508 598 0 721 0
Current children cumulated CPU time (s) 129.7
Current children cumulated vsize (KiB) 261480

[startup+132.8 s]
/proc/loadavg: 1.08 1.02 0.94 2/67 17353
/proc/meminfo: memFree=431340/1022884 swapFree=0/0
[pid=17337] ppid=17336 vsize=9212 CPUtime=18.77
/proc/17337/stat : 17337 (aspuncud-full) S 17336 17337 1745 0 -1 4202496 770 221715 2 9 1 0 1755 121 20 0 1 0 119661511 9433088 365 18446744073709551615 4194304 5129932 140735744079264 140735744077328 140459698943070 0 65536 16781316 1115778811 0 0 0 17 0 0 0 2 0 0
/proc/17337/statm: 2303 365 303 229 0 63 0
[pid=17352] ppid=17337 vsize=229728 CPUtime=112.51
/proc/17352/stat : 17352 (unclasp) R 17337 17337 1745 0 -1 4202496 69616 0 2 0 11229 22 0 0 20 0 1 0 119663428 235241472 57001 18446744073709551615 4194304 6012874 140736141560128 140736141559448 4274948 0 0 16781316 16386 0 0 0 17 0 0 0 3 0 0
/proc/17352/statm: 57432 57001 231 444 0 56980 0
[pid=17353] ppid=17337 vsize=22540 CPUtime=0.01
/proc/17353/stat : 17353 (parse.py) S 17337 17337 1745 0 -1 4202496 1402 0 13 0 1 0 0 0 20 0 1 0 119663428 23080960 1224 18446744073709551615 4194304 6642060 140733569683328 140733569681528 140715137214240 0 0 16777220 20994 0 0 0 17 0 0 0 9 0 0
/proc/17353/statm: 5635 1224 508 598 0 721 0
Current children cumulated CPU time (s) 131.29
Current children cumulated vsize (KiB) 261480

[startup+134.4 s]
/proc/loadavg: 1.08 1.02 0.94 2/67 17353
/proc/meminfo: memFree=431340/1022884 swapFree=0/0
[pid=17337] ppid=17336 vsize=9212 CPUtime=18.77
/proc/17337/stat : 17337 (aspuncud-full) S 17336 17337 1745 0 -1 4202496 770 221715 2 9 1 0 1755 121 20 0 1 0 119661511 9433088 365 18446744073709551615 4194304 5129932 140735744079264 140735744077328 140459698943070 0 65536 16781316 1115778811 0 0 0 17 0 0 0 2 0 0
/proc/17337/statm: 2303 365 303 229 0 63 0
[pid=17352] ppid=17337 vsize=229728 CPUtime=114.09
/proc/17352/stat : 17352 (unclasp) R 17337 17337 1745 0 -1 4202496 69616 0 2 0 11387 22 0 0 20 0 1 0 119663428 235241472 57001 18446744073709551615 4194304 6012874 140736141560128 140736141559448 4548913 0 0 16781316 16386 0 0 0 17 0 0 0 3 0 0
/proc/17352/statm: 57432 57001 231 444 0 56980 0
[pid=17353] ppid=17337 vsize=22540 CPUtime=0.01
/proc/17353/stat : 17353 (parse.py) S 17337 17337 1745 0 -1 4202496 1402 0 13 0 1 0 0 0 20 0 1 0 119663428 23080960 1224 18446744073709551615 4194304 6642060 140733569683328 140733569681528 140715137214240 0 0 16777220 20994 0 0 0 17 0 0 0 9 0 0
/proc/17353/statm: 5635 1224 508 598 0 721 0
Current children cumulated CPU time (s) 132.87
Current children cumulated vsize (KiB) 261480

[startup+135.2 s]
/proc/loadavg: 1.08 1.02 0.94 2/67 17353
/proc/meminfo: memFree=431340/1022884 swapFree=0/0
[pid=17337] ppid=17336 vsize=9212 CPUtime=18.77
/proc/17337/stat : 17337 (aspuncud-full) S 17336 17337 1745 0 -1 4202496 770 221715 2 9 1 0 1755 121 20 0 1 0 119661511 9433088 365 18446744073709551615 4194304 5129932 140735744079264 140735744077328 140459698943070 0 65536 16781316 1115778811 0 0 0 17 0 0 0 2 0 0
/proc/17337/statm: 2303 365 303 229 0 63 0
[pid=17352] ppid=17337 vsize=229728 CPUtime=114.88
/proc/17352/stat : 17352 (unclasp) R 17337 17337 1745 0 -1 4202496 69616 0 2 0 11466 22 0 0 20 0 1 0 119663428 235241472 57001 18446744073709551615 4194304 6012874 140736141560128 140736141559192 4498655 0 0 16781316 16386 0 0 0 17 0 0 0 3 0 0
/proc/17352/statm: 57432 57001 231 444 0 56980 0
[pid=17353] ppid=17337 vsize=22540 CPUtime=0.01
/proc/17353/stat : 17353 (parse.py) S 17337 17337 1745 0 -1 4202496 1402 0 13 0 1 0 0 0 20 0 1 0 119663428 23080960 1224 18446744073709551615 4194304 6642060 140733569683328 140733569681448 140715137214240 0 0 16777220 20994 0 0 0 17 0 0 0 9 0 0
/proc/17353/statm: 5635 1224 508 598 0 721 0
Current children cumulated CPU time (s) 133.66
Current children cumulated vsize (KiB) 261480

[startup+135.6 s]
/proc/loadavg: 1.08 1.02 0.94 2/67 17353
/proc/meminfo: memFree=431340/1022884 swapFree=0/0
[pid=17337] ppid=17336 vsize=9212 CPUtime=18.77
/proc/17337/stat : 17337 (aspuncud-full) S 17336 17337 1745 0 -1 4202496 770 221715 2 9 1 0 1755 121 20 0 1 0 119661511 9433088 365 18446744073709551615 4194304 5129932 140735744079264 140735744077328 140459698943070 0 65536 16781316 1115778811 0 0 0 17 0 0 0 2 0 0
/proc/17337/statm: 2303 365 303 229 0 63 0
[pid=17352] ppid=17337 vsize=229728 CPUtime=115.27
/proc/17352/stat : 17352 (unclasp) R 17337 17337 1745 0 -1 4202496 69616 0 2 0 11505 22 0 0 20 0 1 0 119663428 235241472 57001 18446744073709551615 4194304 6012874 140736141560128 140736141559192 4548906 0 0 16781316 16386 0 0 0 17 0 0 0 3 0 0
/proc/17352/statm: 57432 57001 231 444 0 56980 0
[pid=17353] ppid=17337 vsize=22540 CPUtime=0.01
/proc/17353/stat : 17353 (parse.py) S 17337 17337 1745 0 -1 4202496 1402 0 13 0 1 0 0 0 20 0 1 0 119663428 23080960 1224 18446744073709551615 4194304 6642060 140733569683328 140733569681528 140715137214240 0 0 16777220 20994 0 0 0 17 0 0 0 9 0 0
/proc/17353/statm: 5635 1224 508 598 0 721 0
Current children cumulated CPU time (s) 134.05
Current children cumulated vsize (KiB) 261480

[startup+135.701 s]
/proc/loadavg: 1.08 1.02 0.94 2/67 17353
/proc/meminfo: memFree=431340/1022884 swapFree=0/0
[pid=17337] ppid=17336 vsize=9212 CPUtime=18.77
/proc/17337/stat : 17337 (aspuncud-full) S 17336 17337 1745 0 -1 4202496 770 221715 2 9 1 0 1755 121 20 0 1 0 119661511 9433088 365 18446744073709551615 4194304 5129932 140735744079264 140735744077328 140459698943070 0 65536 16781316 1115778811 0 0 0 17 0 0 0 2 0 0
/proc/17337/statm: 2303 365 303 229 0 63 0
[pid=17352] ppid=17337 vsize=229728 CPUtime=115.37
/proc/17352/stat : 17352 (unclasp) R 17337 17337 1745 0 -1 4202496 69623 0 2 0 11513 24 0 0 20 0 1 0 119663428 235241472 42672 18446744073709551615 4194304 6012874 140736141560128 140736141559528 5474154 0 0 16781316 16386 0 0 0 17 0 0 0 3 0 0
/proc/17352/statm: 57432 42672 238 444 0 56980 0
[pid=17353] ppid=17337 vsize=22540 CPUtime=0.01
/proc/17353/stat : 17353 (parse.py) S 17337 17337 1745 0 -1 4202496 1402 0 13 0 1 0 0 0 20 0 1 0 119663428 23080960 1224 18446744073709551615 4194304 6642060 140733569683328 140733569681448 140715137214240 0 0 16777220 20994 0 0 0 17 0 0 0 9 0 0
/proc/17353/statm: 5635 1224 508 598 0 721 0
Current children cumulated CPU time (s) 134.15
Current children cumulated vsize (KiB) 261480

Child status: 0
Real time (s): 135.786
CPU time (s): 134.244
CPU user time (s): 132.72
CPU system time (s): 1.52409
CPU usage (%): 98.8643
Max. virtual memory (cumulated for all children) (KiB): 785512

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 132.72
system time used= 1.52409
maximum resident set size= 652464
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 293794
page faults= 27
swaps= 0
block input operations= 70704
block output operations= 82264
messages sent= 0
messages received= 0
signals received= 0
voluntary context switches= 206
involuntary context switches= 15540

runsolver used 0.256016 second user time and 0.688043 second system time

The end