0003336: SVN 17079: user's contact_id in tine20_accounts gets incremented

[Gloirin]

Reported by Gurney on 13 Nov 2010 17:21

Version: git master

While my proper user contact_id in tine20_addressbook is 4, it is somehow ignored and one entry is created in tine20_addressbook and the contact_id in tine20_accounts is modified accordingly.

Here's what I found in the log:

[Sat Nov 13 18:15:24 2010] [error] [client 90.84.146.191] PHP Fatal error: Uncaught exception 'Zend_Db_Statement_Exception' with message 'SQLSTATE[23000]: Integrity constraint violation: 1062 Duplicate entry '1000' for key 1' in /media/server/www/tine/library/Zend/Db/Statement/Pdo.php:238

Stack trace:
#0 /media/server/www/tine/library/Zend/Db/Statement.php(284): Zend_Db_Statement_Pdo->execute(Array)
#1 /media/server/www/tine/library/Zend/Db/Adapter/Abstract.php(468): Zend_Db_Statement->execute(Array)
#2 /media/server/www/tine/library/Zend/Db/Adapter/Pdo/Abstract.php(238): Zend_Db_Adapter_Abstract->query('INSERT INTO ti...', Array) #3 /media/server/www/tine/library/Zend/Db/Adapter/Abstract.php(546): Zend_Db_Adapter_Pdo_Abstract->query('INSERT INTO ti...', Array)
#4 /media/server/www/tine/library/Zend/Db/Table/Abstract.php(1047): Zend_Db_Adapter_Abstract->insert('tine20_accounts', Array)
#5 /media/server/www/tine/Tinebase/User/Sql.php(632): Zend_Db_Table_Abstract->insert(Array)
#6 /media/server/www/tine/Tinebase/User.php(417): Tinebase_User_Sql>addUserInSqlBackend(Object(Tinebase in /media/server/www/tine/library/Zend/Db/Statement/Pdo.php on line 238

[Gloirin]

Comment posted by Gurney on 15 Nov 2010 14:07

This happens during login, either through the Web Interface or through Activesync (I had 4000+ entries in tine20_addressbook this morning :p)

[Gloirin]

Comment posted by Gurney on 17 Nov 2010 20:29

I've extensively check the log and nowhere it mentions anything about adding a user in the tine20_addressbook, there's simply no error except the one in the error.log mentionned above.

[Gloirin]

Comment posted by Gurney on 24 Nov 2010 05:56

Latest trunk, still this in my error.log:

[Wed Nov 24 06:46:45 2010] [error] [client 192.168.0.1] PHP Fatal error: Uncaught exception 'Zend_Db_Statement_Exception' with message 'SQLSTATE[23000]: Integrity constraint violation: 1062 Duplicate entry '1000' for key 'PRIMARY'' in /media/server/www/tine/library/Zend/Db/Statement/Pdo.php:238\nStack trace:\n#0 /media/server/www/tine/library/Zend/Db/Statement.php(284): Zend_Db_Statement_Pdo->_execute(Array)\n#1 /media/server/www/tine/library/Zend/Db/Adapter/Abstract.php(468): Zend_Db_Statement->execute(Array)\n#2 /media/server/www/tine/library/Zend/Db/Adapter/Pdo/Abstract.php(238): Zend_Db_Adapter_Abstract->query('INSERT INTO ti...', Array)\n#3 /media/server/www/tine/library/Zend/Db/Adapter/Abstract.php(546): Zend_Db_Adapter_Pdo_Abstract->query('INSERT INTO ti...', Array)\n#4 /media/server/www/tine/library/Zend/Db/Table/Abstract.php(1047): Zend_Db_Adapter_Abstract->insert('tine20_accounts', Array)\n#5 /media/server/www/tine/Tinebase/User/Sql.php(633): Zend_Db_Table_Abstract->insert(Array)\n#6 /media/server/www/tine/Tinebase/User.php(417): Tinebase_User_Sql->addUserInSqlBackend(Object(T in /media/server/www/tine/library/Zend/Db/Statement/Pdo.php on line 238

[Gloirin]

Comment posted by Gurney on 24 Nov 2010 05:58

And sometimes this ones:

[Wed Nov 24 06:24:53 2010] [error] [client 80.10.46.32] PHP Fatal error: Uncaught exception 'Zend_Db_Statement_Exception' with message 'SQLSTATE[40001]: Serialization failure: 1213 Deadlock found when trying to get lock; try restarting transaction' in /media/server/www/tine/library/Zend/Db/Statement/Pdo.php:238\nStack trace:\n#0 /media/server/www/tine/library/Zend/Db/Statement.php(284): Zend_Db_Statement_Pdo->_execute(Array)\n#1 /media/server/www/tine/library/Zend/Db/Adapter/Abstract.php(468): Zend_Db_Statement->execute(Array)\n#2 /media/server/www/tine/library/Zend/Db/Adapter/Pdo/Abstract.php(238): Zend_Db_Adapter_Abstract->query('INSERT INTO ti...', Array)\n#3 /media/server/www/tine/library/Zend/Db/Adapter/Abstract.php(546): Zend_Db_Adapter_Pdo_Abstract->query('INSERT INTO ti...', Array)\n#4 /media/server/www/tine/library/Zend/Db/Table/Abstract.php(1047): Zend_Db_Adapter_Abstract->insert('tine20_accounts', Array)\n#5 /media/server/www/tine/Tinebase/User/Sql.php(633): Zend_Db_Table_Abstract->insert(Array)\n#6 /media/server/www/tine/Tinebase/User.php(417): Tinebase_User_Sql->addUserInSq in /media/server/www/tine/library/Zend/Db/Statement/Pdo.php on line 238

[Wed Nov 24 02:22:58 2010] [error] [client 80.10.46.32] PHP Fatal error: Uncaught exception 'Zend_Db_Statement_Exception' with message 'SQLSTATE[42000]: Syntax error or access violation: 1064 You have an error in your SQL syntax; check the manual that corresponds to your MySQL server version for the right syntax to use near 'JOIN tine20_addressbook AS attendeecontacts ON attendeecontacts.id = `at' at line 43' in /media/server/www/tine/library/Zend/Db/Statement/Pdo.php:238\nStack trace:\n#0 /media/server/www/tine/library/Zend/Db/Statement.php(284): Zend_Db_Statement_Pdo->_execute(Array)\n#1 /media/server/www/tine/library/Zend/Db/Adapter/Abstract.php(468): Zend_Db_Statement->execute(Array)\n#2 /media/server/www/tine/library/Zend/Db/Adapter/Pdo/Abstract.php(238): Zend_Db_Adapter_Abstract->query(Object(Zend_Db_Select), Array)\n#3 /media/server/www/tine/Calendar/Backend/Sql.php(224): Zend_Db_Adapter_Pdo_Abstract->query(Object(Zend_Db_Select))\n#4 /media/server/www/tine/Tinebase/Controller/Record/Abstract.php(132): Calendar_Backend_Sql->search(Object(Calendar_Model_EventFilter), NULL, in /media/server/www/tine/library/Zend/Db/Statement/Pdo.php on line 238

[Gloirin]

Comment posted by Gurney on 24 Nov 2010 17:10

Ok, it seems to happen only when login through ActiveSync.

For some reason Tine wants to insert again my user in the tine20_account table. This leads to the SQLSTATE[23000]: Integrity constraint violation and causes the login to fail.

This doesn't happen (anymore?) through the web interface.

[Gloirin]

Comment posted by Gurney on 28 Nov 2010 08:42

Ok, I made some progress.

In Tinebase_User (tinebase/user.php), in the method syncUser, an exception is thrown in the try (line 371).

It of course results in the try to fail, resulting in the addition of a new contact in the GAB. I think this line needs to be deleted.

I commented it out, and I have new problems :)

In Tinebase_User_Sql (tinebase/user/sql.php), there's a problem in the function updateUserInSqlBackend. Line 517 fails:

[Sun Nov 28 09:08:46 2010] [error] [client 79.95.185.82] PHP Fatal error: Uncaught exception 'Tinebase_Exception_Record_Validation' with message 'Invalid user object. Array\n(\n [0] => Array\n (\n [id] => accountStatus\n [msg] => Array\n (\n [notEmptyInvalid] => Invalid type given, value should be float, string, integer or an object\n )\n\n )\n\n)\n' in /media/server/www/tine/Tinebase/User/Sql.php:517

Stack trace:
#0 /media/server/www/tine/Tinebase/User.php(386): Tinebase_User_Sql->updateUserInSqlBackend(Object(Tinebase_Model_FullUser))
#1 /media/server/www/tine/Tinebase/Controller.php(88): Tinebase_User::syncUser('gurney')
#2 /media/server/www/tine/ActiveSync/Frontend/Http.php(62): Tinebase_Controller->login('gurney', '', '', 'TineActiveSync')
#3 /media/server/www/tine/ActiveSync/Server/Http.php(78): ActiveSync_Frontend_Http->authenticate('gurney', '', '******')
#4 /media/server/www/tine/Tinebase/Core.php(203): ActiveSync_Server_Http->handle()
#5 /media/serv in /media/server/www/tine/Tinebase/User/Sql.php on line 517

Now I will look why my User's AccountStatus is retrieved as "empty" from MySQL.

[Gloirin]

Comment posted by Gurney on 28 Nov 2010 10:26

Some more news :) I was getting the following error :

[Sun Nov 28 10:48:57 2010] [error] [client 79.95.185.82] PHP Fatal error: Uncaught exception 'Zend_Db_Statement_Exception' with message 'SQLSTATE[23000]: Integrity constraint violation: 1048 Column 'status' cannot be null' in /media/server/www/tine/library/Zend/Db/Statement/Pdo.php:238

Stack trace:
#0 /media/server/www/tine/library/Zend/Db/Statement.php(284): Zend_Db_Statement_Pdo->execute(Array)
#1 /media/server/www/tine/library/Zend/Db/Adapter/Abstract.php(468): Zend_Db_Statement->execute(Array)
#2 /media/server/www/tine/library/Zend/Db/Adapter/Pdo/Abstract.php(238): Zend_Db_Adapter_Abstract->query('UPDATE tine20_...', Array) #3 /media/server/www/tine/library/Zend/Db/Adapter/Abstract.php(604): Zend_Db_Adapter_Pdo_Abstract->query('UPDATE tine20...', Array)
#4 /media/server/www/tine/library/Zend/Db/Table/Abstract.php(1104): Zend_Db_Adapter_Abstract->update('tine20_accounts', Array, Array)
#5 /media/server/www/tine/Tinebase/User/Sql.php(552): Zend_Db_Table_Abstract->update(Array, Array)
#6 /media/server/www/tine/Tinebase/User.php(386): Tinebase_User_Sql->updateUserInSqlBackend(O in /media/server/www/tine/library/Zend/Db/Statement/Pdo.php on line 238

And I figured out I missed the shadowInactive attribute in my LDAP user/schema. I added it and the error is gone :)

I'm still not able to get emails show up in my Android device though (related to #3296 ?)

I'll continue to dig up, I have the following error appearing from time to time

[Sun Nov 28 11:16:37 2010] [error] [client 79.95.185.82] PHP Fatal error: Uncaught exception 'Tinebase_Exception_NotFound' with message 'Felamimail_Model_Message record with messageuid 5406 not found!' in /media/server/www/tine/Tinebase/Backend/Sql/Abstract.php:179

Stack trace:
#0 /media/server/www/tine/Felamimail/Controller/Cache/Message.php(653): Tinebase_Backend_Sql_Abstract->getByProperty('5406', 'messageuid')
#1 /media/server/www/tine/Felamimail/Controller/Cache/Message.php(530): Felamimail_Controller_Cache_Message->addMessage(Array, Object(Felamimail_Model_Folder), false)
#2 /media/server/www/tine/Felamimail/Controller/Cache/Message.php(496): Felamimail_Controller_Cache_Message->_addMessagesToCacheAndIncreaseCounters(Array, Object(Felamimail_Model_Folder))
#3 /media/server/www/tine/Felamimail/Controller/Cache/Message.php(140): Felamimail_Controller_Cache_Message->_addMessagesToCache(Object(Felamimail_Model_Folder), Object(Felamimail_Backend_ImapProxy))
#4 /media/server/www/tine/ActiveSync/Controller/Email.php(576): Felamimail_Controller_Cache_Message->updateCache('f83b04980f5 in /media/server/www/tine/Tinebase/Backend/Sql/Abstract.php on line 179

[Sun Nov 28 11:16:56 2010] [error] [client 79.95.185.82] PHP Fatal error: Uncaught exception 'Zend_Db_Statement_Exception' with message 'SQLSTATE[42000]: Syntax error or access violation: 1064 You have an error in your SQL syntax; check the manual that corresponds to your MySQL server version for the right syntax to use near ')) AND ((felamimail_cache_message.received > '2010-09-28 00:00:00')) AND ((`' at line 5' in /media/server/www/tine/library/Zend/Db/Statement/Pdo.php:238

