Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Dictionaries didn't updated in v.18.14.18 #3829

Closed
snvad opened this issue Dec 14, 2018 · 24 comments
Closed

Dictionaries didn't updated in v.18.14.18 #3829

snvad opened this issue Dec 14, 2018 · 24 comments
Assignees
Labels
comp-dictionary Dictionaries

Comments

@snvad
Copy link

snvad commented Dec 14, 2018

Clickhouse version 18.14.18. I have several odbc dictionaries (mssql, postgres) with

...
<lifetime>
    <min> 300 </min>
    <max> 360 </max>
</lifetime>
<layout>
    <complex_key_hashed />
</layout>
...

Data in mssql/postgres updated every 5-10 minutes.
However, dictionary updates are not performed.

If i execute: SYSTEM RELOAD DICTIONARY testdict;
return: long wait and <Error> ExternalDictionaries: Cannot update external dictionary 'testdict', leaving old version: Poco::Exception. Code: 1000, e.code() = 11, e.displayText() = Timeout, e.what() = Timeout in clickhouse-server.err.log

In clickhouse-server.log:

2018.12.14 13:44:49.330725 [ 3037651 ] {cc4c7f10-42be-4cdb-8360-ed633f09ef37} <Debug> executeQuery: (from 127.0.0.1:37228) system reload dictionary testdict
SELECT *
FROM system.query_log
WHERE query_id = 'cc4c7f10-42be-4cdb-8360-ed633f09ef37'

Ok.

0 rows in set. Elapsed: 0.178 sec. Processed 59.33 million rows, 2.67 GB (333.32 million rows/s., 15.00 GB/s.)
SELECT *
FROM system.query_thread_log
WHERE query_id = 'cc4c7f10-42be-4cdb-8360-ed633f09ef37'

Ok.

0 rows in set. Elapsed: 0.124 sec. Processed 12.71 million rows, 571.94 MB (102.32 million rows/s., 4.60 GB/s.)
SELECT
    creation_time,
    last_exception
FROM system.dictionaries
WHERE name = 'testdict'

┌───────creation_time─┬─last_exception────────────────────────────────────────────────────────────────────────────┐
│ 2018-12-06 12:31:52 │ Poco::Exception. Code: 1000, e.code() = 11, e.displayText() = Timeout, e.what() = Timeout │
└─────────────────────┴───────────────────────────────────────────────────────────────────────────────────────────┘

In version 18.14.9 everything works well.

@kotoyants
Copy link

kotoyants commented Dec 14, 2018

+1
After update from 18.10.3 to 18.14.18 dictionaries (clickhouse, postgresql) started to accidentally stop updating. Downgrade to 18.14.9 resolves the issue.
No errors in the log file, only one exeption for PDO dictionary:

Poco::Exception. Code: 1000, e.code() = 11, e.displayText() = Timeout, e.what() = Timeout

An attempt to restart dictionary from the console hangs as unkillable query.

@k0st1an
Copy link

k0st1an commented Dec 15, 2018

+1

@alesapin
Copy link
Member

@angeldestroyer In startup process clickhouse updates dictionaries for the first time. If I understood correctly clickhouse can start with that configuration, but cannot update dictionaries?

Can you set your log-level to trace? Also, can you provide information about your OS? Maybe you use clickhouse in docker? Also I'd like to see output of ps aux | grep clickhouse when dictionaries cannot be updated.

@k0st1an
Copy link

k0st1an commented Dec 15, 2018

OS: ubuntu 16.04.5 LTS (not docker)

SYSTEM RELOAD DICTIONARY <name>

long wait ... log:

2018.12.15 08:53:57.249988 [ 8869 ] {e4af30af-f454-49c2-92e8-5accefc67aab} <Debug> executeQuery: (from [::1]:50352) SYSTEM RELOAD DICTIONARY <name>
$ ps aux | grep clickhouse
clickho+  45479  4.8  1.8 38977092 2393952 ?    Ssl  Dec14  61:34 /usr/bin/clickhouse-server --config=/etc/clickhouse-server/config.xml
clickho+  45521  0.0  0.0 545652 64108 ?        Sl   Dec14   0:18 /usr/bin/clickhouse odbc-bridge --http-port 9018 --listen-host localhost --http-timeout 1800000000

