controller.py 71.8 KB
Newer Older
1
2
3
4
#!/usr/bin/python3


import asyncio
5
import collections
6
from   concurrent.futures   import ThreadPoolExecutor
7
import contextlib
8
import datetime
9
import enum
BAIRE Anthony's avatar
BAIRE Anthony committed
10
import itertools
BAIRE Anthony's avatar
BAIRE Anthony committed
11
import json
12
13
14
import logging
import re
import os
15
import shlex
16
import signal
17
import struct
18
import sys
19
20
21
import time
import threading
import traceback
22

23
import aiohttp
24
import aioredis
25
import docker
BAIRE Anthony's avatar
BAIRE Anthony committed
26
import iso8601
27
import MySQLdb
BAIRE Anthony's avatar
BAIRE Anthony committed
28
29
from   sqlalchemy import desc
import sqlalchemy.orm.scoping
30
import yaml
31

32
import config_reader
33
from database import *
34
from shared_swarm import SharedSwarmClient, ShuttingDown
35

36
37
HOST_PATH="/vol/host/"

38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
##################################################
# default number of concurrent tasks

# pushing images from the sandbox to the registry
NB_PUSH_SANDBOX = 2

# pulling images from the registry to the sandbox
NB_PULL_SANDBOX = 2

# pulling images from the registry to the swarm
NB_PULL_SWARM   = 2

# sandbox actions (start, stop, commit, ...)
NB_SANDBOX_TASKS = 4

# jobs
NB_JOB_TASKS     = 4


# default thread pool (used by most of the tasks)
default_executor = ThreadPoolExecutor(10)

##################################################
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
# redis keys

# job log
REDIS_KEY_JOB_LOG       = "log:job:%d"
REDIS_KEY_JOB_STATE     = "state:job:%d"

# pubsub channels for waking up allgo.aio (frontend) and the controller
# (ourselves)
REDIS_CHANNEL_AIO        = "notify:aio"
REDIS_CHANNEL_CONTROLLER = "notify:controller"

# pubsub messages
REDIS_MESSAGE_JOB_UPDATED    = "job:%d"
REDIS_MESSAGE_WEBAPP_UPDATED = "webapp:%d"


##################################################

79

80
81
82
# interval (in seconds) for polling the db
DB_CHECK_PERIOD = 3600

BAIRE Anthony's avatar
BAIRE Anthony committed
83
log = logging.getLogger("controller")
84

85
86
87
88
89
assert MySQLdb.threadsafety >= 1


class Error(Exception):
    pass
90

91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120

class RateLimiter:
    """Generator for rate limiting

    This asynchronous iterator ensures we spend at least `period` seconds in
    each iteration.

    usage:
        async for _ in RateLimiter(60):
            ...
    """
    def __init__(self, period):
        assert period > 0
        self.period = period
        self._t0 = time.monotonic()-period

    def __aiter__(self):
        return self

    async def __anext__(self):
        t1 = time.monotonic()
        delay = self._t0 - t1 + self.period
        if delay > 0:
            log.debug("rate_limit: sleep %f seconds", delay)
            await asyncio.sleep(delay)
            self._t0 = t1 + delay
        else:
            self._t0 = t1


BAIRE Anthony's avatar
BAIRE Anthony committed
121
122
123
124
125
126
127
128
129
130
131
132
133
def docker_check_error(func, *k, **kw):
    """Wrapper for docker-py methods that produce a stream

    Methods producing a stram (eg: push, build) do not report all errors
    by raising exceptions. Some errors are reported later in the stream.

    This function parses the stream and raise Error() if needed.
    """
    for elem in func(*k, stream=True, **kw):
        js = json.loads(elem.decode())
        if "error" in js:
            raise Error("push error: " + js["error"])

BAIRE Anthony's avatar
BAIRE Anthony committed
134
135
136
137
138
139
140
141
142
@contextlib.contextmanager
def docker_warning(msg, *k, ignore=None):
    """Catch docker errors and issue a warning instead"""
    try:
        yield
    except docker.errors.APIError as e:
        if ignore is None or not isinstance(e, ignore):
            k += e,
            log.warning(msg + " (%s)", *k)
BAIRE Anthony's avatar
BAIRE Anthony committed
143

BAIRE Anthony's avatar
BAIRE Anthony committed
144
145
@contextlib.contextmanager
def report_error(fmt, *k):
BAIRE Anthony's avatar
doc    
BAIRE Anthony committed
146
147
148
149
150
151
152
    """Context manager for logging exceptions

    This function logs exceptions (when leaving the context) with log.error()
    (if the exception inherit from Error) or log.exception() otherwise.

    The log message is prepended with the string generated by: fmt % k
    """
BAIRE Anthony's avatar
BAIRE Anthony committed
153
154
155
156
157
158
159
160
    try:
        yield
    except Exception as e:
        msg = fmt % k
        log_func = log.error if isinstance(e, Error) else log.exception
        log_func("%s (%s)", msg,
                traceback.format_exception_only(type(e), e)[-1].strip())
        raise
161

BAIRE Anthony's avatar
BAIRE Anthony committed
162
163
164
165
166
167
168
169
170
171
172
173
174
def disable_future_warning(fut):
    """Add a dummy callback to a future to prevent asyncio warnings

    Return: the future

    The asynicio module log a warning message when the result of a future is
    not used. This function installs a dummy callback to the future so as to
    avoid this warning. This is useful for futures whose result *may* be
    ignored by the application.
    """
    fut.add_done_callback(lambda f: f.exception())
    return fut

175

176
177
178
179
180
181
182
183
184
def auto_create_task(func):
    """Decorator for forcing the creation of a task when a coroutine function is called

    Return a wrappers that calls the function, create the task on the fly and
    return it. Also it installs a no-op callback to avoid warnings in case the
    result is not used.
    """
    assert asyncio.iscoroutinefunction(func)

BAIRE Anthony's avatar
BAIRE Anthony committed
185
186
    return (lambda *k, **kw:
        disable_future_warning(asyncio.async(func(*k, **kw))))
BAIRE Anthony's avatar
BAIRE Anthony committed
187

188
189
190
191
192
193
194
195
196
197
198
199
200
201
202
203
204
205
def cascade_future(src, dst):
    """propagate the result of a future to another future
    
    This function installs a callback to the future `src`, that propagates its
    result to the future `dst`.
    """
    def callback(fut):
        ex = fut.exception()
        if ex is None:
            dst.set_result(fut.result())
        else:
            dst.set_exception(ex)

    if src.done():
        callback(src)
    else:
        src.add_done_callback(callback)

