Skip to content

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