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/201012061533/p2cudf-paranoid-1.9/rand165.sarge.cudf.sarge.log.runsolver ./p2cudf-paranoid-1.9 /home/misc2010/data/icse/sarge/rand165.sarge.cudf /home/misc2010/tmp/201012061533/p2cudf-paranoid-1.9/rand165.sarge.cudf.sarge.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.27 1.13 1.08 5/47 7115
/proc/meminfo: memFree=811456/1048576 swapFree=2078740/2097144
[pid=7113] ppid=7112 vsize=2568 CPUtime=0
/proc/7113/stat : 7113 (p2cudf-paranoid) S 7112 7113 2059 34821 2220 4202496 378 0 0 0 0 0 0 0 22 0 1 0 874851066 2629632 273 1283457024 134512640 135304128 4287056528 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/7113/statm: 642 273 233 194 0 28 0
[pid=7114] ppid=7113 vsize=2572 CPUtime=0
/proc/7114/stat : 7114 (p2cudf) S 7113 7113 2059 34821 2220 4202496 355 0 0 0 0 0 0 0 25 0 1 0 874851066 2633728 274 1283457024 134512640 135304128 4288220096 18446744073709551615 4294960130 0 0 4 65536 18446744071564457842 0 0 17 0 0 0 0
/proc/7114/statm: 643 274 234 194 0 29 0
[pid=7115] ppid=7114 vsize=2572 CPUtime=0
/proc/7115/stat : 7115 (p2cudf) R 7114 7113 2059 34821 2220 4202560 92 0 0 0 0 0 0 0 25 0 1 0 874851067 2633728 116 1283457024 134512640 135304128 4288220096 18446744073709551615 4294960130 0 65538 0 65538 0 0 0 17 0 0 0 0
/proc/7115/statm: 643 116 75 194 0 29 0
[pid=7116] ppid=7115 vsize=2572 CPUtime=0
/proc/7116/stat : 7116 (p2cudf) R 7115 7113 2059 34821 2220 4202560 0 0 0 0 0 0 0 0 25 0 1 0 874851067 2633728 41 1283457024 134512640 135304128 4288220096 18446744073709551615 4294960130 0 65538 0 65538 0 0 0 17 0 0 0 0
/proc/7116/statm: 643 41 0 194 0 29 0

[startup+0.117908 s]
/proc/loadavg: 1.27 1.13 1.08 5/47 7115
/proc/meminfo: memFree=811456/1048576 swapFree=2078740/2097144
[pid=7113] ppid=7112 vsize=2568 CPUtime=0
/proc/7113/stat : 7113 (p2cudf-paranoid) S 7112 7113 2059 34821 2220 4202496 378 0 0 0 0 0 0 0 22 0 1 0 874851066 2629632 273 1283457024 134512640 135304128 4287056528 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/7113/statm: 642 273 233 194 0 28 0
[pid=7114] ppid=7113 vsize=2576 CPUtime=0.03
/proc/7114/stat : 7114 (p2cudf) S 7113 7113 2059 34821 2220 4202496 392 2999 0 1 0 0 2 1 25 0 1 0 874851066 2637824 282 1283457024 134512640 135304128 4288220096 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/7114/statm: 644 282 241 194 0 30 0
Current children cumulated CPU time (s) 0.03
Current children cumulated vsize (KiB) 5144

[startup+0.207898 s]
/proc/loadavg: 1.27 1.13 1.08 5/47 7115
/proc/meminfo: memFree=811456/1048576 swapFree=2078740/2097144
[pid=7113] ppid=7112 vsize=2568 CPUtime=0
/proc/7113/stat : 7113 (p2cudf-paranoid) S 7112 7113 2059 34821 2220 4202496 378 0 0 0 0 0 0 0 22 0 1 0 874851066 2629632 273 1283457024 134512640 135304128 4287056528 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/7113/statm: 642 273 233 194 0 28 0
[pid=7114] ppid=7113 vsize=2576 CPUtime=0.03
/proc/7114/stat : 7114 (p2cudf) S 7113 7113 2059 34821 2220 4202496 392 2999 0 1 0 0 2 1 25 0 1 0 874851066 2637824 282 1283457024 134512640 135304128 4288220096 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/7114/statm: 644 282 241 194 0 30 0
Current children cumulated CPU time (s) 0.03
Current children cumulated vsize (KiB) 5144

[startup+0.307924 s]
/proc/loadavg: 1.27 1.13 1.08 5/47 7115
/proc/meminfo: memFree=811456/1048576 swapFree=2078740/2097144
[pid=7113] ppid=7112 vsize=2568 CPUtime=0
/proc/7113/stat : 7113 (p2cudf-paranoid) S 7112 7113 2059 34821 2220 4202496 378 0 0 0 0 0 0 0 22 0 1 0 874851066 2629632 273 1283457024 134512640 135304128 4287056528 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/7113/statm: 642 273 233 194 0 28 0
[pid=7114] ppid=7113 vsize=2576 CPUtime=0.03
/proc/7114/stat : 7114 (p2cudf) S 7113 7113 2059 34821 2220 4202496 392 2999 0 1 0 0 2 1 25 0 1 0 874851066 2637824 282 1283457024 134512640 135304128 4288220096 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/7114/statm: 644 282 241 194 0 30 0
Current children cumulated CPU time (s) 0.03
Current children cumulated vsize (KiB) 5144

