[bug]マルチプロセスでlog4netのファイルローテーション時に一部ログが欠損して困った

福岡の香月です。

log4netのRollingFileAppenderを使って日付で出力ファイルが切り替わる設定をしていたところ、日付が変わって新しいファイルへの出力が始まると先頭に出力されるであろうログがなぜか出力されない現象に遭遇しました。
設定はこうです。
複数のプロセスで同じ設定を用いて、同じファイルに対してログ出力します。

<appender name="SystemLogAppender" type="log4net.Appender.RollingFileAppender">
  <file value="log/system.log" />
  <appendToFile value="true" />
  <datePattern value="_yyyyMMdd" />
  <preserveLogFileNameExtension value="true" />
  <staticLogFileName value="false" />
  <lockingModel type="log4net.Appender.FileAppender+InterProcessLock" />
  <encoding value="Shift_JIS"/>
  <maxSizeRollBackups value="-1" />
  <maximumFileSize value="2GB" />
  <layout type="log4net.Layout.PatternLayout">
    <param name="ConversionPattern" value="%d{yyyy-MM-dd HH:mm:ss.fff} %-5p %m%n"/>
  </layout>
</appender>

AppenderはRollingFileAppenderを指定しています。複数プロセスで使用するため、lockingModelはInterProcessLockを指定します。これによりファイルストリームを開きっぱなしにして、mutexで排他制御しながら末端にシークし書き込みを行うことで、複数プロセスから効率的にログ出力を行ってくれます。
複数プロセスから使う場合はこれ以外にもMinimalLockを指定できますが、書き込むたびにファイルのオープンクローズを実施するため速度が求められる場合は不向きでしょう。さらに複数プロセスからの出力が同時に走った場合、片方はオープンできないためログが出力されません。

この設定でビルドし、業務終わりにアプリを起動して一晩中実行させ、翌朝出社して確認しても日付が変わった後のログの内容が足りませんでした。
最初はlog4netの使い方が悪いのか、自分のプログラムにバグがあるのかさんざん悩んだんですがさっぱりわからない。トレース用に埋め込んだログも当然のように出ていないのでどうしたものかと思いました。

しかし、プロセスが1つの場合はちゃんと期待通りのログが出ていました。問題があるのは複数プロセスの場合だけだったのです。

そこでlog4netのロジックを確認することにしました。 幸いなことにソースはこちらから取得できます。
https://github.com/apache/logging-log4net
すると、ファイルが切り替わったあとは最後に書き込んだプロセスのログが先頭に来て、それ以前のログが破棄される作りになっていたのです。

少しずつソースを見てみましょう。今回使っているのはRollingFileAppenderです。日付が変わるときにファイルを切り替える部分は、RollOverTime()という関数であることがわかりました。こうなっています。
https://github.com/apache/logging-log4net/blob/master/src/Appender/RollingFileAppender.cs

protected void RollOverTime(bool fileIsOpen) 
{
    :
    :
    if (fileIsOpen)
    {
        // This will also close the file. This is OK since multiple close operations are safe.
        SafeOpenFile(m_baseFileName, false);
    }
}

ふむふむ、SafeOpenFile()で新しいファイルをオープンしに行くわけね。そして第二引数がfalseと。そしてSaveOpenFile()の実態はベースクラスFileAppenderにありました。
https://github.com/apache/logging-log4net/blob/master/src/Appender/FileAppender.cs
ここから次の順番で呼び出されていきます。

  • RollingFileAppender.OpenFile()
  • FileAppender.OpenFile()
  • FileAppender.InterProcessLock.OpenFile()
  • FileAppender.LockingModelBase.CreateStream()
protected Stream CreateStream(string filename, bool append, FileShare fileShare)
{
	using (CurrentAppender.SecurityContext.Impersonate(this))
	{
		// Ensure that the directory structure exists
		string directoryFullName = Path.GetDirectoryName(filename);

		// Only create the directory if it does not exist
		// doing this check here resolves some permissions failures
		if (!Directory.Exists(directoryFullName))
		{
			Directory.CreateDirectory(directoryFullName);
		}

		FileMode fileOpenMode = append ? FileMode.Append : FileMode.Create;
		return new FileStream(filename, fileOpenMode, FileAccess.Write, fileShare);
	}
}

