runsolver Copyright (C) 2010 Olivier ROUSSEL

This is runsolver version 3.2.9a (svn: 651)

This program is distributed in the hope that it will be useful,
but WITHOUT ANY WARRANTY; without even the implied warranty of
MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
GNU General Public License for more details.

command line: runsolver -s SIGUSR1 -M 1124 -C 300 -d 10 -w /tmp/misc2012/2012-09-02-22:42/full/p2cudf-full-1.15/trendy-size/upgrade/easy/rand261.cudf.log.runsolver /home/competition/p2cudf-full-1.15/p2cudf-full-1.15 /home/competition/data/upgrade/easy/rand261.cudf /tmp/misc2012/2012-09-02-22:42/full/p2cudf-full-1.15/trendy-size/upgrade/easy/rand261.cudf.result -count(removed),-sum(solution,installedsize),-notuptodate(solution),-unsat_recommends(solution),-count(new) 

Enforcing CPUTime limit (soft limit, will send signal-name then SIGKILL): 300 seconds
Enforcing CPUTime limit (hard limit, will send SIGXCPU): 330 seconds
Enforcing VSIZE limit (soft limit, will send signal-name then SIGKILL): 1150976 KiB
Enforcing VSIZE limit (hard limit, stack expansion will fail with SIGSEGV, brk() and mmap() will return ENOMEM): 1202176 KiB
Current StackSize limit: 8192 KiB


[startup+0 s]
/proc/loadavg: 1.85 1.42 1.19 2/59 3390
/proc/meminfo: memFree=449244/1022884 swapFree=0/0
[pid=3390] ppid=3389 vsize=9144 CPUtime=0
/proc/3390/stat : 3390 (p2cudf-full-1.1) R 3389 3390 1733 0 -1 4202496 182 0 0 0 0 0 0 0 20 0 1 0 119862907 9363456 103 18446744073709551615 4194304 5129932 140735174403328 140735174402784 140607989461115 0 0 16781316 0 0 0 0 17 0 0 0 0 0 0
/proc/3390/statm: 2286 103 82 229 0 40 0

[startup+0.200345 s]
/proc/loadavg: 1.85 1.42 1.19 2/59 3390
/proc/meminfo: memFree=449244/1022884 swapFree=0/0
[pid=3390] ppid=3389 vsize=9168 CPUtime=0
/proc/3390/stat : 3390 (p2cudf-full-1.1) S 3389 3390 1733 0 -1 4202496 454 291 0 0 0 0 0 0 20 0 1 0 119862907 9388032 330 18446744073709551615 4194304 5129932 140735174403328 140735174401472 140607982040158 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/3390/statm: 2292 330 280 229 0 52 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 9168

[startup+0.300309 s]
/proc/loadavg: 1.85 1.42 1.19 2/59 3390
/proc/meminfo: memFree=449244/1022884 swapFree=0/0
[pid=3390] ppid=3389 vsize=9168 CPUtime=0
/proc/3390/stat : 3390 (p2cudf-full-1.1) S 3389 3390 1733 0 -1 4202496 454 291 0 0 0 0 0 0 20 0 1 0 119862907 9388032 330 18446744073709551615 4194304 5129932 140735174403328 140735174401472 140607982040158 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/3390/statm: 2292 330 280 229 0 52 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 9168

[startup+0.400346 s]
/proc/loadavg: 1.85 1.42 1.19 2/59 3390
/proc/meminfo: memFree=449244/1022884 swapFree=0/0
[pid=3390] ppid=3389 vsize=9168 CPUtime=0
/proc/3390/stat : 3390 (p2cudf-full-1.1) S 3389 3390 1733 0 -1 4202496 454 291 0 0 0 0 0 0 20 0 1 0 119862907 9388032 330 18446744073709551615 4194304 5129932 140735174403328 140735174401472 140607982040158 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/3390/statm: 2292 330 280 229 0 52 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 9168

[startup+0.700231 s]
/proc/loadavg: 1.85 1.42 1.19 2/59 3390
/proc/meminfo: memFree=449244/1022884 swapFree=0/0
[pid=3390] ppid=3389 vsize=9168 CPUtime=0
/proc/3390/stat : 3390 (p2cudf-full-1.1) S 3389 3390 1733 0 -1 4202496 454 291 0 0 0 0 0 0 20 0 1 0 119862907 9388032 330 18446744073709551615 4194304 5129932 140735174403328 140735174401472 140607982040158 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/3390/statm: 2292 330 280 229 0 52 0
Current children cumulated CPU time (s) 0
Current children cumulated vsize (KiB) 9168

