FT-817 set_freq not working

[mdblack98]

Hello Mike.

I have just build and test.
I seems to be bether.

Start is normal again.
My loop function to read strengh signal with self.rig.get_level_i(Hamlib.RIG_LEVEL_STRENGTH) work. (you dont see in log below beacause i stop it for more readable other bug)
Change mode and read mode is good.

1.So, it's seems to have some problem when i change the frequency.

2.I have also try turn power Off and POwer On and it dont work.

See below, i hope all informations can help you.

1.change the frequency
recording...
rig_init called
yaesu: initrigs4_yaesu called
rig_register called
rig_register: rig_register (1021)
rig_register called
rig_register: rig_register (1027)
rig_register called
rig_register: rig_register (1010)
rig_register called
rig_register: rig_register (1005)
rig_register called
rig_register: rig_register (1006)
rig_register called
rig_register: rig_register (1007)
rig_register called
rig_register: rig_register (1039)
rig_register called
rig_register: rig_register (1009)
rig_register called
rig_register: rig_register (1020)
rig_register called
rig_register: rig_register (1001)
rig_register called
rig_register: rig_register (1022)
rig_register called
rig_register: rig_register (1023)
rig_register called
rig_register: rig_register (1011)
rig_register called
rig_register: rig_register (1015)
rig_register called
rig_register: rig_register (1013)
rig_register called
rig_register: rig_register (1014)
rig_register called
rig_register: rig_register (1028)
rig_register called
rig_register: rig_register (1031)
rig_register called
rig_register: rig_register (1016)
rig_register called
rig_register: rig_register (1003)
rig_register called
rig_register: rig_register (1024)
rig_register called
rig_register: rig_register (1004)
rig_register called
rig_register: rig_register (1025)
rig_register called
rig_register: rig_register (1029)
rig_register called
rig_register: rig_register (1037)
rig_register called
rig_register: rig_register (1032)
rig_register called
rig_register: rig_register (1030)
rig_register called
rig_register: rig_register (1017)
rig_register called
rig_register: rig_register (1019)
rig_register called
rig_register: rig_register (1018)
rig_register called
rig_register: rig_register (1026)
rig_register called
rig_register: rig_register (1033)
rig_register called
rig_register: rig_register (1034)
rig_register called
rig_register: rig_register (1035)
rig_register called
rig_register: rig_register (1036)
rig_register called
rig_register: rig_register (1038)
rig_register called
rig_register: rig_register (1040)
rig_register called
rig_register: rig_register (1041)
ft817_init: called, version 20201012.0
rig_token_lookup called
rig_confparam_lookup called
rig_set_conf called
rig_confparam_lookup called
rig_set_conf: rig_pathname='/dev/ttyUSB0'
rig_token_lookup called
rig_confparam_lookup called
rig_set_conf called
rig_confparam_lookup called
rig_set_conf: retry='5'
rig_open called
port_open called
serial_open called
serial_setup called
serial_setup: tcgetattr
serial_setup: cfmakeraw
serial_setup: cfsetispeed=38400,0x000f
serial_setup: cfsetospeed=38400,0x000f
serial_setup: data_bits=8
serial_setup: parity=0
serial_setup: tcsetattr TCSANOW
serial_flush called
serial_flush: tcflush
ft817_open: called
rig_get_vfo called
rig_get_vfo: no get_vfo
vfo_fixup: vfo=VFOA
vfo_fixup: final vfo=VFOA
rig_open: No set_vfo function rig so default vfo = VFOA
rig_get_vfo called
rig_get_vfo: no get_vfo
rig_get_freq called vfo=currVFO
vfo_fixup: vfo=currVFO
vfo_fixup: Leaving currVFO alone
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
vfo_fixup: vfo=VFOA
vfo_fixup: final vfo=VFOA
rig_get_freq: no set_vfo so vfo=VFOA
ft817_get_freq: called
ft817_get_freq: retries=5
ft817_get_status: called
rig_flush: called for serial device
serial_flush called
serial_flush: tcflush
write_block called
write_block(): TX 5 bytes
0000 00 00 00 00 03 .....
read_block called
read_block(): RX 5 bytes
0000 14 64 00 00 01 .d...
ft817_read_eeprom: called
write_block called
write_block(): TX 5 bytes
0000 00 64 00 00 bb .d...
read_block called
read_block(): RX 2 bytes
0000 85 00 ..
from_bcd_be called
0000 14 64 00 00 01 .d...
ft817_get_freq: retries=4
ft817_get_status: called
rig_flush: called for serial device
serial_flush called
serial_flush: tcflush
write_block called
write_block(): TX 5 bytes
0000 00 00 00 00 03 .....
read_block called
read_block(): RX 5 bytes
0000 14 64 00 00 01 .d...
ft817_read_eeprom: called
write_block called
write_block(): TX 5 bytes
0000 00 64 00 00 bb .d...
read_block called
read_block(): RX 2 bytes
0000 85 00 ..
from_bcd_be called
0000 14 64 00 00 01 .d...
elapsed_ms: start = 0,0
elapsed_ms: after gettime, start = 1602599189,96185841
elapsed_ms: start = 0,0
elapsed_ms: after gettime, start = 1602599189,96212285
rig_get_freq: cache reset age=999000ms, vfo=VFOA, freq=146400000
rig_get_mode called
elapsed_ms: start = 0,0
rig_get_mode: cache check age=1000000ms
rig_get_mode: cache miss age=1000000ms
ft817_get_mode: called
ft817: using cache (0 ms)
rig_get_mode: retcode after get_mode=0
rig_get_mode(1784): debugrig_get_mode(1791): debugrig_passband_normal called
elapsed_ms: start = 0,0
elapsed_ms: after gettime, start = 1602599189,96414597
rig_set_powerstat called
ft817_set_powerstat: called
ft817_send_cmd: called
write_block called
write_block(): TX 5 bytes
0000 ff ff ff ff ff .....
ft817_read_ack: called
read_block called
read_block(): Timed out 3.3046 seconds after 0 chars
ft817_read_ack: error reading ack
ft817_read_ack: adjusting post_write_delay to avoid ack
ft817_send_cmd: called
write_block called
write_block(): TX 5 bytes
0000 00 00 00 00 0f .....
ft817_read_ack: called
http server started
http server started
WARNING:tornado.general:SSL Error on 10 ('2a01:cb10:469:be00:2641:8cff:fe08:f9f3', 50674, 0, 0): [SSL: SSLV3_ALERT_CERTIFICATE_UNKNOWN] sslv3 alert certificate unknown (_ssl.c:1056)
WARNING:tornado.general:SSL Error on 11 ('2a01:cb10:469:be00:2641:8cff:fe08:f9f3', 50675, 0, 0): [SSL: SSLV3_ALERT_CERTIFICATE_UNKNOWN] sslv3 alert certificate unknown (_ssl.c:1056)
WARNING:tornado.general:SSL Error on 12 ('2a01:cb10:469:be00:2641:8cff:fe08:f9f3', 50676, 0, 0): [SSL: SSLV3_ALERT_CERTIFICATE_UNKNOWN] sslv3 alert certificate unknown (_ssl.c:1056)
WARNING:tornado.general:SSL Error on 10 ('2a01:cb10:469:be00:2641:8cff:fe08:f9f3', 50677, 0, 0): [SSL: SSLV3_ALERT_CERTIFICATE_UNKNOWN] sslv3 alert certificate unknown (_ssl.c:1056)
WARNING:tornado.general:SSL Error on 10 ('2a01:cb10:469:be00:2641:8cff:fe08:f9f3', 50680, 0, 0): [SSL: SSLV3_ALERT_CERTIFICATE_UNKNOWN] sslv3 alert certificate unknown (_ssl.c:1056)
new connection on AudioRXHandler socket.
new connection on AudioTXHandler socket.
error TXMETER
rig_set_powerstat called
ft817_set_powerstat: called
ft817_send_cmd: called
write_block called
write_block(): TX 5 bytes
0000 ff ff ff ff ff .....
ft817_read_ack: called
ft817_send_cmd: called
write_block called
write_block(): TX 5 bytes
0000 00 00 00 00 0f .....
ft817_read_ack: called
new connection on ControlTRX socket.
getFreq:
rig_get_freq called vfo=currVFO
vfo_fixup: vfo=currVFO
vfo_fixup: Leaving currVFO alone
elapsed_ms: start = 1602599189,96212285
elapsed_ms: elapsed_msecs=22576
rig_get_freq: cache check age=22576ms
rig_get_freq: cache miss age=22576ms, cached_vfo=VFOA, asked_vfo=currVFO
vfo_fixup: vfo=VFOA
vfo_fixup: final vfo=VFOA
rig_get_freq: no set_vfo so vfo=VFOA
ft817_get_freq: called
ft817_get_freq: retries=5
ft817_get_status: called
rig_flush: called for serial device
serial_flush called
serial_flush: tcflush
write_block called
write_block(): TX 5 bytes
0000 00 00 00 00 03 .....
read_block called
read_block(): RX 5 bytes
0000 14 64 00 00 01 .d...
ft817_read_eeprom: called
write_block called
write_block(): TX 5 bytes
0000 00 64 00 00 bb .d...
read_block called
read_block(): RX 2 bytes
0000 85 00 ..
from_bcd_be called
0000 14 64 00 00 01 .d...
ft817_get_freq: retries=4
ft817_get_status: called
rig_flush: called for serial device
serial_flush called
serial_flush: tcflush
write_block called
write_block(): TX 5 bytes
0000 00 00 00 00 03 .....
read_block called
read_block(): RX 5 bytes
0000 14 64 00 00 01 .d...
ft817_read_eeprom: called
write_block called
write_block(): TX 5 bytes
0000 00 64 00 00 bb .d...
read_block called
read_block(): RX 2 bytes
0000 85 00 ..
from_bcd_be called
0000 14 64 00 00 01 .d...
elapsed_ms: start = 0,0
elapsed_ms: after gettime, start = 1602599211,734947671
elapsed_ms: start = 0,0
elapsed_ms: after gettime, start = 1602599211,734972652
rig_get_freq: cache reset age=999000ms, vfo=VFOA, freq=146400000
Send to all: getFreq:146400000
getMode:
rig_get_mode called
elapsed_ms: start = 1602599189,96414597
elapsed_ms: elapsed_msecs=22647
rig_get_mode: cache check age=22646ms
rig_get_mode: cache miss age=22646ms
ft817_get_mode: called
ft817: using cache (8 ms)
rig_get_mode: retcode after get_mode=0
rig_get_mode(1784): debugrig_get_mode(1791): debugrig_passband_normal called
elapsed_ms: start = 0,0
elapsed_ms: after gettime, start = 1602599211,743300906
Send to all: getMode:USB

