Bug 43044 - italc 3.0 segfault in reportSlaveStateFlags()
italc 3.0 segfault in reportSlaveStateFlags()
Status: CLOSED FIXED
Product: UCS@school
Classification: Unclassified
Component: iTALC
UCS@school 4.1 R2
Other Linux
: P5 normal (vote)
: UCS@school 4.1 R2 vXXX
Assigned To: Florian Best
Sönke Schwardt-Krummrich
: interim-3
Depends on:
Blocks: 41758
  Show dependency treegraph
 
Reported: 2016-11-24 09:57 CET by Jens Thorp-Hansen
Modified: 2016-12-12 13:10 CET (History)
3 users (show)

See Also:
What kind of report is it?: Bug Report
What type of bug is this?: 5: Major Usability: Impairs usability in key scenarios
Who will be affected by this bug?: 3: Will affect average number of installed domains
How will those affected feel about the bug?: 4: A User would return the product
User Pain: 0.343
Enterprise Customer affected?:
School Customer affected?: Yes
ISV affected?:
Waiting Support:
Flags outvoted (downgraded) after PO Review:
Ticket number: 2016112421000151
Bug group (optional): External feedback, Usability
Max CVSS v3 score:


Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description Jens Thorp-Hansen univentionstaff 2016-11-24 09:57:44 CET
seems not to be fixed in 4.1 R2 v8 - please have a look at the customer ticket.

+++ This bug was initially created as a clone of Bug #41752 +++

While debugging the windows iTALC client, several small glitches in our italc2.py have been found.
Comment 1 Florian Best univentionstaff 2016-11-24 10:17:04 CET
The ticket doesn't contain enough useful information. We need the USI.

It is the UMC module process which crashes:

[Wed Nov 23 20:22:21 2016] univention-mana[25921]: segfault at 0 ip           (null) sp 00007f077bffea88 error 14
[Wed Nov 23 20:22:21 2016] univention-mana[25920]: segfault at 0 ip           (null) sp 00007f0780ff8a88 error 14 in python2.7[400000+258000]
[Wed Nov 23 20:22:21 2016]  in python2.7[400000+258000]
[Wed Nov 23 20:22:24 2016] univention-mana[25953]: segfault at 0 ip           (null) sp 00007fef8effca88 error 14 in python2.7[400000+258000]
[Wed Nov 23 20:22:28 2016] univention-mana[25980]: segfault at 0 ip           (null) sp 00007f8609d71a88 error 14 in python2.7[400000+258000]
[Wed Nov 23 20:22:33 2016] univention-mana[26018]: segfault at 0 ip           (null) sp 00007f318e2a0a88 error 14
[Wed Nov 23 20:22:33 2016] univention-mana[26017]: segfault at 0 ip           (null) sp 00007f318eaa1a88 error 14
[Wed Nov 23 20:22:33 2016] univention-mana[26016]: segfault at 0 ip           (null) sp 00007f318f2a2a88 error 14
Comment 2 Sönke Schwardt-Krummrich univentionstaff 2016-11-24 10:46:02 CET
These segfaults are not related to bug 41752.

Can you provide a core dump?
Comment 3 Florian Best univentionstaff 2016-11-24 10:50:30 CET
It would be nice if the customer could activate core dumps and send one of them to us: http://sdb.univention.de/1316

