You are viewing a plain text version of this content. The canonical link for it is here.
Posted to user@mesos.apache.org by Eren Güven <er...@gmail.com> on 2015/10/02 11:00:34 UTC

Re: resource fragmentation/mesos-master offers too low

Hey Vinod,

Mesos: 0.23.0-1.0.ubuntu1404
Marathon: 0.10.1-1.0.416.ubuntu1404
Chronos: 2.4.0-0.1.20150828104228.ubuntu1404

Single master, 16 slaves, each with 6cpu 6mem, many (perhaps not all) had
more resources than mentioned in the logs (mesos offers with 6m mem etc..)
or what was required for the marathon tasks (.25cpu 128mem).

# cat /etc/mesos-master/offer_timeout
30secs

Marathon is running 200-400 tasks at any given time, chronos <20.

There aren't too much interesting in the logs, prior to this many lines of
Marathon app definition and then the 'Not all basic resources satisfied'
spam starts, something like


Sep 29 09:35:35 lab-mesos-master1 marathon[60609]: [INFO] [09/29/2015
09:35:35.938] [marathon-akka.actor.default-dispatcher-1396]
[akka://marathon/user/MarathonScheduler/$a/DeploymentManager/6d87463d-38
d6-4f20-86ba-9caefce12ad7/$a] Successfully started 0 instances of ****
Sep 29 09:35:36 lab-mesos-master1 mesos-master[60442]: I0929
09:35:36.444304 60462 master.cpp:4290] Sending 1 offers to framework
20150928-140031-2581335306-5050-60442-0000 (marathon) at scheduler-3cced
735-b1d8-4739-adae-b479a0411593@127.0.1.1:50185
Sep 29 09:35:36 lab-mesos-master1 mesos-master[60442]: I0929
09:35:36.445269 60462 master.cpp:4290] Sending 3 offers to framework
20150928-104536-2581335306-5050-25731-0000 (chronos-2.4.0) at scheduler-
16cd75ef-d383-4c4c-8239-89a0c1fac536@127.0.1.1:57205
Sep 29 09:35:36 lab-mesos-master1 chronos[60791]: [2015-09-29 09:35:36,447]
INFO Received resource offers
(org.apache.mesos.chronos.scheduler.mesos.MesosJobFramework:82)
Sep 29 09:35:36 lab-mesos-master1 chronos[60791]: [2015-09-29 09:35:36,447]
INFO No tasks scheduled or next task has been disabled.
Sep 29 09:35:36 lab-mesos-master1 chronos[60791]:
 (org.apache.mesos.chronos.scheduler.mesos.MesosJobFramework:131)
