dagent 8.7.80.355 Unable to commit message: disk error (80040116) => Mailbox temporarily unavailable

externa1

@fbartels

Hi Felix

I can confirm the same errors on some mails in dagent and kopano-core and mysql logs with Kopano 8.7 beta on UCS4.3

rg

Christian

fbartels

Thanks for the report @externa1. are you able to provide an eml of a mail causing this?

externa1

@fbartels

Hi Felix - you can download 2 examples from the link:

https://remote.ckc-it.at/nextcloud/index.php/s/yKBdkpb95xMfq65

rg
Christian

fbartels

Thanks @externa1. I have created https://jira.kopano.io/browse/KC-1376 to reproduce this and further look into this.

fbartels

@externa1 @irrlicht I managed to reproduce this issue on a local machine that was upgraded from the current final. For 8.7 we introduced support of utf8mb4 to allow additional characters (see https://jira.kopano.io/browse/KC-725).

Since that database conversion can take some time, we afterwards decided to decouple this from the server start. There is still one remaining pr (not yet merged because of test failures) that will address issues like yours above, when the conversion was not yet run.

The long term “fix” is to run kopano-dbadm usmp (when kopano-server is not running) to convert your database.

PS: small details to add here: if you create a new database this will of course be created with support for utf8mb4. its just old databases that need to be updated.

irrlicht

kopano-dbadm usmp

Thank you Felix,

solution works, mails are delivered - most of them spam :)

For reading “sleeping” mails in mailq from postfix there’s the tool “pfqueue” in the debian repository. It’s easier than postqueue- and postsuper-magic

externa1

@fbartels

Hi Felix,

yes that fixed my problem - all mails in postfix queue could be delivered now

rg
Christian

marnoeBT

i had the same problem.
kopano-dbadm usmp fixed that problem :)

thanks felix

@fbartels I had the same problem as well and kopano-dbadm usmp fixed it. However, when running the command I got the following error

Wed Jan  9 22:20:36 2019: [error  ] 0x556b9f65af88: SQL Failed: All parts of a PRIMARY KEY must be NOT NULL; if you need NULL in a key, use UNIQUE instead, Query: "ALTER TABLE `objectproperty` MODIFY COLUMN `propname` varchar(185) CHARACTER SET utf8mb4 BINARY DEFAULT NULL"
Wed Jan  9 22:20:36 2019: [error  ] KDatabase::I_Update() query failed: "All parts of a PRIMARY KEY must be NOT NULL; if you need NULL in a key, use UNIQUE instead", query: ALTER TABLE `objectproperty` MODIFY COLUMN `propname` varchar(185) CHARACTER SET utf8mb4 BINARY DEFAULT NULL
Wed Jan  9 22:20:36 2019: [error  ] dbadm: action failed: disk error (80000007)

DaveJ

This post is deleted!

DaveJ

Hello all, I had the same issue and could solve delivery problem with kopano-dbadm usmp!
Thanks a lot, I thought this could be a database nightmare, luckily it was a quick job.

But unfortunately I got the same error like @aurel - so I’m wondering what kind of future “behavior” I might notice :-/

