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/201012081559/p2cudf-user-1.10/cfa6fb1e-8dfb-11df-bfef-00163e46d37a.cudf.upgrades.log.runsolver ./p2cudf-user-1.10 /home/misc2010/data/upgrades//cfa6fb1e-8dfb-11df-bfef-00163e46d37a.cudf /home/misc2010/tmp/201012081559/p2cudf-user-1.10/cfa6fb1e-8dfb-11df-bfef-00163e46d37a.cudf.upgrades.result -notuptodate,-removed,-changed 

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: 2.07 1.55 0.68 4/44 4307
/proc/meminfo: memFree=139840/1048576 swapFree=2080404/2097144
[pid=4307] ppid=4306 vsize=2540 CPUtime=0
/proc/4307/stat : 4307 (p2cudf-user-1.1) R 4306 4307 28116 34820 28116 4194304 141 0 0 0 0 0 0 0 25 0 1 0 891720964 2600960 64 1283457024 134512640 135304128 4288140112 18446744073709551615 4160128990 0 0 0 0 0 0 0 17 0 0 0 0
/proc/4307/statm: 635 64 46 194 0 17 0

[startup+0.190721 s]
/proc/loadavg: 2.07 1.55 0.68 4/44 4307
/proc/meminfo: memFree=139840/1048576 swapFree=2080404/2097144
[pid=4307] ppid=4306 vsize=2576 CPUtime=0
/proc/4307/stat : 4307 (p2cudf-user-1.1) S 4306 4307 28116 34820 28116 4202496 380 0 0 0 0 0 0 0 25 0 1 0 891720964 2637824 274 1283457024 134512640 135304128 4288140112 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/4307/statm: 644 274 233 194 0 30 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2576

[startup+0.210731 s]
/proc/loadavg: 2.07 1.55 0.68 4/44 4307
/proc/meminfo: memFree=139840/1048576 swapFree=2080404/2097144
[pid=4307] ppid=4306 vsize=2576 CPUtime=0
/proc/4307/stat : 4307 (p2cudf-user-1.1) S 4306 4307 28116 34820 28116 4202496 380 0 0 0 0 0 0 0 25 0 1 0 891720964 2637824 274 1283457024 134512640 135304128 4288140112 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/4307/statm: 644 274 233 194 0 30 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2576

[startup+0.310741 s]
/proc/loadavg: 2.07 1.55 0.68 4/44 4307
/proc/meminfo: memFree=139840/1048576 swapFree=2080404/2097144
[pid=4307] ppid=4306 vsize=2576 CPUtime=0
/proc/4307/stat : 4307 (p2cudf-user-1.1) S 4306 4307 28116 34820 28116 4202496 380 0 0 0 0 0 0 0 25 0 1 0 891720964 2637824 274 1283457024 134512640 135304128 4288140112 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/4307/statm: 644 274 233 194 0 30 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2576

[startup+0.7108 s]
/proc/loadavg: 2.07 1.55 0.68 4/44 4307
/proc/meminfo: memFree=139840/1048576 swapFree=2080404/2097144
[pid=4307] ppid=4306 vsize=2576 CPUtime=0
/proc/4307/stat : 4307 (p2cudf-user-1.1) S 4306 4307 28116 34820 28116 4202496 380 0 0 0 0 0 0 0 25 0 1 0 891720964 2637824 274 1283457024 134512640 135304128 4288140112 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/4307/statm: 644 274 233 194 0 30 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 2576