206
207
208
209
210
211
212
213
214
215
216
217
218
219
220
221
222
223
224
225
226
227
228
async def _make_aiohttp_client(host):
    """Create a aiohttp session for connecting to a docker engine

    `host` is a docker host url (DOCKER_HOST) it may be either a `tcp://`
    or `unix://` url

    Return a tuple `(session, url)` where `session` is a aiohttp client
    session and `url` is the http(s) url of the docker engine
    """
    url = docker.utils.parse_host(host)
    mo = re.match(r"http\+unix:/+(/.*)", url)
    if mo is None:
        # HTTP over TCP
        connector = None
    else:
        # HTTP over unix socket
        url = "http://DUMMY.localhost"
        path = mo.group(1)
        connector = aiohttp.UnixConnector(path)
    session = aiohttp.ClientSession(connector=connector)
    return session, url
def make_aiohttp_client(host):
    return asyncio.get_event_loop().run_until_complete(_make_aiohttp_client(host))
BAIRE Anthony's avatar
todo    
BAIRE Anthony committed
229

230
class Manager:
BAIRE Anthony's avatar
BAIRE Anthony committed
231
232
233
234
235
236
237
238
239
240
241
242
243
244
245
246
247
248
249
250
251
252
253
254
255
256
257
258
259
260
261
262
263
264
265
266
267
268
269
270
271
272
273
274
275
276
277
278
279
280
281
282
283
284
285
286
287
288
289
290
291
292
293
294
295
296
    """A class for scheduling asynchronous jobs on a collection of keys

    (the one-line summary is not very helpful, sorry)
    

    Job submission

    The job is scheduled on key KEY by calling .process(KEY), the function
    returns an asyncio.Future object (which will receive the result)

    If .process(KEY) is called while a job is already running for KEY, then the
    manager arranges the job to be run a second time in a row for the same key


    Job implementation

    This is an abstract class. The job shall be implemented as the coroutine
    named ._process() in the inherited class.

    The manager guarantees that ._process() cannot be called multiple times
    concurrently for the same key

    In case a shutdown is requested (see .shutdown()):
     - all jobs that are not yet started are cancelled
     - running jobs continue until they return or until they try to acquire the
       internal semaphore (which raises ShuttingDown())


    Concurrency

    The job tasks are all started immediately (whatever the number of existing
    jobs)

    It is possible to limit the concurrency to a maximum number of parallel
    tasks. Manager provides an internal semaphore (the number of tokens is set
    in .__init__())

    The semaphore can be locked in two ways:
     - by locking the manager:

            with (yield from self): ... concurrency limited to `nb_tokens`
            tasks ...

     - by calling .run_in_executor (this is for running non-async code):

            yield from self.run_in_executor(func, args...)

    Shutdown

    When .shutdown() is called the Manager ensures that all jobs are properly
    terminated
     - it cancels all jobs that are not yet started
     - it prevents starting new jobs
     - it lets running pending jobs, but interrupts them if they when ther try
       to acquire the internal semaphore

    All cancel/interrupted tasks have their future raise ShuttingDown().

    .shutdown() returns after all pending jobs are terminated.


    Thread safety

    - Manager is *not* thread safe, all public methods must be called from the
      same thread
    """
297

298
    class _Handle:
BAIRE Anthony's avatar
BAIRE Anthony committed
299
        __slots__ = "key", "cur", "nxt", "rescheduled"
300

301
    def __init__(self, nb_tokens=1, *, executor = default_executor, interruptible = False):
BAIRE Anthony's avatar
BAIRE Anthony committed
302
        # {key: _TaskHandler}
303
        self._handles = {}
304
        self._semaphore = asyncio.Semaphore(nb_tokens)
305
        self._shutdown = asyncio.Future()
306
        self._executor = executor
307
        self._interruptible = interruptible
308
309
310
311
312
313
314
315
316
317

    def _create_task(self, hnd):
        assert hnd.nxt is None
        def reset():
            assert not hnd.cur.done()
            nxt = hnd.nxt
            if nxt is not None:
                cascade_future(hnd.cur, nxt)
                hnd.nxt = None

BAIRE Anthony's avatar
BAIRE Anthony committed
318
319
320
321
322
323
            # recreate the 'rescheduled' future and return it
            hnd.rescheduled = disable_future_warning(asyncio.Future())
            return hnd.rescheduled

        hnd.rescheduled = disable_future_warning(asyncio.Future())
        hnd.cur = asyncio.async(self._process(hnd.key, reset, hnd.rescheduled))
324
        hnd.cur.add_done_callback(lambda fut: self._done(hnd))
BAIRE Anthony's avatar
BAIRE Anthony committed
325
        log.debug("task scheduled %r %r", self, hnd.key)
326
        return hnd.cur
327

BAIRE Anthony's avatar
BAIRE Anthony committed
328
329
330
331
332
    def process(self, key):
        """Schedule the job to be run on key `key`

        returns an asyncio.Future (that will provide the result of ._process())
        """
333
        if self._shutdown.done():
334
335
            return self._shutdown

BAIRE Anthony's avatar
BAIRE Anthony committed
336
        hnd = self._handles.get(key)
337
338
        if hnd is None:
            # create handle
BAIRE Anthony's avatar
BAIRE Anthony committed
339
340
            self._handles[key] = hnd = self._Handle()
            hnd.key = key
341
342
            hnd.cur = None
            hnd.nxt = None
BAIRE Anthony's avatar
BAIRE Anthony committed
343
            hnd.rescheduled = None
344
345
346
347
348
349
350
351

        if hnd.cur is None:
            # create task
            return self._create_task(hnd)
        else:
            # reschedule task
            if hnd.nxt is None:
                hnd.nxt = asyncio.Future()
BAIRE Anthony's avatar
BAIRE Anthony committed
352
353
            if not hnd.rescheduled.done():
                hnd.rescheduled.set_result(None)
354
355
356
357
            return hnd.nxt

    def _done(self, hnd):

BAIRE Anthony's avatar
BAIRE Anthony committed
358
        assert hnd is self._handles.get(hnd.key)
359
360
361
362
        assert hnd.cur.done()

        try:
            hnd.cur.result()
363
364
        except ShuttingDown:
            pass
365
        except Exception:
BAIRE Anthony's avatar
BAIRE Anthony committed
366
            log.exception("task %r %r unhandled exception", self, hnd.key)
367
368
369
370

        nxt     = hnd.nxt
        hnd.cur = hnd.nxt = None
        if nxt is None:
BAIRE Anthony's avatar
BAIRE Anthony committed
371
            del self._handles[hnd.key]
372
        else:
373
            cascade_future(self._create_task(hnd), nxt)
374

375

376
377
    @asyncio.coroutine
    def __iter__(self):
BAIRE Anthony's avatar
BAIRE Anthony committed
378
379
380
381
382
383
384
385
386
387
        """Coroutine for locking the internal semaphore
        
        Usage:
            with (yield from manager):
              ...

        Warning:
            after a shutdown is initiated, this function will always raise
            ShuttingDown()
        """
