See <https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/2537/changes>
Changes: [toenshoff] Fixed Authenticator SASL auxiliary memory access. ------------------------------------------ [...truncated 64895 lines...] I1108 01:49:05.190856 10907 leveldb.cpp:176] Opened db in 3.221795ms I1108 01:49:05.192028 10907 leveldb.cpp:183] Compacted db in 1.139528ms I1108 01:49:05.192077 10907 leveldb.cpp:198] Created db iterator in 15020ns I1108 01:49:05.192096 10907 leveldb.cpp:204] Seeked to beginning of db in 1560ns I1108 01:49:05.192106 10907 leveldb.cpp:273] Iterated through 0 keys in the db in 155ns I1108 01:49:05.192137 10907 replica.cpp:741] Replica recovered with log positions 0 -> 0 with 1 holes and 0 unlearned I1108 01:49:05.192669 10935 recover.cpp:437] Starting replica recovery I1108 01:49:05.192983 10935 recover.cpp:463] Replica is in EMPTY status I1108 01:49:05.194319 10932 replica.cpp:638] Replica in EMPTY status received a broadcasted recover request I1108 01:49:05.194753 10930 recover.cpp:188] Received a recover response from a replica in EMPTY status I1108 01:49:05.195276 10932 recover.cpp:554] Updating replica status to STARTING I1108 01:49:05.196259 10931 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 756748ns I1108 01:49:05.196290 10931 replica.cpp:320] Persisted replica status to STARTING I1108 01:49:05.196527 10931 recover.cpp:463] Replica is in STARTING status I1108 01:49:05.197047 10928 master.cpp:318] Master 20141108-014905-3125920579-55654-10907 (penates.apache.org) started on 67.195.81.186:55654 I1108 01:49:05.197100 10928 master.cpp:364] Master only allowing authenticated frameworks to register I1108 01:49:05.197119 10928 master.cpp:369] Master only allowing authenticated slaves to register I1108 01:49:05.197149 10928 credentials.hpp:36] Loading credentials for authentication from '/tmp/SchedulerTest_TaskRunning_UmTIgW/credentials' I1108 01:49:05.197427 10928 master.cpp:413] Authorization enabled I1108 01:49:05.197758 10925 replica.cpp:638] Replica in STARTING status received a broadcasted recover request I1108 01:49:05.197863 10921 master.cpp:126] No whitelist given. Advertising offers for all slaves I1108 01:49:05.198024 10924 hierarchical_allocator_process.hpp:299] Initializing hierarchical allocator process with master : [email protected]:55654 I1108 01:49:05.198231 10936 recover.cpp:188] Received a recover response from a replica in STARTING status I1108 01:49:05.198763 10927 recover.cpp:554] Updating replica status to VOTING I1108 01:49:05.199261 10925 master.cpp:1263] The newly elected leader is [email protected]:55654 with id 20141108-014905-3125920579-55654-10907 I1108 01:49:05.199288 10925 master.cpp:1276] Elected as the leading master! I1108 01:49:05.199304 10925 master.cpp:1094] Recovering from registrar I1108 01:49:05.199493 10935 registrar.cpp:313] Recovering registrar I1108 01:49:05.199636 10924 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 732162ns I1108 01:49:05.199672 10924 replica.cpp:320] Persisted replica status to VOTING I1108 01:49:05.199812 10933 recover.cpp:568] Successfully joined the Paxos group I1108 01:49:05.200072 10933 recover.cpp:452] Recover process terminated I1108 01:49:05.200537 10924 log.cpp:656] Attempting to start the writer I1108 01:49:05.202018 10936 replica.cpp:474] Replica received implicit promise request with proposal 1 I1108 01:49:05.202795 10936 leveldb.cpp:306] Persisting metadata (8 bytes) to leveldb took 742609ns I1108 01:49:05.202823 10936 replica.cpp:342] Persisted promised to 1 I1108 01:49:05.203902 10925 coordinator.cpp:230] Coordinator attemping to fill missing position I1108 01:49:05.205755 10923 replica.cpp:375] Replica received explicit promise request for position 0 with proposal 2 I1108 01:49:05.206552 10923 leveldb.cpp:343] Persisting action (8 bytes) to leveldb took 760351ns I1108 01:49:05.206580 10923 replica.cpp:676] Persisted action at 0 I1108 01:49:06.198236 10936 hierarchical_allocator_process.hpp:697] No resources available to allocate! I1108 01:49:07.938017 10936 hierarchical_allocator_process.hpp:659] Performed allocation for 0 slaves in 1.739783833secs I1108 01:49:07.939331 10935 replica.cpp:508] Replica received write request for position 0 I1108 01:49:07.939396 10935 leveldb.cpp:438] Reading position from leveldb took 36246ns I1108 01:49:07.940140 10935 leveldb.cpp:343] Persisting action (14 bytes) to leveldb took 703763ns I1108 01:49:07.940172 10935 replica.cpp:676] Persisted action at 0 I1108 01:49:07.940814 10936 replica.cpp:655] Replica received learned notice for position 0 I1108 01:49:07.941447 10936 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 600429ns I1108 01:49:07.941474 10936 replica.cpp:676] Persisted action at 0 I1108 01:49:07.941495 10936 replica.cpp:661] Replica learned NOP action at position 0 I1108 01:49:07.942114 10929 log.cpp:672] Writer started with ending position 0 I1108 01:49:07.943490 10924 leveldb.cpp:438] Reading position from leveldb took 30477ns I1108 01:49:07.946866 10932 registrar.cpp:346] Successfully fetched the registry (0B) in 2.747299072secs I1108 01:49:07.946974 10932 registrar.cpp:445] Applied 1 operations in 17820ns; attempting to update the 'registry' I1108 01:49:07.949985 10922 log.cpp:680] Attempting to append 140 bytes to the log I1108 01:49:07.950160 10936 coordinator.cpp:340] Coordinator attempting to write APPEND action at position 1 I1108 01:49:07.951654 10930 replica.cpp:508] Replica received write request for position 1 I1108 01:49:07.952492 10930 leveldb.cpp:343] Persisting action (159 bytes) to leveldb took 804122ns I1108 01:49:07.952534 10930 replica.cpp:676] Persisted action at 1 I1108 01:49:07.953322 10926 replica.cpp:655] Replica received learned notice for position 1 I1108 01:49:07.953922 10926 leveldb.cpp:343] Persisting action (161 bytes) to leveldb took 572475ns I1108 01:49:07.953953 10926 replica.cpp:676] Persisted action at 1 I1108 01:49:07.953977 10926 replica.cpp:661] Replica learned APPEND action at position 1 I1108 01:49:07.955088 10929 registrar.cpp:490] Successfully updated the 'registry' in 8.06272ms I1108 01:49:07.955226 10929 registrar.cpp:376] Successfully recovered registrar I1108 01:49:07.955533 10926 master.cpp:1121] Recovered 0 slaves from the Registry (102B) ; allowing 10mins for slaves to re-register I1108 01:49:07.955584 10929 log.cpp:699] Attempting to truncate the log to 1 I1108 01:49:07.955783 10921 coordinator.cpp:340] Coordinator attempting to write TRUNCATE action at position 2 I1108 01:49:07.956694 10931 replica.cpp:508] Replica received write request for position 2 I1108 01:49:07.957284 10931 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 556346ns I1108 01:49:07.957315 10931 replica.cpp:676] Persisted action at 2 I1108 01:49:07.958180 10921 replica.cpp:655] Replica received learned notice for position 2 I1108 01:49:07.958752 10921 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 543931ns I1108 01:49:07.958822 10921 leveldb.cpp:401] Deleting ~1 keys from leveldb took 41426ns I1108 01:49:07.958845 10921 replica.cpp:676] Persisted action at 2 I1108 01:49:07.958868 10921 replica.cpp:661] Replica learned TRUNCATE action at position 2 I1108 01:49:07.971034 10927 slave.cpp:169] Slave started on 221)@67.195.81.186:55654 I1108 01:49:07.971081 10927 credentials.hpp:84] Loading credential for authentication from '/tmp/SchedulerTest_TaskRunning_3jzx1l/credential' I1108 01:49:07.971235 10927 slave.cpp:276] Slave using credential for: test-principal I1108 01:49:07.971504 10927 slave.cpp:289] Slave resources: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] I1108 01:49:07.971668 10927 slave.cpp:318] Slave hostname: penates.apache.org I1108 01:49:07.971686 10927 slave.cpp:319] Slave checkpoint: false W1108 01:49:07.971695 10927 slave.cpp:321] Disabling checkpointing is deprecated and the --checkpoint flag will be removed in a future release. Please avoid using this flag I1108 01:49:07.972113 10907 scheduler.cpp:145] Version: 0.22.0 I1108 01:49:07.972687 10931 state.cpp:33] Recovering state from '/tmp/SchedulerTest_TaskRunning_3jzx1l/meta' I1108 01:49:07.973042 10923 status_update_manager.cpp:197] Recovering status update manager I1108 01:49:07.973398 10930 slave.cpp:3464] Finished recovery I1108 01:49:07.974297 10932 status_update_manager.cpp:171] Pausing sending status updates I1108 01:49:07.974309 10925 slave.cpp:602] New master detected at [email protected]:55654 I1108 01:49:07.974351 10925 slave.cpp:665] Authenticating with master [email protected]:55654 I1108 01:49:07.974604 10925 slave.cpp:638] Detecting new master I1108 01:49:07.974731 10922 authenticatee.hpp:133] Creating new client SASL connection I1108 01:49:07.975235 10932 scheduler.cpp:414] New master detected at [email protected]:55654 I1108 01:49:07.975270 10932 scheduler.cpp:463] Authenticating with master [email protected]:55654 I1108 01:49:07.975339 10936 master.cpp:3901] Authenticating slave(221)@67.195.81.186:55654 I1108 01:49:07.975390 10936 master.cpp:3912] Using default CRAM-MD5 authenticator I1108 01:49:07.975466 10924 authenticatee.hpp:133] Creating new client SASL connection I1108 01:49:07.975700 10926 authenticator.hpp:166] Creating new server SASL connection I1108 01:49:07.975754 10936 master.cpp:3901] Authenticating scheduler(1)@67.195.81.186:55654 I1108 01:49:07.975795 10936 master.cpp:3912] Using default CRAM-MD5 authenticator I1108 01:49:07.975860 10931 authenticatee.hpp:224] Received SASL authentication mechanisms: CRAM-MD5 I1108 01:49:07.975899 10931 authenticatee.hpp:250] Attempting to authenticate with mechanism 'CRAM-MD5' I1108 01:49:07.976073 10925 authenticator.hpp:272] Received SASL authentication start I1108 01:49:07.976130 10925 authenticator.hpp:394] Authentication requires more steps I1108 01:49:07.976227 10925 authenticatee.hpp:270] Received SASL authentication step I1108 01:49:07.976325 10925 authenticator.hpp:300] Received SASL authentication step I1108 01:49:07.976341 10928 authenticator.hpp:166] Creating new server SASL connection I1108 01:49:07.976352 10925 auxprop.cpp:99] Request to lookup properties for user: 'test-principal' realm: 'penates.apache.org' server FQDN: 'penates.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false I1108 01:49:07.976382 10925 auxprop.cpp:171] Looking up auxiliary property '*userPassword' I1108 01:49:07.976428 10925 auxprop.cpp:171] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' I1108 01:49:07.976465 10925 auxprop.cpp:99] Request to lookup properties for user: 'test-principal' realm: 'penates.apache.org' server FQDN: 'penates.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true I1108 01:49:07.976480 10925 auxprop.cpp:121] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true I1108 01:49:07.976485 10925 auxprop.cpp:121] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true I1108 01:49:07.976497 10925 authenticator.hpp:386] Authentication success I1108 01:49:07.976567 10923 authenticatee.hpp:224] Received SASL authentication mechanisms: CRAM-MD5 I1108 01:49:07.976596 10923 authenticatee.hpp:250] Attempting to authenticate with mechanism 'CRAM-MD5' I1108 01:49:07.976671 10933 authenticatee.hpp:310] Authentication success I1108 01:49:07.976686 10923 authenticator.hpp:272] Received SASL authentication start I1108 01:49:07.976709 10931 master.cpp:3959] Successfully authenticated principal 'test-principal' at slave(221)@67.195.81.186:55654 I1108 01:49:07.976733 10923 authenticator.hpp:394] Authentication requires more steps I1108 01:49:07.976814 10923 authenticatee.hpp:270] Received SASL authentication step I1108 01:49:07.976938 10924 authenticator.hpp:300] Received SASL authentication step I1108 01:49:07.976975 10924 auxprop.cpp:99] Request to lookup properties for user: 'test-principal' realm: 'penates.apache.org' server FQDN: 'penates.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false I1108 01:49:07.977206 10935 slave.cpp:722] Successfully authenticated with master [email protected]:55654 I1108 01:49:08.092429 10924 auxprop.cpp:171] Looking up auxiliary property '*userPassword' I1108 01:49:08.092476 10924 auxprop.cpp:171] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' I1108 01:49:08.092566 10924 auxprop.cpp:99] Request to lookup properties for user: 'test-principal' realm: 'penates.apache.org' server FQDN: 'penates.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true I1108 01:49:08.092582 10924 auxprop.cpp:121] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true I1108 01:49:08.092591 10924 auxprop.cpp:121] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true I1108 01:49:08.092607 10924 authenticator.hpp:386] Authentication success I1108 01:49:08.092597 10935 slave.cpp:1050] Will retry registration in 7.422361ms if necessary I1108 01:49:08.092744 10932 authenticatee.hpp:310] Authentication success I1108 01:49:08.092888 10925 master.cpp:3068] Registering slave at slave(221)@67.195.81.186:55654 (penates.apache.org) with id 20141108-014905-3125920579-55654-10907-S0 I1108 01:49:08.093072 10932 scheduler.cpp:533] Successfully authenticated with master [email protected]:55654 I1108 01:49:08.093221 10925 master.cpp:3959] Successfully authenticated principal 'test-principal' at scheduler(1)@67.195.81.186:55654 I1108 01:49:08.093713 10934 registrar.cpp:445] Applied 1 operations in 77735ns; attempting to update the 'registry' I1108 01:49:08.094645 10932 master.cpp:1383] Received registration request for framework 'default' at scheduler(1)@67.195.81.186:55654 I1108 01:49:08.094720 10932 master.cpp:1342] Authorizing framework principal 'test-principal' to receive offers for role '*' I1108 01:49:08.095366 10923 master.cpp:1447] Registering framework 20141108-014905-3125920579-55654-10907-0000 (default) at scheduler(1)@67.195.81.186:55654 I1108 01:49:08.095723 10924 hierarchical_allocator_process.hpp:329] Added framework 20141108-014905-3125920579-55654-10907-0000 I1108 01:49:08.095757 10924 hierarchical_allocator_process.hpp:697] No resources available to allocate! I1108 01:49:08.095768 10924 hierarchical_allocator_process.hpp:659] Performed allocation for 0 slaves in 15802ns I1108 01:49:08.095926 10924 scheduler.cpp:582] Enqueuing event 1 from [email protected]:55654 I1108 01:49:08.097185 10925 log.cpp:680] Attempting to append 318 bytes to the log I1108 01:49:08.097571 10936 coordinator.cpp:340] Coordinator attempting to write APPEND action at position 3 I1108 01:49:08.099226 10930 replica.cpp:508] Replica received write request for position 3 I1108 01:49:08.099867 10930 leveldb.cpp:343] Persisting action (337 bytes) to leveldb took 605484ns I1108 01:49:08.099899 10930 replica.cpp:676] Persisted action at 3 I1108 01:49:08.100551 10928 replica.cpp:655] Replica received learned notice for position 3 I1108 01:49:08.101034 10928 leveldb.cpp:343] Persisting action (339 bytes) to leveldb took 455409ns I1108 01:49:08.101068 10928 replica.cpp:676] Persisted action at 3 I1108 01:49:08.101097 10928 replica.cpp:661] Replica learned APPEND action at position 3 I1108 01:49:08.101090 10929 slave.cpp:1050] Will retry registration in 35.377138ms if necessary I1108 01:49:08.101179 10924 master.cpp:3056] Ignoring register slave message from slave(221)@67.195.81.186:55654 (penates.apache.org) as admission is already in progress I1108 01:49:08.102387 10925 registrar.cpp:490] Successfully updated the 'registry' in 8.606976ms I1108 01:49:08.102727 10931 log.cpp:699] Attempting to truncate the log to 3 I1108 01:49:08.102926 10925 coordinator.cpp:340] Coordinator attempting to write TRUNCATE action at position 4 I1108 01:49:08.102977 10931 slave.cpp:2536] Received ping from slave-observer(200)@67.195.81.186:55654 I1108 01:49:08.103065 10932 master.cpp:3122] Registered slave 20141108-014905-3125920579-55654-10907-S0 at slave(221)@67.195.81.186:55654 (penates.apache.org) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] I1108 01:49:08.103210 10931 slave.cpp:756] Registered with master [email protected]:55654; given slave ID 20141108-014905-3125920579-55654-10907-S0 I1108 01:49:08.103221 10923 hierarchical_allocator_process.hpp:442] Added slave 20141108-014905-3125920579-55654-10907-S0 (penates.apache.org) with cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (and cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] available) I1108 01:49:08.103337 10933 status_update_manager.cpp:178] Resuming sending status updates I1108 01:49:08.103449 10923 hierarchical_allocator_process.hpp:734] Offering cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20141108-014905-3125920579-55654-10907-S0 to framework 20141108-014905-3125920579-55654-10907-0000 I1108 01:49:08.103920 10925 replica.cpp:508] Replica received write request for position 4 I1108 01:49:08.103965 10923 hierarchical_allocator_process.hpp:679] Performed allocation for slave 20141108-014905-3125920579-55654-10907-S0 in 665626ns I1108 01:49:08.104343 10922 master.cpp:3843] Sending 1 offers to framework 20141108-014905-3125920579-55654-10907-0000 (default) at scheduler(1)@67.195.81.186:55654 I1108 01:49:08.104629 10922 scheduler.cpp:582] Enqueuing event 3 from [email protected]:55654 I1108 01:49:08.104657 10925 leveldb.cpp:343] Persisting action (16 bytes) to leveldb took 703815ns I1108 01:49:08.104688 10925 replica.cpp:676] Persisted action at 4 I1108 01:49:08.105619 10932 replica.cpp:655] Replica received learned notice for position 4 I1108 01:49:08.106286 10932 leveldb.cpp:343] Persisting action (18 bytes) to leveldb took 638945ns I1108 01:49:08.106355 10932 leveldb.cpp:401] Deleting ~2 keys from leveldb took 42168ns I1108 01:49:08.106377 10932 replica.cpp:676] Persisted action at 4 I1108 01:49:08.106400 10932 replica.cpp:661] Replica learned TRUNCATE action at position 4 I1108 01:49:08.107607 10928 master.cpp:2344] Processing reply for offers: [ 20141108-014905-3125920579-55654-10907-O0 ] on slave 20141108-014905-3125920579-55654-10907-S0 at slave(221)@67.195.81.186:55654 (penates.apache.org) for framework 20141108-014905-3125920579-55654-10907-0000 (default) at scheduler(1)@67.195.81.186:55654 W1108 01:49:08.107735 10928 master.cpp:1990] Executor default for task 1 uses less CPUs (None) than the minimum required (0.01). Please update your executor, as this will be mandatory in future releases. W1108 01:49:08.107774 10928 master.cpp:2001] Executor default for task 1 uses less memory (None) than the minimum required (32MB). Please update your executor, as this will be mandatory in future releases. I1108 01:49:08.107874 10928 master.cpp:2440] Authorizing framework principal 'test-principal' to launch task 1 as user 'jenkins' I1108 01:49:08.109029 10934 master.hpp:877] Adding task 1 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20141108-014905-3125920579-55654-10907-S0 (penates.apache.org) I1108 01:49:08.109150 10934 master.cpp:2503] Launching task 1 of framework 20141108-014905-3125920579-55654-10907-0000 (default) at scheduler(1)@67.195.81.186:55654 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave 20141108-014905-3125920579-55654-10907-S0 at slave(221)@67.195.81.186:55654 (penates.apache.org) I1108 01:49:08.109486 10925 slave.cpp:1081] Got assigned task 1 for framework 20141108-014905-3125920579-55654-10907-0000 I1108 01:49:08.110146 10925 slave.cpp:1191] Launching task 1 for framework 20141108-014905-3125920579-55654-10907-0000 I1108 01:49:08.112793 10925 slave.cpp:3911] Launching executor default of framework 20141108-014905-3125920579-55654-10907-0000 in work directory '/tmp/SchedulerTest_TaskRunning_3jzx1l/slaves/20141108-014905-3125920579-55654-10907-S0/frameworks/20141108-014905-3125920579-55654-10907-0000/executors/default/runs/3ba93585-eb33-47f9-b7ad-900410d45dfb' I1108 01:49:08.162212 10925 exec.cpp:132] Version: 0.22.0 I1108 01:49:08.162586 10930 exec.cpp:182] Executor started at: executor(73)@67.195.81.186:55654 with pid 10907 I1108 01:49:08.162645 10925 slave.cpp:1314] Queuing task '1' for executor default of framework '20141108-014905-3125920579-55654-10907-0000 I1108 01:49:08.162789 10925 slave.cpp:555] Successfully attached file '/tmp/SchedulerTest_TaskRunning_3jzx1l/slaves/20141108-014905-3125920579-55654-10907-S0/frameworks/20141108-014905-3125920579-55654-10907-0000/executors/default/runs/3ba93585-eb33-47f9-b7ad-900410d45dfb' I1108 01:49:08.162914 10925 slave.cpp:2838] Monitoring executor 'default' of framework '20141108-014905-3125920579-55654-10907-0000' in container '3ba93585-eb33-47f9-b7ad-900410d45dfb' I1108 01:49:08.163207 10925 slave.cpp:1858] Got registration for executor 'default' of framework 20141108-014905-3125920579-55654-10907-0000 from executor(73)@67.195.81.186:55654 I1108 01:49:08.163630 10925 slave.cpp:1977] Flushing queued task 1 for executor 'default' of framework 20141108-014905-3125920579-55654-10907-0000 I1108 01:49:08.163861 10921 exec.cpp:206] Executor registered on slave 20141108-014905-3125920579-55654-10907-S0 I1108 01:49:08.165978 10921 exec.cpp:218] Executor::registered took 24357ns I1108 01:49:08.166162 10921 exec.cpp:293] Executor asked to run task '1' I1108 01:49:08.166236 10921 exec.cpp:302] Executor::launchTask took 53610ns I1108 01:49:08.168365 10921 exec.cpp:525] Executor sending status update TASK_RUNNING (UUID: c5a5e286-8534-4608-90b1-ae5c45bffb64) for task 1 of framework 20141108-014905-3125920579-55654-10907-0000 I1108 01:49:08.168683 10921 slave.cpp:2213] Handling status update TASK_RUNNING (UUID: c5a5e286-8534-4608-90b1-ae5c45bffb64) for task 1 of framework 20141108-014905-3125920579-55654-10907-0000 from executor(73)@67.195.81.186:55654 I1108 01:49:08.168948 10931 status_update_manager.cpp:317] Received status update TASK_RUNNING (UUID: c5a5e286-8534-4608-90b1-ae5c45bffb64) for task 1 of framework 20141108-014905-3125920579-55654-10907-0000 I1108 01:49:08.168990 10931 status_update_manager.cpp:494] Creating StatusUpdate stream for task 1 of framework 20141108-014905-3125920579-55654-10907-0000 I1108 01:49:08.169193 10931 status_update_manager.cpp:371] Forwarding update TASK_RUNNING (UUID: c5a5e286-8534-4608-90b1-ae5c45bffb64) for task 1 of framework 20141108-014905-3125920579-55654-10907-0000 to the slave I1108 01:49:08.169399 10934 slave.cpp:2456] Forwarding the update TASK_RUNNING (UUID: c5a5e286-8534-4608-90b1-ae5c45bffb64) for task 1 of framework 20141108-014905-3125920579-55654-10907-0000 to [email protected]:55654 I1108 01:49:08.169643 10934 slave.cpp:2383] Status update manager successfully handled status update TASK_RUNNING (UUID: c5a5e286-8534-4608-90b1-ae5c45bffb64) for task 1 of framework 20141108-014905-3125920579-55654-10907-0000 I1108 01:49:08.169677 10934 slave.cpp:2389] Sending acknowledgement for status update TASK_RUNNING (UUID: c5a5e286-8534-4608-90b1-ae5c45bffb64) for task 1 of framework 20141108-014905-3125920579-55654-10907-0000 to executor(73)@67.195.81.186:55654 I1108 01:49:08.169716 10927 master.cpp:3446] Forwarding status update TASK_RUNNING (UUID: c5a5e286-8534-4608-90b1-ae5c45bffb64) for task 1 of framework 20141108-014905-3125920579-55654-10907-0000 I1108 01:49:08.169888 10931 exec.cpp:339] Executor received status update acknowledgement c5a5e286-8534-4608-90b1-ae5c45bffb64 for task 1 of framework 20141108-014905-3125920579-55654-10907-0000 I1108 01:49:08.169874 10927 master.cpp:3418] Status update TASK_RUNNING (UUID: c5a5e286-8534-4608-90b1-ae5c45bffb64) for task 1 of framework 20141108-014905-3125920579-55654-10907-0000 from slave 20141108-014905-3125920579-55654-10907-S0 at slave(221)@67.195.81.186:55654 (penates.apache.org) I1108 01:49:08.169958 10927 master.cpp:4693] Updating the latest state of task 1 of framework 20141108-014905-3125920579-55654-10907-0000 to TASK_RUNNING I1108 01:49:08.169988 10922 scheduler.cpp:582] Enqueuing event 5 from [email protected]:55654 I1108 01:49:08.171063 10929 master.cpp:698] Master terminating W1108 01:49:08.171238 10929 master.cpp:4738] Removing task 1 with resources cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] of framework 20141108-014905-3125920579-55654-10907-0000 on slave 20141108-014905-3125920579-55654-10907-S0 at slave(221)@67.195.81.186:55654 (penates.apache.org) in non-terminal state TASK_RUNNING I1108 01:49:08.171795 10934 hierarchical_allocator_process.hpp:563] Recovered cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (total allocatable: cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000]) on slave 20141108-014905-3125920579-55654-10907-S0 from framework 20141108-014905-3125920579-55654-10907-0000 I1108 01:49:08.171846 10929 master.cpp:4781] Removing executor 'default' with resources of framework 20141108-014905-3125920579-55654-10907-0000 on slave 20141108-014905-3125920579-55654-10907-S0 at slave(221)@67.195.81.186:55654 (penates.apache.org) I1108 01:49:08.172674 10923 slave.cpp:2621] [email protected]:55654 exited W1108 01:49:08.172708 10923 slave.cpp:2624] Master disconnected! Waiting for a new master to be elected I1108 01:49:08.178273 10930 slave.cpp:2896] Executor 'default' of framework 20141108-014905-3125920579-55654-10907-0000 exited with status 0 I1108 01:49:08.180595 10930 slave.cpp:2213] Handling status update TASK_LOST (UUID: 55fced39-af94-4b2d-8977-7f309db4ec9a) for task 1 of framework 20141108-014905-3125920579-55654-10907-0000 from @0.0.0.0:0 I1108 01:49:08.180683 10930 slave.cpp:4219] Terminating task 1 I1108 01:49:08.180991 10930 slave.cpp:484] Slave terminating I1108 01:49:08.181067 10930 slave.cpp:1531] Asked to shut down framework 20141108-014905-3125920579-55654-10907-0000 by @0.0.0.0:0 I1108 01:49:08.181092 10930 slave.cpp:1556] Shutting down framework 20141108-014905-3125920579-55654-10907-0000 I1108 01:49:08.181152 10930 slave.cpp:3005] Cleaning up executor 'default' of framework 20141108-014905-3125920579-55654-10907-0000 I1108 01:49:08.181366 10922 gc.cpp:56] Scheduling '/tmp/SchedulerTest_TaskRunning_3jzx1l/slaves/20141108-014905-3125920579-55654-10907-S0/frameworks/20141108-014905-3125920579-55654-10907-0000/executors/default/runs/3ba93585-eb33-47f9-b7ad-900410d45dfb' for gc 6.99999790238518days in the future I1108 01:49:08.181443 10930 slave.cpp:3082] Cleaning up framework 20141108-014905-3125920579-55654-10907-0000 I1108 01:49:08.181565 10933 status_update_manager.cpp:279] Closing status update streams for framework 20141108-014905-3125920579-55654-10907-0000 I1108 01:49:08.181613 10922 gc.cpp:56] Scheduling '/tmp/SchedulerTest_TaskRunning_3jzx1l/slaves/20141108-014905-3125920579-55654-10907-S0/frameworks/20141108-014905-3125920579-55654-10907-0000/executors/default' for gc 6.99999790076444days in the future I1108 01:49:08.181670 10933 status_update_manager.cpp:525] Cleaning up status update stream for task 1 of framework 20141108-014905-3125920579-55654-10907-0000 I1108 01:49:08.181741 10922 gc.cpp:56] Scheduling '/tmp/SchedulerTest_TaskRunning_3jzx1l/slaves/20141108-014905-3125920579-55654-10907-S0/frameworks/20141108-014905-3125920579-55654-10907-0000' for gc 6.99999789883259days in the future [ OK ] SchedulerTest.TaskRunning (2999 ms) [----------] 1 test from SchedulerTest (2999 ms total) [----------] Global test environment tear-down [==========] 414 tests from 64 test cases ran. (279615 ms total) [ PASSED ] 413 tests. [ FAILED ] 1 test, listed below: [ FAILED ] MesosContainerizerExecuteTest.IoRedirection 1 FAILED TEST YOU HAVE 5 DISABLED TESTS make[3]: *** [check-local] Error 1 make[3]: Leaving directory `<https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/ws/build/src'> make[2]: *** [check-am] Error 2 make[2]: Leaving directory `<https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/ws/build/src'> make[1]: *** [check] Error 2 make[1]: Leaving directory `<https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-Out-Of-Src-Disable-Java-Disable-Python-Disable-Webui/ws/build/src'> make: *** [check-recursive] Error 1 Test finished Exit status: 2 Build step 'Execute shell' marked build as failure Recording test results
