Mapr-client errors when trying to connect to Data Fabric sandbox 7.0

[rbukarev]

I have installed HPE Data Fabric 7.0 sandbox in a Docker container (I edited the container to expose port 7443 in addition to others). I have installed mapr-client software on a separate VM (both VMs are in GCP cloud). I successfully authorised from the client machine using maprlogin password command and see the ticket in /tmp on the client machine:

[root@cs-roman-engine-03 tmp]# cat maprticket_0
maprdemo.mapr.io bWZzY+ZaDHa......Fivi2W4PZrcvlT5ID9oqaR==

While connected to command line of the sandbox, I wrote some data into /tmp/out.

root@maprdemo:~# hadoop fs -ls /tmp/out/2023-09-28-06
Found 1 items
-rwxr-xr-x   3 roman roman         34 2023-09-28 06:18 /tmp/out/2023-09-28-06/mydatafile.txt

Now I'm trying to browse MapR-FS and run "hadoop fs -ls /tmp/out" command and getting weird results:

1. When running hadoop command in /opt/mapr/bin, there's an error:

[root@cs-roman-engine-03 bin]# pwd
/opt/mapr/bin
[root@cs-roman-engine-03 bin]# ./hadoop fs -ls /tmp/out
ls: Could not create FileClient err: 104

2. When running GCP's (preinstalled) hadoop command, I'm getting weird exceptions, but, in the end, some result:

[root@cs-roman-engine-03 bin]# hadoop fs -ls /tmp/out
Sep 28, 2023 7:32:15 AM com.google.common.cache.LocalCache$Segment$1 run
WARNING: Exception thrown during refresh
com.google.common.cache.CacheLoader$InvalidCacheLoadException: CacheLoader returned null for key 0.
        at com.google.common.cache.LocalCache$Segment.getAndRecordStats(LocalCache.java:2315)
        at com.google.common.cache.LocalCache$Segment$1.run(LocalCache.java:2293)
        at com.google.common.util.concurrent.DirectExecutor.execute(DirectExecutor.java:30)
        at com.google.common.util.concurrent.AbstractFuture.executeListener(AbstractFuture.java:1164)
        at com.google.common.util.concurrent.AbstractFuture.addListener(AbstractFuture.java:708)
        at com.google.common.util.concurrent.AbstractFuture$TrustedFuture.addListener(AbstractFuture.java:113)
        at com.google.common.cache.LocalCache$Segment.loadAsync(LocalCache.java:2288)
        at com.google.common.cache.LocalCache$Segment.refresh(LocalCache.java:2360)
        at com.google.common.cache.LocalCache.refresh(LocalCache.java:4123)
        at com.google.common.cache.LocalCache$LocalLoadingCache.refresh(LocalCache.java:4977)
        at com.mapr.fs.MapRClientImpl.refreshZkConnectString(MapRClientImpl.java:1709)
        at com.mapr.fs.MapRClientImpl.<init>(MapRClientImpl.java:158)
        at com.mapr.fs.MapRFileSystem.lookupClient(MapRFileSystem.java:730)
        at com.mapr.fs.MapRFileSystem.lookupClient(MapRFileSystem.java:789)
        at com.mapr.fs.MapRFileSystem.getMapRFileStatus(MapRFileSystem.java:1569)
        at com.mapr.fs.MapRFileSystem.getFileStatus(MapRFileSystem.java:1219)
        at org.apache.hadoop.fs.FileSystem.exists(FileSystem.java:1467)
        at org.apache.hadoop.fs.Globber.doGlob(Globber.java:236)
        at org.apache.hadoop.fs.Globber.glob(Globber.java:150)
        at org.apache.hadoop.fs.FileSystem.globStatus(FileSystem.java:1698)
        at org.apache.hadoop.fs.shell.PathData.expandAsGlob(PathData.java:326)
        at org.apache.hadoop.fs.shell.Command.expandArgument(Command.java:237)
        at org.apache.hadoop.fs.shell.Command.expandArguments(Command.java:220)
        at org.apache.hadoop.fs.shell.Command.processRawArguments(Command.java:203)
        at org.apache.hadoop.fs.shell.Command.run(Command.java:167)
        at org.apache.hadoop.fs.FsShell.run(FsShell.java:306)
        at org.apache.hadoop.util.ToolRunner.run(ToolRunner.java:70)
        at org.apache.hadoop.util.ToolRunner.run(ToolRunner.java:84)
        at org.apache.hadoop.fs.FsShell.main(FsShell.java:363)

