iRule logging [LB::server pool] crashes tmm on 11.4.1 HF3
F5 support suggested I post on DevCentral to ask if selecting a pool in the Client_Accepted event would mark that pool active (yes) and if making this selection so early in the process I am able to "override" the default pool configured for a virtual server (as far as I can tell, yes).
Instead of posting the question to DevCentral I thought I should just write a rule and test with some log messages. I found out I was right, but I also found out the rule I was using to test crashed tmm on 11.4.1 HF3 three times in a row. This did not happen in my DR environment which is on 11.6.0 HF3.
Basically, the rule and procs just log which pool is selected multiple times between events and function calls. I suspect there must be some difference in how [LB::server pool] is being used between versions. It seems like I have experienced a ton of odd behavior while working with my LTMs.
In the messages below there appears to be a time difference between the log message from the rule and the emerg logger messages. This was not the case in reality. I was monitoring the ltm log for my test messages with tail -f ltm | grep TEST and issuing a request I knew would trigger the rule execution. I saw my first log statement as expected and immediately the emerg logger statements were injected into my console.
- Has someone else experienced this?
- Does anyone know what causes this?
- Do I have to upgrade my production units to 11.6.0 HF3 to fix this?
Messages from daemon.log:
Mar 19 16:33:52 f5cm2 emerg logger: Re-starting tmm
Mar 19 16:33:52 f5cm2 emerg logger: Re-starting tmm1
Mar 19 16:37:24 f5cm2 emerg logger: Re-starting tmm
Mar 19 16:37:24 f5cm2 emerg logger: Re-starting tmm1
Mar 19 16:38:54 f5cm2 emerg logger: Re-starting tmm
Mar 19 16:38:54 f5cm2 emerg logger: Re-starting tmm1
`
Messages from ltm log:
`Mar 19 16:33:20 f5cm2 debug tmm1[8361]: Rule /Common/test : TEST: start pool in rule CLIENT_ACCEPT /Common/expected_pool_name
Mar 19 16:33:20 f5cm2 notice sod[5545]: 01140045:5: HA reports tmm NOT ready.
Mar 19 16:33:20 f5cm2 notice sod[5545]: 010c0050:5: Sod requests links down.
Mar 19 16:33:20 f5cm2 info lacpd[5552]: 01160016:6: Failover event detected. (Switchboard failsafe disabled while offline)
Mar 19 16:33:20 f5cm2 err bcm56xxd[6270]: 012c0010:3: Failover event detected. Marking external interfaces down. bsx.c(3724)
...snip...
Mar 19 16:36:54 f5cm2 debug tmm[15613]: Rule /Common/test : TEST: start pool in rule CLIENT_ACCEPT /Common/expected_pool_name
Mar 19 16:36:54 f5cm2 notice sod[5545]: 01140045:5: HA reports tmm NOT ready.
Mar 19 16:36:54 f5cm2 notice sod[5545]: 010c0050:5: Sod requests links down.
Mar 19 16:36:54 f5cm2 info lacpd[5552]: 01160016:6: Failover event detected. (Switchboard failsafe disabled while offline)
Mar 19 16:36:55 f5cm2 err bcm56xxd[6270]: 012c0010:3: Failover event detected. Marking external interfaces down. bsx.c(3724)
...snip...
Mar 19 16:38:24 f5cm2 debug tmm1[16328]: Rule /Common/test : TEST: start pool in rule CLIENT_ACCEPT /Common/expected_pool_name
Mar 19 16:38:24 f5cm2 notice sod[5545]: 01140045:5: HA reports tmm NOT ready.
Mar 19 16:38:24 f5cm2 notice sod[5545]: 010c0050:5: Sod requests links down.
Mar 19 16:38:24 f5cm2 err bcm56xxd[6270]: 012c0010:3: Failover event detected. Marking external interfaces down. bsx.c(3724)
`
test2 rule:
when CLIENT_ACCEPTED {
log local0.debug "TEST: start pool in rule CLIENT_ACCEPT [LB::server pool]"
call test::client_accepted
log local0.debug "TEST: pool in CLIENT_ACCEPT after function [LB::server pool]"
}
when HTTP_REQUEST {
log local0.debug "TEST: start pool in rule HTTP_REQUEST [LB::server pool]"
call test::http_request
log local0.debug "TEST: pool in HTTP_REQUEST after function [LB::server pool]"
}
test rule
proc client_accepted {
log local0.debug "TEST: pool coming into client_accept [LB::server pool]"
set var 1
switch $var {
"0" {
log local0.debug "TEST: var was set to $var."
}
"1" {
log local0.debug "TEST: var was set to $var."
pool pool_name
log local0.debug "TEST: pool selected in switch on var of client_accept [LB::server pool]"
}
}
log local0.debug "TEST: pool selected in client_accept [LB::server pool]"
}
proc http_request {
log local0.debug "TEST: pool coming into http_request [LB::server pool]"
pool pool2_name
log local0.debug "TEST: pool selected in http_request [LB::server pool]"
}