@KozlovAO thanks for reporting.

Very interesting. I don't think we have any tests for this currently.
Would you mind enabling TRACE level logging and see if you can find where the ESL protocol cmd is submitted to FS?

Thanks for the quick response! :)
Traceback with loglever == TRACE:

Jan 23 17:25:40 (switchio_event_loop[172.16.4.33]) [DEBUG] switchio.Connection@172.16.4.33 connection.py:225 : api cmd 'uuid_broadcast bac24ca0-e411-407e-ab56-73f5947fb5d8 set::test_var=test_val '
Jan 23 17:25:40 (switchio_event_loop[172.16.4.33]) [TRACE] switchio.InboundProtocol@172.16.4.33 protocol.py:225 : Data sent: b'api uuid_broadcast bac24ca0-e411-407e-ab56-73f5947fb5d8 set::test_var=test_val \n\n'
Jan 23 17:25:40 (switchio_event_loop[172.16.4.33]) [DEBUG] switchio.Connection@172.16.4.33 connection.py:225 : api cmd 'uuid_getvar bac24ca0-e411-407e-ab56-73f5947fb5d8 test_var'
Jan 23 17:25:40 (switchio_event_loop[172.16.4.33]) [TRACE] switchio.InboundProtocol@172.16.4.33 protocol.py:225 : Data sent: b'api uuid_getvar bac24ca0-e411-407e-ab56-73f5947fb5d8 test_var\n\n'
Jan 23 17:25:40 (switchio_event_loop[172.16.4.33]) [ERROR] switchio.EventLoop@172.16.4.33 loop.py:52 : <Task finished coro=<on_park() done, defined at ./ontime/daemons/robot_esl_server_async.py:359> exception=TimeoutError()> failed with:
Traceback (most recent call last):
  File "/usr/local/lib/python3.5/dist-packages/switchio/loop.py", line 49, in handle_result
    task.result()
  File "/usr/lib/python3.5/asyncio/futures.py", line 293, in result
    raise self._exception
  File "/usr/lib/python3.5/asyncio/tasks.py", line 239, in _step
    result = coro.send(None)
  File "./ontime/daemons/robot_esl_server_async.py", line 362, in on_park
    print(sess.getvar("test_var"))
  File "/usr/local/lib/python3.5/dist-packages/switchio/models.py", line 226, in getvar
    val = self.con.cmd("uuid_getvar {} {}".format(self.uuid, var))
  File "/usr/local/lib/python3.5/dist-packages/switchio/connection.py", line 246, in cmd
    event = self.api(cmd, block=True)
  File "/usr/local/lib/python3.5/dist-packages/switchio/connection.py", line 235, in api
    block=block,
  File "/usr/local/lib/python3.5/dist-packages/switchio/connection.py", line 53, in run_in_order_threadsafe
    future.result(timeout)
  File "/usr/lib/python3.5/concurrent/futures/_base.py", line 407, in result
    raise TimeoutError()
concurrent.futures._base.TimeoutError
Jan 23 17:25:40 (switchio_event_loop[172.16.4.33]) [TRACE] switchio.InboundProtocol@172.16.4.33 protocol.py:169 : Socket data received:
Content-Type: api/response
Content-Length: 17

+OK Message sent

Jan 23 17:25:40 (switchio_event_loop[172.16.4.33]) [TRACE] switchio.InboundProtocol@172.16.4.33 protocol.py:169 : Socket data received:
Content-Type: api/response
Content-Length: 7

_undef_

It is not clear why he returned "undef"... If execute "uuid_getvar bac24ca0-e411-407e-ab56-73f5947fb5d8 test_var" in fs_cli - returns "test_val" (as need)

I don't think we have any tests for this currently.

I can provide everything for the tests.

@KozlovAO it seems that the api call is working but it's just too slow in responding.

Maybe try adjusting the timeout by making the val = self.con.cmd("uuid_getvar {} {}".format(self.uuid, var)) manually?

It's possible this is just a latency problem with FS - the variable isn't being set on the server side yet?

It's possible this is just a latency problem with FS - the variable isn't being set on the server side yet
no... it's good

Here is that found:

1. script execute "sess.setvar("test_var", "test_val")" + time.sleep(10)
2. while script sleep: execute in fs_cli "uuid_getvar 3a0d7df5-1baf-4430-8941-8b75df3fe3e0 test_var". return: undef !!! :)
3. after sleep, execute in script "val = sess.con.cmd("uuid_getvar {} {}".format(sess.uuid, "test_var"))". As soon as an error (concurrent.futures._base.TimeoutError) - in fs_cli, command from Import issues from switchy #2 return "test_val".

Screen, with error: https://i.imgur.com/IL3vYqk.png
Screen, from fs_cli: https://i.imgur.com/sSyyyHa.png

Еt seems the exchange is done as follows:
1 - sending setvar
2 - getting getvar
3 - getting confirmation on setvar
4 - getting result for getvar

Tried to do "sess.con.cmd("uuid_setvar {} {} {}".format(sess.uuid, "test_var", "test_val"))"...
result: concurrent.futures._base.TimeoutError

Screen: https://i.imgur.com/T9rYESd.png

Ahh I see what you mean. So it's a synchronization problem. We need to block for the setvar to complete first, before issuing getvar.

Hmm, let me just check the code.

@KozlovAO try await sess.setvar() instead.

Oh wait, shoot. We need to change Session.setvar() to return from that call to execute(). This way we return a future that can be awaited.

Do you have a copy of the source to try this?

@KozlovAO try this: await sess.execute('set', '='.join((var, value)))

Yes, that's better. But the error persists: https://i.imgur.com/Mbl4uZl.png

Execution code:

await sess.execute('set', '='.join(("test_var", "test_val")))
val = sess.con.cmd("uuid_getvar {} {}".format(sess.uuid, "test_var"))

Yeah, so now the problem is that the sess.con.cmd() is too slow.

Maybe try,

val = await sess.con.api("uuid_getvar {} {}".format(sess.uuid, "test_var"))

That shouldn't block by default and you can again await the future for the response.
Hmm, that might give you back an event though - this needs to be wrapped correctly if it works.

Yes, it works, but only if you put "time.sleep(1)" between "setvar" and "getvar" ...

await sess.execute('set', '='.join(("test_var", "test_val")))
time.sleep(1)  # if you do not-the result will be __undef__
val = await sess.con.api ("uuid_getvar {} {}". format (sess.uuid, "test_var"))
print(val)

result: "{'Content-Type': 'api/response', 'Content-Length': '8', 'Body': 'test_val\n'}"

but only if you put "time.sleep(1)" between "setvar" and "getvar"

Yeah, so as I suspected that means FS is not blocking until the value is set and is too slow to have had the value set by the time you call getvar().
Btw If you need this to work async you can of course use asyncio.sleep(1) instead.
If you really wanted it to work this way you could async poll in a loop until the value is not _undef_, but honestly that seems a little silly.

Is there a reason you need to use a channel variable for whatever you are doing?
Normally if you need a variable associated with a Session you can just read it using the api which gives access to channel data. If you're trying to set variables for call control I'd just recommend keeping it all in python.

Is there a reason you need to use a channel variable for whatever you are doing?

No, it's only for test

Typically, one event stores a variable and the other one reads it.
Some events do not have the required variables in headers and need to be read from the channel.

Cool.

Yeah so we need a PR to fix the Session.getvar() api I think to return a future then.
If you feel up to it I'll gladly accept that change 👍

hmm... what is PR? ))

https://help.github.com/articles/about-pull-requests/

@KozlovAO btw if you'd like to chat more real-time see our riot room.