New Relic APM入門 第5.3章 - コードレベルパフォーマンス分析 ​

// New Relic Code-Level Metricsの監視対象例
const codeMetricsExample = {
    
    // 関数レベルメトリクス
    function_metrics: {
        function_name: "calculateShippingCost",
        file_path: "/src/services/shipping.js",
        line_number: 142,
        metrics: {
            call_count: 1247,               // 呼び出し回数
            total_time: "45.2s",            // 累計実行時間
            average_time: "36.2ms",         // 平均実行時間
            max_time: "340ms",              // 最大実行時間
            cpu_time: "42.1s",              // CPU使用時間
            wall_clock_time: "45.2s"        // 実時間
        },
        performance_score: 0.73             // パフォーマンススコア
    },
    
    // メソッドチェーン分析
    method_chain: [
        {
            method: "OrderService.processOrder",
            duration: "1.8s",
            self_time: "50ms",              // 自身の処理時間
            children_time: "1.75s"          // 子メソッドの処理時間
        },
        {
            method: "├─ PaymentService.processPayment", 
            duration: "800ms",
            self_time: "20ms",
            children_time: "780ms"
        },
        {
            method: "│  └─ StripeAPI.createCharge",
            duration: "780ms",
            self_time: "780ms",             // 外部API呼び出し
            children_time: "0ms"
        },
        {
            method: "├─ InventoryService.reserveItems",
            duration: "950ms", 
            self_time: "100ms",
            children_time: "850ms"
        },
        {
            method: "│  └─ DatabaseService.updateInventory",
            duration: "850ms",              // ← ボトルネック特定！
            self_time: "850ms",
            query: "UPDATE inventory SET quantity = quantity - ? WHERE..."
        }
    ]
};

// newrelic.js 設定（Code-Level Metrics有効化）
'use strict';

exports.config = {
  app_name: ['ECommerce-API'],
  license_key: process.env.NEW_RELIC_LICENSE_KEY,
  
  // Code-Level Metrics 有効化
  code_level_metrics: {
    enabled: true
  },
  
  // 詳細トランザクション トレーシング
  transaction_tracer: {
    enabled: true,
    transaction_threshold: 0.1,     // 100ms以上の関数を詳細記録
    record_sql: 'raw',
    explain_enabled: true,
    explain_threshold: 0.5,
    stack_trace_threshold: 0.5      // 500ms以上でスタックトレース記録
  },
  
  // 関数レベル監視設定
  attributes: {
    enabled: true,
    include: [
      'request.*',
      'response.*',
      'custom.*'
    ]
  }
};

// app.js - 詳細な関数監視
require('newrelic');
const express = require('express');
const newrelic = require('newrelic');
const app = express();

// 在庫管理サービス（詳細監視対象）
class InventoryService {
    
    // 自動的にCode-Level Metricsで監視される
    async checkStock(items) {
        // 個別関数の詳細監視
        const validationResult = await this.validateItems(items);
        const availability = await this.checkAvailability(validationResult);
        const reservationResult = await this.createReservation(availability);
        
        return reservationResult;
    }
    
    // @newrelic.agent.function_trace() デコレータで手動監視
    @newrelic.agent.function_trace()
    async validateItems(items) {
        // バリデーション処理
        const startTime = Date.now();
        
        try {
            const validItems = [];
            
            for (const item of items) {
                // 各アイテムの詳細検証（監視対象）
                const validation = await this.validateSingleItem(item);
                
                if (validation.valid) {
                    validItems.push(validation.item);
                } else {
                    // 検証失敗の詳細記録
                    newrelic.addCustomAttribute(`validation.failed.${item.id}`, validation.reason);
                }
            }
            
            // 成功メトリクス
            const duration = Date.now() - startTime;
            newrelic.recordMetric('Custom/Inventory/Validation/Duration', duration);
            newrelic.recordMetric('Custom/Inventory/Validation/ItemCount', items.length);
            
            return validItems;
            
        } catch (error) {
            // エラー詳細（関数レベル）
            newrelic.noticeError(error, {
                'function': 'validateItems',
                'items_count': items.length,
                'processing_time': Date.now() - startTime
            });
            throw error;
        }
    }
    
