文書の過去の版を表示しています。


Fluent Bit Redis output plugin

このプラグインは Fluent Bit から Redis にデータを書き込むための Output Plugin。これをインストールして使ってみた。このプラグインの GitHub の Readme.md では、Docker を使った例が載っている。Docker を使わなくても実行できるかよくわからなかったが、いろいろ調べて試してみたら、Docker を使わなくても実行できた。以下そのメモ。ちなみに、このプラグインをインストールする前に、fluent-bit コマンドをインストールしてあり、その時のメモはこちら

インストール

  • git clone して、go でコンパイルする。
  • 以下、インストールコマンド。
    $ cd $HOME/nestdaq/src
    $ git clone https://github.com/majst01/fluent-bit-go-redis-output
    $ cd fluent-bit-go-redis-output
    $ make
    go test -cover -race -coverprofile=coverage.txt -covermode=atomic
    [out-redis] build: version: redis connection to: hosts:[{hosta 6379} {hostb 6379}] db:0 usetls:false tlsskipverify:false key:testkey
    configuration errors: db must be a integer: strconv.Atoi: parsing "a": invalid syntax
    given time is not in a known format, defaulting to now.
    pushed 3 logs
    PASS
    coverage: 75.0% of statements
    ok  	github.com/majst01/fluent-bit-go-redis-output	0.029s
    go build -ldflags "-X 'main.revision=556919d' -X 'main.builddate=2024-01-19 14:13:40+09:00'" -buildmode=c-shared -o out_redis.so .

    途中、 configuration errors と言われるが、問題なさそう。これで、\$HOME/nestdaq/src/fluent-bit-go-redis-output ディレクトリ内に out_redis.h, out_redis.so, coverage.txt というファイルができる。fluent-bit のコマンドでつかうのは、おそらく out_redis.so だけでよさそう。

