Posts for: #Logging

slog の完全移行の少し手前

0時に寝て何度か起きて6時に起きた。土曜日から喉が痛くてコロナ感染の懸念もあったけど、前日は一日中休んでいたせいか、喉の痛みは全くなくなった。たまたまだったのかもしれない。

slog 移行

slog 勉強会 で学んだ LogValuer という interface を使うと、機密情報のログ出力をカスタマイズできる。要はパスワードのような文字列を *** に置き換えるといったことをしたい。もっともシンプルな機密情報を扱う型として Secret を定義した。この Secret でラップした文字列を扱う分には slog のロガーでそのまま出力しても問題ない。

type Secret string

func (s Secret) LogValue() slog.Value {
	return slog.StringValue("***")
}

func (s Secret) String() string {
	return string(s)
}

あと自前で定義していたロガーのログ関数を slog のトップレベル関数を使うように1つずつコードを書き直していった。機密情報に関するところで一部まだ置き換えていないところもあるが、98%のログ出力のコードは slog に直接置き換えた。時間がかかるだけの面倒くさい作業なので、こういうプロジェクトの隙間に地道にやるのがよいと思う。今回も移行にあたって slog のコードを少し読んだが、slog は本当に既存のログ出力の機能で大事なところだけをシンプルに実装していてよく出来ていると思う。

お休み前の勉強会

22時に寝て24時に起きて2時に起きて4時に起きて6時に起きた。晩ご飯食べてからオフィスに戻る元気がない。本当は明日の出張に備えて今晩、実家へ帰ろうと思っていたが、まったく準備ができていないので明日の早朝に帰ることにした。

slog 勉強会

チーム勉強会向けに、今日は軽い話題として slog のブログ記事をピックアップしてみた。この内容を deepl で翻訳して社内の wiki に書いてそれをメンバーと共有した。

うちのプロジェクトの logger はすべて slog に移行済みではあるが、一部 slog を使う前に実装したログ関数があって、そのカスタムログ関数の移行だけまだできていない。アプリケーションの振る舞いには影響を与えないし、急ぐ必要もないので先送りにしているだけ。次の開発フェーズでカスタムログ関数周りもすべて移行して slog で万全の状態にしたい。そのための予備知識として slog でこんなことができるという全体像は理解できた。とてもよい記事だったと思う。

LT 資料の推敲

先日 LT 資料のたたき台 を作成した。いくらか寝かして週のどこかの空いている時間に推敲しようとずっと頭の中にはあったものの、現実にはさぼっていて前日に最終見直しをしている。でも、見直した方がよいところのアイディアは2-3個思いついてはいる。少し手直ししたら明日のイベントに備えて早めに寝る。

出張帰りにオフィスに寄って開発する

18時19分の新幹線に乗って21時前に新神戸駅に着く。この時間帯で帰ってくるのが楽な気がする。新神戸駅についたらいつもそこからタクシーで帰りたいと思う。いまうちの会社は全然儲かってないのでそんなことできないけれど、いつか余裕ができたら出張帰りの電車乗り継ぎをやめてタクシーで直帰してよいルールにしたい。

go 1.21 への移行

昨日 Go 1.21 is released! されたことを知った。自分の作業を中断して早めに移行して問題があれば検出できるしておきたかったので 1.20 から 1.21 への移行をしていた。もっとも大きな移行としてログ出力をすべて log/slog へ移行した。もともと cybozu-go/log という標準の log パッケージに近いものを使っていたので移行そのものは大きな課題にはならなかった。一方で変更することによって運用にどういった影響が出るかは実際に動かさないと気付かないこともあるだろうという視点で早く移行したかった。昨日の夕方に 1.21 で一通りは動くようにして、今朝から細かいところの修正は他のライブラリとして slices/maps といった新規に追加された標準ライブラリを使うように変更していった。リポジトリが数個あるので単純に労力だけの問題。ついでに go-ldap の ci 環境の設定も変えておいた。

github-api-tools 再び

帰りの新幹線の中でてらださんとやり取りしていた。issue 検索に llm の技術を使ってサンプルアプリケーションを作るというアイディアが進んでいて、公けの github issues のデータを使えばいいという話しをした。実際に学習データにするには、一定の前処理したテキストとメタデータが必要になる。github issues からあるプロジェクトの情報を一括で取得する方法はないか?という相談を受けて、github の rest api などを使って取得するのがよいのではないか?と提案した。

私も過去に github での作業時間の検証のために github-api-tools というツールを作っていた。21時半頃にオフィスに戻ってきて、せっかくなので試しにやってみるかと翌1時過ぎぐらいまでコードを書いていた。過去にも issues の機能も作った方がよいよねという課題は残してあった。