    // CPU集約的処理の監視例
    async checkAvailability(validItems) {
        return await newrelic.startBackgroundTransaction('availability_check', async () => {
            
            const availabilityChecks = [];
            
            // 並列処理での詳細監視
            for (const item of validItems) {
                const checkPromise = this.checkSingleItemAvailability(item);
                availabilityChecks.push(checkPromise);
            }
            
            // Promise.all のパフォーマンス監視
            const startTime = Date.now();
            const results = await Promise.all(availabilityChecks);
            const parallelProcessingTime = Date.now() - startTime;
            
            // 並列処理効率メトリクス
            newrelic.recordMetric('Custom/Inventory/Parallel/Duration', parallelProcessingTime);
            newrelic.recordMetric('Custom/Inventory/Parallel/Efficiency', 
                (validItems.length * 100) / parallelProcessingTime); // items/second * 100
            
            return results;
        });
    }
    
    // データベース集約処理の詳細監視
    async checkSingleItemAvailability(item) {
        // データベースクエリの詳細分析
        const queryStartTime = Date.now();
        
        try {
            // 複雑な在庫チェッククエリ（自動監視）
            const query = `
                SELECT 
                    i.quantity,
                    i.reserved,
                    w.available_quantity,
                    p.reorder_point
                FROM inventory i
                JOIN warehouses w ON i.warehouse_id = w.id
                JOIN products p ON i.product_id = p.id
                WHERE i.product_id = ? 
                AND i.warehouse_id IN (
                    SELECT id FROM warehouses 
                    WHERE region = ? 
                    AND status = 'active'
                )
            `;
            
            const result = await database.query(query, [item.product_id, item.region]);
            
            // クエリパフォーマンス記録
            const queryDuration = Date.now() - queryStartTime;
            newrelic.recordMetric('Custom/Database/InventoryCheck/Duration', queryDuration);
            
            // 遅いクエリのアラート
            if (queryDuration > 200) {  // 200ms以上
                newrelic.recordMetric('Custom/Database/InventoryCheck/SlowQuery', 1);
                newrelic.addCustomAttribute('slow_query.product_id', item.product_id);
                newrelic.addCustomAttribute('slow_query.duration', queryDuration);
            }
            
            // ビジネスロジックの処理時間監視
            const businessLogicStart = Date.now();
            const availability = this.calculateAvailability(result[0]);
            const businessLogicDuration = Date.now() - businessLogicStart;
            
            newrelic.recordMetric('Custom/BusinessLogic/AvailabilityCalc/Duration', businessLogicDuration);
            
            return availability;
            
        } catch (error) {
            const queryDuration = Date.now() - queryStartTime;
            
            newrelic.noticeError(error, {
                'function': 'checkSingleItemAvailability',
                'product_id': item.product_id,
                'query_duration': queryDuration,
                'database_error': error.code
            });
            
            throw error;
        }
    }
    
    // メモリ使用量監視
    calculateAvailability(inventoryData) {
        const memUsageBefore = process.memoryUsage();
        
        try {
            // 複雑な在庫計算ロジック
            const calculation = {
                available: inventoryData.quantity - inventoryData.reserved,
                buffer: inventoryData.reorder_point,
                warehouse_stock: inventoryData.available_quantity
            };
            
            // 在庫状況の詳細判定
            let status = 'available';
            if (calculation.available <= 0) {
                status = 'out_of_stock';
            } else if (calculation.available <= calculation.buffer) {
                status = 'low_stock';
            }
            
            // メモリ使用量の変化監視
            const memUsageAfter = process.memoryUsage();
            const memoryDelta = {
                heapUsed: memUsageAfter.heapUsed - memUsageBefore.heapUsed,
                heapTotal: memUsageAfter.heapTotal - memUsageBefore.heapTotal,
                external: memUsageAfter.external - memUsageBefore.external
            };
            
            // メモリ使用量メトリクス
            newrelic.recordMetric('Custom/Memory/AvailabilityCalc/HeapUsed', memoryDelta.heapUsed);
            
            // メモリリークの早期警告
            if (memoryDelta.heapUsed > 1024 * 1024) {  // 1MB以上の増加
                newrelic.recordMetric('Custom/Memory/PotentialLeak', 1);
                newrelic.addCustomAttribute('memory.large_allocation', memoryDelta.heapUsed);
            }
            
            return {
                ...calculation,
                status: status,
                calculated_at: new Date().toISOString()
            };
            
        } catch (error) {
            newrelic.noticeError(error, {
                'function': 'calculateAvailability',
                'inventory_data': JSON.stringify(inventoryData)
            });
            throw error;
        }
    }
}

// Node.js プロファイリング統合実装
const newrelic = require('newrelic');
const v8Profiler = require('v8-profiler-next');
const fs = require('fs').promises;

class PerformanceProfiler {
    
    constructor() {
        this.activeProfiles = new Map();
        this.samplingInterval = 1000; // 1秒間隔
        this.setupContinuousProfiler();
    }
    
    setupContinuousProfiler() {
        """継続的プロファイリングセットアップ"""
        
        // CPU使用率監視
        setInterval(() => {
            this.sampleCpuUsage();
        }, this.samplingInterval);
        
        // メモリ使用量監視
        setInterval(() => {
            this.sampleMemoryUsage();
        }, this.samplingInterval);
        
        // ガベージコレクション監視
        this.setupGCMonitoring();
    }
    
    sampleCpuUsage() {
        """CPU使用率サンプリング"""
        
        const cpuUsage = process.cpuUsage();
        const memUsage = process.memoryUsage();
        
        // New Relic メトリクス記録
        newrelic.recordMetric('Custom/Performance/CPU/User', cpuUsage.user / 1000); // マイクロ秒 → ミリ秒
        newrelic.recordMetric('Custom/Performance/CPU/System', cpuUsage.system / 1000);
        newrelic.recordMetric('Custom/Performance/Memory/HeapUsed', memUsage.heapUsed);
        newrelic.recordMetric('Custom/Performance/Memory/HeapTotal', memUsage.heapTotal);
        newrelic.recordMetric('Custom/Performance/Memory/RSS', memUsage.rss);
        
        // 高CPU使用率アラート
        const totalCpu = (cpuUsage.user + cpuUsage.system) / 1000;
        if (totalCpu > 1000) {  // 1秒以上のCPU時間消費
            newrelic.recordMetric('Custom/Performance/CPU/HighUsage', 1);
            this.triggerCpuProfileCapture();
        }
    }
    
    sampleMemoryUsage() {
        """メモリ使用パターン分析"""
        
        const memUsage = process.memoryUsage();
        
        // メモリリーク検出ロジック
        const currentHeapUsed = memUsage.heapUsed;
        const currentTime = Date.now();
        
        if (!this.memoryBaseline) {
            this.memoryBaseline = { heap: currentHeapUsed, time: currentTime };
            return;
        }
        
        const timeDiff = currentTime - this.memoryBaseline.time;
        const heapDiff = currentHeapUsed - this.memoryBaseline.heap;
        
        // 30分間で100MB以上の継続的増加 = メモリリーク疑い
        if (timeDiff > 30 * 60 * 1000 && heapDiff > 100 * 1024 * 1024) {
            newrelic.recordMetric('Custom/Performance/Memory/PotentialLeak', 1);
            newrelic.addCustomAttribute('memory.leak_rate_mb_per_hour', 
                (heapDiff / 1024 / 1024) / (timeDiff / 60 / 60 / 1000));
                
            this.triggerMemoryProfileCapture();
            
            // ベースライン更新
            this.memoryBaseline = { heap: currentHeapUsed, time: currentTime };
        }
    }
    
    triggerCpuProfileCapture() {
        """CPU プロファイル取得"""
        
        const profileId = `cpu-profile-${Date.now()}`;
        
        // V8 CPU プロファイリング開始
        v8Profiler.startProfiling(profileId, true);
        
        // 10秒後に停止・解析
        setTimeout(async () => {
            try {
                const profile = v8Profiler.stopProfiling(profileId);
                const profileData = JSON.stringify(profile);
                
                // プロファイルデータ解析
                const analysis = this.analyzeCpuProfile(profile);
                
                // New Relic カスタムイベント送信
                newrelic.recordCustomEvent('CPUProfileCaptured', {
                    profileId: profileId,
                    captureTime: new Date().toISOString(),
                    hotFunctions: JSON.stringify(analysis.hotFunctions),
                    totalSamples: analysis.totalSamples,
                    topCpuConsumer: analysis.topFunction
                });
                
                // プロファイルファイル保存（オプション）
                await fs.writeFile(`/tmp/profiles/${profileId}.cpuprofile`, profileData);
                
                console.log(`CPU profile captured: ${profileId}`);
                
            } catch (error) {
                newrelic.noticeError(error, { context: 'cpu_profile_capture' });
            }
        }, 10000);
    }
    
    triggerMemoryProfileCapture() {
        """メモリ プロファイル取得"""
        
        const profileId = `memory-profile-${Date.now()}`;
        
        try {
            // ヒープスナップショット取得
            const snapshot = v8Profiler.takeSnapshot(profileId);
            
            // メモリ使用状況解析
            const analysis = this.analyzeMemorySnapshot(snapshot);
            
            // New Relic カスタムイベント送信
            newrelic.recordCustomEvent('MemoryProfileCaptured', {
                profileId: profileId,
                captureTime: new Date().toISOString(),
                totalObjects: analysis.totalObjects,
                largestObjects: JSON.stringify(analysis.largestObjects),
                suspiciousLeaks: JSON.stringify(analysis.suspiciousLeaks)
            });
            
            // メモリスナップショット解放
            snapshot.delete();
            
            console.log(`Memory profile captured: ${profileId}`);
            
        } catch (error) {
            newrelic.noticeError(error, { context: 'memory_profile_capture' });
        }
    }
    
    analyzeCpuProfile(profile) {
        """CPU プロファイル解析"""
        
        const functionStats = new Map();
        let totalSamples = 0;
        
        // プロファイルノード解析
        function traverseNode(node) {
            if (node.functionName && node.functionName !== '(root)') {
                const key = `${node.functionName}:${node.url}:${node.lineNumber}`;
                
                if (!functionStats.has(key)) {
                    functionStats.set(key, {
                        functionName: node.functionName,
                        url: node.url,
                        lineNumber: node.lineNumber,
                        hitCount: 0,
                        selfTime: 0
                    });
                }
                
                const stats = functionStats.get(key);
                stats.hitCount += node.hitCount;
                stats.selfTime += node.selfTime || 0;
                totalSamples += node.hitCount;
            }
            
            // 子ノード解析
            if (node.children) {
                node.children.forEach(traverseNode);
            }
        }
        
        traverseNode(profile.head);
        
        // CPU使用率上位関数特定
        const sortedFunctions = Array.from(functionStats.values())
            .sort((a, b) => b.hitCount - a.hitCount)
            .slice(0, 10);
        
        return {
            totalSamples: totalSamples,
            hotFunctions: sortedFunctions,
            topFunction: sortedFunctions[0]?.functionName || 'unknown'
        };
    }
    
    analyzeMemorySnapshot(snapshot) {
        """メモリスナップショット解析"""
        
        // 注意：実際の実装では v8-profiler-next の詳細API使用
        // ここでは概念的な解析例を示す
        
        const analysis = {
            totalObjects: 0,
            largestObjects: [],
            suspiciousLeaks: []
        };
        
        // スナップショット内のオブジェクト分析
        // （実装は v8-profiler-next のドキュメント参照）
        
        return analysis;
    }
    
    setupGCMonitoring() {
        """ガベージコレクション監視"""
        
        // GCイベント監視（Node.js v14+）
        if (process.env.NODE_ENV === 'production') {
            const { PerformanceObserver } = require('perf_hooks');
            
            const gcObserver = new PerformanceObserver((list) => {
                const entries = list.getEntries();
                
                entries.forEach(entry => {
                    if (entry.entryType === 'gc') {
                        // GC詳細記録
                        newrelic.recordMetric(`Custom/GC/${entry.detail.kind}/Duration`, entry.duration);
                        newrelic.recordMetric(`Custom/GC/${entry.detail.kind}/Count`, 1);
                        
                        // 長時間GCのアラート
                        if (entry.duration > 100) {  // 100ms以上
                            newrelic.recordMetric('Custom/GC/LongPause', 1);
                            newrelic.addCustomAttribute('gc.long_pause_duration', entry.duration);
                        }
                    }
                });
            });
            
            gcObserver.observe({ entryTypes: ['gc'] });
        }
    }
}

