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/201012091434/cudf2pbo4user-1.0/rand4d6b1c.cudf.difficult.log.runsolver ./cudf2pbo4user-1.0 /home/misc2010/data/2010/difficult//rand4d6b1c.cudf /home/misc2010/tmp/201012091434/cudf2pbo4user-1.0/rand4d6b1c.cudf.difficult.result -changed,-removed,-unmet_recommends,-new 

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.06 1.11 1.04 5/39 29111
/proc/meminfo: memFree=381608/1048576 swapFree=2095372/2097144
[pid=29110] ppid=29109 vsize=2572 CPUtime=0
/proc/29110/stat : 29110 (cudf2pbo4user-1) R 29109 29110 25521 34816 25544 4202496 368 0 0 0 0 0 0 0 25 0 1 0 900146856 2633728 281 1283457024 134512640 135304128 4290942480 18446744073709551615 4294960130 0 65538 4 82432 0 0 0 17 0 0 0 0
/proc/29110/statm: 643 281 240 194 0 29 0
[pid=29111] ppid=29110 vsize=2572 CPUtime=0
/proc/29111/stat : 29111 (cudf2pbo4user-1) R 29110 29110 25521 34816 25544 4202560 0 0 0 0 0 0 0 0 25 0 1 0 900146856 2633728 41 1283457024 134512640 135304128 4290942480 18446744073709551615 4294960130 0 65538 4 82432 0 0 0 17 0 0 0 0
/proc/29111/statm: 643 41 0 194 0 29 0

[startup+0.13733 s]
/proc/loadavg: 1.06 1.11 1.04 5/39 29111
/proc/meminfo: memFree=381608/1048576 swapFree=2095372/2097144
[pid=29110] ppid=29109 vsize=2572 CPUtime=0
/proc/29110/stat : 29110 (cudf2pbo4user-1) S 29109 29110 25521 34816 25544 4202496 385 0 0 0 0 0 0 0 25 0 1 0 900146856 2633728 281 1283457024 134512640 135304128 4290942480 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0
/proc/29110/statm: 643 281 240 194 0 29 0
[pid=29111] ppid=29110 vsize=7464 CPUtime=0.12
/proc/29111/stat : 29111 (cudf_msu32) R 29110 29110 25521 34816 25544 4202496 1678 0 0 0 12 0 0 0 25 0 1 0 900146856 7643136 1570 1283457024 134512640 136125367 4292089760 18446744073709551615 134717802 0 0 0 25121 0 0 0 17 0 0 0 0
/proc/29111/statm: 1866 1570 146 394 0 1470 0
Current children cumulated CPU time (s) 0.12
Current children cumulated vsize (KiB) 10036

[startup+0.205392 s]
/proc/loadavg: 1.06 1.11 1.04 5/39 29111
/proc/meminfo: memFree=381608/1048576 swapFree=2095372/2097144
[pid=29110] ppid=29109 vsize=2572 CPUtime=0
/proc/29110/stat : 29110 (cudf2pbo4user-1) S 29109 29110 25521 34816 25544 4202496 385 0 0 0 0 0 0 0 25 0 1 0 900146856 2633728 281 1283457024 134512640 135304128 4290942480 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0
/proc/29110/statm: 643 281 240 194 0 29 0
[pid=29111] ppid=29110 vsize=10116 CPUtime=0.19
/proc/29111/stat : 29111 (cudf_msu32) R 29110 29110 25521 34816 25544 4202496 2341 0 0 0 17 2 0 0 25 0 1 0 900146856 10358784 2233 1283457024 134512640 136125367 4292089760 18446744073709551615 134717908 0 0 0 25121 0 0 0 17 0 0 0 0
/proc/29111/statm: 2529 2233 146 394 0 2133 0
Current children cumulated CPU time (s) 0.19
Current children cumulated vsize (KiB) 12688

[startup+0.305413 s]
/proc/loadavg: 1.06 1.11 1.04 5/39 29111
/proc/meminfo: memFree=381608/1048576 swapFree=2095372/2097144
[pid=29110] ppid=29109 vsize=2572 CPUtime=0
/proc/29110/stat : 29110 (cudf2pbo4user-1) S 29109 29110 25521 34816 25544 4202496 385 0 0 0 0 0 0 0 25 0 1 0 900146856 2633728 281 1283457024 134512640 135304128 4290942480 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0
/proc/29110/statm: 643 281 240 194 0 29 0
[pid=29111] ppid=29110 vsize=13744 CPUtime=0.29
/proc/29111/stat : 29111 (cudf_msu32) R 29110 29110 25521 34816 25544 4202496 3261 0 0 0 26 3 0 0 25 0 1 0 900146856 14073856 3153 1283457024 134512640 136125367 4292089760 18446744073709551615 134738457 0 0 0 25121 0 0 0 17 0 0 0 0
/proc/29111/statm: 3436 3153 147 394 0 3040 0
Current children cumulated CPU time (s) 0.29
Current children cumulated vsize (KiB) 16316

