td-agentのbuffer_path重複障害

td-agentを起動した場合、buffer_path指定でエラー発生し、嵌ったので設定時メモ。
sourceディレクティブが複数あり、各tagを指定してサーバへ送信している環境。

• 以下構築条件
  • 各sourceディレクティブでtag指定
  • sourceディレクティブでtag名重複は無い
  • サーバ側で他へforwardする
  • buffer_pathの出力先は他と共用は無い
  • buffer_path出力先に{tag}.*を指定

■現象
本条件でtd-agent.logに以下エラーが発生する

2018-07-12 10:06:32 +0900 [error]: Cannot output messages with tag 'www.nginx.access.80-json'
2018-07-12 10:06:33 +0900 [error]: failed to configure sub output copy: Other 'secure_forward' plugin already use same buffer_path: type = secure_forward, buffer_path = /var/td-agent/buffer/secure-forward_www.nginx.access.80-json.*

tag名に重複無く「already use same buffer_path」となる原因不明。

■原因
td-agentの起動owner(td-agent)に起因する事象

# ps aux|grep ruby
td-agent 10382  0.0  0.6 217136 24136 ?        Sl   18:36   0:00 /opt/td-agent/embedded/bin/ruby /usr/sbin/td-agent --log /var/log/td-agent/td-agent.log --use-v1-config --group td-agent --daemon /var/run/td-agent/td-agent.pid
td-agent 10385  0.0  1.5 257184 59076 ?        Sl   18:36   0:01 /opt/td-agent/embedded/bin/ruby /usr/sbin/td-agent --log /var/log/td-agent/td-agent.log --use-v1-config --group td-agent --daemon /var/run/td-agent/td-agent.pid

■対応
td-agentの起動owner(root)を変更

#vi /etc/sysconfig/td-agent
TD_AGENT_USER=root
TD_AGENT_GROUP=root

td-agentの起動ownerを確認

# ps aux|grep ruby
root     13127  0.0  0.6 217136 24156 ?        Sl   15:07   0:00 /opt/td-agent/embedded/bin/ruby /usr/sbin/td-agent --log /var/log/td-agent/td-agent.log --use-v1-config --group root --daemon /var/run/td-agent/td-agent.pid
root     13130  0.2  2.4 306384 97564 ?        Sl   15:07   0:12 /opt/td-agent/embedded/bin/ruby /usr/sbin/td-agent --log /var/log/td-agent/td-agent.log --use-v1-config --group root --daemon /var/run/td-agent/td-agent.pid

正常にownerが変更され、td-agent.logにエラー発生してない事を確認。
logに記載されている内容から原因調査→対応まで嵌ったのでここに記載しておく。

fluentdの複数sourceディレクティブで各label毎に特定record追加

fluent(td-agent)を使用したlabel切り分けで各label毎にrecord追加する対応が発生したので設定時でのメモ。
sourceディレクティブが複数あり、送信時に特定recordを追加して送りたい場合に有効。
汎用性がありそうな為、調査・対応を下記へ記載しておく。

• 以下構築要件
  • sourceディレクティブを各label名にて割り当
  • 各label毎に特定recordを追加

以下td-agent2環境fluentd v0.12以降のバージョン向けの設定例

<source>
  @id in_redis_server
  @type tail
  @label @redis-server
  read_from_head true
  path /var/log/redis/redis.log
  pos_file /var/log/td-agent/redis.pos
  format none
  message_key log_line
  tag test.redis.log
</source>

<source>
  @id in_redis_sentinel
  @type tail
  @label @redis-sentinel
  read_from_head true
  path /var/log/redis/sentinel.log
  pos_file /var/log/td-agent/redis.sentinel.pos
  format none
  message_key log_line
  tag test.redis.log
</source>

<label @redis-server>
  <match>
    @type relabel
    @label @testlabel
  </match>
</label>

<label @redis-sentinel>
  <filter **>
    @type record_transformer
    <record>
      loginfo.subgroup testgroup
      input_tag ${tag}
      last_tag ${tag_parts[-1]}
      redis_type sentinel
    </record>
  </filter>
  <match>
    @type relabel
    @label @testlabel
  </match>