// 使用例：Express アプリケーションでの統合
const app = express();
const profiler = new PerformanceProfiler();

// CPU集約的エンドポイント（プロファイリング対象）
app.post('/api/heavy-computation', async (req, res) => {
    const startTime = Date.now();
    
    try {
        // 重い計算処理（プロファイリング対象）
        const result = await performHeavyComputation(req.body.data);
        
        const processingTime = Date.now() - startTime;
        
        // パフォーマンスメトリクス
        newrelic.recordMetric('Custom/HeavyComputation/Duration', processingTime);
        
        res.json({
            result: result,
            processingTime: processingTime
        });
        
    } catch (error) {
        newrelic.noticeError(error);
        res.status(500).json({ error: error.message });
    }
});

async function performHeavyComputation(data) {
    // CPU集約的処理例
    let result = 0;
    
    for (let i = 0; i < data.iterations; i++) {
        // 複雑な数値計算
        result += Math.sqrt(Math.pow(data.values[i % data.values.length], 2.7));
        
        // メモリ使用量増加処理
        if (i % 10000 === 0) {
            // 中間結果の保存（メモリ使用量監視対象）
            const intermediateResults = new Array(1000).fill(result);
            // ... 処理続行
        }
    }
    
    return result;
}

// 一般的なメモリリークパターンと検出方法

// パターン1: イベントリスナーの適切な削除忘れ
class ProblematicEventHandler {
    constructor() {
        this.data = new Array(10000).fill('large data');  // 大量データ保持
        
        // ❌ 問題：イベントリスナーが削除されない
        document.addEventListener('click', this.handleClick.bind(this));
        setInterval(this.periodicTask.bind(this), 1000);
    }
    
    handleClick(event) {
        // イベント処理中にさらにメモリを使用
        this.temporaryData = new Array(5000).fill(event.target.innerText);
    }
    
    periodicTask() {
        // タイマー処理でメモリ使用増加
        this.additionalData = (this.additionalData || []).concat(new Array(1000).fill(Date.now()));
    }
    
    // ❌ 問題：デストラクタでリソース解放していない
}

// ✅ 改善版：適切なリソース管理
class ImprovedEventHandler {
    constructor() {
        this.data = new Array(10000).fill('large data');
        
        // イベントハンドラーの参照保持
        this.boundHandleClick = this.handleClick.bind(this);
        this.intervalId = null;
        
        document.addEventListener('click', this.boundHandleClick);
        this.intervalId = setInterval(this.periodicTask.bind(this), 1000);
        
        // New Relic でメモリ使用量監視
        this.monitorMemoryUsage();
    }
    
    handleClick(event) {
        // 一時データは適切にスコープ管理
        const temporaryData = new Array(5000).fill(event.target.innerText);
        // 処理後、temporaryData は自動的にガベージコレクション対象
    }
    
    periodicTask() {
        // データサイズ制限
        if (!this.additionalData) this.additionalData = [];
        
        this.additionalData.push(Date.now());
        
        // 古いデータの削除（メモリリーク防止）
        if (this.additionalData.length > 1000) {
            this.additionalData = this.additionalData.slice(-1000);  // 最新1000件のみ保持
        }
        
        // メモリ使用量記録
        const memUsage = process.memoryUsage();
        newrelic.recordMetric('Custom/Memory/PeriodicTask/HeapUsed', memUsage.heapUsed);
    }
    
