-
Notifications
You must be signed in to change notification settings - Fork 0
Debugging Guide
This guide provides systematic procedures for debugging TMI issues including debug logging, log analysis, browser developer tools, and database queries.
TMI supports multiple log levels to control verbosity:
Log Levels:
-
debug- Detailed diagnostic information -
info- General informational messages (default) -
warn- Warning messages for potentially harmful situations -
error- Error messages for serious problems
Enable debug logging:
# Via environment variable
export LOG_LEVEL=debug
./bin/tmiserver
# Via configuration file
echo "log_level: debug" >> config-development.yml
# Via Docker
docker run -e LOG_LEVEL=debug tmi-serverText format (human-readable, development):
export LOG_FORMAT=textExample output:
2025-01-15T10:30:00Z INFO Server starting on :8080
2025-01-15T10:30:01Z DEBUG Connected to PostgreSQL host=localhost port=5432
2025-01-15T10:30:01Z DEBUG Connected to Redis host=localhost port=6379
JSON format (structured, production):
export LOG_FORMAT=jsonExample output:
{"time":"2025-01-15T10:30:00Z","level":"INFO","msg":"Server starting on :8080"}
{"time":"2025-01-15T10:30:01Z","level":"DEBUG","msg":"Connected to PostgreSQL","host":"localhost","port":5432}Enable debug logging for specific components:
# Authentication debugging
export LOG_LEVEL=debug
export AUTH_DEBUG=true
# Database query logging
export DB_LOG_QUERIES=true
# WebSocket debugging
export WS_DEBUG=true
# Webhook debugging
export WEBHOOK_DEBUG=trueSpecify log file location:
# Write logs to file
export LOG_FILE=/var/log/tmi/server.log
./bin/tmiserver
# Or in configuration
log:
level: debug
format: json
file: /var/log/tmi/server.logLog rotation (use logrotate):
# /etc/logrotate.d/tmi
/var/log/tmi/*.log {
daily
rotate 7
compress
delaycompress
notifempty
create 0644 tmi tmi
sharedscripts
postrotate
systemctl reload tmi
endscript
}TMI uses structured logging with consistent fields:
Key fields:
-
time- Timestamp (RFC3339 format) -
level- Log level (DEBUG, INFO, WARN, ERROR) -
msg- Human-readable message -
component- Component name (server, auth, database, websocket) -
user_id- User identifier (when applicable) -
request_id- Request trace ID -
duration- Request/operation duration (milliseconds)
Example log entries:
{"time":"2025-01-15T10:30:00Z","level":"INFO","component":"server","msg":"HTTP request","method":"GET","path":"/api/v1/threat-models","status":200,"duration":45,"user_id":"abc-123"}
{"time":"2025-01-15T10:30:01Z","level":"ERROR","component":"database","msg":"Query failed","query":"SELECT * FROM threat_models","error":"connection refused"}
{"time":"2025-01-15T10:30:02Z","level":"DEBUG","component":"websocket","msg":"Client connected","client_id":"xyz-789"}Search for errors:
# All errors
grep '"level":"ERROR"' logs/tmi.log
# Errors with text format
grep 'ERROR' logs/tmi.log
# Errors in last hour
grep '"level":"ERROR"' logs/tmi.log | grep "$(date -u +%Y-%m-%dT%H)"Search by component:
# Database logs
grep '"component":"database"' logs/tmi.log
# Authentication logs
grep '"component":"auth"' logs/tmi.log
# WebSocket logs
grep '"component":"websocket"' logs/tmi.logSearch by user:
# All activity for specific user
grep '"user_id":"abc-123"' logs/tmi.log
# Failed operations for user
grep '"user_id":"abc-123"' logs/tmi.log | grep '"level":"ERROR"'Search by request:
# Follow request through system
grep '"request_id":"req-xyz-789"' logs/tmi.log
# All GET requests
grep '"method":"GET"' logs/tmi.log
# Slow requests (>1000ms)
grep '"duration":[0-9][0-9][0-9][0-9]' logs/tmi.logjq for JSON logs:
# Pretty print JSON logs
cat logs/tmi.log | jq .
# Extract error messages
cat logs/tmi.log | jq 'select(.level=="ERROR") | .msg'
# Count errors by component
cat logs/tmi.log | jq 'select(.level=="ERROR") | .component' | sort | uniq -c
# Find slowest requests
cat logs/tmi.log | jq 'select(.duration > 1000) | {path, duration}' | sort -k2 -ngrep patterns:
# Authentication failures
grep -i "authentication failed\|unauthorized\|invalid token" logs/tmi.log
# Database errors
grep -i "database error\|connection refused\|query failed" logs/tmi.log
# WebSocket issues
grep -i "websocket.*error\|connection.*closed\|upgrade failed" logs/tmi.log
# Performance issues
grep '"duration":[5-9][0-9][0-9][0-9]' logs/tmi.log # >5 secondsCommon patterns:
# Top 10 API endpoints by count
grep '"method":"' logs/tmi.log | jq -r '.path' | sort | uniq -c | sort -rn | head -10
# Error rate per hour
grep '"level":"ERROR"' logs/tmi.log | jq -r '.time' | cut -d: -f1-2 | uniq -c
# Average request duration by endpoint
grep '"duration":' logs/tmi.log | jq '{path, duration}' | jq -s 'group_by(.path) | map({path: .[0].path, avg: (map(.duration) | add / length)})'Open Developer Tools:
- Chrome/Edge: F12 or Ctrl+Shift+I (Windows/Linux), Cmd+Option+I (Mac)
- Firefox: F12 or Ctrl+Shift+I (Windows/Linux), Cmd+Option+I (Mac)
- Safari: Cmd+Option+I (Mac) - Enable "Show Develop menu" in Preferences first
Key areas to check:
-
Console Tab:
- JavaScript errors
- Failed API calls
- WebSocket connection issues
- Application warnings
-
Network Tab:
- API request/response details
- HTTP status codes
- Request/response headers
- WebSocket handshake
-
Application Tab:
- Local storage (JWT tokens)
- Session storage
- Cookies
- Cache status
Network tab inspection:
- Open Network tab in Developer Tools
- Refresh page or trigger API call
- Find request in list
- Click to view details:
- Headers: Request/response headers, status code
- Preview: Formatted response data
- Response: Raw response data
- Timing: Request timing breakdown
Common issues:
401 Unauthorized:
// Check Authorization header
// Network Tab > Request Headers
Authorization: Bearer eyJhbGciOiJIUzI1...
// Check token in console
console.log(localStorage.getItem('tmi_token'));
// Decode JWT to check expiration
const token = localStorage.getItem('tmi_token');
const payload = JSON.parse(atob(token.split('.')[1]));
console.log('Token expires:', new Date(payload.exp * 1000));CORS errors:
Access to fetch at 'https://api.example.com' from origin 'https://app.example.com'
has been blocked by CORS policy: No 'Access-Control-Allow-Origin' header is present.
Check server CORS configuration:
# Verify CORS headers
curl -H "Origin: https://app.example.com" \
-H "Access-Control-Request-Method: GET" \
-H "Access-Control-Request-Headers: Authorization" \
-X OPTIONS \
-v \
https://api.example.com/api/v1/threat-modelsNetwork errors:
// Check for network connectivity
fetch('https://api.example.com/health')
.then(r => console.log('Server reachable:', r.status))
.catch(e => console.error('Network error:', e));Network tab WebSocket inspection:
- Open Network tab
- Filter by "WS" or "WebSocket"
- Click WebSocket connection
- View Messages tab:
- Outgoing messages (sent)
- Incoming messages (received)
- Message timestamps
Console WebSocket debugging:
// Monitor WebSocket events
const socket = new WebSocket('wss://api.example.com/ws');
socket.onopen = (e) => console.log('WebSocket connected:', e);
socket.onerror = (e) => console.error('WebSocket error:', e);
socket.onclose = (e) => console.log('WebSocket closed:', e.code, e.reason);
socket.onmessage = (e) => console.log('WebSocket message:', JSON.parse(e.data));Common WebSocket issues:
Connection refused:
- Check WebSocket URL (ws:// vs wss://)
- Verify server is running
- Check firewall/proxy settings
Connection closes immediately:
- Check authentication (JWT token)
- Verify CORS headers
- Check server logs for errors
Messages not received:
- Verify subscription is active
- Check Redis connectivity on server
- Monitor Network tab Messages
Set breakpoints:
- Open Sources tab
- Find JavaScript file
- Click line number to set breakpoint
- Trigger action to hit breakpoint
- Inspect variables, step through code
Console debugging:
// Log API responses
fetch('/api/v1/threat-models')
.then(r => r.json())
.then(data => {
console.log('API response:', data);
debugger; // Pause execution here
});
// Log WebSocket messages
socket.onmessage = (e) => {
const data = JSON.parse(e.data);
console.table(data); // Display as table
console.dir(data); // Display as object
};
// Trace function calls
console.trace('Function call stack');psql command line:
# Connect to database
psql -h localhost -U postgres -d tmi
# Or use environment variables
export PGHOST=localhost
export PGUSER=postgres
export PGDATABASE=tmi
psqlFrom Docker:
# Connect to PostgreSQL container
docker exec -it tmi-postgres psql -U postgres -d tmiCheck active connections:
-- List all connections
SELECT pid, usename, application_name, client_addr, state, query
FROM pg_stat_activity
WHERE datname = 'tmi'
ORDER BY state, query_start DESC;
-- Count connections by state
SELECT state, COUNT(*)
FROM pg_stat_activity
WHERE datname = 'tmi'
GROUP BY state;Check database size:
-- Database size
SELECT pg_size_pretty(pg_database_size('tmi')) AS database_size;
-- Table sizes
SELECT schemaname, tablename,
pg_size_pretty(pg_total_relation_size(schemaname||'.'||tablename)) AS size
FROM pg_tables
WHERE schemaname = 'public'
ORDER BY pg_total_relation_size(schemaname||'.'||tablename) DESC
LIMIT 20;
-- Largest indexes
SELECT schemaname, tablename, indexname,
pg_size_pretty(pg_relation_size(indexrelid)) AS size
FROM pg_indexes
JOIN pg_class ON pg_class.relname = indexname
WHERE schemaname = 'public'
ORDER BY pg_relation_size(indexrelid) DESC
LIMIT 10;Check slow queries:
-- Currently running slow queries
SELECT pid, now() - query_start AS duration, state, query
FROM pg_stat_activity
WHERE state = 'active'
AND now() - query_start > interval '5 seconds'
ORDER BY duration DESC;
-- Kill a long-running query (use carefully!)
SELECT pg_terminate_backend(pid)
FROM pg_stat_activity
WHERE pid = <process_id>;Check table statistics:
-- Row counts
SELECT schemaname, tablename, n_live_tup AS row_count
FROM pg_stat_user_tables
WHERE schemaname = 'public'
ORDER BY n_live_tup DESC;
-- Table activity (inserts, updates, deletes)
SELECT schemaname, relname,
seq_scan, seq_tup_read,
idx_scan, idx_tup_fetch,
n_tup_ins, n_tup_upd, n_tup_del
FROM pg_stat_user_tables
WHERE schemaname = 'public'
ORDER BY n_tup_ins + n_tup_upd + n_tup_del DESC;Check indexes:
-- List all indexes
SELECT schemaname, tablename, indexname, indexdef
FROM pg_indexes
WHERE schemaname = 'public'
ORDER BY tablename, indexname;
-- Find unused indexes
SELECT schemaname, tablename, indexname, idx_scan
FROM pg_stat_user_indexes
WHERE schemaname = 'public'
AND idx_scan = 0
AND indexrelname NOT LIKE 'pg_toast%'
ORDER BY pg_relation_size(indexrelid) DESC;
-- Find missing indexes (high seq_scan, no idx_scan)
SELECT schemaname, tablename, seq_scan, idx_scan,
seq_scan - idx_scan AS too_much_seq,
CASE WHEN seq_scan - idx_scan > 0
THEN 'Missing Index?'
ELSE 'OK'
END AS advice
FROM pg_stat_user_tables
WHERE schemaname = 'public'
AND seq_scan - idx_scan > 0
ORDER BY too_much_seq DESC;Application-specific queries:
-- Count threat models by user
SELECT owner, COUNT(*) as threat_model_count
FROM threat_models
GROUP BY owner
ORDER BY threat_model_count DESC
LIMIT 10;
-- Recent threat model activity
SELECT id, name, owner, created_at, modified_at
FROM threat_models
ORDER BY modified_at DESC
LIMIT 20;
-- Users with most authorization grants
SELECT subject, COUNT(*) as grant_count
FROM authorization
GROUP BY subject
ORDER BY grant_count DESC
LIMIT 10;
-- Webhook subscription status
SELECT status, COUNT(*) as count
FROM webhook_subscriptions
GROUP BY status;
-- Failed webhook deliveries
SELECT ws.url, wd.status, COUNT(*) as failure_count
FROM webhook_deliveries wd
JOIN webhook_subscriptions ws ON ws.id = wd.subscription_id
WHERE wd.status = 'failed'
AND wd.created_at > NOW() - INTERVAL '24 hours'
GROUP BY ws.url, wd.status
ORDER BY failure_count DESC;EXPLAIN ANALYZE:
-- Analyze query performance
EXPLAIN ANALYZE
SELECT tm.*, u.email
FROM threat_models tm
JOIN users u ON u.id = tm.owner
WHERE tm.created_at > NOW() - INTERVAL '7 days'
ORDER BY tm.created_at DESC;
-- Look for:
-- - Seq Scan (consider adding index)
-- - High execution time
-- - High row countsEnable query logging:
-- Log slow queries (PostgreSQL config)
ALTER DATABASE tmi SET log_min_duration_statement = 1000; -- Log queries >1s
-- Log all queries (development only)
ALTER DATABASE tmi SET log_statement = 'all';# Connect via redis-cli
redis-cli
# Connect to specific host/port
redis-cli -h localhost -p 6379
# Connect with password
redis-cli -a yourpassword
# From Docker
docker exec -it tmi-redis redis-cliCheck Redis status:
# Server info
redis-cli INFO
# Memory usage
redis-cli INFO memory
# Connected clients
redis-cli CLIENT LIST
# Server statistics
redis-cli INFO statsInspect keys:
# Count keys
redis-cli DBSIZE
# List keys (use carefully in production!)
redis-cli KEYS "*"
# Scan keys safely (paginated)
redis-cli SCAN 0 MATCH "session:*" COUNT 100
# Get key value
redis-cli GET "session:abc123"
# Get key type and TTL
redis-cli TYPE "session:abc123"
redis-cli TTL "session:abc123"WebSocket debugging:
# List WebSocket sessions
redis-cli KEYS "websocket:*"
# Check WebSocket connection
redis-cli GET "websocket:connection:xyz789"
# Monitor real-time commands
redis-cli MONITORWebhook debugging:
# Check event stream
redis-cli XINFO STREAM tmi:events
# View recent events
redis-cli XRANGE tmi:events - + COUNT 10
# Check webhook consumer group
redis-cli XINFO GROUPS tmi:events
# Check pending webhook deliveries
redis-cli XPENDING tmi:events webhook-consumersCache debugging:
# Check cache hit rate
redis-cli INFO stats | grep hit_rate
# Find large keys
redis-cli --bigkeys
# Sample keys
redis-cli --sample-
Check logs:
grep '"component":"auth"' logs/tmi.log | tail -20
-
Verify OAuth configuration:
curl http://localhost:8080/auth/github/login
-
Check JWT token:
// In browser console const token = localStorage.getItem('tmi_token'); console.log(JSON.parse(atob(token.split('.')[1])));
-
Test API with token:
curl -H "Authorization: Bearer $TOKEN" \ http://localhost:8080/api/v1/threat-models
-
Check server logs:
grep '"component":"websocket"' logs/tmi.log -
Verify Redis connectivity:
redis-cli PING redis-cli KEYS "websocket:*" -
Monitor WebSocket in browser:
- Open Network tab, filter by WS
- Check connection status and messages
-
Test WebSocket connection:
websocat wss://api.example.com/ws
-
Check server logs for slow requests:
grep '"duration":[5-9][0-9][0-9]' logs/tmi.log -
Profile application:
# CPU profile curl http://localhost:8080/debug/pprof/profile?seconds=30 > cpu.prof go tool pprof cpu.prof # Memory profile curl http://localhost:8080/debug/pprof/heap > mem.prof go tool pprof mem.prof
-
Check database performance:
-- Find slow queries SELECT query, calls, total_time, mean_time FROM pg_stat_statements ORDER BY mean_time DESC LIMIT 10;
-
Check Redis performance:
# Monitor commands redis-cli MONITOR # Check slow log redis-cli SLOWLOG GET 10
- Common-Issues - Solutions to frequent problems
- Getting-Help - Support resources
- Performance-Troubleshooting - Performance optimization
- Database-Operations - Database procedures
- Monitoring-and-Health - System monitoring
- Using TMI for Threat Modeling
- Accessing TMI
- Creating Your First Threat Model
- Understanding the User Interface
- Working with Data Flow Diagrams
- Managing Threats
- Collaborative Threat Modeling
- Using Notes and Documentation
- Metadata and Extensions
- Planning Your Deployment
- Deploying TMI Server
- Deploying TMI Web Application
- Setting Up Authentication
- Database Setup
- Component Integration
- Post-Deployment
- Monitoring and Health
- Database Operations
- Security Operations
- Performance and Scaling
- Maintenance Tasks