🧳

OCI ロギングにログ出力できるツールを作った。

2022/02/17に公開約4,800字

はじめに

OCI (Oracle Cloud Infrastructure) にはロギング機能があります。通常はエージェントをインストールして、システム上のログファイルを OCI に取り込む形で利用されます。

https://docs.oracle.com/ja-jp/iaas/Content/Logging/Concepts/loggingoverview.htm

OCI ではこのロギング機能にも API が公開されており、各言語向けの SDK を利用する事で、アプリケーションからカスタムログ出力を行える様になっています。

試してみたが...

これは楽しそう、そう思って oci-go-sdk を使って実装してみました。しかし動かない。とにかくエラーが出る。

調べに調べまくった結果、どうやら Python の SDK では動作する。デバッグコードを入れまくって検証した結果、oci-go-sdk がログ出力時に指定している日付フォーマットに起因しているのが分かりました。

//Formats for sdk supported time representations
const sdkTimeFormat = time.RFC3339Nano

time.RFC3339Nano は Go では以下の様に定義されています。

RFC3339Nano = "2006-01-02T15:04:05.999999999Z07:00"

しかし Python ではナノ秒ではなくミリ秒で扱っています。以下は Python で送信に成功した時の日付。

2021-04-06T13:09:10.053Z

こんな変更を加えて試した所 Go でも送信できるのが分かりました。

From f7579616910333a45cf7014066d015c3d0617a9c Mon Sep 17 00:00:00 2001
From: Yasuhiro Matsumoto <mattn.jp@gmail.com>
Date: Wed, 15 Dec 2021 23:14:19 +0900
Subject: [PATCH] Fix sdkTimeFormat

OCI server accept millisecond not nanosecond
---
 common/helpers.go   | 4 ++--
 common/http_test.go | 8 ++++----
 2 files changed, 6 insertions(+), 6 deletions(-)

diff --git a/common/helpers.go b/common/helpers.go
index 39e3cb6979..cc55ac5375 100644
--- a/common/helpers.go
+++ b/common/helpers.go
@@ -124,7 +124,7 @@ var sdkDateType = reflect.TypeOf(SDKDate{})
 var sdkDateTypePtr = reflect.TypeOf(&SDKDate{})
 
 //Formats for sdk supported time representations
-const sdkTimeFormat = time.RFC3339Nano
+const sdkTimeFormat = "2006-01-02T15:04:05.000Z07:00"
 const rfc1123OptionalLeadingDigitsInDay = "Mon, _2 Jan 2006 15:04:05 MST"
 const sdkDateFormat = "2006-01-02"
 
@@ -132,7 +132,7 @@ func tryParsingTimeWithValidFormatsForHeaders(data []byte, headerName string) (t
 	header := strings.ToLower(headerName)
 	switch header {
 	case "lastmodified", "date":
-		t, err = tryParsing(data, time.RFC3339Nano, time.RFC3339, time.RFC1123, rfc1123OptionalLeadingDigitsInDay, time.RFC850, time.ANSIC)
+		t, err = tryParsing(data, time.RFC3339Nano, sdkTimeFormat, time.RFC3339, time.RFC1123, rfc1123OptionalLeadingDigitsInDay, time.RFC850, time.ANSIC)
 		return
 	default: //By default we parse with RFC3339
 		t, err = time.Parse(sdkTimeFormat, string(data))
diff --git a/common/http_test.go b/common/http_test.go
index 42c801d362..66b53c836a 100644
--- a/common/http_test.go
+++ b/common/http_test.go
@@ -241,7 +241,7 @@ func TestHttpMarshalerAll(t *testing.T) {
 	var content map[string]string
 	body, _ := ioutil.ReadAll(request.Body)
 	json.Unmarshal(body, &content)
-	when := s.When.Format(time.RFC3339Nano)
+	when := s.When.Format(sdkTimeFormat)
 	assert.True(t, request.URL.Path == "//101")
 	assert.True(t, request.URL.Query().Get("name") == s.Name)
 	assert.True(t, request.URL.Query().Get("income") == strconv.FormatFloat(float64(s.Income), 'f', 2, 32))
@@ -314,7 +314,7 @@ func TestHttpMarshallerSimpleStructPointers(t *testing.T) {
 	assert.Equal(t, "", request.Header.Get(requestHeaderOpcRetryToken))
 	assert.True(t, strings.Contains(request.URL.Path, "111"))
 	assert.True(t, strings.Contains(string(all), "thekey"))
-	assert.Contains(t, string(all), now.Format(time.RFC3339Nano))
+	assert.Contains(t, string(all), now.Format(sdkTimeFormat))
 }
 
 func TestHttpMarshallerSimpleStructPointersFilled(t *testing.T) {
@@ -1190,11 +1190,11 @@ func TestToStringValue_TimeFormat(t *testing.T) {
 	}{
 		{
 			Input:    "2018-10-15T19:43:05.080Z",
-			Expected: "2018-10-15T19:43:05.08Z",
+			Expected: "2018-10-15T19:43:05.080Z",
 		},
 		{
 			Input:    "2018-10-15T19:43:05Z",
-			Expected: "2018-10-15T19:43:05Z",
+			Expected: "2018-10-15T19:43:05.000Z",
 		},
 	}

本来なら、OCI がナノ秒を扱えるのが正しいですね。issue で報告しても良いですが、pull-req を投げて問題を直感的に認識して貰えるので僕はこの方法を使う事もあります。という事で閉じられる覚悟で pull-req を投げました。

https://github.com/oracle/oci-go-sdk/pull/335

OCI がサービス側を直してくれた

無事、OCI 側の問題だという事を認識してくれ、数週間掛かったけど先日デプロイされました。

めでたしめでたし。

何を作りたかったんだっけ

元はと言えば、OCI のロギングにログを出力する為のツールを作っていたのでした。

https://github.com/mattn/oci-log/

最初のコミットから2ヵ月経過してようやく公開する事ができました。oci-log はこの OCI ロギング機能にログを送信する為のツールです。以下の様な事ができます。

$ tail -f /var/log/syslog | oci-log

アプリケーションの出力をそのまま送信する事もできます。

$ ./app 2>&1 | oci-log

実行には以下の環境変数を設定するかフラグで指定する必要があります。

フラグ 環境変数 意味
-logid OCI_LOG_ID カスタムログのOCID
-source OCI_LOG_SOURCE ログ送信元
-subjec OCI_LOG_SUBJECT 題名
-type OCI_LOG_TYPE 種別

種別とログ内容は「ログの検索」機能で以下の様に表示されます。

他の項目は検索条件として指定可能です。内部ではバッファリング機能が実装されており、一定の時間または100行毎にフラッシュする仕組みが入っていますので、量が多いログ出力であっても OCI 側に負荷を掛ける事無くログ出力される様にしてあります。

おわりに

開発はじめから公開まで2ヵ月掛かってしまいましたが、ようやく OCI も修正されツールとして世に出す事ができました。もし OCI ロギング機能をお使いならば試してみて下さい。

Discussion

ログインするとコメントできます