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/rand180.sarge.cudf.sarge.log.runsolver ./p2cudf-paranoid-1.9 /home/misc2010/data/icse/sarge/rand180.sarge.cudf /home/misc2010/tmp/201012061533/p2cudf-paranoid-1.9/rand180.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.32 1.11 1.09 4/46 9628
/proc/meminfo: memFree=791096/1048576 swapFree=2078740/2097144
[pid=9627] ppid=9626 vsize=2576 CPUtime=0
/proc/9627/stat : 9627 (p2cudf-paranoid) S 9626 9627 2059 34821 2220 4202496 380 0 0 0 0 0 0 0 22 0 1 0 875113270 2637824 274 1283457024 134512640 135304128 4289492208 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/9627/statm: 644 274 233 194 0 30 0
[pid=9628] ppid=9627 vsize=2564 CPUtime=0
/proc/9628/stat : 9628 (p2cudf) R 9627 9627 2059 34821 2220 4202496 311 0 0 0 0 0 0 0 25 0 1 0 875113271 2625536 236 1283457024 134512640 135304128 4287847280 18446744073709551615 134852607 0 0 4 65536 0 0 0 17 0 0 0 0
/proc/9628/statm: 641 236 199 194 0 27 0

[startup+0.192864 s]
/proc/loadavg: 1.32 1.11 1.09 4/46 9628
/proc/meminfo: memFree=791096/1048576 swapFree=2078740/2097144
[pid=9627] ppid=9626 vsize=2576 CPUtime=0
/proc/9627/stat : 9627 (p2cudf-paranoid) S 9626 9627 2059 34821 2220 4202496 380 0 0 0 0 0 0 0 22 0 1 0 875113270 2637824 274 1283457024 134512640 135304128 4289492208 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/9627/statm: 644 274 233 194 0 30 0
[pid=9628] ppid=9627 vsize=2576 CPUtime=0.03
/proc/9628/stat : 9628 (p2cudf) S 9627 9627 2059 34821 2220 4202496 393 2998 0 1 0 0 2 1 25 0 1 0 875113271 2637824 282 1283457024 134512640 135304128 4287847280 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/9628/statm: 644 282 241 194 0 30 0
Current children cumulated CPU time (s) 0.03
Current children cumulated vsize (KiB) 5152

[startup+0.202865 s]
/proc/loadavg: 1.32 1.11 1.09 4/46 9628
/proc/meminfo: memFree=791096/1048576 swapFree=2078740/2097144
[pid=9627] ppid=9626 vsize=2576 CPUtime=0
/proc/9627/stat : 9627 (p2cudf-paranoid) S 9626 9627 2059 34821 2220 4202496 380 0 0 0 0 0 0 0 22 0 1 0 875113270 2637824 274 1283457024 134512640 135304128 4289492208 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/9627/statm: 644 274 233 194 0 30 0
[pid=9628] ppid=9627 vsize=2576 CPUtime=0.03
/proc/9628/stat : 9628 (p2cudf) S 9627 9627 2059 34821 2220 4202496 393 2998 0 1 0 0 2 1 25 0 1 0 875113271 2637824 282 1283457024 134512640 135304128 4287847280 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/9628/statm: 644 282 241 194 0 30 0
Current children cumulated CPU time (s) 0.03
Current children cumulated vsize (KiB) 5152

[startup+0.313235 s]
/proc/loadavg: 1.32 1.11 1.09 4/46 9628
/proc/meminfo: memFree=791096/1048576 swapFree=2078740/2097144
[pid=9627] ppid=9626 vsize=2576 CPUtime=0
/proc/9627/stat : 9627 (p2cudf-paranoid) S 9626 9627 2059 34821 2220 4202496 380 0 0 0 0 0 0 0 22 0 1 0 875113270 2637824 274 1283457024 134512640 135304128 4289492208 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/9627/statm: 644 274 233 194 0 30 0
[pid=9628] ppid=9627 vsize=2576 CPUtime=0.03
/proc/9628/stat : 9628 (p2cudf) S 9627 9627 2059 34821 2220 4202496 393 2998 0 1 0 0 2 1 25 0 1 0 875113271 2637824 282 1283457024 134512640 135304128 4287847280 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/9628/statm: 644 282 241 194 0 30 0
Current children cumulated CPU time (s) 0.03
Current children cumulated vsize (KiB) 5152