[startup+1.50078 s]
/proc/loadavg: 1.85 1.42 1.19 4/70 3402
/proc/meminfo: memFree=396820/1022884 swapFree=0/0
[pid=3390] ppid=3389 vsize=9168 CPUtime=0
/proc/3390/stat : 3390 (p2cudf-full-1.1) S 3389 3390 1733 0 -1 4202496 454 291 0 0 0 0 0 0 20 0 1 0 119862907 9388032 330 18446744073709551615 4194304 5129932 140735174403328 140735174401472 140607982040158 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/3390/statm: 2292 330 280 229 0 52 0
[pid=3393] ppid=3390 vsize=1060412 CPUtime=1.43
/proc/3393/stat : 3393 (java) S 3390 3390 1733 0 -1 4202496 31063 0 0 0 133 10 0 0 20 0 10 0 119862908 1085861888 27882 18446744073709551615 4194304 4228012 140735790323280 140735790314304 139747768872565 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/3393/statm: 265103 27882 2348 9 0 252453 0
[pid=3393/tid=3394] ppid=3390 vsize=1060412 CPUtime=0.67
/proc/3393/task/3394/stat : 3394 (java) R 3390 3390 1733 0 -1 4202560 13251 0 0 0 61 6 0 0 20 0 10 0 119862909 1085861888 27882 18446744073709551615 4194304 4228012 140735790323280 139747775398560 139747673276440 0 4 0 16800975 0 0 0 -1 0 0 0 3 0 0
[pid=3393/tid=3395] ppid=3390 vsize=1060412 CPUtime=0
/proc/3393/task/3395/stat : 3395 (java) S 3390 3390 1733 0 -1 4202560 4 0 0 0 0 0 0 0 20 0 10 0 119862911 1085861888 27882 18446744073709551615 4194304 4228012 140735790323280 139747668044928 139747768886859 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3393/tid=3396] ppid=3390 vsize=1060412 CPUtime=0
/proc/3393/task/3396/stat : 3396 (java) S 3390 3390 1733 0 -1 4202560 15 0 0 0 0 0 0 0 20 0 10 0 119862912 1085861888 27882 18446744073709551615 4194304 4228012 140735790323280 139747666991120 139747768885972 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3393/tid=3397] ppid=3390 vsize=1060412 CPUtime=0
/proc/3393/task/3397/stat : 3397 (java) S 3390 3390 1733 0 -1 4202560 6 0 0 0 0 0 0 0 20 0 10 0 119862912 1085861888 27882 18446744073709551615 4194304 4228012 140735790323280 139747665938336 139747768885972 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3393/tid=3398] ppid=3390 vsize=1060412 CPUtime=0
/proc/3393/task/3398/stat : 3398 (java) S 3390 3390 1733 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 10 0 119862916 1085861888 27882 18446744073709551615 4194304 4228012 140735790323280 139747664886768 139747768894496 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3393/tid=3399] ppid=3390 vsize=1060412 CPUtime=0.38
/proc/3393/task/3399/stat : 3399 (java) R 3390 3390 1733 0 -1 4202560 8741 0 0 0 36 2 0 0 20 0 10 0 119862916 1085861888 27882 18446744073709551615 4194304 4228012 140735790323280 139747663819480 139747755381359 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3393/tid=3400] ppid=3390 vsize=1060412 CPUtime=0.36
/proc/3393/task/3400/stat : 3400 (java) R 3390 3390 1733 0 -1 4202560 7779 0 0 0 34 2 0 0 20 0 10 0 119862916 1085861888 27882 18446744073709551615 4194304 4228012 140735790323280 139747662766664 139747754545553 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3393/tid=3401] ppid=3390 vsize=1060412 CPUtime=0
/proc/3393/task/3401/stat : 3401 (java) S 3390 3390 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 119862916 1085861888 27882 18446744073709551615 4194304 4228012 140735790323280 139747661728976 139747768885972 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3393/tid=3402] ppid=3390 vsize=1060412 CPUtime=0
/proc/3393/task/3402/stat : 3402 (java) S 3390 3390 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 119862916 1085861888 27882 18446744073709551615 4194304 4228012 140735790323280 139747660676480 139747768886859 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 1.43
Current children cumulated vsize (KiB) 1069580

