use logging instead of prints

[dineshyv]

What does this PR do?

This PR moves all print statements to use logging. Things changed:

• Had to add await start_trace("sse_generator") to server.py to actually get tracing working. else was not seeing any logs
• If no telemetry provider is provided in the run.yaml, we will write to stdout
• by default, the logs are going to be in JSON, but we expose an option to configure to output in a human readable way.

Test Plan

json output:

INFO:     ::1:50078 - "POST /alpha/agents/turn/create HTTP/1.1" 200 OK
{"timestamp": "2024-11-21T10:46:28.549597", "trace_id": "_m5MRCvkT7W9", "span_id": "i7nFQUerS4ea", "span_name": "sse_generator.retrieve_rag_context", "type": "log", "severity": "INFO", "message": "Loading sentence transformer for all-MiniLM-L6-v2..."}
{"timestamp": "2024-11-21T10:46:32.083074", "trace_id": "_m5MRCvkT7W9", "span_id": "i7nFQUerS4ea", "span_name": "sse_generator.retrieve_rag_context", "type": "log", "severity": "INFO", "message": "Use pytorch device_name: mps"}
{"timestamp": "2024-11-21T10:46:32.083133", "trace_id": "_m5MRCvkT7W9", "span_id": "i7nFQUerS4ea", "span_name": "sse_generator.retrieve_rag_context", "type": "log", "severity": "INFO", "message": "Load pretrained SentenceTransformer: all-MiniLM-L6-v2"}
Batches: 100% 1/1 [00:00<00:00,  4.34it/s]
{"timestamp": "2024-11-21T10:46:34.512107", "trace_id": "_m5MRCvkT7W9", "span_id": "i7nFQUerS4ea", "span_name": "sse_generator.retrieve_rag_context", "type": "log", "severity": "INFO", "message": "HTTP Request: POST http://localhost:8000/api/v2/tenants/default_tenant/databases/default_database/collections/ae039506-7bdf-412c-8bce-b25ff4237d79/query \"HTTP/1.1 200 OK\""}
{"timestamp": "2024-11-21T10:46:34.524691", "trace_id": "_m5MRCvkT7W9", "span_id": "5clgIM-hQuaI", "span_name": "sse_generator", "type": "log", "severity": "INFO", "message": "role='user' content='What are the top 5 topics that were explained in the documentation? Only list succinct bullet points.' context='Here are the retrieved documents for relevant context:\\n=== START-RETRIEVED-CONTEXT ===\\n\\nid:num-1; content:_\\nthe template from Llama2 to better support multiturn conversations. The same text\\nin the Llama3 Instruct format would look like this:\\n\\n.. code-block:: text\\n\\n    <|begin_of_text|><|start_header_id|>system<|end_header_id|>\\n\\n    You are a helpful, res...<more>...the default setting for our recipes.\\n\\n.. note::\\n\\n  Another common paradigm is \"mixed-precision\" training: where model weights are in ``bfloat16`` (or ``fp16``), and optimizer\\n  states are in ``fp32``. Currently, we don\\'t support mixed-precision training in torchtune.\\n\\n*Sounds great! How do I use it?*\\n\\nSimply use the ``dtype`` flag or config entry in all our recipes! For example, to use half-precision training in ``bf16``,\\nset ``dtype=bf16``.\\n\\n.. _\\n\\n=== END-RETRIEVED-CONTEXT ===\\n'"}

human readable output:

INFO:     Uvicorn running on http://['::', '0.0.0.0']:5000 (Press CTRL+C to quit)
INFO:     ::1:49964 - "GET /alpha/providers/list HTTP/1.1" 200 OK
INFO:     ::1:49964 - "GET /alpha/shields/list HTTP/1.1" 200 OK
/Users/dineshyv/code/llama-stack/llama_stack/distribution/routers/routing_tables.py:299: PydanticDeprecatedSince20: `parse_obj_as` is deprecated. Use `pydantic.TypeAdapter.validate_python` instead. Deprecated in Pydantic V2.0 to be removed in V3.0. See Pydantic V2 Migration Guide at https://errors.pydantic.dev/2.9/migration/
  memory_bank = parse_obj_as(
/Users/dineshyv/miniconda3/envs/llamastack-together/lib/python3.10/site-packages/pydantic/main.py:1138: PydanticDeprecatedSince20: The `json` method is deprecated; use `model_dump_json` instead. Deprecated in Pydantic V2.0 to be removed in V3.0. See Pydantic V2 Migration Guide at https://errors.pydantic.dev/2.9/migration/
  warnings.warn(
21:37:14.710 [INFO] [register_memory_bank] HTTP Request: POST http://localhost:8000/api/v2/tenants/default_tenant/databases/default_database/collections "HTTP/1.1 200 OK"
INFO:     ::1:49964 - "POST /alpha/memory-banks/register HTTP/1.1" 200 OK
INFO:     ::1:49964 - "GET /alpha/models/list HTTP/1.1" 200 OK
INFO:     ::1:49964 - "POST /alpha/agents/create HTTP/1.1" 200 OK
INFO:     ::1:49964 - "POST /alpha/agents/session/create HTTP/1.1" 200 OK
INFO:     ::1:49964 - "POST /alpha/agents/turn/create HTTP/1.1" 200 OK
21:37:14.762 [INFO] [sse_generator.retrieve_rag_context] Loading sentence transformer for all-MiniLM-L6-v2...
21:37:18.553 [INFO] [sse_generator.retrieve_rag_context] Use pytorch device_name: mps
21:37:18.553 [INFO] [sse_generator.retrieve_rag_context] Load pretrained SentenceTransformer: all-MiniLM-L6-v2
Batches: 100% 1/1 [00:00<00:00,  3.61it/s]
21:37:21.141 [INFO] [sse_generator.retrieve_rag_context] HTTP Request: POST http://localhost:8000/api/v2/tenants/default_tenant/databases/default_database/collections/ae039506-7bdf-412c-8bce-b25ff4237d79/query "HTTP/1.1 200 OK"

[raghotham]

Looks good. Can you update the logging format to make it so that the logs are machine parseable?

[ashwinb]

these should be log.exception() and then you don't need the additional param

[ashwinb]

maybe log -> logger, but change error to exception wherever we are in the handler