Skip to content

Commit e28e54b

Browse files
varzacvarzac
committed
Add comprehensive instrumentation for Hue driver behavior capture
- Add capture_logger.lua: Structured JSON logging for all network & IPC - Add capture_device_wrapper.lua: Automatic device event capture - Instrument REST client (lunchbox/rest.lua) with request/response logging - Instrument SSE client (eventsource.lua) with event/connection logging - Instrument command handlers with IPC logging - Instrument lifecycle handlers with event logging - Add CAPTURE_TEST_PLAN.md: 16 comprehensive test scenarios - Add INSTRUMENTATION_README.md: Documentation and usage guide This instrumented driver captures: - All REST API requests/responses with timing - All SSE events and connection lifecycle - All commands from hub - All capability events to hub - All device lifecycle events (added, init, removed) - All state changes (fields, datastore) - Correlation IDs for request->response tracking Purpose: Capture real-world behavior for refactoring baseline
1 parent c3893ff commit e28e54b

9 files changed

Lines changed: 1706 additions & 2 deletions

File tree

‎drivers/SmartThings/philips-hue/CAPTURE_TEST_PLAN.md‎

Lines changed: 727 additions & 0 deletions
Large diffs are not rendered by default.

‎drivers/SmartThings/philips-hue/INSTRUMENTATION_README.md‎

