jive-vlbi / jive5ab

The JIVE VLBI data recording and transport utility
9 stars 5 forks source link

Error: Failed to stop processing chain #34

Closed vlbi-jun-yang closed 9 months ago

vlbi-jun-yang commented 9 months ago

At Onsala, we have just installed the new version of JIVE5ab to support multi-core recording. In our first run, we did a recording test with the default (single-core) setup. However, we noticed an error (Failed to stop processing chain ...) in running record=off after record=on. See the extracted log at the bottom. We also tried to send record=off again. Interestingly, the error was gone in the 2nd run.

202335516:12:26 2023-12-21 15:12:26.56: Reply: !record=  1 ;
202335516:12:26 2023-12-21 15:12:26.56: Processing command 'evlbi?'
202335516:12:26 2023-12-21 15:12:26.56: Reply: !evlbi? 0 : total : 1789817 : loss : 0 ( 0.00%) : out-of-order : 0 ( 0.00%) : extent : 0seqnr/pkt ;
202335516:12:35 2023-12-21 15:12:35.97: Processing command 'mode?'
202335516:12:35 2023-12-21 15:12:35.97: Reply: !mode? 0 : VDIF_8000-16384-32-2 : VDIF : 64 : 256000000.000 : 8000 ;
202335516:16:25 2023-12-21 15:16:25.48: Processing command 'rtime?'
202335516:16:25 2023-12-21 15:16:25.48: Reply: !rtime? 0 : 256433s : 527275GB : 93.4969% : VDIF : 64 : 0MHz : 16449.5Mbps ;
202335516:16:25 2023-12-21 15:16:25.49: Processing command 'mode?'
202335516:16:25 2023-12-21 15:16:25.49: Reply: !mode? 0 : VDIF_8000-16384-32-2 : VDIF : 64 : 256000000.000 : 8000 ;
202335516:16:55 2023-12-21 15:16:55.51: Processing command 'record=on:junyang_on_no0001'
202335516:16:55 2023-12-21 15:16:55.52: net2vbs/recording: suffixes_on_ports=0 (n_non_empty_suffixes=0) datastreams_defined=1
202335516:16:55 2023-12-21 15:16:55.52: Reply: !record=  0  ;
202335516:16:55 2023-12-21 15:16:55.52: multifdreader_stream[140534005884480]: starting
202335516:16:55 2023-12-21 15:16:55.52: getsok: req. server socket@udpsnor:32631
202335516:16:55 2023-12-21 15:16:55.52: netparms: rotate 1 elements
202335516:16:55 2023-12-21 15:16:55.52: multifdreader_stream[140534005884480]: fd=7 streamID=0
202335516:16:55 2023-12-21 15:16:55.52: udpsnorreader_stream: fd=7 data:8032 total:8040 pkts:31872 avbs: 1
202335516:16:55 2023-12-21 15:16:55.52: per_sender_type[10.100.0.40:46227] - first sequencenr# 486676423408
202335516:16:55 2023-12-21 15:16:55.52: handle_seqnr[10.100.0.40:46227] - switch to ACK every 10th packet
202335516:16:55 2023-12-21 15:16:55.52: per_sender_type[10.100.0.41:46227] - first sequencenr# 486673607466
202335516:16:55 2023-12-21 15:16:55.52: handle_seqnr[10.100.0.41:46227] - switch to ACK every 10th packet
202335516:16:56 2023-12-21 15:16:56.49: Processing command 'evlbi?'
202335516:16:56 2023-12-21 15:16:56.49: Reply: !evlbi? 0 : total : 238569 : loss : 0 ( 0.00%) : out-of-order : 0 ( 0.00%) : extent : 0seqnr/pkt ;
202335516:17:01 2023-12-21 15:17:01.51: Processing command 'record=off'
202335516:17:01 2023-12-21 15:17:01.51: Reply: !record=  4 : Failed to stop processing chain: /usr/local/src/jive5ab.git-multi-reader_2023-08-27/src/chain.h@1104 assertion [isptr->udtype==ct.argumenttype()] fails communicate: type mismatch for step 0: expect=P13multifdrdargs got=P12fdreaderargs ;
202335516:17:02 2023-12-21 15:17:02.51: Processing command 'record=off'
202335516:17:02 2023-12-21 15:17:02.51: close_filedescriptor: closed fd#7
202335516:17:02 2023-12-21 15:17:02.51: udpsnorreader_stream: failed to push 20080000 bytes for stream 0 (lost)
202335516:17:02 2023-12-21 15:17:02.51: udpsnorreader_stream: failed to push 20256704 bytes for stream 1 (lost)
202335516:17:02 2023-12-21 15:17:02.51: udpsnorreader_stream: done
202335516:17:02 2023-12-21 15:17:02.51: multifdreader_stream[140534005884480]: terminating
202335516:17:02 2023-12-21 15:17:02.63: net2vbs guard function: transfer done
202335516:17:02 2023-12-21 15:17:02.73: Reply: !record=  1 ;
202335516:17:02 2023-12-21 15:17:02.73: Processing command 'evlbi?'
202335516:17:02 2023-12-21 15:17:02.73: Reply: !evlbi? 0 : total : 1789854 : loss : 0 ( 0.00%) : out-of-order : 0 ( 0.00%) : extent : 0seqnr/pkt ;
202335516:17:13 2023-12-21 15:17:13.52: Processing command 'mode?'
202335516:17:13 2023-12-21 15:17:13.52: Reply: !mode? 0 : VDIF_8000-16384-32-2 : VDIF : 64 : 256000000.000 : 8000 ;
202335517:01:49 2023-12-21 16:01:49.75: Processing command 'version?'
202335517:01:49 2023-12-21 16:01:49.75: Reply: !version?  0 :  jive5ab : 3.1.0-dev : 64bit : Debug : koll : 21-Dec-2023 : 16h08m44s : nossapi : /usr/local/src/etransfer ;
202335517:03:35 2023-12-21 16:03:35.36: Processing command 'net_port?'
202335517:03:35 2023-12-21 16:03:35.36: Reply: !net_port? 0 : 32631 ;
haavee commented 9 months ago

Hi JY/SC, thanks for reporting this! I've pushed a commit that I believe should address (if not fix!) the issue 🤞 Given the date + time I'm not going to make any suggestion as when you could test this, happy holidays!

vlbi-jun-yang commented 9 months ago

Thanks.

vlbi-jun-yang commented 9 months ago

This morning, I did three recording tests with the new version of JIVE5ab. The error is gone. Thanks for the upgrade.

haavee commented 9 months ago

Thanks for letting me know - and glad that it was easy to fix. I'm closing this issue for now.