この日のバイト

開発

　先日からバイト先の刻印機に付属する制御ソフトウェアの修正対応をしていたのですが、制御している機械自体は重量150kgを越える巨大な物なので、家に持って帰るわけにも行かず、普段はエミュレータを使って開発をしているのですが、実機と振る舞いが微妙に違うためにバグの再現が行えず、バイト先に直接訪れて調べてみることにしたのでした。
　
　ちなみに大学に泊まっていた為、就寝3時、起床7時。つまり4時間の睡眠です。あーねむ……。8時半に家を出発し、バイト先に到着したのは10時。
　
　早速刻印機を見せてもらいます。
　1つ目の修正は、刻印機が送ってくる信号というのがASCIIコードの「STX」「ETX」で囲まれる部分に情報を詰めて送ってくるのですが、ソフトウェア側から停止信号を発信した際に、刻印機側から送ってくる情報に割り込んで送られてくるのが旧機種ではOKだったのに対して、新型機はNGという状況らしい。
　
　新型機のクセに中々デリケートな奴です。
　
　早速調査開始。
　ちなみにバイト先でデバッグをするときは、間に相互のパケットを監視する特殊なモニタリング用のハードウェアを置いて行います。これを見ると双方向のパケットが監視できるので、デバッグしやすいのですが、今回はソフトウェア側にもモニタリングのツールを入れてデバッグをすることにしました。
　
　原因はすぐに分かりました。停止命令を送るまでは刻印用の針が動いているので、その針の座標情報が送られてくるのですが、この座標をタイマー関数を使って定期的に取得しているので、停止命令を送る際はタイマーを一時的に止めてやればいいのではないか、と止めて再びデバッグ。
　
　……駄目でした。
　
　この後1時間ほど修正してはリトライを繰り返していたのですが、何をやっても駄目。
　万策尽きたといった頃、停止信号を送る時にはどのような情報が入っているのだろうと、バッファを覗いてみたら、ようやく原因が判明しました。
　
　停止信号を発するまでは刻印機は針を移動させているので、定期的に座標情報を送ってくるのですが、それはソフトウェア側が停止信号を発生させてから、機械に到達する間も機械は送り続けます。
　
　最初に行った修正で「ETX」を確認してから停止信号を送ったとしても、その停止信号が届くまでは機械側は座標情報を送りつけるので、停止信号が機械側に届くまでの時間に座標が発行されると、それはどうしても割り込んでしまう結果になるということが分かりました。こうなると、こちら側では解決の方法はありません。バイト先の開発陣に原因を説明して、シリアルの伝送速度を上げてもらうか、座標の発行する時間間隔を長くしてもらうしかないということを伝えて、問題は解決。
　
　次の修正は刻印機の手動操作画面に入った後、針の原点復帰を行ってから、メニューに戻り、再び手動操作画面に入ると、通信が何故かタイムアウトするという問題の修正に当たることにしました。再現性はほぼ100％なのですが、原因が良く分かりません。
　
　まず、初期化時にタイムアウトしているので、初期化処理のプログラムに検討をつけて、調べてみることに。必要な初期化処理が行われていないんじゃないか、とか調べていたのですが、この時分かったことが2点。
　
　1つ目はタイムアウトの原因はパケットの形として完全なものを送信しなければ、無限ループ状態に陥ってしまうのが原因でした。エラーの発生する箇所は、初期化時に座標情報を取得するコマンドを送信するのですが、その情報に[X0,Y0]といった情報が付加されるようになっているのですが、1回目は完全な形で受信しているのに対し、2回目はX0の部分が欠落し、[,Y0]といった形になっていたため、ソフトウェア側で完全な文字列として認識できず、タイムアウトしていたようです。

　2つ目はソフトウェア側から、初期化時に初期化命令を発行しているのですが、ハードウェア側から、そのレスポンスとして1回目、2回目共に正常なパケットが送られていることが、ハードウェアモニタから確認されています。しかし、私の用意しているソフトウェア側のモニタリングソフトを見てみると、上記のように一部が欠落した状態を表示しています。
　どちらが信用できるかというと、それは当然ハードウェア側の方なので、ソフトウェアのバグか？と思ったのですが、実はそうではなくソフトウェアのモニタリングソフトのほうは「MSComm32.ocx」からソフトウェアに流れるパケットを監視するというものだったので、この結果が示すものとしては「ハードウェアからは正常なパケットが飛んでいますが、MSComm32.ocxからソフトウェアへのパケットが間違っています」ということになります。つまり原因はMSComm32.ocx側のバグか、ソフトウェア側のバグかということになります。今では結構冷静な分析が出来ていますが、初めはさっぱり分からなかったので、見当違いな仮説や憶測も結構立てました。
　
　原因も良く分からぬまま、昼過ぎになったので差し入れの弁当をPascalと食べながら、色々問題の検討を行う。弁当を食べ終わってから後半戦開始。
　
　先ほどの2点の解明から、問題はパケット制御の部分にあるに違いないと判断したので、そこを重点的に調査。調査から1時間弱経った頃に、ついに問題となる部分を発見。それはパケットの初期化処理の部分にありました。
　
　パケットを初期化すると同時に、シリアルのバッファをクリアする命令として、InBufferCount=0という行があったのですが、これが、座標取得命令を飛ばした直後に行われていたため、タイミングによっては座標取得命令のレスポンスの先端が届いた直後あたりに行われ、バッファをクリアしてしまっていたようです。
　
　というわけで、座標取得命令を飛ばす前にバッファをクリアするように修正。
　
　……直った。
　
　というわけで、何とか14時には修正完了。一時期は今日は帰れないかも……という心配もありましたが、無事に作業が終わりました。
　
　しかし、プログラム……なんというかグローバル変数だらけです。どこかいじるときも、他に影響を及ぼさないかヒヤヒヤしながら修正しているので、出来ればもう修正したくないなぁ……と思うのですが、次の新型機ではQRコード・データマトリックス刻印に対応。
　
　……となると、当然ソフトウェア側もQRコード発行命令は必要だよなぁ……インターフェースもいじらないといけないし、複数個所に修正が及びそうなこと必至です。
　しばらく悪夢は続きそうです。