Locked 2.2.0-rc1 rigctld-wsjtx -- Hamlib error with IC-7300


Karza <kari.sillanmaki@...>
 

Hi,

I have a problem with 'rigctld-wsjtx' using wsjt-x 2.2.0-rc1
compiled from sources on Ubuntu 18.04.4 LTS.

Radio is an ICOM IC-7300. 

Rigctld is started with command "./rigctld-wsjtx -m 3073 -r /dev/ttyyUSB0 -s 19200"

I'm getting error "Hamlib error: Feature not available while getting current VFO".

In configuration "Test CAT" goes to green for a few seconds and but then
issues the same error again.

CI-V Transceive is set to OFF in Rig menu.

Here is a trace:

~/ham/wsjtx/wsjtx_2.2.0-rc1/bin$  ./rigctld-wsjtx -m 3073 -r /dev/ttyyUSB0 -s 19200 -vvvvv
main: #1 vfo_mode=0
Recommend using --vfo switch for rigctld if client supports it
rigctl and netrigctl will automatically detect vfo mode
rigctld, Hamlib 4.0~git
Report bugs to <hamlib-developer@...>

rig_init called
initrigs4_icom: _init called
rig_register called
rig_register: rig_register (3055)
rig_register called
rig_register: rig_register (3009)
rig_register called
rig_register: rig_register (3010)
rig_register called
rig_register: rig_register (3011)
rig_register called
rig_register: rig_register (3013)
rig_register called
rig_register: rig_register (3014)
rig_register called
rig_register: rig_register (3015)
rig_register called
rig_register: rig_register (3019)
rig_register called
rig_register: rig_register (3020)
rig_register called
rig_register: rig_register (3021)
rig_register called
rig_register: rig_register (3022)
rig_register called
rig_register: rig_register (3067)
rig_register called
rig_register: rig_register (3023)
rig_register called
rig_register: rig_register (3046)
rig_register called
rig_register: rig_register (3024)
rig_register called
rig_register: rig_register (3028)
rig_register called
rig_register: rig_register (3030)
rig_register called
rig_register: rig_register (3026)
rig_register called
rig_register: rig_register (3027)
rig_register called
rig_register: rig_register (3047)
rig_register called
rig_register: rig_register (3057)
rig_register called
rig_register: rig_register (3063)
rig_register called
rig_register: rig_register (3029)
rig_register called
rig_register: rig_register (3062)
rig_register called
rig_register: rig_register (3045)
rig_register called
rig_register: rig_register (3056)
rig_register called
rig_register: rig_register (3075)
rig_register called
rig_register: rig_register (3060)
rig_register called
rig_register: rig_register (3070)
rig_register called
rig_register: rig_register (3061)
rig_register called
rig_register: rig_register (3073)
rig_register called
rig_register: rig_register (3078)
rig_register called
rig_register: rig_register (3031)
rig_register called
rig_register: rig_register (3012)
rig_register called
rig_register: rig_register (3016)
rig_register called
rig_register: rig_register (3032)
rig_register called
rig_register: rig_register (3034)
rig_register called
rig_register: rig_register (3044)
rig_register called
rig_register: rig_register (3068)
rig_register called
rig_register: rig_register (3035)
rig_register called
rig_register: rig_register (3081)
rig_register called
rig_register: rig_register (3069)
rig_register called
rig_register: rig_register (3077)
rig_register called
rig_register: rig_register (3036)
rig_register called
rig_register: rig_register (3058)
rig_register called
rig_register: rig_register (3080)
rig_register called
rig_register: rig_register (3037)
rig_register called
rig_register: rig_register (3038)
rig_register called
rig_register: rig_register (3039)
rig_register called
rig_register: rig_register (3040)
rig_register called
rig_register: rig_register (3041)
rig_register called
rig_register: rig_register (3042)
rig_register called
rig_register: rig_register (3079)
rig_register called
rig_register: rig_register (3043)
rig_register called
rig_register: rig_register (3066)
rig_register called
rig_register: rig_register (3003)
rig_register called
rig_register: rig_register (3004)
rig_register called
rig_register: rig_register (3006)
rig_register called
rig_register: rig_register (3007)
rig_register called
rig_register: rig_register (3002)
rig_register called
rig_register: rig_register (3052)
rig_register called
rig_register: rig_register (3053)
rig_register called
rig_register: rig_register (3051)
rig_register called
rig_register: rig_register (3064)
rig_register called
rig_register: rig_register (3065)
rig_register called
rig_register: rig_register (3054)
rig_register called
rig_register: rig_register (3083)
rig_register called
rig_register: rig_register (3084)
rig_register called
rig_register: rig_register (3082)
rig_register called
rig_register: rig_register (3071)
rig_register called
rig_register: rig_register (3072)
rig_register called
rig_register: rig_register (3074)
rig_register called
rig_register: rig_register (3076)
icom_init called
icom_init: done
rig_open called
port_open called
serial_open called
serial_open: OPEN before
serial_open: OPEN after
serial_open: serial_setup before
serial_setup called
serial_setup: tcgetattr
serial_setup: cfmakeraw
serial_setup: cfsetispeed
serial_setup: cfsetospeed
serial_setup: tcsetattr TCSANOW
serial_open: serial_setup after
serial_open: serial_flush before
serial_flush called
serial_flush: tcflush
serial_open: serial_flush before
icom_rig_open 733 
icom_rig_open: IC-7300 v20200505.0
icom_get_usb_echo_off called
icom_get_usb_echo_off: retry temp set to 1
serial_flush called
serial_flush: tcflush
write_block called
write_block(): TX 6 bytes
0000    fe fe 94 e0 03 fd                                   ......          
read_string called
read_string(): RX 6 characters
0000    fe fe 94 e0 03 fd                                   ......          
read_string called
read_string(): RX 11 characters
0000    fe fe e0 94 03 00 70 35 05 00 fd                    ......p5...     
icom_get_usb_echo_off: USB echo on detected
icom_rig_open: satmode=0
rig_get_vfo called
rig_set_parm called
rig_has_set_parm called
Opened rig model 3073, 'IC-7300'
Backend version: 20200505.0, Status: Stable
Connection opened from localhost:49670
sync_callback: client lock engaged
sync_callback: client lock disengaged
handle_socket: vfo_mode=0
rigctl_parse: called, interactive=1
rigctl_parse: cmd=\(5c)
rigctl_parse: debug1
rigctl_parse: debug5
rigctl_parse: debug10
sync_callback: client lock engaged
rigctl(d): ð 'currVFO' '' '' ''
rigctl_parse: vfo_mode=0
rigctl_parse: retcode=0
sync_callback: client lock disengaged
handle_socket: vfo_mode=0
rigctl_parse: called, interactive=1
rigctl_parse: cmd=\(5c)
rigctl_parse: debug1
rigctl_parse: debug5
rigctl_parse: debug10
sync_callback: client lock engaged
rigctl(d):  'currVFO' '' '' ''
rigctl_parse: vfo_mode=0
rigctl_parse: retcode=0
sync_callback: client lock disengaged
handle_socket: vfo_mode=0
rigctl_parse: called, interactive=1
rigctl_parse: cmd=v(76)
rigctl_parse: debug1
rigctl_parse: debug5
rigctl_parse: debug10
sync_callback: client lock engaged
rigctl(d): v 'currVFO' '' '' ''
rigctl_parse: vfo_mode=0
rig_get_vfo called
rigctl_parse: return#1 RPRT -11
rigctl_parse: retcode=-11
sync_callback: client lock disengaged
handle_socket: rigctl_parse retcode=-11
handle_socket: vfo_mode=0
rigctl_parse: called, interactive=1
rigctl_parse: cmd= (0a)
rigctl_parse: cmd=m(6d)
rigctl_parse: debug1
rigctl_parse: debug5
rigctl_parse: debug10
sync_callback: client lock engaged
rigctl(d): m 'currVFO' '' '' ''
rigctl_parse: vfo_mode=0
rig_get_mode called
elapsed_ms: start = 0,0
rig_get_mode: cache check age=1000000ms
rig_get_mode: cache miss age=1000000ms
icom_get_mode_with_data called
icom_get_mode called vfo=currVFO
serial_flush called
serial_flush: tcflush
write_block called
write_block(): TX 6 bytes
0000    fe fe 94 e0 04 fd                                   ......          
read_string called
read_string(): RX 6 characters
0000    fe fe 94 e0 04 fd                                   ......          
read_string called
read_string(): RX 8 characters
0000    fe fe e0 94 04 01 01 fd                             ........        
icom_get_mode: modebuf[0]=0x04, modebuf[1]=0x01, mode_len=3
icom2rig_mode: mode=0x01, pd=1
rig_passband_wide called
icom_get_dsp_flt called
serial_flush called
serial_flush: tcflush
write_block called
write_block(): TX 7 bytes
0000    fe fe 94 e0 1a 03 fd                                .......         
read_string called
read_string(): RX 7 characters
0000    fe fe 94 e0 1a 03 fd                                .......         
read_string called
read_string(): RX 8 characters
0000    fe fe e0 94 1a 03 40 fd                             ......@.        
from_bcd called
icom_get_mode: vfo=currVFO returning mode=USB, width=3600
serial_flush called
serial_flush: tcflush
write_block called
write_block(): TX 7 bytes
0000    fe fe 94 e0 1a 06 fd                                .......         
read_string called
read_string(): RX 7 characters
0000    fe fe 94 e0 1a 06 fd                                .......         
read_string called
read_string(): RX 9 characters
0000    fe fe e0 94 1a 06 01 01 fd                          .........       
elapsed_ms: start = 0,0
elapsed_ms: after gettime, start = 1589304664,859462412
rigctl_parse: retcode=0
sync_callback: client lock disengaged
handle_socket: vfo_mode=0
rigctl_parse: called, interactive=1
rigctl_parse: cmd= (0a)
rigctl_parse: cmd=f(66)
rigctl_parse: debug1
rigctl_parse: debug5
rigctl_parse: debug10
sync_callback: client lock engaged
rigctl(d): f 'currVFO' '' '' ''
rigctl_parse: vfo_mode=0
rig_get_freq called vfo=currVFO
elapsed_ms: start = 0,0
rig_get_freq: cache check age=1000000ms
rig_get_freq: cache miss age=1000000ms, cached_vfo=None, asked_vfo=currVFO
icom_get_freq called for currVFO
set_vfo_curr: vfo=currVFO, curr_vfo=None
set_vfo_curr: Asking for currVFO,  currVFO=None
set_vfo_curr: curr_vfo now=None
icom_get_freq: VFO_RX requested, vfo=currVFO
icom_get_freq: using vfo=VFOA
rig_set_vfo called
icom_set_vfo called vfo=VFOA
icom_set_vfo: VFO changing from None to VFOA
serial_flush called
serial_flush: tcflush
write_block called
write_block(): TX 7 bytes
0000    fe fe 94 e0 07 00 fd                                .......         
read_string called
read_string(): RX 7 characters
0000    fe fe 94 e0 07 00 fd                                .......         
read_string called
read_string(): RX 6 characters
0000    fe fe e0 94 fb fd                                   ......          
rig_get_freq called vfo=VFOA
elapsed_ms: start = 1589304664,859856058
elapsed_ms: elapsed_secs=18.0995
rig_get_freq: cache check age=18ms
rig_get_freq: cache miss age=18ms, cached_vfo=None, asked_vfo=VFOA
icom_get_freq called for VFOA
set_vfo_curr: vfo=VFOA, curr_vfo=VFOA
set_vfo_curr: curr_vfo now=VFOA
icom_get_freq: using vfo=VFOA
serial_flush called
serial_flush: tcflush
write_block called
write_block(): TX 6 bytes
0000    fe fe 94 e0 03 fd                                   ......          
read_string called
read_string(): RX 6 characters
0000    fe fe 94 e0 03 fd                                   ......          
read_string called
read_string(): RX 11 characters
0000    fe fe e0 94 03 00 70 35 05 00 fd                    ......p5...     
from_bcd called
elapsed_ms: start = 0,0
elapsed_ms: after gettime, start = 1589304664,898549121
rig_get_freq: cache reset age=999000ms, vfo=VFOA, freq=5.357e+06
elapsed_ms: start = 0,0
elapsed_ms: elapsed_secs=6.87823e+21
elapsed_ms: start = 1589304664,898549121
elapsed_ms: elapsed_secs=6.87823e+21
elapsed_ms: start = 1589304664,859462412
elapsed_ms: elapsed_secs=6.87823e+21
rig_set_vfo: return 0, vfo=VFOA
serial_flush called
serial_flush: tcflush
write_block called
write_block(): TX 6 bytes
0000    fe fe 94 e0 03 fd                                   ......          
read_string called
read_string(): RX 6 characters
0000    fe fe 94 e0 03 fd                                   ......          
read_string called
read_string(): RX 11 characters
0000    fe fe e0 94 03 00 70 35 05 00 fd                    ......p5...     
from_bcd called
elapsed_ms: start = 0,0
elapsed_ms: after gettime, start = 1589304664,918522663
rig_get_freq: cache reset age=999000ms, vfo=currVFO, freq=5.357e+06
rigctl_parse: retcode=0
sync_callback: client lock disengaged
handle_socket: vfo_mode=0
rigctl_parse: called, interactive=1
rigctl_parse: cmd= (0a)
rigctl_parse: cmd=F(46)
rigctl_parse: debug1
rigctl_parse: debug3
rigctl_parse: debug4
rigctl_parse: debug5
rigctl_parse: debug10
sync_callback: client lock engaged
rigctl(d): F 'currVFO' '5357055.000000' '' ''
rigctl_parse: vfo_mode=0
rig_set_freq called
icom_set_freq called currVFO=5357055.000000
icom_set_freq: currVFO asked for so vfo set to VFOA
icom_set_freq: set_vfo_curr=VFOA
set_vfo_curr: vfo=VFOA, curr_vfo=VFOA
set_vfo_curr: curr_vfo now=VFOA
icom_get_freq called for currVFO
set_vfo_curr: vfo=currVFO, curr_vfo=VFOA
set_vfo_curr: Asking for currVFO,  currVFO=VFOA
set_vfo_curr: curr_vfo now=VFOA
icom_get_freq: VFO_RX requested, vfo=currVFO
icom_get_freq: using vfo=VFOA
serial_flush called
serial_flush: tcflush
write_block called
write_block(): TX 6 bytes
0000    fe fe 94 e0 03 fd                                   ......          
read_string called
read_string(): RX 6 characters
0000    fe fe 94 e0 03 fd                                   ......          
read_string called
read_string(): RX 11 characters
0000    fe fe e0 94 03 00 70 35 05 00 fd                    ......p5...     
from_bcd called
to_bcd called
serial_flush called
serial_flush: tcflush
write_block called
write_block(): TX 11 bytes
0000    fe fe 94 e0 05 55 70 35 05 00 fd                    .....Up5...     
read_string called
read_string(): RX 11 characters
0000    fe fe 94 e0 05 55 70 35 05 00 fd                    .....Up5...     
read_string called
read_string(): RX 6 characters
0000    fe fe e0 94 fb fd                                   ......          
elapsed_ms: start = 0,0
elapsed_ms: after gettime, start = 1589304664,958549897
rigctl_parse: return#2 RPRT 0
rigctl_parse: retcode=0
sync_callback: client lock disengaged
handle_socket: vfo_mode=0
rigctl_parse: called, interactive=1
rigctl_parse: cmd= (0a)
rigctl_parse: cmd=F(46)
rigctl_parse: debug1
rigctl_parse: debug3
rigctl_parse: debug4
rigctl_parse: debug5
rigctl_parse: debug10
sync_callback: client lock engaged
rigctl(d): F 'currVFO' '5357000.000000' '' ''
rigctl_parse: vfo_mode=0
rig_set_freq called
icom_set_freq called currVFO=5357000.000000
icom_set_freq: currVFO asked for so vfo set to VFOA
icom_set_freq: set_vfo_curr=VFOA
set_vfo_curr: vfo=VFOA, curr_vfo=VFOA
set_vfo_curr: curr_vfo now=VFOA
icom_get_freq called for currVFO
set_vfo_curr: vfo=currVFO, curr_vfo=VFOA
set_vfo_curr: Asking for currVFO,  currVFO=VFOA
set_vfo_curr: curr_vfo now=VFOA
icom_get_freq: VFO_RX requested, vfo=currVFO
icom_get_freq: using vfo=VFOA
serial_flush called
serial_flush: tcflush
write_block called
write_block(): TX 6 bytes
0000    fe fe 94 e0 03 fd                                   ......          
read_string called
read_string(): RX 6 characters
0000    fe fe 94 e0 03 fd                                   ......          
read_string called
read_string(): RX 11 characters
0000    fe fe e0 94 03 55 70 35 05 00 fd                    .....Up5...     
from_bcd called
to_bcd called
serial_flush called
serial_flush: tcflush
write_block called
write_block(): TX 11 bytes
0000    fe fe 94 e0 05 00 70 35 05 00 fd                    ......p5...     
read_string called
read_string(): RX 11 characters
0000    fe fe 94 e0 05 00 70 35 05 00 fd                    ......p5...     
read_string called
read_string(): RX 6 characters
0000    fe fe e0 94 fb fd                                   ......          
elapsed_ms: start = 0,0
elapsed_ms: after gettime, start = 1589304664,997928130
rigctl_parse: return#2 RPRT 0
rigctl_parse: retcode=0
sync_callback: client lock disengaged
handle_socket: vfo_mode=0
rigctl_parse: called, interactive=1
rigctl_parse: cmd= (0a)
rigctl_parse: cmd=s(73)
rigctl_parse: debug1
rigctl_parse: debug5
rigctl_parse: debug10
sync_callback: client lock engaged
rigctl(d): s 'currVFO' '' '' ''
rigctl_parse: vfo_mode=0
rig_get_split_vfo called
elapsed_ms: start = 0,0
rig_get_split_vfo: cache check age=1000000ms
rig_get_split_vfo: cache miss age=1000000ms
icom_get_split_vfo called
serial_flush called
serial_flush: tcflush
write_block called
write_block(): TX 6 bytes
0000    fe fe 94 e0 0f fd                                   ......          
read_string called
read_string(): RX 6 characters
0000    fe fe 94 e0 0f fd                                   ......          
read_string called
read_string(): RX 7 characters
0000    fe fe e0 94 0f 00 fd                                .......         
icom_get_split_vfos called
icom_get_split_vfos: VFO_HAS_A_B_ONLY, rx=VFOA, tx=VFOB
icom_get_split_vfo: vfo=currVFO rx_vfo=VFOA tx_vfo=VFOB split=0
elapsed_ms: start = 0,0
elapsed_ms: after gettime, start = 1589304665,16501822
rigctl_parse: retcode=0
sync_callback: client lock disengaged
handle_socket: vfo_mode=0
rigctl_parse: called, interactive=1
rigctl_parse: cmd= (0a)
rigctl_parse: cmd=v(76)
rigctl_parse: debug1
rigctl_parse: debug5
rigctl_parse: debug10
sync_callback: client lock engaged
rigctl(d): v 'currVFO' '' '' ''
rigctl_parse: vfo_mode=0
rig_get_vfo called
rigctl_parse: return#1 RPRT -11
rigctl_parse: retcode=-11
sync_callback: client lock disengaged
handle_socket: rigctl_parse retcode=-11
handle_socket: vfo_mode=0
rigctl_parse: called, interactive=1
rigctl_parse: cmd= (0a)
rigctl_parse: cmd=T(54)
rigctl_parse: debug1
rigctl_parse: debug3
rigctl_parse: debug4
rigctl_parse: debug5
rigctl_parse: debug10
sync_callback: client lock engaged
rigctl(d): T 'currVFO' '0' '' ''
rigctl_parse: vfo_mode=0
rig_set_ptt called
icom_set_ptt called
serial_flush called
serial_flush: tcflush
write_block called
write_block(): TX 8 bytes
0000    fe fe 94 e0 1c 00 00 fd                             ........        
read_string called
read_string(): RX 8 characters
0000    fe fe 94 e0 1c 00 00 fd                             ........        
read_string called
read_string(): RX 6 characters
0000    fe fe e0 94 fb fd                                   ......          
elapsed_ms: start = 0,0
elapsed_ms: after gettime, start = 1589304665,574198441
rigctl_parse: return#2 RPRT 0
rigctl_parse: retcode=0
sync_callback: client lock disengaged
handle_socket: vfo_mode=0
rigctl_parse: called, interactive=1
rigctl_parse: cmd= (0a)
rigctl_parse: cmd=q(71)
rigctl_parse: quit returning NETRIGCTL_RET 0
handle_socket: rigctl_parse retcode=1
Connection closed from localhost:49670
Connection opened from localhost:49672
sync_callback: client lock engaged
sync_callback: client lock disengaged
handle_socket: vfo_mode=0
rigctl_parse: called, interactive=1
rigctl_parse: cmd=\(5c)
rigctl_parse: debug1
rigctl_parse: debug5
rigctl_parse: debug10
sync_callback: client lock engaged
rigctl(d): ð 'currVFO' '' '' ''
rigctl_parse: vfo_mode=0
rigctl_parse: retcode=0
sync_callback: client lock disengaged
handle_socket: vfo_mode=0
rigctl_parse: called, interactive=1
rigctl_parse: cmd=\(5c)
rigctl_parse: debug1
rigctl_parse: debug5
rigctl_parse: debug10
sync_callback: client lock engaged
rigctl(d):  'currVFO' '' '' ''
rigctl_parse: vfo_mode=0
rigctl_parse: retcode=0
sync_callback: client lock disengaged
handle_socket: vfo_mode=0
rigctl_parse: called, interactive=1
rigctl_parse: cmd=v(76)
rigctl_parse: debug1
rigctl_parse: debug5
rigctl_parse: debug10
sync_callback: client lock engaged
rigctl(d): v 'currVFO' '' '' ''
rigctl_parse: vfo_mode=0
rig_get_vfo called
rigctl_parse: return#1 RPRT -11
rigctl_parse: retcode=-11
sync_callback: client lock disengaged
handle_socket: rigctl_parse retcode=-11
handle_socket: vfo_mode=0
rigctl_parse: called, interactive=1
rigctl_parse: cmd= (0a)
rigctl_parse: cmd=m(6d)
rigctl_parse: debug1
rigctl_parse: debug5
rigctl_parse: debug10
sync_callback: client lock engaged
rigctl(d): m 'currVFO' '' '' ''
rigctl_parse: vfo_mode=0
rig_get_mode called
elapsed_ms: start = 1557768664,859462412
elapsed_ms: elapsed_secs=3.1536e+10
rig_get_mode: cache check age=-2147483648ms
rig_get_mode: cache hit age=-2147483648ms
rigctl_parse: retcode=0
sync_callback: client lock disengaged
handle_socket: vfo_mode=0
rigctl_parse: called, interactive=1
rigctl_parse: cmd= (0a)
rigctl_parse: cmd=f(66)
rigctl_parse: debug1
rigctl_parse: debug5
rigctl_parse: debug10
sync_callback: client lock engaged
rigctl(d): f 'currVFO' '' '' ''
rigctl_parse: vfo_mode=0
rig_get_freq called vfo=currVFO
elapsed_ms: start = 1589304664,918522663
elapsed_ms: elapsed_secs=960.737
rig_get_freq: cache check age=960ms
rig_get_freq: cache miss age=960ms, cached_vfo=currVFO, asked_vfo=currVFO
icom_get_freq called for currVFO
set_vfo_curr: vfo=currVFO, curr_vfo=VFOA
set_vfo_curr: Asking for currVFO,  currVFO=VFOA
set_vfo_curr: curr_vfo now=VFOA
icom_get_freq: VFO_RX requested, vfo=currVFO
icom_get_freq: using vfo=VFOA
serial_flush called
serial_flush: tcflush
write_block called
write_block(): TX 6 bytes
0000    fe fe 94 e0 03 fd                                   ......          
read_string called
read_string(): RX 6 characters
0000    fe fe 94 e0 03 fd                                   ......          
read_string called
read_string(): RX 11 characters
0000    fe fe e0 94 03 00 70 35 05 00 fd                    ......p5...     
from_bcd called
elapsed_ms: start = 0,0
elapsed_ms: after gettime, start = 1589304665,899036010
rig_get_freq: cache reset age=999000ms, vfo=currVFO, freq=5.357e+06
rigctl_parse: retcode=0
sync_callback: client lock disengaged
handle_socket: vfo_mode=0
rigctl_parse: called, interactive=1
rigctl_parse: cmd= (0a)
rigctl_parse: cmd=F(46)
rigctl_parse: debug1
rigctl_parse: debug3
rigctl_parse: debug4
rigctl_parse: debug5
rigctl_parse: debug10
sync_callback: client lock engaged
rigctl(d): F 'currVFO' '5357055.000000' '' ''
rigctl_parse: vfo_mode=0
rig_set_freq called
icom_set_freq called currVFO=5357055.000000
icom_set_freq: currVFO asked for so vfo set to VFOA
icom_set_freq: set_vfo_curr=VFOA
set_vfo_curr: vfo=VFOA, curr_vfo=VFOA
set_vfo_curr: curr_vfo now=VFOA
icom_get_freq called for currVFO
set_vfo_curr: vfo=currVFO, curr_vfo=VFOA
set_vfo_curr: Asking for currVFO,  currVFO=VFOA
set_vfo_curr: curr_vfo now=VFOA
icom_get_freq: VFO_RX requested, vfo=currVFO
icom_get_freq: using vfo=VFOA
serial_flush called
serial_flush: tcflush
write_block called
write_block(): TX 6 bytes
0000    fe fe 94 e0 03 fd                                   ......          
read_string called
read_string(): RX 6 characters
0000    fe fe 94 e0 03 fd                                   ......          
read_string called
read_string(): RX 11 characters
0000    fe fe e0 94 03 00 70 35 05 00 fd                    ......p5...     
from_bcd called
to_bcd called
serial_flush called
serial_flush: tcflush
write_block called
write_block(): TX 11 bytes
0000    fe fe 94 e0 05 55 70 35 05 00 fd                    .....Up5...     
read_string called
read_string(): RX 11 characters
0000    fe fe 94 e0 05 55 70 35 05 00 fd                    .....Up5...     
read_string called
read_string(): RX 6 characters
0000    fe fe e0 94 fb fd                                   ......          
elapsed_ms: start = 0,0
elapsed_ms: after gettime, start = 1589304665,942436259
rigctl_parse: return#2 RPRT 0
rigctl_parse: retcode=0
sync_callback: client lock disengaged
handle_socket: vfo_mode=0
rigctl_parse: called, interactive=1
rigctl_parse: cmd= (0a)
rigctl_parse: cmd=F(46)
rigctl_parse: debug1
rigctl_parse: debug3
rigctl_parse: debug4
rigctl_parse: debug5
rigctl_parse: debug10
sync_callback: client lock engaged
rigctl(d): F 'currVFO' '5357000.000000' '' ''
rigctl_parse: vfo_mode=0
rig_set_freq called
icom_set_freq called currVFO=5357000.000000
icom_set_freq: currVFO asked for so vfo set to VFOA
icom_set_freq: set_vfo_curr=VFOA
set_vfo_curr: vfo=VFOA, curr_vfo=VFOA
set_vfo_curr: curr_vfo now=VFOA
icom_get_freq called for currVFO
set_vfo_curr: vfo=currVFO, curr_vfo=VFOA
set_vfo_curr: Asking for currVFO,  currVFO=VFOA
set_vfo_curr: curr_vfo now=VFOA
icom_get_freq: VFO_RX requested, vfo=currVFO
icom_get_freq: using vfo=VFOA
serial_flush called
serial_flush: tcflush
write_block called
write_block(): TX 6 bytes
0000    fe fe 94 e0 03 fd                                   ......          
read_string called
read_string(): RX 6 characters
0000    fe fe 94 e0 03 fd                                   ......          
read_string called
read_string(): RX 11 characters
0000    fe fe e0 94 03 55 70 35 05 00 fd                    .....Up5...     
from_bcd called
to_bcd called
serial_flush called
serial_flush: tcflush
write_block called
write_block(): TX 11 bytes
0000    fe fe 94 e0 05 00 70 35 05 00 fd                    ......p5...     
read_string called
read_string(): RX 11 characters
0000    fe fe 94 e0 05 00 70 35 05 00 fd                    ......p5...     
read_string called
read_string(): RX 6 characters
0000    fe fe e0 94 fb fd                                   ......          
elapsed_ms: start = 0,0
elapsed_ms: after gettime, start = 1589304665,986498974
rigctl_parse: return#2 RPRT 0
rigctl_parse: retcode=0
sync_callback: client lock disengaged
handle_socket: vfo_mode=0
rigctl_parse: called, interactive=1
rigctl_parse: cmd= (0a)
rigctl_parse: cmd=s(73)
rigctl_parse: debug1
rigctl_parse: debug5
rigctl_parse: debug10
sync_callback: client lock engaged
rigctl(d): s 'currVFO' '' '' ''
rigctl_parse: vfo_mode=0
rig_get_split_vfo called
elapsed_ms: start = 1589304665,16501822
elapsed_ms: elapsed_secs=971.419
rig_get_split_vfo: cache check age=971ms
rig_get_split_vfo: cache miss age=971ms
icom_get_split_vfo called
serial_flush called
serial_flush: tcflush
write_block called
write_block(): TX 6 bytes
0000    fe fe 94 e0 0f fd                                   ......          
read_string called
read_string(): RX 6 characters
0000    fe fe 94 e0 0f fd                                   ......          
read_string called
read_string(): RX 7 characters
0000    fe fe e0 94 0f 00 fd                                .......         
icom_get_split_vfos called
icom_get_split_vfos: VFO_HAS_A_B_ONLY, rx=VFOA, tx=VFOB
icom_get_split_vfo: vfo=currVFO rx_vfo=VFOA tx_vfo=VFOB split=0
elapsed_ms: start = 0,0
elapsed_ms: after gettime, start = 1589304666,7315479
rigctl_parse: retcode=0
sync_callback: client lock disengaged
handle_socket: vfo_mode=0
rigctl_parse: called, interactive=1
rigctl_parse: cmd= (0a)
rigctl_parse: cmd=v(76)
rigctl_parse: debug1
rigctl_parse: debug5
rigctl_parse: debug10
sync_callback: client lock engaged
rigctl(d): v 'currVFO' '' '' ''
rigctl_parse: vfo_mode=0
rig_get_vfo called
rigctl_parse: return#1 RPRT -11
rigctl_parse: retcode=-11
sync_callback: client lock disengaged
handle_socket: rigctl_parse retcode=-11
handle_socket: vfo_mode=0
rigctl_parse: called, interactive=1
rigctl_parse: cmd= (0a)
rigctl_parse: cmd=T(54)
rigctl_parse: debug1
rigctl_parse: debug3
rigctl_parse: debug4
rigctl_parse: debug5
rigctl_parse: debug10
sync_callback: client lock engaged
rigctl(d): T 'currVFO' '0' '' ''
rigctl_parse: vfo_mode=0
rig_set_ptt called
icom_set_ptt called
serial_flush called
serial_flush: tcflush
write_block called
write_block(): TX 8 bytes
0000    fe fe 94 e0 1c 00 00 fd                             ........        
read_string called
read_string(): RX 8 characters
0000    fe fe 94 e0 1c 00 00 fd                             ........        
read_string called
read_string(): RX 6 characters
0000    fe fe e0 94 fb fd                                   ......          
elapsed_ms: start = 0,0
elapsed_ms: after gettime, start = 1589304668,132265621
rigctl_parse: return#2 RPRT 0
rigctl_parse: retcode=0
sync_callback: client lock disengaged
handle_socket: vfo_mode=0
rigctl_parse: called, interactive=1
rigctl_parse: cmd= (0a)
rigctl_parse: cmd=q(71)
rigctl_parse: quit returning NETRIGCTL_RET 0
handle_socket: rigctl_parse retcode=1
Connection closed from localhost:49672
Connection opened from localhost:49674
sync_callback: client lock engaged
sync_callback: client lock disengaged
handle_socket: vfo_mode=0
rigctl_parse: called, interactive=1
rigctl_parse: cmd=\(5c)
rigctl_parse: debug1
rigctl_parse: debug5
rigctl_parse: debug10
sync_callback: client lock engaged
rigctl(d): ð 'currVFO' '' '' ''
rigctl_parse: vfo_mode=0
rigctl_parse: retcode=0
sync_callback: client lock disengaged
handle_socket: vfo_mode=0
rigctl_parse: called, interactive=1
rigctl_parse: cmd=\(5c)
rigctl_parse: debug1
rigctl_parse: debug5
rigctl_parse: debug10
sync_callback: client lock engaged
rigctl(d):  'currVFO' '' '' ''
rigctl_parse: vfo_mode=0
rigctl_parse: retcode=0
sync_callback: client lock disengaged
handle_socket: vfo_mode=0
rigctl_parse: called, interactive=1
rigctl_parse: cmd=v(76)
rigctl_parse: debug1
rigctl_parse: debug5
rigctl_parse: debug10
sync_callback: client lock engaged
rigctl(d): v 'currVFO' '' '' ''
rigctl_parse: vfo_mode=0
rig_get_vfo called
rigctl_parse: return#1 RPRT -11
rigctl_parse: retcode=-11
sync_callback: client lock disengaged
handle_socket: rigctl_parse retcode=-11
handle_socket: vfo_mode=0
rigctl_parse: called, interactive=1
rigctl_parse: cmd= (0a)
rigctl_parse: cmd=m(6d)
rigctl_parse: debug1
rigctl_parse: debug5
rigctl_parse: debug10
sync_callback: client lock engaged
rigctl(d): m 'currVFO' '' '' ''
rigctl_parse: vfo_mode=0
rig_get_mode called
elapsed_ms: start = 1557768664,859462412
elapsed_ms: elapsed_secs=3.1536e+10
rig_get_mode: cache check age=-2147483648ms
rig_get_mode: cache hit age=-2147483648ms
rigctl_parse: retcode=0
sync_callback: client lock disengaged
handle_socket: vfo_mode=0
rigctl_parse: called, interactive=1
rigctl_parse: cmd= (0a)
rigctl_parse: cmd=f(66)
rigctl_parse: debug1
rigctl_parse: debug5
rigctl_parse: debug10
sync_callback: client lock engaged
rigctl(d): f 'currVFO' '' '' ''
rigctl_parse: vfo_mode=0
rig_get_freq called vfo=currVFO
elapsed_ms: start = 1589304665,899036010
elapsed_ms: elapsed_secs=39438
rig_get_freq: cache check age=39438ms
rig_get_freq: cache miss age=39438ms, cached_vfo=currVFO, asked_vfo=currVFO
icom_get_freq called for currVFO
set_vfo_curr: vfo=currVFO, curr_vfo=VFOA
set_vfo_curr: Asking for currVFO,  currVFO=VFOA
set_vfo_curr: curr_vfo now=VFOA
icom_get_freq: VFO_RX requested, vfo=currVFO
icom_get_freq: using vfo=VFOA
serial_flush called
serial_flush: tcflush
write_block called
write_block(): TX 6 bytes
0000    fe fe 94 e0 03 fd                                   ......          
read_string called
read_string(): RX 6 characters
0000    fe fe 94 e0 03 fd                                   ......          
read_string called
read_string(): RX 11 characters
0000    fe fe e0 94 03 00 70 35 05 00 fd                    ......p5...     
from_bcd called
elapsed_ms: start = 0,0
elapsed_ms: after gettime, start = 1589304705,358406081
rig_get_freq: cache reset age=999000ms, vfo=currVFO, freq=5.357e+06
rigctl_parse: retcode=0
sync_callback: client lock disengaged
handle_socket: vfo_mode=0
rigctl_parse: called, interactive=1
rigctl_parse: cmd= (0a)
rigctl_parse: cmd=F(46)
rigctl_parse: debug1
rigctl_parse: debug3
rigctl_parse: debug4
rigctl_parse: debug5
rigctl_parse: debug10
sync_callback: client lock engaged
rigctl(d): F 'currVFO' '5357055.000000' '' ''
rigctl_parse: vfo_mode=0
rig_set_freq called
icom_set_freq called currVFO=5357055.000000
icom_set_freq: currVFO asked for so vfo set to VFOA
icom_set_freq: set_vfo_curr=VFOA
set_vfo_curr: vfo=VFOA, curr_vfo=VFOA
set_vfo_curr: curr_vfo now=VFOA
icom_get_freq called for currVFO
set_vfo_curr: vfo=currVFO, curr_vfo=VFOA
set_vfo_curr: Asking for currVFO,  currVFO=VFOA
set_vfo_curr: curr_vfo now=VFOA
icom_get_freq: VFO_RX requested, vfo=currVFO
icom_get_freq: using vfo=VFOA
serial_flush called
serial_flush: tcflush
write_block called
write_block(): TX 6 bytes
0000    fe fe 94 e0 03 fd                                   ......          
read_string called
read_string(): RX 6 characters
0000    fe fe 94 e0 03 fd                                   ......          
read_string called
read_string(): RX 11 characters
0000    fe fe e0 94 03 00 70 35 05 00 fd                    ......p5...     
from_bcd called
to_bcd called
serial_flush called
serial_flush: tcflush
write_block called
write_block(): TX 11 bytes
0000    fe fe 94 e0 05 55 70 35 05 00 fd                    .....Up5...     
read_string called
read_string(): RX 11 characters
0000    fe fe 94 e0 05 55 70 35 05 00 fd                    .....Up5...     
read_string called
read_string(): RX 6 characters
0000    fe fe e0 94 fb fd                                   ......          
elapsed_ms: start = 0,0
elapsed_ms: after gettime, start = 1589304705,402120830
rigctl_parse: return#2 RPRT 0
rigctl_parse: retcode=0
sync_callback: client lock disengaged
handle_socket: vfo_mode=0
rigctl_parse: called, interactive=1
rigctl_parse: cmd= (0a)
rigctl_parse: cmd=F(46)
rigctl_parse: debug1
rigctl_parse: debug3
rigctl_parse: debug4
rigctl_parse: debug5
rigctl_parse: debug10
sync_callback: client lock engaged
rigctl(d): F 'currVFO' '5357000.000000' '' ''
rigctl_parse: vfo_mode=0
rig_set_freq called
icom_set_freq called currVFO=5357000.000000
icom_set_freq: currVFO asked for so vfo set to VFOA
icom_set_freq: set_vfo_curr=VFOA
set_vfo_curr: vfo=VFOA, curr_vfo=VFOA
set_vfo_curr: curr_vfo now=VFOA
icom_get_freq called for currVFO
set_vfo_curr: vfo=currVFO, curr_vfo=VFOA
set_vfo_curr: Asking for currVFO,  currVFO=VFOA
set_vfo_curr: curr_vfo now=VFOA
icom_get_freq: VFO_RX requested, vfo=currVFO
icom_get_freq: using vfo=VFOA
serial_flush called
serial_flush: tcflush
write_block called
write_block(): TX 6 bytes
0000    fe fe 94 e0 03 fd                                   ......          
read_string called
read_string(): RX 6 characters
0000    fe fe 94 e0 03 fd                                   ......          
read_string called
read_string(): RX 11 characters
0000    fe fe e0 94 03 55 70 35 05 00 fd                    .....Up5...     
from_bcd called
to_bcd called
serial_flush called
serial_flush: tcflush
write_block called
write_block(): TX 11 bytes
0000    fe fe 94 e0 05 00 70 35 05 00 fd                    ......p5...     
read_string called
read_string(): RX 11 characters
0000    fe fe 94 e0 05 00 70 35 05 00 fd                    ......p5...     
read_string called
read_string(): RX 6 characters
0000    fe fe e0 94 fb fd                                   ......          
elapsed_ms: start = 0,0
elapsed_ms: after gettime, start = 1589304705,446111550
rigctl_parse: return#2 RPRT 0
rigctl_parse: retcode=0
sync_callback: client lock disengaged
handle_socket: vfo_mode=0
rigctl_parse: called, interactive=1
rigctl_parse: cmd= (0a)
rigctl_parse: cmd=s(73)
rigctl_parse: debug1
rigctl_parse: debug5
rigctl_parse: debug10
sync_callback: client lock engaged
rigctl(d): s 'currVFO' '' '' ''
rigctl_parse: vfo_mode=0
rig_get_split_vfo called
elapsed_ms: start = 1589304666,7315479
elapsed_ms: elapsed_secs=39439.9
rig_get_split_vfo: cache check age=39439ms
rig_get_split_vfo: cache miss age=39439ms
icom_get_split_vfo called
serial_flush called
serial_flush: tcflush
write_block called
write_block(): TX 6 bytes
0000    fe fe 94 e0 0f fd                                   ......          
read_string called
read_string(): RX 6 characters
0000    fe fe 94 e0 0f fd                                   ......          
read_string called
read_string(): RX 7 characters
0000    fe fe e0 94 0f 00 fd                                .......         
icom_get_split_vfos called
icom_get_split_vfos: VFO_HAS_A_B_ONLY, rx=VFOA, tx=VFOB
icom_get_split_vfo: vfo=currVFO rx_vfo=VFOA tx_vfo=VFOB split=0
elapsed_ms: start = 0,0
elapsed_ms: after gettime, start = 1589304705,464768349
rigctl_parse: retcode=0
sync_callback: client lock disengaged
handle_socket: vfo_mode=0
rigctl_parse: called, interactive=1
rigctl_parse: cmd= (0a)
rigctl_parse: cmd=v(76)
rigctl_parse: debug1
rigctl_parse: debug5
rigctl_parse: debug10
sync_callback: client lock engaged
rigctl(d): v 'currVFO' '' '' ''
rigctl_parse: vfo_mode=0
rig_get_vfo called
rigctl_parse: return#1 RPRT -11
rigctl_parse: retcode=-11
sync_callback: client lock disengaged
handle_socket: rigctl_parse retcode=-11
handle_socket: vfo_mode=0
rigctl_parse: called, interactive=1
rigctl_parse: cmd= (0a)
rigctl_parse: cmd=T(54)
rigctl_parse: debug1
rigctl_parse: debug3
rigctl_parse: debug4
rigctl_parse: debug5
rigctl_parse: debug10
sync_callback: client lock engaged
rigctl(d): T 'currVFO' '0' '' ''
rigctl_parse: vfo_mode=0
rig_set_ptt called
icom_set_ptt called
serial_flush called
serial_flush: tcflush
write_block called
write_block(): TX 8 bytes
0000    fe fe 94 e0 1c 00 00 fd                             ........        
read_string called
read_string(): RX 8 characters
0000    fe fe 94 e0 1c 00 00 fd                             ........        
read_string called
read_string(): RX 6 characters
0000    fe fe e0 94 fb fd                                   ......          
elapsed_ms: start = 0,0
elapsed_ms: after gettime, start = 1589304707,593353626
rigctl_parse: return#2 RPRT 0
rigctl_parse: retcode=0
sync_callback: client lock disengaged
handle_socket: vfo_mode=0
rigctl_parse: called, interactive=1
rigctl_parse: cmd= (0a)
rigctl_parse: cmd=q(71)
rigctl_parse: quit returning NETRIGCTL_RET 0
handle_socket: rigctl_parse retcode=1
Connection closed from localhost:49674
Connection opened from localhost:49676
sync_callback: client lock engaged
sync_callback: client lock disengaged
handle_socket: vfo_mode=0
rigctl_parse: called, interactive=1
rigctl_parse: cmd=\(5c)
rigctl_parse: debug1
rigctl_parse: debug5
rigctl_parse: debug10
sync_callback: client lock engaged
rigctl(d): ð 'currVFO' '' '' ''
rigctl_parse: vfo_mode=0
rigctl_parse: retcode=0
sync_callback: client lock disengaged
handle_socket: vfo_mode=0
rigctl_parse: called, interactive=1
rigctl_parse: cmd=\(5c)
rigctl_parse: debug1
rigctl_parse: debug5
rigctl_parse: debug10
sync_callback: client lock engaged
rigctl(d):  'currVFO' '' '' ''
rigctl_parse: vfo_mode=0
rigctl_parse: retcode=0
sync_callback: client lock disengaged
handle_socket: vfo_mode=0
rigctl_parse: called, interactive=1
rigctl_parse: cmd=v(76)
rigctl_parse: debug1
rigctl_parse: debug5
rigctl_parse: debug10
sync_callback: client lock engaged
rigctl(d): v 'currVFO' '' '' ''
rigctl_parse: vfo_mode=0
rig_get_vfo called
rigctl_parse: return#1 RPRT -11
rigctl_parse: retcode=-11
sync_callback: client lock disengaged
handle_socket: rigctl_parse retcode=-11
handle_socket: vfo_mode=0
rigctl_parse: called, interactive=1
rigctl_parse: cmd= (0a)
rigctl_parse: cmd=m(6d)
rigctl_parse: debug1
rigctl_parse: debug5
rigctl_parse: debug10
sync_callback: client lock engaged
rigctl(d): m 'currVFO' '' '' ''
rigctl_parse: vfo_mode=0
rig_get_mode called
elapsed_ms: start = 1557768664,859462412
elapsed_ms: elapsed_secs=3.15361e+10
rig_get_mode: cache check age=-2147483648ms
rig_get_mode: cache hit age=-2147483648ms
rigctl_parse: retcode=0
sync_callback: client lock disengaged
handle_socket: vfo_mode=0
rigctl_parse: called, interactive=1
rigctl_parse: cmd= (0a)
rigctl_parse: cmd=f(66)
rigctl_parse: debug1
rigctl_parse: debug5
rigctl_parse: debug10
sync_callback: client lock engaged
rigctl(d): f 'currVFO' '' '' ''
rigctl_parse: vfo_mode=0
rig_get_freq called vfo=currVFO
elapsed_ms: start = 1589304705,358406081
elapsed_ms: elapsed_secs=13399.8
rig_get_freq: cache check age=13399ms
rig_get_freq: cache miss age=13399ms, cached_vfo=currVFO, asked_vfo=currVFO
icom_get_freq called for currVFO
set_vfo_curr: vfo=currVFO, curr_vfo=VFOA
set_vfo_curr: Asking for currVFO,  currVFO=VFOA
set_vfo_curr: curr_vfo now=VFOA
icom_get_freq: VFO_RX requested, vfo=currVFO
icom_get_freq: using vfo=VFOA
serial_flush called
serial_flush: tcflush
write_block called
write_block(): TX 6 bytes
0000    fe fe 94 e0 03 fd                                   ......          
read_string called
read_string(): RX 6 characters
0000    fe fe 94 e0 03 fd                                   ......          
read_string called
read_string(): RX 11 characters
0000    fe fe e0 94 03 00 70 35 05 00 fd                    ......p5...     
from_bcd called
elapsed_ms: start = 0,0
elapsed_ms: after gettime, start = 1589304718,779108362
rig_get_freq: cache reset age=999000ms, vfo=currVFO, freq=5.357e+06
rigctl_parse: retcode=0
sync_callback: client lock disengaged
handle_socket: vfo_mode=0
rigctl_parse: called, interactive=1
rigctl_parse: cmd= (0a)
rigctl_parse: cmd=F(46)
rigctl_parse: debug1
rigctl_parse: debug3
rigctl_parse: debug4
rigctl_parse: debug5
rigctl_parse: debug10
sync_callback: client lock engaged
rigctl(d): F 'currVFO' '5357055.000000' '' ''
rigctl_parse: vfo_mode=0
rig_set_freq called
icom_set_freq called currVFO=5357055.000000
icom_set_freq: currVFO asked for so vfo set to VFOA
icom_set_freq: set_vfo_curr=VFOA
set_vfo_curr: vfo=VFOA, curr_vfo=VFOA
set_vfo_curr: curr_vfo now=VFOA
icom_get_freq called for currVFO
set_vfo_curr: vfo=currVFO, curr_vfo=VFOA
set_vfo_curr: Asking for currVFO,  currVFO=VFOA
set_vfo_curr: curr_vfo now=VFOA
icom_get_freq: VFO_RX requested, vfo=currVFO
icom_get_freq: using vfo=VFOA
serial_flush called
serial_flush: tcflush
write_block called
write_block(): TX 6 bytes
0000    fe fe 94 e0 03 fd                                   ......          
read_string called
read_string(): RX 6 characters
0000    fe fe 94 e0 03 fd                                   ......          
read_string called
read_string(): RX 11 characters
0000    fe fe e0 94 03 00 70 35 05 00 fd                    ......p5...     
from_bcd called
to_bcd called
serial_flush called
serial_flush: tcflush
write_block called
write_block(): TX 11 bytes
0000    fe fe 94 e0 05 55 70 35 05 00 fd                    .....Up5...     
read_string called
read_string(): RX 11 characters
0000    fe fe 94 e0 05 55 70 35 05 00 fd                    .....Up5...     
read_string called
read_string(): RX 6 characters
0000    fe fe e0 94 fb fd                                   ......          
elapsed_ms: start = 0,0
elapsed_ms: after gettime, start = 1589304718,820461521
rigctl_parse: return#2 RPRT 0
rigctl_parse: retcode=0
sync_callback: client lock disengaged
handle_socket: vfo_mode=0
rigctl_parse: called, interactive=1
rigctl_parse: cmd= (0a)
rigctl_parse: cmd=F(46)
rigctl_parse: debug1
rigctl_parse: debug3
rigctl_parse: debug4
rigctl_parse: debug5
rigctl_parse: debug10
sync_callback: client lock engaged
rigctl(d): F 'currVFO' '5357000.000000' '' ''
rigctl_parse: vfo_mode=0
rig_set_freq called
icom_set_freq called currVFO=5357000.000000
icom_set_freq: currVFO asked for so vfo set to VFOA
icom_set_freq: set_vfo_curr=VFOA
set_vfo_curr: vfo=VFOA, curr_vfo=VFOA
set_vfo_curr: curr_vfo now=VFOA
icom_get_freq called for currVFO
set_vfo_curr: vfo=currVFO, curr_vfo=VFOA
set_vfo_curr: Asking for currVFO,  currVFO=VFOA
set_vfo_curr: curr_vfo now=VFOA
icom_get_freq: VFO_RX requested, vfo=currVFO
icom_get_freq: using vfo=VFOA
serial_flush called
serial_flush: tcflush
write_block called
write_block(): TX 6 bytes
0000    fe fe 94 e0 03 fd                                   ......          
read_string called
read_string(): RX 6 characters
0000    fe fe 94 e0 03 fd                                   ......          
read_string called
read_string(): RX 11 characters
0000    fe fe e0 94 03 55 70 35 05 00 fd                    .....Up5...     
from_bcd called
to_bcd called
serial_flush called
serial_flush: tcflush
write_block called
write_block(): TX 11 bytes
0000    fe fe 94 e0 05 00 70 35 05 00 fd                    ......p5...     
read_string called
read_string(): RX 11 characters
0000    fe fe 94 e0 05 00 70 35 05 00 fd                    ......p5...     
read_string called
read_string(): RX 6 characters
0000    fe fe e0 94 fb fd                                   ......          
elapsed_ms: start = 0,0
elapsed_ms: after gettime, start = 1589304718,860570451
rigctl_parse: return#2 RPRT 0
rigctl_parse: retcode=0
sync_callback: client lock disengaged
handle_socket: vfo_mode=0
rigctl_parse: called, interactive=1
rigctl_parse: cmd= (0a)
rigctl_parse: cmd=s(73)
rigctl_parse: debug1
rigctl_parse: debug5
rigctl_parse: debug10
sync_callback: client lock engaged
rigctl(d): s 'currVFO' '' '' ''
rigctl_parse: vfo_mode=0
rig_get_split_vfo called
elapsed_ms: start = 1589304705,464768349
elapsed_ms: elapsed_secs=13397
rig_get_split_vfo: cache check age=13396ms
rig_get_split_vfo: cache miss age=13396ms
icom_get_split_vfo called
serial_flush called
serial_flush: tcflush
write_block called
write_block(): TX 6 bytes
0000    fe fe 94 e0 0f fd                                   ......          
read_string called
read_string(): RX 6 characters
0000    fe fe 94 e0 0f fd                                   ......          
read_string called
read_string(): RX 7 characters
0000    fe fe e0 94 0f 00 fd                                .......         
icom_get_split_vfos called
icom_get_split_vfos: VFO_HAS_A_B_ONLY, rx=VFOA, tx=VFOB
icom_get_split_vfo: vfo=currVFO rx_vfo=VFOA tx_vfo=VFOB split=0
elapsed_ms: start = 0,0
elapsed_ms: after gettime, start = 1589304718,881229504
rigctl_parse: retcode=0
sync_callback: client lock disengaged
handle_socket: vfo_mode=0
rigctl_parse: called, interactive=1
rigctl_parse: cmd= (0a)
rigctl_parse: cmd=v(76)
rigctl_parse: debug1
rigctl_parse: debug5
rigctl_parse: debug10
sync_callback: client lock engaged
rigctl(d): v 'currVFO' '' '' ''
rigctl_parse: vfo_mode=0
rig_get_vfo called
rigctl_parse: return#1 RPRT -11
rigctl_parse: retcode=-11
sync_callback: client lock disengaged
handle_socket: rigctl_parse retcode=-11
handle_socket: vfo_mode=0
rigctl_parse: called, interactive=1
rigctl_parse: cmd= (0a)
rigctl_parse: cmd=T(54)
rigctl_parse: debug1
rigctl_parse: debug3
rigctl_parse: debug4
rigctl_parse: debug5
rigctl_parse: debug10
sync_callback: client lock engaged
rigctl(d): T 'currVFO' '0' '' ''
rigctl_parse: vfo_mode=0
rig_set_ptt called
icom_set_ptt called
serial_flush called
serial_flush: tcflush
write_block called
write_block(): TX 8 bytes
0000    fe fe 94 e0 1c 00 00 fd                             ........        
read_string called
read_string(): RX 8 characters
0000    fe fe 94 e0 1c 00 00 fd                             ........        
read_string called
read_string(): RX 6 characters
0000    fe fe e0 94 fb fd                                   ......          
elapsed_ms: start = 0,0
elapsed_ms: after gettime, start = 1589304720,804346693
rigctl_parse: return#2 RPRT 0
rigctl_parse: retcode=0
sync_callback: client lock disengaged
handle_socket: vfo_mode=0
rigctl_parse: called, interactive=1
rigctl_parse: cmd= (0a)
rigctl_parse: cmd=q(71)
rigctl_parse: quit returning NETRIGCTL_RET 0
handle_socket: rigctl_parse retcode=1
Connection closed from localhost:49676
^Cmain: select
sync_callback: client lock engaged
rig_close called
icom_rig_close: called
port_close called
ser_close called
ser_close: restoring options
sync_callback: client lock disengaged
rig_cleanup called
icom_cleanup called