388
        ctx = yield from iter(self._semaphore)
389
        if self._shutdown.done():
390
391
392
393
394
395
            with ctx:
                raise ShuttingDown()
        return ctx


    @asyncio.coroutine
396
    def run_in_executor(self, *k, lock=True):
BAIRE Anthony's avatar
BAIRE Anthony committed
397
398
399
400
401
        """Run a function in a separate thread (with limited concurrency)

        This function locks the internal semaphore and runs the provided
        functionc call in a separate thread (using the executor)
        """
402
403
404
405
406
407
408
409

        def run():
            coro = asyncio.get_event_loop().run_in_executor(self._executor, *k)
            if self._interruptible:
                return next(asyncio.as_completed((coro, self._shutdown)))
            else:
                return coro
        
410
411
        if lock:
            with (yield from self):
412
                return (yield from run())
413
        else:
414
            return (yield from run())
415
416


BAIRE Anthony's avatar
BAIRE Anthony committed
417
    @asyncio.coroutine
BAIRE Anthony's avatar
BAIRE Anthony committed
418
    def _process(self, key, reset, rescheduled):
BAIRE Anthony's avatar
doc    
BAIRE Anthony committed
419
420
421
422
423
424
425
        """Actual implementation of the job (to be reimplemented in inherited classes)

        The Manager class guarantees that this function cannot be called
        multiple times concurrently on the same key (in case the same key is
        submitted multiple times, they Manager will call this function a second
        time after it has terminated).

BAIRE Anthony's avatar
BAIRE Anthony committed
426
427
428
429
        `rescheduled` is a future whose result is set when the job is being
        rescheduled (if process(key) is called before _process(key ...)
        terminates.

BAIRE Anthony's avatar
doc    
BAIRE Anthony committed
430
431
        `reset` is a function that may be called to reset the 'dirty' state of
        this key (this is to avoid calling ._process() a second time if not
BAIRE Anthony's avatar
BAIRE Anthony committed
432
        necessary) in that case, a new `rescheduled` future is returned.
BAIRE Anthony's avatar
doc    
BAIRE Anthony committed
433
        """
434
435
        raise NotImplementedError()

436
    @asyncio.coroutine
437
    def shutdown(self):
BAIRE Anthony's avatar
BAIRE Anthony committed
438
439
440
441
        """Initiate a graceful shutdown

        This coroutine terminates once all tasks are properly terminated.
        """
442
443
        exc = ShuttingDown()
        self._shutdown.set_exception(exc)
444
        self._shutdown.exception()  # to avoid asyncio warnings
445
446
447
        # cancel all 'next' tasks
        for hnd in self._handles.values():
            if hnd.nxt is not None:
448
                hnd.nxt.set_exception(exc)
449
450
                hnd.nxt = None

451
452
453
454
        if not self._interruptible:
            yield from asyncio.gather(
                    *(h.cur for h in self._handles.values() if h.cur is not None),
                    return_exceptions=True)
BAIRE Anthony's avatar
BAIRE Anthony committed
455

456
457

class SandboxManager(Manager):
BAIRE Anthony's avatar
BAIRE Anthony committed
458
459
460
461
462
463
464
465
466
467
468
469
470
471
472
473
474
475
476
477
478
479
480
481
482
483
484
485
486
487
488
489
490
491
492
493
494
495
496
    """Manager for sandbox operation

    This manager handles all sandbox operations (start, stop, commit).

    Operations are requested asynchronously in the database:
     - Webapp.sandbox_state=starting (for starting a sandbox)
     - Webapp.sandbox_state=stopping (for stopping a sandbox)
     - WebappVersion with state=sandbox (for committing a new image)

    All state changes on Webapp.sandbox_state are atomic (e.g: if the user
    requests a stop while the sandbox is starting then the manager finishes
    with starting the sandbox but does not update the state, and it runs
    immediately again to stop the sandbox)

    Whatever is the value of Webapp.sandbox_state, the manager first examines
    commit requests and makes the commit if requested.

    If the container already exists before starting the webapp (not possible in
    normal operations), then a recovery image is committed first.

    When a commit is successful. The image manager is notified for pushing the
    image to the registry and (if it is not a recovery image) to pull it to the
    swarm (because this image will very likely be used soon).

    State changes:

     - sandbox start:
            starting->running     (normal case)
            starting->start_error (error case)

     - sandbox stop:
            stopping->idle        (normal case)
            stopping->stop_error  (error case)

     - image commit:
            sandbox->committed  (normal case)
            sandbox->error      (error case)
            (none)->committed   (recovery version) 
    """
497

498
    def __init__(self, ctrl, nb_threads = NB_SANDBOX_TASKS):
499
        super().__init__(nb_threads)
500
501
502
        self.ctrl = ctrl


BAIRE Anthony's avatar
BAIRE Anthony committed
503
504
    def inspect_sandbox(self, webapp):
        try:
BAIRE Anthony's avatar
BAIRE Anthony committed
505
506
            return self.ctrl.sandbox.inspect_container(
                    self.ctrl.gen_sandbox_name(webapp))
BAIRE Anthony's avatar
BAIRE Anthony committed
507
508
509
        except docker.errors.NotFound:
            return None

BAIRE Anthony's avatar
BAIRE Anthony committed
510
511
512
513
514
515

    @staticmethod
    def filter_commit_version(query, webapp_id):
        """Narrow a WebappVersion query to select the candidate versions to be committed"""
        return (query.
                filter_by(webapp_id=webapp_id,
BAIRE Anthony's avatar
BAIRE Anthony committed
516
                         state = int(VersionState.SANDBOX))
BAIRE Anthony's avatar
BAIRE Anthony committed
517
518
519
                    )

    def _start(self, webapp, version):
520
521
522
523
524
525
        """Start a webapp sandbox

        (to be executed in a thread pool)
        """

        ctrl = self.ctrl
BAIRE Anthony's avatar
BAIRE Anthony committed
526
        ses  = ctrl.session
527
528

        # prepare sandbox parameters
BAIRE Anthony's avatar
BAIRE Anthony committed
529
530
531

        # docker image
        if version is None:
532
            image = "%s:%s" % (ctrl.gen_factory_name(webapp.docker_os),
BAIRE Anthony's avatar
BAIRE Anthony committed
533
                    webapp.docker_os.version)
534
        else:
BAIRE Anthony's avatar
BAIRE Anthony committed
535
            image = "%s:%s" % (webapp.image_name, version.number)
BAIRE Anthony's avatar
BAIRE Anthony committed
536
537

        log.debug("sandbox %r: using image %r", webapp.docker_name, image)
538
539
540
541
542
543
544
545
546
547
548
549

        # safety checks
        # (because docker_name is used it the paths of the external volumes
        if ("/" in webapp.docker_name) or (webapp.docker_name in ("", ".", "..")):
            raise Error("malformatted docker_name")

        uid = webapp.id + 2000
        if uid < 2000:
            # just for safety
            raise Error("bad webapp id")

        # remove stale container (if any)
