PowerScale: Reading CloudPools Log Messages
Summary: How to parse messages in CloudPools logs.
Instructions
CloudPools logs messages based on the activities or tasks being performed, and the issue encountered or reason for the message. The details in these messages can often be missed, but provide important information towards interpretation. You can find these messages in the messages file isi_cpool_d.log or in isi_cpool_io_d.log.
Here are a couple of examples:
2017-07-03T13:03:59-06:00 <3.3> isilon-1 isi_cpool_d[2547]: [0x800710610]: /b/mnt/src/isilon/lib/isi_cpool_d/task_processing_thread_pool.cpp:run_consumer_function:196: run_consumer_function complete for task ([cache-invalidation/1:054d:b5b7::HEAD]): Writing Cache Header: Read-only file system from write_header (/b/mnt/src/isilon/lib/isi_cpool_cbm/isi_cbm_cache.cpp:360) from clear_state (/b/mnt/src/isilon/lib/isi_cpool_cbm/isi_cbm_cache.cpp:907): clearing cacheheader state from isi_cbm_invalidate_cache_i (/b/mnt/src/isilon/lib/isi_cpool_cbm/isi_cbm_invalidate.cpp:262): Could not reset CACHED state flag for 1:054d:b5b7 from isi_cbm_invalidate_cached_file_opt (/b/mnt/src/isilon/lib/isi_cpool_cbm/isi_cbm_invalidate.cpp:518)
An important key for narrowing down the source and cause of the message is the task information:
Task ([cache-invalidation/1:054d:b5b7::HEAD])
The task type (cache-invalidation) points back to a cloud job that generated the message. In this case job 2, the cache invalidation job:
tf80-1# isi cloud jobs list ID Description Effective State Type -------------------------------------------------------------------------------------- 1 Write updated data back to the cloud running cache-writeback 2 Expire CloudPools cache running cache-invalidation 3 Clean up cache and stub file metadata running local-garbage-collection 4 Clean up unreferenced data in the cloud running cloud-garbage-collection 491 error archive 492 error archive>
The LIN can be used to track down the LIN on that system, if it still exists.
If the task type is Not called out in the message, you can still determine the type of operation.
Here is an example:
If you saw these messages:
2018-08-13T12:49:38+02:00 <3.6> Isilon-1 isi_cpool_d[4520]: [0x80f7d0610]: /b/mnt/src/isilon/lib/isi_cloud_api/cl_provider.cpp:do_with_retry_common:73: Operation: get_object, current try: 0, total retries: 140733193388032, total failures: 1, error: clapi error: CL_OBJ_NOT_FOUND; AEC_NOT_FOUND 2018-08-13T12:49:38+02:00 <3.3> Isilon-1 isi_cpool_d[4520]: [0x80f7d0610]: /b/mnt/src/isilon/lib/isi_cpool_cbm/isi_cbm_error_util.cpp:send_cloudpools_event:314: isi_cpool_cbm error in isi_cph_read_md_blob: CloudPools Object not found. provider RAN, devid 1, account X210_cloud, entitypath m0007430b5526ccc7be54980e747b9db7883ai11/007034b0250780fde1b5283187d98e49_00000000_1, filename , lin 0, offset -1, errormessage clapi error: CL_OBJ_NOT_FOUND; AEC_NOT_FOUND: [error code: CBM_CLAPI_OBJECT_NOT_FOUND]This information tells you the process and thread. You can look back further in the log file (in this case,
isi_cpool_d.log) for the initialization of that thread. Here is the initialization for that thread:
2018-05-23T07:51:43+02:00 <3.6> Isilon-1 isi_cpool_d[4520]: [0x80f7d0610]: /b/mnt/src/isilon/lib/isi_cpool_d/task_processing_thread_pool.cpp:start_thread:506: starting normal thread for type cloud-gc
A cloud garbage collection process has encountered this error. The "Object Not Found" message does not indicate data loss. Because this occurs during a routine garbage collection and cleanup process, the object was already scheduled for deletion. Had this been a recall operation then the error would have been more significant.
The reason for the issue is sometimes provided:
Writing Cache Header: Read-only file system Could not reset CACHED state flag for 1:054d:b5b7
The system is unable to reset the cache state flag for the LIN because the file system is in a read-only state. In this specific case, this was a normal and expected message on a SyncIQ target path, but investigation should be done into whether the path is or should be read-only.
Another example:
2017-06-19T09:13:15-04:00 <3.7> isilon-2 isi_cpool_d[4531]: [0x80ef97c10]: /b/mnt/src/isilon/lib/isi_cpool_d/task_processing_thread_pool.cpp:run_consumer_function:196: run_consumer_function complete for task ([archive/1:5d01:0232::HEAD]/CloudPool-5yrs): File modified after stubbing began; lin 1:5d01:0232: [error code: CBM_STALE_STUB_ERROR] from write_map_core (/b/mnt/src/isilon/lib/isi_cpool_cbm/isi_cbm_mapper.cpp:1615) from write_map (/b/mnt/src/isilon/lib/isi_cpool_cbm/isi_cbm_mapper.cpp:1653) from isi_cph_create_stub (/b/mnt/src/isilon/lib/isi_cpool_cbm/isi_cbm_archive.cpp:1073) from isi_cbm_archive_common (/b/mnt/src/isilon/lib/isi_cpool_cbm/isi_cbm_archive.cpp:934) from isi_cbm_archive (/b/mnt/src/isilon/lib/isi_cpool_cbm/isi_cbm_archive.cpp:312)
In this case, an archive task is being processed:
archive/1:5d01:0232::HEAD
Determine the file pool policy:
CloudPool-5yrs
The specific CloudPools archive job cannot be determined from this error.
What happened:
File modified after stubbing began; lin 1:5d01:0232.
Check that file and see if it could be stubbed (It should during the next archive for that path).
Some other CloudPools error messages provide more cryptic errors. In these cases, you can usually determine the task as part of the clue, but may have to do some research to figure out the meaning of the error.
For Example:
varlog.tar/log/messages: 2017-04-20T18:47:52-06:00 <3.3> isilon-6 isi_cpool_d[3856]: [0x80f24f710]: /b/mnt/src/isilon/lib/isi_cpool_cbm/isi_cbm_error_util.cpp:send_cloudpools_event:314: isi_cpool_cbm error in isi_cph_read_md_blob: CloudPools Object not found. provider AWS, devid 6, account isilon archive, entitypath m000743091d8878539854870242892ceaa45di36/007034b0dea80d459f85b4a16d82cc48_00000000_0, filename , lin 0, offset -1, errormessage clapi error: CL_OBJ_NOT_FOUND; The specified key does not exist.: [error code: CBM_CLAPI_OBJECT_NOT_FOUND]
This does tell you a little:
- What is the Cloud Provider:
Provider AWS - Which node encountered the error:
Devid 6 - What account was used:
Account isilon archive - What is the object path being looked for in the cloud:
entitypath m000743091d8878539854870242892ceaa45di36/007034b0dea80d459f85b4a16d82cc48_00000000_0. - What the problem is:
error message clapi error: CL_OBJ_NOT_FOUND; The specified key does not exist.: [error code: CBM_CLAPI_OBJECT_NOT_FOUND
In this case, see if that object can be found in the cloud storage.
Some other cases:
An error occurred on the Cloud Storage - Check the cloud storage logs or errors: CL_SVR_INTERNAL_ERROR; We encountered an internal error. Please try again.: [error code: CBM_CLAPI_SERVER_ERROR] A network error occurred - make sure that Node can connect to the cloud: CL_COULDNT_CONNECT; Couldn't connect to server: error buf: couldn't connect to host: [error code: CBM_CLAPI_COULDNT_CONNECT] Authentication Failed - Make sure that the account identified has access on the Cloud target: CL_AUTHENTICATION_FAILED; 401: [error code: CBM_CLAPI_AUTHENTICATION_FAILED]