0013528: Changing user account adds 8 MByte garbage to account field xprops, breaks some Admin functions and user cannot log in #6692

Closed
Gloirin opened this Issue Jun 9, 2018 · 14 comments

Comments

Projects
None yet
1 participant
@Gloirin

Gloirin commented Jun 9, 2018

Reported by lab-at-nohl on 6 Oct 2017 19:28

Version: 2017.08.6 Community Edition

As admin I changed a user account (new mail alias) which fails (although new alias is set). Edit window doesn't close.

Error displayed right after changing account settings:

Fatal error: Uncaught PDOException: SQLSTATE[HY000]: General error: 2006 MySQL server has gone away in /var/www/vendor/zendframework/zendframework1/library/Zend/Db/Statement/Pdo.php:228
Stack trace:
#0 /var/www/vendor/zendframework/zendframework1/library/Zend/Db/Statement/Pdo.php(228): PDOStatement->execute(Array)
#1 /var/www/vendor/zendframework/zendframework1/library/Zend/Db/Statement.php(303): Zend_Db_Statement_Pdo->_execute(Array)
#2 /var/www/vendor/zendframework/zendframework1/library/Zend/Db/Adapter/Abstract.php(480): Zend_Db_Statement->execute(Array)
#3 /var/www/vendor/zendframework/zendframework1/library/Zend/Db/Adapter/Pdo/Abstract.php(238): Zend_Db_Adapter_Abstract->query('SELECT DISTINCT...', Array)
#4 /var/www/Tinebase/Acl/Roles.php(197): Zend_Db_Adapter_Pdo_Abstract->query(Object(Zend_Db_Select))
#5 /var/www/Tinebase/Model/User.php(263): Tinebase_Acl_Roles->getApplications('316aa8a2-6c19-1...', false)
#6 /var/www/Tinebase/Server/Abstract.php(149): Tinebase_Model_User->g in /var/www/tine/vendor/zendframework/zendframework1/library/Zend/Db/Statement/Pdo.php on line 235

User cannot log in anymore and its xprops field is full of \\\.

DEBUG Log (short version):