python のコードを滅多に触る機会がなくなってしまったので勘所を思い出したりするのにやや手間取った。それでも自分が過去に作ったものなのですぐにできた。

縁の下のマネージャー

20時にホテルに戻ってきてのんびりしながら気付いたら22時ぐらいになって、少しテレビをみて0時に寝て4時ぐらいから起きてその後はあまり眠れなかった。それでも7時過ぎまでだらだらしていた。

7月後半に実装予定の新機能の設計

9月までに実装する新機能のうち、唯一、私の頭の中で設計の見通しをもっていなかった機能の設計を行うことにした。

ざっくりした機能概要から私がふわっと想定していたものはずっと複雑なものだったのだけど、プロダクトオーナーに要件をヒアリングしているうちにそんな高度なものは求められていないことに気付いた。逆にその高度な機能の仕組みを提供しても、実際に運用の現場で使うにあたって手間暇だけかかってそんなものを求めていないと言われそうな気がした。そこで私が作りたいなと思っていた設計のアイディアは封印することにした。既存の先行プロダクトがもっている機能とほぼ同様のものを、うちらの開発しているプロダクトで実現するだけでよさそうにみえた。そのシンプルな機能の設計を軽くやっておいた。詳細を詰めるのは次のマイルストーンで私ではないメンバーに実装してもらうことになるけれど、なんとなく当初の想定よりも早くできそうに思えた。

ログ出力のリファクタリング

id 連携の処理で複雑なリソースを map 型で扱うときデバッグ用途でリソースを丸ごと dump したい。しかし、パスワードのような機密情報が含まれる場合はそれらはログに出力したくない。この処理をいまは連携種別ごとに実装していて、本質じゃないところで個別実装の手間があるのと機密情報の出力というセキュリティに関するところを毎回プログラマーが手で実装するのもどうかな?という気がして汎用のログユーティリティとしてロガーのライブラリ側で提供することにした。インフラやプラットフォーム的な機能に私は積極的に開発に介入している。

やり方の1つとしてオリジナルのリソースをコピーして機密情報だけ削除した一時的なリソースコピーを dump してログ出力する。go 1.21 で標準ライブラリに追加される maps パッケージを使うと map の操作が簡単にできる。コピー関数もある。しかし、この機能は shallow copy なので map の値にネストした map が含まれる場合はオリジナルの値を書き換えてしまう。ネストした map を調べてそれらもクローンしていく処理を実装した。excludeKeys に除外したい任意のキーを渡し、map の値を再帰的にチェックして取り除く。最終的には次のようなコピーユーティリティになった。

func copyWithoutExcludeKeys(
	fields map[string]any, excludeKeys []string,
) map[string]any {
	cloned := maps.Clone(fields)
	for k, v := range cloned {
		switch t := v.(type) {
		case map[string]string:
			strMapCloned := maps.Clone(t)
			for _, sk := range maps.Keys(strMapCloned) {
				if slices.Contains(excludeKeys, sk) {
					delete(strMapCloned, sk)
				}
			}
			cloned[k] = strMapCloned
		case map[string]any:
			cloned[k] = copyWithoutExcludeKeys(t, excludeKeys)
		case []map[string]any:
			for i, v := range t {
				t[i] = copyWithoutExcludeKeys(v, excludeKeys)
			}
		default:
			if slices.Contains(excludeKeys, k) {
				delete(cloned, k)
			}
		}
	}
	return cloned
}

ログおじさん

23時に寝て3時半に起きて眠れそうになかったからそのまま5時からオフィスで作業してた。

システム構成の検討

コンサルタントから顧客要件のヒアリングを行い、プロダクトを提供するインフラのシステム概要を mermaid で書いた。オンプレとクラウド環境のそれぞれを同じコンテナアプリケーションで動かすための構成を検討した。クラウド環境の一例として aws の構成を考えていて、https と http のプロトコル変換のようなことをするには api gateway を経由しないといけないと考えていたら、alb に証明書を設定して api gateway なくてもいけるとはらさんに教えてもらった。昔からできたそうで、なぜか私が長い間ずっと勘違いしていた。また時間があるときに自分でもやってみようと思う。

Logger の再実装

