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 150 -d 10 -w /tmp/misc2012/2012-09-02-17:21/basic/aspuncud-basic-1.7/paranoid-size/install/rand83.cudf.log.runsolver /home/competition/aspuncud-basic-1.7/aspuncud-basic /home/competition/data/install/rand83.cudf /tmp/misc2012/2012-09-02-17:21/basic/aspuncud-basic-1.7/paranoid-size/install/rand83.cudf.result -count(removed),-sum(solution,installedsize),-count(changed) 

Enforcing CPUTime limit (soft limit, will send signal-name then SIGKILL): 150 seconds
Enforcing CPUTime limit (hard limit, will send SIGXCPU): 180 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.04 0.97 0.87 2/65 7357
/proc/meminfo: memFree=422156/1022884 swapFree=0/0
[pid=7357] ppid=7356 vsize=9204 CPUtime=0
/proc/7357/stat : 7357 (aspuncud-basic) S 7356 7357 32685 0 -1 4202496 430 0 0 0 0 0 0 0 20 0 1 0 37140719 9424896 331 18446744073709551615 4194304 5129932 140734570338480 140734570335944 140582986610464 0 0 16781316 65536 0 0 0 17 0 0 0 0 0 0
/proc/7357/statm: 2301 331 272 229 0 61 0

[startup+0.125228 s]
/proc/loadavg: 1.04 0.97 0.87 2/65 7357
/proc/meminfo: memFree=422156/1022884 swapFree=0/0
[pid=7357] ppid=7356 vsize=9212 CPUtime=0.03
/proc/7357/stat : 7357 (aspuncud-basic) S 7356 7357 32685 0 -1 4202496 698 2808 0 0 0 0 2 1 20 0 1 0 37140719 9433088 364 18446744073709551615 4194304 5129932 140734570338480 140734570337136 140582986466398 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/7357/statm: 2303 364 303 229 0 63 0
Current children cumulated CPU time (s) 0.03
Current children cumulated vsize (KiB) 9212

[startup+0.200341 s]
/proc/loadavg: 1.04 0.97 0.87 2/65 7357
/proc/meminfo: memFree=422156/1022884 swapFree=0/0
[pid=7357] ppid=7356 vsize=9212 CPUtime=0.03
/proc/7357/stat : 7357 (aspuncud-basic) S 7356 7357 32685 0 -1 4202496 698 2808 0 0 0 0 2 1 20 0 1 0 37140719 9433088 364 18446744073709551615 4194304 5129932 140734570338480 140734570337136 140582986466398 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/7357/statm: 2303 364 303 229 0 63 0
Current children cumulated CPU time (s) 0.03
Current children cumulated vsize (KiB) 9212

[startup+0.300363 s]
/proc/loadavg: 1.04 0.97 0.87 2/65 7357
/proc/meminfo: memFree=422156/1022884 swapFree=0/0
[pid=7357] ppid=7356 vsize=9212 CPUtime=0.03
/proc/7357/stat : 7357 (aspuncud-basic) S 7356 7357 32685 0 -1 4202496 698 2808 0 0 0 0 2 1 20 0 1 0 37140719 9433088 364 18446744073709551615 4194304 5129932 140734570338480 140734570337136 140582986466398 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/7357/statm: 2303 364 303 229 0 63 0
Current children cumulated CPU time (s) 0.03
Current children cumulated vsize (KiB) 9212

[startup+0.70024 s]
/proc/loadavg: 1.04 0.97 0.87 2/65 7357
/proc/meminfo: memFree=422156/1022884 swapFree=0/0
[pid=7357] ppid=7356 vsize=9212 CPUtime=0.03
/proc/7357/stat : 7357 (aspuncud-basic) S 7356 7357 32685 0 -1 4202496 698 2808 0 0 0 0 2 1 20 0 1 0 37140719 9433088 364 18446744073709551615 4194304 5129932 140734570338480 140734570337136 140582986466398 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/7357/statm: 2303 364 303 229 0 63 0
Current children cumulated CPU time (s) 0.03
Current children cumulated vsize (KiB) 9212

