search

rubycdp / ferrum

Headless Chrome Ruby API
https://ferrum.rubycdp.com
MIT License
1.71k stars 123 forks source link

Ferrum::BrowserError: Message may have string 'sessionId' property #477

Open bitscraps opened 1 month ago

bitscraps commented 1 month ago

Describe the bug When upgrading to Ferrum 0.15 using Cuprite 0.15.1 we get errors in all our tests. The error being returned is Ferrum::BrowserError: Message may have string 'sessionId' property. This seems to be an error returned from Chrome itself. Looking at the messages being sent I can see that sessionId is being passed to the message with a value of nil. I've compared this to messages being sent by 0.14 where it worked and can see there that sessionId is excluded.

To Reproduce I've managed to get a los of all messages that have been send to chrome from the Client.

{:method=>"Target.setAutoAttach", :params=>{:autoAttach=>true, :waitForDebuggerOnStart=>true, :flatten=>true}, :id=>1}
{:method=>"Target.setDiscoverTargets", :params=>{:discover=>true}, :id=>2}
{:method=>"Runtime.runIfWaitingForDebugger", :params=>{}, :id=>3, :sessionId=>"62CA5EEA9BA327057064982A50E97356"}
{:method=>"Runtime.runIfWaitingForDebugger", :params=>{}, :id=>4, :sessionId=>"0355BF1AE37FA21AB2C41D9F5545D283"}
{:method=>"Runtime.runIfWaitingForDebugger", :params=>{}, :id=>5, :sessionId=>"F3227A2D02CD8B7360CDB4C4A98AEA2C"}
{:method=>"Runtime.runIfWaitingForDebugger", :params=>{}, :id=>6, :sessionId=>"0A146E1C98DD997974CC2A2166DB82D5"}
{:method=>"Runtime.runIfWaitingForDebugger", :params=>{}, :id=>7, :sessionId=>"4E7BED7C59001D87451C772F44B439B6"}
{:method=>"Target.createBrowserContext", :params=>{}, :id=>8}
{:method=>"Target.createTarget", :params=>{:browserContextId=>"8A241AA8F179D7832D0EEB10C8461595", :url=>"about:blank"}, :id=>9}
{:method=>"Runtime.runIfWaitingForDebugger", :params=>{}, :id=>10, :sessionId=>"773A120C288934EA46B827754E61A4FB"}
{:method=>"Page.enable", :params=>{}, :id=>11, :sessionId=>nil}
{:method=>"Page.enable", :params=>{}, :id=>12, :sessionId=>nil}
{:method=>"Page.enable", :params=>{}, :id=>13, :sessionId=>nil}

Expected behavior Expect messages to be sent without issue to Chrome. As in 0.14.

Desktop (please complete the following information):

route commented 1 month ago

New Ferrum has a new feature included, flatten mode, so we use one socket connection to all pages, versus having socket per page. To understand why there's no session id I'd need a full debug log or a minimal reproducible case.

bitscraps commented 1 month ago

What do I need to do to get a full debug log, what does it need to include?

bitscraps commented 1 month ago

I've managed to get a debug log:

▶ 0.009144624998953077 {"method":"Target.setAutoAttach","params":{"autoAttach":true,"waitForDebuggerOnStart":true,"flatten":true},"id":1}
    ◀ 0.06304024999917601 {"id":1,"result":{}}
    ◀ 0.06336499999997613 {"method":"Target.attachedToTarget","params":{"sessionId":"C806DBAD0BCEAFE697ABA33A49CD08EB","targetInfo":{"targetId":"3A6DE0D673B8CB4FEDFC0E2814C9C07F","type":"page","title":"about:blank","url":"about:blank","attached":true,"canAccessOpener":false,"browserContextId":"7AFA5F5CCC71EF50F2B7A06F7BBE7839"},"waitingForDebugger":true}}

▶ 0.06386020799982361 {"method":"Target.setDiscoverTargets","params":{"discover":true},"id":2}
    ◀ 0.06406224999955157 {"method":"Target.attachedToTarget","params":{"sessionId":"CADC4EB456F60A1D2625DBB9F666DDEA","targetInfo":{"targetId":"B3EA91BF0AB2031DDC170F0EB322F5A9","type":"page","title":"","url":"file:///","attached":true,"canAccessOpener":false,"browserContextId":"E5A74AEDEBD1F29EF15435D4CB9C29CF"},"waitingForDebugger":true}}
    ◀ 0.064296791999368 {"id":2,"result":{}}