[startup+0.707997 s]
/proc/loadavg: 1.27 1.13 1.08 5/47 7115
/proc/meminfo: memFree=811456/1048576 swapFree=2078740/2097144
[pid=7113] ppid=7112 vsize=2568 CPUtime=0
/proc/7113/stat : 7113 (p2cudf-paranoid) S 7112 7113 2059 34821 2220 4202496 378 0 0 0 0 0 0 0 22 0 1 0 874851066 2629632 273 1283457024 134512640 135304128 4287056528 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/7113/statm: 642 273 233 194 0 28 0
[pid=7114] ppid=7113 vsize=2576 CPUtime=0.03
/proc/7114/stat : 7114 (p2cudf) S 7113 7113 2059 34821 2220 4202496 392 2999 0 1 0 0 2 1 25 0 1 0 874851066 2637824 282 1283457024 134512640 135304128 4288220096 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/7114/statm: 644 282 241 194 0 30 0
Current children cumulated CPU time (s) 0.03
Current children cumulated vsize (KiB) 5144

[startup+1.50819 s]
/proc/loadavg: 1.41 1.16 1.09 4/57 7136
/proc/meminfo: memFree=772856/1048576 swapFree=2078740/2097144
[pid=7113] ppid=7112 vsize=2568 CPUtime=0
/proc/7113/stat : 7113 (p2cudf-paranoid) S 7112 7113 2059 34821 2220 4202496 378 0 0 0 0 0 0 0 22 0 1 0 874851066 2629632 273 1283457024 134512640 135304128 4287056528 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/7113/statm: 642 273 233 194 0 28 0
[pid=7114] ppid=7113 vsize=2576 CPUtime=0.03
/proc/7114/stat : 7114 (p2cudf) S 7113 7113 2059 34821 2220 4202496 392 2999 0 1 0 0 2 1 25 0 1 0 874851066 2637824 282 1283457024 134512640 135304128 4288220096 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/7114/statm: 644 282 241 194 0 30 0
[pid=7127] ppid=7114 vsize=874360 CPUtime=1.41
/proc/7127/stat : 7127 (java) S 7114 7113 2059 34821 2220 4202496 19050 0 1 0 134 7 0 0 25 0 10 0 874851075 895344640 16521 1283457024 134512640 134550932 4291222848 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/7127/statm: 218590 16521 1732 10 0 215680 0
[pid=7127/tid=7128] ppid=7114 vsize=874360 CPUtime=0.8
/proc/7127/task/7128/stat : 7128 (java) R 7114 7113 2059 34821 2220 4202560 11038 0 1 0 74 6 0 0 25 0 10 0 874851076 895344640 16521 1283457024 134512640 134550932 4291222848 18446744073709551615 4149157777 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=7127/tid=7129] ppid=7114 vsize=874360 CPUtime=0
/proc/7127/task/7129/stat : 7129 (java) S 7114 7113 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 18 0 10 0 874851078 895344640 16521 1283457024 134512640 134550932 4291222848 18446744073709551615 4294960130 0 0 0 16800975 18446612133377258496 0 0 -1 0 0 0 0
[pid=7127/tid=7130] ppid=7114 vsize=874360 CPUtime=0
/proc/7127/task/7130/stat : 7130 (java) S 7114 7113 2059 34821 2220 4202560 9 0 0 0 0 0 0 0 25 0 10 0 874851078 895344640 16521 1283457024 134512640 134550932 4291222848 18446744073709551615 4294960130 0 4 0 16800975 18446612133377258496 0 0 -1 0 0 0 0
[pid=7127/tid=7131] ppid=7114 vsize=874360 CPUtime=0
/proc/7127/task/7131/stat : 7131 (java) S 7114 7113 2059 34821 2220 4202560 4 0 0 0 0 0 0 0 25 0 10 0 874851078 895344640 16521 1283457024 134512640 134550932 4291222848 18446744073709551615 4294960130 0 4 0 16800975 18446612133377258496 0 0 -1 0 0 0 0
[pid=7127/tid=7132] ppid=7114 vsize=874360 CPUtime=0
/proc/7127/task/7132/stat : 7132 (java) S 7114 7113 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 10 0 874851081 895344640 16521 1283457024 134512640 134550932 4291222848 18446744073709551615 4294960130 0 4 0 16800975 18446612133377258496 0 0 -1 0 0 0 0
[pid=7127/tid=7133] ppid=7114 vsize=874360 CPUtime=0.33
/proc/7127/task/7133/stat : 7133 (java) R 7114 7113 2059 34821 2220 4202560 5810 0 0 0 32 1 0 0 23 0 10 0 874851081 895344640 16521 1283457024 134512640 134550932 4291222848 18446744073709551615 4149492191 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=7127/tid=7134] ppid=7114 vsize=874360 CPUtime=0.28
/proc/7127/task/7134/stat : 7134 (java) R 7114 7113 2059 34821 2220 4202560 1089 0 0 0 28 0 0 0 25 0 10 0 874851081 895344640 16521 1283457024 134512640 134550932 4291222848 18446744073709551615 4152186047 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=7127/tid=7135] ppid=7114 vsize=874360 CPUtime=0
/proc/7127/task/7135/stat : 7135 (java) S 7114 7113 2059 34821 2220 4202560 0 0 0 0 0 0 0 0 25 0 10 0 874851081 895344640 16521 1283457024 134512640 134550932 4291222848 18446744073709551615 4294960130 0 4 0 16800975 18446612133377258496 0 0 -1 0 0 0 0
[pid=7127/tid=7136] ppid=7114 vsize=874360 CPUtime=0
/proc/7127/task/7136/stat : 7136 (java) R 7114 7113 2059 34821 2220 4202560 2 0 0 0 0 0 0 0 15 0 10 0 874851081 895344640 16521 1283457024 134512640 134550932 4291222848 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 1.44
Current children cumulated vsize (KiB) 879504

