search

apache / dolphinscheduler

Apache DolphinScheduler is the modern data orchestration platform. Agile to create high performance workflow with low-code
https://dolphinscheduler.apache.org/
Apache License 2.0
12.8k stars 4.6k forks source link

[Bug][Task instance] The task instance shows an error? #4523

Closed masterable closed 3 years ago

masterable commented 3 years ago

For better global communication, Please describe it in English. If you feel the description in English is not clear, then you can append description in Chinese(just for Mandarin(CN)), thx! Describe the bug A clear and concise description of what the bug is. When I ended a data import instance Its status is shown as failed But when I check the log, the log information shows that the data import is complete

To Reproduce Steps to reproduce the behavior, for example:

  1. Go to '...'
  2. Click on '....'
  3. Scroll down to '....'
  4. See error figure 1 image figure 2 image What caused this bug？

Expected behavior A clear and concise description of what you expected to happen.

Screenshots If applicable, add screenshots to help explain your problem.

Which version of Dolphin Scheduler: -[1.3.3-preview]

Additional context Add any other context about the problem here.

Requirement or improvement

zhuangchong commented 3 years ago

Could you please send the execution context in the worker log file to help locate the problem

masterable commented 3 years ago

您能否在工作日志中发送执行上下文，以帮助定位问题

