Marathon: Master refused authentication - Marathon

[akamalov]

Greetings,

Current setup:

Marathon 0.14
Mesos 0.26.0

On Mesos-Master:

/etc/mesos/master/authenticate is set to true
/etc/mesos/master/authenticators is set crammd5

In /etc/sysconfig/mesos-credentials/credentials file I have the following:

marathon 4feaa0f614b821ec4849

In credentials file for Marathon I have the following:

marathon 4feaa0f614b821ec4849

On Marathon, I have environmental variables as follows:

MESOSPHERE_KEYSTORE_PASS="XXXXXX"
MESOSPHERE_KEYSTORE_PATH="/etc/marathon/ssl/marathon.jks"
MARATHON_MESOS_AUTHENTICATION_PRINCIPAL="marathon"
MARATHON_MESOS_AUTHENTICATION_SECRET_FILE="/etc/marathon/marathon.secret"

Trying to bring up marathon, and getting Master refused authentication message.

Short Output:

Feb 24 14:45:26 node236 marathon[27018]: I0224 14:45:26.322141 27115 authenticatee.cpp:99] Initializing client SASL
Feb 24 14:45:26 node236 marathon[27018]: I0224 14:45:26.325283 27115 authenticatee.cpp:123] Creating new client SASL connection
Feb 24 14:45:26 node236 marathon[27018]: I0224 14:45:26.332222 27110 authenticatee.cpp:214] Received SASL authentication mechanisms: CRAM-MD5
Feb 24 14:45:26 node236 marathon[27018]: I0224 14:45:26.332547 27110 authenticatee.cpp:240] Attempting to authenticate with mechanism 'CRAM-MD5'
Feb 24 14:45:26 node236 marathon[27018]: I0224 14:45:26.339634 27116 authenticatee.cpp:260] Received SASL authentication step
Feb 24 14:45:26 node236 marathon[27018]: E0224 14:45:26.347100 27116 sched.cpp:403] Master [email protected]:5050 refused authentication
Feb 24 14:45:26 node236 marathon[27018]: I0224 14:45:26.347175 27116 sched.cpp:1027] Got error 'Master refused authentication'
Feb 24 14:45:26 node236 marathon[27018]: I0224 14:45:26.347194 27116 sched.cpp:1839] Asked to abort the driver
Feb 24 14:45:26 node236 marathon[27018]: [2016-02-24 14:45:26,359] WARN Error: Master refused authentication
Feb 24 14:45:26 node236 marathon[27018]: In case Mesos does not allow registration with the current frameworkId, delete the ZooKeeper Node: /marathon/state/framework:id
Feb 24 14:45:26 node236 marathon[27018]: CAUTION: if you remove this node, all tasks started with the current frameworkId will be orphaned! (mesosphere.marathon.MarathonScheduler$$EnhancerByGuice$$55d6d0f2:Thread-20)

Mesos-Master Status

[root@node236 mesos]# systemctl -l status mesos-master
● mesos-master.service - Mesos Master
   Loaded: loaded (/usr/lib/systemd/system/mesos-master.service; enabled; vendor preset: disabled)
   Active: active (running) since Wed 2016-02-24 14:13:27 EST; 36min ago
 Main PID: 19202 (mesos-master)
   CGroup: /system.slice/mesos-master.service
           ├─19202 /usr/sbin/mesos-master --zk=zk://192.168.1.236:2181,192.168.1.237:2181,192.168.1.238:2181,192.168.1.239:2181,192.168.1.94:2181/mesos --port=5050 --log_dir=/var/log/mesos --acls={  "run_tasks": [{   "principals": {    "type": "ANY"   },   "users": {    "type": "ANY"   }  }],  "register_frameworks": [{   "principals": {    "type": "ANY"   },   "roles": {    "type": "ANY"   }  }] } --authenticate=true --authenticate_slaves=true --authenticators=crammd5 --cluster=Cluster1 --credentials=/etc/sysconfig/mesos-credentials/credentials  --hostname=node236.localnet.net --quorum=3 --work_dir=/var/lib/mesos
           ├─19226 logger -p user.info -t mesos-master[19202]
           └─19227 logger -p user.err -t mesos-master[19202]

Long Output:

Feb 24 14:45:16 node236 marathon: run_jar --mesos_authentication_principal marathon --mesos_authentication_secret_file /etc/marathon/marathon.secret --zk zk://192.168.1.236:2181,192.168.1.237:2181,192.168.1.238:2181,192.168.1.239:2181,192.168.1.94:2181/marathon --master zk://192.168.1.236:2181,192.168.1.237:2181,192.168.1.238:2181,192.168.1.239:2181,192.168.1.94:2181/mesos
Feb 24 14:45:17 node236 marathon[27018]: [2016-02-24 14:45:17,568] INFO Starting Marathon 0.14.0 with --mesos_authentication_principal marathon --mesos_authentication_secret_file /etc/marathon/marathon.secret --zk zk://192.168.1.236:2181,192.168.1.237:2181,192.168.1.238:2181,192.168.1.239:2181,192.168.1.94:2181/marathon --master zk://192.168.1.236:2181,192.168.1.237:2181,192.168.1.238:2181,192.168.1.239:2181,192.168.1.94:2181/mesos (mesosphere.marathon.Main$:main)
Feb 24 14:45:20 node236 marathon[27018]: [2016-02-24 14:45:20,567] INFO Connecting to ZooKeeper... (mesosphere.marathon.Main$:main)
Feb 24 14:45:20 node236 marathon[27018]: [2016-02-24 14:45:20,576] INFO Client environment:zookeeper.version=3.4.6-1569965, built on 02/20/2014 09:09 GMT (org.apache.zookeeper.ZooKeeper:main)
Feb 24 14:45:20 node236 marathon[27018]: [2016-02-24 14:45:20,576] INFO Client environment:host.name=node236.localnet.net (org.apache.zookeeper.ZooKeeper:main)
Feb 24 14:45:20 node236 marathon[27018]: [2016-02-24 14:45:20,576] INFO Client environment:java.version=1.8.0 (org.apache.zookeeper.ZooKeeper:main)
Feb 24 14:45:20 node236 marathon[27018]: [2016-02-24 14:45:20,576] INFO Client environment:java.vendor=IBM Corporation (org.apache.zookeeper.ZooKeeper:main)
Feb 24 14:45:20 node236 marathon[27018]: [2016-02-24 14:45:20,576] INFO Client environment:java.home=/usr/lib/jvm/java-1.8.0-ibm-1.8.0.2.0-1jpp.1.el7.x86_64/jre (org.apache.zookeeper.ZooKeeper:main)
Feb 24 14:45:20 node236 marathon[27018]: [2016-02-24 14:45:20,576] INFO Client environment:java.class.path=/usr/bin/marathon (org.apache.zookeeper.ZooKeeper:main)
Feb 24 14:45:20 node236 marathon[27018]: [2016-02-24 14:45:20,576] INFO Client environment:java.library.path=/usr/local/lib:/usr/lib:/usr/lib64 (org.apache.zookeeper.ZooKeeper:main)
Feb 24 14:45:20 node236 marathon[27018]: [2016-02-24 14:45:20,576] INFO Client environment:java.io.tmpdir=/tmp (org.apache.zookeeper.ZooKeeper:main)
Feb 24 14:45:20 node236 marathon[27018]: [2016-02-24 14:45:20,576] INFO Client environment:java.compiler=j9jit28 (org.apache.zookeeper.ZooKeeper:main)
Feb 24 14:45:20 node236 marathon[27018]: [2016-02-24 14:45:20,576] INFO Client environment:os.name=Linux (org.apache.zookeeper.ZooKeeper:main)
Feb 24 14:45:20 node236 marathon[27018]: [2016-02-24 14:45:20,576] INFO Client environment:os.arch=amd64 (org.apache.zookeeper.ZooKeeper:main)
Feb 24 14:45:20 node236 marathon[27018]: [2016-02-24 14:45:20,576] INFO Client environment:os.version=3.10.0-327.4.4.el7.x86_64 (org.apache.zookeeper.ZooKeeper:main)
Feb 24 14:45:20 node236 marathon[27018]: [2016-02-24 14:45:20,576] INFO Client environment:user.name=root (org.apache.zookeeper.ZooKeeper:main)
Feb 24 14:45:20 node236 marathon[27018]: [2016-02-24 14:45:20,576] INFO Client environment:user.home=/root (org.apache.zookeeper.ZooKeeper:main)
Feb 24 14:45:20 node236 marathon[27018]: [2016-02-24 14:45:20,577] INFO Client environment:user.dir=/ (org.apache.zookeeper.ZooKeeper:main)
Feb 24 14:45:20 node236 marathon[27018]: [2016-02-24 14:45:20,578] INFO Initiating client connection, connectString=node236.localnet.net:2181,node237.localnet.net:2181,node238.localnet.net:2181,node239.localnet.net:2181,node260.localnet.net:2181 sessionTimeout=10000 watcher=com.twitter.common.zookeeper.ZooKeeperClient$3@e1bce1ec (org.apache.zookeeper.ZooKeeper:main)
Feb 24 14:45:20 node236 marathon[27018]: [2016-02-24 14:45:20,604] INFO Opening socket connection to server node237.localnet.net/192.168.1.237:2181. Will not attempt to authenticate using SASL (unknown error) (org.apache.zookeeper.ClientCnxn:main-SendThread(node237.localnet.net:2181))
Feb 24 14:45:20 node236 marathon[27018]: [2016-02-24 14:45:20,648] INFO Socket connection established to node237.localnet.net/192.168.1.237:2181, initiating session (org.apache.zookeeper.ClientCnxn:main-SendThread(node237.localnet.net:2181))
Feb 24 14:45:20 node236 marathon[27018]: [2016-02-24 14:45:20,667] INFO Session establishment complete on server node237.localnet.net/192.168.1.237:2181, sessionid = 0x25269a106c603c5, negotiated timeout = 10000 (org.apache.zookeeper.ClientCnxn:main-SendThread(node237.localnet.net:2181))
Feb 24 14:45:21 node236 marathon[27018]: [2016-02-24 14:45:21,474] WARN Method [public javax.ws.rs.core.Response mesosphere.marathon.api.MarathonExceptionMapper.toResponse(java.lang.Throwable)] is synthetic and is being intercepted by [mesosphere.marathon.DebugModule$MetricsBehavior@1df61a57]. This could indicate a bug.  The method may be intercepted twice, or may not be intercepted at all. (com.google.inject.internal.ProxyFactory:main)
Feb 24 14:45:22 node236 marathon[27018]: [2016-02-24 14:45:22,072] INFO Logging initialized @5653ms (org.eclipse.jetty.util.log:main)
Feb 24 14:45:23 node236 marathon[27018]: [2016-02-24 14:45:23,156] INFO Slf4jLogger started (akka.event.slf4j.Slf4jLogger:marathon-akka.actor.default-dispatcher-3)
Feb 24 14:45:23 node236 marathon[27018]: [2016-02-24 14:45:23,283] INFO Registering in ZooKeeper with hostPort:node236.localnet.net:8080 (mesosphere.marathon.MarathonModule:main)
Feb 24 14:45:23 node236 marathon[27018]: [2016-02-24 14:45:23,384] INFO Calling reviveOffers is enabled. Use --disable_revive_offers_for_new_apps to disable. (mesosphere.marathon.core.flow.FlowModule:main)
Feb 24 14:45:23 node236 marathon[27018]: [2016-02-24 14:45:23,478] INFO Started status update processor with steps:
Feb 24 14:45:23 node236 marathon[27018]: * updateTaskTracker
Feb 24 14:45:23 node236 marathon[27018]: * continueOnError(notifyHealthCheckManager)
Feb 24 14:45:23 node236 marathon[27018]: * continueOnError(notifyRateLimiter)
Feb 24 14:45:23 node236 marathon[27018]: * continueOnError(notifyLaunchQueue)
Feb 24 14:45:23 node236 marathon[27018]: * continueOnError(emitUpdate)
Feb 24 14:45:23 node236 marathon[27018]: * continueOnError(postTaskStatusEvent)
Feb 24 14:45:23 node236 marathon[27018]: * continueOnError(scaleApp) (mesosphere.marathon.core.task.tracker.impl.TaskStatusUpdateProcessorImpl$$EnhancerByGuice$$1ce2140e:main)
Feb 24 14:45:23 node236 marathon[27018]: [2016-02-24 14:45:23,502] INFO All actors suspended:
Feb 24 14:45:23 node236 marathon[27018]: * Actor[akka://marathon/user/offerMatcherManager#137311555]
Feb 24 14:45:23 node236 marathon[27018]: * Actor[akka://marathon/user/reviveOffersWhenWanted#-1004960870]
Feb 24 14:45:23 node236 marathon[27018]: * Actor[akka://marathon/user/offerMatcherLaunchTokens#-1021792506]
Feb 24 14:45:23 node236 marathon[27018]: * Actor[akka://marathon/user/rateLimiter#1469234014]
Feb 24 14:45:23 node236 marathon[27018]: * Actor[akka://marathon/user/launchQueue#763731900]
Feb 24 14:45:23 node236 marathon[27018]: * Actor[akka://marathon/user/killOverdueStagedTasks#1657505069]
Feb 24 14:45:23 node236 marathon[27018]: * Actor[akka://marathon/user/AbdicateOnConnectionLoss#1244933277] (mesosphere.marathon.core.leadership.impl.LeadershipCoordinatorActor:marathon-akka.actor.default-dispatcher-3)
Feb 24 14:45:23 node236 marathon[27018]: [2016-02-24 14:45:23,791] INFO Now standing by. Closing existing handles and rejecting new. (mesosphere.marathon.event.http.HttpEventStreamActor:marathon-akka.actor.default-dispatcher-12)
Feb 24 14:45:23 node236 marathon[27018]: [2016-02-24 14:45:23,879] INFO Adding HTTP support. (mesosphere.chaos.http.HttpModule:main)
Feb 24 14:45:23 node236 marathon[27018]: [2016-02-24 14:45:23,918] INFO Adding HTTPS support. (mesosphere.chaos.http.HttpModule:main)
Feb 24 14:45:23 node236 marathon[27018]: [2016-02-24 14:45:23,919] WARN Both HTTP and HTTPS support have been configured. Consider disabling HTTP with --disable_http (mesosphere.chaos.http.HttpModule:main)
Feb 24 14:45:24 node236 marathon[27018]: [2016-02-24 14:45:24,022] INFO Starting up (mesosphere.marathon.MarathonSchedulerService$$EnhancerByGuice$$44cf946e:MarathonSchedulerService$$EnhancerByGuice$$44cf946e)
Feb 24 14:45:24 node236 marathon[27018]: [2016-02-24 14:45:24,023] INFO jetty-9.3.z-SNAPSHOT (org.eclipse.jetty.server.Server:HttpService$$EnhancerByGuice$$8a89342e STARTING)
Feb 24 14:45:24 node236 marathon[27018]: [2016-02-24 14:45:24,025] INFO Beginning run (mesosphere.marathon.MarathonSchedulerService$$EnhancerByGuice$$44cf946e:MarathonSchedulerService$$EnhancerByGuice$$44cf946e)
Feb 24 14:45:24 node236 marathon[27018]: [2016-02-24 14:45:24,026] INFO Will offer leadership after 500 milliseconds backoff (mesosphere.marathon.MarathonSchedulerService$$EnhancerByGuice$$44cf946e:MarathonSchedulerService$$EnhancerByGuice$$44cf946e)
Feb 24 14:45:24 node236 marathon[27018]: [2016-02-24 14:45:24,475] INFO Registering com.codahale.metrics.jersey.InstrumentedResourceMethodDispatchAdapter as a provider class (com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory:HttpService$$EnhancerByGuice$$8a89342e STARTING)
Feb 24 14:45:24 node236 marathon[27018]: [2016-02-24 14:45:24,480] INFO Registering mesosphere.marathon.api.MarathonExceptionMapper as a provider class (com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory:HttpService$$EnhancerByGuice$$8a89342e STARTING)
Feb 24 14:45:24 node236 marathon[27018]: [2016-02-24 14:45:24,480] INFO Registering mesosphere.marathon.api.v2.AppsResource as a root resource class (com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory:HttpService$$EnhancerByGuice$$8a89342e STARTING)
Feb 24 14:45:24 node236 marathon[27018]: [2016-02-24 14:45:24,480] INFO Registering mesosphere.marathon.api.v2.TasksResource as a root resource class (com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory:HttpService$$EnhancerByGuice$$8a89342e STARTING)
Feb 24 14:45:24 node236 marathon[27018]: [2016-02-24 14:45:24,481] INFO Registering mesosphere.marathon.api.v2.EventSubscriptionsResource as a root resource class (com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory:HttpService$$EnhancerByGuice$$8a89342e STARTING)
Feb 24 14:45:24 node236 marathon[27018]: [2016-02-24 14:45:24,481] INFO Registering mesosphere.marathon.api.v2.QueueResource as a root resource class (com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory:HttpService$$EnhancerByGuice$$8a89342e STARTING)
Feb 24 14:45:24 node236 marathon[27018]: [2016-02-24 14:45:24,481] INFO Registering mesosphere.marathon.api.v2.GroupsResource as a root resource class (com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory:HttpService$$EnhancerByGuice$$8a89342e STARTING)
Feb 24 14:45:24 node236 marathon[27018]: [2016-02-24 14:45:24,481] INFO Registering mesosphere.marathon.api.v2.InfoResource as a root resource class (com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory:HttpService$$EnhancerByGuice$$8a89342e STARTING)
Feb 24 14:45:24 node236 marathon[27018]: [2016-02-24 14:45:24,481] INFO Registering mesosphere.marathon.api.v2.LeaderResource as a root resource class (com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory:HttpService$$EnhancerByGuice$$8a89342e STARTING)
Feb 24 14:45:24 node236 marathon[27018]: [2016-02-24 14:45:24,481] INFO Registering mesosphere.marathon.api.v2.DeploymentsResource as a root resource class (com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory:HttpService$$EnhancerByGuice$$8a89342e STARTING)
Feb 24 14:45:24 node236 marathon[27018]: [2016-02-24 14:45:24,481] INFO Registering mesosphere.marathon.api.v2.ArtifactsResource as a root resource class (com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory:HttpService$$EnhancerByGuice$$8a89342e STARTING)
Feb 24 14:45:24 node236 marathon[27018]: [2016-02-24 14:45:24,481] INFO Registering mesosphere.marathon.api.v2.SchemaResource as a root resource class (com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory:HttpService$$EnhancerByGuice$$8a89342e STARTING)
Feb 24 14:45:24 node236 marathon[27018]: [2016-02-24 14:45:24,484] INFO Initiating Jersey application, version 'Jersey: 1.18.1 02/19/2014 03:28 AM' (com.sun.jersey.server.impl.application.WebApplicationImpl:HttpService$$EnhancerByGuice$$8a89342e STARTING)
Feb 24 14:45:24 node236 marathon[27018]: [2016-02-24 14:45:24,560] INFO Binding com.codahale.metrics.jersey.InstrumentedResourceMethodDispatchAdapter to GuiceManagedComponentProvider with the scope "Singleton" (com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory:HttpService$$EnhancerByGuice$$8a89342e STARTING)
Feb 24 14:45:24 node236 marathon[27018]: [2016-02-24 14:45:24,588] INFO Binding mesosphere.marathon.api.MarathonExceptionMapper to GuiceManagedComponentProvider with the scope "Singleton" (com.sun.jersey.guice.spi.container.GuiceComponentProviderFactory:HttpService$$EnhancerByGuice$$8a89342e STARTING)
Feb 24 14:45:24 node236 marathon[27018]: [2016-02-24 14:45:24,776] INFO Using HA and therefore offering leadership (mesosphere.marathon.MarathonSchedulerService$$EnhancerByGuice$$44cf946e:pool-1-thread-2)
Feb 24 14:45:24 node236 marathon[27018]: [2016-02-24 14:45:24,824] INFO Set group member ID to member_0000001942 (com.twitter.common.zookeeper.Group:pool-1-thread-2)
Feb 24 14:45:24 node236 marathon[27018]: [2016-02-24 14:45:24,898] INFO Candidate /marathon/leader/member_0000001942 is now leader of group: [member_0000001942] (com.twitter.common.zookeeper.CandidateImpl:pool-1-thread-2)
Feb 24 14:45:24 node236 marathon[27018]: [2016-02-24 14:45:24,899] INFO Elected (Leader Interface) (mesosphere.marathon.MarathonSchedulerService$$EnhancerByGuice$$44cf946e:pool-1-thread-2)
Feb 24 14:45:24 node236 marathon[27018]: [2016-02-24 14:45:24,912] INFO Initiating client connection, connectString=192.168.1.236:2181,192.168.1.237:2181,192.168.1.238:2181,192.168.1.239:2181,192.168.1.94:2181 sessionTimeout=10000 watcher=com.twitter.zk.EventBroker@5e9081f0 (org.apache.zookeeper.ZooKeeper:pool-1-thread-2)
Feb 24 14:45:24 node236 marathon[27018]: [2016-02-24 14:45:24,925] INFO Opening socket connection to server 192.168.1.94/192.168.1.94:2181. Will not attempt to authenticate using SASL (unknown error) (org.apache.zookeeper.ClientCnxn:pool-1-thread-2-SendThread(192.168.1.94:2181))
Feb 24 14:45:24 node236 marathon[27018]: [2016-02-24 14:45:24,929] INFO Socket connection established to 192.168.1.94/192.168.1.94:2181, initiating session (org.apache.zookeeper.ClientCnxn:pool-1-thread-2-SendThread(192.168.1.94:2181))
Feb 24 14:45:24 node236 marathon[27018]: [2016-02-24 14:45:24,939] INFO Session establishment complete on server 192.168.1.94/192.168.1.94:2181, sessionid = 0x55269a1250803d1, negotiated timeout = 10000 (org.apache.zookeeper.ClientCnxn:pool-1-thread-2-SendThread(192.168.1.94:2181))
Feb 24 14:45:25 node236 marathon[27018]: [2016-02-24 14:45:25,201] INFO Migration successfully applied for version Version(0, 14, 0) (mesosphere.marathon.state.Migration:pool-1-thread-3)
Feb 24 14:45:25 node236 marathon[27018]: [2016-02-24 14:45:25,205] INFO Call onElected leadership callbacks on EntityStoreCache(MarathonStore(app:)), EntityStoreCache(MarathonStore(group:)), EntityStoreCache(MarathonStore(deployment:)), EntityStoreCache(MarathonStore(framework:)), EntityStoreCache(MarathonStore(taskFailure:)), EntityStoreCache(MarathonStore(task:)), EntityStoreCache(MarathonStore(events:)) (mesosphere.marathon.MarathonSchedulerService$$EnhancerByGuice$$44cf946e:pool-1-thread-2)
Feb 24 14:45:25 node236 marathon[27018]: [2016-02-24 14:45:25,880] INFO Finished onElected leadership callbacks (mesosphere.marathon.MarathonSchedulerService$$EnhancerByGuice$$44cf946e:pool-1-thread-2)
Feb 24 14:45:25 node236 marathon[27018]: [2016-02-24 14:45:25,907] INFO All actors active:
Feb 24 14:45:25 node236 marathon[27018]: * Actor[akka://marathon/user/offerMatcherManager#137311555]
Feb 24 14:45:25 node236 marathon[27018]: * Actor[akka://marathon/user/reviveOffersWhenWanted#-1004960870]
Feb 24 14:45:25 node236 marathon[27018]: * Actor[akka://marathon/user/offerMatcherLaunchTokens#-1021792506]
Feb 24 14:45:25 node236 marathon[27018]: * Actor[akka://marathon/user/rateLimiter#1469234014]
Feb 24 14:45:25 node236 marathon[27018]: * Actor[akka://marathon/user/launchQueue#763731900]
Feb 24 14:45:25 node236 marathon[27018]: * Actor[akka://marathon/user/killOverdueStagedTasks#1657505069]
Feb 24 14:45:25 node236 marathon[27018]: * Actor[akka://marathon/user/AbdicateOnConnectionLoss#1244933277] (mesosphere.marathon.core.leadership.impl.LeadershipCoordinatorActor:marathon-akka.actor.default-dispatcher-13)
Feb 24 14:45:25 node236 marathon[27018]: [2016-02-24 14:45:25,908] INFO Register as ZK Listener (mesosphere.marathon.core.leadership.impl.AbdicateOnConnectionLossActor:marathon-akka.actor.default-dispatcher-13)
Feb 24 14:45:25 node236 marathon[27018]: [2016-02-24 14:45:25,915] INFO started RateLimiterActor (mesosphere.marathon.core.launchqueue.impl.RateLimiterActor:marathon-akka.actor.default-dispatcher-3)
Feb 24 14:45:26 node236 marathon[27018]: [2016-02-24 14:45:26,048] INFO Received offers NOT WANTED notification, canceling 0 revives (mesosphere.marathon.core.flow.impl.ReviveOffersActor:marathon-akka.actor.default-dispatcher-9)
Feb 24 14:45:26 node236 marathon[27018]: [2016-02-24 14:45:26,152] INFO Create new Scheduler Driver with frameworkId: Some(value: "7901cb4e-1e48-4a06-a85b-f340322ad02b-0000"
Feb 24 14:45:26 node236 marathon[27018]: ) (mesosphere.marathon.MarathonSchedulerDriver$:pool-1-thread-2)
Feb 24 14:45:26 node236 marathon[27018]: [2016-02-24 14:45:26,254] INFO Elect leadership (mesosphere.marathon.MarathonSchedulerService$$EnhancerByGuice$$44cf946e:pool-1-thread-2)
Feb 24 14:45:26 node236 marathon[27018]: [2016-02-24 14:45:26,257] INFO Running driver (mesosphere.marathon.MarathonSchedulerService$$EnhancerByGuice$$44cf946e:pool-1-thread-2)
Feb 24 14:45:26 node236 marathon[27018]: [2016-02-24 14:45:26,261] INFO Became active. Accepting event streaming requests. (mesosphere.marathon.event.http.HttpEventStreamActor:marathon-akka.actor.default-dispatcher-9)
Feb 24 14:45:26 node236 marathon[27018]: [2016-02-24 14:45:26,261] INFO Starting scheduler actor (mesosphere.marathon.MarathonSchedulerActor:marathon-akka.actor.default-dispatcher-10)
Feb 24 14:45:26 node236 marathon[27018]: I0224 14:45:26.267725 27107 sched.cpp:166] Version: 0.26.0
Feb 24 14:45:26 node236 marathon[27018]: 2016-02-24 14:45:26,270:27018(0x7ff7a9c55700):ZOO_INFO@log_env@712: Client environment:zookeeper.version=zookeeper C client 3.4.5
Feb 24 14:45:26 node236 marathon[27018]: 2016-02-24 14:45:26,270:27018(0x7ff7a9c55700):ZOO_INFO@log_env@716: Client environment:host.name=node236.localnet.net
Feb 24 14:45:26 node236 marathon[27018]: 2016-02-24 14:45:26,270:27018(0x7ff7a9c55700):ZOO_INFO@log_env@723: Client environment:os.name=Linux
Feb 24 14:45:26 node236 marathon[27018]: 2016-02-24 14:45:26,270:27018(0x7ff7a9c55700):ZOO_INFO@log_env@724: Client environment:os.arch=3.10.0-327.4.4.el7.x86_64
Feb 24 14:45:26 node236 marathon[27018]: 2016-02-24 14:45:26,270:27018(0x7ff7a9c55700):ZOO_INFO@log_env@725: Client environment:os.version=#1 SMP Thu Dec 17 15:51:24 EST 2015
Feb 24 14:45:26 node236 marathon[27018]: 2016-02-24 14:45:26,276:27018(0x7ff7a9c55700):ZOO_INFO@log_env@733: Client environment:user.name=(null)
Feb 24 14:45:26 node236 marathon[27018]: 2016-02-24 14:45:26,277:27018(0x7ff7a9c55700):ZOO_INFO@log_env@741: Client environment:user.home=/root
Feb 24 14:45:26 node236 marathon[27018]: 2016-02-24 14:45:26,277:27018(0x7ff7a9c55700):ZOO_INFO@log_env@753: Client environment:user.dir=/
Feb 24 14:45:26 node236 marathon[27018]: 2016-02-24 14:45:26,277:27018(0x7ff7a9c55700):ZOO_INFO@zookeeper_init@786: Initiating client connection, host=192.168.1.236:2181,192.168.1.237:2181,192.168.1.238:2181,192.168.1.239:2181,192.168.1.94:2181 sessionTimeout=10000 watcher=0x7ff7af146bb0 sessionId=0 sessionPasswd=<null> context=0x7ff848079990 flags=0
Feb 24 14:45:26 node236 marathon[27018]: 2016-02-24 14:45:26,284:27018(0x7ff7a7247700):ZOO_INFO@check_events@1703: initiated connection to server [192.168.1.239:2181]
Feb 24 14:45:26 node236 marathon[27018]: [2016-02-24 14:45:26,285] INFO Reset offerLeadership backoff (mesosphere.marathon.MarathonSchedulerService$$EnhancerByGuice$$44cf946e:pool-1-thread-2)
Feb 24 14:45:26 node236 marathon[27018]: 2016-02-24 14:45:26,291:27018(0x7ff7a7247700):ZOO_INFO@check_events@1750: session establishment complete on server [192.168.1.239:2181], sessionId=0x45269a11d3003e5, negotiated timeout=10000
Feb 24 14:45:26 node236 marathon[27018]: I0224 14:45:26.297334 27111 group.cpp:331] Group process (group(1)@192.168.1.236:53109) connected to ZooKeeper
Feb 24 14:45:26 node236 marathon[27018]: I0224 14:45:26.297570 27111 group.cpp:805] Syncing group operations: queue size (joins, cancels, datas) = (0, 0, 0)
Feb 24 14:45:26 node236 marathon[27018]: I0224 14:45:26.297608 27111 group.cpp:403] Trying to create path '/mesos' in ZooKeeper
Feb 24 14:45:26 node236 marathon[27018]: [2016-02-24 14:45:26,305] INFO Scheduler actor ready (mesosphere.marathon.MarathonSchedulerActor:marathon-akka.actor.default-dispatcher-10)
Feb 24 14:45:26 node236 marathon[27018]: I0224 14:45:26.310520 27111 detector.cpp:156] Detected a new leader: (id='89')
Feb 24 14:45:26 node236 marathon[27018]: I0224 14:45:26.311502 27115 group.cpp:674] Trying to get '/mesos/json.info_0000000089' in ZooKeeper
Feb 24 14:45:26 node236 marathon[27018]: I0224 14:45:26.317384 27115 detector.cpp:482] A new leading master ([email protected]:5050) is detected
Feb 24 14:45:26 node236 marathon[27018]: I0224 14:45:26.317674 27115 sched.cpp:264] New master detected at [email protected]:5050
Feb 24 14:45:26 node236 marathon[27018]: I0224 14:45:26.318277 27115 sched.cpp:320] Authenticating with master [email protected]:5050
Feb 24 14:45:26 node236 marathon[27018]: I0224 14:45:26.318312 27115 sched.cpp:327] Using default CRAM-MD5 authenticatee
Feb 24 14:45:26 node236 marathon[27018]: I0224 14:45:26.322141 27115 authenticatee.cpp:99] Initializing client SASL
Feb 24 14:45:26 node236 marathon[27018]: I0224 14:45:26.325283 27115 authenticatee.cpp:123] Creating new client SASL connection
Feb 24 14:45:26 node236 marathon[27018]: I0224 14:45:26.332222 27110 authenticatee.cpp:214] Received SASL authentication mechanisms: CRAM-MD5
Feb 24 14:45:26 node236 marathon[27018]: I0224 14:45:26.332547 27110 authenticatee.cpp:240] Attempting to authenticate with mechanism 'CRAM-MD5'
Feb 24 14:45:26 node236 marathon[27018]: I0224 14:45:26.339634 27116 authenticatee.cpp:260] Received SASL authentication step
Feb 24 14:45:26 node236 marathon[27018]: E0224 14:45:26.347100 27116 sched.cpp:403] Master [email protected]:5050 refused authentication
Feb 24 14:45:26 node236 marathon[27018]: I0224 14:45:26.347175 27116 sched.cpp:1027] Got error 'Master refused authentication'
Feb 24 14:45:26 node236 marathon[27018]: I0224 14:45:26.347194 27116 sched.cpp:1839] Asked to abort the driver
Feb 24 14:45:26 node236 marathon[27018]: [2016-02-24 14:45:26,359] WARN Error: Master refused authentication
Feb 24 14:45:26 node236 marathon[27018]: In case Mesos does not allow registration with the current frameworkId, delete the ZooKeeper Node: /marathon/state/framework:id
Feb 24 14:45:26 node236 marathon[27018]: CAUTION: if you remove this node, all tasks started with the current frameworkId will be orphaned! (mesosphere.marathon.MarathonScheduler$$EnhancerByGuice$$55d6d0f2:Thread-20)
Feb 24 14:45:26 node236 marathon[27018]: [2016-02-24 14:45:26,360] ERROR Committing suicide! (mesosphere.marathon.MarathonScheduler$$EnhancerByGuice$$55d6d0f2:Thread-20)
Feb 24 14:45:26 node236 marathon[27018]: I0224 14:45:26.362097 27116 sched.cpp:1073] Aborting framework '7901cb4e-1e48-4a06-a85b-f340322ad02b-0000'
Feb 24 14:45:26 node236 marathon[27018]: [2016-02-24 14:45:26,362] INFO reconcile [/nginx-internal] with latest version [2016-02-19T14:15:14.906Z] (mesosphere.marathon.health.MarathonHealthCheckManager$$EnhancerByGuice$$782aa05b:pool-1-thread-7)
Feb 24 14:45:26 node236 marathon[27018]: [2016-02-24 14:45:26,362] INFO reconcile [/mesos-exporter] with latest version [2016-02-17T20:03:48.950Z] (mesosphere.marathon.health.MarathonHealthCheckManager$$EnhancerByGuice$$782aa05b:pool-1-thread-5)
Feb 24 14:45:26 node236 marathon[27018]: [2016-02-24 14:45:26,366] INFO reconcile [/marathon-lb-internal-autoscale] with latest version [2016-02-19T16:21:49.770Z] (mesosphere.marathon.health.MarathonHealthCheckManager$$EnhancerByGuice$$782aa05b:pool-1-thread-3)
Feb 24 14:45:26 node236 marathon[27018]: [2016-02-24 14:45:26,367] INFO reconcile [/mesos-dns] with latest version [2016-02-18T15:10:40.329Z] (mesosphere.marathon.health.MarathonHealthCheckManager$$EnhancerByGuice$$782aa05b:pool-1-thread-9)
Feb 24 14:45:26 node236 marathon[27018]: [2016-02-24 14:45:26,368] INFO reconcile [/cadvisor] with latest version [2016-02-23T19:58:59.241Z] (mesosphere.marathon.health.MarathonHealthCheckManager$$EnhancerByGuice$$782aa05b:pool-1-thread-4)
Feb 24 14:45:26 node236 marathon[27018]: [2016-02-24 14:45:26,368] INFO reconcile [/chronos-marathon] with latest version [2016-02-17T18:24:41.088Z] (mesosphere.marathon.health.MarathonHealthCheckManager$$EnhancerByGuice$$782aa05b:pool-1-thread-6)
Feb 24 14:45:26 node236 marathon[27018]: [2016-02-24 14:45:26,368] INFO reconcile [/product/service/redis] with latest version [2016-02-23T21:20:19.970Z] (mesosphere.marathon.health.MarathonHealthCheckManager$$EnhancerByGuice$$782aa05b:pool-1-thread-10)
Feb 24 14:45:26 node236 marathon[27018]: [2016-02-24 14:45:26,368] INFO reconcile [/product/service/nginx] with latest version [2016-02-23T21:20:19.970Z] (mesosphere.marathon.health.MarathonHealthCheckManager$$EnhancerByGuice$$782aa05b:pool-1-thread-2)
Feb 24 14:45:26 node236 marathon[27018]: [2016-02-24 14:45:26,369] INFO Driver future completed. Executing optional abdication command. (mesosphere.marathon.MarathonSchedulerService$$EnhancerByGuice$$44cf946e:pool-1-thread-1)
Feb 24 14:45:26 node236 marathon[27018]: [2016-02-24 14:45:26,371] INFO Shutting down actor system (mesosphere.marathon.core.base.ActorsModule:Thread-9)
Feb 24 14:45:26 node236 marathon[27018]: [2016-02-24 14:45:26,392] INFO Shutting down services (mesosphere.marathon.Main$:shutdownHook1)
Feb 24 14:45:26 node236 marathon[27018]: [2016-02-24 14:45:26,398] INFO Will offer leadership after 500 milliseconds backoff (mesosphere.marathon.MarathonSchedulerService$$EnhancerByGuice$$44cf946e:pool-1-thread-1)
Feb 24 14:45:26 node236 marathon[27018]: [2016-02-24 14:45:26,398] INFO Defeated (Leader Interface) (mesosphere.marathon.MarathonSchedulerService$$EnhancerByGuice$$44cf946e:main-EventThread)
Feb 24 14:45:26 node236 marathon[27018]: [2016-02-24 14:45:26,399] INFO Call onDefeated leadership callbacks on EntityStoreCache(MarathonStore(app:)), EntityStoreCache(MarathonStore(group:)), EntityStoreCache(MarathonStore(deployment:)), EntityStoreCache(MarathonStore(framework:)), EntityStoreCache(MarathonStore(taskFailure:)), EntityStoreCache(MarathonStore(task:)), EntityStoreCache(MarathonStore(events:)) (mesosphere.marathon.MarathonSchedulerService$$EnhancerByGuice$$44cf946e:main-EventThread)
Feb 24 14:45:26 node236 marathon[27018]: [2016-02-24 14:45:26,401] INFO Shutdown triggered (mesosphere.marathon.MarathonSchedulerService$$EnhancerByGuice$$44cf946e:shutdownHook1)
Feb 24 14:45:26 node236 marathon[27018]: [2016-02-24 14:45:26,402] INFO Stopping driver (mesosphere.marathon.MarathonSchedulerService$$EnhancerByGuice$$44cf946e:shutdownHook1)
Feb 24 14:45:26 node236 marathon[27018]: [2016-02-24 14:45:26,405] INFO Finished onDefeated leadership callbacks (mesosphere.marathon.MarathonSchedulerService$$EnhancerByGuice$$44cf946e:main-EventThread)
Feb 24 14:45:26 node236 marathon[27018]: [2016-02-24 14:45:26,405] INFO Defeat leadership (mesosphere.marathon.MarathonSchedulerService$$EnhancerByGuice$$44cf946e:main-EventThread)
Feb 24 14:45:26 node236 marathon[27018]: [2016-02-24 14:45:26,407] INFO Stopping driver (mesosphere.marathon.MarathonSchedulerService$$EnhancerByGuice$$44cf946e:main-EventThread)
Feb 24 14:45:26 node236 marathon[27018]: [2016-02-24 14:45:26,407] INFO Suspending scheduler actor (mesosphere.marathon.MarathonSchedulerActor:marathon-akka.actor.default-dispatcher-9)
Feb 24 14:45:26 node236 marathon[27018]: I0224 14:45:26.406574 27125 sched.cpp:1805] Asked to stop the driver
Feb 24 14:45:26 node236 marathon[27018]: I0224 14:45:26.407421 27116 sched.cpp:1043] Stopping framework '7901cb4e-1e48-4a06-a85b-f340322ad02b-0000'
Feb 24 14:45:26 node236 marathon[27018]: I0224 14:45:26.407624 27059 sched.cpp:1805] Asked to stop the driver
Feb 24 14:45:26 node236 marathon[27018]: [2016-02-24 14:45:26,408] INFO Now standing by. Closing existing handles and rejecting new. (mesosphere.marathon.event.http.HttpEventStreamActor:marathon-akka.actor.default-dispatcher-9)
Feb 24 14:45:26 node236 marathon[27018]: [2016-02-24 14:45:26,415] INFO Cancelling timer (mesosphere.marathon.MarathonSchedulerService$$EnhancerByGuice$$44cf946e:shutdownHook1)
Feb 24 14:45:26 node236 marathon[27018]: [2016-02-24 14:45:26,415] INFO Removing the blocking of run() (mesosphere.marathon.MarathonSchedulerService$$EnhancerByGuice$$44cf946e:shutdownHook1)
Feb 24 14:45:26 node236 marathon[27018]: [2016-02-24 14:45:26,447] INFO Unregister as ZK Listener (mesosphere.marathon.core.leadership.impl.AbdicateOnConnectionLossActor:marathon-akka.actor.default-dispatcher-11)
Feb 24 14:45:26 node236 marathon[27018]: [2016-02-24 14:45:26,450] INFO Completed run (mesosphere.marathon.MarathonSchedulerService$$EnhancerByGuice$$44cf946e:MarathonSchedulerService$$EnhancerByGuice$$44cf946e)
Feb 24 14:45:26 node236 marathon[27018]: [2016-02-24 14:45:26,460] INFO Message [akka.dispatch.sysmsg.DeathWatchNotification] from Actor[akka://marathon/user/leaderShipCoordinator#-2098942166] to Actor[akka://marathon/user/leaderShipCoordinator#-2098942166] was not delivered. [1] dead letters encountered. This logging can be turned off or adjusted with configuration settings 'akka.log-dead-letters' and 'akka.log-dead-letters-during-shutdown'. (akka.actor.RepointableActorRef:marathon-akka.actor.default-dispatcher-11)
Feb 24 14:45:26 node236 marathon[27018]: [2016-02-24 14:45:26,461] INFO Message [akka.dispatch.sysmsg.DeathWatchNotification] from Actor[akka://marathon/user/leaderShipCoordinator#-2098942166] to Actor[akka://marathon/user/leaderShipCoordinator#-2098942166] was not delivered. [2] dead letters encountered. This logging can be turned off or adjusted with configuration settings 'akka.log-dead-letters' and 'akka.log-dead-letters-during-shutdown'. (akka.actor.RepointableActorRef:marathon-akka.actor.default-dispatcher-11)
Feb 24 14:45:26 node236 marathon[27018]: [2016-02-24 14:45:26,461] INFO Message [akka.dispatch.sysmsg.DeathWatchNotification] from Actor[akka://marathon/user/leaderShipCoordinator#-2098942166] to Actor[akka://marathon/user/leaderShipCoordinator#-2098942166] was not delivered. [3] dead letters encountered. This logging can be turned off or adjusted with configuration settings 'akka.log-dead-letters' and 'akka.log-dead-letters-during-shutdown'. (akka.actor.RepointableActorRef:marathon-akka.actor.default-dispatcher-11)
Feb 24 14:45:26 node236 marathon[27018]: [2016-02-24 14:45:26,462] INFO Message [akka.dispatch.sysmsg.DeathWatchNotification] from Actor[akka://marathon/user/leaderShipCoordinator#-2098942166] to Actor[akka://marathon/user/leaderShipCoordinator#-2098942166] was not delivered. [4] dead letters encountered. This logging can be turned off or adjusted with configuration settings 'akka.log-dead-letters' and 'akka.log-dead-letters-during-shutdown'. (akka.actor.RepointableActorRef:marathon-akka.actor.default-dispatcher-11)
Feb 24 14:45:26 node236 marathon[27018]: [2016-02-24 14:45:26,462] INFO addAllFor [/mesos-dns] version [2016-02-18T15:10:40.329Z] (mesosphere.marathon.health.MarathonHealthCheckManager$$EnhancerByGuice$$782aa05b:pool-1-thread-2)
Feb 24 14:45:26 node236 marathon[27018]: [2016-02-24 14:45:26,463] INFO addAllFor [/product/service/nginx] version [2016-02-23T21:20:19.970Z] (mesosphere.marathon.health.MarathonHealthCheckManager$$EnhancerByGuice$$782aa05b:pool-1-thread-8)
Feb 24 14:45:26 node236 marathon[27018]: [2016-02-24 14:45:26,465] INFO addAllFor [/product/service/redis] version [2016-02-23T21:20:19.970Z] (mesosphere.marathon.health.MarathonHealthCheckManager$$EnhancerByGuice$$782aa05b:pool-1-thread-4)
Feb 24 14:45:26 node236 marathon[27018]: [2016-02-24 14:45:26,466] INFO addAllFor [/chronos-marathon] version [2016-02-17T18:24:41.088Z] (mesosphere.marathon.health.MarathonHealthCheckManager$$EnhancerByGuice$$782aa05b:pool-1-thread-10)
Feb 24 14:45:26 node236 marathon[27018]: [2016-02-24 14:45:26,466] INFO addAllFor [/nginx-internal] version [2016-02-19T14:15:14.906Z] (mesosphere.marathon.health.MarathonHealthCheckManager$$EnhancerByGuice$$782aa05b:pool-1-thread-5)
Feb 24 14:45:26 node236 marathon[27018]: [2016-02-24 14:45:26,471] INFO Message [akka.dispatch.sysmsg.DeathWatchNotification] from Actor[akka://marathon/user/leaderShipCoordinator#-2098942166] to Actor[akka://marathon/user/leaderShipCoordinator#-2098942166] was not delivered. [5] dead letters encountered. This logging can be turned off or adjusted with configuration settings 'akka.log-dead-letters' and 'akka.log-dead-letters-during-shutdown'. (akka.actor.RepointableActorRef:marathon-akka.actor.default-dispatcher-8)
Feb 24 14:45:26 node236 marathon[27018]: [2016-02-24 14:45:26,474] INFO addAllFor [/cadvisor] version [2016-02-23T19:58:59.241Z] (mesosphere.marathon.health.MarathonHealthCheckManager$$EnhancerByGuice$$782aa05b:pool-1-thread-14)
Feb 24 14:45:26 node236 marathon[27018]: [2016-02-24 14:45:26,478] INFO addAllFor [/mesos-exporter] version [2016-02-17T20:03:48.950Z] (mesosphere.marathon.health.MarathonHealthCheckManager$$EnhancerByGuice$$782aa05b:pool-1-thread-17)
Feb 24 14:45:26 node236 marathon[27018]: [2016-02-24 14:45:26,479] INFO addAllFor [/marathon-lb-internal-autoscale] version [2016-02-19T16:21:49.770Z] (mesosphere.marathon.health.MarathonHealthCheckManager$$EnhancerByGuice$$782aa05b:pool-1-thread-13)
Feb 24 14:45:26 node236 marathon[27018]: [2016-02-24 14:45:26,494] INFO Adding health check for app [/nginx-internal] and version [2016-02-19T14:15:14.906Z]: [HealthCheck(Some(/),HTTP,Some(0),None,10 seconds,2 seconds,10 seconds,10,false,None)] (mesosphere.marathon.health.MarathonHealthCheckManager$$EnhancerByGuice$$782aa05b:pool-1-thread-5)
Feb 24 14:45:26 node236 marathon[27018]: [2016-02-24 14:45:26,524] INFO Waiting for services to shut down (mesosphere.marathon.Main$:shutdownHook1)
Feb 24 14:45:26 node236 marathon[27018]: [2016-02-24 14:45:26,532] INFO Adding health check for app [/chronos-marathon] and version [2016-02-17T18:24:41.088Z]: [HealthCheck(None,HTTP,Some(0),Some(Command(curl -f -X GET http://$HOST:8080)),5 seconds,20 seconds,20 seconds,5,false,None)] (mesosphere.marathon.health.MarathonHealthCheckManager$$EnhancerByGuice$$782aa05b:pool-1-thread-10)
Feb 24 14:45:26 node236 marathon[27018]: [2016-02-24 14:45:26,556] INFO Adding health check for app [/cadvisor] and version [2016-02-23T19:58:59.241Z]: [HealthCheck(Some(/),HTTP,Some(0),None,10 seconds,2 seconds,10 seconds,10,false,None)] (mesosphere.marathon.health.MarathonHealthCheckManager$$EnhancerByGuice$$782aa05b:pool-1-thread-14)
Feb 24 14:45:26 node236 marathon[27018]: [2016-02-24 14:45:26,569] ERROR Failed to start all services. Services by state: {STOPPING=[HttpService$$EnhancerByGuice$$8a89342e [STOPPING], MetricsReporterService$$EnhancerByGuice$$2d37aea4 [TERMINATED]], TERMINATED=[MarathonSchedulerService$$EnhancerByGuice$$44cf946e [TERMINATED]]} (mesosphere.marathon.Main$:main)
Feb 24 14:45:26 node236 marathon[27018]: java.lang.IllegalStateException: Expected to be healthy after starting. The following services are not running: {STOPPING=[HttpService$$EnhancerByGuice$$8a89342e [STOPPING]]}
Feb 24 14:45:26 node236 marathon[27018]: #011at com.google.common.util.concurrent.ServiceManager$ServiceManagerState.checkHealthy(ServiceManager.java:710) ~[marathon:0.14.0]
Feb 24 14:45:26 node236 marathon[27018]: #011at com.google.common.util.concurrent.ServiceManager$ServiceManagerState.awaitHealthy(ServiceManager.java:535) ~[marathon:0.14.0]
Feb 24 14:45:26 node236 marathon[27018]: #011at com.google.common.util.concurrent.ServiceManager.awaitHealthy(ServiceManager.java:301) ~[marathon:0.14.0]
Feb 24 14:45:26 node236 marathon[27018]: #011at mesosphere.chaos.App$class.run(App.scala:40) ~[marathon:0.14.0]
Feb 24 14:45:26 node236 marathon[27018]: #011at mesosphere.marathon.MarathonApp.run(Main.scala:18) [marathon:0.14.0]
Feb 24 14:45:26 node236 marathon[27018]: #011at mesosphere.marathon.MarathonApp.runDefault(Main.scala:80) [marathon:0.14.0]
Feb 24 14:45:26 node236 marathon[27018]: #011at mesosphere.marathon.Main$.delayedEndpoint$mesosphere$marathon$Main$1(Main.scala:89) [marathon:0.14.0]
Feb 24 14:45:26 node236 marathon[27018]: #011at mesosphere.marathon.Main$delayedInit$body.apply(Main.scala:88) [marathon:0.14.0]
Feb 24 14:45:26 node236 marathon[27018]: #011at scala.Function0$class.apply$mcV$sp(Function0.scala:34) [marathon:0.14.0]
Feb 24 14:45:26 node236 marathon[27018]: #011at scala.runtime.AbstractFunction0.apply$mcV$sp(AbstractFunction0.scala:12) [marathon:0.14.0]
Feb 24 14:45:26 node236 marathon[27018]: #011at scala.App$$anonfun$main$1.apply(App.scala:76) [marathon:0.14.0]
Feb 24 14:45:26 node236 marathon[27018]: #011at scala.App$$anonfun$main$1.apply(App.scala:76) [marathon:0.14.0]
Feb 24 14:45:26 node236 marathon[27018]: #011at scala.collection.immutable.List.foreach(List.scala:381) [marathon:0.14.0]
Feb 24 14:45:26 node236 marathon[27018]: #011at scala.collection.generic.TraversableForwarder$class.foreach(TraversableForwarder.scala:35) [marathon:0.14.0]
Feb 24 14:45:26 node236 marathon[27018]: #011at scala.App$class.main(App.scala:76) [marathon:0.14.0]
Feb 24 14:45:26 node236 marathon[27018]: #011at mesosphere.marathon.MarathonApp.main(Main.scala:18) [marathon:0.14.0]
Feb 24 14:45:26 node236 marathon[27018]: #011at mesosphere.marathon.Main.main(Main.scala) [marathon:0.14.0]
Feb 24 14:45:26 node236 marathon[27018]: [2016-02-24 14:45:26,569] INFO Shutting down services (mesosphere.marathon.Main$:main)
Feb 24 14:45:26 node236 marathon[27018]: [2016-02-24 14:45:26,570] INFO Waiting for services to shut down (mesosphere.marathon.Main$:main)
Feb 24 14:45:26 node236 marathon[27018]: [2016-02-24 14:45:26,570] INFO Adding health check for app [/mesos-exporter] and version [2016-02-17T20:03:48.950Z]: [HealthCheck(Some(/),HTTP,Some(0),None,300 seconds,60 seconds,20 seconds,3,false,None)] (mesosphere.marathon.health.MarathonHealthCheckManager$$EnhancerByGuice$$782aa05b:pool-1-thread-17)
Feb 24 14:45:26 node236 marathon[27018]: [2016-02-24 14:45:26,576] INFO Using HA and therefore offering leadership (mesosphere.marathon.MarathonSchedulerService$$EnhancerByGuice$$44cf946e:pool-1-thread-5)
Feb 24 14:45:26 node236 marathon[27018]: [2016-02-24 14:45:26,685] INFO Loading plugins implementing 'mesosphere.marathon.plugin.auth.Authorizer' from these urls: [] (mesosphere.marathon.core.plugin.impl.PluginManagerImpl:HttpService$$EnhancerByGuice$$8a89342e STARTING)
Feb 24 14:45:26 node236 marathon[27018]: [2016-02-24 14:45:26,687] INFO Found 0 plugins. (mesosphere.marathon.core.plugin.impl.PluginManagerImpl:HttpService$$EnhancerByGuice$$8a89342e STARTING)
Feb 24 14:45:26 node236 marathon[27018]: [2016-02-24 14:45:26,689] INFO Loading plugins implementing 'mesosphere.marathon.plugin.auth.Authenticator' from these urls: [] (mesosphere.marathon.core.plugin.impl.PluginManagerImpl:HttpService$$EnhancerByGuice$$8a89342e STARTING)
Feb 24 14:45:26 node236 marathon[27018]: [2016-02-24 14:45:26,690] INFO Found 0 plugins. (mesosphere.marathon.core.plugin.impl.PluginManagerImpl:HttpService$$EnhancerByGuice$$8a89342e STARTING)
Feb 24 14:45:26 node236 marathon[27018]: [2016-02-24 14:45:26,758] INFO Started o.e.j.s.ServletContextHandler@20f3b556{/,null,AVAILABLE} (org.eclipse.jetty.server.handler.ContextHandler:HttpService$$EnhancerByGuice$$8a89342e STARTING)
Feb 24 14:45:26 node236 marathon[27018]: [2016-02-24 14:45:26,779] INFO Started ServerConnector@f32f41fc{HTTP/1.1,[http/1.1]}{0.0.0.0:8080} (org.eclipse.jetty.server.ServerConnector:HttpService$$EnhancerByGuice$$8a89342e STARTING)
Feb 24 14:45:26 node236 marathon[27018]: [2016-02-24 14:45:26,788] INFO x509={node236.localnet.net=marathon} wild={} alias=null for SslContextFactory@7f051473(file:///etc/marathon/ssl/marathon.jks,null) (org.eclipse.jetty.util.ssl.SslContextFactory:HttpService$$EnhancerByGuice$$8a89342e STARTING)
Feb 24 14:45:27 node236 marathon[27018]: [2016-02-24 14:45:27,334] INFO Started ServerConnector@8ac50316{SSL,[ssl, http/1.1]}{0.0.0.0:8443} (org.eclipse.jetty.server.ServerConnector:HttpService$$EnhancerByGuice$$8a89342e STARTING)
Feb 24 14:45:27 node236 marathon[27018]: [2016-02-24 14:45:27,334] INFO Started @10917ms (org.eclipse.jetty.server.Server:HttpService$$EnhancerByGuice$$8a89342e STARTING)
Feb 24 14:45:27 node236 marathon[27018]: [2016-02-24 14:45:27,343] INFO Stopped ServerConnector@f32f41fc{HTTP/1.1,[http/1.1]}{0.0.0.0:8080} (org.eclipse.jetty.server.ServerConnector:HttpService$$EnhancerByGuice$$8a89342e STOPPING)
Feb 24 14:45:27 node236 marathon[27018]: [2016-02-24 14:45:27,346] INFO Stopped ServerConnector@8ac50316{SSL,[ssl, http/1.1]}{0.0.0.0:8443} (org.eclipse.jetty.server.ServerConnector:HttpService$$EnhancerByGuice$$8a89342e STOPPING)
Feb 24 14:45:27 node236 marathon[27018]: [2016-02-24 14:45:27,354] INFO Stopped o.e.j.s.ServletContextHandler@20f3b556{/,null,UNAVAILABLE} (org.eclipse.jetty.server.handler.ContextHandler:HttpService$$EnhancerByGuice$$8a89342e STOPPING)
[root@node236 mesos]# 

Any clues what might be causing an error ?

[meichstedt]

Hi @akamalov seems like your marathon.secret file contains

marathon 4feaa0f614b821ec4849

while it should only contain the secret and not the user. You set the principal to use via the --mesos_authentication_principal flag. so your cli flags should be

--mesos_authentication_principal marathon
--mesos_authentication_secret_file /etc/marathon/marathon.secret

and /etc/marathon/marathon.secret should give you 4feaa0f614b821ec4849 only without any spaces or newline characters.

This is decribed here as well.

[akamalov]

Yep, I've been told about that and I removed and re-tried. No dice :( Thanks so much again for your reply.

Alex

[akamalov]

Answering my own question: the problem was a newline in marathon.secret file. Once removed, authentication went through.

Thanks so much!!

Alex

[meichstedt]

Hey @akamalov you might have missed that my answer above included the hint _without any spaces or newline characters_ :grin:

Anyways glad you got it running!

[akamalov]

Thanks a ton!!!!!

[gvenka008c]

@akamalov @meichstedt

I am seeing the 'Master refused authentication' while authenticating Marathon against Mesos Master. Here is the info. Thoughts?

May  8 01:33:35 jmesosmas-03p marathon[32372]: I0508 01:33:35.870514 32617 sched.cpp:326] New master detected at [email protected]:5050
May  8 01:33:35 jmesosmas-03p marathon[32372]: I0508 01:33:35.870781 32617 sched.cpp:382] Authenticating with master [email protected]:5050
May  8 01:33:35 jmesosmas-03p marathon[32372]: I0508 01:33:35.870803 32617 sched.cpp:389] Using default CRAM-MD5 authenticatee
May  8 01:33:35 jmesosmas-03p marathon[32372]: I0508 01:33:35.871073 32617 authenticatee.cpp:97] Initializing client SASL
May  8 01:33:35 jmesosmas-03p marathon[32372]: I0508 01:33:35.872035 32617 authenticatee.cpp:121] Creating new client SASL connection
May  8 01:33:35 jmesosmas-03p mesos-master[27629]: I0508 01:33:35.872970 27657 master.cpp:5521] Authenticating [email protected]:9090
May  8 01:33:35 jmesosmas-03p mesos-master[27629]: I0508 01:33:35.873271 27657 authenticator.cpp:98] Creating new server SASL connection
May  8 01:33:35 jmesosmas-03p marathon[32372]: I0508 01:33:35.874003 32615 authenticatee.cpp:212] Received SASL authentication mechanisms: CRAM-MD5
May  8 01:33:35 jmesosmas-03p marathon[32372]: I0508 01:33:35.874047 32615 authenticatee.cpp:238] Attempting to authenticate with mechanism 'CRAM-MD5'
May  8 01:33:35 jmesosmas-03p marathon[32372]: I0508 01:33:35.875255 32615 authenticatee.cpp:258] Received SASL authentication step
May  8 01:33:35 jmesosmas-03p marathon[32372]: E0508 01:33:35.876106 32615 sched.cpp:465] Master [email protected]:5050 refused authentication
May  8 01:33:35 jmesosmas-03p marathon[32372]: I0508 01:33:35.876124 32615 sched.cpp:1131] Got error 'Master refused authentication'

