Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Optionally log tabbyAPI output to a file in addtion to stdout #228

Closed

Conversation

strikeoncmputrz
Copy link

This PR makes logging to file in JSON format an option at runtime in support of bare metal systemd implementations.

Why should this feature be added?
Tabby should include the option to output logs to a file. Further, it should support serializing the logs to JSON as an option. It is easier to ingest a web application's logs to common solutions like the Elastic Stack when the application writes log output to disk as structured data. The file that the logs are written to can be specified via an environment variable. log_to_file is set to false by default. If enabled, tabbyAPI will write logs to both stdout and to ./tabbyAPI.log unless TABBY_LOG_FILE is specified.

Examples

{                                                                                              
  "text": "2024-10-27T22:12:25.237468-0400 INFO 192.168.1.111:60326 - \"POST /v1/chat/completions HTTP/1.1\" 200\n",                                                                          
  "record": {                                                                                                                                                                                 
    "elapsed": {                                                                                                                                                                              
      "repr": "0:04:55.862488",                                                                
      "seconds": 295.862488                                                                                                                                                                   
    },                                                                                                                                                                                        
    "exception": null,                                                                                                                                                                        
    "extra": {},                                                                               
    "file": {                                                                                                                                                                                 
      "name": "logger.py",
      "path": "/home/x0xxin/Repos/tabbyAPI/common/logger.py"
    },
    "function": "emit",
    "level": {
    "level": {   "                                                                             
      "icon": "ℹ️ ",                                                                            
      "name": "INFO",
      "no": 20
    },
    "line": 80,
    "message": "192.168.1.111:60326 - \"POST /v1/chat/completions HTTP/1.1\" 200",
    "module": "logger",
    "name": "common.logger",
    "process": {
      "id": 949072,
      "name": "MainProcess"
    },
    "thread": {
      "id": 134030637741888,
      "name": "MainThread"
    },
    "time": {
      "repr": "2024-10-27 22:12:25.237468-04:00",
      "timestamp": 1730081545.237468
    }
  }
}
{                                                                                                                                                                                             
  "text": "2024-10-27T22:12:25.237468-0400 INFO 192.168.1.111:60326 - \"POST /v1/chat/completions HTTP/1.1\" 200\n",                                                                          
  "record": {                                                                                                                                                                                 
    "elapsed": {                                                                                                                                                                              
      "repr": "0:04:55.862488",                                                                                                                                                               
      "seconds": 295.862488                                                                                                                                                                   
    },                                                                                                                                                                                        
    "exception": null,                                                                                                                                                                        
    "extra": {},                                                                                                                                                                              
    "file": {                                                                                                                                                                                 
      "name": "logger.py",                                                                                                                                                                    
      "path": "/home/x0xxin/Repos/tabbyAPI/common/logger.py"                                                                                                                                  
    },                                                                                                                                                                                        
    "function": "emit",                                                                                                                                                                       
    "level": {                                                                                                                                                                                
      "icon": "ℹ️ ",                                                                                                                                                                           
      "name": "INFO",                                                                                                                                                                         
      "no": 20                                                                                                                                                                                
    },                                                                                                                                                                                        
    "line": 80,                                                                                                                                                                               
    "message": "192.168.1.111:60326 - \"POST /v1/chat/completions HTTP/1.1\" 200",                                                                                                            
    "module": "logger",                                                                                                                                                                       
    "name": "common.logger",                                                                                                                                                                  
    "process": {                                                                                                                                                                              
      "id": 949072,                                                                                                                                                                           
      "name": "MainProcess"                                                                                                                                                                   
    },                                                                                                                                                                                        
    "thread": {                                                                                                                                                                               
      "id": 134030637741888,                                                                                                                                                                  
    },                                                                                                                                                                                        
    "time": {                                                                                                                                                                                 
      "repr": "2024-10-27 22:12:25.237468-04:00",                                                                                                                                             
      "timestamp": 1730081545.237468                                                                                                                                                          
    }                                                                                                                                                                                         
  }                                                                                                                                                                                           
}                                    
  "record": {
    "elapsed": {
      "repr": "0:04:55.863886",
      "seconds": 295.863886
    },
    "exception": null,
    "extra": {},
    "file": {
      "name": "chat_completion.py",
    "extra": {},                                                                               
    "file": {
      "name": "chat_completion.py",
      "path": "/home/x0xxin/Repos/tabbyAPI/endpoints/OAI/utils/chat_completion.py"
    },
    "function": "stream_generate_chat_completion",
    "level": {
    "level": {   "                                                                             
      "icon": "ℹ️ ",                                                                            
      "name": "INFO",
      "no": 20
    },
    "line": 291,
    "message": "Received chat completion streaming request 23bfb52174bd4ee58eb68ef7e3875eb8",
    "module": "chat_completion",
    "name": "endpoints.OAI.utils.chat_completion",
    "process": {
      "id": 949072,
      "name": "MainProcess"
    },
    "thread": {
      "id": 134030637741888,
      "name": "MainThread"
    },
    "time": {
      "repr": "2024-10-27 22:12:25.238866-04:00",
      "timestamp": 1730081545.238866
    }
  }
}
{
  "text": "2024-10-27T22:12:32.564042-0400 INFO Finished chat completion streaming request 23bfb52174bd4ee58eb68ef7e3875eb8\n",
  "record": {
    "elapsed": {
      "repr": "0:05:03.189062",
      "seconds": 303.189062
    },
    "exception": null,
    "extra": {},
    "file": {
      "name": "chat_completion.py",
      "path": "/home/x0xxin/Repos/tabbyAPI/endpoints/OAI/utils/chat_completion.py"
    },
    "function": "stream_generate_chat_completion",
    "level": {
    "level": {   "                                                                             
      "icon": "ℹ️ ",                                                                            
      "name": "INFO",
      "no": 20
    },
    "line": 356,
    "message": "Finished chat completion streaming request 23bfb52174bd4ee58eb68ef7e3875eb8",
    "module": "chat_completion",
    "name": "endpoints.OAI.utils.chat_completion",
    "process": {
      "id": 949072,
      "name": "MainProcess"
    },
    "thread": {
      "id": 134030637741888,
      "name": "MainThread"
    },
    "time": {
      "repr": "2024-10-27 22:12:32.564042-04:00",
      "timestamp": 1730081552.564042
    }
  }
}
{
  "text": "2024-10-27T22:12:32.565411-0400 INFO Metrics (ID: 23bfb52174bd4ee58eb68ef7e3875eb8): 431 tokens generated in 7.28 seconds (Queue: 0.0 s, Process: 0 cached tokens and 7437 new toke
ns at 7992.09 T/s, Generate: 67.93 T/s, Context: 7437 tokens) \n",
  "record": {
    "elapsed": {
      "repr": "0:05:03.190431",
      "seconds": 303.190431
    },
    "exception": null,
    "extra": {},
    "file": {
      "name": "gen_logging.py",
      "path": "/home/x0xxin/Repos/tabbyAPI/common/gen_logging.py"
    },
    "function": "log_metrics",
    "level": {
    "level": {   "                                                                             
      "icon": "ℹ️ ",                                                                            
      "name": "INFO",
      "no": 20
    },
    "line": 100,
    "message": "Metrics (ID: 23bfb52174bd4ee58eb68ef7e3875eb8): 431 tokens generated in 7.28 seconds (Queue: 0.0 s, Process: 0 cached tokens and 7437 new tokens at 7992.09 T/s, Generate: 67.
93 T/s, Context: 7437 tokens) ",
    "module": "gen_logging",
    "name": "common.gen_logging",
    "process": {
      "id": 949072,
      "name": "MainProcess"
    },
    "thread": {
      "id": 134030637741888,
      "name": "MainThread"
    },
    "time": {
      "repr": "2024-10-27 22:12:32.565411-04:00",
      "timestamp": 1730081552.565411
    }
  }
}

Additional context
You guys rock. No hard feelings if you think this is unnecessary. If my changes don't meet your standards I am happy to adjust as needed.

@bdashore3
Copy link
Member

I'm not against this PR, but is this a generalized standard? Programs that I've previously run purely log stdout to a logfile for later.

@strikeoncmputrz
Copy link
Author

I'm not against this PR, but is this a generalized standard? Programs that I've previously run purely log stdout to a logfile for later.

I appreciate your willingness to consider my PR and have to admit that I don't think it's a generalized standard to write to a log file. Logging to stdout by default is useful, especially for containers and debugging. I think that more robust logging options are driven by use cases that benefit from centralized collection, like securing a service or performance analysis. Logging to stdout or to the journal can make it more complex to extract, transform and load (ETL) metrics and events. I think this is one reason why services like Apache and Nginx log to specific files by default.

I didn't realize how full-featured logger is. It's awesome that it supports log rotation and size limits out of the box. It's also hugely beneficial for ETL that logger can serialize the events to JSON.

My use case for logging to file is ingesting the tabby's events into the Elastic stack to better track performance given different models, variable cache size, and tensor parallelism enabled or disabled. JSON's structure makes ETL far simpler and efficient. I'm creating a TabbyAPI Elastic Agent integration. Rather than writing multiple custom grok parsers I can simply reference the JSON keys.

@strikeoncmputrz
Copy link
Author

@bdashore3 I resolved the formatting issues that ruff reported and merged master into the branch.

@strikeoncmputrz strikeoncmputrz deleted the optional_log_file branch November 9, 2024 01:55
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

2 participants