550
551
        if self.inspect_sandbox(webapp) is not None:
            self._stop(webapp)
552

BAIRE Anthony's avatar
BAIRE Anthony committed
553
        container = webapp.sandbox_name
554
555
        try:
            # prepare the sandbox
556
557
558
559
            # (create ssh keys)
            ctrl.check_host_path("isdir", ctrl.toolbox_path)
            ctrl.check_host_path("isdir", ctrl.sandbox_path)

BAIRE Anthony's avatar
BAIRE Anthony committed
560
            ctrl.sandbox.create_container("busybox:latest", name=container,
561
562
563
564
565
566
567
568
569
570
571
572
573
574
575
576
577
578
579
580
581
582
583
584
585
586
587
588
589
590
591
592
593
594
595
596
597
598
599
600
601
602
603
604
605
606
607
608
609
610
611
612
613
614
615
616
617
618
619
620
621
622
623
624
625
626
627
628
629
630
631
632
633
634
635
636
637
638
639
640
641
642
643
644
645
646
647
648
649
650
651
652
653
654
655
656
657
658
659
660
                    command = ["/bin/sh", "-c", """
set -ex

export PATH="$PATH:/.toolbox/bin"

# clean sandbox dir
rm -rf {sbx}

# create dirs
for dir in {sbx} {etc} {run}
do
    mkdir -p            ${{dir}}
    chown {uid}:65534   ${{dir}}
    chmod 0700          ${{dir}}
done

# xauth file
touch               {run}/XAuthority
chown {uid}:65534   {run}/XAuthority
chmod 0600          {run}/XAuthority

# generate ssh keys
(for type in ecdsa ed25519 rsa
do
    key={etc}/ssh_host_${{type}}_key
    [ -f $key ] || ssh-keygen -N '' -f $key -t $type >&2
    
    echo -n '{hostname}. ' | cat - ${{key}}.pub
done) > {etc}/ssh_known_hosts

# known_host file for allgo-shell
ssh-keygen -H -f {etc}/ssh_known_hosts
chmod 0644       {etc}/ssh_known_hosts
rm -f            {etc}/ssh_known_hosts.old

# authentication key for allgo-shell
rm -f               {etc}/identity
ssh-keygen -N '' -f {etc}/identity
chown {uid}:65534   {etc}/identity

# forced shell for the sshd config 
cat > {etc}/shell <<EOF
#!/bin/sh

export PATH="\$PATH:/.toolbox/bin"

uid=\`id -u\`
shell="\`getent passwd \$uid 2>/dev/null| cut -d : -f 7\`"
if [ -z "\$shell" ] ; then
    shell=/bin/sh
fi

if [ -n "\$SSH_ORIGINAL_COMMAND" ] ; then
    exec "\$shell" -c "\$SSH_ORIGINAL_COMMAND"
else
    exec "\$shell"
fi

EOF
chmod 755 {etc}/shell

# sshd config
cat > {etc}/sshd_config <<EOF
Port 22
Protocol 2

# turned off because it requires creating a 'sshd' user inside the sandbox
UsePrivilegeSeparation no

StrictModes no

ForceCommand /.sandbox/etc/ssh/shell

PermitRootLogin without-password

PubkeyAuthentication yes
AuthorizedKeysFile  /.sandbox/etc/ssh/identity.pub .ssh/authorized_keys .ssh/authorized_keys2

ChallengeResponseAuthentication no
PasswordAuthentication          no

X11Forwarding yes
X11DisplayOffset 10
PrintMotd no
PrintLastLog no
TCPKeepAlive yes

# Allow client to pass locale environment variables
AcceptEnv LANG LC_*

Subsystem sftp internal-sftp

UsePAM no
EOF
                    """.format(uid=uid,
                        hostname = "%s-sandbox-%s" % (ctrl.env, webapp.docker_name),
                        sbx = "/mnt/%s"         % webapp.docker_name,
                        etc = "/mnt/%s/etc/ssh" % webapp.docker_name,
                        run = "/mnt/%s/run"     % webapp.docker_name,
                        )],
661
                    host_config = ctrl.sandbox.create_host_config(
662
663
664
665
                        binds   = {
                            ctrl.sandbox_path: {"bind": "/mnt"},
                            ctrl.toolbox_path: {"bind": "/.toolbox", "mode": "ro"},
                    }))
666
667
            ctrl.sandbox.start(container)
            if ctrl.sandbox.wait(container):
668
669
                log.debug("sandbox %s output:\n%s", webapp.docker_name,
                        ctrl.sandbox.logs(container).decode(errors="replace"))
670
671
672
673
                raise Error("sandbox preparation failed")
            ctrl.sandbox.remove_container(container)

            # create and start the sandbox
674
675
676
677
678

            etc_dir = os.path.join(ctrl.sandbox_path, webapp.docker_name, "etc")
            run_dir = os.path.join(ctrl.sandbox_path, webapp.docker_name, "run")
            ctrl.check_host_path("isdir", etc_dir)
            ctrl.check_host_path("isdir", run_dir)
679
680
681
682

            if version is None and webapp.entrypoint:
                # prepend instructions to initialise a dummy entrypoint
                dn, bn = os.path.split(webapp.entrypoint)
BAIRE Anthony's avatar
todo    
BAIRE Anthony committed
683
                # FIXME: do nothing if entrypoint already exists
684
                prepare = """
685
                    {mkdir}
686
                    test -f {entrypoint} || cat > {entrypoint} <<EOF
687
688
689
690
691
692
693
#!/bin/sh
echo
echo "This is app '{name}' called with parameters '\$@'"
echo
echo "The workdir contains:"
ls -l
EOF
694
                    chmod 0755 -- {entrypoint}
695

696
                """.format( entrypoint  = shlex.quote(webapp.entrypoint),
697
                            name        = webapp.docker_name,
698
699
700
701
702
703
704
705
706
707
708
709
710
711
712
713
                            mkdir       = (("mkdir -p -- %s" % shlex.quote(dn)) if dn else ""))
            else:
                prepare = ""

            command = ["/bin/sh", "-c", """
set -x
export PATH="$PATH:/.toolbox/bin"

{prepare}

# xauth file (needed for X11 forwarding)
touch       /root/.Xauthority
chmod 600   /root/.Xauthority

exec /.toolbox/bin/sshd -D
            """.format(prepare=prepare)]
714