▶ 0.0640857500002312 {"method":"Runtime.runIfWaitingForDebugger","params":{},"id":3,"sessionId":"C806DBAD0BCEAFE697ABA33A49CD08EB"}

▶ 0.06515604199921654 {"method":"Runtime.runIfWaitingForDebugger","params":{},"id":4,"sessionId":"CADC4EB456F60A1D2625DBB9F666DDEA"}
    ◀ 0.0654185419989517 {"id":3,"result":{},"sessionId":"C806DBAD0BCEAFE697ABA33A49CD08EB"}
    ◀ 0.0664067919988156 {"id":4,"result":{},"sessionId":"CADC4EB456F60A1D2625DBB9F666DDEA"}

▶ 0.3072634170002857 {"method":"Target.createBrowserContext","params":{},"id":5}
    ◀ 0.30777354199926776 {"id":5,"result":{"browserContextId":"2805639CD8E3DD33DCFE92F04E3820E5"}}

▶ 0.30799370800014003 {"method":"Target.createTarget","params":{"browserContextId":"2805639CD8E3DD33DCFE92F04E3820E5","url":"about:blank"},"id":6}
    ◀ 0.31178745800025354 {"method":"Target.targetCreated","params":{"targetInfo":{"targetId":"E685C434DDFF9CDDED5A15B53A431F96","type":"page","title":"","url":"","attached":false,"canAccessOpener":false,"browserContextId":"2805639CD8E3DD33DCFE92F04E3820E5"}}}
    ◀ 0.31205879200024356 {"method":"Target.targetInfoChanged","params":{"targetInfo":{"targetId":"E685C434DDFF9CDDED5A15B53A431F96","type":"page","title":"","url":"","attached":true,"canAccessOpener":false,"browserContextId":"2805639CD8E3DD33DCFE92F04E3820E5"}}}
    ◀ 0.3123437920003198 {"method":"Target.attachedToTarget","params":{"sessionId":"4A672D8D2CA1BDC863F7F9D5BDCEBD65","targetInfo":{"targetId":"E685C434DDFF9CDDED5A15B53A431F96","type":"page","title":"","url":"","attached":true,"canAccessOpener":false,"browserContextId":"2805639CD8E3DD33DCFE92F04E3820E5"},"waitingForDebugger":true}}

▶ 0.3127196669993282 {"method":"Runtime.runIfWaitingForDebugger","params":{},"id":7,"sessionId":"4A672D8D2CA1BDC863F7F9D5BDCEBD65"}
    ◀ 0.3159771249993355 {"id":6,"result":{"targetId":"E685C434DDFF9CDDED5A15B53A431F96"}}

▶ 0.3165415000003122 {"method":"Page.enable","params":{},"id":8,"sessionId":null}
    ◀ 0.3174140829996759 {"id":8,"error":{"code":-32600,"message":"Message may have string 'sessionId' property"}}

▶ 0.3182485830002406 {"method":"Page.enable","params":{},"id":9,"sessionId":null}
    ◀ 0.3185496249989228 {"id":9,"error":{"code":-32600,"message":"Message may have string 'sessionId' property"}}

▶ 0.3210659169999417 {"method":"Page.enable","params":{},"id":10,"sessionId":null}
    ◀ 0.321283332999883 {"id":10,"error":{"code":-32600,"message":"Message may have string 'sessionId' property"}}
    ◀ 0.35395833300026425 {"method":"Target.targetInfoChanged","params":{"targetInfo":{"targetId":"E685C434DDFF9CDDED5A15B53A431F96","type":"page","title":"about:blank","url":"about:blank","attached":true,"canAccessOpener":false,"browserContextId":"2805639CD8E3DD33DCFE92F04E3820E5"}}}
    ◀ 0.35515420800038555 {"id":7,"result":{},"sessionId":"4A672D8D2CA1BDC863F7F9D5BDCEBD65"}

I'll see if I can extract a minimal reproducible case from my code tonight

route commented 1 month ago

I don't see where you created 3 Target in the log, how do you create pages? Can you show simplified test at least?

bitscraps commented 1 month ago

So this is running as an Rspec test using Cuprite and Capybara.

At present I only have a test as setup within our app running rails.

The test is simply a visit, which is where it falls over:

scenario 'a business views the academy' do
    puts "Visit page"
    visit buttercms_path
    puts "visited"
    click_link 'All'

    expect(page).to have_http_status 200
  end

I dont believe we are doing anything special regarding our Cuprite setup:

require 'capybara/cuprite'

