*** Reading remote log from gs://europe-west1-rezco-composer-3ae89ff7-bucket/logs/udf_example/udf_table_fe/2018-05-24T00:00:00/1.log. [2018-05-25 09:04:56,528] {cli.py:374} INFO - Running on host airflow-worker-675d4978d-cvqqp [2018-05-25 09:04:56,622] {models.py:1196} INFO - Dependencies all met for [2018-05-25 09:04:56,635] {models.py:1196} INFO - Dependencies all met for [2018-05-25 09:04:56,636] {models.py:1406} INFO - -------------------------------------------------------------------------------- Starting attempt 1 of 2 -------------------------------------------------------------------------------- [2018-05-25 09:04:56,694] {models.py:1427} INFO - Executing on 2018-05-24 00:00:00 [2018-05-25 09:04:56,694] {base_task_runner.py:115} INFO - Running: ['bash', '-c', u'airflow run udf_example udf_table_fe 2018-05-24T00:00:00 --job_id 896 --raw -sd DAGS_FOLDER/UDF_example.py'] [2018-05-25 09:04:59,100] {base_task_runner.py:98} INFO - Subtask: [2018-05-25 09:04:59,100] {configuration.py:206} WARNING - section/key [celery/celery_ssl_active] not found in config [2018-05-25 09:04:59,104] {base_task_runner.py:98} INFO - Subtask: [2018-05-25 09:04:59,103] {default_celery.py:41} WARNING - Celery Executor will run without SSL [2018-05-25 09:04:59,106] {base_task_runner.py:98} INFO - Subtask: [2018-05-25 09:04:59,105] {__init__.py:45} INFO - Using executor CeleryExecutor [2018-05-25 09:04:59,160] {base_task_runner.py:98} INFO - Subtask: [2018-05-25 09:04:59,160] {app.py:42} ERROR - Failed to update environment from json. [2018-05-25 09:04:59,163] {base_task_runner.py:98} INFO - Subtask: [2018-05-25 09:04:59,162] {configuration.py:389} INFO - Reading the config from /etc/airflow/airflow.cfg [2018-05-25 09:04:59,194] {base_task_runner.py:98} INFO - Subtask: [2018-05-25 09:04:59,193] {models.py:189} INFO - Filling up the DagBag from /home/airflow/gcs/dags/UDF_example.py [2018-05-25 09:04:59,683] {base_task_runner.py:98} INFO - Subtask: ['CREATE TEMPORARY FUNCTION multiplyInputs(x FLOAT64, y FLOAT64)\n RETURNS FLOAT64\n LANGUAGE js AS """\n return x*y;\n """;\n '] [2018-05-25 09:04:59,685] {base_task_runner.py:98} INFO - Subtask: WITH numbers AS [2018-05-25 09:04:59,685] {base_task_runner.py:98} INFO - Subtask: (SELECT 1 AS x, 5 as y [2018-05-25 09:04:59,685] {base_task_runner.py:98} INFO - Subtask: UNION ALL [2018-05-25 09:04:59,686] {base_task_runner.py:98} INFO - Subtask: SELECT 2 AS x, 10 as y [2018-05-25 09:04:59,686] {base_task_runner.py:98} INFO - Subtask: UNION ALL [2018-05-25 09:04:59,686] {base_task_runner.py:98} INFO - Subtask: SELECT 3 as x, 15 as y) [2018-05-25 09:04:59,687] {base_task_runner.py:98} INFO - Subtask: SELECT x, y, multiplyInputs(x, y) as product [2018-05-25 09:04:59,687] {base_task_runner.py:98} INFO - Subtask: FROM numbers [2018-05-25 09:04:59,687] {base_task_runner.py:98} INFO - Subtask: [2018-05-25 09:04:59,682] {bigquery_operator.py:90} INFO - Executing: WITH numbers AS [2018-05-25 09:04:59,688] {base_task_runner.py:98} INFO - Subtask: (SELECT 1 AS x, 5 as y [2018-05-25 09:04:59,688] {base_task_runner.py:98} INFO - Subtask: UNION ALL [2018-05-25 09:04:59,689] {base_task_runner.py:98} INFO - Subtask: SELECT 2 AS x, 10 as y [2018-05-25 09:04:59,690] {base_task_runner.py:98} INFO - Subtask: UNION ALL [2018-05-25 09:04:59,690] {base_task_runner.py:98} INFO - Subtask: SELECT 3 as x, 15 as y) [2018-05-25 09:04:59,690] {base_task_runner.py:98} INFO - Subtask: SELECT x, y, multiplyInputs(x, y) as product [2018-05-25 09:04:59,691] {base_task_runner.py:98} INFO - Subtask: FROM numbers [2018-05-25 09:04:59,712] {base_task_runner.py:98} INFO - Subtask: [2018-05-25 09:04:59,712] {gcp_api_base_hook.py:72} INFO - Getting connection using `gcloud auth` user, since no key file is defined for hook. [2018-05-25 09:04:59,750] {base_task_runner.py:98} INFO - Subtask: [2018-05-25 09:04:59,749] {discovery.py:852} INFO - URL being requested: POST https://www.googleapis.com/bigquery/v2/projects/vital-platform-791/jobs?alt=json [2018-05-25 09:04:59,753] {base_task_runner.py:98} INFO - Subtask: [2018-05-25 09:04:59,750] {client.py:595} INFO - Attempting refresh to obtain initial access_token [2018-05-25 09:05:00,069] {base_task_runner.py:98} INFO - Subtask: [2018-05-25 09:05:00,069] {discovery.py:852} INFO - URL being requested: GET https://www.googleapis.com/bigquery/v2/projects/vital-platform-791/jobs/job_RVbUNMmg-LwXpNRpRekhFHVmqAbv?alt=json [2018-05-25 09:05:00,287] {base_task_runner.py:98} INFO - Subtask: Traceback (most recent call last): [2018-05-25 09:05:00,288] {base_task_runner.py:98} INFO - Subtask: File "/usr/local/bin/airflow", line 27, in [2018-05-25 09:05:00,289] {base_task_runner.py:98} INFO - Subtask: args.func(args) [2018-05-25 09:05:00,289] {base_task_runner.py:98} INFO - Subtask: File "/usr/local/lib/python2.7/site-packages/airflow/bin/cli.py", line 392, in run [2018-05-25 09:05:00,290] {base_task_runner.py:98} INFO - Subtask: pool=args.pool, [2018-05-25 09:05:00,290] {base_task_runner.py:98} INFO - Subtask: File "/usr/local/lib/python2.7/site-packages/airflow/utils/db.py", line 50, in wrapper [2018-05-25 09:05:00,290] {base_task_runner.py:98} INFO - Subtask: result = func(*args, **kwargs) [2018-05-25 09:05:00,291] {base_task_runner.py:98} INFO - Subtask: File "/usr/local/lib/python2.7/site-packages/airflow/models.py", line 1492, in _run_raw_task [2018-05-25 09:05:00,291] {base_task_runner.py:98} INFO - Subtask: result = task_copy.execute(context=context) [2018-05-25 09:05:00,292] {base_task_runner.py:98} INFO - Subtask: File "/usr/local/lib/python2.7/site-packages/airflow/contrib/operators/bigquery_operator.py", line 98, in execute [2018-05-25 09:05:00,292] {base_task_runner.py:98} INFO - Subtask: self.create_disposition, self.query_params) [2018-05-25 09:05:00,293] {base_task_runner.py:98} INFO - Subtask: File "/usr/local/lib/python2.7/site-packages/airflow/contrib/hooks/bigquery_hook.py", line 499, in run_query [2018-05-25 09:05:00,293] {base_task_runner.py:98} INFO - Subtask: return self.run_with_configuration(configuration) [2018-05-25 09:05:00,294] {base_task_runner.py:98} INFO - Subtask: File "/usr/local/lib/python2.7/site-packages/airflow/contrib/hooks/bigquery_hook.py", line 853, in run_with_configuration [2018-05-25 09:05:00,294] {base_task_runner.py:98} INFO - Subtask: format(job['status']['errorResult'], job)) [2018-05-25 09:05:00,299] {base_task_runner.py:98} INFO - Subtask: Exception: BigQuery job failed. Final error was: {u'reason': u'invalidQuery', u'message': u'Function not found: multiplyInputs at [7:26]', u'location': u'query'}. The job was: {u'status': {u'state': u'DONE', u'errors': [{u'reason': u'invalidQuery', u'message': u'Function not found: multiplyInputs at [7:26]', u'location': u'query'}], u'errorResult': {u'reason': u'invalidQuery', u'message': u'Function not found: multiplyInputs at [7:26]', u'location': u'query'}}, u'kind': u'bigquery#job', u'statistics': {u'endTime': u'1527239099960', u'creationTime': u'1527239099891', u'startTime': u'1527239099960'}, u'jobReference': {u'projectId': u'vital-platform-791', u'location': u'EU', u'jobId': u'job_RVbUNMmg-LwXpNRpRekhFHVmqAbv'}, u'etag': u'"72k7DzeyeEl4shlhGfnZD_UwX04/Ah69YFn3b-Wq7v9CkBT4-DIDS5M"', u'user_email': u'599199898886-compute@developer.gserviceaccount.com', u'configuration': {u'query': {u'useLegacySql': False, u'destinationTable': {u'projectId': u'vital-platform-791', u'tableId': u'udf_table_fe', u'datasetId': u'alpha_factors'}, u'priority': u'INTERACTIVE', u'writeDisposition': u'WRITE_TRUNCATE', u'allowLargeResults': False, u'createDisposition': u'CREATE_IF_NEEDED', u'query': u'WITH numbers AS\n (SELECT 1 AS x, 5 as y\n UNION ALL\n SELECT 2 AS x, 10 as y\n UNION ALL\n SELECT 3 as x, 15 as y)\n SELECT x, y, multiplyInputs(x, y) as product\n FROM numbers'}}, u'id': u'vital-platform-791:EU.job_RVbUNMmg-LwXpNRpRekhFHVmqAbv', u'selfLink': u'https://www.googleapis.com/bigquery/v2/projects/vital-platform-791/jobs/job_RVbUNMmg-LwXpNRpRekhFHVmqAbv?location=EU'}