[startup+1.50031 s]
/proc/loadavg: 1.04 0.97 0.87 2/67 7370
/proc/meminfo: memFree=397580/1022884 swapFree=0/0
[pid=7357] ppid=7356 vsize=9212 CPUtime=0.03
/proc/7357/stat : 7357 (aspuncud-basic) S 7356 7357 32685 0 -1 4202496 698 2808 0 0 0 0 2 1 20 0 1 0 37140719 9433088 364 18446744073709551615 4194304 5129932 140734570338480 140734570337136 140582986466398 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/7357/statm: 2303 364 303 229 0 63 0
[pid=7370] ppid=7357 vsize=50076 CPUtime=1.44
/proc/7370/stat : 7370 (cudf2lp) R 7357 7357 32685 0 -1 4202496 11315 0 0 0 139 5 0 0 20 0 1 0 37140722 51277824 9581 18446744073709551615 4194304 5690517 140733910357280 140733910353448 4960664 0 0 16781316 0 0 0 0 17 0 0 0 1 0 0
/proc/7370/statm: 12519 9581 160 366 0 12150 0
Current children cumulated CPU time (s) 1.47
Current children cumulated vsize (KiB) 59288

[startup+3.10033 s]
/proc/loadavg: 1.04 0.97 0.87 2/67 7370
/proc/meminfo: memFree=376252/1022884 swapFree=0/0
[pid=7357] ppid=7356 vsize=9212 CPUtime=0.03
/proc/7357/stat : 7357 (aspuncud-basic) S 7356 7357 32685 0 -1 4202496 698 2808 0 0 0 0 2 1 20 0 1 0 37140719 9433088 364 18446744073709551615 4194304 5129932 140734570338480 140734570337136 140582986466398 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/7357/statm: 2303 364 303 229 0 63 0
[pid=7370] ppid=7357 vsize=93028 CPUtime=3.03
/proc/7370/stat : 7370 (cudf2lp) R 7357 7357 32685 0 -1 4202496 26430 0 0 0 291 12 0 0 20 0 1 0 37140722 95260672 19702 18446744073709551615 4194304 5690517 140733910357280 140733910354920 4448896 0 0 16781316 0 0 0 0 17 0 0 0 1 0 0
/proc/7370/statm: 23257 19702 160 366 0 22888 0
Current children cumulated CPU time (s) 3.06
Current children cumulated vsize (KiB) 102240

[startup+6.30032 s]
/proc/loadavg: 1.03 0.97 0.87 2/67 7371
/proc/meminfo: memFree=401052/1022884 swapFree=0/0
[pid=7357] ppid=7356 vsize=9212 CPUtime=5.13
/proc/7357/stat : 7357 (aspuncud-basic) S 7356 7357 32685 0 -1 4202496 726 42129 0 0 0 0 485 28 20 0 1 0 37140719 9433088 364 18446744073709551615 4194304 5129932 140734570338480 140734570337136 140582986466398 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/7357/statm: 2303 364 303 229 0 63 0
[pid=7371] ppid=7357 vsize=31148 CPUtime=1.11
/proc/7371/stat : 7371 (gringo) R 7357 7357 32685 0 -1 4202496 8781 0 0 0 106 5 0 0 20 0 1 0 37141237 31895552 6671 18446744073709551615 4194304 6531320 140736699154800 140736699151416 5562091 0 0 16781316 16386 0 0 0 17 0 0 0 0 0 0
/proc/7371/statm: 7787 6671 259 571 0 7208 0
Current children cumulated CPU time (s) 6.24
Current children cumulated vsize (KiB) 40360

[startup+12.7003 s]
/proc/loadavg: 1.03 0.97 0.87 2/67 7371
/proc/meminfo: memFree=36120/1022884 swapFree=0/0
[pid=7357] ppid=7356 vsize=9212 CPUtime=5.13
/proc/7357/stat : 7357 (aspuncud-basic) S 7356 7357 32685 0 -1 4202496 726 42129 0 0 0 0 485 28 20 0 1 0 37140719 9433088 364 18446744073709551615 4194304 5129932 140734570338480 140734570337136 140582986466398 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/7357/statm: 2303 364 303 229 0 63 0
[pid=7371] ppid=7357 vsize=446660 CPUtime=7.45
/proc/7371/stat : 7371 (gringo) R 7357 7357 32685 0 -1 4202496 106655 0 0 0 701 44 0 0 20 0 1 0 37141237 457379840 97374 18446744073709551615 4194304 6531320 140736699154800 140736699150728 4598432 0 0 16781316 16386 0 0 0 17 0 0 0 0 0 0
/proc/7371/statm: 111665 97374 283 571 0 111086 0
Current children cumulated CPU time (s) 12.58
Current children cumulated vsize (KiB) 455872

