Appearance
Output for a Spark Job
This section presents an example of the output that is logged when you run a Spark job that uses ybrelay
and ybload
to load data into a Yellowbrick table.
2019-07-31 11:33:56.394 [ INFO] <main> ABOUT CLIENT:
app.cli_args =
"-h" "eco1-ha.yellowbrick.io"
"-U" "agoade"
"-d" "agoade_demo"
"--read-sources-concurrently" "ALWAYS"
"--delimiter" "0x7C"
"--quote-char" "0x22"
"--escape-char" "0x22"
"--linesep" "LF"
"--num-readers" "4"
"--bad-row-file" "/var/log/ybrelay/logs/20190731113355-local-1564598030512.bad"
"--logfile" "/var/log/ybrelay/logs/20190731113355-local-1564598030512.log"
"--remote-control-logfile" "/var/log/ybrelay/logs/20190731113355-local-1564598030512.control.log"
"-t" "people2"
"--field-names" "playerid,birthyear,birthmonth,birthday,birthcountry,birthstate,birthcity,deathyear,deathmonth,deathday,deathcountry,deathstate,deathcity,namefirst,namelast,namegiven,weight,height,bats,throws,debut,finalgame,retroid,bbrefid"
"--no-trim-white" "--log-level" "WARN"
"--logfile-log-level" "DEBUG"
"/var/lib/ybrelay/work/local-1564598030512.fifos/task.0"
"/var/lib/ybrelay/work/local-1564598030512.fifos/task.1"
"/var/lib/ybrelay/work/local-1564598030512.fifos/task.2"
"/var/lib/ybrelay/work/local-1564598030512.fifos/task.3"
app.name_and_version = "Yellowbrick Data Relay version 3.0.0-13610"
java.home = "/usr/lib/jvm/java11/jre"
java.version = "11"
jvm.memory = "981.50 MB (max=14.22 GB)"
jvm.name_and_version = "OpenJDK 64-Bit Server VM (build 25.212-b04, mixed mode)"
jvm.options = "-Xmx16g, -Xms1g"
jvm.vendor = "Oracle Corporation"
os.name_and_version = "Linux 3.10.0-957.10.1.el7.x86_64 (amd64)"
2019-07-31 11:33:56.395 [ INFO] <main> Logfile written to /var/log/ybrelay/logs/20190731113355-local-1564598030512.log
2019-07-31 11:33:56.437 [DEBUG] <pool-1-thread-1> BgTask "ybload db init" started
2019-07-31 11:33:56.459 [DEBUG] <pool-1-thread-2> BgTask "LFSourceContext" started
2019-07-31 11:33:56.460 [DEBUG] <pool-1-thread-3> BgTask "LFConcurrencyContext" started
2019-07-31 11:33:56.460 [ INFO] <LFSourceContext> Gathering metadata on input files
2019-07-31 11:33:56.460 [DEBUG] <pool-1-thread-4> BgTask "Choosing apx source encoding" started
2019-07-31 11:33:56.461 [DEBUG] <pool-1-thread-5> BgTask "Determining actual source encoding" started
2019-07-31 11:33:56.468 [DEBUG] <pool-1-thread-6> BgTask "TranscodeContext" started
2019-07-31 11:33:56.469 [DEBUG] <pool-1-thread-7> BgTask "Encoding rSep" started
2019-07-31 11:33:56.469 [DEBUG] <pool-1-thread-8> BgTask "Encoding fSep" started
2019-07-31 11:33:56.470 [DEBUG] <pool-1-thread-9> BgTask "LFScanContext" started
2019-07-31 11:33:56.474 [DEBUG] <main> Wait for source information
2019-07-31 11:33:56.474 [DEBUG] <pool-1-thread-10> BgTask "BulkSession init" started
2019-07-31 11:33:56.484 [DEBUG] <LFSourceContext> BgTask "LFSourceContext" exited
2019-07-31 11:33:56.484 [DEBUG] <main> Received source information
2019-07-31 11:33:56.485 [DEBUG] <LFConcurrencyContext> BgTask "LFConcurrencyContext" exited
2019-07-31 11:33:56.488 [DEBUG] <main> Setting noMoreData on sourceInfoQueue
2019-07-31 11:33:56.488 [DEBUG] <main> Wait for concurrency information
2019-07-31 11:33:56.488 [DEBUG] <main> Creating 13 segment permits
2019-07-31 11:33:56.490 [DEBUG] <main> Pre-allocating 13 source buffers (total RAM 650.0MB)
2019-07-31 11:33:56.726 [DEBUG] <ybload db init> getTableSchema(input): "agoade_demo"."public"."people2"
2019-07-31 11:33:56.726 [ INFO] <Choosing apx source encoding> Assuming source encoding matches database server encoding: LATIN9
2019-07-31 11:33:56.726 [DEBUG] <Choosing apx source encoding> BgTask "Choosing apx source encoding" exited
2019-07-31 11:33:56.748 [DEBUG] <ybload db init> getTableSchema(normalized): "agoade_demo"."public"."people2"
2019-07-31 11:33:56.755 [DEBUG] <ybload db init> BgTask "ybload db init" exited
2019-07-31 11:33:56.919 [ INFO] <main> Starting 4 source PreReaders
2019-07-31 11:33:56.922 [DEBUG] <BgTask idle thread> BgTask "PreReader #0" started
2019-07-31 11:33:56.923 [DEBUG] <BgTask idle thread> BgTask "Sequencer #0" started
2019-07-31 11:33:56.923 [DEBUG] <BgTask idle thread> BgTask "PreReader #1" started
2019-07-31 11:33:56.923 [DEBUG] <BgTask idle thread> BgTask "Sequencer #1" started
2019-07-31 11:33:56.923 [DEBUG] <pool-1-thread-11> BgTask "PreReader #2" started
2019-07-31 11:33:56.924 [DEBUG] <pool-1-thread-12> BgTask "Sequencer #2" started
2019-07-31 11:33:56.924 [DEBUG] <pool-1-thread-13> BgTask "PreReader #3" started
2019-07-31 11:33:56.924 [DEBUG] <pool-1-thread-14> BgTask "Sequencer #3" started
2019-07-31 11:33:56.925 [DEBUG] <pool-1-thread-15> BgTask "Wait for PreReaders" started
2019-07-31 11:33:56.926 [DEBUG] <pool-1-thread-16> BgTask "Wait for Sequencers" started
2019-07-31 11:33:58.753 [DEBUG] <PreReader #2> Starting pre-reading of /var/lib/ybrelay/work/local-1564598030512.fifos/task.3
2019-07-31 11:33:58.754 [DEBUG] <PreReader #1> Starting pre-reading of /var/lib/ybrelay/work/local-1564598030512.fifos/task.0
2019-07-31 11:33:58.754 [DEBUG] <PreReader #0> Starting pre-reading of /var/lib/ybrelay/work/local-1564598030512.fifos/task.1
2019-07-31 11:33:58.754 [DEBUG] <PreReader #3> Starting pre-reading of /var/lib/ybrelay/work/local-1564598030512.fifos/task.2
2019-07-31 11:34:00.591 [DEBUG] <Determining actual source encoding> BgTask "Determining actual source encoding" exited
2019-07-31 11:34:00.591 [DEBUG] <TranscodeContext> BgTask "TranscodeContext" exited
2019-07-31 11:34:00.593 [ INFO] <main> Using database locale: C
2019-07-31 11:34:00.594 [DEBUG] <Encoding fSep> BgTask "Encoding fSep" exited
2019-07-31 11:34:00.594 [DEBUG] <Encoding rSep> BgTask "Encoding rSep" exited
2019-07-31 11:34:00.604 [ INFO] <LFScanContext> Configuration (record/field separation):
--format : CSV
Internal-mode : QUOTE
--delimiter : |
--linesep : \n
--quote-char : "
--escape-char : "
--trim-white : false
--skip-blank-lines : true
--on-missing-field : ERROR
--on-extra-field : ERROR
--on-unescaped-embedded-quote : ERROR
Internal scanner : RecordScannerQuote_1_1
2019-07-31 11:34:00.604 [DEBUG] <LFScanContext> BgTask "LFScanContext" exited
2019-07-31 11:34:00.694 [DEBUG] <main> Destination Schema = TABLE: "agoade_demo"."public"."people2"
"playerid" type=VARCHAR(256)
"birthyear" type=BIGINT
"birthmonth" type=BIGINT
"birthday" type=BIGINT
"birthcountry" type=VARCHAR(256)
"birthstate" type=VARCHAR(256)
"birthcity" type=VARCHAR(256)
"deathyear" type=BIGINT
"deathmonth" type=BIGINT
"deathday" type=BIGINT
"deathcountry" type=VARCHAR(256)
"deathstate" type=VARCHAR(256)
"deathcity" type=VARCHAR(256)
"namefirst" type=VARCHAR(256)
"namelast" type=VARCHAR(256)
"namegiven" type=VARCHAR(256)
"weight" type=BIGINT
"height" type=BIGINT
"bats" type=VARCHAR(256)
"throws" type=VARCHAR(256)
"debut" type=VARCHAR(256)
"finalgame" type=VARCHAR(256)
"retroid" type=VARCHAR(256)
"bbrefid" type=VARCHAR(256)
2019-07-31 11:34:00.737 [ INFO] <main> Configuration (pre-parsing):
--on-zero-char : ERROR
--on-string-too-long : ERROR
--on-invalid-char : REMOVE
--no-convert-ascii-control
--no-convert-c-escape
2019-07-31 11:34:00.749 [ INFO] <main> Configuration (session):
tableName : "agoade_demo"."public"."people2"
keepAliveSeconds: 60
maxBadRows : -1
2019-07-31 11:34:01.325 [ INFO] <BulkSession init> Session Key = CWL72YSdnTskgHuL2qzs8urbok9kQmG5TXj3EiZL7kCtds54Bd-kmUHZp2zfpgtn
2019-07-31 11:34:01.331 [DEBUG] <BulkSession init> Sending BulkService.init(#columns=24, columns="playerid", "birthyear", "birthmonth", "birthday", "birthcountry", "birthstate", "birthcity", "deathyear", "deathmonth", "deathday", "deathcountry", "deathstate", "deathcity", "namefirst", "namelast", "namegiven", "weight", "height", "bats", "throws", "debut", "finalgame", "retroid", "bbrefid") for people2
2019-07-31 11:34:01.596 [DEBUG] <BulkSession init> Received BulkService.init() response for people2
2019-07-31 11:34:01.597 [DEBUG] <BulkSession init> BgTask "BulkSession init" exited
2019-07-31 11:34:01.604 [ INFO] <main> Bad rows will be written to /var/log/ybrelay/logs/20190731113355-local-1564598030512.bad
2019-07-31 11:34:01.617 [DEBUG] <main> Running with 1.2GB of memory. Expandable to 14.2GB
2019-07-31 11:34:01.619 [ INFO] <main> Starting import of 4 files
2019-07-31 11:34:02.043 [ INFO] <main> Starting 4 segment readers
2019-07-31 11:34:02.044 [DEBUG] <BgTask idle thread> BgTask "segment reader #1" started
2019-07-31 11:34:02.044 [DEBUG] <BgTask idle thread> BgTask "segment reader #0" started
2019-07-31 11:34:02.044 [DEBUG] <BgTask idle thread> BgTask "segment reader #2" started
2019-07-31 11:34:02.044 [DEBUG] <BgTask idle thread> BgTask "segment reader #3" started
2019-07-31 11:34:02.047 [ INFO] <main> Opening transaction #1 for people2 ...
2019-07-31 11:34:02.943 [ INFO] <main> Opened transaction #1 for people2
2019-07-31 11:34:02.952 [DEBUG] <BgTask idle thread> BgTask "sender 1.00" started
2019-07-31 11:34:02.952 [DEBUG] <BgTask idle thread> BgTask "sender 1.01" started
2019-07-31 11:34:02.953 [DEBUG] <pool-1-thread-17> BgTask "sender 1.02" started
2019-07-31 11:34:02.953 [DEBUG] <pool-1-thread-18> BgTask "sender 1.03" started
2019-07-31 11:34:02.954 [DEBUG] <pool-1-thread-19> BgTask "sender 1.04" started
2019-07-31 11:34:02.954 [DEBUG] <sender 1.02> Worker(/10.34.205.10:31272) -- Opening
2019-07-31 11:34:02.955 [DEBUG] <sender 1.03> Worker(/10.34.205.10:31273) -- Opening
2019-07-31 11:34:02.955 [DEBUG] <sender 1.04> Worker(/10.34.205.10:31274) -- Opening
2019-07-31 11:34:02.955 [DEBUG] <pool-1-thread-20> BgTask "sender 1.05" started
2019-07-31 11:34:02.954 [DEBUG] <sender 1.01> Worker(/10.34.205.10:31271) -- Opening
2019-07-31 11:34:02.955 [DEBUG] <sender 1.00> Worker(/10.34.205.10:31270) -- Opening
2019-07-31 11:34:02.957 [DEBUG] <pool-1-thread-26> BgTask "sender 1.11" started
2019-07-31 11:34:02.957 [DEBUG] <pool-1-thread-25> BgTask "sender 1.10" started
2019-07-31 11:34:02.957 [DEBUG] <pool-1-thread-24> BgTask "sender 1.09" started
2019-07-31 11:34:02.957 [DEBUG] <pool-1-thread-23> BgTask "sender 1.08" started
2019-07-31 11:34:02.957 [DEBUG] <pool-1-thread-22> BgTask "sender 1.07" started
2019-07-31 11:34:02.957 [DEBUG] <sender 1.05> Worker(/10.34.205.10:31275) -- Opening
2019-07-31 11:34:02.955 [DEBUG] <pool-1-thread-21> BgTask "sender 1.06" started
2019-07-31 11:34:02.962 [DEBUG] <sender 1.07> Worker(/10.34.205.10:31277) -- Opening
2019-07-31 11:34:02.961 [DEBUG] <sender 1.08> Worker(/10.34.205.10:31278) -- Opening
2019-07-31 11:34:02.960 [DEBUG] <sender 1.09> Worker(/10.34.205.10:31279) -- Opening
2019-07-31 11:34:02.960 [DEBUG] <pool-1-thread-29> BgTask "sender 1.14" started
2019-07-31 11:34:02.960 [DEBUG] <pool-1-thread-28> BgTask "sender 1.13" started
2019-07-31 11:34:02.960 [DEBUG] <sender 1.10> Worker(/10.34.205.10:31280) -- Opening
2019-07-31 11:34:02.959 [DEBUG] <sender 1.11> Worker(/10.34.205.10:31281) -- Opening
2019-07-31 11:34:02.958 [DEBUG] <pool-1-thread-27> BgTask "sender 1.12" started
2019-07-31 11:34:02.965 [DEBUG] <sender 1.13> Worker(/10.34.205.10:31283) -- Opening
2019-07-31 11:34:02.963 [DEBUG] <sender 1.14> Worker(/10.34.205.10:31284) -- Opening
2019-07-31 11:34:02.963 [DEBUG] <sender 1.06> Worker(/10.34.205.10:31276) -- Opening
2019-07-31 11:34:02.965 [DEBUG] <sender 1.12> Worker(/10.34.205.10:31282) -- Opening
2019-07-31 11:34:02.969 [DEBUG] <sender 1.04> Worker(/10.34.205.10:31274) -- Opened from LocalSocket(/10.34.205.61:49906)
2019-07-31 11:34:02.969 [DEBUG] <sender 1.01> Worker(/10.34.205.10:31271) -- Opened from LocalSocket(/10.34.205.61:36678)
2019-07-31 11:34:02.969 [DEBUG] <sender 1.09> Worker(/10.34.205.10:31279) -- Opened from LocalSocket(/10.34.205.61:46766)
2019-07-31 11:34:02.969 [DEBUG] <sender 1.08> Worker(/10.34.205.10:31278) -- Opened from LocalSocket(/10.34.205.61:46930)
2019-07-31 11:34:02.969 [DEBUG] <sender 1.10> Worker(/10.34.205.10:31280) -- Opened from LocalSocket(/10.34.205.61:36994)
2019-07-31 11:34:02.969 [DEBUG] <sender 1.02> Worker(/10.34.205.10:31272) -- Opened from LocalSocket(/10.34.205.61:49262)
2019-07-31 11:34:02.969 [DEBUG] <sender 1.03> Worker(/10.34.205.10:31273) -- Opened from LocalSocket(/10.34.205.61:37606)
2019-07-31 11:34:02.969 [DEBUG] <sender 1.06> Worker(/10.34.205.10:31276) -- Opened from LocalSocket(/10.34.205.61:59056)
2019-07-31 11:34:02.969 [DEBUG] <sender 1.14> Worker(/10.34.205.10:31284) -- Opened from LocalSocket(/10.34.205.61:33288)
2019-07-31 11:34:02.969 [DEBUG] <sender 1.12> Worker(/10.34.205.10:31282) -- Opened from LocalSocket(/10.34.205.61:37322)
2019-07-31 11:34:02.969 [DEBUG] <sender 1.05> Worker(/10.34.205.10:31275) -- Opened from LocalSocket(/10.34.205.61:35468)
2019-07-31 11:34:02.969 [DEBUG] <sender 1.00> Worker(/10.34.205.10:31270) -- Opened from LocalSocket(/10.34.205.61:44866)
2019-07-31 11:34:02.969 [DEBUG] <sender 1.11> Worker(/10.34.205.10:31281) -- Opened from LocalSocket(/10.34.205.61:60542)
2019-07-31 11:34:02.969 [DEBUG] <sender 1.07> Worker(/10.34.205.10:31277) -- Opened from LocalSocket(/10.34.205.61:58296)
2019-07-31 11:34:02.969 [DEBUG] <sender 1.13> Worker(/10.34.205.10:31283) -- Opened from LocalSocket(/10.34.205.61:54852)
2019-07-31 11:34:02.972 [DEBUG] <sender 1.03> Worker(/10.34.205.10:31273) -- Sent HELLO
2019-07-31 11:34:02.972 [DEBUG] <sender 1.09> Worker(/10.34.205.10:31279) -- Sent HELLO
2019-07-31 11:34:02.972 [DEBUG] <sender 1.00> Worker(/10.34.205.10:31270) -- Sent HELLO
2019-07-31 11:34:02.972 [DEBUG] <sender 1.12> Worker(/10.34.205.10:31282) -- Sent HELLO
2019-07-31 11:34:02.972 [DEBUG] <sender 1.07> Worker(/10.34.205.10:31277) -- Sent HELLO
2019-07-31 11:34:02.972 [DEBUG] <sender 1.06> Worker(/10.34.205.10:31276) -- Sent HELLO
2019-07-31 11:34:02.972 [DEBUG] <sender 1.01> Worker(/10.34.205.10:31271) -- Sent HELLO
2019-07-31 11:34:02.972 [DEBUG] <sender 1.11> Worker(/10.34.205.10:31281) -- Sent HELLO
2019-07-31 11:34:02.972 [DEBUG] <sender 1.02> Worker(/10.34.205.10:31272) -- Sent HELLO
2019-07-31 11:34:02.972 [DEBUG] <sender 1.04> Worker(/10.34.205.10:31274) -- Sent HELLO
2019-07-31 11:34:02.972 [DEBUG] <sender 1.14> Worker(/10.34.205.10:31284) -- Sent HELLO
2019-07-31 11:34:02.972 [DEBUG] <sender 1.13> Worker(/10.34.205.10:31283) -- Sent HELLO
2019-07-31 11:34:02.972 [DEBUG] <sender 1.05> Worker(/10.34.205.10:31275) -- Sent HELLO
2019-07-31 11:34:02.972 [DEBUG] <sender 1.08> Worker(/10.34.205.10:31278) -- Sent HELLO
2019-07-31 11:34:02.972 [DEBUG] <sender 1.10> Worker(/10.34.205.10:31280) -- Sent HELLO
2019-07-31 11:34:03.896 [ INFO] <PreReader #3> Skipping empty source '/var/lib/ybrelay/work/local-1564598030512.fifos/task.2'
2019-07-31 11:34:03.896 [ INFO] <PreReader #0> Skipping empty source '/var/lib/ybrelay/work/local-1564598030512.fifos/task.1'
2019-07-31 11:34:03.902 [DEBUG] <PreReader #3> Read 0 segments for source#2
2019-07-31 11:34:03.903 [DEBUG] <PreReader #3> Marking source#2 as 'completed'
2019-07-31 11:34:03.903 [DEBUG] <PreReader #0> Read 0 segments for source#1
2019-07-31 11:34:03.903 [DEBUG] <PreReader #3> Setting noMoreData on sequencingQueue #3
2019-07-31 11:34:03.903 [DEBUG] <PreReader #0> Marking source#1 as 'completed'
2019-07-31 11:34:03.903 [DEBUG] <PreReader #3> BgTask "PreReader #3" exited
2019-07-31 11:34:04.222 [DEBUG] <Sequencer #3> BgTask "Sequencer #3" exited
2019-07-31 11:34:04.222 [DEBUG] <PreReader #0> Setting noMoreData on sequencingQueue #0
2019-07-31 11:34:04.223 [DEBUG] <PreReader #0> BgTask "PreReader #0" exited
2019-07-31 11:34:04.223 [DEBUG] <Sequencer #0> BgTask "Sequencer #0" exited
2019-07-31 11:34:04.236 [DEBUG] <PreReader #2> Read 1 segments for source#3
2019-07-31 11:34:04.236 [DEBUG] <PreReader #1> Read 1 segments for source#0
2019-07-31 11:34:04.237 [DEBUG] <segment reader #1> Segment0.0: starting 2 bundle lanes
2019-07-31 11:34:04.237 [DEBUG] <PreReader #1> Setting noMoreData on sequencingQueue #1
2019-07-31 11:34:04.237 [DEBUG] <segment reader #0> Segment3.0: starting 2 bundle lanes
2019-07-31 11:34:04.237 [DEBUG] <PreReader #2> Setting noMoreData on sequencingQueue #2
2019-07-31 11:34:04.237 [DEBUG] <PreReader #1> BgTask "PreReader #1" exited
2019-07-31 11:34:04.238 [DEBUG] <PreReader #2> BgTask "PreReader #2" exited
2019-07-31 11:34:04.238 [DEBUG] <Wait for PreReaders> Last PreReader finished. Calling postReadQueue.setNoMoreData()
2019-07-31 11:34:04.238 [DEBUG] <Wait for PreReaders> Setting noMoreData on postReadQueue
2019-07-31 11:34:04.239 [DEBUG] <Wait for PreReaders> BgTask "Wait for PreReaders" exited
2019-07-31 11:34:04.239 [DEBUG] <BgTask idle thread> BgTask "segment parser #1.0" started
2019-07-31 11:34:04.239 [DEBUG] <segment reader #2> BgTask "segment reader #2" exited
2019-07-31 11:34:04.239 [DEBUG] <BgTask idle thread> BgTask "segment parser #1.1" started
2019-07-31 11:34:04.239 [DEBUG] <BgTask idle thread> BgTask "segment parser #0.1" started
2019-07-31 11:34:04.239 [DEBUG] <segment reader #3> BgTask "segment reader #3" exited
2019-07-31 11:34:04.239 [DEBUG] <BgTask idle thread> BgTask "segment parser #0.0" started
2019-07-31 11:34:04.311 [DEBUG] <segment reader #0> Segment3.0: finalizing audit w/ eofChannelPos=477866
2019-07-31 11:34:04.311 [DEBUG] <segment reader #0> Setting noMoreData on slurpedBundleQueue #0
2019-07-31 11:34:04.376 [DEBUG] <segment parser #0.1> BgTask "segment parser #0.1" exited
2019-07-31 11:34:04.391 [DEBUG] <segment parser #0.0> BgTask "segment parser #0.0" exited
2019-07-31 11:34:04.391 [DEBUG] <segment reader #0> Segment3.0: all bundle lanes exited
2019-07-31 11:34:04.391 [DEBUG] <segment reader #0> Segment3.0: mustAdoptNext=null; curFailed=false
2019-07-31 11:34:04.391 [DEBUG] <segment reader #0> BgTask "segment reader #0" exited
2019-07-31 11:34:04.391 [DEBUG] <Sequencer #2> Segment3.0: sequenced. Submitting to finalizer...
2019-07-31 11:34:04.392 [DEBUG] <Sequencer #2> BgTask "Sequencer #2" exited
2019-07-31 11:34:04.398 [DEBUG] <sender 1.09> Marking source#3 as 'completed'
2019-07-31 11:34:04.435 [DEBUG] <segment reader #1> Segment0.0: finalizing audit w/ eofChannelPos=2097199
2019-07-31 11:34:04.435 [DEBUG] <segment reader #1> Setting noMoreData on slurpedBundleQueue #1
2019-07-31 11:34:04.451 [DEBUG] <segment parser #1.0> BgTask "segment parser #1.0" exited
2019-07-31 11:34:04.475 [DEBUG] <segment parser #1.1> BgTask "segment parser #1.1" exited
2019-07-31 11:34:04.475 [DEBUG] <segment reader #1> Segment0.0: all bundle lanes exited
2019-07-31 11:34:04.476 [DEBUG] <segment reader #1> Segment0.0: mustAdoptNext=null; curFailed=false
2019-07-31 11:34:04.476 [DEBUG] <Sequencer #1> Segment0.0: sequenced. Submitting to finalizer...
2019-07-31 11:34:04.476 [DEBUG] <segment reader #1> BgTask "segment reader #1" exited
2019-07-31 11:34:04.476 [DEBUG] <Sequencer #1> BgTask "Sequencer #1" exited
2019-07-31 11:34:04.476 [DEBUG] <Wait for Sequencers> Last Sequencer finished. Calling preFinalizeQueue.setNoMoreData()
2019-07-31 11:34:04.477 [DEBUG] <Wait for Sequencers> Setting noMoreData on preFinalizeQueue
2019-07-31 11:34:04.477 [DEBUG] <Wait for Sequencers> BgTask "Wait for Sequencers" exited
2019-07-31 11:34:04.477 [ INFO] <main> Flushing last 15981 rows (of 19617 total) for transaction 1
2019-07-31 11:34:04.477 [DEBUG] <main> Setting noMoreData on preSendQueue
2019-07-31 11:34:04.479 [DEBUG] <sender 1.12> Marking source#0 as 'completed'
2019-07-31 11:34:04.480 [DEBUG] <sender 1.12> Validating overall success before closing worker sockets
2019-07-31 11:34:04.481 [DEBUG] <sender 1.12> Declaring success (maybe partial) because we sent some rows
2019-07-31 11:34:04.484 [DEBUG] <sender 1.06> Worker(/10.34.205.10:31276) -- Sent EOF after 3 buffers, 8979 rows, and 0 idle msgs
2019-07-31 11:34:04.484 [DEBUG] <sender 1.03> Worker(/10.34.205.10:31273) -- Sent EOF after 1 buffers, 2990 rows, and 0 idle msgs
2019-07-31 11:34:04.484 [DEBUG] <sender 1.13> Worker(/10.34.205.10:31283) -- Sent EOF after 0 buffers, 0 rows, and 0 idle msgs
2019-07-31 11:34:04.484 [DEBUG] <sender 1.04> Worker(/10.34.205.10:31274) -- Sent EOF after 0 buffers, 0 rows, and 0 idle msgs
2019-07-31 11:34:04.485 [DEBUG] <sender 1.04> Worker(/10.34.205.10:31274) -- Flushing and Closing
2019-07-31 11:34:04.484 [DEBUG] <sender 1.05> Worker(/10.34.205.10:31275) -- Sent EOF after 0 buffers, 0 rows, and 0 idle msgs
2019-07-31 11:34:04.484 [DEBUG] <sender 1.10> Worker(/10.34.205.10:31280) -- Sent EOF after 0 buffers, 0 rows, and 0 idle msgs
2019-07-31 11:34:04.484 [DEBUG] <sender 1.08> Worker(/10.34.205.10:31278) -- Sent EOF after 0 buffers, 0 rows, and 0 idle msgs
2019-07-31 11:34:04.485 [DEBUG] <sender 1.08> Worker(/10.34.205.10:31278) -- Flushing and Closing
2019-07-31 11:34:04.484 [DEBUG] <sender 1.09> Worker(/10.34.205.10:31279) -- Sent EOF after 2 buffers, 3636 rows, and 0 idle msgs
2019-07-31 11:34:04.484 [DEBUG] <sender 1.14> Worker(/10.34.205.10:31284) -- Sent EOF after 0 buffers, 0 rows, and 0 idle msgs
2019-07-31 11:34:04.484 [DEBUG] <sender 1.01> Worker(/10.34.205.10:31271) -- Sent EOF after 1 buffers, 1201 rows, and 0 idle msgs
2019-07-31 11:34:04.486 [DEBUG] <sender 1.01> Worker(/10.34.205.10:31271) -- Flushing and Closing
2019-07-31 11:34:04.484 [DEBUG] <sender 1.07> Worker(/10.34.205.10:31277) -- Sent EOF after 0 buffers, 0 rows, and 0 idle msgs
2019-07-31 11:34:04.484 [DEBUG] <sender 1.12> Worker(/10.34.205.10:31282) -- Sent EOF after 1 buffers, 2811 rows, and 0 idle msgs
2019-07-31 11:34:04.484 [DEBUG] <sender 1.11> Worker(/10.34.205.10:31281) -- Sent EOF after 0 buffers, 0 rows, and 0 idle msgs
2019-07-31 11:34:04.484 [DEBUG] <sender 1.02> Worker(/10.34.205.10:31272) -- Sent EOF after 0 buffers, 0 rows, and 0 idle msgs
2019-07-31 11:34:04.486 [DEBUG] <sender 1.02> Worker(/10.34.205.10:31272) -- Flushing and Closing
2019-07-31 11:34:04.484 [DEBUG] <sender 1.00> Worker(/10.34.205.10:31270) -- Sent EOF after 0 buffers, 0 rows, and 0 idle msgs
2019-07-31 11:34:04.486 [DEBUG] <sender 1.11> Worker(/10.34.205.10:31281) -- Flushing and Closing
2019-07-31 11:34:04.486 [DEBUG] <sender 1.12> Worker(/10.34.205.10:31282) -- Flushing and Closing
2019-07-31 11:34:04.486 [DEBUG] <sender 1.07> Worker(/10.34.205.10:31277) -- Flushing and Closing
2019-07-31 11:34:04.485 [DEBUG] <sender 1.14> Worker(/10.34.205.10:31284) -- Flushing and Closing
2019-07-31 11:34:04.485 [DEBUG] <sender 1.09> Worker(/10.34.205.10:31279) -- Flushing and Closing
2019-07-31 11:34:04.485 [DEBUG] <sender 1.10> Worker(/10.34.205.10:31280) -- Flushing and Closing
2019-07-31 11:34:04.485 [DEBUG] <sender 1.05> Worker(/10.34.205.10:31275) -- Flushing and Closing
2019-07-31 11:34:04.484 [DEBUG] <sender 1.13> Worker(/10.34.205.10:31283) -- Flushing and Closing
2019-07-31 11:34:04.484 [DEBUG] <sender 1.03> Worker(/10.34.205.10:31273) -- Flushing and Closing
2019-07-31 11:34:04.484 [DEBUG] <sender 1.06> Worker(/10.34.205.10:31276) -- Flushing and Closing
2019-07-31 11:34:04.486 [DEBUG] <sender 1.00> Worker(/10.34.205.10:31270) -- Flushing and Closing
2019-07-31 11:34:04.489 [DEBUG] <sender 1.01> Worker(/10.34.205.10:31271) -- Flushed and Closed
2019-07-31 11:34:04.489 [DEBUG] <sender 1.05> Worker(/10.34.205.10:31275) -- Flushed and Closed
2019-07-31 11:34:04.489 [DEBUG] <sender 1.03> Worker(/10.34.205.10:31273) -- Flushed and Closed
2019-07-31 11:34:04.489 [DEBUG] <sender 1.14> Worker(/10.34.205.10:31284) -- Flushed and Closed
2019-07-31 11:34:04.489 [DEBUG] <sender 1.13> Worker(/10.34.205.10:31283) -- Flushed and Closed
2019-07-31 11:34:04.489 [DEBUG] <sender 1.14> BgTask "sender 1.14" exited
2019-07-31 11:34:04.489 [DEBUG] <sender 1.03> BgTask "sender 1.03" exited
2019-07-31 11:34:04.489 [DEBUG] <sender 1.06> Worker(/10.34.205.10:31276) -- Flushed and Closed
2019-07-31 11:34:04.489 [DEBUG] <sender 1.05> BgTask "sender 1.05" exited
2019-07-31 11:34:04.489 [DEBUG] <sender 1.11> Worker(/10.34.205.10:31281) -- Flushed and Closed
2019-07-31 11:34:04.489 [DEBUG] <sender 1.01> BgTask "sender 1.01" exited
2019-07-31 11:34:04.489 [DEBUG] <sender 1.10> Worker(/10.34.205.10:31280) -- Flushed and Closed
2019-07-31 11:34:04.489 [DEBUG] <sender 1.04> Worker(/10.34.205.10:31274) -- Flushed and Closed
2019-07-31 11:34:04.490 [DEBUG] <sender 1.00> Worker(/10.34.205.10:31270) -- Flushed and Closed
2019-07-31 11:34:04.490 [DEBUG] <sender 1.10> BgTask "sender 1.10" exited
2019-07-31 11:34:04.489 [DEBUG] <sender 1.02> Worker(/10.34.205.10:31272) -- Flushed and Closed
2019-07-31 11:34:04.489 [DEBUG] <sender 1.11> BgTask "sender 1.11" exited
2019-07-31 11:34:04.489 [DEBUG] <sender 1.12> Worker(/10.34.205.10:31282) -- Flushed and Closed
2019-07-31 11:34:04.489 [DEBUG] <sender 1.08> Worker(/10.34.205.10:31278) -- Flushed and Closed
2019-07-31 11:34:04.489 [DEBUG] <sender 1.09> Worker(/10.34.205.10:31279) -- Flushed and Closed
2019-07-31 11:34:04.491 [DEBUG] <sender 1.09> BgTask "sender 1.09" exited
2019-07-31 11:34:04.489 [DEBUG] <sender 1.07> Worker(/10.34.205.10:31277) -- Flushed and Closed
2019-07-31 11:34:04.491 [DEBUG] <sender 1.07> BgTask "sender 1.07" exited
2019-07-31 11:34:04.489 [DEBUG] <sender 1.06> BgTask "sender 1.06" exited
2019-07-31 11:34:04.489 [DEBUG] <sender 1.13> BgTask "sender 1.13" exited
2019-07-31 11:34:04.491 [DEBUG] <sender 1.08> BgTask "sender 1.08" exited
2019-07-31 11:34:04.491 [DEBUG] <sender 1.12> BgTask "sender 1.12" exited
2019-07-31 11:34:04.491 [DEBUG] <sender 1.02> BgTask "sender 1.02" exited
2019-07-31 11:34:04.490 [DEBUG] <sender 1.00> BgTask "sender 1.00" exited
2019-07-31 11:34:04.490 [DEBUG] <sender 1.04> BgTask "sender 1.04" exited
2019-07-31 11:34:04.496 [ INFO] <main> Committing 19617 rows into transaction #1 for people2 ...
2019-07-31 11:34:06.640 [DEBUG] <main> Received BulkService.commitTransaction() response for people2
2019-07-31 11:34:06.641 [ INFO] <main> Committed transaction #1 after a total of 3432647 bytes and 19617 good rows
2019-07-31 11:34:06.641 [DEBUG] <main> SessionNotifier: stopping
2019-07-31 11:34:06.689 [ INFO] <main> READ: 2.46MB(246.8KB/s). ROWS G/B: 19617/0( 1.88K/s). WRITE: 3.27MB(329.0KB/s). TIME E/R: 0:00:10/ --:--:--
2019-07-31 11:34:06.691 [ INFO] <main> SUCCESSFUL BULK LOAD: Loaded 19617 good rows in 0:00:10 (READ: 246.8KB/s WRITE: 329.0KB/s)
2019-07-31 11:34:06.691 [DEBUG] <main> SessionNotifier.close() calling ntsStopAndReport(false)
2019-07-31 11:34:06.697 [DEBUG] <main> Sending BulkService.done(success=true, clientMsg=null) for people2
2019-07-31 11:34:06.705 [DEBUG] <main> Received BulkService.done() response for people2
2019-07-31 11:34:06.709 [DEBUG] <main> All top-level threads have stopped