[startup+0.708859 s]
/proc/loadavg: 1.32 1.11 1.09 4/46 9628
/proc/meminfo: memFree=791096/1048576 swapFree=2078740/2097144
[pid=9627] ppid=9626 vsize=2576 CPUtime=0
/proc/9627/stat : 9627 (p2cudf-paranoid) S 9626 9627 2059 34821 2220 4202496 380 0 0 0 0 0 0 0 22 0 1 0 875113270 2637824 274 1283457024 134512640 135304128 4289492208 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/9627/statm: 644 274 233 194 0 30 0
[pid=9628] ppid=9627 vsize=2576 CPUtime=0.03
/proc/9628/stat : 9628 (p2cudf) S 9627 9627 2059 34821 2220 4202496 393 2998 0 1 0 0 2 1 25 0 1 0 875113271 2637824 282 1283457024 134512640 135304128 4287847280 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/9628/statm: 644 282 241 194 0 30 0
Current children cumulated CPU time (s) 0.03
Current children cumulated vsize (KiB) 5152

[startup+1.50909 s]
/proc/loadavg: 1.32 1.11 1.09 4/57 9650
/proc/meminfo: memFree=751124/1048576 swapFree=2078740/2097144
[pid=9627] ppid=9626 vsize=2576 CPUtime=0
/proc/9627/stat : 9627 (p2cudf-paranoid) S 9626 9627 2059 34821 2220 4202496 380 0 0 0 0 0 0 0 22 0 1 0 875113270 2637824 274 1283457024 134512640 135304128 4289492208 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/9627/statm: 644 274 233 194 0 30 0
[pid=9628] ppid=9627 vsize=2576 CPUtime=0.03
/proc/9628/stat : 9628 (p2cudf) S 9627 9627 2059 34821 2220 4202496 393 2998 0 1 0 0 2 1 25 0 1 0 875113271 2637824 282 1283457024 134512640 135304128 4287847280 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/9628/statm: 644 282 241 194 0 30 0
[pid=9641] ppid=9628 vsize=882100 CPUtime=1.29
/proc/9641/stat : 9641 (java) S 9628 9627 2059 34821 2220 4202496 17269 0 1 0 124 5 0 0 25 0 10 0 875113274 903270400 15079 1283457024 134512640 134550932 4292830912 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/9641/statm: 220525 15079 1741 10 0 217615 0
[pid=9641/tid=9642] ppid=9628 vsize=882100 CPUtime=0.42
/proc/9641/task/9642/stat : 9642 (java) R 9628 9627 2059 34821 2220 4202560 7859 0 1 0 38 4 0 0 25 0 10 0 875113275 903270400 15079 1283457024 134512640 134550932 4292830912 18446744073709551615 4095940027 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=9641/tid=9643] ppid=9628 vsize=882100 CPUtime=0
/proc/9641/task/9643/stat : 9643 (java) S 9628 9627 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 18 0 10 0 875113276 903270400 15079 1283457024 134512640 134550932 4292830912 18446744073709551615 4294960130 0 0 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=9641/tid=9644] ppid=9628 vsize=882100 CPUtime=0
/proc/9641/task/9644/stat : 9644 (java) S 9628 9627 2059 34821 2220 4202560 9 0 0 0 0 0 0 0 25 0 10 0 875113277 903270400 15079 1283457024 134512640 134550932 4292830912 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=9641/tid=9645] ppid=9628 vsize=882100 CPUtime=0
/proc/9641/task/9645/stat : 9645 (java) S 9628 9627 2059 34821 2220 4202560 4 0 0 0 0 0 0 0 25 0 10 0 875113277 903270400 15079 1283457024 134512640 134550932 4292830912 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=9641/tid=9646] ppid=9628 vsize=882100 CPUtime=0
/proc/9641/task/9646/stat : 9646 (java) S 9628 9627 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 10 0 875113279 903270400 15079 1283457024 134512640 134550932 4292830912 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=9641/tid=9647] ppid=9628 vsize=882100 CPUtime=0.34
/proc/9641/task/9647/stat : 9647 (java) S 9628 9627 2059 34821 2220 4202560 3209 0 0 0 34 0 0 0 23 0 10 0 875113279 903270400 15079 1283457024 134512640 134550932 4292830912 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=9641/tid=9648] ppid=9628 vsize=882100 CPUtime=0.5
/proc/9641/task/9648/stat : 9648 (java) R 9628 9627 2059 34821 2220 4202560 5086 0 0 0 49 1 0 0 21 0 10 0 875113279 903270400 15079 1283457024 134512640 134550932 4292830912 18446744073709551615 4147918507 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=9641/tid=9649] ppid=9628 vsize=882100 CPUtime=0
/proc/9641/task/9649/stat : 9649 (java) S 9628 9627 2059 34821 2220 4202560 2 0 0 0 0 0 0 0 25 0 10 0 875113279 903270400 15079 1283457024 134512640 134550932 4292830912 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=9641/tid=9650] ppid=9628 vsize=882100 CPUtime=0
/proc/9641/task/9650/stat : 9650 (java) S 9628 9627 2059 34821 2220 4202560 2 0 0 0 0 0 0 0 15 0 10 0 875113279 903270400 15079 1283457024 134512640 134550932 4292830912 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 1.32
Current children cumulated vsize (KiB) 887252