[startup+1.51094 s]
/proc/loadavg: 2.07 1.55 0.68 3/56 4330
/proc/meminfo: memFree=96664/1048576 swapFree=2080404/2097144
[pid=4307] ppid=4306 vsize=2576 CPUtime=0
/proc/4307/stat : 4307 (p2cudf-user-1.1) S 4306 4307 28116 34820 28116 4202496 380 0 0 0 0 0 0 0 25 0 1 0 891720964 2637824 274 1283457024 134512640 135304128 4288140112 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/4307/statm: 644 274 233 194 0 30 0
[pid=4309] ppid=4307 vsize=2572 CPUtime=0.03
/proc/4309/stat : 4309 (p2cudf) S 4307 4307 28116 34820 28116 4202496 391 2993 0 1 0 0 2 1 25 0 1 0 891720965 2633728 281 1283457024 134512640 135304128 4293419136 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/4309/statm: 643 281 241 194 0 29 0
[pid=4321] ppid=4309 vsize=868828 CPUtime=1.47
/proc/4321/stat : 4321 (java) S 4309 4307 28116 34820 28116 4202496 17761 0 1 0 135 12 0 0 25 0 10 0 891720968 889679872 15845 1283457024 134512640 134550932 4289969104 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/4321/statm: 217207 15845 1741 10 0 214297 0
[pid=4321/tid=4322] ppid=4309 vsize=868828 CPUtime=0.7
/proc/4321/task/4322/stat : 4322 (java) R 4309 4307 28116 34820 28116 4202560 11249 0 1 0 60 10 0 0 25 0 10 0 891720968 889679872 15845 1283457024 134512640 134550932 4289969104 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=4321/tid=4323] ppid=4309 vsize=868828 CPUtime=0
/proc/4321/task/4323/stat : 4323 (java) S 4309 4307 28116 34820 28116 4202560 5 0 0 0 0 0 0 0 18 0 10 0 891720970 889679872 15845 1283457024 134512640 134550932 4289969104 18446744073709551615 4294960130 0 0 0 16800975 18446612132549435648 0 0 -1 0 0 0 0
[pid=4321/tid=4324] ppid=4309 vsize=868828 CPUtime=0
/proc/4321/task/4324/stat : 4324 (java) S 4309 4307 28116 34820 28116 4202560 9 0 0 0 0 0 0 0 25 0 10 0 891720970 889679872 15845 1283457024 134512640 134550932 4289969104 18446744073709551615 4294960130 0 4 0 16800975 18446612132549435648 0 0 -1 0 0 0 0
[pid=4321/tid=4325] ppid=4309 vsize=868828 CPUtime=0
/proc/4321/task/4325/stat : 4325 (java) S 4309 4307 28116 34820 28116 4202560 4 0 0 0 0 0 0 0 25 0 10 0 891720970 889679872 15845 1283457024 134512640 134550932 4289969104 18446744073709551615 4294960130 0 4 0 16800975 18446612132549435648 0 0 -1 0 0 0 0
[pid=4321/tid=4326] ppid=4309 vsize=868828 CPUtime=0
/proc/4321/task/4326/stat : 4326 (java) S 4309 4307 28116 34820 28116 4202560 1 0 0 0 0 0 0 0 25 0 10 0 891720973 889679872 15845 1283457024 134512640 134550932 4289969104 18446744073709551615 4294960130 0 4 0 16800975 18446612132549435648 0 0 -1 0 0 0 0
[pid=4321/tid=4327] ppid=4309 vsize=868828 CPUtime=0.17
/proc/4321/task/4327/stat : 4327 (java) S 4309 4307 28116 34820 28116 4202560 835 0 0 0 17 0 0 0 16 0 10 0 891720973 889679872 15845 1283457024 134512640 134550932 4289969104 18446744073709551615 4294960130 0 4 0 16800975 18446612132549435648 0 0 -1 0 0 0 0
[pid=4321/tid=4328] ppid=4309 vsize=868828 CPUtime=0.59
/proc/4321/task/4328/stat : 4328 (java) R 4309 4307 28116 34820 28116 4202560 4562 0 0 0 57 2 0 0 25 0 10 0 891720973 889679872 15845 1283457024 134512640 134550932 4289969104 18446744073709551615 4152039456 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=4321/tid=4329] ppid=4309 vsize=868828 CPUtime=0
/proc/4321/task/4329/stat : 4329 (java) S 4309 4307 28116 34820 28116 4202560 2 0 0 0 0 0 0 0 25 0 10 0 891720973 889679872 15845 1283457024 134512640 134550932 4289969104 18446744073709551615 4294960130 0 4 0 16800975 18446612132549435648 0 0 -1 0 0 0 0
[pid=4321/tid=4330] ppid=4309 vsize=868828 CPUtime=0
/proc/4321/task/4330/stat : 4330 (java) S 4309 4307 28116 34820 28116 4202560 2 0 0 0 0 0 0 0 15 0 10 0 891720973 889679872 15845 1283457024 134512640 134550932 4289969104 18446744073709551615 4294960130 0 4 0 16800975 18446612132549435648 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 1.5
Current children cumulated vsize (KiB) 873976

