情シスは何度でも甦るさ。

OracleDB/Ruby好きの情シス部員がお送りします

PostgreSQLでポイントインタイムリカバリ(PITR)で指定した時間で止めれなくてハマった話

最新までロールバックされちゃうんです

新しいシステムで、Windows Server上でPostgreSQL 10.4 を使うことになり、ポイントインタイムリカバリのテストをやっていたのですよ。 で、ちょっと検索すれば、そのやり方は出てくるし、マニュアル読めば普通に書いてる。Windowsだけど、そこにほとんど機能差は無い。

で、確かにアーカイブログ(WAL)を取っといてベースバックアップを戻して、PITRを実行すると、確かにその状態に戻るんです。 戻るんです。が、

デフォルトだと、READ ONLYモードでリカバリかかるので、通常モードに切り替えるために、サーバを再起動したらええんかいなと思ったら、

2018-10-18 17:44:52.555 JST [3332] LOG: database system was not properly shut down; automatic recovery in progress
2018-10-18 17:44:52.558 JST [3332] LOG: redo starts at 1/29000028
2018-10-18 17:44:52.559 JST [3332] LOG: consistent recovery state reached at 1/2A001088
2018-10-18 17:44:52.559 JST [3332] LOG: invalid record length at 1/2C000098: wanted 24, got 0
2018-10-18 17:44:52.559 JST [3332] LOG: redo done at 1/2C000028

なんか自動でロールフォワードかかっとる。

結果、ポイントインタイムリカバリではなく、最新時点までリカバリがかかってしまった。

うーん、どうすればいいんだ?

キーは"タイムライン"

マニュアルを読み込むも、いまいち記載がない。
なんとなく、タイムラインをスイッチすればいいっぽいのだが、
recovery_target_timeline ='2'
とか指定して起動しても、そんなタイムライン存在しません。とか言われて起動しない。

ということで、色々試してたら、
recovery.conf内に
recovery_target_action = 'promote'
をセットしてDBを起動したら、自動でタイムラインがSwitchされて、通常モードで起動された。

2018-10-18 19:30:53.700 JST [2360] LOG: database system was shut down in recovery at 2018-10-18 19:27:55 JST
2018-10-18 19:30:53.700 JST [2360] LOG: starting point-in-time recovery to 2018-10-18 19:19:10+09
2018-10-18 19:30:53.721 JST [2360] LOG: restored log file "000000010000000100000031" from archive
2018-10-18 19:30:54.653 JST [2360] LOG: redo starts at 1/31000098
2018-10-18 19:30:54.699 JST [2360] LOG: restored log file "000000010000000100000032" from archive
2018-10-18 19:30:55.607 JST [2360] LOG: consistent recovery state reached at 1/32002BE8
2018-10-18 19:30:55.608 JST [5616] LOG: database system is ready to accept read only connections
2018-10-18 19:30:55.608 JST [2360] LOG: recovery stopping before commit of transaction 9738, time 2018-10-18 19:19:14.630902+09
2018-10-18 19:30:55.608 JST [2360] LOG: redo done at 1/32002BE8
2018-10-18 19:30:55.608 JST [2360] LOG: last completed transaction was at log time 2018-10-18 19:19:04.706312+09
2018-10-18 19:30:55.635 JST [2360] LOG: selected new timeline ID: 2
2018-10-18 19:30:56.643 JST [2360] LOG: archive recovery complete
2018-10-18 19:30:56.755 JST [5616] LOG: database system is ready to accept connections

あと、walファイルの名称にも、TIMELINE IDが埋め込まれているらしくそれっぽく変わった。 f:id:ryoben:20181018201315p:plain

結論

最初はちゃんとリカバリできてるか確認するっしょ?

なので、
recovery_target_action = 'pause'
で起動して、READ ONLYモードしてあげるよ。

そいで、大丈夫だったら、
recovery_target_action = 'promote'
にして、再起動かけたら、リカバリ完了だよ。
(recovery.confもrecovery.doneにファイル名が自動で変換される)

ということでした。マニュアルにはこの手順書いてないっぽいんだけど。俺が探しきれてないだけなのだろうか。

閉域網で使ってるiPhoneがMDMと通信できなくてハマった話

MDMの指令を無視するiPhone

うちの閉域網に、業務端末としてiPhoneを導入した。
うちの閉域網から、インターネットに出る口は開いているので、一般のios アプリも許可したのは使える構成。

いざ、キャリアから初期設定された端末たちがぞろぞろと納品してきたのだが、社内の細かいキッティングをしようと思いMDMから指令を与えるも、うんともすんとも言わない状態に。

しかし、社内Wifiからだと繋がる不思議

今回閉域網をキャリアのサービスを使っていた。 経路としては、こうなる。

iPhone => (LTE) => キャリアの設備 => うちの閉域網 => インターネット(MDM)

切り分けを行うために、色々試行錯誤をすると、

①社内Wifiにつなぐ → MDMと通信できない
②社内Wifiにつないで、モバイルデータ通信をOffにする → MDMと通信できる