[startup+3.1008 s]
/proc/loadavg: 1.85 1.42 1.19 4/70 3402
/proc/meminfo: memFree=300464/1022884 swapFree=0/0
[pid=3390] ppid=3389 vsize=9168 CPUtime=0
/proc/3390/stat : 3390 (p2cudf-full-1.1) S 3389 3390 1733 0 -1 4202496 454 291 0 0 0 0 0 0 20 0 1 0 119862907 9388032 330 18446744073709551615 4194304 5129932 140735174403328 140735174401472 140607982040158 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/3390/statm: 2292 330 280 229 0 52 0
[pid=3393] ppid=3390 vsize=1062660 CPUtime=3.02
/proc/3393/stat : 3393 (java) S 3390 3390 1733 0 -1 4202496 76360 0 0 0 274 28 0 0 20 0 10 0 119862908 1088163840 71074 18446744073709551615 4194304 4228012 140735790323280 140735790314304 139747768872565 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/3393/statm: 265665 71074 2368 9 0 253015 0
[pid=3393/tid=3394] ppid=3390 vsize=1062660 CPUtime=1.48
/proc/3393/task/3394/stat : 3394 (java) R 3390 3390 1733 0 -1 4202560 47423 0 0 0 130 18 0 0 20 0 10 0 119862909 1088163840 71074 18446744073709551615 4194304 4228012 140735790323280 139747775398592 139747673214508 0 4 0 16800975 0 0 0 -1 0 0 0 3 0 0
[pid=3393/tid=3395] ppid=3390 vsize=1062660 CPUtime=0.17
/proc/3393/task/3395/stat : 3395 (java) S 3390 3390 1733 0 -1 4202560 7957 0 0 0 14 3 0 0 20 0 10 0 119862911 1088163840 71074 18446744073709551615 4194304 4228012 140735790323280 139747668044928 139747768886859 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3393/tid=3396] ppid=3390 vsize=1062660 CPUtime=0
/proc/3393/task/3396/stat : 3396 (java) S 3390 3390 1733 0 -1 4202560 16 0 0 0 0 0 0 0 20 0 10 0 119862912 1088163840 71074 18446744073709551615 4194304 4228012 140735790323280 139747666991120 139747768885972 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3393/tid=3397] ppid=3390 vsize=1062660 CPUtime=0
/proc/3393/task/3397/stat : 3397 (java) S 3390 3390 1733 0 -1 4202560 9 0 0 0 0 0 0 0 20 0 10 0 119862912 1088163840 71074 18446744073709551615 4194304 4228012 140735790323280 139747665938336 139747768885972 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3393/tid=3398] ppid=3390 vsize=1062660 CPUtime=0
/proc/3393/task/3398/stat : 3398 (java) S 3390 3390 1733 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 10 0 119862916 1088163840 71074 18446744073709551615 4194304 4228012 140735790323280 139747664886768 139747768894496 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3393/tid=3399] ppid=3390 vsize=1062660 CPUtime=0.64
/proc/3393/task/3399/stat : 3399 (java) S 3390 3390 1733 0 -1 4202560 11345 0 0 0 62 2 0 0 20 0 10 0 119862916 1088163840 71074 18446744073709551615 4194304 4228012 140735790323280 139747663834128 139747768885972 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3393/tid=3400] ppid=3390 vsize=1062660 CPUtime=0.69
/proc/3393/task/3400/stat : 3400 (java) S 3390 3390 1733 0 -1 4202560 8343 0 0 0 66 3 0 0 20 0 10 0 119862916 1088163840 71074 18446744073709551615 4194304 4228012 140735790323280 139747662781456 139747768885972 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3393/tid=3401] ppid=3390 vsize=1062660 CPUtime=0
/proc/3393/task/3401/stat : 3401 (java) S 3390 3390 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 119862916 1088163840 71074 18446744073709551615 4194304 4228012 140735790323280 139747661728976 139747768885972 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3393/tid=3402] ppid=3390 vsize=1062660 CPUtime=0
/proc/3393/task/3402/stat : 3402 (java) S 3390 3390 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 119862916 1088163840 71074 18446744073709551615 4194304 4228012 140735790323280 139747660676480 139747768886859 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 3.02
Current children cumulated vsize (KiB) 1071828

[startup+6.30056 s]
/proc/loadavg: 1.78 1.42 1.19 2/70 3402
/proc/meminfo: memFree=20680/1022884 swapFree=0/0
[pid=3390] ppid=3389 vsize=9168 CPUtime=0
/proc/3390/stat : 3390 (p2cudf-full-1.1) S 3389 3390 1733 0 -1 4202496 454 291 0 0 0 0 0 0 20 0 1 0 119862907 9388032 330 18446744073709551615 4194304 5129932 140735174403328 140735174401472 140607982040158 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/3390/statm: 2292 330 280 229 0 52 0
[pid=3393] ppid=3390 vsize=1044232 CPUtime=6.14
/proc/3393/stat : 3393 (java) S 3390 3390 1733 0 -1 4202496 113846 0 0 0 570 44 0 0 20 0 10 0 119862908 1069293568 104264 18446744073709551615 4194304 4228012 140735790323280 140735790314304 139747768872565 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/3393/statm: 261058 104264 2370 9 0 248408 0
[pid=3393/tid=3394] ppid=3390 vsize=1044232 CPUtime=3.33
/proc/3393/task/3394/stat : 3394 (java) R 3390 3390 1733 0 -1 4202560 47492 0 0 0 313 20 0 0 20 0 10 0 119862909 1069293568 104264 18446744073709551615 4194304 4228012 140735790323280 139747775406528 139747673609812 0 4 0 16800975 0 0 0 -1 0 0 0 6 0 0
[pid=3393/tid=3395] ppid=3390 vsize=1044232 CPUtime=1.07
/proc/3393/task/3395/stat : 3395 (java) S 3390 3390 1733 0 -1 4202560 45257 0 0 0 90 17 0 0 20 0 10 0 119862911 1069293568 104264 18446744073709551615 4194304 4228012 140735790323280 139747668044928 139747768886859 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3393/tid=3396] ppid=3390 vsize=1044232 CPUtime=0
/proc/3393/task/3396/stat : 3396 (java) S 3390 3390 1733 0 -1 4202560 16 0 0 0 0 0 0 0 20 0 10 0 119862912 1069293568 104264 18446744073709551615 4194304 4228012 140735790323280 139747666991120 139747768885972 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3393/tid=3397] ppid=3390 vsize=1044232 CPUtime=0
/proc/3393/task/3397/stat : 3397 (java) S 3390 3390 1733 0 -1 4202560 9 0 0 0 0 0 0 0 20 0 10 0 119862912 1069293568 104264 18446744073709551615 4194304 4228012 140735790323280 139747665938336 139747768885972 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3393/tid=3398] ppid=3390 vsize=1044232 CPUtime=0
/proc/3393/task/3398/stat : 3398 (java) S 3390 3390 1733 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 10 0 119862916 1069293568 104264 18446744073709551615 4194304 4228012 140735790323280 139747664886768 139747768894496 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3393/tid=3399] ppid=3390 vsize=1044232 CPUtime=0.83
/proc/3393/task/3399/stat : 3399 (java) R 3390 3390 1733 0 -1 4202560 11445 0 0 0 80 3 0 0 20 0 10 0 119862916 1069293568 104264 18446744073709551615 4194304 4228012 140735790323280 139747663833872 139747752015114 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3393/tid=3400] ppid=3390 vsize=1044232 CPUtime=0.88
/proc/3393/task/3400/stat : 3400 (java) R 3390 3390 1733 0 -1 4202560 8360 0 0 0 85 3 0 0 20 0 10 0 119862916 1069293568 104264 18446744073709551615 4194304 4228012 140735790323280 139747662781200 139747751980224 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3393/tid=3401] ppid=3390 vsize=1044232 CPUtime=0
/proc/3393/task/3401/stat : 3401 (java) S 3390 3390 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 119862916 1069293568 104264 18446744073709551615 4194304 4228012 140735790323280 139747661728976 139747768885972 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3393/tid=3402] ppid=3390 vsize=1044232 CPUtime=0
/proc/3393/task/3402/stat : 3402 (java) S 3390 3390 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 119862916 1069293568 104264 18446744073709551615 4194304 4228012 140735790323280 139747660676480 139747768886859 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 6.14
Current children cumulated vsize (KiB) 1053400

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

