openbmc / bmcweb

A do everything Redfish, KVM, GUI, and DBus webserver for OpenBMC
Apache License 2.0
156 stars 131 forks source link

CI Test: terminate called after throwing an instance of 'boost::wrapexcept<boost::system::system_error>' #159

Closed geissonator closed 3 years ago

geissonator commented 3 years ago

We're running our CI regression suite against a downstream system. The bmcweb version used is the latest in master (f23b729676559f539790580930b1ff3b0c05805b).

During the CI test suite, we're getting this in the journal:

Oct 27 16:30:31 systemxyz bmcweb[225]: terminate called after throwing an instance of 'boost::wrapexcept<boost::system::system_error>'
Oct 27 16:30:31 systemxyz bmcweb[225]:   what():  remote_endpoint: Bad file descriptor
Oct 27 16:30:31 systemxyz systemd[1]: Created slice system-systemd\x2dcoredump.slice.
Oct 27 16:30:31 systemxyz systemd[1]: Started Process Core Dump (PID 484/UID 0).
Oct 27 16:30:31 systemxyz systemd[1]: bmcweb.service: Main process exited, code=dumped, status=6/ABRT
Oct 27 16:30:31 systemxyz systemd[1]: bmcweb.service: Failed with result 'core-dump'.
Oct 27 16:30:32 systemxyz systemd[1]: Started Start bmcweb server.

The test case is Delete_Redfish_Session_Using_Valid_Login. Here's the robot output leading to the fail:

Perform a GET list request and return available resource paths. Description of argument(s): resource_path URI resource absolute path (e.g. "/redfish/v1/SessionService/Sessions").
Start / End / Elapsed:  20201027 11:30:31.142 / 20201027 11:30:32.923 / 00:00:01.781
11:30:31.158    INFO    Attempt 1 of /redfish/v1/SessionService/Sessions    
11:30:31.170    INFO    Response Time to /redfish/v1/SessionService/Sessions: 0.01127684861421585 seconds.  
11:30:31.176    INFO    Attempt 1 of /redfish/v1/SessionService/Sessions/QWNuVpWsvW     
11:30:31.185    INFO    Response Time to /redfish/v1/SessionService/Sessions/QWNuVpWsvW: 0.00806356966495514 seconds.   
11:30:31.190    INFO    Attempt 1 of /redfish/v1/SessionService/Sessions/xrXz6F48xU     
11:30:31.201    INFO    Response Time to /redfish/v1/SessionService/Sessions/xrXz6F48xU: 0.010162051767110825 seconds.  
11:30:31.207    INFO    Attempt 1 of /redfish/v1/SessionService/Sessions/1jl8XoSzTS     
11:30:31.217    INFO    Response Time to /redfish/v1/SessionService/Sessions/1jl8XoSzTS: 0.00998155027627945 seconds.   
11:30:31.223    INFO    Attempt 1 of /redfish/v1/SessionService/Sessions/W79691g9BI     
11:30:31.231    INFO    Response Time to /redfish/v1/SessionService/Sessions/W79691g9BI: 0.007959064096212387 seconds.  
11:30:31.237    INFO    Attempt 1 of /redfish/v1/SessionService/Sessions/HXLdouNdBm     
11:30:31.245    INFO    Response Time to /redfish/v1/SessionService/Sessions/HXLdouNdBm: 0.008081391453742981 seconds.  
11:30:31.251    INFO    Attempt 1 of /redfish/v1/SessionService/Sessions/XnJffjy7Yp     
11:30:31.260    INFO    Response Time to /redfish/v1/SessionService/Sessions/XnJffjy7Yp: 0.008939787745475769 seconds.  
11:30:31.266    INFO    Attempt 1 of /redfish/v1/SessionService/Sessions/DaHiRC6nMY     
11:30:31.275    INFO    Response Time to /redfish/v1/SessionService/Sessions/DaHiRC6nMY: 0.008419781923294067 seconds.  
11:30:31.280    INFO    Attempt 1 of /redfish/v1/SessionService/Sessions/99YDRECb5L     
11:30:31.290    INFO    Response Time to /redfish/v1/SessionService/Sessions/99YDRECb5L: 0.00936480239033699 seconds.   
11:30:31.296    INFO    Attempt 1 of /redfish/v1/SessionService/Sessions/295wQVbYiD     
11:30:31.306    INFO    Response Time to /redfish/v1/SessionService/Sessions/295wQVbYiD: 0.008840102702379227 seconds.  
11:30:31.312    INFO    Attempt 1 of /redfish/v1/SessionService/Sessions/S98PEyGdtK     
11:30:31.323    INFO    Response Time to /redfish/v1/SessionService/Sessions/S98PEyGdtK: 0.010199524462223053 seconds.  
11:30:31.329    INFO    Attempt 1 of /redfish/v1/SessionService/Sessions/FDtB1Lhvxw     
11:30:31.339    INFO    Response Time to /redfish/v1/SessionService/Sessions/FDtB1Lhvxw: 0.0091678686439991 seconds.    
11:30:31.345    INFO    Attempt 1 of /redfish/v1/SessionService/Sessions/yE4AIPuBTh     
11:30:31.354    INFO    Response Time to /redfish/v1/SessionService/Sessions/yE4AIPuBTh: 0.008602768182754517 seconds.  
11:30:31.361    INFO    Attempt 1 of /redfish/v1/SessionService/Sessions/JPmvRUlzZ7     
11:30:31.371    INFO    Response Time to /redfish/v1/SessionService/Sessions/JPmvRUlzZ7: 0.008906397968530655 seconds.  
11:30:31.379    INFO    Attempt 1 of /redfish/v1/SessionService/Sessions/ZHX6u1JEJt     
11:30:31.388    INFO    Response Time to /redfish/v1/SessionService/Sessions/ZHX6u1JEJt: 0.009194035083055496 seconds.  
11:30:31.401    INFO    Attempt 1 of /redfish/v1/SessionService/Sessions/JSrxxEy9WM     
11:30:31.411    INFO    Response Time to /redfish/v1/SessionService/Sessions/JSrxxEy9WM: 0.009195692837238312 seconds.  
11:30:31.423    INFO    Attempt 1 of /redfish/v1/SessionService/Sessions/LZtAdrTFeX     
11:30:31.433    INFO    Response Time to /redfish/v1/SessionService/Sessions/LZtAdrTFeX: 0.008318457752466202 seconds.  
11:30:31.441    INFO    Attempt 1 of /redfish/v1/SessionService/Sessions/iWBouknIIz     
11:30:31.450    INFO    Response Time to /redfish/v1/SessionService/Sessions/iWBouknIIz: 0.00809875875711441 seconds.   
11:30:31.458    INFO    Attempt 1 of /redfish/v1/SessionService/Sessions    
11:30:31.469    INFO    Response Time to /redfish/v1/SessionService/Sessions: 0.010793652385473251 seconds.     
11:30:31.477    INFO    Attempt 1 of /redfish/v1/SessionService/Sessions/zEZWiHKAnD     
11:30:31.488    INFO    Response Time to /redfish/v1/SessionService/Sessions/zEZWiHKAnD: 0.00977972149848938 seconds.   
11:30:31.494    INFO    Attempt 1 of /redfish/v1/SessionService/Sessions/MwxDlFaFps     
11:30:31.505    INFO    Response Time to /redfish/v1/SessionService/Sessions/MwxDlFaFps: 0.01034688949584961 seconds.   
11:30:31.511    INFO    Attempt 1 of /redfish/v1/SessionService/Sessions/hueGsOCxb3     
11:30:31.521    INFO    Response Time to /redfish/v1/SessionService/Sessions/hueGsOCxb3: 0.008308503776788712 seconds.  
11:30:31.529    INFO    Attempt 1 of /redfish/v1/SessionService/Sessions/NwrSqO1vKp     
11:30:31.539    INFO    Response Time to /redfish/v1/SessionService/Sessions/NwrSqO1vKp: 0.008948266506195068 seconds.  
11:30:31.545    INFO    Attempt 1 of /redfish/v1/SessionService/Sessions/LaxtDJoHDD     
11:30:31.555    INFO    Response Time to /redfish/v1/SessionService/Sessions/LaxtDJoHDD: 0.009172055870294571 seconds.  
11:30:31.571    INFO    Attempt 1 of /redfish/v1/SessionService/Sessions/3HDwzJA62T     
11:30:31.581    INFO    Response Time to /redfish/v1/SessionService/Sessions/3HDwzJA62T: 0.009285733103752136 seconds.  
11:30:31.587    INFO    Attempt 1 of /redfish/v1/SessionService/Sessions/RhKN7YukK4     
11:30:31.598    INFO    Response Time to /redfish/v1/SessionService/Sessions/RhKN7YukK4: 0.00990784540772438 seconds.   
11:30:31.606    INFO    Attempt 1 of /redfish/v1/SessionService/Sessions/D8acE2RFoy     
11:30:31.615    INFO    Response Time to /redfish/v1/SessionService/Sessions/D8acE2RFoy: 0.008647341281175613 seconds.  
11:30:31.622    INFO    Attempt 1 of /redfish/v1/SessionService/Sessions/3ZrJG1RGxS     
11:30:31.631    INFO    Response Time to /redfish/v1/SessionService/Sessions/3ZrJG1RGxS: 0.008315838873386383 seconds.  
11:30:31.640    INFO    Attempt 1 of /redfish/v1/SessionService/Sessions/J0IFKdkUvc     
11:30:31.649    INFO    Response Time to /redfish/v1/SessionService/Sessions/J0IFKdkUvc: 0.008223630487918854 seconds.  
11:30:31.655    INFO    Attempt 1 of /redfish/v1/SessionService/Sessions/HONMlgbaf0     
11:30:31.657    INFO    Retrying /redfish/v1/SessionService/Sessions/HONMlgbaf0 [Remote end closed connection without response]     
11:30:32.659    INFO    Attempt 2 of /redfish/v1/SessionService/Sessions/HONMlgbaf0     
11:30:32.913    INFO    Response Time to /redfish/v1/SessionService/Sessions/HONMlgbaf0: 0.04081426560878754 seconds.   
11:30:32.922    FAIL    ValueError: The HTTP status code was not valid:
status:                                           401
valid_status_codes:
  [0]:                                            200
  [1]:                                            404
  [2]:                                            500
