Incremental snapshot sql fails on postgres 9.6

[danielbcook]

Describe the bug

I set up a snapshot model and it runs OK on the first pass (where it creates the table), but on the subsequent passes it returns an error "failed to find conversion function from unknown to text". All of the fields in my Postgres query appear to be properly typed (none are 'unknown'). I suspect this is specific to UNION queries on Postgres 9.6.10 (and below).

Steps To Reproduce

Here is the original query (prior to many attempts to simplify and look for the culprit column). Simply run dbt snapshot twice to reproduce. The results should return one row per day, per user, per table in the UNION which has a relevant row in it.

{% snapshot profile_completion_snapshot %}
    {{
        config(
			target_database='analyticsd',
			target_schema='auxiliary_tables',
			strategy='check',
			unique_key='id',
			check_cols = 'all'
        )
    }}

WITH daily_profile_data as
	(
		SELECT DISTINCT CONCAT(user_id,cast(Now() as date),'usr_accomplishments')::text as id, user_id::varchar(32), 'usr_accomplishments'::varchar(50) as source, 1::smallint as populated, cast(Now() as date) as date FROM x_snapshot.usr_accomplishments
		UNION
		SELECT DISTINCT CONCAT(user_id,cast(Now() as date),'usr_education')::text as id, user_id::varchar(32), 'usr_education'::varchar(50) as source, 1::smallint as populated, cast(Now() as date) as date FROM x_snapshot.usr_education
		UNION
		SELECT DISTINCT CONCAT(user_id,cast(Now() as date),'usr_experiences')::text as id, user_id::varchar(32), 'usr_experiences'::varchar(50) as source, 1::smallint as populated, cast(Now() as date) as date FROM x_snapshot.usr_experiences
		UNION
		SELECT DISTINCT CONCAT(user_id,cast(Now() as date),'usr_interests')::text as id, user_id::varchar(32), 'usr_interests'::varchar(50) as source, 1::smallint as populated, cast(Now() as date) as date FROM x_snapshot.usr_interests
		UNION
		SELECT DISTINCT CONCAT(user_id,cast(Now() as date),'usr_languages')::text as id, user_id::varchar(32), 'usr_languages'::varchar(50) as source, 1::smallint as populated, cast(Now() as date) as date FROM x_snapshot.usr_languages
		UNION
		SELECT DISTINCT CONCAT(user_id,cast(Now() as date),'usr_patents')::text as id, user_id::varchar(32), 'usr_patents'::varchar(50) as source, 1::smallint as populated, cast(Now() as date) as date FROM x_snapshot.usr_patents
		UNION
		SELECT DISTINCT CONCAT(user_id,cast(Now() as date),'usr_publications')::text as id, user_id::varchar(32), 'usr_publications'::varchar(50) as source, 1::smallint as populated, cast(Now() as date) as date FROM x_snapshot.usr_publications
		UNION
		SELECT DISTINCT CONCAT(user_id,cast(Now() as date),'usr_summary')::text as id, user_id::varchar(32), 'usr_summary'::varchar(50) as source, 1::smallint as populated, cast(Now() as date) as date FROM x_snapshot.usr_summary
		UNION
		SELECT DISTINCT CONCAT(user_id,cast(Now() as date),'usr_websites')::text as id, user_id::varchar(32), 'usr_websites'::varchar(50) as source, 1::smallint as populated, cast(Now() as date) as date FROM x_snapshot.usr_websites
	)
SELECT *
FROM daily_profile_data

{% endsnapshot %}

Expected behavior

For subsequent runs of the snapshot to succeed like the first one does.

Screenshots and log output

If applicable, add screenshots or log output to help explain your problem.

System information

Which database are you using dbt with?

• PostgreSQL 9.6.10 on x86_64-pc-linux-gnu, compiled by gcc (Ubuntu 4.8.4-2ubuntu1~14.04.3) 4.8.4, 64-bit
• redshift
• bigquery
• snowflake

The output of dbt --version:

installed version: 0.14.0
   latest version: 0.14.0

The operating system you're using:

Windows Server 2016
Major  Minor  Build  Revision
-----  -----  -----  --------
10     0      14393  0

The output of python --version:

Python 3.7.2

Additional context

dbt.log output

2019-08-05 16:00:16,173 (MainThread): Sending event: {'category': 'dbt', 'action': 'invocation', 'label': 'end', 'context': [<snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x0000029E31B5C438>, <snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x0000029E3081DEB8>, <snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x0000029E3081DD68>]}
2019-08-05 16:00:16,319 (MainThread): Flushing usage events
2019-08-05 16:10:08,835 (MainThread): Tracking: tracking
2019-08-05 16:10:08,839 (MainThread): Sending event: {'category': 'dbt', 'action': 'invocation', 'label': 'start', 'context': [<snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x00000246766970B8>, <snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x0000024676697208>, <snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x0000024676697780>]}
2019-08-05 16:10:09,031 (MainThread): Parsing macros\optimizers\index.sql
2019-08-05 16:10:09,035 (MainThread): Parsing macros\core.sql
2019-08-05 16:10:09,042 (MainThread): Parsing macros\adapters\common.sql
2019-08-05 16:10:09,085 (MainThread): Parsing macros\etc\datetime.sql
2019-08-05 16:10:09,102 (MainThread): Parsing macros\etc\get_custom_alias.sql
2019-08-05 16:10:09,104 (MainThread): Parsing macros\etc\get_custom_schema.sql
2019-08-05 16:10:09,106 (MainThread): Parsing macros\etc\get_relation_comment.sql
2019-08-05 16:10:09,110 (MainThread): Parsing macros\etc\is_incremental.sql
2019-08-05 16:10:09,112 (MainThread): Parsing macros\etc\query.sql
2019-08-05 16:10:09,114 (MainThread): Parsing macros\materializations\helpers.sql
2019-08-05 16:10:09,123 (MainThread): Parsing macros\materializations\common\merge.sql
2019-08-05 16:10:09,131 (MainThread): Parsing macros\materializations\incremental\incremental.sql
2019-08-05 16:10:09,140 (MainThread): Parsing macros\materializations\seed\seed.sql
2019-08-05 16:10:09,157 (MainThread): Parsing macros\materializations\snapshot\snapshot.sql
2019-08-05 16:10:09,179 (MainThread): Parsing macros\materializations\snapshot\snapshot_merge.sql
2019-08-05 16:10:09,182 (MainThread): Parsing macros\materializations\snapshot\strategies.sql
2019-08-05 16:10:09,195 (MainThread): Parsing macros\materializations\table\table.sql
2019-08-05 16:10:09,203 (MainThread): Parsing macros\materializations\view\create_or_replace_view.sql
2019-08-05 16:10:09,209 (MainThread): Parsing macros\materializations\view\view.sql
2019-08-05 16:10:09,216 (MainThread): Parsing macros\schema_tests\accepted_values.sql
2019-08-05 16:10:09,219 (MainThread): Parsing macros\schema_tests\not_null.sql
2019-08-05 16:10:09,221 (MainThread): Parsing macros\schema_tests\relationships.sql
2019-08-05 16:10:09,223 (MainThread): Parsing macros\schema_tests\unique.sql
2019-08-05 16:10:09,226 (MainThread): Parsing macros\adapters.sql
2019-08-05 16:10:09,238 (MainThread): Parsing macros\catalog.sql
2019-08-05 16:10:09,242 (MainThread): Parsing macros\relations.sql
2019-08-05 16:10:09,245 (MainThread): Parsing macros\materializations\snapshot_merge.sql
2019-08-05 16:10:09,272 (MainThread): Parsing model.analytics_augmentation_package.anonymous_user_mappings
2019-08-05 16:10:09,935 (MainThread): Found 31 models, 0 tests, 1 snapshots, 0 analyses, 117 macros, 0 operations, 0 seed files, 0 sources
2019-08-05 16:10:09,938 (MainThread): 
2019-08-05 16:10:09,939 (MainThread): Acquiring new postgres connection "master".
2019-08-05 16:10:09,939 (MainThread): Re-using an available connection from the pool (formerly profile_completion_snapshot).
2019-08-05 16:10:09,959 (MainThread): Parsing macros\core.sql
2019-08-05 16:10:09,965 (MainThread): Parsing macros\adapters\common.sql
2019-08-05 16:10:10,008 (MainThread): Parsing macros\etc\datetime.sql
2019-08-05 16:10:10,018 (MainThread): Parsing macros\etc\get_custom_alias.sql
2019-08-05 16:10:10,020 (MainThread): Parsing macros\etc\get_custom_schema.sql
2019-08-05 16:10:10,023 (MainThread): Parsing macros\etc\get_relation_comment.sql
2019-08-05 16:10:10,026 (MainThread): Parsing macros\etc\is_incremental.sql
2019-08-05 16:10:10,028 (MainThread): Parsing macros\etc\query.sql
2019-08-05 16:10:10,030 (MainThread): Parsing macros\materializations\helpers.sql
2019-08-05 16:10:10,038 (MainThread): Parsing macros\materializations\common\merge.sql
2019-08-05 16:10:10,047 (MainThread): Parsing macros\materializations\incremental\incremental.sql
2019-08-05 16:10:10,056 (MainThread): Parsing macros\materializations\seed\seed.sql
2019-08-05 16:10:10,073 (MainThread): Parsing macros\materializations\snapshot\snapshot.sql
2019-08-05 16:10:10,098 (MainThread): Parsing macros\materializations\snapshot\snapshot_merge.sql
2019-08-05 16:10:10,100 (MainThread): Parsing macros\materializations\snapshot\strategies.sql
2019-08-05 16:10:10,113 (MainThread): Parsing macros\materializations\table\table.sql
2019-08-05 16:10:10,120 (MainThread): Parsing macros\materializations\view\create_or_replace_view.sql
2019-08-05 16:10:10,133 (MainThread): Parsing macros\materializations\view\view.sql
2019-08-05 16:10:10,140 (MainThread): Parsing macros\schema_tests\accepted_values.sql
2019-08-05 16:10:10,142 (MainThread): Parsing macros\schema_tests\not_null.sql
2019-08-05 16:10:10,144 (MainThread): Parsing macros\schema_tests\relationships.sql
2019-08-05 16:10:10,146 (MainThread): Parsing macros\schema_tests\unique.sql
2019-08-05 16:10:10,150 (MainThread): Parsing macros\adapters.sql
2019-08-05 16:10:10,163 (MainThread): Parsing macros\catalog.sql
2019-08-05 16:10:10,167 (MainThread): Parsing macros\relations.sql
2019-08-05 16:10:10,170 (MainThread): Parsing macros\materializations\snapshot_merge.sql
2019-08-05 16:10:10,327 (MainThread): Using postgres connection "master".
2019-08-05 16:10:10,327 (MainThread): On master: 
    select distinct nspname from pg_namespace
  