ここでSafeOpenFile()の第二引数で指定されたfalseは、CreateStreamのappendに代入されていることがわかりました。この場合FileMode.Createが指定され、FileStreamインスタンスが作成されます。
ではこのFileMode.Createはどのような動きをするかというと、

オペレーティング システムが新しいファイルを作成することを指定します。ファイルが既に存在する場合は上書きされます。これには Write 許可が必要です。
FileMode.Create は、ファイルが存在しない場合は CreateNew を使用した要求、ファイルが存在する場合は Truncate を使用した要求と等価です。

https://docs.microsoft.com/ja-jp/dotnet/api/system.io.filemode?view=netcore-3.1

複数のプロセスでログ出力を行う場合、FileStreamを最後に作成するプロセスによりそれまでのプロセスが作成したログファイルの中身がTruncateされて、つまり削除されてしまうわけです。
発生している現象とも合致するのでこれが問題であることを確信しました。

対応するためにはRollingFileAppender.RollOverTime()から呼んでるSafeOpenFile()の第二引数をtrueに知ればよいわけです。実際に修正して確認してみると、見事欠損することなく必要なログが出力されていました。
めでたしめでたし。

なお、SafeOpenFile()はRollingFileAppender.RollOverSize()内からも呼び出しているのでここも忘れずにtrueに変更しましょう。

C#でWOL(Wake-on-LAN)

福岡の香月です。

コロナ対応で世の中はリモートワークが進んでいるようです。中程度スペックの中古PCもたくさん売れているようで、在庫が少なくなっているようですね。

自宅作業する場合、会社のPCにリモートデスクトップでつないで作業することも多いと思いますが、気付いたらPCがシャットダウンしていることがあります。間違って電源切ったとか、夜中にWindows Updateが動いたとか。

そんな時はWOL(Wake-on-LAN)ですが、私はこれについて知識が無かったので調べがてらC#プログラムのWOLツールを作ってみました。プラットフォームは.Net Core 3.1です。
以下全文です。どん!

特徴

  • マジックパケットを飛ばします。マジックパケットとは…
    • UDPで送信するパケット
    • 先頭6バイトに{ 0xFF, 0xFF, 0xFF, 0xFF, 0xFF, 0xFF }
    • 続けて対象PCのmacアドレスを16回
    • 合わせて102バイトのパケットとなる。
  • exeと同じ名前のiniファイルを設定ファイルとして読み込む
  • 設定ファイルにて以下を設定
    • host=対象PCのIPアドレス
    • post=UDPポート(ルータが許可したポートであれば何でもOK)
    • macアドレス=対象PCのmacアドレス
  • エラーが発生した場合はコンソール上にエラーを表示

プログラムは案外簡単でびっくりしました。
それよりもWOLが使える環境の設定が大変そうですね。BIOS、ネットワークカード、Windowsの設定など、情報はぐぐればいろいろ出てきますので一度お試しあれ。

Swagger-PHPでOA\PathItem()エラー

福岡拠点の野田です。
OpenAPI(Swagger)の仕様書を使っていますか?

PHPでは、アノテーションでOpenAPIを定義できるSwagger-PHPというものがあります。使うためには以下を実行します。

composer require --dev zircote/swagger-php

対象のコントローラーを指定するとアノテーションで記載したコメントがAPI仕様書になるという素晴らしいライブラリです。swagger.ymlの書き出し方は、以下。

vendor/zircote/swagger-php/bin/openapi app/Http/Controllers/Api/*Controller.php -o swagger.yml

ここで少しはまりどころがあります。
OA\Infoを定義したクラスには必ずOA\GetやOA\PutといったAPIをセットで定義しなければなりません。それをしないと以下のエラーで怒られます。

Required @OA\PathItem() not found

ちょー分かりにくいエラーなので、私もはまりました。そんなときは汎用エラーレスポンスでも定義してしのぎましょう。

    /**
     * @OA\Put(
     *     path="/api/*",
     *     tags={"ErrorCommon"},
     *     description="APIエラー共通",
     *     @OA\Response(
     *          response="default",
     *          description="APIエラー時の返却データ",
     *          @OA\JsonContent(
     *              @OA\Property(property="error", type="integer", description="エラー値(0:正常/1:エラー)"),
     *              @OA\Property(property="errorId", type="string", description="エラーID"),
     *              @OA\Property(property="code", type="string", description="エラーコード"),
     *              @OA\Property(property="message", type="string", description="エラーメッセージ"),
     *          )
     *     )
     * ),
     */
    private function error() {
        throw new UnsupportedOperationException();
    }

これはライブラリ側でなんとかしてほしかったところではありますが、めげずにswaggerを使っていきましょう。

それでは、また!

nuxt.js環境を構築する

福岡拠点の野田です。

サーバーサイドでレンダリングするSSR(Server Side Rendering)を次の案件で使うことにしました。API側は慣れ親しんだLaravel。

最初に悩むのが環境構築。
どうしようか、というところで参考にしたのが、次の記事。

LaravelとNuxt.jsを同一レポジトリで管理するときの構成https://www.wantedly.com/companies/roxx/post_articles/84615

client フォルダ以下に環境を作る例ですが、とても参考になりました。以下おっかけになりますが手順になります。

install -d client/pages/.gitkeep
install -d client/assets/.gitkeep
install -d client/components/.gitkeep
install -d client/layouts/.gitkeep
install -d client/middleware/.gitkeep
install -d client/plugins/.gitkeep
install -d client/static/.gitkeep
install -d client/store/.gitkeep

nuxtは起動フォルダ配下に.nuxtという一時ファイルを作成します。このため設定ファイルをclient以下に配置して、このフォルダを起動フォルダとします。

設定ファイル (nuxt.config.js)

module.exports = {
    srcDir: '../client/',

    server: {
        port: 5000, // デフォルト: 3000
        host: 'localhost', // デフォルト: localhost,
        timing: false
    },
    css: [
        'bootstrap/dist/css/bootstrap.css',
        'bootstrap-vue/dist/bootstrap-vue.css',
    ],
    plugins: [
        '@/plugins/bootstrap',
    ]
}

起動シェル(再起動シェル)は以下のような感じで作ります。

#!/bin/bash

export nuxt_count=`grep -a "" /proc/*/cmdline | xargs -P1 -r -0 | grep -s nuxt.config.js | grep -v -E '(grep|\.sh)' | wc -l`
while [ $nuxt_count -gt 0 ]
do
    ps aux |grep nuxt.config.js | grep -v -E '(grep|\.sh)' | gawk '{print $2}' | xargs -r kill -9
    sleep 1
    export nuxt_count=`grep -a "" /proc/*/cmdline | xargs -P1 -r -0 | grep -s nuxt.config.js | grep -v -E '(grep|\.sh)' | wc -l`
done

echo "" | ../node_modules/.bin/nuxt -c ./nuxt.config.js &

ちなみにecho “” | はjenkinsから呼び出したとき、標準入力を要求されたので、それ対策で入れています。

このシェルを実行することでnuxt.jsサーバーが起動します。

nuxtは素のvueでやるよりも以下の点で優れていると思います。

  • 自動でルーティングしてくれる。
  • レイアウト機構を持っている。
  • API連携の仕組みも実装しやすい形で持っている。

VueやReactやAngularは、マイクロサービスをつなげる糊の役割をしているフレームワークだと思います。これからもっと深く使っていきたいと思います。

JQコマンドをおぼえた

福岡拠点の野田です。久しぶりの投稿です。

ある案件でAWSを扱っており、ELBからインスタンスが切り離されたか確認してほしいと連絡がありました。生憎、AWS Consoleへの接続アカウントをもらっていない状態で調べられない…と思ったのですが、aws-cliがインストールされてあるサーバーがあることに気づき、そちらで確認してみました。

