両方とも前のリビジョン前のリビジョン次のリビジョン | 前のリビジョン |
softwares:fluent_bit:fluent_bit_go_redit_output [2024/01/19 20:05] – [使ってみる: NestDAQ の出力を Redis に保存] kobayash | softwares:fluent_bit:fluent_bit_go_redit_output [2024/02/01 21:25] (現在) – [使ってみる: NestDAQ の出力を Redis に保存 (その2)] kobayash |
---|
$ pwd # 今いるディレクトリを一応確認 | $ pwd # 今いるディレクトリを一応確認 |
/home/nestdaq/nestdaq/src/fluent-bit-go-redis-output | /home/nestdaq/nestdaq/src/fluent-bit-go-redis-output |
$ fluent-bit -e ./out_redis.so -c fluent-bit.conf | |
$ fluent-bit -e ./out_redis.so -c fluent-bit.conf | $ fluent-bit -e ./out_redis.so -c fluent-bit.conf |
Fluent Bit v3.0.0 | Fluent Bit v3.0.0 |
</code>この中で、INPUT の Paser として plain を指定しており、すべての標準出力を各行ごとにそのまま OUTPUT に流している。 | </code>この中で、INPUT の Paser として plain を指定しており、すべての標準出力を各行ごとにそのまま OUTPUT に流している。 |
* そのあと、[[softwares:fluent_bit:installation_ubuntu_mate_22_04_3|ここ]] の通りに Redis と NestDAQ の daq-webctl を立ち上げる。./topology_stbplayer_scr.sh も ./mq_param_stbplayer_scr.sh 走らせる。すでに Raw データ保存用のディレクトリ (scr, scrdata, data) はあるはず。 | * そのあと、[[softwares:fluent_bit:installation_ubuntu_mate_22_04_3|ここ]] の通りに 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 デバイスを立ち上げる。各出力はデータベース番号 4 の STFBFilePlayer, Scaler, ScrSink, FileSink というキーに保存される。<code> | * \$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) は高橋さんが問題を修正済み。<code> |
<パネル 1> | <パネル 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 | $ ./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 |
<パネル 4> | <パネル 4> |
$ ./start_device.sh FileSink | REDIS_KEY=FileSink fluent-bit -e ./out_redis.so -c ./fluent-bit.conf | $ ./start_device.sh FileSink | REDIS_KEY=FileSink fluent-bit -e ./out_redis.so -c ./fluent-bit.conf |
</code> | </code> 各出力はデータベース番号 4 の STFBFilePlayer, Scaler, ScrSink, FileSink というキーに保存される。 |
* tmux の出力は以下の感じ。 | * tmux の出力は以下の感じ。 |
* {{:softwares:fluent_bit:fluent_bit_go_redis_output_nestdaq_tmux_20240119.png?400|}} | * {{:softwares:fluent_bit:fluent_bit_go_redis_output_nestdaq_tmux_20240119.png?400|}} |
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)\"}" | 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) | (0.80s) |
</code> 大量のメッセージが保持されている。メモリとか大丈夫なんだろうか?また、端末の出力のカラー部分のエスケープシーケンスも保持されてて見にくい。さらに、ダブルクオーテーションとかバックスラッシュもエスケープされているようでさらに読みづらい。fluent-bit configuration file の書き方も含めて今後調査する。 | </code> 大量のメッセージが保持されている。メモリとか大丈夫なんだろうか?また、端末の出力のカラー部分のエスケープシーケンスも保持されてて見にくい。さらに、ダブルクオーテーションとかバックスラッシュもエスケープされているようでさらに読みづらい。あと、よくわかっていないが、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 の保存される。<code> |
| $ 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 上でコメントをいただいた。<code> |
| * 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 |
| </code> とりあえず、このオプションを使って見やすくしてみる。$HOME/run/start_device.sh の 中身の var+=" --severity debug4" を var+=" --severity nolog" にし、fluent bit にパイプせずに実行してみる。<code> |
| <パネル 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 |
| </code> 結果は以下の画像の感じになる。おそらく、Metrics plugin の出力がなくなり、Telemetry plugin の出力が残っている? |
| * {{:softwares:fluent_bit:nestdaq_fairmq_option_no_color_20240129.png?400|}} |
| * さらに、fluent bit に パイプして、redis に書き込んでみる。<code> |
| <パネル 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 |
| </code> Redisの結果は以下の感じ。<code>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\"}"</code>さらに、$HOME/run/fluent-bit.conf で <code> |
| [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} |
| </code> というように、[INPUT] の Name stdin の Parser plain をコメントアウトし、デフォルトの json パーサーを有効にして、NestDAQ + fluent-bit を走らせると、json フォーマットで出力されたメッセージのみ Redis に書き込まれる。Redis の中身は以下のかんじになる。<code> |
| 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\"}"</code> ちなみに、fluent-bit の出力として標準出力に given time is not in a known format, defaulting to now. というメッセージが出るが、これは、fluent-bit-go-redis-output のプラグインの出力 (もっと言うと、 https://github.com/majst01/fluent-bit-go-redis-output/blob/556919d57c274432e54dcaac5a8c308127fde3b4/out_redis.go の出力) メッセージである。タイムスタンプの型(?)が output.FLBTime にも uint64 にもマッチしないときに出されるようだ。つまり、fluent-bit の入力にタイムスタンプがない場合、このメッセージが出ている? |
==== Troubleshooting ==== | ==== Troubleshooting ==== |
* Go 言語がない<code>$ make | * Go 言語がない<code>$ make |