2019-08-05 16:10:10,400 (MainThread): SQL status: SELECT 103 in 0.07 seconds
2019-08-05 16:10:10,449 (MainThread): Using postgres connection "master".
2019-08-05 16:10:10,449 (MainThread): On master: BEGIN
2019-08-05 16:10:10,485 (MainThread): SQL status: BEGIN in 0.04 seconds
2019-08-05 16:10:10,486 (MainThread): Using postgres connection "master".
2019-08-05 16:10:10,486 (MainThread): On master: select
      'analyticsd' as database,
      tablename as name,
      schemaname as schema,
      'table' as type
    from pg_tables
    where schemaname ilike 'public'
    union all
    select
      'analyticsd' as database,
      viewname as name,
      schemaname as schema,
      'view' as type
    from pg_views
    where schemaname ilike 'public'
  
2019-08-05 16:10:10,527 (MainThread): SQL status: SELECT 41 in 0.04 seconds
2019-08-05 16:10:10,575 (MainThread): Using postgres connection "master".
2019-08-05 16:10:10,575 (MainThread): On master: select
      'analyticsd' as database,
      tablename as name,
      schemaname as schema,
      'table' as type
    from pg_tables
    where schemaname ilike 'auxiliary_tables'
    union all
    select
      'analyticsd' as database,
      viewname as name,
      schemaname as schema,
      'view' as type
    from pg_views
    where schemaname ilike 'auxiliary_tables'
  
2019-08-05 16:10:10,613 (MainThread): SQL status: SELECT 0 in 0.04 seconds
2019-08-05 16:10:10,653 (MainThread): Using postgres connection "master".
2019-08-05 16:10:10,653 (MainThread): On master: -- 
    -- 
    with relation as (
        select
            pg_rewrite.ev_class as class,
            pg_rewrite.oid as id
        from pg_rewrite
    ),
    class as (
        select
            oid as id,
            relname as name,
            relnamespace as schema,
            relkind as kind
        from pg_class
    ),
    dependency as (
        select
            pg_depend.objid as id,
            pg_depend.refobjid as ref
        from pg_depend
    ),
    schema as (
        select
            pg_namespace.oid as id,
            pg_namespace.nspname as name
        from pg_namespace
        where nspname != 'information_schema' and nspname not like 'pg_%'
    ),
    referenced as (
        select
            relation.id AS id,
            referenced_class.name ,
            referenced_class.schema ,
            referenced_class.kind
        from relation
        join class as referenced_class on relation.class=referenced_class.id
        where referenced_class.kind in ('r', 'v')
    ),
    relationships as (
        select
            referenced.name as referenced_name,
            referenced.schema as referenced_schema_id,
            dependent_class.name as dependent_name,
            dependent_class.schema as dependent_schema_id,
            referenced.kind as kind
        from referenced
        join dependency on referenced.id=dependency.id
        join class as dependent_class on dependency.ref=dependent_class.id
        where
            (referenced.name != dependent_class.name or
             referenced.schema != dependent_class.schema)
    )

    select
        referenced_schema.name as referenced_schema,
        relationships.referenced_name as referenced_name,
        dependent_schema.name as dependent_schema,
        relationships.dependent_name as dependent_name
    from relationships
    join schema as dependent_schema on relationships.dependent_schema_id=dependent_schema.id
    join schema as referenced_schema on relationships.referenced_schema_id=referenced_schema.id
    group by referenced_schema, referenced_name, dependent_schema, dependent_name
    order by referenced_schema, referenced_name, dependent_schema, dependent_name;
2019-08-05 16:10:10,702 (MainThread): SQL status: SELECT 45 in 0.05 seconds
2019-08-05 16:10:10,737 (MainThread): On master: ROLLBACK
2019-08-05 16:10:10,773 (MainThread): Using postgres connection "master".
2019-08-05 16:10:10,773 (MainThread): On master: BEGIN
2019-08-05 16:10:10,845 (MainThread): SQL status: BEGIN in 0.07 seconds
2019-08-05 16:10:10,845 (MainThread): On master: COMMIT
2019-08-05 16:10:10,846 (MainThread): Using postgres connection "master".
2019-08-05 16:10:10,846 (MainThread): On master: COMMIT
2019-08-05 16:10:10,881 (MainThread): SQL status: COMMIT in 0.04 seconds
2019-08-05 16:10:10,882 (MainThread): 16:10:10 | Concurrency: 6 threads (target='dev')
2019-08-05 16:10:10,882 (MainThread): 16:10:10 | 
2019-08-05 16:10:10,887 (Thread-1): 16:10:10 | 1 of 1 START snapshot profile_completion_snapshot.................... [RUN]
2019-08-05 16:10:10,888 (Thread-1): Acquiring new postgres connection "profile_completion_snapshot".
2019-08-05 16:10:10,888 (Thread-1): Opening a new connection, currently in state init
2019-08-05 16:10:11,138 (Thread-1): Compiling snapshot.analytics_augmentation_package.profile_completion_snapshot
2019-08-05 16:10:11,199 (Thread-1): Using postgres connection "profile_completion_snapshot".
2019-08-05 16:10:11,199 (Thread-1): On profile_completion_snapshot: 
    select count(*) from pg_namespace where nspname = 'auxiliary_tables'
  