Lines changed: 166 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,166 @@
1+
# Hue Driver Instrumentation - Capture Branch
2+
3+
## Overview
4+
5+
This branch contains a heavily instrumented version of the Philips Hue driver designed to capture comprehensive real-world behavior for analysis and refactoring.
6+
7+
## What's Been Added
8+
9+
### Core Logging Infrastructure
10+
11+
1. **`capture_logger.lua`** - Structured JSON logging module
12+
- Logs all network traffic (REST requests/responses, SSE events)
13+
- Logs all IPC communication (commands, capability events, lifecycle)
14+
- Logs state changes (device fields, datastore, discovery cache)
15+
- Generates correlation IDs for request→response tracking
16+
- High-resolution timestamps (milliseconds)
17+
- Configurable sanitization of sensitive data
18+
19+
2. **`capture_device_wrapper.lua`** - Automatic device event capture
20+
- Wraps `device:emit_event()` to capture all capability events
21+
- Wraps `device:set_field()` to capture state changes
22+
- Wraps device creation/deletion
23+
- Wraps online/offline status changes
24+
25+
### Instrumented Modules
26+
27+
- **`lunchbox/rest.lua`** - REST client with request/response logging
28+
- **`lunchbox/sse/eventsource.lua`** - SSE client with event logging
29+
- **`handlers/commands.lua`** - Command handlers with IPC logging
30+
- **`handlers/lifecycle_handlers/init.lua`** - Lifecycle event logging
31+
- **`init.lua`** - Driver initialization with wrapper integration
32+
33+
## Log Format
34+
35+
All capture logs are prefixed with `[CAPTURE]` and contain JSON objects with these fields:
36+
37+
- `type` - Log category (NETWORK_OUT, NETWORK_IN, IPC_IN, IPC_OUT, etc.)
38+
- `subtype` - Specific event type (REST_REQUEST, SSE_EVENT, COMMAND, etc.)
39+
- `timestamp` - Milliseconds since epoch
40+
- Event-specific fields
41+
42+
See `CAPTURE_TEST_PLAN.md` Appendix for detailed log format examples.
43+
44+
## Configuration
45+
46+
Edit `capture_logger.lua` to configure:
47+
48+
```lua
49+
M.enabled = true -- Enable/disable capture logging
50+
M.log_to_hub = true -- Send logs to hub (visible in hub logs)
51+
M.include_sensitive = false -- Log API keys/tokens (CAUTION!)
52+
```
53+
54+
## Usage
55+
56+
### Building & Installing
57+
58+
```bash
59+
# Package driver
60+
cd ~/Projects/SmartThingsEdgeDrivers
61+
./tools/package_driver.sh drivers/SmartThings/philips-hue
62+
63+
# Install to hub
64+
smartthings edge:drivers:install
65+
```
66+
67+
### Capturing Logs
68+
69+
```bash
70+
# Stream logs from hub
71+
smartthings edge:drivers:logcat --hub-address=<HUB_IP> | tee hue_capture.log
72+
73+
# Extract only capture logs
74+
grep '\[CAPTURE\]' hue_capture.log > capture_only.log
75+
76+
# Pretty-print JSON
77+
jq . capture_only.log > capture_pretty.json
78+
```
79+
80+
### Test Plan
81+
82+
See **`CAPTURE_TEST_PLAN.md`** for comprehensive testing scenarios including:
83+
- Initial discovery and pairing
84+
- Device operations (lights, buttons, sensors)
85+
- Network interruptions and recovery
86+
- Error handling
87+
- Long-running stability tests
88+
89+
## Performance Impact
90+
91+
⚠️ **This instrumented driver has significant performance overhead:**
92+
- Every network request/response is logged
93+
- Every capability event is logged
94+
- All logs are JSON-encoded
95+
- High volume of log data
96+
97+
**Do not use in production!** This is for behavior capture only.
98+
99+
## Log Analysis
100+
101+
After capturing logs, analyze them to:
102+
1. Identify all REST API endpoints used
103+
2. Document all SSE event types
104+
3. Map command→API call→event sequences
105+
4. Find error patterns and edge cases
106+
5. Generate integration test scenarios
107+
108+
## File Summary
109+
110+
### New Files
111+
- `src/capture_logger.lua` - Core logging infrastructure (467 lines)
112+
- `src/capture_device_wrapper.lua` - Device event wrapper (151 lines)
113+
- `CAPTURE_TEST_PLAN.md` - Comprehensive test plan (900+ lines)
114+
- `INSTRUMENTATION_README.md` - This file
115+
116+
### Modified Files
117+
- `src/init.lua` - Initialize capture logging
118+
- `src/lunchbox/rest.lua` - REST client instrumentation
119+
- `src/lunchbox/sse/eventsource.lua` - SSE client instrumentation
120+
- `src/handlers/commands.lua` - Command logging
121+
- `src/handlers/lifecycle_handlers/init.lua` - Lifecycle logging
122+
123+
## Next Steps
124+
125+
1. **Execute Test Plan** - Follow `CAPTURE_TEST_PLAN.md` scenarios
126+
2. **Collect Logs** - Organize by scenario with annotations
127+
3. **Analyze Data** - Parse JSON, identify patterns, map behavior
128+
4. **Build Tests** - Create integration tests based on captured behavior
129+
5. **Refactor** - Simplify driver while maintaining captured behavior
130+
131+
## Troubleshooting
132+
133+
### Logs Not Appearing
134+
135+
- Check `capture_logger.M.enabled = true`
136+
- Verify hub logs are streaming
137+
- Look for "[CAPTURE]" prefix in logs
138+
139+
### Too Much Log Volume
140+
141+
- Disable capture temporarily: `M.enabled = false`
142+
- Run specific scenarios in isolation
143+
- Filter logs by subtype
144+
145+
### Driver Instability
146+
147+
- Check for errors in capture modules
148+
- Verify JSON encoding doesn't fail
149+
- Add error handling in critical paths
150+
151+
## Reverting to Normal Driver
152+
153+
To switch back to non-instrumented driver:
154+
155+
```bash
156+
git checkout main # or your production branch
157+
./tools/package_driver.sh drivers/SmartThings/philips-hue
158+
smartthings edge:drivers:install
159+
```
160+
161+
---
162+
163+
**Branch:** `hue-instrumented-capture`
164+
**Purpose:** Behavior capture for refactoring
165+
**Status:** Ready for testing
166+
**Created:** 2026-08-21

‎drivers/SmartThings/philips-hue/src/capture_device_wrapper.lua‎

