search

dkumor / rtcbot

A python WebRTC remote control library
https://rtcbot.readthedocs.io/en/latest/?badge=latest
MIT License
72 stars 30 forks source link

Asyncio: OpenSSL.SSL.WantReadError w/ RuntimeError #48

Closed mbz4 closed 8 months ago

mbz4 commented 1 year ago

Thank you for the amazing work!

I'm trying to run rc.py on a pi4B 2GB RAM (64bit bullseye) in examples/remotecontrol/rc.py

But got the following tracebacks from asyncio:

======== Running on http://0.0.0.0:8080 ========
(Press CTRL+C to quit)
Task exception was never retrieved
future: \<Task finished name='Task-17' coro=\<RTCPeerConnection.\_\_connect() done, defined at /home/pi/env/lib/python3.9/site-packages/aiortc/rtcpeerconnection.py:1000> exception=RuntimeError("Task \<Task pending name='Task-24' coro=\<Connection.recv() running at /home/pi/env/lib/python3.9/site-packages/aioice/ice.py:575> cb=\[\_release\_waiter(\<Future pendi...f881244c0>()\]>)() at /usr/lib/python3.9/asyncio/tasks.py:416\]> got Future \<Future pending> attached to a different loop")>
Traceback (most recent call last):
File "/home/pi/env/lib/python3.9/site-packages/aiortc/rtcdtlstransport.py", line 368, in start
self.ssl.do\_handshake()
File "/home/pi/env/lib/python3.9/site-packages/OpenSSL/SSL.py", line 2182, in do\_handshake
self.\_raise\_ssl\_error(self.\_ssl, result)
File "/home/pi/env/lib/python3.9/site-packages/OpenSSL/SSL.py", line 1790, in \_raise\_ssl\_error
raise WantReadError()
OpenSSL.SSL.WantReadError

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
File "/home/pi/env/lib/python3.9/site-packages/aiortc/rtcpeerconnection.py", line 1010, in \_\_connect
await dtlsTransport.start(self.\_\_remoteDtls\[transceiver\])
File "/home/pi/env/lib/python3.9/site-packages/aiortc/rtcdtlstransport.py", line 371, in start
await self.\_recv\_next()
File "/home/pi/env/lib/python3.9/site-packages/aiortc/rtcdtlstransport.py", line 510, in \_recv\_next
data = await asyncio.wait\_for(self.transport.\_recv(), timeout=timeout)
File "/usr/lib/python3.9/asyncio/tasks.py", line 481, in wait\_for
return fut.result()
File "/home/pi/env/lib/python3.9/site-packages/aioice/ice.py", line 575, in recv
data, component = await self.recvfrom()
File "/home/pi/env/lib/python3.9/site-packages/aioice/ice.py", line 591, in recvfrom
result = await self.\_queue.get()
File "/usr/lib/python3.9/asyncio/queues.py", line 166, in get
await getter
RuntimeError: Task \<Task pending name='Task-24' coro=\<Connection.recv() running at /home/pi/env/lib/python3.9/site-packages/aioice/ice.py:575> cb=\[\_release\_waiter(\<Future pendi...f881244c0>()\]>)() at /usr/lib/python3.9/asyncio/tasks.py:416\]> got Future \<Future pending> attached to a different loop
mbz4 commented 1 year ago

Replicated error w/ skeleton.py:

(env) pi@donkeypi:~/projects/rtcbot/examples/streaming $ python skeleton.py 
======== Running on http://0.0.0.0:8080 ========
(Press CTRL+C to quit)
Got unrecognized error from task.
Traceback (most recent call last):
  File "/home/pi/env/lib/python3.9/site-packages/rtcbot/base/base.py", line 365, in _get
    await self._getTask
  File "/usr/lib/python3.9/asyncio/queues.py", line 166, in get
    await getter
RuntimeError: Task <Task pending name='Task-30' coro=<Queue.get() running at /usr/lib/python3.9/asyncio/queues.py:166> cb=[<TaskWakeupMethWrapper object at 0x7f8f1e6730>()]> got Future <Future pending> attached to a different loop
Got unrecognized error from task.
Traceback (most recent call last):
  File "/home/pi/env/lib/python3.9/site-packages/rtcbot/base/base.py", line 365, in _get
    await self._getTask
  File "/home/pi/env/lib/python3.9/site-packages/rtcbot/base/base.py", line 28, in get
    return await self._callback()
  File "/home/pi/env/lib/python3.9/site-packages/rtcbot/base/base.py", line 365, in _get
    await self._getTask
  File "/usr/lib/python3.9/asyncio/queues.py", line 166, in get
    await getter
RuntimeError: Task <Task pending name='Task-30' coro=<Queue.get() running at /usr/lib/python3.9/asyncio/queues.py:166> cb=[<TaskWakeupMethWrapper object at 0x7f8f1e6730>()]> got Future <Future pending> attached to a different loop
Task exception was never retrieved
future: <Task finished name='Task-28' coro=<DataChannel._messageSender() done, defined at /home/pi/env/lib/python3.9/site-packages/rtcbot/connection.py:56> exception=RuntimeError("Task <Task pending name='Task-30' coro=<Queue.get() running at /usr/lib/python3.9/asyncio/queues.py:166> cb=[<TaskWakeupMethWrapper object at 0x7f8f1e6730>()]> got Future <Future pending> attached to a different loop")>
Traceback (most recent call last):
  File "/home/pi/env/lib/python3.9/site-packages/rtcbot/connection.py", line 61, in _messageSender
    msg = await self._get()
  File "/home/pi/env/lib/python3.9/site-packages/rtcbot/base/base.py", line 365, in _get
    await self._getTask
  File "/home/pi/env/lib/python3.9/site-packages/rtcbot/base/base.py", line 28, in get
    return await self._callback()
  File "/home/pi/env/lib/python3.9/site-packages/rtcbot/base/base.py", line 365, in _get
    await self._getTask
  File "/usr/lib/python3.9/asyncio/queues.py", line 166, in get
    await getter