2019-08-05 16:10:11,278 (Thread-1): SQL status: SELECT 1 in 0.08 seconds
2019-08-05 16:10:11,311 (Thread-1): Using postgres connection "profile_completion_snapshot".
2019-08-05 16:10:11,311 (Thread-1): On profile_completion_snapshot: select * from (
            

    
    
WITH daily_profile_data as
	(
		SELECT cast(CONCAT(cast(user_id as text),cast(Now() as text),cast('usr_accomplishments' as text)) as text) as id FROM x_snapshot.usr_accomplishments
		UNION
		SELECT cast(CONCAT(cast(user_id as text),cast(Now() as text),cast('usr_education' as text)) as text) as id FROM x_snapshot.usr_education
		UNION
		SELECT cast(CONCAT(cast(user_id as text),cast(Now() as text),cast('usr_experiences' as text)) as text) as id FROM x_snapshot.usr_experiences
		UNION
		SELECT cast(CONCAT(cast(user_id as text),cast(Now() as text),cast('usr_interests' as text)) as text) as id FROM x_snapshot.usr_interests
		UNION
		SELECT cast(CONCAT(cast(user_id as text),cast(Now() as text),cast('usr_languages' as text)) as text) as id FROM x_snapshot.usr_languages
		UNION
		SELECT cast(CONCAT(cast(user_id as text),cast(Now() as text),cast('usr_patents' as text)) as text) as id FROM x_snapshot.usr_patents
		UNION
		SELECT cast(CONCAT(cast(user_id as text),cast(Now() as text),cast('usr_publications' as text)) as text) as id FROM x_snapshot.usr_publications
		UNION
		SELECT cast(CONCAT(cast(user_id as text),cast(Now() as text),cast('usr_summary' as text)) as text) as id FROM x_snapshot.usr_summary
		UNION
		SELECT cast(CONCAT(cast(user_id as text),cast(Now() as text),cast('usr_websites' as text)) as text) as id FROM x_snapshot.usr_websites
	)
SELECT *
FROM daily_profile_data
WHERE id IS NOT NULL
    
        ) as __dbt_sbq
        where false
        limit 0
    
2019-08-05 16:10:11,351 (Thread-1): SQL status: SELECT 0 in 0.04 seconds
2019-08-05 16:10:11,355 (Thread-1): Writing runtime SQL for node "snapshot.analytics_augmentation_package.profile_completion_snapshot"
2019-08-05 16:10:11,358 (Thread-1): Using postgres connection "profile_completion_snapshot".
2019-08-05 16:10:11,358 (Thread-1): On profile_completion_snapshot: BEGIN
2019-08-05 16:10:11,397 (Thread-1): SQL status: BEGIN in 0.04 seconds
2019-08-05 16:10:11,398 (Thread-1): Using postgres connection "profile_completion_snapshot".
2019-08-05 16:10:11,398 (Thread-1): On profile_completion_snapshot: create  table
    "analyticsd"."auxiliary_tables"."profile_completion_snapshot"
  as (
    

    select *,
        
  
    md5(
        coalesce(cast(id as varchar ), '')  || '|' || 
    
        coalesce(cast(id as varchar ), '') 
    )

 as dbt_scd_id,
        now()::timestamp without time zone as dbt_updated_at,
        now()::timestamp without time zone as dbt_valid_from,
        nullif(now()::timestamp without time zone, now()::timestamp without time zone) as dbt_valid_to
    from (
        

    
    
WITH daily_profile_data as
	(
		SELECT cast(CONCAT(cast(user_id as text),cast(Now() as text),cast('usr_accomplishments' as text)) as text) as id FROM x_snapshot.usr_accomplishments
		UNION
		SELECT cast(CONCAT(cast(user_id as text),cast(Now() as text),cast('usr_education' as text)) as text) as id FROM x_snapshot.usr_education
		UNION
		SELECT cast(CONCAT(cast(user_id as text),cast(Now() as text),cast('usr_experiences' as text)) as text) as id FROM x_snapshot.usr_experiences
		UNION
		SELECT cast(CONCAT(cast(user_id as text),cast(Now() as text),cast('usr_interests' as text)) as text) as id FROM x_snapshot.usr_interests
		UNION
		SELECT cast(CONCAT(cast(user_id as text),cast(Now() as text),cast('usr_languages' as text)) as text) as id FROM x_snapshot.usr_languages
		UNION
		SELECT cast(CONCAT(cast(user_id as text),cast(Now() as text),cast('usr_patents' as text)) as text) as id FROM x_snapshot.usr_patents
		UNION
		SELECT cast(CONCAT(cast(user_id as text),cast(Now() as text),cast('usr_publications' as text)) as text) as id FROM x_snapshot.usr_publications
		UNION
		SELECT cast(CONCAT(cast(user_id as text),cast(Now() as text),cast('usr_summary' as text)) as text) as id FROM x_snapshot.usr_summary
		UNION
		SELECT cast(CONCAT(cast(user_id as text),cast(Now() as text),cast('usr_websites' as text)) as text) as id FROM x_snapshot.usr_websites
	)
SELECT *
FROM daily_profile_data
WHERE id IS NOT NULL
    
    ) sbq


  );

      