[startup+25.5004 s]
/proc/loadavg: 1.02 0.97 0.87 2/68 7373
/proc/meminfo: memFree=280596/1022884 swapFree=0/0
[pid=7357] ppid=7356 vsize=9212 CPUtime=13.61
/proc/7357/stat : 7357 (aspuncud-basic) S 7356 7357 32685 0 -1 4202496 769 154764 0 0 0 0 1272 89 20 0 1 0 37140719 9433088 364 18446744073709551615 4194304 5129932 140734570338480 140734570336544 140582986466398 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/7357/statm: 2303 364 303 229 0 63 0
[pid=7372] ppid=7357 vsize=142428 CPUtime=11.6
/proc/7372/stat : 7372 (unclasp) R 7357 7357 32685 0 -1 4202496 41309 0 0 0 1145 15 0 0 20 0 1 0 37142097 145846272 35105 18446744073709551615 4194304 6012874 140734310065696 140734310065016 4548474 0 0 16781316 16386 0 0 0 17 0 0 0 0 0 0
/proc/7372/statm: 35607 35105 230 444 0 35155 0
[pid=7373] ppid=7357 vsize=22324 CPUtime=0.01
/proc/7373/stat : 7373 (parse.py) S 7357 7357 32685 0 -1 4202496 1381 0 0 0 1 0 0 0 20 0 1 0 37142097 22859776 1190 18446744073709551615 4194304 6642060 140736646852736 140736646850856 140013135963936 0 0 16777220 20994 0 0 0 17 0 0 0 0 0 0
/proc/7373/statm: 5581 1190 508 598 0 667 0
Current children cumulated CPU time (s) 25.22
Current children cumulated vsize (KiB) 173964

[startup+51.1004 s]
/proc/loadavg: 1.01 0.97 0.87 2/68 7373
/proc/meminfo: memFree=280472/1022884 swapFree=0/0
[pid=7357] ppid=7356 vsize=9212 CPUtime=13.61
/proc/7357/stat : 7357 (aspuncud-basic) S 7356 7357 32685 0 -1 4202496 769 154764 0 0 0 0 1272 89 20 0 1 0 37140719 9433088 364 18446744073709551615 4194304 5129932 140734570338480 140734570336544 140582986466398 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/7357/statm: 2303 364 303 229 0 63 0
[pid=7372] ppid=7357 vsize=142428 CPUtime=37.03
/proc/7372/stat : 7372 (unclasp) R 7357 7357 32685 0 -1 4202496 41326 0 0 0 3687 16 0 0 20 0 1 0 37142097 145846272 35122 18446744073709551615 4194304 6012874 140734310065696 140734310065016 4532216 0 0 16781316 16386 0 0 0 17 0 0 0 0 0 0
/proc/7372/statm: 35607 35122 230 444 0 35155 0
[pid=7373] ppid=7357 vsize=22324 CPUtime=0.01
/proc/7373/stat : 7373 (parse.py) S 7357 7357 32685 0 -1 4202496 1381 0 0 0 1 0 0 0 20 0 1 0 37142097 22859776 1190 18446744073709551615 4194304 6642060 140736646852736 140736646850856 140013135963936 0 0 16777220 20994 0 0 0 17 0 0 0 0 0 0
/proc/7373/statm: 5581 1190 508 598 0 667 0
Current children cumulated CPU time (s) 50.65
Current children cumulated vsize (KiB) 173964

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

[startup+51.2004 s]
/proc/loadavg: 1.01 0.97 0.87 2/68 7373
/proc/meminfo: memFree=280472/1022884 swapFree=0/0
[pid=7357] ppid=7356 vsize=9212 CPUtime=13.61
/proc/7357/stat : 7357 (aspuncud-basic) S 7356 7357 32685 0 -1 4202496 769 154764 0 0 0 0 1272 89 20 0 1 0 37140719 9433088 364 18446744073709551615 4194304 5129932 140734570338480 140734570336544 140582986466398 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/7357/statm: 2303 364 303 229 0 63 0
[pid=7372] ppid=7357 vsize=142428 CPUtime=37.13
/proc/7372/stat : 7372 (unclasp) R 7357 7357 32685 0 -1 4202496 41326 0 0 0 3697 16 0 0 20 0 1 0 37142097 145846272 35122 18446744073709551615 4194304 6012874 140734310065696 140734310065016 4548102 0 0 16781316 16386 0 0 0 17 0 0 0 0 0 0
/proc/7372/statm: 35607 35122 230 444 0 35155 0
[pid=7373] ppid=7357 vsize=22324 CPUtime=0.01
/proc/7373/stat : 7373 (parse.py) S 7357 7357 32685 0 -1 4202496 1381 0 0 0 1 0 0 0 20 0 1 0 37142097 22859776 1190 18446744073709551615 4194304 6642060 140736646852736 140736646850856 140013135963936 0 0 16777220 20994 0 0 0 17 0 0 0 0 0 0
/proc/7373/statm: 5581 1190 508 598 0 667 0
Current children cumulated CPU time (s) 50.75
Current children cumulated vsize (KiB) 173964