#moment where start to try to set frequency

setFreq:145400000
rig_set_freq called vfo=currVFO, freq=1.454e+08
vfo_fixup: vfo=currVFO
vfo_fixup: Leaving currVFO alone
rig_set_freq: TARGETABLE_FREQ vfo=currVFO
ft817: requested freq = 145400000.000000 Hz
to_bcd_be called
rig_force_cache_timeout called
ft817_send_icmd: called
write_block called
write_block(): TX 5 bytes
0000 14 54 00 00 01 .T...
ft817_read_ack: called
elapsed_ms: start = 1602599211,734972652
elapsed_ms: elapsed_msecs=10000
rig_get_freq called vfo=currVFO
vfo_fixup: vfo=currVFO
vfo_fixup: Leaving currVFO alone
elapsed_ms: start = 1602599241,16089000
elapsed_ms: elapsed_msecs=10000
rig_get_freq: cache check age=10000ms
rig_get_freq: cache miss age=10000ms, cached_vfo=VFOA, asked_vfo=currVFO
vfo_fixup: vfo=VFOA
vfo_fixup: final vfo=VFOA
rig_get_freq: no set_vfo so vfo=VFOA
ft817_get_freq: called
ft817_get_freq: retries=5
ft817_get_status: called
rig_flush: called for serial device
serial_flush called
serial_flush: tcflush
write_block called
write_block(): TX 5 bytes
0000 00 00 00 00 03 .....
read_block called