2019-08-05 16:10:11,521 (Thread-1): SQL status: SELECT 9024 in 0.12 seconds
2019-08-05 16:10:11,521 (Thread-1): On profile_completion_snapshot: COMMIT
2019-08-05 16:10:11,521 (Thread-1): Using postgres connection "profile_completion_snapshot".
2019-08-05 16:10:11,521 (Thread-1): On profile_completion_snapshot: COMMIT
2019-08-05 16:10:11,570 (Thread-1): SQL status: COMMIT in 0.05 seconds
2019-08-05 16:10:11,575 (Thread-1): Sending event: {'category': 'dbt', 'action': 'run_model', 'label': '648c6d6a-8b96-427c-8015-496e83d8d770', 'context': [<snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x0000024677887860>]}
2019-08-05 16:10:11,729 (Thread-1): 16:10:11 | 1 of 1 OK snapshotted profile_completion_snapshot.................... [SELECT 9024 in 0.69s]
2019-08-05 16:10:11,808 (MainThread): Using postgres connection "master".
2019-08-05 16:10:11,808 (MainThread): On master: BEGIN
2019-08-05 16:10:11,844 (MainThread): SQL status: BEGIN in 0.04 seconds
2019-08-05 16:10:11,844 (MainThread): On master: COMMIT
2019-08-05 16:10:11,844 (MainThread): Using postgres connection "master".
2019-08-05 16:10:11,844 (MainThread): On master: COMMIT
2019-08-05 16:10:11,880 (MainThread): SQL status: COMMIT in 0.04 seconds
2019-08-05 16:10:11,881 (MainThread): 16:10:11 | 
2019-08-05 16:10:11,881 (MainThread): 16:10:11 | Finished running 1 snapshots in 1.94s.
2019-08-05 16:10:11,882 (MainThread): Connection 'master' was left open.
2019-08-05 16:10:11,882 (MainThread): On master: Close
2019-08-05 16:10:11,883 (MainThread): Connection 'profile_completion_snapshot' was left open.
2019-08-05 16:10:11,883 (MainThread): On profile_completion_snapshot: Close
2019-08-05 16:10:11,894 (MainThread): 
2019-08-05 16:10:11,895 (MainThread): Completed successfully
2019-08-05 16:10:11,896 (MainThread): 
Done. PASS=1 ERROR=0 SKIP=0 TOTAL=1
2019-08-05 16:10:11,896 (MainThread): Sending event: {'category': 'dbt', 'action': 'invocation', 'label': 'end', 'context': [<snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x00000246766A0DD8>, <snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x00000246778A1FD0>, <snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x00000246778A1F60>]}
2019-08-05 16:10:12,042 (MainThread): Flushing usage events
2019-08-05 16:10:16,640 (MainThread): Tracking: tracking
2019-08-05 16:10:16,645 (MainThread): Sending event: {'category': 'dbt', 'action': 'invocation', 'label': 'start', 'context': [<snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x0000018640FF82B0>, <snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x0000018640FF8400>, <snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x0000018640FF8978>]}
2019-08-05 16:10:16,810 (MainThread): Parsing macros\optimizers\index.sql
2019-08-05 16:10:16,815 (MainThread): Parsing macros\core.sql
2019-08-05 16:10:16,822 (MainThread): Parsing macros\adapters\common.sql
2019-08-05 16:10:16,859 (MainThread): Parsing macros\etc\datetime.sql
2019-08-05 16:10:16,869 (MainThread): Parsing macros\etc\get_custom_alias.sql
2019-08-05 16:10:16,871 (MainThread): Parsing macros\etc\get_custom_schema.sql
2019-08-05 16:10:16,874 (MainThread): Parsing macros\etc\get_relation_comment.sql
2019-08-05 16:10:16,877 (MainThread): Parsing macros\etc\is_incremental.sql
2019-08-05 16:10:16,880 (MainThread): Parsing macros\etc\query.sql
2019-08-05 16:10:16,882 (MainThread): Parsing macros\materializations\helpers.sql
2019-08-05 16:10:16,891 (MainThread): Parsing macros\materializations\common\merge.sql
2019-08-05 16:10:16,899 (MainThread): Parsing macros\materializations\incremental\incremental.sql
2019-08-05 16:10:16,908 (MainThread): Parsing macros\materializations\seed\seed.sql
2019-08-05 16:10:16,926 (MainThread): Parsing macros\materializations\snapshot\snapshot.sql
2019-08-05 16:10:16,946 (MainThread): Parsing macros\materializations\snapshot\snapshot_merge.sql
2019-08-05 16:10:16,949 (MainThread): Parsing macros\materializations\snapshot\strategies.sql
2019-08-05 16:10:16,963 (MainThread): Parsing macros\materializations\table\table.sql
2019-08-05 16:10:16,970 (MainThread): Parsing macros\materializations\view\create_or_replace_view.sql
2019-08-05 16:10:16,976 (MainThread): Parsing macros\materializations\view\view.sql
2019-08-05 16:10:16,981 (MainThread): Parsing macros\schema_tests\accepted_values.sql
2019-08-05 16:10:16,984 (MainThread): Parsing macros\schema_tests\not_null.sql
2019-08-05 16:10:16,985 (MainThread): Parsing macros\schema_tests\relationships.sql
2019-08-05 16:10:16,987 (MainThread): Parsing macros\schema_tests\unique.sql
2019-08-05 16:10:16,989 (MainThread): Parsing macros\adapters.sql
2019-08-05 16:10:17,001 (MainThread): Parsing macros\catalog.sql
2019-08-05 16:10:17,004 (MainThread): Parsing macros\relations.sql
2019-08-05 16:10:17,006 (MainThread): Parsing macros\materializations\snapshot_merge.sql
2019-08-05 16:10:17,031 (MainThread): Parsing model.analytics_augmentation_package.anonymous_user_mappings
2019-08-05 16:10:17,032 (MainThread): Acquiring new postgres connection "anonymous_user_mappings".
2019-08-05 16:10:17,033 (MainThread): Opening a new connection, currently in state init
2019-08-05 16:10:17,336 (MainThread): Parsing model.analytics_augmentation_package.authenticated_pages
2019-08-05 16:10:17,337 (MainThread): Acquiring new postgres connection "authenticated_pages".
2019-08-05 16:10:17,337 (MainThread): Re-using an available connection from the pool (formerly anonymous_user_mappings).
2019-08-05 16:10:17,345 (MainThread): Parsing model.analytics_augmentation_package.auth_user_signedup_signedin
2019-08-05 16:10:17,347 (MainThread): Acquiring new postgres connection "auth_user_signedup_signedin".
2019-08-05 16:10:17,347 (MainThread): Re-using an available connection from the pool (formerly authenticated_pages).
2019-08-05 16:10:17,354 (MainThread): Parsing model.analytics_augmentation_package.client_pageviewed_opportunity
2019-08-05 16:10:17,354 (MainThread): Acquiring new postgres connection "client_pageviewed_opportunity".
2019-08-05 16:10:17,354 (MainThread): Re-using an available connection from the pool (formerly auth_user_signedup_signedin).
2019-08-05 16:10:17,363 (MainThread): Parsing model.analytics_augmentation_package.client_statistics
2019-08-05 16:10:17,364 (MainThread): Acquiring new postgres connection "client_statistics".
2019-08-05 16:10:17,365 (MainThread): Re-using an available connection from the pool (formerly client_pageviewed_opportunity).
2019-08-05 16:10:17,374 (MainThread): Parsing model.analytics_augmentation_package.customer_referral_program
2019-08-05 16:10:17,375 (MainThread): Acquiring new postgres connection "customer_referral_program".
2019-08-05 16:10:17,375 (MainThread): Re-using an available connection from the pool (formerly client_statistics).
2019-08-05 16:10:17,384 (MainThread): Parsing model.analytics_augmentation_package.daily_profile_completion
2019-08-05 16:10:17,385 (MainThread): Acquiring new postgres connection "daily_profile_completion".
2019-08-05 16:10:17,386 (MainThread): Re-using an available connection from the pool (formerly customer_referral_program).
2019-08-05 16:10:17,395 (MainThread): Parsing model.analytics_augmentation_package.platform_events
2019-08-05 16:10:17,396 (MainThread): Acquiring new postgres connection "platform_events".
2019-08-05 16:10:17,396 (MainThread): Re-using an available connection from the pool (formerly daily_profile_completion).
2019-08-05 16:10:17,406 (MainThread): Parsing model.analytics_augmentation_package.real_time_utm
2019-08-05 16:10:17,407 (MainThread): Acquiring new postgres connection "real_time_utm".
2019-08-05 16:10:17,407 (MainThread): Re-using an available connection from the pool (formerly platform_events).
2019-08-05 16:10:17,417 (MainThread): Parsing model.analytics_augmentation_package.recent_user_updates
2019-08-05 16:10:17,418 (MainThread): Acquiring new postgres connection "recent_user_updates".
2019-08-05 16:10:17,418 (MainThread): Re-using an available connection from the pool (formerly real_time_utm).
2019-08-05 16:10:17,426 (MainThread): Parsing model.analytics_augmentation_package.salesforce_concept_development
2019-08-05 16:10:17,427 (MainThread): Acquiring new postgres connection "salesforce_concept_development".
2019-08-05 16:10:17,428 (MainThread): Re-using an available connection from the pool (formerly recent_user_updates).
2019-08-05 16:10:17,433 (MainThread): Parsing model.analytics_augmentation_package.salesforce_drafting
2019-08-05 16:10:17,434 (MainThread): Acquiring new postgres connection "salesforce_drafting".
2019-08-05 16:10:17,434 (MainThread): Re-using an available connection from the pool (formerly salesforce_concept_development).
2019-08-05 16:10:17,440 (MainThread): Parsing model.analytics_augmentation_package.temp_all_user_events
2019-08-05 16:10:17,441 (MainThread): Acquiring new postgres connection "temp_all_user_events".
2019-08-05 16:10:17,441 (MainThread): Re-using an available connection from the pool (formerly salesforce_drafting).
2019-08-05 16:10:17,448 (MainThread): Parsing model.analytics_augmentation_package.temp_rfx_page_view
2019-08-05 16:10:17,449 (MainThread): Acquiring new postgres connection "temp_rfx_page_view".
2019-08-05 16:10:17,450 (MainThread): Re-using an available connection from the pool (formerly temp_all_user_events).
2019-08-05 16:10:17,456 (MainThread): Parsing model.analytics_augmentation_package.unique_ip_address
2019-08-05 16:10:17,457 (MainThread): Acquiring new postgres connection "unique_ip_address".
2019-08-05 16:10:17,457 (MainThread): Re-using an available connection from the pool (formerly temp_rfx_page_view).
2019-08-05 16:10:17,466 (MainThread): Parsing model.analytics_augmentation_package.utm_events
2019-08-05 16:10:17,467 (MainThread): Acquiring new postgres connection "utm_events".
2019-08-05 16:10:17,468 (MainThread): Re-using an available connection from the pool (formerly unique_ip_address).
2019-08-05 16:10:17,475 (MainThread): Parsing model.analytics_augmentation_package.x_awards
2019-08-05 16:10:17,476 (MainThread): Acquiring new postgres connection "x_awards".
2019-08-05 16:10:17,476 (MainThread): Re-using an available connection from the pool (formerly utm_events).
2019-08-05 16:10:17,481 (MainThread): Parsing model.analytics_augmentation_package.x_channel_member_group
2019-08-05 16:10:17,482 (MainThread): Acquiring new postgres connection "x_channel_member_group".
2019-08-05 16:10:17,482 (MainThread): Re-using an available connection from the pool (formerly x_awards).
2019-08-05 16:10:17,488 (MainThread): Parsing model.analytics_augmentation_package.x_contract_participant
2019-08-05 16:10:17,489 (MainThread): Acquiring new postgres connection "x_contract_participant".
2019-08-05 16:10:17,489 (MainThread): Re-using an available connection from the pool (formerly x_channel_member_group).
2019-08-05 16:10:17,494 (MainThread): Parsing model.analytics_augmentation_package.x_member_group
2019-08-05 16:10:17,495 (MainThread): Acquiring new postgres connection "x_member_group".
2019-08-05 16:10:17,496 (MainThread): Re-using an available connection from the pool (formerly x_contract_participant).
2019-08-05 16:10:17,501 (MainThread): Parsing model.analytics_augmentation_package.x_quest
2019-08-05 16:10:17,502 (MainThread): Acquiring new postgres connection "x_quest".
2019-08-05 16:10:17,502 (MainThread): Re-using an available connection from the pool (formerly x_member_group).
2019-08-05 16:10:17,507 (MainThread): Parsing model.analytics_augmentation_package.x_referral_data
2019-08-05 16:10:17,508 (MainThread): Acquiring new postgres connection "x_referral_data".
2019-08-05 16:10:17,509 (MainThread): Re-using an available connection from the pool (formerly x_quest).
2019-08-05 16:10:17,514 (MainThread): Parsing model.analytics_augmentation_package.x_review
2019-08-05 16:10:17,515 (MainThread): Acquiring new postgres connection "x_review".
2019-08-05 16:10:17,515 (MainThread): Re-using an available connection from the pool (formerly x_referral_data).
2019-08-05 16:10:17,520 (MainThread): Parsing model.analytics_augmentation_package.x_rfx_topics
2019-08-05 16:10:17,521 (MainThread): Acquiring new postgres connection "x_rfx_topics".
2019-08-05 16:10:17,521 (MainThread): Re-using an available connection from the pool (formerly x_review).
2019-08-05 16:10:17,527 (MainThread): Parsing model.analytics_augmentation_package.x_solution_duration
2019-08-05 16:10:17,528 (MainThread): Acquiring new postgres connection "x_solution_duration".
2019-08-05 16:10:17,528 (MainThread): Re-using an available connection from the pool (formerly x_rfx_topics).
2019-08-05 16:10:17,533 (MainThread): Parsing model.analytics_augmentation_package.x_solution_duration_histogram_buckets
2019-08-05 16:10:17,534 (MainThread): Acquiring new postgres connection "x_solution_duration_histogram_buckets".
2019-08-05 16:10:17,534 (MainThread): Re-using an available connection from the pool (formerly x_solution_duration).
2019-08-05 16:10:17,540 (MainThread): Parsing model.analytics_augmentation_package.x_stages
2019-08-05 16:10:17,542 (MainThread): Acquiring new postgres connection "x_stages".
2019-08-05 16:10:17,542 (MainThread): Re-using an available connection from the pool (formerly x_solution_duration_histogram_buckets).
2019-08-05 16:10:17,548 (MainThread): Parsing model.analytics_augmentation_package.x_submission_histogram_buckets
2019-08-05 16:10:17,549 (MainThread): Acquiring new postgres connection "x_submission_histogram_buckets".
2019-08-05 16:10:17,549 (MainThread): Re-using an available connection from the pool (formerly x_stages).
2019-08-05 16:10:17,557 (MainThread): Parsing model.analytics_augmentation_package.x_unified_country_names
2019-08-05 16:10:17,558 (MainThread): Acquiring new postgres connection "x_unified_country_names".
2019-08-05 16:10:17,558 (MainThread): Re-using an available connection from the pool (formerly x_submission_histogram_buckets).
2019-08-05 16:10:17,571 (MainThread): Parsing model.analytics_augmentation_package.x_unified_date_table
2019-08-05 16:10:17,573 (MainThread): Acquiring new postgres connection "x_unified_date_table".
2019-08-05 16:10:17,573 (MainThread): Re-using an available connection from the pool (formerly x_unified_country_names).
2019-08-05 16:10:17,578 (MainThread): Parsing model.analytics_augmentation_package.x_userd_user_pic_updated
2019-08-05 16:10:17,579 (MainThread): Acquiring new postgres connection "x_userd_user_pic_updated".
2019-08-05 16:10:17,579 (MainThread): Re-using an available connection from the pool (formerly x_unified_date_table).
2019-08-05 16:10:17,587 (MainThread): Parsing snapshot.analytics_augmentation_package.profile_completion_snapshot
2019-08-05 16:10:17,588 (MainThread): Acquiring new postgres connection "profile_completion_snapshot".
2019-08-05 16:10:17,589 (MainThread): Re-using an available connection from the pool (formerly x_userd_user_pic_updated).
2019-08-05 16:10:17,676 (MainThread): Found 31 models, 0 tests, 1 snapshots, 0 analyses, 117 macros, 0 operations, 0 seed files, 0 sources
2019-08-05 16:10:17,680 (MainThread): 
2019-08-05 16:10:17,681 (MainThread): Acquiring new postgres connection "master".
2019-08-05 16:10:17,681 (MainThread): Re-using an available connection from the pool (formerly profile_completion_snapshot).
2019-08-05 16:10:17,698 (MainThread): Parsing macros\core.sql
2019-08-05 16:10:17,704 (MainThread): Parsing macros\adapters\common.sql
2019-08-05 16:10:17,754 (MainThread): Parsing macros\etc\datetime.sql
2019-08-05 16:10:17,766 (MainThread): Parsing macros\etc\get_custom_alias.sql
2019-08-05 16:10:17,768 (MainThread): Parsing macros\etc\get_custom_schema.sql
2019-08-05 16:10:17,771 (MainThread): Parsing macros\etc\get_relation_comment.sql
2019-08-05 16:10:17,773 (MainThread): Parsing macros\etc\is_incremental.sql
2019-08-05 16:10:17,776 (MainThread): Parsing macros\etc\query.sql
2019-08-05 16:10:17,777 (MainThread): Parsing macros\materializations\helpers.sql
2019-08-05 16:10:17,786 (MainThread): Parsing macros\materializations\common\merge.sql
2019-08-05 16:10:17,794 (MainThread): Parsing macros\materializations\incremental\incremental.sql
2019-08-05 16:10:17,803 (MainThread): Parsing macros\materializations\seed\seed.sql
2019-08-05 16:10:17,820 (MainThread): Parsing macros\materializations\snapshot\snapshot.sql
2019-08-05 16:10:17,841 (MainThread): Parsing macros\materializations\snapshot\snapshot_merge.sql
2019-08-05 16:10:17,844 (MainThread): Parsing macros\materializations\snapshot\strategies.sql
2019-08-05 16:10:17,857 (MainThread): Parsing macros\materializations\table\table.sql
2019-08-05 16:10:17,865 (MainThread): Parsing macros\materializations\view\create_or_replace_view.sql
2019-08-05 16:10:17,872 (MainThread): Parsing macros\materializations\view\view.sql
2019-08-05 16:10:17,879 (MainThread): Parsing macros\schema_tests\accepted_values.sql
2019-08-05 16:10:17,881 (MainThread): Parsing macros\schema_tests\not_null.sql
2019-08-05 16:10:17,884 (MainThread): Parsing macros\schema_tests\relationships.sql
2019-08-05 16:10:17,886 (MainThread): Parsing macros\schema_tests\unique.sql
2019-08-05 16:10:17,888 (MainThread): Parsing macros\adapters.sql
2019-08-05 16:10:17,902 (MainThread): Parsing macros\catalog.sql
2019-08-05 16:10:17,906 (MainThread): Parsing macros\relations.sql
2019-08-05 16:10:17,909 (MainThread): Parsing macros\materializations\snapshot_merge.sql
2019-08-05 16:10:18,071 (MainThread): Using postgres connection "master".
2019-08-05 16:10:18,072 (MainThread): On master: 
    select distinct nspname from pg_namespace
  
