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 -W 300 -M 1124 -w /home/cbse/results/sarge-etch/logs/12.runsolver.smart smart --config-file=/home/cbse/var/lib/smart/config install titrax mozilla-locale-ko python2.2-egenix-mxstack libuuid1 websec Enforcing wall clock limit (soft limit, will send signal-name then SIGKILL): 300 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 [startup+0 s] /proc/loadavg: 1.00 0.99 0.91 2/53 4034 /proc/meminfo: memFree=458248/1022884 swapFree=0/0 [pid=4034] ppid=4033 vsize=3152 CPUtime=0 /proc/4034/stat : 4034 (runsolver) R 4033 2806 2806 34818 2806 4202560 0 0 0 0 0 0 0 0 20 0 1 0 1206874 3227648 33 18446744073709551615 134512640 134586868 4293914544 4293912592 4152034352 0 0 0 24578 0 0 0 17 0 0 0 0 0 0 /proc/4034/statm: 788 33 0 19 0 73 0 Current StackSize limit: 8192 KiB [startup+0.197609 s] /proc/loadavg: 1.00 0.99 0.91 2/53 4034 /proc/meminfo: memFree=458248/1022884 swapFree=0/0 [pid=4034] ppid=4033 vsize=120420 CPUtime=0.18 /proc/4034/stat : 4034 (smart) R 4033 4034 2806 34818 2806 4202496 13586 413 0 0 14 4 0 0 20 0 1 0 1206874 123310080 7809 18446744073709551615 4194304 6763684 140735472706624 140735472702616 5748609 0 0 16777216 134217730 0 0 0 17 0 0 0 0 0 0 /proc/4034/statm: 30105 7809 1058 628 0 6658 0 Current children cumulated CPU time (s) 0.18 Current children cumulated vsize (KiB) 120420 [startup+0.200249 s] /proc/loadavg: 1.00 0.99 0.91 2/53 4034 /proc/meminfo: memFree=458248/1022884 swapFree=0/0 [pid=4034] ppid=4033 vsize=120420 CPUtime=0.19 /proc/4034/stat : 4034 (smart) R 4033 4034 2806 34818 2806 4202496 13628 413 0 0 14 5 0 0 20 0 1 0 1206874 123310080 7848 18446744073709551615 4194304 6763684 140735472706624 140735472702680 5512004 0 0 16777216 134217730 0 0 0 17 0 0 0 0 0 0 /proc/4034/statm: 30105 7848 1059 628 0 6658 0 Current children cumulated CPU time (s) 0.19 Current children cumulated vsize (KiB) 120420 [startup+0.300183 s] /proc/loadavg: 1.00 0.99 0.91 2/53 4034 /proc/meminfo: memFree=458248/1022884 swapFree=0/0 [pid=4034] ppid=4033 vsize=135008 CPUtime=0.29 /proc/4034/stat : 4034 (smart) R 4033 4034 2806 34818 2806 4202496 17271 413 0 0 23 6 0 0 20 0 1 0 1206874 138248192 11491 18446744073709551615 4194304 6763684 140735472706624 140735472702568 4363525 0 0 16777216 134217730 0 0 0 17 0 0 0 0 0 0 /proc/4034/statm: 33752 11491 1059 628 0 10305 0 Current children cumulated CPU time (s) 0.29 Current children cumulated vsize (KiB) 135008 [startup+0.700189 s] /proc/loadavg: 1.00 0.99 0.91 2/53 4034 /proc/meminfo: memFree=458248/1022884 swapFree=0/0 [pid=4034] ppid=4033 vsize=196192 CPUtime=0.69 /proc/4034/stat : 4034 (smart) R 4033 4034 2806 34818 2806 4202496 35629 413 0 0 59 10 0 0 20 0 1 0 1206874 200900608 26763 18446744073709551615 4194304 6763684 140735472706624 140735472702424 5743360 0 0 16777216 134217730 0 0 0 17 0 0 0 0 0 0 /proc/4034/statm: 49048 26763 1059 628 0 25601 0 Current children cumulated CPU time (s) 0.69 Current children cumulated vsize (KiB) 196192 [startup+1.5002 s] /proc/loadavg: 1.00 0.99 0.91 2/54 4037 /proc/meminfo: memFree=344904/1022884 swapFree=0/0 [pid=4034] ppid=4033 vsize=207776 CPUtime=1.48 /proc/4034/stat : 4034 (smart) R 4033 4034 2806 34818 2806 4202496 44751 413 0 0 136 12 0 0 20 0 1 0 1206874 212762624 29707 18446744073709551615 4194304 6763684 140735472706624 140735472701760 4414165 0 0 16777216 134217734 0 0 0 17 0 0 0 0 0 0 /proc/4034/statm: 51944 29707 1069 628 0 28497 0 Current children cumulated CPU time (s) 1.48 Current children cumulated vsize (KiB) 207776 [startup+3.10017 s] /proc/loadavg: 1.00 0.99 0.91 2/54 4037 /proc/meminfo: memFree=343292/1022884 swapFree=0/0 [pid=4034] ppid=4033 vsize=207776 CPUtime=3.08 /proc/4034/stat : 4034 (smart) R 4033 4034 2806 34818 2806 4202496 44761 413 0 0 296 12 0 0 20 0 1 0 1206874 212762624 29708 18446744073709551615 4194304 6763684 140735472706624 140735472703576 139788360871220 0 0 16777216 134217734 0 0 0 17 0 0 0 0 0 0 /proc/4034/statm: 51944 29708 1070 628 0 28497 0 Current children cumulated CPU time (s) 3.08 Current children cumulated vsize (KiB) 207776 [startup+6.30018 s] /proc/loadavg: 1.00 0.99 0.91 2/54 4037 /proc/meminfo: memFree=343292/1022884 swapFree=0/0 [pid=4034] ppid=4033 vsize=207776 CPUtime=6.26 /proc/4034/stat : 4034 (smart) R 4033 4034 2806 34818 2806 4202496 44761 413 0 0 614 12 0 0 20 0 1 0 1206874 212762624 29708 18446744073709551615 4194304 6763684 140735472706624 140735472703576 139788360867680 0 0 16777216 134217734 0 0 0 17 0 0 0 0 0 0 /proc/4034/statm: 51944 29708 1070 628 0 28497 0 Current children cumulated CPU time (s) 6.26 Current children cumulated vsize (KiB) 207776 [startup+12.7002 s] /proc/loadavg: 1.00 0.99 0.91 2/54 4037 /proc/meminfo: memFree=343168/1022884 swapFree=0/0 [pid=4034] ppid=4033 vsize=207776 CPUtime=12.64 /proc/4034/stat : 4034 (smart) R 4033 4034 2806 34818 2806 4202496 44761 413 0 0 1252 12 0 0 20 0 1 0 1206874 212762624 29708 18446744073709551615 4194304 6763684 140735472706624 140735472703576 139788343119553 0 0 16777216 134217734 0 0 0 17 0 0 0 0 0 0 /proc/4034/statm: 51944 29708 1070 628 0 28497 0 Current children cumulated CPU time (s) 12.64 Current children cumulated vsize (KiB) 207776 [startup+25.5002 s] /proc/loadavg: 1.00 0.99 0.91 2/54 4037 /proc/meminfo: memFree=343168/1022884 swapFree=0/0 [pid=4034] ppid=4033 vsize=207776 CPUtime=25.39 /proc/4034/stat : 4034 (smart) R 4033 4034 2806 34818 2806 4202496 44761 413 0 0 2527 12 0 0 20 0 1 0 1206874 212762624 29708 18446744073709551615 4194304 6763684 140735472706624 140735472703576 139788343119553 0 0 16777216 134217734 0 0 0 17 0 0 0 0 0 0 /proc/4034/statm: 51944 29708 1070 628 0 28497 0 Current children cumulated CPU time (s) 25.39 Current children cumulated vsize (KiB) 207776 [startup+51.1002 s] /proc/loadavg: 1.00 0.99 0.91 2/54 4037 /proc/meminfo: memFree=343168/1022884 swapFree=0/0 [pid=4034] ppid=4033 vsize=207776 CPUtime=50.91 /proc/4034/stat : 4034 (smart) R 4033 4034 2806 34818 2806 4202496 44761 413 0 0 5079 12 0 0 20 0 1 0 1206874 212762624 29708 18446744073709551615 4194304 6763684 140735472706624 140735472703576 139788343104192 0 0 16777216 134217734 0 0 0 17 0 0 0 0 0 0 /proc/4034/statm: 51944 29708 1070 628 0 28497 0 Current children cumulated CPU time (s) 50.91 Current children cumulated vsize (KiB) 207776 Solver just ended. Dumping a history of the last processes samples [startup+51.2002 s] /proc/loadavg: 1.00 0.99 0.91 2/54 4037 /proc/meminfo: memFree=343168/1022884 swapFree=0/0 [pid=4034] ppid=4033 vsize=207776 CPUtime=51.01 /proc/4034/stat : 4034 (smart) R 4033 4034 2806 34818 2806 4202496 44761 413 0 0 5089 12 0 0 20 0 1 0 1206874 212762624 29708 18446744073709551615 4194304 6763684 140735472706624 140735472703576 139788343119562 0 0 16777216 134217734 0 0 0 17 0 0 0 0 0 0 /proc/4034/statm: 51944 29708 1070 628 0 28497 0 Current children cumulated CPU time (s) 51.01 Current children cumulated vsize (KiB) 207776 [startup+54.4002 s] /proc/loadavg: 1.00 0.99 0.91 2/54 4037 /proc/meminfo: memFree=343168/1022884 swapFree=0/0 [pid=4034] ppid=4033 vsize=207776 CPUtime=54.19 /proc/4034/stat : 4034 (smart) R 4033 4034 2806 34818 2806 4202496 44761 413 0 0 5407 12 0 0 20 0 1 0 1206874 212762624 29708 18446744073709551615 4194304 6763684 140735472706624 140735472703576 139788343119553 0 0 16777216 134217734 0 0 0 17 0 0 0 0 0 0 /proc/4034/statm: 51944 29708 1070 628 0 28497 0 Current children cumulated CPU time (s) 54.19 Current children cumulated vsize (KiB) 207776 [startup+55.2002 s] /proc/loadavg: 1.00 0.99 0.91 2/54 4037 /proc/meminfo: memFree=343168/1022884 swapFree=0/0 [pid=4034] ppid=4033 vsize=207776 CPUtime=54.99 /proc/4034/stat : 4034 (smart) R 4033 4034 2806 34818 2806 4202496 44761 413 0 0 5487 12 0 0 20 0 1 0 1206874 212762624 29708 18446744073709551615 4194304 6763684 140735472706624 140735472703576 5155614 0 0 16777216 134217734 0 0 0 17 0 0 0 0 0 0 /proc/4034/statm: 51944 29708 1070 628 0 28497 0 Current children cumulated CPU time (s) 54.99 Current children cumulated vsize (KiB) 207776 [startup+55.6002 s] /proc/loadavg: 1.00 0.99 0.91 2/54 4037 /proc/meminfo: memFree=343168/1022884 swapFree=0/0 [pid=4034] ppid=4033 vsize=207776 CPUtime=55.39 /proc/4034/stat : 4034 (smart) R 4033 4034 2806 34818 2806 4202496 44761 413 0 0 5527 12 0 0 20 0 1 0 1206874 212762624 29708 18446744073709551615 4194304 6763684 140735472706624 140735472703576 5155011 0 0 16777216 134217734 0 0 0 17 0 0 0 0 0 0 /proc/4034/statm: 51944 29708 1070 628 0 28497 0 Current children cumulated CPU time (s) 55.39 Current children cumulated vsize (KiB) 207776 [startup+56.0002 s] /proc/loadavg: 1.00 0.99 0.91 2/54 4037 /proc/meminfo: memFree=343168/1022884 swapFree=0/0 [pid=4034] ppid=4033 vsize=207792 CPUtime=55.79 /proc/4034/stat : 4034 (smart) R 4033 4034 2806 34818 2806 4202496 44794 413 0 0 5567 12 0 0 20 0 1 0 1206874 212779008 29717 18446744073709551615 4194304 6763684 140735472706624 140735472705512 4424399 0 0 16777216 0 0 0 0 17 0 0 0 0 0 0 /proc/4034/statm: 51948 29717 1076 628 0 28501 0 Current children cumulated CPU time (s) 55.79 Current children cumulated vsize (KiB) 207792 Child status: 0 Real time (s): 56.0141 CPU time (s): 55.8195 CPU user time (s): 55.6835 CPU system time (s): 0.136008 CPU usage (%): 99.6526 Max. virtual memory (cumulated for all children) (KiB): 207792 getrusage(RUSAGE_CHILDREN,...) data: user time used= 55.6835 system time used= 0.136008 maximum resident set size= 120000 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 45628 page faults= 0 swaps= 0 block input operations= 0 block output operations= 8 messages sent= 0 messages received= 0 signals received= 0 voluntary context switches= 6 involuntary context switches= 826 runsolver used 0.064004 second user time and 0.140008 second system time The end