RuntimeError: Task <Task pending name='Task-30' coro=<Queue.get() running at /usr/lib/python3.9/asyncio/queues.py:166> cb=[<TaskWakeupMethWrapper object at 0x7f8f1e6730>()]> got Future <Future pending> attached to a different loop
mbz4 commented 1 year ago

pip list

(env) pi@donkeypi:~/projects/rtcbot/examples/streaming $ pip list
Package                          Version   Editable project location
-------------------------------- --------- ---------------------------
absl-py                          1.4.0
Adafruit-Blinka                  8.20.1
adafruit-circuitpython-busdevice 5.2.6
adafruit-circuitpython-framebuf  1.6.3
adafruit-circuitpython-register  1.9.16
adafruit-circuitpython-requests  2.0.1
adafruit-circuitpython-rplidar   1.2.12
adafruit-circuitpython-ssd1306   2.12.14
adafruit-circuitpython-typing    1.9.4
Adafruit-GPIO                    1.0.3
Adafruit-PCA9685                 1.0.1
Adafruit-PlatformDetect          3.49.0
Adafruit-PureIO                  1.1.11
aiohttp                          3.8.5
aioice                           0.9.0
aiortc                           1.5.0
aiosignal                        1.3.1
astunparse                       1.6.3
async-timeout                    4.0.2
attrs                            23.1.0
av                               10.0.0
cachetools                       5.3.1
certifi                          2020.6.20
cffi                             1.15.1
chardet                          4.0.0
charset-normalizer               3.2.0
colorzero                        1.1
cryptography                     41.0.3
distlib                          0.3.7
distro                           1.5.0
dnspython                        2.4.1
docopt                           0.6.2
donkeycar                        5.0.dev3  /home/pi/projects/donkeycar
filelock                         3.12.2
flatbuffers                      1.12
frozenlist                       1.4.0
gast                             0.4.0
google-auth                      2.22.0
google-auth-oauthlib             0.4.6
google-crc32c                    1.5.0
google-pasta                     0.2.0
gpiozero                         1.6.2
grpcio                           1.56.2
h5py                             3.9.0
idna                             2.10
ifaddr                           0.2.0
importlib-metadata               6.8.0
inputs                           0.5
keras                            2.9.0
Keras-Preprocessing              1.1.2
libclang                         16.0.6
Markdown                         3.4.4
MarkupSafe                       2.1.3
multidict                        6.0.4
numpy                            1.25.2
oauthlib                         3.2.2
opencv-python-headless           4.8.0.74
opt-einsum                       3.3.0
packaging                        23.1
paho-mqtt                        1.6.1
pandas                           2.0.3
picamera2                        0.3.12
pidng                            4.0.9
piexif                           1.1.3
Pillow                           8.1.2
pip                              23.2.1
platformdirs                     3.10.0
prettytable                      3.8.0
progress                         1.6
protobuf                         3.19.6
psutil                           5.9.5
pyasn1                           0.5.0
pyasn1-modules                   0.3.0
pycparser                        2.21
pyee                             11.0.0
pyfiglet                         0.8.post1
pyftdi                           0.54.0
pylibsrtp                        0.8.0
pynmea2                          1.19.0
pyOpenSSL                        23.2.0
pyserial                         3.5
pyserial-asyncio                 0.6
python-apt                       2.2.1
python-dateutil                  2.8.2
python-prctl                     1.7
pytz                             2023.3
pyusb                            1.2.1
PyYAML                           6.0.1
requests                         2.25.1
requests-oauthlib                1.3.1
RPi.GPIO                         0.7.0
rpi-ws281x                       5.0.0
rsa                              4.9
rtcbot                           0.2.5
setuptools                       68.0.0
simple-pid                       2.0.0
simplejpeg                       1.6.4
six                              1.16.0
SoundCard                        0.4.2
spidev                           3.5
ssh-import-id                    5.10
sysv-ipc                         1.1.0
tensorboard                      2.9.1
tensorboard-data-server          0.6.1
tensorboard-plugin-wit           1.8.1
tensorflow                       2.9.0
tensorflow-estimator             2.9.0
tensorflow-io-gcs-filesystem     0.33.0
termcolor                        2.3.0
toml                             0.10.1
tornado                          6.3.2
typing_extensions                4.7.1
tzdata                           2023.3
urllib3                          1.26.5
utm                              0.7.0
v4l2-python3                     0.3.2
virtualenv                       20.24.2
wcwidth                          0.2.6
Werkzeug                         2.3.6
wheel                            0.41.0
wrapt                            1.15.0
yarl                             1.9.2
zipp                             3.16.2
mbz4 commented 1 year ago

Does rtcbot exclusively support ubuntu & Raspbian Buster? @dkumor

mbz4 commented 1 year ago

Tried updating all libs.

Below traceback has added logging & extra print statements.

(env) pi@donkeypi:~/projects/rtcbot/examples/streaming $ python skeleton.py 
DEBUG:asyncio:Using selector: EpollSelector
DEBUG:rtcbot.RTCConnection.ConnectionVideoHandler.SubscriptionProducer:Adding onClose subscription
DEBUG:rtcbot.RTCConnection.ConnectionAudioHandler.SubscriptionProducer:Adding onClose subscription

Starting RTC Peer...

<rtcbot.connection.RTCConnection object at 0x7fa584c880>

DEBUG:rtcbot.RTCConnection.SubscriptionProducer:Adding onClose subscription
DEBUG:asyncio:Using selector: EpollSelector
======== Running on http://0.0.0.0:8080 ========
(Press CTRL+C to quit)
INFO:aiohttp.access:127.0.0.1 [11/Aug/2023:11:17:43 +0000] "GET / HTTP/1.1" 200 1290 "-" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/115.0.0.0 Safari/537.36"

Serving request:

<Request GET /rtcbot.js >

INFO:aiohttp.access:127.0.0.1 [11/Aug/2023:11:17:43 +0000] "GET /rtcbot.js HTTP/1.1" 200 6637 "http://localhost:8081/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/115.0.0.0 Safari/537.36"

collecting request...

<Request POST /connect >

clientOffer:

{'type': 'offer', 'sdp': 'v=0\r\no=- 25354505133507003 2 IN IP4 127.0.0.1\r\ns=-\r\nt=0 0\r\na=group:BUNDLE 0\r\na=extmap-allow-mixed\r\na=msid-semantic: WMS\r\nm=application 4451 UDP/DTLS/SCTP webrtc-datachannel\r\nc=IN IP4 193.40.12.11\r\na=candidate:1054543192 1 udp 2113937151 b166cd8f-f64b-4460-a32f-264313a91dd2.local 55330 typ host generation 0 network-cost 999\r\na=candidate:2300887 1 udp 1677729535 193.40.12.11 4451 typ srflx raddr 0.0.0.0 rport 0 generation 0 network-cost 999\r\na=ice-ufrag:Q8ig\r\na=ice-pwd:tN0hworugvq1QLL/QU0bBhoB\r\na=ice-options:trickle\r\na=fingerprint:sha-256 25:2D:3D:49:24:E4:80:EC:7A:0C:8C:A1:1F:B2:B9:3B:16:1E:72:C3:50:2C:8C:DC:F7:B0:BC:04:6E:3F:A4:E3\r\na=setup:actpass\r\na=mid:0\r\na=sctp-port:5000\r\na=max-message-size:262144\r\n'}

DEBUG:rtcbot.RTCConnection:Setting remote connection description
DEBUG:aiortc.rtcpeerconnection:RTCPeerConnection() setRemoteDescription(offer)
v=0
o=- 25354505133507003 2 IN IP4 127.0.0.1
s=-
t=0 0
a=group:BUNDLE 0
a=extmap-allow-mixed
a=msid-semantic: WMS
m=application 4451 UDP/DTLS/SCTP webrtc-datachannel
c=IN IP4 193.40.12.11
a=candidate:1054543192 1 udp 2113937151 b166cd8f-f64b-4460-a32f-264313a91dd2.local 55330 typ host generation 0 network-cost 999
a=candidate:2300887 1 udp 1677729535 193.40.12.11 4451 typ srflx raddr 0.0.0.0 rport 0 generation 0 network-cost 999
a=ice-ufrag:Q8ig
a=ice-pwd:tN0hworugvq1QLL/QU0bBhoB
a=ice-options:trickle
a=fingerprint:sha-256 25:2D:3D:49:24:E4:80:EC:7A:0C:8C:A1:1F:B2:B9:3B:16:1E:72:C3:50:2C:8C:DC:F7:B0:BC:04:6E:3F:A4:E3
a=setup:actpass
a=mid:0
a=sctp-port:5000
a=max-message-size:262144

INFO:aioice.ice:Connection(0) Remote candidate "b166cd8f-f64b-4460-a32f-264313a91dd2.local" could not be resolved
DEBUG:rtcbot.RTCConnection:Creating response to connection offer
DEBUG:aiortc.rtcpeerconnection:RTCPeerConnection() setLocalDescription(answer)
v=0
o=- 3900741464 3900741464 IN IP4 0.0.0.0
s=-
t=0 0
a=group:BUNDLE 0
a=msid-semantic:WMS *
m=application 9 UDP/DTLS/SCTP webrtc-datachannel
c=IN IP4 0.0.0.0
a=mid:0
a=sctp-port:5000
a=max-message-size:65536
a=ice-ufrag:zfBU
a=ice-pwd:LAldx4KbAxhCLkcnKKHyWp
a=fingerprint:sha-256 BC:19:97:0C:6F:C3:D7:17:02:76:D3:CA:90:A6:94:1C:E1:28:13:50:C2:CA:9A:58:B9:F7:D1:D0:81:CF:05:04
a=setup:active

DEBUG:aiortc.rtcpeerconnection:RTCPeerConnection() iceGatheringState new -> gathering
DEBUG:aioice.ice:Connection(0) protocol(0) connection_made(<_SelectorDatagramTransport fd=15 read=idle write=<idle, bufsize=0>>)
DEBUG:aioice.ice:Connection(0) protocol(0) > ('173.194.76.127', 19302) Message(message_method=Method.BINDING, message_class=Class.REQUEST, transaction_id=b'\xf6\x93Zr\x98dN\x9e\x93,3\xc1')
DEBUG:aioice.ice:Connection(0) protocol(0) < ('173.194.76.127', 19302) Message(message_method=Method.BINDING, message_class=Class.RESPONSE, transaction_id=b'\xf6\x93Zr\x98dN\x9e\x93,3\xc1')
DEBUG:aiortc.rtcpeerconnection:RTCPeerConnection() iceGatheringState gathering -> complete

serverResponse:

{'sdp': 'v=0\r\no=- 3900741464 3900741464 IN IP4 0.0.0.0\r\ns=-\r\nt=0 0\r\na=group:BUNDLE 0\r\na=msid-semantic:WMS *\r\nm=application 44175 UDP/DTLS/SCTP webrtc-datachannel\r\nc=IN IP4 192.168.53.97\r\na=mid:0\r\na=sctp-port:5000\r\na=max-message-size:65536\r\na=candidate:76eab371dee4aceafc80dd4a58ec4f3c 1 udp 2130706431 192.168.53.97 44175 typ host\r\na=candidate:22404e6ca03ddabe9491b09c62499695 1 udp 1694498815 193.40.12.11 6672 typ srflx raddr 192.168.53.97 rport 44175\r\na=end-of-candidates\r\na=ice-ufrag:zfBU\r\na=ice-pwd:LAldx4KbAxhCLkcnKKHyWp\r\na=fingerprint:sha-256 BC:19:97:0C:6F:C3:D7:17:02:76:D3:CA:90:A6:94:1C:E1:28:13:50:C2:CA:9A:58:B9:F7:D1:D0:81:CF:05:04\r\na=setup:active\r\n', 'type': 'answer'}