[startup+3.10953 s]
/proc/loadavg: 1.32 1.11 1.09 4/57 9650
/proc/meminfo: memFree=693540/1048576 swapFree=2078740/2097144
[pid=9627] ppid=9626 vsize=2576 CPUtime=0
/proc/9627/stat : 9627 (p2cudf-paranoid) S 9626 9627 2059 34821 2220 4202496 380 0 0 0 0 0 0 0 22 0 1 0 875113270 2637824 274 1283457024 134512640 135304128 4289492208 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/9627/statm: 644 274 233 194 0 30 0
[pid=9628] ppid=9627 vsize=2576 CPUtime=0.03
/proc/9628/stat : 9628 (p2cudf) S 9627 9627 2059 34821 2220 4202496 393 2998 0 1 0 0 2 1 25 0 1 0 875113271 2637824 282 1283457024 134512640 135304128 4287847280 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/9628/statm: 644 282 241 194 0 30 0
[pid=9641] ppid=9628 vsize=879532 CPUtime=2.88
/proc/9641/stat : 9641 (java) S 9628 9627 2059 34821 2220 4202496 34733 0 1 0 275 13 0 0 25 0 10 0 875113274 900640768 29006 1283457024 134512640 134550932 4292830912 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/9641/statm: 219883 29006 1763 10 0 216973 0
[pid=9641/tid=9642] ppid=9628 vsize=879532 CPUtime=0.94
/proc/9641/task/9642/stat : 9642 (java) R 9628 9627 2059 34821 2220 4202560 21669 0 1 0 83 11 0 0 25 0 10 0 875113275 900640768 29006 1283457024 134512640 134550932 4292830912 18446744073709551615 4096474247 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=9641/tid=9643] ppid=9628 vsize=879532 CPUtime=0
/proc/9641/task/9643/stat : 9643 (java) S 9628 9627 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 15 0 10 0 875113276 900640768 29006 1283457024 134512640 134550932 4292830912 18446744073709551615 4294960130 0 0 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=9641/tid=9644] ppid=9628 vsize=879532 CPUtime=0
/proc/9641/task/9644/stat : 9644 (java) S 9628 9627 2059 34821 2220 4202560 9 0 0 0 0 0 0 0 25 0 10 0 875113277 900640768 29006 1283457024 134512640 134550932 4292830912 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=9641/tid=9645] ppid=9628 vsize=879532 CPUtime=0
/proc/9641/task/9645/stat : 9645 (java) S 9628 9627 2059 34821 2220 4202560 4 0 0 0 0 0 0 0 25 0 10 0 875113277 900640768 29006 1283457024 134512640 134550932 4292830912 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=9641/tid=9646] ppid=9628 vsize=879532 CPUtime=0
/proc/9641/task/9646/stat : 9646 (java) S 9628 9627 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 10 0 875113279 900640768 29006 1283457024 134512640 134550932 4292830912 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=9641/tid=9647] ppid=9628 vsize=879532 CPUtime=0.93
/proc/9641/task/9647/stat : 9647 (java) S 9628 9627 2059 34821 2220 4202560 5114 0 0 0 92 1 0 0 15 0 10 0 875113279 900640768 29006 1283457024 134512640 134550932 4292830912 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=9641/tid=9648] ppid=9628 vsize=879532 CPUtime=0.99
/proc/9641/task/9648/stat : 9648 (java) R 9628 9627 2059 34821 2220 4202560 6835 0 0 0 98 1 0 0 20 0 10 0 875113279 900640768 29006 1283457024 134512640 134550932 4292830912 18446744073709551615 4148377420 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=9641/tid=9649] ppid=9628 vsize=879532 CPUtime=0
/proc/9641/task/9649/stat : 9649 (java) S 9628 9627 2059 34821 2220 4202560 2 0 0 0 0 0 0 0 25 0 10 0 875113279 900640768 29006 1283457024 134512640 134550932 4292830912 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=9641/tid=9650] ppid=9628 vsize=879532 CPUtime=0
/proc/9641/task/9650/stat : 9650 (java) S 9628 9627 2059 34821 2220 4202560 2 0 0 0 0 0 0 0 15 0 10 0 875113279 900640768 29006 1283457024 134512640 134550932 4292830912 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 2.91
Current children cumulated vsize (KiB) 884684

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