    monitorMemoryUsage() {
        setInterval(() => {
            const memUsage = process.memoryUsage();
            
            // ヒープメモリ監視
            newrelic.recordMetric('Custom/Memory/EventHandler/HeapUsed', memUsage.heapUsed);
            newrelic.recordMetric('Custom/Memory/EventHandler/HeapTotal', memUsage.heapTotal);
            
            // メモリリーク検出ロジック
            if (!this.memoryBaseline) {
                this.memoryBaseline = memUsage.heapUsed;
                this.baselineTime = Date.now();
                return;
            }
            
            const timeDiff = Date.now() - this.baselineTime;
            const memoryDiff = memUsage.heapUsed - this.memoryBaseline;
            
            // 10分間で10MB以上の継続増加 = リーク疑い
            if (timeDiff > 10 * 60 * 1000 && memoryDiff > 10 * 1024 * 1024) {
                newrelic.recordMetric('Custom/Memory/EventHandler/PotentialLeak', 1);
                
                // アラート情報
                newrelic.addCustomAttribute('memory.leak_rate_mb_per_min', 
                    (memoryDiff / 1024 / 1024) / (timeDiff / 60 / 1000));
                
                // ベースライン更新
                this.memoryBaseline = memUsage.heapUsed;
                this.baselineTime = Date.now();
            }
        }, 30000);  // 30秒間隔
    }
    
    // ✅ 適切なクリーンアップ
    destroy() {
        // イベントリスナー削除
        document.removeEventListener('click', this.boundHandleClick);
        
        // タイマー停止
        if (this.intervalId) {
            clearInterval(this.intervalId);
            this.intervalId = null;
        }
        
        // データクリア
        this.data = null;
        this.additionalData = null;
        
        newrelic.recordMetric('Custom/Memory/EventHandler/Destroyed', 1);
    }
}

// パターン2: 循環参照によるメモリリーク
class CircularReferenceExample {
    
    // ❌ 問題：循環参照でガベージコレクションされない
    static createProblematicStructure() {
        const parent = { children: [], data: new Array(5000).fill('data') };
        const child1 = { parent: parent, siblings: [], data: new Array(3000).fill('child1') };
        const child2 = { parent: parent, siblings: [], data: new Array(3000).fill('child2') };
        
        // 循環参照作成
        parent.children.push(child1, child2);
        child1.siblings.push(child2);
        child2.siblings.push(child1);
        
        // さらに複雑な参照
        child1.reference = child2;
        child2.reference = child1;
        
        return parent;  // 循環参照でメモリが解放されない
    }
    
    // ✅ 改善版：WeakMap を使用した弱参照
    static createImprovedStructure() {
        const parent = { children: [], data: new Array(5000).fill('data') };
        const child1 = { data: new Array(3000).fill('child1') };
        const child2 = { data: new Array(3000).fill('child2') };
        
        // WeakMap で弱参照関係を作成
        const parentChildMap = new WeakMap();
        const siblingMap = new WeakMap();
        
        // 親子関係
        parentChildMap.set(child1, parent);
        parentChildMap.set(child2, parent);
        parent.children.push(child1, child2);
        
        // 兄弟関係
        siblingMap.set(child1, [child2]);
        siblingMap.set(child2, [child1]);
        
        // メモリ使用量監視
        newrelic.recordMetric('Custom/Memory/Structure/Created', 1);
        
        return {
            parent,
            getParent: (child) => parentChildMap.get(child),
            getSiblings: (child) => siblingMap.get(child)
        };
    }
}

// パターン3: クロージャーによる意図しないメモリ保持
function createProblematicClosure() {
    const largeData = new Array(100000).fill('large data array');  // 大量データ
    const moreData = new Array(50000).fill('more data');
    
    // ❌ 問題：クロージャーが大量データを保持し続ける
    return function smallOperation(input) {
        // 実際には largeData は使用しないが、クロージャーにより参照が残る
        return input * 2 + moreData.length;  // moreData のみ使用
    };
}

// ✅ 改善版：必要なデータのみ抽出
function createImprovedClosure() {
    const largeData = new Array(100000).fill('large data array');
    const moreData = new Array(50000).fill('more data');
    
    // 必要なデータのみ抽出
    const moreDataLength = moreData.length;
    
    // largeData, moreData への参照を削除
    // (実際のコードでは適切なスコープ管理で自動的に解放)
    
    return function smallOperation(input) {
        return input * 2 + moreDataLength;  // 数値のみ保持
    };
}