edtanous commented 3 years ago

I see a couple things going on here:

https://github.com/openbmc/bmcweb/blob/04e438cbad66838724d78ce12f28aff1fb892a63/http/http_connection.hpp#L320

That line needs to use the ec overload of remote_endpoint. This is a perfect example of "Using methods that throw (or not handling bad inputs)" documented in COMMON_ERRORS.md.

Once that is fixed, your crash should go away, but you'll end up with a blank string. Next we need to figure out why the remote_endpoint call is failing. Is this test attempting to request redfish resources from within the bmc? Is it running in ipv6 mode? Is there anything else strange about this network setup (USB NIC, custom nic driver, ect) what would make remote_endpoint fail?

@sunharis Looks like this might be what you were trying to fix here: https://gerrit.openbmc-project.xyz/c/openbmc/bmcweb/+/37616

Can you comment on Andrews failure?

geissonator commented 3 years ago

Thanks for the quick response @edtanous . Will need @gkeishin to comment on the test specifics but I think it basically creates a Refish Session, deletes it, then queries all sessions to be sure it's gone.

https://github.com/openbmc/openbmc-test-automation/blob/master/redfish/service_root/test_service_root.robot#L83

edtanous commented 3 years ago

This is issue number 3 on https://github.com/openbmc/bmcweb/commit/e436008377fbcf287be02c9e9e1b59c6627d7673

Issue number 1 is theory fixed in this commit: https://gerrit.openbmc-project.xyz/c/openbmc/bmcweb/+/37580

There's another patchset here that fixes some other issues: https://gerrit.openbmc-project.xyz/c/openbmc/bmcweb/+/37616

This patch (not up yet) would fix issue number 3.

And the problem for basic auth is still there.

I think we're at the point where we need to revert e436008377fbcf287be02c9e9e1b59c6627d7673, and come at it again in a new patchset. Any objections?

geissonator commented 3 years ago

We did pull in https://gerrit.openbmc-project.xyz/c/openbmc/bmcweb/+/37721 from Gunnar and our CI test passed with it. I'll let you guys sort out what you want to do though.

ratagupt commented 3 years ago

@edtanous : Either the upstream implementation of usage of remote_endpoint or the https://gerrit.openbmc-project.xyz/c/openbmc/bmcweb/+/37616 both are being crashed.

How about getting the IP address of the other end as of following?

accept(ssock, (struct sockaddr *)&clientAddr, &len) inet_ntoa/p(clientAddr.sin_addr).

edtanous commented 3 years ago

This issue has been resolved on master for some time now. Please reopen if you can still reproduce.