Trying to import data using embulk-input-sqlserver and many of the columns aren't coming over.
embulk -b ./embulk_bundle run config3.yml
2015-10-03 16:43:14.912 -0400: Embulk v0.7.5
2015-10-03 16:43:15.767 -0400 [INFO] (transaction): Loaded plugin embulk-input-sqlserver (0.6.0)
2015-10-03 16:43:15.784 -0400 [INFO] (transaction): Loaded plugin embulk-output-postgresql (0.4.1)
2015-10-03 16:43:16.221 -0400 [INFO] (transaction): Connecting to jdbc:postgresql://localhost:5432/relevant_staging options {user=postgres, loglevel=3, tcpKeepAlive=true, loginTimeout=300, socketTimeout=1800}
16:43:16.232 (1) PostgreSQL 9.4 JDBC4.1 (build 1200)
16:43:16.236 (1) Trying to establish a protocol version 3 connection to localhost:5432
16:43:16.240 (1) Receive Buffer Size is 408300
16:43:16.240 (1) Send Buffer Size is 146988
16:43:16.241 (1) FE=> StartupPacket(user=postgres, database=relevant_staging, client_encoding=UTF8, DateStyle=ISO, TimeZone=America/New_York, extra_float_digits=2)
16:43:16.242 (1) <=BE AuthenticationReqMD5(salt=6cca4dcc)
16:43:16.243 (1) FE=> Password(md5digest=md5111ed7aaee2a0ca96d689d2224abeac2)
16:43:16.328 (1) <=BE AuthenticationOk
16:43:16.331 (1) <=BE ParameterStatus(application_name = )
16:43:16.332 (1) <=BE ParameterStatus(client_encoding = UTF8)
16:43:16.332 (1) <=BE ParameterStatus(DateStyle = ISO, MDY)
16:43:16.332 (1) <=BE ParameterStatus(integer_datetimes = on)
16:43:16.332 (1) <=BE ParameterStatus(IntervalStyle = postgres)
16:43:16.332 (1) <=BE ParameterStatus(is_superuser = on)
16:43:16.332 (1) <=BE ParameterStatus(server_encoding = UTF8)
16:43:16.332 (1) <=BE ParameterStatus(server_version = 9.1.14)
16:43:16.332 (1) <=BE ParameterStatus(session_authorization = postgres)
16:43:16.332 (1) <=BE ParameterStatus(standard_conforming_strings = on)
16:43:16.332 (1) <=BE ParameterStatus(TimeZone = America/New_York)
16:43:16.332 (1) <=BE BackendKeyData(pid=62855,ckey=1244144535)
16:43:16.332 (1) <=BE ReadyForQuery(I)
16:43:16.334 (1) simple execute, handler=org.postgresql.core.SetupQueryRunner$SimpleResultHandler@2b8e497f, maxRows=0, fetchSize=0, flags=23
16:43:16.334 (1) FE=> Parse(stmt=null,query="SET extra_float_digits = 3",oids={})
16:43:16.334 (1) FE=> Bind(stmt=null,portal=null)
16:43:16.334 (1) FE=> Execute(portal=null,limit=1)
16:43:16.334 (1) FE=> Sync
16:43:16.335 (1) <=BE ParseComplete [null]
16:43:16.335 (1) <=BE BindComplete [null]
16:43:16.335 (1) <=BE CommandStatus(SET)
16:43:16.335 (1) <=BE ReadyForQuery(I)
16:43:16.336 (1) compatible = 90400
16:43:16.336 (1) loglevel = 3
16:43:16.336 (1) prepare threshold = 5
16:43:16.337 (1) types using binary send = TIMESTAMPTZ,UUID,INT2_ARRAY,INT4_ARRAY,BYTEA,TEXT_ARRAY,TIMETZ,INT8,INT2,INT4,VARCHAR_ARRAY,INT8_ARRAY,POINT,TIMESTAMP,TIME,BOX,FLOAT4,FLOAT8,FLOAT4_ARRAY,FLOAT8_ARRAY
16:43:16.337 (1) types using binary receive = TIMESTAMPTZ,UUID,INT2_ARRAY,INT4_ARRAY,BYTEA,TEXT_ARRAY,TIMETZ,INT8,INT2,INT4,VARCHAR_ARRAY,INT8_ARRAY,POINT,DATE,TIMESTAMP,TIME,BOX,FLOAT4,FLOAT8,FLOAT4_ARRAY,FLOAT8_ARRAY
16:43:16.337 (1) integer date/time = true
2015-10-03 16:43:16.347 -0400 [INFO] (transaction): SQL: SET search_path TO "public"
16:43:16.348 (1) simple execute, handler=org.postgresql.jdbc2.AbstractJdbc2Statement$StatementResultHandler@37c2f0b4, maxRows=0, fetchSize=0, flags=21
16:43:16.348 (1) FE=> Parse(stmt=null,query="SET search_path TO "public"",oids={})
16:43:16.349 (1) FE=> Bind(stmt=null,portal=null)
16:43:16.349 (1) FE=> Describe(portal=null)
16:43:16.349 (1) FE=> Execute(portal=null,limit=1)
16:43:16.349 (1) FE=> Sync
16:43:16.350 (1) <=BE ParseComplete [null]
16:43:16.350 (1) <=BE BindComplete [null]
16:43:16.350 (1) <=BE NoData
16:43:16.350 (1) <=BE CommandStatus(SET)
16:43:16.350 (1) <=BE ReadyForQuery(I)
2015-10-03 16:43:16.351 -0400 [INFO] (transaction): > 0.00 seconds
2015-10-03 16:43:16.351 -0400 [INFO] (transaction): Using insert mode
16:43:16.352 (1) simple execute, handler=org.postgresql.jdbc2.AbstractJdbc2Statement$StatementResultHandler@64dfb31d, maxRows=0, fetchSize=0, flags=1
16:43:16.352 (1) FE=> Parse(stmt=null,query="BEGIN",oids={})
16:43:16.352 (1) FE=> Bind(stmt=null,portal=null)
16:43:16.352 (1) FE=> Execute(portal=null,limit=0)
16:43:16.352 (1) FE=> Parse(stmt=null,query="SELECT NULL AS TABLE_CAT, n.nspname AS TABLE_SCHEM, c.relname AS TABLE_NAME, CASE n.nspname ~ '^pg_' OR n.nspname = 'information_schema' WHEN true THEN CASE WHEN n.nspname = 'pg_catalog' OR n.nspname = 'information_schema' THEN CASE c.relkind WHEN 'r' THEN 'SYSTEM TABLE' WHEN 'v' THEN 'SYSTEM VIEW' WHEN 'i' THEN 'SYSTEM INDEX' ELSE NULL END WHEN n.nspname = 'pg_toast' THEN CASE c.relkind WHEN 'r' THEN 'SYSTEM TOAST TABLE' WHEN 'i' THEN 'SYSTEM TOAST INDEX' ELSE NULL END ELSE CASE c.relkind WHEN 'r' THEN 'TEMPORARY TABLE' WHEN 'i' THEN 'TEMPORARY INDEX' WHEN 'S' THEN 'TEMPORARY SEQUENCE' WHEN 'v' THEN 'TEMPORARY VIEW' ELSE NULL END END WHEN false THEN CASE c.relkind WHEN 'r' THEN 'TABLE' WHEN 'i' THEN 'INDEX' WHEN 'S' THEN 'SEQUENCE' WHEN 'v' THEN 'VIEW' WHEN 'c' THEN 'TYPE' WHEN 'f' THEN 'FOREIGN TABLE' WHEN 'm' THEN 'MATERIALIZED VIEW' ELSE NULL END ELSE NULL END AS TABLE_TYPE, d.description AS REMARKS FROM pg_catalog.pg_namespace n, pg_catalog.pg_class c LEFT JOIN pg_catalog.pg_description d ON (c.oid = d.objoid AND d.objsubid = 0) LEFT JOIN pg_catalog.pg_class dc ON (d.classoid=dc.oid AND dc.relname='pg_class') LEFT JOIN pg_catalog.pg_namespace dn ON (dn.oid=dc.relnamespace AND dn.nspname='pg_catalog') WHERE c.relnamespace = n.oid AND n.nspname LIKE 'public' AND c.relname LIKE 'enc' ORDER BY TABLE_TYPE,TABLE_SCHEM,TABLE_NAME ",oids={})
16:43:16.352 (1) FE=> Bind(stmt=null,portal=null)
16:43:16.352 (1) FE=> Describe(portal=null)
16:43:16.352 (1) FE=> Execute(portal=null,limit=0)
16:43:16.352 (1) FE=> Sync
16:43:16.357 (1) <=BE ParseComplete [null]
16:43:16.358 (1) <=BE BindComplete [null]
16:43:16.358 (1) <=BE CommandStatus(BEGIN)
16:43:16.358 (1) <=BE ParseComplete [null]
16:43:16.358 (1) <=BE BindComplete [null]
16:43:16.358 (1) <=BE RowDescription(5)
16:43:16.358 (1) Field(,<unknown:705>,65534,T)
16:43:16.358 (1) Field(,NAME,64,T)
16:43:16.358 (1) Field(,NAME,64,T)
16:43:16.358 (1) Field(,TEXT,65535,T)
16:43:16.358 (1) Field(,TEXT,65535,T)
16:43:16.359 (1) <=BE DataRow(len=14)
16:43:16.359 (1) <=BE CommandStatus(SELECT 1)
16:43:16.365 (1) <=BE ReadyForQuery(T)
16:43:16.366 (1) simple execute, handler=org.postgresql.jdbc2.AbstractJdbc2Statement$StatementResultHandler@4cd7d5e1, maxRows=0, fetchSize=0, flags=1
16:43:16.366 (1) FE=> Parse(stmt=null,query="SELECT NULL AS TABLE_CAT, n.nspname AS TABLE_SCHEM, ct.relname AS TABLE_NAME, a.attname AS COLUMN_NAME, (i.keys).n AS KEY_SEQ, ci.relname AS PK_NAME FROM pg_catalog.pg_class ct JOIN pg_catalog.pg_attribute a ON (ct.oid = a.attrelid) JOIN pg_catalog.pg_namespace n ON (ct.relnamespace = n.oid) JOIN (SELECT i.indexrelid, i.indrelid, i.indisprimary, information_schema._pg_expandarray(i.indkey) AS keys FROM pg_catalog.pg_index i) i ON (a.attnum = (i.keys).x AND a.attrelid = i.indrelid) JOIN pg_catalog.pg_class ci ON (ci.oid = i.indexrelid) WHERE true AND n.nspname = 'public' AND ct.relname = 'enc' AND i.indisprimary ORDER BY table_name, pk_name, key_seq",oids={})
16:43:16.366 (1) FE=> Bind(stmt=null,portal=null)
16:43:16.366 (1) FE=> Describe(portal=null)
16:43:16.366 (1) FE=> Execute(portal=null,limit=0)
16:43:16.366 (1) FE=> Sync
16:43:16.370 (1) <=BE ParseComplete [null]
16:43:16.370 (1) <=BE BindComplete [null]
16:43:16.370 (1) <=BE RowDescription(6)
16:43:16.370 (1) Field(,<unknown:705>,65534,T)
16:43:16.370 (1) Field(,NAME,64,T)
16:43:16.370 (1) Field(,NAME,64,T)
16:43:16.370 (1) Field(,NAME,64,T)
16:43:16.370 (1) Field(,INT4,4,T)
16:43:16.371 (1) Field(,NAME,64,T)
16:43:16.371 (1) <=BE CommandStatus(SELECT 0)
16:43:16.371 (1) <=BE ReadyForQuery(T)
16:43:16.372 (1) simple execute, handler=org.postgresql.jdbc2.AbstractJdbc2Statement$StatementResultHandler@3686389, maxRows=0, fetchSize=0, flags=1
16:43:16.372 (1) FE=> Parse(stmt=null,query="SELECT * FROM (SELECT n.nspname,c.relname,a.attname,a.atttypid,a.attnotnull OR (t.typtype = 'd' AND t.typnotnull) AS attnotnull,a.atttypmod,a.attlen,row_number() OVER (PARTITION BY a.attrelid ORDER BY a.attnum) AS attnum, pg_catalog.pg_get_expr(def.adbin, def.adrelid) AS adsrc,dsc.description,t.typbasetype,t.typtype FROM pg_catalog.pg_namespace n JOIN pg_catalog.pg_class c ON (c.relnamespace = n.oid) JOIN pg_catalog.pg_attribute a ON (a.attrelid=c.oid) JOIN pg_catalog.pg_type t ON (a.atttypid = t.oid) LEFT JOIN pg_catalog.pg_attrdef def ON (a.attrelid=def.adrelid AND a.attnum = def.adnum) LEFT JOIN pg_catalog.pg_description dsc ON (c.oid=dsc.objoid AND a.attnum = dsc.objsubid) LEFT JOIN pg_catalog.pg_class dc ON (dc.oid=dsc.classoid AND dc.relname='pg_class') LEFT JOIN pg_catalog.pg_namespace dn ON (dc.relnamespace=dn.oid AND dn.nspname='pg_catalog') WHERE a.attnum > 0 AND NOT a.attisdropped AND n.nspname LIKE 'public' AND c.relname LIKE 'enc') c WHERE true ORDER BY nspname,c.relname,attnum ",oids={})
16:43:16.372 (1) FE=> Bind(stmt=null,portal=null)
16:43:16.373 (1) FE=> Describe(portal=null)
16:43:16.373 (1) FE=> Execute(portal=null,limit=0)
16:43:16.373 (1) FE=> Sync
16:43:16.378 (1) <=BE ParseComplete [null]
16:43:16.378 (1) <=BE BindComplete [null]
16:43:16.378 (1) <=BE RowDescription(12)
16:43:16.378 (1) Field(,NAME,64,T)
16:43:16.378 (1) Field(,NAME,64,T)
16:43:16.378 (1) Field(,NAME,64,T)
16:43:16.378 (1) Field(,OID,4,T)
16:43:16.378 (1) Field(,BOOL,1,T)
16:43:16.378 (1) Field(,INT4,4,T)
16:43:16.378 (1) Field(,INT2,2,T)
16:43:16.378 (1) Field(,INT8,8,T)
16:43:16.378 (1) Field(,TEXT,65535,T)
16:43:16.378 (1) Field(,TEXT,65535,T)
16:43:16.378 (1) Field(,OID,4,T)
16:43:16.378 (1) Field(,CHAR,1,T)
16:43:16.378 (1) <=BE DataRow(len=29)
16:43:16.378 (1) <=BE DataRow(len=27)
16:43:16.379 (1) <=BE DataRow(len=26)
16:43:16.379 (1) <=BE DataRow(len=24)
16:43:16.379 (1) <=BE DataRow(len=27)
16:43:16.379 (1) <=BE DataRow(len=29)
16:43:16.379 (1) <=BE DataRow(len=27)
16:43:16.379 (1) <=BE DataRow(len=25)
16:43:16.379 (1) <=BE DataRow(len=32)
16:43:16.379 (1) <=BE DataRow(len=30)
16:43:16.379 (1) <=BE DataRow(len=30)
16:43:16.379 (1) <=BE DataRow(len=29)
16:43:16.379 (1) <=BE CommandStatus(SELECT 12)
16:43:16.379 (1) <=BE ReadyForQuery(T)
2015-10-03 16:43:16.383 -0400 [INFO] (transaction): SQL: DROP TABLE IF EXISTS "enc_56103de32bfcfc80_bl_tmp000"
16:43:16.384 (1) simple execute, handler=org.postgresql.jdbc2.AbstractJdbc2Statement$StatementResultHandler@78318ac2, maxRows=0, fetchSize=0, flags=5
16:43:16.384 (1) FE=> Parse(stmt=null,query="DROP TABLE IF EXISTS "enc_56103de32bfcfc80_bl_tmp000"",oids={})
16:43:16.384 (1) FE=> Bind(stmt=null,portal=null)
16:43:16.384 (1) FE=> Describe(portal=null)
16:43:16.384 (1) FE=> Execute(portal=null,limit=1)
16:43:16.384 (1) FE=> Sync
16:43:16.384 (1) <=BE ParseComplete [null]
16:43:16.384 (1) <=BE BindComplete [null]
16:43:16.384 (1) <=BE NoData
16:43:16.386 (1) <=BE NoticeResponse(NOTICE: table "enc_56103de32bfcfc80_bl_tmp000" does not exist, skipping
Location: File: tablecmds.c, Routine: DropErrorMsgNonExistent, Line: 667
Server SQLState: 00000)
SQLWarning:
16:43:16.387 (1) <=BE CommandStatus(DROP TABLE)
16:43:16.387 (1) <=BE ReadyForQuery(T)
2015-10-03 16:43:16.387 -0400 [INFO] (transaction): > 0.00 seconds
16:43:16.387 (1) simple execute, handler=org.postgresql.jdbc2.AbstractJdbc2Connection$TransactionCommandHandler@37fef327, maxRows=0, fetchSize=0, flags=22
16:43:16.387 (1) FE=> Parse(stmt=S_1,query="COMMIT",oids={})
16:43:16.387 (1) FE=> Bind(stmt=S_1,portal=null)
16:43:16.387 (1) FE=> Execute(portal=null,limit=1)
16:43:16.387 (1) FE=> Sync
16:43:16.388 (1) <=BE ParseComplete [S_1]
16:43:16.388 (1) <=BE BindComplete [null]
16:43:16.388 (1) <=BE CommandStatus(COMMIT)
16:43:16.388 (1) <=BE ReadyForQuery(I)
2015-10-03 16:43:16.396 -0400 [INFO] (transaction): SQL: CREATE TABLE IF NOT EXISTS "enc_56103de32bfcfc80_bl_tmp000" ("encounterid" INT4, "patientid" INT4, "doctorid" INT4, "date" TIMESTAMP, "time" VARCHAR(1000), "starttime" TIMESTAMP, "endtime" TIMESTAMP, "reason" TEXT, "visittype" VARCHAR(1000), "roomno" VARCHAR(1000), "status" VARCHAR(1000), "deleteflag" INT4)
16:43:16.396 (1) simple execute, handler=org.postgresql.jdbc2.AbstractJdbc2Statement$StatementResultHandler@1426370c, maxRows=0, fetchSize=0, flags=5
16:43:16.396 (1) FE=> Parse(stmt=null,query="BEGIN",oids={})
16:43:16.396 (1) FE=> Bind(stmt=null,portal=null)
16:43:16.396 (1) FE=> Execute(portal=null,limit=0)
16:43:16.396 (1) FE=> Parse(stmt=null,query="CREATE TABLE IF NOT EXISTS "enc_56103de32bfcfc80_bl_tmp000" ("encounterid" INT4, "patientid" INT4, "doctorid" INT4, "date" TIMESTAMP, "time" VARCHAR(1000), "starttime" TIMESTAMP, "endtime" TIMESTAMP, "reason" TEXT, "visittype" VARCHAR(1000), "roomno" VARCHAR(1000), "status" VARCHAR(1000), "deleteflag" INT4)",oids={})
16:43:16.396 (1) FE=> Bind(stmt=null,portal=null)
16:43:16.396 (1) FE=> Describe(portal=null)
16:43:16.396 (1) FE=> Execute(portal=null,limit=1)
16:43:16.396 (1) FE=> Sync
16:43:16.401 (1) <=BE ParseComplete [null]
16:43:16.401 (1) <=BE BindComplete [null]
16:43:16.401 (1) <=BE CommandStatus(BEGIN)
16:43:16.401 (1) <=BE ParseComplete [null]
16:43:16.401 (1) <=BE BindComplete [null]
16:43:16.401 (1) <=BE NoData
16:43:16.401 (1) <=BE CommandStatus(CREATE TABLE)
16:43:16.401 (1) <=BE ReadyForQuery(T)
2015-10-03 16:43:16.402 -0400 [INFO] (transaction): > 0.01 seconds
16:43:16.402 (1) simple execute, handler=org.postgresql.jdbc2.AbstractJdbc2Connection$TransactionCommandHandler@9f9146d, maxRows=0, fetchSize=0, flags=22
16:43:16.402 (1) FE=> Bind(stmt=S_1,portal=null)
16:43:16.402 (1) FE=> Execute(portal=null,limit=1)
16:43:16.402 (1) FE=> Sync
16:43:16.403 (1) <=BE BindComplete [null]
16:43:16.403 (1) <=BE CommandStatus(COMMIT)
16:43:16.403 (1) <=BE ReadyForQuery(I)
16:43:16.407 (1) FE=> Terminate
2015-10-03 16:43:16.419 -0400 [INFO] (transaction): {done: 0 / 1, running: 0}
2015-10-03 16:43:16.448 -0400 [INFO] (task-0000): Connecting to jdbc:postgresql://localhost:5432/relevant_staging options {user=postgres, loglevel=3, tcpKeepAlive=true, loginTimeout=300, socketTimeout=1800}
16:43:16.452 (2) PostgreSQL 9.4 JDBC4.1 (build 1200)
16:43:16.452 (2) Trying to establish a protocol version 3 connection to localhost:5432
16:43:16.452 (2) Receive Buffer Size is 408300
16:43:16.452 (2) Send Buffer Size is 146988
16:43:16.452 (2) FE=> StartupPacket(user=postgres, database=relevant_staging, client_encoding=UTF8, DateStyle=ISO, TimeZone=America/New_York, extra_float_digits=2)
16:43:16.454 (2) <=BE AuthenticationReqMD5(salt=474be956)
16:43:16.454 (2) FE=> Password(md5digest=md5109c3c2856176c3d1572c927aa09f791)
16:43:16.456 (2) <=BE AuthenticationOk
16:43:16.457 (2) <=BE ParameterStatus(application_name = )
16:43:16.457 (2) <=BE ParameterStatus(client_encoding = UTF8)
16:43:16.457 (2) <=BE ParameterStatus(DateStyle = ISO, MDY)
16:43:16.457 (2) <=BE ParameterStatus(integer_datetimes = on)
16:43:16.457 (2) <=BE ParameterStatus(IntervalStyle = postgres)
16:43:16.457 (2) <=BE ParameterStatus(is_superuser = on)
16:43:16.457 (2) <=BE ParameterStatus(server_encoding = UTF8)
16:43:16.457 (2) <=BE ParameterStatus(server_version = 9.1.14)
16:43:16.457 (2) <=BE ParameterStatus(session_authorization = postgres)
16:43:16.457 (2) <=BE ParameterStatus(standard_conforming_strings = on)
16:43:16.457 (2) <=BE ParameterStatus(TimeZone = America/New_York)
16:43:16.457 (2) <=BE BackendKeyData(pid=62856,ckey=797625222)
16:43:16.457 (2) <=BE ReadyForQuery(I)
16:43:16.457 (2) simple execute, handler=org.postgresql.core.SetupQueryRunner$SimpleResultHandler@798e1c52, maxRows=0, fetchSize=0, flags=23
16:43:16.457 (2) FE=> Parse(stmt=null,query="SET extra_float_digits = 3",oids={})
16:43:16.457 (2) FE=> Bind(stmt=null,portal=null)
16:43:16.457 (2) FE=> Execute(portal=null,limit=1)
16:43:16.457 (2) FE=> Sync
16:43:16.458 (2) <=BE ParseComplete [null]
16:43:16.458 (2) <=BE BindComplete [null]
16:43:16.458 (2) <=BE CommandStatus(SET)
16:43:16.458 (2) <=BE ReadyForQuery(I)
16:43:16.458 (2) compatible = 90400
16:43:16.458 (2) loglevel = 3
16:43:16.458 (2) prepare threshold = 5
16:43:16.459 (2) types using binary send = TIMESTAMPTZ,UUID,INT2_ARRAY,INT4_ARRAY,BYTEA,TEXT_ARRAY,TIMETZ,INT8,INT2,INT4,VARCHAR_ARRAY,INT8_ARRAY,POINT,TIMESTAMP,TIME,BOX,FLOAT4,FLOAT8,FLOAT4_ARRAY,FLOAT8_ARRAY
16:43:16.459 (2) types using binary receive = TIMESTAMPTZ,UUID,INT2_ARRAY,INT4_ARRAY,BYTEA,TEXT_ARRAY,TIMETZ,INT8,INT2,INT4,VARCHAR_ARRAY,INT8_ARRAY,POINT,DATE,TIMESTAMP,TIME,BOX,FLOAT4,FLOAT8,FLOAT4_ARRAY,FLOAT8_ARRAY
16:43:16.459 (2) integer date/time = true
2015-10-03 16:43:16.460 -0400 [INFO] (task-0000): SQL: SET search_path TO "public"
16:43:16.461 (2) simple execute, handler=org.postgresql.jdbc2.AbstractJdbc2Statement$StatementResultHandler@3527bb0b, maxRows=0, fetchSize=0, flags=21
16:43:16.461 (2) FE=> Parse(stmt=null,query="SET search_path TO "public"",oids={})
16:43:16.461 (2) FE=> Bind(stmt=null,portal=null)
16:43:16.461 (2) FE=> Describe(portal=null)
16:43:16.461 (2) FE=> Execute(portal=null,limit=1)
16:43:16.461 (2) FE=> Sync
16:43:16.462 (2) <=BE ParseComplete [null]
16:43:16.462 (2) <=BE BindComplete [null]
16:43:16.462 (2) <=BE NoData
16:43:16.462 (2) <=BE CommandStatus(SET)
16:43:16.462 (2) <=BE ReadyForQuery(I)
2015-10-03 16:43:16.462 -0400 [INFO] (task-0000): > 0.00 seconds
2015-10-03 16:43:16.463 -0400 [INFO] (task-0000): Copy SQL: COPY "enc_56103de32bfcfc80_bl_tmp000" ("date", "time", "reason") FROM STDIN
2015-10-03 16:43:16.465 -0400 [WARN] (task-0000): An output plugin is compiled with old Embulk plugin API. Please update the plugin version using "embulk gem install" command, or contact a developer of the plugin to upgrade the plugin code using "embulk migrate" command: class org.embulk.output.jdbc.AbstractJdbcOutputPlugin$PluginPageOutput
DriverManager.getConnection("jdbc:sqlserver://10.1.120.111\MSSQLSERVER:1433;databaseName=datamart")
trying com.microsoft.sqlserver.jdbc.SQLServerDriver
getConnection returning com.microsoft.sqlserver.jdbc.SQLServerDriver
2015-10-03 16:43:16.607 -0400 [INFO] (task-0000): SQL: SELECT encounterID, patientID, doctorID, date, time, startTime, endTime, reason, VisitType, roomNo, STATUS, deleteFlag FROM "enc" WHERE date > '2015-09-01'
2015-10-03 16:43:16.662 -0400 [INFO] (task-0000): > 0.05 seconds
2015-10-03 16:43:16.768 -0400 [INFO] (task-0000): Fetched 500 rows.
2015-10-03 16:43:16.806 -0400 [INFO] (task-0000): Fetched 1,000 rows.
2015-10-03 16:43:16.856 -0400 [INFO] (task-0000): Fetched 2,000 rows.
2015-10-03 16:43:16.949 -0400 [INFO] (task-0000): Fetched 4,000 rows.
2015-10-03 16:43:17.109 -0400 [INFO] (task-0000): Fetched 8,000 rows.
2015-10-03 16:43:17.492 -0400 [INFO] (task-0000): Fetched 16,000 rows.
2015-10-03 16:43:18.096 -0400 [INFO] (task-0000): Fetched 32,000 rows.
2015-10-03 16:43:19.322 -0400 [INFO] (task-0000): Fetched 64,000 rows.
2015-10-03 16:43:21.828 -0400 [INFO] (task-0000): Fetched 128,000 rows.
2015-10-03 16:43:24.732 -0400 [INFO] (task-0000): Loading 197,225 rows (7,759,125 bytes)
16:43:24.733 (2) FE=> Query(CopyStart)
16:43:24.733 (2) <=BE CopyInResponse
16:43:24.734 (2) FE=> CopyData(65536)
16:43:24.735 (2) FE=> CopyData(65536)
16:43:24.735 (2) FE=> CopyData(65536)
16:43:24.735 (2) FE=> CopyData(65536)
16:43:24.735 (2) FE=> CopyData(65536)
16:43:24.735 (2) FE=> CopyData(65536)
16:43:24.735 (2) FE=> CopyData(65536)
16:43:24.735 (2) FE=> CopyData(65536)
16:43:24.735 (2) FE=> CopyData(65536)
16:43:24.736 (2) FE=> CopyData(65536)
16:43:24.736 (2) FE=> CopyData(65536)
16:43:24.736 (2) FE=> CopyData(65536)
16:43:24.736 (2) FE=> CopyData(65536)
16:43:24.783 (2) FE=> CopyData(65536)
16:43:24.784 (2) FE=> CopyData(65536)
16:43:24.784 (2) FE=> CopyData(65536)
16:43:24.784 (2) FE=> CopyData(65536)
16:43:24.784 (2) FE=> CopyData(65536)
16:43:24.784 (2) FE=> CopyData(65536)
16:43:24.784 (2) FE=> CopyData(65536)
16:43:24.784 (2) FE=> CopyData(65536)
16:43:24.784 (2) FE=> CopyData(65536)
16:43:24.837 (2) FE=> CopyData(65536)
16:43:24.837 (2) FE=> CopyData(65536)
16:43:24.837 (2) FE=> CopyData(65536)
16:43:24.837 (2) FE=> CopyData(65536)
16:43:24.837 (2) FE=> CopyData(65536)
16:43:24.837 (2) FE=> CopyData(65536)
16:43:24.837 (2) FE=> CopyData(65536)
16:43:24.837 (2) FE=> CopyData(65536)
16:43:24.837 (2) FE=> CopyData(65536)
16:43:24.975 (2) FE=> CopyData(65536)
16:43:24.976 (2) FE=> CopyData(65536)
16:43:24.977 (2) FE=> CopyData(65536)
16:43:24.977 (2) FE=> CopyData(65536)
16:43:24.978 (2) FE=> CopyData(65536)
16:43:24.979 (2) FE=> CopyData(65536)
16:43:24.979 (2) FE=> CopyData(65536)
16:43:24.980 (2) FE=> CopyData(65536)
16:43:25.076 (2) FE=> CopyData(65536)
16:43:25.076 (2) FE=> CopyData(65536)
16:43:25.076 (2) FE=> CopyData(65536)
16:43:25.078 (2) FE=> CopyData(65536)
16:43:25.078 (2) FE=> CopyData(65536)
16:43:25.079 (2) FE=> CopyData(65536)
16:43:25.079 (2) FE=> CopyData(65536)
16:43:25.080 (2) FE=> CopyData(65536)
16:43:25.080 (2) FE=> CopyData(65536)
16:43:25.137 (2) FE=> CopyData(65536)
16:43:25.137 (2) FE=> CopyData(65536)
16:43:25.137 (2) FE=> CopyData(65536)
16:43:25.137 (2) FE=> CopyData(65536)
16:43:25.137 (2) FE=> CopyData(65536)
16:43:25.137 (2) FE=> CopyData(65536)
16:43:25.137 (2) FE=> CopyData(65536)
16:43:25.137 (2) FE=> CopyData(65536)
16:43:25.138 (2) FE=> CopyData(65536)
16:43:25.208 (2) FE=> CopyData(65536)
16:43:25.208 (2) FE=> CopyData(65536)
16:43:25.208 (2) FE=> CopyData(65536)
16:43:25.209 (2) FE=> CopyData(65536)
16:43:25.209 (2) FE=> CopyData(65536)
16:43:25.209 (2) FE=> CopyData(65536)
16:43:25.209 (2) FE=> CopyData(65536)
16:43:25.209 (2) FE=> CopyData(65536)
16:43:25.209 (2) FE=> CopyData(65536)
16:43:25.267 (2) FE=> CopyData(65536)
16:43:25.267 (2) FE=> CopyData(65536)
16:43:25.267 (2) FE=> CopyData(65536)
16:43:25.268 (2) FE=> CopyData(65536)
16:43:25.268 (2) FE=> CopyData(65536)
16:43:25.268 (2) FE=> CopyData(65536)
16:43:25.268 (2) FE=> CopyData(65536)
16:43:25.268 (2) FE=> CopyData(65536)
16:43:25.268 (2) FE=> CopyData(65536)
16:43:25.325 (2) FE=> CopyData(65536)
16:43:25.325 (2) FE=> CopyData(65536)
16:43:25.325 (2) FE=> CopyData(65536)
16:43:25.325 (2) FE=> CopyData(65536)
16:43:25.325 (2) FE=> CopyData(65536)
16:43:25.325 (2) FE=> CopyData(65536)
16:43:25.325 (2) FE=> CopyData(65536)
16:43:25.325 (2) FE=> CopyData(65536)
16:43:25.326 (2) FE=> CopyData(65536)
16:43:25.394 (2) FE=> CopyData(65536)
16:43:25.394 (2) FE=> CopyData(65536)
16:43:25.394 (2) FE=> CopyData(65536)
16:43:25.395 (2) FE=> CopyData(65536)
16:43:25.395 (2) FE=> CopyData(65536)
16:43:25.395 (2) FE=> CopyData(65536)
16:43:25.395 (2) FE=> CopyData(65536)
16:43:25.395 (2) FE=> CopyData(65536)
16:43:25.395 (2) FE=> CopyData(65536)
16:43:25.464 (2) FE=> CopyData(65536)
16:43:25.464 (2) FE=> CopyData(65536)
16:43:25.464 (2) FE=> CopyData(65536)
16:43:25.464 (2) FE=> CopyData(65536)
16:43:25.464 (2) FE=> CopyData(65536)
16:43:25.464 (2) FE=> CopyData(65536)
16:43:25.464 (2) FE=> CopyData(65536)
16:43:25.464 (2) FE=> CopyData(65536)
16:43:25.465 (2) FE=> CopyData(65536)
16:43:25.465 (2) FE=> CopyData(65536)
16:43:25.465 (2) FE=> CopyData(65536)
16:43:25.516 (2) FE=> CopyData(65536)
16:43:25.517 (2) FE=> CopyData(65536)
16:43:25.517 (2) FE=> CopyData(65536)
16:43:25.517 (2) FE=> CopyData(65536)
16:43:25.517 (2) FE=> CopyData(65536)
16:43:25.517 (2) FE=> CopyData(65536)
16:43:25.517 (2) FE=> CopyData(65536)
16:43:25.517 (2) FE=> CopyData(65536)
16:43:25.517 (2) FE=> CopyData(65536)
16:43:25.517 (2) FE=> CopyData(65536)
16:43:25.611 (2) FE=> CopyData(65536)
16:43:25.611 (2) FE=> CopyData(65536)
16:43:25.611 (2) FE=> CopyData(65536)
16:43:25.611 (2) FE=> CopyData(65536)
16:43:25.611 (2) FE=> CopyData(25877)
16:43:25.611 (2) FE=> CopyDone
16:43:25.657 (2) <=BE CommandStatus(COPY 197225)
16:43:25.657 (2) <=BE ReadyForQuery(I)
2015-10-03 16:43:25.657 -0400 [INFO] (task-0000): > 0.92 seconds (loaded 197,225 rows in total)
16:43:25.659 (2) FE=> Terminate
2015-10-03 16:43:25.659 -0400 [INFO] (transaction): {done: 1 / 1, running: 0}
2015-10-03 16:43:25.661 -0400 [INFO] (transaction): Connecting to jdbc:postgresql://localhost:5432/relevant_staging options {user=postgres, loglevel=3, tcpKeepAlive=true, loginTimeout=300, socketTimeout=28800}
16:43:25.662 (3) PostgreSQL 9.4 JDBC4.1 (build 1200)
16:43:25.662 (3) Trying to establish a protocol version 3 connection to localhost:5432
16:43:25.662 (3) Receive Buffer Size is 408300
16:43:25.662 (3) Send Buffer Size is 146988
16:43:25.662 (3) FE=> StartupPacket(user=postgres, database=relevant_staging, client_encoding=UTF8, DateStyle=ISO, TimeZone=America/New_York, extra_float_digits=2)
16:43:25.664 (3) <=BE AuthenticationReqMD5(salt=6a8070b4)
16:43:25.664 (3) FE=> Password(md5digest=md50f98714482529c16eccd017ae2cf393b)
16:43:25.666 (3) <=BE AuthenticationOk
16:43:25.666 (3) <=BE ParameterStatus(application_name = )
16:43:25.666 (3) <=BE ParameterStatus(client_encoding = UTF8)
16:43:25.666 (3) <=BE ParameterStatus(DateStyle = ISO, MDY)
16:43:25.666 (3) <=BE ParameterStatus(integer_datetimes = on)
16:43:25.666 (3) <=BE ParameterStatus(IntervalStyle = postgres)
16:43:25.667 (3) <=BE ParameterStatus(is_superuser = on)
16:43:25.667 (3) <=BE ParameterStatus(server_encoding = UTF8)
16:43:25.667 (3) <=BE ParameterStatus(server_version = 9.1.14)
16:43:25.667 (3) <=BE ParameterStatus(session_authorization = postgres)
16:43:25.667 (3) <=BE ParameterStatus(standard_conforming_strings = on)
16:43:25.667 (3) <=BE ParameterStatus(TimeZone = America/New_York)
16:43:25.667 (3) <=BE BackendKeyData(pid=62858,ckey=676230832)
16:43:25.667 (3) <=BE ReadyForQuery(I)
16:43:25.667 (3) simple execute, handler=org.postgresql.core.SetupQueryRunner$SimpleResultHandler@1cb40342, maxRows=0, fetchSize=0, flags=23
16:43:25.667 (3) FE=> Parse(stmt=null,query="SET extra_float_digits = 3",oids={})
16:43:25.667 (3) FE=> Bind(stmt=null,portal=null)
16:43:25.667 (3) FE=> Execute(portal=null,limit=1)
16:43:25.667 (3) FE=> Sync
16:43:25.667 (3) <=BE ParseComplete [null]
16:43:25.667 (3) <=BE BindComplete [null]
16:43:25.667 (3) <=BE CommandStatus(SET)
16:43:25.667 (3) <=BE ReadyForQuery(I)
16:43:25.668 (3) compatible = 90400
16:43:25.668 (3) loglevel = 3
16:43:25.668 (3) prepare threshold = 5
16:43:25.668 (3) types using binary send = TIMESTAMPTZ,UUID,INT2_ARRAY,INT4_ARRAY,BYTEA,TEXT_ARRAY,TIMETZ,INT8,INT2,INT4,VARCHAR_ARRAY,INT8_ARRAY,POINT,TIMESTAMP,TIME,BOX,FLOAT4,FLOAT8,FLOAT4_ARRAY,FLOAT8_ARRAY
16:43:25.668 (3) types using binary receive = TIMESTAMPTZ,UUID,INT2_ARRAY,INT4_ARRAY,BYTEA,TEXT_ARRAY,TIMETZ,INT8,INT2,INT4,VARCHAR_ARRAY,INT8_ARRAY,POINT,DATE,TIMESTAMP,TIME,BOX,FLOAT4,FLOAT8,FLOAT4_ARRAY,FLOAT8_ARRAY
16:43:25.668 (3) integer date/time = true
2015-10-03 16:43:25.669 -0400 [INFO] (transaction): SQL: SET search_path TO "public"
16:43:25.669 (3) simple execute, handler=org.postgresql.jdbc2.AbstractJdbc2Statement$StatementResultHandler@15c16f19, maxRows=0, fetchSize=0, flags=21
16:43:25.669 (3) FE=> Parse(stmt=null,query="SET search_path TO "public"",oids={})
16:43:25.669 (3) FE=> Bind(stmt=null,portal=null)
16:43:25.670 (3) FE=> Describe(portal=null)
16:43:25.670 (3) FE=> Execute(portal=null,limit=1)
16:43:25.670 (3) FE=> Sync
16:43:25.670 (3) <=BE ParseComplete [null]
16:43:25.670 (3) <=BE BindComplete [null]
16:43:25.670 (3) <=BE NoData
16:43:25.670 (3) <=BE CommandStatus(SET)
16:43:25.670 (3) <=BE ReadyForQuery(I)
2015-10-03 16:43:25.670 -0400 [INFO] (transaction): > 0.00 seconds
2015-10-03 16:43:25.671 -0400 [INFO] (transaction): SQL: INSERT INTO "enc" ("date", "time", "reason") SELECT "date", "time", "reason" FROM "enc_56103de32bfcfc80_bl_tmp000"
16:43:25.671 (3) simple execute, handler=org.postgresql.jdbc2.AbstractJdbc2Statement$StatementResultHandler@1a17dd6f, maxRows=0, fetchSize=0, flags=5
16:43:25.671 (3) FE=> Parse(stmt=null,query="BEGIN",oids={})
16:43:25.671 (3) FE=> Bind(stmt=null,portal=null)
16:43:25.671 (3) FE=> Execute(portal=null,limit=0)
16:43:25.671 (3) FE=> Parse(stmt=null,query="INSERT INTO "enc" ("date", "time", "reason") SELECT "date", "time", "reason" FROM "enc_56103de32bfcfc80_bl_tmp000"",oids={})
16:43:25.671 (3) FE=> Bind(stmt=null,portal=null)
16:43:25.671 (3) FE=> Describe(portal=null)
16:43:25.671 (3) FE=> Execute(portal=null,limit=1)
16:43:25.671 (3) FE=> Sync
16:43:26.155 (3) <=BE ParseComplete [null]
16:43:26.155 (3) <=BE BindComplete [null]
16:43:26.155 (3) <=BE CommandStatus(BEGIN)
16:43:26.155 (3) <=BE ParseComplete [null]
16:43:26.155 (3) <=BE BindComplete [null]
16:43:26.155 (3) <=BE NoData
16:43:26.155 (3) <=BE CommandStatus(INSERT 0 197225)
16:43:26.155 (3) <=BE ReadyForQuery(T)
2015-10-03 16:43:26.155 -0400 [INFO] (transaction): > 0.48 seconds (197,225 rows)
16:43:26.155 (3) simple execute, handler=org.postgresql.jdbc2.AbstractJdbc2Connection$TransactionCommandHandler@be6d228, maxRows=0, fetchSize=0, flags=22
16:43:26.155 (3) FE=> Parse(stmt=S_1,query="COMMIT",oids={})
16:43:26.155 (3) FE=> Bind(stmt=S_1,portal=null)
16:43:26.155 (3) FE=> Execute(portal=null,limit=1)
16:43:26.155 (3) FE=> Sync
16:43:26.178 (3) <=BE ParseComplete [S_1]
16:43:26.178 (3) <=BE BindComplete [null]
16:43:26.178 (3) <=BE CommandStatus(COMMIT)
16:43:26.178 (3) <=BE ReadyForQuery(I)
16:43:26.178 (3) FE=> Terminate
2015-10-03 16:43:26.183 -0400 [INFO] (transaction): Connecting to jdbc:postgresql://localhost:5432/relevant_staging options {user=postgres, loglevel=3, tcpKeepAlive=true, loginTimeout=300, socketTimeout=1800}
16:43:26.183 (4) PostgreSQL 9.4 JDBC4.1 (build 1200)
16:43:26.184 (4) Trying to establish a protocol version 3 connection to localhost:5432
16:43:26.184 (4) Receive Buffer Size is 408300
16:43:26.184 (4) Send Buffer Size is 146988
16:43:26.184 (4) FE=> StartupPacket(user=postgres, database=relevant_staging, client_encoding=UTF8, DateStyle=ISO, TimeZone=America/New_York, extra_float_digits=2)
16:43:26.185 (4) <=BE AuthenticationReqMD5(salt=a60a7f85)
16:43:26.186 (4) FE=> Password(md5digest=md5555a096fd95f961b13a3c4f886dff546)
16:43:26.187 (4) <=BE AuthenticationOk
16:43:26.187 (4) <=BE ParameterStatus(application_name = )
16:43:26.187 (4) <=BE ParameterStatus(client_encoding = UTF8)
16:43:26.187 (4) <=BE ParameterStatus(DateStyle = ISO, MDY)
16:43:26.187 (4) <=BE ParameterStatus(integer_datetimes = on)
16:43:26.187 (4) <=BE ParameterStatus(IntervalStyle = postgres)
16:43:26.187 (4) <=BE ParameterStatus(is_superuser = on)
16:43:26.187 (4) <=BE ParameterStatus(server_encoding = UTF8)
16:43:26.187 (4) <=BE ParameterStatus(server_version = 9.1.14)
16:43:26.187 (4) <=BE ParameterStatus(session_authorization = postgres)
16:43:26.188 (4) <=BE ParameterStatus(standard_conforming_strings = on)
16:43:26.188 (4) <=BE ParameterStatus(TimeZone = America/New_York)
16:43:26.188 (4) <=BE BackendKeyData(pid=62859,ckey=1557919149)
16:43:26.188 (4) <=BE ReadyForQuery(I)
16:43:26.188 (4) simple execute, handler=org.postgresql.core.SetupQueryRunner$SimpleResultHandler@43619446, maxRows=0, fetchSize=0, flags=23
16:43:26.188 (4) FE=> Parse(stmt=null,query="SET extra_float_digits = 3",oids={})
16:43:26.188 (4) FE=> Bind(stmt=null,portal=null)
16:43:26.188 (4) FE=> Execute(portal=null,limit=1)
16:43:26.188 (4) FE=> Sync
16:43:26.188 (4) <=BE ParseComplete [null]
16:43:26.188 (4) <=BE BindComplete [null]
16:43:26.188 (4) <=BE CommandStatus(SET)
16:43:26.188 (4) <=BE ReadyForQuery(I)
16:43:26.188 (4) compatible = 90400
16:43:26.188 (4) loglevel = 3
16:43:26.188 (4) prepare threshold = 5
16:43:26.189 (4) types using binary send = TIMESTAMPTZ,UUID,INT2_ARRAY,INT4_ARRAY,BYTEA,TEXT_ARRAY,TIMETZ,INT8,INT2,INT4,VARCHAR_ARRAY,INT8_ARRAY,POINT,TIMESTAMP,TIME,BOX,FLOAT4,FLOAT8,FLOAT4_ARRAY,FLOAT8_ARRAY
16:43:26.189 (4) types using binary receive = TIMESTAMPTZ,UUID,INT2_ARRAY,INT4_ARRAY,BYTEA,TEXT_ARRAY,TIMETZ,INT8,INT2,INT4,VARCHAR_ARRAY,INT8_ARRAY,POINT,DATE,TIMESTAMP,TIME,BOX,FLOAT4,FLOAT8,FLOAT4_ARRAY,FLOAT8_ARRAY
16:43:26.189 (4) integer date/time = true
2015-10-03 16:43:26.189 -0400 [INFO] (transaction): SQL: SET search_path TO "public"
16:43:26.190 (4) simple execute, handler=org.postgresql.jdbc2.AbstractJdbc2Statement$StatementResultHandler@4c6bba7d, maxRows=0, fetchSize=0, flags=21
16:43:26.190 (4) FE=> Parse(stmt=null,query="SET search_path TO "public"",oids={})
16:43:26.190 (4) FE=> Bind(stmt=null,portal=null)
16:43:26.190 (4) FE=> Describe(portal=null)
16:43:26.190 (4) FE=> Execute(portal=null,limit=1)
16:43:26.190 (4) FE=> Sync
16:43:26.191 (4) <=BE ParseComplete [null]
16:43:26.191 (4) <=BE BindComplete [null]
16:43:26.191 (4) <=BE NoData
16:43:26.191 (4) <=BE CommandStatus(SET)
16:43:26.191 (4) <=BE ReadyForQuery(I)
2015-10-03 16:43:26.191 -0400 [INFO] (transaction): > 0.00 seconds
2015-10-03 16:43:26.191 -0400 [INFO] (transaction): SQL: DROP TABLE IF EXISTS "enc_56103de32bfcfc80_bl_tmp000"
16:43:26.191 (4) simple execute, handler=org.postgresql.jdbc2.AbstractJdbc2Statement$StatementResultHandler@41e8d917, maxRows=0, fetchSize=0, flags=21
16:43:26.191 (4) FE=> Parse(stmt=null,query="DROP TABLE IF EXISTS "enc_56103de32bfcfc80_bl_tmp000"",oids={})
16:43:26.191 (4) FE=> Bind(stmt=null,portal=null)
16:43:26.191 (4) FE=> Describe(portal=null)
16:43:26.191 (4) FE=> Execute(portal=null,limit=1)
16:43:26.191 (4) FE=> Sync
16:43:26.195 (4) <=BE ParseComplete [null]
16:43:26.195 (4) <=BE BindComplete [null]
16:43:26.195 (4) <=BE NoData
16:43:26.195 (4) <=BE CommandStatus(DROP TABLE)
16:43:26.195 (4) <=BE ReadyForQuery(I)
2015-10-03 16:43:26.196 -0400 [INFO] (transaction): > 0.00 seconds
16:43:26.196 (4) FE=> Terminate
2015-10-03 16:43:26.200 -0400 [INFO] (main): Committed.
2015-10-03 16:43:26.201 -0400 [INFO] (main): Next config diff: {"in":{},"out":{}}
skipping: java.sql.DriverInfo
skipping: java.sql.DriverInfo