[startup+6.50057 s]
/proc/loadavg: 1.78 1.42 1.19 2/70 3402
/proc/meminfo: memFree=20680/1022884 swapFree=0/0
[pid=3390] ppid=3389 vsize=9168 CPUtime=0
/proc/3390/stat : 3390 (p2cudf-full-1.1) S 3389 3390 1733 0 -1 4202496 454 291 0 0 0 0 0 0 20 0 1 0 119862907 9388032 330 18446744073709551615 4194304 5129932 140735174403328 140735174401472 140607982040158 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/3390/statm: 2292 330 280 229 0 52 0
[pid=3393] ppid=3390 vsize=1044232 CPUtime=6.34
/proc/3393/stat : 3393 (java) S 3390 3390 1733 0 -1 4202496 114171 0 0 0 590 44 0 0 20 0 10 0 119862908 1069293568 104589 18446744073709551615 4194304 4228012 140735790323280 140735790314304 139747768872565 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/3393/statm: 261058 104589 2370 9 0 248408 0
[pid=3393/tid=3394] ppid=3390 vsize=1044232 CPUtime=3.38
/proc/3393/task/3394/stat : 3394 (java) S 3390 3390 1733 0 -1 4202560 47493 0 0 0 318 20 0 0 20 0 10 0 119862909 1069293568 104589 18446744073709551615 4194304 4228012 140735790323280 139747775406384 139747768885972 0 4 0 16800975 0 0 0 -1 0 0 0 6 0 0
[pid=3393/tid=3395] ppid=3390 vsize=1044232 CPUtime=1.13
/proc/3393/task/3395/stat : 3395 (java) R 3390 3390 1733 0 -1 4202560 45566 0 0 0 96 17 0 0 20 0 10 0 119862911 1069293568 104589 18446744073709551615 4194304 4228012 140735790323280 139747668044304 139747753183353 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3393/tid=3396] ppid=3390 vsize=1044232 CPUtime=0
/proc/3393/task/3396/stat : 3396 (java) S 3390 3390 1733 0 -1 4202560 16 0 0 0 0 0 0 0 20 0 10 0 119862912 1069293568 104589 18446744073709551615 4194304 4228012 140735790323280 139747666991120 139747768885972 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3393/tid=3397] ppid=3390 vsize=1044232 CPUtime=0
/proc/3393/task/3397/stat : 3397 (java) S 3390 3390 1733 0 -1 4202560 9 0 0 0 0 0 0 0 20 0 10 0 119862912 1069293568 104589 18446744073709551615 4194304 4228012 140735790323280 139747665938336 139747768885972 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3393/tid=3398] ppid=3390 vsize=1044232 CPUtime=0
/proc/3393/task/3398/stat : 3398 (java) S 3390 3390 1733 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 10 0 119862916 1069293568 104589 18446744073709551615 4194304 4228012 140735790323280 139747664886768 139747768894496 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3393/tid=3399] ppid=3390 vsize=1044232 CPUtime=0.86
/proc/3393/task/3399/stat : 3399 (java) S 3390 3390 1733 0 -1 4202560 11454 0 0 0 83 3 0 0 20 0 10 0 119862916 1069293568 104589 18446744073709551615 4194304 4228012 140735790323280 139747663834128 139747768885972 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3393/tid=3400] ppid=3390 vsize=1044232 CPUtime=0.93
/proc/3393/task/3400/stat : 3400 (java) S 3390 3390 1733 0 -1 4202560 8366 0 0 0 90 3 0 0 20 0 10 0 119862916 1069293568 104589 18446744073709551615 4194304 4228012 140735790323280 139747662768432 139747768885972 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3393/tid=3401] ppid=3390 vsize=1044232 CPUtime=0
/proc/3393/task/3401/stat : 3401 (java) S 3390 3390 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 119862916 1069293568 104589 18446744073709551615 4194304 4228012 140735790323280 139747661728976 139747768885972 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3393/tid=3402] ppid=3390 vsize=1044232 CPUtime=0
/proc/3393/task/3402/stat : 3402 (java) S 3390 3390 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 119862916 1069293568 104589 18446744073709551615 4194304 4228012 140735790323280 139747660676480 139747768886859 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 6.34
Current children cumulated vsize (KiB) 1053400

