[Bug] Protocol: AttributeError: 'NoneType' object has no attribute 'ReadUntilClose' still occurring on NVidia Shield

[caffeinatedMike]

I think this might be related to #59. It seems the error only occurs on "Official" Android TV OS devices because I have not been able to reproduce the error on my android box that runs an Android Tablet OS. Anyway, the traceback is as follows

Mon Nov 12 2018 13:23:15 GMT-0500 (Eastern Standard Time)

Update for media_player.shieldtv fails
Traceback (most recent call last):
  File "/srv/homeassistant/lib/python3.6/site-packages/homeassistant/helpers/entity.py", line 221, in async_update_ha_state
    await self.async_device_update()
  File "/srv/homeassistant/lib/python3.6/site-packages/homeassistant/helpers/entity.py", line 347, in async_device_update
    await self.async_update()
  File "/home/homeassistant/.homeassistant/custom_components/media_player/androidtv.py", line 255, in async_update
    await self._androidtv.update()
  File "/srv/homeassistant/lib/python3.6/site-packages/androidtv/__init__.py", line 361, in update
    screen_on = await self._screen_on
  File "/srv/homeassistant/lib/python3.6/site-packages/androidtv/__init__.py", line 407, in _screen_on
    screen_on = await self._dump_has('power', 'Display Power', 'state=ON')
  File "/srv/homeassistant/lib/python3.6/site-packages/androidtv/__init__.py", line 461, in _dump_has
    dump_result = await self._dump(service, grep=grep)
  File "/srv/homeassistant/lib/python3.6/site-packages/androidtv/__init__.py", line 448, in _dump
    result = await self._adb.shell('dumpsys {0} | grep "{1}"'.format(service, grep))
  File "/srv/homeassistant/lib/python3.6/site-packages/androidtv/__init__.py", line 298, in shell
    return await fut
  File "/usr/local/lib/python3.6/concurrent/futures/thread.py", line 56, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/srv/homeassistant/lib/python3.6/site-packages/adb/adb_commands.py", line 383, in Shell
    timeout_ms=timeout_ms)
  File "/srv/homeassistant/lib/python3.6/site-packages/adb/adb_protocol.py", line 493, in Command
    result = ''.join(cls.StreamingCommand(usb, service, command, timeout_ms))
  File "/srv/homeassistant/lib/python3.6/site-packages/adb/adb_protocol.py", line 529, in StreamingCommand
    timeout_ms=timeout_ms)
  File "/srv/homeassistant/lib/python3.6/site-packages/adb/adb_protocol.py", line 440, in Open
    timeout_ms=timeout_ms)
  File "/srv/homeassistant/lib/python3.6/site-packages/adb/adb_protocol.py", line 308, in Read
    'Unknown command: %x' % cmd, cmd, (arg0, arg1))
adb.adb_protocol.InvalidCommandError: ('Unknown command: 70736944', 1886611780, (544825708, 1702326096))


Mon Nov 12 2018 13:23:02 GMT-0500 (Eastern Standard Time)

Update for media_player.shieldtv fails
Traceback (most recent call last):
  File "/srv/homeassistant/lib/python3.6/site-packages/homeassistant/helpers/entity.py", line 221, in async_update_ha_state
    await self.async_device_update()
  File "/srv/homeassistant/lib/python3.6/site-packages/homeassistant/helpers/entity.py", line 347, in async_device_update
    await self.async_update()
  File "/home/homeassistant/.homeassistant/custom_components/media_player/androidtv.py", line 255, in async_update
    await self._androidtv.update()
  File "/srv/homeassistant/lib/python3.6/site-packages/androidtv/__init__.py", line 361, in update
    screen_on = await self._screen_on
  File "/srv/homeassistant/lib/python3.6/site-packages/androidtv/__init__.py", line 407, in _screen_on
    screen_on = await self._dump_has('power', 'Display Power', 'state=ON')
  File "/srv/homeassistant/lib/python3.6/site-packages/androidtv/__init__.py", line 461, in _dump_has
    dump_result = await self._dump(service, grep=grep)
  File "/srv/homeassistant/lib/python3.6/site-packages/androidtv/__init__.py", line 448, in _dump
    result = await self._adb.shell('dumpsys {0} | grep "{1}"'.format(service, grep))
  File "/srv/homeassistant/lib/python3.6/site-packages/androidtv/__init__.py", line 298, in shell
    return await fut
  File "/usr/local/lib/python3.6/concurrent/futures/thread.py", line 56, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/srv/homeassistant/lib/python3.6/site-packages/adb/adb_commands.py", line 383, in Shell
    timeout_ms=timeout_ms)
  File "/srv/homeassistant/lib/python3.6/site-packages/adb/adb_protocol.py", line 493, in Command
    result = ''.join(cls.StreamingCommand(usb, service, command, timeout_ms))
  File "/srv/homeassistant/lib/python3.6/site-packages/adb/adb_protocol.py", line 529, in StreamingCommand
    timeout_ms=timeout_ms)
  File "/srv/homeassistant/lib/python3.6/site-packages/adb/adb_protocol.py", line 440, in Open
    timeout_ms=timeout_ms)
  File "/srv/homeassistant/lib/python3.6/site-packages/adb/adb_protocol.py", line 312, in Read
    if time.time() - start > total_timeout_ms:
TypeError: '>' not supported between instances of 'float' and 'NoneType'


Mon Nov 12 2018 13:22:49 GMT-0500 (Eastern Standard Time)

Update for media_player.shieldtv fails
Traceback (most recent call last):
  File "/srv/homeassistant/lib/python3.6/site-packages/homeassistant/helpers/entity.py", line 221, in async_update_ha_state
    await self.async_device_update()
  File "/srv/homeassistant/lib/python3.6/site-packages/homeassistant/helpers/entity.py", line 347, in async_device_update
    await self.async_update()
  File "/home/homeassistant/.homeassistant/custom_components/media_player/androidtv.py", line 255, in async_update
    await self._androidtv.update()
  File "/srv/homeassistant/lib/python3.6/site-packages/androidtv/__init__.py", line 366, in update
    wake_lock = await self._wake_lock
  File "/srv/homeassistant/lib/python3.6/site-packages/androidtv/__init__.py", line 419, in _wake_lock
    wake_lock = await self._dump_has('power', 'Locks', 'size=0')
  File "/srv/homeassistant/lib/python3.6/site-packages/androidtv/__init__.py", line 461, in _dump_has
    dump_result = await self._dump(service, grep=grep)
  File "/srv/homeassistant/lib/python3.6/site-packages/androidtv/__init__.py", line 448, in _dump
    result = await self._adb.shell('dumpsys {0} | grep "{1}"'.format(service, grep))
  File "/srv/homeassistant/lib/python3.6/site-packages/androidtv/__init__.py", line 298, in shell
    return await fut
  File "/usr/local/lib/python3.6/concurrent/futures/thread.py", line 56, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/srv/homeassistant/lib/python3.6/site-packages/adb/adb_commands.py", line 383, in Shell
    timeout_ms=timeout_ms)
  File "/srv/homeassistant/lib/python3.6/site-packages/adb/adb_protocol.py", line 493, in Command
    result = ''.join(cls.StreamingCommand(usb, service, command, timeout_ms))
  File "/srv/homeassistant/lib/python3.6/site-packages/adb/adb_protocol.py", line 531, in StreamingCommand
    for data in connection.ReadUntilClose():
  File "/srv/homeassistant/lib/python3.6/site-packages/adb/adb_protocol.py", line 169, in ReadUntilClose
    cmd, data = self.ReadUntil(b'CLSE', b'WRTE')
  File "/srv/homeassistant/lib/python3.6/site-packages/adb/adb_protocol.py", line 160, in ReadUntil
    self.remote_id, remote_id))
adb.adb_protocol.InvalidResponseError: Incorrect remote id, expected 27640 got 27639