使ってみる

  • fluent-bit-go-redis-output ディレクトリ内に fluent-bit.conf というファイルがあり、これが configuration file の example のようだ。とりあえず、このファイルのバックアップを取ってから、中身を編集し、以下のようにシンプルにしてみる。
    [SERVICE]
        Flush        1
        Daemon       Off
        Log_Level    debug
        Log_File     /dev/stdout
        Parsers_File parsers.conf
        Parsers_File parsers_java.conf
    
    [INPUT]
        Name cpu
    
    [OUTPUT]
        Name  stdout
        Match *
    
    [Output]
        Name redis
        Match *
        UseTLS false
        TLSSkipVerify true
        # if port is ommited, 6379 is used
        Hosts localhost
    #    Password
        DB 4
        Key logstash

    Redis の部分は、Hosts を redis –> localhost, DB 0 –> DB 4 と編集した。これで、実行してみる。Redis のデータベースは NestDAQ では 3 まで使っているので、番号 4 をテストのために使うことにする。Redis が 自分自身のコンピュータ (localhost) で立ち上がっている状態で、以下のコマンドを実行。

    $ pwd # 今いるディレクトリを一応確認
    /home/nestdaq/nestdaq/src/fluent-bit-go-redis-output
    $ fluent-bit -e ./out_redis.so -c fluent-bit.conf
    Fluent Bit v3.0.0
    * Copyright (C) 2015-2024 The Fluent Bit Authors
    * Fluent Bit is a CNCF sub-project under the umbrella of Fluentd
    * https://fluentbit.io
    
     < Omitted >
    
    [2024/01/19 14:37:46] [ info] Configuration:
    [2024/01/19 14:37:46] [ info]  flush time     | 1.000000 seconds
    [2024/01/19 14:37:46] [ info]  grace          | 5 seconds
    [2024/01/19 14:37:46] [ info]  daemon         | 0
    [2024/01/19 14:37:46] [ info] ___________
    [2024/01/19 14:37:46] [ info]  inputs:
    [2024/01/19 14:37:46] [ info]      cpu
    [2024/01/19 14:37:46] [ info] ___________
    [2024/01/19 14:37:46] [ info]  filters:
    [2024/01/19 14:37:46] [ info] ___________
    [2024/01/19 14:37:46] [ info]  outputs:
    [2024/01/19 14:37:46] [ info]      stdout.0
    [2024/01/19 14:37:46] [ info]      redis.1
    [2024/01/19 14:37:46] [ info] ___________
    [2024/01/19 14:37:46] [ info]  collectors:
    [2024/01/19 14:37:46] [ info] [fluent bit] version=3.0.0, commit=71746b3571, pid=1340738
    [2024/01/19 14:37:46] [debug] [engine] coroutine stack size: 24576 bytes (24.0K)
    [2024/01/19 14:37:46] [ info] [storage] ver=1.5.1, type=memory, sync=normal, checksum=off, max_chunks_up=128
    [2024/01/19 14:37:46] [ info] [cmetrics] version=0.6.6
    [2024/01/19 14:37:46] [ info] [ctraces ] version=0.4.0
    [2024/01/19 14:37:46] [ info] [input:cpu:cpu.0] initializing
    [2024/01/19 14:37:46] [ info] [input:cpu:cpu.0] storage_strategy='memory' (memory only)
    [2024/01/19 14:37:46] [debug] [cpu:cpu.0] created event channels: read=22 write=23
    [2024/01/19 14:37:46] [debug] [stdout:stdout.0] created event channels: read=20 write=24
    [2024/01/19 14:37:46] [debug] [redis:redis.1] created event channels: read=30 write=31
    [2024/01/19 14:37:46] [ info] [output:stdout:stdout.0] worker #0 started
    [out-redis] build:2024-01-19 14:13:40+09:00 version:556919d redis connection to: hosts:[{localhost 6379}] db:4 usetls:false tlsskipverify:true key:logstash
    [2024/01/19 14:37:46] [debug] [router] match rule cpu.0:stdout.0
    [2024/01/19 14:37:46] [debug] [router] match rule cpu.0:redis.1
    [2024/01/19 14:37:46] [ info] [sp] stream processor started
    [2024/01/19 14:37:46] [debug] [input chunk] update output instances with new chunk size diff=853, records=1, input=cpu.0
    [2024/01/19 14:37:47] [debug] [task] created task=0x7f91f0024c40 id=0 OK
    [2024/01/19 14:37:47] [debug] [output:stdout:stdout.0] task_id=0 assigned to thread #0
    [0] cpu.0: [[1705642666.410254275, {}], {"cpu_p"=>0.416667, "user_p"=>0.416667, "system_p"=>0.000000, "cpu0.p_cpu"=>0.000000, "cpu0.p_user"=>0.000000, "cpu0.p_system"=>0.000000, "cpu1.p_cpu"=>5.000000, "cpu1.p_user"=>5.000000, "cpu1.p_system"=>0.000000, "cpu2.p_cpu"=>0.000000, "cpu2.p_user"=>0.000000, "cpu2.p_system"=>0.000000, "cpu3.p_cpu"=>0.000000, "cpu3.p_user"=>0.000000, "cpu3.p_system"=>0.000000, "cpu4.p_cpu"=>0.000000, "cpu4.p_user"=>0.000000, "cpu4.p_system"=>0.000000, "cpu5.p_cpu"=>0.000000, "cpu5.p_user"=>0.000000, "cpu5.p_system"=>0.000000, "cpu6.p_cpu"=>0.000000, "cpu6.p_user"=>0.000000, "cpu6.p_system"=>0.000000, "cpu7.p_cpu"=>0.000000, "cpu7.p_user"=>0.000000, "cpu7.p_system"=>0.000000, "cpu8.p_cpu"=>0.000000, "cpu8.p_user"=>0.000000, "cpu8.p_system"=>0.000000, "cpu9.p_cpu"=>0.000000, "cpu9.p_user"=>0.000000, "cpu9.p_system"=>0.000000, "cpu10.p_cpu"=>1.000000, "cpu10.p_user"=>0.000000, "cpu10.p_system"=>1.000000, "cpu11.p_cpu"=>0.000000, "cpu11.p_user"=>0.000000, "cpu11.p_system"=>0.000000}]
    [2024/01/19 14:37:47] [debug] [out flush] cb_destroy coro_id=0
    [2024/01/19 14:37:47] [debug] [input chunk] update output instances with new chunk size diff=853, records=1, input=cpu.0
    given time is not in a known format, defaulting to now.
    pushed 1 logs
    [2024/01/19 14:37:47] [debug] [out flush] cb_destroy coro_id=0
    [2024/01/19 14:37:47] [debug] [task] destroy task=0x7f91f0024c40 (task_id=0)
    [2024/01/19 14:37:48] [debug] [task] created task=0x7f91f0024db0 id=0 OK
    [2024/01/19 14:37:48] [debug] [output:stdout:stdout.0] task_id=0 assigned to thread #0
    [0] cpu.0: [[1705642667.410595688, {}], {"cpu_p"=>3.250000, "user_p"=>2.916667, "system_p"=>0.333333, "cpu0.p_cpu"=>0.000000, "cpu0.p_user"=>0.000000, "cpu0.p_system"=>0.000000, "cpu1.p_cpu"=>29.000000, "cpu1.p_user"=>29.000000, "cpu1.p_system"=>0.000000, "cpu2.p_cpu"=>0.000000, "cpu2.p_user"=>0.000000, "cpu2.p_system"=>0.000000, "cpu3.p_cpu"=>0.000000, "cpu3.p_user"=>0.000000, "cpu3.p_system"=>0.000000, "cpu4.p_cpu"=>2.000000, "cpu4.p_user"=>1.000000, "cpu4.p_system"=>1.000000, "cpu5.p_cpu"=>0.000000, "cpu5.p_user"=>0.000000, "cpu5.p_system"=>0.000000, "cpu6.p_cpu"=>0.000000, "cpu6.p_user"=>0.000000, "cpu6.p_system"=>0.000000, "cpu7.p_cpu"=>0.000000, "cpu7.p_user"=>0.000000, "cpu7.p_system"=>0.000000, "cpu8.p_cpu"=>0.000000, "cpu8.p_user"=>0.000000, "cpu8.p_system"=>0.000000, "cpu9.p_cpu"=>1.000000, "cpu9.p_user"=>1.000000, "cpu9.p_system"=>0.000000, "cpu10.p_cpu"=>3.000000, "cpu10.p_user"=>2.000000, "cpu10.p_system"=>1.000000, "cpu11.p_cpu"=>0.000000, "cpu11.p_user"=>0.000000, "cpu11.p_system"=>0.000000}]
    [2024/01/19 14:37:48] [debug] [out flush] cb_destroy coro_id=1
    [2024/01/19 14:37:48] [debug] [input chunk] update output instances with new chunk size diff=853, records=1, input=cpu.0
    given time is not in a known format, defaulting to now.
    pushed 1 logs
    ...

    こんな感じで、一秒間隔くらいで、メッセージが表示されていく。これを走らせた状態で、別の端末を開き、Redis の中身を見てみる。

    $ redis-cli
    127.0.0.1:6379> info keyspace
    # Keyspace
    db0:keys=54,expires=38,avg_ttl=2286
    db1:keys=49,expires=0,avg_ttl=0
    db2:keys=3,expires=0,avg_ttl=0
    db3:keys=9,expires=0,avg_ttl=0
    db4:keys=2,expires=0,avg_ttl=0
    127.0.0.1:6379> select 4
    OK
    127.0.0.1:6379[4]> keys *
    1) "logstash"
    (integer) 112
    127.0.0.1:6379[4]> llen logstash
    (integer) 112
    127.0.0.1:6379[4]> llen logstash
    (integer) 113
    127.0.0.1:6379[4]> type logstash
    list

    データベース 4 を選択し、Key 一覧を表示してみると、logstash という Key がいる。type は list。list の長さを llen コマンドで確認すると、1秒間隔くらいでどんどん数が増えていく。さらに、logstash の中身を全部表示してみる。

    127.0.0.1:6379[4]> lrange logstash 0 -1
    
     < Omitted >
    
    137) "{\"@tag\":\"cpu.0\",\"@timestamp\":\"2024-01-19T05:43:51.410648338Z\",\"cpu0.p_cpu\":0,\"cpu0.p_system\":0,\"cpu0.p_user\":0,\"cpu1.p_cpu\":0,\"cpu1.p_system\":0,\"cpu1.p_user\":0,\"cpu10.p_cpu\":3,\"cpu10.p_system\":1,\"cpu10.p_user\":2,\"cpu11.p_cpu\":36,\"cpu11.p_system\":0,\"cpu11.p_user\":36,\"cpu2.p_cpu\":1,\"cpu2.p_system\":0,\"cpu2.p_user\":1,\"cpu3.p_cpu\":0,\"cpu3.p_system\":0,\"cpu3.p_user\":0,\"cpu4.p_cpu\":0,\"cpu4.p_system\":0,\"cpu4.p_user\":0,\"cpu5.p_cpu\":0,\"cpu5.p_system\":0,\"cpu5.p_user\":0,\"cpu6.p_cpu\":2,\"cpu6.p_system\":2,\"cpu6.p_user\":0,\"cpu7.p_cpu\":2,\"cpu7.p_system\":0,\"cpu7.p_user\":2,\"cpu8.p_cpu\":2,\"cpu8.p_system\":1,\"cpu8.p_user\":1,\"cpu9.p_cpu\":1,\"cpu9.p_system\":0,\"cpu9.p_user\":1,\"cpu_p\":4.166666666666667,\"system_p\":0.4166666666666667,\"user_p\":3.75}"
    138) "{\"@tag\":\"cpu.0\",\"@timestamp\":\"2024-01-19T05:43:52.41043964Z\",\"cpu0.p_cpu\":2,\"cpu0.p_system\":1,\"cpu0.p_user\":1,\"cpu1.p_cpu\":2,\"cpu1.p_system\":0,\"cpu1.p_user\":2,\"cpu10.p_cpu\":1,\"cpu10.p_system\":0,\"cpu10.p_user\":1,\"cpu11.p_cpu\":32,\"cpu11.p_system\":0,\"cpu11.p_user\":32,\"cpu2.p_cpu\":1,\"cpu2.p_system\":0,\"cpu2.p_user\":1,\"cpu3.p_cpu\":0,\"cpu3.p_system\":0,\"cpu3.p_user\":0,\"cpu4.p_cpu\":1,\"cpu4.p_system\":1,\"cpu4.p_user\":0,\"cpu5.p_cpu\":0,\"cpu5.p_system\":0,\"cpu5.p_user\":0,\"cpu6.p_cpu\":0,\"cpu6.p_system\":0,\"cpu6.p_user\":0,\"cpu7.p_cpu\":1,\"cpu7.p_system\":0,\"cpu7.p_user\":1,\"cpu8.p_cpu\":1,\"cpu8.p_system\":0,\"cpu8.p_user\":1,\"cpu9.p_cpu\":2,\"cpu9.p_system\":0,\"cpu9.p_user\":2,\"cpu_p\":3.5,\"system_p\":0.25,\"user_p\":3.25}"

    こんな感じで表示される。正しく書き込まれている模様。

