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/201103110955/apt-pbo-paranoid-1.0.8/rand948.cudf.heavy.log.runsolver ./apt-pbo-paranoid-1.0.8 /home/misc2010/data/misc4/heavy//rand948.cudf /home/misc2010/tmp/201103110955/apt-pbo-paranoid-1.0.8/rand948.cudf.heavy.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.00 1.01 1.00 5/37 9215 /proc/meminfo: memFree=245628/1048576 swapFree=0/0 [pid=9213] ppid=9212 vsize=1672 CPUtime=0 /proc/9213/stat : 9213 (sh) S 9212 9213 12462 34817 12462 4202496 222 176 0 0 0 0 0 0 18 0 1 0 144959477 1712128 129 1283457024 134512640 134593992 4290987616 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0 /proc/9213/statm: 418 129 112 20 0 45 0 [pid=9215] ppid=9213 vsize=4092 CPUtime=0.02 /proc/9215/stat : 9215 (apt-pbo) R 9213 9213 12462 34817 12462 4202496 706 0 0 0 2 0 0 0 25 0 1 0 144959477 4190208 654 1283457024 134512640 135745756 4286671216 18446744073709551615 134660865 0 0 128 0 0 0 0 17 0 0 0 0 /proc/9215/statm: 1023 654 406 302 0 287 0 [startup+0.193346 s] /proc/loadavg: 1.00 1.01 1.00 5/37 9215 /proc/meminfo: memFree=245628/1048576 swapFree=0/0 [pid=9213] ppid=9212 vsize=1672 CPUtime=0 /proc/9213/stat : 9213 (sh) S 9212 9213 12462 34817 12462 4202496 222 176 0 0 0 0 0 0 18 0 1 0 144959477 1712128 129 1283457024 134512640 134593992 4290987616 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0 /proc/9213/statm: 418 129 112 20 0 45 0 [pid=9215] ppid=9213 vsize=8228 CPUtime=0.05 /proc/9215/stat : 9215 (apt-pbo) S 9213 9213 12462 34817 12462 4202496 1579 409 0 0 4 0 0 1 25 0 1 0 144959477 8425472 1401 1283457024 134512640 135745756 4286671216 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0 /proc/9215/statm: 2057 1401 648 302 0 790 0 Current children cumulated CPU time (s) 0.05 Current children cumulated vsize (KiB) 9900 [startup+0.205386 s] /proc/loadavg: 1.00 1.01 1.00 5/37 9215 /proc/meminfo: memFree=245628/1048576 swapFree=0/0 [pid=9213] ppid=9212 vsize=1672 CPUtime=0 /proc/9213/stat : 9213 (sh) S 9212 9213 12462 34817 12462 4202496 222 176 0 0 0 0 0 0 18 0 1 0 144959477 1712128 129 1283457024 134512640 134593992 4290987616 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0 /proc/9213/statm: 418 129 112 20 0 45 0 [pid=9215] ppid=9213 vsize=8228 CPUtime=0.05 /proc/9215/stat : 9215 (apt-pbo) S 9213 9213 12462 34817 12462 4202496 1579 409 0 0 4 0 0 1 25 0 1 0 144959477 8425472 1401 1283457024 134512640 135745756 4286671216 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0 /proc/9215/statm: 2057 1401 648 302 0 790 0 Current children cumulated CPU time (s) 0.05 Current children cumulated vsize (KiB) 9900 [startup+0.30543 s] /proc/loadavg: 1.00 1.01 1.00 5/37 9215 /proc/meminfo: memFree=245628/1048576 swapFree=0/0 [pid=9213] ppid=9212 vsize=1672 CPUtime=0 /proc/9213/stat : 9213 (sh) S 9212 9213 12462 34817 12462 4202496 222 176 0 0 0 0 0 0 18 0 1 0 144959477 1712128 129 1283457024 134512640 134593992 4290987616 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0 /proc/9213/statm: 418 129 112 20 0 45 0 [pid=9215] ppid=9213 vsize=8228 CPUtime=0.05 /proc/9215/stat : 9215 (apt-pbo) S 9213 9213 12462 34817 12462 4202496 1579 409 0 0 4 0 0 1 25 0 1 0 144959477 8425472 1401 1283457024 134512640 135745756 4286671216 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0 /proc/9215/statm: 2057 1401 648 302 0 790 0 Current children cumulated CPU time (s) 0.05 Current children cumulated vsize (KiB) 9900 [startup+0.705499 s] /proc/loadavg: 1.00 1.01 1.00 5/37 9215 /proc/meminfo: memFree=245628/1048576 swapFree=0/0 [pid=9213] ppid=9212 vsize=1672 CPUtime=0 /proc/9213/stat : 9213 (sh) S 9212 9213 12462 34817 12462 4202496 222 176 0 0 0 0 0 0 18 0 1 0 144959477 1712128 129 1283457024 134512640 134593992 4290987616 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0 /proc/9213/statm: 418 129 112 20 0 45 0 [pid=9215] ppid=9213 vsize=8228 CPUtime=0.05 /proc/9215/stat : 9215 (apt-pbo) S 9213 9213 12462 34817 12462 4202496 1579 409 0 0 4 0 0 1 25 0 1 0 144959477 8425472 1401 1283457024 134512640 135745756 4286671216 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0 /proc/9215/statm: 2057 1401 648 302 0 790 0 Current children cumulated CPU time (s) 0.05 Current children cumulated vsize (KiB) 9900 [startup+1.50544 s] /proc/loadavg: 1.00 1.01 1.00 2/39 9219 /proc/meminfo: memFree=217308/1048576 swapFree=0/0 [pid=9213] ppid=9212 vsize=1672 CPUtime=0 /proc/9213/stat : 9213 (sh) S 9212 9213 12462 34817 12462 4202496 222 176 0 0 0 0 0 0 18 0 1 0 144959477 1712128 129 1283457024 134512640 134593992 4290987616 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0 /proc/9213/statm: 418 129 112 20 0 45 0 [pid=9215] ppid=9213 vsize=8228 CPUtime=0.05 /proc/9215/stat : 9215 (apt-pbo) S 9213 9213 12462 34817 12462 4202496 1579 409 0 0 4 0 0 1 25 0 1 0 144959477 8425472 1401 1283457024 134512640 135745756 4286671216 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0 /proc/9215/statm: 2057 1401 648 302 0 790 0 [pid=9219] ppid=9215 vsize=29684 CPUtime=1.43 /proc/9219/stat : 9219 (cudftodeb.nativ) R 9215 9213 12462 34817 12462 4202496 7089 0 0 0 136 7 0 0 25 0 1 0 144959483 30396416 7009 1283457024 134512640 135029684 4294523216 18446744073709551615 135012031 0 0 0 1024 0 0 0 17 0 0 0 0 /proc/9219/statm: 7421 7009 246 127 0 6802 0 Current children cumulated CPU time (s) 1.48 Current children cumulated vsize (KiB) 39584 [startup+3.10595 s] /proc/loadavg: 1.00 1.01 1.00 2/39 9219 /proc/meminfo: memFree=191040/1048576 swapFree=0/0 [pid=9213] ppid=9212 vsize=1672 CPUtime=0 /proc/9213/stat : 9213 (sh) S 9212 9213 12462 34817 12462 4202496 222 176 0 0 0 0 0 0 18 0 1 0 144959477 1712128 129 1283457024 134512640 134593992 4290987616 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0 /proc/9213/statm: 418 129 112 20 0 45 0 [pid=9215] ppid=9213 vsize=8228 CPUtime=0.05 /proc/9215/stat : 9215 (apt-pbo) S 9213 9213 12462 34817 12462 4202496 1579 409 0 0 4 0 0 1 25 0 1 0 144959477 8425472 1401 1283457024 134512640 135745756 4286671216 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0 /proc/9215/statm: 2057 1401 648 302 0 790 0 [pid=9219] ppid=9215 vsize=61192 CPUtime=3.02 /proc/9219/stat : 9219 (cudftodeb.nativ) R 9215 9213 12462 34817 12462 4202496 14916 0 0 0 294 8 0 0 25 0 1 0 144959483 62660608 14836 1283457024 134512640 135029684 4294523216 18446744073709551615 4159845130 0 0 0 1024 0 0 0 17 0 0 0 0 /proc/9219/statm: 15298 14836 257 127 0 14679 0 Current children cumulated CPU time (s) 3.07 Current children cumulated vsize (KiB) 71092 [startup+6.31259 s] /proc/loadavg: 1.00 1.01 1.00 2/39 9219 /proc/meminfo: memFree=180212/1048576 swapFree=0/0 [pid=9213] ppid=9212 vsize=1672 CPUtime=0 /proc/9213/stat : 9213 (sh) S 9212 9213 12462 34817 12462 4202496 222 176 0 0 0 0 0 0 18 0 1 0 144959477 1712128 129 1283457024 134512640 134593992 4290987616 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0 /proc/9213/statm: 418 129 112 20 0 45 0 [pid=9215] ppid=9213 vsize=8228 CPUtime=6.16 /proc/9215/stat : 9215 (apt-pbo) S 9213 9213 12462 34817 12462 4202496 1752 17953 0 0 5 0 508 103 18 0 1 0 144959477 8425472 1427 1283457024 134512640 135745756 4286671216 18446744073709551615 4294960130 0 0 135 0 18446744071564329979 0 0 17 0 0 0 0 /proc/9215/statm: 2057 1427 653 302 0 790 0 Current children cumulated CPU time (s) 6.16 Current children cumulated vsize (KiB) 9900 [startup+12.7138 s] /proc/loadavg: 1.16 1.05 1.01 4/40 10180 /proc/meminfo: memFree=166220/1048576 swapFree=0/0 [pid=9213] ppid=9212 vsize=1672 CPUtime=0 /proc/9213/stat : 9213 (sh) S 9212 9213 12462 34817 12462 4202496 222 176 0 0 0 0 0 0 18 0 1 0 144959477 1712128 129 1283457024 134512640 134593992 4290987616 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0 /proc/9213/statm: 418 129 112 20 0 45 0 [pid=9215] ppid=9213 vsize=39628 CPUtime=11.25 /proc/9215/stat : 9215 (apt-pbo) S 9213 9213 12462 34817 12462 4202496 65981 546934 0 242 56 48 740 281 25 0 1 0 144959477 40579072 9067 1283457024 134512640 135745756 4286671216 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0 /proc/9215/statm: 9907 9067 4905 302 0 4192 0 Current children cumulated CPU time (s) 11.25 Current children cumulated vsize (KiB) 41300 [startup+25.5062 s] /proc/loadavg: 1.13 1.04 1.01 2/39 10215 /proc/meminfo: memFree=135740/1048576 swapFree=0/0 [pid=9213] ppid=9212 vsize=1672 CPUtime=0 /proc/9213/stat : 9213 (sh) S 9212 9213 12462 34817 12462 4202496 222 176 0 0 0 0 0 0 18 0 1 0 144959477 1712128 129 1283457024 134512640 134593992 4290987616 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0 /proc/9213/statm: 418 129 112 20 0 45 0 [pid=9215] ppid=9213 vsize=40392 CPUtime=11.92 /proc/9215/stat : 9215 (apt-pbo) S 9213 9213 12462 34817 12462 4202496 66297 553215 0 242 56 49 798 289 18 0 1 0 144959477 41361408 9263 1283457024 134512640 135745756 4286671216 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0 /proc/9215/statm: 10098 9263 4908 302 0 4383 0 [pid=10215] ppid=9215 vsize=19988 CPUtime=12.26 /proc/10215/stat : 10215 (wbo) R 9215 9213 12462 34817 12462 4202496 6152 0 0 0 1200 26 0 0 25 0 1 0 144960801 20467712 4559 1283457024 134512640 135755527 4289338464 18446744073709551615 134516982 0 0 0 3 0 0 0 17 0 0 0 0 /proc/10215/statm: 4997 4559 147 304 0 4691 0 Current children cumulated CPU time (s) 24.18 Current children cumulated vsize (KiB) 62052 [startup+51.1125 s] /proc/loadavg: 1.09 1.04 1.01 2/39 10215 /proc/meminfo: memFree=124828/1048576 swapFree=0/0 [pid=9213] ppid=9212 vsize=1672 CPUtime=0 /proc/9213/stat : 9213 (sh) S 9212 9213 12462 34817 12462 4202496 222 176 0 0 0 0 0 0 18 0 1 0 144959477 1712128 129 1283457024 134512640 134593992 4290987616 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0 /proc/9213/statm: 418 129 112 20 0 45 0 [pid=9215] ppid=9213 vsize=40392 CPUtime=11.92 /proc/9215/stat : 9215 (apt-pbo) S 9213 9213 12462 34817 12462 4202496 66297 553215 0 242 56 49 798 289 18 0 1 0 144959477 41361408 9263 1283457024 134512640 135745756 4286671216 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0 /proc/9215/statm: 10098 9263 4908 302 0 4383 0 [pid=10215] ppid=9215 vsize=31028 CPUtime=37.83 /proc/10215/stat : 10215 (wbo) R 9215 9213 12462 34817 12462 4202496 8897 0 0 0 3738 45 0 0 25 0 1 0 144960801 31772672 7304 1283457024 134512640 135755527 4289338464 18446744073709551615 134516976 0 0 0 3 0 0 0 17 0 0 0 0 /proc/10215/statm: 7757 7304 147 304 0 7451 0 Current children cumulated CPU time (s) 49.75 Current children cumulated vsize (KiB) 73092 [startup+102.304 s] /proc/loadavg: 1.03 1.03 1.00 2/39 10215 /proc/meminfo: memFree=109700/1048576 swapFree=0/0 [pid=9213] ppid=9212 vsize=1672 CPUtime=0 /proc/9213/stat : 9213 (sh) S 9212 9213 12462 34817 12462 4202496 222 176 0 0 0 0 0 0 18 0 1 0 144959477 1712128 129 1283457024 134512640 134593992 4290987616 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0 /proc/9213/statm: 418 129 112 20 0 45 0 [pid=9215] ppid=9213 vsize=40392 CPUtime=11.92 /proc/9215/stat : 9215 (apt-pbo) S 9213 9213 12462 34817 12462 4202496 66297 553215 0 242 56 49 798 289 18 0 1 0 144959477 41361408 9263 1283457024 134512640 135745756 4286671216 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0 /proc/9215/statm: 10098 9263 4908 302 0 4383 0 [pid=10215] ppid=9215 vsize=46456 CPUtime=88.97 /proc/10215/stat : 10215 (wbo) R 9215 9213 12462 34817 12462 4202496 12709 0 0 0 8821 76 0 0 25 0 1 0 144960801 47570944 11116 1283457024 134512640 135755527 4289338464 18446744073709551615 134517446 0 0 0 3 0 0 0 17 0 0 0 0 /proc/10215/statm: 11614 11116 147 304 0 11308 0 Current children cumulated CPU time (s) 100.89 Current children cumulated vsize (KiB) 88520 [startup+162.309 s] /proc/loadavg: 1.01 1.02 1.00 2/39 10215 /proc/meminfo: memFree=94572/1048576 swapFree=0/0 [pid=9213] ppid=9212 vsize=1672 CPUtime=0 /proc/9213/stat : 9213 (sh) S 9212 9213 12462 34817 12462 4202496 222 176 0 0 0 0 0 0 18 0 1 0 144959477 1712128 129 1283457024 134512640 134593992 4290987616 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0 /proc/9213/statm: 418 129 112 20 0 45 0 [pid=9215] ppid=9213 vsize=40392 CPUtime=11.92 /proc/9215/stat : 9215 (apt-pbo) S 9213 9213 12462 34817 12462 4202496 66297 553215 0 242 56 49 798 289 18 0 1 0 144959477 41361408 9263 1283457024 134512640 135745756 4286671216 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0 /proc/9215/statm: 10098 9263 4908 302 0 4383 0 [pid=10215] ppid=9215 vsize=61944 CPUtime=148.92 /proc/10215/stat : 10215 (wbo) R 9215 9213 12462 34817 12462 4202496 16529 0 0 0 14796 96 0 0 25 0 1 0 144960801 63430656 14936 1283457024 134512640 135755527 4289338464 18446744073709551615 134589374 0 0 0 3 0 0 0 17 0 0 0 0 /proc/10215/statm: 15486 14936 147 304 0 15180 0 Current children cumulated CPU time (s) 160.84 Current children cumulated vsize (KiB) 104008 [startup+222.314 s] /proc/loadavg: 1.00 1.02 1.00 2/41 10221 /proc/meminfo: memFree=81272/1048576 swapFree=0/0 [pid=9213] ppid=9212 vsize=1672 CPUtime=0 /proc/9213/stat : 9213 (sh) S 9212 9213 12462 34817 12462 4202496 222 176 0 0 0 0 0 0 18 0 1 0 144959477 1712128 129 1283457024 134512640 134593992 4290987616 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0 /proc/9213/statm: 418 129 112 20 0 45 0 [pid=9215] ppid=9213 vsize=40392 CPUtime=11.92 /proc/9215/stat : 9215 (apt-pbo) S 9213 9213 12462 34817 12462 4202496 66297 553215 0 242 56 49 798 289 18 0 1 0 144959477 41361408 9263 1283457024 134512640 135745756 4286671216 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0 /proc/9215/statm: 10098 9263 4908 302 0 4383 0 [pid=10215] ppid=9215 vsize=75172 CPUtime=208.87 /proc/10215/stat : 10215 (wbo) R 9215 9213 12462 34817 12462 4202496 19776 0 0 0 20769 118 0 0 25 0 1 0 144960801 76976128 18183 1283457024 134512640 135755527 4289338464 18446744073709551615 134589280 0 0 0 3 0 0 0 17 0 0 0 0 /proc/10215/statm: 18793 18183 147 304 0 18487 0 Current children cumulated CPU time (s) 220.79 Current children cumulated vsize (KiB) 117236 [startup+282.309 s] /proc/loadavg: 1.00 1.01 1.00 2/40 10226 /proc/meminfo: memFree=56620/1048576 swapFree=0/0 [pid=9213] ppid=9212 vsize=1672 CPUtime=0 /proc/9213/stat : 9213 (sh) S 9212 9213 12462 34817 12462 4202496 222 176 0 0 0 0 0 0 18 0 1 0 144959477 1712128 129 1283457024 134512640 134593992 4290987616 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0 /proc/9213/statm: 418 129 112 20 0 45 0 [pid=9215] ppid=9213 vsize=40392 CPUtime=11.92 /proc/9215/stat : 9215 (apt-pbo) S 9213 9213 12462 34817 12462 4202496 66297 553215 0 242 56 49 798 289 18 0 1 0 144959477 41361408 9263 1283457024 134512640 135745756 4286671216 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0 /proc/9215/statm: 10098 9263 4908 302 0 4383 0 [pid=10215] ppid=9215 vsize=99512 CPUtime=268.8 /proc/10215/stat : 10215 (wbo) R 9215 9213 12462 34817 12462 4202496 25899 0 0 0 26746 134 0 0 25 0 1 0 144960801 101900288 24272 1283457024 134512640 135755527 4289338464 18446744073709551615 134579374 0 0 0 3 0 0 0 17 0 0 0 0 /proc/10215/statm: 24878 24272 147 304 0 24572 0 Current children cumulated CPU time (s) 280.72 Current children cumulated vsize (KiB) 141576 Maximum CPU time exceeded: sending signal-name then SIGKILL [startup+291.611 s] /proc/loadavg: 1.00 1.01 1.00 2/40 10226 /proc/meminfo: memFree=56620/1048576 swapFree=0/0 [pid=9213] ppid=9212 vsize=1672 CPUtime=0 /proc/9213/stat : 9213 (sh) S 9212 9213 12462 34817 12462 4202496 222 176 0 0 0 0 0 0 18 0 1 0 144959477 1712128 129 1283457024 134512640 134593992 4290987616 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0 /proc/9213/statm: 418 129 112 20 0 45 0 [pid=9215] ppid=9213 vsize=40392 CPUtime=11.92 /proc/9215/stat : 9215 (apt-pbo) S 9213 9213 12462 34817 12462 4202496 66297 553215 0 242 56 49 798 289 18 0 1 0 144959477 41361408 9263 1283457024 134512640 135745756 4286671216 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0 /proc/9215/statm: 10098 9263 4908 302 0 4383 0 [pid=10215] ppid=9215 vsize=99512 CPUtime=278.09 /proc/10215/stat : 10215 (wbo) R 9215 9213 12462 34817 12462 4202496 25899 0 0 0 27672 137 0 0 25 0 1 0 144960801 101900288 24272 1283457024 134512640 135755527 4289338464 18446744073709551615 134589267 0 0 0 3 0 0 0 17 0 0 0 0 /proc/10215/statm: 24878 24272 147 304 0 24572 0 Current children cumulated CPU time (s) 290.01 Current children cumulated vsize (KiB) 141576 Sending User defined signal 1 to process tree (bottom up) Sleeping 10 seconds Solver just ended. Dumping a history of the last processes samples [startup+291.611 s] /proc/loadavg: 1.00 1.01 1.00 2/40 10226 /proc/meminfo: memFree=56620/1048576 swapFree=0/0 [pid=9213] ppid=9212 vsize=1672 CPUtime=0 /proc/9213/stat : 9213 (sh) S 9212 9213 12462 34817 12462 4202496 222 176 0 0 0 0 0 0 18 0 1 0 144959477 1712128 129 1283457024 134512640 134593992 4290987616 18446744073709551615 4294960130 0 0 0 2 18446744071564329979 0 0 17 0 0 0 0 /proc/9213/statm: 418 129 112 20 0 45 0 [pid=9215] ppid=9213 vsize=40392 CPUtime=11.92 /proc/9215/stat : 9215 (apt-pbo) S 9213 9213 12462 34817 12462 4202496 66297 553215 0 242 56 49 798 289 18 0 1 0 144959477 41361408 9263 1283457024 134512640 135745756 4286671216 18446744073709551615 4294960130 0 0 128 0 18446744071564457842 0 0 17 0 0 0 0 /proc/9215/statm: 10098 9263 4908 302 0 4383 0 [pid=10215] ppid=9215 vsize=99512 CPUtime=278.09 /proc/10215/stat : 10215 (wbo) R 9215 9213 12462 34817 12462 4202496 25899 0 0 0 27672 137 0 0 25 0 1 0 144960801 101900288 24272 1283457024 134512640 135755527 4289338464 18446744073709551615 134589267 0 0 0 3 0 0 0 17 0 0 0 0 /proc/10215/statm: 24878 24272 147 304 0 24572 0 Current children cumulated CPU time (s) 290.01 Current children cumulated vsize (KiB) 141576 Child status: 138 # WARNING: # CPU time reported by wait4() is probably wrong ! # wait4(...,&childrusage) returns 9213 and gives # childrusage.ru_utime.tv_sec=8 # childrusage.ru_utime.tv_usec=556534 # childrusage.ru_stime.tv_sec=3 # childrusage.ru_stime.tv_usec=384211 # CPU time returned by wait4() is 11.9407 # while last known CPU time is 290.01 # # Solver probably didn't/couldn't wait for its children # Using CPU time of the last sample as value... Real time (s): 291.626 CPU time (s): 290.01 CPU user time (s): 285.26 CPU system time (s): 4.75 CPU usage (%): 99.446 Max. virtual memory (cumulated for all children) (KiB): 141740 getrusage(RUSAGE_CHILDREN,...) data: user time used= 8.55653 system time used= 3.38421 maximum resident set size= 0 integral shared memory size= 0 integral unshared data size= 0 integral unshared stack size= 0 page reclaims= 619920 page faults= 242 swaps= 0 block input operations= 0 block output operations= 0 messages sent= 0 messages received= 0 signals received= 0 voluntary context switches= 4032 involuntary context switches= 2914 runsolver used 0.004 second user time and 0 second system time The end