[startup+3.11153 s]
/proc/loadavg: 2.07 1.55 0.68 4/56 4330
/proc/meminfo: memFree=31604/1048576 swapFree=2080404/2097144
[pid=4307] ppid=4306 vsize=2576 CPUtime=0
/proc/4307/stat : 4307 (p2cudf-user-1.1) S 4306 4307 28116 34820 28116 4202496 380 0 0 0 0 0 0 0 25 0 1 0 891720964 2637824 274 1283457024 134512640 135304128 4288140112 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/4307/statm: 644 274 233 194 0 30 0
[pid=4309] ppid=4307 vsize=2572 CPUtime=0.03
/proc/4309/stat : 4309 (p2cudf) S 4307 4307 28116 34820 28116 4202496 391 2993 0 1 0 0 2 1 25 0 1 0 891720965 2633728 281 1283457024 134512640 135304128 4293419136 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/4309/statm: 643 281 241 194 0 29 0
[pid=4321] ppid=4309 vsize=873048 CPUtime=3.04
/proc/4321/stat : 4321 (java) S 4309 4307 28116 34820 28116 4202496 38576 0 1 0 284 20 0 0 25 0 10 0 891720968 894001152 34035 1283457024 134512640 134550932 4289969104 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/4321/statm: 218262 34035 1769 10 0 215352 0
[pid=4321/tid=4322] ppid=4309 vsize=873048 CPUtime=1.18
/proc/4321/task/4322/stat : 4322 (java) R 4309 4307 28116 34820 28116 4202560 28307 0 1 0 103 15 0 0 25 0 10 0 891720968 894001152 34035 1283457024 134512640 134550932 4289969104 18446744073709551615 4160468819 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=4321/tid=4323] ppid=4309 vsize=873048 CPUtime=0
/proc/4321/task/4323/stat : 4323 (java) S 4309 4307 28116 34820 28116 4202560 5 0 0 0 0 0 0 0 15 0 10 0 891720970 894001152 34035 1283457024 134512640 134550932 4289969104 18446744073709551615 4294960130 0 0 0 16800975 18446612132549435648 0 0 -1 0 0 0 0
[pid=4321/tid=4324] ppid=4309 vsize=873048 CPUtime=0
/proc/4321/task/4324/stat : 4324 (java) S 4309 4307 28116 34820 28116 4202560 9 0 0 0 0 0 0 0 25 0 10 0 891720970 894001152 34035 1283457024 134512640 134550932 4289969104 18446744073709551615 4294960130 0 4 0 16800975 18446612132549435648 0 0 -1 0 0 0 0
[pid=4321/tid=4325] ppid=4309 vsize=873048 CPUtime=0
/proc/4321/task/4325/stat : 4325 (java) S 4309 4307 28116 34820 28116 4202560 4 0 0 0 0 0 0 0 25 0 10 0 891720970 894001152 34035 1283457024 134512640 134550932 4289969104 18446744073709551615 4294960130 0 4 0 16800975 18446612132549435648 0 0 -1 0 0 0 0
[pid=4321/tid=4326] ppid=4309 vsize=873048 CPUtime=0
/proc/4321/task/4326/stat : 4326 (java) S 4309 4307 28116 34820 28116 4202560 1 0 0 0 0 0 0 0 25 0 10 0 891720973 894001152 34035 1283457024 134512640 134550932 4289969104 18446744073709551615 4294960130 0 4 0 16800975 18446612132549435648 0 0 -1 0 0 0 0
[pid=4321/tid=4327] ppid=4309 vsize=873048 CPUtime=1.09
/proc/4321/task/4327/stat : 4327 (java) R 4309 4307 28116 34820 28116 4202560 4561 0 0 0 107 2 0 0 16 0 10 0 891720973 894001152 34035 1283457024 134512640 134550932 4289969104 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=4321/tid=4328] ppid=4309 vsize=873048 CPUtime=0.75
/proc/4321/task/4328/stat : 4328 (java) R 4309 4307 28116 34820 28116 4202560 4593 0 0 0 73 2 0 0 24 0 10 0 891720973 894001152 34035 1283457024 134512640 134550932 4289969104 18446744073709551615 4148451675 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=4321/tid=4329] ppid=4309 vsize=873048 CPUtime=0
/proc/4321/task/4329/stat : 4329 (java) S 4309 4307 28116 34820 28116 4202560 2 0 0 0 0 0 0 0 25 0 10 0 891720973 894001152 34035 1283457024 134512640 134550932 4289969104 18446744073709551615 4294960130 0 4 0 16800975 18446612132549435648 0 0 -1 0 0 0 0
[pid=4321/tid=4330] ppid=4309 vsize=873048 CPUtime=0
/proc/4321/task/4330/stat : 4330 (java) S 4309 4307 28116 34820 28116 4202560 2 0 0 0 0 0 0 0 15 0 10 0 891720973 894001152 34035 1283457024 134512640 134550932 4289969104 18446744073709551615 4294960130 0 4 0 16800975 18446612132549435648 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.07
Current children cumulated vsize (KiB) 878196

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

