Replication stops with "missing chunk number 0 for toast value"

[badboyd]

Bottledwater was running on replication stream mode then it exited with this message

[FATAL] Replication stream was unexpectedly terminated: ERROR: missing chunk number 0 for toast value 507471 in pg_toast_17774
CONTEXT: slot "bottledwater", output plugin "bottledwater", in the change callback, associated LSN E3/32827B38

Exit nicely. Bye bye !

[samstokes]

Unfortunately right now --on-error only applies to errors that occur in the client daemon. That error is coming from the logical decoding output plugin, which currently always terminates the replication stream on error. This can also happen e.g. for very large values: see #36. I'm working on a change that will pass the error policy through to the output plugin, so that if the policy is log it will log and drop.

However, it looks like there's a separate issue here - any idea what that "missing chunk number" error is all about? Are you able to isolate what data or table schema is causing that?

[badboyd]

I think the error is came from this line

I do a research, this error happens with other people too, please look at this

And then I check this guy code
and an example in postgresql code, look like they check this condition VARATT_IS_EXTERNAL_ONDISK before detoasting the datum.

I'm still reading to find out what VARATT_IS_EXTERNAL_ONDISK actually does.

[samstokes]

Hmm, that nabble link has been down for maintenance since yesterday so I can't read the thread you linked to. Does look like there might be an extra case to check for, although it's weird that the pg_plugins code you linked to has an Assert(0) for that code path (and a comment saying "this should never happen")!

If you are able to track this down and verify it fixes the issue you're seeing, it would be great if you could submit it as a pull request.

[abcfy2]

Same issue here.

Writing messages to Kafka in JSON format
Replication slot "bottledwater" exists, streaming changes from 17/3AB2B1B8.
Registering metadata for table moni_alarm (relid 16464)
Opening Kafka topic "moni_alarm" for table "moni_alarm"
Storing key schema for table 16464
Storing row schema for table 16464
Registering metadata for table moni_info_center (relid 16629)
Opening Kafka topic "moni_info_center" for table "moni_info_center"
Storing key schema for table 16629
Storing row schema for table 16629
Registering metadata for table moni_inbox (relid 16621)
Opening Kafka topic "moni_inbox" for table "moni_inbox"
Storing key schema for table 16621
Storing row schema for table 16621
Registering metadata for table moni_equipment (relid 16551)
Opening Kafka topic "moni_equipment" for table "moni_equipment"
Storing key schema for table 16551
Storing row schema for table 16551
Registering metadata for table moni_equipment_location_history (relid 16581)
Opening Kafka topic "moni_equipment_location_history" for table "moni_equipment_location_history"
Storing key schema for table 16581
Storing row schema for table 16581
Registering metadata for table mart_goods (relid 17242)
Opening Kafka topic "mart_goods" for table "mart_goods"
Storing key schema for table 17242
Storing row schema for table 17242
Registering metadata for table comm_login_history (relid 16412)
Opening Kafka topic "comm_login_history" for table "comm_login_history"
Storing key schema for table 16412
Storing row schema for table 16412
Registering metadata for table comm_tools_used_records (relid 41941)
Opening Kafka topic "comm_tools_used_records" for table "comm_tools_used_records"
Storing key schema for table 41941
Storing row schema for table 41941
Registering metadata for table mart_order_goods (relid 17335)
Opening Kafka topic "mart_order_goods" for table "mart_order_goods"
Storing key schema for table 17335
Storing row schema for table 17335
Registering metadata for table mart_order_action (relid 17327)
Opening Kafka topic "mart_order_action" for table "mart_order_action"
Storing key schema for table 17327
Storing row schema for table 17327
Registering metadata for table mart_order_info (relid 17346)
Opening Kafka topic "mart_order_info" for table "mart_order_info"
Storing key schema for table 17346
Storing row schema for table 17346
Registering metadata for table mart_browse_history (relid 19280)
Opening Kafka topic "mart_browse_history" for table "mart_browse_history"
Storing key schema for table 19280
Storing row schema for table 19280
Registering metadata for table mart_goods_goods_category (relid 17295)
Opening Kafka topic "mart_goods_goods_category" for table "mart_goods_goods_category"
Storing row schema for table 17295
/usr/bin/bottledwater: Replication stream was unexpectedly terminated: ERROR:  missing chunk number 0 for toast value 47111 in pg_toast_17242
CONTEXT:  slot "bottledwater", output plugin "bottledwater", in the change callback, associated LSN 17/3AF0A760