715
            ctrl.sandbox.create_container(image, name=container, hostname=container,
716
                    command = command,
717
718
                    host_config = ctrl.sandbox.create_host_config(
                        binds = {
719
720
721
                            etc_dir: {"bind": "/.sandbox/etc", "mode": "ro"},
                            run_dir: {"bind": "/.sandbox/run", "mode": "rw"},
                            ctrl.toolbox_path: {"bind": "/.toolbox", "mode": "ro"},
722
723
724
                            },
                        # TODO: maybe drop other caps
                        cap_drop = ["NET_RAW"],
725
                        restart_policy = {"Name": "unless-stopped"},
726
                        network_mode = ctrl.sandbox_network,
727
728
729
730
731
                        ))

            ctrl.sandbox.start(container)

        except:
BAIRE Anthony's avatar
BAIRE Anthony committed
732
733
            with docker_warning("cleanup error: unable to remove container %r",
                    container, ignore=docker.errors.NotFound):
734
735
736
                ctrl.sandbox.remove_container(container, force=True)
            raise

BAIRE Anthony's avatar
BAIRE Anthony committed
737
    def _commit(self, webapp, versions):
738
739
740
741
742
743
744
745
746
747
748
        """Commit a webapp sandbox

        (to be executed in a thread pool)

        The image version is looked up in webapp_versions (where state==sandbox).
        
        In case of any error, a recovery version is committed instead (to avoid
        loosing the work done inside the sandbox) and the candidates are put in
        error state.
        """
        ctrl = self.ctrl
BAIRE Anthony's avatar
BAIRE Anthony committed
749
        ses  = ctrl.session
750

BAIRE Anthony's avatar
BAIRE Anthony committed
751
752
753
754
755
756
        # pre-commit checks
        # - ensure that there is exactly one candidate webapp_version with
        #   state=sandbox
        # - otherwise:
        #   - put all candidates in error state
        #   - create a recovery version
757

BAIRE Anthony's avatar
BAIRE Anthony committed
758
759
760
761
762
        # version be committed
        version = None
        
        # error msg (if any)
        error = None
763

BAIRE Anthony's avatar
BAIRE Anthony committed
764
765
        # version ids to be recovered
        recover = ()
766

BAIRE Anthony's avatar
BAIRE Anthony committed
767
768
769
770
771
772
        if len(versions) == 1:
            # normal case (sandbox commit)
            version = versions[0]
            if not version.number:
                error   = "empty version number"
                recover = version.id,
773

BAIRE Anthony's avatar
BAIRE Anthony committed
774
775
776
        elif not versions:
            # sandbox rollback (when user drops a sandbox without committing a new image)
            error     = "dangling sandbox"
777

BAIRE Anthony's avatar
BAIRE Anthony committed
778
779
780
781
782
        else:
            # multiple candidates (should never happen)
            error    = "multiple candidate versions (%s)" % (
                ", ".join(map(repr, sorted(v.number for v in versions))))
            recover = tuple(v.id for v in versions)
783

BAIRE Anthony's avatar
BAIRE Anthony committed
784
785
        # TODO: make 'sandbox' a reserved name

BAIRE Anthony's avatar
BAIRE Anthony committed
786
787
788
        if error:
            changelog = "pre-commit error: " + error
            log.error("sandbox %r version id %r: %s", webapp.docker_name, recover, changelog)
789

BAIRE Anthony's avatar
BAIRE Anthony committed
790
            with ses.begin():
791
792
                # put all candidates in 'error state'
                if recover:
BAIRE Anthony's avatar
BAIRE Anthony committed
793
                    ses.execute('''UPDATE dj_webapp_versions
BAIRE Anthony's avatar
fix sql    
BAIRE Anthony committed
794
795
                            SET changelog=CONCAT(changelog, " [", :changelog, "]"), state=:state
                            WHERE id IN :ids''', dict(changelog=changelog, ids=recover,
BAIRE Anthony's avatar
BAIRE Anthony committed
796
                                state=int(VersionState.ERROR)))
797
798

                # create a recovery version
BAIRE Anthony's avatar
BAIRE Anthony committed
799
800
801
802
803
                version = WebappVersion(
                        webapp_id = webapp.id,
                        number    = time.strftime("recovery-%Y%m%d-%H%M%S"),
                        changelog = changelog,
                        published = False,
BAIRE Anthony's avatar
BAIRE Anthony committed
804
                        state     = int(VersionState.SANDBOX))
BAIRE Anthony's avatar
BAIRE Anthony committed
805
806
807
                ses.add(version)
            ses.refresh(version)
            ses.expunge(version)
808

BAIRE Anthony's avatar
BAIRE Anthony committed
809
        assert version is not None
810

BAIRE Anthony's avatar
BAIRE Anthony committed
811
        # commit the docker image
812

BAIRE Anthony's avatar
BAIRE Anthony committed
813
814
        log.debug("dicts %r %r", webapp.__dict__, version.__dict__)
        log.info("commit sandbox %r version %r", webapp.docker_name, version.number)
815

BAIRE Anthony's avatar
BAIRE Anthony committed
816
817
818
819
        container = webapp.sandbox_name
        next_state = image_size = None
        try:
            # stop the container (if stopping or if creating a new sandbox)
BAIRE Anthony's avatar
BAIRE Anthony committed
820
            if webapp.sandbox_state in (SandboxState.STOPPING, SandboxState.STARTING):
BAIRE Anthony's avatar
BAIRE Anthony committed
821
822
               ctrl.sandbox.stop(container)
               ctrl.sandbox.wait(container)
823

BAIRE Anthony's avatar
BAIRE Anthony committed
824
825
            # commit
            cid = ctrl.sandbox.commit(container, webapp.image_name, version.number)
BAIRE Anthony's avatar
BAIRE Anthony committed
826
            next_state = VersionState.COMMITTED
BAIRE Anthony's avatar
BAIRE Anthony committed
827
828
829
830
831
832
833
            image_size = ctrl.sandbox.inspect_image(cid)["Size"]

            return version, error

        except docker.errors.NotFound:
            error = "commit error: container not found %r" % container
            log.error("%s", error)
BAIRE Anthony's avatar
BAIRE Anthony committed
834
            next_state = VersionState.ERROR
BAIRE Anthony's avatar
BAIRE Anthony committed
835
            image_size = 0
BAIRE Anthony's avatar
BAIRE Anthony committed
836
            ses.execute('''UPDATE dj_webapp_versions
BAIRE Anthony's avatar
BAIRE Anthony committed
837
838
839
840
841
842
843
844
845
846
847
848
849
850
851
852
853
854
855
856
857
858
859
860
                    SET changelog=CONCAT(changelog, " [commit error: sandbox is down]")
                    WHERE id=%d''' % version.id)

            # here we do not propagate the error to allow starting/stopping the
            # sandbox immediately (without going through sandbox_state=:error)
            return None, error

        except Exception as e:
            log.exception("sandbox %r version %r: unexpected commit error (sandbox may still be recovered)",
                    webapp.docker_name, version.number)
            raise

        finally:
            # NOTE: if anything unexpected happens, the version is
            # left in state 'sandbox' and we propagate the exception to
            # ensure the work done inside the sandbox is not dropped
            # and the sandbox is pute in 'error' state
            #
            # The error will not be reported to the user. If this is an issue,
            # then the solution would be to create another error state (to be
            # used when the sandbox is still there).
            # 
            if next_state is not None:
                with ses.begin():
