You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@mesos.apache.org by "Greg Mann (JIRA)" <ji...@apache.org> on 2016/04/01 19:30:25 UTC
[jira] [Comment Edited] (MESOS-5060) Requesting /files/read.json
with a negative length value causes subsequent /files requests to 404.
[ https://issues.apache.org/jira/browse/MESOS-5060?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15222026#comment-15222026 ]
Greg Mann edited comment on MESOS-5060 at 4/1/16 5:29 PM:
----------------------------------------------------------
I was able to reproduce this on the current tip of master. Thanks for the bug report, [~tpetr]!
Here's a log from an agent which shows two requests to {{/read.json}}: the first returned a successful response, the second included a negative {{length}} query parameter and the {{Files}} process was killed:
{code}
I0401 10:26:38.672874 313663488 process.cpp:3136] Handling HTTP event for process 'files' with path: '/files/read.json'
I0401 10:26:38.673017 313663488 process.cpp:2484] Spawned process (16)@127.0.0.1:5051
I0401 10:26:38.673032 315273216 process.cpp:2494] Resuming (16)@127.0.0.1:5051 at 2016-04-01 17:26:38.673050880+00:00
I0401 10:26:38.673245 316346368 process.cpp:2494] Resuming AuthenticationRouter(1)@127.0.0.1:5051 at 2016-04-01 17:26:38.673285120+00:00
I0401 10:26:38.673316 316346368 authenticator_manager.cpp:84] Request for '/files/read.json' requires authentication in realm 'mesos-agent' but no authenticator found
I0401 10:26:38.673416 314200064 process.cpp:2494] Resuming (16)@127.0.0.1:5051 at 2016-04-01 17:26:38.673443072+00:00
I0401 10:26:38.673717 315809792 process.cpp:2494] Resuming files@127.0.0.1:5051 at 2016-04-01 17:26:38.673743872+00:00
I0401 10:26:38.674485 316346368 process.cpp:2494] Resuming __http__(2)@127.0.0.1:5051 at 2016-04-01 17:26:38.674512896+00:00
E0401 10:26:38.681279 316882944 process.cpp:1958] Failed to shutdown socket with fd 10: Socket is not connected
I0401 10:26:38.681347 314200064 process.cpp:2494] Resuming __http__(2)@127.0.0.1:5051 at 2016-04-01 17:26:38.681363968+00:00
I0401 10:26:38.681399 314200064 process.cpp:2599] Cleaning up __http__(2)@127.0.0.1:5051
I0401 10:26:38.681484 312590336 process.cpp:2494] Resuming help@127.0.0.1:5051 at 2016-04-01 17:26:38.681499904+00:00
I0401 10:26:38.681502 313126912 process.cpp:2494] Resuming __gc__@127.0.0.1:5051 at 2016-04-01 17:26:38.681520896+00:00
I0401 10:26:38.681607 313663488 process.cpp:2494] Resuming (15)@127.0.0.1:5051 at 2016-04-01 17:26:38.681622016+00:00
I0401 10:26:38.681679 313663488 process.cpp:2599] Cleaning up (15)@127.0.0.1:5051
I0401 10:26:38.681731 316346368 process.cpp:2494] Resuming help@127.0.0.1:5051 at 2016-04-01 17:26:38.681741056+00:00
I0401 10:26:40.393486 313663488 process.cpp:2494] Resuming slave(1)@127.0.0.1:5051 at 2016-04-01 17:26:40.393510912+00:00
I0401 10:26:40.393539 313663488 slave.cpp:4945] Querying resource estimator for oversubscribable resources
I0401 10:26:40.393576 314200064 process.cpp:2494] Resuming (10)@127.0.0.1:5051 at 2016-04-01 17:26:40.393590016+00:00
I0401 10:26:40.393693 315809792 process.cpp:2494] Resuming slave(1)@127.0.0.1:5051 at 2016-04-01 17:26:40.393707008+00:00
I0401 10:26:40.393723 315809792 slave.cpp:4959] Received oversubscribable resources from the resource estimator
I0401 10:26:46.132222 316882944 process.cpp:2484] Spawned process __http__(3)@127.0.0.1:5051
I0401 10:26:46.132216 312590336 process.cpp:2494] Resuming __http__(3)@127.0.0.1:5051 at 2016-04-01 17:26:46.132232960+00:00
I0401 10:26:46.132212 314200064 process.cpp:2494] Resuming __gc__@127.0.0.1:5051 at 2016-04-01 17:26:46.132236032+00:00
I0401 10:26:46.132331 314200064 process.cpp:2494] Resuming (17)@127.0.0.1:5051 at 2016-04-01 17:26:46.132338944+00:00
I0401 10:26:46.132351 314200064 process.cpp:2494] Resuming files@127.0.0.1:5051 at 2016-04-01 17:26:46.132358912+00:00
I0401 10:26:46.132365 314200064 process.cpp:3136] Handling HTTP event for process 'files' with path: '/files/read.json'
I0401 10:26:46.132350 312590336 process.cpp:2484] Spawned process (17)@127.0.0.1:5051
I0401 10:26:46.132478 312590336 process.cpp:2494] Resuming AuthenticationRouter(1)@127.0.0.1:5051 at 2016-04-01 17:26:46.132503040+00:00
I0401 10:26:46.132520 312590336 authenticator_manager.cpp:84] Request for '/files/read.json' requires authentication in realm 'mesos-agent' but no authenticator found
I0401 10:26:46.132506 315809792 process.cpp:2494] Resuming (16)@127.0.0.1:5051 at 2016-04-01 17:26:46.132519936+00:00
libprocess: files@127.0.0.1:5051 terminating due to std::bad_alloc
I0401 10:26:46.132974 314200064 process.cpp:2599] Cleaning up files@127.0.0.1:5051
I0401 10:26:46.133028 314736640 process.cpp:2494] Resuming help@127.0.0.1:5051 at 2016-04-01 17:26:46.133041920+00:00
I0401 10:26:47.953259 316882944 pid.cpp:95] Attempting to parse 'slave-observer(3)@127.0.0.1:5050' into a PID
I0401 10:26:47.953330 316882944 process.cpp:612] Parsed message name 'mesos.internal.PingSlaveMessage' for slave(1)@127.0.0.1:5051 from slave-observer(3)@127.0.0.1:5050
I0401 10:26:47.953425 313126912 process.cpp:2494] Resuming slave(1)@127.0.0.1:5051 at 2016-04-01 17:26:47.953455104+00:00
I0401 10:26:47.953543 313126912 slave.cpp:3664] Received ping from slave-observer(3)@127.0.0.1:5050
I0401 10:26:55.396854 313663488 process.cpp:2494] Resuming slave(1)@127.0.0.1:5051 at 2016-04-01 17:26:55.396896000+00:00
I0401 10:26:55.396931 313663488 slave.cpp:4945] Querying resource estimator for oversubscribable resources
I0401 10:26:55.397075 314736640 process.cpp:2494] Resuming (10)@127.0.0.1:5051 at 2016-04-01 17:26:55.397092096+00:00
I0401 10:26:55.397187 315273216 process.cpp:2494] Resuming slave(1)@127.0.0.1:5051 at 2016-04-01 17:26:55.397209088+00:00
I0401 10:26:55.397233 315273216 slave.cpp:4959] Received oversubscribable resources from the resource estimator
I0401 10:27:02.956861 316882944 pid.cpp:95] Attempting to parse 'slave-observer(3)@127.0.0.1:5050' into a PID
I0401 10:27:02.956915 316882944 process.cpp:612] Parsed message name 'mesos.internal.PingSlaveMessage' for slave(1)@127.0.0.1:5051 from slave-observer(3)@127.0.0.1:5050
I0401 10:27:02.956971 314200064 process.cpp:2494] Resuming slave(1)@127.0.0.1:5051 at 2016-04-01 17:27:02.956988928+00:00
I0401 10:27:02.957041 314200064 slave.cpp:3664] Received ping from slave-observer(3)@127.0.0.1:5050
I0401 10:27:10.398092 315809792 process.cpp:2494] Resuming slave(1)@127.0.0.1:5051 at 2016-04-01 17:27:10.398116096+00:00
I0401 10:27:10.398146 315809792 slave.cpp:4945] Querying resource estimator for oversubscribable resources
I0401 10:27:10.398231 314200064 process.cpp:2494] Resuming (10)@127.0.0.1:5051 at 2016-04-01 17:27:10.398251008+00:00
I0401 10:27:10.398355 316346368 process.cpp:2494] Resuming slave(1)@127.0.0.1:5051 at 2016-04-01 17:27:10.398376960+00:00
I0401 10:27:10.398401 316346368 slave.cpp:4959] Received oversubscribable resources from the resource estimator
{code}
was (Author: greggomann):
I was able to reproduce this on the current tip of master. Thanks for the bug report, [~tpetr]!
> Requesting /files/read.json with a negative length value causes subsequent /files requests to 404.
> --------------------------------------------------------------------------------------------------
>
> Key: MESOS-5060
> URL: https://issues.apache.org/jira/browse/MESOS-5060
> Project: Mesos
> Issue Type: Bug
> Affects Versions: 0.23.0
> Environment: Mesos 0.23.0 on CentOS 6, also Mesos 0.28.0 on OSX
> Reporter: Tom Petr
> Priority: Minor
>
> I accidentally hit a slave's /files/read.json endpoint with a negative length (ex. http://hostname:5051/files/read.json?path=XXX&offset=0&length=-100). The HTTP request timed out after 30 seconds with nothing relevant in the slave logs, and subsequent calls to any of the /files endpoints on that slave immediately returned a HTTP 404 response. We ultimately got things working again by restarting the mesos-slave process (checkpointing FTW!), but it'd be wise to guard against negative lengths on the slave's end too.
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)