See <https://builds.apache.org/job/Mesos-Buildbot/BUILDTOOL=cmake,COMPILER=clang,CONFIGURATION=--verbose%20--disable-libtool-wrappers,ENVIRONMENT=GLOG_v=1%20MESOS_VERBOSE=1,OS=ubuntu%3A14.04,label_exp=(ubuntu)&&(!ubuntu-us1)&&(!ubuntu-eu2)&&(!qnode3)&&(!H23)/4469/display/redirect?page=changes>
Changes: [xujyan] Downgraded the logging level of socket shutdown failures. ------------------------------------------ [...truncated 3.64 MB...] 3: [ OK ] FetcherTest.UseCustomOutputFile (201 ms) 3: [ RUN ] FetcherTest.CustomGzipOutputFile 3: I1117 20:02:30.275444 15995 fetcher.cpp:379] Starting to fetch URIs for container: 160a17ed-b7cb-4d1f-a378-47a27c88f5a4, directory: /tmp/Yq2VNI 3: I1117 20:02:30.276403 15995 fetcher.cpp:876] Fetching URIs using command '/mesos/build/src/mesos-fetcher' 3: I1117 20:02:30.564442 16000 process.cpp:3932] Handling HTTP event for process 'metrics' with path: '/metrics/snapshot' 3: [ OK ] FetcherTest.CustomGzipOutputFile (302 ms) 3: [ RUN ] FetcherTest.HdfsURI 3: I1117 20:02:30.572510 15998 fetcher.cpp:379] Starting to fetch URIs for container: d1ff9570-1fa0-4ac8-afd4-5ceb5d253a8a, directory: /tmp/dN1pWW 3: I1117 20:02:30.573261 15998 fetcher.cpp:876] Fetching URIs using command '/mesos/build/src/mesos-fetcher' 3: I1117 20:02:30.866634 16003 process.cpp:3932] Handling HTTP event for process 'metrics' with path: '/metrics/snapshot' 3: [ OK ] FetcherTest.HdfsURI (302 ms) 3: [ RUN ] FetcherTest.SSLEnvironmentSpillover 3: I1117 20:02:30.879721 16001 fetcher.cpp:379] Starting to fetch URIs for container: ca2a3a40-6974-4a7e-9c74-92f1ef551a80, directory: /tmp/orsvR2 3: I1117 20:02:30.880458 16001 fetcher.cpp:876] Fetching URIs using command '/mesos/build/src/mesos-fetcher' 3: [ OK ] FetcherTest.SSLEnvironmentSpillover (296 ms) 3: [----------] 23 tests from FetcherTest (5127 ms total) 3: 3: [----------] 8 tests from FilesTest 3: [ RUN ] FilesTest.AttachTest 3: [ OK ] FilesTest.AttachTest (2 ms) 3: [ RUN ] FilesTest.DetachTest 3: [ OK ] FilesTest.DetachTest (1 ms) 3: [ RUN ] FilesTest.ReadTest 3: I1117 20:02:31.174196 16002 process.cpp:3932] Handling HTTP event for process 'files' with path: '/files/read' 3: I1117 20:02:31.175022 15996 http.cpp:1185] HTTP GET for /files/read from 172.17.0.6:40206 3: I1117 20:02:31.177660 16001 process.cpp:3932] Handling HTTP event for process 'files' with path: '/files/read' 3: I1117 20:02:31.178356 16007 http.cpp:1185] HTTP GET for /files/read?path=none&offset=hello from 172.17.0.6:40208 3: I1117 20:02:31.181248 15998 process.cpp:3932] Handling HTTP event for process 'files' with path: '/files/read' 3: I1117 20:02:31.181927 16001 http.cpp:1185] HTTP GET for /files/read?path=none&length=hello from 172.17.0.6:40210 3: I1117 20:02:31.184830 16007 process.cpp:3932] Handling HTTP event for process 'files' with path: '/files/read' 3: I1117 20:02:31.185396 15992 http.cpp:1185] HTTP GET for /files/read?path=%2Fmyname&offset=0 from 172.17.0.6:40212 3: I1117 20:02:31.189610 15999 process.cpp:3932] Handling HTTP event for process 'files' with path: '/files/read' 3: I1117 20:02:31.190179 16007 http.cpp:1185] HTTP GET for /files/read?path=myname&offset=0 from 172.17.0.6:40214 3: I1117 20:02:31.193135 15996 process.cpp:3932] Handling HTTP event for process 'files' with path: '/files/read' 3: I1117 20:02:31.193684 15993 http.cpp:1185] HTTP GET for /files/read?path=authorized&offset=0 from 172.17.0.6:40216 3: I1117 20:02:31.196332 16010 process.cpp:3932] Handling HTTP event for process 'files' with path: '/files/read' 3: I1117 20:02:31.196902 15996 http.cpp:1185] HTTP GET for /files/read?path=authorized&offset=0 from 172.17.0.6:40218 3: I1117 20:02:31.199270 15991 process.cpp:3932] Handling HTTP event for process 'files' with path: '/files/read' 3: I1117 20:02:31.199800 16003 http.cpp:1185] HTTP GET for /files/read?path=%2Fmyname&length=-1&offset=0 from 172.17.0.6:40220 3: I1117 20:02:31.202656 16005 process.cpp:3932] Handling HTTP event for process 'files' with path: '/files/read' 3: I1117 20:02:31.203213 16012 http.cpp:1185] HTTP GET for /files/read?path=%2Fmyname&length=-2 from 172.17.0.6:40222 3: I1117 20:02:31.205633 16013 process.cpp:3932] Handling HTTP event for process 'files' with path: '/files/read' 3: I1117 20:02:31.206166 15997 http.cpp:1185] HTTP GET for /files/read?path=%2Fmyname&offset=0&length=2 from 172.17.0.6:40224 3: I1117 20:02:31.208870 16014 process.cpp:3932] Handling HTTP event for process 'files' with path: '/files/read' 3: I1117 20:02:31.209427 16004 http.cpp:1185] HTTP GET for /files/read?path=missing from 172.17.0.6:40226 3: [ OK ] FilesTest.ReadTest (39 ms) 3: [ RUN ] FilesTest.ResolveTest 3: I1117 20:02:31.213176 15996 process.cpp:3932] Handling HTTP event for process 'files' with path: '/files/read' 3: I1117 20:02:31.213765 16006 http.cpp:1185] HTTP GET for /files/read?path=one%2F2%2Fthree&offset=0 from 172.17.0.6:40228 3: I1117 20:02:31.216413 16001 process.cpp:3932] Handling HTTP event for process 'files' with path: '/files/read' 3: I1117 20:02:31.216948 15996 http.cpp:1185] HTTP GET for /files/read?path=%2Fone%2F2%2Fthree&offset=0 from 172.17.0.6:40230 3: I1117 20:02:31.219522 16010 process.cpp:3932] Handling HTTP event for process 'files' with path: '/files/read' 3: I1117 20:02:31.220058 16001 http.cpp:1185] HTTP GET for /files/read?path=two%2Fthree&offset=0 from 172.17.0.6:40232 3: I1117 20:02:31.222743 16000 process.cpp:3932] Handling HTTP event for process 'files' with path: '/files/read' 3: I1117 20:02:31.223343 16010 http.cpp:1185] HTTP GET for /files/read?path=one%2Ftwo%2Fthree&offset=0 from 172.17.0.6:40234 3: I1117 20:02:31.226059 15991 process.cpp:3932] Handling HTTP event for process 'files' with path: '/files/read' 3: I1117 20:02:31.226590 15998 http.cpp:1185] HTTP GET for /files/read?path=%2Fone%2F2%2Fthree&offset=0 from 172.17.0.6:40236 3: I1117 20:02:31.229166 15992 process.cpp:3932] Handling HTTP event for process 'files' with path: '/files/read' 3: I1117 20:02:31.229686 16005 http.cpp:1185] HTTP GET for /files/read?path=one%2Ftwo%2Fthree&offset=0 from 172.17.0.6:40238 3: I1117 20:02:31.232292 16008 process.cpp:3932] Handling HTTP event for process 'files' with path: '/files/read' 3: I1117 20:02:31.232841 15992 http.cpp:1185] HTTP GET for /files/read?path=one%2F2 from 172.17.0.6:40240 3: I1117 20:02:31.235319 16001 process.cpp:3932] Handling HTTP event for process 'files' with path: '/files/read' 3: I1117 20:02:31.235822 16014 http.cpp:1185] HTTP GET for /files/read?path=one from 172.17.0.6:40242 3: I1117 20:02:31.238158 15995 process.cpp:3932] Handling HTTP event for process 'files' with path: '/files/read' 3: I1117 20:02:31.238801 15994 http.cpp:1185] HTTP GET for /files/read?path=one%2F from 172.17.0.6:40244 3: I1117 20:02:31.241163 16004 process.cpp:3932] Handling HTTP event for process 'files' with path: '/files/read' 3: I1117 20:02:31.241667 16010 http.cpp:1185] HTTP GET for /files/read?path=one%2Ftwo%2F from 172.17.0.6:40246 3: I1117 20:02:31.244024 16011 process.cpp:3932] Handling HTTP event for process 'files' with path: '/files/read' 3: I1117 20:02:31.244540 15997 http.cpp:1185] HTTP GET for /files/read?path=two%2F..%2Ftwo from 172.17.0.6:40248 3: [ OK ] FilesTest.ResolveTest (36 ms) 3: [ RUN ] FilesTest.BrowseTest 3: I1117 20:02:31.248726 16010 process.cpp:3932] Handling HTTP event for process 'files' with path: '/files/browse' 3: I1117 20:02:31.249305 15994 http.cpp:1185] HTTP GET for /files/browse?path=one%2F from 172.17.0.6:40250 3: I1117 20:02:31.253741 16004 process.cpp:3932] Handling HTTP event for process 'files' with path: '/files/browse' 3: I1117 20:02:31.254314 16010 http.cpp:1185] HTTP GET for /files/browse?path=one%2F from 172.17.0.6:40252 3: I1117 20:02:31.257598 15991 process.cpp:3932] Handling HTTP event for process 'files' with path: '/files/browse' 3: I1117 20:02:31.258138 16004 http.cpp:1185] HTTP GET for /files/browse?path=one from 172.17.0.6:40254 3: I1117 20:02:31.261225 16014 process.cpp:3932] Handling HTTP event for process 'files' with path: '/files/browse' 3: I1117 20:02:31.261818 15991 http.cpp:1185] HTTP GET for /files/browse?path=one%2F2 from 172.17.0.6:40256 3: I1117 20:02:31.264489 16001 process.cpp:3932] Handling HTTP event for process 'files' with path: '/files/browse' 3: I1117 20:02:31.265054 16014 http.cpp:1185] HTTP GET for /files/browse?path=missing from 172.17.0.6:40258 3: I1117 20:02:31.267969 16010 process.cpp:3932] Handling HTTP event for process 'files' with path: '/files/browse' 3: I1117 20:02:31.268496 15992 http.cpp:1185] HTTP GET for /files/browse?path=one from 172.17.0.6:40260 3: I1117 20:02:31.271615 16011 process.cpp:3932] Handling HTTP event for process 'files' with path: '/files/browse' 3: I1117 20:02:31.272240 15997 http.cpp:1185] HTTP GET for /files/browse?path=one%2F from 172.17.0.6:40262 3: I1117 20:02:31.275346 16014 process.cpp:3932] Handling HTTP event for process 'files' with path: '/files/browse' 3: I1117 20:02:31.275893 16011 http.cpp:1185] HTTP GET for /files/browse?path=%2Ftwo from 172.17.0.6:40264 3: I1117 20:02:31.278498 15995 process.cpp:3932] Handling HTTP event for process 'files' with path: '/files/browse' 3: I1117 20:02:31.279096 16013 http.cpp:1185] HTTP GET for /files/browse?path=%2Ftwo%2F from 172.17.0.6:40266 3: I1117 20:02:31.281486 16010 process.cpp:3932] Handling HTTP event for process 'files' with path: '/files/browse' 3: I1117 20:02:31.282001 15992 http.cpp:1185] HTTP GET for /files/browse?path=one from 172.17.0.6:40268 3: I1117 20:02:31.284255 15991 process.cpp:3932] Handling HTTP event for process 'files' with path: '/files/browse' 3: I1117 20:02:31.284776 16002 http.cpp:1185] HTTP GET for /files/browse?path=one%2F from 172.17.0.6:40270 3: I1117 20:02:31.286967 16003 process.cpp:3932] Handling HTTP event for process 'files' with path: '/files/browse' 3: I1117 20:02:31.287575 16004 http.cpp:1185] HTTP GET for /files/browse?path=%2Ftwo from 172.17.0.6:40272 3: I1117 20:02:31.289779 15999 process.cpp:3932] Handling HTTP event for process 'files' with path: '/files/browse' 3: I1117 20:02:31.290324 16007 http.cpp:1185] HTTP GET for /files/browse?path=%2Ftwo%2F from 172.17.0.6:40274 3: [ OK ] FilesTest.BrowseTest (46 ms) 3: [ RUN ] FilesTest.DownloadTest 3: I1117 20:02:31.294414 15997 process.cpp:3932] Handling HTTP event for process 'files' with path: '/files/download' 3: I1117 20:02:31.294981 16009 http.cpp:1185] HTTP GET for /files/download?path=binary from 172.17.0.6:40276 3: I1117 20:02:31.295338 16010 process.cpp:1649] Sending file at '/tmp/jhls6S/binary' with length 17 3: I1117 20:02:31.297883 15997 process.cpp:3932] Handling HTTP event for process 'files' with path: '/files/download' 3: I1117 20:02:31.298393 16009 http.cpp:1185] HTTP GET for /files/download?path=black.gif from 172.17.0.6:40278 3: I1117 20:02:31.298692 16010 process.cpp:1649] Sending file at '/tmp/jhls6S/black.gif' with length 42 3: I1117 20:02:31.301322 15999 process.cpp:3932] Handling HTTP event for process 'files' with path: '/files/download' 3: I1117 20:02:31.301857 15995 http.cpp:1185] HTTP GET for /files/download?path=authorized.gif from 172.17.0.6:40280 3: I1117 20:02:31.302280 16000 process.cpp:1649] Sending file at '/tmp/jhls6S/black.gif' with length 42 3: I1117 20:02:31.304639 15996 process.cpp:3932] Handling HTTP event for process 'files' with path: '/files/download' 3: I1117 20:02:31.305151 15998 http.cpp:1185] HTTP GET for /files/download?path=authorized.gif from 172.17.0.6:40282 3: [ OK ] FilesTest.DownloadTest (14 ms) 3: [ RUN ] FilesTest.DebugTest 3: I1117 20:02:31.308380 16013 process.cpp:3932] Handling HTTP event for process 'files' with path: '/files/debug' 3: I1117 20:02:31.308953 15991 http.cpp:1185] HTTP GET for /files/debug from 172.17.0.6:40284 3: I1117 20:02:31.311657 15991 process.cpp:3932] Handling HTTP event for process 'files' with path: '/files/debug' 3: I1117 20:02:31.312248 16005 http.cpp:1185] HTTP GET for /files/debug from 172.17.0.6:40286 3: I1117 20:02:31.312324 16005 http.cpp:976] Authorizing principal 'ANY' to GET the '/files/debug' endpoint 3: I1117 20:02:31.315515 15992 process.cpp:3932] Handling HTTP event for process 'files' with path: '/files/debug' 3: I1117 20:02:31.316099 16013 http.cpp:1185] HTTP GET for /files/debug from 172.17.0.6:40288 3: I1117 20:02:31.316149 16013 http.cpp:976] Authorizing principal 'ANY' to GET the '/files/debug' endpoint 3: [ OK ] FilesTest.DebugTest (11 ms) 3: [ RUN ] FilesTest.AuthenticationTest 3: I1117 20:02:31.319412 16006 process.cpp:3932] Handling HTTP event for process 'files' with path: '/files/browse' 3: I1117 20:02:31.322103 16000 process.cpp:3932] Handling HTTP event for process 'files' with path: '/files/read' 3: I1117 20:02:31.324726 15998 process.cpp:3932] Handling HTTP event for process 'files' with path: '/files/download' 3: I1117 20:02:31.327181 16004 process.cpp:3932] Handling HTTP event for process 'files' with path: '/files/debug' 3: [ OK ] FilesTest.AuthenticationTest (11 ms) 3: [----------] 8 tests from FilesTest (161 ms total) 3: 3: [----------] 3 tests from GarbageCollectorTest 3: [ RUN ] GarbageCollectorTest.Schedule 3: I1117 20:02:31.329712 15992 gc.cpp:90] Scheduling 'file1' for gc 10secs in the future 3: I1117 20:02:31.329857 15992 gc.cpp:90] Scheduling 'file2' for gc 10secs in the future 3: I1117 20:02:31.329934 15992 gc.cpp:90] Scheduling 'file3' for gc 15secs in the future 3: I1117 20:02:31.331467 16001 process.cpp:3932] Handling HTTP event for process 'metrics' with path: '/metrics/snapshot' 3: I1117 20:02:31.343348 16004 gc.cpp:208] Deleting file1 3: I1117 20:02:31.343456 16004 gc.cpp:218] Deleted 'file1' 3: I1117 20:02:31.343488 16004 gc.cpp:208] Deleting file2 3: I1117 20:02:31.343525 16004 gc.cpp:218] Deleted 'file2' 3: I1117 20:02:31.346247 15992 gc.cpp:208] Deleting file3 3: I1117 20:02:31.346302 15992 gc.cpp:218] Deleted 'file3' 3: I1117 20:02:31.348451 16001 process.cpp:3932] Handling HTTP event for process 'metrics' with path: '/metrics/snapshot' 3: [ OK ] GarbageCollectorTest.Schedule (28 ms) 3: [ RUN ] GarbageCollectorTest.Unschedule 3: I1117 20:02:31.358469 16001 gc.cpp:124] Unscheduling 'bogus' from gc 3: I1117 20:02:31.358935 16005 gc.cpp:90] Scheduling 'file1' for gc 10secs in the future 3: I1117 20:02:31.359061 16005 gc.cpp:90] Scheduling 'file2' for gc 10secs in the future 3: I1117 20:02:31.359122 16005 gc.cpp:90] Scheduling 'file3' for gc 10secs in the future 3: I1117 20:02:31.359171 16005 gc.cpp:124] Unscheduling 'file2' from gc 3: I1117 20:02:31.359293 16010 gc.cpp:124] Unscheduling 'file3' from gc 3: I1117 20:02:31.359386 15991 gc.cpp:124] Unscheduling 'file1' from gc 3: I1117 20:02:31.360941 15996 gc.cpp:237] Ignoring gc event at 0ns as the paths were already removed, or were unscheduled 3: [ OK ] GarbageCollectorTest.Unschedule (3 ms) 3: [ RUN ] GarbageCollectorTest.Prune 3: I1117 20:02:31.361889 16006 gc.cpp:90] Scheduling 'file1' for gc 10secs in the future 3: I1117 20:02:31.361973 16006 gc.cpp:90] Scheduling 'file2' for gc 10secs in the future 3: I1117 20:02:31.362030 16006 gc.cpp:90] Scheduling 'file3' for gc 15secs in the future 3: I1117 20:02:31.362082 16006 gc.cpp:90] Scheduling 'file4' for gc 15secs in the future 3: I1117 20:02:31.362130 16006 gc.cpp:124] Unscheduling 'file3' from gc 3: I1117 20:02:31.362416 15995 gc.cpp:263] Pruning directories with remaining removal time 10secs 3: I1117 20:02:31.362592 16001 gc.cpp:208] Deleting file1 3: I1117 20:02:31.362646 16001 gc.cpp:218] Deleted 'file1' 3: I1117 20:02:31.362666 16001 gc.cpp:208] Deleting file2 3: I1117 20:02:31.362697 16001 gc.cpp:218] Deleted 'file2' 3: I1117 20:02:31.362898 16012 gc.cpp:263] Pruning directories with remaining removal time 15secs 3: I1117 20:02:31.362994 15993 gc.cpp:208] Deleting file4 3: I1117 20:02:31.363054 15993 gc.cpp:218] Deleted 'file4' 3: [ OK ] GarbageCollectorTest.Prune (2 ms) 3: [----------] 3 tests from GarbageCollectorTest (34 ms total) 3: 3: [----------] 5 tests from GarbageCollectorIntegrationTest 3: [ RUN ] GarbageCollectorIntegrationTest.Restart 3: I1117 20:02:31.365655 15990 cluster.cpp:162] Creating default 'local' authorizer 3: I1117 20:02:31.368233 15997 master.cpp:448] Master fe63dc34-f257-47c6-a007-73d258b32b63 (2e2b068130dc) started on 172.17.0.6:45388 3: I1117 20:02:31.368266 15997 master.cpp:450] Flags at startup: --acls="" --agent_ping_timeout="15secs" --agent_reregister_timeout="10mins" --allocation_interval="1secs" --allocator="HierarchicalDRF" --authenticate_agents="true" --authenticate_frameworks="true" --authenticate_http_frameworks="true" --authenticate_http_readonly="true" --authenticate_http_readwrite="true" --authenticators="crammd5" --authorizers="local" --credentials="/tmp/kwMKmz/credentials" --filter_gpu_resources="true" --framework_sorter="drf" --help="false" --hostname_lookup="true" --http_authenticators="basic" --http_framework_authenticators="basic" --initialize_driver_logging="true" --log_auto_initialize="true" --logbufsecs="0" --logging_level="INFO" --max_agent_ping_timeouts="5" --max_completed_frameworks="50" --max_completed_tasks_per_framework="1000" --max_unreachable_tasks_per_framework="1000" --port="5050" --quiet="false" --recovery_agent_removal_limit="100%" --registry="in_memory" --registry_fetch_timeout="1mins" --registry_gc_interval="15mins" --registry_max_agent_age="2weeks" --registry_max_agent_count="102400" --registry_store_timeout="100secs" --registry_strict="false" --root_submissions="true" --user_sorter="drf" --version="false" --webui_dir="/usr/local/share/mesos/webui" --work_dir="/tmp/kwMKmz/master" --zk_session_timeout="10secs" 3: I1117 20:02:31.368515 15997 master.cpp:499] Master only allowing authenticated frameworks to register 3: I1117 20:02:31.368525 15997 master.cpp:505] Master only allowing authenticated agents to register 3: I1117 20:02:31.368530 15997 master.cpp:511] Master only allowing authenticated HTTP frameworks to register 3: I1117 20:02:31.368535 15997 credentials.hpp:37] Loading credentials for authentication from '/tmp/kwMKmz/credentials' 3: I1117 20:02:31.368796 15997 master.cpp:555] Using default 'crammd5' authenticator 3: I1117 20:02:31.368942 15997 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readonly' 3: I1117 20:02:31.369082 15997 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-readwrite' 3: I1117 20:02:31.369180 15997 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-master-scheduler' 3: I1117 20:02:31.369271 15997 master.cpp:634] Authorization enabled 3: I1117 20:02:31.369407 15999 hierarchical.cpp:171] Initialized hierarchical allocator process 3: I1117 20:02:31.369437 15998 whitelist_watcher.cpp:77] No whitelist given 3: I1117 20:02:31.371969 16013 master.cpp:2213] Elected as the leading master! 3: I1117 20:02:31.371986 16013 master.cpp:1693] Recovering from registrar 3: I1117 20:02:31.372088 16006 registrar.cpp:347] Recovering registrar 3: I1117 20:02:31.372619 16006 registrar.cpp:391] Successfully fetched the registry (0B) in 486144ns 3: I1117 20:02:31.372733 16006 registrar.cpp:495] Applied 1 operations in 40715ns; attempting to update the registry 3: I1117 20:02:31.373220 16006 registrar.cpp:552] Successfully updated the registry in 431104ns 3: I1117 20:02:31.373318 16006 registrar.cpp:424] Successfully recovered registrar 3: I1117 20:02:31.373602 15991 master.cpp:1806] Recovered 0 agents from the registry (129B); allowing 10mins for agents to re-register 3: I1117 20:02:31.373644 15994 hierarchical.cpp:209] Skipping recovery of hierarchical allocator: nothing to recover 3: W1117 20:02:31.378551 15990 process.cpp:3185] Attempted to spawn already running process files@172.17.0.6:45388 3: I1117 20:02:31.378804 15990 cluster.cpp:448] Creating default 'local' authorizer 3: I1117 20:02:31.381186 16001 slave.cpp:262] Mesos agent started on (60)@172.17.0.6:45388 3: I1117 20:02:31.381211 16001 slave.cpp:263] Flags at startup: --acls="" --appc_simple_discovery_uri_prefix="http://"; --appc_store_dir="/tmp/GarbageCollectorIntegrationTest_Restart_bzY7CN/store/appc" --authenticate_http_readonly="true" --authenticate_http_readwrite="true" --authenticatee="crammd5" --authentication_backoff_factor="1secs" --authorizer="local" --cgroups_cpu_enable_pids_and_tids_count="false" --cgroups_enable_cfs="false" --cgroups_hierarchy="/sys/fs/cgroup" --cgroups_limit_swap="false" --cgroups_root="mesos" --container_disk_watch_interval="15secs" --containerizers="mesos" --credential="/tmp/GarbageCollectorIntegrationTest_Restart_bzY7CN/credential" --default_role="*" --disallow_sharing_agent_pid_namespace="false" --disk_watch_interval="1mins" --docker="docker" --docker_kill_orphans="true" --docker_registry="https://registry-1.docker.io"; --docker_remove_delay="6hrs" --docker_socket="/var/run/docker.sock" --docker_stop_timeout="0ns" --docker_store_dir="/tmp/GarbageCollectorIntegrationTest_Restart_bzY7CN/store/docker" --docker_volume_checkpoint_dir="/var/run/mesos/isolators/docker/volume" --enforce_container_disk_quota="false" --executor_registration_timeout="1mins" --executor_reregistration_timeout="2secs" --executor_shutdown_grace_period="50ms" --fetcher_cache_dir="/tmp/GarbageCollectorIntegrationTest_Restart_bzY7CN/fetch" --fetcher_cache_size="2GB" --frameworks_home="" --gc_delay="1weeks" --gc_disk_headroom="0.1" --hadoop_home="" --help="false" --hostname_lookup="true" --http_command_executor="false" --http_credentials="/tmp/GarbageCollectorIntegrationTest_Restart_bzY7CN/http_credentials" --http_heartbeat_interval="30secs" --initialize_driver_logging="true" --isolation="posix/cpu,posix/mem" --launcher="posix" --launcher_dir="/mesos/build/src" --logbufsecs="0" --logging_level="INFO" --max_completed_executors_per_framework="150" --oversubscribed_resources_interval="15secs" --perf_duration="10secs" --perf_interval="1mins" --port="5051" --qos_correction_interval_min="0ns" --quiet="false" --recover="reconnect" --recovery_timeout="15mins" --registration_backoff_factor="10ms" --resources="cpus:2;gpus:0;mem:1024;disk:1024;ports:[31000-32000]" --revocable_cpu_low_priority="true" --runtime_dir="/tmp/GarbageCollectorIntegrationTest_Restart_bzY7CN" --sandbox_directory="/mnt/mesos/sandbox" --strict="true" --switch_user="true" --systemd_enable_support="true" --systemd_runtime_directory="/run/systemd/system" --version="false" --work_dir="/tmp/GarbageCollectorIntegrationTest_Restart_jkHVuG" --zk_session_timeout="10secs" 3: I1117 20:02:31.381551 16001 credentials.hpp:86] Loading credential for authentication from '/tmp/GarbageCollectorIntegrationTest_Restart_bzY7CN/credential' 3: I1117 20:02:31.381700 16001 slave.cpp:295] Agent using credential for: test-principal 3: I1117 20:02:31.381717 16001 credentials.hpp:37] Loading credentials for authentication from '/tmp/GarbageCollectorIntegrationTest_Restart_bzY7CN/http_credentials' 3: I1117 20:02:31.381916 16001 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readonly' 3: I1117 20:02:31.382063 16001 http.cpp:1045] Creating default 'basic' HTTP authenticator for realm 'mesos-agent-readwrite' 3: I1117 20:02:31.383420 16001 slave.cpp:593] Agent resources: [{"name":"cpus","scalar":{"value":2.0},"type":"SCALAR"},{"name":"mem","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"disk","scalar":{"value":1024.0},"type":"SCALAR"},{"name":"ports","ranges":{"range":[{"begin":31000,"end":32000}]},"type":"RANGES"}] 3: I1117 20:02:31.383612 16001 slave.cpp:601] Agent attributes: [ ] 3: I1117 20:02:31.383623 16001 slave.cpp:610] Agent hostname: 2e2b068130dc 3: I1117 20:02:31.383728 15996 status_update_manager.cpp:177] Pausing sending status updates 3: I1117 20:02:31.385340 16008 state.cpp:64] Recovering state from '/tmp/GarbageCollectorIntegrationTest_Restart_jkHVuG/meta' 3: I1117 20:02:31.385601 16000 status_update_manager.cpp:203] Recovering status update manager 3: I1117 20:02:31.385859 16013 slave.cpp:6441] Finished recovery 3: I1117 20:02:31.386473 16007 status_update_manager.cpp:177] Pausing sending status updates 3: I1117 20:02:31.386512 16011 slave.cpp:1007] New master detected at master@172.17.0.6:45388 3: I1117 20:02:31.386646 16011 slave.cpp:1042] Detecting new master 3: I1117 20:02:31.391891 16002 slave.cpp:1069] Authenticating with master master@172.17.0.6:45388 3: I1117 20:02:31.391963 16002 slave.cpp:1078] Using default CRAM-MD5 authenticatee 3: I1117 20:02:31.392181 16010 authenticatee.cpp:121] Creating new client SASL connection 3: I1117 20:02:31.392462 16005 master.cpp:8285] Authenticating slave(60)@172.17.0.6:45388 3: I1117 20:02:31.392555 16006 authenticator.cpp:414] Starting authentication session for crammd5-authenticatee(140)@172.17.0.6:45388 3: I1117 20:02:31.392771 16014 authenticator.cpp:98] Creating new server SASL connection 3: I1117 20:02:31.392966 16004 authenticatee.cpp:213] Received SASL authentication mechanisms: CRAM-MD5 3: I1117 20:02:31.392989 16004 authenticatee.cpp:239] Attempting to authenticate with mechanism 'CRAM-MD5' 3: I1117 20:02:31.393082 15996 authenticator.cpp:204] Received SASL authentication start 3: I1117 20:02:31.393134 15996 authenticator.cpp:326] Authentication requires more steps 3: I1117 20:02:31.393231 16009 authenticatee.cpp:259] Received SASL authentication step 3: I1117 20:02:31.393329 15991 authenticator.cpp:232] Received SASL authentication step 3: I1117 20:02:31.393359 15991 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '2e2b068130dc' server FQDN: '2e2b068130dc' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: false 3: I1117 20:02:31.393369 15991 auxprop.cpp:181] Looking up auxiliary property '*userPassword' 3: I1117 20:02:31.393409 15991 auxprop.cpp:181] Looking up auxiliary property '*cmusaslsecretCRAM-MD5' 3: I1117 20:02:31.393425 15991 auxprop.cpp:109] Request to lookup properties for user: 'test-principal' realm: '2e2b068130dc' server FQDN: '2e2b068130dc' SASL_AUXPROP_VERIFY_AGAINST_HASH: false SASL_AUXPROP_OVERRIDE: false SASL_AUXPROP_AUTHZID: true 3: I1117 20:02:31.393434 15991 auxprop.cpp:131] Skipping auxiliary property '*userPassword' since SASL_AUXPROP_AUTHZID == true 3: I1117 20:02:31.393440 15991 auxprop.cpp:131] Skipping auxiliary property '*cmusaslsecretCRAM-MD5' since SASL_AUXPROP_AUTHZID == true 3: I1117 20:02:31.393451 15991 authenticator.cpp:318] Authentication success 3: I1117 20:02:31.393514 15992 authenticatee.cpp:299] Authentication success 3: I1117 20:02:31.393610 16001 master.cpp:8315] Successfully authenticated principal 'test-principal' at slave(60)@172.17.0.6:45388 3: I1117 20:02:31.393653 15991 authenticator.cpp:432] Authentication session cleanup for crammd5-authenticatee(140)@172.17.0.6:45388 3: I1117 20:02:31.393821 15994 slave.cpp:1161] Successfully authenticated with master master@172.17.0.6:45388 3: I1117 20:02:31.394071 15994 slave.cpp:1682] Will retry registration in 6.034624ms if necessary 3: I1117 20:02:31.394264 16003 master.cpp:6032] Received register agent message from slave(60)@172.17.0.6:45388 (2e2b068130dc) 3: I1117 20:02:31.394295 16003 master.cpp:3870] Authorizing agent with principal 'test-principal' 3: I1117 20:02:31.394685 15995 master.cpp:6092] Authorized registration of agent at slave(60)@172.17.0.6:45388 (2e2b068130dc) 3: I1117 20:02:31.394789 15995 master.cpp:6185] Registering agent at slave(60)@172.17.0.6:45388 (2e2b068130dc) with id fe63dc34-f257-47c6-a007-73d258b32b63-S0 3: I1117 20:02:31.395123 15993 registrar.cpp:495] Applied 1 operations in 76909ns; attempting to update the registry 3: I1117 20:02:31.395695 15993 registrar.cpp:552] Successfully updated the registry in 503040ns 3: I1117 20:02:31.395850 16010 master.cpp:6232] Admitted agent fe63dc34-f257-47c6-a007-73d258b32b63-S0 at slave(60)@172.17.0.6:45388 (2e2b068130dc) write /dev/stdout: resource temporarily unavailable + docker rmi mesos-1510947142-5002 Build step 'Execute shell' marked build as failure Not sending mail to unregistered user xuj...@apple.com