Also installing python-faulthandler and applying the patch from Bug #41681 against /usr/share/pyshared/univention/management/console/log.py would help us to receive a traceback.
Comment 4 Florian Best univentionstaff 2016-11-24 10:51:22 CET
(In reply to Sönke Schwardt-Krummrich from comment #2)
> These segfaults are not related to bug 41752.
Well, they are related to Bug #40316 which was closed as duplicate of that bug.
Comment 5 Jens Thorp-Hansen univentionstaff 2016-11-24 11:41:19 CET
(In reply to Florian Best from comment #1)
> The ticket doesn't contain enough useful information. We need the USI.

The USI is at the ticket. Do you still need the core dumps?
Comment 6 Jens Thorp-Hansen univentionstaff 2016-11-25 11:15:49 CET
Coredumps and Traceback Logs are attached at the ticket. Please tell me if you need more Information.
Comment 7 Florian Best univentionstaff 2016-11-25 11:32:52 CET
upload_CfShRo.gz:

#0  0x00007fe3e55d3f6b in raise () from /lib/x86_64-linux-gnu/libpthread.so.0
#1  <signal handler called>
#2  lockInline (this=0x50) at /usr/include/qt4/QtCore/qmutex.h:187
#3  QMutexLocker (m=0x50, this=<synthetic pointer>) at /usr/include/qt4/QtCore/qmutex.h:109
#4  ItalcVncConnection::enqueueEvent (this=0x0, e=0x7fe37c08d5b0) at /var/build/temp/tmp.sGv0k6SHwb/pbuilder/italc-2.0.25/lib/src/ItalcVncConnection.cpp:711
#5  0x00007fe3bf459f24 in ItalcCoreConnection::enqueueMessage (this=0x7fe37c17fbf0, msg=...) at /var/build/temp/tmp.sGv0k6SHwb/pbuilder/italc-2.0.25/lib/src/ItalcCoreConnection.cpp:354
#6  0x00007fe3bf459fec in ItalcCoreConnection::reportSlaveStateFlags (this=<optimized out>) at /var/build/temp/tmp.sGv0k6SHwb/pbuilder/italc-2.0.25/lib/src/ItalcCoreConnection.cpp:346
#7  0x00007fe3bf743021 in ?? () from /usr/lib/pymodules/python2.7/italc.so
#8  0x00000000004af11e in call_function (oparg=<optimized out>, pp_stack=0x7ffd51b1d6e0) at ../Python/ceval.c:4021
#9  PyEval_EvalFrameEx (f=f@entry=
    Frame 0x37fc7e0, for file /usr/lib/pymodules/python2.7/univention/management/console/modules/computerroom/italc2.py, line 319, in _userInfo (self=<ITALC_Computer(_allowedClients=[], _username=<LockableAttribute(_lock=<thread.lock at remote 0x7fe3a07399f0>, _has_changed=True, _current='anony.mized', _old=None) at remote 0x1c73150>, _homedir=<LockableAttribute(_lock=<thread.lock at remote 0x7fe3a0739bf0>, _has_changed=True, _current='C:\\Users\\anony.mized', _old=None) at remote 0x1c73310>, _dn='cn=foobar,cn=computers,ou=school,dc=somedomain,dc=ch', _core=<ItalcCoreConnection at remote 0x7fe3a0751680>, _timer=None, _computer=<object(_base__no_default=['groups'], co=None, ip_alredy_requested=0, ip=[], old_options=['kerberos', 'samba', 'posix'], oldattr={'macAddress': ['c0:3f:d5:66:b0:8d'], 'cn': ['foobar'], 'krb5PrincipalName': ['host/foobar.sn-lan.somedomain.ch@SOME.DOMAIN'], 'aRecord': ['10.9.1.101'], 'objectClass': ['top', 'person', 'univentionHost', 'univentionWindows', 'krb5Principal'...(truncated), throwflag=throwflag@entry=0)
    at ../Python/ceval.c:2666
#10 0x00000000004b6558 in PyEval_EvalCodeEx (co=<optimized out>, globals=<optimized out>, locals=locals@entry=0x0, args=<optimized out>, argcount=<optimized out>, kws=kws@entry=0x0, kwcount=kwcount@entry=0, defs=defs@entry=0x0, defcount=defcount@entry=0, closure=0x0)
    at ../Python/ceval.c:3253
#11 0x00000000004b715c in function_call.15258 (func=<function at remote 0x372fcf8>, arg=<optimized out>, kw=<optimized out>) at ../Objects/funcobject.c:526
#12 0x000000000046fa04 in PyObject_Call (kw=0x0, arg=
    (<ITALC_Computer(_allowedClients=[], _username=<LockableAttribute(_lock=<thread.lock at remote 0x7fe3a07399f0>, _has_changed=True, _current='anony.mized', _old=None) at remote 0x1c73150>, _homedir=<LockableAttribute(_lock=<thread.lock at remote 0x7fe3a0739bf0>, _has_changed=True, _current='C:\\Users\\anony.mized', _old=None) at remote 0x1c73310>, _dn='cn=foobar,cn=computers,ou=school,dc=somedomain,dc=ch', _core=<ItalcCoreConnection at remote 0x7fe3a0751680>, _timer=None, _computer=<object(_base__no_default=['groups'], co=None, ip_alredy_requested=0, ip=[], old_options=['kerberos', 'samba', 'posix'], oldattr={'macAddress': ['11:22:33:44:55:66'], 'cn': ['foobar'], 'krb5PrincipalName': ['host/foobar.sn-lan.somedomain.ch@SOME.DOMAIN'], 'aRecord': ['10.9.1.101'], 'objectClass': ['top', 'person', 'univentionHost', 'univentionWindows', 'krb5Principal', 'krb5KDCEntry', 'posixAccount', 'shadowAccount', 'sambaSamAccount', 'univentionObject'], 'uidNumber': ['9544'], 'sambaAcctFlags': ['[W         ...(truncated), func=<function at remote 0x372fcf8>)
    at ../Objects/abstract.c:2529
#13 instancemethod_call.8723 (func=<function at remote 0x372fcf8>, arg=
    (<ITALC_Computer(_allowedClients=[], _username=<LockableAttribute(_lock=<thread.lock at remote 0x7fe3a07399f0>, _has_changed=True, _current='anony.mized', _old=None) at remote 0x1c73150>, _homedir=<LockableAttribute(_lock=<thread.lock at remote 0x7fe3a0739bf0>, _has_changed=True, _current='C:\\Users\\anony.mized', _old=None) at remote 0x1c73310>, _dn='cn=foobar,cn=computers,ou=school,dc=somedomain,dc=ch', _core=<ItalcCoreConnection at remote 0x7fe3a0751680>, _timer=None, _computer=<object(_base__no_default=['groups'], co=None, ip_alredy_requested=0, ip=[], old_options=['kerberos', 'samba', 'posix'], oldattr={'macAddress': ['11:22:33:44:55:66'], 'cn': ['foobar'], 'krb5PrincipalName': ['host/foobar.sn-lan.somedomain.ch@SOME.DOMAIN'], 'aRecord': ['10.9.1.101'], 'objectClass': ['top', 'person', 'univentionHost', 'univentionWindows', 'krb5Principal', 'krb5KDCEntry', 'posixAccount', 'shadowAccount', 'sambaSamAccount', 'univentionObject'], 'uidNumber': ['9544'], 'sambaAcctFlags': ['[W         ...(truncated), kw=0x0) at ../Objects/classobject.c:2602
#14 0x0000000000464ebe in PyObject_Call (kw=<optimized out>, arg=(<QString at remote 0x36a6fa0>, <QString at remote 0x36a6d70>), func=<instancemethod at remote 0x2d95f00>) at ../Objects/abstract.c:2529
#15 PyEval_CallObjectWithKeywords (func=<instancemethod at remote 0x2d95f00>, arg=(<QString at remote 0x36a6fa0>, <QString at remote 0x36a6d70>), kw=<optimized out>) at ../Python/ceval.c:3890
#16 0x00007fe3e19738e0 in sip_api_invoke_slot () from /usr/lib/python2.7/dist-packages/sip.so
#17 0x00007fe3e293def6 in ?? () from /usr/lib/python2.7/dist-packages/PyQt4/QtCore.so
#18 0x00007fe3e2941ad7 in ?? () from /usr/lib/python2.7/dist-packages/PyQt4/QtCore.so
#19 0x00007fe3e2941cf6 in ?? () from /usr/lib/python2.7/dist-packages/PyQt4/QtCore.so
#20 0x00007fe3e244ca2e in QObject::event(QEvent*) () from /usr/lib/x86_64-linux-gnu/libQtCore.so.4
#21 0x00007fe3e29275b3 in ?? () from /usr/lib/python2.7/dist-packages/PyQt4/QtCore.so
#22 0x00007fe3e2902cc6 in ?? () from /usr/lib/python2.7/dist-packages/PyQt4/QtCore.so
#23 0x00007fe3e2437b5e in QCoreApplication::notifyInternal(QObject*, QEvent*) () from /usr/lib/x86_64-linux-gnu/libQtCore.so.4
#24 0x00007fe3e243b9e1 in QCoreApplicationPrivate::sendPostedEvents(QObject*, int, QThreadData*) () from /usr/lib/x86_64-linux-gnu/libQtCore.so.4
#25 0x00007fe3e24660e3 in ?? () from /usr/lib/x86_64-linux-gnu/libQtCore.so.4
#26 0x00007fe3e1e05355 in g_main_context_dispatch () from /lib/x86_64-linux-gnu/libglib-2.0.so.0
#27 0x00007fe3e1e05688 in ?? () from /lib/x86_64-linux-gnu/libglib-2.0.so.0
#28 0x00007fe3e1e05744 in g_main_context_iteration () from /lib/x86_64-linux-gnu/libglib-2.0.so.0
#29 0x00007fe3e2466276 in QEventDispatcherGlib::processEvents(QFlags<QEventLoop::ProcessEventsFlag>) () from /usr/lib/x86_64-linux-gnu/libQtCore.so.4
#30 0x00007fe3e243be8f in QCoreApplication::processEvents(QFlags<QEventLoop::ProcessEventsFlag>) () from /usr/lib/x86_64-linux-gnu/libQtCore.so.4
#31 0x00007fe3e28f05ed in ?? () from /usr/lib/python2.7/dist-packages/PyQt4/QtCore.so
#32 0x00000000004af11e in call_function (oparg=<optimized out>, pp_stack=0x7ffd51b1e320) at ../Python/ceval.c:4021
Comment 8 Jens Thorp-Hansen univentionstaff 2016-11-28 08:27:58 CET
Severity: customer reports major impact in the daily workroutine. Severity is high. Please tell me if you need more Information.
Comment 10 Sönke Schwardt-Krummrich univentionstaff 2016-11-28 10:03:19 CET
Just noticed the following lines:

#2  lockInline (this=0x50) at /usr/include/qt4/QtCore/qmutex.h:187
#3  QMutexLocker (m=0x50, this=<synthetic pointer>) at /usr/include/qt4/QtCore/qmutex.h:109
#4  ItalcVncConnection::enqueueEvent (this=0x0, e=0x7fe37c08d5b0) at /var/build/temp/tmp.sGv0k6SHwb/pbuilder/italc-2.0.25/lib/src/ItalcVncConnection.cpp:711
#5  0x00007fe3bf459f24 in ItalcCoreConnection::enqueueMessage (this=0x7fe37c17fbf0, msg=...) at /var/build/temp/tmp.sGv0k6SHwb/pbuilder/italc-2.0.25/lib/src/ItalcCoreConnection.cpp:354
#6  0x00007fe3bf459fec in ItalcCoreConnection::reportSlaveStateFlags (this=<optimized out>) at /var/build/temp/tmp.sGv0k6SHwb/pbuilder/italc-2.0.25/lib/src/ItalcCoreConnection.cpp:346

In #2 and #3 is this=0x50 ==> will produce segfault on usage.
In #4 this is 0x0 ==> NULL pointer ==> segfault
In #5 "m_vncConn->enqueueEvent( new ItalcMessageEvent( m ) );" is called which leads to the result that m_vncConn is NULL at that moment.

Suggested patch:

--- a/ucs-school-4.1r2/italc/italc/lib/src/ItalcCoreConnection.cpp
+++ b/ucs-school-4.1r2/italc/italc/lib/src/ItalcCoreConnection.cpp
@@ -351,7 +351,10 @@ void ItalcCoreConnection::reportSlaveStateFlags()
 void ItalcCoreConnection::enqueueMessage( const ItalcCore::Msg &msg )
 {
 	ItalcCore::Msg m( msg );
-	m_vncConn->enqueueEvent( new ItalcMessageEvent( m ) );
+	if (m_vncConn)
+	{
+		m_vncConn->enqueueEvent( new ItalcMessageEvent( m ) );
+	}
 }
Comment 11 Florian Best univentionstaff 2016-11-28 17:31:55 CET
To provoke this segfault one can use:

# python -c 'import italc; c = italc.ItalcCoreConnection(None); c.reportSlaveStateFlags()'
QObject::connect: Cannot connect (null)::newClient( rfbClient * ) to ItalcCoreConnection::initNewClient( rfbClient * )
Speicherzugriffsfehler

The problem is a threading problem in italc2.py, which does basically the following:

def open():
    self._vnc = italc.ItalcVncConnection()
    self._vnc.stateChanged.connect(self._stateChanged)
def _stateChanged(self, state):
    self._core = italc.ItalcCoreConnection(self._vnc)
    self._core.receivedSlaveStateFlags.connect(self._slaveStateFlags)
def close():
    # here is the actual wrong handling. one have to disconnect all signals before doing such things
    self._vnc = None

def update():
    if self._usernameLastUpdate + ITALC_CORE_TIMEOUT < time.time():
        self.close()
        # … race condition is here. between the close() and the save() the _stateChanged callback is called in another thread, which causes the segfault from the above example because self._vnc is None.
        self.open()
Comment 12 Florian Best univentionstaff 2016-11-28 17:35:06 CET
Add some missing lines:
(In reply to Florian Best from comment #11)
> def open():
>     self._vnc = italc.ItalcVncConnection()
>     self._vnc.stateChanged.connect(self._stateChanged)
> def _stateChanged(self, state):
>     self._core = italc.ItalcCoreConnection(self._vnc)
      self._core.receivedUserInfo.connect(self._userInfo)
>     self._core.receivedSlaveStateFlags.connect(self._slaveStateFlags)
> def close():
>     # here is the actual wrong handling. one have to disconnect all signals
> before doing such things
>     self._vnc = None
> 
> def update():
>     if self._usernameLastUpdate + ITALC_CORE_TIMEOUT < time.time():
>         self.close()
>         # … race condition is here. between the close() and the save() the
> _stateChanged callback is called in another thread, which causes the
> segfault from the above example because self._vnc is None.
>         self.open()

    def _userInfo(self, username, homedir):
        self._core.reportSlaveStateFlags()  # the actual segfault is here
Comment 13 Florian Best univentionstaff 2016-11-28 18:10:25 CET
ucs-school-umc-computerroom.yaml:
r74780 | YAML Bug #43044 Bug #43051

italc.yaml:
r74780 | YAML Bug #43044 Bug #43051

italc (2:2.0.25-13):
r74762 | Bug #43044 / Bug #43051: fix segfaults

ucs-school-umc-computerroom (8.0.12-1):
r74777 | Bug #43044: fix threading issue which caused segfault

ucs-school-italc.yaml:
r74780 | YAML Bug #43044 Bug #43051
Comment 14 Jens Thorp-Hansen univentionstaff 2016-12-01 15:16:33 CET
Happened Again. New Logs and Coredumps are attached at the ticket.
Comment 15 Florian Best univentionstaff 2016-12-01 16:10:26 CET
(In reply to Jens Thorp-Hansen from comment #14)
> Happened Again. New Logs and Coredumps are attached at the ticket.Bug #43092
Comment 16 Sönke Schwardt-Krummrich univentionstaff 2016-12-08 17:44:01 CET
OK: problem was reproducible
OK: code change
OK: functional check (problem is solved)
OK: packages built (ucs-school-umc-computerroom, italc, python-italc)
OK: advisories (applied small changes)
Comment 17 Sönke Schwardt-Krummrich univentionstaff 2016-12-12 13:10:22 CET
UCS@school 4.1 R2 v9 has been released.

http://docs.software-univention.de/changelog-ucsschool-4.1R2v9-de.html