#Moment where is freezing for some seconds.
#In my old python code i only read 1 byte after set
#As i can see one byte is getting after, so no need waiting for more.

0000 00 .
read_block(): Timed out 3.78404 seconds after 1 chars
rig_flush: called for serial device
serial_flush called
serial_flush: tcflush
write_block called
write_block(): TX 5 bytes
0000 00 00 00 00 03 .....
read_block called
read_block(): RX 5 bytes
0000 14 54 00 00 01 .T...
ft817_read_eeprom: called
write_block called
write_block(): TX 5 bytes
0000 00 64 00 00 bb .d...
read_block called
read_block(): RX 2 bytes
0000 85 00 ..
from_bcd_be called
0000 14 54 00 00 01 .T...
ft817_get_freq: retries=4
ft817_get_status: called
rig_flush: called for serial device
serial_flush called
serial_flush: tcflush
write_block called
write_block(): TX 5 bytes
0000 00 00 00 00 03 .....
read_block called
read_block(): RX 5 bytes
0000 14 54 00 00 01 .T... #As you can see get freq work good
ft817_read_eeprom: called
write_block called
write_block(): TX 5 bytes
0000 00 64 00 00 bb .d...
read_block called
read_block(): RX 2 bytes
0000 85 00 ..
from_bcd_be called
0000 14 54 00 00 01 .T...
elapsed_ms: start = 0,0
elapsed_ms: after gettime, start = 1602599254,174783076
elapsed_ms: start = 0,0
elapsed_ms: after gettime, start = 1602599254,174849760
rig_get_freq: cache reset age=999000ms, vfo=VFOA, freq=145400000
elapsed_ms: start = 0,0
elapsed_ms: after gettime, start = 1602599254,174965148
rig_get_freq called vfo=currVFO
vfo_fixup: vfo=currVFO
vfo_fixup: Leaving currVFO alone
elapsed_ms: start = 1602599254,174849760
elapsed_ms: elapsed_msecs=0
rig_get_freq: cache check age=0ms
rig_get_freq: currVFO cache hit age=0ms, freq=145400000
Send to all: getFreq:145400000

For the time line information, my function in python is:

def setMode(self,MODE):
    try:
       
        self.rig.set_mode(Hamlib.rig_parse_mode(MODE))
        self.getMode()
    except:
        print("Could not set the mode via Hamlib!")
    return self.infos["MODE"]
   
def getMode(self):
    try:
        (mode, width) = self.rig.get_mode()
        self.infos["MODE"] = Hamlib.rig_strrmode(mode).upper()
        self.infos["WIDTH"] = width
    except:
        print("Could not obtain the current Mode via Hamlib!")
    return self.infos["MODE"]
    return ""

[mdblack98]

Related to
#330
and
#419

set_powerstat ON was sending bytes which did not get an ACK and was then turning off the ACK processing that we did in #330 . Changed that to not expect an ACK on PWR_ON dummy bytes so hopefully works now.

Mike