https://questdb.io logo
Title
h

Hà Hữu

12/08/2022, 2:23 PM
Hi @Jaromir Hamala i'm getting in my kafka connect
org.apache.kafka.connect.errors.ConnectException: Exiting WorkerSinkTask due to unrecoverable exception.
	at org.apache.kafka.connect.runtime.WorkerSinkTask.deliverMessages(WorkerSinkTask.java:611)
	at org.apache.kafka.connect.runtime.WorkerSinkTask.poll(WorkerSinkTask.java:333)
	at org.apache.kafka.connect.runtime.WorkerSinkTask.iteration(WorkerSinkTask.java:234)
	at org.apache.kafka.connect.runtime.WorkerSinkTask.execute(WorkerSinkTask.java:203)
	at org.apache.kafka.connect.runtime.WorkerTask.doRun(WorkerTask.java:188)
	at org.apache.kafka.connect.runtime.WorkerTask.run(WorkerTask.java:243)
	at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
	at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
	at java.base/java.lang.Thread.run(Thread.java:829)
Caused by: io.questdb.cutlass.line.LineSenderException: [104] send error
	at io.questdb.cutlass.line.tcp.PlainTcpLineChannel.send(PlainTcpLineChannel.java:100)
	at io.questdb.cutlass.line.AbstractLineSender.sendAll(AbstractLineSender.java:380)
	at io.questdb.cutlass.line.LineTcpSender.flush(LineTcpSender.java:81)
	at io.questdb.kafka.BufferingSender.flush(BufferingSender.java:181)
	at io.questdb.kafka.QuestDBSinkTask.put(QuestDBSinkTask.java:75)
	at org.apache.kafka.connect.runtime.WorkerSinkTask.deliverMessages(WorkerSinkTask.java:581)
	... 10 more
j

Jaromir Hamala

12/08/2022, 2:23 PM
hello, what’s the error on the server side?
h

Hà Hữu

12/08/2022, 2:24 PM
it's error in my kafka connect
idk what record make it broken 😐
j

Jaromir Hamala

12/08/2022, 2:24 PM
yes, but this indicates there was an error while sending data to a server. this usually means server closed a connection due to a bad data. when this happens then the server will also log an error.
h

Hà Hữu

12/08/2022, 2:25 PM
i've checked log in my questdb but can't get any error on it
j

Jaromir Hamala

12/08/2022, 2:26 PM
[104] send error
according to https://questdb.io/docs/troubleshooting/os-error-codes/ this means “connection reset by peer”. this can also happen if there is a firewall/NAT between a client and a server and there is a long period of inactivity. is that your case?
h

Hà Hữu

12/08/2022, 2:26 PM
i dont think so i've changed to another topic it's working good
just one topic is error (while beefore it's good)
j

Jaromir Hamala

12/08/2022, 2:28 PM
hm, this is hard to tell without additional info/reproducer. the server also logs clients as they are connecting/disconnecting. is there anything interesting?
btw - what questdb version do you use? we recently released a version 6.6.1 - it has massive improvements in commit lag. it now auto adjust the lag. depending on the shape of your data. it could help you with the “visibility delay”
h

Hà Hữu

12/08/2022, 2:29 PM
yes i've updated to 6.6.1 i'll turn off debug to see error...
@Jaromir Hamala so now auto commit is unsupported right?
j

Jaromir Hamala

12/08/2022, 2:32 PM
before there was a fixed (configurable) delay between “when data arrived” and “when data become visible”. now this is calculated dynamically. if you do not have out of order data then this means your data will become visible earlier then in previous versions.
h

Hà Hữu

12/08/2022, 2:32 PM
this is log in questdb while i'm restart task
questdb_1               | 2022-12-08T14:32:18.082870Z I tcp-line-server connected [ip=172.19.0.15, fd=128]
questdb_1               | 2022-12-08T14:32:21.221173Z I i.q.c.l.t.LineTcpMeasurementScheduler idle table going active [tableName=activities]
questdb_1               | 2022-12-08T14:32:21.221194Z I i.q.c.l.t.TableUpdateDetails closing table writer [tableName=activities]
questdb_1               | 2022-12-08T14:32:21.221198Z I i.q.c.l.t.TableUpdateDetails closing table parsers [tableName=activities]
questdb_1               | 2022-12-08T14:32:21.221217Z I i.q.c.l.t.TableUpdateDetails closing table parsers [tableName=activities]
questdb_1               | 2022-12-08T14:32:21.221258Z I i.q.c.p.WriterPool >> [table=`activities`, thread=36]
questdb_1               | 2022-12-08T14:32:21.221316Z I i.q.c.l.t.LineTcpMeasurementScheduler assigned activities to thread 0
questdb_1               | 2022-12-08T14:32:21.221330Z I i.q.c.l.t.TableUpdateDetails network IO thread using table [workerId=0, tableName=activities, nNetworkIoWorkers=1]
questdb_1               | 2022-12-08T14:32:21.229378Z I i.q.c.l.t.LineTcpWriterJob assigned table to writer thread [tableName=activities, threadId=0]
questdb_1               | 2022-12-08T14:32:21.229442Z I i.q.c.TableWriter switched to o3 [table=activities]
questdb_1               | 2022-12-08T14:32:21.441163Z I i.q.c.l.t.TableUpdateDetails network IO thread using table [workerId=1, tableName=activities, nNetworkIoWorkers=2]
questdb_1               | 2022-12-08T14:32:21.441730Z E i.q.c.l.t.LineTcpConnectionContext [128] could not process line data [table=activities, msg=cast error for line protocol tag [columnWriterIndex=2, columnType=STRING, name=target_uid], errno=0]
questdb_1               | 2022-12-08T14:32:21.441755Z E i.q.c.l.t.LineTcpConnectionContext [128] could not parse measurement, NONE at 414, line (may be mangled due to partial parsing): 'activities,target_uid=UID8543607129 category="admin",user_ip="113.190.235.106",user_ip_country="VN",user_agent="Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/108.0.0.0 Safari/537.36",topic="users",action="update",result="succeed",device="desktop",data="{"otp": false, "uid": "UID8543607129"}"29\"}",id=25522577i,user_id=13i,updated_at=1670467308266000t 1670467308266000000'
questdb_1               | 2022-12-08T14:32:21.441769Z I tcp-line-server scheduling disconnect [fd=128, reason=0]
questdb_1               | 2022-12-08T14:32:21.441781Z I tcp-line-server disconnected [ip=172.19.0.15, fd=128, src=queue]
questdb_1               | 2022-12-08T14:32:21.722477Z I i.q.c.TableWriter o3 commit [table=activities, maxUncommittedRows=500000, o3TimestampMin=2022-12-08T05:39:24.613000Z, o3TimestampMax=2022-12-08T08:47:03.692000Z, o3MaxLagUs=1000000, o3EffectiveLagUs=1000000, lagError=21359962000, o3SpreadUs=11259079000, lagThresholdTimestamp=2022-12-08T08:47:02.692000Z, o3LagRowCount=1, srcOooMax=10637, o3RowCount=10638]
questdb_1               | 2022-12-08T14:32:21.723327Z I i.q.c.TableWriter sorted [table=activities, o3RowCount=10638]
questdb_1               | 2022-12-08T14:32:21.723376Z I i.q.c.TableWriter o3 partition task [table=activities, srcOooLo=0, srcOooHi=10636, srcOooMax=10637, o3RowCount=10638, o3LagRowCount=1, srcDataMax=813446, o3TimestampMin=2022-12-08T05:39:24.613000Z, o3Timestamp=2022-12-08T05:39:24.613000Z, o3TimestampMax=2022-12-08T08:47:01.590000Z, partitionTimestamp=2022-12-08T00:00:00.000000Z, partitionIndex=64, partitionSize=824083, maxTimestamp=2022-12-08T11:35:24.575000Z, last=true, append=false, pCount=1, flattenTimestamp=true, memUsed=1039770142]
questdb_1               | 2022-12-08T14:32:21.792562Z I i.q.c.TableWriter closing last partition [table=activities]
questdb_1               | 2022-12-08T14:32:21.793501Z I i.q.c.TableWriter merged partition [table=`activities`, ts=2022-12-08T00:00:00.000000Z, txn=2092927]
questdb_1               | 2022-12-08T14:32:21.793966Z I i.q.c.TableWriter switched partition [path='/root/.questdb/db/activities/2022-12-08.2092927']
questdb_1               | 2022-12-08T14:32:21.829308Z I i.q.c.TableWriter purged [path=/root/.questdb/db/activities/2022-12-08.2092926]
questdb_1               | 2022-12-08T14:32:22.046005Z I i.q.c.l.t.TableUpdateDetails network IO thread released table [workerId=0, tableName=activities, nNetworkIoWorkers=1]
questdb_1               | 2022-12-08T14:32:22.059044Z I i.q.c.l.t.TableUpdateDetails network IO thread released table [workerId=1, tableName=activities, nNetworkIoWorkers=0]
questdb_1               | 2022-12-08T14:32:22.059066Z I i.q.c.l.t.LineTcpMeasurementScheduler active table going idle [tableName=activities]
questdb_1               | 2022-12-08T14:32:22.062074Z I i.q.c.l.t.LineTcpMeasurementScheduler releasing writer, its been idle since 2022-12-08T14:32:21.441000Z[tableName=activities]
questdb_1               | 2022-12-08T14:32:22.062135Z I i.q.c.TableWriter o3 commit [table=activities, o3RowCount=1]
questdb_1               | 2022-12-08T14:32:22.062294Z I i.q.c.TableWriter sorted [table=activities, o3RowCount=1]
questdb_1               | 2022-12-08T14:32:22.062321Z I i.q.c.TableWriter o3 partition task [table=activities, srcOooLo=0, srcOooHi=0, srcOooMax=1, o3RowCount=1, o3LagRowCount=0, srcDataMax=824083, o3TimestampMin=2022-12-08T08:47:03.692000Z, o3Timestamp=2022-12-08T08:47:03.692000Z, o3TimestampMax=2022-12-08T08:47:03.692000Z, partitionTimestamp=2022-12-08T00:00:00.000000Z, partitionIndex=64, partitionSize=824084, maxTimestamp=2022-12-08T11:35:24.575000Z, last=true, append=false, pCount=1, flattenTimestamp=true, memUsed=1039770142]
questdb_1               | 2022-12-08T14:32:22.128076Z I i.q.c.TableWriter closing last partition [table=activities]
questdb_1               | 2022-12-08T14:32:22.129445Z I i.q.c.TableWriter merged partition [table=`activities`, ts=2022-12-08T00:00:00.000000Z, txn=2092928]
questdb_1               | 2022-12-08T14:32:22.130347Z I i.q.c.TableWriter switched partition [path='/root/.questdb/db/activities/2022-12-08.2092928']
questdb_1               | 2022-12-08T14:32:22.167675Z I i.q.c.TableWriter purged [path=/root/.questdb/db/activities/2022-12-08.2092927]
questdb_1               | 2022-12-08T14:32:22.167723Z I i.q.c.p.WriterPool << [table=`activities`, thread=38]
[table=activities, msg=cast error for line protocol tag [columnWriterIndex=2, columnType=STRING, name=target_uid], errno=0]
j

Jaromir Hamala

12/08/2022, 2:37 PM
I see. yes, this can explain the error. this means the table has a STRING column
target_uid
but the connector is sending it as a SYMBOL. this is easy to fix. just remove it from your connector configuration. there’ll be something like
"symbol=target_uid"
h

Hà Hữu

12/08/2022, 2:37 PM
ahh it's my problem
🙏 thanks u so much
j

Jaromir Hamala

12/08/2022, 2:38 PM
btw - in the next version of QuestDB you won’t need to explicitly configure symbols: clients will be able to send both symbols and strings as string. and a server will automatically convert it as needed.
h

Hà Hữu

12/08/2022, 2:39 PM
what about timestamp column?
j

Jaromir Hamala

12/08/2022, 2:41 PM
the timestamp column has to be configured explicitly on a client side. there is no good way to reliably auto-infer it just from incoming data.
h

Hà Hữu

12/08/2022, 3:16 PM
the data of timestamp column is generated while insrerting right? is the anyway to use created_at data for timestamp data
j

Jaromir Hamala

12/08/2022, 4:03 PM
there are 2 modes: 1. either the server is assigned by QuestDB upon receiving data. by using its local wall-clock. this is the default. 2. you can also tell extract timestamp from data. in this case you have to configure it.