Capybara.register_driver :cuprite do |app|
  Capybara::Cuprite::Driver.new(
    app,
    headless:        !ENV['HEADED_BROWSER'],
    js_errors:       true,
    url:             "http://#{chrome_ip}:9222/json/list",
    window_size:     [1280, 900],
    timeout:         15,
    process_timeout: 30,
    url_blacklist: [/maps.googleapis.com/]
  )
end

This is the log for that test above:

▶ 0.012125792000006186 {"method":"Target.setAutoAttach","params":{"autoAttach":true,"waitForDebuggerOnStart":true,"flatten":true},"id":1}
    ◀ 0.06678391699824715 {"id":1,"result":{}}
    ◀ 0.06701220899776672 {"method":"Target.attachedToTarget","params":{"sessionId":"A04A03D98BFC814EF4D856A0296E9371","targetInfo":{"targetId":"0426F1663CCBB82A18B366D5895F78A8","type":"page","title":"about:blank","url":"about:blank","attached":true,"canAccessOpener":false,"browserContextId":"DF76ECEA06B84B3BE06BAB96C1FA92DD"},"waitingForDebugger":true}}
    ◀ 0.06735037499674945 {"method":"Target.attachedToTarget","params":{"sessionId":"2321990BFE016AFE18B871975824D6AD","targetInfo":{"targetId":"0CEE1D340980028F6F5EE8E1E93647F5","type":"page","title":"about:blank","url":"about:blank","attached":true,"canAccessOpener":false,"browserContextId":"14B6D015E0DF63238BD129DC59EEC2BE"},"waitingForDebugger":true}}

▶ 0.06745887499710079 {"method":"Target.setDiscoverTargets","params":{"discover":true},"id":2}

▶ 0.06757899999865913 {"method":"Runtime.runIfWaitingForDebugger","params":{},"id":3,"sessionId":"A04A03D98BFC814EF4D856A0296E9371"}

▶ 0.06801554199773818 {"method":"Runtime.runIfWaitingForDebugger","params":{},"id":4,"sessionId":"2321990BFE016AFE18B871975824D6AD"}

▶ 0.06821437499820604 {"method":"Runtime.runIfWaitingForDebugger","params":{},"id":5,"sessionId":"217C5E34B564BB27A4E63AB3217C8714"}
    ◀ 0.06782183399991482 {"method":"Target.attachedToTarget","params":{"sessionId":"217C5E34B564BB27A4E63AB3217C8714","targetInfo":{"targetId":"23C797199F72242BBCF2EEDF2649D132","type":"page","title":"about:blank","url":"about:blank","attached":true,"canAccessOpener":false,"browserContextId":"D3496E65F212EBF6AD25C1D9BB317EBF"},"waitingForDebugger":true}}
    ◀ 0.06835487499847659 {"method":"Target.attachedToTarget","params":{"sessionId":"499B1EA0520FE21EE192D5B57FC2EC92","targetInfo":{"targetId":"60FE199F122207986DF4FD32E8A28359","type":"page","title":"about:blank","url":"about:blank","attached":true,"canAccessOpener":false,"browserContextId":"B7AC7137491DBB9A387CCE700AEDE7BB"},"waitingForDebugger":true}}
    ◀ 0.06860749999759719 {"method":"Target.attachedToTarget","params":{"sessionId":"E28A963828B98B5F8E037E70CC11DA36","targetInfo":{"targetId":"64C73AA620625E90953A0F86602217EC","type":"page","title":"about:blank","url":"about:blank","attached":true,"canAccessOpener":false,"browserContextId":"F131F858C4F8BE5314362A83CB21FBCD"},"waitingForDebugger":true}}
    ◀ 0.06896387499728007 {"method":"Target.attachedToTarget","params":{"sessionId":"3AFCE4EEF475E0602AEAB35E674F6BEF","targetInfo":{"targetId":"80B6C13C2884B13D41481DBF7C0DF936","type":"page","title":"about:blank","url":"about:blank","attached":true,"canAccessOpener":false,"browserContextId":"7E4AF3010E92249EA92FB01ED7D44417"},"waitingForDebugger":true}}

▶ 0.06877899999744841 {"method":"Runtime.runIfWaitingForDebugger","params":{},"id":6,"sessionId":"499B1EA0520FE21EE192D5B57FC2EC92"}
    ◀ 0.06941187499978696 {"method":"Target.attachedToTarget","params":{"sessionId":"3B21A47F1074D3E24F2AD6FC637C3915","targetInfo":{"targetId":"856E9996B7B6D2A4CE60FCF718BDF28D","type":"page","title":"about:blank","url":"about:blank","attached":true,"canAccessOpener":false,"browserContextId":"4F753FE28835E3BE1AED90B8A479C603"},"waitingForDebugger":true}}