INFO:aiohttp.access:127.0.0.1 [11/Aug/2023:11:17:43 +0000] "POST /connect HTTP/1.1" 200 877 "http://localhost:8081/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/115.0.0.0 Safari/537.36"
DEBUG:aiortc.rtcicetransport:RTCIceTransport(controlled) - new -> checking
DEBUG:aiortc.rtcpeerconnection:RTCPeerConnection() iceConnectionState new -> checking
DEBUG:aiortc.rtcpeerconnection:RTCPeerConnection() connectionState new -> connecting
INFO:aioice.ice:Connection(0) Check CandidatePair(('192.168.53.97', 44175) -> ('193.40.12.11', 4451)) State.FROZEN -> State.WAITING
DEBUG:rtcbot.RTCConnection:ICE state: checking
INFO:aioice.ice:Connection(0) Check CandidatePair(('192.168.53.97', 44175) -> ('193.40.12.11', 4451)) State.WAITING -> State.IN_PROGRESS
DEBUG:aioice.ice:Connection(0) protocol(0) > ('193.40.12.11', 4451) Message(message_method=Method.BINDING, message_class=Class.REQUEST, transaction_id=b'\xdd\x95\x91X\x16\x12>\x94\n\x99\xb6\x84')
DEBUG:aioice.ice:Connection(0) protocol(0) < ('192.168.53.29', 55330) Message(message_method=Method.BINDING, message_class=Class.REQUEST, transaction_id=b'AvWLnS59dAi3')
DEBUG:aioice.ice:Connection(0) protocol(0) > ('192.168.53.29', 55330) Message(message_method=Method.BINDING, message_class=Class.RESPONSE, transaction_id=b'AvWLnS59dAi3')
INFO:aioice.ice:Connection(0) Discovered peer reflexive candidate Candidate(1GFrn5Ds9P 1 udp 1845501695 192.168.53.29 55330 typ prflx)
INFO:aioice.ice:Connection(0) Check CandidatePair(('192.168.53.97', 44175) -> ('192.168.53.29', 55330)) State.WAITING -> State.IN_PROGRESS
DEBUG:aioice.ice:Connection(0) protocol(0) > ('192.168.53.29', 55330) Message(message_method=Method.BINDING, message_class=Class.REQUEST, transaction_id=b'\x01 \x13\xfb\xc9\x05\xf6\xc9\x17\xff\xfac')
DEBUG:aioice.ice:Connection(0) protocol(0) < ('192.168.53.29', 55330) Message(message_method=Method.BINDING, message_class=Class.RESPONSE, transaction_id=b'\x01 \x13\xfb\xc9\x05\xf6\xc9\x17\xff\xfac')
INFO:aioice.ice:Connection(0) Check CandidatePair(('192.168.53.97', 44175) -> ('192.168.53.29', 55330)) State.IN_PROGRESS -> State.SUCCEEDED
INFO:aioice.ice:Connection(0) ICE completed
DEBUG:aiortc.rtcicetransport:RTCIceTransport(controlled) - checking -> completed
DEBUG:aiortc.rtcpeerconnection:RTCPeerConnection() iceConnectionState checking -> completed
DEBUG:aiortc.rtcdtlstransport:RTCDtlsTransport(client) - State.NEW -> State.CONNECTING
DEBUG:rtcbot.RTCConnection:ICE state: completed
DEBUG:aiortc.rtcdtlstransport:RTCDtlsTransport(client) - DTLS handshake complete
DEBUG:aiortc.rtcdtlstransport:RTCDtlsTransport(client) - State.CONNECTING -> State.CONNECTED
DEBUG:aiortc.rtcpeerconnection:RTCPeerConnection() connectionState connecting -> connected
DEBUG:aiortc.rtcsctptransport:RTCSctpTransport(server) < InitChunk(flags=0)
DEBUG:aiortc.rtcsctptransport:RTCSctpTransport(server) - Peer supports 65535 outbound streams, 65535 max inbound streams
DEBUG:aiortc.rtcsctptransport:RTCSctpTransport(server) > InitAckChunk(flags=0)
DEBUG:aiortc.rtcsctptransport:RTCSctpTransport(server) < CookieEchoChunk(flags=0)
DEBUG:aiortc.rtcsctptransport:RTCSctpTransport(server) > CookieAckChunk(flags=0)
DEBUG:aiortc.rtcsctptransport:RTCSctpTransport(server) - State.CLOSED -> State.ESTABLISHED
DEBUG:aioice.ice:Connection(0) protocol(0) < ('192.168.53.29', 55330) Message(message_method=Method.BINDING, message_class=Class.REQUEST, transaction_id=b'/8nZMgi/FpMy')
DEBUG:aioice.ice:Connection(0) protocol(0) > ('192.168.53.29', 55330) Message(message_method=Method.BINDING, message_class=Class.RESPONSE, transaction_id=b'/8nZMgi/FpMy')
DEBUG:aiortc.rtcsctptransport:RTCSctpTransport(server) < DataChunk(flags=3, tsn=4013116799, stream_id=1, stream_seq=0)
DEBUG:aiortc.rtcdatachannel:RTCDataChannel(1) - connecting -> open
DEBUG:aiortc.rtcsctptransport:RTCSctpTransport(server) > DataChunk(flags=3, tsn=3502065089, stream_id=1, stream_seq=0)
DEBUG:aiortc.rtcsctptransport:RTCSctpTransport(server) - T3 start
DEBUG:rtcbot.RTCConnection.DataChannel:Ready State open
DEBUG:rtcbot.RTCConnection:Got channel: default
DEBUG:rtcbot.RTCConnection.DataChannel.SubscriptionConsumer:Changing subscription from <Queue maxsize=0> to <rtcbot.base.base.NoClosedSubscription object at 0x7f93727b20>
DEBUG:rtcbot.RTCConnection.DataChannel.SubscriptionProducer:Added callback <bound method BaseSubscriptionProducer._put_nowait of <rtcbot.connection.RTCConnection object at 0x7fa584c880>>
DEBUG:rtcbot.RTCConnection.DataChannel.SubscriptionProducer:Adding onReady subscription
DEBUG:rtcbot.RTCConnection.DataChannel.SubscriptionProducer:Adding onClose subscription
DEBUG:aiortc.rtcsctptransport:RTCSctpTransport(server) > SackChunk(flags=0, advertised_rwnd=1048576, cumulative_tsn=4013116799, gaps=[])
DEBUG:rtcbot.RTCConnection.DataChannel:Channel open, ready to send
DEBUG:rtcbot.RTCConnection.DataChannel.SubscriptionProducer:Setting ready to True
DEBUG:rtcbot.RTCConnection.SubscriptionProducer:Setting ready to True
DEBUG:rtcbot.RTCConnection.DataChannel.SubscriptionConsumer:Waiting for new data...
DEBUG:rtcbot.RTCConnection.SubscriptionConsumer:Waiting for new data...
DEBUG:aiortc.rtcsctptransport:RTCSctpTransport(server) < SackChunk(flags=0, advertised_rwnd=4718592, cumulative_tsn=3502065089, gaps=[])
DEBUG:aiortc.rtcsctptransport:RTCSctpTransport(server) - T3 cancel
ERROR:rtcbot.RTCConnection.SubscriptionConsumer:Got unrecognized error from task.
Traceback (most recent call last):
  File "/home/pi/env/lib/python3.9/site-packages/rtcbot/base/base.py", line 365, in _get
    await self._getTask
  File "/usr/lib/python3.9/asyncio/queues.py", line 166, in get
    await getter