2019-08-05 16:10:18,143 (MainThread): SQL status: SELECT 103 in 0.07 seconds
2019-08-05 16:10:18,193 (MainThread): Using postgres connection "master".
2019-08-05 16:10:18,193 (MainThread): On master: BEGIN
2019-08-05 16:10:18,230 (MainThread): SQL status: BEGIN in 0.04 seconds
2019-08-05 16:10:18,231 (MainThread): Using postgres connection "master".
2019-08-05 16:10:18,231 (MainThread): On master: select
      'analyticsd' as database,
      tablename as name,
      schemaname as schema,
      'table' as type
    from pg_tables
    where schemaname ilike 'auxiliary_tables'
    union all
    select
      'analyticsd' as database,
      viewname as name,
      schemaname as schema,
      'view' as type
    from pg_views
    where schemaname ilike 'auxiliary_tables'
  
2019-08-05 16:10:18,272 (MainThread): SQL status: SELECT 1 in 0.04 seconds
2019-08-05 16:10:18,277 (MainThread): Using postgres connection "master".
2019-08-05 16:10:18,277 (MainThread): On master: select
      'analyticsd' as database,
      tablename as name,
      schemaname as schema,
      'table' as type
    from pg_tables
    where schemaname ilike 'public'
    union all
    select
      'analyticsd' as database,
      viewname as name,
      schemaname as schema,
      'view' as type
    from pg_views
    where schemaname ilike 'public'
  