Update for media_player.shieldtv fails
Traceback (most recent call last):
  File "/srv/homeassistant/lib/python3.6/site-packages/homeassistant/helpers/entity.py", line 221, in async_update_ha_state
    await self.async_device_update()
  File "/srv/homeassistant/lib/python3.6/site-packages/homeassistant/helpers/entity.py", line 347, in async_device_update
    await self.async_update()
  File "/home/homeassistant/.homeassistant/custom_components/media_player/androidtv.py", line 255, in async_update
    await self._androidtv.update()
  File "/srv/homeassistant/lib/python3.6/site-packages/androidtv/__init__.py", line 361, in update
    screen_on = await self._screen_on
  File "/srv/homeassistant/lib/python3.6/site-packages/androidtv/__init__.py", line 407, in _screen_on
    screen_on = await self._dump_has('power', 'Display Power', 'state=ON')
  File "/srv/homeassistant/lib/python3.6/site-packages/androidtv/__init__.py", line 461, in _dump_has
    dump_result = await self._dump(service, grep=grep)
  File "/srv/homeassistant/lib/python3.6/site-packages/androidtv/__init__.py", line 448, in _dump
    result = await self._adb.shell('dumpsys {0} | grep "{1}"'.format(service, grep))
  File "/srv/homeassistant/lib/python3.6/site-packages/androidtv/__init__.py", line 298, in shell
    return await fut
  File "/usr/local/lib/python3.6/concurrent/futures/thread.py", line 56, in run
    result = self.fn(*self.args, **self.kwargs)
  File "/srv/homeassistant/lib/python3.6/site-packages/adb/adb_commands.py", line 383, in Shell
    timeout_ms=timeout_ms)
  File "/srv/homeassistant/lib/python3.6/site-packages/adb/adb_protocol.py", line 493, in Command
    result = ''.join(cls.StreamingCommand(usb, service, command, timeout_ms))
  File "/srv/homeassistant/lib/python3.6/site-packages/adb/adb_protocol.py", line 531, in StreamingCommand
    for data in connection.ReadUntilClose():
AttributeError: 'NoneType' object has no attribute 'ReadUntilClose'

I've taken the liberty of modifying the adb_protocol.py file to add in a ton of logging to see what's going on. You can find the modified file's code here and a partial log showing where the error begins to occur here

From what I could gather after jumping down the rabbit hole bouncing from function to function after a few hours I have the following theory:

• The errors are connected (in case that wasn't obvious). First erroring on line 308 of adb_protocol.py, then line 312 because we're receiving a command that isn't expected (we get b'WRTE' while it's looking for either b'CLSE' or b'OKAY'
• The 3rd error (although not obvious at first glance) is still a product of the previous two errors. It seems tied to arg0 in the Read function. In my logging output you can see that arg0 in the Read function is clearly correct though (arg0: 27640).

What's wrong with the adb_protocol.py file? Does anyone know of a fix?

[caffeinatedMike]

@fahhem sorry to intrude, but I'm hoping you can have a look into this error soon when you have the time. I know this repo has become pretty desolate, but this appears to be a pretty significant bug. I've tried to figure it out on my own, but have failed after debugging for a few hours. Hopefully, seeing as you're more aware of the inner-workings of the project you'll know exactly what to look for with my extensive debugging logs.

I know this probably doesn't help much, but I organized the first two errors in a horizontal fashion to easily follow the variable values from function-to-function left-to-right in the attached excel file.
Error Sequence.xlsx

[caffeinatedMike]

@fahhem here is a new issue on the problem. Any insight?

[fahhem]

Are you using the latest python-adb (from GitHub) or the release from PyPI (admittedly I need to update it)?

The remote ID being 27639 means that the device is responding to a different call to the one you're expecting, and we don't support multi-streams (yet). Are you using TCP or USB? If it's TCP, is there a chance someone else is talking to the device at the moment?

[caffeinatedMike]

I'm using this version: https://github.com/JeffLIrion/python-adb/tree/adb-homeassistant, which I believe has been updated. In fact, the editor of that tree has an open issue here (#133) for you to release that version lol. To answer your question, TCP & there is no chance anyone/anything else is talking to the device at the moment. The remote ID error is actually the second error in the logs, but it's the first one that is "Raised". The real first one (receiving WRTE instead of OKAY or CLSE) is a silent error.

Again, this only seems to occur on devices with Android TV OSes (Nvidia Shield). I don't have the issue on my android box.

Any idea why it's receiving WRTE in this case? How can this be fixed?

[caffeinatedMike]

Adding additional links here in hopes it helps you diagnose the problem.

Differential between a working dumpsys power | grep "Display Power"' call and the first error using the same command on the same device: here
Notice how the adb.common.TcpHandle object on line 14 stays the same (showing that it's still using commands from the same device).

To me, it seems the problem originates in either the Pack/Unpack functions and leads to the first (silent) error in the Read function.

The following logs are all for the same device & same adb command.
Successful command: here
First (silent) error for command: here
Second (raised) error for command: here
Third (silent) error for command: here (this one seems stuck in a loop from the Read function.

I hope that helps @fahhem

[caffeinatedMike]

Any input on this @fahhem?

[embray]

See #151 for a possible fix. This worked for me.