C++

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

福岡の香月です。

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

[crayon-673ed13e342be602705234  ]<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>

[crayon-673ed13e342be602705234 ]<appender name="SystemLogAppender" type="log4net.Appender.RollingFileAppender">

</layout>

</appender>

[/crayon]

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

[crayon-673ed13e342c3931990331  ]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);
    }
}

[crayon-673ed13e342c3931990331 ]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);

}

[/crayon]

ふむふむ、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()

[crayon-673ed13e342c7659617606  ]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);
	}
}

[crayon-673ed13e342c7659617606 ]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);

}

[/crayon]

ここで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です。
以下全文です。どん！

[crayon-673ed13e34780685291506  ]
using System;
using System.IO;
using System.Net.Sockets;
using System.Reflection;
using Microsoft.Extensions.Configuration;

namespace WakeOnLAN
{
    class Program
    {
        static void Main(string[] args)
        {
            string name = Assembly.GetEntryAssembly().GetName().Name;
            ConfigurationBuilder builder = new ConfigurationBuilder();
            builder.SetBasePath(Directory.GetCurrentDirectory());
            builder.AddIniFile(name + ".ini");
            IConfiguration config = builder.Build();

            string host = config["host"];
            string sport = config["port"];
            string macAddr = config["macAddr"];

            if (string.IsNullOrEmpty(host))
            {
                Console.WriteLine("設定ファイルに host が設定されていません。");
                return;
            }
            if (string.IsNullOrEmpty(sport))
            {
                Console.WriteLine("設定ファイルに port が設定されていません。");
                return;
            }
            if (string.IsNullOrEmpty(macAddr))
            {
                Console.WriteLine("設定ファイルに macAddr が設定されていません。");
                return;
            }

            int port = 0;
            if (!int.TryParse(sport, out port))
            {
                Console.WriteLine("ポート番号が不正です。");
                return;
            }

            // macアドレス文字列をバイト配列に
            string[] bsary = macAddr.Split('-');
            if (bsary.Length != 6)
            {
                Console.WriteLine("macアドレスが正しくありません。\nipconfig /all で確認してください。\n例）1A-2B-3C-D4-EE-99");
                return;
            }
            byte[] bmac = new byte[6];
            for (int i = 0; i &lt; 6; ++i)
                bmac[i] = Convert.ToByte(bsary[i], 16);

            byte[] packet = new byte[6 + 6 * 16];
            Array.Copy(new byte[] { 0xFF, 0xFF, 0xFF, 0xFF, 0xFF, 0xFF }, 0, packet, 0, 6);
            for (int i=1; i&lt;=16; ++i)
                Array.Copy(bmac, 0, packet, i * bmac.Length, bmac.Length);

            try
            {
                UdpClient udp = new UdpClient();
                udp.Send(packet, packet.Length, host, port);
            }
            catch (Exception e)
            {
                Console.WriteLine("マジックパケットの送信時に例外が発生しました。\n" + e.ToString());
            }
        }
    }
}

[crayon-673ed13e34780685291506 ]

using System;

using System.IO;

using System.Net.Sockets;

using System.Reflection;

using Microsoft.Extensions.Configuration;

namespace WakeOnLAN