BAIRE Anthony's avatar
BAIRE Anthony committed
861
                    ses.execute("UPDATE dj_webapp_versions SET state=%d, docker_image_size=%d WHERE id=%d"
BAIRE Anthony's avatar
BAIRE Anthony committed
862
                            % (next_state, image_size, version.id))
BAIRE Anthony's avatar
BAIRE Anthony committed
863

864

BAIRE Anthony's avatar
BAIRE Anthony committed
865
    @asyncio.coroutine
BAIRE Anthony's avatar
BAIRE Anthony committed
866
    def _manage_commit(self, webapp, versions, *, force=False):
BAIRE Anthony's avatar
BAIRE Anthony committed
867
868
869
870
871
872
873
874
        """Manage sandbox commit (if needed) and notify the image manager

        The commit is performed if one of these conditions is fulfilled:
        - a commit was requested (there is at least one WebappVersion entry
          with state=sandbox for this app)
        - a docker container exists (for this sandbox) and force is true
        """

BAIRE Anthony's avatar
BAIRE Anthony committed
875
        if not (versions or (force and self.inspect_sandbox(webapp) is not None)):
BAIRE Anthony's avatar
BAIRE Anthony committed
876
877
878
            return
        
        # do the commit
BAIRE Anthony's avatar
BAIRE Anthony committed
879
        version, error = yield from self.run_in_executor(self._commit, webapp, versions)
BAIRE Anthony's avatar
BAIRE Anthony committed
880
881

        # trigger push/pull operations (but do not wait)
BAIRE Anthony's avatar
BAIRE Anthony committed
882
        if version is not None:
883
884

            # push to the registry
BAIRE Anthony's avatar
BAIRE Anthony committed
885
            self.ctrl.image_manager.push(version.id)
886
887
888
889

            if not error:
                # preemptive pull to the swarm
                # (the image may be needed soon)
BAIRE Anthony's avatar
BAIRE Anthony committed
890
                self.ctrl.image_manager.pull(version.id, swarm=True)
891
892


BAIRE Anthony's avatar
BAIRE Anthony committed
893
894
    def _stop(self, webapp):
        """Stop a webapp sandbox
895

BAIRE Anthony's avatar
BAIRE Anthony committed
896
        (to be executed in a thread pool)
897
898
899
        """
        try:
            # FIXME: remove volumes (v=True) too ?
BAIRE Anthony's avatar
BAIRE Anthony committed
900
            self.ctrl.sandbox.remove_container(webapp.sandbox_name, force=True)
901
902
903
        except docker.errors.NotFound:
            pass

904
905

    @asyncio.coroutine
BAIRE Anthony's avatar
BAIRE Anthony committed
906
    def _process(self, webapp_id, reset, rescheduled):
907
908
909
        ctrl = self.ctrl

        log.debug("process sandbox %d", webapp_id)
BAIRE Anthony's avatar
BAIRE Anthony committed
910
911
912
913
914
915
916
917

        ses = ctrl.session
        with ses.begin():
            # current state of the sandbox + load docker os
            webapp = ses.query(Webapp).filter_by(id=webapp_id).one()
            webapp.docker_os

            # version to be started
918
            sandbox_version = webapp.sandbox_version
BAIRE Anthony's avatar
BAIRE Anthony committed
919
920
921
922
923
924
925
926
927
928

            # requested commits
            commit_versions = self.filter_commit_version(ses.query(WebappVersion), webapp_id).all()

            ses.expunge_all()

        # docker name of the sandbox & image
        webapp.sandbox_name = ctrl.gen_sandbox_name(webapp)
        webapp.image_name   = ctrl.gen_image_name(webapp)

BAIRE Anthony's avatar
BAIRE Anthony committed
929
        phase = "inspect"
930
        next_state = fail_state = None
931
        try:
BAIRE Anthony's avatar
BAIRE Anthony committed
932
            if webapp.sandbox_state == SandboxState.STARTING:
933
                # start the sandbox
BAIRE Anthony's avatar
BAIRE Anthony committed
934
                phase = "start"
BAIRE Anthony's avatar
BAIRE Anthony committed
935
936
                next_state = SandboxState.RUNNING
                fail_state = SandboxState.START_ERROR
937

BAIRE Anthony's avatar
BAIRE Anthony committed
938
                # commit (if a sandbox exists)
BAIRE Anthony's avatar
BAIRE Anthony committed
939
                yield from self._manage_commit(webapp, commit_versions, force=True)
BAIRE Anthony's avatar
BAIRE Anthony committed
940

BAIRE Anthony's avatar
BAIRE Anthony committed
941
                if sandbox_version is not None:
942
943
944
945
946
947
                    # ensure version belongs to this application
                    if sandbox_version.webapp_id != webapp.id:
                        raise Error("invalid version id %d (belongs to webapp %d)" % (
                            sandbox_version.id, sandbox_version.webapp_id))

                    # pull requested image
BAIRE Anthony's avatar
BAIRE Anthony committed
948
                    yield from ctrl.image_manager.pull(sandbox_version.id)
949
950
951
952
953
                else:
                    # pull image
                    yield from ctrl.image_manager.sandbox_pull_manager.process((
                        ctrl.gen_factory_name(webapp.docker_os),
                        webapp.docker_os.version))
BAIRE Anthony's avatar
BAIRE Anthony committed
954
955

                # start sandbox
BAIRE Anthony's avatar
BAIRE Anthony committed
956
                yield from self.run_in_executor(self._start, webapp, sandbox_version)
957

BAIRE Anthony's avatar
BAIRE Anthony committed
958
            elif webapp.sandbox_state == SandboxState.STOPPING:
959
                # stop the sandbox
BAIRE Anthony's avatar
BAIRE Anthony committed
960
                phase = "stop"
BAIRE Anthony's avatar
BAIRE Anthony committed
961
962
                next_state = SandboxState.IDLE
                fail_state = SandboxState.STOP_ERROR
963

BAIRE Anthony's avatar
BAIRE Anthony committed
964
                # commit (if requested)
BAIRE Anthony's avatar
BAIRE Anthony committed
965
                yield from self._manage_commit(webapp, commit_versions)
966

BAIRE Anthony's avatar
BAIRE Anthony committed
967
                yield from self.run_in_executor(self._stop, webapp)
968
969

            else:
BAIRE Anthony's avatar
BAIRE Anthony committed
970
971
                # commit (if requested)
                phase = "commit"