[startup+9.70073 s]
/proc/loadavg: 1.78 1.42 1.19 4/70 3402
/proc/meminfo: memFree=9960/1022884 swapFree=0/0
[pid=3390] ppid=3389 vsize=9168 CPUtime=0
/proc/3390/stat : 3390 (p2cudf-full-1.1) S 3389 3390 1733 0 -1 4202496 454 291 0 0 0 0 0 0 20 0 1 0 119862907 9388032 330 18446744073709551615 4194304 5129932 140735174403328 140735174401472 140607982040158 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/3390/statm: 2292 330 280 229 0 52 0
[pid=3393] ppid=3390 vsize=1044232 CPUtime=9.43
/proc/3393/stat : 3393 (java) S 3390 3390 1733 0 -1 4202496 125705 0 0 0 895 48 0 0 20 0 10 0 119862908 1069293568 112929 18446744073709551615 4194304 4228012 140735790323280 140735790314304 139747768872565 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/3393/statm: 261058 112929 2375 9 0 248408 0
[pid=3393/tid=3394] ppid=3390 vsize=1044232 CPUtime=4.56
/proc/3393/task/3394/stat : 3394 (java) R 3390 3390 1733 0 -1 4202560 47739 0 0 0 436 20 0 0 20 0 10 0 119862909 1069293568 112929 18446744073709551615 4194304 4228012 140735790323280 139747775407344 139747672918679 0 4 0 16800975 0 0 0 -1 0 0 0 6 0 0
[pid=3393/tid=3395] ppid=3390 vsize=1044232 CPUtime=1.28
/proc/3393/task/3395/stat : 3395 (java) R 3390 3390 1733 0 -1 4202560 53196 0 0 0 108 20 0 0 20 0 10 0 119862911 1069293568 112929 18446744073709551615 4194304 4228012 140735790323280 139747668045128 139747761648887 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3393/tid=3396] ppid=3390 vsize=1044232 CPUtime=0
/proc/3393/task/3396/stat : 3396 (java) S 3390 3390 1733 0 -1 4202560 16 0 0 0 0 0 0 0 20 0 10 0 119862912 1069293568 112929 18446744073709551615 4194304 4228012 140735790323280 139747666991120 139747768885972 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3393/tid=3397] ppid=3390 vsize=1044232 CPUtime=0
/proc/3393/task/3397/stat : 3397 (java) S 3390 3390 1733 0 -1 4202560 9 0 0 0 0 0 0 0 20 0 10 0 119862912 1069293568 112929 18446744073709551615 4194304 4228012 140735790323280 139747665938336 139747768885972 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3393/tid=3398] ppid=3390 vsize=1044232 CPUtime=0
/proc/3393/task/3398/stat : 3398 (java) S 3390 3390 1733 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 10 0 119862916 1069293568 112929 18446744073709551615 4194304 4228012 140735790323280 139747664886768 139747768894496 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3393/tid=3399] ppid=3390 vsize=1044232 CPUtime=1.8
/proc/3393/task/3399/stat : 3399 (java) R 3390 3390 1733 0 -1 4202560 15025 0 0 0 176 4 0 0 20 0 10 0 119862916 1069293568 112929 18446744073709551615 4194304 4228012 140735790323280 139747663833872 139747756209585 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3393/tid=3400] ppid=3390 vsize=1044232 CPUtime=1.76
/proc/3393/task/3400/stat : 3400 (java) R 3390 3390 1733 0 -1 4202560 8453 0 0 0 173 3 0 0 20 0 10 0 119862916 1069293568 112929 18446744073709551615 4194304 4228012 140735790323280 139747662781200 139747755562691 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3393/tid=3401] ppid=3390 vsize=1044232 CPUtime=0
/proc/3393/task/3401/stat : 3401 (java) S 3390 3390 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 119862916 1069293568 112929 18446744073709551615 4194304 4228012 140735790323280 139747661728976 139747768885972 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3393/tid=3402] ppid=3390 vsize=1044232 CPUtime=0
/proc/3393/task/3402/stat : 3402 (java) S 3390 3390 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 10 0 119862916 1069293568 112929 18446744073709551615 4194304 4228012 140735790323280 139747660676480 139747768886859 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 9.43
Current children cumulated vsize (KiB) 1053400