What can be filtered in the log, since there is a lot of data not associated with the dictionary?

@k0st1an
Copy link

k0st1an commented Dec 15, 2018

Process clickhouse odbc-bridge should to down after update dict? Checked at 18.16.0. SYSTEM RELOAD DICTIONARY has worked, but the process is hanging. Restarting works without problems. But this is a fresh install. Maybe when there is a timeout error then SYSTEM RELOAD DICTIONARY will not work.

@alesapin
Copy link
Member

alesapin commented Dec 15, 2018

Process clickhouse odbc-bridge should to down after update dict?

No, this process should stay alive with clickhouse server.

@snvad
Copy link
Author

snvad commented Dec 16, 2018

@alesapin, yes, at start all looks fine. But when the update should be performed - timeout occurs and nothing happens. Not docker, not vm. Package installed from the official repository. In the logs only that indicated when opening issue, without additional information.
OS: Ubuntu 16.04.3 LTS

 76116 ?        Ssl  686:10 /usr/bin/clickhouse-server --config=/etc/clickhouse-server/config.xml
 76162 ?        Sl     5:36 /usr/bin/clickhouse odbc-bridge --http-port 9018 --listen-host localhost --http-timeout 1800000000

@k0st1an
Copy link

k0st1an commented Dec 16, 2018

18.16.0 also has problems.

@alesapin
Copy link
Member

I have tried to reproduce the issue, but everything seems to work fine for me(.
My setup:

  • ubuntu 16.04;
  • clickhouse 18.14.18;
  • postgres from docker image docker run -p 5432:5432 --name some-postgres1 -e POSTGRES_PASSWORD=mysecretpassword -d postgres.
  • unixodbc 2.3.1-4.1
  • odbc-postgresql:amd64 1:09.03.0300-1

configs:
postgres_odbc_hashed_dictionary.xml

<dictionaries>
    <dictionary>
        <name>postgres_odbc_hashed</name>
        <source>
            <odbc>
                <table>clickhouse.test_table</table>
                <connection_string>DSN=postgresql_odbc;</connection_string>
                <db>postgres</db>
            </odbc>
        </source>
        <layout>
                <flat/>
        </layout>

        <lifetime>
            <min>10</min>
            <max>30</max>
        </lifetime>


        <structure>
            <id>
                <name>column1</name>
            </id>

            <attribute>
                <name>column1</name>
                <type>Int64</type>

                <injective>true</injective>
                <null_value/>
            </attribute>

            <attribute>
                <name>column2</name>
                <type>String</type>
                <injective>true</injective>
                <null_value/>
            </attribute>

        </structure>
    </dictionary>
</dictionaries>

odbc.ini

[postgresql_odbc]
UserName=postgres
Database=postgres
Setup=/usr/lib/x86_64-linux-gnu/odbc/libodbcpsqlS.so
RowVersioning=No
Protocol=9.3
ConnSettings=
Driver=/usr/lib/x86_64-linux-gnu/odbc/psqlodbca.so
ReadOnly=No
Password=mysecretpassword
Port=5432
Servername=127.0.0.1
ShowSystemTables=No
Trace      = Yes
TraceFile  = /tmp/chodbc.log

Example usage:

$ PGPASSWORD=mysecretpassword psql -h 127.0.0.1 -U postgres
postgres=# create schema clickhouse;
CREATE SCHEMA
postgres=# create table clickhouse.test_table (column1 int, column2 varchar);
CREATE TABLE
postgres=#insert into clickhouse.test_table values (3, '!');                                                                                                                                                                                                                                                                                                                    
INSERT 0 1
# from clickhouse client
 :) select dictGetString('postgres_odbc_hashed', 'column2', toUInt64(3));