[startup+64.0003 s]
/proc/loadavg: 1.01 0.97 0.87 2/68 7373
/proc/meminfo: memFree=280472/1022884 swapFree=0/0
[pid=7357] ppid=7356 vsize=9212 CPUtime=13.61
/proc/7357/stat : 7357 (aspuncud-basic) S 7356 7357 32685 0 -1 4202496 769 154764 0 0 0 0 1272 89 20 0 1 0 37140719 9433088 364 18446744073709551615 4194304 5129932 140734570338480 140734570336544 140582986466398 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/7357/statm: 2303 364 303 229 0 63 0
[pid=7372] ppid=7357 vsize=142428 CPUtime=49.85
/proc/7372/stat : 7372 (unclasp) R 7357 7357 32685 0 -1 4202496 41327 0 0 0 4969 16 0 0 20 0 1 0 37142097 145846272 35123 18446744073709551615 4194304 6012874 140734310065696 140734310065016 4498571 0 0 16781316 16386 0 0 0 17 0 0 0 0 0 0
/proc/7372/statm: 35607 35123 231 444 0 35155 0
[pid=7373] ppid=7357 vsize=22324 CPUtime=0.01
/proc/7373/stat : 7373 (parse.py) S 7357 7357 32685 0 -1 4202496 1381 0 0 0 1 0 0 0 20 0 1 0 37142097 22859776 1190 18446744073709551615 4194304 6642060 140736646852736 140736646850856 140013135963936 0 0 16777220 20994 0 0 0 17 0 0 0 0 0 0
/proc/7373/statm: 5581 1190 508 598 0 667 0
Current children cumulated CPU time (s) 63.47
Current children cumulated vsize (KiB) 173964

[startup+70.4003 s]
/proc/loadavg: 1.01 0.97 0.87 2/68 7373
/proc/meminfo: memFree=280472/1022884 swapFree=0/0
[pid=7357] ppid=7356 vsize=9212 CPUtime=13.61
/proc/7357/stat : 7357 (aspuncud-basic) S 7356 7357 32685 0 -1 4202496 769 154764 0 0 0 0 1272 89 20 0 1 0 37140719 9433088 364 18446744073709551615 4194304 5129932 140734570338480 140734570336544 140582986466398 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/7357/statm: 2303 364 303 229 0 63 0
[pid=7372] ppid=7357 vsize=142428 CPUtime=56.22
/proc/7372/stat : 7372 (unclasp) R 7357 7357 32685 0 -1 4202496 41327 0 0 0 5606 16 0 0 20 0 1 0 37142097 145846272 35123 18446744073709551615 4194304 6012874 140734310065696 140734310065016 4495024 0 0 16781316 16386 0 0 0 17 0 0 0 0 0 0
/proc/7372/statm: 35607 35123 231 444 0 35155 0
[pid=7373] ppid=7357 vsize=22324 CPUtime=0.01
/proc/7373/stat : 7373 (parse.py) S 7357 7357 32685 0 -1 4202496 1381 0 0 0 1 0 0 0 20 0 1 0 37142097 22859776 1190 18446744073709551615 4194304 6642060 140736646852736 140736646850856 140013135963936 0 0 16777220 20994 0 0 0 17 0 0 0 0 0 0
/proc/7373/statm: 5581 1190 508 598 0 667 0
Current children cumulated CPU time (s) 69.84
Current children cumulated vsize (KiB) 173964

