How to enable FileClient debug logging in MapR

Document created by jbubier Employee on Feb 7, 2016Last modified by jbubier Employee on Feb 7, 2016
Version 2Show Document
  • View in full screen mode

Author: Jonathan Bubier

 

Original Publication Date: November 10, 2014

 

To access MapR's filesystem (MapR-FS) MapR provides a client implementation known as FileClient.  This client is necessary for all access to MapR-FS and is used by the Hadoop command line, the HBase shell, Hive, Pig and map-reduce among many other applications.. 

 

You may find that access to MapR-FS is not behaving as expected and require further details about the client behavior to debug the issue further.  The method for enabling the debug logging within MapR's FileClient differs depending on the client or application you are using to access MapR-FS.  This article will cover a few different methods for getting debug level logging from FileClient when accessing MapR-FS. 

 

1.  Using the hadoop command line

If the access issue is observed using the hadoop command line the debug logging can be enabled directly with the command execution.  For example, the original command is:

 

# hadoop fs -ls <path>

 

To enable debug logging add '-Dfs.mapr.trace=debug' to the command syntax and re-run the command.  Ex:

 


# hadoop fs -Dfs.mapr.trace=debug -ls <path>
Setting continuous mode
2014-11-10 12:12:32,3471 Program: fileclient on Host: NULL IP: 0.0.0.0, Port: 0, PID: 0
2014-11-10 12:12:32,3531 DEBUG Client fs/client/fileclient/cc/client.cc:4531 Thread: 7986 User buffersize = 1024
2014-11-10 12:12:32,3531 DEBUG Client fs/client/fileclient/cc/client.cc:4539 Thread: 7986 Group buffersize = 1024
2014-11-10 12:12:32,3533 DEBUG Client fs/client/fileclient/cc/client.cc:4570 Thread: 7986 PutBuffer memory threshold = 33554432 MB, flush interval = 3 secs, bufferSize =  131072 bytes
2014-11-10 12:12:32,3533 DEBUG Client fs/client/fileclient/cc/client.cc:4581 Thread: 7986 BulkLoader queueSz= 0MB flags=0
2014-11-10 12:12:32,3533 DEBUG JniCommon fs/client/fileclient/cc/jni_common.cc:397 Thread: 7986 GetUserName: Inserting to uid-table root, 0
2014-11-10 12:12:32,3828 DEBUG JniCommon fs/client/fileclient/cc/jni_common.cc:1158 Thread: 7986  -- Enter JNI OpenClient --
2014-11-10 12:12:32,3829 DEBUG Client fs/client/fileclient/cc/client.cc:305 Thread: 7986 InitCreds: number of groups = 1
2014-11-10 12:12:32,3829 DEBUG Client fs/client/fileclient/cc/client.cc:343 Thread: 7986 InitCreds: default user ID = 0
2014-11-10 12:12:32,3830 DEBUG Client fs/client/fileclient/cc/client.cc:349 Thread: 7986 Added gid 0
2014-11-10 12:12:32,3830 DEBUG Client fs/client/fileclient/cc/client.cc:351 Thread: 7986 effective gid 0 found in the group list
2014-11-10 12:12:32,3830 DEBUG Client fs/client/fileclient/cc/client.cc:490 Thread: 7986 Security not enabled
2014-11-10 12:12:32,3830 DEBUG Client fs/client/fileclient/cc/client.cc:5097 Thread: 7986 CheckImpersonation: Impersonation is disabled; all attempts at impersonation will use the process user
2014-11-10 12:12:32,3830 DEBUG Client fs/client/fileclient/cc/client.cc:559 Thread: 7986 Init: cluster my.cluster.com pid 7939, CLDB 10.10.80.177:7222, numCLDBs 3
2014-11-10 12:12:32,3832 DEBUG Cidcache fs/client/fileclient/cc/cidcache.cc:1242 Thread: 7986 Requesting Volume mapr.cluster.root srcCluster null vtype 2 wantMirror 1
2014-11-10 12:12:32,3832 DEBUG Cidcache fs/client/fileclient/cc/cidcache.cc:1250 Thread: 7986 Requesting for cldb information
2014-11-10 12:12:32,3843 DEBUG Cidcache fs/client/fileclient/cc/cidcache.cc:1346 Thread: 7986 Received Cldb Ips from 10.10.80.177:7222
2014-11-10 12:12:32,3844 DEBUG Cidcache fs/client/fileclient/cc/cidcache.cc:1359 Thread: 7986 Received Cldb Ip : 10.10.80.176:7222
2014-11-10 12:12:32,3844 DEBUG Cidcache fs/client/fileclient/cc/cidcache.cc:1359 Thread: 7986 Received Cldb Ip : 10.10.80.177:7222
2014-11-10 12:12:32,3844 DEBUG Cidcache fs/client/fileclient/cc/cidcache.cc:1359 Thread: 7986 Received Cldb Ip : 10.10.80.178:7222
...
2014-11-10 12:12:32,3942 DEBUG JniCommon fs/client/fileclient/cc/jni_common.cc:893 Thread: 7986  -- Enter createJNIFileStatus --
2014-11-10 12:12:32,3942 DEBUG JniCommon fs/client/fileclient/cc/jni_common.cc:137 Thread: 7986 IdLookup: Found user: mapr, id: 2147483632
2014-11-10 12:12:32,3942 DEBUG JniCommon fs/client/fileclient/cc/jni_common.cc:137 Thread: 7986 IdLookup: Found group: mapr, id: 2147483632
2014-11-10 12:12:32,3942 Found 4 items
drwxr-xr-x   - mapr mapr          9 2014-10-01 09:22 /hbase
drwxr-xr-x   - root root          2 2014-11-05 12:00 /tables
drwxr-xr-x   - mapr mapr          3 2014-07-08 12:50 /user
drwxr-xr-x   - mapr mapr          1 2014-06-11 13:45 /var
DEBUG JniCommon fs/client/fileclient/cc/jni_common.cc:1003 Thread: 7986 Created JNIFileStatus obj
2014-11-10 12:12:32,3942 DEBUG JniCommon fs/client/fileclient/cc/jni_common.cc:1013 Thread: 7986  -- Exit createJNIFileStatus --
2014-11-10 12:12:32,3942 DEBUG JniCommon fs/client/fileclient/cc/jni_common.cc:2411 Thread: 7986  -- Exit JNI readdirplus -- /

 

 