[startup+3.22105 s]
/proc/loadavg: 2.07 1.55 0.68 4/56 4330
/proc/meminfo: memFree=31604/1048576 swapFree=2080404/2097144
[pid=4307] ppid=4306 vsize=2576 CPUtime=0
/proc/4307/stat : 4307 (p2cudf-user-1.1) S 4306 4307 28116 34820 28116 4202496 380 0 0 0 0 0 0 0 25 0 1 0 891720964 2637824 274 1283457024 134512640 135304128 4288140112 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/4307/statm: 644 274 233 194 0 30 0
[pid=4309] ppid=4307 vsize=2572 CPUtime=0.03
/proc/4309/stat : 4309 (p2cudf) S 4307 4307 28116 34820 28116 4202496 391 2993 0 1 0 0 2 1 25 0 1 0 891720965 2633728 281 1283457024 134512640 135304128 4293419136 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/4309/statm: 643 281 241 194 0 29 0
[pid=4321] ppid=4309 vsize=873048 CPUtime=3.14
/proc/4321/stat : 4321 (java) S 4309 4307 28116 34820 28116 4202496 39734 0 1 0 294 20 0 0 25 0 10 0 891720968 894001152 35193 1283457024 134512640 134550932 4289969104 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/4321/statm: 218262 35193 1769 10 0 215352 0
[pid=4321/tid=4322] ppid=4309 vsize=873048 CPUtime=1.25
/proc/4321/task/4322/stat : 4322 (java) R 4309 4307 28116 34820 28116 4202560 29447 0 1 0 110 15 0 0 25 0 10 0 891720968 894001152 35193 1283457024 134512640 134550932 4289969104 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=4321/tid=4323] ppid=4309 vsize=873048 CPUtime=0
/proc/4321/task/4323/stat : 4323 (java) S 4309 4307 28116 34820 28116 4202560 5 0 0 0 0 0 0 0 15 0 10 0 891720970 894001152 35193 1283457024 134512640 134550932 4289969104 18446744073709551615 4294960130 0 0 0 16800975 18446612132549435648 0 0 -1 0 0 0 0
[pid=4321/tid=4324] ppid=4309 vsize=873048 CPUtime=0
/proc/4321/task/4324/stat : 4324 (java) S 4309 4307 28116 34820 28116 4202560 9 0 0 0 0 0 0 0 25 0 10 0 891720970 894001152 35193 1283457024 134512640 134550932 4289969104 18446744073709551615 4294960130 0 4 0 16800975 18446612132549435648 0 0 -1 0 0 0 0
[pid=4321/tid=4325] ppid=4309 vsize=873048 CPUtime=0
/proc/4321/task/4325/stat : 4325 (java) S 4309 4307 28116 34820 28116 4202560 4 0 0 0 0 0 0 0 25 0 10 0 891720970 894001152 35193 1283457024 134512640 134550932 4289969104 18446744073709551615 4294960130 0 4 0 16800975 18446612132549435648 0 0 -1 0 0 0 0
[pid=4321/tid=4326] ppid=4309 vsize=873048 CPUtime=0
/proc/4321/task/4326/stat : 4326 (java) S 4309 4307 28116 34820 28116 4202560 1 0 0 0 0 0 0 0 25 0 10 0 891720973 894001152 35193 1283457024 134512640 134550932 4289969104 18446744073709551615 4294960130 0 4 0 16800975 18446612132549435648 0 0 -1 0 0 0 0
[pid=4321/tid=4327] ppid=4309 vsize=873048 CPUtime=1.12
/proc/4321/task/4327/stat : 4327 (java) S 4309 4307 28116 34820 28116 4202560 4579 0 0 0 110 2 0 0 15 0 10 0 891720973 894001152 35193 1283457024 134512640 134550932 4289969104 18446744073709551615 4294960130 0 4 0 16800975 18446612132549435648 0 0 -1 0 0 0 0
[pid=4321/tid=4328] ppid=4309 vsize=873048 CPUtime=0.75
/proc/4321/task/4328/stat : 4328 (java) R 4309 4307 28116 34820 28116 4202560 4593 0 0 0 73 2 0 0 24 0 10 0 891720973 894001152 35193 1283457024 134512640 134550932 4289969104 18446744073709551615 4148451675 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=4321/tid=4329] ppid=4309 vsize=873048 CPUtime=0
/proc/4321/task/4329/stat : 4329 (java) S 4309 4307 28116 34820 28116 4202560 2 0 0 0 0 0 0 0 25 0 10 0 891720973 894001152 35193 1283457024 134512640 134550932 4289969104 18446744073709551615 4294960130 0 4 0 16800975 18446612132549435648 0 0 -1 0 0 0 0
[pid=4321/tid=4330] ppid=4309 vsize=873048 CPUtime=0
/proc/4321/task/4330/stat : 4330 (java) S 4309 4307 28116 34820 28116 4202560 2 0 0 0 0 0 0 0 15 0 10 0 891720973 894001152 35193 1283457024 134512640 134550932 4289969104 18446744073709551615 4294960130 0 4 0 16800975 18446612132549435648 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.17
Current children cumulated vsize (KiB) 878196

