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/201012070034/apt-get-trendy-1.0/randaafcce.cudf.impossible.log.runsolver ./apt-get-trendy-1.0 /home/misc2010/data/2010/impossible//randaafcce.cudf /home/misc2010/tmp/201012070034/apt-get-trendy-1.0/randaafcce.cudf.impossible.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.31 1.09 1.04 2/45 1579
/proc/meminfo: memFree=786172/1048576 swapFree=2077616/2097144
[pid=1571] ppid=1570 vsize=2584 CPUtime=0.01
/proc/1571/stat : 1571 (apt-get-trendy-) S 1570 1571 4159 34819 4229 4202496 516 1358 0 0 0 1 0 0 25 0 1 0 884794219 2646016 280 1283457024 134512640 135304128 4288224176 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/1571/statm: 646 280 237 194 0 32 0
[pid=1579] ppid=1571 vsize=2008 CPUtime=0
/proc/1579/stat : 1579 (cp) D 1571 1571 4159 34819 4229 4202496 238 0 0 0 0 0 0 0 25 0 1 0 884794220 2056192 168 1283457024 134512640 134614052 4289426800 18446744073709551615 4294960130 0 0 0 0 18446744071564252162 0 0 17 0 0 0 0
/proc/1579/statm: 502 168 139 25 0 48 0

[startup+0.201269 s]
/proc/loadavg: 1.31 1.09 1.04 2/45 1579
/proc/meminfo: memFree=786172/1048576 swapFree=2077616/2097144
[pid=1571] ppid=1570 vsize=2584 CPUtime=0.01
/proc/1571/stat : 1571 (apt-get-trendy-) S 1570 1571 4159 34819 4229 4202496 516 1358 0 0 0 1 0 0 25 0 1 0 884794219 2646016 280 1283457024 134512640 135304128 4288224176 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/1571/statm: 646 280 237 194 0 32 0
[pid=1579] ppid=1571 vsize=2008 CPUtime=0
/proc/1579/stat : 1579 (cp) D 1571 1571 4159 34819 4229 4202496 253 0 0 0 0 0 0 0 24 0 1 0 884794220 2056192 183 1283457024 134512640 134614052 4289426800 18446744073709551615 4294960130 0 0 0 0 18446744071564332000 0 0 17 0 0 0 0
/proc/1579/statm: 502 183 145 25 0 48 0
Current children cumulated CPU time (s) 0.01
Current children cumulated vsize (KiB) 4592

[startup+0.305289 s]
/proc/loadavg: 1.31 1.09 1.04 2/45 1579
/proc/meminfo: memFree=786172/1048576 swapFree=2077616/2097144
[pid=1571] ppid=1570 vsize=2584 CPUtime=0.01
/proc/1571/stat : 1571 (apt-get-trendy-) S 1570 1571 4159 34819 4229 4202496 516 1358 0 0 0 1 0 0 25 0 1 0 884794219 2646016 280 1283457024 134512640 135304128 4288224176 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/1571/statm: 646 280 237 194 0 32 0
[pid=1579] ppid=1571 vsize=2008 CPUtime=0
/proc/1579/stat : 1579 (cp) D 1571 1571 4159 34819 4229 4202496 253 0 0 0 0 0 0 0 24 0 1 0 884794220 2056192 183 1283457024 134512640 134614052 4289426800 18446744073709551615 4294960130 0 0 0 0 18446744071564332000 0 0 17 0 0 0 0
/proc/1579/statm: 502 183 145 25 0 48 0
Current children cumulated CPU time (s) 0.01
Current children cumulated vsize (KiB) 4592

[startup+0.405336 s]
/proc/loadavg: 1.31 1.09 1.04 2/45 1579
/proc/meminfo: memFree=786172/1048576 swapFree=2077616/2097144
[pid=1571] ppid=1570 vsize=2584 CPUtime=0.01
/proc/1571/stat : 1571 (apt-get-trendy-) S 1570 1571 4159 34819 4229 4202496 516 1358 0 0 0 1 0 0 25 0 1 0 884794219 2646016 280 1283457024 134512640 135304128 4288224176 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/1571/statm: 646 280 237 194 0 32 0
[pid=1579] ppid=1571 vsize=2008 CPUtime=0
/proc/1579/stat : 1579 (cp) D 1571 1571 4159 34819 4229 4202496 253 0 0 0 0 0 0 0 23 0 1 0 884794220 2056192 183 1283457024 134512640 134614052 4289426800 18446744073709551615 4294960130 0 0 0 0 18446744071564332000 0 0 17 0 0 0 0
/proc/1579/statm: 502 183 145 25 0 48 0
Current children cumulated CPU time (s) 0.01
Current children cumulated vsize (KiB) 4592