[startup+3.20957 s]
/proc/loadavg: 1.32 1.11 1.09 4/57 9650
/proc/meminfo: memFree=693540/1048576 swapFree=2078740/2097144
[pid=9627] ppid=9626 vsize=2576 CPUtime=0
/proc/9627/stat : 9627 (p2cudf-paranoid) S 9626 9627 2059 34821 2220 4202496 380 0 0 0 0 0 0 0 22 0 1 0 875113270 2637824 274 1283457024 134512640 135304128 4289492208 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/9627/statm: 644 274 233 194 0 30 0
[pid=9628] ppid=9627 vsize=2576 CPUtime=0.03
/proc/9628/stat : 9628 (p2cudf) S 9627 9627 2059 34821 2220 4202496 393 2998 0 1 0 0 2 1 25 0 1 0 875113271 2637824 282 1283457024 134512640 135304128 4287847280 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/9628/statm: 644 282 241 194 0 30 0
[pid=9641] ppid=9628 vsize=879532 CPUtime=2.98
/proc/9641/stat : 9641 (java) S 9628 9627 2059 34821 2220 4202496 36391 0 1 0 284 14 0 0 25 0 10 0 875113274 900640768 30664 1283457024 134512640 134550932 4292830912 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/9641/statm: 219883 30664 1763 10 0 216973 0
[pid=9641/tid=9642] ppid=9628 vsize=879532 CPUtime=1
/proc/9641/task/9642/stat : 9642 (java) R 9628 9627 2059 34821 2220 4202560 23319 0 1 0 88 12 0 0 25 0 10 0 875113275 900640768 30664 1283457024 134512640 134550932 4292830912 18446744073709551615 4095595069 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=9641/tid=9643] ppid=9628 vsize=879532 CPUtime=0
/proc/9641/task/9643/stat : 9643 (java) S 9628 9627 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 15 0 10 0 875113276 900640768 30664 1283457024 134512640 134550932 4292830912 18446744073709551615 4294960130 0 0 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=9641/tid=9644] ppid=9628 vsize=879532 CPUtime=0
/proc/9641/task/9644/stat : 9644 (java) S 9628 9627 2059 34821 2220 4202560 9 0 0 0 0 0 0 0 25 0 10 0 875113277 900640768 30664 1283457024 134512640 134550932 4292830912 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=9641/tid=9645] ppid=9628 vsize=879532 CPUtime=0
/proc/9641/task/9645/stat : 9645 (java) S 9628 9627 2059 34821 2220 4202560 4 0 0 0 0 0 0 0 25 0 10 0 875113277 900640768 30664 1283457024 134512640 134550932 4292830912 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=9641/tid=9646] ppid=9628 vsize=879532 CPUtime=0
/proc/9641/task/9646/stat : 9646 (java) S 9628 9627 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 10 0 875113279 900640768 30664 1283457024 134512640 134550932 4292830912 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=9641/tid=9647] ppid=9628 vsize=879532 CPUtime=0.97
/proc/9641/task/9647/stat : 9647 (java) S 9628 9627 2059 34821 2220 4202560 5122 0 0 0 96 1 0 0 15 0 10 0 875113279 900640768 30664 1283457024 134512640 134550932 4292830912 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=9641/tid=9648] ppid=9628 vsize=879532 CPUtime=0.99
/proc/9641/task/9648/stat : 9648 (java) R 9628 9627 2059 34821 2220 4202560 6835 0 0 0 98 1 0 0 20 0 10 0 875113279 900640768 30664 1283457024 134512640 134550932 4292830912 18446744073709551615 4148377420 0 4 0 16800975 0 0 0 -1 0 0 0 0
[pid=9641/tid=9649] ppid=9628 vsize=879532 CPUtime=0
/proc/9641/task/9649/stat : 9649 (java) S 9628 9627 2059 34821 2220 4202560 2 0 0 0 0 0 0 0 25 0 10 0 875113279 900640768 30664 1283457024 134512640 134550932 4292830912 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=9641/tid=9650] ppid=9628 vsize=879532 CPUtime=0
/proc/9641/task/9650/stat : 9650 (java) S 9628 9627 2059 34821 2220 4202560 2 0 0 0 0 0 0 0 15 0 10 0 875113279 900640768 30664 1283457024 134512640 134550932 4292830912 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.01
Current children cumulated vsize (KiB) 884684

