Request: Docker logging in stdout, add timestamp

[Tuumke]

Below are the last few lines of my docker log -f subgen, but there is no way to tell when this error occured. Might be nice to see a date + timestamp in front of it?

INFO:     192.168.90.15:39570 - "POST /detect-language?encode=false HTTP/1.1" 500 Internal Server Error
ERROR:    Exception in ASGI application
Traceback (most recent call last):
  File "/usr/local/lib/python3.10/dist-packages/uvicorn/protocols/http/h11_impl.py", line 412, in run_asgi
    result = await app(  # type: ignore[func-returns-value]
  File "/usr/local/lib/python3.10/dist-packages/uvicorn/middleware/proxy_headers.py", line 84, in __call__
    return await self.app(scope, receive, send)
  File "/usr/local/lib/python3.10/dist-packages/fastapi/applications.py", line 1054, in __call__
    await super().__call__(scope, receive, send)
  File "/usr/local/lib/python3.10/dist-packages/starlette/applications.py", line 123, in __call__
    await self.middleware_stack(scope, receive, send)
  File "/usr/local/lib/python3.10/dist-packages/starlette/middleware/errors.py", line 186, in __call__
    raise exc
  File "/usr/local/lib/python3.10/dist-packages/starlette/middleware/errors.py", line 164, in __call__
    await self.app(scope, receive, _send)
  File "/usr/local/lib/python3.10/dist-packages/starlette/middleware/exceptions.py", line 62, in __call__
    await wrap_app_handling_exceptions(self.app, conn)(scope, receive, send)
  File "/usr/local/lib/python3.10/dist-packages/starlette/_exception_handler.py", line 64, in wrapped_app
    raise exc
  File "/usr/local/lib/python3.10/dist-packages/starlette/_exception_handler.py", line 53, in wrapped_app
    await app(scope, receive, sender)
  File "/usr/local/lib/python3.10/dist-packages/starlette/routing.py", line 758, in __call__
    await self.middleware_stack(scope, receive, send)
  File "/usr/local/lib/python3.10/dist-packages/starlette/routing.py", line 778, in app
    await route.handle(scope, receive, send)
  File "/usr/local/lib/python3.10/dist-packages/starlette/routing.py", line 299, in handle
    await self.app(scope, receive, send)
  File "/usr/local/lib/python3.10/dist-packages/starlette/routing.py", line 79, in app
    await wrap_app_handling_exceptions(app, request)(scope, receive, send)
  File "/usr/local/lib/python3.10/dist-packages/starlette/_exception_handler.py", line 64, in wrapped_app
    raise exc
  File "/usr/local/lib/python3.10/dist-packages/starlette/_exception_handler.py", line 53, in wrapped_app
    await app(scope, receive, sender)
  File "/usr/local/lib/python3.10/dist-packages/starlette/routing.py", line 74, in app
    response = await func(request)
  File "/usr/local/lib/python3.10/dist-packages/fastapi/routing.py", line 278, in app
    raw_response = await run_endpoint_function(
  File "/usr/local/lib/python3.10/dist-packages/fastapi/routing.py", line 193, in run_endpoint_function
    return await run_in_threadpool(dependant.call, **values)
  File "/usr/local/lib/python3.10/dist-packages/starlette/concurrency.py", line 42, in run_in_threadpool
    return await anyio.to_thread.run_sync(func, *args)
  File "/usr/local/lib/python3.10/dist-packages/anyio/to_thread.py", line 56, in run_sync
    return await get_async_backend().run_sync_in_worker_thread(
  File "/usr/local/lib/python3.10/dist-packages/anyio/_backends/_asyncio.py", line 2144, in run_sync_in_worker_thread
    return await future
  File "/usr/local/lib/python3.10/dist-packages/anyio/_backends/_asyncio.py", line 851, in run
    result = context.run(func, *args)
  File "/subgen/subgen.py", line 278, in detect_language
    return {"detected_language": get_lang_pair(whisper_languages, detected_lang_code), "language_code": detected_lang_code}
UnboundLocalError: local variable 'detected_lang_code' referenced before assignment
INFO:faster_whisper:Detected language 'en' with probability 0.98
Detected Language: english
Transcribe:   0%|          | 0/30.0 [00:00<?, ?sec/s]DEBUG:faster_whisper:Processing segment at 00:00.000
Transcribe:  38%|███▊      | 11.4/30.0 [00:14<00:24,  1.30s/sec]DEBUG:faster_whisper:Processing segment at 00:29.620
Transcribe: 100%|██████████| 30.0/30.0 [00:32<00:00,  1.07s/sec]
Adjustment: 100%|██████████| 24.8/24.8 [00:00<00:00, 5702.47sec/s]
DEBUG:root:Queue is empty, clearing/releasing VRAM
INFO:     192.168.90.15:55706 - "POST /detect-language?encode=false HTTP/1.1" 200 OK

[McCloudS]

Just added it. If you have DEBUG True, timestamps should print. If you have UPDATE set to true, it should automatically pull it on container restart. Give it a shot.

It isn't perfect, but it at least give some timestamps on the start/end of events.

[McCloudS]

Nothing heard, assuming we're good.

[Tuumke]

Sorry mate, my bad. I hadn't seen the e-mail notification. Just tested, looking good! No timestamp on the "info" debugs?

p.s. Is it weird i find a 6gb image for a docker container big? Is this because of the ./models? If so, might it be an idea to host them outside the docker container? For example host them on a CDN

[McCloudS]

The info ones are from uvicorn and only show on startup, everything else should have logs.

The docker image size is that large because of the CUDA image and associated packages. The Models are downloaded on runtime.