[startup+3.10862 s]
/proc/loadavg: 1.41 1.16 1.09 4/57 7136
/proc/meminfo: memFree=713172/1048576 swapFree=2078740/2097144
[pid=7113] ppid=7112 vsize=2568 CPUtime=0
/proc/7113/stat : 7113 (p2cudf-paranoid) S 7112 7113 2059 34821 2220 4202496 378 0 0 0 0 0 0 0 22 0 1 0 874851066 2629632 273 1283457024 134512640 135304128 4287056528 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/7113/statm: 642 273 233 194 0 28 0
[pid=7114] ppid=7113 vsize=2576 CPUtime=0.03
/proc/7114/stat : 7114 (p2cudf) S 7113 7113 2059 34821 2220 4202496 392 2999 0 1 0 0 2 1 25 0 1 0 874851066 2637824 282 1283457024 134512640 135304128 4288220096 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/7114/statm: 644 282 241 194 0 30 0
[pid=7127] ppid=7114 vsize=890532 CPUtime=3.01
/proc/7127/stat : 7127 (java) S 7114 7113 2059 34821 2220 4202496 33835 0 1 0 291 10 0 0 25 0 10 0 874851075 911904768 27293 1283457024 134512640 134550932 4291222848 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/7127/statm: 222633 27293 1755 10 0 219723 0
[pid=7127/tid=7128] ppid=7114 vsize=890532 CPUtime=1.3
/proc/7127/task/7128/stat : 7128 (java) R 7114 7113 2059 34821 2220 4202560 17317 0 1 0 124 6 0 0 25 0 10 0 874851076 911904768 27293 1283457024 134512640 134550932 4291222848 18446744073709551615 4149336374 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=7127/tid=7129] ppid=7114 vsize=890532 CPUtime=0
/proc/7127/task/7129/stat : 7129 (java) S 7114 7113 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 16 0 10 0 874851078 911904768 27293 1283457024 134512640 134550932 4291222848 18446744073709551615 4294960130 0 0 0 16800975 18446612133377258496 0 0 -1 0 0 0 0
[pid=7127/tid=7130] ppid=7114 vsize=890532 CPUtime=0
/proc/7127/task/7130/stat : 7130 (java) S 7114 7113 2059 34821 2220 4202560 9 0 0 0 0 0 0 0 25 0 10 0 874851078 911904768 27293 1283457024 134512640 134550932 4291222848 18446744073709551615 4294960130 0 4 0 16800975 18446612133377258496 0 0 -1 0 0 0 0
[pid=7127/tid=7131] ppid=7114 vsize=890532 CPUtime=0
/proc/7127/task/7131/stat : 7131 (java) S 7114 7113 2059 34821 2220 4202560 4 0 0 0 0 0 0 0 25 0 10 0 874851078 911904768 27293 1283457024 134512640 134550932 4291222848 18446744073709551615 4294960130 0 4 0 16800975 18446612133377258496 0 0 -1 0 0 0 0
[pid=7127/tid=7132] ppid=7114 vsize=890532 CPUtime=0
/proc/7127/task/7132/stat : 7132 (java) S 7114 7113 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 10 0 874851081 911904768 27293 1283457024 134512640 134550932 4291222848 18446744073709551615 4294960130 0 4 0 16800975 18446612133377258496 0 0 -1 0 0 0 0
[pid=7127/tid=7133] ppid=7114 vsize=890532 CPUtime=0.93
/proc/7127/task/7133/stat : 7133 (java) R 7114 7113 2059 34821 2220 4202560 11612 0 0 0 90 3 0 0 25 0 10 0 874851081 911904768 27293 1283457024 134512640 134550932 4291222848 18446744073709551615 4152595912 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=7127/tid=7134] ppid=7114 vsize=890532 CPUtime=0.77
/proc/7127/task/7134/stat : 7134 (java) R 7114 7113 2059 34821 2220 4202560 3793 0 0 0 76 1 0 0 25 0 10 0 874851081 911904768 27293 1283457024 134512640 134550932 4291222848 18446744073709551615 4152247944 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=7127/tid=7135] ppid=7114 vsize=890532 CPUtime=0
/proc/7127/task/7135/stat : 7135 (java) S 7114 7113 2059 34821 2220 4202560 0 0 0 0 0 0 0 0 25 0 10 0 874851081 911904768 27293 1283457024 134512640 134550932 4291222848 18446744073709551615 4294960130 0 4 0 16800975 18446612133377258496 0 0 -1 0 0 0 0
[pid=7127/tid=7136] ppid=7114 vsize=890532 CPUtime=0
/proc/7127/task/7136/stat : 7136 (java) S 7114 7113 2059 34821 2220 4202560 2 0 0 0 0 0 0 0 15 0 10 0 874851081 911904768 27293 1283457024 134512640 134550932 4291222848 18446744073709551615 4294960130 0 4 0 16800975 18446612133377258496 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.04
Current children cumulated vsize (KiB) 895676

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