b192f a5c2c admin - 2017-10-06T17:52:07+00:00 DEBUG (7): Tinebase_Controller_Record_ModlogTrait::_writeModLog::71 Writing modlog for Tinebase_Model_FullUser
b192f a5c2c admin - 2017-10-06T17:52:08+00:00 WARN (4): Tinebase_Core::errorHandler::563 Error while sending QUERY packet. PID=25573 in /var/www/vendor/zendframework/zendframework1/library/Zend/Db/Statement/Pdo.php::228 (2)
b192f a5c2c admin - 2017-10-06T17:52:08+00:00 WARN (4): Tinebase_Core::errorHandler::564 #0 [internal function]: Tinebase_Core::errorHandler(2, 'Error while sen...', '/var/www/v...', 228, Array)
b192f a5c2c admin - 2017-10-06T17:52:08+00:00 DEBUG (7): Tinebase_Timemachine_ModificationLog::setModification::486SQLSTATE[HY000]: General error: 2006 MySQL server has gone away, query was: INSERT INTO tine20_timemachine_modlog (change_type, application_id, record_id, record_type, record_backend, modification_time, modification_account, new_value, seq, client, id) VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?) Array
(
[change_type] => updated
[application_id] => 4d98d1a496971797938555321fe87a344d0742be
[record_id] => 31762cfe-6c19-1034-948d-17a0cca20f00
[record_type] => Tinebase_Model_FullUser
[record_backend] => Sql
[modification_time] => 2017-10-06 17:52:07
[modification_account] => 316aa8a2-6c19-1034-9484-17a0cca20f00
[new_value] => {"id":"31762cfe-6c19-1034-948d-17a0cca20f00","model":"Tinebase_Model_FullUser","diff":{"xprops":"{&quot;personalFSQuota&quot;:0}"},"oldData":{"xprops":"&quot;\&quot;\\\&quot;\\\\\\\&quot;<<<< repeat for 8 MByte >>>"\\\\\\\&quot;\\\&quot;\&quot;&quot;"}}
[seq] => 8
[client] => Tinebase_Server_Json - Mozilla/5.0 (Windows NT 6.3; WOW64; rv:52.0) Gecko/20100101 Firefox/52.0
[id] => 25ab26d21a48ca58cc79c25556a05b276175fbc6
)

b192f a5c2c admin - 2017-10-06T17:52:08+00:00 ERR (3): Admin_Controller_User::update::253 PDOException: SQLSTATE[HY000]: General error: 2006 MySQL server has gone away in /var/www/vendor/zendframework/zendframework1/library/Zend/Db/Statement/Pdo.php:228
Stack trace: [...]

<<< Here are two SELECT statements regarding modlog following which can't be executed since MySQL dropped connection (died) >>>

Steps to reproduce: Change any field on user panel as Admin. User cannot login anymore.

Account's field xprops in DB is full with "\\" - set xprops to NULL manually make login possible again.

@Gloirin

This comment has been minimized.

Show comment
Hide comment
@Gloirin

Gloirin Jun 11, 2018

Comment posted by lab-at-nohl on 9 Oct 2017 12:26

One additional note because I couldn't reproduce the error on my devel machine. The user in question (on my production server) has a unusual large storage quota and uses about 100 GByte. It may be related to that.

Gloirin commented Jun 11, 2018

Comment posted by lab-at-nohl on 9 Oct 2017 12:26

One additional note because I couldn't reproduce the error on my devel machine. The user in question (on my production server) has a unusual large storage quota and uses about 100 GByte. It may be related to that.

@Gloirin

This comment has been minimized.

Show comment
Hide comment
@Gloirin

Gloirin Jun 11, 2018

Comment posted by pmehrer on 12 Oct 2017 16:00

thank you for reporting this issue. Do you have maybe access to a database backup that contains the old xprops value before you did the record update?

Is the log still available? Could you look for the line at the beginning of the request?

44445 9c9e2 sclever - 2017-10-12T15:48:48+00:00 DEBUG (7): Tinebase_Server_Json::handle::159 is JSON request. rawdata: array (
0 =>
array (
'jsonrpc' => '2.0',
'method' => 'Admin.saveUser',
'params' =>
array (
'recordData' => .... please DO NOT SEND THE DATA THAT FOLLOWS HERE

only xprops and the end of this array please. ... Probably this will just be
'xprops' => array (
'personalFSQuota' => 0,
),
can you confirm that?

Gloirin commented Jun 11, 2018

Comment posted by pmehrer on 12 Oct 2017 16:00

thank you for reporting this issue. Do you have maybe access to a database backup that contains the old xprops value before you did the record update?

Is the log still available? Could you look for the line at the beginning of the request?

44445 9c9e2 sclever - 2017-10-12T15:48:48+00:00 DEBUG (7): Tinebase_Server_Json::handle::159 is JSON request. rawdata: array (
0 =>
array (
'jsonrpc' => '2.0',
'method' => 'Admin.saveUser',
'params' =>
array (
'recordData' => .... please DO NOT SEND THE DATA THAT FOLLOWS HERE

only xprops and the end of this array please. ... Probably this will just be
'xprops' => array (
'personalFSQuota' => 0,
),
can you confirm that?

@Gloirin

This comment has been minimized.

Show comment
Hide comment
@Gloirin

Gloirin Jun 11, 2018

Comment posted by lab-at-nohl on 13 Oct 2017 12:41

I can confirm that the log shows no other content in xprops array than what you wrote. After that only an empty array customfields follows. Nothing else.

What has been the content in table field xprops before I actually don't know. I propably have Backups (which I had to restore on an other machine unfortunately). According to my memory I would say it was "NULL" because all other users had (have) this... It will take some time...

Can I provide anything else in the meantime?

Gloirin commented Jun 11, 2018

Comment posted by lab-at-nohl on 13 Oct 2017 12:41

I can confirm that the log shows no other content in xprops array than what you wrote. After that only an empty array customfields follows. Nothing else.

What has been the content in table field xprops before I actually don't know. I propably have Backups (which I had to restore on an other machine unfortunately). According to my memory I would say it was "NULL" because all other users had (have) this... It will take some time...

Can I provide anything else in the meantime?

@Gloirin

This comment has been minimized.

Show comment
Hide comment
@Gloirin

Gloirin Jun 11, 2018

Comment posted by pmehrer on 16 Oct 2017 04:31

thank you for checking. I was not able to reproduce this. As the client send a proper value to the server, I am pretty sure that there was something corrupted in the database for that account. Guess we just have to wait for this to show up again. Did you try to alter that account record again? I would guess it works now just fine?

Gloirin commented Jun 11, 2018

Comment posted by pmehrer on 16 Oct 2017 04:31

thank you for checking. I was not able to reproduce this. As the client send a proper value to the server, I am pretty sure that there was something corrupted in the database for that account. Guess we just have to wait for this to show up again. Did you try to alter that account record again? I would guess it works now just fine?

@Gloirin

This comment has been minimized.

Show comment
Hide comment
@Gloirin

Gloirin Jun 11, 2018

Comment posted by lab-at-nohl on 21 Oct 2017 22:45

I can definitely reproduce this but it has random aspects. Because I had the feeling it may be related to the amount of data in Filemanager I took my own user and changed it (it has only some GBytes). I started by setting xprops in table tine20_accounts to NULL.

I added in Admin a alternate mail address, xprops became (the quotes are original): "&quot;\&quot;\\\&quot;\\\\\\\&quot;\\\\\\\\\\\\\\\&quot;\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\&quot;{\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\&quot;personalFSQuota\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\&quot;:0}\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\&quot;\\\\\\\\\\\\\\\&quot;\\\\\\\&quot;\\\&quot;\&quot;&quot;"

Later I changed nothing and just ok'ed the user unchanged, xprops became: {"personalFSQuota":0}

Next time I deleted the new mail alias, xprops became: "&quot;{\&quot;personalFSQuota\&quot;:0}&quot;"

Now I ok'ed the user with whom the problem originally occurred. Nothing changed but my own user changed its xprops to: "&quot;\&quot;\\\&quot;\\\\\\\&quot;\\\\\\\\\\\\\\\&quot;\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\&quot;\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\&quot;{\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\&quot;personalFSQuota\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\&quot;:0}\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\&quot;\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\&quot;\\\\\\\\\\\\\\\&quot;\\\\\\\&quot;\\\&quot;\&quot;&quot;"

Finally I set my user manually to: {"personalFSQuota":0} which to the other user resulted in: "&quot;\&quot;\\\&quot;\\\\\\\&quot;\\\\\\\\\\\\\\\&quot;{\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\&quot;personalFSQuota\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\&quot;:0}\\\\\\\\\\\\\\\&quot;\\\\\\\&quot;\\\&quot;\&quot;&quot;"

At the last step I can't say for sure that there're inter-dependencies because it is the production system (maybe the other user's phone connected).

The other users haven't been changed recently they are still set to NULL and not affected.

=======================================

CONCLUSION:

xprops is set to (wrongly escaped?) garbage randomly (don't know why). It seems to be growing on every change of the user (in Admin or e.g. login). It may even affect other users (which do not have xprops set to NULL). The log is not showing an error.

Gloirin commented Jun 11, 2018

Comment posted by lab-at-nohl on 21 Oct 2017 22:45

I can definitely reproduce this but it has random aspects. Because I had the feeling it may be related to the amount of data in Filemanager I took my own user and changed it (it has only some GBytes). I started by setting xprops in table tine20_accounts to NULL.

I added in Admin a alternate mail address, xprops became (the quotes are original): "&quot;\&quot;\\\&quot;\\\\\\\&quot;\\\\\\\\\\\\\\\&quot;\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\&quot;{\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\&quot;personalFSQuota\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\&quot;:0}\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\&quot;\\\\\\\\\\\\\\\&quot;\\\\\\\&quot;\\\&quot;\&quot;&quot;"

Later I changed nothing and just ok'ed the user unchanged, xprops became: {"personalFSQuota":0}

Next time I deleted the new mail alias, xprops became: "&quot;{\&quot;personalFSQuota\&quot;:0}&quot;"

Now I ok'ed the user with whom the problem originally occurred. Nothing changed but my own user changed its xprops to: "&quot;\&quot;\\\&quot;\\\\\\\&quot;\\\\\\\\\\\\\\\&quot;\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\&quot;\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\&quot;{\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\&quot;personalFSQuota\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\&quot;:0}\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\&quot;\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\&quot;\\\\\\\\\\\\\\\&quot;\\\\\\\&quot;\\\&quot;\&quot;&quot;"

Finally I set my user manually to: {"personalFSQuota":0} which to the other user resulted in: "&quot;\&quot;\\\&quot;\\\\\\\&quot;\\\\\\\\\\\\\\\&quot;{\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\&quot;personalFSQuota\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\&quot;:0}\\\\\\\\\\\\\\\&quot;\\\\\\\&quot;\\\&quot;\&quot;&quot;"

At the last step I can't say for sure that there're inter-dependencies because it is the production system (maybe the other user's phone connected).

The other users haven't been changed recently they are still set to NULL and not affected.

=======================================

CONCLUSION:

xprops is set to (wrongly escaped?) garbage randomly (don't know why). It seems to be growing on every change of the user (in Admin or e.g. login). It may even affect other users (which do not have xprops set to NULL). The log is not showing an error.

@Gloirin

This comment has been minimized.

Show comment
Hide comment
@Gloirin

Gloirin Jun 11, 2018

Comment posted by pmehrer on 2 Nov 2017 12:00

tried to reproduce it again on a clean 2017.08.6 CE. It is not reproducable there. So it would be great if you could provide more information:

you said: "Later I changed nothing and just ok'ed the user unchanged, xprops became: {"personalFSQuota":0}" ... that tells me that the edit dialog sends sane data to the server. and that the issue occurs somewhere else. Can you verify that? Try to reproduce it and look in the logs for data send to the server? As written above:

44445 9c9e2 sclever - 2017-10-12T15:48:48+00:00 DEBUG (7): Tinebase_Server_Json::handle::159 is JSON request. rawdata: array (
0 =>
array (
'jsonrpc' => '2.0',
'method' => 'Admin.saveUser',
'params' =>
array (
'recordData' => .... please DO NOT SEND THE DATA THAT FOLLOWS HERE

only xprops and the end of this array please. ... Probably this will just be
'xprops' => array (
'personalFSQuota' => 0,
),
can you confirm that?

I even dont know yet if this is a FE problem in the JS doing a bad encoding and sending bad data to the server or if this happens somewhere on the server.

Gloirin commented Jun 11, 2018

Comment posted by pmehrer on 2 Nov 2017 12:00

tried to reproduce it again on a clean 2017.08.6 CE. It is not reproducable there. So it would be great if you could provide more information:

you said: "Later I changed nothing and just ok'ed the user unchanged, xprops became: {"personalFSQuota":0}" ... that tells me that the edit dialog sends sane data to the server. and that the issue occurs somewhere else. Can you verify that? Try to reproduce it and look in the logs for data send to the server? As written above:

44445 9c9e2 sclever - 2017-10-12T15:48:48+00:00 DEBUG (7): Tinebase_Server_Json::handle::159 is JSON request. rawdata: array (
0 =>
array (
'jsonrpc' => '2.0',
'method' => 'Admin.saveUser',
'params' =>
array (
'recordData' => .... please DO NOT SEND THE DATA THAT FOLLOWS HERE

only xprops and the end of this array please. ... Probably this will just be
'xprops' => array (
'personalFSQuota' => 0,
),
can you confirm that?

I even dont know yet if this is a FE problem in the JS doing a bad encoding and sending bad data to the server or if this happens somewhere on the server.

@Gloirin

This comment has been minimized.

Show comment
Hide comment
@Gloirin

Gloirin Jun 11, 2018

Comment posted by lab-at-nohl on 12 Nov 2017 02:18

Thank you for your help. The error still persists. I can CONFIRM your assumption. It does not seem to be related to client side.

I wrote a Query-Log by Mysql, please see the changing statement yourself:

172 Query UPDATE tine20_accounts SET login_name = '%USER%', expires_at = NULL, primary_group_id = '%GROUP_ID%', home_dir = '/bin/false', login_shell = NULL, openid = NULL, visibility = 'displayed', contact_id = '%CONTACT_ID%', display_name = 'User, Name', full_name = 'Name User', first_name = 'Name', last_name = 'User', email = 'name@domain.tld', last_modified_by = '%SETUPUSER_ID%', last_modified_time = '2017-11-12 01:12:58', seq = '29', xprops
= '&quot;{\&quot;personalFSQuota\&quot;:0}&quot;', status = 'enabled' WHERE (id = '%ACCOUNT_ID%')

The user account which has xprops is changed. After the change (!) last_modified_by = '%SETUPUSER_ID%'. Before it was the ID of my Administrator. So the culprit is setupuser!

Additionally I noticed that changes mostly occur in seconds 58 or 59 but always after one minute. The change must be initiate by any kind of automated process. Since I tried Tinebase.triggerAsyncEvents already I guess the source is ActionQueue (which is hard to log)...

I hope this helps.

Gloirin commented Jun 11, 2018

Comment posted by lab-at-nohl on 12 Nov 2017 02:18

Thank you for your help. The error still persists. I can CONFIRM your assumption. It does not seem to be related to client side.

I wrote a Query-Log by Mysql, please see the changing statement yourself:

172 Query UPDATE tine20_accounts SET login_name = '%USER%', expires_at = NULL, primary_group_id = '%GROUP_ID%', home_dir = '/bin/false', login_shell = NULL, openid = NULL, visibility = 'displayed', contact_id = '%CONTACT_ID%', display_name = 'User, Name', full_name = 'Name User', first_name = 'Name', last_name = 'User', email = 'name@domain.tld', last_modified_by = '%SETUPUSER_ID%', last_modified_time = '2017-11-12 01:12:58', seq = '29', xprops
= '&quot;{\&quot;personalFSQuota\&quot;:0}&quot;', status = 'enabled' WHERE (id = '%ACCOUNT_ID%')

The user account which has xprops is changed. After the change (!) last_modified_by = '%SETUPUSER_ID%'. Before it was the ID of my Administrator. So the culprit is setupuser!

Additionally I noticed that changes mostly occur in seconds 58 or 59 but always after one minute. The change must be initiate by any kind of automated process. Since I tried Tinebase.triggerAsyncEvents already I guess the source is ActionQueue (which is hard to log)...

I hope this helps.

@Gloirin

This comment has been minimized.

Show comment
Hide comment
@Gloirin

Gloirin Jun 11, 2018

Comment posted by lab-at-nohl on 13 Nov 2017 01:25

One small update on this issue: The "garbage escape strings" in xprops are produced by json_encode when trying to encode an already json formatted string.

Hotfix for Tinebase/User/Sql.php (line 1073):

  •    } elseif (isset($accountData[&#039;xprops&#039;])) {
    
  •    } elseif (isset($accountData[&#039;xprops&#039;]) &amp;&amp; !is_string($accountData[&#039;xprops&#039;])) {
    

BUT: This patch is not sufficient and not a real fix. For any reason the Ldap-Sync for accounts is broken heavily. Some methods (DAV and ActiveSync at least, probably also some UI-calls) always trigger an updateUserInSqlBackend() on each request no matter if Ldap has really changed (which has definitely not).

Despite a lost of resources (caching?) this invokes a permanent change-process of the user in SQL. Whenever I change a user being "admin", after the next call of the user its last_modified_by will be changed to setupuser. This happened for all my active users. I doubt this behavior is related to xprops but I guess it came from new modeling setupuser.

Gloirin commented Jun 11, 2018

Comment posted by lab-at-nohl on 13 Nov 2017 01:25

One small update on this issue: The "garbage escape strings" in xprops are produced by json_encode when trying to encode an already json formatted string.

Hotfix for Tinebase/User/Sql.php (line 1073):

  •    } elseif (isset($accountData[&#039;xprops&#039;])) {
    
  •    } elseif (isset($accountData[&#039;xprops&#039;]) &amp;&amp; !is_string($accountData[&#039;xprops&#039;])) {
    

BUT: This patch is not sufficient and not a real fix. For any reason the Ldap-Sync for accounts is broken heavily. Some methods (DAV and ActiveSync at least, probably also some UI-calls) always trigger an updateUserInSqlBackend() on each request no matter if Ldap has really changed (which has definitely not).

Despite a lost of resources (caching?) this invokes a permanent change-process of the user in SQL. Whenever I change a user being "admin", after the next call of the user its last_modified_by will be changed to setupuser. This happened for all my active users. I doubt this behavior is related to xprops but I guess it came from new modeling setupuser.

@Gloirin

This comment has been minimized.

Show comment
Hide comment
@Gloirin

Gloirin Jun 11, 2018

Comment posted by pmehrer on 13 Nov 2017 08:32

thank you for the detailed analysis. We will fix the double encoding and look into the (presumably unnecessary) account updates in the sql backend. I'll let you know when there is an update on this topic.

Gloirin commented Jun 11, 2018

Comment posted by pmehrer on 13 Nov 2017 08:32

thank you for the detailed analysis. We will fix the double encoding and look into the (presumably unnecessary) account updates in the sql backend. I'll let you know when there is an update on this topic.

@Gloirin

This comment has been minimized.

Show comment
Hide comment
@Gloirin

Gloirin Jun 11, 2018

Comment posted by pmehrer on 13 Nov 2017 08:58

Hotfix for Tinebase/User/Sql.php (line 1073):

  • } elseif (isset($accountData['xprops'])) {
  • } elseif (isset($accountData['xprops']) && is_array($accountData['xprops'])) {

(your fix will work too, but because of Tinebase_Record_Abstract::xprops I would rather check for is_array, it is supposed to be an array) Will continue to look into avoiding unnecessary updates

Gloirin commented Jun 11, 2018

Comment posted by pmehrer on 13 Nov 2017 08:58

Hotfix for Tinebase/User/Sql.php (line 1073):

  • } elseif (isset($accountData['xprops'])) {
  • } elseif (isset($accountData['xprops']) && is_array($accountData['xprops'])) {

(your fix will work too, but because of Tinebase_Record_Abstract::xprops I would rather check for is_array, it is supposed to be an array) Will continue to look into avoiding unnecessary updates

@Gloirin

This comment has been minimized.

Show comment
Hide comment
@Gloirin

Gloirin Jun 11, 2018

Comment posted by pmehrer on 13 Nov 2017 10:34

regarding the often occuring updates:
in our own ldap installation I can not see this:
select last_modified_time from tine20_accounts order by last_modified_time DESC limit 20 \G
nothing unusual there.

Also \Tinebase_User::_syncDataAndUpdateUser makes some sort of diff comparison and only updates the sql backend if required. If you feel the updates are problematic, please look at the log and provide more information which code path the updates take.

thank you for your report again, it was very helpful (not to say essential) to fix the crucial double escaping bug!

Gloirin commented Jun 11, 2018

Comment posted by pmehrer on 13 Nov 2017 10:34

regarding the often occuring updates:
in our own ldap installation I can not see this:
select last_modified_time from tine20_accounts order by last_modified_time DESC limit 20 \G
nothing unusual there.

Also \Tinebase_User::_syncDataAndUpdateUser makes some sort of diff comparison and only updates the sql backend if required. If you feel the updates are problematic, please look at the log and provide more information which code path the updates take.

thank you for your report again, it was very helpful (not to say essential) to fix the crucial double escaping bug!

@Gloirin

This comment has been minimized.

Show comment
Hide comment
@Gloirin

Gloirin Jun 11, 2018

Comment posted by lab-at-nohl on 13 Nov 2017 11:48

  1. Hotfix

I thought about checking for an array, too. But according to documentation, per default json_decode will return an object in most cases. Thus you also need to check for that, I guess. Therefore I decided to test vice versa, hence for a string...

Will you bring the fix to git?

  1. I had a feeling that your Ldap behaves differently. Weird. I will follow up on this.

Regarding your Ldap: Are you sure that setupuser (which is default in pre-authentication phase instead of empty id since some releases) does not overwrite last_modified_by of an account? Although all users in my installation were created by admin by now all are last_modified_by setup user!

I will investigate \Tinebase_User::_syncDataAndUpdateUser further. Yesterday I thought it may be related to a missing property in Ldap (mine has no accountExpire). But I will come back to this issue.

Gloirin commented Jun 11, 2018

Comment posted by lab-at-nohl on 13 Nov 2017 11:48

  1. Hotfix

I thought about checking for an array, too. But according to documentation, per default json_decode will return an object in most cases. Thus you also need to check for that, I guess. Therefore I decided to test vice versa, hence for a string...

Will you bring the fix to git?

  1. I had a feeling that your Ldap behaves differently. Weird. I will follow up on this.

Regarding your Ldap: Are you sure that setupuser (which is default in pre-authentication phase instead of empty id since some releases) does not overwrite last_modified_by of an account? Although all users in my installation were created by admin by now all are last_modified_by setup user!

I will investigate \Tinebase_User::_syncDataAndUpdateUser further. Yesterday I thought it may be related to a missing property in Ldap (mine has no accountExpire). But I will come back to this issue.

@Gloirin

This comment has been minimized.

Show comment
Hide comment
@Gloirin

Gloirin Jun 11, 2018

Comment posted by pmehrer on 13 Nov 2017 14:59

"\Tinebase_User::_syncDataAndUpdateUser further. Yesterday I thought it may be related to a missing property in Ldap (mine has no accountExpire)." -> that sounds like a probable cause, if the accountExpire will be set to a value other than null again later either in the update code path or through an other process, the ldap sync will unset it again and again.

Gloirin commented Jun 11, 2018

Comment posted by pmehrer on 13 Nov 2017 14:59

"\Tinebase_User::_syncDataAndUpdateUser further. Yesterday I thought it may be related to a missing property in Ldap (mine has no accountExpire)." -> that sounds like a probable cause, if the accountExpire will be set to a value other than null again later either in the update code path or through an other process, the ldap sync will unset it again and again.

@Gloirin

This comment has been minimized.

Show comment
Hide comment
@Gloirin

Gloirin Jun 11, 2018

Comment posted by pmehrer on 14 Nov 2017 02:55

  1. Hotfix:
    is merged already https://gerrit.tine20.com/customers/#/c/6359/
    json_decode in the tine20 context is always being called with $assoc = true parameter: json_decode($json, true) => it will always return an array.

Gloirin commented Jun 11, 2018

Comment posted by pmehrer on 14 Nov 2017 02:55

  1. Hotfix:
    is merged already https://gerrit.tine20.com/customers/#/c/6359/
    json_decode in the tine20 context is always being called with $assoc = true parameter: json_decode($json, true) => it will always return an array.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment