Open raphaelcervantes opened 4 years ago
Here is the logs when I add the verbose flag to the dl-serve command
➜ orpheus_site_atlas git:(feature/na-autoscale) ✗ kubectl logs -p na-dripline-python-deployment-8ccc78764-pc5cp
2020-07-21 22:50:06 [ PROG] i/application.cc(128): Final configuration:
{
dripline :
{
alerts-exchange : alerts
broker : rabbitmq-app.default.svc.cluster.local
heartbeat-interval-s : 60
heartbeat-routing-key : heartbeat
loop-timeout-ms : 1000
max-payload-size : 10000
message-wait-ms : 1000
requests-exchange : requests
}
runtime-config :
{
auth_file : /etc/rabbitmq-secret/authentications.json
cmd_at_reconnect :
[
SYST:ERRor?
*OPC?
]
command_terminator :
endpoints :
[
{
base_str : :SENSe:FREQuency:STARt
calibration : {}
log_routing_key_prefix : sensor_double_precision
module : SimpleSCPIEntity
2020-07-21T22:50:06[INFO ] dripline(86) -> python got a master config:
{'dripline': {'alerts-exchange': 'alerts', 'broker': 'rabbitmq-app.default.svc.cluster.local', 'heartbeat-interval-s': 60, 'heartbeat-routing-key': 'heartbeat', 'loop-timeout-ms': 1000, 'max-payload-size': 10000, 'message-wait-ms': 1000, 'requests-exchange': 'requests'}, 'runtime-config': {'auth_file': '/etc/rabbitmq-secret/authentications.json', 'cmd_at_reconnect': [None, 'SYST:ERRor?', '*OPC?'], 'command_terminator': '\n', 'endpoints': [{'base_str': ':SENSe:FREQuency:STARt', 'calibration': '{}', 'log_routing_key_prefix': 'sensor_double_precision', 'module': 'SimpleSCPIEntity', 'name': 'na_start_freq'}, {'base_str': ':SENSe:FREQuency:STOP', 'calibration': '{}', 'log_routing_key_prefix': 'sensor_double_precision', 'module': 'SimpleSCPIEntity', 'name': 'na_stop_freq'}, {'base_str': ':SENSe:FREQuency:CENTer', 'calibration': '{}', 'module': 'SimpleSCPIEntity', 'name': 'na_center_freq'}, {'base_str': ':SENSe:FREQuency:SPAN', 'calibration': '{}', 'module': 'SimpleSCPIEntity', 'name': 'na_freq_span'}, {'base_str': ':SOUR1:POW', 'calibration': '{}', 'log_routing_key_prefix': 'sensor_double_precision', 'module': 'SimpleSCPIEntity', 'name': 'na_power'}, {'base_str': ':SENS:AVER:COUNT', 'calibration': '{}', 'log_routing_key_prefix': 'sensor_double_precision', 'module': 'SimpleSCPIEntity', 'name': 'na_averages'}, {'base_str': ':SENS:AVER:STAT', 'calibration': '{}', 'log_routing_key_prefix': 'sensor_double_precision', 'module': 'SimpleSCPIEntity', 'name': 'na_average_enable'}, {'base_str': ':SENS1:SWE:POIN', 'calibration': '{}', 'module': 'SimpleSCPIEntity', 'name': 'na_sweep_points'}, {'base_str': ':SENS1:BAND:RES', 'calibration': '{}', 'module': 'SimpleSCPIEntity', 'name': 'na_if_band'}, {'calibration': '{}', 'get_str': ':TRIG:SOUR BUS;:TRIG:SING;:STAT:OPER:COND?', 'module': 'FormatEntity', 'name': 'na_trigger'}, {'calibration': 'False if (int({}) & 0b10000) else True', 'get_str': ':STAT:OPER:COND?', 'module': 'FormatEntity', 'name': 'na_sweep_finished'}, {'calibration': '[{}]', 'get_str': ':SENS1:FREQ:DATA?', 'module': 'FormatEntity', 'name': 'na_freq_data'}, {'calibration': '[{}]', 'get_str': ':CALC1:PAR1:DEF S21; *OPC?; :CALC1:DATA:SDAT?', 'log_routing_key_prefix': 'sensor_double_precision_arr', 'module': 'FormatEntity', 'name': 'na_s21_iq_data'}, {'calibration': '[{}]', 'get_str': ':CALC1:PAR1:DEF S11; *OPC?; :CALC1:DATA:SDAT?', 'log_routing_key_prefix': 'sensor_double_precision_arr', 'module': 'FormatEntity', 'name': 'na_s11_iq_data'}, {'module': 'FormatEntity', 'name': 'na_commands', 'set_str': '{}', 'set_value_map': {'autoscale': ':DISP:WIND1:TRAC1:Y:AUTO'}}], 'module': 'EthernetSCPIService', 'name': 'na', 'reconnect_test': '+1', 'response_terminator': '\n', 'socket_info': '("192.168.25.7",5025)', 'socket_timeout': 3}}
2020-07-21T22:50:06[DEBUG ] dripline(35) -> creating object from:
{'auth_file': '/etc/rabbitmq-secret/authentications.json', 'cmd_at_reconnect': [None, 'SYST:ERRor?', '*OPC?'], 'command_terminator': '\n', 'module': 'EthernetSCPIService', 'name': 'na', 'reconnect_test': '+1', 'response_terminator': '\n', 'socket_info': '("192.168.25.7",5025)', 'socket_timeout': 3}
...
name : na_start_freq
}
{
base_str : :SENSe:FREQuency:STOP
calibration : {}
log_routing_key_prefix : sensor_double_precision
module : SimpleSCPIEntity
name : na_stop_freq
}
{
base_str : :SENSe:FREQuency:CENTer
calibration : {}
module : SimpleSCPIEntity
name : na_center_freq
}
{
base_str : :SENSe:FREQuency:SPAN
calibration : {}
module : SimpleSCPIEntity
name : na_freq_span
}
{
base_str : :SOUR1:POW
calibration : {}
log_routing_key_prefix : sensor_double_precision
module : SimpleSCPIEntity
name : na_power
}
{
base_str : :SENS:AVER:COUNT
calibration : {}
log_routing_key_prefix : sensor_double_precision
module : SimpleSCPIEntity
name : na_averages
}
{
base_str : :SENS:AVER:STAT
calibration : {}
log_routing_key_prefix : sensor_double_precision
module : SimpleSCPIEntity
name : na_average_enable
}
{
base_str : :SENS1:SWE:POIN
calibration : {}
module : SimpleSCPIEntity
name : na_sweep_points
}
{
base_str : :SENS1:BAND:RES
calibration : {}
module : SimpleSCPIEntity
name : na_if_band
}
{
2020-07-21T22:50:06[DEBUG ] dripline.implementations.ethernet_scpi_service(52) -> Formatting socket_info: ("192.168.25.7",5025)
calibration : {}
get_str : :TRIG:SOUR BUS;:TRIG:SING;:STAT:OPER:COND?
module : FormatEntity
name : na_trigger
}
{
calibration : False if (int({}) & 0b10000) else True
get_str : :STAT:OPER:COND?
module : FormatEntity
name : na_sweep_finished
}
{
calibration : [{}]
get_str : :SENS1:FREQ:DATA?
module : FormatEntity
name : na_freq_data
}
{
calibration : [{}]
get_str : :CALC1:PAR1:DEF S21; *OPC?; :CALC1:DATA:SDAT?
log_routing_key_prefix : sensor_double_precision_arr
module : FormatEntity
name : na_s21_iq_data
}
{
calibration : [{}]
get_str : :CALC1:PAR1:DEF S11; *OPC?; :CALC1:DATA:SDAT?
log_routing_key_prefix : sensor_double_precision_arr
module : FormatEntity
name : na_s11_iq_data
}
{
module : FormatEntity
name : na_commands
set_str : {}
set_value_map :
{
autoscale : :DISP:WIND1:TRAC1:Y:AUTO
}
}
]
module : EthernetSCPIService
name : na
reconnect_test : +1
response_terminator :
socket_info : ("192.168.25.7",5025)
socket_timeout : 3
}
}
2020-07-21 22:50:06 [ PROG] i/application.cc(129): Ordered args:
[
]
2020-07-21T22:50:06[INFO ] dripline.implementations.ethernet_scpi_service(86) -> Ethernet socket ('192.168.25.7', 5025) established
2020-07-21T22:50:06[DEBUG ] dripline.implementations.ethernet_scpi_service(96) -> Emptying reconnect buffer
2020-07-21T22:50:09[WARNING ] dripline.implementations.ethernet_scpi_service(194) -> socket.timeout condition met; received:
''
2020-07-21T22:50:09[DEBUG ] dripline.implementations.ethernet_scpi_service(198) -> ''
2020-07-21T22:50:09[DEBUG ] dripline.implementations.ethernet_scpi_service(158) -> sending: b'SYST:ERRor?\n'
2020-07-21T22:50:09[DEBUG ] dripline.implementations.ethernet_scpi_service(198) -> '+0,"No error"\n'
2020-07-21T22:50:09[INFO ] dripline.implementations.ethernet_scpi_service(172) -> sync: 'SYST:ERRor?\n' -> '+0,"No error"'
2020-07-21T22:50:09[DEBUG ] dripline.implementations.ethernet_scpi_service(158) -> sending: b'*OPC?\n'
2020-07-21T22:50:09[DEBUG ] dripline.implementations.ethernet_scpi_service(198) -> '+1\n'
2020-07-21T22:50:09[INFO ] dripline.implementations.ethernet_scpi_service(172) -> sync: '*OPC?\n' -> '+1'
2020-07-21T22:50:09[INFO ] dripline(99) -> service built
2020-07-21T22:50:09[DEBUG ] dripline(35) -> creating object from:
{'base_str': ':SENSe:FREQuency:STARt', 'calibration': '{}', 'log_routing_key_prefix': 'sensor_double_precision', 'module': 'SimpleSCPIEntity', 'name': 'na_start_freq'}
...
2020-07-21T22:50:09[DEBUG ] dripline(35) -> creating object from:
{'base_str': ':SENSe:FREQuency:STOP', 'calibration': '{}', 'log_routing_key_prefix': 'sensor_double_precision', 'module': 'SimpleSCPIEntity', 'name': 'na_stop_freq'}
...
2020-07-21T22:50:09[DEBUG ] dripline(35) -> creating object from:
{'base_str': ':SENSe:FREQuency:CENTer', 'calibration': '{}', 'module': 'SimpleSCPIEntity', 'name': 'na_center_freq'}
...
2020-07-21T22:50:09[DEBUG ] dripline(35) -> creating object from:
{'base_str': ':SENSe:FREQuency:SPAN', 'calibration': '{}', 'module': 'SimpleSCPIEntity', 'name': 'na_freq_span'}
...
2020-07-21T22:50:09[DEBUG ] dripline(35) -> creating object from:
{'base_str': ':SOUR1:POW', 'calibration': '{}', 'log_routing_key_prefix': 'sensor_double_precision', 'module': 'SimpleSCPIEntity', 'name': 'na_power'}
...
2020-07-21T22:50:09[DEBUG ] dripline(35) -> creating object from:
{'base_str': ':SENS:AVER:COUNT', 'calibration': '{}', 'log_routing_key_prefix': 'sensor_double_precision', 'module': 'SimpleSCPIEntity', 'name': 'na_averages'}
...
2020-07-21T22:50:09[DEBUG ] dripline(35) -> creating object from:
{'base_str': ':SENS:AVER:STAT', 'calibration': '{}', 'log_routing_key_prefix': 'sensor_double_precision', 'module': 'SimpleSCPIEntity', 'name': 'na_average_enable'}
...
2020-07-21T22:50:09[DEBUG ] dripline(35) -> creating object from:
{'base_str': ':SENS1:SWE:POIN', 'calibration': '{}', 'module': 'SimpleSCPIEntity', 'name': 'na_sweep_points'}
...
2020-07-21T22:50:09[DEBUG ] dripline(35) -> creating object from:
{'base_str': ':SENS1:BAND:RES', 'calibration': '{}', 'module': 'SimpleSCPIEntity', 'name': 'na_if_band'}
...
2020-07-21T22:50:09[DEBUG ] dripline(35) -> creating object from:
{'calibration': '{}', 'get_str': ':TRIG:SOUR BUS;:TRIG:SING;:STAT:OPER:COND?', 'module': 'FormatEntity', 'name': 'na_trigger'}
...
2020-07-21T22:50:09[DEBUG ] dripline(35) -> creating object from:
{'calibration': 'False if (int({}) & 0b10000) else True', 'get_str': ':STAT:OPER:COND?', 'module': 'FormatEntity', 'name': 'na_sweep_finished'}
...
2020-07-21T22:50:09[DEBUG ] dripline(35) -> creating object from:
{'calibration': '[{}]', 'get_str': ':SENS1:FREQ:DATA?', 'module': 'FormatEntity', 'name': 'na_freq_data'}
...
2020-07-21T22:50:09[DEBUG ] dripline(35) -> creating object from:
{'calibration': '[{}]', 'get_str': ':CALC1:PAR1:DEF S21; *OPC?; :CALC1:DATA:SDAT?', 'log_routing_key_prefix': 'sensor_double_precision_arr', 'module': 'FormatEntity', 'name': 'na_s21_iq_data'}
...
2020-07-21T22:50:09[DEBUG ] dripline(35) -> creating object from:
{'calibration': '[{}]', 'get_str': ':CALC1:PAR1:DEF S11; *OPC?; :CALC1:DATA:SDAT?', 'log_routing_key_prefix': 'sensor_double_precision_arr', 'module': 'FormatEntity', 'name': 'na_s11_iq_data'}
...
2020-07-21T22:50:09[DEBUG ] dripline(35) -> creating object from:
{'module': 'FormatEntity', 'name': 'na_commands', 'set_str': '{}', 'set_value_map': {'autoscale': ':DISP:WIND1:TRAC1:Y:AUTO'}}
...
2020-07-21T22:50:09[INFO ] dripline(110) -> about to start the service
2020-07-21T22:50:10[INFO ] dripline(112) -> services started, now to listen
2020-07-21T22:50:36[DEBUG ] dripline.core.endpoint(49) -> new_value is [autoscale]
2020-07-21T22:50:36[DEBUG ] dripline.implementations.entity_endpoints(158) -> value is autoscale; mapped value is: :DISP:WIND1:TRAC1:Y:AUTO
2020-07-21T22:50:36[DEBUG ] dripline.implementations.ethernet_scpi_service(158) -> sending: b':DISP:WIND1:TRAC1:Y:AUTO\n'
2020-07-21T22:50:39[WARNING ] dripline.implementations.ethernet_scpi_service(194) -> socket.timeout condition met; received:
''
2020-07-21T22:50:39[CRITICAL] dripline.implementations.ethernet_scpi_service(129) -> Unexpected socket.timeout
2020-07-21T22:50:39[INFO ] dripline.implementations.ethernet_scpi_service(86) -> Ethernet socket ('192.168.25.7', 5025) established
2020-07-21T22:50:39[DEBUG ] dripline.implementations.ethernet_scpi_service(96) -> Emptying reconnect buffer
2020-07-21T22:50:42[WARNING ] dripline.implementations.ethernet_scpi_service(194) -> socket.timeout condition met; received:
''
2020-07-21T22:50:42[DEBUG ] dripline.implementations.ethernet_scpi_service(198) -> ''
2020-07-21T22:50:42[DEBUG ] dripline.implementations.ethernet_scpi_service(158) -> sending: b'SYST:ERRor?\n'
2020-07-21T22:50:42[DEBUG ] dripline.implementations.ethernet_scpi_service(198) -> '+0,"No error"\n'
2020-07-21T22:50:42[INFO ] dripline.implementations.ethernet_scpi_service(172) -> sync: 'SYST:ERRor?\n' -> '+0,"No error"'
2020-07-21T22:50:42[DEBUG ] dripline.implementations.ethernet_scpi_service(158) -> sending: b'*OPC?\n'
2020-07-21T22:50:42[DEBUG ] dripline.implementations.ethernet_scpi_service(198) -> '+1\n'
2020-07-21T22:50:42[INFO ] dripline.implementations.ethernet_scpi_service(172) -> sync: '*OPC?\n' -> '+1'
2020-07-21T22:50:42[DEBUG ] dripline.implementations.ethernet_scpi_service(158) -> sending: b':DISP:WIND1:TRAC1:Y:AUTO\n'
2020-07-21T22:50:45[WARNING ] dripline.implementations.ethernet_scpi_service(194) -> socket.timeout condition met; received:
''
2020-07-21T22:50:45[CRITICAL] dripline.implementations.ethernet_scpi_service(138) -> Query failed after successful ethernet socket reconnect
2020-07-21 22:50:45 [ERROR] rary/endpoint.cc(191): Caught exception from Python: TypeError: set_reply_cache(): incompatible function arguments. The following argument types are supported:
1. (return_code: _dripline.core.ReturnCode, return_message: str, payload: scarab.Param) -> None
Invoked with: <_dripline.core.DL_ResourceErrorNoResponse object at 0x7ff90129b530>, ThrowReply('Unexpected socket.timeout'), <scarab.Param object at 0x7ff9022eddf0>
At:
/usr/local/lib/python3.7/site-packages/dripline/core/throw_reply.py(29): __init__
/usr/local/lib/python3.7/site-packages/dripline/implementations/ethernet_scpi_service.py(141): send_to_device
/usr/local/lib/python3.7/site-packages/dripline/implementations/entity_endpoints.py(159): on_set
/usr/local/lib/python3.7/site-packages/dripline/core/endpoint.py(56): do_set_request
2020-07-21 22:50:45 [ERROR] brary/service.cc(467): <na> Standard exception caught while handling message: TypeError: set_reply_cache(): incompatible function arguments. The following argument types are supported:
1. (return_code: _dripline.core.ReturnCode, return_message: str, payload: scarab.Param) -> None
Invoked with: <_dripline.core.DL_ResourceErrorNoResponse object at 0x7ff90129b530>, ThrowReply('Unexpected socket.timeout'), <scarab.Param object at 0x7ff9022eddf0>
At:
/usr/local/lib/python3.7/site-packages/dripline/core/throw_reply.py(29): __init__
/usr/local/lib/python3.7/site-packages/dripline/implementations/ethernet_scpi_service.py(141): send_to_device
/usr/local/lib/python3.7/site-packages/dripline/implementations/entity_endpoints.py(159): on_set
/usr/local/lib/python3.7/site-packages/dripline/core/endpoint.py(56): do_set_request
2020-07-21 22:50:45 [ERROR] rary/receiver.cc(399): Exception caught; shutting down.
TypeError: set_reply_cache(): incompatible function arguments. The following argument types are supported:
1. (return_code: _dripline.core.ReturnCode, return_message: str, payload: scarab.Param) -> None
Invoked with: <_dripline.core.DL_ResourceErrorNoResponse object at 0x7ff90129b530>, ThrowReply('Unexpected socket.timeout'), <scarab.Param object at 0x7ff9022eddf0>
At:
/usr/local/lib/python3.7/site-packages/dripline/core/throw_reply.py(29): __init__
/usr/local/lib/python3.7/site-packages/dripline/implementations/ethernet_scpi_service.py(141): send_to_device
/usr/local/lib/python3.7/site-packages/dripline/implementations/entity_endpoints.py(159): on_set
/usr/local/lib/python3.7/site-packages/dripline/core/endpoint.py(56): do_set_request
So based on this more verbose output:
1) your problem is that you're sending a command that produces no response from the device, and so the code doesn't know if it has succeeded or failed silently. The command needs to end with ;*OPC?
or something that will force it to reply
2) This error handling isn't great, the service should have raised a ThrowReply indicating that it didn't get a response.
Just as an update, adding ;*OPC? fixed the error, but leaving this here because the error handling isn't great.
I want to use dripline to send :DISP:WIND1:TRAC1:Y:AUTO command to my VNA (it autoscales the screen). A straightforward get or set is not appropriate because I am not getting a value and I am not setting a parameter to a value. I have tried to configure and endpoint like this:
If I run
set na_commands autoscale
, then I get a scarab error that I don't understand.My pod logs look like this
I do not run into any other socket timeout errors if I connect to other endpoints.