▶ 0.06913062499734224 {"method":"Runtime.runIfWaitingForDebugger","params":{},"id":7,"sessionId":"E28A963828B98B5F8E037E70CC11DA36"}

▶ 0.06964337499812245 {"method":"Runtime.runIfWaitingForDebugger","params":{},"id":8,"sessionId":"3AFCE4EEF475E0602AEAB35E674F6BEF"}
    ◀ 0.06985233399973367 {"method":"Target.attachedToTarget","params":{"sessionId":"36C5FD93AC056AF32FB2EED3B1977689","targetInfo":{"targetId":"95ABF644448DEBBF027AE5DDF9B2BAF0","type":"page","title":"","url":"file:///","attached":true,"canAccessOpener":false,"browserContextId":"672C9149CF3E8394FA090378728B18FD"},"waitingForDebugger":true}}

▶ 0.06998504199873423 {"method":"Runtime.runIfWaitingForDebugger","params":{},"id":9,"sessionId":"3B21A47F1074D3E24F2AD6FC637C3915"}
    ◀ 0.07015787499767612 {"method":"Target.attachedToTarget","params":{"sessionId":"C2901F9DED265335E9AB8E6B2E06F513","targetInfo":{"targetId":"B469BBEF47CB5624B63C866BD019D5B0","type":"page","title":"about:blank","url":"about:blank","attached":true,"canAccessOpener":false,"browserContextId":"0542A10B780D337ADA7FDEAB08A44BE9"},"waitingForDebugger":true}}
    ◀ 0.0707929169984709 {"method":"Target.attachedToTarget","params":{"sessionId":"5BA457D6FC5ECC8FBEC47568C0AD3E52","targetInfo":{"targetId":"C07A41DDB22DF0BBDC7838195F600BCC","type":"page","title":"about:blank","url":"about:blank","attached":true,"canAccessOpener":false,"browserContextId":"1536AD1E242A1AC4EE6597740F109FCC"},"waitingForDebugger":true}}
    ◀ 0.07100083399927826 {"method":"Target.attachedToTarget","params":{"sessionId":"C1763E602C6696871226196645516B61","targetInfo":{"targetId":"C1FFB2E58855903EBBAE886681AB6694","type":"page","title":"about:blank","url":"about:blank","attached":true,"canAccessOpener":false,"browserContextId":"833595C337DA7B9EF41D553053356846"},"waitingForDebugger":true}}
    ◀ 0.07108433399844216 {"id":2,"result":{}}

▶ 0.07084354199832887 {"method":"Runtime.runIfWaitingForDebugger","params":{},"id":10,"sessionId":"36C5FD93AC056AF32FB2EED3B1977689"}

▶ 0.07147137499850942 {"method":"Runtime.runIfWaitingForDebugger","params":{},"id":11,"sessionId":"C2901F9DED265335E9AB8E6B2E06F513"}
#################################
Visit
#################################
    ◀ 0.07120770899928175 {"id":3,"result":{},"sessionId":"A04A03D98BFC814EF4D856A0296E9371"}
    ◀ 0.07274495899764588 {"id":4,"result":{},"sessionId":"2321990BFE016AFE18B871975824D6AD"}
    ◀ 0.07280887499655364 {"id":6,"result":{},"sessionId":"499B1EA0520FE21EE192D5B57FC2EC92"}

▶ 0.072864291996666 {"method":"Target.createBrowserContext","params":{},"id":12}
    ◀ 0.07299924999824725 {"id":5,"result":{},"sessionId":"217C5E34B564BB27A4E63AB3217C8714"}
    ◀ 0.07320929199704551 {"id":8,"result":{},"sessionId":"3AFCE4EEF475E0602AEAB35E674F6BEF"}