BAIRE Anthony's avatar
BAIRE Anthony committed
972
                yield from self._manage_commit(webapp, commit_versions)
BAIRE Anthony's avatar
BAIRE Anthony committed
973

974
975
976
977
        except ShuttingDown:
            next_state = None
            log.info("sandbox %r %s aborted (controller shutdown)", webapp.docker_name, phase)

978
979
980
981
        except BaseException as e:
            next_state = fail_state

            log_func = log.error if isinstance(e, (docker.errors.APIError, Error)) else log.exception
BAIRE Anthony's avatar
BAIRE Anthony committed
982
            log_func ("sandbox %r %s error (%s)", webapp.docker_name, phase,
983
984
985
986
987
988
989
990
                    traceback.format_exception_only(type(e), e)[-1].strip())

        finally:
            if next_state is not None:
                # atomically update the sandbox state in the db
                # (in case another action is requested during the process, eg: the user
                #  stops the sandbox while it is not fully started)
                log.info("sandbox %r is now in state %r", webapp.docker_name, next_state.name)
BAIRE Anthony's avatar
BAIRE Anthony committed
991
                with ses.begin():
BAIRE Anthony's avatar
BAIRE Anthony committed
992
                    ses.execute("UPDATE dj_webapps SET sandbox_state=%d WHERE id=%d AND sandbox_state=%d" %
BAIRE Anthony's avatar
BAIRE Anthony committed
993
                            (next_state, webapp_id, webapp.sandbox_state))
994

995
996
997
            log.debug("done    sandbox %d", webapp_id)


BAIRE Anthony's avatar
BAIRE Anthony committed
998
class JobManager(Manager):
999
    class JobInfo:
BAIRE Anthony's avatar
BAIRE Anthony committed
1000
        __slots__ = "job_id", "ver_id", "ctr_id", "version", "ctr_name", "client", "cpu", "mem", "node_id", "timeout"
1001

1002
    def __init__(self, ctrl):
1003
        super().__init__(0)
BAIRE Anthony's avatar
BAIRE Anthony committed
1004
1005
        self.ctrl = ctrl

1006
1007
1008
1009
1010
1011

    @asyncio.coroutine
    def __iter__(self):
        raise NotImplementedError()


1012
    def _create_job(self, info):
BAIRE Anthony's avatar
BAIRE Anthony committed
1013
1014
        ctrl = self.ctrl
        ses  = ctrl.session
1015
1016
1017
        tmp_img = None

        assert info.ctr_id is None
BAIRE Anthony's avatar
BAIRE Anthony committed
1018
1019
1020

        try:
            with ses.begin():
1021
                job = ses.query(Job).filter_by(id=info.job_id).one()
BAIRE Anthony's avatar
BAIRE Anthony committed
1022
1023
1024
                webapp = job.webapp

                log.info("start job %d (%s:%s)",
1025
                        info.job_id, webapp.docker_name, info.version)
BAIRE Anthony's avatar
BAIRE Anthony committed
1026

BAIRE Anthony's avatar
BAIRE Anthony committed
1027
                job.state = int(JobState.RUNNING)       # pragma: nobranch (TODO: remove (coverage bug))
BAIRE Anthony's avatar
BAIRE Anthony committed
1028
1029
1030

            
            repo = ctrl.gen_image_name(webapp)
1031
            image = "%s:%s" % (repo, info.version)
BAIRE Anthony's avatar
BAIRE Anthony committed
1032
1033
1034
1035

            job_path = ctrl.gen_job_path(job)
            log.debug("job.path: %r", job_path)

1036
1037
1038
            if info.ver_id is None:
                assert info.version == "sandbox"
                image = tmp_img = info.client.commit(ctrl.gen_sandbox_name(webapp), repo, info.version)["Id"]
BAIRE Anthony's avatar
BAIRE Anthony committed
1039
1040
1041
1042
1043
            
            # TODO use another workdir
            # TODO use another uid

            ctrl.check_host_path("isdir", job_path)
1044
            hc = ctrl.sandbox.create_host_config(
1045
                        binds = {job_path: {"bind": "/tmp"}},
1046
1047
1048
                        cap_drop = ["all"],
                        # FIXME: CAP_DAC_OVERRIDE needed because all nfs files have uid,gid=1000,1000
                        cap_add = ["dac_override"],
1049
1050
1051
1052
                        cpu_quota   = (None if info.cpu is None else (info.cpu * 1024)),
                        cpu_period  = (None if info.cpu is None else 1024),
#                        cpu_shares = info.cpu,
                        mem_limit = info.mem,
1053
                    )
1054
1055
1056
1057
            # NOTE: cpu_shares has a different meaining in docker swarm and docker engine
            #  - swarm:  nb of cpus
            #  - engine: 1/1024 share of the total cpu resouces of the machine
            # engine requires  cpu_share>1
1058
            if ctrl.cpu_shares:
BAIRE Anthony's avatar
BAIRE Anthony committed
1059
                # TODO: upgrade docker-py (and use create_host_config)
1060
                hc["CpuShares"] = info.cpu
1061
            log.debug("host_config %r", hc)