How to solve?

[badboyd]

Can you try my commit ?

Please update us if it solves the bug.

[abcfy2]

I can't build from the source(Ubuntu 14.04).

I followed the build steps, but I failed:

make

make -C ext all
Package libsnappy was not found in the pkg-config search path.
Perhaps you should add the directory containing `libsnappy.pc'
to the PKG_CONFIG_PATH environment variable
Package 'libsnappy', required by 'avro-c', not found
make[1]: Entering directory `/root/bottledwater/bottledwater-pg/ext'
make[1]: Nothing to be done for `all'.
make[1]: Leaving directory `/root/bottledwater/bottledwater-pg/ext'
make -C client all
Package libsnappy was not found in the pkg-config search path.
Perhaps you should add the directory containing `libsnappy.pc'
to the PKG_CONFIG_PATH environment variable
Package 'libsnappy', required by 'avro-c', not found
make[1]: Entering directory `/root/bottledwater/bottledwater-pg/client'
gcc -c -std=c99 -D_POSIX_C_SOURCE=200809L -I/usr/include/postgresql -I/usr/include/postgresql/9.4/server  -Wall -Wmissing-prototypes -Wpointer-arith -Wendif-labels -Wmissing-format-attribute -Wformat-security replication.c -o replication.o
In file included from replication.c:13:0:
/usr/include/postgresql/internal/pqexpbuffer.h:149:13: warning: no previous prototype for ‘printfPQExpBuffer’ [-Wmissing-prototypes]
 extern void printfPQExpBuffer(PQExpBuffer str, const char *fmt,...) pg_attribute_printf(2, 3);
             ^
/usr/include/postgresql/internal/pqexpbuffer.h: In function ‘printfPQExpBuffer’:
/usr/include/postgresql/internal/pqexpbuffer.h:149:69: error: expected declaration specifiers before ‘pg_attribute_printf’
 extern void printfPQExpBuffer(PQExpBuffer str, const char *fmt,...) pg_attribute_printf(2, 3);
                                                                     ^
/usr/include/postgresql/internal/pqexpbuffer.h:158:69: error: expected ‘=’, ‘,’, ‘;’, ‘asm’ or ‘__attribute__’ before ‘pg_attribute_printf’
 extern void appendPQExpBuffer(PQExpBuffer str, const char *fmt,...) pg_attribute_printf(2, 3);
                                                                     ^
/usr/include/postgresql/internal/pqexpbuffer.h:165:13: error: storage class specified for parameter ‘appendPQExpBufferStr’
 extern void appendPQExpBufferStr(PQExpBuffer str, const char *data);
             ^
/usr/include/postgresql/internal/pqexpbuffer.h:172:13: error: storage class specified for parameter ‘appendPQExpBufferChar’
 extern void appendPQExpBufferChar(PQExpBuffer str, char ch);
             ^
