Skip to content

Instantly share code, notes, and snippets.

@wickman

wickman/executor_main.log Secret

Created March 22, 2015 03:48
Show Gist options
  • Star 0 You must be signed in to star a gist
  • Fork 0 You must be signed in to fork a gist
  • Save wickman/8640478fcaa660f23740 to your computer and use it in GitHub Desktop.
Save wickman/8640478fcaa660f23740 to your computer and use it in GitHub Desktop.
Download ZIP
pesos-enabled executor log
Raw
executor_main.log
vagrant@192:/var/lib/mesos/slaves/20150321-211748-119646400-5050-15896-S0/frameworks/20150321-211748-119646400-5050-15896-0000/executors/thermos-1426993376246-www-data-prod-hello-0-c37735af-d121-4585-8be9-cec4079c650d/runs/latest$ cat __main__.log
Log file created at: 2015/03/22 03:02:57
Running on machine: 192.168.33.7
[DIWEF]mmdd hh:mm:ss.uuuuuu pid file:line] msg
Command line: ./thermos_executor.pex --announcer-enable --announcer-ensemble localhost:2181
D0322 03:02:57.035119 20646 selector_events.py:71] Using selector: EpollSelector
I0322 03:02:57.035981 20646 executor.py:273] MesosExecutorDriver.start called
I0322 03:02:57.036397 20646 executor.py:61] Registering executor with slave slave(1)@192.168.33.7:5051
I0322 03:02:57.036633 20646 context.py:209] Sending POST executor(1)@192.168.33.7:39880 => http://192.168.33.7:5051/slave(1)/mesos.internal.RegisterExecutorMessage (payload: 289 bytes)
I0322 03:02:57.036794 20646 context.py:187] Establishing connection to slave(1)@192.168.33.7:5051
I0322 03:02:57.037012 20646 context.py:191] Maybe connected to slave(1)@192.168.33.7:5051
I0322 03:02:57.037079 20646 httpd.py:134] Mounting message handler /executor(1)/mesos.internal.ReconnectExecutorMessage
I0322 03:02:57.037302 20646 httpd.py:134] Mounting message handler /executor(1)/mesos.internal.StatusUpdateAcknowledgementMessage
I0322 03:02:57.037503 20646 httpd.py:134] Mounting message handler /executor(1)/mesos.internal.ExecutorReregisteredMessage
I0322 03:02:57.037684 20646 httpd.py:134] Mounting message handler /executor(1)/stop
I0322 03:02:57.037806 20646 httpd.py:134] Mounting message handler /executor(1)/mesos.internal.ShutdownExecutorMessage
I0322 03:02:57.037974 20646 httpd.py:134] Mounting message handler /executor(1)/send_status_update
I0322 03:02:57.038115 20646 httpd.py:134] Mounting message handler /executor(1)/mesos.internal.KillTaskMessage
I0322 03:02:57.038274 20646 httpd.py:134] Mounting message handler /executor(1)/mesos.internal.ExecutorRegisteredMessage
I0322 03:02:57.038470 20646 httpd.py:134] Mounting message handler /executor(1)/abort
I0322 03:02:57.038592 20646 httpd.py:134] Mounting message handler /executor(1)/mesos.internal.RunTaskMessage
I0322 03:02:57.038749 20646 httpd.py:134] Mounting message handler /executor(1)/send_framework_message
I0322 03:02:57.038969 20646 httpd.py:134] Mounting message handler /executor(1)/mesos.internal.FrameworkToExecutorMessage
I0322 03:02:57.039175 20646 executor.py:305] Started driver
I0322 03:02:57.039365 20646 context.py:162] Connection to slave(1)@192.168.33.7:5051 established
I0322 03:02:57.039429 20646 context.py:212] Writing 289 from executor(1)@192.168.33.7:39880 to slave(1)@192.168.33.7:5051
I0322 03:02:57.040952 20646 context.py:214] Wrote 289 from executor(1)@192.168.33.7:39880 to slave(1)@192.168.33.7:5051
I0322 03:02:57.042509 20646 httpd.py:51] Handling mesos.internal.ExecutorRegisteredMessage for executor(1)@192.168.33.7:39880
D0322 03:02:57.042651 20646 httpd.py:59] Delivering mesos.internal.ExecutorRegisteredMessage to executor(1)@192.168.33.7:39880 from slave(1)@192.168.33.7:5051
D0322 03:02:57.042736 20646 httpd.py:60] Request body length: 706
I0322 03:02:57.043467 20646 executor.py:70] Executor registered on slave 20150321-211748-119646400-5050-15896-S0
I0322 03:02:57.043656 20646 executor_base.py:47] Executor [None]: registered() called with:
I0322 03:02:57.043931 20646 executor_base.py:47] Executor [None]: ExecutorInfo: executor_id {
value: "thermos-1426993376246-www-data-prod-hello-0-c37735af-d121-4585-8be9-cec4079c650d"
}
resources {
name: "cpus"
type: SCALAR
scalar {
value: 0.01
}
}
resources {
name: "disk"
type: SCALAR
scalar {
value: 1.0
}
}
resources {
name: "mem"
type: SCALAR
scalar {
value: 1.0
}
}
command {
uris {
value: "/home/vagrant/aurora/dist/thermos_executor.pex"
executable: true
}
value: "./thermos_executor.pex --announcer-enable --announcer-ensemble localhost:2181"
}
framework_id {
value: "20150321-211748-119646400-5050-15896-0000"
}
name: "aurora.task"
source: "www-data.prod.hello.0"
I0322 03:02:57.044024 20646 executor_base.py:47] Executor [None]: FrameworkInfo: user: "root"
name: "TwitterScheduler"
failover_timeout: 1814400.0
checkpoint: false
hostname: "192.168.33.7"
I0322 03:02:57.044251 20646 executor_base.py:47] Executor [None]: SlaveInfo: hostname: "192.168.33.7"
resources {
name: "cpus"
type: SCALAR
scalar {
value: 4.0
}
role: "*"
}
resources {
name: "mem"
type: SCALAR
scalar {
value: 1024.0
}
role: "*"
}
resources {
name: "disk"
type: SCALAR
scalar {
value: 20000.0
}
role: "*"
}
resources {
name: "ports"
type: RANGES
ranges {
range {
begin: 31000
end: 32000
}
}
role: "*"
}
attributes {
name: "host"
type: TEXT
text {
value: "192.168.33.7"
}
}
attributes {
name: "rack"
type: TEXT
text {
value: "a"
}
}
id {
value: "20150321-211748-119646400-5050-15896-S0"
}
checkpoint: true
port: 5051
D0322 03:02:57.044317 20646 util.py:13] executor::registered: 0.7ms
I0322 03:02:57.044663 20646 web.py:1825] 202 POST /executor(1)/mesos.internal.ExecutorRegisteredMessage (192.168.33.7) 2.63ms
I0322 03:02:57.044939 20646 context.py:158] Received 81 bytes from slave(1)@192.168.33.7:5051, discarding.
D0322 03:02:57.045006 20646 context.py:159] data: 'HTTP/1.1 202 Accepted\r\nDate: Sun, 22 Mar 2015 03:02:57 GMT\r\nContent-Length: 0\r\n\r\n'
I0322 03:02:57.045556 20646 httpd.py:51] Handling mesos.internal.RunTaskMessage for executor(1)@192.168.33.7:39880
D0322 03:02:57.045640 20646 httpd.py:59] Delivering mesos.internal.RunTaskMessage to executor(1)@192.168.33.7:39880 from slave(1)@192.168.33.7:5051
D0322 03:02:57.045696 20646 httpd.py:60] Request body length: 1920
I0322 03:02:57.046127 20646 executor_base.py:47] Executor [None]: launchTask got task: www-data/prod/hello:1426993376246-www-data-prod-hello-0-c37735af-d121-4585-8be9-cec4079c650d
D0322 03:02:57.046684 20646 util.py:13] executor::launch_task: 0.6ms
I0322 03:02:57.046894 20646 web.py:1825] 202 POST /executor(1)/mesos.internal.RunTaskMessage (192.168.33.7) 1.64ms
I0322 03:02:57.048064 20646 executor_base.py:47] Executor [20150321-211748-119646400-5050-15896-S0]: Updating 1426993376246-www-data-prod-hello-0-c37735af-d121-4585-8be9-cec4079c650d => STARTING
I0322 03:02:57.048152 20646 executor_base.py:47] Executor [20150321-211748-119646400-5050-15896-S0]: Reason: Initializing sandbox.
I0322 03:02:57.048851 20646 context.py:209] Sending POST executor(1)@192.168.33.7:39880 => http://192.168.33.7:5051/slave(1)/mesos.internal.StatusUpdateMessage (payload: 546 bytes)
I0322 03:02:57.048976 20646 context.py:212] Writing 546 from executor(1)@192.168.33.7:39880 to slave(1)@192.168.33.7:5051
I0322 03:02:57.054474 20646 context.py:214] Wrote 546 from executor(1)@192.168.33.7:39880 to slave(1)@192.168.33.7:5051
I0322 03:02:57.055298 20646 httpd.py:51] Handling mesos.internal.StatusUpdateAcknowledgementMessage for executor(1)@192.168.33.7:39880
D0322 03:02:57.055381 20646 httpd.py:59] Delivering mesos.internal.StatusUpdateAcknowledgementMessage to executor(1)@192.168.33.7:39880 from slave(1)@192.168.33.7:5051
D0322 03:02:57.055407 20646 httpd.py:60] Request body length: 182
I0322 03:02:57.055407 20646 executor.py:137] Executor received status update acknowledgement a2a5e96e-ea56-4691-bb68-324f02a3d21a for task 1426993376246-www-data-prod-hello-0-c37735af-d121-4585-8be9-cec4079c650d of framework 20150321-211748-119646400-5050-15896-0000
E0322 03:02:57.055407 20646 executor.py:141] Unknown status update a2a5e96e-ea56-4691-bb68-324f02a3d21a!
I0322 03:02:57.055603 20646 web.py:1825] 202 POST /executor(1)/mesos.internal.StatusUpdateAcknowledgementMessage (192.168.33.7) 0.54ms
I0322 03:02:57.056191 20646 context.py:158] Received 81 bytes from slave(1)@192.168.33.7:5051, discarding.
D0322 03:02:57.056253 20646 context.py:159] data: 'HTTP/1.1 202 Accepted\r\nDate: Sun, 22 Mar 2015 03:02:57 GMT\r\nContent-Length: 0\r\n\r\n'
D0322 03:02:57.056581 20646 sandbox.py:92] DirectorySandbox: mkdir /var/lib/mesos/slaves/20150321-211748-119646400-5050-15896-S0/frameworks/20150321-211748-119646400-5050-15896-0000/executors/thermos-1426993376246-www-data-prod-hello-0-c37735af-d121-4585-8be9-cec4079c650d/runs/e846b96e-4dd5-4388-9996-59b4a6e622f0/sandbox
D0322 03:02:57.056787 20646 sandbox.py:108] DirectorySandbox: chown www-data:www-data /var/lib/mesos/slaves/20150321-211748-119646400-5050-15896-S0/frameworks/20150321-211748-119646400-5050-15896-0000/executors/thermos-1426993376246-www-data-prod-hello-0-c37735af-d121-4585-8be9-cec4079c650d/runs/e846b96e-4dd5-4388-9996-59b4a6e622f0/sandbox
D0322 03:02:57.056859 20646 sandbox.py:110] DirectorySandbox: chmod 700 /var/lib/mesos/slaves/20150321-211748-119646400-5050-15896-S0/frameworks/20150321-211748-119646400-5050-15896-0000/executors/thermos-1426993376246-www-data-prod-hello-0-c37735af-d121-4585-8be9-cec4079c650d/runs/e846b96e-4dd5-4388-9996-59b4a6e622f0/sandbox
W0322 03:02:57.085975 20646 monitor.py:92] Could not read from checkpoint /var/run/thermos/checkpoints/1426993376246-www-data-prod-hello-0-c37735af-d121-4585-8be9-cec4079c650d/runner
I0322 03:02:57.086210 20646 thermos_task_runner.py:276] Forking off runner with cmdline: /usr/bin/python2.7 /var/lib/mesos/slaves/20150321-211748-119646400-5050-15896-S0/frameworks/20150321-211748-119646400-5050-15896-0000/executors/thermos-1426993376246-www-data-prod-hello-0-c37735af-d121-4585-8be9-cec4079c650d/runs/e846b96e-4dd5-4388-9996-59b4a6e622f0/thermos_runner.pex --setuid=www-data --thermos_json=/var/lib/mesos/slaves/20150321-211748-119646400-5050-15896-S0/frameworks/20150321-211748-119646400-5050-15896-0000/executors/thermos-1426993376246-www-data-prod-hello-0-c37735af-d121-4585-8be9-cec4079c650d/runs/e846b96e-4dd5-4388-9996-59b4a6e622f0/task.json --sandbox=/var/lib/mesos/slaves/20150321-211748-119646400-5050-15896-S0/frameworks/20150321-211748-119646400-5050-15896-0000/executors/thermos-1426993376246-www-data-prod-hello-0-c37735af-d121-4585-8be9-cec4079c650d/runs/e846b96e-4dd5-4388-9996-59b4a6e622f0/sandbox --log_dir=. --task_id=1426993376246-www-data-prod-hello-0-c37735af-d121-4585-8be9-cec4079c650d --log_to_disk=DEBUG --checkpoint_root=/var/run/thermos --hostname=192.168.33.7
D0322 03:02:57.088932 20646 thermos_task_runner.py:289] Waiting for task to start.
D0322 03:02:57.089282 20646 thermos_task_runner.py:298] - sleeping...
D0322 03:02:57.604273 20646 aurora_executor.py:146] Task started.
I0322 03:02:57.604712 20646 executor_base.py:47] Executor [20150321-211748-119646400-5050-15896-S0]: Updating 1426993376246-www-data-prod-hello-0-c37735af-d121-4585-8be9-cec4079c650d => RUNNING
I0322 03:02:57.604861 20646 executor_base.py:47] Executor [20150321-211748-119646400-5050-15896-S0]: Reason: None
I0322 03:02:57.606275 20646 context.py:209] Sending POST executor(1)@192.168.33.7:39880 => http://192.168.33.7:5051/slave(1)/mesos.internal.StatusUpdateMessage (payload: 523 bytes)
I0322 03:02:57.606417 20646 context.py:212] Writing 523 from executor(1)@192.168.33.7:39880 to slave(1)@192.168.33.7:5051
I0322 03:02:57.606595 20646 context.py:214] Wrote 523 from executor(1)@192.168.33.7:39880 to slave(1)@192.168.33.7:5051
I0322 03:02:57.620503 20646 httpd.py:51] Handling mesos.internal.StatusUpdateAcknowledgementMessage for executor(1)@192.168.33.7:39880
D0322 03:02:57.620634 20646 httpd.py:59] Delivering mesos.internal.StatusUpdateAcknowledgementMessage to executor(1)@192.168.33.7:39880 from slave(1)@192.168.33.7:5051
D0322 03:02:57.620687 20646 httpd.py:60] Request body length: 182
I0322 03:02:57.620843 20646 executor.py:137] Executor received status update acknowledgement e0b0fa13-9352-4412-952e-f40d8870305b for task 1426993376246-www-data-prod-hello-0-c37735af-d121-4585-8be9-cec4079c650d of framework 20150321-211748-119646400-5050-15896-0000
E0322 03:02:57.620918 20646 executor.py:141] Unknown status update e0b0fa13-9352-4412-952e-f40d8870305b!
E0322 03:02:57.620981 20646 executor.py:144] Unknown task 1426993376246-www-data-prod-hello-0-c37735af-d121-4585-8be9-cec4079c650d!
I0322 03:02:57.621182 20646 web.py:1825] 202 POST /executor(1)/mesos.internal.StatusUpdateAcknowledgementMessage (192.168.33.7) 0.96ms
I0322 03:02:57.621373 20646 context.py:158] Received 81 bytes from slave(1)@192.168.33.7:5051, discarding.
D0322 03:02:57.621428 20646 context.py:159] data: 'HTTP/1.1 202 Accepted\r\nDate: Sun, 22 Mar 2015 03:02:57 GMT\r\nContent-Length: 0\r\n\r\n'
D0322 03:02:57.632606 20646 ckpt.py:348] Flipping task state from (undefined) to ACTIVE
D0322 03:02:57.632803 20646 ckpt.py:328] Initializing TaskRunner header to RunnerHeader(launch_time_ms=1426993377318, uid=33, task_id='1426993376246-www-data-prod-hello-0-c37735af-d121-4585-8be9-cec4079c650d', hostname='192.168.33.7', sandbox='/var/lib/mesos/slaves/20150321-211748-119646400-5050-15896-S0/frameworks/20150321-211748-119646400-5050-15896-0000/executors/thermos-1426993376246-www-data-prod-hello-0-c37735af-d121-4585-8be9-cec4079c650d/runs/e846b96e-4dd5-4388-9996-59b4a6e622f0/sandbox', log_dir='/var/lib/mesos/slaves/20150321-211748-119646400-5050-15896-S0/frameworks/20150321-211748-119646400-5050-15896-0000/executors/thermos-1426993376246-www-data-prod-hello-0-c37735af-d121-4585-8be9-cec4079c650d/runs/e846b96e-4dd5-4388-9996-59b4a6e622f0/sandbox/.logs', ports={}, user='www-data')
D0322 03:02:57.632911 20646 ckpt.py:379] Running state machine for process=hello/seq=0
D0322 03:02:57.632940 20646 ckpt.py:379] Running state machine for process=hello/seq=1
D0322 03:02:57.632940 20646 ckpt.py:379] Running state machine for process=hello/seq=2
D0322 03:02:57.632940 20646 recordio.py:137] /var/run/thermos/checkpoints/1426993376246-www-data-prod-hello-0-c37735af-d121-4585-8be9-cec4079c650d/runner has no data (current offset = 873)
D0322 03:02:57.633043 20646 resource.py:136] Initialising resource collection for task 1426993376246-www-data-prod-hello-0-c37735af-d121-4585-8be9-cec4079c650d
D0322 03:02:57.633122 20646 resource.py:147] Initialising ResourceHistory of length 180
D0322 03:02:57.639812 20646 resource.py:187] Commencing resource monitoring for task "1426993376246-www-data-prod-hello-0-c37735af-d121-4585-8be9-cec4079c650d"
D0322 03:02:57.647018 20646 disk.py:62] DiskCollectorThread: finished collection of /var/lib/mesos/slaves/20150321-211748-119646400-5050-15896-S0/frameworks/20150321-211748-119646400-5050-15896-0000/executors/thermos-1426993376246-www-data-prod-hello-0-c37735af-d121-4585-8be9-cec4079c650d/runs/e846b96e-4dd5-4388-9996-59b4a6e622f0/sandbox in 0.1ms
D0322 03:03:17.648060 20646 process_collector_psutil.py:94] Calculated rate for pid=20668 and children: 0.0
D0322 03:03:37.651747 20646 process_collector_psutil.py:94] Calculated rate for pid=20668 and children: 0.0
D0322 03:03:57.641339 20646 disk.py:62] DiskCollectorThread: finished collection of /var/lib/mesos/slaves/20150321-211748-119646400-5050-15896-S0/frameworks/20150321-211748-119646400-5050-15896-0000/executors/thermos-1426993376246-www-data-prod-hello-0-c37735af-d121-4585-8be9-cec4079c650d/runs/e846b96e-4dd5-4388-9996-59b4a6e622f0/sandbox in 0.1ms
D0322 03:03:57.651293 20646 process_collector_psutil.py:94] Calculated rate for pid=20668 and children: 0.0
D0322 03:04:17.652847 20646 process_collector_psutil.py:94] Calculated rate for pid=20668 and children: 0.0
D0322 03:04:37.664705 20646 process_collector_psutil.py:94] Calculated rate for pid=20668 and children: 0.0
D0322 03:04:57.644826 20646 disk.py:62] DiskCollectorThread: finished collection of /var/lib/mesos/slaves/20150321-211748-119646400-5050-15896-S0/frameworks/20150321-211748-119646400-5050-15896-0000/executors/thermos-1426993376246-www-data-prod-hello-0-c37735af-d121-4585-8be9-cec4079c650d/runs/e846b96e-4dd5-4388-9996-59b4a6e622f0/sandbox in 0.1ms
D0322 03:04:57.656573 20646 process_collector_psutil.py:94] Calculated rate for pid=20668 and children: 0.0
D0322 03:05:17.658094 20646 process_collector_psutil.py:94] Calculated rate for pid=20668 and children: 0.0
D0322 03:05:37.658551 20646 process_collector_psutil.py:94] Calculated rate for pid=20668 and children: 0.0
D0322 03:05:57.645826 20646 disk.py:62] DiskCollectorThread: finished collection of /var/lib/mesos/slaves/20150321-211748-119646400-5050-15896-S0/frameworks/20150321-211748-119646400-5050-15896-0000/executors/thermos-1426993376246-www-data-prod-hello-0-c37735af-d121-4585-8be9-cec4079c650d/runs/e846b96e-4dd5-4388-9996-59b4a6e622f0/sandbox in 0.2ms
D0322 03:05:57.659157 20646 process_collector_psutil.py:94] Calculated rate for pid=20668 and children: 0.0
D0322 03:06:17.658467 20646 process_collector_psutil.py:94] Calculated rate for pid=20668 and children: 0.0
I0322 03:06:20.575438 20646 httpd.py:51] Handling mesos.internal.KillTaskMessage for executor(1)@192.168.33.7:39880
D0322 03:06:20.575635 20646 httpd.py:59] Delivering mesos.internal.KillTaskMessage to executor(1)@192.168.33.7:39880 from slave(1)@192.168.33.7:5051
D0322 03:06:20.575721 20646 httpd.py:60] Request body length: 121
I0322 03:06:20.575974 20646 executor.py:123] Executor asked to kill task value: "1426993376246-www-data-prod-hello-0-c37735af-d121-4585-8be9-cec4079c650d"
I0322 03:06:20.576159 20646 executor_base.py:47] Executor [20150321-211748-119646400-5050-15896-S0]: killTask got task_id: value: "1426993376246-www-data-prod-hello-0-c37735af-d121-4585-8be9-cec4079c650d"
I0322 03:06:20.576277 20646 executor_base.py:47] Executor [20150321-211748-119646400-5050-15896-S0]: Activating kill manager.
I0322 03:06:20.576364 20646 executor_base.py:47] Executor [20150321-211748-119646400-5050-15896-S0]: killTask returned.
D0322 03:06:20.576450 20646 util.py:13] executor::kill_task: 0.4ms
I0322 03:06:20.576755 20646 web.py:1825] 202 POST /executor(1)/mesos.internal.KillTaskMessage (192.168.33.7) 1.95ms
I0322 03:06:20.579185 20646 status_checker.py:100] KillManager reported StatusResult('Instructed to kill task.', status='TASK_KILLED')
I0322 03:06:20.579329 20646 status_checker.py:100] ChainedStatusChecker reported StatusResult('Instructed to kill task.', status='TASK_KILLED')
I0322 03:06:20.579392 20646 status_manager.py:49] Status manager got StatusResult('Instructed to kill task.', status='TASK_KILLED')
I0322 03:06:20.580912 20646 thermos_task_runner.py:320] ThermosTaskRunner is shutting down.
I0322 03:06:20.580997 20646 thermos_task_runner.py:325] Invoking runner HTTP teardown.
I0322 03:06:20.581049 20646 thermos_task_runner.py:328] Invoking runner.kill
I0322 03:06:20.581106 20646 thermos_task_runner.py:217] Runner is alive, sending SIGUSR1
I0322 03:06:22.095910 20646 thermos_task_runner.py:174] Detected runner termination: pid=20662, signal=0, rc=0
D0322 03:06:22.096323 20646 ckpt.py:348] Flipping task state from (undefined) to ACTIVE
D0322 03:06:22.096638 20646 ckpt.py:328] Initializing TaskRunner header to RunnerHeader(launch_time_ms=1426993377318, uid=33, task_id='1426993376246-www-data-prod-hello-0-c37735af-d121-4585-8be9-cec4079c650d', hostname='192.168.33.7', sandbox='/var/lib/mesos/slaves/20150321-211748-119646400-5050-15896-S0/frameworks/20150321-211748-119646400-5050-15896-0000/executors/thermos-1426993376246-www-data-prod-hello-0-c37735af-d121-4585-8be9-cec4079c650d/runs/e846b96e-4dd5-4388-9996-59b4a6e622f0/sandbox', log_dir='/var/lib/mesos/slaves/20150321-211748-119646400-5050-15896-S0/frameworks/20150321-211748-119646400-5050-15896-0000/executors/thermos-1426993376246-www-data-prod-hello-0-c37735af-d121-4585-8be9-cec4079c650d/runs/e846b96e-4dd5-4388-9996-59b4a6e622f0/sandbox/.logs', ports={}, user='www-data')
D0322 03:06:22.096851 20646 ckpt.py:379] Running state machine for process=hello/seq=0
D0322 03:06:22.097103 20646 ckpt.py:379] Running state machine for process=hello/seq=1
D0322 03:06:22.097421 20646 ckpt.py:379] Running state machine for process=hello/seq=2
D0322 03:06:22.097587 20646 ckpt.py:348] Flipping task state from ACTIVE to ACTIVE
D0322 03:06:22.097735 20646 ckpt.py:348] Flipping task state from ACTIVE to CLEANING
D0322 03:06:22.097896 20646 ckpt.py:379] Running state machine for process=hello/seq=3
D0322 03:06:22.098071 20646 ckpt.py:348] Flipping task state from CLEANING to FINALIZING
D0322 03:06:22.098227 20646 ckpt.py:348] Flipping task state from FINALIZING to KILLED
D0322 03:06:22.098334 20646 recordio.py:137] /var/run/thermos/checkpoints/1426993376246-www-data-prod-hello-0-c37735af-d121-4585-8be9-cec4079c650d/runner has no data (current offset = 1094)
I0322 03:06:22.130146 20646 executor_base.py:47] Executor [20150321-211748-119646400-5050-15896-S0]: Updating 1426993376246-www-data-prod-hello-0-c37735af-d121-4585-8be9-cec4079c650d => KILLED
I0322 03:06:22.130323 20646 executor_base.py:47] Executor [20150321-211748-119646400-5050-15896-S0]: Reason: Instructed to kill task.
I0322 03:06:22.131046 20646 context.py:209] Sending POST executor(1)@192.168.33.7:39880 => http://192.168.33.7:5051/slave(1)/mesos.internal.StatusUpdateMessage (payload: 549 bytes)
I0322 03:06:22.131161 20646 context.py:212] Writing 549 from executor(1)@192.168.33.7:39880 to slave(1)@192.168.33.7:5051
I0322 03:06:22.136843 20646 context.py:214] Wrote 549 from executor(1)@192.168.33.7:39880 to slave(1)@192.168.33.7:5051
I0322 03:06:22.138171 20646 httpd.py:51] Handling mesos.internal.StatusUpdateAcknowledgementMessage for executor(1)@192.168.33.7:39880
D0322 03:06:22.138278 20646 httpd.py:59] Delivering mesos.internal.StatusUpdateAcknowledgementMessage to executor(1)@192.168.33.7:39880 from slave(1)@192.168.33.7:5051
D0322 03:06:22.138331 20646 httpd.py:60] Request body length: 182
I0322 03:06:22.138487 20646 executor.py:137] Executor received status update acknowledgement 7b7494eb-4407-4a74-a43e-5f08b712105f for task 1426993376246-www-data-prod-hello-0-c37735af-d121-4585-8be9-cec4079c650d of framework 20150321-211748-119646400-5050-15896-0000
E0322 03:06:22.138570 20646 executor.py:141] Unknown status update 7b7494eb-4407-4a74-a43e-5f08b712105f!
E0322 03:06:22.138643 20646 executor.py:144] Unknown task 1426993376246-www-data-prod-hello-0-c37735af-d121-4585-8be9-cec4079c650d!
I0322 03:06:22.138854 20646 web.py:1825] 202 POST /executor(1)/mesos.internal.StatusUpdateAcknowledgementMessage (192.168.33.7) 1.42ms
I0322 03:06:22.142067 20646 context.py:158] Received 81 bytes from slave(1)@192.168.33.7:5051, discarding.
D0322 03:06:22.143481 20646 context.py:159] data: 'HTTP/1.1 202 Accepted\r\nDate: Sun, 22 Mar 2015 03:06:22 GMT\r\nContent-Length: 0\r\n\r\n'
I0322 03:06:27.152894 20646 executor.py:340] Executor driver finished with status 4
D0322 03:06:27.153583 20646 context.py:113] Stopping context
I0322 03:06:27.153678 20646 context.py:247] Terminating executor(1)@192.168.33.7:39880
I0322 03:06:27.153732 20646 context.py:250] Unmounting <pesos.executor.ExecutorProcess object at 0x7f50aa85f2d0>
I0322 03:06:27.154048 20646 thermos_executor_main.py:192] Driver finished.
vagrant@192:/var/lib/mesos/slaves/20150321-211748-119646400-5050-15896-S0/frameworks/20150321-211748-119646400-5050-15896-0000/executors/thermos-1426993376246-www-data-prod-hello-0-c37735af-d121-4585-8be9-cec4079c650d/runs/latest$
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment