FluentFormatter produces not serializable message

Bug #1782361 reported by Dmitry Kalashnik
14
This bug affects 3 people
Affects Status Importance Assigned to Milestone
oslo.log
Fix Released
Medium
Stephen Finucane

Bug Description

FluentFormatter allows to put to message not serializable objects.
For example, during instance boot in extra_keys we have {"instance": <class 'nova.objects.instance.Instance'>} extra.

Extra_keys: https://github.com/openstack/oslo.log/blob/master/oslo_log/formatters.py#L323-L325
One of the sources for the key: https://github.com/openstack/nova/blob/master/nova/virt/libvirt/driver.py#L3085

And during instance boot we have a bunch of errors like:

message: Can't output to log
traceback:
Traceback (most recent call last):
  File "/usr/lib/python2.7/dist-packages/fluent/sender.py", line 90, in emit_with_time
    bytes_ = self._make_packet(label, timestamp, data)
  File "/usr/lib/python2.7/dist-packages/fluent/sender.py", line 137, in _make_packet
    return msgpack.packb(packet, **self.msgpack_kwargs)
  File "/usr/lib/python2.7/dist-packages/msgpack/__init__.py", line 47, in packb
    return Packer(**kwargs).pack(o)
  File "msgpack/_packer.pyx", line 223, in msgpack._packer.Packer.pack (msgpack/_packer.cpp:223)
  File "msgpack/_packer.pyx", line 225, in msgpack._packer.Packer.pack (msgpack/_packer.cpp:225)
  File "msgpack/_packer.pyx", line 213, in msgpack._packer.Packer._pack (msgpack/_packer.cpp:213)
  File "msgpack/_packer.pyx", line 184, in msgpack._packer.Packer._pack (msgpack/_packer.cpp:184)
  File "msgpack/_packer.pyx", line 184, in msgpack._packer.Packer._pack (msgpack/_packer.cpp:184)
  File "msgpack/_packer.pyx", line 220, in msgpack._packer.Packer._pack (msgpack/_packer.cpp:220)
TypeError: can't serialize Instance(access_ip_v4=None,access_ip_v6=None,architecture=None,auto_disk_config=False,availability_zone='nova',cell_name=None,cleaned=False,config_drive='',created_at=2018-07-18T13:34:17Z,default_ephemeral_device=None,default_swap_device=None,deleted=False,deleted_at=None,device_metadata=None,disable_terminate=False,display_description=None,display_name='testVM5',ec2_ids=EC2Ids,ephemeral_gb=0,ephemeral_key_uuid=None,fault=<?>,flavor=Flavor(3),host='cmp1',hostname='testvm5',id=30,image_ref='86ec095a-9e8f-4ef4-a07c-46bf9fd781d2',info_cache=InstanceInfoCache,instance_type_id=3,kernel_id='',key_data=None,key_name=None,keypairs=KeyPairList,launch_index=0,launched_at=None,launched_on='cmp1',locked=False,locked_by=None,memory_mb=64,metadata={},migration_context=<?>,new_flavor=None,node='cmp1.dkalashnik-pike-dvr-v2.bud-mk.local',numa_topology=None,old_flavor=None,os_type=None,pci_devices=PciDeviceList,pci_requests=InstancePCIRequests,power_state=0,progress=0,project_id='1f40255ee8bc4f899ac7e7fcf96ef889',ramdisk_id='',reservation_id='r-u06ajlk3',root_device_name='/dev/vda',root_gb=0,security_groups=SecurityGroupList,services=<?>,shutdown_terminate=False,system_metadata={boot_roles='_member_,admin',image_base_image_ref='86ec095a-9e8f-4ef4-a07c-46bf9fd781d2',image_container_format='bare',image_disk_format='qcow2',image_min_disk='0',image_min_ram='0',network_allocated='True',owner_project_name='admin',owner_user_name='admin'},tags=TagList,task_state='spawning',terminated_at=None,updated_at=2018-07-18T13:34:20Z,user_data=None,user_id='176fe61f295e4da4b23fe846d62dc441',uuid=d3856331-fda4-4179-a3d0-9a2a720ffd3d,vcpu_model=VirtCPUModel,vcpus=1,vm_mode=None,vm_state='building')

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix proposed to oslo.log (master)

Fix proposed to branch: master
Review: https://review.openstack.org/594503

Changed in oslo.log:
assignee: nobody → Sam Yaple (s8m)
status: New → In Progress
Revision history for this message
OpenStack Infra (hudson-openstack) wrote :

Fix proposed to branch: master
Review: https://review.opendev.org/679312

Changed in oslo.log:
assignee: Sam Yaple (s8m) → Vladyslav Drok (vdrok)
Ben Nemec (bnemec)
Changed in oslo.log:
importance: Undecided → Medium
Changed in oslo.log:
assignee: Vladyslav Drok (vdrok) → Stephen Finucane (stephenfinucane)
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix merged to oslo.log (master)

Reviewed: https://review.opendev.org/679312
Committed: https://git.openstack.org/cgit/openstack/oslo.log/commit/?id=b52c8cd247e9b185d176bfbc4c24c5a2cb35e5be
Submitter: Zuul
Branch: master

commit b52c8cd247e9b185d176bfbc4c24c5a2cb35e5be
Author: Vladyslav Drok <email address hidden>
Date: Fri Jul 20 14:17:43 2018 +0300

    Serialize complex objects in FluentFormatter

    This change introduces the serialization with basically json dumps,
    falling back to repr for non-serializable object. We check the types
    of the top level objects passed to the formatter, as for example
    an object enclosed into dictionary passed to the logger should be a
    much more rare case.

    Closes-Bug: 1782361
    Change-Id: Ib214f95abfadd91f85b6cce853057a572ec287f6

Changed in oslo.log:
status: In Progress → Fix Released
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix included in openstack/oslo.log 3.45.1

This issue was fixed in the openstack/oslo.log 3.45.1 release.

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Change abandoned on oslo.log (master)

Change abandoned by Stephen Finucane (<email address hidden>) on branch: master
Review: https://review.opendev.org/594503

To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.