[startup+0.714186 s]
/proc/loadavg: 1.31 1.09 1.04 2/45 1579
/proc/meminfo: memFree=786172/1048576 swapFree=2077616/2097144
[pid=1571] ppid=1570 vsize=2584 CPUtime=0.01
/proc/1571/stat : 1571 (apt-get-trendy-) S 1570 1571 4159 34819 4229 4202496 565 1858 0 0 0 1 0 0 21 0 1 0 884794219 2646016 283 1283457024 134512640 135304128 4288224176 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/1571/statm: 646 283 240 194 0 32 0
Current children cumulated CPU time (s) 0.01
Current children cumulated vsize (KiB) 2584

[startup+1.51438 s]
/proc/loadavg: 1.29 1.09 1.04 2/46 1582
/proc/meminfo: memFree=715672/1048576 swapFree=2077616/2097144
[pid=1571] ppid=1570 vsize=2584 CPUtime=0.01
/proc/1571/stat : 1571 (apt-get-trendy-) S 1570 1571 4159 34819 4229 4202496 565 1858 0 0 0 1 0 0 21 0 1 0 884794219 2646016 283 1283457024 134512640 135304128 4288224176 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/1571/statm: 646 283 240 194 0 32 0
[pid=1582] ppid=1571 vsize=25744 CPUtime=1.08
/proc/1582/stat : 1582 (cudftodeb.nativ) R 1571 1571 4159 34819 4229 4202496 6028 0 0 0 105 3 0 0 25 0 1 0 884794262 26361856 5955 1283457024 134512640 135004320 4291270384 18446744073709551615 134986303 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/1582/statm: 6436 5955 225 121 0 5828 0
Current children cumulated CPU time (s) 1.09
Current children cumulated vsize (KiB) 28328

[startup+3.1147 s]
/proc/loadavg: 1.29 1.09 1.04 2/46 1582
/proc/meminfo: memFree=692360/1048576 swapFree=2077616/2097144
[pid=1571] ppid=1570 vsize=2584 CPUtime=0.01
/proc/1571/stat : 1571 (apt-get-trendy-) S 1570 1571 4159 34819 4229 4202496 565 1858 0 0 0 1 0 0 21 0 1 0 884794219 2646016 283 1283457024 134512640 135304128 4288224176 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/1571/statm: 646 283 240 194 0 32 0
[pid=1582] ppid=1571 vsize=59172 CPUtime=2.68
/proc/1582/stat : 1582 (cudftodeb.nativ) R 1571 1571 4159 34819 4229 4202496 14277 0 0 0 259 9 0 0 25 0 1 0 884794262 60592128 14202 1283457024 134512640 135004320 4291270384 18446744073709551615 134959863 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/1582/statm: 14793 14202 225 121 0 14185 0
Current children cumulated CPU time (s) 2.69
Current children cumulated vsize (KiB) 61756

[startup+6.31554 s]
/proc/loadavg: 1.29 1.09 1.04 2/46 1582
/proc/meminfo: memFree=634460/1048576 swapFree=2077616/2097144
[pid=1571] ppid=1570 vsize=2584 CPUtime=0.01
/proc/1571/stat : 1571 (apt-get-trendy-) S 1570 1571 4159 34819 4229 4202496 565 1858 0 0 0 1 0 0 21 0 1 0 884794219 2646016 283 1283457024 134512640 135304128 4288224176 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/1571/statm: 646 283 240 194 0 32 0
[pid=1582] ppid=1571 vsize=116672 CPUtime=5.87
/proc/1582/stat : 1582 (cudftodeb.nativ) R 1571 1571 4159 34819 4229 4202496 28419 0 0 0 571 16 0 0 25 0 1 0 884794262 119472128 28344 1283457024 134512640 135004320 4291270384 18446744073709551615 134996567 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/1582/statm: 29168 28344 236 121 0 28560 0
Current children cumulated CPU time (s) 5.88
Current children cumulated vsize (KiB) 119256

