[
https://issues.apache.org/jira/browse/MESOS-1783?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=14130940#comment-14130940
]
Niklas Quarfot Nielsen commented on MESOS-1783:
-----------------------------------------------
Right - I see the problem. The launch task request fails and the resources are
reoffered and it worked before because we raced out of the test.
We can either discard any subsequent offers or wait for the recovered
resources. Both work, but the first is faster.
I will get a patch ready.
> MasterTest.LaunchDuplicateOfferTest is flaky
> --------------------------------------------
>
> Key: MESOS-1783
> URL: https://issues.apache.org/jira/browse/MESOS-1783
> Project: Mesos
> Issue Type: Bug
> Components: test
> Affects Versions: 0.20.0
> Environment: ubuntu-14.04-gcc Jenkins VM
> Reporter: Yan Xu
>
> {noformat:title=}
> [ RUN ] MasterTest.LaunchDuplicateOfferTest
> Using temporary directory '/tmp/MasterTest_LaunchDuplicateOfferTest_3ifzmg'
> I0909 22:46:59.212977 21883 leveldb.cpp:176] Opened db in 20.307533ms
> I0909 22:46:59.219717 21883 leveldb.cpp:183] Compacted db in 6.470397ms
> I0909 22:46:59.219925 21883 leveldb.cpp:198] Created db iterator in 5571ns
> I0909 22:46:59.220100 21883 leveldb.cpp:204] Seeked to beginning of db in
> 1365ns
> I0909 22:46:59.220268 21883 leveldb.cpp:273] Iterated through 0 keys in the
> db in 658ns
> I0909 22:46:59.220448 21883 replica.cpp:741] Replica recovered with log
> positions 0 -> 0 with 1 holes and 0 unlearned
> I0909 22:46:59.220855 21903 recover.cpp:425] Starting replica recovery
> I0909 22:46:59.221103 21903 recover.cpp:451] Replica is in EMPTY status
> I0909 22:46:59.221626 21903 replica.cpp:638] Replica in EMPTY status received
> a broadcasted recover request
> I0909 22:46:59.221914 21903 recover.cpp:188] Received a recover response from
> a replica in EMPTY status
> I0909 22:46:59.222204 21903 recover.cpp:542] Updating replica status to
> STARTING
> I0909 22:46:59.232590 21900 master.cpp:286] Master
> 20140909-224659-16842879-44263-21883 (trusty) started on 127.0.1.1:44263
> I0909 22:46:59.233278 21900 master.cpp:332] Master only allowing
> authenticated frameworks to register
> I0909 22:46:59.233543 21900 master.cpp:337] Master only allowing
> authenticated slaves to register
> I0909 22:46:59.233934 21900 credentials.hpp:36] Loading credentials for
> authentication from
> '/tmp/MasterTest_LaunchDuplicateOfferTest_3ifzmg/credentials'
> I0909 22:46:59.236431 21900 master.cpp:366] Authorization enabled
> I0909 22:46:59.237522 21898 hierarchical_allocator_process.hpp:299]
> Initializing hierarchical allocator process with master :
> master@127.0.1.1:44263
> I0909 22:46:59.237877 21904 master.cpp:120] No whitelist given. Advertising
> offers for all slaves
> I0909 22:46:59.238723 21903 leveldb.cpp:306] Persisting metadata (8 bytes) to
> leveldb took 16.245391ms
> I0909 22:46:59.238916 21903 replica.cpp:320] Persisted replica status to
> STARTING
> I0909 22:46:59.239203 21903 recover.cpp:451] Replica is in STARTING status
> I0909 22:46:59.239724 21903 replica.cpp:638] Replica in STARTING status
> received a broadcasted recover request
> I0909 22:46:59.239967 21903 recover.cpp:188] Received a recover response from
> a replica in STARTING status
> I0909 22:46:59.240304 21903 recover.cpp:542] Updating replica status to VOTING
> I0909 22:46:59.240684 21900 master.cpp:1212] The newly elected leader is
> master@127.0.1.1:44263 with id 20140909-224659-16842879-44263-21883
> I0909 22:46:59.240846 21900 master.cpp:1225] Elected as the leading master!
> I0909 22:46:59.241149 21900 master.cpp:1043] Recovering from registrar
> I0909 22:46:59.241509 21898 registrar.cpp:313] Recovering registrar
> I0909 22:46:59.248440 21903 leveldb.cpp:306] Persisting metadata (8 bytes) to
> leveldb took 7.864221ms
> I0909 22:46:59.248644 21903 replica.cpp:320] Persisted replica status to
> VOTING
> I0909 22:46:59.248846 21903 recover.cpp:556] Successfully joined the Paxos
> group
> I0909 22:46:59.249330 21897 log.cpp:656] Attempting to start the writer
> I0909 22:46:59.249809 21897 replica.cpp:474] Replica received implicit
> promise request with proposal 1
> I0909 22:46:59.250075 21903 recover.cpp:440] Recover process terminated
> I0909 22:46:59.258286 21897 leveldb.cpp:306] Persisting metadata (8 bytes) to
> leveldb took 8.292514ms
> I0909 22:46:59.258489 21897 replica.cpp:342] Persisted promised to 1
> I0909 22:46:59.258848 21897 coordinator.cpp:230] Coordinator attemping to
> fill missing position
> I0909 22:46:59.259454 21897 replica.cpp:375] Replica received explicit
> promise request for position 0 with proposal 2
> I0909 22:46:59.267755 21897 leveldb.cpp:343] Persisting action (8 bytes) to
> leveldb took 8.109338ms
> I0909 22:46:59.267916 21897 replica.cpp:676] Persisted action at 0
> I0909 22:46:59.270128 21902 replica.cpp:508] Replica received write request
> for position 0
> I0909 22:46:59.270294 21902 leveldb.cpp:438] Reading position from leveldb
> took 27443ns
> I0909 22:46:59.277220 21902 leveldb.cpp:343] Persisting action (14 bytes) to
> leveldb took 6.801267ms
> I0909 22:46:59.277369 21902 replica.cpp:676] Persisted action at 0
> I0909 22:46:59.277628 21902 replica.cpp:655] Replica received learned notice
> for position 0
> I0909 22:46:59.286487 21902 leveldb.cpp:343] Persisting action (16 bytes) to
> leveldb took 8.603502ms
> I0909 22:46:59.286648 21902 replica.cpp:676] Persisted action at 0
> I0909 22:46:59.286761 21902 replica.cpp:661] Replica learned NOP action at
> position 0
> I0909 22:46:59.287091 21902 log.cpp:672] Writer started with ending position 0
> I0909 22:46:59.287461 21902 leveldb.cpp:438] Reading position from leveldb
> took 13360ns
> I0909 22:46:59.288635 21902 registrar.cpp:346] Successfully fetched the
> registry (0B)
> I0909 22:46:59.288818 21902 registrar.cpp:422] Attempting to update the
> 'registry'
> I0909 22:46:59.289894 21901 log.cpp:680] Attempting to append 119 bytes to
> the log
> I0909 22:46:59.290071 21901 coordinator.cpp:340] Coordinator attempting to
> write APPEND action at position 1
> I0909 22:46:59.290390 21901 replica.cpp:508] Replica received write request
> for position 1
> I0909 22:46:59.300258 21901 leveldb.cpp:343] Persisting action (136 bytes) to
> leveldb took 9.7093ms
> I0909 22:46:59.300474 21901 replica.cpp:676] Persisted action at 1
> I0909 22:46:59.300776 21901 replica.cpp:655] Replica received learned notice
> for position 1
> I0909 22:46:59.313390 21901 leveldb.cpp:343] Persisting action (138 bytes) to
> leveldb took 7.861529ms
> I0909 22:46:59.313534 21901 replica.cpp:676] Persisted action at 1
> I0909 22:46:59.313647 21901 replica.cpp:661] Replica learned APPEND action at
> position 1
> I0909 22:46:59.319062 21898 registrar.cpp:479] Successfully updated 'registry'
> I0909 22:46:59.320523 21898 registrar.cpp:372] Successfully recovered
> registrar
> I0909 22:46:59.320739 21898 master.cpp:1070] Recovered 0 slaves from the
> Registry (83B) ; allowing 10mins for slaves to re-register
> I0909 22:46:59.321112 21902 log.cpp:699] Attempting to truncate the log to 1
> I0909 22:46:59.321322 21902 coordinator.cpp:340] Coordinator attempting to
> write TRUNCATE action at position 2
> I0909 22:46:59.321756 21901 replica.cpp:508] Replica received write request
> for position 2
> I0909 22:46:59.332890 21901 leveldb.cpp:343] Persisting action (16 bytes) to
> leveldb took 10.969491ms
> I0909 22:46:59.333034 21901 replica.cpp:676] Persisted action at 2
> I0909 22:46:59.338004 21900 replica.cpp:655] Replica received learned notice
> for position 2
> I0909 22:46:59.349581 21900 leveldb.cpp:343] Persisting action (18 bytes) to
> leveldb took 10.748662ms
> I0909 22:46:59.349805 21900 leveldb.cpp:401] Deleting ~1 keys from leveldb
> took 53406ns
> I0909 22:46:59.349936 21900 replica.cpp:676] Persisted action at 2
> I0909 22:46:59.350049 21900 replica.cpp:661] Replica learned TRUNCATE action
> at position 2
> I0909 22:46:59.354003 21904 slave.cpp:167] Slave started on
> 174)@127.0.1.1:44263
> I0909 22:46:59.354221 21904 credentials.hpp:84] Loading credential for
> authentication from
> '/tmp/MasterTest_LaunchDuplicateOfferTest_KNJT56/credential'
> I0909 22:46:59.354404 21904 slave.cpp:274] Slave using credential for:
> test-principal
> I0909 22:46:59.354634 21904 slave.cpp:287] Slave resources: cpus(*):2;
> mem(*):1024; disk(*):24988; ports(*):[31000-32000]
> I0909 22:46:59.354806 21904 slave.cpp:315] Slave hostname: trusty
> I0909 22:46:59.355002 21904 slave.cpp:316] Slave checkpoint: false
> I0909 22:46:59.355732 21900 state.cpp:33] Recovering state from
> '/tmp/MasterTest_LaunchDuplicateOfferTest_KNJT56/meta'
> I0909 22:46:59.359880 21899 status_update_manager.cpp:193] Recovering status
> update manager
> I0909 22:46:59.360123 21904 slave.cpp:3202] Finished recovery
> I0909 22:46:59.360575 21904 slave.cpp:598] New master detected at
> master@127.0.1.1:44263
> I0909 22:46:59.360752 21901 status_update_manager.cpp:167] New master
> detected at master@127.0.1.1:44263
> I0909 22:46:59.360916 21904 slave.cpp:672] Authenticating with master
> master@127.0.1.1:44263
> I0909 22:46:59.361153 21902 authenticatee.hpp:128] Creating new client SASL
> connection
> I0909 22:46:59.361413 21902 master.cpp:3653] Authenticating
> slave(174)@127.0.1.1:44263
> I0909 22:46:59.361625 21902 authenticator.hpp:156] Creating new server SASL
> connection
> I0909 22:46:59.361927 21902 authenticatee.hpp:219] Received SASL
> authentication mechanisms: CRAM-MD5
> I0909 22:46:59.362068 21902 authenticatee.hpp:245] Attempting to authenticate
> with mechanism 'CRAM-MD5'
> I0909 22:46:59.362210 21902 authenticator.hpp:262] Received SASL
> authentication start
> I0909 22:46:59.362360 21902 authenticator.hpp:384] Authentication requires
> more steps
> I0909 22:46:59.362512 21902 authenticatee.hpp:265] Received SASL
> authentication step
> I0909 22:46:59.362679 21902 authenticator.hpp:290] Received SASL
> authentication step
> I0909 22:46:59.362828 21902 auxprop.cpp:81] Request to lookup properties for
> user: 'test-principal' realm: 'trusty' server FQDN: 'trusty'
> SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
> SASL_AUXPROP_AUTHZID: false
> I0909 22:46:59.362973 21902 auxprop.cpp:153] Looking up auxiliary property
> '*userPassword'
> I0909 22:46:59.363093 21902 auxprop.cpp:153] Looking up auxiliary property
> '*cmusaslsecretCRAM-MD5'
> I0909 22:46:59.363221 21902 auxprop.cpp:81] Request to lookup properties for
> user: 'test-principal' realm: 'trusty' server FQDN: 'trusty'
> SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
> SASL_AUXPROP_AUTHZID: true
> I0909 22:46:59.363354 21902 auxprop.cpp:103] Skipping auxiliary property
> '*userPassword' since SASL_AUXPROP_AUTHZID == true
> I0909 22:46:59.363507 21902 auxprop.cpp:103] Skipping auxiliary property
> '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
> I0909 22:46:59.363642 21902 authenticator.hpp:376] Authentication success
> I0909 22:46:59.363798 21902 authenticatee.hpp:305] Authentication success
> I0909 22:46:59.363898 21898 master.cpp:3693] Successfully authenticated
> principal 'test-principal' at slave(174)@127.0.1.1:44263
> I0909 22:46:59.364150 21904 slave.cpp:645] Detecting new master
> I0909 22:46:59.367167 21904 slave.cpp:729] Successfully authenticated with
> master master@127.0.1.1:44263
> I0909 22:46:59.367414 21898 master.cpp:2843] Registering slave at
> slave(174)@127.0.1.1:44263 (trusty) with id
> 20140909-224659-16842879-44263-21883-0
> I0909 22:46:59.367635 21898 registrar.cpp:422] Attempting to update the
> 'registry'
> I0909 22:46:59.368796 21898 log.cpp:680] Attempting to append 292 bytes to
> the log
> I0909 22:46:59.369040 21898 coordinator.cpp:340] Coordinator attempting to
> write APPEND action at position 3
> I0909 22:46:59.369390 21898 replica.cpp:508] Replica received write request
> for position 3
> I0909 22:46:59.369617 21904 slave.cpp:980] Will retry registration in
> 14.029398ms if necessary
> I0909 22:46:59.370132 21883 sched.cpp:137] Version: 0.21.0
> I0909 22:46:59.370468 21902 sched.cpp:233] New master detected at
> master@127.0.1.1:44263
> I0909 22:46:59.370618 21902 sched.cpp:283] Authenticating with master
> master@127.0.1.1:44263
> I0909 22:46:59.370823 21902 authenticatee.hpp:128] Creating new client SASL
> connection
> I0909 22:46:59.371105 21902 master.cpp:3653] Authenticating
> scheduler-605e2d2e-9f77-4731-9db0-3bfb5bc90722@127.0.1.1:44263
> I0909 22:46:59.371297 21902 authenticator.hpp:156] Creating new server SASL
> connection
> I0909 22:46:59.371500 21902 authenticatee.hpp:219] Received SASL
> authentication mechanisms: CRAM-MD5
> I0909 22:46:59.371628 21902 authenticatee.hpp:245] Attempting to authenticate
> with mechanism 'CRAM-MD5'
> I0909 22:46:59.371762 21902 authenticator.hpp:262] Received SASL
> authentication start
> I0909 22:46:59.371901 21902 authenticator.hpp:384] Authentication requires
> more steps
> I0909 22:46:59.372061 21902 authenticatee.hpp:265] Received SASL
> authentication step
> I0909 22:46:59.372206 21902 authenticator.hpp:290] Received SASL
> authentication step
> I0909 22:46:59.372350 21902 auxprop.cpp:81] Request to lookup properties for
> user: 'test-principal' realm: 'trusty' server FQDN: 'trusty'
> SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
> SASL_AUXPROP_AUTHZID: false
> I0909 22:46:59.372477 21902 auxprop.cpp:153] Looking up auxiliary property
> '*userPassword'
> I0909 22:46:59.372591 21902 auxprop.cpp:153] Looking up auxiliary property
> '*cmusaslsecretCRAM-MD5'
> I0909 22:46:59.372711 21902 auxprop.cpp:81] Request to lookup properties for
> user: 'test-principal' realm: 'trusty' server FQDN: 'trusty'
> SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false
> SASL_AUXPROP_AUTHZID: true
> I0909 22:46:59.372822 21902 auxprop.cpp:103] Skipping auxiliary property
> '*userPassword' since SASL_AUXPROP_AUTHZID == true
> I0909 22:46:59.372932 21902 auxprop.cpp:103] Skipping auxiliary property
> '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true
> I0909 22:46:59.373100 21902 authenticator.hpp:376] Authentication success
> I0909 22:46:59.373235 21902 authenticatee.hpp:305] Authentication success
> I0909 22:46:59.373404 21902 master.cpp:3693] Successfully authenticated
> principal 'test-principal' at
> scheduler-605e2d2e-9f77-4731-9db0-3bfb5bc90722@127.0.1.1:44263
> I0909 22:46:59.373641 21902 sched.cpp:357] Successfully authenticated with
> master master@127.0.1.1:44263
> I0909 22:46:59.373829 21902 sched.cpp:476] Sending registration request to
> master@127.0.1.1:44263
> I0909 22:46:59.373988 21902 master.cpp:1331] Received registration request
> from scheduler-605e2d2e-9f77-4731-9db0-3bfb5bc90722@127.0.1.1:44263
> I0909 22:46:59.374132 21902 master.cpp:1291] Authorizing framework principal
> 'test-principal' to receive offers for role '*'
> I0909 22:46:59.374372 21902 master.cpp:1390] Registering framework
> 20140909-224659-16842879-44263-21883-0000 at
> scheduler-605e2d2e-9f77-4731-9db0-3bfb5bc90722@127.0.1.1:44263
> I0909 22:46:59.374570 21902 sched.cpp:407] Framework registered with
> 20140909-224659-16842879-44263-21883-0000
> I0909 22:46:59.374703 21902 sched.cpp:421] Scheduler::registered took 13117ns
> I0909 22:46:59.374847 21902 hierarchical_allocator_process.hpp:329] Added
> framework 20140909-224659-16842879-44263-21883-0000
> I0909 22:46:59.374977 21902 hierarchical_allocator_process.hpp:697] No
> resources available to allocate!
> I0909 22:46:59.375087 21902 hierarchical_allocator_process.hpp:659] Performed
> allocation for 0 slaves in 110452ns
> I0909 22:46:59.377118 21898 leveldb.cpp:343] Persisting action (311 bytes) to
> leveldb took 7.587205ms
> I0909 22:46:59.377259 21898 replica.cpp:676] Persisted action at 3
> I0909 22:46:59.377576 21898 replica.cpp:655] Replica received learned notice
> for position 3
> I0909 22:46:59.384246 21903 slave.cpp:980] Will retry registration in
> 11.116311ms if necessary
> I0909 22:46:59.384421 21899 master.cpp:2831] Ignoring register slave message
> from slave(174)@127.0.1.1:44263 (trusty) as admission is already in progress
> I0909 22:46:59.386246 21898 leveldb.cpp:343] Persisting action (313 bytes) to
> leveldb took 8.510526ms
> I0909 22:46:59.386385 21898 replica.cpp:676] Persisted action at 3
> I0909 22:46:59.386499 21898 replica.cpp:661] Replica learned APPEND action at
> position 3
> I0909 22:46:59.386991 21898 registrar.cpp:479] Successfully updated 'registry'
> I0909 22:46:59.387271 21898 master.cpp:2883] Registered slave
> 20140909-224659-16842879-44263-21883-0 at slave(174)@127.0.1.1:44263 (trusty)
> I0909 22:46:59.387441 21898 master.cpp:4126] Adding slave
> 20140909-224659-16842879-44263-21883-0 at slave(174)@127.0.1.1:44263 (trusty)
> with cpus(*):2; mem(*):1024; disk(*):24988; ports(*):[31000-32000]
> I0909 22:46:59.387675 21898 slave.cpp:763] Registered with master
> master@127.0.1.1:44263; given slave ID 20140909-224659-16842879-44263-21883-0
> I0909 22:46:59.387945 21898 slave.cpp:2329] Received ping from
> slave-observer(157)@127.0.1.1:44263
> I0909 22:46:59.387819 21902 hierarchical_allocator_process.hpp:442] Added
> slave 20140909-224659-16842879-44263-21883-0 (trusty) with cpus(*):2;
> mem(*):1024; disk(*):24988; ports(*):[31000-32000] (and cpus(*):2;
> mem(*):1024; disk(*):24988; ports(*):[31000-32000] available)
> I0909 22:46:59.388262 21902 hierarchical_allocator_process.hpp:734] Offering
> cpus(*):2; mem(*):1024; disk(*):24988; ports(*):[31000-32000] on slave
> 20140909-224659-16842879-44263-21883-0 to framework
> 20140909-224659-16842879-44263-21883-0000
> I0909 22:46:59.387102 21900 log.cpp:699] Attempting to truncate the log to 3
> I0909 22:46:59.388634 21902 hierarchical_allocator_process.hpp:679] Performed
> allocation for slave 20140909-224659-16842879-44263-21883-0 in 399251ns
> I0909 22:46:59.388725 21903 coordinator.cpp:340] Coordinator attempting to
> write TRUNCATE action at position 4
> I0909 22:46:59.389214 21903 replica.cpp:508] Replica received write request
> for position 4
> I0909 22:46:59.388823 21897 master.hpp:861] Adding offer
> 20140909-224659-16842879-44263-21883-0 with resources cpus(*):2; mem(*):1024;
> disk(*):24988; ports(*):[31000-32000] on slave
> 20140909-224659-16842879-44263-21883-0 (trusty)
> I0909 22:46:59.389583 21897 master.cpp:3600] Sending 1 offers to framework
> 20140909-224659-16842879-44263-21883-0000
> I0909 22:46:59.389947 21897 sched.cpp:544] Scheduler::resourceOffers took
> 29958ns
> W0909 22:46:59.390466 21904 sched.cpp:916] Attempting to launch task 1 with
> an unknown offer 20140909-224659-16842879-44263-21883-0
> I0909 22:46:59.390777 21904 master.hpp:871] Removing offer
> 20140909-224659-16842879-44263-21883-0 with resources cpus(*):2; mem(*):1024;
> disk(*):24988; ports(*):[31000-32000] on slave
> 20140909-224659-16842879-44263-21883-0 (trusty)
> I0909 22:46:59.390964 21899 hierarchical_allocator_process.hpp:563] Recovered
> cpus(*):2; mem(*):1024; disk(*):24988; ports(*):[31000-32000] (total
> allocatable: cpus(*):2; mem(*):1024; disk(*):24988; ports(*):[31000-32000])
> on slave 20140909-224659-16842879-44263-21883-0 from framework
> 20140909-224659-16842879-44263-21883-0000
> W0909 22:46:59.391227 21904 master.cpp:2179] Launch tasks message used
> invalid offers '[ 20140909-224659-16842879-44263-21883-0,
> 20140909-224659-16842879-44263-21883-0 ]': Duplicate offer
> 20140909-224659-16842879-44263-21883-0 in offer list
> I0909 22:47:01.228384 21903 leveldb.cpp:343] Persisting action (16 bytes) to
> leveldb took 1.839011116secs
> I0909 22:47:01.228886 21903 replica.cpp:676] Persisted action at 4
> I0909 22:47:01.238937 21899 replica.cpp:655] Replica received learned notice
> for position 4
> I0909 22:47:01.228714 21897 hierarchical_allocator_process.hpp:734] Offering
> cpus(*):2; mem(*):1024; disk(*):24988; ports(*):[31000-32000] on slave
> 20140909-224659-16842879-44263-21883-0 to framework
> 20140909-224659-16842879-44263-21883-0000
> I0909 22:47:01.240223 21897 hierarchical_allocator_process.hpp:659] Performed
> allocation for 1 slaves in 11.633173ms
> I0909 22:47:01.240360 21904 master.cpp:3207] Sending status update TASK_LOST
> (UUID: 1208f3aa-abb6-4aef-97ff-0a0b6b23bccd) for task 1 of framework
> 20140909-224659-16842879-44263-21883-0000 'Task launched with invalid offers:
> Duplicate offer 20140909-224659-16842879-44263-21883-0 in offer list'
> I0909 22:47:01.240560 21904 master.hpp:861] Adding offer
> 20140909-224659-16842879-44263-21883-1 with resources cpus(*):2; mem(*):1024;
> disk(*):24988; ports(*):[31000-32000] on slave
> 20140909-224659-16842879-44263-21883-0 (trusty)
> I0909 22:47:01.240617 21904 master.cpp:3600] Sending 1 offers to framework
> 20140909-224659-16842879-44263-21883-0000
> I0909 22:47:01.240753 21904 sched.cpp:635] Scheduler::statusUpdate took
> 23007ns
> tests/master_tests.cpp:1355: Failure
> Mock function called more times than expected - returning directly.
> Function call: resourceOffers(0x7fff7e9fc280, @0x2acd5d5e6c90 { 128-byte
> object <10-AF 74-5A CD-2A 00-00 00-00 00-00 00-00 00-00 50-1F 12-7C CD-2A
> 00-00 10-BD 0E-7C CD-2A 00-00 70-A0 11-7C CD-2A 00-00 40-85 12-7C CD-2A 00-00
> 80-0E 12-7C CD-2A 00-00 04-00 00-00 04-00 00-00 04-00 00-00 CD-2A 00-00 00-00
> 00-00 00-00 00-00 00-00 00-00 00-00 00-00 00-00 00-00 32-38 37-39 00-00 00-00
> 00-00 00-00 00-00 00-00 00-00 00-00 00-00 00-00 00-00 00-00 00-00 00-00 0F-00
> 00-00> })
> Expected: to be called once
> Actual: called twice - over-saturated and active
> I0909 22:47:01.241080 21904 sched.cpp:544] Scheduler::resourceOffers took
> 259143ns
> I0909 22:47:01.241225 21883 master.cpp:650] Master terminating
> I0909 22:47:01.241266 21883 master.hpp:871] Removing offer
> 20140909-224659-16842879-44263-21883-1 with resources cpus(*):2; mem(*):1024;
> disk(*):24988; ports(*):[31000-32000] on slave
> 20140909-224659-16842879-44263-21883-0 (trusty)
> I0909 22:47:01.243752 21898 sched.cpp:745] Stopping framework
> '20140909-224659-16842879-44263-21883-0000'
> I0909 22:47:01.243821 21898 slave.cpp:2361] master@127.0.1.1:44263 exited
> W0909 22:47:01.243835 21898 slave.cpp:2364] Master disconnected! Waiting for
> a new master to be elected
> 2014-09-09
> 22:47:01,249:21883(0x2acd87a19700):ZOO_ERROR@handle_socket_error_msg@1697:
> Socket [127.0.0.1:58655] zk retcode=-4, errno=111(Connection refused): server
> refused to accept the client
> I0909 22:47:04.078968 21899 leveldb.cpp:343] Persisting action (18 bytes) to
> leveldb took 2.839904669secs
> I0909 22:47:04.079110 21899 leveldb.cpp:401] Deleting ~2 keys from leveldb
> took 71320ns
> I0909 22:47:04.079128 21899 replica.cpp:676] Persisted action at 4
> I0909 22:47:04.079139 21899 replica.cpp:661] Replica learned TRUNCATE action
> at position 4
> I0909 22:47:04.080659 21883 slave.cpp:475] Slave terminating
> [ FAILED ] MasterTest.LaunchDuplicateOfferTest (4890 ms)
> {noformat}
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