という謎な事象が発生。

①、②も経路は
iPhone => (Wifi) => うちの閉域網 => インターネット(MDM)

となり、当然インターネットに出る経路は同じなのでつながらないはず。
なのに、②の場合なんでモバイルデータ通信を切ってWifiオンリーにしたらMDMに繋がるねん。

ますます、混迷を深める。 切り分けようとして、理由が全く異なる事象にぶち当たってしまったのだろうか。

そもそもMDMiPhoneってどういう通信してるの?

インターネットにあるMDMは、どのようにiPhoneに指示を送っているのだろうか。

ネット上の情報によると、以下の経路でiPhoneに指示が飛ぶ。

MDM => APSN(Apple Push Notificationサービス) => iPhone

で、指示を受けたiPhoneでシステムサービスが起動し、MDMhttpsで通信し、アプリの配信などを行う仕組みだそうだ。

今回のケースでは、MDMからの指示が届いていない模様。

しかし、インターネットから閉域網のiPhoneに向けていきなり通信が行えるはずもない。 ということで調べていくと、iPhoneは通信が可能になると、APSNに対して通信を行い、通信を確立するとAPSNとのセッションを基本的には張りっぱなしにするそうだ。

今回、キャリア側の経路の問題の可能性もあったので、そちらにも確認をお願いしていたが、そちらでは問題がないらしく、どうやらうちの環境に起因している可能性が高そう。

ということで、iPhoneから、MDMへの通信あたりが怪しいということで、調べていくと、見事にiPhoneからインターネットの出口にあるFireWallにて、ポート5223の通信が遮断されているのが、ログから判明。

これだ。

結局のところ

FireWallの設定を変更することで、無事MDMからの指示も届くようになった。

しかし、まだ疑問は残る。なぜ、社内Wifiにつないで、モバイルデータ通信をOffにすると、MDMと通信ができたのか?

FireWallのログを丁寧に調べていくと、どうやらiPhoneは、443のポートでMDMと通信をしていた形跡が出てきた。

iOSの仕様で、「5223 で APNS に接続できなかった場合のフォールバック用」として、443で通信を行うと記載がある。
FireWallも、443のアウトバウンドは許可していたため、そのときだけMDMとの通信に成功していた。

いやでもなんで、モバイルデータ通信OFFが、フォールバックとみなすトリガーなんだよう。

原因は、結構簡単なんだけど、切り分けの調査のために、違う事象が出てきて余計に混乱したというお話でした。

余談

FireWallのログをその後見てると、5223、5224、5228、そして、10006の通信が発生している。

5224は、仕様上使わないってことになってるが、5223と同様にAppleのサーバ向けにあまりに通信してる回数が多かったので、通してみた。

5228は、Androidのプッシュ通知で使用するポートだそうだ。頻度が少ないので拒否にしてるが、実際業務上問題は発生していない(実際は何らかのエラーが起こってる?)

10006も同様。なんの通信なんだこれは。

あと、NTPの123もやりとりしている模様。iPhoneって、NITZ(Network Identify and Time Zone)って3G回線で時間調整してるんじゃなかったの?と思ったけど、NTPでも時刻調整するのね。ってことで、ここはFireWallの通信を許可した。

あと、2195-2196は、全然使ってる様子がない。どういうこっちゃねん。

公開されてる情報と実装が違う気がするのだが、そんなものなのだろうかねぇ。

C#でNPOIを使ってExcelを編集するとフォームボタンに割り当てたマクロが消える

最近、社内で1人しかSQLがわからないために、日々SQLをシコシコと実行する作業に嫌気がさして、 誰でもできるようにWindowsフォームアプリをC#で開発して、運用作業を他の人に振ることにした。

で、DBから抜いた値をExcelに取り込む → ユーザーに渡してユーザー側で編集 → 編集後ExcelをもらってDBの値を洗い替えるって、運用作業があるんですが、

Excel上のマクロを割り当てたフォームボタンが、いざ、NPOIを通して出力するとマクロの割り当てが初期化されるという事象にめぐり当たった。

これが

f:id:ryoben:20180428103139p:plain

こう

f:id:ryoben:20180428103144p:plain

色々と調べてStackOverFlowにも投稿があったのだが、NPOIの仕様で、Excelに直接貼り付けたフォームオブジェクトのマクロは消えるから、フォームにボタン貼り付けたりしようね。

とか、書いてた。

うーん、しかし、ボタンでさくっとマクロを起動したいのですよ。

色々と悩んだ挙句、Excelオープン時に、ボタンにマクロを割り当てるマクロを起動することで、とりあえず難を逃れることに。

Private Sub Auto_Open()
    ActiveSheet.Shapes.Range(Array("ボタン 1")).Select
    Selection.OnAction = "InputCheck"
End Sub

なんかもやっとするよね。

ちなみに、拡張子xmlのファイルだと、普通にボタンに割り当てたマクロはそのままになってたりした。