[startup+4.00494 s]
/proc/loadavg: 2.14 1.58 0.69 4/56 4330
/proc/meminfo: memFree=5856/1048576 swapFree=2080404/2097144
[pid=4307] ppid=4306 vsize=2576 CPUtime=0
/proc/4307/stat : 4307 (p2cudf-user-1.1) S 4306 4307 28116 34820 28116 4202496 380 0 0 0 0 0 0 0 25 0 1 0 891720964 2637824 274 1283457024 134512640 135304128 4288140112 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/4307/statm: 644 274 233 194 0 30 0
[pid=4309] ppid=4307 vsize=2572 CPUtime=0.03
/proc/4309/stat : 4309 (p2cudf) S 4307 4307 28116 34820 28116 4202496 391 2993 0 1 0 0 2 1 25 0 1 0 891720965 2633728 281 1283457024 134512640 135304128 4293419136 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/4309/statm: 643 281 241 194 0 29 0
[pid=4321] ppid=4309 vsize=873372 CPUtime=3.68
/proc/4321/stat : 4321 (java) S 4309 4307 28116 34820 28116 4202496 50170 0 1 0 340 28 0 0 25 0 11 0 891720968 894332928 45629 1283457024 134512640 134550932 4289969104 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/4321/statm: 218343 45629 1771 10 0 215433 0
[pid=4321/tid=4322] ppid=4309 vsize=873372 CPUtime=1.55
/proc/4321/task/4322/stat : 4322 (java) S 4309 4307 28116 34820 28116 4202560 39844 0 1 0 133 22 0 0 25 0 11 0 891720968 894332928 45629 1283457024 134512640 134550932 4289969104 18446744073709551615 4294960130 0 4 0 16800975 18446612132549435648 0 0 -1 0 0 0 0
[pid=4321/tid=4323] ppid=4309 vsize=873372 CPUtime=0
/proc/4321/task/4323/stat : 4323 (java) S 4309 4307 28116 34820 28116 4202560 5 0 0 0 0 0 0 0 15 0 11 0 891720970 894332928 45629 1283457024 134512640 134550932 4289969104 18446744073709551615 4294960130 0 0 0 16800975 18446612132549435648 0 0 -1 0 0 0 0
[pid=4321/tid=4324] ppid=4309 vsize=873372 CPUtime=0
/proc/4321/task/4324/stat : 4324 (java) S 4309 4307 28116 34820 28116 4202560 9 0 0 0 0 0 0 0 25 0 11 0 891720970 894332928 45629 1283457024 134512640 134550932 4289969104 18446744073709551615 4294960130 0 4 0 16800975 18446612132549435648 0 0 -1 0 0 0 0
[pid=4321/tid=4325] ppid=4309 vsize=873372 CPUtime=0
/proc/4321/task/4325/stat : 4325 (java) S 4309 4307 28116 34820 28116 4202560 4 0 0 0 0 0 0 0 25 0 11 0 891720970 894332928 45629 1283457024 134512640 134550932 4289969104 18446744073709551615 4294960130 0 4 0 16800975 18446612132549435648 0 0 -1 0 0 0 0
[pid=4321/tid=4326] ppid=4309 vsize=873372 CPUtime=0
/proc/4321/task/4326/stat : 4326 (java) S 4309 4307 28116 34820 28116 4202560 1 0 0 0 0 0 0 0 25 0 11 0 891720973 894332928 45629 1283457024 134512640 134550932 4289969104 18446744073709551615 4294960130 0 4 0 16800975 18446612132549435648 0 0 -1 0 0 0 0
[pid=4321/tid=4327] ppid=4309 vsize=873372 CPUtime=1.27
/proc/4321/task/4327/stat : 4327 (java) S 4309 4307 28116 34820 28116 4202560 4603 0 0 0 125 2 0 0 16 0 11 0 891720973 894332928 45629 1283457024 134512640 134550932 4289969104 18446744073709551615 4294960130 0 4 0 16800975 18446612132549435648 0 0 -1 0 0 0 0
[pid=4321/tid=4328] ppid=4309 vsize=873372 CPUtime=0.83
/proc/4321/task/4328/stat : 4328 (java) S 4309 4307 28116 34820 28116 4202560 4604 0 0 0 81 2 0 0 24 0 11 0 891720973 894332928 45629 1283457024 134512640 134550932 4289969104 18446744073709551615 4294960130 0 4 0 16800975 18446612132549435648 0 0 -1 0 0 0 0
[pid=4321/tid=4329] ppid=4309 vsize=873372 CPUtime=0
/proc/4321/task/4329/stat : 4329 (java) S 4309 4307 28116 34820 28116 4202560 2 0 0 0 0 0 0 0 25 0 11 0 891720973 894332928 45629 1283457024 134512640 134550932 4289969104 18446744073709551615 4294960130 0 4 0 16800975 18446612132549435648 0 0 -1 0 0 0 0
[pid=4321/tid=4330] ppid=4309 vsize=873372 CPUtime=0
/proc/4321/task/4330/stat : 4330 (java) S 4309 4307 28116 34820 28116 4202560 2 0 0 0 0 0 0 0 15 0 11 0 891720973 894332928 45629 1283457024 134512640 134550932 4289969104 18446744073709551615 4294960130 0 4 0 16800975 18446612132549435648 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.71
Current children cumulated vsize (KiB) 878520