[startup+3.20864 s]
/proc/loadavg: 1.41 1.16 1.09 4/57 7136
/proc/meminfo: memFree=713172/1048576 swapFree=2078740/2097144
[pid=7113] ppid=7112 vsize=2568 CPUtime=0
/proc/7113/stat : 7113 (p2cudf-paranoid) S 7112 7113 2059 34821 2220 4202496 378 0 0 0 0 0 0 0 22 0 1 0 874851066 2629632 273 1283457024 134512640 135304128 4287056528 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/7113/statm: 642 273 233 194 0 28 0
[pid=7114] ppid=7113 vsize=2576 CPUtime=0.03
/proc/7114/stat : 7114 (p2cudf) S 7113 7113 2059 34821 2220 4202496 392 2999 0 1 0 0 2 1 25 0 1 0 874851066 2637824 282 1283457024 134512640 135304128 4288220096 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/7114/statm: 644 282 241 194 0 30 0
[pid=7127] ppid=7114 vsize=891288 CPUtime=3.11
/proc/7127/stat : 7127 (java) S 7114 7113 2059 34821 2220 4202496 34214 0 1 0 301 10 0 0 25 0 10 0 874851075 912678912 27471 1283457024 134512640 134550932 4291222848 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/7127/statm: 222822 27471 1755 10 0 219912 0
[pid=7127/tid=7128] ppid=7114 vsize=891288 CPUtime=1.3
/proc/7127/task/7128/stat : 7128 (java) R 7114 7113 2059 34821 2220 4202560 17317 0 1 0 124 6 0 0 25 0 10 0 874851076 912678912 27471 1283457024 134512640 134550932 4291222848 18446744073709551615 4149336374 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=7127/tid=7129] ppid=7114 vsize=891288 CPUtime=0
/proc/7127/task/7129/stat : 7129 (java) S 7114 7113 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 15 0 10 0 874851078 912678912 27471 1283457024 134512640 134550932 4291222848 18446744073709551615 4294960130 0 0 0 16800975 18446612133377258496 0 0 -1 0 0 0 0
[pid=7127/tid=7130] ppid=7114 vsize=891288 CPUtime=0
/proc/7127/task/7130/stat : 7130 (java) S 7114 7113 2059 34821 2220 4202560 9 0 0 0 0 0 0 0 25 0 10 0 874851078 912678912 27471 1283457024 134512640 134550932 4291222848 18446744073709551615 4294960130 0 4 0 16800975 18446612133377258496 0 0 -1 0 0 0 0
[pid=7127/tid=7131] ppid=7114 vsize=891288 CPUtime=0
/proc/7127/task/7131/stat : 7131 (java) S 7114 7113 2059 34821 2220 4202560 4 0 0 0 0 0 0 0 25 0 10 0 874851078 912678912 27471 1283457024 134512640 134550932 4291222848 18446744073709551615 4294960130 0 4 0 16800975 18446612133377258496 0 0 -1 0 0 0 0
[pid=7127/tid=7132] ppid=7114 vsize=891288 CPUtime=0
/proc/7127/task/7132/stat : 7132 (java) S 7114 7113 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 10 0 874851081 912678912 27471 1283457024 134512640 134550932 4291222848 18446744073709551615 4294960130 0 4 0 16800975 18446612133377258496 0 0 -1 0 0 0 0
[pid=7127/tid=7133] ppid=7114 vsize=891288 CPUtime=1.03
/proc/7127/task/7133/stat : 7133 (java) R 7114 7113 2059 34821 2220 4202560 11991 0 0 0 100 3 0 0 25 0 10 0 874851081 912678912 27471 1283457024 134512640 134550932 4291222848 18446744073709551615 4149228079 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=7127/tid=7134] ppid=7114 vsize=891288 CPUtime=0.77
/proc/7127/task/7134/stat : 7134 (java) R 7114 7113 2059 34821 2220 4202560 3793 0 0 0 76 1 0 0 25 0 10 0 874851081 912678912 27471 1283457024 134512640 134550932 4291222848 18446744073709551615 4152247944 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=7127/tid=7135] ppid=7114 vsize=891288 CPUtime=0
/proc/7127/task/7135/stat : 7135 (java) S 7114 7113 2059 34821 2220 4202560 0 0 0 0 0 0 0 0 25 0 10 0 874851081 912678912 27471 1283457024 134512640 134550932 4291222848 18446744073709551615 4294960130 0 4 0 16800975 18446612133377258496 0 0 -1 0 0 0 0
[pid=7127/tid=7136] ppid=7114 vsize=891288 CPUtime=0
/proc/7127/task/7136/stat : 7136 (java) S 7114 7113 2059 34821 2220 4202560 2 0 0 0 0 0 0 0 15 0 10 0 874851081 912678912 27471 1283457024 134512640 134550932 4291222848 18446744073709551615 4294960130 0 4 0 16800975 18446612133377258496 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.14
Current children cumulated vsize (KiB) 896432

