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/201108251442/packup2mp4pa-0.6/rand519.cudf.user-upgrades.log.runsolver ./packup2mp4pa-0.6 /home/misc2010/data/2011/user-upgrades/rand519.cudf /home/misc2010/tmp/201108251442/packup2mp4pa-0.6/rand519.cudf.user-upgrades.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.65 1.39 1.17 4/36 20239
/proc/meminfo: memFree=279804/1048576 swapFree=0/0
[pid=20238] ppid=20237 vsize=2572 CPUtime=0
/proc/20238/stat : 20238 (packup2mp4pa-0.) S 20237 20238 4778 34817 4778 4202496 379 0 0 0 0 0 0 0 18 0 1 0 11121637 2633728 274 1283457024 134512640 135304128 4292821024 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/20238/statm: 643 274 233 194 0 30 0
[pid=20239] ppid=20238 vsize=3712 CPUtime=0.01
/proc/20239/stat : 20239 (packup) R 20238 20238 4778 34817 4778 4202496 405 0 0 0 1 0 0 0 25 0 1 0 11121637 3801088 334 1283457024 134512640 134752139 4287937344 18446744073709551615 134682048 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/20239/statm: 928 334 286 59 0 92 0

[startup+0.183679 s]
/proc/loadavg: 1.65 1.39 1.17 4/36 20239
/proc/meminfo: memFree=279804/1048576 swapFree=0/0
[pid=20238] ppid=20237 vsize=2572 CPUtime=0
/proc/20238/stat : 20238 (packup2mp4pa-0.) S 20237 20238 4778 34817 4778 4202496 379 0 0 0 0 0 0 0 18 0 1 0 11121637 2633728 274 1283457024 134512640 135304128 4292821024 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/20238/statm: 643 274 233 194 0 30 0
[pid=20239] ppid=20238 vsize=9272 CPUtime=0.19
/proc/20239/stat : 20239 (packup) R 20238 20238 4778 34817 4778 4202496 1797 0 0 0 18 1 0 0 25 0 1 0 11121637 9494528 1726 1283457024 134512640 134752139 4287937344 18446744073709551615 4157429167 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/20239/statm: 2318 1726 286 59 0 1482 0
Current children cumulated CPU time (s) 0.19
Current children cumulated vsize (KiB) 11844

[startup+0.213683 s]
/proc/loadavg: 1.65 1.39 1.17 4/36 20239
/proc/meminfo: memFree=279804/1048576 swapFree=0/0
[pid=20238] ppid=20237 vsize=2572 CPUtime=0
/proc/20238/stat : 20238 (packup2mp4pa-0.) S 20237 20238 4778 34817 4778 4202496 379 0 0 0 0 0 0 0 18 0 1 0 11121637 2633728 274 1283457024 134512640 135304128 4292821024 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/20238/statm: 643 274 233 194 0 30 0
[pid=20239] ppid=20238 vsize=10064 CPUtime=0.21
/proc/20239/stat : 20239 (packup) R 20238 20238 4778 34817 4778 4202496 2006 0 0 0 19 2 0 0 25 0 1 0 11121637 10305536 1935 1283457024 134512640 134752139 4287937344 18446744073709551615 134681493 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/20239/statm: 2516 1935 286 59 0 1680 0
Current children cumulated CPU time (s) 0.21
Current children cumulated vsize (KiB) 12636

[startup+0.303711 s]
/proc/loadavg: 1.65 1.39 1.17 4/36 20239
/proc/meminfo: memFree=279804/1048576 swapFree=0/0
[pid=20238] ppid=20237 vsize=2572 CPUtime=0
/proc/20238/stat : 20238 (packup2mp4pa-0.) S 20237 20238 4778 34817 4778 4202496 379 0 0 0 0 0 0 0 18 0 1 0 11121637 2633728 274 1283457024 134512640 135304128 4292821024 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/20238/statm: 643 274 233 194 0 30 0
[pid=20239] ppid=20238 vsize=12332 CPUtime=0.3
/proc/20239/stat : 20239 (packup) R 20238 20238 4778 34817 4778 4202496 2584 0 0 0 28 2 0 0 25 0 1 0 11121637 12627968 2513 1283457024 134512640 134752139 4287937344 18446744073709551615 134681733 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/20239/statm: 3083 2513 286 59 0 2247 0
Current children cumulated CPU time (s) 0.3
Current children cumulated vsize (KiB) 14904