{

class Program

{

static void Main(string[] args)

{

string name = Assembly.GetEntryAssembly().GetName().Name;

ConfigurationBuilder builder = new ConfigurationBuilder();

builder.SetBasePath(Directory.GetCurrentDirectory());

builder.AddIniFile(name + ".ini");

IConfiguration config = builder.Build();

string host = config["host"];

string sport = config["port"];

string macAddr = config["macAddr"];

if (string.IsNullOrEmpty(host))

{

Console.WriteLine("設定ファイルに host が設定されていません。");

return;

}

if (string.IsNullOrEmpty(sport))

{

Console.WriteLine("設定ファイルに port が設定されていません。");

return;

}

if (string.IsNullOrEmpty(macAddr))

{

Console.WriteLine("設定ファイルに macAddr が設定されていません。");

return;

}

int port = 0;

if (!int.TryParse(sport, out port))

{

Console.WriteLine("ポート番号が不正です。");

return;

}

// macアドレス文字列をバイト配列に

string[] bsary = macAddr.Split('-');

if (bsary.Length != 6)

{

Console.WriteLine("macアドレスが正しくありません。\nipconfig /all で確認してください。\n例）1A-2B-3C-D4-EE-99");

return;

}

byte[] bmac = new byte[6];

for (int i = 0; i < 6; ++i)

bmac[i] = Convert.ToByte(bsary[i], 16);

byte[] packet = new byte[6 + 6 * 16];

Array.Copy(new byte[] { 0xFF, 0xFF, 0xFF, 0xFF, 0xFF, 0xFF }, 0, packet, 0, 6);

for (int i=1; i<=16; ++i)

Array.Copy(bmac, 0, packet, i * bmac.Length, bmac.Length);

try

{

UdpClient udp = new UdpClient();

udp.Send(packet, packet.Length, host, port);

}

catch (Exception e)

{

Console.WriteLine("マジックパケットの送信時に例外が発生しました。\n" + e.ToString());

}

[/crayon]

特徴

マジックパケットを飛ばします。マジックパケットとは…
- 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の設定など、情報はぐぐればいろいろ出てきますので一度お試しあれ。

OpenGLが使うピクセルフォーマット

WindowsアプリでOpenGLを使ってプログラムを組む時の初期化処理の一環で、次のようにピクセルフォーマットを設定してやる必要があります。これを紹介しているサイトはいくつも見つかりますが、これが一体なにを示しているのか？まで解説しているところがないので調べてみました。

int SetupPixcelFormat(HDC hDC)
{
　　PIXELFORMATDESCRIPTOR pfd = {
　　　　sizeof(PIXELFORMATDESCRIPTOR), /* nSize */
　　　　1,                             /* nVersion */
　　　　PFD_DRAW_TO_WINDOW | PFD_SUPPORT_OPENGL | PFD_DOUBLEBUFFER, /* dwFlags */
　　　　PFD_TYPE_RGBA,                 /* iPixelType */
　　　　32,                            /* cColorBits */
　　　　0, 0, 0, 0, 0, 0, 0, 0,
　　　　0,
　　　　0,  0, 0, 0,
　　　　24,                            /* cDepthBits */
　　　　8,                             /* cStencilBits */
　　　　0,
　　　　PFD_MAIN_PLANE,                /* iLayerType */
　　　　0,
　　　　0, 0, 0
　　};

　　int pixelformat = ::ChoosePixelFormat(hDC, &pfd);
　　if (0 == pixelformat)
　　　　return FALSE;

　　if (!::SetPixelFormat(hDC, pixelformat, &pfd))
　　　　return FALSE;
　　return TRUE;
}

int SetupPixcelFormat(HDC hDC)

{

　　PIXELFORMATDESCRIPTOR pfd = {

　　　　sizeof(PIXELFORMATDESCRIPTOR), /* nSize */

　　　　1, /* nVersion */

　　　　PFD_DRAW_TO_WINDOW | PFD_SUPPORT_OPENGL | PFD_DOUBLEBUFFER, /* dwFlags */

　　　　PFD_TYPE_RGBA, /* iPixelType */

　　　　32, /* cColorBits */

　　　　0, 0, 0, 0, 0, 0, 0, 0,

　　　　0, 0, 0, 0,

　　　　24, /* cDepthBits */

　　　　8, /* cStencilBits */

　　　　PFD_MAIN_PLANE, /* iLayerType */

　　　　0, 0, 0

　　};

　　int pixelformat = ::ChoosePixelFormat(hDC, &pfd);

　　if (0 == pixelformat)

　　　　return FALSE;

　　if (!::SetPixelFormat(hDC, pixelformat, &pfd))

　　　　return FALSE;

　　return TRUE;

}

この部分って定型になっていて、気にしなくてもOpenGLプログラミングできますが、一度気になると調べたくなる性分なので仕方ない。

ここで使っているAPIの1つ目はChoosePixelFormat()です。このAPIはアプリを動作させるPC上で使用可能なピクセルフォーマットの番号を返してくれます。第一引数のhDCにはOpenGLで描画するウィンドウのデバイスコンテキストを指定します。第二引数のpfdにはPIXELFORMATDESCRIPTOR 変数のアドレスを指定します。前処理として、このPIXELFORMATDESCRIPTOR のメンバ変数に値を設定してやる必要があります。

nSize
PIXELFORMATDESCRIPTORのサイズ。Windows APIでよくやる手法です。nVersion
絶対1です。

dwFlags
ここで使用目的を指定します。OpenGLではこうです。
(0x01)PFD_DOUBLEBUFFER – ダブルバッファリングで描画高速化
(0x04)PFD_DRAW_TO_WINDOW – ウィンドウに対する描画
(0x20)PFD_SUPPORT_OPENGL – OpenGLサポート

iPixelType
PFD_TYPE_RGBAでRGBAでの使用を宣言します。
もう一つPDF_TYPE_COLORINDEXがありますが、こちらは使いません。

cColorBits
使用する色のビット数を指定します。
8bit – 白黒
24bit – RGB（赤緑青）
32bit – RGBA（赤緑青＋透明度）

これを実行すると入力に応じて適切な番号が返ってくるので、これをSetPixcelFormat()に渡してデバイスコンテキストが使用するピクセルフォーマットとして設定するわけです。

ちなみにそのPCでどのようなピクセルフォーマットが使用可能かを取得するAPIも存在します。

DescribePixelFormat(hDC, i, sizeof(PIXELFORMATDESCRIPTOR), &pfd);

1	DescribePixelFormat(hDC, i, sizeof(PIXELFORMATDESCRIPTOR), &pfd);

DescribePixelFormat(hDC, 0, 0, NULL);でそのPCにあるピクセルフォーマットの個数が返ります。あとは第二引数にその番号を入れてやれば情報を取得することができます。ChoosePixelFormat() で帰ってきた番号を入れることで、OpenGLで使うピクセルフォーマットの内容も分かります。私の環境ではこうなっていました。

 pfd = {
　　sizeof(PIXELFORMATDESCRIPTOR),       /* nSize */
　　1,                                   /* nVersion */
　　PFD_DRAW_TO_WINDOW                   /* dwFlags */
　　　　| PFD_SUPPORT_OPENGL
　　　　| PFD_DOUBLEBUFFER,
　　PFD_TYPE_RGBA,                       /* iPixelType */
　　32,                                  /* cColorBits */
　　8, 16, 8, 8, 8, 0, 8, 24,            /* R/G/B/A のビット位置 */
　　64, 16, 16, 16, 16,                  /* cAccum* のビット数 */
　　24,                                  /* cDepthBits */
　　8,                                   /* cStencilBits */
　　0,                                   /* cAuxBuffers */
　　PFD_MAIN_PLANE,                      /* iLayerType */
　　0, 0, 0, 0};

pfd = {

　　sizeof(PIXELFORMATDESCRIPTOR), /* nSize */

　　1, /* nVersion */

　　PFD_DRAW_TO_WINDOW /* dwFlags */

　　　　| PFD_SUPPORT_OPENGL

　　　　| PFD_DOUBLEBUFFER,

　　PFD_TYPE_RGBA, /* iPixelType */

　　32, /* cColorBits */

　　8, 16, 8, 8, 8, 0, 8, 24, /* R/G/B/A のビット位置 */

　　64, 16, 16, 16, 16, /* cAccum* のビット数 */

　　24, /* cDepthBits */

　　8, /* cStencilBits */

　　0, /* cAuxBuffers */

　　PFD_MAIN_PLANE, /* iLayerType */

　　0, 0, 0, 0};

月	火	水	木	金	土	日
				1	2	3
4	5	6	7	8	9	10
11	12	13	14	15	16	17
18	19	20	21	22	23	24
25	26	27	28	29	30