Can't get variable through getvar() function -> `Session.getvar()` should return a `Future`. #64

KozlovAO · 2019-01-23T13:05:07Z

Hi!
I'm trying to get a variable through * .getvar() and everything ends in an error.
My code:

@coroutine('CHANNEL_PARK')
async def on_park(self, sess):
    sess.setvar("test_var", "test_val")
    print(sess.getvar("test_var"))

Traceback:

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 360, 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

The request for receiving is not visible in the FreeSwitch console...

The text was updated successfully, but these errors were encountered:

goodboy · 2019-01-23T14:09:14Z

@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?

KozlovAO · 2019-01-23T14:34:20Z

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.

goodboy · 2019-01-23T15:51:08Z

@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?

KozlovAO · 2019-01-23T16:13:11Z

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:

script execute "sess.setvar("test_var", "test_val")" + time.sleep(10)
while script sleep: execute in fs_cli "uuid_getvar 3a0d7df5-1baf-4430-8941-8b75df3fe3e0 test_var". return: undef !!! :)
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

KozlovAO · 2019-01-23T16:34:25Z

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

goodboy · 2019-01-23T16:42:31Z

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.

goodboy · 2019-01-23T16:52:18Z

@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?

goodboy · 2019-01-23T17:21:49Z

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

KozlovAO · 2019-01-23T17:42:56Z

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"))

goodboy · 2019-01-23T17:58:34Z

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.

KozlovAO · 2019-01-23T19:36:52Z

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'}"

goodboy · 2019-01-23T20:41:41Z

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.

KozlovAO · 2019-01-23T20:58:15Z

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.

goodboy · 2019-01-23T21:12:30Z

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 👍

KozlovAO · 2019-01-23T21:18:44Z

hmm... what is PR? ))

goodboy · 2019-01-23T21:45:37Z

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

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

KozlovAO changed the title ~~Don't work "cmd" function with block=True, from "Connection" class~~ Can't get variable through getvar() function Jan 23, 2019

goodboy added bug docs labels Jan 23, 2019

goodboy changed the title ~~Can't get variable through getvar() function~~ Can't get variable through getvar() function -> Session.getvar() should return a Future. May 31, 2021

goodboy added the help wanted label May 31, 2021

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Can't get variable through getvar() function -> `Session.getvar()` should return a `Future`. #64

Can't get variable through getvar() function -> `Session.getvar()` should return a `Future`. #64

KozlovAO commented Jan 23, 2019

goodboy commented Jan 23, 2019

KozlovAO commented Jan 23, 2019 •

edited

goodboy commented Jan 23, 2019 •

edited

KozlovAO commented Jan 23, 2019 •

edited

KozlovAO commented Jan 23, 2019

goodboy commented Jan 23, 2019

goodboy commented Jan 23, 2019 •

edited

goodboy commented Jan 23, 2019

KozlovAO commented Jan 23, 2019 •

edited

goodboy commented Jan 23, 2019 •

edited

KozlovAO commented Jan 23, 2019 •

edited

goodboy commented Jan 23, 2019

KozlovAO commented Jan 23, 2019

goodboy commented Jan 23, 2019

KozlovAO commented Jan 23, 2019

goodboy commented Jan 23, 2019

Can't get variable through getvar() function -> Session.getvar() should return a Future. #64

Can't get variable through getvar() function -> Session.getvar() should return a Future. #64

Comments

KozlovAO commented Jan 23, 2019

goodboy commented Jan 23, 2019

KozlovAO commented Jan 23, 2019 • edited

goodboy commented Jan 23, 2019 • edited

KozlovAO commented Jan 23, 2019 • edited

KozlovAO commented Jan 23, 2019

goodboy commented Jan 23, 2019

goodboy commented Jan 23, 2019 • edited

goodboy commented Jan 23, 2019

KozlovAO commented Jan 23, 2019 • edited

goodboy commented Jan 23, 2019 • edited

KozlovAO commented Jan 23, 2019 • edited

goodboy commented Jan 23, 2019

KozlovAO commented Jan 23, 2019

goodboy commented Jan 23, 2019

KozlovAO commented Jan 23, 2019

goodboy commented Jan 23, 2019

Can't get variable through getvar() function -> `Session.getvar()` should return a `Future`. #64

Can't get variable through getvar() function -> `Session.getvar()` should return a `Future`. #64

KozlovAO commented Jan 23, 2019 •

edited

goodboy commented Jan 23, 2019 •

edited

KozlovAO commented Jan 23, 2019 •

edited

goodboy commented Jan 23, 2019 •

edited

KozlovAO commented Jan 23, 2019 •

edited

goodboy commented Jan 23, 2019 •

edited

KozlovAO commented Jan 23, 2019 •

edited