[startup+3.90702 s]
/proc/loadavg: 1.32 1.11 1.09 3/57 9650
/proc/meminfo: memFree=666632/1048576 swapFree=2078740/2097144
[pid=9627] ppid=9626 vsize=2576 CPUtime=0
/proc/9627/stat : 9627 (p2cudf-paranoid) S 9626 9627 2059 34821 2220 4202496 380 0 0 0 0 0 0 0 22 0 1 0 875113270 2637824 274 1283457024 134512640 135304128 4289492208 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/9627/statm: 644 274 233 194 0 30 0
[pid=9628] ppid=9627 vsize=2576 CPUtime=0.03
/proc/9628/stat : 9628 (p2cudf) S 9627 9627 2059 34821 2220 4202496 393 2998 0 1 0 0 2 1 25 0 1 0 875113271 2637824 282 1283457024 134512640 135304128 4287847280 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/9628/statm: 644 282 241 194 0 30 0
[pid=9641] ppid=9628 vsize=880180 CPUtime=3.55
/proc/9641/stat : 9641 (java) S 9628 9627 2059 34821 2220 4202496 38386 0 1 0 341 14 0 0 25 0 11 0 875113274 901304320 32659 1283457024 134512640 134550932 4292830912 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/9641/statm: 220045 32659 1784 10 0 217135 0
[pid=9641/tid=9642] ppid=9628 vsize=880180 CPUtime=1.17
/proc/9641/task/9642/stat : 9642 (java) S 9628 9627 2059 34821 2220 4202560 25243 0 1 0 105 12 0 0 25 0 11 0 875113275 901304320 32659 1283457024 134512640 134550932 4292830912 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=9641/tid=9643] ppid=9628 vsize=880180 CPUtime=0
/proc/9641/task/9643/stat : 9643 (java) S 9628 9627 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 15 0 11 0 875113276 901304320 32659 1283457024 134512640 134550932 4292830912 18446744073709551615 4294960130 0 0 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=9641/tid=9644] ppid=9628 vsize=880180 CPUtime=0
/proc/9641/task/9644/stat : 9644 (java) S 9628 9627 2059 34821 2220 4202560 9 0 0 0 0 0 0 0 25 0 11 0 875113277 901304320 32659 1283457024 134512640 134550932 4292830912 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=9641/tid=9645] ppid=9628 vsize=880180 CPUtime=0
/proc/9641/task/9645/stat : 9645 (java) S 9628 9627 2059 34821 2220 4202560 4 0 0 0 0 0 0 0 25 0 11 0 875113277 901304320 32659 1283457024 134512640 134550932 4292830912 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=9641/tid=9646] ppid=9628 vsize=880180 CPUtime=0
/proc/9641/task/9646/stat : 9646 (java) S 9628 9627 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 11 0 875113279 901304320 32659 1283457024 134512640 134550932 4292830912 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=9641/tid=9647] ppid=9628 vsize=880180 CPUtime=1.11
/proc/9641/task/9647/stat : 9647 (java) S 9628 9627 2059 34821 2220 4202560 5141 0 0 0 110 1 0 0 15 0 11 0 875113279 901304320 32659 1283457024 134512640 134550932 4292830912 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=9641/tid=9648] ppid=9628 vsize=880180 CPUtime=1.26
/proc/9641/task/9648/stat : 9648 (java) S 9628 9627 2059 34821 2220 4202560 6879 0 0 0 125 1 0 0 20 0 11 0 875113279 901304320 32659 1283457024 134512640 134550932 4292830912 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=9641/tid=9649] ppid=9628 vsize=880180 CPUtime=0
/proc/9641/task/9649/stat : 9649 (java) S 9628 9627 2059 34821 2220 4202560 2 0 0 0 0 0 0 0 25 0 11 0 875113279 901304320 32659 1283457024 134512640 134550932 4292830912 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=9641/tid=9650] ppid=9628 vsize=880180 CPUtime=0
/proc/9641/task/9650/stat : 9650 (java) R 9628 9627 2059 34821 2220 4202560 2 0 0 0 0 0 0 0 15 0 11 0 875113279 901304320 32659 1283457024 134512640 134550932 4292830912 18446744073709551615 4294960130 0 4 0 16800975 0 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.58
Current children cumulated vsize (KiB) 885332

