技術をかじる猫

適当に気になった技術や言語、思ったこと考えた事など。

Salesforceのログにインデントをつけるアプリを nodejs で

日記 nodejs Salesforce

Salesforce

2019/4 から Salesforce エンジニアに転職したつつじーです。
半年以上 Salesforce にどっぷり浸かってました（汗

www.kitalive.co.jp

Salesforce は SaaS の大御所で、およそ企業に必要な販売管理、売り上げ管理といった機能をデフォルトで持っています。
また、カスタマイズ機能が非常に豊富で、テーブル定義、処理フロー定義、画面設定、トリガーの設定、アクセス権限設定、バッチの指定、集計の設定、統計の設定、売り上げ予測。
こうした機能が「一切プログラムせずに画面上から設定できる」という強力さがあります。

そんな Salesforce ですから、利用しよう、導入しようという「非IT開発系ベンダー」は凄まじく多いです。
一方でその需要を満たすだけの、カスタマイズサポート、カスタマイズでできない部分の開発などを行うエンジニアが圧倒的に不足中です。

私も就職してから、「なぜエンジニアが死ぬほど少ないか」を理解しました… APEX という存在です。

Apex とは

Apex は Salesforce でほぼ唯一と言っていい開発言語です。
そして 劣化 Java 1.4 と呼べる クソ 言語 です。

Apex は画面上のカスタマイズで補いきれない要件を解決するために実装された独自言語です。

Salesforce では全ての挙動がクラウド上で実行されており、当然そこには複数の企業があります。
となると、リソースの問題や安全の問題が出てくるのですね。
そこで Salesforce は開発者が好き勝手できない様に、わざと制限のある言語を実装したわけです。

ただし、汎用的に言語を作ろうとしたのではなく、あくまで「補助スクリプト」という位置付けで始まり、拡張を繰り返した挙句、一貫性のないひどい言語に仕上がってしまいました（汗
Salesforce もその酷さを理解しているので、最近は pure nodeJs で置き換えれる様に頑張っている様です。

とはいえ、それが実用になるまでは Apex と付き合わざるを得ないので、色々頑張って書いてるのが現状です。

Salesforce の Apex ログ

他の言語から入ってきた人間からみたときに

  • 特にログ出力コードを書かなくても実行ログを出せる
  • ヒープの確保、処理行の実行（with行番号）、メソッドコール&終了、変数への代入、処理時間、クエリの実行内容、実行結果のサマリ など

そう、およそブレークポイントで各行止めて記録したかのようになかなかに詳細なログを自動で吐いてくれます。
そのため、このログを正しく読み取れれば、問題解決もめちゃめちゃスムーズにやれます。

実際、「デバッグのためにログを埋め込む」という必要が無くなるくらいには詳細で強力なログが出ます。
（引き換えに実行されるのがクラウド上であるため、ブレークを仕掛ける…といった運用はできませんが…）

Salesforce Apex ログの問題点

死ぬほどみづらいのです。

例としてはこんな感じ

46.0 APEX_CODE,FINEST;APEX_PROFILING,INFO;CALLOUT,INFO;DB,INFO;NBA,INFO;SYSTEM,DEBUG;VALIDATION,INFO;VISUALFORCE,INFO;WAVE,INFO;WORKFLOW,INFO
21:17:25.0 (836413)|USER_INFO|[EXTERNAL]|0052v00000U12l6|wfower@white-azalea.net|(GMT+09:00) 日本標準時 (Asia/Tokyo)|GMT+09:00
21:17:25.0 (884237)|EXECUTION_STARTED
21:17:25.0 (909684)|CODE_UNIT_STARTED|[EXTERNAL]|01p2v00000RDw3B|TestFizzBuzz.Buzz_Test()
21:17:25.0 (2317055)|HEAP_ALLOCATE|[79]|Bytes:3
21:17:25.0 (2374923)|HEAP_ALLOCATE|[84]|Bytes:152
21:17:25.0 (2393055)|HEAP_ALLOCATE|[399]|Bytes:408
21:17:25.0 (2408807)|HEAP_ALLOCATE|[412]|Bytes:408
21:17:25.0 (2420949)|HEAP_ALLOCATE|[520]|Bytes:48
21:17:25.0 (2452948)|HEAP_ALLOCATE|[139]|Bytes:6
21:17:25.0 (2470802)|HEAP_ALLOCATE|[EXTERNAL]|Bytes:17
21:17:25.0 (2506238)|METHOD_ENTRY|[2]|01p2v00000RDw3B|TestFizzBuzz.TestFizzBuzz()
21:17:25.0 (2517480)|STATEMENT_EXECUTE|[2]
21:17:25.0 (2526450)|STATEMENT_EXECUTE|[2]
21:17:25.0 (2555490)|HEAP_ALLOCATE|[52]|Bytes:5
21:17:25.0 (2585715)|HEAP_ALLOCATE|[58]|Bytes:5
21:17:25.0 (2595597)|HEAP_ALLOCATE|[66]|Bytes:7
21:17:25.0 (3117308)|SYSTEM_MODE_ENTER|false
21:17:25.0 (3140129)|HEAP_ALLOCATE|[EXTERNAL]|Bytes:5
21:17:25.0 (3152746)|SYSTEM_MODE_EXIT|false
21:17:25.0 (3166730)|METHOD_EXIT|[2]|TestFizzBuzz
21:17:25.0 (3223752)|SYSTEM_MODE_ENTER|false
…以下略

わかりますでしょうか？
詳細なのはよいのですが、あくまで「ログ」なのですね…
なので、読みづらくて仕方ない

21:17:25.0 (2506238)|METHOD_ENTRY|[2]|01p2v00000RDw3B|TestFizzBuzz.TestFizzBuzz()
21:17:25.0 (2517480)|STATEMENT_EXECUTE|[2]
21:17:25.0 (2526450)|STATEMENT_EXECUTE|[2]
21:17:25.0 (2555490)|HEAP_ALLOCATE|[52]|Bytes:5
21:17:25.0 (2585715)|HEAP_ALLOCATE|[58]|Bytes:5
21:17:25.0 (2595597)|HEAP_ALLOCATE|[66]|Bytes:7
21:17:25.0 (3117308)|SYSTEM_MODE_ENTER|false
21:17:25.0 (3140129)|HEAP_ALLOCATE|[EXTERNAL]|Bytes:5
21:17:25.0 (3152746)|SYSTEM_MODE_EXIT|false
21:17:25.0 (3166730)|METHOD_EXIT|[2]|TestFizzBuzz

FizzBuzz のコードがこんな感じで書かれていますが、だったらこれをもう少し読みやすく整形しようというのが今回の要旨です。

NodeJs コンソールアプリ

利用したバージョンは下記の通り。

  • nodejs : v11.1.0
  • npm: 6.13.4

NodeJs を使うのは、Salesforce のコマンドラインツール「sfdx」が node で書かれているからです。

と言ってもやることは簡単。

  1. コマンドラインで npm init でプロジェクト作成
  2. コマンドラインで npm install -i command-line-args、npm install -i command-line-usage と叩く
  3. bin ディレクトリを作る
  4. package.json を以下の感じで編集
{
  "name": "log_indent",
  "version": "1.0.0",
  "description": "Add indention to salesforce apex logs.",
  "main": "index.js",
  "scripts": {
    "test": "echo \"Error: no test specified\" && exit 1"
  },
  "keywords": [
    "Salesforce",
    "apex"
  ],
  "author": "つつじー",
  "license": "Apache-2.0",
  "directories": {
    "bin": "bin"
  },
  "dependencies": {
    "command-line-args": "^5.1.1",
    "command-line-usage": "^6.1.0"
  }
}
  1. bin 以下に適当なアプリを書く

そしてソースコード（bin/apex_log_indent.js）は以下の通り。

#!/usr/bin/env node

"use strict";

const commandLineArgs = require('command-line-args');
const commandLineUsage = require('command-line-usage');

const INC_INDENTS = [
    'CONSTRUCTOR_ENTRY',
    'DML_BEGIN',
    'EXECUTION_STARTED',
    'METHOD_ENTRY',
    'SYSTEM_METHOD_ENTRY'
];
const DEC_INDENTS = [
    'CONSTRUCTOR_EXIT',
    'DML_END',
    'METHOD_EXIT',
    'SYSTEM_METHOD_EXIT'
];
const RM_INDENTS = [
    'EXECUTION_FINISHED'
];

const optionDefinitions = [
    {
        name: 'encoding',
        alias: 'e',
        defaultValue: 'UTF-8',
        type: String
    },
    {
        name: 'lineEnding',
        alias: 'l',
        defaultValue: '\n',
        type: String
    },
    {
        name: 'help',
        alias: 'h',
        type: Boolean,
        description: 'show help'
    }
];

function readCommands() {
    return commandLineArgs(optionDefinitions);
}

function printUsage() {
    const sections = [
        {
            header: 'Salesforce apex log indention tool.',
            content: 'Add indent charactors to apex debug log.'
        },
        {
            header: 'Options',
            optionList: optionDefinitions
        }
    ];
    const usage = commandLineUsage(sections);
    console.log(usage);
}

const LINE_REGEX = /\d{2}:\d{2}:\d{2}\.\d+ \(\d+\)\|([A-Z_]+).*/;

function calcCurrentIndent(currentIndent, lineStr) {
    let result = lineStr.match(LINE_REGEX);
    if (result) {
        let first = result[1];
        if (INC_INDENTS.indexOf(first) >= 0) {
            return [currentIndent, currentIndent + 1];
        }
        if (DEC_INDENTS.indexOf(first) >= 0) {
            currentIndent = currentIndent > 0 ? currentIndent - 1 : 0;
            return [currentIndent, currentIndent];
        }
        if (RM_INDENTS.indexOf(first) >= 0) {
            return [0, 0];
        }
    }
    return [currentIndent, currentIndent];
}