Given the operation being performed the output with this option added is likely to be very verbose.  The output can be redirected to a file to review later or provide to MapR support using the following:

 

# hadoop fs -Dfs.mapr.trace=debug -ls / >> ~/debug.out 2>&1

 

This will output the full debug log to a file 'debug.out' in the current user's home directory. 

 

2.  Using core-site.xml

 

If the issue being observed when accessing MapR-FS is from map-reduce tasks, the HBase shell or any application where the '-Dfs.mapr.trace=debug' option cannot be invoked directly the debug logging can be enabled in core-site.xml.  This method can also be used for debugging the command line so the '-Dfs.mapr.trace=debug' option is not needed on every invocation.  Depending on your Hadoop version core-site.xml will be under /opt/mapr/hadoop/hadoop-0.20.2/conf/ or /opt/mapr/hadoop/hadoop-2.4.1/etc/hadoop/core-site.xml.  Add the following property to core-site.xml and save the changes:

 


<property>
<name>fs.mapr.trace</name>
<value>debug</value>
</property>

 

 

Note that making this change in core-site.xml will affect every process that accesses MapR-FS using FileClient and will result in verbose debug output printed to the process' stderr. 

 

3.  Using app-specific configuration

 

As mentioned in #2 above core-site.xml from the HADOOP_CONF directory can be used to fs.mapr.trace to enable FileClient debug level logging.  However as this configuration file is picked up by many processes that access MapR-FS the verbosity can make debugging difficult.  If the issue is specific to a single environment such as Hive, Pig or the HBase shell the configuration can be set specific to just the affected application.  For example, to enable the FileClient logging for just the Hive shell the fs.mapr.trace property XML from #2 can be put in /opt/mapr/hive/hive-<version>/conf/hive-site.xml where <version> is the installed Hive version.  Alternatively the Hive shell can be launched as follows:

 

# hive --hiveconf fs.mapr.trace=debug

 

To enable the FileClient logging for just the HBase shell, for example to diagnose an issue accessing HBase or M7 tables on MapR-FS the fs.mapr.trace property XML from #2 can be put in /opt/mapr/hbase/hbase-<version>/conf/hbase-site.xml where <version> is the installed HBase version. Ex:

 