使ってみる: Redis の key を fluent-bit コマンド実行時に 変える

  • FairMQ デバイスを複数走らせ、それぞれの出力を Redis の異なる Key の値として保存しようとすると、fluent-bit をたちあげたときに、Key の値を与えたくなる。この場合、fluent-bit の configuration file の variables を使うとできる。
  • Configuration file を以下のように変更。
    [SERVICE]
        Flush        1
        Daemon       Off
        Log_Level    debug
        Log_File     /dev/stdout
        Parsers_File parsers.conf
        Parsers_File parsers_java.conf
    
    [INPUT]
        Name cpu
    
    [OUTPUT]
        Name  stdout
        Match *
    
    [Output]
        Name redis
        Match *
        UseTLS false
        TLSSkipVerify true
        # if port is ommited, 6379 is used
        Hosts localhost
    #    Password
        DB 4
        Key ${REDIS_KEY}

    Key の部分を ${REDIS_KEY} として、環境変数から与えるようにしている。これで、fluent-bit を以下のように走らせる。

    $ pwd # 今いるディレクトリを一応確認
    /home/nestdaq/nestdaq/src/fluent-bit-go-redis-output
    $ REDIS_KEY=key1 fluent-bit -e ./out_redis.so -c fluent-bit.conf

    この状態で、Redis の中身をみると、key1 に値が保存されていく。

    $ redis-cli
    127.0.0.1:6379> select 4
    OK
    127.0.0.1:6379[4]> keys *
    1) "key1"
    2) "logstash"
    127.0.0.1:6379[4]> lrange key1 0 -1
    
     < Omitted >
    
    47) "{\"@tag\":\"cpu.0\",\"@timestamp\":\"2024-01-19T09:16:40.41090011Z\",\"cpu0.p_cpu\":3,\"cpu0.p_system\":0,\"cpu0.p_user\":3,\"cpu1.p_cpu\":0,\"cpu1.p_system\":0,\"cpu1.p_user\":0,\"cpu10.p_cpu\":2,\"cpu10.p_system\":1,\"cpu10.p_user\":1,\"cpu11.p_cpu\":29,\"cpu11.p_system\":0,\"cpu11.p_user\":29,\"cpu2.p_cpu\":0,\"cpu2.p_system\":0,\"cpu2.p_user\":0,\"cpu3.p_cpu\":1,\"cpu3.p_system\":1,\"cpu3.p_user\":0,\"cpu4.p_cpu\":0,\"cpu4.p_system\":0,\"cpu4.p_user\":0,\"cpu5.p_cpu\":0,\"cpu5.p_system\":0,\"cpu5.p_user\":0,\"cpu6.p_cpu\":1,\"cpu6.p_system\":1,\"cpu6.p_user\":0,\"cpu7.p_cpu\":0,\"cpu7.p_system\":0,\"cpu7.p_user\":0,\"cpu8.p_cpu\":0,\"cpu8.p_system\":0,\"cpu8.p_user\":0,\"cpu9.p_cpu\":1,\"cpu9.p_system\":0,\"cpu9.p_user\":1,\"cpu_p\":3,\"system_p\":0.16666666666666666,\"user_p\":2.8333333333333335}"