[startup+0.705498 s]
/proc/loadavg: 1.06 1.11 1.04 5/39 29111
/proc/meminfo: memFree=381608/1048576 swapFree=2095372/2097144
[pid=29110] ppid=29109 vsize=2572 CPUtime=0
/proc/29110/stat : 29110 (cudf2pbo4user-1) S 29109 29110 25521 34816 25544 4202496 385 0 0 0 0 0 0 0 25 0 1 0 900146856 2633728 281 1283457024 134512640 135304128 4290942480 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0
/proc/29110/statm: 643 281 240 194 0 29 0
[pid=29111] ppid=29110 vsize=26216 CPUtime=0.68
/proc/29111/stat : 29111 (cudf_msu32) R 29110 29110 25521 34816 25544 4202496 6354 0 0 0 64 4 0 0 25 0 1 0 900146856 26845184 6246 1283457024 134512640 136125367 4292089760 18446744073709551615 135533302 0 0 0 25121 0 0 0 17 0 0 0 0
/proc/29111/statm: 6554 6246 147 394 0 6158 0
Current children cumulated CPU time (s) 0.68
Current children cumulated vsize (KiB) 28788

[startup+1.5075 s]
/proc/loadavg: 1.06 1.11 1.04 2/40 29112
/proc/meminfo: memFree=347116/1048576 swapFree=2095372/2097144
[pid=29110] ppid=29109 vsize=2572 CPUtime=1.2
/proc/29110/stat : 29110 (cudf2pbo4user-1) S 29109 29110 25521 34816 25544 4202496 403 8676 0 0 0 0 98 22 18 0 1 0 900146856 2633728 282 1283457024 134512640 135304128 4290942480 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0
/proc/29110/statm: 643 282 241 194 0 29 0
Current children cumulated CPU time (s) 1.2
Current children cumulated vsize (KiB) 2572

[startup+3.10791 s]
/proc/loadavg: 1.06 1.11 1.04 2/40 29113
/proc/meminfo: memFree=367080/1048576 swapFree=2095372/2097144
[pid=29110] ppid=29109 vsize=2572 CPUtime=1.2
/proc/29110/stat : 29110 (cudf2pbo4user-1) S 29109 29110 25521 34816 25544 4202496 403 8676 0 0 0 0 98 22 18 0 1 0 900146856 2633728 282 1283457024 134512640 135304128 4290942480 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0
/proc/29110/statm: 643 282 241 194 0 29 0
[pid=29113] ppid=29110 vsize=15380 CPUtime=1.85
/proc/29113/stat : 29113 (bmo-pblex32) R 29110 29110 25521 34816 25544 4202496 4224 0 0 0 132 53 0 0 25 0 1 0 900146979 15749120 3504 1283457024 134512640 135887319 4291278608 18446744073709551615 134624789 0 0 0 16899 0 0 0 17 0 0 0 0
/proc/29113/statm: 3845 3504 137 336 0 3507 0
Current children cumulated CPU time (s) 3.05
Current children cumulated vsize (KiB) 17952

[startup+6.30879 s]
/proc/loadavg: 1.05 1.11 1.04 2/40 29113
/proc/meminfo: memFree=365096/1048576 swapFree=2095372/2097144
[pid=29110] ppid=29109 vsize=2572 CPUtime=1.2
/proc/29110/stat : 29110 (cudf2pbo4user-1) S 29109 29110 25521 34816 25544 4202496 403 8676 0 0 0 0 98 22 18 0 1 0 900146856 2633728 282 1283457024 134512640 135304128 4290942480 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0
/proc/29110/statm: 643 282 241 194 0 29 0
[pid=29113] ppid=29110 vsize=16792 CPUtime=5.04
/proc/29113/stat : 29113 (bmo-pblex32) R 29110 29110 25521 34816 25544 4202496 4598 0 0 0 427 77 0 0 25 0 1 0 900146979 17195008 3858 1283457024 134512640 135887319 4291278608 18446744073709551615 134525472 0 0 0 16899 0 0 0 17 0 0 0 0
/proc/29113/statm: 4198 3858 138 336 0 3860 0
Current children cumulated CPU time (s) 6.24
Current children cumulated vsize (KiB) 19364

[startup+12.7104 s]
/proc/loadavg: 1.05 1.11 1.04 2/40 29113
/proc/meminfo: memFree=360508/1048576 swapFree=2095372/2097144
[pid=29110] ppid=29109 vsize=2572 CPUtime=1.2
/proc/29110/stat : 29110 (cudf2pbo4user-1) S 29109 29110 25521 34816 25544 4202496 403 8676 0 0 0 0 98 22 18 0 1 0 900146856 2633728 282 1283457024 134512640 135304128 4290942480 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0
/proc/29110/statm: 643 282 241 194 0 29 0
[pid=29113] ppid=29110 vsize=24148 CPUtime=11.43
/proc/29113/stat : 29113 (bmo-pblex32) R 29110 29110 25521 34816 25544 4202496 8066 0 0 0 1059 84 0 0 25 0 1 0 900146979 24727552 5782 1283457024 134512640 135887319 4291278608 18446744073709551615 134615443 0 0 0 16899 0 0 0 17 0 0 0 0
/proc/29113/statm: 6037 5782 144 336 0 5699 0
Current children cumulated CPU time (s) 12.63
Current children cumulated vsize (KiB) 26720

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

[startup+12.8105 s]
/proc/loadavg: 1.05 1.11 1.04 2/40 29113
/proc/meminfo: memFree=360508/1048576 swapFree=2095372/2097144
[pid=29110] ppid=29109 vsize=2572 CPUtime=1.2
/proc/29110/stat : 29110 (cudf2pbo4user-1) S 29109 29110 25521 34816 25544 4202496 403 8676 0 0 0 0 98 22 18 0 1 0 900146856 2633728 282 1283457024 134512640 135304128 4290942480 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0
/proc/29110/statm: 643 282 241 194 0 29 0
[pid=29113] ppid=29110 vsize=24148 CPUtime=11.53
/proc/29113/stat : 29113 (bmo-pblex32) R 29110 29110 25521 34816 25544 4202496 8066 0 0 0 1069 84 0 0 25 0 1 0 900146979 24727552 5782 1283457024 134512640 135887319 4291278608 18446744073709551615 134525472 0 0 0 16899 0 0 0 17 0 0 0 0
/proc/29113/statm: 6037 5782 144 336 0 5699 0
Current children cumulated CPU time (s) 12.73
Current children cumulated vsize (KiB) 26720

[startup+14.4109 s]
/proc/loadavg: 1.04 1.11 1.04 2/40 29113
/proc/meminfo: memFree=356912/1048576 swapFree=2095372/2097144
[pid=29110] ppid=29109 vsize=2572 CPUtime=1.2
/proc/29110/stat : 29110 (cudf2pbo4user-1) S 29109 29110 25521 34816 25544 4202496 403 8676 0 0 0 0 98 22 18 0 1 0 900146856 2633728 282 1283457024 134512640 135304128 4290942480 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0
/proc/29110/statm: 643 282 241 194 0 29 0
[pid=29113] ppid=29110 vsize=24412 CPUtime=13.14
/proc/29113/stat : 29113 (bmo-pblex32) R 29110 29110 25521 34816 25544 4202496 8115 0 0 0 1226 88 0 0 25 0 1 0 900146979 24997888 5827 1283457024 134512640 135887319 4291278608 18446744073709551615 134615150 0 0 0 16899 0 0 0 17 0 0 0 0
/proc/29113/statm: 6103 5827 144 336 0 5765 0
Current children cumulated CPU time (s) 14.34
Current children cumulated vsize (KiB) 26984

[startup+16.0114 s]
/proc/loadavg: 1.04 1.11 1.04 2/40 29113
/proc/meminfo: memFree=352200/1048576 swapFree=2095372/2097144
[pid=29110] ppid=29109 vsize=2572 CPUtime=1.2
/proc/29110/stat : 29110 (cudf2pbo4user-1) S 29109 29110 25521 34816 25544 4202496 403 8676 0 0 0 0 98 22 18 0 1 0 900146856 2633728 282 1283457024 134512640 135304128 4290942480 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0
/proc/29110/statm: 643 282 241 194 0 29 0
[pid=29113] ppid=29110 vsize=29212 CPUtime=14.72
/proc/29113/stat : 29113 (bmo-pblex32) R 29110 29110 25521 34816 25544 4202496 9824 0 0 0 1381 91 0 0 25 0 1 0 900146979 29913088 7023 1283457024 134512640 135887319 4291278608 18446744073709551615 134525296 0 0 0 16899 0 0 0 17 0 0 0 0
/proc/29113/statm: 7303 7023 144 336 0 6965 0
Current children cumulated CPU time (s) 15.92
Current children cumulated vsize (KiB) 31784

[startup+16.8116 s]
/proc/loadavg: 1.04 1.11 1.04 2/40 29113
/proc/meminfo: memFree=352076/1048576 swapFree=2095372/2097144
[pid=29110] ppid=29109 vsize=2572 CPUtime=1.2
/proc/29110/stat : 29110 (cudf2pbo4user-1) S 29109 29110 25521 34816 25544 4202496 403 8676 0 0 0 0 98 22 18 0 1 0 900146856 2633728 282 1283457024 134512640 135304128 4290942480 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0
/proc/29110/statm: 643 282 241 194 0 29 0
[pid=29113] ppid=29110 vsize=29476 CPUtime=15.51
/proc/29113/stat : 29113 (bmo-pblex32) R 29110 29110 25521 34816 25544 4202496 9923 0 0 0 1456 95 0 0 25 0 1 0 900146979 30183424 7122 1283457024 134512640 135887319 4291278608 18446744073709551615 134614989 0 0 0 16899 0 0 0 17 0 0 0 0
/proc/29113/statm: 7369 7122 144 336 0 7031 0
Current children cumulated CPU time (s) 16.71
Current children cumulated vsize (KiB) 32048

[startup+17.2118 s]
/proc/loadavg: 1.04 1.11 1.04 2/40 29113
/proc/meminfo: memFree=352076/1048576 swapFree=2095372/2097144
[pid=29110] ppid=29109 vsize=2572 CPUtime=1.2
/proc/29110/stat : 29110 (cudf2pbo4user-1) S 29109 29110 25521 34816 25544 4202496 403 8676 0 0 0 0 98 22 18 0 1 0 900146856 2633728 282 1283457024 134512640 135304128 4290942480 18446744073709551615 4294960130 0 65536 4 82434 18446744071564329979 0 0 17 0 0 0 0
/proc/29110/statm: 643 282 241 194 0 29 0
[pid=29113] ppid=29110 vsize=29876 CPUtime=15.91
/proc/29113/stat : 29113 (bmo-pblex32) R 29110 29110 25521 34816 25544 4202496 10004 0 0 0 1494 97 0 0 25 0 1 0 900146979 30593024 7203 1283457024 134512640 135887319 4291278608 18446744073709551615 134605843 0 0 0 16899 0 0 0 17 0 0 0 0
/proc/29113/statm: 7469 7203 144 336 0 7131 0
Current children cumulated CPU time (s) 17.11
Current children cumulated vsize (KiB) 32448

[startup+17.3118 s]
/proc/loadavg: 1.04 1.11 1.04 2/40 29113
/proc/meminfo: memFree=352076/1048576 swapFree=2095372/2097144
[pid=29110] ppid=29109 vsize=2572 CPUtime=17.2
/proc/29110/stat : 29110 (cudf2pbo4user-1) R 29109 29110 25521 34816 25544 4202496 423 18684 0 0 0 0 1599 121 18 0 1 0 900146856 2633728 282 1283457024 134512640 135304128 4290942480 18446744073709551615 4294960130 0 65538 4 82432 0 0 0 17 0 0 0 0
/proc/29110/statm: 643 282 241 194 0 29 0
Current children cumulated CPU time (s) 17.2
Current children cumulated vsize (KiB) 2572

Child status: 0
Real time (s): 17.346
CPU time (s): 17.2571
CPU user time (s): 16.037
CPU system time (s): 1.22008
CPU usage (%): 99.4875
Max. virtual memory (cumulated for all children) (KiB): 37468

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 16.037
system time used= 1.22008
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 20804
page faults= 0
swaps= 0
block input operations= 0
block output operations= 0
messages sent= 0
messages received= 0
signals received= 0
voluntary context switches= 12
involuntary context switches= 3113

runsolver used 0 second user time and 0 second system time

The end