View Issue Details

IDProjectCategoryView StatusLast Update
0013528Tine 2.0Tinebasepublic2017-10-16 06:31
Reporterlab-at-nohlAssigned Topmehrer 
PrioritynormalSeveritycrashReproducibilityalways
Status newResolutionopen 
Product Version2017.08.6 Community Edition 
Target VersionFixed in Version 
Summary0013528: Changing user account adds 8 MByte garbage to account field xprops, breaks some Admin functions and user cannot log in
DescriptionAs 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)
0000002 /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)
0000004 /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":"{\"personalFSQuota\":0}"},"oldData":{"xprops":"\"\\\"\\\\\\\"\\\\\\\\\\\\\\\"<<<< repeat for 8 MByte >>>"\\\\\\\\\\\\\\\"\\\\\\\"\\\"\""}}
[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 ReproduceChange 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.
TagsNo tags attached.
mwticket

Activities

lab-at-nohl

lab-at-nohl

2017-10-09 14:26

developer   ~0020906

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.
pmehrer

pmehrer

2017-10-12 18:00

developer   ~0020932

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?
lab-at-nohl

lab-at-nohl

2017-10-13 14:41

developer   ~0020956

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?
pmehrer

pmehrer

2017-10-16 06:31

developer   ~0020974

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?

Issue History

Date Modified Username Field Change
2017-10-06 21:28 lab-at-nohl New Issue
2017-10-09 08:28 pschuele Assigned To => pmehrer
2017-10-09 14:26 lab-at-nohl Note Added: 0020906
2017-10-12 18:00 pmehrer Note Added: 0020932
2017-10-13 14:41 lab-at-nohl Note Added: 0020956
2017-10-16 06:31 pmehrer Note Added: 0020974