[startup+12.7072 s]
/proc/loadavg: 1.24 1.08 1.04 2/46 1582
/proc/meminfo: memFree=537616/1048576 swapFree=2077616/2097144
[pid=1571] ppid=1570 vsize=2584 CPUtime=0.01
/proc/1571/stat : 1571 (apt-get-trendy-) S 1570 1571 4159 34819 4229 4202496 565 1858 0 0 0 1 0 0 21 0 1 0 884794219 2646016 283 1283457024 134512640 135304128 4288224176 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/1571/statm: 646 283 240 194 0 32 0
[pid=1582] ppid=1571 vsize=183240 CPUtime=12.26
/proc/1582/stat : 1582 (cudftodeb.nativ) R 1571 1571 4159 34819 4229 4202496 44787 0 0 0 1196 30 0 0 25 0 1 0 884794262 187637760 44712 1283457024 134512640 135004320 4291270384 18446744073709551615 134991123 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/1582/statm: 45810 44712 237 121 0 45202 0
Current children cumulated CPU time (s) 12.27
Current children cumulated vsize (KiB) 185824

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

[startup+12.9073 s]
/proc/loadavg: 1.24 1.08 1.04 2/46 1582
/proc/meminfo: memFree=537616/1048576 swapFree=2077616/2097144
[pid=1571] ppid=1570 vsize=2584 CPUtime=0.01
/proc/1571/stat : 1571 (apt-get-trendy-) S 1570 1571 4159 34819 4229 4202496 565 1858 0 0 0 1 0 0 21 0 1 0 884794219 2646016 283 1283457024 134512640 135304128 4288224176 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/1571/statm: 646 283 240 194 0 32 0
[pid=1582] ppid=1571 vsize=97184 CPUtime=12.45
/proc/1582/stat : 1582 (cudftodeb.nativ) R 1571 1571 4159 34819 4229 4202496 44787 0 0 0 1213 32 0 0 25 0 1 0 884794262 99516416 23545 1283457024 134512640 135004320 4291270384 18446744073709551615 134535344 0 0 0 1024 0 0 0 17 0 0 0 0
/proc/1582/statm: 24296 23545 237 121 0 23688 0
Current children cumulated CPU time (s) 12.46
Current children cumulated vsize (KiB) 99768

[startup+16.1026 s]
/proc/loadavg: 1.24 1.08 1.04 2/46 1590
/proc/meminfo: memFree=662364/1048576 swapFree=2077616/2097144
[pid=1571] ppid=1570 vsize=2592 CPUtime=13.91
/proc/1571/stat : 1571 (apt-get-trendy-) S 1570 1571 4159 34819 4229 4202496 701 49929 0 1 0 1 1340 50 18 0 1 0 884794219 2654208 294 1283457024 134512640 135304128 4288224176 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/1571/statm: 648 294 249 194 0 34 0
Current children cumulated CPU time (s) 13.91
Current children cumulated vsize (KiB) 2592

[startup+19.3065 s]
/proc/loadavg: 1.22 1.08 1.04 1/46 1592
/proc/meminfo: memFree=586120/1048576 swapFree=2077616/2097144
[pid=1571] ppid=1570 vsize=2592 CPUtime=13.91
/proc/1571/stat : 1571 (apt-get-trendy-) S 1570 1571 4159 34819 4229 4202496 701 49929 0 1 0 1 1340 50 18 0 1 0 884794219 2654208 294 1283457024 134512640 135304128 4288224176 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/1571/statm: 648 294 249 194 0 34 0
[pid=1592] ppid=1571 vsize=101456 CPUtime=2.02
/proc/1592/stat : 1592 (apt-get) D 1571 1571 4159 34819 4229 4202496 9363 0 535 0 188 14 0 0 18 0 1 0 884795783 103890944 9823 1283457024 134512640 134619611 4287442784 18446744073709551615 4294960130 0 0 4096 134217728 18446744071564332537 0 0 17 0 0 0 0
/proc/1592/statm: 25364 9823 9770 27 0 58 0
Current children cumulated CPU time (s) 15.93
Current children cumulated vsize (KiB) 104048

[startup+20.1103 s]
/proc/loadavg: 1.22 1.08 1.04 2/46 1592
/proc/meminfo: memFree=582648/1048576 swapFree=2077616/2097144
[pid=1571] ppid=1570 vsize=2592 CPUtime=13.91
/proc/1571/stat : 1571 (apt-get-trendy-) S 1570 1571 4159 34819 4229 4202496 701 49929 0 1 0 1 1340 50 18 0 1 0 884794219 2654208 294 1283457024 134512640 135304128 4288224176 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/1571/statm: 648 294 249 194 0 34 0
[pid=1592] ppid=1571 vsize=44412 CPUtime=2.7
/proc/1592/stat : 1592 (apt-get) R 1571 1571 4159 34819 4229 4202496 19057 0 535 0 254 16 0 0 18 0 1 0 884795783 45477888 10052 1283457024 134512640 134619611 4287442784 18446744073709551615 4159613479 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/1592/statm: 11103 10052 9288 27 0 790 0
Current children cumulated CPU time (s) 16.61
Current children cumulated vsize (KiB) 47004

