Open KozlovAO opened 5 years ago
@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:
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 :+1:
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.
Hi! I'm trying to get a variable through * .getvar() and everything ends in an error. My code:
Traceback:
The request for receiving is not visible in the FreeSwitch console...