┌─dictGetString('postgres_odbc_hashed', 'column2', toUInt64(3))─┐
│ !                                                             │
└───────────────────────────────────────────────────────────────┘
postgres=# insert into clickhouse.test_table values (2, 'Hello'), (1, 'World');                                                                                                                                                                                                                                                                                                                
INSERT 0 2
# from clickhouse client
:) select dictGetString('postgres_odbc_hashed', 'column2', toUInt64(2));
┌─dictGetString('postgres_odbc_hashed', 'column2', toUInt64(2))─┐
│                                                                │
└────────────────────────────────────────────────────────────────┘
# sleep 30 secs
:) select dictGetString('postgres_odbc_hashed', 'column2', toUInt64(2));
┌─dictGetString('postgres_odbc_hashed', 'column2', toUInt64(2))─┐
│ Hello                                                         │
└───────────────────────────────────────────────────────────────┘
postgres=# insert into clickhouse.test_table values (4, 'OK');                                                                                                                                                                                                                                                                                                                
INSERT 0 1
:) system reload dictionaries;
Ok.
:) select dictGetString('postgres_odbc_hashed', 'column2', toUInt64(4));
┌─dictGetString('postgres_odbc_hashed', 'column2', toUInt64(4))─┐
│ OK                                                            │
└───────────────────────────────────────────────────────────────┘

Can you provide similar information about your setup or minimal example to reproduce the issue?

P.S. Also we have integration tests in docker which interact via odbc with different databases -- sqlite, postgres and mysql. These tests are also in green state.

@alesapin
Copy link
Member

Sorry, did not notice, that you use complex_key_hashed dictionary, but situation is similar with this config:

<dictionaries>
    <dictionary>
        <name>postgres_odbc_hashed</name>
        <source>
            <odbc>
                <table>clickhouse.test_table</table>
                <connection_string>DSN=postgresql_odbc;</connection_string>
                <db>postgres</db>
            </odbc>
        </source>
        <layout>
                <complex_key_hashed/>
        </layout>

        <lifetime>
            <min>10</min>
            <max>30</max>
        </lifetime>


        <structure>
            <key>
                <attribute>
                    <name>column1</name>
                    <type>Int64</type>
                    <null_value>1</null_value>
                </attribute>
            </key>

            <attribute>
                <name>column2</name>
                <type>String</type>
                <injective>true</injective>
                <null_value/>
            </attribute>

        </structure>
    </dictionary>
</dictionaries>

Queries:

postgres=# insert into clickhouse.test_table values (6 'OK');                                                                                                                                                                                                                                                                                                                                  
INSERT 0 1
:) select dictGetString('postgres_odbc_hashed', 'column2', tuple(toInt64(6)));
┌─dictGetString('postgres_odbc_hashed', 'column2', tuple(toInt64(6)))─┐
│                                                                     │
└─────────────────────────────────────────────────────────────────────┘
:) system reload dictionaries;
Ok. 
:) select dictGetString('postgres_odbc_hashed', 'column2', tuple(toInt64(6)));
┌─dictGetString('postgres_odbc_hashed', 'column2', tuple(toInt64(6)))─┐
│ OK                                                                  │
└─────────────────────────────────────────────────────────────────────┘

@k0st1an
Copy link

k0st1an commented Dec 17, 2018

Error appears when updating one of the dictionaries failed:

Poco::Exception. Code: 1000, e.code() = 11, e.displayText() = Timeout, e.what() = Timeout