Sep 29 09:35:36 lab-mesos-master1 chronos[60791]: [2015-09-29 09:35:36,447]
INFO Declining unused offers.
(org.apache.mesos.chronos.scheduler.mesos.MesosJobFramework:89)
Sep 29 09:35:36 lab-mesos-master1 chronos[60791]: [2015-09-29 09:35:36,448]
INFO Declined unused offers with filter refuseSeconds=5.0 (use
--decline_offer_duration to reconfigure) (org.apache.mesos.chro
nos.scheduler.mesos.MesosJobFramework:97)
Sep 29 09:35:36 lab-mesos-master1 mesos-master[60442]: I0929
09:35:36.450083 60465 master.cpp:2884] Processing DECLINE call for offers:
[ 20150928-140031-2581335306-5050-60442-O436519 ] for framework 20
150928-104536-2581335306-5050-25731-0000 (chronos-2.4.0) at
scheduler-16cd75ef-d383-4c4c-8239-89a0c1fac536@127.0.1.1:57205
Sep 29 09:35:36 lab-mesos-master1 mesos-master[60442]: I0929
09:35:36.451763 60465 master.cpp:2884] Processing DECLINE call for offers:
[ 20150928-140031-2581335306-5050-60442-O436520 ] for framework 20
150928-104536-2581335306-5050-25731-0000 (chronos-2.4.0) at
scheduler-16cd75ef-d383-4c4c-8239-89a0c1fac536@127.0.1.1:57205
Sep 29 09:35:36 lab-mesos-master1 mesos-master[60442]: I0929
09:35:36.453340 60465 master.cpp:2884] Processing DECLINE call for offers:
[ 20150928-140031-2581335306-5050-60442-O436521 ] for framework 20
150928-104536-2581335306-5050-25731-0000 (chronos-2.4.0) at
scheduler-16cd75ef-d383-4c4c-8239-89a0c1fac536@127.0.1.1:57205
Sep 29 09:35:36 lab-mesos-master1 mesos-master[60442]: I0929
09:35:36.457660 60467 hierarchical.hpp:761] Recovered cpus(*):0.05;
mem(*):12; disk(*):41211; ports(*):[31000-31005, 31007-31014, 31016-31063
, 31065-31088, 31090-31146, 31148-31176, 31178-31193, 31195-31226,
31228-31239, 31241-31321, 31323-31367, 31369-31524, 31526-31544,
31546-31562, 31564-31564, 31566-31598, 31600-31667, 31669-31709, 31711
-31711, 31713-31732, 31734-31750, 31752-31850, 31852-31864, 31866-31910,
31912-31992, 31994-32000] (total: cpus(*):6; mem(*):2922; disk(*):41211;
ports(*):[31000-32000], allocated: cpus(*):5.95; mem(*):
2910; ports(*):[31006-31006, 31015-31015, 31064-31064, 31089-31089,
31147-31147, 31177-31177, 31194-31194, 31227-31227, 31240-31240,
31322-31322, 31368-31368, 31525-31525, 31545-31545, 31563-31563, 3156
5-31565, 31599-31599, 31668-31668, 31710-31710, 31712-31712, 31733-31733,
31751-31751, 31851-31851, 31865-31865, 31911-31911, 31993-31993]) on slave
20150827-122131-2581335306-5050-34525-S274 from frame
work 20150928-104536-2581335306-5050-25731-0000
Sep 29 09:35:36 lab-mesos-master1 mesos-master[60442]: I0929
09:35:36.459028 60467 hierarchical.hpp:761] Recovered cpus(*):1.45;
mem(*):70; disk(*):41211; ports(*):[31000-31236, 31238-31242, 31244-31256
, 31258-31262, 31264-31267, 31269-31307, 31309-31313, 31315-31450,
31452-31486, 31488-31618, 31620-31622, 31624-31634, 31636-31653,
31655-31751, 31753-31826, 31828-31837, 31839-31896, 31898-31962, 31964
-31967, 31969-31983, 31985-32000] (total: cpus(*):6; mem(*):2922;
disk(*):41211; ports(*):[31000-32000], allocated: cpus(*):4.55;
mem(*):2852; ports(*):[31237-31237, 31243-31243, 31257-31257, 31263-3126
3, 31268-31268, 31308-31308, 31314-31314, 31451-31451, 31487-31487,
31619-31619, 31623-31623, 31635-31635, 31654-31654, 31752-31752,
31827-31827, 31838-31838, 31897-31897, 31963-31963, 31968-31968, 3198
4-31984]) on slave 20150914-120632-2581335306-5050-1803-S32633 from
framework 20150928-104536-2581335306-5050-25731-0000
Sep 29 09:35:36 lab-mesos-master1 mesos-master[60442]: I0929
09:35:36.461617 60467 hierarchical.hpp:761] Recovered cpus(*):1.35;
mem(*):34; disk(*):41211; ports(*):[31000-31036, 31038-31133, 31135-31135
, 31137-31217, 31219-31278, 31280-31313, 31315-31341, 31343-31386,
31388-31499, 31501-31528, 31530-31550, 31552-31650, 31652-31754,
31756-31788, 31790-31856, 31858-31873, 31875-31881, 31883-31920, 31922
-31939, 31941-31952, 31954-31984, 31986-32000] (total: cpus(*):6;
mem(*):2922; disk(*):41211; ports(*):[31000-32000], allocated:
cpus(*):4.65; mem(*):2888; ports(*):[31037-31037, 31134-31134, 31136-3113
6, 31218-31218, 31279-31279, 31314-31314, 31342-31342, 31387-31387,
31500-31500, 31529-31529, 31551-31551, 31651-31651, 31755-31755,
31789-31789, 31857-31857, 31874-31874, 31882-31882, 31921-31921, 3194
0-31940, 31953-31953, 31985-31985]) on slave
20150827-122131-2581335306-5050-34525-S277 from framework
20150928-104536-2581335306-5050-25731-0000
Sep 29 09:35:36 lab-mesos-master1 marathon[60609]: [2015-09-29
09:35:36,473] INFO started processing 1 offers, launching at most 1 tasks
per offer and 1000 tasks in total (mesosphere.marathon.tasks.Iter
ativeOfferMatcher$:132)
Sep 29 09:35:36 lab-mesos-master1 marathon[60609]: [2015-09-29
09:35:36,474] INFO Offer [20150928-140031-2581335306-5050-60442-O436518].
Not all basic resources satisfied: cpu SATISFIED (0.25 <= 0.79999
99999999998), disk SATISFIED (0.0 <= 0.0), mem NOT SATISFIED (128.0 > 6.0)
(mesosphere.mesos.ResourceMatcher$:121)
Sep 29 09:35:36 lab-mesos-master1 marathon[60609]: [2015-09-29
09:35:36,475] INFO Offer [20150928-140031-2581335306-5050-60442-O436518].
Insufficient resources for [****] (need cpus=0.25, mem=128.0, disk=0.0,
ports=(1 dynamic), available in offer:


... then this starts with Marathon app details in between:


Sep 29 09:35:36 lab-mesos-master1 marathon[60609]: [2015-09-29
09:35:36,474] INFO Offer [20150928-140031-2581335306-5050-60442-O436518].
Not all basic resources satisfied: cpu SATISFIED (0.25 <=
0.7999999999999998), disk SATISFIED (0.0 <= 0.0), mem NOT SATISFIED (128.0
> 6.0) (mesosphere.mesos.ResourceMatcher$:121)
Sep 29 09:35:36 lab-mesos-master1 marathon[60609]: [2015-09-29
09:35:36,481] INFO Offer [20150928-140031-2581335306-5050-60442-O436518].
Not all basic resources satisfied: cpu SATISFIED (0.25 <=
0.7999999999999998), disk SATISFIED (0.0 <= 0.0), mem NOT SATISFIED (128.0
> 6.0) (mesosphere.mesos.ResourceMatcher$:121)
Sep 29 09:35:36 lab-mesos-master1 marathon[60609]: [2015-09-29
09:35:36,483] INFO Offer [20150928-140031-2581335306-5050-60442-O436518].
Not all basic resources satisfied: cpu SATISFIED (0.25 <=
0.7999999999999998), disk SATISFIED (0.0 <= 0.0), mem NOT SATISFIED (320.0
> 6.0) (mesosphere.mesos.ResourceMatcher$:121)
Sep 29 09:35:36 lab-mesos-master1 marathon[60609]: [2015-09-29
09:35:36,484] INFO Offer [20150928-140031-2581335306-5050-60442-O436518].
Not all basic resources satisfied: cpu SATISFIED (0.25 <=
0.7999999999999998), disk SATISFIED (0.0 <= 0.0), mem NOT SATISFIED (128.0
> 6.0) (mesosphere.mesos.ResourceMatcher$:121)
Sep 29 09:35:37 lab-mesos-master1 marathon[60609]: [2015-09-29
09:35:37,493] INFO Offer [20150928-140031-2581335306-5050-60442-O436522].
Not all basic resources satisfied: cpu NOT SATISFIED (0.25 >
0.05000000000000071), disk SATISFIED (0.0 <= 0.0), mem NOT SATISFIED (128.0
> 12.0) (mesosphere.mesos.ResourceMatcher$:121)
Sep 29 09:35:37 lab-mesos-master1 marathon[60609]: [2015-09-29
09:35:37,494] INFO Offer [20150928-140031-2581335306-5050-60442-O436522].
Not all basic resources satisfied: cpu NOT SATISFIED (0.25 >
0.05000000000000071), disk SATISFIED (0.0 <= 0.0), mem NOT SATISFIED (128.0
> 12.0) (mesosphere.mesos.ResourceMatcher$:121)
Sep 29 09:35:37 lab-mesos-master1 marathon[60609]: [2015-09-29
09:35:37,495] INFO Offer [20150928-140031-2581335306-5050-60442-O436522].
Not all basic resources satisfied: cpu NOT SATISFIED (0.25 >
0.05000000000000071), disk SATISFIED (0.0 <= 0.0), mem NOT SATISFIED (320.0
> 12.0) (mesosphere.mesos.ResourceMatcher$:121)
Sep 29 09:35:37 lab-mesos-master1 marathon[60609]: [2015-09-29
09:35:37,496] INFO Offer [20150928-140031-2581335306-5050-60442-O436522].
Not all basic resources satisfied: cpu NOT SATISFIED (0.25 >
0.05000000000000071), disk SATISFIED (0.0 <= 0.0), mem NOT SATISFIED (128.0
> 12.0) (mesosphere.mesos.ResourceMatcher$:121)
Sep 29 09:35:38 lab-mesos-master1 marathon[60609]: [2015-09-29
09:35:38,527] INFO Offer [20150928-140031-2581335306-5050-60442-O436523].
Not all basic resources satisfied: cpu SATISFIED (0.25 <= 1.25), disk
SATISFIED (0.0 <= 0.0), mem NOT SATISFIED (128.0 > 42.0)
(mesosphere.mesos.ResourceMatcher$:121)
Sep 29 09:35:38 lab-mesos-master1 marathon[60609]: [2015-09-29
09:35:38,528] INFO Offer [20150928-140031-2581335306-5050-60442-O436523].
Not all basic resources satisfied: cpu SATISFIED (0.25 <= 1.25), disk
SATISFIED (0.0 <= 0.0), mem NOT SATISFIED (128.0 > 42.0)
(mesosphere.mesos.ResourceMatcher$:121)
Sep 29 09:35:38 lab-mesos-master1 marathon[60609]: [2015-09-29
09:35:38,529] INFO Offer [20150928-140031-2581335306-5050-60442-O436523].
Not all basic resources satisfied: cpu SATISFIED (0.25 <= 1.25), disk
SATISFIED (0.0 <= 0.0), mem NOT SATISFIED (128.0 > 42.0)
(mesosphere.mesos.ResourceMatcher$:121)
Sep 29 09:35:38 lab-mesos-master1 marathon[60609]: [2015-09-29
09:35:38,530] INFO Offer [20150928-140031-2581335306-5050-60442-O436523].
Not all basic resources satisfied: cpu SATISFIED (0.25 <= 1.25), disk
SATISFIED (0.0 <= 0.0), mem NOT SATISFIED (320.0 > 42.0)
(mesosphere.mesos.ResourceMatcher$:121)
Sep 29 09:35:38 lab-mesos-master1 marathon[60609]: [2015-09-29
09:35:38,531] INFO Offer [20150928-140031-2581335306-5050-60442-O436523].
Not all basic resources satisfied: cpu SATISFIED (0.25 <= 1.25), disk
SATISFIED (0.0 <= 0.0), mem NOT SATISFIED (128.0 > 42.0)
(mesosphere.mesos.ResourceMatcher$:121)
Sep 29 09:35:38 lab-mesos-master1 marathon[60609]: [2015-09-29
09:35:38,546] INFO Offer [20150928-140031-2581335306-5050-60442-O436525].
Not all basic resources satisfied: cpu SATISFIED (0.25 <=
0.5500000000000007), disk SATISFIED (0.0 <= 0.0), mem NOT SATISFIED (128.0
> 6.0) (mesosphere.mesos.ResourceMatcher$:121)
Sep 29 09:35:38 lab-mesos-master1 marathon[60609]: [2015-09-29
09:35:38,547] INFO Offer [20150928-140031-2581335306-5050-60442-O436525].
Not all basic resources satisfied: cpu SATISFIED (0.25 <=
0.5500000000000007), disk SATISFIED (0.0 <= 0.0), mem NOT SATISFIED (128.0
> 6.0) (mesosphere.mesos.ResourceMatcher$:121)
Sep 29 09:35:38 lab-mesos-master1 marathon[60609]: [2015-09-29
09:35:38,548] INFO Offer [20150928-140031-2581335306-5050-60442-O436525].
Not all basic resources satisfied: cpu SATISFIED (0.25 <=
0.5500000000000007), disk SATISFIED (0.0 <= 0.0), mem NOT SATISFIED (320.0
> 6.0) (mesosphere.mesos.ResourceMatcher$:121)
Sep 29 09:35:38 lab-mesos-master1 marathon[60609]: [2015-09-29
09:35:38,549] INFO Offer [20150928-140031-2581335306-5050-60442-O436525].
Not all basic resources satisfied: cpu SATISFIED (0.25 <=
0.5500000000000007), disk SATISFIED (0.0 <= 0.0), mem NOT SATISFIED (128.0
> 6.0) (mesosphere.mesos.ResourceMatcher$:121)
Sep 29 09:35:38 lab-mesos-master1 marathon[60609]: [2015-09-29
09:35:38,550] INFO Offer [20150928-140031-2581335306-5050-60442-O436526].
Not all basic resources satisfied: cpu NOT SATISFIED (0.25 >
0.05000000000000071), disk SATISFIED (0.0 <= 0.0), mem SATISFIED (128.0 <=
204.0) (mesosphere.mesos.ResourceMatcher$:121)
Sep 29 09:35:38 lab-mesos-master1 marathon[60609]: [2015-09-29
09:35:38,551] INFO Offer [20150928-140031-2581335306-5050-60442-O436526].
Not all basic resources satisfied: cpu NOT SATISFIED (0.25 >
0.05000000000000071), disk SATISFIED (0.0 <= 0.0), mem SATISFIED (128.0 <=
204.0) (mesosphere.mesos.ResourceMatcher$:121)
Sep 29 09:35:38 lab-mesos-master1 marathon[60609]: [2015-09-29
09:35:38,557] INFO Offer [20150928-140031-2581335306-5050-60442-O436526].
Not all basic resources satisfied: cpu NOT SATISFIED (0.25 >
0.05000000000000071), disk SATISFIED (0.0 <= 0.0), mem NOT SATISFIED (320.0
> 204.0) (mesosphere.mesos.ResourceMatcher$:121)
Sep 29 09:35:38 lab-mesos-master1 marathon[60609]: [2015-09-29
09:35:38,558] INFO Offer [20150928-140031-2581335306-5050-60442-O436526].
Not all basic resources satisfied: cpu NOT SATISFIED (0.25 >
0.05000000000000071), disk SATISFIED (0.0 <= 0.0), mem SATISFIED (128.0 <=
204.0) (mesosphere.mesos.ResourceMatcher$:121)
Sep 29 09:35:38 lab-mesos-master1 marathon[60609]: [2015-09-29
09:35:38,559] INFO Offer [20150928-140031-2581335306-5050-60442-O436527].
Not all basic resources satisfied: cpu not in offer, disk SATISFIED (0.0 <=
0.0), mem SATISFIED (128.0 <= 1964.0)
(mesosphere.mesos.ResourceMatcher$:121)
Sep 29 09:35:38 lab-mesos-master1 marathon[60609]: [2015-09-29
09:35:38,560] INFO Offer [20150928-140031-2581335306-5050-60442-O436527].
Not all basic resources satisfied: cpu not in offer, disk SATISFIED (0.0 <=
0.0), mem SATISFIED (128.0 <= 1964.0)
(mesosphere.mesos.ResourceMatcher$:121)
Sep 29 09:35:38 lab-mesos-master1 marathon[60609]: [2015-09-29
09:35:38,561] INFO Offer [20150928-140031-2581335306-5050-60442-O436527].
Not all basic resources satisfied: cpu not in offer, disk SATISFIED (0.0 <=
0.0), mem SATISFIED (320.0 <= 1964.0)
(mesosphere.mesos.ResourceMatcher$:121)
Sep 29 09:35:38 lab-mesos-master1 marathon[60609]: [2015-09-29
09:35:38,563] INFO Offer [20150928-140031-2581335306-5050-60442-O436527].
Not all basic resources satisfied: cpu not in offer, disk SATISFIED (0.0 <=
0.0), mem SATISFIED (128.0 <= 1964.0)
(mesosphere.mesos.ResourceMatcher$:121)
Sep 29 09:35:38 lab-mesos-master1 marathon[60609]: [2015-09-29
09:35:38,565] INFO Offer [20150928-140031-2581335306-5050-60442-O436528].
Not all basic resources satisfied: cpu SATISFIED (0.25 <=
1.3500000000000014), disk SATISFIED (0.0 <= 0.0), mem NOT SATISFIED (128.0
> 34.0) (mesosphere.mesos.ResourceMatcher$:121)
Sep 29 09:35:38 lab-mesos-master1 marathon[60609]: [2015-09-29
09:35:38,565] INFO Offer [20150928-140031-2581335306-5050-60442-O436528].
Not all basic resources satisfied: cpu SATISFIED (0.25 <=
1.3500000000000014), disk SATISFIED (0.0 <= 0.0), mem NOT SATISFIED (128.0
> 34.0) (mesosphere.mesos.ResourceMatcher$:121)
Sep 29 09:35:38 lab-mesos-master1 marathon[60609]: [2015-09-29
09:35:38,566] INFO Offer [20150928-140031-2581335306-5050-60442-O436528].
Not all basic resources satisfied: cpu SATISFIED (0.25 <=
1.3500000000000014), disk SATISFIED (0.0 <= 0.0), mem NOT SATISFIED (320.0
> 34.0) (mesosphere.mesos.ResourceMatcher$:121)
Sep 29 09:35:38 lab-mesos-master1 marathon[60609]: [2015-09-29
09:35:38,567] INFO Offer [20150928-140031-2581335306-5050-60442-O436528].
Not all basic resources satisfied: cpu SATISFIED (0.25 <=
1.3500000000000014), disk SATISFIED (0.0 <= 0.0), mem NOT SATISFIED (128.0
> 34.0) (mesosphere.mesos.ResourceMatcher$:121)
Sep 29 09:35:38 lab-mesos-master1 marathon[60609]: [2015-09-29
09:35:38,568] INFO Offer [20150928-140031-2581335306-5050-60442-O436529].
Not all basic resources satisfied: cpu not in offer, disk SATISFIED (0.0 <=
0.0), mem SATISFIED (128.0 <= 1688.0)
(mesosphere.mesos.ResourceMatcher$:121)
Sep 29 09:35:38 lab-mesos-master1 marathon[60609]: [2015-09-29
09:35:38,575] INFO Offer [20150928-140031-2581335306-5050-60442-O436529].
Not all basic resources satisfied: cpu not in offer, disk SATISFIED (0.0 <=
0.0), mem SATISFIED (128.0 <= 1688.0)
(mesosphere.mesos.ResourceMatcher$:121)
Sep 29 09:35:38 lab-mesos-master1 marathon[60609]: [2015-09-29
09:35:38,583] INFO Offer [20150928-140031-2581335306-5050-60442-O436529].
Not all basic resources satisfied: cpu not in offer, disk SATISFIED (0.0 <=
0.0), mem SATISFIED (320.0 <= 1688.0)
(mesosphere.mesos.ResourceMatcher$:121)
Sep 29 09:35:38 lab-mesos-master1 marathon[60609]: [2015-09-29
09:35:38,584] INFO Offer [20150928-140031-2581335306-5050-60442-O436529].
Not all basic resources satisfied: cpu not in offer, disk SATISFIED (0.0 <=
0.0), mem SATISFIED (128.0 <= 1688.0)
(mesosphere.mesos.ResourceMatcher$:121)
Sep 29 09:35:38 lab-mesos-master1 marathon[60609]: [2015-09-29
09:35:38,591] INFO Offer [20150928-140031-2581335306-5050-60442-O436530].
Not all basic resources satisfied: cpu SATISFIED (0.25 <=
1.1500000000000004), disk SATISFIED (0.0 <= 0.0), mem NOT SATISFIED (128.0
> 62.0) (mesosphere.mesos.ResourceMatcher$:121)
Sep 29 09:35:38 lab-mesos-master1 marathon[60609]: [2015-09-29
09:35:38,592] INFO Offer [20150928-140031-2581335306-5050-60442-O436530].
Not all basic resources satisfied: cpu SATISFIED (0.25 <=
1.1500000000000004), disk SATISFIED (0.0 <= 0.0), mem NOT SATISFIED (128.0
> 62.0) (mesosphere.mesos.ResourceMatcher$:121)
Sep 29 09:35:38 lab-mesos-master1 marathon[60609]: [2015-09-29
09:35:38,598] INFO Offer [20150928-140031-2581335306-5050-60442-O436530].
Not all basic resources satisfied: cpu SATISFIED (0.25 <=
1.1500000000000004), disk SATISFIED (0.0 <= 0.0), mem NOT SATISFIED (320.0
> 62.0) (mesosphere.mesos.ResourceMatcher$:121)
Sep 29 09:35:38 lab-mesos-master1 marathon[60609]: [2015-09-29
09:35:38,603] INFO Offer [20150928-140031-2581335306-5050-60442-O436530].
Not all basic resources satisfied: cpu SATISFIED (0.25 <=
1.1500000000000004), disk SATISFIED (0.0 <= 0.0), mem NOT SATISFIED (128.0
> 62.0) (mesosphere.mesos.ResourceMatcher$:121)
Sep 29 09:35:38 lab-mesos-master1 marathon[60609]: [2015-09-29
09:35:38,610] INFO Offer [20150928-140031-2581335306-5050-60442-O436531].
Not all basic resources satisfied: cpu SATISFIED (0.25 <=
0.5999999999999996), disk SATISFIED (0.0 <= 0.0), mem NOT SATISFIED (128.0
> 20.0) (mesosphere.mesos.ResourceMatcher$:121)
Sep 29 09:35:38 lab-mesos-master1 marathon[60609]: [2015-09-29
09:35:38,616] INFO Offer [20150928-140031-2581335306-5050-60442-O436531].
Not all basic resources satisfied: cpu SATISFIED (0.25 <=
0.5999999999999996), disk SATISFIED (0.0 <= 0.0), mem NOT SATISFIED (128.0
> 20.0) (mesosphere.mesos.ResourceMatcher$:121)
Sep 29 09:35:38 lab-mesos-master1 marathon[60609]: [2015-09-29
09:35:38,622] INFO Offer [20150928-140031-2581335306-5050-60442-O436531].
Not all basic resources satisfied: cpu SATISFIED (0.25 <=
0.5999999999999996), disk SATISFIED (0.0 <= 0.0), mem NOT SATISFIED (320.0
> 20.0) (mesosphere.mesos.ResourceMatcher$:121)
Sep 29 09:35:38 lab-mesos-master1 marathon[60609]: [2015-09-29
09:35:38,623] INFO Offer [20150928-140031-2581335306-5050-60442-O436531].
Not all basic resources satisfied: cpu SATISFIED (0.25 <=
0.5999999999999996), disk SATISFIED (0.0 <= 0.0), mem NOT SATISFIED (128.0
> 20.0) (mesosphere.mesos.ResourceMatcher$:121)
Sep 29 09:35:38 lab-mesos-master1 marathon[60609]: [2015-09-29
09:35:38,631] INFO Offer [20150928-140031-2581335306-5050-60442-O436532].
Not all basic resources satisfied: cpu SATISFIED (0.25 <=
0.6500000000000004), disk SATISFIED (0.0 <= 0.0), mem NOT SATISFIED (128.0
> 6.0) (mesosphere.mesos.ResourceMatcher$:121)
Sep 29 09:35:38 lab-mesos-master1 marathon[60609]: [2015-09-29
09:35:38,639] INFO Offer [20150928-140031-2581335306-5050-60442-O436532].
Not all basic resources satisfied: cpu SATISFIED (0.25 <=
0.6500000000000004), disk SATISFIED (0.0 <= 0.0), mem NOT SATISFIED (128.0
> 6.0) (mesosphere.mesos.ResourceMatcher$:121)
Sep 29 09:35:38 lab-mesos-master1 marathon[60609]: [2015-09-29
09:35:38,655] INFO Offer [20150928-140031-2581335306-5050-60442-O436532].
Not all basic resources satisfied: cpu SATISFIED (0.25 <=
0.6500000000000004), disk SATISFIED (0.0 <= 0.0), mem NOT SATISFIED (320.0
> 6.0) (mesosphere.mesos.ResourceMatcher$:121)
Sep 29 09:35:38 lab-mesos-master1 marathon[60609]: [2015-09-29
09:35:38,670] INFO Offer [20150928-140031-2581335306-5050-60442-O436532].
Not all basic resources satisfied: cpu SATISFIED (0.25 <=
0.6500000000000004), disk SATISFIED (0.0 <= 0.0), mem NOT SATISFIED (128.0
> 6.0) (mesosphere.mesos.ResourceMatcher$:121)
Sep 29 09:35:38 lab-mesos-master1 marathon[60609]: [2015-09-29
09:35:38,671] INFO Offer [20150928-140031-2581335306-5050-60442-O436533].
Not all basic resources satisfied: cpu SATISFIED (0.25 <=
1.4499999999999993), disk SATISFIED (0.0 <= 0.0), mem NOT SATISFIED (128.0
> 70.0) (mesosphere.mesos.ResourceMatcher$:121)
Sep 29 09:35:38 lab-mesos-master1 marathon[60609]: [2015-09-29
09:35:38,676] INFO Offer [20150928-140031-2581335306-5050-60442-O436533].
Not all basic resources satisfied: cpu SATISFIED (0.25 <=
1.4499999999999993), disk SATISFIED (0.0 <= 0.0), mem NOT SATISFIED (128.0
> 70.0) (mesosphere.mesos.ResourceMatcher$:121)
Sep 29 09:35:38 lab-mesos-master1 marathon[60609]: [2015-09-29
09:35:38,682] INFO Offer [20150928-140031-2581335306-5050-60442-O436533].
Not all basic resources satisfied: cpu SATISFIED (0.25 <=
1.4499999999999993), disk SATISFIED (0.0 <= 0.0), mem NOT SATISFIED (320.0
> 70.0) (mesosphere.mesos.ResourceMatcher$:121)
Sep 29 09:35:38 lab-mesos-master1 marathon[60609]: [2015-09-29
09:35:38,683] INFO Offer [20150928-140031-2581335306-5050-60442-O436533].
Not all basic resources satisfied: cpu SATISFIED (0.25 <=
1.4499999999999993), disk SATISFIED (0.0 <= 0.0), mem NOT SATISFIED (128.0
> 70.0) (mesosphere.mesos.ResourceMatcher$:121)
Sep 29 09:35:38 lab-mesos-master1 marathon[60609]: [2015-09-29
09:35:38,690] INFO Offer [20150928-140031-2581335306-5050-60442-O436534].
Not all basic resources satisfied: cpu SATISFIED (0.25 <= 0.5), disk
SATISFIED (0.0 <= 0.0), mem NOT SATISFIED (128.0 > 34.0)
(mesosphere.mesos.ResourceMatcher$:121)
Sep 29 09:35:38 lab-mesos-master1 marathon[60609]: [2015-09-29
09:35:38,698] INFO Offer [20150928-140031-2581335306-5050-60442-O436534].
Not all basic resources satisfied: cpu SATISFIED (0.25 <= 0.5), disk
SATISFIED (0.0 <= 0.0), mem NOT SATISFIED (128.0 > 34.0)
(mesosphere.mesos.ResourceMatcher$:121)
Sep 29 09:35:38 lab-mesos-master1 marathon[60609]: [2015-09-29
09:35:38,698] INFO Offer [20150928-140031-2581335306-5050-60442-O436534].
Not all basic resources satisfied: cpu SATISFIED (0.25 <= 0.5), disk
SATISFIED (0.0 <= 0.0), mem NOT SATISFIED (320.0 > 34.0)
(mesosphere.mesos.ResourceMatcher$:121)
Sep 29 09:35:38 lab-mesos-master1 marathon[60609]: [2015-09-29
09:35:38,704] INFO Offer [20150928-140031-2581335306-5050-60442-O436534].
Not all basic resources satisfied: cpu SATISFIED (0.25 <= 0.5), disk
SATISFIED (0.0 <= 0.0), mem NOT SATISFIED (128.0 > 34.0)
(mesosphere.mesos.ResourceMatcher$:121)
Sep 29 09:35:38 lab-mesos-master1 marathon[60609]: [2015-09-29
09:35:38,710] INFO Offer [20150928-140031-2581335306-5050-60442-O436535].
Not all basic resources satisfied: cpu SATISFIED (0.25 <=
1.5999999999999996), disk SATISFIED (0.0 <= 0.0), mem NOT SATISFIED (128.0
> 34.0) (mesosphere.mesos.ResourceMatcher$:121)
Sep 29 09:35:38 lab-mesos-master1 marathon[60609]: [2015-09-29
09:35:38,765] INFO Offer [20150928-140031-2581335306-5050-60442-O436535].
Not all basic resources satisfied: cpu SATISFIED (0.25 <=
1.5999999999999996), disk SATISFIED (0.0 <= 0.0), mem NOT SATISFIED (128.0
> 34.0) (mesosphere.mesos.ResourceMatcher$:121)
Sep 29 09:35:38 lab-mesos-master1 marathon[60609]: [2015-09-29
09:35:38,766] INFO Offer [20150928-140031-2581335306-5050-60442-O436535].
Not all basic resources satisfied: cpu SATISFIED (0.25 <=
1.5999999999999996), disk SATISFIED (0.0 <= 0.0), mem NOT SATISFIED (320.0
> 34.0) (mesosphere.mesos.ResourceMatcher$:121)
Sep 29 09:35:38 lab-mesos-master1 marathon[60609]: [2015-09-29
09:35:38,766] INFO Offer [20150928-140031-2581335306-5050-60442-O436535].
Not all basic resources satisfied: cpu SATISFIED (0.25 <=
1.5999999999999996), disk SATISFIED (0.0 <= 0.0), mem NOT SATISFIED (128.0
> 34.0) (mesosphere.mesos.ResourceMatcher$:121)
Sep 29 09:35:38 lab-mesos-master1 marathon[60609]: [2015-09-29
09:35:38,773] INFO Offer [20150928-140031-2581335306-5050-60442-O436536].
Not all basic resources satisfied: cpu not in offer, disk SATISFIED (0.0 <=
0.0), mem SATISFIED (128.0 <= 1154.0)
(mesosphere.mesos.ResourceMatcher$:121)
Sep 29 09:35:38 lab-mesos-master1 marathon[60609]: [2015-09-29
09:35:38,773] INFO Offer [20150928-140031-2581335306-5050-60442-O436536].
Not all basic resources satisfied: cpu not in offer, disk SATISFIED (0.0 <=
0.0), mem SATISFIED (128.0 <= 1154.0)
(mesosphere.mesos.ResourceMatcher$:121)
Sep 29 09:35:38 lab-mesos-master1 marathon[60609]: [2015-09-29
09:35:38,774] INFO Offer [20150928-140031-2581335306-5050-60442-O436536].
Not all basic resources satisfied: cpu not in offer, disk SATISFIED (0.0 <=
0.0), mem SATISFIED (320.0 <= 1154.0)
(mesosphere.mesos.ResourceMatcher$:121)
Sep 29 09:35:38 lab-mesos-master1 marathon[60609]: [2015-09-29
09:35:38,774] INFO Offer [20150928-140031-2581335306-5050-60442-O436536].
Not all basic resources satisfied: cpu not in offer, disk SATISFIED (0.0 <=
0.0), mem SATISFIED (128.0 <= 1154.0)
(mesosphere.mesos.ResourceMatcher$:121)

Cheers


On 29 September 2015 at 21:01, Vinod Kone <vi...@gmail.com> wrote:

> Can you provide more details about your setup and master logs when this
> started to happen? Typically, when a framework declines an offer it sets a
> timeout filter which gives mesos a chance to aggregate free resources on a
> slave into one big offer.
>
> On Tue, Sep 29, 2015 at 6:31 AM, Eren Güven <er...@gmail.com> wrote:
>
>> Hello,
>>
>> I had an incident where mesos kept offering marathon insufficient
>> resources which resulted in lots of forever WAITING tasks in marathon.
>> Below are some example logs I saw. It kept repeating the same insufficient
>> offers even though the cluster had a lot of free resources like ~80cpus and
>> 45G mem. A master restart solved the issue but I was wondering what can
>> result in this situation or if anyone had any pointers on where to dig
>> further.
>>
>> Thanks!
>>
>> cpu SATISFIED (0.25 <= 1.3500000000000014), disk SATISFIED (0.0 <= 0.0),
>> mem NOT SATISFIED (128.0 > 34.0)
>> cpu SATISFIED (0.25 <= 1.3500000000000014), disk SATISFIED (0.0 <= 0.0),
>> mem NOT SATISFIED (160.0 > 34.0)
>> cpu SATISFIED (0.25 <= 1.3500000000000014), disk SATISFIED (0.0 <= 0.0),
>> mem NOT SATISFIED (128.0 > 34.0)
>> cpu SATISFIED (0.25 <= 1.3500000000000014), disk SATISFIED (0.0 <= 0.0),
>> mem NOT SATISFIED (128.0 > 34.0)
>> cpu SATISFIED (0.25 <= 1.3500000000000014), disk SATISFIED (0.0 <= 0.0),
>> mem NOT SATISFIED (128.0 > 34.0)
>> cpu SATISFIED (0.25 <= 1.3500000000000014), disk SATISFIED (0.0 <= 0.0),
>> mem NOT SATISFIED (128.0 > 34.0)
>> cpu SATISFIED (0.25 <= 1.3500000000000014), disk SATISFIED (0.0 <= 0.0),
>> mem NOT SATISFIED (128.0 > 34.0)
>> cpu SATISFIED (0.25 <= 1.3500000000000014), disk SATISFIED (0.0 <= 0.0),
>> mem NOT SATISFIED (128.0 > 34.0)
>> cpu SATISFIED (0.25 <= 1.3500000000000014), disk SATISFIED (0.0 <= 0.0),
>> mem NOT SATISFIED (128.0 > 34.0)
>> cpu SATISFIED (0.25 <= 1.3500000000000014), disk SATISFIED (0.0 <= 0.0),
>> mem NOT SATISFIED (128.0 > 34.0)
>> cpu SATISFIED (0.25 <= 1.1500000000000004), disk SATISFIED (0.0 <= 0.0),
>> mem NOT SATISFIED (128.0 > 62.0)
>> cpu SATISFIED (0.25 <= 1.1500000000000004), disk SATISFIED (0.0 <= 0.0),
>> mem NOT SATISFIED (160.0 > 62.0)
>> cpu SATISFIED (0.25 <= 1.1500000000000004), disk SATISFIED (0.0 <= 0.0),
>> mem NOT SATISFIED (128.0 > 62.0)
>> cpu SATISFIED (0.25 <= 1.1500000000000004), disk SATISFIED (0.0 <= 0.0),
>> mem NOT SATISFIED (128.0 > 62.0)
>> cpu SATISFIED (0.25 <= 1.1500000000000004), disk SATISFIED (0.0 <= 0.0),
>> mem NOT SATISFIED (128.0 > 62.0)
>> cpu SATISFIED (0.25 <= 1.1500000000000004), disk SATISFIED (0.0 <= 0.0),
>> mem NOT SATISFIED (128.0 > 62.0)
>> cpu SATISFIED (0.25 <= 1.1500000000000004), disk SATISFIED (0.0 <= 0.0),
>> mem NOT SATISFIED (128.0 > 62.0)
>> cpu SATISFIED (0.25 <= 1.1500000000000004), disk SATISFIED (0.0 <= 0.0),
>> mem NOT SATISFIED (128.0 > 62.0)
>> cpu SATISFIED (0.25 <= 1.1500000000000004), disk SATISFIED (0.0 <= 0.0),
>> mem NOT SATISFIED (128.0 > 62.0)
>> cpu SATISFIED (0.25 <= 1.1500000000000004), disk SATISFIED (0.0 <= 0.0),
>> mem NOT SATISFIED (128.0 > 62.0)
>> cpu SATISFIED (0.25 <= 0.7999999999999998), disk SATISFIED (0.0 <= 0.0),
>> mem NOT SATISFIED (128.0 > 6.0)
>> cpu SATISFIED (0.25 <= 0.7999999999999998), disk SATISFIED (0.0 <= 0.0),
>> mem NOT SATISFIED (160.0 > 6.0)
>> cpu SATISFIED (0.25 <= 0.7999999999999998), disk SATISFIED (0.0 <= 0.0),
>> mem NOT SATISFIED (128.0 > 6.0)
>> cpu SATISFIED (0.25 <= 0.7999999999999998), disk SATISFIED (0.0 <= 0.0),
>> mem NOT SATISFIED (128.0 > 6.0)
>> cpu SATISFIED (0.25 <= 0.7999999999999998), disk SATISFIED (0.0 <= 0.0),
>> mem NOT SATISFIED (128.0 > 6.0)
>> cpu SATISFIED (0.25 <= 0.7999999999999998), disk SATISFIED (0.0 <= 0.0),
>> mem NOT SATISFIED (128.0 > 6.0)
>> cpu SATISFIED (0.25 <= 0.7999999999999998), disk SATISFIED (0.0 <= 0.0),
>> mem NOT SATISFIED (128.0 > 6.0)
>> cpu SATISFIED (0.25 <= 0.7999999999999998), disk SATISFIED (0.0 <= 0.0),
>> mem NOT SATISFIED (128.0 > 6.0)
>> cpu SATISFIED (0.25 <= 0.7999999999999998), disk SATISFIED (0.0 <= 0.0),
>> mem NOT SATISFIED (128.0 > 6.0)
>> cpu SATISFIED (0.25 <= 0.7999999999999998), disk SATISFIED (0.0 <= 0.0),
>> mem NOT SATISFIED (128.0 > 6.0)
>> cpu SATISFIED (0.25 <= 0.6500000000000004), disk SATISFIED (0.0 <= 0.0),
>> mem NOT SATISFIED (128.0 > 6.0)
>> cpu SATISFIED (0.25 <= 0.6500000000000004), disk SATISFIED (0.0 <= 0.0),
>> mem NOT SATISFIED (160.0 > 6.0)
>> cpu SATISFIED (0.25 <= 0.6500000000000004), disk SATISFIED (0.0 <= 0.0),
>> mem NOT SATISFIED (128.0 > 6.0)
>> cpu SATISFIED (0.25 <= 0.6500000000000004), disk SATISFIED (0.0 <= 0.0),
>> mem NOT SATISFIED (128.0 > 6.0)
>> cpu SATISFIED (0.25 <= 0.6500000000000004), disk SATISFIED (0.0 <= 0.0),
>> mem NOT SATISFIED (128.0 > 6.0)
>> cpu SATISFIED (0.25 <= 0.6500000000000004), disk SATISFIED (0.0 <= 0.0),
>> mem NOT SATISFIED (128.0 > 6.0)
>> cpu SATISFIED (0.25 <= 0.6500000000000004), disk SATISFIED (0.0 <= 0.0),
>> mem NOT SATISFIED (128.0 > 6.0)
>> cpu SATISFIED (0.25 <= 0.6500000000000004), disk SATISFIED (0.0 <= 0.0),
>> mem NOT SATISFIED (128.0 > 6.0)
>> cpu SATISFIED (0.25 <= 0.6500000000000004), disk SATISFIED (0.0 <= 0.0),
>> mem NOT SATISFIED (128.0 > 6.0)
>> cpu SATISFIED (0.25 <= 0.6500000000000004), disk SATISFIED (0.0 <= 0.0),
>> mem NOT SATISFIED (128.0 > 6.0)
>> cpu SATISFIED (0.25 <= 1.25), disk SATISFIED (0.0 <= 0.0), mem NOT
>> SATISFIED (128.0 > 42.0)
>> cpu SATISFIED (0.25 <= 1.25), disk SATISFIED (0.0 <= 0.0), mem NOT
>> SATISFIED (160.0 > 42.0)
>> cpu SATISFIED (0.25 <= 1.25), disk SATISFIED (0.0 <= 0.0), mem NOT
>> SATISFIED (128.0 > 42.0)
>> cpu SATISFIED (0.25 <= 1.25), disk SATISFIED (0.0 <= 0.0), mem NOT
>> SATISFIED (128.0 > 42.0)
>> cpu SATISFIED (0.25 <= 1.25), disk SATISFIED (0.0 <= 0.0), mem NOT
>> SATISFIED (128.0 > 42.0)
>> cpu SATISFIED (0.25 <= 1.25), disk SATISFIED (0.0 <= 0.0), mem NOT
>> SATISFIED (128.0 > 42.0)
>> cpu SATISFIED (0.25 <= 1.25), disk SATISFIED (0.0 <= 0.0), mem NOT
>> SATISFIED (128.0 > 42.0)
>> cpu SATISFIED (0.25 <= 1.25), disk SATISFIED (0.0 <= 0.0), mem NOT
>> SATISFIED (128.0 > 42.0)
>> cpu SATISFIED (0.25 <= 1.25), disk SATISFIED (0.0 <= 0.0), mem NOT
>> SATISFIED (128.0 > 42.0)
>> cpu SATISFIED (0.25 <= 1.25), disk SATISFIED (0.0 <= 0.0), mem NOT
>> SATISFIED (128.0 > 42.0)
>> cpu SATISFIED (0.25 <= 1.549999999999999), disk SATISFIED (0.0 <= 0.0),
>> mem NOT SATISFIED (128.0 > 120.0)
>> cpu SATISFIED (0.25 <= 1.549999999999999), disk SATISFIED (0.0 <= 0.0),
>> mem NOT SATISFIED (160.0 > 120.0)
>> cpu SATISFIED (0.25 <= 1.549999999999999), disk SATISFIED (0.0 <= 0.0),
>> mem NOT SATISFIED (128.0 > 120.0)
>> cpu SATISFIED (0.25 <= 1.549999999999999), disk SATISFIED (0.0 <= 0.0),
>> mem NOT SATISFIED (128.0 > 120.0)
>> cpu SATISFIED (0.25 <= 1.549999999999999), disk SATISFIED (0.0 <= 0.0),
>> mem NOT SATISFIED (128.0 > 120.0)
>> cpu SATISFIED (0.25 <= 1.549999999999999), disk SATISFIED (0.0 <= 0.0),
>> mem NOT SATISFIED (128.0 > 120.0)
>> cpu SATISFIED (0.25 <= 1.549999999999999), disk SATISFIED (0.0 <= 0.0),
>> mem NOT SATISFIED (128.0 > 120.0)
>> cpu SATISFIED (0.25 <= 1.549999999999999), disk SATISFIED (0.0 <= 0.0),
>> mem NOT SATISFIED (128.0 > 120.0)
>> cpu SATISFIED (0.25 <= 1.549999999999999), disk SATISFIED (0.0 <= 0.0),
>> mem NOT SATISFIED (128.0 > 120.0)
>> cpu SATISFIED (0.25 <= 1.549999999999999), disk SATISFIED (0.0 <= 0.0),
>> mem NOT SATISFIED (128.0 > 120.0)
>> cpu SATISFIED (0.25 <= 1.5999999999999996), disk SATISFIED (0.0 <= 0.0),
>> mem NOT SATISFIED (128.0 > 34.0)
>> cpu SATISFIED (0.25 <= 1.5999999999999996), disk SATISFIED (0.0 <= 0.0),
>> mem NOT SATISFIED (160.0 > 34.0)
>> cpu SATISFIED (0.25 <= 1.5999999999999996), disk SATISFIED (0.0 <= 0.0),
>> mem NOT SATISFIED (128.0 > 34.0)
>> cpu SATISFIED (0.25 <= 1.5999999999999996), disk SATISFIED (0.0 <= 0.0),
>> mem NOT SATISFIED (128.0 > 34.0)
>> cpu SATISFIED (0.25 <= 1.5999999999999996), disk SATISFIED (0.0 <= 0.0),
>> mem NOT SATISFIED (128.0 > 34.0)
>> cpu SATISFIED (0.25 <= 1.5999999999999996), disk SATISFIED (0.0 <= 0.0),
>> mem NOT SATISFIED (128.0 > 34.0)
>> cpu SATISFIED (0.25 <= 1.5999999999999996), disk SATISFIED (0.0 <= 0.0),
>> mem NOT SATISFIED (128.0 > 34.0)
>>
>> Cheers
>> Eren
>>
>
>