function toIndent(indent) {
    let str = '';
    for (var i = 0; i < indent; i++) {
        str = str + '    ';
    }
    return str;
}

function readStream(inputText, lineEnding, indentLength) {
    let currentIndention = indentLength;
    inputText.split(lineEnding).forEach(line => {
        let indentions = calcCurrentIndent(currentIndention, line);
        let indent = indentions[0];
        currentIndention = indentions[1];

        process.stdout.write(toIndent(indent) + line + lineEnding);
    });
    return currentIndention;
}

function main() {
    const options = readCommands();
    if(options.help) {
        printUsage();
        process.exit(0);
    }

    const ENCODING = options.encoding;
    const LINE_END = options.lineEnding;

    process.stdin.resume();
    process.stdin.setEncoding(ENCODING);

    let indentLength = 0;
    process.stdin.on('data', str => {
        indentLength = readStream(str, LINE_END, indentLength);
    });
}

main();

まぁシンプルに。

実行してみる

コンソール上で、「npm link」と叩くと、このアプリケーションへのエイリアスが登録されます。
つまりこれで実行できる様になります。

動作仕様は上記コードを読み解くとわかりますが

  1. 起動パラメータは 「-e エンコード」「-l 改行コード」「-h」の３種
  2. 標準入力（process.stdin.on... 近辺）を取得し、INC_INDENTS, DEC_INDENTS の定義にしたがってインデントを計算(calcCurrentIndent)
  3. ログ行をインデント（toIndent）して標準出力へ返す

という感じです。

% npm link  
% apex_log_indent.js -h

Salesforce apex log indention tool.

  Add indent charactors to apex debug log. 

Options

  -e, --encoding string               
  -l, --lineEnding string             
  -h, --help                show help

そして実行。

% cat output.log | apex_log_indent.js
46.0 APEX_CODE,FINEST;APEX_PROFILING,INFO;CALLOUT,INFO;DB,INFO;NBA,INFO;SYSTEM,DEBUG;VALIDATION,INFO;
VISUALFORCE,INFO;WAVE,INFO;WORKFLOW,INFO
21:17:25.0 (836413)|USER_INFO|[EXTERNAL]|0052v00000U12l6|wfower@white-azalea.net|(GMT+09:00) 日本標準時 (Asia/Tokyo)|GMT+09:00
21:17:25.0 (884237)|EXECUTION_STARTED
    21:17:25.0 (909684)|CODE_UNIT_STARTED|[EXTERNAL]|01p2v00000RDw3B|TestFizzBuzz.Buzz_Test()
    21:17:25.0 (2317055)|HEAP_ALLOCATE|[79]|Bytes:3
    21:17:25.0 (2374923)|HEAP_ALLOCATE|[84]|Bytes:152
    21:17:25.0 (2393055)|HEAP_ALLOCATE|[399]|Bytes:408
    21:17:25.0 (2408807)|HEAP_ALLOCATE|[412]|Bytes:408
    21:17:25.0 (2420949)|HEAP_ALLOCATE|[520]|Bytes:48
    21:17:25.0 (2452948)|HEAP_ALLOCATE|[139]|Bytes:6
    21:17:25.0 (2470802)|HEAP_ALLOCATE|[EXTERNAL]|Bytes:17
    21:17:25.0 (2506238)|METHOD_ENTRY|[2]|01p2v00000RDw3B|TestFizzBuzz.TestFizzBuzz()
        21:17:25.0 (2517480)|STATEMENT_EXECUTE|[2]
        21:17:25.0 (2526450)|STATEMENT_EXECUTE|[2]
        21:17:25.0 (2555490)|HEAP_ALLOCATE|[52]|Bytes:5
        21:17:25.0 (2585715)|HEAP_ALLOCATE|[58]|Bytes:5
        21:17:25.0 (2595597)|HEAP_ALLOCATE|[66]|Bytes:7
        21:17:25.0 (3117308)|SYSTEM_MODE_ENTER|false
        21:17:25.0 (3140129)|HEAP_ALLOCATE|[EXTERNAL]|Bytes:5
        21:17:25.0 (3152746)|SYSTEM_MODE_EXIT|false
    21:17:25.0 (3166730)|METHOD_EXIT|[2]|TestFizzBuzz
    21:17:25.0 (3223752)|SYSTEM_MODE_ENTER|false
    21:17:25.0 (3231337)|HEAP_ALLOCATE|[22]|Bytes:5
    21:17:25.0 (3236817)|STATEMENT_EXECUTE|[15]
    21:17:25.0 (3238726)|STATEMENT_EXECUTE|[21]
    21:17:25.0 (3242244)|HEAP_ALLOCATE|[22]|Bytes:4
以下略

コールスタックごとにインデントしてくれるようになるので、多少マシになります。