Bug in libhoney/log_transmission.rb when HONEYCOMB_DEBUG exists

[decimalator]

https://github.com/honeycombio/libhoney-rb/blob/468a4d114481143abcc32901f0e765111a421b6d/lib/libhoney/log_transmission.rb#L24

We ran into a bug in development for file uploads within our application because we use HONEYCOMB_DEBUG=true to prevent dev instances from spamming garbage events into our datasets, while still being able to see the events as they happen.

The problem didn't exist in our staging or production environments, which remove the HONEYCOMB_DEBUG key from the environment so that events flow normally. We patched libhoney/log_transmission.rb to have it print with .to_s.as_json instead of just .to_json and the crashes stopped.

A dump of the error is attached. Below is an example event that was triggering the bug:

{"meta.beeline_version"=>"0.5.0", "meta.local_hostname"=>"0d5385d8fe9d", "service_name"=>"od2", "meta.package"=>"rails", "meta.package_version"=>"5.1.6", "type"=>"http_server", "name"=>"hyrax/uploads#create", "request.method"=>"PATCH", "request.path"=>"/uploads/", "request.protocol"=>"http", "request.http_version"=>"HTTP/1.1", "request.host"=>"joshgum.library.oregonstate.edu:3000", "request.remote_addr"=>"192.168.80.1", "request.header.user_agent"=>"Mozilla/5.0 (Macintosh; Intel Mac OS X 10_14_2) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/71.0.3578.80 Safari/537.36", "trace.trace_id"=>"04a82779-cfbf-4be8-8294-92feac012644", "trace.span_id"=>"04a82779-cfbf-4be8-8294-92feac012644", "response.status_code"=>200, "duration_ms"=>6513.9651, "request.params.utf8"=>"1", "request.params._method"=>"patch", "request.params.authenticity_token"=>"7iMeGlmZRsQShM5rzYY+pstATasUoBkSon3PUugf5tSidfAps1WHS+JZT3Rp08sSXy1wNlioXS2ngv6aQD6WdA==", "request.params.video"=>{"title"=>["test", ""], "dcmi_type"=>"", "rights_statement"=>"http://rightsstatements.org/vocab/InC/1.0/", "height"=>"", "width"=>"", "abstract"=>[""], "accepted_name_usage"=>[""], "access_restrictions"=>"", "accession_number"=>[""], "acquisition_date"=>[""], "alternative"=>[""], "arranger"=>[""], "art_series"=>[""], "artist"=>[""], "author"=>[""], "award"=>[""], "award_date"=>[""], "barcode"=>[""], "biographical_information"=>[""], "box"=>[""], "box_name"=>[""], "box_number"=>[""], "canzoniere_poems"=>[""], "caption_title"=>[""], "cartographer"=>[""], "citation"=>[""], "collected_date"=>[""], "collector"=>[""], "common_name"=>[""], "compass_direction"=>[""], "composer"=>[""], "contents"=>[""], "conversion"=>[""], "copy_location"=>[""], "copyright_claimant"=>[""], "cover_description"=>[""], "coverage"=>[""], "created"=>[""], "creator_display"=>[""], "cultural_context"=>[""], "current_repository_id"=>[""], "date"=>[""], "date_digitized"=>"", "dedicatee"=>[""], "description_of_manifestation"=>[""], "designer"=>[""], "donor"=>[""], "editor"=>[""], "ethnographic_term"=>[""], "event"=>[""], "exhibit"=>[""], "extent"=>[""], "family"=>[""], "file_size"=>"", "folder_name"=>[""], "folder_number"=>[""], "form_of_work"=>[""], "format"=>[""], "former_owner"=>[""], "genus"=>[""], "gps_latitude"=>"", "gps_longitude"=>"", "has_finding_aid"=>[""], "has_part"=>["", ""], "has_version"=>[""], "higher_classification"=>[""], "hydrologic_unit_code"=>[""], "identification_verification_status"=>"", "illustrator"=>[""], "inscription"=>[""], "institution"=>[""], "interviewee"=>[""], "interviewer"=>[""], "isPartOf"=>[""], "is_version_of"=>[""], "issued"=>[""], "item_locator"=>[""], "language"=>[""], "layout"=>[""], "lc_subject"=>[""], "legal_name"=>[""], "license"=>"", "local_collection_id"=>[""], "local_collection_name"=>[""], "location"=>[""], "location_copyshelf_location"=>[""], "longitude_latitude_identification"=>[""], "lyricist"=>[""], "material"=>[""], "measurements"=>[""], "military_branch"=>[""], "military_highest_rank"=>"", "military_occupation"=>[""], "military_service_location"=>[""], "mode_of_issuance"=>[""], "modified"=>["2018-12-07T22:56:43+00:00", ""], "mods_note"=>[""], "object_orientation"=>"", "oembed_url"=>"http://www.google.com", "order"=>[""], "original_name_usage"=>[""], "owner"=>"", "patron"=>[""], "photographer"=>[""], "phylum_or_division"=>[""], "physical_extent"=>[""], "place_of_production"=>[""], "primary_set"=>"", "print_maker"=>[""], "provenance"=>[""], "publication_place"=>[""], "publisher"=>[""], "ranger_district"=>[""], "recipient"=>[""], "relation"=>[""], "replaces_url"=>"", "repository"=>"", "resource_type"=>[""], "rights"=>[""], "rights_holder"=>[""], "scientific_name_authorship"=>[""], "scribe"=>[""], "series_name"=>[""], "series_number"=>[""], "set"=>[""], "source"=>[""], "source_condition"=>[""], "species"=>[""], "specimentype"=>"", "sports_team"=>[""], "state_or_edition"=>[""], "street_address"=>[""], "style_or_period"=>[""], "subject"=>[""], "submission_date"=>"2018-11-21T20:10:59+00:00", "taxon_class"=>[""], "technique"=>[""], "temporal"=>[""], "tgn"=>[""], "transcriber"=>[""], "translator"=>[""], "tribal_classes"=>[""], "tribal_notes"=>[""], "tribal_terms"=>[""], "tribal_title"=>[""], "use_restrictions"=>[""], "view_date"=>[""], "water_basin"=>[""], "workType"=>[""], "admin_set_id"=>"admin_set/default", "member_of_collection_ids"=>"", "find_child_work"=>"", "permissions_attributes"=>{"0"=>{"access"=>"edit", "id"=>"09fbb2e7-69d2-40ac-9cc3-552c585bf021/be/bf/d5/40/bebfd540-390a-4866-b2df-8da794883809"}}, "visibility"=>"open", "visibility_during_embargo"=>"restricted", "embargo_release_date"=>"2018-12-11", "visibility_after_embargo"=>"open", "visibility_during_lease"=>"open", "lease_expiration_date"=>"2018-12-11", "visibility_after_lease"=>"restricted", "version"=>"W/\"7586e27c8d1a95c03f21e315783851bc5629da91\""}, "request.params.uploaded_files"=>["", "42"], "request.params.new_group_name_skel"=>"Select a group", "request.params.new_group_permission_skel"=>"none", "request.params.new_user_name_skel"=>"", "request.params.new_user_permission_skel"=>"none", "request.params.files"=>[#<ActionDispatch::Http::UploadedFile:0x000055a7a67b0388 @tempfile=#<Tempfile:/tmp/RackMultipart20181210-160-14t2cad.png>, @original_filename="avatar.png", @content_type="image/png", @headers="Content-Disposition: form-data; name=\"files[]\"; filename=\"avatar.png\"\r\nContent-Type: image/png\r\n">], "request.controller"=>"hyrax/uploads", "request.action"=>"create", "request.route"=>"PATCH /uploads", "app.version"=>"WC2-0.0.1", "app.classname"=>"Hyrax::UploadsController"} Let me know if you need help reproducing.

[decimalator]

Attached error dump referenced above:

libhoney-rb.txt

[straleyb]

We were able to get to that point in the code in a debugger. The transformation from the hash to json worked when it was converted to a string and then printed as json @output.puts(event.data.to_s.as_json)

This might or might not be the fix, But im not sure if it has any unintended side effects for the Honeycomb code base.

[martin308]

Thanks for the report @decimalator @straleyb. I looked into this and it seems that the event would still have issues in the other environments it just wouldn't be reported. I put a quick go at a potential solution over in #37