[startup+4.80895 s]
/proc/loadavg: 1.41 1.16 1.09 4/57 7136
/proc/meminfo: memFree=674236/1048576 swapFree=2078740/2097144
[pid=7113] ppid=7112 vsize=2568 CPUtime=0
/proc/7113/stat : 7113 (p2cudf-paranoid) S 7112 7113 2059 34821 2220 4202496 378 0 0 0 0 0 0 0 22 0 1 0 874851066 2629632 273 1283457024 134512640 135304128 4287056528 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/7113/statm: 642 273 233 194 0 28 0
[pid=7114] ppid=7113 vsize=2576 CPUtime=0.03
/proc/7114/stat : 7114 (p2cudf) S 7113 7113 2059 34821 2220 4202496 392 2999 0 1 0 0 2 1 25 0 1 0 874851066 2637824 282 1283457024 134512640 135304128 4288220096 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/7114/statm: 644 282 241 194 0 30 0
[pid=7127] ppid=7114 vsize=891612 CPUtime=4.72
/proc/7127/stat : 7127 (java) S 7114 7113 2059 34821 2220 4202496 42621 0 1 0 460 12 0 0 25 0 11 0 874851075 913010688 35878 1283457024 134512640 134550932 4291222848 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/7127/statm: 222903 35878 1770 10 0 219993 0
[pid=7127/tid=7128] ppid=7114 vsize=891612 CPUtime=1.87
/proc/7127/task/7128/stat : 7128 (java) S 7114 7113 2059 34821 2220 4202560 25627 0 1 0 180 7 0 0 25 0 11 0 874851076 913010688 35878 1283457024 134512640 134550932 4291222848 18446744073709551615 4294960130 0 4 0 16800975 18446612133377258496 0 0 -1 0 0 0 0
[pid=7127/tid=7129] ppid=7114 vsize=891612 CPUtime=0
/proc/7127/task/7129/stat : 7129 (java) S 7114 7113 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 15 0 11 0 874851078 913010688 35878 1283457024 134512640 134550932 4291222848 18446744073709551615 4294960130 0 0 0 16800975 18446612133377258496 0 0 -1 0 0 0 0
[pid=7127/tid=7130] ppid=7114 vsize=891612 CPUtime=0
/proc/7127/task/7130/stat : 7130 (java) S 7114 7113 2059 34821 2220 4202560 9 0 0 0 0 0 0 0 25 0 11 0 874851078 913010688 35878 1283457024 134512640 134550932 4291222848 18446744073709551615 4294960130 0 4 0 16800975 18446612133377258496 0 0 -1 0 0 0 0
[pid=7127/tid=7131] ppid=7114 vsize=891612 CPUtime=0
/proc/7127/task/7131/stat : 7131 (java) S 7114 7113 2059 34821 2220 4202560 4 0 0 0 0 0 0 0 25 0 11 0 874851078 913010688 35878 1283457024 134512640 134550932 4291222848 18446744073709551615 4294960130 0 4 0 16800975 18446612133377258496 0 0 -1 0 0 0 0
[pid=7127/tid=7132] ppid=7114 vsize=891612 CPUtime=0
/proc/7127/task/7132/stat : 7132 (java) S 7114 7113 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 11 0 874851081 913010688 35878 1283457024 134512640 134550932 4291222848 18446744073709551615 4294960130 0 4 0 16800975 18446612133377258496 0 0 -1 0 0 0 0
[pid=7127/tid=7133] ppid=7114 vsize=891612 CPUtime=1.55
/proc/7127/task/7133/stat : 7133 (java) R 7114 7113 2059 34821 2220 4202560 12037 0 0 0 152 3 0 0 25 0 11 0 874851081 913010688 35878 1283457024 134512640 134550932 4291222848 18446744073709551615 4153019567 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=7127/tid=7134] ppid=7114 vsize=891612 CPUtime=1.27
/proc/7127/task/7134/stat : 7134 (java) R 7114 7113 2059 34821 2220 4202560 3844 0 0 0 126 1 0 0 25 0 11 0 874851081 913010688 35878 1283457024 134512640 134550932 4291222848 18446744073709551615 4151972890 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=7127/tid=7135] ppid=7114 vsize=891612 CPUtime=0
/proc/7127/task/7135/stat : 7135 (java) S 7114 7113 2059 34821 2220 4202560 0 0 0 0 0 0 0 0 25 0 11 0 874851081 913010688 35878 1283457024 134512640 134550932 4291222848 18446744073709551615 4294960130 0 4 0 16800975 18446612133377258496 0 0 -1 0 0 0 0
[pid=7127/tid=7136] ppid=7114 vsize=891612 CPUtime=0
/proc/7127/task/7136/stat : 7136 (java) R 7114 7113 2059 34821 2220 4202560 2 0 0 0 0 0 0 0 15 0 11 0 874851081 913010688 35878 1283457024 134512640 134550932 4291222848 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 4.75
Current children cumulated vsize (KiB) 896756