</label>  

■出力イメージ

2018-06-29T18:17:41+09:00    test.redis.log  {"log_line":"testmessage","loginfo.subgroup":"testgroup","input_tag":"test.redis.log","last_tag":"log","redis_type":"sentinel","loginfo.hostname":"testhost","loginfo.group":"groupname"}

正常にrecord追加出来た。
条件分岐して、個別に情報追記を行う場合に便利に使えそうではある。

Zabbix で fluentd のbuffer・キュー等の項目を監視する

fluent(td-agent)サーバ構築時、buffer等の監視設定時のメモ。
Buffer溢れ、転送先サーバ接続不可などの検知に使用出来ればと考えた。
設定方法を下記へ記載しておく。

• 以下監視項目
  • buffer_queue_length -> (バッファーに蓄積されているキューの数)buffer_queue_limitで設定した値を超えるとログデータがロストするので注意
  • buffer_total_queued_size -> (バッファーに蓄積されている合計サイズ)buffer_queue_limit×buffer_chunk_limitの値を超えるとログデータがロストするので注意
  • retry_count -> ( 再送を試みた回数)retry_limitで設定した回数を超えるとバッファーがリセットされるので注意
  • dirused -> ( フォルダ容量)Bufferに指定されているフォルダ総容量
  • bufnum -> ( フォルダファイル数)Bufferに指定されているフォルダファイル数
  • filetime -> ( フォルダ日時)Bufferに指定されているフォルダに保存されているもっとも古いファイルスタンプ

■以下、zabbixのuserparameter設定

# cat /etc/zabbix/zabbix_agentd.d/userparameter_fluentd.conf
##
# $1: 24220 or 24221 or 24222
# $2: buffer_queue_length or buffer_total_queued_size or retry_count
#
UserParameter=fluentd.queue.get[*],curl -s "localhost:$1/api/plugins.json" | /usr/bin/jq ".plugins[] | .$2" | sort -nr |grep -v null | head -n1
#UserParameter=fluentd.queue.get[*],/root/fluentd.queue.get.sh $1 $2

# cat /etc/zabbix/zabbix_agentd.d/userparameter_td-agent.conf
UserParameter=td-agent.dirused[*],du -bs $1 | cut -f1 2>/dev/null
UserParameter=td-agent.bufnum[*],ls -lt $1 2>/dev/null | wc -l
UserParameter=td-agent.filetime[*],ls -trl --time-style='+%s' $1 | head -n2 | sed -e '1d' | sed -E 's/\s+/,/g' | cut -d, -f6 2>/dev/null
UserParameter=td-agent.chunknum[*],ls /data/buffer/secure-forward_tag.* |wc -l

また、過去に別途shファイルを起動した形式でしたが上記にまとめた。

# cat /root/fluentd.queue.get.sh
#!/bin/bash

##
# $1: 24220 or 24221 or 24222
#
PORT=$1

##
# $2: buffer_queue_length or buffer_total_queued_size or retry_count
#
VALUE=$2

curl -s "localhost:${PORT}/api/plugins.json" | /usr/bin/jq ".plugins[] | .${VALUE}"

後は、zabbixの管理画面でよしなに設定すれば監視される。

fluentdの一時的labelの書き換え

fluent(td-agent)を使用したlabel切り分けで一時的設定→送信時変更する対応が発生したので設定時でのメモ。
sourceディレクティブが複数あり、送信時にsubgroup化して送りたい場合に有効。
sourceディレクティブにsubgroup機能が無い為、送信時のlabelディレクティブ時に追加。
汎用性がありそうな為、調査・対応を下記へ記載しておく。

• 以下構築要件
  • sourceディレクティブで一時的に送信時のグループ名をlabel割り当
  • 一時的割り当てしたグループ名にtd-agent送信時のsubgroupを追加
  • labelを本来設定する名称へ変更

以下td-agent2環境fluentd v0.12以降のバージョン向けの設定例