[startup+72.0003 s]
/proc/loadavg: 1.01 0.97 0.87 2/68 7373
/proc/meminfo: memFree=280472/1022884 swapFree=0/0
[pid=7357] ppid=7356 vsize=9212 CPUtime=13.61
/proc/7357/stat : 7357 (aspuncud-basic) S 7356 7357 32685 0 -1 4202496 769 154764 0 0 0 0 1272 89 20 0 1 0 37140719 9433088 364 18446744073709551615 4194304 5129932 140734570338480 140734570336544 140582986466398 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/7357/statm: 2303 364 303 229 0 63 0
[pid=7372] ppid=7357 vsize=142428 CPUtime=57.8
/proc/7372/stat : 7372 (unclasp) R 7357 7357 32685 0 -1 4202496 41327 0 0 0 5764 16 0 0 20 0 1 0 37142097 145846272 35123 18446744073709551615 4194304 6012874 140734310065696 140734310065016 4548913 0 0 16781316 16386 0 0 0 17 0 0 0 0 0 0
/proc/7372/statm: 35607 35123 231 444 0 35155 0
[pid=7373] ppid=7357 vsize=22324 CPUtime=0.01
/proc/7373/stat : 7373 (parse.py) S 7357 7357 32685 0 -1 4202496 1381 0 0 0 1 0 0 0 20 0 1 0 37142097 22859776 1190 18446744073709551615 4194304 6642060 140736646852736 140736646850856 140013135963936 0 0 16777220 20994 0 0 0 17 0 0 0 0 0 0
/proc/7373/statm: 5581 1190 508 598 0 667 0
Current children cumulated CPU time (s) 71.42
Current children cumulated vsize (KiB) 173964

[startup+72.8003 s]
/proc/loadavg: 1.01 0.97 0.87 2/68 7373
/proc/meminfo: memFree=280472/1022884 swapFree=0/0
[pid=7357] ppid=7356 vsize=9212 CPUtime=13.61
/proc/7357/stat : 7357 (aspuncud-basic) S 7356 7357 32685 0 -1 4202496 769 154764 0 0 0 0 1272 89 20 0 1 0 37140719 9433088 364 18446744073709551615 4194304 5129932 140734570338480 140734570336544 140582986466398 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/7357/statm: 2303 364 303 229 0 63 0
[pid=7372] ppid=7357 vsize=142428 CPUtime=58.6
/proc/7372/stat : 7372 (unclasp) R 7357 7357 32685 0 -1 4202496 41327 0 0 0 5844 16 0 0 20 0 1 0 37142097 145846272 35123 18446744073709551615 4194304 6012874 140734310065696 140734310065016 4532216 0 0 16781316 16386 0 0 0 17 0 0 0 0 0 0
/proc/7372/statm: 35607 35123 231 444 0 35155 0
[pid=7373] ppid=7357 vsize=22324 CPUtime=0.01
/proc/7373/stat : 7373 (parse.py) S 7357 7357 32685 0 -1 4202496 1381 0 0 0 1 0 0 0 20 0 1 0 37142097 22859776 1190 18446744073709551615 4194304 6642060 140736646852736 140736646850856 140013135963936 0 0 16777220 20994 0 0 0 17 0 0 0 0 0 0
/proc/7373/statm: 5581 1190 508 598 0 667 0
Current children cumulated CPU time (s) 72.22
Current children cumulated vsize (KiB) 173964

[startup+73.6003 s]
/proc/loadavg: 1.01 0.97 0.87 2/68 7373
/proc/meminfo: memFree=280472/1022884 swapFree=0/0
[pid=7357] ppid=7356 vsize=9212 CPUtime=13.61
/proc/7357/stat : 7357 (aspuncud-basic) S 7356 7357 32685 0 -1 4202496 769 154764 0 0 0 0 1272 89 20 0 1 0 37140719 9433088 364 18446744073709551615 4194304 5129932 140734570338480 140734570336544 140582986466398 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/7357/statm: 2303 364 303 229 0 63 0
[pid=7372] ppid=7357 vsize=142428 CPUtime=59.4
/proc/7372/stat : 7372 (unclasp) R 7357 7357 32685 0 -1 4202496 41327 0 0 0 5923 17 0 0 20 0 1 0 37142097 145846272 35123 18446744073709551615 4194304 6012874 140734310065696 140734310065016 4494997 0 0 16781316 16386 0 0 0 17 0 0 0 0 0 0
/proc/7372/statm: 35607 35123 231 444 0 35155 0
[pid=7373] ppid=7357 vsize=22324 CPUtime=0.01
/proc/7373/stat : 7373 (parse.py) S 7357 7357 32685 0 -1 4202496 1381 0 0 0 1 0 0 0 20 0 1 0 37142097 22859776 1190 18446744073709551615 4194304 6642060 140736646852736 140736646850856 140013135963936 0 0 16777220 20994 0 0 0 17 0 0 0 0 0 0
/proc/7373/statm: 5581 1190 508 598 0 667 0
Current children cumulated CPU time (s) 73.02
Current children cumulated vsize (KiB) 173964

