Forum Discussion

Eric_Frankenfie's avatar
Eric_Frankenfie
Icon for Nimbostratus rankNimbostratus
Dec 16, 2013

Logging Variables

I have an iRule which performs the following: 1. Read the contents of the XML through an XML profile 2. Sets the variable 'id' to $XML::values($I) 3. If the value equals an entry in the data group, sends the traffic to pool_A 4. Else, sends the traffic to pool_B 5. Logs the variable 'id' and the pool member the traffic was sent to

This is the iRule:

when XML_CONTENT_BASED_ROUTING
{ 
 for {set i 0} { $i < $XML::count } {incr i} { 
 set id $XML::values($i) 
if { ([matchclass $XML::values($i) equals DataGroup_by_Org])} { 
 pool pool_A 
 } else {
pool pool_B
}
 }
}

when LB_SELECTED {
log local0. "3189: orgName $id sent to [LB::server addr]"
}

I am having an issue with the logging portion. When I look at the log entry, the variable can't be read. This is the entry in the logs:

Dec 15 14:39:09 local/tmm1 err tmm1[21886]: 01220001:3: TCL error: Routing_by_Org - can't read "id": no such variable while executing "log local0. "3189: orgName $id sent to [LB::server addr]""

8 Replies

  • I take it you're doing this in a 10.x or early 11.x version? Your code works in 11.4, so I'd suggest some additional logging:

     

    when XML_CONTENT_BASED_ROUTING {
        log local0. "here"   
        for { set i 0 } { $i < $XML::count } { incr i } { 
            set id $XML::values($i)
            log local0. "Current ID = $id" 
            if { ( [matchclass $XML::values($i) equals DataGroup_by_Org] ) } { 
                log local0. "Sending to pool_A" 
                pool pool_A 
            } else {
                log local0. "Sending to pool_B"
                pool pool_B
            }
        }
    }
    when LB_SELECTED {
        log local0. "here: [LB::server addr]"
        log local0. "3189: orgName $id sent to [LB::server addr]"
    }

    Can you report back what you get in the logs?

     

  • The LTM is running 10.2 and I am pretty certain this was working properly last week. I have made the modifications you recommended, but I will need to wait for the developers to test.

     

  • The logging seems to be working now...The odd thing is the only changes were the additional logging statements.

    Dec 16 17:10:17 local/tmm info tmm[21885]: Rule Routing_by_Org : 3187
    
    Dec 16 17:10:17 local/tmm info tmm[21885]: Rule Routing_by_Org : Current orgName is 023099999
    
    Dec 16 17:10:17 local/tmm info tmm[21885]: Rule Routing_by_Org : Sending traffic to pool_A
    
    Dec 16 17:10:17 local/tmm info tmm[21885]: Rule Routing_by_Org : 3188: 10.206.57.239
    
    Dec 16 17:10:17 local/tmm info tmm[21885]: Rule Routing_by_Org : 3189: orgName 023099999 sent to 10.206.57.239
    
  • Looks like I am having this same issue again. The variable cannot be read because it does not look like the XML_CONTENT_BASED_ROUTING is being triggered. The second like of the iRule logs '3187' and when I search the logs there are no entries for 3187. Rather the logs only have the variable error which makes sense if the XML content is not being processed.

     

    Nothing changed since this last stopped working and I am at a loss.

     

    Any ideas?

     

  • I think there's really two issues here, the first being why the XMLCBR event isn't firing, and the second being the missing variable. If you think about this from an atomic TCP session perspective, any event that is triggered within a given TCP session should have access to the variables set by previous events within that same TCP session, so barring any anomalies, is it safe to say that not every TCP session has an XML request in it? Or is it possible that a given XML request doesn't match your xpath criteria? In either case, the safest thing you could probably do is to make sure the variable exists before you try to access it.

    if { [info exists id] } { log local0. "... $id ..." }    
    

    You could also apply try/catch logic, but that might be less intuitive than the above for the simple possibility of one missing variable. With the error avoided, you're free to troubleshoot the xpath, and it'd be interesting then to see if an XML request always precedes an LB selection in a TCP session. I'm still guessing not.

  • The developers have told me only certain methods will contain the XML we are looking for in the XML profile. Therefore, some traffic will match and other traffic will not match.

     

  • That more or less explains why the id value is failing, because the XMLCBR event isn't firing in every TCP session. So are you okay with the [info exists ] check in the LB_SELECTED event?