After this the dictionaries are not updated. SYSTEM RELOAD DICTIONARIES is wery long... infinity (

If kill the clickhouse odbc-bridge, it will restart. Everything works up to the next error.

@alesapin
Copy link
Member

alesapin commented Dec 17, 2018

@k0st1an I.e. single update performed after odbc-bridge restart, but all consecutive updates hang?
clickhouse-server communicate with clickhouse odbc-bridge via http, using tcp port 9018 on localhost. Maybe you have some iptables rules which forbid these connections?
If you enable trace log level you should see following messages in clickhouse-server.log:

2018.12.17 12:42:22.285039 [ 33 ] {} <Trace> ReadWriteBufferFromHTTP: Sending request to http://localhost:9018/ping
2018.12.17 12:42:22.285491 [ 33 ] {} <Trace> ReadWriteBufferFromHTTP: Sending request to http://localhost:9018/?connection_string=DSN%3Dpostgresql_odbc%3B&columns=columns%20format%20version%3A%201%0A2%20columns%3A%0A%60column1%60%20Int64%0A%60column2%60%20String%0A&max_block_size=8192
2018.12.17 12:42:52.289815 [ 33 ] {} <Trace> ODBCDictionarySource: SELECT "column1", "column2" FROM "postgres"."clickhouse"."test_table";

Try to curl these URLs.

@k0st1an
Copy link

k0st1an commented Dec 17, 2018

curl http://localhost:9018/ping

Not works if last_exception is Poco::Exception. Code: 1000, e.code() = 11, e.displayText() = Timeout, e.what() = Timeout

@alesapin
Copy link
Member

alesapin commented Dec 17, 2018

Was clickhouse odbc-bridge alive when you have tried to curl? What exactly curl http://localhost:9018/ping output?

Anyway, need logs of clickhouse-server in trace level or reproducible example. Also I'd like to see dictionary config.

@k0st1an
Copy link

k0st1an commented Dec 17, 2018

┌─version()─┐
│ 18.16.0   │
└───────────┘
...
┌─name────────┬─type─────────────┬─bytes_allocated─┬─last_exception────────────────────────────────────────────────────────────────────────────┐
│ xxxxxxxxx   │ Hashed           │        18200680 │ Poco::Exception. Code: 1000, e.code() = 11, e.displayText() = Timeout, e.what() = Timeout │
└─────────────┴──────────────────┴─────────────────┴───────────────────────────────────────────────────────────────────────────────────────────┘

5 rows in set. Elapsed: 0.003 sec.

c4.domain.com :) ^C
user@clickhouse4:~$ curl http://localhost:9018/ping
^C

When execute curl log of clickhouse is clear, no records.

user@clickhouse4:~$ ps aux | grep click
user   22400  0.0  0.0  14224   940 pts/0    S+   12:35   0:00 grep --color=auto click
clickho+  66753 66.3  9.3 101511004 12344280 ?  Ssl  Dec15 2010:43 /usr/bin/clickhouse-server --config=/etc/clickhouse-server/config.xml
clickho+  66892  0.0  0.0      0     0 ?        Z    Dec15   0:33 [clickhouse] <defunct>
clickho+ 133504  0.1  0.1 623996 175368 ?       Sl   10:23   0:12 /usr/bin/clickhouse odbc-bridge --http-port 9018 --listen-host localhost --http-timeout 1800000000
user@clickhouse4:~$ sudo kill -9 133504
user@clickhouse4:~$ curl http://localhost:9018/ping
Ok.
┌─name────────┬─type─────────────┬─bytes_allocated─┬─last_exception─┐
│ xxxxxxxxx   │ Hashed           │        18200680 │                │
└─────────────┴──────────────────┴─────────────────┴────────────────┘

@k0st1an
Copy link

k0st1an commented Dec 17, 2018

SYSTEM RELOAD DICTIONARIES executed N count. no problem. Then at some point timeout.

@alesapin
Copy link
Member

Sorry, this diagnosis is not enought.

@snvad
Copy link
Author

snvad commented Dec 18, 2018

The problem is not reproduced on a small number of dictionaries (or allocated_memory).

"Disabled" all dictionaries and restarted CH (I have 12 Hashed/ComplexKeyHashed dictionaries with size ranging from 100KB to 1,4GB). Enable two test-dictionaries.