kopano-dbadm usmp
Sun Jan 13 16:45:19 2019: [notice ] dbadm: executing action "usmp-column-shrink"
Sun Jan 13 16:45:19 2019: [notice ] usmp: discovering overly long named properties...
Sun Jan 13 16:45:19 2019: [notice ] usmp: purging long namedprops from "properties"...
Sun Jan 13 16:45:19 2019: [notice ] usmp: expunged 0 rows
Sun Jan 13 16:45:19 2019: [notice ] usmp: purging long namedprops from "tproperties"...
Sun Jan 13 16:45:19 2019: [notice ] usmp: expunged 0 rows
Sun Jan 13 16:45:19 2019: [notice ] usmp: purging long namedprops from "mvproperties"...
Sun Jan 13 16:45:19 2019: [notice ] usmp: expunged 0 rows
Sun Jan 13 16:45:19 2019: [notice ] usmp: purging long namedprops from "indexedproperties"...
Sun Jan 13 16:45:19 2019: [notice ] usmp: expunged 0 rows
Sun Jan 13 16:45:19 2019: [notice ] usmp: purging long namedprops from "singleinstances"...
Sun Jan 13 16:45:19 2019: [notice ] usmp: expunged 0 rows
Sun Jan 13 16:45:19 2019: [notice ] usmp: purging long namedprops from "lob"...
Sun Jan 13 16:45:19 2019: [notice ] usmp: expunged 0 rows
Sun Jan 13 16:45:19 2019: [notice ] usmp: resizing names.namestring...
Sun Jan 13 16:45:19 2019: [notice ] usmp: resizing receivefolder.messageclass...
Sun Jan 13 16:45:20 2019: [notice ] usmp: resizing objectproperty.propname...
Sun Jan 13 16:45:20 2019: [notice ] usmp: resizing objectmvproperty.propname...
Sun Jan 13 16:45:20 2019: [notice ] usmp: resizing settings.name...
Sun Jan 13 16:45:20 2019: [notice ] dbadm: executing action "usmp-charset"
Sun Jan 13 16:45:20 2019: [notice ] usmp: converting "abchanges" to utf8mb4...
Sun Jan 13 16:45:20 2019: [notice ] usmp: converting "acl" to utf8mb4...
Sun Jan 13 16:45:20 2019: [notice ] usmp: converting "changes" to utf8mb4...
Sun Jan 13 16:45:20 2019: [notice ] usmp: converting "deferredupdate" to utf8mb4...
Sun Jan 13 16:45:20 2019: [notice ] usmp: converting "hierarchy" to utf8mb4...
Sun Jan 13 16:45:20 2019: [notice ] usmp: converting "indexedproperties" to utf8mb4...
Sun Jan 13 16:45:20 2019: [notice ] usmp: converting "lob" to utf8mb4...
Sun Jan 13 16:45:20 2019: [notice ] usmp: converting "mvproperties" to utf8mb4...
Sun Jan 13 16:45:20 2019: [notice ] usmp: converting "object" to utf8mb4...
Sun Jan 13 16:45:20 2019: [notice ] usmp: converting "objectrelation" to utf8mb4...
Sun Jan 13 16:45:20 2019: [notice ] usmp: converting "outgoingqueue" to utf8mb4...
Sun Jan 13 16:45:20 2019: [notice ] usmp: converting "properties" to utf8mb4...
Sun Jan 13 16:46:58 2019: [notice ] usmp: converting "receivefolder" to utf8mb4...
Sun Jan 13 16:46:58 2019: [notice ] usmp: converting "searchresults" to utf8mb4...
Sun Jan 13 16:46:58 2019: [notice ] usmp: converting "settings" to utf8mb4...
Sun Jan 13 16:46:58 2019: [notice ] usmp: converting "singleinstances" to utf8mb4...
Sun Jan 13 16:47:00 2019: [notice ] usmp: converting "stores" to utf8mb4...
Sun Jan 13 16:47:00 2019: [notice ] usmp: converting "syncedmessages" to utf8mb4...
Sun Jan 13 16:47:00 2019: [notice ] usmp: converting "syncs" to utf8mb4...
Sun Jan 13 16:47:00 2019: [notice ] usmp: converting "tproperties" to utf8mb4...
Sun Jan 13 16:49:33 2019: [notice ] usmp: converting "users" to utf8mb4...
Sun Jan 13 16:49:33 2019: [notice ] usmp: converting "versions" to utf8mb4...
Sun Jan 13 16:49:33 2019: [notice ] usmp: converting "objectproperty" to utf8mb4...
Sun Jan 13 16:49:33 2019: [error  ] 0x55e62988ef88: SQL Failed: All parts of a PRIMARY KEY must be NOT NULL; if you need NULL in a key, use UNIQUE instead, Query: "ALTER TABLE `objectproperty` MODIFY COLUMN `propname` varchar(185) CHARACTER SET utf8mb4 BINARY DEFAULT NULL"
Sun Jan 13 16:49:33 2019: [error  ] KDatabase::I_Update() query failed: "All parts of a PRIMARY KEY must be NOT NULL; if you need NULL in a key, use UNIQUE instead", query: ALTER TABLE `objectproperty` MODIFY COLUMN `propname` varchar(185) CHARACTER SET utf8mb4 BINARY DEFAULT NULL
Sun Jan 13 16:49:33 2019: [error  ] dbadm: action failed: disk error (80000007)

maybe it is because I use this database since a long time? > 8 years

+-------+-------+-------+----------+------------------+---------------------+
| major | minor | micro | revision | databaserevision | updatetime          |
+-------+-------+-------+----------+------------------+---------------------+
|     6 |    30 |     0 |    20002 |               29 | 2010-07-27 17:11:02 |

If I can support for further analyses, export things or whatever - please let me know

Cheers!
DaveJ

avalon

I have the same problem, for now I’ve rollback everything.
To my last working version 8.7.80.424.3b35b58f3-0+49.1

fbartels

@avalon which same problem? the “unable to commit” message or the sql error when running kopano-dbadm?

avalon

@fbartels After try to update with “kopano-dbadm usmp” I have the following issue:

Mon Jan 14 17:54:24 2019: [notice ] usmp: converting "versions" to utf8mb4...
Mon Jan 14 17:54:24 2019: [notice ] usmp: converting "objectproperty" to utf8mb4...
Mon Jan 14 17:54:24 2019: [error  ] 0x55697c529f90: SQL Failed: All parts of a PRIMARY KEY must be NOT NULL; if you need NULL in a key, use UNIQUE instead, Query: "ALTER TABLE `objectproperty` MODIFY COLUMN `propname` varchar(185) CHARACTER SET utf8mb4 BINARY DEFAULT NULL"
Mon Jan 14 17:54:24 2019: [error  ] KDatabase::I_Update() query failed: "All parts of a PRIMARY KEY must be NOT NULL; if you need NULL in a key, use UNIQUE instead", query: ALTER TABLE `objectproperty` MODIFY COLUMN `propname` varchar(185) CHARACTER SET utf8mb4 BINARY DEFAULT NULL
Mon Jan 14 17:54:24 2019: [error  ] dbadm: action failed: disk error (80000007)

