From 0acdf7bd21a1953d8e5ba07fb39a7187f049527f Mon Sep 17 00:00:00 2001 From: txh18 Date: Wed, 18 Nov 2015 13:04:26 +0800 Subject: h300 and h400 worked well, log added --- nerv/examples/lmptb/logs/LOG-tnn-h300 | 9372 ++++++++++++++++++++++++++++++ nerv/examples/lmptb/logs/LOG-tnn-h400 | 9372 ++++++++++++++++++++++++++++++ nerv/examples/lmptb/m-tests/LOG-tnn-h400 | 7688 ------------------------ 3 files changed, 18744 insertions(+), 7688 deletions(-) create mode 100644 nerv/examples/lmptb/logs/LOG-tnn-h300 create mode 100644 nerv/examples/lmptb/logs/LOG-tnn-h400 delete mode 100644 nerv/examples/lmptb/m-tests/LOG-tnn-h400 diff --git a/nerv/examples/lmptb/logs/LOG-tnn-h300 b/nerv/examples/lmptb/logs/LOG-tnn-h300 new file mode 100644 index 0000000..77fd612 --- /dev/null +++ b/nerv/examples/lmptb/logs/LOG-tnn-h300 @@ -0,0 +1,9372 @@ +Greetings +[SCHEDULER]: applying arg[2](global_conf.hidden_size=300)... +[SCHEDULER]: printing global_conf... +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 +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 +log_w_num 40000 +work_dir /home/slhome/txh18/workspace/nerv/play/dagL_test +batch_size 10 +hidden_size 300 +timer nerv.Timer +sche_log_pre [SCHEDULER]: +nn_act_default 0 +max_iter 35 +valid_fn /home/slhome/txh18/workspace/nerv/nerv/nerv/examples/lmptb/PTBdata/ptb.valid.txt.adds +lrate 1 +momentum 0 +wcost 1e-05 +chunk_size 15 +cumat_type table: 0x40935010 +[SCHEDULER]: printing training scheduling options... +lr_half false +start_iter -1 +ppl_last 100000 +[SCHEDULER]: printing training scheduling end. +[SCHEDULER]: creating work_dir... +[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... +===INITIAL VALIDATION=== +[SCHEDULER]: preparing parameters... +[SCHEDULER]: loading parameter from file /home/slhome/txh18/workspace/nerv/play/dagL_test/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 +[SCHEDULER]: preparing layers end. +[SCHEDULER]: Generate and initing TNN ... + selectL1 0 +selectL1 recurrentL1 0 +recurrentL1 sigmoidL1 0 +sigmoidL1 combinerL1 0 +combinerL1 recurrentL1 1 +combinerL1 outputL 0 +outputL softmaxL 0 + softmaxL 0 +softmaxL 0 +recurrentL1 #dim_in: 2 #dim_out: 1 #i_conns_p: 2 #o_conns_p 1 +outputL #dim_in: 1 #dim_out: 1 #i_conns_p: 1 #o_conns_p 1 +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 +[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: file expires, closing. +[SCHEDULER]: Displaying result: +[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... +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 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 +[SCHEDULER ITER1 LR1]: preparing layers end. +[SCHEDULER ITER1 LR1]: Generate and initing TNN ... + selectL1 0 +selectL1 recurrentL1 0 +recurrentL1 sigmoidL1 0 +sigmoidL1 combinerL1 0 +combinerL1 recurrentL1 1 +combinerL1 outputL 0 +outputL softmaxL 0 + softmaxL 0 +softmaxL 0 +recurrentL1 #dim_in: 2 #dim_out: 1 #i_conns_p: 2 #o_conns_p 1 +outputL #dim_in: 1 #dim_out: 1 #i_conns_p: 1 #o_conns_p 1 +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 +[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: file expires, closing. +[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]: 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: file expires, closing. +[SCHEDULER ITER1 LR1]: Displaying result: +[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: file expires, closing. +[SCHEDULER ITER1 LR1]: Displaying result: +[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 ITER2 LR1]: preparing parameters... +[SCHEDULER ITER2 LR1]: loading parameter from file /home/slhome/txh18/workspace/nerv/play/dagL_test/params.1... +reading chunk 0 from 0 +metadata: return {type="nerv.LinearTransParam",id="ltp_hh"} + +reading chunk 1 from 1076633 +metadata: return {type="nerv.BiasParam",id="bp_h"} + +reading chunk 2 from 1080289 +metadata: return {type="nerv.LinearTransParam",id="ltp_ho"} + +reading chunk 3 from 35608824 +metadata: return {type="nerv.BiasParam",id="bp_o"} + +reading chunk 4 from 35725140 +metadata: return {type="nerv.LinearTransParam",id="ltp_ih"} + +reading chunk 5 from 70244205 +[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 +[SCHEDULER ITER2 LR1]: preparing layers end. +[SCHEDULER ITER2 LR1]: Generate and initing TNN ... + selectL1 0 +selectL1 recurrentL1 0 +recurrentL1 sigmoidL1 0 +sigmoidL1 combinerL1 0 +combinerL1 recurrentL1 1 +combinerL1 outputL 0 +outputL softmaxL 0 + softmaxL 0 +softmaxL 0 +recurrentL1 #dim_in: 2 #dim_out: 1 #i_conns_p: 2 #o_conns_p 1 +outputL #dim_in: 1 #dim_out: 1 #i_conns_p: 1 #o_conns_p 1 +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 +[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: file expires, closing. +[SCHEDULER ITER2 LR1]: Displaying result: +[SCHEDULER ITER2 LR1]: LMResult status of rnn: +[SCHEDULER ITER2 LR1]: Doing on /home/slhome/txh18/workspace/nerv/play/dagL_test/train_fn_shuf end. +[SCHEDULER ITER2 LR1]: shuffling training file +===PEEK ON TEST 2=== +[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 ITER2 LR1]: 40087 words processed Wed Nov 18 10:18:18 2015. + [SCHEDULER ITER2 LR1]: log prob per sample :-2.380761. + [global_conf.timer]: time spent on tnn_beforeprocess:0.46919 clock time + [global_conf.timer]: time spent on tnn_actual_layer_propagate:2.74486 clock time + [global_conf.timer]: time spent on most_out_loop_lmprocessfile:3.43873 clock time + [global_conf.timer]: time spent on tnn_afterprocess:0.11428 clock time +[LOG]LMSeqReader: file expires, closing. +[SCHEDULER ITER2 LR1]: Displaying result: +[SCHEDULER ITER2 LR1]: LMResult status of rnn: +[SCHEDULER ITER2 LR1]: Doing on /home/slhome/txh18/workspace/nerv/nerv/nerv/examples/lmptb/PTBdata/ptb.test.txt.adds end. +===VALIDATION 2=== +[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 ITER2 LR1]: 40095 words processed Wed Nov 18 10:18:27 2015. + [SCHEDULER ITER2 LR1]: log prob per sample :-2.427169. + [global_conf.timer]: time spent on tnn_beforeprocess:0.46685 clock time + [global_conf.timer]: time spent on tnn_actual_layer_propagate:2.74609 clock time + [global_conf.timer]: time spent on most_out_loop_lmprocessfile:3.43747 clock time + [global_conf.timer]: time spent on tnn_afterprocess:0.11425 clock time +[LOG]LMSeqReader: file expires, closing. +[SCHEDULER ITER2 LR1]: Displaying result: +[SCHEDULER ITER2 LR1]: LMResult status of rnn: +[SCHEDULER ITER2 LR1]: Doing on /home/slhome/txh18/workspace/nerv/nerv/nerv/examples/lmptb/PTBdata/ptb.valid.txt.adds end. +[SCHEDULER ITER2 LR1]: PPL improves, saving net to file /home/slhome/txh18/workspace/nerv/play/dagL_test/params.2... + +[SCHEDULER ITER3 LR1]: preparing parameters... +[SCHEDULER ITER3 LR1]: loading parameter from file /home/slhome/txh18/workspace/nerv/play/dagL_test/params.2... +reading chunk 0 from 0 +metadata: return {type="nerv.LinearTransParam",id="ltp_ih"} + +reading chunk 1 from 34525805 +metadata: return {type="nerv.BiasParam",id="bp_h"} + +reading chunk 2 from 34529462 +metadata: return {type="nerv.LinearTransParam",id="ltp_ho"} + +reading chunk 3 from 69074656 +metadata: return {type="nerv.BiasParam",id="bp_o"} + +reading chunk 4 from 69190773 +metadata: return {type="nerv.LinearTransParam",id="ltp_hh"} + +reading chunk 5 from 70267310 +[SCHEDULER ITER3 LR1]: preparing parameters end. +[SCHEDULER ITER3 LR1]: preparing layers... +(10:18:36 2015-11-18)[nerv] info: create layer: recurrentL1 +(10:18:36 2015-11-18)[nerv] info: create layer: sigmoidL1 +(10:18:36 2015-11-18)[nerv] info: create layer: combinerL1 +(10:18:36 2015-11-18)[nerv] info: create layer: outputL +(10:18:36 2015-11-18)[nerv] info: create layer: softmaxL +(10:18:36 2015-11-18)[nerv] info: create layer: selectL1 +[SCHEDULER ITER3 LR1]: preparing layers end. +[SCHEDULER ITER3 LR1]: Generate and initing TNN ... + selectL1 0 +selectL1 recurrentL1 0 +recurrentL1 sigmoidL1 0 +sigmoidL1 combinerL1 0 +combinerL1 recurrentL1 1 +combinerL1 outputL 0 +outputL softmaxL 0 + softmaxL 0 +softmaxL 0 +recurrentL1 #dim_in: 2 #dim_out: 1 #i_conns_p: 2 #o_conns_p 1 +outputL #dim_in: 1 #dim_out: 1 #i_conns_p: 1 #o_conns_p 1 +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 +[SCHEDULER ITER3 LR1]: Initing TNN end. +===ITERATION 3 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 ITER3 LR1]: 40092 words processed Wed Nov 18 10:18:47 2015. + [SCHEDULER ITER3 LR1]: log prob per sample :-2.536047. + [global_conf.timer]: time spent on tnn_beforeprocess:0.46841 clock time + [global_conf.timer]: time spent on tnn_actual_layer_propagate:2.72824 clock time + [global_conf.timer]: time spent on most_out_loop_lmprocessfile:10.22868 clock time + [global_conf.timer]: time spent on tnn_actual_layer_update:4.56381 clock time + [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.10451 clock time + [global_conf.timer]: time spent on tnn_afterprocess:0.11928 clock time +[SCHEDULER ITER3 LR1]: 80099 words processed Wed Nov 18 10:18:58 2015. + [SCHEDULER ITER3 LR1]: log prob per sample :-2.483923. + [global_conf.timer]: time spent on tnn_beforeprocess:0.46813 clock time + [global_conf.timer]: time spent on tnn_actual_layer_propagate:2.71587 clock time + [global_conf.timer]: time spent on most_out_loop_lmprocessfile:10.19287 clock time + [global_conf.timer]: time spent on tnn_actual_layer_update:4.55022 clock time + [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.09750 clock time + [global_conf.timer]: time spent on tnn_afterprocess:0.11941 clock time +[SCHEDULER ITER3 LR1]: 120004 words processed Wed Nov 18 10:19:10 2015. + [SCHEDULER ITER3 LR1]: log prob per sample :-2.458421. + [global_conf.timer]: time spent on tnn_beforeprocess:0.46654 clock time + [global_conf.timer]: time spent on tnn_actual_layer_propagate:2.71644 clock time + [global_conf.timer]: time spent on most_out_loop_lmprocessfile:10.18811 clock time + [global_conf.timer]: time spent on tnn_actual_layer_update:4.54561 clock time + [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.09506 clock time + [global_conf.timer]: time spent on tnn_afterprocess:0.11902 clock time +[SCHEDULER ITER3 LR1]: 160114 words processed Wed Nov 18 10:19:22 2015. + [SCHEDULER ITER3 LR1]: log prob per sample :-2.448869. + [global_conf.timer]: time spent on tnn_beforeprocess:0.46564 clock time + [global_conf.timer]: time spent on tnn_actual_layer_propagate:2.72314 clock time + [global_conf.timer]: time spent on most_out_loop_lmprocessfile:10.21041 clock time + [global_conf.timer]: time spent on tnn_actual_layer_update:4.55762 clock time + [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.10313 clock time + [global_conf.timer]: time spent on tnn_afterprocess:0.11887 clock time +[SCHEDULER ITER3 LR1]: 200066 words processed Wed Nov 18 10:19:34 2015. + [SCHEDULER ITER3 LR1]: log prob per sample :-2.441952. + [global_conf.timer]: time spent on tnn_beforeprocess:0.46164 clock time + [global_conf.timer]: time spent on tnn_actual_layer_propagate:2.72174 clock time + [global_conf.timer]: time spent on most_out_loop_lmprocessfile:10.18569 clock time + [global_conf.timer]: time spent on tnn_actual_layer_update:4.54325 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.11905 clock time +[SCHEDULER ITER3 LR1]: 240045 words processed Wed Nov 18 10:19:46 2015. + [SCHEDULER ITER3 LR1]: log prob per sample :-2.432993. + [global_conf.timer]: time spent on tnn_beforeprocess:0.46397 clock time + [global_conf.timer]: time spent on tnn_actual_layer_propagate:2.72148 clock time + [global_conf.timer]: time spent on most_out_loop_lmprocessfile:10.19430 clock time + [global_conf.timer]: time spent on tnn_actual_layer_update:4.54829 clock time + [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.09770 clock time + [global_conf.timer]: time spent on tnn_afterprocess:0.11958 clock time +[SCHEDULER ITER3 LR1]: 280057 words processed Wed Nov 18 10:19:58 2015. + [SCHEDULER ITER3 LR1]: log prob per sample :-2.427091. + [global_conf.timer]: time spent on tnn_beforeprocess:0.46420 clock time + [global_conf.timer]: time spent on tnn_actual_layer_propagate:2.72248 clock time + [global_conf.timer]: time spent on most_out_loop_lmprocessfile:10.22334 clock time + [global_conf.timer]: time spent on tnn_actual_layer_update:4.56521 clock time + [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.10595 clock time + [global_conf.timer]: time spent on tnn_afterprocess:0.11918 clock time +[SCHEDULER ITER3 LR1]: 320106 words processed Wed Nov 18 10:20:10 2015. + [SCHEDULER ITER3 LR1]: log prob per sample :-2.420076. + [global_conf.timer]: time spent on tnn_beforeprocess:0.46241 clock time + [global_conf.timer]: time spent on tnn_actual_layer_propagate:2.73121 clock time + [global_conf.timer]: time spent on most_out_loop_lmprocessfile:10.23973 clock time + [global_conf.timer]: time spent on tnn_actual_layer_update:4.57037 clock time + [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.10789 clock time + [global_conf.timer]: time spent on tnn_afterprocess:0.11974 clock time +[SCHEDULER ITER3 LR1]: 360024 words processed Wed Nov 18 10:20:22 2015. + [SCHEDULER ITER3 LR1]: log prob per sample :-2.416144. + [global_conf.timer]: time spent on tnn_beforeprocess:0.46100 clock time + [global_conf.timer]: time spent on tnn_actual_layer_propagate:2.72642 clock time + [global_conf.timer]: time spent on most_out_loop_lmprocessfile:10.20227 clock time + [global_conf.timer]: time spent on tnn_actual_layer_update:4.55015 clock time + [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.09891 clock time + [global_conf.timer]: time spent on tnn_afterprocess:0.11940 clock time +[SCHEDULER ITER3 LR1]: 400089 words processed Wed Nov 18 10:20:34 2015. + [SCHEDULER ITER3 LR1]: log prob per sample :-2.412820. + [global_conf.timer]: time spent on tnn_beforeprocess:0.46143 clock time + [global_conf.timer]: time spent on tnn_actual_layer_propagate:2.73168 clock time + [global_conf.timer]: time spent on most_out_loop_lmprocessfile:10.23198 clock time + [global_conf.timer]: time spent on tnn_actual_layer_update:4.56644 clock time + [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.10677 clock time + [global_conf.timer]: time spent on tnn_afterprocess:0.12013 clock time +[SCHEDULER ITER3 LR1]: 440067 words processed Wed Nov 18 10:20:46 2015. + [SCHEDULER ITER3 LR1]: log prob per sample :-2.410263. + [global_conf.timer]: time spent on tnn_beforeprocess:0.46165 clock time + [global_conf.timer]: time spent on tnn_actual_layer_propagate:2.72661 clock time + [global_conf.timer]: time spent on most_out_loop_lmprocessfile:10.19516 clock time + [global_conf.timer]: time spent on tnn_actual_layer_update:4.54854 clock time + [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.09580 clock time + [global_conf.timer]: time spent on tnn_afterprocess:0.11913 clock time +[SCHEDULER ITER3 LR1]: 480051 words processed Wed Nov 18 10:20:58 2015. + [SCHEDULER ITER3 LR1]: log prob per sample :-2.407979. + [global_conf.timer]: time spent on tnn_beforeprocess:0.46140 clock time + [global_conf.timer]: time spent on tnn_actual_layer_propagate:2.72909 clock time + [global_conf.timer]: time spent on most_out_loop_lmprocessfile:10.20697 clock time + [global_conf.timer]: time spent on tnn_actual_layer_update:4.55568 clock time + [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.09783 clock time + [global_conf.timer]: time spent on tnn_afterprocess:0.11971 clock time +[SCHEDULER ITER3 LR1]: 520140 words processed Wed Nov 18 10:21:10 2015. + [SCHEDULER ITER3 LR1]: log prob per sample :-2.405734. + [global_conf.timer]: time spent on tnn_beforeprocess:0.46027 clock time + [global_conf.timer]: time spent on tnn_actual_layer_propagate:2.72708 clock time + [global_conf.timer]: time spent on most_out_loop_lmprocessfile:10.22339 clock time + [global_conf.timer]: time spent on tnn_actual_layer_update:4.56616 clock time + [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.10415 clock time + [global_conf.timer]: time spent on tnn_afterprocess:0.11944 clock time +[SCHEDULER ITER3 LR1]: 560132 words processed Wed Nov 18 10:21:22 2015. + [SCHEDULER ITER3 LR1]: log prob per sample :-2.403532. + [global_conf.timer]: time spent on tnn_beforeprocess:0.45910 clock time + [global_conf.timer]: time spent on tnn_actual_layer_propagate:2.71769 clock time + [global_conf.timer]: time spent on most_out_loop_lmprocessfile:10.18242 clock time + [global_conf.timer]: time spent on tnn_actual_layer_update:4.54602 clock time + [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.09924 clock time + [global_conf.timer]: time spent on tnn_afterprocess:0.11878 clock time +[SCHEDULER ITER3 LR1]: 600118 words processed Wed Nov 18 10:21:33 2015. + [SCHEDULER ITER3 LR1]: log prob per sample :-2.401175. + [global_conf.timer]: time spent on tnn_beforeprocess:0.45834 clock time + [global_conf.timer]: time spent on tnn_actual_layer_propagate:2.71657 clock time + [global_conf.timer]: time spent on most_out_loop_lmprocessfile:10.17742 clock time + [global_conf.timer]: time spent on tnn_actual_layer_update:4.54693 clock time + [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.09537 clock time + [global_conf.timer]: time spent on tnn_afterprocess:0.11830 clock time +[SCHEDULER ITER3 LR1]: 640090 words processed Wed Nov 18 10:21:45 2015. + [SCHEDULER ITER3 LR1]: log prob per sample :-2.398582. + [global_conf.timer]: time spent on tnn_beforeprocess:0.45838 clock time + [global_conf.timer]: time spent on tnn_actual_layer_propagate:2.71715 clock time + [global_conf.timer]: time spent on most_out_loop_lmprocessfile:10.17104 clock time + [global_conf.timer]: time spent on tnn_actual_layer_update:4.54186 clock time + [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.09427 clock time + [global_conf.timer]: time spent on tnn_afterprocess:0.11879 clock time +[SCHEDULER ITER3 LR1]: 680075 words processed Wed Nov 18 10:21:57 2015. + [SCHEDULER ITER3 LR1]: log prob per sample :-2.397244. + [global_conf.timer]: time spent on tnn_beforeprocess:0.46118 clock time + [global_conf.timer]: time spent on tnn_actual_layer_propagate:2.73236 clock time + [global_conf.timer]: time spent on most_out_loop_lmprocessfile:10.21270 clock time + [global_conf.timer]: time spent on tnn_actual_layer_update:4.55627 clock time + [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.09701 clock time + [global_conf.timer]: time spent on tnn_afterprocess:0.12054 clock time +[SCHEDULER ITER3 LR1]: 720043 words processed Wed Nov 18 10:22:09 2015. + [SCHEDULER ITER3 LR1]: log prob per sample :-2.396091. + [global_conf.timer]: time spent on tnn_beforeprocess:0.46029 clock time + [global_conf.timer]: time spent on tnn_actual_layer_propagate:2.72831 clock time + [global_conf.timer]: time spent on most_out_loop_lmprocessfile:10.20086 clock time + [global_conf.timer]: time spent on tnn_actual_layer_update:4.55243 clock time + [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.09483 clock time + [global_conf.timer]: time spent on tnn_afterprocess:0.11977 clock time +[SCHEDULER ITER3 LR1]: 760012 words processed Wed Nov 18 10:22:21 2015. + [SCHEDULER ITER3 LR1]: log prob per sample :-2.394789. + [global_conf.timer]: time spent on tnn_beforeprocess:0.46249 clock time + [global_conf.timer]: time spent on tnn_actual_layer_propagate:2.72900 clock time + [global_conf.timer]: time spent on most_out_loop_lmprocessfile:10.20841 clock time + [global_conf.timer]: time spent on tnn_actual_layer_update:4.55161 clock time + [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.10074 clock time + [global_conf.timer]: time spent on tnn_afterprocess:0.11922 clock time +[SCHEDULER ITER3 LR1]: 800113 words processed Wed Nov 18 10:22:33 2015. + [SCHEDULER ITER3 LR1]: log prob per sample :-2.393428. + [global_conf.timer]: time spent on tnn_beforeprocess:0.45947 clock time + [global_conf.timer]: time spent on tnn_actual_layer_propagate:2.72019 clock time + [global_conf.timer]: time spent on most_out_loop_lmprocessfile:10.20872 clock time + [global_conf.timer]: time spent on tnn_actual_layer_update:4.56109 clock time + [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.10514 clock time + [global_conf.timer]: time spent on tnn_afterprocess:0.11855 clock time +[SCHEDULER ITER3 LR1]: 840089 words processed Wed Nov 18 10:22:45 2015. + [SCHEDULER ITER3 LR1]: log prob per sample :-2.391343. + [global_conf.timer]: time spent on tnn_beforeprocess:0.45778 clock time + [global_conf.timer]: time spent on tnn_actual_layer_propagate:2.71939 clock time + [global_conf.timer]: time spent on most_out_loop_lmprocessfile:10.17808 clock time + [global_conf.timer]: time spent on tnn_actual_layer_update:4.54550 clock time + [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.09538 clock time + [global_conf.timer]: time spent on tnn_afterprocess:0.11851 clock time +[SCHEDULER ITER3 LR1]: 880052 words processed Wed Nov 18 10:22:57 2015. + [SCHEDULER ITER3 LR1]: log prob per sample :-2.389966. + [global_conf.timer]: time spent on tnn_beforeprocess:0.45967 clock time + [global_conf.timer]: time spent on tnn_actual_layer_propagate:2.72022 clock time + [global_conf.timer]: time spent on most_out_loop_lmprocessfile:10.18124 clock time + [global_conf.timer]: time spent on tnn_actual_layer_update:4.54495 clock time + [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.09355 clock time + [global_conf.timer]: time spent on tnn_afterprocess:0.11946 clock time +[LOG]LMSeqReader: file expires, closing. +[SCHEDULER ITER3 LR1]: Displaying result: +[SCHEDULER ITER3 LR1]: LMResult status of rnn: +[SCHEDULER ITER3 LR1]: Doing on /home/slhome/txh18/workspace/nerv/play/dagL_test/train_fn_shuf end. +[SCHEDULER ITER3 LR1]: shuffling training file +===PEEK ON TEST 3=== +[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 ITER3 LR1]: 40087 words processed Wed Nov 18 10:23:06 2015. + [SCHEDULER ITER3 LR1]: log prob per sample :-2.338319. + [global_conf.timer]: time spent on tnn_beforeprocess:0.46632 clock time + [global_conf.timer]: time spent on tnn_actual_layer_propagate:2.73173 clock time + [global_conf.timer]: time spent on most_out_loop_lmprocessfile:3.42069 clock time + [global_conf.timer]: time spent on tnn_afterprocess:0.11427 clock time +[LOG]LMSeqReader: file expires, closing. +[SCHEDULER ITER3 LR1]: Displaying result: +[SCHEDULER ITER3 LR1]: LMResult status of rnn: +[SCHEDULER ITER3 LR1]: Doing on /home/slhome/txh18/workspace/nerv/nerv/nerv/examples/lmptb/PTBdata/ptb.test.txt.adds end. +===VALIDATION 3=== +[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 ITER3 LR1]: 40095 words processed Wed Nov 18 10:23:15 2015. + [SCHEDULER ITER3 LR1]: log prob per sample :-2.387513. + [global_conf.timer]: time spent on tnn_beforeprocess:0.46562 clock time + [global_conf.timer]: time spent on tnn_actual_layer_propagate:2.73144 clock time + [global_conf.timer]: time spent on most_out_loop_lmprocessfile:3.41963 clock time + [global_conf.timer]: time spent on tnn_afterprocess:0.11445 clock time +[LOG]LMSeqReader: file expires, closing. +[SCHEDULER ITER3 LR1]: Displaying result: +[SCHEDULER ITER3 LR1]: LMResult status of rnn: +[SCHEDULER ITER3 LR1]: Doing on /home/slhome/txh18/workspace/nerv/nerv/nerv/examples/lmptb/PTBdata/ptb.valid.txt.adds end. +[SCHEDULER ITER3 LR1]: PPL improves, saving net to file /home/slhome/txh18/workspace/nerv/play/dagL_test/params.3... + +[SCHEDULER ITER4 LR1]: preparing parameters... +[SCHEDULER ITER4 LR1]: loading parameter from file /home/slhome/txh18/workspace/nerv/play/dagL_test/params.3... +reading chunk 0 from 0 +metadata: return {type="nerv.LinearTransParam",id="ltp_hh"} + +reading chunk 1 from 1076112 +metadata: return {type="nerv.BiasParam",id="bp_h"} + +reading chunk 2 from 1079769 +metadata: return {type="nerv.LinearTransParam",id="ltp_ho"} + +reading chunk 3 from 35639160 +metadata: return {type="nerv.BiasParam",id="bp_o"} + +reading chunk 4 from 35755265 +metadata: return {type="nerv.LinearTransParam",id="ltp_ih"} + +reading chunk 5 from 70285481 +[SCHEDULER ITER4 LR1]: preparing parameters end. +[SCHEDULER ITER4 LR1]: preparing layers... +(10:23:24 2015-11-18)[nerv] info: create layer: recurrentL1 +(10:23:24 2015-11-18)[nerv] info: create layer: sigmoidL1 +(10:23:24 2015-11-18)[nerv] info: create layer: combinerL1 +(10:23:24 2015-11-18)[nerv] info: create layer: outputL +(10:23:24 2015-11-18)[nerv] info: create layer: softmaxL +(10:23:24 2015-11-18)[nerv] info: create layer: selectL1 +[SCHEDULER ITER4 LR1]: preparing layers end. +[SCHEDULER ITER4 LR1]: Generate and initing TNN ... + selectL1 0 +selectL1 recurrentL1 0 +recurrentL1 sigmoidL1 0 +sigmoidL1 combinerL1 0 +combinerL1 recurrentL1 1 +combinerL1 outputL 0 +outputL softmaxL 0 + softmaxL 0 +softmaxL 0 +recurrentL1 #dim_in: 2 #dim_out: 1 #i_conns_p: 2 #o_conns_p 1 +outputL #dim_in: 1 #dim_out: 1 #i_conns_p: 1 #o_conns_p 1 +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 +[SCHEDULER ITER4 LR1]: Initing TNN end. +===ITERATION 4 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 ITER4 LR1]: 40092 words processed Wed Nov 18 10:23:35 2015. + [SCHEDULER ITER4 LR1]: log prob per sample :-2.356761. + [global_conf.timer]: time spent on tnn_beforeprocess:0.47160 clock time + [global_conf.timer]: time spent on tnn_actual_layer_propagate:2.75773 clock time + [global_conf.timer]: time spent on most_out_loop_lmprocessfile:10.29264 clock time + [global_conf.timer]: time spent on tnn_actual_layer_update:4.58409 clock time + [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.10959 clock time + [global_conf.timer]: time spent on tnn_afterprocess:0.11998 clock time +[SCHEDULER ITER4 LR1]: 80099 words processed Wed Nov 18 10:23:47 2015. + [SCHEDULER ITER4 LR1]: log prob per sample :-2.354343. + [global_conf.timer]: time spent on tnn_beforeprocess:0.46970 clock time + [global_conf.timer]: time spent on tnn_actual_layer_propagate:2.73607 clock time + [global_conf.timer]: time spent on most_out_loop_lmprocessfile:10.21454 clock time + [global_conf.timer]: time spent on tnn_actual_layer_update:4.55435 clock time + [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.09187 clock time + [global_conf.timer]: time spent on tnn_afterprocess:0.11917 clock time +[SCHEDULER ITER4 LR1]: 120004 words processed Wed Nov 18 10:23:59 2015. + [SCHEDULER ITER4 LR1]: log prob per sample :-2.348934. + [global_conf.timer]: time spent on tnn_beforeprocess:0.46688 clock time + [global_conf.timer]: time spent on tnn_actual_layer_propagate:2.73326 clock time + [global_conf.timer]: time spent on most_out_loop_lmprocessfile:10.21025 clock time + [global_conf.timer]: time spent on tnn_actual_layer_update:4.55149 clock time + [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.09277 clock time + [global_conf.timer]: time spent on tnn_afterprocess:0.11852 clock time +[SCHEDULER ITER4 LR1]: 160114 words processed Wed Nov 18 10:24:11 2015. + [SCHEDULER ITER4 LR1]: log prob per sample :-2.350011. + [global_conf.timer]: time spent on tnn_beforeprocess:0.47103 clock time + [global_conf.timer]: time spent on tnn_actual_layer_propagate:2.76141 clock time + [global_conf.timer]: time spent on most_out_loop_lmprocessfile:10.29215 clock time + [global_conf.timer]: time spent on tnn_actual_layer_update:4.58396 clock time + [global_conf.timer]: time spent on tnn_actual_layer_backpropagate:2.10589 clock time + [global_conf.timer]: time spent on tnn_afterprocess:0.12027 clock time +[SCHEDULER ITER4 LR1]: 200066 words processed Wed Nov 18 10:24:23 2015. + [SCHEDULER ITER4 LR1]: log prob per sample :-2.350221. + [global_conf.timer]: time spent on tnn_beforeprocess:0.46486 clock time + [global_conf.timer]: time spent on tnn_actual_layer_propagate:2.74205 clock time + [global_conf.timer]: time spent on most_out_loop_lmprocessfile:10.22571 clock time + [global_conf.ti