2019-08-05 16:10:18,315 (MainThread): SQL status: SELECT 41 in 0.04 seconds
2019-08-05 16:10:18,410 (MainThread): Using postgres connection "master".
2019-08-05 16:10:18,411 (MainThread): On master: -- 
    -- 
    with relation as (
        select
            pg_rewrite.ev_class as class,
            pg_rewrite.oid as id
        from pg_rewrite
    ),
    class as (
        select
            oid as id,
            relname as name,
            relnamespace as schema,
            relkind as kind
        from pg_class
    ),
    dependency as (
        select
            pg_depend.objid as id,
            pg_depend.refobjid as ref
        from pg_depend
    ),
    schema as (
        select
            pg_namespace.oid as id,
            pg_namespace.nspname as name
        from pg_namespace
        where nspname != 'information_schema' and nspname not like 'pg_%'
    ),
    referenced as (
        select
            relation.id AS id,
            referenced_class.name ,
            referenced_class.schema ,
            referenced_class.kind
        from relation
        join class as referenced_class on relation.class=referenced_class.id
        where referenced_class.kind in ('r', 'v')
    ),
    relationships as (
        select
            referenced.name as referenced_name,
            referenced.schema as referenced_schema_id,
            dependent_class.name as dependent_name,
            dependent_class.schema as dependent_schema_id,
            referenced.kind as kind
        from referenced
        join dependency on referenced.id=dependency.id
        join class as dependent_class on dependency.ref=dependent_class.id
        where
            (referenced.name != dependent_class.name or
             referenced.schema != dependent_class.schema)
    )

    select
        referenced_schema.name as referenced_schema,
        relationships.referenced_name as referenced_name,
        dependent_schema.name as dependent_schema,
        relationships.dependent_name as dependent_name
    from relationships
    join schema as dependent_schema on relationships.dependent_schema_id=dependent_schema.id
    join schema as referenced_schema on relationships.referenced_schema_id=referenced_schema.id
    group by referenced_schema, referenced_name, dependent_schema, dependent_name
    order by referenced_schema, referenced_name, dependent_schema, dependent_name;
2019-08-05 16:10:18,459 (MainThread): SQL status: SELECT 45 in 0.05 seconds
2019-08-05 16:10:18,511 (MainThread): On master: ROLLBACK
2019-08-05 16:10:18,548 (MainThread): Using postgres connection "master".
2019-08-05 16:10:18,548 (MainThread): On master: BEGIN
2019-08-05 16:10:18,619 (MainThread): SQL status: BEGIN in 0.07 seconds
2019-08-05 16:10:18,620 (MainThread): On master: COMMIT
2019-08-05 16:10:18,620 (MainThread): Using postgres connection "master".
2019-08-05 16:10:18,620 (MainThread): On master: COMMIT
2019-08-05 16:10:18,656 (MainThread): SQL status: COMMIT in 0.04 seconds
2019-08-05 16:10:18,657 (MainThread): 16:10:18 | Concurrency: 6 threads (target='dev')
2019-08-05 16:10:18,658 (MainThread): 16:10:18 | 
2019-08-05 16:10:18,665 (Thread-1): 16:10:18 | 1 of 1 START snapshot profile_completion_snapshot.................... [RUN]
2019-08-05 16:10:18,666 (Thread-1): Acquiring new postgres connection "profile_completion_snapshot".
2019-08-05 16:10:18,666 (Thread-1): Opening a new connection, currently in state init
2019-08-05 16:10:18,890 (Thread-1): Compiling snapshot.analytics_augmentation_package.profile_completion_snapshot
2019-08-05 16:10:18,951 (Thread-1): Using postgres connection "profile_completion_snapshot".
2019-08-05 16:10:18,952 (Thread-1): On profile_completion_snapshot: 
    select count(*) from pg_namespace where nspname = 'auxiliary_tables'
  
2019-08-05 16:10:19,024 (Thread-1): SQL status: SELECT 1 in 0.07 seconds
2019-08-05 16:10:19,059 (Thread-1): Using postgres connection "profile_completion_snapshot".
2019-08-05 16:10:19,059 (Thread-1): On profile_completion_snapshot: select * from (
            

    
    
WITH daily_profile_data as
	(
		SELECT cast(CONCAT(cast(user_id as text),cast(Now() as text),cast('usr_accomplishments' as text)) as text) as id FROM x_snapshot.usr_accomplishments
		UNION
		SELECT cast(CONCAT(cast(user_id as text),cast(Now() as text),cast('usr_education' as text)) as text) as id FROM x_snapshot.usr_education
		UNION
		SELECT cast(CONCAT(cast(user_id as text),cast(Now() as text),cast('usr_experiences' as text)) as text) as id FROM x_snapshot.usr_experiences
		UNION
		SELECT cast(CONCAT(cast(user_id as text),cast(Now() as text),cast('usr_interests' as text)) as text) as id FROM x_snapshot.usr_interests
		UNION
		SELECT cast(CONCAT(cast(user_id as text),cast(Now() as text),cast('usr_languages' as text)) as text) as id FROM x_snapshot.usr_languages
		UNION
		SELECT cast(CONCAT(cast(user_id as text),cast(Now() as text),cast('usr_patents' as text)) as text) as id FROM x_snapshot.usr_patents
		UNION
		SELECT cast(CONCAT(cast(user_id as text),cast(Now() as text),cast('usr_publications' as text)) as text) as id FROM x_snapshot.usr_publications
		UNION
		SELECT cast(CONCAT(cast(user_id as text),cast(Now() as text),cast('usr_summary' as text)) as text) as id FROM x_snapshot.usr_summary
		UNION
		SELECT cast(CONCAT(cast(user_id as text),cast(Now() as text),cast('usr_websites' as text)) as text) as id FROM x_snapshot.usr_websites
	)
SELECT *
FROM daily_profile_data
WHERE id IS NOT NULL
    
        ) as __dbt_sbq
        where false
        limit 0
    
2019-08-05 16:10:19,096 (Thread-1): SQL status: SELECT 0 in 0.04 seconds
2019-08-05 16:10:19,102 (Thread-1): Using postgres connection "profile_completion_snapshot".
2019-08-05 16:10:19,103 (Thread-1): On profile_completion_snapshot: BEGIN
2019-08-05 16:10:19,138 (Thread-1): SQL status: BEGIN in 0.04 seconds
2019-08-05 16:10:19,139 (Thread-1): Using postgres connection "profile_completion_snapshot".
2019-08-05 16:10:19,139 (Thread-1): On profile_completion_snapshot: 
      select
          column_name,
          data_type,
          character_maximum_length,
          numeric_precision,
          numeric_scale

      from "analyticsd".information_schema.columns
      where table_name = 'profile_completion_snapshot'
        
        and table_schema = 'auxiliary_tables'
        
      order by ordinal_position

  
2019-08-05 16:10:19,184 (Thread-1): SQL status: SELECT 5 in 0.04 seconds
2019-08-05 16:10:19,211 (Thread-1): Using postgres connection "profile_completion_snapshot".
2019-08-05 16:10:19,212 (Thread-1): On profile_completion_snapshot: 
        create temporary table
    "profile_completion_snapshot__dbt_tmp20190805161019207525"
  as (
    with snapshot_query as (

        

    
    
WITH daily_profile_data as
	(
		SELECT cast(CONCAT(cast(user_id as text),cast(Now() as text),cast('usr_accomplishments' as text)) as text) as id FROM x_snapshot.usr_accomplishments
		UNION
		SELECT cast(CONCAT(cast(user_id as text),cast(Now() as text),cast('usr_education' as text)) as text) as id FROM x_snapshot.usr_education
		UNION
		SELECT cast(CONCAT(cast(user_id as text),cast(Now() as text),cast('usr_experiences' as text)) as text) as id FROM x_snapshot.usr_experiences
		UNION
		SELECT cast(CONCAT(cast(user_id as text),cast(Now() as text),cast('usr_interests' as text)) as text) as id FROM x_snapshot.usr_interests
		UNION
		SELECT cast(CONCAT(cast(user_id as text),cast(Now() as text),cast('usr_languages' as text)) as text) as id FROM x_snapshot.usr_languages
		UNION
		SELECT cast(CONCAT(cast(user_id as text),cast(Now() as text),cast('usr_patents' as text)) as text) as id FROM x_snapshot.usr_patents
		UNION
		SELECT cast(CONCAT(cast(user_id as text),cast(Now() as text),cast('usr_publications' as text)) as text) as id FROM x_snapshot.usr_publications
		UNION
		SELECT cast(CONCAT(cast(user_id as text),cast(Now() as text),cast('usr_summary' as text)) as text) as id FROM x_snapshot.usr_summary
		UNION
		SELECT cast(CONCAT(cast(user_id as text),cast(Now() as text),cast('usr_websites' as text)) as text) as id FROM x_snapshot.usr_websites
	)
SELECT *
FROM daily_profile_data
WHERE id IS NOT NULL
    

    ),

    source_data as (

        select *,
            
  
    md5(
        coalesce(cast(id as varchar ), '')  || '|' || 
    
        coalesce(cast(id as varchar ), '') 
    )

 as dbt_scd_id,
            id as dbt_unique_key,
            now()::timestamp without time zone as dbt_updated_at,
            now()::timestamp without time zone as dbt_valid_from,
            nullif(now()::timestamp without time zone, now()::timestamp without time zone) as dbt_valid_to

        from snapshot_query
    ),

    snapshotted_data as (

        select *,
            id as dbt_unique_key

        from "analyticsd"."auxiliary_tables"."profile_completion_snapshot"

    ),

    insertions as (

        select
            'insert' as dbt_change_type,
            source_data.*

        from source_data
        left outer join snapshotted_data on snapshotted_data.dbt_unique_key = source_data.dbt_unique_key
        where snapshotted_data.dbt_unique_key is null
           or (
                snapshotted_data.dbt_unique_key is not null
            and snapshotted_data.dbt_valid_to is null
            and (
                (
        
            snapshotted_data.id != source_data.id
            or
            (snapshotted_data.id is null) != (source_data.id is null)

        
        )
            )
        )

    )

    select * from insertions
  );

    