<source>
  @id test_id
  @type   config_expander
  <config>
    @type tail
    @label @testgroup
    read_from_head true
    path {log_path}.log
    pos_file {posfilepath}.pos
    format multiline
    format_firstline /^\[\d{4}.\d{2}.\d{2}/
    format1 /^\[(?<time>\d{4}.\d{2}.\d{2}\s\d{2}:\d{2}:\d{2})\]\s(?<log_line>.*)/
    message_key log_line
    tag testtag
  </config>
</source>

<label @testgroup>
  <filter **>
    @type record_transformer
    <record>
      loginfo.subgroup testgroup
    </record>
  </filter>
  <match>
    @type relabel
    @label @testlabel
  </match>
</label>

後は、送信時のmatchディレクティブでよしなに設定すれば送信される。

ホスト側からリモートコマンド実行

ansibleのplaybookを使用し、ホスト側から配下内に複数クライアントへ特定コマンドを実行する
* 下記サンプルはmysqlのerror,slowに一括でコマンド実行しログ出力させる。
* td-agent等使用し、ログ収集行う場合のテスト出力で便利

# cat hosts
[hostlist]
hosta ansible_host=172.27.1.1
hostb ansible_host=172.27.1.2
hostc ansible_host=172.27.1.3

# cat test.yml

---
- hosts: hostlist
  become: yes
  become_method: su
  become_user: root
  roles:
     - td-agent
  tasks:

    - name: check mysql errlog
      shell: echo "2018-04-05T01:10141.161639+09:00 0 [Warning] "tables_priv" entry "user mysql.session@localhost" ignored in --skip-name-resolve mode." >> /data/mysql/{{ inventory_hostname }}.errlog

    - name: check mysql slow
      shell: mysql -u[username] -p[passwd] -e "select sleep(2);"

■ 実行
* -C：テスト実行
* -l：hosts内の特定ホストのみ実行

# ansible-playbook -i hosts -u [username] -l hosta,hostb --ask-pass --ask-become-pass test.yml --diff -C

Loop over dates with bash in Linux

特定日時間でのループ処理

• start、endを指定
• daily処理

上記要件の場合の処理script

#!/bin/bash

START=2017-10-22
END=2017-12-31

CURRENT=$START
while true; do
    echo $CURRENT
    if [ "$CURRENT" = "$END" ]; then
        break
    fi
    CURRENT=`date -d "$CURRENT 1day" +%Y-%m-%d`
done

たまにメンテナンスで使用するので便利

ref)

Loop over dates with bash in Linux - oinume journal

mongodb 2.6 クラスタ構成で過負荷対応

クラスタ構成環境のmongosで下記エラー発生。
調査・対応を下記へ記載しておく。

• エラー内容
  • mongos service is down on vm****
  • Processor load is too high on vm****
  • ※ロードアベレージは上がっているが、CPU負荷は増えていない。

対応方法

1.カーネル設定

vm.swappinessの設定をします。
vm.swappinessは、swap領域の扱いを制御するカーネルの設定です。
この設定値が小さければ小さいほどswapを抑制します。
デフォルトは、vm.swappiness=60です。

参考）Swappiness
vm.swappiness = 0 メモリが一杯になるまでスワップを利用しない
vm.swappiness = 60 規定値
vm.swappiness = 100 全体のパフォーマンスに影響しうるほど積極的にスワップ処理を行う

Swappiness - Wikipedia

設定確認

# sysctl vm.swappiness
vm.swappiness = 60

設定変更

# echo 10 > /proc/sys/vm/swappiness

設定確認

# sysctl vm.swappiness
vm.swappiness = 10

sysctl.confに設定を追記

# vim /etc/sysctl.conf
vm.swappiness = 10

2.logrotate設定

公式ドキュメントによると下記3パターンの設定方法がある。

• mongo shell

  • mongos> db.runCommand( { logRotate : 1 } )
  • { "ok" : 1 }

• bash

  • shell> kill -SIGUSR1
  • shell> killall -SIGUSR1 mongod

Rotate Log Files — MongoDB Manual 2.6