ELBの一覧を表示するコマンドは以下のようなものになります。

 aws --output json --region ap-northeast-1 elb describe-load-balancers

けれども、awsのコマンドで出てくる内容はjsonで縦に長い!必要な情報だけに整理したいときに役立つのがjq(恐らくjson queryの略)コマンドになります。jsonの中からDNSNameと紐づくインスタンスを見たい場合は、以下のようなクエリをjqに投げます。

 aws --output json --region ap-northeast-1 elb describe-load-balancers | jq -r '.LoadBalancerDescriptions[] | {DNSName, Instances}'

jqコマンドの基本は、配列のフィルターと生成。.から始まる要素がフィルターされる内容になります。{}や[]で配列を再構築します。詳しいやり方は以下をご参考ください。

すぐれものなのは、jsonからcsvを作れること。以下のような感じでフィルターと配列の再構築を利用すれば、@csvでcsvの作成も楽々です。

aws --output json --region ap-northeast-1 elb describe-load-balancers | jq -r '.LoadBalancerDescriptions[] | [.DNSName, .Instances[].InstanceId] | @csv'

zabbixと連携させたりとか、 レポート出力を簡易化できないかとか夢が広がりますよね?是非、jqを使ってより良いjsonライフを!

[Python]拡張モジュールをWin Debug版DLLで試すとエラー

福岡拠点の香月です。

Windows環境で動作するPython3.6.6の拡張モジュールをC++で作りました。
開発ツールはVisual Studio 2015です。
早速作成した拡張モジュールのDebug版を使ってみようとPythonインタプリタを起動してモジュールロードしたんですが゙………

とこのようにエラーが発生してしまいました。インタプリタも強制終了しているようです。

これは拡張モジュールがDebug版なので、Pythonバイナリもデバッグ版を使う必要があります。python_d.exeがpython.exeと同じ場所にあるのでそれを使いましょう。
また、拡張モジュール名にも「_d」が必要です。Release版が「spam.pyd」ならDebug版では「spam_d.pyd」です。リネームで十分です。

このようにFatal Python Errorは発生せずに続行できます。
Debug版でのデバッグをあきらめて、Release版に無理やりデバッグ情報をつけてデバッグしていた方、是非これをお試しあれ。

これに気付く前にVisual Studio 2017のドキュメントで次のようなものを見つけていました。
https://docs.microsoft.com/ja-jp/visualstudio/python/working-with-c-cpp-python-in-visual-studio?view=vs-2017
以下抜粋

警告

デバッグ構成の場合でも [C/C++] > [コード生成] > [ランタイム ライブラリ] のオプションを常にマルチスレッド DLL (/MD) に設定します。これは、この設定がデバッグ以外の Python バイナリのビルドに使用されるためです。
マルチスレッド デバッグ DLL (/MDd) オプションを設定すると、デバッグ構成をビルドするときに、”C1189: Py_LIMITED_API は Py_DEBUG、Py_TRACE_REFS、Py_REF_DEBUG と互換性がありません” というエラーが表示されます。 さらに、ビルド エラーを避けるために Py_LIMITED_API を
削除すると、モジュールをインポートしようとしたときに Python がクラッシュします (後で説明しますが、クラッシュは DLL のPyModule_Create の呼び出し内で発生し、出力メッセージは “Fatal Python error: PyThreadState_Get: no current thread (Python 致命的エラー: PyThreadState_Get: 現在のスレッドがありません)” です)。
/MDd オプションは Python デバッグ バイナリ (python_d.exe など) のビルドに使われますが、拡張 DLL に対して選ぶと、やはり Py_LIMITED_API のビルド エラーになります。

でもこんなことする必要なく、python_d.exeを使うだけでOKですよー。

SkypeのメッセージをDBから眺める

福岡拠点の野田です。
暑い日が続きますが、いかがお過ごしでしょうか。

