[
https://issues.apache.org/jira/browse/HDFS-16356?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
FliegenKLATSCH updated HDFS-16356:
----------------------------------
Description:
I see the following issue in one of 3 JournalNodes:
"Only Namenode and another JournalNode may access this servlet".
The journalnode wants to download an edit log (shortly after startup) from
another journalnode, but in the request the short username equals the (long)
principal name and thus the request gets denied.
I'll add a PR which trims the principal to the actual short name, but I am not
sure why in the first place the request token contains the full principal name
and what the desired name actually is. Maybe I have a misconfiguration on my
end?
"Server" side (scn1):
{code:bash}
2021-11-26 09:02:04,609 DEBUG
org.apache.hadoop.security.authentication.server.AuthenticationFilter: Request
[https://scn1:8481/getJournal?jid=backups&segmentTxId=136002159
98&storageInfo=-65%3A1807091115%3A1522842919075%3ACID-661a9237-3a5d-4895-8257-1a2cc3642e98&inProgressOk=false]
user [jn/s...@example.com] authenticated
2021-11-26 09:02:04,610 DEBUG org.eclipse.jetty.servlet.ServletHandler: call
servlet
getJournal@e931eb01==org.apache.hadoop.hdfs.qjournal.server.GetJournalEditServlet,jsp=null,ord
er=-1,inst=true,async=true
2021-11-26 09:02:04,610 DEBUG
org.apache.hadoop.hdfs.qjournal.server.GetJournalEditServlet: Validating
request made by jn/s...@example.com / jn/s...@example.com. This user is:
jn/s...@example.com (auth:KERBEROS)
2021-11-26 09:02:04,610 DEBUG org.apache.hadoop.hdfs.server.namenode.NameNode:
Setting fs.defaultFS to hdfs://scn1:8020
2021-11-26 09:02:04,610 DEBUG org.apache.hadoop.hdfs.server.namenode.NameNode:
Setting fs.defaultFS to hdfs://scn3:8020
2021-11-26 09:02:04,610 DEBUG
org.apache.hadoop.hdfs.qjournal.server.GetJournalEditServlet: isValidRequestor
is comparing to valid requestor: nn/s...@example.com
2021-11-26 09:02:04,610 DEBUG
org.apache.hadoop.hdfs.qjournal.server.GetJournalEditServlet: isValidRequestor
is comparing to valid requestor: nn/s...@example.com
2021-11-26 09:02:04,610 DEBUG
org.apache.hadoop.hdfs.qjournal.server.GetJournalEditServlet: isValidRequestor
is rejecting: jn/s...@example.com
{code}
"Client" side (scn2):
{code:bash}
2021-11-26 08:56:03,377 INFO
org.apache.hadoop.hdfs.qjournal.server.JournalNodeSyncer: Syncing Journal
/0.0.0.0:8485 with scn1/1.2.6.9:8485, journal id: backups
2021-11-26 08:56:03,397 INFO
org.apache.hadoop.hdfs.qjournal.server.JournalNodeSyncer: Downloading missing
Edit Log from
https://scn1:8481/getJournal?jid=backups&segmentTxId=13600215998&storageInfo=-65%3A1807091115%3A1522842919075%3ACID-661a9237-3a5d-4895-8257-1a2cc3642e98&inProgressOk=false
to /hdfs/journal/backups
2021-11-26 08:56:03,412 ERROR
org.apache.hadoop.hdfs.qjournal.server.JournalNodeSyncer: Download of Edit Log
file for Syncing failed. Deleting temp file:
/hdfs/journal/backups/edits.sync/edits_0000000013600215998-0000000013600227922
org.apache.hadoop.hdfs.server.common.HttpGetFailedException: Image transfer
servlet at
https://scn1:8481/getJournal?jid=backups&segmentTxId=13600215998&storageInfo=-65%3A1807091115%3A152242919075%3ACID-661a9237-3a5d-4895-8257-1a2cc3642e98&inProgressOk=false
failed with status code 403
Response message:
Only Namenode and another JournalNode may access this servlet
at org.apache.hadoop.hdfs.server.common.Util.doGetUrl(Util.java:168)
at
org.apache.hadoop.hdfs.qjournal.server.JournalNodeSyncer.lambda$downloadMissingLogSegment$1(JournalNodeSyncer.java:448)
at java.base/java.security.AccessController.doPrivileged(Native Method)
at java.base/javax.security.auth.Subject.doAs(Subject.java:423)
at
org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1845)
at
org.apache.hadoop.security.SecurityUtil.doAsUser(SecurityUtil.java:518)
at
org.apache.hadoop.security.SecurityUtil.doAsLoginUser(SecurityUtil.java:499)
at
org.apache.hadoop.hdfs.qjournal.server.JournalNodeSyncer.downloadMissingLogSegment(JournalNodeSyncer.java:443)
at
org.apache.hadoop.hdfs.qjournal.server.JournalNodeSyncer.getMissingLogSegments(JournalNodeSyncer.java:355)
at
org.apache.hadoop.hdfs.qjournal.server.JournalNodeSyncer.syncWithJournalAtIndex(JournalNodeSyncer.java:259)
at
org.apache.hadoop.hdfs.qjournal.server.JournalNodeSyncer.syncJournals(JournalNodeSyncer.java:227)
at
org.apache.hadoop.hdfs.qjournal.server.JournalNodeSyncer.lambda$startSyncJournalsDaemon$0(JournalNodeSyncer.java:187)
at java.base/java.lang.Thread.run(Thread.java:829)
2021-11-26 08:56:03,412 WARN
org.apache.hadoop.hdfs.qjournal.server.JournalNodeSyncer: Deleting
/hdfs/journal/backups/edits.sync/edits_0000000013600215998-0000000013600227922
has failed
2021-11-26 08:56:03,412 ERROR
org.apache.hadoop.hdfs.qjournal.server.JournalNodeSyncer: Aborting current sync
attempt.
{code}
{code:xml}
<name>dfs.journalnode.kerberos.principal</name>
<value>jn/_h...@example.com</value>
{code}
was:
I see the following issue in one of 3 JournalNodes:
"Only Namenode and another JournalNode may access this servlet".
The journalnode wants to download an edit log (shortly after startup) from
another journalnode, but in the request the short username equals the (long)
principal name and thus the request gets denied.
I'll add a PR which trims the principal to the actual short name, but I am not
sure why in the first place the request token contains the full principal name
and what the desired name actually is. Maybe I have a misconfiguration on my
end?
> JournalNode short name missmatch
> --------------------------------
>
> Key: HDFS-16356
> URL: https://issues.apache.org/jira/browse/HDFS-16356
> Project: Hadoop HDFS
> Issue Type: Bug
> Components: journal-node
> Affects Versions: 3.3.0
> Reporter: FliegenKLATSCH
> Priority: Major
> Labels: pull-request-available
> Time Spent: 20m
> Remaining Estimate: 0h
>
> I see the following issue in one of 3 JournalNodes:
> "Only Namenode and another JournalNode may access this servlet".
> The journalnode wants to download an edit log (shortly after startup) from
> another journalnode, but in the request the short username equals the (long)
> principal name and thus the request gets denied.
> I'll add a PR which trims the principal to the actual short name, but I am
> not sure why in the first place the request token contains the full principal
> name and what the desired name actually is. Maybe I have a misconfiguration
> on my end?
> "Server" side (scn1):
> {code:bash}
> 2021-11-26 09:02:04,609 DEBUG
> org.apache.hadoop.security.authentication.server.AuthenticationFilter:
> Request [https://scn1:8481/getJournal?jid=backups&segmentTxId=136002159
> 98&storageInfo=-65%3A1807091115%3A1522842919075%3ACID-661a9237-3a5d-4895-8257-1a2cc3642e98&inProgressOk=false]
> user [jn/s...@example.com] authenticated
> 2021-11-26 09:02:04,610 DEBUG org.eclipse.jetty.servlet.ServletHandler: call
> servlet
> getJournal@e931eb01==org.apache.hadoop.hdfs.qjournal.server.GetJournalEditServlet,jsp=null,ord
> er=-1,inst=true,async=true
> 2021-11-26 09:02:04,610 DEBUG
> org.apache.hadoop.hdfs.qjournal.server.GetJournalEditServlet: Validating
> request made by jn/s...@example.com / jn/s...@example.com. This user is:
> jn/s...@example.com (auth:KERBEROS)
> 2021-11-26 09:02:04,610 DEBUG
> org.apache.hadoop.hdfs.server.namenode.NameNode: Setting fs.defaultFS to
> hdfs://scn1:8020
> 2021-11-26 09:02:04,610 DEBUG
> org.apache.hadoop.hdfs.server.namenode.NameNode: Setting fs.defaultFS to
> hdfs://scn3:8020
> 2021-11-26 09:02:04,610 DEBUG
> org.apache.hadoop.hdfs.qjournal.server.GetJournalEditServlet:
> isValidRequestor is comparing to valid requestor: nn/s...@example.com
> 2021-11-26 09:02:04,610 DEBUG
> org.apache.hadoop.hdfs.qjournal.server.GetJournalEditServlet:
> isValidRequestor is comparing to valid requestor: nn/s...@example.com
> 2021-11-26 09:02:04,610 DEBUG
> org.apache.hadoop.hdfs.qjournal.server.GetJournalEditServlet:
> isValidRequestor is rejecting: jn/s...@example.com
> {code}
> "Client" side (scn2):
> {code:bash}
> 2021-11-26 08:56:03,377 INFO
> org.apache.hadoop.hdfs.qjournal.server.JournalNodeSyncer: Syncing Journal
> /0.0.0.0:8485 with scn1/1.2.6.9:8485, journal id: backups
> 2021-11-26 08:56:03,397 INFO
> org.apache.hadoop.hdfs.qjournal.server.JournalNodeSyncer: Downloading missing
> Edit Log from
> https://scn1:8481/getJournal?jid=backups&segmentTxId=13600215998&storageInfo=-65%3A1807091115%3A1522842919075%3ACID-661a9237-3a5d-4895-8257-1a2cc3642e98&inProgressOk=false
> to /hdfs/journal/backups
> 2021-11-26 08:56:03,412 ERROR
> org.apache.hadoop.hdfs.qjournal.server.JournalNodeSyncer: Download of Edit
> Log file for Syncing failed. Deleting temp file:
> /hdfs/journal/backups/edits.sync/edits_0000000013600215998-0000000013600227922
> org.apache.hadoop.hdfs.server.common.HttpGetFailedException: Image transfer
> servlet at
> https://scn1:8481/getJournal?jid=backups&segmentTxId=13600215998&storageInfo=-65%3A1807091115%3A152242919075%3ACID-661a9237-3a5d-4895-8257-1a2cc3642e98&inProgressOk=false
> failed with status code 403
> Response message:
> Only Namenode and another JournalNode may access this servlet
> at org.apache.hadoop.hdfs.server.common.Util.doGetUrl(Util.java:168)
> at
> org.apache.hadoop.hdfs.qjournal.server.JournalNodeSyncer.lambda$downloadMissingLogSegment$1(JournalNodeSyncer.java:448)
> at java.base/java.security.AccessController.doPrivileged(Native
> Method)
> at java.base/javax.security.auth.Subject.doAs(Subject.java:423)
> at
> org.apache.hadoop.security.UserGroupInformation.doAs(UserGroupInformation.java:1845)
> at
> org.apache.hadoop.security.SecurityUtil.doAsUser(SecurityUtil.java:518)
> at
> org.apache.hadoop.security.SecurityUtil.doAsLoginUser(SecurityUtil.java:499)
> at
> org.apache.hadoop.hdfs.qjournal.server.JournalNodeSyncer.downloadMissingLogSegment(JournalNodeSyncer.java:443)
> at
> org.apache.hadoop.hdfs.qjournal.server.JournalNodeSyncer.getMissingLogSegments(JournalNodeSyncer.java:355)
> at
> org.apache.hadoop.hdfs.qjournal.server.JournalNodeSyncer.syncWithJournalAtIndex(JournalNodeSyncer.java:259)
> at
> org.apache.hadoop.hdfs.qjournal.server.JournalNodeSyncer.syncJournals(JournalNodeSyncer.java:227)
> at
> org.apache.hadoop.hdfs.qjournal.server.JournalNodeSyncer.lambda$startSyncJournalsDaemon$0(JournalNodeSyncer.java:187)
> at java.base/java.lang.Thread.run(Thread.java:829)
> 2021-11-26 08:56:03,412 WARN
> org.apache.hadoop.hdfs.qjournal.server.JournalNodeSyncer: Deleting
> /hdfs/journal/backups/edits.sync/edits_0000000013600215998-0000000013600227922
> has failed
> 2021-11-26 08:56:03,412 ERROR
> org.apache.hadoop.hdfs.qjournal.server.JournalNodeSyncer: Aborting current
> sync attempt.
> {code}
> {code:xml}
> <name>dfs.journalnode.kerberos.principal</name>
> <value>jn/_h...@example.com</value>
> {code}
--
This message was sent by Atlassian Jira
(v8.20.1#820001)
---------------------------------------------------------------------
To unsubscribe, e-mail: hdfs-issues-unsubscr...@hadoop.apache.org
For additional commands, e-mail: hdfs-issues-h...@hadoop.apache.org