▶ 0.07334799999807728 {"method":"Runtime.runIfWaitingForDebugger","params":{},"id":13,"sessionId":"5BA457D6FC5ECC8FBEC47568C0AD3E52"}
    ◀ 0.07347620899963658 {"id":7,"result":{},"sessionId":"E28A963828B98B5F8E037E70CC11DA36"}
    ◀ 0.07354058399869245 {"id":9,"result":{},"sessionId":"3B21A47F1074D3E24F2AD6FC637C3915"}
    ◀ 0.07380929199644015 {"id":10,"result":{},"sessionId":"36C5FD93AC056AF32FB2EED3B1977689"}
    ◀ 0.07412429199757753 {"id":11,"result":{},"sessionId":"C2901F9DED265335E9AB8E6B2E06F513"}
    ◀ 0.07417549999809125 {"id":12,"result":{"browserContextId":"6C75228CFF1DD847A452430AEC7050F0"}}
    ◀ 0.07462524999937159 {"id":13,"result":{},"sessionId":"5BA457D6FC5ECC8FBEC47568C0AD3E52"}

▶ 0.07361149999996996 {"method":"Runtime.runIfWaitingForDebugger","params":{},"id":14,"sessionId":"C1763E602C6696871226196645516B61"}

▶ 0.07454970899925684 {"method":"Target.createTarget","params":{"browserContextId":"6C75228CFF1DD847A452430AEC7050F0","url":"about:blank"},"id":15}
    ◀ 0.07500091699694167 {"id":14,"result":{},"sessionId":"C1763E602C6696871226196645516B61"}
    ◀ 0.08022558399898116 {"method":"Target.targetCreated","params":{"targetInfo":{"targetId":"93401C61B82369A9A78D65368EC0A03F","type":"page","title":"","url":"","attached":false,"canAccessOpener":false,"browserContextId":"6C75228CFF1DD847A452430AEC7050F0"}}}
    ◀ 0.08059445899925777 {"method":"Target.targetInfoChanged","params":{"targetInfo":{"targetId":"93401C61B82369A9A78D65368EC0A03F","type":"page","title":"","url":"","attached":true,"canAccessOpener":false,"browserContextId":"6C75228CFF1DD847A452430AEC7050F0"}}}
    ◀ 0.08110429199950886 {"method":"Target.attachedToTarget","params":{"sessionId":"8E57280DAE001F37EBF8B4DE63C2825C","targetInfo":{"targetId":"93401C61B82369A9A78D65368EC0A03F","type":"page","title":"","url":"","attached":true,"canAccessOpener":false,"browserContextId":"6C75228CFF1DD847A452430AEC7050F0"},"waitingForDebugger":true}}

▶ 0.08140487499986193 {"method":"Runtime.runIfWaitingForDebugger","params":{},"id":16,"sessionId":"8E57280DAE001F37EBF8B4DE63C2825C"}
    ◀ 0.08728633399732644 {"id":15,"result":{"targetId":"93401C61B82369A9A78D65368EC0A03F"}}

▶ 0.08826995899653411 {"method":"Page.enable","params":{},"id":17,"sessionId":null}
    ◀ 0.08916533399678883 {"id":17,"error":{"code":-32600,"message":"Message may have string 'sessionId' property"}}

▶ 0.09005662499839673 {"method":"Page.enable","params":{},"id":18,"sessionId":null}
    ◀ 0.09026645899939467 {"id":18,"error":{"code":-32600,"message":"Message may have string 'sessionId' property"}}

▶ 0.09102345899736974 {"method":"Page.enable","params":{},"id":19,"sessionId":null}
    ◀ 0.09122437499900116 {"id":19,"error":{"code":-32600,"message":"Message may have string 'sessionId' property"}}
    ◀ 0.12950933399770292 {"method":"Target.targetInfoChanged","params":{"targetInfo":{"targetId":"93401C61B82369A9A78D65368EC0A03F","type":"page","title":"about:blank","url":"about:blank","attached":true,"canAccessOpener":false,"browserContextId":"6C75228CFF1DD847A452430AEC7050F0"}}}
    ◀ 0.13183795899749384 {"id":16,"result":{},"sessionId":"8E57280DAE001F37EBF8B4DE63C2825C"}

Could this be a bug in Cuprite instead, should I raise an issue there instead.

route commented 1 month ago

Let's keep the convo here for now, I'll take care of it. I first need to understand where the issue lies

route commented 1 month ago

What is chrome_ip? The only outlier I noticed

bitscraps commented 1 month ago

chrome_ip contains the IP address of the docker container running our Chrome instance

route commented 1 month ago

This is the issue I'd say. What is your setup? The docker is running locally or we talk about CI? Does it work locally?

bitscraps commented 1 month ago

This is running a docker setup locally. The same setup works correctly with ferrum 0.14 and cuprite 0.15. However upgrading to ferrum 0.15 and cuprite 0.15.1 it starts to fail. The only changes are these 2 gems. The same docker setup works with the previous versions.