Any ideas? 
73 de Kari, oh2gqc







Karza <kari.sillanmaki@...>
 

Hello Devs,
I wonder if anyone noticed this issue I reported yesterday...
https://groups.io/g/WSJTX/message/9902

Today I used Wireshark to see what is going on 'on the wire':

Here's the latter part of the trace:

This part is where I think WSJT-X is finding out VFO granularity.

All OK so far.

0000   00 00 03 04 00 06 00 00 00 00 00 00 00 00 08 00   ................
0010   45 00 00 36 e1 e7 40 00 40 06 5a d8 7f 00 00 01   E..6áç@.@.ZØ....
0020   7f 00 00 01 b3 22 11 b4 e2 00 7c a0 bc 9a b0 80   ....³".´â.| ¼.°.
0030   80 18 02 00 fe 2a 00 00 01 01 08 0a bb ef c7 f8   ....þ*......»ïÇø
0040   bb ef c7 f6 66 0a                                 »ïÇöf.

0000   00 00 03 04 00 06 00 00 00 00 00 00 00 00 08 00   ................
0010   45 00 00 41 72 d0 40 00 40 06 c9 e4 7f 00 00 01   E..ArÐ@.@.Éä....
0020   7f 00 00 01 11 b4 b3 22 bc 9a b0 80 e2 00 7c a2   .....´³"¼.°.â.|¢
0030   80 18 02 00 fe 35 00 00 01 01 08 0a bb ef c8 34   ....þ5......»ïÈ4
0040   bb ef c7 f8 35 33 35 37 30 30 30 0a 56 46 4f 41   »ïÇø5357000.VFOA
0050   0a                                                .