┌─name─────────────────────┬─type─────────────┬─key──────┬─element_count─┬─formatReadableSize(bytes_allocated)─┬───────creation_time─┬─last_exception─┐
│ postgres_odbc_hashed_str │ ComplexKeyHashed │ (String) │             2 │ 18.37 KiB                           │ 2018-12-18 11:03:19 │                │
│ postgres_odbc_hashed     │ ComplexKeyHashed │ (Int64)  │             3 │ 18.37 KiB                           │ 2018-12-18 11:01:24 │                │
└──────────────────────────┴──────────────────┴──────────┴───────────────┴─────────────────────────────────────┴─────────────────────┴────────────────┘

2 rows in set. Elapsed: 0.008 sec.
SYSTEM RELOAD DICTIONARIES

Ok.

0 rows in set. Elapsed: 0.068 sec.

I return my dictionary:

SYSTEM RELOAD DICTIONARIES

Ok.

0 rows in set. Elapsed: 64.055 sec.

## Get info
┌─name─────────────────────┬─type─────────────┬─key──────┬─element_count─┬─formatReadableSize(bytes_allocated)─┬───────creation_time─┬─last_exception─┐
│ <dict_name_1>            │ Hashed           │ UInt64   │        462832742.19 MiB                          │ 2018-12-18 11:07:46 │                │
│ postgres_odbc_hashed     │ ComplexKeyHashed │ (Int64)  │             318.37 KiB                           │ 2018-12-18 11:07:46 │                │
│ postgres_odbc_hashed_str │ ComplexKeyHashed │ (String) │             218.37 KiB                           │ 2018-12-18 11:09:11 │                │
└──────────────────────────┴──────────────────┴──────────┴───────────────┴─────────────────────────────────────┴─────────────────────┴────────────────┘

Enable one more:

SYSTEM RELOAD DICTIONARIES

Ok.

0 rows in set. Elapsed: 32.791 sec.

## Get info ...
┌─name─────────────────────┬─type─────────────┬─key──────┬─element_count─┬─formatReadableSize(bytes_allocated)─┬───────creation_time─┬─last_exception─┐
│ <dict_name_2>            │ Hashed           │ UInt64   │          57439.96 MiB                            │ 2018-12-18 11:11:26 │                │
│ <dict_name_1>            │ Hashed           │ UInt64   │        462833742.19 MiB                          │ 2018-12-18 11:11:26 │                │
│ postgres_odbc_hashed     │ ComplexKeyHashed │ (Int64)  │             318.37 KiB                           │ 2018-12-18 11:11:26 │                │
│ postgres_odbc_hashed_str │ ComplexKeyHashed │ (String) │             218.37 KiB                           │ 2018-12-18 11:13:11 │                │
└──────────────────────────┴──────────────────┴──────────┴───────────────┴─────────────────────────────────────┴─────────────────────┴────────────────┘

Enable one more:

SYSTEM RELOAD DICTIONARIES

...... long-long time ...... and file <dict_name_3>-preprocessed.xml is not created.

Information about this dictionary from a working server:

┌─type───┬─key────┬─element_count─┬─size───────┬───────creation_time─┬─last_exception─┐
│ Hashed │ UInt64 │           995156.35 KiB │ 2018-12-18 11:22:16 │                │
└────────┴────────┴───────────────┴────────────┴─────────────────────┴────────────────┘

Just in case

 $ free -hm
              total        used        free      shared  buff/cache   available
Memory:         19G        4,8G        1,1G         24M         13G         14G

$ ps ax | grep clickhouse
 49074 ?        Ssl    1:16 /usr/bin/clickhouse-server --config=/etc/clickhouse-server/config.xml
 49105 ?        Sl     1:22 /usr/bin/clickhouse odbc-bridge --http-port 9018 --listen-host localhost --http-timeout 1800000000

If i do kill -p 49105 and try reload dictionaries:

SYSTEM RELOAD DICTIONARIES

Ok.

0 rows in set. Elapsed: 47.224 sec.