报错日志 [INFO] 2021-01-21 20:43:45.092 - [taskAppId=TASK-1-30-44]:[127] - -> Warning: /opt/module/app/sqoop-1.4.7/../hcatalog does not exist! HCatalog jobs will fail. Please set $HCAT_HOME to the root of your HCatalog installation. Warning: /opt/module/app/sqoop-1.4.7/../accumulo does not exist! Accumulo imports will fail. Please set $ACCUMULO_HOME to the root of your Accumulo installation. 2021-01-21 20:43:45,091 INFO sqoop.Sqoop: Running Sqoop version: 1.4.7 [INFO] 2021-01-21 20:43:47.793 - [taskAppId=TASK-1-30-44]:[127] - -> 2021-01-21 20:43:45,170 WARN tool.BaseSqoopTool: Setting your password on the command-line is insecure. Consider using -P instead. 2021-01-21 20:43:45,172 INFO tool.BaseSqoopTool: Using Hive-specific delimiters for output. You can override 2021-01-21 20:43:45,172 INFO tool.BaseSqoopTool: delimiters with --fields-terminated-by, etc. 2021-01-21 20:43:45,295 INFO manager.MySQLManager: Preparing to use a MySQL streaming resultset. 2021-01-21 20:43:45,302 INFO tool.CodeGenTool: Beginning code generation Thu Jan 21 20:43:45 CST 2021 WARN: Establishing SSL connection without server's identity verification is not recommended. According to MySQL 5.5.45+, 5.6.26+ and 5.7.6+ requirements SSL connection must be established by default if explicit option isn't set. For compliance with existing applications not using SSL the verifyServerCertificate property is set to 'false'. You need either to explicitly disable SSL by setting useSSL=false, or set useSSL=true and provide truststore for server certificate verification. 2021-01-21 20:43:45,656 INFO manager.SqlManager: Executing SQL statement: SELECT t. FROM ew_client_extend AS t LIMIT 1 2021-01-21 20:43:45,684 INFO manager.SqlManager: Executing SQL statement: SELECT t. FROM ew_client_extend AS t LIMIT 1 2021-01-21 20:43:45,694 INFO orm.CompilationManager: HADOOP_MAPRED_HOME is /opt/module/app/hadoop-3.0.3 Note: /tmp/sqoop-hadoop/compile/0b3403fb2d392ce9f460eb7439b317d7/ew_client_extend.java uses or overrides a deprecated API. [INFO] 2021-01-21 20:43:48.936 - [taskAppId=TASK-1-30-44]:[127] - -> Note: Recompile with -Xlint:deprecation for details. 2021-01-21 20:43:47,796 INFO orm.CompilationManager: Writing jar file: /tmp/sqoop-hadoop/compile/0b3403fb2d392ce9f460eb7439b317d7/ew_client_extend.jar 2021-01-21 20:43:48,935 INFO tool.ImportTool: Destination directory ew_client_extend is not present, hence not deleting. [INFO] 2021-01-21 20:43:56.376 - [taskAppId=TASK-1-30-44]:[127] - -> 2021-01-21 20:43:48,936 WARN manager.MySQLManager: It looks like you are importing from mysql. 2021-01-21 20:43:48,936 WARN manager.MySQLManager: This transfer can be faster! Use the --direct 2021-01-21 20:43:48,936 WARN manager.MySQLManager: option to exercise a MySQL-specific fast path. 2021-01-21 20:43:48,936 INFO manager.MySQLManager: Setting zero DATETIME behavior to convertToNull (mysql) 2021-01-21 20:43:48,942 INFO mapreduce.ImportJobBase: Beginning import of ew_client_extend 2021-01-21 20:43:48,944 INFO Configuration.deprecation: mapred.job.tracker is deprecated. Instead, use mapreduce.jobtracker.address 2021-01-21 20:43:48,951 INFO Configuration.deprecation: mapred.jar is deprecated. Instead, use mapreduce.job.jar 2021-01-21 20:43:48,971 INFO Configuration.deprecation: mapred.map.tasks is deprecated. Instead, use mapreduce.job.maps 2021-01-21 20:43:49,043 INFO client.RMProxy: Connecting to ResourceManager at /xxx.xxx.xxx.xx:8032 2021-01-21 20:43:49,839 INFO mapreduce.JobResourceUploader: Disabling Erasure Coding for path: /tmp/hadoop-yarn/staging/hadoop/.staging/job_1611138063868_0050 Thu Jan 21 20:43:56 CST 2021 WARN: Establishing SSL connection without server's identity verification is not recommended. According to MySQL 5.5.45+, 5.6.26+ and 5.7.6+ requirements SSL connection must be established by default if explicit option isn't set. For compliance with existing applications not using SSL the verifyServerCertificate property is set to 'false'. You need either to explicitly disable SSL by setting useSSL=false, or set useSSL=true and provide truststore for server certificate verification. [INFO] 2021-01-21 20:44:18.133 - [taskAppId=TASK-1-30-44]:[127] - -> 2021-01-21 20:43:56,385 INFO db.DBInputFormat: Using read commited transaction isolation 2021-01-21 20:43:56,536 INFO mapreduce.JobSubmitter: number of splits:1 2021-01-21 20:43:56,593 INFO Configuration.deprecation: yarn.resourcemanager.zk-address is deprecated. Instead, use hadoop.zk.address 2021-01-21 20:43:56,593 INFO Configuration.deprecation: yarn.resourcemanager.system-metrics-publisher.enabled is deprecated. Instead, use yarn.system-metrics-publisher.enabled 2021-01-21 20:43:56,694 INFO mapreduce.JobSubmitter: Submitting tokens for job: job_1611138063868_0050 2021-01-21 20:43:56,696 INFO mapreduce.JobSubmitter: Executing with tokens: [] 2021-01-21 20:43:56,908 INFO conf.Configuration: resource-types.xml not found 2021-01-21 20:43:56,909 INFO resource.ResourceUtils: Unable to find 'resource-types.xml'. 2021-01-21 20:43:56,983 INFO impl.YarnClientImpl: Submitted application application_1611138063868_0050 2021-01-21 20:43:57,019 INFO mapreduce.Job: The url to track the job: http://xxxxxxx:8088/proxy/application_1611138063868_0050/ 2021-01-21 20:43:57,020 INFO mapreduce.Job: Running job: job_1611138063868_0050 2021-01-21 20:44:18,133 INFO mapreduce.Job: Job job_1611138063868_0050 running in uber mode : false [INFO] 2021-01-21 20:45:08.370 - [taskAppId=TASK-1-30-44]:[127] - -> 2021-01-21 20:44:18,134 INFO mapreduce.Job: map 0% reduce 0% 2021-01-21 20:45:08,370 INFO mapreduce.Job: map 100% reduce 0% [INFO] 2021-01-21 20:45:13.237 - [taskAppId=TASK-1-30-44]:[127] - -> 2021-01-21 20:45:08,378 INFO mapreduce.Job: Job job_1611138063868_0050 completed successfully 2021-01-21 20:45:08,467 INFO mapreduce.Job: Counters: 32 File System Counters FILE: Number of bytes read=0 FILE: Number of bytes written=214715 FILE: Number of read operations=0 FILE: Number of large read operations=0 FILE: Number of write operations=0 HDFS: Number of bytes read=87 HDFS: Number of bytes written=405641822 HDFS: Number of read operations=6 HDFS: Number of large read operations=0 HDFS: Number of write operations=2 Job Counters Launched map tasks=1 Other local map tasks=1 Total time spent by all maps in occupied slots (ms)=95816 Total time spent by all reduces in occupied slots (ms)=0 Total time spent by all map tasks (ms)=47908 Total vcore-milliseconds taken by all map tasks=47908 Total megabyte-milliseconds taken by all map tasks=49057792 Map-Reduce Framework Map input records=1006930 Map output records=1006930 Input split bytes=87 Spilled Records=0 Failed Shuffles=0 Merged Map outputs=0 GC time elapsed (ms)=218 CPU time spent (ms)=33160 Physical memory (bytes) snapshot=463380480 Virtual memory (bytes) snapshot=2676310016 Total committed heap usage (bytes)=398458880 Peak Map Physical memory (bytes)=469815296 Peak Map Virtual memory (bytes)=2694959104 File Input Format Counters Bytes Read=0 File Output Format Counters Bytes Written=405641822 2021-01-21 20:45:08,477 INFO mapreduce.ImportJobBase: Transferred 386.8502 MB in 79.4935 seconds (4.8664 MB/sec) 2021-01-21 20:45:08,480 INFO mapreduce.ImportJobBase: Retrieved 1006930 records. 2021-01-21 20:45:08,480 INFO mapreduce.ImportJobBase: Publishing Hive/Hcat import job data to Listeners for table ew_client_extend Thu Jan 21 20:45:08 CST 2021 WARN: Establishing SSL connection without server's identity verification is not recommended. According to MySQL 5.5.45+, 5.6.26+ and 5.7.6+ requirements SSL connection must be established by default if explicit option isn't set. For compliance with existing applications not using SSL the verifyServerCertificate property is set to 'false'. You need either to explicitly disable SSL by setting useSSL=false, or set useSSL=true and provide truststore for server certificate verification. 2021-01-21 20:45:08,497 INFO manager.SqlManager: Executing SQL statement: SELECT t.* FROM ew_client_extend AS t LIMIT 1 2021-01-21 20:45:08,508 WARN hive.TableDefWriter: Column create_time had to be cast to a less precise type in Hive 2021-01-21 20:45:08,508 WARN hive.TableDefWriter: Column update_time had to be cast to a less precise type in Hive 2021-01-21 20:45:08,508 WARN hive.TableDefWriter: Column earliest_create_time had to be cast to a less precise type in Hive 2021-01-21 20:45:08,523 INFO hive.HiveImport: Loading uploaded data into Hive 2021-01-21 20:45:08,532 INFO conf.HiveConf: Found configuration file file:/opt/module/app/hive-3.1.2/conf/hive-site.xml 2021-01-21 20:45:13,236 INFO hive.HiveImport: 2021-01-21 20:45:13,230 [myid:] - INFO [main:HiveConf@187] - Found configuration file file:/opt/module/app/hive-3.1.2/conf/hive-site.xml [INFO] 2021-01-21 20:45:16.637 - [taskAppId=TASK-1-30-44]:[127] - -> 2021-01-21 20:45:16,636 INFO hive.HiveImport: Hive Session ID = b7fdc24f-10a2-44a1-8e39-b9601da93a17 [INFO] 2021-01-21 20:45:18.169 - [taskAppId=TASK-1-30-44]:[127] - -> 2021-01-21 20:45:16,637 INFO hive.HiveImport: 2021-01-21 20:45:16,636 [myid:] - INFO [main:SessionState$LogHelper@1227] - Hive Session ID = b7fdc24f-10a2-44a1-8e39-b9601da93a17 2021-01-21 20:45:16,698 INFO hive.HiveImport: 2021-01-21 20:45:16,698 INFO hive.HiveImport: Logging initialized using configuration in jar:file:/opt/module/app/hive-3.1.2/lib/hive-common-3.1.2.jar!/hive-log4j2.properties Async: true 2021-01-21 20:45:16,698 INFO hive.HiveImport: 2021-01-21 20:45:16,698 [myid:] - INFO [main:SessionState$LogHelper@1227] - 2021-01-21 20:45:16,698 INFO hive.HiveImport: Logging initialized using configuration in jar:file:/opt/module/app/hive-3.1.2/lib/hive-common-3.1.2.jar!/hive-log4j2.properties Async: true 2021-01-21 20:45:18,169 INFO hive.HiveImport: 2021-01-21 20:45:18,168 [myid:] - INFO [main:SessionState@790] - Created HDFS directory: /tmp/hive/hadoop/b7fdc24f-10a2-44a1-8e39-b9601da93a17 [INFO] 2021-01-21 20:45:19.340 - [taskAppId=TASK-1-30-44]:[127] - -> 2021-01-21 20:45:18,190 INFO hive.HiveImport: 2021-01-21 20:45:18,190 [myid:] - INFO [main:SessionState@790] - Created local directory: /tmp/hadoop/b7fdc24f-10a2-44a1-8e39-b9601da93a17 2021-01-21 20:45:18,200 INFO hive.HiveImport: 2021-01-21 20:45:18,199 [myid:] - INFO [main:SessionState@790] - Created HDFS directory: /tmp/hive/hadoop/b7fdc24f-10a2-44a1-8e39-b9601da93a17/_tmp_space.db 2021-01-21 20:45:18,202 INFO hive.HiveImport: 2021-01-21 20:45:18,201 [myid:] - INFO [main:HiveConf@5040] - Using the default value passed in for log id: b7fdc24f-10a2-44a1-8e39-b9601da93a17 2021-01-21 20:45:18,202 INFO hive.HiveImport: 2021-01-21 20:45:18,202 [myid:] - INFO [main:SessionState@441] - Updating thread name to b7fdc24f-10a2-44a1-8e39-b9601da93a17 main 2021-01-21 20:45:19,339 INFO hive.HiveImport: 2021-01-21 20:45:19,339 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:HiveMetaStore$HMSHandler@717] - 0: Opening raw store with implementation class:org.apache.hadoop.hive.metastore.ObjectStore [INFO] 2021-01-21 20:45:20.391 - [taskAppId=TASK-1-30-44]:[127] - -> 2021-01-21 20:45:19,368 INFO hive.HiveImport: 2021-01-21 20:45:19,367 [myid:] - WARN [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:ObjectStore@638] - datanucleus.autoStartMechanismMode is set to unsupported value null . Setting it to value: ignored 2021-01-21 20:45:19,381 INFO hive.HiveImport: 2021-01-21 20:45:19,381 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:ObjectStore@481] - ObjectStore, initialize called 2021-01-21 20:45:19,383 INFO hive.HiveImport: 2021-01-21 20:45:19,383 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:MetastoreConf@1240] - Found configuration file file:/opt/module/app/hive-3.1.2/conf/hive-site.xml 2021-01-21 20:45:19,384 INFO hive.HiveImport: 2021-01-21 20:45:19,384 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:MetastoreConf@1233] - Unable to find config file hivemetastore-site.xml 2021-01-21 20:45:19,384 INFO hive.HiveImport: 2021-01-21 20:45:19,384 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:MetastoreConf@1240] - Found configuration file null 2021-01-21 20:45:19,386 INFO hive.HiveImport: 2021-01-21 20:45:19,385 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:MetastoreConf@1233] - Unable to find config file metastore-site.xml 2021-01-21 20:45:19,387 INFO hive.HiveImport: 2021-01-21 20:45:19,385 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:MetastoreConf@1240] - Found configuration file null 2021-01-21 20:45:19,552 INFO hive.HiveImport: 2021-01-21 20:45:19,552 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:Log4JLogger@77] - Property datanucleus.cache.level2 unknown - will be ignored 2021-01-21 20:45:19,747 INFO hive.HiveImport: 2021-01-21 20:45:19,747 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:HikariDataSource@71] - HikariPool-1 - Starting... 2021-01-21 20:45:20,000 INFO hive.HiveImport: 2021-01-21 20:45:20,000 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:HikariDataSource@73] - HikariPool-1 - Start completed. 2021-01-21 20:45:20,041 INFO hive.HiveImport: 2021-01-21 20:45:20,040 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:HikariDataSource@71] - HikariPool-2 - Starting... 2021-01-21 20:45:20,049 INFO hive.HiveImport: 2021-01-21 20:45:20,048 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:HikariDataSource@73] - HikariPool-2 - Start completed. 2021-01-21 20:45:20,102 INFO hive.HiveImport: 2021-01-21 20:45:20,101 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:ObjectStore@670] - Setting MetaStore object pin classes with hive.metastore.cache.pinobjtypes="Table,StorageDescriptor,SerDeInfo,Partition,Database,Type,FieldSchema,Order" 2021-01-21 20:45:20,214 INFO hive.HiveImport: 2021-01-21 20:45:20,214 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:MetaStoreDirectSql@186] - Using direct SQL, underlying DB is MYSQL 2021-01-21 20:45:20,216 INFO hive.HiveImport: 2021-01-21 20:45:20,215 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:ObjectStore@396] - Initialized ObjectStore 2021-01-21 20:45:20,391 INFO hive.HiveImport: 2021-01-21 20:45:20,391 [myid:] - WARN [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:Log4JLogger@96] - Metadata has jdbc-type of null yet this is not valid. Ignored [INFO] 2021-01-21 20:45:22.258 - [taskAppId=TASK-1-30-44]:[127] - -> 2021-01-21 20:45:20,392 INFO hive.HiveImport: 2021-01-21 20:45:20,392 [myid:] - WARN [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:Log4JLogger@96] - Metadata has jdbc-type of null yet this is not valid. Ignored 2021-01-21 20:45:20,393 INFO hive.HiveImport: 2021-01-21 20:45:20,392 [myid:] - WARN [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:Log4JLogger@96] - Metadata has jdbc-type of null yet this is not valid. Ignored 2021-01-21 20:45:20,393 INFO hive.HiveImport: 2021-01-21 20:45:20,393 [myid:] - WARN [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:Log4JLogger@96] - Metadata has jdbc-type of null yet this is not valid. Ignored 2021-01-21 20:45:20,394 INFO hive.HiveImport: 2021-01-21 20:45:20,393 [myid:] - WARN [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:Log4JLogger@96] - Metadata has jdbc-type of null yet this is not valid. Ignored 2021-01-21 20:45:20,394 INFO hive.HiveImport: 2021-01-21 20:45:20,394 [myid:] - WARN [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:Log4JLogger@96] - Metadata has jdbc-type of null yet this is not valid. Ignored 2021-01-21 20:45:22,257 INFO hive.HiveImport: 2021-01-21 20:45:22,257 [myid:] - WARN [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:Log4JLogger@96] - Metadata has jdbc-type of null yet this is not valid. Ignored [INFO] 2021-01-21 20:45:24.051 - [taskAppId=TASK-1-30-44]:[127] - -> 2021-01-21 20:45:22,258 INFO hive.HiveImport: 2021-01-21 20:45:22,258 [myid:] - WARN [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:Log4JLogger@96] - Metadata has jdbc-type of null yet this is not valid. Ignored 2021-01-21 20:45:22,259 INFO hive.HiveImport: 2021-01-21 20:45:22,258 [myid:] - WARN [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:Log4JLogger@96] - Metadata has jdbc-type of null yet this is not valid. Ignored 2021-01-21 20:45:22,259 INFO hive.HiveImport: 2021-01-21 20:45:22,259 [myid:] - WARN [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:Log4JLogger@96] - Metadata has jdbc-type of null yet this is not valid. Ignored 2021-01-21 20:45:22,259 INFO hive.HiveImport: 2021-01-21 20:45:22,259 [myid:] - WARN [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:Log4JLogger@96] - Metadata has jdbc-type of null yet this is not valid. Ignored 2021-01-21 20:45:22,260 INFO hive.HiveImport: 2021-01-21 20:45:22,259 [myid:] - WARN [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:Log4JLogger@96] - Metadata has jdbc-type of null yet this is not valid. Ignored 2021-01-21 20:45:24,051 INFO hive.HiveImport: 2021-01-21 20:45:24,049 [myid:] - WARN [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:Log4JLogger@96] - Metadata has jdbc-type of null yet this is not valid. Ignored [INFO] 2021-01-21 20:45:27.140 - [taskAppId=TASK-1-30-44]:[127] - -> 2021-01-21 20:45:24,052 INFO hive.HiveImport: 2021-01-21 20:45:24,051 [myid:] - WARN [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:Log4JLogger@96] - Metadata has jdbc-type of null yet this is not valid. Ignored 2021-01-21 20:45:24,052 INFO hive.HiveImport: 2021-01-21 20:45:24,052 [myid:] - WARN [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:Log4JLogger@96] - Metadata has jdbc-type of null yet this is not valid. Ignored 2021-01-21 20:45:24,053 INFO hive.HiveImport: 2021-01-21 20:45:24,052 [myid:] - WARN [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:Log4JLogger@96] - Metadata has jdbc-type of null yet this is not valid. Ignored 2021-01-21 20:45:24,053 INFO hive.HiveImport: 2021-01-21 20:45:24,053 [myid:] - WARN [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:Log4JLogger@96] - Metadata has jdbc-type of null yet this is not valid. Ignored 2021-01-21 20:45:24,054 INFO hive.HiveImport: 2021-01-21 20:45:24,054 [myid:] - WARN [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:Log4JLogger@96] - Metadata has jdbc-type of null yet this is not valid. Ignored 2021-01-21 20:45:27,140 INFO hive.HiveImport: 2021-01-21 20:45:27,140 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:HiveMetaStore$HMSHandler@812] - Added admin role in metastore [INFO] 2021-01-21 20:45:28.856 - [taskAppId=TASK-1-30-44]:[127] - -> 2021-01-21 20:45:27,145 INFO hive.HiveImport: 2021-01-21 20:45:27,145 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:HiveMetaStore$HMSHandler@821] - Added public role in metastore 2021-01-21 20:45:27,168 INFO hive.HiveImport: 2021-01-21 20:45:27,167 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:HiveMetaStore$HMSHandler@861] - No user is added in admin role, since config is empty 2021-01-21 20:45:27,328 INFO hive.HiveImport: 2021-01-21 20:45:27,328 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:RetryingMetaStoreClient@97] - RetryingMetaStoreClient proxy=class org.apache.hadoop.hive.ql.metadata.SessionHiveMetaStoreClient ugi=hadoop (auth:SIMPLE) retries=1 delay=1 lifetime=0 2021-01-21 20:45:27,359 INFO hive.HiveImport: 2021-01-21 20:45:27,358 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:HiveMetaStore$HMSHandler@895] - 0: get_all_functions 2021-01-21 20:45:27,360 INFO hive.HiveImport: 2021-01-21 20:45:27,360 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:HiveMetaStore$HMSHandler@347] - ugi=hadoop ip=unknown-ip-addr cmd=get_all_functions
2021-01-21 20:45:27,397 INFO hive.HiveImport: Hive Session ID = 6e1db8ba-3b60-411d-a8c0-188b5b9d0909 2021-01-21 20:45:27,397 INFO hive.HiveImport: 2021-01-21 20:45:27,397 [myid:] - INFO [pool-10-thread-1:SessionState$LogHelper@1227] - Hive Session ID = 6e1db8ba-3b60-411d-a8c0-188b5b9d0909 2021-01-21 20:45:27,402 INFO hive.HiveImport: 2021-01-21 20:45:27,402 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:HiveConf@5040] - Using the default value passed in for log id: b7fdc24f-10a2-44a1-8e39-b9601da93a17 2021-01-21 20:45:27,420 INFO hive.HiveImport: 2021-01-21 20:45:27,419 [myid:] - INFO [pool-10-thread-1:SessionState@790] - Created HDFS directory: /tmp/hive/hadoop/6e1db8ba-3b60-411d-a8c0-188b5b9d0909 2021-01-21 20:45:27,422 INFO hive.HiveImport: 2021-01-21 20:45:27,422 [myid:] - INFO [pool-10-thread-1:SessionState@790] - Created local directory: /tmp/hadoop/6e1db8ba-3b60-411d-a8c0-188b5b9d0909 2021-01-21 20:45:27,433 INFO hive.HiveImport: 2021-01-21 20:45:27,433 [myid:] - INFO [pool-10-thread-1:SessionState@790] - Created HDFS directory: /tmp/hive/hadoop/6e1db8ba-3b60-411d-a8c0-188b5b9d0909/_tmp_space.db 2021-01-21 20:45:27,435 INFO hive.HiveImport: 2021-01-21 20:45:27,435 [myid:] - INFO [pool-10-thread-1:HiveMetaStore$HMSHandler@895] - 1: get_databases: @hive# 2021-01-21 20:45:27,436 INFO hive.HiveImport: 2021-01-21 20:45:27,435 [myid:] - INFO [pool-10-thread-1:HiveMetaStore$HMSHandler@347] - ugi=hadoop ip=unknown-ip-addr cmd=get_databases: @hive#
2021-01-21 20:45:27,437 INFO hive.HiveImport: 2021-01-21 20:45:27,437 [myid:] - INFO [pool-10-thread-1:HiveMetaStore$HMSHandler@717] - 1: Opening raw store with implementation class:org.apache.hadoop.hive.metastore.ObjectStore 2021-01-21 20:45:27,439 INFO hive.HiveImport: 2021-01-21 20:45:27,438 [myid:] - INFO [pool-10-thread-1:ObjectStore@481] - ObjectStore, initialize called 2021-01-21 20:45:27,459 INFO hive.HiveImport: 2021-01-21 20:45:27,458 [myid:] - INFO [pool-10-thread-1:MetaStoreDirectSql@186] - Using direct SQL, underlying DB is MYSQL 2021-01-21 20:45:27,459 INFO hive.HiveImport: 2021-01-21 20:45:27,459 [myid:] - INFO [pool-10-thread-1:ObjectStore@396] - Initialized ObjectStore 2021-01-21 20:45:27,469 INFO hive.HiveImport: 2021-01-21 20:45:27,468 [myid:] - INFO [pool-10-thread-1:HiveMetaStore$HMSHandler@895] - 1: get_tables_by_type: db=@hive#admp_test pat=.,type=MATERIALIZED_VIEW 2021-01-21 20:45:27,469 INFO hive.HiveImport: 2021-01-21 20:45:27,468 [myid:] - INFO [pool-10-thread-1:HiveMetaStore$HMSHandler@347] - ugi=hadoop ip=unknown-ip-addr cmd=get_tables_by_type: db=@hive#admp_test pat=.,type=MATERIALIZED_VIEW
2021-01-21 20:45:27,477 INFO hive.HiveImport: 2021-01-21 20:45:27,477 [myid:] - INFO [pool-10-thread-1:HiveMetaStore$HMSHandler@895] - 1: get_multi_table : db=admp_test tbls= 2021-01-21 20:45:27,477 INFO hive.HiveImport: 2021-01-21 20:45:27,477 [myid:] - INFO [pool-10-thread-1:HiveMetaStore$HMSHandler@347] - ugi=hadoop ip=unknown-ip-addr cmd=get_multi_table : db=admp_test tbls=
2021-01-21 20:45:27,480 INFO hive.HiveImport: 2021-01-21 20:45:27,479 [myid:] - INFO [pool-10-thread-1:HiveMetaStore$HMSHandler@895] - 1: get_tables_by_type: db=@hive#default pat=.,type=MATERIALIZED_VIEW 2021-01-21 20:45:27,480 INFO hive.HiveImport: 2021-01-21 20:45:27,480 [myid:] - INFO [pool-10-thread-1:HiveMetaStore$HMSHandler@347] - ugi=hadoop ip=unknown-ip-addr cmd=get_tables_by_type: db=@hive#default pat=.,type=MATERIALIZED_VIEW
2021-01-21 20:45:27,484 INFO hive.HiveImport: 2021-01-21 20:45:27,484 [myid:] - INFO [pool-10-thread-1:HiveMetaStore$HMSHandler@895] - 1: get_multi_table : db=default tbls= 2021-01-21 20:45:27,485 INFO hive.HiveImport: 2021-01-21 20:45:27,484 [myid:] - INFO [pool-10-thread-1:HiveMetaStore$HMSHandler@347] - ugi=hadoop ip=unknown-ip-addr cmd=get_multi_table : db=default tbls=
2021-01-21 20:45:27,485 INFO hive.HiveImport: 2021-01-21 20:45:27,485 [myid:] - INFO [pool-10-thread-1:HiveMaterializedViewsRegistry$Loader@171] - Materialized views registry has been initialized 2021-01-21 20:45:27,492 INFO hive.HiveImport: 2021-01-21 20:45:27,492 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:Driver@554] - Compiling command(queryId=hadoop_20210121204527_337d88f7-27a6-4b71-9634-178cf2065f62): CREATE TABLE IF NOT EXISTS admp_test.ods_ew_client_extend ( client_extend_id INT, sso_merchant_id INT, external_userid STRING, avatar STRING, follow_user_count INT, follow_users STRING, enterprise_tags STRING, earliest_add_way INT, earliest_channel_id INT, earliest_channel_name STRING, create_time STRING, create_user STRING, update_time STRING, update_user STRING, status TINYINT, earliest_create_time STRING, earliest_follow_userid STRING, earliest_follow_name STRING) COMMENT 'Imported by sqoop on 2021/01/21 20:45:08' ROW FORMAT DELIMITED FIELDS TERMINATED BY '\001' LINES TERMINATED BY '\012' STORED AS TEXTFILE 2021-01-21 20:45:28,856 INFO hive.HiveImport: 2021-01-21 20:45:28,855 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:Driver@285] - Concurrency mode is disabled, not creating a lock manager [INFO] 2021-01-21 20:45:29.227 - [taskAppId=TASK-1-30-44]:[127] - -> 2021-01-21 20:45:28,859 INFO hive.HiveImport: 2021-01-21 20:45:28,858 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:SemanticAnalyzer@12123] - Starting Semantic Analysis 2021-01-21 20:45:28,877 INFO hive.HiveImport: 2021-01-21 20:45:28,877 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:SQLStdHiveAccessController@96] - Created SQLStdHiveAccessController for session context : HiveAuthzSessionContext [sessionString=b7fdc24f-10a2-44a1-8e39-b9601da93a17, clientType=HIVECLI] 2021-01-21 20:45:28,879 INFO hive.HiveImport: 2021-01-21 20:45:28,878 [myid:] - WARN [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:SessionState@950] - METASTORE_FILTER_HOOK will be ignored, since hive.security.authorization.manager is set to instance of HiveAuthorizerFactory. 2021-01-21 20:45:28,879 INFO hive.HiveImport: 2021-01-21 20:45:28,879 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:HiveMetaStoreClient@346] - Mestastore configuration metastore.filter.hook changed from org.apache.hadoop.hive.metastore.DefaultMetaStoreFilterHookImpl to org.apache.hadoop.hive.ql.security.authorization.plugin.AuthorizationMetaStoreFilterHook 2021-01-21 20:45:28,881 INFO hive.HiveImport: 2021-01-21 20:45:28,881 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:HiveMetaStore$HMSHandler@895] - 0: Cleaning up thread local RawStore... 2021-01-21 20:45:28,881 INFO hive.HiveImport: 2021-01-21 20:45:28,881 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:HiveMetaStore$HMSHandler@347] - ugi=hadoop ip=unknown-ip-addr cmd=Cleaning up thread local RawStore...
2021-01-21 20:45:28,881 INFO hive.HiveImport: 2021-01-21 20:45:28,881 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:HiveMetaStore$HMSHandler@895] - 0: Done cleaning up thread local RawStore 2021-01-21 20:45:28,882 INFO hive.HiveImport: 2021-01-21 20:45:28,881 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:HiveMetaStore$HMSHandler@347] - ugi=hadoop ip=unknown-ip-addr cmd=Done cleaning up thread local RawStore
2021-01-21 20:45:28,884 INFO hive.HiveImport: 2021-01-21 20:45:28,884 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:HiveMetaStore$HMSHandler@717] - 0: Opening raw store with implementation class:org.apache.hadoop.hive.metastore.ObjectStore 2021-01-21 20:45:28,884 INFO hive.HiveImport: 2021-01-21 20:45:28,884 [myid:] - WARN [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:ObjectStore@638] - datanucleus.autoStartMechanismMode is set to unsupported value null . Setting it to value: ignored 2021-01-21 20:45:28,885 INFO hive.HiveImport: 2021-01-21 20:45:28,885 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:ObjectStore@481] - ObjectStore, initialize called 2021-01-21 20:45:28,899 INFO hive.HiveImport: 2021-01-21 20:45:28,898 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:MetaStoreDirectSql@186] - Using direct SQL, underlying DB is MYSQL 2021-01-21 20:45:28,899 INFO hive.HiveImport: 2021-01-21 20:45:28,899 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:ObjectStore@396] - Initialized ObjectStore 2021-01-21 20:45:28,900 INFO hive.HiveImport: 2021-01-21 20:45:28,899 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:RetryingMetaStoreClient@97] - RetryingMetaStoreClient proxy=class org.apache.hadoop.hive.ql.metadata.SessionHiveMetaStoreClient ugi=hadoop (auth:SIMPLE) retries=1 delay=1 lifetime=0 2021-01-21 20:45:28,910 INFO hive.HiveImport: 2021-01-21 20:45:28,909 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:SemanticAnalyzer@12993] - Creating table admp_test.ods_ew_client_extend position=27 2021-01-21 20:45:28,930 INFO hive.HiveImport: 2021-01-21 20:45:28,930 [myid:] - WARN [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:ObjectStore@638] - datanucleus.autoStartMechanismMode is set to unsupported value null . Setting it to value: ignored 2021-01-21 20:45:28,930 INFO hive.HiveImport: 2021-01-21 20:45:28,930 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:ObjectStore@481] - ObjectStore, initialize called 2021-01-21 20:45:28,941 INFO hive.HiveImport: 2021-01-21 20:45:28,941 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:MetaStoreDirectSql@186] - Using direct SQL, underlying DB is MYSQL 2021-01-21 20:45:28,941 INFO hive.HiveImport: 2021-01-21 20:45:28,941 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:ObjectStore@396] - Initialized ObjectStore 2021-01-21 20:45:28,942 INFO hive.HiveImport: 2021-01-21 20:45:28,942 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:RetryingMetaStoreClient@97] - RetryingMetaStoreClient proxy=class org.apache.hadoop.hive.ql.metadata.SessionHiveMetaStoreClient ugi=hadoop (auth:SIMPLE) retries=1 delay=1 lifetime=0 2021-01-21 20:45:28,944 INFO hive.HiveImport: 2021-01-21 20:45:28,944 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:HiveMetaStore$HMSHandler@895] - 0: get_table : tbl=hive.admp_test.ods_ew_client_extend 2021-01-21 20:45:28,944 INFO hive.HiveImport: 2021-01-21 20:45:28,944 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:HiveMetaStore$HMSHandler@347] - ugi=hadoop ip=unknown-ip-addr cmd=get_table : tbl=hive.admp_test.ods_ew_client_extend 2021-01-21 20:45:29,058 INFO hive.HiveImport: 2021-01-21 20:45:29,058 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:Driver@666] - Semantic Analysis Completed (retrial = false) 2021-01-21 20:45:29,060 INFO hive.HiveImport: 2021-01-21 20:45:29,060 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:Driver@374] - Returning Hive schema: Schema(fieldSchemas:null, properties:null) 2021-01-21 20:45:29,065 INFO hive.HiveImport: 2021-01-21 20:45:29,065 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:Driver@781] - Completed compiling command(queryId=hadoop_20210121204527_337d88f7-27a6-4b71-9634-178cf2065f62); Time taken: 1.604 seconds 2021-01-21 20:45:29,066 INFO hive.HiveImport: 2021-01-21 20:45:29,066 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:ReExecDriver@156] - Execution #1 of query 2021-01-21 20:45:29,066 INFO hive.HiveImport: 2021-01-21 20:45:29,066 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:Driver@285] - Concurrency mode is disabled, not creating a lock manager 2021-01-21 20:45:29,067 INFO hive.HiveImport: 2021-01-21 20:45:29,066 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:Driver@2255] - Executing command(queryId=hadoop_20210121204527_337d88f7-27a6-4b71-9634-178cf2065f62): CREATE TABLE IF NOT EXISTS admp_test.ods_ew_client_extend ( client_extend_id INT, sso_merchant_id INT, external_userid STRING, avatar STRING, follow_user_count INT, follow_users STRING, enterprise_tags STRING, earliest_add_way INT, earliest_channel_id INT, earliest_channel_name STRING, create_time STRING, create_user STRING, update_time STRING, update_user STRING, status TINYINT, earliest_create_time STRING, earliest_follow_userid STRING, earliest_follow_name STRING) COMMENT 'Imported by sqoop on 2021/01/21 20:45:08' ROW FORMAT DELIMITED FIELDS TERMINATED BY '\001' LINES TERMINATED BY '\012' STORED AS TEXTFILE 2021-01-21 20:45:29,071 INFO hive.HiveImport: 2021-01-21 20:45:29,071 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:Driver@2531] - Completed executing command(queryId=hadoop_20210121204527_337d88f7-27a6-4b71-9634-178cf2065f62); Time taken: 0.005 seconds 2021-01-21 20:45:29,071 INFO hive.HiveImport: OK 2021-01-21 20:45:29,071 INFO hive.HiveImport: 2021-01-21 20:45:29,071 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:SessionState$LogHelper@1227] - OK 2021-01-21 20:45:29,071 INFO hive.HiveImport: 2021-01-21 20:45:29,071 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:Driver@285] - Concurrency mode is disabled, not creating a lock manager 2021-01-21 20:45:29,072 INFO hive.HiveImport: Time taken: 1.612 seconds 2021-01-21 20:45:29,072 INFO hive.HiveImport: 2021-01-21 20:45:29,072 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:SessionState$LogHelper@1227] - Time taken: 1.612 seconds 2021-01-21 20:45:29,072 INFO hive.HiveImport: 2021-01-21 20:45:29,072 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:HiveConf@5040] - Using the default value passed in for log id: b7fdc24f-10a2-44a1-8e39-b9601da93a17 2021-01-21 20:45:29,073 INFO hive.HiveImport: 2021-01-21 20:45:29,072 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:SessionState@452] - Resetting thread name to main 2021-01-21 20:45:29,073 INFO hive.HiveImport: 2021-01-21 20:45:29,073 [myid:] - INFO [main:HiveConf@5040] - Using the default value passed in for log id: b7fdc24f-10a2-44a1-8e39-b9601da93a17 2021-01-21 20:45:29,073 INFO hive.HiveImport: 2021-01-21 20:45:29,073 [myid:] - INFO [main:SessionState@441] - Updating thread name to b7fdc24f-10a2-44a1-8e39-b9601da93a17 main 2021-01-21 20:45:29,075 INFO hive.HiveImport: 2021-01-21 20:45:29,075 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:Driver@554] - Compiling command(queryId=hadoop_20210121204529_1e6a171d-d2bc-49fb-8621-754bff76b39c): 2021-01-21 20:45:29,075 INFO hive.HiveImport: LOAD DATA INPATH 'hdfs://xxx.xxx.xxx.xx:8020/user/hadoop/ew_client_extend' OVERWRITE INTO TABLE admp_test.ods_ew_client_extend 2021-01-21 20:45:29,078 INFO hive.HiveImport: 2021-01-21 20:45:29,078 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:Driver@285] - Concurrency mode is disabled, not creating a lock manager 2021-01-21 20:45:29,083 INFO hive.HiveImport: 2021-01-21 20:45:29,083 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:HiveMetaStore$HMSHandler@895] - 0: get_table : tbl=hive.admp_test.ods_ew_client_extend 2021-01-21 20:45:29,083 INFO hive.HiveImport: 2021-01-21 20:45:29,083 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:HiveMetaStore$HMSHandler@347] - ugi=hadoop ip=unknown-ip-addr cmd=get_table : tbl=hive.admp_test.ods_ew_client_extend 2021-01-21 20:45:29,206 INFO hive.HiveImport: 2021-01-21 20:45:29,206 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:Driver@666] - Semantic Analysis Completed (retrial = false) 2021-01-21 20:45:29,206 INFO hive.HiveImport: 2021-01-21 20:45:29,206 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:Driver@374] - Returning Hive schema: Schema(fieldSchemas:null, properties:null) 2021-01-21 20:45:29,207 INFO hive.HiveImport: 2021-01-21 20:45:29,207 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:Driver@781] - Completed compiling command(queryId=hadoop_20210121204529_1e6a171d-d2bc-49fb-8621-754bff76b39c); Time taken: 0.131 seconds 2021-01-21 20:45:29,207 INFO hive.HiveImport: 2021-01-21 20:45:29,207 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:ReExecDriver@156] - Execution #1 of query 2021-01-21 20:45:29,207 INFO hive.HiveImport: 2021-01-21 20:45:29,207 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:Driver@285] - Concurrency mode is disabled, not creating a lock manager 2021-01-21 20:45:29,207 INFO hive.HiveImport: 2021-01-21 20:45:29,207 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:Driver@2255] - Executing command(queryId=hadoop_20210121204529_1e6a171d-d2bc-49fb-8621-754bff76b39c): 2021-01-21 20:45:29,207 INFO hive.HiveImport: LOAD DATA INPATH 'hdfs://xxx.xxx.xxx.xx:8020/user/hadoop/ew_client_extend' OVERWRITE INTO TABLE admp_test.ods_ew_client_extend 2021-01-21 20:45:29,210 INFO hive.HiveImport: 2021-01-21 20:45:29,210 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:Driver@2662] - Starting task [Stage-0:MOVE] in serial mode 2021-01-21 20:45:29,211 INFO hive.HiveImport: 2021-01-21 20:45:29,210 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:HiveMetaStore$HMSHandler@895] - 0: Cleaning up thread local RawStore... 2021-01-21 20:45:29,211 INFO hive.HiveImport: 2021-01-21 20:45:29,211 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:HiveMetaStore$HMSHandler@347] - ugi=hadoop ip=unknown-ip-addr cmd=Cleaning up thread local RawStore...
2021-01-21 20:45:29,211 INFO hive.HiveImport: 2021-01-21 20:45:29,211 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:HiveMetaStore$HMSHandler@895] - 0: Done cleaning up thread local RawStore 2021-01-21 20:45:29,211 INFO hive.HiveImport: 2021-01-21 20:45:29,211 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:HiveMetaStore$HMSHandler@347] - ugi=hadoop ip=unknown-ip-addr cmd=Done cleaning up thread local RawStore
2021-01-21 20:45:29,211 INFO hive.HiveImport: Loading data to table admp_test.ods_ew_client_extend 2021-01-21 20:45:29,212 INFO hive.HiveImport: 2021-01-21 20:45:29,211 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:SessionState$LogHelper@1227] - Loading data to table admp_test.ods_ew_client_extend from hdfs://xxx.xxx.xxx.xx:8020/user/hadoop/ew_client_extend 2021-01-21 20:45:29,214 INFO hive.HiveImport: 2021-01-21 20:45:29,214 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:HiveMetaStore$HMSHandler@717] - 0: Opening raw store with implementation class:org.apache.hadoop.hive.metastore.ObjectStore 2021-01-21 20:45:29,214 INFO hive.HiveImport: 2021-01-21 20:45:29,214 [myid:] - WARN [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:ObjectStore@638] - datanucleus.autoStartMechanismMode is set to unsupported value null . Setting it to value: ignored 2021-01-21 20:45:29,215 INFO hive.HiveImport: 2021-01-21 20:45:29,214 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:ObjectStore@481] - ObjectStore, initialize called 2021-01-21 20:45:29,225 INFO hive.HiveImport: 2021-01-21 20:45:29,225 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:MetaStoreDirectSql@186] - Using direct SQL, underlying DB is MYSQL 2021-01-21 20:45:29,225 INFO hive.HiveImport: 2021-01-21 20:45:29,225 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:ObjectStore@396] - Initialized ObjectStore 2021-01-21 20:45:29,226 INFO hive.HiveImport: 2021-01-21 20:45:29,226 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:RetryingMetaStoreClient@97] - RetryingMetaStoreClient proxy=class org.apache.hadoop.hive.ql.metadata.SessionHiveMetaStoreClient ugi=hadoop (auth:SIMPLE) retries=1 delay=1 lifetime=0 2021-01-21 20:45:29,227 INFO hive.HiveImport: 2021-01-21 20:45:29,226 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:HiveMetaStore$HMSHandler@895] - 0: get_table : tbl=hive.admp_test.ods_ew_client_extend [INFO] 2021-01-21 20:45:30.458 - [taskAppId=TASK-1-30-44]:[127] - -> 2021-01-21 20:45:29,227 INFO hive.HiveImport: 2021-01-21 20:45:29,227 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:HiveMetaStore$HMSHandler@347] - ugi=hadoop ip=unknown-ip-addr cmd=get_table : tbl=hive.admp_test.ods_ew_client_extend 2021-01-21 20:45:29,533 INFO hive.HiveImport: 2021-01-21 20:45:29,532 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:HiveMetaStore$HMSHandler@895] - 0: get_table : tbl=hive.admp_test.ods_ew_client_extend 2021-01-21 20:45:29,533 INFO hive.HiveImport: 2021-01-21 20:45:29,533 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:HiveMetaStore$HMSHandler@347] - ugi=hadoop ip=unknown-ip-addr cmd=get_table : tbl=hive.admp_test.ods_ew_client_extend 2021-01-21 20:45:29,568 INFO hive.HiveImport: 2021-01-21 20:45:29,568 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:HiveMetaStore$HMSHandler@895] - 0: get_database: @hive#admp_test 2021-01-21 20:45:29,568 INFO hive.HiveImport: 2021-01-21 20:45:29,568 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:HiveMetaStore$HMSHandler@347] - ugi=hadoop ip=unknown-ip-addr cmd=get_database: @hive#admp_test
2021-01-21 20:45:29,610 INFO hive.HiveImport: 2021-01-21 20:45:29,610 [myid:] - INFO [Delete-Thread-0:TrashPolicyDefault@168] - Moved: 'hdfs://xxx.xxx.xxx.xx:8020/hive/warehouse/admp_test.db/ods/ods_ew_client_extend/part-m-00000' to trash at: hdfs://xxx.xxx.xxx.xx:8020/user/hadoop/.Trash/Current/hive/warehouse/admp_test.db/ods/ods_ew_client_extend/part-m-000001611233129596 2021-01-21 20:45:29,611 INFO hive.HiveImport: 2021-01-21 20:45:29,610 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:FileUtils@580] - Creating directory if it doesn't exist: hdfs://xxx.xxx.xxx.xx:8020/hive/warehouse/admp_test.db/ods/ods_ew_client_extend 2021-01-21 20:45:29,663 INFO hive.HiveImport: 2021-01-21 20:45:29,662 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:HiveMetaStore$HMSHandler@895] - 0: alter_table: hive.admp_test.ods_ew_client_extend newtbl=ods_ew_client_extend 2021-01-21 20:45:29,663 INFO hive.HiveImport: 2021-01-21 20:45:29,663 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:HiveMetaStore$HMSHandler@347] - ugi=hadoop ip=unknown-ip-addr cmd=alter_table: hive.admp_test.ods_ew_client_extend newtbl=ods_ew_client_extend
2021-01-21 20:45:29,782 INFO hive.HiveImport: 2021-01-21 20:45:29,782 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:Driver@2662] - Starting task [Stage-1:STATS] in serial mode 2021-01-21 20:45:29,782 INFO hive.HiveImport: 2021-01-21 20:45:29,782 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:HiveMetaStore$HMSHandler@895] - 0: Cleaning up thread local RawStore... 2021-01-21 20:45:29,782 INFO hive.HiveImport: 2021-01-21 20:45:29,782 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:HiveMetaStore$HMSHandler@347] - ugi=hadoop ip=unknown-ip-addr cmd=Cleaning up thread local RawStore...
2021-01-21 20:45:29,783 INFO hive.HiveImport: 2021-01-21 20:45:29,783 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:HiveMetaStore$HMSHandler@895] - 0: Done cleaning up thread local RawStore 2021-01-21 20:45:29,783 INFO hive.HiveImport: 2021-01-21 20:45:29,783 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:HiveMetaStore$HMSHandler@347] - ugi=hadoop ip=unknown-ip-addr cmd=Done cleaning up thread local RawStore
2021-01-21 20:45:29,783 INFO hive.HiveImport: 2021-01-21 20:45:29,783 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:BasicStatsTask@96] - Executing stats task 2021-01-21 20:45:29,785 INFO hive.HiveImport: 2021-01-21 20:45:29,785 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:HiveMetaStore$HMSHandler@717] - 0: Opening raw store with implementation class:org.apache.hadoop.hive.metastore.ObjectStore 2021-01-21 20:45:29,786 INFO hive.HiveImport: 2021-01-21 20:45:29,785 [myid:] - WARN [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:ObjectStore@638] - datanucleus.autoStartMechanismMode is set to unsupported value null . Setting it to value: ignored 2021-01-21 20:45:29,786 INFO hive.HiveImport: 2021-01-21 20:45:29,786 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:ObjectStore@481] - ObjectStore, initialize called 2021-01-21 20:45:29,794 INFO hive.HiveImport: 2021-01-21 20:45:29,793 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:MetaStoreDirectSql@186] - Using direct SQL, underlying DB is MYSQL 2021-01-21 20:45:29,794 INFO hive.HiveImport: 2021-01-21 20:45:29,794 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:ObjectStore@396] - Initialized ObjectStore 2021-01-21 20:45:29,794 INFO hive.HiveImport: 2021-01-21 20:45:29,794 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:RetryingMetaStoreClient@97] - RetryingMetaStoreClient proxy=class org.apache.hadoop.hive.ql.metadata.SessionHiveMetaStoreClient ugi=hadoop (auth:SIMPLE) retries=1 delay=1 lifetime=0 2021-01-21 20:45:29,795 INFO hive.HiveImport: 2021-01-21 20:45:29,795 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:HiveMetaStore$HMSHandler@895] - 0: get_table : tbl=hive.admp_test.ods_ew_client_extend 2021-01-21 20:45:29,795 INFO hive.HiveImport: 2021-01-21 20:45:29,795 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:HiveMetaStore$HMSHandler@347] - ugi=hadoop ip=unknown-ip-addr cmd=get_table : tbl=hive.admp_test.ods_ew_client_extend 2021-01-21 20:45:29,903 INFO hive.HiveImport: 2021-01-21 20:45:29,903 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:HiveMetaStore$HMSHandler@895] - 0: alter_table: hive.admp_test.ods_ew_client_extend newtbl=ods_ew_client_extend 2021-01-21 20:45:29,903 INFO hive.HiveImport: 2021-01-21 20:45:29,903 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:HiveMetaStore$HMSHandler@347] - ugi=hadoop ip=unknown-ip-addr cmd=alter_table: hive.admp_test.ods_ew_client_extend newtbl=ods_ew_client_extend
2021-01-21 20:45:29,970 INFO hive.HiveImport: 2021-01-21 20:45:29,969 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:BasicStatsTask@280] - Table admp_test.ods_ew_client_extend stats: [numFiles=1, totalSize=405641822] 2021-01-21 20:45:29,970 INFO hive.HiveImport: 2021-01-21 20:45:29,970 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:Driver@2531] - Completed executing command(queryId=hadoop_20210121204529_1e6a171d-d2bc-49fb-8621-754bff76b39c); Time taken: 0.763 seconds 2021-01-21 20:45:29,970 INFO hive.HiveImport: OK 2021-01-21 20:45:29,970 INFO hive.HiveImport: 2021-01-21 20:45:29,970 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:SessionState$LogHelper@1227] - OK 2021-01-21 20:45:29,971 INFO hive.HiveImport: 2021-01-21 20:45:29,970 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:Driver@285] - Concurrency mode is disabled, not creating a lock manager 2021-01-21 20:45:29,971 INFO hive.HiveImport: Time taken: 0.896 seconds 2021-01-21 20:45:29,971 INFO hive.HiveImport: 2021-01-21 20:45:29,971 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:SessionState$LogHelper@1227] - Time taken: 0.896 seconds 2021-01-21 20:45:29,971 INFO hive.HiveImport: 2021-01-21 20:45:29,971 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:HiveConf@5040] - Using the default value passed in for log id: b7fdc24f-10a2-44a1-8e39-b9601da93a17 2021-01-21 20:45:29,971 INFO hive.HiveImport: 2021-01-21 20:45:29,971 [myid:] - INFO [b7fdc24f-10a2-44a1-8e39-b9601da93a17 main:SessionState@452] - Resetting thread name to main 2021-01-21 20:45:29,972 INFO hive.HiveImport: 2021-01-21 20:45:29,971 [myid:] - INFO [main:HiveConf@5040] - Using the default value passed in for log id: b7fdc24f-10a2-44a1-8e39-b9601da93a17 2021-01-21 20:45:29,991 INFO hive.HiveImport: 2021-01-21 20:45:29,991 [myid:] - INFO [main:SessionState@885] - Deleted directory: /tmp/hive/hadoop/b7fdc24f-10a2-44a1-8e39-b9601da93a17 on fs with scheme hdfs 2021-01-21 20:45:29,997 INFO hive.HiveImport: 2021-01-21 20:45:29,997 [myid:] - INFO [main:SessionState@885] - Deleted directory: /tmp/hadoop/b7fdc24f-10a2-44a1-8e39-b9601da93a17 on fs with scheme file 2021-01-21 20:45:30,004 INFO hive.HiveImport: 2021-01-21 20:45:30,004 [myid:] - INFO [main:HiveMetaStore$HMSHandler@895] - 0: Cleaning up thread local RawStore... 2021-01-21 20:45:30,004 INFO hive.HiveImport: 2021-01-21 20:45:30,004 [myid:] - INFO [main:HiveMetaStore$HMSHandler@347] - ugi=hadoop ip=unknown-ip-addr cmd=Cleaning up thread local RawStore...
2021-01-21 20:45:30,004 INFO hive.HiveImport: 2021-01-21 20:45:30,004 [myid:] - INFO [main:HiveMetaStore$HMSHandler@895] - 0: Done cleaning up thread local RawStore 2021-01-21 20:45:30,005 INFO hive.HiveImport: 2021-01-21 20:45:30,004 [myid:] - INFO [main:HiveMetaStore$HMSHandler@347] - ugi=hadoop ip=unknown-ip-addr cmd=Done cleaning up thread local RawStore
2021-01-21 20:45:30,458 INFO hive.HiveImport: Hive import complete.