プロダクトのコアな部分の実装は私がみた方がよいだろうと考えていて、そのうちの1つ Logger の設計がよくなかったので私が作り直した。といっても cybozu-go/log を使った薄いラッパーを設けただけ。チームメンバーからどこでエラーが起きているか追跡しにくいという声があったのでログ出力したところのソースコードの情報を出力しようと考えた。ググればたくさん出てくる。スタックフレームにアクセスする標準パッケージとして runtime を使うとできる。runtime.Caller と runtime.Callers は似て非なる関数のようでファイル名と行番号だけでよければ Caller を使った方がシンプルになると思う。関数名もほしかったら Callers を使ったスタックフレーム自体から取得する必要がある。

func Trace(skip int) (file string, funcName string) {
  pc := make([]uintptr, 15)
  n := runtime.Callers(skip, pc)
  frames := runtime.CallersFrames(pc[:n])
  frame, _ := frames.Next()
  _file := frame.File[strings.Index(frame.File, sourceRepositoryPath)+8:]
  file = fmt.Sprintf("%s:%d", _file, frame.Line)
  return file, frame.Function
}

この情報を cybozu-go/log の map に追加するようなログ関数を提供するようにした。cybozu-go/log は標準の log パッケージに足りないところだけを追加していて、そのシンプルさと拡張性の高さを私は気に入ってよく使っている。私が気に入っているのでもっと有名になってほしい。

前のお手伝いでもログ基盤を含めて Logger を作っていて、またいまも Logger を作り直していて、気付いたら私は Logger やログ出力に一家言あるような、ログおじさんになりつつある。

log4j2 の設定ファイルの動的な読み込み

0時に寝て7時に起きた。

バッチ処理モジュール

cli でバッチ処理モジュールを作った。コマンドラインの引数パーサーと yml のパーサーを使うことにした。

ロガー実装に log4j2 を使っているので設定ファイルはアプリケーションの設定ファイルと log4j2 の設定ファイルの2つになる。それぞれ環境ごとに用意してエントリーポイントから起動したタイミングで明示的に設定ファイルを読み込むようにした。

log4j2 の yml 設定ファイルを動的にどうやって設定するかはドキュメントにもとくに書いてなかった気がする。log4j2 のソースコードやテストコードを読みながら次のようにしたら反映された。

public static Config load(BatchEnvironment env) {
    var path = String.format("config-%s.yml", env.getName());
    var inputStream = ConfigUtil.class.getClassLoader().getResourceAsStream(path);
    var yaml = new Yaml(new Constructor(Config.class));
    return yaml.load(inputStream);
}

アプリケーションの設定は yml 設定に対応する Config クラスを定義しておいて次のようにして読み込む。

public static void initializeLogSettings(BatchEnvironment env) throws IOException {
    var path = String.format("log4j2-%s.yml", env.getName());
    var inputStream = ConfigUtil.class.getClassLoader().getResourceAsStream(path);
    var source = new ConfigurationSource(inputStream);
    var configuration = new YamlConfigurationFactory().getConfiguration(null, source);
    Configurator.initialize(configuration);
}

ちょっとした cli を作るときにちょっとしたライブラリがあると楽でよい。

欠損金の繰り戻し還付の申請の誤り

国税局から電話がかかってきた。初めて提出した欠損金の繰り戻し還付の申請があちこち間違ってますよと。申請書類と一緒に法人税の申告書もみてもらっていて、還付申請した金額も申告の別表1に記入する必要があって、それも一緒に修正してねという話し。法人税の修正申告と還付の訂正依頼の2つが必要とのこと。税務署の人たちは本当に丁寧で親切にあれが間違っている、これが間違っていると教えてくれる。素人が法人決算やっているので初めて行う手続きの間違いはつきものだけど、税務署の人たちが教えてくれるので本当に助かる。感謝。

datadog のログアーカイブ

1時に寝て5時半に起きた。

datadog のログアーカイブ

datadog には Log Archives という機能があって、datadog 経由でログをどこかのストレージに永続化できる。datadog プラットフォーム上では設定した期間内のログしか検索できず、おそらく料金の予算にあわせて期間を設定して、それが過ぎたら消えていくのだと思う。aws なら s3 に datadog に連携されたログをパイプライン処理してそのまま永続化できる。そのための s3 バケットの作成、s3 バケットへの datadog からのアクセス権限ロールの設定、datadog の aws インテグレーションの設定などをした。ドキュメントを読みながら1日あれば設定できたので難しくはない。もう cdk の設定にも慣れた感じで必要な権限を cdk の Stack としてコードで管理できるようにした。保守もばっちり。永続化されるログは gzip 圧縮されて時系列に s3 に永続化されるみたい。

spring boot の環境とログ設定

0時に寝て4時に起きて6時に起きた。

spring のプロファイル設定