[startup+0.70381 s]
/proc/loadavg: 1.65 1.39 1.17 4/36 20239
/proc/meminfo: memFree=279804/1048576 swapFree=0/0
[pid=20238] ppid=20237 vsize=2572 CPUtime=0
/proc/20238/stat : 20238 (packup2mp4pa-0.) S 20237 20238 4778 34817 4778 4202496 379 0 0 0 0 0 0 0 18 0 1 0 11121637 2633728 274 1283457024 134512640 135304128 4292821024 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/20238/statm: 643 274 233 194 0 30 0
[pid=20239] ppid=20238 vsize=21652 CPUtime=0.7
/proc/20239/stat : 20239 (packup) R 20238 20238 4778 34817 4778 4202496 4895 0 0 0 66 4 0 0 25 0 1 0 11121637 22171648 4824 1283457024 134512640 134752139 4287937344 18446744073709551615 4157430565 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/20239/statm: 5413 4824 286 59 0 4577 0
Current children cumulated CPU time (s) 0.7
Current children cumulated vsize (KiB) 24224

[startup+1.50398 s]
/proc/loadavg: 1.60 1.38 1.17 2/37 20240
/proc/meminfo: memFree=253504/1048576 swapFree=0/0
[pid=20238] ppid=20237 vsize=2572 CPUtime=0
/proc/20238/stat : 20238 (packup2mp4pa-0.) S 20237 20238 4778 34817 4778 4202496 379 0 0 0 0 0 0 0 18 0 1 0 11121637 2633728 274 1283457024 134512640 135304128 4292821024 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/20238/statm: 643 274 233 194 0 30 0
[pid=20239] ppid=20238 vsize=37372 CPUtime=1.43
/proc/20239/stat : 20239 (packup) S 20238 20238 4778 34817 4778 4202496 8878 0 0 0 132 11 0 0 25 0 1 0 11121637 38268928 8757 1283457024 134512640 134752139 4287937344 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/20239/statm: 9343 8757 324 59 0 8507 0
Current children cumulated CPU time (s) 1.43
Current children cumulated vsize (KiB) 39944

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

[startup+1.614 s]
/proc/loadavg: 1.60 1.38 1.17 2/37 20240
/proc/meminfo: memFree=253504/1048576 swapFree=0/0
[pid=20238] ppid=20237 vsize=2572 CPUtime=0
/proc/20238/stat : 20238 (packup2mp4pa-0.) S 20237 20238 4778 34817 4778 4202496 379 0 0 0 0 0 0 0 18 0 1 0 11121637 2633728 274 1283457024 134512640 135304128 4292821024 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/20238/statm: 643 274 233 194 0 30 0
[pid=20239] ppid=20238 vsize=37372 CPUtime=1.43
/proc/20239/stat : 20239 (packup) S 20238 20238 4778 34817 4778 4202496 8878 0 0 0 132 11 0 0 25 0 1 0 11121637 38268928 8757 1283457024 134512640 134752139 4287937344 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/20239/statm: 9343 8757 324 59 0 8507 0
Current children cumulated CPU time (s) 1.43
Current children cumulated vsize (KiB) 39944

[startup+2.40416 s]
/proc/loadavg: 1.60 1.38 1.17 2/39 20244
/proc/meminfo: memFree=240328/1048576 swapFree=0/0
[pid=20238] ppid=20237 vsize=2572 CPUtime=0
/proc/20238/stat : 20238 (packup2mp4pa-0.) S 20237 20238 4778 34817 4778 4202496 379 0 0 0 0 0 0 0 18 0 1 0 11121637 2633728 274 1283457024 134512640 135304128 4292821024 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/20238/statm: 643 274 233 194 0 30 0
[pid=20239] ppid=20238 vsize=37376 CPUtime=1.94
/proc/20239/stat : 20239 (packup) S 20238 20238 4778 34817 4778 4202496 8924 4369 0 0 133 17 39 5 21 0 1 0 11121637 38273024 8766 1283457024 134512640 134752139 4287937344 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/20239/statm: 9344 8766 332 59 0 8508 0
[pid=20243] ppid=20239 vsize=1676 CPUtime=0
/proc/20243/stat : 20243 (sh) S 20239 20238 4778 34817 4778 4202496 146 0 0 0 0 0 0 0 21 0 1 0 11121833 1716224 124 1283457024 134512640 134593992 4289369424 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/20243/statm: 419 124 108 20 0 46 0
[pid=20244] ppid=20243 vsize=19592 CPUtime=0.43
/proc/20244/stat : 20244 (minisatp_32) R 20243 20238 4778 34817 4778 4202496 6388 0 0 0 40 3 0 0 25 0 1 0 11121834 20062208 4547 1283457024 134512640 135413687 4289375600 18446744073709551615 134696603 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/20244/statm: 4898 4547 108 220 0 4676 0
Current children cumulated CPU time (s) 2.37
Current children cumulated vsize (KiB) 61216