0000   00 00 03 04 00 06 00 00 00 00 00 00 00 00 08 00   ................
0010   45 00 00 45 e1 e8 40 00 40 06 5a c8 7f 00 00 01   E..Eáè@.@.ZÈ....
0020   7f 00 00 01 b3 22 11 b4 e2 00 7c a2 bc 9a b0 8d   ....³".´â.|¢¼.°.
0030   80 18 02 00 fe 39 00 00 01 01 08 0a bb ef c8 35   ....þ9......»ïÈ5
0040   bb ef c8 34 46 20 35 33 35 37 30 35 35 2e 30 30   »ïÈ4F 5357055.00
0050   30 30 30 30 0a                                    0000.

0000   00 00 03 04 00 06 00 00 00 00 00 00 00 00 08 00   ................
0010   45 00 00 3b 72 d2 40 00 40 06 c9 e8 7f 00 00 01   E..;rÒ@.@.Éè....
0020   7f 00 00 01 11 b4 b3 22 bc 9a b0 8d e2 00 7c b3   .....´³"¼.°.â.|³
0030   80 18 02 00 fe 2f 00 00 01 01 08 0a bb ef c8 5f   ....þ/......»ïÈ_
0040   bb ef c8 35 52 50 52 54 20 30 0a                  »ïÈ5RPRT 0.