Here is the Mesos Master setting

[root@jmesosmas-03p auth]# more acls
{ "run_tasks": [ { "principals": { "type": "ANY" }, "users": { "type": "ANY" } } ], "register_frameworks": [ { "principals": { "type": "ANY" }, "roles": { "type": "ANY" } } ] }

[root@jmesosmas-03p auth]# more credentials
marathon marathonsecret


[root@jmesosmas-03p mesos-master]# more acls
file:///etc/mesos/auth/acls

[root@jmesosmas-03p mesos-master]# more credentials
file:///etc/mesos/auth/credentials

[root@jmesosmas-03p mesos-master]# more authenticate
true

Here is the marathon configuration

[root@jmesosmas-03p conf]# more mesos_authentication_principal
marathon

[root@jmesosmas-03p conf]# more mesos_authentication_secret_file
/etc/mesos/auth/marathon.secret

[root@jmesosmas-03p conf]# more /etc/mesos/auth/marathon.secret
marathonsecret

Here is the list of packages

# rpm -qa | grep cyrus
cyrus-sasl-md5-2.1.26-20.el7_2.x86_64
cyrus-sasl-lib-2.1.26-20.el7_2.x86_64
cyrus-sasl-plain-2.1.26-20.el7_2.x86_64
cyrus-sasl-2.1.26-20.el7_2.x86_64

I followed the same steps as outlined in the below link
https://mesosphere.github.io/marathon/docs/framework-authentication.html

[akamalov]

@gvenka008c, please make sure that you do not have a newline in your marathon.secret. This was the case with me. Use "echo -n and restart your mesos-master(s).

Alex

[gvenka008c]

@akamalov Yes. That worked. I think we should have a way to update the info in the document as well at https://mesosphere.github.io/marathon/docs/framework-authentication.html

The secret file cannot have a trailing newline. To not add a newline simply run:

$ echo -n "secret" > /path/to/secret/file

[gkleiman]

@gvenka008c please feel free to create a PR with the documentation update. I'll be happy to merge it.