[startup+5.60908 s]
/proc/loadavg: 1.41 1.16 1.09 5/59 7139
/proc/meminfo: memFree=667524/1048576 swapFree=2078740/2097144
[pid=7113] ppid=7112 vsize=2568 CPUtime=0
/proc/7113/stat : 7113 (p2cudf-paranoid) S 7112 7113 2059 34821 2220 4202496 378 0 0 0 0 0 0 0 22 0 1 0 874851066 2629632 273 1283457024 134512640 135304128 4287056528 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/7113/statm: 642 273 233 194 0 28 0
[pid=7114] ppid=7113 vsize=2576 CPUtime=0.03
/proc/7114/stat : 7114 (p2cudf) S 7113 7113 2059 34821 2220 4202496 392 2999 0 1 0 0 2 1 25 0 1 0 874851066 2637824 282 1283457024 134512640 135304128 4288220096 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/7114/statm: 644 282 241 194 0 30 0
[pid=7127] ppid=7114 vsize=891936 CPUtime=5.52
/proc/7127/stat : 7127 (java) S 7114 7113 2059 34821 2220 4202496 43499 0 1 0 540 12 0 0 25 0 11 0 874851075 913342464 36756 1283457024 134512640 134550932 4291222848 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/7127/statm: 222984 36756 1791 10 0 220074 0
[pid=7127/tid=7128] ppid=7114 vsize=891936 CPUtime=2.08
/proc/7127/task/7128/stat : 7128 (java) R 7114 7113 2059 34821 2220 4202560 26415 0 1 0 201 7 0 0 25 0 11 0 874851076 913342464 36756 1283457024 134512640 134550932 4291222848 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=7127/tid=7129] ppid=7114 vsize=891936 CPUtime=0
/proc/7127/task/7129/stat : 7129 (java) S 7114 7113 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 16 0 11 0 874851078 913342464 36756 1283457024 134512640 134550932 4291222848 18446744073709551615 4294960130 0 0 0 16800975 18446612133377258496 0 0 -1 0 0 0 0
[pid=7127/tid=7130] ppid=7114 vsize=891936 CPUtime=0
/proc/7127/task/7130/stat : 7130 (java) S 7114 7113 2059 34821 2220 4202560 9 0 0 0 0 0 0 0 25 0 11 0 874851078 913342464 36756 1283457024 134512640 134550932 4291222848 18446744073709551615 4294960130 0 4 0 16800975 18446612133377258496 0 0 -1 0 0 0 0
[pid=7127/tid=7131] ppid=7114 vsize=891936 CPUtime=0
/proc/7127/task/7131/stat : 7131 (java) S 7114 7113 2059 34821 2220 4202560 4 0 0 0 0 0 0 0 25 0 11 0 874851078 913342464 36756 1283457024 134512640 134550932 4291222848 18446744073709551615 4294960130 0 4 0 16800975 18446612133377258496 0 0 -1 0 0 0 0
[pid=7127/tid=7132] ppid=7114 vsize=891936 CPUtime=0
/proc/7127/task/7132/stat : 7132 (java) S 7114 7113 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 11 0 874851081 913342464 36756 1283457024 134512640 134550932 4291222848 18446744073709551615 4294960130 0 4 0 16800975 18446612133377258496 0 0 -1 0 0 0 0
[pid=7127/tid=7133] ppid=7114 vsize=891936 CPUtime=1.89
/proc/7127/task/7133/stat : 7133 (java) R 7114 7113 2059 34821 2220 4202560 12088 0 0 0 186 3 0 0 22 0 11 0 874851081 913342464 36756 1283457024 134512640 134550932 4291222848 18446744073709551615 4153020227 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=7127/tid=7134] ppid=7114 vsize=891936 CPUtime=1.53
/proc/7127/task/7134/stat : 7134 (java) S 7114 7113 2059 34821 2220 4202560 3878 0 0 0 152 1 0 0 25 0 11 0 874851081 913342464 36756 1283457024 134512640 134550932 4291222848 18446744073709551615 4294960130 0 4 0 16800975 18446612133377258496 0 0 -1 0 0 0 0
[pid=7127/tid=7135] ppid=7114 vsize=891936 CPUtime=0
/proc/7127/task/7135/stat : 7135 (java) S 7114 7113 2059 34821 2220 4202560 0 0 0 0 0 0 0 0 25 0 11 0 874851081 913342464 36756 1283457024 134512640 134550932 4291222848 18446744073709551615 4294960130 0 4 0 16800975 18446612133377258496 0 0 -1 0 0 0 0
[pid=7127/tid=7136] ppid=7114 vsize=891936 CPUtime=0
/proc/7127/task/7136/stat : 7136 (java) S 7114 7113 2059 34821 2220 4202560 2 0 0 0 0 0 0 0 15 0 11 0 874851081 913342464 36756 1283457024 134512640 134550932 4291222848 18446744073709551615 4294960130 0 4 0 16800975 18446612133377258496 0 0 -1 0 0 0 0
[pid=7127/tid=7139] ppid=7114 vsize=891936 CPUtime=0
/proc/7127/task/7139/stat : 7139 (java) R 7114 7113 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 11 0 874851607 913342464 36756 1283457024 134512640 134550932 4291222848 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 5.55
Current children cumulated vsize (KiB) 897080