masterable commented 3 years ago

您能否在工作日志中发送执行上下文，以帮助定位问题 I coded the server address in the log, I hope it will not prevent you from viewing

zhuangchong commented 3 years ago 
2021-01-21 20:45:30,458 INFO hive.HiveImport: Hive import complete.

No more text?

masterable commented 3 years ago 
2021-01-21 20:45:30,458 INFO hive.HiveImport: Hive import complete.

No more text? YES,This is what puzzles me

zhuangchong commented 3 years ago

@masterable

Modify the logback-worker.xml file of the node where the worker-server resides, commenting lines 59-62

    <filter class="ch.qos.logback.classic.filter.ThresholdFilter">
            <level>INFO</level>
        </filter>
        <filter class="org.apache.dolphinscheduler.server.log.WorkerLogFilter"/>

To perform your task again, check the Worker.log for any associated exception logs.

masterable commented 3 years ago

ch.qos.logback.classic.filter.ThresholdFilter

It's ok,thanks image But there is still a problem. My dolphinsheduler is deployed in a cluster. When I check the dolphinscheduler-worker.log, the first 192.168.150.2 and third 192.168.150.4 servers do not display the error message. Only the second one 192.168.150.3 shows the error message. The error prompts me Yarn 'S address is not recognized

Below is my configuration example

如果没有使用到Yarn,保持以下默认值即可;如果ResourceManager是HA，则配置为ResourceManager节点的主备ip或者hostname,比如"192.168.xx.xx,192.168.xx.xx";如果是单ResourceManager请配置yarnHaIps=""即可

yarnHaIps="192.168.xx.xx"

如果ResourceManager是HA或者没有使用到Yarn保持默认值即可；如果是单ResourceManager，请配置真实的ResourceManager主机名或者ip

singleYarnIp="192.168.150.1"

Since I did not use the mode Yarn-HA, I only configured one, but why did the other two machines report no errors?

My cluster configuration is as follows

192.168.150.1 masterserver 192.168.150.2 loggerserver workerserver apiapplicationserver 192.168.150.3 loggerserver workerserver 192.168.150.4 loggerserver workerserver

Why only the worker of the server 192.168.150.3 reported an error?