[startup+73.8077 s]
/proc/loadavg: 1.01 0.97 0.87 2/68 7373
/proc/meminfo: memFree=280472/1022884 swapFree=0/0
[pid=7357] ppid=7356 vsize=9212 CPUtime=13.61
/proc/7357/stat : 7357 (aspuncud-basic) S 7356 7357 32685 0 -1 4202496 769 154764 0 0 0 0 1272 89 20 0 1 0 37140719 9433088 364 18446744073709551615 4194304 5129932 140734570338480 140734570336544 140582986466398 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/7357/statm: 2303 364 303 229 0 63 0
[pid=7372] ppid=7357 vsize=142428 CPUtime=59.6
/proc/7372/stat : 7372 (unclasp) R 7357 7357 32685 0 -1 4202496 41327 0 0 0 5943 17 0 0 20 0 1 0 37142097 145846272 35123 18446744073709551615 4194304 6012874 140734310065696 140734310065016 4300185 0 0 16781316 16386 0 0 0 17 0 0 0 0 0 0
/proc/7372/statm: 35607 35123 231 444 0 35155 0
[pid=7373] ppid=7357 vsize=22324 CPUtime=0.01
/proc/7373/stat : 7373 (parse.py) S 7357 7357 32685 0 -1 4202496 1381 0 0 0 1 0 0 0 20 0 1 0 37142097 22859776 1190 18446744073709551615 4194304 6642060 140736646852736 140736646850936 140013135963936 0 0 16777220 20994 0 0 0 17 0 0 0 0 0 0
/proc/7373/statm: 5581 1190 508 598 0 667 0
Current children cumulated CPU time (s) 73.22
Current children cumulated vsize (KiB) 173964

[startup+73.9008 s]
/proc/loadavg: 1.01 0.97 0.87 2/68 7373
/proc/meminfo: memFree=280472/1022884 swapFree=0/0
[pid=7357] ppid=7356 vsize=9212 CPUtime=13.61
/proc/7357/stat : 7357 (aspuncud-basic) S 7356 7357 32685 0 -1 4202496 769 154764 0 0 0 0 1272 89 20 0 1 0 37140719 9433088 364 18446744073709551615 4194304 5129932 140734570338480 140734570336544 140582986466398 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/7357/statm: 2303 364 303 229 0 63 0
[pid=7372] ppid=7357 vsize=142428 CPUtime=59.69
/proc/7372/stat : 7372 (unclasp) R 7357 7357 32685 0 -1 4202496 41333 0 0 0 5952 17 0 0 20 0 1 0 37142097 145846272 31033 18446744073709551615 4194304 6012874 140734310065696 140734310065112 5474154 0 0 16781316 16386 0 0 0 17 0 0 0 0 0 0
/proc/7372/statm: 35607 31033 237 444 0 35155 0
[pid=7373] ppid=7357 vsize=22324 CPUtime=0.01
/proc/7373/stat : 7373 (parse.py) S 7357 7357 32685 0 -1 4202496 1381 0 0 0 1 0 0 0 20 0 1 0 37142097 22859776 1190 18446744073709551615 4194304 6642060 140736646852736 140736646850936 140013135963936 0 0 16777220 20994 0 0 0 17 0 0 0 0 0 0
/proc/7373/statm: 5581 1190 508 598 0 667 0
Current children cumulated CPU time (s) 73.31
Current children cumulated vsize (KiB) 173964

Child status: 0
Real time (s): 73.9614
CPU time (s): 73.4006
CPU user time (s): 72.2725
CPU system time (s): 1.12807
CPU usage (%): 99.2418
Max. virtual memory (cumulated for all children) (KiB): 482324

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 72.2725
system time used= 1.12807
maximum resident set size= 413400
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 198536
page faults= 1
swaps= 0
block input operations= 64
block output operations= 52624
messages sent= 0
messages received= 0
signals received= 0
voluntary context switches= 119
involuntary context switches= 1231

runsolver used 0.176011 second user time and 0.312019 second system time

The end