[startup+6.00423 s]
/proc/loadavg: 1.41 1.16 1.09 5/59 7139
/proc/meminfo: memFree=667524/1048576 swapFree=2078740/2097144
[pid=7113] ppid=7112 vsize=2568 CPUtime=0
/proc/7113/stat : 7113 (p2cudf-paranoid) S 7112 7113 2059 34821 2220 4202496 378 0 0 0 0 0 0 0 22 0 1 0 874851066 2629632 273 1283457024 134512640 135304128 4287056528 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/7113/statm: 642 273 233 194 0 28 0
[pid=7114] ppid=7113 vsize=2576 CPUtime=0.03
/proc/7114/stat : 7114 (p2cudf) S 7113 7113 2059 34821 2220 4202496 392 2999 0 1 0 0 2 1 25 0 1 0 874851066 2637824 282 1283457024 134512640 135304128 4288220096 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/7114/statm: 644 282 241 194 0 30 0
[pid=7127] ppid=7114 vsize=891936 CPUtime=5.55
/proc/7127/stat : 7127 (java) S 7114 7113 2059 34821 2220 4202496 43581 0 1 0 543 12 0 0 25 0 11 0 874851075 913342464 36838 1283457024 134512640 134550932 4291222848 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/7127/statm: 222984 36838 1791 10 0 220074 0
[pid=7127/tid=7128] ppid=7114 vsize=891936 CPUtime=2.08
/proc/7127/task/7128/stat : 7128 (java) S 7114 7113 2059 34821 2220 4202560 26491 0 1 0 201 7 0 0 25 0 11 0 874851076 913342464 36838 1283457024 134512640 134550932 4291222848 18446744073709551615 4294960130 0 4 0 16800975 18446612133377258496 0 0 -1 0 0 0 0
[pid=7127/tid=7129] ppid=7114 vsize=891936 CPUtime=0
/proc/7127/task/7129/stat : 7129 (java) S 7114 7113 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 16 0 11 0 874851078 913342464 36838 1283457024 134512640 134550932 4291222848 18446744073709551615 4294960130 0 0 0 16800975 18446612133377258496 0 0 -1 0 0 0 0
[pid=7127/tid=7130] ppid=7114 vsize=891936 CPUtime=0
/proc/7127/task/7130/stat : 7130 (java) S 7114 7113 2059 34821 2220 4202560 9 0 0 0 0 0 0 0 25 0 11 0 874851078 913342464 36838 1283457024 134512640 134550932 4291222848 18446744073709551615 4294960130 0 4 0 16800975 18446612133377258496 0 0 -1 0 0 0 0
[pid=7127/tid=7131] ppid=7114 vsize=891936 CPUtime=0
/proc/7127/task/7131/stat : 7131 (java) S 7114 7113 2059 34821 2220 4202560 4 0 0 0 0 0 0 0 25 0 11 0 874851078 913342464 36838 1283457024 134512640 134550932 4291222848 18446744073709551615 4294960130 0 4 0 16800975 18446612133377258496 0 0 -1 0 0 0 0
[pid=7127/tid=7132] ppid=7114 vsize=891936 CPUtime=0
/proc/7127/task/7132/stat : 7132 (java) S 7114 7113 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 11 0 874851081 913342464 36838 1283457024 134512640 134550932 4291222848 18446744073709551615 4294960130 0 4 0 16800975 18446612133377258496 0 0 -1 0 0 0 0
[pid=7127/tid=7133] ppid=7114 vsize=891936 CPUtime=1.92
/proc/7127/task/7133/stat : 7133 (java) S 7114 7113 2059 34821 2220 4202560 12091 0 0 0 189 3 0 0 22 0 11 0 874851081 913342464 36838 1283457024 134512640 134550932 4291222848 18446744073709551615 4294960130 0 4 0 16800975 18446612133377258496 0 0 -1 0 0 0 0
[pid=7127/tid=7134] ppid=7114 vsize=891936 CPUtime=1.53
/proc/7127/task/7134/stat : 7134 (java) S 7114 7113 2059 34821 2220 4202560 3878 0 0 0 152 1 0 0 24 0 11 0 874851081 913342464 36838 1283457024 134512640 134550932 4291222848 18446744073709551615 4294960130 0 4 0 16800975 18446612133377258496 0 0 -1 0 0 0 0
[pid=7127/tid=7135] ppid=7114 vsize=891936 CPUtime=0
/proc/7127/task/7135/stat : 7135 (java) S 7114 7113 2059 34821 2220 4202560 0 0 0 0 0 0 0 0 25 0 11 0 874851081 913342464 36838 1283457024 134512640 134550932 4291222848 18446744073709551615 4294960130 0 4 0 16800975 18446612133377258496 0 0 -1 0 0 0 0
[pid=7127/tid=7136] ppid=7114 vsize=891936 CPUtime=0
/proc/7127/task/7136/stat : 7136 (java) S 7114 7113 2059 34821 2220 4202560 2 0 0 0 0 0 0 0 15 0 11 0 874851081 913342464 36838 1283457024 134512640 134550932 4291222848 18446744073709551615 4294960130 0 4 0 16800975 18446612133377258496 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 5.58
Current children cumulated vsize (KiB) 897080

