2024-08-19 16:38:46,743 INFO [train_multi_KD3.py:1188] (3/4) Training started
2024-08-19 16:38:46,743 INFO [train_multi_KD3.py:1198] (3/4) Device: cuda:3
2024-08-19 16:38:46,743 INFO [train_multi_KD3.py:1213] (3/4) Using dtype=torch.bfloat16
2024-08-19 16:38:46,743 INFO [train_multi_KD3.py:1215] (3/4) {'best_train_loss': inf, 'best_valid_loss': inf, 'best_train_epoch': -1, 'best_valid_epoch': -1, 'batch_idx_train': 0, 'log_interval': 50, 'reset_interval': 200, 'valid_interval': 3000, 'feature_dim': 80, 'subsampling_factor': 4, 'warm_step': 2000, 'env_info': {'k2-version': '1.24.3', 'k2-build-type': 'Release', 'k2-with-cuda': True, 'k2-git-sha1': 'e400fa3b456faf8afe0ee5bfe572946b4921a3db', 'k2-git-date': 'Sat Jul 15 04:21:50 2023', 'lhotse-version': '1.16.0', 'torch-version': '2.0.1+cu117', 'torch-cuda-available': True, 'torch-cuda-version': '11.7', 'python-version': '3.9', 'icefall-git-branch': 'multi_KD_with_wenet', 'icefall-git-sha1': '3210a8ed-dirty', 'icefall-git-date': 'Mon Aug 19 16:16:48 2024', 'icefall-path': '/xy/mnt/yangxiaoyu/workspace/icefall_multi_KD', 'k2-path': '/root/anaconda3/lib/python3.9/site-packages/k2/__init__.py', 'lhotse-path': '/root/anaconda3/lib/python3.9/site-packages/lhotse/__init__.py', 'hostname': 'NGK_xiaoyu'}, 'world_size': 4, 'master_port': 13440, 'tensorboard': True, 'num_epochs': 35, 'start_epoch': 31, 'start_batch': 0, 'exp_dir': PosixPath('multi_KD/exp_causal1_delta6KD_LS1_5fold+wenetspech0_0fold+as_unbalanced1+vox_1_vox2_base_lr_0.045_use_beats_1_scale_1.0_use_ecapa_1_layer_2_scale_10.0_1_scale_1.0_specaug0_musan0_with_task_ID_stop_early1_share_asr1_md1500_amp_bf16'), 'bpe_model': 'data/lang_bpe_500/bpe.model', 'base_lr': 0.045, 'lr_batches': 7500, 'lr_epochs': 3.5, 'ref_duration': 600, 'seed': 42, 'print_diagnostics': False, 'inf_check': False, 'save_every_n': 4000, 'keep_last_k': 30, 'average_period': 200, 'stop_early': True, 'use_fp16': False, 'use_bf16': True, 'share_asr': True, 'beats_loss_scale': 1.0, 'ecapa_loss_scale': 10.0, 'whisper_loss_scale': 1.0, 'whisper_cb_loss_scale': 0.01, 'repeat_librispeech': 5, 'repeat_wenetspeech': 0, 'num_encoder_layers': '2,2,3,4,3,2', 'downsampling_factor': '1,2,4,8,4,2', 'feedforward_dim': '512,768,1024,1536,1024,768', 'num_heads': '4,4,4,8,4,4', 'encoder_dim': '192,256,384,512,384,256', 'query_head_dim': '32', 'value_head_dim': '12', 'pos_head_dim': '4', 'pos_dim': 48, 'encoder_unmasked_dim': '192,192,256,256,256,192', 'cnn_module_kernel': '31,31,15,15,15,31', 'decoder_dim': 512, 'joiner_dim': 512, 'causal': True, 'chunk_size': '16,32,64,-1', 'left_context_frames': '64,128,256,-1', 'use_transducer': True, 'use_ctc': False, 'speaker_input_idx': 2, 'whisper_dim': 1280, 'use_task_id': True, 'num_codebooks': 32, 'mvq_kd_layer_idx': -1, 'use_subsampled_output': True, 'delta_t': 6, 'full_libri': True, 'mini_libri': False, 'use_libriheavy': False, 'libriheavy_subset': 'small', 'use_librispeech': True, 'use_wenetspeech': False, 'use_audioset': True, 'audioset_subset': 'unbalanced', 'use_voxceleb': True, 'voxceleb_subset': 'vox2', 'use_fma': False, 'fma_subset': 'large', 'manifest_dir': PosixPath('data/fbank_LSVoxAs_with_whisper_large-v3_with_taskID'), 'max_duration': 1500, 'bucketing_sampler': False, 'num_buckets': 30, 'concatenate_cuts': False, 'duration_factor': 1.0, 'gap': 1.0, 'on_the_fly_feats': False, 'shuffle': True, 'drop_last': True, 'return_cuts': True, 'num_workers': 1, 'enable_spec_aug': False, 'spec_aug_time_warp_factor': 80, 'enable_musan': False, 'enable_audioset': False, 'use_musan_separately': False, 'input_strategy': 'PrecomputedFeatures', 'drop_features': False, 'return_audio': False, 'use_beats': True, 'use_ecapa': True, 'use_whisper': True, 'whisper_mvq': False, 'beats_ckpt': 'data/models/BEATs/BEATs_iter3_plus_AS2M_finetuned_on_AS2M_cpt2.pt', 'whisper_version': 'large-v3', 'use_mert': False, 'dtype': torch.bfloat16, 'use_amp': True}
2024-08-19 16:38:46,744 INFO [train_multi_KD3.py:1217] (3/4) About to create model
2024-08-19 16:38:47,107 INFO [model_shift.py:142] (3/4) Delta_t: 6 when computing the distillation loss
2024-08-19 16:38:47,116 INFO [train_multi_KD3.py:1221] (3/4) Number of model parameters: 66484678
2024-08-19 16:38:47,116 INFO [checkpoint.py:112] (3/4) Loading checkpoint from multi_KD/exp_causal1_delta6KD_LS1_5fold+wenetspech0_0fold+as_unbalanced1+vox_1_vox2_base_lr_0.045_use_beats_1_scale_1.0_use_ecapa_1_layer_2_scale_10.0_1_scale_1.0_specaug0_musan0_with_task_ID_stop_early1_share_asr1_md1500_amp_bf16/epoch-30.pt
2024-08-19 16:38:53,466 INFO [train_multi_KD3.py:1236] (3/4) Using DDP
2024-08-19 16:38:54,621 INFO [train_multi_KD3.py:1248] (3/4) Loading optimizer state dict
2024-08-19 16:38:54,903 INFO [train_multi_KD3.py:1256] (3/4) Loading scheduler state dict
2024-08-19 16:38:54,903 INFO [kd_datamodule.py:690] (3/4) About to get train 960 cuts
2024-08-19 16:38:54,948 INFO [kd_datamodule.py:862] (3/4) About to get the voxceleb cuts.
2024-08-19 16:38:54,949 INFO [kd_datamodule.py:873] (3/4) Adding voxceleb2 cuts.
2024-08-19 16:38:54,950 INFO [train_multi_KD3.py:1319] (3/4) Getting audioset cuts
2024-08-19 16:38:54,951 INFO [kd_datamodule.py:881] (3/4) About to get the audioset cuts for KD.
2024-08-19 16:38:54,953 INFO [train_multi_KD3.py:1325] (3/4) Using mux to combine Librispeech: True, WenetSpeech: False, audioset: True and voxceleb: True
2024-08-19 16:39:02,989 INFO [train_multi_KD3.py:1327] (3/4) Using mux to combine [CutSet(len=1406195) [underlying data type: <class 'lhotse.lazy.LazyMapper'>], CutSet(len=1187704) [underlying data type: <class 'lhotse.lazy.LazyMapper'>], CutSet(len=1904746) [underlying data type: <class 'lhotse.lazy.LazyMapper'>]]
2024-08-19 16:39:02,989 INFO [train_multi_KD3.py:1328] (3/4) Using weights: [1406195, 1187704, 1904746]
2024-08-19 16:39:02,990 INFO [train_multi_KD3.py:1337] (3/4) CutSet(len=4498645) [underlying data type: <class 'lhotse.lazy.LazyIteratorMultiplexer'>]
2024-08-19 16:39:02,990 INFO [kd_datamodule.py:449] (3/4) Disable MUSAN
2024-08-19 16:39:02,990 INFO [kd_datamodule.py:489] (3/4) Disable SpecAugment
2024-08-19 16:39:02,990 INFO [kd_datamodule.py:491] (3/4) About to create train dataset
2024-08-19 16:39:02,990 INFO [kd_datamodule.py:528] (3/4) Using SimpleCutSampler
2024-08-19 16:39:02,990 INFO [kd_datamodule.py:536] (3/4) About to create train dataloader
2024-08-19 16:39:02,991 INFO [kd_datamodule.py:756] (3/4) About to get dev-clean cuts
2024-08-19 16:39:02,992 INFO [kd_datamodule.py:774] (3/4) About to get dev-other cuts
2024-08-19 16:39:02,994 INFO [kd_datamodule.py:570] (3/4) About to create dev dataset
2024-08-19 16:39:03,280 INFO [kd_datamodule.py:591] (3/4) About to create dev dataloader
2024-08-19 16:39:03,280 INFO [kd_datamodule.py:833] (3/4) About to get the test set of voxceleb1 set.
2024-08-19 16:39:03,281 INFO [kd_datamodule.py:570] (3/4) About to create dev dataset
2024-08-19 16:39:03,518 INFO [kd_datamodule.py:591] (3/4) About to create dev dataloader
2024-08-19 16:39:03,518 INFO [kd_datamodule.py:893] (3/4) About to get the audioset eval cuts.
2024-08-19 16:39:03,519 INFO [kd_datamodule.py:570] (3/4) About to create dev dataset
2024-08-19 16:39:04,036 INFO [kd_datamodule.py:591] (3/4) About to create dev dataloader
2024-08-19 16:39:04,036 INFO [train_multi_KD3.py:1417] (3/4) ['ASR_libri', 'SV_voxceleb1', 'AT_audioset']
2024-08-19 16:39:04,036 INFO [train_multi_KD3.py:1421] (3/4) Loading grad scaler state dict