Zodbconvert incredibly slow [solved]

Plone Support Deployment & hosting
,
1

Hi,

I just started zodbconvert to convert a zeo storage (Data.fs and blobstorage) to an Oracle database instance. Together it is round about 24MB of data. However the conversion is ultra slow as you can see here:

2021-03-22 13:49:51,685 [relstorage.storage.copy] INFO Counting the transactions to copy.
2021-03-22 13:49:51,685 [relstorage.storage.copy] DEBUG Opened the other iterator: <ZODB.FileStorage.FileStorage.FileIterator object at 0x7f6d2123e700>
2021-03-22 13:49:51,685 [relstorage.storage.copy] DEBUG Iterator <ZODB.FileStorage.FileStorage.FileIterator object at 0x7f6d2123e700> doesn't support len()
2021-03-22 13:49:51,701 [relstorage.storage.copy] INFO Copying 1094 transactions
2021-03-22 13:51:02,379 [relstorage.storage.copy] INFO Copied tid 278263010425497958,    1 records |  0.031 MB/s (    20/  1094,  1.83%)
2021-03-22 13:51:07,402 [relstorage.storage.copy] DEBUG Copying <_io.BufferedReader name='/home/bibdok/resources/initDB/blobstorage/0x00/0x00/0x00/0x00/0x00/0x03/0x9a/0x7f/0x03dc96bc3554e477.blob'> to temporary blob file /home/bibdok/plone/instance/var/cacheblob/tmp/tmpjndmzs72.tmp for upload
2021-03-22 13:51:13,081 [relstorage.storage.copy] DEBUG Removing temporary blob file /home/bibdok/plone/instance/var/cacheblob/tmp/tmpjndmzs72.tmp
2021-03-22 13:53:01,544 [relstorage.storage.copy] INFO Copied tid 278269461149199854,    2 records |  0.022 MB/s (    30/  1094,  2.74%)
2021-03-22 13:58:51,543 [relstorage.storage.copy] INFO Copied tid 278286534009307767,    8 records |  0.008 MB/s (    40/  1094,  3.66%)
2021-03-22 14:04:40,362 [relstorage.storage.copy] INFO Copied tid 278293057120174677,    1 records |  0.005 MB/s (    50/  1094,  4.57%)

And that's all I am seeing up to now.

This is the script I am using:

<filestorage source>
    path /home/user/resources/initDB/Data.fs
    blob-dir /home/user/resources/initDB/blobstorage
</filestorage>

<relstorage destination>
    shared-blob-dir false
    blob-dir /home/user/plone/instance/var/cacheblob
    <oracle>
        dsn (DESCRIPTION=(ADDRESS=(PROTOCOL=TCP)(HOST=xxx)(PORT=1521))(CONNECT_DATA=(SID=xxx)))
        user xxx
        password xxx
    </oracle>
</relstorage>

There are other similar topics but they are not helping me:

Oh, and I am using Plone 5.2.2 with Relstorage in version 3.3.2 with Python 3.8 and the Oracle client in version 19.9.0.0.0 on CentOS 7 within a docker.

What is hapenning here? Why is it so slow? When working with an already initialized Plone it is very fast.

2

When I check the current SQL statement that is running on the database server, it is always this:

SELECT
    zoid,
    tid,
    prev_tid,
    current_object_state.state
FROM
    temp_store
        JOIN current_object_state
            USING (zoid)
WHERE (tid <> prev_tid)

If I call this manually it needs round about 35 seconds and returns an empty list. It is not clear to me what it does. But it does this for every transaction if sure will take a while. I could imagine that there are some indexes or foreign keys missing or something like that. I will try to find a ways to make it faster.

I also tried it with RelStorage in Version 3.4 but the speed has not changed.

3

I found the culprit. There is the view current_object_state of this form:

CREATE OR REPLACE FORCE EDITIONABLE VIEW "CURRENT_OBJECT_STATE" (
	"ZOID",
	"TID",
	"STATE"
) AS 
	SELECT
		zoid,
		tid,
		state
	FROM object_state
		JOIN current_object
			USING (zoid, tid);

The table object_state already has an unique index over (ZOID, TID) but the table current_object does not. So I added one manually:

CREATE UNIQUE INDEX "CURRENT_OBJECT_UI" ON "CURRENT_OBJECT" ("ZOID", "TID")

Now the SELECT from my previous post only lasts 55 ms instead of 35 s. So it is over 600 times faster! Now after starting zodbconvert again it is also a lot faster. Instead of 139 transactions after 68 minutes I now got 631 transactions after 8.6 minutes. That is nearly 36 times as fast as before.

I will send that fix to the RelStorage people over at Github.

2 Likes
4

For reference here is the issue on Github: [oracle] zodbconvert incredibly slow. Here is a fix. · Issue #450 · zodb/relstorage · GitHub