[startup+6.20717 s]
/proc/loadavg: 1.41 1.16 1.09 5/59 7139
/proc/meminfo: memFree=667524/1048576 swapFree=2078740/2097144
[pid=7113] ppid=7112 vsize=2568 CPUtime=0
/proc/7113/stat : 7113 (p2cudf-paranoid) S 7112 7113 2059 34821 2220 4202496 378 0 0 0 0 0 0 0 22 0 1 0 874851066 2629632 273 1283457024 134512640 135304128 4287056528 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/7113/statm: 642 273 233 194 0 28 0
[pid=7114] ppid=7113 vsize=2576 CPUtime=0.03
/proc/7114/stat : 7114 (p2cudf) S 7113 7113 2059 34821 2220 4202496 392 2999 0 1 0 0 2 1 25 0 1 0 874851066 2637824 282 1283457024 134512640 135304128 4288220096 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/7114/statm: 644 282 241 194 0 30 0
[pid=7127] ppid=7114 vsize=891936 CPUtime=5.6
/proc/7127/stat : 7127 (java) S 7114 7113 2059 34821 2220 4202496 43701 0 1 0 547 13 0 0 25 0 10 0 874851075 913342464 36958 1283457024 134512640 134550932 4291222848 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/7127/statm: 222984 36958 1791 10 0 220074 0
[pid=7127/tid=7128] ppid=7114 vsize=891936 CPUtime=2.08
/proc/7127/task/7128/stat : 7128 (java) S 7114 7113 2059 34821 2220 4202560 26491 0 1 0 201 7 0 0 20 0 10 0 874851076 913342464 36958 1283457024 134512640 134550932 4291222848 18446744073709551615 4294960130 0 4 0 16800975 18446612133377258496 0 0 -1 0 0 0 0
[pid=7127/tid=7129] ppid=7114 vsize=891936 CPUtime=0
/proc/7127/task/7129/stat : 7129 (java) S 7114 7113 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 16 0 10 0 874851078 913342464 36958 1283457024 134512640 134550932 4291222848 18446744073709551615 4294960130 0 0 0 16800975 18446612133377258496 0 0 -1 0 0 0 0
[pid=7127/tid=7130] ppid=7114 vsize=891936 CPUtime=0
/proc/7127/task/7130/stat : 7130 (java) S 7114 7113 2059 34821 2220 4202560 9 0 0 0 0 0 0 0 25 0 10 0 874851078 913342464 36958 1283457024 134512640 134550932 4291222848 18446744073709551615 4294960130 0 4 0 16800975 18446612133377258496 0 0 -1 0 0 0 0
[pid=7127/tid=7131] ppid=7114 vsize=891936 CPUtime=0
/proc/7127/task/7131/stat : 7131 (java) S 7114 7113 2059 34821 2220 4202560 4 0 0 0 0 0 0 0 25 0 10 0 874851078 913342464 36958 1283457024 134512640 134550932 4291222848 18446744073709551615 4294960130 0 4 0 16800975 18446612133377258496 0 0 -1 0 0 0 0
[pid=7127/tid=7132] ppid=7114 vsize=891936 CPUtime=0
/proc/7127/task/7132/stat : 7132 (java) S 7114 7113 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 10 0 874851081 913342464 36958 1283457024 134512640 134550932 4291222848 18446744073709551615 4294960130 0 4 0 16800975 18446612133377258496 0 0 -1 0 0 0 0
[pid=7127/tid=7133] ppid=7114 vsize=891936 CPUtime=1.92
/proc/7127/task/7133/stat : 7133 (java) S 7114 7113 2059 34821 2220 4202560 12091 0 0 0 189 3 0 0 22 0 10 0 874851081 913342464 36958 1283457024 134512640 134550932 4291222848 18446744073709551615 4294960130 0 4 0 16800975 18446612133377258496 0 0 -1 0 0 0 0
[pid=7127/tid=7134] ppid=7114 vsize=891936 CPUtime=1.55
/proc/7127/task/7134/stat : 7134 (java) S 7114 7113 2059 34821 2220 4202560 3879 0 0 0 154 1 0 0 19 0 10 0 874851081 913342464 36958 1283457024 134512640 134550932 4291222848 18446744073709551615 4294960130 0 4 0 16800975 18446612133377258496 0 0 -1 0 0 0 0
[pid=7127/tid=7135] ppid=7114 vsize=891936 CPUtime=0
/proc/7127/task/7135/stat : 7135 (java) S 7114 7113 2059 34821 2220 4202560 0 0 0 0 0 0 0 0 25 0 10 0 874851081 913342464 36958 1283457024 134512640 134550932 4291222848 18446744073709551615 4294960130 0 4 0 16800975 18446612133377258496 0 0 -1 0 0 0 0
[pid=7127/tid=7136] ppid=7114 vsize=891936 CPUtime=0
/proc/7127/task/7136/stat : 7136 (java) R 7114 7113 2059 34821 2220 4202560 2 0 0 0 0 0 0 0 15 0 10 0 874851081 913342464 36958 1283457024 134512640 134550932 4291222848 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 5.63
Current children cumulated vsize (KiB) 897080

Child status: 0
Real time (s): 6.21916
CPU time (s): 5.64035
CPU user time (s): 5.49234
CPU system time (s): 0.148009
CPU usage (%): 90.6931
Max. virtual memory (cumulated for all children) (KiB): 898760

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 5.49234
system time used= 0.148009
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 47495
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= 293
involuntary context switches= 308

runsolver used 0 second user time and 0.008 second system time

The end