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 -s SIGUSR1 -M 1124 -C 300 -d 10 -w /tmp/misc2012/2012-09-02-22:42/full/aspuncud-full-1.7/dist-upgrade/real/d5026b8e-3477-11e0-986e-00163e3d3b7c.cudf.log.runsolver /home/competition/aspuncud-full-1.7/aspuncud-full /home/competition/data/real/d5026b8e-3477-11e0-986e-00163e3d3b7c.cudf /tmp/misc2012/2012-09-02-22:42/full/aspuncud-full-1.7/dist-upgrade/real/d5026b8e-3477-11e0-986e-00163e3d3b7c.cudf.result -notuptodate(solution),-aligned(solution,source,sourceversion),-unsat_recommends(solution),-count(new) 

Enforcing CPUTime limit (soft limit, will send signal-name then SIGKILL): 300 seconds
Enforcing CPUTime limit (hard limit, will send SIGXCPU): 330 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.01 1.05 1.01 2/59 13299
/proc/meminfo: memFree=396208/1022884 swapFree=0/0
[pid=13299] ppid=13298 vsize=3152 CPUtime=0
/proc/13299/stat : 13299 (runsolver) R 13298 1750 1750 0 -1 4202560 0 0 0 0 0 0 0 0 20 0 1 0 118019151 3227648 32 18446744073709551615 134512640 134586868 4288205648 4288203696 4151354416 0 0 16781316 24578 0 0 0 17 0 0 0 0 0 0
/proc/13299/statm: 788 32 0 19 0 73 0
Current StackSize limit: 8192 KiB


[startup+0.188227 s]
/proc/loadavg: 1.01 1.05 1.01 2/59 13299
/proc/meminfo: memFree=396208/1022884 swapFree=0/0
[pid=13299] ppid=13298 vsize=9212 CPUtime=0.02
/proc/13299/stat : 13299 (aspuncud-full) S 13298 13299 1750 0 -1 4202496 695 2814 0 0 0 0 2 0 20 0 1 0 118019151 9433088 364 18446744073709551615 4194304 5129932 140733497949216 140733497947872 139980900074590 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/13299/statm: 2303 364 303 229 0 63 0
Current children cumulated CPU time (s) 0.02
Current children cumulated vsize (KiB) 9212

[startup+0.200325 s]
/proc/loadavg: 1.01 1.05 1.01 2/59 13299
/proc/meminfo: memFree=396208/1022884 swapFree=0/0
[pid=13299] ppid=13298 vsize=9212 CPUtime=0.02
/proc/13299/stat : 13299 (aspuncud-full) S 13298 13299 1750 0 -1 4202496 695 2814 0 0 0 0 2 0 20 0 1 0 118019151 9433088 364 18446744073709551615 4194304 5129932 140733497949216 140733497947872 139980900074590 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/13299/statm: 2303 364 303 229 0 63 0
Current children cumulated CPU time (s) 0.02
Current children cumulated vsize (KiB) 9212

[startup+0.300226 s]
/proc/loadavg: 1.01 1.05 1.01 2/59 13299
/proc/meminfo: memFree=396208/1022884 swapFree=0/0
[pid=13299] ppid=13298 vsize=9212 CPUtime=0.02
/proc/13299/stat : 13299 (aspuncud-full) S 13298 13299 1750 0 -1 4202496 695 2814 0 0 0 0 2 0 20 0 1 0 118019151 9433088 364 18446744073709551615 4194304 5129932 140733497949216 140733497947872 139980900074590 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/13299/statm: 2303 364 303 229 0 63 0
Current children cumulated CPU time (s) 0.02
Current children cumulated vsize (KiB) 9212

[startup+0.700228 s]
/proc/loadavg: 1.01 1.05 1.01 2/59 13299
/proc/meminfo: memFree=396208/1022884 swapFree=0/0
[pid=13299] ppid=13298 vsize=9212 CPUtime=0.02
/proc/13299/stat : 13299 (aspuncud-full) S 13298 13299 1750 0 -1 4202496 695 2814 0 0 0 0 2 0 20 0 1 0 118019151 9433088 364 18446744073709551615 4194304 5129932 140733497949216 140733497947872 139980900074590 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/13299/statm: 2303 364 303 229 0 63 0
Current children cumulated CPU time (s) 0.02
Current children cumulated vsize (KiB) 9212

[startup+1.50023 s]
/proc/loadavg: 1.01 1.05 1.01 2/61 13312
/proc/meminfo: memFree=354024/1022884 swapFree=0/0
[pid=13299] ppid=13298 vsize=9212 CPUtime=0.02
/proc/13299/stat : 13299 (aspuncud-full) S 13298 13299 1750 0 -1 4202496 695 2814 0 0 0 0 2 0 20 0 1 0 118019151 9433088 364 18446744073709551615 4194304 5129932 140733497949216 140733497947872 139980900074590 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/13299/statm: 2303 364 303 229 0 63 0
[pid=13312] ppid=13299 vsize=65876 CPUtime=1.3
/proc/13312/stat : 13312 (cudf2lp) R 13299 13299 1750 0 -1 4202496 18083 0 0 0 122 8 0 0 20 0 1 0 118019153 67457024 14685 18446744073709551615 4194304 5690517 140736981332704 140736981329832 4271595 0 0 16781316 0 0 0 0 17 0 0 0 15 0 0
/proc/13312/statm: 16469 14685 168 366 0 16100 0
Current children cumulated CPU time (s) 1.32
Current children cumulated vsize (KiB) 75088