[startup+11.3006 s]
/proc/loadavg: 1.88 1.44 1.20 3/71 3403
/proc/meminfo: memFree=15408/1022884 swapFree=0/0
[pid=3390] ppid=3389 vsize=9168 CPUtime=0
/proc/3390/stat : 3390 (p2cudf-full-1.1) S 3389 3390 1733 0 -1 4202496 454 291 0 0 0 0 0 0 20 0 1 0 119862907 9388032 330 18446744073709551615 4194304 5129932 140735174403328 140735174401472 140607982040158 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/3390/statm: 2292 330 280 229 0 52 0
[pid=3393] ppid=3390 vsize=1045260 CPUtime=11
/proc/3393/stat : 3393 (java) S 3390 3390 1733 0 -1 4202496 125814 0 0 0 1051 49 0 0 20 0 11 0 119862908 1070346240 112726 18446744073709551615 4194304 4228012 140735790323280 140735790314304 139747768872565 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/3393/statm: 261315 112726 2380 9 0 248665 0
[pid=3393/tid=3394] ppid=3390 vsize=1045260 CPUtime=5.2
/proc/3393/task/3394/stat : 3394 (java) R 3390 3390 1733 0 -1 4202560 47801 0 0 0 500 20 0 0 20 0 11 0 119862909 1070346240 112726 18446744073709551615 4194304 4228012 140735790323280 139747775406056 139747673873580 0 4 0 16800975 0 0 0 -1 0 0 0 11 0 0
[pid=3393/tid=3395] ppid=3390 vsize=1045260 CPUtime=1.29
/proc/3393/task/3395/stat : 3395 (java) S 3390 3390 1733 0 -1 4202560 53197 0 0 0 109 20 0 0 20 0 11 0 119862911 1070346240 112726 18446744073709551615 4194304 4228012 140735790323280 139747668044928 139747768886859 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3393/tid=3396] ppid=3390 vsize=1045260 CPUtime=0
/proc/3393/task/3396/stat : 3396 (java) S 3390 3390 1733 0 -1 4202560 16 0 0 0 0 0 0 0 20 0 11 0 119862912 1070346240 112726 18446744073709551615 4194304 4228012 140735790323280 139747666991120 139747768885972 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3393/tid=3397] ppid=3390 vsize=1045260 CPUtime=0
/proc/3393/task/3397/stat : 3397 (java) S 3390 3390 1733 0 -1 4202560 9 0 0 0 0 0 0 0 20 0 11 0 119862912 1070346240 112726 18446744073709551615 4194304 4228012 140735790323280 139747665938336 139747768885972 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3393/tid=3398] ppid=3390 vsize=1045260 CPUtime=0
/proc/3393/task/3398/stat : 3398 (java) S 3390 3390 1733 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 11 0 119862916 1070346240 112726 18446744073709551615 4194304 4228012 140735790323280 139747664886768 139747768894496 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3393/tid=3399] ppid=3390 vsize=1045260 CPUtime=2.26
/proc/3393/task/3399/stat : 3399 (java) S 3390 3390 1733 0 -1 4202560 15035 0 0 0 222 4 0 0 20 0 11 0 119862916 1070346240 112726 18446744073709551615 4194304 4228012 140735790323280 139747663834128 139747768885972 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3393/tid=3400] ppid=3390 vsize=1045260 CPUtime=2.2
/proc/3393/task/3400/stat : 3400 (java) S 3390 3390 1733 0 -1 4202560 8483 0 0 0 217 3 0 0 20 0 11 0 119862916 1070346240 112726 18446744073709551615 4194304 4228012 140735790323280 139747662781456 139747768885972 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3393/tid=3401] ppid=3390 vsize=1045260 CPUtime=0
/proc/3393/task/3401/stat : 3401 (java) S 3390 3390 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 11 0 119862916 1070346240 112726 18446744073709551615 4194304 4228012 140735790323280 139747661728976 139747768885972 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3393/tid=3402] ppid=3390 vsize=1045260 CPUtime=0
/proc/3393/task/3402/stat : 3402 (java) S 3390 3390 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 11 0 119862916 1070346240 112726 18446744073709551615 4194304 4228012 140735790323280 139747660676480 139747768886859 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3393/tid=3403] ppid=3390 vsize=1045260 CPUtime=0
/proc/3393/task/3403/stat : 3403 (java) S 3390 3390 1733 0 -1 4202560 6 0 0 0 0 0 0 0 20 0 11 0 119863926 1070346240 112726 18446744073709551615 4194304 4228012 140735790323280 139747659470688 139747768886859 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 11
Current children cumulated vsize (KiB) 1054428