RuntimeError: Task <Task pending name='Task-30' coro=<Queue.get() running at /usr/lib/python3.9/asyncio/queues.py:166> cb=[<TaskWakeupMethWrapper object at 0x7f93727790>()]> got Future <Future pending> attached to a different loop
ERROR:rtcbot.RTCConnection.DataChannel.SubscriptionConsumer:Got unrecognized error from task.
Traceback (most recent call last):
  File "/home/pi/env/lib/python3.9/site-packages/rtcbot/base/base.py", line 365, in _get
    await self._getTask
  File "/home/pi/env/lib/python3.9/site-packages/rtcbot/base/base.py", line 28, in get
    return await self._callback()
  File "/home/pi/env/lib/python3.9/site-packages/rtcbot/base/base.py", line 365, in _get
    await self._getTask
  File "/usr/lib/python3.9/asyncio/queues.py", line 166, in get
    await getter
RuntimeError: Task <Task pending name='Task-30' coro=<Queue.get() running at /usr/lib/python3.9/asyncio/queues.py:166> cb=[<TaskWakeupMethWrapper object at 0x7f93727790>()]> got Future <Future pending> attached to a different loop
ERROR:asyncio:Task exception was never retrieved
future: <Task finished name='Task-28' coro=<DataChannel._messageSender() done, defined at /home/pi/env/lib/python3.9/site-packages/rtcbot/connection.py:56> exception=RuntimeError("Task <Task pending name='Task-30' coro=<Queue.get() running at /usr/lib/python3.9/asyncio/queues.py:166> cb=[<TaskWakeupMethWrapper object at 0x7f93727790>()]> got Future <Future pending> attached to a different loop")>
Traceback (most recent call last):
  File "/home/pi/env/lib/python3.9/site-packages/rtcbot/connection.py", line 61, in _messageSender
    msg = await self._get()
  File "/home/pi/env/lib/python3.9/site-packages/rtcbot/base/base.py", line 365, in _get
    await self._getTask
  File "/home/pi/env/lib/python3.9/site-packages/rtcbot/base/base.py", line 28, in get
    return await self._callback()
  File "/home/pi/env/lib/python3.9/site-packages/rtcbot/base/base.py", line 365, in _get
    await self._getTask
  File "/usr/lib/python3.9/asyncio/queues.py", line 166, in get
    await getter
