Changing time several times causes snmp to deadlock

SNMP++/AGENT++
1

I have a function that changes the machine’s time, which is read and set via the mib.

I am running with agentx++ and the subagent appears to detach from the master agent. Whenever I change time more than a couple of times, snmp stops responding and keeps returning (snmp no such obejct) for any “get” query.

I use AgentPro to generate the code. Then I tried changing the time by using both clock_settime() and settimeofday() - from commit_set_request() and get identical results.

I also tried calling this function with a thread and detached it… Still the same.
Below is the log from a successful execution:

20120421.00:19:52: 139805823473408: (4)DEBUG : AgentXSlave: received something on ports
20120421.00:19:52: 139805823473408: (2)EVENT : AgentXRequestList: request received (context)(tid)(pid)(siz)(type)(err)(status): (), (14), (23), (0), (9), (0), (0)
20120421.00:19:52: 139805823473408: (2)DEBUG : LockQueue: adding lock request (ptr): (139805614696136)
20120421.00:19:52: 139805823473408: (2)DEBUG : LockQueue: adding release request (ptr): (139805614696136)
20120421.00:19:52: 139805823473408: (2)DEBUG : LockQueue: adding lock request (ptr): (139805614696136)
20120421.00:19:52: 139805823473408: (1)DEBUG : TaskManager: task manager found
20120421.00:19:52: 139805823473408: (2)DEBUG : TaskManager: after notify
20120421.00:19:52: 139805873833728: (2)EVENT : SubAgent: starting thread execution
20120421.00:19:52: 139805873833728: (2)EVENT : SubAgentXMib: COMMITSET (tid)(pid)(oid)…: (14), (23), (1.3.6.1.4.1.12182.4.1.7.1.41.0)
20120421.00:19:52: 139805873833728: (3)EVENT : Agent: committing set request: (14)
20120421.00:19:52: 139805873833728: (3)EVENT : RequestList: finished subrequest (ind)(oid)(val)(syn): (0), (1.3.6.1.4.1.12182.4.1.7.1.41.0), (2013-04-21T00:19:00Z), (4)
20120421.00:19:52: 139805873833728: (3)EVENT : AgentX: sending agentx pdu (sd)(type)(sid)(tid)(pid)(err)(errind): (9), (18), (3), (14), (23), (0), (0)
20120421.00:19:52: 139805873833728: (4)EVENT : RequestListAgentX: request answered (id)(status)(tid)(err)(removed)(sz): (14), (0), (14), (0), (0), (1)
20120421.00:19:52: 139805873833728: (2)DEBUG : LockQueue: adding release request (ptr): (139805614696136)
20130421.00:19:00: 139805873833728: (2)EVENT : Agent: finished thread execution

And here is a log that is dumped when deadlock happens:
20130421.00:19:09: 139805823473408: (4)DEBUG : AgentXSlave: received something on ports
20130421.00:19:09: 139805823473408: (2)EVENT : AgentXRequestList: request received (context)(tid)(pid)(siz)(type)(err)(status): (), (15), (25), (0), (5), (0), (0)
20130421.00:19:09: 139805823473408: (2)DEBUG : LockQueue: adding lock request (ptr): (139805614696136)
20130421.00:19:09: 139805823473408: (1)DEBUG : TaskManager: task manager found
20130421.00:19:09: 139805823473408: (2)DEBUG : TaskManager: after notify
20130421.00:19:09: 139805873833728: (2)EVENT : SubAgent: starting thread execution
20130421.00:19:09: 139805873833728: (2)EVENT : SubAgentXMib: GET (tid)(pid)(oid)…: (15), (25), (1.3.6.1.4.1.12182.4.1.7.1.40.0)
20130421.00:19:09: 139805873833728: (3)EVENT : Mib: process subrequest: get request, oid: (15), (1.3.6.1.4.1.12182.4.1.7.1.40.0)
20130421.00:19:09: 139805873833728: (3)EVENT : RequestList: finished subrequest (ind)(oid)(val)(syn): (0), (1.3.6.1.4.1.12182.4.1.7.1.40.0), (939), (66)
20130421.00:19:09: 139805873833728: (3)EVENT : AgentX: sending agentx pdu (sd)(type)(sid)(tid)(pid)(err)(errind): (9), (18), (3), (15), (25), (0), (0)
20130421.00:19:09: 139805873833728: (4)EVENT : RequestListAgentX: request answered (id)(status)(tid)(err)(removed)(sz): (15), (0), (15), (0), (1), (1)
20130421.00:19:09: 139805873833728: (2)DEBUG : LockQueue: adding release request (ptr): (139805614696136)
20130421.00:19:09: 139805873833728: (2)EVENT : Agent: finished thread execution
20130421.00:19:09: 139805823473408: (4)DEBUG : AgentXSlave: received something on ports
20130421.00:19:09: 139805823473408: (2)EVENT : AgentXRequestList: request received (context)(tid)(pid)(siz)(type)(err)(status): (), (16), (26), (0), (5), (0), (0)
20130421.00:19:09: 139805823473408: (2)DEBUG : LockQueue: adding lock request (ptr): (139805614696136)
20130421.00:19:09: 139805823473408: (1)DEBUG : TaskManager: task manager found
20130421.00:19:09: 139805823473408: (2)DEBUG : TaskManager: after notify
20130421.00:19:09: 139805873833728: (2)EVENT : SubAgent: starting thread execution
20130421.00:19:09: 139805873833728: (2)EVENT : SubAgentXMib: GET (tid)(pid)(oid)…: (16), (26), (1.3.6.1.4.1.12182.4.1.7.1.41.0)
20130421.00:19:09: 139805873833728: (3)EVENT : Mib: process subrequest: get request, oid: (16), (1.3.6.1.4.1.12182.4.1.7.1.41.0)
20130421.00:19:09: 139805873833728: (3)EVENT : RequestList: finished subrequest (ind)(oid)(val)(syn): (0), (1.3.6.1.4.1.12182.4.1.7.1.41.0), (2013-04-21T00:19:09Z), (4)
20130421.00:19:09: 139805873833728: (3)EVENT : AgentX: sending agentx pdu (sd)(type)(sid)(tid)(pid)(err)(errind): (9), (18), (3), (16), (26), (0), (0)
20130421.00:19:09: 139805873833728: (4)EVENT : RequestListAgentX: request answered (id)(status)(tid)(err)(removed)(sz): (16), (0), (16), (0), (1), (1)
20130421.00:19:09: 139805873833728: (2)DEBUG : LockQueue: adding release request (ptr): (139805614696136)
20130421.00:19:09: 139805873833728: (2)EVENT : Agent: finished thread execution

2

Hi,
What version of SNMP++ and AGENT++ are you using?
Latest versions should support cpu time on some operating systems, where this issue should not occur anymore.
On systems and older versions this behavior is known and cannot be (easily) changed, except by closing any Snmp sessions before the time change and reopening them afterwards.
Best regards,
Frank

3

Hello, thank you for your fast response :slight_smile:

I am using:

agent+±4.1.0
snmp+±3.3.10
Linux kernel 4.14.139