bashを使用したローテーションが簡易で良いと考えたが、
実行した場合mongosが落ちるという事象が発生。
原因不明な為、mongo shellを使用したケースで対応。

### cat /root/mongologrotate.sh 
#/bin/sh

# mongod log lotate
mongo --quiet admin /root/MongoLogRotate.js

# clear old olgs
cd {/mongologdir}
DELDAY=`date --date '30 days ago' '+%Y-%m-%d'`

for LINE in `find -iname "mongod.log.$DELDAY*"`
do
  echo "delete $LINE"
  rm -f $LINE
done

### cat /root/MongoLogRotate.js 
db.auth("root", "******")
db.runCommand( { logRotate : 1 } )

### crontab -l
00 15 * * * /bin/sh /root/mongologrotate.sh

3.[slab | page]cache設定

上記2パターンを実行したケースにおいても現象改善されない状況。下記記事からcache設定。

UPDATE: It's fair that the memory usage looks high, which might lead to the conclusion it's another process. There's no other processes using any significant memory on the server; the memory appears to be consumed in the cache, but I'm not clear why that would be the case:

mongodb - Mongod resident memory usage low - Stack Overflow

OS側が保持している各cache設定を開放。

開放前のメモリー使用状況

### free -m
             total       used       free     shared    buffers     cached
Mem:         15951      15204        746          0        145      10355
-/+ buffers/cache:       4703      11248 
Swap:          511        140        371 

### cat /proc/meminfo 
MemTotal:       16334048 kB
MemFree:          764992 kB
Buffers:          149060 kB
Cached:         10604528 kB
SwapCached:         7712 kB
Active:          8825784 kB
Inactive:        5337972 kB
Active(anon):    2757160 kB
Inactive(anon):   653428 kB
Active(file):    6068624 kB
Inactive(file):  4684544 kB
Unevictable:           0 kB
Mlocked:               0 kB
SwapTotal:        524284 kB
SwapFree:         380280 kB
Dirty:                36 kB

OS保持の各cache開放

# free && sync && echo 3 > /proc/sys/vm/drop_caches && echo "" && free

開放後のメモリー使用状況

### free -m
             total       used       free     shared    buffers     cached
Mem:         15951       4908      11042          0        166       1183
-/+ buffers/cache:       3559      12392 
Swap:          511        124        387 

### cat /proc/meminfo 
MemTotal:       16334048 kB
MemFree:        11306796 kB
Buffers:          170120 kB
Cached:          1212012 kB
SwapCached:         5716 kB
Active:          3907484 kB
Inactive:          99016 kB
Active(anon):    2608944 kB
Inactive(anon):    15848 kB
Active(file):    1298540 kB
Inactive(file):    83168 kB
Unevictable:           0 kB
Mlocked:               0 kB
SwapTotal:        524284 kB
SwapFree:         396408 kB
Dirty:                40 kB
Writeback:             0 kB
AnonPages:       2618788 kB
Mapped:            14892 kB
Shmem:               424 kB
Slab:             326744 kB
SReclaimable:      84616 kB
SUnreclaim:       242128 kB
KernelStack:      410944 kB
PageTables:        63036 kB
NFS_Unstable:          0 kB
Bounce:                0 kB
WritebackTmp:          0 kB
CommitLimit:     8691308 kB
Committed_AS:   28622200 kB
VmallocTotal:   34359738367 kB
VmallocUsed:      171952 kB
VmallocChunk:   34359558216 kB
HardwareCorrupted:     0 kB
AnonHugePages:   1978368 kB
HugePages_Total:       0
HugePages_Free:        0
HugePages_Rsvd:        0
HugePages_Surp:        0
Hugepagesize:       2048 kB
DirectMap4k:       10240 kB
DirectMap2M:    16766976 kB

cache開放後、free領域がmongoに割り当てされれば問題ない為
mongo shell 起動し、物理メモリ(resident)領域がcache開放前後で増加しているか確認。

mongos> db.serverStatus().mem
{ "bits" : 64, "resident" : 3299, "virtual" : 29016, "supported" : true }

Linuxでページキャッシュを確認・解放してみた - Qiita