And no one can sign up anymore.

fbartels

“Sign up” as in “create a new account” or do you mean “sign in” as in “log in to an existing account”?

avalon

@fbartels I mean all existing accounts

irrlicht

Did you restart kopano-server? I haven’t yet, had the same errors in log and everything ist (still) working.

avalon

I have restarted the kopano-server several times, unfortunately without success.

avalon

I make a test system with kopano-core 8.7.80.465.4206adbb5-0+56.1 and new mysql 5.7 DB.
after create some users I start “kopano-dbadm usmp” and have the same error but I have no issues with login.

If I use the DB from my production system and execute “kopano-cli --list-users” no users was found:

User list for Default (1):
User             Full Name            Homeserver
----------------------------------------------------------
SYSTEM           SYSTEM               Kopano

and all stores are orphan

kopano-cli --list-orphans
Stores without users:
Store guid                       Username             Last login       Store size       Store type
--------------------------------------------------------------------------------------------------------
25EE6C4DBE9449709ADBD99A1A8CD6F5                      <unknown>        10.34 MB         private
EE70C69EDD554758B99610A230328E0B                      <unknown>        0.00 MB          private
0A09F0CD74D3407695912AB78A96BA14                      <unknown>        0.00 MB          private
2C8151E0090341A79CD15CCEEACF5FA8                      <unknown>        204.33 MB        private
3E24FE9A034C436C99DDDE74E59CF45B                      <unknown>        1.21 MB          private
19A661641F044990AE1A3ACA8C7683C6                      <unknown>        0.05 MB          private
B15B7158FA7F4A4C8452A917EF6E0EDC                      <unknown>        2.75 MB          private
0415275BFC3848CCA3A2913E6D8C5307                      <unknown>        1768.48 MB       private
CF1551436B054851A8BD7D34B05168C5                      <unknown>        0.02 MB          private
4BDC5A4C216C468AA17C566452062E66                      <unknown>        4423.90 MB       private
5B8F8A911A334F3781FA9BC06F1E0690                      <unknown>        343.77 MB        private
827D1FB7BFC0416094F243E70150B0AB                      <unknown>        2141.51 MB       private
Users without stores (0):
User             Full Name            Homeserver
----------------------------------------------------------

I found the issue.

[kopano]> select * from users;
+----+------------------+-------------+---------------------+---------+
| id | externid         | objectclass | signature           | company |
+----+------------------+-------------+---------------------+---------+
|  1 | NULL             |      196610 |                     |       0 |
|  2 | NULL             |       65537 |                     |       0 |
| 13 | 0f|▒@ތ▒h%▒E}      |      196610 | 2011-07-10 16:54:46 |       0 |
+----+------------------+-------------+---------------------+---------+
3 rows in set (0.00 sec)

The users table is damaged after execute kopano-dbadm usmp .

Before this table looks like this:

[kopano]> select * from users;
+----+------------------+-------------+---------------------+---------+
| id | externid         | objectclass | signature           | company |
+----+------------------+-------------+---------------------+---------+
|  1 | NULL             |      196610 |                     |       0 |
|  2 | NULL             |       65537 |                     |       0 |
|  9 | ▒yl\9nJj▒▒▒▒-rK▒       |       65537 | 2018-02-28 08:52:38 |       0 |
| 10 | ▒▒▒▒J▒▒l$[▒▒;▒          |       65537 | 2018-02-28 08:52:31 |       0 |
| 12 | E~▒▒?C▒▒▒Hʕ+Ky       |       65537 | 2018-03-09 11:21:53 |       0 |
| 13 | 0f|▒@ތ▒h%▒E}      |      196610 | 2011-07-10 16:54:46 |       0 |
| 14 | ~
        M▒▒JǊ▒l▒.8▒▒        |       65538 | 2011-07-14 14:06:06 |       0 |
| 16 | ▒E_▒▒BËy8▒1Z▒       |       65538 | 2011-07-15 20:44:25 |       0 |
| 44 | ▒^▒▒h B▒▒%▒▒r▒▒▒           |       65537 | 2011-07-18 21:32:45 |       0 |
| 46 |6,M▒▒s%▒qo▒     |       65537 | 2012-11-29 18:59:40 |       0 |
| 47 | ▒
▒K▒C▒▒,▒▒eOѥ         |       65537 | 2015-02-09 08:59:36 |       0 |
| 48 | ▒▒Q▒(▒Os▒~▒Qn▒▒z         |       65537 | 2018-02-19 21:34:42 |       0 |
| 49 |RZ▒`▒B▒▒▒>▒▒Y▒▒          |       65537 | 2015-05-31 23:24:55 |       0 |
| 50 | ▒▒▒▒▒@B▒r|▒b▒           |       65537 | 2018-01-30 16:57:04 |       0 |
| 53 | I▒]▒▒EZ▒
               ▒ ▒t;       |       65537 | 2018-02-28 08:00:32 |       0 |
+----+------------------+-------------+---------------------+---------+
15 rows in set (0.00 sec)

mibrymb

I have had this happen to me.