Skypeが新しくなって、だいぶ使いにくくなったなぁ、と感じます。履歴をコピーしたり検索することも不自由に感じることが多くなりました。備忘録的に残していた書き込みをWikiに転載するため、どうにかまとめてコピーすることができないかと思い、少し調べてみました。

現在 2018/08/06 Windows バージョンの Skype 履歴は以下のファイルに格納されていることを確認しました。

%localappdata%\Packages\Microsoft.SkypeApp_kzf8qxf38zg5c\LocalState\\skype.db

参考:Q.how do I export my chat history?
https://answers.microsoft.com/en-us/skype/forum/skype_win10-skype_messms-skype_instamessms/how-do-i-export-my-chat-history/20849b44-d68a-40f4-8cb8-6a2dc88e9e7e

テキストエディタで開いてみたところ先頭に「SQLite format 3」と記載されているではないですか。SQLiteは、パブリックドメインの軽量なRDBシステムです。SQLをサポートしており、Skypeに限らず、いろいろなアプリケーションのデータ保持に利用されています。

SQLiteファイルへの接続ですが、ODBCで接続する方法もありますが、今回はみんなが大好きな「A5:SQL Mk-2」を使っての接続を紹介します。A5:SQL Mk-2は、ER図も描けるとても優れたデータベースツールです。今回はこれを使ってファイルを参照します。

A5:SQL Mk-2
https://a5m2.mmatsubara.com/

step 1. データベースに追加

step 2. 左下の追加ボタンを押下

step 3. SQLiteを選択

step 4. skype.db を選択します。直に接続すると破損する可能性があるため、コピーしたファイルに繋ぎましょう。

step 5.ログイン認証は表示されますが、そのまま接続できます。

step 6.  messages が書き込みテーブルです。

これでスレッドの書き込みの検索、編集も思いのままです。
無事、スレッドからWikiへの転載も完了することができました。

よく使うウィンドウズのショートカット

福岡拠点の野田です。GWは晴れ間もありましたが、ここ数日雨が続いていて梅雨が気になる今日この頃です。

今回はよく使うWindowsのショートカットを紹介したいと思います。
よく使うWindowsのショートカットといえば、ctrl + alt + delete がよく知られていますが、ほかにどんなものがあるかご存知ですか?

以下は、私がよく使うWindowsのショートカットです。

その1: ctrl + esc

アプリを開きたいときにスタートボタンをマウスで押すのは、面倒ですよね。そのまま開きたいアプリ名を入力するとアプリ検索をして実行することができます。cmd と入力すればコマンドプロンプトが、excel と入力すればエクセルを検索されるので、そのままエンターを押下すると開くことができます。

その2:windowボタン + L

席を外すとき、画面ロックをかけるのは面倒なもの。このショートカットを使えば楽々です。トイレに急がなければならないときもばっちりです。

その3:windowボタン + P

プロジェクターに映像が出ない!そんなときに使うコマンドです。出番は少ないですが、勉強会などでプレゼンするときは心強い味方です。

その4:windowボタン + tab

alt + tab を使った画面切り替えや alt + shift + tab の切り替え戻しパターンもよく使いますが、画面の開いた順にさかのぼりたいときはこれが良いと思います。

その5:windowボタン + D からの alt + F4

複合技です。デスクトップ表示してから alt + F4 を押すとシャットダウン/再起動ダイアログを表示することができます。window を開いているときに閉じるコマンドとして有名な alt + F4 ですが、デスクトップ表示している状態でこの技を使うとシャットダウンすることができます。

番外編

alt + space からの n 押下。
いま開いている画面を最小化したいときに使います。
そこのあなた!Youtubeを見ていて隠したい時に使っちゃいけないですよ!

ショートカットキーを使うことで作業効率も上がると思います。
何か良いコマンドを見つけたら是非教えていただければと思います。

[JavaScript]D3.jsでグラフを書こう!

福岡拠点の野田です。今日は、データ解析に欠かせない可視化を支援するツールとして、D3.jsの使い方を紹介します。

