rabbit51

it's since Nov.30 2005
May.29 2014, transferred from broach

NVR500のsyslogwatch関数timeout値誤差

2012-02-19 11:04:34 | NVR500
NVR500のlua関数syslogwatch()で指定するtimeout値(秒数)が90秒の誤差を生む原因を調べてみた。
syslogwatch()関数に指定するtimeout値を変化させたときのtimeout時刻との差を調べるためのluaスクリプトを作り調査した。

-- syslogwatch timeout testing
-- syslogwatch timeout time
Interval = 9600

rt.syslog("info","[LUA] syslogwatch-test.lua Start syslogwatch Interval = " .. Interval .. "sec")
-- MAIN
while(true) do
local rtn,str,ntime,rtime
ntime=os.time()+Interval
rtn,str = rt.syslogwatch("Testing",1,Interval)
rtime=os.time()
if (rtn==0) then
rt.syslog("info","[LUA] syslogwatch-test.lua Timeout syslogwatch Interval = " .. Interval .. "sec. dif = " .. os.difftime(rtime,ntime) .. "sec")
else
rt.syslog("info","[LUA] syslogwatch-test.lua Matched syslogwatch Interval = " .. Interval .. "sec. dif = " .. os.difftime(rtime,ntime) .. "sec")
end

end --while

調査方法は、Interval値(timeout秒数)を変化させtimeoutしたときの時刻との差を幾つか調べることにした。
結果は、

20分毎(1200秒)でtimeoutするようIntervalを設定して結果を取得すると

2012/02/18 18:56:01: [LUA] syslogwatch-test.lua Start syslogwatch Interval = 1200sec
2012/02/18 19:16:02: [LUA] syslogwatch-test.lua Timeout syslogwatch Interval = 1200sec. dif = 1sec
2012/02/18 19:36:03: [LUA] syslogwatch-test.lua Timeout syslogwatch Interval = 1200sec. dif = 1sec
2012/02/18 19:56:05: [LUA] syslogwatch-test.lua Timeout syslogwatch Interval = 1200sec. dif = 2sec
2012/02/18 20:16:06: [LUA] syslogwatch-test.lua Timeout syslogwatch Interval = 1200sec. dif = 1sec
2012/02/18 20:36:08: [LUA] syslogwatch-test.lua Timeout syslogwatch Interval = 1200sec. dif = 2sec
2012/02/18 20:56:09: [LUA] syslogwatch-test.lua Timeout syslogwatch Interval = 1200sec. dif = 1sec
2012/02/18 21:16:11: [LUA] syslogwatch-test.lua Timeout syslogwatch Interval = 1200sec. dif = 2sec
2012/02/18 21:36:12: [LUA] syslogwatch-test.lua Timeout syslogwatch Interval = 1200sec. dif = 1sec
2012/02/18 21:56:14: [LUA] syslogwatch-test.lua Timeout syslogwatch Interval = 1200sec. dif = 1sec
2012/02/18 22:16:15: [LUA] syslogwatch-test.lua Timeout syslogwatch Interval = 1200sec. dif = 1sec
2012/02/18 22:36:16: [LUA] syslogwatch-test.lua Timeout syslogwatch Interval = 1200sec. dif = 1sec
2012/02/18 22:56:18: [LUA] syslogwatch-test.lua Timeout syslogwatch Interval = 1200sec. dif = 2sec

約1秒から2秒の差が発生している。
1日(24時間=1440分=86400秒)で90秒の誤差がtimeout用tickの誤差だとすると1200秒に対する誤差は、1.25秒なので1から2秒の誤差結果と一致する。
1日で90秒の誤差なので1秒当たり1/960秒の誤差(遅れ)が発生していることになる。
10秒の誤差を生むInterval値は、9600にすれば良いと推察される。
Interval値を9600でテストスクリプトを動作させてみた。

2012/02/18 23:03:20: [LUA] syslogwatch-test.lua Start syslogwatch Interval = 9600sec
2012/02/19 01:43:29: [LUA] syslogwatch-test.lua Timeout syslogwatch Interval = 9600sec. dif = 9sec
2012/02/19 04:23:39: [LUA] syslogwatch-test.lua Timeout syslogwatch Interval = 9600sec. dif = 10sec
2012/02/19 07:03:49: [LUA] syslogwatch-test.lua Timeout syslogwatch Interval = 9600sec. dif = 10sec
2012/02/19 09:43:59: [LUA] syslogwatch-test.lua Timeout syslogwatch Interval = 9600sec. dif = 10sec

で予測通りの結果が得られた。
この結果を元にNVR500でDynDNSの登録更新をしてみたのスクリプトを変更することとした。

コメント
  • X
  • Facebookでシェアする
  • はてなブックマークに追加する
  • LINEでシェアする

(続)NVR500でDynDNSの登録更新してみた

2012-02-11 11:55:09 | NVR500
NVR500でDynDNSの登録更新してみた」で作成したLUAプログラムの実行時間間隔が90秒づつ進んでいく。
------------------------------------------------------------------------
2012/02/01 01:41:12 [LUA] Task(1) detected time out in rt.syslogwatch
2012/02/02 01:42:42
2012/02/03 01:44:12
2012/02/04 01:45:42
2012/02/05 01:47:12
2012/02/06 01:48:43
2012/02/07 01:50:12
2012/02/08 01:51:43
2012/02/09 01:53:13
2012/02/10 01:54:42
2012/02/11 01:56:12
------------------------------------------------------------------------
luaプログラムを確認したが、これほど大きな時間差で進んでいくことは無いと思う。
yamaha luaのライブラリ関数仕様をチェックしてみた。
rt.httprequest()のtimeoutデフォルト値が30秒【使っている】
rt.mail()のtimeoutデフォルト値が60秒【使っていない】
rt.syslogwatch()のtimeoutは1から864000までの任意値でデフォルトなし【使っている】
関連性が見受けられない。
syslog出力をdebug levelで確認してみた
------------------------------------------------------------------------
2012/01/31 01:39:42: [LUA] Task(1) detected time out in rt.syslogwatch
2012/01/31 01:39:43: [LUA] dyndns-update.lua DynDNS force update IP=121.xxx.yyy.zzz
2012/01/31 01:39:43: [LUA] Task(1) started rt.httprequest
2012/01/31 01:39:43: [LUA] Task(1) completed rt.httprequest
2012/01/31 01:39:43: [LUA] dyndns-update.lua DynDNS Updated IP= 121.xxx.yyy.zzz
2012/01/31 01:39:43: [LUA] Task(1) started rt.syslogwatch
------------------------------------------------------------------------
rt.httprequest()関数はtimeoutしていないし、デフォルト値が加算されていることも無い
rt.syslogwatch()関数がtimeoutするとき+90秒ずれているように見える
rt.syslogwatch()のtimeout指定値を-90秒で設定して様子をみる必要がありそうです
要件等。。。
コメント
  • X
  • Facebookでシェアする
  • はてなブックマークに追加する
  • LINEでシェアする