RuntimeError: Task <Task pending name='Task-30' coro=<Queue.get() running at /usr/lib/python3.9/asyncio/queues.py:166> cb=[<TaskWakeupMethWrapper object at 0x7f93727790>()]> got Future <Future pending> attached to a different loop
DEBUG:aioice.ice:Connection(0) protocol(0) < ('192.168.53.29', 55330) Message(message_method=Method.BINDING, message_class=Class.REQUEST, transaction_id=b'iIEnG0ofPg9Y')
DEBUG:aioice.ice:Connection(0) protocol(0) > ('192.168.53.29', 55330) Message(message_method=Method.BINDING, message_class=Class.RESPONSE, transaction_id=b'iIEnG0ofPg9Y')
DEBUG:aioice.ice:Connection(0) protocol(0) < ('192.168.53.29', 55330) Message(message_method=Method.BINDING, message_class=Class.REQUEST, transaction_id=b'rV/CG54RqlHs')
DEBUG:aioice.ice:Connection(0) protocol(0) > ('192.168.53.29', 55330) Message(message_method=Method.BINDING, message_class=Class.RESPONSE, transaction_id=b'rV/CG54RqlHs')
DEBUG:aioice.ice:Connection(0) protocol(0) < ('192.168.53.29', 55330) Message(message_method=Method.BINDING, message_class=Class.REQUEST, transaction_id=b't11KKtbs41FI')
DEBUG:aioice.ice:Connection(0) protocol(0) > ('192.168.53.29', 55330) Message(message_method=Method.BINDING, message_class=Class.RESPONSE, transaction_id=b't11KKtbs41FI')
DEBUG:aioice.ice:Connection(0) protocol(0) > ('192.168.53.29', 55330) Message(message_method=Method.BINDING, message_class=Class.REQUEST, transaction_id=b'\xe2\xd5\xc6\xde\xd4\x07H\x05\xfd\x8b6\xe6')
DEBUG:aioice.ice:Connection(0) protocol(0) < ('192.168.53.29', 55330) Message(message_method=Method.BINDING, message_class=Class.RESPONSE, transaction_id=b'\xe2\xd5\xc6\xde\xd4\x07H\x05\xfd\x8b6\xe6')
DEBUG:aioice.ice:Connection(0) protocol(0) < ('192.168.53.29', 55330) Message(message_method=Method.BINDING, message_class=Class.REQUEST, transaction_id=b'Vh9DuOPyW72V')
DEBUG:aioice.ice:Connection(0) protocol(0) > ('192.168.53.29', 55330) Message(message_method=Method.BINDING, message_class=Class.RESPONSE, transaction_id=b'Vh9DuOPyW72V')
DEBUG:aioice.ice:Connection(0) protocol(0) < ('192.168.53.29', 55330) Message(message_method=Method.BINDING, message_class=Class.REQUEST, transaction_id=b'byjZr7EWMgDQ')
DEBUG:aioice.ice:Connection(0) protocol(0) > ('192.168.53.29', 55330) Message(message_method=Method.BINDING, message_class=Class.RESPONSE, transaction_id=b'byjZr7EWMgDQ')
DEBUG:aioice.ice:Connection(0) protocol(0) > ('192.168.53.29', 55330) Message(message_method=Method.BINDING, message_class=Class.REQUEST, transaction_id=b'\xa5\xc7\xf6v\x8cC\xde\x8dv\x01\x02\xe2')
DEBUG:aioice.ice:Connection(0) protocol(0) < ('192.168.53.29', 55330) Message(message_method=Method.BINDING, message_class=Class.RESPONSE, transaction_id=b'\xa5\xc7\xf6v\x8cC\xde\x8dv\x01\x02\xe2')
DEBUG:aioice.ice:Connection(0) protocol(0) < ('192.168.53.29', 55330) Message(message_method=Method.BINDING, message_class=Class.REQUEST, transaction_id=b'MkSYkfkJGkYK')
DEBUG:aioice.ice:Connection(0) protocol(0) > ('192.168.53.29', 55330) Message(message_method=Method.BINDING, message_class=Class.RESPONSE, transaction_id=b'MkSYkfkJGkYK')
DEBUG:aioice.ice:Connection(0) protocol(0) < ('192.168.53.29', 55330) Message(message_method=Method.BINDING, message_class=Class.REQUEST, transaction_id=b'm6bPphtHtX0+')
DEBUG:aioice.ice:Connection(0) protocol(0) > ('192.168.53.29', 55330) Message(message_method=Method.BINDING, message_class=Class.RESPONSE, transaction_id=b'm6bPphtHtX0+')
DEBUG:aioice.ice:Connection(0) protocol(0) > ('192.168.53.29', 55330) Message(message_method=Method.BINDING, message_class=Class.REQUEST, transaction_id=b'\xb3\xadZz\xa0\xcb\xf5x`\x1b\xb6\x88')
DEBUG:aioice.ice:Connection(0) protocol(0) < ('192.168.53.29', 55330) Message(message_method=Method.BINDING, message_class=Class.RESPONSE, transaction_id=b'\xb3\xadZz\xa0\xcb\xf5x`\x1b\xb6\x88')
DEBUG:aioice.ice:Connection(0) protocol(0) < ('192.168.53.29', 55330) Message(message_method=Method.BINDING, message_class=Class.REQUEST, transaction_id=b'OZ8u/Fc2fLDg')
DEBUG:aioice.ice:Connection(0) protocol(0) > ('192.168.53.29', 55330) Message(message_method=Method.BINDING, message_class=Class.RESPONSE, transaction_id=b'OZ8u/Fc2fLDg')
DEBUG:aioice.ice:Connection(0) protocol(0) < ('192.168.53.29', 55330) Message(message_method=Method.BINDING, message_class=Class.REQUEST, transaction_id=b'7DM5AVhhTmYw')
DEBUG:aioice.ice:Connection(0) protocol(0) > ('192.168.53.29', 55330) Message(message_method=Method.BINDING, message_class=Class.RESPONSE, transaction_id=b'7DM5AVhhTmYw')
DEBUG:aioice.ice:Connection(0) protocol(0) > ('192.168.53.29', 55330) Message(message_method=Method.BINDING, message_class=Class.REQUEST, transaction_id=b'#OWo\xf0FbB\xd2\xfa\xcdc')
DEBUG:aioice.ice:Connection(0) protocol(0) > ('192.168.53.29', 55330) Message(message_method=Method.BINDING, message_class=Class.REQUEST, transaction_id=b'\xdf\xa0\xa5\tD0\xfe[\xf9\xeb\xcbS')

Serving request:

<Request GET /rtcbot.js >

INFO:aiohttp.access:127.0.0.1 [11/Aug/2023:11:18:15 +0000] "GET /rtcbot.js HTTP/1.1" 200 6637 "http://localhost:8081/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/115.0.0.0 Safari/537.36"
DEBUG:aioice.ice:Connection(0) protocol(0) > ('192.168.53.29', 55330) Message(message_method=Method.BINDING, message_class=Class.REQUEST, transaction_id=b'\xee\xe1Z\x96$?\x07\x9a\x1f+4o')

collecting request...

<Request POST /connect >

clientOffer:

{'type': 'offer', 'sdp': 'v=0\r\no=- 310868604692091414 2 IN IP4 127.0.0.1\r\ns=-\r\nt=0 0\r\na=group:BUNDLE 0\r\na=extmap-allow-mixed\r\na=msid-semantic: WMS\r\nm=application 45832 UDP/DTLS/SCTP webrtc-datachannel\r\nc=IN IP4 193.40.12.11\r\na=candidate:955443483 1 udp 2113937151 8741dcce-7192-410a-a55e-6fd9fda32a1c.local 63184 typ host generation 0 network-cost 999\r\na=candidate:101384084 1 udp 1677729535 193.40.12.11 45832 typ srflx raddr 0.0.0.0 rport 0 generation 0 network-cost 999\r\na=ice-ufrag:wj5v\r\na=ice-pwd:W4jmRdBc/qC4iOkaRidSqbqr\r\na=ice-options:trickle\r\na=fingerprint:sha-256 B0:70:9D:40:EA:38:22:89:B6:CD:68:6B:BB:04:F9:DE:64:43:B2:C1:8A:41:7A:F3:9F:A5:55:41:2E:35:CB:3D\r\na=setup:actpass\r\na=mid:0\r\na=sctp-port:5000\r\na=max-message-size:262144\r\n'}