2019-08-05 16:10:19,438 (Thread-1): SQL status: SELECT 9024 in 0.23 seconds
2019-08-05 16:10:19,442 (Thread-1): Using postgres connection "profile_completion_snapshot".
2019-08-05 16:10:19,442 (Thread-1): On profile_completion_snapshot: 
        insert into "profile_completion_snapshot__dbt_tmp20190805161019207525" (dbt_change_type, dbt_scd_id, dbt_valid_to)
        select dbt_change_type, dbt_scd_id, dbt_valid_to from (
            with snapshot_query as (

        

    
    
WITH daily_profile_data as
	(
		SELECT cast(CONCAT(cast(user_id as text),cast(Now() as text),cast('usr_accomplishments' as text)) as text) as id FROM x_snapshot.usr_accomplishments
		UNION
		SELECT cast(CONCAT(cast(user_id as text),cast(Now() as text),cast('usr_education' as text)) as text) as id FROM x_snapshot.usr_education
		UNION
		SELECT cast(CONCAT(cast(user_id as text),cast(Now() as text),cast('usr_experiences' as text)) as text) as id FROM x_snapshot.usr_experiences
		UNION
		SELECT cast(CONCAT(cast(user_id as text),cast(Now() as text),cast('usr_interests' as text)) as text) as id FROM x_snapshot.usr_interests
		UNION
		SELECT cast(CONCAT(cast(user_id as text),cast(Now() as text),cast('usr_languages' as text)) as text) as id FROM x_snapshot.usr_languages
		UNION
		SELECT cast(CONCAT(cast(user_id as text),cast(Now() as text),cast('usr_patents' as text)) as text) as id FROM x_snapshot.usr_patents
		UNION
		SELECT cast(CONCAT(cast(user_id as text),cast(Now() as text),cast('usr_publications' as text)) as text) as id FROM x_snapshot.usr_publications
		UNION
		SELECT cast(CONCAT(cast(user_id as text),cast(Now() as text),cast('usr_summary' as text)) as text) as id FROM x_snapshot.usr_summary
		UNION
		SELECT cast(CONCAT(cast(user_id as text),cast(Now() as text),cast('usr_websites' as text)) as text) as id FROM x_snapshot.usr_websites
	)
SELECT *
FROM daily_profile_data
WHERE id IS NOT NULL
    

    ),

    source_data as (

        select
            *,
            
  
    md5(
        coalesce(cast(id as varchar ), '')  || '|' || 
    
        coalesce(cast(id as varchar ), '') 
    )

 as dbt_scd_id,
            id as dbt_unique_key,
            now()::timestamp without time zone as dbt_updated_at,
            now()::timestamp without time zone as dbt_valid_from

        from snapshot_query
    ),

    snapshotted_data as (

        select *,
            id as dbt_unique_key

        from "analyticsd"."auxiliary_tables"."profile_completion_snapshot"

    ),

    updates as (

        select
            'update' as dbt_change_type,
            snapshotted_data.dbt_scd_id,
            source_data.dbt_valid_from as dbt_valid_to

        from source_data
        join snapshotted_data on snapshotted_data.dbt_unique_key = source_data.dbt_unique_key
        where snapshotted_data.dbt_valid_to is null
        and (
            (
        
            snapshotted_data.id != source_data.id
            or
            (snapshotted_data.id is null) != (source_data.id is null)

        
        )
        )

    )

    select * from updates
        ) dbt_sbq;
    
2019-08-05 16:10:19,555 (Thread-1): SQL status: INSERT 0 0 in 0.11 seconds
2019-08-05 16:10:19,562 (Thread-1): Using postgres connection "profile_completion_snapshot".
2019-08-05 16:10:19,562 (Thread-1): On profile_completion_snapshot: 
      select
          column_name,
          data_type,
          character_maximum_length,
          numeric_precision,
          numeric_scale

      from information_schema.columns
      where table_name = 'profile_completion_snapshot__dbt_tmp20190805161019207525'
        
      order by ordinal_position

  
2019-08-05 16:10:19,602 (Thread-1): SQL status: SELECT 7 in 0.04 seconds
2019-08-05 16:10:19,608 (Thread-1): Using postgres connection "profile_completion_snapshot".
2019-08-05 16:10:19,609 (Thread-1): On profile_completion_snapshot: 
      select
          column_name,
          data_type,
          character_maximum_length,
          numeric_precision,
          numeric_scale

      from "analyticsd".information_schema.columns
      where table_name = 'profile_completion_snapshot'
        
        and table_schema = 'auxiliary_tables'
        
      order by ordinal_position

  
2019-08-05 16:10:19,647 (Thread-1): SQL status: SELECT 5 in 0.04 seconds
2019-08-05 16:10:19,653 (Thread-1): Using postgres connection "profile_completion_snapshot".
2019-08-05 16:10:19,654 (Thread-1): On profile_completion_snapshot: 
      select
          column_name,
          data_type,
          character_maximum_length,
          numeric_precision,
          numeric_scale

      from information_schema.columns
      where table_name = 'profile_completion_snapshot__dbt_tmp20190805161019207525'
        
      order by ordinal_position

  
2019-08-05 16:10:19,692 (Thread-1): SQL status: SELECT 7 in 0.04 seconds
2019-08-05 16:10:19,700 (Thread-1): Using postgres connection "profile_completion_snapshot".
2019-08-05 16:10:19,700 (Thread-1): On profile_completion_snapshot: 
      select
          column_name,
          data_type,
          character_maximum_length,
          numeric_precision,
          numeric_scale

      from "analyticsd".information_schema.columns
      where table_name = 'profile_completion_snapshot'
        
        and table_schema = 'auxiliary_tables'
        
      order by ordinal_position

  
2019-08-05 16:10:19,738 (Thread-1): SQL status: SELECT 5 in 0.04 seconds
2019-08-05 16:10:19,745 (Thread-1): Using postgres connection "profile_completion_snapshot".
2019-08-05 16:10:19,746 (Thread-1): On profile_completion_snapshot: 
      select
          column_name,
          data_type,
          character_maximum_length,
          numeric_precision,
          numeric_scale

      from information_schema.columns
      where table_name = 'profile_completion_snapshot__dbt_tmp20190805161019207525'
        
      order by ordinal_position

  
2019-08-05 16:10:19,784 (Thread-1): SQL status: SELECT 7 in 0.04 seconds
2019-08-05 16:10:19,796 (Thread-1): Writing runtime SQL for node "snapshot.analytics_augmentation_package.profile_completion_snapshot"
2019-08-05 16:10:19,804 (Thread-1): Using postgres connection "profile_completion_snapshot".
2019-08-05 16:10:19,805 (Thread-1): On profile_completion_snapshot: 
          update "analyticsd"."auxiliary_tables"."profile_completion_snapshot"
    set dbt_valid_to = DBT_INTERNAL_SOURCE.dbt_valid_to
    from "profile_completion_snapshot__dbt_tmp20190805161019207525" as DBT_INTERNAL_SOURCE
    where DBT_INTERNAL_SOURCE.dbt_scd_id = "analyticsd"."auxiliary_tables"."profile_completion_snapshot".dbt_scd_id
      and DBT_INTERNAL_SOURCE.dbt_change_type = 'update'
      and "analyticsd"."auxiliary_tables"."profile_completion_snapshot".dbt_valid_to is null;

    insert into "analyticsd"."auxiliary_tables"."profile_completion_snapshot" ("id", "dbt_scd_id", "dbt_updated_at", "dbt_valid_from", "dbt_valid_to")
    select DBT_INTERNAL_SOURCE."id",DBT_INTERNAL_SOURCE."dbt_scd_id",DBT_INTERNAL_SOURCE."dbt_updated_at",DBT_INTERNAL_SOURCE."dbt_valid_from",DBT_INTERNAL_SOURCE."dbt_valid_to"
    from "profile_completion_snapshot__dbt_tmp20190805161019207525" as DBT_INTERNAL_SOURCE
    where DBT_INTERNAL_SOURCE.dbt_change_type = 'insert';

      
