BES Logs ... What's in them? Part 10 of 20 (POLC log) - IT Policy
Posted 07-05-2009 at 04:00 AM by hdawg
Tags bb policy service, bes log, blackberry logs, blackberry polc log, blackberry policy, blackberry policy log, blackberry server logs, polc log, policy service
Welcome to Part 10 of the 20 part series looking at the BES logs. (Part 9).
My favorite log to tail is the BlackBerry Policy Service (POLC) log. To tail the log, use tail.exe from the Windows Server 2003 Resource Kit.
The POLC log is the place to go for looking at anything related to IT Policy, Application Control Policy and Software Configuration (Deployment).
Here's what you'll see when pushing an IT Policy:
[40000] (07/01 12:11:57.484):{0x166C} {testuser1@port3101.org, PIN=FFFFFFFF, UserId=70}SCS::PollDBQueueNewRequests - Queuing SET_ITPOLICY_REQUEST request
[40000] (07/01 12:12:12.687):{0x16E4} {testuser1@port3101.org, PIN=FFFFFFFF, UserId=70}RequestHandler:: DoWork - Processing SET_ITPOLICY_REQUEST request
[40000] (07/01 12:12:12.703):{0x16E4} {testuser1@port3101.org, PIN=FFFFFFFF, UserId=70}RequestHandler::SendToRelay - SubmitToRelaySendQ, Tag=11009
[30000] (07/01 12:12:12.718):{0x16E4} {testuser1@port3101.org, PIN=FFFFFFFF, UserId=70}RequestHandler::SendQueuedITAdminCommandToDevice Sending data to device, contentType=ITADMIN, size=537, RefId=0, TransactionId=-901092938, Tag=13913
[40000] (07/01 12:12:12.718):{0x16E4} {testuser1@port3101.org, PIN=FFFFFFFF, UserId=70}RequestHandler::SendToRelay - SubmitToRelaySendQ, Tag=13913
[40000] (07/01 12:12:12.734):{0x16E4} {testuser1@port3101.org, PIN=FFFFFFFF, UserId=70}RequestHandler:: DoWork - Completed Processing SET_ITPOLICY_REQUEST request
[40000] (07/01 12:14:07.203):{0x11B0} {testuser1@port3101.org, PIN=FFFFFFFF, UserId=70}RequestHandler:: DoWork - Processing DEVICE_SEND_STATUS_EVENT request
[30000] (07/01 12:14:07.203):{0x11B0} {testuser1@port3101.org, PIN=FFFFFFFF, UserId=70}RequestHandler:: DoDeviceSentProcessing - Message has been delivered to device, Tag=13913
[40000] (07/01 12:14:07.203):{0x11B0} {testuser1@port3101.org, PIN=FFFFFFFF, UserId=70}RequestHandler:: DoITPolicyDeviceSentProcessing - ITPolicy GME Receive Ack for the command SET_IT_POLICY_COMMAND - Processing packet, Tag=13913
[40000] (07/01 12:14:07.218):{0x11B0} {testuser1@port3101.org, PIN=FFFFFFFF, UserId=70}RequestHandler:: DoWork - Completed Processing DEVICE_SEND_STATUS_EVENT request
[40000] (07/01 12:14:15.203):{0xA4C} {testuser1@port3101.org, PIN=FFFFFFFF, UserId=70}RequestHandler:: DoWork - Processing NEW_MESSAGE request
[40000] (07/01 12:14:15.203):{0xA4C} {testuser1@port3101.org, PIN=FFFFFFFF, UserId=70}RequestHandler:: DoGMEReceiveProcessing - Receiving packet from device, size=47, TransactionId=948454966, Tag=9844749, content type=ITADMIN, cmd=0x3
[40000] (07/01 12:14:15.203):{0xA4C} {testuser1@port3101.org, PIN=FFFFFFFF, UserId=70}RequestHandler::HandleITADMINDataCommand - ITPolicy Success Ack for the command SET_IT_POLICY_COMMAND - Processing packet, Tag=9844749
[40000] (07/01 12:14:15.203):{0xA4C} {testuser1@port3101.org, PIN=FFFFFFFF, UserId=70}RequestHandler::SendToRelay - SubmitToRelaySendQ, Tag=9844749
[40000] (07/01 12:14:15.203):{0xA4C} {testuser1@port3101.org, PIN=FFFFFFFF, UserId=70}RequestHandler:: DoWork - Completed Processing NEW_MESSAGE request
Alternatively, you could have an attempt to set an IT Policy FAIL ...
[20000] (06/01 19:06:00):{0x24E0} {userA@company.com, PIN=FFFFFFFF, UserId=1}RequestHandler::HandleITADMINDataCommand - ITPolicy Fail Ack for the command SET_IT_POLICY_COMMAND - Processing packet, Tag=18265833
If that happens, unfortunately the only solution that works is to wipe and reactivate.
Tomorrow I'll continue with the POLC log looking at Application Control Policy and Software Configuration.
My favorite log to tail is the BlackBerry Policy Service (POLC) log. To tail the log, use tail.exe from the Windows Server 2003 Resource Kit.
The POLC log is the place to go for looking at anything related to IT Policy, Application Control Policy and Software Configuration (Deployment).
Here's what you'll see when pushing an IT Policy:
[40000] (07/01 12:11:57.484):{0x166C} {testuser1@port3101.org, PIN=FFFFFFFF, UserId=70}SCS::PollDBQueueNewRequests - Queuing SET_ITPOLICY_REQUEST request
[40000] (07/01 12:12:12.687):{0x16E4} {testuser1@port3101.org, PIN=FFFFFFFF, UserId=70}RequestHandler:: DoWork - Processing SET_ITPOLICY_REQUEST request
[40000] (07/01 12:12:12.703):{0x16E4} {testuser1@port3101.org, PIN=FFFFFFFF, UserId=70}RequestHandler::SendToRelay - SubmitToRelaySendQ, Tag=11009
[30000] (07/01 12:12:12.718):{0x16E4} {testuser1@port3101.org, PIN=FFFFFFFF, UserId=70}RequestHandler::SendQueuedITAdminCommandToDevice Sending data to device, contentType=ITADMIN, size=537, RefId=0, TransactionId=-901092938, Tag=13913
[40000] (07/01 12:12:12.718):{0x16E4} {testuser1@port3101.org, PIN=FFFFFFFF, UserId=70}RequestHandler::SendToRelay - SubmitToRelaySendQ, Tag=13913
[40000] (07/01 12:12:12.734):{0x16E4} {testuser1@port3101.org, PIN=FFFFFFFF, UserId=70}RequestHandler:: DoWork - Completed Processing SET_ITPOLICY_REQUEST request
[40000] (07/01 12:14:07.203):{0x11B0} {testuser1@port3101.org, PIN=FFFFFFFF, UserId=70}RequestHandler:: DoWork - Processing DEVICE_SEND_STATUS_EVENT request
[30000] (07/01 12:14:07.203):{0x11B0} {testuser1@port3101.org, PIN=FFFFFFFF, UserId=70}RequestHandler:: DoDeviceSentProcessing - Message has been delivered to device, Tag=13913
[40000] (07/01 12:14:07.203):{0x11B0} {testuser1@port3101.org, PIN=FFFFFFFF, UserId=70}RequestHandler:: DoITPolicyDeviceSentProcessing - ITPolicy GME Receive Ack for the command SET_IT_POLICY_COMMAND - Processing packet, Tag=13913
[40000] (07/01 12:14:07.218):{0x11B0} {testuser1@port3101.org, PIN=FFFFFFFF, UserId=70}RequestHandler:: DoWork - Completed Processing DEVICE_SEND_STATUS_EVENT request
[40000] (07/01 12:14:15.203):{0xA4C} {testuser1@port3101.org, PIN=FFFFFFFF, UserId=70}RequestHandler:: DoWork - Processing NEW_MESSAGE request
[40000] (07/01 12:14:15.203):{0xA4C} {testuser1@port3101.org, PIN=FFFFFFFF, UserId=70}RequestHandler:: DoGMEReceiveProcessing - Receiving packet from device, size=47, TransactionId=948454966, Tag=9844749, content type=ITADMIN, cmd=0x3
[40000] (07/01 12:14:15.203):{0xA4C} {testuser1@port3101.org, PIN=FFFFFFFF, UserId=70}RequestHandler::HandleITADMINDataCommand - ITPolicy Success Ack for the command SET_IT_POLICY_COMMAND - Processing packet, Tag=9844749
[40000] (07/01 12:14:15.203):{0xA4C} {testuser1@port3101.org, PIN=FFFFFFFF, UserId=70}RequestHandler::SendToRelay - SubmitToRelaySendQ, Tag=9844749
[40000] (07/01 12:14:15.203):{0xA4C} {testuser1@port3101.org, PIN=FFFFFFFF, UserId=70}RequestHandler:: DoWork - Completed Processing NEW_MESSAGE request
- First is the IT Policy push being queued up.
- Then the BES actually processes the request ... notice the short delay ... at this point the policy is Processing.
- The IT Policy is actually sent and confirmed as sent (but not received yet) ... you'd see a IT Policy Status of Sent at this point.
- The handheld has confirmed receipt of the IT Policy, but has not yet applied it. At this point, the policy status will show as Received.
- The handheld has processed the IT Policy change; at this point, the policy status will show as Applied Successfully.
Alternatively, you could have an attempt to set an IT Policy FAIL ...
[20000] (06/01 19:06:00):{0x24E0} {userA@company.com, PIN=FFFFFFFF, UserId=1}RequestHandler::HandleITADMINDataCommand - ITPolicy Fail Ack for the command SET_IT_POLICY_COMMAND - Processing packet, Tag=18265833
If that happens, unfortunately the only solution that works is to wipe and reactivate.
Tomorrow I'll continue with the POLC log looking at Application Control Policy and Software Configuration.
Total Comments 0











