項目
付録¶
パターン文字列¶
パターン文字列はログ設定ファイルでパターンの指定を行う箇所で利用できます。%変換文字列 のように指定します。例)%logger
ロガー名¶
変換文字列 説明 c{length}lo{length}logger{length} ロガー名を表示します。length を指定することで、出力するロガー名の長さを制限します。例)mainPackage.sub.sample.Bar というロガー名を出力する場合
変換文字列 出力結果 %logger mainPackage.sub.sample.Bar %logger{10} m.s.s.Bar %logger{15} m.s.sample.Bar
出力日時¶
変換文字列 説明 d{pattern}date{pattern}d{pattern, timezone}date{pattern, timezone} ログの出力を行った日時を表示します。pattern を指定することで出力する日時の表示形式を変更することが可能です。pattern で指定可能な形式は java.text.SimpleDateFormat と同様です。pattern を指定しない場合は yyyy-MM-dd HH:mm:ss,SSS で表示します。timezone を指定することで、特定のタイムゾーンでの日時で表示することが可能です。timezone で指定可能な形式は、Asia/Tokyo などの java.util.Timezone#getTimeZone(String) で指定する値と同様です。timezone を指定しない場合は、Java VMのデフォルトのタイムゾーンで表示します。例)日本時間 2013年10月1日 1時2分3秒4ミリ秒にログを出力した場合※ Java VMのデフォルトのタイムゾーンは Asia/Tokyo とします。
変換文字列 出力結果 %d 2013-10-01 01:02:03,004 %d{yyyy/MM/dd} 2013/10/01 %d{yyyy/MM/dd, GMT} 2013/09/31 %d{'yyyy-MM-dd HH:mm:ss,SSS', GMT} 2013-09-31 16:02:03,004 コラム
timezone の指定を行いつつ、pattern に , (カンマ)を含む形式を指定する場合は、pattern の文字列を ' (クォート)で括ってください。
MDC¶
変換文字列 説明 X{key}MDC{key}X{key:-default}MDC{key:-default} ログが生成したスレッドのMDCの内容を表示します。key にMDCのキーを指定します。default を指定した場合、指定したキーにの値が null であった場合に default の値が出力されます。MDCの詳細については「MDC」を参照してください。
例外¶
変換文字列 説明 ex{depth}exception{depth}throwable{depth}ex{depth, evaluator...}exception{depth, evaluator...}throwable{depth, evaluator...} 例外を出力します。depth に値を指定した場合の動作は以下の通りです。
値 出力内容 short 最初のスタックトレースのみ表示します。ネストしたスタックトレースを表示しません。 full ネストしたスタックトレースをすべて表示します。depth を指定しない場合のデフォルト値です。 整数 スタックトレースを指定した深さまで表示します。 evaluator の指定方法についてはLogbackのWebサイト「パターン文字列ex」を参照してください。
パッケージ情報付き例外¶
変換文字列 説明 xEx{depth}xException{depth}xThrowable{depth}xEx{depth, evaluator...}xException{depth, evaluator...}xThrowable{depth, evaluator...}
値 出力内容 short 最初のスタックトレースのみ表示します。ネストしたスタックトレースを表示しません。 full ネストしたスタックトレースをすべて表示します。depth を指定しない場合のデフォルト値です。 整数 スタックトレースを指定した深さまで表示します。 evaluator の指定方法についてはLogbackのWebサイト「パターン文字列xEx」を参照してください。
置換¶
変換文字列 説明 replace(p){r, t} 対象の文字列の置換を行います。p で指定した文字列に含まれる r をすべて t に変換します。r は正規表現で記述します。例)ロガー名の . (ドット)を / (スラッシュ)に置換する
ロガー名 jp.co.intra_mart.common.platform.log.Logger %logger{10} による出力 j.c.i.c.p.l.Logger %replace(%logger{10}){'\.`, `\/'} による出力 j/c/i/c/p/l.Logger
逆表示例外¶
変換文字列 説明 rEx{depth}rootException{depth}rEx{depth, evaluator...}rootException{depth, evaluator...} 例外を発生元を先頭で出力します。「例外」や「パッケージ情報付き例外」ではネストした例外の「外側」から「内側」の順に表示しますが、このパターン文字列では「内側」から「外側」の順に表示します。depth に値を指定した場合の動作は以下の通りです。
値 出力内容 short 最初のスタックトレース(根本の例外)のみ表示します。 full ネストしたスタックトレースをすべて表示します。depth を指定しない場合のデフォルト値です。 整数 スタックトレースを指定した深さまで表示します。 evaluator の指定方法についてはLogbackのWebサイト「パターン文字列rEx」を参照してください。
ログを解析する¶
ログ解析方法の例を紹介します。サーバの運用状態を知りたい場合にシステムログ、リクエストログなどのログを1つのファイルにまとめることにより、様々な情報を得ることができます。コラム
解析に必要な情報は、あらかじめログ設定ファイルに設定しておく必要があります。各ログファイルで出力可能な項目については、「特定用途ログ」を参照してください。
トランザクション単位での調査¶
スレッド、出力時間、ログ出力順序番号でソートを行うことにより、ログメッセージを処理トランザクション毎にまとまることができます。
セットアップ実行ログについて¶
テナント環境セットアップ、および、サンプルデータセットアップの実行結果は、セットアップ実行結果ログに出力されます。詳細は、「テナント環境セットアップ 仕様書のセットアップ実行結果ログ」を参照してください。
インポートエラーの原因をログから追跡する¶
インポートエラーが発生した場合にその原因を追跡する方法を紹介します。注意
以下は、「インポート・エクスポートログ」の設定が初期設定である前提の説明です。
インポートの実行IDを特定します。
実行IDを特定する方法は以下の通りです。
実行IDはインポートエラー発生時に標準出力に出力されるエラーログから特定する
例)アカウントインポート実行エラー時の出力
[ERROR] I.j.c.i.f.d.u.ImportExportLog - [E.IWP.IMPORTEXPORT.IMPORTER.10001] データのインポートに失敗しました。 実行クラス = jp.co.intra_mart.system.admin.account.data.AccountInfoXmlImporter, 実行ID = <%実行ID%>テナント環境セットアップ、または、サンプルデータセットアップにてインポートエラーが発生した場合は、セットアップ実行ログに出力されている実行IDを参照する
例)アカウントインポート実行エラー時の出力
<import-result-detail-data success="false"> <module-id>im_sample_data</module-id> <execute-id><%実行ID%></execute-id> <import-type>DML</import-type> <importer-id>jp.co.intra_mart.import.StandardAccountXmlImporter</importer-id> <target-name>products/import/basic/im_sample_data/im_sample_data-account.xml</target-name> <message>[E.IWP.IMPORTEXPORT.IMPORTER.10001] データのインポートに失敗しました。 実行クラス = jp.co.intra_mart.system.admin.account.data.AccountInfoXmlImporter, 実行ID = <%実行ID%></message> </import-result-detail-data>インポートログを特定します。
システムストレージに出力されている、インポートログを特定します。ログは <STORAGE_PATH>/system/storage/log/import-export フォルダ直下に出力されます。ファイル名は <%実行ID%>.log です。インポートログからエラー原因を特定します。
インポートログの付与情報、例外を元にエラー原因を特定します。以下は、アカウントインポートジョブの実行により、インポートエラーが発生した際のエラーログです。出力されている処理番号(MDCキー:data.io.record.num)から、5番目に処理されたデータがエラーであること、また、出力されている例外情報から、アカウントに指定されているロケールIDの指定が不正であることが読み取れます。[2013-10-18 10:46:19.999] 5i7um1o07vj9k : [INFO ] 0 - [I.IWP.IMPORTEXPORT.IMPORTER.10001] インポートを開始します。 実行クラス = jp.co.intra_mart.system.admin.account.data.AccountInfoXmlImporter, 実行ID = a0fd4cdd-0b2d-4ed4-a2db-b86d1971140b : - [2013-10-18 10:46:20.179] 5i7um1o080j9t : [ERROR] 5 - [E.IWP.IMPORTEXPORT.IMPORTER.10001] データのインポートに失敗しました。 実行クラス = jp.co.intra_mart.system.admin.account.data.AccountInfoXmlImporter, 実行ID = a0fd4cdd-0b2d-4ed4-a2db-b86d1971140b : - jp.co.intra_mart.foundation.data.exception.DataImporterException: jp.co.intra_mart.system.data.importer.validation.exception.ValidateException: [E.IWP.IMPORTER.ACCOUNT.00001] ロケールマスタに定義されていないロケールIDが指定されています。 at jp.co.intra_mart.system.admin.account.data.AbstractAccountInfoImporter.validate(AbstractAccountInfoImporter.java:328) at jp.co.intra_mart.system.admin.account.data.AbstractAccountInfoImporter.execute(AbstractAccountInfoImporter.java:85) at jp.co.intra_mart.system.admin.account.data.AbstractAccountInfoImporter.execute(AbstractAccountInfoImporter.java:44) at jp.co.intra_mart.system.data.importer.impl.AbstractDataImporter.importData(AbstractDataImporter.java:153) at jp.co.intra_mart.foundation.data.importer.DataImportExecutor.importData(DataImportExecutor.java:189) at jp.co.intra_mart.system.job_scheduler.import_export.StandardImportJob.executeImport(StandardImportJob.java:109) at jp.co.intra_mart.system.job_scheduler.import_export.StandardImportJob.execute(StandardImportJob.java:91) at jp.co.intra_mart.system.job_scheduler.quartz.jobs.AbstractJobnetExecuter.executeJob(AbstractJobnetExecuter.java:288) at jp.co.intra_mart.system.job_scheduler.quartz.jobs.SerializeJobnetExecuter.executeJobnet(SerializeJobnetExecuter.java:62) at jp.co.intra_mart.system.job_scheduler.quartz.jobs.AbstractJobnetExecuter.execute(AbstractJobnetExecuter.java:70) at org.quartz.core.JobRunShell.run(JobRunShell.java:213) at jp.co.intra_mart.system.job_scheduler.quartz.threadpool.ExecutorThreadPool$WorkerThread.run(ExecutorThreadPool.java:530) Caused by: jp.co.intra_mart.system.data.importer.validation.exception.ValidateException: [E.IWP.IMPORTER.ACCOUNT.00001] ロケールマスタに定義されていないロケールIDが指定されています。 at jp.co.intra_mart.system.admin.account.data.validate.AccountValidator.localeId(AccountValidator.java:89) at jp.co.intra_mart.system.admin.account.data.validate.AccountValidator.validate(AccountValidator.java:59) at jp.co.intra_mart.system.admin.account.data.AbstractAccountInfoImporter.validate(AbstractAccountInfoImporter.java:325) ... 11 common frames omitted
JMXによるログ設定の操作¶
JMX(Java Management Extensions)利用してログレベルの取得、変更を行う方法を紹介します。コラム
JMXによる操作を行うには im_logger.xml に <jmxConfigurator> が設定されている必要があります。intra-mart Accel Platform の初期状態では設定されています。コラム
以下は、ローカルプロセスとして起動しているアプリケーションサーバのログ設定を操作する手順です。外部のリモートプロセスのアプリケーションサーバのログ設定を操作を行う必要がある場合は、適切なJMXを別途行ってください。
アプリケーションを起動します。
アプリケーションサーバが利用しているJava VMのjconsoleを起動します。
jconsoleは %JAVA_HOME%/bin 直下に配置されています。
該当するアプリケーションサーバのプロセスを選択し、「接続」をクリックします。
「MBean」タブをクリックします。
ch.qos.logback.classic > default > ch.qos.logback.classic.jmx.JMXConfigurator > 操作 をクリックします。
以下の操作が行えます。
getLoggerEffectiveLevel
指定したロガー名を利用した場合に有効となるログレベルが取得できます。第1引数にはロガー名を指定します。ロガー名を持つロガーが存在しない場合は、ルートロガーのログレベルが取得できます。getLoggerLevel
指定したロガー名を持つロガーに設定されているログレベルが取得できます。第1引数にはロガー名を指定します。ロガー名を持つロガーが存在しない場合は、nullが返却されます。setLoggerLevel
指定したロガー名に対してログレベルを設定します。第1引数にはロガー名を指定します。第2引数にはログレベルを指定します。
MDCに格納されている値でログを分割する¶
MDCに格納されている値ごとにログファイルを分割する方法を紹介します。セキュリティログ をMDCキー security.id.usertype を利用して、一般ユーザ、システム管理者などのユーザ種別ごとに別々に出力するサンプルを作成します。
セキュリティログ設定ファイル(%CONTEXT_PATH%/WEB-INF/conf/log/im_logger_security.xml)を以下のように変更します。
<included> <!-- appender "SECURITY_FILE" の設定を省略しています。 --> <appender name="PER_USERTYPE" class="ch.qos.logback.classic.sift.SiftingAppender"> <discriminator> <key>security.id.usertype</key> <defaultValue>unknown</defaultValue> </discriminator> <sift> <appender name="FILE-${security.id.usertype}" class="ch.qos.logback.core.FileAppender"> <file>${im.log}/platform/security_per_usertype/${security.id.usertype}.log</file> <append>true</append> <encoder> <pattern>[%d{yyyy-MM-dd HH:mm:ss.SSS}] [%thread] %X{log.report.sequence} %-5level %logger{255} %X{log.id} - %X{security.id.session} %X{security.id.account} %X{security.id.usertype} [%X{log.message.code}] %msg %X{request.id}%nopex%n</pattern> </encoder> </appender> </sift> </appender> <logger name="SECURITY_LOG" additivity="false"> <level value="warn" /> <appender-ref ref="STDOUT" /> <appender-ref ref="SECURITY_FILE" /> <appender-ref ref="PER_USERTYPE" /> </logger> </included>アプリケーションを起動(再起動)します。
一般ユーザログイン画面(http://<HOST>:<PORT>/<CONTEXT_PATH>/login)にアクセスし、存在しない一般ユーザのユーザコード/パスワードを入力しログインに失敗します。
コラム
ログインに失敗することでセキュリティログ(WARNレベル)を出力します。
システム管理者ログイン画面(http://<HOST>:<PORT>/<CONTEXT_PATH>/system/login)にアクセスし、存在しないシステム管理者のユーザコード/パスワードを入力しログインに失敗します。
コラム
ログインに失敗することでセキュリティログ(WARNレベル)を出力します。
%CONTEXT_PATH%/WEB-INF/log/security_per_usertype 直下に、user.log と administrator.log がそれぞれ出力されています。
コラム
一般ユーザでのセキュリティログが user.log に、システム管理者でのセキュリティログが administrator.log に出力されます。
独自に作成したログの実装を利用する¶
アプリケーション開発者が独自のAppenderやEncoderを作成できます。独自に作成したクラスが含まれるjarファイルを %CONTEXT_PATH%/WEB-INF/lib 直下に配置することで利用できます。
commons-logging, log4jの利用について¶
commons-loggingライブラリ、および、log4jライブラリを利用したログ出力を行うアプリケーションも、プログラムを変更すること無くログ出力を行うことができます。intra-mart Accel Platform で利用しているSLF4Jのブリッジライブラリのバージョン情報は以下の通りです。
iAP の バージョン バージョン jarファイル名 2013 Summer(Damask) 以前 1.6.6 jcl-over-slf4j-1.6.6.jarlog4j-over-slf4j-1.6.6.jar2013 Autumn(Eden) から 2014 Winter(Iceberg) 以前 1.7.5 jcl-over-slf4j-1.7.5.jarlog4j-over-slf4j-1.7.5.jar2015 Spring(Juno) 以降 1.7.10 jcl-over-slf4j-1.7.10.jarlog4j-over-slf4j-1.7.10.jarこの方法でログを出力する場合、commons-logging、および、log4jのログ設定は、利用できません。それぞれの設定を intra-mart Accel Platform のログ設定ファイルに移行する必要があります。ログ設定ファイルの作成方法ついては「ログ設定」を参照してください。
SQLログを出力する¶
log4jdbcを利用する場合¶
SQLログの出力は、パフォーマンスやデータ量など運用時の各種要件を考慮した上で、DBベンダー提供のツールやOSS等の各種ライブラリを利用してください。ここでは、「log4jdbc」を利用して intra-mart Accel Platform 上で発行しているSQLをログに出力する方法を紹介します。(log4jdbcに関するお問い合わせはlog4jdbcのWebサイトで行ってください。)以下はアプリケーションサーバ Resin での手順です。
必要な資材を準備します。
log4jdbcの取得
https://code.google.com/archive/p/log4jdbc/downloads から log4jdbc4-*.jar をダウンロードします。
Janinoライブラリの取得
intra-mart Accel Platform では Job Scheduler Service が一定の間隔でジョブの監視を行うため、定期的にSQLを発行します。このSQLがログへ出力されることを抑制するために「EvaluatorFilter」と「JaninoEventEvaluator」を利用します。資材を配置します。
%CONTEXT_PATH%/WEB-INF/lib 直下に取得した log4jdbc4-*.jar、janino-*.jar、commons-compiler-*.jar を配置します。
resin-web.xml を変更します。
%CONTEXT_PATH%/WEB-INF/resin-web.xml のJDBCドライバの完全修飾クラス名、データベース接続先を変更します。
PostgreSQL
変更前
<type>org.postgresql.ds.PGConnectionPoolDataSource</type> <url>jdbc:postgresql://localhost:5432/dbname</url>変更後
<type>net.sf.log4jdbc.DriverSpy</type> <url>jdbc:log4jdbc:postgresql://localhost:5432/dbname</url>Oracle Database
変更前
<type>oracle.jdbc.pool.OracleConnectionPoolDataSource</type> <url>jdbc:oracle:thin:@localhost:1521:orcl</url>変更後
<type>net.sf.log4jdbc.DriverSpy</type> <url>jdbc:log4jdbc:oracle:thin:@localhost:1521:orcl</url>Microsoft SQL Server
変更前
<type>com.microsoft.sqlserver.jdbc.SQLServerConnectionPoolDataSource</type> <url>jdbc:sqlserver://localhost:1433;DatabaseName=databasename</url>変更後
<type>net.sf.log4jdbc.DriverSpy</type> <url>jdbc:log4jdbc:sqlserver://localhost:1433;DatabaseName=databasename</url>コラム
ホストやデータベース名は開発環境にあわせて設定してください。
コラム
Java 17 を利用する場合、「プリペアドステートメントキャッシュ設定」では prepared-statement-cache-size タグの設定を外し、JDBC 1.0 の設定方法で初期化パラメータを設定してください。
ログ設定ファイルを作成する
%CONTEXT_PATH%/WEB-INF/conf/log 直下に im_logger_log4jdbc.xml を作成し、内容を以下のようにします。
<included> <appender name="JDBC_STDOUT" class="ch.qos.logback.core.ConsoleAppender"> <filter class="ch.qos.logback.core.filter.EvaluatorFilter"> <evaluator> <expression>return message.contains("IMJOB_QRTZ_SCHEDULER_STATE") || message.contains("IMJOB_QRTZ_TRIGGERS") || message.contains("im_async_task_info");</expression> </evaluator> <onMatch>DENY</onMatch> <onMismatch>NEUTRAL</onMismatch> </filter> <encoder> <outputPatternAsHeader>true</outputPatternAsHeader> <pattern>[%level] %logger{10} - %msg%n</pattern> </encoder> </appender> <logger name="jdbc.sqlonly" additivity="false"> <level value="off" /> </logger> <logger name="jdbc.sqltiming" additivity="false"> <level value="info" /> <appender-ref ref="JDBC_STDOUT" /> </logger> <logger name="jdbc.audit" additivity="false"> <level value="off" /> </logger> <logger name="jdbc.resultset" additivity="false"> <level value="off" /> </logger> <logger name="jdbc.connection" additivity="false"> <level value="off" /> </logger> </included>アプリケーションを起動(再起動)します。
コラム
Java 17 を利用する場合は、起動時のJVM引数に以下を追加してください。--add-opens=java.base/sun.util.calendar=ALL-UNNAMED--add-opens=java.base/java.time=ALL-UNNAMED--add-opens=java.base/java.time.zone=ALL-UNNAMED--add-opens=java.base/java.util.concurrent=ALL-UNNAMEDコンソール(標準出力)を確認します。
SQLを利用する処理が動作するごとに以下のようなログが出力されます。[INFO] j.sqltiming - select b.menu_group_id from ( SELECT menu_group_id FROM b_m_menu_group_cate_inclusion WHERE category IN ('im_sitemap_pc') ) a inner join b_m_menu_group_b b on a.menu_group_id = b.menu_group_id inner join b_m_menu_b c on b.menu_id = c.menu_id ORDER BY c.sort_number,b.menu_group_id {executed in 43 msec} [INFO] j.sqltiming - SELECT * FROM imaz_resource WHERE resource_id = 'd0b2358a8017b27c11bfacc2e7640f85b47d3f89aeacaaebe3d1c24ba92486be' {executed in 0 msec} [INFO] j.sqltiming - select a.resource_group_set_id, a.resource_group_id from imaz_resource_group a inner join imaz_resource_group_ath b on a.resource_group_set_id = b.resource_group_set_id and a.resource_group_id = b.resource_group_id where b.resource_id = 'd0b2358a8017b27c11bfacc2e7640f85b47d3f89aeacaaebe3d1c24ba92486be' order by a.resource_group_set_id, a.resource_group_id {executed in 2 msec} [INFO] j.sqltiming - select a.resource_group_id, a.resource_group_set_id, c.resource_id, c.uri, c.resource_type from imaz_resource_group a left join imaz_resource_group_ath b on a.resource_group_id = b.resource_group_id left join imaz_resource c on b.resource_id = c.resource_id where a.resource_group_id = 'd0b2358a8017b27c11bfacc2e7640f85b47d3f89aeacaaebe3d1c24ba92486be' order by a.resource_group_set_id, a.resource_group_id, c.resource_type, c.resource_id {executed in 1 msec}
mirageを利用する場合¶
mirageフレームワークモジュールの機能を使用することで、バインド変数値付きのSQLログをコンソールに出力できます。
%CONTEXT_PATH%/WEB-INF/conf/log 直下の im_logger_mirage.xml を開きます。
SqlExecutor のログレベルを「debug」に変更します。
1 2 3 4 5 6 7 8 9 10 <included> <logger name="jp.co.intra_mart.mirage" additivity="false"> <level value="info" /> <appender-ref ref="STDOUT" /> </logger> <logger name="jp.co.intra_mart.mirage.SqlExecutor" additivity="false"> <level value="debug" /> <appender-ref ref="STDOUT" /> </logger> </included>アプリケーションを起動(再起動)します。
コラム
このログは、mirageフレームワークを利用した機能からSQL発行を行った場合にのみ出力されます。スクリプト開発モデルのTenantDatabaseオブジェクト、SharedDatabaseオブジェクト からの実行時などが該当します。コラム
開発環境での利用を想定しているため、インストール時にはSQLログ出力が行われないように設定されています。必要に応じてログレベルを変更してください。