Re: [Qemu-devel] [RFC PATCH v2] qmp.py: Fix exception parsing partial JSON

[Philippe Mathieu-Daudé]

On 06/06/2018 05:05 PM, Eduardo Habkost wrote:
> On Wed, Jun 06, 2018 at 04:27:31PM -0300, Philippe Mathieu-Daudé wrote:
>> The readline() call returns partial data.
> 
> How can this be reproduced?  Despite not being forbidden by the
> QMP specification, QEMU normally doesn't break QMP replies in
> multiple lines, and readline() is not supposed to return a
> partial line unless it encounters EOF.

$ git rev-parse HEAD
c1c2a435905ae76b159c573b0c0d6f095b45ebc6

config copy/pasted from:
https://wiki.qemu.org/index.php/Documentation/QMP#Trying_it
(now looking at it, it seems I'm mixing configs...)

$ cat qmp.conf
[chardev "qmp"]
  backend = "socket"
  path = "/tmp/qmp.sock"
  server = "on"
  wait = "off"
[mon "qmp"]
  mode = "control"
  chardev = "qmp"
  pretty = "on"

$ arm-softmmu/qemu-system-arm -M lm3s6965evb -kernel /dev/zero \
 -readconfig qmp.conf -S

> 
> 
>> Keep appending until the JSON buffer is complete.
>>
>> This fixes:
>>
>>     $ scripts/qmp/qmp-shell -v -p /tmp/qmp.sock
>>     Traceback (most recent call last):
>>       File "scripts/qmp/qmp-shell", line 456, in <module>
>>         main()
>>       File "scripts/qmp/qmp-shell", line 441, in main
>>         qemu.connect(negotiate)
>>       File "scripts/qmp/qmp-shell", line 284, in connect
>>         self._greeting = super(QMPShell, self).connect(negotiate)
>>       File "scripts/qmp/qmp.py", line 143, in connect
>>         return self.__negotiate_capabilities()
>>       File "scripts/qmp/qmp.py", line 71, in __negotiate_capabilities
>>         greeting = self.__json_read()
>>       File "scripts/qmp/qmp.py", line 85, in __json_read
>>         resp = json.loads(data)
>>       File "/usr/lib/python2.7/json/__init__.py", line 339, in loads
>>         return _default_decoder.decode(s)
>>       File "/usr/lib/python2.7/json/decoder.py", line 364, in decode
>>         obj, end = self.raw_decode(s, idx=_w(s, 0).end())
>>       File "/usr/lib/python2.7/json/decoder.py", line 380, in raw_decode
>>         obj, end = self.scan_once(s, idx)
>>     ValueError: Expecting object: line 1 column 3 (char 2)
>>
>> Signed-off-by: Philippe Mathieu-Daudé <address@hidden>
>> ---
>> Since v1:
>> - addressed Daniel review: clean data after json.loads() succeeds
>> - add a XXX comment
>>
>> Daniel suggested this is due to blocking i/o.
>>
>> I'm sure there is a nicer/more pythonic way to do this, but this works for 
>> me,
>> sorry :)
> 
> It looks like there's no elegant solution for this:
> https://stackoverflow.com/a/21709058
> 
>>
>>  scripts/qmp/qmp.py | 13 ++++++++++---
>>  1 file changed, 10 insertions(+), 3 deletions(-)
>>
>> diff --git a/scripts/qmp/qmp.py b/scripts/qmp/qmp.py
>> index 5c8cf6a056..14f0b48936 100644
>> --- a/scripts/qmp/qmp.py
>> +++ b/scripts/qmp/qmp.py
>> @@ -78,11 +78,18 @@ class QEMUMonitorProtocol(object):
>>          raise QMPCapabilitiesError
>>  
>>      def __json_read(self, only_event=False):
>> +        data = ""
>>          while True:
>> -            data = self.__sockfile.readline()
>> -            if not data:
>> +            tmp = self.__sockfile.readline()
>> +            if not tmp:
>>                  return
>> -            resp = json.loads(data)
>> +            data += tmp
>> +            try:
>> +                resp = json.loads(data)
>> +            except ValueError:
>> +                # XXX: blindly loop, even if QEMU ever sends malformed data
>> +                continue
> 
> I was going to suggest using json.JSONDecoder.raw_decode() and
> saving the remaining data in case we already read partial data
> for a second JSON message.
> 
> But the QMP specification says all messages are terminated with
> CRLF, so we we should never see the data for two different
> messages in a single readline() call.  Noting this in a comment
> wouldn't hurt, though.
> 
> The patch seems reasonable, but first I would like to understand
> how this bug can be triggered.
> 
>> +            data = ""
>>              if 'event' in resp:
>>                  self.logger.debug("<<< %s", resp)
>>                  self.__events.append(resp)
>> -- 
>> 2.17.1
>>
>