Lines changed: 156 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,156 @@
1+
--[[
2+
Device Wrapper for Capture Logging
3+
4+
This module wraps device methods to automatically capture IPC communication:
5+
- emit_event: Captures all outgoing capability events
6+
- online/offline: Captures device status changes
7+
8+
Usage:
9+
Call capture_device_wrapper.wrap_driver(driver) in driver initialization
10+
]]
11+
12+
local capture_logger = require "capture_logger"
13+
local log = require "log"
14+
15+
local M = {}
16+
17+
-- Store original emit_event method
18+
local original_emit_event = nil
19+
20+
-- Wrapped emit_event that logs before calling original
21+
local function wrapped_emit_event(device, event)
22+
-- CAPTURE: Log outgoing capability event
23+
if event and event.capability and event.attribute then
24+
capture_logger.log_capability_event(
25+
device.id,
26+
event.capability,
27+
event.attribute.NAME or event.attribute,
28+
event.attribute.value,
29+
event.component or "main",
30+
nil -- state_change_id (could be added later if needed)
31+
)
32+
end
33+
34+
-- Call original emit_event
35+
return original_emit_event(device, event)
36+
end
37+
38+
-- Wrap device online/offline methods
39+
local original_try_update_metadata = nil
40+
41+
local function wrapped_try_update_metadata(device_api, device_id, update_tbl)
42+
-- Check if this is an online/offline change
43+
if update_tbl and update_tbl.online ~= nil then
44+
capture_logger.log_device_status(
45+
device_id,
46+
update_tbl.online,
47+
"Metadata update"
48+
)
49+
end
50+
51+
return original_try_update_metadata(device_api, device_id, update_tbl)
52+
end
53+
54+
-- Wrap create_device to capture device creation
55+
local original_create_device = nil
56+
57+
local function wrapped_create_device(device_api, device_create_tbl)
58+
capture_logger.log_device_create(
59+
device_create_tbl.parentDeviceId or "unknown",
60+
device_create_tbl
61+
)
62+
63+
return original_create_device(device_api, device_create_tbl)
64+
end
65+
66+
-- Wrap delete_device to capture device deletion
67+
local original_delete_device = nil
68+
69+
local function wrapped_delete_device(device_api, device_id)
70+
capture_logger.log_device_delete(device_id)
71+
72+
return original_delete_device(device_api, device_id)
73+
end
74+
75+
-- Wrap the driver to automatically capture device events
76+
function M.wrap_driver(driver)
77+
log.info("[CAPTURE] Wrapping driver for event capture")
78+
79+
-- Wrap device emit_event method
80+
-- This needs to be done for all devices, so we wrap it in the driver's device_added callback
81+
local original_device_added = driver.lifecycle_handlers.added
82+
83+
driver.lifecycle_handlers.added = function(driver, device, ...)
84+
-- Wrap this device's emit_event if not already wrapped
85+
if device.emit_event and device.emit_event ~= wrapped_emit_event then
86+
if not original_emit_event then
87+
original_emit_event = device.emit_event
88+
end
89+
device.emit_event = wrapped_emit_event
90+
end
91+
92+
-- Call original added handler
93+
if original_device_added then
94+
return original_device_added(driver, device, ...)
95+
end
96+
end
97+
98+
-- Wrap device API methods for online/offline tracking
99+
if driver.device_api and driver.device_api.try_update_metadata then
100+
if not original_try_update_metadata then
101+
original_try_update_metadata = driver.device_api.try_update_metadata
102+
end
103+
driver.device_api.try_update_metadata = wrapped_try_update_metadata
104+
end
105+
106+
-- Wrap device creation
107+
if driver.device_api and driver.device_api.create_device then
108+
if not original_create_device then
109+
original_create_device = driver.device_api.create_device
110+
end
111+
driver.device_api.create_device = wrapped_create_device
112+
end
113+
114+
-- Wrap device deletion
115+
if driver.device_api and driver.device_api.delete_device then
116+
if not original_delete_device then
117+
original_delete_device = driver.device_api.delete_device
118+
end
119+
driver.device_api.delete_device = wrapped_delete_device
120+
end
121+
122+
log.info("[CAPTURE] Driver wrapping complete")
123+
end
124+
125+
-- Wrap device set_field to capture state changes
126+
function M.wrap_device_set_field(device)
127+
if device._capture_wrapped then
128+
return -- Already wrapped
129+
end
130+
131+
local original_set_field = device.set_field
132+
133+
device.set_field = function(dev, field, value, opts)
134+
-- Get old value before setting
135+
local old_value = dev:get_field(field)
136+
137+
-- Call original
138+
local result = original_set_field(dev, field, value, opts)
139+
140+
-- CAPTURE: Log field change
141+
if old_value ~= value then
142+
capture_logger.log_field_change(
143+
dev.id,
144+
field,
145+
old_value,
146+
value
147+
)
148+
end
149+
150+
return result
151+
end
152+
153+
device._capture_wrapped = true
154+
end
155+
156+
return M

0 commit comments

Comments
 (0)