Bug 1582458

Summary: Unhandled exception in plug-in! error: [Errno 32] Broken pipe
Product: Red Hat Enterprise Linux 7 Reporter: Jakub Krysl <jkrysl>
Component: libstoragemgmtAssignee: Gris Ge <fge>
Status: CLOSED ERRATA QA Contact: Jakub Krysl <jkrysl>
Severity: unspecified Docs Contact:
Priority: unspecified    
Version: 7.5   
Target Milestone: rc   
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: libstoragemgmt-1.6.2-2.el7 Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2018-10-30 10:10:39 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:

Description Jakub Krysl 2018-05-25 09:45:25 UTC
Description of problem:
When issuing a command using lsmcli and aborting it (CTRL+C), there is quite high change to get broken pipe error. I think it matters mostly on timing, so with proper timing user would get this every time.

I tested ontap and sim plugins, got broken pipe on both.
I tested lsmcli commands volume-create, volume-delete, volume-replicate-range and managed to get broken pipe with all of them.

Ontap:
# lsmcli volume-create --name broken_pipe --size 10G --pool /vol/vol0
^C
# systemctl status libstoragemgmt
● libstoragemgmt.service - libstoragemgmt plug-in server daemon
   Loaded: loaded (/usr/lib/systemd/system/libstoragemgmt.service; enabled; vendor preset: enabled)
   Active: active (running) since Fri 2018-05-25 09:22:47 CEST; 2h 11min ago
 Main PID: 1289 (lsmd)
    Tasks: 2 (limit: 4915)
   CGroup: /system.slice/libstoragemgmt.service
           └─1289 /usr/bin/lsmd -d

May 25 09:22:47 localhost.localdomain systemd[1]: Started libstoragemgmt plug-in server daemon.
May 25 11:34:33 localhost.localdomain /ontap_lsmplugin[9208]: ontap_lsmplugin: Unhandled exception in plug-in!
May 25 11:34:33 localhost.localdomain /ontap_lsmplugin[9208]: ontap_lsmplugin: Traceback (most recent call last):
May 25 11:34:33 localhost.localdomain /ontap_lsmplugin[9208]: ontap_lsmplugin:   File "/usr/lib/python3.6/site-packages/lsm/_pluginrunner.py", line 114, in run
May 25 11:34:33 localhost.localdomain /ontap_lsmplugin[9208]: ontap_lsmplugin:     self.tp.send_resp(result)
May 25 11:34:33 localhost.localdomain /ontap_lsmplugin[9208]: ontap_lsmplugin:   File "/usr/lib/python3.6/site-packages/lsm/_transport.py", line 171, in send_resp
May 25 11:34:33 localhost.localdomain /ontap_lsmplugin[9208]: ontap_lsmplugin:     self._send_msg(json.dumps(r, cls=_DataEncoder))
May 25 11:34:33 localhost.localdomain /ontap_lsmplugin[9208]: ontap_lsmplugin:   File "/usr/lib/python3.6/site-packages/lsm/_transport.py", line 75, in _send_msg
May 25 11:34:33 localhost.localdomain /ontap_lsmplugin[9208]: ontap_lsmplugin:     self.s.sendall(bytes(s.encode('utf-8')))
May 25 11:34:33 localhost.localdomain /ontap_lsmplugin[9208]: ontap_lsmplugin: BrokenPipeError: [Errno 32] Broken pipe

Sim:
# lsmcli -u "sim://" volume-delete --vol VOL_ID_00001 --force
^C
# systemctl status libstoragemgmt0G                                                                                                                                                           
● libstoragemgmt.service - libstoragemgmt plug-in server daemon                                          
   Loaded: loaded (/usr/lib/systemd/system/libstoragemgmt.service; enabled; vendor preset: enabled)      
   Active: active (running) since Fri 2018-05-25 11:32:02 CEST; 59s ago                                  
 Main PID: 1898 (lsmd)                              
   CGroup: /system.slice/libstoragemgmt.service     
           └─1898 /usr/bin/lsmd -d                  

May 25 11:32:02 ***** systemd[1]: Starting libstoragemgmt plug-in server daemon...                                                                                                   
May 25 11:32:59 ***** sim_lsmplugin[1909]: sim_lsmplugin: Unhandled exception in plug-in!                                                                                            
May 25 11:32:59 ***** sim_lsmplugin[1909]: sim_lsmplugin: Traceback (most recent call last):                                                                                         
May 25 11:32:59 ***** sim_lsmplugin[1909]: sim_lsmplugin:   File "/usr/lib/python2.7/site-packages/lsm/_pluginrunner.py", line 114, in run                                           
May 25 11:32:59 ***** sim_lsmplugin[1909]: sim_lsmplugin:     self.tp.send_resp(result)                                                                                              
May 25 11:32:59 ***** sim_lsmplugin[1909]: sim_lsmplugin:   File "/usr/lib/python2.7/site-packages/lsm/_transport.py", line 171, in send_resp                                        
May 25 11:32:59 ***** sim_lsmplugin[1909]: sim_lsmplugin:     self._send_msg(json.dumps(r, cls=_DataEncoder))                                                                        
May 25 11:32:59 ***** sim_lsmplugin[1909]: sim_lsmplugin:   File "/usr/lib/python2.7/site-packages/lsm/_transport.py", line 75, in _send_msg                                         
May 25 11:32:59 ***** sim_lsmplugin[1909]: sim_lsmplugin:     self.s.sendall(bytes(s.encode('utf-8')))                                                                               
May 25 11:32:59 ***** sim_lsmplugin[1909]: sim_lsmplugin: error: [Errno 32] Broken pipe 


Version-Release number of selected component (if applicable):
libstoragemgmt-1.6.2-1

How reproducible:
90% manual, with proper timing 100%

Steps to Reproduce:
1. interrupt lsmcli command
2. check systemctl status libstoragemgmt

Actual results:
broken pipe error due to unhandled exception in plugin

Expected results:
no broken pipe

Additional info:

Comment 2 Gris Ge 2018-05-28 17:38:03 UTC
I will create patch to discard this harmless pipe error.

Comment 3 Gris Ge 2018-06-12 11:31:28 UTC
Patch sent to upstream:
https://github.com/libstorage/libstoragemgmt/pull/333

Comment 6 Jakub Krysl 2018-07-12 12:25:10 UTC
# systemctl status libstoragemgmt
● libstoragemgmt.service - libstoragemgmt plug-in server daemon
   Loaded: loaded (/usr/lib/systemd/system/libstoragemgmt.service; enabled; vendor preset: enabled)
   Active: active (running) since Thu 2018-07-12 14:20:35 CEST; 2min 53s ago
 Main PID: 22792 (lsmd)
   CGroup: /system.slice/libstoragemgmt.service
           └─22792 /usr/bin/lsmd -d

Jul 12 14:20:35 ***** systemd[1]: Started libstoragemgmt plug-in server daemon.
Jul 12 14:21:13 ***** ontap_lsmplugin[22795]: ontap_lsmplugin: Client went away, exiting plug-in
Jul 12 14:23:08 ***** sim_lsmplugin[22807]: sim_lsmplugin: Client went away, exiting plug-in

Comment 8 errata-xmlrpc 2018-10-30 10:10:39 UTC
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.

For information on the advisory, and where to find the updated
files, follow the link below.

If the solution does not work for you, open a new bug report.

https://access.redhat.com/errata/RHBA-2018:3112