/usr/include/postgresql/internal/pqexpbuffer.h:179:13: error: storage class specified for parameter ‘appendBinaryPQExpBuffer’
 extern void appendBinaryPQExpBuffer(PQExpBuffer str,
             ^
replication.c:45:58: error: expected ‘=’, ‘,’, ‘;’, ‘asm’ or ‘__attribute__’ before ‘{’ token
 int replication_slot_create(replication_stream_t stream) {
                                                          ^
replication.c:97:56: error: expected ‘=’, ‘,’, ‘;’, ‘asm’ or ‘__attribute__’ before ‘{’ token
 int replication_slot_drop(replication_stream_t stream) {
                                                        ^
replication.c:116:59: error: expected ‘=’, ‘,’, ‘;’, ‘asm’ or ‘__attribute__’ before ‘{’ token
 int replication_stream_check(replication_stream_t stream) {
                                                           ^
replication.c:146:85: error: expected ‘=’, ‘,’, ‘;’, ‘asm’ or ‘__attribute__’ before ‘{’ token
 int replication_stream_start(replication_stream_t stream, const char *error_policy) {
                                                                                     ^
replication.c:172:60: error: expected ‘=’, ‘,’, ‘;’, ‘asm’ or ‘__attribute__’ before ‘{’ token
 int replication_stream_finish(replication_stream_t stream) {
                                                            ^
replication.c:187:58: error: expected ‘=’, ‘,’, ‘;’, ‘asm’ or ‘__attribute__’ before ‘{’ token
 int replication_stream_poll(replication_stream_t stream) {
                                                          ^
replication.c:233:63: error: expected ‘=’, ‘,’, ‘;’, ‘asm’ or ‘__attribute__’ before ‘{’ token
 int replication_stream_keepalive(replication_stream_t stream) {
                                                               ^
replication.c:255:81: error: expected ‘=’, ‘,’, ‘;’, ‘asm’ or ‘__attribute__’ before ‘{’ token
 int parse_keepalive_message(replication_stream_t stream, char *buf, int buflen) {
                                                                                 ^
replication.c:312:80: error: expected ‘=’, ‘,’, ‘;’, ‘asm’ or ‘__attribute__’ before ‘{’ token
 int parse_xlogdata_message(replication_stream_t stream, char *buf, int buflen) {
                                                                                ^
replication.c:346:61: error: expected ‘=’, ‘,’, ‘;’, ‘asm’ or ‘__attribute__’ before ‘{’ token
 int send_checkpoint(replication_stream_t stream, int64 now) {
                                                             ^
replication.c:375:62: error: expected ‘=’, ‘,’, ‘;’, ‘asm’ or ‘__attribute__’ before ‘{’ token
 void repl_error(replication_stream_t stream, char *fmt, ...) {
                                                              ^
replication.c:384:22: error: expected ‘=’, ‘,’, ‘;’, ‘asm’ or ‘__attribute__’ before ‘{’ token
 int64 current_time() {
                      ^
replication.c:396:38: error: expected ‘=’, ‘,’, ‘;’, ‘asm’ or ‘__attribute__’ before ‘{’ token
 void sendint64(int64 i64, char *buf) {
                                      ^
replication.c:405:28: error: expected ‘=’, ‘,’, ‘;’, ‘asm’ or ‘__attribute__’ before ‘{’ token
 int64 recvint64(char *buf) {
                            ^
In file included from replication.c:13:0:
/usr/include/postgresql/internal/pqexpbuffer.h:149:13: error: old-style parameter declarations in prototyped function definition
 extern void printfPQExpBuffer(PQExpBuffer str, const char *fmt,...) pg_attribute_printf(2, 3);
             ^
replication.c:415:1: error: expected ‘{’ at end of input
 }
 ^
make[1]: *** [replication.o] Error 1
make[1]: Leaving directory `/root/bottledwater/bottledwater-pg/client'
make: *** [all] Error 2

[badboyd]

What source are you trying to build ? Can you share your source ?

[abcfy2]

Your pull request #101

git clone https://github.com/confluentinc/bottledwater-pg.git
git fetch origin pull/101/head:pull101
git checkout pull101

But I tried the master branch code to build, still this error.

[badboyd]

I build it successfully.

Please check this error, I see this from your log

Package libsnappy was not found in the pkg-config search path.
Perhaps you should add the directory containing `libsnappy.pc'
to the PKG_CONFIG_PATH environment variable
Package 'libsnappy', required by 'avro-c', not found

[abcfy2]

But I've already installed the libsnappy1 package:

apt-get install libsnappy1
Reading package lists... Done
Building dependency tree       
Reading state information... Done
libsnappy1 is already the newest version.
0 upgraded, 0 newly installed, 0 to remove and 0 not upgraded.

[badboyd]

Please check this, I think this issue is already fixed.
#49

And you can also try my commit with your souce by this:
git cherry-pick f5156d9c27830fd72c58f29a6a6aaa564a5fbff7

[abcfy2]

I know the reason.

Here is my repo:

deb http://apt.postgresql.org/pub/repos/apt/ trusty-pgdg main

But this repo will install libpq-dev 9.5.4-1.pgdg14.04+1. How to install 9.4 version?

[badboyd]

You can do like this

echo "deb http://apt.postgresql.org/pub/repos/apt/ trusty-pgdg main 9.4" > /etc/apt/source.list.d/pgsql.list

apt-get update
apt-get purge libpq5
apt-get install libedit-dev libpq5=9.4* libpq-dev=9.4*
apt-mark hold libpq5
apt-get install postgresql-9.4 postgresql-server-dev-9.4

I tried and it fixed your problem.

[abcfy2]

Finall I build success, but get this error:

[FATAL] Replication stream was unexpectedly terminated: ERROR:  could not load library "/usr/lib/postgresql/9.4/lib/bottledwater.so": /usr/lib/postgresql/9.4/lib/bottledwater.so: undefined symbol: avro_schema_union_append

Ah, it's very hard for me to build from source. I wish to use a deb package for deploying. Waiting for ppa update: https://launchpad.net/~stub/+archive/ubuntu/bottledwater (But this ppa has no postgresql-9.5 extension)

[abcfy2]

@badboyd Seems not helpful. Still this error. I've checkout your code and restarted bottledwater and postgresql.

[INFO] Writing messages to Kafka in JSON format
[INFO] Replication slot "bottledwater" exists, streaming changes from 17/3AB2B1B8.
[INFO] Registering metadata for table moni_alarm (relid 16464)
[INFO] Opening Kafka topic "moni_alarm" for table "moni_alarm"
[INFO] Storing key schema for table 16464
[INFO] Storing row schema for table 16464
[INFO] Registering metadata for table moni_info_center (relid 16629)
[INFO] Opening Kafka topic "moni_info_center" for table "moni_info_center"
[INFO] Storing key schema for table 16629
[INFO] Storing row schema for table 16629
[INFO] Registering metadata for table moni_inbox (relid 16621)
[INFO] Opening Kafka topic "moni_inbox" for table "moni_inbox"
[INFO] Storing key schema for table 16621
[INFO] Storing row schema for table 16621
[INFO] Registering metadata for table moni_equipment (relid 16551)
[INFO] Opening Kafka topic "moni_equipment" for table "moni_equipment"
[INFO] Storing key schema for table 16551
[INFO] Storing row schema for table 16551
[INFO] Registering metadata for table moni_equipment_location_history (relid 16581)
[INFO] Opening Kafka topic "moni_equipment_location_history" for table "moni_equipment_location_history"
[INFO] Storing key schema for table 16581
[INFO] Storing row schema for table 16581
[INFO] Registering metadata for table mart_goods (relid 17242)
[INFO] Opening Kafka topic "mart_goods" for table "mart_goods"
[INFO] Storing key schema for table 17242
[INFO] Storing row schema for table 17242
[INFO] Registering metadata for table comm_login_history (relid 16412)
[INFO] Opening Kafka topic "comm_login_history" for table "comm_login_history"
[INFO] Storing key schema for table 16412
[INFO] Storing row schema for table 16412
[INFO] Registering metadata for table comm_tools_used_records (relid 41941)
[INFO] Opening Kafka topic "comm_tools_used_records" for table "comm_tools_used_records"
[INFO] Storing key schema for table 41941
[INFO] Storing row schema for table 41941
[INFO] Registering metadata for table mart_order_goods (relid 17335)
[INFO] Opening Kafka topic "mart_order_goods" for table "mart_order_goods"
[INFO] Storing key schema for table 17335
[INFO] Storing row schema for table 17335
[INFO] Registering metadata for table mart_order_action (relid 17327)
[INFO] Opening Kafka topic "mart_order_action" for table "mart_order_action"
[INFO] Storing key schema for table 17327
[INFO] Storing row schema for table 17327
[INFO] Registering metadata for table mart_order_info (relid 17346)
[INFO] Opening Kafka topic "mart_order_info" for table "mart_order_info"
[INFO] Storing key schema for table 17346
[INFO] Storing row schema for table 17346
[INFO] Registering metadata for table mart_browse_history (relid 19280)
[INFO] Opening Kafka topic "mart_browse_history" for table "mart_browse_history"
[INFO] Storing key schema for table 19280
[INFO] Storing row schema for table 19280
[INFO] Registering metadata for table mart_goods_goods_category (relid 17295)
[INFO] Opening Kafka topic "mart_goods_goods_category" for table "mart_goods_goods_category"
[INFO] Storing row schema for table 17295
[FATAL] Replication stream was unexpectedly terminated: ERROR:  missing chunk number 0 for toast value 47111 in pg_toast_17242
CONTEXT:  slot "bottledwater", output plugin "bottledwater", in the change callback, associated LSN 17/3AF0A760

[badboyd]

Could you please give me more information about your table schema, this table mart_goods_goods_category ?

[badboyd]

Can you try add a log to see where is the problem from ?
Forgive me but did you install the new extension to Postgresql ?

[abcfy2]

Yes, I've installed the extension. Here is my tar package:

# tar tf bottledwater.tar.xz 
usr/local/include/avro/
usr/local/include/avro/generic.h
usr/local/include/avro/allocation.h
usr/local/include/avro/resolver.h
usr/local/include/avro/basics.h
usr/local/include/avro/data.h
usr/local/include/avro/legacy.h
usr/local/include/avro/refcount.h
usr/local/include/avro/schema.h
usr/local/include/avro/value.h
usr/local/include/avro/io.h
usr/local/include/avro/errors.h
usr/local/include/avro/platform.h
usr/local/include/avro/consumer.h
usr/local/include/avro/msstdint.h
usr/local/include/avro/msinttypes.h
usr/local/lib/libavro.a
usr/local/lib/libavro.so
usr/local/lib/libavro.so.23.0.0
usr/local/lib/pkgconfig/avro-c.pc
usr/local/include/librdkafka/
usr/local/include/librdkafka/rdkafka.h
usr/local/include/librdkafka/rdkafkacpp.h
usr/local/lib/librdkafka++.a
usr/local/lib/librdkafka++.so
usr/local/lib/librdkafka++.so.1
usr/local/lib/librdkafka.a
usr/local/lib/librdkafka.so
usr/local/lib/librdkafka.so.1
usr/lib/postgresql/9.4/lib/bottledwater.so
usr/share/postgresql/9.4/extension/bottledwater--0.1.sql
usr/share/postgresql/9.4/extension/bottledwater.control
usr/local/bin/bottledwater
usr/local/bin/bwtest

Here the schema:

 \d+ mart_goods_goods_category 
                   Table "public.mart_goods_goods_category"
      Column       |  Type  | Modifiers | Storage | Stats target | Description 
-------------------+--------+-----------+---------+--------------+-------------
 goods_id          | bigint | not null  | plain   |              | 
 goods_category_id | bigint |           | plain   |              | 
Foreign-key constraints:
    "FK_3muxf4ctk0cfnvpt0mnn6jyri" FOREIGN KEY (goods_id) REFERENCES mart_goods(id)
    "FK_csywkh613dv9jbywm0alhhju" FOREIGN KEY (goods_category_id) REFERENCES mart_goods_category(id)

But how to get more logs from bottledwater? I can't find any debug or verbose args.

 /usr/local/bin/bottledwater -d "postgres://" -b "127.0.0.1" -f json -u -x -e log
[INFO] Writing messages to Kafka in JSON format
[INFO] Replication slot "bottledwater" exists, streaming changes from 17/3AB2B1B8.
[INFO] Registering metadata for table moni_alarm (relid 16464)
[INFO] Opening Kafka topic "moni_alarm" for table "moni_alarm"
[INFO] Storing key schema for table 16464
[INFO] Storing row schema for table 16464
[INFO] Registering metadata for table moni_info_center (relid 16629)
[INFO] Opening Kafka topic "moni_info_center" for table "moni_info_center"
[INFO] Storing key schema for table 16629
[INFO] Storing row schema for table 16629
[INFO] Registering metadata for table moni_inbox (relid 16621)
[INFO] Opening Kafka topic "moni_inbox" for table "moni_inbox"
[INFO] Storing key schema for table 16621
[INFO] Storing row schema for table 16621
[INFO] Registering metadata for table moni_equipment (relid 16551)
[INFO] Opening Kafka topic "moni_equipment" for table "moni_equipment"
[INFO] Storing key schema for table 16551
[INFO] Storing row schema for table 16551
[INFO] Registering metadata for table moni_equipment_location_history (relid 16581)
[INFO] Opening Kafka topic "moni_equipment_location_history" for table "moni_equipment_location_history"
[INFO] Storing key schema for table 16581
[INFO] Storing row schema for table 16581
[INFO] Registering metadata for table mart_goods (relid 17242)
[INFO] Opening Kafka topic "mart_goods" for table "mart_goods"
[INFO] Storing key schema for table 17242
[INFO] Storing row schema for table 17242
[INFO] Registering metadata for table comm_login_history (relid 16412)
[INFO] Opening Kafka topic "comm_login_history" for table "comm_login_history"
[INFO] Storing key schema for table 16412
[INFO] Storing row schema for table 16412
[INFO] Registering metadata for table comm_tools_used_records (relid 41941)
[INFO] Opening Kafka topic "comm_tools_used_records" for table "comm_tools_used_records"
[INFO] Storing key schema for table 41941
[INFO] Storing row schema for table 41941
[INFO] Registering metadata for table mart_order_goods (relid 17335)
[INFO] Opening Kafka topic "mart_order_goods" for table "mart_order_goods"
[INFO] Storing key schema for table 17335
[INFO] Storing row schema for table 17335
[INFO] Registering metadata for table mart_order_action (relid 17327)
[INFO] Opening Kafka topic "mart_order_action" for table "mart_order_action"
[INFO] Storing key schema for table 17327
[INFO] Storing row schema for table 17327
[INFO] Registering metadata for table mart_order_info (relid 17346)
[INFO] Opening Kafka topic "mart_order_info" for table "mart_order_info"
[INFO] Storing key schema for table 17346
[INFO] Storing row schema for table 17346
[INFO] Registering metadata for table mart_browse_history (relid 19280)
[INFO] Opening Kafka topic "mart_browse_history" for table "mart_browse_history"
[INFO] Storing key schema for table 19280
[INFO] Storing row schema for table 19280
[INFO] Registering metadata for table mart_goods_goods_category (relid 17295)
[INFO] Opening Kafka topic "mart_goods_goods_category" for table "mart_goods_goods_category"
[INFO] Storing row schema for table 17295
[FATAL] Replication stream was unexpectedly terminated: ERROR:  missing chunk number 0 for toast value 47111 in pg_toast_17242
CONTEXT:  slot "bottledwater", output plugin "bottledwater", in the change callback, associated LSN 17/3AF0A760

[abcfy2]

I've recreated the extension, and seemed to be working:

select pg_drop_replication_slot('bottledwater');
drop extension bottledwater;
create extension bottledwater;

# /usr/local/bin/bottledwater -d postgres:// -b 127.0.0.1 -f json -u -x -e log
[INFO] Writing messages to Kafka in JSON format
[INFO] Created replication slot "bottledwater", skipping snapshot and streaming changes from 17/A3535058.
[INFO] Registering metadata for table moni_equipment (relid 16551)
[INFO] Opening Kafka topic "moni_equipment" for table "moni_equipment"
[INFO] Storing key schema for table 16551
[INFO] Storing row schema for table 16551
[INFO] Registering metadata for table moni_equipment_location_history (relid 16581)
[INFO] Opening Kafka topic "moni_equipment_location_history" for table "moni_equipment_location_history"
[INFO] Storing key schema for table 16581
[INFO] Storing row schema for table 16581
[INFO] Registering metadata for table comm_login_history (relid 16412)
[INFO] Opening Kafka topic "comm_login_history" for table "comm_login_history"
[INFO] Storing key schema for table 16412
[INFO] Storing row schema for table 16412
[INFO] Registering metadata for table moni_alarm (relid 16464)
[INFO] Opening Kafka topic "moni_alarm" for table "moni_alarm"
[INFO] Storing key schema for table 16464
[INFO] Storing row schema for table 16464
[INFO] Registering metadata for table moni_info_center (relid 16629)
[INFO] Opening Kafka topic "moni_info_center" for table "moni_info_center"
[INFO] Storing key schema for table 16629
[INFO] Storing row schema for table 16629
[INFO] Registering metadata for table moni_inbox (relid 16621)
[INFO] Opening Kafka topic "moni_inbox" for table "moni_inbox"
[INFO] Storing key schema for table 16621
[INFO] Storing row schema for table 16621

[badboyd]

So the fix works. Nice. 👍🏻
Please report here if you meet another problem.