1822458
Members
2537
Online
109642
Solutions
SOLVED
The logging data you collected from the 11.23 client is not enough to tell me what the problem is. The only thing I can say with any degree of certainty looking at this data is that the rpc.lockd on the NFS server is either not replying to the client's lock requests or is replying to the wrong port number on the client because the client's rpc.lockd never gets the reply.
Here's the only real interesting thing in this logfile:
________________________________________
LOCKD QUEUES:
***** granted reclocks *****
***** msg queue *****
(4012a350), oh=ux01 29103, svr=ux05.quadax.net,
fh=400100020000000a000a000000003900673da64f000a000000000002000049e0,
op=2, range=[0, 2199023255552], client=ux01, cookie=5462873b
proc= 7, (msg reply = NULL)
(4012a2a0), oh=ux01 20030, svr=ux05.quadax.net,
fh=400100020000000a000a00000000203924ad37fb000a000000000002000049e0,
op=2, range=[0, 2199023255552], client=ux01, cookie=7d4dd4bf
proc= 7, (msg reply = NULL)
(4012a1f0), oh=ux01 15103, svr=ux05.quadax.net,
fh=400100020000000a000a00000000390119b4ad0a000a000000000002000049e0,
op=2, range=[0, 2199023255552], client=ux01, cookie=6a96ceb6
proc= 7, (msg reply = NULL)
(40129e80), oh=ux01 20967, svr=ux05.quadax.net,
fh=400100020000000a000a000000003c6d37b6ae37000a000000000002000049e0,
op=2, range=[0, 2199023255552], client=ux01, cookie=7a7d7082
proc= 7, (msg reply = NULL)
...
The first couple lines show me there are currently no locks being held by this client because the Granted queue is empty. The Message queue has many entries with a message reply status of NULL. This means the client has sent all these lock requests (and we know they are lock requests because the PROC= 7 maps to NLM_LOCK_MSG in the rpc.lockd protocol) to the server and never received a reply (reply = NULL).
So the client is trying desperately to lock files on the server and the server is either not replying or sending the replies to the wrong place.
The only way to really get a good read on this would be to enable debug rpc.lockd logging on the client and server *AND* collect a network trace during the problem. The lockd logging will tell us what the respective daemons are doing from a locking perspective and the network trace will tell us if the lock requests and replies are being sent to the correct destinations.
You have the correct method of turning on rpc.lockd logging on the 11.23 system (obviously since you sent in debug logging data), but on 11.31 systems it is controlled by a kctune parameter:
# kctune klm_log_level=9
This will enable debug rpc.lockd logging to the console buffer and /var/adm/syslog/syslog.log file.
As for the -C option, there's no harm in adding that to the LOCKD_OPTIONS string of the /etc/rc.config.d/nfsconf file on the 11.23 system. This option doesn't exist on 11.31, so only modify the 11.23 system. That way when rpc.lockd is re-started on the 11.23 system it will have the proper option.
Hope this helps,
Dave
I work at HPE
HPE Support Center offers support for your HPE services and products when and how you need it. Get started with HPE Support Center today.
[Any personal opinions expressed are mine, and not official statements on behalf of Hewlett Packard Enterprise]
Here's the only real interesting thing in this logfile:
________________________________________
LOCKD QUEUES:
***** granted reclocks *****
***** msg queue *****
(4012a350), oh=ux01 29103, svr=ux05.quadax.net,
fh=400100020000000a000a000000003900673da64f000a000000000002000049e0,
op=2, range=[0, 2199023255552], client=ux01, cookie=5462873b
proc= 7, (msg reply = NULL)
(4012a2a0), oh=ux01 20030, svr=ux05.quadax.net,
fh=400100020000000a000a00000000203924ad37fb000a000000000002000049e0,
op=2, range=[0, 2199023255552], client=ux01, cookie=7d4dd4bf
proc= 7, (msg reply = NULL)
(4012a1f0), oh=ux01 15103, svr=ux05.quadax.net,
fh=400100020000000a000a00000000390119b4ad0a000a000000000002000049e0,
op=2, range=[0, 2199023255552], client=ux01, cookie=6a96ceb6
proc= 7, (msg reply = NULL)
(40129e80), oh=ux01 20967, svr=ux05.quadax.net,
fh=400100020000000a000a000000003c6d37b6ae37000a000000000002000049e0,
op=2, range=[0, 2199023255552], client=ux01, cookie=7a7d7082
proc= 7, (msg reply = NULL)
...
The first couple lines show me there are currently no locks being held by this client because the Granted queue is empty. The Message queue has many entries with a message reply status of NULL. This means the client has sent all these lock requests (and we know they are lock requests because the PROC= 7 maps to NLM_LOCK_MSG in the rpc.lockd protocol) to the server and never received a reply (reply = NULL).
So the client is trying desperately to lock files on the server and the server is either not replying or sending the replies to the wrong place.
The only way to really get a good read on this would be to enable debug rpc.lockd logging on the client and server *AND* collect a network trace during the problem. The lockd logging will tell us what the respective daemons are doing from a locking perspective and the network trace will tell us if the lock requests and replies are being sent to the correct destinations.
You have the correct method of turning on rpc.lockd logging on the 11.23 system (obviously since you sent in debug logging data), but on 11.31 systems it is controlled by a kctune parameter:
# kctune klm_log_level=9
This will enable debug rpc.lockd logging to the console buffer and /var/adm/syslog/syslog.log file.
As for the -C option, there's no harm in adding that to the LOCKD_OPTIONS string of the /etc/rc.config.d/nfsconf file on the 11.23 system. This option doesn't exist on 11.31, so only modify the 11.23 system. That way when rpc.lockd is re-started on the 11.23 system it will have the proper option.
Hope this helps,
Dave
I work at HPE
HPE Support Center offers support for your HPE services and products when and how you need it. Get started with HPE Support Center today.
[Any personal opinions expressed are mine, and not official statements on behalf of Hewlett Packard Enterprise]
Remember from my previous post:
> # kctune klm_log_level=9
>
> This will enable debug rpc.lockd logging
> to the console buffer and
> /var/adm/syslog/syslog.log file.
This is the KLM subsystem logging the lock request processing to syslog as I indicated. When klm_log_level is set to 9 you should see this kind of information whenever the system is dealing with NFS file locks. If you don't see this stuff in the syslog then the system is currently not doing any NFS file locking.
Does this mean things are working now?
Dave
I work at HPE
HPE Support Center offers support for your HPE services and products when and how you need it. Get started with HPE Support Center today.
[Any personal opinions expressed are mine, and not official statements on behalf of Hewlett Packard Enterprise]
> # kctune klm_log_level=9
>
> This will enable debug rpc.lockd logging
> to the console buffer and
> /var/adm/syslog/syslog.log file.
This is the KLM subsystem logging the lock request processing to syslog as I indicated. When klm_log_level is set to 9 you should see this kind of information whenever the system is dealing with NFS file locks. If you don't see this stuff in the syslog then the system is currently not doing any NFS file locking.
Does this mean things are working now?
Dave
I work at HPE
HPE Support Center offers support for your HPE services and products when and how you need it. Get started with HPE Support Center today.
[Any personal opinions expressed are mine, and not official statements on behalf of Hewlett Packard Enterprise]
Ok, let us know if the problem reoccurs after the reboot. Hopefully if it does you'll have the data needed to troubleshoot it.
Dave
I work at HPE
HPE Support Center offers support for your HPE services and products when and how you need it. Get started with HPE Support Center today.
[Any personal opinions expressed are mine, and not official statements on behalf of Hewlett Packard Enterprise]
Dave
I work at HPE
HPE Support Center offers support for your HPE services and products when and how you need it. Get started with HPE Support Center today.
[Any personal opinions expressed are mine, and not official statements on behalf of Hewlett Packard Enterprise]
Hi Derrick,
> Are you saying that if logging is already
> on when the problem first occurs, you
> would expect to see some event which
> causes the lockd process to be
> unresponsive?
Exactly. The vast majority of the file locking issues I've worked on fall into two buckets:
1) Locking never worked
2) Locking worked for a while then stopped
In cases where locking has never worked, it's pretty easy to figure out by collecting a debug logfile from both sides and reproducing the problem. It's also very easy to reproduce the problem because locking is broken completely.
Cases where locking works for a while then mysteriously stops are much harder to figure out because it's usually not possible to reproduce them at will. In these situations having the historical data from before the problem began is critical as it helps pinpoint when the trouble began and what sequence of events took the system from a working state to a failing state. This helps us know where to focus our investigation.
> I know this is a very difficult (maybe
> impossible) question to answer, but I
> would very much like to avoid this issue
> occurring again. Based on the information
> shared already do you have any hunch as to
> what possible causes of the issue could
> be?
The data you've provided so far is all post-problem, so all I see is the client sending requests and never getting a response. Not enough information for me to determine root cause.
In the 2nd set of data you attached, I do see the client sending some CANCEL messages, so if rpc.lockd on the 11.23 system is not running with the -C option yet, that's definitely the next thing you should enable.
> Or any ideas for a way to more
> gracefully recover without needing to
> reboot?
Everything I've seen so far is pointing to the server stops responding. Also, the fact that you reboot the 11.31 system and the problem clears up is more justification of this being a server-side issue.
If you enter the following on the 11.31 server:
# /sbin/init.d/lockmgr stop
# /sbin/init.d/lockmgr start
and it doesn't recover gracefully then you may be left with no other recourse than rebooting the server.
> If the problem does occur again what would
> be the most useful tool for gathering
> network trace data? Nettl, tcpdump, other?
Nettl is fine. It captures data in a format that either netfmt or Wireshark can decode.
Regards,
Dave
I work at HPE
HPE Support Center offers support for your HPE services and products when and how you need it. Get started with HPE Support Center today.
[Any personal opinions expressed are mine, and not official statements on behalf of Hewlett Packard Enterprise]
> Are you saying that if logging is already
> on when the problem first occurs, you
> would expect to see some event which
> causes the lockd process to be
> unresponsive?
Exactly. The vast majority of the file locking issues I've worked on fall into two buckets:
1) Locking never worked
2) Locking worked for a while then stopped
In cases where locking has never worked, it's pretty easy to figure out by collecting a debug logfile from both sides and reproducing the problem. It's also very easy to reproduce the problem because locking is broken completely.
Cases where locking works for a while then mysteriously stops are much harder to figure out because it's usually not possible to reproduce them at will. In these situations having the historical data from before the problem began is critical as it helps pinpoint when the trouble began and what sequence of events took the system from a working state to a failing state. This helps us know where to focus our investigation.
> I know this is a very difficult (maybe
> impossible) question to answer, but I
> would very much like to avoid this issue
> occurring again. Based on the information
> shared already do you have any hunch as to
> what possible causes of the issue could
> be?
The data you've provided so far is all post-problem, so all I see is the client sending requests and never getting a response. Not enough information for me to determine root cause.
In the 2nd set of data you attached, I do see the client sending some CANCEL messages, so if rpc.lockd on the 11.23 system is not running with the -C option yet, that's definitely the next thing you should enable.
> Or any ideas for a way to more
> gracefully recover without needing to
> reboot?
Everything I've seen so far is pointing to the server stops responding. Also, the fact that you reboot the 11.31 system and the problem clears up is more justification of this being a server-side issue.
If you enter the following on the 11.31 server:
# /sbin/init.d/lockmgr stop
# /sbin/init.d/lockmgr start
and it doesn't recover gracefully then you may be left with no other recourse than rebooting the server.
> If the problem does occur again what would
> be the most useful tool for gathering
> network trace data? Nettl, tcpdump, other?
Nettl is fine. It captures data in a format that either netfmt or Wireshark can decode.
Regards,
Dave
I work at HPE
HPE Support Center offers support for your HPE services and products when and how you need it. Get started with HPE Support Center today.
[Any personal opinions expressed are mine, and not official statements on behalf of Hewlett Packard Enterprise]
> we tried to prevent it by happening by
> restarting the lockd process on the host
> server. This was done using the command:
> /sbin/init.d/lockmgr stop
> /sbin/init.d/lockmgr start
>
> Does the fact that the terminate command caused
> the process to stop functioning as a host
> (but did not terminate the process) provide any
> insight to what our problem could be to
> anyone?
Not me. As I've said, the best way to figure out why this problem happens is to enable logging on the client and server before the problem occurs and then wait for it to happen - on its own, not by terminating daemons. That's your best chance to capture the state of both systems when things are working properly and the event that causes one of them to start misbehaving.
Dave
I work at HPE
HPE Support Center offers support for your HPE services and products when and how you need it. Get started with HPE Support Center today.
[Any personal opinions expressed are mine, and not official statements on behalf of Hewlett Packard Enterprise]