0000   00 00 03 04 00 06 00 00 00 00 00 00 00 00 08 00   ................
0010   45 00 00 45 e1 e9 40 00 40 06 5a c7 7f 00 00 01   E..Eáé@.@.ZÇ....
0020   7f 00 00 01 b3 22 11 b4 e2 00 7c b3 bc 9a b0 94   ....³".´â.|³¼.°.
0030   80 18 02 00 fe 39 00 00 01 01 08 0a bb ef c8 5f   ....þ9......»ïÈ_
0040   bb ef c8 5f 46 20 35 33 35 37 30 30 30 2e 30 30   »ïÈ_F 5357000.00
0050   30 30 30 30 0a                                    0000.

0000   00 00 03 04 00 06 00 00 00 00 00 00 00 00 08 00   ................
0010   45 00 00 3b 72 d4 40 00 40 06 c9 e6 7f 00 00 01   E..;rÔ@.@.Éæ....
0020   7f 00 00 01 11 b4 b3 22 bc 9a b0 94 e2 00 7c c4   .....´³"¼.°.â.|Ä
0030   80 18 02 00 fe 2f 00 00 01 01 08 0a bb ef c8 87   ....þ/......»ïÈ.
0040   bb ef c8 5f 52 50 52 54 20 30 0a                  »ïÈ_RPRT 0.

