ラベル cron の投稿を表示しています。 すべての投稿を表示
ラベル cron の投稿を表示しています。 すべての投稿を表示

2017年1月20日金曜日

/var/log/cron に crond[xxxx]: (CRON) bad minute (/etc/cron.d/hoge.crontab) メッセージが出る

CentOS 7.3 で crontab を書いていて、/var/log/cron に謎のエラーが出て、しばし格闘したので備忘録です。
出力されたのは、次のメッセージです。
Jan 20 07:19:01 hoge crond[2587]: (CRON) bad minute (/etc/cron.d/hoge.crontab)
hoge.crontab の中身は、こちらです。例示のため、エッセンスに絞ってます。
OP=
30 7 * * * root [ -z "$OP" ] && true
実際に作成していた crontab は、もっと長いもので、どこに問題があるか分からず、徐々に削っていったら、OP= の行が原因とわかりました。おそらく、cronie に誤認されているものと思います。次のように書き換えたらエラー出なくなりました。
OP=""
30 7 * * * root [ -z "$OP" ] && true
やれやれ、こんなところで凝ったことをしようとしないほうが良いですね。

調査の過程で、次のページを参考にさせてもらいました。綺麗&上手にまとめてらっしゃるもんだなあと、感心してしまいました。
http://www.server-memo.net/tips/etc-crontab.html