2019-08-05 16:10:19,841 (Thread-1): Postgres error: failed to find conversion function from unknown to text

2019-08-05 16:10:19,842 (Thread-1): On profile_completion_snapshot: ROLLBACK
2019-08-05 16:10:19,881 (Thread-1): Sending event: {'category': 'dbt', 'action': 'run_model', 'label': 'a36623c4-4faa-43ca-a318-122fb313ac52', 'context': [<snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x0000018642205A90>]}
2019-08-05 16:10:20,023 (Thread-1): 16:10:20 | 1 of 1 ERROR snapshotting profile_completion_snapshot................ [ERROR in 1.21s]
2019-08-05 16:10:20,073 (MainThread): Using postgres connection "master".
2019-08-05 16:10:20,074 (MainThread): On master: BEGIN
2019-08-05 16:10:20,109 (MainThread): SQL status: BEGIN in 0.04 seconds
2019-08-05 16:10:20,110 (MainThread): On master: COMMIT
2019-08-05 16:10:20,110 (MainThread): Using postgres connection "master".
2019-08-05 16:10:20,110 (MainThread): On master: COMMIT
2019-08-05 16:10:20,146 (MainThread): SQL status: COMMIT in 0.04 seconds
2019-08-05 16:10:20,147 (MainThread): 16:10:20 | 
2019-08-05 16:10:20,147 (MainThread): 16:10:20 | Finished running 1 snapshots in 2.47s.
2019-08-05 16:10:20,147 (MainThread): Connection 'master' was left open.
2019-08-05 16:10:20,148 (MainThread): On master: Close
2019-08-05 16:10:20,148 (MainThread): Connection 'profile_completion_snapshot' was left open.
2019-08-05 16:10:20,149 (MainThread): On profile_completion_snapshot: Close
2019-08-05 16:10:20,160 (MainThread): 
2019-08-05 16:10:20,160 (MainThread): Completed with 1 errors:
2019-08-05 16:10:20,161 (MainThread): 
2019-08-05 16:10:20,161 (MainThread): Database Error in snapshot profile_completion_snapshot (snapshots\profile_completion_snapshot.sql)
2019-08-05 16:10:20,162 (MainThread):   failed to find conversion function from unknown to text
2019-08-05 16:10:20,163 (MainThread): 
Done. PASS=0 ERROR=1 SKIP=0 TOTAL=1
2019-08-05 16:10:20,164 (MainThread): Sending event: {'category': 'dbt', 'action': 'invocation', 'label': 'end', 'context': [<snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x00000186410252E8>, <snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x0000018642205588>, <snowplow_tracker.self_describing_json.SelfDescribingJson object at 0x0000018642205470>]}
2019-08-05 16:10:20,321 (MainThread): Flushing usage events

[drewbanin]

Thanks for this really thorough report @danielbcook! I was able to install postgres 9.6 locally, and I found that I see the exact same error message you do.

Here's a minimal test case:

-- snapshots/my_snapshot.sql

{% snapshot my_snapshot %}
    {{
        config(
            target_schema='archived_data',
            updated_at='loaded_at',
            strategy='timestamp',
            unique_key='number')
    }}

    select
        now() as loaded_at,
        1 as number

{% endsnapshot %}

Run it with:

dbt snapshot # should succeed
dbt snapshot # should fail

I was able to fix this by modifying the postgres implementation of postgres__snapshot_merge_sql to look like:

{% macro postgres__snapshot_merge_sql(target, source, insert_cols) -%}
    {%- set insert_cols_csv = insert_cols | join(', ') -%}

    update {{ target }}
    set dbt_valid_to = DBT_INTERNAL_SOURCE.dbt_valid_to
    from {{ source }} as DBT_INTERNAL_SOURCE
    where DBT_INTERNAL_SOURCE.dbt_scd_id = {{ target }}.dbt_scd_id
      and DBT_INTERNAL_SOURCE.dbt_change_type::text = 'update'::text
      and {{ target }}.dbt_valid_to is null;

    insert into {{ target }} ({{ insert_cols_csv }})
    select {% for column in insert_cols -%}
        DBT_INTERNAL_SOURCE.{{ column }} {%- if not loop.last %}, {%- endif %}
    {%- endfor %}
    from {{ source }} as DBT_INTERNAL_SOURCE
    where DBT_INTERNAL_SOURCE.dbt_change_type::text = 'insert'::text;
{% endmacro %}

It appears that the operative cast is in the lines:

and DBT_INTERNAL_SOURCE.dbt_change_type::text = 'update'::text

and

where DBT_INTERNAL_SOURCE.dbt_change_type::text = 'insert'::text;

Interestingly, we only need to cast the left side of the equality (eg. dbt_change_type::text). I totally expected the right side to be the problem! Let's cast them both for good measure.

Last thing to say here: dbt is intended for use with analytical databases, and its core support for postgres is a function of dbt's Redshift support. While I'm happy to make this particular change (I think we can sneak it in for the imminent 0.14.1 release), we will generally be less aggressive in prioritizing bug fixes that target postgres, and especially those that effect older version of postgres! This particular issue doesn't appear to be a problem on pg >= 11, for instance.

[danielbcook]

Yes! I’m two-for-two in valid bug reports. Thanks for considering this for a fix. Do you guys have a target date for 0.14.1? On Aug 5, 2019, at 7:13 PM, Drew Banin <notifications@github.com<mailto:notifications@github.com>> wrote: Thanks for this really thorough report @danielbcook<https://github.com/danielbcook>! I was able to install postgres 9.6 locally, and I found that I see the exact same error message you do. Here's a minimal test case:

…

-- snapshots/my_snapshot.sql {% snapshot my_snapshot %} {{ config( target_schema='archived_data', updated_at='loaded_at', strategy='timestamp', unique_key='number') }} select now() as loaded_at, 1 as number {% endsnapshot %} Run it with: dbt snapshot # should succeed dbt snapshot # should fail I was able to fix this by modifying the postgres implementation of postgres__snapshot_merge_sql to look like: {% macro postgres__snapshot_merge_sql(target, source, insert_cols) -%} {%- set insert_cols_csv = insert_cols | join(', ') -%} update {{ target }} set dbt_valid_to = DBT_INTERNAL_SOURCE.dbt_valid_to from {{ source }} as DBT_INTERNAL_SOURCE where DBT_INTERNAL_SOURCE.dbt_scd_id = {{ target }}.dbt_scd_id and DBT_INTERNAL_SOURCE.dbt_change_type::text = 'update'::text and {{ target }}.dbt_valid_to is null; insert into {{ target }} ({{ insert_cols_csv }}) select {% for column in insert_cols -%} DBT_INTERNAL_SOURCE.{{ column }} {%- if not loop.last %}, {%- endif %} {%- endfor %} from {{ source }} as DBT_INTERNAL_SOURCE where DBT_INTERNAL_SOURCE.dbt_change_type::text = 'insert'::text; {% endmacro %} It appears that the operative cast is in the lines: and DBT_INTERNAL_SOURCE.dbt_change_type::text = 'update'::text and where DBT_INTERNAL_SOURCE.dbt_change_type::text = 'insert'::text; Interestingly, we only need to cast the left side of the equality (eg. dbt_change_type::text). I totally expected the right side to be the problem! Let's cast them both for good measure. Last thing to say here: dbt is intended for use with analytical databases, and its core support for postgres is a function of dbt's Redshift support. While I'm happy to make this particular change (I think we can sneak it in for the imminent 0.14.1 release), we will generally be less aggressive in prioritizing bug fixes that target postgres, and especially those that effect older version of postgres! This particular issue doesn't appear to be a problem on pg >= 11, for instance. — You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub<#1665>, or mute the thread<https://github.com/notifications/unsubscribe-auth/AIUPWEUWBG5UD2MEONZEWYLQDDM35ANCNFSM4IJPUVHQ>.

[drewbanin]

Hoping to have an RC out tomorrow! We'll slip this in along with a couple of other in-progress changes -- should be live on all channels early next week!