[startup+4.31511 s]
/proc/loadavg: 1.21 1.09 1.08 2/58 9653
/proc/meminfo: memFree=663400/1048576 swapFree=2078740/2097144
[pid=9627] ppid=9626 vsize=2576 CPUtime=0
/proc/9627/stat : 9627 (p2cudf-paranoid) S 9626 9627 2059 34821 2220 4202496 380 0 0 0 0 0 0 0 22 0 1 0 875113270 2637824 274 1283457024 134512640 135304128 4289492208 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/9627/statm: 644 274 233 194 0 30 0
[pid=9628] ppid=9627 vsize=2576 CPUtime=0.03
/proc/9628/stat : 9628 (p2cudf) S 9627 9627 2059 34821 2220 4202496 393 2998 0 1 0 0 2 1 25 0 1 0 875113271 2637824 282 1283457024 134512640 135304128 4287847280 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/9628/statm: 644 282 241 194 0 30 0
[pid=9641] ppid=9628 vsize=880180 CPUtime=3.57
/proc/9641/stat : 9641 (java) S 9628 9627 2059 34821 2220 4202496 38394 0 1 0 343 14 0 0 25 0 11 0 875113274 901304320 32667 1283457024 134512640 134550932 4292830912 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/9641/statm: 220045 32667 1784 10 0 217135 0
[pid=9641/tid=9642] ppid=9628 vsize=880180 CPUtime=1.17
/proc/9641/task/9642/stat : 9642 (java) S 9628 9627 2059 34821 2220 4202560 25243 0 1 0 105 12 0 0 25 0 11 0 875113275 901304320 32667 1283457024 134512640 134550932 4292830912 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=9641/tid=9643] ppid=9628 vsize=880180 CPUtime=0
/proc/9641/task/9643/stat : 9643 (java) S 9628 9627 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 15 0 11 0 875113276 901304320 32667 1283457024 134512640 134550932 4292830912 18446744073709551615 4294960130 0 0 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=9641/tid=9644] ppid=9628 vsize=880180 CPUtime=0
/proc/9641/task/9644/stat : 9644 (java) S 9628 9627 2059 34821 2220 4202560 9 0 0 0 0 0 0 0 25 0 11 0 875113277 901304320 32667 1283457024 134512640 134550932 4292830912 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=9641/tid=9645] ppid=9628 vsize=880180 CPUtime=0
/proc/9641/task/9645/stat : 9645 (java) S 9628 9627 2059 34821 2220 4202560 4 0 0 0 0 0 0 0 25 0 11 0 875113277 901304320 32667 1283457024 134512640 134550932 4292830912 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=9641/tid=9646] ppid=9628 vsize=880180 CPUtime=0
/proc/9641/task/9646/stat : 9646 (java) S 9628 9627 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 11 0 875113279 901304320 32667 1283457024 134512640 134550932 4292830912 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=9641/tid=9647] ppid=9628 vsize=880180 CPUtime=1.11
/proc/9641/task/9647/stat : 9647 (java) S 9628 9627 2059 34821 2220 4202560 5141 0 0 0 110 1 0 0 15 0 11 0 875113279 901304320 32667 1283457024 134512640 134550932 4292830912 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=9641/tid=9648] ppid=9628 vsize=880180 CPUtime=1.27
/proc/9641/task/9648/stat : 9648 (java) S 9628 9627 2059 34821 2220 4202560 6880 0 0 0 126 1 0 0 15 0 11 0 875113279 901304320 32667 1283457024 134512640 134550932 4292830912 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=9641/tid=9649] ppid=9628 vsize=880180 CPUtime=0
/proc/9641/task/9649/stat : 9649 (java) S 9628 9627 2059 34821 2220 4202560 2 0 0 0 0 0 0 0 25 0 11 0 875113279 901304320 32667 1283457024 134512640 134550932 4292830912 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=9641/tid=9650] ppid=9628 vsize=880180 CPUtime=0
/proc/9641/task/9650/stat : 9650 (java) S 9628 9627 2059 34821 2220 4202560 2 0 0 0 0 0 0 0 15 0 11 0 875113279 901304320 32667 1283457024 134512640 134550932 4292830912 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=9641/tid=9653] ppid=9628 vsize=880180 CPUtime=0.01
/proc/9641/task/9653/stat : 9653 (java) R 9628 9627 2059 34821 2220 4202560 11 0 0 0 1 0 0 0 20 0 11 0 875113648 901304320 32667 1283457024 134512640 134550932 4292830912 18446744073709551615 4095593639 0 4 0 16800975 0 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.6
Current children cumulated vsize (KiB) 885332