Stack trace:
#0 /media/server/www/tine/library/Zend/Db/Statement.php(284): Zend_Db_Statement_Pdo->execute(Array)
#1 /media/server/www/tine/library/Zend/Db/Adapter/Abstract.php(468): Zend_Db_Statement->execute(Array)
#2 /media/server/www/tine/library/Zend/Db/Adapter/Pdo/Abstract.php(238): Zend_Db_Adapter_Abstract->query(Object(Zend_Db_Select), Array)
#3 /media/server/www/tine/Tinebase/Backend/Sql/Abstract.php(308): Zend_Db_Adapter_Pdo_Abstract->query(Object(Zend_Db_Select))
#4 /media/server/www/tine/Tinebase/Controller/Record/Abstract.php(131): Tinebase_Backend_Sql_Abstract->search(Object(Felamimail_Model in /media/server/www/tine/library/Zend/Db/Statement/Pdo.php on line 238

[Gloirin]

Comment posted by lkneschke on 5 Dec 2010 18:02

I could reproduce the problem.

Can you please update from SVn and check if it is working now?

[Gloirin]

Comment posted by Gurney on 6 Dec 2010 18:56

yes, it works now!

Thanks!

[Gloirin]

Comment posted by lkneschke on 6 Dec 2010 19:04

Very nice! Thanks for your very helpful bugreport!