[startup+20.9104 s]
/proc/loadavg: 1.22 1.08 1.04 2/46 1592
/proc/meminfo: memFree=582648/1048576 swapFree=2077616/2097144
[pid=1571] ppid=1570 vsize=2592 CPUtime=13.91
/proc/1571/stat : 1571 (apt-get-trendy-) S 1570 1571 4159 34819 4229 4202496 701 49929 0 1 0 1 1340 50 18 0 1 0 884794219 2654208 294 1283457024 134512640 135304128 4288224176 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/1571/statm: 648 294 249 194 0 34 0
[pid=1592] ppid=1571 vsize=44848 CPUtime=3.5
/proc/1592/stat : 1592 (apt-get) R 1571 1571 4159 34819 4229 4202496 19152 0 535 0 334 16 0 0 20 0 1 0 884795783 45924352 10147 1283457024 134512640 134619611 4287442784 18446744073709551615 4159727085 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/1592/statm: 11212 10147 9292 27 0 899 0
Current children cumulated CPU time (s) 17.41
Current children cumulated vsize (KiB) 47440

[startup+21.3105 s]
/proc/loadavg: 1.21 1.08 1.04 2/46 1592
/proc/meminfo: memFree=582400/1048576 swapFree=2077616/2097144
[pid=1571] ppid=1570 vsize=2592 CPUtime=13.91
/proc/1571/stat : 1571 (apt-get-trendy-) S 1570 1571 4159 34819 4229 4202496 701 49929 0 1 0 1 1340 50 18 0 1 0 884794219 2654208 294 1283457024 134512640 135304128 4288224176 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/1571/statm: 648 294 249 194 0 34 0
[pid=1592] ppid=1571 vsize=44848 CPUtime=3.9
/proc/1592/stat : 1592 (apt-get) R 1571 1571 4159 34819 4229 4202496 19152 0 535 0 374 16 0 0 20 0 1 0 884795783 45924352 10147 1283457024 134512640 134619611 4287442784 18446744073709551615 4159727085 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/1592/statm: 11212 10147 9292 27 0 899 0
Current children cumulated CPU time (s) 17.81
Current children cumulated vsize (KiB) 47440

[startup+21.4105 s]
/proc/loadavg: 1.21 1.08 1.04 2/46 1592
/proc/meminfo: memFree=582400/1048576 swapFree=2077616/2097144
[pid=1571] ppid=1570 vsize=2592 CPUtime=13.91
/proc/1571/stat : 1571 (apt-get-trendy-) S 1570 1571 4159 34819 4229 4202496 701 49929 0 1 0 1 1340 50 18 0 1 0 884794219 2654208 294 1283457024 134512640 135304128 4288224176 18446744073709551615 4294960130 0 65536 4 65538 18446744071564329979 0 0 17 0 0 0 0
/proc/1571/statm: 648 294 249 194 0 34 0
[pid=1592] ppid=1571 vsize=44848 CPUtime=4
/proc/1592/stat : 1592 (apt-get) R 1571 1571 4159 34819 4229 4202496 19152 0 535 0 384 16 0 0 21 0 1 0 884795783 45924352 10147 1283457024 134512640 134619611 4287442784 18446744073709551615 4159727407 0 0 4096 134217728 0 0 0 17 0 0 0 0
/proc/1592/statm: 11212 10147 9292 27 0 899 0
Current children cumulated CPU time (s) 17.91
Current children cumulated vsize (KiB) 47440

Child status: 100
Real time (s): 21.4769
CPU time (s): 17.9891
CPU user time (s): 17.3011
CPU system time (s): 0.688043
CPU usage (%): 83.7603
Max. virtual memory (cumulated for all children) (KiB): 185824

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 17.3011
system time used= 0.688043
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 69803
page faults= 536
swaps= 0
block input operations= 0
block output operations= 0
messages sent= 0
messages received= 0
signals received= 0
voluntary context switches= 589
involuntary context switches= 337

runsolver used 0 second user time and 0 second system time

The end