[startup+2.6042 s]
/proc/loadavg: 1.60 1.38 1.17 2/39 20244
/proc/meminfo: memFree=240328/1048576 swapFree=0/0
[pid=20238] ppid=20237 vsize=2572 CPUtime=0
/proc/20238/stat : 20238 (packup2mp4pa-0.) S 20237 20238 4778 34817 4778 4202496 379 0 0 0 0 0 0 0 18 0 1 0 11121637 2633728 274 1283457024 134512640 135304128 4292821024 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/20238/statm: 643 274 233 194 0 30 0
[pid=20239] ppid=20238 vsize=37376 CPUtime=1.94
/proc/20239/stat : 20239 (packup) S 20238 20238 4778 34817 4778 4202496 8924 4369 0 0 133 17 39 5 21 0 1 0 11121637 38273024 8766 1283457024 134512640 134752139 4287937344 18446744073709551615 4294960130 0 65536 18950 8192 18446744071564329979 0 0 17 0 0 0 0
/proc/20239/statm: 9344 8766 332 59 0 8508 0
[pid=20243] ppid=20239 vsize=1676 CPUtime=0
/proc/20243/stat : 20243 (sh) S 20239 20238 4778 34817 4778 4202496 146 0 0 0 0 0 0 0 21 0 1 0 11121833 1716224 124 1283457024 134512640 134593992 4289369424 18446744073709551615 4294960130 0 0 18944 2 18446744071564329979 0 0 17 0 0 0 0
/proc/20243/statm: 419 124 108 20 0 46 0
[pid=20244] ppid=20243 vsize=23740 CPUtime=0.63
/proc/20244/stat : 20244 (minisatp_32) R 20243 20238 4778 34817 4778 4202496 8091 0 0 0 59 4 0 0 25 0 1 0 11121834 24309760 5320 1283457024 134512640 135413687 4289375600 18446744073709551615 134698792 0 0 18944 0 0 0 0 17 0 0 0 0
/proc/20244/statm: 5935 5320 108 220 0 5713 0
Current children cumulated CPU time (s) 2.57
Current children cumulated vsize (KiB) 65364

[startup+2.70424 s]
/proc/loadavg: 1.60 1.38 1.17 2/39 20244
/proc/meminfo: memFree=240328/1048576 swapFree=0/0
[pid=20238] ppid=20237 vsize=2572 CPUtime=0
/proc/20238/stat : 20238 (packup2mp4pa-0.) S 20237 20238 4778 34817 4778 4202496 379 0 0 0 0 0 0 0 18 0 1 0 11121637 2633728 274 1283457024 134512640 135304128 4292821024 18446744073709551615 4294960130 0 65536 4 84482 18446744071564329979 0 0 17 0 0 0 0
/proc/20238/statm: 643 274 233 194 0 30 0
[pid=20239] ppid=20238 vsize=37380 CPUtime=2.68
/proc/20239/stat : 20239 (packup) R 20238 20238 4778 34817 4778 4202496 16050 12979 0 0 135 19 104 10 16 0 1 0 11121637 38277120 8780 1283457024 134512640 134752139 4287937344 18446744073709551615 4159193284 0 0 18944 8192 0 0 0 17 0 0 0 0
/proc/20239/statm: 9345 8780 345 59 0 8509 0
Current children cumulated CPU time (s) 2.68
Current children cumulated vsize (KiB) 39952

Child status: 0
Real time (s): 2.74472
CPU time (s): 2.74817
CPU user time (s): 2.42015
CPU system time (s): 0.32802
CPU usage (%): 100.126
Max. virtual memory (cumulated for all children) (KiB): 66128

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 2.42015
system time used= 0.32802
maximum resident set size= 0
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 30542
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= 11
involuntary context switches= 73

runsolver used 0 second user time and 0 second system time

The end