question

Naraen avatar image
Naraen asked Naraen commented

Why does the DSBulk logs show both 7 errors and 0 errors?

hi, total number of records to be loaded = 5,025,918

We have set log level verbosity =2 for ds bulk logging. We could observe the following,

total | failed | rows/s | p50ms | p99ms | p999ms
5,025,918 | 0 | 4,869 | 1.56 | 4.10 | 40.37

2021-04-12 18:45:23 WARN Operation LOAD_20210412-182809-177296 completed with 7 errors in 17 minutes and 12 seconds.
2021-04-12 18:45:23 DEBUG Operation LOAD_20210412-182809-177296 closing.
2021-04-12 18:45:23 INFO Records: total: 5,025,918, successful: 5,025,918, failed: 0
2021-04-12 18:45:23 INFO Memory usage: used: 428 MB, free: 464 MB, allocated: 893 MB, available: 3,970 MB, total gc count: 151, total gc time: 3,282 ms
2021-04-12 18:45:23 INFO Writes: total: 5,025,918, successful: 5,025,911, failed: 7, in-flight: 0
2021-04-12 18:45:23 INFO Throughput: 4,869 writes/second
2021-04-12 18:45:23 INFO Latencies: mean 1.56, 75p 0.97, 99p 4.10, 999p 40.37 milliseconds
2021-04-12 18:45:25 INFO Final stats:
2021-04-12 18:45:25 INFO Records: total: 5,025,918, successful: 5,025,918, failed: 0
2021-04-12 18:45:25 INFO Memory usage: used: 430 MB, free: 462 MB, allocated: 893 MB, available: 3,970 MB, total gc count: 151, total gc time: 3,282 ms
2021-04-12 18:45:25 INFO Writes: total: 5,025,918, successful: 5,025,911, failed: 7, in-flight: 0
2021-04-12 18:45:25 INFO Throughput: 4,859 writes/second
2021-04-12 18:45:25 INFO Latencies: mean 1.56, 75p 0.97, 99p 4.10, 999p 40.37 milliseconds
2021-04-12 18:45:25 INFO Rejected records can be found in the following file(s): load.bad
2021-04-12 18:45:25 INFO Errors are detailed in the following file(s): load-errors.log
2021-04-12 18:45:25 INFO Last processed positions can be found in positions.txt
2021-04-12 18:45:25 DEBUG Operation LOAD_20210412-182809-177296 closed.

From the above highlighted lines, it says7 errors sometimes and 0 errors sometimes. At last it fails with 7 errors. But count matches exactly ie, total number to be loaded and total loaded as shown in logs.

So is the error shown really an error or if the count matches we can consider the process is successful?

dsbulk
10 |1000
Toggle Comment visibility. Current Visibility: Viewable by all users

Up to 8 attachments (including images) can be used with a maximum of 1.0 MiB each and 10.0 MiB total.

1 Answer

Erick Ramirez avatar image
Erick Ramirez answered Naraen commented

The log output you posted indicates to me that you have more than 1 instance of the dsbulk command running roughly at the same time so the entries are overlapping.

The output also states that some records were rejected so you should check the file load.bad:

2021-04-12 18:45:25 INFO Rejected records can be found in the following file(s): load.bad

You should also check the errors log for details of why the load failed:

2021-04-12 18:45:25 INFO Errors are detailed in the following file(s): load-errors.log

Cheers!

1 comment Share
10 |1000
Toggle Comment visibility. Current Visibility: Viewable by all users

Up to 8 attachments (including images) can be used with a maximum of 1.0 MiB each and 10.0 MiB total.

Naraen avatar image Naraen commented ·

hi @Erick Ramirez

I checked. Only one instance was running at that time.

if i check 

load-errors.log, load.bad

They have some records and warnings reg timeout at LOCAL_QUORUM.
But if i check the total number of records loaded, that exactly matches the original count.
So is it really an error or how should we conclude if it is a success or failure.
0 Likes 0 ·