hbase(main):001:0> scan '/t1',{LIMIT=>1}
ROW                                                 COLUMN+CELL
Setting continuous mode
2014-11-10 13:24:39,5987 Program: fileclient on Host: NULL IP: 0.0.0.0, Port: 0, PID: 0
2014-11-10 13:24:39,6051 DEBUG Client fs/client/fileclient/cc/client.cc:4531 Thread: 24369 User buffersize = 1024
2014-11-10 13:24:39,6051 DEBUG Client fs/client/fileclient/cc/client.cc:4539 Thread: 24369 Group buffersize = 1024
2014-11-10 13:24:39,6064 DEBUG Client fs/client/fileclient/cc/client.cc:4570 Thread: 24369 PutBuffer memory threshold = 33554432 MB, flush interval = 3 secs, bufferSize =  131072 bytes
2014-11-10 13:24:39,6064 DEBUG Client fs/client/fileclient/cc/client.cc:4581 Thread: 24369 BulkLoader queueSz= 0MB flags=0
2014-11-10 13:24:39,6064 DEBUG JniCommon fs/client/fileclient/cc/jni_common.cc:397 Thread: 24369 GetUserName: Inserting to uid-table root, 0
2014-11-10 13:24:39,6206 DEBUG JniCommon fs/client/fileclient/cc/jni_common.cc:1158 Thread: 24369  -- Enter JNI OpenClient --
2014-11-10 13:24:39,6207 DEBUG Client fs/client/fileclient/cc/client.cc:305 Thread: 24369 InitCreds: number of groups = 1
2014-11-10 13:24:39,6207 DEBUG Client fs/client/fileclient/cc/client.cc:343 Thread: 24369 InitCreds: default user ID = 0
2014-11-10 13:24:39,6208 DEBUG Client fs/client/fileclient/cc/client.cc:349 Thread: 24369 Added gid 0
2014-11-10 13:24:39,6208 DEBUG Client fs/client/fileclient/cc/client.cc:351 Thread: 24369 effective gid 0 found in the group list
2014-11-10 13:24:39,6208 DEBUG Client fs/client/fileclient/cc/client.cc:490 Thread: 24369 Security not enabled
...
2014-11-10 13:24:39,6805 DEBUG Client fs/client/fileclient/cc/scanner.cc:183 Thread: 24369 Scanner FetchData: Scan of table /t1 received 1 rows
2014-11-10 13:24:39,6805 DEBUG Client fs/client/fileclient/cc/scanner.cc:188 Thread: 24369 Scanner FetchData: Finished scanning for table /t1
2014-11-10 13:24:39,6806 DEBUG Client fs/client/fileclient/cc/scanner.cc:240 Thread: 24369  -- Exit Scanner FetchData -- table /t1, err 0
2014-11-10 13:24:39,6806 DEBUG JniCommon fs/client/fileclient/cc/jni_common.cc:7889 Thread: 24369 -- Exit JNI GetScanner -- table /t1, scanner=0x7f2a18be3e20
2014-11-10 13:24:39,6892 DEBUG JniCommon fs/client/fileclient/cc/jni_common.cc:7929 Thread: 24369 -- Enter JNI ScanNext -- table /t1, rows = 100, scanner = 139818780474912
2014-11-10 13:24:39,6893 DEBUG Client fs/client/fileclient/cc/scanner.cc:31 Thread: 24369  -- Enter Scanner Next -- table /t1, numRows = 100
2014-11-10 13:24:39,6893 DEBUG Client fs/client/fileclient/cc/scanner.cc:64 Thread: 24369  -- Exit Scanner Next -- table /t1, Error = Success(0), numRows = 99
2014-11-10 13:24:39,6893 DEBUG JniCommon fs/client/fileclient/cc/jni_common.cc:7125 Thread: 24369 SetResult: Got row with #cells 1, #columns 1
2014-11-10 13:24:39,6893 DEBUG JniCommon fs/client/fileclient/cc/jni_
-ABC                                               column=cf1:col1, timestamp=1407950604357, value=val1
1 row(s) in 0.3220 seconds

 

hbase(main):002:0>

 

4.  Programmatically within application code

 

If the issue being observed when accessing MapR-FS is from user application code the 'fs.mapr.trace' configuration can be added directly to the application configuration code.  Ex:

 

 

Configuration conf = new Configuration(); conf.set("fs.mapr.trace","debug");

 


This will enable FileClient debug logging when the application code is run and calls are made to access MapR-FS.

1 person found this helpful

Attachments

    Outcomes