使ってみる: NestDAQ の出力を Redis に保存

  • とりあえず FairMQ デバイスの標準出力を全部パイプして Redis に書き込むようにしてみる。
  • NestDAQ と nestdaq-user-impl は こちら の手順にしたがってインストールしたものを使う。
  • script を実行している \$HOME/run/ ディレクトリに fluent-bit-go-redit-output の fluent-bit.conf, parsers.conf, out_redis.so をコピーしてくる。
    $ cd $HOME/run
    $ cp $HOME/nestdaq/src/fluent-bit-go-redis-output/fluent-bit.conf ./
    $ cp $HOME/nestdaq/src/fluent-bit-go-redis-output/parsers.conf ./
    $ cp $HOME/nestdaq/src/fluent-bit-go-redis-output/out_redis.so ./

    そしたら、fluent-bit.conf を以下のように編集。

    [SERVICE]
        Flush        1
        Daemon       Off
        Log_Level    debug
        Log_File     /dev/stdout
        Parsers_File parsers.conf
    
    [INPUT]
        Name stdin
        Parser plain
        
    [OUTPUT]
        Name  stdout
        Match *
    
    [Output]
        Name redis
        Match *
        UseTLS false
        TLSSkipVerify true
        # if port is ommited, 6379 is used
        Hosts localhost
    #    Password
        DB 4
        Key ${REDIS_KEY}

    この中で、INPUT の Paser として plain を指定しており、すべての標準出力を各行ごとにそのまま OUTPUT に流している。

  • そのあと、ここ の通りに Redis と NestDAQ の daq-webctl を立ち上げる。./topology_stbplayer_scr.sh も ./mq_param_stbplayer_scr.sh 走らせる。すでに Raw データ保存用のディレクトリ (scr, scrdata, data) はあるはず。
  • \$HOME/nestdaq/run ディレクトリで tmux を立ち上げ、4分割 (Ctrl-b % と Ctrl-b “ を使う。パネル移動は Ctrl-b o。)し、以下のように出力をパイプして FairMQ デバイスを立ち上げる。ちなみに、start_device.sh の中では、METRICS_PLUGINを外し、DAQSERVICE_PLUGIN, CONFIG_PLUGIN, TELEMETRY_PLUGIN をロードしている。TELEMETRY_PLUGIN と METRICS_PLUGIN を2つロードするとデッドロックするところがあったため。現在 (2024/01/19 8:00PM) は高橋さんが問題を修正済み。
    <パネル 1>
    $ ./start_device.sh STFBFilePlayer --wait 1000 --in-file run000408_00_stf.dat | REDIS_KEY=STFBFilePlayer fluent-bit -e ./out_redis.so -c ./fluent-bit.conf
    <パネル 2>
    $ ./start_device.sh Scaler | REDIS_KEY=Scaler fluent-bit -e ./out_redis.so -c ./fluent-bit.conf
    <パネル 3>
    $ ./start_device.sh FileSink --service-name ScrSink | REDIS_KEY=ScrSink fluent-bit -e ./out_redis.so -c ./fluent-bit.conf
    <パネル 4>
    $ ./start_device.sh FileSink | REDIS_KEY=FileSink fluent-bit -e ./out_redis.so -c ./fluent-bit.conf

    各出力はデータベース番号 4 の STFBFilePlayer, Scaler, ScrSink, FileSink というキーに保存される。

  • tmux の出力は以下の感じ。
  • また、Redis の中身は以下の感じ。
    $ redis-cli
    127.0.0.1:6379> select 4
    OK
    127.0.0.1:6379[4]> keys *
    1) "Scaler"
    2) "STFBFilePlayer"
    3) "ScrSink"
    4) "FileSink"
    127.0.0.1:6379[4]> lrange Scaler 0 -1 
    
     < Omitted >
    
    50333) "{\"@tag\":\"stdin.0\",\"@timestamp\":\"2024-01-19T11:00:19.414887549Z\",\"message\":\"6.0e+01:0.0e+00|\"}"
    50334) "{\"@tag\":\"stdin.0\",\"@timestamp\":\"2024-01-19T11:00:19.414929979Z\",\"message\":\"6.1e+01:0.0e+00|\"}"
    50335) "{\"@tag\":\"stdin.0\",\"@timestamp\":\"2024-01-19T11:00:19.414974813Z\",\"message\":\"6.2e+01:0.0e+00|\"}"
    50336) "{\"@tag\":\"stdin.0\",\"@timestamp\":\"2024-01-19T11:00:19.415017688Z\",\"message\":\"6.3e+01:0.0e+00|\"}"
    50337) "{\"@tag\":\"stdin.0\",\"@timestamp\":\"2024-01-19T11:00:19.41506022Z\",\"message\":\"{\\\"id\\\":\\\"Scaler-0\\\",\\\"service-name\\\":\\\"Scaler\\\",\\\"process_name\\\":\\\"Scaler\\\",\\\"timestamp\\\":\\\"20:00:19.398088\\\",\\\"file\\\":\\\"Device.cxx\\\",\\\"line\\\":\\\"757\\\",\\\"func\\\":\\\"LogSocketRates\\\",\\\"severity\\\":\\\"INFO\\\",\\\"time_t\\\":\\\"1705662019\\\",\\\"log\\\":\\\" in[0]: in: 1 (0.000304 MB) out: 0 (0 MB)\\\"}\"}"
    50338) "{\"@tag\":\"stdin.0\",\"@timestamp\":\"2024-01-19T11:00:19.41510353Z\"}"
    50339) "{\"@tag\":\"stdin.0\",\"@timestamp\":\"2024-01-19T11:00:19.415143851Z\",\"message\":\"[\\u001b[01;36m20:00:19\\u001b[0m][\\u001b[01;32mINFO\\u001b[0m]  in[0]: in: 1 (0.000304 MB) out: 0 (0 MB)\"}"
    50340) "{\"@tag\":\"stdin.0\",\"@timestamp\":\"2024-01-19T11:00:19.415189363Z\",\"message\":\"{\\\"id\\\":\\\"Scaler-0\\\",\\\"service-name\\\":\\\"Scaler\\\",\\\"process_name\\\":\\\"Scaler\\\",\\\"timestamp\\\":\\\"20:00:19.398265\\\",\\\"file\\\":\\\"Device.cxx\\\",\\\"line\\\":\\\"757\\\",\\\"func\\\":\\\"LogSocketRates\\\",\\\"severity\\\":\\\"INFO\\\",\\\"time_t\\\":\\\"1705662019\\\",\\\"log\\\":\\\"out[0]: in: 0 (0 MB) out: 1 (0.00056 MB)\\\"}\"}"
    50341) "{\"@tag\":\"stdin.0\",\"@timestamp\":\"2024-01-19T11:00:19.415234633Z\"}"
    50342) "{\"@tag\":\"stdin.0\",\"@timestamp\":\"2024-01-19T11:00:19.415278047Z\",\"message\":\"[\\u001b[01;36m20:00:19\\u001b[0m][\\u001b[01;32mINFO\\u001b[0m] out[0]: in: 0 (0 MB) out: 1 (0.00056 MB)\"}"
    50343) "{\"@tag\":\"stdin.0\",\"@timestamp\":\"2024-01-19T11:00:20.410363252Z\",\"message\":\"{\\\"id\\\":\\\"Scaler-0\\\",\\\"service-name\\\":\\\"Scaler\\\",\\\"process_name\\\":\\\"Scaler\\\",\\\"timestamp\\\":\\\"20:00:20.398522\\\",\\\"file\\\":\\\"Device.cxx\\\",\\\"line\\\":\\\"757\\\",\\\"func\\\":\\\"LogSocketRates\\\",\\\"severity\\\":\\\"INFO\\\",\\\"time_t\\\":\\\"1705662020\\\",\\\"log\\\":\\\" in[0]: in: 1 (0.00044 MB) out: 0 (0 MB)\\\"}\"}"
    50344) "{\"@tag\":\"stdin.0\",\"@timestamp\":\"2024-01-19T11:00:20.41044532Z\"}"
    50345) "{\"@tag\":\"stdin.0\",\"@timestamp\":\"2024-01-19T11:00:20.410496187Z\",\"message\":\"[\\u001b[01;36m20:00:20\\u001b[0m][\\u001b[01;32mINFO\\u001b[0m]  in[0]: in: 1 (0.00044 MB) out: 0 (0 MB)\"}"
    50346) "{\"@tag\":\"stdin.0\",\"@timestamp\":\"2024-01-19T11:00:20.410542475Z\",\"message\":\"{\\\"id\\\":\\\"Scaler-0\\\",\\\"service-name\\\":\\\"Scaler\\\",\\\"process_name\\\":\\\"Scaler\\\",\\\"timestamp\\\":\\\"20:00:20.398728\\\",\\\"file\\\":\\\"Device.cxx\\\",\\\"line\\\":\\\"757\\\",\\\"func\\\":\\\"LogSocketRates\\\",\\\"severity\\\":\\\"INFO\\\",\\\"time_t\\\":\\\"1705662020\\\",\\\"log\\\":\\\"out[0]: in: 0 (0 MB) out: 1 (0.00056 MB)\\\"}\"}"
    50347) "{\"@tag\":\"stdin.0\",\"@timestamp\":\"2024-01-19T11:00:20.41058677Z\"}"
    50348) "{\"@tag\":\"stdin.0\",\"@timestamp\":\"2024-01-19T11:00:20.410626053Z\",\"message\":\"[\\u001b[01;36m20:00:20\\u001b[0m][\\u001b[01;32mINFO\\u001b[0m] out[0]: in: 0 (0 MB) out: 1 (0.00056 MB)\"}"
    (0.80s)

    大量のメッセージが保持されている。メモリとか大丈夫なんだろうか?また、端末の出力のカラー部分のエスケープシーケンスも保持されてて見にくい。さらに、ダブルクオーテーションとかバックスラッシュもエスケープされているようでさらに読みづらい。あと、よくわかっていないが、given time is not in a known format, defaulting to now. というメッセージが大量に出ているのをなんとかしたい。fluent-bit configuration file の書き方も含めて今後調査する。

