gistfile1.txt

2019-03-31 16:04:17.972 | ERROR    | uvicorn.lifespan.on:main:47 - Exception in 'lifespan' protocol

Traceback (most recent call last):

  File "/usr/lib64/python3.7/asyncio/runners.py", line 43, in run
    return loop.run_until_complete(main)
           │    │                  └ <coroutine object process_plans at 0x7f413f2d7748>
           │    └ <bound method BaseEventLoop.run_until_complete of <_UnixSelectorEventLoop running=True closed=False debug=False>>
           └ <_UnixSelectorEventLoop running=True closed=False debug=False>
  File "/usr/lib64/python3.7/asyncio/base_events.py", line 584, in run_until_complete
    return future.result()
           │      └ <built-in method result of _asyncio.Task object at 0x7f413f3c3d68>
           └ <Task finished coro=<process_plans() done, defined at ./churo.py:55> exception=CalledProcessError(2, 'touch /09161092-625a-aaaa-...

  File "./churo.py", line 80, in process_plans
    create_task(plan_cams(plan, tasks.download.download_cam)) for plan in plans
    │           │               │     │        │                          └ [{'routine': 'download', 'region': 1, 'first_uik': 1, 'last_uik': 2, 'hour_start': 1, 'hour_end': 2, 'id': 1, 'finished': False,...
    │           │               │     │        └ <function download_cam at 0x7f413ef15488>
    │           │               │     └ <module 'tasks.download' from '/home/z/pproj/schitayte-tools/churo/tasks/download.py'>
    │           │               └ <module 'tasks' from '/home/z/pproj/schitayte-tools/churo/tasks/__init__.py'>
    │           └ <function plan_cams at 0x7f413f72d488>
    └ <function create_task at 0x7f413f9536a8>

  File "./churo.py", line 48, in plan_cams
    await gather(*cams)
          │       └ [<Task finished coro=<download_cam() done, defined at /home/z/pproj/schitayte-tools/churo/tasks/download.py:147> exception=Calle...
          └ <function gather at 0x7f413f930378>

  File "./churo.py", line 48, in plan_cams
    await gather(*cams)
          │       └ [<Task finished coro=<download_cam() done, defined at /home/z/pproj/schitayte-tools/churo/tasks/download.py:147> exception=Calle...
          └ <function gather at 0x7f413f930378>

  File "/home/z/pproj/schitayte-tools/churo/tasks/download.py", line 179, in download_cam
    await gather(*[x.wait() for x in state._downloadpool])
          │                          │     └ <Scheduler jobs=31>
          │                          └ {'plans': {1: {'routine': 'download', 'region': 1, 'first_uik': 1, 'last_uik': 2, 'hour_start': 1, 'hour_end': 2, 'id': 1, 'fini...
          └ <function gather at 0x7f413f930378>

  File "/home/z/pproj/schitayte-tools/churo/tasks/download.py", line 179, in download_cam
    await gather(*[x.wait() for x in state._downloadpool])
          │                          │     └ <Scheduler jobs=31>
          │                          └ {'plans': {1: {'routine': 'download', 'region': 1, 'first_uik': 1, 'last_uik': 2, 'hour_start': 1, 'hour_end': 2, 'id': 1, 'fini...
          └ <function gather at 0x7f413f930378>

  File "/home/z/pproj/schitayte-tools/churo/tasks/download.py", line 179, in download_cam
    await gather(*[x.wait() for x in state._downloadpool])
          │                          │     └ <Scheduler jobs=31>
          │                          └ {'plans': {1: {'routine': 'download', 'region': 1, 'first_uik': 1, 'last_uik': 2, 'hour_start': 1, 'hour_end': 2, 'id': 1, 'fini...
          └ <function gather at 0x7f413f930378>
  [Previous line repeated 5 more times]

  File "/home/u1/.virtualenvs/videospeed/lib/python3.7/site-packages/aiojobs/_job.py", line 64, in wait
    await self._close(scheduler.close_timeout)
          │    │      │         └ 0.1
          │    │      └ <Scheduler jobs=31>
          │    └ <bound method Job._close of <Job closed coro=<<coroutine object process_segment at 0x7f413ec85448>>>>
          └ <Job closed coro=<<coroutine object process_segment at 0x7f413ec85448>>>
  File "/home/u1/.virtualenvs/videospeed/lib/python3.7/site-packages/aiojobs/_job.py", line 89, in _close
    await self._task
          │    └ <Task finished coro=<process_segment() done, defined at /home/z/pproj/schitayte-tools/churo/tasks/download.py:90> exception=Call...
          └ <Job closed coro=<<coroutine object process_segment at 0x7f413ec85448>>>
  File "/home/u1/.virtualenvs/videospeed/lib/python3.7/site-packages/aiojobs/_job.py", line 59, in wait
    loop=self._loop)
         │    └ <_UnixSelectorEventLoop running=True closed=False debug=False>
         └ <Job closed coro=<<coroutine object process_segment at 0x7f413ec85448>>>
  File "/home/u1/.virtualenvs/videospeed/lib/python3.7/site-packages/aiojobs/_job.py", line 64, in wait
    await self._close(scheduler.close_timeout)
          │    │      │         └ 0.1
          │    │      └ <Scheduler jobs=31>
          │    └ <bound method Job._close of <Job closed coro=<<coroutine object process_segment at 0x7f413ec85448>>>>
          └ <Job closed coro=<<coroutine object process_segment at 0x7f413ec85448>>>
  File "/home/u1/.virtualenvs/videospeed/lib/python3.7/site-packages/aiojobs/_job.py", line 89, in _close
    await self._task
          │    └ <Task finished coro=<process_segment() done, defined at /home/z/pproj/schitayte-tools/churo/tasks/download.py:90> exception=Call...
          └ <Job closed coro=<<coroutine object process_segment at 0x7f413ec85448>>>
  File "/home/u1/.virtualenvs/videospeed/lib/python3.7/site-packages/aiojobs/_job.py", line 59, in wait
    loop=self._loop)
         │    └ <_UnixSelectorEventLoop running=True closed=False debug=False>
         └ <Job closed coro=<<coroutine object process_segment at 0x7f413ec85448>>>
  File "/home/u1/.virtualenvs/videospeed/lib/python3.7/site-packages/aiojobs/_job.py", line 64, in wait
    await self._close(scheduler.close_timeout)
          │    │      │         └ 0.1
          │    │      └ <Scheduler jobs=31>
          │    └ <bound method Job._close of <Job closed coro=<<coroutine object process_segment at 0x7f413ec85448>>>>
          └ <Job closed coro=<<coroutine object process_segment at 0x7f413ec85448>>>
  File "/home/u1/.virtualenvs/videospeed/lib/python3.7/site-packages/aiojobs/_job.py", line 89, in _close
    await self._task
          │    └ <Task finished coro=<process_segment() done, defined at /home/z/pproj/schitayte-tools/churo/tasks/download.py:90> exception=Call...
          └ <Job closed coro=<<coroutine object process_segment at 0x7f413ec85448>>>
  File "/home/u1/.virtualenvs/videospeed/lib/python3.7/site-packages/aiojobs/_job.py", line 59, in wait
    loop=self._loop)
         │    └ <_UnixSelectorEventLoop running=True closed=False debug=False>
         └ <Job closed coro=<<coroutine object process_segment at 0x7f413ec85448>>>
  File "/home/u1/.virtualenvs/videospeed/lib/python3.7/site-packages/aiojobs/_job.py", line 64, in wait
    await self._close(scheduler.close_timeout)
          │    │      │         └ 0.1
          │    │      └ <Scheduler jobs=31>
          │    └ <bound method Job._close of <Job closed coro=<<coroutine object process_segment at 0x7f413ec85448>>>>
          └ <Job closed coro=<<coroutine object process_segment at 0x7f413ec85448>>>
  File "/home/u1/.virtualenvs/videospeed/lib/python3.7/site-packages/aiojobs/_job.py", line 89, in _close
    await self._task
          │    └ <Task finished coro=<process_segment() done, defined at /home/z/pproj/schitayte-tools/churo/tasks/download.py:90> exception=Call...
          └ <Job closed coro=<<coroutine object process_segment at 0x7f413ec85448>>>
  File "/home/u1/.virtualenvs/videospeed/lib/python3.7/site-packages/aiojobs/_job.py", line 59, in wait
    loop=self._loop)
         │    └ <_UnixSelectorEventLoop running=True closed=False debug=False>
         └ <Job closed coro=<<coroutine object process_segment at 0x7f413ec85448>>>
  File "/home/u1/.virtualenvs/videospeed/lib/python3.7/site-packages/aiojobs/_job.py", line 64, in wait
    await self._close(scheduler.close_timeout)
          │    │      │         └ 0.1
          │    │      └ <Scheduler jobs=31>
          │    └ <bound method Job._close of <Job closed coro=<<coroutine object process_segment at 0x7f413ec85448>>>>
          └ <Job closed coro=<<coroutine object process_segment at 0x7f413ec85448>>>
  File "/home/u1/.virtualenvs/videospeed/lib/python3.7/site-packages/aiojobs/_job.py", line 89, in _close
    await self._task
          │    └ <Task finished coro=<process_segment() done, defined at /home/z/pproj/schitayte-tools/churo/tasks/download.py:90> exception=Call...
          └ <Job closed coro=<<coroutine object process_segment at 0x7f413ec85448>>>
  File "/home/u1/.virtualenvs/videospeed/lib/python3.7/site-packages/aiojobs/_job.py", line 59, in wait
    loop=self._loop)
         │    └ <_UnixSelectorEventLoop running=True closed=False debug=False>
         └ <Job closed coro=<<coroutine object process_segment at 0x7f413ec85448>>>
  File "/home/u1/.virtualenvs/videospeed/lib/python3.7/site-packages/aiojobs/_job.py", line 64, in wait
    await self._close(scheduler.close_timeout)
          │    │      │         └ 0.1
          │    │      └ <Scheduler jobs=31>
          │    └ <bound method Job._close of <Job closed coro=<<coroutine object process_segment at 0x7f413ec85448>>>>
          └ <Job closed coro=<<coroutine object process_segment at 0x7f413ec85448>>>
  File "/home/u1/.virtualenvs/videospeed/lib/python3.7/site-packages/aiojobs/_job.py", line 89, in _close
    await self._task
          │    └ <Task finished coro=<process_segment() done, defined at /home/z/pproj/schitayte-tools/churo/tasks/download.py:90> exception=Call...
          └ <Job closed coro=<<coroutine object process_segment at 0x7f413ec85448>>>
  File "/home/u1/.virtualenvs/videospeed/lib/python3.7/site-packages/aiojobs/_job.py", line 59, in wait
    loop=self._loop)
         │    └ <_UnixSelectorEventLoop running=True closed=False debug=False>
         └ <Job closed coro=<<coroutine object process_segment at 0x7f413ec85448>>>
  File "/home/u1/.virtualenvs/videospeed/lib/python3.7/site-packages/aiojobs/_job.py", line 64, in wait
    await self._close(scheduler.close_timeout)
          │    │      │         └ 0.1
          │    │      └ <Scheduler jobs=31>
          │    └ <bound method Job._close of <Job closed coro=<<coroutine object process_segment at 0x7f413ec85448>>>>
          └ <Job closed coro=<<coroutine object process_segment at 0x7f413ec85448>>>
  File "/home/u1/.virtualenvs/videospeed/lib/python3.7/site-packages/aiojobs/_job.py", line 89, in _close
    await self._task
          │    └ <Task finished coro=<process_segment() done, defined at /home/z/pproj/schitayte-tools/churo/tasks/download.py:90> exception=Call...
          └ <Job closed coro=<<coroutine object process_segment at 0x7f413ec85448>>>
  File "/home/u1/.virtualenvs/videospeed/lib/python3.7/site-packages/aiojobs/_job.py", line 59, in wait
    loop=self._loop)
         │    └ <_UnixSelectorEventLoop running=True closed=False debug=False>
         └ <Job closed coro=<<coroutine object process_segment at 0x7f413ec85448>>>
  File "/home/u1/.virtualenvs/videospeed/lib/python3.7/site-packages/aiojobs/_job.py", line 64, in wait
    await self._close(scheduler.close_timeout)
          │    │      │         └ 0.1
          │    │      └ <Scheduler jobs=31>
          │    └ <bound method Job._close of <Job closed coro=<<coroutine object process_segment at 0x7f413ec85448>>>>
          └ <Job closed coro=<<coroutine object process_segment at 0x7f413ec85448>>>
  File "/home/u1/.virtualenvs/videospeed/lib/python3.7/site-packages/aiojobs/_job.py", line 89, in _close
    await self._task
          │    └ <Task finished coro=<process_segment() done, defined at /home/z/pproj/schitayte-tools/churo/tasks/download.py:90> exception=Call...
          └ <Job closed coro=<<coroutine object process_segment at 0x7f413ec85448>>>
  File "/home/u1/.virtualenvs/videospeed/lib/python3.7/site-packages/aiojobs/_job.py", line 59, in wait
    loop=self._loop)
         │    └ <_UnixSelectorEventLoop running=True closed=False debug=False>
         └ <Job closed coro=<<coroutine object process_segment at 0x7f413ec85448>>>
  File "/home/u1/.virtualenvs/videospeed/lib/python3.7/site-packages/aiojobs/_job.py", line 50, in _do_wait
    return await self._task
                 │    └ <Task finished coro=<process_segment() done, defined at /home/z/pproj/schitayte-tools/churo/tasks/download.py:90> exception=Call...
                 └ <Job closed coro=<<coroutine object process_segment at 0x7f413ec85448>>>
  File "/home/u1/.virtualenvs/videospeed/lib/python3.7/site-packages/aiojobs/_job.py", line 50, in _do_wait
    return await self._task
                 │    └ <Task finished coro=<process_segment() done, defined at /home/z/pproj/schitayte-tools/churo/tasks/download.py:90> exception=Call...
                 └ <Job closed coro=<<coroutine object process_segment at 0x7f413ec85448>>>
  File "/home/u1/.virtualenvs/videospeed/lib/python3.7/site-packages/aiojobs/_job.py", line 50, in _do_wait
    return await self._task
                 │    └ <Task finished coro=<process_segment() done, defined at /home/z/pproj/schitayte-tools/churo/tasks/download.py:90> exception=Call...
                 └ <Job closed coro=<<coroutine object process_segment at 0x7f413ec85448>>>
  [Previous line repeated 5 more times]

  File "/home/z/pproj/schitayte-tools/churo/tasks/download.py", line 120, in process_segment
    await download_segment(tmp, camid, timestart)
          │                │    │      └ datetime.datetime(2018, 10, 11, 1, 0, tzinfo=datetime.timezone(datetime.timedelta(seconds=10800)))
          │                │    └ '09161092-625a-aaaa-aaaa-64db8b377dbf-sub'
          │                └ PosixPath('/09161092-625a-aaaa-aaaa-64db8b377dbf-sub-1-0-1.flv')
          └ <function download_segment at 0x7f413ef150d0>

  File "/home/z/pproj/schitayte-tools/churo/tasks/download.py", line 37, in download_segment
    await sh(cmd)
          │  └ 'touch /09161092-625a-aaaa-aaaa-64db8b377dbf-sub-1-0-1.flv; sleep 3; ls /drh'
          └ <function sh at 0x7f413f2de048>

  File "/home/z/pproj/schitayte-tools/churo/tasks/tools.py", line 64, in sh
    raise CalledProcessError(proc.returncode, cmd, stdout, stderr)
          │                  │    │           │    │       └ b"touch: cannot touch '/09161092-625a-aaaa-aaaa-64db8b377dbf-sub-1-0-1.flv': Permission denied\nls: cannot access '/drh': No suc...
          │                  │    │           │    └ b''
          │                  │    │           └ 'touch /09161092-625a-aaaa-aaaa-64db8b377dbf-sub-1-0-1.flv; sleep 3; ls /drh'
          │                  │    └ 2
          │                  └ <Process 30467>
          └ <class 'subprocess.CalledProcessError'>

subprocess.CalledProcessError: Command 'touch /09161092-625a-aaaa-aaaa-64db8b377dbf-sub-1-0-1.flv; sleep 3; ls /drh' returned non-zero exit status 2.


During handling of the above exception, another exception occurred:


Traceback (most recent call last):

  File "./churo.py", line 232, in <module>
    cli(auto_envvar_prefix='CHURO')
    └ <click.core.Group object at 0x7f413f2db6a0>

  File "/home/u1/.virtualenvs/videospeed/lib/python3.7/site-packages/click/core.py", line 764, in __call__
    return self.main(*args, **kwargs)
           │    │     │       └ {'auto_envvar_prefix': 'CHURO'}
           │    │     └ ()
           │    └ <bound method BaseCommand.main of <click.core.Group object at 0x7f413f2db6a0>>
           └ <click.core.Group object at 0x7f413f2db6a0>
  File "/home/u1/.virtualenvs/videospeed/lib/python3.7/site-packages/click/core.py", line 717, in main
    rv = self.invoke(ctx)
         │    │      └ <click.core.Context object at 0x7f413f2dbf98>
         │    └ <bound method MultiCommand.invoke of <click.core.Group object at 0x7f413f2db6a0>>
         └ <click.core.Group object at 0x7f413f2db6a0>
  File "/home/u1/.virtualenvs/videospeed/lib/python3.7/site-packages/click/core.py", line 1137, in invoke
    return _process_result(sub_ctx.command.invoke(sub_ctx))
           │               │       │       │      └ <click.core.Context object at 0x7f413f6fde48>
           │               │       │       └ <bound method MultiCommand.invoke of <click.core.Group object at 0x7f413f2db588>>
           │               │       └ <click.core.Group object at 0x7f413f2db588>
           │               └ <click.core.Context object at 0x7f413f6fde48>
           └ <function MultiCommand.invoke.<locals>._process_result at 0x7f413f2de1e0>
  File "/home/u1/.virtualenvs/videospeed/lib/python3.7/site-packages/click/core.py", line 1137, in invoke
    return _process_result(sub_ctx.command.invoke(sub_ctx))
           │               │       │       │      └ <click.core.Context object at 0x7f413f2f78d0>
           │               │       │       └ <bound method Command.invoke of <click.core.Command object at 0x7f413f2db7b8>>
           │               │       └ <click.core.Command object at 0x7f413f2db7b8>
           │               └ <click.core.Context object at 0x7f413f2f78d0>
           └ <function MultiCommand.invoke.<locals>._process_result at 0x7f413f307158>
  File "/home/u1/.virtualenvs/videospeed/lib/python3.7/site-packages/click/core.py", line 956, in invoke
    return ctx.invoke(self.callback, **ctx.params)
           │   │      │    │           │   └ {'elect_date': datetime.datetime(2018, 10, 11, 0, 0), 'download': True, 'merge': True, 'export': True}
           │   │      │    │           └ <click.core.Context object at 0x7f413f2f78d0>
           │   │      │    └ <function plans_run at 0x7f413f2de510>
           │   │      └ <click.core.Command object at 0x7f413f2db7b8>
           │   └ <bound method Context.invoke of <click.core.Context object at 0x7f413f2f78d0>>
           └ <click.core.Context object at 0x7f413f2f78d0>
  File "/home/u1/.virtualenvs/videospeed/lib/python3.7/site-packages/click/core.py", line 555, in invoke
    return callback(*args, **kwargs)
           │         │       └ {'elect_date': datetime.datetime(2018, 10, 11, 0, 0), 'download': True, 'merge': True, 'export': True}
           │         └ ()
           └ <function plans_run at 0x7f413f2de510>

  File "./churo.py", line 145, in plans_run
    asyncio.run(process_plans(**kw))
    │       │   │               └ {'download': True, 'merge': True, 'export': True}
    │       │   └ <function process_plans at 0x7f413f2de0d0>
    │       └ <function run at 0x7f413f930ae8>
    └ <module 'asyncio' from '/usr/lib64/python3.7/asyncio/__init__.py'>

  File "/usr/lib64/python3.7/asyncio/runners.py", line 46, in run
    _cancel_all_tasks(loop)
    │                 └ <_UnixSelectorEventLoop running=True closed=False debug=False>
    └ <function _cancel_all_tasks at 0x7f413f8d6510>
  File "/usr/lib64/python3.7/asyncio/runners.py", line 62, in _cancel_all_tasks
    tasks.gather(*to_cancel, loop=loop, return_exceptions=True))
    │     │       │          │    └ <_UnixSelectorEventLoop running=True closed=False debug=False>
    │     │       │          └ <_UnixSelectorEventLoop running=True closed=False debug=False>
    │     │       └ {<Task cancelled coro=<Process._read_stream() done, defined at /usr/lib64/python3.7/asyncio/subprocess.py:156>>, <Task cancelled...
    │     └ <function gather at 0x7f413f930378>
    └ <module 'asyncio.tasks' from '/usr/lib64/python3.7/asyncio/tasks.py'>
  File "/usr/lib64/python3.7/asyncio/base_events.py", line 571, in run_until_complete
    self.run_forever()
    │    └ <bound method BaseEventLoop.run_forever of <_UnixSelectorEventLoop running=True closed=False debug=False>>
    └ <_UnixSelectorEventLoop running=True closed=False debug=False>
  File "/usr/lib64/python3.7/asyncio/base_events.py", line 539, in run_forever
    self._run_once()
    │    └ <bound method BaseEventLoop._run_once of <_UnixSelectorEventLoop running=True closed=False debug=False>>
    └ <_UnixSelectorEventLoop running=True closed=False debug=False>
  File "/usr/lib64/python3.7/asyncio/base_events.py", line 1775, in _run_once
    handle._run()
    │      └ <bound method Handle._run of <Handle <TaskWakeupMethWrapper object at 0x7f413ec7c348>(<Future cancelled>)>>
    └ <Handle <TaskWakeupMethWrapper object at 0x7f413ec7c348>(<Future cancelled>)>
  File "/usr/lib64/python3.7/asyncio/events.py", line 88, in _run
    self._context.run(self._callback, *self._args)
    │    │        │   │    │           │    └ (<Future cancelled>,)
    │    │        │   │    │           └ <Handle <TaskWakeupMethWrapper object at 0x7f413ec7c348>(<Future cancelled>)>
    │    │        │   │    └ <TaskWakeupMethWrapper object at 0x7f413ec7c348>
    │    │        │   └ <Handle <TaskWakeupMethWrapper object at 0x7f413ec7c348>(<Future cancelled>)>
    │    │        └ <built-in method run of Context object at 0x7f413ec834c8>
    │    └ <Context object at 0x7f413ec834c8>
    └ <Handle <TaskWakeupMethWrapper object at 0x7f413ec7c348>(<Future cancelled>)>
> File "/home/u1/.virtualenvs/videospeed/lib/python3.7/site-packages/uvicorn/lifespan/on.py", line 43, in main
    await app_instance(self.receive, self.send)
          │            │    │        │    └ <bound method LifespanOn.send of <uvicorn.lifespan.on.LifespanOn object at 0x7f413ef227f0>>
          │            │    │        └ <uvicorn.lifespan.on.LifespanOn object at 0x7f413ef227f0>
          │            │    └ <bound method LifespanOn.receive of <uvicorn.lifespan.on.LifespanOn object at 0x7f413ef227f0>>
          │            └ <uvicorn.lifespan.on.LifespanOn object at 0x7f413ef227f0>
          └ <bound method Lifespan.asgi of <starlette.routing.Lifespan object at 0x7f413f2a16a0>>
  File "/home/u1/.virtualenvs/videospeed/lib/python3.7/site-packages/starlette/routing.py", line 481, in asgi
    message = await receive()
    │               └ <bound method LifespanOn.receive of <uvicorn.lifespan.on.LifespanOn object at 0x7f413ef227f0>>
    └ {'type': 'lifespan.startup'}
  File "/home/u1/.virtualenvs/videospeed/lib/python3.7/site-packages/uvicorn/lifespan/on.py", line 73, in receive
    return await self.receive_queue.get()
                 │    │             └ <bound method Queue.get of <Queue at 0x7f413ec7f5f8 maxsize=0 tasks=1>>
                 │    └ <Queue at 0x7f413ec7f5f8 maxsize=0 tasks=1>
                 └ <uvicorn.lifespan.on.LifespanOn object at 0x7f413ef227f0>
  File "/usr/lib64/python3.7/asyncio/queues.py", line 159, in get
    await getter
          └ <Future cancelled>

concurrent.futures._base.CancelledError
Traceback (most recent call last):
  File "/home/z/pproj/schitayte-tools/churo/tasks/download.py", line 120, in process_segment
    await download_segment(tmp, camid, timestart)
  File "/home/z/pproj/schitayte-tools/churo/tasks/download.py", line 37, in download_segment
    await sh(cmd)
  File "/home/z/pproj/schitayte-tools/churo/tasks/tools.py", line 64, in sh
    raise CalledProcessError(proc.returncode, cmd, stdout, stderr)
subprocess.CalledProcessError: Command 'touch /09161092-625a-aaaa-aaaa-64db8b377dbf-sub-1-0-1.flv; sleep 3; ls /drh' returned non-zero exit status 2.