[startup+4.20497 s]
/proc/loadavg: 2.14 1.58 0.69 4/56 4330
/proc/meminfo: memFree=5856/1048576 swapFree=2080404/2097144
[pid=4307] ppid=4306 vsize=2576 CPUtime=0
/proc/4307/stat : 4307 (p2cudf-user-1.1) S 4306 4307 28116 34820 28116 4202496 380 0 0 0 0 0 0 0 25 0 1 0 891720964 2637824 274 1283457024 134512640 135304128 4288140112 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/4307/statm: 644 274 233 194 0 30 0
[pid=4309] ppid=4307 vsize=2572 CPUtime=0.03
/proc/4309/stat : 4309 (p2cudf) S 4307 4307 28116 34820 28116 4202496 391 2993 0 1 0 0 2 1 25 0 1 0 891720965 2633728 281 1283457024 134512640 135304128 4293419136 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/4309/statm: 643 281 241 194 0 29 0
[pid=4321] ppid=4309 vsize=873372 CPUtime=3.68
/proc/4321/stat : 4321 (java) S 4309 4307 28116 34820 28116 4202496 50170 0 1 0 340 28 0 0 25 0 11 0 891720968 894332928 45629 1283457024 134512640 134550932 4289969104 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/4321/statm: 218343 45629 1771 10 0 215433 0
[pid=4321/tid=4322] ppid=4309 vsize=873372 CPUtime=1.55
/proc/4321/task/4322/stat : 4322 (java) S 4309 4307 28116 34820 28116 4202560 39844 0 1 0 133 22 0 0 25 0 11 0 891720968 894332928 45629 1283457024 134512640 134550932 4289969104 18446744073709551615 4294960130 0 4 0 16800975 18446612132549435648 0 0 -1 0 0 0 0
[pid=4321/tid=4323] ppid=4309 vsize=873372 CPUtime=0
/proc/4321/task/4323/stat : 4323 (java) S 4309 4307 28116 34820 28116 4202560 5 0 0 0 0 0 0 0 15 0 11 0 891720970 894332928 45629 1283457024 134512640 134550932 4289969104 18446744073709551615 4294960130 0 0 0 16800975 18446612132549435648 0 0 -1 0 0 0 0
[pid=4321/tid=4324] ppid=4309 vsize=873372 CPUtime=0
/proc/4321/task/4324/stat : 4324 (java) S 4309 4307 28116 34820 28116 4202560 9 0 0 0 0 0 0 0 25 0 11 0 891720970 894332928 45629 1283457024 134512640 134550932 4289969104 18446744073709551615 4294960130 0 4 0 16800975 18446612132549435648 0 0 -1 0 0 0 0
[pid=4321/tid=4325] ppid=4309 vsize=873372 CPUtime=0
/proc/4321/task/4325/stat : 4325 (java) S 4309 4307 28116 34820 28116 4202560 4 0 0 0 0 0 0 0 25 0 11 0 891720970 894332928 45629 1283457024 134512640 134550932 4289969104 18446744073709551615 4294960130 0 4 0 16800975 18446612132549435648 0 0 -1 0 0 0 0
[pid=4321/tid=4326] ppid=4309 vsize=873372 CPUtime=0
/proc/4321/task/4326/stat : 4326 (java) S 4309 4307 28116 34820 28116 4202560 1 0 0 0 0 0 0 0 25 0 11 0 891720973 894332928 45629 1283457024 134512640 134550932 4289969104 18446744073709551615 4294960130 0 4 0 16800975 18446612132549435648 0 0 -1 0 0 0 0
[pid=4321/tid=4327] ppid=4309 vsize=873372 CPUtime=1.27
/proc/4321/task/4327/stat : 4327 (java) S 4309 4307 28116 34820 28116 4202560 4603 0 0 0 125 2 0 0 16 0 11 0 891720973 894332928 45629 1283457024 134512640 134550932 4289969104 18446744073709551615 4294960130 0 4 0 16800975 18446612132549435648 0 0 -1 0 0 0 0
[pid=4321/tid=4328] ppid=4309 vsize=873372 CPUtime=0.83
/proc/4321/task/4328/stat : 4328 (java) S 4309 4307 28116 34820 28116 4202560 4604 0 0 0 81 2 0 0 24 0 11 0 891720973 894332928 45629 1283457024 134512640 134550932 4289969104 18446744073709551615 4294960130 0 4 0 16800975 18446612132549435648 0 0 -1 0 0 0 0
[pid=4321/tid=4329] ppid=4309 vsize=873372 CPUtime=0
/proc/4321/task/4329/stat : 4329 (java) S 4309 4307 28116 34820 28116 4202560 2 0 0 0 0 0 0 0 25 0 11 0 891720973 894332928 45629 1283457024 134512640 134550932 4289969104 18446744073709551615 4294960130 0 4 0 16800975 18446612132549435648 0 0 -1 0 0 0 0
[pid=4321/tid=4330] ppid=4309 vsize=873372 CPUtime=0
/proc/4321/task/4330/stat : 4330 (java) S 4309 4307 28116 34820 28116 4202560 2 0 0 0 0 0 0 0 15 0 11 0 891720973 894332928 45629 1283457024 134512640 134550932 4289969104 18446744073709551615 4294960130 0 4 0 16800975 18446612132549435648 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.71
Current children cumulated vsize (KiB) 878520

Child status: 0
Real time (s): 4.29122
CPU time (s): 3.74423
CPU user time (s): 3.42421
CPU system time (s): 0.32002
CPU usage (%): 87.2533
Max. virtual memory (cumulated for all children) (KiB): 879816

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 3.42421
system time used= 0.32002
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 53958
page faults= 2
swaps= 0
block input operations= 0
block output operations= 0
messages sent= 0
messages received= 0
signals received= 0
voluntary context switches= 390
involuntary context switches= 417

runsolver used 0 second user time and 0.012 second system time

The end