使ってみる: NestDAQ の出力を Redis に保存 (その2)

  • 標準出力をそのまま Redis に書くと、色付き文字などのエスケープシーケンスが沢山あり、見るのが大変である。Telemetry plugin ありの 2024/1/29 時点の最新の NestDAQ を使うと、Telemetry plugin の出力が json フォーマットで出力されるが、以下のように Redis の保存される。
    $ redis-cli
    127.0.0.1:6379> select 4
    OK
    127.0.0.1:6379[4]> lrange Scaler 0 -1 
    
      < Omitted >
    
    133394) "{\"@tag\":\"stdin.0\",\"@timestamp\":\"2024-01-29T06:25:41.867264379Z\",\"message\":\"{\\\"id\\\":\\\"Scaler-0\\\",\\\"service-name\\\":\\\"Scaler\\\",\\\"process_name\\\":\\\"Scaler\\\",\\\"timestamp\\\":\\\"15:25:41.483464\\\",\\\"file\\\":\\\"Device.cxx\\\",\\\"line\\\":\\\"757\\\",\\\"func\\\":\\\"LogSocketRates\\\",\\\"severity\\\":\\\"INFO\\\",\\\"time_t\\\":\\\"1706509541\\\",\\\"log\\\":\\\" in[0]: in: 0.999001 (0.000815185 MB) out: 0 (0 MB)\\\"}\"}"
    133395) "{\"@tag\":\"stdin.0\",\"@timestamp\":\"2024-01-29T06:25:41.867273023Z\"}"
    133396) "{\"@tag\":\"stdin.0\",\"@timestamp\":\"2024-01-29T06:25:41.86728056Z\",\"message\":\"[\\u001b[01;36m15:25:41\\u001b[0m][\\u001b[01;32mINFO\\u001b[0m]  in[0]: in: 0.999001 (0.000815185 MB) out: 0 (0 MB)\"}"
    133397) "{\"@tag\":\"stdin.0\",\"@timestamp\":\"2024-01-29T06:25:41.867288791Z\",\"message\":\"{\\\"id\\\":\\\"Scaler-0\\\",\\\"service-name\\\":\\\"Scaler\\\",\\\"process_name\\\":\\\"Scaler\\\",\\\"timestamp\\\":\\\"15:25:41.485479\\\",\\\"file\\\":\\\"Device.cxx\\\",\\\"line\\\":\\\"757\\\",\\\"func\\\":\\\"LogSocketRates\\\",\\\"severity\\\":\\\"INFO\\\",\\\"time_t\\\":\\\"1706509541\\\",\\\"log\\\":\\\"out[0]: in: 0 (0 MB) out: 0.999001 (0.000559441 MB)\\\"}\"}"
    133398) "{\"@tag\":\"stdin.0\",\"@timestamp\":\"2024-01-29T06:25:41.867296049Z\"}"
    133399) "{\"@tag\":\"stdin.0\",\"@timestamp\":\"2024-01-29T06:25:41.867303618Z\",\"message\":\"[\\u001b[01;36m15:25:41\\u001b[0m][\\u001b[01;32mINFO\\u001b[0m] out[0]: in: 0 (0 MB) out: 0.999001 (0.000559441 MB)\"}"
    <code> この件について高橋さんから2024/1/19 9:09PM (JST) に Mattermost 上でコメントをいただいた。
        * https://www.rcnp.osaka-u.ac.jp/mattermost/spadi-alliance/pl/h11f8u91b3fm5rssc1un1guf5y
        * <code>FairMQのコマンドライン引数で
    
        --color false でFairMQ built-inのコンソール出力のモノクロ化
        --severity <level> でFairMQ built-inのコンソール出力のログレベル切り替え。--severity nolog とすると std::cout, std::cerrに直接出しているか、custom log sink (TelemetryPluginなど)を使っている場合にコンソールに出ます
    
    https://github.com/FairRootGroup/FairMQ/blob/master/docs/Logging.md#5-logging

    とりあえず、このオプションを使って見やすくしてみる。$HOME/run/start_device.sh の 中身の var+=” –severity debug4“ を var+=” –severity nolog“ にし、fluent bit にパイプせずに実行してみる。

    <パネル 1>
    $ ./start_device.sh STFBFilePlayer --wait 1000 --in-file run000408_00_stf.dat --color false
    <パネル 2>
    $ ./start_device.sh Scaler --color false
    <パネル 3>
    $ ./start_device.sh FileSink --service-name ScrSink --color false
    <パネル 4>
    $ ./start_device.sh FileSink --color false

    結果は以下の画像の感じになる。おそらく、Metrics plugin の出力がなくなり、Telemetry plugin の出力が残っている?

  • さらに、fluent bit に パイプして、redis に書き込んでみる。
    <パネル 1>
    $ ./start_device.sh STFBFilePlayer --wait 1000 --in-file run000408_00_stf.dat --color false | REDIS_KEY=STFBFilePlayer fluent-bit -e ./out_redis.so -c ./fluent-bit.conf
    <パネル 2>
    $ ./start_device.sh Scaler --color false | REDIS_KEY=Scaler fluent-bit -e ./out_redis.so -c ./fluent-bit.conf
    <パネル 3>
    $ ./start_device.sh FileSink --service-name ScrSink --color false | REDIS_KEY=ScrSink fluent-bit -e ./out_redis.so -c ./fluent-bit.conf
    <パネル 4>
    $ ./start_device.sh FileSink --color false | REDIS_KEY=FileSink fluent-bit -e ./out_redis.so -c ./fluent-bit.conf

    Redisの結果は以下の感じ。

    160698) "{\"@tag\":\"stdin.0\",\"@timestamp\":\"2024-01-29T06:51:24.864656566Z\",\"message\":\"{\\\"id\\\":\\\"Scaler-0\\\",\\\"service-name\\\":\\\"Scaler\\\",\\\"process_name\\\":\\\"Scaler\\\",\\\"timestamp\\\":\\\"15:51:24.628999\\\",\\\"file\\\":\\\"Scaler.cxx\\\",\\\"line\\\":\\\"158\\\",\\\"func\\\":\\\"HandleData\\\",\\\"severity\\\":\\\"INFO\\\",\\\"time_t\\\":\\\"1706511084\\\",\\\"log\\\":\\\"tsHeartbeatCounter: 100\\\"}\"}"
    160699) "{\"@tag\":\"stdin.0\",\"@timestamp\":\"2024-01-29T06:51:24.864680934Z\"}"
    160700) "{\"@tag\":\"stdin.0\",\"@timestamp\":\"2024-01-29T06:51:24.864716753Z\",\"message\":\"{\\\"id\\\":\\\"Scaler-0\\\",\\\"service-name\\\":\\\"Scaler\\\",\\\"process_name\\\":\\\"Scaler\\\",\\\"timestamp\\\":\\\"15:51:24.629088\\\",\\\"file\\\":\\\"Scaler.cxx\\\",\\\"line\\\":\\\"159\\\",\\\"func\\\":\\\"HandleData\\\",\\\"severity\\\":\\\"INFO\\\",\\\"time_t\\\":\\\"1706511084\\\",\\\"log\\\":\\\"tsHeartbeatFlag   : 0\\\"}\"}"
    160701) "{\"@tag\":\"stdin.0\",\"@timestamp\":\"2024-01-29T06:51:24.864743743Z\"}"

    さらに、$HOME/run/fluent-bit.conf で

    [SERVICE]
        Flush        1
        Daemon       Off
        Log_Level    debug
        Log_File     /dev/stdout
        Parsers_File parsers.conf
    
    [INPUT]
        Name stdin
    #    Parser plain                                                                                                                                                                                                                           
    
    [OUTPUT]
        Name  stdout
        Match *
    
    [Output]
        Name redis
        Match *
        UseTLS false
        TLSSkipVerify true
        # if port is ommited, 6379 is used                                                                                                                                                                                                      
        Hosts localhost
    #    Password                                                                                                                                                                                                                               
        DB 4
        Key ${REDIS_KEY}

    というように、[INPUT] の Name stdin の Parser plain をコメントアウトし、デフォルトの json パーサーを有効にして、NestDAQ + fluent-bit を走らせると、json フォーマットで出力されたメッセージのみ Redis に書き込まれる。Redis の中身は以下のかんじになる。

    571) "{\"@tag\":\"stdin.0\",\"@timestamp\":\"2024-01-29T07:00:46.864559421Z\",\"file\":\"Scaler.cxx\",\"func\":\"HandleData\",\"id\":\"Scaler-0\",\"line\":\"158\",\"log\":\"tsHeartbeatCounter: 995\",\"process_name\":\"Scaler\",\"service-name\":\"Scaler\",\"severity\":\"INFO\",\"time_t\":\"1706511646\",\"timestamp\":\"16:00:46.615054\"}"
    572) "{\"@tag\":\"stdin.0\",\"@timestamp\":\"2024-01-29T07:00:47.86408278Z\",\"file\":\"Device.cxx\",\"func\":\"LogSocketRates\",\"id\":\"Scaler-0\",\"line\":\"757\",\"log\":\" in[0]: in: 0.997009 (0.000693918 MB) out: 0 (0 MB)\",\"process_name\":\"Scaler\",\"service-name\":\"Scaler\",\"severity\":\"INFO\",\"time_t\":\"1706511647\",\"timestamp\":\"16:00:47.568216\"}"
    573) "{\"@tag\":\"stdin.0\",\"@timestamp\":\"2024-01-29T07:00:47.864251756Z\",\"file\":\"Device.cxx\",\"func\":\"LogSocketRates\",\"id\":\"Scaler-0\",\"line\":\"757\",\"log\":\"out[0]: in: 0 (0 MB) out: 0.997009 (0.000558325 MB)\",\"process_name\":\"Scaler\",\"service-name\":\"Scaler\",\"severity\":\"INFO\",\"time_t\":\"1706511647\",\"timestamp\":\"16:00:47.568961\"}"
    574) "{\"@tag\":\"stdin.0\",\"@timestamp\":\"2024-01-29T07:00:47.86440722Z\",\"_attr\":{\"title\":\"Scaler2D\",\"xtitle\":\"\",\"ytitle\":\"\"},\"_stat\":{\"Entries\":0},\"counts\":[[0,2455,0,1496,0,1524,0,1367,0,1328,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,521,0,469,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0],[0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0]],\"xbins\":{\"max\":64,\"min\":0},\"ybins\":{\"max\":2,\"min\":0}}"
    575) "{\"@tag\":\"stdin.0\",\"@timestamp\":\"2024-01-29T07:00:47.864544819Z\",\"file\":\"Scaler.cxx\",\"func\":\"HandleData\",\"id\":\"Scaler-0\",\"line\":\"158\",\"log\":\"tsHeartbeatCounter: 1000\",\"process_name\":\"Scaler\",\"service-name\":\"Scaler\",\"severity\":\"INFO\",\"time_t\":\"1706511647\",\"timestamp\":\"16:00:47.619254\"}"

    ちなみに、fluent-bit の出力として標準出力に given time is not in a known format, defaulting to now. というメッセージが出るが、これは、https://github.com/majst01/fluent-bit-go-redis-output/blob/556919d57c274432e54dcaac5a8c308127fde3b4/out_redis.go に書いてあるメッセージである。fluent-bit-go-redis-output のプラグインの出力であり、fluent-bit の入力にタイムスタンプがない場合、このメッセージが出ているように見える。

Troubleshooting

  • Go 言語がない
    $ make
    go test -cover -race -coverprofile=coverage.txt -covermode=atomic
    make: go: No such file or directory
    make: *** [Makefile:17: test] Error 127

    Go 言語をインストールする。

    $ sudo apt install golang-go 
softwares/fluent_bit/fluent_bit_go_redit_output.1706514171.txt.gz · 最終更新: 2024/01/29 16:42 by kobayash
CC Attribution-Share Alike 4.0 International
Driven by DokuWiki Recent changes RSS feed Valid CSS Valid XHTML 1.0