hirosejn / HJN

TAT log Diver
https://hirosejn.github.io/HJN/dist/tatLogDiver.min.html
0 stars 0 forks source link

シミュレータバグ対応 #61

Closed hirosejn closed 6 years ago

hirosejn commented 6 years ago

FIX

[x] 1時間のシナリオで10回に1度程度、排他なしvAppがWEB,APで300秒タイムアウトになる(12/13FIX) -> baseModel で指定されたリソース取得シーケンスに、holdingを設定していないため   Abend時にリソース解放されずにタイムアウトしていた [x] Menu / filterの指定が効かない(Menu / Simulator対応に伴うデグレ)(12/12FIX) -> FileReader.Property("Filter") を追加して使用 [x] 1時間のシナリオで10回に1度程度、残リソース不整合発生(12/11FIX) -> _waitingQty の管理をやめ _waitHeap のみで滞留を管理 [x] 1hourシナリオの自動生成時に、排他なしvAppがWEB,APで300秒タイムアウトになる(12/10FIX)  startTime と sequenceTime が逆転、ログメッセージに [0]wait:TBL_B が出るケース -> E_HTOのabend時に、waitHeapにあるvAppを削除していなかったため、 [x] E_HTOが連続するとき、start時刻が集中し、end時刻がhold時間に比例する。逆のはず。(12/9FIX) -> resourceにthis._system = systemを保持させる [x] リソース数を0にしたとき、繰返し最終回のE_QOFログ(OK)のあとに、同一時間のN_000ログ(BUG)が出る(12/3FIX) -> リソース枯渇による失敗時、最初のシーケンスから再開する処理に、繰返し回数終了の考慮もれ [x] 処理時間(eTAT)が短すぎる(12/3FIX) -> vApp.next()の中で、ログ出力(_finish())前に、シーケンスを初期化していた [x] JSON:"clients" : [ {"num":0, 指定時に3回起動される(12/3FIX) -> num = num || 3 を num = (typeof(num) === "number") ? num : 1; に修正 [x] JSONで thinkTimeMin":"2sec", "thinkTime": "2sec" のとき2秒となるべきところ4秒になる(12/1FIX ) -> _waitHeap.pop()時に、this._waitingQty--; 漏れ [x] 最初のリソース取得失敗時、ログ出力対象外としていた、(12/1FIX )

改善

[x] シミュレータログ出力機能をログレベル指定できるように変更(12/1) [x] 自動生成データのlog recordsダウンロードファイルの第三カラムにレコードイメージを追加  併せて、File [CSV delimiter]の区切り文字を使用

見た目のバグ

[x] 下段の末尾が、CTPSのみ長い(UNITを考慮して丸め)(12/1FIX) -> 下段のx軸範囲の丸め単位の指定ミス [x] Plotsの日時に誤った時差補正がかかっている(12/1FIX) -> HJN.util.D2S(x, format, true)

リファクタリング系(ソースの読みやすさ改善等)

[x] フィールド名を、実例に即した名称から、リソース種類に依存しない汎用名称に変更(12/1FIX)

hirosejn commented 6 years ago

(12/1反映分) 誤ったシミュレーション結果となる場合があるバグ [x] JSONで thinkTimeMin":"2sec", "thinkTime": "2sec" のとき2秒となるべきところ4秒になる -> _waitHeap.pop()時に、this._waitingQty--; 漏れ [x] 最初のリソース取得失敗時、ログ出力対象外としていた、  また_seaquenceIdxを末尾に設定していなかった [x] testシナリオの自動生成時に、排他なしvAppがWEB,APで300秒タイムアウトになる(DBキュー?) -> _waitHeap.pop()時に、this._waitingQty--; 漏れ -> vResource.next()時の、次回スケジュール時刻算出に残処理を考慮に入れていなかった -> vApp.abend()時に、リソース解放有無指定がなくwait中アベンド時に不要な解放をしていた -> _executingQty がマイナスになることがある(holdの際にリソース枯渇時の実装漏れ)

改善(効率に影響) [x] Resource.next() の次回タイムアウトチェック要否をqueueサイズのみで行い、0 < timeouteのチェックが漏れている [x] シミュレータログ出力機能をログレベル指定できるように変更

改善 [x] 自動生成データのlog recordsダウンロードファイルの第三カラムにレコードイメージを追加  併せて、File [CSV delimiter]の区切り文字を使用

見た目のバグ [x] 下段の末尾が、CTPSのみ長い(UNITを考慮して丸め)-> 下段のx軸範囲の丸め単位の指定ミス [x] Plotsの日時に誤った時差補正がかかっている -> HJN.util.D2S(x, format, true)

リファクタリング系(ソースの読みやすさ改善等) [x] フィールド名を、実例に即した名称から、リソース種類に依存しない汎用名称に変更

新旧 タイムアウト時間 最大数 使用数 管理用Heap
処理待ち(旧) queueTimeout queueDepth queueLength waitQueue
処理(旧) holdTimeout capacity remaining残数 timeoutHeap
処理待ち(新) waitTimeout waitCapacity waitingQty waitHeap
処理(新) execTimeout execCapacity executingQty execHeap
処理(新改) holdTimeout holdCapacity holdingQty holdHeap
hirosejn commented 6 years ago

(12/3FIX分) 誤ったシミュレーション結果となる場合があるバグ [x] テストシナリオで、holdQty>holdヒープサイズ となる場合がある -> abend時にfreeするリソースの順番を、holidings登録順序の逆にする -> _sequenceIdx と _sequence長が同じことがある(終了時にリソース解放失敗) -> Heap._del() のdownHeap前の子ノード有無判定ロジックに誤り [x] holdTimeout多発時のTATのstartTimeが揃っている -> holdTimeout 判定ミス  if (this._holdTimeout <= now - holdTimeoutTime) -> if (holdTimeoutTime <= now) -> abend時のisHolding解釈誤り(holdリソースおよびスケジューラ開放漏れ) [x] リソース数を0にしたとき、繰返し最終回のE_QOFログ(OK)のあとに、同一時間のN_000ログ(BUG)が出る -> リソース枯渇による失敗時、最初のシーケンスから再開する処理に、繰返し回数終了の考慮もれ [x] 処理時間が短すぎる -> vApp.next()の中で、ログ出力(_finish())前に、シーケンスを初期化していた [x] JSON:"clients" : [ {"num":0, 指定時に3回起動される -> num = num || 3 を num = (typeof(num) === "number") ? num : 1; に修正 リファクタリング系 [x] 名称変更 exec... -> hold...

hirosejn commented 6 years ago

(12/4 FIX分) [x] 1hourシナリオの自動生成時に、排他なしvAppがWEB,APで300秒タイムアウトになる  holdQty>holdヒープサイズ(1個違い) となる場合と相関あり(holdキュー?) -> リソースタイムアウト時に、Qtyを二重引き落とししていた(タイムアウトAPPを呼び元リソースからdelしたのち、hold一覧に当該リソースがあると再度delしていたため) -> virtualSystemByJson.Execute()で、model.times のデフォルト指定がないため、undifinedで0が設定されていたた   引数を m.times から (typeof(m.times) === "number") ? m.times : 1, に変更

残バグ [ ] 1hourシナリオの自動生成時に、TBL_BロックvAppがWEB,APで300秒弱でE_HTOタイムアウトになる [ ] TBL_BのholdHeapが空の時にholdQtyが、-8,-9となる

hirosejn commented 6 years ago

(12/5反映分) [x] holdQty>holdヒープサイズ となる -> E_HTO時にリソースを pop,とQty--で削除していた。リソース削除は free() のみで行う [x] holdedResourceのdelを外すと永久ループする(_holdHeap) -> for (var i = holdings.length - 1; 0 < i; i--) { の i === 0も処理対象なので for (var i = holdings.length - 1; 0 <= i; i--) { に修正 -> abend E_HTO時、vAppに自リソースをfree()させていたためfree()していないケースが発生していた。E_HTO時に自リソースにfree()し、vAppはholdedResourceをfree()対象外とする。

残バグ [ ] 1hourシナリオの自動生成時に、排他なしvAppがWEB,APで300秒タイムアウトになる  startTime と sequenceTime が逆転している時と相関あり [ ] E_HTOが連続するとき、start時刻が集中し、end時刻がhold時間に比例する。逆のはず。

hirosejn commented 6 years ago

(12/9反映分) バグ [x] VirtualApp.prototype.abend()でE_HTO のとき holdedResourceを開放していない  -> isHolding === true のとき、開放する

[x] E_HTOが連続するとき、start時刻が集中、E_HTOでstartがseqenceTimeより将来となるエラーも併発  E_HTOでabendしたappがholdしていたresourceをfreeする際の時刻がhold resourceの時刻を使用していた。systemもしくはabend appの時刻を使用する必要がある★★★  resourceにthis._system = systemを保持させる  app.setSequenceTime(this.getTime(), "hold:" + this._name); ->app.setSequenceTime(this._system.getTime(), "hold:" + this._name);

[x] testシナリオでリソース残量不整合発生  00:00:06.007 testAB20(1-2) [DB 0=0 1=0] del " unkown error!! FORCE★: holdingQty modified"  タイムアウトリソースを開放したあと、abend処理内でも開放していたため  以下の true -> falseに変更

// appの使用時間がタイムアウトしたリソースを解放する(注:abendで解放させると永久ループする)
events = events.concat(this.free(app));                
// appをタイムアウト時刻にアベンドさせる(holdリソース解放を伴う)
events = events.concat(app.abend(system, this,"E_HTO", 
               this._name + " hold timeout", true, holdTimeoutTime));

機能追加 [x] ログメッセージに、ステータス更新履歴を追加

残バグ [ ] 1hourシナリオの自動生成時に、排他なしvAppがWEB,APで300秒タイムアウトになる  startTime と sequenceTime が逆転している時と相関あり  ログメッセージに [0]wait:TBL_B 発生時と相関あり

hirosejn commented 6 years ago

(12/10) リファクタリング [Violation] Avoid using document.write().  対策

        var iHtml = "<html><head><style>body{font-size: 10px; margin: 1px; }</style></head>" +
                    "<body id='iHtmlBody'>" + iHtmlBody + "</body></html>";
        var iframe = document.getElementById(elementId);
        iframe.contentWindow.document.open();
        iframe.contentWindow.document.write(iHtml);
        iframe.contentWindow.document.close();

        var body = document.createElement('body');
        body.innerHTML = ""
            + "<style>body{font-size: 10px; margin: 1px; }</style>"
            + "<body id='iHtmlBody'>" + iHtmlBody + "</body>";
        var iframe = document.getElementById(elementId);
        iframe.contentDocument.body = body;

に修正

微修正 [x] JSONのtestシナリオに、JSONの記述方法を記入

hirosejn commented 6 years ago

(12/10) 残バグ [ ] 1時間のシナリオで10回に1度程度、残リソース不整合発生 userB6(-1-3) [TBL_B 7=8 0=0] abend " unkown error!! FORCE★: holdingQty modified"

[ ] 1時間のシナリオで10回に1度程度、排他なしvAppがWEB,APで300秒タイムアウトになる 1970/01/02 16:47:17.954, 298311, E_HTO userS49 WEB hold timeout 排他なし(WEBのみ) [5: free:WEB]47:17.954 seq:42:19.643 [5:E_HTO]47:17.954

FIX [x] 1hourシナリオの自動生成時に、排他なしvAppがWEB,APで300秒タイムアウトになる  startTime と sequenceTime が逆転している時と相関あり  ログメッセージに [0]wait:TBL_B 発生時と相関あり -> E_HTOのabend時に、waitHeapにあるvAppを削除していなかったため、   start後、過去時刻のwaitHeapのvAppが適用されていた   VirtualResource.prototype.release を追加し、abend時に呼び出す処理を追加

step1 当該appが [4:E_HTO] で終了 E_HTO userT4 DB hold timeout select A update B,C 【増】
[0:WEB]38:45.851 [1:AP]38:45.854 [2:DB]38:45.859 [3:]38:45.903 [4:E_HTO]38:55.854

sterp2 当該appが [0:hold:TBL_B]38:55.87 で始まり、終了時に不整合 16:38:56.664 userT4(19-7) finish() Unexpected error★ _startTime > _sequenceTime:16:39:12.361 113952361 > 113936664 Idx:7 "N_000 userT4 select A update B,C 【増】
[0:hold:TBL_B]38:55.876 [0:WEB]38:55.883 [1:AP]38:55.889 [2:hold:DB]38:56.437 [2:DB]38:56.446 [3:]38:56.516 [4:TBL_B]38:56.567 [5:TBL_C]38:56.650 [6:]38:56.664

hirosejn commented 6 years ago

(12/11) 残バグ [ ] 1時間のシナリオで10回に1度程度、排他なしvAppがWEB,APで300秒タイムアウトになる "N_000 userB6 バッチ処理 update B*****
[0:start]25:… seq:25:45.362 [2:free:DB]25:45.351 seq:25:45.362"

リファクタリングネタ [ ] FileReader.prototype.createFilter()function Filter()コンストラクタ内で、  ベタでvar c = HJN.chart.fileReaderを取っている。  HJN.chart.fileReader.createFilter() で呼び出しているので、  HJN.util.FileReader.createFilter(HJN.chart.fileReader) とした方がまし  getterOfLine = HJN.chart.fileReader.createGetterOfLine(file), も同様

FIX [x] Plotsクリック時に、HJN.Plot.List[i].tpsPlot.n なしエラー(12/12FIX) [x] Menu / filterの指定が効かない(Menu / Simulator対応に伴うデグレ)(12/12FIX) HJN.util.FileReaderコンストラクタのthis.configId = "_config_" + "File"; // #53 を修正をしていないため、FileReader.prototype.createFilter()FileReader.prototype.getValue() 内処理が"_config_File"を参照し"_config_Filter"を参照していない  -> FileReader.Property("Filter") を追加★し使用

[x] 1時間のシナリオで10回に1度程度、残リソース不整合発生(12/11FIX) userB6(-1-3) [TBL_B 7=8 0=0] abend " unkown error!! FORCE★: holdingQty modified"  -> 12/10に追加したVirtualResource.prototype.release で、waitHeapからの削除のみで、waitQty の削減処理が不足    _waitingQty と _waitHeapの二重管理する必要がないため、   _waitingQtyの増減処理を削除★し、滞留数は _waitHeap.size() に変更

機能追加 [x] add:グラフのPointクリック時に、lineViewer表示文字列をクリップボードにコピー(12/12ADD)  HJN.util.CopyToClipboardを作成し、HJN.Plot.PointClickCallbackから呼び出す

hirosejn commented 6 years ago

(12/13) FIX [x] 1時間のシナリオで10回に1度程度、排他なしvAppがWEB,APで300秒タイムアウトになる -> baseModel で指定されたリソース取得シーケンスに、holdingを設定していないため   Abend時にリソース解放されずにタイムアウトしていた(12/13FIX)

"N_000 userB6 バッチ処理 update B***** [0:start]25:… seq:25:45.362 [2🆓DB]25:45.351 seq:25:45.362"

原因

  baseModel で指定されたリソースを取得するシーケンスに、holdingを設定していないため  baseModel のリソース取得のAbend時に、取得リソースが解放されずに残置され、  300秒後に、突然E_HTOが発生していた

対応

 VirtualSystem.getModelで、baseModelのリソース取得シーケンスにもholdingを設定する

証跡

55:{x: 114109553, y: 7, sTatIdx: 0, message: "E_QOF userS61 [AP] over flow 排他なし(WEBのみ)↵ [0:start]41:49.546★ [0:WEB]41:49.553 [1:E_QOF]41:49.553"} 56:{x: 114110358, y: 4, sTatIdx: 0, message: "E_QOF userS61 [AP] over flow 排他なし(WEBのみ)↵ [0:start]41:50.354 [0:WEB]41:50.358 [1:E_QOF]41:50.358"} 57:{x: 114111203, y: 9, sTatIdx: 0, message: "E_QOF userS61 [AP] over flow 排他なし(WEBのみ)↵ [0:start]41:51.194 [0:WEB]41:51.203 [1:E_QOF]41:51.203"} 58:{x: 114112188, y: 16, sTatIdx: 0, message: "E_QOF userS61 [AP] over flow 排他なし(WEBのみ)↵ [0:start]41:52.172 [0:WEB]41:52.188 [1:E_QOF]41:52.188"} 59:{x: 114112785, y: 5, sTatIdx: 0, message: "E_QOF userS61 [AP] over flow 排他なし(WEBのみ)↵ [0:start]41:52.780 [0:WEB]41:52.785 [1:E_QOF]41:52.785"} 60:{x: 114409546, y: 296761, sTatIdx: 0, message: "E_HTO userS61 WEB hold timeout 排他なし(WEBのみ)↵ [5:free:WEB]46:49.546 seq:41:52.785 [5:E_HTO]46:49.546★"} ★<--55のstart時刻から300秒後に発生

this: VirtualApp _baseMessage :"排他なし(WEBのみ)↵" _message :"排他なし(WEBのみ)↵ [5:free:WEB]46:49.546 seq:41:52.785 [5:E_HTO]46:49.546" _sequence :Array(5) 0:{hold: "WEB", tatMin: 2, tat: 5, free: Array(0)} ★<-- E_HTO発生 1:{hold: "AP", tatMin: 2, tat: 5, free: Array(0)}  ★<---E_QOF発生時にWEBを解放していない 2:{hold: "DB", tatMin: 2, tat: 5, free: Array(0)} 3:{tatMin: 100, tat: 500, hold: "", holding: Array(3)} 4:{hold: "", tatMin: 6, tat: 15, free: Array(3)} _sequenceIdx :5 _times :-1

リファクタリングネタ [ ] FileReader.prototype.createFilter()のfunction Filter()コンストラクタ内で、  ベタでvar c = HJN.chart.fileReaderを取っている。  HJN.chart.fileReader.createFilter() で呼び出しているので、  HJN.util.FileReader.createFilter(HJN.chart.fileReader) とした方がまし  getterOfLine = HJN.chart.fileReader.createGetterOfLine(file), も同様

[ ] シミュレータのmessage編集処理が遅い  特に文字列置換を行うHJN.util.D2Sの大量呼出しが2割を占める  修正時に、Filter機能がデグレしないよう注意要