Found 1 items
drwxr-xr-x   - anthony gke-00cbfe9f484941f993aa          2 2023-09-28 06:29 /tmp/out/2023-09-28-06

Now, I don't really need GCP's hadoop command, but I'd like the "native" one to work. How can I do some diagnostics to check that my mapr-client is configured correctly? @ldarby any comment? thank you very much in advance?

[ldarby]

Hi @rbukarev,

The 104 means 'Connection reset by peer' (in this case, it's a standard errno), please try enabling debug like this for more info:

[root@cs-roman-engine-03 bin]# ./hadoop fs -Dfs.mapr.trace=DEBUG -ls /tmp/out

Regards,
Laurence Darby

[rbukarev]

@ldarby thanks! Here's the debug info (my questions follow it). 10.128.0.18 is the address of VM hosting MapR container.

23/09/28 11:10:14 DEBUG fs.MapRFileSystem: Enter getFileStatus: path maprfs:/tmp
23/09/28 11:10:14 DEBUG fs.MapRFileSystem: Enter getMapRFileStatus path maprfs:/tmp
23/09/28 11:10:14 DEBUG client.MapRLoginHttpsClient: Entering authenticate if needed.
23/09/28 11:10:14 DEBUG client.MapRLoginHttpsClient: Kerberos not configured for this cluster.
23/09/28 11:10:14 DEBUG client.MapRLoginHttpsClient: found existing MapR ticket
23/09/28 11:10:14 DEBUG client.MapRLoginHttpsClient: Already have good ticket, done
2023-09-28 11:10:14,5985 DEBUG Client fc/client.cc:13269 Thread: 8592 shmemsize: 2560 raSize: 0 largePagePoolSize: 0
2023-09-28 11:10:14,6095 DEBUG Client fc/client.cc:13290 Thread: 8592 connect timeout value : 0
2023-09-28 11:10:14,6095 DEBUG Client fc/client.cc:13300 Thread: 8592 binding inactive threshold seconds : requested 0 actual 0
2023-09-28 11:10:14,6095 DEBUG Client fc/client.cc:13313 Thread: 8592 User buffersize = 1024
2023-09-28 11:10:14,6095 DEBUG Client fc/client.cc:13321 Thread: 8592 Group buffersize = 1024
2023-09-28 11:10:14,6095 INFO Client fc/client.cc:13341 Thread: 8592 Uid cache timeout set to 1800 seconds
2023-09-28 11:10:14,6095 DEBUG Client fc/writequeue.cc :67 Thread: 8592 Initializing 8 number of writer/flusher threads
2023-09-28 11:10:14,6100 DEBUG Client fc/client.cc:13397 Thread: 8592 PutBuffer memory threshold = 33554432 MB, flush interval = 3 secs, bufferSize =  131072 bytes,  rpcServerSelectFuncType: 0
2023-09-28 11:10:14,6100 DEBUG Client fc/client.cc:13400 Thread: 8592 Schema ttl = 10000 milliseconds
2023-09-28 11:10:14,6100 DEBUG Client fc/client.cc:13403 Thread: 8592 TabletMap ttl = 3600000 milliseconds
2023-09-28 11:10:14,6101 DEBUG Client fc/client.cc:13406 Thread: 8592 tableCacheMaxLruSize = 134217728 bytes
2023-09-28 11:10:14,6101 DEBUG Client fc/client.cc:13409 Thread: 8592 tableCacheMaxSize = 157286400 bytes
2023-09-28 11:10:14,6101 DEBUG Client fc/client.cc:13420 Thread: 8592 BulkLoader queueSz= 0MB flags=0
2023-09-28 11:10:14,6102 DEBUG Client fc/client.cc:1960 Thread: 8592 JavaInit: succeeded
2023-09-28 11:10:14,6105 DEBUG Client fc/client.cc:1867 Thread: 8592 InitCreds: number of groups = 4
2023-09-28 11:10:14,6106 DEBUG Client fc/client.cc:1905 Thread: 8592 InitCreds: default user ID = 1005
2023-09-28 11:10:14,6106 DEBUG Client fc/client.cc:1911 Thread: 8592 Added gid 4
2023-09-28 11:10:14,6106 DEBUG Client fc/client.cc:1911 Thread: 8592 Added gid 39
2023-09-28 11:10:14,6106 DEBUG Client fc/client.cc:1911 Thread: 8592 Added gid 1000
2023-09-28 11:10:14,6106 DEBUG Client fc/client.cc:1911 Thread: 8592 Added gid 1006
2023-09-28 11:10:14,6106 DEBUG Client fc/client.cc:1913 Thread: 8592 effective gid 1006 found in the group list
2023-09-28 11:10:14,6107 DEBUG Client fc/client.cc:1918 Thread: 8592 effective gid moved to top from index 3
2023-09-28 11:10:14,6108 DEBUG ApiCommon fc/api_common.cc:230 Thread: 8592 IdInsert: Inserted roman, 1001
2023-09-28 11:10:14,6108 DEBUG ApiCommon fc/api_common.cc:2697 Thread: 8592 Success: Inserting to uid-table 1001, roman, TRUE
2023-09-28 11:10:14,6108 DEBUG ApiCommon fc/api_common.cc:172 Thread: 8592 IdLookup: Found user: roman, id: 1001
2023-09-28 11:10:14,6108 DEBUG Client fc/client.cc:2725 Thread: 8592 Default uid,username set to secure uid = 1001, roman
2023-09-28 11:10:14,6108 DEBUG ApiCommon fc/api_common.cc:172 Thread: 8592 IdLookup: Found user: roman, id: 1001
2023-09-28 11:10:14,6109 DEBUG Client fc/writebuf.cc:411 Thread: 8592 Idle flusher started!
2023-09-28 11:10:14,6109 DEBUG Client fc/client.cc:2434 Thread: 8592 Init: cluster maprdemo.mapr.io pid 8370, CLDB 10.128.0.18:7222, numCLDBs 1
2023-09-28 11:10:14,6116 DEBUG Client fc/client.cc:617 Thread: 8592 ClusterConf file being used is: /opt/mapr/hadoop/hadoop-2.7.6/etc/mapr-clusters.conf
2023-09-28 11:10:14,6124 DEBUG Cidcache fc/cidcache.cc:2570 Thread: 8592 MfsUtilKey is set for cluster maprdemo.mapr.io
2023-09-28 11:10:14,6125 DEBUG Cidcache fc/cidcache.cc:3051 Thread: 8592 Found cldb cluster information for: maprdemo.mapr.io
2023-09-28 11:10:14,6125 DEBUG Cidcache fc/cidcache.cc:3461 Thread: 8592 Number of additional ports: 1
2023-09-28 11:10:14,6126 DEBUG Cidcache fc/cidcache.cc:2966 Thread: 8592 cldb index 0 : 10.128.0.18:7223
2023-09-28 11:10:14,6126 DEBUG Cidcache fc/cidcache.cc:2966 Thread: 8592 cldb index 1 : 10.128.0.18:7222
2023-09-28 11:10:14,6126 DEBUG Cidcache fc/cidcache.cc:3051 Thread: 8592 Found cldb cluster information for: maprdemo.mapr.io
2023-09-28 11:10:14,6126 DEBUG Cidcache fc/cidcache.cc:3441 Thread: 8592 Number of unreachable cldb ips: 0
2023-09-28 11:10:14,6127 DEBUG Cidcache fc/cidcache.cc:3594 Thread: 8592 Requesting Volume mapr.cluster.root srcCluster null vtype 2 wantMirror 1
2023-09-28 11:10:14,6129 DEBUG Cidcache fc/cidcache.cc:3602 Thread: 8592 Requesting for cldb information
2023-09-28 11:10:14,6535 DEBUG Cidcache fc/cidcache.cc:4277 Thread: 8592 Invalidating CLDB binding: 10.128.0.18:7223
2023-09-28 11:10:14,6535 DEBUG Cidcache fc/cidcache.cc:4277 Thread: 8592 Invalidating CLDB binding: 10.128.0.18:7222
2023-09-28 11:10:14,6535 DEBUG Cidcache fc/cidcache.cc:4132 Thread: 8592 CLDB binding: 10.128.0.18:7222is invalid 
2023-09-28 11:10:14,6535 DEBUG Cidcache fc/cidcache.cc:4132 Thread: 8592 CLDB binding: 10.128.0.18:7223is invalid 
2023-09-28 11:10:14,6535 DEBUG Cidcache fc/cidcache.cc:4147 Thread: 8592 No valid cldb binding is found
2023-09-28 11:10:14,6536 DEBUG Client fc/client.cc:617 Thread: 8592 ClusterConf file being used is: /opt/mapr/hadoop/hadoop-2.7.6/etc/mapr-clusters.conf
2023-09-28 11:10:14,6536 ERROR Cidcache fc/cidcache.cc:4172 Thread: 8592 CLDB index: 0 10.128.0.18:7223 InvalTime: 1695899414653
2023-09-28 11:10:14,6536 ERROR Cidcache fc/cidcache.cc:4172 Thread: 8592 CLDB index: 1 10.128.0.18:7222 InvalTime: 1695899414653
2023-09-28 11:10:14,6543 ERROR Cidcache fc/cidcache.cc:4174 Thread: 8592 MoveToNextCldb: No valid CLDB entries, sleep 5 seconds
2023-09-28 11:10:14,6543 DEBUG Cidcache fc/cidcache.cc:5321 Thread: 8592 Sending RPC to CLDB: 10.128.0.18:7223
2023-09-28 11:10:14,6934 ERROR Cidcache fc/cidcache.cc:5332 Thread: 8592 Received error Connection reset by peer(104) while trying to reach CLDB: 10.128.0.18:7223
2023-09-28 11:10:14,6934 ERROR Cidcache fc/cidcache.cc:1262 Thread: 8592 proc RPC error Connection reset by peer (104) to CLDB 10.128.0.18:7223 failed
2023-09-28 11:10:14,6934 DEBUG Cidcache fc/cidcache.cc:4277 Thread: 8592 Invalidating CLDB binding: 10.128.0.18:7223
2023-09-28 11:10:14,6934 DEBUG Cidcache fc/cidcache.cc:4277 Thread: 8592 Invalidating CLDB binding: 10.128.0.18:7222
2023-09-28 11:10:14,6934 DEBUG Cidcache fc/cidcache.cc:4132 Thread: 8592 CLDB binding: 10.128.0.18:7222is invalid 
2023-09-28 11:10:14,6934 DEBUG Cidcache fc/cidcache.cc:4132 Thread: 8592 CLDB binding: 10.128.0.18:7223is invalid 
2023-09-28 11:10:14,6940 DEBUG Cidcache fc/cidcache.cc:4147 Thread: 8592 No valid cldb binding is found
2023-09-28 11:10:14,6941 DEBUG Client fc/client.cc:617 Thread: 8592 ClusterConf file being used is: /opt/mapr/hadoop/hadoop-2.7.6/etc/mapr-clusters.conf
2023-09-28 11:10:14,6941 ERROR Cidcache fc/cidcache.cc:4172 Thread: 8592 CLDB index: 0 10.128.0.18:7223 InvalTime: 1695899414693
2023-09-28 11:10:14,6941 ERROR Cidcache fc/cidcache.cc:4172 Thread: 8592 CLDB index: 1 10.128.0.18:7222 InvalTime: 1695899414693
2023-09-28 11:10:14,6941 ERROR Cidcache fc/cidcache.cc:4174 Thread: 8592 MoveToNextCldb: No valid CLDB entries, sleep 5 seconds
2023-09-28 11:10:24,6945 DEBUG Cidcache fc/cidcache.cc:2627 Thread: 8592 Lookup of volume mapr.cluster.root failed, error Connection reset by peer(104): 
2023-09-28 11:10:24,6945 ERROR Client fc/client.cc:2499 Thread: 8592 Init: Failed to initialize cidCache for cluster maprdemo.mapr.io, CLDB 10.128.0.18:7222, errls: Could not create FileClient err: 104
23/09/28 11:10:25 DEBUG fs.MapRFileSystem: Enter close:
23/09/28 11:10:25 DEBUG fs.MapRFileSystem: Exit close:
or 104
2023-09-28 11:10:24,6950 ERROR Client fc/client.cc:2078 Thread: 8592 Failed to initialize client for cluster maprdemo.mapr.io, error Connection reset by peer(104)
2023-09-28 11:10:24,6950 DEBUG Client fc/client.cc:2362 Thread: 8592 MapClient object destructor
2023-09-28 11:10:25,6145 DEBUG Client fc/client.cc:2411 Thread: 8592 MapClient object destroyed
2023-09-28 11:10:25,6147 ERROR JniCommon fc/jni_MapRClient.cc:712 Thread: 8592 GetClient: Failed, numRpcThreads: 0
2023-09-28 11:10:25,6147 DEBUG JniCommon fc/jni_MapRClient.cc:741 Thread: 8592  -- Exit JNI OpenClientInternal --

I can see the port 7222 is open, but 7223 is not. Should I change the container config so that port would be mapped, too?

And why is it not connecting via 7222?

[rbukarev]

So I opened port 7223 on the docker container, and now ./hadoop fs -ls /tmp/out works fine. But interestingly, I didn't notice that port mentioned in debug this time (*shrugs*)

Now, I wonder how I can get rid of this exception:

[roman@cs-roman-engine-03 bin]$ ./hadoop fs -ls /tmp/out
Sep 28, 2023 11:59:43 AM com.google.common.cache.LocalCache$Segment$1 run
WARNING: Exception thrown during refresh
com.google.common.cache.CacheLoader$InvalidCacheLoadException: CacheLoader returned null for key 0.
        at com.google.common.cache.LocalCache$Segment.getAndRecordStats(LocalCache.java:2315)
        at com.google.common.cache.LocalCache$Segment$1.run(LocalCache.java:2293)
        at com.google.common.util.concurrent.DirectExecutor.execute(DirectExecutor.java:30)
        at com.google.common.util.concurrent.AbstractFuture.executeListener(AbstractFuture.java:1164)
        at com.google.common.util.concurrent.AbstractFuture.addListener(AbstractFuture.java:708)
        at com.google.common.util.concurrent.AbstractFuture$TrustedFuture.addListener(AbstractFuture.java:113)
        at com.google.common.cache.LocalCache$Segment.loadAsync(LocalCache.java:2288)
        at com.google.common.cache.LocalCache$Segment.refresh(LocalCache.java:2360)
        at com.google.common.cache.LocalCache.refresh(LocalCache.java:4123)
        at com.google.common.cache.LocalCache$LocalLoadingCache.refresh(LocalCache.java:4977)
        at com.mapr.fs.MapRClientImpl.refreshZkConnectString(MapRClientImpl.java:1709)
        at com.mapr.fs.MapRClientImpl.<init>(MapRClientImpl.java:158)
        at com.mapr.fs.MapRFileSystem.lookupClient(MapRFileSystem.java:730)
        at com.mapr.fs.MapRFileSystem.lookupClient(MapRFileSystem.java:789)
        at com.mapr.fs.MapRFileSystem.getMapRFileStatus(MapRFileSystem.java:1569)
        at com.mapr.fs.MapRFileSystem.getFileStatus(MapRFileSystem.java:1219)
        at org.apache.hadoop.fs.FileSystem.exists(FileSystem.java:1467)
        at org.apache.hadoop.fs.Globber.doGlob(Globber.java:236)
        at org.apache.hadoop.fs.Globber.glob(Globber.java:150)
        at org.apache.hadoop.fs.FileSystem.globStatus(FileSystem.java:1698)
        at org.apache.hadoop.fs.shell.PathData.expandAsGlob(PathData.java:326)
        at org.apache.hadoop.fs.shell.Command.expandArgument(Command.java:237)
        at org.apache.hadoop.fs.shell.Command.expandArguments(Command.java:220)
        at org.apache.hadoop.fs.shell.Command.processRawArguments(Command.java:203)
        at org.apache.hadoop.fs.shell.Command.run(Command.java:167)
        at org.apache.hadoop.fs.FsShell.run(FsShell.java:306)
        at org.apache.hadoop.util.ToolRunner.run(ToolRunner.java:70)
        at org.apache.hadoop.util.ToolRunner.run(ToolRunner.java:84)
        at org.apache.hadoop.fs.FsShell.main(FsShell.java:363)

Found 2 items
drwxr-xr-x   - roman gke-00cbfe9f484941f993aa          2 2023-09-28 06:29 /tmp/out/2023-09-28-06
drwxr-xr-x   - roman gke-00cbfe9f484941f993aa          1 2023-09-28 11:56 /tmp/out/2023-09-28-11

Mind you, this time I'm running hadoop utility specifically from /opt/mapr/bin

[ldarby]

Hi @rbukarev,

I've confirmed it randomly picks one of the 7222 or 7223 ports, in the debug output it either has this:

2023-09-28 11:10:14,6126 DEBUG Cidcache fc/cidcache.cc:2966 Thread: 8592 cldb index 0 : 10.128.0.18:7223
2023-09-28 11:10:14,6126 DEBUG Cidcache fc/cidcache.cc:2966 Thread: 8592 cldb index 1 : 10.128.0.18:7222

or the other way with index 0: 7222 and index 1: 7223, and it only tries the first and doesn't retry the 2nd (it only retries other IPs, i.e. multiple CLDBs with HA).  The multiple ports are for performance reasons, see https://docs.ezmeral.hpe.com/datafabric-customer-managed/74/ReferenceGuide/MapRPorts.html.

Since the stack trace from the google hadoop shows it picked up the MapR client libraries (I believe that's necessary for it to connect at all) then possibly it could try to connect to port 7223 as well and was just chance that it didn't.

Regards,
Laurence

[ldarby]

@rbukarev About the stack trace, it mentions the com.google.common java libraries, there is a copy of these shipped in the mapr-client package (in /opt/mapr/lib/guava...jar, which MapR hadoop uses), so possibly your system has a separate copy of this library and the Google hadoop has picked up that version via the classpath, and maybe that version isn't compatible with the MapR client library (which Google hadoop is using)?

Regards,
Laurence

[rbukarev · Accepted solution]

I reproduced the same error in Azure VM, where no preinstalled hadoop utility exists on VMs.

Then I realised that I'm using mapr-client v.7 (Hadoop 2.7.6) while my Sandbox Container had Hadoop 3.5. 

Apparently, even if I used Sandbox instalation script from Mapr 7.0 section of HPE website, by default it pulls maprtech/...latest image, which was obviously not 7.0

[rbukarev]

I also realised that MapR 7.0 Sandbox is not secured cluster. Now I need to reconfigure it as a secured one.