1062
            info.ctr_id = info.client.create_container(image, name=info.ctr_name,
1063
                    working_dir = "/tmp",
1064
                    # NOTE: the command line is a little complex, but this is
BAIRE Anthony's avatar
todos    
BAIRE Anthony committed
1065
                    #   to ensure that (TODO write tests for this):
1066
1067
1068
                    #   - no output is lost (we go though a pipe in case the
                    #     app has multiple processes writing to stdout/stderr
                    #     concurrently)
1069
                    #     FIXME: maybe ">>allgo.log  2>&1" is sufficent
1070
1071
                    #   - we get the exit code of the app (not the exit code of
                    #     cat)
BAIRE Anthony's avatar
BAIRE Anthony committed
1072
1073
                    #   - SIGTERM & SIGALRM are forwarded to the process (and
                    #     we call wait again becauce of EINTR)
1074
1075
1076
1077
                    #   - we have no unusual dependencies (only sh, cat, trap,
                    #     kill and mkfifo)
                    #   - we display a warning if the memory limit was reached
                    #     during the job
1078
                    command = ["/bin/sh", "-c", """
1079
1080
1081
1082
                                pid=
                                interrupted=
                                sighnd() {{
                                    (echo
BAIRE Anthony's avatar
BAIRE Anthony committed
1083
                                    echo "====  ALLGO JOB $2  ===="
1084
                                    kill "-$1" "$pid") 2>&1 | tee -a allgo.log
BAIRE Anthony's avatar
BAIRE Anthony committed
1085
                                    trap '' TERM ALRM
1086
1087
                                    interrupted=1
                                }}
BAIRE Anthony's avatar
BAIRE Anthony committed
1088
1089
                                trap "sighnd TERM ABORT"   TERM
                                trap "sighnd ALRM TIMEOUT" ALRM
1090
                                fifo=/.allgo.fifo.{job_id}
1091
                                mkfifo "$fifo" 2>&1 | tee -a allgo.log || exit $?
1092

1093
                                exec cat <"$fifo" | tee -a allgo.log &
1094
1095
1096
1097
1098
1099
                                exec "$@" >"$fifo" 2>&1 &
                                pid=$!

                                wait %2
                                code=$?
                                if [ -n "$interrupted" ] ; then
1100
                                    wait %2
1101
                                    code=$?
1102
                                fi
1103
                                wait %1
BAIRE Anthony's avatar
BAIRE Anthony committed
1104
1105
1106
1107
1108
1109
1110
1111
1112
1113
1114
1115
1116
                                trap '' TERM ALRM

                                [ -n "$interrupted" ] || (
                                    echo
                                    if [ $code -eq 0 ] ; then
                                        echo "====  ALLGO JOB SUCCESS  ===="
                                    else
                                        echo "====  ALLGO JOB ERROR  ===="
                                        echo "process exited with code $code"
                                    fi

                                    failcnt="`cat /sys/fs/cgroup/memory/memory.failcnt`"
                                    if [ "$failcnt" -ne 0 ] ; then
BAIRE Anthony's avatar
BAIRE Anthony committed
1117
                                        echo "WARNING: memory limit was reached (memory.failcnt=$failcnt)"
BAIRE Anthony's avatar
BAIRE Anthony committed
1118
                                    fi
1119
                                ) | tee -a allgo.log 
1120
1121

                                exit $code
BAIRE Anthony's avatar
BAIRE Anthony committed
1122
                        """.format(job_id=job.id),
1123
                        "job%d" % job.id, webapp.entrypoint] + shlex.split(job.param),
BAIRE Anthony's avatar
BAIRE Anthony committed
1124

1125
                    labels = {"allgo.tmp_img": tmp_img or ""},
1126
                    environment=["constraint:node==" + info.node_id],
1127
                    host_config = hc)["Id"]
1128
            info.client.start(info.ctr_id)
1129
1130
1131
1132
1133

            with ses.begin():
                # save the container_id into the db
                job.container_id = info.ctr_id

1134
        except:
BAIRE Anthony's avatar
todo    
BAIRE Anthony committed
1135
            #TODO introduce a state JobState.ERROR
1136
1137
            self._remove_job(info, tmp_img=tmp_img)
            raise
BAIRE Anthony's avatar
BAIRE Anthony committed
1138
1139


1140
1141
    def _remove_job(self, info, *, tmp_img=None):
        ses = self.ctrl.session
BAIRE Anthony's avatar
BAIRE Anthony committed
1142

1143
1144
1145
        # TODO: report launch errors to the user
        # TODO: report exit code to the user
        # TODO: use another uid
BAIRE Anthony's avatar
BAIRE Anthony committed
1146

1147
1148
1149
1150
1151
1152
1153
        def parse_docker_timestamp(value):
            return datetime.datetime.strptime(
                    # limit the precision to the microsecond
                    # (othewise strptime fails)
                    re.sub(r"(\.\d{,6})\d*Z$", r"\1Z", value),
                    # iso8601 format
                    "%Y-%m-%dT%H:%M:%S.%fZ")
BAIRE Anthony's avatar
BAIRE Anthony committed
1154

1155
1156
1157
1158
1159
1160
1161
1162
1163
1164
1165
1166
        with ses.begin():
            job = ses.query(Job).filter_by(id=info.job_id).one()

            exec_time = 0.0
            if info.ctr_id is not None:
                try:
                    js = info.client.inspect_container(info.ctr_id)
                except docker.errors.NotFound:
                    pass
                else:
                    started_at  = js["State"].get("StartedAt", "0001-")
                    finished_at = js["State"].get("FinishedAt")
BAIRE Anthony's avatar
BAIRE Anthony committed
1167

1168
1169
1170
1171
1172
1173
                    # default docker date is '0001-01-01T00:00:00Z'
                    if not started_at.startswith("0001-"):
                        try:
                            exec_time =( parse_docker_timestamp(finished_at)
                                        - parse_docker_timestamp(started_at)
                                        ).total_seconds()
BAIRE Anthony's avatar
BAIRE Anthony committed
1174
1175
                        except Exception: # pragma: nocover
                            log.exception("job %d: unable to compute exec time", info.job_id)
BAIRE Anthony's avatar
BAIRE Anthony committed
1176

1177
                    if tmp_img is None:
BAIRE Anthony's avatar
BAIRE Anthony committed
1178
                        tmp_img = js["Config"]["Labels"].get("allgo.tmp_img") or None
BAIRE Anthony's avatar
BAIRE Anthony committed
1179

1180
1181
                with docker_warning("job %d: cleanup error: unable to remove container", info.job_id):
                    info.client.remove_container(info.ctr_id)
BAIRE Anthony's avatar
BAIRE Anthony committed
1182
1183

            if tmp_img is not None:
1184
1185
1186
1187
1188
                with docker_warning("job %d: cleanup error: unable to remove tmp image", info.job_id):
                    info.client.remove_image(tmp_img)

            job.exec_time = exec_time
            job.state     = int(JobState.DONE)
1189
            job.container_id = None
BAIRE Anthony's avatar
BAIRE Anthony committed
1190
1191
1192
1193
            if job.result == JobResult.NONE:
                # FIXME: maybe we should have a 'unknown' result
                log.warning("job %d has not result, will fallback to 'ERROR'", info.job_id)
                job.result = int(JobResult.ERROR)
1194

BAIRE Anthony's avatar
BAIRE Anthony committed
1195
        log.info("done  job %d (result=%s, duration=%fs)", info.job_id, JobResult(job.result).name, exec_time)
1196
1197
1198


    @asyncio.coroutine
BAIRE Anthony's avatar
BAIRE Anthony committed
1199
    def _finish_job(self, info, reset):
1200
        # wait for container termination (if running)
1201
        if info.ctr_id is not None:
BAIRE Anthony's avatar
BAIRE Anthony committed
1202
1203
1204
1205
1206
1207
1208
1209
1210
1211
1212
            def kill(sig):
                log.debug("kill job %d (signal %d)", info.job_id, sig)
                with docker_warning("unable to kill container %r", info.ctr_id):
                    info.client.kill(info.ctr_id, sig)

            @asyncio.coroutine
            def stop(sig, reason):
                log.info("stop  job %d (%s)", info.job_id, reason)
                try:
                    # graceful kill
                    kill(sig)
BAIRE Anthony's avatar
BAIRE Anthony committed
1213
                    yield from asyncio.wait_for(asyncio.shield(wait_task), timeout=5)
BAIRE Anthony's avatar
BAIRE Anthony committed
1214