[ATLAS-1567] Regression: AtlasHook for falcon seems to be broken, it is not invoked when a falcon cluster entity is submitted

• Type: Bug
• Status: Resolved
• Priority: Blocker
• Resolution: Fixed
• Affects Version/s: trunk
• Fix Version/s: 0.8-incubating
• Component/s: atlas-intg
• Assignee: Nixon Rodrigues
• Reporter: Ayub Pathan
• Created: 17/Feb/17 19:41
• Updated: 22/Feb/17 18:37
• Resolved: 22/Feb/17 18:37

Description

Falcon logs showing the cluster submitted successfully, but still the hook is not invoked

2017-02-17 19:23:40,020 INFO  - [726486469@qtp-1828868503-10 - 39424028-a0e3-490f-ba04-1d025619e782:] ~ HttpServletRequest RemoteUser is hrt_qa (Servlets:47)
2017-02-17 19:23:40,020 INFO  - [726486469@qtp-1828868503-10 - 39424028-a0e3-490f-ba04-1d025619e782:hrt_qa:POST//entities/submit/cluster] ~ Logging in hrt_qa (CurrentUser:65)
2017-02-17 19:23:40,021 INFO  - [726486469@qtp-1828868503-10 - 39424028-a0e3-490f-ba04-1d025619e782:hrt_qa:POST//entities/submit/cluster] ~ Request from authenticated user: hrt_qa, URL=/api/entities/submit/cluster, doAs user: null (FalconAuthenticationFilter:185)
2017-02-17 19:23:40,021 INFO  - [726486469@qtp-1828868503-10 - 39424028-a0e3-490f-ba04-1d025619e782:hrt_qa:POST//entities/submit/cluster] ~ Authorizing user=hrt_qa against request=RequestParts{resource='entities', action='submit', entityType='cluster'} (FalconAuthorizationFilter:78)
2017-02-17 19:23:40,021 INFO  - [726486469@qtp-1828868503-10 - 39424028-a0e3-490f-ba04-1d025619e782:hrt_qa:POST//entities/submit/cluster] ~ Authorization for action=submit will be done in the API (DefaultAuthorizationProvider:315)
2017-02-17 19:23:40,021 INFO  - [726486469@qtp-1828868503-10 - 39424028-a0e3-490f-ba04-1d025619e782:hrt_qa:POST//entities/submit/cluster] ~ Authorization succeeded for user=hrt_qa, proxy=hrt_qa (FalconAuthorizationFilter:88)
2017-02-17 19:23:40,034 INFO  - [726486469@qtp-1828868503-10 - 39424028-a0e3-490f-ba04-1d025619e782:hrt_qa:POST//entities/submit/cluster] ~ Parsed Entity: cl1 (EntityParser:102)
2017-02-17 19:23:40,040 INFO  - [726486469@qtp-1828868503-10 - 39424028-a0e3-490f-ba04-1d025619e782:hrt_qa:POST//entities/submit/cluster] ~ Parsed Entity: cl1 (EntityParser:102)
2017-02-17 19:23:40,040 INFO  - [726486469@qtp-1828868503-10 - 39424028-a0e3-490f-ba04-1d025619e782:hrt_qa:POST//entities/submit/cluster] ~ Lock acquired for submit on (cluster) cl1 by 726486469@qtp-1828868503-10 - 39424028-a0e3-490f-ba04-1d025619e782 (MemoryLocks:54)
2017-02-17 19:23:40,040 ERROR - [726486469@qtp-1828868503-10 - 39424028-a0e3-490f-ba04-1d025619e782:hrt_qa:POST//entities/submit/cluster] ~ Entity node (CLUSTER) cl1 not found in entity graph. (EntityGraph:71)
2017-02-17 19:23:40,041 INFO  - [726486469@qtp-1828868503-10 - 39424028-a0e3-490f-ba04-1d025619e782:hrt_qa:POST//entities/submit/cluster] ~ Successfully released lock on (cluster) cl1 by 726486469@qtp-1828868503-10 - 39424028-a0e3-490f-ba04-1d025619e782 (MemoryLocks:70)
2017-02-17 19:23:40,041 INFO  - [726486469@qtp-1828868503-10 - 39424028-a0e3-490f-ba04-1d025619e782:hrt_qa:POST//entities/submit/cluster] ~ All locks released on cl1 (AbstractEntityManager:489)
2017-02-17 19:23:40,050 INFO  - [726486469@qtp-1828868503-10 - 39424028-a0e3-490f-ba04-1d025619e782:hrt_qa:POST//entities/submit/cluster] ~ {Action:submit, Dimensions:{colo=NULL, entityType=cluster}, Status: SUCCEEDED, Time-taken:26995845 ns} (METRIC:38)
2017-02-17 19:23:40,051 INFO  - [726486469@qtp-1828868503-10 - 39424028-a0e3-490f-ba04-1d025619e782:] ~ Audit: hrt_qa@172.27.21.202 performed http://ctr-e129-1487033772569-4286-01-000004.hwx.site:15000/api/entities/submit/cluster (172.27.17.129) at 2017-02-17T19:23Z (AUDIT:48)
2017-02-17 19:23:40,051 INFO  - [726486469@qtp-1828868503-10 - 39424028-a0e3-490f-ba04-1d025619e782:] ~ Audit: hrt_qa@172.27.21.202 performed http://ctr-e129-1487033772569-4286-01-000004.hwx.site:15000/api/entities/submit/cluster (172.27.17.129) at 2017-02-17T19:23Z (AUDIT:48)
2017-02-17 19:23:51,101 WARN  - [HiveClientCache-cleaner-0:] ~ Evicted client has non-zero user count: 1 (metastore:443)

Falcon running command - showing hook jars classpath

[root@ctr-e129-1487033772569-4286-01-000004 conf]# ps axu | grep -i falcon
falcon     66767  0.2  0.2 9242152 751692 ?      Sl   Feb16   4:00 /usr/lib/jvm/java-openjdk/bin/java -Xmx1024m -noverify -Dfalcon.embeddedmq=True -Dfalcon.emeddedmq.port=61616 -Dfalcon.log.dir=/grid/0/log/falcon -Dfalcon.embeddedmq.data=/hadoop/falcon/embeddedmq/data -Dfalcon.home=/usr/hdp/current/falcon-server -Dconfig.location=/usr/hdp/current/falcon-server/conf -Dfalcon.app.type=falcon -Dfalcon.catalog.service.enabled= -cp /usr/hdp/current/falcon-server/conf:/usr/hdp/2.6.0.0-512/hadoop/conf:/usr/hdp/2.6.0.0-512/hadoop/lib/*:/usr/hdp/2.6.0.0-512/hadoop/.//*:/usr/hdp/2.6.0.0-512/hadoop-hdfs/./:/usr/hdp/2.6.0.0-512/hadoop-hdfs/lib/*:/usr/hdp/2.6.0.0-512/hadoop-hdfs/.//*:/usr/hdp/2.6.0.0-512/hadoop-yarn/lib/*:/usr/hdp/2.6.0.0-512/hadoop-yarn/.//*:/usr/hdp/2.6.0.0-512/hadoop-mapreduce/lib/*:/usr/hdp/2.6.0.0-512/hadoop-mapreduce/.//*::mysql-connector-java.jar:mysql-jdbc-qe.jar:/usr/hdp/2.6.0.0-512/tez/*:/usr/hdp/2.6.0.0-512/tez/lib/*:/usr/hdp/2.6.0.0-512/tez/conf:/usr/hdp/current/falcon-server/server/webapp/falcon/WEB-INF/classes:/usr/hdp/current/falcon-server/server/webapp/falcon/WEB-INF/lib/*:/usr/hdp/current/falcon-server/libext/*:/usr/hdp/current/atlas-client/hook/falcon/*: org.apache.falcon.FalconServer -app /usr/hdp/current/falcon-server/server/webapp/falcon -port 15000
root     1091491  0.0  0.0  10632   968 pts/0    S+   19:27   0:00 grep --color=auto -i falcon

Below output shows that - the falcon-bridge jars are loaded.

[root@ctr-e129-1487033772569-4286-01-000004 conf]# lsof -p 66767 | grep jar | grep falcon-bridge
java    66767 falcon  mem       REG              253,8    35338  134808586 /usr/hdp/2.6.0.0-512/atlas/hook/falcon/atlas-falcon-plugin-impl/falcon-bridge-0.8.0.2.6.0.0-512.jar
java    66767 falcon  mem       REG              253,8    10294   67140617 /usr/hdp/2.6.0.0-512/atlas/hook/falcon/falcon-bridge-shim-0.8.0.2.6.0.0-512.jar
java    66767 falcon  613r      REG              253,8    10294   67140617 /usr/hdp/2.6.0.0-512/atlas/hook/falcon/falcon-bridge-shim-0.8.0.2.6.0.0-512.jar
java    66767 falcon  664r      REG              253,8    35338  134808586 /usr/hdp/2.6.0.0-512/atlas/hook/falcon/atlas-falcon-plugin-impl/falcon-bridge-0.8.0.2.6.0.0-512.jar
[root@ctr-e129-1487033772569-4286-01-000004 conf]#