Now command 's' is sent to get split VFO.

0000   00 00 03 04 00 06 00 00 00 00 00 00 00 00 08 00   ................
0010   45 00 00 36 e1 ea 40 00 40 06 5a d5 7f 00 00 01   E..6áê@.@.ZÕ....
0020   7f 00 00 01 b3 22 11 b4 e2 00 7c c4 bc 9a b0 9b   ....³".´â.|ļ.°.
0030   80 18 02 00 fe 2a 00 00 01 01 08 0a bb ef c8 88   ....þ*......»ïÈ.
0040   bb ef c8 87 73 0a                                 »ïÈ.s.

I's VFOB, thank you very much.

0000   00 00 03 04 00 06 00 00 00 00 00 00 00 00 08 00   ................
0010   45 00 00 3b 72 d6 40 00 40 06 c9 e4 7f 00 00 01   E..;rÖ@.@.Éä....
0020   7f 00 00 01 11 b4 b3 22 bc 9a b0 9b e2 00 7c c6   .....´³"¼.°.â.|Æ
0030   80 18 02 00 fe 2f 00 00 01 01 08 0a bb ef c8 9b   ....þ/......»ïÈ.
0040   bb ef c8 88 30 0a 56 46 4f 42 0a                  »ïÈ.0.VFOB.