DEBUG:rtcbot.RTCConnection:Creating response to connection offer
ERROR:aiohttp.server:Error handling request
Traceback (most recent call last):
  File "/home/pi/env/lib/python3.9/site-packages/aiohttp/web_protocol.py", line 433, in _handle_request
    resp = await request_handler(request)
  File "/home/pi/env/lib/python3.9/site-packages/aiohttp/web_app.py", line 504, in _handle
    resp = await handler(request)
  File "/home/pi/projects/rtcbot/examples/streaming/skeleton.py", line 28, in connect
    serverResponse = await conn.getLocalDescription(clientOffer)
  File "/home/pi/env/lib/python3.9/site-packages/rtcbot/connection.py", line 410, in getLocalDescription
    answer = await self._rtc.createAnswer()
  File "/home/pi/env/lib/python3.9/site-packages/aiortc/rtcpeerconnection.py", line 517, in createAnswer
    raise InvalidStateError(
aiortc.exceptions.InvalidStateError: Cannot create answer in signaling state "stable"
INFO:aiohttp.access:127.0.0.1 [11/Aug/2023:11:18:15 +0000] "POST /connect HTTP/1.1" 500 244 "http://localhost:8081/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/115.0.0.0 Safari/537.36"
DEBUG:aioice.ice:Connection(0) protocol(0) > ('192.168.53.29', 55330) Message(message_method=Method.BINDING, message_class=Class.REQUEST, transaction_id=b'#\n\x8c\x9a\xbf\x14K\x8e6G\xec\xff')
DEBUG:aioice.ice:Connection(0) protocol(0) > ('192.168.53.29', 55330) Message(message_method=Method.BINDING, message_class=Class.REQUEST, transaction_id=b'\xc7Vvb\xea`d\x8d\xe3F\x964')
DEBUG:aioice.ice:Connection(0) protocol(0) > ('192.168.53.29', 55330) Message(message_method=Method.BINDING, message_class=Class.REQUEST, transaction_id=b'\x85\xf5\xab\xe3\x156\xc2\x8b\x051N\xb3')
INFO:aioice.ice:Connection(0) Consent to send expired
DEBUG:aioice.ice:Connection(0) protocol(0) connection_lost(None)
DEBUG:aiortc.rtcdtlstransport:RTCDtlsTransport(client) - State.CONNECTED -> State.CLOSED
DEBUG:rtcbot.RTCConnection.DataChannel:Channel State: closed
DEBUG:rtcbot.RTCConnection.DataChannel.SubscriptionConsumer:Closing
DEBUG:rtcbot.RTCConnection.DataChannel.SubscriptionProducer:Closing
DEBUG:rtcbot.RTCConnection.DataChannel.SubscriptionProducer:Setting ready to False
DEBUG:rtcbot.RTCConnection.SubscriptionProducer:Setting ready to True
DEBUG:rtcbot.RTCConnection.DataChannel.SubscriptionProducer:Firing onClose
DEBUG:rtcbot.RTCConnection:Closing connection
DEBUG:rtcbot.RTCConnection.SubscriptionConsumer:Closing
DEBUG:rtcbot.RTCConnection.SubscriptionProducer:Closing
DEBUG:rtcbot.RTCConnection.SubscriptionProducer:Setting ready to False
DEBUG:rtcbot.RTCConnection.SubscriptionProducer:Firing onClose
DEBUG:rtcbot.RTCConnection.ConnectionVideoHandler.trackSubscriber.SubscriptionProducer:Closing
DEBUG:rtcbot.RTCConnection.ConnectionVideoHandler.trackSubscriber.SubscriptionProducer:Setting ready to False
DEBUG:rtcbot.RTCConnection.ConnectionVideoHandler.trackSubscriber.SubscriptionProducer:Firing onClose
DEBUG:rtcbot.RTCConnection.ConnectionVideoHandler.SubscriptionConsumer:Closing
DEBUG:rtcbot.RTCConnection.ConnectionVideoHandler.SubscriptionProducer:Closing
DEBUG:rtcbot.RTCConnection.ConnectionVideoHandler.SubscriptionProducer:Setting ready to False
DEBUG:rtcbot.RTCConnection.ConnectionVideoHandler.SubscriptionProducer:Firing onClose
DEBUG:rtcbot.RTCConnection.ConnectionAudioHandler.trackSubscriber.SubscriptionProducer:Closing
DEBUG:rtcbot.RTCConnection.ConnectionAudioHandler.trackSubscriber.SubscriptionProducer:Setting ready to False
DEBUG:rtcbot.RTCConnection.ConnectionAudioHandler.trackSubscriber.SubscriptionProducer:Firing onClose
DEBUG:rtcbot.RTCConnection.ConnectionAudioHandler.SubscriptionConsumer:Closing
DEBUG:rtcbot.RTCConnection.ConnectionAudioHandler.SubscriptionProducer:Closing
DEBUG:rtcbot.RTCConnection.ConnectionAudioHandler.SubscriptionProducer:Setting ready to False
DEBUG:rtcbot.RTCConnection.ConnectionAudioHandler.SubscriptionProducer:Firing onClose
DEBUG:rtcbot.RTCConnection.dataChannelSubscriber.SubscriptionProducer:Closing
DEBUG:rtcbot.RTCConnection.dataChannelSubscriber.SubscriptionProducer:Setting ready to False
DEBUG:rtcbot.RTCConnection.dataChannelSubscriber.SubscriptionProducer:Firing onClose
ERROR:asyncio:Task exception was never retrieved
future: <Task finished name='Task-34' coro=<cleanup() done, defined at /home/pi/projects/rtcbot/examples/streaming/skeleton.py:75> exception=TypeError("object NoneType can't be used in 'await' expression")>
Traceback (most recent call last):
  File "/home/pi/projects/rtcbot/examples/streaming/skeleton.py", line 76, in cleanup
    await conn.close()
TypeError: object NoneType can't be used in 'await' expression
ERROR:asyncio:Exception in callback AsyncIOEventEmitter._emit_run.<locals>.callback(<Task finishe... is running')>) at /home/pi/env/lib/python3.9/site-packages/pyee/asyncio.py:69
handle: <Handle AsyncIOEventEmitter._emit_run.<locals>.callback(<Task finishe... is running')>) at /home/pi/env/lib/python3.9/site-packages/pyee/asyncio.py:69>
Traceback (most recent call last):
  File "/usr/lib/python3.9/asyncio/events.py", line 80, in _run
    self._context.run(self._callback, *self._args)
  File "/home/pi/env/lib/python3.9/site-packages/pyee/asyncio.py", line 77, in callback
    self.emit("error", exc)
  File "/home/pi/env/lib/python3.9/site-packages/pyee/base.py", line 211, in emit
    self._emit_handle_potential_error(event, args[0] if args else None)
  File "/home/pi/env/lib/python3.9/site-packages/pyee/base.py", line 169, in _emit_handle_potential_error
    raise error
  File "/home/pi/env/lib/python3.9/site-packages/rtcbot/connection.py", line 54, in stateChange
    self.close()
  File "/home/pi/env/lib/python3.9/site-packages/rtcbot/connection.py", line 93, in close
    super().close()
  File "/home/pi/env/lib/python3.9/site-packages/rtcbot/base/base.py", line 546, in close
    BaseSubscriptionConsumer.close(self)
  File "/home/pi/env/lib/python3.9/site-packages/rtcbot/base/base.py", line 487, in close
    super().close()
  File "/home/pi/env/lib/python3.9/site-packages/rtcbot/base/base.py", line 295, in close
    super().close()
  File "/home/pi/env/lib/python3.9/site-packages/rtcbot/base/events.py", line 211, in close
    subscription()
  File "/home/pi/env/lib/python3.9/site-packages/rtcbot/connection.py", line 567, in close
    self._loop.run_until_complete(self._rtc.close())
  File "/usr/lib/python3.9/asyncio/base_events.py", line 618, in run_until_complete
    self._check_running()
  File "/usr/lib/python3.9/asyncio/base_events.py", line 580, in _check_running
    raise RuntimeError(
RuntimeError: Cannot run the event loop while another loop is running
DEBUG:aiortc.rtcicetransport:RTCIceTransport(controlled) - completed -> failed
DEBUG:aiortc.rtcpeerconnection:RTCPeerConnection() iceConnectionState completed -> failed
DEBUG:aiortc.rtcpeerconnection:RTCPeerConnection() connectionState connected -> failed
DEBUG:rtcbot.RTCConnection:ICE state: failed
DEBUG:rtcbot.RTCConnection.SubscriptionProducer:Setting error to failed
ERROR:asyncio:Exception in callback AsyncIOEventEmitter._emit_run.<locals>.callback(<Task finishe... expression")>) at /home/pi/env/lib/python3.9/site-packages/pyee/asyncio.py:69
handle: <Handle AsyncIOEventEmitter._emit_run.<locals>.callback(<Task finishe... expression")>) at /home/pi/env/lib/python3.9/site-packages/pyee/asyncio.py:69>
Traceback (most recent call last):
  File "/usr/lib/python3.9/asyncio/events.py", line 80, in _run
    self._context.run(self._callback, *self._args)
  File "/home/pi/env/lib/python3.9/site-packages/pyee/asyncio.py", line 77, in callback
    self.emit("error", exc)
  File "/home/pi/env/lib/python3.9/site-packages/pyee/base.py", line 211, in emit
    self._emit_handle_potential_error(event, args[0] if args else None)
  File "/home/pi/env/lib/python3.9/site-packages/pyee/base.py", line 169, in _emit_handle_potential_error
    raise error
  File "/home/pi/env/lib/python3.9/site-packages/rtcbot/connection.py", line 466, in _onIceConnectionStateChange
    await self.close()
TypeError: object NoneType can't be used in 'await' expression
^CERROR:asyncio:unhandled exception during asyncio.run() shutdown
task: <Task finished name='Task-1' coro=<_run_app() done, defined at /home/pi/env/lib/python3.9/site-packages/aiohttp/web.py:289> exception=TypeError("object NoneType can't be used in 'await' expression")>
Traceback (most recent call last):
  File "/home/pi/env/lib/python3.9/site-packages/aiohttp/web.py", line 433, in _run_app
    await asyncio.sleep(delay)
  File "/usr/lib/python3.9/asyncio/tasks.py", line 654, in sleep
    return await future
asyncio.exceptions.CancelledError

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/home/pi/env/lib/python3.9/site-packages/aiohttp/web.py", line 435, in _run_app
    await runner.cleanup()
  File "/home/pi/env/lib/python3.9/site-packages/aiohttp/web_runner.py", line 293, in cleanup
    await site.stop()
  File "/home/pi/env/lib/python3.9/site-packages/aiohttp/web_runner.py", line 76, in stop
    await self._runner.shutdown()
  File "/home/pi/env/lib/python3.9/site-packages/aiohttp/web_runner.py", line 369, in shutdown
    await self._app.shutdown()
  File "/home/pi/env/lib/python3.9/site-packages/aiohttp/web_app.py", line 424, in shutdown
    await self.on_shutdown.send(self)
  File "/home/pi/env/lib/python3.9/site-packages/aiosignal/__init__.py", line 36, in send
    await receiver(*args, **kwargs)  # type: ignore
  File "/home/pi/projects/rtcbot/examples/streaming/skeleton.py", line 76, in cleanup
    await conn.close()
TypeError: object NoneType can't be used in 'await' expression
/usr/lib/python3.9/enum.py:360: RuntimeWarning: coroutine 'RTCPeerConnection.close' was never awaited
  return cls.__new__(cls, value)
RuntimeWarning: Enable tracemalloc to get the object allocation traceback

It appears the error occurs here:

...
ERROR:rtcbot.RTCConnection.SubscriptionConsumer:Got unrecognized error from task.
Traceback (most recent call last):
  File "/home/pi/env/lib/python3.9/site-packages/rtcbot/base/base.py", line 365, in _get
    await self._getTask
  File "/usr/lib/python3.9/asyncio/queues.py", line 166, in get
    await getter
RuntimeError: Task <Task pending name='Task-30' coro=<Queue.get() running at /usr/lib/python3.9/asyncio/queues.py:166> cb=[<TaskWakeupMethWrapper object at 0x7f93727790>()]> got Future <Future pending> attached to a different loop
ERROR:rtcbot.RTCConnection.DataChannel.SubscriptionConsumer:Got unrecognized error from task.
...
tristanryerparke commented 4 months ago

I'm having this same issue with the basic video streaming example. At first I don't get the error (but streaming doesn't work) and then if I reload the page I get the same error in the python console. What were you able to do to fix it? I'm running the same system/os.