spring の Profiles の仕組みを使って環境ごとの設定を作る。デプロイは k8s で管理しているため、spring boot の Externalized Configuration の仕組みを使って、環境変数から application.yml に定義された設定を書き換える。k8s は kustomize で管理していて prod, test, dev の3つの環境で任意の設定を記述できる。

問題はログ出力の設定を環境ごとに変えたい。具体的には datadog に連携されるログは構造化ログ (json lines) を、ローカルの開発ではコンソールログをみたい。Log4j Spring Boot Support によると、1つの設定ファイルに複数のプロファイル設定を記述できるようにもみえるけど、実際にやってみたらうまく動かなかった。xml ではなく yml を使っているせいかもしれないし、私の記述方法が誤っているのかもしれない。いずれにしても yml で複数のプロファイルを設定しているサンプルをみつけられなかった。

そこで Different Log4j2 Configurations per Spring Profile をみて、環境ごとにログ設定ファイルも分割することにした。application.yml には次のように記述する。

spring:
  profiles:
    active: dev

logging:
  config: classpath:log4j2-${spring.profiles.active}.yml

ローカル開発向けの lgo4j2-dev.yml は次のようになる。

Configuration:
  status: warn
  name: YAMLConfig
  appenders:
    Console:
      name: STDOUT
      target: SYSTEM_OUT
      PatternLayout:
        Pattern: "%d{yyyy-MM-dd HH:mm:ss.SSS}[%t]%-5level %logger{36} - %msg%n"

k8s のマニフェストで環境変数を次のように定義すれば prod というプロファイルが設定される。

apiVersion: apps/v1
kind: Deployment
metadata:
  name: my-service
spec:
  template:
    spec:
      containers:
      - name: my-service
        env:
        - name: spring.profiles.active
          value: "prod"

クラウド環境向けの log4j2-prod.yml は次のようになる。

Configuration:
  status: warn
  name: YAMLConfig
  appenders:
    Console:
      name: STDOUT
      target: SYSTEM_OUT
      EcsLayout:
        serviceName: my-service
        serviceNodeName: null
        includeMarkers: true
        KeyValuePair:
        - key: type
          value: app

クロスデフォルト

0時に寝て6時半に起きた。5時台には起きているんだけど、起き上がるところまではなかなかいけない。

恒大集団のデフォルト

11月から利払の期日の日はチェックしていて、支払うときは2-3日前には支払いを完了したというニュースが出ていたように思う。今日の支払いは前日に支払いしたというニュースが出ないからダメなんだろうなと様子をみていた。

1つの債務がデフォルトした場合、残りの債務も一括返済しないといけないことを クロスデフォルト と呼ぶらしい。契約書にクロスデフォルト条項として書いてあるらしい。記事によると、クロスデフォルトによって約190億ドル (約2.1兆円) のオフショア債の返済を一括でしないといけないらしい。リーマンショックのようなことは起きないという見通しだけど、うちみたいな零細企業は世の中の影響を諸に受けるのでお仕事に影響がでなければいいなぁといったところ。

アプリケーションログの調査

昨日の続き。ecs-logging-java で JSON Lines でログを制御するところで spring-boot の設定で tomcat のアクセスログの設定ができる。tomcat のアクセスログを log4j のレイアウトの仕組みを使って ecs-logging-java が提供する EcsLayout に変更できないかを3時間ほど調査して、どうもできないようだというのを教えてもらった。tomcat は apache のログを出力するという目的で実装されているから log4j の柔軟なログに対応していないという理屈。

じゃあ、どうやって apache のアクセスログを JSON Lines にするかというと、PatternLayout のパターンに json のフォーマットを直書きしてしまうというやり方がある。なんかプログラミングでスマートに解決したいところだけど、その仕組みがないなら仕方ないかって感じでこれでやろうと思う。

アプリケーションログの調査

1時に寝て7時に起きた。

アプリケーションログの調査

お仕事でログの整理をやろうとしていて、そのためのライブラリとして ecs-logging-java を調べてた。

一番のモチベーションは JSON Lines でログを管理したいというところ。この手の実装や読み込んでログ分析したりとかはあちこちでやってきたので親近感はある。既存のログからの移行も含めていろいろ設計していかないといけない。私の感覚だとアプリケーションの開発初期にログの設計や出力周りを作り込むものだけど、そうじゃない文化の開発もあるんだなという印象。あとからログ設計するとか、移行や既存のコードに手を入れたり、開発初期に作り込むより手間暇かかる気がするんだけど、そんな時間もなく開発してたってことなのかなぁ。