ついでに、その他のハマりどころとして、環境変数 (例では OP=) の後半にコメント (#) は書けないという事を知りました。man 5 crontab に記述ありました。みなさまも、お気をつけください。

2015年6月17日水曜日

うるう秒(閏秒)の際にcronが二重に実行されるかも?という都市伝説(?)について

今年のうるう秒調整(2015年7月1日午前9:00日本時間)実施まで、あと二週間に迫りましたが、 うるう秒の際に cron ジョブが二重に実行されるかも?という都市伝説(?)を耳にしたことがあるので、CentOS 6 に関して調べてみました。
そもそも /var/log/cron を見渡すと、どれもこれも毎分 :01 秒を狙っている感じです。
[root@hoge ~]# tail /var/log/cron
Jun 16 00:10:01 hoge CROND[9508]: (root) CMD (/usr/lib64/sa/sa1 1 1)
Jun 16 00:11:01 hoge CROND[9546]: (root) CMD (/usr/lib64/sa/sa1 1 1)
Jun 17 01:33:31 hoge crond[2699]: (CRON) INFO (RANDOM_DELAY will be scaled with factor 72% if used.)
Jun 17 01:33:31 hoge crond[2699]: (CRON) INFO (running with inotify support)
Jun 17 01:34:01 hoge CROND[5736]: (root) CMD (/usr/lib64/sa/sa1 1 1)
Jun 17 01:35:01 hoge CROND[6163]: (root) CMD (/usr/lib64/sa/sa1 1 1)
Jun 17 01:36:01 hoge CROND[6197]: (root) CMD (/usr/lib64/sa/sa1 1 1)
Jun 17 01:37:01 hoge CROND[6223]: (root) CMD (/usr/lib64/sa/sa1 1 1)
Jun 17 01:38:01 hoge CROND[6254]: (root) CMD (/usr/lib64/sa/sa1 1 1)
Jun 17 01:39:01 hoge CROND[6736]: (root) CMD (/usr/lib64/sa/sa1 1 1)
それで検索してみますと、cronie について調べている先人の方がおられ、やはり毎分 :01 秒を狙ってスリープしているようです。
http://moro-archive.hatenablog.com/entry/2015/03/17/011823
なぜ、:01 秒狙いなのか?ソース上にはコメントないみたいですが、もしかしたら、うるう秒のことが視野に入っているということなのかも。

というわけで、あっけなく調査終了です。こういった実装なら、うるう秒の際に cron ジョブが二重に実行されるということは、なさそうです。

Linux カーネルのうるう秒調整は、:59 秒を 2 回続ける(ミリ秒単位だと ... :59.998 , :59.999 , :59.000 ... と進める)という実装になってますが、それって cron も意識しているのかもしれませんね。

■関連記事 2017年1月1日の うるう秒 調整時の ntpd の挙動観測データ (次回投稿するつもり)
2015年7月1日の うるう秒 調整時の ntpd の挙動観測データ
2012年7月1日の うるう秒 調整時の ntpd の挙動観測データ
ntpd を1日止めた場合のズレはどの程度か?

2012年6月19日火曜日

第2水曜日にcronスケジュールしたい

第2水曜日および第3水曜日にcronスケジュールしたいと思ったのですが、調べてみるとcronで指定可能なパターンでは、スケジュールできないことを知りました。

http://www.atmarkit.co.jp/bbs/phpBB/viewtopic.php?topic=20020&forum=10

ZFS ファイルシステムの scrub 処理 (整合性チェック) を定期的に動かしたいのですが、zfs-fuse に標準で備わっている設定方法だと、毎週行うか否かの2択になっており、それはちょっと動かし過ぎと思いました。
RAIDZ と RAIDZ2 の2つのストレージプール (tank1, tank2) を作成して ZFS を利用していますが、tank1 は月1回、tank2 は2ヶ月に1回の頻度で scrub を動かしたいため、前述の URL の情報を参考に、自作スクリプトを作りました。どなたかの参考になれば幸いと思いますので、掲載します。
#!/bin/bash
#
# Name: my-zfs-fuse-scrub
#

TARGET=""
if [[ "$1" = 20??-??-?? ]] ; then
    TARGET="-d $1"
elif [ -n "$1" ] ; then
    echo "Usage: my-zfs-fuse-scrub [YYYY-MM-DD]" 1>&2
fi

MONTH=`date +%-m $TARGET`
DAY=`date +%-d $TARGET`
WEEKDAY=`LANG=C date +%a $TARGET`

get_W() {
    local D=$1
    local F L
    for W in 1 2 3 4 5
    do
        F=$((1+($W-1)*7))
        L=$((F+6))
        if let "$F <= $D && $D <= $L" ; then
            break
        fi
    done
}

test_get_W() {
    local D
    for D in `seq 1 31`
    do
        get_W $D
        printf "D=%-2d W=%d\n" $D $W
    done
}
##DEBUG## test_get_W && exit 1

get_W $DAY

if [ "$W,$WEEKDAY" = "2,Wed" ] ; then
    if [ -z "$TARGET" ] ; then
        /usr/bin/zpool scrub tank1
    else
        echo "DEBUG: zpool scrub tank1 run @ $1"
    fi
fi

if [ "$W,$WEEKDAY" = "3,Wed" ] && let "$MONTH%2 == 0" ; then
    if [ -z "$TARGET" ] ; then
        /usr/bin/zpool scrub tank2
    else
        echo "DEBUG: zpool scrub tank2 run @ $1"
    fi
fi

exit 0
これを、次のように crontab に登録することで、毎月第2水曜日 AM1:00 に tank1 の scrub を実行、偶数月の第3水曜日 AM1:00 に tank2 の scrub を実行するようにスケジューリングしました。
0 1 * * Wed /root/bin/my-zfs-fuse-scrub
なお、実行日を確認し易いように、デバッグ機能をつけてあります。
# cal 6 2012
      June 2012
Su Mo Tu We Th Fr Sa 
                1  2
 3  4  5  6  7  8  9
10 11 12 13 14 15 16
17 18 19 20 21 22 23
24 25 26 27 28 29 30

# ./my-zfs-fuse-scrub 2012-06-13
DEBUG: zpool scrub tank1 run @ 2012-06-13
# ./my-zfs-fuse-scrub 2012-06-20
DEBUG: zpool scrub tank2 run @ 2012-06-20
# ./my-zfs-fuse-scrub 2012-06-27
#
# cal 7 2012
      July 2012
Su Mo Tu We Th Fr Sa 
 1  2  3  4  5  6  7
 8  9 10 11 12 13 14
15 16 17 18 19 20 21
22 23 24 25 26 27 28
29 30 31

# ./my-zfs-fuse-scrub 2012-07-11
DEBUG: zpool scrub tank1 run @ 2012-07-11
# ./my-zfs-fuse-scrub 2012-07-18
#
さあこれで、まずは、今晩深夜 1:00 に tank2 への scrub がちゃんと動くはず...何か間違いを犯していなければ。。

2012-06-23追記
ログを確認したところ、うまく行っていました。
# cat /var/log/cron
...
Jun 20 01:00:01 xxxx CROND[28792]: (root) CMD (/root/bin/my-zfs-fuse-scrub)
...
# zpool status

  pool: tank1
 state: ONLINE
 scrub: none requested
config:

...

errors: No known data errors

  pool: tank2
 state: ONLINE
 scrub: scrub completed after 0h42m with 0 errors on Wed Jun 20 01:42:50 2012
config:

...

errors: No known data errors
次は、7/11 (第2水曜) に tank1 の scrub が動き、7/18 (第3水曜日 && 奇数月) には tank2 への scrub が行われない、というふうにプログラムできたはずです。

2012-07-20追記
その後のログを確認したところ、意図した通りに動作していました。
# who -b
         system boot  2012-07-03 12:14
# uptime
 08:07:13 up 14 days, 19:53,  3 users,  load average: 0.12, 0.09, 0.09
# uname -a
Linux xxxx 2.6.32-220.13.1.el6.x86_64 #1 SMP Tue Apr 17 23:56:34 BST 2012 x86_64 x86_64 x86_64 GNU/Linux
# cat /etc/redhat-release 
CentOS release 6.3 (Final)
# grep zfs-fuse /var/log/cron
Jul  3 13:26:01 xxxx run-parts(/etc/cron.weekly)[12348]: starting 98-zfs-fuse-scrub
Jul  3 13:26:01 xxxx run-parts(/etc/cron.weekly)[12355]: finished 98-zfs-fuse-scrub
Jul  4 01:00:01 xxxx CROND[41538]: (root) CMD (/root/bin/my-zfs-fuse-scrub)
Jul 10 03:10:01 xxxx run-parts(/etc/cron.weekly)[30291]: starting 98-zfs-fuse-scrub
Jul 10 03:10:01 xxxx run-parts(/etc/cron.weekly)[30298]: finished 98-zfs-fuse-scrub
Jul 11 01:00:01 xxxx CROND[4220]: (root) CMD (/root/bin/my-zfs-fuse-scrub)
Jul 17 03:37:01 xxxx run-parts(/etc/cron.weekly)[43573]: starting 98-zfs-fuse-scrub
Jul 17 03:37:01 xxxx run-parts(/etc/cron.weekly)[43580]: finished 98-zfs-fuse-scrub
Jul 18 01:00:01 xxxx CROND[15841]: (root) CMD (/root/bin/my-zfs-fuse-scrub)
# zpool status | grep scrub:
 scrub: scrub completed after 1h13m with 0 errors on Wed Jul 11 02:13:35 2012
 scrub: none requested
# zpool status
  pool: tank1
 state: ONLINE
 scrub: scrub completed after 1h13m with 0 errors on Wed Jul 11 02:13:35 2012
config:

...

errors: No known data errors

  pool: tank2
 state: ONLINE
 scrub: none requested
config:

...

errors: No known data errors

これであとは、5年くらい運用・利用できたら、コスト(投資額+構築労力)に見合うかなと思います。

2015-02-10追記
備忘録。この記事を書いた当時は zfs-fuse を使ってたが、その後、ZFS on Linux に切り替えて継続利用中。
当時新品の HDD (ちなみに全て AFT の 2.5inch 7200rpm 750G)で組んで、2年半経過しましたが、今のところ不良セクタはありません。

2010年12月25日土曜日

CentOS 5 の sysstat の採取周期を 1 分毎に変更

CentOS 5 のデフォルトの sysstat 採取周期は 10 分になっているが、これだとアラ過ぎると感じることがあるので、自分の管理しているサーバでは 1 分周期に変更している。

デフォルトの /etc/cron.d/sysstat は、次のようになっている。
# run system activity accounting tool every 10 minutes
*/10 * * * * root /usr/lib64/sa/sa1 1 1
# generate a daily summary of process accounting at 23:53
53 23 * * * root /usr/lib64/sa/sa2 -A
これを、次のように変更する。
# run system activity accounting tool every 1 minutes
*/1 * * * * root /usr/lib64/sa/sa1 1 1
# generate a daily summary of process accounting at 23:53
53 23 * * * root /usr/lib64/sa/sa2 -A
もちろん、格納ファイル (/var/log/sa/saXX, XX は日付) のサイズは 10 倍になるのだが、デフォルトの 10 分間隔で、500 KB/日 程度のものなので、今の大容量時代では、10 倍になったところで取るに足りない。過去 7日分 (/etc/sysconfig/sysstat の HISTORY で指定) として、5MB x 7 = 35 MB ほど。

sar のデータをグラフ化する場合などに、10 分毎のサンプルのほうが都合がいいこともあるかもしれないが、そのような場合は、sar -i オプションを使えばいい。

# sar -f /var/log/sa/sa25 | head -35
Linux 2.6.18-194.26.1.el5 (my41)        12/25/2010

12:00:01 AM       CPU     %user     %nice   %system   %iowait    %steal     %idle
12:01:01 AM       all      0.05      0.00      0.12      0.01      0.00     99.82
12:02:01 AM       all      0.04      0.00      0.16      0.00      0.00     99.80
12:03:01 AM       all      0.17      0.00      0.32      0.01      0.00     99.51
12:04:01 AM       all      0.04      0.00      0.13      0.00      0.00     99.83
12:05:01 AM       all      0.06      0.00      0.17      0.00      0.00     99.77
12:06:01 AM       all      0.03      0.00      0.15      0.00      0.00     99.82
12:07:01 AM       all      0.11      0.00      0.25      0.00      0.00     99.64
12:08:01 AM       all      0.32      0.00      0.32      0.00      0.00     99.35
12:09:01 AM       all      0.32      0.00      0.20      0.00      0.00     99.48
12:10:01 AM       all      0.03      0.00      0.14      0.00      0.00     99.83
12:11:01 AM       all      0.04      0.00      0.20      0.00      0.00     99.76
12:12:01 AM       all      0.04      0.00      0.14      0.01      0.00     99.81
12:13:01 AM       all      0.13      0.00      0.22      0.00      0.00     99.65
12:14:01 AM       all      0.04      0.00      0.17      0.00      0.00     99.79
12:15:01 AM       all      0.06      0.00      0.15      0.00      0.00     99.79
12:16:01 AM       all      0.04      0.00      0.09      0.00      0.00     99.87
12:17:01 AM       all      0.12      0.00      0.28      0.00      0.00     99.60
12:18:01 AM       all      0.07      0.00      0.12      0.00      0.00     99.81
12:19:01 AM       all      0.14      0.00      0.23      0.00      0.00     99.63
12:20:01 AM       all      0.05      0.00      0.15      0.00      0.00     99.80
12:21:01 AM       all      0.04      0.00      0.15      0.00      0.00     99.81
12:22:01 AM       all      0.05      0.00      0.13      0.00      0.00     99.82
12:23:01 AM       all      0.13      0.00      0.26      0.00      0.00     99.61
12:24:01 AM       all      0.06      0.00      0.14      0.00      0.00     99.80
12:25:01 AM       all      0.04      0.00      0.12      0.00      0.00     99.84
12:26:01 AM       all      0.05      0.00      0.16      0.00      0.00     99.79
12:27:01 AM       all      0.13      0.00      0.24      0.00      0.00     99.63
12:28:01 AM       all      0.06      0.00      0.17      0.00      0.00     99.77
12:29:01 AM       all      0.09      0.00      0.19      0.01      0.00     99.70
12:30:01 AM       all      0.03      0.00      0.13      0.00      0.00     99.83
12:31:01 AM       all      0.07      0.00      0.20      0.00      0.00     99.73
12:32:01 AM       all      0.04      0.00      0.14      0.00      0.00     99.82

# sar -i 600 -f /var/log/sa/sa25 | head -6          ※-i オプションで 600秒=10分 指定
Linux 2.6.18-194.26.1.el5 (my41)        12/25/2010

12:00:01 AM       CPU     %user     %nice   %system   %iowait    %steal     %idle
12:10:01 AM       all      0.12      0.00      0.20      0.00      0.00     99.68
12:20:01 AM       all      0.07      0.00      0.18      0.00      0.00     99.75
12:30:01 AM       all      0.07      0.00      0.17      0.00      0.00     99.76

下記も参照ください。
CentOS 5 の sysstat のデフォルトではディスクアクセス統計が採取されない

2013-02-06追記
sar -i は、少々バグっているバージョンがあるようなので、ご注意を。基本、最新使うべし!

2017-06-14追記
sa1 と sa2 が同時に動くとエラーになる場合がある。回避方法。
# run system activity accounting tool every 1 minutes
*/1 * * * * root /usr/lib64/sa/sa1 1 1
# generate a daily summary of process accounting at 23:53
53 23 * * * root sleep 20;/usr/lib64/sa/sa2 -A
sa2 を動かす必要あるかな?とも思うのだが。
人気ブログランキングへ にほんブログ村 IT技術ブログへ