## Get info
┌─name─────────────────────┬─type─────────────┬─key──────┬─element_count─┬─formatReadableSize(bytes_allocated)─┬───────creation_time─┬─last_exception─┐
│ <dict_name_2>            │ Hashed           │ UInt64   │          57439.96 MiB                            │ 2018-12-18 11:38:12 │                │
│ <dict_name_1>            │ Hashed           │ UInt64   │        462856742.19 MiB                          │ 2018-12-18 11:38:12 │                │
│ postgres_odbc_hashed     │ ComplexKeyHashed │ (Int64)  │             318.37 KiB                           │ 2018-12-18 11:38:12 │                │
│ <dict_name_3>            │ Hashed           │ UInt64   │           995156.35 KiB                          │ 2018-12-18 11:38:12 │                │
│ postgres_odbc_hashed_str │ ComplexKeyHashed │ (String) │             218.37 KiB                           │ 2018-12-18 11:39:57 │                │
└──────────────────────────┴──────────────────┴──────────┴───────────────┴─────────────────────────────────────┴─────────────────────┴────────────────┘
$ curl http://localhost:9018/ping
Ok.

Reload dictionaries again:

SYSTEM RELOAD DICTIONARIES

....... nothing happens ......

and now $ curl http://localhost:9018/ping - nothing happens too.

@snvad
Copy link
Author

snvad commented Dec 18, 2018

I tried to "enable" dictionaries from small to large.
Up to this point, everything was fine:

┌─type─────────────┬─key──────┬─element_count─┬─formatReadableSize(bytes_allocated)─┬───────creation_time─┬─last_exception─┐
│ ComplexKeyHashed │ (String) │             2 │ 18.37 KiB                           │ 2018-12-18 12:14:17 │                │
│ ComplexKeyHashed │ (Int64)  │             3 │ 18.37 KiB                           │ 2018-12-18 12:14:17 │                │
│ Hashed           │ UInt64   │           995 │ 156.35 KiB                          │ 2018-12-18 12:14:15 │                │
│ ComplexKeyHashed │ (String) │          9853 │ 6.25 MiB                            │ 2018-12-18 12:14:17 │                │
│ Hashed           │ UInt64   │          5744 │ 9.96 MiB                            │ 2018-12-18 12:14:15 │                │
│ Hashed           │ UInt64   │        327974 │ 16.00 MiB                           │ 2018-12-18 12:14:17 │                │
│ ComplexKeyHashed │ (String) │          5744 │ 19.57 MiB                           │ 2018-12-18 12:14:17 │                │
└──────────────────┴──────────┴───────────────┴─────────────────────────────────────┴─────────────────────┴────────────────┘

When I tried to add a ~410MB dictionary - problem repeated

## from another CH v18.14.9
┌─type───┬─key────┬─element_count─┬─size───────┬───────creation_time─┬─last_exception─┐
│ Hashed │ UInt64 │        462892409.22 MiB │ 2018-12-18 12:17:22 │                │
└────────┴────────┴───────────────┴────────────┴─────────────────────┴────────────────┘

@alesapin
Copy link
Member

alesapin commented Dec 18, 2018

@k0st1an @angeldestroyer as workaround specify settings for odbc-bridge logging:
#3825 (comment)

@snvad
Copy link
Author

snvad commented Dec 19, 2018

I don't know why, but after adding the specified logging settings, the error is not reproduced. Dictionaries reload in 2-3 minutes. Previously, you could wait more than 10 minutes and nothing happened or see timeout error.
@k0st1an, what about you?

@alesapin
Copy link
Member

alesapin commented Dec 19, 2018

@angeldestroyer
odbc-bridge created pipe (stdout) for logging, which nobody read from. Logging messages were written to this pipe until it reaches 64K (default linux pipe size) and everything works perfectly. After that attempt to log any message led to hang up on write syscal (pipe were overflown).

@k0st1an
Copy link

k0st1an commented Dec 19, 2018

@angeldestroyer After the changes, everything works well.

@alesapin
Copy link
Member

alesapin commented Dec 19, 2018

v18.14.19-stable released, please update and try to disable settings. This fix is almost the only in this version.

@filimonov filimonov added the comp-dictionary Dictionaries label May 8, 2019
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
comp-dictionary Dictionaries
Projects
None yet
Development

No branches or pull requests

5 participants