Now here is where the trouble begins: WSJT-X sends command 'v'
followed by a carriage-return:

0000   00 00 03 04 00 06 00 00 00 00 00 00 00 00 08 00   ................
0010   45 00 00 36 e1 ec 40 00 40 06 5a d3 7f 00 00 01   E..6áì@.@.ZÓ....
0020   7f 00 00 01 b3 22 11 b4 e2 00 7c c6 bc 9a b0 a2   ....³".´â.|Ƽ.°¢
0030   80 18 02 00 fe 2a 00 00 01 01 08 0a bb ef d0 a1   ....þ*......»ïС
0040   bb ef c8 9b 76 0a                                 »ïÈ.v.

Rigctrld is not happy with that query and sends back negative acknowledgement:

0000   00 00 03 04 00 06 00 00 00 00 00 00 00 00 08 00   ................
0010   45 00 00 3d 72 d7 40 00 40 06 c9 e1 7f 00 00 01   E..=r×@.@.Éá....
0020   7f 00 00 01 11 b4 b3 22 bc 9a b0 a2 e2 00 7c c8   .....´³"¼.°¢â.|È
0030   80 18 02 00 fe 31 00 00 01 01 08 0a bb ef d0 a2   ....þ1......»ïТ
0040   bb ef d0 a1 52 50 52 54 20 2d 31 31 0a            »ïСRPRT -11.

After this WSJT-X closes down the network connection and an error
is reported.

Same response is returned if command 'v' is sent using netcat connection.

73's de Kari, oh2gqc