[startup+4.40711 s]
/proc/loadavg: 1.21 1.09 1.08 2/58 9653
/proc/meminfo: memFree=663400/1048576 swapFree=2078740/2097144
[pid=9627] ppid=9626 vsize=2576 CPUtime=0
/proc/9627/stat : 9627 (p2cudf-paranoid) S 9626 9627 2059 34821 2220 4202496 380 0 0 0 0 0 0 0 22 0 1 0 875113270 2637824 274 1283457024 134512640 135304128 4289492208 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/9627/statm: 644 274 233 194 0 30 0
[pid=9628] ppid=9627 vsize=2576 CPUtime=0.03
/proc/9628/stat : 9628 (p2cudf) S 9627 9627 2059 34821 2220 4202496 393 2998 0 1 0 0 2 1 25 0 1 0 875113271 2637824 282 1283457024 134512640 135304128 4287847280 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/9628/statm: 644 282 241 194 0 30 0
[pid=9641] ppid=9628 vsize=880180 CPUtime=3.64
/proc/9641/stat : 9641 (java) S 9628 9627 2059 34821 2220 4202496 38536 0 1 0 348 16 0 0 25 0 10 0 875113274 901304320 32809 1283457024 134512640 134550932 4292830912 18446744073709551615 4294960130 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0
/proc/9641/statm: 220045 32809 1784 10 0 217135 0
[pid=9641/tid=9642] ppid=9628 vsize=880180 CPUtime=1.17
/proc/9641/task/9642/stat : 9642 (java) S 9628 9627 2059 34821 2220 4202560 25243 0 1 0 105 12 0 0 19 0 10 0 875113275 901304320 32809 1283457024 134512640 134550932 4292830912 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=9641/tid=9643] ppid=9628 vsize=880180 CPUtime=0
/proc/9641/task/9643/stat : 9643 (java) S 9628 9627 2059 34821 2220 4202560 5 0 0 0 0 0 0 0 15 0 10 0 875113276 901304320 32809 1283457024 134512640 134550932 4292830912 18446744073709551615 4294960130 0 0 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=9641/tid=9644] ppid=9628 vsize=880180 CPUtime=0
/proc/9641/task/9644/stat : 9644 (java) S 9628 9627 2059 34821 2220 4202560 9 0 0 0 0 0 0 0 25 0 10 0 875113277 901304320 32809 1283457024 134512640 134550932 4292830912 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=9641/tid=9645] ppid=9628 vsize=880180 CPUtime=0
/proc/9641/task/9645/stat : 9645 (java) S 9628 9627 2059 34821 2220 4202560 4 0 0 0 0 0 0 0 25 0 10 0 875113277 901304320 32809 1283457024 134512640 134550932 4292830912 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=9641/tid=9646] ppid=9628 vsize=880180 CPUtime=0
/proc/9641/task/9646/stat : 9646 (java) S 9628 9627 2059 34821 2220 4202560 1 0 0 0 0 0 0 0 25 0 10 0 875113279 901304320 32809 1283457024 134512640 134550932 4292830912 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=9641/tid=9647] ppid=9628 vsize=880180 CPUtime=1.11
/proc/9641/task/9647/stat : 9647 (java) S 9628 9627 2059 34821 2220 4202560 5141 0 0 0 110 1 0 0 15 0 10 0 875113279 901304320 32809 1283457024 134512640 134550932 4292830912 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=9641/tid=9648] ppid=9628 vsize=880180 CPUtime=1.29
/proc/9641/task/9648/stat : 9648 (java) S 9628 9627 2059 34821 2220 4202560 6882 0 0 0 128 1 0 0 16 0 10 0 875113279 901304320 32809 1283457024 134512640 134550932 4292830912 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=9641/tid=9649] ppid=9628 vsize=880180 CPUtime=0
/proc/9641/task/9649/stat : 9649 (java) S 9628 9627 2059 34821 2220 4202560 2 0 0 0 0 0 0 0 25 0 10 0 875113279 901304320 32809 1283457024 134512640 134550932 4292830912 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
[pid=9641/tid=9650] ppid=9628 vsize=880180 CPUtime=0
/proc/9641/task/9650/stat : 9650 (java) S 9628 9627 2059 34821 2220 4202560 2 0 0 0 0 0 0 0 15 0 10 0 875113279 901304320 32809 1283457024 134512640 134550932 4292830912 18446744073709551615 4294960130 0 4 0 16800975 18446612133359097920 0 0 -1 0 0 0 0
Current children cumulated CPU time (s) 3.67
Current children cumulated vsize (KiB) 885332

Child status: 0
Real time (s): 4.43036
CPU time (s): 3.70023
CPU user time (s): 3.50822
CPU system time (s): 0.192012
CPU usage (%): 83.5199
Max. virtual memory (cumulated for all children) (KiB): 890716

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 3.50822
system time used= 0.192012
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 42331
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= 669
involuntary context switches= 658

runsolver used 0 second user time and 0 second system time

The end