From dfb6b4edc88b971eaaea1c73f841cddf014ebad0 Mon Sep 17 00:00:00 2001 From: txh18 Date: Wed, 23 Dec 2015 22:28:09 +0800 Subject: get a new log for rnnlm_h300 --- nerv/examples/lmptb/logs/LOG-tnn-h300 | 16189 ++++++++++++++++---------------- 1 file changed, 7988 insertions(+), 8201 deletions(-) diff --git a/nerv/examples/lmptb/logs/LOG-tnn-h300 b/nerv/examples/lmptb/logs/LOG-tnn-h300 index 77fd612..3e99c5d 100644 --- a/nerv/examples/lmptb/logs/LOG-tnn-h300 +++ b/nerv/examples/lmptb/logs/LOG-tnn-h300 @@ -1,69 +1,64 @@ Greetings -[SCHEDULER]: applying arg[2](global_conf.hidden_size=300)... +[SCHEDULER]: not user setting, all default... [SCHEDULER]: printing global_conf... +log_fn /home/slhome/txh18/workspace/ptb/EXP-nerv/rnnlm_tnnh300ch15ba10slr1wc1e-06/log_lstm_tnn_train-test_TT12_23_15-25-01 test_fn /home/slhome/txh18/workspace/nerv/nerv/nerv/examples/lmptb/PTBdata/ptb.test.txt.adds train_fn /home/slhome/txh18/workspace/nerv/nerv/nerv/examples/lmptb/PTBdata/ptb.train.txt.adds -param_random function: 0x40237598 -train_fn_shuf_bak /home/slhome/txh18/workspace/nerv/play/dagL_test/train_fn_shuf_bak -decay_iter 16 -mmat_type table: 0x409280f8 +param_random function: 0x41a72790 +train_fn_shuf_bak /home/slhome/txh18/workspace/ptb/EXP-nerv/rnnlm_tnnh300ch15ba10slr1wc1e-06/train_fn_shuf_bak +decay_iter 15 +mmat_type table: 0x4148c690 vocab_fn /home/slhome/txh18/workspace/nerv/nerv/nerv/examples/lmptb/PTBdata/vocab -train_fn_shuf /home/slhome/txh18/workspace/nerv/play/dagL_test/train_fn_shuf -param_fn /home/slhome/txh18/workspace/nerv/play/dagL_test/params +train_fn_shuf /home/slhome/txh18/workspace/ptb/EXP-nerv/rnnlm_tnnh300ch15ba10slr1wc1e-06/train_fn_shuf +work_dir_base /home/slhome/txh18/workspace/ptb/EXP-nerv/rnnlm_tnn +param_fn /home/slhome/txh18/workspace/ptb/EXP-nerv/rnnlm_tnnh300ch15ba10slr1wc1e-06/params log_w_num 40000 -work_dir /home/slhome/txh18/workspace/nerv/play/dagL_test +work_dir /home/slhome/txh18/workspace/ptb/EXP-nerv/rnnlm_tnnh300ch15ba10slr1wc1e-06 batch_size 10 hidden_size 300 timer nerv.Timer sche_log_pre [SCHEDULER]: nn_act_default 0 -max_iter 35 +max_iter 30 valid_fn /home/slhome/txh18/workspace/nerv/nerv/nerv/examples/lmptb/PTBdata/ptb.valid.txt.adds lrate 1 momentum 0 -wcost 1e-05 +wcost 1e-06 chunk_size 15 -cumat_type table: 0x40935010 +cumat_type table: 0x4149e6a8 [SCHEDULER]: printing training scheduling options... lr_half false start_iter -1 +test_iter -1 ppl_last 100000 [SCHEDULER]: printing training scheduling end. [SCHEDULER]: creating work_dir... +(15:25:07 2015-12-23)[nerv] info: CAUTION[LOG_REDIRECT], all nerv.printf/info/warning/error calls will be double-written to /home/slhome/txh18/workspace/ptb/EXP-nerv/rnnlm_tnnh300ch15ba10slr1wc1e-06/log_lstm_tnn_train-test_TT12_23_15-25-01 [SCHEDULER]: building vocab... [LOG]LMVocab: Vocab building on file /home/slhome/txh18/workspace/nerv/nerv/nerv/examples/lmptb/PTBdata/vocab... [LOG]LMVocab: Building finished, vocab size now is 10000. [SCHEDULER]: preparing parameters... -[SCHEDULER]: first time, generating parameters... +[SCHEDULER]: first time, prepare some pre-set parameters, and leaving other parameters to auto-generation... ===INITIAL VALIDATION=== [SCHEDULER]: preparing parameters... -[SCHEDULER]: loading parameter from file /home/slhome/txh18/workspace/nerv/play/dagL_test/params.0... +[SCHEDULER]: loading parameter from file /home/slhome/txh18/workspace/ptb/EXP-nerv/rnnlm_tnnh300ch15ba10slr1wc1e-06/params.0... reading chunk 0 from 0 -metadata: return {type="nerv.LinearTransParam",id="ltp_ih"} - -reading chunk 1 from 34510155 -metadata: return {type="nerv.LinearTransParam",id="ltp_hh"} - -reading chunk 2 from 35545278 -metadata: return {type="nerv.LinearTransParam",id="ltp_ho"} - -reading chunk 3 from 70045626 -metadata: return {type="nerv.BiasParam",id="bp_h"} - -reading chunk 4 from 70049129 -metadata: return {type="nerv.BiasParam",id="bp_o"} - -reading chunk 5 from 70164107 [SCHEDULER]: preparing parameters end. [SCHEDULER]: preparing layers... -(10:08:46 2015-11-18)[nerv] info: create layer: recurrentL1 -(10:08:46 2015-11-18)[nerv] info: create layer: sigmoidL1 -(10:08:46 2015-11-18)[nerv] info: create layer: combinerL1 -(10:08:46 2015-11-18)[nerv] info: create layer: outputL -(10:08:46 2015-11-18)[nerv] info: create layer: softmaxL -(10:08:46 2015-11-18)[nerv] info: create layer: selectL1 +(15:25:10 2015-12-23)[nerv] info: create layer: sigmoidL1 +(15:25:10 2015-12-23)[nerv] info: create layer: combinerL1 +(15:25:10 2015-12-23)[nerv] info: create layer: selectL1 +(15:25:10 2015-12-23)[nerv] info: Param [ltp] of layer [selectL1] is not found in layer_conf or layer_conf.paramRepo, switch to auto-generate. +(15:25:22 2015-12-23)[nerv] info: create layer: outputL +(15:25:22 2015-12-23)[nerv] info: Param [ltp] of layer [outputL] is not found in layer_conf or layer_conf.paramRepo, switch to auto-generate. +(15:25:35 2015-12-23)[nerv] info: Param [bp] of layer [outputL] is not found in layer_conf or layer_conf.paramRepo, switch to auto-generate. +(15:25:35 2015-12-23)[nerv] info: create layer: softmaxL +(15:25:35 2015-12-23)[nerv] info: create layer: recurrentL1 +(15:25:35 2015-12-23)[nerv] info: Param [bp] of layer [recurrentL1] is not found in layer_conf or layer_conf.paramRepo, switch to auto-generate. +(15:25:35 2015-12-23)[nerv] info: Param [ltp_hh] of layer [recurrentL1] is not found in layer_conf or layer_conf.paramRepo, switch to auto-generate. [SCHEDULER]: preparing layers end. [SCHEDULER]: Generate and initing TNN ... +(15:25:35 2015-12-23)[nerv] info: tnn(TNN) will extend storage beyond MB border for time steps 5... selectL1 0 selectL1 recurrentL1 0 recurrentL1 sigmoidL1 0 @@ -79,54 +74,70 @@ combinerL1 #dim_in: 1 #dim_out: 2 #i_conns_p: 1 #o_conns_p 2 sigmoidL1 #dim_in: 1 #dim_out: 1 #i_conns_p: 1 #o_conns_p 1 selectL1 #dim_in: 1 #dim_out: 1 #i_conns_p: 0 #o_conns_p 1 softmaxL #dim_in: 2 #dim_out: 1 #i_conns_p: 1 #o_conns_p 0 -TNN initing storage selectL1 -> recurrentL1 -TNN initing storage recurrentL1 -> sigmoidL1 -TNN initing storage sigmoidL1 -> combinerL1 -TNN initing storage combinerL1 -> recurrentL1 -TNN initing storage combinerL1 -> outputL -TNN initing storage outputL -> softmaxL +(15:25:35 2015-12-23)[nerv] info: TNN initing storage selectL1->recurrentL1 +(15:25:35 2015-12-23)[nerv] info: TNN initing storage recurrentL1->sigmoidL1 +(15:25:35 2015-12-23)[nerv] info: TNN initing storage sigmoidL1->combinerL1 +(15:25:35 2015-12-23)[nerv] info: TNN initing storage combinerL1->recurrentL1 +(15:25:35 2015-12-23)[nerv] info: TNN initing storage combinerL1->outputL +(15:25:35 2015-12-23)[nerv] info: TNN initing storage outputL->softmaxL [SCHEDULER]: Initing TNN end. [LOG]LMSeqReader: opening file /home/slhome/txh18/workspace/nerv/nerv/nerv/examples/lmptb/PTBdata/ptb.valid.txt.adds... -batch_size: 10 chunk_size 15 -[SCHEDULER]: 40095 words processed Wed Nov 18 10:08:51 2015. - [SCHEDULER]: log prob per sample :-4.003230. - [global_conf.timer]: time spent on tnn_beforeprocess:0.47666 clock time - [global_conf.timer]: time spent on most_out_loop_lmprocessfile:4.10684 clock time - [global_conf.timer]: time spent on tnn_actual_layer_propagate:3.41463 clock time - [global_conf.timer]: time spent on tnn_afterprocess:0.12208 clock time +[LOG]LMSeqReader: batch_size: 10 chunk_size 15 +[LOG]LMSeqReader: se_mode: false +(15:25:37 2015-12-23)[nerv] info: TNN initing storage selectL1->recurrentL1 +(15:25:37 2015-12-23)[nerv] info: TNN initing storage recurrentL1->sigmoidL1 +(15:25:37 2015-12-23)[nerv] info: TNN initing storage sigmoidL1->combinerL1 +(15:25:37 2015-12-23)[nerv] info: TNN initing storage combinerL1->recurrentL1 +(15:25:37 2015-12-23)[nerv] info: TNN initing storage combinerL1->outputL +(15:25:37 2015-12-23)[nerv] info: TNN initing storage outputL->softmaxL +(15:25:37 2015-12-23)[nerv] info: LMTrainer.lm_process_file_rnn: begin processing... +[SCHEDULER]: 40095 words processed Wed Dec 23 15:25:45 2015. + [SCHEDULER]: log prob per sample :-3.991694. + [global_conf.timer]: time spent on tnn_beforeprocess:0.52286 clock time + [global_conf.timer]: time spent on most_out_loop_lmprocessfile:7.15208 clock time + [global_conf.timer]: time spent on tnn_actual_layer_propagate:6.36437 clock time + [global_conf.timer]: time spent on tnn_afterprocess:0.15894 clock time [LOG]LMSeqReader: file expires, closing. +(15:25:52 2015-12-23)[nerv] info: lmseqreader file ends, printing stats... +al_sen_start:false [SCHEDULER]: Displaying result: -[SCHEDULER]: LMResult status of rnn: +[SCHEDULER]: LMResult status of rnn: [SCHEDULER]: Doing on /home/slhome/txh18/workspace/nerv/nerv/nerv/examples/lmptb/PTBdata/ptb.valid.txt.adds end. [SCHEDULER ITER1 LR1]: preparing parameters... -[SCHEDULER ITER1 LR1]: loading parameter from file /home/slhome/txh18/workspace/nerv/play/dagL_test/params.0... +[SCHEDULER ITER1 LR1]: loading parameter from file /home/slhome/txh18/workspace/ptb/EXP-nerv/rnnlm_tnnh300ch15ba10slr1wc1e-06/params.0... reading chunk 0 from 0 -metadata: return {type="nerv.LinearTransParam",id="ltp_ih"} +metadata: return {type="nerv.BiasParam",id="recurrentL1_bp"} -reading chunk 1 from 34510155 -metadata: return {type="nerv.LinearTransParam",id="ltp_hh"} +reading chunk 1 from 3512 +metadata: return {type="nerv.BiasParam",id="outputL_bp"} -reading chunk 2 from 35545278 -metadata: return {type="nerv.LinearTransParam",id="ltp_ho"} +reading chunk 2 from 118553 +metadata: return {type="nerv.LinearTransParam",id="recurrentL1_ltp_hh"} -reading chunk 3 from 70045626 -metadata: return {type="nerv.BiasParam",id="bp_h"} +reading chunk 3 from 1154327 +metadata: return {type="nerv.LinearTransParam",id="outputL_ltp"} -reading chunk 4 from 70049129 -metadata: return {type="nerv.BiasParam",id="bp_o"} +reading chunk 4 from 35653985 +metadata: return {type="nerv.LinearTransParam",id="selectL1_ltp"} -reading chunk 5 from 70164107 +reading chunk 5 from 70164146 [SCHEDULER ITER1 LR1]: preparing parameters end. [SCHEDULER ITER1 LR1]: preparing layers... -(10:08:58 2015-11-18)[nerv] info: create layer: recurrentL1 -(10:08:58 2015-11-18)[nerv] info: create layer: sigmoidL1 -(10:08:58 2015-11-18)[nerv] info: create layer: combinerL1 -(10:08:58 2015-11-18)[nerv] info: create layer: outputL -(10:08:58 2015-11-18)[nerv] info: create layer: softmaxL -(10:08:58 2015-11-18)[nerv] info: create layer: selectL1 +(15:25:55 2015-12-23)[nerv] info: create layer: sigmoidL1 +(15:25:55 2015-12-23)[nerv] info: create layer: combinerL1 +(15:25:55 2015-12-23)[nerv] info: create layer: selectL1 +(15:25:55 2015-12-23)[nerv] info: Param [ltp] of layer [selectL1] found in layer_conf.paramRepo. +(15:25:55 2015-12-23)[nerv] info: create layer: outputL +(15:25:55 2015-12-23)[nerv] info: Param [ltp] of layer [outputL] found in layer_conf.paramRepo. +(15:25:55 2015-12-23)[nerv] info: Param [bp] of layer [outputL] found in layer_conf.paramRepo. +(15:25:55 2015-12-23)[nerv] info: create layer: softmaxL +(15:25:55 2015-12-23)[nerv] info: create layer: recurrentL1 +(15:25:55 2015-12-23)[nerv] info: Param [bp] of layer [recurrentL1] found in layer_conf.paramRepo. +(15:25:55 2015-12-23)[nerv] info: Param [ltp_hh] of layer [recurrentL1] found in layer_conf.paramRepo. [SCHEDULER ITER1 LR1]: preparing layers end. [SCHEDULER ITER1 LR1]: Generate and initing TNN ... +(15:25:55 2015-12-23)[nerv] info: tnn(TNN) will extend storage beyond MB border for time steps 5... selectL1 0 selectL1 recurrentL1 0 recurrentL1 sigmoidL1 0 @@ -142,253 +153,289 @@ combinerL1 #dim_in: 1 #dim_out: 2 #i_conns_p: 1 #o_conns_p 2 sigmoidL1 #dim_in: 1 #dim_out: 1 #i_conns_p: 1 #o_conns_p 1 selectL1 #dim_in: 1 #dim_out: 1 #i_conns_p: 0 #o_conns_p 1 softmaxL #dim_in: 2 #dim_out: 1 #i_conns_p: 1 #o_conns_p 0 -TNN initing storage selectL1 -> recurrentL1 -TNN initing storage recurrentL1 -> sigmoidL1 -TNN initing storage sigmoidL1 -> combinerL1 -TNN initing storage combinerL1 -> recurrentL1 -TNN initing storage combinerL1 -> outputL -TNN initing storage outputL -> softmaxL +(15:25:55 2015-12-23)[nerv] info: TNN initing storage selectL1->recurrentL1 +(15:25:55 2015-12-23)[nerv] info: TNN initing storage recurrentL1->sigmoidL1 +(15:25:55 2015-12-23)[nerv] info: TNN initing storage sigmoidL1->combinerL1 +(15:25:55 2015-12-23)[nerv] info: TNN initing storage combinerL1->recurrentL1 +(15:25:55 2015-12-23)[nerv] info: TNN initing storage combinerL1->outputL +(15:25:55 2015-12-23)[nerv] info: TNN initing storage outputL->softmaxL [SCHEDULER ITER1 LR1]: Initing TNN end. ===ITERATION 1 LR 1.000000=== -[LOG]LMSeqReader: opening file /home/slhome/txh18/workspace/nerv/play/dagL_test/train_fn_shuf... -batch_size: 10 chunk_size 15 -[SCHEDULER ITER1 LR1]: 40099 words processed Wed Nov 18 10:09:09 2015. - [SCHEDULER ITER1 LR1]: log prob per sample :-3.210428. - [global_conf.timer]: time spent on tnn_beforeprocess:0.47135 clock time - [global_conf.timer]: time spent on tnn_actual_layer_propagate:2.75538 clock time - [global_conf.timer]: time spent on most_out_loop_lmprocessfile:10.22335 clock time - [global_conf.timer]: time spent on tnn_actual_layer_update:4.57185 clock time - [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.10319 clock time - [global_conf.timer]: time spent on tnn_afterprocess:0.12114 clock time -[SCHEDULER ITER1 LR1]: 80063 words processed Wed Nov 18 10:09:21 2015. - [SCHEDULER ITER1 LR1]: log prob per sample :-3.048713. - [global_conf.timer]: time spent on tnn_beforeprocess:0.46917 clock time - [global_conf.timer]: time spent on tnn_actual_layer_propagate:2.75080 clock time - [global_conf.timer]: time spent on most_out_loop_lmprocessfile:10.19680 clock time - [global_conf.timer]: time spent on tnn_actual_layer_update:4.56019 clock time - [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.09740 clock time - [global_conf.timer]: time spent on tnn_afterprocess:0.12030 clock time -[SCHEDULER ITER1 LR1]: 120068 words processed Wed Nov 18 10:09:33 2015. - [SCHEDULER ITER1 LR1]: log prob per sample :-2.984911. - [global_conf.timer]: time spent on tnn_beforeprocess:0.47044 clock time - [global_conf.timer]: time spent on tnn_actual_layer_propagate:2.74848 clock time - [global_conf.timer]: time spent on most_out_loop_lmprocessfile:10.18711 clock time - [global_conf.timer]: time spent on tnn_actual_layer_update:4.55472 clock time - [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.09624 clock time - [global_conf.timer]: time spent on tnn_afterprocess:0.12070 clock time -[SCHEDULER ITER1 LR1]: 160017 words processed Wed Nov 18 10:09:45 2015. - [SCHEDULER ITER1 LR1]: log prob per sample :-2.930297. - [global_conf.timer]: time spent on tnn_beforeprocess:0.47130 clock time - [global_conf.timer]: time spent on tnn_actual_layer_propagate:2.75352 clock time - [global_conf.timer]: time spent on most_out_loop_lmprocessfile:10.20206 clock time - [global_conf.timer]: time spent on tnn_actual_layer_update:4.55933 clock time - [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.09779 clock time - [global_conf.timer]: time spent on tnn_afterprocess:0.12088 clock time -[SCHEDULER ITER1 LR1]: 200138 words processed Wed Nov 18 10:09:57 2015. - [SCHEDULER ITER1 LR1]: log prob per sample :-2.897628. - [global_conf.timer]: time spent on tnn_beforeprocess:0.46695 clock time - [global_conf.timer]: time spent on tnn_actual_layer_propagate:2.76538 clock time - [global_conf.timer]: time spent on most_out_loop_lmprocessfile:10.23399 clock time - [global_conf.timer]: time spent on tnn_actual_layer_update:4.57699 clock time - [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.10442 clock time - [global_conf.timer]: time spent on tnn_afterprocess:0.12134 clock time -[SCHEDULER ITER1 LR1]: 240007 words processed Wed Nov 18 10:10:09 2015. - [SCHEDULER ITER1 LR1]: log prob per sample :-2.867407. - [global_conf.timer]: time spent on tnn_beforeprocess:0.46510 clock time - [global_conf.timer]: time spent on tnn_actual_layer_propagate:2.73963 clock time - [global_conf.timer]: time spent on most_out_loop_lmprocessfile:10.15285 clock time - [global_conf.timer]: time spent on tnn_actual_layer_update:4.54229 clock time - [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.08908 clock time - [global_conf.timer]: time spent on tnn_afterprocess:0.12042 clock time -[SCHEDULER ITER1 LR1]: 280135 words processed Wed Nov 18 10:10:21 2015. - [SCHEDULER ITER1 LR1]: log prob per sample :-2.842329. - [global_conf.timer]: time spent on tnn_beforeprocess:0.46714 clock time - [global_conf.timer]: time spent on tnn_actual_layer_propagate:2.75314 clock time - [global_conf.timer]: time spent on most_out_loop_lmprocessfile:10.21984 clock time - [global_conf.timer]: time spent on tnn_actual_layer_update:4.57472 clock time - [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.10567 clock time - [global_conf.timer]: time spent on tnn_afterprocess:0.12149 clock time -[SCHEDULER ITER1 LR1]: 320080 words processed Wed Nov 18 10:10:33 2015. - [SCHEDULER ITER1 LR1]: log prob per sample :-2.823036. - [global_conf.timer]: time spent on tnn_beforeprocess:0.46701 clock time - [global_conf.timer]: time spent on tnn_actual_layer_propagate:2.75169 clock time - [global_conf.timer]: time spent on most_out_loop_lmprocessfile:10.20551 clock time - [global_conf.timer]: time spent on tnn_actual_layer_update:4.56419 clock time - [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.10051 clock time - [global_conf.timer]: time spent on tnn_afterprocess:0.12255 clock time -[SCHEDULER ITER1 LR1]: 360059 words processed Wed Nov 18 10:10:45 2015. - [SCHEDULER ITER1 LR1]: log prob per sample :-2.800986. - [global_conf.timer]: time spent on tnn_beforeprocess:0.47814 clock time - [global_conf.timer]: time spent on tnn_actual_layer_propagate:2.79713 clock time - [global_conf.timer]: time spent on most_out_loop_lmprocessfile:10.30428 clock time - [global_conf.timer]: time spent on tnn_actual_layer_update:4.58719 clock time - [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.10865 clock time - [global_conf.timer]: time spent on tnn_afterprocess:0.12425 clock time -[SCHEDULER ITER1 LR1]: 400021 words processed Wed Nov 18 10:10:57 2015. - [SCHEDULER ITER1 LR1]: log prob per sample :-2.786891. - [global_conf.timer]: time spent on tnn_beforeprocess:0.45977 clock time - [global_conf.timer]: time spent on tnn_actual_layer_propagate:2.73850 clock time - [global_conf.timer]: time spent on most_out_loop_lmprocessfile:10.17294 clock time - [global_conf.timer]: time spent on tnn_actual_layer_update:4.55793 clock time - [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.09813 clock time - [global_conf.timer]: time spent on tnn_afterprocess:0.12008 clock time -[SCHEDULER ITER1 LR1]: 440102 words processed Wed Nov 18 10:11:09 2015. - [SCHEDULER ITER1 LR1]: log prob per sample :-2.770894. - [global_conf.timer]: time spent on tnn_beforeprocess:0.46478 clock time - [global_conf.timer]: time spent on tnn_actual_layer_propagate:2.75843 clock time - [global_conf.timer]: time spent on most_out_loop_lmprocessfile:10.22462 clock time - [global_conf.timer]: time spent on tnn_actual_layer_update:4.57475 clock time - [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.10523 clock time - [global_conf.timer]: time spent on tnn_afterprocess:0.12179 clock time -[SCHEDULER ITER1 LR1]: 480051 words processed Wed Nov 18 10:11:21 2015. - [SCHEDULER ITER1 LR1]: log prob per sample :-2.754795. - [global_conf.timer]: time spent on tnn_beforeprocess:0.46079 clock time - [global_conf.timer]: time spent on tnn_actual_layer_propagate:2.74221 clock time - [global_conf.timer]: time spent on most_out_loop_lmprocessfile:10.17129 clock time - [global_conf.timer]: time spent on tnn_actual_layer_update:4.55381 clock time - [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.09688 clock time - [global_conf.timer]: time spent on tnn_afterprocess:0.12041 clock time -[SCHEDULER ITER1 LR1]: 520093 words processed Wed Nov 18 10:11:33 2015. - [SCHEDULER ITER1 LR1]: log prob per sample :-2.740832. - [global_conf.timer]: time spent on tnn_beforeprocess:0.46013 clock time - [global_conf.timer]: time spent on tnn_actual_layer_propagate:2.74097 clock time - [global_conf.timer]: time spent on most_out_loop_lmprocessfile:10.19854 clock time - [global_conf.timer]: time spent on tnn_actual_layer_update:4.57069 clock time - [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.10617 clock time - [global_conf.timer]: time spent on tnn_afterprocess:0.12053 clock time -[SCHEDULER ITER1 LR1]: 560039 words processed Wed Nov 18 10:11:45 2015. - [SCHEDULER ITER1 LR1]: log prob per sample :-2.725416. - [global_conf.timer]: time spent on tnn_beforeprocess:0.45905 clock time - [global_conf.timer]: time spent on tnn_actual_layer_propagate:2.73400 clock time - [global_conf.timer]: time spent on most_out_loop_lmprocessfile:10.16478 clock time - [global_conf.timer]: time spent on tnn_actual_layer_update:4.55572 clock time - [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.09740 clock time - [global_conf.timer]: time spent on tnn_afterprocess:0.12013 clock time -[SCHEDULER ITER1 LR1]: 600112 words processed Wed Nov 18 10:11:57 2015. - [SCHEDULER ITER1 LR1]: log prob per sample :-2.716177. - [global_conf.timer]: time spent on tnn_beforeprocess:0.46687 clock time - [global_conf.timer]: time spent on tnn_actual_layer_propagate:2.76335 clock time - [global_conf.timer]: time spent on most_out_loop_lmprocessfile:10.25973 clock time - [global_conf.timer]: time spent on tnn_actual_layer_update:4.58834 clock time - [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.11483 clock time - [global_conf.timer]: time spent on tnn_afterprocess:0.12277 clock time -[SCHEDULER ITER1 LR1]: 640076 words processed Wed Nov 18 10:12:09 2015. - [SCHEDULER ITER1 LR1]: log prob per sample :-2.705623. - [global_conf.timer]: time spent on tnn_beforeprocess:0.46173 clock time - [global_conf.timer]: time spent on tnn_actual_layer_propagate:2.74375 clock time - [global_conf.timer]: time spent on most_out_loop_lmprocessfile:10.17842 clock time - [global_conf.timer]: time spent on tnn_actual_layer_update:4.55617 clock time - [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.09811 clock time - [global_conf.timer]: time spent on tnn_afterprocess:0.12090 clock time -[SCHEDULER ITER1 LR1]: 680026 words processed Wed Nov 18 10:12:21 2015. - [SCHEDULER ITER1 LR1]: log prob per sample :-2.696685. - [global_conf.timer]: time spent on tnn_beforeprocess:0.46080 clock time - [global_conf.timer]: time spent on tnn_actual_layer_propagate:2.73873 clock time - [global_conf.timer]: time spent on most_out_loop_lmprocessfile:10.16648 clock time - [global_conf.timer]: time spent on tnn_actual_layer_update:4.55295 clock time - [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.09625 clock time - [global_conf.timer]: time spent on tnn_afterprocess:0.12004 clock time -[SCHEDULER ITER1 LR1]: 720133 words processed Wed Nov 18 10:12:33 2015. - [SCHEDULER ITER1 LR1]: log prob per sample :-2.687998. - [global_conf.timer]: time spent on tnn_beforeprocess:0.46041 clock time - [global_conf.timer]: time spent on tnn_actual_layer_propagate:2.73861 clock time - [global_conf.timer]: time spent on most_out_loop_lmprocessfile:10.19165 clock time - [global_conf.timer]: time spent on tnn_actual_layer_update:4.57016 clock time - [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.10446 clock time - [global_conf.timer]: time spent on tnn_afterprocess:0.12015 clock time -[SCHEDULER ITER1 LR1]: 760048 words processed Wed Nov 18 10:12:45 2015. - [SCHEDULER ITER1 LR1]: log prob per sample :-2.676801. - [global_conf.timer]: time spent on tnn_beforeprocess:0.45850 clock time - [global_conf.timer]: time spent on tnn_actual_layer_propagate:2.73148 clock time - [global_conf.timer]: time spent on most_out_loop_lmprocessfile:10.15910 clock time - [global_conf.timer]: time spent on tnn_actual_layer_update:4.55561 clock time - [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.09577 clock time - [global_conf.timer]: time spent on tnn_afterprocess:0.11943 clock time -[SCHEDULER ITER1 LR1]: 800117 words processed Wed Nov 18 10:12:57 2015. - [SCHEDULER ITER1 LR1]: log prob per sample :-2.669544. - [global_conf.timer]: time spent on tnn_beforeprocess:0.45975 clock time - [global_conf.timer]: time spent on tnn_actual_layer_propagate:2.74013 clock time - [global_conf.timer]: time spent on most_out_loop_lmprocessfile:10.19139 clock time - [global_conf.timer]: time spent on tnn_actual_layer_update:4.56894 clock time - [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.10351 clock time - [global_conf.timer]: time spent on tnn_afterprocess:0.12031 clock time -[SCHEDULER ITER1 LR1]: 840116 words processed Wed Nov 18 10:13:09 2015. - [SCHEDULER ITER1 LR1]: log prob per sample :-2.659602. - [global_conf.timer]: time spent on tnn_beforeprocess:0.46031 clock time - [global_conf.timer]: time spent on tnn_actual_layer_propagate:2.73769 clock time - [global_conf.timer]: time spent on most_out_loop_lmprocessfile:10.17842 clock time - [global_conf.timer]: time spent on tnn_actual_layer_update:4.56008 clock time - [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.10197 clock time - [global_conf.timer]: time spent on tnn_afterprocess:0.12018 clock time -[SCHEDULER ITER1 LR1]: 880037 words processed Wed Nov 18 10:13:20 2015. - [SCHEDULER ITER1 LR1]: log prob per sample :-2.652101. - [global_conf.timer]: time spent on tnn_beforeprocess:0.45781 clock time - [global_conf.timer]: time spent on tnn_actual_layer_propagate:2.73064 clock time - [global_conf.timer]: time spent on most_out_loop_lmprocessfile:10.15936 clock time - [global_conf.timer]: time spent on tnn_actual_layer_update:4.55415 clock time - [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.09854 clock time - [global_conf.timer]: time spent on tnn_afterprocess:0.11997 clock time +[LOG]LMSeqReader: opening file /home/slhome/txh18/workspace/ptb/EXP-nerv/rnnlm_tnnh300ch15ba10slr1wc1e-06/train_fn_shuf... +[LOG]LMSeqReader: batch_size: 10 chunk_size 15 +[LOG]LMSeqReader: se_mode: false +(15:25:55 2015-12-23)[nerv] info: TNN initing storage selectL1->recurrentL1 +(15:25:55 2015-12-23)[nerv] info: TNN initing storage recurrentL1->sigmoidL1 +(15:25:55 2015-12-23)[nerv] info: TNN initing storage sigmoidL1->combinerL1 +(15:25:55 2015-12-23)[nerv] info: TNN initing storage combinerL1->recurrentL1 +(15:25:55 2015-12-23)[nerv] info: TNN initing storage combinerL1->outputL +(15:25:55 2015-12-23)[nerv] info: TNN initing storage outputL->softmaxL +(15:25:55 2015-12-23)[nerv] info: LMTrainer.lm_process_file_rnn: begin processing... +[SCHEDULER ITER1 LR1]: 40099 words processed Wed Dec 23 15:26:11 2015. + [SCHEDULER ITER1 LR1]: log prob per sample :-3.208733. + [global_conf.timer]: time spent on tnn_beforeprocess:0.49912 clock time + [global_conf.timer]: time spent on tnn_actual_layer_propagate:6.18861 clock time + [global_conf.timer]: time spent on most_out_loop_lmprocessfile:15.10438 clock time + [global_conf.timer]: time spent on tnn_actual_layer_update:5.86339 clock time + [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.13806 clock time + [global_conf.timer]: time spent on tnn_afterprocess:0.15891 clock time +[SCHEDULER ITER1 LR1]: 80063 words processed Wed Dec 23 15:26:27 2015. + [SCHEDULER ITER1 LR1]: log prob per sample :-3.027452. + [global_conf.timer]: time spent on tnn_beforeprocess:0.50375 clock time + [global_conf.timer]: time spent on tnn_actual_layer_propagate:6.16717 clock time + [global_conf.timer]: time spent on most_out_loop_lmprocessfile:15.04599 clock time + [global_conf.timer]: time spent on tnn_actual_layer_update:5.83912 clock time + [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.12530 clock time + [global_conf.timer]: time spent on tnn_afterprocess:0.15900 clock time +[SCHEDULER ITER1 LR1]: 120068 words processed Wed Dec 23 15:26:43 2015. + [SCHEDULER ITER1 LR1]: log prob per sample :-2.949047. + [global_conf.timer]: time spent on tnn_beforeprocess:0.49959 clock time + [global_conf.timer]: time spent on tnn_actual_layer_propagate:6.17205 clock time + [global_conf.timer]: time spent on most_out_loop_lmprocessfile:15.04428 clock time + [global_conf.timer]: time spent on tnn_actual_layer_update:5.83331 clock time + [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.12965 clock time + [global_conf.timer]: time spent on tnn_afterprocess:0.15888 clock time +[SCHEDULER ITER1 LR1]: 160017 words processed Wed Dec 23 15:27:00 2015. + [SCHEDULER ITER1 LR1]: log prob per sample :-2.892670. + [global_conf.timer]: time spent on tnn_beforeprocess:0.52759 clock time + [global_conf.timer]: time spent on tnn_actual_layer_propagate:6.48079 clock time + [global_conf.timer]: time spent on most_out_loop_lmprocessfile:15.64937 clock time + [global_conf.timer]: time spent on tnn_actual_layer_update:6.00684 clock time + [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.16768 clock time + [global_conf.timer]: time spent on tnn_afterprocess:0.16836 clock time +[SCHEDULER ITER1 LR1]: 200138 words processed Wed Dec 23 15:27:17 2015. + [SCHEDULER ITER1 LR1]: log prob per sample :-2.862344. + [global_conf.timer]: time spent on tnn_beforeprocess:0.50400 clock time + [global_conf.timer]: time spent on tnn_actual_layer_propagate:6.26080 clock time + [global_conf.timer]: time spent on most_out_loop_lmprocessfile:15.23420 clock time + [global_conf.timer]: time spent on tnn_actual_layer_update:5.90703 clock time + [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.13851 clock time + [global_conf.timer]: time spent on tnn_afterprocess:0.16026 clock time +[SCHEDULER ITER1 LR1]: 240007 words processed Wed Dec 23 15:27:34 2015. + [SCHEDULER ITER1 LR1]: log prob per sample :-2.832988. + [global_conf.timer]: time spent on tnn_beforeprocess:0.50224 clock time + [global_conf.timer]: time spent on tnn_actual_layer_propagate:6.27449 clock time + [global_conf.timer]: time spent on most_out_loop_lmprocessfile:15.24373 clock time + [global_conf.timer]: time spent on tnn_actual_layer_update:5.89637 clock time + [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.13873 clock time + [global_conf.timer]: time spent on tnn_afterprocess:0.15986 clock time +[SCHEDULER ITER1 LR1]: 280135 words processed Wed Dec 23 15:27:51 2015. + [SCHEDULER ITER1 LR1]: log prob per sample :-2.807892. + [global_conf.timer]: time spent on tnn_beforeprocess:0.52736 clock time + [global_conf.timer]: time spent on tnn_actual_layer_propagate:6.50277 clock time + [global_conf.timer]: time spent on most_out_loop_lmprocessfile:15.71085 clock time + [global_conf.timer]: time spent on tnn_actual_layer_update:6.03449 clock time + [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.17865 clock time + [global_conf.timer]: time spent on tnn_afterprocess:0.16944 clock time +[SCHEDULER ITER1 LR1]: 320080 words processed Wed Dec 23 15:28:07 2015. + [SCHEDULER ITER1 LR1]: log prob per sample :-2.787610. + [global_conf.timer]: time spent on tnn_beforeprocess:0.47566 clock time + [global_conf.timer]: time spent on tnn_actual_layer_propagate:6.02338 clock time + [global_conf.timer]: time spent on most_out_loop_lmprocessfile:14.73258 clock time + [global_conf.timer]: time spent on tnn_actual_layer_update:5.75188 clock time + [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.10406 clock time + [global_conf.timer]: time spent on tnn_afterprocess:0.14869 clock time +[SCHEDULER ITER1 LR1]: 360059 words processed Wed Dec 23 15:28:23 2015. + [SCHEDULER ITER1 LR1]: log prob per sample :-2.765522. + [global_conf.timer]: time spent on tnn_beforeprocess:0.46910 clock time + [global_conf.timer]: time spent on tnn_actual_layer_propagate:5.98256 clock time + [global_conf.timer]: time spent on most_out_loop_lmprocessfile:14.64817 clock time + [global_conf.timer]: time spent on tnn_actual_layer_update:5.72921 clock time + [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.09774 clock time + [global_conf.timer]: time spent on tnn_afterprocess:0.14636 clock time +[SCHEDULER ITER1 LR1]: 400021 words processed Wed Dec 23 15:28:39 2015. + [SCHEDULER ITER1 LR1]: log prob per sample :-2.751868. + [global_conf.timer]: time spent on tnn_beforeprocess:0.46969 clock time + [global_conf.timer]: time spent on tnn_actual_layer_propagate:5.98096 clock time + [global_conf.timer]: time spent on most_out_loop_lmprocessfile:14.64490 clock time + [global_conf.timer]: time spent on tnn_actual_layer_update:5.72892 clock time + [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.09642 clock time + [global_conf.timer]: time spent on tnn_afterprocess:0.14590 clock time +[SCHEDULER ITER1 LR1]: 440102 words processed Wed Dec 23 15:28:55 2015. + [SCHEDULER ITER1 LR1]: log prob per sample :-2.736409. + [global_conf.timer]: time spent on tnn_beforeprocess:0.47132 clock time + [global_conf.timer]: time spent on tnn_actual_layer_propagate:6.00369 clock time + [global_conf.timer]: time spent on most_out_loop_lmprocessfile:14.69775 clock time + [global_conf.timer]: time spent on tnn_actual_layer_update:5.74976 clock time + [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.10222 clock time + [global_conf.timer]: time spent on tnn_afterprocess:0.14619 clock time +[SCHEDULER ITER1 LR1]: 480051 words processed Wed Dec 23 15:29:11 2015. + [SCHEDULER ITER1 LR1]: log prob per sample :-2.721181. + [global_conf.timer]: time spent on tnn_beforeprocess:0.46899 clock time + [global_conf.timer]: time spent on tnn_actual_layer_propagate:5.98351 clock time + [global_conf.timer]: time spent on most_out_loop_lmprocessfile:14.64798 clock time + [global_conf.timer]: time spent on tnn_actual_layer_update:5.72954 clock time + [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.09617 clock time + [global_conf.timer]: time spent on tnn_afterprocess:0.14592 clock time +[SCHEDULER ITER1 LR1]: 520093 words processed Wed Dec 23 15:29:27 2015. + [SCHEDULER ITER1 LR1]: log prob per sample :-2.708133. + [global_conf.timer]: time spent on tnn_beforeprocess:0.47288 clock time + [global_conf.timer]: time spent on tnn_actual_layer_propagate:6.01261 clock time + [global_conf.timer]: time spent on most_out_loop_lmprocessfile:14.72172 clock time + [global_conf.timer]: time spent on tnn_actual_layer_update:5.75420 clock time + [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.10711 clock time + [global_conf.timer]: time spent on tnn_afterprocess:0.14766 clock time +[SCHEDULER ITER1 LR1]: 560039 words processed Wed Dec 23 15:29:43 2015. + [SCHEDULER ITER1 LR1]: log prob per sample :-2.693347. + [global_conf.timer]: time spent on tnn_beforeprocess:0.47246 clock time + [global_conf.timer]: time spent on tnn_actual_layer_propagate:6.00098 clock time + [global_conf.timer]: time spent on most_out_loop_lmprocessfile:14.68805 clock time + [global_conf.timer]: time spent on tnn_actual_layer_update:5.74210 clock time + [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.09885 clock time + [global_conf.timer]: time spent on tnn_afterprocess:0.14709 clock time +[SCHEDULER ITER1 LR1]: 600112 words processed Wed Dec 23 15:29:59 2015. + [SCHEDULER ITER1 LR1]: log prob per sample :-2.684825. + [global_conf.timer]: time spent on tnn_beforeprocess:0.47372 clock time + [global_conf.timer]: time spent on tnn_actual_layer_propagate:6.03642 clock time + [global_conf.timer]: time spent on most_out_loop_lmprocessfile:14.75985 clock time + [global_conf.timer]: time spent on tnn_actual_layer_update:5.76671 clock time + [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.10646 clock time + [global_conf.timer]: time spent on tnn_afterprocess:0.14797 clock time +[SCHEDULER ITER1 LR1]: 640076 words processed Wed Dec 23 15:30:16 2015. + [SCHEDULER ITER1 LR1]: log prob per sample :-2.674873. + [global_conf.timer]: time spent on tnn_beforeprocess:0.51025 clock time + [global_conf.timer]: time spent on tnn_actual_layer_propagate:6.37618 clock time + [global_conf.timer]: time spent on most_out_loop_lmprocessfile:15.42601 clock time + [global_conf.timer]: time spent on tnn_actual_layer_update:5.94153 clock time + [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.15211 clock time + [global_conf.timer]: time spent on tnn_afterprocess:0.16617 clock time +[SCHEDULER ITER1 LR1]: 680026 words processed Wed Dec 23 15:30:33 2015. + [SCHEDULER ITER1 LR1]: log prob per sample :-2.666825. + [global_conf.timer]: time spent on tnn_beforeprocess:0.50876 clock time + [global_conf.timer]: time spent on tnn_actual_layer_propagate:6.36958 clock time + [global_conf.timer]: time spent on most_out_loop_lmprocessfile:15.46533 clock time + [global_conf.timer]: time spent on tnn_actual_layer_update:5.96944 clock time + [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.15677 clock time + [global_conf.timer]: time spent on tnn_afterprocess:0.16815 clock time +[SCHEDULER ITER1 LR1]: 720133 words processed Wed Dec 23 15:30:50 2015. + [SCHEDULER ITER1 LR1]: log prob per sample :-2.658816. + [global_conf.timer]: time spent on tnn_beforeprocess:0.49595 clock time + [global_conf.timer]: time spent on tnn_actual_layer_propagate:6.25148 clock time + [global_conf.timer]: time spent on most_out_loop_lmprocessfile:15.18774 clock time + [global_conf.timer]: time spent on tnn_actual_layer_update:5.88182 clock time + [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.13916 clock time + [global_conf.timer]: time spent on tnn_afterprocess:0.15690 clock time +[SCHEDULER ITER1 LR1]: 760048 words processed Wed Dec 23 15:31:07 2015. + [SCHEDULER ITER1 LR1]: log prob per sample :-2.648532. + [global_conf.timer]: time spent on tnn_beforeprocess:0.50178 clock time + [global_conf.timer]: time spent on tnn_actual_layer_propagate:6.32493 clock time + [global_conf.timer]: time spent on most_out_loop_lmprocessfile:15.32939 clock time + [global_conf.timer]: time spent on tnn_actual_layer_update:5.92035 clock time + [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.14429 clock time + [global_conf.timer]: time spent on tnn_afterprocess:0.16224 clock time +[SCHEDULER ITER1 LR1]: 800117 words processed Wed Dec 23 15:31:24 2015. + [SCHEDULER ITER1 LR1]: log prob per sample :-2.642086. + [global_conf.timer]: time spent on tnn_beforeprocess:0.50275 clock time + [global_conf.timer]: time spent on tnn_actual_layer_propagate:6.30792 clock time + [global_conf.timer]: time spent on most_out_loop_lmprocessfile:15.31499 clock time + [global_conf.timer]: time spent on tnn_actual_layer_update:5.91857 clock time + [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.15170 clock time + [global_conf.timer]: time spent on tnn_afterprocess:0.16169 clock time +[SCHEDULER ITER1 LR1]: 840116 words processed Wed Dec 23 15:31:41 2015. + [SCHEDULER ITER1 LR1]: log prob per sample :-2.633060. + [global_conf.timer]: time spent on tnn_beforeprocess:0.51405 clock time + [global_conf.timer]: time spent on tnn_actual_layer_propagate:6.40662 clock time + [global_conf.timer]: time spent on most_out_loop_lmprocessfile:15.48276 clock time + [global_conf.timer]: time spent on tnn_actual_layer_update:5.95914 clock time + [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.15308 clock time + [global_conf.timer]: time spent on tnn_afterprocess:0.16813 clock time +[SCHEDULER ITER1 LR1]: 880037 words processed Wed Dec 23 15:31:58 2015. + [SCHEDULER ITER1 LR1]: log prob per sample :-2.626273. + [global_conf.timer]: time spent on tnn_beforeprocess:0.49958 clock time + [global_conf.timer]: time spent on tnn_actual_layer_propagate:6.27819 clock time + [global_conf.timer]: time spent on most_out_loop_lmprocessfile:15.22222 clock time + [global_conf.timer]: time spent on tnn_actual_layer_update:5.87408 clock time + [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.14477 clock time + [global_conf.timer]: time spent on tnn_afterprocess:0.15965 clock time [LOG]LMSeqReader: file expires, closing. +(15:32:02 2015-12-23)[nerv] info: lmseqreader file ends, printing stats... +al_sen_start:false [SCHEDULER ITER1 LR1]: Displaying result: -[SCHEDULER ITER1 LR1]: LMResult status of rnn: -[SCHEDULER ITER1 LR1]: Doing on /home/slhome/txh18/workspace/nerv/play/dagL_test/train_fn_shuf end. +[SCHEDULER ITER1 LR1]: LMResult status of rnn: +[SCHEDULER ITER1 LR1]: Doing on /home/slhome/txh18/workspace/ptb/EXP-nerv/rnnlm_tnnh300ch15ba10slr1wc1e-06/train_fn_shuf end. [SCHEDULER ITER1 LR1]: shuffling training file ===PEEK ON TEST 1=== [LOG]LMSeqReader: opening file /home/slhome/txh18/workspace/nerv/nerv/nerv/examples/lmptb/PTBdata/ptb.test.txt.adds... -batch_size: 10 chunk_size 15 -[SCHEDULER ITER1 LR1]: 40087 words processed Wed Nov 18 10:13:30 2015. - [SCHEDULER ITER1 LR1]: log prob per sample :-2.504076. - [global_conf.timer]: time spent on tnn_beforeprocess:0.46941 clock time - [global_conf.timer]: time spent on tnn_actual_layer_propagate:2.75798 clock time - [global_conf.timer]: time spent on most_out_loop_lmprocessfile:3.45029 clock time - [global_conf.timer]: time spent on tnn_afterprocess:0.11464 clock time +[LOG]LMSeqReader: batch_size: 10 chunk_size 15 +[LOG]LMSeqReader: se_mode: false +(15:32:05 2015-12-23)[nerv] info: TNN initing storage selectL1->recurrentL1 +(15:32:05 2015-12-23)[nerv] info: TNN initing storage recurrentL1->sigmoidL1 +(15:32:05 2015-12-23)[nerv] info: TNN initing storage sigmoidL1->combinerL1 +(15:32:05 2015-12-23)[nerv] info: TNN initing storage combinerL1->recurrentL1 +(15:32:05 2015-12-23)[nerv] info: TNN initing storage combinerL1->outputL +(15:32:05 2015-12-23)[nerv] info: TNN initing storage outputL->softmaxL +(15:32:05 2015-12-23)[nerv] info: LMTrainer.lm_process_file_rnn: begin processing... +[SCHEDULER ITER1 LR1]: 40087 words processed Wed Dec 23 15:32:13 2015. + [SCHEDULER ITER1 LR1]: log prob per sample :-2.490319. + [global_conf.timer]: time spent on tnn_beforeprocess:0.52150 clock time + [global_conf.timer]: time spent on tnn_actual_layer_propagate:6.47313 clock time + [global_conf.timer]: time spent on most_out_loop_lmprocessfile:7.29086 clock time + [global_conf.timer]: time spent on tnn_afterprocess:0.15853 clock time [LOG]LMSeqReader: file expires, closing. +(15:32:21 2015-12-23)[nerv] info: lmseqreader file ends, printing stats... +al_sen_start:false [SCHEDULER ITER1 LR1]: Displaying result: -[SCHEDULER ITER1 LR1]: LMResult status of rnn: +[SCHEDULER ITER1 LR1]: LMResult status of rnn: [SCHEDULER ITER1 LR1]: Doing on /home/slhome/txh18/workspace/nerv/nerv/nerv/examples/lmptb/PTBdata/ptb.test.txt.adds end. ===VALIDATION 1=== [LOG]LMSeqReader: opening file /home/slhome/txh18/workspace/nerv/nerv/nerv/examples/lmptb/PTBdata/ptb.valid.txt.adds... -batch_size: 10 chunk_size 15 -[SCHEDULER ITER1 LR1]: 40095 words processed Wed Nov 18 10:13:39 2015. - [SCHEDULER ITER1 LR1]: log prob per sample :-2.547314. - [global_conf.timer]: time spent on tnn_beforeprocess:0.46703 clock time - [global_conf.timer]: time spent on tnn_actual_layer_propagate:2.75630 clock time - [global_conf.timer]: time spent on most_out_loop_lmprocessfile:3.44636 clock time - [global_conf.timer]: time spent on tnn_afterprocess:0.11481 clock time +[LOG]LMSeqReader: batch_size: 10 chunk_size 15 +[LOG]LMSeqReader: se_mode: false +(15:32:21 2015-12-23)[nerv] info: TNN initing storage selectL1->recurrentL1 +(15:32:21 2015-12-23)[nerv] info: TNN initing storage recurrentL1->sigmoidL1 +(15:32:21 2015-12-23)[nerv] info: TNN initing storage sigmoidL1->combinerL1 +(15:32:21 2015-12-23)[nerv] info: TNN initing storage combinerL1->recurrentL1 +(15:32:21 2015-12-23)[nerv] info: TNN initing storage combinerL1->outputL +(15:32:21 2015-12-23)[nerv] info: TNN initing storage outputL->softmaxL +(15:32:22 2015-12-23)[nerv] info: LMTrainer.lm_process_file_rnn: begin processing... +[SCHEDULER ITER1 LR1]: 40095 words processed Wed Dec 23 15:32:30 2015. + [SCHEDULER ITER1 LR1]: log prob per sample :-2.537461. + [global_conf.timer]: time spent on tnn_beforeprocess:0.52284 clock time + [global_conf.timer]: time spent on tnn_actual_layer_propagate:6.48628 clock time + [global_conf.timer]: time spent on most_out_loop_lmprocessfile:7.30197 clock time + [global_conf.timer]: time spent on tnn_afterprocess:0.15646 clock time [LOG]LMSeqReader: file expires, closing. +(15:32:37 2015-12-23)[nerv] info: lmseqreader file ends, printing stats... +al_sen_start:false [SCHEDULER ITER1 LR1]: Displaying result: -[SCHEDULER ITER1 LR1]: LMResult status of rnn: +[SCHEDULER ITER1 LR1]: LMResult status of rnn: [SCHEDULER ITER1 LR1]: Doing on /home/slhome/txh18/workspace/nerv/nerv/nerv/examples/lmptb/PTBdata/ptb.valid.txt.adds end. -[SCHEDULER ITER1 LR1]: PPL improves, saving net to file /home/slhome/txh18/workspace/nerv/play/dagL_test/params.1... +[SCHEDULER ITER1 LR1]: PPL improves, saving net to file /home/slhome/txh18/workspace/ptb/EXP-nerv/rnnlm_tnnh300ch15ba10slr1wc1e-06/params.1... [SCHEDULER ITER2 LR1]: preparing parameters... -[SCHEDULER ITER2 LR1]: loading parameter from file /home/slhome/txh18/workspace/nerv/play/dagL_test/params.1... +[SCHEDULER ITER2 LR1]: loading parameter from file /home/slhome/txh18/workspace/ptb/EXP-nerv/rnnlm_tnnh300ch15ba10slr1wc1e-06/params.1... reading chunk 0 from 0 -metadata: return {type="nerv.LinearTransParam",id="ltp_hh"} +metadata: return {type="nerv.BiasParam",id="recurrentL1_bp"} -reading chunk 1 from 1076633 -metadata: return {type="nerv.BiasParam",id="bp_h"} +reading chunk 1 from 3667 +metadata: return {type="nerv.BiasParam",id="outputL_bp"} -reading chunk 2 from 1080289 -metadata: return {type="nerv.LinearTransParam",id="ltp_ho"} +reading chunk 2 from 120000 +metadata: return {type="nerv.LinearTransParam",id="recurrentL1_ltp_hh"} -reading chunk 3 from 35608824 -metadata: return {type="nerv.BiasParam",id="bp_o"} +reading chunk 3 from 1196590 +metadata: return {type="nerv.LinearTransParam",id="outputL_ltp"} -reading chunk 4 from 35725140 -metadata: return {type="nerv.LinearTransParam",id="ltp_ih"} +reading chunk 4 from 35732588 +metadata: return {type="nerv.LinearTransParam",id="selectL1_ltp"} -reading chunk 5 from 70244205 +reading chunk 5 from 70253773 [SCHEDULER ITER2 LR1]: preparing parameters end. [SCHEDULER ITER2 LR1]: preparing layers... -(10:13:48 2015-11-18)[nerv] info: create layer: recurrentL1 -(10:13:48 2015-11-18)[nerv] info: create layer: sigmoidL1 -(10:13:48 2015-11-18)[nerv] info: create layer: combinerL1 -(10:13:48 2015-11-18)[nerv] info: create layer: outputL -(10:13:48 2015-11-18)[nerv] info: create layer: softmaxL -(10:13:48 2015-11-18)[nerv] info: create layer: selectL1 +(15:32:42 2015-12-23)[nerv] info: create layer: sigmoidL1 +(15:32:42 2015-12-23)[nerv] info: create layer: combinerL1 +(15:32:42 2015-12-23)[nerv] info: create layer: selectL1 +(15:32:42 2015-12-23)[nerv] info: Param [ltp] of layer [selectL1] found in layer_conf.paramRepo. +(15:32:42 2015-12-23)[nerv] info: create layer: outputL +(15:32:42 2015-12-23)[nerv] info: Param [ltp] of layer [outputL] found in layer_conf.paramRepo. +(15:32:42 2015-12-23)[nerv] info: Param [bp] of layer [outputL] found in layer_conf.paramRepo. +(15:32:42 2015-12-23)[nerv] info: create layer: softmaxL +(15:32:42 2015-12-23)[nerv] info: create layer: recurrentL1 +(15:32:42 2015-12-23)[nerv] info: Param [bp] of layer [recurrentL1] found in layer_conf.paramRepo. +(15:32:42 2015-12-23)[nerv] info: Param [ltp_hh] of layer [recurrentL1] found in layer_conf.paramRepo. [SCHEDULER ITER2 LR1]: preparing layers end. [SCHEDULER ITER2 LR1]: Generate and initing TNN ... +(15:32:42 2015-12-23)[nerv] info: tnn(TNN) will extend storage beyond MB border for time steps 5... selectL1 0 selectL1 recurrentL1 0 recurrentL1 sigmoidL1 0 @@ -404,253 +451,289 @@ combinerL1 #dim_in: 1 #dim_out: 2 #i_conns_p: 1 #o_conns_p 2 sigmoidL1 #dim_in: 1 #dim_out: 1 #i_conns_p: 1 #o_conns_p 1 selectL1 #dim_in: 1 #dim_out: 1 #i_conns_p: 0 #o_conns_p 1 softmaxL #dim_in: 2 #dim_out: 1 #i_conns_p: 1 #o_conns_p 0 -TNN initing storage selectL1 -> recurrentL1 -TNN initing storage recurrentL1 -> sigmoidL1 -TNN initing storage sigmoidL1 -> combinerL1 -TNN initing storage combinerL1 -> recurrentL1 -TNN initing storage combinerL1 -> outputL -TNN initing storage outputL -> softmaxL +(15:32:42 2015-12-23)[nerv] info: TNN initing storage selectL1->recurrentL1 +(15:32:42 2015-12-23)[nerv] info: TNN initing storage recurrentL1->sigmoidL1 +(15:32:42 2015-12-23)[nerv] info: TNN initing storage sigmoidL1->combinerL1 +(15:32:42 2015-12-23)[nerv] info: TNN initing storage combinerL1->recurrentL1 +(15:32:42 2015-12-23)[nerv] info: TNN initing storage combinerL1->outputL +(15:32:42 2015-12-23)[nerv] info: TNN initing storage outputL->softmaxL [SCHEDULER ITER2 LR1]: Initing TNN end. ===ITERATION 2 LR 1.000000=== -[LOG]LMSeqReader: opening file /home/slhome/txh18/workspace/nerv/play/dagL_test/train_fn_shuf... -batch_size: 10 chunk_size 15 -[SCHEDULER ITER2 LR1]: 40092 words processed Wed Nov 18 10:13:59 2015. - [SCHEDULER ITER2 LR1]: log prob per sample :-2.541969. - [global_conf.timer]: time spent on tnn_beforeprocess:0.46836 clock time - [global_conf.timer]: time spent on tnn_actual_layer_propagate:2.72598 clock time - [global_conf.timer]: time spent on most_out_loop_lmprocessfile:10.22414 clock time - [global_conf.timer]: time spent on tnn_actual_layer_update:4.56508 clock time - [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.09968 clock time - [global_conf.timer]: time spent on tnn_afterprocess:0.11795 clock time -[SCHEDULER ITER2 LR1]: 80099 words processed Wed Nov 18 10:14:11 2015. - [SCHEDULER ITER2 LR1]: log prob per sample :-2.535649. - [global_conf.timer]: time spent on tnn_beforeprocess:0.46987 clock time - [global_conf.timer]: time spent on tnn_actual_layer_propagate:2.73527 clock time - [global_conf.timer]: time spent on most_out_loop_lmprocessfile:10.21641 clock time - [global_conf.timer]: time spent on tnn_actual_layer_update:4.55211 clock time - [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.09413 clock time - [global_conf.timer]: time spent on tnn_afterprocess:0.11941 clock time -[SCHEDULER ITER2 LR1]: 120004 words processed Wed Nov 18 10:14:23 2015. - [SCHEDULER ITER2 LR1]: log prob per sample :-2.527511. - [global_conf.timer]: time spent on tnn_beforeprocess:0.46606 clock time - [global_conf.timer]: time spent on tnn_actual_layer_propagate:2.72308 clock time - [global_conf.timer]: time spent on most_out_loop_lmprocessfile:10.19836 clock time - [global_conf.timer]: time spent on tnn_actual_layer_update:4.54952 clock time - [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.09336 clock time - [global_conf.timer]: time spent on tnn_afterprocess:0.11779 clock time -[SCHEDULER ITER2 LR1]: 160114 words processed Wed Nov 18 10:14:35 2015. - [SCHEDULER ITER2 LR1]: log prob per sample :-2.522344. - [global_conf.timer]: time spent on tnn_beforeprocess:0.46532 clock time - [global_conf.timer]: time spent on tnn_actual_layer_propagate:2.72510 clock time - [global_conf.timer]: time spent on most_out_loop_lmprocessfile:10.22327 clock time - [global_conf.timer]: time spent on tnn_actual_layer_update:4.56668 clock time - [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.10154 clock time - [global_conf.timer]: time spent on tnn_afterprocess:0.11830 clock time -[SCHEDULER ITER2 LR1]: 200066 words processed Wed Nov 18 10:14:46 2015. - [SCHEDULER ITER2 LR1]: log prob per sample :-2.517881. - [global_conf.timer]: time spent on tnn_beforeprocess:0.46174 clock time - [global_conf.timer]: time spent on tnn_actual_layer_propagate:2.71860 clock time - [global_conf.timer]: time spent on most_out_loop_lmprocessfile:10.18739 clock time - [global_conf.timer]: time spent on tnn_actual_layer_update:4.55076 clock time - [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.09280 clock time - [global_conf.timer]: time spent on tnn_afterprocess:0.11754 clock time -[SCHEDULER ITER2 LR1]: 240045 words processed Wed Nov 18 10:14:58 2015. - [SCHEDULER ITER2 LR1]: log prob per sample :-2.512076. - [global_conf.timer]: time spent on tnn_beforeprocess:0.46366 clock time - [global_conf.timer]: time spent on tnn_actual_layer_propagate:2.72754 clock time - [global_conf.timer]: time spent on most_out_loop_lmprocessfile:10.21275 clock time - [global_conf.timer]: time spent on tnn_actual_layer_update:4.55625 clock time - [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.09893 clock time - [global_conf.timer]: time spent on tnn_afterprocess:0.11910 clock time -[SCHEDULER ITER2 LR1]: 280057 words processed Wed Nov 18 10:15:10 2015. - [SCHEDULER ITER2 LR1]: log prob per sample :-2.507676. - [global_conf.timer]: time spent on tnn_beforeprocess:0.47597 clock time - [global_conf.timer]: time spent on tnn_actual_layer_propagate:2.79397 clock time - [global_conf.timer]: time spent on most_out_loop_lmprocessfile:10.37668 clock time - [global_conf.timer]: time spent on tnn_actual_layer_update:4.60190 clock time - [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.11988 clock time - [global_conf.timer]: time spent on tnn_afterprocess:0.12311 clock time -[SCHEDULER ITER2 LR1]: 320106 words processed Wed Nov 18 10:15:22 2015. - [SCHEDULER ITER2 LR1]: log prob per sample :-2.500944. - [global_conf.timer]: time spent on tnn_beforeprocess:0.46251 clock time - [global_conf.timer]: time spent on tnn_actual_layer_propagate:2.73117 clock time - [global_conf.timer]: time spent on most_out_loop_lmprocessfile:10.22486 clock time - [global_conf.timer]: time spent on tnn_actual_layer_update:4.56401 clock time - [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.10012 clock time - [global_conf.timer]: time spent on tnn_afterprocess:0.11863 clock time -[SCHEDULER ITER2 LR1]: 360024 words processed Wed Nov 18 10:15:34 2015. - [SCHEDULER ITER2 LR1]: log prob per sample :-2.497026. - [global_conf.timer]: time spent on tnn_beforeprocess:0.45968 clock time - [global_conf.timer]: time spent on tnn_actual_layer_propagate:2.73210 clock time - [global_conf.timer]: time spent on most_out_loop_lmprocessfile:10.20736 clock time - [global_conf.timer]: time spent on tnn_actual_layer_update:4.55524 clock time - [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.09260 clock time - [global_conf.timer]: time spent on tnn_afterprocess:0.11888 clock time -[SCHEDULER ITER2 LR1]: 400089 words processed Wed Nov 18 10:15:46 2015. - [SCHEDULER ITER2 LR1]: log prob per sample :-2.493683. - [global_conf.timer]: time spent on tnn_beforeprocess:0.46353 clock time - [global_conf.timer]: time spent on tnn_actual_layer_propagate:2.74623 clock time - [global_conf.timer]: time spent on most_out_loop_lmprocessfile:10.24888 clock time - [global_conf.timer]: time spent on tnn_actual_layer_update:4.56961 clock time - [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.10136 clock time - [global_conf.timer]: time spent on tnn_afterprocess:0.11942 clock time -[SCHEDULER ITER2 LR1]: 440067 words processed Wed Nov 18 10:15:58 2015. - [SCHEDULER ITER2 LR1]: log prob per sample :-2.490451. - [global_conf.timer]: time spent on tnn_beforeprocess:0.46117 clock time - [global_conf.timer]: time spent on tnn_actual_layer_propagate:2.73519 clock time - [global_conf.timer]: time spent on most_out_loop_lmprocessfile:10.21602 clock time - [global_conf.timer]: time spent on tnn_actual_layer_update:4.55836 clock time - [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.09430 clock time - [global_conf.timer]: time spent on tnn_afterprocess:0.11994 clock time -[SCHEDULER ITER2 LR1]: 480051 words processed Wed Nov 18 10:16:10 2015. - [SCHEDULER ITER2 LR1]: log prob per sample :-2.487587. - [global_conf.timer]: time spent on tnn_beforeprocess:0.45998 clock time - [global_conf.timer]: time spent on tnn_actual_layer_propagate:2.73365 clock time - [global_conf.timer]: time spent on most_out_loop_lmprocessfile:10.20277 clock time - [global_conf.timer]: time spent on tnn_actual_layer_update:4.55319 clock time - [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.09232 clock time - [global_conf.timer]: time spent on tnn_afterprocess:0.11882 clock time -[SCHEDULER ITER2 LR1]: 520140 words processed Wed Nov 18 10:16:22 2015. - [SCHEDULER ITER2 LR1]: log prob per sample :-2.484627. - [global_conf.timer]: time spent on tnn_beforeprocess:0.45975 clock time - [global_conf.timer]: time spent on tnn_actual_layer_propagate:2.72819 clock time - [global_conf.timer]: time spent on most_out_loop_lmprocessfile:10.21976 clock time - [global_conf.timer]: time spent on tnn_actual_layer_update:4.56564 clock time - [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.10028 clock time - [global_conf.timer]: time spent on tnn_afterprocess:0.11841 clock time -[SCHEDULER ITER2 LR1]: 560132 words processed Wed Nov 18 10:16:33 2015. - [SCHEDULER ITER2 LR1]: log prob per sample :-2.481780. - [global_conf.timer]: time spent on tnn_beforeprocess:0.45692 clock time - [global_conf.timer]: time spent on tnn_actual_layer_propagate:2.71231 clock time - [global_conf.timer]: time spent on most_out_loop_lmprocessfile:10.16816 clock time - [global_conf.timer]: time spent on tnn_actual_layer_update:4.54569 clock time - [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.09361 clock time - [global_conf.timer]: time spent on tnn_afterprocess:0.11724 clock time -[SCHEDULER ITER2 LR1]: 600118 words processed Wed Nov 18 10:16:45 2015. - [SCHEDULER ITER2 LR1]: log prob per sample :-2.479088. - [global_conf.timer]: time spent on tnn_beforeprocess:0.45915 clock time - [global_conf.timer]: time spent on tnn_actual_layer_propagate:2.73072 clock time - [global_conf.timer]: time spent on most_out_loop_lmprocessfile:10.18993 clock time - [global_conf.timer]: time spent on tnn_actual_layer_update:4.54640 clock time - [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.09120 clock time - [global_conf.timer]: time spent on tnn_afterprocess:0.11835 clock time -[SCHEDULER ITER2 LR1]: 640090 words processed Wed Nov 18 10:16:57 2015. - [SCHEDULER ITER2 LR1]: log prob per sample :-2.475904. - [global_conf.timer]: time spent on tnn_beforeprocess:0.45833 clock time - [global_conf.timer]: time spent on tnn_actual_layer_propagate:2.72455 clock time - [global_conf.timer]: time spent on most_out_loop_lmprocessfile:10.18397 clock time - [global_conf.timer]: time spent on tnn_actual_layer_update:4.54664 clock time - [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.09177 clock time - [global_conf.timer]: time spent on tnn_afterprocess:0.11810 clock time -[SCHEDULER ITER2 LR1]: 680075 words processed Wed Nov 18 10:17:09 2015. - [SCHEDULER ITER2 LR1]: log prob per sample :-2.474017. - [global_conf.timer]: time spent on tnn_beforeprocess:0.45720 clock time - [global_conf.timer]: time spent on tnn_actual_layer_propagate:2.71394 clock time - [global_conf.timer]: time spent on most_out_loop_lmprocessfile:10.16784 clock time - [global_conf.timer]: time spent on tnn_actual_layer_update:4.54518 clock time - [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.09097 clock time - [global_conf.timer]: time spent on tnn_afterprocess:0.11778 clock time -[SCHEDULER ITER2 LR1]: 720043 words processed Wed Nov 18 10:17:21 2015. - [SCHEDULER ITER2 LR1]: log prob per sample :-2.471783. - [global_conf.timer]: time spent on tnn_beforeprocess:0.45892 clock time - [global_conf.timer]: time spent on tnn_actual_layer_propagate:2.72588 clock time - [global_conf.timer]: time spent on most_out_loop_lmprocessfile:10.19146 clock time - [global_conf.timer]: time spent on tnn_actual_layer_update:4.55005 clock time - [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.09232 clock time - [global_conf.timer]: time spent on tnn_afterprocess:0.11806 clock time -[SCHEDULER ITER2 LR1]: 760012 words processed Wed Nov 18 10:17:33 2015. - [SCHEDULER ITER2 LR1]: log prob per sample :-2.469729. - [global_conf.timer]: time spent on tnn_beforeprocess:0.46006 clock time - [global_conf.timer]: time spent on tnn_actual_layer_propagate:2.73453 clock time - [global_conf.timer]: time spent on most_out_loop_lmprocessfile:10.21522 clock time - [global_conf.timer]: time spent on tnn_actual_layer_update:4.55667 clock time - [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.09724 clock time - [global_conf.timer]: time spent on tnn_afterprocess:0.11897 clock time -[SCHEDULER ITER2 LR1]: 800113 words processed Wed Nov 18 10:17:45 2015. - [SCHEDULER ITER2 LR1]: log prob per sample :-2.467617. - [global_conf.timer]: time spent on tnn_beforeprocess:0.46246 clock time - [global_conf.timer]: time spent on tnn_actual_layer_propagate:2.74674 clock time - [global_conf.timer]: time spent on most_out_loop_lmprocessfile:10.25543 clock time - [global_conf.timer]: time spent on tnn_actual_layer_update:4.57267 clock time - [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.10430 clock time - [global_conf.timer]: time spent on tnn_afterprocess:0.11946 clock time -[SCHEDULER ITER2 LR1]: 840089 words processed Wed Nov 18 10:17:57 2015. - [SCHEDULER ITER2 LR1]: log prob per sample :-2.465015. - [global_conf.timer]: time spent on tnn_beforeprocess:0.46102 clock time - [global_conf.timer]: time spent on tnn_actual_layer_propagate:2.74097 clock time - [global_conf.timer]: time spent on most_out_loop_lmprocessfile:10.21331 clock time - [global_conf.timer]: time spent on tnn_actual_layer_update:4.55202 clock time - [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.09360 clock time - [global_conf.timer]: time spent on tnn_afterprocess:0.11916 clock time -[SCHEDULER ITER2 LR1]: 880052 words processed Wed Nov 18 10:18:09 2015. - [SCHEDULER ITER2 LR1]: log prob per sample :-2.463152. - [global_conf.timer]: time spent on tnn_beforeprocess:0.46119 clock time - [global_conf.timer]: time spent on tnn_actual_layer_propagate:2.74489 clock time - [global_conf.timer]: time spent on most_out_loop_lmprocessfile:10.23141 clock time - [global_conf.timer]: time spent on tnn_actual_layer_update:4.55830 clock time - [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.09725 clock time - [global_conf.timer]: time spent on tnn_afterprocess:0.12007 clock time +[LOG]LMSeqReader: opening file /home/slhome/txh18/workspace/ptb/EXP-nerv/rnnlm_tnnh300ch15ba10slr1wc1e-06/train_fn_shuf... +[LOG]LMSeqReader: batch_size: 10 chunk_size 15 +[LOG]LMSeqReader: se_mode: false +(15:32:42 2015-12-23)[nerv] info: TNN initing storage selectL1->recurrentL1 +(15:32:42 2015-12-23)[nerv] info: TNN initing storage recurrentL1->sigmoidL1 +(15:32:42 2015-12-23)[nerv] info: TNN initing storage sigmoidL1->combinerL1 +(15:32:42 2015-12-23)[nerv] info: TNN initing storage combinerL1->recurrentL1 +(15:32:42 2015-12-23)[nerv] info: TNN initing storage combinerL1->outputL +(15:32:42 2015-12-23)[nerv] info: TNN initing storage outputL->softmaxL +(15:32:42 2015-12-23)[nerv] info: LMTrainer.lm_process_file_rnn: begin processing... +[SCHEDULER ITER2 LR1]: 40092 words processed Wed Dec 23 15:32:59 2015. + [SCHEDULER ITER2 LR1]: log prob per sample :-2.543962. + [global_conf.timer]: time spent on tnn_beforeprocess:0.51651 clock time + [global_conf.timer]: time spent on tnn_actual_layer_propagate:6.33365 clock time + [global_conf.timer]: time spent on most_out_loop_lmprocess