ben is this expected? On Wed, Sep 24, 2014 at 1:34 PM, Apache Jenkins Server < jenk...@builds.apache.org> wrote:
> See < > https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/2123/changes > > > > Changes: > > [yujie.jay] Added support for getting socket diagnosis information. > > ------------------------------------------ > [...truncated 66610 lines...] > I0924 20:33:00.593726 832 leveldb.cpp:306] Persisting metadata (8 bytes) > to leveldb took 327703ns > I0924 20:33:00.593744 832 replica.cpp:342] Persisted promised to 1 > I0924 20:33:00.593941 832 coordinator.cpp:230] Coordinator attemping to > fill missing position > I0924 20:33:00.594296 832 replica.cpp:375] Replica received explicit > promise request for position 0 with proposal 2 > I0924 20:33:00.594422 832 leveldb.cpp:343] Persisting action (8 bytes) > to leveldb took 107194ns > I0924 20:33:00.594439 832 replica.cpp:676] Persisted action at 0 > I0924 20:33:00.594730 832 replica.cpp:508] Replica received write > request for position 0 > I0924 20:33:00.594758 832 leveldb.cpp:438] Reading position from leveldb > took 13083ns > I0924 20:33:00.594856 832 leveldb.cpp:343] Persisting action (14 bytes) > to leveldb took 77629ns > I0924 20:33:00.594872 832 replica.cpp:676] Persisted action at 0 > I0924 20:33:00.595029 832 replica.cpp:655] Replica received learned > notice for position 0 > I0924 20:33:00.595180 832 leveldb.cpp:343] Persisting action (16 bytes) > to leveldb took 134269ns > I0924 20:33:00.595196 832 replica.cpp:676] Persisted action at 0 > I0924 20:33:00.595204 832 replica.cpp:661] Replica learned NOP action at > position 0 > I0924 20:33:00.595366 832 log.cpp:672] Writer started with ending > position 0 > I0924 20:33:00.595626 832 leveldb.cpp:438] Reading position from leveldb > took 9422ns > I0924 20:33:00.598917 830 registrar.cpp:346] Successfully fetched the > registry (0B) > I0924 20:33:00.598953 830 registrar.cpp:422] Attempting to update the > 'registry' > I0924 20:33:00.599956 833 network.hpp:424] ZooKeeper group memberships > changed > I0924 20:33:00.600060 833 group.cpp:659] Trying to get > '/znode/log_replicas/0000000000' in ZooKeeper > I0924 20:33:00.600378 834 group.cpp:717] Found non-sequence node > 'log_replicas' at '/znode' in ZooKeeper > I0924 20:33:00.600553 845 log.cpp:680] Attempting to append 137 bytes to > the log > I0924 20:33:00.600610 830 coordinator.cpp:340] Coordinator attempting to > write APPEND action at position 1 > I0924 20:33:00.600862 841 network.hpp:466] ZooKeeper group PIDs: { > log-replica(423)@67.195.81.190:60680 } > I0924 20:33:00.600909 831 replica.cpp:508] Replica received write > request for position 1 > I0924 20:33:00.601269 831 leveldb.cpp:343] Persisting action (156 bytes) > to leveldb took 337675ns > I0924 20:33:00.601289 831 replica.cpp:676] Persisted action at 1 > I0924 20:33:00.601471 831 replica.cpp:655] Replica received learned > notice for position 1 > I0924 20:33:00.601583 831 leveldb.cpp:343] Persisting action (158 bytes) > to leveldb took 92858ns > I0924 20:33:00.601599 831 replica.cpp:676] Persisted action at 1 > I0924 20:33:00.601610 831 replica.cpp:661] Replica learned APPEND action > at position 1 > I0924 20:33:00.601862 842 registrar.cpp:479] Successfully updated > 'registry' > I0924 20:33:00.601912 842 registrar.cpp:372] Successfully recovered > registrar > I0924 20:33:00.601965 841 log.cpp:699] Attempting to truncate the log to > 1 > I0924 20:33:00.602013 841 coordinator.cpp:340] Coordinator attempting to > write TRUNCATE action at position 2 > I0924 20:33:00.602012 831 master.cpp:1070] Recovered 0 slaves from the > Registry (99B) ; allowing 10mins for slaves to re-register > I0924 20:33:00.602293 836 replica.cpp:508] Replica received write > request for position 2 > I0924 20:33:00.602401 836 leveldb.cpp:343] Persisting action (16 bytes) > to leveldb took 88110ns > I0924 20:33:00.602419 836 replica.cpp:676] Persisted action at 2 > I0924 20:33:00.602726 843 replica.cpp:655] Replica received learned > notice for position 2 > I0924 20:33:00.602864 843 leveldb.cpp:343] Persisting action (18 bytes) > to leveldb took 116799ns > I0924 20:33:00.602893 843 leveldb.cpp:401] Deleting ~1 keys from leveldb > took 13705ns > I0924 20:33:00.602907 843 replica.cpp:676] Persisted action at 2 > I0924 20:33:00.602918 843 replica.cpp:661] Replica learned TRUNCATE > action at position 2 > 2014-09-24 20:33:00,615:816(0x2ba5e6355700):ZOO_INFO@log_env@712: Client > environment:zookeeper.version=zookeeper C client 3.4.5 > 2014-09-24 20:33:00,615:816(0x2ba5e6355700):ZOO_INFO@log_env@716: Client > environment:host.name=pietas.apache.org > 2014-09-24 20:33:00,615:816(0x2ba5e6355700):ZOO_INFO@log_env@723: Client > environment:os.name=Linux > 2014-09-24 20:33:00,615:816(0x2ba5e6355700):ZOO_INFO@log_env@724: Client > environment:os.arch=3.13.0-24-generic > 2014-09-24 20:33:00,615:816(0x2ba5e6355700):ZOO_INFO@log_env@725: Client > environment:os.version=#47-Ubuntu SMP Fri May 2 23:30:00 UTC 2014 > 2014-09-24 20:33:00,615:816(0x2ba5e6355700):ZOO_INFO@log_env@733: Client > environment:user.name=(null) > 2014-09-24 20:33:00,615:816(0x2ba5e6355700):ZOO_INFO@log_env@741: Client > environment:user.home=/home/jenkins > 2014-09-24 20:33:00,615:816(0x2ba5e6355700):ZOO_INFO@log_env@753: Client > environment:user.dir=/tmp/RegistrarZooKeeperTest_TaskRunning_WlkuVu > 2014-09-24 20:33:00,615:816(0x2ba5e6355700):ZOO_INFO@zookeeper_init@786: > Initiating client connection, host=127.0.0.1:49812 sessionTimeout=10000 > watcher=0x2ba5e1fc8220 sessionId=0 sessionPasswd=<null> > context=0x2ba6300815b0 flags=0 > I0924 20:33:00.616447 842 slave.cpp:169] Slave started on 212)@ > 67.195.81.190:60680 > I0924 20:33:00.616479 842 credentials.hpp:84] Loading credential for > authentication from > '/tmp/RegistrarZooKeeperTest_TaskRunning_goEyvG/credential' > 2014-09-24 20:33:00,616:816(0x2ba966adb700):ZOO_INFO@check_events@1703: > initiated connection to server [127.0.0.1:49812] > I0924 20:33:00.616574 842 slave.cpp:276] Slave using credential for: > test-principal > I0924 20:33:00.619999 816 sched.cpp:137] Version: 0.21.0 > I0924 20:33:00.620539 842 slave.cpp:289] Slave resources: cpus(*):2; > mem(*):1024; disk(*):1024; ports(*):[31000-32000] > I0924 20:33:00.620580 838 sched.cpp:233] New master detected at > master@67.195.81.190:60680 > I0924 20:33:00.620609 838 sched.cpp:283] Authenticating with master > master@67.195.81.190:60680 > I0924 20:33:00.620618 842 slave.cpp:317] Slave hostname: > pietas.apache.org > I0924 20:33:00.620633 842 slave.cpp:318] Slave checkpoint: false > I0924 20:33:00.620713 838 authenticatee.hpp:128] Creating new client > SASL connection > I0924 20:33:00.620831 838 master.cpp:3661] Authenticating > scheduler-f00cbbab-8d81-4de7-b29d-85142325f060@67.195.81.190:60680 > I0924 20:33:00.621031 838 authenticator.hpp:156] Creating new server > SASL connection > I0924 20:33:00.621109 838 state.cpp:33] Recovering state from > '/tmp/RegistrarZooKeeperTest_TaskRunning_goEyvG/meta' > I0924 20:33:00.621219 833 authenticatee.hpp:219] Received SASL > authentication mechanisms: CRAM-MD5 > I0924 20:33:00.621247 833 authenticatee.hpp:245] Attempting to > authenticate with mechanism 'CRAM-MD5' > I0924 20:33:00.621248 838 status_update_manager.cpp:193] Recovering > status update manager > I0924 20:33:00.621285 833 authenticator.hpp:262] Received SASL > authentication start > I0924 20:33:00.621327 833 authenticator.hpp:384] Authentication requires > more steps > I0924 20:33:00.621350 838 slave.cpp:3220] Finished recovery > I0924 20:33:00.621361 833 authenticatee.hpp:265] Received SASL > authentication step > I0924 20:33:00.621408 833 authenticator.hpp:290] Received SASL > authentication step > I0924 20:33:00.621430 833 auxprop.cpp:81] Request to lookup properties > for user: 'test-principal' realm: 'pietas.apache.org' server FQDN: ' > pietas.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false > SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false > I0924 20:33:00.621443 833 auxprop.cpp:153] Looking up auxiliary property > '*userPassword' > I0924 20:33:00.621458 833 auxprop.cpp:153] Looking up auxiliary property > '*cmusaslsecretCRAM-MD5' > I0924 20:33:00.621471 833 auxprop.cpp:81] Request to lookup properties > for user: 'test-principal' realm: 'pietas.apache.org' server FQDN: ' > pietas.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false > SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true > I0924 20:33:00.621482 833 auxprop.cpp:103] Skipping auxiliary property > '*userPassword' since SASL_AUXPROP_AUTHZID == true > I0924 20:33:00.621491 833 auxprop.cpp:103] Skipping auxiliary property > '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true > I0924 20:33:00.621508 833 authenticator.hpp:376] Authentication success > I0924 20:33:00.621544 833 authenticatee.hpp:305] Authentication success > I0924 20:33:00.621559 838 master.cpp:3701] Successfully authenticated > principal 'test-principal' at > scheduler-f00cbbab-8d81-4de7-b29d-85142325f060@67.195.81.190:60680 > I0924 20:33:00.621738 833 sched.cpp:357] Successfully authenticated with > master master@67.195.81.190:60680 > I0924 20:33:00.621757 833 sched.cpp:476] Sending registration request to > master@67.195.81.190:60680 > I0924 20:33:00.621815 833 master.cpp:1331] Received registration request > from scheduler-f00cbbab-8d81-4de7-b29d-85142325f060@67.195.81.190:60680 > I0924 20:33:00.621840 833 master.cpp:1291] Authorizing framework > principal 'test-principal' to receive offers for role '*' > I0924 20:33:00.621961 833 master.cpp:1390] Registering framework > 20140924-203300-3193029443-60680-816-0000 at > scheduler-f00cbbab-8d81-4de7-b29d-85142325f060@67.195.81.190:60680 > I0924 20:33:00.622068 833 sched.cpp:407] Framework registered with > 20140924-203300-3193029443-60680-816-0000 > I0924 20:33:00.622095 833 sched.cpp:421] Scheduler::registered took > 10483ns > I0924 20:33:00.622139 833 hierarchical_allocator_process.hpp:329] Added > framework 20140924-203300-3193029443-60680-816-0000 > I0924 20:33:00.622153 833 hierarchical_allocator_process.hpp:697] No > resources available to allocate! > I0924 20:33:00.622161 833 hierarchical_allocator_process.hpp:659] > Performed allocation for 0 slaves in 10066ns > 2014-09-24 20:33:00,622:816(0x2ba966adb700):ZOO_INFO@check_events@1750: > session establishment complete on server [127.0.0.1:49812], > sessionId=0x148a95df6510004, negotiated timeout=10000 > I0924 20:33:00.623364 833 group.cpp:313] Group process (group(58)@ > 67.195.81.190:60680) connected to ZooKeeper > I0924 20:33:00.623385 833 group.cpp:790] Syncing group operations: queue > size (joins, cancels, datas) = (0, 0, 0) > I0924 20:33:00.623397 833 group.cpp:385] Trying to create path '/znode' > in ZooKeeper > I0924 20:33:00.624841 833 group.cpp:717] Found non-sequence node > 'log_replicas' at '/znode' in ZooKeeper > I0924 20:33:00.624920 837 detector.cpp:138] Detected a new leader: > (id='0') > I0924 20:33:00.625027 837 group.cpp:659] Trying to get > '/znode/info_0000000000' in ZooKeeper > I0924 20:33:00.625854 842 detector.cpp:433] A new leading master (UPID= > master@67.195.81.190:60680) is detected > I0924 20:33:00.625921 842 slave.cpp:600] New master detected at > master@67.195.81.190:60680 > I0924 20:33:00.625952 842 slave.cpp:674] Authenticating with master > master@67.195.81.190:60680 > I0924 20:33:00.625982 838 status_update_manager.cpp:167] New master > detected at master@67.195.81.190:60680 > I0924 20:33:00.625999 842 slave.cpp:647] Detecting new master > I0924 20:33:00.626024 838 authenticatee.hpp:128] Creating new client > SASL connection > I0924 20:33:00.626104 842 master.cpp:3661] Authenticating slave(212)@ > 67.195.81.190:60680 > I0924 20:33:00.626180 838 authenticator.hpp:156] Creating new server > SASL connection > I0924 20:33:00.626247 842 authenticatee.hpp:219] Received SASL > authentication mechanisms: CRAM-MD5 > I0924 20:33:00.626268 842 authenticatee.hpp:245] Attempting to > authenticate with mechanism 'CRAM-MD5' > I0924 20:33:00.626305 842 authenticator.hpp:262] Received SASL > authentication start > I0924 20:33:00.626348 842 authenticator.hpp:384] Authentication requires > more steps > I0924 20:33:00.626387 842 authenticatee.hpp:265] Received SASL > authentication step > I0924 20:33:00.626430 842 authenticator.hpp:290] Received SASL > authentication step > I0924 20:33:00.626449 842 auxprop.cpp:81] Request to lookup properties > for user: 'test-principal' realm: 'pietas.apache.org' server FQDN: ' > pietas.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false > SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false > I0924 20:33:00.626461 842 auxprop.cpp:153] Looking up auxiliary property > '*userPassword' > I0924 20:33:00.626474 842 auxprop.cpp:153] Looking up auxiliary property > '*cmusaslsecretCRAM-MD5' > I0924 20:33:00.626487 842 auxprop.cpp:81] Request to lookup properties > for user: 'test-principal' realm: 'pietas.apache.org' server FQDN: ' > pietas.apache.org' SASL_AUXPROP_VERIFY_AGAINST_HASH: false > SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true > I0924 20:33:00.626498 842 auxprop.cpp:103] Skipping auxiliary property > '*userPassword' since SASL_AUXPROP_AUTHZID == true > I0924 20:33:00.626507 842 auxprop.cpp:103] Skipping auxiliary property > '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true > I0924 20:33:00.626523 842 authenticator.hpp:376] Authentication success > I0924 20:33:00.626564 842 authenticatee.hpp:305] Authentication success > I0924 20:33:00.626585 838 master.cpp:3701] Successfully authenticated > principal 'test-principal' at slave(212)@67.195.81.190:60680 > I0924 20:33:00.626613 842 slave.cpp:731] Successfully authenticated with > master master@67.195.81.190:60680 > I0924 20:33:00.626673 842 slave.cpp:994] Will retry registration in > 19.168762ms if necessary > I0924 20:33:00.626729 838 master.cpp:2865] Registering slave at > slave(212)@67.195.81.190:60680 (pietas.apache.org) with id > 20140924-203300-3193029443-60680-816-0 > I0924 20:33:00.626848 842 registrar.cpp:422] Attempting to update the > 'registry' > I0924 20:33:00.628783 845 log.cpp:680] Attempting to append 330 bytes to > the log > I0924 20:33:00.628842 842 coordinator.cpp:340] Coordinator attempting to > write APPEND action at position 3 > I0924 20:33:00.629164 833 replica.cpp:508] Replica received write > request for position 3 > I0924 20:33:00.629333 833 leveldb.cpp:343] Persisting action (349 bytes) > to leveldb took 146163ns > I0924 20:33:00.629350 833 replica.cpp:676] Persisted action at 3 > I0924 20:33:00.629566 833 replica.cpp:655] Replica received learned > notice for position 3 > I0924 20:33:00.629952 833 leveldb.cpp:343] Persisting action (351 bytes) > to leveldb took 368520ns > I0924 20:33:00.629971 833 replica.cpp:676] Persisted action at 3 > I0924 20:33:00.629981 833 replica.cpp:661] Replica learned APPEND action > at position 3 > I0924 20:33:00.630314 833 registrar.cpp:479] Successfully updated > 'registry' > I0924 20:33:00.630394 833 log.cpp:699] Attempting to truncate the log to > 3 > I0924 20:33:00.630451 833 master.cpp:2905] Registered slave > 20140924-203300-3193029443-60680-816-0 at slave(212)@67.195.81.190:60680 ( > pietas.apache.org) > I0924 20:33:00.630467 833 master.cpp:4116] Adding slave > 20140924-203300-3193029443-60680-816-0 at slave(212)@67.195.81.190:60680 ( > pietas.apache.org) with cpus(*):2; mem(*):1024; disk(*):1024; > ports(*):[31000-32000] > I0924 20:33:00.630576 833 coordinator.cpp:340] Coordinator attempting to > write TRUNCATE action at position 4 > I0924 20:33:00.630658 833 slave.cpp:765] Registered with master > master@67.195.81.190:60680; given slave ID > 20140924-203300-3193029443-60680-816-0 > I0924 20:33:00.630740 833 hierarchical_allocator_process.hpp:442] Added > slave 20140924-203300-3193029443-60680-816-0 (pietas.apache.org) with > cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] (and > cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] available) > I0924 20:33:00.630806 833 hierarchical_allocator_process.hpp:734] > Offering cpus(*):2; mem(*):1024; disk(*):1024; ports(*):[31000-32000] on > slave 20140924-203300-3193029443-60680-816-0 to framework > 20140924-203300-3193029443-60680-816-0000 > I0924 20:33:00.630911 833 hierarchical_allocator_process.hpp:679] > Performed allocation for slave 20140924-203300-3193029443-60680-816-0 in > 133866ns > I0924 20:33:00.630965 833 slave.cpp:2347] Received ping from > slave-observer(192)@67.195.81.190:60680 > I0924 20:33:00.631018 833 master.hpp:867] Adding offer > 20140924-203300-3193029443-60680-816-0 with resources cpus(*):2; > mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave > 20140924-203300-3193029443-60680-816-0 (pietas.apache.org) > I0924 20:33:00.631067 833 master.cpp:3608] Sending 1 offers to framework > 20140924-203300-3193029443-60680-816-0000 > I0924 20:33:00.631202 833 sched.cpp:544] Scheduler::resourceOffers took > 19690ns > I0924 20:33:00.631383 833 replica.cpp:508] Replica received write > request for position 4 > I0924 20:33:00.631510 833 leveldb.cpp:343] Persisting action (16 bytes) > to leveldb took 107618ns > I0924 20:33:00.631527 833 replica.cpp:676] Persisted action at 4 > I0924 20:33:00.631710 833 replica.cpp:655] Replica received learned > notice for position 4 > I0924 20:33:00.631821 833 leveldb.cpp:343] Persisting action (18 bytes) > to leveldb took 95708ns > I0924 20:33:00.631855 833 leveldb.cpp:401] Deleting ~2 keys from leveldb > took 16107ns > I0924 20:33:00.631866 833 replica.cpp:676] Persisted action at 4 > I0924 20:33:00.631876 833 replica.cpp:661] Replica learned TRUNCATE > action at position 4 > I0924 20:33:00.633397 832 master.hpp:876] Removing offer > 20140924-203300-3193029443-60680-816-0 with resources cpus(*):2; > mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave > 20140924-203300-3193029443-60680-816-0 (pietas.apache.org) > I0924 20:33:00.633450 832 master.cpp:2218] Processing reply for offers: > [ 20140924-203300-3193029443-60680-816-0 ] on slave > 20140924-203300-3193029443-60680-816-0 at slave(212)@67.195.81.190:60680 ( > pietas.apache.org) for framework 20140924-203300-3193029443-60680-816-0000 > W0924 20:33:00.633496 832 master.cpp:1888] Executor default for task > 0a6942ee-8509-4fd8-9cea-e5d59c1d2ecc uses less CPUs (None) than the minimum > required (0.01). Please update your executor, as this will be mandatory in > future releases. > W0924 20:33:00.633518 832 master.cpp:1899] Executor default for task > 0a6942ee-8509-4fd8-9cea-e5d59c1d2ecc uses less memory (None) than the > minimum required (32MB). Please update your executor, as this will be > mandatory in future releases. > I0924 20:33:00.633535 832 master.cpp:2301] Authorizing framework > principal 'test-principal' to launch task > 0a6942ee-8509-4fd8-9cea-e5d59c1d2ecc as user 'jenkins' > I0924 20:33:00.633889 833 master.hpp:844] Adding task > 0a6942ee-8509-4fd8-9cea-e5d59c1d2ecc with resources cpus(*):2; mem(*):1024; > disk(*):1024; ports(*):[31000-32000] on slave > 20140924-203300-3193029443-60680-816-0 (pietas.apache.org) > I0924 20:33:00.633936 833 master.cpp:2366] Launching task > 0a6942ee-8509-4fd8-9cea-e5d59c1d2ecc of framework > 20140924-203300-3193029443-60680-816-0000 with resources cpus(*):2; > mem(*):1024; disk(*):1024; ports(*):[31000-32000] on slave > 20140924-203300-3193029443-60680-816-0 at slave(212)@67.195.81.190:60680 ( > pietas.apache.org) > I0924 20:33:00.634052 830 slave.cpp:1025] Got assigned task > 0a6942ee-8509-4fd8-9cea-e5d59c1d2ecc for framework > 20140924-203300-3193029443-60680-816-0000 > I0924 20:33:00.634263 830 slave.cpp:1135] Launching task > 0a6942ee-8509-4fd8-9cea-e5d59c1d2ecc for framework > 20140924-203300-3193029443-60680-816-0000 > I0924 20:33:00.638197 830 exec.cpp:132] Version: 0.21.0 > I0924 20:33:00.638267 838 exec.cpp:182] Executor started at: > executor(69)@67.195.81.190:60680 with pid 816 > I0924 20:33:00.638311 830 slave.cpp:1248] Queuing task > '0a6942ee-8509-4fd8-9cea-e5d59c1d2ecc' for executor default of framework > '20140924-203300-3193029443-60680-816-0000 > I0924 20:33:00.638355 830 slave.cpp:554] Successfully attached file > '/tmp/RegistrarZooKeeperTest_TaskRunning_goEyvG/slaves/20140924-203300-3193029443-60680-816-0/frameworks/20140924-203300-3193029443-60680-816-0000/executors/default/runs/445855aa-a345-4e09-a948-7a236bd63073' > I0924 20:33:00.638394 830 slave.cpp:2560] Monitoring executor 'default' > of framework '20140924-203300-3193029443-60680-816-0000' in container > '445855aa-a345-4e09-a948-7a236bd63073' > I0924 20:33:00.638520 830 slave.cpp:1758] Got registration for executor > 'default' of framework 20140924-203300-3193029443-60680-816-0000 from > executor(69)@67.195.81.190:60680 > I0924 20:33:00.638644 830 slave.cpp:1877] Flushing queued task > 0a6942ee-8509-4fd8-9cea-e5d59c1d2ecc for executor 'default' of framework > 20140924-203300-3193029443-60680-816-0000 > I0924 20:33:00.638682 839 exec.cpp:206] Executor registered on slave > 20140924-203300-3193029443-60680-816-0 > I0924 20:33:00.640259 839 exec.cpp:218] Executor::registered took 13780ns > I0924 20:33:00.640336 839 exec.cpp:293] Executor asked to run task > '0a6942ee-8509-4fd8-9cea-e5d59c1d2ecc' > I0924 20:33:00.640374 839 exec.cpp:302] Executor::launchTask took 22430ns > I0924 20:33:00.642021 839 exec.cpp:525] Executor sending status update > TASK_RUNNING (UUID: 68ce3db0-1f2f-46e3-82f5-5e43af24e42f) for task > 0a6942ee-8509-4fd8-9cea-e5d59c1d2ecc of framework > 20140924-203300-3193029443-60680-816-0000 > I0924 20:33:00.642138 839 slave.cpp:2111] Handling status update > TASK_RUNNING (UUID: 68ce3db0-1f2f-46e3-82f5-5e43af24e42f) for task > 0a6942ee-8509-4fd8-9cea-e5d59c1d2ecc of framework > 20140924-203300-3193029443-60680-816-0000 from executor(69)@ > 67.195.81.190:60680 > I0924 20:33:00.642233 841 status_update_manager.cpp:320] Received status > update TASK_RUNNING (UUID: 68ce3db0-1f2f-46e3-82f5-5e43af24e42f) for task > 0a6942ee-8509-4fd8-9cea-e5d59c1d2ecc of framework > 20140924-203300-3193029443-60680-816-0000 > I0924 20:33:00.642253 841 status_update_manager.cpp:499] Creating > StatusUpdate stream for task 0a6942ee-8509-4fd8-9cea-e5d59c1d2ecc of > framework 20140924-203300-3193029443-60680-816-0000 > I0924 20:33:00.642328 841 status_update_manager.cpp:373] Forwarding > status update TASK_RUNNING (UUID: 68ce3db0-1f2f-46e3-82f5-5e43af24e42f) for > task 0a6942ee-8509-4fd8-9cea-e5d59c1d2ecc of framework > 20140924-203300-3193029443-60680-816-0000 to master@67.195.81.190:60680 > I0924 20:33:00.642442 839 master.cpp:3231] Forwarding status update > TASK_RUNNING (UUID: 68ce3db0-1f2f-46e3-82f5-5e43af24e42f) for task > 0a6942ee-8509-4fd8-9cea-e5d59c1d2ecc of framework > 20140924-203300-3193029443-60680-816-0000 > I0924 20:33:00.642447 840 slave.cpp:2268] Status update manager > successfully handled status update TASK_RUNNING (UUID: > 68ce3db0-1f2f-46e3-82f5-5e43af24e42f) for task > 0a6942ee-8509-4fd8-9cea-e5d59c1d2ecc of framework > 20140924-203300-3193029443-60680-816-0000 > I0924 20:33:00.642465 840 slave.cpp:2274] Sending acknowledgement for > status update TASK_RUNNING (UUID: 68ce3db0-1f2f-46e3-82f5-5e43af24e42f) for > task 0a6942ee-8509-4fd8-9cea-e5d59c1d2ecc of framework > 20140924-203300-3193029443-60680-816-0000 to executor(69)@ > 67.195.81.190:60680 > I0924 20:33:00.642503 839 master.cpp:3203] Status update TASK_RUNNING > (UUID: 68ce3db0-1f2f-46e3-82f5-5e43af24e42f) for task > 0a6942ee-8509-4fd8-9cea-e5d59c1d2ecc of framework > 20140924-203300-3193029443-60680-816-0000 from slave > 20140924-203300-3193029443-60680-816-0 at slave(212)@67.195.81.190:60680 ( > pietas.apache.org) > I0924 20:33:00.642544 838 exec.cpp:339] Executor received status update > acknowledgement 68ce3db0-1f2f-46e3-82f5-5e43af24e42f for task > 0a6942ee-8509-4fd8-9cea-e5d59c1d2ecc of framework > 20140924-203300-3193029443-60680-816-0000 > I0924 20:33:00.642575 837 sched.cpp:635] Scheduler::statusUpdate took > 23973ns > I0924 20:33:00.642640 837 master.cpp:2715] Forwarding status update > acknowledgement 68ce3db0-1f2f-46e3-82f5-5e43af24e42f for task > 0a6942ee-8509-4fd8-9cea-e5d59c1d2ecc of framework > 20140924-203300-3193029443-60680-816-0000 to slave > 20140924-203300-3193029443-60680-816-0 at slave(212)@67.195.81.190:60680 ( > pietas.apache.org) > I0924 20:33:00.642787 832 status_update_manager.cpp:398] Received status > update acknowledgement (UUID: 68ce3db0-1f2f-46e3-82f5-5e43af24e42f) for > task 0a6942ee-8509-4fd8-9cea-e5d59c1d2ecc of framework > 20140924-203300-3193029443-60680-816-0000 > I0924 20:33:00.642842 832 slave.cpp:1698] Status update manager > successfully handled status update acknowledgement (UUID: > 68ce3db0-1f2f-46e3-82f5-5e43af24e42f) for task > 0a6942ee-8509-4fd8-9cea-e5d59c1d2ecc of framework > 20140924-203300-3193029443-60680-816-0000 > I0924 20:33:00.642961 816 master.cpp:650] Master terminating > W0924 20:33:00.642983 816 master.cpp:4407] Removing task > 0a6942ee-8509-4fd8-9cea-e5d59c1d2ecc with resources cpus(*):2; mem(*):1024; > disk(*):1024; ports(*):[31000-32000] of framework > 20140924-203300-3193029443-60680-816-0000 on slave > 20140924-203300-3193029443-60680-816-0 at slave(212)@67.195.81.190:60680 ( > pietas.apache.org) in non-terminal state TASK_RUNNING > I0924 20:33:00.643085 816 master.cpp:4450] Removing executor 'default' > with resources of framework 20140924-203300-3193029443-60680-816-0000 on > slave 20140924-203300-3193029443-60680-816-0 at slave(212)@ > 67.195.81.190:60680 (pietas.apache.org) > I0924 20:33:00.643787 840 sched.cpp:745] Stopping framework > '20140924-203300-3193029443-60680-816-0000' > I0924 20:33:00.643910 840 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 20140924-203300-3193029443-60680-816-0 > from framework 20140924-203300-3193029443-60680-816-0000 > I0924 20:33:00.643961 840 slave.cpp:2379] master@67.195.81.190:60680 > exited > W0924 20:33:00.643975 840 slave.cpp:2382] Master disconnected! Waiting > for a new master to be elected > 2014-09-24 20:33:00,644:816(0x2ba5e14abf80):ZOO_INFO@zookeeper_close@2505: > Closing zookeeper sessionId=0x148a95df6510002 to [127.0.0.1:49812] > > I0924 20:33:00.648608 842 contender.cpp:186] Now cancelling the > membership: 0 > I0924 20:33:00.648691 831 group.cpp:619] Trying to remove > '/znode/info_0000000000' in ZooKeeper > 2014-09-24 20:33:00,653:816(0x2ba5e5d52700):ZOO_INFO@zookeeper_close@2505: > Closing zookeeper sessionId=0x148a95df6510001 to [127.0.0.1:49812] > > 2014-09-24 20:33:00,654:816(0x2ba5e6154700):ZOO_INFO@zookeeper_close@2505: > Closing zookeeper sessionId=0x148a95df6510003 to [127.0.0.1:49812] > > I0924 20:33:00.654940 845 group.cpp:717] Found non-sequence node > 'log_replicas' at '/znode' in ZooKeeper > I0924 20:33:00.655000 845 detector.cpp:126] The current leader (id=0) is > lost > I0924 20:33:00.655014 845 detector.cpp:138] Detected a new leader: None > I0924 20:33:00.655122 845 slave.cpp:593] Lost leading master > I0924 20:33:00.655138 845 slave.cpp:647] Detecting new master > 2014-09-24 20:33:00,656:816(0x2ba5e14abf80):ZOO_INFO@zookeeper_close@2505: > Closing zookeeper sessionId=0x148a95df6510000 to [127.0.0.1:49812] > > I0924 20:33:00.659768 834 slave.cpp:2618] Executor 'default' of > framework 20140924-203300-3193029443-60680-816-0000 exited with status 0 > I0924 20:33:00.661319 834 slave.cpp:2111] Handling status update > TASK_LOST (UUID: ad6a4fb9-17e0-4c09-a74c-ae5b66590341) for task > 0a6942ee-8509-4fd8-9cea-e5d59c1d2ecc of framework > 20140924-203300-3193029443-60680-816-0000 from @0.0.0.0:0 > I0924 20:33:00.661351 834 slave.cpp:3938] Terminating task > 0a6942ee-8509-4fd8-9cea-e5d59c1d2ecc > I0924 20:33:00.661470 834 slave.cpp:477] Slave terminating > I0924 20:33:00.661491 834 slave.cpp:1431] Asked to shut down framework > 20140924-203300-3193029443-60680-816-0000 by @0.0.0.0:0 > W0924 20:33:00.661504 834 slave.cpp:1439] Ignoring shutdown framework > message for 20140924-203300-3193029443-60680-816-0000 because the slave has > not yet registered with the master > 2014-09-24 20:33:00,664:816(0x2ba5e14abf80):ZOO_INFO@zookeeper_close@2505: > Closing zookeeper sessionId=0x148a95df6510004 to [127.0.0.1:49812] > > [ OK ] RegistrarZooKeeperTest.TaskRunning (148 ms) > I0924 20:33:00.665292 816 zookeeper_test_server.cpp:118] Shutting down > ZooKeeperTestServer on port 49812 > [----------] 1 test from RegistrarZooKeeperTest (148 ms total) > > [----------] 1 test from HTTP > [ RUN ] HTTP.ModelTask > [ OK ] HTTP.ModelTask (0 ms) > [----------] 1 test from HTTP (0 ms total) > > [----------] Global test environment tear-down > [==========] 411 tests from 66 test cases ran. (455394 ms total) > [ PASSED ] 411 tests. > > YOU HAVE 6 DISABLED TESTS > > make[3]: Leaving directory `< > https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/ws/src > '> > make[2]: Leaving directory `< > https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/ws/src > '> > make[1]: Leaving directory `< > https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/ws/src > '> > Making check in ec2 > make[1]: Entering directory `< > https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/ws/ec2 > '> > make[1]: Nothing to be done for `check'. > make[1]: Leaving directory `< > https://builds.apache.org/job/Mesos-Trunk-Ubuntu-Build-In-Src-Set-JAVA_HOME/ws/ec2 > '> > Test finished > Exit status: 0 > Recording test results > No test report files were found. Configuration error? > Build step 'Publish JUnit test result report' changed build result to > FAILURE >