可視化をするとき、棒グラフだったり、線グラフを出力することが多いと思います。Python、Rなどを使った画像出力ももちろん簡単に実現できるのですが、凝った複雑なグラフを出そうとするとき、D3.jsで描くSVGの柔軟性には目を見張るところがあります。SVGは、Scalable Vector Graphicsの略でベクター情報のイメージデータになります。そのため、拡大しても非常に高精細に表示することができます。また、CSSやJavasciptでイベント制御も可能なため、凝った動きのあるグラフを実現できます。

D3.jsの最新版は、ver5.1.0(2018/05/02時点)になります。ver3.xからver4.xにアップデートした際に大きく変更があったため、今回は個人的にもなじみのあるver3.xでの使い方を紹介します。

使うためには、HTMLヘッダーに以下を組み込むだけ。とても簡単です。

ver3.x

 

ちなみにver5.xでは以下のような感じです。

ここからは、ver3.xでの記述例になります。
以下のような流れでグラフを表示します。

1) 領域確保

グラフを表示する領域を確保します。軸に値を表示するため、マージンを確保します。


2) スケール設定

値の描画変換を行うスケール(基準となる物差し)を指定します。のちにデータ描画でも使います。


3) 軸の描画

スケールをもとに軸を描画します。


4) 補助線の描画

必須ではないですが、指定することでぐっとクオリティがアップします。


5) データ値の描画

線グラフだったり、点グラフだったり、棒グラフなどデータを描画します。今回は、線グラフを扱います。

これでCSVを読み込むと以下のようなグラフを表示することができるようになります。

SVGは、HTMLと同じくXMLで記述されるDOM(文書オブジェクトモデル)の1種です。イベント処理も差し込むことができるため、HTMLと同様な感覚で動的処理を扱えるのは強みと思います。D3.js自体、jQueryなどと同様、DOM操作するための言語とも言えます。慣れが若干必要ですが、凝ったグラフの描けるは大きな魅力です。

これを機会にぜひ触れてみてください。

[PHP]ExcelでUTF-8のCSVが文字化けしないようにBOMをつけよう!

福岡拠点の香月です。

この記事はブラウザからダウンロードするCSVファイルをWebサーバー上で作成するようなPHPプログラムを開発している人向けのトピックです。

ExcelをインストールするとCSVファイル(Comma-Separeted Values)がExcelに関連づきます。テキストエディタでCSVファイルを開く場合と違い、Excelで開くと列が揃って見やすいという利点があります。やったー!

Excelやその他WindowsのアプリでCSVファイルを作成した場合、日本語も問題なく扱えます。保存して改めてExcelで開いても正しく表示されますよね。
しかし、WebからCSVファイルをダウンロードしてExcelで開いた場合に、稀に日本語が文字化けしていることがあります。

サーバー上で次のようなプログラムを組んでcsvファイルを出力します。

クライアント側で保存したcsvファイルをExcelで開くと…

残念ですね。これはCSVファイルの文字コードの違いが問題です。
Windowsのアプリでファイル保存した場合、文字コードはほぼShift-JISとなります。対して近年のWebサーバーで扱う文字コードはほぼUTF-8となっており、CSVファイルもUTF-8であることが多いでしょう。で、このUTF-8の文字コードですが、コード表上はアルファベットや記号(日本語を含む2バイト文字以外)はShift-JISと同じコード範囲を使用しています。つまり、アルファベットや記号だけで書かれたUTF-8のファイルは、Shift-JISのファイルと全く同一ということになります。
日本語Windows上のExcelでCSVファイルを読み込む場合、UTF-8とShift-JISの区別がつかないため、ExcelさんはShift-JISとして読んでしまい、日本語部分が文字化けしてしまう、ということになります。

この問題はUTF-8のCSVファイルの先頭に「BOM」をつけて出力することで回避することができます。先ほどのプログラムの先頭をこうしてBOMを追加します。

クライアント側で保存したcsvファイルをExcelで開くと…

正しく日本語で表示させることができました。

ちなみにこのBOMはユニコードの種類によってコードが決まっています。
ユーティリティ関数としてこのような関数を1つ作っておくと便利ですよ。