[startup+3.10023 s]
/proc/loadavg: 1.00 1.05 1.01 2/61 13313
/proc/meminfo: memFree=365432/1022884 swapFree=0/0
[pid=13299] ppid=13298 vsize=9212 CPUtime=1.8
/proc/13299/stat : 13299 (aspuncud-full) S 13298 13299 1750 0 -1 4202496 722 22508 0 0 0 0 166 14 20 0 1 0 118019151 9433088 364 18446744073709551615 4194304 5129932 140733497949216 140733497947872 139980900074590 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/13299/statm: 2303 364 303 229 0 63 0
[pid=13313] ppid=13299 vsize=108184 CPUtime=1.11
/proc/13313/stat : 13313 (gringo) R 13299 13299 1750 0 -1 4202496 25642 0 0 0 101 10 0 0 20 0 1 0 118019348 110780416 21457 18446744073709551615 4194304 6531320 140737447785392 140737447782008 4359010 0 0 16781316 16386 0 0 0 17 0 0 0 0 0 0
/proc/13313/statm: 27046 21457 282 571 0 26467 0
Current children cumulated CPU time (s) 2.91
Current children cumulated vsize (KiB) 117396

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

[startup+3.20033 s]
/proc/loadavg: 1.00 1.05 1.01 2/61 13313
/proc/meminfo: memFree=365432/1022884 swapFree=0/0
[pid=13299] ppid=13298 vsize=9212 CPUtime=1.8
/proc/13299/stat : 13299 (aspuncud-full) S 13298 13299 1750 0 -1 4202496 722 22508 0 0 0 0 166 14 20 0 1 0 118019151 9433088 364 18446744073709551615 4194304 5129932 140733497949216 140733497947872 139980900074590 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/13299/statm: 2303 364 303 229 0 63 0
[pid=13313] ppid=13299 vsize=127480 CPUtime=1.21
/proc/13313/stat : 13313 (gringo) R 13299 13299 1750 0 -1 4202496 29858 0 0 0 110 11 0 0 20 0 1 0 118019348 130539520 25673 18446744073709551615 4194304 6531320 140737447785392 140737447781736 4452624 0 0 16781316 16386 0 0 0 17 0 0 0 0 0 0
/proc/13313/statm: 31870 25673 282 571 0 31291 0
Current children cumulated CPU time (s) 3.01
Current children cumulated vsize (KiB) 136692

[startup+3.60032 s]
/proc/loadavg: 1.00 1.05 1.01 2/61 13313
/proc/meminfo: memFree=262380/1022884 swapFree=0/0
[pid=13299] ppid=13298 vsize=9212 CPUtime=3.35
/proc/13299/stat : 13299 (aspuncud-full) S 13298 13299 1750 0 -1 4202496 761 56991 0 0 0 0 304 31 20 0 1 0 118019151 9433088 364 18446744073709551615 4194304 5129932 140733497949216 140733497947280 139980900074590 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/13299/statm: 2303 364 303 229 0 63 0
Current children cumulated CPU time (s) 3.35
Current children cumulated vsize (KiB) 9212

[startup+3.80023 s]
/proc/loadavg: 1.00 1.05 1.01 2/61 13313
/proc/meminfo: memFree=262380/1022884 swapFree=0/0
[pid=13299] ppid=13298 vsize=9212 CPUtime=3.35
/proc/13299/stat : 13299 (aspuncud-full) S 13298 13299 1750 0 -1 4202496 761 56991 0 0 0 0 304 31 20 0 1 0 118019151 9433088 364 18446744073709551615 4194304 5129932 140733497949216 140733497947280 139980900074590 0 65536 16781316 1115778811 0 0 0 17 0 0 0 0 0 0
/proc/13299/statm: 2303 364 303 229 0 63 0
Current children cumulated CPU time (s) 3.35
Current children cumulated vsize (KiB) 9212

Child status: 0
Real time (s): 3.86131
CPU time (s): 3.69223
CPU user time (s): 3.31621
CPU system time (s): 0.376023
CPU usage (%): 95.6213
Max. virtual memory (cumulated for all children) (KiB): 156556

getrusage(RUSAGE_CHILDREN,...) data:
user time used= 3.31621
system time used= 0.376023
maximum resident set size= 121176
integral shared memory size= 0
integral unshared data size= 0
integral unshared stack size= 0
page reclaims= 72962
page faults= 0
swaps= 0
block input operations= 29472
block output operations= 18664
messages sent= 0
messages received= 0
signals received= 0
voluntary context switches= 128
involuntary context switches= 510

runsolver used 0.008 second user time and 0.016001 second system time

The end