[startup+11.7008 s]
/proc/loadavg: 1.88 1.44 1.20 3/71 3403
/proc/meminfo: memFree=15408/1022884 swapFree=0/0
[pid=3390] ppid=3389 vsize=9168 CPUtime=0
/proc/3390/stat : 3390 (p2cudf-full-1.1) S 3389 3390 1733 0 -1 4202496 454 291 0 0 0 0 0 0 20 0 1 0 119862907 9388032 330 18446744073709551615 4194304 5129932 140735174403328 140735174401472 140607982040158 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/3390/statm: 2292 330 280 229 0 52 0
[pid=3393] ppid=3390 vsize=1046288 CPUtime=11.24
/proc/3393/stat : 3393 (java) S 3390 3390 1733 0 -1 4202496 125837 0 0 0 1075 49 0 0 20 0 11 0 119862908 1071398912 112747 18446744073709551615 4194304 4228012 140735790323280 140735790314304 139747768872565 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/3393/statm: 261572 112747 2381 9 0 248922 0
[pid=3393/tid=3394] ppid=3390 vsize=1046288 CPUtime=5.32
/proc/3393/task/3394/stat : 3394 (java) S 3390 3390 1733 0 -1 4202560 47811 0 0 0 512 20 0 0 20 0 11 0 119862909 1071398912 112747 18446744073709551615 4194304 4228012 140735790323280 139747775407024 139747768885972 0 4 0 16800975 0 0 0 -1 0 0 0 11 0 0
[pid=3393/tid=3395] ppid=3390 vsize=1046288 CPUtime=1.29
/proc/3393/task/3395/stat : 3395 (java) S 3390 3390 1733 0 -1 4202560 53197 0 0 0 109 20 0 0 20 0 11 0 119862911 1071398912 112747 18446744073709551615 4194304 4228012 140735790323280 139747668044928 139747768886859 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3393/tid=3396] ppid=3390 vsize=1046288 CPUtime=0
/proc/3393/task/3396/stat : 3396 (java) S 3390 3390 1733 0 -1 4202560 16 0 0 0 0 0 0 0 20 0 11 0 119862912 1071398912 112747 18446744073709551615 4194304 4228012 140735790323280 139747666991120 139747768885972 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3393/tid=3397] ppid=3390 vsize=1046288 CPUtime=0
/proc/3393/task/3397/stat : 3397 (java) S 3390 3390 1733 0 -1 4202560 9 0 0 0 0 0 0 0 20 0 11 0 119862912 1071398912 112747 18446744073709551615 4194304 4228012 140735790323280 139747665938336 139747768885972 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3393/tid=3398] ppid=3390 vsize=1046288 CPUtime=0
/proc/3393/task/3398/stat : 3398 (java) S 3390 3390 1733 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 11 0 119862916 1071398912 112747 18446744073709551615 4194304 4228012 140735790323280 139747664886768 139747768894496 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3393/tid=3399] ppid=3390 vsize=1046288 CPUtime=2.34
/proc/3393/task/3399/stat : 3399 (java) S 3390 3390 1733 0 -1 4202560 15039 0 0 0 230 4 0 0 20 0 11 0 119862916 1071398912 112747 18446744073709551615 4194304 4228012 140735790323280 139747663834128 139747768885972 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3393/tid=3400] ppid=3390 vsize=1046288 CPUtime=2.25
/proc/3393/task/3400/stat : 3400 (java) S 3390 3390 1733 0 -1 4202560 8486 0 0 0 222 3 0 0 20 0 11 0 119862916 1071398912 112747 18446744073709551615 4194304 4228012 140735790323280 139747662781456 139747768885972 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3393/tid=3401] ppid=3390 vsize=1046288 CPUtime=0
/proc/3393/task/3401/stat : 3401 (java) S 3390 3390 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 11 0 119862916 1071398912 112747 18446744073709551615 4194304 4228012 140735790323280 139747661728976 139747768885972 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3393/tid=3402] ppid=3390 vsize=1046288 CPUtime=0
/proc/3393/task/3402/stat : 3402 (java) S 3390 3390 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 11 0 119862916 1071398912 112747 18446744073709551615 4194304 4228012 140735790323280 139747660676480 139747768886859 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 11.24
Current children cumulated vsize (KiB) 1055456

[startup+12.1008 s]
/proc/loadavg: 1.88 1.44 1.20 3/71 3403
/proc/meminfo: memFree=15408/1022884 swapFree=0/0
[pid=3390] ppid=3389 vsize=9168 CPUtime=0
/proc/3390/stat : 3390 (p2cudf-full-1.1) S 3389 3390 1733 0 -1 4202496 454 291 0 0 0 0 0 0 20 0 1 0 119862907 9388032 330 18446744073709551615 4194304 5129932 140735174403328 140735174401472 140607982040158 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/3390/statm: 2292 330 280 229 0 52 0
[pid=3393] ppid=3390 vsize=1046288 CPUtime=11.3
/proc/3393/stat : 3393 (java) S 3390 3390 1733 0 -1 4202496 125840 0 0 0 1081 49 0 0 20 0 11 0 119862908 1071398912 112750 18446744073709551615 4194304 4228012 140735790323280 140735790314304 139747768872565 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/3393/statm: 261572 112750 2381 9 0 248922 0
[pid=3393/tid=3394] ppid=3390 vsize=1046288 CPUtime=5.32
/proc/3393/task/3394/stat : 3394 (java) S 3390 3390 1733 0 -1 4202560 47811 0 0 0 512 20 0 0 20 0 11 0 119862909 1071398912 112750 18446744073709551615 4194304 4228012 140735790323280 139747775407024 139747768885972 0 4 0 16800975 0 0 0 -1 0 0 0 11 0 0
[pid=3393/tid=3395] ppid=3390 vsize=1046288 CPUtime=1.29
/proc/3393/task/3395/stat : 3395 (java) S 3390 3390 1733 0 -1 4202560 53197 0 0 0 109 20 0 0 20 0 11 0 119862911 1071398912 112750 18446744073709551615 4194304 4228012 140735790323280 139747668044928 139747768886859 0 0 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3393/tid=3396] ppid=3390 vsize=1046288 CPUtime=0
/proc/3393/task/3396/stat : 3396 (java) S 3390 3390 1733 0 -1 4202560 16 0 0 0 0 0 0 0 20 0 11 0 119862912 1071398912 112750 18446744073709551615 4194304 4228012 140735790323280 139747666991120 139747768885972 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3393/tid=3397] ppid=3390 vsize=1046288 CPUtime=0
/proc/3393/task/3397/stat : 3397 (java) S 3390 3390 1733 0 -1 4202560 9 0 0 0 0 0 0 0 20 0 11 0 119862912 1071398912 112750 18446744073709551615 4194304 4228012 140735790323280 139747665938336 139747768885972 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3393/tid=3398] ppid=3390 vsize=1046288 CPUtime=0
/proc/3393/task/3398/stat : 3398 (java) S 3390 3390 1733 0 -1 4202560 1 0 0 0 0 0 0 0 20 0 11 0 119862916 1071398912 112750 18446744073709551615 4194304 4228012 140735790323280 139747664886768 139747768894496 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3393/tid=3399] ppid=3390 vsize=1046288 CPUtime=2.34
/proc/3393/task/3399/stat : 3399 (java) S 3390 3390 1733 0 -1 4202560 15039 0 0 0 230 4 0 0 20 0 11 0 119862916 1071398912 112750 18446744073709551615 4194304 4228012 140735790323280 139747663834128 139747768885972 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3393/tid=3400] ppid=3390 vsize=1046288 CPUtime=2.25
/proc/3393/task/3400/stat : 3400 (java) S 3390 3390 1733 0 -1 4202560 8486 0 0 0 222 3 0 0 20 0 11 0 119862916 1071398912 112750 18446744073709551615 4194304 4228012 140735790323280 139747662781456 139747768885972 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3393/tid=3401] ppid=3390 vsize=1046288 CPUtime=0
/proc/3393/task/3401/stat : 3401 (java) S 3390 3390 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 11 0 119862916 1071398912 112750 18446744073709551615 4194304 4228012 140735790323280 139747661728976 139747768885972 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
[pid=3393/tid=3402] ppid=3390 vsize=1046288 CPUtime=0
/proc/3393/task/3402/stat : 3402 (java) S 3390 3390 1733 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 11 0 119862916 1071398912 112750 18446744073709551615 4194304 4228012 140735790323280 139747660676480 139747768886859 0 4 0 16800975 0 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 11.3
Current children cumulated vsize (KiB) 1055456

[startup+12.2017 s]
/proc/loadavg: 1.88 1.44 1.20 2/62 3404
/proc/meminfo: memFree=455320/1022884 swapFree=0/0
[pid=3390] ppid=3389 vsize=9168 CPUtime=0
/proc/3390/stat : 3390 (p2cudf-full-1.1) S 3389 3390 1733 0 -1 4202496 454 291 0 0 0 0 0 0 20 0 1 0 119862907 9388032 330 18446744073709551615 4194304 5129932 140735174403328 140735174401472 140607982040158 0 65536 16781316 65538 0 0 0 17 0 0 0 0 0 0
/proc/3390/statm: 2292 330 280 229 0 52 0
[pid=3393] ppid=3390 vsize=0 CPUtime=11.4
/proc/3393/stat : 3393 (java) Z 3390 3390 1733 0 -1 4203532 125851 0 0 0 1086 54 0 0 20 0 2 0 119862908 0 0 18446744073709551615 0 0 0 0 0 0 0 0 16800975 18446744073709551615 0 0 17 0 0 0 0 0 0
/proc/3393/statm: 0 0 0 0 0 0 0
[pid=3393/tid=3404] ppid=3390 vsize=0 CPUtime=0.15
/proc/3393/task/3404/stat : 3404 (java) R 3390 3390 1733 0 -1 4203588 9 0 0 0 9 6 0 0 20 0 2 0 119864060 0 0 18446744073709551615 0 0 0 0 0 0 4 0 16800975 18446744073709551615 0 0 -1 0 0 0 0 0 0
Current children cumulated CPU time (s) 11.4
Current children cumulated vsize (KiB) 9168

Child status: 0
Real time (s): 12.2081
CPU time (s): 11.4167
CPU user time (s): 10.8727
CPU system time (s): 0.544034
CPU usage (%): 93.5173
Max. virtual memory (cumulated for all children) (KiB): 1072300

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 10.8727
system time used= 0.544034
maximum resident set size= 457176
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 126609
page faults= 0
swaps= 0
block input operations= 42384
block output operations= 176
messages sent= 0
messages received= 0
signals received= 0
voluntary context switches= 1001
involuntary context switches= 3321

runsolver used 0.044002 second user time and 0.088005 second system time

The end